Commits

Adam Ahmed committed 7e953a7

Add logging throough MEAT

Comments (0)

Files changed (6)

 node_modules
 lib/gapps/data/auth_tokens
+.*\.log
 
 var logger = new (winston.Logger)({
     transports: [
-      new winston.transports.Console(),
+        new winston.transports.Console(),
         new winston.transports.File({
       	    filename: path.join(__dirname, '..', 'meat.log')
         })
     ],
     exceptionHandlers: [
+        new winston.transports.Console(),
         new winston.transports.File({
         	filename: path.join(__dirname, '..', 'meat-exception.log')
         })
     app.configure(function() {
         app.set('view engine', 'jade');
         app.set('views', __dirname + '/views');
-        app.use(express.logger(fs.createWriteStream(path.join(__dirname, '..', 'meat-web.log'), { flags : 'a' })));
+        app.use(express.logger({ stream : fs.createWriteStream(path.join(__dirname, '..', 'meat-web.log'), {
+            flags : 'a'
+        })}));
         app.use(express['static'](__dirname + "/../public"));
     });
 

lib/gapps/datasource.js

     );
 }
 
+function eventFilter(gevent) {
+    var attendees = gevent.attendees || [];
+    var keep = gevent.status === 'confirmed' && attendees.some(function(attendee) {
+        // since we asked for events in this room, the room attendee is self=true.
+        // We need to check that the room accepted the event and filter it out otherwise.
+        return attendee.self && attendee.responseStatus === 'accepted';
+    });
+    return keep;
+} 
 
 
 var defaultUpdateSeconds = 60 * 10;
 Datasource.prototype = new (require('events').EventEmitter)();
 
 Datasource.prototype.setTokenData = function(tokenData) {
-    this.gcal = gcal(tokenData);
+    this.gcal = gcal(tokenData, this.logger);
     this.emit('authenticated');
     var self = this;
     this.updateRooms(this.enable.bind(this));
 };
 
 Datasource.prototype.setUpdatePeriod = function(seconds) {
+    this.logger.info('Data update period has been changed from ' +
+        this._periodSeconds + 's to ' + seconds + 's.');
     this._periodSeconds = seconds;
 };
 
 }
 Datasource.prototype.updateRooms = function(cb) {
     var self = this;
+    this.logger.info('Updating room list.');
     this.gcal.getRooms(function(err, res) {
         if (err) {
             self.emit('error', err);
             cb(err);
             return;
         }
-        if (!res || !res.items) {
+        if (!res || (!res.items && !res.kind)) {
             self.emit('error', {
                 message : 'Unrecognized response.',
                 responseBody : res
             return;
         }
 
+        res.items = res.items || [];
+
         var oldRooms = self._rooms;
         var newRooms = res.items.filter(self._roomFilter).map(wrapGRoom);
 
+        self.logger.info('Found ' + res.items.length + ' rooms.');
+        if (res.items.length > newRooms.length) {
+            var rejected = res.items.filter(function() { return !self._roomFilter.apply(this, arguments); });
+            rejected.forEach(function(room) {
+                self.logger.info('Rejected room ' + room.id);
+            });
+        }
+
         // use all the new room data, but migrate over any event data so we don't lose it needlessly.
         newRooms.forEach(function(newRoom) {
             var oldRoomIndex = roomIndexForKey(self, newRoom.getKey());
 };
 
 Datasource.prototype.load = function(cb) {
-    var self = this;
+    this.logger.info('Loading new room events.');
     var cnt = 0;
     var gcal = this.gcal;
     this._rooms.forEach(function(room) {
+        this.logger.info('Requesting events for ' + room.getName());
         cnt++;
         gcal.getUpcomingEvents(room.getKey(), function(err, res) {
             cnt--;
 
             if (err) {
-                self.emit('error', err);
+                this.logger.error('Error requesting events for ' + room.getName(), err);
+                this.emit('error', err);
                 cb(err);
                 return;
             }
             if (!res || (!res.items && !res.kind)) {
-                self.emit('error', {
+                this.logger.error('Unrecognized response when requesting events for ' + room.getName(), res);
+                this.emit('error', {
                     message : 'Unrecognized response.',
                     responseBody : res
                 });
                 return;
             }
 
-            room.setEvents(res.items ? res.items.filter(function(gevent) {
-                var attendees = gevent.attendees || [];
-                var keep = gevent.status === 'confirmed' && attendees.some(function(attendee) {
-                    // since we asked for events in this room, the room attendee is self=true.
-                    // We need to check that the room accepted the event and filter it out otherwise.
-                    return attendee.self && attendee.responseStatus === 'accepted';
-                });
-                return keep;
-            }).map(function(gevent) {
-                return wrapGEvent(gevent, res.timeZone, self.logger);
-            }) : []);
+            res.items = res.items || [];
+
+            this.logger.info('Got back ' + res.items.length + ' events for ' + room.getName() + '.');
+
+            var filteredEvents = res.items.filter(eventFilter).map(function(gevent) {
+                return wrapGEvent(gevent, res.timeZone, this.logger);
+            }.bind(this));
+
+            if (filteredEvents.length !== res.items.length) {
+                res.items.filter(function() { return !eventFilter.apply(this, arguments); }).forEach(function(item) {
+                    this.logger.info('Event rejected for ' + room.getName()+ ': ' +
+                        (item.id || 'No ID') + ' (' + (item.summary || ' No summary') + ')');
+                }.bind(this));
+            }
+
+            room.setEvents(filteredEvents);
 
             if (!cnt) {
+                this.logger.info('Finished loading events for all rooms.');
                 cb();
             }
-        });
-    });
+        }.bind(this));
+    }.bind(this));
 };
 
 function beginUpdates(ds, intervalMs) {
     if (ds.enabled) {
         ds.load(function() {
+            ds.logger.info('Queuing another event load in ' + (intervalMs/1000) + 's');
             setTimeout(function() { beginUpdates(ds, intervalMs); }, intervalMs);
         });
     } else {
 
 Datasource.prototype.enable = function() {
     if (!this.gcal) {
+        this.logger.warn('datasource is not initialized. Not enabling data updates.');
         return;
     }
+    this.logger.info('Enabling data updates.');
 
     // don't start a new loop if we're already enabled or if we disabled and reenabled fast enough that
     // the update loop wasn't interrupted.
     }
 };
 Datasource.prototype.disable = function() {
-    logger.log('Disabling data updates.');
+    this.logger.info('Disabling data updates.');
     this.disabling = this.enabled;
     this.enabled = false;
 };

lib/gapps/gcal.js

     }
     return arr.join('&');
 }
-function makeRequest(token, method, uri, opt_data, cb) {
+function makeRequest(token, method, uri, data, logger, cb) {
     var timeout, timedOut;
 
-    if (typeof opt_data === 'function') {
-        cb = opt_data;
-        opt_data = undefined;
-    }
-
     var options = url.parse(uri);
     options.headers = {
         'Authorization' : 'Bearer ' + token
     };
-    if (opt_data) {
+    if (data) {
         options.headers['content-type'] = 'application/json';
     }
     options.method = method;
 
+    logger.info('GCal requesting HTTP ' + method + ' ' + uri);
+
     var req = https.request(options, function(res) {
-        var data = '';
-        res.on('data', function(d) { data += d; });
+        var resBody = '';
+        res.on('data', function(d) { resBody += d; });
         res.on('end', function() {
             if (timedOut) {
                 return;
             }
             clearTimeout(timeout);
+
+            logger.info('GCal got response from ' + uri);
+
             var json;
             try {
-                json = JSON.parse(data);
+                json = JSON.parse(resBody);
             } catch(e) {
+                logger.warn('GCal got non-JSON response from ' + uri, resBody);
                 cb({
                     message : e,
                     url : uri,
-                    responseBody : data,
-                    requestBody : opt_data
+                    responseBody : resBody,
+                    requestBody : data
                 });
             }
             cb(null, json);
     req.on('error', cb);
     timeout = setTimeout(function() {
         timedOut = true;
+        logger.warn('GCal request to ' + uri + ' timed out.');
         req.abort();
         cb('Timed out.');
     }, 20 * 1000);
 
-    if (opt_data) {
-        req.write(typeof opt_data === 'string' ? opt_data : JSON.stringify(opt_data));
+    if (data) {
+        req.write(typeof data === 'string' ? data : JSON.stringify(data));
     }
     req.end();
 }
 
-function GCal(tokenData) {
+function GCal(tokenData, logger) {
     this._tokenData = tokenData;
+    this.logger = logger;
 }
 
 GCal.prototype.book = function(calendarId, startDate, endDate, cb) {
                     email : calendarId,
                     resource : true
                 }]
-            }, cb);
+            }, self.logger, cb);
     });
 };
 GCal.prototype.getUpcomingEvents = function(calendarId, cb) {
                 singleEvents : true,
                 timeMin : new Date().toISOString(),
                 timeMax : new Date(new Date().getTime() + (24 * 60 * 60 * 1000)).toISOString()
-            }), cb);
+            }), undefined, self.logger, cb);
     });
 };
 GCal.prototype.getEvent = function(calendarId, eventId, cb) {
         }
 
         makeRequest(self._tokenData.getToken(), 'GET',
-            'https://www.googleapis.com/calendar/v3/calendars/' + calendarId + '/events/' + eventId, cb);
+            'https://www.googleapis.com/calendar/v3/calendars/' + calendarId + '/events/' + eventId,
+             undefined, self.logger, cb);
     });
 };
 GCal.prototype.getRooms = function(cb) {
         }
 
         makeRequest(self._tokenData.getToken(), 'GET',
-            'https://www.googleapis.com/calendar/v3/users/me/calendarList', cb);
+            'https://www.googleapis.com/calendar/v3/users/me/calendarList', undefined, self.logger, cb);
     });
 };
 
-module.exports = function(tokenData) {
-    return new GCal(tokenData);
+module.exports = function(tokenData, logger) {
+    return new GCal(tokenData, logger);
 };

lib/models/room.js

 	this._events = [];
 }
 Room.prototype.getKey = function() { return this._key; };
+Room.prototype.getName = function() { return this._name; };
 Room.prototype.getEvents = function() { return this._events; };
 
 Room.prototype.setEvents = function(events) {
Tip: Filter by directory path e.g. /media app.js to search for public/media/app.js.
Tip: Use camelCasing e.g. ProjME to search for ProjectModifiedEvent.java.
Tip: Filter by extension type e.g. /repo .js to search for all .js files in the /repo directory.
Tip: Separate your search with spaces e.g. /ssh pom.xml to search for src/ssh/pom.xml.
Tip: Use ↑ and ↓ arrow keys to navigate and return to view the file.
Tip: You can also navigate files with Ctrl+j (next) and Ctrl+k (previous) and view the file with Ctrl+o.
Tip: You can also navigate files with Alt+j (next) and Alt+k (previous) and view the file with Alt+o.