search

nucypher / nucypher-monitor

NuCypher network intelligence crawler and web dashboard
7 stars 15 forks source link

Unhandled log error (dashboard) #37

Closed KPrasch closed 4 years ago

KPrasch commented 4 years ago 
nucypher-monitor dashboard --provider ... --network cassandra --poa
Traceback (most recent call last):
  File "/usr/lib/python3.7/logging/__init__.py", line 1028, in emit
    stream.write(msg + self.terminator)
  File "/home/kieran/.local/share/virtualenvs/nucypher-monitor-Xewuu8ce/lib/python3.7/site-packages/twisted/web/wsgi.py", line 140, in write
    message=(data,)
  File "/home/kieran/.local/share/virtualenvs/nucypher-monitor-Xewuu8ce/lib/python3.7/site-packages/twisted/logger/_logger.py", line 254, in error
    self.emit(LogLevel.error, format, **kwargs)
  File "/home/kieran/.local/share/virtualenvs/nucypher-monitor-Xewuu8ce/lib/python3.7/site-packages/twisted/logger/_logger.py", line 144, in emit
    self.observer(event)
--- <exception caught here> ---
  File "/home/kieran/.local/share/virtualenvs/nucypher-monitor-Xewuu8ce/lib/python3.7/site-packages/twisted/logger/_observer.py", line 131, in __call__
    observer(event)
  File "/home/kieran/.local/share/virtualenvs/nucypher-monitor-Xewuu8ce/lib/python3.7/site-packages/twisted/logger/_file.py", line 50, in __call__
    text = self.formatEvent(event)
  File "/home/kieran/.local/share/virtualenvs/nucypher-monitor-Xewuu8ce/lib/python3.7/site-packages/twisted/logger/_json.py", line 252, in <lambda>
    lambda event: u"{0}{1}\n".format(recordSeparator, eventAsJSON(event))
  File "/home/kieran/.local/share/virtualenvs/nucypher-monitor-Xewuu8ce/lib/python3.7/site-packages/twisted/logger/_json.py", line 203, in eventAsJSON
    flattenEvent(event)
  File "/home/kieran/.local/share/virtualenvs/nucypher-monitor-Xewuu8ce/lib/python3.7/site-packages/twisted/logger/_flatten.py", line 87, in flattenEvent
    aFormatter.parse(event["log_format"])
builtins.ValueError: unmatched '{' in format spec
derekpierre commented 4 years ago

The full exception is 

Unable to format event {'system': 'wsgi', 'isError': True, 'message': ('[2020-03-06 16:17:04,568] ERROR in app: Exception on /_dash-update-component [POST]\nTraceback (most recent call last):\n  File "/Users/derek/.local/share/virtualenvs/nucypher-monitor-3hnjUmmD/lib/python3.7/site-packages/flask/app.py", line 2446, in wsgi_app\n    response = self.full_dispatch_request()\n  File "/Users/derek/.local/share/virtualenvs/nucypher-monitor-3hnjUmmD/lib/python3.7/site-packages/flask/app.py", line 1951, in full_dispatch_request\n    rv = self.handle_user_exception(e)\n  File "/Users/derek/.local/share/virtualenvs/nucypher-monitor-3hnjUmmD/lib/python3.7/site-packages/flask/app.py", line 1820, in handle_user_exception\n    reraise(exc_type, exc_value, tb)\n  File "/Users/derek/.local/share/virtualenvs/nucypher-monitor-3hnjUmmD/lib/python3.7/site-packages/flask/_compat.py", line 39, in reraise\n    raise value\n  File "/Users/derek/.local/share/virtualenvs/nucypher-monitor-3hnjUmmD/lib/python3.7/site-packages/flask/app.py", line 1949, in full_dispatch_request\n    rv = self.dispatch_request()\n  File "/Users/derek/.local/share/virtualenvs/nucypher-monitor-3hnjUmmD/lib/python3.7/site-packages/flask/app.py", line 1935, in dispatch_request\n    return self.view_functions[rule.endpoint](**req.view_args)\n  File "/Users/derek/.local/share/virtualenvs/nucypher-monitor-3hnjUmmD/lib/python3.7/site-packages/dash/dash.py", line 1461, in dispatch\n    response.set_data(self.callback_map[output]["callback"](*args))\n  File "/Users/derek/.local/share/virtualenvs/nucypher-monitor-3hnjUmmD/lib/python3.7/site-packages/dash/dash.py", line 1341, in add_context\n    output_value = func(*args, **kwargs)  # %% callback invoked %%\n  File "/Users/derek/Documents/Github/repos/monitor/nucypher-monitor/monitor/dashboard.py", line 125, in known_nodes\n    node_tables = components.known_nodes(nodes_dict=data[\'node_details\'])\n  File "/Users/derek/Documents/Github/repos/monitor/nucypher-monitor/monitor/components.py", line 219, in known_nodes\n    buckets = {\'active\': sorted([*nodes_dict[\'confirmed\'], *nodes_dict[\'pending\']], key=lambda n: n[\'timestamp\']),\nKeyError: \'confirmed\'\n',), 'log_logger': <Logger 'twisted.web.wsgi._ErrorStream'>, 'log_level': <LogLevel=error>, 'log_namespace': 'twisted.web.wsgi._ErrorStream', 'log_source': <twisted.web.wsgi._ErrorStream object at 0x10647b050>, 'log_format': '[2020-03-06 16:17:04,568] ERROR in app: Exception on /_dash-update-component [POST]\nTraceback (most recent call last):\n  File "/Users/derek/.local/share/virtualenvs/nucypher-monitor-3hnjUmmD/lib/python3.7/site-packages/flask/app.py", line 2446, in wsgi_app\n    response = self.full_dispatch_request()\n  File "/Users/derek/.local/share/virtualenvs/nucypher-monitor-3hnjUmmD/lib/python3.7/site-packages/flask/app.py", line 1951, in full_dispatch_request\n    rv = self.handle_user_exception(e)\n  File "/Users/derek/.local/share/virtualenvs/nucypher-monitor-3hnjUmmD/lib/python3.7/site-packages/flask/app.py", line 1820, in handle_user_exception\n    reraise(exc_type, exc_value, tb)\n  File "/Users/derek/.local/share/virtualenvs/nucypher-monitor-3hnjUmmD/lib/python3.7/site-packages/flask/_compat.py", line 39, in reraise\n    raise value\n  File "/Users/derek/.local/share/virtualenvs/nucypher-monitor-3hnjUmmD/lib/python3.7/site-packages/flask/app.py", line 1949, in full_dispatch_request\n    rv = self.dispatch_request()\n  File "/Users/derek/.local/share/virtualenvs/nucypher-monitor-3hnjUmmD/lib/python3.7/site-packages/flask/app.py", line 1935, in dispatch_request\n    return self.view_functions[rule.endpoint](**req.view_args)\n  File "/Users/derek/.local/share/virtualenvs/nucypher-monitor-3hnjUmmD/lib/python3.7/site-packages/dash/dash.py", line 1461, in dispatch\n    response.set_data(self.callback_map[output]["callback"](*args))\n  File "/Users/derek/.local/share/virtualenvs/nucypher-monitor-3hnjUmmD/lib/python3.7/site-packages/dash/dash.py", line 1341, in add_context\n    output_value = func(*args, **kwargs)  # %% callback invoked %%\n  File "/Users/derek/Documents/Github/repos/monitor/nucypher-monitor/monitor/dashboard.py", line 125, in known_nodes\n    node_tables = components.known_nodes(nodes_dict=data[\'node_details\'])\n  File "/Users/derek/Documents/Github/repos/monitor/nucypher-monitor/monitor/components.py", line 219, in known_nodes\n    buckets = {\'active\': sorted([*nodes_dict[\'confirmed\'], *nodes_dict[\'pending\']], key=lambda n: n[\'timestamp\']),\nKeyError: \'confirmed\'\n', 'log_time': 1583529424.568458}: unmatched '{' in format spec
Temporarily disabling observer <twisted.logger._file.FileLogObserver object at 0x107b05fd0> due to exception: [Failure instance: Traceback: <class 'ValueError'>: unmatched '{' in format spec
/Users/derek/anaconda3/lib/python3.7/logging/__init__.py:1028:emit

Which seems to boil down to the following:

"/Users/derek/Documents/Github/repos/monitor/nucypher-monitor/monitor/components.py", line 219, in known_nodes\n    buckets = {\'active\': sorted([*nodes_dict[\'confirmed\'], *nodes_dict[\'pending\']], key=lambda n: n[\'timestamp\']),\nKeyError: \'confirmed\'\n',

The cause of this issue is if the dashboard is run too early, then the crawler doesn't know about many nodes and sometimes just the teacher. Example stats output

...
'next_period': '1 day, 0:00:00',
 'node_details': {'unconfirmed': [{'fleet_state_icon': '?',
    'last_seen': 'No Connection to Node',
    'nickname': 'DarkMagenta Diamond Red Mountain',
    'rest_url': '54.152.254.4:9151',
    'staker_address': '0xcC0678E51a8237b762c09d6548d2d07285609e98',
    'status': {'color': 'red',
     'missed_confirmations': 27,
     'status': 'Unconfirmed'},
    'timestamp': '2020-01-21T00:45:40Z',
    'uptime': '48d:18h:27m'}]},
 'prev_states': [{'color_hex': '#4169E1',
   'color_name': 'RoyalBlue',
   'nickname': 'RoyalBlue Saturn',
   'symbol': '♄',
   'updated': 'Mon, 09 Mar 2020 19:12:55 GMT'}],
...

The node_details only has one node in it that is unconfirmed. The resulting node_details dict therefore has no entry for confirmed leading to a KeyError.

This is fixed via https://github.com/nucypher/nucypher-monitor/pull/53/commits/e747fcf64ed2916447462f00ea7a8ad27d002fb8 in #53.

derekpierre commented 4 years ago

Fixed in #53 (merged via #26)