logging changes

src/app.js

@@ -7,25 +7,7 @@ const ffmpeg = require('fluent-ffmpeg');
 const uniqueFilename = require('unique-filename');
 const endpoints = require('./endpoints.js');
 
-//const winston = require('winston');
+const logger = require('./logger.js')
-//setup custom logger
-const { createLogger, format, transports } = require('winston');
-const { combine, timestamp, label, printf } = format;
-
-const logFormat = printf(({ level, message, label, timestamp }) => {
-  return `${timestamp} [${label}] ${level}: ${message}`;
-});
-
-const logger = createLogger({
-  format: combine(    
-    label({ label: 'ffmpegapi' }),
-    timestamp(),
-    logFormat
-  ),
-  transports: [new transports.Console({
-    level: process.env.LOG_LEVEL || 'info'
-  })]
-});
 
 fileSizeLimit = parseInt(process.env.FILE_SIZE_LIMIT_BYTES || "536870912") //536870912 = 512MB 
 port = 3000;
@@ -34,7 +16,7 @@ timeout = 3600000;
 // catch SIGINT and SIGTERM and exit
 // Using a single function to handle multiple signals
 function handle(signal) {
-    console.log(`Received ${signal}. Exiting...`);
+    logger.info(`Received ${signal}. Exiting...`);
     process.exit(1)
   }  
 //SIGINT is typically CTRL-C
@@ -42,8 +24,6 @@ process.on('SIGINT', handle);
 //SIGTERM is sent to terminate process, for example docker stop sends SIGTERM
 process.on('SIGTERM', handle);
 
-
-
 app.use(compression());
 
 for (let prop in endpoints.types) {
@@ -53,7 +33,6 @@ for (let prop in endpoints.types) {
         app.post('/' + prop, function(req, res) {
             let hitLimit = false;
             let fileName = '';
-            //let savedFile = uniqueFilename(__dirname + '/uploads/');
             let savedFile = uniqueFilename('/tmp/');
             let busboy = new Busboy({
                 headers: req.headers,
@@ -62,10 +41,7 @@ for (let prop in endpoints.types) {
                     fileSize: fileSizeLimit,
             }});
             busboy.on('filesLimit', function() {
-                logger.error(JSON.stringify({
+                logger.error(`upload file size limit hit. max file size ${fileSizeLimit} bytes.`)
-                    type: 'filesLimit',
-                    message: 'Upload file size limit hit',
-                }));
             });
 
             busboy.on('file', function(
@@ -77,38 +53,30 @@ for (let prop in endpoints.types) {
             ) {
                 file.on('limit', function(file) {
                     hitLimit = true;
-                    let err = {file: filename, error: 'exceeds max size limit'};
+                    let msg = `${filename} exceeds max size limit. max file size ${fileSizeLimit} bytes.`
-                    err = JSON.stringify(err);
+                    logger.error(msg);
-                    logger.error(err);
                     res.writeHead(500, {'Connection': 'close'});
-                    res.end(err);
+                    res.end(JSON.stringify({error: msg}));
                 });
                 let log = {
                     file: filename,
                     encoding: encoding,
                     mimetype: mimetype,
                 };
-                logger.log('debug',JSON.stringify(log));
+                logger.debug(`file:${log.file}, encoding: ${log.encoding}, mimetype: ${log.mimetype}`);
                 file.on('data', function(data) {
                     bytes += data.length;
                 });
                 file.on('end', function(data) {
                     log.bytes = bytes;
-                    logger.log('debug',JSON.stringify(log));
+                    logger.debug(`file: ${log.file}, encoding: ${log.encoding}, mimetype: ${log.mimetype}, bytes: ${log.bytes}`);
                 });
 
                 fileName = filename;
-                logger.log('debug',JSON.stringify({
+                logger.debug(`uploading ${fileName}`)
-                    action: 'Uploading',
-                    name: fileName,
-                }));
                 let written = file.pipe(fs.createWriteStream(savedFile));
-
                 if (written) {
-                    logger.log('debug',JSON.stringify({
+                    logger.debug(`${fileName} saved, path: ${savedFile}`)
-                        action: 'saved',
-                        path: savedFile,
-                    }));
                 }
             });
             busboy.on('finish', function() {
@@ -116,53 +84,32 @@ for (let prop in endpoints.types) {
                     fs.unlinkSync(savedFile);
                     return;
                 }
-                logger.log('debug',JSON.stringify({
+                logger.debug(`upload complete. file: ${fileName}`)
-                    action: 'upload complete',
-                    name: fileName,
-                }));
                 let outputFile = savedFile + '.' + ffmpegParams.extension;
-                logger.log('debug',JSON.stringify({
+                logger.debug(`begin conversion from ${savedFile} to ${outputFile}`)
-                    action: 'begin conversion',
+                
-                    from: savedFile,
+                //ffmpeg processing...
-                    to: outputFile,
-                }));
                 let ffmpegConvertCommand = ffmpeg(savedFile);
                 ffmpegConvertCommand
                         .renice(15)
                         .outputOptions(ffmpegParams.outputOptions)
                         .on('error', function(err) {
-                            let log = JSON.stringify({
+                            logger.error(`${err}`);
-                                type: 'ffmpeg',
-                                message: err,
-                            });
-                            logger.error(log);
                             fs.unlinkSync(savedFile);
                             res.writeHead(500, {'Connection': 'close'});
-                            res.end(log);
+                            res.end(JSON.stringify({error: `${err}`}));
                         })
                         .on('end', function() {
                             fs.unlinkSync(savedFile);
-                            logger.log('debug',JSON.stringify({
+                            logger.debug(`starting download to client ${savedFile}`);
-                                action: 'starting download to client',
-                                file: savedFile,
-                            }));
 
                             res.download(outputFile, null, function(err) {
                                 if (err) {
-                                    logger.error(JSON.stringify({
+                                    logger.error(`download ${err}`);
-                                        type: 'download',
-                                        message: err,
-                                    }));
                                 }
-                                logger.log('debug',JSON.stringify({
+                                logger.debug(`deleting ${outputFile}`);
-                                    action: 'deleting',
-                                    file: outputFile,
-                                }));
                                 if (fs.unlinkSync(outputFile)) {
-                                    logger.log('debug',JSON.stringify({
+                                    logger.debug(`deleted ${outputFile}`);
-                                        action: 'deleted',
-                                        file: outputFile,
-                                    }));
                                 }
                             });
                         })
@@ -182,18 +129,11 @@ require('express-readme')(app, {
 const server = app.listen(port, function() {
     let host = server.address().address;
     let port = server.address().port;
-    logger.info(JSON.stringify({
+    logger.info('listening http://'+host+':'+port)
-        action: 'listening',
-        url: 'http://'+host+':'+port,
-    }));
 });
 
-
 server.on('connection', function(socket) {
-    logger.log('debug',JSON.stringify({
+    logger.debug(`new connection, timeout: ${timeout}`);
-        action: 'new connection',
-        timeout: timeout,
-    }));
     socket.setTimeout(timeout);
     socket.server.timeout = timeout;
     server.keepAliveTimeout = timeout;

src/logger.js

@@ -0,0 +1,17 @@
+//setup custom logger
+const { createLogger, format, transports } = require('winston');
+const { combine, timestamp, label, printf } = format;
+
+const logFormat = printf(({ level, message, label, timestamp }) => {
+  return `${timestamp} ${level.toUpperCase()}: ${message}`;
+});
+
+module.exports = createLogger({
+  format: combine(    
+    timestamp(),
+    logFormat
+  ),
+  transports: [new transports.Console({
+    level: process.env.LOG_LEVEL || 'info'
+  })]
+});