feature: logging system (#11)

* feature: init logging system * fix: delete duplicate datatime * fix: logging cmd format
cnstark · Dec 25, 2020 · 678e120 · 678e120
1 parent b269279
commit 678e120
Show file tree

Hide file tree

Showing 5 changed files with 97 additions and 10 deletions.
diff --git a/.gitignore b/.gitignore
@@ -3,6 +3,7 @@ __pycache__
 
 running_log
 private_key
+server_log
 
 */migrations/*
 !*/migrations/__init__.py

diff --git a/gpu_info/utils.py b/gpu_info/utils.py
@@ -1,9 +1,12 @@
 import os
 import subprocess
 import json
+import logging
 
 from .models import GPUServer, GPUInfo
 
+task_logger = logging.getLogger('django.task')
+
 
 def ssh_execute(host, user, exec_cmd, private_key_path=None):
     if private_key_path is None:
@@ -88,6 +91,6 @@ def update_gpu_info(self):
                         gpu_info.processes = '\n'.join(map(lambda x: json.dumps(x), gpu['processes']))
                         gpu_info.save()
             except subprocess.CalledProcessError:
-                print('Update ' + server.ip + ' failed')
+                task_logger.error('Update ' + server.ip + ' failed')
                 server.valid = False
                 server.save()
diff --git a/gpu_tasker/settings.py b/gpu_tasker/settings.py
@@ -139,6 +139,83 @@
 if not os.path.isdir(PRIVATE_KEY_DIR):
     os.makedirs(PRIVATE_KEY_DIR)
 
+SERVER_LOG_DIR = os.path.join(BASE_DIR, 'server_log')
+if not os.path.isdir(SERVER_LOG_DIR):
+    os.makedirs(SERVER_LOG_DIR)
+
+LOGGING = {
+    'version': 1,
+    'disable_existing_loggers': True,
+    'formatters': {
+        'standard': {
+            'format': '%(asctime)s [%(threadName)s:%(thread)d] [%(name)s:%(lineno)d] [%(module)s:%(funcName)s] [%(levelname)s]- %(message)s'},
+    },
+    'filters': {
+        'require_debug_true': {
+            '()': 'django.utils.log.RequireDebugTrue',
+        },
+        'require_debug_false': {
+            '()': 'django.utils.log.RequireDebugFalse',
+        }
+    },
+    'handlers': {
+        'null': {
+            'level': 'DEBUG',
+            'class': 'logging.NullHandler',
+        },
+        'console': {
+            'level': 'DEBUG',
+            'class': 'logging.StreamHandler',
+            'formatter': 'standard'
+        },
+        'req_err': {
+            'level': 'ERROR',
+            'class': 'logging.handlers.RotatingFileHandler',
+            'filename': os.path.join(SERVER_LOG_DIR, 'request_error.log'),
+            'maxBytes': 1024 * 1024 * 5,
+            'backupCount': 5,
+            'formatter': 'standard',
+        },
+        'req_info': {
+            'level': 'INFO',
+            'class': 'logging.handlers.RotatingFileHandler',
+            'filename': os.path.join(SERVER_LOG_DIR, 'request_info.log'),
+            'maxBytes': 1024 * 1024 * 5,
+            'backupCount': 5,
+            'formatter': 'standard',
+        },
+        'info_log': {
+            'level': 'INFO',
+            'class': 'logging.handlers.RotatingFileHandler',
+            'filename': os.path.join(SERVER_LOG_DIR, 'task_info.log'),
+            'maxBytes': 1024 * 1024 * 5,
+            'backupCount': 5,
+            'formatter': 'standard',
+        },
+    },
+    'loggers': {  # logging管理器
+        'django': {
+            'handlers': ['req_info'],
+            'level': 'INFO',
+            'propagate': False
+        },
+        'django.request': {
+            'handlers': ['req_err'],
+            'level': 'ERROR',
+            'propagate': False,
+        },
+        'django.task': {
+            'handlers': ['info_log', 'console'],
+            'level': 'INFO',
+            'propagate': False,
+        },
+        'django.security.DisallowedHost': {
+            'handlers': ['null'],
+            'propagate': False,
+        },
+    }
+}
+
 try:
     from gpu_tasker.email_settings import *
     EMAIL_NOTIFICATION = True

diff --git a/main.py b/main.py
@@ -5,6 +5,7 @@
 import time
 from datetime import datetime
 import threading
+import logging
 
 import django
 
@@ -15,18 +16,19 @@
 from task.models import GPUTask
 from task.utils import run_task
 from gpu_info.models import GPUServer
-from gpu_info.utils import GPUInfoUpdater, add_hostname
+from gpu_info.utils import GPUInfoUpdater
+
+task_logger = logging.getLogger('django.task')
 
 
 if __name__ == '__main__':
     server_username, server_private_key_path, gpustat_path = get_admin_config()
 
     gpu_updater = GPUInfoUpdater(server_username, gpustat_path, server_private_key_path)
     while True:
-        print('{:s}, Running processes: {:d}'.format(
-            datetime.now().strftime("%Y-%m-%d %H:%M:%S"),
-            threading.active_count() - 1)
-        )
+        task_logger.info('Running processes: {:d}'.format(
+            threading.active_count() - 1
+        ))
         start_time = time.time()
         gpu_updater.update_gpu_info()
         for task in GPUTask.objects.filter(status=0):

diff --git a/task/utils.py b/task/utils.py
@@ -4,6 +4,7 @@
 import json
 import time
 import traceback
+import logging
 
 from gpu_tasker.settings import RUNNING_LOG_DIR
 from .models import GPUTask, GPUTaskRunningLog
@@ -12,6 +13,9 @@
     send_task_start_email, send_task_finish_email, send_task_fail_email
 
 
+task_logger = logging.getLogger('django.task')
+
+
 def generate_ssh_cmd(host, user, exec_cmd, private_key_path=None):
     exec_cmd = exec_cmd.replace('$', '\\$')
     if private_key_path is None:
@@ -24,7 +28,7 @@ def generate_ssh_cmd(host, user, exec_cmd, private_key_path=None):
 class RemoteProcess:
     def __init__(self, user, host, cmd, workspace="~", private_key_path=None, output_file=None):
         self.cmd = generate_ssh_cmd(host, user, "cd {} && {}".format(workspace, cmd), private_key_path)
-        print(self.cmd)
+        task_logger.info('cmd:\n' + self.cmd)
         if output_file is not None:
             self.output_file = output_file
             with open(self.output_file, "wb") as out:
@@ -82,7 +86,7 @@ def run_task(task, available_server):
             log_file_path
         )
         pid = process.pid()
-        print('Task {:d}-{:s} is running, pid: {:d}'.format(task.id, task.name, pid))
+        task_logger.info('Task {:d}-{:s} is running, pid: {:d}'.format(task.id, task.name, pid))
 
         # save process status
         running_log.pid = pid
@@ -97,7 +101,7 @@ def run_task(task, available_server):
 
         # wait for return
         return_code = process.get_return_code()
-        print('Task {:d}-{:s} stopped, return_code: {:d}'.format(task.id, task.name, return_code))
+        task_logger.info('Task {:d}-{:s} stopped, return_code: {:d}'.format(task.id, task.name, return_code))
 
         # save process status
         running_log.status = 2 if return_code == 0 else -1
@@ -112,7 +116,7 @@ def run_task(task, available_server):
             send_task_fail_email(running_log)
     except Exception:
         es = traceback.format_exc()
-        print(es)
+        task_logger.error(es)
         running_log.status = -1
         running_log.save()
         task.status = -1