Note: This is test shard 8 of 8.
[==========] Running 33 tests from 3 test suites.
[----------] Global test environment set-up.
[----------] 31 tests from Parameters/TestRpc
[ RUN      ] Parameters/TestRpc.TestMessengerCreateDestroy/UnixSocket_SSL
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 08:02:40.978403 14927 rpc-test.cc:236] started messenger TestCreateDestroy
[       OK ] Parameters/TestRpc.TestMessengerCreateDestroy/UnixSocket_SSL (24 ms)
[ RUN      ] Parameters/TestRpc.TestNegotiationDeadlock/TCP_IPv4_SSL
I20260812 08:02:40.988692 14955 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 0.0.0.0:42407 every 8 connection(s)
I20260812 08:02:40.988695 14958 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 0.0.0.0:42407 every 8 connection(s)
[       OK ] Parameters/TestRpc.TestNegotiationDeadlock/TCP_IPv4_SSL (28 ms)
[ RUN      ] Parameters/TestRpc.TestCall/TCP_IPv6_SSL
I20260812 08:02:41.014137 14986 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket [::]:35947 every 8 connection(s)
I20260812 08:02:41.014175 14988 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket [::]:35947 every 8 connection(s)
I20260812 08:02:41.014519 14927 rpc-test.cc:301] Connecting to [::]:35947
[       OK ] Parameters/TestRpc.TestCall/TCP_IPv6_SSL (42 ms)
[ RUN      ] Parameters/TestRpc.TestCallWithChainCertAndChainCA/UnixSocket_SSL
I20260812 08:02:41.061399 15026 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-bb90eec068f64bb4bdb72155bfbd2a0c.sock every 8 connection(s)
I20260812 08:02:41.061437 15027 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-bb90eec068f64bb4bdb72155bfbd2a0c.sock every 8 connection(s)
W20260812 08:02:41.070050 15022 connection.cc:207] Error closing socket: Network error: TlsSocket::Close: SSL_ERROR_ZERO_RETURN
[       OK ] Parameters/TestRpc.TestCallWithChainCertAndChainCA/UnixSocket_SSL (20 ms)
[ RUN      ] Parameters/TestRpc.TestCallWithPasswordProtectedKey/TCP_IPv4_SSL
I20260812 08:02:41.078589 15077 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 0.0.0.0:43655 every 8 connection(s)
I20260812 08:02:41.078632 15078 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 0.0.0.0:43655 every 8 connection(s)
[       OK ] Parameters/TestRpc.TestCallWithPasswordProtectedKey/TCP_IPv4_SSL (21 ms)
[ RUN      ] Parameters/TestRpc.TestCallWithBadPasswordProtectedKey/TCP_IPv6_SSL
[       OK ] Parameters/TestRpc.TestCallWithBadPasswordProtectedKey/TCP_IPv6_SSL (7 ms)
[ RUN      ] Parameters/TestRpc.TestCallToBadServer/UnixSocket_SSL
I20260812 08:02:41.110854 14927 rpc-test.cc:461] Status: Network error: Client connection negotiation failed: client connection to 0.0.0.0:0: connect: Connection refused (error 111)
I20260812 08:02:41.111399 14927 rpc-test.cc:461] Status: Network error: Client connection negotiation failed: client connection to 0.0.0.0:0: connect: Connection refused (error 111)
I20260812 08:02:41.111887 14927 rpc-test.cc:461] Status: Network error: Client connection negotiation failed: client connection to 0.0.0.0:0: connect: Connection refused (error 111)
I20260812 08:02:41.112314 14927 rpc-test.cc:461] Status: Network error: Client connection negotiation failed: client connection to 0.0.0.0:0: connect: Connection refused (error 111)
I20260812 08:02:41.112859 14927 rpc-test.cc:461] Status: Network error: Client connection negotiation failed: client connection to 0.0.0.0:0: connect: Connection refused (error 111)
[       OK ] Parameters/TestRpc.TestCallToBadServer/UnixSocket_SSL (12 ms)
[ RUN      ] Parameters/TestRpc.TestWrongService/TCP_IPv4_SSL
I20260812 08:02:41.125679 15157 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 0.0.0.0:35739 every 8 connection(s)
I20260812 08:02:41.125717 15158 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 0.0.0.0:35739 every 8 connection(s)
I20260812 08:02:41.145701 15154 messenger.cc:364] service WrongServiceName not registered on TestServer
[       OK ] Parameters/TestRpc.TestWrongService/TCP_IPv4_SSL (34 ms)
[ RUN      ] Parameters/TestRpc.TestHighFDs/TCP_IPv6_SSL
I20260812 08:02:41.294804 15203 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket [::]:34339 every 8 connection(s)
I20260812 08:02:41.294858 15204 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket [::]:34339 every 8 connection(s)
[       OK ] Parameters/TestRpc.TestHighFDs/TCP_IPv6_SSL (171 ms)
[ RUN      ] Parameters/TestRpc.TestConnectionKeepalive/UnixSocket_SSL
I20260812 08:02:41.337687 15234 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-c43a4db1381340fa8541a24295e127dc.sock every 8 connection(s)
I20260812 08:02:41.337723 15236 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-c43a4db1381340fa8541a24295e127dc.sock every 8 connection(s)
I20260812 08:02:41.338017 14927 rpc-test.cc:555] Connecting to unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-c43a4db1381340fa8541a24295e127dc.sock
W20260812 08:02:41.821233 15255 connection.cc:207] Error closing socket: Network error: TlsSocket::Close: SSL_ERROR_ZERO_RETURN
[       OK ] Parameters/TestRpc.TestConnectionKeepalive/UnixSocket_SSL (1039 ms)
[ RUN      ] Parameters/TestRpc.TestClientConnectionMetrics/TCP_IPv4_SSL
I20260812 08:02:42.370060 15284 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 0.0.0.0:40055 every 8 connection(s)
I20260812 08:02:42.370191 15287 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 0.0.0.0:40055 every 8 connection(s)
I20260812 08:02:42.370483 14927 rpc-test.cc:636] Connecting to 0.0.0.0:40055
[       OK ] Parameters/TestRpc.TestClientConnectionMetrics/TCP_IPv4_SSL (14404 ms)
[ RUN      ] Parameters/TestRpc.TestReopenOutboundConnections/TCP_IPv6_SSL
I20260812 08:02:56.772277 15323 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket [::]:46627 every 8 connection(s)
I20260812 08:02:56.772432 15325 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket [::]:46627 every 8 connection(s)
I20260812 08:02:56.772761 14927 rpc-test.cc:724] Connecting to [::]:46627
[       OK ] Parameters/TestRpc.TestReopenOutboundConnections/TCP_IPv6_SSL (126 ms)
[ RUN      ] Parameters/TestRpc.TestCredentialsPolicy/UnixSocket_SSL
I20260812 08:02:56.926093 15363 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-bfda393b053f43f8b3531879198c06d0.sock every 8 connection(s)
I20260812 08:02:56.926146 15361 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-bfda393b053f43f8b3531879198c06d0.sock every 8 connection(s)
I20260812 08:02:56.926550 14927 rpc-test.cc:766] Connecting to unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-bfda393b053f43f8b3531879198c06d0.sock
W20260812 08:02:56.946854 15360 connection.cc:207] Error closing socket: Network error: TlsSocket::Close: SSL_ERROR_ZERO_RETURN
W20260812 08:02:56.951383 15360 connection.cc:207] Error closing socket: Network error: TlsSocket::Close: SSL_ERROR_ZERO_RETURN
[       OK ] Parameters/TestRpc.TestCredentialsPolicy/UnixSocket_SSL (61 ms)
[ RUN      ] Parameters/TestRpc.TestCallLongerThanKeepalive/TCP_IPv4_SSL
I20260812 08:02:56.960894 15398 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 0.0.0.0:42105 every 8 connection(s)
I20260812 08:02:56.960950 15399 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 0.0.0.0:42105 every 8 connection(s)
I20260812 08:02:56.976290 15403 rpc-test-base.h:261] got call: sleep_micros: 3000000 deferred: true
I20260812 08:02:59.977304 15403 rpcz_store.cc:275] Call kudu.rpc.GenericCalculatorService.Sleep from 127.0.0.1:60172 (request call id 0) took 3001 ms. Trace:
I20260812 08:02:59.977459 15403 rpcz_store.cc:276] 0812 08:02:56.976157 (+     0us) service_pool.cc:167] Inserting onto call queue
0812 08:02:56.976268 (+   111us) service_pool.cc:224] Handling call
0812 08:02:59.977279 (+3001011us) inbound_call.cc:177] Queueing success response
Metrics: {}
[       OK ] Parameters/TestRpc.TestCallLongerThanKeepalive/TCP_IPv4_SSL (3027 ms)
[ RUN      ] Parameters/TestRpc.TestTCPKeepalive/TCP_IPv6_SSL
I20260812 08:03:00.000561 15444 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket [::]:43483 every 8 connection(s)
I20260812 08:03:00.000654 15446 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket [::]:43483 every 8 connection(s)
I20260812 08:03:00.016935 15452 rpc-test-base.h:261] got call: sleep_micros: 8000000 deferred: true
I20260812 08:03:08.017481 15452 rpcz_store.cc:275] Call kudu.rpc.GenericCalculatorService.Sleep from [::1]:57454 (request call id 0) took 8000 ms. Trace:
I20260812 08:03:08.017594 15452 rpcz_store.cc:276] 0812 08:03:00.016855 (+     0us) service_pool.cc:167] Inserting onto call queue
0812 08:03:00.016917 (+    62us) service_pool.cc:224] Handling call
0812 08:03:08.017459 (+8000542us) inbound_call.cc:177] Queueing success response
Metrics: {}
[       OK ] Parameters/TestRpc.TestTCPKeepalive/TCP_IPv6_SSL (8040 ms)
[ RUN      ] Parameters/TestRpc.TestRpcSidecarWithSizeLimits/UnixSocket_SSL
I20260812 08:03:08.029480 15477 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-fe2b0ecf55304c5485dc79e280773097.sock every 8 connection(s)
I20260812 08:03:08.029604 15479 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-fe2b0ecf55304c5485dc79e280773097.sock every 8 connection(s)
W20260812 08:03:08.234320 15482 serialization.cc:72] Serialized kudu.rpc_test.SendTwoStringsResponsePB (62914568 bytes) is larger than the maximum configured RPC message size (52428800 bytes). Sending anyway, but peer may reject the data.
W20260812 08:03:08.234841 15497 connection.cc:573] client connection to unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-fe2b0ecf55304c5485dc79e280773097.sock recv error: Network error: RPC frame had a length of 62914584, but we only support messages up to 20971520 bytes long.
W20260812 08:03:08.234938 15497 connection.cc:169] shutting down client connection to unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-fe2b0ecf55304c5485dc79e280773097.sock with pending inbound data: 4/62914584 bytes received; last active 0 ns ago: status Network error: RPC frame had a length of 62914584, but we only support messages up to 20971520 bytes long.
W20260812 08:03:08.235266 15474 connection.cc:466] server connection from unix:<unnamed> torn down before Call kudu.rpc.GenericCalculatorService.SendTwoStrings from unix:<unnamed> (request call id 0) could send its response
W20260812 08:03:08.235474 15474 connection.cc:207] Error closing socket: Network error: TlsSocket::Close: SSL_ERROR_ZERO_RETURN
I20260812 08:03:08.258949 15508 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-fe2b0ecf55304c5485dc79e280773097.sock every 8 connection(s)
I20260812 08:03:08.259001 15506 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-fe2b0ecf55304c5485dc79e280773097.sock every 8 connection(s)
W20260812 08:03:08.388443 15511 serialization.cc:72] Serialized kudu.rpc_test.SendTwoStringsResponsePB (62914568 bytes) is larger than the maximum configured RPC message size (52428800 bytes). Sending anyway, but peer may reject the data.
W20260812 08:03:08.642160 15503 connection.cc:207] Error closing socket: Network error: TlsSocket::Close: SSL_ERROR_ZERO_RETURN
[       OK ] Parameters/TestRpc.TestRpcSidecarWithSizeLimits/UnixSocket_SSL (622 ms)
[ RUN      ] Parameters/TestRpc.TestMaxSmallSidecars/TCP_IPv4_SSL
I20260812 08:03:08.662914 15550 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 0.0.0.0:45619 every 8 connection(s)
I20260812 08:03:08.662926 15551 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 0.0.0.0:45619 every 8 connection(s)
[       OK ] Parameters/TestRpc.TestMaxSmallSidecars/TCP_IPv4_SSL (50 ms)
[ RUN      ] Parameters/TestRpc.TestRpcSidecarLimits/TCP_IPv6_SSL
I20260812 08:03:10.702082 15584 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket [::]:38053 every 8 connection(s)
I20260812 08:03:10.702142 15585 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket [::]:38053 every 8 connection(s)
W20260812 08:03:10.708415 14927 serialization.cc:72] Serialized kudu.rpc_test.PushStringsRequestPB (2147483654 bytes) is larger than the maximum configured RPC message size (52428800 bytes). Sending anyway, but peer may reject the data.
W20260812 08:03:10.712245 15583 connection.cc:573] server connection from [::1]:57118 recv error: Network error: RPC frame had a length of 2147483714, but we only support messages up to 52428800 bytes long.
W20260812 08:03:10.712333 15583 connection.cc:169] shutting down server connection from [::1]:57118 with pending inbound data: 4/2147483714 bytes received; last active 0 ns ago: status Network error: RPC frame had a length of 2147483714, but we only support messages up to 52428800 bytes long.
W20260812 08:03:10.712627 15607 connection.cc:207] Error closing socket: Network error: TlsSocket::Close: SSL_ERROR_ZERO_RETURN
I20260812 08:03:10.735916 15633 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket [::]:34685 every 8 connection(s)
I20260812 08:03:10.735955 15634 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket [::]:34685 every 8 connection(s)
W20260812 08:03:19.447594 15625 connection.cc:615] server connection from [::1]:33238: received bad data: 'Corruption: Invalid packet: message had a length of 2147483710, but we only support messages up to 2147483647 bytes
'
[       OK ] Parameters/TestRpc.TestRpcSidecarLimits/TCP_IPv6_SSL (10756 ms)
[ RUN      ] Parameters/TestRpc.TestCallTimeout/UnixSocket_SSL
I20260812 08:03:19.457394 15668 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-70fccecffbf142359bddbf70de42ad8a.sock every 8 connection(s)
I20260812 08:03:19.457511 15669 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-70fccecffbf142359bddbf70de42ad8a.sock every 8 connection(s)
I20260812 08:03:19.476804 14927 rpc-test-base.h:702] status: Timed out: connection negotiation to unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-70fccecffbf142359bddbf70de42ad8a.sock for RPC Sleep timed out after 0.000s (ON_OUTBOUND_QUEUE), seconds elapsed: 0.000636641
I20260812 08:03:19.489185 15674 rpc-test-base.h:261] got call: sleep_micros: 700000
I20260812 08:03:19.677747 14927 rpc-test-base.h:702] status: Timed out: Sleep RPC to unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-70fccecffbf142359bddbf70de42ad8a.sock timed out after 0.200s (SENT), seconds elapsed: 0.200801
I20260812 08:03:19.678452 15671 rpc-test-base.h:261] got call: sleep_micros: 2000000
W20260812 08:03:20.189517 15674 rpcz_store.cc:267] Call kudu.rpc.GenericCalculatorService.Sleep from unix:<unnamed> (request call id 1) took 700 ms (client timeout 200 ms). Trace:
W20260812 08:03:20.189646 15674 rpcz_store.cc:269] 0812 08:03:19.489097 (+     0us) service_pool.cc:167] Inserting onto call queue
0812 08:03:19.489161 (+    64us) service_pool.cc:224] Handling call
0812 08:03:20.189492 (+700331us) inbound_call.cc:177] Queueing success response
Metrics: {}
I20260812 08:03:21.179549 14927 rpc-test-base.h:702] status: Timed out: Sleep RPC to unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-70fccecffbf142359bddbf70de42ad8a.sock timed out after 1.500s (SENT), seconds elapsed: 1.50163
W20260812 08:03:21.678764 15671 rpcz_store.cc:267] Call kudu.rpc.GenericCalculatorService.Sleep from unix:<unnamed> (request call id 2) took 2000 ms (client timeout 1500 ms). Trace:
W20260812 08:03:21.678886 15671 rpcz_store.cc:269] 0812 08:03:19.678362 (+     0us) service_pool.cc:167] Inserting onto call queue
0812 08:03:19.678436 (+    74us) service_pool.cc:224] Handling call
0812 08:03:21.678739 (+2000303us) inbound_call.cc:177] Queueing success response
Metrics: {}
W20260812 08:03:21.679107 15664 connection.cc:466] server connection from unix:<unnamed> torn down before Call kudu.rpc.GenericCalculatorService.Sleep from unix:<unnamed> (request call id 2) could send its response
[       OK ] Parameters/TestRpc.TestCallTimeout/UnixSocket_SSL (2229 ms)
[ RUN      ] Parameters/TestRpc.TestServerShutsDown/TCP_IPv4_SSL
I20260812 08:03:21.681422 14927 rpc-test.cc:1246] Connecting to 0.0.0.0:41735
W20260812 08:03:21.683727 15690 negotiation.cc:336] Failed RPC negotiation. Trace:
0812 08:03:21.683173 (+     0us) reactor.cc:730] Submitting negotiation task for client connection to 0.0.0.0:41735 (local address 127.0.0.1:53476)
0812 08:03:21.683273 (+   100us) negotiation.cc:107] Waiting for socket to connect
0812 08:03:21.683286 (+    13us) client_negotiation.cc:175] Beginning negotiation
0812 08:03:21.683386 (+   100us) client_negotiation.cc:262] Sending NEGOTIATE NegotiatePB request
0812 08:03:21.683457 (+    71us) negotiation.cc:326] Negotiation complete: Network error: Client connection negotiation failed: client connection to 0.0.0.0:41735: BlockingWrite error: write error: Broken pipe (error 32)
Metrics: {"client-negotiator.queue_time_us":27}
[       OK ] Parameters/TestRpc.TestServerShutsDown/TCP_IPv4_SSL (3 ms)
[ RUN      ] Parameters/TestRpc.TestRpcHandlerLatencyMetric/TCP_IPv6_SSL
I20260812 08:03:21.691462 15720 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket [::]:45181 every 8 connection(s)
I20260812 08:03:21.691591 15724 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket [::]:45181 every 8 connection(s)
I20260812 08:03:21.725558 14927 rpc-test.cc:1357] Sleep() min lat: 20526
I20260812 08:03:21.725647 14927 rpc-test.cc:1358] Sleep() mean lat: 20526
I20260812 08:03:21.725675 14927 rpc-test.cc:1359] Sleep() max lat: 20526
I20260812 08:03:21.725687 14927 rpc-test.cc:1360] Sleep() #calls: 1
[       OK ] Parameters/TestRpc.TestRpcHandlerLatencyMetric/TCP_IPv6_SSL (43 ms)
[ RUN      ] Parameters/TestRpc.TimedOutOnResponseMetric/UnixSocket_SSL
I20260812 08:03:21.750551 15765 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-3876bbfb91774317a6958a978a84db44.sock every 8 connection(s)
I20260812 08:03:21.750591 15767 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-3876bbfb91774317a6958a978a84db44.sock every 8 connection(s)
W20260812 08:03:21.973850 15772 rpcz_store.cc:267] Call kudu.rpc_test.CalculatorService.Sleep from unix:<unnamed> (request call id 3) took 50 ms (client timeout 25 ms). Trace:
W20260812 08:03:21.973961 15772 rpcz_store.cc:269] 0812 08:03:21.923564 (+     0us) service_pool.cc:167] Inserting onto call queue
0812 08:03:21.923619 (+    55us) service_pool.cc:224] Handling call
0812 08:03:21.973809 (+ 50190us) inbound_call.cc:177] Queueing success response
Related trace 'test_child':
Metrics: {"test_sleep_us":50000,"child_traces":[["test_child",{"related_trace_metric":1}]]}
W20260812 08:03:22.031297 15772 rpcz_store.cc:267] Call kudu.rpc_test.CalculatorService.Sleep from unix:<unnamed> (request call id 4) took 50 ms (client timeout 50 ms). Trace:
W20260812 08:03:22.031389 15772 rpcz_store.cc:269] 0812 08:03:21.981033 (+     0us) service_pool.cc:167] Inserting onto call queue
0812 08:03:21.981097 (+    64us) service_pool.cc:224] Handling call
0812 08:03:22.031275 (+ 50178us) inbound_call.cc:177] Queueing success response
Related trace 'test_child':
Metrics: {"test_sleep_us":50000,"child_traces":[["test_child",{"related_trace_metric":1}]]}
W20260812 08:03:22.033166 15761 connection.cc:207] Error closing socket: Network error: TlsSocket::Close: SSL_ERROR_ZERO_RETURN
[       OK ] Parameters/TestRpc.TimedOutOnResponseMetric/UnixSocket_SSL (306 ms)
[ RUN      ] Parameters/TestRpc.AcceptorDispatchingTimesMetric/TCP_IPv4_SSL
I20260812 08:03:22.037166 15822 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 0.0.0.0:44991 every 8 connection(s)
I20260812 08:03:22.037180 15823 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 0.0.0.0:44991 every 8 connection(s)
W20260812 08:03:22.037976 15814 negotiation.cc:336] Failed RPC negotiation. Trace:
0812 08:03:22.037695 (+     0us) reactor.cc:730] Submitting negotiation task for server connection from 127.0.0.1:44970 (local address 127.0.0.1:44991)
0812 08:03:22.037825 (+   130us) server_negotiation.cc:207] Beginning negotiation
0812 08:03:22.037829 (+     4us) server_negotiation.cc:400] Waiting for connection header
0812 08:03:22.037918 (+    89us) negotiation.cc:326] Negotiation complete: Network error: Server connection negotiation failed: server connection from 127.0.0.1:44970: BlockingRecv error: recv got EOF from 127.0.0.1:44970 (error 108)
Metrics: {"server-negotiator.queue_time_us":52}
[       OK ] Parameters/TestRpc.AcceptorDispatchingTimesMetric/TCP_IPv4_SSL (5 ms)
[ RUN      ] Parameters/TestRpc.RpcPendingConnectionsMetric/TCP_IPv6_SSL
I20260812 08:03:22.043002 15852 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 0.0.0.0:44257 every 8 connection(s)
I20260812 08:03:22.043118 15854 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 0.0.0.0:44257 every 8 connection(s)
W20260812 08:03:22.044138 15843 negotiation.cc:336] Failed RPC negotiation. Trace:
0812 08:03:22.043777 (+     0us) reactor.cc:730] Submitting negotiation task for server connection from 127.0.0.1:44712 (local address 127.0.0.1:44257)
0812 08:03:22.043932 (+   155us) server_negotiation.cc:207] Beginning negotiation
0812 08:03:22.043937 (+     5us) server_negotiation.cc:400] Waiting for connection header
0812 08:03:22.044043 (+   106us) negotiation.cc:326] Negotiation complete: Network error: Server connection negotiation failed: server connection from 127.0.0.1:44712: BlockingRecv error: recv got EOF from 127.0.0.1:44712 (error 108)
Metrics: {"server-negotiator.queue_time_us":43}
[       OK ] Parameters/TestRpc.RpcPendingConnectionsMetric/TCP_IPv6_SSL (4 ms)
[ RUN      ] Parameters/TestRpc.TestRpcCallbackDestroysMessenger/UnixSocket_SSL
[       OK ] Parameters/TestRpc.TestRpcCallbackDestroysMessenger/UnixSocket_SSL (25 ms)
[ RUN      ] Parameters/TestRpc.TestApplicationFeatureFlag/TCP_IPv4_SSL
I20260812 08:03:22.081312 15889 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 0.0.0.0:33605 every 8 connection(s)
I20260812 08:03:22.081351 15890 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 0.0.0.0:33605 every 8 connection(s)
W20260812 08:03:22.097630 15886 messenger.cc:376] Unable to handle RPC call: Not implemented: call requires unsupported application feature flags: 99
[       OK ] Parameters/TestRpc.TestApplicationFeatureFlag/TCP_IPv4_SSL (29 ms)
[ RUN      ] Parameters/TestRpc.TestApplicationFeatureFlagUnsupportedServer/TCP_IPv6_SSL
I20260812 08:03:22.108413 15932 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket [::]:41753 every 8 connection(s)
I20260812 08:03:22.108378 15931 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket [::]:41753 every 8 connection(s)
[       OK ] Parameters/TestRpc.TestApplicationFeatureFlagUnsupportedServer/TCP_IPv6_SSL (56 ms)
[ RUN      ] Parameters/TestRpc.TestCancellation/UnixSocket_SSL
I20260812 08:03:22.162876 15977 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-d15c7beebc164629b67b3fec11dd3dd5.sock every 8 connection(s)
I20260812 08:03:22.162935 15980 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-d15c7beebc164629b67b3fec11dd3dd5.sock every 8 connection(s)
I20260812 08:03:22.163259 14927 rpc-test.cc:1779] Connecting to unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-d15c7beebc164629b67b3fec11dd3dd5.sock
I20260812 08:03:22.181407 14927 rpc-test-base.h:702] status: Aborted: Sleep RPC to unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-d15c7beebc164629b67b3fec11dd3dd5.sock is cancelled in state READY, seconds elapsed: 8.7673e-05
I20260812 08:03:22.184026 14927 rpc-test-base.h:702] status: Aborted: Sleep RPC to unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-d15c7beebc164629b67b3fec11dd3dd5.sock is cancelled in state ON_OUTBOUND_QUEUE, seconds elapsed: 0.000149663
I20260812 08:03:22.192829 14927 rpc-test-base.h:702] status: Aborted: Sleep RPC to unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-d15c7beebc164629b67b3fec11dd3dd5.sock is cancelled in state SENT, seconds elapsed: 0.000278037
I20260812 08:03:22.192934 15984 rpc-test-base.h:261] got call: sleep_micros: 510000
I20260812 08:03:22.201005 14927 rpc-test-base.h:702] status: Aborted: Sleep RPC to unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-d15c7beebc164629b67b3fec11dd3dd5.sock is cancelled in state SENT, seconds elapsed: 0.000309473
I20260812 08:03:22.201095 15981 rpc-test-base.h:261] got call: sleep_micros: 510000
I20260812 08:03:22.201488 15988 rpc-test-base.h:261] got call: sleep_micros: 1500000
W20260812 08:03:22.703293 15984 rpcz_store.cc:267] Call kudu.rpc.GenericCalculatorService.Sleep from unix:<unnamed> (request call id 7) took 510 ms (client timeout 10 ms). Trace:
W20260812 08:03:22.703419 15984 rpcz_store.cc:269] 0812 08:03:22.192846 (+     0us) service_pool.cc:167] Inserting onto call queue
0812 08:03:22.192916 (+    70us) service_pool.cc:224] Handling call
0812 08:03:22.703268 (+510352us) inbound_call.cc:177] Queueing success response
Metrics: {}
W20260812 08:03:22.711362 15981 rpcz_store.cc:267] Call kudu.rpc.GenericCalculatorService.Sleep from unix:<unnamed> (request call id 11) took 510 ms (client timeout 10 ms). Trace:
W20260812 08:03:22.711504 15981 rpcz_store.cc:269] 0812 08:03:22.201035 (+     0us) service_pool.cc:167] Inserting onto call queue
0812 08:03:22.201087 (+    52us) service_pool.cc:224] Handling call
0812 08:03:22.711343 (+510256us) inbound_call.cc:177] Queueing success response
Metrics: {}
I20260812 08:03:23.202234 14927 rpc-test-base.h:702] status: Timed out: Sleep RPC to unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-d15c7beebc164629b67b3fec11dd3dd5.sock timed out after 1.000s (SENT), seconds elapsed: 1.00108
I20260812 08:03:23.202960 15981 rpc-test-base.h:261] got call: sleep_micros: 1500000
W20260812 08:03:23.701781 15988 rpcz_store.cc:267] Call kudu.rpc.GenericCalculatorService.Sleep from unix:<unnamed> (request call id 12) took 1500 ms (client timeout 1000 ms). Trace:
W20260812 08:03:23.701941 15988 rpcz_store.cc:269] 0812 08:03:22.201418 (+     0us) service_pool.cc:167] Inserting onto call queue
0812 08:03:22.201458 (+    40us) service_pool.cc:224] Handling call
0812 08:03:23.701757 (+1500299us) inbound_call.cc:177] Queueing success response
Metrics: {}
I20260812 08:03:24.203667 14927 rpc-test-base.h:702] status: Timed out: Sleep RPC to unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-d15c7beebc164629b67b3fec11dd3dd5.sock timed out after 1.000s (SENT), seconds elapsed: 1.00126
W20260812 08:03:24.204360 15974 messenger.cc:376] Unable to handle RPC call: Not implemented: call requires unsupported application feature flags: 99, 1
W20260812 08:03:24.205044 15974 messenger.cc:376] Unable to handle RPC call: Not implemented: call requires unsupported application feature flags: 99, 1
W20260812 08:03:24.236085 15974 connection.cc:207] Error closing socket: Network error: TlsSocket::Close: SSL_ERROR_ZERO_RETURN
W20260812 08:03:24.703271 15981 rpcz_store.cc:267] Call kudu.rpc.GenericCalculatorService.Sleep from unix:<unnamed> (request call id 13) took 1500 ms (client timeout 1000 ms). Trace:
W20260812 08:03:24.703387 15981 rpcz_store.cc:269] 0812 08:03:23.202861 (+     0us) service_pool.cc:167] Inserting onto call queue
0812 08:03:23.202947 (+    86us) service_pool.cc:224] Handling call
0812 08:03:24.703247 (+1500300us) inbound_call.cc:177] Queueing success response
Metrics: {}
W20260812 08:03:24.703678 15974 connection.cc:466] server connection from unix:<unnamed> torn down before Call kudu.rpc.GenericCalculatorService.Sleep from unix:<unnamed> (request call id 13) could send its response
[       OK ] Parameters/TestRpc.TestCancellation/UnixSocket_SSL (2549 ms)
[ RUN      ] Parameters/TestRpc.TestCancellationMultiThreads/TCP_IPv4_SSL
I20260812 08:03:24.718529 16017 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 0.0.0.0:34803 every 8 connection(s)
I20260812 08:03:24.718571 16018 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 0.0.0.0:34803 every 8 connection(s)
I20260812 08:03:24.718894 14927 rpc-test.cc:1939] Connecting to 0.0.0.0:34803
[       OK ] Parameters/TestRpc.TestCancellationMultiThreads/TCP_IPv4_SSL (16931 ms)
[ RUN      ] Parameters/TestRpc.TestPerformanceBySocketType/TCP_IPv6_SSL
I20260812 08:03:41.655467 16112 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket [::]:33065 every 8 connection(s)
I20260812 08:03:41.655519 16114 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket [::]:33065 every 8 connection(s)
I20260812 08:03:41.655887 14927 rpc-test.cc:1977] Connecting to [::]:33065
I20260812 08:03:46.577829 14927 rpc-test.cc:1990] Sending 1024MB via ssl-enabled tcp socket: real 4.914s	user 1.843s	sys 1.085s
I20260812 08:03:51.780195 14927 rpc-test.cc:1990] Sending 1024MB via ssl-enabled tcp socket: real 5.202s	user 1.857s	sys 1.030s
I20260812 08:03:56.672161 14927 rpc-test.cc:1990] Sending 1024MB via ssl-enabled tcp socket: real 4.892s	user 1.870s	sys 1.067s
I20260812 08:04:01.890354 14927 rpc-test.cc:1990] Sending 1024MB via ssl-enabled tcp socket: real 5.218s	user 1.912s	sys 1.063s
I20260812 08:04:07.084408 14927 rpc-test.cc:1990] Sending 1024MB via ssl-enabled tcp socket: real 5.194s	user 1.938s	sys 1.002s
[       OK ] Parameters/TestRpc.TestPerformanceBySocketType/TCP_IPv6_SSL (25449 ms)
[ RUN      ] Parameters/TestRpc.TestCallId/UnixSocket_SSL
I20260812 08:04:07.106326 16154 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-c0682cdc75d64d6a98f0f0bf4425efed.sock every 8 connection(s)
I20260812 08:04:07.106365 16155 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket unix:/tmp/dist-test-taskfKlZ_K/test-tmp/rpc-test-c0682cdc75d64d6a98f0f0bf4425efed.sock every 8 connection(s)
W20260812 08:04:07.127025 16149 connection.cc:207] Error closing socket: Network error: TlsSocket::Close: SSL_ERROR_ZERO_RETURN
[       OK ] Parameters/TestRpc.TestCallId/UnixSocket_SSL (41 ms)
[----------] 31 tests from Parameters/TestRpc (86172 ms total)

[----------] 1 test from Parameters/TestRpcSocketTxRxQueue
[ RUN      ] Parameters/TestRpcSocketTxRxQueue.AcceptorRxQueueSizeMetric/TCP_IPv4_NoSSL
I20260812 08:04:07.130641 16192 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 0.0.0.0:38169 every 1 connection(s)
I20260812 08:04:07.130662 16194 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 0.0.0.0:38169 every 1 connection(s)
W20260812 08:04:07.131500 16188 negotiation.cc:336] Failed RPC negotiation. Trace:
0812 08:04:07.131224 (+     0us) reactor.cc:730] Submitting negotiation task for server connection from 127.0.0.1:46022 (local address 127.0.0.1:38169)
0812 08:04:07.131347 (+   123us) server_negotiation.cc:207] Beginning negotiation
0812 08:04:07.131350 (+     3us) server_negotiation.cc:400] Waiting for connection header
0812 08:04:07.131439 (+    89us) negotiation.cc:326] Negotiation complete: Network error: Server connection negotiation failed: server connection from 127.0.0.1:46022: BlockingRecv error: recv got EOF from 127.0.0.1:46022 (error 108)
Metrics: {"server-negotiator.queue_time_us":44}
[       OK ] Parameters/TestRpcSocketTxRxQueue.AcceptorRxQueueSizeMetric/TCP_IPv4_NoSSL (7 ms)
[----------] 1 test from Parameters/TestRpcSocketTxRxQueue (7 ms total)

[----------] 1 test from Parameters/TestRpcWithIpModes
[ RUN      ] Parameters/TestRpcWithIpModes.TestRpcWithDifferentIpConfigModes/2
I20260812 08:04:07.139549 16205 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket [::]:36427 every 8 connection(s)
I20260812 08:04:07.139621 16206 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket [::]:36427 every 8 connection(s)
W20260812 08:04:07.140902 16213 negotiation.cc:336] Failed RPC negotiation. Trace:
0812 08:04:07.140267 (+     0us) reactor.cc:730] Submitting negotiation task for server connection from [::ffff:127.0.0.1]:41584 (local address [::ffff:127.0.0.1]:36427)
0812 08:04:07.140563 (+   296us) server_negotiation.cc:207] Beginning negotiation
0812 08:04:07.140567 (+     4us) server_negotiation.cc:400] Waiting for connection header
0812 08:04:07.140794 (+   227us) negotiation.cc:326] Negotiation complete: Network error: Server connection negotiation failed: server connection from [::ffff:127.0.0.1]:41584: BlockingRecv error: recv got EOF from [::ffff:127.0.0.1]:41584 (error 108)
Metrics: {"server-negotiator.queue_time_us":172,"thread_start_us":83,"threads_started":1}
W20260812 08:04:07.140911 16217 negotiation.cc:336] Failed RPC negotiation. Trace:
0812 08:04:07.140341 (+     0us) reactor.cc:730] Submitting negotiation task for server connection from [::1]:58816 (local address [::1]:36427)
0812 08:04:07.140678 (+   337us) server_negotiation.cc:207] Beginning negotiation
0812 08:04:07.140682 (+     4us) server_negotiation.cc:400] Waiting for connection header
0812 08:04:07.140799 (+   117us) negotiation.cc:326] Negotiation complete: Network error: Server connection negotiation failed: server connection from [::1]:58816: BlockingRecv error: recv got EOF from [::1]:58816 (error 108)
Metrics: {"server-negotiator.queue_time_us":268,"thread_start_us":100,"threads_started":1}
[       OK ] Parameters/TestRpcWithIpModes.TestRpcWithDifferentIpConfigModes/2 (5 ms)
[----------] 1 test from Parameters/TestRpcWithIpModes (5 ms total)

[----------] Global test environment tear-down
[==========] 33 tests from 3 test suites ran. (86185 ms total)
[  PASSED  ] 33 tests.
