Compaction exhausting disk resources in InfluxDB 1.2.2-1

[dylanzr]

Bug report

System info:
CentOS 7.3
InfluxDB 1.2.2
KVM Virtual machine with 20 cpu and 128G RAM

Steps to reproduce:

1. Leave running
2. System runs out of disk space

Expected behavior:
Compactions run without exhausting available disk space.

Actual behavior:
This system currently has 3T of SSD storage available to InfluxDB. Since I've been unable to keep this online, I've moved all but 6 telegraf agents to a new system.

After restarting InfluxDB, about 1.3T of space is free, but in just 14 hours of running with just the 6 telegraf agents writing, all 3T of disk space has been used. This drops back down to 1.3T free again when restarting. This all seems to be a result of compaction and it seems that the number of "*.tsm.tmp" files never drops.

Additional info:
I'm unsure if compaction logs are useful here. The only recent changes are upgrading from 1.1.1 and deleting 30d of a single measurement.

This debug output was taken immediately after a restart, as I had pprof disabled.

block
goroutine
heap
vars
iostat
shards
stats
diagnostics

InfluxDB has now been running for 20 minutes with no agents writing. Disk utilization has grown by about 100G and there are now 60 tmp files.

Thanks in advance.

[hpbieker]

It looks like it is trying to recompact all your shards. From the gorutine.txt it looks like you have 12 compactions running, but I guess you have even more or some of your shard are larger than the others. You might want to try the latest nightly build, as you can not limit the number of compactions running concurrently (#8276). If you set this to a low enough number, you can also limit the disk space required by Influx from tmp files (number of compactions * max size of a shard >= tmp disk usage).

[dylanzr]

Even if it were compacting all shards, would it be expected that it could nearly double the on-disk usage? I'd not expect that to be the case given that logs indicate some compactions do complete.

[jwilder]

@dzr0001 Yes, compactions write out new TSM files which can increase disk usage while they are running. TSM files are immutable so the existing ones are left unchanged while they run. @hpbieker suggestion might be your best option currently. Can you attach the logs?

[dylanzr]

@jwilder I'll sanitize them and attach momentarily. As best I can tell there are currently 29 compactions running, but shouldn't I see fewer of these tmp files?

# find /var/lib/influxdb/ -name "*.tmp"  | wc -l
452

[hpbieker]

How many folders have .tsm.tmp files? And what is the size of these folders (without the .tsm.tmp)?

[jwilder]

@dzr0001 The tmp files are the newly compacted TSM files. As compactions run, new TSM files w/ tmp extension are written. You should see new tmp files created in the shard dirs where compactions are currently running. The tmp files are removed once the compaction completes for that shard.

[dylanzr]

This log includes all entries after the latest restart.

influxdb.log.txt

[jwilder]

@dzr0001 Do you have any *.tombstone files in any of the shard dirs? For example, any in /var/lib/influxdb/data/telegraf/1y/208/?

[dylanzr]

@jwilder Yes, 767 of them across several shards.

[jwilder]

Ok, that might be why all the shards are triggering a compaction at once. There must have been a delete or drop statement run that required data to be removed from many shards. From the logs, the shards look like they are fully compacted/optimized so the deletes are triggering the new compactions.

[dylanzr]

I mentioned deleting some data in the original report. It was 30d of a smaller measurement that was deleted. Triggering compactions across all shards like that makes it difficult to impossible to be able to drop any data. I suspect this would exhibit the same behavior if this data were deleted as a result of a retention plan expiring old data.

[jwilder]

Sorry, missed that in the issue description. Retention policy deletion removes the whole shard and is a different code path from deleting individual measurement or series. You would not see this when dropping a shard manually (via drop shard) or via retention policy enforcement which ends up dropping shards that are expired.

If you deleted a data that should only exist in a single shard and it tombstoned data in other shards, that would be a bug since it would cause the shards to be recompacted unnecessarily.

[dylanzr]

I would expect my deletions to fall within 4 shards, as the shard group duration is 7 days. There was little data in this before 9/1/2016, and my specific query was

delete from "cpu" where time < '2016-10-01'

Shard info:

> show retention policies
name    duration  shardGroupDuration replicaN default
----    --------  ------------------ -------- -------
default 0s        168h0m0s           1        false
1y      8736h0m0s 168h0m0s           1        true

name: telegraf
id  database retention_policy shard_group start_time           end_time             expiry_time          owners
--  -------- ---------------- ----------- ----------           --------             -----------          ------
2   telegraf default          2           2016-08-29T00:00:00Z 2016-09-05T00:00:00Z 2016-09-05T00:00:00Z 
8   telegraf default          8           2016-09-05T00:00:00Z 2016-09-12T00:00:00Z 2016-09-12T00:00:00Z 
15  telegraf default          15          2016-09-12T00:00:00Z 2016-09-19T00:00:00Z 2016-09-19T00:00:00Z 
25  telegraf default          25          2016-09-19T00:00:00Z 2016-09-26T00:00:00Z 2016-09-26T00:00:00Z 
17  telegraf 1y               17          2016-09-12T00:00:00Z 2016-09-19T00:00:00Z 2017-09-18T00:00:00Z 
26  telegraf 1y               26          2016-09-19T00:00:00Z 2016-09-26T00:00:00Z 2017-09-25T00:00:00Z 
32  telegraf 1y               32          2016-09-26T00:00:00Z 2016-10-03T00:00:00Z 2017-10-02T00:00:00Z 
40  telegraf 1y               40          2016-10-03T00:00:00Z 2016-10-10T00:00:00Z 2017-10-09T00:00:00Z 
48  telegraf 1y               48          2016-10-10T00:00:00Z 2016-10-17T00:00:00Z 2017-10-16T00:00:00Z 
56  telegraf 1y               56          2016-10-17T00:00:00Z 2016-10-24T00:00:00Z 2017-10-23T00:00:00Z 
64  telegraf 1y               64          2016-10-24T00:00:00Z 2016-10-31T00:00:00Z 2017-10-30T00:00:00Z 
72  telegraf 1y               72          2016-10-31T00:00:00Z 2016-11-07T00:00:00Z 2017-11-06T00:00:00Z 
80  telegraf 1y               80          2016-11-07T00:00:00Z 2016-11-14T00:00:00Z 2017-11-13T00:00:00Z 
88  telegraf 1y               88          2016-11-14T00:00:00Z 2016-11-21T00:00:00Z 2017-11-20T00:00:00Z 
96  telegraf 1y               96          2016-11-21T00:00:00Z 2016-11-28T00:00:00Z 2017-11-27T00:00:00Z 
104 telegraf 1y               104         2016-11-28T00:00:00Z 2016-12-05T00:00:00Z 2017-12-04T00:00:00Z 
112 telegraf 1y               112         2016-12-05T00:00:00Z 2016-12-12T00:00:00Z 2017-12-11T00:00:00Z 
120 telegraf 1y               120         2016-12-12T00:00:00Z 2016-12-19T00:00:00Z 2017-12-18T00:00:00Z 
128 telegraf 1y               128         2016-12-19T00:00:00Z 2016-12-26T00:00:00Z 2017-12-25T00:00:00Z 
136 telegraf 1y               136         2016-12-26T00:00:00Z 2017-01-02T00:00:00Z 2018-01-01T00:00:00Z 
144 telegraf 1y               144         2017-01-02T00:00:00Z 2017-01-09T00:00:00Z 2018-01-08T00:00:00Z 
152 telegraf 1y               152         2017-01-09T00:00:00Z 2017-01-16T00:00:00Z 2018-01-15T00:00:00Z 
160 telegraf 1y               160         2017-01-16T00:00:00Z 2017-01-23T00:00:00Z 2018-01-22T00:00:00Z 
168 telegraf 1y               168         2017-01-23T00:00:00Z 2017-01-30T00:00:00Z 2018-01-29T00:00:00Z 
176 telegraf 1y               176         2017-01-30T00:00:00Z 2017-02-06T00:00:00Z 2018-02-05T00:00:00Z 
184 telegraf 1y               184         2017-02-06T00:00:00Z 2017-02-13T00:00:00Z 2018-02-12T00:00:00Z 
192 telegraf 1y               192         2017-02-13T00:00:00Z 2017-02-20T00:00:00Z 2018-02-19T00:00:00Z 
200 telegraf 1y               200         2017-02-20T00:00:00Z 2017-02-27T00:00:00Z 2018-02-26T00:00:00Z 
208 telegraf 1y               208         2017-02-27T00:00:00Z 2017-03-06T00:00:00Z 2018-03-05T00:00:00Z 
216 telegraf 1y               216         2017-03-06T00:00:00Z 2017-03-13T00:00:00Z 2018-03-12T00:00:00Z 
224 telegraf 1y               224         2017-03-13T00:00:00Z 2017-03-20T00:00:00Z 2018-03-19T00:00:00Z 
232 telegraf 1y               232         2017-03-20T00:00:00Z 2017-03-27T00:00:00Z 2018-03-26T00:00:00Z 
240 telegraf 1y               240         2017-03-27T00:00:00Z 2017-04-03T00:00:00Z 2018-04-02T00:00:00Z 
248 telegraf 1y               248         2017-04-03T00:00:00Z 2017-04-10T00:00:00Z 2018-04-09T00:00:00Z 
256 telegraf 1y               256         2017-04-10T00:00:00Z 2017-04-17T00:00:00Z 2018-04-16T00:00:00Z 
264 telegraf 1y               264         2017-04-17T00:00:00Z 2017-04-24T00:00:00Z 2018-04-23T00:00:00Z 
272 telegraf 1y               272         2017-04-24T00:00:00Z 2017-05-01T00:00:00Z 2018-04-30T00:00:00Z 
280 telegraf 1y               280         2017-05-01T00:00:00Z 2017-05-08T00:00:00Z 2018-05-07T00:00:00Z 
288 telegraf 1y               288         2017-05-08T00:00:00Z 2017-05-15T00:00:00Z 2018-05-14T00:00:00Z 

This instance was installed originally with 0.13, but 1.0 was installed on 9/12, in case that has any bearing on anything.

[jwilder]

@dzr0001 I was able to repro what you are seeing. Tombstones are getting written for TSM files that do not contain the deleted data which triggers many shard compactions. #8372 should fix it.

[dylanzr]

@jwilder Excellent, this will be very helpful. For the existing tombstones is there any way to clean those up beyond using the nightly build to limit compactions until it completes?

[jwilder]

When your server is down, you can remove the tombstone files from shards that are outside of the time range you deleted. Removing the tombstone files will cause any deleted data contained in those tombstone files to re-appear again after restart though.

[dylanzr]

Ok, great. Thanks for identifying the culprit so quickly. Would these long compaction cycles also contribute to higher than anticipated memory utilization? I was running into some OOM issues but am not able to reproduce those right now while no clients are using this database.