Refactor logging

lib/client.js

@@ -29,19 +29,24 @@ class Client {
   constructor(req, res, connection) {
     this.req = req;
     this.res = res;
+    this.ip = req.socket.remoteAddress;
     this.connection = connection;
   }
 
   static() {
-    const { req: { url }, res } = this;
+    const { req: { url, method }, res, ip } = this;
     const filePath = url === '/' ? '/index.html' : url;
     const fileExt = path.extname(filePath).substring(1);
     const mimeType = MIME_TYPES[fileExt] || MIME_TYPES.html;
     res.writeHead(200, { ...HEADERS, 'Content-Type': mimeType });
     if (res.writableEnded) return;
     const data = application.static.get(filePath);
-    if (data) res.end(data);
-    else this.error(404);
+    if (data) {
+      res.end(data);
+      application.logger.log(`${ip}\t${method}\t${url}`);
+      return;
+    }
+    this.error(404);
   }
 
   redirect(location) {
@@ -51,38 +56,43 @@ class Client {
     res.end();
   }
 
-  error(status, err, callId = err) {
-    const { req: { url }, res, connection } = this;
-    const reason = http.STATUS_CODES[status];
+  error(code, err, callId = err) {
+    const { req: { url, method }, res, connection, ip } = this;
+    const status = http.STATUS_CODES[code];
     if (typeof err === 'number') err = undefined;
-    const error = err ? err.stack : reason;
-    const msg = status === 403 ? err.message : `${url} - ${error} - ${status}`;
-    application.logger.error(msg);
-    const packet = { callback: callId, error: { message: reason } };
-    const result = JSON.stringify(packet);
+    const reason = err ? err.stack : status;
+    application.logger.error(`${ip}\t${method}\t${url}\t${code}\t${reason}`);
     if (connection) {
-      connection.send(result);
+      const packet = { callback: callId, error: { code, message: status } };
+      connection.send(JSON.stringify(packet));
       return;
     }
     if (res.writableEnded) return;
-    res.writeHead(status, { 'Content-Type': MIME_TYPES.json });
-    res.end(result);
+    res.writeHead(code, { 'Content-Type': MIME_TYPES.json });
+    const packet = { code, error: status };
+    res.end(JSON.stringify(packet));
   }
 
   message(data) {
+    let packet;
     try {
-      const packet = JSON.parse(data);
-      const [callType, methodName] = Object.keys(packet);
-      const callId = packet[callType];
-      const args = packet[methodName];
-      this.rpc(callId, methodName, args);
+      packet = JSON.parse(data);
     } catch (err) {
-      application.logger.error(err.message);
+      this.error(500, new Error('JSON parsing error'));
+      return;
+    }
+    const [callType, methodName] = Object.keys(packet);
+    const callId = packet[callType];
+    const args = packet[methodName];
+    if (callId && args) {
+      this.rpc(callId, methodName, args);
+      return;
     }
+    this.error(500, new Error('Packet structure error'));
   }
 
   async rpc(callId, method, args) {
-    const { res, connection } = this;
+    const { res, connection, ip } = this;
     const { semaphore } = application.server;
     try {
       await semaphore.enter();
@@ -91,25 +101,27 @@ class Client {
       return;
     }
     try {
-      const session = await application.auth.restore(this);
+      let session = await application.auth.restore(this);
       const proc = application.runMethod(method, session);
       if (!proc) {
         this.error(404, callId);
         return;
       }
       if (!session && proc.access !== 'public') {
-        this.error(403, new Error(`Forbidden: /api/${method}`), callId);
+        this.error(403, callId);
         return;
       }
       const result = await proc.method(args);
       if (!session && proc.access === 'public') {
-        const session = application.auth.start(this, result.userId);
+        session = application.auth.start(this, result.userId);
         result.token = session.token;
       }
       const packet = { callback: callId, result };
       const data = JSON.stringify(packet);
       if (connection) connection.send(data);
       else res.end(data);
+      const token = session ? session.token : 'anonymous';
+      application.logger.log(`${ip}\t${token}\t${method}`);
     } catch (err) {
       this.error(500, err, callId);
     } finally {

lib/logger.js

@@ -8,6 +8,8 @@ const COLORS = {
   error: '\x1b[0;31m',
 };
 
+const DATETIME_LENGTH = 19;
+
 class Logger {
   constructor(logPath, threadId = 0) {
     this.path = logPath;
@@ -18,7 +20,8 @@ class Logger {
   }
 
   write(level = 'info', s) {
-    const date = new Date().toISOString();
+    const now = new Date().toISOString();
+    const date = now.substring(0, DATETIME_LENGTH);
     const color = COLORS[level];
     const line = date + '\t' + s;
     console.log(color + line + '\x1b[0m');

lib/server.js

@@ -49,10 +49,9 @@ const listener = (req, res) => {
     clients.delete(connection);
   });
 
-  application.logger.log(`${method}\t${url}`);
   if (url === '/api') {
     if (method !== 'POST') {
-      client.error(403, new Error(`Forbidden: ${url}`));
+      client.error(403);
       return;
     }
     receiveBody(req).then(data => {