1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30 package com.jcabi.log;
31
32 import java.io.ByteArrayInputStream;
33 import java.io.Closeable;
34 import java.io.File;
35 import java.io.FileInputStream;
36 import java.io.IOException;
37 import java.io.InputStream;
38 import java.io.StringWriter;
39 import java.util.Timer;
40 import java.util.TimerTask;
41 import java.util.concurrent.CountDownLatch;
42 import java.util.concurrent.TimeUnit;
43 import java.util.logging.Level;
44 import org.apache.commons.lang3.StringUtils;
45 import org.apache.commons.lang3.SystemUtils;
46 import org.apache.log4j.SimpleLayout;
47 import org.apache.log4j.WriterAppender;
48 import org.apache.log4j.spi.Filter;
49 import org.apache.log4j.spi.LoggingEvent;
50 import org.hamcrest.MatcherAssert;
51 import org.hamcrest.Matchers;
52 import org.junit.jupiter.api.Assertions;
53 import org.junit.jupiter.api.Assumptions;
54 import org.junit.jupiter.api.Disabled;
55 import org.junit.jupiter.api.Test;
56 import org.mockito.Mockito;
57
58
59
60
61
62
63
64
65
66
67
68
69 @SuppressWarnings({ "PMD.TooManyMethods", "PMD.AvoidDuplicateLiterals" })
70 final class VerboseProcessTest {
71
72 @Test
73 @Disabled
74 void runsACommandLineScript() {
75 Assumptions.assumeFalse(SystemUtils.IS_OS_WINDOWS, "");
76 final VerboseProcess process = new VerboseProcess(
77 new ProcessBuilder("echo", "hey \u20ac!").redirectErrorStream(true)
78 );
79 MatcherAssert.assertThat(
80 process.stdout(),
81 Matchers.containsString("\u20ac!")
82 );
83 }
84
85 @Test
86 @Disabled
87 void echosUnicodeCorrectly() {
88 Assumptions.assumeFalse(SystemUtils.IS_OS_WINDOWS, "");
89 MatcherAssert.assertThat(
90 new VerboseProcess(
91 new ProcessBuilder(
92 "/bin/bash", "-c",
93 "echo -n \u0442\u0435\u0441\u0442 | hexdump"
94 )
95 ).stdout(),
96 Matchers.containsString("0000000 d1 82 d0 b5 d1 81 d1 82")
97 );
98 }
99
100 @Test
101 void runsACommandLineScriptWithException() {
102 Assumptions.assumeFalse(SystemUtils.IS_OS_WINDOWS, "");
103 final VerboseProcess process = new VerboseProcess(
104 new ProcessBuilder("cat", "/non-existing-file.txt")
105 .redirectErrorStream(true)
106 );
107 try {
108 process.stdout();
109 Assertions.fail("exception expected");
110 } catch (final IllegalArgumentException ex) {
111 MatcherAssert.assertThat(
112 ex.getMessage(),
113 Matchers.containsString("No such file or directory")
114 );
115 }
116 }
117
118 @Test
119 void runsACommandLineScriptWithExceptionNoRedir() throws Exception {
120 Assumptions.assumeFalse(SystemUtils.IS_OS_WINDOWS, "");
121 final VerboseProcess process = new VerboseProcess(
122 new ProcessBuilder("cat", "/non-existing-file.txt")
123 );
124 final VerboseProcess.Result result = process.waitFor();
125 MatcherAssert.assertThat(
126 result.code(),
127 Matchers.equalTo(1)
128 );
129 MatcherAssert.assertThat(
130 result.stderr(),
131 Matchers.containsString("No such file or directory")
132 );
133 }
134
135 @Test
136 void handlesLongRunningCommand() {
137 Assumptions.assumeFalse(SystemUtils.IS_OS_WINDOWS, "");
138 final VerboseProcess process = new VerboseProcess(
139 new ProcessBuilder("/bin/bash", "-c", "sleep 2; echo 'done'")
140 );
141 MatcherAssert.assertThat(
142 process.stdout(),
143 Matchers.startsWith("done")
144 );
145 }
146
147 @Test
148 void rejectsNullProcesses() {
149 Assertions.assertThrows(
150 RuntimeException.class,
151 () -> {
152 final ProcessBuilder builder = null;
153 new VerboseProcess(builder);
154 }
155 );
156 }
157
158 @Test
159 void rejectsStdoutWithLevelAll() {
160 try {
161 new VerboseProcess(
162 Mockito.mock(Process.class), Level.ALL, Level.INFO
163 );
164 Assertions.fail("IllegalArgumentException expected");
165 } catch (final IllegalArgumentException ex) {
166 MatcherAssert.assertThat(
167 ex.getMessage(),
168 Matchers.equalTo(
169 StringUtils.join(
170 "stdout LEVEL can't be set to ALL because it is ",
171 "intended only for internal configuration"
172 )
173 )
174 );
175 }
176 }
177
178 @Test
179 void rejectsStderrWithLevelAll() {
180 try {
181 new VerboseProcess(
182 Mockito.mock(Process.class), Level.INFO, Level.ALL
183 );
184 Assertions.fail("IllegalArgumentException expected here");
185 } catch (final IllegalArgumentException ex) {
186 MatcherAssert.assertThat(
187 ex.getMessage(),
188 Matchers.equalTo(
189 StringUtils.join(
190 "stderr LEVEL can't be set to ALL because it is ",
191 "intended only for internal configuration"
192 )
193 )
194 );
195 }
196 }
197
198 @Test
199 @SuppressWarnings("PMD.DoNotUseThreads")
200 void quietlyTerminatesLongRunningProcess() throws Exception {
201 Assumptions.assumeFalse(SystemUtils.IS_OS_WINDOWS, "");
202 final Process proc = new ProcessBuilder("sleep", "10000").start();
203 final VerboseProcess process = new VerboseProcess(proc);
204 final CountDownLatch start = new CountDownLatch(1);
205 final CountDownLatch done = new CountDownLatch(1);
206 new Thread(
207 new VerboseRunnable(
208 () -> {
209 start.countDown();
210 process.stdoutQuietly();
211 done.countDown();
212 }
213 )
214 ).start();
215 start.await();
216 TimeUnit.SECONDS.sleep(1L);
217 proc.destroy();
218 MatcherAssert.assertThat(
219 done.await(1L, TimeUnit.MINUTES),
220 Matchers.is(true)
221 );
222 }
223
224 @Test
225 void stdoutQuietlyLogsErrors() {
226 final StringWriter writer = new StringWriter();
227 org.apache.log4j.Logger.getRootLogger().addAppender(
228 new WriterAppender(new SimpleLayout(), writer)
229 );
230 final ProcessBuilder builder;
231 final String message = "hello dear friend";
232 if (SystemUtils.IS_OS_WINDOWS) {
233 builder = new ProcessBuilder("cmd", "/c", "echo", message, "1>&2");
234 } else {
235 builder = new ProcessBuilder(
236 "cat", String.format("/non-existing-file-%s ", message)
237 );
238 }
239 final VerboseProcess process = new VerboseProcess(
240 builder, Level.OFF, Level.WARNING
241 );
242 process.stdoutQuietly();
243 MatcherAssert.assertThat(
244 writer.toString(),
245 Matchers.containsString(message)
246 );
247 }
248
249 @Test
250 @SuppressWarnings("PMD.AvoidFileStream")
251 void logsErrorWhenUnderlyingStreamIsClosed() throws Exception {
252 final StringWriter writer = new StringWriter();
253 org.apache.log4j.Logger.getRootLogger().addAppender(
254 new WriterAppender(new SimpleLayout(), writer)
255 );
256 final Process prc = Mockito.mock(Process.class);
257 final Closeable stdout = new FileInputStream(
258 File.createTempFile("temp", "test")
259 );
260 stdout.close();
261 Mockito.doReturn(stdout).when(prc).getInputStream();
262 Mockito.doReturn(new ByteArrayInputStream(new byte[0]))
263 .when(prc).getErrorStream();
264 final VerboseProcess process = new VerboseProcess(
265 prc,
266 Level.FINEST,
267 Level.FINEST
268 );
269 Logger.debug(
270 this,
271 "#logsErrorWhenUnderlyingStreamIsClosed(): vrbPrc.hashCode=%s",
272 process.hashCode()
273 );
274 process.stdout();
275 MatcherAssert.assertThat(
276 writer.toString(),
277 Matchers.containsString("Error reading from process stream")
278 );
279 }
280
281 @Test
282 void terminatesMonitorsAndProcessIfClosedInstantly()
283 throws Exception {
284 this.terminatesMonitorsAndProcessIfClosed(0L);
285 }
286
287 @Test
288 void terminatesMonitorsAndProcessIfClosedShortly()
289 throws Exception {
290 this.terminatesMonitorsAndProcessIfClosed(50L);
291 }
292
293 @Test
294 void terminatesMonitorsAndProcessIfClosedNormal() throws Exception {
295 final long delay = 400L;
296 this.terminatesMonitorsAndProcessIfClosed(delay);
297 }
298
299
300
301
302
303
304
305
306
307 private void terminatesMonitorsAndProcessIfClosed(final long delay)
308 throws Exception {
309 final InputStream input = new VerboseProcessTest.InfiniteInputStream('i');
310 final InputStream error = new VerboseProcessTest.InfiniteInputStream('e');
311 final Process prc = Mockito.mock(Process.class);
312 Mockito.doReturn(input).when(prc).getInputStream();
313 Mockito.doReturn(error).when(prc).getErrorStream();
314 Mockito.doAnswer(
315 invocation -> {
316 input.close();
317 error.close();
318 return null;
319 }
320 ).when(prc).destroy();
321 final VerboseProcess process = new VerboseProcess(
322 prc,
323 Level.FINEST,
324 Level.FINEST
325 );
326 Logger.debug(
327 this,
328 "terminatesMntrsAndPrcssIfClosed delay=%d vrbPrc.hashCode=%s",
329 delay,
330 process.hashCode()
331 );
332 final StringWriter writer = new StringWriter();
333 final WriterAppender appender = new WriterAppender(
334 new SimpleLayout(),
335 writer
336 );
337 appender.addFilter(new VerboseProcessTest.VrbPrcMonitorFilter(process));
338 org.apache.log4j.Logger.getLogger(
339 VerboseProcess.class
340 ).addAppender(appender);
341 if (delay == 0L) {
342 process.close();
343 } else {
344 new Timer(true).schedule(
345 new TimerTask() {
346 @Override
347 public void run() {
348 process.close();
349 }
350 },
351 delay
352 );
353 }
354 process.stdoutQuietly();
355 TimeUnit.MILLISECONDS.sleep(1000L);
356 Mockito.verify(
357 prc,
358 Mockito.atLeastOnce()
359 ).destroy();
360 MatcherAssert.assertThat(
361 writer.toString(),
362 Matchers.not(Matchers
363 .containsString("Error reading from process stream")
364 )
365 );
366 }
367
368
369
370
371
372
373 private final class InfiniteInputStream extends InputStream {
374
375
376
377 private static final int LINE_FEED = 0xA;
378
379
380
381
382 private final transient char chr;
383
384
385
386
387 private transient boolean feed;
388
389
390
391
392 private transient boolean closed;
393
394
395
396
397
398
399 InfiniteInputStream(final char character) {
400 super();
401 this.chr = character;
402 }
403
404 @Override
405 public int read() throws IOException {
406 if (this.closed) {
407 throw new IOException("Stream closed");
408 }
409 final int next;
410 if (this.feed) {
411 this.feed = false;
412 next = VerboseProcessTest.InfiniteInputStream.LINE_FEED;
413 } else {
414 this.feed = true;
415 next = this.chr;
416 }
417 return next;
418 }
419
420 @Override
421 public void close() {
422 this.closed = true;
423 }
424 }
425
426
427
428
429
430
431
432
433
434 private final class VrbPrcMonitorFilter extends Filter {
435
436
437
438 private static final String THREADNAME_START = "VrbPrc.Monitor-";
439
440
441
442
443 private final transient int hash;
444
445
446
447
448
449
450
451 VrbPrcMonitorFilter(final VerboseProcess prc) {
452 super();
453 this.hash = prc.hashCode();
454 }
455
456 @Override
457 public int decide(final LoggingEvent event) {
458 final String thread = event.getThreadName();
459 final int decision;
460 if (thread.startsWith(VerboseProcessTest.VrbPrcMonitorFilter.THREADNAME_START
461 + this.hash
462 )) {
463 decision = Filter.ACCEPT;
464 } else {
465 decision = Filter.DENY;
466 }
467 return decision;
468 }
469 }
470 }