|
2021-05-02T21:01:03.331+0800 7fc4a7d83700 1 -- [v2:127.0.0.1:6810/17116,v1:127.0.0.1:6811/17116] <== client.4397 127.0.0.1:0/233630719 3 ==== osd_op(client.4397.0:5 4.f 4.1eaca32f (undecoded) ondisk+retry+read+known_if_redirected e71) v8 ==== 233+0+0 (crc 0 0 0) 0x55f2bf047180 con 0x55f2af89d400
|
|
2021-05-02T21:01:03.331+0800 7fc4a7d83700 15 osd.1 71 enqueue_op 0x55f2becedce0 prio 63 type 42 cost 0 latency 0.000032 epoch 71 osd_op(client.4397.0:5 4.f 4.1eaca32f (undecoded) ondisk+retry+read+known_if_redirected e71) v8
|
|
2021-05-02T21:01:03.331+0800 7fc4a7d83700 20 osd.1 op_wq(0) _enqueue OpSchedulerItem(4.f PGOpItem(op=osd_op(client.4397.0:5 4.f 4.1eaca32f (undecoded) ondisk+retry+read+known_if_redirected e71) v8) prio 63 cost 0 e71)
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 20 osd.1 op_wq(0) _process 4.f to_process <> waiting <> waiting_peering {}
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 20 osd.1 op_wq(0) _process OpSchedulerItem(4.f PGOpItem(op=osd_op(client.4397.0:5 4.f 4.1eaca32f (undecoded) ondisk+retry+read+known_if_redirected e71) v8) prio 63 cost 0 e71) queued
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 20 osd.1 op_wq(0) _process 4.f to_process <OpSchedulerItem(4.f PGOpItem(op=osd_op(client.4397.0:5 4.f 4.1eaca32f (undecoded) ondisk+retry+read+known_if_redirected e71) v8) prio 63 cost 0 e71)> waiting <> waiting_peering {}
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 20 osd.1 op_wq(0) _process OpSchedulerItem(4.f PGOpItem(op=osd_op(client.4397.0:5 4.f 4.1eaca32f (undecoded) ondisk+retry+read+known_if_redirected e71) v8) prio 63 cost 0 e71) pg 0x55f2afb30000
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 10 osd.1 71 dequeue_op 0x55f2becedce0 prio 63 cost 0 latency 0.000105 osd_op(client.4397.0:5 4.f 4.1eaca32f (undecoded) ondisk+retry+read+known_if_redirected e71) v8 pg pg[4.f( v 25'2 (0'0,25'2] local-lis/les=24/25 n=2 ec=24/24 lis/c=24/24 les/c/f=25/25/0 sis=24) [1,2,0] r=0 lpr=24 crt=25'2 lcod 25'1 mlcod 25'1 active+clean]
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 10 osd.1 pg_epoch: 71 pg[4.f( v 25'2 (0'0,25'2] local-lis/les=24/25 n=2 ec=24/24 lis/c=24/24 les/c/f=25/25/0 sis=24) [1,2,0] r=0 lpr=24 crt=25'2 lcod 25'1 mlcod 25'1 active+clean] _handle_message: 0x55f2becedce0
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 20 osd.1 pg_epoch: 71 pg[4.f( v 25'2 (0'0,25'2] local-lis/les=24/25 n=2 ec=24/24 lis/c=24/24 les/c/f=25/25/0 sis=24) [1,2,0] r=0 lpr=24 crt=25'2 lcod 25'1 mlcod 25'1 active+clean] do_op: op osd_op(client.4397.0:5 4.f 4:f4c53578:::zonegroups_names.default:head [read 0~0] snapc 0=[] RETRY=1 ondisk+retry+read+known_if_redirected e71) v8
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 20 osd.1 pg_epoch: 71 pg[4.f( v 25'2 (0'0,25'2] local-lis/les=24/25 n=2 ec=24/24 lis/c=24/24 les/c/f=25/25/0 sis=24) [1,2,0] r=0 lpr=24 crt=25'2 lcod 25'1 mlcod 25'1 active+clean] op_has_sufficient_caps session=0x55f2af919e00 pool=4 (.rgw.root ) pool_app_metadata={rgw={}} need_read_cap=1 need_write_cap=0 classes=[] -> yes
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 10 osd.1 pg_epoch: 71 pg[4.f( v 25'2 (0'0,25'2] local-lis/les=24/25 n=2 ec=24/24 lis/c=24/24 les/c/f=25/25/0 sis=24) [1,2,0] r=0 lpr=24 crt=25'2 lcod 25'1 mlcod 25'1 active+clean] do_op osd_op(client.4397.0:5 4.f 4:f4c53578:::zonegroups_names.default:head [read 0~0] snapc 0=[] RETRY=1 ondisk+retry+read+known_if_redirected e71) v8 may_read -> read-ordered flags ondisk+retry+read+known_if_redirected
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 10 osd.1 pg_epoch: 71 pg[4.f( v 25'2 (0'0,25'2] local-lis/les=24/25 n=2 ec=24/24 lis/c=24/24 les/c/f=25/25/0 sis=24) [1,2,0] r=0 lpr=24 crt=25'2 lcod 25'1 mlcod 25'1 active+clean] get_object_context: found obc in cache: 0x55f2af8322c0
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 10 osd.1 pg_epoch: 71 pg[4.f( v 25'2 (0'0,25'2] local-lis/les=24/25 n=2 ec=24/24 lis/c=24/24 les/c/f=25/25/0 sis=24) [1,2,0] r=0 lpr=24 crt=25'2 lcod 25'1 mlcod 25'1 active+clean] get_object_context: 0x55f2af8322c0 4:f4c53578:::zonegroups_names.default:head rwstate(none n=0 w=0) oi: 4:f4c53578:::zonegroups_names.default:head(25'2 client.4325.0:82 dirty|data_digest s 46 uv 2 dd a7f21d3f alloc_hint [0 0 0]) exists: 1 ssc: 0x55f2be7a9ce0 snapset: 0=[]:{}
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 10 osd.1 pg_epoch: 71 pg[4.f( v 25'2 (0'0,25'2] local-lis/les=24/25 n=2 ec=24/24 lis/c=24/24 les/c/f=25/25/0 sis=24) [1,2,0] r=0 lpr=24 crt=25'2 lcod 25'1 mlcod 25'1 active+clean] find_object_context 4:f4c53578:::zonegroups_names.default:head @head oi=4:f4c53578:::zonegroups_names.default:head(25'2 client.4325.0:82 dirty|data_digest s 46 uv 2 dd a7f21d3f alloc_hint [0 0 0])
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 20 osd.1 pg_epoch: 71 pg[4.f( v 25'2 (0'0,25'2] local-lis/les=24/25 n=2 ec=24/24 lis/c=24/24 les/c/f=25/25/0 sis=24) [1,2,0] r=0 lpr=24 crt=25'2 lcod 25'1 mlcod 25'1 active+clean] maybe_handle_manifest_detail: 4:f4c53578:::zonegroups_names.default:head is not manifest object
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 20 osd.1 pg_epoch: 71 pg[4.f( v 25'2 (0'0,25'2] local-lis/les=24/25 n=2 ec=24/24 lis/c=24/24 les/c/f=25/25/0 sis=24) [1,2,0] r=0 lpr=24 crt=25'2 lcod 25'1 mlcod 25'1 active+clean] do_op obc obc(4:f4c53578:::zonegroups_names.default:head rwstate(read n=1 w=0))
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 10 osd.1 pg_epoch: 71 pg[4.f( v 25'2 (0'0,25'2] local-lis/les=24/25 n=2 ec=24/24 lis/c=24/24 les/c/f=25/25/0 sis=24) [1,2,0] r=0 lpr=24 crt=25'2 lcod 25'1 mlcod 25'1 active+clean] execute_ctx 0x55f2be956d00
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 10 osd.1 pg_epoch: 71 pg[4.f( v 25'2 (0'0,25'2] local-lis/les=24/25 n=2 ec=24/24 lis/c=24/24 les/c/f=25/25/0 sis=24) [1,2,0] r=0 lpr=24 crt=25'2 lcod 25'1 mlcod 25'1 active+clean] execute_ctx 4:f4c53578:::zonegroups_names.default:head [read 0~0] ov 25'2
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 10 osd.1 pg_epoch: 71 pg[4.f( v 25'2 (0'0,25'2] local-lis/les=24/25 n=2 ec=24/24 lis/c=24/24 les/c/f=25/25/0 sis=24) [1,2,0] r=0 lpr=24 crt=25'2 lcod 25'1 mlcod 25'1 active+clean] do_osd_op 4:f4c53578:::zonegroups_names.default:head [read 0~0]
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 10 osd.1 pg_epoch: 71 pg[4.f( v 25'2 (0'0,25'2] local-lis/les=24/25 n=2 ec=24/24 lis/c=24/24 les/c/f=25/25/0 sis=24) [1,2,0] r=0 lpr=24 crt=25'2 lcod 25'1 mlcod 25'1 active+clean] do_osd_op read 0~0
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 20 osd.1 pg_epoch: 71 pg[4.f( v 25'2 (0'0,25'2] local-lis/les=24/25 n=2 ec=24/24 lis/c=24/24 les/c/f=25/25/0 sis=24) [1,2,0] r=0 lpr=24 crt=25'2 lcod 25'1 mlcod 25'1 active+clean] do_read
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 15 bluestore(/home/wzl/ceph/build/dev/osd1) read 4.f_head #4:f4c53578:::zonegroups_names.default:head# 0x0~2e
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 20 _pin0x55f2ad54a000 #4:f4c53578:::zonegroups_names.default:head# pinned
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 20 bluestore(/home/wzl/ceph/build/dev/osd1) _do_read 0x0~2e size 0x2e (46)
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 20 bluestore(/home/wzl/ceph/build/dev/osd1) _do_read defaulting to buffered read
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 20 bluestore(/home/wzl/ceph/build/dev/osd1) _read_cache blob Blob(0x55f2be7411f0 blob([0x41000~1000] csum crc32c/0x1000) use_tracker(0x1000 0x2e) SharedBlob(0x55f2be741260 sbid 0x0)) need 0x0~2e cache has 0x[0~2e]
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 20 _unpin0x55f2ad54a000 #4:f4c53578:::zonegroups_names.default:head# unpinned
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 10 bluestore(/home/wzl/ceph/build/dev/osd1) read 4.f_head #4:f4c53578:::zonegroups_names.default:head# 0x0~2e = 46
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 10 osd.1 pg_epoch: 71 pg[4.f( v 25'2 (0'0,25'2] local-lis/les=24/25 n=2 ec=24/24 lis/c=24/24 les/c/f=25/25/0 sis=24) [1,2,0] r=0 lpr=24 crt=25'2 lcod 25'1 mlcod 25'1 active+clean] read got 46 / 46 bytes from obj 4:f4c53578:::zonegroups_names.default:head
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 20 osd.1 pg_epoch: 71 pg[4.f( v 25'2 (0'0,25'2] local-lis/les=24/25 n=2 ec=24/24 lis/c=24/24 les/c/f=25/25/0 sis=24) [1,2,0] r=0 lpr=24 crt=25'2 lcod 25'1 mlcod 25'1 active+clean] execute_ctx alloc reply 0x55f2afab8000 result 0
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 15 osd.1 pg_epoch: 71 pg[4.f( v 25'2 (0'0,25'2] local-lis/les=24/25 n=2 ec=24/24 lis/c=24/24 les/c/f=25/25/0 sis=24) [1,2,0] r=0 lpr=24 crt=25'2 lcod 25'1 mlcod 25'1 active+clean] do_osd_op_effects client.4397 con 0x55f2af89d400
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 15 osd.1 pg_epoch: 71 pg[4.f( v 25'2 (0'0,25'2] local-lis/les=24/25 n=2 ec=24/24 lis/c=24/24 les/c/f=25/25/0 sis=24) [1,2,0] r=0 lpr=24 crt=25'2 lcod 25'1 mlcod 25'1 active+clean] log_op_stats osd_op(client.4397.0:5 4.f 4:f4c53578:::zonegroups_names.default:head [read 0~46 out=46b] snapc 0=[] RETRY=1 ondisk+retry+read+known_if_redirected e71) v8 inb 0 outb 46 lat 0.000458
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 20 osd.1 pg_epoch: 71 pg[4.f( v 25'2 (0'0,25'2] local-lis/les=24/25 n=2 ec=24/24 lis/c=24/24 les/c/f=25/25/0 sis=24) [1,2,0] r=0 lpr=24 crt=25'2 lcod 25'1 mlcod 25'1 active+clean] prepare_stats_for_publish reporting purged_snaps []
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 15 osd.1 pg_epoch: 71 pg[4.f( v 25'2 (0'0,25'2] local-lis/les=24/25 n=2 ec=24/24 lis/c=24/24 les/c/f=25/25/0 sis=24) [1,2,0] r=0 lpr=24 crt=25'2 lcod 25'1 mlcod 25'1 active+clean] publish_stats_to_osd 71:79
|
|
2021-05-02T21:01:03.331+0800 7fc48ea8e700 1 -- [v2:127.0.0.1:6810/17116,v1:127.0.0.1:6811/17116] --> 127.0.0.1:0/233630719 -- osd_op_reply(5 zonegroups_names.default [read 0~46 out=46b] v0'0 uv2 ondisk = 0) v8 -- 0x55f2afab8000 con 0x55f2af89d400
|