[Error] Error while handling path request. The contained exception was: division by zero
Started by p1ld7a b2e101f8b8d8c776... ·
Hello all,
When running rnsd 1.4.0 locally, I frequently see the following error in the logs:
[Error] Error while handling path request. The contained exception was: division by zero
And today, I would like to know where it comes from... I did a small investigation.
The message seems to be emitted by Transport.path_request_handler() @ https://github.com/markqvist/Reticulum/blob/b2188ce9a746a35b770b10bea1b7ccbe93b4e198/RNS/Transport.py#L2996
The handler itself does not appear to contain any division that could cause a ZeroDivisionError. We need to dig deeper. The exception seems to originate from one of the functions called inside the handler and then bubble up to its broad try/except block.
The relevant call chain appears to be:
Transport.path_request_handler()
└── Transport.path_request()
└── Transport.request_path(..., recursive=True)
When a path is unknown and recursive path discovery is enabled, Transport.path_request() forwards the request to other interfaces:
Transport.request_path(
destination_hash,
on_interface=interface,
tag=tag,
recursive=True,
)
Inside Transport.request_path(), the recursive path-request rate limiting contains 2 possible divisions by 0:
tx_time = (
(len(path_request_data) + RNS.Reticulum.HEADER_MINSIZE) * 8
) / on_interface.bitrate
wait_time = tx_time / on_interface.announce_cap
This suggests that the error may occur when either:
on_interface.bitrate == 0
or:
on_interface.announce_cap == 0
The default values should normally be non-zero: the base interface bitrate defaults to 62500, and the global announce cap defaults to 2. It therefore seems possible that one particular interface implementation or configuration overrides one of these values with zero. None of these directive are modified in my local config either.
At this stage, this is still only the most likely explanation. It does not log the traceback, so the exact failing line is lost.
Logging the interface values immediately before the calculations in Transport.request_path() could identify the affected interface:
RNS.log(
f"Recursive path request on {on_interface}: "
f"bitrate={on_interface.bitrate}, "
f"announce_cap={on_interface.announce_cap}",
RNS.LOG_ERROR,
)
Has anyone else encountered this already ?
I would also be interested to know whether an interface can legitimately have a bitrate or announce cap of 0, or whether these values should be validated before the rate-limiting calculations.
p1ld7a wrote:
...
I would also be interested to know whether an interface can legitimately have a bitrate or announce cap of 0, or whether these values should be validated before the rate-limiting calculations.
Not really because 0 bitrate is below the minimum 5 bits per second for Reticulum
Hmm, that's an interesting one. Haven't seen that ever before, and I look at a lot of logs, lol :P I'm very curious to know what in your setup creates the conditions for causing that.
You can modify the code running locally, and in the relevant except block, just add:
RNS.trace_exception(e)
# And optionally, the interface
# parameter logging you mentioned
That should give a very clear idea about what is going on.
I did it, here's the result:
[Error] Error while handling path request. The contained exception was: division by zero
[Error] An unhandled <class 'ZeroDivisionError'> exception occurred: division by zero
[Error] Traceback (most recent call last):
File "/nix/store/y6z9s1z0crrvv74xvq6bhyfidk783w5j-python3.14-rns-1.4.1/lib/python3.14/site-packages/RNS/Transport.py", line 2988, in path_request_handler
Transport.path_request(destination_hash,
~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^
Transport.from_local_client(packet),
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
packet.receiving_interface,
^^^^^^^^^^^^^^^^^^^^^^^^^^^
requestor_transport_id = requesting_transport_instance,
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
tag=tag_bytes)
^^^^^^^^^^^^^^
File "/nix/store/y6z9s1z0crrvv74xvq6bhyfidk783w5j-python3.14-rns-1.4.1/lib/python3.14/site-packages/RNS/Transport.py", line 3137, in path_request
Transport.request_path(destination_hash, on_interface=interface, tag=tag, recursive=True)
~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/nix/store/y6z9s1z0crrvv74xvq6bhyfidk783w5j-python3.14-rns-1.4.1/lib/python3.14/site-packages/RNS/Transport.py", line 2892, in request_path
tx_time = ((len(path_request_data)+RNS.Reticulum.HEADER_MINSIZE)*8) / on_interface.bitrate
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^~~~~~~~~~~~~~~~~~~~~~
ZeroDivisionError: division by zero
Here's my RNS config file:
[reticulum]
enable_transport = true
share_instance = Yes
instance_name = x1c
discover_interfaces = true
autoconnect_discovered_interfaces = 10
panic_on_interface_error = true
[logging]
loglevel = 4
logtimestamps = no
[interfaces]
[[auto]]
type = AutoInterface
enabled = true
[[LoRa USB]]
type = RNodeInterface
enabled = false
discoverable = yes
port = /dev/ttyACM0
# Long fast
frequency = 869525000
bandwidth = 250000
spreadingfactor = 11
codingrate = 5
txpower = 22
[[RNode 471F]]
type = RNodeInterface
enabled = true
discoverable = yes
port = ble://C9:F8:4A:73:EC:BF
frequency = 869525000
bandwidth = 250000
txpower = 22
spreadingfactor = 11
codingrate = 5
[[RNode 268C]]
type = RNodeInterface
enabled = true
discoverable = yes
port = ble://FE:E7:AB:CA:47:C3
frequency = 869525000
bandwidth = 250000
spreadingfactor = 11
codingrate = 5
txpower = 22
[[RNode 9891]]
type = RNodeInterface
enabled = true
discoverable = yes
port = ble://D7:8D:59:02:38:78
frequency = 869525000
bandwidth = 250000
spreadingfactor = 11
codingrate = 5
txpower = 22
[[RNode 869C]]
type = RNodeInterface
enabled = true
discoverable = yes
port = ble://FD:BB:31:B8:36:B9
frequency = 869525000
bandwidth = 250000
spreadingfactor = 11
codingrate = 5
txpower = 22
[[RNode BF83]]
type = RNodeInterface
enabled = true
discoverable = yes
port = ble://E6:40:B8:04:EE:0E
frequency = 869525000
bandwidth = 250000
spreadingfactor = 11
codingrate = 5
txpower = 22
Let me know what kind of information you need, here's a few of them:
Python: 3.14.6
Dependencies:
- qrcode: version 8.2
- lxmf: version 1.0.1
- pyserial: version 3.5
- cffi: version 2.1.0
- rns: version 1.4.1
Let me know if you need anything else.
Thank you!
p1ld7a wrote:
I did it, here's the result:
[Error] Error while handling path request. The contained exception was: division by zero [Error] An unhandled <class 'ZeroDivisionError'> exception occurred: division by zero [Error] Traceback (most recent call last): File "/nix/store/y6z9s1z0crrvv74xvq6bhyfidk783w5j-python3.14-rns-1.4.1/lib/python3.14/site-packages/RNS/Transport.py", line 2988, in path_request_handler Transport.path_request(destination_hash, ~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^ Transport.from_local_client(packet), ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ packet.receiving_interface, ^^^^^^^^^^^^^^^^^^^^^^^^^^^ requestor_transport_id = requesting_transport_instance, ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ tag=tag_bytes) ^^^^^^^^^^^^^^ File "/nix/store/y6z9s1z0crrvv74xvq6bhyfidk783w5j-python3.14-rns-1.4.1/lib/python3.14/site-packages/RNS/Transport.py", line 3137, in path_request Transport.request_path(destination_hash, on_interface=interface, tag=tag, recursive=True) ~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/nix/store/y6z9s1z0crrvv74xvq6bhyfidk783w5j-python3.14-rns-1.4.1/lib/python3.14/site-packages/RNS/Transport.py", line 2892, in request_path tx_time = ((len(path_request_data)+RNS.Reticulum.HEADER_MINSIZE)*8) / on_interface.bitrate ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^~~~~~~~~~~~~~~~~~~~~~ ZeroDivisionError: division by zeroHere's my RNS config file:
[reticulum] enable_transport = true share_instance = Yes instance_name = x1c discover_interfaces = true autoconnect_discovered_interfaces = 10 panic_on_interface_error = true [logging] loglevel = 4 logtimestamps = no [interfaces] [[auto]] type = AutoInterface enabled = true [[LoRa USB]] type = RNodeInterface enabled = false discoverable = yes port = /dev/ttyACM0 # Long fast frequency = 869525000 bandwidth = 250000 spreadingfactor = 11 codingrate = 5 txpower = 22 [[RNode 471F]] type = RNodeInterface enabled = true discoverable = yes port = ble://C9:F8:4A:73:EC:BF frequency = 869525000 bandwidth = 250000 txpower = 22 spreadingfactor = 11 codingrate = 5 [[RNode 268C]] type = RNodeInterface enabled = true discoverable = yes port = ble://FE:E7:AB:CA:47:C3 frequency = 869525000 bandwidth = 250000 spreadingfactor = 11 codingrate = 5 txpower = 22 [[RNode 9891]] type = RNodeInterface enabled = true discoverable = yes port = ble://D7:8D:59:02:38:78 frequency = 869525000 bandwidth = 250000 spreadingfactor = 11 codingrate = 5 txpower = 22 [[RNode 869C]] type = RNodeInterface enabled = true discoverable = yes port = ble://FD:BB:31:B8:36:B9 frequency = 869525000 bandwidth = 250000 spreadingfactor = 11 codingrate = 5 txpower = 22 [[RNode BF83]] type = RNodeInterface enabled = true discoverable = yes port = ble://E6:40:B8:04:EE:0E frequency = 869525000 bandwidth = 250000 spreadingfactor = 11 codingrate = 5 txpower = 22Let me know what kind of information you need, here's a few of them:
Python: 3.14.6 Dependencies: - qrcode: version 8.2 - lxmf: version 1.0.1 - pyserial: version 3.5 - cffi: version 2.1.0 - rns: version 1.4.1Let me know if you need anything else.
Thank you!
RNodes initialize self.bitrate = 0 and only update after getting telemetry from the device. So offline/reconecting/partial init BLE Rnodes can remain at zero.
You've got a few on there so probably various ones you've tried over time, or conditionally available ones, yeah? That's probably it
I added a few more debugging information, especially in request_path():
[Error] Recursive path request on Shared Instance[rns/x1c]: bitrate=1000000000, announce_cap=2
[Error] Recursive path request on BackboneInterface[rns.not-a-number.io/192.168.2.116:4242]: bitrate=100000000, announce_cap=0.02
[Error] Recursive path request on AutoInterface[auto]: bitrate=10000000, announce_cap=0.02
[Error] Recursive path request on BackboneInterface[Dark Doodad 23/207.174.40.24:4242]: bitrate=5000000.0, announce_cap=0.02
[Error] Recursive path request on BackboneInterface[Mari El RNS/rns.lngserv.ru:4242]: bitrate=5000000.0, announce_cap=0.02
[Error] Recursive path request on BackboneInterface[Northern Ireland MySQL proxy/northernirelandreticulum.uk:3306]: bitrate=5000000.0, announce_cap=0.02
[Error] Recursive path request on BackboneInterface[DjVolSky TCP/rns.djvolsky.ydns.eu:4242]: bitrate=5000000.0, announce_cap=0.02
[Error] Recursive path request on BackboneInterface[rns.quacksradio.com/rns.quacksradio.com:4242]: bitrate=5000000.0, announce_cap=0.02
[Error] Recursive path request on BackboneInterface[Arg0net RNS-VPS Italy/82.223.44.241:4242]: bitrate=5000000.0, announce_cap=0.02
[Error] Recursive path request on BackboneInterface[CORE - Central Ohio Radio Enthusiasts/rns.core.radio:4242]: bitrate=5000000.0, announce_cap=0.02
[Error] Recursive path request on RNodeInterface[RNode 268C]: bitrate=1074.21875, announce_cap=0.02
[Error] Recursive path request on RNodeInterface[RNode 9891]: bitrate=1074.21875, announce_cap=0.02
[Error] Recursive path request on RNodeInterface[RNode 471F]: bitrate=1074.21875, announce_cap=0.02
[Error] Recursive path request on RNodeInterface[RNode 869C]: bitrate=0, announce_cap=0.02
[Error] Error while handling path request. The contained exception was: division by zero
[Error] An unhandled <class 'ZeroDivisionError'> exception occurred: division by zero
[Error] Traceback (most recent call last):
File "/nix/store/9f1k6sm3c1397hwns6chz5p393lv0hhf-python3.14-rns-1.4.1/lib/python3.14/site-packages/RNS/Transport.py", line 2995, in path_request_handler
Transport.path_request(destination_hash,
~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^
Transport.from_local_client(packet),
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
packet.receiving_interface,
^^^^^^^^^^^^^^^^^^^^^^^^^^^
requestor_transport_id = requesting_transport_instance,
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
tag=tag_bytes)
^^^^^^^^^^^^^^
File "/nix/store/9f1k6sm3c1397hwns6chz5p393lv0hhf-python3.14-rns-1.4.1/lib/python3.14/site-packages/RNS/Transport.py", line 3144, in path_request
Transport.request_path(destination_hash, on_interface=interface, tag=tag, recursive=True)
~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/nix/store/9f1k6sm3c1397hwns6chz5p393lv0hhf-python3.14-rns-1.4.1/lib/python3.14/site-packages/RNS/Transport.py", line 2899, in request_path
tx_time = ((len(path_request_data)+RNS.Reticulum.HEADER_MINSIZE)*8) / on_interface.bitrate
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^~~~~~~~~~~~~~~~~~~~~~
ZeroDivisionError: division by zero
[Notice] Opening BLE connection for RNodeInterface[RNode 869C]...
[Error] AutoInterface[auto] No multicast echoes received on wlan0. The networking hardware or a firewall may be blocking multicast traffic.
^C^C⏎
We notice:
[Error] Recursive path request on RNodeInterface[RNode 869C]: bitrate=0, announce_cap=0.02
This is the one causing the issue.
Those RNode are actually all valid, it's just that RNode 869C is out of reach at the moment.
Thinking out loud here but perhaps we could improve the path resolving mechanism by filtering out interfaces where bitrate is equal to 0 ?
Good debugging :)
Should be fixed now in 4760103aa660f3fdd628a8124875dda672a71ac9:
diff --git a/RNS/Transport.py b/RNS/Transport.py
index 6820572b..1453f78d 100755
--- a/RNS/Transport.py
+++ b/RNS/Transport.py
@@ -3126,6 +3126,7 @@ class Transport:
for interface in Transport.interfaces:
if search_mode_filter and not interface.mode in search_mode_filter: continue
+ if not interface.online: continue
if not interface == attached_interface:
if interface.should_egress_limit_pr():
RNS.log(f"Not sending recursive path request on {interface} due to active egress limiting", RNS.LOG_EXTREME) if RNS.sl(RNS.LOG_EXTREME) else None
Mark wrote:
Good debugging :)
Should be fixed now in
4760103aa660f3fdd628a8124875dda672a71ac9:diff --git a/RNS/Transport.py b/RNS/Transport.py index 6820572b..1453f78d 100755 --- a/RNS/Transport.py +++ b/RNS/Transport.py @@ -3126,6 +3126,7 @@ class Transport: for interface in Transport.interfaces: if search_mode_filter and not interface.mode in search_mode_filter: continue + if not interface.online: continue if not interface == attached_interface: if interface.should_egress_limit_pr(): RNS.log(f"Not sending recursive path request on {interface} due to active egress limiting", RNS.LOG_EXTREME) if RNS.sl(RNS.LOG_EXTREME) else None
Wow speedy fix!
Huh, on the web the diff addition gets rendered in a different font to the rest of the diff, making the indent appear incorrect.
Yeah, I did notice that indent weirdness on the web version, nomadnet works fine. I figured it would make sense anyway ;)
Thanks p1ld7a! If you tried out the fix on your system and it actually works, let me know - would be good with confirmation that it actually fixes it when the RNode is not connectable and startup (and if it goes down subsequently - but should only really occur if it can't be brought up on start).