Project

General

Profile

Actions

Bug #10441

closed

osd: dup watch can reply before watch is persisted

Added by Sage Weil over 9 years ago. Updated about 9 years ago.

Status:
Resolved
Priority:
Urgent
Assignee:
Category:
-
Target version:
-
% Done:

0%

Source:
Q/A
Tags:
Backport:
Regression:
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Pull request ID:
Crash signature (v1):
Crash signature (v2):

Description

- watch1 received by osd
- osd starts repop
- connection reset
- watch2 resent by client
- watch2 sees watch is already registered (* bug is here *), replies
- watch2's session is connected to watch
- watch1 commits
- watch1's session is connected to watch (but this is the old con that is not disconnected)

ubuntu@teuthology:/a/sage-2014-12-29_21:21:14-rados:basic-wip-recovery-temp---basic-multi/685213


Related issues 2 (0 open2 closed)

Related to Ceph - Bug #13971: "test/multi_stress_watch.cc: 61: FAILED assert(!ret)" in rados-hammer-distro-basic-openstackCan't reproduce12/03/2015

Actions
Has duplicate Ceph - Bug #10564: test/multi_stress_watch.cc: 60: FAILED assert(!ret)DuplicateSage Weil01/18/2015

Actions
Actions #1

Updated by Sage Weil over 9 years ago

2014-12-29 21:51:14.635215 7f378225a700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5895 (21'2800,21'5895] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 crt=21'5893 lcod 21'5894 mlcod 21'5894 active+clean] find_object_context 5/bd210e3e/repobj/head @head oi=5/bd210e3e/repobj/head(21'5895 client.4105.0:11987 
wrlock_by=unknown.0.0:0 dirty|data_digest|omap_digest s 0 uv 1 dd ffffffff od ffffffff)
2014-12-29 21:51:14.635232 7f378225a700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5895 (21'2800,21'5895] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 crt=21'5893 lcod 21'5894 mlcod 21'5894 active+clean] execute_ctx 0x4f07e00
2014-12-29 21:51:14.635246 7f378225a700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5895 (21'2800,21'5895] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 crt=21'5893 lcod 21'5894 mlcod 21'5894 active+clean] do_op 5/bd210e3e/repobj/head [watch watch cookie 17799488] ov 21'5895 av 21'5896 snapc 0=[] snapset 0=[
]:[]+head
2014-12-29 21:51:14.635255 7f378225a700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5895 (21'2800,21'5895] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 crt=21'5893 lcod 21'5894 mlcod 21'5894 active+clean] do_osd_op 5/bd210e3e/repobj/head [watch watch cookie 17799488]
2014-12-29 21:51:14.635262 7f378225a700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5895 (21'2800,21'5895] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 crt=21'5893 lcod 21'5894 mlcod 21'5894 active+clean] do_osd_op  watch watch cookie 17799488
2014-12-29 21:51:14.635269 7f378225a700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5895 (21'2800,21'5895] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 crt=21'5893 lcod 21'5894 mlcod 21'5894 active+clean] watch watch: ctx->obc=0x451ab00 cookie=17799488 oi.version=5895 ctx->at_version=21'5896
2014-12-29 21:51:14.635276 7f378225a700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5895 (21'2800,21'5895] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 crt=21'5893 lcod 21'5894 mlcod 21'5894 active+clean] watch: oi.user_version=1
2014-12-29 21:51:14.635282 7f378225a700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5895 (21'2800,21'5895] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 crt=21'5893 lcod 21'5894 mlcod 21'5894 active+clean] watch: peer_addr=10.214.136.28:0/1053718
2014-12-29 21:51:14.635291 7f378225a700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5895 (21'2800,21'5895] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 crt=21'5893 lcod 21'5894 mlcod 21'5894 active+clean]  registered new watch watch(cookie 17799488 30s 10.214.136.28:0/1053718) by client.4105
2014-12-29 21:51:14.635302 7f378225a700 20 osd.2 pg_epoch: 21 pg[5.6( v 21'5895 (21'2800,21'5895] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 crt=21'5893 lcod 21'5894 mlcod 21'5894 active+clean] make_writeable 5/bd210e3e/repobj/head snapset=0x476cb60  snapc=0=[]
2014-12-29 21:51:14.635310 7f378225a700 20 osd.2 pg_epoch: 21 pg[5.6( v 21'5895 (21'2800,21'5895] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 crt=21'5893 lcod 21'5894 mlcod 21'5894 active+clean] make_writeable 5/bd210e3e/repobj/head done, snapset=0=[]:[]+head
2014-12-29 21:51:14.635317 7f378225a700 20 osd.2 pg_epoch: 21 pg[5.6( v 21'5895 (21'2800,21'5895] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 crt=21'5893 lcod 21'5894 mlcod 21'5894 active+clean] finish_ctx 5/bd210e3e/repobj/head 0x4f07e00 op modify  
2014-12-29 21:51:14.635338 7f378225a700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5895 (21'2800,21'5895] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 crt=21'5893 lcod 21'5894 mlcod 21'5894 active+clean]  set mtime to 2014-12-29 21:51:14.634445
2014-12-29 21:51:14.635355 7f378225a700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5895 (21'2800,21'5895] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 crt=21'5893 lcod 21'5894 mlcod 21'5894 active+clean]  final snapset 0=[]:[]+head in 5/bd210e3e/repobj/head
2014-12-29 21:51:14.635368 7f378225a700 20 osd.2 pg_epoch: 21 pg[5.6( v 21'5895 (21'2800,21'5895] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 crt=21'5893 lcod 21'5894 mlcod 21'5894 active+clean]  zeroing write result code 0
2014-12-29 21:51:14.635375 7f378225a700 20 osd.2 pg_epoch: 21 pg[5.6( v 21'5895 (21'2800,21'5895] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 crt=21'5893 lcod 21'5894 mlcod 21'5894 active+clean]  op order client.4105 tid 11988 last was 11987
2014-12-29 21:51:14.635382 7f378225a700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5895 (21'2800,21'5895] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 crt=21'5893 lcod 21'5894 mlcod 21'5894 active+clean] new_repop rep_tid 5896 on osd_op(client.4105.0:11988 repobj [watch watch cookie 17799488] 5.bd210e3e on
disk+write+known_if_redirected e21) v4
2014-12-29 21:51:14.635392 7f378225a700  7 osd.2 pg_epoch: 21 pg[5.6( v 21'5895 (21'2800,21'5895] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 crt=21'5893 lcod 21'5894 mlcod 21'5894 active+clean] issue_repop rep_tid 5896 o 5/bd210e3e/repobj/head
2014-12-29 21:51:14.635457 7f378225a700 20 osd.2 21 share_map_peer 0x38ab020 already has epoch 21
2014-12-29 21:51:14.635465 7f378225a700  1 -- 10.214.136.28:6809/50180 --> 10.214.136.28:6805/50179 -- osd_sub_op(client.4105.0:11988 5.6 5/bd210e3e/repobj/head [] v 21'5896 snapset=0=[]:[] snapc=0=[]) v11 -- ?+821 0x4cf2c00 con 0x38ab020
2014-12-29 21:51:14.635508 7f378225a700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5895 (21'2800,21'5895] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 crt=21'5893 lcod 21'5894 mlcod 21'5894 active+clean] append_log log((21'2800,21'5895], crt=21'5893) [21'5896 (21'5895) modify   5/bd210e3e/repobj/head by cl
ient.4105.0:11988 2014-12-29 21:51:14.634445]
2014-12-29 21:51:14.635555 7f378225a700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5896 (21'2800,21'5896] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 luod=21'5895 crt=21'5893 lcod 21'5894 mlcod 21'5894 active+clean] add_log_entry 21'5896 (21'5895) modify   5/bd210e3e/repobj/head by client.4105.0:11988 201
4-12-29 21:51:14.634445
2014-12-29 21:51:14.635602 7f378225a700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5896 (21'2800,21'5896] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 luod=21'5895 crt=21'5894 lcod 21'5894 mlcod 21'5894 active+clean] append_log  adding 1 keys
2014-12-29 21:51:14.635630 7f378225a700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5896 (21'2800,21'5896] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 luod=21'5895 crt=21'5894 lcod 21'5894 mlcod 21'5894 active+clean] append_log: trimming to 21'5894 entries 21'5894 (21'5893) modify   5/bd210e3e/repobj/head 
by client.4105.0:11984 2014-12-29 21:51:14.571454
2014-12-29 21:51:14.635696 7f378225a700 10 write_log with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, dirty_divergent_priors: 0, writeout_from: 21'5896, trimmed: 
2014-12-29 21:51:14.635942 7f3778d27700  1 -- 10.214.136.28:6808/50180 >> :/0 pipe(0x3a83000 sd=52 :6808 s=0 pgs=0 cs=0 l=0 c=0x467f760).accept sd=52 10.214.136.28:53023/0
2014-12-29 21:51:14.636374 7f3778d27700 10 osd.2 21  new session 0x5187e00 con=0x467f760 addr=10.214.136.28:0/1053718
2014-12-29 21:51:14.636451 7f3778d27700 10 osd.2 21  session 0x5187e00 client.admin has caps osdcap[grant(*)] 'allow *'
2014-12-29 21:51:14.636946 7f3778d27700  1 -- 10.214.136.28:6808/50180 <== client.4105 10.214.136.28:0/1053718 1 ==== osd_op(client.4105.0:11989 repobj [watch watch cookie 17799488] 5.bd210e3e ondisk+write+known_if_redirected e21) v4 ==== 157+0+0 (3245774995 0 0) 0x5187900 con 0x467f760
2014-12-29 21:51:14.637094 7f3778d27700 20 osd.2 21 should_share_map client.4105 10.214.136.28:0/1053718 21
2014-12-29 21:51:14.637142 7f3778d27700 15 osd.2 21 enqueue_op 0x4b35100 prio 63 cost 0 latency 0.000307 osd_op(client.4105.0:11989 repobj [watch watch cookie 17799488] 5.bd210e3e ondisk+write+known_if_redirected e21) v4
2014-12-29 21:51:14.640977 7f378225a700  5 filestore(/var/lib/ceph/osd/ceph-2) queue_transactions existing osr(5.6 0x38362b0)/0x38362b0
2014-12-29 21:51:14.640993 7f378225a700 10 journal op_submit_start 5980
2014-12-29 21:51:14.640994 7f378225a700  5 filestore(/var/lib/ceph/osd/ceph-2) queue_transactions (parallel) 5980 0x476e600
2014-12-29 21:51:14.640996 7f378225a700 10 journal op_journal_transactions 5980 0x476e600
2014-12-29 21:51:14.641001 7f378225a700  5 journal submit_entry seq 5980 len 2232 (0x4950020)
2014-12-29 21:51:14.641028 7f378225a700  5 filestore(/var/lib/ceph/osd/ceph-2) queue_op 0x4173e80 seq 5980 osr(5.6 0x38362b0) 2226 bytes   (queue has 1 ops and 2226 bytes)
2014-12-29 21:51:14.641038 7f378225a700 10 journal op_submit_finish 5980
2014-12-29 21:51:14.641040 7f378225a700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5896 (21'2800,21'5896] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 luod=21'5895 crt=21'5894 lcod 21'5894 mlcod 21'5894 active+clean] eval_repop repgather(0x4093d40 21'5896 rep_tid=5896 committed?=0 applied?=0 lock=0 op=osd_
op(client.4105.0:11988 repobj [watch watch cookie 17799488] 5.bd210e3e ondisk+write+known_if_redirected e21) v4) wants=d
2014-12-29 21:51:14.641054 7f378225a700 10 osd.2 21 dequeue_op 0x4b34e00 finish
2014-12-29 21:51:14.641073 7f3784a5f700 10 osd.2 21 dequeue_op 0x4b35100 prio 63 cost 0 latency 0.004239 osd_op(client.4105.0:11989 repobj [watch watch cookie 17799488] 5.bd210e3e ondisk+write+known_if_redirected e21) v4 pg pg[5.6( v 21'5896 (21'2800,21'5896] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 l
pr=20 luod=21'5895 crt=21'5894 lcod 21'5894 mlcod 21'5894 active+clean]
2014-12-29 21:51:14.641089 7f3784a5f700 20 osd.2 pg_epoch: 21 pg[5.6( v 21'5896 (21'2800,21'5896] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 luod=21'5895 crt=21'5894 lcod 21'5894 mlcod 21'5894 active+clean] op_has_sufficient_caps pool=5 (reppool ) owner=0 need_read_cap=0 need_write_cap=1 need_cla
ss_read_cap=0 need_class_write_cap=0 -> yes
2014-12-29 21:51:14.641099 7f3784a5f700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5896 (21'2800,21'5896] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 luod=21'5895 crt=21'5894 lcod 21'5894 mlcod 21'5894 active+clean] handle_message: 0x4b35100
2014-12-29 21:51:14.641106 7f3784a5f700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5896 (21'2800,21'5896] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 luod=21'5895 crt=21'5894 lcod 21'5894 mlcod 21'5894 active+clean] do_op osd_op(client.4105.0:11989 repobj [watch watch cookie 17799488] 5.bd210e3e ondisk+wr
ite+known_if_redirected e21) v4 may_write -> write-ordered flags ondisk+write+known_if_redirected
2014-12-29 21:51:14.641119 7f3784a5f700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5896 (21'2800,21'5896] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 luod=21'5895 crt=21'5894 lcod 21'5894 mlcod 21'5894 active+clean] get_object_context: found obc in cache: 0x451ab00
2014-12-29 21:51:14.641125 7f3784a5f700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5896 (21'2800,21'5896] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 luod=21'5895 crt=21'5894 lcod 21'5894 mlcod 21'5894 active+clean] get_object_context: 0x451ab00 5/bd210e3e/repobj/head rwstate(write n=1 w=0) oi: 5/bd210e3e
/repobj/head(21'5896 client.4105.0:11988 wrlock_by=unknown.0.0:0 dirty|data_digest|omap_digest s 0 uv 1 dd ffffffff od ffffffff) ssc: 0x476cb20 snapset: 0=[]:[]+head
2014-12-29 21:51:14.641137 7f3784a5f700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5896 (21'2800,21'5896] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 luod=21'5895 crt=21'5894 lcod 21'5894 mlcod 21'5894 active+clean] find_object_context 5/bd210e3e/repobj/head @head oi=5/bd210e3e/repobj/head(21'5896 client.
4105.0:11988 wrlock_by=unknown.0.0:0 dirty|data_digest|omap_digest s 0 uv 1 dd ffffffff od ffffffff)
2014-12-29 21:51:14.641153 7f3784a5f700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5896 (21'2800,21'5896] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 luod=21'5895 crt=21'5894 lcod 21'5894 mlcod 21'5894 active+clean] execute_ctx 0x4f0ec00
2014-12-29 21:51:14.641166 7f3784a5f700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5896 (21'2800,21'5896] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 luod=21'5895 crt=21'5894 lcod 21'5894 mlcod 21'5894 active+clean] do_op 5/bd210e3e/repobj/head [watch watch cookie 17799488] ov 21'5896 av 21'5897 snapc 0=[] snapset 0=[]:[]+head
2014-12-29 21:51:14.641175 7f3784a5f700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5896 (21'2800,21'5896] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 luod=21'5895 crt=21'5894 lcod 21'5894 mlcod 21'5894 active+clean] do_osd_op 5/bd210e3e/repobj/head [watch watch cookie 17799488]
2014-12-29 21:51:14.641182 7f3784a5f700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5896 (21'2800,21'5896] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 luod=21'5895 crt=21'5894 lcod 21'5894 mlcod 21'5894 active+clean] do_osd_op  watch watch cookie 17799488
2014-12-29 21:51:14.641189 7f3784a5f700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5896 (21'2800,21'5896] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 luod=21'5895 crt=21'5894 lcod 21'5894 mlcod 21'5894 active+clean] watch watch: ctx->obc=0x451ab00 cookie=17799488 oi.version=5896 ctx->at_version=21'5897
2014-12-29 21:51:14.641198 7f3784a5f700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5896 (21'2800,21'5896] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 luod=21'5895 crt=21'5894 lcod 21'5894 mlcod 21'5894 active+clean] watch: oi.user_version=1
2014-12-29 21:51:14.641204 7f3784a5f700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5896 (21'2800,21'5896] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 luod=21'5895 crt=21'5894 lcod 21'5894 mlcod 21'5894 active+clean] watch: peer_addr=10.214.136.28:0/1053718
2014-12-29 21:51:14.641042 7f37943bf700 20 journal write_thread_entry woke up
2014-12-29 21:51:14.641212 7f3784a5f700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5896 (21'2800,21'5896] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 luod=21'5895 crt=21'5894 lcod 21'5894 mlcod 21'5894 active+clean]  found existing watch watch(cookie 17799488 30s 10.214.136.28:0/1053718) by client.4105
2014-12-29 21:51:14.641226 7f37943bf700 10 journal room 104407039 max_size 104857600 pos 24702976 header.start 24256512 top 4096
2014-12-29 21:51:14.641225 7f3784a5f700 15 osd.2 pg_epoch: 21 pg[5.6( v 21'5896 (21'2800,21'5896] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 luod=21'5895 crt=21'5894 lcod 21'5894 mlcod 21'5894 active+clean] do_osd_op_effects client.4105 con 0x467f760
2014-12-29 21:51:14.641232 7f37943bf700 10 journal check_for_full at 24702976 : 4096 < 104407039
2014-12-29 21:51:14.641236 7f37943bf700 15 journal prepare_single_write 1 will write 24702976 : seq 5980 len 2232 -> 4096 (head 40 pre_pad 0 ebl 2232 post_pad 1784 tail 40) (ebl alignment -1)
2014-12-29 21:51:14.641233 7f3784a5f700 15 osd.2 pg_epoch: 21 pg[5.6( v 21'5896 (21'2800,21'5896] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 luod=21'5895 crt=21'5894 lcod 21'5894 mlcod 21'5894 active+clean] do_osd_op_effects applying watch connect on session 0x5187e00 watcher 17799488,client.4105
2014-12-29 21:51:14.641256 7f3784a5f700 15 osd.2 pg_epoch: 21 pg[5.6( v 21'5896 (21'2800,21'5896] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 luod=21'5895 crt=21'5894 lcod 21'5894 mlcod 21'5894 active+clean] do_osd_op_effects new watcher 17799488,client.4105
2014-12-29 21:51:14.641264 7f3784a5f700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5896 (21'2800,21'5896] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 luod=21'5895 crt=21'5894 lcod 21'5894 mlcod 21'5894 active+clean]  -- Watch(17799488,client.4105) Watch()
2014-12-29 21:51:14.641273 7f3784a5f700 10 osd.2 pg_epoch: 21 pg[5.6( v 21'5896 (21'2800,21'5896] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 luod=21'5895 crt=21'5894 lcod 21'5894 mlcod 21'5894 active+clean]  -- Watch(17799488,client.4105) connecting
2014-12-29 21:51:14.641281 7f3784a5f700 15 osd.2 pg_epoch: 21 pg[5.6( v 21'5896 (21'2800,21'5896] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 luod=21'5895 crt=21'5894 lcod 21'5894 mlcod 21'5894 active+clean]  -- Watch(17799488,client.4105) registering callback, timeout: 30
2014-12-29 21:51:14.641296 7f37943bf700 20 journal prepare_multi_write queue_pos now 24707072
2014-12-29 21:51:14.641299 7f37943bf700 15 journal do_write writing 24702976~4096
2014-12-29 21:51:14.641296 7f3784a5f700 15 osd.2 pg_epoch: 21 pg[5.6( v 21'5896 (21'2800,21'5896] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 luod=21'5895 crt=21'5894 lcod 21'5894 mlcod 21'5894 active+clean] log_op_stats osd_op(client.4105.0:11989 repobj [watch watch cookie 17799488] 5.bd210e3e ondisk+write+known_if_redirected e21) v4 inb 0 outb 0 rlat 0.000000 lat 0.004461
2014-12-29 21:51:14.641309 7f3784a5f700 15 osd.2 pg_epoch: 21 pg[5.6( v 21'5896 (21'2800,21'5896] local-les=21 n=1 ec=20 les/c 21/21 20/20/20) [2,0] r=0 lpr=20 luod=21'5895 crt=21'5894 lcod 21'5894 mlcod 21'5894 active+clean] publish_stats_to_osd 21:11954
2014-12-29 21:51:14.641317 7f37943bf700 10 journal align_bl total memcopy: 4096
2014-12-29 21:51:14.641315 7f3784a5f700  1 -- 10.214.136.28:6808/50180 --> 10.214.136.28:0/1053718 -- osd_op_reply(11989 repobj [watch watch cookie 17799488] v0'0 uv1 ondisk = 0) v6 -- ?+0 0x48acdc0 con 0x467f760

Actions #2

Updated by Sage Weil over 9 years ago

  • Status changed from New to Fix Under Review
  • Assignee changed from Sage Weil to Samuel Just
Actions #3

Updated by Sage Weil about 9 years ago

  • Status changed from Fix Under Review to Resolved
Actions #4

Updated by Yuri Weinstein over 8 years ago

  • Related to Bug #13971: "test/multi_stress_watch.cc: 61: FAILED assert(!ret)" in rados-hammer-distro-basic-openstack added
Actions

Also available in: Atom PDF