Bug #51626: OSD uses all host memory (80g) on startup due to pg_split - RADOS - Ceph

Actions

Copy link

Bug #51626

open

OSD uses all host memory (80g) on startup due to pg_split

Added by Tor Martin Ølberg almost 3 years ago. Updated about 2 years ago.

Status:

New

Priority:

Normal

Assignee:

Category:

Target version:

% Done:

Source:

Tags:

16.2.5,15.2.4,15.2.13

Backport:

Regression:

Severity:

2 - major

Reviewed:

Affected Versions:

Ceph - v15.2.13, Ceph - v15.2.5, Ceph - v16.2.5

ceph-qa-suite:

Component(RADOS):

Pull request ID:

Crash signature (v1):

Crash signature (v2):

Description

After upgrading from 15.2.4 to 15.2.13 some OSDs fails to start.

The OSDs which are failing to start seem to be failing due to pg_split trying to happen on a specific pool.

exporting the troublesome pgs from the osd allows the OSD to start but yields dataloss. reimporting the pg triggers the fault state again.

Looking at perf dumps it looks like buffer_anon is taking up most of the memory and is never being flushed.

During the fault state the OSD output (with log level 50/50) is:

2021-07-11T11:02:59.252+0200 7f3a0754b700 10 osd.19 151095 do_waiters -- finish
2021-07-11T11:02:59.252+0200 7f3a0754b700 20 osd.19 151095 tick last_purged_snaps_scrub 2021-07-11T00:02:32.071851+0200 next 2021-07-12T00:02:32.071851+0200
2021-07-11T11:03:00.280+0200 7f3a0754b700 10 osd.19 151095 tick
2021-07-11T11:03:00.280+0200 7f3a0754b700 10 osd.19 151095 do_waiters -- start
2021-07-11T11:03:00.280+0200 7f3a0754b700 10 osd.19 151095 do_waiters -- finish
2021-07-11T11:03:00.280+0200 7f3a0754b700 20 osd.19 151095 tick last_purged_snaps_scrub 2021-07-11T00:02:32.071851+0200 next 2021-07-12T00:02:32.071851+0200
2021-07-11T11:03:00.720+0200 7f39ee519700 30 osd.19 151095 heartbeat_entry woke up
2021-07-11T11:03:00.720+0200 7f39ee519700 30 osd.19 151095 heartbeat
2021-07-11T11:03:00.720+0200 7f39ee519700 30 osd.19 151095 heartbeat: daily_loadavg 4.08824
2021-07-11T11:03:00.720+0200 7f39ee519700 30 osd.19 151095 heartbeat checking stats
2021-07-11T11:03:00.720+0200 7f39ee519700  5 osd.19 151095 heartbeat osd_stat(store_statfs(0x5382fd0000/0x40000000/0x101e0bfe000, data 0x94f7c3851b/0x951dc20000, compress 0x22bb0bce/0x4bff0000/0xa30e0000, omap 0x20e2f8, meta 0x947efd08), peers [] op hist [])
2021-07-11T11:03:00.724+0200 7f39ee519700 20 osd.19 151095 check_full_status cur ratio 0.675189, physical ratio 0.675189, new state none 
2021-07-11T11:03:00.724+0200 7f39ee519700 30 osd.19 151095 heartbeat lonely?
2021-07-11T11:03:00.724+0200 7f39ee519700 30 osd.19 151095 heartbeat done
2021-07-11T11:03:00.724+0200 7f39ee519700 30 osd.19 151095 heartbeat_entry sleeping for 3.5
2021-07-11T11:03:01.280+0200 7f3a0754b700 10 osd.19 151095 tick
2021-07-11T11:03:01.280+0200 7f3a0754b700 10 osd.19 151095 do_waiters -- start
2021-07-11T11:03:01.280+0200 7f3a0754b700 10 osd.19 151095 do_waiters -- finish
2021-07-11T11:03:01.280+0200 7f3a0754b700 20 osd.19 151095 tick last_purged_snaps_scrub 2021-07-11T00:02:32.071851+0200 next 2021-07-12T00:02:32.071851+0200

So far we've tried compiling from source master/16.2.15,15.2.13 and 15.2.4 all of them which seem to have the same issue.

logfile can be found here (cant attach it because its 20mb)
https://drive.google.com/file/d/1VZpwnx6VDlWZKdOTpNIVF1zxQtpoKSzQ/view?usp=sharing

Related issues 1 (0 open — 1 closed)

Actions

Copy link

Updated by Loïc Dachary over 2 years ago

Target version deleted (~~v16.2.5~~)

Actions

Copy link

Updated by Gonzalo Aguilar Delgado over 2 years ago

Any update? I have the same trouble...

I downgraded kernel to 4.XX because with newer kernel I cannot even get this
I'm using XFS, don't know if this helps

root@blue-compute:/# ceph-osd --version
ceph version 16.2.6 (ee28fb57e47e9f88813e24bbf4c14496ca299d31) pacific (stable)

---
part of the log

2021-12-30T13:17:30.273+0000 7f4c2d082640 10 osd.2 1492194 do_waiters -- start
2021-12-30T13:17:30.273+0000 7f4c2d082640 10 osd.2 1492194 do_waiters -- finish
2021-12-30T13:17:30.273+0000 7f4c2d082640 20 osd.2 1492194 tick last_purged_snaps_scrub 2021-12-30T11:58:25.837843+0000 next 2021-12-31T11:58:25.837843+0000
2021-12-30T13:17:30.985+0000 7f4bfcf7d640 30 osd.2 1492194 heartbeat_entry woke up
2021-12-30T13:17:30.985+0000 7f4bfcf7d640 30 osd.2 1492194 heartbeat
2021-12-30T13:17:30.985+0000 7f4bfcf7d640 30 osd.2 1492194 heartbeat: daily_loadavg 2.18009
2021-12-30T13:17:30.985+0000 7f4bfcf7d640 30 osd.2 1492194 heartbeat checking stats
2021-12-30T13:17:30.985+0000 7f4bfcf7d640 5 osd.2 1492194 heartbeat osd_stat(store_statfs(0x2a4269f000/0x0/0x73224a0000, data 0x2a4269f000/0x2a4269f000, compress 0x0/0x0/0x0, omap 0x1b359e0c, meta 0x0), peers [] op hist [])
2021-12-30T13:17:30.985+0000 7f4bfcf7d640 20 osd.2 1492194 check_full_status cur ratio 0.632954, physical ratio 0.632954, new state none
2021-12-30T13:17:30.985+0000 7f4bfcf7d640 30 osd.2 1492194 heartbeat lonely?
2021-12-30T13:17:30.985+0000 7f4bfcf7d640 30 osd.2 1492194 heartbeat done
2021-12-30T13:17:30.985+0000 7f4bfcf7d640 30 osd.2 1492194 heartbeat_entry sleeping for 5.3

Actions

Copy link

Updated by Tor Martin Ølberg over 2 years ago

Gonzalo Aguilar Delgado wrote:

Any update? I have the same trouble...

I downgraded kernel to 4.XX because with newer kernel I cannot even get this
I'm using XFS, don't know if this helps

root@blue-compute:/# ceph-osd --version
ceph version 16.2.6 (ee28fb57e47e9f88813e24bbf4c14496ca299d31) pacific (stable)

---
part of the log

2021-12-30T13:17:30.273+0000 7f4c2d082640 10 osd.2 1492194 do_waiters -- start
2021-12-30T13:17:30.273+0000 7f4c2d082640 10 osd.2 1492194 do_waiters -- finish
2021-12-30T13:17:30.273+0000 7f4c2d082640 20 osd.2 1492194 tick last_purged_snaps_scrub 2021-12-30T11:58:25.837843+0000 next 2021-12-31T11:58:25.837843+0000
2021-12-30T13:17:30.985+0000 7f4bfcf7d640 30 osd.2 1492194 heartbeat_entry woke up
2021-12-30T13:17:30.985+0000 7f4bfcf7d640 30 osd.2 1492194 heartbeat
2021-12-30T13:17:30.985+0000 7f4bfcf7d640 30 osd.2 1492194 heartbeat: daily_loadavg 2.18009
2021-12-30T13:17:30.985+0000 7f4bfcf7d640 30 osd.2 1492194 heartbeat checking stats
2021-12-30T13:17:30.985+0000 7f4bfcf7d640 5 osd.2 1492194 heartbeat osd_stat(store_statfs(0x2a4269f000/0x0/0x73224a0000, data 0x2a4269f000/0x2a4269f000, compress 0x0/0x0/0x0, omap 0x1b359e0c, meta 0x0), peers [] op hist [])
2021-12-30T13:17:30.985+0000 7f4bfcf7d640 20 osd.2 1492194 check_full_status cur ratio 0.632954, physical ratio 0.632954, new state none
2021-12-30T13:17:30.985+0000 7f4bfcf7d640 30 osd.2 1492194 heartbeat lonely?
2021-12-30T13:17:30.985+0000 7f4bfcf7d640 30 osd.2 1492194 heartbeat done
2021-12-30T13:17:30.985+0000 7f4bfcf7d640 30 osd.2 1492194 heartbeat_entry sleeping for 5.3

Hi,

Probably not what you want to hear but I ended up exporting the pgs which caused the osd not to start. In the end I essentially had to wipe out a complete pool to get it going again. Even if I tried importing the pgs which caused the issue they wouldnt restart again and the OSD would be killed again. In my case I lost some data, thankfully not important data but at that point it was more important to get the cluster out of a degraded state then loosing that data.

Actions

Copy link