def start_runtime(plugin_location=None): if plugin_location is None and (len(sys.argv) < 3 or sys.argv[1] != 'start_plugin'): sys.stderr.write('Usage: python {0} start_plugin <path>\n'.format( sys.argv[0])) sys.stderr.flush() sys.exit(1) elif not (len(sys.argv) < 3 or sys.argv[1] != 'start_plugin'): plugin_location = sys.argv[2] def watch_parent(): parent = os.getppid() # If the parent process gets kills, this process will be attached to init. # In that case the plugin should stop running. while True: if os.getppid() != parent: os._exit(1) time.sleep(1) # Keep an eye on our parent process watcher = BaseThread(name='pluginwatch', target=watch_parent) watcher.daemon = True watcher.start() # Start the runtime try: runtime = PluginRuntime(path=plugin_location) runtime.process_stdin() except BaseException as ex: writer = PluginIPCWriter(os.fdopen(sys.stdout.fileno(), 'wb', 0)) writer.log_exception('__main__', ex) os._exit(1) os._exit(0)
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)
def _start_background_tasks(self): # type: () -> None """ Start all background tasks. """ for decorated_method in self._decorated_methods['background_task']: thread = BaseThread(name='plugin{}'.format( decorated_method.__name__), target=self._run_background_task, args=(decorated_method, )) thread.daemon = True thread.start()
def _handle_stop(self): def delayed_stop(): time.sleep(2) os._exit(0) stop_thread = BaseThread(name='pluginstop', target=delayed_stop) stop_thread.daemon = True stop_thread.start() self._stopped = True
def _start(self): def stop(signum, frame): """ This function is called on SIGTERM. """ _ = signum, frame self._stop = True signal(SIGTERM, stop) receiver = BaseThread(name='msgclientrecv', target=self._message_receiver) receiver.daemon = True receiver.start()
class RunnerWatchdog(object): def __init__(self, plugin_runner, threshold=0.25, check_interval=60): # type: (PluginRunner, float, int) -> None self._plugin_runner = plugin_runner self._threshold = threshold self._check_interval = check_interval self._stopped = False self._thread = None # type: Optional[Thread] def stop(self): # type: () -> None self._stopped = True if self._thread is not None: self._thread.join() def start(self): # type: () -> bool self._stopped = False success = self._run() # Initial sync run self._thread = BaseThread(name='watchdog{0}'.format( self._plugin_runner.name), target=self.run) self._thread.daemon = True self._thread.start() return success def run(self): self._plugin_runner.logger('[Watchdog] Started') while not self._stopped: self._run() for _ in range(self._check_interval * 2): # Small sleep cycles, to be able to finish the thread quickly time.sleep(0.5) if self._stopped: break self._plugin_runner.logger('[Watchdog] Stopped') def _run(self): try: score = self._plugin_runner.error_score() if score > self._threshold: self._plugin_runner.logger( '[Watchdog] Stopping unhealthy runner') self._plugin_runner.stop() if not self._plugin_runner.is_running(): self._plugin_runner.logger( '[Watchdog] Starting stopped runner') self._plugin_runner.start() return True except Exception as e: self._plugin_runner.logger( '[Watchdog] Exception in watchdog: {0}'.format(e)) return False
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 RS485(object): """ Replicates the pyserial interface. """ def __init__(self, serial): # type: (Serial) -> None """ Initialize a rs485 connection using the serial port. """ self._serial = serial fileno = serial.fileno() if fileno is not None: flags_rs485 = SER_RS485_ENABLED | SER_RS485_RTS_ON_SEND serial_rs485 = struct.pack('hhhhhhhh', flags_rs485, 0, 0, 0, 0, 0, 0, 0) fcntl.ioctl(fileno, TIOCSRS485, serial_rs485) self._serial.timeout = None self._running = False self._thread = BaseThread(name='rS485read', target=self._reader) self._thread.daemon = True # TODO why does this stream byte by byte? self.read_queue = Queue() # type: Queue[bytearray] def start(self): # type: () -> None if not self._running: self._running = True self._thread.start() def stop(self): # type: () -> None self._running = False def write(self, data): # type: (bytes) -> None """ Write data to serial port """ self._serial.write(data) def _reader(self): # type: () -> None try: while self._running: data = bytearray(self._serial.read(1)) if len(data) == 1: self.read_queue.put(data[:1]) size = self._serial.inWaiting() if size > 0: data = bytearray(self._serial.read(size)) for i in range(size): self.read_queue.put(data[i:i + 1]) except Exception as ex: print('Error in reader: {0}'.format(ex))
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, command, cid, callback ): # type: (CoreCommandSpec, int, Callable[[Dict[str, Any]], None]) -> None """ Create a background consumer using a cmd, cid and callback. :param command: the CoreCommand to consume. :param cid: the communication id. :param callback: function to call when an instance was found. """ self.cid = cid self.command = command self._callback = callback self._queue = Queue() # type: Queue[Dict[str, Any]] self._callback_thread = BaseThread(name='coredelivery', target=self._consumer) self._callback_thread.setDaemon(True) self._callback_thread.start() def _consumer(self): while True: try: self.deliver() except Exception: logger.exception( 'Unexpected exception delivering background consumer data') time.sleep(1) def get_hash(self): # type: () -> int """ Get an identification hash for this consumer. """ return Toolbox.hash(CoreCommunicator.START_OF_REPLY + bytearray([self.cid]) + self.command.response_instruction) def consume(self, payload): # type: (bytearray) -> None """ Consume payload. """ data = self.command.consume_response_payload(payload) self._queue.put(data) def deliver(self): """ Deliver data to the callback functions. """ self._callback(self._queue.get())
def _process(self): now = time.time() self.refresh_schedules() # Bug fix pending_schedules = [] for schedule_id in list(self._schedules.keys()): schedule_tuple = self._schedules.get(schedule_id) if schedule_tuple is None: continue schedule_dto, schedule = schedule_tuple if schedule_dto.status != 'ACTIVE': continue if schedule_dto.end is not None and schedule_dto.end < time.time(): schedule_dto.status = 'COMPLETED' schedule.status = 'COMPLETED' schedule.save() continue if schedule_dto.next_execution is not None and schedule_dto.next_execution < now - 60: continue pending_schedules.append(schedule_dto) # Sort the schedules according to their next_execution pending_schedules = list( sorted(pending_schedules, key=attrgetter('next_execution'))) if not pending_schedules: return next_start = pending_schedules[0].next_execution schedules_to_execute = [ schedule for schedule in pending_schedules if schedule.next_execution < next_start + 60 ] if not schedules_to_execute: return # Let this thread hang until it's time to execute the schedule logger.debug('next pending schedule %s, waiting %ss', datetime.fromtimestamp(next_start), next_start - now) self._event.wait(next_start - now) if self._event.isSet( ): # If a new schedule is saved, stop hanging and refresh the schedules self._event.clear() return thread = BaseThread(name='schedulingexc', target=self._execute_schedule, args=(schedules_to_execute, schedule)) thread.daemon = True thread.start()
def _process(self): for schedule_id in list(self._schedules.keys()): schedule_tuple = self._schedules.get(schedule_id) if schedule_tuple is None: continue schedule_dto, schedule = schedule_tuple if schedule_dto.status != 'ACTIVE': continue if schedule_dto.end is not None and schedule_dto.end < time.time(): schedule_dto.status = 'COMPLETED' schedule.status = 'COMPLETED' schedule.save() continue if schedule_dto.is_due: thread = BaseThread(name='schedulingexc', target=self._execute_schedule, args=(schedule_dto, schedule)) thread.daemon = True thread.start()
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)
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 MaintenanceCoreCommunicator(MaintenanceCommunicator): @Inject def __init__(self, cli_serial=INJECTED): """ :param cli_serial: Serial port to communicate with :type cli_serial: serial.Serial """ self._serial = cli_serial self._write_lock = Lock() self._receiver_callback = None self._deactivated_callback = None self._maintenance_active = False self._stopped = True self._read_data_thread = None self._active = False def start(self): self._stopped = False self._read_data_thread = BaseThread(name='maintenanceread', target=self._read_data) self._read_data_thread.daemon = True self._read_data_thread.start() def stop(self): self._stopped = True def is_active(self): return self._active def activate(self): self._active = True # Core has a separate serial port def deactivate(self, join=True): _ = join self._active = False # Core has a separate serial port if self._deactivated_callback is not None: self._deactivated_callback() def set_receiver(self, callback): self._receiver_callback = callback def set_deactivated(self, callback): self._deactivated_callback = callback def _read_data(self): data = '' previous_length = 0 while not self._stopped: # Read what's now on the buffer num_bytes = self._serial.inWaiting() if num_bytes > 0: data += self._serial.read(num_bytes) if len(data) == previous_length: time.sleep(0.1) continue previous_length = len(data) if '\n' not in data: continue message, data = data.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') def write(self, message): if message is None: return with self._write_lock: self._serial.write('{0}\r\n'.format(message.strip()))
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)
class MaintenanceController(object): SOCKET_TIMEOUT = 60 @Inject def __init__(self, maintenance_communicator=INJECTED, ssl_private_key=INJECTED, ssl_certificate=INJECTED): """ :type maintenance_communicator: gateway.maintenance_communicator.MaintenanceCommunicator """ self._consumers = {} self._privatekey_filename = ssl_private_key self._certificate_filename = ssl_certificate self._maintenance_communicator = maintenance_communicator if self._maintenance_communicator: self._maintenance_communicator.set_receiver(self._received_data) self._connection = None self._server_thread = None ####################### # Internal management # ####################### def start(self): # type: () -> None if self._maintenance_communicator: self._maintenance_communicator.start() def stop(self): # type: () -> None if self._maintenance_communicator: self._maintenance_communicator.stop() def _received_data(self, message): try: if self._connection is not None: self._connection.sendall('{0}\n'.format(message.rstrip())) except Exception: logger.exception( 'Exception forwarding maintenance data to socket connection.') for consumer_id, callback in self._consumers.items(): try: callback(message.rstrip()) except Exception: logger.exception( 'Exception forwarding maintenance data to consumer %s', str(consumer_id)) def _activate(self): if not self._maintenance_communicator.is_active(): self._maintenance_communicator.activate() def _deactivate(self): if self._maintenance_communicator.is_active(): self._maintenance_communicator.deactivate() ################# # Subscriptions # ################# def add_consumer(self, consumer_id, callback): self._consumers[consumer_id] = callback self._activate() def remove_consumer(self, consumer_id): self._consumers.pop(consumer_id, None) if not self._consumers: logger.info('Stopping maintenance mode due to no consumers.') self._deactivate() ########## # Socket # ########## def open_maintenace_socket(self): """ Opens a TCP/SSL socket, connecting it with the maintenance service """ port = random.randint(6000, 7000) self._server_thread = BaseThread(name='maintenancesock', target=self._run_socket_server, args=[port]) self._server_thread.daemon = True self._server_thread.start() return port def _run_socket_server(self, port): connection_timeout = MaintenanceController.SOCKET_TIMEOUT logger.info('Starting maintenance socket on port %s', port) sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM) sock.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1) sock.settimeout(connection_timeout) sock = System.get_ssl_socket( sock, private_key_filename=self._privatekey_filename, certificate_filename=self._certificate_filename) sock.bind(('', port)) sock.listen(1) try: logger.info('Waiting for maintenance connection.') self._connection, address = sock.accept() logger.info('Maintenance connection from %s', str(address)) self._handle_connection() logger.info( 'Maintenance session ended, closing maintenance socket') sock.close() except socket.timeout: logger.info('Maintenance socket timed out, closing.') sock.close() except Exception: logger.exception('Error in maintenance service') sock.close() def _handle_connection(self): """ Handles one incoming connection. """ try: self._connection.settimeout(1) self._connection.sendall( 'Activating maintenance mode, waiting for other actions to complete ...\n' ) self._activate() self._connection.sendall('Connected\n') while self._maintenance_communicator.is_active(): try: try: data = self._connection.recv(1024) if not data: logger.info( 'Stopping maintenance mode due to no data.') break if data.startswith('exit'): logger.info( 'Stopping maintenance mode due to exit.') break self._maintenance_communicator.write(data) except Exception as exception: if System.handle_socket_exception( self._connection, exception, logger): continue else: logger.exception( 'Unexpected exception receiving connection data' ) break except Exception: logger.exception('Exception in maintenance mode') break except InMaintenanceModeException: self._connection.sendall('Maintenance mode already active.\n') finally: self._deactivate() logger.info('Maintenance mode deactivated') self._connection.close() self._connection = None ####### # I/O # ####### def write(self, message): self._maintenance_communicator.write(message)
class PluginRunner(object): class State(object): RUNNING = 'RUNNING' STOPPED = 'STOPPED' def __init__(self, name, runtime_path, plugin_path, logger, command_timeout=5.0, state_callback=None): self.runtime_path = runtime_path self.plugin_path = plugin_path self.command_timeout = command_timeout self._logger = logger self._cid = 0 self._proc = None # type: Optional[subprocess.Popen[bytes]] self._running = False self._process_running = False self._command_lock = Lock() self._response_queue = Queue() # type: Queue[Dict[str,Any]] self._writer = None # type: Optional[PluginIPCWriter] self._reader = None # type: Optional[PluginIPCReader] self._state_callback = state_callback # type: Optional[Callable[[str, str], None]] self.name = name self.version = None self.interfaces = None self._decorators_in_use = {} self._exposes = [] self._metric_collectors = [] self._metric_receivers = [] self._async_command_thread = None self._async_command_queue = None # type: Optional[Queue[Optional[Dict[str, Any]]]] self._commands_executed = 0 self._commands_failed = 0 self.__collector_runs = {} # type: Dict[str,float] def start(self): # type: () -> None if self._running: raise Exception('PluginRunner is already running') self.logger('[Runner] Starting') python_executable = sys.executable if python_executable is None or len(python_executable) == 0: python_executable = '/usr/bin/python' self._proc = subprocess.Popen([ python_executable, 'runtime.py', 'start_plugin', self.plugin_path ], stdin=subprocess.PIPE, stdout=subprocess.PIPE, stderr=None, cwd=self.runtime_path, close_fds=True) assert self._proc.stdout, 'Plugin stdout not available' self._process_running = True self._commands_executed = 0 self._commands_failed = 0 assert self._proc.stdin, 'Plugin stdin not defined' self._writer = PluginIPCWriter(stream=self._proc.stdin) self._reader = PluginIPCReader(stream=self._proc.stdout, logger=lambda message, ex: self.logger( '{0}: {1}'.format(message, ex)), command_receiver=self._process_command, name=self.name) self._reader.start() start_out = self._do_command('start', timeout=180) self.name = start_out['name'] self.version = start_out['version'] self.interfaces = start_out['interfaces'] self._decorators_in_use = start_out['decorators'] self._exposes = start_out['exposes'] self._metric_collectors = start_out['metric_collectors'] self._metric_receivers = start_out['metric_receivers'] exception = start_out.get('exception') if exception is not None: raise RuntimeError(exception) self._async_command_queue = Queue(1000) self._async_command_thread = BaseThread( name='plugincmd{0}'.format(self.plugin_path), target=self._perform_async_commands) self._async_command_thread.daemon = True self._async_command_thread.start() self._running = True if self._state_callback is not None: self._state_callback(self.name, PluginRunner.State.RUNNING) self.logger('[Runner] Started') def logger(self, message): # type: (str) -> None self._logger(message) logger_.info('Plugin {0} - {1}'.format(self.name, message)) def get_webservice(self, webinterface): # type: (WebInterface) -> Service return Service(self, webinterface) def is_running(self): # type: () -> bool return self._running def stop(self): # type: () -> None if self._process_running: self._running = False self.logger('[Runner] Sending stop command') try: self._do_command('stop') except Exception as exception: self.logger( '[Runner] Exception during stopping plugin: {0}'.format( exception)) time.sleep(0.1) if self._reader: self._reader.stop() self._process_running = False if self._async_command_queue is not None: self._async_command_queue.put( None) # Triggers an abort on the read thread if self._proc and self._proc.poll() is None: self.logger('[Runner] Terminating process') try: self._proc.terminate() except Exception as exception: self.logger( '[Runner] Exception during terminating plugin: {0}'. format(exception)) time.sleep(0.5) if self._proc.poll() is None: self.logger('[Runner] Killing process') try: self._proc.kill() except Exception as exception: self.logger( '[Runner] Exception during killing plugin: {0}'. format(exception)) if self._state_callback is not None: self._state_callback(self.name, PluginRunner.State.STOPPED) self.logger('[Runner] Stopped') def process_input_status(self, data, action_version=1): if action_version in [1, 2]: if action_version == 1: payload = {'status': data} else: event_json = data.serialize() payload = {'event': event_json} self._do_async(action='input_status', payload=payload, should_filter=True, action_version=action_version) else: self.logger('Input status version {} not supported.'.format( action_version)) def process_output_status(self, data, action_version=1): if action_version in [1, 2]: if action_version == 1: payload = {'status': data} else: event_json = data.serialize() payload = {'event': event_json} self._do_async(action='output_status', payload=payload, should_filter=True, action_version=action_version) else: self.logger('Output status version {} not supported.'.format( action_version)) def process_shutter_status(self, data, action_version=1): if action_version in [1, 2, 3]: if action_version == 1: payload = {'status': data} elif action_version == 2: status, detail = data payload = {'status': {'status': status, 'detail': detail}} else: event_json = data.serialize() payload = {'event': event_json} self._do_async(action='shutter_status', payload=payload, should_filter=True, action_version=action_version) else: self.logger('Shutter status version {} not supported.'.format( action_version)) def process_ventilation_status(self, data, action_version=1): if action_version in [1]: event_json = data.serialize() payload = {'event': event_json} self._do_async(action='ventilation_status', payload=payload, should_filter=True, action_version=action_version) else: self.logger('Ventilation status version {} not supported.'.format( action_version)) def process_thermostat_status(self, data, action_version=1): if action_version in [1]: event_json = data.serialize() payload = {'event': event_json} self._do_async(action='thermostat_status', payload=payload, should_filter=True, action_version=action_version) else: self.logger('Thermostat status version {} not supported.'.format( action_version)) def process_thermostat_group_status(self, data, action_version=1): if action_version in [1]: event_json = data.serialize() payload = {'event': event_json} self._do_async(action='thermostat_group_status', payload=payload, should_filter=True, action_version=action_version) else: self.logger( 'Thermostat group status version {} not supported.'.format( action_version)) def process_event(self, code): self._do_async('receive_events', {'code': code}, should_filter=True) def collect_metrics(self): for mc in self._metric_collectors: try: now = time.time() (name, interval) = (mc['name'], mc['interval']) if self.__collector_runs.get(name, 0.0) < now - interval: self.__collector_runs[name] = now metrics = self._do_command('collect_metrics', {'name': name})['metrics'] for metric in metrics: if metric is None: continue metric['source'] = self.name yield metric except Exception as exception: self.logger( '[Runner] Exception while collecting metrics {0}: {1}'. format(exception, traceback.format_exc())) def get_metric_receivers(self): return self._metric_receivers def distribute_metrics(self, method, metrics): self._do_async('distribute_metrics', { 'name': method, 'metrics': metrics }) def get_metric_definitions(self): return self._do_command('get_metric_definitions')['metric_definitions'] def request(self, method, args=None, kwargs=None): if args is None: args = [] if kwargs is None: kwargs = {} ret = self._do_command('request', { 'method': method, 'args': args, 'kwargs': kwargs }) if ret['success']: return ret['response'] elif 'stacktrace' in ret: raise Exception('{0}: {1}'.format(ret['exception'], ret['stacktrace'])) raise Exception(ret['exception']) def remove_callback(self): # type: () -> None self._do_command('remove_callback') def _process_command(self, response): # type: (Dict[str,Any]) -> None if not self._process_running: return assert self._proc, 'Plugin process not defined' exit_code = self._proc.poll() if exit_code is not None: self.logger( '[Runner] Stopped with exit code {0}'.format(exit_code)) self._process_running = False return if response['cid'] == 0: self._handle_async_response(response) elif response['cid'] == self._cid: self._response_queue.put(response) else: self.logger( '[Runner] Received message with unknown cid: {0}'.format( response)) def _handle_async_response(self, response): # type: (Dict[str,Any]) -> None if response['action'] == 'logs': self.logger(response['logs']) else: self.logger('[Runner] Unkown async message: {0}'.format(response)) def _do_async(self, action, payload, should_filter=False, action_version=1): # type: (str, Dict[str,Any], bool, int) -> None has_receiver = False for decorator_name, decorator_versions in six.iteritems( self._decorators_in_use): # the action version is linked to a specific decorator version has_receiver |= (action == decorator_name and action_version in decorator_versions) if not self._process_running or (should_filter and not has_receiver): return try: assert self._async_command_queue, 'Command Queue not defined' self._async_command_queue.put( { 'action': action, 'payload': payload, 'action_version': action_version }, block=False) except Full: self.logger('Async action cannot be queued, queue is full') def _perform_async_commands(self): # type: () -> None while self._process_running: try: # Give it a timeout in order to check whether the plugin is not stopped. assert self._async_command_queue, 'Command Queue not defined' command = self._async_command_queue.get(block=True, timeout=10) if command is None: continue # Used to exit this thread self._do_command(command['action'], payload=command['payload'], action_version=command['action_version']) except Empty: self._do_async('ping', {}) except Exception as exception: self.logger( '[Runner] Failed to perform async command: {0}'.format( exception)) def _do_command(self, action, payload=None, timeout=None, action_version=1): # type: (str, Dict[str,Any], Optional[float], int) -> Dict[str,Any] if payload is None: payload = {} self._commands_executed += 1 if timeout is None: timeout = self.command_timeout if not self._process_running: raise Exception('Plugin was stopped') with self._command_lock: try: command = self._create_command(action, payload, action_version) assert self._writer, 'Plugin stdin not defined' self._writer.write(command) except Exception: self._commands_failed += 1 raise try: response = self._response_queue.get(block=True, timeout=timeout) while response['cid'] != self._cid: response = self._response_queue.get(block=False) exception = response.get('_exception') if exception is not None: raise RuntimeError(exception) return response except Empty: metadata = '' if action == 'request': metadata = ' {0}'.format(payload['method']) if self._running: self.logger( '[Runner] No response within {0}s ({1}{2})'.format( timeout, action, metadata)) self._commands_failed += 1 raise Exception('Plugin did not respond') def _create_command(self, action, payload=None, action_version=1): # type: (str, Dict[str,Any], int) -> Dict[str,Any] if payload is None: payload = {} self._cid += 1 command = { 'cid': self._cid, 'action': action, 'action_version': action_version } command.update(payload) return command def error_score(self): # type: () -> float if self._commands_executed == 0: return 0.0 else: score = float(self._commands_failed) / self._commands_executed self._commands_failed = 0 self._commands_executed = 0 return score def get_queue_length(self): # type: () -> int if self._async_command_queue is None: return 0 return self._async_command_queue.qsize()
if len(sys.argv) < 3 or sys.argv[1] != 'start': sys.stderr.write('Usage: python {0} start <path>\n'.format( sys.argv[0])) sys.stderr.flush() sys.exit(1) def watch_parent(): parent = os.getppid() # If the parent process gets kills, this process will be attached to init. # In that case the plugin should stop running. while True: if os.getppid() != parent: os._exit(1) time.sleep(1) # Keep an eye on our parent process watcher = BaseThread(name='pluginwatch', target=watch_parent) watcher.daemon = True watcher.start() # Start the runtime try: runtime = PluginRuntime(path=sys.argv[2]) runtime.process_stdin() except BaseException as ex: writer = PluginIPCWriter(os.fdopen(sys.stdout.fileno(), 'wb', 0)) writer.log_exception('__main__', ex) os._exit(1) os._exit(0)
class PassthroughService(object): """ The Passthrough service creates two threads: one for reading from and one for writing to the master. """ @Inject def __init__(self, master_communicator=INJECTED, passthrough_serial=INJECTED, verbose=False): self.__master_communicator = master_communicator self.__passthrough_serial = passthrough_serial self.__verbose = verbose self.__stopped = False self.__reader_thread = None self.__writer_thread = None self.__master_communicator.enable_passthrough() def start(self): """ Start the Passthrough service, this launches the two threads. """ self.__reader_thread = BaseThread(name='passthroughread', target=self.__reader) self.__reader_thread.daemon = True self.__reader_thread.start() self.__writer_thread = BaseThread(name='passthroughwrite', target=self.__writer) self.__writer_thread.daemon = True self.__writer_thread.start() def __reader(self): """ Reads from the master and writes to the passthrough serial. """ while not self.__stopped: data = self.__master_communicator.get_passthrough_data() if data and len(data) > 0: if self.__verbose: logger.info("Data for passthrough: %s", printable(data)) self.__passthrough_serial.write(data) def __writer(self): """ Reads from the passthrough serial and writes to the master. """ while not self.__stopped: data = self.__passthrough_serial.read(1) if data and len(data) > 0: num_bytes = self.__passthrough_serial.inWaiting() if num_bytes > 0: data += self.__passthrough_serial.read(num_bytes) try: if self.__verbose: logger.info("Data from passthrough: %s", printable(data)) self.__master_communicator.send_passthrough_data(data) except InMaintenanceModeException: logger.info( "Dropped passthrough communication in maintenance mode." ) def stop(self): """ Stop the Passthrough service. """ self.__stopped = True
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)