gistfile1.txt

  agenda:worker processDbResult() called with success, checking whether to process job immediately or not +3ms
  agenda:worker Agenda.stop called, clearing interval for processJobs() +49ms
  agenda:worker Agenda._unlockJobs() +1ms
  agenda:worker about to unlock jobs with ids: [] +0ms
  agenda:worker successful connection to MongoDB using collection: [agendaJobs] +11ms
  agenda:worker init database collection using name [agendaJobs] +1ms
  agenda:worker attempting index creation +0ms
  agenda:worker index creation success +2ms
  agenda:worker job [someJob] defined with following options: 
  agenda:worker { fn: [Function: jobProcessor],
  agenda:worker   concurrency: 5,
  agenda:worker   lockLimit: 0,
  agenda:worker   priority: 0,
  agenda:worker   lockLifetime: 600000,
  agenda:worker   running: 0,
  agenda:worker   locked: 0 } +67ms
  agenda:worker job [send email] defined with following options: 
  agenda:worker { fn: [Function: jobProcessor],
  agenda:worker   concurrency: 5,
  agenda:worker   lockLimit: 0,
  agenda:worker   priority: 0,
  agenda:worker   lockLifetime: 600000,
  agenda:worker   running: 0,
  agenda:worker   locked: 0 } +0ms
  agenda:worker job [some job] defined with following options: 
  agenda:worker { fn: [Function: jobProcessor],
  agenda:worker   concurrency: 5,
  agenda:worker   lockLimit: 0,
  agenda:worker   priority: 0,
  agenda:worker   lockLifetime: 600000,
  agenda:worker   running: 0,
  agenda:worker   locked: 0 } +0ms
  agenda:worker job [do work] defined with following options: 
  agenda:worker { fn: [Function: jobProcessor],
  agenda:worker   concurrency: 5,
  agenda:worker   lockLimit: 0,
  agenda:worker   priority: 0,
  agenda:worker   lockLifetime: 600000,
  agenda:worker   running: 0,
  agenda:worker   locked: 0 } +1ms
  agenda:worker job [immediateJob] defined with following options: 
  agenda:worker { fn: [Function],
  agenda:worker   concurrency: 5,
  agenda:worker   lockLimit: 0,
  agenda:worker   priority: 0,
  agenda:worker   lockLifetime: 600000,
  agenda:worker   running: 0,
  agenda:worker   locked: 0 } +1ms
setting to now.
  agenda:worker Agenda.now(immediateJob, [Object]) +0ms
  agenda:worker Agenda.create(immediateJob, [Object]) +0ms
  agenda:worker attempting to save a job into Agenda instance +0ms
  agenda:worker set job props: 
  agenda:worker { name: 'immediateJob',
  agenda:worker   data: undefined,
  agenda:worker   type: 'normal',
  agenda:worker   priority: 0,
  agenda:worker   nextRunAt: 2017-07-29T06:39:28.153Z,
  agenda:worker   lastModifiedBy: undefined } +1ms
  agenda:worker current time stored as 2017-07-29T06:39:28.154Z +0ms
  agenda:worker using default behavior, inserting new job via insertOne() with props that were set: 
  agenda:worker { name: 'immediateJob',
  agenda:worker   data: undefined,
  agenda:worker   type: 'normal',
  agenda:worker   priority: 0,
  agenda:worker   nextRunAt: 2017-07-29T06:39:28.153Z,
  agenda:worker   lastModifiedBy: undefined } +0ms
starting.
  agenda:worker Agenda.start called, creating interval to call processJobs every [5000ms] +2ms
started.
  agenda:worker queuing up job to process: [someJob] +2ms
  agenda:worker job [someJob] lock status: shouldLock = true +1ms
  agenda:worker _findAndLockNextJob(someJob, [Function], cb) +0ms
  agenda:worker queuing up job to process: [send email] +2ms
  agenda:worker job [send email] lock status: shouldLock = true +1ms
  agenda:worker _findAndLockNextJob(send email, [Function], cb) +0ms
  agenda:worker queuing up job to process: [some job] +1ms
  agenda:worker job [some job] lock status: shouldLock = true +0ms
  agenda:worker _findAndLockNextJob(some job, [Function], cb) +0ms
  agenda:worker queuing up job to process: [do work] +1ms
  agenda:worker job [do work] lock status: shouldLock = true +0ms
  agenda:worker _findAndLockNextJob(do work, [Function], cb) +0ms
  agenda:worker queuing up job to process: [immediateJob] +0ms
  agenda:worker job [immediateJob] lock status: shouldLock = true +1ms
  agenda:worker _findAndLockNextJob(immediateJob, [Function], cb) +0ms
  agenda:worker processDbResult() called with success, checking whether to process job immediately or not +1ms
  agenda:worker [immediateJob:597c2da00f45d80a3b007328] job would have ran by nextScanAt, processing the job immediately +0ms
  agenda:worker job was passed directly to processJobs(), locking and running immediately +1ms
  agenda:worker job [immediateJob] lock status: shouldLock = true +0ms
  agenda:worker found a job available to lock, creating a new job on Agenda with id [597c2da00f45d80a3b007328] +13ms
  agenda:worker [immediateJob:597c2da00f45d80a3b007328] job locked while filling queue +1ms
  agenda:worker job [immediateJob] lock status: shouldLock = true +1ms
  agenda:worker _findAndLockNextJob(immediateJob, [Function], cb) +0ms
  agenda:worker no jobs to current lock on the fly, returning +7ms
  agenda:worker queuing up job to process: [someJob] +5s
  agenda:worker job [someJob] lock status: shouldLock = true +1ms
  agenda:worker _findAndLockNextJob(someJob, [Function], cb) +0ms
  agenda:worker queuing up job to process: [send email] +1ms
  agenda:worker job [send email] lock status: shouldLock = true +0ms
  agenda:worker _findAndLockNextJob(send email, [Function], cb) +0ms
  agenda:worker queuing up job to process: [some job] +1ms
  agenda:worker job [some job] lock status: shouldLock = true +0ms
  agenda:worker _findAndLockNextJob(some job, [Function], cb) +0ms
  agenda:worker queuing up job to process: [do work] +1ms
  agenda:worker job [do work] lock status: shouldLock = true +0ms
  agenda:worker _findAndLockNextJob(do work, [Function], cb) +0ms
  agenda:worker queuing up job to process: [immediateJob] +0ms
  agenda:worker job [immediateJob] lock status: shouldLock = true +0ms
  agenda:worker _findAndLockNextJob(immediateJob, [Function], cb) +0ms
        1) runs the job immediately
  agenda:worker Agenda.stop called, clearing interval for processJobs() +3s
  agenda:worker Agenda._unlockJobs() +0ms
  agenda:worker about to unlock jobs with ids: [ 597c2da00f45d80a3b007328 ] +0ms