Deleted data is being recovered on server restart

[spantaleev]

This seems to affect influxdb 0.5.6, reproducible on 2 different machines (running Archlinux and CentOS 5).

Possibly similar to #342, but it's not about dropping the database completely.

Steps to reproduce, starting with a fresh database:

1. Insert one (or a few) data points
2. Execute a DELETE query that deletes the points
3. Execute some COUNT queries to confirm that the points are gone
4. Restart influxdb (gracefully)
5. Execute a COUNT query - observe that all deleted points have made it back into the database

Steps 1 to 3 may be repeated a few times before continuing with step 4. It doesn't make a difference.

I've tried another similar experiment too, where step 2 doesn't delete all points, but leaves a few. The results are the same - the points that were deleted are resurrected. So it doesn't seem to matter whether you completely empty the database or not - it will recover the missing data anyway.

Some potentially helpful log entries:

[04/13/14 16:25:43] [INFO] Setting server id to 1 and recovering
[04/13/14 16:25:43] [INFO] Checking /opt/influxdb/shared/data/wal/log.1, last: 0, size: 107
[04/13/14 16:25:44] [INFO] Adding short term shard: 1 - start: Thu Apr 10 03:00:00 +0300 EEST 2014 (1397088000). end: Thu Apr 17 03:00:00 +0300 EEST 2014 (1397692800). isLocal: %!d(bool=true). servers: [%!s(uint32=1)]
[2014/04/13 16:25:44 EEST] [INFO] (cluster.(*ClusterConfiguration).AddShards:871) Adding short term shard: 1 - start: Thu Apr 10 03:00:00 +0300 EEST 2014 (1397088000). end: Thu Apr 17 03:00:00 +0300 EEST 2014 (1397692800). isLocal: %!d(bool=true). servers: [%!s(uint32=1)]
[04/13/14 16:25:48] [INFO] Recovering from log...
[04/13/14 16:25:48] [INFO] local: Initializing write buffer with buffer size of 10000
[04/13/14 16:25:48] [INFO] Waiting for servers to recover
[2014/04/13 16:25:48 EEST] [INFO] (server.(*Server).ListenAndServe:91) Recovering from log...
[2014/04/13 16:25:48 EEST] [INFO] (cluster.NewWriteBuffer:26) local: Initializing write buffer with buffer size of 10000
[2014/04/13 16:25:48 EEST] [INFO] (cluster.(*ClusterConfiguration).RecoverFromWAL:955) Waiting for servers to recover
[04/13/14 16:25:48] [INFO] Recovering local server
[04/13/14 16:25:48] [INFO] Recovering server 1 from request 1
[04/13/14 16:25:48] [INFO] Replaying from /opt/influxdb/shared/data/wal/log.1:0
[2014/04/13 16:25:48 EEST] [INFO] (cluster.func·004:937) Recovering local server
[2014/04/13 16:25:48 EEST] [INFO] (wal.(*WAL).RecoverServerFromLastCommit:131) Recovering server 1 from request 1
[2014/04/13 16:25:48 EEST] [INFO] (wal.(*WAL).RecoverServerFromRequestNumber:181) Replaying from /opt/influxdb/shared/data/wal/log.1:0
[04/13/14 16:25:48] [INFO] /opt/influxdb/shared/data/wal/log.1 yielded 2 requests
[04/13/14 16:25:48] [INFO] Recovered local server
[2014/04/13 16:25:48 EEST] [INFO] (wal.(*WAL).RecoverServerFromRequestNumber:187) /opt/influxdb/shared/data/wal/log.1 yielded 2 requests
[2014/04/13 16:25:48 EEST] [INFO] (cluster.func·004:939) Recovered local server
[04/13/14 16:25:48] [INFO] recovered
[04/13/14 16:25:48] [INFO] Connecting to other nodes in the cluster
[04/13/14 16:25:48] [INFO] Starting admin interface on port 8083
[04/13/14 16:25:48] [INFO] Starting Http Api server on port 8086

[jvshahid]

This is definitely a bug that we'll look at. Moving to 0.5.7