Clever Geek Handbook

What a third-party .jar was preparing for us ...

I’ll tell you about one amusing incident that made our whole team sweat a lot, and almost brought some to a nervous breakdown. The result of this research is an effective tool that any developer can use to get the rest of the team on the nerves. The point of this post is to warn about possible non-trivial situations and be prepared for them.





Lyrical digression



, . open-source , - , , , . , . , . . , . , work-around, , .



:



  • . , .
  • . , , . , , , StackOverflow.
  • , , .
  • . , . : , “ ” .
  • . , .


.





, . , , SFTP .



:



public class Task implements Runnable {
    static final Logger log = LoggerFactory.getLogger(Task.class);

    public void run() {
        log.info("Task started");
        try(var remoteFile = createRemoteFile(xxx)) {
            this.setState(STARTED);
            for (int page = 0;;page++) {
                var block = service.requestDataBlock(page);
                if (block == null) break;
                transformData(block);
                remoteFile.writeDataBlock(block);
            }
            this.setState(FINISHED);
            log.info("Task finished");
        } catch (Exception ex) {
            log.error("Task failed", ex);
            this.setState(ERROR);
        }
    }
}


, , state=STARTED . — - . "Task started", "Task finished" "Task failed".



1



, , . — - dead lock. , thread dump , . .



2



, thread dump, , — . - "Task started", "Task finished" "Task failed"! , , Throwable Error, Exception. catch(Exception) catch(Throwable) . — , thread dump- .



3



, . , , thread dump, , . - . , . !



4



— , — , . , - OutOfMemoryError, catch ( OutOfMemoryError). java -XX:+CrashOnOutOfMemoryError -XX:+HeapDumpOnOutOfMemoryError. java- OutOfMemory hs_err_pid, — memory dump . : OutOfMemory — ( ), , .



5



. : , ! - Thread.stop(), , - JDK. — , , - , . System.out.println(), try-catch . :



java.lang.StackOverflowError
    at java.lang.reflect.InvocationTargetException.<init>(InvocationTargetException.java:72)
    at sun.reflect.GeneratedMethodAccessor1.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at ch.qos.logback.classic.spi.ThrowableProxy.<init>(ThrowableProxy.java:66)
    at ch.qos.logback.classic.spi.ThrowableProxy.<init>(ThrowableProxy.java:72)
    at ch.qos.logback.classic.spi.ThrowableProxy.<init>(ThrowableProxy.java:72)
    at ch.qos.logback.classic.spi.ThrowableProxy.<init>(ThrowableProxy.java:72)
    at ch.qos.logback.classic.spi.ThrowableProxy.<init>(ThrowableProxy.java:72)
    at ch.qos.logback.classic.spi.ThrowableProxy.<init>(ThrowableProxy.java:72)
            ...


! , Logback. , , — Error, ! , :



log.error("Task failed", ex);




What a Terrible Failure (WTF?!)



- ? ThrowableProxy Logback , suppressed exceptions, :



suppressed = new ThrowableProxy[throwableSuppressed.length];
for (int i = 0; i < throwableSuppressed.length; i++) {
   this.suppressed[i] = new ThrowableProxy(throwableSuppressed[i]);
   this.suppressed[i].commonFrames = 
        ThrowableProxyUtil.findNumberOfCommonFrames(throwableSuppressed[i].getStackTrace(),
                   stackTraceElementProxyArray);
}


, suppressed exceptions . :



@Test
public void testLogback() throws Exception {
    Logger log = LoggerFactory.getLogger(TestLogback.class);
    //    java 
    // java.lang.IllegalArgumentException: Self-suppression not permitted
    //ex.addSuppressed(ex);
    //   
    Exception ex = new Exception("Test exception");
    Exception ex1 = new Exception("Test exception1");
    ex.addSuppressed(ex1);
    ex1.addSuppressed(ex);
    log.error("Exception", ex);
}


— StackOverflowError! Java, ( 19000 maven-) , , . Logback , SFTP — Apache VFS. IOException suppressed, IOException. .



Logback ? , 2014 :

https://jira.qos.ch/browse/LOGBACK-1027

2019:

https://jira.qos.ch/browse/LOGBACK-1454

.



, Java ? , ex.printStackTrace(), , CIRCULAR REFERENCE:



java.io.IOException: Test exception
    at org.example.test.TestLogback.lambda$testJavaOutput$1(TestLogback.java:43)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)
    Suppressed: java.lang.Exception: Test exception1
        at org.example.test.TestLogback.lambda$testJavaOutput$1(TestLogback.java:44)
        ... 5 more
    [CIRCULAR REFERENCE:java.lang.Exception: Test exception]


java.util.logging.



Log4j , suppressed exception.



14:15:22.154 [main] ERROR org.example.test.TestLogback - Test
java.lang.Exception: Test exception
    at org.example.test.TestLogback.testLog4j(TestLogback.java:61) [test-classes/:?]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_251]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_251]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_251]
    at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_251]
    Suppressed: java.lang.Exception: Test exception1
        at org.example.test.TestLogback.testLog4j(TestLogback.java:62) [test-classes/:?]
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_251]
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_251]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_251]
        at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_251]
        Suppressed: java.lang.Exception: Test exception
            at org.example.test.TestLogback.testLog4j(TestLogback.java:61) [test-classes/:?]
            at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_251]
            at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_251]
            at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_251]
            at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_251]




Logback — . , :



  • , , , . .
  • , , .
  • , .
  • , .
  • Don't expect your ticket to be quickly fixed or a pull request quickly accepted - it will take several months to several years before the fix is ​​published in the official repository.
  • If you are using Logback, adapt the exception by removing circular references before logging it. This can only be done in the top-level handlers in Thread and ExecutorService.


More articles:


All Articles