@@ -12,6 +12,20 @@ def _ack_data(address1, address2, sequence):
1212 return RadioPacket (address1 , RadioPacketType .ACK , sequence ,
1313 struct .pack (">I" , address2 ))
1414
15+ class MessageExchange :
16+ def __init__ (self ):
17+ self .unique_packets = 0
18+ self .repeated_sends = 0
19+ self .receive_timeouts = 0
20+ self .repeated_receives = 0
21+ self .protocol_errors = 0
22+ self .bad_packets = 0
23+ self .radio_errors = 0
24+ self .successful = False
25+ self .queued = 0
26+ self .started = 0
27+ self .ended = 0
28+
1529class PdmRadio :
1630 def __init__ (self , radio_address , msg_sequence = 0 , pkt_sequence = 0 , packet_radio = None ):
1731 self .radio_address = radio_address
@@ -44,6 +58,8 @@ def __init__(self, radio_address, msg_sequence=0, pkt_sequence=0, packet_radio=N
4458 self .pdm_message_address = None
4559 self .ack_address_override = None
4660
61+ self .stats = []
62+ self .current_exchange = MessageExchange ()
4763 self .radio_lock = RLock ()
4864 self .start ()
4965
@@ -67,6 +83,7 @@ def send_message_get_message(self, message,
6783 ack_address_override = None ,
6884 tx_power = None , double_take = False ,
6985 expect_critical_follow_up = False ):
86+ queued = time .time ()
7087 with self .radio_lock :
7188 if self .radio_thread is None :
7289 raise PacketRadioError ("Radio is stopped" )
@@ -86,8 +103,12 @@ def send_message_get_message(self, message,
86103
87104 self .response_received .wait ()
88105 self .response_received .clear ()
106+ self .current_exchange .queued = queued
107+
89108 if self .pod_message is None :
109+ self .current_exchange .successful = False
90110 raise self .response_exception
111+ self .current_exchange .successful = True
91112 return self .pod_message
92113
93114 def get_packet (self , timeout = 30000 ):
@@ -117,6 +138,9 @@ def _radio_loop(self):
117138 self ._disconnect ()
118139 break
119140
141+ self .current_exchange = MessageExchange ()
142+ self .current_exchange .started = time .time ()
143+
120144 try :
121145 self .pod_message = self ._send_and_get (self .pdm_message , self .pdm_message_address ,
122146 self .ack_address_override ,
@@ -127,18 +151,20 @@ def _radio_loop(self):
127151 self .pod_message = None
128152 self .response_exception = e
129153
130-
131154 if self .response_exception is None :
132155 ack_packet = self ._final_ack (self .ack_address_override , self .packet_sequence )
156+ self .current_exchange .ended = time .time ()
133157 self .response_received .set ()
134158 try :
135159 self ._send_packet (ack_packet , allow_premature_exit_after = 3.5 )
136160 except Exception as e :
137161 self .logger .exception ("Error during ending conversation, ignored." )
138162
139163 else :
164+ self .current_exchange .ended = time .time ()
140165 self .response_received .set ()
141166
167+
142168 def _interim_ack (self , ack_address_override , sequence ):
143169 if ack_address_override is None :
144170 return _ack_data (self .radio_address , self .radio_address , sequence )
@@ -202,6 +228,8 @@ def _send_and_get(self, pdm_message, pdm_message_address, ack_address_override=N
202228 received = None
203229 packet_count = len (packets )
204230
231+ self .current_exchange .unique_packets = packet_count * 2
232+
205233 for part in range (0 , packet_count ):
206234 packet = packets [part ]
207235 repeat_count = - 1
@@ -266,6 +294,7 @@ def _send_and_get(self, pdm_message, pdm_message_address, ack_address_override=N
266294 raise
267295 except PacketRadioError :
268296 self .logger .debug ("Trying to recover from radio error" )
297+ self .current_exchange .radio_errors += 1
269298 if part == 0 :
270299 if repeat_count < 2 :
271300 self ._radio_init ()
@@ -303,8 +332,11 @@ def _send_and_get(self, pdm_message, pdm_message_address, ack_address_override=N
303332 self ._reset_sequences ()
304333 raise
305334 except ProtocolError :
306- if part == 0 and repeat_count == 0 :
335+ if expected_type == RadioPacketType . POD and received . type == RadioPacketType . ACK :
307336 self .logger .debug ("Trying to recover from protocol error" )
337+ self .packet_sequence = (received .sequence + 1 ) % 32
338+ packet = self ._interim_ack (ack_address_override = self .ack_address_override ,
339+ sequence = self .packet_sequence )
308340 continue
309341 else :
310342 raise
@@ -314,6 +346,7 @@ def _send_and_get(self, pdm_message, pdm_message_address, ack_address_override=N
314346
315347
316348 self .packet_logger .info ("SENT MSG %s" % pdm_message )
349+ part_count = 0
317350 if received .type == RadioPacketType .POD :
318351 part_count = 1
319352 self .logger .debug ("Received POD message part %d." % part_count )
@@ -333,7 +366,12 @@ def _send_and_get(self, pdm_message, pdm_message_address, ack_address_override=N
333366
334367 def _exchange_packets (self , packet_to_send , expected_type , timeout = 10 ):
335368 start_time = None
369+ first = True
336370 while start_time is None or time .time () - start_time < timeout :
371+ if first :
372+ first = False
373+ else :
374+ self .current_exchange .repeated_sends += 1
337375 if self .last_packet_timestamp is None or time .time () - self .last_packet_timestamp > 4 :
338376 received = self .packet_radio .send_and_receive_packet (packet_to_send .get_data (), 0 , 0 , 300 , 1 , 300 )
339377 else :
@@ -344,17 +382,20 @@ def _exchange_packets(self, packet_to_send, expected_type, timeout=10):
344382 self .packet_logger .info ("SEND PKT %s" % packet_to_send )
345383
346384 if received is None :
385+ self .current_exchange .receive_timeouts += 1
347386 self .packet_logger .debug ("RECV PKT None" )
348387 self .packet_radio .tx_up ()
349388 continue
350389 p , rssi = self ._get_packet (received )
351390 if p is None :
391+ self .current_exchange .bad_packets += 1
352392 self .packet_logger .debug ("RECV PKT BAD DATA: %s" % received .hex ())
353393 self .packet_radio .tx_down ()
354394 continue
355395
356396 self .packet_logger .info ("RECV PKT %s" % p )
357397 if p .address != self .radio_address :
398+ self .current_exchange .bad_packets += 1
358399 self .packet_logger .debug ("RECV PKT ADDR MISMATCH" )
359400 self .packet_radio .tx_down ()
360401 continue
@@ -364,6 +405,7 @@ def _exchange_packets(self, packet_to_send, expected_type, timeout=10):
364405 if self .last_packet_received is not None and \
365406 p .sequence == self .last_packet_received .sequence and \
366407 p .type == self .last_packet_received .type :
408+ self .current_exchange .repeated_receives += 1
367409 self .packet_logger .debug ("RECV PKT previous" )
368410 self .packet_radio .tx_up ()
369411 continue
@@ -373,19 +415,23 @@ def _exchange_packets(self, packet_to_send, expected_type, timeout=10):
373415
374416 if expected_type is not None and p .type != expected_type :
375417 self .packet_logger .debug ("RECV PKT unexpected type %s" % p )
418+ self .current_exchange .protocol_errors += 1
376419 raise ProtocolError ("Unexpected packet type received" )
377420
378421 if p .sequence != (packet_to_send .sequence + 1 ) % 32 :
379422 self .packet_sequence = (p .sequence + 1 ) % 32
380423 self .packet_logger .debug ("RECV PKT unexpected sequence %s" % p )
381424 self .last_packet_received = p
425+ self .current_exchange .protocol_errors += 1
382426 raise ProtocolError ("Incorrect packet sequence received" )
383427
384428 return p
429+
385430 raise OmnipyTimeoutError ("Exceeded timeout while send and receive" )
386431
387432 def _send_packet (self , packet_to_send , timeout = 25 , allow_premature_exit_after = None ):
388433 start_time = None
434+ self .current_exchange .unique_packets += 1
389435 while start_time is None or time .time () - start_time < timeout :
390436 try :
391437 self .packet_logger .info ("SEND PKT %s" % packet_to_send )
@@ -408,24 +454,28 @@ def _send_packet(self, packet_to_send, timeout=25, allow_premature_exit_after=No
408454 break
409455 p , rssi = self ._get_packet (received )
410456 if p is None :
457+ self .current_exchange .bad_packets += 1
411458 self .packet_logger .debug ("RECV PKT bad %s" % received .hex ())
412459 self .packet_radio .tx_down ()
413460 continue
414461
415462 if p .address != self .radio_address :
463+ self .current_exchange .bad_packets += 1
416464 self .packet_logger .debug ("RECV PKT ADDR MISMATCH" )
417465 self .packet_radio .tx_down ()
418466 continue
419467
420468 self .last_packet_timestamp = time .time ()
421469 if self .last_packet_received is not None :
470+ self .current_exchange .repeated_receives += 1
422471 if p .type == self .last_packet_received .type and p .sequence == self .last_packet_received .sequence :
423472 self .packet_logger .debug ("RECV PKT previous" )
424473 self .packet_radio .tx_up ()
425474 continue
426475
427476 self .packet_logger .info ("RECV PKT %s" % p )
428477 self .packet_logger .debug ("RECEIVED unexpected packet: %s" % p )
478+ self .current_exchange .protocol_errors = 1
429479 self .last_packet_received = p
430480 self .packet_sequence = (p .sequence + 1 ) % 32
431481 packet_to_send .with_sequence (self .packet_sequence )
@@ -434,6 +484,7 @@ def _send_packet(self, packet_to_send, timeout=25, allow_premature_exit_after=No
434484
435485
436486 except PacketRadioError :
487+ self .current_exchange .radio_errors += 1
437488 self .logger .exception ("Radio error during send and receive, retrying" )
438489 if not self ._radio_init (3 ):
439490 raise
0 commit comments