On Wed, 2007-09-19 at 11:29 +0100, Gordon Sim wrote:
> Alan Conway wrote:
> On another note there are actually two flushes sent in this test per
> publish. As the channel is in synchronous mode the peer sends one itself
> (should be a synch now, that wasn't implemented when this was started).
> The explicit flush is no no longer necessary. However thats not the
> cause of the failure I don't think.
Aha, those are the extra flushes I was seeing. Well that means I don't
have a clue what's going on...
> I can't actually reproduce the issue... If you have a broker log I can
> have a look at it.
I get it semi-reliably on amd-32:/home/aconway/svn/qpid with:
while make check TESTS="start_broker python_tests stop_broker"
PYTHON_TESTS=tests_0-10.execution QPID_TRACE=1; do true; done
Perpahs
Success and fail logs attached. I modified execution.py to put the loop
index in the routing key for a more readable log, just comitted that
modification now.
Thanks,
Alan.
2007-Sep-18 17:38:18 debug Forked daemon child process
2007-Sep-18 17:38:19 info Persistence not enabled, no recovery attempted.
2007-Sep-18 17:38:19 info Listening on port -19829
2007-Sep-18 17:38:19 debug Daemon ready on port: 45707
2007-Sep-18 17:38:21 debug INIT [0x5c47008]
2007-Sep-18 17:38:21 debug SENT: Frame[channel=0; ConnectionStartBody: version-major=0; version-minor=10; server-properties={}; mechanisms=PLAIN; locales=en_US]
2007-Sep-18 17:38:21 debug RECV: Frame[channel=0; ConnectionStartOkBody: client-properties={}; mechanism=AMQPLAIN; response=LOGINS guestPASSWORDS guest; locale=en_US]
2007-Sep-18 17:38:21 debug SENT: Frame[channel=0; ConnectionTuneBody: channel-max=32767; frame-max=65536; heartbeat=0]
2007-Sep-18 17:38:21 debug RECV: Frame[channel=0; ConnectionTuneOkBody: channel-max=32767; frame-max=65536; heartbeat=0]
2007-Sep-18 17:38:21 debug RECV: Frame[channel=0; ConnectionOpenBody: virtual-host=/; capabilities=; insist=0]
2007-Sep-18 17:38:21 debug SENT: Frame[channel=0; ConnectionOpenOkBody: known-hosts=]
2007-Sep-18 17:38:21 debug RECV: Frame[channel=1; ChannelOpenBody: out-of-band=]
2007-Sep-18 17:38:22 debug SENT: Frame[channel=1; ChannelOpenOkBody: ]
2007-Sep-18 17:38:22 debug RECV: Frame[channel=1; BasicPublishBody: ticket=0; exchange=; routing-key=; reject-unroutable=0; immediate=0]
2007-Sep-18 17:38:22 debug RECV: Frame[channel=1; header (67 bytes); properties={DeliveryProperties: discard-unroutable=0; redelivered=0; priority=0; delivery-mode=0; ttl=0; timestamp=0; expiration=0; exchange=; routing-key=MessageProperties: content-length=0; message-id=; correlation-id=; reply-to=ReplyTo: exchange-name=; routing-key=; content-type=; content-encoding=; type=; user-id=; app-id=; transaction-id=; security-token=; application-headers={}}]
2007-Sep-18 17:38:22 warning DirectExchange could not route message with key
2007-Sep-18 17:38:22 debug RECV: Frame[channel=1; ExecutionFlushBody: ]
2007-Sep-18 17:38:22 debug SENT: Frame[channel=1; ExecutionCompleteBody: cumulative-execution-mark=1; ranged-execution-set={}]
2007-Sep-18 17:38:23 debug RECV: Frame[channel=1; ExecutionFlushBody: ]
2007-Sep-18 17:38:23 debug SENT: Frame[channel=1; ExecutionCompleteBody: cumulative-execution-mark=1; ranged-execution-set={}]
2007-Sep-18 17:38:23 debug RECV: Frame[channel=1; BasicPublishBody: ticket=0; exchange=; routing-key=; reject-unroutable=0; immediate=0]
2007-Sep-18 17:38:23 debug RECV: Frame[channel=1; header (67 bytes); properties={DeliveryProperties: discard-unroutable=0; redelivered=0; priority=0; delivery-mode=0; ttl=0; timestamp=0; expiration=0; exchange=; routing-key=MessageProperties: content-length=0; message-id=; correlation-id=; reply-to=ReplyTo: exchange-name=; routing-key=; content-type=; content-encoding=; type=; user-id=; app-id=; transaction-id=; security-token=; application-headers={}}]
2007-Sep-18 17:38:23 warning DirectExchange could not route message with key
2007-Sep-18 17:38:23 debug RECV: Frame[channel=1; ExecutionFlushBody: ]
2007-Sep-18 17:38:23 debug SENT: Frame[channel=1; ExecutionCompleteBody: cumulative-execution-mark=2; ranged-execution-set={}]
2007-Sep-18 17:38:23 debug RECV: Frame[channel=0; ConnectionCloseBody: reply-code=200; reply-text=; class-id=0; method-id=0]
2007-Sep-18 17:38:23 debug SENT: Frame[channel=0; ConnectionCloseOkBody: ]
2007-Sep-18 17:38:23 notice Shutting down on signal 2
2007-Sep-18 17:46:24 debug Forked daemon child process
2007-Sep-18 17:46:24 info Persistence not enabled, no recovery attempted.
2007-Sep-18 17:46:24 info Listening on port -8771
2007-Sep-18 17:46:24 debug Daemon ready on port: 56765
2007-Sep-18 17:46:25 debug INIT [0x10f8de0]
2007-Sep-18 17:46:25 debug SENT: Frame[channel=0; ConnectionStartBody: version-major=0; version-minor=10; server-properties={}; mechanisms=PLAIN; locales=en_US]
2007-Sep-18 17:46:25 debug RECV: Frame[channel=0; ConnectionStartOkBody: client-properties={}; mechanism=AMQPLAIN; response=LOGINS guestPASSWORDS guest; locale=en_US]
2007-Sep-18 17:46:25 debug SENT: Frame[channel=0; ConnectionTuneBody: channel-max=32767; frame-max=65536; heartbeat=0]
2007-Sep-18 17:46:25 debug RECV: Frame[channel=0; ConnectionTuneOkBody: channel-max=32767; frame-max=65536; heartbeat=0]
2007-Sep-18 17:46:25 debug RECV: Frame[channel=0; ConnectionOpenBody: virtual-host=/; capabilities=; insist=0]
2007-Sep-18 17:46:25 debug SENT: Frame[channel=0; ConnectionOpenOkBody: known-hosts=]
2007-Sep-18 17:46:25 debug RECV: Frame[channel=1; ChannelOpenBody: out-of-band=]
2007-Sep-18 17:46:25 debug SENT: Frame[channel=1; ChannelOpenOkBody: ]
2007-Sep-18 17:46:25 debug RECV: Frame[channel=1; BasicPublishBody: ticket=0; exchange=; routing-key=; reject-unroutable=0; immediate=0]
2007-Sep-18 17:46:25 debug RECV: Frame[channel=1; header (67 bytes); properties={DeliveryProperties: discard-unroutable=0; redelivered=0; priority=0; delivery-mode=0; ttl=0; timestamp=0; expiration=0; exchange=; routing-key=MessageProperties: content-length=0; message-id=; correlation-id=; reply-to=ReplyTo: exchange-name=; routing-key=; content-type=; content-encoding=; type=; user-id=; app-id=; transaction-id=; security-token=; application-headers={}}]
2007-Sep-18 17:46:25 warning DirectExchange could not route message with key
2007-Sep-18 17:46:25 debug RECV: Frame[channel=1; ExecutionFlushBody: ]
2007-Sep-18 17:46:25 debug SENT: Frame[channel=1; ExecutionCompleteBody: cumulative-execution-mark=1; ranged-execution-set={}]
2007-Sep-18 17:46:26 debug RECV: Frame[channel=1; ExecutionFlushBody: ]
2007-Sep-18 17:46:26 debug RECV: Frame[channel=1; BasicPublishBody: ticket=0; exchange=; routing-key=; reject-unroutable=0; immediate=0]
2007-Sep-18 17:46:26 debug RECV: Frame[channel=1; header (67 bytes); properties={DeliveryProperties: discard-unroutable=0; redelivered=0; priority=0; delivery-mode=0; ttl=0; timestamp=0; expiration=0; exchange=; routing-key=MessageProperties: content-length=0; message-id=; correlation-id=; reply-to=ReplyTo: exchange-name=; routing-key=; content-type=; content-encoding=; type=; user-id=; app-id=; transaction-id=; security-token=; application-headers={}}]
2007-Sep-18 17:46:26 warning DirectExchange could not route message with key
2007-Sep-18 17:46:26 debug RECV: Frame[channel=1; ExecutionFlushBody: ]
2007-Sep-18 17:46:26 debug SENT: Frame[channel=1; ExecutionCompleteBody: cumulative-execution-mark=1; ranged-execution-set={}]
2007-Sep-18 17:46:26 debug SENT: Frame[channel=1; ExecutionCompleteBody: cumulative-execution-mark=2; ranged-execution-set={}]
2007-Sep-18 17:46:26 debug RECV: Frame[channel=1; ExecutionFlushBody: ]
2007-Sep-18 17:46:26 debug RECV: Frame[channel=1; BasicPublishBody: ticket=0; exchange=; routing-key=; reject-unroutable=0; immediate=0]
2007-Sep-18 17:46:26 debug RECV: Frame[channel=1; header (67 bytes); properties={DeliveryProperties: discard-unroutable=0; redelivered=0; priority=0; delivery-mode=0; ttl=0; timestamp=0; expiration=0; exchange=; routing-key=MessageProperties: content-length=0; message-id=; correlation-id=; reply-to=ReplyTo: exchange-name=; routing-key=; content-type=; content-encoding=; type=; user-id=; app-id=; transaction-id=; security-token=; application-headers={}}]
2007-Sep-18 17:46:26 warning DirectExchange could not route message with key
2007-Sep-18 17:46:26 debug RECV: Frame[channel=1; ExecutionFlushBody: ]
2007-Sep-18 17:46:26 debug SENT: Frame[channel=1; ExecutionCompleteBody: cumulative-execution-mark=2; ranged-execution-set={}]
2007-Sep-18 17:46:26 debug SENT: Frame[channel=1; ExecutionCompleteBody: cumulative-execution-mark=3; ranged-execution-set={}]
2007-Sep-18 17:46:26 debug RECV: Frame[channel=1; ExecutionFlushBody: ]
2007-Sep-18 17:46:26 debug RECV: Frame[channel=0; ConnectionCloseBody: reply-code=200; reply-text=; class-id=0; method-id=0]
2007-Sep-18 17:46:26 debug SENT: Frame[channel=1; ExecutionCompleteBody: cumulative-execution-mark=3; ranged-execution-set={}]
2007-Sep-18 17:46:26 debug SENT: Frame[channel=0; ConnectionCloseOkBody: ]
2007-Sep-18 17:46:26 notice Shutting down on signal 2
