Actions
Bug #53110
open[rbd-mirror] handle_unregister_watch: error
Status:
New
Priority:
Normal
Assignee:
-
Target version:
-
% Done:
0%
Source:
Tags:
Backport:
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Pull request ID:
Crash signature (v1):
Crash signature (v2):
Description
2021-10-30T16:51:43.425 INFO:tasks.rbd_mirror.cluster2.client.mirror.3.smithi196.stderr:2021-10-30T16:51:43.425+0000 7f354c639700 -1 rbd::mirror::RemotePoolPoller: 0x56178153d040 handle_mirror_peer_ping: failed to ping remote mirror peer: (2) No such file or directory
2021-10-30T16:51:43.425 INFO:tasks.rbd_mirror.cluster2.client.mirror.3.smithi196.stderr:2021-10-30T16:51:43.425+0000 7f354c639700 -1 rbd::mirror::RemotePoolPoller: 0x56178153d040 handle_mirror_peer_list: failed to retrieve mirror peers: (2) No such file or directory
2021-10-30T16:51:43.425 INFO:tasks.rbd_mirror.cluster2.client.mirror.3.smithi196.stderr:2021-10-30T16:51:43.425+0000 7f354c639700 -1 rbd::mirror::PoolReplayer: 0x561781659b00 handle_remote_pool_meta_updated: remote pool metadata updated unexpectedly
2021-10-30T16:51:43.432 INFO:tasks.rbd_mirror.cluster2.client.mirror.3.smithi196.stderr:2021-10-30T16:51:43.433+0000 7f3559e54700 -1 rbd::mirror::InstanceWatcher: 0x561781563500 handle_unregister_watch: error unregistering instance watcher for rbd_mirror_instance.8090 object: (2) No such file or directory
2021-10-30T16:51:43.434 INFO:tasks.rbd_mirror.cluster2.client.mirror.3.smithi196.stderr:2021-10-30T16:51:43.434+0000 7f3553647700 -1 rbd::mirror::InstanceWatcher: 0x561781563880 handle_unregister_instance: error unregistering instance: (2) No such file or directory
2021-10-30T16:51:43.434 INFO:tasks.rbd_mirror.cluster2.client.mirror.3.smithi196.stderr:2021-10-30T16:51:43.434+0000 7f3553647700 -1 rbd::mirror::InstanceWatcher: 0x561781563500 handle_unregister_instance: error unregistering instance: (2) No such file or directory
2021-10-30T16:51:43.435 INFO:tasks.rbd_mirror.cluster2.client.mirror.3.smithi196.stderr:2021-10-30T16:51:43.434+0000 7f354c639700 -1 rbd::mirror::MirrorStatusUpdater 0x5617847c6120 handle_shut_down_mirror_status_watcher: failed to shut down mirror status watcher: (2) No such file or directory
2021-10-30T16:51:43.435 INFO:tasks.rbd_mirror.cluster2.client.mirror.3.smithi196.stderr:2021-10-30T16:51:43.434+0000 7f3559653700 -1 rbd::mirror::NamespaceReplayer: 0x561783bce1a0 handle_shut_down_remote_status_updater: error shutting remote mirror status updater down: (2) No such file or directory
2021-10-30T16:51:43.435 INFO:tasks.rbd_mirror.cluster2.client.mirror.3.smithi196.stderr:2021-10-30T16:51:43.434+0000 7f354c639700 -1 rbd::mirror::MirrorStatusUpdater 0x5617817d0ea0 handle_shut_down_mirror_status_watcher: failed to shut down mirror status watcher: (2) No such file or directory
2021-10-30T16:51:43.435 INFO:tasks.rbd_mirror.cluster2.client.mirror.3.smithi196.stderr:2021-10-30T16:51:43.434+0000 7f3559e54700 -1 rbd::mirror::NamespaceReplayer: 0x561783bce000 handle_shut_down_remote_status_updater: error shutting remote mirror status updater down: (2) No such file or directory
2021-10-30T16:51:43.576 INFO:tasks.rbd_mirror.cluster2.client.mirror.3.smithi196.stderr:2021-10-30T16:51:43.576+0000 7f353ee1e700 -1 rbd::mirror::RemotePoolPoller: 0x56178153d930 handle_mirror_peer_ping: failed to ping remote mirror peer: (2) No such file or directory
2021-10-30T16:51:43.577 INFO:tasks.rbd_mirror.cluster2.client.mirror.3.smithi196.stderr:2021-10-30T16:51:43.576+0000 7f353ee1e700 -1 rbd::mirror::RemotePoolPoller: 0x56178153d930 handle_mirror_peer_list: failed to retrieve mirror peers: (2) No such file or directory
2021-10-30T16:51:43.577 INFO:tasks.rbd_mirror.cluster2.client.mirror.3.smithi196.stderr:2021-10-30T16:51:43.576+0000 7f353ee1e700 -1 rbd::mirror::PoolReplayer: 0x561783a5af00 handle_remote_pool_meta_updated: remote pool metadata updated unexpectedly
2021-10-30T16:51:43.600 INFO:tasks.workunit.cluster1.client.mirror.smithi196.stderr:pool 'mirror_parent' does not exist
2021-10-30T16:51:43.610 INFO:tasks.workunit.cluster1.client.mirror.smithi196.stderr:+ for cluster in "${CLUSTER1}" "${CLU
Updated by Deepika Upadhyay over 2 years ago
/ceph/teuthology-archive/ideepika-2021-11-02_12:33:30-rbd-wip-ssd-cache-testing-distro-basic-smithi/6477630/teuthology.log
Updated by Deepika Upadhyay over 2 years ago
- Subject changed from [rbd::mirror] handle_unregister_watch: error to [rbd-mirror] handle_unregister_watch: error
Updated by Mykola Golub over 2 years ago
These watch (and other) errors are not the real problem for this test failure. They are after the test is finished and the environment is cleaning up. And the mirror pools may be deleted before the rbd-mirror process are stopped and then there are many those "(2) No such file or directory" errors.
The real problem for the test is:
2021-11-02T15:45:22.992 INFO:tasks.workunit.cluster1.client.mirror.smithi187.stderr:+ rbd --cluster cluster2 export mirror/image_cluster1.client.mirror.5-clone30@snap /tmp/tmp.6gZQgp5rO1/cluster2-mirror-image_cluster1.client.mirror.5-clone30.export 2021-11-02T15:45:23.215 INFO:tasks.workunit.cluster1.client.mirror.smithi187.stderr:error setting snapshot context: (2) No such file or directory
I.e. the test created a snapshot mirror/image_cluster1.client.mirror.5-clone30@snap on the primary (cluster1) image, waited for image replay to complete, and tried to export the snapshot from the non-primary (replayed) image to a file and faile because the snapshot did not exist here (was not replayed).
And later when the test outputs the clusters state after failure, we may see that indeed the snapshot exists on the primary but not on non-primary:
2021-11-02T15:46:56.836 INFO:tasks.workunit.cluster1.client.mirror.smithi187.stdout:image image_cluster1.client.mirror.5-clone30 snapshots 2021-11-02T15:46:56.836 INFO:tasks.workunit.cluster1.client.mirror.smithi187.stderr:+ echo image image_cluster1.client.mirror.5-clone30 snapshots 2021-11-02T15:46:56.837 INFO:tasks.workunit.cluster1.client.mirror.smithi187.stderr:+ rbd --cluster cluster1 -p mirror --namespace snap ls --all image_cluster1.client.mirror.5-clone30 2021-11-02T15:46:57.128 INFO:tasks.workunit.cluster1.client.mirror.smithi187.stdout:SNAPID NAME SIZE PROTECTED TIMESTAMP NAMESPACE 2021-11-02T15:46:57.129 INFO:tasks.workunit.cluster1.client.mirror.smithi187.stdout: 425 snap 220 MiB yes Tue Nov 2 15:27:20 2021 user 2021-11-02T15:46:57.129 INFO:tasks.workunit.cluster1.client.mirror.smithi187.stdout: 996 2c7db535-4d32-4708-9351-acf542134060 220 MiB Tue Nov 2 15:35:08 2021 user 2021-11-02T15:46:57.143 INFO:tasks.workunit.cluster1.client.mirror.smithi187.stderr:+ echo ... 2021-11-02T15:48:25.036 INFO:tasks.workunit.cluster1.client.mirror.smithi187.stdout:image image_cluster1.client.mirror.5-clone30 snapshots 2021-11-02T15:48:25.037 INFO:tasks.workunit.cluster1.client.mirror.smithi187.stderr:+ echo 2021-11-02T15:48:25.037 INFO:tasks.workunit.cluster1.client.mirror.smithi187.stderr:+ echo image image_cluster1.client.mirror.5-clone30 snapshots 2021-11-02T15:48:25.037 INFO:tasks.workunit.cluster1.client.mirror.smithi187.stderr:+ rbd --cluster cluster2 -p mirror --namespace snap ls --all image_cluster1.client.mirror.5-clone30 2021-11-02T15:48:25.255 INFO:tasks.workunit.cluster1.client.mirror.smithi187.stdout:SNAPID NAME SIZE PROTECTED TIMESTAMP NAMESPACE 2021-11-02T15:48:25.256 INFO:tasks.workunit.cluster1.client.mirror.smithi187.stdout: 1012 2c7db535-4d32-4708-9351-acf542134060 17 MiB Tue Nov 2 15:35:12 2021 user 2021-11-02T15:48:25.268 INFO:tasks.workunit.cluster1.client.mirror.smithi187.stderr:+ echo
Need to look in the rbd-mirror logs to see what was going on during image image_cluster1.client.mirror.5-clone30 (global_id 3c4a0dc6-4fa3-4799-80d7-59c4c4ff0357) replay.
Actions