[JIRA] [vsphere-cloud] (JENKINS-15504) NPE on running a job

Mon, 29 Apr 2013 15:18:46 -0700

I've seen this as well. Some digging around in the console log suggests that the following sequence occurs. Please note, my snapshots are taken in powered-off state, using jnlp connection, set to revert after 1 build, slave to remain online as much as possible.

1. Slave comes online normally
2. Build assigned to slave, build runs to completion normally.
3. vsphere plugin starts to shutdown and revert the node
4. while the shutdown/disconnect is running, another build dequeues into the slave node and starts running.
5. While the second build is running, the vm finally shuts down and reverts, resulting in either a socket exception, the null pointer exception shown above, or a channelclosed exception.

Log from catalina follows one of my build nodes through a couple of sequences. I've put in markers to indicate when various builds started and stopped.

Apr 28, 2013 10:13:05 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Finished wait for VMTools
>>>>>> http://hbo-jenkins/jenkins/job/Build-Common_Types_1.x/20/ BUILD RAN AT THIS POINT <<<<<<<<<
Apr 28, 2013 10:41:33 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Running disconnect procedure...
Apr 28, 2013 10:41:33 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Shutting down Virtual Machine...
Apr 28, 2013 10:41:33 PM hudson.remoting.SynchronousCommandTransport$ReaderThread run
SEVERE: I/O error in channel HIORTCBLD1
–
Apr 28, 2013 10:41:33 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: Disconnecting the slave agent on HIORTCBLD1 due to limited build threshold
Apr 28, 2013 10:41:34 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Attempting a graceful shutdown
Apr 28, 2013 10:41:54 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Guest shutdown succeeded
Apr 28, 2013 10:41:54 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Reverting to snapshot:build 11
Apr 28, 2013 10:41:58 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Running disconnect procedure...
Apr 28, 2013 10:41:58 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Shutting down Virtual Machine...
Apr 28, 2013 10:41:58 PM jenkins.slaves.JnlpSlaveAgentProtocol$Handler$1 onClosed
WARNING: Channel reader thread: HIORTCBLD1 for + HIORTCBLD1 terminated
–
Apr 28, 2013 10:43:20 PM hudson.slaves.SlaveComputer tryReconnect
INFO: Attempting to reconnect HIORTCBLD1
Apr 28, 2013 10:43:20 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Starting Virtual Machine...
Apr 28, 2013 10:43:20 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Reverting to snapshot:build 11
Apr 28, 2013 10:43:26 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Powering on VM
Apr 28, 2013 10:43:29 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Waiting for VMTools
>>>>>> http://hbo-jenkins/jenkins/job/Build-PTO_Custom_Components/36/ BUILD RAN AT THIS POINT <<<<<<<<<
Apr 28, 2013 10:44:14 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] VM Tools are running
Apr 28, 2013 10:44:14 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Finished wait for VMTools
–
Apr 28, 2013 11:14:01 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: Disconnecting the slave agent on HIORTCBLD1 due to limited build threshold
>>>>>> http://hbo-jenkins/jenkins/job/Build-iFast-rtc/138/ BUILD RAN AT THIS POINT <<<<<<<<<
Apr 28, 2013 11:14:01 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Running disconnect procedure...
Apr 28, 2013 11:14:01 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Shutting down Virtual Machine...
Apr 28, 2013 11:14:01 PM hudson.remoting.SynchronousCommandTransport$ReaderThread run
SEVERE: I/O error in channel HIORTCBLD1
–
Apr 28, 2013 11:14:02 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Attempting a graceful shutdown
Apr 28, 2013 11:14:02 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: Disconnecting the slave agent on HIORTCBLD1 due to limited build threshold
–
Apr 28, 2013 11:14:27 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Guest shutdown succeeded
Apr 28, 2013 11:14:27 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Reverting to snapshot:build 11
–
Apr 28, 2013 11:14:32 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Running disconnect procedure...
Apr 28, 2013 11:14:32 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Shutting down Virtual Machine...
Apr 28, 2013 11:14:32 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Running disconnect procedure...
Apr 28, 2013 11:14:32 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Shutting down Virtual Machine...
Apr 28, 2013 11:14:32 PM jenkins.slaves.JnlpSlaveAgentProtocol$Handler$1 onClosed
WARNING: Channel reader thread: HIORTCBLD1 for + HIORTCBLD1 terminated
–
Apr 28, 2013 11:15:20 PM hudson.slaves.SlaveComputer tryReconnect
INFO: Attempting to reconnect HIORTCBLD1
Apr 28, 2013 11:15:20 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Starting Virtual Machine...
Apr 28, 2013 11:15:20 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Reverting to snapshot:build 11
Apr 28, 2013 11:15:25 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Powering on VM
Apr 28, 2013 11:15:30 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Waiting for VMTools
–
Apr 28, 2013 11:16:45 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] VM Tools are running
Apr 28, 2013 11:16:45 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Finished wait for VMTools
>>>>>> http://hbo-jenkins/jenkins/job/Build-iFast-rtc/139/ BUILD RAN AT THIS POINT <<<<<<<<<
Apr 28, 2013 11:44:14 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Running disconnect procedure...
Apr 28, 2013 11:44:14 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Shutting down Virtual Machine...
Apr 28, 2013 11:44:14 PM hudson.remoting.SynchronousCommandTransport$ReaderThread run
SEVERE: I/O error in channel HIORTCBLD1
–
Apr 28, 2013 11:44:14 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: Disconnecting the slave agent on HIORTCBLD1 due to limited build threshold
Apr 28, 2013 11:44:14 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Attempting a graceful shutdown
Apr 28, 2013 11:44:20 PM hudson.slaves.SlaveComputer tryReconnect
INFO: Attempting to reconnect HIORTCBLD1
Apr 28, 2013 11:44:20 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Starting Virtual Machine...
Apr 28, 2013 11:44:20 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Reverting to snapshot:build 11
Apr 28, 2013 11:44:39 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Guest shutdown succeeded
Apr 28, 2013 11:44:39 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Reverting to snapshot:build 11
Apr 28, 2013 11:44:46 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Running disconnect procedure...
Apr 28, 2013 11:44:46 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Shutting down Virtual Machine...
Apr 28, 2013 11:44:46 PM jenkins.slaves.JnlpSlaveAgentProtocol$Handler$1 onClosed
WARNING: Channel reader thread: HIORTCBLD1 for + HIORTCBLD1 terminated
–
Apr 28, 2013 11:46:20 PM hudson.slaves.SlaveComputer tryReconnect
INFO: Attempting to reconnect HIORTCBLD1
Apr 28, 2013 11:46:20 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Starting Virtual Machine...
Apr 28, 2013 11:46:20 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Reverting to snapshot:build 11
Apr 28, 2013 11:46:28 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Powering on VM
Apr 28, 2013 11:46:38 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Waiting for VMTools
–
Apr 28, 2013 11:47:48 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] VM Tools are running
Apr 28, 2013 11:47:48 PM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Finished wait for VMTools
>>>>>> http://hbo-jenkins/jenkins/job/Build-iFast-rtc/140/ BUILD RAN AT THIS POINT <<<<<<<<<
Apr 29, 2013 12:17:52 AM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Running disconnect procedure...
Apr 29, 2013 12:17:52 AM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Shutting down Virtual Machine...
Apr 29, 2013 12:17:52 AM hudson.remoting.SynchronousCommandTransport$ReaderThread run
SEVERE: I/O error in channel HIORTCBLD1
–
Apr 29, 2013 12:17:52 AM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: Disconnecting the slave agent on HIORTCBLD1 due to limited build threshold
Apr 29, 2013 12:17:52 AM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Attempting a graceful shutdown
Apr 29, 2013 12:18:27 AM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Guest shutdown succeeded
Apr 29, 2013 12:18:27 AM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Reverting to snapshot:build 11
Apr 29, 2013 12:18:34 AM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Running disconnect procedure...
Apr 29, 2013 12:18:34 AM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Shutting down Virtual Machine...
Apr 29, 2013 12:18:34 AM jenkins.slaves.JnlpSlaveAgentProtocol$Handler$1 onClosed
WARNING: Channel reader thread: HIORTCBLD1 for + HIORTCBLD1 terminated
–
Apr 29, 2013 12:19:20 AM hudson.slaves.SlaveComputer tryReconnect
INFO: Attempting to reconnect HIORTCBLD1
Apr 29, 2013 12:19:20 AM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Starting Virtual Machine...
Apr 29, 2013 12:19:20 AM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Reverting to snapshot:build 11
Apr 29, 2013 12:19:25 AM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Powering on VM
Apr 29, 2013 12:19:30 AM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Waiting for VMTools
–
Apr 29, 2013 12:21:05 AM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] VM Tools are running
Apr 29, 2013 12:21:05 AM org.jenkinsci.plugins.vSphereCloud InternalLog
INFO: [HIORTCBLD1] Finished wait for VMTools

Regards,
Aaron
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators.
For more information on JIRA, see: http://www.atlassian.com/software/jira

--
You received this message because you are subscribed to the Google Groups "Jenkins Issues" group.
To unsubscribe from this group and stop receiving emails from it, send an email to jenkinsci-issues+unsubscr...@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.
 
 

Reply via email to