Add more logging.

p1stream · Mar 5, 2015 · 554e975 · 554e975
1 parent e6f170f
commit 554e975
Show file tree

Hide file tree

Showing 6 changed files with 50 additions and 11 deletions.
diff --git a/lib/index.js b/lib/index.js
@@ -19,10 +19,10 @@ module.exports = function() {
     scope.server = http.createServer(scope.app);
 
     // Load all services, models and controllers.
-    require('./svc/util')(scope);
-    require('./svc/config')(scope);
-    require('./svc/objStore')(scope);
     require('./svc/logging')(scope);
+    require('./svc/objStore')(scope);
+    require('./svc/config')(scope);
+    require('./svc/util')(scope);
 
     require('./model/roots')(scope);
     require('./model/sources')(scope);

diff --git a/lib/model/mixers.js b/lib/model/mixers.js
@@ -124,10 +124,14 @@ module.exports = function(scope) {
         obj.$watchValue(function() {
             return !obj.hadError && obj.numFrameListeners;
         }, function(shouldRun) {
-            if (shouldRun && !obj.$instance)
+            if (shouldRun && !obj.$instance) {
+                obj.$log.info("Mixer activated");
                 start();
-            else if (!shouldRun && obj.$instance)
+            }
+            else if (!shouldRun && obj.$instance) {
+                obj.$log.info("Mixer deactivated");
                 stop();
+            }
         });
 
         // Stop the mixer on destroy.

diff --git a/lib/model/sources.js b/lib/model/sources.js
@@ -25,10 +25,14 @@ module.exports = function(scope) {
                 val = !!val;
                 if (running !== val) {
                     running = val;
-                    if (val)
+                    if (val) {
+                        obj.$log.info("Source activated");
                         params.start();
-                    else
+                    }
+                    else {
+                        obj.$log.info("Source deactivated");
                         params.stop();
+                    }
                 }
             });
 

diff --git a/lib/svc/config.js b/lib/svc/config.js
@@ -5,6 +5,7 @@ var userPaths = require('../userPaths');
 module.exports = function(scope) {
     scope.cfgFile = userPaths.configPath();
 
+    scope.log.info("Reading config file '%s'", scope.cfgFile);
     try {
         scope.cfg = JSON.parse(fs.readFileSync(scope.cfgFile, 'utf8'));
     }
@@ -13,12 +14,16 @@ module.exports = function(scope) {
             scope.log.error(err, "Could not read '%s'", scope.cfgFile);
         scope.cfg = {};
     }
+    scope.log.debug("Loaded %d objects", _.size(scope.cfg));
 
     // Create instances of all objects in configuration.
     // Should be called once after all onCreate listeners are installed.
     scope.initFromConfig = function() {
         scope.$broadcast('preInit');
+
+        scope.log.debug("Initializing %d objects", _.size(scope.cfg));
         _.each(scope.cfg, scope.o.$create);
+
         scope.$broadcast('postInit');
     };
 
@@ -32,6 +37,7 @@ module.exports = function(scope) {
         });
 
         // Write the file.
+        scope.log.info("Writing config file '%s'", scope.cfgFile);
         try {
             var json = JSON.stringify(cfg, function(key, value) {
                 return key[0] === '$' ? undefined : value;
@@ -40,6 +46,9 @@ module.exports = function(scope) {
         }
         catch (err) {
             scope.log.error(err, "Could not write '%s'", scope.cfgFile);
+            return;
         }
+
+        scope.log.debug("Wrote %d objects", _.size(cfg));
     };
 };
diff --git a/lib/svc/logging.js b/lib/svc/logging.js
@@ -43,9 +43,26 @@ module.exports = function(scope) {
         streams: streams
     });
 
-    // Create a logger per object.
-    scope.o.$onCreate(function(obj) {
-        obj.$log = scope.log.child({ obj: obj.$id });
+    // Say hi!
+    var version = require('../../package.json').version;
+    scope.log.info("P1stream v%s starting", version);
+
+    // HTTP request logging
+    scope.app.use(function(req, res, next) {
+        var isApiRequest = (req.url.slice(0, 5) === '/api/');
+
+        var writeHead = res.writeHead;
+        res.writeHead = function(a, b, c) {
+            res.writeHead = writeHead;
+            res.writeHead(a, b, c);
+
+            var level = (res.statusCode >= 400) ? 'warn' :
+                        (isApiRequest ? 'info' : 'debug');
+            scope.log[level]("%s - %s %s - %s", req.socket.remoteAddress,
+                req.method, req.url, res.statusCode);
+        };
+
+        next();
     });
 
     // Helper method to handle standard events.

diff --git a/lib/svc/objStore.js b/lib/svc/objStore.js
@@ -16,17 +16,22 @@ module.exports = function(scope) {
 
     // Create an object.
     store.$create = function(cfg, id) {
+        if (!id) id = uuid();
         var obj = _.extend(scope.$new(), methods, {
-            $id: id || uuid(),
+            $id: id,
             $refs: Object.create(null),
+            $log: scope.log.child({ obj: id }),
             $sticky: false,     // Whether to disable GC.
             $ephemeral: false,  // Whether to disable saving to config.
             cfg: cfg
         });
 
         store[obj.$id] = obj;
+        obj.$log.trace("Object created");
+
         obj.$on('$destroy', function() {
             delete store[obj.$id];
+            obj.$log.trace("Object destroyed");
         });
 
         createListeners.forEach(function(fn) {