log: indicate which sink is the cause of an error when a logging error is reporte #72461
Labels
A-error-handling
Error messages, error propagations/annotations
A-logging
In and around the logging infrastructure.
C-enhancement
Solution expected to add code/behavior + preserve backward-compat (pg compat issues are exception)
Comments
knz
added
C-enhancement
knz
added a commit
to rauchenstein/cockroach
that referenced
this issue
Nov 4, 2021
Release note: None
knz
added a commit
to rauchenstein/cockroach
that referenced
this issue
Nov 4, 2021
Release note: None
andreimatei
added a commit
to andreimatei/cockroach
that referenced
this issue
Jun 3, 2022
This is a rewrite of bufferSink (now called bufferedSink). As opposed to before, the code is smaller, more efficient, and, most importantly, simpler. I couldn't understand the previous code well, and I think it made new additions to it (in particular, adding a shutdown sequence) hard to analyze. The semantics of this buffer are now better and simpler. Before, a log message was traveling through a sequence of two buffers before being eventually delivered to the wrapped sink: 1. The message was first placed into an accumulator buffer. 2. Then, when that buffer grows too old or too large, the accumulator buffer is placed into a queue to be flushed later, and the accumulator was reset. 3. There was a limit on the size of this queue of batches to be flushed. When the queue was full, new messages were dropped. There were two goroutines managing these two buffers, which is one too many. This behavior of queuing multiple, distinct flushes, was peculiar at best. There's generally no reason to not coalesce all the flushes into one, thus speeding them up and reducing the risk of message drops. The bufferSink's memory limit was not explicit, and difficult enough to infer: it was set indirectly from the combination of limits on the two buffers, expressed in different units. Now, the sequence of two buffers (the accumulator and the flush queue) is gone. There's a single buffer accumulating new messages, plus at most one in-flight flush which captures its buffer. As soon as a flush is triggered, the buffer is reset. The buffer is now configured with a memory limit and, when that limit is reached, the _oldest_ messages in the buffer are dropped, instead of the newest. This, combined with the blocking semantics of the forceSync option, means that a forceSync message is never dropped (unless its size is, by itself, larger than the buffer limit). The number of goroutines running for the bufferSink drops from two to one. Fixes cockroachdb#72461 by including the type name of the failed sink in error messages. I think that should be good enough. Release note: None
andreimatei
added a commit
to andreimatei/cockroach
that referenced
this issue
Jun 7, 2022
This is a rewrite of bufferSink (now called bufferedSink). As opposed to before, the code is smaller, more efficient, and, most importantly, simpler. I couldn't understand the previous code well, and I think it made new additions to it (in particular, adding a shutdown sequence) hard to analyze. The semantics of this buffer are now better and simpler. Before, a log message was traveling through a sequence of two buffers before being eventually delivered to the wrapped sink: 1. The message was first placed into an accumulator buffer. 2. Then, when that buffer grows too old or too large, the accumulator buffer is placed into a queue to be flushed later, and the accumulator was reset. 3. There was a limit on the size of this queue of batches to be flushed. When the queue was full, new messages were dropped. There were two goroutines managing these two buffers, which is one too many. This behavior of queuing multiple, distinct flushes, was peculiar at best. There's generally no reason to not coalesce all the flushes into one, thus speeding them up and reducing the risk of message drops. The bufferSink's memory limit was not explicit, and difficult enough to infer: it was set indirectly from the combination of limits on the two buffers, expressed in different units. Now, the sequence of two buffers (the accumulator and the flush queue) is gone. There's a single buffer accumulating new messages, plus at most one in-flight flush which captures its buffer. As soon as a flush is triggered, the buffer is reset. The buffer is now configured with a memory limit and, when that limit is reached, the _oldest_ messages in the buffer are dropped, instead of the newest. This, combined with the blocking semantics of the forceSync option, means that a forceSync message is never dropped (unless its size is, by itself, larger than the buffer limit). The number of goroutines running for the bufferSink drops from two to one. Fixes cockroachdb#72461 by including the type name of the failed sink in error messages. I think that should be good enough. Release note: None
abarganier
pushed a commit
to abarganier/cockroach
that referenced
this issue
Jun 22, 2022
This is a rewrite of bufferSink (now called bufferedSink). As opposed to before, the code is smaller, more efficient, and, most importantly, simpler. I couldn't understand the previous code well, and I think it made new additions to it (in particular, adding a shutdown sequence) hard to analyze. The semantics of this buffer are now better and simpler. Before, a log message was traveling through a sequence of two buffers before being eventually delivered to the wrapped sink: 1. The message was first placed into an accumulator buffer. 2. Then, when that buffer grows too old or too large, the accumulator buffer is placed into a queue to be flushed later, and the accumulator was reset. 3. There was a limit on the size of this queue of batches to be flushed. When the queue was full, new messages were dropped. There were two goroutines managing these two buffers, which is one too many. This behavior of queuing multiple, distinct flushes, was peculiar at best. There's generally no reason to not coalesce all the flushes into one, thus speeding them up and reducing the risk of message drops. The bufferSink's memory limit was not explicit, and difficult enough to infer: it was set indirectly from the combination of limits on the two buffers, expressed in different units. Now, the sequence of two buffers (the accumulator and the flush queue) is gone. There's a single buffer accumulating new messages, plus at most one in-flight flush which captures its buffer. As soon as a flush is triggered, the buffer is reset. The buffer is now configured with a memory limit and, when that limit is reached, the _oldest_ messages in the buffer are dropped, instead of the newest. This, combined with the blocking semantics of the forceSync option, means that a forceSync message is never dropped (unless its size is, by itself, larger than the buffer limit). The number of goroutines running for the bufferSink drops from two to one. Fixes cockroachdb#72461 by including the type name of the failed sink in error messages. I think that should be good enough. Release note: None
abarganier
pushed a commit
to abarganier/cockroach
that referenced
this issue
Jun 22, 2022
This is a rewrite of bufferSink (now called bufferedSink). As opposed to before, the code is smaller, more efficient, and, most importantly, simpler. I couldn't understand the previous code well, and I think it made new additions to it (in particular, adding a shutdown sequence) hard to analyze. The semantics of this buffer are now better and simpler. Before, a log message was traveling through a sequence of two buffers before being eventually delivered to the wrapped sink: 1. The message was first placed into an accumulator buffer. 2. Then, when that buffer grows too old or too large, the accumulator buffer is placed into a queue to be flushed later, and the accumulator was reset. 3. There was a limit on the size of this queue of batches to be flushed. When the queue was full, new messages were dropped. There were two goroutines managing these two buffers, which is one too many. This behavior of queuing multiple, distinct flushes, was peculiar at best. There's generally no reason to not coalesce all the flushes into one, thus speeding them up and reducing the risk of message drops. The bufferSink's memory limit was not explicit, and difficult enough to infer: it was set indirectly from the combination of limits on the two buffers, expressed in different units. Now, the sequence of two buffers (the accumulator and the flush queue) is gone. There's a single buffer accumulating new messages, plus at most one in-flight flush which captures its buffer. As soon as a flush is triggered, the buffer is reset. The buffer is now configured with a memory limit and, when that limit is reached, the _oldest_ messages in the buffer are dropped, instead of the newest. This, combined with the blocking semantics of the forceSync option, means that a forceSync message is never dropped (unless its size is, by itself, larger than the buffer limit). The number of goroutines running for the bufferSink drops from two to one. Fixes cockroachdb#72461 by including the type name of the failed sink in error messages. I think that should be good enough. Release note: None
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
This is follow up work to #70330.
Currently in
log/flags.gowe see the following:The
logging errormessage does not include detail about which sink is causing the error, which makes troubleshooting difficult.We want to annotate some information about the sink in the error report.
Jira issue: CRDB-11169
The text was updated successfully, but these errors were encountered: