Search code examples
jenkinsnexussonatype

Jenkins: nexusPolicyEvaluation fails with "Could not verify application public id from IQ Server"


I have Nexus IQ Plugin v.2.19.0-01 installed on my jenkins and calling the nexusPolicyEvaluation in the dsl pipeline as follows

nexusPolicyEvaluation failBuildOnNetworkError: true, iqApplication: 'TestApp', iqStage: 'build', jobCredentialsId: ''

This worked fine until today where I suddenly receive the following error:

org.apache.http.client.HttpResponseException: Resource not found, please check your request URL.
    at com.sonatype.nexus.api.m.a(SourceFile:60)
    at com.sonatype.nexus.api.m.a(SourceFile:65)
    at com.sonatype.nexus.api.n.a(SourceFile:67)
    at com.sonatype.nexus.api.cy.verifyOrCreateApplication(SourceFile:75)
Caused: com.sonatype.nexus.api.exception.IqClientException: Could not verify application public id from IQ Server
    at com.sonatype.nexus.api.cy.verifyOrCreateApplication(SourceFile:78)
    at com.sonatype.nexus.api.iq.IqClient$verifyOrCreateApplication.call(Unknown Source)
    at org.sonatype.nexus.ci.iq.IqPolicyEvaluatorUtil.evaluatePolicy(IqPolicyEvaluatorUtil.groovy:52)
    at org.sonatype.nexus.ci.iq.IqPolicyEvaluatorUtil$evaluatePolicy.call(Unknown Source)
    at org.sonatype.nexus.ci.iq.PolicyEvaluatorExecution.run(PolicyEvaluatorExecution.groovy:48)
    at org.sonatype.nexus.ci.iq.PolicyEvaluatorExecution.run(PolicyEvaluatorExecution.groovy)
    at org.jenkinsci.plugins.workflow.steps.SynchronousNonBlockingStepExecution$1$1.call(SynchronousNonBlockingStepExecution.java:49)
    at hudson.security.ACL.impersonate(ACL.java:260)
    at org.jenkinsci.plugins.workflow.steps.SynchronousNonBlockingStepExecution$1.run(SynchronousNonBlockingStepExecution.java:46)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    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:748)
Finished: FAILURE

There were no changes made to the call in the pipeline nor to the general settings in Jenkins - the url and credentials are correct and "Test Connection" is successful.

In addition I checked the IQ server, which is running and I actually get a valid response when issuing an web request

Invoke-WebRequest 'http://clm.mycompany.intra:8070/api/v2/applications?publicId=TestApp' -Headers $headers

Any clue how I can verify the url? I also do not find any useful information when googling for the errors. So I am a bit lost what could cause the problem.

Update 1: The application log clm-server.log on the IQ server tells me the following

2018-05-14 13:01:24,413+0200 DEBUG [qtp903987069-37 - GET /rest/policy/stages?context=ci]  org.apache.shiro.session.mgt.DefaultSessionManager - Unable to resolve session ID from SessionKey [org.apache.shiro.web.session.mgt.WebSessionKey@67c99f0c].  Returning null to indicate a session could not be found.
2018-05-14 13:01:24,413+0200 DEBUG [qtp903987069-37 - GET /rest/policy/stages?context=ci]  org.apache.shiro.web.servlet.OncePerRequestFilter - Filter 'reverseProxy' is not enabled for the current request.  Proceeding without invoking this filter.
2018-05-14 13:01:24,413+0200 DEBUG [qtp903987069-37 - GET /rest/policy/stages?context=ci]  org.apache.shiro.realm.AuthenticatingRealm - Looked up AuthenticationInfo [admin] from doGetAuthenticationInfo
2018-05-14 13:01:24,413+0200 DEBUG [qtp903987069-37 - GET /rest/policy/stages?context=ci]  org.apache.shiro.realm.AuthenticatingRealm - AuthenticationInfo caching is disabled for info [admin].  Submitted token: [org.apache.shiro.authc.UsernamePasswordToken - admin, rememberMe=false (10.120.16.12)].
2018-05-14 13:01:24,678+0200 DEBUG [qtp903987069-37 - GET /rest/policy/stages?context=ci]  org.apache.shiro.authc.AbstractAuthenticator - Authentication successful for token [org.apache.shiro.authc.UsernamePasswordToken - admin, rememberMe=false (10.120.16.12)].  Returned account [admin]
2018-05-14 13:01:24,678+0200 DEBUG [qtp903987069-37 - GET /rest/policy/stages?context=ci]  org.apache.shiro.subject.support.DefaultSubjectContext - No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
2018-05-14 13:01:24,678+0200 DEBUG [qtp903987069-37 - GET /rest/policy/stages?context=ci]  org.apache.shiro.subject.support.DefaultSubjectContext - No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
2018-05-14 13:01:24,678+0200 DEBUG [qtp903987069-37 - GET /rest/policy/stages?context=ci] admin com.sonatype.insight.brain.policy.LicensedStagesResource - Received request to get licensed stages for context ci
2018-05-14 13:01:24,725+0200 DEBUG [qtp903987069-33 - GET /rest/policy/stages?context=ci]  org.apache.shiro.session.mgt.DefaultSessionManager - Unable to resolve session ID from SessionKey [org.apache.shiro.web.session.mgt.WebSessionKey@40c8a5a8].  Returning null to indicate a session could not be found.
2018-05-14 13:01:24,725+0200 DEBUG [qtp903987069-33 - GET /rest/policy/stages?context=ci]  org.apache.shiro.web.servlet.OncePerRequestFilter - Filter 'reverseProxy' is not enabled for the current request.  Proceeding without invoking this filter.
2018-05-14 13:01:24,725+0200 DEBUG [qtp903987069-33 - GET /rest/policy/stages?context=ci]  org.apache.shiro.realm.AuthenticatingRealm - Looked up AuthenticationInfo [admin] from doGetAuthenticationInfo
2018-05-14 13:01:24,725+0200 DEBUG [qtp903987069-33 - GET /rest/policy/stages?context=ci]  org.apache.shiro.realm.AuthenticatingRealm - AuthenticationInfo caching is disabled for info [admin].  Submitted token: [org.apache.shiro.authc.UsernamePasswordToken - admin, rememberMe=false (10.120.16.12)].
2018-05-14 13:01:24,975+0200 DEBUG [qtp903987069-33 - GET /rest/policy/stages?context=ci]  org.apache.shiro.authc.AbstractAuthenticator - Authentication successful for token [org.apache.shiro.authc.UsernamePasswordToken - admin, rememberMe=false (10.120.16.12)].  Returned account [admin]
2018-05-14 13:01:24,975+0200 DEBUG [qtp903987069-33 - GET /rest/policy/stages?context=ci]  org.apache.shiro.subject.support.DefaultSubjectContext - No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
2018-05-14 13:01:24,975+0200 DEBUG [qtp903987069-33 - GET /rest/policy/stages?context=ci]  org.apache.shiro.subject.support.DefaultSubjectContext - No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
2018-05-14 13:01:24,975+0200 DEBUG [qtp903987069-33 - GET /rest/policy/stages?context=ci] admin com.sonatype.insight.brain.policy.LicensedStagesResource - Received request to get licensed stages for context ci
2018-05-14 13:15:03,906+0200 DEBUG [qtp903987069-141 - POST /rest/integration/applications/verifyOrCreate/TestApp?goal=EVALUATE_APPLICATION]  org.apache.shiro.session.mgt.DefaultSessionManager - Unable to resolve session ID from SessionKey [org.apache.shiro.web.session.mgt.WebSessionKey@3b2a0d51].  Returning null to indicate a session could not be found.
2018-05-14 13:15:03,906+0200 DEBUG [qtp903987069-141 - POST /rest/integration/applications/verifyOrCreate/TestApp?goal=EVALUATE_APPLICATION]  org.apache.shiro.web.servlet.OncePerRequestFilter - Filter 'reverseProxy' is not enabled for the current request.  Proceeding without invoking this filter.
2018-05-14 13:15:03,906+0200 DEBUG [qtp903987069-141 - POST /rest/integration/applications/verifyOrCreate/TestApp?goal=EVALUATE_APPLICATION]  org.apache.shiro.realm.AuthenticatingRealm - Looked up AuthenticationInfo [admin] from doGetAuthenticationInfo
2018-05-14 13:15:03,906+0200 DEBUG [qtp903987069-141 - POST /rest/integration/applications/verifyOrCreate/TestApp?goal=EVALUATE_APPLICATION]  org.apache.shiro.realm.AuthenticatingRealm - AuthenticationInfo caching is disabled for info [admin].  Submitted token: [org.apache.shiro.authc.UsernamePasswordToken - admin, rememberMe=false (10.120.16.12)].
2018-05-14 13:15:04,187+0200 DEBUG [qtp903987069-141 - POST /rest/integration/applications/verifyOrCreate/TestApp?goal=EVALUATE_APPLICATION]  org.apache.shiro.authc.AbstractAuthenticator - Authentication successful for token [org.apache.shiro.authc.UsernamePasswordToken - admin, rememberMe=false (10.120.16.12)].  Returned account [admin]
2018-05-14 13:15:04,187+0200 DEBUG [qtp903987069-141 - POST /rest/integration/applications/verifyOrCreate/TestApp?goal=EVALUATE_APPLICATION]  org.apache.shiro.subject.support.DefaultSubjectContext - No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
2018-05-14 13:15:04,187+0200 DEBUG [qtp903987069-141 - POST /rest/integration/applications/verifyOrCreate/TestApp?goal=EVALUATE_APPLICATION]  org.apache.shiro.subject.support.DefaultSubjectContext - No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
2018-05-14 13:15:04,187+0200 DEBUG [qtp903987069-141 - POST /rest/integration/applications/verifyOrCreate/TestApp?goal=EVALUATE_APPLICATION] admin com.sonatype.insight.jaxrs.error.ErrorResponseGenerator - null for uri: http://clm.mycompany.intra:8070/rest/integration/applications/verifyOrCreate/TestApp?goal=EVALUATE_APPLICATION
2018-05-14 13:15:05,016+0200 DEBUG [qtp903987069-37 - POST /rest/integration/applications/verifyOrCreate/TestApp?goal=EVALUATE_APPLICATION]  org.apache.shiro.session.mgt.DefaultSessionManager - Unable to resolve session ID from SessionKey [org.apache.shiro.web.session.mgt.WebSessionKey@64719843].  Returning null to indicate a session could not be found.
2018-05-14 13:15:05,016+0200 DEBUG [qtp903987069-37 - POST /rest/integration/applications/verifyOrCreate/TestApp?goal=EVALUATE_APPLICATION]  org.apache.shiro.web.servlet.OncePerRequestFilter - Filter 'reverseProxy' is not enabled for the current request.  Proceeding without invoking this filter.
2018-05-14 13:15:05,016+0200 DEBUG [qtp903987069-37 - POST /rest/integration/applications/verifyOrCreate/TestApp?goal=EVALUATE_APPLICATION]  org.apache.shiro.realm.AuthenticatingRealm - Looked up AuthenticationInfo [admin] from doGetAuthenticationInfo
2018-05-14 13:15:05,016+0200 DEBUG [qtp903987069-37 - POST /rest/integration/applications/verifyOrCreate/TestApp?goal=EVALUATE_APPLICATION]  org.apache.shiro.realm.AuthenticatingRealm - AuthenticationInfo caching is disabled for info [admin].  Submitted token: [org.apache.shiro.authc.UsernamePasswordToken - admin, rememberMe=false (10.120.16.12)].
2018-05-14 13:15:05,329+0200 DEBUG [qtp903987069-37 - POST /rest/integration/applications/verifyOrCreate/TestApp?goal=EVALUATE_APPLICATION]  org.apache.shiro.authc.AbstractAuthenticator - Authentication successful for token [org.apache.shiro.authc.UsernamePasswordToken - admin, rememberMe=false (10.120.16.12)].  Returned account [admin]
2018-05-14 13:15:05,329+0200 DEBUG [qtp903987069-37 - POST /rest/integration/applications/verifyOrCreate/TestApp?goal=EVALUATE_APPLICATION]  org.apache.shiro.subject.support.DefaultSubjectContext - No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
2018-05-14 13:15:05,329+0200 DEBUG [qtp903987069-37 - POST /rest/integration/applications/verifyOrCreate/TestApp?goal=EVALUATE_APPLICATION]  org.apache.shiro.subject.support.DefaultSubjectContext - No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
2018-05-14 13:15:05,329+0200 DEBUG [qtp903987069-37 - POST /rest/integration/applications/verifyOrCreate/TestApp?goal=EVALUATE_APPLICATION] admin com.sonatype.insight.jaxrs.error.ErrorResponseGenerator - null for uri: http://clm.mycompany.intra:8070/rest/integration/applications/verifyOrCreate/TestApp?goal=EVALUATE_APPLICATION
2

Solution

  • We still use an older version of Nexus IQ server and it appears that the latest version of the Platform Plugin (3.0.20180425-130011.728733c) adds a feature which requires IQ Server 1.47+. Therefore downgrading to the previous plugin release (3.0.20180214-134325.e135900) solves the problem.

    Thanks to SonaType for the quick help in that.