Some tests in omicron-nexus::test_all stall out and hang

[sunshowers]

Some example buildomat runs:

On main: https://github.com/oxidecomputer/omicron/runs/20227366854

omicron-nexus::test_all integration_tests::projects::test_project_deletion_with_vpc
omicron-nexus::test_all integration_tests::silos::test_saml_idp_metadata_data_valid

On a PR: https://github.com/oxidecomputer/omicron/pull/4773/checks?check_run_id=20231856893

omicron-nexus::test_all integration_tests::console_api::test_session_me_groups

[rcgoodfellow]

I have what feels like a similar issue, but with different tests hanging. In this run, the following tests hung.

omicron-nexus::test_all integration_tests::rack::test_rack_initialization
omicron-nexus app::update::tests::test_update_deployments

Here is a link to the CI job. In this run, the illumos integration tests passed, but the Linux ones did not. This also comes from a commit that only changed an unrelated buildomat script and the previous commit on that branch passed CI on the Linux build-and-test job.

[smklein]

Just observed this failure here: https://github.com/oxidecomputer/omicron/pull/4783/checks?check_run_id=20286750269

omicron-nexus::test_all integration_tests::images::test_make_disk_from_image appears to have been running non-stop for almost two hours. Looks like this happened on Ubuntu-22.04.

Reading what's going on from just the Nexus log is getting kinda difficult - the rendered log is 25,000 lines long, of which ~20,000 of those lines are from BackgroundTasks.

[sunshowers]

#4780 should hopefully land very soon, just waiting on the deploy job.

[smklein]

Couple more cases that just showed up: #4783

[5411](https://buildomat.eng.oxide.computer/wg/0/details/01HKPQ0KFEGHYZHDSCY6RC9JMB/1BHKCrXA6UrkcAbAz5lm6dq48ZkaSiQTlDYpWR0cbxtrF0bK/01HKPQ1NSF26P9RMQR6KSEPM7V#S5411)	2024-01-09T11:12:47.656Z	   Canceling due to signal: 2 tests still running
[5412](https://buildomat.eng.oxide.computer/wg/0/details/01HKPQ0KFEGHYZHDSCY6RC9JMB/1BHKCrXA6UrkcAbAz5lm6dq48ZkaSiQTlDYpWR0cbxtrF0bK/01HKPQ1NSF26P9RMQR6KSEPM7V#S5412)	2024-01-09T11:12:47.665Z	     SIGTERM [6351.638s] omicron-nexus::test_all integration_tests::oximeter::test_oximeter_reregistration
[5413](https://buildomat.eng.oxide.computer/wg/0/details/01HKPQ0KFEGHYZHDSCY6RC9JMB/1BHKCrXA6UrkcAbAz5lm6dq48ZkaSiQTlDYpWR0cbxtrF0bK/01HKPQ1NSF26P9RMQR6KSEPM7V#S5413)	2024-01-09T11:12:47.669Z	     SIGTERM [6220.087s] omicron-nexus::test_all integration_tests::role_assignments::test_role_assignments_silo

(These also look wholly unrelated to the PR, but same symptom. Something must have merged recently to cause this timeout across such a broad set of tests to trigger much more frequently)

[sunshowers]

Here's a post-#4780 failure: https://github.com/oxidecomputer/omicron/runs/20299512003

Link to failing stdout/stderr. Sadly this doesn't appear to be helpful.

[sunshowers]

While looking at the logs I found this interesting issue:

2024-01-09T12:32:00.369Z	WARN	test_reject_creating_disk_from_snapshot (clickhouse-client): failed to read version
    collector_id = 39e6175b-4df2-4730-b11d-cbc1e60a2e78
    error = Telemetry database unavailable: error sending request for url (http://[::1]:465/?output_format_json_quote_64bit_integers=0): error trying to connect: tcp connect error: Connection refused (os error 111)
    file = oximeter/db/src/client.rs:868
    id = dcf208b1-e86c-4472-a0ac-8874804fe091
2024-01-09T12:32:00.371Z	WARN	test_reject_creating_disk_from_snapshot (oximeter): failed to create ClickHouse client
    error = Database(DatabaseUnavailable("error sending request for url (http://[::1]:465/?output_format_json_quote_64bit_integers=0): error trying to connect: tcp connect error: Connection refused (os error 111)"))
    file = oximeter/collector/src/lib.rs:213
    retry_after = 167.267012453s

The port number seems suspiciously low -- it's definitely below 1024 which is strange.

Wondering if #4755 is responsible. I'm not sure exactly why but looking at commits on main, it looks like test_all started flaking out after that commit landed.

[bnaecker]

That's an interesting correlation, and I also don't see why that commit would cause it. For background, ClickHouse is started with a port of 0; it gets some available one from the OS; and then we fish the actual port it bound out of the log file. That machinery has all worked pretty well for a while now, but it's possible moving the log files around introduced some problem. It also seems possible to get a port < 1024 when run with elevated priveleges, so perhaps this is a red herring if the tests are run that way.

[sunshowers]

We sadly don't have logs for clickhouse itself as part of the failed test uploads -- we should probably work to upload them.

[bnaecker]

Hmm, I'm not sure why we don't have those ClickHouse log files. It sure looks like TMPDIR is set to /var/tmp/omicron_tmp in .github/buildomat/build-and-test.sh, and the ClickHouseInstance will use Utf8TempDir for storage. Is it possible that the buildomat rules for uploading artifacts misses those? IIRC, the temporary directories for ClickHouse usually look like /tmp/.tmppEavQr, so perhaps the leading . causes them to be missed.

[bnaecker]

I don't think that's it. Buildomat uses glob to find files matching the output rules, and that crate seems to find tempdirs created with a leading . just fine.