Jenkins Integration Exception Path parameter "item" value must not be null


#1

We’ve been using Spinnaker to run Smoke Tests via a job in Jenkins that’s been working well for us until this morning when we randomly started seeing this error when trying to kick off the job.

This shows in the UI for the stage:

Exception
Path parameter "item" value must not be null.

I SSH’d into the box and see that

$ uptime
14:59:44 up 36 days, 47 min,  1 user,  load average: 1.00, 1.14, 1.12

so even though our hal config is pointing at master-unvalidated it shouldn’t have been updated in the last 36 days (meaning nothing in the way spinnaker works should’ve changed)

$ ping OUR_JENKINS_URL
PING OUR_JENKINS_URL (OUR_JENKINS_IP) 56(84) bytes of data.
64 bytes from OUR_JENKINS_URL (OUR_JENKINS_IP): icmp_seq=1 ttl=248 time=21.3 ms

and we can still access our Jenkins server from the Spinnaker box.

I’m guessing that a restart of Spinnaker might fix the issue but wanted to give it a little time to see if its able to auto recover. Hoping to get more information on what this means and how to mitigate/fix it going forward. Thanks!

I’m seeing the following error log from IGOR that seems to be related.

logger:  "c.n.s.igor.jenkins.JenkinsBuildMonitor"   
  message:  "Failed to update monitor items for monitor=JenkinsBuildMonitor:partition=our-jenkins-server

com.netflix.hystrix.exception.HystrixRuntimeException: jenkins-our-jenkins-server-getProjects failed and no fallback available.
	at com.netflix.hystrix.AbstractCommand$16.call(AbstractCommand.java:801) ~[hystrix-core-1.4.21.jar:1.4.21]
	at com.netflix.hystrix.AbstractCommand$16.call(AbstractCommand.java:785) ~[hystrix-core-1.4.21.jar:1.4.21]
	at rx.internal.operators.OperatorOnErrorResumeNextViaFunction$4.onError(OperatorOnErrorResumeNextViaFunction.java:140) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OnSubscribeDoOnEach$DoOnEachSubscriber.onError(OnSubscribeDoOnEach.java:87) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OnSubscribeDoOnEach$DoOnEachSubscriber.onError(OnSubscribeDoOnEach.java:87) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OnSubscribeDoOnEach$DoOnEachSubscriber.onError(OnSubscribeDoOnEach.java:87) ~[rxjava-1.3.8.jar:1.3.8]
	at com.netflix.hystrix.AbstractCommand$DeprecatedOnFallbackHookApplication$1.onError(AbstractCommand.java:1514) ~[hystrix-core-1.4.21.jar:1.4.21]
	at com.netflix.hystrix.AbstractCommand$FallbackHookApplication$1.onError(AbstractCommand.java:1404) ~[hystrix-core-1.4.21.jar:1.4.21]
	at com.netflix.hystrix.HystrixCommand$2.call(HystrixCommand.java:314) ~[hystrix-core-1.4.21.jar:1.4.21]
	at com.netflix.hystrix.HystrixCommand$2.call(HystrixCommand.java:306) ~[hystrix-core-1.4.21.jar:1.4.21]
	at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:48) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:30) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:48) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:30) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.Observable.unsafeSubscribe(Observable.java:10327) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OnSubscribeDoOnEach.call(OnSubscribeDoOnEach.java:41) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OnSubscribeDoOnEach.call(OnSubscribeDoOnEach.java:30) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.Observable.unsafeSubscribe(Observable.java:10327) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OnSubscribeDoOnEach.call(OnSubscribeDoOnEach.java:41) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OnSubscribeDoOnEach.call(OnSubscribeDoOnEach.java:30) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.Observable.unsafeSubscribe(Observable.java:10327) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OnSubscribeDoOnEach.call(OnSubscribeDoOnEach.java:41) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OnSubscribeDoOnEach.call(OnSubscribeDoOnEach.java:30) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:48) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:30) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.Observable.unsafeSubscribe(Observable.java:10327) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OnSubscribeDoOnEach.call(OnSubscribeDoOnEach.java:41) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OnSubscribeDoOnEach.call(OnSubscribeDoOnEach.java:30) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.Observable.unsafeSubscribe(Observable.java:10327) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OnSubscribeDoOnEach.call(OnSubscribeDoOnEach.java:41) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OnSubscribeDoOnEach.call(OnSubscribeDoOnEach.java:30) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.Observable.unsafeSubscribe(Observable.java:10327) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OnSubscribeDoOnEach.call(OnSubscribeDoOnEach.java:41) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OnSubscribeDoOnEach.call(OnSubscribeDoOnEach.java:30) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.Observable.unsafeSubscribe(Observable.java:10327) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OnSubscribeDoOnEach.call(OnSubscribeDoOnEach.java:41) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OnSubscribeDoOnEach.call(OnSubscribeDoOnEach.java:30) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.Observable.unsafeSubscribe(Observable.java:10327) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OperatorOnErrorResumeNextViaFunction$4.onError(OperatorOnErrorResumeNextViaFunction.java:142) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OnSubscribeDoOnEach$DoOnEachSubscriber.onError(OnSubscribeDoOnEach.java:87) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OnSubscribeDoOnEach$DoOnEachSubscriber.onError(OnSubscribeDoOnEach.java:87) ~[rxjava-1.3.8.jar:1.3.8]
	at com.netflix.hystrix.AbstractCommand$HystrixObservableTimeoutOperator$3.onError(AbstractCommand.java:1005) ~[hystrix-core-1.4.21.jar:1.4.21]
	at rx.internal.operators.OnSubscribeDoOnEach$DoOnEachSubscriber.onError(OnSubscribeDoOnEach.java:87) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OperatorSubscribeOn$SubscribeOnSubscriber.onError(OperatorSubscribeOn.java:80) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OnSubscribeDoOnEach$DoOnEachSubscriber.onError(OnSubscribeDoOnEach.java:87) ~[rxjava-1.3.8.jar:1.3.8]
	at com.netflix.hystrix.AbstractCommand$DeprecatedOnRunHookApplication$1.onError(AbstractCommand.java:1473) ~[hystrix-core-1.4.21.jar:1.4.21]
	at com.netflix.hystrix.AbstractCommand$ExecutionHookApplication$1.onError(AbstractCommand.java:1369) ~[hystrix-core-1.4.21.jar:1.4.21]
	at com.netflix.hystrix.HystrixCommand$1.call(HystrixCommand.java:297) ~[hystrix-core-1.4.21.jar:1.4.21]
	at com.netflix.hystrix.HystrixCommand$1.call(HystrixCommand.java:289) ~[hystrix-core-1.4.21.jar:1.4.21]
	at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:48) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:30) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:48) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:30) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.Observable.unsafeSubscribe(Observable.java:10327) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OnSubscribeDoOnEach.call(OnSubscribeDoOnEach.java:41) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OnSubscribeDoOnEach.call(OnSubscribeDoOnEach.java:30) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.Observable.unsafeSubscribe(Observable.java:10327) ~[rxjava-1.3.8.jar:1.3.8]
	at com.netflix.hystrix.AbstractCommand$5.call(AbstractCommand.java:517) ~[hystrix-core-1.4.21.jar:1.4.21]
	at com.netflix.hystrix.AbstractCommand$5.call(AbstractCommand.java:495) ~[hystrix-core-1.4.21.jar:1.4.21]
	at rx.Observable.unsafeSubscribe(Observable.java:10327) ~[rxjava-1.3.8.jar:1.3.8]
	at rx.internal.operators.OperatorSubscribeOn$SubscribeOnSubscriber.call(OperatorSubscribeOn.java:100) ~[rxjava-1.3.8.jar:1.3.8]
	at com.netflix.hystrix.strategy.concurrency.HystrixContexSchedulerAction$1.call(HystrixContexSchedulerAction.java:56) ~[hystrix-core-1.4.21.jar:1.4.21]
	at com.netflix.hystrix.strategy.concurrency.HystrixContexSchedulerAction$1.call(HystrixContexSchedulerAction.java:47) ~[hystrix-core-1.4.21.jar:1.4.21]
	at com.netflix.hystrix.strategy.concurrency.HystrixContexSchedulerAction.call(HystrixContexSchedulerAction.java:69) ~[hystrix-core-1.4.21.jar:1.4.21]
	at rx.internal.schedulers.ScheduledAction.run(ScheduledAction.java:55) ~[rxjava-1.3.8.jar:1.3.8]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[na:1.8.0_171]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[na:1.8.0_171]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[na:1.8.0_171]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[na:1.8.0_171]
	at java.lang.Thread.run(Thread.java:748) ~[na:1.8.0_171]
Caused by: retrofit.RetrofitError: our.jenkins.server.com: System error
	at retrofit.RetrofitError.networkError(RetrofitError.java:27) ~[retrofit-1.9.0.jar:na]
	at retrofit.RestAdapter$RestHandler.invokeRequest(RestAdapter.java:395) ~[retrofit-1.9.0.jar:na]
	at retrofit.RestAdapter$RestHandler.invoke(RestAdapter.java:240) ~[retrofit-1.9.0.jar:na]
	at com.sun.proxy.$Proxy88.getProjects(Unknown Source) ~[na:na]
	at com.netflix.spinnaker.igor.jenkins.client.JenkinsClient$getProjects.call(Unknown Source) ~[na:na]
	at com.netflix.spinnaker.igor.jenkins.service.JenkinsService$_getProjects_closure1.doCall(JenkinsService.groovy:77) ~[igor-web-0.12.0-20180625022808.jar:0.12.0-20180625022808]
	at com.netflix.spinnaker.igor.jenkins.service.JenkinsService$_getProjects_closure1.doCall(JenkinsService.groovy) ~[igor-web-0.12.0-20180625022808.jar:0.12.0-20180625022808]
	at sun.reflect.GeneratedMethodAccessor169.invoke(Unknown Source) ~[na:na]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_171]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_171]
	at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:93) ~[groovy-all-2.4.13.jar:2.4.13]
	at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:325) ~[groovy-all-2.4.13.jar:2.4.13]
	at org.codehaus.groovy.runtime.metaclass.ClosureMetaClass.invokeMethod(ClosureMetaClass.java:294) ~[groovy-all-2.4.13.jar:2.4.13]
	at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1022) ~[groovy-all-2.4.13.jar:2.4.13]
	at groovy.lang.Closure.call(Closure.java:414) ~[groovy-all-2.4.13.jar:2.4.13]
	at com.netflix.spinnaker.hystrix.SimpleHystrixCommand.run(SimpleHystrixCommand.groovy:53) ~[kork-hystrix-1.137.0.jar:1.137.0]
	at com.netflix.hystrix.HystrixCommand$1.call(HystrixCommand.java:294) ~[hystrix-core-1.4.21.jar:1.4.21]
	... 22 common frames omitted
Caused by: java.net.UnknownHostException: our.jenkins.server.com: System error
	at java.net.Inet6AddressImpl.lookupAllHostAddr(Native Method) ~[na:1.8.0_171]
	at java.net.InetAddress$2.lookupAllHostAddr(InetAddress.java:928) ~[na:1.8.0_171]
	at java.net.InetAddress.getAddressesFromNameService(InetAddress.java:1323) ~[na:1.8.0_171]
	at java.net.InetAddress.getAllByName0(InetAddress.java:1276) ~[na:1.8.0_171]
	at java.net.InetAddress.getAllByName(InetAddress.java:1192) ~[na:1.8.0_171]
	at java.net.InetAddress.getAllByName(InetAddress.java:1126) ~[na:1.8.0_171]
	at com.squareup.okhttp.Dns$1.lookup(Dns.java:39) ~[okhttp-2.7.0.jar:na]
	at com.squareup.okhttp.internal.http.RouteSelector.resetNextInetSocketAddress(RouteSelector.java:175) ~[okhttp-2.7.0.jar:na]
	at com.squareup.okhttp.internal.http.RouteSelector.nextProxy(RouteSelector.java:141) ~[okhttp-2.7.0.jar:na]
	at com.squareup.okhttp.internal.http.RouteSelector.next(RouteSelector.java:83) ~[okhttp-2.7.0.jar:na]
	at com.squareup.okhttp.internal.http.StreamAllocation.findConnection(StreamAllocation.java:164) ~[okhttp-2.7.0.jar:na]
	at com.squareup.okhttp.internal.http.StreamAllocation.findHealthyConnection(StreamAllocation.java:126) ~[okhttp-2.7.0.jar:na]
	at com.squareup.okhttp.internal.http.StreamAllocation.newStream(StreamAllocation.java:95) ~[okhttp-2.7.0.jar:na]
	at com.squareup.okhttp.internal.http.HttpEngine.connect(HttpEngine.java:283) ~[okhttp-2.7.0.jar:na]
	at com.squareup.okhttp.internal.http.HttpEngine.sendRequest(HttpEngine.java:224) ~[okhttp-2.7.0.jar:na]
	at com.squareup.okhttp.Call.getResponse(Call.java:286) ~[okhttp-2.7.0.jar:na]
	at com.squareup.okhttp.Call$ApplicationInterceptorChain.proceed(Call.java:243) ~[okhttp-2.7.0.jar:na]
	at com.squareup.okhttp.Call.getResponseWithInterceptorChain(Call.java:205) ~[okhttp-2.7.0.jar:na]
	at com.squareup.okhttp.Call.execute(Call.java:80) ~[okhttp-2.7.0.jar:na]
	at retrofit.client.OkClient.execute(OkClient.java:53) ~[retrofit-1.9.0.jar:na]
	at retrofit.RestAdapter$RestHandler.invokeRequest(RestAdapter.java:326) ~[retrofit-1.9.0.jar:na]
	... 37 common frames omitted
"   
  pid:  "32227"   
  thread:  "RxIoScheduler-4"   

#2

@briananderson1222: From the stack trace, it looks like somehow Java wasn’t able to resolve the DNS for your Jenkins instance to an IP address. In particular, it looks like it’s trying to resolve the name to an IPv6 address.

Does your Spinnaker box have IPv6 connectivity? (GCE instances, for example, do not.) If not, I’m confused why Java would be trying to resolve an IPv6 address; it should use IPv4 when the machine doesn’t have IPv6 connectivity.

Can you try to ping from your Spinnaker box with the -4 and -6 flags to see if you can reach your Jenkins server via the IPv4 and IPv6 addresses, respectively?


#3

@ezimanyi I have not configured IPv6 for this VM running in GCE. The instance had been running for about 36 days prior to this error so it is strange that it happened all of the sudden and wasn’t able to recover until I restarted the machine (I didn’t try just doing a hal deploy apply because I made some changes to our startup script). Before I shut it down though I was able to ping our Jenkins server from within the box. I’m not super familiar with these -4 and -6 flags but would be happy to try them if I had a little more information on it.

Thanks!


#4

The -4 and -6 flags force ping to only use IPv4 or IPv6, respectively, so is a good way of checking if you can connect to an endpoint via IPv4, IPv6, or both.

That being said, after digging into the error message a bit more, and trying some things with my igor installation, I don’t think IPv4 vs IPv6 was the issue here. The fact that the error stacktrace came from IPv6 is likely because it tried IPv4 before IPv6 and only threw the exception after both failed.

More interestingly, when I try to resolve an unresolvable host, I get:
java.net.UnknownHostException: host.name: Name or service not known
whereas your error was
java.net.UnknownHostException: host.name: System error.
By adding an invalid DNS hosts to my system resolv.conf, I was able to get:
java.net.UnknownHostException: host.name: Temporary failure in name resolution
but never saw System error nor could I find any documentation on what would cause that particular error.

Given that DNS resolution appears to have been working fine at the system level on the box (as you were able to ping your CI server) the best I can come up with is that somehow the Java DNS resolver ended up in a bad state and was no longer able to properly call out to the system DNS. My guess is that restarting igor might have resolved that, though of course I’m not sure.

While it’s resolved now after you rebooted the system, I’d definitely be interested in hearing if you see this again—if there is some sort of issue that only affects long-running instances of igor, then it’s worth some time digging into it some more.