Skip to content

'integration-shadow' ci test: articlient-extra operation timed out at exit

The 'integration-shadow' test has started failing on main.

For example https://gitlab.torproject.org/tpo/core/arti/-/jobs/1130051:

** Shadow completed successfully
+ for HOST in articlient articlient-extra articlient-bridge articlient-bridge-obfs4
++ grep -c stream-success shadow.data/hosts/articlient/tgen.1003.stdout
+ successes=10
+ '[' 10 = 10 ']'
+ echo 'Simulation successful'
Simulation successful
+ for HOST in articlient articlient-extra articlient-bridge articlient-bridge-obfs4
++ grep -c stream-success shadow.data/hosts/articlient-extra/tgen.1003.stdout
+ successes=9
+ '[' 9 = 10 ']'
Failed. Only got 9 successful streams.
+ echo 'Failed. Only got 9 successful streams.'
+ exit 1

articlient-extra:

2000-01-01 00:28:49 946686529.676000 [critical] [tgen-stream.c:1787] [_tgenstream_runTransportEventLoop] transport connection or proxy handshake failed, stream cannot begin
2000-01-01 00:28:49 946686529.676000 [message] [tgen-stream.c:1721] [_tgenstream_log] [stream-error] transport [fd=7,local=localhost:127.0.0.1:20459,proxy=localhost:127.0.0.1:9000,remote=fileserver:11.0.0.14:80,state=ERROR,error=STATUS] stream [id=6,vertexid=stream,name=articlient-extra,peername=(null),sendsize=5000000,recvsize=5000000,sendstate=SEND_COMMAND,recvstate=RECV_NONE,error=PROXY] bytes [total-bytes-recv=0,total-bytes-send=0,payload-bytes-recv=0,payload-bytes-send=0,payload-progress-recv=0.00%,payload-progress-send=0.00%] times [created-ts=946686519676000,usecs-to-socket-create=0,usecs-to-socket-connect=0,usecs-to-proxy-init=0,usecs-to-proxy-choice=0,usecs-to-proxy-request=0,usecs-to-proxy-response=-1,usecs-to-command=-1,usecs-to-response=-1,usecs-to-first-byte-recv=-1,usecs-to-last-byte-recv=-1,usecs-to-checksum-recv=-1,usecs-to-first-byte-send=-1,usecs-to-last-byte-send=-1,usecs-to-checksum-send=-1,now-ts=946686529676000]

articlient-extra:

2000-01-01T00:28:49Z  WARN arti::socks: connection exited with error: error: operation timed out at exit

fileserver:

2000-01-01 00:28:56 946686536.609000 [critical] [tgen-stream.c:492] [_tgenstream_read] read(): transport [fd=10,local=NULL:0.0.0.0:80,proxy=NULL:0.0.0.0:0,remote=exit1:11.0.0.12:17968,state=SUCCESS_EOF,error=NONE] stream [id=22,vertexid=passive-stream,name=fileserver,peername=(null),sendsize=0,recvsize=0,sendstate=SEND_NONE,recvstate=RECV_AUTHENTICATE,error=NONE] closed unexpectedly
2000-01-01 00:28:56 946686536.609000 [message] [tgen-stream.c:1721] [_tgenstream_log] [stream-error] transport [fd=10,local=NULL:0.0.0.0:80,proxy=NULL:0.0.0.0:0,remote=exit1:11.0.0.12:17968,state=SUCCESS_EOF,error=NONE] stream [id=22,vertexid=passive-stream,name=fileserver,peername=(null),sendsize=0,recvsize=0,sendstate=SEND_NONE,recvstate=RECV_ERROR,error=READEOF] bytes [total-bytes-recv=0,total-bytes-send=0,payload-bytes-recv=0,payload-bytes-send=0,payload-progress-recv=?,payload-progress-send=?] times [created-ts=946686529510000,usecs-to-socket-create=0,usecs-to-socket-connect=0,usecs-to-proxy-init=-1,usecs-to-proxy-choice=-1,usecs-to-proxy-request=-1,usecs-to-proxy-response=-1,usecs-to-command=-1,usecs-to-response=-1,usecs-to-first-byte-recv=-1,usecs-to-last-byte-recv=-1,usecs-to-checksum-recv=-1,usecs-to-first-byte-send=-1,usecs-to-last-byte-send=-1,usecs-to-checksum-send=-1,now-ts=946686536609000]

exit1:

Jan 01 00:28:49.459 [info] connection_edge_finished_connecting(): Exit connection (connecting) to 11.0.0.14:80 established.
Edited by opara