1 package org.apache.maven.plugin.surefire.booterclient.output;
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22 import org.apache.maven.plugin.surefire.booterclient.lazytestprovider.NotifiableTestStream;
23 import org.apache.maven.plugin.surefire.log.api.ConsoleLogger;
24 import org.apache.maven.plugin.surefire.report.DefaultReporterFactory;
25 import org.apache.maven.shared.utils.cli.StreamConsumer;
26 import org.apache.maven.surefire.report.ConsoleOutputReceiver;
27 import org.apache.maven.surefire.report.ReportEntry;
28 import org.apache.maven.surefire.report.RunListener;
29 import org.apache.maven.surefire.report.StackTraceWriter;
30 import org.apache.maven.surefire.report.TestSetReportEntry;
31
32 import java.io.BufferedReader;
33 import java.io.File;
34 import java.io.IOException;
35 import java.io.StringReader;
36 import java.nio.ByteBuffer;
37 import java.util.Collections;
38 import java.util.Map;
39 import java.util.Queue;
40 import java.util.Set;
41 import java.util.StringTokenizer;
42 import java.util.TreeSet;
43 import java.util.concurrent.ConcurrentHashMap;
44 import java.util.concurrent.ConcurrentLinkedQueue;
45 import java.util.concurrent.atomic.AtomicBoolean;
46 import java.util.concurrent.atomic.AtomicLong;
47
48 import static java.lang.Integer.decode;
49 import static java.lang.System.currentTimeMillis;
50 import static java.util.Collections.unmodifiableMap;
51 import static org.apache.maven.surefire.booter.ForkingRunListener.BOOTERCODE_BYE;
52 import static org.apache.maven.surefire.booter.ForkingRunListener.BOOTERCODE_CONSOLE;
53 import static org.apache.maven.surefire.booter.ForkingRunListener.BOOTERCODE_DEBUG;
54 import static org.apache.maven.surefire.booter.ForkingRunListener.BOOTERCODE_ERROR;
55 import static org.apache.maven.surefire.booter.ForkingRunListener.BOOTERCODE_NEXT_TEST;
56 import static org.apache.maven.surefire.booter.ForkingRunListener.BOOTERCODE_STDERR;
57 import static org.apache.maven.surefire.booter.ForkingRunListener.BOOTERCODE_STDOUT;
58 import static org.apache.maven.surefire.booter.ForkingRunListener.BOOTERCODE_STOP_ON_NEXT_TEST;
59 import static org.apache.maven.surefire.booter.ForkingRunListener.BOOTERCODE_SYSPROPS;
60 import static org.apache.maven.surefire.booter.ForkingRunListener.BOOTERCODE_TESTSET_COMPLETED;
61 import static org.apache.maven.surefire.booter.ForkingRunListener.BOOTERCODE_TESTSET_STARTING;
62 import static org.apache.maven.surefire.booter.ForkingRunListener.BOOTERCODE_TEST_ASSUMPTIONFAILURE;
63 import static org.apache.maven.surefire.booter.ForkingRunListener.BOOTERCODE_TEST_ERROR;
64 import static org.apache.maven.surefire.booter.ForkingRunListener.BOOTERCODE_TEST_FAILED;
65 import static org.apache.maven.surefire.booter.ForkingRunListener.BOOTERCODE_TEST_SKIPPED;
66 import static org.apache.maven.surefire.booter.ForkingRunListener.BOOTERCODE_TEST_STARTING;
67 import static org.apache.maven.surefire.booter.ForkingRunListener.BOOTERCODE_TEST_SUCCEEDED;
68 import static org.apache.maven.surefire.booter.ForkingRunListener.BOOTERCODE_WARNING;
69 import static org.apache.maven.surefire.booter.Shutdown.KILL;
70 import static org.apache.maven.surefire.report.CategorizedReportEntry.reportEntry;
71 import static org.apache.maven.surefire.util.internal.StringUtils.isNotBlank;
72 import static org.apache.maven.surefire.util.internal.StringUtils.unescapeBytes;
73 import static org.apache.maven.surefire.util.internal.StringUtils.unescapeString;
74
75
76
77
78
79
80
81
82 public class ForkClient
83 implements StreamConsumer
84 {
85 private static final String PRINTABLE_JVM_NATIVE_STREAM = "Listening for transport dt_socket at address:";
86 private static final long START_TIME_ZERO = 0L;
87 private static final long START_TIME_NEGATIVE_TIMEOUT = -1L;
88
89 private final DefaultReporterFactory defaultReporterFactory;
90
91 private final Map<String, String> testVmSystemProperties = new ConcurrentHashMap<>();
92
93 private final NotifiableTestStream notifiableTestStream;
94
95 private final Queue<String> testsInProgress = new ConcurrentLinkedQueue<>();
96
97
98
99
100
101 private final AtomicLong testSetStartedAt = new AtomicLong( START_TIME_ZERO );
102
103 private final ConsoleLogger log;
104
105
106
107
108 private final AtomicBoolean printedErrorStream;
109
110 private final int forkNumber;
111
112
113
114
115 private RunListener testSetReporter;
116
117
118
119
120 private volatile boolean saidGoodBye;
121
122 private volatile StackTraceWriter errorInFork;
123
124 public ForkClient( DefaultReporterFactory defaultReporterFactory, NotifiableTestStream notifiableTestStream,
125 ConsoleLogger log, AtomicBoolean printedErrorStream, int forkNumber )
126 {
127 this.defaultReporterFactory = defaultReporterFactory;
128 this.notifiableTestStream = notifiableTestStream;
129 this.log = log;
130 this.printedErrorStream = printedErrorStream;
131 this.forkNumber = forkNumber;
132 }
133
134 protected void stopOnNextTest()
135 {
136 }
137
138 public void kill()
139 {
140 if ( !saidGoodBye )
141 {
142 notifiableTestStream.shutdown( KILL );
143 }
144 }
145
146
147
148
149
150
151
152
153 public final void tryToTimeout( long currentTimeMillis, int forkedProcessTimeoutInSeconds )
154 {
155 if ( forkedProcessTimeoutInSeconds > 0 )
156 {
157 final long forkedProcessTimeoutInMillis = 1000 * forkedProcessTimeoutInSeconds;
158 final long startedAt = testSetStartedAt.get();
159 if ( startedAt > START_TIME_ZERO && currentTimeMillis - startedAt >= forkedProcessTimeoutInMillis )
160 {
161 testSetStartedAt.set( START_TIME_NEGATIVE_TIMEOUT );
162 notifiableTestStream.shutdown( KILL );
163 }
164 }
165 }
166
167 public final DefaultReporterFactory getDefaultReporterFactory()
168 {
169 return defaultReporterFactory;
170 }
171
172 @Override
173 public final void consumeLine( String s )
174 {
175 if ( isNotBlank( s ) )
176 {
177 processLine( s );
178 }
179 }
180
181 private void setCurrentStartTime()
182 {
183 if ( testSetStartedAt.get() == START_TIME_ZERO )
184 {
185
186
187 testSetStartedAt.compareAndSet( START_TIME_ZERO, currentTimeMillis() );
188 }
189 }
190
191 public final boolean hadTimeout()
192 {
193 return testSetStartedAt.get() == START_TIME_NEGATIVE_TIMEOUT;
194 }
195
196 private RunListener getTestSetReporter()
197 {
198 if ( testSetReporter == null )
199 {
200 testSetReporter = defaultReporterFactory.createReporter();
201 }
202 return testSetReporter;
203 }
204
205 private void processLine( String event )
206 {
207 final OperationalData op;
208 try
209 {
210 op = new OperationalData( event );
211 }
212 catch ( RuntimeException e )
213 {
214 logStreamWarning( e, event );
215 return;
216 }
217 final String remaining = op.getData();
218 switch ( op.getOperationId() )
219 {
220 case BOOTERCODE_TESTSET_STARTING:
221 getTestSetReporter().testSetStarting( createReportEntry( remaining ) );
222 setCurrentStartTime();
223 break;
224 case BOOTERCODE_TESTSET_COMPLETED:
225 testsInProgress.clear();
226
227 getTestSetReporter().testSetCompleted( createReportEntry( remaining, testVmSystemProperties ) );
228 break;
229 case BOOTERCODE_TEST_STARTING:
230 ReportEntry reportEntry = createReportEntry( remaining );
231 testsInProgress.offer( reportEntry.getSourceName() );
232
233 getTestSetReporter().testStarting( createReportEntry( remaining ) );
234 break;
235 case BOOTERCODE_TEST_SUCCEEDED:
236 reportEntry = createReportEntry( remaining );
237 testsInProgress.remove( reportEntry.getSourceName() );
238
239 getTestSetReporter().testSucceeded( createReportEntry( remaining ) );
240 break;
241 case BOOTERCODE_TEST_FAILED:
242 reportEntry = createReportEntry( remaining );
243 testsInProgress.remove( reportEntry.getSourceName() );
244
245 getTestSetReporter().testFailed( createReportEntry( remaining ) );
246 break;
247 case BOOTERCODE_TEST_SKIPPED:
248 reportEntry = createReportEntry( remaining );
249 testsInProgress.remove( reportEntry.getSourceName() );
250
251 getTestSetReporter().testSkipped( createReportEntry( remaining ) );
252 break;
253 case BOOTERCODE_TEST_ERROR:
254 reportEntry = createReportEntry( remaining );
255 testsInProgress.remove( reportEntry.getSourceName() );
256
257 getTestSetReporter().testError( createReportEntry( remaining ) );
258 break;
259 case BOOTERCODE_TEST_ASSUMPTIONFAILURE:
260 reportEntry = createReportEntry( remaining );
261 testsInProgress.remove( reportEntry.getSourceName() );
262
263 getTestSetReporter().testAssumptionFailure( createReportEntry( remaining ) );
264 break;
265 case BOOTERCODE_SYSPROPS:
266 int keyEnd = remaining.indexOf( "," );
267 StringBuilder key = new StringBuilder();
268 StringBuilder value = new StringBuilder();
269 unescapeString( key, remaining.substring( 0, keyEnd ) );
270 unescapeString( value, remaining.substring( keyEnd + 1 ) );
271 testVmSystemProperties.put( key.toString(), value.toString() );
272 break;
273 case BOOTERCODE_STDOUT:
274 writeTestOutput( remaining, true );
275 break;
276 case BOOTERCODE_STDERR:
277 writeTestOutput( remaining, false );
278 break;
279 case BOOTERCODE_CONSOLE:
280 getOrCreateConsoleLogger()
281 .info( createConsoleMessage( remaining ) );
282 break;
283 case BOOTERCODE_NEXT_TEST:
284 notifiableTestStream.provideNewTest();
285 break;
286 case BOOTERCODE_ERROR:
287 errorInFork = deserializeStackTraceWriter( new StringTokenizer( remaining, "," ) );
288 break;
289 case BOOTERCODE_BYE:
290 saidGoodBye = true;
291 notifiableTestStream.acknowledgeByeEventReceived();
292 break;
293 case BOOTERCODE_STOP_ON_NEXT_TEST:
294 stopOnNextTest();
295 break;
296 case BOOTERCODE_DEBUG:
297 getOrCreateConsoleLogger()
298 .debug( createConsoleMessage( remaining ) );
299 break;
300 case BOOTERCODE_WARNING:
301 getOrCreateConsoleLogger()
302 .warning( createConsoleMessage( remaining ) );
303 break;
304 default:
305 logStreamWarning( event );
306 }
307 }
308
309 private void logStreamWarning( String event )
310 {
311 logStreamWarning( null, event );
312 }
313
314 private void logStreamWarning( Throwable e, String event )
315 {
316 if ( event == null || !event.contains( PRINTABLE_JVM_NATIVE_STREAM ) )
317 {
318 String msg = "Corrupted STDOUT by directly writing to native stream in forked JVM " + forkNumber + ".";
319
320 InPluginProcessDumpSingleton util = InPluginProcessDumpSingleton.getSingleton();
321 File reportsDir = defaultReporterFactory.getReportsDirectory();
322 File dump =
323 e == null
324 ? util.dumpStreamText( msg + " Stream '" + event + "'.", reportsDir, forkNumber )
325 : util.dumpStreamException( e, msg + " Stream '" + event + "'.", reportsDir, forkNumber );
326
327 if ( printedErrorStream.compareAndSet( false, true ) )
328 {
329 log.warning( msg + " See FAQ web page and the dump file " + dump.getAbsolutePath() );
330 }
331
332 if ( log.isDebugEnabled() && event != null )
333 {
334 log.debug( event );
335 }
336 }
337 else
338 {
339 if ( log.isDebugEnabled() )
340 {
341 log.debug( event );
342 }
343 else if ( log.isInfoEnabled() )
344 {
345 log.info( event );
346 }
347 else
348 {
349
350 System.out.println( event );
351 }
352 }
353 }
354
355 private void writeTestOutput( String remaining, boolean isStdout )
356 {
357 int csNameEnd = remaining.indexOf( ',' );
358 String charsetName = remaining.substring( 0, csNameEnd );
359 String byteEncoded = remaining.substring( csNameEnd + 1 );
360 ByteBuffer unescaped = unescapeBytes( byteEncoded, charsetName );
361
362 if ( unescaped.hasArray() )
363 {
364 byte[] convertedBytes = unescaped.array();
365 getOrCreateConsoleOutputReceiver()
366 .writeTestOutput( convertedBytes, unescaped.position(), unescaped.remaining(), isStdout );
367 }
368 else
369 {
370 byte[] convertedBytes = new byte[unescaped.remaining()];
371 unescaped.get( convertedBytes, 0, unescaped.remaining() );
372 getOrCreateConsoleOutputReceiver()
373 .writeTestOutput( convertedBytes, 0, convertedBytes.length, isStdout );
374 }
375 }
376
377 public final void consumeMultiLineContent( String s )
378 throws IOException
379 {
380 BufferedReader stringReader = new BufferedReader( new StringReader( s ) );
381 for ( String s1 = stringReader.readLine(); s1 != null; s1 = stringReader.readLine() )
382 {
383 consumeLine( s1 );
384 }
385 }
386
387 private String createConsoleMessage( String remaining )
388 {
389 return unescape( remaining );
390 }
391
392 private TestSetReportEntry createReportEntry( String untokenized )
393 {
394 return createReportEntry( untokenized, Collections.<String, String>emptyMap() );
395 }
396
397 private TestSetReportEntry createReportEntry( String untokenized, Map<String, String> systemProperties )
398 {
399 StringTokenizer tokens = new StringTokenizer( untokenized, "," );
400 try
401 {
402 String source = nullableCsv( tokens.nextToken() );
403 String name = nullableCsv( tokens.nextToken() );
404 String group = nullableCsv( tokens.nextToken() );
405 String message = nullableCsv( tokens.nextToken() );
406 String elapsedStr = tokens.nextToken();
407 Integer elapsed = "null".equals( elapsedStr ) ? null : decode( elapsedStr );
408 final StackTraceWriter stackTraceWriter =
409 tokens.hasMoreTokens() ? deserializeStackTraceWriter( tokens ) : null;
410
411 return reportEntry( source, name, group, stackTraceWriter, elapsed, message, systemProperties );
412 }
413 catch ( RuntimeException e )
414 {
415 throw new RuntimeException( untokenized, e );
416 }
417 }
418
419 private StackTraceWriter deserializeStackTraceWriter( StringTokenizer tokens )
420 {
421 String stackTraceMessage = nullableCsv( tokens.nextToken() );
422 String smartStackTrace = nullableCsv( tokens.nextToken() );
423 String stackTrace = tokens.hasMoreTokens() ? nullableCsv( tokens.nextToken() ) : null;
424 boolean hasTrace = stackTrace != null;
425 return hasTrace ? new DeserializedStacktraceWriter( stackTraceMessage, smartStackTrace, stackTrace ) : null;
426 }
427
428 private String nullableCsv( String source )
429 {
430 return "null".equals( source ) ? null : unescape( source );
431 }
432
433 private String unescape( String source )
434 {
435 StringBuilder stringBuffer = new StringBuilder( source.length() );
436 unescapeString( stringBuffer, source );
437 return stringBuffer.toString();
438 }
439
440 public final Map<String, String> getTestVmSystemProperties()
441 {
442 return unmodifiableMap( testVmSystemProperties );
443 }
444
445
446
447
448
449
450
451 public final RunListener getReporter()
452 {
453 return getTestSetReporter();
454 }
455
456 private ConsoleOutputReceiver getOrCreateConsoleOutputReceiver()
457 {
458 return (ConsoleOutputReceiver) getTestSetReporter();
459 }
460
461 private ConsoleLogger getOrCreateConsoleLogger()
462 {
463 return (ConsoleLogger) getTestSetReporter();
464 }
465
466 public void close( boolean hadTimeout )
467 {
468
469 }
470
471 public final boolean isSaidGoodBye()
472 {
473 return saidGoodBye;
474 }
475
476 public final StackTraceWriter getErrorInFork()
477 {
478 return errorInFork;
479 }
480
481 public final boolean isErrorInFork()
482 {
483 return errorInFork != null;
484 }
485
486 public Set<String> testsInProgress()
487 {
488 return new TreeSet<>( testsInProgress );
489 }
490
491 public boolean hasTestsInProgress()
492 {
493 return !testsInProgress.isEmpty();
494 }
495
496 private static final class OperationalData
497 {
498 private final byte operationId;
499 private final String data;
500
501 OperationalData( String event )
502 {
503 operationId = (byte) event.charAt( 0 );
504 int comma = event.indexOf( ",", 3 );
505 if ( comma < 0 )
506 {
507 throw new IllegalArgumentException( "Stream stdin corrupted. Expected comma after third character "
508 + "in command '" + event + "'." );
509 }
510 int rest = event.indexOf( ",", comma );
511 data = event.substring( rest + 1 );
512 }
513
514 byte getOperationId()
515 {
516 return operationId;
517 }
518
519 String getData()
520 {
521 return data;
522 }
523 }
524 }