add slf4j via log4j 2 logging

This commit is contained in:
2017-02-05 09:53:25 +01:00
parent 175a866c90
commit 3722ba02b1
5 changed files with 61 additions and 22 deletions

View File

@@ -6,6 +6,7 @@ import java.io.InputStreamReader;
import java.io.PrintWriter; import java.io.PrintWriter;
import java.net.ServerSocket; import java.net.ServerSocket;
import java.net.Socket; import java.net.Socket;
import java.net.SocketAddress;
import java.net.SocketTimeoutException; import java.net.SocketTimeoutException;
import java.nio.file.Path; import java.nio.file.Path;
import java.time.OffsetDateTime; import java.time.OffsetDateTime;
@@ -23,6 +24,9 @@ import org.lucares.pdb.api.Entry;
import org.lucares.pdb.api.Tags; import org.lucares.pdb.api.Tags;
import org.lucares.performance.db.BlockingQueueIterator; import org.lucares.performance.db.BlockingQueueIterator;
import org.lucares.performance.db.PerformanceDb; import org.lucares.performance.db.PerformanceDb;
import org.lucares.performance.db.ingestor.TcpIngestorTest;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import com.fasterxml.jackson.core.type.TypeReference; import com.fasterxml.jackson.core.type.TypeReference;
import com.fasterxml.jackson.databind.MappingIterator; import com.fasterxml.jackson.databind.MappingIterator;
@@ -30,6 +34,7 @@ import com.fasterxml.jackson.databind.ObjectMapper;
import com.fasterxml.jackson.databind.ObjectReader; import com.fasterxml.jackson.databind.ObjectReader;
public class TcpIngestor implements AutoCloseable { public class TcpIngestor implements AutoCloseable {
private static final Logger LOGGER = LoggerFactory.getLogger(TcpIngestorTest.class);
public static final int PORT = 17347; public static final int PORT = 17347;
@@ -58,8 +63,9 @@ public class TcpIngestor implements AutoCloseable {
@Override @Override
public Void call() throws Exception { public Void call() throws Exception {
Thread.currentThread().setName("worker-" + clientSocket.getInetAddress()); final SocketAddress clientAddress = clientSocket.getRemoteSocketAddress();
System.out.println("opening streams to client"); Thread.currentThread().setName("worker-" + clientAddress);
LOGGER.info("opening streams to client");
try (PrintWriter out = new PrintWriter(clientSocket.getOutputStream(), true); try (PrintWriter out = new PrintWriter(clientSocket.getOutputStream(), true);
BufferedReader in = new BufferedReader(new InputStreamReader(clientSocket.getInputStream())); BufferedReader in = new BufferedReader(new InputStreamReader(clientSocket.getInputStream()));
@@ -69,11 +75,11 @@ public class TcpIngestor implements AutoCloseable {
double duration = 0.0; double duration = 0.0;
int count = 0; int count = 0;
System.out.println("reading from stream"); LOGGER.info("reading from stream");
while (iterator.hasNext()) { while (iterator.hasNext()) {
final long start = System.nanoTime(); final long start = System.nanoTime();
// System.out.println("read: " + line); // LOGGER.info("read: " + line);
@SuppressWarnings("unchecked") @SuppressWarnings("unchecked")
final Map<String, Object> object = (Map<String, Object>) iterator.next(); final Map<String, Object> object = (Map<String, Object>) iterator.next();
@@ -83,7 +89,7 @@ public class TcpIngestor implements AutoCloseable {
count++; count++;
if (count == 100000) { if (count == 100000) {
// System.out.println("reading " + count + " took " + // LOGGER.info("reading " + count + " took " +
// duration + "ms"); // duration + "ms");
duration = 0.0; duration = 0.0;
count = 0; count = 0;
@@ -94,7 +100,7 @@ public class TcpIngestor implements AutoCloseable {
} }
} }
System.out.println("connection closed"); LOGGER.info("connection closed: " + clientAddress);
} }
return null; return null;
@@ -148,9 +154,9 @@ public class TcpIngestor implements AutoCloseable {
} }
public TcpIngestor(final Path dataDirectory) { public TcpIngestor(final Path dataDirectory) {
System.out.println("opening performance db: " + dataDirectory); LOGGER.info("opening performance db: " + dataDirectory);
db = new PerformanceDb(dataDirectory); db = new PerformanceDb(dataDirectory);
System.out.println("performance db open"); LOGGER.info("performance db open");
} }
public void start() throws Exception { public void start() throws Exception {
@@ -179,17 +185,17 @@ public class TcpIngestor implements AutoCloseable {
Thread.currentThread().setName("socket-listener"); Thread.currentThread().setName("socket-listener");
try (ServerSocket serverSocket = new ServerSocket( try (ServerSocket serverSocket = new ServerSocket(
PORT/* , 10, InetAddress.getLocalHost() */);) { PORT/* , 10, InetAddress.getLocalHost() */);) {
System.out.println("listening on port " + PORT); LOGGER.info("listening on port " + PORT);
serverSocket.setSoTimeout((int) TimeUnit.MILLISECONDS.toMillis(100)); serverSocket.setSoTimeout((int) TimeUnit.MILLISECONDS.toMillis(100));
while (acceptNewConnections.get()) { while (acceptNewConnections.get()) {
try { try {
final Socket clientSocket = serverSocket.accept(); final Socket clientSocket = serverSocket.accept();
System.out.println("accepted connection: " + clientSocket.getRemoteSocketAddress()); LOGGER.info("accepted connection: " + clientSocket.getRemoteSocketAddress());
workerThreadPool.submit(new Handler(clientSocket, queue)); workerThreadPool.submit(new Handler(clientSocket, queue));
System.out.println("handler submitted"); LOGGER.info("handler submitted");
} catch (final SocketTimeoutException e) { } catch (final SocketTimeoutException e) {
// expected every 100ms // expected every 100ms
// needed to be able to stop the server // needed to be able to stop the server
@@ -197,20 +203,20 @@ public class TcpIngestor implements AutoCloseable {
e.printStackTrace(); e.printStackTrace();
} }
} }
System.out.println("not accepting new connections. "); LOGGER.info("not accepting new connections. ");
System.out.println("stopping worker pool"); LOGGER.info("stopping worker pool");
workerThreadPool.shutdown(); workerThreadPool.shutdown();
try { try {
workerThreadPool.awaitTermination(10, TimeUnit.MINUTES); workerThreadPool.awaitTermination(10, TimeUnit.MINUTES);
System.out.println("workers stopped"); LOGGER.info("workers stopped");
} catch (final InterruptedException e) { } catch (final InterruptedException e) {
e.printStackTrace(); e.printStackTrace();
} }
System.out.println("adding poison"); LOGGER.info("adding poison");
queue.offer(Entry.POISON); queue.offer(Entry.POISON);
} catch (final Exception e) { } catch (final Exception e) {
e.printStackTrace(); LOGGER.error("", e);
throw e; throw e;
} }
return null; return null;
@@ -219,16 +225,16 @@ public class TcpIngestor implements AutoCloseable {
@Override @Override
public void close() { public void close() {
acceptNewConnections.set(false); acceptNewConnections.set(false);
System.out.println("stopped accept thread"); LOGGER.info("stopped accept thread");
serverThreadPool.shutdown(); serverThreadPool.shutdown();
try { try {
serverThreadPool.awaitTermination(10, TimeUnit.MINUTES); serverThreadPool.awaitTermination(10, TimeUnit.MINUTES);
} catch (final InterruptedException e) { } catch (final InterruptedException e) {
e.printStackTrace(); Thread.interrupted();
} }
System.out.println("closing database"); LOGGER.info("closing database");
db.close(); db.close();
System.out.println("close done"); LOGGER.info("close done");
} }
public static void main(final String[] args) throws Exception { public static void main(final String[] args) throws Exception {
@@ -236,7 +242,7 @@ public class TcpIngestor implements AutoCloseable {
Runtime.getRuntime().addShutdownHook(new Thread() { Runtime.getRuntime().addShutdownHook(new Thread() {
@Override @Override
public void run() { public void run() {
System.out.println("shutdown hook"); LOGGER.info("shutdown hook");
} }
}); });

View File

@@ -20,6 +20,8 @@ import org.lucares.pdb.api.Entry;
import org.lucares.performance.db.FileUtils; import org.lucares.performance.db.FileUtils;
import org.lucares.performance.db.PerformanceDb; import org.lucares.performance.db.PerformanceDb;
import org.lucares.recommind.logs.TcpIngestor; import org.lucares.recommind.logs.TcpIngestor;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.testng.Assert; import org.testng.Assert;
import org.testng.annotations.AfterMethod; import org.testng.annotations.AfterMethod;
import org.testng.annotations.BeforeMethod; import org.testng.annotations.BeforeMethod;
@@ -31,6 +33,9 @@ import liquibase.exception.LiquibaseException;
@Test @Test
public class TcpIngestorTest { public class TcpIngestorTest {
private static final Logger LOGGER = LoggerFactory.getLogger(TcpIngestorTest.class);
private Path dataDirectory; private Path dataDirectory;
@BeforeMethod @BeforeMethod
@@ -67,7 +72,7 @@ public class TcpIngestorTest {
send(entryA, entryB); send(entryA, entryB);
} catch (final Exception e) { } catch (final Exception e) {
e.printStackTrace(); LOGGER.error("", e);
throw e; throw e;
} }
@@ -100,6 +105,7 @@ public class TcpIngestorTest {
channel.write(src); channel.write(src);
channel.close(); channel.close();
LOGGER.trace("closed sender connection");
} }
private SocketChannel connect() throws IOException { private SocketChannel connect() throws IOException {

View File

@@ -3,4 +3,10 @@ dependencies {
compile project(':pdb-api') compile project(':pdb-api')
compile 'org.lucares:ludb:1.0.20170101101722' compile 'org.lucares:ludb:1.0.20170101101722'
compile 'com.fasterxml.jackson.core:jackson-databind:2.8.6' compile 'com.fasterxml.jackson.core:jackson-databind:2.8.6'
compile 'org.apache.logging.log4j:log4j-api:2.8'
compile 'org.apache.logging.log4j:log4j-core:2.8'
compile group: 'org.apache.logging.log4j', name: 'log4j-slf4j-impl', version: '2.8'
} }

View File

@@ -3,8 +3,13 @@ package org.lucares.performance.db;
import java.util.Optional; import java.util.Optional;
import java.util.concurrent.BlockingQueue; import java.util.concurrent.BlockingQueue;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public final class BlockingQueueIterator<E> implements BlockingIterator<E> { public final class BlockingQueueIterator<E> implements BlockingIterator<E> {
private static final Logger LOGGER = LoggerFactory.getLogger(BlockingQueueIterator.class);
private final BlockingQueue<E> queue; private final BlockingQueue<E> queue;
private boolean closed = false; private boolean closed = false;
@@ -23,9 +28,12 @@ public final class BlockingQueueIterator<E> implements BlockingIterator<E> {
return Optional.empty(); return Optional.empty();
} }
LOGGER.trace("wait for next entry");
final E next = queue.take(); final E next = queue.take();
LOGGER.trace("received entry: {}", next);
if (next == poison) { if (next == poison) {
LOGGER.trace("received poison");
closed = true; closed = true;
return Optional.empty(); return Optional.empty();
} }

View File

@@ -0,0 +1,13 @@
name = PropertiesConfig
appenders = console
appender.console.type = Console
appender.console.name = STDOUT
appender.console.layout.type = PatternLayout
appender.console.layout.pattern = %d{yyyy-MM-dd HH:mm:ss.SSS} [%-5level] [%t] %c{1} - %msg%n
rootLogger.level = trace
rootLogger.appenderRef.stdout.ref = STDOUT