feat: logger pino in project

package.json

@@ -12,6 +12,7 @@
   "license": "GPL-3.0",
   "dependencies": {
     "curve25519-js": "^0.0.4",
+    "pino": "^7.11.0",
     "protobufjs": "6.8.8"
   },
   "files": [

src/curve.js

@@ -2,6 +2,9 @@
 'use strict';
 
 const curveJs = require('curve25519-js');
+const logger = require('./logger');
+const loggerChild = logger.getLogger().child({ module: 'curve' });
+
 const nodeCrypto = require('crypto');
 // from: https://github.com/digitalbazaar/x25519-key-agreement-key-2019/blob/master/lib/crypto.js
 const PUBLIC_KEY_DER_PREFIX = Buffer.from([
@@ -34,7 +37,7 @@ function scrubPubKeyFormat(pubKey) {
     if (pubKey.byteLength == 33) {
         return pubKey.slice(1);
     } else {
-        console.error("WARNING: Expected pubkey of length 33, please report the ST and client that generated the pubkey");
+        loggerChild.error("WARNING: Expected pubkey of length 33, please report the ST and client that generated the pubkey");
         return pubKey;
     }
 }

src/logger.js

@@ -0,0 +1,11 @@
+const loggerPino = require('pino');
+
+const _logger = loggerPino();
+
+function getLogger(){
+    return _logger;
+}
+
+
+module.exports = { getLogger }
+

src/queue_job.js

@@ -1,12 +1,14 @@
 // vim: ts=4:sw=4:expandtab
-
+
+const logger = require('./logger');
+const loggerChild = logger.getLogger().child({ module: 'queue_job' });
+
  /*
   * jobQueue manages multiple queues indexed by device to serialize
   * session io ops on the database.
   */
 'use strict';
 
-
 const _queueAsyncBuckets = new Map();
 const _gcLimit = 10000;
 
@@ -47,7 +49,7 @@ module.exports = function(bucket, awaitable) {
         if (typeof bucket === 'string') {
             awaitable.name = bucket;
         } else {
-            console.warn("Unhandled bucket type (for naming):", typeof bucket, bucket);
+            loggerChild.warn({ bucketTypeof: typeof bucket, bucket }, "Unhandled bucket type (for naming):");
         }
     }
     let inactive;

src/session_builder.js

@@ -8,13 +8,13 @@ const crypto = require('./crypto');
 const curve = require('./curve');
 const errors = require('./errors');
 const queueJob = require('./queue_job');
-
-
+const logger = require('./logger');
 class SessionBuilder {
 
     constructor(storage, protocolAddress) {
         this.addr = protocolAddress;
         this.storage = storage;
+        this.logger = logger.getLogger().child({ module: 'session_builder' });
     }
 
     async initOutgoing(device) {
@@ -43,7 +43,7 @@ class SessionBuilder {
             } else {
                 const openSession = record.getOpenSession();
                 if (openSession) {
-                    console.warn("Closing stale open session for new outgoing prekey bundle");
+                    this.logger.warn("Closing stale open session for new outgoing prekey bundle");
                     record.closeSession(openSession);
                 }
             }
@@ -71,7 +71,7 @@ class SessionBuilder {
         }   
         const existingOpenSession = record.getOpenSession();
         if (existingOpenSession) {
-            console.warn("Closing open session in favor of incoming prekey bundle");
+            this.logger.warn("Closing open session in favor of incoming prekey bundle");
             record.closeSession(existingOpenSession);
         }
         record.setSession(await this.initSession(false, preKeyPair, signedPreKeyPair,

src/session_cipher.js

@@ -10,6 +10,9 @@ const errors = require('./errors');
 const protobufs = require('./protobufs');
 const queueJob = require('./queue_job');
 
+const logger = require('./logger');
+const loggerChild = logger.getLogger().child({ module: 'session_cipher' });
+
 const VERSION = 3;
 
 function assertBuffer(value) {
@@ -154,9 +157,9 @@ class SessionCipher {
                 errs.push(e);
             }
         }
-        console.error("Failed to decrypt message with any known session...");
+        loggerChild.error("Failed to decrypt message with any known session...");
         for (const e of errs) {
-            console.error("Session error:" + e, e.stack);
+            loggerChild.error({ stack: e.stack }, "Session error:" + e);
         }
         throw new errors.SessionError("No matching sessions found for message");
     }
@@ -179,7 +182,7 @@ class SessionCipher {
                 // was the most current.  Simply make a note of it and continue.  If our
                 // actual open session is for reason invalid, that must be handled via
                 // a full SessionError response.
-                console.warn("Decrypted message with closed session.");
+                loggerChild.warn("Decrypted message with closed session.");
             }
             await this.storeRecord(record);
             return result.plaintext;

src/session_record.js

@@ -2,6 +2,9 @@
 
 const BaseKeyType = require('./base_key_type');
 
+const logger = require('./logger');
+const loggerChild = logger.getLogger().child({ module: 'session_record' });
+
 const CLOSED_SESSIONS_MAX = 40;
 const SESSION_RECORD_VERSION = 'v1';
 
@@ -170,9 +173,9 @@ const migrations = [{
         } else {
             for (const key in sessions) {
                 if (sessions[key].indexInfo.closed === -1) {
-                    console.error('V1 session storage migration error: registrationId',
-                                  data.registrationId, 'for open session version',
-                                  data.version);
+                    loggerChild.error(
+                        { data }, 'V1 session storage migration error: registrationId ** for open session version **'
+                    );
                 }
             }
         }
@@ -190,7 +193,7 @@ class SessionRecord {
         let run = (data.version === undefined);
         for (let i = 0; i < migrations.length; ++i) {
             if (run) {
-                console.info("Migrating session to:", migrations[i].version);
+                loggerChild.info({migration : migrations[i]}, "Migrating session to");
                 migrations[i].migrate(data);
             } else if (migrations[i].version === data.version) {
                 run = true;
@@ -267,18 +270,18 @@ class SessionRecord {
 
     closeSession(session) {
         if (this.isClosed(session)) {
-            console.warn("Session already closed", session);
+            loggerChild.warn({ session }, "Session already closed");
             return;
         }
-        console.info("Closing session:", session);
+        loggerChild.info({session}, "Closing session");
         session.indexInfo.closed = Date.now();
     }
 
     openSession(session) {
         if (!this.isClosed(session)) {
-            console.warn("Session already open");
+            loggerChild.warn("Session already open");
         }
-        console.info("Opening session:", session);
+        loggerChild.info({session}, "Opening session");
         session.indexInfo.closed = -1;
     }
 
@@ -298,7 +301,7 @@ class SessionRecord {
                 }
             }
             if (oldestKey) {
-                console.info("Removing old closed session:", oldestSession);
+                loggerChild.info({ oldestSession }, "Removing old closed session");
                 delete this.sessions[oldestKey];
             } else {
                 throw new Error('Corrupt sessions object');