Adding Perl script to analyze run results, adding feature of message file and determining if Announce needs to be repeated
This commit is contained in:
parent
cd7c41f898
commit
48e9aac047
2 changed files with 284 additions and 6 deletions
|
|
@ -44,6 +44,9 @@ running = True
|
|||
active_links = {}
|
||||
active_links_lock = threading.Lock()
|
||||
temporary_config_dir = None
|
||||
message_file_text = None
|
||||
message_file_path = None
|
||||
message_chunk_size = 900
|
||||
|
||||
|
||||
|
||||
|
|
@ -54,6 +57,23 @@ def log(msg):
|
|||
print(f"[{timestamp}.{milliseconds:03d}] {msg}", flush=True)
|
||||
|
||||
|
||||
def normalise_argv(argv):
|
||||
normalised = [argv[0]]
|
||||
key_value_args = {
|
||||
"message_file": "--message-file",
|
||||
"message-file": "--message-file",
|
||||
}
|
||||
|
||||
for arg in argv[1:]:
|
||||
key, separator, value = arg.partition("=")
|
||||
if separator and key in key_value_args:
|
||||
normalised.extend([key_value_args[key], value])
|
||||
else:
|
||||
normalised.append(arg)
|
||||
|
||||
return normalised
|
||||
|
||||
|
||||
def stop(_signum=None, _frame=None):
|
||||
global running
|
||||
running = False
|
||||
|
|
@ -248,6 +268,63 @@ def send_link_packet(link, text):
|
|||
RNS.Packet(link, payload, create_receipt=False).send()
|
||||
|
||||
|
||||
def active_link_count():
|
||||
with active_links_lock:
|
||||
links = list(active_links.values())
|
||||
|
||||
return sum(1 for link in links if link.status == RNS.Link.ACTIVE)
|
||||
|
||||
|
||||
def load_message_file(path):
|
||||
expanded_path = os.path.abspath(os.path.expanduser(path))
|
||||
with open(expanded_path, "r", encoding="utf-8") as file_handle:
|
||||
return expanded_path, file_handle.read()
|
||||
|
||||
|
||||
def utf8_chunks(text, max_bytes):
|
||||
chunk = ""
|
||||
chunk_bytes = 0
|
||||
|
||||
for character in text:
|
||||
character_bytes = len(character.encode("utf-8"))
|
||||
if chunk and chunk_bytes + character_bytes > max_bytes:
|
||||
yield chunk
|
||||
chunk = character
|
||||
chunk_bytes = character_bytes
|
||||
else:
|
||||
chunk += character
|
||||
chunk_bytes += character_bytes
|
||||
|
||||
if chunk:
|
||||
yield chunk
|
||||
|
||||
|
||||
def send_message_file(link):
|
||||
if message_file_text is None:
|
||||
return
|
||||
|
||||
chunks = list(utf8_chunks(message_file_text, message_chunk_size))
|
||||
total = max(1, len(chunks))
|
||||
total_bytes = len(message_file_text.encode("utf-8"))
|
||||
log(f"Sending file {message_file_path} as {total} chunk(s), {total_bytes} bytes")
|
||||
|
||||
for index, chunk_text in enumerate(chunks):
|
||||
if not running or link.status != RNS.Link.ACTIVE:
|
||||
return
|
||||
|
||||
send_link_packet(
|
||||
link,
|
||||
f"file_chunk {index + 1}/{total} from {NODE_NAME} "
|
||||
f"bytes={len(chunk_text.encode('utf-8'))} file={os.path.basename(message_file_path)} data={chunk_text}",
|
||||
)
|
||||
time.sleep(0.1)
|
||||
|
||||
|
||||
def start_message_file_sender(link):
|
||||
if message_file_text is not None:
|
||||
threading.Thread(target=send_message_file, args=(link,), daemon=True).start()
|
||||
|
||||
|
||||
def link_packet_received(message, packet):
|
||||
try:
|
||||
text = message.decode("utf-8", errors="replace")
|
||||
|
|
@ -276,6 +353,7 @@ def outbound_link_established(link):
|
|||
|
||||
log(f"Outbound link established: {key}")
|
||||
send_link_packet(link, f"hello from {NODE_NAME}")
|
||||
start_message_file_sender(link)
|
||||
|
||||
|
||||
def inbound_link_established(link):
|
||||
|
|
@ -288,6 +366,7 @@ def inbound_link_established(link):
|
|||
|
||||
log(f"Inbound link established: {key}")
|
||||
send_link_packet(link, f"hello back from {NODE_NAME}")
|
||||
start_message_file_sender(link)
|
||||
|
||||
|
||||
def direct_packet_received(data, packet):
|
||||
|
|
@ -295,10 +374,13 @@ def direct_packet_received(data, packet):
|
|||
log(f"RX direct packet: {text}")
|
||||
|
||||
|
||||
def announce_loop(destination, interval):
|
||||
def announce_loop(destination, interval, only_when_disconnected):
|
||||
while running:
|
||||
destination.announce(app_data=NODE_NAME.encode("utf-8"))
|
||||
log(f"Announced {RNS.prettyhexrep(destination.hash)} as {NODE_NAME}")
|
||||
if only_when_disconnected and active_link_count() > 0:
|
||||
log("Skipped announce because an active Reticulum link exists")
|
||||
else:
|
||||
destination.announce(app_data=NODE_NAME.encode("utf-8"))
|
||||
log(f"Announced {RNS.prettyhexrep(destination.hash)} as {NODE_NAME}")
|
||||
|
||||
for _ in range(interval):
|
||||
if not running:
|
||||
|
|
@ -375,6 +457,22 @@ def parse_args():
|
|||
parser.add_argument("--announce-interval", type=int, default=30)
|
||||
parser.add_argument("--send-interval", type=int, default=10)
|
||||
parser.add_argument("--path-timeout", type=int, default=120)
|
||||
parser.add_argument(
|
||||
"--message-file",
|
||||
default=None,
|
||||
help="Send this UTF-8 text file once per established link instead of periodic heartbeats",
|
||||
)
|
||||
parser.add_argument(
|
||||
"--message-chunk-size",
|
||||
type=int,
|
||||
default=900,
|
||||
help="Maximum UTF-8 bytes per file chunk packet",
|
||||
)
|
||||
parser.add_argument(
|
||||
"--announce-only-when-disconnected",
|
||||
action="store_true",
|
||||
help="Skip periodic announces while at least one Reticulum link is active",
|
||||
)
|
||||
|
||||
parser.add_argument(
|
||||
"--ble-role",
|
||||
|
|
@ -402,7 +500,10 @@ def parse_args():
|
|||
help="Reticulum log verbosity for this run",
|
||||
)
|
||||
|
||||
return parser.parse_args()
|
||||
args = parser.parse_args(normalise_argv(sys.argv)[1:])
|
||||
if args.message_chunk_size < 1:
|
||||
parser.error("--message-chunk-size must be at least 1")
|
||||
return args
|
||||
|
||||
|
||||
if __name__ == "__main__":
|
||||
|
|
@ -417,6 +518,9 @@ if __name__ == "__main__":
|
|||
NODE_NAME = args.name or socket.gethostname().split(".")[0]
|
||||
identity_path = args.identity or default_identity_path(args.config, NODE_NAME)
|
||||
reticulum_config = runtime_config_dir(args, NODE_NAME)
|
||||
message_chunk_size = args.message_chunk_size
|
||||
if args.message_file:
|
||||
message_file_path, message_file_text = load_message_file(args.message_file)
|
||||
|
||||
log(f"Starting node {NODE_NAME}")
|
||||
log(f"Reticulum config: {args.config or '~/.reticulum'}")
|
||||
|
|
@ -441,9 +545,17 @@ if __name__ == "__main__":
|
|||
|
||||
log(f"Destination hash: {RNS.prettyhexrep(destination.hash)}")
|
||||
log("Use this hash as --peer on the other node.")
|
||||
if message_file_text is not None:
|
||||
log(f"Message file mode: {message_file_path} ({len(message_file_text.encode('utf-8'))} bytes)")
|
||||
log("Periodic heartbeats are disabled in message file mode.")
|
||||
|
||||
threading.Thread(target=announce_loop, args=(destination, args.announce_interval), daemon=True).start()
|
||||
threading.Thread(target=heartbeat_loop, args=(args.send_interval,), daemon=True).start()
|
||||
threading.Thread(
|
||||
target=announce_loop,
|
||||
args=(destination, args.announce_interval, args.announce_only_when_disconnected),
|
||||
daemon=True,
|
||||
).start()
|
||||
if message_file_text is None:
|
||||
threading.Thread(target=heartbeat_loop, args=(args.send_interval,), daemon=True).start()
|
||||
|
||||
if args.peer:
|
||||
threading.Thread(target=connect_to_peer, args=(args.peer, args.path_timeout), daemon=True).start()
|
||||
|
|
|
|||
166
scripts/analyze_reticulum_latency.pl
Executable file
166
scripts/analyze_reticulum_latency.pl
Executable file
|
|
@ -0,0 +1,166 @@
|
|||
#!/usr/bin/env perl
|
||||
# ./analyze_reticulum_latency_20260516_0842.pl 20250516_0836_zerodev1.txt 20250516_0836_zerodev2.txt
|
||||
# chmod 755 analyze_reticulum_latency_20260516_0842.pl
|
||||
# 2026-05-16 ChatGPT
|
||||
# $Header$
|
||||
# $HeadURL$
|
||||
|
||||
use strict;
|
||||
use warnings;
|
||||
use POSIX qw(strftime);
|
||||
use Time::Local qw(timegm);
|
||||
use List::Util qw(min max sum);
|
||||
|
||||
my $usage = "Usage: $0 node1.log node2.log [more.log ...]\n";
|
||||
@ARGV >= 2 or die $usage;
|
||||
|
||||
my %mon = (
|
||||
Jan => 0, Feb => 1, Mar => 2, Apr => 3, May => 4, Jun => 5,
|
||||
Jul => 6, Aug => 7, Sep => 8, Oct => 9, Nov => 10, Dec => 11,
|
||||
);
|
||||
|
||||
my %tz_offset = (
|
||||
UTC => 0,
|
||||
GMT => 0,
|
||||
PST => -8 * 3600,
|
||||
PDT => -7 * 3600,
|
||||
);
|
||||
|
||||
my @rows;
|
||||
my %by_dir;
|
||||
|
||||
for my $file (@ARGV) {
|
||||
open my $fh, '<', $file or die "Cannot open $file: $!\n";
|
||||
|
||||
my $first = <$fh>;
|
||||
defined $first or die "Empty file: $file\n";
|
||||
chomp $first;
|
||||
|
||||
my ($year, $month, $day, $tz) = parse_log_date($first);
|
||||
my $receiver = receiver_from_filename($file);
|
||||
|
||||
while (my $line = <$fh>) {
|
||||
chomp $line;
|
||||
|
||||
# Example:
|
||||
# [08:33:11.753] RX link=<...>: hello from zerodev2 send_epoch=1778945591.644050
|
||||
next unless $line =~ /^\[(\d\d):(\d\d):(\d\d)\.(\d{3})\]\s+RX\s+.*?:\s+(.+?)\s+from\s+(\S+)\s+send_epoch=([0-9]+(?:\.[0-9]+)?)/;
|
||||
|
||||
my ($hh, $mi, $ss, $ms, $message, $sender, $send_epoch) = ($1, $2, $3, $4, $5, $6, $7);
|
||||
|
||||
my $recv_epoch = epoch_from_local_parts($year, $month, $day, $hh, $mi, $ss, $ms, $tz);
|
||||
my $latency = $recv_epoch - $send_epoch;
|
||||
|
||||
my $row = {
|
||||
file => $file,
|
||||
sender => $sender,
|
||||
receiver => $receiver,
|
||||
message => $message,
|
||||
send_epoch => $send_epoch + 0.0,
|
||||
recv_epoch => $recv_epoch + 0.0,
|
||||
latency => $latency + 0.0,
|
||||
line => $line,
|
||||
};
|
||||
|
||||
push @rows, $row;
|
||||
push @{ $by_dir{"$sender->$receiver"} }, $row;
|
||||
}
|
||||
|
||||
close $fh;
|
||||
}
|
||||
|
||||
if (!@rows) {
|
||||
die "No RX lines with send_epoch= were found. Add send_epoch to the payload before running this analyzer.\n";
|
||||
}
|
||||
|
||||
print "Reticulum BLE latency analysis\n";
|
||||
print "Generated: ", strftime('%Y-%m-%d %H:%M:%S %Z', localtime), "\n";
|
||||
print "Input files:\n";
|
||||
print " $_\n" for @ARGV;
|
||||
print "\n";
|
||||
|
||||
for my $dir (sort keys %by_dir) {
|
||||
my @lat = map { $_->{latency} } @{ $by_dir{$dir} };
|
||||
my $n = scalar @lat;
|
||||
my $mean = sum(@lat) / $n;
|
||||
my $median = percentile(50, @lat);
|
||||
my $p95 = percentile(95, @lat);
|
||||
my $stddev = stddev(@lat);
|
||||
|
||||
printf "Direction: %s\n", $dir;
|
||||
printf " samples : %d\n", $n;
|
||||
printf " min : %.6f s %.3f ms\n", min(@lat), min(@lat) * 1000.0;
|
||||
printf " median : %.6f s %.3f ms\n", $median, $median * 1000.0;
|
||||
printf " mean : %.6f s %.3f ms\n", $mean, $mean * 1000.0;
|
||||
printf " p95 : %.6f s %.3f ms\n", $p95, $p95 * 1000.0;
|
||||
printf " max : %.6f s %.3f ms\n", max(@lat), max(@lat) * 1000.0;
|
||||
printf " stddev : %.6f s %.3f ms\n", $stddev, $stddev * 1000.0;
|
||||
print "\n";
|
||||
}
|
||||
|
||||
print "Per-message detail:\n";
|
||||
printf "%10s %-10s %-10s %-18s %12s\n", 'lat_ms', 'sender', 'receiver', 'message', 'recv_minus_send';
|
||||
for my $r (sort { $a->{recv_epoch} <=> $b->{recv_epoch} } @rows) {
|
||||
printf "%10.3f %-10s %-10s %-18s %12.6f\n",
|
||||
$r->{latency} * 1000.0,
|
||||
$r->{sender},
|
||||
$r->{receiver},
|
||||
$r->{message},
|
||||
$r->{latency};
|
||||
}
|
||||
|
||||
print "\n";
|
||||
print "Caution: one-way latency assumes sender and receiver clocks are synchronized.\n";
|
||||
print "For tighter measurement, include chronyc tracking output near the run, or use echo/ACK round-trip timestamps.\n";
|
||||
|
||||
sub parse_log_date {
|
||||
my ($line) = @_;
|
||||
|
||||
# Supports:
|
||||
# Sat May 16 08:32:49 PDT 2026
|
||||
# Sat May 16 08:32:51 AM PDT 2026
|
||||
if ($line =~ /^\S+\s+(\S+)\s+(\d{1,2})\s+\d\d:\d\d:\d\d(?:\s+(?:AM|PM))?\s+(\S+)\s+(\d{4})/i) {
|
||||
my ($mon_name, $day, $tz, $year) = ($1, $2, uc($3), $4);
|
||||
exists $mon{$mon_name} or die "Cannot parse month '$mon_name' in: $line\n";
|
||||
exists $tz_offset{$tz} or die "Unknown timezone '$tz' in: $line\nAdd it to %tz_offset.\n";
|
||||
return ($year, $mon{$mon_name}, $day, $tz);
|
||||
}
|
||||
|
||||
die "Cannot parse log date from first line: $line\n";
|
||||
}
|
||||
|
||||
sub epoch_from_local_parts {
|
||||
my ($year, $month, $day, $hh, $mi, $ss, $ms, $tz) = @_;
|
||||
my $epoch_as_if_utc = timegm($ss, $mi, $hh, $day, $month, $year - 1900);
|
||||
return $epoch_as_if_utc - $tz_offset{$tz} + ($ms / 1000.0);
|
||||
}
|
||||
|
||||
sub receiver_from_filename {
|
||||
my ($file) = @_;
|
||||
return $1 if $file =~ /(zerodev\d+)/;
|
||||
return $file;
|
||||
}
|
||||
|
||||
sub percentile {
|
||||
my ($p, @values) = @_;
|
||||
@values = sort { $a <=> $b } @values;
|
||||
return undef unless @values;
|
||||
return $values[0] if @values == 1;
|
||||
|
||||
my $rank = ($p / 100.0) * (@values - 1);
|
||||
my $lo = int($rank);
|
||||
my $hi = $lo + 1;
|
||||
return $values[$lo] if $hi > $#values;
|
||||
|
||||
my $frac = $rank - $lo;
|
||||
return $values[$lo] + (($values[$hi] - $values[$lo]) * $frac);
|
||||
}
|
||||
|
||||
sub stddev {
|
||||
my (@values) = @_;
|
||||
return 0 if @values < 2;
|
||||
my $mean = sum(@values) / @values;
|
||||
my $ss = 0;
|
||||
$ss += ($_ - $mean) ** 2 for @values;
|
||||
return sqrt($ss / @values);
|
||||
}
|
||||
Loading…
Add table
Add a link
Reference in a new issue