jasbani
asked on
Date/TimeStamp in Native Logs for GC
Hello Experts,
I have an issue going on where I want to line up an error in the SystemOut.log to the GC output. Actually I am having issues of CPU Starvation.
So I want to line-up CPU Starvation with GC cycles. To do that, I want to know the exact time when cpu starvation happen in systemout.log and the native_stdout.log.
The argument is already passed "-XX:+PrintGCDetails -XX:+PrintGCTimeStamps" under generic jvm
how can I line-up both the output to get the desired results.
OS - SOLARIS 9
{Heap before gc invocations=20576:
PSYoungGen total 173824K, used 173785K [0xe8000000, 0xf3c00000, 0xf8000000)
eden space 169472K, 100% used [0xe8000000,0xf2580000,0xf
from space 4352K, 99% used [0xf2a40000,0xf2e76658,0xf
to space 10816K, 0% used [0xf3170000,0xf3170000,0xf
PSOldGen total 1310720K, used 998583K [0x98000000, 0xe8000000, 0xe8000000)
object space 1310720K, 76% used [0x98000000,0xd4f2dd60,0xe
PSPermGen total 172032K, used 169515K [0x88000000, 0x92800000, 0x98000000)
object space 172032K, 98% used [0x88000000,0x9258ae28,0x9
504427.177: [GC [PSYoungGen: 173785K->10670K(178432K)] 1172368K->1011439K(1489152
Heap after gc invocations=20576:
PSYoungGen total 178432K, used 10670K [0xe8000000, 0xf3c00000, 0xf8000000)
eden space 167616K, 0% used [0xe8000000,0xe8000000,0xf
from space 10816K, 98% used [0xf3170000,0xf3bdbbb8,0xf
to space 12096K, 0% used [0xf2460000,0xf2460000,0xf
PSOldGen total 1310720K, used 1000769K [0x98000000, 0xe8000000, 0xe8000000)
object space 1310720K, 76% used [0x98000000,0xd5150440,0xe
PSPermGen total 172032K, used 169515K [0x88000000, 0x92800000, 0x98000000)
I have an issue going on where I want to line up an error in the SystemOut.log to the GC output. Actually I am having issues of CPU Starvation.
So I want to line-up CPU Starvation with GC cycles. To do that, I want to know the exact time when cpu starvation happen in systemout.log and the native_stdout.log.
The argument is already passed "-XX:+PrintGCDetails -XX:+PrintGCTimeStamps" under generic jvm
how can I line-up both the output to get the desired results.
OS - SOLARIS 9
{Heap before gc invocations=20576:
PSYoungGen total 173824K, used 173785K [0xe8000000, 0xf3c00000, 0xf8000000)
eden space 169472K, 100% used [0xe8000000,0xf2580000,0xf
from space 4352K, 99% used [0xf2a40000,0xf2e76658,0xf
to space 10816K, 0% used [0xf3170000,0xf3170000,0xf
PSOldGen total 1310720K, used 998583K [0x98000000, 0xe8000000, 0xe8000000)
object space 1310720K, 76% used [0x98000000,0xd4f2dd60,0xe
PSPermGen total 172032K, used 169515K [0x88000000, 0x92800000, 0x98000000)
object space 172032K, 98% used [0x88000000,0x9258ae28,0x9
504427.177: [GC [PSYoungGen: 173785K->10670K(178432K)] 1172368K->1011439K(1489152
Heap after gc invocations=20576:
PSYoungGen total 178432K, used 10670K [0xe8000000, 0xf3c00000, 0xf8000000)
eden space 167616K, 0% used [0xe8000000,0xe8000000,0xf
from space 10816K, 98% used [0xf3170000,0xf3bdbbb8,0xf
to space 12096K, 0% used [0xf2460000,0xf2460000,0xf
PSOldGen total 1310720K, used 1000769K [0x98000000, 0xe8000000, 0xe8000000)
object space 1310720K, 76% used [0x98000000,0xd5150440,0xe
PSPermGen total 172032K, used 169515K [0x88000000, 0x92800000, 0x98000000)
Mick Barry
why don'yt you just log them both to the same file?
ASKER
I think I won't be able to do that since I am not able to reproduce the issue at my wish. The CPU Starvation can happens any time during 24 hrs.
how is your current logging handled?
> 504427.177: [GC [PSYoungGen: 1
the first number is the timestamp
some interesting stuff here if you want to visualize the output
http://sujitpal.blogspot.com/2006/08/charting-jvm-garbage-collection.html
the first number is the timestamp
some interesting stuff here if you want to visualize the output
http://sujitpal.blogspot.com/2006/08/charting-jvm-garbage-collection.html
ASKER
Thanks for the above url. It looks good. But I want to compare the logs, if any of you guys know how to get accurate timestamps from the GC on Solaris I would greatly appropriate it.
ASKER
Agreed that first number is a timestamp but it won't give you but I cannot map it with the time stamp under SystemOut.log when the error hits.
theres already a timestamp at the beginjing of each line, see my earlier comment
naturally you will need to convert it :)
Though I still don't understand why you don't just log both to the same log file.
Though I still don't understand why you don't just log both to the same log file.
ASKER
> 504427.177: [GC [PSYoungGen: 1
The above time stamp won't tell you the time what time the GC happened. It is showing the start time of next GC cycle or I would say time stamp when jvm started. How can i Map this time stamp with the SystemOut.log time stamp to see what was happening on GC when I hit CPU Starvation.
The above time stamp won't tell you the time what time the GC happened. It is showing the start time of next GC cycle or I would say time stamp when jvm started. How can i Map this time stamp with the SystemOut.log time stamp to see what was happening on GC when I hit CPU Starvation.
its the timestamp of the log entry, ie the time associated woiht the details it is logging
it would correspond to the timestamp in your app log
it would correspond to the timestamp in your app log
ASKER
can you example,,,how can we relate two different logs without similar type of time stamp...
you have to either write something that converts them, or log both to the same file so you don't need to
ASKER
I think writing logs to the same fine is a better idea, can you tell me how can I write both logs to the same file with example. Thanks for your help
ASKER CERTIFIED SOLUTION
membership
This solution is only available to members.
To access this solution, you must be a member of Experts Exchange.