batch entries between TcpIngestor and PerformanceDB

One bottleneck was the blocking queue used to transport entries
from the listener thread to the ingestor thread.
Reduced the bottleneck by batching entries.
Interestingly the batch size of 100 was better than batch size
of 1000 and better than 10.
This commit is contained in:
2018-12-21 13:11:35 +01:00
parent 73ad27ab96
commit d95a71e32e
5 changed files with 121 additions and 47 deletions

View File

@@ -0,0 +1,42 @@
package org.lucares.pdb.api;
import java.util.ArrayList;
import java.util.Arrays;
import java.util.Collection;
import java.util.Iterator;
import java.util.List;
public class Entries implements Iterable<Entry> {
/**
* A special {@link Entries} instance that can be used as poison object for
* {@link BlockingQueueIterator}.
*/
public static final Entries POISON = new Entries(0);
private final List<Entry> entries;
public Entries(final int initialSize) {
entries = new ArrayList<>(initialSize);
}
public Entries(final Entry... entries) {
this.entries = new ArrayList<>(Arrays.asList(entries));
}
public Entries(final Collection<Entry> entries) {
this.entries = new ArrayList<>(entries);
}
public void add(final Entry entry) {
entries.add(entry);
}
@Override
public Iterator<Entry> iterator() {
return entries.iterator();
}
public int size() {
return entries.size();
}
}

View File

@@ -7,12 +7,6 @@ import java.time.format.DateTimeFormatter;
public class Entry { public class Entry {
/**
* A special {@link Entry} that can be used as poison object for
* {@link BlockingQueueIterator}.
*/
public static final Entry POISON = new Entry(Long.MIN_VALUE, -1, null);
private final long value; private final long value;
private final Tags tags; private final Tags tags;
@@ -39,9 +33,6 @@ public class Entry {
@Override @Override
public String toString() { public String toString() {
if (this == POISON) {
return "POISON ENTRY";
}
final OffsetDateTime date = Instant.ofEpochMilli(epochMilli).atOffset(ZoneOffset.UTC); final OffsetDateTime date = Instant.ofEpochMilli(epochMilli).atOffset(ZoneOffset.UTC);
return date.format(DateTimeFormatter.ISO_ZONED_DATE_TIME) + " = " + value + " (" + tags.asString() + ")"; return date.format(DateTimeFormatter.ISO_ZONED_DATE_TIME) + " = " + value + " (" + tags.asString() + ")";

View File

@@ -20,6 +20,7 @@ import java.util.regex.Pattern;
import javax.annotation.PreDestroy; import javax.annotation.PreDestroy;
import org.lucares.pdb.api.Entries;
import org.lucares.pdb.api.Entry; import org.lucares.pdb.api.Entry;
import org.lucares.performance.db.BlockingQueueIterator; import org.lucares.performance.db.BlockingQueueIterator;
import org.lucares.performance.db.PerformanceDb; import org.lucares.performance.db.PerformanceDb;
@@ -50,9 +51,9 @@ public class TcpIngestor implements Ingestor, AutoCloseable, DisposableBean {
public final static class Handler implements Callable<Void> { public final static class Handler implements Callable<Void> {
final Socket clientSocket; final Socket clientSocket;
private final ArrayBlockingQueue<Entry> queue; private final ArrayBlockingQueue<Entries> queue;
public Handler(final Socket clientSocket, final ArrayBlockingQueue<Entry> queue) { public Handler(final Socket clientSocket, final ArrayBlockingQueue<Entries> queue) {
this.clientSocket = clientSocket; this.clientSocket = clientSocket;
this.queue = queue; this.queue = queue;
} }
@@ -67,6 +68,9 @@ public class TcpIngestor implements Ingestor, AutoCloseable, DisposableBean {
final LineToEntryTransformer transformer; final LineToEntryTransformer transformer;
LOGGER.debug("reading from stream"); LOGGER.debug("reading from stream");
final int chunksize = 100;
Entries entries = new Entries(chunksize);
String line; String line;
// determine stream type (json or csv) // determine stream type (json or csv)
@@ -76,7 +80,7 @@ public class TcpIngestor implements Ingestor, AutoCloseable, DisposableBean {
final Optional<Entry> entry = transformer.toEntry(line); final Optional<Entry> entry = transformer.toEntry(line);
if (entry.isPresent()) { if (entry.isPresent()) {
LOGGER.debug("adding entry to queue: {}", entry); LOGGER.debug("adding entry to queue: {}", entry);
queue.put(entry.get()); entries.add(entry.get());
} }
} else { } else {
final String[] columnHeaders = line.split(Pattern.quote(",")); final String[] columnHeaders = line.split(Pattern.quote(","));
@@ -90,12 +94,18 @@ public class TcpIngestor implements Ingestor, AutoCloseable, DisposableBean {
if (entry.isPresent()) { if (entry.isPresent()) {
LOGGER.debug("adding entry to queue: {}", entry); LOGGER.debug("adding entry to queue: {}", entry);
queue.put(entry.get()); entries.add(entry.get());
} }
} catch (final JsonParseException e) { } catch (final JsonParseException e) {
LOGGER.info("json parse error in line '" + line + "'", e); LOGGER.info("json parse error in line '" + line + "'", e);
} }
if (entries.size() == chunksize) {
queue.put(entries);
entries = new Entries(chunksize);
} }
}
queue.put(entries);
LOGGER.debug("connection closed: " + clientAddress); LOGGER.debug("connection closed: " + clientAddress);
} catch (final Throwable e) { } catch (final Throwable e) {
LOGGER.warn("Stream handling failed", e); LOGGER.warn("Stream handling failed", e);
@@ -121,7 +131,7 @@ public class TcpIngestor implements Ingestor, AutoCloseable, DisposableBean {
@Override @Override
public void start() throws Exception { public void start() throws Exception {
final ArrayBlockingQueue<Entry> queue = new ArrayBlockingQueue<>(10_000); final ArrayBlockingQueue<Entries> queue = new ArrayBlockingQueue<>(10);
serverThreadPool.submit(() -> { serverThreadPool.submit(() -> {
Thread.currentThread().setName("db-ingestion"); Thread.currentThread().setName("db-ingestion");
@@ -129,7 +139,7 @@ public class TcpIngestor implements Ingestor, AutoCloseable, DisposableBean {
boolean finished = false; boolean finished = false;
while (!finished) { while (!finished) {
try { try {
db.putEntries(new BlockingQueueIterator<>(queue, Entry.POISON)); db.putEntries(new BlockingQueueIterator<>(queue, Entries.POISON));
finished = true; finished = true;
} catch (final Exception e) { } catch (final Exception e) {
LOGGER.warn("Write to database failed. Will retry with the next element.", e); LOGGER.warn("Write to database failed. Will retry with the next element.", e);
@@ -141,12 +151,12 @@ public class TcpIngestor implements Ingestor, AutoCloseable, DisposableBean {
serverThreadPool.submit(() -> listen(queue)); serverThreadPool.submit(() -> listen(queue));
} }
private Void listen(final ArrayBlockingQueue<Entry> queue) throws IOException { private Void listen(final ArrayBlockingQueue<Entries> queue) throws IOException {
Thread.currentThread().setName("socket-listener"); Thread.currentThread().setName("socket-listener");
try (ServerSocket serverSocket = new ServerSocket(PORT);) { try (ServerSocket serverSocket = new ServerSocket(PORT);) {
LOGGER.info("listening on port " + PORT); LOGGER.info("listening on port " + PORT);
serverSocket.setSoTimeout((int) TimeUnit.MILLISECONDS.toMillis(100)); serverSocket.setSoTimeout((int) TimeUnit.MILLISECONDS.toMillis(2));
while (acceptNewConnections.get()) { while (acceptNewConnections.get()) {
try { try {
@@ -174,7 +184,7 @@ public class TcpIngestor implements Ingestor, AutoCloseable, DisposableBean {
Thread.interrupted(); Thread.interrupted();
} }
LOGGER.debug("adding poison"); LOGGER.debug("adding poison");
queue.put(Entry.POISON); queue.put(Entries.POISON);
} catch (final InterruptedException e) { } catch (final InterruptedException e) {
LOGGER.info("Listener thread interrupted. Likely while adding the poison. " LOGGER.info("Listener thread interrupted. Likely while adding the poison. "
+ "That would mean that the db-ingestion thread will not terminate. "); + "That would mean that the db-ingestion thread will not terminate. ");

View File

@@ -0,0 +1,26 @@
package org.lucares.performance.db;
import java.util.Iterator;
import org.lucares.pdb.api.Entries;
import org.lucares.pdb.api.Entry;
public class EntryToEntriesIterator implements Iterator<Entries> {
private final Iterator<Entry> entryIterator;
public EntryToEntriesIterator(final Iterator<Entry> entryIterator) {
this.entryIterator = entryIterator;
}
@Override
public boolean hasNext() {
return entryIterator.hasNext();
}
@Override
public Entries next() {
return new Entries(entryIterator.next());
}
}

View File

@@ -12,6 +12,7 @@ import java.util.SortedSet;
import java.util.stream.Stream; import java.util.stream.Stream;
import org.lucares.collections.LongList; import org.lucares.collections.LongList;
import org.lucares.pdb.api.Entries;
import org.lucares.pdb.api.Entry; import org.lucares.pdb.api.Entry;
import org.lucares.pdb.api.GroupResult; import org.lucares.pdb.api.GroupResult;
import org.lucares.pdb.api.Result; import org.lucares.pdb.api.Result;
@@ -37,21 +38,22 @@ public class PerformanceDb implements AutoCloseable {
tagsToFile = new TagsToFile(dataStore); tagsToFile = new TagsToFile(dataStore);
} }
public void putEntry(final Entry entry) throws WriteException { void putEntry(final Entry entry) throws WriteException {
putEntries(Arrays.asList(entry)); putEntries(Arrays.asList(entry));
} }
public void putEntries(final Iterable<Entry> entries) throws WriteException { void putEntries(final Iterable<Entry> entries) throws WriteException {
putEntries(entries.iterator()); putEntries(entries.iterator());
} }
public void putEntries(final Iterator<Entry> entries) throws WriteException { private void putEntries(final Iterator<Entry> entries) throws WriteException {
final BlockingIteratorIterator<Entry> iterator = new BlockingIteratorIterator<>(entries); final EntryToEntriesIterator entriesIterator = new EntryToEntriesIterator(entries);
final BlockingIteratorIterator<Entries> iterator = new BlockingIteratorIterator<>(entriesIterator);
putEntries(iterator); putEntries(iterator);
} }
public void putEntries(final BlockingIterator<Entry> entries) throws WriteException { public void putEntries(final BlockingIterator<Entries> entriesIterator) throws WriteException {
final Duration timeBetweenSyncs = Duration.ofSeconds(1); final Duration timeBetweenSyncs = Duration.ofSeconds(1);
long count = 0; long count = 0;
@@ -62,13 +64,15 @@ public class PerformanceDb implements AutoCloseable {
long nextSync = lastSync + timeBetweenSyncs.toMillis(); long nextSync = lastSync + timeBetweenSyncs.toMillis();
while (true) { while (true) {
final Optional<Entry> entryOptional = entries.next(); final Optional<Entries> entriesOptional = entriesIterator.next();
if (!entryOptional.isPresent()) { if (!entriesOptional.isPresent()) {
break; break;
} }
final Entry entry = entryOptional.get();
try {
final Entries entries = entriesOptional.get();
for (final Entry entry : entries) {
try {
final Tags tags = entry.getTags(); final Tags tags = entry.getTags();
final long dateAsEpochMilli = entry.getEpochMilli(); final long dateAsEpochMilli = entry.getEpochMilli();
@@ -83,8 +87,8 @@ public class PerformanceDb implements AutoCloseable {
final long duration = end - lastSync; final long duration = end - lastSync;
final long entriesPerSecond = (long) (insertionsSinceLastSync / (duration / 1000.0)); final long entriesPerSecond = (long) (insertionsSinceLastSync / (duration / 1000.0));
METRICS_LOGGER.debug( METRICS_LOGGER.debug(String.format("inserting %d/s ; total: %,d; last: %s",
String.format("inserting %d/s ; total: %,d; last: %s", entriesPerSecond, count, entry)); entriesPerSecond, count, entry));
lastSync = System.currentTimeMillis(); lastSync = System.currentTimeMillis();
nextSync = lastSync + timeBetweenSyncs.toMillis(); nextSync = lastSync + timeBetweenSyncs.toMillis();
@@ -97,6 +101,7 @@ public class PerformanceDb implements AutoCloseable {
LOGGER.info("", e); LOGGER.info("", e);
} }
} }
}
} catch (final RuntimeException e) { } catch (final RuntimeException e) {
throw new WriteException(e); throw new WriteException(e);