search

veny / GearmaNode

Node.js library for the Gearman distributed job system with support for multiple servers
Apache License 2.0
101 stars 35 forks source link

GearmaNode 0.2.0 failing on repeated high frequency jobs. #25

Closed squareproton closed 9 years ago

squareproton commented 9 years ago

I've been migrating a node application away from andris9/node-gearman to take advantage of the additional features available in GearmaNode (job priorities and background jobs) and also because it looks like andris9/node-gearman is no longer maintained. Unfortunately we have run into problems with GearmaNode not returning the correct data if multiple jobs are submitted to a client in quick succession. Am I using GearmaNode wrong?

GearmanNode 0.2.0 (the latest in npm) on node v0.10.37. Gearman 1.0.6 on Ubuntu 12.04.5 LTS. The minimal test case is below.

var gearmanode = require('gearmanode');

gearmanode.Client.logger.transports.console.level = 'error';

// worker which returns a incrementing int
var cnt = 0;
var worker = gearmanode.worker();
worker.addFunction('wtf', function (job) {
    var response = {
        'cnt': ++cnt
    }
    job.workComplete(JSON.stringify(response));
});

// hammer the server with repeated jobs with gearmanode as client
var client = gearmanode.client();
setInterval(function() {
    var job = client.submitJob(
        "wtf",
        JSON.stringify({"something": true}),
        {}
    );
    job.on('complete', function () {
        try {
            var response = JSON.parse(job.response);
        } catch (e) {
            // the response should always be valid json
            console.log("FAIL")
            console.log(job.response.toString())
            console.log(job);
            process.exit();
        }
        console.log("job %s complete", response.cnt);
     });
}, 20);

// hammer the server with repeated jobs with node-gearman as client
// var NodeGearman = require("node-gearman");
// var nodegearman = new NodeGearman();
// setInterval(function() {
// 
//     var job = nodegearman.submitJob(
//         "wtf",
//         JSON.stringify({"something": true})
//     );
// 
//     job.on("data", function(data){
//         try {
//             var response = JSON.parse(data);
//         } catch (e) {
//             // the response should always be valid json
//             console.log("FAIL", data);
//             process.exit();
//         }
//         console.log("job %s complete", response.cnt);
//     });
// 
// }, 20);

If this script is executed the following is returned.

info: GearmaNode 0.2.0, running on Node.js v0.10.37 [linux x64], with pid 25006
job 1 complete
job 2 complete
job 3 complete
job 4 complete
job 5 complete
FAIL
{"cnt":6}REH:printnode-pete:4409
{ uuid: 'b18bc33d-915f-401c-89c7-0cc4a6bf6261',
  clientOrWorker: 
   { _type: 'Client',
     jobServers: [ [Object] ],
     jobs: 
      { 'localhost:4730#H:printnode-pete:4406': [Object],
        'localhost:4730#H:printnode-pete:4407': [Object],
        'localhost:4730#H:printnode-pete:4408': [Object] },
     loadBalancer: { nodeCount: 1, badNodes: {}, recoverTime: 30000, lastIndex: 0 },
     domain: null,
     _events: {},
     _maxListeners: 10 },
  name: 'wtf',
  payload: '{"something":true}',
  background: false,
  priority: 'NORMAL',
  encoding: 'utf8',
  processing: false,
  domain: null,
  _events: { complete: [Function] },
  _maxListeners: 10,
  jobServerUid: 'localhost:4730',
  handle: 'H:printnode-pete:4405',
  response: <Buffer 7b 22 63 6e 74 22 3a 36 7d 00 52 45 53 00 00 00 08 00 00 00 15 48 3a 70 72 69 6e 74 6e 6f 64 65 2d 70 65 74 65 3a 34 34 30 39> }

Jobs 1-5 return valid JSON but job 6 returns {"cnt":6}REH:printnode-pete:4409 which triggers a JSON parsing error and dumps everything to the console.

Replacing the worker with a PHP version yields the same result.

If the client is replaced with andris9/node-gearman the script runs indefinitely which, I think, suggests the problem is with either the GearmaNode client or my usage of it.

Switching on debugging back for another run yields the following logs from gearmanode and gearman respectively.

GearmaNode

info: GearmaNode 0.2.0, running on Node.js v0.10.37 [linux x64], with pid 25046
info: worker initialized with 1 job server(s)
debug: packet encoded, type=CAN_DO, buffer.size=15
debug: unconnected job server, uid=localhost:4730
debug: packet encoded, type=PRE_SLEEP, buffer.size=12
debug: unconnected job server, uid=localhost:4730
info: registered function name=wtf on server uid=localhost:4730
info: client initialized with 1 job server(s)
debug: load balancing: strategy=Sequence, recoverTime=30000[ms]
verbose: packet sent, type=CAN_DO, len=15
verbose: packet sent, type=PRE_SLEEP, len=12
debug: connection established, uid=localhost:4730
debug: packet encoded, type=SUBMIT_JOB, buffer.size=35
debug: unconnected job server, uid=localhost:4730
verbose: packet sent, type=SUBMIT_JOB, len=35
debug: job submited, name=wtf, unique=undefined
debug: connection established, uid=localhost:4730
verbose: received packet, len=30
verbose: received packet: 0 52 45 53 0 0 0 8 0 0 0 12 48 3a 70 72 69 6e 74 6e 6f 64 65 2d 70 65 74 65 3a 31
verbose: packet parsed, bytes=30, type=JOB_CREATED
debug: no more a job waiting 4 state JOB_CREATED
debug: response for client: type=JOB_CREATED, uid=localhost:4730#H:printnode-pete:1
verbose: received packet, len=12
verbose: received packet: 0 52 45 53 0 0 0 6 0 0 0 0
verbose: packet parsed, bytes=12, type=NOOP
debug: packet encoded, type=GRAB_JOB, buffer.size=12
verbose: packet sent, type=GRAB_JOB, len=12
verbose: received packet, len=53
verbose: received packet: 0 52 45 53 0 0 0 b 0 0 0 29 48 3a 70 72 69 6e 74 6e 6f 64 65 2d 70 65 74 65 3a 31 0 77 74 66 0 7b 22 73 6f 6d 65 74 68 69 6e 67 22 3a 74 72 75 65 7d
verbose: packet parsed, bytes=53, type=JOB_ASSIGN
debug: packet encoded, type=WORK_COMPLETE, buffer.size=40
verbose: packet sent, type=WORK_COMPLETE, len=40
debug: packet encoded, type=PRE_SLEEP, buffer.size=12
verbose: packet sent, type=PRE_SLEEP, len=12
debug: function finished, name=wtf, result=undefined
verbose: received packet, len=40
verbose: received packet: 0 52 45 53 0 0 0 d 0 0 0 1c 48 3a 70 72 69 6e 74 6e 6f 64 65 2d 70 65 74 65 3a 31 0 7b 22 63 6e 74 22 3a 31 7d
verbose: packet parsed, bytes=40, type=WORK_COMPLETE
debug: response for client: type=WORK_COMPLETE, uid=localhost:4730#H:printnode-pete:1
job 1 complete
debug: packet encoded, type=SUBMIT_JOB, buffer.size=35
verbose: packet sent, type=SUBMIT_JOB, len=35
debug: job submited, name=wtf, unique=undefined
verbose: received packet, len=30
verbose: received packet: 0 52 45 53 0 0 0 8 0 0 0 12 48 3a 70 72 69 6e 74 6e 6f 64 65 2d 70 65 74 65 3a 32
verbose: packet parsed, bytes=30, type=JOB_CREATED
debug: no more a job waiting 4 state JOB_CREATED
debug: response for client: type=JOB_CREATED, uid=localhost:4730#H:printnode-pete:2
debug: packet encoded, type=SUBMIT_JOB, buffer.size=35
verbose: packet sent, type=SUBMIT_JOB, len=35
debug: job submited, name=wtf, unique=undefined
verbose: received packet, len=30
verbose: received packet: 0 52 45 53 0 0 0 8 0 0 0 12 48 3a 70 72 69 6e 74 6e 6f 64 65 2d 70 65 74 65 3a 33
verbose: packet parsed, bytes=30, type=JOB_CREATED
debug: no more a job waiting 4 state JOB_CREATED
debug: response for client: type=JOB_CREATED, uid=localhost:4730#H:printnode-pete:3
verbose: received packet, len=12
verbose: received packet: 0 52 45 53 0 0 0 6 0 0 0 0
verbose: packet parsed, bytes=12, type=NOOP
debug: packet encoded, type=GRAB_JOB, buffer.size=12
verbose: packet sent, type=GRAB_JOB, len=12
verbose: received packet, len=53
verbose: received packet: 0 52 45 53 0 0 0 b 0 0 0 29 48 3a 70 72 69 6e 74 6e 6f 64 65 2d 70 65 74 65 3a 32 0 77 74 66 0 7b 22 73 6f 6d 65 74 68 69 6e 67 22 3a 74 72 75 65 7d
verbose: packet parsed, bytes=53, type=JOB_ASSIGN
debug: packet encoded, type=WORK_COMPLETE, buffer.size=40
verbose: packet sent, type=WORK_COMPLETE, len=40
debug: packet encoded, type=PRE_SLEEP, buffer.size=12
verbose: packet sent, type=PRE_SLEEP, len=12
debug: function finished, name=wtf, result=undefined
verbose: received packet, len=40
verbose: received packet: 0 52 45 53 0 0 0 d 0 0 0 1c 48 3a 70 72 69 6e 74 6e 6f 64 65 2d 70 65 74 65 3a 32 0 7b 22 63 6e 74 22 3a 32 7d
verbose: packet parsed, bytes=40, type=WORK_COMPLETE
debug: response for client: type=WORK_COMPLETE, uid=localhost:4730#H:printnode-pete:2
job 2 complete
debug: packet encoded, type=SUBMIT_JOB, buffer.size=35
verbose: packet sent, type=SUBMIT_JOB, len=35
debug: job submited, name=wtf, unique=undefined
verbose: received packet, len=30
verbose: received packet: 0 52 45 53 0 0 0 8 0 0 0 12 48 3a 70 72 69 6e 74 6e 6f 64 65 2d 70 65 74 65 3a 34
verbose: packet parsed, bytes=30, type=JOB_CREATED
debug: no more a job waiting 4 state JOB_CREATED
debug: response for client: type=JOB_CREATED, uid=localhost:4730#H:printnode-pete:4
verbose: received packet, len=12
verbose: received packet: 0 52 45 53 0 0 0 6 0 0 0 0
verbose: packet parsed, bytes=12, type=NOOP
debug: packet encoded, type=GRAB_JOB, buffer.size=12
verbose: packet sent, type=GRAB_JOB, len=12
debug: packet encoded, type=SUBMIT_JOB, buffer.size=35
verbose: packet sent, type=SUBMIT_JOB, len=35
debug: job submited, name=wtf, unique=undefined
verbose: received packet, len=53
verbose: received packet: 0 52 45 53 0 0 0 b 0 0 0 29 48 3a 70 72 69 6e 74 6e 6f 64 65 2d 70 65 74 65 3a 33 0 77 74 66 0 7b 22 73 6f 6d 65 74 68 69 6e 67 22 3a 74 72 75 65 7d
verbose: packet parsed, bytes=53, type=JOB_ASSIGN
debug: packet encoded, type=WORK_COMPLETE, buffer.size=40
verbose: packet sent, type=WORK_COMPLETE, len=40
debug: packet encoded, type=PRE_SLEEP, buffer.size=12
verbose: packet sent, type=PRE_SLEEP, len=12
debug: function finished, name=wtf, result=undefined
verbose: received packet, len=70
verbose: received packet: 0 52 45 53 0 0 0 8 0 0 0 12 48 3a 70 72 69 6e 74 6e 6f 64 65 2d 70 65 74 65 3a 35 0 52 45 53 0 0 0 d 0 0 0 1c 48 3a 70 72 69 6e 74 6e 6f 64 65 2d 70 65 74 65 3a 33 0 7b 22 63 6e 74 22 3a 33 7d
verbose: packet parsed, bytes=30, type=JOB_CREATED
debug: no more a job waiting 4 state JOB_CREATED
debug: response for client: type=JOB_CREATED, uid=localhost:4730#H:printnode-pete:5
verbose: packet parsed, bytes=40, type=WORK_COMPLETE
debug: response for client: type=WORK_COMPLETE, uid=localhost:4730#H:printnode-pete:3
job 3 complete
debug: packet encoded, type=SUBMIT_JOB, buffer.size=35
verbose: packet sent, type=SUBMIT_JOB, len=35
debug: job submited, name=wtf, unique=undefined
verbose: received packet, len=30
verbose: received packet: 0 52 45 53 0 0 0 8 0 0 0 12 48 3a 70 72 69 6e 74 6e 6f 64 65 2d 70 65 74 65 3a 36
verbose: packet parsed, bytes=30, type=JOB_CREATED
debug: no more a job waiting 4 state JOB_CREATED
debug: response for client: type=JOB_CREATED, uid=localhost:4730#H:printnode-pete:6
verbose: received packet, len=12
verbose: received packet: 0 52 45 53 0 0 0 6 0 0 0 0
verbose: packet parsed, bytes=12, type=NOOP
debug: packet encoded, type=GRAB_JOB, buffer.size=12
verbose: packet sent, type=GRAB_JOB, len=12
debug: packet encoded, type=SUBMIT_JOB, buffer.size=35
verbose: packet sent, type=SUBMIT_JOB, len=35
debug: job submited, name=wtf, unique=undefined
verbose: received packet, len=53
verbose: received packet: 0 52 45 53 0 0 0 b 0 0 0 29 48 3a 70 72 69 6e 74 6e 6f 64 65 2d 70 65 74 65 3a 34 0 77 74 66 0 7b 22 73 6f 6d 65 74 68 69 6e 67 22 3a 74 72 75 65 7d
verbose: packet parsed, bytes=53, type=JOB_ASSIGN
debug: packet encoded, type=WORK_COMPLETE, buffer.size=40
verbose: packet sent, type=WORK_COMPLETE, len=40
debug: packet encoded, type=PRE_SLEEP, buffer.size=12
verbose: packet sent, type=PRE_SLEEP, len=12
debug: function finished, name=wtf, result=undefined
verbose: received packet, len=70
verbose: received packet: 0 52 45 53 0 0 0 8 0 0 0 12 48 3a 70 72 69 6e 74 6e 6f 64 65 2d 70 65 74 65 3a 37 0 52 45 53 0 0 0 d 0 0 0 1c 48 3a 70 72 69 6e 74 6e 6f 64 65 2d 70 65 74 65 3a 34 0 7b 22 63 6e 74 22 3a 34 7d
verbose: packet parsed, bytes=30, type=JOB_CREATED
debug: no more a job waiting 4 state JOB_CREATED
debug: response for client: type=JOB_CREATED, uid=localhost:4730#H:printnode-pete:7
verbose: packet parsed, bytes=40, type=WORK_COMPLETE
debug: response for client: type=WORK_COMPLETE, uid=localhost:4730#H:printnode-pete:4
job 4 complete
debug: packet encoded, type=SUBMIT_JOB, buffer.size=35
verbose: packet sent, type=SUBMIT_JOB, len=35
debug: job submited, name=wtf, unique=undefined
verbose: received packet, len=30
verbose: received packet: 0 52 45 53 0 0 0 8 0 0 0 12 48 3a 70 72 69 6e 74 6e 6f 64 65 2d 70 65 74 65 3a 38
verbose: packet parsed, bytes=30, type=JOB_CREATED
debug: no more a job waiting 4 state JOB_CREATED
debug: response for client: type=JOB_CREATED, uid=localhost:4730#H:printnode-pete:8
verbose: received packet, len=12
verbose: received packet: 0 52 45 53 0 0 0 6 0 0 0 0
verbose: packet parsed, bytes=12, type=NOOP
debug: packet encoded, type=GRAB_JOB, buffer.size=12
verbose: packet sent, type=GRAB_JOB, len=12
verbose: received packet, len=53
verbose: received packet: 0 52 45 53 0 0 0 b 0 0 0 29 48 3a 70 72 69 6e 74 6e 6f 64 65 2d 70 65 74 65 3a 35 0 77 74 66 0 7b 22 73 6f 6d 65 74 68 69 6e 67 22 3a 74 72 75 65 7d
verbose: packet parsed, bytes=53, type=JOB_ASSIGN
debug: packet encoded, type=WORK_COMPLETE, buffer.size=40
verbose: packet sent, type=WORK_COMPLETE, len=40
debug: packet encoded, type=PRE_SLEEP, buffer.size=12
verbose: packet sent, type=PRE_SLEEP, len=12
debug: function finished, name=wtf, result=undefined
debug: packet encoded, type=SUBMIT_JOB, buffer.size=35
verbose: packet sent, type=SUBMIT_JOB, len=35
debug: job submited, name=wtf, unique=undefined
verbose: received packet, len=70
verbose: received packet: 0 52 45 53 0 0 0 d 0 0 0 1c 48 3a 70 72 69 6e 74 6e 6f 64 65 2d 70 65 74 65 3a 35 0 7b 22 63 6e 74 22 3a 35 7d 0 52 45 53 0 0 0 8 0 0 0 12 48 3a 70 72 69 6e 74 6e 6f 64 65 2d 70 65 74 65 3a 39
verbose: packet parsed, bytes=40, type=WORK_COMPLETE
debug: response for client: type=WORK_COMPLETE, uid=localhost:4730#H:printnode-pete:5
FAIL
{"cnt":5}REH:printnode-pete:9
{ uuid: 'dcf11f89-ec14-41cd-ac1f-e85fb01525b0',
  clientOrWorker: 
   { _type: 'Client',
     jobServers: [ [Object] ],
     jobs: 
      { 'localhost:4730#H:printnode-pete:6': [Object],
        'localhost:4730#H:printnode-pete:7': [Object],
        'localhost:4730#H:printnode-pete:8': [Object] },
     loadBalancer: { nodeCount: 1, badNodes: {}, recoverTime: 30000, lastIndex: 0 },
     domain: null,
     _events: {},
     _maxListeners: 10 },
  name: 'wtf',
  payload: '{"something":true}',
  background: false,
  priority: 'NORMAL',
  encoding: 'utf8',
  processing: false,
  domain: null,
  _events: { complete: [Function] },
  _maxListeners: 10,
  jobServerUid: 'localhost:4730',
  handle: 'H:printnode-pete:5',
  response: <Buffer 7b 22 63 6e 74 22 3a 35 7d 00 52 45 53 00 00 00 08 00 00 00 12 48 3a 70 72 69 6e 74 6e 6f 64 65 2d 70 65 74 65 3a 39> }

Gearman

gearmand --verbose DEBUG -l stderr

   INFO 2015-03-31 20:37:20.486931 [  main ] Initializing Gear
   INFO 2015-03-31 20:37:20.487463 [  main ] Starting up(25038), verbose set to DEBUG
  DEBUG 2015-03-31 20:37:20.487791 [  main ] Method for libevent: epoll -> libgearman-server/gearmand.cc:336
  DEBUG 2015-03-31 20:37:20.488319 [  main ] Trying to listen on 0.0.0.0:4730 -> libgearman-server/gearmand.cc:576
   INFO 2015-03-31 20:37:20.488521 [  main ] Listening on 0.0.0.0:4730 (8)
  DEBUG 2015-03-31 20:37:20.488923 [  main ] Trying to listen on :::4730 -> libgearman-server/gearmand.cc:576
   INFO 2015-03-31 20:37:20.489208 [  main ] Listening on :::4730 (9)
  DEBUG 2015-03-31 20:37:20.489391 [  main ] Creating wakeup pipe -> libgearman-server/gearmand.cc:832
  DEBUG 2015-03-31 20:37:20.489577 [  main ] Creating 4 threads -> libgearman-server/gearmand.cc:350
  DEBUG 2015-03-31 20:37:20.489769 [  main ] Initializing libevent for IO thread -> libgearman-server/gearmand_thread.cc:207
  DEBUG 2015-03-31 20:37:20.489981 [  main ] Creating IO thread wakeup pipe -> libgearman-server/gearmand_thread.cc:477
  DEBUG 2015-03-31 20:37:20.490089 [  main ] Thread 1 created -> libgearman-server/gearmand_thread.cc:256
  DEBUG 2015-03-31 20:37:20.490170 [  main ] Initializing libevent for IO thread -> libgearman-server/gearmand_thread.cc:207
  DEBUG 2015-03-31 20:37:20.490225 [  main ] Creating IO thread wakeup pipe -> libgearman-server/gearmand_thread.cc:477
  DEBUG 2015-03-31 20:37:20.490306 [  main ] Thread 2 created -> libgearman-server/gearmand_thread.cc:256
  DEBUG 2015-03-31 20:37:20.490345 [  main ] Initializing libevent for IO thread -> libgearman-server/gearmand_thread.cc:207
  DEBUG 2015-03-31 20:37:20.490394 [  main ] Creating IO thread wakeup pipe -> libgearman-server/gearmand_thread.cc:477
  DEBUG 2015-03-31 20:37:20.490467 [  main ] Thread 3 created -> libgearman-server/gearmand_thread.cc:256
  DEBUG 2015-03-31 20:37:20.490506 [  main ] Initializing libevent for IO thread -> libgearman-server/gearmand_thread.cc:207
  DEBUG 2015-03-31 20:37:20.490571 [  main ] Creating IO thread wakeup pipe -> libgearman-server/gearmand_thread.cc:477
  DEBUG 2015-03-31 20:37:20.490658 [  main ] Thread 4 created -> libgearman-server/gearmand_thread.cc:256
  DEBUG 2015-03-31 20:37:20.490697 [  main ] replaying queue: begin -> libgearman-server/gearmand.cc:363
  DEBUG 2015-03-31 20:37:20.490727 [  main ] __replay -> libgearman-server/plugins/queue/default/queue.cc:100
  DEBUG 2015-03-31 20:37:20.490757 [  main ] replaying queue: end -> libgearman-server/gearmand.cc:369
   INFO 2015-03-31 20:37:20.490786 [  main ] Adding event for listening socket (8)
   INFO 2015-03-31 20:37:20.490818 [  main ] Adding event for listening socket (9)
  DEBUG 2015-03-31 20:37:20.490851 [  main ] Adding event for wakeup pipe -> libgearman-server/gearmand.cc:885
  DEBUG 2015-03-31 20:37:20.490883 [  main ] Entering main event loop -> libgearman-server/gearmand.cc:378
  DEBUG 2015-03-31 20:37:20.491009 [     4 ] Entering thread event loop -> libgearman-server/gearmand_thread.cc:445
  DEBUG 2015-03-31 20:37:20.491067 [     3 ] Entering thread event loop -> libgearman-server/gearmand_thread.cc:445
  DEBUG 2015-03-31 20:37:20.491149 [     2 ] Entering thread event loop -> libgearman-server/gearmand_thread.cc:445
  DEBUG 2015-03-31 20:37:20.491242 [     1 ] Entering thread event loop -> libgearman-server/gearmand_thread.cc:445
  DEBUG 2015-03-31 20:37:20.491287 [  main ] staring up Epoch thread -> libgearman-server/timer.cc:61
  DEBUG 2015-03-31 20:37:20.496888 [  main ] accept() 32 -> libgearman-server/gearmand.cc:799
   INFO 2015-03-31 20:37:20.497082 [  main ] Accepted connection from 127.0.0.1:60461
  DEBUG 2015-03-31 20:37:20.497443 [     4 ] Received CON wakeup event -> libgearman-server/gearmand_thread.cc:602
  DEBUG 2015-03-31 20:37:20.497707 [     4 ] setsockopt() 32 -> libgearman-server/io.cc:809
  DEBUG 2015-03-31 20:37:20.498035 [     4 ]       127.0.0.1:60461 Watching  POLLIN  -> libgearman-server/gearmand_thread.cc:151
   INFO 2015-03-31 20:37:20.498347 [     4 ] Gear connection made
  DEBUG 2015-03-31 20:37:20.498638 [     4 ] 127.0.0.1:60461 Ready     POLLIN  -> libgearman-server/gearmand_con.cc:118
  DEBUG 2015-03-31 20:37:20.498932 [     4 ] read 22 bytes -> libgearman-server/io.cc:686
   INFO 2015-03-31 20:37:20.499232 [     4 ] Gear unpack
  DEBUG 2015-03-31 20:37:20.499550 [     4 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_OPTION_REQ -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:20.499851 [     4 ] Received OPTION_REQ 127.0.0.1:168975465 -> libgearman-server/thread.cc:318
  DEBUG 2015-03-31 20:37:20.499871 [     4 ]       127.0.0.1:60461 Watching  POLLIN  -> libgearman-server/gearmand_thread.cc:151
  DEBUG 2015-03-31 20:37:20.499906 [  proc ]       127.0.0.1:60461 packet command  OPTION_REQ -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:20.499926 [  proc ] 'exceptions' -> libgearman-server/server.cc:485
  DEBUG 2015-03-31 20:37:20.500015 [     4 ] Received RUN wakeup event -> libgearman-server/gearmand_thread.cc:607
  DEBUG 2015-03-31 20:37:20.500141 [     4 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_OPTION_RES -> libgearman-server/plugins/protocol/gear/protocol.cc:274
  DEBUG 2015-03-31 20:37:20.500305 [     4 ] send() 22 bytes to peer 127.0.0.1:60461 -> libgearman-server/io.cc:275
  DEBUG 2015-03-31 20:37:20.500319 [     4 ] Sent OPTION_RES to 127.0.0.1:168975465 -> libgearman-server/thread.cc:365
  DEBUG 2015-03-31 20:37:20.500331 [     4 ] 127.0.0.1:60461 Ready     POLLIN  -> libgearman-server/gearmand_con.cc:118
  DEBUG 2015-03-31 20:37:20.500353 [     4 ] read 523 bytes -> libgearman-server/io.cc:686
   INFO 2015-03-31 20:37:20.500363 [     4 ] Gear unpack
  DEBUG 2015-03-31 20:37:20.500370 [     4 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_CAN_DO -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:20.500377 [     4 ] Received CAN_DO 127.0.0.1:168975465 -> libgearman-server/thread.cc:318
   INFO 2015-03-31 20:37:20.500491 [     4 ] Gear unpack
  DEBUG 2015-03-31 20:37:20.500500 [  proc ]       127.0.0.1:60461 packet command  CAN_DO -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:20.500511 [  proc ] Registering function: PrintNode.Worker.Postfix.recieve -> libgearman-server/server.cc:509
  DEBUG 2015-03-31 20:37:20.500524 [     4 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_CAN_DO -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:20.500532 [     4 ] Received CAN_DO 127.0.0.1:168975465 -> libgearman-server/thread.cc:318
   INFO 2015-03-31 20:37:20.500544 [     4 ] Gear unpack
  DEBUG 2015-03-31 20:37:20.500550 [  proc ]       127.0.0.1:60461 packet command  CAN_DO -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:20.500561 [  proc ] Registering function: PrintNode.Worker.Normality.fixSequences -> libgearman-server/server.cc:509
  DEBUG 2015-03-31 20:37:20.500570 [     4 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_CAN_DO -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:20.500577 [     4 ] Received CAN_DO 127.0.0.1:168975465 -> libgearman-server/thread.cc:318
   INFO 2015-03-31 20:37:20.500788 [     4 ] Gear unpack
  DEBUG 2015-03-31 20:37:20.501041 [     4 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_CAN_DO -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:20.500800 [  proc ]       127.0.0.1:60461 packet command  CAN_DO -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:20.501069 [  proc ] Registering function: PrintNode.Worker.Normality.fixRedundantUsesClause -> libgearman-server/server.cc:509
  DEBUG 2015-03-31 20:37:20.501085 [     4 ] Received CAN_DO 127.0.0.1:168975465 -> libgearman-server/thread.cc:318
   INFO 2015-03-31 20:37:20.501224 [     4 ] Gear unpack
  DEBUG 2015-03-31 20:37:20.501237 [  proc ]       127.0.0.1:60461 packet command  CAN_DO -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:20.501254 [  proc ] Registering function: PrintNode.Worker.Normality.generateNotifications -> libgearman-server/server.cc:509
  DEBUG 2015-03-31 20:37:20.501268 [     4 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_CAN_DO -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:20.501280 [     4 ] Received CAN_DO 127.0.0.1:168975465 -> libgearman-server/thread.cc:318
   INFO 2015-03-31 20:37:20.501292 [     4 ] Gear unpack
  DEBUG 2015-03-31 20:37:20.501500 [  proc ]       127.0.0.1:60461 packet command  CAN_DO -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:20.501524 [  proc ] Registering function: PrintNode.Worker.Normality.generateLogTables -> libgearman-server/server.cc:509
  DEBUG 2015-03-31 20:37:20.501539 [     4 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_CAN_DO -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:20.501551 [     4 ] Received CAN_DO 127.0.0.1:168975465 -> libgearman-server/thread.cc:318
   INFO 2015-03-31 20:37:20.501563 [     4 ] Gear unpack
  DEBUG 2015-03-31 20:37:20.501571 [  proc ]       127.0.0.1:60461 packet command  CAN_DO -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:20.501586 [  proc ] Registering function: PrintNode.Worker.Normality.schemaSpy -> libgearman-server/server.cc:509
  DEBUG 2015-03-31 20:37:20.501605 [     4 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_CAN_DO -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:20.501616 [     4 ] Received CAN_DO 127.0.0.1:168975465 -> libgearman-server/thread.cc:318
   INFO 2015-03-31 20:37:20.501628 [     4 ] Gear unpack
  DEBUG 2015-03-31 20:37:20.501636 [  proc ]       127.0.0.1:60461 packet command  CAN_DO -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:20.501904 [  proc ] Registering function: PrintNode.Worker.Normality.generateEntities -> libgearman-server/server.cc:509
  DEBUG 2015-03-31 20:37:20.501925 [     4 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_CAN_DO -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:20.501937 [     4 ] Received CAN_DO 127.0.0.1:168975465 -> libgearman-server/thread.cc:318
   INFO 2015-03-31 20:37:20.501949 [     4 ] Gear unpack
  DEBUG 2015-03-31 20:37:20.501957 [  proc ]       127.0.0.1:60461 packet command  CAN_DO -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:20.501973 [  proc ] Registering function: PrintNode.Worker.Import.database -> libgearman-server/server.cc:509
  DEBUG 2015-03-31 20:37:20.501986 [     4 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_CAN_DO -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:20.501997 [     4 ] Received CAN_DO 127.0.0.1:168975465 -> libgearman-server/thread.cc:318
   INFO 2015-03-31 20:37:20.502009 [     4 ] Gear unpack
  DEBUG 2015-03-31 20:37:20.502016 [  proc ]       127.0.0.1:60461 packet command  CAN_DO -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:20.502031 [  proc ] Registering function: PrintNode.Worker.Email.registration -> libgearman-server/server.cc:509
  DEBUG 2015-03-31 20:37:20.502044 [     4 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_CAN_DO -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:20.502055 [     4 ] Received CAN_DO 127.0.0.1:168975465 -> libgearman-server/thread.cc:318
  DEBUG 2015-03-31 20:37:20.502149 [     4 ] read 494 bytes -> libgearman-server/io.cc:686
  DEBUG 2015-03-31 20:37:20.502165 [  proc ]       127.0.0.1:60461 packet command  CAN_DO -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:20.502181 [  proc ] Registering function: PrintNode.Worker.Database.modifyResolverBlock -> libgearman-server/server.cc:509
   INFO 2015-03-31 20:37:20.502195 [     4 ] Gear unpack
  DEBUG 2015-03-31 20:37:20.502205 [     4 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_CAN_DO -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:20.502453 [     4 ] Received CAN_DO 127.0.0.1:168975465 -> libgearman-server/thread.cc:318
   INFO 2015-03-31 20:37:20.502472 [     4 ] Gear unpack
  DEBUG 2015-03-31 20:37:20.502480 [  proc ]       127.0.0.1:60461 packet command  CAN_DO -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:20.502496 [  proc ] Registering function: PrintNode.Worker.Database.restoreDatabase -> libgearman-server/server.cc:509
  DEBUG 2015-03-31 20:37:20.502511 [     4 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_CAN_DO -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:20.502522 [     4 ] Received CAN_DO 127.0.0.1:168975465 -> libgearman-server/thread.cc:318
   INFO 2015-03-31 20:37:20.502534 [     4 ] Gear unpack
  DEBUG 2015-03-31 20:37:20.502616 [  proc ]       127.0.0.1:60461 packet command  CAN_DO -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:20.502635 [  proc ] Registering function: PrintNode.Worker.Database.getName -> libgearman-server/server.cc:509
  DEBUG 2015-03-31 20:37:20.502650 [     4 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_CAN_DO -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:20.502662 [     4 ] Received CAN_DO 127.0.0.1:168975465 -> libgearman-server/thread.cc:318
   INFO 2015-03-31 20:37:20.502674 [     4 ] Gear unpack
  DEBUG 2015-03-31 20:37:20.502681 [  proc ]       127.0.0.1:60461 packet command  CAN_DO -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:20.502696 [  proc ] Registering function: PrintNode.Worker.Database.generateYamlComparisonCommand -> libgearman-server/server.cc:509
  DEBUG 2015-03-31 20:37:20.502710 [     4 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_CAN_DO -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:20.502721 [     4 ] Received CAN_DO 127.0.0.1:168975465 -> libgearman-server/thread.cc:318
   INFO 2015-03-31 20:37:20.502733 [     4 ] Gear unpack
  DEBUG 2015-03-31 20:37:20.502740 [  proc ]       127.0.0.1:60461 packet command  CAN_DO -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:20.502984 [  proc ] Registering function: PrintNode.Worker.Database.generateYamlExportCommand -> libgearman-server/server.cc:509
  DEBUG 2015-03-31 20:37:20.503005 [     4 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_CAN_DO -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:20.503016 [     4 ] Received CAN_DO 127.0.0.1:168975465 -> libgearman-server/thread.cc:318
   INFO 2015-03-31 20:37:20.503041 [     4 ] Gear unpack
  DEBUG 2015-03-31 20:37:20.503051 [  proc ]       127.0.0.1:60461 packet command  CAN_DO -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:20.503153 [  proc ] Registering function: PrintNode.Worker.Database.vacuumAnalyse -> libgearman-server/server.cc:509
  DEBUG 2015-03-31 20:37:20.503174 [     4 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_CAN_DO -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:20.503186 [     4 ] Received CAN_DO 127.0.0.1:168975465 -> libgearman-server/thread.cc:318
   INFO 2015-03-31 20:37:20.503198 [     4 ] Gear unpack
  DEBUG 2015-03-31 20:37:20.503206 [  proc ]       127.0.0.1:60461 packet command  CAN_DO -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:20.503221 [  proc ] Registering function: PrintNode.Worker.Database.fixSequences -> libgearman-server/server.cc:509
  DEBUG 2015-03-31 20:37:20.503234 [     4 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_CAN_DO -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:20.503245 [     4 ] Received CAN_DO 127.0.0.1:168975465 -> libgearman-server/thread.cc:318
   INFO 2015-03-31 20:37:20.503257 [     4 ] Gear unpack
  DEBUG 2015-03-31 20:37:20.503264 [  proc ]       127.0.0.1:60461 packet command  CAN_DO -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:20.503279 [  proc ] Registering function: PrintNode.Worker.Database.checkAssets -> libgearman-server/server.cc:509
  DEBUG 2015-03-31 20:37:20.503292 [     4 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_CAN_DO -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:20.503303 [     4 ] Received CAN_DO 127.0.0.1:168975465 -> libgearman-server/thread.cc:318
   INFO 2015-03-31 20:37:20.503315 [     4 ] Gear unpack
  DEBUG 2015-03-31 20:37:20.503322 [  proc ]       127.0.0.1:60461 packet command  CAN_DO -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:20.503337 [  proc ] Registering function: PrintNode.Worker.Database.generate -> libgearman-server/server.cc:509
  DEBUG 2015-03-31 20:37:20.503350 [     4 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_CAN_DO -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:20.503361 [     4 ] Received CAN_DO 127.0.0.1:168975465 -> libgearman-server/thread.cc:318
   INFO 2015-03-31 20:37:20.503638 [     4 ] Gear unpack
  DEBUG 2015-03-31 20:37:20.503650 [  proc ]       127.0.0.1:60461 packet command  CAN_DO -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:20.503666 [  proc ] Registering function: worker.4332.quit -> libgearman-server/server.cc:509
  DEBUG 2015-03-31 20:37:20.503680 [     4 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_CAN_DO -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:20.503691 [     4 ] Received CAN_DO 127.0.0.1:168975465 -> libgearman-server/thread.cc:318
   INFO 2015-03-31 20:37:20.503789 [     4 ] Gear unpack
  DEBUG 2015-03-31 20:37:20.503805 [  proc ]       127.0.0.1:60461 packet command  CAN_DO -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:20.503822 [  proc ] Registering function: worker.4332.status -> libgearman-server/server.cc:509
  DEBUG 2015-03-31 20:37:20.504094 [     4 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_GRAB_JOB_ALL -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:20.504110 [     4 ] Received GRAB_JOB_ALL 127.0.0.1:168975465 -> libgearman-server/thread.cc:318
  DEBUG 2015-03-31 20:37:20.504125 [     4 ]       127.0.0.1:60461 Watching  POLLIN  -> libgearman-server/gearmand_thread.cc:151
  DEBUG 2015-03-31 20:37:20.504135 [  proc ]       127.0.0.1:60461 packet command  GRAB_JOB_ALL -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:20.504161 [     4 ] Received RUN wakeup event -> libgearman-server/gearmand_thread.cc:607
  DEBUG 2015-03-31 20:37:20.504174 [     4 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_NO_JOB -> libgearman-server/plugins/protocol/gear/protocol.cc:274
  DEBUG 2015-03-31 20:37:20.504213 [     4 ] send() 12 bytes to peer 127.0.0.1:60461 -> libgearman-server/io.cc:275
  DEBUG 2015-03-31 20:37:20.504228 [     4 ] Sent NO_JOB to 127.0.0.1:168975465 -> libgearman-server/thread.cc:365
  DEBUG 2015-03-31 20:37:20.504388 [     4 ] 127.0.0.1:60461 Ready     POLLIN  -> libgearman-server/gearmand_con.cc:118
  DEBUG 2015-03-31 20:37:20.504405 [     4 ] read 12 bytes -> libgearman-server/io.cc:686
   INFO 2015-03-31 20:37:20.504416 [     4 ] Gear unpack
  DEBUG 2015-03-31 20:37:20.504426 [     4 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_PRE_SLEEP -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:20.504437 [     4 ] Received PRE_SLEEP 127.0.0.1:168975465 -> libgearman-server/thread.cc:318
  DEBUG 2015-03-31 20:37:20.504450 [     4 ]       127.0.0.1:60461 Watching  POLLIN  -> libgearman-server/gearmand_thread.cc:151
  DEBUG 2015-03-31 20:37:20.504460 [  proc ]       127.0.0.1:60461 packet command  PRE_SLEEP -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:27.373655 [  main ] accept() 33 -> libgearman-server/gearmand.cc:799
   INFO 2015-03-31 20:37:27.373740 [  main ] Accepted connection from 127.0.0.1:60462
  DEBUG 2015-03-31 20:37:27.373808 [     3 ] Received CON wakeup event -> libgearman-server/gearmand_thread.cc:602
  DEBUG 2015-03-31 20:37:27.373841 [     3 ] setsockopt() 33 -> libgearman-server/io.cc:809
  DEBUG 2015-03-31 20:37:27.373859 [     3 ]       127.0.0.1:60462 Watching  POLLIN  -> libgearman-server/gearmand_thread.cc:151
   INFO 2015-03-31 20:37:27.373867 [     3 ] Gear connection made
  DEBUG 2015-03-31 20:37:27.374642 [     3 ] 127.0.0.1:60462 Ready     POLLIN  -> libgearman-server/gearmand_con.cc:118
  DEBUG 2015-03-31 20:37:27.374669 [     3 ] read 15 bytes -> libgearman-server/io.cc:686
   INFO 2015-03-31 20:37:27.374674 [     3 ] Gear unpack
  DEBUG 2015-03-31 20:37:27.374681 [     3 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_CAN_DO -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:27.374685 [     3 ] Received CAN_DO 127.0.0.1:168977257 -> libgearman-server/thread.cc:318
  DEBUG 2015-03-31 20:37:27.374705 [     3 ]       127.0.0.1:60462 Watching  POLLIN  -> libgearman-server/gearmand_thread.cc:151
  DEBUG 2015-03-31 20:37:27.374725 [  proc ]       127.0.0.1:60462 packet command  CAN_DO -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:27.374739 [  proc ] Registering function: wtf -> libgearman-server/server.cc:509
  DEBUG 2015-03-31 20:37:27.375525 [     3 ] 127.0.0.1:60462 Ready     POLLIN  -> libgearman-server/gearmand_con.cc:118
  DEBUG 2015-03-31 20:37:27.375537 [     3 ] read 12 bytes -> libgearman-server/io.cc:686
   INFO 2015-03-31 20:37:27.375540 [     3 ] Gear unpack
  DEBUG 2015-03-31 20:37:27.375543 [     3 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_PRE_SLEEP -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:27.375547 [     3 ] Received PRE_SLEEP 127.0.0.1:168977257 -> libgearman-server/thread.cc:318
  DEBUG 2015-03-31 20:37:27.375566 [     3 ]       127.0.0.1:60462 Watching  POLLIN  -> libgearman-server/gearmand_thread.cc:151
  DEBUG 2015-03-31 20:37:27.375576 [  proc ]       127.0.0.1:60462 packet command  PRE_SLEEP -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:27.396238 [  main ] accept() 34 -> libgearman-server/gearmand.cc:799
   INFO 2015-03-31 20:37:27.396257 [  main ] Accepted connection from 127.0.0.1:60463
  DEBUG 2015-03-31 20:37:27.396305 [     2 ] Received CON wakeup event -> libgearman-server/gearmand_thread.cc:602
  DEBUG 2015-03-31 20:37:27.396332 [     2 ] setsockopt() 34 -> libgearman-server/io.cc:809
  DEBUG 2015-03-31 20:37:27.396346 [     2 ]       127.0.0.1:60463 Watching  POLLIN  -> libgearman-server/gearmand_thread.cc:151
   INFO 2015-03-31 20:37:27.396350 [     2 ] Gear connection made
  DEBUG 2015-03-31 20:37:27.396800 [     2 ] 127.0.0.1:60463 Ready     POLLIN  -> libgearman-server/gearmand_con.cc:118
  DEBUG 2015-03-31 20:37:27.396830 [     2 ] read 35 bytes -> libgearman-server/io.cc:686
   INFO 2015-03-31 20:37:27.396835 [     2 ] Gear unpack
  DEBUG 2015-03-31 20:37:27.396902 [     2 ] GEAR length: 18 gearmand_command_t: GEARMAN_COMMAND_SUBMIT_JOB -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:27.396921 [     2 ] Received SUBMIT_JOB 127.0.0.1:168979049 -> libgearman-server/thread.cc:318
  DEBUG 2015-03-31 20:37:27.396930 [     2 ]       127.0.0.1:60463 Watching  POLLIN  -> libgearman-server/gearmand_thread.cc:151
  DEBUG 2015-03-31 20:37:27.396940 [  proc ]       127.0.0.1:60463 packet command  SUBMIT_JOB -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:27.396946 [  proc ] Received submission, function:wtf unique: with 2 arguments -> libgearman-server/server.cc:231
  DEBUG 2015-03-31 20:37:27.396951 [  proc ] Comparing queue 0 to limit 0 for priority 1 -> libgearman-server/job.cc:174
 NOTICE 2015-03-31 20:37:27.396976 [  proc ] accepted,wtf,,0 -> libgearman-server/server.cc:301
  DEBUG 2015-03-31 20:37:27.396991 [     3 ] Received RUN wakeup event -> libgearman-server/gearmand_thread.cc:607
  DEBUG 2015-03-31 20:37:27.396996 [     3 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_NOOP -> libgearman-server/plugins/protocol/gear/protocol.cc:274
  DEBUG 2015-03-31 20:37:27.397016 [     3 ] send() 12 bytes to peer 127.0.0.1:60462 -> libgearman-server/io.cc:275
  DEBUG 2015-03-31 20:37:27.397024 [     3 ] Sent NOOP to 127.0.0.1:168977257 -> libgearman-server/thread.cc:365
  DEBUG 2015-03-31 20:37:27.397034 [     2 ] Received RUN wakeup event -> libgearman-server/gearmand_thread.cc:607
  DEBUG 2015-03-31 20:37:27.397041 [     2 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_JOB_CREATED -> libgearman-server/plugins/protocol/gear/protocol.cc:274
  DEBUG 2015-03-31 20:37:27.397056 [     2 ] send() 30 bytes to peer 127.0.0.1:60463 -> libgearman-server/io.cc:275
  DEBUG 2015-03-31 20:37:27.397060 [     2 ] Sent JOB_CREATED to 127.0.0.1:168979049 -> libgearman-server/thread.cc:365
  DEBUG 2015-03-31 20:37:27.404243 [     3 ] 127.0.0.1:60462 Ready     POLLIN  -> libgearman-server/gearmand_con.cc:118
  DEBUG 2015-03-31 20:37:27.404274 [     3 ] read 12 bytes -> libgearman-server/io.cc:686
   INFO 2015-03-31 20:37:27.404278 [     3 ] Gear unpack
  DEBUG 2015-03-31 20:37:27.404282 [     3 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_GRAB_JOB -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:27.404285 [     3 ] Received GRAB_JOB 127.0.0.1:168977257 -> libgearman-server/thread.cc:318
  DEBUG 2015-03-31 20:37:27.404293 [     3 ]       127.0.0.1:60462 Watching  POLLIN  -> libgearman-server/gearmand_thread.cc:151
  DEBUG 2015-03-31 20:37:27.404302 [  proc ]       127.0.0.1:60462 packet command  GRAB_JOB -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:27.404308 [  proc ] Jobs available for wtf: 1 -> libgearman-server/gearmand_con.cc:291
  DEBUG 2015-03-31 20:37:27.404325 [  proc ] Sending GEARMAN_COMMAND_JOB_ASSIGN Function: wtf(3) with data sized (18) -> libgearman-server/server.cc:642
  DEBUG 2015-03-31 20:37:27.404341 [     3 ] Received RUN wakeup event -> libgearman-server/gearmand_thread.cc:607
  DEBUG 2015-03-31 20:37:27.404345 [     3 ] GEAR length: 18 gearmand_command_t: GEARMAN_COMMAND_JOB_ASSIGN -> libgearman-server/plugins/protocol/gear/protocol.cc:274
  DEBUG 2015-03-31 20:37:27.404357 [     3 ] send() 53 bytes to peer 127.0.0.1:60462 -> libgearman-server/io.cc:275
  DEBUG 2015-03-31 20:37:27.404361 [     3 ] Sent JOB_ASSIGN to 127.0.0.1:168977257 -> libgearman-server/thread.cc:365
  DEBUG 2015-03-31 20:37:27.406902 [     3 ] 127.0.0.1:60462 Ready     POLLIN  -> libgearman-server/gearmand_con.cc:118
  DEBUG 2015-03-31 20:37:27.406915 [     3 ] read 40 bytes -> libgearman-server/io.cc:686
   INFO 2015-03-31 20:37:27.406919 [     3 ] Gear unpack
  DEBUG 2015-03-31 20:37:27.406923 [     3 ] GEAR length: 9 gearmand_command_t: GEARMAN_COMMAND_WORK_COMPLETE -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:27.406927 [     3 ] Received WORK_COMPLETE 127.0.0.1:168977257 -> libgearman-server/thread.cc:318
  DEBUG 2015-03-31 20:37:27.406934 [     3 ]       127.0.0.1:60462 Watching  POLLIN  -> libgearman-server/gearmand_thread.cc:151
  DEBUG 2015-03-31 20:37:27.406942 [  proc ]       127.0.0.1:60462 packet command  WORK_COMPLETE -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:27.406971 [     2 ] Received RUN wakeup event -> libgearman-server/gearmand_thread.cc:607
  DEBUG 2015-03-31 20:37:27.406978 [     2 ] GEAR length: 9 gearmand_command_t: GEARMAN_COMMAND_WORK_COMPLETE -> libgearman-server/plugins/protocol/gear/protocol.cc:274
  DEBUG 2015-03-31 20:37:27.406992 [     2 ] send() 40 bytes to peer 127.0.0.1:60463 -> libgearman-server/io.cc:275
  DEBUG 2015-03-31 20:37:27.406997 [     2 ] Sent WORK_COMPLETE to 127.0.0.1:168979049 -> libgearman-server/thread.cc:365
  DEBUG 2015-03-31 20:37:27.407000 [     2 ] free() packet's data -> libgearman-server/packet.cc:393
  DEBUG 2015-03-31 20:37:27.418242 [     2 ] 127.0.0.1:60463 Ready     POLLIN  -> libgearman-server/gearmand_con.cc:118
  DEBUG 2015-03-31 20:37:27.418260 [     2 ] read 35 bytes -> libgearman-server/io.cc:686
   INFO 2015-03-31 20:37:27.418264 [     2 ] Gear unpack
  DEBUG 2015-03-31 20:37:27.418269 [     2 ] GEAR length: 18 gearmand_command_t: GEARMAN_COMMAND_SUBMIT_JOB -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:27.418273 [     2 ] Received SUBMIT_JOB 127.0.0.1:168979049 -> libgearman-server/thread.cc:318
  DEBUG 2015-03-31 20:37:27.418280 [     2 ]       127.0.0.1:60463 Watching  POLLIN  -> libgearman-server/gearmand_thread.cc:151
  DEBUG 2015-03-31 20:37:27.418289 [  proc ]       127.0.0.1:60463 packet command  SUBMIT_JOB -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:27.418294 [  proc ] Received submission, function:wtf unique: with 2 arguments -> libgearman-server/server.cc:231
  DEBUG 2015-03-31 20:37:27.418299 [  proc ] Comparing queue 0 to limit 0 for priority 1 -> libgearman-server/job.cc:174
 NOTICE 2015-03-31 20:37:27.418314 [  proc ] accepted,wtf,,0 -> libgearman-server/server.cc:301
  DEBUG 2015-03-31 20:37:27.418325 [     2 ] Received RUN wakeup event -> libgearman-server/gearmand_thread.cc:607
  DEBUG 2015-03-31 20:37:27.418329 [     2 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_JOB_CREATED -> libgearman-server/plugins/protocol/gear/protocol.cc:274
  DEBUG 2015-03-31 20:37:27.418340 [     2 ] send() 30 bytes to peer 127.0.0.1:60463 -> libgearman-server/io.cc:275
  DEBUG 2015-03-31 20:37:27.418345 [     2 ] Sent JOB_CREATED to 127.0.0.1:168979049 -> libgearman-server/thread.cc:365
  DEBUG 2015-03-31 20:37:27.442140 [     2 ] 127.0.0.1:60463 Ready     POLLIN  -> libgearman-server/gearmand_con.cc:118
  DEBUG 2015-03-31 20:37:27.442163 [     2 ] read 35 bytes -> libgearman-server/io.cc:686
   INFO 2015-03-31 20:37:27.442168 [     2 ] Gear unpack
  DEBUG 2015-03-31 20:37:27.442185 [     2 ] GEAR length: 18 gearmand_command_t: GEARMAN_COMMAND_SUBMIT_JOB -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:27.442191 [     2 ] Received SUBMIT_JOB 127.0.0.1:168979049 -> libgearman-server/thread.cc:318
  DEBUG 2015-03-31 20:37:27.442200 [     2 ]       127.0.0.1:60463 Watching  POLLIN  -> libgearman-server/gearmand_thread.cc:151
  DEBUG 2015-03-31 20:37:27.442211 [  proc ]       127.0.0.1:60463 packet command  SUBMIT_JOB -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:27.442218 [  proc ] Received submission, function:wtf unique: with 2 arguments -> libgearman-server/server.cc:231
  DEBUG 2015-03-31 20:37:27.442223 [  proc ] Comparing queue 1 to limit 0 for priority 1 -> libgearman-server/job.cc:174
 NOTICE 2015-03-31 20:37:27.442234 [  proc ] accepted,wtf,,0 -> libgearman-server/server.cc:301
  DEBUG 2015-03-31 20:37:27.442244 [     2 ] Received RUN wakeup event -> libgearman-server/gearmand_thread.cc:607
  DEBUG 2015-03-31 20:37:27.442249 [     2 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_JOB_CREATED -> libgearman-server/plugins/protocol/gear/protocol.cc:274
  DEBUG 2015-03-31 20:37:27.442261 [     2 ] send() 30 bytes to peer 127.0.0.1:60463 -> libgearman-server/io.cc:275
  DEBUG 2015-03-31 20:37:27.442265 [     2 ] Sent JOB_CREATED to 127.0.0.1:168979049 -> libgearman-server/thread.cc:365
  DEBUG 2015-03-31 20:37:27.444166 [     3 ] 127.0.0.1:60462 Ready     POLLIN  -> libgearman-server/gearmand_con.cc:118
  DEBUG 2015-03-31 20:37:27.444179 [     3 ] read 12 bytes -> libgearman-server/io.cc:686
   INFO 2015-03-31 20:37:27.444183 [     3 ] Gear unpack
  DEBUG 2015-03-31 20:37:27.444187 [     3 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_PRE_SLEEP -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:27.444190 [     3 ] Received PRE_SLEEP 127.0.0.1:168977257 -> libgearman-server/thread.cc:318
  DEBUG 2015-03-31 20:37:27.444198 [     3 ]       127.0.0.1:60462 Watching  POLLIN  -> libgearman-server/gearmand_thread.cc:151
  DEBUG 2015-03-31 20:37:27.444289 [  proc ]       127.0.0.1:60462 packet command  PRE_SLEEP -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:27.444309 [     3 ] Received RUN wakeup event -> libgearman-server/gearmand_thread.cc:607
  DEBUG 2015-03-31 20:37:27.444314 [     3 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_NOOP -> libgearman-server/plugins/protocol/gear/protocol.cc:274
  DEBUG 2015-03-31 20:37:27.444325 [     3 ] send() 12 bytes to peer 127.0.0.1:60462 -> libgearman-server/io.cc:275
  DEBUG 2015-03-31 20:37:27.444329 [     3 ] Sent NOOP to 127.0.0.1:168977257 -> libgearman-server/thread.cc:365
  DEBUG 2015-03-31 20:37:27.447184 [     3 ] 127.0.0.1:60462 Ready     POLLIN  -> libgearman-server/gearmand_con.cc:118
  DEBUG 2015-03-31 20:37:27.447196 [     3 ] read 12 bytes -> libgearman-server/io.cc:686
   INFO 2015-03-31 20:37:27.447200 [     3 ] Gear unpack
  DEBUG 2015-03-31 20:37:27.447203 [     3 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_GRAB_JOB -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:27.447206 [     3 ] Received GRAB_JOB 127.0.0.1:168977257 -> libgearman-server/thread.cc:318
  DEBUG 2015-03-31 20:37:27.447212 [     3 ]       127.0.0.1:60462 Watching  POLLIN  -> libgearman-server/gearmand_thread.cc:151
  DEBUG 2015-03-31 20:37:27.447220 [  proc ]       127.0.0.1:60462 packet command  GRAB_JOB -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:27.447224 [  proc ] Jobs available for wtf: 2 -> libgearman-server/gearmand_con.cc:291
  DEBUG 2015-03-31 20:37:27.447227 [  proc ] Sending GEARMAN_COMMAND_JOB_ASSIGN Function: wtf(3) with data sized (18) -> libgearman-server/server.cc:642
  DEBUG 2015-03-31 20:37:27.447238 [     3 ] Received RUN wakeup event -> libgearman-server/gearmand_thread.cc:607
  DEBUG 2015-03-31 20:37:27.447242 [     3 ] GEAR length: 18 gearmand_command_t: GEARMAN_COMMAND_JOB_ASSIGN -> libgearman-server/plugins/protocol/gear/protocol.cc:274
  DEBUG 2015-03-31 20:37:27.447253 [     3 ] send() 53 bytes to peer 127.0.0.1:60462 -> libgearman-server/io.cc:275
  DEBUG 2015-03-31 20:37:27.447257 [     3 ] Sent JOB_ASSIGN to 127.0.0.1:168977257 -> libgearman-server/thread.cc:365
  DEBUG 2015-03-31 20:37:27.450087 [     3 ] 127.0.0.1:60462 Ready     POLLIN  -> libgearman-server/gearmand_con.cc:118
  DEBUG 2015-03-31 20:37:27.450101 [     3 ] read 40 bytes -> libgearman-server/io.cc:686
   INFO 2015-03-31 20:37:27.450105 [     3 ] Gear unpack
  DEBUG 2015-03-31 20:37:27.450109 [     3 ] GEAR length: 9 gearmand_command_t: GEARMAN_COMMAND_WORK_COMPLETE -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:27.450113 [     3 ] Received WORK_COMPLETE 127.0.0.1:168977257 -> libgearman-server/thread.cc:318
  DEBUG 2015-03-31 20:37:27.450120 [     3 ]       127.0.0.1:60462 Watching  POLLIN  -> libgearman-server/gearmand_thread.cc:151
  DEBUG 2015-03-31 20:37:27.450128 [  proc ]       127.0.0.1:60462 packet command  WORK_COMPLETE -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:27.450144 [     2 ] Received RUN wakeup event -> libgearman-server/gearmand_thread.cc:607
  DEBUG 2015-03-31 20:37:27.450149 [     2 ] GEAR length: 9 gearmand_command_t: GEARMAN_COMMAND_WORK_COMPLETE -> libgearman-server/plugins/protocol/gear/protocol.cc:274
  DEBUG 2015-03-31 20:37:27.450159 [     2 ] send() 40 bytes to peer 127.0.0.1:60463 -> libgearman-server/io.cc:275
  DEBUG 2015-03-31 20:37:27.450163 [     2 ] Sent WORK_COMPLETE to 127.0.0.1:168979049 -> libgearman-server/thread.cc:365
  DEBUG 2015-03-31 20:37:27.450166 [     2 ] free() packet's data -> libgearman-server/packet.cc:393
  DEBUG 2015-03-31 20:37:27.465876 [     2 ] 127.0.0.1:60463 Ready     POLLIN  -> libgearman-server/gearmand_con.cc:118
  DEBUG 2015-03-31 20:37:27.465915 [     2 ] read 35 bytes -> libgearman-server/io.cc:686
   INFO 2015-03-31 20:37:27.465924 [     2 ] Gear unpack
  DEBUG 2015-03-31 20:37:27.465933 [     2 ] GEAR length: 18 gearmand_command_t: GEARMAN_COMMAND_SUBMIT_JOB -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:27.465941 [     2 ] Received SUBMIT_JOB 127.0.0.1:168979049 -> libgearman-server/thread.cc:318
  DEBUG 2015-03-31 20:37:27.465972 [     2 ]       127.0.0.1:60463 Watching  POLLIN  -> libgearman-server/gearmand_thread.cc:151
  DEBUG 2015-03-31 20:37:27.465994 [  proc ]       127.0.0.1:60463 packet command  SUBMIT_JOB -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:27.466006 [  proc ] Received submission, function:wtf unique: with 2 arguments -> libgearman-server/server.cc:231
  DEBUG 2015-03-31 20:37:27.466015 [  proc ] Comparing queue 1 to limit 0 for priority 1 -> libgearman-server/job.cc:174
 NOTICE 2015-03-31 20:37:27.466051 [  proc ] accepted,wtf,,0 -> libgearman-server/server.cc:301
  DEBUG 2015-03-31 20:37:27.466071 [     2 ] Received RUN wakeup event -> libgearman-server/gearmand_thread.cc:607
  DEBUG 2015-03-31 20:37:27.466080 [     2 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_JOB_CREATED -> libgearman-server/plugins/protocol/gear/protocol.cc:274
  DEBUG 2015-03-31 20:37:27.466103 [     2 ] send() 30 bytes to peer 127.0.0.1:60463 -> libgearman-server/io.cc:275
  DEBUG 2015-03-31 20:37:27.466112 [     2 ] Sent JOB_CREATED to 127.0.0.1:168979049 -> libgearman-server/thread.cc:365
  DEBUG 2015-03-31 20:37:27.488247 [     3 ] 127.0.0.1:60462 Ready     POLLIN  -> libgearman-server/gearmand_con.cc:118
  DEBUG 2015-03-31 20:37:27.488271 [     3 ] read 12 bytes -> libgearman-server/io.cc:686
   INFO 2015-03-31 20:37:27.488279 [     3 ] Gear unpack
  DEBUG 2015-03-31 20:37:27.488285 [     3 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_PRE_SLEEP -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:27.488292 [     3 ] Received PRE_SLEEP 127.0.0.1:168977257 -> libgearman-server/thread.cc:318
  DEBUG 2015-03-31 20:37:27.488307 [     3 ]       127.0.0.1:60462 Watching  POLLIN  -> libgearman-server/gearmand_thread.cc:151
  DEBUG 2015-03-31 20:37:27.488321 [  proc ]       127.0.0.1:60462 packet command  PRE_SLEEP -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:27.488343 [     3 ] Received RUN wakeup event -> libgearman-server/gearmand_thread.cc:607
  DEBUG 2015-03-31 20:37:27.488351 [     3 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_NOOP -> libgearman-server/plugins/protocol/gear/protocol.cc:274
  DEBUG 2015-03-31 20:37:27.488371 [     3 ] send() 12 bytes to peer 127.0.0.1:60462 -> libgearman-server/io.cc:275
  DEBUG 2015-03-31 20:37:27.488379 [     3 ] Sent NOOP to 127.0.0.1:168977257 -> libgearman-server/thread.cc:365
  DEBUG 2015-03-31 20:37:27.492245 [     3 ] 127.0.0.1:60462 Ready     POLLIN  -> libgearman-server/gearmand_con.cc:118
  DEBUG 2015-03-31 20:37:27.492266 [     3 ] read 12 bytes -> libgearman-server/io.cc:686
   INFO 2015-03-31 20:37:27.492273 [     3 ] Gear unpack
  DEBUG 2015-03-31 20:37:27.492278 [     3 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_GRAB_JOB -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:27.492285 [     3 ] Received GRAB_JOB 127.0.0.1:168977257 -> libgearman-server/thread.cc:318
  DEBUG 2015-03-31 20:37:27.492297 [     3 ]       127.0.0.1:60462 Watching  POLLIN  -> libgearman-server/gearmand_thread.cc:151
  DEBUG 2015-03-31 20:37:27.492311 [  proc ]       127.0.0.1:60462 packet command  GRAB_JOB -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:27.492319 [  proc ] Jobs available for wtf: 2 -> libgearman-server/gearmand_con.cc:291
  DEBUG 2015-03-31 20:37:27.492325 [  proc ] Sending GEARMAN_COMMAND_JOB_ASSIGN Function: wtf(3) with data sized (18) -> libgearman-server/server.cc:642
  DEBUG 2015-03-31 20:37:27.492345 [     3 ] Received RUN wakeup event -> libgearman-server/gearmand_thread.cc:607
  DEBUG 2015-03-31 20:37:27.492353 [     3 ] GEAR length: 18 gearmand_command_t: GEARMAN_COMMAND_JOB_ASSIGN -> libgearman-server/plugins/protocol/gear/protocol.cc:274
  DEBUG 2015-03-31 20:37:27.492373 [     3 ] send() 53 bytes to peer 127.0.0.1:60462 -> libgearman-server/io.cc:275
  DEBUG 2015-03-31 20:37:27.492381 [     3 ] Sent JOB_ASSIGN to 127.0.0.1:168977257 -> libgearman-server/thread.cc:365
  DEBUG 2015-03-31 20:37:27.494204 [     2 ] 127.0.0.1:60463 Ready     POLLIN  -> libgearman-server/gearmand_con.cc:118
  DEBUG 2015-03-31 20:37:27.494223 [     2 ] read 35 bytes -> libgearman-server/io.cc:686
   INFO 2015-03-31 20:37:27.494230 [     2 ] Gear unpack
  DEBUG 2015-03-31 20:37:27.494237 [     2 ] GEAR length: 18 gearmand_command_t: GEARMAN_COMMAND_SUBMIT_JOB -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:27.494244 [     2 ] Received SUBMIT_JOB 127.0.0.1:168979049 -> libgearman-server/thread.cc:318
  DEBUG 2015-03-31 20:37:27.494256 [     2 ]       127.0.0.1:60463 Watching  POLLIN  -> libgearman-server/gearmand_thread.cc:151
  DEBUG 2015-03-31 20:37:27.494270 [  proc ]       127.0.0.1:60463 packet command  SUBMIT_JOB -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:27.494279 [  proc ] Received submission, function:wtf unique: with 2 arguments -> libgearman-server/server.cc:231
  DEBUG 2015-03-31 20:37:27.494286 [  proc ] Comparing queue 2 to limit 0 for priority 1 -> libgearman-server/job.cc:174
 NOTICE 2015-03-31 20:37:27.494299 [  proc ] accepted,wtf,,0 -> libgearman-server/server.cc:301
  DEBUG 2015-03-31 20:37:27.494314 [     2 ] Received RUN wakeup event -> libgearman-server/gearmand_thread.cc:607
  DEBUG 2015-03-31 20:37:27.494322 [     2 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_JOB_CREATED -> libgearman-server/plugins/protocol/gear/protocol.cc:274
  DEBUG 2015-03-31 20:37:27.494341 [     2 ] send() 30 bytes to peer 127.0.0.1:60463 -> libgearman-server/io.cc:275
  DEBUG 2015-03-31 20:37:27.494349 [     2 ] Sent JOB_CREATED to 127.0.0.1:168979049 -> libgearman-server/thread.cc:365
  DEBUG 2015-03-31 20:37:27.499534 [     3 ] 127.0.0.1:60462 Ready     POLLIN  -> libgearman-server/gearmand_con.cc:118
  DEBUG 2015-03-31 20:37:27.499554 [     3 ] read 40 bytes -> libgearman-server/io.cc:686
   INFO 2015-03-31 20:37:27.499561 [     3 ] Gear unpack
  DEBUG 2015-03-31 20:37:27.499567 [     3 ] GEAR length: 9 gearmand_command_t: GEARMAN_COMMAND_WORK_COMPLETE -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:27.499574 [     3 ] Received WORK_COMPLETE 127.0.0.1:168977257 -> libgearman-server/thread.cc:318
  DEBUG 2015-03-31 20:37:27.499586 [     3 ]       127.0.0.1:60462 Watching  POLLIN  -> libgearman-server/gearmand_thread.cc:151
  DEBUG 2015-03-31 20:37:27.499600 [  proc ]       127.0.0.1:60462 packet command  WORK_COMPLETE -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:27.499624 [     2 ] Received RUN wakeup event -> libgearman-server/gearmand_thread.cc:607
  DEBUG 2015-03-31 20:37:27.499632 [     2 ] GEAR length: 9 gearmand_command_t: GEARMAN_COMMAND_WORK_COMPLETE -> libgearman-server/plugins/protocol/gear/protocol.cc:274
  DEBUG 2015-03-31 20:37:27.499648 [     2 ] send() 40 bytes to peer 127.0.0.1:60463 -> libgearman-server/io.cc:275
  DEBUG 2015-03-31 20:37:27.499656 [     2 ] Sent WORK_COMPLETE to 127.0.0.1:168979049 -> libgearman-server/thread.cc:365
  DEBUG 2015-03-31 20:37:27.499662 [     2 ] free() packet's data -> libgearman-server/packet.cc:393
  DEBUG 2015-03-31 20:37:27.517878 [     2 ] 127.0.0.1:60463 Ready     POLLIN  -> libgearman-server/gearmand_con.cc:118
  DEBUG 2015-03-31 20:37:27.517889 [     2 ] read 35 bytes -> libgearman-server/io.cc:686
   INFO 2015-03-31 20:37:27.517892 [     2 ] Gear unpack
  DEBUG 2015-03-31 20:37:27.517896 [     2 ] GEAR length: 18 gearmand_command_t: GEARMAN_COMMAND_SUBMIT_JOB -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:27.517955 [     2 ] Received SUBMIT_JOB 127.0.0.1:168979049 -> libgearman-server/thread.cc:318
  DEBUG 2015-03-31 20:37:27.517966 [     2 ]       127.0.0.1:60463 Watching  POLLIN  -> libgearman-server/gearmand_thread.cc:151
  DEBUG 2015-03-31 20:37:27.517974 [  proc ]       127.0.0.1:60463 packet command  SUBMIT_JOB -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:27.517978 [  proc ] Received submission, function:wtf unique: with 2 arguments -> libgearman-server/server.cc:231
  DEBUG 2015-03-31 20:37:27.517982 [  proc ] Comparing queue 2 to limit 0 for priority 1 -> libgearman-server/job.cc:174
 NOTICE 2015-03-31 20:37:27.517989 [  proc ] accepted,wtf,,0 -> libgearman-server/server.cc:301
  DEBUG 2015-03-31 20:37:27.517997 [     2 ] Received RUN wakeup event -> libgearman-server/gearmand_thread.cc:607
  DEBUG 2015-03-31 20:37:27.518001 [     2 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_JOB_CREATED -> libgearman-server/plugins/protocol/gear/protocol.cc:274
  DEBUG 2015-03-31 20:37:27.518012 [     2 ] send() 30 bytes to peer 127.0.0.1:60463 -> libgearman-server/io.cc:275
  DEBUG 2015-03-31 20:37:27.518016 [     2 ] Sent JOB_CREATED to 127.0.0.1:168979049 -> libgearman-server/thread.cc:365
  DEBUG 2015-03-31 20:37:27.536251 [     3 ] 127.0.0.1:60462 Ready     POLLIN  -> libgearman-server/gearmand_con.cc:118
  DEBUG 2015-03-31 20:37:27.536273 [     3 ] read 12 bytes -> libgearman-server/io.cc:686
   INFO 2015-03-31 20:37:27.536281 [     3 ] Gear unpack
  DEBUG 2015-03-31 20:37:27.536287 [     3 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_PRE_SLEEP -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:27.536296 [     3 ] Received PRE_SLEEP 127.0.0.1:168977257 -> libgearman-server/thread.cc:318
  DEBUG 2015-03-31 20:37:27.536304 [     3 ]       127.0.0.1:60462 Watching  POLLIN  -> libgearman-server/gearmand_thread.cc:151
  DEBUG 2015-03-31 20:37:27.536311 [  proc ]       127.0.0.1:60462 packet command  PRE_SLEEP -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:27.536322 [     3 ] Received RUN wakeup event -> libgearman-server/gearmand_thread.cc:607
  DEBUG 2015-03-31 20:37:27.536326 [     3 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_NOOP -> libgearman-server/plugins/protocol/gear/protocol.cc:274
  DEBUG 2015-03-31 20:37:27.536336 [     3 ] send() 12 bytes to peer 127.0.0.1:60462 -> libgearman-server/io.cc:275
  DEBUG 2015-03-31 20:37:27.536340 [     3 ] Sent NOOP to 127.0.0.1:168977257 -> libgearman-server/thread.cc:365
  DEBUG 2015-03-31 20:37:27.543692 [     3 ] 127.0.0.1:60462 Ready     POLLIN  -> libgearman-server/gearmand_con.cc:118
  DEBUG 2015-03-31 20:37:27.543713 [     3 ] read 12 bytes -> libgearman-server/io.cc:686
   INFO 2015-03-31 20:37:27.543720 [     3 ] Gear unpack
  DEBUG 2015-03-31 20:37:27.543726 [     3 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_GRAB_JOB -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:27.543733 [     3 ] Received GRAB_JOB 127.0.0.1:168977257 -> libgearman-server/thread.cc:318
  DEBUG 2015-03-31 20:37:27.543745 [     3 ]       127.0.0.1:60462 Watching  POLLIN  -> libgearman-server/gearmand_thread.cc:151
  DEBUG 2015-03-31 20:37:27.543760 [  proc ]       127.0.0.1:60462 packet command  GRAB_JOB -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:27.543768 [  proc ] Jobs available for wtf: 3 -> libgearman-server/gearmand_con.cc:291
  DEBUG 2015-03-31 20:37:27.543775 [  proc ] Sending GEARMAN_COMMAND_JOB_ASSIGN Function: wtf(3) with data sized (18) -> libgearman-server/server.cc:642
  DEBUG 2015-03-31 20:37:27.543821 [     3 ] Received RUN wakeup event -> libgearman-server/gearmand_thread.cc:607
  DEBUG 2015-03-31 20:37:27.543831 [     3 ] GEAR length: 18 gearmand_command_t: GEARMAN_COMMAND_JOB_ASSIGN -> libgearman-server/plugins/protocol/gear/protocol.cc:274
  DEBUG 2015-03-31 20:37:27.543851 [     3 ] send() 53 bytes to peer 127.0.0.1:60462 -> libgearman-server/io.cc:275
  DEBUG 2015-03-31 20:37:27.543859 [     3 ] Sent JOB_ASSIGN to 127.0.0.1:168977257 -> libgearman-server/thread.cc:365
  DEBUG 2015-03-31 20:37:27.546184 [     2 ] 127.0.0.1:60463 Ready     POLLIN  -> libgearman-server/gearmand_con.cc:118
  DEBUG 2015-03-31 20:37:27.546203 [     2 ] read 35 bytes -> libgearman-server/io.cc:686
   INFO 2015-03-31 20:37:27.546210 [     2 ] Gear unpack
  DEBUG 2015-03-31 20:37:27.546216 [     2 ] GEAR length: 18 gearmand_command_t: GEARMAN_COMMAND_SUBMIT_JOB -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:27.546224 [     2 ] Received SUBMIT_JOB 127.0.0.1:168979049 -> libgearman-server/thread.cc:318
  DEBUG 2015-03-31 20:37:27.546236 [     2 ]       127.0.0.1:60463 Watching  POLLIN  -> libgearman-server/gearmand_thread.cc:151
  DEBUG 2015-03-31 20:37:27.546250 [  proc ]       127.0.0.1:60463 packet command  SUBMIT_JOB -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:27.546259 [  proc ] Received submission, function:wtf unique: with 2 arguments -> libgearman-server/server.cc:231
  DEBUG 2015-03-31 20:37:27.546266 [  proc ] Comparing queue 3 to limit 0 for priority 1 -> libgearman-server/job.cc:174
 NOTICE 2015-03-31 20:37:27.546280 [  proc ] accepted,wtf,,0 -> libgearman-server/server.cc:301
  DEBUG 2015-03-31 20:37:27.546295 [     2 ] Received RUN wakeup event -> libgearman-server/gearmand_thread.cc:607
  DEBUG 2015-03-31 20:37:27.546302 [     2 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_JOB_CREATED -> libgearman-server/plugins/protocol/gear/protocol.cc:274
  DEBUG 2015-03-31 20:37:27.546321 [     2 ] send() 30 bytes to peer 127.0.0.1:60463 -> libgearman-server/io.cc:275
  DEBUG 2015-03-31 20:37:27.546329 [     2 ] Sent JOB_CREATED to 127.0.0.1:168979049 -> libgearman-server/thread.cc:365
  DEBUG 2015-03-31 20:37:27.550458 [     3 ] 127.0.0.1:60462 Ready     POLLIN  -> libgearman-server/gearmand_con.cc:118
  DEBUG 2015-03-31 20:37:27.550478 [     3 ] read 40 bytes -> libgearman-server/io.cc:686
   INFO 2015-03-31 20:37:27.550485 [     3 ] Gear unpack
  DEBUG 2015-03-31 20:37:27.550491 [     3 ] GEAR length: 9 gearmand_command_t: GEARMAN_COMMAND_WORK_COMPLETE -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:27.550499 [     3 ] Received WORK_COMPLETE 127.0.0.1:168977257 -> libgearman-server/thread.cc:318
  DEBUG 2015-03-31 20:37:27.550511 [     3 ]       127.0.0.1:60462 Watching  POLLIN  -> libgearman-server/gearmand_thread.cc:151
  DEBUG 2015-03-31 20:37:27.550524 [  proc ]       127.0.0.1:60462 packet command  WORK_COMPLETE -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:27.550547 [     2 ] Received RUN wakeup event -> libgearman-server/gearmand_thread.cc:607
  DEBUG 2015-03-31 20:37:27.550555 [     2 ] GEAR length: 9 gearmand_command_t: GEARMAN_COMMAND_WORK_COMPLETE -> libgearman-server/plugins/protocol/gear/protocol.cc:274
  DEBUG 2015-03-31 20:37:27.550572 [     2 ] send() 40 bytes to peer 127.0.0.1:60463 -> libgearman-server/io.cc:275
  DEBUG 2015-03-31 20:37:27.550580 [     2 ] Sent WORK_COMPLETE to 127.0.0.1:168979049 -> libgearman-server/thread.cc:365
  DEBUG 2015-03-31 20:37:27.550586 [     2 ] free() packet's data -> libgearman-server/packet.cc:393
  DEBUG 2015-03-31 20:37:27.570782 [     2 ] 127.0.0.1:60463 Ready     POLLIN  -> libgearman-server/gearmand_con.cc:118
  DEBUG 2015-03-31 20:37:27.570794 [     2 ] read 35 bytes -> libgearman-server/io.cc:686
   INFO 2015-03-31 20:37:27.570797 [     2 ] Gear unpack
  DEBUG 2015-03-31 20:37:27.570801 [     2 ] GEAR length: 18 gearmand_command_t: GEARMAN_COMMAND_SUBMIT_JOB -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:27.570804 [     2 ] Received SUBMIT_JOB 127.0.0.1:168979049 -> libgearman-server/thread.cc:318
  DEBUG 2015-03-31 20:37:27.570810 [     2 ]       127.0.0.1:60463 Watching  POLLIN  -> libgearman-server/gearmand_thread.cc:151
  DEBUG 2015-03-31 20:37:27.570973 [  proc ]       127.0.0.1:60463 packet command  SUBMIT_JOB -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:27.570979 [  proc ] Received submission, function:wtf unique: with 2 arguments -> libgearman-server/server.cc:231
  DEBUG 2015-03-31 20:37:27.570983 [  proc ] Comparing queue 3 to limit 0 for priority 1 -> libgearman-server/job.cc:174
 NOTICE 2015-03-31 20:37:27.570990 [  proc ] accepted,wtf,,0 -> libgearman-server/server.cc:301
  DEBUG 2015-03-31 20:37:27.570999 [     2 ] Received RUN wakeup event -> libgearman-server/gearmand_thread.cc:607
  DEBUG 2015-03-31 20:37:27.571003 [     2 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_JOB_CREATED -> libgearman-server/plugins/protocol/gear/protocol.cc:274
  DEBUG 2015-03-31 20:37:27.571014 [     2 ] send() 30 bytes to peer 127.0.0.1:60463 -> libgearman-server/io.cc:275
  DEBUG 2015-03-31 20:37:27.571018 [     2 ] Sent JOB_CREATED to 127.0.0.1:168979049 -> libgearman-server/thread.cc:365
  DEBUG 2015-03-31 20:37:27.588142 [     3 ] 127.0.0.1:60462 Ready     POLLIN  -> libgearman-server/gearmand_con.cc:118
  DEBUG 2015-03-31 20:37:27.588183 [     3 ] read 12 bytes -> libgearman-server/io.cc:686
   INFO 2015-03-31 20:37:27.588191 [     3 ] Gear unpack
  DEBUG 2015-03-31 20:37:27.588198 [     3 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_PRE_SLEEP -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:27.588205 [     3 ] Received PRE_SLEEP 127.0.0.1:168977257 -> libgearman-server/thread.cc:318
  DEBUG 2015-03-31 20:37:27.588222 [     3 ]       127.0.0.1:60462 Watching  POLLIN  -> libgearman-server/gearmand_thread.cc:151
  DEBUG 2015-03-31 20:37:27.588239 [  proc ]       127.0.0.1:60462 packet command  PRE_SLEEP -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:27.588265 [     3 ] Received RUN wakeup event -> libgearman-server/gearmand_thread.cc:607
  DEBUG 2015-03-31 20:37:27.588273 [     3 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_NOOP -> libgearman-server/plugins/protocol/gear/protocol.cc:274
  DEBUG 2015-03-31 20:37:27.588293 [     3 ] send() 12 bytes to peer 127.0.0.1:60462 -> libgearman-server/io.cc:275
  DEBUG 2015-03-31 20:37:27.588301 [     3 ] Sent NOOP to 127.0.0.1:168977257 -> libgearman-server/thread.cc:365
  DEBUG 2015-03-31 20:37:27.591250 [     3 ] 127.0.0.1:60462 Ready     POLLIN  -> libgearman-server/gearmand_con.cc:118
  DEBUG 2015-03-31 20:37:27.591269 [     3 ] read 12 bytes -> libgearman-server/io.cc:686
   INFO 2015-03-31 20:37:27.591276 [     3 ] Gear unpack
  DEBUG 2015-03-31 20:37:27.591282 [     3 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_GRAB_JOB -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:27.591288 [     3 ] Received GRAB_JOB 127.0.0.1:168977257 -> libgearman-server/thread.cc:318
  DEBUG 2015-03-31 20:37:27.591300 [     3 ]       127.0.0.1:60462 Watching  POLLIN  -> libgearman-server/gearmand_thread.cc:151
  DEBUG 2015-03-31 20:37:27.591314 [  proc ]       127.0.0.1:60462 packet command  GRAB_JOB -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:27.591322 [  proc ] Jobs available for wtf: 4 -> libgearman-server/gearmand_con.cc:291
  DEBUG 2015-03-31 20:37:27.591329 [  proc ] Sending GEARMAN_COMMAND_JOB_ASSIGN Function: wtf(3) with data sized (18) -> libgearman-server/server.cc:642
  DEBUG 2015-03-31 20:37:27.591348 [     3 ] Received RUN wakeup event -> libgearman-server/gearmand_thread.cc:607
  DEBUG 2015-03-31 20:37:27.591356 [     3 ] GEAR length: 18 gearmand_command_t: GEARMAN_COMMAND_JOB_ASSIGN -> libgearman-server/plugins/protocol/gear/protocol.cc:274
  DEBUG 2015-03-31 20:37:27.591374 [     3 ] send() 53 bytes to peer 127.0.0.1:60462 -> libgearman-server/io.cc:275
  DEBUG 2015-03-31 20:37:27.591382 [     3 ] Sent JOB_ASSIGN to 127.0.0.1:168977257 -> libgearman-server/thread.cc:365
  DEBUG 2015-03-31 20:37:27.595237 [     3 ] 127.0.0.1:60462 Ready     POLLIN  -> libgearman-server/gearmand_con.cc:118
  DEBUG 2015-03-31 20:37:27.595257 [     3 ] read 40 bytes -> libgearman-server/io.cc:686
   INFO 2015-03-31 20:37:27.595264 [     3 ] Gear unpack
  DEBUG 2015-03-31 20:37:27.595270 [     3 ] GEAR length: 9 gearmand_command_t: GEARMAN_COMMAND_WORK_COMPLETE -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:27.595278 [     3 ] Received WORK_COMPLETE 127.0.0.1:168977257 -> libgearman-server/thread.cc:318
  DEBUG 2015-03-31 20:37:27.595289 [     3 ]       127.0.0.1:60462 Watching  POLLIN  -> libgearman-server/gearmand_thread.cc:151
  DEBUG 2015-03-31 20:37:27.595303 [  proc ]       127.0.0.1:60462 packet command  WORK_COMPLETE -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:27.595330 [     2 ] Received RUN wakeup event -> libgearman-server/gearmand_thread.cc:607
  DEBUG 2015-03-31 20:37:27.595339 [     2 ] GEAR length: 9 gearmand_command_t: GEARMAN_COMMAND_WORK_COMPLETE -> libgearman-server/plugins/protocol/gear/protocol.cc:274
  DEBUG 2015-03-31 20:37:27.595356 [     2 ] send() 40 bytes to peer 127.0.0.1:60463 -> libgearman-server/io.cc:275
  DEBUG 2015-03-31 20:37:27.595364 [     2 ] Sent WORK_COMPLETE to 127.0.0.1:168979049 -> libgearman-server/thread.cc:365
  DEBUG 2015-03-31 20:37:27.595370 [     2 ] free() packet's data -> libgearman-server/packet.cc:393
  DEBUG 2015-03-31 20:37:27.598496 [     2 ] 127.0.0.1:60463 Ready     POLLIN  -> libgearman-server/gearmand_con.cc:118
  DEBUG 2015-03-31 20:37:27.598516 [     2 ] read 35 bytes -> libgearman-server/io.cc:686
   INFO 2015-03-31 20:37:27.598520 [     2 ] Gear unpack
  DEBUG 2015-03-31 20:37:27.598524 [     2 ] GEAR length: 18 gearmand_command_t: GEARMAN_COMMAND_SUBMIT_JOB -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:27.598528 [     2 ] Received SUBMIT_JOB 127.0.0.1:168979049 -> libgearman-server/thread.cc:318
  DEBUG 2015-03-31 20:37:27.598537 [     2 ]       127.0.0.1:60463 Watching  POLLIN  -> libgearman-server/gearmand_thread.cc:151
  DEBUG 2015-03-31 20:37:27.598546 [  proc ]       127.0.0.1:60463 packet command  SUBMIT_JOB -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:27.598552 [  proc ] Received submission, function:wtf unique: with 2 arguments -> libgearman-server/server.cc:231
  DEBUG 2015-03-31 20:37:27.598556 [  proc ] Comparing queue 3 to limit 0 for priority 1 -> libgearman-server/job.cc:174
 NOTICE 2015-03-31 20:37:27.598566 [  proc ] accepted,wtf,,0 -> libgearman-server/server.cc:301
  DEBUG 2015-03-31 20:37:27.598575 [     2 ] Received RUN wakeup event -> libgearman-server/gearmand_thread.cc:607
  DEBUG 2015-03-31 20:37:27.598579 [     2 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_JOB_CREATED -> libgearman-server/plugins/protocol/gear/protocol.cc:274
  DEBUG 2015-03-31 20:37:27.598590 [     2 ] send() 30 bytes to peer 127.0.0.1:60463 -> libgearman-server/io.cc:275
  DEBUG 2015-03-31 20:37:27.598595 [     2 ] Sent JOB_CREATED to 127.0.0.1:168979049 -> libgearman-server/thread.cc:365
  DEBUG 2015-03-31 20:37:27.610039 [     3 ] 127.0.0.1:60462 Ready     POLLIN  -> libgearman-server/gearmand_con.cc:118
  DEBUG 2015-03-31 20:37:27.610069 [     3 ] read 12 bytes -> libgearman-server/io.cc:686
   INFO 2015-03-31 20:37:27.610075 [     3 ] Gear unpack
  DEBUG 2015-03-31 20:37:27.610078 [     3 ] GEAR length: 0 gearmand_command_t: GEARMAN_COMMAND_PRE_SLEEP -> libgearman-server/plugins/protocol/gear/protocol.cc:248
  DEBUG 2015-03-31 20:37:27.610082 [     3 ] Received PRE_SLEEP 127.0.0.1:168977257 -> libgearman-server/thread.cc:318
   INFO 2015-03-31 20:37:27.610090 [     3 ] Peer connection has called close() 127.0.0.1:60462
   INFO 2015-03-31 20:37:27.610093 [     3 ] Disconnected 127.0.0.1:60462
  DEBUG 2015-03-31 20:37:27.610170 [  proc ]       127.0.0.1:60462 packet command  PRE_SLEEP -> libgearman-server/server.cc:98
  DEBUG 2015-03-31 20:37:27.610186 [     3 ] Received RUN wakeup event -> libgearman-server/gearmand_thread.cc:607
  DEBUG 2015-03-31 20:37:27.610198 [     3 ] Received RUN wakeup event -> libgearman-server/gearmand_thread.cc:607
   INFO 2015-03-31 20:37:27.610202 [     3 ] Gear connection disconnected
  DEBUG 2015-03-31 20:37:27.610334 [     2 ] 127.0.0.1:60463 Ready     POLLIN  -> libgearman-server/gearmand_con.cc:118
   INFO 2015-03-31 20:37:27.610344 [     2 ] Peer connection has called close() 127.0.0.1:60463
   INFO 2015-03-31 20:37:27.610348 [     2 ] Disconnected 127.0.0.1:60463
  DEBUG 2015-03-31 20:37:27.610378 [     2 ] Received RUN wakeup event -> libgearman-server/gearmand_thread.cc:607
   INFO 2015-03-31 20:37:27.610383 [     2 ] Gear connection disconnected
^C  DEBUG 2015-03-31 20:37:32.079204 [  main ] Received SHUTDOWN wakeup event -> libgearman-server/gearmand.cc:969
   INFO 2015-03-31 20:37:32.079295 [  main ] Clearing event for listening socket (8)
   INFO 2015-03-31 20:37:32.079308 [  main ] Clearing event for listening socket (9)
  DEBUG 2015-03-31 20:37:32.079316 [  main ] Clearing event for wakeup pipe -> libgearman-server/gearmand.cc:901
  DEBUG 2015-03-31 20:37:32.079329 [  main ] Exited main event loop -> libgearman-server/gearmand.cc:386
  DEBUG 2015-03-31 20:37:32.079338 [  main ] shutting down Epoch thread -> libgearman-server/timer.cc:124
  DEBUG 2015-03-31 20:37:32.079891 [  main ] shutdown of Epoch completed -> libgearman-server/timer.cc:155
   INFO 2015-03-31 20:37:32.079909 [  main ] Closing listening socket (8)
   INFO 2015-03-31 20:37:32.079944 [  main ] Closing listening socket (9)
  DEBUG 2015-03-31 20:37:32.080006 [  main ] Closing wakeup pipe -> libgearman-server/gearmand.cc:870
  DEBUG 2015-03-31 20:37:32.080020 [  main ] Shutting down all threads -> libgearman-server/gearmand.cc:251
  DEBUG 2015-03-31 20:37:32.080032 [  main ] Shutting down thread 4 -> libgearman-server/gearmand_thread.cc:267
  DEBUG 2015-03-31 20:37:32.080164 [     4 ] Received SHUTDOWN wakeup event -> libgearman-server/gearmand_thread.cc:597
  DEBUG 2015-03-31 20:37:32.083791 [     4 ] Clearing event for IO thread wakeup pipe 4 -> libgearman-server/gearmand_thread.cc:536
  DEBUG 2015-03-31 20:37:32.084292 [     4 ] Exiting thread event loop -> libgearman-server/gearmand_thread.cc:453
  DEBUG 2015-03-31 20:37:32.084377 [  main ] Closing IO thread wakeup pipe -> libgearman-server/gearmand_thread.cc:524
  ERROR 2015-03-31 20:37:32.084525 [  proc ] GEARMAND_WAKEUP_RUN(Bad file descriptor) -> libgearman-server/gearmand_thread.cc:382
   INFO 2015-03-31 20:37:32.084789 [  main ] Gear connection disconnected
  DEBUG 2015-03-31 20:37:32.084860 [  main ] Thread 4 shutdown complete -> libgearman-server/gearmand_thread.cc:352
  DEBUG 2015-03-31 20:37:32.084871 [  main ] Shutting down thread 3 -> libgearman-server/gearmand_thread.cc:267
  DEBUG 2015-03-31 20:37:32.084901 [     3 ] Received SHUTDOWN wakeup event -> libgearman-server/gearmand_thread.cc:597
  DEBUG 2015-03-31 20:37:32.084917 [     3 ] Clearing event for IO thread wakeup pipe 3 -> libgearman-server/gearmand_thread.cc:536
  DEBUG 2015-03-31 20:37:32.084926 [     3 ] Exiting thread event loop -> libgearman-server/gearmand_thread.cc:453
  DEBUG 2015-03-31 20:37:32.084948 [  main ] Closing IO thread wakeup pipe -> libgearman-server/gearmand_thread.cc:524
  DEBUG 2015-03-31 20:37:32.084972 [  main ] Thread 3 shutdown complete -> libgearman-server/gearmand_thread.cc:352
  DEBUG 2015-03-31 20:37:32.084981 [  main ] Shutting down thread 2 -> libgearman-server/gearmand_thread.cc:267
  DEBUG 2015-03-31 20:37:32.085023 [     2 ] Received SHUTDOWN wakeup event -> libgearman-server/gearmand_thread.cc:597
  DEBUG 2015-03-31 20:37:32.085038 [     2 ] Clearing event for IO thread wakeup pipe 2 -> libgearman-server/gearmand_thread.cc:536
  DEBUG 2015-03-31 20:37:32.085047 [     2 ] Exiting thread event loop -> libgearman-server/gearmand_thread.cc:453
  DEBUG 2015-03-31 20:37:32.085096 [  main ] Closing IO thread wakeup pipe -> libgearman-server/gearmand_thread.cc:524
  DEBUG 2015-03-31 20:37:32.085132 [  main ] Thread 2 shutdown complete -> libgearman-server/gearmand_thread.cc:352
  DEBUG 2015-03-31 20:37:32.085148 [  main ] Shutting down thread 1 -> libgearman-server/gearmand_thread.cc:267
  DEBUG 2015-03-31 20:37:32.085204 [     1 ] Received SHUTDOWN wakeup event -> libgearman-server/gearmand_thread.cc:597
  DEBUG 2015-03-31 20:37:32.085223 [     1 ] Clearing event for IO thread wakeup pipe 1 -> libgearman-server/gearmand_thread.cc:536
  DEBUG 2015-03-31 20:37:32.085232 [     1 ] Exiting thread event loop -> libgearman-server/gearmand_thread.cc:453
  DEBUG 2015-03-31 20:37:32.085275 [  main ] Closing IO thread wakeup pipe -> libgearman-server/gearmand_thread.cc:524
  DEBUG 2015-03-31 20:37:32.085300 [  main ] Thread 1 shutdown complete -> libgearman-server/gearmand_thread.cc:352
  DEBUG 2015-03-31 20:37:32.085342 [  main ] removing queue: FUNCTION -> libgearman-server/gearmand.cc:159
   INFO 2015-03-31 20:37:32.085356 [  main ] Shutdown complete
veny commented 9 years ago

I can simulate the bug, so a good prerequisite for a bug fix.

veny commented 9 years ago

problem caused by joining 2 Gearman responses in one network packet. there is an error in parsing.

will be solved ASAP.

veny commented 9 years ago

I commited a fix. please try a version from github. when you confirm the fix, I release a new version.

copy of your code is commited too, in folder test/BF25.

squareproton commented 9 years ago

Nice one veny and a big thanks for the hard work you put into this! It's work like you are doing here that makes the opensource ecosystem such a pleasure to be a part of.

I'll try the new version tomorrow and let you know how it goes.

squareproton commented 9 years ago

Yes. This issue is not longer reproducible at commit 0178f8632521dd97339fde7c06f90760de6455bb.

veny commented 9 years ago

fix released in v0.2.1