From 48e9aac047a867bb2a850fddcb795330b66cb198 Mon Sep 17 00:00:00 2001 From: John Poole Date: Sat, 16 May 2026 10:09:48 -0700 Subject: [PATCH] Adding Perl script to analyze run results, adding feature of message file and determining if Announce needs to be repeated --- examples/ble_dual_node_echo.py | 124 +++++++++++++++++++- scripts/analyze_reticulum_latency.pl | 166 +++++++++++++++++++++++++++ 2 files changed, 284 insertions(+), 6 deletions(-) create mode 100755 scripts/analyze_reticulum_latency.pl diff --git a/examples/ble_dual_node_echo.py b/examples/ble_dual_node_echo.py index d992a61..38a7298 100755 --- a/examples/ble_dual_node_echo.py +++ b/examples/ble_dual_node_echo.py @@ -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() diff --git a/scripts/analyze_reticulum_latency.pl b/scripts/analyze_reticulum_latency.pl new file mode 100755 index 0000000..8001a7b --- /dev/null +++ b/scripts/analyze_reticulum_latency.pl @@ -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); +}