[JAVA-2383] Java driver IllegalStateException: state should be: elapsed time is positive Created: 14/Nov/16  Updated: 27/Nov/16  Resolved: 18/Nov/16

Status: Closed
Project: Java Driver
Component/s: Monitoring
Affects Version/s: 3.3.0
Fix Version/s: 3.4.0

Type: Bug Priority: Minor - P4
Reporter: SWitte [X] Assignee: Jeffrey Yemin
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Mongo Java driver 3.3.0, MongoDB 3.2.10 (localhost), Running in WebSphere 8.5.5.10, IBMJAVA7 7.0.9.40, Windows 7 Professional


Issue Links:
Depends
is depended on by DRIVERS-336 Change "no maxStalenessSeconds" value... Closed
Duplicate
is duplicated by JAVA-2391 Change "no maxStalenessMS" value from... Closed

 Description   

I see the following exceptions in my log file.

[11/14/16 15:55:22:187 CET] 00000b52 cluster       I com.mongodb.diagnostics.logging.SLF4JLogger info Exception in monitor thread while connecting to server localhost:27017
                                 java.lang.IllegalStateException: state should be: elapsed time is positive
	at com.mongodb.assertions.Assertions.isTrue(Assertions.java:70)
	at com.mongodb.event.ServerHeartbeatSucceededEvent.<init>(ServerHeartbeatSucceededEvent.java:47)
	at com.mongodb.connection.DefaultServerMonitor$ServerMonitorRunnable.lookupServerDescription(DefaultServerMonitor.java:183)
	at com.mongodb.connection.DefaultServerMonitor$ServerMonitorRunnable.run(DefaultServerMonitor.java:123)
	at java.lang.Thread.run(Thread.java:798)

Code causing the exception:

class DefaultServerMonitor implements ServerMonitor {
...
private ServerDescription lookupServerDescription(final InternalConnection connection) {
...
            long start = System.nanoTime();
            try {
                BsonDocument isMasterResult = executeCommand("admin", new BsonDocument("ismaster", new BsonInt32(1)), connection);
                long elapsedTimeNanos = System.nanoTime() - start;
                averageRoundTripTime.addSample(elapsedTimeNanos);
 
                serverMonitorListener.serverHeartbeatSucceeded(
                        new ServerHeartbeatSucceededEvent(connection.getDescription().getConnectionId(), isMasterResult, elapsedTimeNanos));

    public ServerHeartbeatSucceededEvent(final ConnectionId connectionId, final BsonDocument reply, final long elapsedTimeNanos) {
        this.connectionId = notNull("connectionId", connectionId);
        this.reply = notNull("reply", reply);
        isTrue("elapsed time is positive", elapsedTimeNanos > 0);
        this.elapsedTimeNanos = elapsedTimeNanos;
    }

Could the elapsed time be '0' ?
Maybe the check should be "elapsedTimeNanos >= 0" ?



 Comments   
Comment by Githook User [ 18/Nov/16 ]

Author:

{u'username': u'jyemin', u'name': u'Jeff Yemin', u'email': u'jeff.yemin@10gen.com'}

Message: JAVA-2383: Allow elapsed time of zero nanoseconds for VMs that have imprecise nanosecond clocks
Branch: master
https://github.com/mongodb/mongo-java-driver/commit/365213f404d9f672eb1353544e391ba1ba36a957

Comment by Jeffrey Yemin [ 14/Nov/16 ]

Looks like the resolution of System.nanoTime on your platform is large enough that it results in 0 elapsed time even with a network call.

Generated at Thu Feb 08 08:57:04 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.