Skip to content

Commit

Permalink
fixing SLF4J-515
Browse files Browse the repository at this point in the history
Signed-off-by: Ceki Gulcu <ceki@qos.ch>
  • Loading branch information
ceki committed Jul 8, 2021
1 parent 33e7bf2 commit 816da3d
Show file tree
Hide file tree
Showing 3 changed files with 287 additions and 3 deletions.
17 changes: 14 additions & 3 deletions slf4j-simple/src/main/java/org/slf4j/impl/SimpleLogger.java
Original file line number Diff line number Diff line change
Expand Up @@ -26,6 +26,8 @@

import java.io.PrintStream;
import java.util.Date;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.locks.ReentrantLock;

import org.slf4j.Logger;
import org.slf4j.event.LoggingEvent;
Expand Down Expand Up @@ -159,6 +161,9 @@ public class SimpleLogger extends MarkerIgnoringBase {
private static boolean INITIALIZED = false;
static SimpleLoggerConfiguration CONFIG_PARAMS = null;

private static final long MAX_TRY_LOCK_DURATION = 200L;
static ReentrantLock lock = new ReentrantLock();

This comment has been minimized.

Copy link
@Tibor17

Tibor17 Jul 8, 2021

ReentrantLock cannot be optimized by CPU and the JVM and the JIT because the Mutex and main memory/cache reconsilation/flush has to be acquired and happen. I would use synchronized and no problem with timeout and the InterruptedException.

This comment has been minimized.

Copy link
@Tibor17

Tibor17 Jul 8, 2021

It must be private static final to cover the requirements in JSR-133 Java Memory Model.

This comment has been minimized.

Copy link
@ceki

ceki Jul 8, 2021

Author Member

Thank you for you feedback. By "No problem" do you mean a timeout is unnecessary?

This comment has been minimized.

Copy link
@Tibor17

Tibor17 Jul 8, 2021

well, for our problem it is unnecessary.
Pls see my comment in Jira where I explained why you do not need to worry about a deadlock.


static void lazyInit() {
if (INITIALIZED) {
return;
Expand Down Expand Up @@ -315,9 +320,15 @@ protected String renderLevel(int level) {
void write(StringBuilder buf, Throwable t) {
PrintStream targetStream = CONFIG_PARAMS.outputChoice.getTargetPrintStream();

targetStream.println(buf.toString());
writeThrowable(t, targetStream);
targetStream.flush();
try {
lock.tryLock(MAX_TRY_LOCK_DURATION, TimeUnit.MILLISECONDS);

This comment has been minimized.

Copy link
@Tibor17

Tibor17 Jul 8, 2021

If you want to timeout the I/O operations then this must not be a constant, it should be backwards compatible to infinite and the value should be in the properties file. But here we talk about two things - one fix and one feature.

targetStream.println(buf.toString());
writeThrowable(t, targetStream);
targetStream.flush();
} catch (InterruptedException e) {

This comment has been minimized.

Copy link
@Tibor17

Tibor17 Jul 8, 2021

the interrupted state must be renewed - it's a pattern.

This comment has been minimized.

Copy link
@ceki

ceki Jul 9, 2021

Author Member

Yes, that's true.

} finally {
lock.unlock();
}
}

protected void writeThrowable(Throwable t, PrintStream targetStream) {
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,129 @@
/**
* Copyright (c) 2004-2021 QOS.ch
* All rights reserved.
*
* Permission is hereby granted, free of charge, to any person obtaining
* a copy of this software and associated documentation files (the
* "Software"), to deal in the Software without restriction, including
* without limitation the rights to use, copy, modify, merge, publish,
* distribute, sublicense, and/or sell copies of the Software, and to
* permit persons to whom the Software is furnished to do so, subject to
* the following conditions:
*
* The above copyright notice and this permission notice shall be
* included in all copies or substantial portions of the Software.
*
* THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND,
* EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF
* MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND
* NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE
* LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION
* OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION
* WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE.
*
*/
package org.slf4j.simple.multiThreadedExecution;

import java.io.PrintStream;

import org.junit.After;
import org.junit.Before;
import org.junit.Test;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

/**
* Tests that output in multi-threaded environments is not mingled.
*
* See also https://jira.qos.ch/browse/SLF4J-515
*/
public class MultithereadedExecutionTest {

private static int THREAD_COUNT = 2;
private Thread[] threads = new Thread[THREAD_COUNT];

private final PrintStream oldOut = System.out;
StateCheckingPrintStream scps = new StateCheckingPrintStream(oldOut);

volatile boolean signal = false;

@Before
public void setup() {
System.setErr(scps);
// System.setProperty(SimpleLogger.LOG_FILE_KEY, "System.err");
// LoggerFactoryFriend.reset();
}

@After
public void tearDown() throws Exception {
// LoggerFactoryFriend.reset();
// System.clearProperty(SimpleLogger.LOG_FILE_KEY);
System.setErr(oldOut);
}

@Test
public void test() throws Throwable {
WithException withException = new WithException();
Other other = new Other();
threads[0] = new Thread(withException);
threads[1] = new Thread(other);
threads[0].start();
threads[1].start();
Thread.sleep(100);
signal = true;
threads[0].join();
threads[1].join();

if (withException.throwable != null) {
throw withException.throwable;
}

if (other.throwable != null) {
throw other.throwable;
}

}

class WithException implements Runnable {

Throwable throwable;

This comment has been minimized.

Copy link
@Tibor17

Tibor17 Jul 8, 2021

must be volatile

Logger logger = LoggerFactory.getLogger(WithException.class);

This comment has been minimized.

Copy link
@Tibor17

Tibor17 Jul 8, 2021

must be final


@Override
public void run() { // TODO Auto-generated method stub
int i = 0;

while (!signal) {
try {
logger.info("Hello {}", i, new Throwable("i=" + i));
i++;
} catch (Throwable t) {
throwable = t;
MultithereadedExecutionTest.this.signal = true;
return;
}
}

}
}

class Other implements Runnable {
Throwable throwable;

This comment has been minimized.

Copy link
@Tibor17

Tibor17 Jul 8, 2021

must be volatile

Logger logger = LoggerFactory.getLogger(Other.class);

This comment has been minimized.

Copy link
@Tibor17

Tibor17 Jul 8, 2021

must be final


@Override
public void run() {
int i = 0;
while (!signal) {
try {
logger.info("Other {}", i++);
} catch (Throwable t) {
throwable = t;
MultithereadedExecutionTest.this.signal = true;
return;
}
}
}
}

}
Original file line number Diff line number Diff line change
@@ -0,0 +1,144 @@
/**
* Copyright (c) 2004-2021 QOS.ch
* All rights reserved.
*
* Permission is hereby granted, free of charge, to any person obtaining
* a copy of this software and associated documentation files (the
* "Software"), to deal in the Software without restriction, including
* without limitation the rights to use, copy, modify, merge, publish,
* distribute, sublicense, and/or sell copies of the Software, and to
* permit persons to whom the Software is furnished to do so, subject to
* the following conditions:
*
* The above copyright notice and this permission notice shall be
* included in all copies or substantial portions of the Software.
*
* THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND,
* EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF
* MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND
* NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE
* LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION
* OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION
* WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE.
*
*/
package org.slf4j.simple.multiThreadedExecution;

import java.io.PrintStream;
import java.util.ArrayList;
import java.util.Collections;
import java.util.List;
import java.util.regex.Pattern;

public class StateCheckingPrintStream extends PrintStream {

enum State {
INITIAL, UNKNOWN, HELLO, THROWABLE, AT1, AT2, OTHER;
}

PrintStream other;

This comment has been minimized.

Copy link
@Tibor17

Tibor17 Jul 8, 2021

This is never used.


List<String> stringList = Collections.synchronizedList(new ArrayList<String>());

This comment has been minimized.

Copy link
@Tibor17

Tibor17 Jul 8, 2021

Pls use Java's COWAL to be on Java 1.5+.
Pls make the field private final to satisfy JSR-133.


State currentState = State.INITIAL;

This comment has been minimized.

Copy link
@Tibor17

Tibor17 Jul 8, 2021

Perhaps private volatile field.


public StateCheckingPrintStream(PrintStream ps) {
super(ps);
}

public void print(String s) {
}

public void println(String s) {

State next = computeState(s);
//System.out.println(next + " " + s);
switch (currentState) {
case INITIAL:
currentState = next;
break;

case UNKNOWN:
currentState = next;
break;

case OTHER:
if (next == State.UNKNOWN) {
currentState = State.UNKNOWN;
return;
}

if (next != State.OTHER && next != State.HELLO) {
throw badState(s, currentState, next);
}
currentState = next;
break;

case HELLO:
if (next != State.THROWABLE) {
throw badState(s, currentState, next);
}
currentState = next;
break;
case THROWABLE:
if (next != State.AT1) {
throw badState(s, currentState, next);
}
currentState = next;
break;

case AT1:
if (next != State.AT2) {
throw badState(s, currentState, next);
}
currentState = next;
break;

case AT2:
currentState = next;
break;
default:
throw new IllegalStateException("Unreachable code");
}

stringList.add(s);
}

private IllegalStateException badState(String s, State currentState2, State next) {
return new IllegalStateException("Unexpected state " + next + " for current state " + currentState2 + " for " + s);

}

String OTHER_PATTERN_STR = ".*Other \\d{1,5}";
String HELLO_PATTERN_STR = ".*Hello \\d{1,5}";
String THROWABLE_PATTERN_STR = "java.lang.Throwable: i=\\d{1,5}";
String AT1_PATTERN_STR = "\\s*at " + this.getClass().getPackage().getName() + ".*";
String AT2_PATTERN_STR = "\\s*at " + ".*Thread.java.*";

Pattern PATTERN_OTHER = Pattern.compile(OTHER_PATTERN_STR);
Pattern PATTERN_HELLO = Pattern.compile(HELLO_PATTERN_STR);
Pattern PATTERN_THROWABLE = Pattern.compile(THROWABLE_PATTERN_STR);
Pattern PATTERN_AT1 = Pattern.compile(AT1_PATTERN_STR);
Pattern PATTERN_AT2 = Pattern.compile(AT2_PATTERN_STR);

private State computeState(String s) {

if (PATTERN_OTHER.matcher(s).matches()) {
return State.OTHER;
} else if (PATTERN_HELLO.matcher(s).matches()) {
return State.HELLO;
} else if (PATTERN_THROWABLE.matcher(s).matches()) {
return State.THROWABLE;
} else if (PATTERN_AT1.matcher(s).matches()) {
return State.AT1;
} else if (PATTERN_AT2.matcher(s).matches()) {
return State.AT2;
} else {
return State.UNKNOWN;
}
}

public void println(Object o) {
println(o.toString());
}
}

0 comments on commit 816da3d

Please sign in to comment.