diff --git a/.github/workflows/tests.yml b/.github/workflows/tests.yml index 8f26304c..4c491a57 100644 --- a/.github/workflows/tests.yml +++ b/.github/workflows/tests.yml @@ -133,6 +133,10 @@ jobs: name: Test MicroCeph Cluster features. suite: cluster-tests + - id: rgw-datalog-crash-tests + name: Regression test for RGW datalog admin request segfault (issue #810) + suite: rgw-datalog-crash-tests + - id: rbd-replication-test name: Test MicroCeph RBD Remote Replication features. suite: rbd-replication-test diff --git a/snap/snapcraft.yaml b/snap/snapcraft.yaml index 71728465..a8920b84 100644 --- a/snap/snapcraft.yaml +++ b/snap/snapcraft.yaml @@ -12,7 +12,7 @@ confinement: strict package-repositories: - type: apt - ppa: lmlogiudice/ceph-tentacle-rc + ppa: johnramsden/noble-caracal-ceph-tentacle plugs: load-rbd: diff --git a/tests/robot/README.md b/tests/robot/README.md index 3b57a8f3..99b6b359 100644 --- a/tests/robot/README.md +++ b/tests/robot/README.md @@ -73,13 +73,14 @@ Each directory under `tests/robot/` is a suite: api-tests nfs-test availability-zone-tests nfs-multinode-test cephadm-adopt-test rbd-replication-test -cephfs-replication-test single-system-tests -cluster-tests static-checks -dsl-functional-tests test-maintenance-modes -loop-file-tests test-sequential-mon-host-refresh -messenger-v2-tests unit-tests -multi-node-tests upgrade-reef-tests +cephfs-replication-test rgw-datalog-crash-tests +cluster-tests single-system-tests +dsl-functional-tests static-checks +loop-file-tests test-maintenance-modes +messenger-v2-tests test-sequential-mon-host-refresh +multi-node-tests unit-tests multi-node-tests-with-custom-microceph-ip + upgrade-reef-tests wal-db-tests wiping-test ``` diff --git a/tests/robot/resources/microceph_harness.py b/tests/robot/resources/microceph_harness.py index 12f17440..23c29f1a 100644 --- a/tests/robot/resources/microceph_harness.py +++ b/tests/robot/resources/microceph_harness.py @@ -10,6 +10,7 @@ import ipaddress import json import re +import shlex import subprocess import tempfile import time @@ -28,6 +29,7 @@ rbd_primary_image_count, rbd_synced_image_count, ) +from rgw_admin_ops import rgw_user_s3_credentials from snap_services import enabled_active_services from streaming_process import run_streaming_process @@ -848,6 +850,90 @@ def read_base64_file_from_container(self, container, path): # Non-raising (check=False), matching the previous run_in_container_unchecked call. return self.exec_in_container(container, "sudo", "base64", "-w0", path, timeout=30, quiet=True).stdout.strip() + # ----------------------------------------------------------------------- + # RGW admin-ops API + # ----------------------------------------------------------------------- + + def create_rgw_system_user(self, uid, display_name): + """Creates a system RGW user on the outer VM, returning its S3 key pair. + + A system user is what the /admin/ endpoints need. RGW checks the per-op + cap first but falls back to is_admin() when it is absent, and is_admin() + is true for a --system user, so no --caps argument is required. An + already-existing uid is reused rather than failing the keyword. + + Runs quiet: the secret key still reaches log.html but is kept off the + CI console. + """ + existing = self.run_in_vm( + f"sudo microceph.radosgw-admin user info --uid={uid}", 60, quiet=True) + if existing.rc == 0: + return rgw_user_s3_credentials(existing.stdout) + created = self.run_in_vm_and_check( + f"sudo microceph.radosgw-admin user create --uid={uid} " + f"--display-name={display_name} --system", + 60, quiet=True) + return rgw_user_s3_credentials(created.stdout) + + def send_signed_rgw_admin_request(self, access_key, secret_key, query, timeout=60): + """Issues one SigV4-signed GET against the outer VM's RGW admin-ops API. + + *query* is the query string appended to /admin/log?. Returns the raw + exec result; callers split its stdout with Curl Body And Status. + + Deliberately non-raising: a radosgw that dies mid-request makes curl + exit 52 ("Empty reply from server"), and that outcome has to reach the + assertions rather than abort the keyword. The command is a single curl + with no pipeline, so bash's -e/-o pipefail cannot alter the rc that + curl itself returns. + + The credential is shell-quoted rather than interpolated: RGW secrets + are drawn from an alphabet that includes '/' and '+', and Ceph's JSON + formatter escapes the slashes, so nothing here should depend on the + generated key happening to be free of shell metacharacters. + """ + credential = shlex.quote(f"{access_key}:{secret_key}") + return self.run_in_vm( + f"curl -sS --max-time 20 -w '\\n%{{http_code}}' " + f'--aws-sigv4 "aws:amz:us-east-1:s3" --user {credential} ' + f'"http://localhost:80/admin/log?{query}"', + timeout, + ) + + # ----------------------------------------------------------------------- + # Daemon crash forensics + # ----------------------------------------------------------------------- + + def get_snap_service_restart_count(self, service): + """Returns systemd's NRestarts counter for snap.microceph..service. + + A daemon killed by a signal is restarted by systemd, so this counter + moving across a narrow window corroborates a crash independently of any + log wording. + """ + result = self.run_in_vm( + f"systemctl show snap.microceph.{service}.service --property=NRestarts", + 30, quiet=True) + return self._safe_int(result.stdout.partition("=")[2]) + + def get_vm_file_size(self, path): + """Returns the size of *path* in the outer VM in bytes, or 0 if absent.""" + result = self.run_in_vm(f"sudo stat -c %s -- {path}", 30, quiet=True) + if result.rc != 0: + return 0 + return self._safe_int(result.stdout) + + def read_vm_file_from_offset(self, path, offset): + """Returns the contents of *path* in the outer VM from byte *offset* on. + + Lets a test look at only what a daemon logged since a known point, so a + stale banner from an earlier crash cannot match. tail counts bytes from + 1, hence the +1. + """ + result = self.run_in_vm_and_check( + f"sudo tail -c +{int(offset) + 1} -- {path}", 30, quiet=True) + return result.stdout + # ----------------------------------------------------------------------- # OSD pollers # ----------------------------------------------------------------------- diff --git a/tests/robot/resources/microceph_harness.resource b/tests/robot/resources/microceph_harness.resource index 4a3a5e8a..b23f18eb 100644 --- a/tests/robot/resources/microceph_harness.resource +++ b/tests/robot/resources/microceph_harness.resource @@ -9,6 +9,7 @@ Library microceph_harness.py Library streaming_process.py Library snap_services.py Library cephfs_replication.py +Library rgw_admin_ops.py *** Variables *** ${SNAP_PATH} ${EMPTY} diff --git a/tests/robot/resources/rgw_admin_ops.py b/tests/robot/resources/rgw_admin_ops.py new file mode 100644 index 00000000..fc0e3714 --- /dev/null +++ b/tests/robot/resources/rgw_admin_ops.py @@ -0,0 +1,126 @@ +"""Robot Framework library: parsing of RGW admin-ops API responses. + +Keeps the JSON shape checks for the /admin/log endpoints, and the rgw log +crash-signature match the issue #810 regression suite relies on, out of the +.robot suites as single unit-testable functions. + +The shape helpers deliberately raise rather than return a bool: a response that +is empty, truncated, or an error document means the request never really +reached the handler under test, and a regression suite that only asked "did +anything come back" would pass in exactly that case. +""" + +import json +import re + +# Ceph's fatal-signal handler always writes this banner, independent of the +# configured debug level, followed by a backtrace. +CRASH_BANNER = "Caught signal (Segmentation fault)" + +# Frames unique to the issue #810 crash path. The banner alone would also match +# an unrelated segfault elsewhere in the daemon, so a match requires both. +CRASH_FRAMES = re.compile(r"run_coro|RGWOp_DATALog|rethrow_exception") + + +def curl_body_and_status(curl_stdout): + """Split the stdout of ``curl -w '\\n%{http_code}'`` into (body, status). + + curl writes the status code on its own final line after the response body, + so everything before the last newline is the body. A request whose server + died part-way through produces no body and the status ``000``. + """ + body, _, status = curl_stdout.rpartition("\n") + return body.strip(), status.strip() + + +def rgw_user_s3_credentials(user_json_text): + """Return the (access_key, secret_key) of the first S3 key of an RGW user. + + *user_json_text* is the stdout of ``radosgw-admin user create`` or + ``radosgw-admin user info``. + """ + doc = _decode(user_json_text, "radosgw-admin user") + keys = doc.get("keys") + if not keys: + raise AssertionError(f"radosgw-admin user has no S3 keys: {user_json_text!r}") + return keys[0]["access_key"], keys[0]["secret_key"] + + +def datalog_num_objects(body): + """Return num_objects from a ``GET /admin/log?type=data`` response. + + The healthy document is ``{"num_objects": }``, written by + RGWOp_DATALog_Info::send_response. + """ + doc = _decode(body, "datalog info") + if "num_objects" not in doc: + raise AssertionError(f'datalog info response has no "num_objects": {body!r}') + return doc["num_objects"] + + +def datalog_shard_info_marker(body): + """Return the marker from a ``GET /admin/log?type=data&id=&info`` response. + + The healthy document is ``{"marker": , "last_update": }``. + RGWOp_DATALog_ShardInfo::send_response writes it as + ``encode_json("info", RGWDataChangesLogInfo)``, but "info" is the root + section and Ceph's JSON formatter drops the root section's name, so the + dumped fields land at the top level rather than nested under it -- the same + reason ``open_object_section("num_objects")`` yields ``{"num_objects": }`` + and not ``{"num_objects": {"num_objects": }}``. + + An idle shard's marker is legitimately empty, so callers must not treat "" + as a failure -- returning at all is what this asserts. + """ + doc = _decode(body, "datalog shard info") + missing = [key for key in ("marker", "last_update") if key not in doc] + if missing: + raise AssertionError(f"datalog shard info is missing {missing}: {body!r}") + return doc["marker"] + + +def datalog_list_entry_count(body): + """Return the entry count of a ``GET /admin/log?type=data&id=`` response. + + The healthy document is ``{"marker": ..., "last_update": ..., "truncated": + , "entries": [...]}``, written by RGWOp_DATALog_List::send_response. + An idle shard returns an empty array, so 0 is a valid result. + """ + doc = _decode(body, "datalog list") + entries = doc.get("entries") + if not isinstance(entries, list): + raise AssertionError(f'datalog list response has no "entries" array: {body!r}') + return len(entries) + + +def datalog_crash_signature(log_text, context_lines=20): + """Return the issue #810 SIGSEGV excerpt in *log_text*, or "" if absent. + + A match needs the fatal-signal banner followed within *context_lines* by a + frame from the crashing path, so an unrelated segfault elsewhere in radosgw + is not misreported as this bug. + + *log_text* must be only the log written since the request under test -- + passing a whole log file would match a stale banner from an earlier crash. + """ + lines = log_text.splitlines() + for index, line in enumerate(lines): + if CRASH_BANNER not in line: + continue + excerpt = "\n".join(lines[index:index + context_lines]) + if CRASH_FRAMES.search(excerpt): + return excerpt + return "" + + +def _decode(body, what): + """json.loads *body*, reporting a parse failure as a response-shape error.""" + if not body: + raise AssertionError(f"{what} response body is empty -- nothing came back") + try: + doc = json.loads(body) + except ValueError as exc: + raise AssertionError(f"{what} response is not JSON ({exc}): {body!r}") + if not isinstance(doc, dict): + raise AssertionError(f"{what} response is not a JSON object: {body!r}") + return doc diff --git a/tests/robot/resources/test_harness_helpers.py b/tests/robot/resources/test_harness_helpers.py index 00731477..a23da75e 100644 --- a/tests/robot/resources/test_harness_helpers.py +++ b/tests/robot/resources/test_harness_helpers.py @@ -22,6 +22,14 @@ rbd_primary_image_count, rbd_synced_image_count, ) +from rgw_admin_ops import ( + curl_body_and_status, + datalog_crash_signature, + datalog_list_entry_count, + datalog_num_objects, + datalog_shard_info_marker, + rgw_user_s3_credentials, +) from streaming_process import run_streaming_process @@ -1066,4 +1074,141 @@ def test_log_exec_quiet_keeps_console_clean(monkeypatch): def test_log_exec_no_output_prints_nothing(monkeypatch): cap = _with_logger(monkeypatch) H()._log_exec("mkdir -p ~/x", _Res(0, "", ""), quiet=False) - assert cap.console_lines == [] \ No newline at end of file + assert cap.console_lines == [] + + +# --------------------------------------------------------------------------- +# rgw_admin_ops -- RGW admin-ops responses and the issue #810 crash signature +# --------------------------------------------------------------------------- + +def test_curl_body_and_status_splits_trailing_code(): + assert curl_body_and_status('{"num_objects":128}\n200') == ('{"num_objects":128}', "200") + + +def test_curl_body_and_status_empty_body_on_dropped_connection(): + # curl still writes its -w output when the server dies mid-request. + assert curl_body_and_status("\n000") == ("", "000") + + +def test_curl_body_and_status_body_containing_newlines(): + assert curl_body_and_status('{\n "info": {}\n}\n200') == ('{\n "info": {}\n}', "200") + + +def test_rgw_user_s3_credentials_takes_first_key(): + doc = '{"user_id": "u", "keys": [{"access_key": "AK", "secret_key": "SK"}]}' + assert rgw_user_s3_credentials(doc) == ("AK", "SK") + + +def test_rgw_user_s3_credentials_rejects_keyless_user(): + with pytest.raises(AssertionError) as exc: + rgw_user_s3_credentials('{"user_id": "u", "keys": []}') + assert "no S3 keys" in str(exc.value) + + +def test_datalog_num_objects_reads_shard_count(): + assert datalog_num_objects('{"num_objects":128}') == 128 + + +def test_datalog_num_objects_rejects_wrong_document(): + with pytest.raises(AssertionError) as exc: + datalog_num_objects('{"info": {}}') + assert "num_objects" in str(exc.value) + + +def test_datalog_shard_info_marker_reads_marker(): + # encode_json("info", ...) is the root section, whose name Ceph's formatter + # drops, so the fields are top level and not nested under "info". + body = '{"marker":"1_1755000000.1_5","last_update":"2026-08-14T18:00:00.0Z"}' + assert datalog_shard_info_marker(body) == "1_1755000000.1_5" + + +def test_datalog_shard_info_marker_allows_empty_marker_on_idle_shard(): + # Verbatim from radosgw 20.2.1 on a freshly enabled gateway. + assert datalog_shard_info_marker('{"marker":"","last_update":"0.000000"}') == "" + + +def test_datalog_shard_info_marker_rejects_missing_field(): + with pytest.raises(AssertionError) as exc: + datalog_shard_info_marker('{"marker":""}') + assert "last_update" in str(exc.value) + + +def test_datalog_shard_info_marker_rejects_empty_body(): + # What a crashed gateway leaves behind: no response at all. + with pytest.raises(AssertionError) as exc: + datalog_shard_info_marker("") + assert "nothing came back" in str(exc.value) + + +def test_datalog_shard_info_marker_rejects_html_error_page(): + with pytest.raises(AssertionError) as exc: + datalog_shard_info_marker("502 Bad Gateway") + assert "not JSON" in str(exc.value) + + +def test_datalog_list_entry_count_counts_entries(): + body = '{"marker":"m","last_update":"0.000000","truncated":false,"entries":[1,2,3]}' + assert datalog_list_entry_count(body) == 3 + + +def test_datalog_list_entry_count_zero_on_idle_shard(): + # Verbatim from radosgw 20.2.1 on a freshly enabled gateway. + body = '{"marker":"","last_update":"0.000000","truncated":false,"entries":[]}' + assert datalog_list_entry_count(body) == 0 + + +def test_datalog_shard_info_and_list_shapes_do_not_collide(): + # List is ShardInfo's document plus truncated/entries, so the shard-info + # check must not accidentally accept a list response as its own shape being + # the whole story -- each parser asserts on the field it actually needs. + list_body = '{"marker":"m","last_update":"0.000000","truncated":false,"entries":[]}' + assert datalog_shard_info_marker(list_body) == "m" + with pytest.raises(AssertionError): + datalog_list_entry_count('{"marker":"m","last_update":"0.000000"}') + + +def test_datalog_list_entry_count_rejects_missing_entries(): + with pytest.raises(AssertionError) as exc: + datalog_list_entry_count('{"marker":"m"}') + assert "entries" in str(exc.value) + + +CRASH_LOG = """2026-08-14T18:00:00.000+0000 7f0 -1 *** Caught signal (Segmentation fault) ** + in thread 7f0 thread_name:radosgw + ceph version 20.2.1 (6a49aff47758778a5f5951e731d437c317f72fb2) tentacle (stable) + 1: /lib/x86_64-linux-gnu/libc.so.6(+0x45330) [0x7f0] + 2: (std::rethrow_exception(std::__exception_ptr::exception_ptr)+0x0) [0x7f0] + 3: (int rgw::run_coro(DoutPrefixProvider*, ...)+0x1a1) [0x7f0] + 4: (RGWOp_DATALog_ShardInfo::execute(optional_yield)+0x9d) [0x7f0] + 5: (rgw_process_authenticated(RGWHandler_REST*, RGWOp*&, ...)+0x8a1) [0x7f0] +""" + + +def test_datalog_crash_signature_matches_banner_with_frames(): + excerpt = datalog_crash_signature(CRASH_LOG) + assert "Caught signal (Segmentation fault)" in excerpt + assert "RGWOp_DATALog_ShardInfo" in excerpt + + +def test_datalog_crash_signature_ignores_unrelated_segfault(): + # A segfault elsewhere in radosgw must not be reported as issue #810. + other = """*** Caught signal (Segmentation fault) ** + 1: (RGWPutObj::execute(optional_yield)+0x10) [0x7f0] + 2: (rgw_process_authenticated(...)+0x8a1) [0x7f0] +""" + assert datalog_crash_signature(other) == "" + + +def test_datalog_crash_signature_ignores_frames_without_banner(): + # run_coro appears in ordinary debug output; on its own it means nothing. + assert datalog_crash_signature("3: (int rgw::run_coro<...>) returned 0\n") == "" + + +def test_datalog_crash_signature_empty_on_clean_log(): + assert datalog_crash_signature("2026-08-14T18:00:00.000+0000 7f0 1 civetweb: 0x0: GET /\n") == "" + + +def test_datalog_crash_signature_ignores_frames_beyond_context_window(): + # The frame must belong to *this* backtrace, not one further down the log. + log = "*** Caught signal (Segmentation fault) **\n" + ("padding\n" * 30) + "run_coro\n" + assert datalog_crash_signature(log, context_lines=20) == "" \ No newline at end of file diff --git a/tests/robot/rgw-datalog-crash-tests/rgw_datalog_crash_tests.robot b/tests/robot/rgw-datalog-crash-tests/rgw_datalog_crash_tests.robot new file mode 100644 index 00000000..b3d95d27 --- /dev/null +++ b/tests/robot/rgw-datalog-crash-tests/rgw_datalog_crash_tests.robot @@ -0,0 +1,108 @@ +*** Settings *** +Documentation rgw-datalog-crash-tests +... Regression coverage for issue #810: a signed request to RGW's datalog +... admin endpoints segfaults radosgw when Ceph is built against a Boost +... whose asio spawn handler rethrows a completion's std::exception_ptr +... without checking it holds an exception. rgw::run_coro's stackful-yield +... branch is the only co_spawn(..., yield_context) user in the Ceph tree +... and the datalog admin ops are its only callers, so every +... GET /admin/log?type=data&id=N kills the gateway on an affected build. +... One node, one zone: multisite is how the bug surfaced in the field +... (data sync polls these endpoints every cycle) but the datalog is +... started for every non-raw RGW driver, so no peer zone is needed to +... trigger it. +Resource ../resources/microceph_harness.resource +Suite Setup RGW Datalog Crash Suite Setup +Suite Teardown Teardown MicroCeph Environment +Test Tags single-node rgw regression issue-810 lxd integration + +*** Variables *** +${RGW_ADMIN_UID} datalogprobe +${RGW_LOG} /var/snap/microceph/common/logs/ceph-client.radosgw.gateway.log + +*** Keywords *** +RGW Datalog Crash Suite Setup + Launch Outer Test VM vm_name=microceph-rgw-datalog-vm + Copy Scripts To VM + Copy Snap To VM + Install Tools + Install And Bootstrap MicroCeph + Run In VM And Check sudo microceph disk add loop,1G,3 120 + Wait For OSD Count 3 + Enable RGW + # Fail here, not mid-assertion, if the gateway's log is not where the crash + # checks will look for it. + Run In VM And Check test -f ${RGW_LOG} 30 + ${access_key} ${secret_key}= Create RGW System User ${RGW_ADMIN_UID} ${RGW_ADMIN_UID} + Set Suite Variable ${RGW_ACCESS_KEY} ${access_key} + Set Suite Variable ${RGW_SECRET_KEY} ${secret_key} + +RGW Must Survive Datalog Query + [Documentation] Sends one signed GET to /admin/log? and fails if + ... radosgw died servicing it. Returns the response body so the caller + ... can check the handler actually answered. + ... + ... Two independent signals, both required. The primary is the rgw log: + ... the dying process writes its own fatal-signal banner and backtrace, + ... and only the log names the crashing frames, so it cannot be confused + ... with an OOM kill or a deliberate restart. Only the log written since + ... this request is examined. The corroborating signal is systemd's + ... restart counter, which owes nothing to log wording and so still + ... fires if a future Ceph reword breaks the pattern. + ... + ... The HTTP status is checked last and is not a crash signal -- curl + ... reports the same "empty reply" for a dropped connection as for a + ... dead server -- but asserting it here is what stops the test passing + ... when the request never reached the handler at all. + [Arguments] ${query} + Wait For RGW 1 + ${restarts_before}= Get Snap Service Restart Count rgw + ${log_size_before}= Get VM File Size ${RGW_LOG} + ${result}= Send Signed RGW Admin Request ${RGW_ACCESS_KEY} ${RGW_SECRET_KEY} ${query} + # Let the dying process finish flushing its backtrace and systemd notice the + # exit before either signal is read. + Sleep 3s + ${new_log}= Read VM File From Offset ${RGW_LOG} ${log_size_before} + ${crash}= Datalog Crash Signature ${new_log} + Should Be Empty ${crash} + ... msg=radosgw segfaulted servicing /admin/log?${query} (issue #810):\n${crash} + ${restarts_after}= Get Snap Service Restart Count rgw + Should Be Equal As Integers ${restarts_before} ${restarts_after} + ... msg=snap.microceph.rgw restarted (NRestarts ${restarts_before} -> ${restarts_after}) while servicing /admin/log?${query} + ${body} ${status}= Curl Body And Status ${result.stdout} + Should Be Equal As Strings ${status} 200 + ... msg=/admin/log?${query} answered HTTP ${status}, not 200 (curl rc ${result.rc}) + RETURN ${body} + +*** Test Cases *** +Test Datalog Info Query Succeeds + [Documentation] Control case. GET /admin/log?type=data dispatches to + ... RGWOp_DATALog_Info, which reads the shard count straight from config + ... and never enters a coroutine, so it answers even on an affected + ... build. A failure here means the cluster or the request signing is + ... broken, not that issue #810 is present -- fix that before reading + ... anything into the other two cases. + ${body}= RGW Must Survive Datalog Query type=data + ${num_objects}= Datalog Num Objects ${body} + Should Be True ${num_objects} > 0 + ... msg=datalog reports ${num_objects} shards, so there is no shard 0 for the other cases to query + +Test Datalog Shard Info Query Does Not Crash RGW + [Documentation] The request from issue #810. Having both id and info + ... dispatches to RGWOp_DATALog_ShardInfo, which fetches the shard's + ... marker through rgw::run_coro's stackful-yield branch -- the + ... co_spawn(..., yield) call a mismatched Boost turns into a null + ... exception_ptr rethrow on the success path. + ${body}= RGW Must Survive Datalog Query type=data&id=0&info + ${marker}= Datalog Shard Info Marker ${body} + Log datalog shard 0 marker: '${marker}' + +Test Datalog List Query Does Not Crash RGW + [Documentation] The sibling endpoint. id without info dispatches to + ... RGWOp_DATALog_List, which drives the same run_coro branch twice + ... (list_entries then get_info) and is equally exposed. Multisite data + ... sync polls this alongside shard-info, so leaving it uncovered would + ... let half the reported failure back in. + ${body}= RGW Must Survive Datalog Query type=data&id=0 + ${entries}= Datalog List Entry Count ${body} + Log datalog shard 0 returned ${entries} entries