Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Random p2/PGP fails on "Installing org.eclipse.wtp.releng.tools.feature.feature.group" #268

Closed
iloveeclipse opened this issue May 17, 2023 · 9 comments
Closed

Random p2/PGP fails on "Installing org.eclipse.wtp.releng.tools.feature.feature.group" #268

iloveeclipse opened this issue May 17, 2023 · 9 comments

Comments

@iloveeclipse
Copy link
Member

We observe periodic build fails in https://ci.eclipse.org/releng/job/Releng/job/ep-collectResults/ job, see eclipse-platform/eclipse.platform.releng.aggregator#1075

Two last fails were caused by errors reported in p2 / PGP code, so opening issue here to investigate.

https://ci.eclipse.org/releng/job/Releng/job/ep-collectResults/1322/console

05:16:20 Installing org.eclipse.wtp.releng.tools.feature.feature.group 1.2.0.v201902122017.
05:16:22 !SESSION 2023-05-16 23:15:55.677 -----------------------------------------------
05:16:22 eclipse.buildId=4.27.0.I20230302-0300
05:16:22 java.version=11.0.18
05:16:22 java.vendor=Ubuntu
05:16:22 BootLoader constants: OS=linux, ARCH=x86_64, WS=gtk, NL=en
05:16:22 Framework arguments:  -application org.eclipse.equinox.p2.director -repository https://download.eclipse.org/eclipse/updates/4.28-I-builds/,https://download.eclipse.org/eclipse/updates/buildtools/,https://download.eclipse.org/webtools/downloads/drops/R3.27.0/R-3.27.0-20220829002010/repositoryunittests/ -installIU org.eclipse.platform.ide,org.eclipse.pde.api.tools,org.eclipse.releng.build.tools.feature.feature.group,org.eclipse.wtp.releng.tools.feature.feature.group -destination /home/data/httpd/download.eclipse.org/eclipse/workingDir/ep-collectResults-1322/basebuilder -profile SDKProfile
05:16:22 Command-line arguments:  -os linux -ws gtk -arch x86_64 -debug -consolelog -data /home/data/httpd/download.eclipse.org/eclipse/workingDir/ep-collectResults-1322/workspace-toolsinstall -application org.eclipse.equinox.p2.director -repository https://download.eclipse.org/eclipse/updates/4.28-I-builds/,https://download.eclipse.org/eclipse/updates/buildtools/,https://download.eclipse.org/webtools/downloads/drops/R3.27.0/R-3.27.0-20220829002010/repositoryunittests/ -installIU org.eclipse.platform.ide,org.eclipse.pde.api.tools,org.eclipse.releng.build.tools.feature.feature.group,org.eclipse.wtp.releng.tools.feature.feature.group -destination /home/data/httpd/download.eclipse.org/eclipse/workingDir/ep-collectResults-1322/basebuilder -profile SDKProfile
05:16:22 
05:16:22 !ENTRY org.eclipse.equinox.p2.director 0 0 2023-05-16 23:16:22.311
05:16:22 !MESSAGE Overall install request is satisfiable
05:16:22 !SUBENTRY 1 org.eclipse.equinox.p2.director 0 0 2023-05-16 23:16:22.313
05:16:22 !MESSAGE Add request for Eclipse Platform releng build tools 1.1.0.v20230221-0840 (org.eclipse.releng.build.tools.feature.feature.group 1.1.0.v20230221-0840) is satisfiable
05:16:22 !SUBENTRY 1 org.eclipse.equinox.p2.director 0 0 2023-05-16 23:16:22.313
05:16:22 !MESSAGE Add request for Eclipse Platform 4.28.0.I20230516-1800 (org.eclipse.platform.ide 4.28.0.I20230516-1800) is satisfiable
05:16:22 !SUBENTRY 1 org.eclipse.equinox.p2.director 0 0 2023-05-16 23:16:22.313
05:16:22 !MESSAGE Add request for Releng Tools Feature 1.2.0.v201902122017 (org.eclipse.wtp.releng.tools.feature.feature.group 1.2.0.v201902122017) is satisfiable
05:16:22 !SUBENTRY 1 org.eclipse.equinox.p2.director 0 0 2023-05-16 23:16:22.313
05:16:22 !MESSAGE Add request for API Tools 1.3.0.v20230501-1515 (org.eclipse.pde.api.tools 1.3.0.v20230501-1515) is satisfiable
05:16:54 
05:16:54 !ENTRY org.eclipse.equinox.p2.artifact.repository 4 0 2023-05-16 23:16:54.350
05:16:54 !MESSAGE Iterator failed to get next object: invalid armor
05:16:54 !STACK 0
05:16:54 org.bouncycastle.openpgp.PGPRuntimeOperationException: Iterator failed to get next object: invalid armor
05:16:54 	at org.bouncycastle.openpgp.PGPObjectFactory$1.getObject(Unknown Source)
05:16:54 	at org.bouncycastle.openpgp.PGPObjectFactory$1.hasNext(Unknown Source)
05:16:54 	at java.base/java.lang.Iterable.forEach(Iterable.java:74)
05:16:54 	at org.eclipse.equinox.internal.p2.artifact.processors.pgp.PGPPublicKeyStore.readPublicKeys(PGPPublicKeyStore.java:101)
05:16:54 	at org.eclipse.equinox.internal.p2.engine.phases.CertificateChecker.checkCertificates(CertificateChecker.java:219)
05:16:54 	at org.eclipse.equinox.internal.p2.engine.phases.CertificateChecker.start(CertificateChecker.java:119)
05:16:54 	at org.eclipse.equinox.internal.p2.engine.phases.CheckTrust.completePhase(CheckTrust.java:64)
05:16:54 	at org.eclipse.equinox.internal.p2.engine.Phase.postPerform(Phase.java:254)
05:16:54 	at org.eclipse.equinox.internal.p2.engine.Phase.perform(Phase.java:105)
05:16:54 	at org.eclipse.equinox.internal.p2.engine.PhaseSet.perform(PhaseSet.java:50)
05:16:54 	at org.eclipse.equinox.internal.p2.engine.Engine.perform(Engine.java:80)
05:16:54 	at org.eclipse.equinox.internal.p2.engine.Engine.perform(Engine.java:48)
05:16:54 	at org.eclipse.equinox.internal.provisional.p2.director.PlanExecutionHelper.executePlan(PlanExecutionHelper.java:48)
05:16:54 	at org.eclipse.equinox.internal.provisional.p2.director.PlanExecutionHelper.executePlan(PlanExecutionHelper.java:28)
05:16:54 	at org.eclipse.equinox.internal.p2.director.app.DirectorApplication.executePlan(DirectorApplication.java:788)
05:16:54 	at org.eclipse.equinox.internal.p2.director.app.DirectorApplication.planAndExecute(DirectorApplication.java:778)
05:16:54 	at org.eclipse.equinox.internal.p2.director.app.DirectorApplication.performProvisioningActions(DirectorApplication.java:759)
05:16:54 	at org.eclipse.equinox.internal.p2.director.app.DirectorApplication.run(DirectorApplication.java:1082)
05:16:54 	at org.eclipse.equinox.internal.p2.director.app.DirectorApplication.start(DirectorApplication.java:1220)
05:16:54 	at org.eclipse.equinox.internal.app.EclipseAppHandle.run(EclipseAppHandle.java:203)
05:16:54 	at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication(EclipseAppLauncher.java:136)
05:16:54 	at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start(EclipseAppLauncher.java:104)
05:16:54 	at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:402)
05:16:54 	at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:255)
05:16:54 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
05:16:54 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
05:16:54 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
05:16:54 	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
05:16:54 	at org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:659)
05:16:54 	at org.eclipse.equinox.launcher.Main.basicRun(Main.java:596)
05:16:54 	at org.eclipse.equinox.launcher.Main.run(Main.java:1467)
05:16:54 	at org.eclipse.equinox.launcher.Main.main(Main.java:1440)
05:16:54 Caused by: java.io.IOException: invalid armor
05:16:54 	at org.bouncycastle.bcpg.ArmoredInputStream.decode(Unknown Source)
05:16:54 	at org.bouncycastle.bcpg.ArmoredInputStream.read(Unknown Source)
05:16:54 	at org.bouncycastle.bcpg.ArmoredInputStream.read(Unknown Source)
05:16:54 	at org.bouncycastle.bcpg.BCPGInputStream.read(Unknown Source)
05:16:54 	at org.bouncycastle.bcpg.BCPGInputStream$PartialInputStream.read(Unknown Source)
05:16:54 	at java.base/java.io.BufferedInputStream.fill(BufferedInputStream.java:252)
05:16:54 	at java.base/java.io.BufferedInputStream.read(BufferedInputStream.java:271)
05:16:54 	at org.bouncycastle.bcpg.BCPGInputStream.read(Unknown Source)
05:16:54 	at org.bouncycastle.bcpg.PublicKeyPacket.<init>(Unknown Source)
05:16:54 	at org.bouncycastle.bcpg.PublicSubkeyPacket.<init>(Unknown Source)
05:16:54 	at org.bouncycastle.bcpg.BCPGInputStream.readPacket(Unknown Source)
05:16:54 	at org.bouncycastle.openpgp.PGPPublicKeyRing.readPublicKeyPacket(Unknown Source)
05:16:54 	at org.bouncycastle.openpgp.PGPPublicKeyRing.readSubkey(Unknown Source)
05:16:54 	at org.bouncycastle.openpgp.PGPObjectFactory.nextObject(Unknown Source)
05:16:54 	... 32 more
05:17:04 Installation failed.
05:17:04 An error occurred while installing the items
05:17:04 	session context was:(profile=SDKProfile, phase=org.eclipse.equinox.internal.p2.engine.phases.Install, operand=null --> [R]org.eclipse.jface 3.30.0.v20230509-0720, action=org.eclipse.equinox.internal.p2.touchpoint.eclipse.actions.InstallBundleAction).
05:17:04 	The artifact file for osgi.bundle,org.eclipse.jface,3.30.0.v20230509-0720 was not found.

https://ci.eclipse.org/releng/job/Releng/job/ep-collectResults/1323/console

05:27:56 Installing org.eclipse.wtp.releng.tools.feature.feature.group 1.2.0.v201902122017.
05:27:58 !SESSION 2023-05-16 23:27:32.335 -----------------------------------------------
05:27:58 eclipse.buildId=4.27.0.I20230302-0300
05:27:58 java.version=11.0.18
05:27:58 java.vendor=Ubuntu
05:27:58 BootLoader constants: OS=linux, ARCH=x86_64, WS=gtk, NL=en
05:27:58 Framework arguments:  -application org.eclipse.equinox.p2.director -repository https://download.eclipse.org/eclipse/updates/4.28-I-builds/,https://download.eclipse.org/eclipse/updates/buildtools/,https://download.eclipse.org/webtools/downloads/drops/R3.27.0/R-3.27.0-20220829002010/repositoryunittests/ -installIU org.eclipse.platform.ide,org.eclipse.pde.api.tools,org.eclipse.releng.build.tools.feature.feature.group,org.eclipse.wtp.releng.tools.feature.feature.group -destination /home/data/httpd/download.eclipse.org/eclipse/workingDir/ep-collectResults-1323/basebuilder -profile SDKProfile
05:27:58 Command-line arguments:  -os linux -ws gtk -arch x86_64 -debug -consolelog -data /home/data/httpd/download.eclipse.org/eclipse/workingDir/ep-collectResults-1323/workspace-toolsinstall -application org.eclipse.equinox.p2.director -repository https://download.eclipse.org/eclipse/updates/4.28-I-builds/,https://download.eclipse.org/eclipse/updates/buildtools/,https://download.eclipse.org/webtools/downloads/drops/R3.27.0/R-3.27.0-20220829002010/repositoryunittests/ -installIU org.eclipse.platform.ide,org.eclipse.pde.api.tools,org.eclipse.releng.build.tools.feature.feature.group,org.eclipse.wtp.releng.tools.feature.feature.group -destination /home/data/httpd/download.eclipse.org/eclipse/workingDir/ep-collectResults-1323/basebuilder -profile SDKProfile
05:27:58 
05:27:58 !ENTRY org.eclipse.equinox.p2.director 0 0 2023-05-16 23:27:58.900
05:27:58 !MESSAGE Overall install request is satisfiable
05:27:58 !SUBENTRY 1 org.eclipse.equinox.p2.director 0 0 2023-05-16 23:27:58.902
05:27:58 !MESSAGE Add request for Eclipse Platform releng build tools 1.1.0.v20230221-0840 (org.eclipse.releng.build.tools.feature.feature.group 1.1.0.v20230221-0840) is satisfiable
05:27:58 !SUBENTRY 1 org.eclipse.equinox.p2.director 0 0 2023-05-16 23:27:58.903
05:27:58 !MESSAGE Add request for Eclipse Platform 4.28.0.I20230516-1800 (org.eclipse.platform.ide 4.28.0.I20230516-1800) is satisfiable
05:27:58 !SUBENTRY 1 org.eclipse.equinox.p2.director 0 0 2023-05-16 23:27:58.903
05:27:58 !MESSAGE Add request for Releng Tools Feature 1.2.0.v201902122017 (org.eclipse.wtp.releng.tools.feature.feature.group 1.2.0.v201902122017) is satisfiable
05:27:58 !SUBENTRY 1 org.eclipse.equinox.p2.director 0 0 2023-05-16 23:27:58.903
05:27:58 !MESSAGE Add request for API Tools 1.3.0.v20230501-1515 (org.eclipse.pde.api.tools 1.3.0.v20230501-1515) is satisfiable
05:28:35 
05:28:35 !ENTRY org.eclipse.equinox.p2.artifact.repository 4 0 2023-05-16 23:28:35.219
05:28:35 !MESSAGE Iterator failed to get next object: null
05:28:35 !STACK 0
05:28:35 org.bouncycastle.openpgp.PGPRuntimeOperationException: Iterator failed to get next object: null
05:28:35 	at org.bouncycastle.openpgp.PGPObjectFactory$1.getObject(Unknown Source)
05:28:35 	at org.bouncycastle.openpgp.PGPObjectFactory$1.hasNext(Unknown Source)
05:28:35 	at java.base/java.lang.Iterable.forEach(Iterable.java:74)
05:28:35 	at org.eclipse.equinox.internal.p2.artifact.processors.pgp.PGPPublicKeyStore.readPublicKeys(PGPPublicKeyStore.java:101)
05:28:35 	at org.eclipse.equinox.internal.p2.engine.phases.CertificateChecker.checkCertificates(CertificateChecker.java:219)
05:28:35 	at org.eclipse.equinox.internal.p2.engine.phases.CertificateChecker.start(CertificateChecker.java:119)
05:28:35 	at org.eclipse.equinox.internal.p2.engine.phases.CheckTrust.completePhase(CheckTrust.java:64)
05:28:35 	at org.eclipse.equinox.internal.p2.engine.Phase.postPerform(Phase.java:254)
05:28:35 	at org.eclipse.equinox.internal.p2.engine.Phase.perform(Phase.java:105)
05:28:35 	at org.eclipse.equinox.internal.p2.engine.PhaseSet.perform(PhaseSet.java:50)
05:28:35 	at org.eclipse.equinox.internal.p2.engine.Engine.perform(Engine.java:80)
05:28:35 	at org.eclipse.equinox.internal.p2.engine.Engine.perform(Engine.java:48)
05:28:35 	at org.eclipse.equinox.internal.provisional.p2.director.PlanExecutionHelper.executePlan(PlanExecutionHelper.java:48)
05:28:35 	at org.eclipse.equinox.internal.provisional.p2.director.PlanExecutionHelper.executePlan(PlanExecutionHelper.java:28)
05:28:35 	at org.eclipse.equinox.internal.p2.director.app.DirectorApplication.executePlan(DirectorApplication.java:788)
05:28:35 	at org.eclipse.equinox.internal.p2.director.app.DirectorApplication.planAndExecute(DirectorApplication.java:778)
05:28:35 	at org.eclipse.equinox.internal.p2.director.app.DirectorApplication.performProvisioningActions(DirectorApplication.java:759)
05:28:35 	at org.eclipse.equinox.internal.p2.director.app.DirectorApplication.run(DirectorApplication.java:1082)
05:28:35 	at org.eclipse.equinox.internal.p2.director.app.DirectorApplication.start(DirectorApplication.java:1220)
05:28:35 	at org.eclipse.equinox.internal.app.EclipseAppHandle.run(EclipseAppHandle.java:203)
05:28:35 	at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication(EclipseAppLauncher.java:136)
05:28:35 	at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start(EclipseAppLauncher.java:104)
05:28:35 	at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:402)
05:28:35 	at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:255)
05:28:35 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
05:28:35 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
05:28:35 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
05:28:35 	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
05:28:35 	at org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:659)
05:28:35 	at org.eclipse.equinox.launcher.Main.basicRun(Main.java:596)
05:28:35 	at org.eclipse.equinox.launcher.Main.run(Main.java:1467)
05:28:35 	at org.eclipse.equinox.launcher.Main.main(Main.java:1440)
05:28:35 Caused by: java.io.EOFException
05:28:35 	at org.bouncycastle.bcpg.BCPGInputStream.readFully(Unknown Source)
05:28:35 	at org.bouncycastle.bcpg.BCPGInputStream.readFully(Unknown Source)
05:28:35 	at org.bouncycastle.bcpg.MPInteger.<init>(Unknown Source)
05:28:35 	at org.bouncycastle.bcpg.RSAPublicBCPGKey.<init>(Unknown Source)
05:28:35 	at org.bouncycastle.bcpg.PublicKeyPacket.<init>(Unknown Source)
05:28:35 	at org.bouncycastle.bcpg.PublicSubkeyPacket.<init>(Unknown Source)
05:28:35 	at org.bouncycastle.bcpg.BCPGInputStream.readPacket(Unknown Source)
05:28:35 	at org.bouncycastle.openpgp.PGPPublicKeyRing.readPublicKeyPacket(Unknown Source)
05:28:35 	at org.bouncycastle.openpgp.PGPPublicKeyRing.readSubkey(Unknown Source)
05:28:35 	at org.bouncycastle.openpgp.PGPObjectFactory.nextObject(Unknown Source)
05:28:35 	... 32 more
05:28:39 Installation failed.
05:28:39 An error occurred while installing the items
05:28:39 	session context was:(profile=SDKProfile, phase=org.eclipse.equinox.internal.p2.engine.phases.Install, operand=null --> [R]org.eclipse.equinox.jsp.jasper.registry 1.2.100.v20211021-1418, action=org.eclipse.equinox.internal.p2.touchpoint.eclipse.actions.InstallBundleAction).
05:28:39 	The artifact file for osgi.bundle,org.eclipse.equinox.jsp.jasper.registry,1.2.100.v20211021-1418 was not found.
05:28:39 
05:28:39 !ENTRY org.eclipse.equinox.p2.engine 4 4 2023-05-16 23:28:39.588
05:28:39 !MESSAGE An error occurred while installing the items
05:28:39 !SUBENTRY 1 org.eclipse.equinox.p2.engine 4 0 2023-05-16 23:28:39.593
05:28:39 !MESSAGE session context was:(profile=SDKProfile, phase=org.eclipse.equinox.internal.p2.engine.phases.Install, operand=null --> [R]org.eclipse.equinox.jsp.jasper.registry 1.2.100.v20211021-1418, action=org.eclipse.equinox.internal.p2.touchpoint.eclipse.actions.InstallBundleAction).
05:28:39 !SUBENTRY 1 org.eclipse.equinox.p2.touchpoint.eclipse 4 0 2023-05-16 23:28:39.593
05:28:39 !MESSAGE The artifact file for osgi.bundle,org.eclipse.equinox.jsp.jasper.registry,1.2.100.v20211021-1418 was not found.
05:28:39 There were errors. See log file: /home/data/httpd/download.eclipse.org/eclipse/workingDir/ep-collectResults-1323/workspace-toolsinstall/.metadata/.log
@iloveeclipse iloveeclipse mentioned this issue May 17, 2023
Open
@merks
Copy link
Contributor

merks commented May 17, 2023

At this point in the code, we know the string value being processed so we'd have more information about what's wrong if we included the string in the logged message, e.g, like this:

image

WDYT?

@iloveeclipse
Copy link
Member Author

Sore, if that would give more insights, why not?

I wonder if there is some kind of network issues at eclipse.org infra and that the data is only partially downloaded to disk.

  • Is there a way to validate the pgp content if that is in "proper" format or incomplete somehow?
  • Is there a way to retry the operation and fetch that data one more time in case we would see a sign it could be incomplete?

@merks
Copy link
Contributor

merks commented May 17, 2023

My sense is that some partial data is involved, but given this (artifacts.xml) comes from jar/xml.xz, I don't think it can be partially complete and still unpack. This (bouncy castle) logic does validate that the content is well-formed... If we could see the string, we could get a sense of how it looks wrong. Note that this logic just logs the exception and returns an empty set. The failure is happens because there is a signature that cannot be verified for lack of a key...

Should I try add this information for M3? The runway is getting short...

@merks
Copy link
Contributor

merks commented May 17, 2023

@iloveeclipse

I take it that trying to change this for M3 is too late.

@iloveeclipse
Copy link
Member Author

Note that this logic just logs the exception and returns an empty set. The failure is happens because there is a signature that cannot be verified for lack of a key...

But that is not reported anywhere?

I take it that trying to change this for M3 is too late.

Adding extra data to logs can be done for RC builds, as long as the changes are "small" and reviewed :-)

@merks
Copy link
Contributor

merks commented May 17, 2023

If you have a way to reproduce the problem I'll given a full explanation. :-P

The whole thing likely to be a red-herring where there is some other corruption involved and this is just a symptom, and the stack traces don't line up with the latest code in CertificateChecker, which hasn't changed in 5 weeks.

@iloveeclipse
Copy link
Member Author

the stack traces don't line up with the latest code in CertificateChecker

Probably to be addressed in eclipse-platform/eclipse.platform.releng.aggregator#1075
I assume we use some older platform version to run these tasks? may be we should update?

@iloveeclipse
Copy link
Member Author

If you have a way to reproduce the problem I'll given a full explanation

Interestingly, the fails stopped immediately after I've reported this ticket (and were failing almost every day before).
So it seems it is enough to open a ticket to fix an infra issue :-)
Ed, feel free to close if you do not plan any work here.

@merks
Copy link
Contributor

merks commented May 23, 2023

Sometimes I get the feeling that a partially published I-build is visible. Very infrequently the maven publishing build fails getting artifacts. Let’s keep our fingers crossed. 🤞

@merks merks closed this as completed May 23, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@merks @iloveeclipse