activemq-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Guy Allard (Commented) (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (APLO-88) ACK followed by DISCONNECT Leaves Message Available
Date Fri, 09 Dec 2011 02:17:40 GMT

    [ https://issues.apache.org/jira/browse/APLO-88?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13165769#comment-13165769
] 

Guy Allard commented on APLO-88:
--------------------------------

Comment 2 tonight ...

I spent some time looking at this today:

- Cloned current github:  commit e707a72.
- Added warnings to Queue.scala
- Added warnings to StompCodec.scala
- Ran a build, yada yada, ....

Result of that is:

2011-12-08 20:27:39,647 | INFO  | OS     : Linux 3.0.0-13-generic (Ubuntu 11.10) | console
| hawtdispatch-DEFAULT-1
2011-12-08 20:27:39,649 | INFO  | JVM    : OpenJDK 64-Bit Server VM 1.6.0_23 (Sun Microsystems
Inc.) | console | hawtdispatch-DEFAULT-1
2011-12-08 20:27:39,649 | INFO  | Apollo : 1.0-SNAPSHOT (at: /home/apollo/apache-apollo-1.0-SNAPSHOT)
| console | hawtdispatch-DEFAULT-1
2011-12-08 20:27:39,650 | INFO  | OS is restricting the open file limit to: 5120 | console
| hawtdispatch-DEFAULT-1
2011-12-08 20:27:39,807 | DEBUG | Starting administration interface | org.apache.activemq.apollo.broker.jetty.JettyWebServer
| Apollo Task
2011-12-08 20:27:39,869 | INFO  | Starting store: bdb store at /home/apollo/my-broker-snap/data
| console | hawtdispatch-DEFAULT-2
2011-12-08 20:27:39,945 | INFO  | Accepting connections at: tls://0.0.0.0:62614 | console
| hawtdispatch-DEFAULT-1
2011-12-08 20:27:39,952 | INFO  | Accepting connections at: tcp://0.0.0.0:62613 | console
| hawtdispatch-DEFAULT-1
2011-12-08 20:27:41,303 | INFO  | Administration interface available at: https://127.0.0.1:62681/
| console | Apollo Task
2011-12-08 20:27:41,304 | INFO  | Administration interface available at: http://127.0.0.1:62680/
| console | Apollo Task
2011-12-08 20:28:57,035 | WARN  | returning command: StompFrame(CONNECT,List((login,my), (passcode,mypw),
(content-length,0), (content-type,text/plain; charset=UTF-8)),BufferContent({ offset: 89,
length: 0, data: "" }),List()) | org.apache.activemq.apollo.stomp.StompCodec | hawtdispatch-DEFAULT-2
2011-12-08 20:28:57,061 | WARN  | returning command: StompFrame(SUBSCRIBE,List((ack,client),
(destination,/queue/rtest.03), (content-length,0), (content-type,text/plain; charset=UTF-8)),BufferContent({
offset: 197, length: 0, data: "" }),List()) | org.apache.activemq.apollo.stomp.StompCodec
| hawtdispatch-DEFAULT-2
2011-12-08 20:28:57,076 | WARN  | returning command: StompFrame(SEND,List((current_time,2011-12-08
20:28:57 -0500), (destination,/queue/rtest.03), (content-length,16), (content-type,text/plain;
charset=UTF-8)),BufferContent({ offset: 329, length: 16, data: "a simple message" }),List())
| org.apache.activemq.apollo.stomp.StompCodec | hawtdispatch-DEFAULT-2
2011-12-08 20:28:57,133 | DEBUG | created queue: rtest.03 | org.apache.activemq.apollo.broker.Queue
| hawtdispatch-DEFAULT-1
2011-12-08 20:28:57,189 | DEBUG | producer route attaching to conusmer. | org.apache.activemq.apollo.broker.DeliveryProducerRoute
| hawtdispatch-DEFAULT-3
2011-12-08 20:28:57,267 | WARN  | returning command: StompFrame(ACK,List((message-id,my-broker-snap-1-1),
(content-length,0), (content-type,text/plain; charset=UTF-8)),BufferContent({ offset: 438,
length: 0, data: "" }),List()) | org.apache.activemq.apollo.stomp.StompCodec | hawtdispatch-DEFAULT-2
2011-12-08 20:28:57,270 | WARN  | returning command: StompFrame(UNSUBSCRIBE,List((destination,/queue/rtest.03),
(content-length,0), (content-type,text/plain; charset=UTF-8)),BufferContent({ offset: 537,
length: 0, data: "" }),List()) | org.apache.activemq.apollo.stomp.StompCodec | hawtdispatch-DEFAULT-2
2011-12-08 20:28:57,272 | WARN  | returning command: StompFrame(DISCONNECT,List((receipt,/queue/rtest.03
2011-12-08 20:28:57 -0500), (content-length,0), (content-type,text/plain; charset=UTF-8)),BufferContent({
offset: 657, length: 0, data: "" }),List()) | org.apache.activemq.apollo.stomp.StompCodec
| hawtdispatch-DEFAULT-2
2011-12-08 20:28:57,290 | WARN  | ACK Starts | org.apache.activemq.apollo.broker.Subscription
| hawtdispatch-DEFAULT-3
2011-12-08 20:28:57,292 | DEBUG | Internal protocol error: message delivery acked/nacked multiple
times: 1 | org.apache.activemq.apollo.broker.Subscription | hawtdispatch-DEFAULT-3
2011-12-08 20:28:57,317 | DEBUG | producer route detaching from conusmer. | org.apache.activemq.apollo.broker.DeliveryProducerRoute
| hawtdispatch-DEFAULT-1





                
> ACK followed by DISCONNECT Leaves Message Available
> ---------------------------------------------------
>
>                 Key: APLO-88
>                 URL: https://issues.apache.org/jira/browse/APLO-88
>             Project: ActiveMQ Apollo
>          Issue Type: Bug
>          Components: apollo-stomp
>         Environment: Linux, Ubuntu 11.04
>            Reporter: Guy Allard
>         Attachments: aplo-88-log.txt
>
>
> An ACK (client mode) followed by a DISCONNECT with no wait time between the frames appears
to leave message on the queue.
> I am seeing this with apache-apollo-1.0-20111012.032531-204-unix-distro.tar.gz and at
least one previous snapshot.
> I stumbled on to this while working on a new 1.1 client in go.  It occurs with either
a 1.0 or 1.1 connection.  The go code is very raw and not publicly available yet.
> However it recreates with 1.0 using the Ruby stomp gem.  Code to recreate:
> # ---------
> require 'rubygems'
> require 'stomp'
> #
> c = Stomp::Connection.open('my', 'mypw', 'localhost', 62613) # Apollo is here
> c.subscribe "/queue/rtest.01", :ack => :client
> c.publish "/queue/rtest.01", "a simple message"
> msg = c.receive
> c.ack msg.headers['message-id']
> # sleep 5
> c.disconnect
> # ---------
> And is (usually) accompanied by:
> 2011-10-13 22:56:00,041 | DEBUG | Internal protocol error: message delivery acked/nacked
multiple times: 1 | org.apache.activemq.apollo.broker.Subscription | hawtdispatch-DEFAULT-1
> in apollo.log
> Calling 'flush' on the socket seems to have no affect (in either Ruby or go).
> If you uncomment the 'sleep' in the above Ruby code, the problem will (usually) *not*
occur.
> I do get some slightly different results with the go test bed, but let's start with this
............

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

Mime
View raw message