Merge #3095

Generic traceback handling in python.

Conflicts:
	src/bin/memmgr/memmgr.py.in

src/bin/bind10/init.py.in

@@ -78,6 +78,7 @@ from isc.log_messages.init_messages import *
 import isc.bind10.component
 import isc.bind10.special_component
 import isc.bind10.socket_cache
+import isc.util.traceback_handler
 import libutil_io_python
 import tempfile
 
@@ -1368,4 +1369,4 @@ def main():
     sys.exit(b10_init.exitcode)
 
 if __name__ == "__main__":
-    main()
+    isc.util.traceback_handler.traceback_handler(main)

src/bin/bindctl/bindctl_main.py.in

@@ -26,6 +26,7 @@ from bindctl import command_sets
 import pprint
 from optparse import OptionParser, OptionValueError
 import isc.util.process
+import isc.util.traceback_handler
 
 isc.util.process.rename()
 
@@ -150,7 +151,7 @@ def set_bindctl_options(parser):
                       default=None, action='store',
                       help='Directory to store the password CSV file')
 
-if __name__ == '__main__':
+def main():
     parser = OptionParser(version = VERSION)
     set_bindctl_options(parser)
     (options, args) = parser.parse_args()
@@ -161,3 +162,6 @@ if __name__ == '__main__':
     command_sets.prepare_execute_commands(tool)
     result = tool.run()
     sys.exit(result)
+
+if __name__ == '__main__':
+    isc.util.traceback_handler.traceback_handler(main)

src/bin/cfgmgr/b10-cfgmgr.py.in

@@ -30,6 +30,7 @@ import isc.log
 isc.log.init("b10-cfgmgr", buffer=True)
 from isc.config.cfgmgr import ConfigManager, ConfigManagerDataReadError, logger
 from isc.log_messages.cfgmgr_messages import *
+import isc.util.traceback_handler
 
 isc.util.process.rename()
 
@@ -128,4 +129,4 @@ def main():
     return 0
 
 if __name__ == "__main__":
-    sys.exit(main())
+    sys.exit(isc.util.traceback_handler.traceback_handler(main))

src/bin/cmdctl/cmdctl.py.in

@@ -48,6 +48,7 @@ from optparse import OptionParser, OptionValueError
 from hashlib import sha1
 from isc.util import socketserver_mixin
 from isc.log_messages.cmdctl_messages import *
+import isc.util.traceback_handler
 
 isc.log.init("b10-cmdctl", buffer=True)
 logger = isc.log.Logger("cmdctl")
@@ -675,7 +676,7 @@ def set_cmd_options(parser):
     parser.add_option("-v", "--verbose", dest="verbose", action="store_true", default=False,
             help="display more about what is going on")
 
-if __name__ == '__main__':
+def main():
     set_signal_handler()
     parser = OptionParser(version = __version__)
     set_cmd_options(parser)
@@ -701,3 +702,6 @@ if __name__ == '__main__':
     logger.info(CMDCTL_EXITING)
 
     sys.exit(result)
+
+if __name__ == '__main__':
+    isc.util.traceback_handler.traceback_handler(main)

src/bin/dbutil/dbutil.py.in

@@ -58,6 +58,7 @@ sys.excepthook = my_except_hook
 import os, sqlite3, shutil
 from optparse import OptionParser
 import isc.util.process
+import isc.util.traceback_handler
 import isc.log
 from isc.log_messages.dbutil_messages import *
 
@@ -566,9 +567,11 @@ def parse_command():
     sys.exit(EXIT_COMMAND_ERROR)
 
 
-if __name__ == "__main__":
+def main():
     (options, args) = parse_command()
 
+    global logger
+
     if options.verbose:
         isc.log.init("b10-dbutil", "DEBUG", 99)
         logger = isc.log.Logger("dbutil")
@@ -619,3 +622,6 @@ if __name__ == "__main__":
             exit_code = EXIT_UPGRADE_ERROR
 
     sys.exit(exit_code)
+
+if __name__ == "__main__":
+    isc.util.traceback_handler.traceback_handler(main)

src/bin/ddns/ddns.py.in

@@ -28,6 +28,7 @@ from isc.config.ccsession import *
 from isc.config.module_spec import ModuleSpecError
 from isc.cc import SessionError, SessionTimeout, ProtocolError
 import isc.util.process
+import isc.util.traceback_handler
 import isc.util.cio.socketsession
 import isc.server_common.tsig_keyring
 from isc.server_common.dns_tcp import DNSTCPContext
@@ -738,9 +739,8 @@ def main(ddns_server=None):
         logger.error(DDNS_CONFIG_ERROR, str(e))
     except SessionTimeout as e:
         logger.error(DDNS_CC_SESSION_TIMEOUT_ERROR)
-    except Exception as e:
-        logger.error(DDNS_UNCAUGHT_EXCEPTION, type(e).__name__, str(e))
-    clear_socket()
+    finally:
+        clear_socket()
 
 if '__main__' == __name__:
-    main()
+    isc.util.traceback_handler.traceback_handler(main)

src/bin/ddns/ddns_messages.mes

@@ -237,11 +237,6 @@ DDNS UPDATE messages, it will return SERVFAIL. However, this does point to
 an underlying problem in the messaging system, and should be inspected.
 The specific error is printed in the log message.
 
-% DDNS_UNCAUGHT_EXCEPTION uncaught exception of type %1: %2
-The b10-ddns process encountered an uncaught exception and will now shut
-down. This is indicative of a programming error and should not happen under
-normal circumstances. The exception type and message are printed.
-
 % DDNS_UPDATE_NOTIFY notified %1 of updates to %2
 Debug message.  b10-ddns has made updates to a zone based on an update
 request and has successfully notified an external module of the updates.

src/bin/ddns/tests/ddns_test.py

@@ -1375,7 +1375,6 @@ class TestMain(unittest.TestCase):
         self.check_exception(isc.config.ModuleCCSessionError("error"))
         self.check_exception(ddns.DDNSConfigError("error"))
         self.check_exception(isc.cc.SessionTimeout("error"))
-        self.check_exception(Exception("error"))
 
         # Add one that is not a subclass of Exception, and hence not
         # caught. Misuse BaseException for that.

src/bin/loadzone/loadzone.py.in

@@ -23,6 +23,7 @@ from optparse import OptionParser
 from isc.dns import *
 from isc.datasrc import *
 import isc.util.process
+import isc.util.traceback_handler
 import isc.log
 from isc.log_messages.loadzone_messages import *
 from datetime import timedelta
@@ -351,11 +352,14 @@ class LoadZoneRunner:
             logger.error(LOADZONE_UNEXPECTED_FAILURE, ex)
         return 1
 
-if '__main__' == __name__:
+def main():
     runner = LoadZoneRunner(sys.argv[1:])
     ret = runner.run()
     sys.exit(ret)
 
+if '__main__' == __name__:
+    isc.util.traceback_handler.traceback_handler(main)
+
 ## Local Variables:
 ## mode: python
 ## End:

src/bin/memmgr/memmgr.py.in

@@ -32,6 +32,7 @@ from isc.server_common.datasrc_clients_mgr \
 from isc.memmgr.datasrc_info import DataSrcInfo, SegmentInfo
 from isc.memmgr.builder import MemorySegmentBuilder
 import isc.util.process
+import isc.util.traceback_handler
 
 MODULE_NAME = 'memmgr'
 
@@ -252,6 +253,9 @@ class Memmgr(BIND10Server):
                 SegmentInfo.UPDATING
             self._cmd_to_builder(cmd)
 
-if '__main__' == __name__:
+def main():
     mgr = Memmgr()
     sys.exit(mgr.run(MODULE_NAME))
+
+if '__main__' == __name__:
+    isc.util.traceback_handler.traceback_handler(main)

src/bin/msgq/msgq.py.in

@@ -33,6 +33,7 @@ import threading
 import isc.config.ccsession
 from optparse import OptionParser, OptionValueError
 import isc.util.process
+import isc.util.traceback_handler
 from isc.cc.proto_defs import *
 import isc.log
 from isc.log_messages.msgq_messages import *
@@ -779,7 +780,7 @@ def signal_handler(msgq, signal, frame):
     if msgq:
         msgq.stop()
 
-if __name__ == "__main__":
+def main():
     def check_port(option, opt_str, value, parser):
         """Function to insure that the port we are passed is actually
         a valid port number. Used by OptionParser() on startup."""
@@ -855,3 +856,6 @@ if __name__ == "__main__":
     msgq.shutdown()
 
     logger.info(MSGQ_EXITING)
+
+if __name__ == "__main__":
+    isc.util.traceback_handler.traceback_handler(main)

src/bin/stats/stats.py.in

@@ -29,6 +29,7 @@ import select
 import isc.cc
 import isc.config
 import isc.util.process
+import isc.util.traceback_handler
 import isc.log
 from isc.log_messages.stats_messages import *
 
@@ -722,7 +723,7 @@ class Stats:
                 1, "specified arguments are incorrect: " \
                     + "owner: " + str(owner) + ", name: " + str(name))
 
-if __name__ == "__main__":
+def main():
     try:
         parser = OptionParser()
         parser.add_option(
@@ -746,3 +747,6 @@ if __name__ == "__main__":
         logger.info(STATS_STOPPED_BY_KEYBOARD)
 
     logger.info(STATS_EXITING)
+
+if __name__ == "__main__":
+    isc.util.traceback_handler.traceback_handler(main)

src/bin/stats/stats_httpd.py.in

@@ -35,6 +35,7 @@ import re
 import isc.cc
 import isc.config
 import isc.util.process
+import isc.util.traceback_handler
 from isc.util.address_formatter import AddressFormatter
 
 import isc.log
@@ -598,7 +599,7 @@ class StatsHttpd:
                 "%s: %s" % (err.__class__.__name__, err))
         return string.Template(lines)
 
-if __name__ == "__main__":
+def main():
     try:
         parser = OptionParser()
         parser.add_option(
@@ -622,3 +623,6 @@ if __name__ == "__main__":
         logger.info(STATSHTTPD_STOPPED_BY_KEYBOARD)
 
     logger.info(STATSHTTPD_EXITING)
+
+if __name__ == "__main__":
+    isc.util.traceback_handler.traceback_handler(main)

src/bin/xfrin/xfrin.py.in

@@ -31,6 +31,7 @@ from isc.config.ccsession import *
 from isc.statistics.dns import Counters
 from isc.notify import notify_out
 import isc.util.process
+import isc.util.traceback_handler
 from isc.util.address_formatter import AddressFormatter
 from isc.datasrc import DataSourceClient, ZoneFinder
 import isc.net.parse
@@ -1849,4 +1850,4 @@ def main(xfrin_class, use_signal=True):
     logger.info(XFRIN_EXITING)
 
 if __name__ == '__main__':
-    main(Xfrin)
+    isc.util.traceback_handler.traceback_handler(lambda: main(Xfrin))

src/bin/xfrout/xfrout.py.in

@@ -30,6 +30,7 @@ from isc.cc import SessionError, SessionTimeout
 from isc.statistics.dns import Counters
 from isc.notify import notify_out
 import isc.util.process
+import isc.util.traceback_handler
 import fcntl
 import socket
 import select
@@ -1166,7 +1167,7 @@ def set_cmd_options(parser):
     parser.add_option("-v", "--verbose", dest="verbose", action="store_true",
             help="display more about what is going on")
 
-if '__main__' == __name__:
+def main():
     try:
         parser = OptionParser()
         set_cmd_options(parser)
@@ -1191,3 +1192,6 @@ if '__main__' == __name__:
         xfrout_server.shutdown()
 
     logger.info(XFROUT_EXITING)
+
+if '__main__' == __name__:
+    isc.util.traceback_handler.traceback_handler(main)

src/bin/zonemgr/zonemgr.py.in

@@ -37,6 +37,7 @@ import errno
 from optparse import OptionParser, OptionValueError
 from isc.config.ccsession import *
 import isc.util.process
+import isc.util.traceback_handler
 from isc.log_messages.zonemgr_messages import *
 from isc.notify import notify_out
 from isc.server_common.datasrc_clients_mgr import DataSrcClientsMgr, ConfigError
@@ -802,7 +803,7 @@ def set_cmd_options(parser):
     parser.add_option("-v", "--verbose", dest="verbose", action="store_true",
             help="display more about what is going on")
 
-if '__main__' == __name__:
+def main():
     try:
         logger.debug(DBG_START_SHUT, ZONEMGR_STARTING)
         parser = OptionParser()
@@ -830,3 +831,6 @@ if '__main__' == __name__:
         zonemgrd.shutdown()
 
     logger.info(ZONEMGR_SHUTDOWN)
+
+if '__main__' == __name__:
+    isc.util.traceback_handler.traceback_handler(main)

src/lib/python/isc/log_messages/Makefile.am

@@ -21,6 +21,7 @@ EXTRA_DIST += server_common_messages.py
 EXTRA_DIST += dbutil_messages.py
 EXTRA_DIST += msgq_messages.py
 EXTRA_DIST += pycc_messages.py
+EXTRA_DIST += util_messages.py
 
 CLEANFILES = __init__.pyc
 CLEANFILES += init_messages.pyc
@@ -43,6 +44,7 @@ CLEANFILES += server_common_messages.pyc
 CLEANFILES += dbutil_messages.pyc
 CLEANFILES += msgq_messages.pyc
 CLEANFILES += pycc_messages.pyc
+CLEANFILES += util_messages.pyc
 
 CLEANDIRS = __pycache__
 

src/lib/python/isc/log_messages/util_messages.py

@@ -0,0 +1 @@
+from work.util_messages import *

src/lib/python/isc/util/Makefile.am

@@ -1,8 +1,20 @@
 SUBDIRS = . cio tests
 
-python_PYTHON =  __init__.py process.py socketserver_mixin.py file.py
+python_PYTHON =  __init__.py process.py socketserver_mixin.py file.py \
+	traceback_handler.py
+BUILT_SOURCES = $(PYTHON_LOGMSGPKG_DIR)/work/util_messages.py
 python_PYTHON += address_formatter.py
 
+EXTRA_DIST = util_messages.mes
+
+CLEANFILES = $(PYTHON_LOGMSGPKG_DIR)/work/util_messages.py
+CLEANFILES += $(PYTHON_LOGMSGPKG_DIR)/work/util_messages.pyc
+
+# Define rule to build logging source files from message file
+$(PYTHON_LOGMSGPKG_DIR)/work/util_messages.py: util_messages.mes
+	$(top_builddir)/src/lib/log/compiler/message \
+		-d $(PYTHON_LOGMSGPKG_DIR)/work -p $(srcdir)/util_messages.mes
+
 pythondir = $(pyexecdir)/isc/util
 
 CLEANDIRS = __pycache__

src/lib/python/isc/util/tests/Makefile.am

@@ -1,6 +1,6 @@
 PYCOVERAGE_RUN = @PYCOVERAGE_RUN@
 PYTESTS = process_test.py socketserver_mixin_test.py file_test.py
-PYTESTS += address_formatter_test.py
+PYTESTS += address_formatter_test.py traceback_handler_test.py
 EXTRA_DIST = $(PYTESTS)
 
 # If necessary (rare cases), explicitly specify paths to dynamic libraries

src/lib/python/isc/util/tests/address_formatter_test.py

@@ -62,7 +62,5 @@ class AddressFormatterTest(unittest.TestCase):
         self.assertRaises(ValueError, str, AddressFormatter(("::1", 123), 1))
         self.assertRaises(ValueError, str, AddressFormatter(("::1", 123), 1))
 
-
-
 if __name__ == "__main__":
     unittest.main()

src/lib/python/isc/util/tests/traceback_handler_test.py

@@ -0,0 +1,101 @@
+# Copyright (C) 2013  Internet Systems Consortium.
+#
+# Permission to use, copy, modify, and distribute this software for any
+# purpose with or without fee is hereby granted, provided that the above
+# copyright notice and this permission notice appear in all copies.
+#
+# THE SOFTWARE IS PROVIDED "AS IS" AND INTERNET SYSTEMS CONSORTIUM
+# DISCLAIMS ALL WARRANTIES WITH REGARD TO THIS SOFTWARE INCLUDING ALL
+# IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS. IN NO EVENT SHALL
+# INTERNET SYSTEMS CONSORTIUM BE LIABLE FOR ANY SPECIAL, DIRECT,
+# INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES WHATSOEVER RESULTING
+# FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN ACTION OF CONTRACT,
+# NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN CONNECTION
+# WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.
+
+import unittest
+import os
+import isc.log
+import isc.util.traceback_handler
+
+class TracebackHandlerTest(unittest.TestCase):
+    def setUp(self):
+        """
+        Save some things to be restored later, if we overwrite them
+        for tests.
+        """
+        self.exit = isc.util.traceback_handler.sys.exit
+        self.logger = isc.util.traceback_handler.logger
+        # Sanity check - the functions exist.
+        self.assertTrue(self.exit)
+        self.assertTrue(self.logger)
+
+    def tearDown(self):
+        """
+        Restore mocked things.
+        """
+        isc.util.traceback_handler.sys.exit = self.exit
+        isc.util.traceback_handler.logger = self.logger
+
+    def test_success(self):
+        """
+        Test the handler doesn't influence the result of successful
+        function.
+        """
+        self.called = False
+        def succ():
+            self.called = True
+            return 42
+
+        self.assertEqual(42,
+                         isc.util.traceback_handler.traceback_handler(succ))
+        self.assertTrue(self.called)
+
+    def test_success_no_returned_value(self):
+        """
+        Test the handler handles the case where main() returns nothing.
+        """
+        self.called = False
+        def succ():
+            self.called = True
+            return
+
+        self.assertIsNone(isc.util.traceback_handler.traceback_handler(succ))
+        self.assertTrue(self.called)
+
+    def test_exception(self):
+        """
+        Test the exception is caught and logged, but not propagated.
+        """
+        # Mock up bunch of things
+        self.exited = False
+        def exit(status):
+            self.assertEqual(1, status)
+            self.exited = True
+        isc.util.traceback_handler.sys.exit = exit
+        self.logged = False
+        obj = self
+        class Logger:
+            def fatal(self, message, ename, exception, filename):
+                obj.assertTrue(isinstance(exception, Exception))
+                obj.assertEqual('Exception', ename)
+                obj.assertTrue(os.path.isfile(filename))
+                with open(filename) as f:
+                    text = f.read()
+                obj.assertTrue(text.startswith('Traceback'))
+                os.remove(filename)
+                obj.logged = True
+        isc.util.traceback_handler.logger = Logger()
+        # The failing function
+        def fail():
+            raise Exception('Anybody there?')
+        # Does not raise, but returns nothing
+        self.assertIsNone(isc.util.traceback_handler.traceback_handler(fail))
+        # It logged and exited (sane values for those are checked in the mocks)
+        self.assertTrue(self.exited)
+        self.assertTrue(self.logged)
+
+if __name__ == "__main__":
+    isc.log.init("bind10")
+    isc.log.resetUnitTestRootLogger()
+    unittest.main()

src/lib/python/isc/util/traceback_handler.py

@@ -0,0 +1,39 @@
+# Copyright (C) 2013  Internet Systems Consortium.
+#
+# Permission to use, copy, modify, and distribute this software for any
+# purpose with or without fee is hereby granted, provided that the above
+# copyright notice and this permission notice appear in all copies.
+#
+# THE SOFTWARE IS PROVIDED "AS IS" AND INTERNET SYSTEMS CONSORTIUM
+# DISCLAIMS ALL WARRANTIES WITH REGARD TO THIS SOFTWARE INCLUDING ALL
+# IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS. IN NO EVENT SHALL
+# INTERNET SYSTEMS CONSORTIUM BE LIABLE FOR ANY SPECIAL, DIRECT,
+# INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES WHATSOEVER RESULTING
+# FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN ACTION OF CONTRACT,
+# NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN CONNECTION
+# WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.
+
+from isc.log_messages.util_messages import *
+import sys
+import tempfile
+import os
+import traceback
+
+logger = isc.log.Logger('util')
+
+def traceback_handler(main):
+    """
+    Handle uncaught exception from the main callable.
+
+    The function runs the callable passed as main (it is called
+    without any provided parameters). If it raises any exception,
+    the exception is logged and the application is terminated.
+    """
+    try:
+        return main()
+    except Exception as e:
+        fd, name = tempfile.mkstemp(text=True)
+        with os.fdopen(fd, 'w') as handle:
+            traceback.print_exc(None, handle)
+        logger.fatal(PYTHON_UNHANDLED_EXCEPTION, type(e).__name__, e, name)
+        sys.exit(1)

src/lib/python/isc/util/util_messages.mes

@@ -0,0 +1,26 @@
+# Copyright (C) 2013  Internet Systems Consortium, Inc. ("ISC")
+#
+# Permission to use, copy, modify, and/or distribute this software for any
+# purpose with or without fee is hereby granted, provided that the above
+# copyright notice and this permission notice appear in all copies.
+#
+# THE SOFTWARE IS PROVIDED "AS IS" AND ISC DISCLAIMS ALL WARRANTIES WITH
+# REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF MERCHANTABILITY
+# AND FITNESS.  IN NO EVENT SHALL ISC BE LIABLE FOR ANY SPECIAL, DIRECT,
+# INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES WHATSOEVER RESULTING FROM
+# LOSS OF USE, DATA OR PROFITS, WHETHER IN AN ACTION OF CONTRACT, NEGLIGENCE
+# OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN CONNECTION WITH THE USE OR
+# PERFORMANCE OF THIS SOFTWARE.
+
+# No namespace declaration - these constants go in the global namespace
+# of the isc.util.util_messages python module.
+
+% PYTHON_UNHANDLED_EXCEPTION program terminated with exception %1: %2. More info in %3
+A program encountered an unexpected situation and terminated because it
+didn't know how to handle it. The exact problem is logged in the
+message. This might be caused by a bug in the program, a broken
+installation, or just a very rare condition which wasn't handled in the
+code. A full stack trace is left in the generated file. If you report a
+bug for this exception, please include that file. The file will not be
+deleted automatically and you may want to remove it when you no longer
+need the information there.