Repository: zoofIO/flexx
Pull request #163 (2016-07-22 23:45:21)

Prevent websocket close
Solves #164. Not sure if this is the best way to solve it thoug.




Patch:
diff --git a/flexx/app/clientcore.py b/flexx/app/clientcore.py
index ab00a92..5c6e78e 100644
--- a/flexx/app/clientcore.py
+++ b/flexx/app/clientcore.py
@@ -148,19 +148,24 @@ class FlexxJS:
             if window.flexx.ws is not None:
                 window.flexx.ws.send("WARN " + msg)
         def error(self, msg):
-            window.console.ori_error(msg)
-            if window.flexx.ws is not None:
-                window.flexx.ws.send("ERROR " + msg)
+            evt = dict(message=str(msg), error=msg, preventDefault=lambda: None)
+            on_error(evt)
         def on_error(self, evt):
             msg = evt.message
             if evt.error.stack:
-                stack = [x.replace('@', ' @ ') if '.js' in x else x.split('@')[0]
-                         for x in evt.error.stack.splitlines()]
+                stack = evt.error.stack.splitlines()
+                if evt.message in stack[0]:
+                    stack.pop(0)
                 msg += '\n' + '\n'.join(stack)
+                session_needle = '?session_id=' + flexx_session_id
+                msg = msg.replace('@', ' @ ').replace(session_needle, '')  # Firefox
             elif evt.message and evt.lineno:  # message, url, linenumber (not in nodejs)
                 msg += "\nIn %s:%i" % (evt.filename, evt.lineno)
-            window.console.error(msg)
+            # Handle error
             evt.preventDefault()  # Don't do the standard error 
+            window.console.ori_error(msg)
+            if window.flexx.ws is not None:
+                window.flexx.ws.send("ERROR " + evt.message)
         # Set new versions
         window.console.log = log
         window.console.info = info
diff --git a/flexx/app/session.py b/flexx/app/session.py
index bd96394..5f8e33b 100644
--- a/flexx/app/session.py
+++ b/flexx/app/session.py
@@ -333,7 +333,8 @@ class Session(SessionAssets):
         if command.startswith('RET '):
             print(command[4:])  # Return value
         elif command.startswith('ERROR '):
-            logger.error('JS - ' + command[6:].strip())
+            logger.error('JS - ' + command[6:].strip() +
+                         ' (stack trace in browser console)')
         elif command.startswith('WARN '):
             logger.warn('JS - ' + command[5:].strip())
         elif command.startswith('PRINT '):
diff --git a/flexx/app/tornadoserver.py b/flexx/app/tornadoserver.py
index 898398a..9b6dcc9 100644
--- a/flexx/app/tornadoserver.py
+++ b/flexx/app/tornadoserver.py
@@ -177,10 +177,22 @@ class TornadoServer(AbstractServer):
         self._server.stop()
     
     def call_later(self, delay, callback, *args, **kwargs):
+        # We use a wrapper func so that exceptions are processed via our
+        # logging system. Also fixes that Tornado seems to close websockets
+        # when an exception occurs (issue #164) though one could also
+        # use ``with tornado.stack_context.NullContext()`` to make callbacks
+        # be called more "independently".
+        def wrapper():
+            try:
+                callback(*args, **kwargs)
+            except Exception as err:
+                err.skip_tb = 1
+                logger.exception(err)
+        
         if delay <= 0:
-            self._loop.add_callback(callback, *args, **kwargs)
+            self._loop.add_callback(wrapper)
         else:
-            self._loop.call_later(delay, callback, *args, **kwargs)
+            self._loop.call_later(delay, wrapper)
     
     @property
     def app(self):
@@ -290,27 +302,34 @@ class MainHandler(tornado.web.RequestHandler):
                     self.write(session.get_page().encode())
                 else:
                     self.write('No app "%s" is currently hosted.' % app_name)
-            elif file_name and '.js:' in file_name:
+            elif file_name and ('.js:' in file_name or file_name.startswith(':')):
                 # Request for a view of a JS source file at a certain line, redirect
                 fname, where = file_name.split(':')[:2]
-                self.redirect('/%s/%s.debug%s#L%s' % (app_name, fname, where, where))
+                self.redirect('/%s/%s.debug%s#L%s' %
+                              (app_name, fname.replace('/:', ':'), where, where))
             elif file_name and '.debug' in file_name:
                 # Show JS source file at a certain line
                 fname, lineno = file_name.split('.debug', 1)
-                try:
-                    res = assets.load_asset(fname)
-                except (IOError, IndexError):
-                    self.write('invalid resource: %s' % fname)
+                if not fname:  # root app
+                    session = manager.create_session(app_name)
+                    res = session.get_page().encode()
+                    session.close()
                 else:
-                    lines = ['<html><head><style>%s</style></head><body>' % 
-                             "pre {display:inline} #L%s {background:#cca;}" % lineno]
-                    for i, line in enumerate(res.decode().splitlines()):
-                        table = {ord('&'): '&amp;', ord('<'): '&lt;', ord('>'): '&gt;'}
-                        line = line.translate(table).replace('\t', '    ')
-                        lines.append('<a id="L%i">%i<pre>  %s</pre></a><br />' %
-                                     (i+1, i+1, line))
-                    lines.append('</body></html>')
-                    self.write('\n'.join(lines))
+                    try:
+                        res = assets.load_asset(fname)
+                    except (IOError, IndexError):
+                        self.write('invalid resource: %s' % fname)
+                        return
+                # Build HTML page
+                lines = ['<html><head><style>%s</style></head><body>' % 
+                            "pre {display:inline} #L%s {background:#cca;}" % lineno]
+                for i, line in enumerate(res.decode().splitlines()):
+                    table = {ord('&'): '&amp;', ord('<'): '&lt;', ord('>'): '&gt;'}
+                    line = line.translate(table).replace('\t', '    ')
+                    lines.append('<a id="L%i">%i<pre>  %s</pre></a><br />' %
+                                    (i+1, i+1, line))
+                lines.append('</body></html>')
+                self.write('\n'.join(lines))
             elif file_name:
                 # A resource, e.g. js/css/icon
                 if file_name.endswith('.css'):
@@ -454,7 +473,11 @@ class WSHandler(tornado.websocket.WebSocketHandler):
                     raise
                 self.write_message("PRINT Flexx server says hi", binary=BINARY)
         else:
-            self._session._receive_command(message)
+            try:
+                self._session._receive_command(message)
+            except Exception as err:
+                err.skip_tb = 1
+                logger.exception(err)
     
     def on_close(self):
         """ Called when the connection is closed.
diff --git a/flexx/event/_handler.py b/flexx/event/_handler.py
index f4fce53..38c42fc 100644
--- a/flexx/event/_handler.py
+++ b/flexx/event/_handler.py
@@ -2,7 +2,6 @@
 Implementation of handler class and corresponding descriptor.
 """
 
-import sys
 import inspect
 import weakref
 
@@ -251,17 +250,10 @@ class Handler:
                 self(*events)
             except Exception as err:
                 if this_is_js():
-                    console.log(err)
+                    console.error(err)
                 else:
-                    # Allow post-mortem debugging
-                    type_, value, tb = sys.exc_info()
-                    tb = tb.tb_next  # Skip *this* frame
-                    sys.last_type = type_
-                    sys.last_value = value
-                    sys.last_traceback = tb
-                    tb = None  # Get rid of it in this namespace
-                    # Show the exception
-                    logger.exception(value)
+                    err.skip_tb = 2
+                    logger.exception(err)
     
     
     ## Connecting
diff --git a/flexx/ui/examples/errors.py b/flexx/ui/examples/errors.py
index 1eb07d8..466a794 100644
--- a/flexx/ui/examples/errors.py
+++ b/flexx/ui/examples/errors.py
@@ -59,5 +59,5 @@ class Errors(ui.Widget):
 
 
 if __name__ == '__main__':
-    m = app.launch(Errors)
+    m = app.launch(Errors, 'firefox')
     app.run()
diff --git a/flexx/util/logging.py b/flexx/util/logging.py
index 3f772e9..a774cfe 100644
--- a/flexx/util/logging.py
+++ b/flexx/util/logging.py
@@ -14,7 +14,9 @@ set_log_level()
 
 import re
 import sys
+import time
 import logging
+import traceback
 
 
 MODULE_NAME = __name__.split('.')[0]
@@ -28,15 +30,32 @@ class _Formatter(logging.Formatter):
     """Formatter that optionally prepends caller """
     
     def __init__(self):
-        super().__init__('%(levelname)s %(name)s: %(message)s')
+        super().__init__()  # '%(levelname)s %(name)s: %(message)s')
         self.prepend_caller = False
     
     def format(self, record):
-        out = logging.Formatter.format(self, record)
-        if self.prepend_caller:
-            part1, part2 = out.split(':', 1)
-            out = part1 + ' ' + record.funcName + '():' + part2
-        return out
+        base = '[{} {} {}] '.format(record.levelname[0],
+                                    time.strftime('%H:%M:%S'),
+                                    record.name)
+        if isinstance(record.msg, Exception):
+            # Get excepion info and skip first frames
+            type_, value, tb = sys.exc_info()
+            for _ in range(getattr(value, 'skip_tb', 0)):
+                tb = tb.tb_next
+            # Enable post mortem debugging
+            sys.last_type = type_
+            sys.last_value = value
+            sys.last_traceback = tb
+            # Compose message
+            out = ''.join(traceback.format_list(traceback.extract_tb(tb)))
+            del tb  # we don't want to hold too much references to this
+            return base + str(value) + '\n' + out.rstrip()
+        else:
+            out = base + str(record.msg)
+            if self.prepend_caller:
+                part1, part2 = out.split(':', 1)
+                out = part1 + ' ' + record.funcName + '():' + part2
+            return out
 
 
 class _Handler(logging.StreamHandler):


Test patch:
diff --git a/flexx/app/tests/test_model.py b/flexx/app/tests/test_model.py
index 0dfb112..2f1ce17 100644
--- a/flexx/app/tests/test_model.py
+++ b/flexx/app/tests/test_model.py
@@ -9,7 +9,6 @@ import tornado
 from flexx.app.model import Model, _get_active_models
 from flexx import event, app
 
-
 class Foo1(Model):
     
     @event.prop
@@ -222,8 +221,7 @@ def test_active_models():
             return record
     
     handler = PMHandler()
-    root_logger = logging.getLogger()
-    root_logger.addHandler(handler)
+    app.logger.addHandler(handler)
     
     # Test that we prevent going back to Tornado in context
     handler.last_type = None
diff --git a/flexx/util/tests/test_logging.py b/flexx/util/tests/test_logging.py
index 50d8bb5..adbda4c 100644
--- a/flexx/util/tests/test_logging.py
+++ b/flexx/util/tests/test_logging.py
@@ -39,11 +39,11 @@ def test_capture():
     
     assert 'flexx' in msg1
     assert 'AA' in msg1
-    assert 'WARNING' in msg1
+    assert '[W ' in msg1
     
     assert 'flexx' in msg2
     assert 'BB' in msg2
-    assert 'INFO' in msg2
+    assert '[I' in msg2
 
 
 def test_match():