[jboss-user] [Installation, Configuration & DEPLOYMENT] - Re: Silent application server crash with jboss-4.0.3SP1

sachin.mohan@kbcfp.com do-not-reply at jboss.com
Wed Apr 2 17:35:57 EDT 2008


I see it in the logs. There are no errors in the logs that would trigger this. 

The jboss command line we use to start is:

/prod/cbtech/pkgs/sunos-5.10-i86pc/jdk1.5.0_06/bin/java -server -XX:+UseConcMarkSweepGC -verbose:gc -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -Xloggc:/data/cbtech-local/135/jboss/server/ejb/log/gc.log -ms2800m -mx2800m -XX:+DisableExplicitGC -XX:NewSize=85m -XX:MaxNewSize=85m -XX:CMSInitiatingOccupancyFraction=85 -Djboss.partition.name=PartitionEJB-135 -Djboss.partition.udpGroup=228.1.3.135 -classpath /data/cbtech-local/135/jboss/bin/run.jar:/prod/cbtech/pkgs/sunos-5.10-i86pc/jdk1.5.0_06/lib/tools.jar:/usr/local/pkgs/tibrv-7.4.1/lib/tibrvj.jar org.jboss.Main -c ejb

And it crashed again today without any undeploy messages. Following were the logs seen around the time it crashed.

GC-LOG (last lines):
428770.447: [GC 428770.447: [ParNew: 86912K->0K(86976K), 0.1210544 secs] 2165379K->2114565K(2867136K), 0.1212449 secs]
428780.330: [GC 428780.331: [ParNew: 86912K->0K(86976K), 0.1337211 secs] 2201477K->2146088K(2867136K), 0.1339104 secs]
428787.036: [GC 428787.036: [ParNew: 86912K->0K(86976K), 0.1621513 secs] 2233000K->2193530K(2867136K), 0.1623363 secs]
428788.272: [GC 428788.272: [ParNew (promotion failed): 86873K->86873K(86976K), 21.4087057 secs]428809.681: [CMS (concurrent mode failure): 2206872K->1201836K(2780160K), 12.1240322 secs] 2280403K->1201836K(2867
136K), 33.5330371 secs]
428832.636: [GC 428832.636: [ParNew: 86912K->0K(86976K), 0.1898448 secs] 1288748K->1248557K(2867136K), 0.1900673 secs]

Console Log (around the time it died):

17:08:07,676 ERROR [com.kbcfp.insight.components.clientObjectCacheDelegateService.server.DefaultClientObjectCacheDelegate] Finalized DefaultClientObjectCacheDelegate
17:08:07,681 WARN  [org.jgroups.protocols.FD] I was suspected, but will not remove myself from membership (waiting for EXIT message)
17:08:07,681 WARN  [org.jgroups.protocols.FD] I was suspected, but will not remove myself from membership (waiting for EXIT message)
17:08:07,683 WARN  [org.jgroups.protocols.pbcast.GMS] checkSelfInclusion() failed, cbcalcsx1:52572 (additional data: 15 bytes) is not a member of view [cbcalcsx2:40421 (additional data: 15 bytes)|22] [cbcalcsx2:40421 (additional data: 15 bytes), cbappsx22:63549 (additional data: 20 bytes), cbcalcsx3:32821 (additional data: 15 bytes), cbcalcsx4:43849 (additional data: 15 bytes), cbappsx25:35017 (additional data: 15 bytes)]; discarding view
17:08:07,683 WARN  [org.jgroups.protocols.pbcast.GMS] I (cbcalcsx1:52572 (additional data: 15 bytes)) am being shunned, will leave and rejoin group (prev_members are [cbcalcsx2:40421 (additional data: 15 bytes)  cbappsx22:63549 (additional data: 20 bytes) cbcalcsx3:32821 (additional data: 15 bytes) cbcalcsx4:43849 (additional data: 15 bytes) cbappsx25:34450 (additional data: 15 bytes) cbcalcsx1:52572 (additional data: 15 bytes) cbappsx25:43841 (additional data: 15 bytes) cbappsx25:35017 (additional data: 15 bytes) ])

Server Log (Around the time it died):

17:08:07,681 WARN  #UpHandler (FD) [protocols.FD                  ] I was suspected, but will not remove myself from membership (waiting for EXIT message)
17:08:07,681 WARN  #UpHandler (FD) [protocols.FD                  ] I was suspected, but will not remove myself from membership (waiting for EXIT message)
17:08:07,683 WARN  #UpHandler (GMS) [pbcast.GMS                    ] checkSelfInclusion() failed, cbcalcsx1:52572 (additional data: 15 bytes) is not a member of view [cbcalcsx2:40421 (additional data: 15 bytes) |22] [cbcalcsx2:40421 (additional data: 15 bytes), cbappsx22:63549 (additional data: 20 bytes), cbcalcsx3:32821 (additional data: 15 bytes), cbcalcsx4:43849 (additional data: 15 bytes), cbappsx25:35017 (additio nal data: 15 bytes)]; discarding view
17:08:07,683 WARN  #UpHandler (GMS) [pbcast.GMS                    ] I (cbcalcsx1:52572 (additional data: 15 bytes)) am being shunned, will leave and rejoin group (prev_members are [cbcalcsx2:40421 (additional data: 15 bytes) cbappsx22:63549 (additional data: 20 bytes) cbcalcsx3:32821 (additional data: 15 bytes) cbcalcsx4:43849 (additional data: 15 bytes) cbappsx25:34450 (additional data: 15 bytes) cbcalcsx1:52572 (a dditional data: 15 bytes) cbappsx25:43841 (additional data: 15 bytes) cbappsx25:35017 (additional data: 15 bytes) ])
17:08:07,684 INFO  #UpHandler (STATE_TRANSFER) [jgroups.JChannel              ] received an EXIT event, will leave the channel
17:08:07,686 INFO  #CloserThread [jgroups.JChannel              ] closing the channel
17:08:07,689 DEBUG #JMS SessionPool Worker-0 [ejb2.UserBean                 ] Activating UserBean
17:08:08,191 WARN  #RMI TCP Connection(31656)-10.64.35.221 [server.TabletDelegate         ] recalcTabletStructure took 34234ms
17:08:08,194 WARN  #RMI TCP Connection(31656)-10.64.35.221 [server.TabletDelegate         ] getTabletStructure took 34237ms
17:08:08,194 WARN  #RMI TCP Connection(31656)-10.64.35.221 [server.TabletDelegate         ] recalcUpdateRegion took 34237ms
17:08:08,194 WARN  #pool-1-thread-1 [server.TabletManager          ] processDelegate spent 34231ms to executing TabletDelegate Search: TabletFilter:m_region = null
m_currency = null
m_country = null
m_category = 0
m_showIlliquid = true
m_showDuplicates = true
m_showRelevant = true
m_activated = true
 PrefixFilter:
m_searchType: Name+Quick+Bloomberg+Local+SPN+Cusip+All+Underlying SPN+Same Underlying+Org Id+Org Name+Org Shortcode+Org Bloombergcode+CParty Name+Text Filter+(847708415)
 m_searchText: null m_searchEtid: null m_isInteract: false m_isGoto: false
17:08:08,195 WARN  #pool-1-thread-5 [server.TabletManager          ] trigger() took 34232ms to execute 33 tablet delegates
17:08:08,502 INFO  #CloserThread [jgroups.JChannel              ] reconnecting to group PartitionEJB-135
17:08:08,509 INFO  #DownHandler (UDP) [protocols.UDP                 ] unicast sockets will use interface 10.64.1.13
17:08:08,509 INFO  #DownHandler (UDP) [protocols.UDP                 ] socket information:
local_addr=cbcalcsx1:50030 (additional data: 15 bytes), mcast_addr=228.1.3.135:45566, bind_addr=/10.64.1.13, ttl=8
sock: bound to 10.64.1.13:50030, receive buffer size=150000, send buffer size=800000
mcast_recv_sock: bound to 10.64.1.13:45566, send buffer size=800000, receive buffer size=150000
mcast_send_sock: bound to 10.64.1.13:50031, send buffer size=800000, receive buffer size=150000
17:08:08,510 INFO  #UpHandler (GMS) [STDOUT                        ]
-------------------------------------------------------
GMS: address is cbcalcsx1:50030 (additional data: 15 bytes)
-------------------------------------------------------
17:08:08,517 INFO  #CloserThread [jgroups.JChannel              ] fetching the state (auto_getstate=true)
17:08:08,517 DEBUG #MessageDispatcher up processing thread [foAlertService.FOAlertServiceComponent] membership view changed recieved
17:08:08,518 INFO  #MessageDispatcher up processing thread [HAPartition.PartitionEJB-135  ] New cluster view for partition PartitionEJB-135: 23 ([10.64.1.14:1299, 204.253.249.133:1299, 10.64.1.15:1299, 10.64.1.  16:1299, 10.64.1.45:1299, 10.64.1.13:1299] delta: 0)
17:08:08,518 INFO  #MessageDispatcher up processing thread [tedReplicantManagerImpl.PartitionEJB-135] I am (10.64.1.13:1299) received membershipChanged event:
17:08:08,518 INFO  #MessageDispatcher up processing thread [tedReplicantManagerImpl.PartitionEJB-135] Dead members: 0 ([])
17:08:08,518 INFO  #MessageDispatcher up processing thread [tedReplicantManagerImpl.PartitionEJB-135] New Members : 0 ([])
17:08:08,518 INFO  #MessageDispatcher up processing thread [tedReplicantManagerImpl.PartitionEJB-135] All Members : 6 ([10.64.1.14:1299, 204.253.249.133:1299, 10.64.1.15:1299, 10.64.1.16:1299, 10.64.1.45:1299, 10.64.1.13:1299])
17:08:08,524 INFO  #CloserThread [jgroups.JChannel              ] state was retrieved successfully
17:08:08,586 INFO  #DRM Async Publisher#1 [ejb.ProxyFactory              ] Bound EJB Home 'IDT2.MiniTabState' to jndi 'IDT2.MiniTabState'
17:08:08,587 INFO  #DRM Async Publisher#1 [ejb.ProxyFactory              ] Bound EJB Home 'IDT2.HouseKeeping' to jndi 'IDT2.HouseKeeping'
17:08:09,842 INFO  #pool-1-thread-3 [calc.PAndLCalculator          ] Couldn't find holding for holding=(desk=3057, book=10073, spn=51001656, spnccy=1760000) period 7
17:08:13,072 DEBUG #pool-1-thread-5 [calc.PAndLCalculator          ] -3.4147bp move triggered FX recalculation - spn=1760115 was 0.1952, now 0.1951
---------------- no more logs after this --------

View the original post : http://www.jboss.com/index.html?module=bb&op=viewtopic&p=4141115#4141115

Reply to the post : http://www.jboss.com/index.html?module=bb&op=posting&mode=reply&p=4141115



More information about the jboss-user mailing list