From ca5bb35bbbcab515a34b9f431ac48fecbf7d495a Mon Sep 17 00:00:00 2001
From: Alan Hamlett <alan.hamlett@gmail.com>
Date: Thu, 22 Oct 2015 23:15:57 -0700
Subject: [PATCH] correctly log exception tracebacks

---
 tests/test_logging.py                      | 25 ++++++++++++++++++++++
 wakatime/logger.py                         | 10 ++++++---
 wakatime/projects/git.py                   |  4 ++--
 wakatime/projects/mercurial.py             |  4 ++--
 wakatime/projects/wakatime_project_file.py |  4 ++--
 wakatime/stats.py                          |  2 +-
 6 files changed, 39 insertions(+), 10 deletions(-)

diff --git a/tests/test_logging.py b/tests/test_logging.py
index eb99dfa..33a670d 100644
--- a/tests/test_logging.py
+++ b/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)
diff --git a/wakatime/logger.py b/wakatime/logger.py
index 19f8581..f6bd947 100644
--- a/wakatime/logger.py
+++ b/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,
diff --git a/wakatime/projects/git.py b/wakatime/projects/git.py
index 2e8b561..091f5c9 100644
--- a/wakatime/projects/git.py
+++ b/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):
diff --git a/wakatime/projects/mercurial.py b/wakatime/projects/mercurial.py
index 7cb3e5e..399edd5 100644
--- a/wakatime/projects/mercurial.py
+++ b/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):
diff --git a/wakatime/projects/wakatime_project_file.py b/wakatime/projects/wakatime_project_file.py
index 2b9ada5..76fc7d2 100644
--- a/wakatime/projects/wakatime_project_file.py
+++ b/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
diff --git a/wakatime/stats.py b/wakatime/stats.py
index 07b9bb7..2606fa4 100644
--- a/wakatime/stats.py
+++ b/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