PR-SCTP issue if start fragment of a data chunk goes missing #286

smayoral · 2018-12-20T14:38:36Z

Hi,

I will try to describe the problem I have using an unordered channel either with
DATA_CHANNEL_RELIABLE_UNORDERED or with DATA_CHANNEL_PARTIAL_RELIABLE_REXMIT_UNORDERED.

My SCTP implementation sends:
DataChunk0Fragment0 TSN=0 Start/End
DataChunk1Fragment0 TSN=1 Start
DataChunk1Fragment1 TSN=2 End
DataChunk2Fragment0 TSN=3 Start/End
DataChunk3Fragment0 TSN=4 Start
DataChunk3Fragment1 TSN=5 End
DataChunk4Fragment0 TSN=6 Start/End
DataChunk5Fragment0 TSN=7 Start
DataChunk5Fragment1 TSN=8 End

usrsctp receives: (TSN=1 goes missing which is a start fragment)
DataChunk0Fragment0 TSN=0
DataChunk1Fragment1 TSN=2
DataChunk2Fragment0 TSN=3 (express delivery, highest_tsn_inside_nr_map=3, cumulative_tsn=0)
DataChunk3Fragment0 TSN=4 (Start Flag, fsn_included=4, top=4)
DataChunk3Fragment1 TSN=5
DataChunk4Fragment0 TSN=6 (express delivery, highest_tsn_inside_nr_map=6, cumulative_tsn=0)
DataChunk5Fragment0 TSN=7
DataChunk5Fragment1 TSN=8

I (sender) get following SACK Messages:
CumTsnAck CumTsn=0 Gap Start=2 End=2
CumTsnAck CumTsn=0 Gap Start=2 End=3
CumTsnAck CumTsn=0 Gap Start=2 End=4
CumTsnAck CumTsn=0 Gap Start=2 End=5
CumTsnAck CumTsn=0 Gap Start=2 End=6
CumTsnAck CumTsn=0 Gap Start=2 End=7
CumTsnAck CumTsn=0 Gap Start=2 End=8

My problem is that I have no idea what to send in the ForwardTSN message. I think I tried every possible combination but I never get the right DataChunks.
I would expect to get DataChunk2, DataChunk3, DataChunk4 and DataChunk5 but I get

DataChunk2 and DataChunk4 always since they are unfragmented.
DataChunk5 depending of Tsn in ForwardTSN Message
DataChunk3Fragment1 which is wrong since SCTP is configured reliable. SCTP must ensure the integrity of the data chunks.

Could you please give me some advice about the ForwardTSN Message? According to the RFC3758 cumTsn+StartGap-1 should be ok for the receiver.

Best Regards,
Sergio

EDIT: I finally found a working case and this is when I select DATA_CHANNEL_RELIABLE and I send Data Chunks with the Unordered Flag unset.
In this case the receiving queue will not be processed if a fragment gets lost and my ForwardTSN Message (cumTsn+StartGap-1) does what I expected.

tuexen · 2018-12-23T18:07:39Z

You wouldn't send a FORWARD-TSN chunk in case of a DATA_CHANNEL_RELIABLE_UNORDERED data channel or a DATA_CHANNEL_PARTIAL_RELIABLE_REXMIT_UNORDERED with a Reliability Parameter > 0. In both cases you would retransmit TSN=1 after receiving the third loss indication:

CumTsnAck CumTsn=0 Gap Start=2 End=4

This is describes as Fast Retransmission in RFC 4960.
Only for DATA_CHANNEL_PARTIAL_RELIABLE_REXMIT_UNORDERED with a Reliability Parameter = 0 you would send a FORWARD-TSN chunk in the above example. In that case you would abandon TSN=1 and TSN=2. So the New Cumulative TSN would be 2 and the stream identifier listed would be the one of the DATA chunk with TSN=1 and TSN=2. See the description in RFC 3758.

smayoral · 2018-12-23T21:31:47Z

Hi,
thank you very much for you reply.

the problem is that usrsctp library ignores my TSN=1 and TSN=2 because the library received TSN=4 before (start of a fragmented data chunk)

When the library gets my TSNs, the function sctp_flush_reassm_for_str_seq is called and following condition is checked:

if (!asoc->idata_supported && !ordered && SCTP_TSN_GT(control->fsn_included, cumtsn)) {

control->fsn_included is equal to 4 and cumtsn is equal to 2 and the Forward-TSNs are apparently ignored.

Another question is why you implemented express delivery for unfragmented data chunks but not for DataChunk3 or DataChunk5 is the example above since they were received completely. I think there is no reason to keep these data chunks in the queue.

Best regards,
Sergio.

tuexen · 2018-12-23T23:56:44Z

Hi,
thank you very much for you reply.

the problem is that usrsctp library ignores my TSN=1 and TSN=2 because the library received

TSN=4 before (start of a fragmented data chunk)
Wasn't TSN=1 dropped on the wire? Are you saying TSN=2 is dropped by the SACK even though it was acked in a GAP?

When the library gets my TSNs, the function sctp_flush_reassm_for_str_seq is called and following condition is checked:

if (!asoc->idata_supported && !ordered && SCTP_TSN_GT(control->fsn_included, cumtsn)) {

control->fsn_included is equal to 4 and cumtsn is equal to 2 and the Forward-TSNs are apparently ignored.

fsn_included means fragment sequence number. Why are you referring to FORWARD-TSN?

Another question is why you implemented express delivery for unfragmented data chunks but not for DataChunk3 or DataChunk5 is the example above since they were received completely. I think there is no reason to keep these data chunks in the queue.

The implementation might not be optimal...

Best regards
Michael

Best regards,
Sergio.

smayoral · 2018-12-24T08:52:03Z

Hi Michael,
I think it is difficult to explain the problem in this way. I will reproduce the problem again and send you the call stack of the usrsctp library after receiving each fragment.
But this should be easily reproduced:

Send a sequence like the example above without waiting for SACKs (all fragments at once)
Drop DataChunk1Fragment0 (Start Fragment) on the wire
Use ForwardTSN to tell the receiver to ignore DataChunk1 and keep processing the received data

At the receiving side:

I expect DataChunk0, DataChunk2, DataChunk3, DataChunk4, DataChunk5
I actually get DataChunk0, DataChunk2 and DataChunk4 (fragment data chunks are not processed)

Hopefully the call stack adds some clarity to the problem.

Best regards,
Sergio.

tuexen · 2018-12-24T09:09:49Z

Hi Michael,
I think it is difficult to explain the problem in this way. I will reproduce the problem again and send you the call stack of the usrsctp library after receiving each fragment.
But this should be easily reproduced:

Send a sequence like the example above without waiting for SACKs (all fragments at once)

Drop DataChunk1Fragment0 (Start Fragment) on the wire

Use ForwardTSN to tell the receiver to ignore DataChunk1 and keep processing the received data

At the receiving side:

I expect DataChunk0, DataChunk2, DataChunk3, DataChunk4, DataChunk5

I agree.

I actually get DataChunk0, DataChunk2 and DataChunk4 (fragment data chunks are not processed)

OK.

I can write a packetdrill script in the next days and test it on the FreeBSD kernel stack, which should behave identical to the usrsctp stack.

I'll post it here and will report whether it reproduces the issue you are seeing.

Best regards
Michael

Hopefully the call stack adds some clarity to the problem.

Best regards,
Sergio.

smayoral · 2018-12-26T10:28:34Z

Hi,
I defined SCTP_DEBUG with SCTP_DEBUG_ALL flag.
I have attached the resulting log.

My application sends:
DataChunk0 (lenght=1000 Bytes msg='A')
DataChunk1 (lenght=2000 Bytes msg='B') (DataChunk1Fragment0 goes missing)
DataChunk2 (lenght=1000 Bytes msg='C')
DataChunk3 (lenght=2000 Bytes msg='D')
DataChunk4 (lenght=1000 Bytes msg='E')
DataChunk5 (lenght=2000 Bytes msg='F')

usrsctp receives:
DataChunk0 (lenght=1000 Bytes msg='A')
DataChunk2 (lenght=1000 Bytes msg='C')
DataChunk4 (lenght=1000 Bytes msg='E')

Let me know if you need something else.

Best Regards,
Sergio

SCTP_DEBUG:

SCTP: add HMAC id 1 to list
SCTP: added chunk 193 (0xc1) to Auth list
SCTP: added chunk 128 (0x80) to Auth list
Bind called port: 10039
Addr: IPv4 address: 0.0.0.0:10039
Main hash to bind at head:0077706C, bound port:10039 - in tcp_pool=0
recv_function_udp: Received 52 bytes. - calling sctp_common_input_processing with off=12
stcb:00000000 inp:00781400
stcb is 00000000
Ok, Common input processing called, m:0078A780 iphlen:0 offset:12 length:52 stcb:00000000
sctp_process_control: iphlen=0, offset=12, length=52 stcb:00000000
Its an INIT of len:40 vtag:0
sctp_process_control: processing a chunk type=1, len=40
SCTP_INIT
sctp_handle_init: handling INIT tcb:00000000
sctp_handle_init: sending INIT-ACK
Check for unrecognized param's
Calling ipv4 output routine from low level src addr:c0a80106
Destination is c0a80106
RTP route is 00792150 through
IP output returns 0
recv_function_udp: Received 272 bytes. - calling sctp_common_input_processing with off=12
stcb:00000000 inp:00781400
stcb is 00000000
Ok, Common input processing called, m:007ADB80 iphlen:0 offset:12 length:272 stcb:00000000
sctp_process_control: iphlen=0, offset=12, length=272 stcb:00000000
sctp_process_control: processing a chunk type=10, len=260
SCTP_COOKIE_ECHO, stcb 00000000
sctp_handle_cookie: handling COOKIE-ECHO
Allocate an association for peer:IPv4 address: 192.168.1.6:5000
Port:5000
Adding an address (from:1) to the peer: IPv4 address: 192.168.1.6:5000
Association 00786D40 now allocated
Adding an address (from:2) to the peer: IPv4 address: 192.168.1.6:5000
SCTP: add HMAC id 1 to list
SCTP: added chunk 128 (0x80) to Auth list
SCTP: added chunk 193 (0xc1) to Auth list
moving to OPEN state
processing init-ack addresses
SCTP: add HMAC id 1 to list
SCTP: added chunk 193 (0xc1) to Auth list
SCTP: added chunk 128 (0x80) to Auth list
Association change SCTP_COMM_UP, streams (in/out) = (10/5), supports PR MULTIBUF.
Peer address 192.168.1.6 is now SCTP_ADDR_CONFIRMED (error = 0x00000000).
Check for chunk output prw:163840 tqe:0 tf=0
Calling chunk OUTPUT
Select source addr for:IPv4 address: 192.168.1.6:5000
ifn from route:00000000 ifn_index:1
No ifn emit interface?
Trying Plan B
Examine interface {51D1988E-2767-4C64-A7DA-41ACEE7145D6}
Found ifn:00000000 0 preferred source addresses
No preferred -- skipping to next
Examine interface {A478D621-55F2-4B90-A29D-0379EF5C4389}
Found ifn:00000000 0 preferred source addresses
No preferred -- skipping to next
Examine interface {CD762321-4C91-435B-BDE0-60D5104AE688}
Found ifn:00000000 0 preferred source addresses
No preferred -- skipping to next
Examine interface {CFE8B69F-EE93-48FF-A578-1A4129E04F40}
Found ifn:00000000 0 preferred source addresses
No preferred -- skipping to next
Examine interface {259650B9-B314-42BD-A269-24578FC4FEBA}
Is destination preferred:IPv4 address: 192.168.1.6:0
src_loop:0 src_priv:1 src_glob:0
dest_loop:0 dest_priv:1 dest_glob:0
YES
Found ifn:00000000 1 preferred source addresses
num preferred:1 on interface:0078B3E0 cur_addr_num:0
Is destination preferred:IPv4 address: 192.168.1.6:0
src_loop:0 src_priv:1 src_glob:0
dest_loop:0 dest_priv:1 dest_glob:0
YES
we selected 0
Source:IPv4 address: 192.168.1.6:0
Dest:IPv4 address: 192.168.1.6:5000
Calling ipv4 output routine from low level src addr:c0a80106
Destination is c0a80106
RTP route is 00792250 through
IP output returns 0
m-c-o put out 1
Ok, we have put out 1 chunks
chunk OUTPUT returns
Connected to 192.168.1.6:5000.
recv_function_udp: Received 40 bytes. - calling sctp_common_input_processing with off=12
Ok, Common input processing called, m:007ADCB8 iphlen:0 offset:12 length:40 stcb:00786D40
stcb:00786D40 state:8
chunk_flags:0x3 look for control on queues 00000000
chunk_flags: 0x3 ordered: 1 MID: 0 control: 0077B4B8
Queue control: 0077B4B8 for reordering MID: 0
handle_message 50 length=12<1
handle_message 3
DATA_CHANNEL_OPEN_REQUEST 50 length=12<8
handle_open_request_message 0 flags=0
handle_open_request_message unordered=0
send_open_response_message
Send called addr:00000000 send length 6
Calling ipv4 output routine from low level src addr:c0a80106
Destination is c0a80106
RTP route is 00792250 through
IP output returns 0
m-c-o put out 1
Ok, we have put out 1 chunks
USR Send complete qo:0 prw:163560 unsent:6 tf:22 cooq:1 toqs:22 err:0
Check for chunk output prw:163560 tqe:0 tf=22
Calling chunk OUTPUT
Calling ipv4 output routine from low level src addr:c0a80106
Destination is c0a80106
RTP route is 00792250 through
IP output returns 0
m-c-o put out 1
Ok, we have put out 1 chunks
chunk OUTPUT returns
recv_function_udp: Received 28 bytes. - calling sctp_common_input_processing with off=12
Ok, Common input processing called, m:007AEA20 iphlen:0 offset:12 length:28 stcb:00786D40
stcb:00786D40 state:8
sctp_process_control: iphlen=0, offset=12, length=28 stcb:00786D40
sctp_process_control: processing a chunk type=3, len=16
SCTP_SACK
SCTP_SACK process cum_ack:7a2a7d58 num_seg:0 a_rwnd:163834
Check for chunk output prw:163834 tqe:1 tf=0
recv_function_udp: Received 1028 bytes. - calling sctp_common_input_processing with off=12
Ok, Common input processing called, m:007AD910 iphlen:0 offset:12 length:1028 stcb:00786D40
stcb:00786D40 state:8
chunk_flags:0x7 look for control on queues 00000000
chunk_flags: 0x7 ordered: 0 MID: 1 control: 007AC770
Injecting control: 007AC770 to be read (MID: 1)
handle_message 52 length=1000<1
Message received of length 1000 on channel with id 0: AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
Check for chunk output prw:163834 tqe:1 tf=0
recv_function_udp: Received 828 bytes. - calling sctp_common_input_processing with off=12
Ok, Common input processing called, m:007ADDF0 iphlen:0 offset:12 length:828 stcb:00786D40
stcb:00786D40 state:8
chunk_flags:0x5 look for control on queues 00000000
chunk_flags: 0x5 ordered: 0 MID: 2 control: 007AC770
Building ck: 0077B4B8 for control: 007AC770 to be read (MID: 2)
Queue data to stream for reasm control: 007AC770 MID: 2
Check for chunk output prw:163834 tqe:0 tf=0
Calling chunk OUTPUT
Calling ipv4 output routine from low level src addr:c0a80106
Destination is c0a80106
RTP route is 00792250 through
IP output returns 0
m-c-o put out 1
Ok, we have put out 1 chunks
chunk OUTPUT returns
recv_function_udp: Received 1028 bytes. - calling sctp_common_input_processing with off=12
Ok, Common input processing called, m:007AE2D0 iphlen:0 offset:12 length:1028 stcb:00786D40
stcb:00786D40 state:8
chunk_flags:0x7 look for control on queues 007AC770
chunk_flags: 0x7 ordered: 0 MID: 3 control: 007AC808
Injecting control: 007AC808 to be read (MID: 3)
handle_message 52 length=1000<1
Message received of length 1000 on channel with id 0: CCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCC
Check for chunk output prw:163834 tqe:0 tf=0
Calling chunk OUTPUT
Calling ipv4 output routine from low level src addr:c0a80106
Destination is c0a80106
RTP route is 00792250 through
IP output returns 0
m-c-o put out 1
Ok, we have put out 1 chunks
chunk OUTPUT returns
recv_function_udp: Received 1228 bytes. - calling sctp_common_input_processing with off=12
Ok, Common input processing called, m:007AD1C0 iphlen:0 offset:12 length:1228 stcb:00786D40
stcb:00786D40 state:8
chunk_flags:0x6 look for control on queues 007AC770
chunk_flags: 0x6 ordered: 0 MID: 4 control: 007AC770
Building ck: 0078AD70 for control: 007AC770 to be read (MID: 4)
Queue data to stream for reasm control: 007AC770 MID: 4
chunk is a first fsn: 5 becomes fsn_included
Check for chunk output prw:163834 tqe:0 tf=0
Calling chunk OUTPUT
Calling ipv4 output routine from low level src addr:c0a80106
Destination is c0a80106
RTP route is 00792250 through
IP output returns 0
m-c-o put out 1
Ok, we have put out 1 chunks
chunk OUTPUT returns
recv_function_udp: Received 828 bytes. - calling sctp_common_input_processing with off=12
Ok, Common input processing called, m:007AE408 iphlen:0 offset:12 length:828 stcb:00786D40
stcb:00786D40 state:8
chunk_flags:0x5 look for control on queues 007AC770
chunk_flags: 0x5 ordered: 0 MID: 4 control: 007AC770
Building ck: 0078AD70 for control: 007AC770 to be read (MID: 4)
Queue data to stream for reasm control: 007AC770 MID: 4
Check for chunk output prw:163834 tqe:0 tf=0
Calling chunk OUTPUT
Calling ipv4 output routine from low level src addr:c0a80106
Destination is c0a80106
RTP route is 00792250 through
IP output returns 0
m-c-o put out 1
Ok, we have put out 1 chunks
chunk OUTPUT returns
recv_function_udp: Received 1028 bytes. - calling sctp_common_input_processing with off=12
Ok, Common input processing called, m:007ADA48 iphlen:0 offset:12 length:1028 stcb:00786D40
stcb:00786D40 state:8
chunk_flags:0x7 look for control on queues 007AC770
chunk_flags: 0x7 ordered: 0 MID: 5 control: 007AC8A0
Injecting control: 007AC8A0 to be read (MID: 5)
handle_message 52 length=1000<1
Message received of length 1000 on channel with id 0: EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE
Check for chunk output prw:163834 tqe:0 tf=0
Calling chunk OUTPUT
Calling ipv4 output routine from low level src addr:c0a80106
Destination is c0a80106
RTP route is 00792250 through
IP output returns 0
m-c-o put out 1
Ok, we have put out 1 chunks
chunk OUTPUT returns
recv_function_udp: Received 1228 bytes. - calling sctp_common_input_processing with off=12
Ok, Common input processing called, m:007AD910 iphlen:0 offset:12 length:1228 stcb:00786D40
stcb:00786D40 state:8
chunk_flags:0x6 look for control on queues 007AC770
chunk_flags: 0x6 ordered: 0 MID: 6 control: 007AC770
Building ck: 007AC808 for control: 007AC770 to be read (MID: 6)
Queue data to stream for reasm control: 007AC770 MID: 6
chunk is a first fsn: 8 becomes fsn_included
Check for chunk output prw:163834 tqe:0 tf=0
Calling chunk OUTPUT
Calling ipv4 output routine from low level src addr:c0a80106
Destination is c0a80106
RTP route is 00792250 through
IP output returns 0
m-c-o put out 1
Ok, we have put out 1 chunks
chunk OUTPUT returns
recv_function_udp: Received 828 bytes. - calling sctp_common_input_processing with off=12
Ok, Common input processing called, m:007AE2D0 iphlen:0 offset:12 length:828 stcb:00786D40
stcb:00786D40 state:8
chunk_flags:0x5 look for control on queues 007AC770
chunk_flags: 0x5 ordered: 0 MID: 6 control: 007AC770
Building ck: 007AC8A0 for control: 007AC770 to be read (MID: 6)
Queue data to stream for reasm control: 007AC770 MID: 6
Check for chunk output prw:163834 tqe:0 tf=0
Calling chunk OUTPUT
Calling ipv4 output routine from low level src addr:c0a80106
Destination is c0a80106
RTP route is 00792250 through
IP output returns 0
m-c-o put out 1
Ok, we have put out 1 chunks
chunk OUTPUT returns
recv_function_udp: Received 24 bytes. - calling sctp_common_input_processing with off=12
Ok, Common input processing called, m:007ADF28 iphlen:0 offset:12 length:24 stcb:00786D40
stcb:00786D40 state:8
sctp_process_control: iphlen=0, offset=12, length=24 stcb:00786D40
sctp_process_control: processing a chunk type=192, len=10
SCTP_FWD_TSN
Check for chunk output prw:163834 tqe:0 tf=0
Calling chunk OUTPUT
Calling ipv4 output routine from low level src addr:c0a80106
Destination is c0a80106
RTP route is 00792250 through
IP output returns 0
m-c-o put out 1
Ok, we have put out 1 chunks
chunk OUTPUT returns
recv_function_udp: Received 24 bytes. - calling sctp_common_input_processing with off=12
Ok, Common input processing called, m:007ADA48 iphlen:0 offset:12 length:24 stcb:00786D40
stcb:00786D40 state:8
sctp_process_control: iphlen=0, offset=12, length=24 stcb:00786D40
sctp_process_control: processing a chunk type=192, len=10
SCTP_FWD_TSN
Check for chunk output prw:163834 tqe:0 tf=0
Calling chunk OUTPUT
Calling ipv4 output routine from low level src addr:c0a80106
Destination is c0a80106
RTP route is 00792250 through
IP output returns 0
m-c-o put out 1
Ok, we have put out 1 chunks
chunk OUTPUT returns
recv_function_udp: Received 24 bytes. - calling sctp_common_input_processing with off=12
Ok, Common input processing called, m:007ADA48 iphlen:0 offset:12 length:24 stcb:00786D40
stcb:00786D40 state:8
sctp_process_control: iphlen=0, offset=12, length=24 stcb:00786D40
sctp_process_control: processing a chunk type=192, len=10
SCTP_FWD_TSN
Check for chunk output prw:163834 tqe:0 tf=0
Calling chunk OUTPUT
Calling ipv4 output routine from low level src addr:c0a80106
Destination is c0a80106
RTP route is 00792250 through
IP output returns 0
m-c-o put out 1
Ok, we have put out 1 chunks
chunk OUTPUT returns
recv_function_udp: Received 24 bytes. - calling sctp_common_input_processing with off=12
Ok, Common input processing called, m:007ADA48 iphlen:0 offset:12 length:24 stcb:00786D40
stcb:00786D40 state:8
sctp_process_control: iphlen=0, offset=12, length=24 stcb:00786D40
sctp_process_control: processing a chunk type=192, len=10
SCTP_FWD_TSN
Check for chunk output prw:163834 tqe:0 tf=0
Calling chunk OUTPUT
Calling ipv4 output routine from low level src addr:c0a80106
Destination is c0a80106
RTP route is 00792250 through
IP output returns 0
m-c-o put out 1
Ok, we have put out 1 chunks
chunk OUTPUT returns
recv_function_udp: Received 24 bytes. - calling sctp_common_input_processing with off=12
Ok, Common input processing called, m:007AEF00 iphlen:0 offset:12 length:24 stcb:00786D40
stcb:00786D40 state:8
sctp_process_control: iphlen=0, offset=12, length=24 stcb:00786D40
sctp_process_control: processing a chunk type=192, len=10
SCTP_FWD_TSN
Check for chunk output prw:163834 tqe:0 tf=0
Calling chunk OUTPUT
Calling ipv4 output routine from low level src addr:c0a80106
Destination is c0a80106
RTP route is 00792250 through
IP output returns 0
m-c-o put out 1
Ok, we have put out 1 chunks
chunk OUTPUT returns
recv_function_udp: Received 24 bytes. - calling sctp_common_input_processing with off=12
Ok, Common input processing called, m:007AE540 iphlen:0 offset:12 length:24 stcb:00786D40
stcb:00786D40 state:8
sctp_process_control: iphlen=0, offset=12, length=24 stcb:00786D40
sctp_process_control: processing a chunk type=192, len=10
SCTP_FWD_TSN
Check for chunk output prw:163834 tqe:0 tf=0
Calling chunk OUTPUT
Calling ipv4 output routine from low level src addr:c0a80106
Destination is c0a80106
RTP route is 00792250 through
IP output returns 0
m-c-o put out 1
Ok, we have put out 1 chunks
chunk OUTPUT returns
recv_function_udp: Received 24 bytes. - calling sctp_common_input_processing with off=12
Ok, Common input processing called, m:007AE8E8 iphlen:0 offset:12 length:24 stcb:00786D40
stcb:00786D40 state:8
sctp_process_control: iphlen=0, offset=12, length=24 stcb:00786D40
sctp_process_control: processing a chunk type=192, len=10
SCTP_FWD_TSN
Check for chunk output prw:163834 tqe:0 tf=0
Calling chunk OUTPUT
Calling ipv4 output routine from low level src addr:c0a80106
Destination is c0a80106
RTP route is 00792250 through
IP output returns 0
m-c-o put out 1
Ok, we have put out 1 chunks
chunk OUTPUT returns
Calling ipv4 output routine from low level src addr:c0a80106
Destination is c0a80106
RTP route is 00792250 through
IP output returns 0
m-c-o put out 1
Ok, we have put out 1 chunks

tuexen · 2019-01-01T14:53:51Z

The following packetdrill shows how the stack currently behaves:

 0.0 `sysctl -w net.inet.sctp.ecn_enable=0`
+0.0 `sysctl -w net.inet.sctp.pr_enable=1`
+0.0 `sysctl -w net.inet.sctp.asconf_enable=0`
+0.0 `sysctl -w net.inet.sctp.auth_enable=0`
+0.0 `sysctl -w net.inet.sctp.reconfig_enable=1`
+0.0 `sysctl -w net.inet.sctp.nrsack_enable=0`
+0.0 `sysctl -w net.inet.sctp.pktdrop_enable=0`

+0.0 socket(..., SOCK_STREAM, IPPROTO_SCTP) = 3
+0.0 fcntl(3, F_GETFL) = 0x2 (flags O_RDWR)
+0.0 fcntl(3, F_SETFL, O_RDWR|O_NONBLOCK) = 0
+0.1 connect(3, ..., ...) = -1 EINPROGRESS (Operation now in progress)
+0.0 > sctp: INIT[flgs=0, tag=1, a_rwnd=..., os=..., is=..., tsn=1, ...]
+0.1 < sctp: INIT_ACK[flgs=0, tag=2, a_rwnd=1500, os=1, is=1, tsn=0, STATE_COOKIE[len=5, val=...]]
+0.0 > sctp: COOKIE_ECHO[flgs=0, len=5, val=...]
+0.1 < sctp: COOKIE_ACK[flgs=0]
+0.0 getsockopt(3, SOL_SOCKET, SO_ERROR, [0], [4]) = 0
// First complete message is received.
+0.0 < sctp: DATA[flgs=UBE, len=1468, tsn=0, sid=0, ssn=0, ppid=53]
+0.0 > sctp: SACK[flgs=0, cum_tsn=0, a_rwnd=..., gaps=[], dups=[]]
+0.0 recv(3, ..., 2000, 0) = 1452
// First fragment of second message is missing.
+0.0 < sctp: DATA[flgs=UE, len=1116, tsn=2, sid=0, ssn=0, ppid=53]
+0.0 > sctp: SACK[flgs=0, cum_tsn=0, a_rwnd=..., gaps=[2:2], dups=[]]
// Third complete message is received.
+0.0 < sctp: DATA[flgs=UBE, len=1416, tsn=3, sid=0, ssn=0, ppid=53]
+0.0 > sctp: SACK[flgs=0, cum_tsn=0, a_rwnd=..., gaps=[2:3], dups=[]]
+0.0 recv(3, ..., 2000, 0) = 1400
// Fourth fragmented message is received. Could be delivered, but isn't.
+0.0 < sctp: DATA[flgs=UB, len=1416, tsn=4, sid=0, ssn=0, ppid=53]
+0.0 > sctp: SACK[flgs=0, cum_tsn=0, a_rwnd=..., gaps=[2:4], dups=[]]
+0.0 < sctp: DATA[flgs=UE, len=1416, tsn=5, sid=0, ssn=0, ppid=53]
+0.0 > sctp: SACK[flgs=0, cum_tsn=0, a_rwnd=..., gaps=[2:5], dups=[]]
+0.0 recv(3, ..., 3000, 0) = -1 EAGAIN (Resource temporarily unavailable)
// Fifth complete message is received.
+0.0 < sctp: DATA[flgs=UBE, len=1316, tsn=6, sid=0, ssn=0, ppid=53]
+0.0 > sctp: SACK[flgs=0, cum_tsn=0, a_rwnd=..., gaps=[2:6], dups=[]]
+0.0 recv(3, ..., 2000, 0) = 1300
// Sixth fragmented message is received. Could be delivered, but isn't.
+0.0 < sctp: DATA[flgs=UB, len=1216, tsn=7, sid=0, ssn=0, ppid=53]
+0.0 > sctp: SACK[flgs=0, cum_tsn=0, a_rwnd=..., gaps=[2:7], dups=[]]
+0.0 < sctp: DATA[flgs=UE, len=1216, tsn=8, sid=0, ssn=0, ppid=53]
+0.0 > sctp: SACK[flgs=0, cum_tsn=0, a_rwnd=..., gaps=[2:8], dups=[]]
+0.0 recv(3, ..., 3000, 0) = -1 EAGAIN (Resource temporarily unavailable)
// Missing first fragment of second message is received.
+0.0 < sctp: DATA[flgs=UB, len=1116, tsn=1, sid=0, ssn=0, ppid=53]
+0.0 > sctp: SACK[flgs=0, cum_tsn=8, a_rwnd=..., gaps=[], dups=[]]
// Second reassembled message gets delivered.
+0.0 recv(3, ..., 3000, 0) = 2200
// Fourth reassembled message gets delivered.
+0.0 recv(3, ..., 3000, 0) = 2800
// Sixth reassembled message gets delivered.
+0.0 recv(3, ..., 3000, 0) = 2400
// Tear down the association
+0.0 close(3) = 0
+0.0 > sctp: SHUTDOWN[flgs=0, cum_tsn=8]
+0.1 < sctp: SHUTDOWN_ACK[flgs=0]
+0.0 > sctp: SHUTDOWN_COMPLETE[flgs=0]

Basically, reassembled unordered messages might not get delivered as soon as possible. This is a limitation of the current implementation. I can try to look at removing this limitation...

smayoral · 2019-01-01T21:01:45Z

Hi,
you write "Missing first fragment of second message is received."
What if this message really gets lost?
Did you try to use ForwardTSN? The library should deliver queued messages after processing ForwardTSN message but it doesn't.

In my tests, using ForwardTSN, the fragmented messages get never delivered, probably because the missing messages never arrive.

Thanks again for testing this issue.

tuexen · 2019-01-01T23:53:21Z

The point is if the first fragment is lost, it is retransmitted by the peer, if it is not abandoned.

However, if it is abandoned, you are right, there is a bug. The following scripts does NOT run:

 0.0 `sysctl -w net.inet.sctp.ecn_enable=0`
+0.0 `sysctl -w net.inet.sctp.pr_enable=1`
+0.0 `sysctl -w net.inet.sctp.asconf_enable=0`
+0.0 `sysctl -w net.inet.sctp.auth_enable=0`
+0.0 `sysctl -w net.inet.sctp.reconfig_enable=1`
+0.0 `sysctl -w net.inet.sctp.nrsack_enable=0`
+0.0 `sysctl -w net.inet.sctp.pktdrop_enable=0`

+0.0 socket(..., SOCK_STREAM, IPPROTO_SCTP) = 3
+0.0 fcntl(3, F_GETFL) = 0x2 (flags O_RDWR)
+0.0 fcntl(3, F_SETFL, O_RDWR|O_NONBLOCK) = 0
+0.1 connect(3, ..., ...) = -1 EINPROGRESS (Operation now in progress)
+0.0 > sctp: INIT[flgs=0, tag=1, a_rwnd=..., os=..., is=..., tsn=1, ...]
+0.1 < sctp: INIT_ACK[flgs=0, tag=2, a_rwnd=1500, os=1, is=1, tsn=0, FORWARD_TSN_SUPPORTED[], STATE_COOKIE[len=5, val=...]]
+0.0 > sctp: COOKIE_ECHO[flgs=0, len=5, val=...]
+0.1 < sctp: COOKIE_ACK[flgs=0]
+0.0 getsockopt(3, SOL_SOCKET, SO_ERROR, [0], [4]) = 0
// First complete message is received.
+0.0 < sctp: DATA[flgs=UBE, len=1468, tsn=0, sid=0, ssn=0, ppid=53]
+0.0 > sctp: SACK[flgs=0, cum_tsn=0, a_rwnd=..., gaps=[], dups=[]]
+0.0 recv(3, ..., 2000, 0) = 1452
// First fragment of second message is missing.
+0.0 < sctp: DATA[flgs=UE, len=1116, tsn=2, sid=0, ssn=0, ppid=53]
+0.0 > sctp: SACK[flgs=0, cum_tsn=0, a_rwnd=..., gaps=[2:2], dups=[]]
// Third complete message is received.
+0.0 < sctp: DATA[flgs=UBE, len=1416, tsn=3, sid=0, ssn=0, ppid=53]
+0.0 > sctp: SACK[flgs=0, cum_tsn=0, a_rwnd=..., gaps=[2:3], dups=[]]
+0.0 recv(3, ..., 2000, 0) = 1400
// Fourth fragmented message is received. Could be delivered, but isn't.
+0.0 < sctp: DATA[flgs=UB, len=1416, tsn=4, sid=0, ssn=0, ppid=53]
+0.0 > sctp: SACK[flgs=0, cum_tsn=0, a_rwnd=..., gaps=[2:4], dups=[]]
+0.0 < sctp: DATA[flgs=UE, len=1416, tsn=5, sid=0, ssn=0, ppid=53]
+0.0 > sctp: SACK[flgs=0, cum_tsn=0, a_rwnd=..., gaps=[2:5], dups=[]]
+0.0 recv(3, ..., 3000, 0) = -1 EAGAIN (Resource temporarily unavailable)
// Fifth complete message is received.
+0.0 < sctp: DATA[flgs=UBE, len=1316, tsn=6, sid=0, ssn=0, ppid=53]
+0.0 > sctp: SACK[flgs=0, cum_tsn=0, a_rwnd=..., gaps=[2:6], dups=[]]
+0.0 recv(3, ..., 2000, 0) = 1300
// Sixth fragmented message is received. Could be delivered, but isn't.
+0.0 < sctp: DATA[flgs=UB, len=1216, tsn=7, sid=0, ssn=0, ppid=53]
+0.0 > sctp: SACK[flgs=0, cum_tsn=0, a_rwnd=..., gaps=[2:7], dups=[]]
+0.0 < sctp: DATA[flgs=UE, len=1216, tsn=8, sid=0, ssn=0, ppid=53]
+0.0 > sctp: SACK[flgs=0, cum_tsn=0, a_rwnd=..., gaps=[2:8], dups=[]]
+0.0 recv(3, ..., 3000, 0) = -1 EAGAIN (Resource temporarily unavailable)
// Second message was abandoned by peer.
+0.0 < sctp: FORWARD_TSN[cum_tsn=2, ids=[{0,0}]]
+0.0 > sctp: SACK[flgs=0, cum_tsn=8, a_rwnd=..., gaps=[], dups=[]]
// Fourth reassembled message gets delivered.
+0.0 recv(3, ..., 3000, 0) = 2800
// Sixth reassembled message gets delivered.
+0.0 recv(3, ..., 3000, 0) = 2400
// Tear down the association
+0.0 close(3) = 0
+0.0 > sctp: SHUTDOWN[flgs=0, cum_tsn=8]
+0.1 < sctp: SHUTDOWN_ACK[flgs=0]
+0.0 > sctp: SHUTDOWN_COMPLETE[flgs=0]

It hangs at the recv() call for the fourth message. Will look into it.

smayoral · 2019-01-02T08:57:34Z

That is exactly the problem I am having, nice that you could also reproduce it.

and FORWARD-TSN. This bug was reported in sctplab/usrsctp#286 for the userland stack. This is joint work with rrs@. MFC after: 1 week git-svn-id: svn+ssh://svn.freebsd.org/base/head@345494 ccf9f872-aa2e-dd11-9fc8-001c23d0bc1f

and FORWARD-TSN. This bug was reported in sctplab/usrsctp#286 for the userland stack. This is joint work with rrs@. MFC after: 1 week

and FORWARD-TSN. This bug was reported in sctplab/usrsctp#286 for the userland stack. This is joint work with rrs@. MFC after: 1 week git-svn-id: https://svn.freebsd.org/base/head@345494 ccf9f872-aa2e-dd11-9fc8-001c23d0bc1f

and FORWARD-TSN. This bug was reported in sctplab/usrsctp#286 for the userland stack. This is joint work with rrs@. MFC after: 1 week

and FORWARD-TSN. This bug was reported in sctplab/usrsctp#286 for the userland stack. This is joint work with rrs@. MFC after: 1 week git-svn-id: svn+ssh://svn.freebsd.org/base/head@345494 ccf9f872-aa2e-dd11-9fc8-001c23d0bc1f

Fix the handling of fragmented unordered messages when using DATA chunks and FORWARD-TSN. This bug was reported in sctplab/usrsctp#286 for the userland stack. This is joint work with rrs@.

Fix the handling of fragmented unordered messages when using DATA chunks and FORWARD-TSN. This bug was reported in sctplab/usrsctp#286 for the userland stack. This is joint work with rrs@. git-svn-id: https://svn.freebsd.org/base/stable/12@347117 ccf9f872-aa2e-dd11-9fc8-001c23d0bc1f

Fix the handling of fragmented unordered messages when using DATA chunks and FORWARD-TSN. This bug was reported in sctplab/usrsctp#286 for the userland stack. This is joint work with rrs@.

Fix the handling of fragmented unordered messages when using DATA chunks and FORWARD-TSN. This bug was reported in sctplab/usrsctp#286 for the userland stack. This is joint work with rrs@. git-svn-id: https://svn.freebsd.org/base/stable/11@347677 ccf9f872-aa2e-dd11-9fc8-001c23d0bc1f

tuexen closed this as completed in 6dcb0e0 Mar 26, 2019

uqs pushed a commit to freebsd/freebsd-src that referenced this issue May 4, 2019

MFC r345494:

b4f2430

Fix the handling of fragmented unordered messages when using DATA chunks and FORWARD-TSN. This bug was reported in sctplab/usrsctp#286 for the userland stack. This is joint work with rrs@.

uqs pushed a commit to freebsd/freebsd-src that referenced this issue May 16, 2019

MFC r345494:

21f17b7

Fix the handling of fragmented unordered messages when using DATA chunks and FORWARD-TSN. This bug was reported in sctplab/usrsctp#286 for the userland stack. This is joint work with rrs@.

mstyura pushed a commit to mstyura/usrsctp that referenced this issue Oct 2, 2019

Fix sctplab#286.

0cfd465

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

PR-SCTP issue if start fragment of a data chunk goes missing #286

PR-SCTP issue if start fragment of a data chunk goes missing #286

smayoral commented Dec 20, 2018 •

edited

Loading

tuexen commented Dec 23, 2018

smayoral commented Dec 23, 2018

tuexen commented Dec 23, 2018 •

edited

Loading

smayoral commented Dec 24, 2018

tuexen commented Dec 24, 2018

smayoral commented Dec 26, 2018

tuexen commented Jan 1, 2019

smayoral commented Jan 1, 2019

tuexen commented Jan 1, 2019

smayoral commented Jan 2, 2019

PR-SCTP issue if start fragment of a data chunk goes missing #286

PR-SCTP issue if start fragment of a data chunk goes missing #286

Comments

smayoral commented Dec 20, 2018 • edited Loading

tuexen commented Dec 23, 2018

smayoral commented Dec 23, 2018

tuexen commented Dec 23, 2018 • edited Loading

smayoral commented Dec 24, 2018

tuexen commented Dec 24, 2018

smayoral commented Dec 26, 2018

tuexen commented Jan 1, 2019

smayoral commented Jan 1, 2019

tuexen commented Jan 1, 2019

smayoral commented Jan 2, 2019

smayoral commented Dec 20, 2018 •

edited

Loading

tuexen commented Dec 23, 2018 •

edited

Loading