ingester_v2 reporting quite a bit of "failed to delete idle TSDB" error

[alvinlin123]

Describe the bug
We are seeing error message like

level=error ts=2020-12-15T21:33:44.395830698Z caller=ingester_v2.go:1623 msg="failed to delete idle TSDB" user=some-user-id err="unlinkat /data/tsdb/some-user-id: directory not empty"

We are using this commit

To Reproduce
I am not sure

Expected behavior
A clear and concise description of what you expected to happen.

Environment:

• Infrastructure: EKS
• Deployment tool: Helm

Storage Engine

• [ X ] Blocks
• Chunks

Additional Context
The error happens during a call to os.RemoveAll() call, research shows that RemoveAll() might return "directory not empty" error if file are created under the directory while the removal process is on going. So I am wondering if there is any background process in ingester that maybe interfering with the local TSDB deletion process?

[pstibrany]

Would it be possible to check those non-empty directories and see what files are there?

[alvinlin123]

I am on the same thought trail @pstibrany :-)

I just looked at few example directories, and the directory has a single thanos.shipper.json file. Also, the last modify timestamp is same as timestamp (up to seconds precision) where the error was reported.

Shipper running concurrently?

[pstibrany]

Shipper running concurrently?

Thanks, that may actually be the case.

[alvinlin123]

Should there be some kind of lock or retry then? If using lock, I wonder if it will affect overall performance if the ship_interval is configure at a low number.

[pstibrany]

Should there be some kind of lock or retry then? If using lock, I wonder if it will affect overall performance if the ship_interval is configure at a low number.

I was thinking of something simpler:

• add a wait group per TSDB, that would be increased when shipping starts, and “done” when shipping (call to Sync) is finished
• when closing TSDB with shipper, first stop shipping (there is shipper context already) and then “wait” for sync group to make sure that shipper is really stopped. Only delete directory after this step.

This doesn’t affect performance of shipping. The only tricky part is how to write a unit test for it. (Likely with mocked shipper, whose Sync takes a long time, and we verify that dir isn’t deleted until Sync finishes).

There may be a better way to solve this, but I think this should work. Would you like to send a PR?

[pstibrany]

• when closing TSDB with shipper, first stop shipping (there is shipper context already) and then “wait” for sync group to make sure that shipper is really stopped. Only delete directory after this step.

“there is shipper context already” – I misremembered this. There isn’t.

Since shipping only works for users which are in i.TSDBState.dbs, we can do this check after removing user from this map. There will still be a race... as getTSDBUsers returns a copy of the map (used by shipBlocks) so I’d suggest modifying shipBlocks to check for closing and closed state of TSDB, and avoid shipping if one of these is set.

[pracucci]

so I’d suggest modifying shipBlocks to check for closing and closed state of TSDB, and avoid shipping if one of these is set

This wouldn't solve the race condition anyway. shipBlocks() may pass that check and then the closing of the idle TSDB may happen while shipping is still on-going.

[pracucci]

add a wait group per TSDB, that would be increased when shipping starts, and “done” when shipping (call to Sync) is finished

I don't think this is viable too, because of a property of sync.WaitGroup which I recently learned (and I believe there's some already existing misuse):

Note that calls with a positive delta that occur when the counter is zero must happen before a Wait. Calls with a negative delta, or calls with a positive delta that start when the counter is greater than zero, may happen at any time. Typically this means the calls to Add should execute before the statement creating the goroutine or other event to be waited for. If a WaitGroup is reused to wait for several independent sets of events, new Add calls must happen after all previous Wait calls have returned. See the WaitGroup example.

From: https://golang.org/pkg/sync/#WaitGroup.Add

[pstibrany]

I don't think this is viable too, because of a property of sync.WaitGroup which I recently learned (and I believe there's some already existing misuse):

I don’t see how that’s a misuse, or how that contradicts suggested usage.

[pracucci]

I don't think this is viable too, because of a property of sync.WaitGroup which I recently learned (and I believe there's some already existing misuse):

I don’t see how that’s a misuse, or how that contradicts suggested usage.

When you call Wait() you need to have the guarantee that the WaitGroup counter is > 0, but you don't have it, unless you add an extra protection around it.

I'm currently experimenting the idea to add another userTSDB state activeShipping. Being able to use the casState() is quite handy and code changes would be minimal.

[pstibrany]

When you call Wait() you need to have the guarantee that the WaitGroup counter is > 0, but you don't have it, unless you add an extra protection around it.

This is not true. Wait() can be called if there was no Add before.

What the comment you quoted says is that you cannot call Add (with positive number) while there is another blocked Wait in progress. But that is not our scenario.

[pstibrany]

In different words, WaitGroup remembers two things: “value” (modified via Add/Done) and number of “waiters”. If “value” is 0, Wait() doesn’t increase “waiters” but returns immediately. If “waiters” > 0, “value” cannot be increased (this is what comment is about).

[pstibrany]

Back to our problem... since there is only single shipper per TSDB which can increase WaitGroup, I think it’s a viable solution.