diff --git a/main.py b/main.py index 41bc10a..d513f6f 100644 --- a/main.py +++ b/main.py @@ -4,6 +4,7 @@ import sys import datetime import arrow import argparse +import logging from tconnectsync.api import TConnectApi from tconnectsync.process import process_time_range @@ -26,6 +27,7 @@ except Exception: def parse_args(): parser = argparse.ArgumentParser(description="Syncs bolus, basal, and IOB data from Tandem Diabetes t:connect to Nightscout.") parser.add_argument('--pretend', dest='pretend', action='store_const', const=True, default=False, help='Pretend mode: do not upload any data to Nightscout.') + parser.add_argument('-v', '--verbose', dest='verbose', action='store_const', const=True, default=False, help='Verbose mode: show extra logging details') parser.add_argument('--start-date', dest='start_date', type=str, default=None, help='The oldest date to process data from. Must be specified with --end-date.') parser.add_argument('--end-date', dest='end_date', type=str, default=None, help='The newest date to process data until (inclusive). Must be specified with --start-date.') parser.add_argument('--days', dest='days', type=int, default=1, help='The number of days of t:connect data to read in. Cannot be used with --from-date and --until-date.') @@ -37,6 +39,12 @@ def parse_args(): def main(): args = parse_args() + if args.verbose: + logging.basicConfig(level=logging.DEBUG) + logging.root.debug("Set logging level to DEBUG") + else: + logging.basicConfig(level=logging.INFO) + if args.auto_update and (args.start_date or args.end_date): raise Exception('Auto-update cannot be used with start/end date') diff --git a/tconnectsync/api/android.py b/tconnectsync/api/android.py index a178b5b..3f73b1c 100644 --- a/tconnectsync/api/android.py +++ b/tconnectsync/api/android.py @@ -6,11 +6,15 @@ import csv import base64 import arrow import time +import logging from bs4 import BeautifulSoup +from ..util import timeago from .common import ApiException, ApiLoginException +logger = logging.getLogger(__name__) + """ The AndroidApi class contains methods which are queried in the t:connect Android application. These methods are a part of the tdc API which require @@ -67,6 +71,8 @@ class AndroidApi: self.userId = j["user"]["id"] self.patientObjectId = j["user"]["patientObjectId"] + logger.info("Logged in to AndroidApi successfully (expiration: %s, %s)" % (self.accessTokenExpiresAt, timeago(self.accessTokenExpiresAt))) + def needs_relogin(self): diff = (arrow.get(self.accessTokenExpiresAt) - arrow.get()) return (diff.seconds <= 5 * 60) diff --git a/tconnectsync/api/controliq.py b/tconnectsync/api/controliq.py index fb8544c..69bcd3e 100644 --- a/tconnectsync/api/controliq.py +++ b/tconnectsync/api/controliq.py @@ -7,6 +7,7 @@ import logging from bs4 import BeautifulSoup +from ..util import timeago from .common import parse_date, base_headers, ApiException, ApiLoginException logger = logging.getLogger(__name__) @@ -43,6 +44,7 @@ class ControlIQApi: self.userGuid = req.cookies['UserGUID'] self.accessToken = req.cookies['accessToken'] self.accessTokenExpiresAt = req.cookies['accessTokenExpiresAt'] + logger.info("Logged in to ControlIQApi successfully (expiration: %s, %s)" % (self.accessTokenExpiresAt, timeago(self.accessTokenExpiresAt))) return True def _build_login_data(self, email, password, soup): diff --git a/tconnectsync/api/ws2.py b/tconnectsync/api/ws2.py index ae8c52d..150d44f 100644 --- a/tconnectsync/api/ws2.py +++ b/tconnectsync/api/ws2.py @@ -2,6 +2,7 @@ import requests import datetime import csv import logging +import time from .common import parse_date, base_headers, ApiException @@ -66,9 +67,12 @@ class WS2Api: try: req_text = self.get('therapytimeline2csv/%s/%s/%s?format=csv' % (self.userGuid, startDate, endDate), {}) except ApiException as e: + # This seems to occur as some kind of soft rate-limit. logger.warn("Received ApiException in therapy_timeline_csv: (retry count %d) %s" % (tries, e)) if e.status_code == 500: - logger.error("HTTP 500 in therapy_timeline_csv (retry count %d): %s" % (tries, e)) + sleep_seconds = (tries+1) * 60 + logger.error("Retrying in %d seconds after HTTP 500 in therapy_timeline_csv (retry count %d): %s" % (sleep_seconds, tries, e)) + time.sleep(sleep_seconds) if tries < self.MAX_RETRIES: return self.therapy_timeline_csv(start, end, tries+1) raise e diff --git a/tconnectsync/autoupdate.py b/tconnectsync/autoupdate.py index 87f3956..b3d914b 100644 --- a/tconnectsync/autoupdate.py +++ b/tconnectsync/autoupdate.py @@ -6,7 +6,9 @@ from .secret import ( PUMP_SERIAL_NUMBER, AUTOUPDATE_DEFAULT_SLEEP_SECONDS, AUTOUPDATE_MAX_SLEEP_SECONDS, - AUTOUPDATE_USE_FIXED_SLEEP + AUTOUPDATE_USE_FIXED_SLEEP, + AUTOUPDATE_FAILURE_MINUTES, + AUTOUPDATE_RESTART_ON_FAILURE ) logger = logging.getLogger(__name__) @@ -34,9 +36,13 @@ def process_auto_update(tconnect, nightscout, time_start, time_end, pretend): else: added = process_time_range(tconnect, nightscout, time_start, time_end, pretend) logger.info('Added %d items from process_time_range' % added) - if len(added) == 0 and last_event_index: - logger.error('An event index change was recorded, but no new data was found via the API.') - logger.error('If this error reoccurs, try restarting tconnectsync.') + if len(added) == 0: + if last_event_index: + logger.error('An event index change was recorded, but no new data was found via the API. ' + + 'If this error reoccurs, try restarting tconnectsync.') + else: + last_process_time_range = now + if last_event_index: time_diffs.append(now - last_event_time) @@ -46,6 +52,21 @@ def process_auto_update(tconnect, nightscout, time_start, time_end, pretend): last_event_time = now else: logger.info('No new reported t:connect data. (last event index: %d)' % last_event['maxPumpEventIndex']) + now = time.time() + + if (now - last_event_time) >= 60 * AUTOUPDATE_FAILURE_MINUTES: + logger.error("No new data event indexes have been detected for over %d minutes. " % AUTOUPDATE_FAILURE_MINUTES + + "The t:connect app might no longer be functioning.") + + if AUTOUPDATE_RESTART_ON_FAILURE: + raise AutoupdateFailureException + elif (now - last_process_time_range) >= 60 * AUTOUPDATE_FAILURE_MINUTES: + logger.error("No new data has been found via the API for over %d minutes. " % AUTOUPDATE_FAILURE_MINUTES + + "tconnectsync might not be functioning properly.") + + if AUTOUPDATE_RESTART_ON_FAILURE: + raise AutoupdateFailureException + if len(time_diffs) > 2: logger.info('Sleeping 60 seconds after unexpected no index change. (New data might be delayed.)') @@ -65,4 +86,7 @@ def process_auto_update(tconnect, nightscout, time_start, time_end, pretend): # Sleep for a rolling average of time between updates logger.info('Sleeping for %d sec' % sleep_secs) - time.sleep(sleep_secs) \ No newline at end of file + time.sleep(sleep_secs) + +class AutoupdateFailureException(RuntimeError): + pass \ No newline at end of file diff --git a/tconnectsync/process.py b/tconnectsync/process.py index 8b98f84..17eddaf 100644 --- a/tconnectsync/process.py +++ b/tconnectsync/process.py @@ -1,6 +1,9 @@ import logging import datetime +import arrow +import time +from .util import timeago from .api.common import ApiException from .sync.basal import ( process_ciq_basal_events, @@ -15,6 +18,7 @@ from .sync.iob import ( process_iob_events, ns_write_iob_events ) +from .parser.tconnect import TConnectEntry logger = logging.getLogger(__name__) @@ -46,7 +50,10 @@ def process_time_range(tconnect, nightscout, time_start, time_end, pretend): bolusData = csvdata["bolusData"] if readingData and len(readingData) > 0: - logger.info("Last CGM reading from t:connect: %s" % (readingData[-1]['EventDateTime'] if 'EventDateTime' in readingData[-1] else readingData)) + lastReading = readingData[-1]['EventDateTime'] if 'EventDateTime' in readingData[-1] else 0 + lastReading = TConnectEntry._datetime_parse(lastReading) + logger.debug(readingData[-1]) + logger.info("Last CGM reading from t:connect: %s (%s)" % (lastReading, timeago(lastReading))) else: logger.warn("No last CGM reading is able to be determined") diff --git a/tconnectsync/secret.py b/tconnectsync/secret.py index 0e9f736..51e86e1 100644 --- a/tconnectsync/secret.py +++ b/tconnectsync/secret.py @@ -15,6 +15,9 @@ def get_number(name, default): print("Current value: %s" % val) sys.exit(1) +def get_bool(name, default): + return str(get(name, default) or '').lower() in ('true', '1') + TCONNECT_EMAIL = get('TCONNECT_EMAIL', 'email@email.com') TCONNECT_PASSWORD = get('TCONNECT_PASSWORD', 'password') @@ -27,14 +30,17 @@ TIMEZONE_NAME = get('TIMEZONE_NAME', 'America/New_York') # Optional configuration -AUTOUPDATE_DEFAULT_SLEEP_SECONDS = get_number('AUTOUPDATE_DEFAULT_SLEEP_SECONDS', '60') -AUTOUPDATE_MAX_SLEEP_SECONDS = get_number('AUTOUPDATE_MAX_SLEEP_SECONDS', '600') -AUTOUPDATE_USE_FIXED_SLEEP = get_number('AUTOUPDATE_USE_FIXED_SLEEP', '0') +AUTOUPDATE_DEFAULT_SLEEP_SECONDS = get_number('AUTOUPDATE_DEFAULT_SLEEP_SECONDS', '300') # 5 minutes +AUTOUPDATE_MAX_SLEEP_SECONDS = get_number('AUTOUPDATE_MAX_SLEEP_SECONDS', '1500') # 25 minutes +AUTOUPDATE_USE_FIXED_SLEEP = get_bool('AUTOUPDATE_USE_FIXED_SLEEP', 'false') +AUTOUPDATE_FAILURE_MINUTES = get_number('AUTOUPDATE_FAILURE_MINUTES', '180') # 3 hours +AUTOUPDATE_RESTART_ON_FAILURE = get_bool('AUTOUPDATE_RESTART_ON_FAILURE', 'false') _config = ['TCONNECT_EMAIL', 'TCONNECT_PASSWORD', 'PUMP_SERIAL_NUMBER', 'NS_URL', 'NS_SECRET', 'TIMEZONE_NAME', 'AUTOUPDATE_DEFAULT_SLEEP_SECONDS', 'AUTOUPDATE_MAX_SLEEP_SECONDS', - 'AUTOUPDATE_USE_FIXED_SLEEP'] + 'AUTOUPDATE_USE_FIXED_SLEEP', 'AUTOUPDATE_FAILURE_MINUTES', + 'AUTOUPDATE_RESTART_ON_FAILURE'] if __name__ == '__main__': for k in locals(): diff --git a/tconnectsync/sync/basal.py b/tconnectsync/sync/basal.py index 31e420f..f11b624 100644 --- a/tconnectsync/sync/basal.py +++ b/tconnectsync/sync/basal.py @@ -62,6 +62,7 @@ def add_csv_basal_events(basalEvents, data): Given processed basal data, adds basal events to Nightscout. """ def ns_write_basal_events(nightscout, basalEvents, pretend=False): + logger.debug("ns_write_basal_events: querying for last uploaded entry") last_upload = nightscout.last_uploaded_entry(BASAL_EVENTTYPE) last_upload_time = None if last_upload: diff --git a/tconnectsync/sync/bolus.py b/tconnectsync/sync/bolus.py index c5ada49..0357f30 100644 --- a/tconnectsync/sync/bolus.py +++ b/tconnectsync/sync/bolus.py @@ -34,6 +34,7 @@ def process_bolus_events(bolusdata): Given processed bolus data, adds bolus events to Nightscout. """ def ns_write_bolus_events(nightscout, bolusEvents, pretend=False): + logger.debug("ns_write_bolus_events: querying for last uploaded entry") last_upload = nightscout.last_uploaded_entry(BOLUS_EVENTTYPE) last_upload_time = None if last_upload: diff --git a/tconnectsync/sync/iob.py b/tconnectsync/sync/iob.py index c430a19..f1f1134 100644 --- a/tconnectsync/sync/iob.py +++ b/tconnectsync/sync/iob.py @@ -25,6 +25,7 @@ def process_iob_events(iobdata): Given processed IOB data, creates a single Nightscout activity definition to store IOB. """ def ns_write_iob_events(nightscout, iobEvents, pretend=False): + logger.debug("ns_write_iob_events: querying for last uploaded entry") last_upload = nightscout.last_uploaded_activity(IOB_ACTIVITYTYPE) last_upload_time = None if last_upload: diff --git a/tconnectsync/util/__init__.py b/tconnectsync/util/__init__.py new file mode 100644 index 0000000..ec28b14 --- /dev/null +++ b/tconnectsync/util/__init__.py @@ -0,0 +1,17 @@ +import arrow + +def timeago(timestamp): + seconds = (arrow.get() - arrow.get(timestamp)).total_seconds() + fmt = '%s ago' if seconds >= 0 else 'in %s' + seconds = abs(seconds) + + ret = '' + if seconds//86400 > 0: + ret += '%d days, ' % (seconds//86400) + seconds = seconds % 86400 + if seconds//3600 > 0: + ret += '%d hours, ' % (seconds//3600) + seconds = seconds % 3600 + ret += '%d minutes' % (seconds//60) + + return fmt % ret