Snapshot_deletion threadpool active thread count stuck at 1 after encountering failure

[tomchlee]

Describe the bug

After upgrading form Opensearch 2.15.0 to 2.18.0, sometimes deleting a snapshot resulted in snapshot_deletion threadpool active thread count stuck at 1 after encountering failure. Logs on cluster_manager node showed:

[2025-05-13T23:53:31,217][INFO ][o.o.s.SnapshotsService   ] [es-master-mis-30-2-0] deleting snapshots [smartsearch_min-2025-05-03.183003] from repository [s3_repository]
[2025-05-13T23:54:05,259][WARN ][o.o.r.b.BlobStoreRepository] [es-master-mis-30-2-0] [s3_repository] Failed to delete following blobs during snapshot delete : [Tuple [v1=[mis-30-2][indices][e7NMXjIlSOOS1MTWMTOr4Q][10], v2=__e05l2htCSi2L3NcdX5b2ww], Tuple [v1=[mis-30-2][indices][e7NMXjIlSOOS1MTWMTOr4Q][81], v2=__KNHrjCURQ0uCeIT35WyA_w], Tuple [v1=[mis-30-2][indices][e7NMXjIlSOOS1MTWMTOr4Q][56], v2=__yRISy4RpTL67SWuJVBbX4g]...
[2025-05-13T23:54:03,817][WARN ][o.o.r.b.BlobStoreRepository] [es-master-mis-30-2-0] [s3_repository] Failed to delete following blobs during snapshot delete : [Tuple [v1=[mis-30-2][indices][e7NMXjIlSOOS1MTWMTOr4Q][111], v2=__YW_-KjNvTzmcDBDL8Onm2Q], Tuple [v1=[mis-30-2][indices][e7NMXjIlSOOS1MTWMTOr4Q][147], v2=__-VaRQ2tTSEyD-8TLi2aFxw], Tuple [v1=[mis-30-2][indices][e7NMXjIlSOOS1MTWMTOr4Q][137], v2=__JBgcvFxWRH6vUN6pa_fXuw]...
[2025-05-13T23:54:04,347][WARN ][o.o.r.b.BlobStoreRepository] [es-master-mis-30-2-0] [s3_repository] Failed to delete following blobs during snapshot delete : [Tuple [v1=[mis-30-2][indices][e7NMXjIlSOOS1MTWMTOr4Q][24], v2=__AFiAbKSBR2Gq4XcaYqa-lA], Tuple [v1=[mis-30-2][indices][e7NMXjIlSOOS1MTWMTOr4Q][66], v2=__OHzTRuKpQPuarw2u3OtvGw]...
...

There were no pending tasks (checked via GET _cluster/pending_tasks). Thread count would become 0 only when the cluster manager node was restarted. Then when I tried to get the list of snapshots, the snapshot was gone, but trying to delete the next snapshot resulted in the same behavior with the "Failed to delete following blobs ..." log entry listing new blobs as well as blobs from previous snapshot deletion. These log entries only listed blobs that failed to be deleted but no cause of the failure, and there were no other log entries related to snapshot deletion error.

Also, I noticed whenever I made a repository setting update such changing chunk size, subsequent request to retrieve list of snapshots returned with the follow error:

{ 
  "error": { 
    "root_cause": [ 
      { 
        "type": "illegal_state_exception",
        "reason": "Connection pool shut down"
      }
    ],
    "type": "illegal_state_exception",
    "reason": "Connection pool shut down"
  },
  "status": 500
}

The request would work again only after restarting cluster manager nodes.

Related component

Storage:Snapshots

To Reproduce

1. Create a snapshot management policy to take snapshot of the entire cluster every day at 12am and 12pm, and delete schedule of every day at 2am and 2pm. Keep minimum of 2 and max of 7 snapshots.
2. Let policy take effect for a few days.
3. Observe that snapshot deletion thread count remain at non-zero value.

Note that this behavior doesn't happen every time but once it does, subsequent snapshot deletions (after cluster manager node restart) will run into this behavior. Also, this symptom seems only to occur for our large clusters where there are daily indices with some indices have 250 shards and size of 3-4TB.

Expected behavior

Snapshot_deletion threadpool active thread count should become 0 even after encountering failure.

Additional Details

Plugins
Please list all plugins currently enabled.

Screenshots
If applicable, add screenshots to help explain your problem.

Host/Environment (please complete the following information):

• OS: [e.g. iOS]
• Version [e.g. 22]

Additional context
Add any other context about the problem here.

[krisfreedain]

Catch All Triage - 1 2

[prudhvigodithi]

Adding @shwetathareja @sachinpkale @Bukhtawar to please take a look and provide some insights. @tomchlee is there way this can be reproduced with some steps ?

[tomchlee]

Adding @shwetathareja @sachinpkale @Bukhtawar to please take a look and provide some insights. @tomchlee is there way this can be reproduced with some steps ?

@prudhvigodithi I have updated To Reproduce section in the Description.

[prudhvigodithi]

@prudhvigodithi I have updated To Reproduce section in the Description.

Thanks @tomchlee, just curious I see you mentioned as 2.18, did you also try upgrading to 2.19.1 (the latest 2.x version) and have you seen this issue ?
@getsaurabh02 @andrross

[tomchlee]

We haven't tried upgrading to 2.19.1 as this symptom has only manifested itself in our production clusters which have indices of that size. We could look into upgrading to 2.19.1 but it will take a bit of time to go through testing in lab.

[shwetathareja]

@tomchlee this looks like an issue with stale shard deletion. It may require bouncing the OpenSearch process on data nodes as temporary mitigation in case it happen in your production. Can you please paste the full message why was it failing to delete the blob in this case?

cc: @ashking94 who worked on the snapshot code recently

[shwetathareja]

@ashking94

We are catching all exceptions and then retrying, does it handle for the case where blobs might be deleted in S3 already but due to intermittent network error, request failed and then it would try again...

OpenSearch/server/src/main/java/org/opensearch/repositories/blobstore/BlobStoreRepository.java

Lines 1667 to 1678 in 33ebf94

	} catch (Exception e) {
	logger.warn(
	() -> new ParameterizedMessage(
	"[{}] Failed to delete following blobs during snapshot delete : {}",
	metadata.name(),
	filesToDelete
	),
	e
	);
	l.onFailure(e);
	}
	executeStaleShardDelete(staleFilesToDeleteInBatch, remoteStoreLockManagerFactory, listener);

[ashking94]

Thanks for reporting the issue @tomchlee. I have couple of questions:

1. Were you able to take a thread dump when the snapshot_deletion active thread count showed up as 1 continuously? Can you share the thread dump if you have one. I suspect if this could be some stats related issue.
2. Can you share the exact command for the update repository that led to list snapshot failing after that?

[tomchlee]

@tomchlee this looks like an issue with stale shard deletion. It may require bouncing the OpenSearch process on data nodes as temporary mitigation in case it happen in your production. Can you please paste the full message why was it failing to delete the blob in this case?

cc: @ashking94 who worked on the snapshot code recently

The log entry is quite long so I've truncated large chunk of middle portion which just list more tuples:

[2025-06-06T22:05:50,268][WARN ][o.o.r.b.BlobStoreRepository] [es-master-mis-30-3-2] [s3_repository] Failed to delete following blobs during snapshot delete : [Tuple [v1=[mis-30-3][indices][ONGyzZEZQ1WPGciAr_fkZQ][50], v2=__zjxXlrOaRGWgwe4z_b0Kyw], Tuple [v1=[mis-30-3][indices][RR4lDG0gRxuA13b7mgB1Wg][66], v2=__eI4ikUTCQlCsMckfEEyX_w], Tuple [v1=[mis-30-3][indices][o-X6U5HeSdeidBzJY2XAmQ][5], v2=__ZlQlkoO9TbS6qR7FdtpgRg], Tuple [v1=[mis-30-3][indices][2duN29lpRgSDUPwXK6NGNg][79], v2=__hx_wzhpnTwK4hO97S59UfA], Tuple [v1=[mis-30-3][indices][ljTDObqbTdGqTXdywDC0lg][107], v2=snap-4aLSK_YESZuCjAaOJy6XxQ.dat], Tuple [v1=[mis-30-3][indices][_GuNA3B9QGuKGkPYLcR1Cg][1], v2=__QeJNadMZTiWSIpUY4EsoYw], Tuple [v1=[mis-30-3][indices][sHHxP9GqQU-2hqbmBhOHdA][139], v2=___5ITtFpdR_OyzkYVs9434g], Tuple [v1=[mis-30-3][indices][gs0rbbAxRJuDBIck6BZfcQ][79], v2=__ECeywjzuShmYBdkSi8xAwA], Tuple [v1=[mis-30-3][indices][2duN29lpRgSDUPwXK6NGNg][102], v2=__le_gaXJLQ8a0Hj7BdrTRMA], Tuple [v1=[mis-30-3][indices][X8IDXnPuSxKIFkZpCRmYeA][128], v2=__voCnpHSHTOC0CkCFtSTUEw], Tuple [v1=[mis-30-3][indices][mwgniftDTa6WpZNy3glBTQ][68], v2=__GKvNcwmtSzOsKLDRjAl3UQ], Tuple [v1=[mis-30-3][indices][X8IDXnPuSxKIFkZpCRmYeA][108], v2=__WAhvgy3UTsyylLhljDvmpg], Tuple [v1=[mis-30-3][indices][iIED6ilrRQu_hqvLmx9o5g][137], v2=snap-amXHXu-ARoeVCtk3fr1cmg.dat], Tuple [v1=[mis-30-3][indices][_uukV0MESyyd9geXut9uMw][108], v2=__FG_HhGupRwm517zDcvgLfg], ... *** TRUNCATED *** ... Tuple [v1=[mis-30-3][indices][mwgniftDTa6WpZNy3glBTQ][46], v2=__1xM-NwbBSS21BW6mzFShOw], Tuple [v1=[mis-30-3][indices][iIED6ilrRQu_hqvLmx9o5g][81], v2=__GV7GUYo3QWWB42Mmf8yhCw], Tuple [v1=[mis-30-3][indices][ljTDObqbTdGqTXdywDC0lg][142], v2=index-jZRPP0E3Ti6VymwRK8ynig], Tuple [v1=[mis-30-3][indices][a13te36rQP-cisW8hGQDJw][135], v2=__3aUaGvNlTAOou6qiwDmsKg], Tuple [v1=[mis-30-3][indices][RR4lDG0gRxuA13b7mgB1Wg][93], v2=__-pZFhACTS-eIuNAy4j0_SQ], Tuple [v1=[mis-30-3][indices][qQQMvwLHSTGrJFVDszzuOQ][115], v2=__cm2txdrYT46KNI4VT82Wcg], Tuple [v1=[mis-30-3][indices][a13te36rQP-cisW8hGQDJw][26], v2=__KF95t3w1SIaVL-IKUWZpqg], Tuple [v1=[mis-30-3][indices][Mm_yUwerT1qJSR___QPUZw][0], v2=snap-8StXo3tsQ_qFbFU_ToHKaA.dat], Tuple [v1=[mis-30-3][indices][UOaIOyopTQ2M492ty3dc4g][95], v2=__cpChtqeXQgigNad66RwnAg], Tuple [v1=[mis-30-3][indices][X8IDXnPuSxKIFkZpCRmYeA][46], v2=__B0SV-8eXSHGIizmrps_7dA], Tuple [v1=[mis-30-3][indices][2duN29lpRgSDUPwXK6NGNg][23], v2=__KqwYvL3DS9mU4u7meOW5Eg]]

I didn't find any exception logged.