[JIRA] (JENKINS-61792) DoubleLaunchChecker false positive

6 views
Skip to first unread message

wadex.cline@intel.com (JIRA)

unread,
Apr 2, 2020, 7:42:03 PM4/2/20
to jenkinsc...@googlegroups.com
Wade Cline created an issue
 
Jenkins / Bug JENKINS-61792
DoubleLaunchChecker false positive
Issue Type: Bug Bug
Assignee: Unassigned
Components: core
Created: 2020-04-02 23:41
Environment: Debian GNU/Linux 10
openjdk 11.0.6 2020-01-14
OpenJDK Runtime Environment (build 11.0.6+10-post-Debian-1deb10u1)
OpenJDK 64-Bit Server VM (build 11.0.6+10-post-Debian-1deb10u1, mixed mode, sharing)
Jenkins ver. 2.204.5
Launched & installed via standard Debian service
Accessed directly
Priority: Minor Minor
Reporter: Wade Cline

(Copied from e-mail)

A few weeks ago we ran into an issue where Jenkins reported that two instances were running with the same host directory:

--------
Error

Jenkins detected that you appear to be running more than one instance of Jenkins that share the same home directory '/var/lib/jenkins'. This greatly confuses Jenkins and you will likely experience strange
behaviors, so please correct the situation.
This Jenkins:1541674003 contextPath="" at 29119@NPG-CID-Jenkins-OR
Other Jenkins:1541674003 contextPath="" at 29119@NPG-CID-Jenkins-OR
--------

The two identifiers reported were exactly the same. Looking at the source, I found 'core/src/main/java/hudson/util/DoubleLaunchChecher.java', and, from there, found the following entry in the Jenkins log file:

--------
2020-03-17 01:14:10.096+0000 [id=66] SEVERE hudson.util.DoubleLaunchChecker#execute: Collision detected. timestamp=1584403930000, expected=1584403930092
--------

Note that the time stamps are a mere 92 milliseconds apart and appear to be from the same instance. At first I expected that this might be a filesystem timestamp resolution issue, but running 'ls -a --full-time'
showed that the filesystem did indeed support high-resolution timestamps (output snipped):

--------
rw-rr- 1 jenkins jenkins 53 2020-03-20 11:50:10.193592799 -0700 .owner
--------

I also wrote a quick Java test program to see if the timestamping code worked as expected, and it did indeed:

--------
import org.apache.commons.io.FileUtils;
import java.io.File;
import java.io.IOException;

public class Test {
public static void main(String args[]) {
File timestampFile = new File(".owner");
long t = timestampFile.lastModified();
try

{ FileUtils.writeStringToFile(timestampFile, "Oh God how did this get here I am not good with computer"); }

catch (IOException e)

{ System.out.println("It broke"); }

long t2 = timestampFile.lastModified();
System.out.println("Old Timestamp: " + t);
System.out.println("New Timestamp: " + t2);
}
}
--------
root@NPG-CID-Jenkins-OR:~# java -cp "/root/jenkins/WEB-INF/lib/" ./Test.java
Note: ./Test.java uses or overrides a deprecated API.
Note: Recompile with -Xlint:deprecation for details.
Old Timestamp: 1584733878748
New Timestamp: 1584734059361
root@NPG-CID-Jenkins-OR:~# java -cp "/root/jenkins/WEB-INF/lib/" ./Test.java
Note: ./Test.java uses or overrides a deprecated API.
Note: Recompile with -Xlint:deprecation for details.
Old Timestamp: 1584734059361
New Timestamp: 1584734060529
root@NPG-CID-Jenkins-OR:~# java -cp "/root/jenkins/WEB-INF/lib/" ./Test.java
Note: ./Test.java uses or overrides a deprecated API.
Note: Recompile with -Xlint:deprecation for details.
Old Timestamp: 1584734060529
New Timestamp: 1584734062861
--------

So now I suspect that perhaps the DoubleLaunchChecker is erroneously being run twice on startup, but am not sure how I would test that hypothesis.

Has anyone seen this issue before, or have any ideas how to debug it?

Since the issue appears to be a false positive we've gone ahead and told Jenkins to ignore the issue for now.

Add Comment Add Comment
 
This message was sent by Atlassian Jira (v7.13.12#713012-sha1:6e07c38)
Atlassian logo

o.v.nenashev@gmail.com (JIRA)

unread,
Apr 3, 2020, 5:34:03 AM4/3/20
to jenkinsc...@googlegroups.com

> Has anyone seen this issue before, or have any ideas how to debug it?

I have not seen such issue before. It may be easily a filesystem problem or a glitch in the code.

Did you hit this issue only once?

 

wadex.cline@intel.com (JIRA)

unread,
Apr 3, 2020, 2:12:03 PM4/3/20
to jenkinsc...@googlegroups.com
Wade Cline commented on Bug JENKINS-61792
 
Re: DoubleLaunchChecker false positive

We've hit this issue twice recently on the same machine, here is the snippet from earlier:

2020-03-14 02:02:45.357+0000 [id=56]    SEVERE  hudson.util.DoubleLaunchChecker#execute: Collision detected. timestamp=1584146805000, expected=1584146805350

The underlying filesystem is 'ext4' with standard options 'rw,relatime,errors=remount-ro', and the unit test shows that the filesystem does support sub-second timestamps... and yet the messages appear to suggest the opposite.

There might be an uncommon case which causes the sub-second timestamp to be downgraded to a second timestamp when writing to disk (yet that didn't happen in the unit test I wrote), or there might be something more nefarious going on here.

Reply all
Reply to author
Forward
0 new messages