EAGAIN on read event (upcall handler)
Closed this issue · 3 comments
I can reproduce an occurrence where the upcall handler is being called and the SCTP_EVENT_READ event is present but usrsctp_recvv returns -1 and errno is set to EAGAIN.
If needed, I can provide a tracefile.
It's quite hard to consistently reproduce the behaviour. I have boiled it down to the smallest message sizes where the error still occurs. However, the error only occurs with a ~50% chance. Note that this is an application where two clients communicate with one another using the same process. I cannot reproduce this behaviour with the standalone clients.
I've provided trace files for both the case where usrsctp_recvv sets errno to EAGAIN and for the case where it works without further errors (same code). I've added a 5s sleep when EAGAIN occurs so you can see it in the tracefile.
trace-sctp-EAGAIN-client1.pcapng.gz
trace-sctp-EAGAIN-client2.pcapng.gz
trace-sctp-NOEAGAIN-client1.pcapng.gz
trace-sctp-NOEAGAIN-client2.pcapng.gz
This is the logging output for the EAGAIN case:
[000000000] data-channel-sctp-loopback-app: Init
[000000042] helper-handler: (A) ICE gatherer state: gathering
[000000042] helper-handler: (A) ICE gatherer local candidate, URL:
[000000042] helper-handler: (A) ICE gatherer local candidate, URL:
[000000042] helper-handler: (A) ICE gatherer last local candidate
[000000042] helper-handler: (A) ICE gatherer state: complete
[000000042] helper-handler: (A) ICE transport state: checking
[000000042] helper-handler: (A) DTLS transport state change: connecting
[000000049] helper-handler: (A) SCTP transport state change: connecting
[000000049] helper-handler: (B) ICE gatherer state: gathering
[000000049] helper-handler: (B) ICE gatherer local candidate, URL:
[000000049] helper-handler: (B) ICE gatherer local candidate, URL:
[000000049] helper-handler: (B) ICE gatherer last local candidate
[000000049] helper-handler: (B) ICE gatherer state: complete
[000000049] helper-handler: (B) ICE transport state: checking
[000000049] helper-handler: (B) DTLS transport state change: connecting
[000000053] helper-handler: (B) SCTP transport state change: connecting
[000000055] helper-handler: (B) ICE transport state: connected
[000000069] helper-handler: (A) ICE transport state: connected
[000000071] helper-handler: (A) DTLS transport state change: connected
[000000071] data-channel-sctp-loopback-app: (A) DTLS role: server
[000000071] helper-handler: (B) DTLS transport state change: connected
[000000071] data-channel-sctp-loopback-app: (B) DTLS role: client
[000000078] helper-handler: (B) Data channel open: cat-noises
[000000078] data-channel-sctp-loopback-app: (B) Sending 16384 bytes
[000000078] helper-handler: (B) Data channel open: bear-noises
[000000078] helper-handler: (B) SCTP transport state change: connected
[000000085] helper-handler: (A) Data channel open: cat-noises
[000000085] data-channel-sctp-loopback-app: (A) Sending 16384 bytes
[000000085] helper-handler: (A) SCTP transport state change: connected
[000000085] helper-handler: (A) New data channel instance: bear-noises
[000000115] helper-handler: (B) ICE transport state: completed
[000001079] data-channel-sctp-loopback-app: (B) Sending 262144 bytes
[000001080] data-channel-sctp-loopback-app: (B) Closing channel
[000001083] helper-handler: (A) Incoming message for data channel cat-noises: 16384 bytes
[000001098] helper-handler: (B) Incoming message for data channel cat-noises: 16384 bytes
[000001100] sctp-transport: @ruengeler: usrsctp raised a read event but returned EAGAIN
[000006106] main: long async blocking: 5006>100 ms (h=0x7f8f4bb3220b arg=0x5556f31a5450)
[000006107] conncheck: stun response: [host|UDP|192.168.122.1:45828 --> prflx|UDP|10.26.2.4:35289] Connection timed out
[000006107] helper-handler: (A) ICE transport state: completed
[000006107] conncheck: stun response: [host|UDP|10.26.2.4:35865 --> prflx|UDP|10.26.2.4:1024] Connection timed out
[000006142] sctp-transport: No message handler, message of 262144 bytes has been discarded
[000006339] helper-handler: (B) Data channel buffered amount low: cat-noises
[000006344] helper-handler: (A) Data channel buffered amount low: cat-noises[000011729] helper-handler: Exiting
[000011730] helper-handler: (A) Data channel closed: cat-noises
[000011734] helper-handler: (A) SCTP transport state change: closed
[000011734] helper-handler: (A) DTLS transport state change: closed
[000011734] helper-handler: (A) ICE gatherer state: closed
[000011736] helper-handler: (B) Data channel closed: cat-noises
[000011736] helper-handler: (B) Data channel closed: bear-noises
[000011739] helper-handler: (B) SCTP transport state change: closed
[000011739] helper-handler: (B) DTLS transport state change: closed
[000011739] helper-handler: (B) ICE gatherer state: closed
[000011740] sctp-transport: Closed usrsctp
Let me know if you need the code.
After building the project from scratch, I cannot reproduce the error anymore. I will reopen this issue in case it happens again.