goldsi...@gmx.de<mailto:goldsi...@gmx.de> writes:
Maybe. As a starter, you should disable everything you can in tcp_output (TCP_OUTPUT_DEBUG, TCP_CWND_DEBUG). Then once the error happens, try dumping the lwip_stats plus the whole tcp_pcb that doesn't send any more. There's no function to do that, so you'll have to write that on your own. I mean every member of the tcp_pcb plus all "interesting" members of lists like unsent, unacked etc. Below is debug output for TCP up until it fails (minus a lot more ahead of that that was OK). The last 4 lines repeat forever. Our application disconnects and reconnects after 5 seconds of no response which unfortunately has kept customers at bay because the system does recover on its own. We make commercial ink jet printers so if the customer is printing it's bad - even worse with a 500 lb paper roll. The only good thing is only one customer is seeing disconnects hourly or more. I get them in less than 5 minutes which is great for testing. tcp_receive: pcb->rttest 467 rtseq 44078 ackno 44410 tcp_receive: experienced rtt 1 ticks (500 msec). tcp_receive: RTO 4 (2000 milliseconds) tcp_output: nothing to send (0x00000000) tcp_output: snd_wnd 63244, cwnd 23364, wnd 23364, seg == NULL, ack 44410 tcp_slowtmr: processing active pcb tcp_slowtmr: polling application tcp_output: nothing to send (0x00000000) tcp_output: snd_wnd 63244, cwnd 23364, wnd 23364, seg == NULL, ack 44410 tcp_write(pcb=0x008449f8, data=0x0083ae20, len=332, apiflags=0) tcp_write: queuelen: 0 tcp_write: queueing 44410:44742 tcp_write: 2 (after enqueued) tcp_output: snd_wnd 63244, cwnd 23364, wnd 23364, effwnd 332, seq 44410, ack 44410 tcp_output: snd_wnd 63244, cwnd 23364, wnd 23364, effwnd 332, seq 44410, ack 44410, i 0 tcp_output_segment: rtseq 44410 tcp_output_segment: 44410:44742 tcp_output: nothing to send (0x00000000) tcp_output: snd_wnd 63244, cwnd 23364, wnd 23364, seg == NULL, ack 44410 tcp_slowtmr: processing active pcb tcp_slowtmr: polling application tcp_output: nothing to send (0x00000000) tcp_output: snd_wnd 63244, cwnd 23364, wnd 23364, seg == NULL, ack 44410 tcp_receive: window update 62912 tcp_receive: congestion avoidance cwnd 23455 tcp_receive: queuelen 2 ... 0 (after freeing unacked) tcp_receive: pcb->rttest 469 rtseq 44410 ackno 44742 tcp_receive: experienced rtt 1 ticks (500 msec). tcp_receive: RTO 4 (2000 milliseconds) tcp_output: nothing to send (0x00000000) tcp_output: snd_wnd 62912, cwnd 23455, wnd 23455, seg == NULL, ack 44742 tcp_slowtmr: processing active pcb tcp_slowtmr: polling application tcp_output: nothing to send (0x00000000) tcp_output: snd_wnd 62912, cwnd 23455, wnd 23455, seg == NULL, ack 44742 tcp_write(pcb=0x008449f8, data=0x0083af6c, len=332, apiflags=0) tcp_write: queuelen: 0 tcp_write: queueing 44742:45074 tcp_write: 2 (after enqueued) tcp_output: snd_wnd 62912, cwnd 23455, wnd 23455, effwnd 332, seq 44742, ack 44742 tcp_output: snd_wnd 62912, cwnd 23455, wnd 23455, effwnd 332, seq 44742, ack 44742, i 0 tcp_output_segment: rtseq 44742 tcp_output_segment: 44742:45074 tcp_output: nothing to send (0x00000000) tcp_output: snd_wnd 62912, cwnd 23455, wnd 23455, seg == NULL, ack 44742 tcp_slowtmr: processing active pcb tcp_slowtmr: polling application tcp_output: nothing to send (0x00000000) tcp_output: snd_wnd 62912, cwnd 23455, wnd 23455, seg == NULL, ack 44742 tcp_receive: window update 64240 tcp_receive: congestion avoidance cwnd 23545 tcp_receive: queuelen 2 ... 0 (after freeing unacked) tcp_receive: pcb->rttest 471 rtseq 44742 ackno 45074 tcp_receive: experienced rtt 1 ticks (500 msec). tcp_receive: RTO 4 (2000 milliseconds) tcp_output: nothing to send (0x00000000) tcp_output: snd_wnd 64240, cwnd 23545, wnd 23545, seg == NULL, ack 45074 tcp_slowtmr: processing active pcb tcp_slowtmr: polling application tcp_output: nothing to send (0x00000000) tcp_output: snd_wnd 64240, cwnd 23545, wnd 23545, seg == NULL, ack 45074 tcp_write(pcb=0x008449f8, data=0x0083b0b8, len=332, apiflags=0) tcp_write: queuelen: 0 tcp_write: queueing 45074:45406 tcp_write: 2 (after enqueued) tcp_output: snd_wnd 64240, cwnd 23545, wnd 23545, effwnd 332, seq 45074, ack 45074 tcp_output: snd_wnd 64240, cwnd 23545, wnd 23545, effwnd 332, seq 45074, ack 45074, i 0 tcp_output_segment: rtseq 45074 tcp_output_segment: 45074:45406 tcp_output: nothing to send (0x00000000) tcp_output: snd_wnd 64240, cwnd 23545, wnd 23545, seg == NULL, ack 45074 tcp_slowtmr: processing active pcb tcp_slowtmr: polling application tcp_output: nothing to send (0x00000000) tcp_output: snd_wnd 64240, cwnd 23545, wnd 23545, seg == NULL, ack 45074 tcp_receive: window update 63908 tcp_receive: congestion avoidance cwnd 23635 tcp_receive: queuelen 2 ... 0 (after freeing unacked) tcp_receive: pcb->rttest 473 rtseq 45074 ackno 45406 tcp_receive: experienced rtt 1 ticks (500 msec). tcp_receive: RTO 4 (2000 milliseconds) tcp_output: nothing to send (0x00000000) tcp_output: snd_wnd 63908, cwnd 23635, wnd 23635, seg == NULL, ack 45406 tcp_slowtmr: processing active pcb tcp_slowtmr: polling application tcp_output: nothing to send (0x00000000) tcp_output: snd_wnd 63908, cwnd 23635, wnd 23635, seg == NULL, ack 45406 tcp_write(pcb=0x008449f8, data=0x0083b204, len=332, apiflags=0) tcp_write: queuelen: 0 tcp_write: queueing 45406:45738 tcp_write: 2 (after enqueued) tcp_output: snd_wnd 63908, cwnd 23635, wnd 23635, effwnd 332, seq 45406, ack 45406 tcp_output: snd_wnd 63908, cwnd 23635, wnd 23635, effwnd 332, seq 45406, ack 45406, i 0 tcp_output_segment: rtseq 45406 tcp_output_segment: 45406:45738 tcp_output: nothing to send (0x00000000) tcp_output: snd_wnd 63908, cwnd 23635, wnd 23635, seg == NULL, ack 45406 tcp_slowtmr: processing active pcb tcp_slowtmr: polling application tcp_output: nothing to send (0x00000000) tcp_output: snd_wnd 63908, cwnd 23635, wnd 23635, seg == NULL, ack 45406 tcp_receive: window update 63576 tcp_receive: congestion avoidance cwnd 23725 tcp_receive: queuelen 2 ... 0 (after freeing unacked) tcp_receive: pcb->rttest 475 rtseq 45406 ackno 45738 tcp_receive: experienced rtt 1 ticks (500 msec). tcp_receive: RTO 4 (2000 milliseconds) tcp_output: nothing to send (0x00000000) tcp_output: snd_wnd 63576, cwnd 23725, wnd 23725, seg == NULL, ack 45738 tcp_slowtmr: processing active pcb tcp_slowtmr: polling application tcp_output: nothing to send (0x00000000) tcp_output: snd_wnd 63576, cwnd 23725, wnd 23725, seg == NULL, ack 45738 tcp_write(pcb=0x008449f8, data=0x0083b350, len=332, apiflags=0) tcp_write: queuelen: 0 tcp_write: queueing 45738:46070 tcp_write: 2 (after enqueued) tcp_output: snd_wnd 63576, cwnd 23725, wnd 23725, effwnd 332, seq 45738, ack 45738 tcp_output: snd_wnd 63576, cwnd 23725, wnd 23725, effwnd 332, seq 45738, ack 45738, i 0 tcp_output_segment: rtseq 45738 tcp_output_segment: 45738:46070 tcp_output: nothing to send (0x00000000) tcp_output: snd_wnd 63576, cwnd 23725, wnd 23725, seg == NULL, ack 45738 tcp_slowtmr: processing active pcb tcp_slowtmr: polling application tcp_output: nothing to send (0x00000000) tcp_output: snd_wnd 63576, cwnd 23725, wnd 23725, seg == NULL, ack 45738 tcp_receive: window update 63244 tcp_receive: congestion avoidance cwnd 23814 tcp_receive: queuelen 2 ... 0 (after freeing unacked) tcp_receive: pcb->rttest 477 rtseq 45738 ackno 46070 tcp_receive: experienced rtt 1 ticks (500 msec). tcp_receive: RTO 4 (2000 milliseconds) tcp_output: nothing to send (0x00000000) tcp_output: snd_wnd 63244, cwnd 23814, wnd 23814, seg == NULL, ack 46070 tcp_slowtmr: processing active pcb tcp_slowtmr: polling application tcp_output: nothing to send (0x00000000) tcp_output: snd_wnd 63244, cwnd 23814, wnd 23814, seg == NULL, ack 46070 tcp_write(pcb=0x008449f8, data=0x0083b49c, len=332, apiflags=0) tcp_write: queuelen: 0 tcp_write: queueing 46070:46402 tcp_write: 2 (after enqueued) tcp_output: snd_wnd 63244, cwnd 23814, wnd 23814, effwnd 332, seq 46070, ack 46070 tcp_output: snd_wnd 63244, cwnd 23814, wnd 23814, effwnd 332, seq 46070, ack 46070, i 0 tcp_output_segment: rtseq 46070 tcp_output_segment: 46070:46402 tcp_output: nothing to send (0x00000000) tcp_output: snd_wnd 63244, cwnd 23814, wnd 23814, seg == NULL, ack 46070 tcp_slowtmr: processing active pcb tcp_slowtmr: polling application tcp_output: nothing to send (0x00000000) tcp_output: snd_wnd 63244, cwnd 23814, wnd 23814, seg == NULL, ack 46070 tcp_slowtmr: processing active pcb tcp_slowtmr: polling application tcp_output: nothing to send (0x00000000) tcp_output: snd_wnd 63244, cwnd 23814, wnd 23814, seg == NULL, ack 46070 tcp_write(pcb=0x008449f8, data=0x0083b5e8, len=332, apiflags=0) tcp_write: queuelen: 2 tcp_write: queueing 46402:46734 tcp_write: 4 (after enqueued) tcp_output: snd_wnd 63244, cwnd 23814, wnd 23814, effwnd 664, seq 46402, ack 46070 tcp_output: snd_wnd 63244, cwnd 23814, wnd 23814, effwnd 664, seq 46402, ack 46070, i 0 tcp_output_segment: 46402:46734 tcp_output: nothing to send (0x00000000) tcp_output: snd_wnd 63244, cwnd 23814, wnd 23814, seg == NULL, ack 46070 tcp_slowtmr: processing active pcb tcp_slowtmr: polling application tcp_output: nothing to send (0x00000000) tcp_output: snd_wnd 63244, cwnd 23814, wnd 23814, seg == NULL, ack 46070 tcp_slowtmr: processing active pcb tcp_slowtmr: rtime 4 pcb->rto 4 tcp_slowtmr: cwnd 1460 ssthresh 11907 tcp_output: snd_wnd 63244, cwnd 1460, wnd 1460, effwnd 332, seq 46070, ack 46070 tcp_output: snd_wnd 63244, cwnd 1460, wnd 1460, effwnd 332, seq 46070, ack 46070, i 0 tcp_output_segment: rtseq 46070 tcp_output_segment: 46070:46402 tcp_output: snd_wnd 63244, cwnd 1460, wnd 1460, effwnd 664, seq 46402, ack 46070, i 1 tcp_output_segment: 46402:46734 tcp_slowtmr: polling application tcp_output: nothing to send (0x00000000) tcp_output: snd_wnd 63244, cwnd 1460, wnd 1460, seg == NULL, ack 46070 tcp_write(pcb=0x008449f8, data=0x0083b734, len=332, apiflags=0) tcp_write: queuelen: 4 tcp_write: queueing 46734:47066 tcp_write: 6 (after enqueued) tcp_output: snd_wnd 63244, cwnd 1460, wnd 1460, effwnd 996, seq 46734, ack 46070 tcp_output: snd_wnd 63244, cwnd 1460, wnd 1460, effwnd 996, seq 46734, ack 46070, i 0 tcp_output_segment: 46734:47066 tcp_output: nothing to send (0x00000000) tcp_output: snd_wnd 63244, cwnd 1460, wnd 1460, seg == NULL, ack 46070 tcp_slowtmr: processing active pcb tcp_slowtmr: polling application tcp_output: nothing to send (0x00000000) tcp_output: snd_wnd 63244, cwnd 1460, wnd 1460, seg == NULL, ack 46070 tcp_slowtmr: processing active pcb tcp_slowtmr: polling application tcp_output: nothing to send (0x00000000) tcp_output: snd_wnd 63244, cwnd 1460, wnd 1460, seg == NULL, ack 46070 Oh, and do you have TCP_OVERSIZE enabled? I recall the early versions having bugs, although I'm not sure they could result in the behaviour you're seeing... Yes! #define TCP_OVERSIZE TCP_MSS #define TCP_MSS (1460) I'll set it to 0 and test again. I can understand that! The step from 1.4.1 to 2.0.x is a large one. On the other hand, 2.0.2 really has many bugs fixed, so it'll definitively be the more stable version. But release tests are always required, of course. The step is huge but *all good* - we will be moving to 2.0.2. I've kept up on and off with the updates and changes. I wanted to update but I hung on to the "it ain't broke" philosophy, especially going from one product to 9. It's hard to update because all customers are in production. It's very hard to test in-house real-world. So we have to roll out slowly to "tolerant" customers. Thanks Simon, Bill
_______________________________________________ lwip-users mailing list lwip-users@nongnu.org https://lists.nongnu.org/mailman/listinfo/lwip-users
