class BackgroundConsumer(object): """ A consumer that runs in the background. The BackgroundConsumer does not provide get() but does a callback to a function whenever a message was consumed. """ def __init__(self, cmd, cid, callback, send_to_passthrough=False): """ Create a background consumer using a cmd, cid and callback. :param cmd: the MasterCommand to consume. :param cid: the communication id. :param callback: function to call when an instance was found. :param send_to_passthrough: whether to send the command to the passthrough. """ self.cmd = cmd self.cid = cid self.callback = callback self.last_cmd_data = None # type: Optional[bytearray] # Keep the data of the last command. self.send_to_passthrough = send_to_passthrough self._queue = Queue() self._running = True self._callback_thread = BaseThread(name='masterdeliver', target=self._consumer) self._callback_thread.setDaemon(True) self._callback_thread.start() def get_prefix(self): # type: () -> bytearray """ Get the prefix of the answer from the master. """ return bytearray(self.cmd.output_action) + bytearray([self.cid]) def stop(self): self._running = False self._callback_thread.join() def _consumer(self): while self._running: try: self._consume() except Empty: pass except Exception: logger.exception('Unexpected exception delivering background consumer data') time.sleep(1) def _consume(self): self.callback(self._queue.get(block=True, timeout=0.25)) def consume(self, data, partial_result): # type: (bytearray, Optional[Result]) -> Tuple[int, Result, bool] """ Consume data. """ (bytes_consumed, last_result, done) = self.cmd.consume_output(data, partial_result) self.last_cmd_data = (self.get_prefix() + last_result.actual_bytes) if done else None return bytes_consumed, last_result, done def deliver(self, output): # type: (Result) -> None self._queue.put(output)
class PluginIPCReader(object): """ This class handles IPC communications. It uses a stream of msgpack encoded dict values. """ def __init__(self, stream, logger, command_receiver=None, name=None): # type: (IO[bytes], Callable[[str,Exception],None], Callable[[Dict[str,Any]],None],Optional[str]) -> None self._command_queue = Queue() self._unpacker = msgpack.Unpacker( stream, read_size=1, raw=False) # type: msgpack.Unpacker[Dict[str,Any]] self._read_thread = None # type: Optional[Thread] self._logger = logger self._running = False self._command_receiver = command_receiver self._name = name def start(self): # type: () -> None self._running = True self._read_thread = BaseThread(name='ipcread', target=self._read) self._read_thread.daemon = True self._read_thread.start() def stop(self): # type: () -> None self._running = False if self._read_thread is not None: self._read_thread.join() def _read(self): # type: () -> None while self._running: try: command = next(self._unpacker) if not isinstance(command, dict): raise ValueError('invalid value %s' % command) if self._command_receiver is not None: self._command_receiver(command) else: self._command_queue.put(command) except StopIteration as ex: self._logger('PluginIPCReader %s stopped' % self._name, ex) self._running = False except Exception as ex: self._logger('Unexpected read exception', ex) def get(self, block=True, timeout=None): return self._command_queue.get(block, timeout)
class CoreCommunicator(object): """ Uses a serial port to communicate with the Core and updates the output state. Provides methods to send CoreCommands. """ # Message constants. There are here for better code readability, you can't just simply change them START_OF_REQUEST = bytearray(b'STR') END_OF_REQUEST = bytearray(b'\r\n\r\n') START_OF_REPLY = bytearray(b'RTR') END_OF_REPLY = bytearray(b'\r\n') @Inject def __init__(self, controller_serial=INJECTED): # type: (Serial) -> None self._verbose = logger.level >= logging.DEBUG self._serial = controller_serial self._serial_write_lock = Lock() self._cid_lock = Lock() self._serial_bytes_written = 0 self._serial_bytes_read = 0 self._cid = None # type: Optional[int] # Reserved CIDs: 0 = Core events, 1 = uCAN transport, 2 = Slave transport self._cids_in_use = set() # type: Set[int] self._consumers = { } # type: Dict[int, List[Union[Consumer, BackgroundConsumer]]] self._last_success = 0.0 self._stop = False self._word_helper = WordField('') self._read_thread = None # type: Optional[BaseThread] self._command_total_histogram = Counter() # type: Counter self._command_success_histogram = Counter() # type: Counter self._command_timeout_histogram = Counter() # type: Counter self._communication_stats = { 'calls_succeeded': [], 'calls_timedout': [], 'bytes_written': 0, 'bytes_read': 0 } # type: Dict[str,Any] self._debug_buffer = { 'read': {}, 'write': {} } # type: Dict[str, Dict[float, bytearray]] self._debug_buffer_duration = 300 def start(self): """ Start the CoreComunicator, this starts the background read thread. """ self._stop = False self._read_thread = BaseThread(name='coreread', target=self._read) self._read_thread.setDaemon(True) self._read_thread.start() def stop(self): self._stop = True if self._read_thread is not None: self._read_thread.join() self._read_thread = None def get_communication_statistics(self): return self._communication_stats def reset_communication_statistics(self): self._communication_stats = { 'calls_succeeded': [], 'calls_timedout': [], 'bytes_written': 0, 'bytes_read': 0 } def get_command_histograms(self): return { 'total': dict(self._command_total_histogram), 'success': dict(self._command_success_histogram), 'timeout': dict(self._command_timeout_histogram) } def reset_command_histograms(self): self._command_total_histogram.clear() self._command_success_histogram.clear() self._command_timeout_histogram.clear() def get_debug_buffer(self): # type: () -> Dict[str,Dict[float,str]] def process(buffer): return {k: printable(v) for k, v in six.iteritems(buffer)} return { 'read': process(self._debug_buffer['read']), 'write': process(self._debug_buffer['write']) } def get_seconds_since_last_success(self): # type: () -> float """ Get the number of seconds since the last successful communication. """ if self._last_success == 0: return 0.0 # No communication - return 0 sec since last success else: return time.time() - self._last_success def _get_cid(self): # type: () -> int """ Get a communication id. 0 and 1 are reserved. """ def _increment_cid(current_cid): # type: (Optional[int]) -> int # Reserved CIDs: 0 = Core events, 1 = uCAN transport, 2 = Slave transport return current_cid + 1 if (current_cid is not None and current_cid < 255) else 3 def _available(candidate_cid): # type: (Optional[int]) -> bool if candidate_cid is None: return False if candidate_cid == self._cid: return False if candidate_cid in self._cids_in_use: return False return True with self._cid_lock: cid = self._cid # type: Optional[int] # Initial value while not _available(cid): cid = _increment_cid(cid) if cid == self._cid: # Seems there is no CID available at this moment raise RuntimeError('No available CID') if cid is None: # This is impossible due to `_available`, but mypy doesn't know that raise RuntimeError('CID should not be None') self._cid = cid self._cids_in_use.add(cid) return cid def _write_to_serial(self, data): # type: (bytearray) -> None """ Write data to the serial port. :param data: the data to write """ with self._serial_write_lock: if self._verbose: logger.debug('Writing to Core serial: {0}'.format( printable(data))) threshold = time.time() - self._debug_buffer_duration self._debug_buffer['write'][time.time()] = data for t in self._debug_buffer['write'].keys(): if t < threshold: del self._debug_buffer['write'][t] self._serial.write(data) self._serial_bytes_written += len(data) self._communication_stats['bytes_written'] += len(data) def register_consumer( self, consumer): # type: (Union[Consumer, BackgroundConsumer]) -> None """ Register a consumer :param consumer: The consumer to register. """ self._consumers.setdefault(consumer.get_hash(), []).append(consumer) def discard_cid(self, cid): # type: (int) -> None """ Discards a Command ID. """ with self._cid_lock: self._cids_in_use.discard(cid) def unregister_consumer( self, consumer): # type: (Union[Consumer, BackgroundConsumer]) -> None """ Unregister a consumer """ consumers = self._consumers.get(consumer.get_hash(), []) if consumer in consumers: consumers.remove(consumer) self.discard_cid(consumer.cid) def do_basic_action(self, action_type, action, device_nr=0, extra_parameter=0, timeout=2, log=True): # type: (int, int, int, int, Optional[int], bool) -> Optional[Dict[str, Any]] """ Sends a basic action to the Core with the given action type and action number """ if log: logger.info('BA: Execute {0} {1} {2} {3}'.format( action_type, action, device_nr, extra_parameter)) return self.do_command(CoreAPI.basic_action(), { 'type': action_type, 'action': action, 'device_nr': device_nr, 'extra_parameter': extra_parameter }, timeout=timeout) def do_command(self, command, fields, timeout=2): # type: (CoreCommandSpec, Dict[str, Any], Union[T_co, int]) -> Union[T_co, Dict[str, Any]] """ Send a command over the serial port and block until an answer is received. If the Core does not respond within the timeout period, a CommunicationTimedOutException is raised :param command: specification of the command to execute :param fields: A dictionary with the command input field values :param timeout: maximum allowed time before a CommunicationTimedOutException is raised """ cid = self._get_cid() consumer = Consumer(command, cid) command = consumer.command try: self._command_total_histogram.update({str(command.instruction): 1}) self._consumers.setdefault(consumer.get_hash(), []).append(consumer) self._send_command(cid, command, fields) except Exception: self.discard_cid(cid) raise try: result = None # type: Any if isinstance(consumer, Consumer) and timeout is not None: result = consumer.get(timeout) self._last_success = time.time() self._communication_stats['calls_succeeded'].append(time.time()) self._communication_stats[ 'calls_succeeded'] = self._communication_stats[ 'calls_succeeded'][-50:] self._command_success_histogram.update( {str(command.instruction): 1}) return result except CommunicationTimedOutException: self.unregister_consumer(consumer) self._communication_stats['calls_timedout'].append(time.time()) self._communication_stats[ 'calls_timedout'] = self._communication_stats[ 'calls_timedout'][-50:] self._command_timeout_histogram.update( {str(command.instruction): 1}) raise def _send_command( self, cid, command, fields): # type: (int, CoreCommandSpec, Dict[str, Any]) -> None """ Send a command over the serial port :param cid: The command ID :param command: The Core CommandSpec :param fields: A dictionary with the command input field values """ payload = command.create_request_payload(fields) checked_payload = (bytearray([cid]) + command.instruction + self._word_helper.encode(len(payload)) + payload) data = (CoreCommunicator.START_OF_REQUEST + checked_payload + bytearray(b'C') + CoreCommunicator._calculate_crc(checked_payload) + CoreCommunicator.END_OF_REQUEST) self._write_to_serial(data) @staticmethod def _calculate_crc(data): # type: (bytearray) -> bytearray """ Calculate the CRC of the data. :param data: Data for which to calculate the CRC :returns: CRC """ crc = 0 for byte in data: crc += byte return bytearray([crc % 256]) def _read(self): """ Code for the background read thread: reads from the serial port and forward certain messages to waiting consumers Request format: 'STR' + {CID, 1 byte} + {command, 2 bytes} + {length, 2 bytes} + {payload, `length` bytes} + 'C' + {checksum, 1 byte} + '\r\n\r\n' Response format: 'RTR' + {CID, 1 byte} + {command, 2 bytes} + {length, 2 bytes} + {payload, `length` bytes} + 'C' + {checksum, 1 byte} + '\r\n' """ data = bytearray() message_length = None header_fields = None header_length = len( CoreCommunicator.START_OF_REPLY ) + 1 + 2 + 2 # RTR + CID (1 byte) + command (2 bytes) + length (2 bytes) footer_length = 1 + 1 + len( CoreCommunicator.END_OF_REPLY) # 'C' + checksum (1 byte) + \r\n need_more_data = False while not self._stop: try: # Wait for data if more data is expected if need_more_data: readers, _, _ = select.select([self._serial], [], [], 1) if not readers: continue need_more_data = False # Read what's now on the serial port num_bytes = self._serial.inWaiting() if num_bytes > 0: data += self._serial.read(num_bytes) # Update counters self._serial_bytes_read += num_bytes self._communication_stats['bytes_read'] += num_bytes # Wait for the full message, or the header length min_length = message_length or header_length if len(data) < min_length: need_more_data = True continue if message_length is None: # Check if the data contains the START_OF_REPLY if CoreCommunicator.START_OF_REPLY not in data: need_more_data = True continue # Align with START_OF_REPLY if not data.startswith(CoreCommunicator.START_OF_REPLY): data = CoreCommunicator.START_OF_REPLY + data.split( CoreCommunicator.START_OF_REPLY, 1)[-1] if len(data) < header_length: continue header_fields = CoreCommunicator._parse_header(data) message_length = header_fields[ 'length'] + header_length + footer_length # If not all data is present, wait for more data if len(data) < message_length: continue message = data[:message_length] # type: bytearray data = data[message_length:] # A possible message is received, log where appropriate if self._verbose: logger.debug('Reading from Core serial: {0}'.format( printable(message))) threshold = time.time() - self._debug_buffer_duration self._debug_buffer['read'][time.time()] = message for t in self._debug_buffer['read'].keys(): if t < threshold: del self._debug_buffer['read'][t] # Validate message boundaries correct_boundaries = message.startswith( CoreCommunicator.START_OF_REPLY) and message.endswith( CoreCommunicator.END_OF_REPLY) if not correct_boundaries: logger.info('Unexpected boundaries: {0}'.format( printable(message))) # Reset, so we'll wait for the next RTR message_length = None data = message[ 3:] + data # Strip the START_OF_REPLY, and restore full data continue # Validate message CRC crc = bytearray([message[-3]]) payload = message[8:-4] # type: bytearray checked_payload = message[3:-4] # type: bytearray expected_crc = CoreCommunicator._calculate_crc(checked_payload) if crc != expected_crc: logger.info( 'Unexpected CRC ({0} vs expected {1}): {2}'.format( crc, expected_crc, printable(checked_payload))) # Reset, so we'll wait for the next RTR message_length = None data = message[ 3:] + data # Strip the START_OF_REPLY, and restore full data continue # A valid message is received, reliver it to the correct consumer consumers = self._consumers.get(header_fields['hash'], []) for consumer in consumers[:]: if self._verbose: logger.debug( 'Delivering payload to consumer {0}.{1}: {2}'. format(header_fields['command'], header_fields['cid'], printable(payload))) consumer.consume(payload) if isinstance(consumer, Consumer): self.unregister_consumer(consumer) self.discard_cid(header_fields['cid']) # Message processed, cleaning up message_length = None except Exception: logger.exception('Unexpected exception at Core read thread') data = bytearray() message_length = None @staticmethod def _parse_header( data): # type: (bytearray) -> Dict[str, Union[int, bytearray]] base = len(CoreCommunicator.START_OF_REPLY) return { 'cid': data[base], 'command': data[base + 1:base + 3], 'hash': Toolbox.hash(data[:base + 3]), 'length': struct.unpack('>H', data[base + 3:base + 5])[0] }
class PowerCommunicator(object): """ Uses a serial port to communicate with the power modules. """ @Inject def __init__(self, power_serial=INJECTED, power_store=INJECTED, pubsub=INJECTED, time_keeper_period=60, address_mode_timeout=300): # type: (RS485, PowerStore, PubSub, int, int) -> None """ Default constructor. :param power_serial: Serial port to communicate with :type power_serial: Instance of :class`RS485` :param verbose: Print all serial communication to stdout. """ self.__verbose = logger.level >= logging.DEBUG self.__serial = power_serial self.__serial_lock = RLock() self.__cid = 1 self.__address_mode = False self.__address_mode_stop = False self.__address_thread = None # type: Optional[Thread] self.__address_mode_timeout = address_mode_timeout self.__power_store = power_store self.__pubsub = pubsub self.__last_success = 0 # type: float if time_keeper_period != 0: self.__time_keeper = TimeKeeper( self, power_store, time_keeper_period) # type: Optional[TimeKeeper] else: self.__time_keeper = None self.__communication_stats_calls = { 'calls_succeeded': [], 'calls_timedout': [] } # type: Dict[str, List] self.__communication_stats_bytes = { 'bytes_written': 0, 'bytes_read': 0 } # type: Dict[str, int] self.__debug_buffer = { 'read': {}, 'write': {} } # type: Dict[str,Dict[float,str]] self.__debug_buffer_duration = 300 def start(self): # type: () -> None """ Start the power communicator. """ if self.__time_keeper is not None: self.__time_keeper.start() def stop(self): # type: () -> None if self.__time_keeper is not None: self.__time_keeper.stop() def get_communication_statistics(self): # type: () -> Dict[str, Any] ret = {} # type: Dict[str, Any] ret.update(self.__communication_stats_calls) ret.update(self.__communication_stats_bytes) return ret def reset_communication_statistics(self): # type: () -> None self.__communication_stats_calls = { 'calls_succeeded': [], 'calls_timedout': [] } self.__communication_stats_bytes = { 'bytes_written': 0, 'bytes_read': 0 } def get_communicator_health(self): # type: () -> HEALTH stats = self.get_communication_statistics() calls_timedout = [call for call in stats['calls_timedout']] calls_succeeded = [call for call in stats['calls_succeeded']] if len(calls_timedout) == 0: # If there are no timeouts at all return CommunicationStatus.SUCCESS all_calls = sorted(calls_timedout + calls_succeeded) if len(all_calls) <= 10: # Not enough calls made to have a decent view on what's going on logger.warning( 'Observed energy communication failures, but not enough calls') return CommunicationStatus.UNSTABLE if not any(t in calls_timedout for t in all_calls[-10:]): logger.warning( 'Observed energy communication failures, but recent calls recovered' ) # The last X calls are successfull return CommunicationStatus.UNSTABLE calls_last_x_minutes = [t for t in all_calls if t > time.time() - 180] if len(calls_last_x_minutes) <= 5: logger.warning( 'Observed energy communication failures, but not recent enough' ) # Not enough recent calls return CommunicationStatus.UNSTABLE ratio = len([t for t in calls_last_x_minutes if t in calls_timedout ]) / float(len(calls_last_x_minutes)) if ratio < 0.25: # Less than 25% of the calls fail, let's assume everything is just "fine" logger.warning( 'Observed energy communication failures, but there\'s only a failure ratio of {:.2f}%' .format(ratio * 100)) return CommunicationStatus.UNSTABLE else: return CommunicationStatus.FAILURE def get_debug_buffer(self): # type: () -> Dict[str, Dict[Any, Any]] return self.__debug_buffer def get_seconds_since_last_success(self): # type: () -> float """ Get the number of seconds since the last successful communication. """ if self.__last_success == 0: return 0 # No communication - return 0 sec since last success else: return time.time() - self.__last_success def __get_cid(self): # type: () -> int """ Get a communication id """ (ret, self.__cid) = (self.__cid, (self.__cid % 255) + 1) return ret def __debug(self, action, data): # type: (str, Optional[bytearray]) -> None if self.__verbose and data is not None: logger.debug("%.3f %s power: %s" % (time.time(), action, printable(data))) def __write_to_serial(self, data): # type: (bytearray) -> None """ Write data to the serial port. :param data: the data to write """ self.__debug('writing to', data) self.__serial.write(data) self.__communication_stats_bytes['bytes_written'] += len(data) threshold = time.time() - self.__debug_buffer_duration self.__debug_buffer['write'][time.time()] = printable(data) for t in self.__debug_buffer['write'].keys(): if t < threshold: del self.__debug_buffer['write'][t] def do_command(self, address, cmd, *data): # type: (int, PowerCommand, DataType) -> Tuple[Any, ...] """ Send a command over the serial port and block until an answer is received. If the power module does not respond within the timeout period, a CommunicationTimedOutException is raised. :param address: Address of the power module :type address: 2 bytes string :param cmd: the command to execute :param data: data for the command :raises: :class`CommunicationTimedOutException` if power module did not respond in time :raises: :class`InAddressModeException` if communicator is in address mode :returns: dict containing the output fields of the command """ if self.__address_mode: raise InAddressModeException() def do_once(_address, _cmd, *_data): # type: (int, PowerCommand, DataType) -> Tuple[Any, ...] """ Send the command once. """ try: cid = self.__get_cid() send_data = _cmd.create_input(_address, cid, *_data) self.__write_to_serial(send_data) if _address == power_api.BROADCAST_ADDRESS: self.__communication_stats_calls['calls_succeeded'].append( time.time()) self.__communication_stats_calls[ 'calls_succeeded'] = self.__communication_stats_calls[ 'calls_succeeded'][-50:] return () # No reply on broadcast messages ! else: tries = 0 while True: # In this loop we might receive data that didn't match the expected header. This might happen # if we for some reason had a timeout on the previous call, and we now read the response # to that call. In this case, we just re-try (up to 3 times), as the correct data might be # next in line. header, response_data = self.__read_from_serial() if not _cmd.check_header(header, _address, cid): if _cmd.is_nack( header, _address, cid) and response_data == bytearray([2]): raise UnkownCommandException('Unknown command') tries += 1 logger.warning( "Header did not match command ({0})".format( tries)) if tries == 3: raise Exception( "Header did not match command ({0})". format(tries)) else: break self.__last_success = time.time() return_data = _cmd.read_output(response_data) self.__communication_stats_calls['calls_succeeded'].append( time.time()) self.__communication_stats_calls[ 'calls_succeeded'] = self.__communication_stats_calls[ 'calls_succeeded'][-50:] return return_data except CommunicationTimedOutException: self.__communication_stats_calls['calls_timedout'].append( time.time()) self.__communication_stats_calls[ 'calls_timedout'] = self.__communication_stats_calls[ 'calls_timedout'][-50:] raise with self.__serial_lock: try: return do_once(address, cmd, *data) except UnkownCommandException: # This happens when the module is stuck in the bootloader. logger.error("Got UnkownCommandException") do_once(address, power_api.bootloader_jump_application()) time.sleep(1) return self.do_command(address, cmd, *data) except CommunicationTimedOutException: # Communication timed out, try again. return do_once(address, cmd, *data) except Exception as ex: logger.exception("Unexpected error: {0}".format(ex)) time.sleep(0.25) return do_once(address, cmd, *data) def start_address_mode(self): # type: () -> None """ Start address mode. :raises: :class`InAddressModeException` if communicator is in maintenance mode. """ if self.__address_mode: raise InAddressModeException() self.__address_mode = True self.__address_mode_stop = False with self.__serial_lock: self.__address_thread = BaseThread(name='poweraddressmode', target=self.__do_address_mode) self.__address_thread.daemon = True self.__address_thread.start() def __do_address_mode(self): # type: () -> None """ This code is running in a thread when in address mode. """ if self.__power_store is None: self.__address_mode = False self.__address_thread = None return expire = time.time() + self.__address_mode_timeout address_mode = power_api.set_addressmode(power_api.ENERGY_MODULE) address_mode_p1c = power_api.set_addressmode(power_api.P1_CONCENTRATOR) want_an_address_8 = power_api.want_an_address(power_api.POWER_MODULE) want_an_address_12 = power_api.want_an_address(power_api.ENERGY_MODULE) want_an_address_p1c = power_api.want_an_address( power_api.P1_CONCENTRATOR) set_address = power_api.set_address(power_api.ENERGY_MODULE) set_address_p1c = power_api.set_address(power_api.P1_CONCENTRATOR) # AGT start data = address_mode.create_input(power_api.BROADCAST_ADDRESS, self.__get_cid(), power_api.ADDRESS_MODE) self.__write_to_serial(data) data = address_mode_p1c.create_input(power_api.BROADCAST_ADDRESS, self.__get_cid(), power_api.ADDRESS_MODE) self.__write_to_serial(data) # Wait for WAA and answer. while not self.__address_mode_stop and time.time() < expire: try: header, data = self.__read_from_serial() if set_address.check_header_partial( header) or set_address_p1c.check_header_partial( header): continue version = None if want_an_address_8.check_header_partial(header): version = power_api.POWER_MODULE elif want_an_address_12.check_header_partial(header): version = power_api.ENERGY_MODULE elif want_an_address_p1c.check_header_partial(header): version = power_api.P1_CONCENTRATOR if version is None: logger.warning( "Received unexpected message in address mode") else: (old_address, cid) = (header[:2][1], header[2:3]) # Ask power_controller for new address, and register it. new_address = self.__power_store.get_free_address() if self.__power_store.module_exists(old_address): self.__power_store.readdress_power_module( old_address, new_address) else: self.__power_store.register_power_module( new_address, version) # Send new address to module if version == power_api.P1_CONCENTRATOR: address_data = set_address_p1c.create_input( old_address, ord(cid), new_address) else: # Both power- and energy module share the same API address_data = set_address.create_input( old_address, ord(cid), new_address) self.__write_to_serial(address_data) except CommunicationTimedOutException: pass # Didn't receive a command, no problem. except Exception as exception: logger.exception("Got exception in address mode: %s", exception) # AGT stop data = address_mode.create_input(power_api.BROADCAST_ADDRESS, self.__get_cid(), power_api.NORMAL_MODE) self.__write_to_serial(data) data = address_mode_p1c.create_input(power_api.BROADCAST_ADDRESS, self.__get_cid(), power_api.NORMAL_MODE) self.__write_to_serial(data) self.__address_mode = False def stop_address_mode(self): # type: () -> None """ Stop address mode. """ if not self.__address_mode: raise Exception("Not in address mode !") self.__address_mode_stop = True if self.__address_thread: self.__address_thread.join() self.__address_thread = None master_event = MasterEvent(MasterEvent.Types.POWER_ADDRESS_EXIT, {}) self.__pubsub.publish_master_event(PubSub.MasterTopics.POWER, master_event) def in_address_mode(self): # type: () -> bool """ Returns whether the PowerCommunicator is in address mode. """ return self.__address_mode def __read_from_serial(self): # type: () -> Tuple[bytearray, bytearray] """ Read a PowerCommand from the serial port. """ phase = 0 index = 0 header = bytearray() length = 0 data = bytearray() crc = 0 command = bytearray() try: while phase < 8: byte = self.__serial.read_queue.get(True, 0.25) command += byte self.__communication_stats_bytes['bytes_read'] += 1 if phase == 0: # Skip non 'R' bytes if byte == bytearray(b'R'): phase = 1 else: phase = 0 elif phase == 1: # Expect 'T' if byte == bytearray(b'T'): phase = 2 else: raise Exception("Unexpected character") elif phase == 2: # Expect 'R' if byte == bytearray(b'R'): phase = 3 index = 0 else: raise Exception("Unexpected character") elif phase == 3: # Read the header fields header += byte index += 1 if index == 8: length = ord(byte) if length > 0: phase = 4 index = 0 else: phase = 5 elif phase == 4: # Read the data data += byte index += 1 if index == length: phase = 5 elif phase == 5: # Read the CRC code crc = ord(byte) phase = 6 elif phase == 6: # Expect '\r' if byte == bytearray(b'\r'): phase = 7 else: raise Exception("Unexpected character") elif phase == 7: # Expect '\n' if byte == bytearray(b'\n'): phase = 8 else: raise Exception("Unexpected character") if PowerCommand.get_crc(header, data) != crc: raise Exception('CRC doesn\'t match') except Empty: raise CommunicationTimedOutException('Communication timed out') except Exception: self.__debug('reading from', command) raise finally: self.__debug('reading from', command) threshold = time.time() - self.__debug_buffer_duration self.__debug_buffer['read'][time.time()] = printable(command) for t in self.__debug_buffer['read'].keys(): if t < threshold: del self.__debug_buffer['read'][t] return header, data
class MaintenanceClassicCommunicator(MaintenanceCommunicator): """ The maintenance communicator handles maintenance communication with the Master """ MAINTENANCE_TIMEOUT = 600 @Inject def __init__(self, master_communicator=INJECTED, pubsub=INJECTED): # type: (MasterCommunicator, PubSub) -> None """ Construct a MaintenanceCommunicator. :param master_communicator: the communication with the master. :type master_communicator: master.master_communicator.MasterCommunicator """ self._master_communicator = master_communicator self._pubsub = pubsub self._deactivated_sent = False self._last_maintenance_send_time = 0.0 self._stopped = False self._maintenance_timeout_timer = None # type: Optional[Timer] self._read_data_thread = None # type: Optional[Thread] self._receiver_callback = None # type: Optional[Callable[[str],None]] def start(self): # type: () -> None pass # Classic doesn't have a permanent running maintenance def stop(self): # type: () -> None pass # Classic doesn't have a permanent running maintenance def set_receiver(self, callback): # type: (Callable[[str],None]) -> None self._receiver_callback = callback def is_active(self): # type: () -> bool return self._master_communicator.in_maintenance_mode() def activate(self): # type: () -> None """ Activates maintenance mode, If no data is send for too long, maintenance mode will be closed automatically. """ logger.info('Activating maintenance mode') self._last_maintenance_send_time = time.time() self._master_communicator.start_maintenance_mode() self._maintenance_timeout_timer = Timer(MaintenanceClassicCommunicator.MAINTENANCE_TIMEOUT, self._check_maintenance_timeout) self._maintenance_timeout_timer.start() self._stopped = False self._read_data_thread = BaseThread(target=self._read_data, name='maintenanceread') self._read_data_thread.daemon = True self._read_data_thread.start() self._deactivated_sent = False def deactivate(self, join=True): # type: (bool) -> None logger.info('Deactivating maintenance mode') self._stopped = True if join and self._read_data_thread is not None: self._read_data_thread.join() self._read_data_thread = None self._master_communicator.stop_maintenance_mode() if self._maintenance_timeout_timer is not None: self._maintenance_timeout_timer.cancel() self._maintenance_timeout_timer = None if self._deactivated_sent is False: master_event = MasterEvent(MasterEvent.Types.MAINTENANCE_EXIT, {}) self._pubsub.publish_master_event(PubSub.MasterTopics.MAINTENANCE, master_event) self._deactivated_sent = True def _check_maintenance_timeout(self): # type: () -> None """ Checks if the maintenance if the timeout is exceeded, and closes maintenance mode if required. """ timeout = MaintenanceClassicCommunicator.MAINTENANCE_TIMEOUT if self._master_communicator.in_maintenance_mode(): current_time = time.time() if self._last_maintenance_send_time + timeout < current_time: logger.info('Stopping maintenance mode because of timeout.') self.deactivate() else: wait_time = self._last_maintenance_send_time + timeout - current_time self._maintenance_timeout_timer = Timer(wait_time, self._check_maintenance_timeout) self._maintenance_timeout_timer.start() else: self.deactivate() def write(self, message): # type: (str) -> None self._last_maintenance_send_time = time.time() data = '{0}\r\n'.format(message.strip()).encode() self._master_communicator.send_maintenance_data(bytearray(data)) def _read_data(self): # type: () -> None """ Reads from the serial port and writes to the socket. """ buffer = '' while not self._stopped: try: data = self._master_communicator.get_maintenance_data() if data is None: continue buffer += data.decode() while '\n' in buffer: message, buffer = buffer.split('\n', 1) if self._receiver_callback is not None: try: self._receiver_callback(message.rstrip()) except Exception: logger.exception('Unexpected exception during maintenance callback') except Exception: logger.exception('Exception in maintenance read thread') break self.deactivate(join=False)
class MasterCommunicator(object): """ Uses a serial port to communicate with the master and updates the output state. Provides methods to send MasterCommands, Passthrough and Maintenance. """ @Inject def __init__(self, controller_serial=INJECTED, init_master=True, passthrough_timeout=0.2): # type: (Serial, bool, float) -> None """ :param controller_serial: Serial port to communicate with :param init_master: Send an initialization sequence to the master to make sure we are in CLI mode. This can be turned of for testing. :param verbose: Print all serial communication to stdout. :param passthrough_timeout: The time to wait for an answer on a passthrough message (in sec) """ self.__init_master = init_master self.__verbose = logger.level >= logging.DEBUG self.__serial = controller_serial self.__serial_write_lock = Lock() self.__command_lock = Lock() self.__cid = 1 self.__maintenance_mode = False self.__maintenance_queue = Queue() # type: Queue[bytearray] self.__update_mode = False self.__consumers = [ ] # type: List[Union[Consumer, BackgroundConsumer]] self.__passthrough_enabled = False self.__passthrough_mode = False self.__passthrough_timeout = passthrough_timeout self.__passthrough_queue = Queue() # type: Queue[bytearray] self.__passthrough_done = Event() self.__last_success = 0.0 self.__running = False self.__read_thread = None # type: Optional[Thread] self.__command_total_histogram = Counter() # type: Counter self.__command_success_histogram = Counter() # type: Counter self.__command_timeout_histogram = Counter() # type: Counter self.__communication_stats = { 'calls_succeeded': [], 'calls_timedout': [], 'bytes_written': 0, 'bytes_read': 0 } # type: Dict[str,Any] self.__debug_buffer = { 'read': {}, 'write': {} } # type: Dict[str, Dict[float,bytearray]] self.__debug_buffer_duration = 300 def start(self): # type: () -> None """ Start the MasterComunicator, this starts the background read thread. """ if self.__init_master: self._flush_serial_input() if not self.__read_thread: self.__read_thread = BaseThread(name='masterread', target=self.__read) self.__read_thread.daemon = True if not self.__running: self.__running = True self.__read_thread.start() def stop(self): # type: () -> None self.__running = False if self.__read_thread: self.__read_thread.join() self.__read_thread = None def update_mode_start(self): # type: () -> None if self.__maintenance_mode: raise InMaintenanceModeException() self.__update_mode = True def update_mode_stop(self): # type: () -> None self._flush_serial_input() self.__update_mode = False def _flush_serial_input(self): # type: () -> None def _flush(): """ Try to read from the serial input and discard the bytes read. """ i = 0 data = self.__serial.read(1) while len(data) > 0 and i < 100: data = self.__serial.read(1) i += 1 self.__serial.timeout = 1 self.__serial.write(bytearray(b' ' * 18 + b'\r\n')) _flush() self.__serial.write(bytearray(b'exit\r\n')) _flush() self.__serial.write(bytearray(b' ' * 10)) _flush() self.__serial.timeout = None # TODO: make non blocking def enable_passthrough(self): self.__passthrough_enabled = True def get_communication_statistics(self): return self.__communication_stats def reset_communication_statistics(self): self.__communication_stats = { 'calls_succeeded': [], 'calls_timedout': [], 'bytes_written': 0, 'bytes_read': 0 } def get_command_histograms(self): return { 'total': dict(self.__command_total_histogram), 'success': dict(self.__command_success_histogram), 'timeout': dict(self.__command_timeout_histogram) } def reset_command_histograms(self): self.__command_total_histogram.clear() self.__command_success_histogram.clear() self.__command_timeout_histogram.clear() def get_debug_buffer(self): # type: () -> Dict[str,Dict[float,str]] def process(buffer): return {k: printable(v) for k, v in six.iteritems(buffer)} return { 'read': process(self.__debug_buffer['read']), 'write': process(self.__debug_buffer['write']) } def get_seconds_since_last_success(self): """ Get the number of seconds since the last successful communication. """ if self.__last_success == 0: return 0 # No communication - return 0 sec since last success else: return time.time() - self.__last_success def __get_cid(self): """ Get a communication id """ (ret, self.__cid) = (self.__cid, (self.__cid % 255) + 1) return ret def __write_to_serial(self, data): """ Write data to the serial port. :param data: the data to write :type data: string """ # Don't touch the serial during updates. if self.__update_mode: raise MasterUnavailable() with self.__serial_write_lock: if self.__verbose: logger.debug('Writing to Master serial: {0}'.format( printable(data))) threshold = time.time() - self.__debug_buffer_duration self.__debug_buffer['write'][time.time()] = data for t in self.__debug_buffer['write'].keys(): if t < threshold: del self.__debug_buffer['write'][t] self.__serial.write(data) # TODO: make non blocking self.__communication_stats['bytes_written'] += len(data) def register_consumer(self, consumer): """ Register a customer consumer with the communicator. An instance of :class`Consumer` will be removed when consumption is done. An instance of :class`BackgroundConsumer` stays active and is thus able to consume multiple messages. :param consumer: The consumer to register. :type consumer: Consumer or BackgroundConsumer. """ self.__consumers.append(consumer) def do_raw_action(self, action, size, output_size=None, data=None, timeout=2): # type: (str, int, Optional[int], Optional[bytearray], Union[T_co, int]) -> Union[T_co, Dict[str, Any]] input_field = Field.padding(13) if data is None else Field.bytes( 'data', len(data)) command = MasterCommandSpec( action, [input_field], [Field.bytes('data', size), Field.lit('\r\n')]) return self.do_command(command, fields={'data': data}, timeout=timeout) def do_command(self, cmd, fields=None, timeout=2, extended_crc=False): # type: (MasterCommandSpec, Optional[Dict[str,Any]], Union[T_co, int], bool) -> Union[T_co, Dict[str, Any]] """ Send a command over the serial port and block until an answer is received. If the master does not respond within the timeout period, a CommunicationTimedOutException is raised :param cmd: specification of the command to execute :param fields: an instance of one of the available fields :param timeout: maximum allowed time before a CommunicationTimedOutException is raised :param extended_crc: indicates whether to include the action in the CRC :returns: dict containing the output fields of the command """ if self.__maintenance_mode: raise InMaintenanceModeException() if fields is None: fields = dict() cid = self.__get_cid() consumer = Consumer(cmd, cid) inp = cmd.create_input(cid, fields, extended_crc) with self.__command_lock: self.__command_total_histogram.update({str(cmd.action): 1}) self.__consumers.append(consumer) self.__write_to_serial(inp) try: result = consumer.get(timeout).fields if cmd.output_has_crc() and not MasterCommunicator.__check_crc( cmd, result, extended_crc): raise CrcCheckFailedException() else: self.__last_success = time.time() self.__communication_stats['calls_succeeded'].append( time.time()) self.__communication_stats[ 'calls_succeeded'] = self.__communication_stats[ 'calls_succeeded'][-50:] self.__command_success_histogram.update( {str(cmd.action): 1}) return result except CommunicationTimedOutException: if cmd.action != bytearray(b'FV'): # The FV instruction is a direct call to the Slave module. Older versions did not implement this # call, so this call can timeout while it's expected. We don't take those into account. self.__communication_stats['calls_timedout'].append( time.time()) self.__communication_stats[ 'calls_timedout'] = self.__communication_stats[ 'calls_timedout'][-50:] self.__command_timeout_histogram.update({str(cmd.action): 1}) raise @staticmethod def __check_crc(cmd, result, extended_crc=False): # type: (MasterCommandSpec, Result, bool) -> bool """ Calculate the CRC of the data for a certain master command. :param cmd: instance of MasterCommandSpec. :param result: A dict containing the result of the master command. :param extended_crc: Indicates whether the action should be included in the crc :returns: boolean """ crc = 0 if extended_crc: crc += cmd.action[0] crc += cmd.action[1] for field in cmd.output_fields: if Field.is_crc(field): break else: for byte in field.encode(result[field.name]): crc += byte return result['crc'] == bytearray([67, (crc // 256), (crc % 256)]) def __passthrough_wait(self): """ Waits until the passthrough is done or a timeout is reached. """ if not self.__passthrough_done.wait(self.__passthrough_timeout): logger.info('Timed out on passthrough message') self.__passthrough_mode = False self.__command_lock.release() def __push_passthrough_data(self, data): if self.__passthrough_enabled: self.__passthrough_queue.put(data) def send_passthrough_data(self, data): """ Send raw data on the serial port. :param data: string of bytes with raw command for the master. :raises: :class`InMaintenanceModeException` if master is in maintenance mode. """ if self.__maintenance_mode: raise InMaintenanceModeException() if not self.__passthrough_mode: self.__command_lock.acquire() self.__passthrough_done.clear() self.__passthrough_mode = True passthrough_thread = BaseThread(name='passthroughwait', target=self.__passthrough_wait) passthrough_thread.daemon = True passthrough_thread.start() self.__write_to_serial(data) def get_passthrough_data(self): """ Get data that wasn't consumed by do_command. Blocks if no data available or in maintenance mode. :returns: string containing unprocessed output """ data = self.__passthrough_queue.get() if data[-4:] == bytearray(b'\r\n\r\n'): self.__passthrough_done.set() return data def start_maintenance_mode(self): """ Start maintenance mode. :raises: :class`InMaintenanceModeException` if master is in maintenance mode. """ if self.__maintenance_mode: raise InMaintenanceModeException() while True: try: self.__maintenance_queue.get(block=False) except Empty: break self.__maintenance_mode = True self.send_maintenance_data(master_api.to_cli_mode().create_input(0)) def send_maintenance_data(self, data): """ Send data to the master in maintenance mode. :param data: data to send to the master :type data: string """ if not self.__maintenance_mode: raise Exception('Not in maintenance mode !') self.__write_to_serial(data) def get_maintenance_data(self): """ Get data from the master in maintenance mode. :returns: string containing unprocessed output """ if not self.__maintenance_mode: raise Exception('Not in maintenance mode !') try: return self.__maintenance_queue.get(timeout=1) except Empty: return None def stop_maintenance_mode(self): """ Stop maintenance mode. """ if self.__maintenance_mode: self.send_maintenance_data(bytearray(b'exit\r\n')) self.__maintenance_mode = False def in_maintenance_mode(self): """ Returns whether the MasterCommunicator is in maintenance mode. """ return self.__maintenance_mode def __get_start_bytes(self): """ Create a dict that maps the start byte to a list of consumers. """ start_bytes = { } # type: Dict[int, List[Union[Consumer, BackgroundConsumer]]] for consumer in self.__consumers: start_byte = consumer.get_prefix()[0] if start_byte in start_bytes: start_bytes[start_byte].append(consumer) else: start_bytes[start_byte] = [consumer] return start_bytes def __read(self): """ Code for the background read thread: reads from the serial port, checks if consumers for incoming bytes, if not: put in pass through buffer. """ def consumer_done(_consumer): """ Callback for when consumer is done. ReadState does not access parent directly. """ if isinstance(_consumer, Consumer): self.__consumers.remove(_consumer) elif isinstance( _consumer, BackgroundConsumer) and _consumer.send_to_passthrough: self.__push_passthrough_data(_consumer.last_cmd_data) class ReadState(object): """" The read state keeps track of the current consumer and the partial result for that consumer. """ def __init__(self): self.current_consumer = None # type: Optional[Union[Consumer, BackgroundConsumer]] self.partial_result = None # type: Optional[Result] def should_resume(self): """ Checks whether we should resume consuming data with the current_consumer. """ return self.current_consumer is not None def should_find_consumer(self): """ Checks whether we should find a new consumer. """ return self.current_consumer is None def set_consumer(self, _consumer): """ Set a new consumer. """ self.current_consumer = _consumer self.partial_result = None def consume(self, _data): # type: (bytearray) -> bytearray """ Consume the bytes in data using the current_consumer, and return the bytes that were not used. """ assert read_state.current_consumer try: bytes_consumed, result, done = read_state.current_consumer.consume( _data, read_state.partial_result) except ValueError as value_error: logger.error( 'Could not consume/decode message from the master: {0}' .format(value_error)) # Consumer failed, reset. self.current_consumer = None self.partial_result = None return _data if done: assert self.current_consumer consumer_done(self.current_consumer) self.current_consumer.deliver(result) self.current_consumer = None self.partial_result = None return _data[bytes_consumed:] self.partial_result = result return bytearray() read_state = ReadState() data = bytearray() while self.__running: # Don't touch the serial during updates. if self.__update_mode: time.sleep(2) continue # TODO: use a non blocking serial instead? readers, _, _ = select.select([self.__serial], [], [], 2) if not readers: continue num_bytes = self.__serial.inWaiting() data += self.__serial.read(num_bytes) if len(data) > 0: self.__communication_stats['bytes_read'] += num_bytes threshold = time.time() - self.__debug_buffer_duration self.__debug_buffer['read'][time.time()] = data for t in self.__debug_buffer['read'].keys(): if t < threshold: del self.__debug_buffer['read'][t] if self.__verbose: logger.debug('Reading from Master serial: {0}'.format( printable(data))) if read_state.should_resume(): data = read_state.consume(data) # No else here: data might not be empty when current_consumer is done if read_state.should_find_consumer(): start_bytes = self.__get_start_bytes() leftovers = bytearray( ) # for unconsumed bytes; these will go to the passthrough. while len(data) > 0: if data[0] in start_bytes: # Prefixes are 3 bytes, make sure we have enough data to match if len(data) >= 3: match = False for consumer in start_bytes[data[0]]: if data[:3] == consumer.get_prefix(): # Found matching consumer read_state.set_consumer(consumer) data = read_state.consume( data[3:]) # Strip off prefix # Consumers might have changed, update start_bytes start_bytes = self.__get_start_bytes() match = True break if match: continue else: # All commands end with '\r\n', there are no prefixes that start # with \r\n so the last bytes of a command will not get stuck # waiting for the next serial.read() break leftovers.append(data[0]) data = data[1:] if len(leftovers) > 0: if not self.__maintenance_mode: self.__push_passthrough_data(leftovers) else: self.__maintenance_queue.put(leftovers)