X-Git-Url: https://git.opendaylight.org/gerrit/gitweb?a=blobdiff_plain;ds=sidebyside;f=opendaylight%2Fmd-sal%2Fsal-akka-segmented-journal%2Fsrc%2Fmain%2Fjava%2Forg%2Fopendaylight%2Fcontroller%2Fakka%2Fsegjournal%2FSegmentedJournalActor.java;fp=opendaylight%2Fmd-sal%2Fsal-akka-segmented-journal%2Fsrc%2Fmain%2Fjava%2Forg%2Fopendaylight%2Fcontroller%2Fakka%2Fsegjournal%2FSegmentedJournalActor.java;h=d440cbed1c9e73e967cfbd0509755d8d21b585df;hb=e81293b942432e0f55d70511f43e261ef5dfd0f8;hp=e5c5b7807b0b9ea016cdc4aa0835f49daf5ff8dd;hpb=069be3c07ba7649f5bb71bf8097cedc3555a40b0;p=controller.git

diff --git a/opendaylight/md-sal/sal-akka-segmented-journal/src/main/java/org/opendaylight/controller/akka/segjournal/SegmentedJournalActor.java b/opendaylight/md-sal/sal-akka-segmented-journal/src/main/java/org/opendaylight/controller/akka/segjournal/SegmentedJournalActor.java
index e5c5b7807b..d440cbed1c 100644
--- a/opendaylight/md-sal/sal-akka-segmented-journal/src/main/java/org/opendaylight/controller/akka/segjournal/SegmentedJournalActor.java
+++ b/opendaylight/md-sal/sal-akka-segmented-journal/src/main/java/org/opendaylight/controller/akka/segjournal/SegmentedJournalActor.java
@@ -19,6 +19,7 @@ import com.codahale.metrics.Meter;
 import com.codahale.metrics.MetricRegistry;
 import com.codahale.metrics.Timer;
 import com.google.common.base.MoreObjects;
+import com.google.common.base.Stopwatch;
 import io.atomix.storage.StorageLevel;
 import io.atomix.storage.journal.Indexed;
 import io.atomix.storage.journal.SegmentedJournal;
@@ -289,13 +290,16 @@ final class SegmentedJournalActor extends AbstractActor {
     private void handleWriteMessages(final WriteMessages message) {
         ensureOpen();
 
-        final long startTicks = System.nanoTime();
+        final Stopwatch sw = Stopwatch.createStarted();
         final long start = dataJournal.lastWrittenSequenceNr();
+        final long bytes = dataJournal.handleWriteMessages(message);
+        sw.stop();
 
-        dataJournal.handleWriteMessages(message);
-
-        batchWriteTime.update(System.nanoTime() - startTicks, TimeUnit.NANOSECONDS);
+        batchWriteTime.update(sw.elapsed(TimeUnit.NANOSECONDS), TimeUnit.NANOSECONDS);
         messageWriteCount.mark(dataJournal.lastWrittenSequenceNr() - start);
+
+        // log message after statistics are updated
+        LOG.debug("{}: write of {} bytes completed in {}", persistenceId, bytes, sw);
     }
 
     private void handleUnknown(final Object message) {
@@ -308,6 +312,7 @@ final class SegmentedJournalActor extends AbstractActor {
             return;
         }
 
+        final Stopwatch sw = Stopwatch.createStarted();
         deleteJournal = SegmentedJournal.<Long>builder().withDirectory(directory).withName("delete")
                 .withNamespace(DELETE_NAMESPACE).withMaxSegmentSize(DELETE_SEGMENT_SIZE).build();
         final Indexed<Long> lastEntry = deleteJournal.writer().getLastEntry();
@@ -316,7 +321,7 @@ final class SegmentedJournalActor extends AbstractActor {
         dataJournal = new DataJournalV0(persistenceId, messageSize, context().system(), storage, directory,
             maxEntrySize, maxSegmentSize);
         dataJournal.deleteTo(lastDelete);
-        LOG.debug("{}: journal open with last index {}, deleted to {}", persistenceId,
+        LOG.debug("{}: journal open in {} with last index {}, deleted to {}", persistenceId, sw,
             dataJournal.lastWrittenSequenceNr(), lastDelete);
     }
 }