PINO JSON logging

packages/api/src/controllers/archive.js

@@ -6,6 +6,9 @@ const socket = require('../utility/socket');
 const { saveFreeTableData } = require('../utility/freeTableStorage');
 const loadFilesRecursive = require('../utility/loadFilesRecursive');
 const getJslFileName = require('../utility/getJslFileName');
+const { getLogger } = require('dbgate-tools');
+
+const logger = getLogger();
 
 module.exports = {
   folders_meta: true,
@@ -68,7 +71,7 @@ module.exports = {
         ...fileType('.matview.sql', 'matview.sql'),
       ];
     } catch (err) {
-      console.log('Error reading archive files', err.message);
+      logger.error('Error reading archive files', err.message);
       return [];
     }
   },

packages/api/src/controllers/auth.js

@@ -3,8 +3,11 @@ const jwt = require('jsonwebtoken');
 const getExpressPath = require('../utility/getExpressPath');
 const uuidv1 = require('uuid/v1');
 const { getLogins } = require('../utility/hasPermission');
+const { getLogger } = require('dbgate-tools');
 const AD = require('activedirectory2').promiseWrapper;
 
+const logger = getLogger();
+
 const tokenSecret = uuidv1();
 
 function shouldAuthorizeApi() {
@@ -51,7 +54,7 @@ function authMiddleware(req, res, next) {
       return next();
     }
 
-    console.log('Sending invalid token error', err.message);
+    logger.error('Sending invalid token error', err.message);
 
     return unauthorizedResponse(req, res, 'invalid token');
   }
@@ -74,7 +77,7 @@ module.exports = {
 
     const payload = jwt.decode(access_token);
 
-    console.log('User payload returned from OAUTH:', payload);
+    logger.info({ payload }, 'User payload returned from OAUTH');
 
     const login =
       process.env.OAUTH_LOGIN_FIELD && payload && payload[process.env.OAUTH_LOGIN_FIELD]
@@ -122,7 +125,7 @@ module.exports = {
           accessToken: jwt.sign({ login }, tokenSecret, { expiresIn: getTokenLifetime() }),
         };
       } catch (err) {
-        console.log('Failed active directory authentization', err.message);
+        logger.error('Failed active directory authentization', err);
         return {
           error: err.message,
         };

packages/api/src/controllers/connections.js

@@ -12,10 +12,12 @@ const { pickSafeConnectionInfo } = require('../utility/crypting');
 const JsonLinesDatabase = require('../utility/JsonLinesDatabase');
 
 const processArgs = require('../utility/processArgs');
-const { safeJsonParse } = require('dbgate-tools');
+const { safeJsonParse, getLogger } = require('dbgate-tools');
 const platformInfo = require('../utility/platformInfo');
 const { connectionHasPermission, testConnectionPermission } = require('../utility/hasPermission');
 
+const logger = getLogger();
+
 let volatileConnections = {};
 
 function getNamedArgs() {
@@ -86,13 +88,13 @@ function getPortalCollections() {
       sslKeyFile: process.env[`SSL_KEY_FILE_${id}`],
       sslRejectUnauthorized: process.env[`SSL_REJECT_UNAUTHORIZED_${id}`],
     }));
-    console.log('Using connections from ENV variables:');
-    console.log(JSON.stringify(connections.map(pickSafeConnectionInfo), undefined, 2));
+
+    logger.info({ connections: connections.map(pickSafeConnectionInfo) }, 'Using connections from ENV variables');
     const noengine = connections.filter(x => !x.engine);
     if (noengine.length > 0) {
-      console.log(
-        'Warning: Invalid CONNECTIONS configutation, missing ENGINE for connection ID:',
-        noengine.map(x => x._id)
+      logger.warn(
+        { connections: noengine.map(x => x._id) },
+        'Invalid CONNECTIONS configutation, missing ENGINE for connection ID'
       );
     }
     return connections;

packages/api/src/controllers/databaseConnections.js

@@ -12,6 +12,7 @@ const {
   matchPairedObjects,
   extendDatabaseInfo,
   modelCompareDbDiffOptions,
+  getLogger,
 } = require('dbgate-tools');
 const { html, parse } = require('diff2html');
 const { handleProcessCommunication } = require('../utility/processComm');
@@ -29,6 +30,8 @@ const processArgs = require('../utility/processArgs');
 const { testConnectionPermission } = require('../utility/hasPermission');
 const { MissingCredentialsError } = require('../utility/exceptions');
 
+const logger = getLogger();
+
 module.exports = {
   /** @type {import('dbgate-types').OpenedDatabaseConnection[]} */
   opened: [],
@@ -60,7 +63,7 @@ module.exports = {
 
   handle_error(conid, database, props) {
     const { error } = props;
-    console.log(`Error in database connection ${conid}, database ${database}: ${error}`);
+    logger.error(`Error in database connection ${conid}, database ${database}: ${error}`);
   },
   handle_response(conid, database, { msgid, ...response }) {
     const [resolve, reject] = this.requests[msgid];
@@ -137,7 +140,7 @@ module.exports = {
   queryData_meta: true,
   async queryData({ conid, database, sql }, req) {
     testConnectionPermission(conid, req);
-    console.log(`Processing query, conid=${conid}, database=${database}, sql=${sql}`);
+    logger.info({ conid, database, sql }, 'Processing query');
     const opened = await this.ensureOpened(conid, database);
     // if (opened && opened.status && opened.status.name == 'error') {
     //   return opened.status;
@@ -157,7 +160,7 @@ module.exports = {
   runScript_meta: true,
   async runScript({ conid, database, sql }, req) {
     testConnectionPermission(conid, req);
-    console.log(`Processing script, conid=${conid}, database=${database}, sql=${sql}`);
+    logger.info({ conid, database, sql }, 'Processing script');
     const opened = await this.ensureOpened(conid, database);
     const res = await this.sendRequest(opened, { msgtype: 'runScript', sql });
     return res;

packages/api/src/controllers/runners.js

@@ -6,10 +6,17 @@ const byline = require('byline');
 const socket = require('../utility/socket');
 const { fork } = require('child_process');
 const { rundir, uploadsdir, pluginsdir, getPluginBackendPath, packagedPluginList } = require('../utility/directories');
-const { extractShellApiPlugins, extractShellApiFunctionName, jsonScriptToJavascript } = require('dbgate-tools');
+const {
+  extractShellApiPlugins,
+  extractShellApiFunctionName,
+  jsonScriptToJavascript,
+  getLogger,
+  safeJsonParse,
+} = require('dbgate-tools');
 const { handleProcessCommunication } = require('../utility/processComm');
 const processArgs = require('../utility/processArgs');
 const platformInfo = require('../utility/platformInfo');
+const logger = getLogger();
 
 function extractPlugins(script) {
   const requireRegex = /\s*\/\/\s*@require\s+([^\s]+)\s*\n/g;
@@ -29,13 +36,14 @@ const requirePluginsTemplate = (plugins, isExport) =>
 
 const scriptTemplate = (script, isExport) => `
 const dbgateApi = require(${isExport ? `'dbgate-api'` : 'process.env.DBGATE_API'});
+const logger = dbgateApi.getLogger();
 dbgateApi.initializeApiEnvironment();
 ${requirePluginsTemplate(extractPlugins(script), isExport)}
 require=null;
 async function run() {
 ${script}
 await dbgateApi.finalizer.run();
-console.log('Finished job script');
+logger.info('Finished job script');
 }
 dbgateApi.runScript(run);
 `;
@@ -59,19 +67,17 @@ module.exports = {
   requests: {},
 
   dispatchMessage(runid, message) {
-    if (message) console.log('...', message.message);
-    if (_.isString(message)) {
-      socket.emit(`runner-info-${runid}`, {
-        message,
-        time: new Date(),
-        severity: 'info',
-      });
-    }
-    if (_.isPlainObject(message)) {
+    if (message) {
+      const json = safeJsonParse(message.message);
+
+      if (json) logger.info(json);
+      else logger.info(message.message);
+
       socket.emit(`runner-info-${runid}`, {
         time: new Date(),
         severity: 'info',
         ...message,
+        message: json ? json.msg : message.message,
       });
     }
   },
@@ -98,7 +104,7 @@ module.exports = {
     fs.writeFileSync(`${scriptFile}`, scriptText);
     fs.mkdirSync(directory);
     const pluginNames = _.union(fs.readdirSync(pluginsdir()), packagedPluginList);
-    console.log(`RUNNING SCRIPT ${scriptFile}`);
+    logger.info({ scriptFile }, 'Running script');
     // const subprocess = fork(scriptFile, ['--checkParent', '--max-old-space-size=8192'], {
     const subprocess = fork(
       scriptFile,
@@ -124,7 +130,7 @@ module.exports = {
     byline(subprocess.stderr).on('data', pipeDispatcher('error'));
     subprocess.on('exit', code => {
       this.rejectRequest(runid, { message: 'No data retured, maybe input data source is too big' });
-      console.log('... EXIT process', code);
+      logger.info({ code, pid: subprocess.pid }, 'Exited process');
       socket.emit(`runner-done-${runid}`, code);
     });
     subprocess.on('error', error => {

packages/api/src/controllers/scheduler.js

@@ -4,6 +4,9 @@ const path = require('path');
 const cron = require('node-cron');
 const runners = require('./runners');
 const { hasPermission } = require('../utility/hasPermission');
+const { getLogger } = require('dbgate-tools');
+
+const logger = getLogger();
 
 const scheduleRegex = /\s*\/\/\s*@schedule\s+([^\n]+)\n/;
 
@@ -21,7 +24,7 @@ module.exports = {
     if (!match) return;
     const pattern = match[1];
     if (!cron.validate(pattern)) return;
-    console.log(`Schedule script ${file} with pattern ${pattern}`);
+    logger.info(`Schedule script ${file} with pattern ${pattern}`);
     const task = cron.schedule(pattern, () => runners.start({ script: text }));
     this.tasks.push(task);
   },

packages/api/src/controllers/sessions.js

@@ -8,6 +8,9 @@ const path = require('path');
 const { handleProcessCommunication } = require('../utility/processComm');
 const processArgs = require('../utility/processArgs');
 const { appdir } = require('../utility/directories');
+const { getLogger } = require('dbgate-tools');
+
+const logger = getLogger();
 
 module.exports = {
   /** @type {import('dbgate-types').OpenedSession[]} */
@@ -120,7 +123,7 @@ module.exports = {
       throw new Error('Invalid session');
     }
 
-    console.log(`Processing query, sesid=${sesid}, sql=${sql}`);
+    logger.info({ sesid, sql }, 'Processing query');
     this.dispatchMessage(sesid, 'Query execution started');
     session.subprocess.send({ msgtype: 'executeQuery', sql });
 
@@ -158,7 +161,7 @@ module.exports = {
       throw new Error('Invalid session');
     }
 
-    console.log(`Starting profiler, sesid=${sesid}`);
+    logger.info({ sesid }, 'Starting profiler');
     session.loadingReader_jslid = jslid;
     session.subprocess.send({ msgtype: 'startProfiler', jslid });
 

packages/api/src/controllers/uploads.js

@@ -1,6 +1,8 @@
 const path = require('path');
 const { uploadsdir } = require('../utility/directories');
 const uuidv1 = require('uuid/v1');
+const { getLogger } = require('dbgate-tools');
+const logger = getLogger();
 
 module.exports = {
   upload_meta: {
@@ -15,7 +17,7 @@ module.exports = {
     }
     const uploadName = uuidv1();
     const filePath = path.join(uploadsdir(), uploadName);
-    console.log(`Uploading file ${data.name}, size=${data.size}`);
+    logger.info(`Uploading file ${data.name}, size=${data.size}`);
 
     data.mv(filePath, () => {
       res.json({