users@grizzly.java.net

Re: Grizzly/Comet GF V3 hangs

From: Carla Mott <Carla.Mott_at_Sun.COM>
Date: Tue, 31 Mar 2009 09:49:26 -0700

I put in a fix for this issue last week and I heard back from at least
one person in the connector area that things were working. Has anyone
on this alias tried the default config (with log files rotating) on the
latest build? I wanted to verify that the problem is fixed.

Thanks,
Carla

Carla Mott wrote:
> Thanks for reporting back what is going on. Last week requested that I
> change the default back to what prelude is doing but I had not gotten an
> ok to do so.
>
> You have a work around so you can continue. Note that if you reinstall
> the server you will have to change the property again. I have more
> specifics so I can look and see what is happening in the rotation code
> that causes this.
>
> Thanks,
> Carla
>
> felixx wrote:
>> I've changed the rotationLimitInBytes and it works fine now (800
>> clients, a
>> lot of logging).
>> See below the original logging.properties content (default in GF V3).
>> When
>> the server hangs it suddenly creates around 50 log files
>> (server.log_2009-03-23T16-xx-yy) , each 2 M in size, with the SAME
>> content.
>> I guess something is wrong when the log file is about to be rotated.
>>
>> GlassFish logging.properties list
>> #Mon Mar 23 17:20:15 EDT 2009
>> javax.enterprise.system.tools.admin.level=INFO
>> handlers=java.util.logging.ConsoleHandler
>> java.util.logging.ConsoleHandler.formatter=com.sun.enterprise.server.logging.UniformLogFormatter
>>
>> connector=INFO
>> org.apache.jasper.level=INFO
>> javax.enterprise.resource.corba.level=INFO
>> verifier=INFO
>> javax.enterprise.system.core.classloading.level=INFO
>> javax.enterprise.resource.jta.level=INFO
>> java.util.logging.ConsoleHandler.level=INFO
>> com.sun.enterprise.server.logging.GFFileHandler.file=C\:\\glassfishv3\\glassfish\\domains\\domain1/logs/server.log
>>
>> javax.enterprise.system.webservices.saaj.level=INFO
>> java.util.logging.FileHandler.formatter=java.util.logging.XMLFormatter
>> javax.enterprise.system.tools.deployment.level=INFO
>> javax.enterprise.system.container.ejb.level=INFO
>> javax.enterprise.system.core.transaction.level=INFO
>> org.apache.catalina.level=INFO
>> node-agent=INFO
>> com.sun.enterprise.server.logging.GFFileHandler.rotationTimelimitInMinutes=0
>>
>> javax.enterprise.system.container.ejb.mdb.level=INFO
>> org.apache.coyote.level=INFO
>> javax.level=INFO
>> java.util.logging.FileHandler.limit=50000
>> javax.enterprise.resource.javamail.level=INFO
>> com.sun.enterprise.server.logging.GFFileHandler.logtoConsole=false
>> javax.enterprise.system.webservices.rpc.level=INFO
>> javax.enterprise.system.container.web.level=INFO
>> javax.enterprise.system.util.level=INFO
>> javax.enterprise.resource.resourceadapter.level=INFO
>> management-event=INFO
>> javax.enterprise.resource.jms.level=INFO
>> com.sun.enterprise.server.logging.GFFileHandler.rotationLimitInBytes=2000000
>>
>> javax.enterprise.system.core.config.level=INFO
>> javax.enterprise.system.level=INFO
>> javax.enterprise.system.core.security.level=INFO
>> javax.enterprise.system.container.cmp.level=INFO
>> java.util.logging.FileHandler.pattern=%h/java%u.log
>> com.sun.enterprise.server.logging.SyslogHandler.useSystemLogging=false
>> synchronization=INFO
>> group-management-services=INFO
>> com.sun.enterprise.server.logging.GFFileHandler.alarms=false
>> javax.enterprise.system.webservices.registry.level=INFO
>> javax.enterprise.system.core.selfmanagement.level=INFO
>> com.sun.enterprise.server.logging.GFFileHandler.formatter=com.sun.enterprise.server.logging.UniformLogFormatter
>>
>> .level=INFO
>> java.util.logging.FileHandler.count=1
>> javax.enterprise.resource.jdo.level=INFO
>> javax.enterprise.system.core.naming.level=INFO
>> com.sun.enterprise.server.logging.GFFileHandler.retainErrorsStasticsForHours=5
>>
>>
>>
>>
>>
>> Carla Mott wrote:
>>>
>>> file is not attached but I see that file rotation is on which is what
>>> I was wondering about.
>>>
>>> you have lots of log files because the property mentioned below is
>>> set to something other than 0. Setting it to 0 means that you want
>>> all log messages to go to one file.
>>>
>>> Could it be that you are hitting some system resource with all those
>>> files?
>>>
>>>
>>> Please set the following property to 0 and rerun you test.
>>> com.sun.enterprise.server.logging.GFFileHandler.rotationLimitInBytes
>>>
>>> Let me know if you notice different behavior.
>>>
>>> Thanks,
>>> CArla
>>>
>>> felixx wrote:
>>>> Sorry, try now
>>>> Something must funny there, i got a huge number of log files created
>>>>
>>>>
>>>> Carla Mott wrote:
>>>>> I don't see the properties file.
>>>>>
>>>>> felixx wrote:
>>>>>> Thanks guys, Properties file attached.
>>>>>> Still, why the server was totally dead, i mean not only Comet, no
>>>>>> response
>>>>>> at all on 8080/4848 I'll run some more tests and let you know.
>>>>>> Richard, are you talking about concatenating the log messages or the
>>>>>> events?
>>>>>>
>>>>>> Carla Mott wrote:
>>>>>>> Can someone send me the logging.properties file that is in the
>>>>>>> config dir for this domain?
>>>>>>>
>>>>>>> This mechanism (using ArrayBlockingQueue) has been used for all
>>>>>>> of prelude so I wonder if the config is causing the problem as
>>>>>>> somethings have changed in this area.
>>>>>>>
>>>>>>> What is the following property in that file set to and if not 0 does
>>>>>>> the problem go away if set to 0?
>>>>>>>
>>>>>>> com.sun.enterprise.server.logging.GFFileHandler.rotationLimitInBytes
>>>>>>>
>>>>>>> you can just change the file but you will have to restart the server
>>>>>>> for the new value to take affect.
>>>>>>>
>>>>>>> Thanks,
>>>>>>> Carla
>>>>>>>
>>>>>>> Jeanfrancois Arcand wrote:
>>>>>>>> Salut,
>>>>>>>>
>>>>>>>> gustav trede wrote:
>>>>>>>>> so your overwhelming the log at info level from the onEvent
>>>>>>>>> method, all cometworker threads are waiting inside the logger.
>>>>>>>> Indeed! Adding Carla to the thread as she might now why:
>>>>>>>>
>>>>>>>>> CometWorker-7" daemon prio=6 tid=0x075c9400 nid=0x2198 waiting
>>>>>>>>> on condition [0x0fc8f000..0x0fc8fc68]
>>>>>>>>> java.lang.Thread.State: WAITING (parking)
>>>>>>>>> at sun.misc.Unsafe.park(Native Method)
>>>>>>>>> - parking to wait for <0x1c8b3988> (a
>>>>>>>>> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
>>>>>>>>>
>>>>>>>>> at
>>>>>>>>> java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
>>>>>>>>> at
>>>>>>>>> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1925)
>>>>>>>>>
>>>>>>>>> at
>>>>>>>>> java.util.concurrent.ArrayBlockingQueue.put(ArrayBlockingQueue.java:252)
>>>>>>>>>
>>>>>>>>> at
>>>>>>>>> com.sun.enterprise.server.logging.GFFileHandler.publish(GFFileHandler.java:509)
>>>>>>>>>
>>>>>>>>> at java.util.logging.Logger.log(Logger.java:472)
>>>>>>>>> at java.util.logging.Logger.doLog(Logger.java:494)
>>>>>>>>> at java.util.logging.Logger.log(Logger.java:517)
>>>>>>>>> at java.util.logging.Logger.info(Logger.java:1036)
>>>>>>>>> at
>>>>>>>>> com.bcs.mm.model.EventSubscriber.onEvent(EventSubscriber.java:99)
>>>>>>>>> at
>>>>>>>>> com.sun.grizzly.comet.concurrent.DefaultConcurrentCometHandler.EnQueueEvent(DefaultConcurrentCometHandler.java:152)
>>>>>>>>>
>>>>>>>>> at
>>>>>>>>> com.sun.grizzly.comet.DefaultNotificationHandler.notify0(DefaultNotificationHandler.java:179)
>>>>>>>>>
>>>>>>>>> at
>>>>>>>>> com.sun.grizzly.comet.DefaultNotificationHandler$2.run(DefaultNotificationHandler.java:142)
>>>>>>>>>
>>>>>>>>> at
>>>>>>>>> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885)
>>>>>>>>>
>>>>>>>>> at
>>>>>>>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
>>>>>>>>>
>>>>>>>>> at java.lang.Thread.run(Thread.java:619)
>>>>>>>> I don't think this is a bug in Grizzly IMO, but a problem with
>>>>>>>> the logger in GlassFish (hence the micro benchmark we have in
>>>>>>>> Grizzly
>>>>>>>> cannot catch it).
>>>>>>>>
>>>>>>>> Thanks!
>>>>>>>>
>>>>>>>> -- Jeanfrancois
>>>>>>>>
>>>>>>>>
>>>>>>>>> 2009/3/23 felixx <dolaru_at_sympatico.ca
>>>>>>>>> <mailto:dolaru_at_sympatico.ca>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> File attached, thanks.
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> felixx wrote:
>>>>>>>>> >
>>>>>>>>> > GF V3 build 41, Win Vista, Java HotSpot(TM) Server VM
>>>>>>>>> (10.0-b19) for
>>>>>>>>> > windows-x86 JRE (1.6.0_05-b13);
>>>>>>>>> > Simple Comet test scenario: 100 java streaming clients
>>>>>>>>> connected
>>>>>>>>> to the
>>>>>>>>> > same Comet context, 1 event is posted to the context every
>>>>>>>>> second.
>>>>>>>>> > Works fine for approx 50-60 seconds then the server
>>>>>>>>> hangs. Nothing is
>>>>>>>>> > pushed to the clients anymore, no request is served on 8080
>>>>>>>>> or 4848
>>>>>>>>> > (tested via browser), the server is dead.
>>>>>>>>> > Looks like a random/race condition.
>>>>>>>>> >
>>>>>>>>> >
>>>>>>>>>
>>>>>>>>> http://www.nabble.com/file/p22664213/stack.txt stack.txt
>>>>>>>>> --
>>>>>>>>> View this message in context:
>>>>>>>>>
>>>>>>>>> http://www.nabble.com/Grizzly-Comet-GF-V3-hangs-tp22663593p22664213.html
>>>>>>>>>
>>>>>>>>> Sent from the Grizzly - Users mailing list archive at
>>>>>>>>> Nabble.com.
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> ---------------------------------------------------------------------
>>>>>>>>>
>>>>>>>>> To unsubscribe, e-mail: users-unsubscribe_at_grizzly.dev.java.net
>>>>>>>>> <mailto:users-unsubscribe_at_grizzly.dev.java.net>
>>>>>>>>> For additional commands, e-mail:
>>>>>>>>> users-help_at_grizzly.dev.java.net
>>>>>>>>> <mailto:users-help_at_grizzly.dev.java.net>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> --
>>>>>>>>> regards
>>>>>>>>> gustav trede
>>>>>>>>>
>>>>>>>>>
>>>>>>>> ---------------------------------------------------------------------
>>>>>>>>
>>>>>>>> To unsubscribe, e-mail: users-unsubscribe_at_grizzly.dev.java.net
>>>>>>>> For additional commands, e-mail: users-help_at_grizzly.dev.java.net
>>>>>>>>
>>>>>>> ---------------------------------------------------------------------
>>>>>>>
>>>>>>> To unsubscribe, e-mail: users-unsubscribe_at_grizzly.dev.java.net
>>>>>>> For additional commands, e-mail: users-help_at_grizzly.dev.java.net
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>> http://www.nabble.com/file/p22667362/logging.properties
>>>>>> logging.properties
>>>>> ---------------------------------------------------------------------
>>>>> To unsubscribe, e-mail: users-unsubscribe_at_grizzly.dev.java.net
>>>>> For additional commands, e-mail: users-help_at_grizzly.dev.java.net
>>>>>
>>>>>
>>>>>
>>>> http://www.nabble.com/file/p22667693/logging.properties
>>>> logging.properties
>>>
>>> ---------------------------------------------------------------------
>>> To unsubscribe, e-mail: users-unsubscribe_at_grizzly.dev.java.net
>>> For additional commands, e-mail: users-help_at_grizzly.dev.java.net
>>>
>>>
>>>
>>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe_at_grizzly.dev.java.net
> For additional commands, e-mail: users-help_at_grizzly.dev.java.net
>