hudson 1.217 issue -" Please wait while hudson is getting ready to work..."

classic Classic list List threaded Threaded
16 messages Options
Reply | Threaded
Open this post in threaded view
|

hudson 1.217 issue -" Please wait while hudson is getting ready to work..."

mezlight
All,
 
I am getting a NullPointerException for the slaves when deployed 1.217, which displays "Please wait while hudson is getting ready to work..."
Any clues...
 
Thanks,
~Jay
 
 
 
 
 
 
 
[#|2008-05-21T13:17:12.111-0400|INFO|sun-appserver9.1|javax.enterprise.system.core.selfmanagement|_ThreadID=10;_ThreadName=main;|SMGT0007: Self Management Rules service is enabled|#]
 
[#|2008-05-21T13:17:12.186-0400|WARNING|sun-appserver9.1|javax.enterprise.system.container.ejb|_ThreadID=10;_ThreadName=main;_RequestID=4c2fc416-86e5-4fc6-909b-7358e9142acf;|EJBLifeCycle: Automatic  timer migration component not enabled  for DAS instance|#]
 
[#|2008-05-21T13:17:12.218-0400|INFO|sun-appserver9.1|javax.enterprise.system.core|_ThreadID=10;_ThreadName=main;|Application server startup complete.|#]
 
[#|2008-05-21T13:17:12.918-0400|INFO|sun-appserver9.1|org.springframework.web.context.support.StaticWebApplicationContext|_ThreadID=17;_ThreadName=hudson initialization thread;|Refreshing [hidden email]: display name [Root WebApplicationContext]; startup date [Wed May 21 13:17:12 EDT 2008]; root of context hierarchy|#]
 
[#|2008-05-21T13:17:12.920-0400|INFO|sun-appserver9.1|org.springframework.web.context.support.StaticWebApplicationContext|_ThreadID=17;_ThreadName=hudson initialization thread;|Bean factory for application context [org.springframework.web.context.support.StaticWebApplicationContext@1362ca8]: [hidden email]|#]
 
[#|2008-05-21T13:17:12.921-0400|INFO|sun-appserver9.1|org.springframework.beans.factory.support.DefaultListableBeanFactory|_ThreadID=17;_ThreadName=hudson initialization thread;|Pre-instantiating singletons in [hidden email]: defining beans [authenticationManager,userDetailsService]; root of factory hierarchy|#]
 
[#|2008-05-21T13:17:12.960-0400|INFO|sun-appserver9.1|hudson.model.Hudson|_ThreadID=17;_ThreadName=hudson initialization thread;|Took 1760 ms to load|#]
 
[#|2008-05-21T13:17:13.007-0400|SEVERE|sun-appserver9.1|hudson.WebAppMain|_ThreadID=17;_ThreadName=hudson initialization thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Failed to initialize Hudson
java.lang.NullPointerException
        at hudson.slaves.SlaveComputer.closeChannel(SlaveComputer.java:259)
        at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
        at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
        at hudson.model.Computer.<init>(Computer.java:74)
        at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
        at hudson.model.Slave.createComputer(Slave.java:246)
        at hudson.model.Hudson.updateComputer(Hudson.java:576)
        at hudson.model.Hudson.updateComputerList(Hudson.java:556)
        at hudson.model.Hudson.<init>(Hudson.java:351)
        at hudson.WebAppMain$2.run(WebAppMain.java:155)
|#]
 
[#|2008-05-21T13:17:13.010-0400|WARNING|sun-appserver9.1|javax.enterprise.system.stream.err|_ThreadID=17;_ThreadName=hudson initialization thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Exception in thread "hudson initialization thread" |#]
 
[#|2008-05-21T13:17:13.018-0400|WARNING|sun-appserver9.1|javax.enterprise.system.stream.err|_ThreadID=17;_ThreadName=hudson initialization thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|java.lang.NullPointerException
        at hudson.slaves.SlaveComputer.closeChannel(SlaveComputer.java:259)
        at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
        at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
        at hudson.model.Computer.<init>(Computer.java:74)
        at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
        at hudson.model.Slave.createComputer(Slave.java:246)
        at hudson.model.Hudson.updateComputer(Hudson.java:576)
        at hudson.model.Hudson.updateComputerList(Hudson.java:556)
        at hudson.model.Hudson.<init>(Hudson.java:351)
        at hudson.WebAppMain$2.run(WebAppMain.java:155)
|#]
 
[#|2008-05-21T13:17:38.074-0400|INFO|sun-appserver9.1|javax.enterprise.resource.webcontainer.jsf.config|_ThreadID=18;_ThreadName=httpWorkerThread-9048-1;;|Initializing Sun's JavaServer Faces implementation (1.2_04-b20-p03) for context ''|#]
Reply | Threaded
Open this post in threaded view
|

Re: hudson 1.217 issue -" Please wait while hudson is getting ready to work..."

stephenconnolly
other than you have a null pointer!

a stack trace might help us

Sent from my iPod

On 21 May 2008, at 18:30, "Messmer, Jason" <[hidden email]> wrote:

All,
 
I am getting a NullPointerException for the slaves when deployed 1.217, which displays "Please wait while hudson is getting ready to work..."
Any clues...
 
Thanks,
~Jay
 
 
 
 
 
 
 
[#|2008-05-21T13:17:12.111-0400|INFO|sun-appserver9.1|javax.enterprise.system.core.selfmanagement|_ThreadID=10;_ThreadName=main;|SMGT0007: Self Management Rules service is enabled|#]
 
[#|2008-05-21T13:17:12.186-0400|WARNING|sun-appserver9.1|javax.enterprise.system.container.ejb|_ThreadID=10;_ThreadName=main;_RequestID=4c2fc416-86e5-4fc6-909b-7358e9142acf;|EJBLifeCycle: Automatic  timer migration component not enabled  for DAS instance|#]
 
[#|2008-05-21T13:17:12.218-0400|INFO|sun-appserver9.1|javax.enterprise.system.core|_ThreadID=10;_ThreadName=main;|Application server startup complete.|#]
 
[#|2008-05-21T13:17:12.918-0400|INFO|sun-appserver9.1|org.springframework.web.context.support.StaticWebApplicationContext|_ThreadID=17;_ThreadName=hudson initialization thread;|Refreshing [hidden email]@1362ca8: display name [Root WebApplicationContext]; startup date [Wed May 21 13:17:12 EDT 2008]; root of context hierarchy|#]
 
[#|2008-05-21T13:17:12.920-0400|INFO|sun-appserver9.1|org.springframework.web.context.support.StaticWebApplicationContext|_ThreadID=17;_ThreadName=hudson initialization thread;|Bean factory for application context [org.springframework.web.context.support.StaticWebApplicationContext@1362ca8]: [hidden email]|#]
 
[#|2008-05-21T13:17:12.921-0400|INFO|sun-appserver9.1|org.springframework.beans.factory.support.DefaultListableBeanFactory|_ThreadID=17;_ThreadName=hudson initialization thread;|Pre-instantiating singletons in [hidden email]: defining beans [authenticationManager,userDetailsService]; root of factory hierarchy|#]
 
[#|2008-05-21T13:17:12.960-0400|INFO|sun-appserver9.1|hudson.model.Hudson|_ThreadID=17;_ThreadName=hudson initialization thread;|Took 1760 ms to load|#]
 
[#|2008-05-21T13:17:13.007-0400|SEVERE|sun-appserver9.1|hudson.WebAppMain|_ThreadID=17;_ThreadName=hudson initialization thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Failed to initialize Hudson
java.lang.NullPointerException
        at hudson.slaves.SlaveComputer.closeChannel(SlaveComputer.java:259)
        at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
        at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
        at hudson.model.Computer.<init>(Computer.java:74)
        at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
        at hudson.model.Slave.createComputer(Slave.java:246)
        at hudson.model.Hudson.updateComputer(Hudson.java:576)
        at hudson.model.Hudson.updateComputerList(Hudson.java:556)
        at hudson.model.Hudson.<init>(Hudson.java:351)
        at hudson.WebAppMain$2.run(WebAppMain.java:155)
|#]
 
[#|2008-05-21T13:17:13.010-0400|WARNING|sun-appserver9.1|javax.enterprise.system.stream.err|_ThreadID=17;_ThreadName=hudson initialization thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Exception in thread "hudson initialization thread" |#]
 
[#|2008-05-21T13:17:13.018-0400|WARNING|sun-appserver9.1|javax.enterprise.system.stream.err|_ThreadID=17;_ThreadName=hudson initialization thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|java.lang.NullPointerException
        at hudson.slaves.SlaveComputer.closeChannel(SlaveComputer.java:259)
        at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
        at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
        at hudson.model.Computer.<init>(Computer.java:74)
        at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
        at hudson.model.Slave.createComputer(Slave.java:246)
        at hudson.model.Hudson.updateComputer(Hudson.java:576)
        at hudson.model.Hudson.updateComputerList(Hudson.java:556)
        at hudson.model.Hudson.<init>(Hudson.java:351)
        at hudson.WebAppMain$2.run(WebAppMain.java:155)
|#]
 
[#|2008-05-21T13:17:38.074-0400|INFO|sun-appserver9.1|javax.enterprise.resource.webcontainer.jsf.config
Reply | Threaded
Open this post in threaded view
|

Re: hudson 1.217 issue -" Please wait while hudson is getting ready to work..."

Kohsuke Kawaguchi
Administrator
Stephen Connolly wrote:
> other than you have a null pointer!
>
> a stack trace might help us

It's in the log:

[#|2008-05-21T13:17:13.007-0400|SEVERE|sun-appserver9.1|
 > hudson.WebAppMain|_ThreadID=17;_ThreadName=hudson initialization
 > thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Failed to
 > initialize Hudson
 > java.lang.NullPointerException
 >         at hudson.slaves.SlaveComputer.closeChannel
 > (SlaveComputer.java:259)
 >         at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
 >         at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
 >         at hudson.model.Computer.<init>(Computer.java:74)
 >         at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
 >         at hudson.model.Slave.createComputer(Slave.java:246)
 >         at hudson.model.Hudson.updateComputer(Hudson.java:576)
 >         at hudson.model.Hudson.updateComputerList(Hudson.java:556)
 >         at hudson.model.Hudson.<init>(Hudson.java:351)
 >         at hudson.WebAppMain$2.run(WebAppMain.java:155)
 > |#]


>
> Sent from my iPod
>
> On 21 May 2008, at 18:30, "Messmer, Jason" <[hidden email]>  
> wrote:
>
>> All,
>>
>> I am getting a NullPointerException for the slaves when deployed  
>> 1.217, which displays "Please wait while hudson is getting ready to  
>> work..."
>> Any clues...
>>
>> Thanks,
>> ~Jay
>>
>>
>>
>>
>>
>>
>>
>> [#|2008-05-21T13:17:12.111-0400|INFO|sun-appserver9.1|
>> javax.enterprise.system.core.selfmanagement|
>> _ThreadID=10;_ThreadName=main;|SMGT0007: Self Management Rules  
>> service is enabled|#]
>>
>> [#|2008-05-21T13:17:12.186-0400|WARNING|sun-appserver9.1|
>> javax.enterprise.system.container.ejb|
>> _ThreadID=
>> 10;_ThreadName=main;_RequestID=4c2fc416-86e5-4fc6-909b-7358e9142acf;|
>> EJBLifeCycle: Automatic  timer migration component not enabled  for  
>> DAS instance|#]
>>
>> [#|2008-05-21T13:17:12.218-0400|INFO|sun-appserver9.1|
>> javax.enterprise.system.core|_ThreadID=10;_ThreadName=main;|
>> Application server startup complete.|#]
>>
>> [#|2008-05-21T13:17:12.918-0400|INFO|sun-appserver9.1|
>> org.springframework.web.context.support.StaticWebApplicationContext|
>> _ThreadID=17;_ThreadName=hudson initialization thread;|Refreshing  
>> org.
>> springframework.
>> web.context.support.StaticWebApplicationContext@1362ca8: display  
>> name [Root WebApplicationContext]; startup date [Wed May 21 13:17:12  
>> EDT 2008]; root of context hierarchy|#]
>>
>> [#|2008-05-21T13:17:12.920-0400|INFO|sun-appserver9.1|
>> org.springframework.web.context.support.StaticWebApplicationContext|
>> _ThreadID=17;_ThreadName=hudson initialization thread;|Bean factory  
>> for application context [org.springframework.web.context.support.StaticWebApplicationContext
>> @1362ca8]:  
>> org.
>> springframework.
>> beans.factory.support.DefaultListableBeanFactory@d7373f|#]
>>
>> [#|2008-05-21T13:17:12.921-0400|INFO|sun-appserver9.1|
>> org.springframework.beans.factory.support.DefaultListableBeanFactory|
>> _ThreadID=17;_ThreadName=hudson initialization thread;|Pre-
>> instantiating singletons in  
>> org.
>> springframework.
>> beans.factory.support.DefaultListableBeanFactory@d7373f: defining  
>> beans [authenticationManager,userDetailsService]; root of factory  
>> hierarchy|#]
>>
>> [#|2008-05-21T13:17:12.960-0400|INFO|sun-appserver9.1|
>> hudson.model.Hudson|_ThreadID=17;_ThreadName=hudson initialization  
>> thread;|Took 1760 ms to load|#]
>>
>> [#|2008-05-21T13:17:13.007-0400|SEVERE|sun-appserver9.1|
>> hudson.WebAppMain|_ThreadID=17;_ThreadName=hudson initialization  
>> thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Failed to  
>> initialize Hudson
>> java.lang.NullPointerException
>>         at hudson.slaves.SlaveComputer.closeChannel
>> (SlaveComputer.java:259)
>>         at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
>>         at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
>>         at hudson.model.Computer.<init>(Computer.java:74)
>>         at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
>>         at hudson.model.Slave.createComputer(Slave.java:246)
>>         at hudson.model.Hudson.updateComputer(Hudson.java:576)
>>         at hudson.model.Hudson.updateComputerList(Hudson.java:556)
>>         at hudson.model.Hudson.<init>(Hudson.java:351)
>>         at hudson.WebAppMain$2.run(WebAppMain.java:155)
>> |#]
>>
>> [#|2008-05-21T13:17:13.010-0400|WARNING|sun-appserver9.1|
>> javax.enterprise.system.stream.err|_ThreadID=17;_ThreadName=hudson  
>> initialization thread;_RequestID=cd5b4695-
>> a356-45fb-873a-17367207533f;|Exception in thread "hudson  
>> initialization thread" |#]
>>
>> [#|2008-05-21T13:17:13.018-0400|WARNING|sun-appserver9.1|
>> javax.enterprise.system.stream.err|_ThreadID=17;_ThreadName=hudson  
>> initialization thread;_RequestID=cd5b4695-
>> a356-45fb-873a-17367207533f;|java.lang.NullPointerException
>>         at hudson.slaves.SlaveComputer.closeChannel
>> (SlaveComputer.java:259)
>>         at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
>>         at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
>>         at hudson.model.Computer.<init>(Computer.java:74)
>>         at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
>>         at hudson.model.Slave.createComputer(Slave.java:246)
>>         at hudson.model.Hudson.updateComputer(Hudson.java:576)
>>         at hudson.model.Hudson.updateComputerList(Hudson.java:556)
>>         at hudson.model.Hudson.<init>(Hudson.java:351)
>>         at hudson.WebAppMain$2.run(WebAppMain.java:155)
>> |#]
>>
>> [#|2008-05-21T13:17:38.074-0400|INFO|sun-appserver9.1|
>> javax.enterprise.resource.webcontainer.jsf.config
>

--
Kohsuke Kawaguchi
Sun Microsystems                   [hidden email]

smime.p7s (4K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: hudson 1.217 issue -" Please wait while hudson is getting ready to work..."

stephenconnolly
Ahhh the iPod didn;t show the log!

On Wed, May 21, 2008 at 8:03 PM, Kohsuke Kawaguchi <[hidden email]> wrote:
Stephen Connolly wrote:
other than you have a null pointer!

a stack trace might help us

It's in the log:


[#|2008-05-21T13:17:13.007-0400|SEVERE|sun-appserver9.1|
> hudson.WebAppMain|_ThreadID=17;_ThreadName=hudson initialization
> thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Failed to
> initialize Hudson
> java.lang.NullPointerException
>         at hudson.slaves.SlaveComputer.closeChannel
> (SlaveComputer.java:259)
>         at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
>         at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
>         at hudson.model.Computer.<init>(Computer.java:74)
>         at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
>         at hudson.model.Slave.createComputer(Slave.java:246)
>         at hudson.model.Hudson.updateComputer(Hudson.java:576)
>         at hudson.model.Hudson.updateComputerList(Hudson.java:556)
>         at hudson.model.Hudson.<init>(Hudson.java:351)
>         at hudson.WebAppMain$2.run(WebAppMain.java:155)
> |#]



Sent from my iPod

On 21 May 2008, at 18:30, "Messmer, Jason" <[hidden email]>  wrote:

All,

I am getting a NullPointerException for the slaves when deployed  1.217, which displays "Please wait while hudson is getting ready to  work..."
Any clues...

Thanks,
~Jay







[#|2008-05-21T13:17:12.111-0400|INFO|sun-appserver9.1| javax.enterprise.system.core.selfmanagement| _ThreadID=10;_ThreadName=main;|SMGT0007: Self Management Rules  service is enabled|#]

[#|2008-05-21T13:17:12.186-0400|WARNING|sun-appserver9.1| javax.enterprise.system.container.ejb| _ThreadID= 10;_ThreadName=main;_RequestID=4c2fc416-86e5-4fc6-909b-7358e9142acf;| EJBLifeCycle: Automatic  timer migration component not enabled  for  DAS instance|#]

[#|2008-05-21T13:17:12.218-0400|INFO|sun-appserver9.1| javax.enterprise.system.core|_ThreadID=10;_ThreadName=main;| Application server startup complete.|#]

[#|2008-05-21T13:17:12.918-0400|INFO|sun-appserver9.1| org.springframework.web.context.support.StaticWebApplicationContext| _ThreadID=17;_ThreadName=hudson initialization thread;|Refreshing  org. springframework. web.context.support.StaticWebApplicationContext@1362ca8: display  name [Root WebApplicationContext]; startup date [Wed May 21 13:17:12  EDT 2008]; root of context hierarchy|#]

[#|2008-05-21T13:17:12.920-0400|INFO|sun-appserver9.1| org.springframework.web.context.support.StaticWebApplicationContext| _ThreadID=17;_ThreadName=hudson initialization thread;|Bean factory  for application context [org.springframework.web.context.support.StaticWebApplicationContext @1362ca8]:  org. springframework. beans.factory.support.DefaultListableBeanFactory@d7373f|#]

[#|2008-05-21T13:17:12.921-0400|INFO|sun-appserver9.1| org.springframework.beans.factory.support.DefaultListableBeanFactory| _ThreadID=17;_ThreadName=hudson initialization thread;|Pre- instantiating singletons in  org. springframework. beans.factory.support.DefaultListableBeanFactory@d7373f: defining  beans [authenticationManager,userDetailsService]; root of factory  hierarchy|#]

[#|2008-05-21T13:17:12.960-0400|INFO|sun-appserver9.1| hudson.model.Hudson|_ThreadID=17;_ThreadName=hudson initialization  thread;|Took 1760 ms to load|#]

[#|2008-05-21T13:17:13.007-0400|SEVERE|sun-appserver9.1| hudson.WebAppMain|_ThreadID=17;_ThreadName=hudson initialization  thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Failed to  initialize Hudson
java.lang.NullPointerException
       at hudson.slaves.SlaveComputer.closeChannel (SlaveComputer.java:259)
       at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
       at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
       at hudson.model.Computer.<init>(Computer.java:74)
       at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
       at hudson.model.Slave.createComputer(Slave.java:246)
       at hudson.model.Hudson.updateComputer(Hudson.java:576)
       at hudson.model.Hudson.updateComputerList(Hudson.java:556)
       at hudson.model.Hudson.<init>(Hudson.java:351)
       at hudson.WebAppMain$2.run(WebAppMain.java:155)
|#]

[#|2008-05-21T13:17:13.010-0400|WARNING|sun-appserver9.1| javax.enterprise.system.stream.err|_ThreadID=17;_ThreadName=hudson  initialization thread;_RequestID=cd5b4695- a356-45fb-873a-17367207533f;|Exception in thread "hudson  initialization thread" |#]

[#|2008-05-21T13:17:13.018-0400|WARNING|sun-appserver9.1| javax.enterprise.system.stream.err|_ThreadID=17;_ThreadName=hudson  initialization thread;_RequestID=cd5b4695- a356-45fb-873a-17367207533f;|java.lang.NullPointerException
       at hudson.slaves.SlaveComputer.closeChannel (SlaveComputer.java:259)
       at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
       at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
       at hudson.model.Computer.<init>(Computer.java:74)
       at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
       at hudson.model.Slave.createComputer(Slave.java:246)
       at hudson.model.Hudson.updateComputer(Hudson.java:576)
       at hudson.model.Hudson.updateComputerList(Hudson.java:556)
       at hudson.model.Hudson.<init>(Hudson.java:351)
       at hudson.WebAppMain$2.run(WebAppMain.java:155)
|#]

[#|2008-05-21T13:17:38.074-0400|INFO|sun-appserver9.1| javax.enterprise.resource.webcontainer.jsf.config



--
Kohsuke Kawaguchi
Sun Microsystems                   [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: hudson 1.217 issue -" Please wait while hudson is getting ready to work..."

stephenconnolly
so the channelLock has not been initialized!

seems like partially constructed objects leaking from the constructor.... we all have to read the train book again

On Wed, May 21, 2008 at 8:10 PM, Stephen Connolly <[hidden email]> wrote:
Ahhh the iPod didn;t show the log!


On Wed, May 21, 2008 at 8:03 PM, Kohsuke Kawaguchi <[hidden email]> wrote:
Stephen Connolly wrote:
other than you have a null pointer!

a stack trace might help us

It's in the log:


[#|2008-05-21T13:17:13.007-0400|SEVERE|sun-appserver9.1|
> hudson.WebAppMain|_ThreadID=17;_ThreadName=hudson initialization
> thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Failed to
> initialize Hudson
> java.lang.NullPointerException
>         at hudson.slaves.SlaveComputer.closeChannel
> (SlaveComputer.java:259)
>         at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
>         at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
>         at hudson.model.Computer.<init>(Computer.java:74)
>         at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
>         at hudson.model.Slave.createComputer(Slave.java:246)
>         at hudson.model.Hudson.updateComputer(Hudson.java:576)
>         at hudson.model.Hudson.updateComputerList(Hudson.java:556)
>         at hudson.model.Hudson.<init>(Hudson.java:351)
>         at hudson.WebAppMain$2.run(WebAppMain.java:155)
> |#]



Sent from my iPod

On 21 May 2008, at 18:30, "Messmer, Jason" <[hidden email]>  wrote:

All,

I am getting a NullPointerException for the slaves when deployed  1.217, which displays "Please wait while hudson is getting ready to  work..."
Any clues...

Thanks,
~Jay







[#|2008-05-21T13:17:12.111-0400|INFO|sun-appserver9.1| javax.enterprise.system.core.selfmanagement| _ThreadID=10;_ThreadName=main;|SMGT0007: Self Management Rules  service is enabled|#]

[#|2008-05-21T13:17:12.186-0400|WARNING|sun-appserver9.1| javax.enterprise.system.container.ejb| _ThreadID= 10;_ThreadName=main;_RequestID=4c2fc416-86e5-4fc6-909b-7358e9142acf;| EJBLifeCycle: Automatic  timer migration component not enabled  for  DAS instance|#]

[#|2008-05-21T13:17:12.218-0400|INFO|sun-appserver9.1| javax.enterprise.system.core|_ThreadID=10;_ThreadName=main;| Application server startup complete.|#]

[#|2008-05-21T13:17:12.918-0400|INFO|sun-appserver9.1| org.springframework.web.context.support.StaticWebApplicationContext| _ThreadID=17;_ThreadName=hudson initialization thread;|Refreshing  org. springframework. web.context.support.StaticWebApplicationContext@1362ca8: display  name [Root WebApplicationContext]; startup date [Wed May 21 13:17:12  EDT 2008]; root of context hierarchy|#]

[#|2008-05-21T13:17:12.920-0400|INFO|sun-appserver9.1| org.springframework.web.context.support.StaticWebApplicationContext| _ThreadID=17;_ThreadName=hudson initialization thread;|Bean factory  for application context [org.springframework.web.context.support.StaticWebApplicationContext @1362ca8]:  org. springframework. beans.factory.support.DefaultListableBeanFactory@d7373f|#]

[#|2008-05-21T13:17:12.921-0400|INFO|sun-appserver9.1| org.springframework.beans.factory.support.DefaultListableBeanFactory| _ThreadID=17;_ThreadName=hudson initialization thread;|Pre- instantiating singletons in  org. springframework. beans.factory.support.DefaultListableBeanFactory@d7373f: defining  beans [authenticationManager,userDetailsService]; root of factory  hierarchy|#]

[#|2008-05-21T13:17:12.960-0400|INFO|sun-appserver9.1| hudson.model.Hudson|_ThreadID=17;_ThreadName=hudson initialization  thread;|Took 1760 ms to load|#]

[#|2008-05-21T13:17:13.007-0400|SEVERE|sun-appserver9.1| hudson.WebAppMain|_ThreadID=17;_ThreadName=hudson initialization  thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Failed to  initialize Hudson
java.lang.NullPointerException
       at hudson.slaves.SlaveComputer.closeChannel (SlaveComputer.java:259)
       at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
       at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
       at hudson.model.Computer.<init>(Computer.java:74)
       at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
       at hudson.model.Slave.createComputer(Slave.java:246)
       at hudson.model.Hudson.updateComputer(Hudson.java:576)
       at hudson.model.Hudson.updateComputerList(Hudson.java:556)
       at hudson.model.Hudson.<init>(Hudson.java:351)
       at hudson.WebAppMain$2.run(WebAppMain.java:155)
|#]

[#|2008-05-21T13:17:13.010-0400|WARNING|sun-appserver9.1| javax.enterprise.system.stream.err|_ThreadID=17;_ThreadName=hudson  initialization thread;_RequestID=cd5b4695- a356-45fb-873a-17367207533f;|Exception in thread "hudson  initialization thread" |#]

[#|2008-05-21T13:17:13.018-0400|WARNING|sun-appserver9.1| javax.enterprise.system.stream.err|_ThreadID=17;_ThreadName=hudson  initialization thread;_RequestID=cd5b4695- a356-45fb-873a-17367207533f;|java.lang.NullPointerException
       at hudson.slaves.SlaveComputer.closeChannel (SlaveComputer.java:259)
       at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
       at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
       at hudson.model.Computer.<init>(Computer.java:74)
       at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
       at hudson.model.Slave.createComputer(Slave.java:246)
       at hudson.model.Hudson.updateComputer(Hudson.java:576)
       at hudson.model.Hudson.updateComputerList(Hudson.java:556)
       at hudson.model.Hudson.<init>(Hudson.java:351)
       at hudson.WebAppMain$2.run(WebAppMain.java:155)
|#]

[#|2008-05-21T13:17:38.074-0400|INFO|sun-appserver9.1| javax.enterprise.resource.webcontainer.jsf.config



--
Kohsuke Kawaguchi
Sun Microsystems                   [hidden email]


Reply | Threaded
Open this post in threaded view
|

Re: hudson 1.217 issue -" Please wait while hudson is getting ready to work..."

stephenconnolly
Hmmm I am not sure why this NPE is happening...

on line 101: we call closeChannel(), which will set the channel to null... and close it if it is null... but line 99 ensures that channel has to be null...

Somehow, launch is being called before the SlaveComputer constructor has completed... that is bad practice. We should be using a factory method according to Java Concurrency In Practice.

Before I added the missing synchronization, this was not an issue, as the channelLock field was not being consulted until the launch's task on the executor started, which is usually after the constructor completes.

The launch is being triggered in the super constructor, which is why channelLock has not been initialized.

There are some bad concurrency issue smells all over this code.

I think the quick fix is to remove line 101.

The long fix is to remove this hidden automatic launch from within the constructor of Computer

On Wed, May 21, 2008 at 8:14 PM, Stephen Connolly <[hidden email]> wrote:
so the channelLock has not been initialized!

seems like partially constructed objects leaking from the constructor.... we all have to read the train book again


On Wed, May 21, 2008 at 8:10 PM, Stephen Connolly <[hidden email]> wrote:
Ahhh the iPod didn;t show the log!


On Wed, May 21, 2008 at 8:03 PM, Kohsuke Kawaguchi <[hidden email]> wrote:
Stephen Connolly wrote:
other than you have a null pointer!

a stack trace might help us

It's in the log:


[#|2008-05-21T13:17:13.007-0400|SEVERE|sun-appserver9.1|
> hudson.WebAppMain|_ThreadID=17;_ThreadName=hudson initialization
> thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Failed to
> initialize Hudson
> java.lang.NullPointerException
>         at hudson.slaves.SlaveComputer.closeChannel
> (SlaveComputer.java:259)
>         at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
>         at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
>         at hudson.model.Computer.<init>(Computer.java:74)
>         at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
>         at hudson.model.Slave.createComputer(Slave.java:246)
>         at hudson.model.Hudson.updateComputer(Hudson.java:576)
>         at hudson.model.Hudson.updateComputerList(Hudson.java:556)
>         at hudson.model.Hudson.<init>(Hudson.java:351)
>         at hudson.WebAppMain$2.run(WebAppMain.java:155)
> |#]



Sent from my iPod

On 21 May 2008, at 18:30, "Messmer, Jason" <[hidden email]>  wrote:

All,

I am getting a NullPointerException for the slaves when deployed  1.217, which displays "Please wait while hudson is getting ready to  work..."
Any clues...

Thanks,
~Jay







[#|2008-05-21T13:17:12.111-0400|INFO|sun-appserver9.1| javax.enterprise.system.core.selfmanagement| _ThreadID=10;_ThreadName=main;|SMGT0007: Self Management Rules  service is enabled|#]

[#|2008-05-21T13:17:12.186-0400|WARNING|sun-appserver9.1| javax.enterprise.system.container.ejb| _ThreadID= 10;_ThreadName=main;_RequestID=4c2fc416-86e5-4fc6-909b-7358e9142acf;| EJBLifeCycle: Automatic  timer migration component not enabled  for  DAS instance|#]

[#|2008-05-21T13:17:12.218-0400|INFO|sun-appserver9.1| javax.enterprise.system.core|_ThreadID=10;_ThreadName=main;| Application server startup complete.|#]

[#|2008-05-21T13:17:12.918-0400|INFO|sun-appserver9.1| org.springframework.web.context.support.StaticWebApplicationContext| _ThreadID=17;_ThreadName=hudson initialization thread;|Refreshing  org. springframework. web.context.support.StaticWebApplicationContext@1362ca8: display  name [Root WebApplicationContext]; startup date [Wed May 21 13:17:12  EDT 2008]; root of context hierarchy|#]

[#|2008-05-21T13:17:12.920-0400|INFO|sun-appserver9.1| org.springframework.web.context.support.StaticWebApplicationContext| _ThreadID=17;_ThreadName=hudson initialization thread;|Bean factory  for application context [org.springframework.web.context.support.StaticWebApplicationContext @1362ca8]:  org. springframework. beans.factory.support.DefaultListableBeanFactory@d7373f|#]

[#|2008-05-21T13:17:12.921-0400|INFO|sun-appserver9.1| org.springframework.beans.factory.support.DefaultListableBeanFactory| _ThreadID=17;_ThreadName=hudson initialization thread;|Pre- instantiating singletons in  org. springframework. beans.factory.support.DefaultListableBeanFactory@d7373f: defining  beans [authenticationManager,userDetailsService]; root of factory  hierarchy|#]

[#|2008-05-21T13:17:12.960-0400|INFO|sun-appserver9.1| hudson.model.Hudson|_ThreadID=17;_ThreadName=hudson initialization  thread;|Took 1760 ms to load|#]

[#|2008-05-21T13:17:13.007-0400|SEVERE|sun-appserver9.1| hudson.WebAppMain|_ThreadID=17;_ThreadName=hudson initialization  thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Failed to  initialize Hudson
java.lang.NullPointerException
       at hudson.slaves.SlaveComputer.closeChannel (SlaveComputer.java:259)
       at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
       at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
       at hudson.model.Computer.<init>(Computer.java:74)
       at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
       at hudson.model.Slave.createComputer(Slave.java:246)
       at hudson.model.Hudson.updateComputer(Hudson.java:576)
       at hudson.model.Hudson.updateComputerList(Hudson.java:556)
       at hudson.model.Hudson.<init>(Hudson.java:351)
       at hudson.WebAppMain$2.run(WebAppMain.java:155)
|#]

[#|2008-05-21T13:17:13.010-0400|WARNING|sun-appserver9.1| javax.enterprise.system.stream.err|_ThreadID=17;_ThreadName=hudson  initialization thread;_RequestID=cd5b4695- a356-45fb-873a-17367207533f;|Exception in thread "hudson  initialization thread" |#]

[#|2008-05-21T13:17:13.018-0400|WARNING|sun-appserver9.1| javax.enterprise.system.stream.err|_ThreadID=17;_ThreadName=hudson  initialization thread;_RequestID=cd5b4695- a356-45fb-873a-17367207533f;|java.lang.NullPointerException
       at hudson.slaves.SlaveComputer.closeChannel (SlaveComputer.java:259)
       at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
       at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
       at hudson.model.Computer.<init>(Computer.java:74)
       at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
       at hudson.model.Slave.createComputer(Slave.java:246)
       at hudson.model.Hudson.updateComputer(Hudson.java:576)
       at hudson.model.Hudson.updateComputerList(Hudson.java:556)
       at hudson.model.Hudson.<init>(Hudson.java:351)
       at hudson.WebAppMain$2.run(WebAppMain.java:155)
|#]

[#|2008-05-21T13:17:38.074-0400|INFO|sun-appserver9.1| javax.enterprise.resource.webcontainer.jsf.config



--
Kohsuke Kawaguchi
Sun Microsystems                   [hidden email]



Reply | Threaded
Open this post in threaded view
|

Re: hudson 1.217 issue -" Please wait while hudson is getting ready to work..."

stephenconnolly
Yep... should have looked at the stack trace:

        at hudson.slaves.SlaveComputer.closeChannel(SlaveComputer.java:259)
        at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
****   at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)  *****
        at hudson.model.Computer.<init>(Computer.java:74)
        at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)

Calling non-final methods from a constructor will lead you to ruin!

SlaveComputer.<init> calls it's super, which calls setNode, which is overridden by SlaveComputer... now we are in SlaveComputer, but we are not fully constructed

On Wed, May 21, 2008 at 8:25 PM, Stephen Connolly <[hidden email]> wrote:
Hmmm I am not sure why this NPE is happening...

on line 101: we call closeChannel(), which will set the channel to null... and close it if it is null... but line 99 ensures that channel has to be null...

Somehow, launch is being called before the SlaveComputer constructor has completed... that is bad practice. We should be using a factory method according to Java Concurrency In Practice.

Before I added the missing synchronization, this was not an issue, as the channelLock field was not being consulted until the launch's task on the executor started, which is usually after the constructor completes.

The launch is being triggered in the super constructor, which is why channelLock has not been initialized.

There are some bad concurrency issue smells all over this code.

I think the quick fix is to remove line 101.

The long fix is to remove this hidden automatic launch from within the constructor of Computer


On Wed, May 21, 2008 at 8:14 PM, Stephen Connolly <[hidden email]> wrote:
so the channelLock has not been initialized!

seems like partially constructed objects leaking from the constructor.... we all have to read the train book again


On Wed, May 21, 2008 at 8:10 PM, Stephen Connolly <[hidden email]> wrote:
Ahhh the iPod didn;t show the log!


On Wed, May 21, 2008 at 8:03 PM, Kohsuke Kawaguchi <[hidden email]> wrote:
Stephen Connolly wrote:
other than you have a null pointer!

a stack trace might help us

It's in the log:


[#|2008-05-21T13:17:13.007-0400|SEVERE|sun-appserver9.1|
> hudson.WebAppMain|_ThreadID=17;_ThreadName=hudson initialization
> thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Failed to
> initialize Hudson
> java.lang.NullPointerException
>         at hudson.slaves.SlaveComputer.closeChannel
> (SlaveComputer.java:259)
>         at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
>         at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
>         at hudson.model.Computer.<init>(Computer.java:74)
>         at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
>         at hudson.model.Slave.createComputer(Slave.java:246)
>         at hudson.model.Hudson.updateComputer(Hudson.java:576)
>         at hudson.model.Hudson.updateComputerList(Hudson.java:556)
>         at hudson.model.Hudson.<init>(Hudson.java:351)
>         at hudson.WebAppMain$2.run(WebAppMain.java:155)
> |#]



Sent from my iPod

On 21 May 2008, at 18:30, "Messmer, Jason" <[hidden email]>  wrote:

All,

I am getting a NullPointerException for the slaves when deployed  1.217, which displays "Please wait while hudson is getting ready to  work..."
Any clues...

Thanks,
~Jay







[#|2008-05-21T13:17:12.111-0400|INFO|sun-appserver9.1| javax.enterprise.system.core.selfmanagement| _ThreadID=10;_ThreadName=main;|SMGT0007: Self Management Rules  service is enabled|#]

[#|2008-05-21T13:17:12.186-0400|WARNING|sun-appserver9.1| javax.enterprise.system.container.ejb| _ThreadID= 10;_ThreadName=main;_RequestID=4c2fc416-86e5-4fc6-909b-7358e9142acf;| EJBLifeCycle: Automatic  timer migration component not enabled  for  DAS instance|#]

[#|2008-05-21T13:17:12.218-0400|INFO|sun-appserver9.1| javax.enterprise.system.core|_ThreadID=10;_ThreadName=main;| Application server startup complete.|#]

[#|2008-05-21T13:17:12.918-0400|INFO|sun-appserver9.1| org.springframework.web.context.support.StaticWebApplicationContext| _ThreadID=17;_ThreadName=hudson initialization thread;|Refreshing  org. springframework. web.context.support.StaticWebApplicationContext@1362ca8: display  name [Root WebApplicationContext]; startup date [Wed May 21 13:17:12  EDT 2008]; root of context hierarchy|#]

[#|2008-05-21T13:17:12.920-0400|INFO|sun-appserver9.1| org.springframework.web.context.support.StaticWebApplicationContext| _ThreadID=17;_ThreadName=hudson initialization thread;|Bean factory  for application context [org.springframework.web.context.support.StaticWebApplicationContext @1362ca8]:  org. springframework. beans.factory.support.DefaultListableBeanFactory@d7373f|#]

[#|2008-05-21T13:17:12.921-0400|INFO|sun-appserver9.1| org.springframework.beans.factory.support.DefaultListableBeanFactory| _ThreadID=17;_ThreadName=hudson initialization thread;|Pre- instantiating singletons in  org. springframework. beans.factory.support.DefaultListableBeanFactory@d7373f: defining  beans [authenticationManager,userDetailsService]; root of factory  hierarchy|#]

[#|2008-05-21T13:17:12.960-0400|INFO|sun-appserver9.1| hudson.model.Hudson|_ThreadID=17;_ThreadName=hudson initialization  thread;|Took 1760 ms to load|#]

[#|2008-05-21T13:17:13.007-0400|SEVERE|sun-appserver9.1| hudson.WebAppMain|_ThreadID=17;_ThreadName=hudson initialization  thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Failed to  initialize Hudson
java.lang.NullPointerException
       at hudson.slaves.SlaveComputer.closeChannel (SlaveComputer.java:259)
       at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
       at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
       at hudson.model.Computer.<init>(Computer.java:74)
       at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
       at hudson.model.Slave.createComputer(Slave.java:246)
       at hudson.model.Hudson.updateComputer(Hudson.java:576)
       at hudson.model.Hudson.updateComputerList(Hudson.java:556)
       at hudson.model.Hudson.<init>(Hudson.java:351)
       at hudson.WebAppMain$2.run(WebAppMain.java:155)
|#]

[#|2008-05-21T13:17:13.010-0400|WARNING|sun-appserver9.1| javax.enterprise.system.stream.err|_ThreadID=17;_ThreadName=hudson  initialization thread;_RequestID=cd5b4695- a356-45fb-873a-17367207533f;|Exception in thread "hudson  initialization thread" |#]

[#|2008-05-21T13:17:13.018-0400|WARNING|sun-appserver9.1| javax.enterprise.system.stream.err|_ThreadID=17;_ThreadName=hudson  initialization thread;_RequestID=cd5b4695- a356-45fb-873a-17367207533f;|java.lang.NullPointerException
       at hudson.slaves.SlaveComputer.closeChannel (SlaveComputer.java:259)
       at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
       at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
       at hudson.model.Computer.<init>(Computer.java:74)
       at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
       at hudson.model.Slave.createComputer(Slave.java:246)
       at hudson.model.Hudson.updateComputer(Hudson.java:576)
       at hudson.model.Hudson.updateComputerList(Hudson.java:556)
       at hudson.model.Hudson.<init>(Hudson.java:351)
       at hudson.WebAppMain$2.run(WebAppMain.java:155)
|#]

[#|2008-05-21T13:17:38.074-0400|INFO|sun-appserver9.1| javax.enterprise.resource.webcontainer.jsf.config



--
Kohsuke Kawaguchi
Sun Microsystems                   [hidden email]




Reply | Threaded
Open this post in threaded view
|

Re: hudson 1.217 issue -" Please wait while hudson is getting ready to work..."

stephenconnolly
Of course none of this was a problem until I noticed that closeChannel was not using the lock it should have been sharing with setChannel!

On Wed, May 21, 2008 at 8:28 PM, Stephen Connolly <[hidden email]> wrote:
Yep... should have looked at the stack trace:


        at hudson.slaves.SlaveComputer.closeChannel(SlaveComputer.java:259)
        at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
****   at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)  *****
        at hudson.model.Computer.<init>(Computer.java:74)
        at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)

Calling non-final methods from a constructor will lead you to ruin!

SlaveComputer.<init> calls it's super, which calls setNode, which is overridden by SlaveComputer... now we are in SlaveComputer, but we are not fully constructed


On Wed, May 21, 2008 at 8:25 PM, Stephen Connolly <[hidden email]> wrote:
Hmmm I am not sure why this NPE is happening...

on line 101: we call closeChannel(), which will set the channel to null... and close it if it is null... but line 99 ensures that channel has to be null...

Somehow, launch is being called before the SlaveComputer constructor has completed... that is bad practice. We should be using a factory method according to Java Concurrency In Practice.

Before I added the missing synchronization, this was not an issue, as the channelLock field was not being consulted until the launch's task on the executor started, which is usually after the constructor completes.

The launch is being triggered in the super constructor, which is why channelLock has not been initialized.

There are some bad concurrency issue smells all over this code.

I think the quick fix is to remove line 101.

The long fix is to remove this hidden automatic launch from within the constructor of Computer


On Wed, May 21, 2008 at 8:14 PM, Stephen Connolly <[hidden email]> wrote:
so the channelLock has not been initialized!

seems like partially constructed objects leaking from the constructor.... we all have to read the train book again


On Wed, May 21, 2008 at 8:10 PM, Stephen Connolly <[hidden email]> wrote:
Ahhh the iPod didn;t show the log!


On Wed, May 21, 2008 at 8:03 PM, Kohsuke Kawaguchi <[hidden email]> wrote:
Stephen Connolly wrote:
other than you have a null pointer!

a stack trace might help us

It's in the log:


[#|2008-05-21T13:17:13.007-0400|SEVERE|sun-appserver9.1|
> hudson.WebAppMain|_ThreadID=17;_ThreadName=hudson initialization
> thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Failed to
> initialize Hudson
> java.lang.NullPointerException
>         at hudson.slaves.SlaveComputer.closeChannel
> (SlaveComputer.java:259)
>         at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
>         at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
>         at hudson.model.Computer.<init>(Computer.java:74)
>         at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
>         at hudson.model.Slave.createComputer(Slave.java:246)
>         at hudson.model.Hudson.updateComputer(Hudson.java:576)
>         at hudson.model.Hudson.updateComputerList(Hudson.java:556)
>         at hudson.model.Hudson.<init>(Hudson.java:351)
>         at hudson.WebAppMain$2.run(WebAppMain.java:155)
> |#]



Sent from my iPod

On 21 May 2008, at 18:30, "Messmer, Jason" <[hidden email]>  wrote:

All,

I am getting a NullPointerException for the slaves when deployed  1.217, which displays "Please wait while hudson is getting ready to  work..."
Any clues...

Thanks,
~Jay







[#|2008-05-21T13:17:12.111-0400|INFO|sun-appserver9.1| javax.enterprise.system.core.selfmanagement| _ThreadID=10;_ThreadName=main;|SMGT0007: Self Management Rules  service is enabled|#]

[#|2008-05-21T13:17:12.186-0400|WARNING|sun-appserver9.1| javax.enterprise.system.container.ejb| _ThreadID= 10;_ThreadName=main;_RequestID=4c2fc416-86e5-4fc6-909b-7358e9142acf;| EJBLifeCycle: Automatic  timer migration component not enabled  for  DAS instance|#]

[#|2008-05-21T13:17:12.218-0400|INFO|sun-appserver9.1| javax.enterprise.system.core|_ThreadID=10;_ThreadName=main;| Application server startup complete.|#]

[#|2008-05-21T13:17:12.918-0400|INFO|sun-appserver9.1| org.springframework.web.context.support.StaticWebApplicationContext| _ThreadID=17;_ThreadName=hudson initialization thread;|Refreshing  org. springframework. web.context.support.StaticWebApplicationContext@1362ca8: display  name [Root WebApplicationContext]; startup date [Wed May 21 13:17:12  EDT 2008]; root of context hierarchy|#]

[#|2008-05-21T13:17:12.920-0400|INFO|sun-appserver9.1| org.springframework.web.context.support.StaticWebApplicationContext| _ThreadID=17;_ThreadName=hudson initialization thread;|Bean factory  for application context [org.springframework.web.context.support.StaticWebApplicationContext @1362ca8]:  org. springframework. beans.factory.support.DefaultListableBeanFactory@d7373f|#]

[#|2008-05-21T13:17:12.921-0400|INFO|sun-appserver9.1| org.springframework.beans.factory.support.DefaultListableBeanFactory| _ThreadID=17;_ThreadName=hudson initialization thread;|Pre- instantiating singletons in  org. springframework. beans.factory.support.DefaultListableBeanFactory@d7373f: defining  beans [authenticationManager,userDetailsService]; root of factory  hierarchy|#]

[#|2008-05-21T13:17:12.960-0400|INFO|sun-appserver9.1| hudson.model.Hudson|_ThreadID=17;_ThreadName=hudson initialization  thread;|Took 1760 ms to load|#]

[#|2008-05-21T13:17:13.007-0400|SEVERE|sun-appserver9.1| hudson.WebAppMain|_ThreadID=17;_ThreadName=hudson initialization  thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Failed to  initialize Hudson
java.lang.NullPointerException
       at hudson.slaves.SlaveComputer.closeChannel (SlaveComputer.java:259)
       at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
       at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
       at hudson.model.Computer.<init>(Computer.java:74)
       at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
       at hudson.model.Slave.createComputer(Slave.java:246)
       at hudson.model.Hudson.updateComputer(Hudson.java:576)
       at hudson.model.Hudson.updateComputerList(Hudson.java:556)
       at hudson.model.Hudson.<init>(Hudson.java:351)
       at hudson.WebAppMain$2.run(WebAppMain.java:155)
|#]

[#|2008-05-21T13:17:13.010-0400|WARNING|sun-appserver9.1| javax.enterprise.system.stream.err|_ThreadID=17;_ThreadName=hudson  initialization thread;_RequestID=cd5b4695- a356-45fb-873a-17367207533f;|Exception in thread "hudson  initialization thread" |#]

[#|2008-05-21T13:17:13.018-0400|WARNING|sun-appserver9.1| javax.enterprise.system.stream.err|_ThreadID=17;_ThreadName=hudson  initialization thread;_RequestID=cd5b4695- a356-45fb-873a-17367207533f;|java.lang.NullPointerException
       at hudson.slaves.SlaveComputer.closeChannel (SlaveComputer.java:259)
       at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
       at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
       at hudson.model.Computer.<init>(Computer.java:74)
       at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
       at hudson.model.Slave.createComputer(Slave.java:246)
       at hudson.model.Hudson.updateComputer(Hudson.java:576)
       at hudson.model.Hudson.updateComputerList(Hudson.java:556)
       at hudson.model.Hudson.<init>(Hudson.java:351)
       at hudson.WebAppMain$2.run(WebAppMain.java:155)
|#]

[#|2008-05-21T13:17:38.074-0400|INFO|sun-appserver9.1| javax.enterprise.resource.webcontainer.jsf.config



--
Kohsuke Kawaguchi
Sun Microsystems                   [hidden email]





Reply | Threaded
Open this post in threaded view
|

Re: hudson 1.217 issue -" Please wait while hudson is getting ready to work..."

stephenconnolly
I have committed to SVN a commenting out of line 279.

This is the quickest "safe" fix to let people work again.

The real fix is to re-organise the constructors to prevent partially constructed objects leaking... which I don't have the time for at the moment

-Stephen

On Wed, May 21, 2008 at 8:30 PM, Stephen Connolly <[hidden email]> wrote:
Of course none of this was a problem until I noticed that closeChannel was not using the lock it should have been sharing with setChannel!


On Wed, May 21, 2008 at 8:28 PM, Stephen Connolly <[hidden email]> wrote:
Yep... should have looked at the stack trace:


        at hudson.slaves.SlaveComputer.closeChannel(SlaveComputer.java:259)
        at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
****   at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)  *****
        at hudson.model.Computer.<init>(Computer.java:74)
        at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)

Calling non-final methods from a constructor will lead you to ruin!

SlaveComputer.<init> calls it's super, which calls setNode, which is overridden by SlaveComputer... now we are in SlaveComputer, but we are not fully constructed


On Wed, May 21, 2008 at 8:25 PM, Stephen Connolly <[hidden email]> wrote:
Hmmm I am not sure why this NPE is happening...

on line 101: we call closeChannel(), which will set the channel to null... and close it if it is null... but line 99 ensures that channel has to be null...

Somehow, launch is being called before the SlaveComputer constructor has completed... that is bad practice. We should be using a factory method according to Java Concurrency In Practice.

Before I added the missing synchronization, this was not an issue, as the channelLock field was not being consulted until the launch's task on the executor started, which is usually after the constructor completes.

The launch is being triggered in the super constructor, which is why channelLock has not been initialized.

There are some bad concurrency issue smells all over this code.

I think the quick fix is to remove line 101.

The long fix is to remove this hidden automatic launch from within the constructor of Computer


On Wed, May 21, 2008 at 8:14 PM, Stephen Connolly <[hidden email]> wrote:
so the channelLock has not been initialized!

seems like partially constructed objects leaking from the constructor.... we all have to read the train book again


On Wed, May 21, 2008 at 8:10 PM, Stephen Connolly <[hidden email]> wrote:
Ahhh the iPod didn;t show the log!


On Wed, May 21, 2008 at 8:03 PM, Kohsuke Kawaguchi <[hidden email]> wrote:
Stephen Connolly wrote:
other than you have a null pointer!

a stack trace might help us

It's in the log:


[#|2008-05-21T13:17:13.007-0400|SEVERE|sun-appserver9.1|
> hudson.WebAppMain|_ThreadID=17;_ThreadName=hudson initialization
> thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Failed to
> initialize Hudson
> java.lang.NullPointerException
>         at hudson.slaves.SlaveComputer.closeChannel
> (SlaveComputer.java:259)
>         at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
>         at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
>         at hudson.model.Computer.<init>(Computer.java:74)
>         at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
>         at hudson.model.Slave.createComputer(Slave.java:246)
>         at hudson.model.Hudson.updateComputer(Hudson.java:576)
>         at hudson.model.Hudson.updateComputerList(Hudson.java:556)
>         at hudson.model.Hudson.<init>(Hudson.java:351)
>         at hudson.WebAppMain$2.run(WebAppMain.java:155)
> |#]



Sent from my iPod

On 21 May 2008, at 18:30, "Messmer, Jason" <[hidden email]>  wrote:

All,

I am getting a NullPointerException for the slaves when deployed  1.217, which displays "Please wait while hudson is getting ready to  work..."
Any clues...

Thanks,
~Jay







[#|2008-05-21T13:17:12.111-0400|INFO|sun-appserver9.1| javax.enterprise.system.core.selfmanagement| _ThreadID=10;_ThreadName=main;|SMGT0007: Self Management Rules  service is enabled|#]

[#|2008-05-21T13:17:12.186-0400|WARNING|sun-appserver9.1| javax.enterprise.system.container.ejb| _ThreadID= 10;_ThreadName=main;_RequestID=4c2fc416-86e5-4fc6-909b-7358e9142acf;| EJBLifeCycle: Automatic  timer migration component not enabled  for  DAS instance|#]

[#|2008-05-21T13:17:12.218-0400|INFO|sun-appserver9.1| javax.enterprise.system.core|_ThreadID=10;_ThreadName=main;| Application server startup complete.|#]

[#|2008-05-21T13:17:12.918-0400|INFO|sun-appserver9.1| org.springframework.web.context.support.StaticWebApplicationContext| _ThreadID=17;_ThreadName=hudson initialization thread;|Refreshing  org. springframework. web.context.support.StaticWebApplicationContext@1362ca8: display  name [Root WebApplicationContext]; startup date [Wed May 21 13:17:12  EDT 2008]; root of context hierarchy|#]

[#|2008-05-21T13:17:12.920-0400|INFO|sun-appserver9.1| org.springframework.web.context.support.StaticWebApplicationContext| _ThreadID=17;_ThreadName=hudson initialization thread;|Bean factory  for application context [org.springframework.web.context.support.StaticWebApplicationContext @1362ca8]:  org. springframework. beans.factory.support.DefaultListableBeanFactory@d7373f|#]

[#|2008-05-21T13:17:12.921-0400|INFO|sun-appserver9.1| org.springframework.beans.factory.support.DefaultListableBeanFactory| _ThreadID=17;_ThreadName=hudson initialization thread;|Pre- instantiating singletons in  org. springframework. beans.factory.support.DefaultListableBeanFactory@d7373f: defining  beans [authenticationManager,userDetailsService]; root of factory  hierarchy|#]

[#|2008-05-21T13:17:12.960-0400|INFO|sun-appserver9.1| hudson.model.Hudson|_ThreadID=17;_ThreadName=hudson initialization  thread;|Took 1760 ms to load|#]

[#|2008-05-21T13:17:13.007-0400|SEVERE|sun-appserver9.1| hudson.WebAppMain|_ThreadID=17;_ThreadName=hudson initialization  thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Failed to  initialize Hudson
java.lang.NullPointerException
       at hudson.slaves.SlaveComputer.closeChannel (SlaveComputer.java:259)
       at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
       at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
       at hudson.model.Computer.<init>(Computer.java:74)
       at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
       at hudson.model.Slave.createComputer(Slave.java:246)
       at hudson.model.Hudson.updateComputer(Hudson.java:576)
       at hudson.model.Hudson.updateComputerList(Hudson.java:556)
       at hudson.model.Hudson.<init>(Hudson.java:351)
       at hudson.WebAppMain$2.run(WebAppMain.java:155)
|#]

[#|2008-05-21T13:17:13.010-0400|WARNING|sun-appserver9.1| javax.enterprise.system.stream.err|_ThreadID=17;_ThreadName=hudson  initialization thread;_RequestID=cd5b4695- a356-45fb-873a-17367207533f;|Exception in thread "hudson  initialization thread" |#]

[#|2008-05-21T13:17:13.018-0400|WARNING|sun-appserver9.1| javax.enterprise.system.stream.err|_ThreadID=17;_ThreadName=hudson  initialization thread;_RequestID=cd5b4695- a356-45fb-873a-17367207533f;|java.lang.NullPointerException
       at hudson.slaves.SlaveComputer.closeChannel (SlaveComputer.java:259)
       at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
       at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
       at hudson.model.Computer.<init>(Computer.java:74)
       at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
       at hudson.model.Slave.createComputer(Slave.java:246)
       at hudson.model.Hudson.updateComputer(Hudson.java:576)
       at hudson.model.Hudson.updateComputerList(Hudson.java:556)
       at hudson.model.Hudson.<init>(Hudson.java:351)
       at hudson.WebAppMain$2.run(WebAppMain.java:155)
|#]

[#|2008-05-21T13:17:38.074-0400|INFO|sun-appserver9.1| javax.enterprise.resource.webcontainer.jsf.config



--
Kohsuke Kawaguchi
Sun Microsystems                   [hidden email]






Reply | Threaded
Open this post in threaded view
|

Re: hudson 1.217 issue -" Please wait while hudson is getting ready to work..."

Kohsuke Kawaguchi
Administrator

No, this won't launch a slave when Hudson first comes online.

I think a quickest safe fix is to roll back the synchronized block in
the closeChannel.

I mean, the race condition will be fairly rare, isn't it?

Stephen Connolly wrote:

> I have committed to SVN a commenting out of line 279.
>
> This is the quickest "safe" fix to let people work again.
>
> The real fix is to re-organise the constructors to prevent partially
> constructed objects leaking... which I don't have the time for at the moment
>
> -Stephen
>
> On Wed, May 21, 2008 at 8:30 PM, Stephen Connolly <
> [hidden email]> wrote:
>
>> Of course none of this was a problem until I noticed that closeChannel was
>> not using the lock it should have been sharing with setChannel!
>>
>>
>> On Wed, May 21, 2008 at 8:28 PM, Stephen Connolly <
>> [hidden email]> wrote:
>>
>>> Yep... should have looked at the stack trace:
>>>
>>>         at
>>> hudson.slaves.SlaveComputer.closeChannel(SlaveComputer.java:259)
>>>         at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
>>> ****   at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
>>> *****
>>>         at hudson.model.Computer.<init>(Computer.java:74)
>>>         at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
>>>
>>> Calling non-final methods from a constructor will lead you to ruin!
>>>
>>> SlaveComputer.<init> calls it's super, which calls setNode, which is
>>> overridden by SlaveComputer... now we are in SlaveComputer, but we are not
>>> fully constructed
>>>
>>>
>>> On Wed, May 21, 2008 at 8:25 PM, Stephen Connolly <
>>> [hidden email]> wrote:
>>>
>>>> Hmmm I am not sure why this NPE is happening...
>>>>
>>>> on line 101: we call closeChannel(), which will set the channel to
>>>> null... and close it if it is null... but line 99 ensures that channel has
>>>> to be null...
>>>>
>>>> Somehow, launch is being called before the SlaveComputer constructor has
>>>> completed... that is bad practice. We should be using a factory method
>>>> according to Java Concurrency In Practice.
>>>>
>>>> Before I added the missing synchronization, this was not an issue, as the
>>>> channelLock field was not being consulted until the launch's task on the
>>>> executor started, which is usually after the constructor completes.
>>>>
>>>> The launch is being triggered in the super constructor, which is why
>>>> channelLock has not been initialized.
>>>>
>>>> There are some bad concurrency issue smells all over this code.
>>>>
>>>> I think the quick fix is to remove line 101.
>>>>
>>>> The long fix is to remove this hidden automatic launch from within the
>>>> constructor of Computer
>>>>
>>>>
>>>> On Wed, May 21, 2008 at 8:14 PM, Stephen Connolly <
>>>> [hidden email]> wrote:
>>>>
>>>>> so the channelLock has not been initialized!
>>>>>
>>>>> seems like partially constructed objects leaking from the
>>>>> constructor.... we all have to read the train book again
>>>>>
>>>>>
>>>>> On Wed, May 21, 2008 at 8:10 PM, Stephen Connolly <
>>>>> [hidden email]> wrote:
>>>>>
>>>>>> Ahhh the iPod didn;t show the log!
>>>>>>
>>>>>>
>>>>>> On Wed, May 21, 2008 at 8:03 PM, Kohsuke Kawaguchi <
>>>>>> [hidden email]> wrote:
>>>>>>
>>>>>>> Stephen Connolly wrote:
>>>>>>>
>>>>>>>> other than you have a null pointer!
>>>>>>>>
>>>>>>>> a stack trace might help us
>>>>>>>>
>>>>>>>
>>>>>>> It's in the log:
>>>>>>>
>>>>>>>
>>>>>>> [#|2008-05-21T13:17:13.007-0400|SEVERE|sun-appserver9.1|
>>>>>>> > hudson.WebAppMain|_ThreadID=17;_ThreadName=hudson initialization
>>>>>>> > thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Failed to
>>>>>>> > initialize Hudson
>>>>>>> > java.lang.NullPointerException
>>>>>>> >         at hudson.slaves.SlaveComputer.closeChannel
>>>>>>> > (SlaveComputer.java:259)
>>>>>>> >         at
>>>>>>> hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
>>>>>>> >         at
>>>>>>> hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
>>>>>>> >         at hudson.model.Computer.<init>(Computer.java:74)
>>>>>>> >         at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
>>>>>>> >         at hudson.model.Slave.createComputer(Slave.java:246)
>>>>>>> >         at hudson.model.Hudson.updateComputer(Hudson.java:576)
>>>>>>> >         at hudson.model.Hudson.updateComputerList(Hudson.java:556)
>>>>>>> >         at hudson.model.Hudson.<init>(Hudson.java:351)
>>>>>>> >         at hudson.WebAppMain$2.run(WebAppMain.java:155)
>>>>>>> > |#]
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>> Sent from my iPod
>>>>>>>>
>>>>>>>> On 21 May 2008, at 18:30, "Messmer, Jason" <[hidden email]>
>>>>>>>>  wrote:
>>>>>>>>
>>>>>>>>  All,
>>>>>>>>>
>>>>>>>>> I am getting a NullPointerException for the slaves when deployed
>>>>>>>>>  1.217, which displays "Please wait while hudson is getting ready to
>>>>>>>>>  work..."
>>>>>>>>> Any clues...
>>>>>>>>>
>>>>>>>>> Thanks,
>>>>>>>>> ~Jay
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> [#|2008-05-21T13:17:12.111-0400|INFO|sun-appserver9.1|
>>>>>>>>> javax.enterprise.system.core.selfmanagement|
>>>>>>>>> _ThreadID=10;_ThreadName=main;|SMGT0007: Self Management Rules  service is
>>>>>>>>> enabled|#]
>>>>>>>>>
>>>>>>>>> [#|2008-05-21T13:17:12.186-0400|WARNING|sun-appserver9.1|
>>>>>>>>> javax.enterprise.system.container.ejb| _ThreadID=
>>>>>>>>> 10;_ThreadName=main;_RequestID=4c2fc416-86e5-4fc6-909b-7358e9142acf;|
>>>>>>>>> EJBLifeCycle: Automatic  timer migration component not enabled  for  DAS
>>>>>>>>> instance|#]
>>>>>>>>>
>>>>>>>>> [#|2008-05-21T13:17:12.218-0400|INFO|sun-appserver9.1|
>>>>>>>>> javax.enterprise.system.core|_ThreadID=10;_ThreadName=main;| Application
>>>>>>>>> server startup complete.|#]
>>>>>>>>>
>>>>>>>>> [#|2008-05-21T13:17:12.918-0400|INFO|sun-appserver9.1|
>>>>>>>>> org.springframework.web.context.support.StaticWebApplicationContext|
>>>>>>>>> _ThreadID=17;_ThreadName=hudson initialization thread;|Refreshing  org.
>>>>>>>>> springframework. web.context.support.StaticWebApplicationContext@1362ca8:
>>>>>>>>> display  name [Root WebApplicationContext]; startup date [Wed May 21
>>>>>>>>> 13:17:12  EDT 2008]; root of context hierarchy|#]
>>>>>>>>>
>>>>>>>>> [#|2008-05-21T13:17:12.920-0400|INFO|sun-appserver9.1|
>>>>>>>>> org.springframework.web.context.support.StaticWebApplicationContext|
>>>>>>>>> _ThreadID=17;_ThreadName=hudson initialization thread;|Bean factory  for
>>>>>>>>> application context
>>>>>>>>> [org.springframework.web.context.support.StaticWebApplicationContext
>>>>>>>>> @1362ca8]:  org. springframework.
>>>>>>>>> beans.factory.support.DefaultListableBeanFactory@d7373f|#]
>>>>>>>>>
>>>>>>>>> [#|2008-05-21T13:17:12.921-0400|INFO|sun-appserver9.1|
>>>>>>>>> org.springframework.beans.factory.support.DefaultListableBeanFactory|
>>>>>>>>> _ThreadID=17;_ThreadName=hudson initialization thread;|Pre- instantiating
>>>>>>>>> singletons in  org. springframework.
>>>>>>>>> beans.factory.support.DefaultListableBeanFactory@d7373f: defining
>>>>>>>>>  beans [authenticationManager,userDetailsService]; root of factory
>>>>>>>>>  hierarchy|#]
>>>>>>>>>
>>>>>>>>> [#|2008-05-21T13:17:12.960-0400|INFO|sun-appserver9.1|
>>>>>>>>> hudson.model.Hudson|_ThreadID=17;_ThreadName=hudson initialization
>>>>>>>>>  thread;|Took 1760 ms to load|#]
>>>>>>>>>
>>>>>>>>> [#|2008-05-21T13:17:13.007-0400|SEVERE|sun-appserver9.1|
>>>>>>>>> hudson.WebAppMain|_ThreadID=17;_ThreadName=hudson initialization
>>>>>>>>>  thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Failed to
>>>>>>>>>  initialize Hudson
>>>>>>>>> java.lang.NullPointerException
>>>>>>>>>        at hudson.slaves.SlaveComputer.closeChannel
>>>>>>>>> (SlaveComputer.java:259)
>>>>>>>>>        at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
>>>>>>>>>        at
>>>>>>>>> hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
>>>>>>>>>        at hudson.model.Computer.<init>(Computer.java:74)
>>>>>>>>>        at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
>>>>>>>>>        at hudson.model.Slave.createComputer(Slave.java:246)
>>>>>>>>>        at hudson.model.Hudson.updateComputer(Hudson.java:576)
>>>>>>>>>        at hudson.model.Hudson.updateComputerList(Hudson.java:556)
>>>>>>>>>        at hudson.model.Hudson.<init>(Hudson.java:351)
>>>>>>>>>        at hudson.WebAppMain$2.run(WebAppMain.java:155)
>>>>>>>>> |#]
>>>>>>>>>
>>>>>>>>> [#|2008-05-21T13:17:13.010-0400|WARNING|sun-appserver9.1|
>>>>>>>>> javax.enterprise.system.stream.err|_ThreadID=17;_ThreadName=hudson
>>>>>>>>>  initialization thread;_RequestID=cd5b4695-
>>>>>>>>> a356-45fb-873a-17367207533f;|Exception in thread "hudson  initialization
>>>>>>>>> thread" |#]
>>>>>>>>>
>>>>>>>>> [#|2008-05-21T13:17:13.018-0400|WARNING|sun-appserver9.1|
>>>>>>>>> javax.enterprise.system.stream.err|_ThreadID=17;_ThreadName=hudson
>>>>>>>>>  initialization thread;_RequestID=cd5b4695-
>>>>>>>>> a356-45fb-873a-17367207533f;|java.lang.NullPointerException
>>>>>>>>>        at hudson.slaves.SlaveComputer.closeChannel
>>>>>>>>> (SlaveComputer.java:259)
>>>>>>>>>        at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
>>>>>>>>>        at
>>>>>>>>> hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
>>>>>>>>>        at hudson.model.Computer.<init>(Computer.java:74)
>>>>>>>>>        at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
>>>>>>>>>        at hudson.model.Slave.createComputer(Slave.java:246)
>>>>>>>>>        at hudson.model.Hudson.updateComputer(Hudson.java:576)
>>>>>>>>>        at hudson.model.Hudson.updateComputerList(Hudson.java:556)
>>>>>>>>>        at hudson.model.Hudson.<init>(Hudson.java:351)
>>>>>>>>>        at hudson.WebAppMain$2.run(WebAppMain.java:155)
>>>>>>>>> |#]
>>>>>>>>>
>>>>>>>>> [#|2008-05-21T13:17:38.074-0400|INFO|sun-appserver9.1|
>>>>>>>>> javax.enterprise.resource.webcontainer.jsf.config
>>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>
>>>>>>> --
>>>>>>> Kohsuke Kawaguchi
>>>>>>> Sun Microsystems                   [hidden email]
>>>>>>>
>>>>>>
>>>>>>
>>>>>
>>>>
>>>
>>
>

--
Kohsuke Kawaguchi
Sun Microsystems                   [hidden email]

smime.p7s (4K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: hudson 1.217 issue -" Please wait while hudson is getting ready to work..."

stephenconnolly
I'd rather remove line 101 if you want to keep the launch...

anyway the slave will start within 1min of hudson coming online now

On Wed, May 21, 2008 at 8:38 PM, Kohsuke Kawaguchi <[hidden email]> wrote:

No, this won't launch a slave when Hudson first comes online.

I think a quickest safe fix is to roll back the synchronized block in the closeChannel.

I mean, the race condition will be fairly rare, isn't it?


Stephen Connolly wrote:
I have committed to SVN a commenting out of line 279.

This is the quickest "safe" fix to let people work again.

The real fix is to re-organise the constructors to prevent partially
constructed objects leaking... which I don't have the time for at the moment

-Stephen

On Wed, May 21, 2008 at 8:30 PM, Stephen Connolly <
[hidden email]> wrote:

Of course none of this was a problem until I noticed that closeChannel was
not using the lock it should have been sharing with setChannel!


On Wed, May 21, 2008 at 8:28 PM, Stephen Connolly <
[hidden email]> wrote:

Yep... should have looked at the stack trace:

       at
hudson.slaves.SlaveComputer.closeChannel(SlaveComputer.java:259)
       at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
****   at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
*****
       at hudson.model.Computer.<init>(Computer.java:74)
       at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)

Calling non-final methods from a constructor will lead you to ruin!

SlaveComputer.<init> calls it's super, which calls setNode, which is
overridden by SlaveComputer... now we are in SlaveComputer, but we are not
fully constructed


On Wed, May 21, 2008 at 8:25 PM, Stephen Connolly <
[hidden email]> wrote:

Hmmm I am not sure why this NPE is happening...

on line 101: we call closeChannel(), which will set the channel to
null... and close it if it is null... but line 99 ensures that channel has
to be null...

Somehow, launch is being called before the SlaveComputer constructor has
completed... that is bad practice. We should be using a factory method
according to Java Concurrency In Practice.

Before I added the missing synchronization, this was not an issue, as the
channelLock field was not being consulted until the launch's task on the
executor started, which is usually after the constructor completes.

The launch is being triggered in the super constructor, which is why
channelLock has not been initialized.

There are some bad concurrency issue smells all over this code.

I think the quick fix is to remove line 101.

The long fix is to remove this hidden automatic launch from within the
constructor of Computer


On Wed, May 21, 2008 at 8:14 PM, Stephen Connolly <
[hidden email]> wrote:

so the channelLock has not been initialized!

seems like partially constructed objects leaking from the
constructor.... we all have to read the train book again


On Wed, May 21, 2008 at 8:10 PM, Stephen Connolly <
[hidden email]> wrote:

Ahhh the iPod didn;t show the log!


On Wed, May 21, 2008 at 8:03 PM, Kohsuke Kawaguchi <
[hidden email]> wrote:

Stephen Connolly wrote:

other than you have a null pointer!

a stack trace might help us


It's in the log:


[#|2008-05-21T13:17:13.007-0400|SEVERE|sun-appserver9.1|
> hudson.WebAppMain|_ThreadID=17;_ThreadName=hudson initialization
> thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Failed to
> initialize Hudson
> java.lang.NullPointerException
>         at hudson.slaves.SlaveComputer.closeChannel
> (SlaveComputer.java:259)
>         at
hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
>         at
hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
>         at hudson.model.Computer.<init>(Computer.java:74)
>         at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
>         at hudson.model.Slave.createComputer(Slave.java:246)
>         at hudson.model.Hudson.updateComputer(Hudson.java:576)
>         at hudson.model.Hudson.updateComputerList(Hudson.java:556)
>         at hudson.model.Hudson.<init>(Hudson.java:351)
>         at hudson.WebAppMain$2.run(WebAppMain.java:155)
> |#]



Sent from my iPod

On 21 May 2008, at 18:30, "Messmer, Jason" <[hidden email]>
 wrote:

 All,

I am getting a NullPointerException for the slaves when deployed
 1.217, which displays "Please wait while hudson is getting ready to
 work..."
Any clues...

Thanks,
~Jay







[#|2008-05-21T13:17:12.111-0400|INFO|sun-appserver9.1|
javax.enterprise.system.core.selfmanagement|
_ThreadID=10;_ThreadName=main;|SMGT0007: Self Management Rules  service is
enabled|#]

[#|2008-05-21T13:17:12.186-0400|WARNING|sun-appserver9.1|
javax.enterprise.system.container.ejb| _ThreadID=
10;_ThreadName=main;_RequestID=4c2fc416-86e5-4fc6-909b-7358e9142acf;|
EJBLifeCycle: Automatic  timer migration component not enabled  for  DAS
instance|#]

[#|2008-05-21T13:17:12.218-0400|INFO|sun-appserver9.1|
javax.enterprise.system.core|_ThreadID=10;_ThreadName=main;| Application
server startup complete.|#]

[#|2008-05-21T13:17:12.918-0400|INFO|sun-appserver9.1|
org.springframework.web.context.support.StaticWebApplicationContext|
_ThreadID=17;_ThreadName=hudson initialization thread;|Refreshing  org.
springframework. web.context.support.StaticWebApplicationContext@1362ca8:
display  name [Root WebApplicationContext]; startup date [Wed May 21
13:17:12  EDT 2008]; root of context hierarchy|#]

[#|2008-05-21T13:17:12.920-0400|INFO|sun-appserver9.1|
org.springframework.web.context.support.StaticWebApplicationContext|
_ThreadID=17;_ThreadName=hudson initialization thread;|Bean factory  for
application context
[org.springframework.web.context.support.StaticWebApplicationContext
@1362ca8]:  org. springframework.
beans.factory.support.DefaultListableBeanFactory@d7373f|#]

[#|2008-05-21T13:17:12.921-0400|INFO|sun-appserver9.1|
org.springframework.beans.factory.support.DefaultListableBeanFactory|
_ThreadID=17;_ThreadName=hudson initialization thread;|Pre- instantiating
singletons in  org. springframework.
beans.factory.support.DefaultListableBeanFactory@d7373f: defining
 beans [authenticationManager,userDetailsService]; root of factory
 hierarchy|#]

[#|2008-05-21T13:17:12.960-0400|INFO|sun-appserver9.1|
hudson.model.Hudson|_ThreadID=17;_ThreadName=hudson initialization
 thread;|Took 1760 ms to load|#]

[#|2008-05-21T13:17:13.007-0400|SEVERE|sun-appserver9.1|
hudson.WebAppMain|_ThreadID=17;_ThreadName=hudson initialization
 thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Failed to
 initialize Hudson
java.lang.NullPointerException
      at hudson.slaves.SlaveComputer.closeChannel
(SlaveComputer.java:259)
      at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
      at
hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
      at hudson.model.Computer.<init>(Computer.java:74)
      at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
      at hudson.model.Slave.createComputer(Slave.java:246)
      at hudson.model.Hudson.updateComputer(Hudson.java:576)
      at hudson.model.Hudson.updateComputerList(Hudson.java:556)
      at hudson.model.Hudson.<init>(Hudson.java:351)
      at hudson.WebAppMain$2.run(WebAppMain.java:155)
|#]

[#|2008-05-21T13:17:13.010-0400|WARNING|sun-appserver9.1|
javax.enterprise.system.stream.err|_ThreadID=17;_ThreadName=hudson
 initialization thread;_RequestID=cd5b4695-
a356-45fb-873a-17367207533f;|Exception in thread "hudson  initialization
thread" |#]

[#|2008-05-21T13:17:13.018-0400|WARNING|sun-appserver9.1|
javax.enterprise.system.stream.err|_ThreadID=17;_ThreadName=hudson
 initialization thread;_RequestID=cd5b4695-
a356-45fb-873a-17367207533f;|java.lang.NullPointerException
      at hudson.slaves.SlaveComputer.closeChannel
(SlaveComputer.java:259)
      at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
      at
hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
      at hudson.model.Computer.<init>(Computer.java:74)
      at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
      at hudson.model.Slave.createComputer(Slave.java:246)
      at hudson.model.Hudson.updateComputer(Hudson.java:576)
      at hudson.model.Hudson.updateComputerList(Hudson.java:556)
      at hudson.model.Hudson.<init>(Hudson.java:351)
      at hudson.WebAppMain$2.run(WebAppMain.java:155)
|#]

[#|2008-05-21T13:17:38.074-0400|INFO|sun-appserver9.1|
javax.enterprise.resource.webcontainer.jsf.config




--
Kohsuke Kawaguchi
Sun Microsystems                   [hidden email]










--
Kohsuke Kawaguchi
Sun Microsystems                   [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: hudson 1.217 issue -" Please wait while hudson is getting ready to work..."

Kohsuke Kawaguchi
Administrator
Stephen Connolly wrote:
> I'd rather remove line 101 if you want to keep the launch...

I think we need a safe fix, and in that regard restoring the old
behavior is better.

> anyway the slave will start within 1min of hudson coming online now

The problem with this is that the jobs that are postponed when Hudson
was shut down the last time will now move to the master when it came back.


> On Wed, May 21, 2008 at 8:38 PM, Kohsuke Kawaguchi <
> [hidden email]> wrote:
>
>>
>> No, this won't launch a slave when Hudson first comes online.
>>
>> I think a quickest safe fix is to roll back the synchronized block in the
>> closeChannel.
>>
>> I mean, the race condition will be fairly rare, isn't it?
>>
>>
>> Stephen Connolly wrote:
>>
>>> I have committed to SVN a commenting out of line 279.
>>>
>>> This is the quickest "safe" fix to let people work again.
>>>
>>> The real fix is to re-organise the constructors to prevent partially
>>> constructed objects leaking... which I don't have the time for at the
>>> moment
>>>
>>> -Stephen
>>>
>>> On Wed, May 21, 2008 at 8:30 PM, Stephen Connolly <
>>> [hidden email]> wrote:
>>>
>>>  Of course none of this was a problem until I noticed that closeChannel
>>>> was
>>>> not using the lock it should have been sharing with setChannel!
>>>>
>>>>
>>>> On Wed, May 21, 2008 at 8:28 PM, Stephen Connolly <
>>>> [hidden email]> wrote:
>>>>
>>>>  Yep... should have looked at the stack trace:
>>>>>
>>>>>        at
>>>>> hudson.slaves.SlaveComputer.closeChannel(SlaveComputer.java:259)
>>>>>        at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
>>>>> ****   at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
>>>>> *****
>>>>>        at hudson.model.Computer.<init>(Computer.java:74)
>>>>>        at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
>>>>>
>>>>> Calling non-final methods from a constructor will lead you to ruin!
>>>>>
>>>>> SlaveComputer.<init> calls it's super, which calls setNode, which is
>>>>> overridden by SlaveComputer... now we are in SlaveComputer, but we are
>>>>> not
>>>>> fully constructed
>>>>>
>>>>>
>>>>> On Wed, May 21, 2008 at 8:25 PM, Stephen Connolly <
>>>>> [hidden email]> wrote:
>>>>>
>>>>>  Hmmm I am not sure why this NPE is happening...
>>>>>>
>>>>>> on line 101: we call closeChannel(), which will set the channel to
>>>>>> null... and close it if it is null... but line 99 ensures that channel
>>>>>> has
>>>>>> to be null...
>>>>>>
>>>>>> Somehow, launch is being called before the SlaveComputer constructor
>>>>>> has
>>>>>> completed... that is bad practice. We should be using a factory method
>>>>>> according to Java Concurrency In Practice.
>>>>>>
>>>>>> Before I added the missing synchronization, this was not an issue, as
>>>>>> the
>>>>>> channelLock field was not being consulted until the launch's task on
>>>>>> the
>>>>>> executor started, which is usually after the constructor completes.
>>>>>>
>>>>>> The launch is being triggered in the super constructor, which is why
>>>>>> channelLock has not been initialized.
>>>>>>
>>>>>> There are some bad concurrency issue smells all over this code.
>>>>>>
>>>>>> I think the quick fix is to remove line 101.
>>>>>>
>>>>>> The long fix is to remove this hidden automatic launch from within the
>>>>>> constructor of Computer
>>>>>>
>>>>>>
>>>>>> On Wed, May 21, 2008 at 8:14 PM, Stephen Connolly <
>>>>>> [hidden email]> wrote:
>>>>>>
>>>>>>  so the channelLock has not been initialized!
>>>>>>>
>>>>>>> seems like partially constructed objects leaking from the
>>>>>>> constructor.... we all have to read the train book again
>>>>>>>
>>>>>>>
>>>>>>> On Wed, May 21, 2008 at 8:10 PM, Stephen Connolly <
>>>>>>> [hidden email]> wrote:
>>>>>>>
>>>>>>>  Ahhh the iPod didn;t show the log!
>>>>>>>>
>>>>>>>>
>>>>>>>> On Wed, May 21, 2008 at 8:03 PM, Kohsuke Kawaguchi <
>>>>>>>> [hidden email]> wrote:
>>>>>>>>
>>>>>>>>  Stephen Connolly wrote:
>>>>>>>>>
>>>>>>>>>  other than you have a null pointer!
>>>>>>>>>>
>>>>>>>>>> a stack trace might help us
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>> It's in the log:
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> [#|2008-05-21T13:17:13.007-0400|SEVERE|sun-appserver9.1|
>>>>>>>>> > hudson.WebAppMain|_ThreadID=17;_ThreadName=hudson initialization
>>>>>>>>> > thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Failed to
>>>>>>>>> > initialize Hudson
>>>>>>>>> > java.lang.NullPointerException
>>>>>>>>> >         at hudson.slaves.SlaveComputer.closeChannel
>>>>>>>>> > (SlaveComputer.java:259)
>>>>>>>>> >         at
>>>>>>>>> hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
>>>>>>>>> >         at
>>>>>>>>> hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
>>>>>>>>> >         at hudson.model.Computer.<init>(Computer.java:74)
>>>>>>>>> >         at
>>>>>>>>> hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
>>>>>>>>> >         at hudson.model.Slave.createComputer(Slave.java:246)
>>>>>>>>> >         at hudson.model.Hudson.updateComputer(Hudson.java:576)
>>>>>>>>> >         at hudson.model.Hudson.updateComputerList(Hudson.java:556)
>>>>>>>>> >         at hudson.model.Hudson.<init>(Hudson.java:351)
>>>>>>>>> >         at hudson.WebAppMain$2.run(WebAppMain.java:155)
>>>>>>>>> > |#]
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>  Sent from my iPod
>>>>>>>>>>
>>>>>>>>>> On 21 May 2008, at 18:30, "Messmer, Jason" <
>>>>>>>>>> [hidden email]>
>>>>>>>>>>  wrote:
>>>>>>>>>>
>>>>>>>>>>  All,
>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>> I am getting a NullPointerException for the slaves when deployed
>>>>>>>>>>>  1.217, which displays "Please wait while hudson is getting ready
>>>>>>>>>>> to
>>>>>>>>>>>  work..."
>>>>>>>>>>> Any clues...
>>>>>>>>>>>
>>>>>>>>>>> Thanks,
>>>>>>>>>>> ~Jay
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>> [#|2008-05-21T13:17:12.111-0400|INFO|sun-appserver9.1|
>>>>>>>>>>> javax.enterprise.system.core.selfmanagement|
>>>>>>>>>>> _ThreadID=10;_ThreadName=main;|SMGT0007: Self Management Rules
>>>>>>>>>>>  service is
>>>>>>>>>>> enabled|#]
>>>>>>>>>>>
>>>>>>>>>>> [#|2008-05-21T13:17:12.186-0400|WARNING|sun-appserver9.1|
>>>>>>>>>>> javax.enterprise.system.container.ejb| _ThreadID=
>>>>>>>>>>>
>>>>>>>>>>> 10;_ThreadName=main;_RequestID=4c2fc416-86e5-4fc6-909b-7358e9142acf;|
>>>>>>>>>>> EJBLifeCycle: Automatic  timer migration component not enabled
>>>>>>>>>>>  for  DAS
>>>>>>>>>>> instance|#]
>>>>>>>>>>>
>>>>>>>>>>> [#|2008-05-21T13:17:12.218-0400|INFO|sun-appserver9.1|
>>>>>>>>>>> javax.enterprise.system.core|_ThreadID=10;_ThreadName=main;|
>>>>>>>>>>> Application
>>>>>>>>>>> server startup complete.|#]
>>>>>>>>>>>
>>>>>>>>>>> [#|2008-05-21T13:17:12.918-0400|INFO|sun-appserver9.1|
>>>>>>>>>>>
>>>>>>>>>>> org.springframework.web.context.support.StaticWebApplicationContext|
>>>>>>>>>>> _ThreadID=17;_ThreadName=hudson initialization thread;|Refreshing
>>>>>>>>>>>  org.
>>>>>>>>>>> springframework.
>>>>>>>>>>> web.context.support.StaticWebApplicationContext@1362ca8:
>>>>>>>>>>> display  name [Root WebApplicationContext]; startup date [Wed May
>>>>>>>>>>> 21
>>>>>>>>>>> 13:17:12  EDT 2008]; root of context hierarchy|#]
>>>>>>>>>>>
>>>>>>>>>>> [#|2008-05-21T13:17:12.920-0400|INFO|sun-appserver9.1|
>>>>>>>>>>>
>>>>>>>>>>> org.springframework.web.context.support.StaticWebApplicationContext|
>>>>>>>>>>> _ThreadID=17;_ThreadName=hudson initialization thread;|Bean
>>>>>>>>>>> factory  for
>>>>>>>>>>> application context
>>>>>>>>>>>
>>>>>>>>>>> [org.springframework.web.context.support.StaticWebApplicationContext
>>>>>>>>>>> @1362ca8]:  org. springframework.
>>>>>>>>>>> beans.factory.support.DefaultListableBeanFactory@d7373f|#]
>>>>>>>>>>>
>>>>>>>>>>> [#|2008-05-21T13:17:12.921-0400|INFO|sun-appserver9.1|
>>>>>>>>>>>
>>>>>>>>>>> org.springframework.beans.factory.support.DefaultListableBeanFactory|
>>>>>>>>>>> _ThreadID=17;_ThreadName=hudson initialization thread;|Pre-
>>>>>>>>>>> instantiating
>>>>>>>>>>> singletons in  org. springframework.
>>>>>>>>>>> beans.factory.support.DefaultListableBeanFactory@d7373f: defining
>>>>>>>>>>>  beans [authenticationManager,userDetailsService]; root of factory
>>>>>>>>>>>  hierarchy|#]
>>>>>>>>>>>
>>>>>>>>>>> [#|2008-05-21T13:17:12.960-0400|INFO|sun-appserver9.1|
>>>>>>>>>>> hudson.model.Hudson|_ThreadID=17;_ThreadName=hudson initialization
>>>>>>>>>>>  thread;|Took 1760 ms to load|#]
>>>>>>>>>>>
>>>>>>>>>>> [#|2008-05-21T13:17:13.007-0400|SEVERE|sun-appserver9.1|
>>>>>>>>>>> hudson.WebAppMain|_ThreadID=17;_ThreadName=hudson initialization
>>>>>>>>>>>  thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Failed to
>>>>>>>>>>>  initialize Hudson
>>>>>>>>>>> java.lang.NullPointerException
>>>>>>>>>>>       at hudson.slaves.SlaveComputer.closeChannel
>>>>>>>>>>> (SlaveComputer.java:259)
>>>>>>>>>>>       at
>>>>>>>>>>> hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
>>>>>>>>>>>       at
>>>>>>>>>>> hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
>>>>>>>>>>>       at hudson.model.Computer.<init>(Computer.java:74)
>>>>>>>>>>>       at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
>>>>>>>>>>>       at hudson.model.Slave.createComputer(Slave.java:246)
>>>>>>>>>>>       at hudson.model.Hudson.updateComputer(Hudson.java:576)
>>>>>>>>>>>       at hudson.model.Hudson.updateComputerList(Hudson.java:556)
>>>>>>>>>>>       at hudson.model.Hudson.<init>(Hudson.java:351)
>>>>>>>>>>>       at hudson.WebAppMain$2.run(WebAppMain.java:155)
>>>>>>>>>>> |#]
>>>>>>>>>>>
>>>>>>>>>>> [#|2008-05-21T13:17:13.010-0400|WARNING|sun-appserver9.1|
>>>>>>>>>>> javax.enterprise.system.stream.err|_ThreadID=17;_ThreadName=hudson
>>>>>>>>>>>  initialization thread;_RequestID=cd5b4695-
>>>>>>>>>>> a356-45fb-873a-17367207533f;|Exception in thread "hudson
>>>>>>>>>>>  initialization
>>>>>>>>>>> thread" |#]
>>>>>>>>>>>
>>>>>>>>>>> [#|2008-05-21T13:17:13.018-0400|WARNING|sun-appserver9.1|
>>>>>>>>>>> javax.enterprise.system.stream.err|_ThreadID=17;_ThreadName=hudson
>>>>>>>>>>>  initialization thread;_RequestID=cd5b4695-
>>>>>>>>>>> a356-45fb-873a-17367207533f;|java.lang.NullPointerException
>>>>>>>>>>>       at hudson.slaves.SlaveComputer.closeChannel
>>>>>>>>>>> (SlaveComputer.java:259)
>>>>>>>>>>>       at
>>>>>>>>>>> hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
>>>>>>>>>>>       at
>>>>>>>>>>> hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
>>>>>>>>>>>       at hudson.model.Computer.<init>(Computer.java:74)
>>>>>>>>>>>       at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
>>>>>>>>>>>       at hudson.model.Slave.createComputer(Slave.java:246)
>>>>>>>>>>>       at hudson.model.Hudson.updateComputer(Hudson.java:576)
>>>>>>>>>>>       at hudson.model.Hudson.updateComputerList(Hudson.java:556)
>>>>>>>>>>>       at hudson.model.Hudson.<init>(Hudson.java:351)
>>>>>>>>>>>       at hudson.WebAppMain$2.run(WebAppMain.java:155)
>>>>>>>>>>> |#]
>>>>>>>>>>>
>>>>>>>>>>> [#|2008-05-21T13:17:38.074-0400|INFO|sun-appserver9.1|
>>>>>>>>>>> javax.enterprise.resource.webcontainer.jsf.config
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>> --
>>>>>>>>> Kohsuke Kawaguchi
>>>>>>>>> Sun Microsystems                   [hidden email]
>>>>>>>>>
>>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>
>>>>>>
>>>>>
>>>>
>>>
>>
>> --
>> Kohsuke Kawaguchi
>> Sun Microsystems                   [hidden email]
>>
>

--
Kohsuke Kawaguchi
Sun Microsystems                   [hidden email]

smime.p7s (4K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: hudson 1.217 issue -" Please wait while hudson is getting ready to work..."

stephenconnolly
OK, well I'll remove the synchronized and put back in 279....

with a cheeky twist!

On Wed, May 21, 2008 at 8:47 PM, Kohsuke Kawaguchi <[hidden email]> wrote:
Stephen Connolly wrote:
I'd rather remove line 101 if you want to keep the launch...

I think we need a safe fix, and in that regard restoring the old behavior is better.


anyway the slave will start within 1min of hudson coming online now

The problem with this is that the jobs that are postponed when Hudson was shut down the last time will now move to the master when it came back.



On Wed, May 21, 2008 at 8:38 PM, Kohsuke Kawaguchi <
[hidden email]> wrote:


No, this won't launch a slave when Hudson first comes online.

I think a quickest safe fix is to roll back the synchronized block in the
closeChannel.

I mean, the race condition will be fairly rare, isn't it?


Stephen Connolly wrote:

I have committed to SVN a commenting out of line 279.

This is the quickest "safe" fix to let people work again.

The real fix is to re-organise the constructors to prevent partially
constructed objects leaking... which I don't have the time for at the
moment

-Stephen

On Wed, May 21, 2008 at 8:30 PM, Stephen Connolly <
[hidden email]> wrote:

 Of course none of this was a problem until I noticed that closeChannel
was
not using the lock it should have been sharing with setChannel!


On Wed, May 21, 2008 at 8:28 PM, Stephen Connolly <
[hidden email]> wrote:

 Yep... should have looked at the stack trace:

      at
hudson.slaves.SlaveComputer.closeChannel(SlaveComputer.java:259)
      at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
****   at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
*****
      at hudson.model.Computer.<init>(Computer.java:74)
      at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)

Calling non-final methods from a constructor will lead you to ruin!

SlaveComputer.<init> calls it's super, which calls setNode, which is
overridden by SlaveComputer... now we are in SlaveComputer, but we are
not
fully constructed


On Wed, May 21, 2008 at 8:25 PM, Stephen Connolly <
[hidden email]> wrote:

 Hmmm I am not sure why this NPE is happening...

on line 101: we call closeChannel(), which will set the channel to
null... and close it if it is null... but line 99 ensures that channel
has
to be null...

Somehow, launch is being called before the SlaveComputer constructor
has
completed... that is bad practice. We should be using a factory method
according to Java Concurrency In Practice.

Before I added the missing synchronization, this was not an issue, as
the
channelLock field was not being consulted until the launch's task on
the
executor started, which is usually after the constructor completes.

The launch is being triggered in the super constructor, which is why
channelLock has not been initialized.

There are some bad concurrency issue smells all over this code.

I think the quick fix is to remove line 101.

The long fix is to remove this hidden automatic launch from within the
constructor of Computer


On Wed, May 21, 2008 at 8:14 PM, Stephen Connolly <
[hidden email]> wrote:

 so the channelLock has not been initialized!

seems like partially constructed objects leaking from the
constructor.... we all have to read the train book again


On Wed, May 21, 2008 at 8:10 PM, Stephen Connolly <
[hidden email]> wrote:

 Ahhh the iPod didn;t show the log!


On Wed, May 21, 2008 at 8:03 PM, Kohsuke Kawaguchi <
[hidden email]> wrote:

 Stephen Connolly wrote:

 other than you have a null pointer!

a stack trace might help us


It's in the log:


[#|2008-05-21T13:17:13.007-0400|SEVERE|sun-appserver9.1|
> hudson.WebAppMain|_ThreadID=17;_ThreadName=hudson initialization
> thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Failed to
> initialize Hudson
> java.lang.NullPointerException
>         at hudson.slaves.SlaveComputer.closeChannel
> (SlaveComputer.java:259)
>         at
hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
>         at
hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
>         at hudson.model.Computer.<init>(Computer.java:74)
>         at
hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
>         at hudson.model.Slave.createComputer(Slave.java:246)
>         at hudson.model.Hudson.updateComputer(Hudson.java:576)
>         at hudson.model.Hudson.updateComputerList(Hudson.java:556)
>         at hudson.model.Hudson.<init>(Hudson.java:351)
>         at hudson.WebAppMain$2.run(WebAppMain.java:155)
> |#]



 Sent from my iPod

On 21 May 2008, at 18:30, "Messmer, Jason" <
[hidden email]>
 wrote:

 All,


I am getting a NullPointerException for the slaves when deployed
 1.217, which displays "Please wait while hudson is getting ready
to
 work..."
Any clues...

Thanks,
~Jay







[#|2008-05-21T13:17:12.111-0400|INFO|sun-appserver9.1|
javax.enterprise.system.core.selfmanagement|
_ThreadID=10;_ThreadName=main;|SMGT0007: Self Management Rules
 service is
enabled|#]

[#|2008-05-21T13:17:12.186-0400|WARNING|sun-appserver9.1|
javax.enterprise.system.container.ejb| _ThreadID=

10;_ThreadName=main;_RequestID=4c2fc416-86e5-4fc6-909b-7358e9142acf;|
EJBLifeCycle: Automatic  timer migration component not enabled
 for  DAS
instance|#]

[#|2008-05-21T13:17:12.218-0400|INFO|sun-appserver9.1|
javax.enterprise.system.core|_ThreadID=10;_ThreadName=main;|
Application
server startup complete.|#]

[#|2008-05-21T13:17:12.918-0400|INFO|sun-appserver9.1|

org.springframework.web.context.support.StaticWebApplicationContext|
_ThreadID=17;_ThreadName=hudson initialization thread;|Refreshing
 org.
springframework.
web.context.support.StaticWebApplicationContext@1362ca8:
display  name [Root WebApplicationContext]; startup date [Wed May
21
13:17:12  EDT 2008]; root of context hierarchy|#]

[#|2008-05-21T13:17:12.920-0400|INFO|sun-appserver9.1|

org.springframework.web.context.support.StaticWebApplicationContext|
_ThreadID=17;_ThreadName=hudson initialization thread;|Bean
factory  for
application context

[org.springframework.web.context.support.StaticWebApplicationContext
@1362ca8]:  org. springframework.
beans.factory.support.DefaultListableBeanFactory@d7373f|#]

[#|2008-05-21T13:17:12.921-0400|INFO|sun-appserver9.1|

org.springframework.beans.factory.support.DefaultListableBeanFactory|
_ThreadID=17;_ThreadName=hudson initialization thread;|Pre-
instantiating
singletons in  org. springframework.
beans.factory.support.DefaultListableBeanFactory@d7373f: defining
 beans [authenticationManager,userDetailsService]; root of factory
 hierarchy|#]

[#|2008-05-21T13:17:12.960-0400|INFO|sun-appserver9.1|
hudson.model.Hudson|_ThreadID=17;_ThreadName=hudson initialization
 thread;|Took 1760 ms to load|#]

[#|2008-05-21T13:17:13.007-0400|SEVERE|sun-appserver9.1|
hudson.WebAppMain|_ThreadID=17;_ThreadName=hudson initialization
 thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Failed to
 initialize Hudson
java.lang.NullPointerException
     at hudson.slaves.SlaveComputer.closeChannel
(SlaveComputer.java:259)
     at
hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
     at
hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
     at hudson.model.Computer.<init>(Computer.java:74)
     at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
     at hudson.model.Slave.createComputer(Slave.java:246)
     at hudson.model.Hudson.updateComputer(Hudson.java:576)
     at hudson.model.Hudson.updateComputerList(Hudson.java:556)
     at hudson.model.Hudson.<init>(Hudson.java:351)
     at hudson.WebAppMain$2.run(WebAppMain.java:155)
|#]

[#|2008-05-21T13:17:13.010-0400|WARNING|sun-appserver9.1|
javax.enterprise.system.stream.err|_ThreadID=17;_ThreadName=hudson
 initialization thread;_RequestID=cd5b4695-
a356-45fb-873a-17367207533f;|Exception in thread "hudson
 initialization
thread" |#]

[#|2008-05-21T13:17:13.018-0400|WARNING|sun-appserver9.1|
javax.enterprise.system.stream.err|_ThreadID=17;_ThreadName=hudson
 initialization thread;_RequestID=cd5b4695-
a356-45fb-873a-17367207533f;|java.lang.NullPointerException
     at hudson.slaves.SlaveComputer.closeChannel
(SlaveComputer.java:259)
     at
hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
     at
hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
     at hudson.model.Computer.<init>(Computer.java:74)
     at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
     at hudson.model.Slave.createComputer(Slave.java:246)
     at hudson.model.Hudson.updateComputer(Hudson.java:576)
     at hudson.model.Hudson.updateComputerList(Hudson.java:556)
     at hudson.model.Hudson.<init>(Hudson.java:351)
     at hudson.WebAppMain$2.run(WebAppMain.java:155)
|#]

[#|2008-05-21T13:17:38.074-0400|INFO|sun-appserver9.1|
javax.enterprise.resource.webcontainer.jsf.config




--
Kohsuke Kawaguchi
Sun Microsystems                   [hidden email]










--
Kohsuke Kawaguchi
Sun Microsystems                   [hidden email]




--
Kohsuke Kawaguchi
Sun Microsystems                   [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: hudson 1.217 issue -" Please wait while hudson is getting ready to work..."

stephenconnolly
Hmmm...

I was going to commit:


    private void closeChannel() {
        if (channelLock == null) {
            logger.log(Level.SEVERE, "Partially constructed object escaping from constructors... nag Hudson developers to fix this");
            return;
        }
        synchronized (channelLock) {
            Channel c = channel;
            channel = null;
            isUnix = null;
            if (c != null) {
                try {
                    c.close();
                } catch (IOException e) {
                    logger.log(Level.SEVERE, "Failed to terminate channel to " + getDisplayName(), e);
                }
            }
        }
    }

but you went for the less cheeky one... I'll leave your version in place

On Wed, May 21, 2008 at 8:51 PM, Stephen Connolly <[hidden email]> wrote:
OK, well I'll remove the synchronized and put back in 279....

with a cheeky twist!


On Wed, May 21, 2008 at 8:47 PM, Kohsuke Kawaguchi <[hidden email]> wrote:
Stephen Connolly wrote:
I'd rather remove line 101 if you want to keep the launch...

I think we need a safe fix, and in that regard restoring the old behavior is better.


anyway the slave will start within 1min of hudson coming online now

The problem with this is that the jobs that are postponed when Hudson was shut down the last time will now move to the master when it came back.



On Wed, May 21, 2008 at 8:38 PM, Kohsuke Kawaguchi <
[hidden email]> wrote:


No, this won't launch a slave when Hudson first comes online.

I think a quickest safe fix is to roll back the synchronized block in the
closeChannel.

I mean, the race condition will be fairly rare, isn't it?


Stephen Connolly wrote:

I have committed to SVN a commenting out of line 279.

This is the quickest "safe" fix to let people work again.

The real fix is to re-organise the constructors to prevent partially
constructed objects leaking... which I don't have the time for at the
moment

-Stephen

On Wed, May 21, 2008 at 8:30 PM, Stephen Connolly <
[hidden email]> wrote:

 Of course none of this was a problem until I noticed that closeChannel
was
not using the lock it should have been sharing with setChannel!


On Wed, May 21, 2008 at 8:28 PM, Stephen Connolly <
[hidden email]> wrote:

 Yep... should have looked at the stack trace:

      at
hudson.slaves.SlaveComputer.closeChannel(SlaveComputer.java:259)
      at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
****   at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
*****
      at hudson.model.Computer.<init>(Computer.java:74)
      at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)

Calling non-final methods from a constructor will lead you to ruin!

SlaveComputer.<init> calls it's super, which calls setNode, which is
overridden by SlaveComputer... now we are in SlaveComputer, but we are
not
fully constructed


On Wed, May 21, 2008 at 8:25 PM, Stephen Connolly <
[hidden email]> wrote:

 Hmmm I am not sure why this NPE is happening...

on line 101: we call closeChannel(), which will set the channel to
null... and close it if it is null... but line 99 ensures that channel
has
to be null...

Somehow, launch is being called before the SlaveComputer constructor
has
completed... that is bad practice. We should be using a factory method
according to Java Concurrency In Practice.

Before I added the missing synchronization, this was not an issue, as
the
channelLock field was not being consulted until the launch's task on
the
executor started, which is usually after the constructor completes.

The launch is being triggered in the super constructor, which is why
channelLock has not been initialized.

There are some bad concurrency issue smells all over this code.

I think the quick fix is to remove line 101.

The long fix is to remove this hidden automatic launch from within the
constructor of Computer


On Wed, May 21, 2008 at 8:14 PM, Stephen Connolly <
[hidden email]> wrote:

 so the channelLock has not been initialized!

seems like partially constructed objects leaking from the
constructor.... we all have to read the train book again


On Wed, May 21, 2008 at 8:10 PM, Stephen Connolly <
[hidden email]> wrote:

 Ahhh the iPod didn;t show the log!


On Wed, May 21, 2008 at 8:03 PM, Kohsuke Kawaguchi <
[hidden email]> wrote:

 Stephen Connolly wrote:

 other than you have a null pointer!

a stack trace might help us


It's in the log:


[#|2008-05-21T13:17:13.007-0400|SEVERE|sun-appserver9.1|
> hudson.WebAppMain|_ThreadID=17;_ThreadName=hudson initialization
> thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Failed to
> initialize Hudson
> java.lang.NullPointerException
>         at hudson.slaves.SlaveComputer.closeChannel
> (SlaveComputer.java:259)
>         at
hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
>         at
hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
>         at hudson.model.Computer.<init>(Computer.java:74)
>         at
hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
>         at hudson.model.Slave.createComputer(Slave.java:246)
>         at hudson.model.Hudson.updateComputer(Hudson.java:576)
>         at hudson.model.Hudson.updateComputerList(Hudson.java:556)
>         at hudson.model.Hudson.<init>(Hudson.java:351)
>         at hudson.WebAppMain$2.run(WebAppMain.java:155)
> |#]



 Sent from my iPod

On 21 May 2008, at 18:30, "Messmer, Jason" <
[hidden email]>
 wrote:

 All,


I am getting a NullPointerException for the slaves when deployed
 1.217, which displays "Please wait while hudson is getting ready
to
 work..."
Any clues...

Thanks,
~Jay







[#|2008-05-21T13:17:12.111-0400|INFO|sun-appserver9.1|
javax.enterprise.system.core.selfmanagement|
_ThreadID=10;_ThreadName=main;|SMGT0007: Self Management Rules
 service is
enabled|#]

[#|2008-05-21T13:17:12.186-0400|WARNING|sun-appserver9.1|
javax.enterprise.system.container.ejb| _ThreadID=

10;_ThreadName=main;_RequestID=4c2fc416-86e5-4fc6-909b-7358e9142acf;|
EJBLifeCycle: Automatic  timer migration component not enabled
 for  DAS
instance|#]

[#|2008-05-21T13:17:12.218-0400|INFO|sun-appserver9.1|
javax.enterprise.system.core|_ThreadID=10;_ThreadName=main;|
Application
server startup complete.|#]

[#|2008-05-21T13:17:12.918-0400|INFO|sun-appserver9.1|

org.springframework.web.context.support.StaticWebApplicationContext|
_ThreadID=17;_ThreadName=hudson initialization thread;|Refreshing
 org.
springframework.
web.context.support.StaticWebApplicationContext@1362ca8:
display  name [Root WebApplicationContext]; startup date [Wed May
21
13:17:12  EDT 2008]; root of context hierarchy|#]

[#|2008-05-21T13:17:12.920-0400|INFO|sun-appserver9.1|

org.springframework.web.context.support.StaticWebApplicationContext|
_ThreadID=17;_ThreadName=hudson initialization thread;|Bean
factory  for
application context

[org.springframework.web.context.support.StaticWebApplicationContext
@1362ca8]:  org. springframework.
beans.factory.support.DefaultListableBeanFactory@d7373f|#]

[#|2008-05-21T13:17:12.921-0400|INFO|sun-appserver9.1|

org.springframework.beans.factory.support.DefaultListableBeanFactory|
_ThreadID=17;_ThreadName=hudson initialization thread;|Pre-
instantiating
singletons in  org. springframework.
beans.factory.support.DefaultListableBeanFactory@d7373f: defining
 beans [authenticationManager,userDetailsService]; root of factory
 hierarchy|#]

[#|2008-05-21T13:17:12.960-0400|INFO|sun-appserver9.1|
hudson.model.Hudson|_ThreadID=17;_ThreadName=hudson initialization
 thread;|Took 1760 ms to load|#]

[#|2008-05-21T13:17:13.007-0400|SEVERE|sun-appserver9.1|
hudson.WebAppMain|_ThreadID=17;_ThreadName=hudson initialization
 thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Failed to
 initialize Hudson
java.lang.NullPointerException
     at hudson.slaves.SlaveComputer.closeChannel
(SlaveComputer.java:259)
     at
hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
     at
hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
     at hudson.model.Computer.<init>(Computer.java:74)
     at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
     at hudson.model.Slave.createComputer(Slave.java:246)
     at hudson.model.Hudson.updateComputer(Hudson.java:576)
     at hudson.model.Hudson.updateComputerList(Hudson.java:556)
     at hudson.model.Hudson.<init>(Hudson.java:351)
     at hudson.WebAppMain$2.run(WebAppMain.java:155)
|#]

[#|2008-05-21T13:17:13.010-0400|WARNING|sun-appserver9.1|
javax.enterprise.system.stream.err|_ThreadID=17;_ThreadName=hudson
 initialization thread;_RequestID=cd5b4695-
a356-45fb-873a-17367207533f;|Exception in thread "hudson
 initialization
thread" |#]

[#|2008-05-21T13:17:13.018-0400|WARNING|sun-appserver9.1|
javax.enterprise.system.stream.err|_ThreadID=17;_ThreadName=hudson
 initialization thread;_RequestID=cd5b4695-
a356-45fb-873a-17367207533f;|java.lang.NullPointerException
     at hudson.slaves.SlaveComputer.closeChannel
(SlaveComputer.java:259)
     at
hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
     at
hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
     at hudson.model.Computer.<init>(Computer.java:74)
     at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
     at hudson.model.Slave.createComputer(Slave.java:246)
     at hudson.model.Hudson.updateComputer(Hudson.java:576)
     at hudson.model.Hudson.updateComputerList(Hudson.java:556)
     at hudson.model.Hudson.<init>(Hudson.java:351)
     at hudson.WebAppMain$2.run(WebAppMain.java:155)
|#]

[#|2008-05-21T13:17:38.074-0400|INFO|sun-appserver9.1|
javax.enterprise.resource.webcontainer.jsf.config




--
Kohsuke Kawaguchi
Sun Microsystems                   [hidden email]










--
Kohsuke Kawaguchi
Sun Microsystems                   [hidden email]




--
Kohsuke Kawaguchi
Sun Microsystems                   [hidden email]


Reply | Threaded
Open this post in threaded view
|

RE: hudson 1.217 issue -" Please wait while hudson is getting ready to work..."

Adam Purkiss
Nag Nag Nag Nag Nag Nag Nag Nag Nag - repeat until fixed
 

 

Date: Wed, 21 May 2008 20:53:06 +0100
From: [hidden email]
To: [hidden email]
Subject: Re: hudson 1.217 issue -" Please wait while hudson is getting ready to work..."

Hmmm...

I was going to commit:


    private void closeChannel() {
        if (channelLock == null) {
            logger.log(Level.SEVERE, "Partially constructed object escaping from constructors... nag Hudson developers to fix this");
            return;
        }
        synchronized (channelLock) {
            Channel c = channel;
            channel = null;
            isUnix = null;
            if (c != null) {
                try {
                    c.close();
                } catch (IOException e) {
                    logger.log(Level.SEVERE, "Failed to terminate channel to " + getDisplayName(), e);
                }
            }
        }
    }

but you went for the less cheeky one... I'll leave your version in place

On Wed, May 21, 2008 at 8:51 PM, Stephen Connolly <[hidden email]> wrote:
OK, well I'll remove the synchronized and put back in 279....

with a cheeky twist!


On Wed, May 21, 2008 at 8:47 PM, Kohsuke Kawaguchi <[hidden email]> wrote:
Stephen Connolly wrote:
I'd rather remove line 101 if you want to keep the launch...

I think we need a safe fix, and in that regard restoring the old behavior is better.


anyway the slave will start within 1min of hudson coming online now

The problem with this is that the jobs that are postponed when Hudson was shut down the last time will now move to the master when it came back.



On Wed, May 21, 2008 at 8:38 PM, Kohsuke Kawaguchi <
[hidden email]> wrote:


No, this won't launch a slave when Hudson first comes online.

I think a quickest safe fix is to roll back the synchronized block in the
closeChannel.

I mean, the race condition will be fairly rare, isn't it?


Stephen Connolly wrote:

I have committed to SVN a commenting out of line 279.

This is the quickest "safe" fix to let people work again.

The real fix is to re-organise the constructors to prevent partially
constructed objects leaking... which I don't have the time for at the
moment

-Stephen

On Wed, May 21, 2008 at 8:30 PM, Stephen Connolly <
[hidden email]> wrote:

 Of course none of this was a problem until I noticed that closeChannel
was
not using the lock it should have been sharing with setChannel!


On Wed, May 21, 2008 at 8:28 PM, Stephen Connolly <
[hidden email]> wrote:

 Yep... should have looked at the stack trace:

      at
hudson.slaves.SlaveComputer.closeChannel(SlaveComputer.java:259)
      at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
****   at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
*****
      at hudson.model.Computer.<init>(Computer.java:74)
      at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)

Calling non-final methods from a constructor will lead you to ruin!

SlaveComputer.<init> calls it's super, which calls setNode, which is
overridden by SlaveComputer... now we are in SlaveComputer, but we are
not
fully constructed


On Wed, May 21, 2008 at 8:25 PM, Stephen Connolly <
[hidden email]> wrote:

 Hmmm I am not sure why this NPE is happening...

on line 101: we call closeChannel(), which will set the channel to
null... and close it if it is null... but line 99 ensures that channel
has
to be null...

Somehow, launch is being called before the SlaveComputer constructor
has
completed... that is bad practice. We should be using a factory method
according to Java Concurrency In Practice.

Before I added the missing synchronization, this was not an issue, as
the
channelLock field was not being consulted until the launch's task on
the
executor started, which is usually after the constructor completes.

The launch is being triggered in the super constructor, which is why
channelLock has not been initialized.

There are some bad concurrency issue smells all over this code.

I think the quick fix is to remove line 101.

The long fix is to remove this hidden automatic launch from within the
constructor of Computer


On Wed, May 21, 2008 at 8:14 PM, Stephen Connolly <
[hidden email]> wrote:

 so the channelLock has not been initialized!

seems like partially constructed objects leaking from the
constructor.... we all have to read the train book again


On Wed, May 21, 2008 at 8:10 PM, Stephen Connolly <
[hidden email]> wrote:

 Ahhh the iPod didn;t show the log!


On Wed, May 21, 2008 at 8:03 PM, Kohsuke Kawaguchi <
[hidden email]> wrote:

 Stephen Connolly wrote:

 other than you have a null pointer!

a stack trace might help us


It's in the log:


[#|2008-05-21T13:17:13.007-0400|SEVERE|sun-appserver9.1|
> hudson.WebAppMain|_ThreadID=17;_ThreadName=hudson initialization
> thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Failed to
> initialize Hudson
> java.lang.NullPointerException
>         at hudson.slaves.SlaveComputer.closeChannel
> (SlaveComputer.java:259)
>         at
hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
>         at
hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
>         at hudson.model.Computer.<init>(Computer.java:74)
>         at
hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
>         at hudson.model.Slave.createComputer(Slave.java:246)
>         at hudson.model.Hudson.updateComputer(Hudson.java:576)
>         at hudson.model.Hudson.updateComputerList(Hudson.java:556)
>         at hudson.model.Hudson.<init>(Hudson.java:351)
>         at hudson.WebAppMain$2.run(WebAppMain.java:155)
> |#]



 Sent from my iPod

On 21 May 2008, at 18:30, "Messmer, Jason" <
[hidden email]>
 wrote:

 All,


I am getting a NullPointerException for the slaves when deployed
 1.217, which displays "Please wait while hudson is getting ready
to
 work..."
Any clues...

Thanks,
~Jay







[#|2008-05-21T13:17:12.111-0400|INFO|sun-appserver9.1|
javax.enterprise.system.core.selfmanagement|
_ThreadID=10;_ThreadName=main;|SMGT0007: Self Management Rules
 service is
enabled|#]

[#|2008-05-21T13:17:12.186-0400|WARNING|sun-appserver9.1|
javax.enterprise.system.container.ejb| _ThreadID=

10;_ThreadName=main;_RequestID=4c2fc416-86e5-4fc6-909b-7358e9142acf;|
EJBLifeCycle: Automatic  timer migration component not enabled
 for  DAS
instance|#]

[#|2008-05-21T13:17:12.218-0400|INFO|sun-appserver9.1|
javax.enterprise.system.core|_ThreadID=10;_ThreadName=main;|
Application
server startup complete.|#]

[#|2008-05-21T13:17:12.918-0400|INFO|sun-appserver9.1|

org.springframework.web.context.support.StaticWebApplicationContext|
_ThreadID=17;_ThreadName=hudson initialization thread;|Refreshing
 org.
springframework.
web.context.support.StaticWebApplicationContext@1362ca8:
display  name [Root WebApplicationContext]; startup date [Wed May
21
13:17:12  EDT 2008]; root of context hierarchy|#]

[#|2008-05-21T13:17:12.920-0400|INFO|sun-appserver9.1|

org.springframework.web.context.support.StaticWebApplicationContext|
_ThreadID=17;_ThreadName=hudson initialization thread;|Bean
factory  for
application context

[org.springframework.web.context.support.StaticWebApplicationContext
@1362ca8]:  org. springframework.
beans.factory.support.DefaultListableBeanFactory@d7373f|#]

[#|2008-05-21T13:17:12.921-0400|INFO|sun-appserver9.1|

org.springframework.beans.factory.support.DefaultListableBeanFactory|
_ThreadID=17;_ThreadName=hudson initialization thread;|Pre-
instantiating
singletons in  org. springframework.
beans.factory.support.DefaultListableBeanFactory@d7373f: defining
 beans [authenticationManager,userDetailsService]; root of factory
 hierarchy|#]

[#|2008-05-21T13:17:12.960-0400|INFO|sun-appserver9.1|
hudson.model.Hudson|_ThreadID=17;_ThreadName=hudson initialization
 thread;|Took 1760 ms to load|#]

[#|2008-05-21T13:17:13.007-0400|SEVERE|sun-appserver9.1|
hudson.WebAppMain|_ThreadID=17;_ThreadName=hudson initialization
 thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Failed to
 initialize Hudson
java.lang.NullPointerException
     at hudson.slaves.SlaveComputer.closeChannel
(SlaveComputer.java:259)
     at
hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
     at
hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
     at hudson.model.Computer.<init>(Computer.java:74)
     at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
     at hudson.model.Slave.createComputer(Slave.java:246)
     at hudson.model.Hudson.updateComputer(Hudson.java:576)
     at hudson.model.Hudson.updateComputerList(Hudson.java:556)
     at hudson.model.Hudson.<init>(Hudson.java:351)
     at hudson.WebAppMain$2.run(WebAppMain.java:155)
|#]

[#|2008-05-21T13:17:13.010-0400|WARNING|sun-appserver9.1|
javax.enterprise.system.stream.err|_ThreadID=17;_ThreadName=hudson
 initialization thread;_RequestID=cd5b4695-
a356-45fb-873a-17367207533f;|Exception in thread "hudson
 initialization
thread" |#]

[#|2008-05-21T13:17:13.018-0400|WARNING|sun-appserver9.1|
javax.enterprise.system.stream.err|_ThreadID=17;_ThreadName=hudson
 initialization thread;_RequestID=cd5b4695-
a356-45fb-873a-17367207533f;|java.lang.NullPointerException
     at hudson.slaves.SlaveComputer.closeChannel
(SlaveComputer.java:259)
     at
hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)
     at
hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)
     at hudson.model.Computer.<init>(Computer.java:74)
     at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)
     at hudson.model.Slave.createComputer(Slave.java:246)
     at hudson.model.Hudson.updateComputer(Hudson.java:576)
     at hudson.model.Hudson.updateComputerList(Hudson.java:556)
     at hudson.model.Hudson.<init>(Hudson.java:351)
     at hudson.WebAppMain$2.run(WebAppMain.java:155)
|#]

[#|2008-05-21T13:17:38.074-0400|INFO|sun-appserver9.1|
javax.enterprise.resource.webcontainer.jsf.config




--
Kohsuke Kawaguchi
Sun Microsystems                   [hidden email]










--
Kohsuke Kawaguchi
Sun Microsystems                   [hidden email]




--
Kohsuke Kawaguchi
Sun Microsystems                   [hidden email]




Reply | Threaded
Open this post in threaded view
|

Re: hudson 1.217 issue -" Please wait while hudson is getting ready to work..."

Kohsuke Kawaguchi
Administrator
Adam Purkiss wrote:
> Nag Nag Nag Nag Nag Nag Nag Nag Nag - repeat until fixed

1.218 is on its way.

> On Wed, May 21, 2008 at 8:47 PM, Kohsuke Kawaguchi <[hidden email]> wrote:
>
> Stephen Connolly wrote:
> I'd rather remove line 101 if you want to keep the launch...I think we need a safe fix, and in that regard restoring the old behavior is better.
>
> anyway the slave will start within 1min of hudson coming online nowThe problem with this is that the jobs that are postponed when Hudson was shut down the last time will now move to the master when it came back.
>
>
>
> On Wed, May 21, 2008 at 8:38 PM, Kohsuke Kawaguchi <[hidden email]> wrote:
> No, this won't launch a slave when Hudson first comes online.I think a quickest safe fix is to roll back the synchronized block in thecloseChannel.I mean, the race condition will be fairly rare, isn't it?Stephen Connolly wrote:
> I have committed to SVN a commenting out of line 279.This is the quickest "safe" fix to let people work again.The real fix is to re-organise the constructors to prevent partiallyconstructed objects leaking... which I don't have the time for at themoment-StephenOn Wed, May 21, 2008 at 8:30 PM, Stephen Connolly <[hidden email]> wrote: Of course none of this was a problem until I noticed that closeChannel
> wasnot using the lock it should have been sharing with setChannel!On Wed, May 21, 2008 at 8:28 PM, Stephen Connolly <[hidden email]> wrote: Yep... should have looked at the stack trace:
>       athudson.slaves.SlaveComputer.closeChannel(SlaveComputer.java:259)      at hudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)****   at hudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)*****      at hudson.model.Computer.<init>(Computer.java:74)      at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)Calling non-final methods from a constructor will lead you to ruin!SlaveComputer.<init> calls it's super, which calls setNode, which isoverridden by SlaveComputer... now we are in SlaveComputer, but we arenotfully constructedOn Wed, May 21, 2008 at 8:25 PM, Stephen Connolly <[hidden email]> wrote: Hmmm I am not sure why this NPE is happening...
> on line 101: we call closeChannel(), which will set the channel tonull... and close it if it is null... but line 99 ensures that channelhasto be null...Somehow, launch is being called before the SlaveComputer constructorhascompleted... that is bad practice. We should be using a factory methodaccording to Java Concurrency In Practice.Before I added the missing synchronization, this was not an issue, asthechannelLock field was not being consulted until the launch's task ontheexecutor started, which is usually after the constructor completes.The launch is being triggered in the super constructor, which is whychannelLock has not been initialized.There are some bad concurrency issue smells all over this code.I think the quick fix is to remove line 101.The long fix is to remove this hidden automatic launch from within theconstructor of ComputerOn Wed, May 21, 2008 at 8:14 PM, Stephen Connolly <[hidden email]> wrote: so the channelLock has not been initialized!
> seems like partially constructed objects leaking from theconstructor... we all have to read the train book againOn Wed, May 21, 2008 at 8:10 PM, Stephen Connolly <[hidden email]> wrote: Ahhh the iPod didn;t show the log!
> On Wed, May 21, 2008 at 8:03 PM, Kohsuke Kawaguchi <[hidden email]> wrote: Stephen Connolly wrote:
>  other than you have a null pointer!
> a stack trace might help usIt's in the log:[#|2008-05-21T13:17:13.007-0400|SEVERE|sun-appserver9.1|> hudson.WebAppMain|_ThreadID=17;_ThreadName=hudson initialization> thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Failed to> initialize Hudson> java.lang.NullPointerException>         at hudson.slaves.SlaveComputer.closeChannel> (SlaveComputer.java:259)>         athudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)>         athudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)>         at hudson.model.Computer.<init>(Computer.java:74)>         athudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)>         at hudson.model.Slave.createComputer(Slave.java:246)>         at hudson.model.Hudson.updateComputer(Hudson.java:576)>         at hudson.model.Hudson.updateComputerList(Hudson.java:556)>         at hudson.model.Hudson.<init>(Hudson.java:351)>         at hudson.WebAppMain$2.run(WebAppMain.java:155)> |#] Sent from my iPod
> On 21 May 2008, at 18:30, "Messmer, Jason" <[hidden email]> wrote: All,
> I am getting a NullPointerException for the slaves when deployed 1.217, which displays "Please wait while hudson is getting readyto work..."Any clues...Thanks,~Jay[#|2008-05-21T13:17:12.111-0400|INFO|sun-appserver9.1|javax.enterprise.system.core.selfmanagement|_ThreadID=10;_ThreadName=main;|SMGT0007: Self Management Rules service isenabled|#][#|2008-05-21T13:17:12.186-0400|WARNING|sun-appserver9.1|javax.enterprise.system.container.ejb| _ThreadID=10;_ThreadName=main;_RequestID=4c2fc416-86e5-4fc6-909b-7358e9142acf;|EJBLifeCycle: Automatic  timer migration component not enabled for  DASinstance|#][#|2008-05-21T13:17:12.218-0400|INFO|sun-appserver9.1|javax.enterprise.system.core|_ThreadID=10;_ThreadName=main;|Applicationserver startup complete.|#][#|2008-05-21T13:17:12.918-0400|INFO|sun-appserver9.1|org.springframework.web.context.support.StaticWebApplicationContext|_ThreadID=17;_ThreadName=hudson initialization thread;|Refreshing org.springframework.web.context.support.StaticW
ebApplicationContext@1362ca8:display  name [Root WebApplicationContext]; startup date [Wed May2113:17:12  EDT 2008]; root of context hierarchy|#][#|2008-05-21T13:17:12.920-0400|INFO|sun-appserver9.1|org.springframework.web.context.support.StaticWebApplicationContext|_ThreadID=17;_ThreadName=hudson initialization thread;|Beanfactory  forapplication context[org.springframework.web.context.support.StaticWebApplicationContext@1362ca8]:  org. springframework.beans.factory.support.DefaultListableBeanFactory@d7373f|#][#|2008-05-21T13:17:12.921-0400|INFO|sun-appserver9.1|org.springframework.beans.factory.support.DefaultListableBeanFactory|_ThreadID=17;_ThreadName=hudson initialization thread;|Pre-instantiatingsingletons in  org. springframework.beans.factory.support.DefaultListableBeanFactory@d7373f: defining beans [authenticationManager,userDetailsService]; root of factory hierarchy|#][#|2008-05-21T13:17:12.960-0400|INFO|sun-appserver9.1|hudson.model.Hudson|_ThreadID=17;_ThreadName=
hudson initialization thread;|Took 1760 ms to load|#][#|2008-05-21T13:17:13.007-0400|SEVERE|sun-appserver9.1|hudson.WebAppMain|_ThreadID=17;_ThreadName=hudson initialization thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Failed to initialize Hudsonjava.lang.NullPointerException     at hudson.slaves.SlaveComputer.closeChannel(SlaveComputer.java:259)     athudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)     athudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)     at hudson.model.Computer.<init>(Computer.java:74)     at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)     at hudson.model.Slave.createComputer(Slave.java:246)     at hudson.model.Hudson.updateComputer(Hudson.java:576)     at hudson.model.Hudson.updateComputerList(Hudson.java:556)     at hudson.model.Hudson.<init>(Hudson.java:351)     at hudson.WebAppMain$2.run(WebAppMain.java:155)|#][#|2008-05-21T13:17:13.010-0400|WARNING|sun-appserver9.1|javax.enterprise.system.stream.err|_Thr
eadID=17;_ThreadName=hudson initialization thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|Exception in thread "hudson initializationthread" |#][#|2008-05-21T13:17:13.018-0400|WARNING|sun-appserver9.1|javax.enterprise.system.stream.err|_ThreadID=17;_ThreadName=hudson initialization thread;_RequestID=cd5b4695-a356-45fb-873a-17367207533f;|java.lang.NullPointerException     at hudson.slaves.SlaveComputer.closeChannel(SlaveComputer.java:259)     athudson.slaves.SlaveComputer.launch(SlaveComputer.java:101)     athudson.slaves.SlaveComputer.setNode(SlaveComputer.java:279)     at hudson.model.Computer.<init>(Computer.java:74)     at hudson.slaves.SlaveComputer.<init>(SlaveComputer.java:66)     at hudson.model.Slave.createComputer(Slave.java:246)     at hudson.model.Hudson.updateComputer(Hudson.java:576)     at hudson.model.Hudson.updateComputerList(Hudson.java:556)     at hudson.model.Hudson.<init>(Hudson.java:351)     at hudson.WebAppMain$2.run(WebAppMain.java:155)|#][#|200
8-05-21T13:17:38.074-0400|INFO|sun-appserver9.1|javax.enterprise.resource.webcontainer.jsf.config--Kohsuke KawaguchiSun Microsystems                   [hidden email]--Kohsuke KawaguchiSun Microsystems                   [hidden email]--
>
>
> Kohsuke KawaguchiSun Microsystems                   [hidden email]
> _________________________________________________________________
>
>


--
Kohsuke Kawaguchi
Sun Microsystems                   [hidden email]

smime.p7s (4K) Download Attachment