Actions
Bug #9220
closedobjecter doesn't reconnect watch on interval change w/ same primary
% Done:
0%
Source:
Q/A
Tags:
Backport:
firefly
Regression:
Severity:
Reviewed:
Affected Versions:
ceph-qa-suite:
Pull request ID:
Crash signature (v1):
Crash signature (v2):
Description
ubuntu@teuthology:/a/teuthology-2014-08-24_02:30:02-rados-next-testing-basic-multi/446803
2014-08-24 14:13:30.039746 7faf01235700 20 osd.3 pg_epoch: 948 pg[113.2s0( v 944'2 (0'0,944'2] local-les=946 n=1 ec=941 les/c 946/944 945/945/941) [3,4,1] r=0 lpr=945 pi=941-944/1 crt=0'0 lcod 944'1 mlcod 0'0 active+degraded] op_has_sufficient_caps pool=113 (test-rados-api-plana40-12123-5 test-rados-api-plana40-121 23-6) owner=0 need_read_cap=0 need_write_cap=1 need_class_read_cap=0 need_class_write_cap=0 -> yes 2014-08-24 14:13:30.039776 7faf01235700 10 osd.3 pg_epoch: 948 pg[113.2s0( v 944'2 (0'0,944'2] local-les=946 n=1 ec=941 les/c 946/944 945/945/941) [3,4,1] r=0 lpr=945 pi=941-944/1 crt=0'0 lcod 944'1 mlcod 0'0 active+degraded] handle_message: osd_op(client.4886.0:2 test-rados-api-plana40-12123-6/foo [watch add cooki e 1 ver 0] 113.e3ef388a ondisk+read+write+known_if_redirected e941) v4 2014-08-24 14:13:30.039808 7faf01235700 10 osd.3 pg_epoch: 948 pg[113.2s0( v 944'2 (0'0,944'2] local-les=946 n=1 ec=941 les/c 946/944 945/945/941) [3,4,1] r=0 lpr=945 pi=941-944/1 crt=0'0 lcod 944'1 mlcod 0'0 active+degraded] do_op osd_op(client.4886.0:2 test-rados-api-plana40-12123-6/foo [watch add cookie 1 ver 0] 113.e3ef388a ondisk+read+write+known_if_redirected e941) v4 may_write -> write-ordered flags ondisk+read+write+known_if_redirected 2014-08-24 14:13:30.039844 7faf01235700 10 osd.3 pg_epoch: 948 pg[113.2s0( v 944'2 (0'0,944'2] local-les=946 n=1 ec=941 les/c 946/944 945/945/941) [3,4,1] r=0 lpr=945 pi=941-944/1 crt=0'0 lcod 944'1 mlcod 0'0 active+degraded] readable_with_acting: locs:1(2),3(0) 2014-08-24 14:13:30.039879 7faf01235700 7 osd.3 pg_epoch: 948 pg[113.2s0( v 944'2 (0'0,944'2] local-les=946 n=1 ec=941 les/c 946/944 945/945/941) [3,4,1] r=0 lpr=945 pi=941-944/1 crt=0'0 lcod 944'1 mlcod 0'0 active+degraded] degraded e3ef388a/foo/head/test-rados-api-plana40-12123-6/113, recovering 2014-08-24 14:13:30.039906 7faf01235700 10 osd.3 pg_epoch: 948 pg[113.2s0( v 944'2 (0'0,944'2] local-les=946 n=1 ec=941 les/c 946/944 945/945/941) [3,4,1] r=0 lpr=945 pi=941-944/1 crt=0'0 lcod 944'1 mlcod 0'0 active+degraded] prep_object_replica_pushes: on e3ef388a/foo/head/test-rados-api-plana40-12123-6/113 2014-08-24 14:13:30.039933 7faf01235700 15 filestore(/var/lib/ceph/osd/ceph-3) getattr 113.2s0_head/e3ef388a/foo/head/test-rados-api-plana40-12123-6/113/18446744073709551615/0 '_' 2014-08-24 14:13:30.040033 7faf01235700 10 filestore(/var/lib/ceph/osd/ceph-3) getattr 113.2s0_head/e3ef388a/foo/head/test-rados-api-plana40-12123-6/113/18446744073709551615/0 '_' = 624 2014-08-24 14:13:30.040064 7faf01235700 15 filestore(/var/lib/ceph/osd/ceph-3) getattr 113.2s0_head/e3ef388a/foo/head/test-rados-api-plana40-12123-6/113/18446744073709551615/0 'snapset' 2014-08-24 14:13:30.040084 7faf01235700 10 filestore(/var/lib/ceph/osd/ceph-3) getattr 113.2s0_head/e3ef388a/foo/head/test-rados-api-plana40-12123-6/113/18446744073709551615/0 'snapset' = 31 2014-08-24 14:13:30.040097 7faf01235700 10 osd.3 pg_epoch: 948 pg[113.2s0( v 944'2 (0'0,944'2] local-les=946 n=1 ec=941 les/c 946/944 945/945/941) [3,4,1] r=0 lpr=945 pi=941-944/1 crt=0'0 lcod 944'1 mlcod 0'0 active+degraded] populate_obc_watchers e3ef388a/foo/head/test-rados-api-plana40-12123-6/113 2014-08-24 14:13:30.040127 7faf01235700 10 osd.3 pg_epoch: 948 pg[113.2s0( v 944'2 (0'0,944'2] local-les=946 n=1 ec=941 les/c 946/944 945/945/941) [3,4,1] r=0 lpr=945 pi=941-944/1 crt=0'0 lcod 944'1 mlcod 0'0 active+degraded] unconnected watcher 1,client.4886 will expire 30.000000 2014-08-24 14:13:30.040157 7faf01235700 10 osd.3 pg_epoch: 948 pg[113.2s0( v 944'2 (0'0,944'2] local-les=946 n=1 ec=941 les/c 946/944 945/945/941) [3,4,1] r=0 lpr=945 pi=941-944/1 crt=0'0 lcod 944'1 mlcod 0'0 active+degraded] -- Watch(1,client.4886) Watch() 2014-08-24 14:13:30.040174 7faf01235700 10 osd.3 pg_epoch: 948 pg[113.2s0( v 944'2 (0'0,944'2] local-les=946 n=1 ec=941 les/c 946/944 945/945/941) [3,4,1] r=0 lpr=945 pi=941-944/1 crt=0'0 lcod 944'1 mlcod 0'0 active+degraded] -- Watch(1,client.4886) disconnect 2014-08-24 14:13:30.040188 7faf01235700 15 osd.3 pg_epoch: 948 pg[113.2s0( v 944'2 (0'0,944'2] local-les=946 n=1 ec=941 les/c 946/944 945/945/941) [3,4,1] r=0 lpr=945 pi=941-944/1 crt=0'0 lcod 944'1 mlcod 0'0 active+degraded] -- Watch(1,client.4886) registering callback, timeout: 30 2014-08-24 14:13:30.040212 7faf01235700 20 osd.3 pg_epoch: 948 pg[113.2s0( v 944'2 (0'0,944'2] local-les=946 n=1 ec=941 les/c 946/944 945/945/941) [3,4,1] r=0 lpr=945 pi=941-944/1 crt=0'0 lcod 944'1 mlcod 0'0 active+degraded] ReplicatedPG::check_blacklisted_obc_watchers for obc e3ef388a/foo/head/test-rados-api-plan ... and when the op comes around again, it's seen as a dup ...
Actions