1 | /* |
2 | * Copyright (c) 2015, 2016, Oracle and/or its affiliates. All rights reserved. |
3 | * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. |
4 | * |
5 | * This code is free software; you can redistribute it and/or modify it |
6 | * under the terms of the GNU General Public License version 2 only, as |
7 | * published by the Free Software Foundation. |
8 | * |
9 | * This code is distributed in the hope that it will be useful, but WITHOUT |
10 | * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or |
11 | * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License |
12 | * version 2 for more details (a copy is included in the LICENSE file that |
13 | * accompanied this code). |
14 | * |
15 | * You should have received a copy of the GNU General Public License version |
16 | * 2 along with this work; if not, write to the Free Software Foundation, |
17 | * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA. |
18 | * |
19 | * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA |
20 | * or visit www.oracle.com if you need additional information or have any |
21 | * questions. |
22 | * |
23 | */ |
24 | #include "precompiled.hpp" |
25 | #include "gc/shared/gcTraceTime.inline.hpp" |
26 | #include "logTestFixture.hpp" |
27 | #include "logTestUtils.inline.hpp" |
28 | #include "logging/log.hpp" |
29 | #include "runtime/interfaceSupport.inline.hpp" |
30 | #include "unittest.hpp" |
31 | |
32 | class GCTraceTimeTest : public LogTestFixture { |
33 | }; |
34 | |
35 | TEST_VM_F(GCTraceTimeTest, full) { |
36 | set_log_config(TestLogFileName, "gc=debug,gc+start=debug" ); |
37 | |
38 | LogTarget(Debug, gc) gc_debug; |
39 | LogTarget(Debug, gc, start) gc_start_debug; |
40 | |
41 | EXPECT_TRUE(gc_debug.is_enabled()); |
42 | EXPECT_TRUE(gc_start_debug.is_enabled()); |
43 | |
44 | { |
45 | ThreadInVMfromNative tvn(JavaThread::current()); |
46 | MutexLocker lock(Heap_lock); // Needed to read heap usage |
47 | GCTraceTime(Debug, gc) timer("Test GC" , NULL, GCCause::_allocation_failure, true); |
48 | } |
49 | |
50 | const char* expected[] = { |
51 | "[gc,start" , "] Test GC (Allocation Failure)" , |
52 | "[gc" , "] Test GC (Allocation Failure) " , "M) " , "ms" , |
53 | NULL |
54 | }; |
55 | EXPECT_TRUE(file_contains_substrings_in_order(TestLogFileName, expected)); |
56 | } |
57 | |
58 | TEST_VM_F(GCTraceTimeTest, full_multitag) { |
59 | set_log_config(TestLogFileName, "gc+ref=debug,gc+ref+start=debug" ); |
60 | |
61 | LogTarget(Debug, gc, ref) gc_debug; |
62 | LogTarget(Debug, gc, ref, start) gc_start_debug; |
63 | |
64 | EXPECT_TRUE(gc_debug.is_enabled()); |
65 | EXPECT_TRUE(gc_start_debug.is_enabled()); |
66 | |
67 | { |
68 | ThreadInVMfromNative tvn(JavaThread::current()); |
69 | MutexLocker lock(Heap_lock); // Needed to read heap usage |
70 | GCTraceTime(Debug, gc, ref) timer("Test GC" , NULL, GCCause::_allocation_failure, true); |
71 | } |
72 | |
73 | const char* expected[] = { |
74 | "[gc,ref,start" , "] Test GC (Allocation Failure)" , |
75 | "[gc,ref" , "] Test GC (Allocation Failure) " , "M) " , "ms" , |
76 | NULL |
77 | }; |
78 | EXPECT_TRUE(file_contains_substrings_in_order(TestLogFileName, expected)); |
79 | } |
80 | |
81 | TEST_VM_F(GCTraceTimeTest, no_heap) { |
82 | set_log_config(TestLogFileName, "gc=debug,gc+start=debug" ); |
83 | |
84 | LogTarget(Debug, gc) gc_debug; |
85 | LogTarget(Debug, gc, start) gc_start_debug; |
86 | |
87 | EXPECT_TRUE(gc_debug.is_enabled()); |
88 | EXPECT_TRUE(gc_start_debug.is_enabled()); |
89 | |
90 | { |
91 | GCTraceTime(Debug, gc) timer("Test GC" , NULL, GCCause::_allocation_failure, false); |
92 | } |
93 | |
94 | const char* expected[] = { |
95 | // [2.975s][debug][gc,start] Test GC (Allocation Failure) |
96 | "[gc,start" , "] Test GC (Allocation Failure)" , |
97 | // [2.975s][debug][gc ] Test GC (Allocation Failure) 0.026ms |
98 | "[gc" , "] Test GC (Allocation Failure) " , "ms" , |
99 | NULL |
100 | }; |
101 | EXPECT_TRUE(file_contains_substrings_in_order(TestLogFileName, expected)); |
102 | |
103 | const char* not_expected[] = { |
104 | // [2.975s][debug][gc ] Test GC 59M->59M(502M) 0.026ms |
105 | "[gc" , "] Test GC " , "M) " , "ms" , |
106 | }; |
107 | EXPECT_FALSE(file_contains_substrings_in_order(TestLogFileName, not_expected)); |
108 | } |
109 | |
110 | TEST_VM_F(GCTraceTimeTest, no_cause) { |
111 | set_log_config(TestLogFileName, "gc=debug,gc+start=debug" ); |
112 | |
113 | LogTarget(Debug, gc) gc_debug; |
114 | LogTarget(Debug, gc, start) gc_start_debug; |
115 | |
116 | EXPECT_TRUE(gc_debug.is_enabled()); |
117 | EXPECT_TRUE(gc_start_debug.is_enabled()); |
118 | |
119 | { |
120 | ThreadInVMfromNative tvn(JavaThread::current()); |
121 | MutexLocker lock(Heap_lock); // Needed to read heap usage |
122 | GCTraceTime(Debug, gc) timer("Test GC" , NULL, GCCause::_no_gc, true); |
123 | } |
124 | |
125 | const char* expected[] = { |
126 | // [2.975s][debug][gc,start] Test GC |
127 | "[gc,start" , "] Test GC" , |
128 | // [2.975s][debug][gc ] Test GC 59M->59M(502M) 0.026ms |
129 | "[gc" , "] Test GC " , "M) " , "ms" , |
130 | NULL |
131 | }; |
132 | EXPECT_TRUE(file_contains_substrings_in_order(TestLogFileName, expected)); |
133 | } |
134 | |
135 | TEST_VM_F(GCTraceTimeTest, no_heap_no_cause) { |
136 | set_log_config(TestLogFileName, "gc=debug,gc+start=debug" ); |
137 | |
138 | LogTarget(Debug, gc) gc_debug; |
139 | LogTarget(Debug, gc, start) gc_start_debug; |
140 | |
141 | EXPECT_TRUE(gc_debug.is_enabled()); |
142 | EXPECT_TRUE(gc_start_debug.is_enabled()); |
143 | |
144 | { |
145 | GCTraceTime(Debug, gc) timer("Test GC" , NULL, GCCause::_no_gc, false); |
146 | } |
147 | |
148 | const char* expected[] = { |
149 | // [2.975s][debug][gc,start] Test GC |
150 | "[gc,start" , "] Test GC" , |
151 | // [2.975s][debug][gc ] Test GC 0.026ms |
152 | "[gc" , "] Test GC " , "ms" , |
153 | NULL |
154 | }; |
155 | EXPECT_TRUE(file_contains_substrings_in_order(TestLogFileName, expected)); |
156 | |
157 | const char* not_expected[] = { |
158 | // [2.975s][debug][gc ] Test GC 59M->59M(502M) 0.026ms |
159 | "[gc" , "] Test GC " , "M) " , "ms" , |
160 | }; |
161 | EXPECT_FALSE(file_contains_substrings_in_order(TestLogFileName, not_expected)); |
162 | } |
163 | |