Add status command

issue10098
review347481002

CHANGELOG

@@ -1,3 +1,4 @@
+* Add status command
 * Add document widget on form view
 * Add full text and similarity search and FullText field
 * Add URL type to icon

bin/trytond-stat

@@ -0,0 +1,84 @@
+#!/usr/bin/env python3
+# This file is part of Tryton.  The COPYRIGHT file at the top level of
+# this repository contains the full copyright notices and license terms.
+import curses
+import datetime as dt
+import sys
+import os
+
+DIR = os.path.abspath(os.path.normpath(os.path.join(__file__,
+    '..', '..', 'trytond')))
+if os.path.isdir(DIR):
+    sys.path.insert(0, os.path.dirname(DIR))
+
+import trytond.commandline as commandline
+from trytond.config import config
+
+parser = commandline.get_parser_stat()
+options = parser.parse_args()
+config.update_etc(options.configfile)
+
+import trytond.status as status
+
+
+def main(stdscr):
+    global reverse
+    stdscr.nodelay(1)
+    reverse = True
+    processes = {}
+    status_pad = curses.newpad(1, 1)
+
+    def refresh_status():
+        now = dt.datetime.now()
+        height, width = stdscr.getmaxyx()
+
+        def expired(process):
+            return process['expire'] > now
+
+        def format(since, pid, request):
+            since = str(dt.timedelta(seconds=int(since)))
+            return f"{pid:>5} {since:>18} {request}"
+        status_pad.clear()
+        status = [format(*i) for i in sorted(
+                ((msg['since'], p['id'], msg['request'])
+                    for p in filter(expired, processes.values())
+                    for msg in p['status']),
+                reverse=reverse)]
+        prow = max(len(status), height - 2)
+        pcol = width - 2
+        status_pad.resize(prow + 2, pcol)
+        for i, line in enumerate(status, 1):
+            status_pad.addnstr(i, 1, line.ljust(pcol), pcol - 2)
+        status_pad.border(0)
+        status_pad.addnstr(
+            0, 0, ' {pid:>5} {since:>18} {request}'.format(
+                pid="pid",
+                since="TIME" + ('↑' if reverse else '↓'),
+                request="request"
+                ).upper().ljust(pcol),
+            pcol, curses.A_REVERSE)
+        status_pad.refresh(0, 0, 0, 0, height - 1, width)
+
+    def refresh():
+        global reverse
+        refresh_status()
+        stdscr.refresh()
+
+        key = stdscr.getch()
+        if key == ord('q'):
+            sys.exit()
+        elif key == ord('r'):
+            reverse = not reverse
+            refresh()
+
+    def update(data=None):
+        if data:
+            pid = data['id']
+            data['expire'] = dt.datetime.now() + dt.timedelta(seconds=10)
+            processes[pid] = data
+        refresh()
+    refresh()
+    status.listen(config.get('database', 'path'), update)
+
+
+curses.wrapper(main)

setup.py

@@ -111,6 +111,7 @@ setup(name=name,
         'bin/trytond-console',
         'bin/trytond-cron',
         'bin/trytond-worker',
+        'bin/trytond-stat',
         ],
     classifiers=[
         'Development Status :: 5 - Production/Stable',

trytond/commandline.py

@@ -117,6 +117,12 @@ def get_parser_console():
     return parser
 
 
+def get_parser_stat():
+    parser = get_base_parser()
+    parser.epilog = "To exit press 'q', to inverse sort order press 'r'."
+    return parser
+
+
 def config_log(options):
     if options.logconf:
         logging.config.fileConfig(options.logconf)

trytond/config.py

@@ -1,9 +1,12 @@
 # This file is part of Tryton.  The COPYRIGHT file at the top level of
 # this repository contains the full copyright notices and license terms.
-import os
+import __main__ as main
 import configparser
-import urllib.parse
 import logging
+import os
+import urllib.parse
+
+from . import status
 
 __all__ = ['config', 'get_hostname', 'get_port', 'split_netloc',
     'parse_listen', 'parse_uri']
@@ -151,3 +154,6 @@ class TrytonConfigParser(configparser.ConfigParser):
 
 
 config = TrytonConfigParser()
+
+if os.path.basename(main.__file__) != 'trytond-stat':
+    status.start(config.get('database', 'path'))

trytond/ir/cron.py

@@ -11,6 +11,7 @@ from trytond.model import (
     ModelView, ModelSQL, DeactivableMixin, fields, dualmethod)
 from trytond.pool import Pool
 from trytond.pyson import Eval
+from trytond.status import processing
 from trytond.transaction import Transaction
 from trytond.worker import run_task
 
@@ -140,21 +141,23 @@ class Cron(DeactivableMixin, ModelSQL, ModelView):
                     ])
 
             for cron in crons:
-                logger.info("Run cron %s", cron.id)
+                name = '<Cron %s@%s %s>' % (cron.id, db_name, cron.method)
+                logger.info("%s started", name)
                 for count in range(retry, -1, -1):
                     if count != retry:
                         time.sleep(0.02 * (retry - count))
                     try:
-                        cron.run_once()
-                        cron.next_call = cron.compute_next_call(now)
-                        cron.save()
-                        transaction.commit()
+                        with processing(name):
+                            cron.run_once()
+                            cron.next_call = cron.compute_next_call(now)
+                            cron.save()
+                            transaction.commit()
                     except Exception as e:
                         transaction.rollback()
                         if (isinstance(e, backend.DatabaseOperationalError)
                                 and count):
                             continue
-                        logger.error('Running cron %s', cron.id, exc_info=True)
+                        logger.error('%s failed', name, exc_info=True)
                     break
         while transaction.tasks:
             task_id = transaction.tasks.pop()

trytond/protocols/dispatcher.py

@@ -163,7 +163,7 @@ def _dispatch(request, pool, *args, **kwargs):
         username = username.decode('utf-8')
     log_args = (
         obj, method, args, kwargs, username, request.remote_addr, request.path)
-    logger.info(log_message, *log_args)
+    logger.debug(log_message, *log_args)
 
     retry = config.getint('database', 'retry')
     for count in range(retry, -1, -1):

trytond/protocols/jsonrpc.py

@@ -135,11 +135,17 @@ class JSONRequest(Request):
 
     @cached_property
     def rpc_method(self):
-        return self.parsed_data['method']
+        try:
+            return self.parsed_data['method']
+        except Exception:
+            pass
 
     @cached_property
     def rpc_params(self):
-        return self.parsed_data['params']
+        try:
+            return self.parsed_data['params']
+        except Exception:
+            pass
 
 
 class JSONProtocol:

trytond/protocols/wrappers.py

@@ -30,6 +30,24 @@ class Request(_Request):
 
     view_args = None
 
+    def __repr__(self):
+        args = []
+        try:
+            if self.url is None or isinstance(self.url, str):
+                url = self.url
+            else:
+                url = self.url.decode(self.url_charset)
+            auth = self.authorization
+            args.append("%s@%s" % (
+                    auth.get('userid', auth.username), self.remote_addr))
+            args.append("'%s'" % url)
+            args.append("[%s]" % self.method)
+            args.append("%s" % (self.rpc_method or ''))
+        except Exception:
+            args.append("(invalid WSGI environ)")
+        return "<%s %s>" % (
+            self.__class__.__name__, " ".join(filter(None, args)))
+
     @property
     def decoded_data(self):
         if self.content_encoding == 'gzip':
@@ -60,6 +78,8 @@ class Request(_Request):
 
     @cached_property
     def user_id(self):
+        if not self.view_args:
+            return None
         database_name = self.view_args.get('database_name')
         if not database_name:
             return None

trytond/status.py

@@ -0,0 +1,103 @@
+# This file is part of Tryton.  The COPYRIGHT file at the top level of
+# this repository contains the full copyright notices and license terms.
+import json
+import logging
+import os
+import socket
+import threading
+import time
+from collections import namedtuple
+from contextlib import contextmanager
+
+status = dict()
+logger = logging.getLogger(__name__)
+address = 'trytond-stat.socket'
+
+Process = namedtuple('Process', ['start_time', 'request'])
+
+
+@contextmanager
+def processing(request):
+    process = Process(time.perf_counter(), request)
+    status[id(process)] = process
+    try:
+        yield
+    finally:
+        status.pop(id(process), None)
+
+
+def log():
+    msg = []
+    now = time.perf_counter()
+    for process in sorted(status.copy().values(), key=lambda p: p.start_time):
+        msg.append({
+                'since': now - process.start_time,
+                'request': str(process.request),
+                })
+    return {
+        'id': os.getpid(),
+        'status': msg,
+        }
+
+
+def dump(path):
+    sock = socket.socket(socket.AF_UNIX)
+    try:
+        try:
+            sock.connect(os.path.join(path, address))
+        except socket.error:
+            return False
+        try:
+            sock.sendall(json.dumps(log()).encode('utf-8'))
+        except socket.error:
+            pass
+    finally:
+        sock.close()
+    return True
+
+
+def dumper(path):
+    while True:
+        if dump(path):
+            time.sleep(5)
+        else:
+            time.sleep(60)
+
+
+def start(path):
+    threading.Thread(target=dumper, args=(path,), daemon=True).start()
+
+
+def listen(path, callback=None):
+    sock = socket.socket(socket.AF_UNIX)
+    socket_file = os.path.join(path, address)
+    try:
+        sock.bind(socket_file)
+        sock.listen(1)
+        sock.settimeout(5)
+        while True:
+            try:
+                connection, client_address = sock.accept()
+            except socket.timeout:
+                if callback:
+                    callback()
+                continue
+            try:
+                data = b''
+                while True:
+                    chunk = connection.recv(1024)
+                    if not chunk:
+                        break
+                    else:
+                        data += chunk
+                try:
+                    data = json.loads(data)
+                except ValueError:
+                    continue
+                if callback:
+                    callback(data)
+            finally:
+                connection.close()
+    finally:
+        sock.close()
+        os.unlink(socket_file)

trytond/worker.py

@@ -13,6 +13,7 @@ from sql import Flavor
 from trytond import backend
 from trytond.config import config
 from trytond.pool import Pool
+from trytond.status import processing
 from trytond.transaction import Transaction
 
 __all__ = ['work']
@@ -98,7 +99,8 @@ def run_task(pool, task_id):
     if not isinstance(pool, Pool):
         pool = Pool(pool)
     Queue = pool.get('ir.queue')
-    logger.info('task "%d" started', task_id)
+    name = '<Task %s@%s>' % (task_id, pool.database_name)
+    logger.info('%s started', name)
     retry = config.getint('database', 'retry')
     try:
         for count in range(retry, -1, -1):
@@ -111,16 +113,17 @@ def run_task(pool, task_id):
                     except ValueError:
                         # the task was rollbacked, nothing to do
                         break
-                    task.run()
+                    with processing(name):
+                        task.run()
                     break
                 except backend.DatabaseOperationalError:
                     if count:
                         transaction.rollback()
                         continue
                     raise
-        logger.info('task "%d" done', task_id)
+        logger.info('%s done', name)
     except backend.DatabaseOperationalError:
-        logger.info('task "%d" failed, retrying', task_id, exc_info=True)
+        logger.info('%s failed, retrying', name, exc_info=True)
         if not config.getboolean('queue', 'worker', default=False):
             time.sleep(0.02 * retry)
         try:
@@ -132,6 +135,6 @@ def run_task(pool, task_id):
                 Queue.push(task.name, task.data, scheduled_at=scheduled_at)
         except Exception:
             logger.critical(
-                'rescheduling task "%d" failed', task_id, exc_info=True)
+                'rescheduling %s failed', name, exc_info=True)
     except Exception:
-        logger.critical('task "%d" failed', task_id, exc_info=True)
+        logger.critical('%s failed', name, exc_info=True)

trytond/wsgi.py

@@ -40,6 +40,7 @@ from trytond.config import config
 from trytond.protocols.wrappers import Request
 from trytond.protocols.jsonrpc import JSONProtocol
 from trytond.protocols.xmlrpc import XMLProtocol
+from trytond.status import processing
 from trytond.tools import resolve
 
 __all__ = ['TrytondWSGI', 'app']
@@ -163,6 +164,7 @@ class TrytondWSGI(object):
                 break
         else:
             request = Request(environ)
+        logger.info('%s', request)
 
         origin = request.headers.get('Origin')
         origin_host = urllib.parse.urlparse(origin).netloc if origin else ''
@@ -178,11 +180,12 @@ class TrytondWSGI(object):
             if not getattr(endpoint, 'allow_null_origin', False):
                 abort(HTTPStatus.FORBIDDEN)
 
-        data = self.dispatch_request(request)
-        if not isinstance(data, (Response, HTTPException)):
-            response = self.make_response(request, data)
-        else:
-            response = data
+        with processing(request):
+            data = self.dispatch_request(request)
+            if not isinstance(data, (Response, HTTPException)):
+                response = self.make_response(request, data)
+            else:
+                response = data
 
         if origin and isinstance(response, Response):
             response.headers['Access-Control-Allow-Origin'] = origin