Project

General

Profile

Bug #1874 » osd0.log

osd0 log section for tid 3705 - David McBride, 01/04/2012 03:27 AM

 
-- 146.169.3.15:6801/3830 <== client.4128 146.169.6.14:0/2607773536 90 ==== osd_op(client.4128.1:3705 1000000007e.00000012 [read 3891200~303104 [1@-1]] 0.6e114bf3) ==== 128+0+0 (2071135576 0 0) 0x218bd80 con 0x228ec80
Jan 4 10:59:29 terra15 osd.0[3831]: 7f0986c64700 osd.0 368 _dispatch 0x218bd80 osd_op(client.4128.1:3705 1000000007e.00000012 [read 3891200~303104 [1@-1]] 0.6e114bf3)
Jan 4 10:59:29 terra15 osd.0[3831]: 7f0986c64700 osd.0 368 require_same_or_newer_map 368 (i am 368) 0x218bd80
Jan 4 10:59:29 terra15 osd.0[3831]: 7f0986c64700 osd.0 368 _share_map_incoming client.4128 146.169.6.14:0/2607773536 368
Jan 4 10:59:29 terra15 osd.0[3831]: 7f0986c64700 osd.0 368 pg[0.f3( v 224'1476 (59'1470,224'1476] n=1474 ec=1 les/c 367/368 342/342/329) [0,3,2] r=0 lpr=342 lcod 0'0 mlcod 0'0 !hml active+clean] enqueue_op 0x218bd80 osd_op(client.4128.1:3705 1000000007e.00000012 [read 3891200~303104 [1@-1]] 0.6e114bf3)
Jan 4 10:59:29 terra15 osd.0[3831]: 7f0986c64700 osd.0 368 op_has_sufficient_caps pool=0 (data) owner=0 perm=7 may_read=1 may_write=0 may_exec=0 require_exec_caps=0
Jan 4 10:59:29 terra15 osd.0[3831]: 7f0983b5d700 osd.0 368 dequeue_op osd_op(client.4128.1:3705 1000000007e.00000012 [read 3891200~303104 [1@-1]] 0.6e114bf3) pg pg[0.f3( v 224'1476 (59'1470,224'1476] n=1474 ec=1 les/c 367/368 342/342/329) [0,3,2] r=0 lpr=342 lcod 0'0 mlcod 0'0 !hml active+clean]
Jan 4 10:59:29 terra15 osd.0[3831]: 7f0983b5d700 osd.0 368 _share_map_outgoing osd.3 146.169.3.18:6801/32131 already has epoch 368
Jan 4 10:59:29 terra15 osd.0[3831]: 7f0983b5d700 osd.0 368 _share_map_outgoing osd.2 146.169.3.17:6802/21383 already has epoch 368
Jan 4 10:59:29 terra15 osd.0[3831]: 7f0983b5d700 osd.0 368 pg[0.f3( v 224'1476 (59'1470,224'1476] n=1474 ec=1 les/c 367/368 342/342/329) [0,3,2] r=0 lpr=342 lcod 0'0 mlcod 0'0 !hml active+clean] do_op osd_op(client.4128.1:3705 1000000007e.00000012 [read 3891200~303104 [1@-1]] 0.6e114bf3)
Jan 4 10:59:29 terra15 osd.0[3831]: 7f0983b5d700 filestore(/data/osd) getattr 0.f3_head/1000000007e.00000012/head/6e114bf3 '_'
Jan 4 10:59:29 terra15 osd.0[3831]: 7f0983b5d700 filestore(/data/osd) getattr 0.f3_head/1000000007e.00000012/head/6e114bf3 '_' = 181
Jan 4 10:59:29 terra15 osd.0[3831]: 7f0983b5d700 osd.0 368 pg[0.f3( v 224'1476 (59'1470,224'1476] n=1474 ec=1 les/c 367/368 342/342/329) [0,3,2] r=0 lpr=342 lcod 0'0 mlcod 0'0 !hml active+clean] get_object_context 1000000007e.00000012/head/6e114bf3 read 1000000007e.00000012/head/6e114bf3(9'3 client.4112.1:485 wrlock_by=unknown.0.0:0)
Jan 4 10:59:29 terra15 osd.0[3831]: 7f0983b5d700 osd.0 368 pg[0.f3( v 224'1476 (59'1470,224'1476] n=1474 ec=1 les/c 367/368 342/342/329) [0,3,2] r=0 lpr=342 lcod 0'0 mlcod 0'0 !hml active+clean] find_object_context 1000000007e.00000012/head/6e114bf3 @head
Jan 4 10:59:29 terra15 osd.0[3831]: 7f0983b5d700 osd.0 368 pg[0.f3( v 224'1476 (59'1470,224'1476] n=1474 ec=1 les/c 367/368 342/342/329) [0,3,2] r=0 lpr=342 lcod 0'0 mlcod 0'0 !hml active+clean] do_op mode is idle(wr=0)
Jan 4 10:59:29 terra15 osd.0[3831]: 7f0983b5d700 osd.0 368 pg[0.f3( v 224'1476 (59'1470,224'1476] n=1474 ec=1 les/c 367/368 342/342/329) [0,3,2] r=0 lpr=342 lcod 0'0 mlcod 0'0 !hml active+clean] do_op mode now idle(wr=0)
Jan 4 10:59:29 terra15 osd.0[3831]: 7f0983b5d700 osd.0 368 pg[0.f3( v 224'1476 (59'1470,224'1476] n=1474 ec=1 les/c 367/368 342/342/329) [0,3,2] r=0 lpr=342 lcod 0'0 mlcod 0'0 !hml active+clean] do_op 1000000007e.00000012/head/6e114bf3 [read 3891200~303104 [1@-1]] ov 9'3
Jan 4 10:59:29 terra15 osd.0[3831]: 7f0983b5d700 osd.0 368 pg[0.f3( v 224'1476 (59'1470,224'1476] n=1474 ec=1 les/c 367/368 342/342/329) [0,3,2] r=0 lpr=342 lcod 0'0 mlcod 0'0 !hml active+clean] taking ondisk_read_lock
Jan 4 10:59:29 terra15 osd.0[3831]: 7f0983b5d700 osd.0 368 pg[0.f3( v 224'1476 (59'1470,224'1476] n=1474 ec=1 les/c 367/368 342/342/329) [0,3,2] r=0 lpr=342 lcod 0'0 mlcod 0'0 !hml active+clean] do_osd_op 1000000007e.00000012/head/6e114bf3 [read 3891200~303104 [1@-1]]
Jan 4 10:59:29 terra15 osd.0[3831]: 7f0983b5d700 osd.0 368 pg[0.f3( v 224'1476 (59'1470,224'1476] n=1474 ec=1 les/c 367/368 342/342/329) [0,3,2] r=0 lpr=342 lcod 0'0 mlcod 0'0 !hml active+clean] do_osd_op read 3891200~303104 [1@-1]
Jan 4 10:59:29 terra15 osd.0[3831]: 7f0983b5d700 filestore(/data/osd) read 0.f3_head/1000000007e.00000012/head/6e114bf3 3891200~303104
Jan 4 10:59:29 terra15 osd.0[3831]: 7f0983b5d700 filestore(/data/osd) FileStore::read 0.f3_head/1000000007e.00000012/head/6e114bf3 3891200~303104/303104
Jan 4 10:59:29 terra15 osd.0[3831]: 7f0983b5d700 osd.0 368 pg[0.f3( v 224'1476 (59'1470,224'1476] n=1474 ec=1 les/c 367/368 342/342/329) [0,3,2] r=0 lpr=342 lcod 0'0 mlcod 0'0 !hml active+clean] read got 303104 / 303104 bytes from obj 1000000007e.00000012/head/6e114bf3
Jan 4 10:59:29 terra15 osd.0[3831]: 7f0983b5d700 osd.0 368 pg[0.f3( v 224'1476 (59'1470,224'1476] n=1474 ec=1 les/c 367/368 342/342/329) [0,3,2] r=0 lpr=342 lcod 0'0 mlcod 0'0 !hml active+clean] dropping ondisk_read_lock
Jan 4 10:59:29 terra15 osd.0[3831]: 7f0983b5d700 osd.0 368 pg[0.f3( v 224'1476 (59'1470,224'1476] n=1474 ec=1 les/c 367/368 342/342/329) [0,3,2] r=0 lpr=342 lcod 0'0 mlcod 0'0 !hml active+clean] log_op_stats osd_op(client.4128.1:3705 1000000007e.00000012 [read 3891200~303104 [1@-1]] 0.6e114bf3) inb 0 outb 303104 rlat 0.000000 lat 0.006850
Jan 4 10:59:29 terra15 osd.0[3831]: 7f0983b5d700 -- 146.169.3.15:6801/3830 --> 146.169.6.14:0/2607773536 -- osd_op_reply(3705 1000000007e.00000012 [read 3891200~303104 [1@-1]] = 0) v1 -- ?+303104 0x2058540 con 0x228ec80
Jan 4 10:59:29 terra15 osd.0[3831]: 7f0983b5d700 osd.0 368 pg[0.f3( v 224'1476 (59'1470,224'1476] n=1474 ec=1 les/c 367/368 342/342/329) [0,3,2] r=0 lpr=342 lcod 0'0 mlcod 0'0 !hml active+clean] put_object_context 1000000007e.00000012/head/6e114bf3 1 -> 0
Jan 4 10:59:29 terra15 osd.0[3831]: 7f0983b5d700 osd.0 368 dequeue_op 0x218bd80 finish

(1-1/2)