Skip to content

Commit

Permalink
- Converted ProtPerfHelper to use strings instead of protocols
Browse files Browse the repository at this point in the history 
- Added perf numbers for TP.doSend() (https://issues.redhat.com/browse/JGRP-2801)
- Added rules to prot-perf.btm for queue-time and TP.doSend()
  • Loading branch information
@belaban
belaban committed May 22, 2024
1 parent 5c53271 commit 5b07172
Show file tree
Hide file tree
Showing 5 changed files with 161 additions and 30 deletions.
5 changes: 5 additions & 0 deletions bin/bm.sh
View file
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,11 @@ fi
PGM=$1
SCRIPT=$2

if [ ! -f $SCRIPT ]; then
echo "** Script $SCRIPT not found **"
exit 1
fi

SCRIPT_DIR=$( cd -- "$( dirname -- "${BASH_SOURCE[0]}" )" &> /dev/null && pwd )
LIB=`dirname $SCRIPT_DIR`/lib
BM_OPTS="-Dorg.jboss.byteman.compile.to.bytecode=true"
Expand Down
6 changes: 5 additions & 1 deletion bin/gen-profiling.sh
View file
Original file line number Diff line number Diff line change
@@ -1,4 +1,8 @@
#!/bin/bash

## Generates a byteman script for profile data
java org.jgroups.util.GenerateProfilingScript $*

# Add classpath of classes for which to generate rules, e.g.:
# java -cp "/Users/bela/IspnPerfTest/target/libs/*" org.jgroups.util.GenerateProfilingScript $*

java org.jgroups.util.GenerateProfilingScript $*
68 changes: 67 additions & 1 deletion conf/scripts/ProtPerf/prot-perf.btm
View file
Original file line number Diff line number Diff line change
Expand Up @@ -192,4 +192,70 @@ AT ENTRY
BIND msg=$1;
IF TRUE
DO setTime(msg, 0, true);
ENDRULE
ENDRULE

# Measures time for sending a message via TP.doSend()
RULE Begin TP.doSend()
CLASS ^TP
HELPER org.jgroups.util.ProtPerfHelper
COMPILE
METHOD doSend
AT ENTRY
BIND curr_thread=Thread.currentThread();
IF TRUE
DO link(curr_thread, System.nanoTime());
ENDRULE

RULE End TP.doSend()
CLASS ^TP
HELPER org.jgroups.util.ProtPerfHelper
COMPILE
METHOD doSend
AT EXIT
BIND curr_thread=Thread.currentThread();
cluster=$this.getClusterName();
start_time:Long=unlink(curr_thread);
diff:long=System.nanoTime() - start_time;
IF TRUE
DO downTime(cluster, "doSend", diff);
ENDRULE


# Measures the time from when a message is added to the TQB's queue (TQB.send()), until it is serialized (and then sent)
RULE Begin QueueTime
CLASS TransferQueueBundler
HELPER org.jgroups.util.ProtPerfHelper
COMPILE
METHOD send(Message)
AT ENTRY
BIND msg=$1;
IF TRUE
DO setTime(msg, true);
ENDRULE


RULE TransferQueueBundler.sendSingleMessage()
CLASS BaseBundler
HELPER org.jgroups.util.ProtPerfHelper
COMPILE
METHOD sendSingleMessage
AT ENTRY
BIND msg=$1;
cluster=$this.transport.getClusterName();
IF TRUE
DO System.out.println("-- sending single msg " + msg);
downTime(cluster, message, "tqb");
ENDRULE

RULE TransferQueueBundler.sendMessageList()
CLASS BaseBundler
HELPER org.jgroups.util.ProtPerfHelper
COMPILE
METHOD sendMessageList
AT ENTRY
BIND dest=$1;
cluster=$this.transport.getClusterName();
list=$3;
IF TRUE
DO downTime(cluster, list, "tqb");
ENDRULE
8 changes: 4 additions & 4 deletions src/org/jgroups/util/Util.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -2626,10 +2626,10 @@ public static String suffix(TimeUnit u) {
case NANOSECONDS: return "ns";
case MICROSECONDS: return "us";
case MILLISECONDS: return "ms";
case SECONDS: return "s";
case MINUTES: return "m";
case HOURS: return "h";
case DAYS: return "d";
case SECONDS: return "s ";
case MINUTES: return "m ";
case HOURS: return "h ";
case DAYS: return "d ";
default: return u.toString();
}
}
Expand Down
104 changes: 80 additions & 24 deletions tests/util/org/jgroups/util/ProtPerfHelper.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -7,7 +7,9 @@
import org.jgroups.protocols.TP;
import org.jgroups.stack.DiagnosticsHandler;
import org.jgroups.stack.Protocol;
import org.jgroups.stack.ProtocolStack;

import java.util.ArrayList;
import java.util.HashMap;
import java.util.List;
import java.util.Map;
Expand Down Expand Up @@ -48,11 +50,33 @@ public void downTime(Message msg, Protocol prot) {
if(prot != null && hdr.startDown() > 0) {
long time=System.nanoTime() - hdr.startDown(); // ns
if(time > 0)
ph.add(getClusterName(prot), prot.getClass(), time, true);
ph.add(getClusterName(prot), prot.getName(), time, true);
}
hdr.startDown(System.nanoTime());
}

@SuppressWarnings("MethodMayBeStatic")
public void downTime(String cluster, Message msg, String name) {
ProtPerfHeader hdr=getOrAddHeader(msg);
if(hdr.startDown() > 0) {
long time=System.nanoTime() - hdr.startDown(); // ns
if(time > 0)
ph.add(cluster, name, time, true);
}
hdr.startDown(System.nanoTime());
}

public void downTime(String cluster, List<Message> list, String name) {
for(Message msg: list)
downTime(cluster, msg, name);
}


@SuppressWarnings("MethodMayBeStatic")
public void downTime(String cluster, String name, long time) {
ph.add(cluster, name, time, true);
}



@SuppressWarnings("MethodMayBeStatic")
Expand All @@ -61,7 +85,7 @@ public void upTime(Message msg, Protocol prot) {
if(prot != null && hdr.startUp() > 0) {
long time=System.nanoTime() - hdr.startUp(); // ns
if(time > 0)
ph.add(getClusterName(prot), prot.getClass(), time, false);
ph.add(getClusterName(prot), prot.getName(), time, false);
}
hdr.startUp(System.nanoTime());
}
Expand All @@ -72,7 +96,7 @@ public void upTime(MessageBatch batch, Protocol prot) {
if(prot != null && batch.timestamp() > 0) {
long time=System.nanoTime() - batch.timestamp(); // ns
if(time > 0)
ph.add(getClusterName(prot), prot.getClass(), time, false);
ph.add(getClusterName(prot), prot.getName(), time, false);
}
batch.timestamp(System.nanoTime());
}
Expand Down Expand Up @@ -115,8 +139,8 @@ protected static ProtPerfHeader getOrAddHeader(Message msg) {


protected static class ProtPerfProbeHandler implements DiagnosticsHandler.ProbeHandler {
protected final Map<String,List<Class<? extends Protocol>>> ordering;
protected final Map<String,Map<Class<? extends Protocol>,Entry>> map;
protected final Map<String,List<String>> ordering;
protected final Map<String,Map<String,Entry>> map;

public ProtPerfProbeHandler() {
ordering=Util.createConcurrentMap(20);
Expand All @@ -125,8 +149,8 @@ public ProtPerfProbeHandler() {

public void addOrdering(TP transport) {
List<Protocol> protocols=transport.getProtocolStack().getProtocols();
List<Class<? extends Protocol>> classes=protocols.stream().map(Protocol::getClass).collect(Collectors.toList());
ordering.putIfAbsent(transport.getClusterName(), classes);
List<String> prot_names=protocols.stream().map(Protocol::getName).collect(Collectors.toList());
ordering.putIfAbsent(transport.getClusterName(), prot_names);
}

public Map<String,String> handleProbe(String... keys) {
Expand Down Expand Up @@ -158,7 +182,8 @@ else if(key.startsWith("perf"))
}

public String[] supportedKeys() {
return new String[]{"perf", "perf-down", "perf-up", "perf-down-detailed", "perf-up-detailed", "perf-reset"};
return new String[]{"perf", "perf-down", "perf-up", "perf-down-detailed", "perf-up-detailed",
"perf-reset", "perf-help"};
}

// perf-down=<clustername>: returns '<clustername>'
Expand All @@ -168,18 +193,18 @@ protected static String clusterSuffix(String key) {
return key.substring(index+1);
}

protected void add(String cluster, Class<? extends Protocol> clazz, long value, boolean down) {
protected void add(String cluster, String name, long value, boolean down) {
if(cluster == null)
cluster=DEFAULT;
Map<Class<? extends Protocol>,Entry> m=map.computeIfAbsent(cluster, k -> Util.createConcurrentMap(20));
Entry e=m.computeIfAbsent(clazz, cl -> new Entry());
Map<String,Entry> m=map.computeIfAbsent(cluster, k -> Util.createConcurrentMap(20));
Entry e=m.computeIfAbsent(name, cl -> new Entry());
e.add(value, down);
}

protected String dumpStats(String cluster, boolean down, boolean up, boolean detailed) {
if(cluster == null)
return dumpAllStacks(down, up, detailed);
Map<Class<? extends Protocol>,Entry> m=map.get(cluster);
Map<String,Entry> m=map.get(cluster);
return m != null ? dumpStats(cluster, m, down, up, detailed) : String.format("cluster '%s' not found", cluster);
}

Expand All @@ -189,30 +214,54 @@ protected String dumpAllStacks(boolean down, boolean up, boolean detailed) {
.collect(Collectors.joining("\n"));
}

protected String dumpStats(String cluster, Map<Class<? extends Protocol>,Entry> m,
boolean down, boolean up, boolean detailed) {
protected String dumpStats(String cluster, Map<String,Entry> m, boolean down, boolean up, boolean detailed) {
String format=String.format("%%-20s | %%%ds", detailed? 25 : 12);
double avg_down_sum=0, avg_up_sum=0;
List<Class<? extends Protocol>> order=ordering.get(cluster);
List<String> order=ordering.get(cluster);
if(order != null) {
List<String> other_keys=new ArrayList<>(m.keySet());
other_keys.removeAll(order);
other_keys.remove(ProtocolStack.class.getSimpleName());
StringBuilder sb=new StringBuilder("\n");
for(Class<? extends Protocol> cl: order) {
Entry e=m.get(cl);
for(String name: order) {
Entry e=m.get(name);
if(e != null) {
if(down)
avg_down_sum+=e.avg_down.getAverage();
else
avg_up_sum+=e.avg_up.getAverage();
}
sb.append(String.format("%-20s %s\n", cl.getSimpleName() + ":", e == null? "n/a" : e.toString(down,up,detailed)));
sb.append(String.format(format, name + ":", e == null? "n/a" : e.toString(down,up,detailed)));
sb.append("\n");
}
if(!other_keys.isEmpty()) {
for(String name: other_keys) {
Entry e=m.get(name);
if(e != null) {
if(down) {
if(e.avg_down.count() == 0)
continue;
avg_down_sum+=e.avg_down.getAverage();
}
else {
if(e.avg_up.count() == 0)
continue;
avg_up_sum+=e.avg_up.getAverage();
}
}
sb.append(String.format(format, " " + name + ":", e == null? " n/a" : e.toString(down,up,detailed)));
sb.append("\n");
}
}
sb.append("-".repeat(30));
sb.append(String.format("\n%-20s %s\n", "TOTAL" + ":",
sb.append("-".repeat(34)).append("\n");
sb.append(String.format(format, "TOTAL:",
down? printTime(avg_down_sum, NANOSECONDS) : printTime(avg_up_sum, NANOSECONDS)));
sb.append("\n");
return sb.toString();
}
else
return m.entrySet().stream()
.map(e -> String.format("%-20s %s", e.getKey().getSimpleName() + ":", e.getValue().toString(down, up, detailed)))
.map(e -> String.format(format, e.getKey() + ":", e.getValue().toString(down, up, detailed)))
.collect(Collectors.joining("\n"));
}

Expand Down Expand Up @@ -254,14 +303,21 @@ public String toString() {
}

public String toString(boolean down, boolean up, boolean detailed) {
return String.format("%s %s", down? print(avg_down, detailed) : "", up? print(avg_up, detailed) : "");
StringBuilder sb=new StringBuilder();
if(down)
sb.append(print(avg_down, detailed));
if(up) {
if(down)
sb.append(" ");
sb.append(print(avg_up, detailed));
}
return sb.toString();
}

public static String print(AverageMinMax avg, boolean detailed) {
return detailed?
avg.toString() :
String.format("%,.2f %s (%s)", avg.getAverage()/1000.0, "us",
String.format("%,d", avg.count()));
Util.printTime(avg.getAverage(), NANOSECONDS);
}
}
}

0 comments on commit 5b07172

Please sign in to comment.