REM: Add publishing time to publisher log #295
Conversation
EIFA-4757 Information message contains information about time needed to communicate with MB. Publishing time has been added to publisher log.
| LocalDateTime publishStartTime = LocalDateTime.now(); | ||
| channel.basicPublish(exchangeName, routingKey, msgProps, msg.getBytes()); | ||
| log.info("Published message {} with size {} bytes on exchange '{}' with routing key '{}'", eventId, | ||
| msg.getBytes().length, exchangeName, routingKey); | ||
| LocalDateTime publishEndTime = LocalDateTime.now(); | ||
| Duration diff = Duration.between(publishStartTime, publishEndTime); | ||
| String duration = String.format("%d:%02d:%02d.%03d", | ||
| diff.toHours(), | ||
| diff.toMinutesPart(), | ||
| diff.toSecondsPart(), | ||
| diff.toMillisPart()); | ||
| log.info("Published message {} with size {} bytes on exchange '{}' with routing key '{}' with the duration of {}", eventId, | ||
| msg.getBytes().length, exchangeName, routingKey, duration); |
There was a problem hiding this comment.
I don't think LocalDateTime is a great choice when you want to measure the duration between two events. Since it denotes a timezone-less local time it'll behave quite badly during DST shifts, and in general when the system's time changes. Prefer a monotonic clock like System.nanoTime().
I also don't think logging time series data like this is a great idea in general. It would be much more useful to expose a proper numerical metric (e.g. via OpenTelemetry or Prometheus) that interested parties can pick up.
Don't you want to include the time required to get the message confirmed by the broker?
There was a problem hiding this comment.
Yes, please, use nanoTime(), as described, for example, here: https://www.baeldung.com/java-measure-elapsed-time. I think it's the most effective method to measure method time.
The general idea here is to help monitor liveness/healthness of communication line to MB and/or the MB itself. It was originated by people managing REMReM/MB components.
There were some tests performed with Micrometer. They offer good data, but they have a statistical nature. However, when an issue related to particular event is to be investigated, it publish time may come very handy.
There was a problem hiding this comment.
I don't think LocalDateTime is a great choice when you want to measure the duration between two events. Since it denotes a timezone-less local time it'll behave quite badly during DST shifts, and in general when the system's time changes. Prefer a monotonic clock like System.nanoTime().
I also don't think logging time series data like this is a great idea in general. It would be much more useful to expose a proper numerical metric (e.g. via OpenTelemetry or Prometheus) that interested parties can pick up.
Don't you want to include the time required to get the message confirmed by the broker?
Done
There was a problem hiding this comment.
Yes, please, use nanoTime(), as described, for example, here: https://www.baeldung.com/java-measure-elapsed-time. I think it's the most effective method to measure method time.
The general idea here is to help monitor liveness/healthness of communication line to MB and/or the MB itself. It was originated by people managing REMReM/MB components.
There were some tests performed with Micrometer. They offer good data, but they have a statistical nature. However, when an issue related to particular event is to be investigated, it publish time may come very handy.
Done
| LocalDateTime publishStartTime = LocalDateTime.now(); | ||
| channel.basicPublish(exchangeName, routingKey, msgProps, msg.getBytes()); | ||
| log.info("Published message {} with size {} bytes on exchange '{}' with routing key '{}'", eventId, | ||
| msg.getBytes().length, exchangeName, routingKey); | ||
| LocalDateTime publishEndTime = LocalDateTime.now(); | ||
| Duration diff = Duration.between(publishStartTime, publishEndTime); | ||
| String duration = String.format("%d:%02d:%02d.%03d", | ||
| diff.toHours(), | ||
| diff.toMinutesPart(), | ||
| diff.toSecondsPart(), | ||
| diff.toMillisPart()); | ||
| log.info("Published message {} with size {} bytes on exchange '{}' with routing key '{}' with the duration of {}", eventId, | ||
| msg.getBytes().length, exchangeName, routingKey, duration); |
There was a problem hiding this comment.
Yes, please, use nanoTime(), as described, for example, here: https://www.baeldung.com/java-measure-elapsed-time. I think it's the most effective method to measure method time.
The general idea here is to help monitor liveness/healthness of communication line to MB and/or the MB itself. It was originated by people managing REMReM/MB components.
There were some tests performed with Micrometer. They offer good data, but they have a statistical nature. However, when an issue related to particular event is to be investigated, it publish time may come very handy.
3 participants
EIFA-4757
Information message contains information about time needed to communicate with MB. Publishing time has been added to publisher log.
Applicable Issues
Description of the Change
Publishing time has been added to publisher log.
Alternate Designs
Possible Drawbacks
Sign-off
Developer's Certificate of Origin 1.1
By making a contribution to this project, I certify that:
(a) The contribution was created in whole or in part by me and I
have the right to submit it under the open source license
indicated in the file; or
(b) The contribution is based upon previous work that, to the best
of my knowledge, is covered under an appropriate open source
license and I have the right under that license to submit that
work with modifications, whether created in whole or in part
by me, under the same open source license (unless I am
permitted to submit under a different license), as indicated
in the file; or
(c) The contribution was provided directly to me by some other
person who certified (a), (b) or (c) and I have not modified
it.
(d) I understand and agree that this project and the contribution
are public and that a record of the contribution (including all
personal information I submit with it, including my sign-off) is
maintained indefinitely and may be redistributed consistent with
this project or the open source license(s) involved.
Signed-off-by: