View Javadoc
1   /*
2    * Copyright (c) 2012-2024, jcabi.com
3    * All rights reserved.
4    *
5    * Redistribution and use in source and binary forms, with or without
6    * modification, are permitted provided that the following conditions
7    * are met: 1) Redistributions of source code must retain the above
8    * copyright notice, this list of conditions and the following
9    * disclaimer. 2) Redistributions in binary form must reproduce the above
10   * copyright notice, this list of conditions and the following
11   * disclaimer in the documentation and/or other materials provided
12   * with the distribution. 3) Neither the name of the jcabi.com nor
13   * the names of its contributors may be used to endorse or promote
14   * products derived from this software without specific prior written
15   * permission.
16   *
17   * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
18   * "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT
19   * NOT LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND
20   * FITNESS FOR A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL
21   * THE COPYRIGHT HOLDER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT,
22   * INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES
23   * (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR
24   * SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION)
25   * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT,
26   * STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE)
27   * ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED
28   * OF THE POSSIBILITY OF SUCH DAMAGE.
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   * Test case for {@link VerboseProcess}.
60   *
61   * @checkstyle MultipleStringLiterals (500 lines)
62   * @checkstyle ClassDataAbstractionCoupling (200 lines)
63   * @todo #18 Locale/encoding problem in two test methods here. I'm not
64   *  sure how to fix them, but they should be fixed. They fail on some
65   *  machines, while run perfectly on others. They also fail when being
66   *  executed from IntelliJ.
67   * @since 0.1
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      * VerboseProcess can terminate its monitors and underlying Process if
301      * closed after specified time since real usage.
302      * @param delay Time in milliseconds between usage of vrbcPrc starts and
303      *  its close() issued
304      * @throws Exception If something goes wrong
305      * @checkstyle ExecutableStatementCountCheck (100 lines)
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      * {@link InputStream} returning endless flow of characters.
370      *
371      * @since 0.1
372      */
373     private final class InfiniteInputStream extends InputStream {
374         /**
375          * End of line.
376          */
377         private static final int LINE_FEED = 0xA;
378 
379         /**
380          * Character, endlessly repeated in the stream.
381          */
382         private final transient char chr;
383 
384         /**
385          * Whether the next char in the stream should be EOL.
386          */
387         private transient boolean feed;
388 
389         /**
390          * Whether this stream is closed.
391          */
392         private transient boolean closed;
393 
394         /**
395          * Construct an InputStream returning endless combination of this
396          * character and end of line.
397          * @param character Character to return in the stream
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      * Filter of log messages of {@link VerboseProcess}'s monitor threads.
428      *
429      * <p>It filters out messages of monitor threads, that doesn't belong to
430      * specific {@link VerboseProcess}.
431      *
432      * @since 0.1
433      */
434     private final class VrbPrcMonitorFilter extends Filter {
435         /**
436          * Monitor's log message start.
437          */
438         private static final String THREADNAME_START = "VrbPrc.Monitor-";
439 
440         /**
441          * HashCode of {@link VerboseProcess} to filter.
442          */
443         private final transient int hash;
444 
445         /**
446          * Create filter for this process.
447          *
448          * <p>The messages from its monitor threads will be filtered in.
449          * @param prc Process
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 }