BigBlueButton/bigbluebutton-Github
1
0
Fork 0
Code Issues Pull Requests Packages Projects Releases Wiki Activity

Webhooks: use winston for logging and rotate log files

Browse Source
This commit is contained in:
Leonardo Crauss Daronco 2014-11-14 14:12:37 -02:00
parent 6260f26101
commit 536decff7c
12 changed files with 78 additions and 43 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

1
labs/bbb-callback/.gitignore vendored
View File

@ -3,3 +3,4 @@
*.log
node_modules/
config_local.coffee
log/*

13
labs/bbb-callback/README.md
View File

@ -229,7 +229,7 @@ More details
* Hooks are only removed if a call to `/destroy` is made or if the callbacks for the hook fail too many times (~12) for a long period of time (~5min). They are never removed otherwise. Valid for both global hooks and hooks for specific meetings.
* If a meeting is created while the webhooks app is down, callbacks will never be triggered for this meeting. The app needs to detect the create event (`meeting_created_message`) to have a mapping of internal to external meeting IDs.
* Mappings are removed after 24 hours of inactivity. If there are no events at all for a given meeting, it will be assumed dead. This is done to prevent data from being stored forever on redis.
* External URLs are expected to respond with an HTTP status 200. Anything different from it will be considered an error and the callback will be called again. This includes URLs that redirect to some other place.
* External URLs are expected to respond with the HTTP status 200, 201 or 202. Anything different from these values will be considered an error and the callback will be called again. This includes URLs that redirect to some other place.
Development
-----------
@ -296,7 +296,16 @@ sudo chown root:root /etc/monit/conf.d/bbb-webhooks
Open the file and edit it. You might need to change things like the port used by the application.
8. Start the application:
8. Copy logrotate's configuration file and install it:
```bash
sudo cp config/bbb-webhooks.logrotate /etc/logrotate.d/bbb-webhooks
sudo chown root:root /etc/logrotate.d/bbb-webhooks
sudo chmod 644 /etc/logrotate.d/bbb-webhooks
sudo logrotate -s /var/lib/logrotate/status /etc/logrotate.d/bbb-webhooks
```
9. Start the application:
```bash
sudo service bbb-webhooks start

1
labs/bbb-callback/application.coffee
View File

@ -6,6 +6,7 @@ WebServer = require("./web_server")
# Class that defines the application. Listens for events on redis and starts the
# process to perform the callback calls.
# TODO: add port (-p) and log level (-l) to the command line args
module.exports = class Application
constructor: ->

13
labs/bbb-callback/callback_emitter.coffee
View File

@ -4,6 +4,7 @@ url = require('url')
EventEmitter = require('events').EventEmitter
config = require("./config")
Logger = require("./logger")
Utils = require("./utils")
# Use to perform a callback. Will try several times until the callback is
@ -33,7 +34,7 @@ module.exports = class CallbackEmitter extends EventEmitter
# get the next interval we have to wait and schedule a new try
interval = config.hooks.retryIntervals[@nextInterval]
if interval?
console.log "xx> Trying the callback again in #{interval/1000.0} secs"
Logger.warn "xx> Trying the callback again in #{interval/1000.0} secs"
@nextInterval++
@_scheduleNext(interval)
@ -67,13 +68,13 @@ module.exports = class CallbackEmitter extends EventEmitter
request requestOptions, (error, response, body) ->
# TODO: treat redirects
if error? or response.statusCode != 200
console.log "xx> Error in the callback call to: [#{requestOptions.uri}] for #{simplifiedEvent(data.event)}"
console.log "xx> Error:", error
console.log "xx> Status:", response.statusCode
if error? or response.statusCode not in [200, 201, 202]
Logger.warn "xx> Error in the callback call to: [#{requestOptions.uri}] for #{simplifiedEvent(data.event)}"
Logger.warn "xx> Error:", error
Logger.warn "xx> Status:", response.statusCode
callback error, false
else
console.log "==> Successful callback call to: [#{requestOptions.uri}] for #{simplifiedEvent(data.event)}"
Logger.info "==> Successful callback call to: [#{requestOptions.uri}] for #{simplifiedEvent(data.event)}"
callback null, true
# A simple string that identifies the event

8
labs/bbb-callback/config/bbb-webhooks.logrotate Normal file
View File

@ -0,0 +1,8 @@
/usr/local/bigbluebutton/bbb-webhooks/log/*.log {
size 300M
copytruncate
rotate 30
compress
missingok
notifempty
}

23
labs/bbb-callback/hook.coffee
View File

@ -5,6 +5,7 @@ redis = require("redis")
config = require("./config")
CallbackEmitter = require("./callback_emitter")
IDMapping = require("./id_mapping")
Logger = require("./logger")
# The database of hooks.
# Used always from memory, but saved to redis for persistence.
@ -35,18 +36,18 @@ module.exports = class Hook
save: (callback) ->
@redisClient.hmset config.redis.keys.hook(@id), @toRedis(), (error, reply) =>
console.log "Hook: error saving hook to redis!", error, reply if error?
Logger.error "Hook: error saving hook to redis!", error, reply if error?
@redisClient.sadd config.redis.keys.hooks, @id, (error, reply) =>
console.log "Hook: error saving hookID to the list of hooks!", error, reply if error?
Logger.error "Hook: error saving hookID to the list of hooks!", error, reply if error?
db[@id] = this
callback?(error, db[@id])
destroy: (callback) ->
@redisClient.srem config.redis.keys.hooks, @id, (error, reply) =>
console.log "Hook: error removing hookID from the list of hooks!", error, reply if error?
Logger.error "Hook: error removing hookID from the list of hooks!", error, reply if error?
@redisClient.del config.redis.keys.hook(@id), (error) =>
console.log "Hook: error removing hook from redis!", error if error?
Logger.error "Hook: error removing hook from redis!", error if error?
if db[@id]
delete db[@id]
@ -65,7 +66,7 @@ module.exports = class Hook
# Puts a new message in the queue. Will also trigger a processing in the queue so this
# message might be processed instantly.
enqueue: (message) ->
console.log "Hook: enqueueing message", JSON.stringify(message)
Logger.info "Hook: enqueueing message", JSON.stringify(message)
@queue.push message
@_processQueue()
@ -100,7 +101,7 @@ module.exports = class Hook
# gave up trying to perform the callback, remove the hook forever
@emitter.on "stopped", (error) =>
console.log "Hook: too many failed attempts to perform a callback call, removing the hook", JSON.stringify(hook)
Logger.warn "Hook: too many failed attempts to perform a callback call, removing the hook", JSON.stringify(hook)
@destroy()
@addSubscription = (callbackURL, meetingID=null, callback) ->
@ -110,7 +111,7 @@ module.exports = class Hook
else
msg = "Hook: adding a hook with callback URL [#{callbackURL}]"
msg += " for the meeting [#{meetingID}]" if meetingID?
console.log msg
Logger.info msg
hook = new Hook()
hook.id = nextID++
@ -123,7 +124,7 @@ module.exports = class Hook
if hook?
msg = "Hook: removing the hook with callback URL [#{hook.callbackURL}]"
msg += " for the meeting [#{hook.externalMeetingID}]" if hook.externalMeetingID?
console.log msg
Logger.info msg
hook.destroy (error, removed) -> callback?(error, removed)
else
@ -179,12 +180,12 @@ module.exports = class Hook
tasks = []
client.smembers config.redis.keys.hooks, (error, hooks) =>
console.log "Hook: error getting list of hooks from redis", error if error?
Logger.error "Hook: error getting list of hooks from redis", error if error?
hooks.forEach (id) =>
tasks.push (done) =>
client.hgetall config.redis.keys.hook(id), (error, hookData) ->
console.log "Hook: error getting information for a hook from redis", error if error?
Logger.error "Hook: error getting information for a hook from redis", error if error?
if hookData?
hook = new Hook()
@ -197,5 +198,5 @@ module.exports = class Hook
async.series tasks, (errors, result) ->
hooks = _.map(Hook.allSync(), (hook) -> "[#{hook.id}] #{hook.callbackURL}")
console.log "Hook: finished resync, hooks registered:", hooks
Logger.info "Hook: finished resync, hooks registered:", hooks
callback?()

21
labs/bbb-callback/id_mapping.coffee
View File

@ -3,6 +3,7 @@ async = require("async")
redis = require("redis")
config = require("./config")
Logger = require("./logger")
# The database of mappings. Uses the externalID as key because it changes less than
# the internal ID (e.g. the internalID can change for different meetings in the same
@ -35,18 +36,18 @@ module.exports = class IDMapping
save: (callback) ->
@redisClient.hmset config.redis.keys.mapping(@id), @toRedis(), (error, reply) =>
console.log "Hook: error saving mapping to redis!", error, reply if error?
Logger.error "Hook: error saving mapping to redis!", error, reply if error?
@redisClient.sadd config.redis.keys.mappings, @id, (error, reply) =>
console.log "Hook: error saving mapping ID to the list of mappings!", error, reply if error?
Logger.error "Hook: error saving mapping ID to the list of mappings!", error, reply if error?
db[@externalMeetingID] = this
callback?(error, db[@externalMeetingID])
destroy: (callback) ->
@redisClient.srem config.redis.keys.mappings, @id, (error, reply) =>
console.log "Hook: error removing mapping ID from the list of mappings!", error, reply if error?
Logger.error "Hook: error removing mapping ID from the list of mappings!", error, reply if error?
@redisClient.del config.redis.keys.mapping(@id), (error) =>
console.log "Hook: error removing mapping from redis!", error if error?
Logger.error "Hook: error removing mapping from redis!", error if error?
if db[@externalMeetingID]
delete db[@externalMeetingID]
@ -78,14 +79,14 @@ module.exports = class IDMapping
mapping.externalMeetingID = externalMeetingID
mapping.lastActivity = new Date().getTime()
mapping.save (error, result) ->
console.log "IDMapping: added or changed meeting mapping to the list #{externalMeetingID}:", mapping.print()
Logger.info "IDMapping: added or changed meeting mapping to the list #{externalMeetingID}:", mapping.print()
callback?(error, result)
@removeMapping = (internalMeetingID, callback) ->
for external, mapping of db
if mapping.internalMeetingID is internalMeetingID
mapping.destroy (error, result) ->
console.log "IDMapping: removing meeting mapping from the list #{external}:", mapping.print()
Logger.info "IDMapping: removing meeting mapping from the list #{external}:", mapping.print()
callback?(error, result)
@getInternalMeetingID = (externalMeetingID) ->
@ -125,7 +126,7 @@ module.exports = class IDMapping
mapping.lastActivity < now - config.mappings.timeout
)
unless _.isEmpty(toRemove)
console.log "IDMapping: expiring the mappings:", _.map(toRemove, (map) -> map.print())
Logger.info "IDMapping: expiring the mappings:", _.map(toRemove, (map) -> map.print())
toRemove.forEach (mapping) -> mapping.destroy()
# Initializes global methods for this model.
@ -140,12 +141,12 @@ module.exports = class IDMapping
tasks = []
client.smembers config.redis.keys.mappings, (error, mappings) =>
console.log "Hook: error getting list of mappings from redis", error if error?
Logger.error "Hook: error getting list of mappings from redis", error if error?
mappings.forEach (id) =>
tasks.push (done) =>
client.hgetall config.redis.keys.mapping(id), (error, mappingData) ->
console.log "Hook: error getting information for a mapping from redis", error if error?
Logger.error "Hook: error getting information for a mapping from redis", error if error?
if mappingData?
mapping = new IDMapping()
@ -158,5 +159,5 @@ module.exports = class IDMapping
async.series tasks, (errors, result) ->
mappings = _.map(IDMapping.allSync(), (m) -> m.print())
console.log "IDMapping: finished resync, mappings registered:", mappings
Logger.info "IDMapping: finished resync, mappings registered:", mappings
callback?()

0
labs/bbb-callback/log/.gitkeep Normal file
View File

10
labs/bbb-callback/logger.coffee Normal file
View File

@ -0,0 +1,10 @@
winston = require("winston")
logger = new (winston.Logger)(
transports: [
new (winston.transports.Console)({ timestamp: true, colorize: true }),
new (winston.transports.File)({ filename: "log/application.log", timestamp: true })
]
)
module.exports = logger

3
labs/bbb-callback/package.json
View File

@ -14,7 +14,8 @@
"lodash": "2.4.1",
"async": "0.9.0",
"express": "4.10.2",
"sha1": "1.1.0"
"sha1": "1.1.0",
"winston": "0.8.3"
},
"engines": {
"node": "0.10.26"

15
labs/bbb-callback/web_hooks.coffee
View File

@ -6,6 +6,7 @@ request = require("request")
config = require("./config")
Hook = require("./hook")
IDMapping = require("./id_mapping")
Logger = require("./logger")
# Web hooks will listen for events on redis coming from BigBlueButton and
# perform HTTP calls with them to all registered hooks.
@ -24,7 +25,7 @@ module.exports = class WebHooks
# Subscribe to the events on pubsub that might need to be sent in callback calls.
_subscribeToEvents: ->
@subscriberEvents.on "psubscribe", (channel, count) ->
console.log "WebHooks: subscribed to " + channel
Logger.info "WebHooks: subscribed to " + channel
@subscriberEvents.on "pmessage", (pattern, channel, message) =>
try
@ -34,11 +35,11 @@ module.exports = class WebHooks
IDMapping.reportActivity(id)
if @_filterMessage(channel, message)
console.log "WebHooks: processing message on [#{channel}]:", JSON.stringify(message)
Logger.info "WebHooks: processing message on [#{channel}]:", JSON.stringify(message)
@_processEvent(message)
catch e
console.log "WebHooks: error processing the message", message, ":", e
Logger.error "WebHooks: error processing the message", message, ":", e
@subscriberEvents.psubscribe config.hooks.pchannel
@ -64,17 +65,17 @@ module.exports = class WebHooks
hooks = hooks.concat(Hook.findByExternalMeetingIDSync(eMeetingID))
hooks.forEach (hook) ->
console.log "WebHooks: enqueueing a message in the hook:", hook.callbackURL
Logger.info "WebHooks: enqueueing a message in the hook:", hook.callbackURL
hook.enqueue message
# Subscribe to the meeting events on pubsub to keep track of the mapping
# of meeting IDs.
_subscribeToMeetings: ->
@subscriberMeetings.on "subscribe", (channel, count) ->
console.log "WebHooks: subscribed to meetings channel ", channel
Logger.info "WebHooks: subscribed to meetings channel ", channel
@subscriberMeetings.on "message", (channel, message) =>
console.log "WebHooks: got message on meetings channel [#{channel}]", message
Logger.info "WebHooks: got message on meetings channel [#{channel}]", message
try
message = JSON.parse(message)
if message.header?.name is "meeting_created_message"
@ -83,6 +84,6 @@ module.exports = class WebHooks
IDMapping.removeMapping(message.payload?.meeting_id)
catch e
console.log "WebHooks: error processing the message", JSON.stringify(message), ":", e
Logger.error.log "WebHooks: error processing the message", JSON.stringify(message), ":", e
@subscriberMeetings.subscribe config.hooks.meetingsChannel

13
labs/bbb-callback/web_server.coffee
View File

@ -4,6 +4,7 @@ url = require("url")
config = require("./config")
Hook = require("./hook")
Logger = require("./logger")
Utils = require("./utils")
# Web server that listens for API calls and process them.
@ -16,16 +17,16 @@ module.exports = class WebServer
start: (port) ->
@server = @app.listen(port)
unless @server.address()?
console.log "Could not bind to port", port
console.log "Aborting."
Logger.error "Could not bind to port", port
Logger.error "Aborting."
process.exit(1)
console.log "== Server listening on port", port, "in", @app.settings.env.toUpperCase(), "mode"
Logger.info "Server listening on port", port, "in", @app.settings.env.toUpperCase(), "mode"
_registerRoutes: ->
# Request logger
@app.all "*", (req, res, next) ->
unless fromMonit(req)
console.log "<==", req.method, "request to", req.url, "from:", clientDataSimple(req)
Logger.info "<==", req.method, "request to", req.url, "from:", clientDataSimple(req)
next()
@app.get "/bigbluebutton/api/hooks/create", @_validateChecksum, @_create
@ -105,13 +106,13 @@ module.exports = class WebServer
if checksum is Utils.checksumAPI(req.url, config.bbb.sharedSecret)
next()
else
console.log "checksum check failed, sending a checksumError response"
Logger.info "checksum check failed, sending a checksumError response"
res.setHeader("Content-Type", "text/xml")
res.send cleanupXML(config.api.responses.checksumError)
respondWithXML = (res, msg) ->
msg = cleanupXML(msg)
console.log "==> respond with:", msg
Logger.info "==> respond with:", msg
res.setHeader("Content-Type", "text/xml")
res.send msg