Repository navigation
Conversation
…3207 * including high frequency logging filter, once per 10 seconds
akka-ci
added
validating
|
Test PASSed. |
There was a problem hiding this comment.
The functionality sounds definitely useful.
I find the API and the implementation a bit indirect so that I'm not completely sure that it works correctly in all cases or if we want to accept some edge cases. I haven't thought enough about it to suggest improvements, though.
| } | ||
| } | ||
|
|
||
| def reset(): Unit = |
There was a problem hiding this comment.
used from test to avoid waiting for timer to trigger it, the entire class is private[akka]
| val d = discarded | ||
| val discardInfo = | ||
| if (d == 0) "" | ||
| else s" ([$d] similar log messages were discarded in last [${within.toMillis} ms])" // first time after a reset |
There was a problem hiding this comment.
As this is logged only lazily, I guess, the statement is not quite accurate, since the time between reset and getting here again is not counted. Not sure if it is important, but I could imagine that it would get confusing in the edge case where the next message only comes in quite a bit later.
There was a problem hiding this comment.
I can keep around a timestamp of when the the first message was discarded.
I was thinking about if I should log the count when the reset happens, but keeping around a previous lazy log statement is not an option and then it would have to be some general message which isn't as useful.
There was a problem hiding this comment.
If these aren't shared between different log purposes then the general message could be as useful if a HiFrequencyLogger has an event name e.g. N log messages were dropped for [Dropped Artery Message].
| } | ||
|
|
||
| def reset(): Unit = | ||
| discarded = math.max(0L, count.getAndSet(0) - maxCalls) |
There was a problem hiding this comment.
Is it really guaranteed, that discarded is already set when the next if (n == 1L) branch is taken? Maybe just setting a volatile flag here would be enough, so that the complete handling code can be in filter?
There was a problem hiding this comment.
in theory that might be possible but the result wouldn't be worse than possibly misreporting the count
in practice reset is only called from the scheduled timer, i.e. not often
don't think I can move it to filter because the count is reset to 0 here
There was a problem hiding this comment.
A thread in filter could see count as 0 but not see the discarded value so we could miss logging the discard info some times as d == 0 or we could log the previous discard value which would be confusing.
How about setting discard to 0 in the else of working out discardInfo and scheduling the timer after doing this so we know that it won't (due to some crazy pause) also be touching discard?
| val d = discarded | ||
| val discardInfo = | ||
| if (d == 0) "" | ||
| else s" ([$d] similar log messages were discarded in last [${within.toMillis} ms])" // first time after a reset |
There was a problem hiding this comment.
I guess there is a possibility that one thread is still busy with this branch while another already logged the second message. Probably not to bad but might still be confusing. In any case, might warrant a comment if this is a trade off that we would accept.
There was a problem hiding this comment.
Right, but the alternative would be to introduce a lock (synchronized) and that is not something we would want. I don't think it will matter much. They will have very identical log timestamps. Also, the typical usage is probably to have maxCalls = 1 and then it will not happen.
| } else { | ||
| droppedMessageLogging.filter { discardInfo ⇒ | ||
| log.warning( | ||
| s"Dropping message [{}] from [{}] to [{}] due to quarantined system [{}]$discardInfo", |
There was a problem hiding this comment.
We might be losing the exact point of time here when the log message changes from due to {} to due to quarantined system because of the filter putting all messages into the same bin. Maybe it's not important enough but otherwise it could be confusing.
There was a problem hiding this comment.
I don't think it's important. It was debug logging after all, and we have other important logging of quarantine events.
akka-ci
added
validating
|
Test FAILed. |
|
PLS BUILD |
akka-ci
added
validating
|
Test PASSed. |
akka-ci
added
validating
|
Test PASSed. |
1 similar comment
|
Test PASSed. |
akka-ci
added
validating
|
Test FAILed. |
chbatey
left a comment
chbatey
left a comment
There was a problem hiding this comment.
👍 to getting this in, would prevent the need for DEBUG logs / OS send queue stats for a tricky thing to DEBUG
|
Superseded by simplified logging of |
4 participants
This is probably useful in more places.
Refs #23207