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

kamon.metric.Timer warns about negative values due to NTP time sync #3480

Open
deemru opened this issue May 18, 2021 · 7 comments
Open

kamon.metric.Timer warns about negative values due to NTP time sync #3480

deemru opened this issue May 18, 2021 · 7 comments
Assignees
Labels

Comments

@deemru
Copy link
Member

deemru commented May 18, 2021

We still (on the newest node 1.3.4) get errors like these:
WARN [ecution-context-global-XX] kamon.metric.Timer - Failed to record value [-70000000] on [span.processing-time,{operation=block-appender,error=false}] because the value is outside of the configured range. The recorded value was adjusted to the highest trackable value [3600000000000]. You might need to change your dynamic range configuration for this metric

This is not just annoying to see (was reported many times for years) but this also means the code executes and spends CPU cycles on non active functionality:

kamon.enable = no
kamon.modules.influxdb-span-reporter.enabled = no
metrics.enable = no

Because metrics calls (as far as i understand) are unconditional (for example just search for measureSuccessful)

Please, for god sake, make these metrics completely turned off by metrics.enable = no and i mean off = check config once and don`t waste CPU cycles anymore on that.

@phearnot
Copy link
Member

Hi @deemru, thanks for reaching out. The root cause of an issue at hand is not actually the metrics subsystem, it's NTP. Note that the value which did not fit in the range is negative: it's because the time has been adjusted during block application. This is most likely due to the fact that the pool.ntp.org name has been resolved to an address of another server, which is not quite in sync with the one used during the preceding time sync attempt. To work around this issue, you can specify an exact address of your preferred NTP server in the waves.ntp-server parameter.

Unfortunately, as stated in kamon-io/Kamon#585, Kamon is built in such way that it's not supposed to be turned off. Metrics collection (even in hot code paths) does not have measurable impact on the node's overall performance (please share your benchmark data if your experience differs from what we've measured). What may impact performance or resource consumption are reporters which deliver aggregated metrics to storage backends like InfluxDB. Those are disabled by default.

If you prefer not to see metrics-related messages in your logs, you can add the following line to your custom logback.xml:

<logger name="kamon" level="OFF"/>

@deemru
Copy link
Member Author

deemru commented May 18, 2021

Can you please explain to me how this code which should do many many things to complete is better than if you just add before it simple condition like if( metrics.enabled ) do stuff?

Task(metrics.microblockProcessingTimeStats.measureSuccessful {
:

@phearnot
Copy link
Member

As I've said, «doing many things to complete» does not take that long, so there's no point in optimizing this piece, because these optimizations will not yield measurable block application speedup.

@deemru
Copy link
Member Author

deemru commented May 18, 2021

For me your approach to resolve this issue is look like:

  • you set waves.miner.enable = no but we still do full processing just not sending results to other nodes
  • you set waves.rest-api.enable= no but we send everything to /dev/null it is fast

@phearnot
Copy link
Member

I'm sorry, I can't see how enabling/disabling miner or REST API is related to the original issue. If you are concerned with API or miner performance impact on import speed or ordinary block application, please consider opening another issue.

We will consider tweaking measureSuccessful to ignore negative values so that there won't be any confusing warnings in the logs, in the meantime please use a workaround.

@phearnot phearnot changed the title Metrics still out of control kamon.metric.Timer warns about negative values due to NTP time sync May 18, 2021
@deemru
Copy link
Member Author

deemru commented May 18, 2021

Metrics metrics.enable = no as another enable-like features must be completely disabled its functionality because it is set to enable = no not because it fast or not.

In our world of metrics, telemetry etc. An user should be sure he can opt-out of these things.

@phearnot
Copy link
Member

No reporters are enabled by default, so nothing is shared with third party, unless explicitly configured. I believe this fits the definition of opt-in.

I'm locking this issue, because the root cause has been identified and action plan has been determined. Please feel free to open a separate issue if you feel so inclined.

@wavesplatform wavesplatform locked as too heated and limited conversation to collaborators May 19, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
Projects
None yet
Development

No branches or pull requests

2 participants