nexus `external_endpoints` task hung

[davepacheco]

This was observed in our colo environment and (internal) details are under oxidecomputer/colo#148.

The upshot is that some runaway automation created a ton of TLS certificates again and in one of the three Nexus instances, the external_endpoints task got hung, apparently for days. The root cause is still being determined but appears to be a missed wakeup in the kernel on the database side. This ticket will cover the analysis and information about mitigation and workarounds. More details coming!

[davepacheco]

Initial observations

Attempting to use a particular Silo by DNS name results in intermittent TLS errors.

This turned out to be one of the silos added after the external_endpoints task started hanging. The intermittency was a result of the randomness of which Nexus instance you hit. Only one of the three got stuck and would produce this error. The other two were fine.

Mitigation

Our colo environment essentially has the ability to override the external DNS that gets served to end users (from one backed by the rack). We used this to remove the bad Nexus from external DNS, which restored service to end users while allowing us to debug it.

Follow ups

Besides fixing the underlying bug, we might explore:

• An operational switch (with omdb) to effect the same kind of change that we applied outside the environment: to temporarily remove a Nexus instance from external DNS to allow further debugging. This is not the first time we've had an individual instance stuck and wanted to debug it but it was affecting service. While such an override is in place, this should be reported as an Active Problem so that nobody forgets about it. (CC @hawkw)
• Using PostgreSQL's session_timeout with a generous timeout to cause connections like this to terminate? (We'd ideally want to test that it would actually work -- it's not clear that it would, depending on how the timeout is implemented.)
• Some other generous timeout on the client?

Data collected

From the busted Nexus, omdb nexus background-tasks show:

task: "external_endpoints"
  configured period: every 1m
  currently executing: iter 56640, triggered by a periodic timer firing
    started at 2026-01-13T06:24:06.793Z, running for 223934474ms
  last completed activation: iter 56639, triggered by a periodic timer firing
    started at 2026-01-13T06:20:46.661Z (224134s ago) and ran for 200100ms
    external API endpoints: 161 ('*' below marks default)

          SILO_ID                              DNS_NAME
          3274bfe0-2cef-4983-9315-740cf1e4ad19 admin.sys.r3.oxide-preview.com

A good one looks like this:

task: "external_endpoints"
  configured period: every 1m
  currently executing: iter 56608, triggered by a periodic timer firing
    started at 2026-01-15T20:32:54.884Z, running for 54816ms
  last completed activation: iter 56607, triggered by a periodic timer firing
    started at 2026-01-15T20:28:59.759Z (289s ago) and ran for 235091ms
    external API endpoints: 162 ('*' below marks default)

          SILO_ID                              DNS_NAME
          3274bfe0-2cef-4983-9315-740cf1e4ad19 admin.sys.r3.oxide-preview.com

From the database, we collected SHOW STATEMENTS and saw a query that was stuck for a few days.

We identified a particular Nexus process and cockroach process that were involved in the stuck query. We collected:

• both sides: pfiles
• both sides: userland stacks
• a core file from the Nexus side
• both sides: the struct sonode in the kernel
• both sides: netstat -f inet -P tcp
• both sides: connstat -o laddr,lport,raddr,rport,inbytes,outbytes,retransbytes,suna,unsent,state
• cockroach side: cockroach debug zip (includes query information, goroutine stacks, etc.)
• cockroach side: kernel event port state

This data is referenced in oxidecomputer/colo#148 but I'll include the relevant stuff in comments below.

The affected Nexus: fd00:1122:3344:11d::22 (port 64207 is the one that sent the stuck query).
The affected Cockroach: fd00:1122:3344:105::3 (port 32221 is CockroachDB) (node 1, IP determined via cockroach node status).
The query started around 2026-01-13T06:24:12.285734Z.

Initial observations

omdb nexus background-tasks show for the affected Nexus reported that the external_endpoints task had been running for days (since about the time above).

The CockroachDB cluster reports exactly one query running, which involves listing a page of 200 TLS certificates. This query has been running for 2+ days, since 2026-01-13 06:24:12.285734. This query completes in 3-4ms when run directly with cockroach sql. (This rules out the possibility that a lock is held on these exact rows.) Other queries are running in CockroachDB and completing promptly. This is just the only one that’s sticking around.

root@[fd00:1122:3344:116::3]:32221/omicron> SHOW CLUSTER STATEMENTS;
              query_id             | node_id |            session_id            | user_name |           start            |                                                                                                                                                                                                               query                                                                                                                                                                                                                |         client_address         | application_name | distributed |   phase
-----------------------------------+---------+----------------------------------+-----------+----------------------------+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------------------+------------------+-------------+------------
  188d6fdba1e8ebb10000000000000005 |       5 | 188d6fd8b85ed08b0000000000000005 | root      | 2026-01-23 18:33:37.731301 | SHOW CLUSTER STATEMENTS                                                                                                                                                                                                                                                                                                                                                                                                            | [fd00:1122:3344:116::3]:39621  | $ cockroach sql  |    false    | executing
  188a364004fcf09e0000000000000001 |       1 | 188a363a9bcdc8f90000000000000001 | root      | 2026-01-13 06:24:12.285734 | SELECT certificate.id, certificate.name, certificate.description, certificate.time_created, certificate.time_modified, certificate.time_deleted, certificate.silo_id, certificate.service, certificate.cert, certificate.key FROM certificate WHERE (((certificate.id > '7393254a-db08-4ba9-bed2-c1334fb9fa13') AND (certificate.time_deleted IS NULL)) AND (certificate.service = 'nexus')) ORDER BY certificate.id ASC LIMIT 200 | [fd00:1122:3344:11d::22]:64207 |                  |    false    | executing
  188d6fdba232c6060000000000000004 |       4 | 188d6fd5521ef63a0000000000000004 | root      | 2026-01-23 18:33:37.736132 | SELECT 1                                                                                                                                                                                                                                                                                                                                                                                                                           | [fd00:1122:3344:106::22]:46721 |                  |    NULL     | preparing
(3 rows)

root@[fd00:1122:3344:116::3]:32221/omicron> SELECT
    t.id AS txn_id,
    t.start,
    t.num_stmts,
    t.num_retries,
    t.num_auto_retries,
    now() - t.start AS txn_duration,
    t.txn_string,
    s.query,
    s.phase,
    s.application_name
FROM crdb_internal.cluster_transactions t
JOIN crdb_internal.cluster_queries s ON t.id = s.txn_id
ORDER BY txn_duration DESC;
                 txn_id                |           start            | num_stmts | num_retries | num_auto_retries |      txn_duration       |                                                                                                  txn_string                                                                                                   |                                                                                                                                                                                                               query                                                                                                                                                                                                                |   phase   |    application_name
---------------------------------------+----------------------------+-----------+-------------+------------------+-------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-----------+--------------------------
  5dbd8ea7-ae6c-437c-8c1a-80c638ee606d | 2026-01-13 06:24:12.285766 |         1 |           0 |                0 | 10 days 12:10:44.096467 | "sql txn" meta={id=5dbd8ea7 key=/Min pri=0.00827964 epo=0 ts=1768285452.285758693,0 min=1768285452.285758693,0 seq=0} lock=false stat=PENDING rts=1768285452.285758693,0 wto=false gul=1768285452.785758693,0 | SELECT certificate.id, certificate.name, certificate.description, certificate.time_created, certificate.time_modified, certificate.time_deleted, certificate.silo_id, certificate.service, certificate.cert, certificate.key FROM certificate WHERE (((certificate.id > '7393254a-db08-4ba9-bed2-c1334fb9fa13') AND (certificate.time_deleted IS NULL)) AND (certificate.service = 'nexus')) ORDER BY certificate.id ASC LIMIT 200 | executing |
  9dd86573-1826-489a-8ef9-2b649791d6e5 | 2026-01-23 18:34:51.895158 |         1 |           0 |                0 | 00:00:04.487075         | "sql txn" meta={id=9dd86573 key=/Min pri=0.00024685 epo=0 ts=1769193261.895186426,0 min=1769193261.895186426,0 seq=0} lock=false stat=PENDING rts=1769193261.895186426,0 wto=false gul=1769193261.895186426,0 | CREATE STATISTICS __auto__ FROM [377] WITH OPTIONS THROTTLING 0.9 AS OF SYSTEM TIME '-30s'                                                                                                                                                                                                                                                                                                                                         | executing | $ internal-create-stats
  130c9bfa-7849-4b53-849e-303f0077225d | 2026-01-23 18:34:56.382249 |         1 |           0 |                0 | -00:00:00.000016        | "sql txn" meta={id=130c9bfa key=/Min pri=0.01592590 epo=0 ts=1769193296.382241162,0 min=1769193296.382241162,0 seq=0} lock=false stat=PENDING rts=1769193296.382241162,0 wto=false gul=1769193296.882241162,0 | SELECT t.id AS txn_id, t.start, t.num_stmts, t.num_retries, t.num_auto_retries, now() - t.start AS txn_duration, t.txn_string, s.query, s.phase, s.application_name FROM crdb_internal.cluster_transactions AS t JOIN crdb_internal.cluster_queries AS s ON t.id = s.txn_id ORDER BY txn_duration DESC                                                                                                                             | executing | $ cockroach sql
(3 rows)


Time: 11ms total (execution 11ms / network 1ms)

root@[fd00:1122:3344:116::3]:32221/omicron> select locks.*,s.query from crdb_internal.cluster_locks as locks LEFT JOIN crdb_internal.cluster_queries s ON locks.txn_id = s.txn_id;
  range_id | table_id | database_name | schema_name | table_name | index_name | lock_key | lock_key_pretty | txn_id | ts | lock_strength | durability | granted | contended | duration | query
-----------+----------+---------------+-------------+------------+------------+----------+-----------------+--------+----+---------------+------------+---------+-----------+----------+--------
(0 rows)


Time: 135ms total (execution 134ms / network 0ms)

On the Nexus side: no thread is spinning 100% on-CPU. (Determined by watching prstat -mLc -p NEXUS_PID 1 for several seconds.) (This rules out a spinloop and some kinds of starvation we've seen in the past resulting from lack of task stealing in tokio.)

From netstat and connstat:

root@oxz_nexus_f3f20c9b:~# netstat -f inet6 -P tcp -n

TCP: IPv6
   Local Address                     Remote Address                 Swind  Send-Q Rwind  Recv-Q    State      If 
--------------------------------- --------------------------------- ------ ------ ------ ------ ----------- -----
...
fd00:1122:3344:11d::22.64207      fd00:1122:3344:105::3.32221       1008864      0 1008864      0 ESTABLISHED

root@oxz_nexus_f3f20c9b:~# connstat -o laddr,lport,raddr,rport,inbytes,outbytes,retransbytes,suna,unsent,state -Flport=64207
LADDR LPORT RADDR RPORT INBYTES OUTBYTES RETRANSBYTES SUNA UNSENT STATE
fd00:1122:3344:11d::22 64207 fd00:1122:3344:105::3 32221 330137 2559 0 0 0 ESTABLISHED

root@oxz_cockroachdb_e8f86fbb:~# netstat -f inet6 -P tcp -n

TCP: IPv6
   Local Address                     Remote Address                 Swind  Send-Q Rwind  Recv-Q    State      If 
--------------------------------- --------------------------------- ------ ------ ------ ------ ----------- -----
...
fd00:1122:3344:105::3.32221       fd00:1122:3344:11d::22.64207      1008864      0 1008864      0 ESTABLISHED 
...

root@oxz_cockroachdb_e8f86fbb:~# connstat -o laddr,lport,raddr,rport,inbytes,outbytes,retransbytes,suna,unsent,state -Frport=64207
LADDR LPORT RADDR RPORT INBYTES OUTBYTES RETRANSBYTES SUNA UNSENT STATE
fd00:1122:3344:105::3 32221 fd00:1122:3344:11d::22 64207 2559 330137 0 0 0 ESTABLISHED

Both sides agree:

• the 4-tuple exists (so no silently dropped TCP connection)
• on the number of bytes sent and received in each direction
• there is no unsent or unacknowledged data
• no retransmits

This rules out a lot of potential networking issues.

The cockroach cluster itself appears healthy based on cockroach node status:

root@oxz_cockroachdb_371fba3a:~# cockroach node status --url 'postgresql://root@[fd00:1122:3344:116::3]:32221/omicron?sslmode=disable' --all
warning: --url specifies database "omicron", but command "status" does not accept a database name - database name ignored
  id |            address            |          sql_address          |          build          |         started_at         |         updated_at         | locality | is_available | is_live | replicas_leaders | replicas_leaseholders | ranges | ranges_unavailable | ranges_underreplicated | live_bytes  |  key_bytes  | value_bytes | intent_bytes | system_bytes | gossiped_replicas | is_decommissioning | membership | is_draining
-----+-------------------------------+-------------------------------+-------------------------+----------------------------+----------------------------+----------+--------------+---------+------------------+-----------------------+--------+--------------------+------------------------+-------------+-------------+-------------+--------------+--------------+-------------------+--------------------+------------+--------------
   1 | [fd00:1122:3344:105::3]:32221 | [fd00:1122:3344:105::3]:32221 | v22.1.22-44-g2eee7afbdf | 2025-11-20 22:29:23.27921  | 2026-01-23 18:35:52.938583 |          |         true |    true |               66 |                    66 |    328 |                  0 |                      0 | 26567336099 | 10419486091 | 30397469148 |         5652 |      1194024 |        328        |              false |   active   |    false
   2 | [fd00:1122:3344:102::3]:32221 | [fd00:1122:3344:102::3]:32221 | v22.1.22-44-g2eee7afbdf | 2025-12-12 06:31:57.74912  | 2026-01-23 18:35:54.517761 |          |         true |    true |               65 |                    65 |    328 |                  0 |                      0 | 26567954799 | 10419481447 | 30397984201 |       241962 |      1194024 |        328        |              false |   active   |    false
   3 | [fd00:1122:3344:109::3]:32221 | [fd00:1122:3344:109::3]:32221 | v22.1.22-44-g2eee7afbdf | 2025-11-20 23:22:56.723109 | 2026-01-23 18:35:53.531484 |          |         true |    true |               61 |                    61 |    328 |                  0 |                      0 | 26567498266 | 10419181056 | 30397792591 |       314888 |       266125 |        328        |              false |   active   |    false
   4 | [fd00:1122:3344:11f::3]:32221 | [fd00:1122:3344:11f::3]:32221 | v22.1.22-44-g2eee7afbdf | 2025-11-20 21:26:24.825494 | 2026-01-23 18:35:50.682938 |          |         true |    true |               66 |                    66 |    328 |                  0 |                      0 | 26565957845 | 10417367742 | 30396468230 |        41654 |       266122 |        328        |              false |   active   |    false
   5 | [fd00:1122:3344:116::3]:32221 | [fd00:1122:3344:116::3]:32221 | v22.1.22-44-g2eee7afbdf | 2026-01-10 03:03:46.816112 | 2026-01-23 18:35:51.153122 |          |         true |    true |               70 |                    70 |    328 |                  0 |                      0 | 26566109776 | 10417409993 | 30396588284 |        84820 |       266122 |        328        |              false |   active   |    false
(5 rows)

It shows a normal-looking number of ranges/leaders/replicas/leaseholders per node and no unavailable or under-replicated ranges. All five nodes are "available" and not "draining".

Logs report no hosts or cluster nodes restarting around the time of the failure. There's nothing of note in the Cockroach node 1 log around the time of the failure. There's also nothing of note in the Nexus log around that time.

[davepacheco]

Nexus side (looks okay)

I spent some time with the Nexus core file to try to better understand if there was a missed wakeup or other sort of async Rust issue here. One thing that helps considerably is that the way we implemented async-bb8-diesel (our async adapter for diesel) is using block_on, which runs synchronous code in a thread where that's okay. So unlike most async code, which is hard to debug from a core file when blocked, we have the actual thread doing the work blocked in the core file.

We quickly found that thread 0x267f (9855) was our thread of interest. We got there by noticing that there were four threads in libpq in the core file, but it was the only one that wasn't moving over time. truss -p 7804/9855 showed it here for several hours:

truss -p 7804/9855
/9855:  pollsys(0xFFFFF5FFBD1FF2A8, 1, 0x00000000, 0x00000000) (sleeping...)

In the core file, the stack is:

> 267f::findstack -tv
stack pointer for thread 9855 [tokio-runtime-worker]: fffff5ffbd1ff240
[ fffff5ffbd1ff240 libc.so.1`__pollsys+0xa() ]
  fffff5ffbd1ff280 int libc.so.1`poll+0x5a((struct pollfd *)fffff5ffbd1ff2a8, (nfds_t)1, (int)ffffffff)
  fffff5ffbd1ff3f0 libpq.so.5`pqSocketCheck.part.0+0x99()
  fffff5ffbd1ff420 int libpq.so.5`pqWaitTimed+0x34()
  fffff5ffbd1ff490 PGresult * libpq.so.5`PQgetResult+0x88()
  fffff5ffbd1ff540 diesel::pg::connection::stmt::Statement::execute::h73c071924e8904dc+0x2cc()
  fffff5ffbd1ff880 <diesel::pg::connection::PgConnection as diesel::connection::LoadConnection<B>>::load::ha4a5a270929110f7+0x5f2()
  fffff5ffbd1ffab0 <diesel_dtrace::DTraceConnection<C> as diesel::connection::LoadConnection>::load::h7f8a5765e46facc9+0x45e()
  fffff5ffbd1ffb90 diesel::query_dsl::RunQueryDsl::load::h55ecc0df851af2e0+0x81()
  fffff5ffbd1ffcf0 <tokio::runtime::blocking::task::BlockingTask<T> as core::future::future::Future>::poll::hae72cb24b8926d16+0x145()
  fffff5ffbd1ffdf0 tokio::runtime::task::harness::Harness<T,S>::poll::he1f6e892b5c3aa11+0x6f()
  fffff5ffbd1ffea0 tokio::runtime::blocking::pool::Inner::run::ha21447871d64532b+0xe4()
  fffff5ffbd1ffee0 std::sys::backtrace::__rust_begin_short_backtrace::h8317f95ccfa91cd7+0x3e()
  fffff5ffbd1fff80 core::ops::function::FnOnce::call_once{{vtable.shim}}::hc15a7237adc9a859+0x97()
  fffff5ffbd1fffb0 std::sys::pal::unix::thread::Thread::new::thread_start::h51c10c3cf848ec37+0x2f()
  fffff5ffbd1fffe0 void * libc.so.1`_thrp_setup+0x77((ulwp_t *)fffff5ffedb32240)
  fffff5ffbd1ffff0 libc.so.1`_lwp_start()

At the top of the stack we see the call to poll with a pollset of size 1 and an infinite timeout. Let's look at the pollset:

> fffff5ffbd1ff2a8::print struct pollfd
{
    fd = 0x89
    events = 0x9
    revents = 0
}

This is fd 0x89 = 137. Those events are POLLIN | POLLERR. That's what the thread is waiting for on this fd.

From pfiles, fd 137 is:

root@oxz_nexus_f3f20c9b:~# pfiles 7804
7804:   /opt/oxide/omicron-nexus/bin/nexus /var/svc/manifest/site/nexus/config
...
 137: S_IFSOCK mode:0666 dev:525,0 ino:2303604654 uid:0 gid:0 rdev:0,0
      O_RDWR|O_NONBLOCK|O_CLOEXEC
        SOCK_STREAM
        SO_KEEPALIVE,SO_SNDBUF(49152),SO_RCVBUF(1008864)
        sockname: AF_INET6 fd00:1122:3344:11d::22  port: 64207
        peername: AF_INET6 fd00:1122:3344:105::3  port: 32221
...

That is the same four-tuple (IP/port pairs) that we saw on the CockroachDB side that was responsible for the query. This tells us pretty conclusively that it's this thread in Nexus that's trying to make that query (and that makes sense, since it's been blocked).

Next I wanted to find more information from libpq. At least on my dev system, libpq comes from a PostgreSQL 13.11 package, so I went to the source for PostgreSQL 13.11. I won't be deep linking everywhere here but the function on the stack here is PQgetResult, whose source in the latest stable PostgreSQL 13 is here.

The main structure of interest is the struct pg_conn. Miraculously, our core file seems to have CTF for libpq because mdb knows about struct pg_conn. I initially tried to fish the arguments from the PQgetResult stack frame, but without -msave_args (or equivalent), this proved hard. Instead, I took a brute force approach: I started from the frame pointer near the top of the stack and tried to print everything I could find as a struct pg_conn, printed the dbName field (which I'd already figured should be "omicron"), and looked for anything that looked right:

> fffff5ffbd1ff240,0t128/Kn  | ::print -a struct pg_conn dbName ! grep omicron
mdb: failed to read dbName pointer at 51: no mapping for address
mdb: failed to read dbName pointer at 50: no mapping for address
mdb: failed to read dbName pointer at d000000000bb9: no mapping for address
mdb: failed to read dbName pointer at 9000000d9: no mapping for address
..
1b15eb060 dbName = 0xde588ad8 "omicron"
...
1b15eb060 dbName = 0xde588ad8 "omicron"
...
1b15eb060 dbName = 0xde588ad8 "omicron"
...
1b15eb060 dbName = 0xde588ad8 "omicron"
...
1b15eb060 dbName = 0xde588ad8 "omicron"

This got several valid hits -- fortunately, all the same value. Now, the dbName field is at offset 0x50:

> ::offsetof 'struct pg_conn' dbName
offsetof (struct pg_conn, dbName) = 0x50, sizeof (...->dbName) = 8

so here's the full struct pgConn:

> 1b15eb060-50=p
                0x1b15eb010
> 0x1b15eb010::print struct pg_conn
{
    pghost = 0x12b690040 "fd00:1122:3344:105::3"
    pghostaddr = 0
    pgport = 0xf0fda528 "32221"
    pgtty = 0xe726a3b8 ""
    connect_timeout = 0
    pgtcp_user_timeout = 0
    client_encoding_initial = 0
    pgoptions = 0x19a76e5d8 ""
    appname = 0
    fbappname = 0
    dbName = 0xde588ad8 "omicron"
    replication = 0
    pguser = 0x179ac7528 "root"
    pgpass = 0
    pgpassfile = 0xa2dd0510 "/root/.pgpass"
    channel_binding = 0x1948b10a8 "prefer"
    keepalives = 0
    keepalives_idle = 0
    keepalives_interval = 0
    keepalives_count = 0
    sslmode = 0x1a21b4438 "disable"
    sslcompression = 0x1e28ad8b8 "0"
    sslkey = 0
    sslcert = 0
    sslpassword = 0
    sslrootcert = 0
    sslcrl = 0
    requirepeer = 0
    gssencmode = 0x1b4fc8c08 "disable"
    krbsrvname = 0x1d01f9110 "postgres"
    gsslib = 0
    ssl_min_protocol_version = 0x6b416c08 "TLSv1.2"
    ssl_max_protocol_version = 0
    target_session_attrs = 0x1b3c8b18 "any"
    Pfdebug = 0
    noticeHooks = {
        noticeRec = libpq.so.5`defaultNoticeReceiver
        noticeRecArg = 0
        noticeProc = _ZN6diesel2pg10connection21noop_notice_processor17hef013f2e8fbd1ec8E
        noticeProcArg = 0
    }
    events = 0
    nEvents = 0
    eventArraySize = 0
    status = 0 (CONNECTION_OK)
    asyncStatus = 1 (PGASYNC_BUSY)
    xactStatus = 0 (PQTRANS_IDLE)
    queryclass = 1 (PGQUERY_EXTENDED)
    last_query = 0
    last_sqlstate = [ '\0', '\0', '\0', '\0', '\0', '\0' ]
    options_valid = 0x1
    nonblocking = 0
    singleRowMode = 0
    copy_is_binary = '\0'
    copy_already_done = 0
    notifyHead = 0
    notifyTail = 0
    nconnhost = 0x1
    whichhost = 0
    connhost = 0x1d8d2fc50
    connip = 0x114f0f580 "fd00:1122:3344:105::3"
    sock = 0x89
    laddr = {
        addr = {
            ss_family = 0x1a
            _ss_pad1 = [ '\372', '\317', '\0', '\0', '\0', '\0' ]
            _ss_align = +5.7189246e-169
            _ss_pad2 = [ '\0', '\0', '\0', '\0', '\0', '\0', '\0', '\"', '\0', '\0', '\0', '\0', '\0', '\0', '\0', '\0', '\0', '\0', '\0', '\0'
, '\0', '\0', '\0', '\0', '\0', '\0', '\0', '\0', '\0', '\0', '\0', '\0', ... ]
        }
        salen = 0x20
    }
    raddr = {
        addr = {
            ss_family = 0x1a
            _ss_pad1 = [ '}', '\335', '\0', '\0', '\0', '\0' ]
            _ss_align = +1.4514298e-284
            _ss_pad2 = [ '\0', '\0', '\0', '\0', '\0', '\0', '\0', '\003', '\0', '\0', '\0', '\0', '\0', '\0', '\0', '\0', '\0', '\0', '\0', '
\0', '\0', '\0', '\0', '\0', '\0', '\0', '\0', '\0', '\0', '\0', '\0', '\0', ... ]
        }
        salen = 0x20
    }
    pversion = 0x30000
    sversion = 0x1fbd0
    auth_req_received = 0x1
    password_needed = 0
    sigpipe_so = 0
    sigpipe_flag = 0x1
    write_failed = 0
    write_err_msg = 0
    try_next_addr = 0
    try_next_host = 0
    addrlist = 0
    addr_cur = 0
    addrlist_family = 0
    setenv_state = 8 (SETENV_STATE_IDLE)
    next_eo = 0
    send_appname = 0x1
    be_pid = 0x1c0ba0
    be_key = 0x60e75e2f
    pstatus = 0x1e7d6650
    client_encoding = 0x6
    std_strings = 0x1
    verbosity = 1 (PQERRORS_DEFAULT)
    show_context = 0x1 (PQSHOW_CONTEXT_ERRORS)
    lobjfuncs = 0
    inBuffer = 0x5e474010 "D"
    inBufSize = 0x4000
    inStart = 0xcd4
    inCursor = 0xcd4
    inEnd = 0xcd4
    outBuffer = 0xafc8e010 "B"
    outBufSize = 0x4000
    outCount = 0
    outMsgStart = 0x5f
    outMsgEnd = 0x63
    rowBuf = 0x41907850
    rowBufLen = 0x20
    result = 0x382e15d0
    next_result = 0
    sasl_state = 0
    ssl_in_use = 0
    allow_ssl_try = 0
    wait_ssl_try = 0
    ssl = 0
    peer = 0
    engine = 0
    errorMessage = {
        data = 0x1f66897d0 ""
        len = 0
        maxlen = 0x100
    }
    workBuffer = {
        data = 0x44130010 "key"
        len = 0x3
        maxlen = 0x100
    }
}

A bunch of those fields look right: pghost, pgport, dbName, sslmode, etc.

At this point I looked through the diesel execute code (see the thread stack above) and how it calls into libpq. It winds up calling either PQsendQueryPrepared or PQsendQueryParams. Both of those wind up calling PQsendQueryGuts, which winds up sending almost the same sequence of messages either way:

1528     /*
1529      * We will send Parse (if needed), Bind, Describe Portal, Execute, Sync,
1530      * using specified statement name and the unnamed portal.
1531      */

For pqSendQueryPrepared, the statement name is non-NULL and the command is NULL. For pqSendQueryParams, the statement name is the empty string and the command is non-NULL. Since last_query == NULL on the conn, we can infer that this was pqSendQueryPrepared.

Can we find anything interesting in the inBuffer and outBuffer? Let's start with the outBuffer. Summarizing the key fields from above:

> 0x1b15eb010::print -t struct pg_conn ! grep out[A-Z]
    char *outBuffer = 0xafc8e010 "B"
    int outBufSize = 0x4000
    int outCount = 0
    int outMsgStart = 0x5f
    int outMsgEnd = 0x63

From code inspection of the functions pqSendQueryPrepared calls:

• When starting to send a message:
  • we write the message type byte to the out buffer at "outCount"
  • outMsgStart is set just past that and this is where the length will go
  • outMsgEnd is set just past that
• If we were to write more bytes, we'd just write them at outMsgEnd and increment outCount
• When we finish the message, we compute the length as outMsgEnd - outMsgStart and store that at outMsgStart. Then we set outCount to outMsgEnd.
• We may do this whole process a few times to enqueue several messages.
• When we reach a flush or 8K, we attempt to send it all.
  • As we succeed, we shift it over in the buffer so the start of the buffer always reflects what's to be sent next
  • We always send up to outCount.
  • On success, outCount will become 0 again.

From the state above, we would expect that the last "send" included the bytes 0 - 0x63 from outBuffer. The last message would have started at outMsgStart - 1. That's a sync message that's 4 bytes long:

> 0xafc8e010+0x5f-1,0t5/nB
0xafc8e06e:     
                53      
                0       
                0       
                0       
                4       

I used this as a protocol reference. What we need to know here is pretty simple: 0x53 is S, which makes it a Sync message. The next four bytes are the length of the message including the length field, which is 4 bytes. So that's the whole message. This Sync message appears to tell the server that the client is done sending data for now.

I had Claude write a tool for parsing PostgreSQL protocol data from a dump. (Candidly, I did not verify this, so its output could be taken with a grain of salt.) Then I exported the buffer data from mdb:

> 0xafc8e010,0x63/nB

Copy/pasted that to a file called outbuffer.txt. I realized I needed to pad the single-digit bytes to be two digits for the next step, so I did that with vim:

%s/\s\+\([0-9a-f]\)\s\+$/ 0\1 /g

Then I turned it back into binary with:

$ xxd -r -p < outbuffer.txt > outbuffer.bin

Amazingly, the tool reported no errors and printed exactly what we'd expect for a client that had just sent a query using the "extended" protocol flow:

$ cargo run -- parse --direction client --file outbuffer.bin
...
Parsing frontend messages from offset 0 in "outbuffer.bin"
File size: 99 bytes

Starting parse at offset 0

[Offset 0] Type: 'B' (0x42), Length: 76
  Bind:
    Portal: ""
    Statement: "__diesel_stmt_2"
    Parameter format codes: 3 codes
      [0]: 1 (binary)
      [1]: 1 (binary)
      [2]: 1 (binary)
    Parameters: 3
      [0]: 16 bytes (binary)
      [1]: "nexus"
      [2]: 8 bytes (binary)
    Result format codes: 1
      [0]: 1 (binary)

[Offset 77] Type: 'D' (0x44), Length: 6
  Describe: Portal ""

[Offset 84] Type: 'E' (0x45), Length: 9
  Execute:
    Portal: ""
    Max rows: unlimited

[Offset 94] Type: 'S' (0x53), Length: 4
  Sync


Parsed 4 messages

It's worth noting that when I did this incorrectly many times (before I'd discovered I had to pad the single-digit bytes, for example), the tool did report lots of parse errors. In fact, with various data and offsets I gave it, it very rarely reported no errors (which is what you would expect if it worked).

In terms of what it's telling us:

• the client is binding three parameters to a named prepared query called __diesel_stmt_2
  • the first and third are 16 and 8 bytes of binary data, but the middle one is the string "nexus"
• the client executes the query with "max rows: unlimited", which means that the client wants the server to send all the rows. (This is separate from a limit built into the query.)
• the client sends Sync, which tells the server it's done sending messages for now

Now, the query Cockroach reports has three bound parameters: a certificate uuid (for pagination, 16 bytes), a certificate service (which is always "nexus" here), and (I think) a limit (which would be an i64, or 8 bytes).

Finally, notice these state fields:

    status = 0 (CONNECTION_OK)
    asyncStatus = 1 (PGASYNC_BUSY)
    xactStatus = 0 (PQTRANS_IDLE)
    queryclass = 1 (PGQUERY_EXTENDED)

Altogether, this is consistent with a client that has sent an ordinary query and is waiting for a response.

Now, what's in the inbuffer? I used the same approach and the same tool. Key fields:

    char *inBuffer = 0xc894010 "2"
    int inBufSize = 0x4000
    int inStart = 0x69
    int inCursor = 0x69
    int inEnd = 0x69

The tool reports the following. I've trimmed much of the data because it does contain TLS private keys:

Parsing backend messages from offset 0 in "inbuffer.bin"
File size: 3284 bytes

Starting parse at offset 0

[Offset 0] Type: 'D' (0x44), Length: 3283
  DataRow: 10 fields
    [0]: 16 bytes (binary)
    [1]: cassette-1767458590
    [2]: Automated certificate update
    [3]: 8 bytes (binary)
    [4]: 8 bytes (binary)
    [5]: NULL
    [6]: 16 bytes (binary)
    [7]: nexus
    [8]: -----BEGIN CERTIFICATE-----
...
-----END CERTIFICATE-----

-----BEGIN CERTIFICATE-----
...
-----END CERTIFICATE-----
    [9]: -----BEGIN PRIVATE KEY-----
...
-----END PRIVATE KEY-----



Parsed 1 messages

That looks like an ordinary, well-formed row from the table. So again: this is all consistent with a client that's just waiting for more data from the server. Having separately confirmed that there's no data queued on the socket in either direction, I think we've accounted for the most recent data sent and received on this socket and there's nothing on the client side that it's waiting for (either to send or to receive). Hence my conclusion that the problem might be on the server side.

[davepacheco]

Suspicious kernel state

I'll start with a direct line to the indicting kernel state.

At the Cockroach level, SHOW STATEMENTS reported this row:

  188a364004fcf09e0000000000000001 |       1 | 188a363a9bcdc8f90000000000000001 | root      | 2026-01-13 06:24:12.285734 | SELECT certificate.id, certificate.name, certificate.description, certificate.time_created, certificate.time_modified, certificate.time_deleted, certificate.silo_id, certificate.service, certificate.cert, certificate.key FROM certificate WHERE (((certificate.id > '7393254a-db08-4ba9-bed2-c1334fb9fa13') AND (certificate.time_deleted IS NULL)) AND (certificate.service = 'nexus')) ORDER BY certificate.id ASC LIMIT 200                                                                                                                                                                                                                                                                                                                    | [fd00:1122:3344:11d::22]:64207 |                  |    false    | executing

(These columns are query_id, node_id, session_id, user_name, start, query, client_address, application_name, distributed, phase.)

As I mentioned, that remote peer address ([fd00:1122:3344:11d::22]:64207) for the client that made this query matches the socket that Nexus was polling on and the query matches what we'd expect for the external_endpoints background task (will post more on that separately).

Still on the cockroach side, in mdb -k, we can find this fd:

> ::pgrep -x cockroach
S PID    PPID   PGID   SID    UID    FLAGS      ADDR             NAME
R 3869   1      3171   3171   0      0x4a014400 fffffcfaf167f008 cockroach

> ::pgrep -x cockroach | ::pfiles ! grep 64207
 149 SOCK fffffcfa3e5d0e00 socket: AF_INET6 0:3:fd00:1122:3344:11d:: 32221 remote: AF_INET6 fd00:1122:3344:11d::22 64207

We can also find the fd of Golang's event port:

> ::pgrep -x cockroach | ::pfiles ! grep -i port
   4 PORT fffffcfdc55a4800 [event port (port=fffffcfae05f1940)]

From this, we can find the association for fd 149 (the socket) and see what state it's in. (I worked this out by reading the implementation of port_associate.) We start with the port_fdcache that's hanging off the port_queue that's hanging off the port:

> fffffcfae05f1940::print -t port_t
port_t {
    ...
    port_queue_t port_queue = {
        ...
        struct port_fdcache *portq_pcp = 0xfffffcfafcb08aa0
	...
    }
}

This contains a hash table:

> fffffcfafcb08aa0::print port_fdcache_t
{
    pc_lock = {
        _opaque = [ 0 ]
    }
    pc_lclosecv = {
        _opaque = 0
    }
    pc_hash = 0xfffffcfafa582000
    pc_hashsize = 0x200
    pc_fdcount = 0x282
    _pc_pad = 0
    pc_flag = 0x8
}

Per port_cache_lookup_fp, we use PORT_FD_BUCKET to find the bucket, and that just uses the fd number mod the hashsize, which is 149 % 0x200, or just 149. This is an index into pc_hash. Computing that as pc_hash + 149 * sizeof (void *), we get 0xfffffcfafa5824a8. That does indeed look like the right thing:

> fffffcfafa5824a8/p
0xfffffcfafa5824a8:             0xfffffd9a206ba780
> fffffd9a206ba780::print portfd_t
{
    pfd_pd = {
        pd_fd = 0x95
        pd_events = 0x5
        pd_fp = 0xfffffef61e5d31c8
        pd_php = 0xfffffcfb5db86438
        pd_thread = 0
        pd_pcache = 0xfffffcfafcb08aa0
        pd_next = 0
        pd_hashnext = 0xfffffcfa7b05b600
        pd_count = 0
        pd_nsets = 0
        pd_ref = 0
        pd_portev = 0xfffffcfbdb7c9c30
        pd_gen = 0
        pd_epolldata = 0
    }
    pfd_next = 0
    pfd_prev = 0
    pfd_thread = 0xfffffcfc4620f100
}

That's an entry in the hash table and pd_fd is 0x95 == 149, so that is indeed ours. pd_events is 0x5, which is POLLIN | POLLOUT. So the last association was for these two events.

Let's look at the port_kevent_t:

> fffffcfbdb7c9c30::print port_kevent_t
{
    portkev_lock = {
        _opaque = [ 0 ]
    }
    portkev_source = 0x4
    portkev_events = 0
    portkev_flags = 0xa
    portkev_pid = 0xf1d
    portkev_object = 0x95
    portkev_user = 0xf5ffeeec18e13460
    portkev_callback = port_fd_callback
    portkev_arg = 0xfffffd9a206ba780
    portkev_port = 0xfffffcfae05f1940
    portkev_node = {
        list_next = 0
        list_prev = 0
    }
}

In particular, portkev_flags being 0xa means:

#define PORT_KEV_CACHED         0x02    /* port local cached, don't free */
...
#define PORT_KEV_VALID          0x08    /* event associated and enabled */

Critically, PORT_KEV_VALID means that this is a valid association that has not fired. When the event does get triggered, PORT_KEV_VALID is cleared right before calling port_send_event (see port_associate_fd for an example where this happens). When the event is queued on the port, PORT_KEV_DONEQ gets set (0x10). Neither of those is the case here, so this looks like an active association waiting to fire.

But what's it waiting on? Note that port_associate_fd itself has to check if the events are already ready and fire the event if so. It does this by calling VOP_POLL(), which eventually lands in so_poll(). It checks this:
https://github.com/oxidecomputer/illumos-gate/blob/1fa798f9b00a501e30150ed40ba2e5a24ab1c2bb/usr/src/uts/common/fs/sockfs/sockcommon_sops.c#L889-L906

where SO_SND_FLOWCTRLD is here:
https://github.com/oxidecomputer/illumos-gate/blob/1fa798f9b00a501e30150ed40ba2e5a24ab1c2bb/usr/src/uts/common/sys/socketvar.h#L351-L352

From @augustuswm's data above, we have:

fffffcfa3e5d0e00::print vnode_t v_data | ::print -t struct sonode
struct sonode {
    ...
    uint_t so_state = 0x81
    uint_t so_mode = 0xc28
    ...
    short so_pollev = 0x1
    ...
    unsigned int:1 so_snd_qfull :1 = 0
    ...
}

Note too that:

#define SM_CONNREQUIRED         0x008   /* connection required by protocol */

#define SS_ISCONNECTED          0x00000001 /* socket connected to a peer */

All of this means that so_poll would now set POLLOUT in *reventsp. To me, the combination of an active association for this event with conditions that reflect the event should currently be asserted points to a missed wakeup. Maybe I've missed something?

[davepacheco]

I have not dug deeply, but parts of this look superficially similar to https://www.illumos.org/issues/13463.