Project

General

Profile

Actions
Copy link

Bug #56503

open

Deleting large (~850gb) objects causes OSD to crash

Added by Marcin Gibula almost 2 years ago. Updated over 1 year ago.

Status:
New
Priority:
Normal
Assignee:
-
Target version:
-
% Done:

0%

Source:
Community (user)
Tags:
Backport:
Regression:
No
Severity:
2 - major
Reviewed:
Affected Versions:
Ceph - v16.2.9
ceph-qa-suite:
Pull request ID:
Crash signature (v1):
Crash signature (v2):

Description

After deleting large S3 object - around 850GB in size, OSDs in our cluster started becaming laggy, unresponsive and eventually suiciding.
We've managed to reproduce this by following steps:

1. Upload large object
2. Delete it
3. Run radosgw-admin gc list (or gc process)

After that, OSDs that are storing .rgw.gc pool become unstable and eventually crash.

ceph version 16.2.9 (4c3647a322c0ff5a1dd2344e039859dcbd28c830) pacific (stable)
 1: /lib/x86_64-linux-gnu/libpthread.so.0(+0x12980) [0x7f8daa3d0980]
 2: pthread_kill()
 3: (ceph::HeartbeatMap::_check(ceph::heartbeat_handle_d const*, char const*, std::chrono::time_point<ceph::coarse_mono_clock, std::chrono::duration<unsigned long, std::ratio<1l, 1000000000l> > >)+0x472) [0x55943ed4cb02]
 4: (ceph::HeartbeatMap::reset_timeout(ceph::heartbeat_handle_d*, std::chrono::duration<unsigned long, std::ratio<1l, 1000000000l> >, std::chrono::duration<unsigned long, std::ratio<1l, 1000000000l> >)+0x72) [0x55943ed4d2a2]
 5: (ShardedThreadPool::shardedthreadpool_worker(unsigned int)+0x498) [0x55943ed72748]
 6: (ShardedThreadPool::WorkThreadSharded::entry()+0x10) [0x55943ed75c20]
 7: /lib/x86_64-linux-gnu/libpthread.so.0(+0x76db) [0x7f8daa3c56db]
 8: clone()
 NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

When running with debug_osd=10, there are lots and lots of messages like this:

2022-07-08T11:21:05.647+0200 7f57b18a5700 10 osd.0 pg_epoch: 782299 pg[14.2( v 782289'638107506 (778682'638104180,782289'638107506] local-lis/les=782298/782299 n=928 ec=36/36 lis/c=782298/782286 les/c/f=782299/782287/0 sis=782298) [0,160] r=0 lpr=782298 pi=[782286,782298)/3 crt=782289'638107506 lcod 782274'638107504 mlcod 0'0 active+undersized+degraded mbc={}] read got 1024 / 1024 bytes from obj 14:4ee803b6:::gc.21:head
2022-07-08T11:21:05.651+0200 7f57b18a5700 10 osd.0 pg_epoch: 782299 pg[14.2( v 782289'638107506 (778682'638104180,782289'638107506] local-lis/les=782298/782299 n=928 ec=36/36 lis/c=782298/782286 les/c/f=782299/782287/0 sis=782298) [0,160] r=0 lpr=782298 pi=[782286,782298)/3 crt=782289'638107506 lcod 782274'638107504 mlcod 0'0 active+undersized+degraded mbc={}] do_osd_op 14:4ee803b6:::gc.21:head [sync_read 80662864~1024]
2022-07-08T11:21:05.651+0200 7f57b18a5700 10 osd.0 pg_epoch: 782299 pg[14.2( v 782289'638107506 (778682'638104180,782289'638107506] local-lis/les=782298/782299 n=928 ec=36/36 lis/c=782298/782286 les/c/f=782299/782287/0 sis=782298) [0,160] r=0 lpr=782298 pi=[782286,782298)/3 crt=782289'638107506 lcod 782274'638107504 mlcod 0'0 active+undersized+degraded mbc={}] do_osd_op sync_read 80662864~1024
2022-07-08T11:21:05.651+0200 7f57b18a5700 10 osd.0 pg_epoch: 782299 pg[14.2( v 782289'638107506 (778682'638104180,782289'638107506] local-lis/les=782298/782299 n=928 ec=36/36 lis/c=782298/782286 les/c/f=782299/782287/0 sis=782298) [0,160] r=0 lpr=782298 pi=[782286,782298)/3 crt=782289'638107506 lcod 782274'638107504 mlcod 0'0 active+undersized+degraded mbc={}] read got 1024 / 1024 bytes from obj 14:4ee803b6:::gc.21:head
2022-07-08T11:21:05.651+0200 7f57d08e3700 10 osd.0 782301 internal heartbeat not healthy, dropping ping request
2022-07-08T11:21:05.651+0200 7f57d00e2700 10 osd.0 782301 internal heartbeat not healthy, dropping ping request

Actions
Copy link
 #1

Updated by Marcin Gibula almost 2 years ago

And here is dump_ops_in_flight from one of the OSDs. This OSD has block.db on SSD by the way. As you can see this single op executes for over two minutes and during this time, OSD seems to be unresponsive.

  1. ceph daemon /var/run/ceph/ceph-osd.128.asok dump_ops_in_flight {
    "ops": [ {
    "description": "osd_op(client.1923390230.0:120 14.2 14:4ee803b6:::gc.21:head [call rgw_gc.rgw_gc_queue_list_entries in=46b] snapc 0=[] ondisk+read+known_if_redirected e782347)",
    "initiated_at": "2022-07-08T11:40:49.941841+0200",
    "age": 126.413930776,
    "duration": 126.413979579,
    "type_data": {
    "flag_point": "started",
    "client_info": {
    "client": "client.1923390230",
    "client_addr": "192.168.4.5:0/2884874510",
    "tid": 120
    },
    "events": [ {
    "event": "initiated",
    "time": "2022-07-08T11:40:49.941841+0200",
    "duration": 0
    }, {
    "event": "throttled",
    "time": "2022-07-08T11:40:49.941841+0200",
    "duration": 4294967295.9999981
    }, {
    "event": "header_read",
    "time": "2022-07-08T11:40:49.941839+0200",
    "duration": 7.8180000000000004e-06
    }, {
    "event": "all_read",
    "time": "2022-07-08T11:40:49.941847+0200",
    "duration": 7.4900000000000005e-07
    }, {
    "event": "dispatched",
    "time": "2022-07-08T11:40:49.941848+0200",
    "duration": 2.2879999999999999e-06
    }, {
    "event": "queued_for_pg",
    "time": "2022-07-08T11:40:49.941850+0200",
    "duration": 1.7442e-05
    }, {
    "event": "reached_pg",
    "time": "2022-07-08T11:40:49.941867+0200",
    "duration": 1.4905e-05
    }, {
    "event": "started",
    "time": "2022-07-08T11:40:49.941882+0200",
    "duration": 4.1517999999999998e-05
    }
    ]
    }
    }
    ],
    "num_ops": 1
    }
Actions
Copy link
 #2

Updated by Casey Bodley almost 2 years ago

  • Project changed from rgw to RADOS
Actions
Copy link
 #3

Updated by Radoslaw Zarzynski over 1 year ago

Do you have logs with debug_bluestore=20 maybe?

Mark, can this be related to the RocksDB's tombstones issues?

Actions
Copy link
 #4

Updated by Marcin Gibula over 1 year ago

Ok, I'll try to reproduce this

Actions
Copy link
 #5

Updated by Igor Fedotov over 1 year ago

Radoslaw Zarzynski wrote:

Do you have logs with debug_bluestore=20 maybe?

Mark, can this be related to the RocksDB's tombstones issues?

I'm pretty sure it is.

Actions
Copy link
 #6

Updated by Marcin Gibula over 1 year ago

Ok,
so here's what I did:
1. I moved .rgw.gc pool to different crush tree to isolate affected OSDs
2. I increased osd_heartbeat_grace to 180 to prevent them being marked as down.
3. I uploaded 850GB object via S3 radosgw and deleted it.
4. After deletion, I executed 'radosgw-admin gc list'. Without increased osd_heartbeat_grace that would be enough to mark osd as down.

I did set debug_bluestore=20 before that, and log is full of entries like below, the entire file has over 100MB. Is there any procedure for uploading such files here?

2022-08-05T15:09:00.146+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _read_cache  blob Blob(0x5636f18f56b0 blob([0x5ef50000~10000] csum crc32c/0x1000) use_tracker(0x4*0x4000 0x[4000,4000,4000,4000]) SharedBlob(0x5636f18f5790 sbid 0x0)) need 0xb797~400 cache has 0x[b797~400]
2022-08-05T15:09:00.146+0200 7f57b28a7700 20 _unpin0x563678353000   #14:b8a44b84:::gc.7:head# unpinned
2022-08-05T15:09:00.146+0200 7f57b28a7700 10 bluestore(/var/lib/ceph/osd/ceph-0) read 14.5_head #14:b8a44b84:::gc.7:head# 0x7a0b797~400 = 1024
2022-08-05T15:09:00.150+0200 7f57b28a7700 15 bluestore(/var/lib/ceph/osd/ceph-0) read 14.5_head #14:b8a44b84:::gc.7:head# 0x7a0bb97~400
2022-08-05T15:09:00.150+0200 7f57b28a7700 20 _pin0x563678353000   #14:b8a44b84:::gc.7:head# pinned
2022-08-05T15:09:00.150+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read 0x7a0bb97~400 size 0x8000000 (134217728)
2022-08-05T15:09:00.150+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read defaulting to buffered read
2022-08-05T15:09:00.150+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _read_cache  blob Blob(0x5636f18f56b0 blob([0x5ef50000~10000] csum crc32c/0x1000) use_tracker(0x4*0x4000 0x[4000,4000,4000,4000]) SharedBlob(0x5636f18f5790 sbid 0x0)) need 0xbb97~400 cache has 0x[bb97~400]
2022-08-05T15:09:00.150+0200 7f57b28a7700 20 _unpin0x563678353000   #14:b8a44b84:::gc.7:head# unpinned
2022-08-05T15:09:00.150+0200 7f57b28a7700 10 bluestore(/var/lib/ceph/osd/ceph-0) read 14.5_head #14:b8a44b84:::gc.7:head# 0x7a0bb97~400 = 1024
2022-08-05T15:09:00.150+0200 7f57b28a7700 15 bluestore(/var/lib/ceph/osd/ceph-0) read 14.5_head #14:b8a44b84:::gc.7:head# 0x7a0bf97~400
2022-08-05T15:09:00.150+0200 7f57b28a7700 20 _pin0x563678353000   #14:b8a44b84:::gc.7:head# pinned
2022-08-05T15:09:00.150+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read 0x7a0bf97~400 size 0x8000000 (134217728)
2022-08-05T15:09:00.150+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read defaulting to buffered read
2022-08-05T15:09:00.150+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _read_cache  blob Blob(0x5636f18f56b0 blob([0x5ef50000~10000] csum crc32c/0x1000) use_tracker(0x4*0x4000 0x[4000,4000,4000,4000]) SharedBlob(0x5636f18f5790 sbid 0x0)) need 0xbf97~400 cache has 0x[bf97~69]
2022-08-05T15:09:00.150+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _prepare_read_ioc  blob Blob(0x5636f18f56b0 blob([0x5ef50000~10000] csum crc32c/0x1000) use_tracker(0x4*0x4000 0x[4000,4000,4000,4000]) SharedBlob(0x5636f18f5790 sbid 0x0)) need {<0xc000, 0x1000> : [0x7a0c000:c000~397]}
2022-08-05T15:09:00.150+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _prepare_read_ioc    region 0x7a0c000: 0xc000 reading 0xc000~1000
2022-08-05T15:09:00.150+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read waiting for aio
2022-08-05T15:09:00.150+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _generate_read_result_bl  blob Blob(0x5636f18f56b0 blob([0x5ef50000~10000] csum crc32c/0x1000) use_tracker(0x4*0x4000 0x[4000,4000,4000,4000]) SharedBlob(0x5636f18f5790 sbid 0x0)) need 0x{<0xc000, 0x1000> : [0x7a0c000:c000~397]}
2022-08-05T15:09:00.150+0200 7f57b28a7700 20 bluestore.BufferSpace(0x5636f18f57a8 in 0x5636775472b0) _discard 0xc000~1000
2022-08-05T15:09:00.150+0200 7f57b28a7700 20 _add level 1 near 0 on buffer(0x56367c1bc1c0 space 0x5636f18f57a8 0xc000~1000 clean) which has cache_private 0
2022-08-05T15:09:00.150+0200 7f57b28a7700 20 _trim_to buffer_warm_in -> out buffer(0x5636f0566640 space 0x563682647208 0xd000~1000 clean)
2022-08-05T15:09:00.150+0200 7f57b28a7700 20 _trim_to evicted 4 KiB from warm_in list, done evicting warm_in buffers
2022-08-05T15:09:00.150+0200 7f57b28a7700 20 _trim_to buffer_warm_out rm buffer(0x56367bffb6e0 space 0x56367d704af8 0xd000~1000 empty)
2022-08-05T15:09:00.150+0200 7f57b28a7700 20 _rm buffer(0x56367bffb6e0 space 0x56367d704af8 0xd000~1000 empty)
2022-08-05T15:09:00.150+0200 7f57b28a7700 20 _unpin0x563678353000   #14:b8a44b84:::gc.7:head# unpinned
2022-08-05T15:09:00.150+0200 7f57b28a7700 10 bluestore(/var/lib/ceph/osd/ceph-0) read 14.5_head #14:b8a44b84:::gc.7:head# 0x7a0bf97~400 = 1024
2022-08-05T15:09:00.154+0200 7f57b28a7700 15 bluestore(/var/lib/ceph/osd/ceph-0) read 14.5_head #14:b8a44b84:::gc.7:head# 0x7a0c397~400
2022-08-05T15:09:00.154+0200 7f57b28a7700 20 _pin0x563678353000   #14:b8a44b84:::gc.7:head# pinned
2022-08-05T15:09:00.154+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read 0x7a0c397~400 size 0x8000000 (134217728)
2022-08-05T15:09:00.154+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read defaulting to buffered read
2022-08-05T15:09:00.154+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _read_cache  blob Blob(0x5636f18f56b0 blob([0x5ef50000~10000] csum crc32c/0x1000) use_tracker(0x4*0x4000 0x[4000,4000,4000,4000]) SharedBlob(0x5636f18f5790 sbid 0x0)) need 0xc397~400 cache has 0x[c397~400]
2022-08-05T15:09:00.154+0200 7f57b28a7700 20 _unpin0x563678353000   #14:b8a44b84:::gc.7:head# unpinned
2022-08-05T15:09:00.154+0200 7f57b28a7700 10 bluestore(/var/lib/ceph/osd/ceph-0) read 14.5_head #14:b8a44b84:::gc.7:head# 0x7a0c397~400 = 1024
2022-08-05T15:09:00.154+0200 7f57b28a7700 15 bluestore(/var/lib/ceph/osd/ceph-0) read 14.5_head #14:b8a44b84:::gc.7:head# 0x7a0c797~400
2022-08-05T15:09:00.154+0200 7f57b28a7700 20 _pin0x563678353000   #14:b8a44b84:::gc.7:head# pinned
2022-08-05T15:09:00.154+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read 0x7a0c797~400 size 0x8000000 (134217728)
2022-08-05T15:09:00.154+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read defaulting to buffered read
2022-08-05T15:09:00.154+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _read_cache  blob Blob(0x5636f18f56b0 blob([0x5ef50000~10000] csum crc32c/0x1000) use_tracker(0x4*0x4000 0x[4000,4000,4000,4000]) SharedBlob(0x5636f18f5790 sbid 0x0)) need 0xc797~400 cache has 0x[c797~400]
2022-08-05T15:09:00.154+0200 7f57b28a7700 20 _unpin0x563678353000   #14:b8a44b84:::gc.7:head# unpinned
2022-08-05T15:09:00.154+0200 7f57b28a7700 10 bluestore(/var/lib/ceph/osd/ceph-0) read 14.5_head #14:b8a44b84:::gc.7:head# 0x7a0c797~400 = 1024
2022-08-05T15:09:00.154+0200 7f57b28a7700 15 bluestore(/var/lib/ceph/osd/ceph-0) read 14.5_head #14:b8a44b84:::gc.7:head# 0x7a0cb97~400
2022-08-05T15:09:00.154+0200 7f57b28a7700 20 _pin0x563678353000   #14:b8a44b84:::gc.7:head# pinned
2022-08-05T15:09:00.154+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read 0x7a0cb97~400 size 0x8000000 (134217728)
2022-08-05T15:09:00.154+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read defaulting to buffered read
2022-08-05T15:09:00.154+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _read_cache  blob Blob(0x5636f18f56b0 blob([0x5ef50000~10000] csum crc32c/0x1000) use_tracker(0x4*0x4000 0x[4000,4000,4000,402022-08-05T15:09:00.154+0200 7f57b28a7700 20 _unpin0x563678353000   #14:b8a44b84:::gc.7:head# unpinned
2022-08-05T15:09:00.154+0200 7f57b28a7700 10 bluestore(/var/lib/ceph/osd/ceph-0) read 14.5_head #14:b8a44b84:::gc.7:head# 0x7a0cb97~400 = 1024
2022-08-05T15:09:00.158+0200 7f57b28a7700 15 bluestore(/var/lib/ceph/osd/ceph-0) read 14.5_head #14:b8a44b84:::gc.7:head# 0x7a0cf97~400
2022-08-05T15:09:00.158+0200 7f57b28a7700 20 _pin0x563678353000   #14:b8a44b84:::gc.7:head# pinned
2022-08-05T15:09:00.158+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read 0x7a0cf97~400 size 0x8000000 (134217728)
2022-08-05T15:09:00.158+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read defaulting to buffered read
2022-08-05T15:09:00.158+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _read_cache  blob Blob(0x5636f18f56b0 blob([0x5ef50000~10000] csum crc32c/0x1000) use_tracker(0x4*0x4000 0x[4000,4000,4000,4000]) SharedBlob(0x5636f18f5790 sbid 0x0)) need 0xcf97~400 cache has 0x[cf97~69]
2022-08-05T15:09:00.158+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _prepare_read_ioc  blob Blob(0x5636f18f56b0 blob([0x5ef50000~10000] csum crc32c/0x1000) use_tracker(0x4*0x4000 0x[4000,4000,4000,4000]) SharedBlob(0x5636f18f5790 sbid 0x0)) need {<0xd000, 0x1000> : [0x7a0d000:d000~397]}
2022-08-05T15:09:00.158+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _prepare_read_ioc    region 0x7a0d000: 0xd000 reading 0xd000~1000
2022-08-05T15:09:00.158+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read waiting for aio
2022-08-05T15:09:00.158+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _generate_read_result_bl  blob Blob(0x5636f18f56b0 blob([0x5ef50000~10000] csum crc32c/0x1000) use_tracker(0x4*0x4000 0x[4000,4000,4000,4000]) SharedBlob(0x5636f18f5790 sbid 0x0)) need 0x{<0xd000, 0x1000> : [0x7a0d000:d000~397]}
2022-08-05T15:09:00.158+0200 7f57b28a7700 20 bluestore.BufferSpace(0x5636f18f57a8 in 0x5636775472b0) _discard 0xd000~1000
2022-08-05T15:09:00.158+0200 7f57b28a7700 20 _add level 1 near 0 on buffer(0x56367c1bb5c0 space 0x5636f18f57a8 0xd000~1000 clean) which has cache_private 0
2022-08-05T15:09:00.158+0200 7f57b28a7700 20 _trim_to buffer_warm_in -> out buffer(0x5636f0565380 space 0x563682647208 0xe000~1000 clean)
2022-08-05T15:09:00.158+0200 7f57b28a7700 20 _trim_to evicted 4 KiB from warm_in list, done evicting warm_in buffers
2022-08-05T15:09:00.158+0200 7f57b28a7700 20 _trim_to buffer_warm_out rm buffer(0x56367bffd660 space 0x56367d704af8 0xe000~1000 empty)
2022-08-05T15:09:00.158+0200 7f57b28a7700 20 _rm buffer(0x56367bffd660 space 0x56367d704af8 0xe000~1000 empty)
2022-08-05T15:09:00.158+0200 7f57b28a7700 20 _unpin0x563678353000   #14:b8a44b84:::gc.7:head# unpinned
2022-08-05T15:09:00.158+0200 7f57b28a7700 10 bluestore(/var/lib/ceph/osd/ceph-0) read 14.5_head #14:b8a44b84:::gc.7:head# 0x7a0cf97~400 = 1024
2022-08-05T15:09:00.158+0200 7f57b28a7700 15 bluestore(/var/lib/ceph/osd/ceph-0) read 14.5_head #14:b8a44b84:::gc.7:head# 0x7a0d397~400
2022-08-05T15:09:00.158+0200 7f57b28a7700 20 _pin0x563678353000   #14:b8a44b84:::gc.7:head# pinned
2022-08-05T15:09:00.158+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read 0x7a0d397~400 size 0x8000000 (134217728)
2022-08-05T15:09:00.158+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read defaulting to buffered read
2022-08-05T15:09:00.158+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _read_cache  blob Blob(0x5636f18f56b0 blob([0x5ef50000~10000] csum crc32c/0x1000) use_tracker(0x4*0x4000 0x[4000,4000,4000,4000]) SharedBlob(0x5636f18f5790 sbid 0x0)) need 0xd397~400 cache has 0x[d397~400]
2022-08-05T15:09:00.158+0200 7f57b28a7700 20 _unpin0x563678353000   #14:b8a44b84:::gc.7:head# unpinned
2022-08-05T15:09:00.158+0200 7f57b28a7700 10 bluestore(/var/lib/ceph/osd/ceph-0) read 14.5_head #14:b8a44b84:::gc.7:head# 0x7a0d397~400 = 1024
2022-08-05T15:09:00.162+0200 7f57b28a7700 15 bluestore(/var/lib/ceph/osd/ceph-0) read 14.5_head #14:b8a44b84:::gc.7:head# 0x7a0d797~400
2022-08-05T15:09:00.162+0200 7f57b28a7700 20 _pin0x563678353000   #14:b8a44b84:::gc.7:head# pinned
2022-08-05T15:09:00.162+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read 0x7a0d797~400 size 0x8000000 (134217728)
2022-08-05T15:09:00.162+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read defaulting to buffered read
2022-08-05T15:09:00.162+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _read_cache  blob Blob(0x5636f18f56b0 blob([0x5ef50000~10000] csum crc32c/0x1000) use_tracker(0x4*0x4000 0x[4000,4000,4000,4000]) SharedBlob(0x5636f18f5790 sbid 0x0)) need 0xd797~400 cache has 0x[d797~400]
2022-08-05T15:09:00.162+0200 7f57b28a7700 20 _unpin0x563678353000   #14:b8a44b84:::gc.7:head# unpinned
2022-08-05T15:09:00.162+0200 7f57b28a7700 10 bluestore(/var/lib/ceph/osd/ceph-0) read 14.5_head #14:b8a44b84:::gc.7:head# 0x7a0d797~400 = 1024
2022-08-05T15:09:00.162+0200 7f57b28a7700 15 bluestore(/var/lib/ceph/osd/ceph-0) read 14.5_head #14:b8a44b84:::gc.7:head# 0x7a0db97~400
2022-08-05T15:09:00.162+0200 7f57b28a7700 20 _pin0x563678353000   #14:b8a44b84:::gc.7:head# pinned
2022-08-05T15:09:00.162+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read 0x7a0db97~400 size 0x8000000 (134217728)
2022-08-05T15:09:00.162+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read defaulting to buffered read
2022-08-05T15:09:00.162+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _read_cache  blob Blob(0x5636f18f56b0 blob([0x5ef50000~10000] csum crc32c/0x1000) use_tracker(0x4*0x4000 0x[4000,4000,4000,4000]) SharedBlob(0x5636f18f5790 sbid 0x0)) need 0xdb97~400 cache has 0x[db97~400]
2022-08-05T15:09:00.162+0200 7f57b28a7700 20 _unpin0x563678353000   #14:b8a44b84:::gc.7:head# unpinned
2022-08-05T15:09:00.162+0200 7f57b28a7700 10 bluestore(/var/lib/ceph/osd/ceph-0) read 14.5_head #14:b8a44b84:::gc.7:head# 0x7a0db97~400 = 1024
2022-08-05T15:09:00.162+0200 7f57b28a7700 15 bluestore(/var/lib/ceph/osd/ceph-0) read 14.5_head #14:b8a44b84:::gc.7:head# 0x7a0df97~400
2022-08-05T15:09:00.162+0200 7f57b28a7700 20 _pin0x563678353000   #14:b8a44b84:::gc.7:head# pinned
2022-08-05T15:09:00.162+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read 0x7a0df97~400 size 0x8000000 (134217728)
2022-08-05T15:09:00.162+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read defaulting to buffered read
2022-08-05T15:09:00.162+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _read_cache  blob Blob(0x5636f18f56b0 blob([0x5ef50000~10000] csum crc32c/0x1000) use_tracker(0x4*0x4000 0x[4000,4000,4000,4000]) SharedBlob(0x5636f18f5790 sbid 0x0)) need 0xdf97~400 cache has 0x[df97~69]
2022-08-05T15:09:00.162+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _prepare_read_ioc  blob Blob(0x5636f18f56b0 blob([0x5ef50000~10000] csum crc32c/0x1000) use_tracker(0x4*0x4000 0x[4000,4000,4000,4000]) SharedBlob(0x5636f18f5790 sbid 0x0)) need {<0xe000, 0x1000> : [0x7a0e000:e000~397]}00]) SharedBlob(0x5636f18f5790 sbid 0x0)) need 0xcb97~400 cache has 0x[cb97~400]
2022-08-05T15:09:00.162+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _prepare_read_ioc    region 0x7a0e000: 0xe000 reading 0xe000~1000
2022-08-05T15:09:00.162+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read waiting for aio
2022-08-05T15:09:00.166+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _generate_read_result_bl  blob Blob(0x5636f18f56b0 blob([0x5ef50000~10000] csum crc32c/0x1000) use_tracker(0x4*0x4000 0x[4000,4000,4000,4000]) SharedBlob(0x5636f18f5790 sbid 0x0)) need 0x{<0xe000, 0x1000> : [0x7a0e000:e000~397]}
2022-08-05T15:09:00.166+0200 7f57b28a7700 20 bluestore.BufferSpace(0x5636f18f57a8 in 0x5636775472b0) _discard 0xe000~1000
2022-08-05T15:09:00.166+0200 7f57b28a7700 20 _add level 1 near 0 on buffer(0x56367c1bbb00 space 0x5636f18f57a8 0xe000~1000 clean) which has cache_private 0
2022-08-05T15:09:00.166+0200 7f57b28a7700 20 _trim_to buffer_warm_in -> out buffer(0x5636f0567d20 space 0x563682647208 0xf000~1000 clean)
2022-08-05T15:09:00.166+0200 7f57b28a7700 20 _trim_to evicted 4 KiB from warm_in list, done evicting warm_in buffers
2022-08-05T15:09:00.166+0200 7f57b28a7700 20 _trim_to buffer_warm_out rm buffer(0x56368441c840 space 0x56367d704af8 0xf000~1000 empty)
2022-08-05T15:09:00.166+0200 7f57b28a7700 20 _rm buffer(0x56368441c840 space 0x56367d704af8 0xf000~1000 empty)
2022-08-05T15:09:00.166+0200 7f57b28a7700 20 _unpin0x563678353000   #14:b8a44b84:::gc.7:head# unpinned
2022-08-05T15:09:00.166+0200 7f57b28a7700 10 bluestore(/var/lib/ceph/osd/ceph-0) read 14.5_head #14:b8a44b84:::gc.7:head# 0x7a0df97~400 = 1024
2022-08-05T15:09:00.166+0200 7f57b28a7700 15 bluestore(/var/lib/ceph/osd/ceph-0) read 14.5_head #14:b8a44b84:::gc.7:head# 0x7a0e397~400
2022-08-05T15:09:00.166+0200 7f57b28a7700 20 _pin0x563678353000   #14:b8a44b84:::gc.7:head# pinned
2022-08-05T15:09:00.166+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read 0x7a0e397~400 size 0x8000000 (134217728)
2022-08-05T15:09:00.166+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read defaulting to buffered read
2022-08-05T15:09:00.166+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _read_cache  blob Blob(0x5636f18f56b0 blob([0x5ef50000~10000] csum crc32c/0x1000) use_tracker(0x4*0x4000 0x[4000,4000,4000,4000]) SharedBlob(0x5636f18f5790 sbid 0x0)) need 0xe397~400 cache has 0x[e397~400]
2022-08-05T15:09:00.166+0200 7f57b28a7700 20 _unpin0x563678353000   #14:b8a44b84:::gc.7:head# unpinned
2022-08-05T15:09:00.166+0200 7f57b28a7700 10 bluestore(/var/lib/ceph/osd/ceph-0) read 14.5_head #14:b8a44b84:::gc.7:head# 0x7a0e397~400 = 1024
2022-08-05T15:09:00.166+0200 7f57b28a7700 15 bluestore(/var/lib/ceph/osd/ceph-0) read 14.5_head #14:b8a44b84:::gc.7:head# 0x7a0e797~400
2022-08-05T15:09:00.166+0200 7f57b28a7700 20 _pin0x563678353000   #14:b8a44b84:::gc.7:head# pinned
2022-08-05T15:09:00.166+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read 0x7a0e797~400 size 0x8000000 (134217728)
2022-08-05T15:09:00.166+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read defaulting to buffered read
2022-08-05T15:09:00.166+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _read_cache  blob Blob(0x5636f18f56b0 blob([0x5ef50000~10000] csum crc32c/0x1000) use_tracker(0x4*0x4000 0x[4000,4000,4000,4000]) SharedBlob(0x5636f18f5790 sbid 0x0)) need 0xe797~400 cache has 0x[e797~400]
2022-08-05T15:09:00.166+0200 7f57b28a7700 20 _unpin0x563678353000   #14:b8a44b84:::gc.7:head# unpinned
2022-08-05T15:09:00.166+0200 7f57b28a7700 10 bluestore(/var/lib/ceph/osd/ceph-0) read 14.5_head #14:b8a44b84:::gc.7:head# 0x7a0e797~400 = 1024
2022-08-05T15:09:00.166+0200 7f57c30c8700 20 bluestore.MempoolThread(0x563678242b90) _resize_shards cache_size: 1932735282 kv_alloc: 1761607680 kv_used: 1745607184 kv_onode_alloc: 42949672 kv_onode_used: -22 meta_alloc: 83886080 meta_used: 11818539 data_alloc: 75497472 data_used: 5091328
2022-08-05T15:09:00.170+0200 7f57b28a7700 15 bluestore(/var/lib/ceph/osd/ceph-0) read 14.5_head #14:b8a44b84:::gc.7:head# 0x7a0eb97~400
2022-08-05T15:09:00.170+0200 7f57b28a7700 20 _pin0x563678353000   #14:b8a44b84:::gc.7:head# pinned
2022-08-05T15:09:00.170+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read 0x7a0eb97~400 size 0x8000000 (134217728)
2022-08-05T15:09:00.170+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read defaulting to buffered read
2022-08-05T15:09:00.170+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _read_cache  blob Blob(0x5636f18f56b0 blob([0x5ef50000~10000] csum crc32c/0x1000) use_tracker(0x4*0x4000 0x[4000,4000,4000,4000]) SharedBlob(0x5636f18f5790 sbid 0x0)) need 0xeb97~400 cache has 0x[eb97~400]
2022-08-05T15:09:00.170+0200 7f57b28a7700 20 _unpin0x563678353000   #14:b8a44b84:::gc.7:head# unpinned
2022-08-05T15:09:00.170+0200 7f57b28a7700 10 bluestore(/var/lib/ceph/osd/ceph-0) read 14.5_head #14:b8a44b84:::gc.7:head# 0x7a0eb97~400 = 1024
2022-08-05T15:09:00.170+0200 7f57b28a7700 15 bluestore(/var/lib/ceph/osd/ceph-0) read 14.5_head #14:b8a44b84:::gc.7:head# 0x7a0ef97~400
2022-08-05T15:09:00.170+0200 7f57b28a7700 20 _pin0x563678353000   #14:b8a44b84:::gc.7:head# pinned
2022-08-05T15:09:00.170+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read 0x7a0ef97~400 size 0x8000000 (134217728)
2022-08-05T15:09:00.170+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read defaulting to buffered read
2022-08-05T15:09:00.170+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _read_cache  blob Blob(0x5636f18f56b0 blob([0x5ef50000~10000] csum crc32c/0x1000) use_tracker(0x4*0x4000 0x[4000,4000,4000,4000]) SharedBlob(0x5636f18f5790 sbid 0x0)) need 0xef97~400 cache has 0x[ef97~69]
2022-08-05T15:09:00.170+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _prepare_read_ioc  blob Blob(0x5636f18f56b0 blob([0x5ef50000~10000] csum crc32c/0x1000) use_tracker(0x4*0x4000 0x[4000,4000,4000,4000]) SharedBlob(0x5636f18f5790 sbid 0x0)) need {<0xf000, 0x1000> : [0x7a0f000:f000~397]}
2022-08-05T15:09:00.170+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _prepare_read_ioc    region 0x7a0f000: 0xf000 reading 0xf000~1000
2022-08-05T15:09:00.170+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _do_read waiting for aio
2022-08-05T15:09:00.170+0200 7f57b28a7700 20 bluestore(/var/lib/ceph/osd/ceph-0) _generate_read_result_bl  blob Blob(0x5636f18f56b0 blob([0x5ef50000~10000] csum crc32c/0x1000) use_tracker(0x4*0x4000 0x[4000,4000,4000,4000]) SharedBlob(0x5636f18f5790 sbid 0x0)) need 0x{<0xf000, 0x1000> : [0x7a0f000:f000~397]}
2022-08-05T15:09:00.170+0200 7f57b28a7700 20 bluestore.BufferSpace(0x5636f18f57a8 in 0x5636775472b0) _discard 0xf000~1000
2022-08-05T15:09:00.170+0200 7f57b28a7700 20 _add level 1 near 0 on buffer(0x56367c1bbd40 space 0x5636f18f57a8 0xf000~1000 clean) which has cache_private 0
2022-08-05T15:09:00.170+0200 7f57b28a7700 20 _trim_to buffer_warm_in -> out buffer(0x5636f0565ec0 space 0x563682649e38 0x0~1000 clean)
2022-08-05T15:09:00.170+0200 7f57b28a7700 20 _trim_to evicted 4 KiB from warm_in list, done evicting warm_in buffers
Actions
Copy link
 #7

Updated by Radoslaw Zarzynski over 1 year ago

Hello Marin! Yup, we have. Check this out: https://docs.ceph.com/en/quincy/man/8/ceph-post-file/.

Actions
Copy link
 #8

Updated by Radoslaw Zarzynski over 1 year ago

  • Project changed from RADOS to bluestore

Moving to BlueStore per Igor's comment.

Actions
Copy link
 #9

Updated by Marcin Gibula over 1 year ago

Ok, here's the OSD log

ceph-post-file: ee5c8225-7061-4278-8099-a5f29bb8f2f9

Actions
Copy link

Also available in: Atom PDF