[ODLPARENT-88] Testing of one karaf4 feature may take more than 10 minutes Created: 28/Apr/17  Updated: 06/Sep/21  Resolved: 06/Sep/21

Status: Resolved
Project: odlparent
Component/s: General
Affects Version/s: 2.0.5
Fix Version/s: None

Type: Bug
Reporter: Miroslav Kovac Assignee: Unassigned
Resolution: Cannot Reproduce Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Operating System: All
Platform: All

Issue Links:
Duplicate
is duplicated by ODLPARENT-89 SingleFeatureTest does not always tim... Resolved
External issue ID: 8333

 Description   

A good examples of this bug would be [1],[2]. Basicly singleFeatureTest somethimes failes just with - Build timed out (after 360 minutes). Marking the build as failed - which is timeout for whole build. Maximum time for one feature should be 10 minutes, But in those two examples you can see that time exceeds this 10 mins by far more.

[1] https://jenkins.opendaylight.org/releng/job/netconf-verify-carbon-mvn33-openjdk8/1685/console
[2] https://jenkins.opendaylight.org/releng/job/netconf-verify-carbon-mvn33-openjdk8/1678/console

 Comments   
Comment by Robert Varga [ 04/May/17 ]

https://logs.opendaylight.org/releng/jenkins092/netconf-verify-carbon-mvn33-openjdk8/1685/archives/features/netconf-connector/odl-netconf-connector-all/target/surefire-reports/org.opendaylight.odlparent.featuretest.SingleFeatureTest-output.txt.gz

This looks like the test itself failed in ~10 minutes:

2017-04-28 08:23:59,907 | ERROR | ime-limited test | SingleFeatureTest | 73 - PAXEXAM-PROBE-5faad4d3-3ec4-47f8-b247-0e475d126ba5 - 0.0.0 | installFeature() failed
java.lang.InterruptedException
at java.util.concurrent.FutureTask.awaitDone(FutureTask.java:404)[:1.8.0_121]
at java.util.concurrent.FutureTask.get(FutureTask.java:191)[:1.8.0_121]
at org.apache.karaf.features.internal.service.FeaturesServiceImpl.doProvisionInThread(FeaturesServiceImpl.java:1077)[8:org.apache.karaf.features.core:4.0.9]
at org.apache.karaf.features.internal.service.FeaturesServiceImpl.installFeatures(FeaturesServiceImpl.java:954)[8:org.apache.karaf.features.core:4.0.9]
at org.apache.karaf.features.internal.service.FeaturesServiceImpl.installFeatures(FeaturesServiceImpl.java:847)[8:org.apache.karaf.features.core:4.0.9]
at org.apache.karaf.features.internal.service.FeaturesServiceImpl.installFeature(FeaturesServiceImpl.java:832)[8:org.apache.karaf.features.core:4.0.9]
at org.apache.karaf.features.internal.service.FeaturesServiceImpl.installFeature(FeaturesServiceImpl.java:837)[8:org.apache.karaf.features.core:4.0.9]
at org.opendaylight.odlparent.featuretest.SingleFeatureTest.installFeature(SingleFeatureTest.java:368)
at org.opendaylight.odlparent.featuretest.SingleFeatureTest.installFeatureCatchAndLog(SingleFeatureTest.java:338)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)[:1.8.0_121]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)[:1.8.0_121]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)[:1.8.0_121]
at java.lang.reflect.Method.invoke(Method.java:498)[:1.8.0_121]
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)[71:org.ops4j.pax.tipi.junit:4.12.0.1]
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)[71:org.ops4j.pax.tipi.junit:4.12.0.1]
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)[71:org.ops4j.pax.tipi.junit:4.12.0.1]
at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)[71:org.ops4j.pax.tipi.junit:4.12.0.1]
at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:298)[71:org.ops4j.pax.tipi.junit:4.12.0.1]
at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:292)[71:org.ops4j.pax.tipi.junit:4.12.0.1]
at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_121]
at java.lang.Thread.run(Thread.java:745)[:1.8.0_121]

after which the container started stopping, but it seems the shutdown process hung on:

2017-04-28 08:24:01,019 | INFO | Framework stop | Activator | 330 - org.ops4j.pax.web.pax-web-extender-war - 4.3.0 | Destroying extension for bundle org.opendaylight.aaa.idmlight

Comment by Robert Varga [ 04/May/17 ]

On odlparent side, we probably should instruct pax-exam to hard-kill the container after a installFeature() timeout.

Furthermore we should dump the bundle status to identify who is holding up the startup.

Comment by Michael Vorburger [ 04/May/17 ]

> On odlparent side, we probably should instruct pax-exam to
> hard-kill the container after a installFeature() timeout.

Hm, is there a ready-made option for this? I don't recall seeing one..

This may be more than 3' of work and require contributing to PAX?

> Furthermore we should dump the bundle status to
> identify who is holding up the startup.

Following https://git.opendaylight.org/gerrit/#/c/51908/, normally this should already happen? It won't dump the status just when it times out, but normally should have just before? (Using Awaitility, I'm not sure we can do the dump just before the timeout; we may have to make a contribution to Awaitility [or justwrite the spin loop ourselves]; or perhaps we can catch InterruptedException and dump there. But having it just a little earlier in the log as is already may be sufficient?)

Comment by Robert Varga [ 06/Sep/21 ]

Most SFTs finish in under a minute. There really is not much we can do on testing side to speed things up.

Generated at Wed Feb 07 20:27:36 UTC 2024 using Jira 8.20.10#820010-sha1:ace47f9899e9ee25d7157d59aa17ab06aee30d3d.