You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@qpid.apache.org by Ivo Wever <we...@axini.com> on 2020/07/01 14:31:28 UTC
Figuring out the reason for a delay before a message is sent
Hi,
I have a setup that results in the following wire messages being sent
(recorded using wireshark), where the first column is a timestamp, the
second a direction and third one or more wire frames:
0.00 > Protocol-Header 1-0-0 open begin attach attach
0.68 < Protocol-Header 1-0-0 open begin attach attach flow
0.68 > flow transfer
0.70 < flow disposition
0.70 < transfer
0.70 > flow
8.21 > transfer
8.23 < flow disposition
8.23 < transfer
What I am trying to figure out is why there is a delay between the
transfer that is received at 0.70 and the transfer that is sent at 8.21,
because the 'sender.send(payload)' was called very shortly after 0.70.
After the initial quick back-and-forth, it seems to consistently take
~7.5 seconds before a 'sender.send(payload)' results in an actual
transfer (you can consider the above sequence as extending further with
the same pattern if that). That is also the moment at which an
'on_sendable' is triggered on the handler.
This is using the Ruby version of Qpid Proton 0.30.0. The disposition
messages are all 'accepts', the flow messages all indicate more messages
are welcome. What could be going on here? It's not the sending process
is busy: it's looping over a 200ms sleep while waiting for the response
to arrive (though as it happens it's actually mostly waiting for the
request to be sent, after which the response promptly arrives)
Does anyone have a clue for what may be going on here?
best regards,
--
Ivo
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@qpid.apache.org
For additional commands, e-mail: users-help@qpid.apache.org
Re: Figuring out the reason for a delay before a message is sent
Posted by Andrew Stitcher <as...@apache.org>.
On Wed, 2020-07-08 at 08:32 +0200, Ivo Wever wrote:
> ...
> I figured it out via the C++ examples and documentation; the Ruby
> examples miss an example for this and there is not yet a version of
> the
> general documentation for Ruby. So if you're using the Ruby client,
> it's
> advisable to also closely look at the C++ (or perhaps Python; haven't
> checked that closely) documentation.
The ruby bindings are lightly maintained currently, as the core team
currently has no one with strong ruby skills and we seem to have no
major users actively using this binding. So any contibutaions you can
make will be welcomed!
Of course the lack of core team expertise will unfortunately make it
take a little longer initially for someone to look at any suggested
patches or PRs.
Regards
Andrew
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@qpid.apache.org
For additional commands, e-mail: users-help@qpid.apache.org
Re: Figuring out the reason for a delay before a message is sent
Posted by Ivo Wever <we...@axini.com>.
On 7/1/20 9:10 PM, Gordon Sim wrote:
> On 01/07/2020 3:31 pm, Ivo Wever wrote:
>> Hi,
>>
>> I have a setup that results in the following wire messages being sent
>> (recorded using wireshark), where the first column is a timestamp, the
>> second a direction and third one or more wire frames:
>>
>> 0.00 > Protocol-Header 1-0-0 open begin attach attach
>> 0.68 < Protocol-Header 1-0-0 open begin attach attach flow
>> 0.68 > flow transfer
>> 0.70 < flow disposition
>> 0.70 < transfer
>> 0.70 > flow
>> 8.21 > transfer
>> 8.23 < flow disposition
>> 8.23 < transfer
>>
>> What I am trying to figure out is why there is a delay between the
>> transfer that is received at 0.70 and the transfer that is sent at 8.21,
>> because the 'sender.send(payload)' was called very shortly after 0.70.
>>
>> After the initial quick back-and-forth, it seems to consistently take
>> ~7.5 seconds before a 'sender.send(payload)' results in an actual
>> transfer (you can consider the above sequence as extending further with
>> the same pattern if that). That is also the moment at which an
>> 'on_sendable' is triggered on the handler.
>>
>> This is using the Ruby version of Qpid Proton 0.30.0. The disposition
>> messages are all 'accepts', the flow messages all indicate more messages
>> are welcome. What could be going on here? It's not the sending process
>> is busy: it's looping over a 200ms sleep while waiting for the response
>> to arrive (though as it happens it's actually mostly waiting for the
>> request to be sent, after which the response promptly arrives)
>>
>> Does anyone have a clue for what may be going on here?
>
> I don't know anything about the ruby binding specifically, but it is an
> event driven, single threaded api. If you are doing any sleep in a
> proton callback you are preventing the event thread from performing any
> work.
>
> (You could try the simple_send.rb example to make sure there isn't
> something generically strange going on).
>
Hi,
I've since figured out the problem: all the Ruby examples send messages
from within the Proton thread, but I am handling incoming messages
outside of it and need to use
connection.work_queue.add do
sender.send(payload)
end
to 'notify' the Proton thread that I would like it to send a message.
The original 7.5 second timeout resulted from a 15000 ms idle-timeout
set by my peer, which Proton halves and uses as an (upper limit) timeout
for a blocking call to a 'select' over sockets. Adding something to the
work queue causes the select to return and the container loop to
proceed. If you don't, it will only proceed after the timeout.
I accidentally first only replied with this to Gordon, who confirmed:
> Proton is in general a single threaded api. You should only invoke
> most methods on a connection from the thread that is handling the io
> for the connection.
I figured it out via the C++ examples and documentation; the Ruby
examples miss an example for this and there is not yet a version of the
general documentation for Ruby. So if you're using the Ruby client, it's
advisable to also closely look at the C++ (or perhaps Python; haven't
checked that closely) documentation.
best regards,
--
Ivo
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@qpid.apache.org
For additional commands, e-mail: users-help@qpid.apache.org
Re: Figuring out the reason for a delay before a message is sent
Posted by Gordon Sim <gs...@redhat.com>.
On 01/07/2020 3:31 pm, Ivo Wever wrote:
> Hi,
>
> I have a setup that results in the following wire messages being sent
> (recorded using wireshark), where the first column is a timestamp, the
> second a direction and third one or more wire frames:
>
> 0.00 > Protocol-Header 1-0-0 open begin attach attach
> 0.68 < Protocol-Header 1-0-0 open begin attach attach flow
> 0.68 > flow transfer
> 0.70 < flow disposition
> 0.70 < transfer
> 0.70 > flow
> 8.21 > transfer
> 8.23 < flow disposition
> 8.23 < transfer
>
> What I am trying to figure out is why there is a delay between the
> transfer that is received at 0.70 and the transfer that is sent at 8.21,
> because the 'sender.send(payload)' was called very shortly after 0.70.
>
> After the initial quick back-and-forth, it seems to consistently take
> ~7.5 seconds before a 'sender.send(payload)' results in an actual
> transfer (you can consider the above sequence as extending further with
> the same pattern if that). That is also the moment at which an
> 'on_sendable' is triggered on the handler.
>
> This is using the Ruby version of Qpid Proton 0.30.0. The disposition
> messages are all 'accepts', the flow messages all indicate more messages
> are welcome. What could be going on here? It's not the sending process
> is busy: it's looping over a 200ms sleep while waiting for the response
> to arrive (though as it happens it's actually mostly waiting for the
> request to be sent, after which the response promptly arrives)
>
> Does anyone have a clue for what may be going on here?
I don't know anything about the ruby binding specifically, but it is an
event driven, single threaded api. If you are doing any sleep in a
proton callback you are preventing the event thread from performing any
work.
(You could try the simple_send.rb example to make sure there isn't
something generically strange going on).
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@qpid.apache.org
For additional commands, e-mail: users-help@qpid.apache.org