Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Debug panic in packet assembler #261

Closed
pothos opened this issue Aug 29, 2018 · 8 comments
Closed

Debug panic in packet assembler #261

pothos opened this issue Aug 29, 2018 · 8 comments
Labels
kind/bug

Comments

@pothos
Copy link
Contributor

pothos commented Aug 29, 2018 •
edited

In debug mode I got a panic if the packet assembler is overwhelmed for long time with 1 byte sends and probably misses to reject it due to an overflow or similar? (Even though I have no idea how the sender got into sending only single bytes – maybe it isn't related to the panic and it works with multiple of bytes, too. Edit: Ah, the silly window syndrome.).

TRACE 2018-08-29T22:15:48Z: smoltcp::socket::tcp: #13:192.168.1.201:8080:192.168.1.202:56349: assembler: [ (446) 283 (295) 103 (626) 737 (497510) ]
TRACE 2018-08-29T22:15:48Z: smoltcp::socket::tcp: #13:192.168.1.201:8080:192.168.1.202:56349: ACKing incoming segment
TRACE 2018-08-29T22:15:48Z: smoltcp::socket::tcp: #13:192.168.1.201:8080:192.168.1.202:56349: rx buffer: receiving 1 octets at offset 2490
TRACE 2018-08-29T22:15:48Z: smoltcp::socket::tcp: #13:192.168.1.201:8080:192.168.1.202:56349: assembler: [ (446) 283 (295) 103 (626) 738 (497509) ]
TRACE 2018-08-29T22:15:48Z: smoltcp::socket::tcp: #13:192.168.1.201:8080:192.168.1.202:56349: ACKing incoming segment
TRACE 2018-08-29T22:15:48Z: smoltcp::socket::tcp: #13:192.168.1.201:8080:192.168.1.202:56349: rx buffer: receiving 1 octets at offset 2491
TRACE 2018-08-29T22:15:48Z: smoltcp::socket::tcp: #13:192.168.1.201:8080:192.168.1.202:56349: assembler: [ (446) 283 (295) 103 (626) 739 (497508) ]
TRACE 2018-08-29T22:15:48Z: smoltcp::socket::tcp: #13:192.168.1.201:8080:192.168.1.202:56349: ACKing incoming segment
TRACE 2018-08-29T22:15:48Z: smoltcp::socket::tcp: #13:192.168.1.201:8080:192.168.1.202:56349: rx buffer: receiving 1 octets at offset 2492
TRACE 2018-08-29T22:15:48Z: smoltcp::socket::tcp: #13:192.168.1.201:8080:192.168.1.202:56349: assembler: [ (446) 283 (295) 103 (626) 740 (497507) ]
TRACE 2018-08-29T22:15:48Z: smoltcp::socket::tcp: #13:192.168.1.201:8080:192.168.1.202:56349: ACKing incoming segment
DEBUG 2018-08-29T22:15:48Z: smoltcp::socket::tcp: #13:192.168.1.201:8080:192.168.1.202:56349: assembler: too many holes to add 1 octets at offset 2836
[… many more]
DEBUG 2018-08-29T22:15:48Z: smoltcp::socket::tcp: #13:192.168.1.201:8080:192.168.1.202:56349: assembler: too many holes to add 1 octets at offset 4074
[…]
DEBUG 2018-08-29T22:15:48Z: smoltcp::socket::tcp: #13:192.168.1.201:8080:192.168.1.202:56349: assembler: too many holes to add 1 octets at offset 4075
DEBUG 2018-08-29T22:15:48Z: smoltcp::iface::ethernet: cannot process ingress packet: dropped by socket
DEBUG 2018-08-29T22:15:48Z: smoltcp::iface::ethernet: packet dump follows:
EthernetII src=aa-bb-cc-dd-ee-02 dst=aa-bb-cc-dd-ee-07 type=IPv4
\ IPv4 src=192.168.1.202 dst=192.168.1.201 proto=TCP
 \ TCP src=56349 dst=8080 seq=505333 ack=1 win=62500 len=1
poll result: Dropped
panicked at 'assertion failed: size == 0', ./smoltcp/src/storage/assembler.rs:201:9
stack backtrace:
   0:     0x563f39a3d57e - std::sys::unix::backtrace::tracing::imp::unwind_backtrace::h1410ee01a7694834
                               at libstd/sys/unix/backtrace/tracing/gcc_s.rs:49
   1:     0x563f39a2ad96 - std::sys_common::backtrace::print::h1962f4c30d928b1d
                               at libstd/sys_common/backtrace.rs:71
                               at libstd/sys_common/backtrace.rs:59
   2:     0x563f39a2915d - std::panicking::default_hook::{{closure}}::h66071f1a30ddacaa
                               at libstd/panicking.rs:211
   3:     0x563f39a28ed0 - std::panicking::default_hook::h8288f681d56575d2
                               at libstd/panicking.rs:227
   4:     0x563f39a297cc - std::panicking::rust_panic_with_hook::h46fa5def146c1328
                               at libstd/panicking.rs:475
   5:     0x563f39a24caf - std::panicking::begin_panic::hafaf759661cad18b
                               at /checkout/src/libstd/panicking.rs:409
   6:     0x563f399f4d2b - smoltcp::storage::assembler::Assembler::add::h18d6fa689dd019ad
                               at ./smoltcp/src/storage/assembler.rs:201
   7:     0x563f399af4b8 - smoltcp::socket::tcp::TcpSocket::process::h0e8c82c6a50e097b
                               at ./smoltcp/src/socket/tcp.rs:1249
   8:     0x563f399ddf13 - smoltcp::iface::ethernet::InterfaceInner::process_tcp::h60c7cba9920864db
                               at ./smoltcp/src/iface/ethernet.rs:1308
   9:     0x563f395965ee - smoltcp::iface::ethernet::InterfaceInner::process_ipv4::hb008add919e7d7ad
                               at ./smoltcp/src/iface/ethernet.rs:936
  10:     0x563f3959732e - smoltcp::iface::ethernet::InterfaceInner::process_ethernet::haa742a5de2d6922e
                               at ./smoltcp/src/iface/ethernet.rs:736
  11:     0x563f3957dfbb - <smoltcp::iface::ethernet::Interface<'b, 'c, 'e, DeviceT>>::socket_ingress::{{closure}}::h3e90c5c09cd413d2
                               at ./smoltcp/src/iface/ethernet.rs:505
  12:     0x563f3951f600 - <RxToken as smoltcp::phy::RxToken>::consume::hf259c7e3ae4dbad1
                               at …
  13:     0x563f3957db96 - <smoltcp::iface::ethernet::Interface<'b, 'c, 'e, DeviceT>>::socket_ingress::hc1d013d9d870336a
                               at ./smoltcp/src/iface/ethernet.rs:504
  14:     0x563f3958012e - <smoltcp::iface::ethernet::Interface<'b, 'c, 'e, DeviceT>>::poll::hce442aff8bb9beff
                               at ./smoltcp/src/iface/ethernet.rs:441
[…]
@whitequark
Copy link
Contributor

This is interesting. The logic in Assembler::add is not trivial. Do you think you could record a trace under rr so that I can step back through it?

@pothos
Copy link
Contributor Author

pothos commented Sep 22, 2018

That's a good idea - or I try to reproduce this in a test case. What do you think would happen in a release compile?

@whitequark
Copy link
Contributor

I have no idea, but probably data loss--this assert is there for a good reason. We actually might want to elevate it to assert!.

@pothos
Copy link
Contributor Author

pothos commented Sep 22, 2018

The while loop can be left if index == self.contigs.len(). What should be the result in this case?

@whitequark
Copy link
Contributor

I don't actually know! I wrote this code a while ago and I don't remember the exact rationale for that condition. How about adding a fuzzer-based test that generates and feeds the assembler random data ranges and sees what happens? That should discover a reduced test case for the crash very rapidly.

@pothos
Copy link
Contributor Author

pothos commented Sep 22, 2018 •
edited

I'm new to reading it as well and reported this here in case others also observe it. By reading quickly, I'm very suspicious about this part because it can explain why suddenly the 1-length packet was not dropped anymore:

                self.contigs[index].shrink_hole_by(offset + size);
                let inserted = self.add_contig_at(index)?;

The ? in add_contig_at was responsible for rejecting the packet with the "too many holes" error. But the line before changed the contig state even if this line will reject the packet.

@whitequark
Copy link
Contributor

Excellent catch! Can you write a testcase?

@pothos
Copy link
Contributor Author

pothos commented Sep 22, 2018

I'll have to dive into it a bit more, then yes ;)

pothos added a commit to pothos/smoltcp that referenced this issue Sep 22, 2018
@pothos
Only change the assembler state on success
9ccf18e 
The current hole was always shrinked even if the
packet assembler rejected adding a packet due to
not being able to insert a new hole.

Shrink only after a new hole was added.
Shrinking before or after does not make a difference
because offset + size < hole_size and thus
contigs[index] is not empty, passing the
debug_assert in add_contig_at.

smoltcp-rs#261
@pothos pothos mentioned this issue Sep 22, 2018
Closed
m-labs-homu pushed a commit that referenced this issue Sep 22, 2018
@pothos
Only change the assembler state on success
68869de 
The current hole was always shrinked even if the
packet assembler rejected adding a packet due to
not being able to insert a new hole.

Shrink only after a new hole was added.
Shrinking before or after does not make a difference
because offset + size < hole_size and thus
contigs[index] is not empty, passing the
debug_assert in add_contig_at.

#261

Closes: #265
Approved by: whitequark
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
kind/bug
Milestone
No milestone
Development

No branches or pull requests
2 participants
@whitequark @pothos