Dear Greg,
Thank you, I have tried to trace the log, the snapid should similar. Accurately, I'm modifying the source code of client, I want to implement a new MDS for it. Here list the two versions of log. The first one is original log. The second one is the client log after I modified.
Thank you and Best Regards
Thomas
The original log.
2013-11-25 15:43:37.236728 7fdd7484f780 3 client.5703 _ll_get_inode 1000000003a.head
2013-11-25 15:43:37.236733 7fdd7484f780 10 client.5703 _getattr mask Xs issued=1
2013-11-25 15:43:37.236737 7fdd7484f780 3 client.5703 _getxattr(1000000003a, "security.capability", 0) = -61
2013-11-25 15:43:37.236785 7fdd7484f780 3 client.5703 ll_write 0x27b5c80 1000000003a 0~10
2013-11-25 15:43:37.236790 7fdd7484f780 10 client.5703 cur file size is 0
2013-11-25 15:43:37.236797 7fdd7484f780 10 client.5703 wanted_max_size 0 -> 10
2013-11-25 15:43:37.236800 7fdd7484f780 10 client.5703 check_caps on 1000000003a.head(ref=3 cap_refs={} open={2=1} mode=102750 size=0 mtime=2013-11-26 00:10:28.056292 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[1000000003a ts 0/0 objects 0 dirty_or_tx 0] parents=0x27a1ba0 0x7fdd60097fa0) wanted pAsxXsxFxwb used - is_delayed=0
2013-11-25 15:43:37.236833 7fdd7484f780 10 client.5703 cap_delay_requeue on 1000000003a.head(ref=3 cap_refs={} open={2=1} mode=102750 size=0 mtime=2013-11-26 00:10:28.056292 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[1000000003a ts 0/0 objects 0 dirty_or_tx 0] parents=0x27a1ba0 0x7fdd60097fa0)
2013-11-25 15:43:37.236858 7fdd7484f780 10 client.5703 cap mds.0 issued pAsxLsXsxFsxcrwb implemented pAsxLsXsxFsxcrwb revoking -
2013-11-25 15:43:37.236873 7fdd7484f780 10 client.5703 delaying cap release
2013-11-25 15:43:37.236876 7fdd7484f780 10 client.5703 get_caps 1000000003a.head(ref=3 cap_refs={} open={2=1} mode=102750 size=0 mtime=2013-11-26 00:10:28.056292 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[1000000003a ts 0/0 objects 0 dirty_or_tx 0] parents=0x27a1ba0 0x7fdd60097fa0) have pAsxLsXsxFsxcrwb need Fw want Fb but not Fb revoking -
2013-11-25 15:43:37.236923 7fdd7484f780 10 client.5703 snaprealm snaprealm(1 nref=2 c=0 seq=1 parent=0 my_snaps=[] cached_snapc=1=[])
2013-11-25 15:43:37.236930 7fdd7484f780 5 client.5703 get_cap_ref got first FILE_BUFFER ref on 1000000003a.head(ref=4 cap_refs={4096=1,8192=0} open={2=1} mode=102750 size=0 mtime=2013-11-26 00:10:28.056292 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[1000000003a ts 0/0 objects 0 dirty_or_tx 0] parents=0x27a1ba0 0x7fdd60097fa0)
2013-11-25 15:43:37.237052 7fdd7484f780 10 -- 192.168.35.82:0/2376 connect_rank to 192.168.35.84:6800/8058, creating pipe and registering
2013-11-25 15:43:37.237131 7fdd7484f780 10 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=-1 :0 s=1 pgs=0 cs=0 l=1 c=0x2843ab0).register_pipe
2013-11-25 15:43:37.237153 7fdd7484f780 10 -- 192.168.35.82:0/2376 get_connection osd.1 192.168.35.84:6800/8058 new 0x2843850
2013-11-25 15:43:37.237145 7fdd7040f700 10 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=-1 :0 s=1 pgs=0 cs=0 l=1 c=0x2843ab0).writer: state = connecting policy.server=0
2013-11-25 15:43:37.237228 7fdd7040f700 10 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=-1 :0 s=1 pgs=0 cs=0 l=1 c=0x2843ab0).connect 0
2013-11-25 15:43:37.237260 7fdd7040f700 10 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :0 s=1 pgs=0 cs=0 l=1 c=0x2843ab0).connecting to 192.168.35.84:6800/8058
2013-11-25 15:43:37.237275 7fdd7484f780 1 -- 192.168.35.82:0/2376 --> 192.168.35.84:6800/8058 -- osd_op(client.5703.0:1 1000000003a.00000000 [write 0~10 [1@-1]] 0.92a3958f snapc 1=[] e38) v4 -- ?+0 0x2844090 con 0x2843ab0
2013-11-25 15:43:37.237299 7fdd7484f780 20 -- 192.168.35.82:0/2376 submit_message osd_op(client.5703.0:1 1000000003a.00000000 [write 0~10 [1@-1]] 0.92a3958f snapc 1=[] e38) v4 remote, 192.168.35.84:6800/8058, have pipe.
2013-11-25 15:43:37.238043 7fdd7040f700 20 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=1 pgs=0 cs=0 l=1 c=0x2843ab0).connect read peer addr 192.168.35.84:6800/8058 on socket 0
2013-11-25 15:43:37.238072 7fdd7040f700 20 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=1 pgs=0 cs=0 l=1 c=0x2843ab0).connect peer addr for me is 192.168.35.82:33572/0
2013-11-25 15:43:37.238101 7fdd7040f700 10 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=1 pgs=0 cs=0 l=1 c=0x2843ab0).connect sent my addr 192.168.35.82:0/2376
2013-11-25 15:43:37.238164 7fdd7040f700 10 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=1 pgs=0 cs=0 l=1 c=0x2843ab0).connect.authorizer_len=174 protocol=2
2013-11-25 15:43:37.238197 7fdd7040f700 10 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=1 pgs=0 cs=0 l=1 c=0x2843ab0).connect sending gseq=3 cseq=0 proto=24
2013-11-25 15:43:37.238216 7fdd7040f700 20 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=1 pgs=0 cs=0 l=1 c=0x2843ab0).connect wrote (self +) cseq, waiting for reply
2013-11-25 15:43:37.238840 7fdd7040f700 20 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=1 pgs=0 cs=0 l=1 c=0x2843ab0).connect got reply tag 1 connect_seq 1 global_seq 1118592 proto 24 flags 1 features 34359738367
2013-11-25 15:43:37.238859 7fdd7040f700 10 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=1 pgs=0 cs=0 l=1 c=0x2843ab0).reply.authorizer_len=36
2013-11-25 15:43:37.238903 7fdd7040f700 10 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=2 pgs=1118592 cs=1 l=1 c=0x2843ab0).connect success 1, lossy = 1, features 34359738367
2013-11-25 15:43:37.238936 7fdd7040f700 20 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=2 pgs=1118592 cs=1 l=1 c=0x2843ab0).connect starting reader
2013-11-25 15:43:37.238947 7fdd6a7fc700 10 client.5703 ms_handle_connect on 192.168.35.84:6800/8058
2013-11-25 15:43:37.239019 7fdd7040f700 10 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=2 pgs=1118592 cs=1 l=1 c=0x2843ab0).writer: state = open policy.server=0
2013-11-25 15:43:37.239038 7fdd7040f700 20 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=2 pgs=1118592 cs=1 l=1 c=0x2843ab0).writer encoding 1 features 34359738367 0x2844090 osd_op(client.5703.0:1 1000000003a.00000000 [write 0~10 [1@-1]] 0.92a3958f snapc 1=[] e38) v4
2013-11-25 15:43:37.239105 7fdd7040f700 20 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=2 pgs=1118592 cs=1 l=1 c=0x2843ab0).writer signed seq # 1): sig = 24422482693570454
2013-11-25 15:43:37.239125 7fdd7040f700 20 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=2 pgs=1118592 cs=1 l=1 c=0x2843ab0).writer sending 1 0x2844090
2013-11-25 15:43:37.239150 7fdd7040f700 10 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=2 pgs=1118592 cs=1 l=1 c=0x2843ab0).writer: state = open policy.server=0
2013-11-25 15:43:37.239164 7fdd7040f700 20 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=2 pgs=1118592 cs=1 l=1 c=0x2843ab0).writer sleeping
2013-11-25 15:43:37.239139 7fdd7030e700 20 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=2 pgs=1118592 cs=1 l=1 c=0x2843ab0).reader reading tag...
2013-11-25 15:43:37.253029 7fdd7030e700 20 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=2 pgs=1118592 cs=1 l=1 c=0x2843ab0).reader got ACK
2013-11-25 15:43:37.253052 7fdd7030e700 15 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=2 pgs=1118592 cs=1 l=1 c=0x2843ab0).reader got ack seq 1
2013-11-25 15:43:37.253063 7fdd7030e700 20 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=2 pgs=1118592 cs=1 l=1 c=0x2843ab0).reader reading tag...
2013-11-25 15:43:37.253074 7fdd7030e700 20 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=2 pgs=1118592 cs=1 l=1 c=0x2843ab0).reader got MSG
2013-11-25 15:43:37.253086 7fdd7030e700 20 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=2 pgs=1118592 cs=1 l=1 c=0x2843ab0).reader got envelope type=43 src osd.1 front=119 data=0 off 0
2013-11-25 15:43:37.253106 7fdd7030e700 10 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=2 pgs=1118592 cs=1 l=1 c=0x2843ab0).reader wants 119 from dispatch throttler 0/104857600
2013-11-25 15:43:37.253122 7fdd7030e700 20 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=2 pgs=1118592 cs=1 l=1 c=0x2843ab0).reader got front 119
2013-11-25 15:43:37.253137 7fdd7030e700 10 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=2 pgs=1118592 cs=1 l=1 c=0x2843ab0).aborted = 0
2013-11-25 15:43:37.253146 7fdd7030e700 20 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=2 pgs=1118592 cs=1 l=1 c=0x2843ab0).reader got 119 + 0 + 0 byte message
2013-11-25 15:43:37.253220 7fdd7030e700 10 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=2 pgs=1118592 cs=1 l=1 c=0x2843ab0).reader got message 1 0x7fdd3c0017d0 osd_op_reply(1 1000000003a.00000000 [write 0~10] v38'1 uv1 ondisk = 0) v4
2013-11-25 15:43:37.253243 7fdd7030e700 20 -- 192.168.35.82:0/2376 queue 0x7fdd3c0017d0 prio 127
2013-11-25 15:43:37.253257 7fdd7030e700 20 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=2 pgs=1118592 cs=1 l=1 c=0x2843ab0).reader reading tag...
2013-11-25 15:43:37.253264 7fdd6a7fc700 1 -- 192.168.35.82:0/2376 <== osd.1 192.168.35.84:6800/8058 1 ==== osd_op_reply(1 1000000003a.00000000 [write 0~10] v38'1 uv1 ondisk = 0) v4 ==== 119+0+0 (2991878044 0 0) 0x7fdd3c0017d0 con 0x2843ab0
2013-11-25 15:43:37.253283 7fdd6a7fc700 1 client.5703 ms_dispatch msg 43
2013-11-25 15:43:37.253319 7fdd6a7fc700 10 client.5703 check_caps on 1000000003a.head(ref=5 cap_refs={4096=1,8192=0} open={2=1} mode=102750 size=0 mtime=2013-11-26 00:10:28.056292 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[1000000003a ts 0/0 objects 0 dirty_or_tx 0] parents=0x27a1ba0 0x7fdd60097fa0) wanted pAsxXsxFxwb used Fw is_delayed=0
2013-11-25 15:43:37.253360 7fdd6a7fc700 10 client.5703 cap_delay_requeue on 1000000003a.head(ref=5 cap_refs={4096=1,8192=0} open={2=1} mode=102750 size=0 mtime=2013-11-26 00:10:28.056292 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[1000000003a ts 0/0 objects 0 dirty_or_tx 0] parents=0x27a1ba0 0x7fdd60097fa0)
2013-11-25 15:43:37.253395 7fdd6a7fc700 10 client.5703 cap mds.0 issued pAsxLsXsxFsxcrwb implemented pAsxLsXsxFsxcrwb revoking -
2013-11-25 15:43:37.253409 7fdd6a7fc700 10 client.5703 delaying cap release
2013-11-25 15:43:37.253411 7fdd6a7fc700 5 client.5703 put_cap_ref dropped last FILE_BUFFER ref on 1000000003a.head(ref=5 cap_refs={4096=1,8192=0} open={2=1} mode=102750 size=0 mtime=2013-11-26 00:10:28.056292 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[1000000003a ts 0/0 objects 0 dirty_or_tx 0] parents=0x27a1ba0 0x7fdd60097fa0)
2013-11-25 15:43:37.253436 7fdd6a7fc700 10 client.5703 put_inode on 1000000003a.head(ref=5 cap_refs={4096=1,8192=0} open={2=1} mode=102750 size=0 mtime=2013-11-26 00:10:28.056292 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[1000000003a ts 0/0 objects 0 dirty_or_tx 0] parents=0x27a1ba0 0x7fdd60097fa0)
2013-11-25 15:43:37.253459 7fdd6a7fc700 15 client.5703 sync_write_commit unsafe_sync_write = 0
2013-11-25 15:43:37.253477 7fdd7040f700 10 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=2 pgs=1118592 cs=1 l=1 c=0x2843ab0).writer: state = open policy.server=0
2013-11-25 15:43:37.253489 7fdd7040f700 10 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=2 pgs=1118592 cs=1 l=1 c=0x2843ab0).write_ack 1
2013-11-25 15:43:37.253502 7fdd7040f700 10 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=2 pgs=1118592 cs=1 l=1 c=0x2843ab0).writer: state = open policy.server=0
2013-11-25 15:43:37.253462 7fdd6a7fc700 10 client.5703 put_inode on 1000000003a.head(ref=4 cap_refs={4096=1,8192=0} open={2=1} mode=102750 size=0 mtime=2013-11-26 00:10:28.056292 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[1000000003a ts 0/0 objects 0 dirty_or_tx 0] parents=0x27a1ba0 0x7fdd60097fa0)
2013-11-25 15:43:37.253511 7fdd7040f700 20 -- 192.168.35.82:0/2376 >> 192.168.35.84:6800/8058 pipe(0x2843850 sd=0 :33572 s=2 pgs=1118592 cs=1 l=1 c=0x2843ab0).writer sleeping
2013-11-25 15:43:37.253521 7fdd6a7fc700 10 -- 192.168.35.82:0/2376 dispatch_throttle_release 119 to dispatch throttler 119/104857600
2013-11-25 15:43:37.253531 7fdd6a7fc700 20 -- 192.168.35.82:0/2376 done calling dispatch on 0x7fdd3c0017d0
2013-11-25 15:43:37.253535 7fdd7484f780 10 client.5703 mark_caps_dirty 1000000003a.head(ref=3 cap_refs={4096=1,8192=0} open={2=1} mode=102750 size=10 mtime=2013-11-26 00:10:28.056292 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) objectset[1000000003a ts 0/0 objects 0 dirty_or_tx 0] parents=0x27a1ba0 0x7fdd60097fa0) - -> Fw
2013-11-25 15:43:37.253572 7fdd7484f780 7 client.5703 wrote to 10, extending file size
2013-11-25 15:43:37.253576 7fdd7484f780 10 client.5703 mark_caps_dirty 1000000003a.head(ref=4 cap_refs={4096=1,8192=0} open={2=1} mode=102750 size=10 mtime=2013-11-25 15:43:37.253576 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) dirty_caps=Fw objectset[1000000003a ts 0/0 objects 0 dirty_or_tx 0] parents=0x27a1ba0 0x7fdd60097fa0) Fw -> Fw
2013-11-25 15:43:37.253608 7fdd7484f780 3 client.5703 ll_write 0x27b5c80 0~10 = 10
2013-11-25 15:43:37.253712 7fdd7484f780 3 client.5703 ll_release 0x27b5c80 1000000003a
2013-11-25 15:43:37.253726 7fdd7484f780 5 client.5703 _release_fh 0x27b5c80 mode 2 on 1000000003a.head(ref=4 cap_refs={4096=0,8192=0} open={2=1} mode=102750 size=10 mtime=2013-11-25 15:43:37.253576 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) dirty_caps=Fw objectset[1000000003a ts 0/0 objects 0 dirty_or_tx 0] parents=0x27a1ba0 0x7fdd60097fa0)
2013-11-25 15:43:37.253781 7fdd7484f780 10 client.5703 _flush 1000000003a.head(ref=4 cap_refs={4096=0,8192=0} open={2=0} mode=102750 size=10 mtime=2013-11-25 15:43:37.253576 caps=pAsxLsXsxFsxcrwb(0=pAsxLsXsxFsxcrwb) dirty_caps=Fw objectset[1000000003a ts 0/0 objects 0 dirty_or_tx 0] parents=0x27a1ba0 0x7fdd60097fa0)
2013-11-25 15:43:37.253812 7fdd7484f780 10 client.5703 nothing to flush
My Log.
client.5705 ll_getxattr 10000000034.head security.capability size 0
2013-11-25 15:46:15.468656 7fb1b37a4780 3 client.5705 _ll_get_inode 10000000034.head
2013-11-25 15:46:15.468660 7fb1b37a4780 10 client.5705 _getattr mask Xs issued=0
2013-11-25 15:46:15.468672 7fb1b37a4780 10 client.5705 _getattr result=0
2013-11-25 15:46:15.468675 7fb1b37a4780 3 client.5705 _getxattr(10000000034, "security.capability", 0) = -61
2013-11-25 15:46:15.468721 7fb1b37a4780 3 client.5705 ll_write 0x31f3730 10000000034 0~10
2013-11-25 15:46:15.468728 7fb1b37a4780 10 client.5705 cur file size is 0
2013-11-25 15:46:15.468735 7fb1b37a4780 10 client.5705 snaprealm snaprealm(10000000034 nref=0 c=0 seq=0 parent=0 my_snaps=[] cached_snapc=0=[])
2013-11-25 15:46:15.468846 7fb1b37a4780 1 -- 192.168.35.82:0/2491 --> 192.168.36.206:6789/0 -- mon_subscribe({mdsmap=0+,monmap=2+,osdmap=39}) v2 -- ?+0 0x3254f10 con 0x31e1e20
2013-11-25 15:46:15.468865 7fb1b37a4780 20 -- 192.168.35.82:0/2491 submit_message mon_subscribe({mdsmap=0+,monmap=2+,osdmap=39}) v2 remote, 192.168.36.206:6789/0, have pipe.
2013-11-25 15:46:15.468894 7fb1b37a4780 1 -- 192.168.35.82:0/2491 --> 192.168.36.206:6789/0 -- mon_get_version(what=osdmap handle=1) v1 -- ?+0 0x3255520 con 0x31e1e20
2013-11-25 15:46:15.468896 7fb1b379c700 10 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).writer: state = open policy.server=0
2013-11-25 15:46:15.468949 7fb1b379c700 20 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).writer encoding 6 features 34359738367 0x3254f10 mon_subscribe({mdsmap=0+,monmap=2+,osdmap=39}) v2
2013-11-25 15:46:15.468992 7fb1b379c700 20 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).writer no session security
2013-11-25 15:46:15.469007 7fb1b379c700 20 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).writer sending 6 0x3254f10
2013-11-25 15:46:15.469019 7fb1b37a4780 20 -- 192.168.35.82:0/2491 submit_message mon_get_version(what=osdmap handle=1) v1 remote, 192.168.36.206:6789/0, have pipe.
2013-11-25 15:46:15.469044 7fb1b379c700 10 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).writer: state = open policy.server=0
2013-11-25 15:46:15.469056 7fb1b379c700 20 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).writer encoding 7 features 34359738367 0x3255520 mon_get_version(what=osdmap handle=1) v1
2013-11-25 15:46:15.469084 7fb1b379c700 20 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).writer no session security
2013-11-25 15:46:15.469094 7fb1b379c700 20 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).writer sending 7 0x3255520
2013-11-25 15:46:15.469114 7fb1b379c700 10 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).writer: state = open policy.server=0
2013-11-25 15:46:15.469124 7fb1b379c700 20 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).writer sleeping
2013-11-25 15:46:15.469953 7fb1b0669700 20 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).reader got ACK
2013-11-25 15:46:15.469978 7fb1b0669700 15 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).reader got ack seq 6
2013-11-25 15:46:15.469989 7fb1b0669700 20 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).reader reading tag...
2013-11-25 15:46:15.470000 7fb1b0669700 20 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).reader got MSG
2013-11-25 15:46:15.470012 7fb1b0669700 20 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).reader got envelope type=21 src mon.0 front=591 data=0 off 0
2013-11-25 15:46:15.470031 7fb1b0669700 10 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).reader wants 591 from dispatch throttler 0/104857600
2013-11-25 15:46:15.470050 7fb1b0669700 20 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).reader got front 591
2013-11-25 15:46:15.470062 7fb1b0669700 10 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).aborted = 0
2013-11-25 15:46:15.470071 7fb1b0669700 20 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).reader got 591 + 0 + 0 byte message
2013-11-25 15:46:15.470088 7fb1b0669700 10 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).No session security set
2013-11-25 15:46:15.470104 7fb1b0669700 10 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).reader got message 9 0x7fb1980023d0 mdsmap(e 82) v1
2013-11-25 15:46:15.470115 7fb1b0669700 20 -- 192.168.35.82:0/2491 queue 0x7fb1980023d0 prio 196
2013-11-25 15:46:15.470131 7fb1b0669700 20 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).reader reading tag...
2013-11-25 15:46:15.470144 7fb1b0669700 20 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).reader got MSG
2013-11-25 15:46:15.470141 7fb1a17fa700 1 -- 192.168.35.82:0/2491 <== mon.0 192.168.36.206:6789/0 9 ==== mdsmap(e 82) v1 ==== 591+0+0 (2957863745 0 0) 0x7fb1980023d0 con 0x31e1e20
2013-11-25 15:46:15.470163 7fb1a17fa700 10 client.5705 CEPH_MSG_MDS_MAP
2013-11-25 15:46:15.470156 7fb1b0669700 20 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).reader got envelope type=16 src mon.0 front=20 data=0 off 0
2013-11-25 15:46:15.470166 7fb1a17fa700 10 -- 192.168.35.82:0/2491 dispatch_throttle_release 591 to dispatch throttler 591/104857600
2013-11-25 15:46:15.470167 7fb1b0669700 10 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).reader wants 20 from dispatch throttler 591/104857600
2013-11-25 15:46:15.470174 7fb1a17fa700 20 -- 192.168.35.82:0/2491 done calling dispatch on 0x7fb1980023d0
2013-11-25 15:46:15.470182 7fb1b0669700 20 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).reader got front 20
2013-11-25 15:46:15.470205 7fb1b0669700 10 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).aborted = 0
2013-11-25 15:46:15.470214 7fb1b0669700 20 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).reader got 20 + 0 + 0 byte message
2013-11-25 15:46:15.470231 7fb1b0669700 10 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).No session security set
2013-11-25 15:46:15.470240 7fb1b0669700 10 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).reader got message 10 0x7fb198003340 mon_subscribe_ack(300s) v1
2013-11-25 15:46:15.470250 7fb1b0669700 20 -- 192.168.35.82:0/2491 queue 0x7fb198003340 prio 196
2013-11-25 15:46:15.470259 7fb1b0669700 20 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).reader reading tag...
2013-11-25 15:46:15.470265 7fb1a17fa700 1 -- 192.168.35.82:0/2491 <== mon.0 192.168.36.206:6789/0 10 ==== mon_subscribe_ack(300s) v1 ==== 20+0+0 (174772310 0 0) 0x7fb198003340 con 0x31e1e20
2013-11-25 15:46:15.470275 7fb1b379c700 10 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).writer: state = open policy.server=0
2013-11-25 15:46:15.470287 7fb1b379c700 10 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).write_ack 10
2013-11-25 15:46:15.470291 7fb1a17fa700 10 -- 192.168.35.82:0/2491 dispatch_throttle_release 20 to dispatch throttler 20/104857600
2013-11-25 15:46:15.470298 7fb1a17fa700 20 -- 192.168.35.82:0/2491 done calling dispatch on 0x7fb198003340
2013-11-25 15:46:15.470299 7fb1b379c700 10 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).writer: state = open policy.server=0
2013-11-25 15:46:15.470309 7fb1b379c700 20 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).writer sleeping
2013-11-25 15:46:15.539041 7fb1b0669700 20 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).reader got ACK
2013-11-25 15:46:15.539063 7fb1b0669700 15 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).reader got ack seq 7
2013-11-25 15:46:15.539073 7fb1b0669700 20 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).reader reading tag...
2013-11-25 15:46:15.539083 7fb1b0669700 20 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).reader got MSG
2013-11-25 15:46:15.539094 7fb1b0669700 20 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).reader got envelope type=20 src mon.0 front=24 data=0 off 0
2013-11-25 15:46:15.539109 7fb1b0669700 10 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).reader wants 24 from dispatch throttler 0/104857600
2013-11-25 15:46:15.539124 7fb1b0669700 20 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).reader got front 24
2013-11-25 15:46:15.539136 7fb1b0669700 10 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).aborted = 0
2013-11-25 15:46:15.539144 7fb1b0669700 20 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).reader got 24 + 0 + 0 byte message
2013-11-25 15:46:15.539155 7fb1b0669700 10 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).No session security set
2013-11-25 15:46:15.539167 7fb1b0669700 10 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).reader got message 11 0x7fb1980044d0 mon_check_map_ack(handle=1 version=38) v2
2013-11-25 15:46:15.539177 7fb1b0669700 20 -- 192.168.35.82:0/2491 queue 0x7fb1980044d0 prio 196
2013-11-25 15:46:15.539187 7fb1b0669700 20 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).reader reading tag...
2013-11-25 15:46:15.539192 7fb1a17fa700 1 -- 192.168.35.82:0/2491 <== mon.0 192.168.36.206:6789/0 11 ==== mon_check_map_ack(handle=1 version=38) v2 ==== 24+0+0 (4174327601 0 0) 0x7fb1980044d0 con 0x31e1e20
2013-11-25 15:46:15.539201 7fb1b379c700 10 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).writer: state = open policy.server=0
2013-11-25 15:46:15.539213 7fb1b379c700 10 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).write_ack 11
2013-11-25 15:46:15.539223 7fb1b379c700 10 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).writer: state = open policy.server=0
2013-11-25 15:46:15.539220 7fb1a17fa700 10 -- 192.168.35.82:0/2491 dispatch_throttle_release 24 to dispatch throttler 24/104857600
2013-11-25 15:46:15.539238 7fb1a17fa700 20 -- 192.168.35.82:0/2491 done calling dispatch on 0x7fb1980044d0
2013-11-25 15:46:15.539234 7fb1b379c700 20 -- 192.168.35.82:0/2491 >> 192.168.36.206:6789/0 pipe(0x31e1bc0 sd=5 :45579 s=2 pgs=12 cs=1 l=1 c=0x31e1e20).writer sleeping
2013-11-25 15:46:15.539280 7fb1a8ff9700 15 client.5705 sync_write_commit unsafe_sync_write = 0
2013-11-25 15:46:15.539333 7fb1a8ff9700 10 client.5705 put_inode on 10000000034.head(ref=4 cap_refs={} open={2=1} mode=102450 size=0 mtime=2013-11-25 15:46:15.468439 caps=- objectset[10000000034 ts 1/18446744073709551615 objects 0 dirty_or_tx 0] parents=0x31d4ba0 0x3253480)
2013-11-25 15:46:15.539383 7fb1a8ff9700 10 client.5705 put_inode left 3
2013-11-25 15:46:15.539412 7fb1b37a4780 7 client.5705 wrote to 10, extending file size
2013-11-25 15:46:15.539423 7fb1b37a4780 3 client.5705 ll_write 0x31f3730 0~10 = 10
2013-11-25 15:46:15.539525 7fb1b37a4780 3 client.5705 ll_release 0x31f3730 10000000034
2013-11-25 15:46:15.539530 7fb1b37a4780 5 client.5705 _release_fh 0x31f3730 mode 2 on 10000000034.head(ref=3 cap_refs={} open={2=1} mode=102450 size=10 mtime=2013-11-25 15:46:15.539420 caps=- objectset[10000000034 ts 1/18446744073709551615 objects 0 dirty_or_tx 0] parents=0x31d4ba0 0x3253480)
2013-11-25 15:46:15.539550 7fb1b37a4780 10 client.5705 _flush 10000000034.head(ref=3 cap_refs={} open={2=0} mode=102450 size=10 mtime=2013-11-25 15:46:15.539420 caps=- objectset[10000000034 ts 1/18446744073709551615 objects 0 dirty_or_tx 0] parents=0x31d4ba0 0x3253480)
2013-11-25 15:46:15.539563 7fb1b37a4780 10 client.5705 nothing to flush
-----Original Message-----
From: Gregory Farnum [mailto:greg@xxxxxxxxxxx]
Sent: Monday, 25 November, 2013 2:22 PM
To: Luo Shaobo (DSI)
Cc: ceph-devel@xxxxxxxxxxxxxxx
Subject: Re: How to use the class Filer in Ceph
I haven't looked at the Filer code (or anything around it) in a while, but if I were to guess, "in->snapid" is set to something which doesn't exist.
Are you actually using the Filer in some new code that includes inodes, or modifying the Client classes? Looking at how they initialize things should help you through this.
Also, you could turn on messenger debugging to see exactly what your program is sending to the OSDs and check if that looks right (and, if necessary, turn on OSD debugging and see what's making it decide ENOENT).
-Greg
Software Engineer #42 @ http://inktank.com | http://ceph.com
On Thu, Nov 21, 2013 at 9:30 PM, Luo Shaobo (DSI) <luosb@xxxxxxxxxxxxxxxxx> wrote:
> Dear All,
>
> Currently, I’m using the class Filer to operate the OSD directly. And below list the codes.
> The write_trunc routing return success, but I can’t read back the object, and I got r = -2, -ENOENT.
> Would anyone help me to answer the question that how to use those functions? Thanks!
>
> The input parameters are:
> in->ino = 0x10000000035;
> In->layout.fl_stripe_unit = stripe_unit = 4194304;
> In->layout.fl_stripe_count = stripe_count = 1; layout.fl_object_size =
> In->object_size = 4194304; layout.fl_pg_pool = 0;
> in->snaprealm = new SnapRealm(in->ino);
> in->snaprealm->build_snap_context();
>
> The writing code looks like this.
> Mutex flock("MClient::_write flock");
> Cond cond;
> bool done = false;
> Context *onfinish = new C_SafeCond(&flock, &cond, &done);
> Context *onsafe = new C_Client_SyncCommit(this, in);
>
> unsafe_sync_write++;
> get_cap_ref(in, CEPH_CAP_FILE_BUFFER); // released by onsafe
> callback
>
> r = filer->write_trunc(in->ino, &in->layout, in->snaprealm->get_snap_context(),
> offset, size, bl, ceph_clock_now(cct), 0,
> in->truncate_size, in->truncate_seq,
> onfinish, onsafe);
> if (r < 0)
> goto done;
>
> client_lock.Unlock();
> flock.Lock();
> while (!done)
> cond.Wait(flock);
> flock.Unlock();
>
> The reading code looks like this.
>
> Mutex flock("MClient::_read_sync flock"); bool done = false;
> Context *onfinish = new C_SafeCond(&flock, &cond, &done, &r);
> bufferlist tbl;
>
> int wanted = left;
> filer->read_trunc(in->ino, &in->layout, in->snapid,
> pos, left, &tbl, 0,
> in->truncate_size, in->truncate_seq,
> onfinish);
> client_lock.Unlock();
> flock.Lock();
> while (!done)
> cond.Wait(flock);
> flock.Unlock();
>
> Thomas
________________________________
This email and any attachments are confidential and may be privileged. If you are not the intended recipient, please delete it and notify us immediately. Please do not copy or use it for any purpose, or disclose its contents to any other person. This email does not constitute a contract offer, a contract amendment, or an acceptance of a contract offer. Thank you.
��.n��������+%������w��{.n����z��u���ܨ}���Ơz�j:+v�����w����ޙ��&�)ߡ�a����z�ޗ���ݢj��w�f
