3 Replies Latest reply on Mar 3, 2010 2:20 AM by jfclere

Exception thrown while parsing MCMP INFO response

edwinb1 Feb 20, 2010 5:50 AM

Greetings,

Recently, I've been observing the following exception from mod_cluster/Tomcat from time to time:

Feb 18, 2010 11:11:47 PM org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor processChildren
SEVERE: Exception invoking periodic operation:
java.lang.IllegalArgumentException: Node: [1],Name: par.2,Balancer: mycluster,Domain: par,Host: 169.70.168.86,Port: 46190,Type: ajp,Flushpackets: Off,Flushwait: 10000,Ping: 10000000,Smax: 26,Ttl: 60000000,Elected: 0,Read: 0,Transfered: 0,Connected: 0,Load: 100
Node: [2],Name: par.9,Balancer: mycluster,Domain: par,Host: 169.70.168.98,Port: 45389,Type: ajp,Flushpackets: Off,Flushwait: 10000,Ping: 10000000,Smax: 26,Ttl: 60000000,Elected: 0,Read: 0,Transfered: 0,Connected: 0,Load: 100
Node: [4],Name: par.10,Balancer: mycluster,Domain: par,Host: 169.70.168.85,Port: 48419,Type: ajp,Flushpackets: Off,Flushwait: 10000,Ping: 10000000,Smax: 26,Ttl: 60000000,Elected: 0,Read: 0,Transfered: 0,Connected: 0,Load: 100
Node: [5],Name: f-syn-landing.2,Balancer: mycluster,Domain: f-syn-landing,Host: 169.70.168.87,Port: 47531,Type: ajp,Flushpackets: Off,Flushwait: 10000,Ping: 10000000,Smax: 26,Ttl: 60000000,Elected: 0,Read: 0,Transfered: 0,Connected: 0,Load: 100
Node: [6],Name: TransfersWeb.1,Balancer: mycluster,Domain: TransfersWeb,Host: 169.70.168.86,Port: 48125,Type: ajp,Flushpackets: Off,Flushwait: 10000,Ping: 10000000,Smax: 26,Ttl: 60000000,Elected: 0,Read: 0,Transfered: 0,Connected: 0,Load: 100
Node: [7],Name: f-sync-utils.2,Balancer: mycluster,Domain: f-sync-utils,Host: 169.70.168.87,Port: 59851,Type: ajp,Flushpackets: Off,Flushwait: 10000,Ping: 10000000,Smax: 26,Ttl: 60000000,Elected: 0,Read: 0,Transfered: 0,Connected: 0,Load: 100
Node: [8],Name: Mike.5,Balancer: mycluster,Domain: Mike,Host: 169.70.168.95,Port: 55815,Type: ajp,Flushpackets: Off,Flushwait: 10000,Ping: 10000000,Smax: 26,Ttl: 60000000,Elected: 0,Read: 0,Transfered: 0,Connected: 0,Load: 100
Node: [9],Name: Mike.4,Balancer: mycluster,Domain: Mike,Host: 169.70.168.94,Port: 45822,Type: ajp,Flushpackets: Off,Flushwait: 10000,Ping: 10000000,Smax: 26,Ttl: 60000000,Elected: 0,Read: 0,Transfered: 0,Connected: 0,Load: 100
Node: [10],Name: par.4,Balancer: mycluster,Domain: par,Host: 169.70.168.94,Port: 36784,Type: ajp,Flushpackets: Off,Flushwait: 10000,Ping: 10000000,Smax: 26,Ttl: 60000000,Elected: 0,Read: 0,Transfered: 0,Connected: 0,Load: 100
Node: [11],Name: Guestbook2.1,Balancer: mycluster,Domain: Guestbook2,Host: 169.70.168.87,Port: 41828,Type: ajp,Flushpackets: Off,Flushwait: 10000,Ping: 10000000,Smax: 26,Ttl: 60000000,Elected: 0,Read: 0,Transfered: 0,Connected: 0,Load: 100
Node: [12],Name: f-syn-landing.1,Balancer: mycluster,Domain: f-syn-landing,Host: 169.70.168.86,Port: 57548,Type: ajp,Flushpackets: Off,Flushwait: 10000,Ping: 10000000,Smax: 26,Ttl: 60000000,Elected: 0,Read: 0,Transfered: 0,Connected: 0,Load: 100
Node: [13],Name: par.7,Balancer: mycluster,Domain: par,Host: 169.70.168.97,Port: 56902,Type: ajp,Flushpackets: Off,Flushwait: 10000,Ping: 10000000,Smax: 26,Ttl: 60000000,Elected: 0,Read: 0,Transfered: 0,Connected: 0,Load: 100
Node: [14],Name: f-sso-redir.1,Balancer: mycluster,Domain: f-sso-redir,Host: 169.70.168.86,Port: 56340,Type: ajp,Flushpackets: Off,Flushwait: 10000,Ping: 10000000,Smax: 26,Ttl: 60000000,Elected: 0,Read: 0,Transfered: 0,Connected: 0,Load: 100
Node: [15],Name: f-syn-signup.1,Balancer: mycluster,Domain: f-syn-signup,Host: 169.70.168.86,Port: 60930,Type: ajp,Flushpackets: Off,Flushwait: 10000,Ping: 10000000,Smax: 26,Ttl: 60000000,Elected: 0,Read: 0,Transfered: 0,Connected: 0,Load: 100
Node: [16],Name: par.1,Balancer: mycluster,Domain: par,Host: 169.70.168.87,Port: 58735,Type: ajp,Flushpackets: Off,Flushwait: 10000,Ping: 10000000,Smax: 26,Ttl: 60000000,Elected: 0,Read: 0,Transfered: 0,Connected: 0,Load: 100
Node: [17],Name: f-syn-signup.2,Balancer: mycluster,Domain: f-syn-signup,Host: 169.70.168.87,Port: 47124,Type: ajp,Flushpackets: Off,Flushwait: 10000,Ping: 10000000,Smax: 26,Ttl: 60000000,Elected: 0,Read: 0,Transfered: 0,Connected: 0,Load: 100
Node: [18],Name: par.8,Balancer: mycluster,Domain: par,Host: 169.70.168.84,Port: 38533,Type: ajp,Flushpackets: Off,Flushwait: 10000,Ping: 10000000,Smax: 26,Ttl: 60000000,Elected: 0,Read: 0,Transfered: 0,Connected: 0,Load: 100
Node: [19],Name: par.5,Balancer: mycluster,Domain: par,Host: 169.70.168.95,Port: 44940,Type: ajp,Flushpackets: Off,Flushwait: 10000,Ping: 10000000,Smax: 26,Ttl: 60000000,Elected: 0,Read: 0,Transfered: 0,Connected: 0,Load: 100
Node: [20],Name: par.6,Balancer: mycluster,Domain: par,Host: 169.70.168.83,Port: 49207,Type: ajp,Flushpackets: Off,Flushwait: 10000,Ping: 10000000,Smax: 26,Ttl: 60000000,Elected: 0,Read: 0,Transfered: 0,Connected: 0,Load: 100
Node: [21],Name: par.3,Balancer: mycluster,Domain: par,Host: 169.70.168.88,Port: 48819,Type: ajp,Flushpackets: Off,Flushwait: 10000,Ping: 10000000,Smax: 26,Ttl: 60000000,Elected: 0,Read: 0,Transfered: 0,Connected: 0,Load: 100
Node: [22],Name: f-sso-redir.2,Balancer: mycluster,Domain: f-sso-redir,Host: 169.70.168.87,Port: 43815,Type: ajp,Flushpackets: Off,Flushwait: 10000,Ping: 10000000,Smax: 26,Ttl: 60000000,Elected: 0,Read: 0,Transfered: 0,Connected: 0,Load: 100
Node: [25],Name: REMOVED,Balancer: mycluster,Domain: f-sync-utils,Host: 169.70.168.86,Port: 51143,Type: ajp,Flushpackets: Off,Flushwait: 10000,Ping: 10000000,Smax: 26,Ttl: 60000000,Elected: 0,Read: 0,Transfered: 0,Connected: 0,Load: 100
Vhost: [2:1:1], Alias: localhost
Vhost: [10:1:2], Alias: localhost
Vhost: [4:1:3], Alias: localhost
Vhost: [6:1:4], Alias: localhost
Vhost: [7:1:5], Alias: localhost
Vhost: [5:1:6], Alias: localhost
Vhost: [8:1:7], Alias: localhost
Vhost: [9:1:8], Alias: localhost
Vhost: [11:1:9], Alias: localhost
Vhost: [12:1:10], Alias: localhost
Vhost: [13:1:11], Alias: localhost
Vhost: [1:1:12], Alias: localhost
Vhost: [14:1:13], Alias: localhost
Vhost: [15:1:14], Alias: localhost
Vhost: [16:1:15], Alias: localhost
Vhost: [17:1:16], Alias: localhost
Vhost: [19:1:17], Alias: localhost
Vhost: [18:1:18], Alias: localhost
Vhost: [20:1:19], Alias: localhost
Vhost: [21:1:20], Alias: localhost
Vhost: [22:1:21], Alias: localhost
Vhost: [24:1:22], Alias: localhost
Vhost: [25:1:24], Alias: localhost
Context: [2:1:1], Context: /par, Status: ENABLED
Context: [9:1:2], Context: /Mike, Status: ENABLED
Context: [6:1:3], Context: /secure/TransfersWeb, Status: ENABLED
Context: [4:1:4], Context: /par, Status: ENABLED
Context: [7:1:5], Context: /f-sync-utils, Status: ENABLED
Context: [5:1:6], Context: /f-syn-landing, Status: ENABLED
Context: [8:1:7], Context: /Mike, Status: ENABLED
Context: [10:1:8], Context: /par, Status: ENABLED
Context: [11:1:9], Context: /Guestbook2, Status: ENABLED
Context: [12:1:10], Context: /f-syn-landing, Status: ENABLED
Context: [13:1:11], Context: /par, Status: ENABLED
Context: [1:1:12], Context: /par, Status: ENABLED
Context: [14:1:13], Context: /f-sso-redir, Status: ENABLED
Context: [15:1:14], Context: /secure/f-syn-signup, Status: ENABLED
Context: [16:1:15], Context: /par, Status: ENABLED
Context: [17:1:16], Context: /secure/f-syn-signup, Status: ENABLED
Context: [19:1:17], Context: /par, Status: ENABLED
Context: [18:1:18], Context: /par, Status: ENABLED
Context: [20:1:19], Context: /par, Status: ENABLED
Context: [21:1:20], Context: /par, Status: ENABLED
Context: [22:1:21], Context: /f-sso-redir, Status: ENABLED
Context: [24:1:22], Context: /f-sync-utils, Status: ENABLED
Context: [25:1:24], Context: /f-sync-utils, Status: ENABLED

at org.jboss.modcluster.mcmp.impl.DefaultMCMPResponseParser.parseInfoResponse(DefaultMCMPResponseParser.java:102)
at org.jboss.modcluster.mcmp.impl.DefaultMCMPHandler.status(DefaultMCMPHandler.java:409)
at org.jboss.modcluster.mcmp.impl.DefaultMCMPHandler.status(DefaultMCMPHandler.java:338)
at org.jboss.modcluster.ModClusterService.status(ModClusterService.java:395)
at org.jboss.modcluster.catalina.CatalinaEventHandlerAdapter.lifecycleEvent(CatalinaEventHandlerAdapter.java:169)
at org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:119)
at org.apache.catalina.core.ContainerBase.backgroundProcess(ContainerBase.java:1337)
at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1601)
at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.run(ContainerBase.java:1590)
at java.lang.Thread.run(Thread.java:619)

The apparent cause for this is the "Vhost: [24:1:22]" entry has no corresponding "Node: [24]" entry.

The remaining members of the "f-sync-utils" domain are:

"Node: [7],Name: f-sync-utils.2"

"Node: [25],Name: REMOVED" (Used to be named "f-sync-utils.1")

Can this condition arrise while a node is being shutdown?

Thanks for any help.

Edwin

1. Re: Exception thrown while parsing MCMP INFO response

jfclere Feb 22, 2010 2:57 AM (in response to edwinb1)

"The apparent cause for this is the "Vhost: [24:1:22]" entry has no corresponding "Node: [24]" entry."
Yes that is the problem. Somehow you have a host and contexts that doesn't correspond to a node that shouldn't happend.
Do you have a way to reproduce the problem easly?
Actions
2. Re: Exception thrown while parsing MCMP INFO response

edwinb1 Mar 2, 2010 1:16 PM (in response to jfclere)

It appears that 2 of the 3 Tomcat instances serving the 'f-sync-utils' context were in a collision from being configure to the same domain/jvmRoute values.

While I would certainly advocate a means of preventing such an occurence on the worker provisioning side, are there any thoughts on how to detect and possibly handle this condition?
Actions
3. Re: Exception thrown while parsing MCMP INFO response

jfclere Mar 3, 2010 2:20 AM (in response to edwinb1)

That is something hard to prevent because for the httpd logic it is hard to know what happends because the CONFIG message would be the same if you were changing the node configuration and restarting it.
Actions

Go to original post