correctly log exception tracebacks

tests/test_logging.py

@@ -104,3 +104,28 @@ class LoggingTestCase(utils.TestCase):
         self.assertEquals(output[2], u('WakaTime DEBUG Sending heartbeat to api at https://wakatime.com/api/v1/heartbeats'))
         self.assertIn('Python', output[3])
         self.assertIn('response_code', output[4])
+
+    @log_capture()
+    def test_exception_traceback(self, logs):
+        logging.disable(logging.NOTSET)
+
+        response = Response()
+        response.status_code = 0
+        self.patched['wakatime.packages.requests.adapters.HTTPAdapter.send'].return_value = response
+
+        now = u(int(time.time()))
+        entity = 'tests/samples/codefiles/python.py'
+        config = 'tests/samples/configs/good_config.cfg'
+        args = ['--file', entity, '--config', config, '--time', now]
+
+        with utils.mock.patch('wakatime.stats.open') as mock_open:
+            mock_open.side_effect = IOError('FooBar')
+
+            retval = execute(args)
+            self.assertEquals(retval, 102)
+            self.assertEquals(sys.stdout.getvalue(), '')
+            self.assertEquals(sys.stderr.getvalue(), '')
+
+            output = u("\n").join([u(' ').join(x) for x in logs.actual()])
+            self.assertIn(u('WakaTime ERROR Traceback (most recent call last):'), output)
+            self.assertIn(u('IOError: FooBar'), output)

wakatime/logger.py

@@ -11,7 +11,7 @@
 
 import logging
 import os
-import sys
+import traceback
 
 from .compat import u
 try:
@@ -70,8 +70,9 @@ class JsonFormatter(logging.Formatter):
             del data['plugin']
         return CustomEncoder().encode(data)
 
-    def formatException(self, exc_info):
-        return sys.exec_info[2].format_exc()
+
+def traceback_formatter(*args, **kwargs):
+    logging.getLogger('WakaTime').error(traceback.format_exc())
 
 
 def set_log_level(logger, args):
@@ -102,6 +103,9 @@ def setup_logging(args, version):
     handler.setFormatter(formatter)
     logger.addHandler(handler)
 
+    # add custom traceback logging method
+    logger.traceback = traceback_formatter
+
     warnings_formatter = JsonFormatter(datefmt='%Y/%m/%d %H:%M:%S %z')
     warnings_formatter.setup(
         timestamp=args.timestamp,

wakatime/projects/git.py

@@ -44,9 +44,9 @@ class Git(BaseProject):
                     with open(head, 'r', encoding=sys.getfilesystemencoding()) as fh:
                         return u(fh.readline().strip().rsplit('/', 1)[-1])
                 except:
-                    log.exception("Exception:")
+                    log.traceback()
             except IOError:  # pragma: nocover
-                log.exception("Exception:")
+                log.traceback()
         return None
 
     def _project_base(self):

wakatime/projects/mercurial.py

@@ -42,9 +42,9 @@ class Mercurial(BaseProject):
                     with open(branch_file, 'r', encoding=sys.getfilesystemencoding()) as fh:
                         return u(fh.readline().strip().rsplit('/', 1)[-1])
                 except:
-                    log.exception("Exception:")
+                    log.traceback()
             except IOError:  # pragma: nocover
-                log.exception("Exception:")
+                log.traceback()
         return u('default')
 
     def _find_hg_config_dir(self, path):

wakatime/projects/wakatime_project_file.py

@@ -41,9 +41,9 @@ class WakaTimeProjectFile(BaseProject):
                         self._project_name = u(fh.readline().strip())
                         self._project_branch = u(fh.readline().strip())
                 except:
-                    log.exception("Exception:")
+                    log.traceback()
             except IOError:  # pragma: nocover
-                log.exception("Exception:")
+                log.traceback()
 
             return True
         return False

wakatime/stats.py

@@ -191,5 +191,5 @@ def get_file_contents(file_name):
             with open(file_name, 'r', encoding=sys.getfilesystemencoding()) as fh:
                 text = fh.read(512000)
         except:
-            log.exception("Exception:")
+            log.traceback()
     return text