users@grizzly.java.net

Re: Grizzly/Comet GF V3 hangs

From: felixx <dolaru_at_sympatico.ca>
Date: Mon, 23 Mar 2009 14:32:29 -0700 (PDT)

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
>
>
>

-- 
View this message in context: http://www.nabble.com/Grizzly-Comet-GF-V3-hangs-tp22663593p22669651.html
Sent from the Grizzly - Users mailing list archive at Nabble.com.