You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@qpid.apache.org by Nitin Shah <ns...@btisystems.com> on 2014/04/03 22:50:32 UTC
RE: Qpid and Behavior on NTP time change
Gordon , Qpid team,
Can you explain what that means. We have the situation where , when the time gets changed and in this case forward , qpid invariably locks up and messages stop flowing. This mode of failure we see a lot off and it seems like there is no solution we have come across. We are gathering logs as I speak by turning on the verbose logs and can post those to you as soon as we have them. Your help in getting to the bottom of this will help us tremendously.
So the scenario is that the module that is running the QPID broker, its time is updated by the linux 'date' command and this time information is then sent to the other modules via QPID messages. As soon as the date change is applied on the other modules ( as a result of receiving the date change message and executing the linux 'date' command) , qpid seems to lock up and no more messages can be transferred. The time change is a jump and could be 15 minutes.
Let me know if I can provide any further information.
Thanks
Nitin
-----Original Message-----
From: Gordon Sim [mailto:gsim@redhat.com]
Sent: Friday, March 28, 2014 11:41 AM
To: dev@qpid.apache.org
Subject: Re: Qpid and Behavior on NTP time change
On 03/28/2014 02:50 PM, Nitin Shah wrote:
> When TIME changed thru the CLI on the module that is running the broker , a time Change time of a minute through CLI saw the following errors on primary Module ( running the broker ) but no errors on the other modules.
>
> 2014-03-27T10:38:34.919457-04:00 scm1 qpidd[28177]: 2014-03-27
> 10:38:34 [Protocol] error Connection
> qpid.172.16.0.4:5672-172.16.0.4:37806 timed out: closing
> 2014-03-27T10:38:34.928981-04:00 scm1 qpidd[28177]: 2014-03-27
> 10:38:34 [Protocol] error Connection
> qpid.172.16.0.4:5672-172.16.0.4:37807 timed out: closing
> 2014-03-27T10:38:34.929669-04:00 scm1 qpidd[28177]: 2014-03-27
> 10:38:34 [Protocol] error Connection
> qpid.172.16.0.4:5672-172.16.0.4:37810 timed out: closing
> 2014-03-27T10:38:34.930076-04:00 scm1 qpidd[28177]: 2014-03-27
> 10:38:34 [Protocol] error Connection
> qpid.172.16.0.4:5672-172.16.0.4:37808 timed out: closing
> 2014-03-27T10:38:34.930490-04:00 scm1 qpidd[28177]: 2014-03-27
> 10:38:34 [Protocol] error Connection
> qpid.172.16.0.4:5672-172.16.0.4:37809 timed out: closing
> 2014-03-27T10:38:34.930855-04:00 scm1 qpidd[28177]: 2014-03-27
> 10:38:34 [Protocol] error Connection
> qpid.172.16.0.4:5672-172.16.0.4:37811 timed out: closing
> 2014-03-27T10:38:34.931833-04:00 scm1 qpidd[28177]: 2014-03-27
> 10:38:34 [Protocol] error Connection
> qpid.172.16.0.4:5672-172.16.0.4:37812 timed out: closing
> 2014-03-27T10:38:34.932094-04:00 scm1 qpidd[28177]: 2014-03-27
> 10:38:34 [Protocol] error Connection
> qpid.172.16.0.4:5672-172.16.0.4:37813 timed out: closing
> 2014-03-27T10:38:34.932484-04:00 scm1 qpidd[28177]: 2014-03-27
> 10:38:34 [Protocol] error Connection
> qpid.172.16.0.4:5672-172.16.0.4:37814 timed out: closing
>
>
> Changed time by 10 minutes
> Saw the same errors as above on primary SCM ( the one running the
> broker )and saw following errors on payload modules
>
> 2014-03-27T10:40:54.413172-04:00 pld0103 TransceiverAgent[9469]:
> [1.E.Mbus]: qpid connection failed exception
> 2014-03-27T10:40:54.435011-04:00 pld0103 DigiAgentSim[9467]:
> [1.E.Mbus]: qpid connection failed exception
This is consistent with heartbeat failures.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org For additional commands, e-mail: dev-help@qpid.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org
RE: Qpid and Behavior on NTP time change
Posted by Nitin Shah <ns...@btisystems.com>.
Hi Gordon and Ted,
Thanks for your responses. Yesterday we tried experiments by turning OFF heartbeats and that had NO problems. I assume that Heartbeats are there to detect client failures ( like they die ). Is there a way to have heartbeats also enabled?
Nitin
______________________________
From: Gordon Sim [gsim@redhat.com]
Sent: Tuesday, April 08, 2014 4:50 AM
To: dev@qpid.apache.org
Subject: Re: Qpid and Behavior on NTP time change
On 04/03/2014 09:50 PM, Nitin Shah wrote:
> Gordon , Qpid team,
>
> Can you explain what that means.
Changing the time will confuse the broker (and the c++ client) in their
processing of heartbeats (since they use the time to determine when
heartbeats should be sent and when they should be expected).
As Andrew suggested earlier in the thread, you could try changing to use
a monotonic clock (by patching your local source). I believe there is a
JIRA open for this, and if you do pursue that route and want to attach a
patch and details of your experiments, that would speed up getting it
into a release.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org
Re: Qpid and Behavior on NTP time change
Posted by Gordon Sim <gs...@redhat.com>.
On 04/03/2014 09:50 PM, Nitin Shah wrote:
> Gordon , Qpid team,
>
> Can you explain what that means.
Changing the time will confuse the broker (and the c++ client) in their
processing of heartbeats (since they use the time to determine when
heartbeats should be sent and when they should be expected).
As Andrew suggested earlier in the thread, you could try changing to use
a monotonic clock (by patching your local source). I believe there is a
JIRA open for this, and if you do pursue that route and want to attach a
patch and details of your experiments, that would speed up getting it
into a release.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org
Re: Qpid and Behavior on NTP time change
Posted by Ted Ross <tr...@redhat.com>.
Nitin,
What I think Gordon was pointing out is that your log suggests that when
the time was changed, your broker connections immediately timed-out as
though they had not seen heartbeats for a long time.
As an experiment, can you try running without heartbeats (or a very long
heartbeat interval) to see if you have the same problem?
You say the system "locks up". Can you be very specific about what is
actually happening? Can you use the "qpid-stat" tool on the broker
system to monitor the broker's operation? The -c option shows active
connections, -q shows queues and their counters. Both should shed some
light on what is causing the perceived lock-up.
-Ted
On 04/03/2014 04:50 PM, Nitin Shah wrote:
> Gordon , Qpid team,
>
> Can you explain what that means. We have the situation where , when the time gets changed and in this case forward , qpid invariably locks up and messages stop flowing. This mode of failure we see a lot off and it seems like there is no solution we have come across. We are gathering logs as I speak by turning on the verbose logs and can post those to you as soon as we have them. Your help in getting to the bottom of this will help us tremendously.
>
> So the scenario is that the module that is running the QPID broker, its time is updated by the linux 'date' command and this time information is then sent to the other modules via QPID messages. As soon as the date change is applied on the other modules ( as a result of receiving the date change message and executing the linux 'date' command) , qpid seems to lock up and no more messages can be transferred. The time change is a jump and could be 15 minutes.
>
> Let me know if I can provide any further information.
>
> Thanks
>
> Nitin
>
> -----Original Message-----
> From: Gordon Sim [mailto:gsim@redhat.com]
> Sent: Friday, March 28, 2014 11:41 AM
> To: dev@qpid.apache.org
> Subject: Re: Qpid and Behavior on NTP time change
>
> On 03/28/2014 02:50 PM, Nitin Shah wrote:
>> When TIME changed thru the CLI on the module that is running the broker , a time Change time of a minute through CLI saw the following errors on primary Module ( running the broker ) but no errors on the other modules.
>>
>> 2014-03-27T10:38:34.919457-04:00 scm1 qpidd[28177]: 2014-03-27
>> 10:38:34 [Protocol] error Connection
>> qpid.172.16.0.4:5672-172.16.0.4:37806 timed out: closing
>> 2014-03-27T10:38:34.928981-04:00 scm1 qpidd[28177]: 2014-03-27
>> 10:38:34 [Protocol] error Connection
>> qpid.172.16.0.4:5672-172.16.0.4:37807 timed out: closing
>> 2014-03-27T10:38:34.929669-04:00 scm1 qpidd[28177]: 2014-03-27
>> 10:38:34 [Protocol] error Connection
>> qpid.172.16.0.4:5672-172.16.0.4:37810 timed out: closing
>> 2014-03-27T10:38:34.930076-04:00 scm1 qpidd[28177]: 2014-03-27
>> 10:38:34 [Protocol] error Connection
>> qpid.172.16.0.4:5672-172.16.0.4:37808 timed out: closing
>> 2014-03-27T10:38:34.930490-04:00 scm1 qpidd[28177]: 2014-03-27
>> 10:38:34 [Protocol] error Connection
>> qpid.172.16.0.4:5672-172.16.0.4:37809 timed out: closing
>> 2014-03-27T10:38:34.930855-04:00 scm1 qpidd[28177]: 2014-03-27
>> 10:38:34 [Protocol] error Connection
>> qpid.172.16.0.4:5672-172.16.0.4:37811 timed out: closing
>> 2014-03-27T10:38:34.931833-04:00 scm1 qpidd[28177]: 2014-03-27
>> 10:38:34 [Protocol] error Connection
>> qpid.172.16.0.4:5672-172.16.0.4:37812 timed out: closing
>> 2014-03-27T10:38:34.932094-04:00 scm1 qpidd[28177]: 2014-03-27
>> 10:38:34 [Protocol] error Connection
>> qpid.172.16.0.4:5672-172.16.0.4:37813 timed out: closing
>> 2014-03-27T10:38:34.932484-04:00 scm1 qpidd[28177]: 2014-03-27
>> 10:38:34 [Protocol] error Connection
>> qpid.172.16.0.4:5672-172.16.0.4:37814 timed out: closing
>>
>>
>> Changed time by 10 minutes
>> Saw the same errors as above on primary SCM ( the one running the
>> broker )and saw following errors on payload modules
>>
>> 2014-03-27T10:40:54.413172-04:00 pld0103 TransceiverAgent[9469]:
>> [1.E.Mbus]: qpid connection failed exception
>> 2014-03-27T10:40:54.435011-04:00 pld0103 DigiAgentSim[9467]:
>> [1.E.Mbus]: qpid connection failed exception
> This is consistent with heartbeat failures.
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org For additional commands, e-mail: dev-help@qpid.apache.org
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
> For additional commands, e-mail: dev-help@qpid.apache.org
>
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org