[JIRA] (JENKINS-60625) Dashboard rendering blocked on UpdateSite.getJSONObject

0 views
Skip to first unread message

jglick@cloudbees.com (JIRA)

unread,
Jan 2, 2020, 5:21:03 PM1/2/20
to jenkinsc...@googlegroups.com
Jesse Glick created an issue
 
Jenkins / Bug JENKINS-60625
Dashboard rendering blocked on UpdateSite.getJSONObject
Issue Type: Bug Bug
Assignee: Jesse Glick
Components: core
Created: 2020-01-02 22:20
Labels: performance lts-candidate
Priority: Major Major
Reporter: Jesse Glick

Recently I have noticed Jenkins page rendering being blocked for a long time (sometimes nearly 30s) with stack traces such as

"Handling GET /jenkins/ from ... : ... View/index.jelly AdministrativeMonitorsDecorator/footer.jelly" ...
   java.lang.Thread.State: RUNNABLE
	at java.lang.String.<init>(String.java:207)
	at java.lang.String.substring(String.java:1933)
	at net.sf.json.util.JSONTokener.matches(JSONTokener.java:110)
	at net.sf.json.JSONObject._fromJSONTokener(JSONObject.java:912)
	at net.sf.json.JSONObject.fromObject(JSONObject.java:156)
	at net.sf.json.util.JSONTokener.nextValue(JSONTokener.java:348)
	at net.sf.json.JSONArray._fromJSONTokener(JSONArray.java:1131)
	at net.sf.json.JSONArray.fromObject(JSONArray.java:125)
	at net.sf.json.util.JSONTokener.nextValue(JSONTokener.java:351)
	at net.sf.json.JSONObject._fromJSONTokener(JSONObject.java:955)
	at net.sf.json.JSONObject.fromObject(JSONObject.java:156)
	at net.sf.json.util.JSONTokener.nextValue(JSONTokener.java:348)
	at net.sf.json.JSONObject._fromJSONTokener(JSONObject.java:955)
	at net.sf.json.JSONObject.fromObject(JSONObject.java:156)
	at net.sf.json.util.JSONTokener.nextValue(JSONTokener.java:348)
	at net.sf.json.JSONObject._fromJSONTokener(JSONObject.java:955)
	at net.sf.json.JSONObject._fromString(JSONObject.java:1145)
	at net.sf.json.JSONObject.fromObject(JSONObject.java:162)
	at net.sf.json.JSONObject.fromObject(JSONObject.java:132)
	at hudson.model.UpdateSite.getJSONObject(UpdateSite.java:338)
	at hudson.model.UpdateSite.getData(UpdateSite.java:323)
	at hudson.model.UpdateCenter.getCoreSource(UpdateCenter.java:604)
	at hudson.model.UpdateCenter$CoreUpdateMonitor.getData(UpdateCenter.java:1035)
	at hudson.model.UpdateCenter$CoreUpdateMonitor.isActivated(UpdateCenter.java:1030)
	at jenkins.model.Jenkins.lambda$getActiveAdministrativeMonitors$0(Jenkins.java:2183)
	at jenkins.model.Jenkins$$Lambda$103/1298422401.test(Unknown Source)
	at java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:174)
	at java.util.Iterator.forEachRemaining(Iterator.java:116)
	at java.util.Spliterators$IteratorSpliterator.forEachRemaining(Spliterators.java:1801)
	at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:482)
	at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:472)
	at java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:708)
	at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
	at java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:566)
	at jenkins.model.Jenkins.getActiveAdministrativeMonitors(Jenkins.java:2188)
	at jenkins.management.AdministrativeMonitorsDecorator.getActiveAdministrativeMonitors(AdministrativeMonitorsDecorator.java:77)
	at jenkins.management.AdministrativeMonitorsDecorator.getActiveAdministrativeMonitorsCount(AdministrativeMonitorsDecorator.java:72)
	at jenkins.management.AdministrativeMonitorsDecorator.shouldDisplay(AdministrativeMonitorsDecorator.java:131)

or

  java.lang.Thread.State: RUNNABLE
	at java.util.regex.Pattern.compile(java...@11.0.5/Pattern.java:1757)
	at java.util.regex.Pattern.<init>(java...@11.0.5/Pattern.java:1428)
	at java.util.regex.Pattern.compile(java...@11.0.5/Pattern.java:1068)
	at net.sf.json.regexp.JdkRegexpMatcher.<init>(JdkRegexpMatcher.java:38)
	at net.sf.json.regexp.JdkRegexpMatcher.<init>(JdkRegexpMatcher.java:31)
	at net.sf.json.regexp.RegexpUtils.getMatcher(RegexpUtils.java:39)
	at net.sf.json.util.JSONTokener.matches(JSONTokener.java:111)
	at net.sf.json.JSONObject._fromJSONTokener(JSONObject.java:912)
	at net.sf.json.JSONObject.fromObject(JSONObject.java:156)
	at net.sf.json.util.JSONTokener.nextValue(JSONTokener.java:348)
	at net.sf.json.JSONArray._fromJSONTokener(JSONArray.java:1131)
	at net.sf.json.JSONArray.fromObject(JSONArray.java:125)
	at net.sf.json.util.JSONTokener.nextValue(JSONTokener.java:351)
	at net.sf.json.JSONObject._fromJSONTokener(JSONObject.java:955)
	at net.sf.json.JSONObject.fromObject(JSONObject.java:156)
	at net.sf.json.util.JSONTokener.nextValue(JSONTokener.java:348)
	at net.sf.json.JSONObject._fromJSONTokener(JSONObject.java:955)
	at net.sf.json.JSONObject.fromObject(JSONObject.java:156)
	at net.sf.json.util.JSONTokener.nextValue(JSONTokener.java:348)
	at net.sf.json.JSONObject._fromJSONTokener(JSONObject.java:955)
	at net.sf.json.JSONObject._fromString(JSONObject.java:1145)
	at net.sf.json.JSONObject.fromObject(JSONObject.java:162)
	at net.sf.json.JSONObject.fromObject(JSONObject.java:132)

While loading the JSON text from disk takes just milliseconds, the parsing is extremely slow (hundreds of times slower than jq, for example). This seems to be due to poor code in json-lib, especially this which repeatedly compiles patterns where a simple .startsWith("null") would apparently have sufficed!

The poor performance of JSONObject.fromObject might not have been so noticeable except that some administrative monitors blocked on the parsing, contrary to the Javadoc in AdministrativeMonitor.isActivated.

Add Comment Add Comment
 
This message was sent by Atlassian Jira (v7.13.6#713006-sha1:cc4451f)
Atlassian logo

jglick@cloudbees.com (JIRA)

unread,
Jan 2, 2020, 5:22:03 PM1/2/20
to jenkinsc...@googlegroups.com
Jesse Glick started work on Bug JENKINS-60625
 
Change By: Jesse Glick
Status: Open In Progress

jglick@cloudbees.com (JIRA)

unread,
Jan 2, 2020, 5:27:01 PM1/2/20
to jenkinsc...@googlegroups.com

jglick@cloudbees.com (JIRA)

unread,
Jan 4, 2020, 9:23:02 AM1/4/20
to jenkinsc...@googlegroups.com
Change By: Jesse Glick
Status: In Review Fixed but Unreleased
Resolution: Fixed
Released As: 2.212

dbeck@cloudbees.com (JIRA)

unread,
Jan 13, 2020, 12:25:03 PM1/13/20
to jenkinsc...@googlegroups.com

dbeck@cloudbees.com (JIRA)

unread,
Jan 13, 2020, 12:25:03 PM1/13/20
to jenkinsc...@googlegroups.com

jglick@cloudbees.com (JIRA)

unread,
Jan 13, 2020, 12:43:03 PM1/13/20
to jenkinsc...@googlegroups.com
Jesse Glick commented on Bug JENKINS-60625
 
Re: Dashboard rendering blocked on UpdateSite.getJSONObject

Note that I am still inclined to look for ways to patch or bypass this library to minimize even background CPU, but that would be tracked as a separate issue and presumably not be an LTS candidate.

ogondza@gmail.com (JIRA)

unread,
Jan 13, 2020, 2:45:03 PM1/13/20
to jenkinsc...@googlegroups.com
Oliver Gondža updated an issue
 
Change By: Oliver Gondža
Labels: 2.204.2-rejected lts-candidate performance

ogondza@gmail.com (JIRA)

unread,
Jan 13, 2020, 2:47:02 PM1/13/20
to jenkinsc...@googlegroups.com
Oliver Gondža commented on Bug JENKINS-60625
 
Re: Dashboard rendering blocked on UpdateSite.getJSONObject

I would like to give this change some more soaking time so postponing to 2.204.3

 

Reply all
Reply to author
Forward
0 new messages