[rabbitmq-discuss] Connection problems with Rabbitmq 1.4.0
Maarten Engelen
At the moment I have a problem connecting to the RabbitMQ broker. I'm
running version 1.4.0 on Erlang R12B4. The OS is OS X 10.5.5. Before
running any examples I did a reset of the rabbitmq broker.
I tried connecting with a ruby client and had problems connecting. The
ruby eventmachine loop quit unexpectedly so I tried to use the
RabbitMQ Java client to see if I had better luck with that library.
But also this library crashes when connecting to the broker.
I attached the error message I get from running one of the examples:
> java -classpath
.:rabbitmq-client.jar:commons-cli-1.1.jar:commons-io-1.2.jar
com/rabbitmq/examples/TestMain
/com/rabbitmq/examples/TestMain.class
com.rabbitmq.examples.TestMain : javac v49.0 on 1.5.0_16
AMQConnection.mainLoop: connection close
AMQConnection.mainLoop: connection close
Main thread caught exception: java.io.IOException
java.io.IOException
at com.rabbitmq.client.impl.AMQChannel.wrap(AMQChannel.java:105)
at com.rabbitmq.client.impl.AMQConnection.open(AMQConnection.java:359)
at com.rabbitmq.client.impl.AMQConnection.<init>(AMQConnection.java:193)
at com.rabbitmq.client.impl.AMQConnection.<init>(AMQConnection.java:164)
at com.rabbitmq.client.ConnectionFactory.newConnection(ConnectionFactory.java:159)
at com.rabbitmq.client.ConnectionFactory.newConnection(ConnectionFactory.java:207)
at com.rabbitmq.client.ConnectionFactory.newConnection(ConnectionFactory.java:221)
at com.rabbitmq.client.ConnectionFactory.newConnection(ConnectionFactory.java:232)
at com.rabbitmq.examples.TestMain.runConnectionNegotiationTest(TestMain.java:118)
at com.rabbitmq.examples.TestMain.main(TestMain.java:61)
Caused by: com.rabbitmq.client.ShutdownSignalException (connection
error; reason: java.io.EOFException)
at com.rabbitmq.client.impl.AMQConnection.shutdown(AMQConnection.java:588)
at com.rabbitmq.client.impl.AMQConnection$MainLoop.run(AMQConnection.java:458)
Caused by: java.io.EOFException
at java.io.DataInputStream.readUnsignedByte(DataInputStream.java:264)
at com.rabbitmq.client.impl.Frame.readFrom(Frame.java:111)
at com.rabbitmq.client.impl.SocketFrameHandler.readFrame(SocketFrameHandler.java:143)
at com.rabbitmq.client.impl.AMQConnection.readFrame(AMQConnection.java:284)
at com.rabbitmq.client.impl.AMQConnection$MainLoop.run(AMQConnection.java:427)
I get similar errors when trying to set up a connection with my own
Java code. Any ideas on what may cause this are greatly appreciated.
Regards,
Maarten
_______________________________________________
rabbitmq-discuss mailing list
rabbitmq...@lists.rabbitmq.com
http://lists.rabbitmq.com/cgi-bin/mailman/listinfo/rabbitmq-discuss
Matthias Radestock
Maarten Engelen wrote:
> At the moment I have a problem connecting to the RabbitMQ broker. I'm
> running version 1.4.0 on Erlang R12B4. The OS is OS X 10.5.5. Before
> running any examples I did a reset of the rabbitmq broker.
What do you mean by "reset"? Did you run the "rabbitmqctl reset"
command? If so, did you subsequently restart the rabbit app with
"rabbitmqctl start_app"?
> > java -classpath
> .:rabbitmq-client.jar:commons-cli-1.1.jar:commons-io-1.2.jar
> com/rabbitmq/examples/TestMain
> /com/rabbitmq/examples/TestMain.class
> com.rabbitmq.examples.TestMain : javac v49.0 on 1.5.0_16
> AMQConnection.mainLoop: connection close
> AMQConnection.mainLoop: connection close
> Main thread caught exception: java.io.IOException
> java.io.IOException
> at com.rabbitmq.client.impl.AMQChannel.wrap(AMQChannel.java:105)
> at com.rabbitmq.client.impl.AMQConnection.open(AMQConnection.java:359)
> at com.rabbitmq.client.impl.AMQConnection.<init>(AMQConnection.java:193)
> at com.rabbitmq.client.impl.AMQConnection.<init>(AMQConnection.java:164)
> at com.rabbitmq.client.ConnectionFactory.newConnection(ConnectionFactory.java:159)
My guess would be that either the the Erlang node isn't running at all
or the Rabbit application inside it isn't running.
What does "rabbitmqctl status" return?
Matthias.
Matthias Radestock
Maarten Engelen wrote:
> I do a rabbitmqctl stop_app, followed by a reset and start_app command.
ok. That's fine.
>> What does "rabbitmqctl status" return?
>
> It returns the following:
>
> Starting...Status of node rabbit@Workstation ...
> [{running_applications,[{rabbit,"RabbitMQ","1.4.0"},
> {mnesia,"MNESIA CXC 138 12","4.4.5"},
> {os_mon,"CPO CXC 138 46","2.1.7"},
> {sasl,"SASL CXC 138 11","2.1.5.3"},
> {stdlib,"ERTS CXC 138 10","1.15.4"},
> {kernel,"ERTS CXC 138 10","2.12.4"}]},
> {nodes,[rabbit@Workstation]},
> {running_nodes,[rabbit@Workstation]}]
That all looks fine.
> Also connecting directly to port 5672 allows me to connect.
>
> I just saw the following error in the logs which I didn't notive
> before when running TestMain:
> [...]
> =ERROR REPORT==== 27-Nov-2008::12:11:55 ===
> error on TCP connection <0.1837.0> from 127.0.0.1:63516
> {bad_version,0,1}
That is normal. TestMain runs various tests, including some that are
designed to provoke error cases, such as protocol version mismatches.
> When running ProducerMain or ConsumerMain I get the same Java error,
That's strange. The fact that you can connect to the port means rabbit
is listening. Furthermore, the log messages show that TestMain was able
to connect, but only once.
Please run the test through the tracer, i.e. start the tracer with
sh runjava.sh com.rabbitmq.tools.Tracer
and then run TestMain with
sh runjava.sh com.rabbitmq.examples.TestMain localhost 5673
and send me the output from the tracer.
Regards,
Matthias.
PS: please keep the list cc'ed.
Maarten Engelen
2008/11/27 Matthias Radestock <matt...@lshift.net>:
>> When running ProducerMain or ConsumerMain I get the same Java error,
>
> That's strange. The fact that you can connect to the port means rabbit is
> listening. Furthermore, the log messages show that TestMain was able to
> connect, but only once.
>
> Please run the test through the tracer, i.e. start the tracer with
> sh runjava.sh com.rabbitmq.tools.Tracer
> and then run TestMain with
> sh runjava.sh com.rabbitmq.examples.TestMain localhost 5673
> and send me the output from the tracer.
The following output came back from the Tracer:
com.rabbitmq.tools.Tracer.WITHHOLD_INBOUND_HEARTBEATS = false
com.rabbitmq.tools.Tracer.WITHHOLD_OUTBOUND_HEARTBEATS = false
com.rabbitmq.tools.Tracer.NO_ASSEMBLE_FRAMES = false
com.rabbitmq.tools.Tracer.NO_DECODE_FRAMES = false
java.io.EOFException
at java.io.DataInputStream.readUnsignedByte(DataInputStream.java:264)
at com.rabbitmq.client.impl.Frame.readFrom(Frame.java:111)
at com.rabbitmq.tools.Tracer$DirectionHandler.readFrame(Tracer.java:167)
at com.rabbitmq.tools.Tracer$DirectionHandler.doFrame(Tracer.java:198)
at com.rabbitmq.tools.Tracer$DirectionHandler.run(Tracer.java:231)
at java.lang.Thread.run(Thread.java:613)
java.io.EOFException
at java.io.DataInputStream.readUnsignedByte(DataInputStream.java:264)
at com.rabbitmq.client.impl.Frame.readFrom(Frame.java:111)
at com.rabbitmq.tools.Tracer$DirectionHandler.readFrame(Tracer.java:167)
at com.rabbitmq.tools.Tracer$DirectionHandler.doFrame(Tracer.java:198)
at com.rabbitmq.tools.Tracer$DirectionHandler.run(Tracer.java:231)
at java.lang.Thread.run(Thread.java:613)
The error message from TestMain is the same as before.
Regards,
Maarten
Matthias Radestock
Maarten Engelen wrote:
> The following output came back from the Tracer:
>
> com.rabbitmq.tools.Tracer.WITHHOLD_INBOUND_HEARTBEATS = false
> com.rabbitmq.tools.Tracer.WITHHOLD_OUTBOUND_HEARTBEATS = false
> com.rabbitmq.tools.Tracer.NO_ASSEMBLE_FRAMES = false
> com.rabbitmq.tools.Tracer.NO_DECODE_FRAMES = false
> java.io.EOFException
> at java.io.DataInputStream.readUnsignedByte(DataInputStream.java:264)
> at com.rabbitmq.client.impl.Frame.readFrom(Frame.java:111)
> at com.rabbitmq.tools.Tracer$DirectionHandler.readFrame(Tracer.java:167)
> at com.rabbitmq.tools.Tracer$DirectionHandler.doFrame(Tracer.java:198)
> at com.rabbitmq.tools.Tracer$DirectionHandler.run(Tracer.java:231)
> at java.lang.Thread.run(Thread.java:613)
Looks like tracing at the AMQP level isn't getting us anywhere :(
So let's try tracing at the network level. You will need to have tcpdump
installed and be able to get root privileges. Run
sudo /usr/sbin/tcpdump -i lo dst port 5672 -w trace.pcap
then run TestMain and send me the resulting trace.pcap.
Matthias.
Maarten Engelen
2008/11/27 Matthias Radestock <matt...@lshift.net>:
>> The following output came back from the Tracer:
>>
>> com.rabbitmq.tools.Tracer.WITHHOLD_INBOUND_HEARTBEATS = false
>> com.rabbitmq.tools.Tracer.WITHHOLD_OUTBOUND_HEARTBEATS = false
>> com.rabbitmq.tools.Tracer.NO_ASSEMBLE_FRAMES = false
>> com.rabbitmq.tools.Tracer.NO_DECODE_FRAMES = false
>> java.io.EOFException
>> at
>> java.io.DataInputStream.readUnsignedByte(DataInputStream.java:264)
>> at com.rabbitmq.client.impl.Frame.readFrom(Frame.java:111)
>> at
>> com.rabbitmq.tools.Tracer$DirectionHandler.readFrame(Tracer.java:167)
>> at
>> com.rabbitmq.tools.Tracer$DirectionHandler.doFrame(Tracer.java:198)
>> at com.rabbitmq.tools.Tracer$DirectionHandler.run(Tracer.java:231)
>> at java.lang.Thread.run(Thread.java:613)
>
> Looks like tracing at the AMQP level isn't getting us anywhere :(
>
> So let's try tracing at the network level. You will need to have tcpdump
> installed and be able to get root privileges. Run
> sudo /usr/sbin/tcpdump -i lo dst port 5672 -w trace.pcap
> then run TestMain and send me the resulting trace.pcap.
I have attached the zipped trace.pcap. It contains a single run of TestMain.
Maarten
Matthias Radestock
Maarten Engelen wrote:
> Attached the new file. The contents have been captured
> with `tcpdump -i lo0 -w trace.pcap port 5672`
It looks like the client is sending a perfectly correct protocol header
but the server just closes the socket rather than sending a
connection.start method.
Are there any errors in the rabbit-sasl.log?
Also, how do you start rabbit, and do you experience the same problems
right after starting it?
Maarten Engelen
2008/11/27 Matthias Radestock <matt...@lshift.net>:
>> Attached the new file. The contents have been captured
>> with `tcpdump -i lo0 -w trace.pcap port 5672`
>
> It looks like the client is sending a perfectly correct protocol header but
> the server just closes the socket rather than sending a connection.start
> method.
Ok, that fits my experience with the other libraries I used.
>
> Are there any errors in the rabbit-sasl.log?
Actually, there are:
=CRASH REPORT==== 27-Nov-2008::15:52:27 ===
crasher:
pid: <0.1925.0>
registered_name: []
exception error: undefined function rabbit_log:message/4
in function rabbit_writer:assemble_frames/2
in call from rabbit_writer:internal_send_command/3
in call from rabbit_reader:send_on_channel0/2
in call from rabbit_reader:handle_input/3
in call from rabbit_reader:mainloop/3
in call from rabbit_reader:start_connection/3
initial call: rabbit_reader:init(<0.1303.0>)
ancestors: [rabbit_tcp_client_sup,rabbit_sup,<0.1161.0>]
messages: []
links: [<0.1303.0>,#Port<0.522>]
dictionary: []
trap_exit: true
status: running
heap_size: 987
stack_size: 23
reductions: 286
neighbours:
=SUPERVISOR REPORT==== 27-Nov-2008::15:52:27 ===
Supervisor: {local,rabbit_tcp_client_sup}
Context: child_terminated
Reason: undef
Offender: [{pid,<0.1925.0>},
{name,tcp_client},
{mfa,{rabbit_reader,start_link,[]}},
{restart_type,temporary},
{shutdown,brutal_kill},
{child_type,worker}]
And this actually makes a lot of sense. After having problems running
my code I rebuild rabbit with debugging set to on. I totally forgot
that I was running rabbit with this flag on true during compilation.
The debug flag makes this define in rabbit.hrl active:
-define(LOGMESSAGE(D,C,M,Co), rabbit_log:message(D,C,M,Co)).
rabbit_log:message does not exist in rabbit_log.erl and ?LOGMESSAGE is
called in the first line of rabbit_writer:assemble_frames/2. Which
creates on obvious crash.
After recompiling rabbit the examples work as expected.
Matthias, thank you for your help with this (ending up as a minor) problem.
Maarten