This problem started day after installing Patch for 8.5 -> 8.5.1_GA_3056. Installation was done acording to the manual
OpenJDK 64-Bit Server VM (25.40-b01) for linux-amd64 JRE (1.8.0-internal-build_2014_07_29_16_56-b00), built on Jul 29 2014 17:01:58 by "build" with gcc 4.4.3
Memory: 4k page, physical 8061084k(1924228k free), swap 2099192k(2003828k free)
CommandLine flags: -XX:GCLogFileSize=4194304 -XX:InitialHeapSize=2092957696 -XX:MaxHeapSize=2092957696 -XX:MaxNewSize=523239424 -XX:MaxTenuringThreshold=6 -XX:NewSize=523239424 -XX:NumberOfGCLogFil
es=20 -XX:OldPLABSize=16 -XX:-OmitStackTraceInFastThrow -XX:+PrintGC -XX:+PrintGCApplicationStoppedTime -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:SoftRefLRUPolicyMSPerMB
=1 -XX:ThreadStackSize=256 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:-UseGCLogFileRotation -XX:+UseParNewGC
2014-11-13T08:10:56.330+0100: 1,137: Total time for which application threads were stopped: 0,0003162 seconds
...
2014-11-13T08:11:05.215+0100: 10,022: [GC (Allocation Failure) 10,028: [ParNew: 408832K->8227K(459904K), 0,0280990 secs] 408832K->8227K(1992832K), 0,0340511 secs] [Times: user=0,07 sys=0,02, real=0
,04 secs]
...
2014-11-13T08:11:05.255+0100: 10,062: Total time for which application threads were stopped: 0,0004473 seconds
gc.log full of errors
gc.log full of errors
The "GC (Allocation Failure)" is not directly an error but means that the GC (Garbage Collector) was started due to limited memory. If it happens too often it might be a bug/memory leak though.
-
MichalSapsa
- Posts: 9
- Joined: Tue Nov 18, 2014 6:52 am
gc.log full of errors
It's been 2 day straight that gc.log is populating.
2014-11-19T14:55:33.048+0100: 85428,400: Total time for which application threads were stopped: 0,0011318 seconds
2014-11-19T14:55:33.080+0100: 85428,432: Total time for which application threads were stopped: 0,0011014 seconds
2014-11-19T14:55:33.348+0100: 85428,700: Total time for which application threads were stopped: 0,0010291 seconds
2014-11-19T14:55:34.892+0100: 85430,244: Total time for which application threads were stopped: 0,0010044 seconds
2014-11-19T14:55:37.719+0100: 85433,071: Total time for which application threads were stopped: 0,0010769 seconds
2014-11-19T14:55:39.736+0100: 85435,089: Total time for which application threads were stopped: 0,0010018 seconds
2014-11-19T14:55:39.841+0100: 85435,194: Total time for which application threads were stopped: 0,0010056 seconds
2014-11-19T14:55:40.675+0100: 85436,027: Total time for which application threads were stopped: 0,0010418 seconds
2014-11-19T14:55:40.879+0100: 85436,231: Total time for which application threads were stopped: 0,0011297 seconds
2014-11-19T14:55:46.100+0100: 85441,453: Total time for which application threads were stopped: 0,0010808 seconds
2014-11-19T14:55:50.927+0100: 85446,280: Total time for which application threads were stopped: 0,0022286 seconds
2014-11-19T14:55:51.370+0100: 85446,722: Total time for which application threads were stopped: 0,0009977 seconds
2014-11-19T14:55:53.245+0100: 85448,597: Total time for which application threads were stopped: 0,0010342 seconds
Server is 8GB Ram:
free
total used free shared buffers cached
Mem: 8061084 7710056 351028 352 278548 3843140
-/+ buffers/cache: 3588368 4472716
Swap: 2099192 30096 2069096
2014-11-19T14:55:33.048+0100: 85428,400: Total time for which application threads were stopped: 0,0011318 seconds
2014-11-19T14:55:33.080+0100: 85428,432: Total time for which application threads were stopped: 0,0011014 seconds
2014-11-19T14:55:33.348+0100: 85428,700: Total time for which application threads were stopped: 0,0010291 seconds
2014-11-19T14:55:34.892+0100: 85430,244: Total time for which application threads were stopped: 0,0010044 seconds
2014-11-19T14:55:37.719+0100: 85433,071: Total time for which application threads were stopped: 0,0010769 seconds
2014-11-19T14:55:39.736+0100: 85435,089: Total time for which application threads were stopped: 0,0010018 seconds
2014-11-19T14:55:39.841+0100: 85435,194: Total time for which application threads were stopped: 0,0010056 seconds
2014-11-19T14:55:40.675+0100: 85436,027: Total time for which application threads were stopped: 0,0010418 seconds
2014-11-19T14:55:40.879+0100: 85436,231: Total time for which application threads were stopped: 0,0011297 seconds
2014-11-19T14:55:46.100+0100: 85441,453: Total time for which application threads were stopped: 0,0010808 seconds
2014-11-19T14:55:50.927+0100: 85446,280: Total time for which application threads were stopped: 0,0022286 seconds
2014-11-19T14:55:51.370+0100: 85446,722: Total time for which application threads were stopped: 0,0009977 seconds
2014-11-19T14:55:53.245+0100: 85448,597: Total time for which application threads were stopped: 0,0010342 seconds
Server is 8GB Ram:
free
total used free shared buffers cached
Mem: 8061084 7710056 351028 352 278548 3843140
-/+ buffers/cache: 3588368 4472716
Swap: 2099192 30096 2069096
gc.log full of errors
Those aren't errors either but just infos. You found them in zmmailboxd.out in 8.0 and they went into its own logile in 8.5.
gc.log full of errors
What you are looking for is the output of
fgrep ': [GC' /opt/zimbra/log/gc.log
From a quick glance I can see a lot of "GC (Allocation Failure)" on a completely idle 8.5.0 installation as well.
fgrep ': [GC' /opt/zimbra/log/gc.log
From a quick glance I can see a lot of "GC (Allocation Failure)" on a completely idle 8.5.0 installation as well.
-
tbachman1688
- Posts: 5
- Joined: Mon Dec 08, 2014 1:10 pm
gc.log full of errors
I'm getting a ton of these as well. Running Ubuntu 14.04LTS with a fresh install of Zimbra 8.5.1_GA_3056 (build 20141103151510).
2014-12-08T11:36:08.463-0800: 14116.561: [GC (Allocation Failure) 14116.561: [ParNew: 391292K->12364K(430400K), 0.0129636 secs] 548069K->169818K(1865024K), 0.0131892 secs] [Times: user=0.08 sys=0.00, real=0.01 secs]
2014-12-08T11:37:09.887-0800: 14177.985: [GC (Allocation Failure) 14177.985: [ParNew: 394956K->10764K(430400K), 0.0129140 secs] 552410K->168465K(1865024K), 0.0130923 secs] [Times: user=0.08 sys=0.00, real=0.01 secs]
2014-12-08T11:39:04.377-0800: 14292.475: [GC (Allocation Failure) 14292.475: [ParNew: 393356K->9019K(430400K), 0.0150303 secs] 551057K->166972K(1865024K), 0.0152968 secs] [Times: user=0.07 sys=0.00, real=0.02 secs]
2014-12-08T11:39:59.370-0800: 14347.468: [GC (Allocation Failure) 14347.468: [ParNew: 391611K->10912K(430400K), 0.0155968 secs] 549564K->169711K(1865024K), 0.0158374 secs] [Times: user=0.07 sys=0.00, real=0.02 secs]
2014-12-08T11:41:33.832-0800: 14441.930: [GC (Allocation Failure) 14441.930: [ParNew: 393504K->8239K(430400K), 0.0120666 secs] 552303K->167688K(1865024K), 0.0122822 secs] [Times: user=0.08 sys=0.00, real=0.01 secs]
2014-12-08T11:42:37.908-0800: 14506.006: [GC (Allocation Failure) 14506.006: [ParNew: 390831K->10041K(430400K), 0.0117085 secs] 550280K->169750K(1865024K), 0.0119294 secs] [Times: user=0.07 sys=0.00, real=0.01 secs]
2014-12-08T11:43:55.307-0800: 14583.404: [GC (Allocation Failure) 14583.405: [ParNew: 392633K->8991K(430400K), 0.0148788 secs] 552342K->171125K(1865024K), 0.0150878 secs] [Times: user=0.09 sys=0.00, real=0.01 secs]
2014-12-08T11:45:24.886-0800: 14672.983: [GC (Allocation Failure) 14672.984: [ParNew: 391583K->6489K(430400K), 0.0146456 secs] 553717K->168790K(1865024K), 0.0148221 secs] [Times: user=0.08 sys=0.00, real=0.02 secs]
2014-12-08T11:46:28.348-0800: 14736.446: [GC (Allocation Failure) 14736.446: [ParNew: 389081K->7238K(430400K), 0.0099955 secs] 551382K->169796K(1865024K), 0.0102216 secs] [Times: user=0.06 sys=0.00, real=0.00 secs]
2014-12-08T11:47:07.524-0800: 14775.622: [GC (Allocation Failure) 14775.622: [ParNew: 389830K->6616K(430400K), 0.0101961 secs] 552388K->169462K(1865024K), 0.0104110 secs] [Times: user=0.07 sys=0.00, real=0.01 secs]
2014-12-08T11:49:15.161-0800: 14903.258: [GC (Allocation Failure) 14903.258: [ParNew: 389208K->8305K(430400K), 0.0129054 secs] 552054K->171584K(1865024K), 0.0130942 secs] [Times: user=0.07 sys=0.00, real=0.01 secs]
2014-12-08T11:50:14.737-0800: 14962.835: [GC (Allocation Failure) 14962.835: [ParNew: 390897K->8034K(430400K), 0.0112726 secs] 554176K->171952K(1865024K), 0.0115130 secs] [Times: user=0.07 sys=0.00, real=0.02 secs]
2014-12-08T11:52:48.091-0800: 15116.189: [GC (Allocation Failure) 15116.189: [ParNew: 390626K->7913K(430400K), 0.0141620 secs] 554544K->172148K(1865024K), 0.0143481 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
2014-12-08T11:53:50.185-0800: 15178.282: [GC (Allocation Failure) 15178.283: [ParNew: 390505K->9083K(430400K), 0.0161002 secs] 554740K->173771K(1865024K), 0.0163212 secs] [Times: user=0.08 sys=0.00, real=0.02 secs]
2014-12-08T11:55:05.835-0800: 15253.933: [GC (Allocation Failure) 15253.933: [ParNew: 391675K->9528K(430400K), 0.0114845 secs] 556363K->174541K(1865024K), 0.0116626 secs] [Times: user=0.07 sys=0.00, real=0.02 secs]
2014-12-08T11:56:41.330-0800: 15349.428: [GC (Allocation Failure) 15349.428: [ParNew: 392120K->7679K(430400K), 0.0122348 secs] 557133K->172716K(1865024K), 0.0124142 secs] [Times: user=0.05 sys=0.00, real=0.01 secs]
2014-12-08T11:59:03.027-0800: 15491.125: [GC (Allocation Failure) 15491.125: [ParNew: 390271K->9501K(430400K), 0.0141344 secs] 555308K->175842K(1865024K), 0.0143147 secs] [Times: user=0.08 sys=0.01, real=0.01 secs]
2014-12-08T12:00:28.227-0800: 15576.324: [GC (Allocation Failure) 15576.324: [ParNew: 392093K->8782K(430400K), 0.0109129 secs] 558434K->175354K(1865024K), 0.0110985 secs] [Times: user=0.07 sys=0.00, real=0.00 secs]
2014-12-08T12:02:55.913-0800: 15724.011: [GC (Allocation Failure) 15724.011: [ParNew: 391374K->9147K(430400K), 0.0188724 secs] 557946K->176165K(1865024K), 0.0191077 secs] [Times: user=0.09 sys=0.00, real=0.02 secs]
2014-12-08T12:04:22.315-0800: 15810.413: [GC (Allocation Failure) 15810.413: [ParNew: 391739K->10352K(430400K), 0.0132631 secs] 558757K->178077K(1865024K), 0.0134479 secs] [Times: user=0.07 sys=0.01, real=0.02 secs]
2014-12-08T12:07:00.028-0800: 15968.126: [GC (Allocation Failure) 15968.126: [ParNew: 392944K->9057K(430400K), 0.0119502 secs] 560669K->176820K(1865024K), 0.0121271 secs] [Times: user=0.08 sys=0.00, real=0.01 secs]
2014-12-08T12:08:41.577-0800: 16069.675: [GC (Allocation Failure) 16069.675: [ParNew: 391649K->11013K(430400K), 0.0137983 secs] 559412K->179056K(1865024K), 0.0140296 secs] [Times: user=0.09 sys=0.00, real=0.02 secs]
2014-12-08T12:09:43.479-0800: 16131.577: [GC (Allocation Failure) 16131.577: [ParNew: 393605K->9868K(430400K), 0.0123124 secs] 561648K->178457K(1865024K), 0.0125647 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
Any ideas?
2014-12-08T11:36:08.463-0800: 14116.561: [GC (Allocation Failure) 14116.561: [ParNew: 391292K->12364K(430400K), 0.0129636 secs] 548069K->169818K(1865024K), 0.0131892 secs] [Times: user=0.08 sys=0.00, real=0.01 secs]
2014-12-08T11:37:09.887-0800: 14177.985: [GC (Allocation Failure) 14177.985: [ParNew: 394956K->10764K(430400K), 0.0129140 secs] 552410K->168465K(1865024K), 0.0130923 secs] [Times: user=0.08 sys=0.00, real=0.01 secs]
2014-12-08T11:39:04.377-0800: 14292.475: [GC (Allocation Failure) 14292.475: [ParNew: 393356K->9019K(430400K), 0.0150303 secs] 551057K->166972K(1865024K), 0.0152968 secs] [Times: user=0.07 sys=0.00, real=0.02 secs]
2014-12-08T11:39:59.370-0800: 14347.468: [GC (Allocation Failure) 14347.468: [ParNew: 391611K->10912K(430400K), 0.0155968 secs] 549564K->169711K(1865024K), 0.0158374 secs] [Times: user=0.07 sys=0.00, real=0.02 secs]
2014-12-08T11:41:33.832-0800: 14441.930: [GC (Allocation Failure) 14441.930: [ParNew: 393504K->8239K(430400K), 0.0120666 secs] 552303K->167688K(1865024K), 0.0122822 secs] [Times: user=0.08 sys=0.00, real=0.01 secs]
2014-12-08T11:42:37.908-0800: 14506.006: [GC (Allocation Failure) 14506.006: [ParNew: 390831K->10041K(430400K), 0.0117085 secs] 550280K->169750K(1865024K), 0.0119294 secs] [Times: user=0.07 sys=0.00, real=0.01 secs]
2014-12-08T11:43:55.307-0800: 14583.404: [GC (Allocation Failure) 14583.405: [ParNew: 392633K->8991K(430400K), 0.0148788 secs] 552342K->171125K(1865024K), 0.0150878 secs] [Times: user=0.09 sys=0.00, real=0.01 secs]
2014-12-08T11:45:24.886-0800: 14672.983: [GC (Allocation Failure) 14672.984: [ParNew: 391583K->6489K(430400K), 0.0146456 secs] 553717K->168790K(1865024K), 0.0148221 secs] [Times: user=0.08 sys=0.00, real=0.02 secs]
2014-12-08T11:46:28.348-0800: 14736.446: [GC (Allocation Failure) 14736.446: [ParNew: 389081K->7238K(430400K), 0.0099955 secs] 551382K->169796K(1865024K), 0.0102216 secs] [Times: user=0.06 sys=0.00, real=0.00 secs]
2014-12-08T11:47:07.524-0800: 14775.622: [GC (Allocation Failure) 14775.622: [ParNew: 389830K->6616K(430400K), 0.0101961 secs] 552388K->169462K(1865024K), 0.0104110 secs] [Times: user=0.07 sys=0.00, real=0.01 secs]
2014-12-08T11:49:15.161-0800: 14903.258: [GC (Allocation Failure) 14903.258: [ParNew: 389208K->8305K(430400K), 0.0129054 secs] 552054K->171584K(1865024K), 0.0130942 secs] [Times: user=0.07 sys=0.00, real=0.01 secs]
2014-12-08T11:50:14.737-0800: 14962.835: [GC (Allocation Failure) 14962.835: [ParNew: 390897K->8034K(430400K), 0.0112726 secs] 554176K->171952K(1865024K), 0.0115130 secs] [Times: user=0.07 sys=0.00, real=0.02 secs]
2014-12-08T11:52:48.091-0800: 15116.189: [GC (Allocation Failure) 15116.189: [ParNew: 390626K->7913K(430400K), 0.0141620 secs] 554544K->172148K(1865024K), 0.0143481 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
2014-12-08T11:53:50.185-0800: 15178.282: [GC (Allocation Failure) 15178.283: [ParNew: 390505K->9083K(430400K), 0.0161002 secs] 554740K->173771K(1865024K), 0.0163212 secs] [Times: user=0.08 sys=0.00, real=0.02 secs]
2014-12-08T11:55:05.835-0800: 15253.933: [GC (Allocation Failure) 15253.933: [ParNew: 391675K->9528K(430400K), 0.0114845 secs] 556363K->174541K(1865024K), 0.0116626 secs] [Times: user=0.07 sys=0.00, real=0.02 secs]
2014-12-08T11:56:41.330-0800: 15349.428: [GC (Allocation Failure) 15349.428: [ParNew: 392120K->7679K(430400K), 0.0122348 secs] 557133K->172716K(1865024K), 0.0124142 secs] [Times: user=0.05 sys=0.00, real=0.01 secs]
2014-12-08T11:59:03.027-0800: 15491.125: [GC (Allocation Failure) 15491.125: [ParNew: 390271K->9501K(430400K), 0.0141344 secs] 555308K->175842K(1865024K), 0.0143147 secs] [Times: user=0.08 sys=0.01, real=0.01 secs]
2014-12-08T12:00:28.227-0800: 15576.324: [GC (Allocation Failure) 15576.324: [ParNew: 392093K->8782K(430400K), 0.0109129 secs] 558434K->175354K(1865024K), 0.0110985 secs] [Times: user=0.07 sys=0.00, real=0.00 secs]
2014-12-08T12:02:55.913-0800: 15724.011: [GC (Allocation Failure) 15724.011: [ParNew: 391374K->9147K(430400K), 0.0188724 secs] 557946K->176165K(1865024K), 0.0191077 secs] [Times: user=0.09 sys=0.00, real=0.02 secs]
2014-12-08T12:04:22.315-0800: 15810.413: [GC (Allocation Failure) 15810.413: [ParNew: 391739K->10352K(430400K), 0.0132631 secs] 558757K->178077K(1865024K), 0.0134479 secs] [Times: user=0.07 sys=0.01, real=0.02 secs]
2014-12-08T12:07:00.028-0800: 15968.126: [GC (Allocation Failure) 15968.126: [ParNew: 392944K->9057K(430400K), 0.0119502 secs] 560669K->176820K(1865024K), 0.0121271 secs] [Times: user=0.08 sys=0.00, real=0.01 secs]
2014-12-08T12:08:41.577-0800: 16069.675: [GC (Allocation Failure) 16069.675: [ParNew: 391649K->11013K(430400K), 0.0137983 secs] 559412K->179056K(1865024K), 0.0140296 secs] [Times: user=0.09 sys=0.00, real=0.02 secs]
2014-12-08T12:09:43.479-0800: 16131.577: [GC (Allocation Failure) 16131.577: [ParNew: 393605K->9868K(430400K), 0.0123124 secs] 561648K->178457K(1865024K), 0.0125647 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
Any ideas?