From 0b66ce059821920223e5e0c22b8f5b0a0e3fd154 Mon Sep 17 00:00:00 2001 From: kevin-tritz Date: Tue, 26 Mar 2024 22:14:07 -0400 Subject: [PATCH] replace time.monotonic with adafruit_ticks to preserve timing precision --- adafruit_wiznet5k/adafruit_wiznet5k.py | 17 ++++--- adafruit_wiznet5k/adafruit_wiznet5k_dhcp.py | 46 ++++++++++++------- adafruit_wiznet5k/adafruit_wiznet5k_dns.py | 6 ++- adafruit_wiznet5k/adafruit_wiznet5k_socket.py | 18 +++++--- requirements.txt | 1 + 5 files changed, 55 insertions(+), 33 deletions(-) diff --git a/adafruit_wiznet5k/adafruit_wiznet5k.py b/adafruit_wiznet5k/adafruit_wiznet5k.py index 9b43c76..5a66d4b 100644 --- a/adafruit_wiznet5k/adafruit_wiznet5k.py +++ b/adafruit_wiznet5k/adafruit_wiznet5k.py @@ -51,6 +51,7 @@ import time import gc from micropython import const +from adafruit_ticks import ticks_ms, ticks_diff from adafruit_bus_device.spi_device import SPIDevice import adafruit_wiznet5k.adafruit_wiznet5k_dhcp as dhcp @@ -249,8 +250,9 @@ def __init__( self.udp_from_port = [0] * self.max_sockets # Wait to give the Ethernet link to initialise. - stop_time = time.monotonic() + 5 - while time.monotonic() < stop_time: + start_time = ticks_ms() + timeout = 5000 + while ticks_diff(ticks_ms(), start_time) < timeout: if self.link_status: break debug_msg("Ethernet link is down…", self._debug) @@ -764,9 +766,10 @@ def socket_close(self, socket_num: int) -> None: self._sock_num_in_range(socket_num) self._write_sncr(socket_num, _CMD_SOCK_CLOSE) debug_msg(" Waiting for socket to close…", self._debug) - timeout = time.monotonic() + 5.0 + start = ticks_ms() + timeout = 5000 while self._read_snsr(socket_num) != SNSR_SOCK_CLOSED: - if time.monotonic() > timeout: + if ticks_diff(ticks_ms(), start) > timeout: raise RuntimeError( "Wiznet5k failed to close socket, status = {}.".format( self._read_snsr(socket_num) @@ -889,7 +892,7 @@ def socket_write( bytes_to_write = _SOCK_SIZE else: bytes_to_write = len(buffer) - stop_time = time.monotonic() + timeout + start_time = ticks_ms() # If buffer is available, start the transfer free_size = self._get_tx_free_size(socket_num) @@ -897,7 +900,7 @@ def socket_write( free_size = self._get_tx_free_size(socket_num) status = self.socket_status(socket_num) if status not in (SNSR_SOCK_ESTABLISHED, SNSR_SOCK_CLOSE_WAIT) or ( - timeout and time.monotonic() > stop_time + timeout and ticks_diff(ticks_ms(), start_time) / 1000 > timeout ): raise RuntimeError("Unable to write data to the socket.") @@ -920,7 +923,7 @@ def socket_write( _SNSR_SOCK_CLOSING, ): raise RuntimeError("No data was sent, socket was closed.") - if timeout and time.monotonic() > stop_time: + if timeout and ticks_diff(ticks_ms(), start_time) / 1000 > timeout: raise RuntimeError("Operation timed out. No data sent.") if self.read_snir(socket_num) & SNIR_TIMEOUT: self.write_snir(socket_num, SNIR_TIMEOUT) diff --git a/adafruit_wiznet5k/adafruit_wiznet5k_dhcp.py b/adafruit_wiznet5k/adafruit_wiznet5k_dhcp.py index b4ff581..27261e1 100644 --- a/adafruit_wiznet5k/adafruit_wiznet5k_dhcp.py +++ b/adafruit_wiznet5k/adafruit_wiznet5k_dhcp.py @@ -29,6 +29,7 @@ import time from random import randint from micropython import const +from adafruit_ticks import ticks_ms, ticks_diff, ticks_add from adafruit_wiznet5k.adafruit_wiznet5k_debug import ( # pylint: disable=ungrouped-imports debug_msg, ) @@ -152,6 +153,7 @@ def __init__( self._dhcp_state = _STATE_INIT self._transaction_id = randint(1, 0x7FFFFFFF) self._start_time = 0.0 + self._start_ticks = 0 self._blocking = False self._renew = None @@ -209,13 +211,14 @@ def _dsm_reset(self) -> None: self._renew = None self._increment_transaction_id() self._start_time = time.monotonic() + self._start_ticks = ticks_ms() def _increment_transaction_id(self) -> None: """Increment the transaction ID and roll over from 0x7fffffff to 0.""" debug_msg("Incrementing transaction ID", self._debug) self._transaction_id = (self._transaction_id + 1) & 0x7FFFFFFF - def _next_retry_time(self, *, attempt: int, interval: int = 4) -> float: + def _next_retry_time(self, *, attempt: int, interval: int = 4) -> int: """Calculate a retry stop time. The interval is calculated as an exponential fallback with a random variation to @@ -227,7 +230,7 @@ def _next_retry_time(self, *, attempt: int, interval: int = 4) -> float: :param int interval: The base retry interval in seconds. Defaults to 4 as per the DHCP standard for Ethernet connections. Minimum value 2, defaults to 4. - :returns float: The timeout in time.monotonic() seconds. + :returns int: The timeout in ticks_ms milliseconds. :raises ValueError: If the interval is not > 1 second as this could return a zero or negative delay. @@ -235,10 +238,10 @@ def _next_retry_time(self, *, attempt: int, interval: int = 4) -> float: debug_msg("Calculating next retry time and incrementing retries.", self._debug) if interval <= 1: raise ValueError("Retry interval must be > 1 second.") - delay = 2**attempt * interval + randint(-1, 1) + time.monotonic() + delay = (2**attempt * interval + randint(-1, 1)) * 1000 return delay - def _receive_dhcp_response(self, socket_num: int, timeout: float) -> int: + def _receive_dhcp_response(self, socket_num: int, timeout: int) -> int: """ Receive data from the socket in response to a DHCP query. @@ -249,12 +252,13 @@ def _receive_dhcp_response(self, socket_num: int, timeout: float) -> int: maximum packet size is limited by the size of the global buffer. :param int socket_num: Socket to read from. - :param float timeout: time.monotonic at which attempt should time out. + :param int timeout: ticks_ms interval at which attempt should time out. :returns int: The number of bytes stored in the global buffer. """ debug_msg("Receiving a DHCP response.", self._debug) - while time.monotonic() < timeout: + start_time = ticks_ms() + while ticks_diff(ticks_ms(), start_time) < timeout: # DHCP returns the query plus additional data. The query length is 236 bytes. if self._eth.socket_available(socket_num, _SNMR_UDP) > 236: bytes_count, bytes_read = self._eth.read_udp(socket_num, _BUFF_LENGTH) @@ -285,9 +289,11 @@ def _process_messaging_states(self, *, message_type: int): self._dhcp_state = _STATE_INIT elif message_type == _DHCP_ACK: debug_msg("Message is ACK, setting FSM state to BOUND.", self._debug) - self._t1 = self._start_time + self._lease // 2 - self._t2 = self._start_time + self._lease - self._lease // 8 - self._lease += self._start_time + self._t1 = ticks_add(self._start_ticks, self._lease // 2) + self._t2 = ticks_diff( + ticks_add(self._start_ticks, self._lease), self._lease // 8 + ) + self._lease = ticks_add(self._lease, self._start_ticks) self._increment_transaction_id() if not self._renew: self._eth.ifconfig = ( @@ -330,13 +336,14 @@ def _handle_dhcp_message(self) -> int: else: dhcp_server = _BROADCAST_SERVER_ADDR sock_num = None - deadline = time.monotonic() + 5.0 + deadline = 5000 + start_time = ticks_ms() try: while sock_num is None: sock_num = self._eth.get_socket() if sock_num == 0xFF: sock_num = None - if time.monotonic() > deadline: + if ticks_diff(ticks_ms(), start_time) > deadline: raise RuntimeError("Unable to initialize UDP socket.") self._eth.src_port = 68 @@ -349,7 +356,8 @@ def _handle_dhcp_message(self) -> int: for attempt in range(4): # Initial attempt plus 3 retries. self._eth.socket_write(sock_num, _BUFF[:message_length]) next_resend = self._next_retry_time(attempt=attempt) - while time.monotonic() < next_resend: + start_time = ticks_ms() + while ticks_diff(ticks_ms(), start_time) < next_resend: if self._receive_dhcp_response(sock_num, next_resend): try: msg_type_in = self._parse_dhcp_response() @@ -382,17 +390,17 @@ def _dhcp_state_machine(self, *, blocking: bool = False) -> None: self._blocking = blocking while True: if self._dhcp_state == _STATE_BOUND: - now = time.monotonic() - if now < self._t1: + now = ticks_ms() + if ticks_diff(now, self._t1) < 0: debug_msg("No timers have expired. Exiting FSM.", self._debug) return - if now > self._lease: + if ticks_diff(now, self._lease) > 0: debug_msg( "Lease has expired, switching state to INIT.", self._debug ) self._blocking = True self._dhcp_state = _STATE_INIT - elif now > self._t2: + elif ticks_diff(now, self._t2) > 0: debug_msg( "T2 has expired, switching state to REBINDING.", self._debug ) @@ -407,6 +415,7 @@ def _dhcp_state_machine(self, *, blocking: bool = False) -> None: debug_msg("FSM state is RENEWING.", self._debug) self._renew = "renew" self._start_time = time.monotonic() + self._start_ticks = ticks_ms() self._dhcp_state = _STATE_REQUESTING if self._dhcp_state == _STATE_REBINDING: @@ -414,6 +423,7 @@ def _dhcp_state_machine(self, *, blocking: bool = False) -> None: self._renew = "rebind" self.dhcp_server_ip = _BROADCAST_SERVER_ADDR self._start_time = time.monotonic() + self._start_ticks = ticks_ms() self._dhcp_state = _STATE_REQUESTING if self._dhcp_state == _STATE_INIT: @@ -486,7 +496,9 @@ def option_writer( # Transaction ID (xid) _BUFF[4:8] = self._transaction_id.to_bytes(4, "big") # Seconds elapsed - _BUFF[8:10] = int(time.monotonic() - self._start_time).to_bytes(2, "big") + _BUFF[8:10] = int(ticks_diff(ticks_ms(), self._start_ticks) / 1000).to_bytes( + 2, "big" + ) # Flags (only bit 0 is used, all other bits must be 0) if broadcast: _BUFF[10] = 0b10000000 diff --git a/adafruit_wiznet5k/adafruit_wiznet5k_dns.py b/adafruit_wiznet5k/adafruit_wiznet5k_dns.py index f014c68..ee5591c 100644 --- a/adafruit_wiznet5k/adafruit_wiznet5k_dns.py +++ b/adafruit_wiznet5k/adafruit_wiznet5k_dns.py @@ -26,6 +26,7 @@ import time from random import getrandbits from micropython import const +from adafruit_ticks import ticks_ms, ticks_diff _QUERY_FLAG = const(0x00) _OPCODE_STANDARD_QUERY = const(0x00) @@ -261,9 +262,10 @@ def gethostbyname(self, hostname: bytes) -> Union[int, bytes]: ipaddress = -1 for _ in range(5): # wait for a response - socket_timeout = time.monotonic() + 5.0 + socket_timeout = 5000 + start_time = ticks_ms() while not self._iface.socket_available(dns_socket, 0x02): - if time.monotonic() > socket_timeout: + if ticks_diff(ticks_ms(), start_time) > socket_timeout: _debug_print( debug=self._debug, message="* DNS ERROR: Did not receive DNS response (socket timeout).", diff --git a/adafruit_wiznet5k/adafruit_wiznet5k_socket.py b/adafruit_wiznet5k/adafruit_wiznet5k_socket.py index 5626592..e1832de 100644 --- a/adafruit_wiznet5k/adafruit_wiznet5k_socket.py +++ b/adafruit_wiznet5k/adafruit_wiznet5k_socket.py @@ -31,6 +31,7 @@ from micropython import const import adafruit_wiznet5k as wiznet5k +from adafruit_ticks import ticks_ms, ticks_diff # pylint: disable=invalid-name _the_interface: Optional[WIZNET5K] = None @@ -396,12 +397,15 @@ def accept( the connection, and address is the address bound to the socket on the other end of the connection. """ - stamp = time.monotonic() + stamp = ticks_ms() while self._status not in ( wiznet5k.adafruit_wiznet5k.SNSR_SOCK_SYNRECV, wiznet5k.adafruit_wiznet5k.SNSR_SOCK_ESTABLISHED, ): - if self._timeout and 0 < self._timeout < time.monotonic() - stamp: + if ( + self._timeout + and 0 < self._timeout < ticks_diff(ticks_ms(), stamp) / 1000 + ): raise TimeoutError("Failed to accept connection.") if self._status == wiznet5k.adafruit_wiznet5k.SNSR_SOCK_CLOSED: self.close() @@ -564,7 +568,7 @@ def recv_into(self, buffer: bytearray, nbytes: int = 0, flags: int = 0) -> int: if not 0 <= nbytes <= len(buffer): raise ValueError("nbytes must be 0 to len(buffer)") - last_read_time = time.monotonic() + last_read_time = ticks_ms() num_to_read = len(buffer) if nbytes == 0 else nbytes num_read = 0 while num_to_read > 0: @@ -583,7 +587,7 @@ def recv_into(self, buffer: bytearray, nbytes: int = 0, flags: int = 0) -> int: num_avail = self._available() if num_avail > 0: - last_read_time = time.monotonic() + last_read_time = ticks_ms() bytes_to_read = min(num_to_read, num_avail) if self._sock_type == SOCK_STREAM: bytes_read = _the_interface.socket_read( @@ -606,7 +610,7 @@ def recv_into(self, buffer: bytearray, nbytes: int = 0, flags: int = 0) -> int: if self._timeout == 0: # non-blocking mode break - if time.monotonic() - last_read_time > self._timeout: + if ticks_diff(ticks_ms(), last_read_time) / 1000 > self._timeout: raise timeout("timed out") return num_read @@ -644,7 +648,7 @@ def _readline(self) -> bytes: :return bytes: The data read from the socket. """ - stamp = time.monotonic() + stamp = ticks_ms() while b"\r\n" not in self._buffer: avail = self._available() if avail: @@ -655,7 +659,7 @@ def _readline(self) -> bytes: if ( self._timeout and not avail - and 0 < self._timeout < time.monotonic() - stamp + and 0 < self._timeout < ticks_diff(ticks_ms(), stamp) / 1000 ): self.close() raise RuntimeError("Didn't receive response, failing out...") diff --git a/requirements.txt b/requirements.txt index a45c547..6061ee9 100644 --- a/requirements.txt +++ b/requirements.txt @@ -4,3 +4,4 @@ Adafruit-Blinka adafruit-circuitpython-busdevice +adafruit-circuitpython-ticks