Chronograf query does not return all records from per-program-timing table

[tao-stones]

Problem

Validator calls datapoint_info() to insert multiple records to same table within a millisecond, when querying InfluxDn, only the last insertion in query result.

For example, from the log of validator that reports metrics to tds:

[2021-09-10T17:40:23.785238238Z INFO  solana_metrics::metrics] datapoint: per_program_timings slot=93422612i pubkey="Vote111111111111111111111111111111111111111" execute_us=171398i accumulated_units=0i count=1102i
[2021-09-10T17:40:23.785260354Z INFO  solana_metrics::metrics] datapoint: per_program_timings slot=93422612i pubkey="8tfDNiaEyrV6Q1U4DEXrEigs9DoDtkugzFbybENEbCDz" execute_us=4153i accumulated_units=5023i count=2i
[2021-09-10T17:40:23.785265142Z INFO  solana_metrics::metrics] datapoint: per_program_timings slot=93422612i pubkey="all" execute_us=175551i accumulated_units=5023i count=1104i

within same millisecond, it added 3 records to pre_program_timings for slot 93422612 with different values.

when run query in chrnograf:

SELECT * FROM "tds"."autogen"."per_program_timings" WHERE time > :dashboardTime: AND time < :upperDashboardTime: AND "host_id"='C655ertkV4BUt9Cso2HVc5vQ2qoV4MKdktXZSVUPyK5Y' AND slot = 93422612;

It only returns the last insertion.

The question is if all three records were added to InfluxDb but query only returns last one, or the database is gated somehow only the last insertion added to DB.

Proposed Solution

[tao-stones]

@joeaba some background, I noticed this when I am querying InfluxDB to get per_program_timing records for BPF programs (as part of issue #19627 ), noticed the query results not exactly match with log. If you need reproduce it, I think it is not hard, let me know. Thanks!

[joeaba]

@axleiro can you please help me take a look? The data points exist so we should be able to query them

[ryoqun]

@taozhu-chicago this is due to our ./metrics code is truncating to ms granularity.... maybe we should fix this. I stumbled on this as well for other metrics. Firstly, we have to know why the code isn't doing ns granularity (influxdb's default behavior).

[denispalab]

Ryo is right here, after some R&D I found that the actual data inside the database regarding that particular “slot no.” is not 3 but only a single entry.. so the query is actually correctly fetching all the data that is present in database. We might have several cases like this

[tao-stones]

Thanks @ryoqun @axleiro for looking into it. Would be nice to keep Influx's default ns granularity, or at least at us is storage is an issue.

[behzadnouri]

I sent out #20623 to switch to nanoseconds, as this problem is impacting this metric as well:
https://github.com/solana-labs/solana/blob/005d6863f/core/src/window_service.rs#L101-L107

[github-actions]

This issue has been automatically locked since there has not been any activity in past 7 days after it was closed. Please open a new issue for related bugs.