How can I debug latency in a UDP multicast request/reply?

I'm building a real-time wireless link between a PC base station and a dozen robots, each transmitting at 60Hz.

For testing I wrote a Python script that sends UDP multicast packets over my WiFi network. And then on another multicast group I have two ESP8266 sending replies. One sends at 60Hz to simulate the real set-up, and the other spams at 10 times that rate to simulate congestion from the other devices.

First I only looked at packet loss, which was kind of as expected. But then I started to look at round-trip time. I made my Python script write the current time, and made the "real" node echo them back. (spammer messages are ignored)

With the spammer node turned off I get 10ms round-trip, but with the spammer, it starts at 100ms and slowly grows to over a second.

How can I debug this issue?

I tried to use Wireshark, but since they are separate UDP streams with custom data in them, I could not figure out any sensible analysis.

I figured the packets probably get stuck in a queue somewhere, so some googling suggested you can look at the queue length with the following command. Sure, the queue is not empty, but if I turn the spammer node off, nothing much changes in the queue length, while round-trip drops back to 10ms.

netstat -c --udp -an
Proto Recv-Q Send-Q Local Address           Foreign Address         State      
udp    40256      0 0.0.0.0:8080            0.0.0.0:*   

I thought maybe my Python code is just too slow to handle 600 messages per second. Running on PyPy made absolutely no difference, so I'm a bit hesitant to write the whole thing in C. It has almost 2ms per packet to do almost nothing.

Base station code:

import socket
import struct
import sched, time
import threading

base_multicast = '239.255.0.34'
robot_multicast = '239.255.0.35'
port = 8080


sock = socket.socket(socket.AF_INET, socket.SOCK_DGRAM, socket.IPPROTO_UDP)
sock.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1)
sock.bind(('', port))

mreq = struct.pack("4sl", socket.inet_aton(robot_multicast), socket.INADDR_ANY)
sock.setsockopt(socket.IPPROTO_IP, socket.IP_ADD_MEMBERSHIP, mreq)

# schedule base station packets

send_sock = socket.socket(socket.AF_INET, socket.SOCK_DGRAM, socket.IPPROTO_UDP)
send_sock.setsockopt(socket.IPPROTO_IP, socket.IP_MULTICAST_TTL, 2)

rate = 1/60
#sock.settimeout(rate)

s = sched.scheduler(time.time, time.sleep)

def send(now):
    nxt = now+rate
    s.enterabs(nxt, 1, send, argument=(nxt,))

    tstr = struct.pack("d", time.time())
    send_sock.sendto(tstr, (base_multicast, port))
    print(".", end='')


s.enter(1, 1, send, argument=(time.time(),))

t = threading.Thread(target=s.run)
t.daemon = True
t.start()

start = time.time()
avg_dur = 0
avg_ping = 0
while True:
  try:
      data = sock.recv(10240)
  except socket.timeout:
      continue
  now = time.time()
  duration = now-start
  start = now
  avg_dur = 0.99*avg_dur + 0.01*duration

  try:
      (t,) = struct.unpack("d", data)
      ping = now-t
      avg_ping = 0.99*avg_ping + 0.01*ping
      print(len(data), 1/avg_dur, avg_ping)
  except struct.error: # spammer message
      pass

Robot node: (spammer is identical, except it sends replyPacket 10 times in a loop)

#include <ESP8266WiFi.h>
#include <WiFiUdp.h>

const char* ssid = "mywifi";
const char* password = "password";

IPAddress base_multicast(239, 255, 0, 34);
IPAddress robot_multicast(239, 255, 0, 35);

WiFiUDP Udp;
unsigned int port = 8080;  // local port to listen on
char incomingPacket[255];  // buffer for incoming packets
char  replyPacket[] = "Hi there! Got the message :-))))";  // a reply string to send back

int rate = 1000/60;
unsigned long mytime;
unsigned long count;

float avg_diff = 0;


void setup()
{
  Serial.begin(115200);
  Serial.println();

  Serial.printf("Connecting to %s ", ssid);
  WiFi.begin(ssid, password);
  while (WiFi.status() != WL_CONNECTED)
  {
    delay(500);
    Serial.print(".");
  }
  Serial.println(" connected");

  //Udp.begin(localUdpPort);
  Udp.beginMulticast(WiFi.localIP(), base_multicast, port);
  Serial.printf("Now listening at IP %s, UDP port %d\n", WiFi.localIP().toString().c_str(), port);

  mytime = millis();
}

void loop()
{
  int packetSize = Udp.parsePacket();
  if (packetSize)
  {
    // receive incoming UDP packets
    unsigned long diff = micros() - mytime;
    avg_diff = 0.9*avg_diff + 0.1*diff;
    mytime = micros();
    int rcv_rate = 1000000/avg_diff;
    Serial.println(rcv_rate);
    int len = Udp.read(incomingPacket, 255);
    delay(random(rate));
    //Serial.printf("UDP packet contents: %s\n", incomingPacket);
    Udp.beginPacketMulticast(robot_multicast, port, WiFi.localIP());
    Udp.write(incomingPacket, len);
    Udp.endPacket();
  }
}