May 2023 - logback-dev - mailman3.qos.ch

[JIRA] Updates for LOGBACK-1743: SocketReceiver configuration broken
by logback developers list 30 May '23

30 May '23

logback / LOGBACK-1743 [Open] SocketReceiver configuration broken ============================== Here's what changed in this issue in the last few minutes. This issue has been created This issue is now assigned to you. View or comment on issue using this link https://jira.qos.ch/browse/LOGBACK-1743 ============================== Issue created ------------------------------ Volker Götz created this issue on 30/May/23 23:19 Summary: SocketReceiver configuration broken Issue Type: Bug Affects Versions: 1.4.0, 1.4.7 Assignee: Logback dev list Created: 30/May/23 23:19 Priority: Major Reporter: Volker Götz Description: The standard {{ServerSocketReceiver}} configuration, as mentioned in the [documentation chapter 13 |https://logback.qos.ch/manual/receivers.html] is not working anymore. The XML configuration cannot be parsed: {code} Can't handle model of type class ch.qos.logback.classic.model.ReceiverModel with tag: receiver at line 13 Ignoring unknown property [port] in [ch.qos.logback.classic.LoggerContext] {code} Configuration file: {code:xml} <configuration debug="true"> <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender"> <encoder> <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger - %msg%n</pattern> </encoder> </appender> <root level="DEBUG"> <appender-ref ref="CONSOLE" /> </root> <receiver class="ch.qos.logback.classic.net.server.ServerSocketReceiver"> <port>9876</port> </receiver> </configuration> {code} The full log output with the error: {code} 23:16:45,076 |-INFO in ch.qos.logback.classic.LoggerContext[default] - This is logback-classic version 1.4.7 23:16:45,091 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml] 23:16:45,093 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [file:/Users/volker/Workspaces/IntelliJ/G-ITS/logback-receiver/build/resources/main/logback.xml] 23:16:45,170 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [CONSOLE] 23:16:45,171 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender] 23:16:45,175 |-INFO in ch.qos.logback.core.model.processor.ImplicitModelHandler - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property 23:16:45,183 |-INFO in ch.qos.logback.classic.model.processor.RootLoggerModelHandler - Setting level of ROOT logger to DEBUG 23:16:45,183 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [CONSOLE] to Logger[ROOT] 23:16:45,186 |-ERROR in ch.qos.logback.core.model.processor.DefaultProcessor@3023df74 - Can't handle model of type class ch.qos.logback.classic.model.ReceiverModel with tag: receiver at line 13 23:16:45,187 |-WARN in ch.qos.logback.core.model.processor.ImplicitModelHandler - Ignoring unknown property [port] in [ch.qos.logback.classic.LoggerContext] 23:16:45,187 |-ERROR in ch.qos.logback.core.model.processor.DefaultProcessor@3023df74 - Can't handle model of type class ch.qos.logback.classic.model.ReceiverModel with tag: receiver at line 13 23:16:45,187 |-INFO in ch.qos.logback.core.model.processor.DefaultProcessor@3023df74 - End of configuration. 23:16:45,188 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@5e0e82ae - Registering current configuration as safe fallback point {code} ============================== This message was sent by Atlassian Jira (v9.6.0#960000-sha1:a3ee8af)

1 0

[JIRA] (LOGBACK-1735) ILoggingEvent#getInstant should return `Instant.ofEpochMills(getTimeStamp())` instead of null for compatibility
by logback developers list 30 May '23

30 May '23

1 0

[JIRA] (LOGBACK-1742) Allow LogbackMDCAdapter to be set non-statically
by logback developers list 21 May '23

21 May '23

1 0

[JIRA] Updates for LOGBACK-1742: Allow LogbackMDCAdapter to be set non-statically
by logback developers list 21 May '23

21 May '23

logback / LOGBACK-1742 [Open] Allow LogbackMDCAdapter to be set non-statically ============================== Here's what changed in this issue in the last few minutes. This issue has been created This issue is now assigned to you. View or comment on issue using this link https://jira.qos.ch/browse/LOGBACK-1742 ============================== Issue created ------------------------------ Ceki Gülcü created this issue on 21/May/23 22:54 Summary: Allow LogbackMDCAdapter to be set non-statically Issue Type: Bug Assignee: Logback dev list Created: 21/May/23 22:54 Priority: Major Reporter: Ceki Gülcü ============================== This message was sent by Atlassian Jira (v9.6.0#960000-sha1:a3ee8af)

1 0

[JIRA] Updates for LOGBACK-1741: AsyncAppender hangs intermittently
by logback developers list 16 May '23

16 May '23

logback / LOGBACK-1741 [Open] AsyncAppender hangs intermittently ============================== Here's what changed in this issue in the last few minutes. This issue has been created This issue is now assigned to you. View or comment on issue using this link https://jira.qos.ch/browse/LOGBACK-1741 ============================== Issue created ------------------------------ Jingfei Hu created this issue on 16/May/23 13:56 Summary: AsyncAppender hangs intermittently Issue Type: Bug Affects Versions: 1.3.1 Assignee: Logback dev list Components: logback-classic, logback-core Created: 16/May/23 13:56 Environment: openjdk version "1.8.0_332" OpenJDK Runtime Environment (build 1.8.0_332-b718) OpenJDK 64-Bit Server VM (build 25.332-b718, mixed mode) Labels: AsyncAppender Priority: Major Reporter: Jingfei Hu Description: Hello team, Recently we leverage AsyncAppender to reduce latency as logging. It does help to reduce the latency in case of large amounts of logging events. However, we spot a hang issue. Though, for now, it occurs only once, we're afraid it's a bug of logback or JDK and it might happen again. Below is the thread stack, almost all threads of our process are blocked on this lock and we fail to locate the thread owning this lock(it's weird that jstack doesn't show which thread holds that lock, we guess the thread holding the lock might crash for somehow reason, but we have no way to prove that) {code:java} "msgWorkTP-582450565-6-thread-1" #642 prio=5 os_prio=0 tid=0x00007efec4094000 nid=0x4ca7 waiting on condition [0x00007efe841f9000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park0(Native Method) - parking to wait for <0x00000007463ab208> (a java.util.concurrent.locks.ReentrantLock$NonfairSync) at sun.misc.Unsafe.park(Unsafe.java:1038) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:176) at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:842) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:876) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1207) at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:209) at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285) at java.util.concurrent.ArrayBlockingQueue.remainingCapacity(ArrayBlockingQueue.java:468) at ch.qos.logback.core.AsyncAppenderBase.isQueueBelowDiscardingThreshold(AsyncAppenderBase.java:170) at ch.qos.logback.core.AsyncAppenderBase.append(AsyncAppenderBase.java:162) at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:85) at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:51) at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:272) at ch.qos.logback.classic.Logger.callAppenders(Logger.java:259) at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:426) at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:386) at ch.qos.logback.classic.Logger.info(Logger.java:584) {code} Our configuration is below {code:java}  <appender name="ASYNC_MODULE_APPENDER" class="ch.qos.logback.classic.AsyncAppender"> <appender-ref ref="MODULE_APPENDER" /> <queueSize>1024</queueSize> <discardingThreshold>0</discardingThreshold> <neverBlock>true</neverBlock> </appender> {code} And module configuration of MODULE_APPENDER is below {code:java} <appender name="MODULE_APPENDER" class="ch.qos.logback.core.rolling.RollingFileAppender"> <file>${user.home}/logs/sandbox/platform-test-support-sandbox-module.log</file> <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy"> <FileNamePattern>${user.home}/logs/sandbox/platform-test-support-sandbox-module.log.%d{yyyy-MM-dd}.%i</FileNamePattern> <maxFileSize>100MB</maxFileSize> <MaxHistory>5</MaxHistory> <totalSizeCap>500MB</totalSizeCap> </rollingPolicy> <encoder> <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %msg%n</pattern> <charset>UTF-8</charset> </encoder> <filter class="ch.qos.logback.classic.filter.ThresholdFilter"> <level>INFO</level> </filter> </appender> {code} ============================== This message was sent by Atlassian Jira (v9.6.0#960000-sha1:a3ee8af)

1 0

[JIRA] Updates for LOGBACK-1740: Number of async tasks limited to 32 on
by logback developers list 16 May '23

16 May '23

logback / LOGBACK-1740 [Open] Number of async tasks limited to 32 on ============================== Here's what changed in this issue in the last few minutes. This issue has been created This issue is now assigned to you. View or comment on issue using this link https://jira.qos.ch/browse/LOGBACK-1740 ============================== Issue created ------------------------------ dgodmun created this issue on 16/May/23 9:43 Summary: Number of async tasks limited to 32 on Issue Type: Bug Affects Versions: 1.3.7 Assignee: Logback dev list Components: logback-core Created: 16/May/23 9:43 Labels: SizeAndTimeBasedRollingPolicy Priority: Major Reporter: dgodmun Description: Hello, I've found an issue related with the class CoreConstants: /** * Maximum number of threads to allow in a context's executor service. */ // if you need a different MAX_POOL_SIZE, please file create a jira issue // asking to make MAX_POOL_SIZE a parameter. public static final int MAX_POOL_SIZE = 32; The size of the pool is causing a problem when using SizeAndTimeBasedRollingPolicy at the end of the day when the number of files in the logger is bigger than 32. See log details of the issue: 02:00:01,852 |-INFO in c.q.l.co.rolling.helper.RenameUtil - Renaming file [/.../DEMO_LP3/USDAED.log] to [/.../DEMO_LP3/USDAED.2023-05-11.0.log2522180056964847.tmp] 02:00:01,852 |-ERROR in SizeAndTimeBasedFNATP [FILE-SIFT] - Appender [FILE-SIFT] failed to append. java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.FutureTask@398bae3b[Not completed, task = java.util.concurrent.Executors$RunnableAdapter@198af505[Wrapped task = ch.qos.logback.core.rolling.helper.Compressor$CompressionRunnable@3d7e666b]] rejected from java.util.concurrent.ThreadPoolExecutor@296f8602[Running, pool size = 32, active threads = 32, queued tasks = 0, completed tasks = 91] at java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.FutureTask@398bae3b[Not completed, task = java.util.concurrent.Executors$RunnableAdapter@198af505[Wrapped task = ch.qos.logback.core.rolling.helper.Compressor$CompressionRunnable@3d7e666b]] rejected from java.util.concurrent.ThreadPoolExecutor@296f8602[Running, pool size = 32, active threads = 32, queued tasks = 0, completed tasks = 91] at at java.base/java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2065) at at java.base/java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:833) at at java.base/java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1365) at at java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:123) at at ch.qos.logback.core.rolling.helper.Compressor.asyncCompress(Compressor.java:229) at at ch.qos.logback.core.rolling.TimeBasedRollingPolicy.renameRawAndAsyncCompress(TimeBasedRollingPolicy.java:196) at at ch.qos.logback.core.rolling.TimeBasedRollingPolicy.rollover(TimeBasedRollingPolicy.java:182) at at ch.qos.logback.core.rolling.RollingFileAppender.attemptRollover(RollingFileAppender.java:220) at at ch.qos.logback.core.rolling.RollingFileAppender.rollover(RollingFileAppender.java:198) at at ch.qos.logback.core.rolling.RollingFileAppender.subAppend(RollingFileAppender.java:246) at at ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:102) at at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:85) at at ch.qos.logback.core.sift.SiftingAppenderBase.append(SiftingAppenderBase.java:122) at at ch.qos.logback.core.AppenderBase.doAppend(AppenderBase.java:83) at at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachab The issue leaves a tmp file in the disk. In order to reproduce it is just required having more than 32 files to roll with a reasonable size, if the queue of the thread pool is full then it will fail. It would be very interesting having the possibility of defining the number of threads by configuration. I know the case I'm working on is very special, it is not comming having so many files rolling at the end of the day for the logger. Thank you very much. ============================== This message was sent by Atlassian Jira (v9.6.0#960000-sha1:a3ee8af)

1 0

[JIRA] Updates for LOGBACK-1739: Some Flaky Test
by logback developers list 12 May '23

12 May '23

logback / LOGBACK-1739 [Open] Some Flaky Test ============================== Here's what changed in this issue in the last few minutes. This issue has been created This issue is now assigned to you. View or comment on issue using this link https://jira.qos.ch/browse/LOGBACK-1739 ============================== Issue created ------------------------------ Agor Malon created this issue on 12/May/23 20:28 Summary: Some Flaky Test Issue Type: Bug Affects Versions: 1.4.7 Assignee: Logback dev list Components: logback-classic, logback-core Created: 12/May/23 20:28 Labels: Tests Priority: Major Reporter: Agor Malon Description: Hello, We tried running your project and discovered that it contains some flaky tests (i.e., tests that nondeterministically pass and fail). We found these tests to fail more frequently when running them on certain machines of ours. To prevent others from running this project and its tests in machines that may result in flaky tests, we suggest adding information to the README.md file indicating the minimum resource configuration for running the tests of this project as to prevent observation of test flakiness. If we run this project in a machine with 1cpu and 1gb ram, we observe flaky tests. We found that the tests in this project did not have any flaky tests when we ran it on machines with 2cpu and 4gb ram. Here is a list of the tests we have identified and their likelihood of failure on a system with less than the recommended 2 CPUs and 4 GB RAM. # ch.qos.logback.core.AsyncAppenderBaseTest#lossyAppenderShouldOnlyLoseCertainEvents (4 out 10) # ch.qos.logback.core.AsyncAppenderBaseTest#verifyInterruptionOfWorkerIsSwallowed (5 out 10) # ch.qos.logback.classic.net.SMTPAppender_GreenTest#synchronousSmoke (6 out 10) # ch.qos.logback.classic.LoggerContextConcurrentResetTest#concurrentReset (3 out 10) # ch.qos.logback.core.net.server.ServerSocketAppenderBaseFunctionalTest#testLogEventClient (4 out 10) # ch.qos.logback.core.AsyncAppenderBaseTest#stopExitsWhenMaxRuntimeReached (7 out 10) Please let me know if you would like us to create a pull request on this matter (possibly to the readme of this project). Thank you for your attention to this matter. We hope that our recommendations will be helpful in improving the quality and performance of your project, especially for others to use. h3. Reproducing {code:java} FROM maven:3.5.4-jdk-11 WORKDIR /home/ RUN git clone https://github.com/qos-ch/logback/ && \ cd logback && \ git checkout 6abce2f047a58292d23f3d80f40dab2b9912aa3f WORKDIR /home/logback RUN mvn install -DskipTests ENTRYPOINT ["mvn", "test", "-fn"] {code} Build the image: {code:java} $> mkdir tmp $> cp Dockerfile tmp $> cd tmp $> docker build -t logback . # estimated time of build 3m {code} Running: this configuration likely prevents flakiness (no flakiness in 10 runs) {code:java} $> docker run --rm --memory=4g --cpus=2 --memory-swap=-1 logback | tee output.txt $> grep "Failures:" output.txt # checking results {code} this other configuration can’t prevent flaky tests (observation in 10 runs) {code:java} $> docker run --rm --memory=1g --cpus=1 --memory-swap=-1 logback | tee output2.txt $> grep "Failures:" output2.txt # checking results {code} ============================== This message was sent by Atlassian Jira (v9.6.0#960000-sha1:a3ee8af)

1 0

[JIRA] (LOGBACK-1738) Some flaky tests
by logback developers list 12 May '23

12 May '23

1 0

[JIRA] (LOGBACK-1738) Some flaky tests
by logback developers list 12 May '23

12 May '23

1 0

[JIRA] (LOGBACK-1738) Some flaky tests
by logback developers list 12 May '23

12 May '23

1 0