Debugging query slowing down at one time-point

1

Hi, I have encountered a weird situation where querying for the count of “value” (my measurement) is extremely slow (17min to respond) after a given point, more precisely at 1416225559920ms. If I query for the point 1ms before (1416225559919ms), it quickly returns no answer. If I query for the time before with an actual answer (1416225559880ms) it returns in 0.1s. If I query for the point after (1416225559960ms) it again takes 17 minutes to respond. If I query sufficiently long after it is fast again (but I have not binary search to exactly where it gets slow).

The query in question is (but with different times substituted):
“q=SELECT count(“value”) FROM “autogen”.“database” WHERE time = 1416225559920ms AND “tag1” = ‘Val1’ AND “Tag2” = ‘Val2’”

If I instead ask for just “value” at time= 1416225559920ms it returns in 0.2 seconds.

The database consists of 186 series (as reported by ‘influx_inspect report -exact’).

In this database I experimented with adding a tag “week_nr” which includes the week_nr of the point, to see if this would let me parallelize the queries. As you see this tag is unspecified in the query. This could be relevant, but I don’t see why it would make the query slow for only these time-points. Could it be that 1416225559920ms is in some unfortunate slow block?
There is only one shard (retention policy 9000weeks).
The tsm-files is fully compacted at the time of query.

How to proceed debugging this?

2

I did some more analysis with the new “explain analyze”, and got some interesting results. For the slow time I got these:

    "                ├── float_blocks_decoded: 13957"

    "                ├── float_blocks_size_bytes: 74389344"

While for the fast point earlier I get

    "                ├── float_blocks_decoded: 22"
    "                ├── float_blocks_size_bytes: 124004"

I also get 22 decoded if I ask for “value” instead of “count(value)”, which I find even weirder. But 13k does not seem high enough to explain 17min.

By using influx_inspect dumptsm I found that the block has this entry in the tsm file:
72690 2096892964 13752941155646 5482 float64 2014-11-17T23:49:20.08Z 1000 s8b/gor 425/5054
while preceding entries have “rle/gor 12/5021” (or similar numbers) for the last two entries. But this held for other timestamps around 12/24, and they did not have the same slowness, so I guess it is a red herring.