node-amqp icon indicating copy to clipboard operation
node-amqp copied to clipboard

Unhandled connection error: COMMAND_INVALID - second 'channel.open' seen

Open lookfirst opened this issue 12 years ago • 3 comments

Save this to foo.coffee and run coffee foo.coffee...

amqp = require('amqp')
amqp.createConnection "YOUR CONNECTION URL", {}, (connection) ->
    connection.exchange 'ldexchange', {type: 'direct', confirm: true, durable: true}, (exchange) ->

It outputs the error that is the subject of this issue. Any idea why?

Using the connection.on 'ready' works fine for me, but I really need to make sure that this stuff is all setup before my app tries to to send messages, so I'd rather use callbacks to set everything up.

lookfirst avatar Jan 17 '13 02:01 lookfirst

I had to change your code a bit, but this works for me:

amqp = require('amqp')
amqp.createConnection {url: "amqp://guest:guest@localhost:5672"}, (connection) ->
    connection.exchange 'ldexchange', {type: 'direct', confirm: true, durable: true}, (exchange) ->

I received an error with your parameters to createConnection, but I have no idea if this is the error you see:

TypeError: Object.getOwnPropertyNames called on non-object
    at Function.getOwnPropertyNames (native)
    at mixin (..../node-amqp/amqp.js:39:14)
    at Connection.setOptions (..../node-amqp/amqp.js:1020:3)
    at new Connection (..../node-amqp/amqp.js:798:8)
    at Object.exports.createConnection (..../node-amqp/amqp.js:1010:11)
    at Object.<anonymous> (..../node-amqp/foo.coffee:6:8)
    at Object.<anonymous> (..../node-amqp/foo.coffee:14:4)
    at Module._compile (module.js:449:26)
    at Object.exports.run (..../node_modules/coffee-script/lib/coffee-script/coffee-script.js:83:25)
    at compileScript (..../node_modules/coffee-script/lib/coffee-script/command.js:177:29)

Did this help?

zeisss avatar Jan 26 '13 00:01 zeisss

I'm seeing this problem too.

It appears to happen when you try to declare an exchange in the same tick of the event loop as the readyCallback is called.

This is the debug output I get when running into this issue:

making non-ssl connection
setting connection timeout to 10000
Initiating handshake...
connected so resetting connection timeout
execute: 0100000000014a000a000a0009000001250c6361706162696c69746965734600000058127075626c69736865725f636f6e6669726d7374011a65786368616e67655f65786368616e67655f62696e64696e677374010a62617369632e6e61636b740116636f6e73756d65725f63616e63656c5f6e6f74696679740109636f707972696768745300000027436f707972696768742028432920323030372d3230313320476f5069766f74616c2c20496e632e0b696e666f726d6174696f6e53000000354c6963656e73656420756e64657220746865204d504c2e202053656520687474703a2f2f7777772e7261626269746d712e636f6d2f08706c6174666f726d530000000a45726c616e672f4f54500770726f6475637453000000085261626269744d510776657273696f6e5300000005332e312e350000000e414d51504c41494e20504c41494e00000005656e5f5553ce
Executing method 0 { name: 'connectionStart',
  fields:
   [ { name: 'versionMajor', domain: 'octet' },
     { name: 'versionMinor', domain: 'octet' },
     { name: 'serverProperties', domain: 'table' },
     { name: 'mechanisms', domain: 'longstr' },
     { name: 'locales', domain: 'longstr' } ],
  methodIndex: 10,
  classIndex: 10 } { versionMajor: 0,
  versionMinor: 9,
  serverProperties:
   { capabilities:
      { publisher_confirms: true,
        exchange_exchange_bindings: true,
        'basic.nack': true,
        consumer_cancel_notify: true },
     copyright: 'Copyright (C) 2007-2013 GoPivotal, Inc.',
     information: 'Licensed under the MPL.  See http://www.rabbitmq.com/',
     platform: 'Erlang/OTP',
     product: 'RabbitMQ',
     version: '3.1.5' },
  mechanisms: 'AMQPLAIN PLAIN',
  locales: 'en_US' }
0 > connectionStart {"versionMajor":0,"versionMinor":9,"serverProperties":{"capabilities":{"publisher_confirms":true,"exchange_exchange_bindings":true,"basic.nack":true,"consumer_cancel_notify":true},"copyright":"Copyright (C) 2007-2013 GoPivotal, Inc.","information":"Licensed under the MPL.  See http://www.rabbitmq.com/","platform":"Erlang/OTP","product":"RabbitMQ","version":"3.1.5"},"mechanisms":"AMQPLAIN PLAIN","locales":"en_US"}
0 < connectionStartOk {"clientProperties":{"version":"0.2.0","platform":"node-v0.10.26","product":"node-amqp"},"mechanism":"AMQPLAIN","response":{"LOGIN":"guest","PASSWORD":"guest"},"locale":"en_US"}
sending frame: 1,0,0,0,0,0,129,0,10,0,11,0,0,0,67,7,118,101,114,115,105,111,110,83,0,0,0,5,48,46,50,46,48,8,112,108,97,116,102,111,114,109,83,0,0,0,13,110,111,100,101,45,118,48,46,49,48,46,50,54,7,112,114,111,100,117,99,116,83,0,0,0,9,110,111,100,101,45,97,109,113,112,8,65,77,81,80,76,65,73,78,0,0,0,35,5,76,79,71,73,78,83,0,0,0,5,103,117,101,115,116,8,80,65,83,83,87,79,82,68,83,0,0,0,5,103,117,101,115,116,5,101,110,95,85,83,206
execute: 0100000000000c000a001e0000000200000258ce
Executing method 0 { name: 'connectionTune',
  fields:
   [ { name: 'channelMax', domain: 'short' },
     { name: 'frameMax', domain: 'long' },
     { name: 'heartbeat', domain: 'short' } ],
  methodIndex: 30,
  classIndex: 10 } { channelMax: 0, frameMax: 131072, heartbeat: 600 }
0 > connectionTune {"channelMax":0,"frameMax":131072,"heartbeat":600}
tweaking maxFrameBuffer to 131072
0 < connectionTuneOk {"channelMax":0,"frameMax":131072,"heartbeat":0}
sending frame: 1,0,0,0,0,0,12,0,10,0,31,0,0,0,2,0,0,0,0,206
0 < connectionOpen {"virtualHost":"/","reserved1":"","reserved2":true}
sending frame: 1,0,0,0,0,0,8,0,10,0,40,1,47,0,1,206
execute: 01000000000005000a002900ce
Executing method 0 { name: 'connectionOpenOk',
  fields: [ { name: 'reserved1', domain: 'shortstr' } ],
  methodIndex: 41,
  classIndex: 10 } { reserved1: '' }
0 > connectionOpenOk {"reserved1":""}
1 < channelOpen {"reserved1":""}
sending frame: 1,0,1,0,0,0,5,0,20,0,10,0,206
2 < channelOpen {"reserved1":""}
sending frame: 1,0,2,0,0,0,5,0,20,0,10,0,206
1 < channelOpen {"reserved1":""}
sending frame: 1,0,1,0,0,0,5,0,20,0,10,0,206
2 < channelOpen {"reserved1":""}
sending frame: 1,0,2,0,0,0,5,0,20,0,10,0,206
3 < channelOpen {"reserved1":""}
sending frame: 1,0,3,0,0,0,5,0,20,0,10,0,206
4 < channelOpen {"reserved1":""}
sending frame: 1,0,4,0,0,0,5,0,20,0,10,0,206
execute: 010001000000080014000b00000000ce010002000000080014000b00000000ce01000000000037000a003201f72c434f4d4d414e445f494e56414c4944202d207365636f6e6420276368616e6e656c2e6f70656e27207365656e0014000ace
Executing method 1 { name: 'channelOpenOk',
  fields: [ { name: 'reserved1', domain: 'longstr' } ],
  methodIndex: 11,
  classIndex: 20 } { reserved1: '' }
1 > channelOpenOk {"reserved1":""}
1 < exchangeDeclare {"reserved1":0,"reserved2":false,"reserved3":false,"exchange":"counters","type":"topic","passive":false,"durable":true,"autoDelete":false,"internal":false,"noWait":false,"arguments":{}}
sending frame: 1,0,1,0,0,0,26,0,40,0,10,0,0,8,99,111,117,110,116,101,114,115,5,116,111,112,105,99,2,0,0,0,0,206
Executing method 2 { name: 'channelOpenOk',
  fields: [ { name: 'reserved1', domain: 'longstr' } ],
  methodIndex: 11,
  classIndex: 20 } { reserved1: '' }
2 > channelOpenOk {"reserved1":""}
2 < exchangeDeclare {"reserved1":0,"reserved2":false,"reserved3":false,"exchange":"pageview","type":"topic","passive":false,"durable":true,"autoDelete":false,"internal":false,"noWait":false,"arguments":{}}
sending frame: 1,0,2,0,0,0,26,0,40,0,10,0,0,8,112,97,103,101,118,105,101,119,5,116,111,112,105,99,2,0,0,0,0,206
Executing method 0 { name: 'connectionClose',
  fields:
   [ { name: 'replyCode', domain: 'short' },
     { name: 'replyText', domain: 'shortstr' },
     { name: 'classId', domain: 'short' },
     { name: 'methodId', domain: 'short' } ],
  methodIndex: 50,
  classIndex: 10 } { replyCode: 503,
  replyText: 'COMMAND_INVALID - second \'channel.open\' seen',
  classId: 20,
  methodId: 10 }
0 > connectionClose {"replyCode":503,"replyText":"COMMAND_INVALID - second 'channel.open' seen","classId":20,"methodId":10}
error: amqp error code=503

For the time being I've worked around this by wrapping code in the ready callback in a setImmediate(). It seems running on the next tick helps avoid the issue. Here's the debug output for that:

making non-ssl connection
setting connection timeout to 10000
Initiating handshake...
connected so resetting connection timeout
execute: 0100000000014a000a000a0009000001250c6361706162696c69746965734600000058127075626c69736865725f636f6e6669726d7374011a65786368616e67655f65786368616e67655f62696e64696e677374010a62617369632e6e61636b740116636f6e73756d65725f63616e63656c5f6e6f74696679740109636f707972696768745300000027436f707972696768742028432920323030372d3230313320476f5069766f74616c2c20496e632e0b696e666f726d6174696f6e53000000354c6963656e73656420756e64657220746865204d504c2e202053656520687474703a2f2f7777772e7261626269746d712e636f6d2f08706c6174666f726d530000000a45726c616e672f4f54500770726f6475637453000000085261626269744d510776657273696f6e5300000005332e312e350000000e414d51504c41494e20504c41494e00000005656e5f5553ce
Executing method 0 { name: 'connectionStart',
  fields:
   [ { name: 'versionMajor', domain: 'octet' },
     { name: 'versionMinor', domain: 'octet' },
     { name: 'serverProperties', domain: 'table' },
     { name: 'mechanisms', domain: 'longstr' },
     { name: 'locales', domain: 'longstr' } ],
  methodIndex: 10,
  classIndex: 10 } { versionMajor: 0,
  versionMinor: 9,
  serverProperties:
   { capabilities:
      { publisher_confirms: true,
        exchange_exchange_bindings: true,
        'basic.nack': true,
        consumer_cancel_notify: true },
     copyright: 'Copyright (C) 2007-2013 GoPivotal, Inc.',
     information: 'Licensed under the MPL.  See http://www.rabbitmq.com/',
     platform: 'Erlang/OTP',
     product: 'RabbitMQ',
     version: '3.1.5' },
  mechanisms: 'AMQPLAIN PLAIN',
  locales: 'en_US' }
0 > connectionStart {"versionMajor":0,"versionMinor":9,"serverProperties":{"capabilities":{"publisher_confirms":true,"exchange_exchange_bindings":true,"basic.nack":true,"consumer_cancel_notify":true},"copyright":"Copyright (C) 2007-2013 GoPivotal, Inc.","information":"Licensed under the MPL.  See http://www.rabbitmq.com/","platform":"Erlang/OTP","product":"RabbitMQ","version":"3.1.5"},"mechanisms":"AMQPLAIN PLAIN","locales":"en_US"}
0 < connectionStartOk {"clientProperties":{"version":"0.2.0","platform":"node-v0.10.26","product":"node-amqp"},"mechanism":"AMQPLAIN","response":{"LOGIN":"guest","PASSWORD":"guest"},"locale":"en_US"}
sending frame: 1,0,0,0,0,0,129,0,10,0,11,0,0,0,67,7,118,101,114,115,105,111,110,83,0,0,0,5,48,46,50,46,48,8,112,108,97,116,102,111,114,109,83,0,0,0,13,110,111,100,101,45,118,48,46,49,48,46,50,54,7,112,114,111,100,117,99,116,83,0,0,0,9,110,111,100,101,45,97,109,113,112,8,65,77,81,80,76,65,73,78,0,0,0,35,5,76,79,71,73,78,83,0,0,0,5,103,117,101,115,116,8,80,65,83,83,87,79,82,68,83,0,0,0,5,103,117,101,115,116,5,101,110,95,85,83,206
execute: 0100000000000c000a001e0000000200000258ce
Executing method 0 { name: 'connectionTune',
  fields:
   [ { name: 'channelMax', domain: 'short' },
     { name: 'frameMax', domain: 'long' },
     { name: 'heartbeat', domain: 'short' } ],
  methodIndex: 30,
  classIndex: 10 } { channelMax: 0, frameMax: 131072, heartbeat: 600 }
0 > connectionTune {"channelMax":0,"frameMax":131072,"heartbeat":600}
tweaking maxFrameBuffer to 131072
0 < connectionTuneOk {"channelMax":0,"frameMax":131072,"heartbeat":0}
sending frame: 1,0,0,0,0,0,12,0,10,0,31,0,0,0,2,0,0,0,0,206
0 < connectionOpen {"virtualHost":"/","reserved1":"","reserved2":true}
sending frame: 1,0,0,0,0,0,8,0,10,0,40,1,47,0,1,206
execute: 01000000000005000a002900ce
Executing method 0 { name: 'connectionOpenOk',
  fields: [ { name: 'reserved1', domain: 'shortstr' } ],
  methodIndex: 41,
  classIndex: 10 } { reserved1: '' }
0 > connectionOpenOk {"reserved1":""}
1 < channelOpen {"reserved1":""}
sending frame: 1,0,1,0,0,0,5,0,20,0,10,0,206
2 < channelOpen {"reserved1":""}
sending frame: 1,0,2,0,0,0,5,0,20,0,10,0,206
execute: 010001000000080014000b00000000ce
Executing method 1 { name: 'channelOpenOk',
  fields: [ { name: 'reserved1', domain: 'longstr' } ],
  methodIndex: 11,
  classIndex: 20 } { reserved1: '' }
1 > channelOpenOk {"reserved1":""}
1 < exchangeDeclare {"reserved1":0,"reserved2":false,"reserved3":false,"exchange":"counters","type":"topic","passive":false,"durable":true,"autoDelete":false,"internal":false,"noWait":false,"arguments":{}}
sending frame: 1,0,1,0,0,0,26,0,40,0,10,0,0,8,99,111,117,110,116,101,114,115,5,116,111,112,105,99,2,0,0,0,0,206
execute: 010002000000080014000b00000000ce
Executing method 2 { name: 'channelOpenOk',
  fields: [ { name: 'reserved1', domain: 'longstr' } ],
  methodIndex: 11,
  classIndex: 20 } { reserved1: '' }
2 > channelOpenOk {"reserved1":""}
2 < exchangeDeclare {"reserved1":0,"reserved2":false,"reserved3":false,"exchange":"pageview","type":"topic","passive":false,"durable":true,"autoDelete":false,"internal":false,"noWait":false,"arguments":{}}
sending frame: 1,0,2,0,0,0,26,0,40,0,10,0,0,8,112,97,103,101,118,105,101,119,5,116,111,112,105,99,2,0,0,0,0,206
execute: 010001000000040028000bce
Executing method 1 { name: 'exchangeDeclareOk',
  fields: [],
  methodIndex: 11,
  classIndex: 40 } {}
1 > exchangeDeclareOk {}
execute: 010002000000040028000bce
Executing method 2 { name: 'exchangeDeclareOk',
  fields: [],
  methodIndex: 11,
  classIndex: 40 } {}
2 > exchangeDeclareOk {}

TheDeveloper avatar Apr 04 '14 15:04 TheDeveloper

I ran into this issue when calling connection.publish several times in the same tick of the event loop. Solved it by using process.setImmediate.

matomesc avatar Aug 02 '14 15:08 matomesc