Modbus fixture is swamped by load within one test run (was: degrades after weeks of uptime) #909

Closed
opened 2026-11-13 08:33:05 -05:00 by dohertj2 · 2 comments
Owner

Found during the #615 G2 full-suite run (2026-11-13, master 16ddddb2).

otopcua-pymodbus-standard (otopcua-pymodbus:3.13.0, 10.100.0.35:5020, up since 2026-10-22) still accepted connections, but it answered late:

  • Its log showed asyncio slow-callback warnings ("took 0.146 seconds").
  • It logged thousands of ERROR transport:378 Cancel send, because not connected! lines (8,839 in 6 minutes): each reply was sent after the client had already timed out.

Effect: 8 of the 12 runnable Driver.Modbus.IntegrationTests failed with BadCommunicationError (0x80050000), null reads, or a connect timeout. DL205 smoke, AddressingGrammar ×3 and CommsRecovery ×4 failed, in the full run and again when the project ran alone.

docker restart otopcua-pymodbus-standard fixed it: 12/12 passed immediately.

Follow-up options:

  • a compose healthcheck that issues a real FC3 read with a deadline, plus restart: unless-stopped / autoheal;
  • or a scheduled restart.

Also consider lowering the fixture's log level: the per-frame recv/send debug lines are themselves a lot of output.

Found during the #615 G2 full-suite run (2026-11-13, master `16ddddb2`). `otopcua-pymodbus-standard` (`otopcua-pymodbus:3.13.0`, `10.100.0.35:5020`, up since 2026-10-22) still accepted connections, but it answered late: - Its log showed asyncio slow-callback warnings ("took 0.146 seconds"). - It logged thousands of `ERROR transport:378 Cancel send, because not connected!` lines (8,839 in 6 minutes): each reply was sent after the client had already timed out. Effect: 8 of the 12 runnable `Driver.Modbus.IntegrationTests` failed with `BadCommunicationError` (0x80050000), null reads, or a connect timeout. DL205 smoke, AddressingGrammar ×3 and CommsRecovery ×4 failed, in the full run and again when the project ran alone. `docker restart otopcua-pymodbus-standard` fixed it: 12/12 passed immediately. Follow-up options: - a compose healthcheck that issues a real FC3 read with a deadline, plus `restart: unless-stopped` / autoheal; - or a scheduled restart. Also consider lowering the fixture's log level: the per-frame `recv`/`send` debug lines are themselves a lot of output.
dohertj2 added the type:infrapriority:p3 labels 2026-11-13 08:33:05 -05:00
Author
Owner

Update: this is not uptime, it is load. The fixture wedges within a single test run:

  • Full suite (f416b883), 19 min after a restart: the simulator was swamped again. DriverProbeHandshakeE2eTests.Modbus_Green_AgainstModbusSim failed with "Probe timed out after 10s" and the Modbus suite failed 8/12.
  • Restart, then Host.IntegrationTests alone: 350/350 passed, Modbus probe included. Right after it, the Modbus suite failed 8/12 again.
  • Restart, then the Modbus suite alone: 12/12 pass.

With no client connected, the simulator keeps logging recv frames for a while. It is working through a backlog: replies go out after the clients' 2 s deadline, hence Cancel send, because not connected!. It also logs asyncio _accept_connection … took 0.1–0.4 s.

The compose command runs pymodbus.simulator with no log argument and every frame is logged, so the per-frame debug logging is a likely multiplier. Try --log info (or the simulator's equivalent) and an FC3-read healthcheck. CommsRecoveryTests also connects repeatedly, which is a likely load source. Until fixed, the Modbus wire tests are order-dependent inside a full run.

**Update: this is not uptime, it is load.** The fixture wedges within a single test run: - **Full suite (`f416b883`), 19 min after a restart:** the simulator was swamped again. `DriverProbeHandshakeE2eTests.Modbus_Green_AgainstModbusSim` failed with "Probe timed out after 10s" and the Modbus suite failed 8/12. - **Restart, then `Host.IntegrationTests` alone:** 350/350 passed, Modbus probe included. Right after it, the Modbus suite failed 8/12 again. - **Restart, then the Modbus suite alone:** 12/12 pass. With no client connected, the simulator keeps logging `recv` frames for a while. It is working through a backlog: replies go out after the clients' 2 s deadline, hence `Cancel send, because not connected!`. It also logs asyncio `_accept_connection … took 0.1–0.4 s`. The compose `command` runs `pymodbus.simulator` with no log argument and every frame is logged, so the per-frame debug logging is a likely multiplier. Try `--log info` (or the simulator's equivalent) and an FC3-read healthcheck. `CommsRecoveryTests` also connects repeatedly, which is a likely load source. Until fixed, the Modbus wire tests are order-dependent inside a full run.
dohertj2 changed title from Modbus fixture otopcua-pymodbus-standard degrades after weeks of uptime: 8 integration tests fail BadCommunicationError until restarted to Modbus fixture is swamped by load within one test run (was: degrades after weeks of uptime) 2026-11-13 08:58:01 -05:00
Author
Owner

Fixed in fc08892e (merged 79371402). Root cause: pymodbus 3.13 hardcodes asyncio debug=True in its simulator main, ~10x throughput loss (100 clients: ~150 req/s debug vs ~2,400 req/s off). docker-dev's 98 int3b connections (~220 req/s) already exceeded the debug-mode ceiling. Fixture now launches via run_simulator.py (debug off) with an FC03 healthcheck, in-container watchdog, restart: unless-stopped, log rotation; deployed to /opt/otopcua-modbus. 10/10 runs 12/12 incl. 5 under ~10x load. The 49 int3b-* drivers in the docker-dev ConfigDb were also disabled (deploy 300fc98a); re-enable for gate D.

Fixed in fc08892e (merged 79371402). Root cause: pymodbus 3.13 hardcodes asyncio debug=True in its simulator main, ~10x throughput loss (100 clients: ~150 req/s debug vs ~2,400 req/s off). docker-dev's 98 int3b connections (~220 req/s) already exceeded the debug-mode ceiling. Fixture now launches via run_simulator.py (debug off) with an FC03 healthcheck, in-container watchdog, restart: unless-stopped, log rotation; deployed to /opt/otopcua-modbus. 10/10 runs 12/12 incl. 5 under ~10x load. The 49 int3b-* drivers in the docker-dev ConfigDb were also disabled (deploy 300fc98a); re-enable for gate D.
Sign in to join this conversation.
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: dohertj2/lmxopcua#909