From 16a29f7e5d5abd6165d8588e1a48ba589c8da410 Mon Sep 17 00:00:00 2001 From: Trygve Date: Thu, 17 Mar 2022 21:57:10 +0100 Subject: [PATCH] =?UTF-8?q?Startet=20p=C3=A5=20lesing=20av=20mtr?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- event_mgr.py | 3 + mtr_log_extractor.py | 200 +++++++++++++++++++++++++++++++ mtrlog.py | 47 ++++++++ mtrreader.py | 276 +++++++++++++++++++++++++++++++++++++++++++ serial_async_test.py | 41 +++++++ 5 files changed, 567 insertions(+) create mode 100644 mtr_log_extractor.py create mode 100644 mtrlog.py create mode 100644 mtrreader.py create mode 100644 serial_async_test.py diff --git a/event_mgr.py b/event_mgr.py index 9cd17ee..575fcb9 100644 --- a/event_mgr.py +++ b/event_mgr.py @@ -1,5 +1,6 @@ #!/usr/bin/env python import otime +import mtr_log_extractor as mle import json import asyncio from difflib import Differ @@ -81,5 +82,7 @@ async def main(): db_file_u = None if __name__ == "__main__": + print(dir(mle)) + print('🤔') start() asyncio.run(main()) diff --git a/mtr_log_extractor.py b/mtr_log_extractor.py new file mode 100644 index 0000000..9fcf780 --- /dev/null +++ b/mtr_log_extractor.py @@ -0,0 +1,200 @@ +#!/usr/bin/env python3 + +import argparse +import logging +import logging.handlers +import os +import serial +import sys +from datetime import datetime, timedelta +import time + +import mtrreader +import mtrlog + + +def create_argparser(): + argparser = argparse.ArgumentParser( + formatter_class=argparse.ArgumentDefaultsHelpFormatter) + argparser.add_argument( + '-p', + '--serial-port', + default='/dev/ttyMTR', + help="Serial port device of MTR") + argparser.add_argument( + '-t', + '--serial-port-polling-timeout', + metavar='TIMEOUT', + type=int, + help=( + 'Number of seconds to spend polling MTR for status before ' + 'giving up. (Exits with status code {} on timeout.)'.format( + exit_code_serial_port_unresponsive))) + argparser.add_argument( + '-f', + '--output-file-name', + default="mtr-{}.log", + help=( + 'Name of output file in the "MTR log file" format read by ' + 'tTime (See http://ttime.no. Format described at ' + 'http://ttime.no/rs232.pdf.) ' + 'A {} in the filename will be replaced with a timestamp in ' + 'the ISO 8601 combined date and time basic format.')) + argparser.add_argument( + '-d', + '--destination', + nargs='+', + metavar='DEST_ARG', + help=( + "Send MTR log file to a destination. Supported destinations: " + "an HTTP URL (accepting POST form uploads) or " + "'dropbox path/to/apitokenfile [/upload/dir]'")) + argparser.add_argument( + '-l', + '--log', + nargs='+', + metavar='LOG_ARG', + default=['syslog', '/dev/log', 'local0'], + help=( + "Configure logging. LOG_ARG can be a log file path or the " + "default (using multiple values) 'syslog [SOCKET] [FACILITY]' " + "where SOCKET is '/dev/log' and FACILITY is 'local0' by " + "default.")) + return argparser + + +def initialize_logging(): + logger = logging.getLogger() + logger.setLevel(logging.DEBUG) + if args.log[0] == 'syslog': + address = args.log[1] if len(args.log) >= 2 else '/dev/log' + facility = args.log[2] if len(args.log) >= 3 else 'local0' + syslog_handler = logging.handlers.SysLogHandler( + address=address, + facility=facility) + syslog_handler.setFormatter(logging.Formatter(logging.BASIC_FORMAT)) + logger.addHandler(syslog_handler) + else: + log_file = args.log[0] + file_handler = logging.handlers.WatchedFileHandler(log_file) + file_handler.setFormatter(logging.Formatter(logging.BASIC_FORMAT)) + logger.addHandler(file_handler) + return logger + + +def should_poll_mtr_for_status(timeout_uptime): + no_timeout_set = timeout_uptime is None + return no_timeout_set or uptime() < timeout_uptime + + +def uptime(): + with open('/proc/uptime', 'r') as f: + uptime_seconds = float(f.readline().split()[0]) + return timedelta(seconds=uptime_seconds) + + +def is_status_response(messages): + return (len(messages) == 1 + and isinstance(messages[0], mtrreader.MtrStatusMessage)) + + +def serial_port_with_live_mtr( + port, polling_timeout_secs, retry_wait_time_secs, serial_timeout_secs): + if polling_timeout_secs is None: + polling_timeout_uptime = None + logger.info("Polling serial port %s forever", port) + else: + polling_timeout_uptime = ( + uptime() + timedelta(seconds=polling_timeout_secs)) + logger.info( + "Polling serial port %s for status for %s seconds (until " + "uptime is %s)", + port, polling_timeout_secs, polling_timeout_uptime) + + while should_poll_mtr_for_status(polling_timeout_uptime): + try: + serial_port = serial.Serial( + port=port, baudrate=9600, timeout=serial_timeout_secs) + + logger.info( + "Opened serial port %s, sending 'status' command '/ST'...", + port) + mtr_reader_status = mtrreader.MtrReader(serial_port) + mtr_reader_status.send_status_command() + messages = mtr_reader_status.receive() + if is_status_response(messages): + logger.info( + "MTR status response received, ID is %d", + messages[0].mtr_id()) + return serial_port + + except serial.SerialException: + # Just log the error, the device could have been suddenly + # connected and could be responding next time. + logger.info(( + "MTR status polling failed; Serial port %s was closed or " + "couldn't be opened"), port) + + logger.info( + "Retrying MTR status polling in %d seconds", + retry_wait_time_secs) + time.sleep(retry_wait_time_secs) + + logger.info( + "No status response received on serial port %s in %d seconds. " + "Giving up.", + port, polling_timeout_secs) + return None + + +def write_mtr_log_file(log_lines, output_filename): + with open(output_filename, 'wb') as output_file: + for log_line in log_lines: + output_file.write(("%s\n" % log_line).encode('utf-8')) + logger.info("Wrote log file %s", output_filename) + return output_filename + + +def upload_mtr_log_file_dropbox(log_file_name, upload_dir, token): + dbx = dropbox.Dropbox(token) + with open(log_file_name, 'rb') as f: + upload_filename = os.path.basename(f.name) + dbx.files_upload(f.read(), upload_dir + "/" + upload_filename) + return + + +def upload_mtr_log_file_http(log_file_name, url): + with open(log_file_name, 'rb') as f: + requests.post(url, files={'file': f}) + return + + +exit_code_serial_port_unresponsive = 100 + +argparser = create_argparser() +args = argparser.parse_args() +logger = initialize_logging() + +serial_port = serial_port_with_live_mtr( + args.serial_port, + polling_timeout_secs=args.serial_port_polling_timeout, + retry_wait_time_secs=5, + serial_timeout_secs=3) +if serial_port is None: + logger.info( + "Serial port is unresponsive, exiting... (status=%d)", + exit_code_serial_port_unresponsive) + sys.exit(exit_code_serial_port_unresponsive) + +mtr_reader = mtrreader.MtrReader(serial_port) +destination_args = args.destination +dropbox_api_token = None +output_filename = ( + args.output_file_name.format(datetime.now().strftime('%Y%m%dT%H%M%S'))) + +mtr_reader.send_spool_all_command() +data_messages = mtr_reader.receive() +datetime_extracted = datetime.now() +log_lines = mtrlog.MtrLogFormatter().format_all( + data_messages, datetime_extracted) +mtr_log_file_name = write_mtr_log_file(log_lines, output_filename) diff --git a/mtrlog.py b/mtrlog.py new file mode 100644 index 0000000..26e8e38 --- /dev/null +++ b/mtrlog.py @@ -0,0 +1,47 @@ +import logging + +logger = logging.getLogger() + + +class MtrLogFormatter: + + def format_all(self, data_messages, datetime_extracted): + log_lines = [] + for data_message in data_messages: + log_lines.append(self.format(data_message, datetime_extracted)) + return log_lines + + def format(self, msg, datetime_extracted): + log_line = [] + log_line.append('"M"') + log_line.append('"0"') + log_line.append('"%d"' % msg.mtr_id()) + log_line.append('"%06d"' % msg.card_id()) + print('"%06d"' % msg.card_id()) + + log_line.append( + '"%s"' % datetime_extracted.strftime('%d.%m.%y %H:%M:%S.000')) + log_line.append( + '"%02d.%02d.%02d %02d:%02d:%02d.%03d"' % ( + msg.timestamp_day(), + msg.timestamp_month(), + msg.timestamp_year(), + msg.timestamp_hours(), + msg.timestamp_minutes(), + msg.timestamp_seconds(), + msg.timestamp_milliseconds())) + log_line.append('%06d' % msg.card_id()) + log_line.append('%04d' % 0) # skipped product week + log_line.append('%04d' % 0) # skipped product year + controls = [] + for (control_code, time_at_control) in msg.splits(): + log_line.append('%03d' % control_code) + controls.append('%03d' % control_code) + + log_line.append('%05d' % time_at_control) + print(controls) + log_line.append('%07d' % msg.packet_num()) + + log_line_str = ",".join(log_line) + logger.info("Converted message to log line format: %s", log_line_str) + return log_line_str diff --git a/mtrreader.py b/mtrreader.py new file mode 100644 index 0000000..7173fe4 --- /dev/null +++ b/mtrreader.py @@ -0,0 +1,276 @@ +# From http://ttime.no/rs232.pdf +# +# MESSAGE DESCRIPTION: +# ==================== +# +# MTR--datamessage +# --------------- +# Fieldname # bytes +# Preamble 4 FFFFFFFF(hex) (4 "FF"'s never occur "inside" a message). +# (Can be used to "resynchronize" logic if a connection is +# broken) +# Package-size 1 number of bytes excluding preamble (=230) +# Package-type 1 'M' as "MTR-datamessage" +# MTR-id 2 Serial number of MTR2; Least significant byte first +# Timestamp 6 Binary Year, Month, Day, Hour, Minute, Second +# TS-milliseconds 2 Milliseconds NOT YET USED, WILL BE 0 IN THIS VERSION +# Package# 4 Binary Counter, from 1 and up; Least sign byte first +# Card-id 3 Binary, Least sign byte first +# Producweek 1 0-53 ; 0 when package is retrived from "history" +# Producyear 1 94-99,0-..X ; 0 when package is retrived from "history" +# ECardHeadSum 1 Headchecksum from card; 0 when package is retrived from +# "history" +# The following fields are repeated 50 times: +# CodeN 1 ControlCode; unused positions have 0 +# TimeN 2 Time binary seconds. Least sign. first, Most sign. last; +# unused:0 +# ASCII-string 56 Various info depending on ECard-type; 20h (all spaces) +# when retr. from "history" (See ASCII-String) +# Checksum 1 Binary SUM (MOD 256) of all bytes including Preamble +# NULL-Filler 1 Binary 0 (to avoid potential 5 FF's. Making it easier to +# hunt PREAMBLE +# --------------------------------------- +# Size 234 +# +# Status-message +# -------------- +# Fieldname # bytes +# Preamble 4 FFFFFFFF(hex) (FFFFFFFF never occur elsewhere within +# a frame). +# Package-size 1 number of bytes excluding preamble (=55) +# Package-type 1 'S' as "Status-message" (0x53) +# MTR-id 2 Serial number of MTR2. +# CurrentTime 6 Binary Year, Month, Day, Hour, Minute, Second +# CurrentMilliseconds 2 Milliseconds NOT YET USED, WILL BE 0 IN THIS VERSION +# BatteryStatus 1 1 if battery low. 0 if battery OK. +# RecentPackage# 4 if this is 0, then ALL following # should be ignored! +# OldestPackage# 4 note: If RecentPack==0 then this is still 1! meaning: +# Number of packages in MTR is +# "RecentPackage# - OldestPackage# + 1" +# CurrentSessionStart# 4 Current session is from here to RecentPackage +# (if NOT = 0) +# Prev1SessStart# 4 Prev session was from Prev1SessStart# to +# CurrentSessionStart# - 1 +# Prev2SessStart# 4 +# Prev3SessStart# 4 +# Prev4SessStart# 4 +# Prev5SessStart# 4 +# Prev6SessStart# 4 +# Prev7SessStart# 4 +# Checksum 1 Binary SUM (MOD 256) of all bytes including Preamble +# NULL-Filler 1 Binary 0 (to avoid potential 5 FF's. Making it easier +# to hunt PREAMBLE +# --------------------------------------- +# Size 59 + +import logging + +logger = logging.getLogger() + + +def extend_with(old_items, new_items): + old_items.extend(new_items) + return new_items + + +def checksum_of(message_bytes): + return sum(message_bytes) % 256 + + +class MtrReader: + + def __init__(self, serial_port): + self.serial_port = serial_port + + def send_status_command(self): + self.serial_port.write(b'/ST') + + def send_spool_all_command(self): + self.serial_port.write(b'/SA') + + def receive(self): + messages = [] + timed_out = False + PREAMBLE = b'\xFF\xFF\xFF\xFF' + while not timed_out: + preamble_buffer = bytearray() + while preamble_buffer != PREAMBLE: + if len(preamble_buffer) == len(PREAMBLE): + # make room for incoming byte + preamble_buffer.pop(0) + + bytes_read_waiting = self.serial_port.read() + timed_out = len(bytes_read_waiting) == 0 + if timed_out: + logger.debug( + 'Timed out, returning %d messages', len(messages)) + return messages + + preamble_buffer.extend(bytes_read_waiting) + logger.debug( + 'Byte read waiting (hex): %s ' + '(current preamble buffer: %s)', + bytes_read_waiting.hex(), + preamble_buffer.hex()) + + logger.debug('Saw preable, start package parsing') + message_bytes = bytearray() + message_bytes.extend(preamble_buffer) + + package_size_numbytes = 1 + package_type_numbytes = 1 + package_size = int.from_bytes( + extend_with( + message_bytes, + self.serial_port.read(package_size_numbytes)), + 'little') + package_type = int.from_bytes( + extend_with( + message_bytes, + self.serial_port.read(package_type_numbytes)), + 'little') + + num_remaining_bytes_expected = ( + package_size + - package_size_numbytes + - package_type_numbytes) + remaining_bytes = self.serial_port.read( + num_remaining_bytes_expected) + if len(remaining_bytes) < num_remaining_bytes_expected: + logger.warning('Did not receive expected number of bytes') + continue + message_bytes.extend(remaining_bytes) + + msg = None + if (package_type == ord('M')): + msg = MtrDataMessage(message_bytes) + elif package_type == ord('S'): + msg = MtrStatusMessage(message_bytes) + else: + logger.warning('Got unsupported package type %d', package_type) + continue + + logger.info( + "Got message number %d (hex): %s", + len(messages) + 1, message_bytes.hex()) + if not msg.is_checksum_valid(): + logger.warning("Message has incorrect checksum") + continue + + messages.append(msg) + + return messages + + +class MtrStatusMessage: + + def __init__(self, message_bytes): + self.message_bytes = message_bytes + + def mtr_id(self): + return int.from_bytes(self.message_bytes[6:8], 'little') + + def timestamp_year(self): + return int.from_bytes(self.message_bytes[8:9], 'little') + + def timestamp_month(self): + return int.from_bytes(self.message_bytes[9:10], 'little') + + def timestamp_day(self): + return int.from_bytes(self.message_bytes[10:11], 'little') + + def timestamp_hours(self): + return int.from_bytes(self.message_bytes[11:12], 'little') + + def timestamp_minutes(self): + return int.from_bytes(self.message_bytes[12:13], 'little') + + def timestamp_seconds(self): + return int.from_bytes(self.message_bytes[13:14], 'little') + + def timestamp_milliseconds(self): + return int.from_bytes(self.message_bytes[14:16], 'little') + + def battery_status(self): + return int.from_bytes(self.message_bytes[16:17], 'little') + + # package number fields not supported (yet) + + def is_checksum_valid(self): + checksum = int.from_bytes(self.message_bytes[57:58], 'little') + # calculate checksum for message bytes up until checksum + calculated_checksum = checksum_of(self.message_bytes[:57]) + logger.debug( + "Calculated checksum %d, read %d", + calculated_checksum, checksum) + return checksum == calculated_checksum + + +class MtrDataMessage: + + def __init__(self, message_bytes): + self.message_bytes = message_bytes + + def mtr_id(self): + return int.from_bytes(self.message_bytes[6:8], 'little') + + def timestamp_year(self): + return int.from_bytes(self.message_bytes[8:9], 'little') + + def timestamp_month(self): + return int.from_bytes(self.message_bytes[9:10], 'little') + + def timestamp_day(self): + return int.from_bytes(self.message_bytes[10:11], 'little') + + def timestamp_hours(self): + return int.from_bytes(self.message_bytes[11:12], 'little') + + def timestamp_minutes(self): + return int.from_bytes(self.message_bytes[12:13], 'little') + + def timestamp_seconds(self): + return int.from_bytes(self.message_bytes[13:14], 'little') + + def timestamp_milliseconds(self): + return int.from_bytes(self.message_bytes[14:16], 'little') + + def packet_num(self): + return int.from_bytes(self.message_bytes[16:20], 'little') + + def card_id(self): + return int.from_bytes(self.message_bytes[20:23], 'little') + + # product week (1 byte) + # product year (1 byte) + # ecard head checksum (1 byte) + + def splits(self): + splits = [] + splits_offset = 26 + code_numbytes = 1 + time_numbytes = 2 + split_numbytes = code_numbytes + time_numbytes + for split_index in range(50): + code_offset = splits_offset + split_index * split_numbytes + time_offset = code_offset + code_numbytes + code = int.from_bytes( + self.message_bytes[code_offset:code_offset+code_numbytes], + 'little') + time = int.from_bytes( + self.message_bytes[time_offset:time_offset+time_numbytes], + 'little') + splits.append((code, time)) + return splits + + def ascii_string(self): + return self.message_bytes[176:232].decode('ascii') + + def is_checksum_valid(self): + checksum = int.from_bytes(self.message_bytes[232:233], 'little') + # calculate checksum for message bytes up until checksum + calculated_checksum = checksum_of(self.message_bytes[:232]) + logger.debug( + "Calculated checksum %d, read %d", + calculated_checksum, checksum) + return checksum == calculated_checksum diff --git a/serial_async_test.py b/serial_async_test.py new file mode 100644 index 0000000..09f858e --- /dev/null +++ b/serial_async_test.py @@ -0,0 +1,41 @@ +import asyncio +import serial_asyncio +from rich.console import Console +from rich import inspect +from datetime import datetime + +import mtrreader +import mtrlog + +class OutputProtocol(asyncio.Protocol): + def connection_made(self, transport): + self.transport = transport + print('port opened', transport) + transport.serial.rts = False # You can manipulate Serial object via transport + transport.write(b'Hello, World!\n') # Write serial data via transport + + def data_received(self, data): + print('data received', repr(data)) + msg = mtrreader.MtrDataMessage(data) + inspect(msg) + print(mtrlog.MtrLogFormatter.format(self, msg, datetime.now())) + if b'\n' in data: + self.transport.close() + + def connection_lost(self, exc): + print('port closed') + self.transport.loop.stop() + + def pause_writing(self): + print('pause writing') + print(self.transport.get_write_buffer_size()) + + def resume_writing(self): + print(self.transport.get_write_buffer_size()) + print('resume writing') + +loop = asyncio.get_event_loop() +coro = serial_asyncio.create_serial_connection(loop, OutputProtocol, '/dev/ttyUSB0', baudrate=9600) +transport, protocol = loop.run_until_complete(coro) +loop.run_forever() +loop.close()