Upgrading to 16.2.11 timing out on ceph-volume due to raw list performance bug, downgrade isn't possible due to new OP code in bluestore
4 Apr
2023
4 Apr
'23
11:18 p.m.
Trying to upgrade a containerized setup from 16.2.10 to 16.2.11 gave us two
big surprises, I wanted to share in case anyone else encounters the same. I
don't see any nice solution to this apart from a new release that fixes the
performance regression that completely breaks the container setup in
cephadm due to timeouts:
After some digging, we would that the it was the "ceph-volume" command that
kept timing out, and after a ton of digging, found that it does so because
of
https://github.com/ceph/ceph/commit/bea9f4b643ce32268ad79c0fc257b25ff2f8333…
which was introduced into 16.2.11.
Unfortunately, the vital fix for this
https://github.com/ceph/ceph/commit/8d7423c3e75afbe111c91e699ef3cb1c0beee61b
was not included in 16.2.11
So, in a setup like ours, with *many* devices, a simple "ceph-volume raw
list" now takes over 10 minutes to run (instead of 5 seconds in 16.2.10).
As a result, the service files that cephadm generates
[Service]
LimitNOFILE=1048576
LimitNPROC=1048576
EnvironmentFile=-/etc/environment
ExecStart=/bin/bash
/var/lib/ceph/5406fed0-d52b-11ec-beff-7ed30a54847b/%i/unit.run
ExecStop=-/bin/bash -c '/bin/podman stop
ceph-5406fed0-d52b-11ec-beff-7ed30a54847b-%i ; bash
/var/lib/ceph/5406fed0-d52b-11ec-beff-7ed30a54847b/%i/unit.stop'
ExecStopPost=-/bin/bash
/var/lib/ceph/5406fed0-d52b-11ec-beff-7ed30a54847b/%i/unit.poststop
KillMode=none
Restart=on-failure
RestartSec=10s
TimeoutStartSec=120
TimeoutStopSec=120
StartLimitInterval=30min
StartLimitBurst=5
ExecStartPre=-/bin/rm -f %t/%n-pid %t/%n-cid
ExecStopPost=-/bin/rm -f %t/%n-pid %t/%n-cid
Type=forking
PIDFile=%t/%n-pid
Delegate=yes
will repeatedly be marked as failed, as they take over 2 minutes to run
now. This tells systemd to restart, and we now have an infinite loop, as
the 5 restarts takes over 50 minutes, it never even triggers the
StarLimitInterval, leaving this OSD in an infinite loop over listing the
n^2 devices (which, as a bonus, is also filling up the root disk with an
enormous amount of repeated logging in ceph-volume.log as it infinitely
tries to figure out if a block device is a bluestore)
And trying to just fix the service or unit files manually to at least just
stop this container from being incorrectly restarted over and over, is also
a dead end, since the orchestration stuff just overwrites this
automatically, and restarts the services again.
I found it seemed to be
/var/lib/ceph/5406fed0-d52b-11ec-beff-7ed30a54847b/cephadm.8d0364fef6c92fc3580b0d022e32241348e6f11a7694d2b957cdafcb9d059ff2
on my system that generated these files, so i tried tweaking that to have
the necessary 1200 second TimeoutStart and finally that managed to get the
darn container to stop restarting endlessly. (I admit i'm very fuzzy on how
these services and orchestration stuff is triggered as i usually don't work
on our storage stuff)
Still though, it takes 11 minutes to start each OSD service now, so this
isn't great.
We wanted to revert back to 16.2.10 but it turns out to also be a no-go, as
a new operation added to bluefs https://github.com/ceph/ceph/pull/42750 in
16.2.11 (though this isn't mentioned in the changelogs, i had to compare
the source code to see that it was in fact added 16.2.11). So trying to
revert an OSD then fails with:
debug 2023-04-04T11:42:45.927+0000 7f2c12f6a200 -1 bluefs _replay 0x100000:
stop: unrecognized op 12
debug 2023-04-04T11:42:45.927+0000 7f2c12f6a200 -1 bluefs mount failed to
replay log: (5) Input/output error
debug 2023-04-04T11:42:45.927+0000 7f2c12f6a200 -1
bluestore(/var/lib/ceph/osd/ceph-10) _open_bluefs failed bluefs mount: (5)
Input/output error
debug 2023-04-04T11:42:45.927+0000 7f2c12f6a200 -1
bluestore(/var/lib/ceph/osd/ceph-10) _open_db failed to prepare db
environment:
debug 2023-04-04T11:42:45.927+0000 7f2c12f6a200 1 bdev(0x5590e80a0400
/var/lib/ceph/osd/ceph-10/block) close
debug 2023-04-04T11:42:46.153+0000 7f2c12f6a200 -1 osd.10 0 OSD:init:
unable to mount object store
debug 2023-04-04T11:42:46.153+0000 7f2c12f6a200 -1 ** ERROR: osd init
failed: (5) Input/output error
Ouch
Best regards, Mikael
5 Apr
5 Apr
7:07 a.m.
On Wed, Apr 05, 2023 at 01:18:57AM +0200, Mikael Öhman wrote:
Trying to upgrade a containerized setup from 16.2.10
to 16.2.11 gave us two
big surprises, I wanted to share in case anyone else encounters the same. I
don't see any nice solution to this apart from a new release that fixes the
performance regression that completely breaks the container setup in
cephadm due to timeouts:
After some digging, we would that the it was the "ceph-volume" command that
kept timing out, and after a ton of digging, found that it does so because
of
https://github.com/ceph/ceph/commit/bea9f4b643ce32268ad79c0fc257b25ff2f8333…
which was introduced into 16.2.11.
Unfortunately, the vital fix for this
https://github.com/ceph/ceph/commit/8d7423c3e75afbe111c91e699ef3cb1c0beee61b
was not included in 16.2.11
So, in a setup like ours, with *many* devices, a simple "ceph-volume raw
list" now takes over 10 minutes to run (instead of 5 seconds in 16.2.10).
"Me too"
https://lore.kernel.org/ceph-devel/ZAgb8KZ5NWEkAWWF@onthe.net.au/
Chris
7:35 a.m.
Hi Mikael, thanks for sharing this (see also https://www.stroustrup.com/whitespace98.pdf,
python ha ha ha). We would probably have observed the same problem (70+ OSDs per host).
You might want to consider configuring deployment against a local registry and use a
patched image. Local container images is always a god idea, post-release patches are
common and not an exception.
Best regards,
=================
Frank Schilder
AIT Risø Campus
Bygning 109, rum S14
________________________________________
From: Mikael Öhman <micketeer(a)gmail.com>
Sent: Wednesday, April 5, 2023 1:18 AM
To: ceph-users(a)ceph.io
Subject: [ceph-users] Upgrading to 16.2.11 timing out on ceph-volume due to raw list
performance bug, downgrade isn't possible due to new OP code in bluestore
Trying to upgrade a containerized setup from 16.2.10 to 16.2.11 gave us two
big surprises, I wanted to share in case anyone else encounters the same. I
don't see any nice solution to this apart from a new release that fixes the
performance regression that completely breaks the container setup in
cephadm due to timeouts:
After some digging, we would that the it was the "ceph-volume" command that
kept timing out, and after a ton of digging, found that it does so because
of
https://github.com/ceph/ceph/commit/bea9f4b643ce32268ad79c0fc257b25ff2f8333…
which was introduced into 16.2.11.
Unfortunately, the vital fix for this
https://github.com/ceph/ceph/commit/8d7423c3e75afbe111c91e699ef3cb1c0beee61b
was not included in 16.2.11
So, in a setup like ours, with *many* devices, a simple "ceph-volume raw
list" now takes over 10 minutes to run (instead of 5 seconds in 16.2.10).
As a result, the service files that cephadm generates
[Service]
LimitNOFILE=1048576
LimitNPROC=1048576
EnvironmentFile=-/etc/environment
ExecStart=/bin/bash
/var/lib/ceph/5406fed0-d52b-11ec-beff-7ed30a54847b/%i/unit.run
ExecStop=-/bin/bash -c '/bin/podman stop
ceph-5406fed0-d52b-11ec-beff-7ed30a54847b-%i ; bash
/var/lib/ceph/5406fed0-d52b-11ec-beff-7ed30a54847b/%i/unit.stop'
ExecStopPost=-/bin/bash
/var/lib/ceph/5406fed0-d52b-11ec-beff-7ed30a54847b/%i/unit.poststop
KillMode=none
Restart=on-failure
RestartSec=10s
TimeoutStartSec=120
TimeoutStopSec=120
StartLimitInterval=30min
StartLimitBurst=5
ExecStartPre=-/bin/rm -f %t/%n-pid %t/%n-cid
ExecStopPost=-/bin/rm -f %t/%n-pid %t/%n-cid
Type=forking
PIDFile=%t/%n-pid
Delegate=yes
will repeatedly be marked as failed, as they take over 2 minutes to run
now. This tells systemd to restart, and we now have an infinite loop, as
the 5 restarts takes over 50 minutes, it never even triggers the
StarLimitInterval, leaving this OSD in an infinite loop over listing the
n^2 devices (which, as a bonus, is also filling up the root disk with an
enormous amount of repeated logging in ceph-volume.log as it infinitely
tries to figure out if a block device is a bluestore)
And trying to just fix the service or unit files manually to at least just
stop this container from being incorrectly restarted over and over, is also
a dead end, since the orchestration stuff just overwrites this
automatically, and restarts the services again.
I found it seemed to be
/var/lib/ceph/5406fed0-d52b-11ec-beff-7ed30a54847b/cephadm.8d0364fef6c92fc3580b0d022e32241348e6f11a7694d2b957cdafcb9d059ff2
on my system that generated these files, so i tried tweaking that to have
the necessary 1200 second TimeoutStart and finally that managed to get the
darn container to stop restarting endlessly. (I admit i'm very fuzzy on how
these services and orchestration stuff is triggered as i usually don't work
on our storage stuff)
Still though, it takes 11 minutes to start each OSD service now, so this
isn't great.
We wanted to revert back to 16.2.10 but it turns out to also be a no-go, as
a new operation added to bluefs https://github.com/ceph/ceph/pull/42750 in
16.2.11 (though this isn't mentioned in the changelogs, i had to compare
the source code to see that it was in fact added 16.2.11). So trying to
revert an OSD then fails with:
debug 2023-04-04T11:42:45.927+0000 7f2c12f6a200 -1 bluefs _replay 0x100000:
stop: unrecognized op 12
debug 2023-04-04T11:42:45.927+0000 7f2c12f6a200 -1 bluefs mount failed to
replay log: (5) Input/output error
debug 2023-04-04T11:42:45.927+0000 7f2c12f6a200 -1
bluestore(/var/lib/ceph/osd/ceph-10) _open_bluefs failed bluefs mount: (5)
Input/output error
debug 2023-04-04T11:42:45.927+0000 7f2c12f6a200 -1
bluestore(/var/lib/ceph/osd/ceph-10) _open_db failed to prepare db
environment:
debug 2023-04-04T11:42:45.927+0000 7f2c12f6a200 1 bdev(0x5590e80a0400
/var/lib/ceph/osd/ceph-10/block) close
debug 2023-04-04T11:42:46.153+0000 7f2c12f6a200 -1 osd.10 0 OSD:init:
unable to mount object store
debug 2023-04-04T11:42:46.153+0000 7f2c12f6a200 -1 ** ERROR: osd init
failed: (5) Input/output error
Ouch
Best regards, Mikael
_______________________________________________
ceph-users mailing list -- ceph-users(a)ceph.io
To unsubscribe send an email to ceph-users-leave(a)ceph.io
2:28 p.m.
Thank you for the suggestion Frank. We've managed to avoid patches so far,
but I guess that convenience ends now :(
With
# lsblk -P -p -o 'NAME' | wc -l
137
it takes about 10 minutes to run. 70 probably would also bring you over the
2 minute timeout window, so I certainly wouldn't consider updating unless
you have this bug patched.
Best regards, Mikael
On Wed, Apr 5, 2023 at 9:35 AM Frank Schilder <frans(a)dtu.dk> wrote:
Hi Mikael, thanks for sharing this (see also
https://www.stroustrup.com/whitespace98.pdf, python ha ha ha). We would
probably have observed the same problem (70+ OSDs per host). You might want
to consider configuring deployment against a local registry and use a
patched image. Local container images is always a god idea, post-release
patches are common and not an exception.
Best regards,
=================
Frank Schilder
AIT Risø Campus
Bygning 109, rum S14
________________________________________
From: Mikael Öhman <micketeer(a)gmail.com>
Sent: Wednesday, April 5, 2023 1:18 AM
To: ceph-users(a)ceph.io
Subject: [ceph-users] Upgrading to 16.2.11 timing out on ceph-volume due
to raw list performance bug, downgrade isn't possible due to new OP code in
bluestore
Trying to upgrade a containerized setup from 16.2.10 to 16.2.11 gave us two
big surprises, I wanted to share in case anyone else encounters the same. I
don't see any nice solution to this apart from a new release that fixes the
performance regression that completely breaks the container setup in
cephadm due to timeouts:
After some digging, we would that the it was the "ceph-volume" command that
kept timing out, and after a ton of digging, found that it does so because
of
https://github.com/ceph/ceph/commit/bea9f4b643ce32268ad79c0fc257b25ff2f8333…
which was introduced into 16.2.11.
Unfortunately, the vital fix for this
https://github.com/ceph/ceph/commit/8d7423c3e75afbe111c91e699ef3cb1c0beee61b
was not included in 16.2.11
So, in a setup like ours, with *many* devices, a simple "ceph-volume raw
list" now takes over 10 minutes to run (instead of 5 seconds in 16.2.10).
As a result, the service files that cephadm generates
[Service]
LimitNOFILE=1048576
LimitNPROC=1048576
EnvironmentFile=-/etc/environment
ExecStart=/bin/bash
/var/lib/ceph/5406fed0-d52b-11ec-beff-7ed30a54847b/%i/unit.run
ExecStop=-/bin/bash -c '/bin/podman stop
ceph-5406fed0-d52b-11ec-beff-7ed30a54847b-%i ; bash
/var/lib/ceph/5406fed0-d52b-11ec-beff-7ed30a54847b/%i/unit.stop'
ExecStopPost=-/bin/bash
/var/lib/ceph/5406fed0-d52b-11ec-beff-7ed30a54847b/%i/unit.poststop
KillMode=none
Restart=on-failure
RestartSec=10s
TimeoutStartSec=120
TimeoutStopSec=120
StartLimitInterval=30min
StartLimitBurst=5
ExecStartPre=-/bin/rm -f %t/%n-pid %t/%n-cid
ExecStopPost=-/bin/rm -f %t/%n-pid %t/%n-cid
Type=forking
PIDFile=%t/%n-pid
Delegate=yes
will repeatedly be marked as failed, as they take over 2 minutes to run
now. This tells systemd to restart, and we now have an infinite loop, as
the 5 restarts takes over 50 minutes, it never even triggers the
StarLimitInterval, leaving this OSD in an infinite loop over listing the
n^2 devices (which, as a bonus, is also filling up the root disk with an
enormous amount of repeated logging in ceph-volume.log as it infinitely
tries to figure out if a block device is a bluestore)
And trying to just fix the service or unit files manually to at least just
stop this container from being incorrectly restarted over and over, is also
a dead end, since the orchestration stuff just overwrites this
automatically, and restarts the services again.
I found it seemed to be
/var/lib/ceph/5406fed0-d52b-11ec-beff-7ed30a54847b/cephadm.8d0364fef6c92fc3580b0d022e32241348e6f11a7694d2b957cdafcb9d059ff2
on my system that generated these files, so i tried tweaking that to have
the necessary 1200 second TimeoutStart and finally that managed to get the
darn container to stop restarting endlessly. (I admit i'm very fuzzy on how
these services and orchestration stuff is triggered as i usually don't work
on our storage stuff)
Still though, it takes 11 minutes to start each OSD service now, so this
isn't great.
We wanted to revert back to 16.2.10 but it turns out to also be a no-go, as
a new operation added to bluefs https://github.com/ceph/ceph/pull/42750 in
16.2.11 (though this isn't mentioned in the changelogs, i had to compare
the source code to see that it was in fact added 16.2.11). So trying to
revert an OSD then fails with:
debug 2023-04-04T11:42:45.927+0000 7f2c12f6a200 -1 bluefs _replay 0x100000:
stop: unrecognized op 12
debug 2023-04-04T11:42:45.927+0000 7f2c12f6a200 -1 bluefs mount failed to
replay log: (5) Input/output error
debug 2023-04-04T11:42:45.927+0000 7f2c12f6a200 -1
bluestore(/var/lib/ceph/osd/ceph-10) _open_bluefs failed bluefs mount: (5)
Input/output error
debug 2023-04-04T11:42:45.927+0000 7f2c12f6a200 -1
bluestore(/var/lib/ceph/osd/ceph-10) _open_db failed to prepare db
environment:
debug 2023-04-04T11:42:45.927+0000 7f2c12f6a200 1 bdev(0x5590e80a0400
/var/lib/ceph/osd/ceph-10/block) close
debug 2023-04-04T11:42:46.153+0000 7f2c12f6a200 -1 osd.10 0 OSD:init:
unable to mount object store
debug 2023-04-04T11:42:46.153+0000 7f2c12f6a200 -1 ** ERROR: osd init
failed: (5) Input/output error
Ouch
Best regards, Mikael
_______________________________________________
ceph-users mailing list -- ceph-users(a)ceph.io
To unsubscribe send an email to ceph-users-leave(a)ceph.io
400
days inactive
401
days old
3 comments
3 participants
participants (3)
-
Chris Dunlop -
Frank Schilder -
Mikael Öhman