TCP transactions taking progressively longer

Viewed 108

I have a piece of equipment I'm trying to talk to over TCP. It's quite simple, and the following (python) code is pretty much exactly what I want to do in practice.

What should happen is I send a packet to request the device change a setting, then it should receive an "operation complete packet" (which is just '1').

I've implemented the code below in C with the same result, so I'm confident it isn't a Python problem.

import numpy as np
import socket

sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)

# Set some values to send to the device
values = np.arange(0.2, 1.0, 0.02)

sock.connect(('192.168.1.147', 9221))

for value in values:
    # This string sets a value, then requests an operation complete output.
    sock.sendall('I1 %1.3f; *OPC?'.encode('utf-8') % (value, ))
    print(sock.recv(32)) # Prints out '1', or b'1\r\n' in python 3

What I actually experience is the output is the expected output but the delay between the sending and receiving gets progressively longer until I have to kill the program.

The resultant wireshark output is interesting:

No.     Time           Source                Destination           Protocol Length Info
      4 2.970271597    192.168.1.106         192.168.1.147         TCP      74     49938 → 9221 [SYN] Seq=0 Win=26880 Len=0 MSS=8960 SACK_PERM=1 TSval=26446953 TSecr=0 WS=128
      5 2.971102415    192.168.1.147         192.168.1.106         TCP      60     9221 → 49938 [SYN, ACK] Seq=0 Ack=1 Win=5840 Len=0 MSS=1460
      6 2.971118924    192.168.1.106         192.168.1.147         TCP      54     49938 → 9221 [ACK] Seq=1 Ack=1 Win=26880 Len=0
      7 2.971152591    192.168.1.106         192.168.1.147         TCP      69     49938 → 9221 [PSH, ACK] Seq=1 Ack=1 Win=26880 Len=15
      8 2.977589098    192.168.1.147         192.168.1.106         TCP      60     9221 → 49938 [PSH, ACK] Seq=1 Ack=1 Win=5840 Len=3
      9 2.977597172    192.168.1.106         192.168.1.147         TCP      54     49938 → 9221 [ACK] Seq=16 Ack=4 Win=26880 Len=0
     10 2.977948459    192.168.1.147         192.168.1.106         TCP      60     9221 → 49938 [ACK] Seq=1 Ack=16 Win=5840 Len=0
     11 2.977952056    192.168.1.106         192.168.1.147         TCP      54     [TCP Dup ACK 9#1] 49938 → 9221 [ACK] Seq=16 Ack=4 Win=26880 Len=0
     12 3.167593066    192.168.1.106         192.168.1.147         TCP      69     [TCP Spurious Retransmission] 49938 → 9221 [PSH, ACK] Seq=1 Ack=4 Win=26880 Len=15
     13 3.168475846    192.168.1.147         192.168.1.106         TCP      60     [TCP Dup ACK 10#1] 9221 → 49938 [ACK] Seq=4 Ack=16 Win=5840 Len=0
     14 3.168487149    192.168.1.106         192.168.1.147         TCP      69     49938 → 9221 [PSH, ACK] Seq=16 Ack=4 Win=26880 Len=15
     15 3.174457755    192.168.1.147         192.168.1.106         TCP      60     9221 → 49938 [PSH, ACK] Seq=4 Ack=16 Win=5840 Len=3
     16 3.174481722    192.168.1.106         192.168.1.147         TCP      54     49938 → 9221 [ACK] Seq=31 Ack=7 Win=26880 Len=0
     17 3.174817948    192.168.1.147         192.168.1.106         TCP      60     9221 → 49938 [ACK] Seq=4 Ack=31 Win=5840 Len=0
     18 3.567587105    192.168.1.106         192.168.1.147         TCP      69     [TCP Spurious Retransmission] 49938 → 9221 [PSH, ACK] Seq=16 Ack=7 Win=26880 Len=15
     19 3.568540028    192.168.1.147         192.168.1.106         TCP      60     [TCP Dup ACK 17#1] 9221 → 49938 [ACK] Seq=7 Ack=31 Win=5840 Len=0
     20 3.568551611    192.168.1.106         192.168.1.147         TCP      69     49938 → 9221 [PSH, ACK] Seq=31 Ack=7 Win=26880 Len=15
     21 3.574509787    192.168.1.147         192.168.1.106         TCP      60     9221 → 49938 [PSH, ACK] Seq=7 Ack=31 Win=5840 Len=3
     22 3.574533527    192.168.1.106         192.168.1.147         TCP      54     49938 → 9221 [ACK] Seq=46 Ack=10 Win=26880 Len=0
     23 3.574857577    192.168.1.147         192.168.1.106         TCP      60     9221 → 49938 [ACK] Seq=7 Ack=46 Win=5840 Len=0
     24 3.574870866    192.168.1.106         192.168.1.147         TCP      54     [TCP Dup ACK 22#1] 49938 → 9221 [ACK] Seq=46 Ack=10 Win=26880 Len=0
     25 4.367591502    192.168.1.106         192.168.1.147         TCP      69     [TCP Spurious Retransmission] 49938 → 9221 [PSH, ACK] Seq=31 Ack=10 Win=26880 Len=15
     26 4.368487116    192.168.1.147         192.168.1.106         TCP      60     [TCP Dup ACK 23#1] 9221 → 49938 [ACK] Seq=10 Ack=46 Win=5840 Len=0
     27 4.368498284    192.168.1.106         192.168.1.147         TCP      69     49938 → 9221 [PSH, ACK] Seq=46 Ack=10 Win=26880 Len=15
     28 4.374526599    192.168.1.147         192.168.1.106         TCP      60     9221 → 49938 [PSH, ACK] Seq=10 Ack=46 Win=5840 Len=3
     29 4.374558188    192.168.1.106         192.168.1.147         TCP      54     49938 → 9221 [ACK] Seq=61 Ack=13 Win=26880 Len=0
     30 4.374881659    192.168.1.147         192.168.1.106         TCP      60     9221 → 49938 [ACK] Seq=10 Ack=61 Win=5840 Len=0
     31 4.374896303    192.168.1.106         192.168.1.147         TCP      54     [TCP Dup ACK 29#1] 49938 → 9221 [ACK] Seq=61 Ack=13 Win=26880 Len=0
     32 5.971603454    192.168.1.106         192.168.1.147         TCP      69     [TCP Spurious Retransmission] 49938 → 9221 [PSH, ACK] Seq=46 Ack=13 Win=26880 Len=15
     33 5.972478351    192.168.1.147         192.168.1.106         TCP      60     [TCP Dup ACK 30#1] 9221 → 49938 [ACK] Seq=13 Ack=61 Win=5840 Len=0
     34 5.972490012    192.168.1.106         192.168.1.147         TCP      69     49938 → 9221 [PSH, ACK] Seq=61 Ack=13 Win=26880 Len=15
     35 5.978397699    192.168.1.147         192.168.1.106         TCP      60     9221 → 49938 [PSH, ACK] Seq=13 Ack=61 Win=5840 Len=3
     36 5.978418493    192.168.1.106         192.168.1.147         TCP      54     49938 → 9221 [ACK] Seq=76 Ack=16 Win=26880 Len=0
     37 5.978754841    192.168.1.147         192.168.1.106         TCP      60     9221 → 49938 [ACK] Seq=13 Ack=76 Win=5840 Len=0
     38 5.978768499    192.168.1.106         192.168.1.147         TCP      54     [TCP Dup ACK 36#1] 49938 → 9221 [ACK] Seq=76 Ack=16 Win=26880 Len=0
     43 7.134413907    192.168.1.106         192.168.1.147         TCP      69     49938 → 9221 [FIN, PSH, ACK] Seq=76 Ack=16 Win=26880 Len=15
     44 7.140478879    192.168.1.147         192.168.1.106         TCP      60     9221 → 49938 [PSH, ACK] Seq=16 Ack=76 Win=5840 Len=3
     45 7.140515226    192.168.1.106         192.168.1.147         TCP      54     49938 → 9221 [RST] Seq=76 Win=0 Len=0
     46 7.140822269    192.168.1.147         192.168.1.106         TCP      60     9221 → 49938 [ACK] Seq=16 Ack=91 Win=5840 Len=0
     47 7.140838249    192.168.1.106         192.168.1.147         TCP      54     49938 → 9221 [RST] Seq=91 Win=0 Len=0

(At which point I killed it)

What it suggests to me is that the ACK is being sent, but is being ignored for some reason (malformed in some way?). The original packet is then sent again with progressively longer delays (which I suspect is correct behaviour for lost packets), which results in the transmission buffer being backed up so the new packet is not being sent. Wireshark seems to think the resend is spurious as is demonstrated by the "Spurious Retransmission".

The device is responding to the packet as soon as it's sent the first time, which I can see from it's display.

It's possible there is some protocol incorrectness going on, but I don't know how to diagnose the problem. I'm happy for a work around to this - it's not production at this stage.

(FYI, the device is a TTi power supply).

1 Answers
Related