Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Adds overdue information about setting timestamps and duration #46

Merged
merged 1 commit into from
Sep 10, 2016

Conversation

codefromthecrypt
Copy link
Member

This comes up a lot, and I had notes. Here's an attempt to collect them all into one place.

See openzipkin/zipkin#1280
See #40

@codefromthecrypt
Copy link
Member Author

PTAL @mansu @rogeralsing @marcingrzejszczak @abesto @yurishkuro and anyone else who cares

@codefromthecrypt
Copy link
Member Author

also cc @basvanbeek @nicmunroe

@codefromthecrypt
Copy link
Member Author

and also @jcarres-mdsol

codefromthecrypt pushed a commit to openzipkin/zipkin that referenced this pull request Sep 9, 2016
Previously, Zipkin wrote the wrong timestamp when receiving spans that
are missing timestamp data. It is still the case that instrumentation
libraries aren't updated to add this. Until then, we have to guess a
little more smartly so as to not record incorrect timestamps.

This does the following when Span.timestamp is missing:
* If there is a "cs", use that (because client always is authoritative)
* If there is an "sr" in a root span, use that
* Otherwise, return null instead of choosing an arbitrary low value.

This also is more careful when updating timestamps, for example, in
MySQL, we only update if the span's timestamp is set.

This change has some impact, notably that duration queries now require
instrumentation to update to actually set Span.duration. Also,
elasticsearch "timestamp_millis" field is now used directly for queries.

To facilitate better instrumentation, I've added more documentation:
openzipkin/openzipkin.github.io#46

Fixes #1281
codefromthecrypt pushed a commit to openzipkin/zipkin that referenced this pull request Sep 9, 2016
Previously, Zipkin wrote the wrong timestamp when receiving spans that
are missing timestamp data. It is still the case that instrumentation
libraries aren't updated to add this. Until then, we have to guess a
little more smartly so as to not record incorrect timestamps.

This does the following when Span.timestamp is missing:
* If there is a "cs", use that (because client always is authoritative)
* If there is an "sr" in a root span, use that
* Otherwise, return null instead of choosing an arbitrary low value.

This also is more careful when updating timestamps, for example, in
MySQL, we only update if the span's timestamp is set or on client send.

This change has some impact, notably that duration queries now require
instrumentation to update to actually set Span.duration. Also,
elasticsearch "timestamp_millis" field is now used directly for queries.

To facilitate better instrumentation, I've added more documentation:
openzipkin/openzipkin.github.io#46
** Timestamps are microseconds **
All Zipkin timestamps are in epoch microseconds (not milliseconds). This value
should use the most precise measurement available. For example, `clock_gettime`
or syncing nanoTime against a tick of currentTimeMillis. If none of this works,
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't think extracting epoch microseconds by using a tick of currentTimeMillis works. I tried to do something along these lines and the clock drift/correction that the JVM does with currentTimeMillis means your epoch microseconds gets out of whack extremely quickly.

If someone has a valid solution I'd love to see it, but I don't think one exists unfortunately. :(

What does work is just multiplying epoch millis by 1000 like you said, and then using nanoTime to calculate the duration. The start timestamp loses a little resolution due to syncing to a tick of currentTimeMillis, but the duration is at least microsecond accurate.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

thanks for letting me know.. about that. I'll remove the bad advice :)

On Sat, Sep 10, 2016 at 4:30 AM, Nic Munroe notifications@github.com
wrote:

In pages/instrumenting.md
#46 (comment)
:

Thrift Tracing

Finagle clients and servers negotate whether they can handle extra information
in the header of the thrift message when a connection is established. Once
negotiated trace data is packed into the front of each thrift message.
+
+Timestamps and duration
+=====
+
+Span recording is when timing information or metadata is structured and reported
+to zipkin. One of the most important parts of this process is appropriately
+recording timestamps and duration.
+
+** Timestamps are microseconds **
+All Zipkin timestamps are in epoch microseconds (not milliseconds). This value
+should use the most precise measurement available. For example, clock_gettime
+or syncing nanoTime against a tick of currentTimeMillis. If none of this works,

I don't think extracting epoch microseconds by using a tick of
currentTimeMillis works. I tried to do something along these lines and the
clock drift/correction that the JVM does with currentTimeMillis means your
epoch microseconds gets out of whack extremely quickly.

If someone has a valid solution I'd love to see it, but I don't think one
exists unfortunately. :(

What does work is just multiplying epoch millis by 1000 like you said,
and then using nanoTime to calculate the duration. The start timestamp
loses a little resolution due to syncing to a tick of currentTimeMillis,
but the duration is at least microsecond accurate.


You are receiving this because you authored the thread.
Reply to this email directly, view it on GitHub
https://github.com/openzipkin/openzipkin.github.io/pull/46/files/733b1f0cb4cf982708e9db319a7ab3af90766880#r78243889,
or mute the thread
https://github.com/notifications/unsubscribe-auth/AAD616kqzabf77PDeNZ7LeWPI3Yl8wbiks5qocHxgaJpZM4J40Js
.

@abesto
Copy link
Member

abesto commented Sep 11, 2016

🎆 Thanks!

@jcarres-mdsol
Copy link

sounds good, I think that's how our clients behave currently

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

4 participants