me-box / databox

Databox container manager and dashboard server
MIT License
94 stars 25 forks source link

Network creation error on clean install #4

Closed Toshbrown closed 7 years ago

Toshbrown commented 7 years ago

When starting Databox from clean state some of the networks fail to create.

Toshbrown commented 7 years ago

Test code

 var Docker = require('dockerode');
 var docker = new Docker();

 const createNetwork = function(name) {
   return docker.createNetwork({
        Name: name,
       Driver: 'bridge'
    });
 };

 const networks = ["net_1","net_2","net_3","net_4","net_5"];

 Promise.all(networks.map(createNetwork))
 .then((res)=>{
     console.log(res);
 })
 .catch((err)=>{
     console.log('[ERROR]',err);
});

Error

  /Users/tosh/Documents/projects/databox/databox/node_modules/dockerode/lib/network.js:43
  callback(err, data);
  ^
 TypeError: callback is not a function at/Users/tosh/Documents/projects/databox/databox/node_modules/dockerode/lib/network.js:43:7
at Modem.buildPayload (/Users/tosh/Documents/projects/databox/databox/node_modules/docker-modem/lib/modem.js:255:7)
at IncomingMessage.<anonymous> (/Users/tosh/Documents/projects/databox/databox/node_modules/docker-modem/lib/modem.js:214:14)
at emitNone (events.js:91:20)
at IncomingMessage.emit (events.js:188:7)
at endReadableNT (_stream_readable.js:974:12)
at _combinedTickCallback (internal/process/next_tick.js:80:11)
at process._tickCallback (internal/process/next_tick.js:104:9)

Looks like a dockerode problem:

https://github.com/apocas/dockerode/blob/master/lib/network.js#L18 callback function is set to 1 so its not returning a promise as its checking for undefined

@yousefamar can you confirm?

yousefamar commented 7 years ago

I get the same error. Turns out callback is a number somehow instead of a function. Digging for bugs in Dockerode.

yousefamar commented 7 years ago

You'll never believe the reason for this bug...

To recreate, I did:

databox/container-manager (master|…)» cat test.js
new require('dockerode')().createNetwork({
        Name: 'n1',
        Driver: 'bridge'
})
.then((res)=>{
        console.log(res);
})
.catch((err)=>{
        console.log('[ERROR]', err);
});
databox/container-manager (master|…)» DEBUG=* node test
  modem Sending: { path: '/networks/create?Name=n1&Driver=bridge',
  method: 'POST',
  headers: { 'Content-Type': 'application/json', 'Content-Length': 31 },
  key: undefined,
  cert: undefined,
  ca: undefined,
  socketPath: '/var/run/docker.sock' } +0ms
  modem Received: {"Id":"f75fa8f5ef791d109461d9352a5242da594b12425fd846ad7387c1f5a4bca1f8","Warning":"Network with name n1 (id : a72f7223e7036bd6b275107728fb343c8d222caa4ad70065248f5912af392222) already exists"}
 +346ms
  modem Sending: { path: '/networks/f75fa8f5ef791d109461d9352a5242da594b12425fd846ad7387c1f5a4bca1f8',
  method: 'GET',
  headers: { 'Transfer-Encoding': 'chunked' },
  key: undefined,
  cert: undefined,
  ca: undefined,
  socketPath: '/var/run/docker.sock' } +6ms
undefined
  modem Received: {"Name":"n1","Id":"f75fa8f5ef791d109461d9352a5242da594b12425fd846ad7387c1f5a4bca1f8","Created":"2017-03-28T21:37:07.197993797+01:00","Scope":"local","Driver":"bridge","EnableIPv6":false,"IPAM":{"Driver":"default","Options":null,"Config":[{"Subnet":"192.168.176.0/20","Gateway":"192.168.176.1"}]},"Internal":false,"Attachable":false,"Containers":{},"Options":{},"Labels":{}}
 +6ms
/home/amar/proj/phd/databox/container-manager/node_modules/dockerode/lib/network.js:43
      callback(err, data);
      ^

TypeError: callback is not a function
    at /home/amar/proj/phd/databox/container-manager/node_modules/dockerode/lib/network.js:43:7
    at Modem.buildPayload (/home/amar/proj/phd/databox/container-manager/node_modules/docker-modem/lib/modem.js:255:7)
    at IncomingMessage.<anonymous> (/home/amar/proj/phd/databox/container-manager/node_modules/docker-modem/lib/modem.js:214:14)
    at emitNone (events.js:91:20)
    at IncomingMessage.emit (events.js:188:7)
    at endReadableNT (_stream_readable.js:974:12)
    at _combinedTickCallback (internal/process/next_tick.js:80:11)
    at process._tickCallback (internal/process/next_tick.js:104:9)

I was baffled for a bit, but narrowed it down to console.log(res). res is a Network instance, and yet, toString() doesn't crash. If you check the stack trace before network.js:43, it says that Network.inspect throws the error (because callback is a number, not a function, as mentioned) but nothing in Dockerode calls Network.inspect.

So I dug into NodeJS source code, following the stack trace, and found this: https://github.com/nodejs/node/blob/master/lib/util.js#L350. Node calls Network.inspect!!!

Some more digging, and it turns out, putting an .inspect function on an Object prototype is similar to overriding .toString, in that you can use it to help create human-readable logs. More info: https://nodejs.org/api/util.html#util_custom_inspection_functions_on_objects

Conclusion

The network does actually get created; it's just logging a Network that fails and throws an error. If you replace console.log(res) with console.log(res.toString()) (or nothing), all's well with the world again.

The bug is in Dockerode — I guess they didn't realise that .inspect() is reserved (as I didn't). I'll raise an issue in Dockerode and they can decide if they want to rename it or not.

P.S. As a bonus, there's a "bug" with the Docker Remote API: it doesn't stop you from creating duplicate networks, only warning you, while Docker CLI does and throws an error.

Toshbrown commented 7 years ago

@yousefamar Amazing work 🥇

I could not see where/why inspect() was being called. It also explains why when debugging the infamous #50 and #54 pr's adding console.logs was causing inconsistent behaviour.

mor1 commented 7 years ago

Turtles all the way down... :) Nicely done! (Also, JavaScript eh...)

yousefamar commented 7 years ago

Ty all! Dockerode has a accepted my PR upstream so this issue should be resolved.