dropbox / amqp-coffee

An AMQP 0.9.1 client for Node.js.
MIT License
79 stars 30 forks source link

Unspecified "error" event thrown #23

Closed schonfeld closed 10 years ago

schonfeld commented 10 years ago

Hey there.

I've been using the wrapper in prod for almost a week now, and for the most part, it's been working great.

I noticed today that every few hours, an unspecified error event is thrown from Connection.js. I've included the stack trace, and screenshots from my logs. Please, let me know if there's anything else I can provide...

Stack Trace Gist: https://gist.githubusercontent.com/schonfeld/271cf723bed2385aa02d/raw/65a18c13552ad0053482383751e44ede1185d683/gistfile1.txt

Screenshot: https://www.dropbox.com/s/gm5geyrf6pyp1mg/Screenshot%202014-08-11%2012.43.29.png

Thanks,

schonfeld commented 10 years ago

It's worth mentioning that I do have an event listener for the connection's error event. Here's my init code:

var connection = new amqp(cfg.rabbitmq, function(err, _connection) {
  if(err) { throw err; }

  logger.info('Rabbit connection is now open.');

  queue.connection = connection;

  connection.on('ready', function(_error) {
    logger.info('RabbitMQ connection ready.', _error);
  });

  connection.on('error', function(_error) {
    logger.warn('A RabbitMQ error was thrown.', _error);
  });

  connection.on('close', function(_reason) {
    logger.warn('This RabbitMQ connection was closed.', _reason);
  });

  return next();
});
barshow commented 10 years ago

Bunch of options to dig into this.

you can run with DEBUG=amqp* AMQP=3 That will spit out all kinds of amqp details and we could actually figure out whats happening.

It looks like a consumer channel error being emitted. You could catch it like this

  consumer = connection.consume "test queue", {}, (message)->
    console.log message

  consumer.on 'error', (e)->
    console.error "Consumer error", e

If you are using exclusive queues you could try https://github.com/dropbox/amqp-coffee/tree/feature/0.1.19 It will NOT emit a error event on channel errors if theres a waiting callback, but still would during a reconnect as theres no waiting callback. It hasn't been merged to master yet but probably will within a day or two.

schonfeld commented 10 years ago

I've been avoiding using exclusive queues until you release 0.1.19 :) I'll try setting up error listeners on the consumer objects. I'll keep the thread posted.

Thanks, as always, @barshow.

barshow commented 10 years ago

running with DEBUG=amqp* AMQP=3 will also spit out whatever the error is.

schonfeld commented 10 years ago

I'm hesitant to run with those flags in prod. Should I just get over myself and use those?

barshow commented 10 years ago

It wont print any packet data, just transactional stuff and if you do AMQP=2 you will get even less data, but maybe not enough to figure this out. It could make your log files blow up depending on number of publishes. But we ran it on at level 3 in prod for a long time :)

schonfeld commented 10 years ago

Alright, so I ran the process overnight with log level 3 (and also caught consumer errors):

nodejs.log:  Tue, 12 Aug 2014 05:47:46 GMT amqp:Connection We missed a heartbeat, destroying the connection.
nodejs.log:  Tue, 12 Aug 2014 05:47:47 GMT amqp:Connection Connection closed reconnecting...

[#7969] [warn] This RabbitMQ connection was closed.

nodejs.log:  Tue, 12 Aug 2014 05:47:54 GMT amqp:AMQPParser 0 > method connectionStart {"versionMajor":0,"versionMinor":9,"serverProperties":{"capabilities":{"publisher_confirms":true,"exchange_exchange_bindings":true,"basic.nack":true,"consumer_cancel_notify":true,"connection.blocked":true,"consumer_priorities":true,"authentication_failure_close":true,"per_consumer_qos":true},"cluster_name":"REDACTED","copyright":"Copyright (C) 2007-2014 GoPivotal, Inc.","information":"Licensed under the MPL.  See http://www.rabbitmq.com/","platform":"Erlang/OTP","product":"RabbitMQ","version":"3.3.4"},"mechanisms":"AMQPLAIN PLAIN","locales":"en_US"}
nodejs.log:  Tue, 12 Aug 2014 05:47:54 GMT amqp:Connection 0 < connectionStartOk {"clientProperties":{"version":"0.1.18","platform":"ip-172-31-10-137-node-v0.10.21","product":"node-amqp-coffee"},"mechanism":"AMQPLAIN","response":{"LOGIN":"REDACTED","PASSWORD":"REDACTED"},"locale":"en_US"}
nodejs.log:  Tue, 12 Aug 2014 05:47:57 GMT amqp:AMQPParser 0 > method connectionTune {"channelMax":0,"frameMax":131072,"heartbeat":580}
nodejs.log:  Tue, 12 Aug 2014 05:47:57 GMT amqp:Connection 0 < connectionTuneOk {"channelMax":0,"frameMax":131072,"heartbeat":10}
nodejs.log:  Tue, 12 Aug 2014 05:47:57 GMT amqp:Connection 0 < connectionOpen {"virtualHost":"REDACTED"}
nodejs.log:  Tue, 12 Aug 2014 05:48:51 GMT amqp:AMQPParser 0 > method connectionOpenOk {"reserved1":""}
nodejs.log:  Tue, 12 Aug 2014 05:48:51 GMT amqp:Channel State is closed... reconnecting
nodejs.log:  Tue, 12 Aug 2014 05:48:51 GMT amqp:Connection 2 < channelOpen {}

[#7969] [info] RabbitMQ connection ready.

nodejs.log:  Tue, 12 Aug 2014 05:48:53 GMT amqp:Connection [ 'Connection Error ', { [Error: write ECONNRESET] code: 'ECONNRESET', errno: 'ECONNRESET', syscall: 'write' }, undefined, 'REDACTED HOST ADDRESS' ]
nodejs.log:  Tue, 12 Aug 2014 05:48:53 GMT amqp:Connection [ 'Connection Error ', { [Error: write ECONNRESET] code: 'ECONNRESET', errno: 'ECONNRESET', syscall: 'write' }, undefined, 'REDACTED HOST ADDRESS' ]
nodejs.log:  Tue, 12 Aug 2014 05:48:53 GMT amqp:Connection Connection closed reconnecting...

[#7969] [warn] RabbitMQ consumer has thrown an error. Consumer name: "mailer". 
[#7969] [warn] This RabbitMQ connection was closed. 

At a different instance, I noticed that a similar error was accompanied by this exception:

[#27561] [warn]     { [Error: NOT_ALLOWED - attempt to reuse consumer tag 'ip-172-31-10-137 #27561'] 
[#27561] [warn]       code: 530, 
[#27561] [warn]       err_message: 'Error: NOT_ALLOWED - attempt to reuse consumer tag \'ip-172-31-10-137 #27561\'', 
[#27561] [warn]       err_stack:  
[#27561] [warn]        [ 'Error: NOT_ALLOWED - attempt to reuse consumer tag \'ip-172-31-10-137 #27561\'', 
[#27561] [warn]          '    at Connection._onMethod (/var/node_modules/amqp-coffee/bin/src/lib/Connection.js:604:17)', 
[#27561] [warn]          '    at AMQPParser.<anonymous> (/var/node_modules/amqp-coffee/bin/src/lib/Connection.js:4:61)', 
[#27561] [warn]          '    at AMQPParser.EventEmitter.emit (events.js:106:17)', 
[#27561] [warn]          '    at AMQPParser.parseMethodFrame (/var/node_modules/amqp-coffee/bin/src/lib/AMQPParser.js:110:19)', 
[#27561] [warn]          '    at AMQPParser.frameEnd (/var/node_modules/amqp-coffee/bin/src/lib/AMQPParser.js:80:16)', 
[#27561] [warn]          '    at AMQPParser.frame (/var/node_modules/amqp-coffee/bin/src/lib/AMQPParser.js:63:21)', 
[#27561] [warn]          '    at AMQPParser.header (/var/node_modules/amqp-coffee/bin/src/lib/AMQPParser.js:50:21)', 
[#27561] [warn]          '    at AMQPParser.frameEnd (/var/node_modules/amqp-coffee/bin/src/lib/AMQPParser.js:94:19)', 
[#27561] [warn]          '    at AMQPParser.frame (/var/node_modules/amqp-coffee/bin/src/lib/AMQPParser.js:63:21)', 
[#27561] [warn]          '    at AMQPParser.header (/var/node_modules/amqp-coffee/bin/src/lib/AMQPParser.js:50:21)' ] } 

Not sure why Rabbit would hold on to non-existing consumer tags (I set my tags to %HOSTNAME% #%PID%), but I went ahead and removed my fixed consumerTags. I don't really mind if it auto-assigns those.

I wonder why those ECONNRESETs are happening. Any clues?

I'm seeing a lot of [Error: write EPIPE] code: 'EPIPE', errno: 'EPIPE', syscall: 'write', fatal: true in the logs.

Finally, I think all this stems from the fact we keep missing heartbeats, and then terminate connections. It seems that when we do that, it also terminates any job that is currently being processed by our scripts. What could be the cause for these missing heartbeats? This happens a lot...

Mikxail commented 10 years ago

I have same error.

log

  amqp:Connection Connected to localhost:5672 +0ms
  amqp:AMQPParser 0 > method connectionStart {"versionMajor":0,"versionMinor":9,"serverProperties":{"capabilities":{"publisher_confirms":true,"exchange_exchange_bindings":true,"basic.nack":true,"consumer_cancel_notify":true,"connection.blocked":true,"consumer_priorities":true,"authentication_failure_close":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.2.4"},"mechanisms":"AMQPLAIN PLAIN","locales":"en_US"} +1ms
  amqp:Connection 0 < connectionStartOk {"clientProperties":{"version":"0.0.1","platform":"pcname-node-v0.8.26","product":"node-amqp-coffee"},"mechanism":"AMQPLAIN","response":{"LOGIN":"guest","PASSWORD":"guest"},"locale":"en_US"} +1ms
  amqp:AMQPParser 0 > method connectionTune {"channelMax":0,"frameMax":131072,"heartbeat":580} +0ms
  amqp:Connection 0 < connectionTuneOk {"channelMax":0,"frameMax":131072,"heartbeat":10} +0ms
  amqp:Connection 0 < connectionOpen {"virtualHost":"/"} +1ms
  amqp:AMQPParser 0 > method connectionOpenOk {"reserved1":""} +39ms
  amqp:Connection 1 < channelOpen {} +2ms
  amqp:AMQPParser 1 > method channelOpenOk {"reserved1":""} +1ms
  amqp:Connection 1 < exchangeDeclare {"exchange":"myex1","type":"direct","durable":true,"passive":false,"noWait":false,"autoDelete":true,"arguments":{},"internal":false} +1ms
  amqp:AMQPParser 1 > method exchangeDeclareOk {} +4ms
  amqp:Queue [ 'New queue', '{"queue":"qName"}' ] +1ms
  amqp:Connection 1 < queueDeclare {"queue":"qName","autoDelete":true,"arguments":{},"noWait":false,"exclusive":false,"durable":false,"passive":false} +0ms
  amqp:AMQPParser 1 > method queueDeclareOk {"queue":"qName","messageCount":0,"consumerCount":0} +4ms
  '1': { queue: 'qName', messageCount: 0, consumerCount: 0 } }
  amqp:Connection 1 < queueBind {"queue":"qName","exchange":"myex1","routingKey":"qName","arguments":{}} +1ms
  amqp:AMQPParser 1 > method queueBindOk {} +1ms
  amqp:Consumer channel open for consumer 2 undefined +0ms
  amqp:Connection 2 < channelOpen {} +0ms
  amqp:Consumer Consuming to qName on channel 2 +0ms
  amqp:Consumer my before set qos +0ms
  amqp:AMQPParser 2 > method channelOpenOk {"reserved1":""} +1ms
  amqp:Connection 2 < basicQos {"prefetchCount":1,"prefetchSize":0,"global":false} +0ms
  amqp:AMQPParser 2 > method basicQosOk {} +0ms
  amqp:Connection 2 < basicConsume {"noAck":false,"noLocal":false,"exclusive":false,"noWait":false,"arguments":{},"queue":"qName","consumerTag":"pcname-15652-1407947205481"} +0ms
  amqp:Consumer onMethod basicQosOk, {} +1ms
  amqp:AMQPParser 2 > method basicConsumeOk {"consumerTag":"pcname-15652-1407947205481"} +0ms
  amqp:Consumer onMethod basicConsumeOk, {"consumerTag":"pcname-15652-1407947205481"} +0ms
  amqp:Connection 1 < channelClose {"replyText":"Goodbye","replyCode":200,"classId":0,"methodId":0} +3s
  amqp:AMQPParser 1 > method channelCloseOk {} +1ms

  amqp:Connection We missed a heartbeat, destroying the connection. +37s
  amqp:Consumer my before set qos +1ms
  amqp:Connection Connection closed reconnecting... +0ms
  amqp:AMQPParser 0 > method connectionStart {"versionMajor":0,"versionMinor":9,"serverProperties":{"capabilities":{"publisher_confirms":true,"exchange_exchange_bindings":true,"basic.nack":true,"consumer_cancel_notify":true,"connection.blocked":true,"consumer_priorities":true,"authentication_failure_close":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.2.4"},"mechanisms":"AMQPLAIN PLAIN","locales":"en_US"} +1s
  amqp:Connection 0 < connectionStartOk {"clientProperties":{"version":"0.0.1","platform":"pcname-node-v0.8.26","product":"node-amqp-coffee"},"mechanism":"AMQPLAIN","response":{"LOGIN":"guest","PASSWORD":"guest"},"locale":"en_US"} +0ms
  amqp:AMQPParser 0 > method connectionTune {"channelMax":0,"frameMax":131072,"heartbeat":580} +0ms
  amqp:Connection 0 < connectionTuneOk {"channelMax":0,"frameMax":131072,"heartbeat":10} +0ms
  amqp:Connection 0 < connectionOpen {"virtualHost":"/"} +1ms
  amqp:AMQPParser 0 > method connectionOpenOk {"reserved1":""} +39ms
  amqp:Channel State is closed... reconnecting +0ms
  amqp:Connection 2 < channelOpen {} +1ms
  amqp:AMQPParser 2 > method channelOpenOk {"reserved1":""} +1ms
  amqp:Connection 2 < basicQos {"prefetchCount":1,"prefetchSize":0,"global":false} +0ms
  amqp:AMQPParser 2 > method basicQosOk {} +0ms
  amqp:Connection 2 < basicConsume {"noAck":false,"noLocal":false,"exclusive":false,"noWait":false,"arguments":{},"queue":"qName","consumerTag":"pcname-15652-1407947205481","reserved1":0} +1ms
  amqp:Consumer onMethod basicQosOk, {} +0ms
  amqp:AMQPParser 2 > method channelClose {"replyCode":404,"replyText":"NOT_FOUND - no queue 'qName' in vhost '/'","classId":60,"methodId":20} +1ms
  amqp:Channel Channel closed by server {"replyCode":404,"replyText":"NOT_FOUND - no queue 'qName' in vhost '/'","classId":60,"methodId":20} +0ms

events.js:73
        throw new Error("Uncaught, unspecified 'error' event.");
              ^
Error: Uncaught, unspecified 'error' event.
  at Consumer.EventEmitter.emit (events.js:73:15)
  at Consumer._channelClosed (/tmp/amqp-coffee-test/node_modules/amqp-coffee/src/lib/Consumer.coffee:131:8)
  at Consumer.__bind [as _channelClosed] (/tmp/amqp-coffee-test/node_modules/amqp-coffee/src/lib/Consumer.coffee:2:1)
  at Consumer.Channel._onChannelMethod (/tmp/amqp-coffee-test/node_modules/amqp-coffee/src/lib/Channel.coffee:224:10)
  at Connection._onMethod (/tmp/amqp-coffee-test/node_modules/amqp-coffee/src/lib/Connection.coffee:443:26)
  at AMQPParser.__bind (/tmp/amqp-coffee-test/node_modules/amqp-coffee/src/lib/Connection.coffee:1:1)
  at AMQPParser.EventEmitter.emit (events.js:106:17)
  at AMQPParser.parseMethodFrame (/tmp/amqp-coffee-test/node_modules/amqp-coffee/src/lib/AMQPParser.coffee:116:6)
  at AMQPParser.frameEnd (/tmp/amqp-coffee-test/node_modules/amqp-coffee/src/lib/AMQPParser.coffee:91:35)
  at AMQPParser.frame (/tmp/amqp-coffee-test/node_modules/amqp-coffee/src/lib/AMQPParser.coffee:75:15)
  at AMQPParser.header (/tmp/amqp-coffee-test/node_modules/amqp-coffee/src/lib/AMQPParser.coffee:61:15)
  at AMQPParser.execute (/tmp/amqp-coffee-test/node_modules/amqp-coffee/src/lib/AMQPParser.coffee:27:16)
  at Socket.Connection._setupParser (/tmp/amqp-coffee-test/node_modules/amqp-coffee/src/lib/Connection.coffee:282:45)
  at Socket.EventEmitter.emit (events.js:96:17)
  at TCP.onread (net.js:397:14)

Test script:

amqp = require 'amqp-coffee'

conn = new amqp (err) ->
    conn.exchange {exchange: "myex1", type: "direct", durable: true}, (err, ex)->
        ex.declare ->
            conn.queue {queue: "qName"}, (err, q) ->
                q.declare ->
                    q.bind "myex1", "qName", ->
                        consumer = conn.consume "qName", {prefetchCount: 1}, (msg) ->
                            setTimeout ->
                                msg.ack()
                            , 1000
                        , (err, r) ->
                            console.log "-----consume setup", arguments

After running this script you need wait sometime. After 1-2 minutes it crashing.

barshow commented 10 years ago

@Mikxail looks like your amqp server is crashing and destroying that queue. you need a error handler on the consumer to detect that. Or to make that queue durable.

barshow commented 10 years ago

@schonfeld your error with the reusing of a consumer tag is really interesting, I am investigating that now. Is your amqp server on a flakey wan like network or is it close to the consumer? EPIPE means the tcp socket is closed. I would try making heartbeats quicker, or if your using aws maybe try opening the ephemeral ports between the consumer and server.

schonfeld commented 10 years ago

@barshow my workers live on AWS, while Rabbit lives on GCE (5 node rabbit cluster). I wouldn't really call either of those flakey WANs, but there's def some distance between them.

I had a theory that the heartbeats are being missed cos the workers are CPU intensive... So I upped the heartbeat to 60s. So far, I've noticed far less missed heartbeats. But, this doesn't feel like a solution. Along with inc'ing the heartbeat, I also skipped the load balancer and pointed amqp directly to the cluster's 5 IPs, FWIW.

barshow commented 10 years ago

@schonfeld skipping the load balancers could be a good idea, without quickish heartbeats the lb could close the connections. did skipping those help at all?a

schonfeld commented 10 years ago

@barshow I am seeing less heartbeat drops for sure. No connection resets since. But, I don't quite know what the trigger for those is, so its nearly impossible to reproduce this problem on command. Running @Mikxail's script isn't crashing on my local, even when I run the CPU to 100%.

Is missing an occasional heartbeat considered okay? Or is it a cursor for bad things to come?

barshow commented 10 years ago

Missing the heartbeats should mean your connect is closed, and it wasn't expected. Firewalls and load balancers are usually the culprits there. It should deal with it properly. @Mikxail 's log seemed to indicated that his amqp server actually restarted.. as the queue didn't exist after reconnect and it didnt seem to be a auto delete queue

schonfeld commented 10 years ago

Ah, I see. In that case, I'm in a different boat than @Mikxail.

I'm definitely still seeing missed heartbeats, even with direct IP connections. I'd assume Rabbit should be "advanced" enough to be able to handle cross-network (AWS + GCE) usage. I'll keep digging. If you think of anything else that might be an issue here, please do chime in.

Thanks for all your time and help, @barshow!

barshow commented 10 years ago

@Mikxail i would suggest shorter heartbeats like 15 seconds. also is your process really busy like 100% all the time?

Mikxail commented 10 years ago

@barshow my amqp server (rabbitmq) worked without restarts. I don't sent any messages to amqp. My cpu is 15% load.

I'll try short heartbeat latter and report you

barshow commented 10 years ago

@Mikxail you're queue deleted before the reconnect I think switching to durable or double checking the amqp server logs to see what happened there.

Mikxail commented 10 years ago

@barshow i'll tried conn = new amqp {heartbeat: 2000}, (err) -> log:

...............
  amqp:AMQPParser 2 > method channelOpenOk {"reserved1":""} +0ms
  amqp:Connection 2 < basicQos {"prefetchCount":1,"prefetchSize":0,"global":false} +0ms
  amqp:AMQPParser 2 > method basicQosOk {} +1ms
  amqp:Connection 2 < basicConsume {"noAck":false,"noLocal":false,"exclusive":false,"noWait":false,"arguments":{},"queue":"qName","consumerTag":"mikhail-SVS1312S9RB-506-1407966536443"} +0ms
  amqp:Consumer onMethod basicQosOk, {} +0ms
  amqp:AMQPParser 2 > method basicConsumeOk {"consumerTag":"mikhail-SVS1312S9RB-506-1407966536443"} +0ms
  amqp:Consumer onMethod basicConsumeOk, {"consumerTag":"mikhail-SVS1312S9RB-506-1407966536443"} +1ms
  amqp:Connection 1 < channelClose {"replyText":"Goodbye","replyCode":200,"classId":0,"methodId":0} +3s
  amqp:AMQPParser 1 > method channelCloseOk {} +2ms

......there ok, next log after 60-180 sec....

  amqp:Connection We missed a heartbeat, destroying the connection. +1m
  amqp:Consumer my before set qos +0ms
  amqp:Connection Connection closed reconnecting... +1ms
  amqp:AMQPParser 0 > method connectionStart {"versionMajor":0,"versionMinor":9,"serverProperties":{"capabilities":{"publisher_confirms":true,"exchange_exchange_bindings":true,"basic.nack":true,"consumer_cancel_notify":true,"connection.blocked":true,"consumer_priorities":true,"authentication_failure_close":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.2.4"},"mechanisms":"AMQPLAIN PLAIN","locales":"en_US"} +1s
  amqp:Connection 0 < connectionStartOk {"clientProperties":{"version":"0.0.1","platform":"mikhail-SVS1312S9RB-node-v0.8.26","product":"node-amqp-coffee"},"mechanism":"AMQPLAIN","response":{"LOGIN":"guest","PASSWORD":"guest"},"locale":"en_US"} +0ms
  amqp:AMQPParser 0 > method connectionTune {"channelMax":0,"frameMax":131072,"heartbeat":580} +2ms
  amqp:Connection 0 < connectionTuneOk {"channelMax":0,"frameMax":131072,"heartbeat":10} +1ms
  amqp:Connection 0 < connectionOpen {"virtualHost":"/"} +0ms
  amqp:AMQPParser 0 > method connectionOpenOk {"reserved1":""} +40ms
  amqp:Channel State is closed... reconnecting +0ms
  amqp:Connection 2 < channelOpen {} +0ms
  amqp:AMQPParser 2 > method channelOpenOk {"reserved1":""} +1ms
  amqp:Connection 2 < basicQos {"prefetchCount":1,"prefetchSize":0,"global":false} +0ms
  amqp:AMQPParser 2 > method basicQosOk {} +0ms
  amqp:Connection 2 < basicConsume {"noAck":false,"noLocal":false,"exclusive":false,"noWait":false,"arguments":{},"queue":"qName","consumerTag":"mikhail-SVS1312S9RB-506-1407966536443","reserved1":0} +1ms
  amqp:Consumer onMethod basicQosOk, {} +0ms
  amqp:AMQPParser 2 > method channelClose {"replyCode":404,"replyText":"NOT_FOUND - no queue 'qName' in vhost '/'","classId":60,"methodId":20} +0ms
  amqp:Channel Channel closed by server {"replyCode":404,"replyText":"NOT_FOUND - no queue 'qName' in vhost '/'","classId":60,"methodId":20} +0ms

events.js:73
        throw new Error("Uncaught, unspecified 'error' event.");
              ^
Error: Uncaught, unspecified 'error' event.
  at Consumer.EventEmitter.emit (events.js:73:15)
  at Consumer._channelClosed (/home/mikhail/git/test-node-amqp/node_modules/amqp-coffee/src/lib/Consumer.coffee:131:8)
  at Consumer.__bind [as _channelClosed] (/home/mikhail/git/test-node-amqp/node_modules/amqp-coffee/src/lib/Consumer.coffee:2:1)
  at Consumer.Channel._onChannelMethod (/home/mikhail/git/test-node-amqp/node_modules/amqp-coffee/src/lib/Channel.coffee:224:10)
  at Connection._onMethod (/home/mikhail/git/test-node-amqp/node_modules/amqp-coffee/src/lib/Connection.coffee:443:26)
  at AMQPParser.__bind (/home/mikhail/git/test-node-amqp/node_modules/amqp-coffee/src/lib/Connection.coffee:1:1)
  at AMQPParser.EventEmitter.emit (events.js:106:17)
  at AMQPParser.parseMethodFrame (/home/mikhail/git/test-node-amqp/node_modules/amqp-coffee/src/lib/AMQPParser.coffee:116:6)
  at AMQPParser.frameEnd (/home/mikhail/git/test-node-amqp/node_modules/amqp-coffee/src/lib/AMQPParser.coffee:91:35)
  at AMQPParser.frame (/home/mikhail/git/test-node-amqp/node_modules/amqp-coffee/src/lib/AMQPParser.coffee:75:15)
  at AMQPParser.header (/home/mikhail/git/test-node-amqp/node_modules/amqp-coffee/src/lib/AMQPParser.coffee:61:15)
  at AMQPParser.execute (/home/mikhail/git/test-node-amqp/node_modules/amqp-coffee/src/lib/AMQPParser.coffee:27:16)
  at Socket.Connection._setupParser (/home/mikhail/git/test-node-amqp/node_modules/amqp-coffee/src/lib/Connection.coffee:282:45)
  at Socket.EventEmitter.emit (events.js:96:17)
  at TCP.onread (net.js:397:14)

Next I tried conn = new amqp {heartbeat: 40000}, (err) -> Log and error is same.

Next I tried

conn = new amqp (err) ->
    conn.queue {queue: "qName", durable: true}, (err, q) ->

and same error again

.............
  amqp:Consumer onMethod basicQosOk, {} +0ms
  amqp:AMQPParser 2 > method channelClose {"replyCode":404,"replyText":"NOT_FOUND - no queue 'qName' in vhost '/'","classId":60,"methodId":20} +0ms
  amqp:Channel Channel closed by server {"replyCode":404,"replyText":"NOT_FOUND - no queue 'qName' in vhost '/'","classId":60,"methodId":20} +0ms
Mikxail commented 10 years ago

@barshow if I understand right there is two problems.

  1. missing heartbeats. It's reason for losing connection. amqp:Connection We missed a heartbeat, destroying the connection. +1m
  2. queue will not recreated after reconnect. It's reason for uncaught error after bad response from amqp server amqp:AMQPParser 2 > method channelClose {"replyCode":404,"replyText":"NOT_FOUND - no queue 'qName' in vhost '/'","classId":60,"methodId":20} +0ms

I tried conn.queue {queue: "qName", autoDelete: false}, (err, q) ->. It's partially solved the problem. Heartbeats is missing but script doesn't crashing.

barshow commented 10 years ago

0.1.19 may fix some of these problems around alerting on bad connections etc. however the missing heartbeats could be a indication of actual network problems... do you feel like that is unlikely?