Menu
▾
▴
Re: [Wrapper-user] -verbose:gc and wrapper log extra new lines
|
From: Christian M. <chr...@ta...> - 2011-05-27 07:25:05
|
Jakob, I was doing some tests on our machines and could reproduce the problem with the extra line feed you are seeing. The line feed was more likely to occur when a system is under heavy load, since the GC log entry is actually done by a System.print and a println so it looks it's one line, but actually 2 prints. On heavy load the time between those 2 prints is increasing and with some bad timing, the wrapper will read and printout stdout in between causing the extra line feed. We will work on fixing this for the next release. I'm very sorry for the inconveniences this might have caused you. Best Regards, Christian On Thu, May 26, 2011 at 5:12 PM, Jakob Ericsson <jak...@gm...> wrote: > Christian, > > It did not help. > > TATUS | wrapper | 2011/05/26 10:07:59 | Java Service Wrapper Standard > Edition 64-bit 3.5.7 > STATUS | wrapper | 2011/05/26 10:07:59 | Copyright (C) 1999-2010 > Tanuki Software, Ltd. All Rights Reserved. > STATUS | wrapper | 2011/05/26 10:07:59 | http://wrapper.tanukisoftware.com > STATUS | wrapper | 2011/05/26 10:07:59 | Licensed to XXXXXXXXXXXXXXXX > NOTICE | wrapper | 2011/05/26 10:07:59 | > NOTICE | wrapper | 2011/05/26 10:07:59 | > -------------------------------------------------------------------- > NOTICE | wrapper | 2011/05/26 10:07:59 | Thank you for your interest > in the Java Service Wrapper. > NOTICE | wrapper | 2011/05/26 10:07:59 | > NOTICE | wrapper | 2011/05/26 10:07:59 | You are running with a full > featured trial License Key which will > NOTICE | wrapper | 2011/05/26 10:07:59 | allow you to run or restart > the Java Service Wrapper as many times > NOTICE | wrapper | 2011/05/26 10:07:59 | as you like until > 2011/06/26. If the Wrapper is running at that > NOTICE | wrapper | 2011/05/26 10:07:59 | point, it will shutdown on > its own after an additional 24 hours. > NOTICE | wrapper | 2011/05/26 10:07:59 | > NOTICE | wrapper | 2011/05/26 10:07:59 | The Java Service Wrapper > requires a License Key to activate the > NOTICE | wrapper | 2011/05/26 10:07:59 | software. License Keys can > be purchased on the Java Service Wrapper > NOTICE | wrapper | 2011/05/26 10:07:59 | web site: > NOTICE | wrapper | 2011/05/26 10:07:59 | > http://wrapper.tanukisoftware.com/purchase > NOTICE | wrapper | 2011/05/26 10:07:59 | > NOTICE | wrapper | 2011/05/26 10:07:59 | This trial License Key in > intended for testing and development and > NOTICE | wrapper | 2011/05/26 10:07:59 | should not be used as part > of a production environment. > NOTICE | wrapper | 2011/05/26 10:07:59 | > -------------------------------------------------------------------- > NOTICE | wrapper | 2011/05/26 10:07:59 | > STATUS | wrapper | 2011/05/26 10:07:59 | > INFO | jvm 1 | 2011/05/26 10:08:15 | [Full GC 176171K->2577K(6134208K), 0.0631505 secs] > INFO | jvm 1 | 2011/05/26 10:08:15 | [GC 2577K(6134208K), 0.0003601 secs] > INFO | jvm 1 | 2011/05/26 10:08:17 | > INFO | jvm 1 | 2011/05/26 10:08:31 | [GC 1260945K->62371K(6134208K), 0.0745148 secs] > INFO | jvm 1 | 2011/05/26 10:08:36 | [GC > INFO | jvm 1 | 2011/05/26 10:08:36 | 637829K(6134208K), 0.3924890 secs] > INFO | jvm 1 | 2011/05/26 10:08:41 | [GC 1320710K->110578K(6134208K), 0.0913535 secs] > INFO | jvm 1 | 2011/05/26 10:08:45 | [GC > INFO | jvm 1 | 2011/05/26 10:08:46 | 720854K(6134208K), 0.5177127 secs] > INFO | jvm 1 | 2011/05/26 10:08:48 | [GC > INFO | jvm 1 | 2011/05/26 10:08:48 | 1368946K->154958K(6134208K), 0.4591796 secs] > INFO | jvm 1 | 2011/05/26 10:08:52 | [GC > INFO | jvm 1 | 2011/05/26 10:08:52 | 761585K(6134208K), 0.3975162 secs] > INFO | jvm 1 | 2011/05/26 10:08:56 | [GC 1413232K->126244K(6134208K), 0.0503159 secs] > INFO | jvm 1 | 2011/05/26 10:08:59 | [GC > INFO | jvm 1 | 2011/05/26 10:08:59 | 733916K(6134208K), 0.4527670 secs] > INFO | jvm 1 | 2011/05/26 10:09:03 | [GC 1384612K->158331K(6134208K), 0.0369100 secs] > INFO | jvm 1 | 2011/05/26 10:09:07 | [GC > INFO | jvm 1 | 2011/05/26 10:09:07 | 757702K(6134208K), 0.4024972 secs] > INFO | jvm 1 | 2011/05/26 10:09:11 | [GC 1416676K->141412K(6134208K), 0.0650510 secs] > INFO | jvm 1 | 2011/05/26 10:09:12 | [GC > INFO | jvm 1 | 2011/05/26 10:09:13 | 763342K(6134208K), 0.2949841 secs] > > > /Jakob > > > On Thu, May 26, 2011 at 9:19 AM, Jakob Ericsson > <jak...@gm...> wrote: >> Hi, >> >> We are running on bundled version in TC-server >> (http://www.springsource.com/products/tcserver), which seems to be >> 3.2.3. In 64-bit mode. >> I will give it a go and test on later version if possible to get it to start. >> >> /Jakob >> >> >> On Thu, May 26, 2011 at 8:40 AM, Christian Mueller >> <chr...@ta...> wrote: >>> Jakob, >>> >>> What version of the Wrapper are you running? >>> >>> What you report sounds familiar, and has been reported in the past. We >>> were working on improving this for the 3.4.0 release: >>> >>> * Fix a problem where Java log output would sometimes get extra line >>> feeds when under heavy load. >>> http://wrapper.tanukisoftware.com/doc/english/release-notes.html#3.4.0 >>> >>> Could you please try version 3.4.0 (or any later) and see if this >>> resolves your problem? >>> >>> Best Regards, >>> Christian >>> >>> On Thu, May 26, 2011 at 3:26 PM, Jakob Ericsson >>> <jak...@gm...> wrote: >>>> Hi, >>>> >>>> We are using the tanuki wrapper together with TCserver/tomcat and want >>>> to have -verbose:gc to the wrapper log. We used to log to specific >>>> file but this was overwritten during every jvm restart. Somewhat >>>> explained in this post, >>>> http://stackoverflow.com/questions/3822097/rolling-garbage-collector-logs-in-java. >>>> >>>> But now we are facing another problem. The wrapper-log is sometimes >>>> adding new lines in the middle of a gc log statement. Is this a flush >>>> issue? >>>> How can I prevent this in the wrapper log? >>>> >>>> INFO | jvm 1 | 2011/05/26 04:49:22 | [GC >>>> 1868705K->610204K(6134208K), 0.0062318 secs] >>>> INFO | jvm 1 | 2011/05/26 04:51:04 | [GC >>>> 1868572K->610487K(6134208K), 0.0055004 secs] >>>> INFO | jvm 1 | 2011/05/26 04:53:03 | [GC >>>> 1868855K->610658K(6134208K), 0.0042818 secs] >>>> INFO | jvm 1 | 2011/05/26 04:54:21 | [GC >>>> 1869026K->610890K(6134208K), 0.0049682 secs] >>>> INFO | jvm 1 | 2011/05/26 04:55:36 | [GC >>>> 1869258K->611066K(6134208K), 0.0054197 secs] >>>> INFO | jvm 1 | 2011/05/26 04:56:45 | [GC >>>> 1869434K->611094K(6134208K), 0.0041137 secs] >>>> INFO | jvm 1 | 2011/05/26 04:57:48 | [GC >>>> INFO | jvm 1 | 2011/05/26 04:57:48 | >>>> 1869462K->611304K(6134208K), 0.0060016 secs] >>>> INFO | jvm 1 | 2011/05/26 04:58:46 | [GC >>>> INFO | jvm 1 | 2011/05/26 04:58:46 | >>>> 1869672K->610972K(6134208K), 0.0053010 secs] >>>> INFO | jvm 1 | 2011/05/26 04:59:59 | [GC >>>> 1869340K->611257K(6134208K), 0.0040952 secs] >>>> INFO | jvm 1 | 2011/05/26 05:01:28 | [GC >>>> 1869625K->612006K(6134208K), 0.0079602 secs] >>>> INFO | jvm 1 | 2011/05/26 05:03:00 | [GC >>>> 1870374K->612103K(6134208K), 0.0053934 secs] >>>> >>>> >>>> If logging to a specific file, result looks like this. No new lines! >>>> >>>> 0.853: [GC 2405K(6134208K), 0.0003878 secs] >>>> 16.915: [GC 1260773K->62176K(6134208K), 0.0711920 secs] >>>> 21.357: [GC 637590K(6134208K), 0.4003372 secs] >>>> 26.548: [GC 1320507K->110141K(6134208K), 0.0879849 secs] >>>> 30.754: [GC 722976K(6134208K), 0.5191931 secs] >>>> 33.719: [GC 1368509K->137204K(6134208K), 0.2726067 secs] >>>> >>>> >>>> We are running Windows 2008 server R2. >>>> >>>> Regards, >>>> Jakob >>>> >>>> ------------------------------------------------------------------------------ >>>> vRanger cuts backup time in half-while increasing security. >>>> With the market-leading solution for virtual backup and recovery, >>>> you get blazing-fast, flexible, and affordable data protection. >>>> Download your free trial now. >>>> http://p.sf.net/sfu/quest-d2dcopy1 >>>> _______________________________________________ >>>> Wrapper-user mailing list >>>> Wra...@li... >>>> https://lists.sourceforge.net/lists/listinfo/wrapper-user >>>> >>> >>> ------------------------------------------------------------------------------ >>> vRanger cuts backup time in half-while increasing security. >>> With the market-leading solution for virtual backup and recovery, >>> you get blazing-fast, flexible, and affordable data protection. >>> Download your free trial now. >>> http://p.sf.net/sfu/quest-d2dcopy1 >>> _______________________________________________ >>> Wrapper-user mailing list >>> Wra...@li... >>> https://lists.sourceforge.net/lists/listinfo/wrapper-user >>> >> >> >> >> -- >> Jakob Ericsson, JAKERI AB >> http://www.jakeri.net/ >> -- >> > > > > -- > Jakob Ericsson, JAKERI AB > http://www.jakeri.net/ > -- > > ------------------------------------------------------------------------------ > vRanger cuts backup time in half-while increasing security. > With the market-leading solution for virtual backup and recovery, > you get blazing-fast, flexible, and affordable data protection. > Download your free trial now. > http://p.sf.net/sfu/quest-d2dcopy1 > _______________________________________________ > Wrapper-user mailing list > Wra...@li... > https://lists.sourceforge.net/lists/listinfo/wrapper-user > |
