Uploaded image for project: 'Jenkins'
  1. Jenkins
  2. JENKINS-19561

Unsafe & inefficient concurrency in XStream

    XMLWordPrintable

    Details

    • Similar Issues:
    • Released As:
      2.266

      Description

      Related to JENKINS-13154, we are still seeing lots of congestion with Jenkins 1.517 and our builds may still stay tens of minutes in "Waiting for Jenkins to finish collecting data" -phase.

      The place has changed though, now thread dumps show lots of these:

      java.lang.Thread.State: BLOCKED (on object monitor)
      at java.util.Collections$SynchronizedMap.get(Collections.java:2031)
      waiting to lock <0x000000070c6dcfa8> (a java.util.Collections$SynchronizedMap)
      at com.thoughtworks.xstream.core.DefaultConverterLookup.lookupConverterForType(DefaultConverterLookup.java:49)

        Attachments

          Issue Links

            Activity

            Hide
            t_kurki Teppo Kurki added a comment -

            Access to converters apparently needs to be synchronized per JENKINS-18775 but the execution path to the cached converters should be as free of synchronization as possible.

            typeToConverterMap has changed for more synchronization in two steps:

            (1)
            from ConcurrentHashMap to Collections.synchronizedMap(new WeakHashMap());
            https://github.com/jenkinsci/xstream/blob/3ee1dba0e7a0ae2a12759c87bea9cbb6578e19f7/xstream/src/java/com/thoughtworks/xstream/core/DefaultConverterLookup.java

            (2) from just having synchronized access to the map to total synchronization in JENKINS-18775

            I assume the WeakHashMap is needed in XStream in the general case, but if CI uses XStream for a fixed set of classes we could maybe do without that so that ConcurrentHashMap would do the trick?

            Show
            t_kurki Teppo Kurki added a comment - Access to converters apparently needs to be synchronized per JENKINS-18775 but the execution path to the cached converters should be as free of synchronization as possible. typeToConverterMap has changed for more synchronization in two steps: (1) from ConcurrentHashMap to Collections.synchronizedMap(new WeakHashMap()); https://github.com/jenkinsci/xstream/blob/3ee1dba0e7a0ae2a12759c87bea9cbb6578e19f7/xstream/src/java/com/thoughtworks/xstream/core/DefaultConverterLookup.java (2) from just having synchronized access to the map to total synchronization in JENKINS-18775 I assume the WeakHashMap is needed in XStream in the general case, but if CI uses XStream for a fixed set of classes we could maybe do without that so that ConcurrentHashMap would do the trick?
            Hide
            jglick Jesse Glick added a comment -

            if CI uses XStream for a fixed set of classes

            It is quite open-ended in fact.

            Discussions in http://jira.codehaus.org/browse/XSTR-744 indicate that using a single XStream2 instance (actually there are a handful of such singletons, in Items, Run, UpdateCenter, and User, as well as the general one in Jenkins) is unsupported—since we have no idea which thread will use these instances, they should really be loaded from a ThreadLocal. Unfortunately these singletons are public fields, not gated through methods, and they are in fact stateful (plugins can add converters to them), so that is not straightforward.

            Possibly XStream2 could be a façade which keeps a per-thread pool of actual implementations and delegates all method calls to them, which would allow us to remove the thread-related patches from the Jenkins fork, and which might permit better performance without sacrificing safety: there would be overhead for looking up the proxy, but this would only be incurred roughly once per XmlFile load, which is negligible compared to I/O costs. The rest of the load would only use monitors for the converter cache, which should be quick.

            Show
            jglick Jesse Glick added a comment - if CI uses XStream for a fixed set of classes It is quite open-ended in fact. Discussions in http://jira.codehaus.org/browse/XSTR-744 indicate that using a single XStream2 instance (actually there are a handful of such singletons, in Items , Run , UpdateCenter , and User , as well as the general one in Jenkins ) is unsupported—since we have no idea which thread will use these instances, they should really be loaded from a ThreadLocal . Unfortunately these singletons are public fields, not gated through methods, and they are in fact stateful (plugins can add converters to them), so that is not straightforward. Possibly XStream2 could be a façade which keeps a per-thread pool of actual implementations and delegates all method calls to them, which would allow us to remove the thread-related patches from the Jenkins fork, and which might permit better performance without sacrificing safety: there would be overhead for looking up the proxy, but this would only be incurred roughly once per XmlFile load, which is negligible compared to I/O costs. The rest of the load would only use monitors for the converter cache, which should be quick.
            Hide
            jglick Jesse Glick added a comment -

            As of JENKINS-16301 in 1.518 fingerprint saving does not normally use XStream at all, so the issue is really about general (de)serialization performance.

            Show
            jglick Jesse Glick added a comment - As of JENKINS-16301 in 1.518 fingerprint saving does not normally use XStream at all, so the issue is really about general (de)serialization performance.
            Hide
            jglick Jesse Glick added a comment -

            http://xstream.codehaus.org/annotations-tutorial.html#AutoDetect

            Can also lead to deadlocks, such as this one loading lots of jobs:

            Found one Java-level deadlock:
            =============================
            "Loading job item-00006":
              waiting to lock monitor 0x00007f0df00054f8 (object 0x000000008a956ac8, a java.lang.Class),
              which is held by "Loading job item-00007"
            "Loading job item-00007":
              waiting to lock monitor 0x00007f0dfc3fe2f0 (object 0x000000008a955c08, a java.lang.Class),
              which is held by "Loading job item-00006"
            
            Java stack information for the threads listed above:
            ===================================================
            "Loading job item-00006":
            	at java.lang.Class.initAnnotationsIfNecessary(Class.java:3095)
            	- waiting to lock <0x000000008a956ac8> (a java.lang.Class for jenkins.model.lazy.LazyBuildMixIn$LazyLoadingJob)
            	at java.lang.Class.getAnnotation(Class.java:3057)
            	at com.thoughtworks.xstream.mapper.AnnotationMapper$UnprocessedTypesSet.add(AnnotationMapper.java:625)
            	at com.thoughtworks.xstream.mapper.AnnotationMapper$UnprocessedTypesSet.add(AnnotationMapper.java:610)
            	at com.thoughtworks.xstream.mapper.AnnotationMapper$1.add(AnnotationMapper.java:250)
            	at com.thoughtworks.xstream.mapper.AnnotationMapper$1.add(AnnotationMapper.java:245)
            	at com.thoughtworks.xstream.mapper.AnnotationMapper.addParametrizedTypes(AnnotationMapper.java:279)
            	at com.thoughtworks.xstream.mapper.AnnotationMapper.processTypes(AnnotationMapper.java:204)
            	- locked <0x000000008a955c08> (a java.lang.Class for jenkins.model.lazy.LazyBuildMixIn$LazyLoadingRun)
            	at com.thoughtworks.xstream.mapper.AnnotationMapper.processAnnotations(AnnotationMapper.java:182)
            	at com.thoughtworks.xstream.mapper.AnnotationMapper.defaultImplementationOf(AnnotationMapper.java:141)
            	at hudson.util.xstream.MapperDelegate.defaultImplementationOf(MapperDelegate.java:59)
            	at com.thoughtworks.xstream.mapper.MapperWrapper.defaultImplementationOf(MapperWrapper.java:46)
            	at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:54)
            	at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:50)
            	at com.thoughtworks.xstream.core.TreeUnmarshaller.start(TreeUnmarshaller.java:134)
            	at com.thoughtworks.xstream.core.AbstractTreeMarshallingStrategy.unmarshal(AbstractTreeMarshallingStrategy.java:32)
            	at com.thoughtworks.xstream.XStream.unmarshal(XStream.java:1189)
            	at hudson.util.XStream2.unmarshal(XStream2.java:113)
            	at com.thoughtworks.xstream.XStream.unmarshal(XStream.java:1173)
            	at com.thoughtworks.xstream.XStream.fromXML(XStream.java:1053)
            	at hudson.XmlFile.read(XmlFile.java:142)
            	at hudson.model.Items.load(Items.java:277)
            	at ...
            "Loading job item-00007":
            	at java.lang.Class.initAnnotationsIfNecessary(Class.java:3095)
            	- waiting to lock <0x000000008a955c08> (a java.lang.Class for jenkins.model.lazy.LazyBuildMixIn$LazyLoadingRun)
            	at java.lang.Class.getAnnotation(Class.java:3057)
            	at com.thoughtworks.xstream.mapper.AnnotationMapper$UnprocessedTypesSet.add(AnnotationMapper.java:625)
            	at com.thoughtworks.xstream.mapper.AnnotationMapper$UnprocessedTypesSet.add(AnnotationMapper.java:610)
            	at com.thoughtworks.xstream.mapper.AnnotationMapper$1.add(AnnotationMapper.java:250)
            	at com.thoughtworks.xstream.mapper.AnnotationMapper$1.add(AnnotationMapper.java:245)
            	at com.thoughtworks.xstream.mapper.AnnotationMapper.addParametrizedTypes(AnnotationMapper.java:279)
            	at com.thoughtworks.xstream.mapper.AnnotationMapper.processTypes(AnnotationMapper.java:204)
            	- locked <0x000000008a956ac8> (a java.lang.Class for jenkins.model.lazy.LazyBuildMixIn$LazyLoadingJob)
            	at com.thoughtworks.xstream.mapper.AnnotationMapper.processAnnotations(AnnotationMapper.java:182)
            	at com.thoughtworks.xstream.mapper.AnnotationMapper.getLocalConverter(AnnotationMapper.java:153)
            	at hudson.util.xstream.MapperDelegate.getLocalConverter(MapperDelegate.java:112)
            	at com.thoughtworks.xstream.mapper.MapperWrapper.getLocalConverter(MapperWrapper.java:99)
            	at hudson.util.RobustReflectionConverter.unmarshalField(RobustReflectionConverter.java:348)
            	at hudson.util.RobustReflectionConverter.doUnmarshal(RobustReflectionConverter.java:289)
            	at hudson.util.RobustReflectionConverter.unmarshal(RobustReflectionConverter.java:228)
            	at com.thoughtworks.xstream.core.TreeUnmarshaller.convert(TreeUnmarshaller.java:72)
            	at com.thoughtworks.xstream.core.AbstractReferenceUnmarshaller.convert(AbstractReferenceUnmarshaller.java:65)
            	at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:66)
            	at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:50)
            	at com.thoughtworks.xstream.core.TreeUnmarshaller.start(TreeUnmarshaller.java:134)
            	at com.thoughtworks.xstream.core.AbstractTreeMarshallingStrategy.unmarshal(AbstractTreeMarshallingStrategy.java:32)
            	at com.thoughtworks.xstream.XStream.unmarshal(XStream.java:1189)
            	at hudson.util.XStream2.unmarshal(XStream2.java:113)
            	at com.thoughtworks.xstream.XStream.unmarshal(XStream.java:1173)
            	at com.thoughtworks.xstream.XStream.fromXML(XStream.java:1053)
            	at hudson.XmlFile.read(XmlFile.java:142)
            	at hudson.model.Items.load(Items.java:277)
            	at ...
            
            Show
            jglick Jesse Glick added a comment - http://xstream.codehaus.org/annotations-tutorial.html#AutoDetect Can also lead to deadlocks, such as this one loading lots of jobs: Found one Java-level deadlock: ============================= "Loading job item-00006": waiting to lock monitor 0x00007f0df00054f8 (object 0x000000008a956ac8, a java.lang.Class), which is held by "Loading job item-00007" "Loading job item-00007": waiting to lock monitor 0x00007f0dfc3fe2f0 (object 0x000000008a955c08, a java.lang.Class), which is held by "Loading job item-00006" Java stack information for the threads listed above: =================================================== "Loading job item-00006": at java.lang.Class.initAnnotationsIfNecessary(Class.java:3095) - waiting to lock <0x000000008a956ac8> (a java.lang.Class for jenkins.model.lazy.LazyBuildMixIn$LazyLoadingJob) at java.lang.Class.getAnnotation(Class.java:3057) at com.thoughtworks.xstream.mapper.AnnotationMapper$UnprocessedTypesSet.add(AnnotationMapper.java:625) at com.thoughtworks.xstream.mapper.AnnotationMapper$UnprocessedTypesSet.add(AnnotationMapper.java:610) at com.thoughtworks.xstream.mapper.AnnotationMapper$1.add(AnnotationMapper.java:250) at com.thoughtworks.xstream.mapper.AnnotationMapper$1.add(AnnotationMapper.java:245) at com.thoughtworks.xstream.mapper.AnnotationMapper.addParametrizedTypes(AnnotationMapper.java:279) at com.thoughtworks.xstream.mapper.AnnotationMapper.processTypes(AnnotationMapper.java:204) - locked <0x000000008a955c08> (a java.lang.Class for jenkins.model.lazy.LazyBuildMixIn$LazyLoadingRun) at com.thoughtworks.xstream.mapper.AnnotationMapper.processAnnotations(AnnotationMapper.java:182) at com.thoughtworks.xstream.mapper.AnnotationMapper.defaultImplementationOf(AnnotationMapper.java:141) at hudson.util.xstream.MapperDelegate.defaultImplementationOf(MapperDelegate.java:59) at com.thoughtworks.xstream.mapper.MapperWrapper.defaultImplementationOf(MapperWrapper.java:46) at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:54) at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:50) at com.thoughtworks.xstream.core.TreeUnmarshaller.start(TreeUnmarshaller.java:134) at com.thoughtworks.xstream.core.AbstractTreeMarshallingStrategy.unmarshal(AbstractTreeMarshallingStrategy.java:32) at com.thoughtworks.xstream.XStream.unmarshal(XStream.java:1189) at hudson.util.XStream2.unmarshal(XStream2.java:113) at com.thoughtworks.xstream.XStream.unmarshal(XStream.java:1173) at com.thoughtworks.xstream.XStream.fromXML(XStream.java:1053) at hudson.XmlFile.read(XmlFile.java:142) at hudson.model.Items.load(Items.java:277) at ... "Loading job item-00007": at java.lang.Class.initAnnotationsIfNecessary(Class.java:3095) - waiting to lock <0x000000008a955c08> (a java.lang.Class for jenkins.model.lazy.LazyBuildMixIn$LazyLoadingRun) at java.lang.Class.getAnnotation(Class.java:3057) at com.thoughtworks.xstream.mapper.AnnotationMapper$UnprocessedTypesSet.add(AnnotationMapper.java:625) at com.thoughtworks.xstream.mapper.AnnotationMapper$UnprocessedTypesSet.add(AnnotationMapper.java:610) at com.thoughtworks.xstream.mapper.AnnotationMapper$1.add(AnnotationMapper.java:250) at com.thoughtworks.xstream.mapper.AnnotationMapper$1.add(AnnotationMapper.java:245) at com.thoughtworks.xstream.mapper.AnnotationMapper.addParametrizedTypes(AnnotationMapper.java:279) at com.thoughtworks.xstream.mapper.AnnotationMapper.processTypes(AnnotationMapper.java:204) - locked <0x000000008a956ac8> (a java.lang.Class for jenkins.model.lazy.LazyBuildMixIn$LazyLoadingJob) at com.thoughtworks.xstream.mapper.AnnotationMapper.processAnnotations(AnnotationMapper.java:182) at com.thoughtworks.xstream.mapper.AnnotationMapper.getLocalConverter(AnnotationMapper.java:153) at hudson.util.xstream.MapperDelegate.getLocalConverter(MapperDelegate.java:112) at com.thoughtworks.xstream.mapper.MapperWrapper.getLocalConverter(MapperWrapper.java:99) at hudson.util.RobustReflectionConverter.unmarshalField(RobustReflectionConverter.java:348) at hudson.util.RobustReflectionConverter.doUnmarshal(RobustReflectionConverter.java:289) at hudson.util.RobustReflectionConverter.unmarshal(RobustReflectionConverter.java:228) at com.thoughtworks.xstream.core.TreeUnmarshaller.convert(TreeUnmarshaller.java:72) at com.thoughtworks.xstream.core.AbstractReferenceUnmarshaller.convert(AbstractReferenceUnmarshaller.java:65) at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:66) at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:50) at com.thoughtworks.xstream.core.TreeUnmarshaller.start(TreeUnmarshaller.java:134) at com.thoughtworks.xstream.core.AbstractTreeMarshallingStrategy.unmarshal(AbstractTreeMarshallingStrategy.java:32) at com.thoughtworks.xstream.XStream.unmarshal(XStream.java:1189) at hudson.util.XStream2.unmarshal(XStream2.java:113) at com.thoughtworks.xstream.XStream.unmarshal(XStream.java:1173) at com.thoughtworks.xstream.XStream.fromXML(XStream.java:1053) at hudson.XmlFile.read(XmlFile.java:142) at hudson.model.Items.load(Items.java:277) at ...
            Hide
            scm_issue_link SCM/JIRA link daemon added a comment -

            Code changed in jenkins
            User: Jesse Glick
            Path:
            core/src/main/java/hudson/util/XStream2.java
            http://jenkins-ci.org/commit/jenkins/1568a8bc24a3bc93e815a4b88bab6d46806e8842
            Log:
            JENKINS-19561 Edited comment.

            Show
            scm_issue_link SCM/JIRA link daemon added a comment - Code changed in jenkins User: Jesse Glick Path: core/src/main/java/hudson/util/XStream2.java http://jenkins-ci.org/commit/jenkins/1568a8bc24a3bc93e815a4b88bab6d46806e8842 Log: JENKINS-19561 Edited comment.
            Hide
            dogfood dogfood added a comment -

            Integrated in jenkins_main_trunk #3356
            JENKINS-19561 Edited comment. (Revision 1568a8bc24a3bc93e815a4b88bab6d46806e8842)

            Result = SUCCESS
            Jesse Glick : 1568a8bc24a3bc93e815a4b88bab6d46806e8842
            Files :

            • core/src/main/java/hudson/util/XStream2.java
            Show
            dogfood dogfood added a comment - Integrated in jenkins_main_trunk #3356 JENKINS-19561 Edited comment. (Revision 1568a8bc24a3bc93e815a4b88bab6d46806e8842) Result = SUCCESS Jesse Glick : 1568a8bc24a3bc93e815a4b88bab6d46806e8842 Files : core/src/main/java/hudson/util/XStream2.java
            Hide
            jglick Jesse Glick added a comment -

            Seems to be the cause of occasional test failures in Workflow (not known to occur in production, but might):

            java.util.ConcurrentModificationException: null
            	at java.util.LinkedHashMap$LinkedHashIterator.nextEntry(LinkedHashMap.java:394)
            	at java.util.LinkedHashMap$EntryIterator.next(LinkedHashMap.java:413)
            	at java.util.LinkedHashMap$EntryIterator.next(LinkedHashMap.java:412)
            	at com.thoughtworks.xstream.converters.collections.MapConverter.marshal(MapConverter.java:75)
            	at com.thoughtworks.xstream.core.AbstractReferenceMarshaller.convert(AbstractReferenceMarshaller.java:69)
            	at com.thoughtworks.xstream.core.TreeMarshaller.convertAnother(TreeMarshaller.java:58)
            	at com.thoughtworks.xstream.core.AbstractReferenceMarshaller$1.convertAnother(AbstractReferenceMarshaller.java:84)
            	at hudson.util.RobustReflectionConverter.marshallField(RobustReflectionConverter.java:223)
            	at hudson.util.RobustReflectionConverter$2.writeField(RobustReflectionConverter.java:210)
            	at hudson.util.RobustReflectionConverter$2.visit(RobustReflectionConverter.java:182)
            	at com.thoughtworks.xstream.converters.reflection.PureJavaReflectionProvider.visitSerializableFields(PureJavaReflectionProvider.java:138)
            	at hudson.util.RobustReflectionConverter.doMarshal(RobustReflectionConverter.java:167)
            	at hudson.util.RobustReflectionConverter.marshal(RobustReflectionConverter.java:108)
            	at com.thoughtworks.xstream.core.AbstractReferenceMarshaller.convert(AbstractReferenceMarshaller.java:69)
            	at com.thoughtworks.xstream.core.TreeMarshaller.convertAnother(TreeMarshaller.java:58)
            	at com.thoughtworks.xstream.core.TreeMarshaller.convertAnother(TreeMarshaller.java:43)
            	at com.thoughtworks.xstream.core.TreeMarshaller.start(TreeMarshaller.java:82)
            	at com.thoughtworks.xstream.core.AbstractTreeMarshallingStrategy.marshal(AbstractTreeMarshallingStrategy.java:37)
            	at com.thoughtworks.xstream.XStream.marshal(XStream.java:1026)
            	at com.thoughtworks.xstream.XStream.marshal(XStream.java:1015)
            	at com.thoughtworks.xstream.XStream.toXML(XStream.java:988)
            	at hudson.XmlFile.write(XmlFile.java:178)
            	at hudson.model.Run.save(Run.java:1915)
            	at org.jenkinsci.plugins.workflow.support.steps.input.InputStepExecution.postSettlement(InputStepExecution.java:196)
            	at org.jenkinsci.plugins.workflow.support.steps.input.InputStepExecution.proceed(InputStepExecution.java:149)
            	at org.jenkinsci.plugins.workflow.steps.parallel.ParallelStepTest$9.evaluate(ParallelStepTest.java:360)
            
            Show
            jglick Jesse Glick added a comment - Seems to be the cause of occasional test failures in Workflow (not known to occur in production, but might): java.util.ConcurrentModificationException: null at java.util.LinkedHashMap$LinkedHashIterator.nextEntry(LinkedHashMap.java:394) at java.util.LinkedHashMap$EntryIterator.next(LinkedHashMap.java:413) at java.util.LinkedHashMap$EntryIterator.next(LinkedHashMap.java:412) at com.thoughtworks.xstream.converters.collections.MapConverter.marshal(MapConverter.java:75) at com.thoughtworks.xstream.core.AbstractReferenceMarshaller.convert(AbstractReferenceMarshaller.java:69) at com.thoughtworks.xstream.core.TreeMarshaller.convertAnother(TreeMarshaller.java:58) at com.thoughtworks.xstream.core.AbstractReferenceMarshaller$1.convertAnother(AbstractReferenceMarshaller.java:84) at hudson.util.RobustReflectionConverter.marshallField(RobustReflectionConverter.java:223) at hudson.util.RobustReflectionConverter$2.writeField(RobustReflectionConverter.java:210) at hudson.util.RobustReflectionConverter$2.visit(RobustReflectionConverter.java:182) at com.thoughtworks.xstream.converters.reflection.PureJavaReflectionProvider.visitSerializableFields(PureJavaReflectionProvider.java:138) at hudson.util.RobustReflectionConverter.doMarshal(RobustReflectionConverter.java:167) at hudson.util.RobustReflectionConverter.marshal(RobustReflectionConverter.java:108) at com.thoughtworks.xstream.core.AbstractReferenceMarshaller.convert(AbstractReferenceMarshaller.java:69) at com.thoughtworks.xstream.core.TreeMarshaller.convertAnother(TreeMarshaller.java:58) at com.thoughtworks.xstream.core.TreeMarshaller.convertAnother(TreeMarshaller.java:43) at com.thoughtworks.xstream.core.TreeMarshaller.start(TreeMarshaller.java:82) at com.thoughtworks.xstream.core.AbstractTreeMarshallingStrategy.marshal(AbstractTreeMarshallingStrategy.java:37) at com.thoughtworks.xstream.XStream.marshal(XStream.java:1026) at com.thoughtworks.xstream.XStream.marshal(XStream.java:1015) at com.thoughtworks.xstream.XStream.toXML(XStream.java:988) at hudson.XmlFile.write(XmlFile.java:178) at hudson.model.Run.save(Run.java:1915) at org.jenkinsci.plugins.workflow.support.steps.input.InputStepExecution.postSettlement(InputStepExecution.java:196) at org.jenkinsci.plugins.workflow.support.steps.input.InputStepExecution.proceed(InputStepExecution.java:149) at org.jenkinsci.plugins.workflow.steps.parallel.ParallelStepTest$9.evaluate(ParallelStepTest.java:360)
            Hide
            jglick Jesse Glick added a comment -

            Confirmed to occur in production using Pipeline 1.14.1 on 1.625.x:

            …	WARNING	j.u.ErrorLoggingScheduledThreadPoolExecutor#afterExecute: failure in task not wrapped in SafeTimerTaskjava.lang.RuntimeException: Failed to serialize org.jenkinsci.plugins.workflow.job.WorkflowRun#execution for class org.jenkinsci.plugins.workflow.job.WorkflowRun
            	at hudson.util.RobustReflectionConverter$2.writeField(RobustReflectionConverter.java:215)
            	at hudson.util.RobustReflectionConverter$2.visit(RobustReflectionConverter.java:183)
            	at com.thoughtworks.xstream.converters.reflection.PureJavaReflectionProvider.visitSerializableFields(PureJavaReflectionProvider.java:138)
            	at hudson.util.RobustReflectionConverter.doMarshal(RobustReflectionConverter.java:168)
            	at hudson.util.RobustReflectionConverter.marshal(RobustReflectionConverter.java:109)
            	at com.thoughtworks.xstream.core.AbstractReferenceMarshaller.convert(AbstractReferenceMarshaller.java:69)
            	at com.thoughtworks.xstream.core.TreeMarshaller.convertAnother(TreeMarshaller.java:58)
            	at com.thoughtworks.xstream.core.TreeMarshaller.convertAnother(TreeMarshaller.java:43)
            	at com.thoughtworks.xstream.core.TreeMarshaller.start(TreeMarshaller.java:82)
            	at com.thoughtworks.xstream.core.AbstractTreeMarshallingStrategy.marshal(AbstractTreeMarshallingStrategy.java:37)
            	at com.thoughtworks.xstream.XStream.marshal(XStream.java:1026)
            	at com.thoughtworks.xstream.XStream.marshal(XStream.java:1015)
            	at com.thoughtworks.xstream.XStream.toXML(XStream.java:988)
            	at hudson.XmlFile.write(XmlFile.java:178)
            	at hudson.model.Run.save(Run.java:1901)
            	at org.jenkinsci.plugins.workflow.job.WorkflowRun.copyLogs(WorkflowRun.java:397)
            	at org.jenkinsci.plugins.workflow.job.WorkflowRun.access$600(WorkflowRun.java:111)
            	at org.jenkinsci.plugins.workflow.job.WorkflowRun$3.run(WorkflowRun.java:265)
            	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
            	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
            	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
            	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
            	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
            	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
            	at java.lang.Thread.run(Thread.java:745)
            Caused by: java.util.ConcurrentModificationException
            	at java.util.HashMap$HashIterator.nextNode(HashMap.java:1429)
            	at java.util.HashMap$EntryIterator.next(HashMap.java:1463)
            	at java.util.HashMap$EntryIterator.next(HashMap.java:1461)
            	at com.thoughtworks.xstream.converters.collections.MapConverter.marshal(MapConverter.java:75)
            	at com.thoughtworks.xstream.core.AbstractReferenceMarshaller.convert(AbstractReferenceMarshaller.java:69)
            	at com.thoughtworks.xstream.core.TreeMarshaller.convertAnother(TreeMarshaller.java:58)
            	at com.thoughtworks.xstream.core.TreeMarshaller.convertAnother(TreeMarshaller.java:43)
            	at com.thoughtworks.xstream.core.AbstractReferenceMarshaller$1.convertAnother(AbstractReferenceMarshaller.java:88)
            	at org.jenkinsci.plugins.workflow.cps.CpsFlowExecution$ConverterImpl.writeChild(CpsFlowExecution.java:949)
            	at org.jenkinsci.plugins.workflow.cps.CpsFlowExecution$ConverterImpl.marshal(CpsFlowExecution.java:925)
            	at hudson.util.XStream2$AssociatedConverterImpl.marshal(XStream2.java:361)
            	at com.thoughtworks.xstream.core.AbstractReferenceMarshaller.convert(AbstractReferenceMarshaller.java:69)
            	at com.thoughtworks.xstream.core.TreeMarshaller.convertAnother(TreeMarshaller.java:58)
            	at com.thoughtworks.xstream.core.AbstractReferenceMarshaller$1.convertAnother(AbstractReferenceMarshaller.java:84)
            	at hudson.util.RobustReflectionConverter.marshallField(RobustReflectionConverter.java:224)
            	at hudson.util.RobustReflectionConverter$2.writeField(RobustReflectionConverter.java:211)
            	... 24 more
            
            Show
            jglick Jesse Glick added a comment - Confirmed to occur in production using Pipeline 1.14.1 on 1.625.x: … WARNING j.u.ErrorLoggingScheduledThreadPoolExecutor#afterExecute: failure in task not wrapped in SafeTimerTaskjava.lang.RuntimeException: Failed to serialize org.jenkinsci.plugins.workflow.job.WorkflowRun#execution for class org.jenkinsci.plugins.workflow.job.WorkflowRun at hudson.util.RobustReflectionConverter$2.writeField(RobustReflectionConverter.java:215) at hudson.util.RobustReflectionConverter$2.visit(RobustReflectionConverter.java:183) at com.thoughtworks.xstream.converters.reflection.PureJavaReflectionProvider.visitSerializableFields(PureJavaReflectionProvider.java:138) at hudson.util.RobustReflectionConverter.doMarshal(RobustReflectionConverter.java:168) at hudson.util.RobustReflectionConverter.marshal(RobustReflectionConverter.java:109) at com.thoughtworks.xstream.core.AbstractReferenceMarshaller.convert(AbstractReferenceMarshaller.java:69) at com.thoughtworks.xstream.core.TreeMarshaller.convertAnother(TreeMarshaller.java:58) at com.thoughtworks.xstream.core.TreeMarshaller.convertAnother(TreeMarshaller.java:43) at com.thoughtworks.xstream.core.TreeMarshaller.start(TreeMarshaller.java:82) at com.thoughtworks.xstream.core.AbstractTreeMarshallingStrategy.marshal(AbstractTreeMarshallingStrategy.java:37) at com.thoughtworks.xstream.XStream.marshal(XStream.java:1026) at com.thoughtworks.xstream.XStream.marshal(XStream.java:1015) at com.thoughtworks.xstream.XStream.toXML(XStream.java:988) at hudson.XmlFile.write(XmlFile.java:178) at hudson.model.Run.save(Run.java:1901) at org.jenkinsci.plugins.workflow.job.WorkflowRun.copyLogs(WorkflowRun.java:397) at org.jenkinsci.plugins.workflow.job.WorkflowRun.access$600(WorkflowRun.java:111) at org.jenkinsci.plugins.workflow.job.WorkflowRun$3.run(WorkflowRun.java:265) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) Caused by: java.util.ConcurrentModificationException at java.util.HashMap$HashIterator.nextNode(HashMap.java:1429) at java.util.HashMap$EntryIterator.next(HashMap.java:1463) at java.util.HashMap$EntryIterator.next(HashMap.java:1461) at com.thoughtworks.xstream.converters.collections.MapConverter.marshal(MapConverter.java:75) at com.thoughtworks.xstream.core.AbstractReferenceMarshaller.convert(AbstractReferenceMarshaller.java:69) at com.thoughtworks.xstream.core.TreeMarshaller.convertAnother(TreeMarshaller.java:58) at com.thoughtworks.xstream.core.TreeMarshaller.convertAnother(TreeMarshaller.java:43) at com.thoughtworks.xstream.core.AbstractReferenceMarshaller$1.convertAnother(AbstractReferenceMarshaller.java:88) at org.jenkinsci.plugins.workflow.cps.CpsFlowExecution$ConverterImpl.writeChild(CpsFlowExecution.java:949) at org.jenkinsci.plugins.workflow.cps.CpsFlowExecution$ConverterImpl.marshal(CpsFlowExecution.java:925) at hudson.util.XStream2$AssociatedConverterImpl.marshal(XStream2.java:361) at com.thoughtworks.xstream.core.AbstractReferenceMarshaller.convert(AbstractReferenceMarshaller.java:69) at com.thoughtworks.xstream.core.TreeMarshaller.convertAnother(TreeMarshaller.java:58) at com.thoughtworks.xstream.core.AbstractReferenceMarshaller$1.convertAnother(AbstractReferenceMarshaller.java:84) at hudson.util.RobustReflectionConverter.marshallField(RobustReflectionConverter.java:224) at hudson.util.RobustReflectionConverter$2.writeField(RobustReflectionConverter.java:211) ... 24 more
            Hide
            jglick Jesse Glick added a comment -

            Codehaus is dead, and I cannot find a new location for XSTR-744, but mail archives can be found here.

            Show
            jglick Jesse Glick added a comment - Codehaus is dead, and I cannot find a new location for XSTR-744, but mail archives can be found here .
            Hide
            jglick Jesse Glick added a comment -

            XStream2 could be a façade which keeps a per-thread pool of actual implementations

            Though this could introduce its own performance problems, if you have a lot of threads coming online and newly needing instances: initialization is not so cheap.

            The alternative is to not call AnnotationMapper.autodetectAnnotations, but this implies either not honoring XStream annotations (incompatible for some plugins—example), or processing them when the plugin is loaded (not practical without some way of quickly finding annotated classes without scanning every class file).

            Rather than a ThreadLocal it might be better to have an unbounded pool of instances. When a method is called and the pool is empty, a new instance would be created; otherwise an instance would be withdrawn from the pool. When the method completes the instance would be returned to the pool.

            Show
            jglick Jesse Glick added a comment - XStream2 could be a façade which keeps a per-thread pool of actual implementations Though this could introduce its own performance problems, if you have a lot of threads coming online and newly needing instances: initialization is not so cheap. The alternative is to not call AnnotationMapper.autodetectAnnotations , but this implies either not honoring XStream annotations (incompatible for some plugins— example ), or processing them when the plugin is loaded (not practical without some way of quickly finding annotated classes without scanning every class file). Rather than a ThreadLocal it might be better to have an unbounded pool of instances. When a method is called and the pool is empty, a new instance would be created; otherwise an instance would be withdrawn from the pool. When the method completes the instance would be returned to the pool.
            Hide
            jglick Jesse Glick added a comment -

            AFAICT these are our patches. Note in particular the addition of synchronized to DefaultConverterLookup.lookupConverterForType, which can cause deadlocks and monitor contention.

            Show
            jglick Jesse Glick added a comment - AFAICT these are our patches . Note in particular the addition of synchronized to DefaultConverterLookup.lookupConverterForType , which can cause deadlocks and monitor contention.
            Hide
            jglick Jesse Glick added a comment -

            The above ConcurrentModificationException may actually be some unrelated problem in a non-thread-safe Map-valued field somewhere. Currently RobustMapConverter does not override marshal to catch that and report it in a helpful manner. Looks like the same could be true of RobustCollectionConverter.

            My current thinking on the thread-safe variant would be to subclass XStream2 and override various marshal, unmarshal, toXML, and fromXML overloads to delegate to a pooled instance, initialized with a copy of all various fields like ConverterLookup. Not perfect since calls to alias and the like which happened concurrently with reading or writing could still cause problems, but this is much less likely than race conditions initializing annotation-based metadata. Not sure how to reproduce the original problems in a test, though. Maybe it would suffice to just try replacing the version of XStream in Jenkins with a stock one and seeing what tests fail or flake.

            Show
            jglick Jesse Glick added a comment - The above ConcurrentModificationException may actually be some unrelated problem in a non-thread-safe Map -valued field somewhere. Currently RobustMapConverter does not override marshal to catch that and report it in a helpful manner. Looks like the same could be true of RobustCollectionConverter . My current thinking on the thread-safe variant would be to subclass XStream2 and override various marshal , unmarshal , toXML , and fromXML overloads to delegate to a pooled instance, initialized with a copy of all various fields like ConverterLookup . Not perfect since calls to alias and the like which happened concurrently with reading or writing could still cause problems, but this is much less likely than race conditions initializing annotation-based metadata. Not sure how to reproduce the original problems in a test, though. Maybe it would suffice to just try replacing the version of XStream in Jenkins with a stock one and seeing what tests fail or flake.
            Hide
            gareth_western Gareth Western added a comment - - edited

            I believe that this is a known issue in the X-Stream library. Hopefully it will be addressed soon.

            Show
            gareth_western Gareth Western added a comment - - edited I believe that this is a known issue in the X-Stream library . Hopefully it will be addressed soon.
            Hide
            jglick Jesse Glick added a comment -

            Gareth Western while there may be bugs in XStream which affect Jenkins, the basic issue here is a bug in Jenkins: it is using XStream in a way that is explicitly listed as unsupported.

            Show
            jglick Jesse Glick added a comment - Gareth Western while there may be bugs in XStream which affect Jenkins, the basic issue here is a bug in Jenkins: it is using XStream in a way that is explicitly listed as unsupported.
            Hide
            jglick Jesse Glick added a comment -

            Sam Van Oort I consider this a defect, not an “improvement”: Jenkins is violating the XStream usage guidelines at its peril.

            Show
            jglick Jesse Glick added a comment - Sam Van Oort I consider this a defect, not an “improvement”: Jenkins is violating the XStream usage guidelines at its peril.
            Hide
            conf Alexey Shein added a comment -

            Any news on this one? Is there anything that can be done from my (user's) side to help? It causes serious Jenkins degradation issues for us

            Show
            conf Alexey Shein added a comment - Any news on this one? Is there anything that can be done from my (user's) side to help? It causes serious Jenkins degradation issues for us
            Hide
            jglick Jesse Glick added a comment -

            Is there anything that can be done from my (user's) side to help?

            Not that I can think of.

            Show
            jglick Jesse Glick added a comment - Is there anything that can be done from my (user's) side to help? Not that I can think of.
            Show
            jglick Jesse Glick added a comment - https://x-stream.github.io/annotations-tutorial.html#AutoDetect
            Hide
            jglick Jesse Glick added a comment -

            jenkins #4944 should address this.

            Show
            jglick Jesse Glick added a comment - jenkins #4944 should address this.
            Hide
            jglick Jesse Glick added a comment -

            The CME in InputStepExecution.postSettlement may have been fixed by https://github.com/jenkinsci/pipeline-plugin/pull/309/commits/52ddff0780f577b911b4780b6f9c1e09e752337c.

            The WorkflowRun#execution looks similar to the error purportedly fixed by https://github.com/jenkinsci/pipeline-plugin/commit/1d5797c49a8f0edb6064b55143614a2da4c207d4; I do not recall seeing anything like it recently.

            Show
            jglick Jesse Glick added a comment - The CME in InputStepExecution.postSettlement may have been fixed by https://github.com/jenkinsci/pipeline-plugin/pull/309/commits/52ddff0780f577b911b4780b6f9c1e09e752337c . The WorkflowRun#execution looks similar to the error purportedly fixed by https://github.com/jenkinsci/pipeline-plugin/commit/1d5797c49a8f0edb6064b55143614a2da4c207d4 ; I do not recall seeing anything like it recently.

              People

              Assignee:
              jglick Jesse Glick
              Reporter:
              mp3 Mikko Peltonen
              Votes:
              7 Vote for this issue
              Watchers:
              15 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved: