Many thanks for the update Pavel, I've been tied up on a bunch of
(non-Qpid) things so haven't got round to reproducing it myself, but I
was suspecting a bug given that the Session close() at least *looked*
like it was attempting to sync from an initial visual inspection of the
code.
Out of curiosity in the code you had below did removing the log message
make a difference i.e. cause the issue?
Frase.
On 14/05/13 12:12, Pavel Moravec wrote:
Hi Fraser,
I got the error, it is coincidentally a bug I already filed:
https://issues.apache.org/jira/browse/QPID-4524.
(if one comments out in the reproducer the second "producer.send(..)" call, you
get precisely what you reported)
I already updated the JIRA per some finding (yours and mine).
Kind regards,
Pavel
----- Original Message -----
From: "Fraser Adams" <[email protected]>
To: [email protected]
Sent: Tuesday, May 7, 2013 7:39:37 PM
Subject: Re: Exception when calling close - Java client/C++ broker.
Hi Pavel,
Thanks for having a go reproducing this, I'm afraid that the detail is a
bit second hand, but the issue was specifically with pretty big message
size with a persistent queue using the c++ broker.
In particular my colleague said that it only started becoming weird at a
message size of 1MB (1024*1024) with (1024*1024 - 1) the issue didn't
appear.
Skimming through your code (and without a copy of my colleagues code
handy) the only difference I can guess at is that he's likely to have done:
byte[] data = new byte[1024*1024];
msg.writeBytes(data);
to try this out - shouldn't make any odds though, you did try 1MB as
msgSize??
I think he also explicitly closed the producer and session before the
connection, again it shouldn't make any odds I think the main point is
that it's in the middle of trying to persist a large durable message
when close gets called.
One other thing, in my post I said that "He tried using sync_publish but
reckons that didn't help" well he got back to me today and said that
this *does* actually work - he was setting it in the brokerList
initially when he moved it to the main URL it worked, as did setting it
as a JVM property.
He's pretty adamant that he is seeing this behaviour and I've no reason
to doubt him, but as it only happens when 1MB is reached and only for
persistent messages I think its a race condition between the persistence
and the close and as I say below it's weird that it's exactly 1024*1024
where it starts happening so I'm thinking there's a cache/buffer beyond
which disk sync/flush is occurring that taking more time. I guess that
if your machine is a different spec it might affect reproducibility??!!??
Thinking about it have you tried it *without* the logging between send()
and close()?? It's just possible that the logging takes just enough time
to make it work OK - my colleague tried a short sleep call and that
fixed the problem too.
I've also asked him to try down-casting Session to AMQSession and
calling sync() on that to see if it makes any difference and also to try
a transacted session (which should call sync() when commit() is called).
Looking through the implementation methods though it looks like Session
close() is calling an underlying sync method, but there's some guard
code around it so it's possible that it's not actually being called in
some circumstances.
Not syncing seems the most likely 'cause especially given that
sync_publish does appear to work and I'd bet his python example also
calls sync() JMS obviously doesn't have an explicit sync() call hence
the other thoughts above.
Thanks again for having a go reproducing it. When I get a moment I'll
have a go at reproducing it myself, though I'll need to build the
persistence module 'cause I never use it myself.
Frase
On 07/05/13 11:58, Pavel Moravec wrote:
Hi Fraser,
I tried to reproduce it but havent succeeded. Having following code
snippet:
Properties properties = new Properties();
properties.setProperty("java.naming.factory.initial",
"org.apache.qpid.jndi.PropertiesFileInitialContextFactory");
properties.setProperty("connectionfactory." +
"qpidConnectionfactory",
"amqp://guest:guest@clientid/test?brokerlist='tcp://localhost:5672?sasl_mechs='PLAIN''");
Context ctx = new InitialContext(properties);
ConnectionFactory conFac = (ConnectionFactory)
ctx.lookup("qpidConnectionfactory");
Connection connection = conFac.createConnection("guest", "guest");
Destination destination = new AMQAnyDestination(address);
Session session = connection.createSession(false,
Session.AUTO_ACKNOWLEDGE);
BytesMessage msg = session.createBytesMessage();
for (int i=0; i<msgSize; i++)
msg.writeChar('A');
MessageProducer prod = session.createProducer(destination);
log.info("Before send");
prod.send(msg);
log.info("After send");
connection.close();
log.info("After close");
and running it for various msgSize, I saw no exception being raised :-/
I guess there have to be something more (configuration-specific)..
Kind regards,
Pavel
----- Original Message -----
From: "Fraser Adams" <[email protected]>
To: [email protected]
Sent: Friday, May 3, 2013 9:17:05 AM
Subject: Exception when calling close - Java client/C++ broker.
Hi all,
A colleague of mine mailed me the other day with some behaviour I hadn't
come across before.
in précis he was messing about with a Java client and C++ broker (Qpid
0.18 I believe but I doubt that's relevant here).
The client was very simple: create Connection, create Session, create
MessageProducer, create ByteMessage, send message, close Connection.
What was interesting was when the message got larger.
So he sent to a persistent queue and when the message hit 1MB
(1024*1024) he got an Exception when closing. Interestingly when he
tried with a message just one octet less (1024*1024 - 1) the Exception
didn't occur.
I can't recall the exact Exception he mentioned unfortunately, but it
related to not closing cleanly.
The message did actually end up on the queue, and if he loops with
several messages all messages get sent and the issue is clearly caused
at the end during the call to close.
My response to him was that I suspected that it related to the default
behaviour of Qpid, which is to use asynchronous delivery for efficiency,
which kind of "bends" the JMS spec a little (IIRC send should block
until a broker has taken responsibility for the message and close should
block until the pending message has been delivered).
The hitting 1MB was weird, but I reckoned that it related to caching
behaviour, so below 1MB the broker has the message in cache/buffers and
the flush/sync to actual disk doesn't immediately occur, so the acks go
back to the client pretty much instantly thus close is happy, but when
it hits 1MB a disk flush occurs which hits real disk and takes longer
thus triggering the Exception due to closing while the transfer is in
progress. I might be wrong, but it feels plausible and definitely felt
like a race condition between persisting the message and closing the
connection.
What I'm not clear on is how to make such a scenario behave cleanly. I
did suggest that if he was really sending one message and closing
immediately then it might make sense to force synchronous behaviour. He
tried using sync_publish but reckons that didn't help, which surprised me.
Of course adding a delay between calling send and close makes it behave
properly, but that feels like a cop-out solution for what is clearly a
race condition.
Can anyone suggest the "correct" solution for the case where you really
want to send a (big durable) message and immediately close the connection?
One other thing, my colleague mentioned that he'd tried the same
scenario with a python client and he said that it didn't behave like this.
thoughts?
MTIA,
Frase
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
