You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@qpid.apache.org by Sami Siitonen <sa...@fi.abb.com> on 2018/11/15 10:44:33 UTC
Changing system time causes J-Broker to drop connections
Hello,
I've setup J-Broker version 6.1.4 on Windows 10 platform using OpenJDK version 9.0.0.1-ojdkbuildea and using RabbitMQ-client version 4.1.3 from .Net. The problem is very similar to this bug description in the C++-broker: https://bugzilla.redhat.com/show_bug.cgi?id=1080165 The broker drops all connections every time when system time is changed (for example daylight saving time changes, running broker in virtual machine and suspending/resuming it etc). It can be repeated by changing system time more than timeout limit. It seems like walltime is used instead of monotonic time where calculating timeouts are performed.
I' ve managed to workaround this by disabling heartbeating in the client side but obviously this is not a proper solution. I couldn't find any bug report about this problem at J-Broker so I'm asking that if this is some configuration problem or problem with JDK or is this bug in J-Broker. I also tried to upgrade the broker to version 7.0.6 and RabbitMQ to 5.1.0 with no effect.
Cheers,
Sami
Re: Changing system time causes J-Broker to drop connections
Posted by Rob Godfrey <ro...@gmail.com>.
On Fri, 23 Nov 2018 at 14:01, Sami Siitonen <sa...@fi.abb.com>
wrote:
> Hi,
>
> Sorry about the DST, I didn't verify that part of the problem myself when I
> got this thing to solve and included it as a (bad) example so it probably
> doesn't cause any erratic behaviour in J-Broker.
>
Yeah - sorry that's the part I picked up upon... the actual report
"Changing system time causes [...] drop[ped] connections" is entirely
accurate...
I think it's just a bit use-case dependent as to whether this is a bug or
"feature" (e.g. if you paused a VM for 5 seconds and then resumed it, then
using wall-clock time would mean that the next heartbeat would be more
likely to be sent at the correct time (to a client on a different machine),
whereas system time may cause a client to assume the broker is dead and
disconnect because the broker waited an extra 5 seconds to send a
heartbeat).
> My problem more specifically manifests itself in a server pair where time
> (among other things) is synced between these two servers. The network
> connection between those servers might be down for a long time and time
> might jump back or forth more than the value of timeout at the moment when
> connection is re-established or at least we should take that into account
> by
> some other way than setting timeout value to some arbitrary big number. The
> broker and clients runs only locally in both servers, luckily no
> communication between servers.
> Basically I cannot guarantee that the system time will not jump around
> because of these syncs, it might even jump back to past.
> It sounds an interesting solution if walltime is used to determine if a
> timeout occurred or not because knowledge of the absolute time should be
> irrelevant, only difference between two events should matter. This kind of
> behavior was considered as a bug in C++ QPID and resolved couple of years
> ago:
> https://bugzilla.redhat.com/show_bug.cgi?id=1080165
>
>
Yeah - again it very much depends on the use case. In your use case I can
see that this is "buggy" behaviour.
> So you mentioned that switch to System.nanoTime is planned. In the
> meanwhile
> is there any better way to work this around than disabling heartbeating
> altogether?
>
>
Not really. Honestly, I find the value of heartbeating somewhat dubious,
especially if client and broker are on the same machine. At that point the
only error condition you are catching is that the client (or broker) has
got stuck in some condition where it is "hung" but has not closed the TCP
connection.
I'll look at doing a change to moving to nanoTime, but it's the sort of
think that is likely to generate subtle bugs (point in time millis since
epoch, point in time nanos, and elapsed millis will all use "long" as the
datatype, so there's a higher chance of messing something up).
-- Rob
> --
> Sami
>
>
>
>
> --
> Sent from:
> http://qpid.2158936.n2.nabble.com/Apache-Qpid-users-f2158936.html
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@qpid.apache.org
> For additional commands, e-mail: users-help@qpid.apache.org
>
>
Re: Changing system time causes J-Broker to drop connections
Posted by Sami Siitonen <sa...@fi.abb.com>.
Hi,
Sorry about the DST, I didn't verify that part of the problem myself when I
got this thing to solve and included it as a (bad) example so it probably
doesn't cause any erratic behaviour in J-Broker.
My problem more specifically manifests itself in a server pair where time
(among other things) is synced between these two servers. The network
connection between those servers might be down for a long time and time
might jump back or forth more than the value of timeout at the moment when
connection is re-established or at least we should take that into account by
some other way than setting timeout value to some arbitrary big number. The
broker and clients runs only locally in both servers, luckily no
communication between servers.
Basically I cannot guarantee that the system time will not jump around
because of these syncs, it might even jump back to past.
It sounds an interesting solution if walltime is used to determine if a
timeout occurred or not because knowledge of the absolute time should be
irrelevant, only difference between two events should matter. This kind of
behavior was considered as a bug in C++ QPID and resolved couple of years
ago:
https://bugzilla.redhat.com/show_bug.cgi?id=1080165
So you mentioned that switch to System.nanoTime is planned. In the meanwhile
is there any better way to work this around than disabling heartbeating
altogether?
--
Sami
--
Sent from: http://qpid.2158936.n2.nabble.com/Apache-Qpid-users-f2158936.html
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@qpid.apache.org
For additional commands, e-mail: users-help@qpid.apache.org
Re: Changing system time causes J-Broker to drop connections
Posted by Rob Godfrey <ro...@gmail.com>.
The connection timeouts are defined by the AMQP protocol and, since in
general the two ends of the connection would be on different machines,
implicitly refer to externally observable time (to the extent that such a
concept is meaningful).
You are changing the literal system time in your system, not just having it
update for daylight saving. Daylight saving does not change "number of
elapsed milliseconds since the epoch". Unless your system is suffering
really dreadful drift, regular updates via NTP will not adversely affect
the timeout processing, as the magnitude of any NTP updates should be small
(and connection timeout thresholds should be (relatively) large - certainly
in the order of multiple seconds, not milliseconds).
Admittedly there is a case to be made to switch to System.nanoTime since it
wouldn't be affected by updates to the system time, but then if the updates
are being done by NTP, and your system is so poor at accurate time
measuring that that is making significant updates, it is probably breaking
the AMQP contract for timeouts to use the inaccurate timekeeping of your
machine. Changing the system time is effectively changing "reality" and
I'm not sure that there is a right or wrong approach here - if you see a
lot of drift and significant updates from NTP I'd just use longer
connection timeouts, or turn them off completely if you want to suspend VMs.
If the broker were dropping connections due to daylight saving times
changes that would definitely be a bug - and I'm pretty confident that on a
correctly set up machine it won't happen... dropping due to changing the
system time is much less clear to me
-- Rob
On Fri, 23 Nov 2018 at 10:32, Sami Siitonen <sa...@fi.abb.com>
wrote:
> I verified that system.currentTimeMillis returns walltime instead of
> monotonic time so it cannot be used to calculate timeouts.
> The problem here concerns every situation where walltime has shifted
> somehow
> and adjusted back, for example when system clock is somehow drifted enough
> and NTP is used to adjust the clock.
> I did a short test program:
>
> import java.text.DateFormat;
> import java.text.SimpleDateFormat;
> import java.util.Date;
> import java.io.Console;
> import java.io.IOException;
> import java.lang.*;
>
> public class JavaTimeTest
> {
> public static void main(String[] args)
> {
> DateFormat dateFormat = new SimpleDateFormat("dd.MM.yyyy
> HH:mm:ss");
>
> long currentTimeBefore = System.currentTimeMillis();
> System.out.println("Current time is now: " + currentTimeBefore +
> "ms");
> System.out.println("As DateTime it is: " +
> dateFormat.format(currentTimeBefore));
>
> System.out.println("Change time and press enter to continue...");
> try
> {
> System.in.read();
> }
> catch (IOException e)
> {
> e.printStackTrace();
> }
>
> long currentTimeAfter = System.currentTimeMillis();
> System.out.println("Current time is now: " + currentTimeAfter +
> "ms");
> System.out.println("As DateTime it is: " +
> dateFormat.format(currentTimeAfter));
>
> long timeDiff = currentTimeAfter - currentTimeBefore;
> System.out.println("Difference is: " + timeDiff + "ms");
> }
> }
>
> .. and the printout looks like this when I manually change system time a
> day
> forward:
>
> Current time is now: 1542964907800ms
> As DateTime it is: 23.11.2018 11:21:47
> Change time and press enter to continue...
>
> (...at this point I changed system time manually...)
>
> Current time is now: 1543051313048ms
> As DateTime it is: 24.11.2018 11:21:53
> Difference is: 86405248ms
>
> I hope this clarifies the problem.
>
> --
> Sami
>
>
>
>
> --
> Sent from:
> http://qpid.2158936.n2.nabble.com/Apache-Qpid-users-f2158936.html
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@qpid.apache.org
> For additional commands, e-mail: users-help@qpid.apache.org
>
>
Re: Changing system time causes J-Broker to drop connections
Posted by Sami Siitonen <sa...@fi.abb.com>.
I verified that system.currentTimeMillis returns walltime instead of
monotonic time so it cannot be used to calculate timeouts.
The problem here concerns every situation where walltime has shifted somehow
and adjusted back, for example when system clock is somehow drifted enough
and NTP is used to adjust the clock.
I did a short test program:
import java.text.DateFormat;
import java.text.SimpleDateFormat;
import java.util.Date;
import java.io.Console;
import java.io.IOException;
import java.lang.*;
public class JavaTimeTest
{
public static void main(String[] args)
{
DateFormat dateFormat = new SimpleDateFormat("dd.MM.yyyy HH:mm:ss");
long currentTimeBefore = System.currentTimeMillis();
System.out.println("Current time is now: " + currentTimeBefore +
"ms");
System.out.println("As DateTime it is: " +
dateFormat.format(currentTimeBefore));
System.out.println("Change time and press enter to continue...");
try
{
System.in.read();
}
catch (IOException e)
{
e.printStackTrace();
}
long currentTimeAfter = System.currentTimeMillis();
System.out.println("Current time is now: " + currentTimeAfter +
"ms");
System.out.println("As DateTime it is: " +
dateFormat.format(currentTimeAfter));
long timeDiff = currentTimeAfter - currentTimeBefore;
System.out.println("Difference is: " + timeDiff + "ms");
}
}
.. and the printout looks like this when I manually change system time a day
forward:
Current time is now: 1542964907800ms
As DateTime it is: 23.11.2018 11:21:47
Change time and press enter to continue...
(...at this point I changed system time manually...)
Current time is now: 1543051313048ms
As DateTime it is: 24.11.2018 11:21:53
Difference is: 86405248ms
I hope this clarifies the problem.
--
Sami
--
Sent from: http://qpid.2158936.n2.nabble.com/Apache-Qpid-users-f2158936.html
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@qpid.apache.org
For additional commands, e-mail: users-help@qpid.apache.org
Re: Changing system time causes J-Broker to drop connections
Posted by Rob Godfrey <ro...@gmail.com>.
The Qpid Broker-J uses offsets from System.currentTimeMillis (defined by
Java as "the difference, measured in milliseconds, between the current time
and midnight, January 1, 1970 UTC") and so should not be affected by
changed to DST or whatever. Suspending/resuming inside a VM would be a
different case as the connection will actually have been idle while the VM
is suspended.
When you see these disconnections occurring when changing timezone / DST
have you turned on protocol tracing...can we see clients which have been
sending traffic being disconnected?
-- Rob
On Thu, 15 Nov 2018 at 11:44, Sami Siitonen <sa...@fi.abb.com>
wrote:
> Hello,
>
> I've setup J-Broker version 6.1.4 on Windows 10 platform using OpenJDK
> version 9.0.0.1-ojdkbuildea and using RabbitMQ-client version 4.1.3 from
> .Net. The problem is very similar to this bug description in the
> C++-broker: https://bugzilla.redhat.com/show_bug.cgi?id=1080165 The
> broker drops all connections every time when system time is changed (for
> example daylight saving time changes, running broker in virtual machine and
> suspending/resuming it etc). It can be repeated by changing system time
> more than timeout limit. It seems like walltime is used instead of
> monotonic time where calculating timeouts are performed.
>
> I' ve managed to workaround this by disabling heartbeating in the client
> side but obviously this is not a proper solution. I couldn't find any bug
> report about this problem at J-Broker so I'm asking that if this is some
> configuration problem or problem with JDK or is this bug in J-Broker. I
> also tried to upgrade the broker to version 7.0.6 and RabbitMQ to 5.1.0
> with no effect.
>
> Cheers,
> Sami
>