search

iande / onstomp

A STOMP messaging client library for Ruby
http://mathish.com/projects/onstomp.html
Other
23 stars 11 forks source link

ActiveMQ: unterminated header: 'ERROR' (OnStomp::MalformedHeaderError) #29

Closed l8nite closed 8 years ago

l8nite commented 8 years ago

I haven't root-caused this yet, but in case you might have an idea on the best way to debug:

from onstomp-1.0.9/lib/onstomp/connections/serializers/stomp_1_1.rb:61:in `split_header': unterminated header: 'ERROR' (OnStomp::MalformedHeaderError)
from onstomp-1.0.9/lib/onstomp/connections/serializers/stomp_1.rb:113:in `finish_header_line'
from onstomp-1.0.9/lib/onstomp/connections/serializers/stomp_1.rb:84:in `parser_flush'
from onstomp-1.0.9/lib/onstomp/connections/serializers/stomp_1.rb:50:in `parse_header_line'
from onstomp-1.0.9/lib/onstomp/connections/serializers/stomp_1.rb:147:in `bytes_to_frame'
from onstomp-1.0.9/lib/onstomp/connections/base.rb:242:in `io_process_read'
from onstomp-1.0.9/lib/onstomp/connections/base.rb:153:in `io_process'
from onstomp-1.0.9/lib/onstomp/components/threaded_processor.rb:28:in `block in start'
l8nite commented 8 years ago

I ended up dumping the read/write frames manually by hacking up the connection classes... looks like this is due to an ERROR frame from AMQ violating the protocol and including a newline where it shouldn't... don't have a solid repro yet, but I'm working on it.

iande commented 8 years ago

If you can post the entire frame, I'd like to see that. ActiveMQ is the primary message broker I test against.

l8nite commented 8 years ago

I think I can explain this.

I connected with an incorrect ack mode (I intended to use client-individual, but due to a symbol-vs-string issue in my options hash, the onstomp client was using auto).

Then, my subscribe callback was sending an ACK for every message, and AMQ was complaining about it:

>>>ERROR
>>>content-type:text/plain
>>>message:Unexpected ACK received for message-id [ID\cSCPRDEHRPVT33-51884-635795561461907647-1\c22553\c1\c1\c1]
>>>
>>>org.apache.activemq.transport.stomp.ProtocolException: Unexpected ACK received for message-id [ID:SCPRDEHRPVT33-51884-635795561461907647-1:22553:1:1:1]
        at org.apache.activemq.transport.stomp.ProtocolConverter.onStompAck(ProtocolConverter.java:462)
        at org.apache.activemq.transport.stomp.ProtocolConverter.onStompCommand(ProtocolConverter.java:247)
        at org.apache.activemq.transport.stomp.StompTransportFilter.onCommand(StompTransportFilter.java:75)
        at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
        at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214)
        at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)
        at java.lang.Thread.run(Thread.java:744)

>>>
>>>0</DateAndTimeOfServiceUtc><FacilityGuid>0fcd8d5a [snip]

Ok, so the ERROR frame itself looks fine and isn't violating the protocol, but AMQ is sending a bogus message frame immediately afterwards. This doesn't happen every time, and the bogus content appears to be truncated in random places.

My guess is that AMQ has a write buffer somewhere it is overwriting with the ERROR output but is not clearing it beforehand.

In any case, fixing the ack mode alleviated this particular issue.