Add logging to project

bulk_reminders/api.py

@@ -1,9 +1,9 @@
 from __future__ import print_function
 
 import datetime
+import logging
 import os.path
 import re
-import traceback
 from typing import Any, Iterator, List, Optional, Tuple, Union
 
 from PyQt5 import QtGui
@@ -23,49 +23,62 @@ TIME_REGEX = re.compile(r'\d{2}:\d{2}(?:AM|PM)')
 DATE_FORMAT = '%Y-%m-%d'
 DATETIME_FORMAT = DATE_FORMAT + ' %H:%M%p'
 
+logger = logging.getLogger(__file__)
+logger.setLevel(logging.DEBUG)
+
 
 class Calendar(object):
+    TOKEN_FILE = 'token.json'
+
     def __init__(self) -> None:
         self.credentials: Optional[Credentials] = None
         self.service: Optional[Resource] = None
 
     def save_token(self) -> None:
         """Store the credentials for later use."""
-        with open('token.json', 'w') as token:
+        logger.debug('Saving token to token.json')
+        with open(Calendar.TOKEN_FILE, 'w') as token:
             token.write(self.credentials.to_json())
 
     def authenticate_via_token(self) -> bool:
         """Attempt to login using the tokens stored in token.json"""
-        if os.path.exists('token.json'):
+        logger.info('Attempting to authenticate via token')
+        if os.path.exists(Calendar.TOKEN_FILE):
             self.credentials = Credentials.from_authorized_user_file('token.json', SCOPES)
             if self.credentials and self.credentials.expired and self.credentials.refresh_token:
                 try:
+                    logger.info('Refreshing token')
                     self.credentials.refresh(Request())
                 except BaseException as e:
-                    traceback.print_exc()
+                    logger.error('Failed to refresh token', exc_info=e)
                     return False
-                self.save_token()
+                else:
+                    logger.info('Successfully authenticated via token')
+                    self.save_token()
             return True
         return False
 
     def authenticate_via_oauth(self) -> bool:
         """Attempt to acquire credentials"""
         try:
-            flow = InstalledAppFlow.from_client_secrets_file(
-                    'credentials.json', SCOPES)
+            flow = InstalledAppFlow.from_client_secrets_file('credentials.json', SCOPES)
             self.credentials = flow.run_local_server(port=0)
-            self.save_token()
         except BaseException as e:
-            traceback.print_exc()
+            logger.error('Failed to authenticate via OAuth 2.0 flow', exc_info=e)
             return False
+        else:
+            self.save_token()
+            return True
 
     def setupService(self) -> None:
         """Setup the Google App Engine API Service for the Calendar API"""
+        logger.debug('Initializing Calendar API Service')
         self.service = build('calendar', 'v3', credentials=self.credentials)
 
     def getCalendars(self) -> Iterator[Any]:
         """Retrieve all calendar data"""
-        page_token = None
+        logger.debug('Retrieving all calendar data')
+        page, page_token = 1, None
         while True:
             calendar_list = self.service.calendarList().list(pageToken=page_token, minAccessRole='writer').execute()
             for entry in calendar_list['items']:
@@ -76,12 +89,16 @@ class Calendar(object):
                 yield entry
 
             # Continue loading more calendars
+            page += 1
             page_token = calendar_list.get('nextPageToken')
             if page_token is None:
                 break
 
+            logger.debug(f'Retrieving page {page} of Calendars')
+
     def getEvents(self, calendarID: str) -> List[Any]:
         """Retrieves up to 2500 events for a given calendar ordered by occurrence that happen in the future."""
+        logger.debug(f'Retrieving all events from Calendar {calendarID}')
         now = datetime.datetime.utcnow().isoformat() + 'Z'  # 'Z' indicates UTC time
         events = self.service.events().list(calendarId=calendarID, timeMin=now,
                                             maxResults=2500, singleEvents=True,

bulk_reminders/gui.py

@@ -1,3 +1,4 @@
+import logging
 from typing import Iterator, List
 
 from PyQt5 import QtCore, QtGui, QtWidgets
@@ -10,12 +11,16 @@ from bulk_reminders.load import LoadDialog
 from bulk_reminders.oauth import OAuthDialog
 from bulk_reminders.undo import IDPair, Stage
 
+logging.basicConfig(format='[%(asctime)s] [%(levelname)s] [%(threadName)s] %(message)s')
+logger = logging.getLogger(__file__)
+logger.setLevel(logging.DEBUG)
 
 class MainWindow(QMainWindow, Ui_MainWindow):
     def __init__(self, *args, **kwargs):
         # Initial UI setup
         super(MainWindow, self).__init__(*args, **kwargs)
         self.setupUi(self)
+        logger.debug('UI Initialized.')
         self.show()
 
         self.calendar = api.Calendar()
@@ -63,6 +68,7 @@ class MainWindow(QMainWindow, Ui_MainWindow):
         self.loadEventsButton.clicked.connect(self.load_events)
         self.cachedLoadText = ''
         self.readyEvents: List[Event] = []
+        self.apiEvents: List[dict] = []
 
         self.populate()
 
@@ -119,6 +125,7 @@ class MainWindow(QMainWindow, Ui_MainWindow):
         self.eventCountLabel.setText(f'{len(self.readyEvents)} ready, {undoable} undoable in {stage} stages, {foreign} foreign ({total})')
 
         self.eventsView.setRowCount(len(events))
+        logger.debug(f'Populating table with {self.eventsView.rowCount()} events.')
         for row, event in enumerate(events):
             event.fill_row(row, self.eventsView)
 
@@ -126,4 +133,5 @@ class MainWindow(QMainWindow, Ui_MainWindow):
     def comboBoxChanged(self, row) -> None:
         """When the Calendar Selection combobox"""
         self.currentCalendarID = self.comboModel.item(row).data()
+        logger.info(f'Switching to Calendar "{self.comboModel.item(row).text()} ({self.currentCalendarID})"')
         self.populate()

bulk_reminders/load.py

@@ -1,3 +1,4 @@
+import logging
 import os
 import re
 from typing import List, Optional
@@ -9,6 +10,9 @@ from PyQt5.QtWidgets import QApplication, QDialog, QLabel
 from bulk_reminders.api import Event
 from bulk_reminders.load_base import Ui_Dialog
 
+logger = logging.getLogger(__file__)
+logger.setLevel(logging.DEBUG)
+
 REGEX = re.compile(
     r'\s*([\w\d\s,.;\'!\[\]()]{1,})\s+\|\s+(\d{4}-\d{2}-\d{2})\s+(\d{1,2}:\d{2}(?:AM|PM))?\s*(\d{4}-\d{2}-\d{2})(\d{1,2}:\d{2}(?:AM|PM))?')
 
@@ -46,6 +50,7 @@ class LoadDialog(QDialog, Ui_Dialog):
         try:
             self.parsed = list(map(Event.parse_raw, results))
         except ValueError:
+            logger.debug('Dialog input has data errors (invalid dates etc.)')
             resultsText += ' Data error.'
         self.eventCountLabel.setText(resultsText)
 

bulk_reminders/oauth.py

@@ -1,3 +1,4 @@
+import logging
 from typing import Callable, Optional
 
 from PyQt5.QtCore import Qt
@@ -5,6 +6,10 @@ from PyQt5.QtWidgets import QDialog
 
 from bulk_reminders.oauth_base import Ui_Dialog
 
+logger = logging.getLogger(__file__)
+logger.setLevel(logging.DEBUG)
+
+
 class OAuthDialog(QDialog, Ui_Dialog):
     def __init__(self, *args, callback: Optional[Callable] = None, **kwargs):
         super(QDialog, self).__init__(*args, **kwargs)
@@ -16,6 +21,7 @@ class OAuthDialog(QDialog, Ui_Dialog):
             callback()
             self.accept()
         else:
+            logger.debug('No callback given for OAuth Dialog; closing immediately.')
             self.reject()
         self._closable = True
 
@@ -23,6 +29,6 @@ class OAuthDialog(QDialog, Ui_Dialog):
         if self.closable:
             super(QDialog, self).closeEvent(evnt)
         else:
+            logger.debug('Ignoring close event.')
             evnt.ignore()
-            self.setWindowState(Qt.WindowMinimized)
-
+            self.setWindowState(Qt.WindowActive)

bulk_reminders/undo.py

@@ -1,9 +1,12 @@
-import json
+import logging
 import os
 from typing import Iterator, List
 
 import jsonpickle
 
+logger = logging.getLogger(__file__)
+logger.setLevel(logging.DEBUG)
+
 
 class HistoryManager(object):
     def __init__(self, file: str) -> None:
@@ -20,11 +23,13 @@ class HistoryManager(object):
 
     def load(self) -> None:
         """Load data from the undo history file"""
+        logger.info('Loading from undo history file.')
         with open(self.file, 'r') as file:
             self.stages = jsonpickle.decode(file.read())
 
     def save(self) -> None:
         """Save data to the undo history file."""
+        logger.info('Saving to undo history file.')
         with open(self.file, 'w') as file:
             file.write(jsonpickle.encode(self.stages))
 
@@ -34,10 +39,10 @@ class HistoryManager(object):
 
     def exists(self, eventID: 'IDPair') -> int:
         """Check if a given Event ID exists anywhere in the undo history data. Returns the stage index or -1 if it wasn't found."""
-        print(f'Checking for {eventID} in undo history')
         for stage in self.stages:
             for undoable in stage.events:
                 if eventID == undoable.eventID:
+                    logger.debug(f'Found Event {eventID} in Stage {stage.index}')
                     return stage.index
         return -1
 
@@ -59,6 +64,7 @@ class HistoryManager(object):
 
     def addStage(self, newStage: 'Stage'):
         """Adds and inserts a new Stage at the start of the history."""
+        logger.debug(f'Adding new stage with {len(newStage)} events.')
         self.stages.insert(0, newStage)
         self.save()
 
@@ -94,4 +100,3 @@ class IDPair(object):
     def __hash__(self):
         """Returns a hash value for the IDPair"""
         return hash((self.calendarID, self.eventID))
-