Nexus node timing out on API requests

[askfongjojo]

One of the three nexus nodes on rack2 (sled 21) is timing out on API requests. The log lines show that the request is able to reach the nexus (i.e., not a network path issue) but no further progress is made after that:

root@oxz_nexus_014e6bb4:~# tail -f `svcs -L nexus` | egrep -v 'producer|metrics|query' | looker
16:49:05.400Z DEBG 014e6bb4-1937-467b-935c-f26b0cbf9700 (ServerContext): resolved TLS certificate
    certificate = TlsCertificate { digest: "e3344ca8626a50e6e8a9807fe590fb0c38642ebc212112f395929f7ada7d47e9" }
    server_name = oxide.sys.rack2.eng.oxide.computer
    silo_id = 7bd7623a-68ed-4636-8ecb-b59e3b068787
16:49:05.482Z INFO 014e6bb4-1937-467b-935c-f26b0cbf9700 (dropshot_external): accepted connection
    file = /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/dropshot-0.16.4/src/server.rs:1025
    local_addr = 172.30.2.5:443
    remote_addr = 172.20.17.42:64331
16:49:05.562Z DEBG 014e6bb4-1937-467b-935c-f26b0cbf9700 (ServerContext): roles
    roles = RoleSet { roles: {} }
16:49:05.563Z DEBG 014e6bb4-1937-467b-935c-f26b0cbf9700 (ServerContext): authorize result
    action = Query
    actor = Some(Actor::UserBuiltin { user_builtin_id: 001de000-05e4-4000-8000-000000000003 (built_in_user), .. })
    resource = Database
    result = Ok(())
16:49:05.599Z INFO 014e6bb4-1937-467b-935c-f26b0cbf9700 (dropshot_internal): accepted connection
    file = /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/dropshot-0.16.4/src/server.rs:1025
    local_addr = [fd00:1122:3344:102::2f]:12221
    remote_addr = [fd00:1122:3344:106::1:dbd]:58972
16:49:07.076Z INFO 014e6bb4-1937-467b-935c-f26b0cbf9700 (dropshot_internal): accepted connection
    file = /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/dropshot-0.16.4/src/server.rs:1025
    local_addr = [fd00:1122:3344:102::2f]:12221
    remote_addr = [fd00:1122:3344:104::1]:54171
16:49:07.493Z INFO 014e6bb4-1937-467b-935c-f26b0cbf9700 (dropshot_internal): accepted connection
    file = /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/dropshot-0.16.4/src/server.rs:1025
    local_addr = [fd00:1122:3344:102::2f]:12221
    remote_addr = [fd00:1122:3344:108::2]:50482
16:49:07.856Z INFO 014e6bb4-1937-467b-935c-f26b0cbf9700 (dropshot_internal): accepted connection
    file = /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/dropshot-0.16.4/src/server.rs:1025
    local_addr = [fd00:1122:3344:102::2f]:12221
    remote_addr = [fd00:1122:3344:10a::2e]:53239
16:49:09.327Z INFO 014e6bb4-1937-467b-935c-f26b0cbf9700 (dropshot_internal): accepted connection
    file = /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/dropshot-0.16.4/src/server.rs:1025
    local_addr = [fd00:1122:3344:102::2f]:12221
    remote_addr = [fd00:1122:3344:102::1:ca8]:53763
16:49:09.615Z INFO 014e6bb4-1937-467b-935c-f26b0cbf9700 (dropshot_internal): accepted connection
    file = /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/dropshot-0.16.4/src/server.rs:1025
    local_addr = [fd00:1122:3344:102::2f]:12221
    remote_addr = [fd00:1122:3344:108::2]:46410
16:49:09.658Z INFO 014e6bb4-1937-467b-935c-f26b0cbf9700 (dropshot_internal): accepted connection
    file = /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/dropshot-0.16.4/src/server.rs:1025
    local_addr = [fd00:1122:3344:102::2f]:12221
    remote_addr = [fd00:1122:3344:102::1:cb5]:42434
16:49:10.364Z INFO 014e6bb4-1937-467b-935c-f26b0cbf9700 (dropshot_internal): accepted connection
    file = /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/dropshot-0.16.4/src/server.rs:1025
    local_addr = [fd00:1122:3344:102::2f]:12221
    remote_addr = [fd00:1122:3344:104::1:b40]:45422
16:49:10.749Z INFO 014e6bb4-1937-467b-935c-f26b0cbf9700 (dropshot_internal): accepted connection
    file = /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/dropshot-0.16.4/src/server.rs:1025
    local_addr = [fd00:1122:3344:102::2f]:12221
    remote_addr = [fd00:1122:3344:10a::1:d51]:39378
16:49:11.429Z INFO 014e6bb4-1937-467b-935c-f26b0cbf9700 (dropshot_internal): accepted connection
    file = /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/dropshot-0.16.4/src/server.rs:1025
    local_addr = [fd00:1122:3344:102::2f]:12221
    remote_addr = [fd00:1122:3344:127::1:1c6]:42394
16:49:11.914Z INFO 014e6bb4-1937-467b-935c-f26b0cbf9700 (dropshot_internal): accepted connection
    file = /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/dropshot-0.16.4/src/server.rs:1025
    local_addr = [fd00:1122:3344:102::2f]:12221
    remote_addr = [fd00:1122:3344:127::1:1b9]:61847
16:49:12.587Z INFO 014e6bb4-1937-467b-935c-f26b0cbf9700 (dropshot_internal): accepted connection
    file = /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/dropshot-0.16.4/src/server.rs:1025
    local_addr = [fd00:1122:3344:102::2f]:12221
    remote_addr = [fd00:1122:3344:109::1:d9d]:51943
16:49:14.458Z INFO 014e6bb4-1937-467b-935c-f26b0cbf9700 (dropshot_internal): accepted connection
    file = /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/dropshot-0.16.4/src/server.rs:1025
    local_addr = [fd00:1122:3344:102::2f]:12221
    remote_addr = [fd00:1122:3344:107::1:b9a]:53385
16:49:14.930Z INFO 014e6bb4-1937-467b-935c-f26b0cbf9700 (dropshot_internal): accepted connection
    file = /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/dropshot-0.16.4/src/server.rs:1025
    local_addr = [fd00:1122:3344:102::2f]:12221
    remote_addr = [fd00:1122:3344:127::1:1c5]:58277
16:49:15.739Z INFO 014e6bb4-1937-467b-935c-f26b0cbf9700 (dropshot_internal): accepted connection
    file = /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/dropshot-0.16.4/src/server.rs:1025
    local_addr = [fd00:1122:3344:102::2f]:12221
    remote_addr = [fd00:1122:3344:10b::1:d68]:52502
16:49:16.429Z INFO 014e6bb4-1937-467b-935c-f26b0cbf9700 (dropshot_internal): accepted connection
    file = /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/dropshot-0.16.4/src/server.rs:1025
    local_addr = [fd00:1122:3344:102::2f]:12221
    remote_addr = [fd00:1122:3344:109::1:d97]:39305
16:49:16.478Z INFO 014e6bb4-1937-467b-935c-f26b0cbf9700 (dropshot_internal): accepted connection
    file = /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/dropshot-0.16.4/src/server.rs:1025
    local_addr = [fd00:1122:3344:102::2f]:12221
    remote_addr = [fd00:1122:3344:105::1:e85]:39013
16:49:16.969Z INFO 014e6bb4-1937-467b-935c-f26b0cbf9700 (dropshot_internal): accepted connection
    file = /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/dropshot-0.16.4/src/server.rs:1025
    local_addr = [fd00:1122:3344:102::2f]:12221
    remote_addr = [fd00:1122:3344:109::1]:36819
16:49:17.549Z INFO 014e6bb4-1937-467b-935c-f26b0cbf9700 (dropshot_internal): accepted connection
    file = /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/dropshot-0.16.4/src/server.rs:1025
    local_addr = [fd00:1122:3344:102::2f]:12221
    remote_addr = [fd00:1122:3344:107::1:ba2]:45468
16:49:18.138Z INFO 014e6bb4-1937-467b-935c-f26b0cbf9700 (dropshot_internal): accepted connection
    file = /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/dropshot-0.16.4/src/server.rs:1025
    local_addr = [fd00:1122:3344:102::2f]:12221
    remote_addr = [fd00:1122:3344:10a::1:d53]:48375
16:49:18.964Z INFO 014e6bb4-1937-467b-935c-f26b0cbf9700 (dropshot_internal): accepted connection
    file = /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/dropshot-0.16.4/src/server.rs:1025
    local_addr = [fd00:1122:3344:102::2f]:12221
    remote_addr = [fd00:1122:3344:108::1:d09]:63597
16:49:20.269Z INFO 014e6bb4-1937-467b-935c-f26b0cbf9700 (dropshot_internal): accepted connection
    file = /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/dropshot-0.16.4/src/server.rs:1025
    local_addr = [fd00:1122:3344:102::2f]:12221
    remote_addr = [fd00:1122:3344:10b::1:d6b]:37547
16:49:20.325Z INFO 014e6bb4-1937-467b-935c-f26b0cbf9700 (dropshot_internal): accepted connection
    file = /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/dropshot-0.16.4/src/server.rs:1025
    local_addr = [fd00:1122:3344:102::2f]:12221
    remote_addr = [fd00:1122:3344:108::1:d00]:43319
16:49:20.338Z WARN 014e6bb4-1937-467b-935c-f26b0cbf9700 (dropshot_external): request handling cancelled (client disconnected)
    file = /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/dropshot-0.16.4/src/server.rs:801
    latency_us = 14775729
    local_addr = 172.30.2.5:443
    method = GET
    remote_addr = 172.20.17.42:64331
    req_id = 451df565-85b0-4cb8-8b87-c8ecb731bdf4
    uri = /v1/me

Rack2 is running on 17.0.0-0.ci+git27a65080e1b.

[askfongjojo]

The nexus is also unresponsive to omdb requests:

root@oxz_switch1:~# omdb nexus background-tasks list | grep bundle
note: Nexus URL not specified.  Will pick one from DNS.
note: using DNS server for subnet fd00:1122:3344::/48
note: (if this is not right, use --dns-server to specify an alternate DNS server)
note: using Nexus URL http://[fd00:1122:3344:102::2f]:12232
Error: listing background tasks

Caused by:
    0: Communication Error: error sending request for url (http://[fd00:1122:3344:102::2f]:12232/bgtasks)
    1: error sending request for url (http://[fd00:1122:3344:102::2f]:12232/bgtasks)
    2: operation timed out

[askfongjojo]

I also happen to have a support bundle assigned on this nexus and the bundle has been stuck in collecting status:

root@[fd00:1122:3344:105::3]:32221/omicron> select * from support_bundle order by time_created desc limit 3;
                   id                  |         time_created          |   reason_for_creation   |             reason_for_failure              |   state    |               zpool_id               |              dataset_id              |            assigned_nexus            |     user_comment
---------------------------------------+-------------------------------+-------------------------+---------------------------------------------+------------+--------------------------------------+--------------------------------------+--------------------------------------+-----------------------
  c77ab161-945c-4487-aa02-89f11312b6ae | 2025-10-19 05:32:25.212662+00 | Created by external API | NULL                                        | collecting | 34dadf3f-f60c-4acc-b82b-4b0c82224222 | 1e08dc12-398d-4001-bb5c-86aa8b3842a3 | 014e6bb4-1937-467b-935c-f26b0cbf9700 | after online update
  2f507420-a01b-4722-baf1-2b949f3d4c9f | 2025-10-19 01:44:27.668817+00 | Created by external API | Nexus managing this bundle no longer exists | failed     | 613b58fc-5a80-42dc-a61c-b143cf220fb5 | 1c9b4db5-8758-4862-9d91-42273d3f9d03 | dcb27edf-5a97-459a-92c0-63d795744055 | during online update
  cd00c20a-4949-4025-963c-7b9c3efc0f31 | 2025-10-18 05:59:09.652031+00 | Created by external API | Nexus managing this bundle no longer exists | failed     | 9005671f-3d90-4ed1-be15-ad65b9a65bd5 | 1aed763c-1a6b-439e-a1f1-78b9e017bf86 | eeb9c1f9-7ce0-449c-871e-910e56c94173 | NULL

The nexus has been healthy after the rack update for at least a few hours so the stuck bundle may be related?

[davepacheco]

Initial observations

Most requests to this one Nexus instance hang. Requests that it can reject quickly do fail quickly:

root@oxz_switch1:~# curl -i http://[fd00:1122:3344:102::2f]:12232/foo
HTTP/1.1 404 Not Found
content-type: application/json
x-request-id: de9b549c-0bf8-429b-b628-9324c9f97743
content-length: 84
date: Mon, 20 Oct 2025 22:22:30 GMT

{
  "request_id": "de9b549c-0bf8-429b-b628-9324c9f97743",
  "message": "Not Found"
}root@oxz_switch1:~# 

and in fact some requests can complete:

# curl -s -i http://[fd00:1122:3344:102::2f]:12232/quiesce | less

HTTP/1.1 200 OK
content-type: application/json
x-request-id: e68d0536-60ea-4753-a9af-66cbc1d6710d
content-length: 113491177
date: Mon, 20 Oct 2025 22:23:18 GMT

{"state":{"state":"running"},...

It appears that requests that read from the database are what get stuck. This is almost everything because we do authz checks for almost everything, even on the internal API, and these read role assignments from the database.

If we look for request logs for, say, a request to GET /sagas, we get this far:

19:45:17.521Z DEBG 014e6bb4-1937-467b-935c-f26b0cbf9700 (dropshot_lockstep): authorize result
    action = Query
    actor = Some(Actor::UserBuiltin { user_builtin_id: 001de000-05e4-4000-8000-000000000002 (built_in_user), .. })
    authenticated = true
    local_addr = [fd00:1122:3344:102::2f]:12232
    method = GET
    remote_addr = [fd00:1122:3344:108::2]:41966
    req_id = 18b8277d-a998-4282-bbe7-5149675bbaf4
    resource = Database
    result = Ok(())
    uri = /sagas
    user_builtin_id = 001de000-05e4-4000-8000-000000000002

This is a successful authz check, but not for anything interesting -- it's for asking if the user is allowed to query the database in the first place. They are. Then we get stuck.

I checked briefly to see if there were stuck database queries that could account for this, but found none:

root@[fd00:1122:3344:108::3]:32221/omicron> select client_address,active_queries,last_active_query,session_start,oldest_query_start from crdb_internal.cluster_sessions where client_address like '%fd00:1122:3344:102::2f%';
          client_address         | active_queries | last_active_query |       session_start        | oldest_query_start
---------------------------------+----------------+-------------------+----------------------------+---------------------
  [fd00:1122:3344:102::2f]:56826 |                | SELECT 1          | 2025-10-19 05:37:00.888796 | NULL
  [fd00:1122:3344:102::2f]:60888 |                | SELECT 1          | 2025-10-19 05:37:00.889235 | NULL
  [fd00:1122:3344:102::2f]:38876 |                | SELECT 1          | 2025-10-19 05:37:00.888884 | NULL
  [fd00:1122:3344:102::2f]:63698 |                | SELECT 1          | 2025-10-19 05:37:00.889154 | NULL
  [fd00:1122:3344:102::2f]:35496 |                | SELECT 1          | 2025-10-19 05:37:00.888851 | NULL
  [fd00:1122:3344:102::2f]:51712 |                | SELECT 1          | 2025-10-19 05:37:00.889189 | NULL
  [fd00:1122:3344:102::2f]:38011 |                | SELECT 1          | 2025-10-19 05:37:00.888852 | NULL
  [fd00:1122:3344:102::2f]:37020 |                | SELECT 1          | 2025-10-19 05:37:00.889276 | NULL
  [fd00:1122:3344:102::2f]:36668 |                | SELECT 1          | 2025-10-19 05:37:00.888917 | NULL
  [fd00:1122:3344:102::2f]:33465 |                | SELECT 1          | 2025-10-19 05:37:00.889354 | NULL
(10 rows)


Time: 7ms total (execution 6ms / network 0ms)

Tracing

Unfortunately, we don't have great visibility into what's going in inside Nexus when something gets hung here. I went to apply the same approach we used in #8334, which is easier now that we have tokio-dtrace probes: trace tokio activity (task poll start/stop, spawn, terminate), dropshot activity, plus pid provider probes to figure out what functions were called before the task went to sleep. We iterated on this quite a bit. Most recently we've got trace7.d:

#!/usr/sbin/dtrace -Cs

/*
 * Traces tokio task activity and attempts to correlate it with dropshot
 * and Nexus activity.
 *
 * This is intended to be used for a case where you have a dropshot request
 * that's hanging and you want to see what it was doing right up until when it
 * hung.
 */

#pragma D option quiet
/* #pragma D option bufpolicy=ring */

BEGIN
{
        printf("tracing.\n");
}

/*
 * Track taskid.
 * The corresponding "done" probe is traced last so that we have all the other
 * data for it.
 */

tokio$1:::task-poll-start
{
        self->taskid = arg0;
}

/* For all traced probes, print a uniform start of line. */

#define ROW_START \
        printf("%Y.%09d tid %5d taskid %5d %s::%s ", \
            walltimestamp, walltimestamp % 1000000000, \
            tid, self->taskid, probeprov, probename); \

/*
 * Print a newline for the above line for the probes for which we have
 * nothing else to print out.
 */
tokio$1:::task-poll-start,
tokio$1:::task-poll-end,
tokio$1:::task-terminate
/self->taskid/
{
        ROW_START;
        printf("\n");
}

qorb$1:::*
/self->taskid/
{
        ROW_START;
        printf("%s\n", copyinstr(arg0));
}

pid$1:nexus:*nexus*:entry,
pid$1:nexus:*nexus*:return,
pid$1:nexus:*tokio*:entry,
pid$1:nexus:*tokio*:return,
pid$1:nexus:*qorb*:entry,
pid$1:nexus:*qorb*:return
/self->taskid/
{
        ROW_START;
        printf("%s\n", probefunc);
        this->printed = 1;
}

tokio$1:::task-spawn
/self->taskid/
{
        ROW_START;
        printf("new taskid: %d\n", arg0);
}

dropshot$1:::request-start,
dropshot$1:::request-done
/self->taskid/
{
        ROW_START;
        this->s = copyinstr(arg0);
        printf("request id %s path %s\n", json(this->s, "ok.id"),
            json(this->s, "ok.path"));
        this->s = 0;
}

/* Finish tracking taskids */

tokio$1:::task-poll-end
{
        self->taskid = 0;
}

I ran it like this:

# ./trace7.d 815 2>&1 | tee hang7.out
# demangle < hang7.out > hang7_demangled.out

Note that this takes quite a while (probably around 30s) to enable all the probes. When we run it, we've kicked off a curl request that will hang (GET /bgtasks) and also waited for a round of qorb rebalancing, which happens every minute (it will become clear why in a minute).

Searching the file for /bgtasks, you can find:

2025 Oct 20 21:59:03.410346033 tid    98 taskid 4335951 dropshot815::request-start request id 8c5ccc51-fe6f-4196-8c62-6c4022ca990f path /bgtasks

and follow that taskid to where it spawns a new task to handle the request:

2025 Oct 20 21:59:03.410346033 tid    98 taskid 4335951 tokio815::task-spawn new taskid: 4335952

then we can see everything that task did:

BRM42220031 # grep 4335952 hang7_demangled.out 
2025 Oct 20 21:59:03.410346033 tid    98 taskid 4335951 tokio815::task-spawn new taskid: 4335952
2025 Oct 20 21:59:03.410346033 tid    89 taskid 4335952 tokio815::task-poll-start 
2025 Oct 20 21:59:03.410346033 tid    89 taskid 4335952 pid815::entry tokio::runtime::task::raw::poll::h8d01fda375189088
2025 Oct 20 21:59:03.410346033 tid    89 taskid 4335952 pid815::return tokio::runtime::task::raw::poll::h8d01fda375189088
2025 Oct 20 21:59:03.410346033 tid    89 taskid 4335952 pid815::entry tokio::runtime::task::harness::Harness<T,S>::poll::h85652f6b08aabc78
2025 Oct 20 21:59:03.410346033 tid    89 taskid 4335952 pid815::entry tokio::runtime::task::state::State::transition_to_running::hc48753b452bfb585
2025 Oct 20 21:59:03.410346033 tid    89 taskid 4335952 pid815::return tokio::runtime::task::state::State::transition_to_running::hc48753b452bfb585
2025 Oct 20 21:59:03.410346033 tid    89 taskid 4335952 pid815::entry tokio::runtime::task::core::Core<T,S>::poll::h4167d064899bae5b
2025 Oct 20 21:59:03.410346033 tid    89 taskid 4335952 pid815::entry tokio::runtime::task::core::TaskIdGuard::enter::h5e381b3afc4a7b1c
2025 Oct 20 21:59:03.410346033 tid    89 taskid 4335952 pid815::return tokio::runtime::task::core::TaskIdGuard::enter::h5e381b3afc4a7b1c
2025 Oct 20 21:59:03.410346033 tid    89 taskid 4335952 pid815::entry _ZN4core3ptr179drop_in_place$LT$$LT$$LP$$RP$$u20$as$u20$dropshot..extractor..common..RequestExtractor$GT$..from_request$LT$omicrnexus
2025 Oct 20 21:59:03.410346033 tid    89 taskid 4335952 pid815::return _ZN4core3ptr179drop_in_place$LT$$LT$$LP$$RP$$u20$as$u20$dropshot..extractor..common..RequestExtractor$GT$..from_request$LT$omicrnexus
2025 Oct 20 21:59:03.410346033 tid    89 taskid 4335952 pid815::entry omicron_nexus::context::op_context_for_internal_api::{{closure}}::hbc1f39becc4d15ed
2025 Oct 20 21:59:03.410346033 tid    89 taskid 4335952 pid815::entry nexus_auth::context::OpContext::log_and_metadata_for_authn::h25772b71836369b6
2025 Oct 20 21:59:03.410346033 tid    89 taskid 4335952 pid815::entry <nexus_auth::authn::Actor as core::fmt::Debug>::fmt::hba36abc418b84ad8
2025 Oct 20 21:59:03.410346033 tid    89 taskid 4335952 pid815::return <nexus_auth::authn::Actor as core::fmt::Debug>::fmt::hba36abc418b84ad8
2025 Oct 20 21:59:03.410346033 tid    89 taskid 4335952 pid815::return nexus_auth::context::OpContext::log_and_metadata_for_authn::h25772b71836369b6
2025 Oct 20 21:59:03.410346033 tid    89 taskid 4335952 pid815::entry nexus_auth::context::OpContext::load_request_metadata::hbfb8c8dcff67fa5c
2025 Oct 20 21:59:03.410346033 tid    89 taskid 4335952 pid815::return nexus_auth::context::OpContext::load_request_metadata::hbfb8c8dcff67fa5c
2025 Oct 20 21:59:03.410346033 tid    89 taskid 4335952 pid815::return omicron_nexus::context::op_context_for_internal_api::{{closure}}::hbc1f39becc4d15ed
2025 Oct 20 21:59:03.410346033 tid    89 taskid 4335952 pid815::entry <nexus_auth::authz::api_resources::Fleet as oso::PolarClass>::get_polar_class_builder::he4c45a63f59c149b
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return <nexus_auth::authz::api_resources::Fleet as oso::PolarClass>::get_polar_class_builder::he4c45a63f59c149b
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry nexus_auth::authz::roles::load_roles_for_resource_tree::_$u7b$$u7b$closure$u7d$$u7d$::hbca4bb2a1bf29345 (.llvm.138533801718603nexus)
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry _ZN114_$LT$nexus_auth..authz..api_resources..Fleet$u20$as$u20$nexus_auth..authz..api_resources..ApiResourceWithRoles$GT$11resournexus
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return _ZN114_$LT$nexus_auth..authz..api_resources..Fleet$u20$as$u20$nexus_auth..authz..api_resources..ApiResourceWithRoles$GT$11resournexus
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry nexus_auth::authz::roles::load_directly_attached_roles::{{closure}}::hc5a457385c0fa288
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry nexus_auth::authn::Context::actor::h532981fe5a503088
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return nexus_auth::authn::Context::actor::h532981fe5a503088
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry _ZN16nexus_db_queries2db9datastore4auth101_$LT$impl$u20$nexus_auth..storage..Storage$u20$for$u20$nexus_db_queries..db..datastorenexus
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return _ZN16nexus_db_queries2db9datastore4auth101_$LT$impl$u20$nexus_auth..storage..Storage$u20$for$u20$nexus_db_queries..db..datastorenexus
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry _ZN100_$LT$nexus_db_schema..schema..address_lot_block..table$u20$as$u20$diesel..query_builder..AsQuery$GT$8as_query17h22dcda633fnexus
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return _ZN100_$LT$nexus_db_schema..schema..address_lot_block..table$u20$as$u20$diesel..query_builder..AsQuery$GT$8as_query17h22dcda633fnexus
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry _ZN100_$LT$nexus_db_schema..schema..address_lot_block..table$u20$as$u20$diesel..query_builder..AsQuery$GT$8as_query17h22dcda633fnexus
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return _ZN100_$LT$nexus_db_schema..schema..address_lot_block..table$u20$as$u20$diesel..query_builder..AsQuery$GT$8as_query17h22dcda633fnexus
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry _ZN100_$LT$nexus_db_schema..schema..address_lot_block..table$u20$as$u20$diesel..query_builder..AsQuery$GT$8as_query17h22dcda633fnexus
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return _ZN100_$LT$nexus_db_schema..schema..address_lot_block..table$u20$as$u20$diesel..query_builder..AsQuery$GT$8as_query17h22dcda633fnexus
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry nexus_db_queries::db::datastore::DataStore::pool_connection_authorized::{{closure}}::hc6c391f53bba2718
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry _ZN107_$LT$nexus_auth..authz..oso_generic..Database$u20$as$u20$nexus_auth..authz..context..AuthorizedResource$GT$11polar_class17nexus
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return _ZN107_$LT$nexus_auth..authz..oso_generic..Database$u20$as$u20$nexus_auth..authz..context..AuthorizedResource$GT$11polar_class17nexus
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry _ZN107_$LT$nexus_auth..authz..oso_generic..Database$u20$as$u20$nexus_auth..authz..context..AuthorizedResource$GT$10load_roles17hnexus
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return _ZN107_$LT$nexus_auth..authz..oso_generic..Database$u20$as$u20$nexus_auth..authz..context..AuthorizedResource$GT$10load_roles17hnexus
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry nexus_auth::authz::actor::AnyActor::new::h1e9f309a5417c1a4
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return nexus_auth::authz::actor::AnyActor::new::h1e9f309a5417c1a4
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry nexus_auth::authn::Context::actor::h532981fe5a503088
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return nexus_auth::authn::Context::actor::h532981fe5a503088
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry core::ptr::drop_in_place$LT$nexus_auth..authz..actor..AnyActor$GT$::h8cb1c4187394a557 (.llvm.17130064514558685687)
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return core::ptr::drop_in_place$LT$nexus_auth..authz..actor..AnyActor$GT$::h8cb1c4187394a557 (.llvm.17130064514558685687)
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry core::ptr::drop_in_place$LT$nexus_auth..authz..actor..AuthenticatedActor$GT$::h2af4037e815f2ce7 (.llvm.11551558777027292440)
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return core::ptr::drop_in_place$LT$nexus_auth..authz..actor..AuthenticatedActor$GT$::h2af4037e815f2ce7 (.llvm.11551558777027292440)
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry nexus_auth::authn::Context::actor::h532981fe5a503088
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return nexus_auth::authn::Context::actor::h532981fe5a503088
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry <nexus_auth::authn::Actor as core::fmt::Debug>::fmt::hba36abc418b84ad8
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return <nexus_auth::authn::Actor as core::fmt::Debug>::fmt::hba36abc418b84ad8
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry tokio::sync::watch::Sender<T>::send_if_modified::h36b7b03dcf60467b
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry tokio::sync::watch::state::AtomicState::increment_version_while_locked::h195db6bc09b3d630
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return tokio::sync::watch::state::AtomicState::increment_version_while_locked::h195db6bc09b3d630
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry tokio::sync::watch::big_notify::BigNotify::notify_waiters::hf023abf40d770c5e
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry tokio::sync::notify::Notify::notify_waiters::hb88264cacde68de9
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return tokio::sync::notify::Notify::notify_waiters::hb88264cacde68de9
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry tokio::sync::notify::Notify::notify_waiters::hb88264cacde68de9
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return tokio::sync::notify::Notify::notify_waiters::hb88264cacde68de9
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry tokio::sync::notify::Notify::notify_waiters::hb88264cacde68de9
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return tokio::sync::notify::Notify::notify_waiters::hb88264cacde68de9
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry tokio::sync::notify::Notify::notify_waiters::hb88264cacde68de9
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return tokio::sync::notify::Notify::notify_waiters::hb88264cacde68de9
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry tokio::sync::notify::Notify::notify_waiters::hb88264cacde68de9
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return tokio::sync::notify::Notify::notify_waiters::hb88264cacde68de9
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry tokio::sync::notify::Notify::notify_waiters::hb88264cacde68de9
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return tokio::sync::notify::Notify::notify_waiters::hb88264cacde68de9
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry tokio::sync::notify::Notify::notify_waiters::hb88264cacde68de9
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return tokio::sync::notify::Notify::notify_waiters::hb88264cacde68de9
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return tokio::sync::watch::big_notify::BigNotify::notify_waiters::hf023abf40d770c5e
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry tokio::sync::notify::Notify::notify_waiters::hb88264cacde68de9
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return tokio::sync::notify::Notify::notify_waiters::hb88264cacde68de9
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return tokio::sync::watch::Sender<T>::send_if_modified::h36b7b03dcf60467b
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry qorb::ClaimId::new::hcd1c25cf96fe6205
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return qorb::ClaimId::new::hcd1c25cf96fe6205
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 qorb815::claim-start crdb
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry <tokio::sync::batch_semaphore::Acquire as core::future::future::Future>::poll::h2ab6b9ca4e7d1696
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry tokio::runtime::task::waker::clone_waker::h7c601355f53dcb0a
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return tokio::runtime::task::waker::clone_waker::h7c601355f53dcb0a
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return <tokio::sync::batch_semaphore::Acquire as core::future::future::Future>::poll::h2ab6b9ca4e7d1696
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return nexus_auth::authz::roles::load_directly_attached_roles::{{closure}}::hc5a457385c0fa288
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry <tokio::runtime::task::core::TaskIdGuard as core::ops::drop::Drop>::drop::h5ba00a5cc15b07ae
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return <tokio::runtime::task::core::TaskIdGuard as core::ops::drop::Drop>::drop::h5ba00a5cc15b07ae
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return tokio::runtime::task::core::Core<T,S>::poll::h4167d064899bae5b
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::entry tokio::runtime::task::state::State::transition_to_idle::h25ccd06b80c3cea1
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 pid815::return tokio::runtime::task::state::State::transition_to_idle::h25ccd06b80c3cea1
2025 Oct 20 21:59:03.411343651 tid    89 taskid 4335952 tokio815::task-poll-end 

Here's how I read this:

• we start polling the new task
• we start doing request extraction in dropshot
• we construct an OpContext (this is generally the first thing we do for all API requests)
• we start doing authz/authn checks (note: the first line in bgtasks_list is indeed an authz check)
• this starts loading roles for the whole resource tree around authz::FLEET
• this loads roles directly attached to the fleet using load_directly_attached_roles()
• (we must have inlined the call to datastore.role_asgn_list_for().)
• this calls pool_connection_authorized() to get a database connection
• this does an authz check (remember, we're still in a higher-level authz check) to determine if you can query the database -- this succeeds and produces the log message we saw above
• from code inspection: this winds up calling into the Nexus pool's claim(), which does stuff with the watch channel
• then this calls into the qorb pool's claim(), which does the ClaimId::new()
• we see the probe claim-start fire
• from the probes: the task tries to acquire a semaphore, but can't, so it clones a waker so that it can be woken back up when the semaphore has permits available
• then it returns from the native functions, all the way to the top level task poll

Now, from code inspection, after the claim-start probe, the task should enter do_claim() (apparently inlined, because we don't see it in the output). Then we try to send a message on the mpsc channel to the qorb pool's task to ask for a claim. mpsc::Sender::send does try to acquire a semaphore, so this is all consistent with this task blocking on the qorb pool waiting for a claim.

Here's where things get confusing. What's the receiver side of that channel doing? The body of that task is PoolInner::run(). The body of that is a tokio::select loop that's waiting for any of several things to happen:

• recv on our channel to return a message
• a timer to fire for the oldest blocked claim, to trigger qorb to fail the claim request if it's waited too long
• a change in the stream of events coming from the resolver, indicating that we need to adjust the backends
• a 60-second ticker to fire to trigger rebalancing
• a change in the stream of backend status reports that would trigger a rebalance and potentially satisfying a claim

Here's what's interesting: we see DTrace probes from the 60-second rebalance timer fire like clockwork. That suggests that the task is not blocked nor stuck on-CPU -- it's fully able to call recv on our watch channel. By looking for the rebalance probes, we can find the taskid:

BRM42220031 # grep rebalance-start.*crdb hang7.out 
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 qorb815::rebalance-start crdb

and then we can see everything it did while we were tracing:

BRM42220031 # grep 'taskid   130' hang7.out 
BRM42220031 # grep 'taskid   130' hang7_demangled.out 
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 tokio815::task-poll-start 
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry tokio::runtime::task::raw::poll::h98e2a4af9ff5c069
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return tokio::runtime::task::raw::poll::h98e2a4af9ff5c069
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry tokio::runtime::task::harness::Harness<T,S>::poll::hb1f4d32270ab5fc1
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry tokio::runtime::task::state::State::transition_to_running::hc48753b452bfb585
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return tokio::runtime::task::state::State::transition_to_running::hc48753b452bfb585
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry tokio::runtime::task::core::Core<T,S>::poll::h1fae05d75a08aedd
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry tokio::runtime::task::core::TaskIdGuard::enter::h5e381b3afc4a7b1c
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return tokio::runtime::task::core::TaskIdGuard::enter::h5e381b3afc4a7b1c
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry qorb::pool::Pool$LT$Conn$GT$::new::_$u7b$$u7b$closure$u7d$$u7d$::h3352a70336b9843c (.llvm.10388221640079881160)
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry tokio::task::coop::Budget::has_remaining::h0c18b267c54ef9f3
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return tokio::task::coop::Budget::has_remaining::h0c18b267c54ef9f3
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry tokio::macros::support::thread_rng_n::h0e5d2ec378988983
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return tokio::macros::support::thread_rng_n::h0e5d2ec378988983
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry tokio::sync::mpsc::chan::Rx<T,S>::recv::hf1e10cca61c2f69a
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry tokio::sync::mpsc::list::Rx$LT$T$GT$::pop::h8499e2d478bfed1d (.llvm.16696573479048730848)
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return tokio::sync::mpsc::list::Rx$LT$T$GT$::pop::h8499e2d478bfed1d (.llvm.16696573479048730848)
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry tokio::sync::task::atomic_waker::AtomicWaker::register_by_ref::hce23dd46925d2997
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry tokio::runtime::task::waker::clone_waker::h7c601355f53dcb0a
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return tokio::runtime::task::waker::clone_waker::h7c601355f53dcb0a
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry tokio::runtime::task::waker::drop_waker::h7a1ab930376402e0
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry tokio::sync::mpsc::list::Rx$LT$T$GT$::pop::h8499e2d478bfed1d (.llvm.16696573479048730848)
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return tokio::sync::mpsc::list::Rx$LT$T$GT$::pop::h8499e2d478bfed1d (.llvm.16696573479048730848)
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return tokio::sync::mpsc::chan::Rx<T,S>::recv::hf1e10cca61c2f69a
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry _ZN100_$LT$tokio_stream..wrappers..watch..WatchStream$LT$T$GT$$u20$as$u20$futures_core..stream..Stream$GT$9poll_next17h6d4a9a561nexus
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry _ZN100_$LT$tokio_stream..wrappers..watch..WatchStream$LT$T$GT$$u20$as$u20$futures_core..stream..Stream$GT$9poll_next17h6d4a9a561nexus
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry tokio_stream::wrappers::watch::make_future::{{closure}}::hf53774c95796860d
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry <tokio::task::coop::Coop<F> as core::future::future::Future>::poll::h99257c0dba7b166a
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry <tokio::sync::notify::Notified as core::future::future::Future>::poll::hfc7c60615f9eda19
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry tokio::sync::notify::NotifiedProject::poll_notified::h50a58047a385bfb3 (.llvm.8247371145572912925)
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return <tokio::sync::notify::Notified as core::future::future::Future>::poll::hfc7c60615f9eda19
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return tokio_stream::wrappers::watch::make_future::{{closure}}::hf53774c95796860d
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return _ZN100_$LT$tokio_stream..wrappers..watch..WatchStream$LT$T$GT$$u20$as$u20$futures_core..stream..Stream$GT$9poll_next17h6d4a9a561nexus
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return _ZN100_$LT$tokio_stream..wrappers..watch..WatchStream$LT$T$GT$$u20$as$u20$futures_core..stream..Stream$GT$9poll_next17h6d4a9a561nexus
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry tokio::time::interval::Interval::poll_tick::h9be755ed2eb73230
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry <tokio::time::sleep::Sleep as core::future::future::Future>::poll::h9ebf719e6df6643c
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry tokio::runtime::task::waker::clone_waker::h7c601355f53dcb0a
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return tokio::runtime::task::waker::clone_waker::h7c601355f53dcb0a
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return <tokio::time::sleep::Sleep as core::future::future::Future>::poll::h9ebf719e6df6643c
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry tokio::time::clock::now::h2cb92d77bf2f7ed8
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return tokio::time::clock::now::h2cb92d77bf2f7ed8
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry tokio::time::sleep::Sleep::reset_without_reregister::h702b12626bf885b5
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return tokio::time::sleep::Sleep::reset_without_reregister::h702b12626bf885b5
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return tokio::time::interval::Interval::poll_tick::h9be755ed2eb73230
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry qorb::pool::PoolInner<Conn>::rebalance::{{closure}}::h0045d44d5b5e9db2
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 qorb815::rebalance-start crdb
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry qorb::slot::Set<Conn>::get_state::hf39ef87f6d7b1d71
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry tokio::sync::watch::state::AtomicState::load::h88ad7dcebe5292a5
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return tokio::sync::watch::state::AtomicState::load::h88ad7dcebe5292a5
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return qorb::slot::Set<Conn>::get_state::hf39ef87f6d7b1d71
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry qorb::slot::Set<Conn>::get_state::hf39ef87f6d7b1d71
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry tokio::sync::watch::state::AtomicState::load::h88ad7dcebe5292a5
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return tokio::sync::watch::state::AtomicState::load::h88ad7dcebe5292a5
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return qorb::slot::Set<Conn>::get_state::hf39ef87f6d7b1d71
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry qorb::slot::Set<Conn>::get_state::hf39ef87f6d7b1d71
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry tokio::sync::watch::state::AtomicState::load::h88ad7dcebe5292a5
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return tokio::sync::watch::state::AtomicState::load::h88ad7dcebe5292a5
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return qorb::slot::Set<Conn>::get_state::hf39ef87f6d7b1d71
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry qorb::slot::Set<Conn>::get_state::hf39ef87f6d7b1d71
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry tokio::sync::watch::state::AtomicState::load::h88ad7dcebe5292a5
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return tokio::sync::watch::state::AtomicState::load::h88ad7dcebe5292a5
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return qorb::slot::Set<Conn>::get_state::hf39ef87f6d7b1d71
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry qorb::slot::Set<Conn>::get_state::hf39ef87f6d7b1d71
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry tokio::sync::watch::state::AtomicState::load::h88ad7dcebe5292a5
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return tokio::sync::watch::state::AtomicState::load::h88ad7dcebe5292a5
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return qorb::slot::Set<Conn>::get_state::hf39ef87f6d7b1d71
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry qorb::slot::Set<Conn>::get_stats::h1db6c82bbbb55dbb
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return qorb::slot::Set<Conn>::get_stats::h1db6c82bbbb55dbb
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry qorb::slot::Set<Conn>::get_stats::h1db6c82bbbb55dbb
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return qorb::slot::Set<Conn>::get_stats::h1db6c82bbbb55dbb
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry qorb::slot::Set<Conn>::get_stats::h1db6c82bbbb55dbb
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return qorb::slot::Set<Conn>::get_stats::h1db6c82bbbb55dbb
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry qorb::slot::Set<Conn>::get_stats::h1db6c82bbbb55dbb
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return qorb::slot::Set<Conn>::get_stats::h1db6c82bbbb55dbb
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry qorb::slot::Set<Conn>::get_stats::h1db6c82bbbb55dbb
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return qorb::slot::Set<Conn>::get_stats::h1db6c82bbbb55dbb
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry <tokio::sync::batch_semaphore::Acquire as core::future::future::Future>::poll::h2ab6b9ca4e7d1696
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::sync::batch_semaphore::Acquire as core::future::future::Future>::poll::h2ab6b9ca4e7d1696
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::sync::batch_semaphore::Acquire as core::ops::drop::Drop>::drop::hb92b7cb2d9e1ad70
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::sync::batch_semaphore::Acquire as core::ops::drop::Drop>::drop::hb92b7cb2d9e1ad70
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::sync::mpsc::list::Tx$LT$T$GT$::find_block::h0d48165c9afa82fd (.llvm.16696573479048730848)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::sync::mpsc::list::Tx$LT$T$GT$::find_block::h0d48165c9afa82fd (.llvm.16696573479048730848)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::sync::task::atomic_waker::AtomicWaker::wake::h0a37bd7539de4a0e
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::task::waker::wake_by_val::h98e2b9cc778dced6
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::task::state::State::transition_to_notified_by_val::h3fd3a42d00ca20cc
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::runtime::task::state::State::transition_to_notified_by_val::h3fd3a42d00ca20cc
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::task::raw::schedule::h42ea4cd8a9dd8892
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::runtime::task::raw::schedule::h42ea4cd8a9dd8892
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry _ZN5tokio7runtime9scheduler12multi_thread6worker73_$LT$impl$u20$tokio..runtime..scheduler..multi_thread..handle..Handle$GT$13schnexus
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry _ZN5tokio7runtime9scheduler12multi_thread6worker73_$LT$impl$u20$tokio..runtime..scheduler..multi_thread..handle..Handle$GT$13schnexus
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::scheduler::multi_thread::queue::Local<T>::push_back_or_overflow::h65d7c0a546658096
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::runtime::scheduler::multi_thread::queue::Local<T>::push_back_or_overflow::h65d7c0a546658096
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::scheduler::multi_thread::idle::Idle::worker_to_notify::h81ea73462a00c107
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::runtime::scheduler::multi_thread::idle::Idle::worker_to_notify::h81ea73462a00c107
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::scheduler::multi_thread::park::Unparker::unpark::hc59761ba290e2abf
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return _ZN5tokio7runtime9scheduler12multi_thread6worker73_$LT$impl$u20$tokio..runtime..scheduler..multi_thread..handle..Handle$GT$13schnexus
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return _ZN5tokio7runtime9scheduler12multi_thread6worker73_$LT$impl$u20$tokio..runtime..scheduler..multi_thread..handle..Handle$GT$13schnexus
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::sync::batch_semaphore::Acquire as core::future::future::Future>::poll::h2ab6b9ca4e7d1696
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::sync::batch_semaphore::Acquire as core::future::future::Future>::poll::h2ab6b9ca4e7d1696
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::sync::batch_semaphore::Acquire as core::ops::drop::Drop>::drop::hb92b7cb2d9e1ad70
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::sync::batch_semaphore::Acquire as core::ops::drop::Drop>::drop::hb92b7cb2d9e1ad70
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::sync::mpsc::list::Tx$LT$T$GT$::find_block::h0d48165c9afa82fd (.llvm.16696573479048730848)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::sync::mpsc::list::Tx$LT$T$GT$::find_block::h0d48165c9afa82fd (.llvm.16696573479048730848)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::sync::task::atomic_waker::AtomicWaker::wake::h0a37bd7539de4a0e
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::task::waker::wake_by_val::h98e2b9cc778dced6
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::task::state::State::transition_to_notified_by_val::h3fd3a42d00ca20cc
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::runtime::task::state::State::transition_to_notified_by_val::h3fd3a42d00ca20cc
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::task::raw::schedule::h42ea4cd8a9dd8892
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::runtime::task::raw::schedule::h42ea4cd8a9dd8892
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry _ZN5tokio7runtime9scheduler12multi_thread6worker73_$LT$impl$u20$tokio..runtime..scheduler..multi_thread..handle..Handle$GT$13schnexus
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry _ZN5tokio7runtime9scheduler12multi_thread6worker73_$LT$impl$u20$tokio..runtime..scheduler..multi_thread..handle..Handle$GT$13schnexus
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::scheduler::multi_thread::queue::Local<T>::push_back_or_overflow::h65d7c0a546658096
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::runtime::scheduler::multi_thread::queue::Local<T>::push_back_or_overflow::h65d7c0a546658096
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::scheduler::multi_thread::idle::Idle::worker_to_notify::h81ea73462a00c107
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::runtime::scheduler::multi_thread::idle::Idle::worker_to_notify::h81ea73462a00c107
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return _ZN5tokio7runtime9scheduler12multi_thread6worker73_$LT$impl$u20$tokio..runtime..scheduler..multi_thread..handle..Handle$GT$13schnexus
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return _ZN5tokio7runtime9scheduler12multi_thread6worker73_$LT$impl$u20$tokio..runtime..scheduler..multi_thread..handle..Handle$GT$13schnexus
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::sync::batch_semaphore::Acquire as core::future::future::Future>::poll::h2ab6b9ca4e7d1696
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::sync::batch_semaphore::Acquire as core::future::future::Future>::poll::h2ab6b9ca4e7d1696
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::sync::batch_semaphore::Acquire as core::ops::drop::Drop>::drop::hb92b7cb2d9e1ad70
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::sync::batch_semaphore::Acquire as core::ops::drop::Drop>::drop::hb92b7cb2d9e1ad70
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::sync::mpsc::list::Tx$LT$T$GT$::find_block::h0d48165c9afa82fd (.llvm.16696573479048730848)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::sync::mpsc::list::Tx$LT$T$GT$::find_block::h0d48165c9afa82fd (.llvm.16696573479048730848)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::sync::task::atomic_waker::AtomicWaker::wake::h0a37bd7539de4a0e
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::task::waker::wake_by_val::h98e2b9cc778dced6
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::task::state::State::transition_to_notified_by_val::h3fd3a42d00ca20cc
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::runtime::task::state::State::transition_to_notified_by_val::h3fd3a42d00ca20cc
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::task::raw::schedule::h42ea4cd8a9dd8892
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::runtime::task::raw::schedule::h42ea4cd8a9dd8892
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry _ZN5tokio7runtime9scheduler12multi_thread6worker73_$LT$impl$u20$tokio..runtime..scheduler..multi_thread..handle..Handle$GT$13schnexus
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry _ZN5tokio7runtime9scheduler12multi_thread6worker73_$LT$impl$u20$tokio..runtime..scheduler..multi_thread..handle..Handle$GT$13schnexus
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::scheduler::multi_thread::queue::Local<T>::push_back_or_overflow::h65d7c0a546658096
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::runtime::scheduler::multi_thread::queue::Local<T>::push_back_or_overflow::h65d7c0a546658096
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::scheduler::multi_thread::idle::Idle::worker_to_notify::h81ea73462a00c107
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::runtime::scheduler::multi_thread::idle::Idle::worker_to_notify::h81ea73462a00c107
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return _ZN5tokio7runtime9scheduler12multi_thread6worker73_$LT$impl$u20$tokio..runtime..scheduler..multi_thread..handle..Handle$GT$13schnexus
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return _ZN5tokio7runtime9scheduler12multi_thread6worker73_$LT$impl$u20$tokio..runtime..scheduler..multi_thread..handle..Handle$GT$13schnexus
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::sync::batch_semaphore::Acquire as core::future::future::Future>::poll::h2ab6b9ca4e7d1696
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::sync::batch_semaphore::Acquire as core::future::future::Future>::poll::h2ab6b9ca4e7d1696
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::sync::batch_semaphore::Acquire as core::ops::drop::Drop>::drop::hb92b7cb2d9e1ad70
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::sync::batch_semaphore::Acquire as core::ops::drop::Drop>::drop::hb92b7cb2d9e1ad70
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::sync::mpsc::list::Tx$LT$T$GT$::find_block::h0d48165c9afa82fd (.llvm.16696573479048730848)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::sync::mpsc::list::Tx$LT$T$GT$::find_block::h0d48165c9afa82fd (.llvm.16696573479048730848)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::sync::task::atomic_waker::AtomicWaker::wake::h0a37bd7539de4a0e
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::task::waker::wake_by_val::h98e2b9cc778dced6
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::task::state::State::transition_to_notified_by_val::h3fd3a42d00ca20cc
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::runtime::task::state::State::transition_to_notified_by_val::h3fd3a42d00ca20cc
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::task::raw::schedule::h42ea4cd8a9dd8892
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::runtime::task::raw::schedule::h42ea4cd8a9dd8892
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry _ZN5tokio7runtime9scheduler12multi_thread6worker73_$LT$impl$u20$tokio..runtime..scheduler..multi_thread..handle..Handle$GT$13schnexus
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry _ZN5tokio7runtime9scheduler12multi_thread6worker73_$LT$impl$u20$tokio..runtime..scheduler..multi_thread..handle..Handle$GT$13schnexus
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::scheduler::multi_thread::queue::Local<T>::push_back_or_overflow::h65d7c0a546658096
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::runtime::scheduler::multi_thread::queue::Local<T>::push_back_or_overflow::h65d7c0a546658096
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::scheduler::multi_thread::idle::Idle::worker_to_notify::h81ea73462a00c107
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::runtime::scheduler::multi_thread::idle::Idle::worker_to_notify::h81ea73462a00c107
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return _ZN5tokio7runtime9scheduler12multi_thread6worker73_$LT$impl$u20$tokio..runtime..scheduler..multi_thread..handle..Handle$GT$13schnexus
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return _ZN5tokio7runtime9scheduler12multi_thread6worker73_$LT$impl$u20$tokio..runtime..scheduler..multi_thread..handle..Handle$GT$13schnexus
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::sync::batch_semaphore::Acquire as core::future::future::Future>::poll::h2ab6b9ca4e7d1696
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::sync::batch_semaphore::Acquire as core::future::future::Future>::poll::h2ab6b9ca4e7d1696
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::sync::batch_semaphore::Acquire as core::ops::drop::Drop>::drop::hb92b7cb2d9e1ad70
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::sync::batch_semaphore::Acquire as core::ops::drop::Drop>::drop::hb92b7cb2d9e1ad70
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::sync::mpsc::list::Tx$LT$T$GT$::find_block::h0d48165c9afa82fd (.llvm.16696573479048730848)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::sync::mpsc::list::Tx$LT$T$GT$::find_block::h0d48165c9afa82fd (.llvm.16696573479048730848)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::sync::task::atomic_waker::AtomicWaker::wake::h0a37bd7539de4a0e
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::task::waker::wake_by_val::h98e2b9cc778dced6
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::task::state::State::transition_to_notified_by_val::h3fd3a42d00ca20cc
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::runtime::task::state::State::transition_to_notified_by_val::h3fd3a42d00ca20cc
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::task::raw::schedule::h42ea4cd8a9dd8892
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::runtime::task::raw::schedule::h42ea4cd8a9dd8892
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry _ZN5tokio7runtime9scheduler12multi_thread6worker73_$LT$impl$u20$tokio..runtime..scheduler..multi_thread..handle..Handle$GT$13schnexus
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry _ZN5tokio7runtime9scheduler12multi_thread6worker73_$LT$impl$u20$tokio..runtime..scheduler..multi_thread..handle..Handle$GT$13schnexus
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::scheduler::multi_thread::queue::Local<T>::push_back_or_overflow::h65d7c0a546658096
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::runtime::scheduler::multi_thread::queue::Local<T>::push_back_or_overflow::h65d7c0a546658096
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::scheduler::multi_thread::idle::Idle::worker_to_notify::h81ea73462a00c107
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::runtime::scheduler::multi_thread::idle::Idle::worker_to_notify::h81ea73462a00c107
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return _ZN5tokio7runtime9scheduler12multi_thread6worker73_$LT$impl$u20$tokio..runtime..scheduler..multi_thread..handle..Handle$GT$13schnexus
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return _ZN5tokio7runtime9scheduler12multi_thread6worker73_$LT$impl$u20$tokio..runtime..scheduler..multi_thread..handle..Handle$GT$13schnexus
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry qorb::slot::Set<Conn>::failure_count::hc8f00c01e4d6ee37
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry qorb::window_counter::WindowedCounter::sum::h7cf7247c7353c153
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry qorb::window_counter::WindowedCounter::expire::h5f40d5713665b849 (.llvm.252458257457390352)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::time::instant::Instant::elapsed::h2981ad92954d1449
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::time::clock::now::h2cb92d77bf2f7ed8
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::time::clock::now::h2cb92d77bf2f7ed8
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::time::instant::Instant::elapsed::h2981ad92954d1449
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::time::instant::Instant::elapsed::h2981ad92954d1449
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::time::clock::now::h2cb92d77bf2f7ed8
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::time::clock::now::h2cb92d77bf2f7ed8
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::time::instant::Instant::elapsed::h2981ad92954d1449
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return qorb::window_counter::WindowedCounter::expire::h5f40d5713665b849 (.llvm.252458257457390352)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return qorb::window_counter::WindowedCounter::sum::h7cf7247c7353c153
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return qorb::slot::Set<Conn>::failure_count::hc8f00c01e4d6ee37
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry qorb::rebalancer::add_random_jitter::h0c54421cd0135519
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return qorb::rebalancer::add_random_jitter::h0c54421cd0135519
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry qorb::slot::Set<Conn>::failure_count::hc8f00c01e4d6ee37
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry qorb::window_counter::WindowedCounter::sum::h7cf7247c7353c153
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry qorb::window_counter::WindowedCounter::expire::h5f40d5713665b849 (.llvm.252458257457390352)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::time::instant::Instant::elapsed::h2981ad92954d1449
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::time::clock::now::h2cb92d77bf2f7ed8
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::time::clock::now::h2cb92d77bf2f7ed8
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::time::instant::Instant::elapsed::h2981ad92954d1449
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::time::instant::Instant::elapsed::h2981ad92954d1449
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::time::clock::now::h2cb92d77bf2f7ed8
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::time::clock::now::h2cb92d77bf2f7ed8
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::time::instant::Instant::elapsed::h2981ad92954d1449
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return qorb::window_counter::WindowedCounter::expire::h5f40d5713665b849 (.llvm.252458257457390352)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return qorb::window_counter::WindowedCounter::sum::h7cf7247c7353c153
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return qorb::slot::Set<Conn>::failure_count::hc8f00c01e4d6ee37
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry qorb::rebalancer::add_random_jitter::h0c54421cd0135519
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return qorb::rebalancer::add_random_jitter::h0c54421cd0135519
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry qorb::slot::Set<Conn>::failure_count::hc8f00c01e4d6ee37
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry qorb::window_counter::WindowedCounter::sum::h7cf7247c7353c153
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry qorb::window_counter::WindowedCounter::expire::h5f40d5713665b849 (.llvm.252458257457390352)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::time::instant::Instant::elapsed::h2981ad92954d1449
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::time::clock::now::h2cb92d77bf2f7ed8
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::time::clock::now::h2cb92d77bf2f7ed8
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::time::instant::Instant::elapsed::h2981ad92954d1449
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::time::instant::Instant::elapsed::h2981ad92954d1449
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::time::clock::now::h2cb92d77bf2f7ed8
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::time::clock::now::h2cb92d77bf2f7ed8
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::time::instant::Instant::elapsed::h2981ad92954d1449
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return qorb::window_counter::WindowedCounter::expire::h5f40d5713665b849 (.llvm.252458257457390352)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return qorb::window_counter::WindowedCounter::sum::h7cf7247c7353c153
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return qorb::slot::Set<Conn>::failure_count::hc8f00c01e4d6ee37
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry qorb::rebalancer::add_random_jitter::h0c54421cd0135519
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return qorb::rebalancer::add_random_jitter::h0c54421cd0135519
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry qorb::slot::Set<Conn>::failure_count::hc8f00c01e4d6ee37
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry qorb::window_counter::WindowedCounter::sum::h7cf7247c7353c153
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry qorb::window_counter::WindowedCounter::expire::h5f40d5713665b849 (.llvm.252458257457390352)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::time::instant::Instant::elapsed::h2981ad92954d1449
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::time::clock::now::h2cb92d77bf2f7ed8
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::time::clock::now::h2cb92d77bf2f7ed8
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::time::instant::Instant::elapsed::h2981ad92954d1449
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::time::instant::Instant::elapsed::h2981ad92954d1449
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::time::clock::now::h2cb92d77bf2f7ed8
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::time::clock::now::h2cb92d77bf2f7ed8
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::time::instant::Instant::elapsed::h2981ad92954d1449
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return qorb::window_counter::WindowedCounter::expire::h5f40d5713665b849 (.llvm.252458257457390352)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return qorb::window_counter::WindowedCounter::sum::h7cf7247c7353c153
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return qorb::slot::Set<Conn>::failure_count::hc8f00c01e4d6ee37
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry qorb::rebalancer::add_random_jitter::h0c54421cd0135519
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return qorb::rebalancer::add_random_jitter::h0c54421cd0135519
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry qorb::slot::Set<Conn>::failure_count::hc8f00c01e4d6ee37
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry qorb::window_counter::WindowedCounter::sum::h7cf7247c7353c153
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry qorb::window_counter::WindowedCounter::expire::h5f40d5713665b849 (.llvm.252458257457390352)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::time::instant::Instant::elapsed::h2981ad92954d1449
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::time::clock::now::h2cb92d77bf2f7ed8
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::time::clock::now::h2cb92d77bf2f7ed8
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::time::instant::Instant::elapsed::h2981ad92954d1449
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::time::instant::Instant::elapsed::h2981ad92954d1449
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::time::clock::now::h2cb92d77bf2f7ed8
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::time::clock::now::h2cb92d77bf2f7ed8
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::time::instant::Instant::elapsed::h2981ad92954d1449
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return qorb::window_counter::WindowedCounter::expire::h5f40d5713665b849 (.llvm.252458257457390352)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return qorb::window_counter::WindowedCounter::sum::h7cf7247c7353c153
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return qorb::slot::Set<Conn>::failure_count::hc8f00c01e4d6ee37
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry qorb::rebalancer::add_random_jitter::h0c54421cd0135519
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return qorb::rebalancer::add_random_jitter::h0c54421cd0135519
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 qorb815::rebalance-done crdb
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::task::coop::Budget::has_remaining::h0c18b267c54ef9f3
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::task::coop::Budget::has_remaining::h0c18b267c54ef9f3
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::macros::support::thread_rng_n::h0e5d2ec378988983
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::macros::support::thread_rng_n::h0e5d2ec378988983
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry _ZN100_$LT$tokio_stream..wrappers..watch..WatchStream$LT$T$GT$$u20$as$u20$futures_core..stream..Stream$GT$9poll_next17h6d4a9a561nexus
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry _ZN100_$LT$tokio_stream..wrappers..watch..WatchStream$LT$T$GT$$u20$as$u20$futures_core..stream..Stream$GT$9poll_next17h6d4a9a561nexus
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio_stream::wrappers::watch::make_future::{{closure}}::hf53774c95796860d
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::task::coop::Coop<F> as core::future::future::Future>::poll::h99257c0dba7b166a
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::sync::notify::Notified as core::future::future::Future>::poll::hfc7c60615f9eda19
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::sync::notify::NotifiedProject::poll_notified::h50a58047a385bfb3 (.llvm.8247371145572912925)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::sync::notify::Notified as core::future::future::Future>::poll::hfc7c60615f9eda19
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio_stream::wrappers::watch::make_future::{{closure}}::hf53774c95796860d
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return _ZN100_$LT$tokio_stream..wrappers..watch..WatchStream$LT$T$GT$$u20$as$u20$futures_core..stream..Stream$GT$9poll_next17h6d4a9a561nexus
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return _ZN100_$LT$tokio_stream..wrappers..watch..WatchStream$LT$T$GT$$u20$as$u20$futures_core..stream..Stream$GT$9poll_next17h6d4a9a561nexus
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::time::interval::Interval::poll_tick::h9be755ed2eb73230
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::time::sleep::Sleep as core::future::future::Future>::poll::h9ebf719e6df6643c
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::time::entry::TimerEntry::reset::h54d30ba2650f6358 (.llvm.5131811265238561059)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::runtime::time::entry::TimerEntry::reset::h54d30ba2650f6358 (.llvm.5131811265238561059)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::time::<impl tokio::runtime::time::handle::Handle>::reregister::h3f0d3cadd725373e
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::time::wheel::Wheel::insert::h492b5a28a8473787
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::runtime::time::wheel::Wheel::insert::h492b5a28a8473787
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::task::waker::clone_waker::h7c601355f53dcb0a
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::runtime::task::waker::clone_waker::h7c601355f53dcb0a
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::task::waker::drop_waker::h7a1ab930376402e0
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::time::sleep::Sleep as core::future::future::Future>::poll::h9ebf719e6df6643c
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::time::interval::Interval::poll_tick::h9be755ed2eb73230
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry _ZN97_$LT$tokio_stream..stream_map..StreamMap$LT$K$C$V$GT$$u20$as$u20$futures_core..stream..Stream$GT$9poll_next17he816e32b4686bnexus
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry _ZN97_$LT$tokio_stream..stream_map..StreamMap$LT$K$C$V$GT$$u20$as$u20$futures_core..stream..Stream$GT$9poll_next17he816e32b4686bnexus
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio_stream::stream_map::rand::thread_rng_n::hbfb0a48dd232e861
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio_stream::stream_map::rand::thread_rng_n::hbfb0a48dd232e861
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio_stream::wrappers::watch::make_future::{{closure}}::hb880c97bc6e05dbf
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::task::coop::Coop<F> as core::future::future::Future>::poll::h99257c0dba7b166a
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::sync::notify::Notified as core::future::future::Future>::poll::hfc7c60615f9eda19
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::sync::notify::NotifiedProject::poll_notified::h50a58047a385bfb3 (.llvm.8247371145572912925)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::sync::notify::Notified as core::future::future::Future>::poll::hfc7c60615f9eda19
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio_stream::wrappers::watch::make_future::{{closure}}::hb880c97bc6e05dbf
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio_stream::wrappers::watch::make_future::{{closure}}::hb880c97bc6e05dbf
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::task::coop::Coop<F> as core::future::future::Future>::poll::h99257c0dba7b166a
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::sync::notify::Notified as core::future::future::Future>::poll::hfc7c60615f9eda19
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::sync::notify::NotifiedProject::poll_notified::h50a58047a385bfb3 (.llvm.8247371145572912925)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::sync::notify::Notified as core::future::future::Future>::poll::hfc7c60615f9eda19
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio_stream::wrappers::watch::make_future::{{closure}}::hb880c97bc6e05dbf
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio_stream::wrappers::watch::make_future::{{closure}}::hb880c97bc6e05dbf
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::task::coop::Coop<F> as core::future::future::Future>::poll::h99257c0dba7b166a
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::sync::notify::Notified as core::future::future::Future>::poll::hfc7c60615f9eda19
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::sync::notify::NotifiedProject::poll_notified::h50a58047a385bfb3 (.llvm.8247371145572912925)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::sync::notify::Notified as core::future::future::Future>::poll::hfc7c60615f9eda19
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio_stream::wrappers::watch::make_future::{{closure}}::hb880c97bc6e05dbf
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio_stream::wrappers::watch::make_future::{{closure}}::hb880c97bc6e05dbf
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::task::coop::Coop<F> as core::future::future::Future>::poll::h99257c0dba7b166a
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::sync::notify::Notified as core::future::future::Future>::poll::hfc7c60615f9eda19
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::sync::notify::NotifiedProject::poll_notified::h50a58047a385bfb3 (.llvm.8247371145572912925)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::sync::notify::Notified as core::future::future::Future>::poll::hfc7c60615f9eda19
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio_stream::wrappers::watch::make_future::{{closure}}::hb880c97bc6e05dbf
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio_stream::wrappers::watch::make_future::{{closure}}::hb880c97bc6e05dbf
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::task::coop::Coop<F> as core::future::future::Future>::poll::h99257c0dba7b166a
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::sync::notify::Notified as core::future::future::Future>::poll::hfc7c60615f9eda19
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::sync::notify::NotifiedProject::poll_notified::h50a58047a385bfb3 (.llvm.8247371145572912925)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::sync::notify::Notified as core::future::future::Future>::poll::hfc7c60615f9eda19
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio_stream::wrappers::watch::make_future::{{closure}}::hb880c97bc6e05dbf
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return _ZN97_$LT$tokio_stream..stream_map..StreamMap$LT$K$C$V$GT$$u20$as$u20$futures_core..stream..Stream$GT$9poll_next17he816e32b4686bnexus
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return _ZN97_$LT$tokio_stream..stream_map..StreamMap$LT$K$C$V$GT$$u20$as$u20$futures_core..stream..Stream$GT$9poll_next17he816e32b4686bnexus
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::sync::mpsc::chan::Rx<T,S>::recv::hf1e10cca61c2f69a
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::sync::mpsc::list::Rx$LT$T$GT$::pop::h8499e2d478bfed1d (.llvm.16696573479048730848)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::sync::mpsc::list::Rx$LT$T$GT$::pop::h8499e2d478bfed1d (.llvm.16696573479048730848)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::sync::task::atomic_waker::AtomicWaker::register_by_ref::hce23dd46925d2997
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::task::waker::clone_waker::h7c601355f53dcb0a
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::runtime::task::waker::clone_waker::h7c601355f53dcb0a
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::task::waker::drop_waker::h7a1ab930376402e0
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::sync::mpsc::list::Rx$LT$T$GT$::pop::h8499e2d478bfed1d (.llvm.16696573479048730848)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::sync::mpsc::list::Rx$LT$T$GT$::pop::h8499e2d478bfed1d (.llvm.16696573479048730848)
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::task::coop::RestoreOnPending as core::ops::drop::Drop>::drop::hb2bd5dfb9ef37277
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::sync::mpsc::chan::Rx<T,S>::recv::hf1e10cca61c2f69a
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry <tokio::runtime::task::core::TaskIdGuard as core::ops::drop::Drop>::drop::h5ba00a5cc15b07ae
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return <tokio::runtime::task::core::TaskIdGuard as core::ops::drop::Drop>::drop::h5ba00a5cc15b07ae
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::runtime::task::core::Core<T,S>::poll::h1fae05d75a08aedd
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::runtime::task::state::State::transition_to_idle::h25ccd06b80c3cea1
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::runtime::task::state::State::transition_to_idle::h25ccd06b80c3cea1
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 tokio815::task-poll-end 
BRM42220031 # 

Of particular note:

• rebalance-start is one of the first things it does. It's the first thing outside tokio that it does.
• rebalance-done is one of the last things it does. It's the last thing outside tokio that it does.
• All of this happened not close in time to the sending. It finished 15 seconds before the request came in. From other rounds of tracing, it seems like this task is doing nothing but the rebalancing.
• We do see two calls to recv in there:

BRM42220031 # grep 'taskid   130' hang7_demangled.out  | grep recv
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::entry tokio::sync::mpsc::chan::Rx<T,S>::recv::hf1e10cca61c2f69a
2025 Oct 20 21:58:43.053504035 tid    89 taskid   130 pid815::return tokio::sync::mpsc::chan::Rx<T,S>::recv::hf1e10cca61c2f69a
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::entry tokio::sync::mpsc::chan::Rx<T,S>::recv::hf1e10cca61c2f69a
2025 Oct 20 21:58:43.054504228 tid    89 taskid   130 pid815::return tokio::sync::mpsc::chan::Rx<T,S>::recv::hf1e10cca61c2f69a

Putting all this together it looks like:

• The tasks handling these HTTP requests are blocking on mpsc::Sender::send trying to acquire a qorb claim
• The mpsc::Receiver is calling recv() as part of a tokio::select! loop, but it's not ever getting any messages from the channel

This could happen if the receiver is so busy getting other events from the tokio::select! loop that it never manages to get this one. That's not what's going on because there are long intervals between task-poll-end and task-poll-start where the task is idle. Alternatively, it could be that the runtime and/or CPUs are so busy with other work that they're not managing to poll this task, even though it's available. It's definitely not the CPUs, though. They're pretty idle (based on mpstat 1) and the process is also not using much CPU (based on prstat -mLc -p 815 1). It doesn't seem like the runtime, but that's admittedly harder to be sure about. One thing I can say is that tid 89 was running this task until 21:58:43.054504228. At that point the task became idle. It wasn't until 21:58:54.349971061 that the same thread picked up a different task. So it's not like this thread was busy running other tasks.

The other obvious conclusion is that there's some bug in the mpsc channel implementation such that the Sender can think the channel is full while the receiver thinks it's empty. I found no recent tokio issues, open or closed, about this. It seems unlikely, but I'm running out of other explanations.

Next steps

Questions we wish we could answer, but currently cannot easily:

• Can we confirm that the sender is trying to send to the same channel that the receiver is reading from? (This is hard because printing data structures from the core file or from DTrace is hard.)
• Does the channel actually have a message on it or not? If so, how long has it been there? (Same problem.)
• What exactly does tokio think these tasks are blocked on, when they're blocked? (We think the HTTP request is blocked on sending to the channel. Is it? We think the pool task is indeed calling recv and that's blocking because there are no messages present. Is that right?)
• Is there somehow more than one pool and we're looking at different instances? (We can't find any evidence of that. From code inspection, there shouldn't be.)

Approaches:

• work on tooling to print out these data structures, either in general or just do it by hand for our specific case?

[davepacheco]

I've put a bunch of the data into catacomb:/staff/core/omicron-9259

dap@castle /staff/core/omicron-9259 $ ls -l
total 53583
-rw-rw-r--+  1 dap      staff      17842 Oct 20 23:13 hang1.out.gz
-rw-rw-r--+  1 dap      staff      14365 Oct 20 23:13 hang2_demangled.out.gz
-rw-rw-r--+  1 dap      staff      14404 Oct 20 23:13 hang2.out.gz
-rw-rw-r--+  1 dap      staff      55340 Oct 20 23:13 hang3_demangled.out.gz
-rw-rw-r--+  1 dap      staff      55204 Oct 20 23:13 hang3.out.gz
-rw-rw-r--+  1 dap      staff      41235 Oct 20 23:13 hang4_demangled.out.gz
-rw-rw-r--+  1 dap      staff      41115 Oct 20 23:13 hang4.out.gz
-rw-rw-r--+  1 dap      staff     160681 Oct 20 23:13 hang5_demangled.out.gz
-rw-rw-r--+  1 dap      staff     161667 Oct 20 23:13 hang5.out.gz
-rw-rw-r--+  1 dap      staff     619143 Oct 20 23:13 hang6_demangled.out.gz
-rw-rw-r--+  1 dap      staff     622419 Oct 20 23:13 hang6.out.gz
-rw-rw-r--+  1 dap      staff     755938 Oct 20 23:13 hang7_demangled.gz
-rw-rw-r--+  1 dap      staff    14369200 Oct 20 23:13 hang7_demangled.out
-rw-rw-r--+  1 dap      staff     759677 Oct 20 23:13 hang7.gz
-rw-rw-r--+  1 dap      staff    14923083 Oct 20 23:13 hang7.out
-rw-rw-r--+  1 dap      staff    1930700 Oct 20 23:13 hang8.out.gz
-rw-rw-r--+  1 dap      staff    167960995 Oct 20 23:14 nexus-went-bad.log
-rwxrwxr-x+  1 dap      staff       2028 Oct 20 23:11 trace-nexus-hang-with-qorb-and-tokio-more.d
-rwxrwxr-x+  1 dap      staff       2190 Oct 20 23:11 trace-nexus-hang-with-qorb-and-tokio.d
-rwxrwxr-x+  1 dap      staff       1918 Oct 20 23:11 trace-nexus-hang-with-qorb.d
-rwxrwxr-x+  1 dap      staff       1735 Oct 20 23:11 trace-nexus-hang.d
-rwxrwxr-x+  1 dap      staff       1729 Oct 20 23:11 trace7.d
-rwxrwxr-x+  1 dap      staff       1730 Oct 20 23:11 trace8.d

I don't think there's anything interesting in hang1 - hang6, or the trace*.d scripts, that's not covered by trace.d/hang7.out. trace8 was an attempt to use DTrace -F (fancy mode) that didn't work out so that can be ignored, too. nexus-went-bad.log is the log file from the period where this Nexus started having this problem.

I've removed most of these from the sled on dogfood to avoid cluttering it up.

[davepacheco]

While doing this, we noticed that the quiesce subsystem should have stacks from where all the hung requests blocked waiting for database claims. I've saved the output of:

$ omdb nexus --nexus-internal-url http://[fd00:1122:3344:102::2f]:12232/ quiesce show --stacks > quiesce-show-stacks.txt

this into the same directory, along with:

$ omdb nexus --nexus-internal-url http://[fd00:1122:3344:102::2f]:12232/ quiesce show > quiesce-show.txt

These show:

dap@castle /staff/core/omicron-9259 $ head -n 20 quiesce-show.txt 
running normally (not quiesced, not quiescing)
saga quiesce:
    new sagas: Allowed
    drained as of blueprint: none
    blueprint for last completed recovery pass: 445f2516-dc2f-4203-b525-caac351973ea
    blueprint for last reassignment pass: 445f2516-dc2f-4203-b525-caac351973ea
    reassignment generation: 1 (pass running: no)
    recovered generation: 1
    recovered at least once successfully: yes
    recovery pending: yes (generation 1, blueprint id 445f2516-dc2f-4203-b525-caac351973ea)
    sagas running: 0
database connections held: 182859
    claim 756632 held since 2025-10-19 05:37:04.127467139 UTC (1day 15h 10m 16s 864ms ago)
    claim 756635 held since 2025-10-19 05:37:04.127906135 UTC (1day 15h 10m 16s 864ms ago)
    claim 756636 held since 2025-10-19 05:37:04.132467182 UTC (1day 15h 10m 16s 859ms ago)
    claim 756637 held since 2025-10-19 05:37:04.132873645 UTC (1day 15h 10m 16s 859ms ago)
    claim 756638 held since 2025-10-19 05:37:04.185553490 UTC (1day 15h 10m 16s 806ms ago)
    claim 756639 held since 2025-10-19 05:37:04.227669397 UTC (1day 15h 10m 16s 764ms ago)
    claim 756640 held since 2025-10-19 05:37:04.227796322 UTC (1day 15h 10m 16s 764ms ago)
    claim 756641 held since 2025-10-19 05:37:04.260190724 UTC (1day 15h 10m 16s 731ms ago)
...

The stacks are pretty much what you'd expect and not all that helpful:

dap@castle /staff/core/omicron-9259 $ head -n 100 quiesce-show-stacks.txt 
running normally (not quiesced, not quiescing)
saga quiesce:
    new sagas: Allowed
    drained as of blueprint: none
    blueprint for last completed recovery pass: 445f2516-dc2f-4203-b525-caac351973ea
    blueprint for last reassignment pass: 445f2516-dc2f-4203-b525-caac351973ea
    reassignment generation: 1 (pass running: no)
    recovered generation: 1
    recovered at least once successfully: yes
    recovery pending: yes (generation 1, blueprint id 445f2516-dc2f-4203-b525-caac351973ea)
    sagas running: 0
database connections held: 182871
    claim 756632 held since 2025-10-19 05:37:04.127467139 UTC (1day 15h 10m 26s 535ms ago)
    acquired by:
           0: nexus_db_queries::db::datastore::DataStore::pool_connection_unauthorized::{{closure}}
           1: nexus_db_queries::db::datastore::DataStore::pool_connection_authorized::{{closure}}
           2: nexus_db_queries::db::datastore::auth::<impl nexus_auth::storage::Storage for nexus_db_queries::db::datastore::DataStore>::role_asgn_list_for::{{closure}}
           3: nexus_auth::authz::roles::load_directly_attached_roles::{{closure}}
           4: nexus_auth::authz::roles::load_roles_for_resource_tree::{{closure}}

    claim 756635 held since 2025-10-19 05:37:04.127906135 UTC (1day 15h 10m 26s 535ms ago)
    acquired by:
           0: nexus_db_queries::db::datastore::DataStore::pool_connection_unauthorized::{{closure}}
           1: nexus_db_queries::db::datastore::DataStore::pool_connection_authorized::{{closure}}
           2: nexus_db_queries::db::datastore::lookup_interface::<impl nexus_db_lookup::datastore_interface::LookupDataStore for nexus_db_queries::db::datastore::DataStore>::pool_connection_authorized::{{closure}}

    claim 756636 held since 2025-10-19 05:37:04.132467182 UTC (1day 15h 10m 26s 530ms ago)
    acquired by:
           0: nexus_db_queries::db::datastore::DataStore::pool_connection_unauthorized::{{closure}}
           1: nexus_db_queries::db::datastore::DataStore::pool_connection_authorized::{{closure}}
           2: omicron_nexus::app::background::tasks::support_bundle_collector::BundleCollection::collect_host_ereports::{{closure}}
           3: tokio::runtime::task::harness::Harness<T,S>::poll

    claim 756637 held since 2025-10-19 05:37:04.132873645 UTC (1day 15h 10m 26s 530ms ago)
    acquired by:
           0: nexus_db_queries::db::datastore::DataStore::pool_connection_unauthorized::{{closure}}
           1: nexus_db_queries::db::datastore::DataStore::pool_connection_authorized::{{closure}}
           2: omicron_nexus::app::background::tasks::support_bundle_collector::BundleCollection::collect_sp_ereports::{{closure}}
           3: tokio::runtime::task::harness::Harness<T,S>::poll
...

[davepacheco]

In case we want to dig into the channel data structure, I created a core file like this. First I wanted to check that I was tracing something that looked right:

dtrace -q -n 'tokio$1:::task-poll-start/arg0 == 130/{ self->f = 1; printf("%Y task 130 poll start\n", walltimestamp); }' -n 'tokio$1:::task-poll-end/self->f/{ self->f = 0; printf("%Y task 130 poll end\n", walltimestamp)}' -n 'pid$1::*mpsc*recv*:entry/self->f/{ printf("%Y task 130 %s:entry\n", walltimestamp, probefunc); }' 815
2025 Oct 20 23:11:43 task 130 poll start
2025 Oct 20 23:11:43 task 130 _ZN5tokio4sync4mpsc4chan15Rx$LT$T$C$S$GT$4recv17hf1e10cca61c2f69aE:entry
2025 Oct 20 23:11:43 task 130 _ZN5tokio4sync4mpsc4chan15Rx$LT$T$C$S$GT$4recv17hf1e10cca61c2f69aE:entry
2025 Oct 20 23:11:43 task 130 poll end
2025 Oct 20 23:12:43 task 130 poll start
2025 Oct 20 23:12:43 task 130 _ZN5tokio4sync4mpsc4chan15Rx$LT$T$C$S$GT$4recv17hf1e10cca61c2f69aE:entry
2025 Oct 20 23:12:43 task 130 _ZN5tokio4sync4mpsc4chan15Rx$LT$T$C$S$GT$4recv17hf1e10cca61c2f69aE:entry
2025 Oct 20 23:12:43 task 130 poll end
2025 Oct 20 23:13:43 task 130 poll start
2025 Oct 20 23:13:43 task 130 _ZN5tokio4sync4mpsc4chan15Rx$LT$T$C$S$GT$4recv17hf1e10cca61c2f69aE:entry
2025 Oct 20 23:13:43 task 130 poll end
2025 Oct 20 23:14:43 task 130 poll start
2025 Oct 20 23:14:43 task 130 _ZN5tokio4sync4mpsc4chan15Rx$LT$T$C$S$GT$4recv17hf1e10cca61c2f69aE:entry
2025 Oct 20 23:14:43 task 130 poll end
2025 Oct 20 23:15:43 task 130 poll start
2025 Oct 20 23:15:43 task 130 _ZN5tokio4sync4mpsc4chan15Rx$LT$T$C$S$GT$4recv17hf1e10cca61c2f69aE:entry
2025 Oct 20 23:15:43 task 130 poll end
2025 Oct 20 23:16:43 task 130 poll start
2025 Oct 20 23:16:43 task 130 _ZN5tokio4sync4mpsc4chan15Rx$LT$T$C$S$GT$4recv17hf1e10cca61c2f69aE:entry
2025 Oct 20 23:16:43 task 130 poll end
^C

Then I used this to stop it on entry to that function:

BRM42220031 # dtrace -w -q -n 'tokio$1:::task-poll-start/arg0 == 130/{ self->f = 1; printf("%Y task 130 poll start\n", walltimestamp); }' -n 'tokio$1:::task-poll-end/self->f/{ self->f = 0; printf("%Y task 130 poll end\n", walltimestamp)}' -n 'pid$1::*mpsc*recv*:entry/self->f/{ printf("%Y task 130 %s:entry\n", walltimestamp, probefunc); stop(); exit(0); }' 815
2025 Oct 20 23:18:15 task 130 poll start
2025 Oct 20 23:18:15 task 130 _ZN5tokio4sync4mpsc4chan15Rx$LT$T$C$S$GT$4recv17hf1e10cca61c2f69aE:entry

Then:

BRM42220031 # cd /pool/ext/0d2805da-6d24-4e57-a700-0c3865c05544/crypt/debug/oxz_nexus_2898657e-4141-4c05-851b-147bffc6bbbd
BRM42220031 # gcore 815
gcore: core.815 dumped
BRM42220031 # prun 815
BRM42220031 # 

I've copied the core file to the same directory as the other data.