Logging and output cleanup.

gradle.properties

@@ -1,3 +1,3 @@
 projectId               = jperf
 projectGroup            = biz.nellemann.jperf
-projectVersion          = 0.0.3
+projectVersion          = 0.0.4

src/main/java/biz/nellemann/jperf/Statistics.java

@@ -17,47 +17,82 @@ package biz.nellemann.jperf;
 
 import java.time.Duration;
 import java.time.Instant;
+import java.time.ZoneId;
+import java.time.format.DateTimeFormatter;
 
 public class Statistics {
 
+    private final int MAX_TICKS_AVG = 300;
+    private final int LOG_AVG_MODULO = 30;
+    private final DateTimeFormatter formatter = DateTimeFormatter.ofPattern("yyyy-MM-dd HH:mm:ss").withZone(ZoneId.systemDefault());
     private long packetsTransferred, packetsTransferredTotal = 0;
     private long bytesTransferred, bytesTransferredTotal = 0;
-    private long bytesPerSec, packesPerSec = 0;
+    private long bytesPerSec;
+    private long packetsPerSec;
     private long packetsUnacked = 0;
+    private int tickItererations = 0;
+
+    private final long[] bytesPerSecAvgTmp = new long[MAX_TICKS_AVG];
+    private final long[] packetsPerSecAvgTmp = new long[MAX_TICKS_AVG];
 
     private Instant timestamp1 = Instant.now();
-    private Instant timestamp2 = Instant.now();
 
 
     public void reset() {
         timestamp1 = Instant.now();
     }
 
+
     public void tick() {
 
-        timestamp2 = Instant.now();
+        Instant timestamp2 = Instant.now();
         if(Duration.between(timestamp1, timestamp2).toMillis() >= 1000) {
+
             // Because we do this every second ...
             bytesPerSec = bytesTransferred;
-            packesPerSec = packetsTransferred;
+            packetsPerSec = packetsTransferred;
+            bytesPerSecAvgTmp[tickItererations] = bytesTransferred;
+            packetsPerSecAvgTmp[tickItererations] = packetsTransferred;
+
             timestamp1 = timestamp2;
-            print();
+            printStatus();
+
             bytesTransferred = 0;
             packetsTransferred = 0;
+
+            if(++tickItererations >= MAX_TICKS_AVG) {
+                tickItererations = 0;
+            }
+
+            if(tickItererations % LOG_AVG_MODULO == 0) {
+                printAverage();
+            }
+
         }
 
-    }
-
-
-    public void print() {
-        System.out.printf("%-30s Status: %8d pkt/s %12d B/s %10d KB/s %8d MB/s\n", Instant.now().toString(), packesPerSec, bytesPerSec, bytesPerSec/1_000, bytesPerSec/1_000_000);
 
     }
 
-    public void summary() {
-        System.out.printf("%-29s Summary: %8d pkts %13d B %12d KB %10d MB %6d GB\n", Instant.now().toString(), packetsTransferredTotal, bytesTransferredTotal, bytesTransferredTotal /1_000, bytesTransferredTotal /1_000_000, bytesTransferredTotal/1_000_000_000);
+
+    public void printStatus() {
+        System.out.printf("%-19s -  Status: %10d pkt/s %14d B/s %12d KB/s %8d MB/s\n", formatter.format(Instant.now()), packetsPerSec, bytesPerSec, bytesPerSec/1_000, bytesPerSec/1_000_000);
+
     }
 
+
+    public void printSummary() {
+        System.out.println();
+        System.out.printf("%-19s - Summary: %10d pkts  %14d B   %12d KB   %8d MB   %8.2f GB\n", formatter.format(Instant.now()), packetsTransferredTotal, bytesTransferredTotal, bytesTransferredTotal /1_000, bytesTransferredTotal /1_000_000, (double) bytesTransferredTotal/1_000_000_000);
+    }
+
+
+    public void printAverage() {
+        long bytesPerSecAvg = getAverage(bytesPerSecAvgTmp, bytesTransferred);
+        long packetsPerSecAvg = getAverage(packetsPerSecAvgTmp, packetsTransferred);
+        System.out.printf("%-19s - Average: %10d pkt/s %14d B/s %12d KB/s %8d MB/s %8.2f GB/s\n", formatter.format(Instant.now()), packetsPerSecAvg, bytesPerSecAvg, bytesPerSecAvg /1_000, bytesPerSecAvg /1_000_000, (double) bytesPerSecAvg /1_000_000_000);
+    }
+
+
     public void ack() {
         packetsUnacked--;
     }
@@ -69,17 +104,51 @@ public class Statistics {
         packetsTransferredTotal++;
     }
 
+
     public void transferBytes(long bytes) {
         bytesTransferred += bytes;
         bytesTransferredTotal += bytes;
     }
 
+
     public long getPacketsUnacked() {
         return packetsUnacked;
     }
 
+
     public long getPacketsTransferredTotal() {
         return packetsTransferredTotal;
     }
 
+
+    private long getAverage(long[] array, long fallback) {
+        long avg = getAverage(array);
+        if(avg < 1) {
+            return fallback;
+        }
+        return avg;
+    }
+
+
+    private long getAverage(long[] array) {
+        if(array.length <= 1) {
+            return 0;
+        }
+        int len = 0;
+        long sum = 0;
+        for (long l : array) {
+            if(l > 0) {
+                sum += l;
+                len++;
+            }
+        }
+
+        long avg = 0;
+        if(len > 0) {
+            avg = sum / len;
+        }
+        return avg;
+    }
+
+
 }

src/main/java/biz/nellemann/jperf/UdpClient.java

@@ -35,19 +35,20 @@ public class UdpClient {
     private final InetAddress address;
     private final DatagramSocket socket;
 
-    private byte[] buf = new byte[256];
-
-    private int packetCount;
-    private int packetSize;
+    private final byte[] buf = new byte[256];
+    private final int packetCount;
+    private final int packetSize;
 
 
     public UdpClient(String hostname, int port, int packets, int size) throws UnknownHostException, SocketException {
         log.info("UdpClient() - target: {}, port: {}", hostname, port);
+
         this.port = port;
-        socket = new DatagramSocket();
-        address = InetAddress.getByName(hostname);
         this.packetCount = packets;
         this.packetSize = size;
+
+        socket = new DatagramSocket();
+        address = InetAddress.getByName(hostname);
         statistics = new Statistics();
     }
 
@@ -74,11 +75,10 @@ public class UdpClient {
 
         long sequence = 0;
 
-        // Start datagram
+        // Send handshake
         Datagram datagram = new Datagram(DataType.HANDSHAKE.getValue(), packetSize, sequence++, packetCount);
         send(datagram);
 
-        // TODO: Wait for ACK
         datagram = receive();
         if(datagram.getType() != DataType.ACK.getValue()) {
             log.warn("No ACK!");
@@ -111,7 +111,8 @@ public class UdpClient {
 
         Thread.sleep(100);
         close();
-        statistics.summary();
+        statistics.printAverage();
+        statistics.printSummary();
     }
 
 }

src/main/java/biz/nellemann/jperf/UdpServer.java

@@ -99,7 +99,8 @@ public class UdpServer extends Thread {
             statistics.tick();
             if(ackEnd && statistics.getPacketsTransferredTotal() > datagram.getMaxPkt()) {
                 running = false;
-                statistics.summary();
+                statistics.printAverage();
+                statistics.printSummary();
             }
 
 

src/main/resources/logback.xml

@@ -3,7 +3,7 @@
     <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
         <withJansi>false</withJansi>
         <encoder>
-            <pattern>%cyan(%d{HH:mm:ss.SSS}) %gray([%thread]) %highlight(%-5level) %magenta(%logger{32}) - %msg%n</pattern>
+            <pattern>%cyan(%d{yyyy-MM-dd HH:mm:ss.SSS}) %gray([%-10thread]) %highlight(%-5level) %magenta(%logger{12}) - %msg%n</pattern>
         </encoder>
     </appender>