Bug #18310: LibRadosWatchNotify.WatchNotify2Timeout FAILED - Ceph - Ceph

Actions

Copy link

Bug #18310

closed

LibRadosWatchNotify.WatchNotify2Timeout FAILED

Added by Sage Weil over 7 years ago. Updated over 7 years ago.

Status:

Resolved

Priority:

Immediate

Assignee:

Samuel Just

Category:

Target version:

% Done:

Source:

Tags:

Backport:

Regression:

Severity:

3 - minor

Reviewed:

Affected Versions:

ceph-qa-suite:

Pull request ID:

Crash signature (v1):

Crash signature (v2):

Description

2016-12-20T05:12:42.685 INFO:tasks.workunit.client.0.smithi083.stdout:         api_watch_notify: [ RUN      ] LibRadosWatchNotify.WatchNotify2Timeout
2016-12-20T05:12:42.685 INFO:tasks.workunit.client.0.smithi083.stdout:         api_watch_notify: watch_notify2_test_cb from 4151 notify_id 201863462913 cookie 93897496216032
2016-12-20T05:12:42.685 INFO:tasks.workunit.client.0.smithi083.stdout:         api_watch_notify: watch_notify2_test_cb from 4151 notify_id 206158430210 cookie 93897496216032
2016-12-20T05:12:42.685 INFO:tasks.workunit.client.0.smithi083.stdout:         api_watch_notify: watch_notify2_test_errcb cookie 93897496216032 err -110
2016-12-20T05:12:42.685 INFO:tasks.workunit.client.0.smithi083.stdout:         api_watch_notify: watch_notify2_test_cb from 4151 notify_id 223338299395 cookie 93897496216032
2016-12-20T05:12:42.685 INFO:tasks.workunit.client.0.smithi083.stdout:         api_watch_notify: watch_notify2_test_cb from 4151 notify_id 223338299396 cookie 93897496216032
2016-12-20T05:12:42.685 INFO:tasks.workunit.client.0.smithi083.stdout:         api_watch_notify: /build/ceph-11.1.0-6129-g409601b/src/test/librados/watch_notify.cc:725: Failure
2016-12-20T05:12:42.685 INFO:tasks.workunit.client.0.smithi083.stdout:         api_watch_notify: Expected: (rados_watch_check(ioctx, handle)) > (0), actual: -110 vs 0
2016-12-20T05:12:42.685 INFO:tasks.workunit.client.0.smithi083.stdout:         api_watch_notify: [  FAILED  ] LibRadosWatchNotify.WatchNotify2Timeout (5030 ms)

/a/sage-2016-12-20_03:05:39-rados-wip-sage-testing---basic-smithi/648787
/a/sage-2016-12-19_17:12:41-rados-wip-sage-testing---basic-smithi/647308

Actions

Copy link

Updated by Sage Weil over 7 years ago

Looks like fallout from 89fd030bf9436dc4e37cc3a0f935ec077455d9d5

client ops are

2016-12-20 05:12:36.599302 7fba237fe700 20 client.4151.objecter 192     6.291fb0be      osd.3   foo     [watch reconnect cookie 93897496216032 gen 2]
...
2016-12-20 05:12:36.599309 7fba237fe700 20 client.4151.objecter 194     6.291fb0be      osd.3   foo     [watch ping cookie 93897496216032 gen 2]

and osd does this

2016-12-20 05:12:36.615060 7fb033208700 10 osd.3 pg_epoch: 52 pg[6.6( v 47'10 (0'0,47'10] local-les=52 n=1 ec=18 les/c/f 52/32/0 50/51/18) [3,5,0] r=0 lpr=51 pi=31-50/2 rops=1 crt=47'10 lcod 47'9 mlcod 0'0 active+recovery_wait+degraded] do_op osd_op(client.4151.0:192 6.291fb0be test-rados-api-smithi083-10730-10/foo [watch reconnect cookie 93897496216032 gen 2] snapc 0=[] ondisk+write+known_if_redirected e51) v7 may_write may_read -> write-ordered flags ondisk+write+known_if_redirected
...note write ordered...
2016-12-20 05:12:36.616014 7fb033208700 10 osd.3 pg_epoch: 52 pg[6.6( v 47'10 (0'0,47'10] local-les=52 n=1 ec=18 les/c/f 52/32/0 50/51/18) [3,5,0] r=0 lpr=51 pi=31-50/2 rops=1 crt=47'10 lcod 47'9 mlcod 0'0 active+recovery_wait+degraded] do_op osd_op(client.4151.0:194 6.291fb0be test-rados-api-smithi083-10730-10/foo [watch ping cookie 93897496216032 gen 2] snapc 0=[] ondisk+write+known_if_redirected e51) v7 may_read -> read-ordered flags ondisk+write+known_if_redirected
...note read ordered!...
2016-12-20 05:12:36.616293 7fb033208700  1 -- 172.21.15.68:6800/13817 --> 172.21.15.83:0/1204261170 -- osd_op_reply(194 foo [watch ping cookie 93897496216032 gen 2] v0'0 uv0 ondisk = -110 ((110) Connection timed out)) v7 -- 0x7fb06039a000 con 0

Actions

Copy link