add time in queue#1481
Conversation
There was a problem hiding this comment.
Looks good but we should floor wall clock based durations at zero. This also doesn't necessarily measure time in the queue; it depends on whether the timestamp type is CreationTime (timestamp taken at sender) or LogAppendTime (timestamp taken at broker). It's only really the time spent in the queue if the timestamp is a log append time. There should be different tag names based on this, e.g. "record.total_time" if it's a creation timestamp. As you're probably aware log.message.timestamp.type may be configured at the topic level, so traced applications could see very different values for this tag otherwise.
|
|
||
| final long produceTime = record.timestamp(); | ||
| final long consumeTime = TimeUnit.NANOSECONDS.toMillis(span.getLocalRootSpan().getStartTime()); | ||
| span.setTag("record.time_in_queue_milliseconds", consumeTime - produceTime); |
There was a problem hiding this comment.
Since both timestamps are wall clock based, this duration can be negative. If that would break things elsewhere, it should be guarded with a Math.max(consumeTime - produceTime, 0L)
There was a problem hiding this comment.
I agree with using max. Also, can we rename to record.queue_time_ms? I think spelling it out is unnecessarily verbose.
|
|
||
| final long produceTime = record.timestamp(); | ||
| final long consumeTime = TimeUnit.NANOSECONDS.toMillis(span.getLocalRootSpan().getStartTime()); | ||
| span.setTag("record.time_in_queue_milliseconds", consumeTime - produceTime); |
There was a problem hiding this comment.
If we add "record.time_in_queue_milliseconds" to DDTags we can avoid materialising its UTF-8 encoding during serialisation.
There was a problem hiding this comment.
we haven't really done this to all the integrations... for example, see line 62-63. Let's not worry about it in this PR.
tylerbenson
left a comment
tylerbenson
left a comment
There was a problem hiding this comment.
Thanks for the contribution @ziquanmiao! A few changes below... You also need to update KafkaClientTest and KafkaStreamsTest with the new tag.
|
|
||
| final long produceTime = record.timestamp(); | ||
| final long consumeTime = TimeUnit.NANOSECONDS.toMillis(span.getLocalRootSpan().getStartTime()); | ||
| span.setTag("record.time_in_queue_milliseconds", consumeTime - produceTime); |
There was a problem hiding this comment.
we haven't really done this to all the integrations... for example, see line 62-63. Let's not worry about it in this PR.
|
|
||
| final long produceTime = record.timestamp(); | ||
| final long consumeTime = TimeUnit.NANOSECONDS.toMillis(span.getLocalRootSpan().getStartTime()); | ||
| span.setTag("record.time_in_queue_milliseconds", consumeTime - produceTime); |
There was a problem hiding this comment.
I agree with using max. Also, can we rename to record.queue_time_ms? I think spelling it out is unnecessarily verbose.
| span.setTag("offset", record.offset()); | ||
|
|
||
| final long produceTime = record.timestamp(); | ||
| final long consumeTime = TimeUnit.NANOSECONDS.toMillis(span.getLocalRootSpan().getStartTime()); |
There was a problem hiding this comment.
| final long consumeTime = TimeUnit.NANOSECONDS.toMillis(span.getLocalRootSpan().getStartTime()); | |
| final long consumeTime = TimeUnit.NANOSECONDS.toMillis(span.getStartTime()); |
Semantically, the span passed into the method is the one representing the consuming of the message. Besides, it will always be the root span anyway.
|
@richardstartin I don't think we'd be able to distinguish which kind of timestamp is represented. Perhaps it would be better to use something more generic like |
|
@tylerbenson to distinguish just look at the timestamp type on the consumer record :) |
…nts class so we can capture their encodings
|
@ziquanmiao I've updated the tests and applied some of the suggestions made. We can forget about the timestamp type for the time being. Just be aware if becomes pertinent to know whether it's a broker or sender timestamp, we could do something about it. |
* Add time in queue (DataDog/dd-trace-java#1481) * Minor upgrades (DataDog/dd-trace-java#1495) * Allow user to disable kafka time in queue tag (DataDog/dd-trace-java#1487) * Replace Set<Integer> with BitSet for HTTP statuses (DataDog/dd-trace-java#1496) * Register WeakMapProvider earlier in AgentInstaller (DataDog/dd-trace-java#1480) * Update codenarc (DataDog/dd-trace-java#1500) Co-authored-by: Tyler Benson <tyler.benson@datadoghq.com> Co-authored-by: Nikolay Martynov <mar.kolya@gmail.com> Co-authored-by: Richard Startin <richard.startin@datadoghq.com>
3 participants
Adds visibility on how long transactions spend in a kafka queue
submits the time difference between the start of the consumer span and the record's timestamp to generate an estimation of time spent in queue