Merge pull request #201 from Holzhaus/add-more-logging

Add more logging

4 files changed, 33 insertions, 8 deletions

diff --git a/client/brain.py b/client/brain.py
index 6daa366..d905853 100644
--- a/client/brain.py
+++ b/client/brain.py
@@ -61,13 +61,15 @@ class Brain(object):
         """
         for module in self.modules:
             for text in texts:
-
                 if module.isValid(text):
+                    self._logger.debug("'%s' is a valid phrase for module '%s'", text, module.__name__)
                     try:
                         module.handle(text, self.mic, self.profile)
-                        return
                     except:
                         self._logger.error('Failed to execute module', exc_info=True)
-                        self.mic.say(
-                            "I'm sorry. I had some trouble with that operation. Please try again later.")
+                        self.mic.say("I'm sorry. I had some trouble with that operation. Please try again later.")
+                    else:
+                        self._logger.debug("Handling of phrase '%s' by module '%s' completed", text, module.__name__)
+                    finally:
                         return
+        self._logger.debug("No module was able to handle any of these phrases: %r", texts)
diff --git a/client/conversation.py b/client/conversation.py
index 8ec912c..0746b7f 100644
--- a/client/conversation.py
+++ b/client/conversation.py
@@ -1,4 +1,5 @@
 # -*- coding: utf-8-*-
+import logging
 from notifier import Notifier
 from musicmode import *
 from brain import Brain
@@ -8,6 +9,7 @@ from mpd import MPDClient
 class Conversation(object):
 
     def __init__(self, persona, mic, profile):
+        self._logger = logging.getLogger(__name__)
         self.persona = persona
         self.mic = mic
         self.profile = profile
@@ -20,6 +22,7 @@ class Conversation(object):
         # check if input is meant to start the music module
         for text in texts:
             if any(x in text.upper() for x in ["SPOTIFY", "MUSIC"]):
+                self._logger.debug("Preparing to start music module")
                 # check if mpd client is running
                 try:
                     client = MPDClient()
@@ -27,31 +30,42 @@ class Conversation(object):
                     client.idletimeout = None
                     client.connect("localhost", 6600)
                 except:
+                    self._logger.critical("Can't connect to mpd client, cannot start music mode.", exc_info=True)
                     self.mic.say(
                         "I'm sorry. It seems that Spotify is not enabled. Please read the documentation to learn how to configure Spotify.")
                     return
 
                 self.mic.say("Please give me a moment, I'm loading your Spotify playlists.")
+                self._logger.debug("Starting music mode")
                 music_mode = MusicMode(self.persona, self.mic)
                 music_mode.handleForever()
+                self._logger.debug("Exiting music mode")
                 return
 
         self.brain.query(texts)
 
     def handleForever(self):
         """Delegates user input to the handling function when activated."""
+        self._logger.info("Starting to handle conversation with keyword '%s'.", self.persona)
         while True:
-
             # Print notifications until empty
             notifications = self.notifier.getAllNotifications()
             for notif in notifications:
-                print notif
+                self._logger.info("Received notification: '%s'", str(notif))
 
+            self._logger.debug("Started listening for keyword '%s'", self.persona)
             threshold, transcribed = self.mic.passiveListen(self.persona)
+            self._logger.debug("Stopped listening for keyword '%s'", self.persona)
+
             if not transcribed or not threshold:
+                self._logger.info("Nothing has been said or transcribed.")
                 continue
+            self._logger.info("Keyword '%s' has been said!", self.persona)
 
+            self._logger.debug("Started to listen actively with threshold: %r", threshold)
             input = self.mic.activeListenToAllOptions(threshold)
+            self._logger.debug("Stopped to listen actively with threshold: %r", threshold)
+            
             if input:
                 self.delegateInput(input)
             else:
diff --git a/client/notifier.py b/client/notifier.py
index 6911ed5..2ae66f8 100644
--- a/client/notifier.py
+++ b/client/notifier.py
@@ -3,8 +3,6 @@ import Queue
 from modules import Gmail
 from apscheduler.scheduler import Scheduler
 import logging
-logging.basicConfig()
-
 
 class Notifier(object):
 
@@ -18,12 +16,15 @@ class Notifier(object):
             self.timestamp = self.gather(self.timestamp)
 
     def __init__(self, profile):
+        self._logger = logging.getLogger(__name__)
         self.q = Queue.Queue()
         self.profile = profile
         self.notifiers = []
 
         if 'gmail_address' in profile and 'gmail_password' in profile:
             self.notifiers.append(self.NotificationClient(self.handleEmailNotifications, None))
+        else:
+            self._logger.warning('gmail_address or gmail_password not set in profile, Gmail notifier will not be used')
 
         sched = Scheduler()
         sched.start()
diff --git a/client/test.py b/client/test.py
index 23dd619..501fe6f 100644
--- a/client/test.py
+++ b/client/test.py
@@ -3,6 +3,7 @@
 import os
 import sys
 import unittest
+import logging
 import argparse
 from mock import patch, Mock
 from urllib2 import URLError, urlopen
@@ -237,8 +238,15 @@ if __name__ == '__main__':
         description='Test suite for the Jasper client code.')
     parser.add_argument('--light', action='store_true',
                         help='runs a subset of the tests (only requires Python dependencies)')
+    parser.add_argument('--debug', action='store_true',
+                        help='show debug messages')
     args = parser.parse_args()
 
+    logging.basicConfig()
+    logger = logging.getLogger()
+    if args.debug:
+        logger.setLevel(logging.DEBUG)
+
     # Change CWD to jasperpath.LIB_PATH
     os.chdir(jasperpath.LIB_PATH)