From fa51f8fdf20bd5578353009cb49cf4fdf7ed71fb Mon Sep 17 00:00:00 2001 From: Hemna Date: Sat, 19 Dec 2020 16:35:53 -0500 Subject: [PATCH] Big patch This commit adds the new send-message command for sending messages. This also redoes the logging of sent/rx'd packets to a single method which is syncrhonized, so we don't get intermixed log messages for packets. Also adds email address validation during startup, and optionally disables the validation via a command line switch. without email validation for production running aprsd, emails sent can turn up garbage and cause issues when those emails are received by aprsd message processing as invalid content. --- aprsd/email.py | 45 ++++++++++++++- aprsd/main.py | 103 ++++++++++++++++++++++++++++++--- aprsd/messaging.py | 132 +++++++++++++++++++++++++++++++++++++------ aprsd/plugin.py | 7 ++- aprsd/utils.py | 13 +++++ dev-requirements.txt | 5 +- requirements.in | 1 + requirements.txt | 6 +- tests/test_main.py | 3 +- 9 files changed, 280 insertions(+), 35 deletions(-) diff --git a/aprsd/email.py b/aprsd/email.py index 5f27f86..8c270a1 100644 --- a/aprsd/email.py +++ b/aprsd/email.py @@ -10,6 +10,7 @@ from email.mime.text import MIMEText import imapclient import six +from validate_email import validate_email from aprsd import messaging @@ -83,7 +84,43 @@ def _smtp_connect(): return server -def validate_email(): +def validate_shortcuts(config): + shortcuts = config.get("shortcuts", None) + if not shortcuts: + return + + LOG.info( + "Validating {} Email shortcuts. This can take up to 10 seconds" + " per shortcut".format(len(shortcuts)) + ) + delete_keys = [] + for key in shortcuts: + is_valid = validate_email( + email_address=shortcuts[key], + check_regex=True, + check_mx=True, + from_address=config["smtp"]["login"], + helo_host=config["smtp"]["host"], + smtp_timeout=10, + dns_timeout=10, + use_blacklist=False, + debug=False, + ) + if not is_valid: + LOG.error( + "'{}' is an invalid email address. Removing shortcut".format( + shortcuts[key] + ) + ) + delete_keys.append(key) + + for key in delete_keys: + del config["shortcuts"][key] + + LOG.info("Available shortcuts: {}".format(config["shortcuts"])) + + +def validate_email_config(config, disable_validation=False): """function to simply ensure we can connect to email services. This helps with failing early during startup. @@ -93,6 +130,12 @@ def validate_email(): LOG.info("Checking SMTP configuration") smtp_server = _smtp_connect() + # Now validate and flag any shortcuts as invalid + if not disable_validation: + validate_shortcuts(config) + else: + LOG.info("Shortcuts email validation is Disabled!!, you were warned.") + if imap_server and smtp_server: return True else: diff --git a/aprsd/main.py b/aprsd/main.py index 51a40bc..e5f8256 100644 --- a/aprsd/main.py +++ b/aprsd/main.py @@ -159,6 +159,7 @@ def setup_logging(config, loglevel, quiet): fh = RotatingFileHandler(log_file, maxBytes=(10248576 * 5), backupCount=4) else: fh = NullHandler() + fh.setFormatter(log_formatter) LOG.addHandler(fh) @@ -190,11 +191,9 @@ def process_packet(packet): else: ack = "0" - LOG.debug(" Received message______________") - LOG.debug(" Raw : {}".format(packet["raw"])) - LOG.debug(" From : {}".format(fromcall)) - LOG.debug(" Message : {}".format(message)) - LOG.debug(" Msg number : {}".format(str(ack))) + messaging.log_message( + "Received Message", packet["raw"], message, fromcall=fromcall, ack=ack + ) found_command = False # Get singleton of the PM @@ -239,7 +238,6 @@ def sample_config(): click.echo(yaml.dump(utils.DEFAULT_CONFIG_DICT)) -# main() ### @main.command() @click.option( "--loglevel", @@ -260,7 +258,96 @@ def sample_config(): default=utils.DEFAULT_CONFIG_FILE, help="The aprsd config file to use for options.", ) -def server(loglevel, quiet, config_file): +@click.option( + "--aprs-login", + envvar="APRS_LOGIN", + show_envvar=True, + help="What callsign to send the message from.", +) +@click.option( + "--aprs-password", + envvar="APRS_PASSWORD", + show_envvar=True, + help="the APRS-IS password for APRS_LOGIN", +) +@click.argument("tocallsign") +@click.argument("command", default="location") +def send_message( + loglevel, quiet, config_file, aprs_login, aprs_password, tocallsign, command +): + """Send a message to a callsign via APRS_IS.""" + click.echo("{} {} {} {}".format(aprs_login, aprs_password, tocallsign, command)) + + click.echo("Load config") + config = utils.parse_config(config_file) + if not aprs_login: + click.echo("Must set --aprs_login or APRS_LOGIN") + return + + if not aprs_password: + click.echo("Must set --aprs-password or APRS_PASSWORD") + return + + config["aprs"]["login"] = aprs_login + config["aprs"]["password"] = aprs_password + messaging.CONFIG = config + + setup_logging(config, loglevel, quiet) + LOG.info("APRSD Started version: {}".format(aprsd.__version__)) + + def rx_packet(packet): + LOG.debug("Got packet back {}".format(packet)) + messaging.log_packet(packet) + resp = packet.get("response", None) + if resp == "ack": + sys.exit(0) + + cl = client.Client(config) + messaging.send_message_direct(tocallsign, command) + + try: + # This will register a packet consumer with aprslib + # When new packets come in the consumer will process + # the packet + aprs_client = client.get_client() + aprs_client.consumer(rx_packet, raw=False) + except aprslib.exceptions.ConnectionDrop: + LOG.error("Connection dropped, reconnecting") + time.sleep(5) + # Force the deletion of the client object connected to aprs + # This will cause a reconnect, next time client.get_client() + # is called + cl.reset() + + +# main() ### +@main.command() +@click.option( + "--loglevel", + default="DEBUG", + show_default=True, + type=click.Choice( + ["CRITICAL", "ERROR", "WARNING", "INFO", "DEBUG"], case_sensitive=False + ), + show_choices=True, + help="The log level to use for aprsd.log", +) +@click.option("--quiet", is_flag=True, default=False, help="Don't log to stdout") +@click.option( + "--disable-validation", + is_flag=True, + default=False, + help="Disable email shortcut validation. Bad email addresses can result in broken email responses!!", +) +@click.option( + "-c", + "--config", + "config_file", + show_default=True, + default=utils.DEFAULT_CONFIG_FILE, + help="The aprsd config file to use for options.", +) +def server(loglevel, quiet, disable_validation, config_file): """Start the aprsd server process.""" signal.signal(signal.SIGINT, signal_handler) @@ -280,7 +367,7 @@ def server(loglevel, quiet, config_file): # TODO(walt): Make email processing/checking optional? # Maybe someone only wants this to process messages with plugins only. - valid = email.validate_email() + valid = email.validate_email_config(config, disable_validation) if not valid: LOG.error("Failed to validate email config options") sys.exit(-1) diff --git a/aprsd/messaging.py b/aprsd/messaging.py index 24d3d55..9877c91 100644 --- a/aprsd/messaging.py +++ b/aprsd/messaging.py @@ -27,10 +27,14 @@ def send_ack_thread(tocall, ack, retry_count): tocall = tocall.ljust(9) # pad to nine chars line = "{}>APRS::{}:ack{}\n".format(CONFIG["aprs"]["login"], tocall, ack) for i in range(retry_count, 0, -1): - LOG.info("Sending ack __________________ Tx({})".format(i)) - LOG.info("Raw : {}".format(line.rstrip("\n"))) - LOG.info("To : {}".format(tocall)) - LOG.info("Ack number : {}".format(ack)) + log_message( + "Sending ack", + line.rstrip("\n"), + None, + ack=ack, + tocall=tocall, + retry_number=i, + ) cl.sendall(line) # aprs duplicate detection is 30 secs? # (21 only sends first, 28 skips middle) @@ -60,15 +64,13 @@ def send_message_thread(tocall, message, this_message_number, retry_count): LOG.debug("DEBUG: send_message_thread msg:ack combos are: ") LOG.debug(pprint.pformat(ack_dict)) if ack_dict[this_message_number] != 1: - LOG.info( - "Sending message_______________ {}(Tx{})".format( - str(this_message_number), str(i) - ) + log_message( + "Sending Message", + line.rstrip("\n"), + message, + tocall=tocall, + retry_number=i, ) - LOG.info("Raw : {}".format(line.rstrip("\n"))) - LOG.info("To : {}".format(tocall)) - # LOG.info("Message : {}".format(message.encode(errors='ignore'))) - LOG.info("Message : {}".format(message)) # tn.write(line) cl.sendall(line) # decaying repeats, 31 to 93 second intervals @@ -118,6 +120,104 @@ def send_message(tocall, message): # end send_message() +def log_packet(packet): + fromcall = packet.get("from", None) + tocall = packet.get("to", None) + + response_type = packet.get("response", None) + msg = packet.get("message_text", None) + msg_num = packet.get("msgNo", None) + ack = packet.get("ack", None) + + log_message( + "Packet", + packet["raw"], + msg, + fromcall=fromcall, + tocall=tocall, + ack=ack, + packet_type=response_type, + msg_num=msg_num, + ) + + +def log_message( + header, + raw, + message, + tocall=None, + fromcall=None, + msg_num=None, + retry_number=None, + ack=None, + packet_type=None, +): + """ + + Log a message entry. + + This builds a long string with newlines for the log entry, so that + it's thread safe. If we log each item as a separate log.debug() call + Then the message information could get multiplexed with other log + messages. Each python log call is automatically synchronized. + + + """ + + log_list = [""] + if retry_number: + # LOG.info(" {} _______________(TX:{})".format(header, retry_number)) + log_list.append(" {} _______________(TX:{})".format(header, retry_number)) + else: + # LOG.info(" {} _______________".format(header)) + log_list.append(" {} _______________".format(header)) + + # LOG.info(" Raw : {}".format(raw)) + log_list.append(" Raw : {}".format(raw)) + + if packet_type: + # LOG.info(" Packet : {}".format(packet_type)) + log_list.append(" Packet : {}".format(packet_type)) + if tocall: + # LOG.info(" To : {}".format(tocall)) + log_list.append(" To : {}".format(tocall)) + if fromcall: + # LOG.info(" From : {}".format(fromcall)) + log_list.append(" From : {}".format(fromcall)) + + if ack: + # LOG.info(" Ack : {}".format(ack)) + log_list.append(" Ack : {}".format(ack)) + else: + # LOG.info(" Message : {}".format(message)) + log_list.append(" Message : {}".format(message)) + if msg_num: + # LOG.info(" Msg number : {}".format(msg_num)) + log_list.append(" Msg number : {}".format(msg_num)) + # LOG.info(" {} _______________ Complete".format(header)) + log_list.append(" {} _______________ Complete".format(header)) + + LOG.info("\n".join(log_list)) + + +def send_message_direct(tocall, message): + """Send a message without a separate thread.""" + cl = client.get_client() + this_message_number = 1 + fromcall = CONFIG["aprs"]["login"] + line = "{}>APRS::{}:{}{{{}\n".format( + fromcall, + tocall, + message, + str(this_message_number), + ) + LOG.debug("DEBUG: send_message_thread msg:ack combos are: ") + log_message( + "Sending Message", line.rstrip("\n"), message, tocall=tocall, fromcall=fromcall + ) + cl.sendall(line) + + def process_message(line): f = re.search("^(.*)>", line) fromcall = f.group(1) @@ -139,11 +239,9 @@ def process_message(line): # ack not requested, but lets send one as 0 ack_num = "0" - LOG.info("Received message______________") - LOG.info("Raw : " + line) - LOG.info("From : " + fromcall) - LOG.info("Message : " + message) - LOG.info("Msg number : " + str(ack_num)) + log_message( + "Received message", line, message, fromcall=fromcall, msg_num=str(ack_num) + ) return (fromcall, message, ack_num) # end process_message() diff --git a/aprsd/plugin.py b/aprsd/plugin.py index b5b83f8..6b88b7c 100644 --- a/aprsd/plugin.py +++ b/aprsd/plugin.py @@ -286,6 +286,7 @@ class LocationPlugin(APRSDPluginBase): response = requests.get(url) # aprs_data = json.loads(response.read()) aprs_data = json.loads(response.text) + LOG.debug("LocationPlugin: aprs_data = {}".format(aprs_data)) lat = aprs_data["entries"][0]["lat"] lon = aprs_data["entries"][0]["lng"] try: # altitude not always provided @@ -294,9 +295,9 @@ class LocationPlugin(APRSDPluginBase): alt = 0 altfeet = int(alt * 3.28084) aprs_lasttime_seconds = aprs_data["entries"][0]["lasttime"] - aprs_lasttime_seconds = aprs_lasttime_seconds.encode( - "ascii", errors="ignore" - ) # unicode to ascii + # aprs_lasttime_seconds = aprs_lasttime_seconds.encode( + # "ascii", errors="ignore" + # ) # unicode to ascii delta_seconds = time.time() - int(aprs_lasttime_seconds) delta_hours = delta_seconds / 60 / 60 url2 = ( diff --git a/aprsd/utils.py b/aprsd/utils.py index 6259f4b..6d7970b 100644 --- a/aprsd/utils.py +++ b/aprsd/utils.py @@ -1,8 +1,10 @@ """Utilities and helper functions.""" import errno +import functools import os import sys +import threading import click import yaml @@ -47,6 +49,17 @@ DEFAULT_CONFIG_DICT = { DEFAULT_CONFIG_FILE = "~/.config/aprsd/aprsd.yml" +def synchronized(wrapped): + lock = threading.Lock() + + @functools.wraps(wrapped) + def _wrap(*args, **kwargs): + with lock: + return wrapped(*args, **kwargs) + + return _wrap + + def env(*vars, **kwargs): """This returns the first environment variable set. if none are non-empty, defaults to '' or keyword arg default diff --git a/dev-requirements.txt b/dev-requirements.txt index be5c5e4..087a674 100644 --- a/dev-requirements.txt +++ b/dev-requirements.txt @@ -37,10 +37,10 @@ pyflakes==2.2.0 # via flake8 pygments==2.7.3 # via sphinx pyparsing==2.4.7 # via packaging pytest-cov==2.10.1 # via -r dev-requirements.in -pytest==6.2.0 # via -r dev-requirements.in, pytest-cov +pytest==6.2.1 # via -r dev-requirements.in, pytest-cov pytz==2020.4 # via babel regex==2020.11.13 # via black -requests>=2.25.0 # via sphinx +requests==2.25.1 # via sphinx six==1.15.0 # via tox, virtualenv snowballstemmer==2.0.0 # via sphinx sphinx==3.3.1 # via -r dev-requirements.in @@ -50,7 +50,6 @@ sphinxcontrib-htmlhelp==1.0.3 # via sphinx sphinxcontrib-jsmath==1.0.1 # via sphinx sphinxcontrib-qthelp==1.0.3 # via sphinx sphinxcontrib-serializinghtml==1.1.4 # via sphinx -thesmuggler==1.0.1 # via -r dev-requirements.in toml==0.10.2 # via black, pytest, tox tox==3.20.1 # via -r dev-requirements.in typed-ast==1.4.1 # via black, mypy diff --git a/requirements.in b/requirements.in index 63e1739..3d89156 100644 --- a/requirements.in +++ b/requirements.in @@ -8,3 +8,4 @@ six requests thesmuggler aprslib +py3-validate-email diff --git a/requirements.txt b/requirements.txt index 87fbd06..ba02e11 100644 --- a/requirements.txt +++ b/requirements.txt @@ -9,14 +9,16 @@ certifi==2020.12.5 # via requests chardet==4.0.0 # via requests click-completion==0.5.2 # via -r requirements.in click==7.1.2 # via -r requirements.in, click-completion -idna==2.10 # via requests +dnspython==2.0.0 # via py3-validate-email +filelock==3.0.12 # via py3-validate-email +idna==2.10 # via py3-validate-email, requests imapclient==2.1.0 # via -r requirements.in jinja2==2.11.2 # via click-completion markupsafe==1.1.1 # via jinja2 pbr==5.5.1 # via -r requirements.in pluggy==0.13.1 # via -r requirements.in +py3-validate-email==0.2.12 # via -r requirements.in pyyaml==5.3.1 # via -r requirements.in -requests>=2.25.0 # via -r requirements.in shellingham==1.3.2 # via click-completion six==1.15.0 # via -r requirements.in, click-completion, imapclient thesmuggler==1.0.1 # via -r requirements.in diff --git a/tests/test_main.py b/tests/test_main.py index 68989bf..b6a8b06 100644 --- a/tests/test_main.py +++ b/tests/test_main.py @@ -19,5 +19,6 @@ class testMain(unittest.TestCase): """Test to make sure we fail.""" imap_mock.return_value = None smtp_mock.return_value = {"smaiof": "fire"} + config = mock.MagicMock() - email.validate_email() + email.validate_email_config(config, True)