From aaa765adf89f213306a07f784fa6cda335694fc0 Mon Sep 17 00:00:00 2001 From: John Poole Date: Mon, 25 May 2026 14:10:58 -0700 Subject: [PATCH] After trial upon which import_exercise_26_ble_log.pl & schema were created. --- .../Codex_1_initial_prompt.md | 2 +- exercises/26_Bluetooth_discover/README.md | 80 +- .../scripts/create_exercise_26_ble_schema.sql | 379 +++++++++ .../scripts/exercise_26_smoke_test.awk | 141 ++++ .../scripts/import_exercise_26_ble_log.pl | 732 ++++++++++++++++++ exercises/26_Bluetooth_discover/src/main.cpp | 114 ++- 6 files changed, 1378 insertions(+), 70 deletions(-) create mode 100644 exercises/26_Bluetooth_discover/scripts/create_exercise_26_ble_schema.sql create mode 100755 exercises/26_Bluetooth_discover/scripts/exercise_26_smoke_test.awk create mode 100644 exercises/26_Bluetooth_discover/scripts/import_exercise_26_ble_log.pl diff --git a/exercises/26_Bluetooth_discover/Codex_1_initial_prompt.md b/exercises/26_Bluetooth_discover/Codex_1_initial_prompt.md index afdb67c..581dc7d 100644 --- a/exercises/26_Bluetooth_discover/Codex_1_initial_prompt.md +++ b/exercises/26_Bluetooth_discover/Codex_1_initial_prompt.md @@ -67,7 +67,7 @@ Functional requirements: - today's date - ChatGPT/Codex generated - Subversion keywords: $Id$ and $HeadURL$ -18. Add logging on the SD card using YYYYMMDD_HHMISS_[UNIT NAME]_ble_seach.log. Logging should include date + time, both epoch high precision and regular human readable (not high precision), GPS coordinates of current receiving unit, the advertisement received, the RSSI strength of the received transmission. +18. Add logging on the SD card using YYYYMMDD_HHMISS_[UNIT NAME]_ble_search.log. Logging should include date + time, both epoch high precision and regular human readable (not high precision), GPS coordinates of current receiving unit, the advertisement received, the RSSI strength of the received transmission. 19. Include web interface such as in Exercise 18, or later -- I cannot remember for sure, that allows downloading of the log files and deletion of the log files. We had a system where each unit had a unique IP for it, use that. Implementation details: diff --git a/exercises/26_Bluetooth_discover/README.md b/exercises/26_Bluetooth_discover/README.md index 013811d..9fda38e 100644 --- a/exercises/26_Bluetooth_discover/README.md +++ b/exercises/26_Bluetooth_discover/README.md @@ -26,12 +26,13 @@ pio device monitor -b 115200 -p /dev/ttytBOB ## Behavior -- Advertises manufacturer data in this format: `TBMSND|1|NODE|seq|uptime`. -- Accepts only advertisements with prefix `TBMSND`, version `1`, and node name in `AMY, BOB, CY, DAN, ED, FLO, GUY`. +- Advertises manufacturer data in this format: `B2|NODE|seq|tx_epoch_ms`. +- Accepts current `B2` advertisements and legacy `TBMSND|1|NODE|seq|uptime` advertisements from known nodes in `AMY, BOB, CY, DAN, ED, FLO, GUY`. - Displays heard nodes sorted by rolling RSSI average, strongest first. - Drops stale entries after 20 seconds. -- Logs accepted advertisements to SD as `/logs/YYYYMMDD_HHMISS_NODE_ble_seach.log`. -- Starts a WiFi AP for log access when SD is available. +- Logs accepted advertisements to SD as `/logs/YYYYMMDD_HHMISS_NODE_ble_search.log`. +- Refreshes the receiver GPS position at 1 Hz and logs the last known receiver coordinates plus GPS fix age. +- Starts a WiFi AP and HTTP web service during boot. This does not wait for GPS. Default web addresses: @@ -78,25 +79,25 @@ pio device monitor -b 115200 -p /dev/ttytAMY | tee logs/ble_discovery_AMY_YYYYMM Here are two logs from ED and FLO which were activated in the field. ```bash jlpoole@jp ~/work/tbeam/logs $ ls -lath ed/*_16* --rw-r--r-- 1 jlpoole jlpoole 1.1M May 25 09:53 ed/20260525_162217_ED_ble_seach.log +-rw-r--r-- 1 jlpoole jlpoole 1.1M May 25 09:53 ed/20260525_162217_ED_ble_search.log jlpoole@jp ~/work/tbeam/logs $ ls -lath flo/*_16* --rw-r--r-- 1 jlpoole jlpoole 1.1M May 25 09:53 flo/20260525_162213_FLO_ble_seach.log +-rw-r--r-- 1 jlpoole jlpoole 1.1M May 25 09:53 flo/20260525_162213_FLO_ble_search.log jlpoole@jp ~/work/tbeam/logs $ ``` -Here are start and end samples from both: +Here are start and end samples from an earlier trial. These show the previous 12-column schema; current firmware uses the 14-column schema described below. ```bash -jlpoole@jp ~/work/tbeam/logs $ cat -n ed/20260525_162217_ED_ble_seach.log|head -n 3 +jlpoole@jp ~/work/tbeam/logs $ cat -n ed/20260525_162217_ED_ble_search.log|head -n 3 1 human_time,epoch_ms,receiver,lat,lon,heard,rssi,avg_rssi,age_s,count,seq,payload 2 2026-05-25 16:22:18,1779726138897,ED,44.9364577,-123.0218702,FLO,-56,-56,0,1,1,TBMSND|1|FLO|0001|0775 3 2026-05-25 16:22:18,1779726138938,ED,44.9364577,-123.0218702,FLO,-51,-54,0,2,1,TBMSND|1|FLO|0001|0775 -jlpoole@jp ~/work/tbeam/logs $ cat -n ed/20260525_162217_ED_ble_seach.log|tail -n 1 +jlpoole@jp ~/work/tbeam/logs $ cat -n ed/20260525_162217_ED_ble_search.log|tail -n 1 10277 2026-05-25 16:47:42,1779727662217,ED,44.9364577,-123.0218702,FLO,-42,-42,0,10276,611,TBMSND|1|FLO|0611|2300 -jlpoole@jp ~/work/tbeam/logs $ cat -n flo/20260525_162213_FLO_ble_seach.log|head -n 3 +jlpoole@jp ~/work/tbeam/logs $ cat -n flo/20260525_162213_FLO_ble_search.log|head -n 3 1 human_time,epoch_ms,receiver,lat,lon,heard,rssi,avg_rssi,age_s,count,seq,payload 2 2026-05-25 16:22:16,1779726136737,FLO,44.9365132,-123.0218183,ED,-52,-52,0,1,0,TBMSND|1|ED|0000|0805 3 2026-05-25 16:22:16,1779726136829,FLO,44.9365132,-123.0218183,ED,-51,-52,0,2,0,TBMSND|1|ED|0000|0805 -jlpoole@jp ~/work/tbeam/logs $ cat -n flo/20260525_162213_FLO_ble_seach.log|tail -n 1 +jlpoole@jp ~/work/tbeam/logs $ cat -n flo/20260525_162213_FLO_ble_search.log|tail -n 1 10121 2026-05-25 16:47:37,1779727657219,FLO,44.9365132,-123.0218183,ED,-41,-40,0,10120,608,TBMSND|1|ED|0608|2325 jlpoole@jp ~/work/tbeam/logs $ ``` @@ -104,61 +105,54 @@ The header represents: | Column | Header | Explanation | | ---: | --- | --- | -| 1 | `human_time` | Receiver timestamp in human-readable UTC form based on Greenwich Mean Time ("G 0 +GROUP BY trial_id, receiver, heard; + +COMMIT; diff --git a/exercises/26_Bluetooth_discover/scripts/exercise_26_smoke_test.awk b/exercises/26_Bluetooth_discover/scripts/exercise_26_smoke_test.awk new file mode 100755 index 0000000..84f48a9 --- /dev/null +++ b/exercises/26_Bluetooth_discover/scripts/exercise_26_smoke_test.awk @@ -0,0 +1,141 @@ +#!/usr/bin/awk -f +# $Id$ +# $HeadURL$ +# +# Example: +# awk -f exercise_26_smoke_test.awk "$FLO_LOG" +# awk -f exercise_26_smoke_test.awk "$ED_LOG" +# +# BLE Exercise 26 GPS smoke test. + +BEGIN { + FS = "," + + # Approximate feet per degree latitude. + # Good enough for a smoke test around Salem, Oregon. + FEET_PER_DEG_LAT = 364000 +} + +NR == 1 { next } + +$4 != "" && $5 != "" { + n++ + + lat = $4 + 0 + lon = $5 + 0 + gps_age = $6 + 0 + + if (n == 1) { + first_time = $1 + first_lat = lat + first_lon = lon + + min_lat = max_lat = lat + min_lon = max_lon = lon + min_gps_age = max_gps_age = gps_age + } + +dlat_ft = (lat - first_lat) * FEET_PER_DEG_LAT + +pi = atan2(0, -1) +first_lat_rad = first_lat * pi / 180 +feet_per_deg_lon_here = FEET_PER_DEG_LAT * cos(first_lat_rad) + +dlon_ft = (lon - first_lon) * feet_per_deg_lon_here +dist_from_start_ft = sqrt(dlat_ft * dlat_ft + dlon_ft * dlon_ft) + +if (dist_from_start_ft > max_dist_from_start_ft) { + max_dist_from_start_ft = dist_from_start_ft + max_dist_time = $1 + max_dist_lat = lat + max_dist_lon = lon +} + + + last_time = $1 + last_lat = lat + last_lon = lon + + if (n % 2 == 0) { + mid_time = $1 + mid_lat = lat + mid_lon = lon + } + + key = sprintf("%.7f,%.7f", lat, lon) + seen[key]++ + + sum_lat += lat + sum_lon += lon + sum2_lat += lat * lat + sum2_lon += lon * lon + + sum_gps_age += gps_age + if (gps_age < min_gps_age) min_gps_age = gps_age + if (gps_age > max_gps_age) max_gps_age = gps_age + + if (lat < min_lat) min_lat = lat + if (lat > max_lat) max_lat = lat + if (lon < min_lon) min_lon = lon + if (lon > max_lon) max_lon = lon +} + +END { + if (n < 2) { + print "Not enough coordinate rows" + exit + } + + mean_lat = sum_lat / n + mean_lon = sum_lon / n + + sd_lat = sqrt((sum2_lat - n * mean_lat * mean_lat) / (n - 1)) + sd_lon = sqrt((sum2_lon - n * mean_lon * mean_lon) / (n - 1)) + + lat_range_deg = max_lat - min_lat + lon_range_deg = max_lon - min_lon + + pi = atan2(0, -1) + mean_lat_rad = mean_lat * pi / 180 + feet_per_deg_lon = FEET_PER_DEG_LAT * cos(mean_lat_rad) + + lat_range_ft = lat_range_deg * FEET_PER_DEG_LAT + lon_range_ft = lon_range_deg * feet_per_deg_lon + + sd_lat_ft = sd_lat * FEET_PER_DEG_LAT + sd_lon_ft = sd_lon * feet_per_deg_lon + + diag_ft = sqrt(lat_range_ft * lat_range_ft + lon_range_ft * lon_range_ft) + + printf "rows: %d\n", n + printf "distinct coordinate pairs: %d\n", length(seen) + printf "\n" + + printf "first: %s %.7f, %.7f\n", first_time, first_lat, first_lon + printf "mid: %s %.7f, %.7f\n", mid_time, mid_lat, mid_lon + printf "last: %s %.7f, %.7f\n", last_time, last_lat, last_lon + printf "\n" + + printf "mean_lat: %.8f\n", mean_lat + printf "mean_lon: %.8f\n", mean_lon + printf "sd_lat: %.10f degrees %.2f ft\n", sd_lat, sd_lat_ft + printf "sd_lon: %.10f degrees %.2f ft\n", sd_lon, sd_lon_ft + printf "\n" + + printf "min_lat: %.8f\n", min_lat + printf "max_lat: %.8f\n", max_lat + printf "min_lon: %.8f\n", min_lon + printf "max_lon: %.8f\n", max_lon + printf "\n" + + printf "lat_range: %.10f degrees %.2f ft north/south\n", lat_range_deg, lat_range_ft + printf "lon_range: %.10f degrees %.2f ft east/west\n", lon_range_deg, lon_range_ft + printf "bbox_diagonal: %.2f ft\n", diag_ft + printf "\n" + + printf "gps_age_ms min/avg/max: %.0f / %.1f / %.0f\n", min_gps_age, sum_gps_age / n, max_gps_age + +printf "max_dist_from_start: %.2f ft\n", max_dist_from_start_ft +printf "max_dist_time: %s\n", max_dist_time +printf "max_dist_coord: %.7f, %.7f\n", max_dist_lat, max_dist_lon +} diff --git a/exercises/26_Bluetooth_discover/scripts/import_exercise_26_ble_log.pl b/exercises/26_Bluetooth_discover/scripts/import_exercise_26_ble_log.pl new file mode 100644 index 0000000..b6a9d7e --- /dev/null +++ b/exercises/26_Bluetooth_discover/scripts/import_exercise_26_ble_log.pl @@ -0,0 +1,732 @@ +#!/usr/bin/env perl +# $Id$ +# $HeadURL$ +# +# Example: +# +# sqlite3 ble_fieldtest_20260525_1945_ed_flo.sqlite < create_exercise_26_ble_schema.sql +# +# ./import_exercise_26_ble_log.pl \ +# --db ble_fieldtest_20260525_1945_ed_flo.sqlite \ +# --log "$FLO_LOG" +# +# ./import_exercise_26_ble_log.pl \ +# --db ble_fieldtest_20260525_1945_ed_flo.sqlite \ +# --log "$ED_LOG" +# +# Manifest: +# +# The importer expects a manifest file with the same name as the log plus +# ".manifest" appended. +# +# Example: +# flo/20260525_194537_FLO_ble_search.log.manifest +# +# Simple key=value format: +# +# trial_name=Peck Cottage ED FLO BLE walk test 20260525_1945 +# trial_label=peck_cottage_ed_flo_20260525_1945 +# firmware_exercise=26_Bluetooth_discover +# firmware_git_commit=unknown +# field_site=Peck Cottage steps +# operator=jlpoole +# receiver_role=moving +# receiver_start_description=upside-down plastic pot at Peck Cottage steps +# receiver_notes=FLO was hand-carried north and across the street, then returned to base. +# test_notes=Two-unit BLE discovery test. ED stationary, FLO moving. +# +# Purpose: +# +# Import Exercise 26 BLE Discovery logs into SQLite. +# +# Required Perl modules: +# +# DBI +# DBD::SQLite +# Digest::SHA +# Getopt::Long +# File::Basename +# +# Gentoo package hints: +# +# emerge --ask dev-perl/DBI dev-perl/DBD-SQLite +# + +use strict; +use warnings; + +use DBI; +use Digest::SHA qw(sha256_hex); +use File::Basename qw(basename); +use Getopt::Long qw(GetOptions); + +my $db_file; +my $log_file; +my $help; + +GetOptions( + 'db=s' => \$db_file, + 'log=s' => \$log_file, + 'help' => \$help, +) or die usage(); + +if ($help) { + print usage(); + exit 0; +} + +die usage() unless defined $db_file && defined $log_file; + +die "Database file does not exist: $db_file\n" + unless -f $db_file; + +die "Log file does not exist: $log_file\n" + unless -f $log_file; + +my $manifest_file = $log_file . ".manifest"; + +die "Manifest file does not exist: $manifest_file\n" + unless -f $manifest_file; + +my %manifest = read_manifest($manifest_file); + +my $trial_label = required_manifest(\%manifest, 'trial_label'); +my $trial_name = required_manifest(\%manifest, 'trial_name'); + +my $sha256 = file_sha256($log_file); +my $byte_count = -s $log_file; +my $base_name = basename($log_file); + +my $dbh = DBI->connect( + "dbi:SQLite:dbname=$db_file", + "", + "", + { + RaiseError => 1, + AutoCommit => 0, + sqlite_unicode => 1, + } +); + +$dbh->do('PRAGMA foreign_keys = ON'); + +eval { + my $existing = $dbh->selectrow_array( + 'SELECT log_file_id FROM log_file WHERE sha256 = ?', + undef, + $sha256 + ); + + if (defined $existing) { + die "This log already appears to be imported: log_file_id=$existing sha256=$sha256\n"; + } + + my $trial_id = upsert_trial($dbh, \%manifest); + + my $log_stats = scan_log_for_stats($log_file); + + my $receiver = $log_stats->{receiver} + or die "Could not determine receiver from log: $log_file\n"; + + upsert_unit($dbh, $receiver); + + my $log_file_id = insert_log_file( + $dbh, + trial_id => $trial_id, + receiver => $receiver, + path => $log_file, + basename => $base_name, + manifest_path => $manifest_file, + sha256 => $sha256, + byte_count => $byte_count, + source_row_count => $log_stats->{source_row_count}, + first_rx_epoch_ms => $log_stats->{first_rx_epoch_ms}, + last_rx_epoch_ms => $log_stats->{last_rx_epoch_ms}, + receiver_role => $manifest{receiver_role}, + receiver_start_description => $manifest{receiver_start_description}, + receiver_notes => $manifest{receiver_notes}, + test_notes => $manifest{test_notes}, + ); + + insert_manifest_kv($dbh, $log_file_id, \%manifest); + + import_log_rows( + $dbh, + trial_id => $trial_id, + log_file_id => $log_file_id, + log_file => $log_file, + ); + + update_trial_time_bounds($dbh, $trial_id); + + $dbh->commit; + + print "Imported log successfully\n"; + print " database: $db_file\n"; + print " log: $log_file\n"; + print " manifest: $manifest_file\n"; + print " trial_id: $trial_id\n"; + print " log_file_id: $log_file_id\n"; + print " receiver: $receiver\n"; + print " rows: $log_stats->{source_row_count}\n"; + print " sha256: $sha256\n"; +}; + +if ($@) { + my $err = $@; + eval { $dbh->rollback }; + die $err; +} + +$dbh->disconnect; + +exit 0; + +sub usage { + return <<"EOF"; +Usage: + $0 --db DATABASE.sqlite --log path/to/log.csv + +Example: + $0 --db ble_fieldtest_20260525_1945_ed_flo.sqlite --log "\$FLO_LOG" + +The importer expects a manifest beside the log: + + path/to/log.csv.manifest + +EOF +} + +sub required_manifest { + my ($manifest_ref, $key) = @_; + + die "Manifest is missing required key: $key\n" + unless exists $manifest_ref->{$key} + && defined $manifest_ref->{$key} + && $manifest_ref->{$key} ne ''; + + return $manifest_ref->{$key}; +} + +sub read_manifest { + my ($path) = @_; + + open my $fh, '<', $path + or die "Could not open manifest $path: $!\n"; + + my %manifest; + + while (my $line = <$fh>) { + chomp $line; + $line =~ s/\r\z//; + + next if $line =~ /^\s*$/; + next if $line =~ /^\s*#/; + + die "Bad manifest line, expected key=value: $line\n" + unless $line =~ /^\s*([^=]+?)\s*=\s*(.*?)\s*$/; + + my ($key, $value) = ($1, $2); + + $key =~ s/^\s+|\s+$//g; + $value =~ s/^\s+|\s+$//g; + + die "Empty manifest key in line: $line\n" + if $key eq ''; + + $manifest{$key} = $value; + } + + close $fh; + + return %manifest; +} + +sub file_sha256 { + my ($path) = @_; + + open my $fh, '<:raw', $path + or die "Could not open $path for SHA-256: $!\n"; + + my $ctx = Digest::SHA->new(256); + $ctx->addfile($fh); + + close $fh; + + return $ctx->hexdigest; +} + +sub scan_log_for_stats { + my ($path) = @_; + + open my $fh, '<', $path + or die "Could not open log $path: $!\n"; + + my $header = <$fh>; + die "Empty log file: $path\n" unless defined $header; + + chomp $header; + $header =~ s/\r\z//; + + my @cols = split /,/, $header, -1; + validate_header(@cols); + + my $row_count = 0; + my $receiver; + my $first_rx_epoch_ms; + my $last_rx_epoch_ms; + + while (my $line = <$fh>) { + chomp $line; + $line =~ s/\r\z//; + next if $line =~ /^\s*$/; + + my @f = split /,/, $line, -1; + + next unless @f >= 14; + + $row_count++; + + my $rx_epoch_ms = to_int_or_undef($f[1]); + my $rx_receiver = $f[2]; + + $receiver //= $rx_receiver; + + if (defined $rx_epoch_ms) { + $first_rx_epoch_ms //= $rx_epoch_ms; + $last_rx_epoch_ms = $rx_epoch_ms; + } + } + + close $fh; + + return { + receiver => $receiver, + source_row_count => $row_count, + first_rx_epoch_ms => $first_rx_epoch_ms, + last_rx_epoch_ms => $last_rx_epoch_ms, + }; +} + +sub validate_header { + my (@cols) = @_; + + my @expected = qw( + human_time + rx_epoch_ms + receiver + rx_lat + rx_lon + rx_gps_age_ms + heard + rssi + avg_rssi + age_s + count + seq + tx_epoch_ms + payload + ); + + die "Unexpected column count in header. Expected 14, got " . scalar(@cols) . "\n" + unless @cols == @expected; + + for my $i (0 .. $#expected) { + die "Unexpected header column " . ($i + 1) . ". Expected '$expected[$i]', got '$cols[$i]'\n" + unless $cols[$i] eq $expected[$i]; + } +} + +sub upsert_trial { + my ($dbh, $manifest_ref) = @_; + + my $trial_label = required_manifest($manifest_ref, 'trial_label'); + my $trial_name = required_manifest($manifest_ref, 'trial_name'); + + my $existing = $dbh->selectrow_array( + 'SELECT trial_id FROM trial WHERE trial_label = ?', + undef, + $trial_label + ); + + return $existing if defined $existing; + + my $sth = $dbh->prepare(q{ + INSERT INTO trial ( + trial_label, + trial_name, + field_site, + operator, + firmware_exercise, + firmware_git_commit, + notes + ) + VALUES (?, ?, ?, ?, ?, ?, ?) + }); + + $sth->execute( + $trial_label, + $trial_name, + $manifest_ref->{field_site}, + $manifest_ref->{operator}, + $manifest_ref->{firmware_exercise}, + $manifest_ref->{firmware_git_commit}, + $manifest_ref->{test_notes}, + ); + + return $dbh->sqlite_last_insert_rowid; +} + +sub upsert_unit { + my ($dbh, $unit_name) = @_; + + return unless defined $unit_name && $unit_name ne ''; + + my $sth = $dbh->prepare(q{ + INSERT OR IGNORE INTO unit (unit_name) + VALUES (?) + }); + + $sth->execute($unit_name); +} + +sub insert_log_file { + my ($dbh, %arg) = @_; + + my $sth = $dbh->prepare(q{ + INSERT INTO log_file ( + trial_id, + receiver, + path, + basename, + manifest_path, + sha256, + byte_count, + source_row_count, + first_rx_epoch_ms, + last_rx_epoch_ms, + receiver_role, + receiver_start_description, + receiver_notes, + test_notes + ) + VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) + }); + + $sth->execute( + $arg{trial_id}, + $arg{receiver}, + $arg{path}, + $arg{basename}, + $arg{manifest_path}, + $arg{sha256}, + $arg{byte_count}, + $arg{source_row_count}, + $arg{first_rx_epoch_ms}, + $arg{last_rx_epoch_ms}, + $arg{receiver_role}, + $arg{receiver_start_description}, + $arg{receiver_notes}, + $arg{test_notes}, + ); + + return $dbh->sqlite_last_insert_rowid; +} + +sub insert_manifest_kv { + my ($dbh, $log_file_id, $manifest_ref) = @_; + + my $sth = $dbh->prepare(q{ + INSERT INTO log_manifest_kv (log_file_id, key, value) + VALUES (?, ?, ?) + }); + + for my $key (sort keys %{$manifest_ref}) { + $sth->execute($log_file_id, $key, $manifest_ref->{$key}); + } +} + +sub import_log_rows { + my ($dbh, %arg) = @_; + + my $trial_id = $arg{trial_id}; + my $log_file_id = $arg{log_file_id}; + my $log_file = $arg{log_file}; + + open my $fh, '<', $log_file + or die "Could not open log $log_file: $!\n"; + + my $header = <$fh>; + die "Empty log file: $log_file\n" unless defined $header; + + chomp $header; + $header =~ s/\r\z//; + validate_header(split /,/, $header, -1); + + my $raw_sth = $dbh->prepare(q{ + INSERT INTO ble_observation_raw ( + trial_id, + log_file_id, + source_line_no, + human_time, + rx_epoch_ms, + receiver, + rx_lat, + rx_lon, + rx_gps_age_ms, + heard, + rssi, + avg_rssi, + age_s, + count, + seq, + tx_epoch_ms, + payload + ) + VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) + }); + + my $obs_sth = $dbh->prepare(q{ + INSERT INTO ble_observation ( + raw_id, + trial_id, + log_file_id, + source_line_no, + rx_epoch_ms, + rx_epoch_s, + tx_epoch_ms, + tx_epoch_s, + rx_tx_delta_ms, + receiver, + heard, + rx_lat, + rx_lon, + rx_gps_age_ms, + rssi, + avg_rssi, + age_s, + receiver_count, + receiver_seq_field, + payload_raw, + payload_kind, + payload_node, + payload_seq, + payload_tx_epoch_ms, + payload_legacy_uptime, + parse_warning + ) + VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) + }); + + my $line_no = 1; + my $data_rows = 0; + + while (my $line = <$fh>) { + $line_no++; + chomp $line; + $line =~ s/\r\z//; + + next if $line =~ /^\s*$/; + + my @f = split /,/, $line, -1; + + die "Line $line_no has too few columns. Expected 14, got " . scalar(@f) . "\n" + unless @f >= 14; + + my $human_time = $f[0]; + my $rx_epoch_ms = to_int_or_undef($f[1]); + my $receiver = $f[2]; + my $rx_lat = to_num_or_undef($f[3]); + my $rx_lon = to_num_or_undef($f[4]); + my $rx_gps_age_ms = to_int_or_undef($f[5]); + my $heard = $f[6]; + my $rssi = to_int_or_undef($f[7]); + my $avg_rssi = to_int_or_undef($f[8]); + my $age_s = to_int_or_undef($f[9]); + my $count = to_int_or_undef($f[10]); + my $seq = to_int_or_undef($f[11]); + my $tx_epoch_ms = to_int_or_undef($f[12]); + my $payload = $f[13]; + + die "Line $line_no has no rx_epoch_ms\n" + unless defined $rx_epoch_ms; + + die "Line $line_no has no receiver\n" + unless defined $receiver && $receiver ne ''; + + die "Line $line_no has no heard unit\n" + unless defined $heard && $heard ne ''; + + upsert_unit($dbh, $receiver); + upsert_unit($dbh, $heard); + + $raw_sth->execute( + $trial_id, + $log_file_id, + $line_no, + $human_time, + $rx_epoch_ms, + $receiver, + $rx_lat, + $rx_lon, + $rx_gps_age_ms, + $heard, + $rssi, + $avg_rssi, + $age_s, + $count, + $seq, + $tx_epoch_ms, + $payload, + ); + + my $raw_id = $dbh->sqlite_last_insert_rowid; + + my $parsed = parse_payload($payload); + + my $rx_epoch_s = $rx_epoch_ms / 1000.0; + + my $tx_epoch_s; + my $rx_tx_delta_ms; + + if (defined $tx_epoch_ms && $tx_epoch_ms > 0) { + $tx_epoch_s = $tx_epoch_ms / 1000.0; + $rx_tx_delta_ms = $rx_epoch_ms - $tx_epoch_ms; + } + + $obs_sth->execute( + $raw_id, + $trial_id, + $log_file_id, + $line_no, + $rx_epoch_ms, + $rx_epoch_s, + $tx_epoch_ms, + $tx_epoch_s, + $rx_tx_delta_ms, + $receiver, + $heard, + $rx_lat, + $rx_lon, + $rx_gps_age_ms, + $rssi, + $avg_rssi, + $age_s, + $count, + $seq, + $payload, + $parsed->{payload_kind}, + $parsed->{payload_node}, + $parsed->{payload_seq}, + $parsed->{payload_tx_epoch_ms}, + $parsed->{payload_legacy_uptime}, + $parsed->{parse_warning}, + ); + + $data_rows++; + } + + close $fh; + + return $data_rows; +} + +sub parse_payload { + my ($payload) = @_; + + my %p = ( + payload_kind => undef, + payload_node => undef, + payload_seq => undef, + payload_tx_epoch_ms => undef, + payload_legacy_uptime => undef, + parse_warning => undef, + ); + + if (!defined $payload || $payload eq '') { + $p{parse_warning} = 'empty payload'; + return \%p; + } + + my @parts = split /\|/, $payload, -1; + + if (@parts == 4 && $parts[0] eq 'B2') { + $p{payload_kind} = 'B2'; + $p{payload_node} = $parts[1]; + $p{payload_seq} = to_int_or_undef($parts[2]); + $p{payload_tx_epoch_ms} = to_int_or_undef($parts[3]); + + if (!defined $p{payload_seq}) { + $p{parse_warning} = 'B2 payload seq was not numeric'; + } + elsif (!defined $p{payload_tx_epoch_ms}) { + $p{parse_warning} = 'B2 payload tx_epoch_ms was not numeric'; + } + + return \%p; + } + + if (@parts == 5 && $parts[0] eq 'TBMSND' && $parts[1] eq '1') { + $p{payload_kind} = 'TBMSND1'; + $p{payload_node} = $parts[2]; + $p{payload_seq} = to_int_or_undef($parts[3]); + $p{payload_legacy_uptime} = to_int_or_undef($parts[4]); + + if (!defined $p{payload_seq}) { + $p{parse_warning} = 'legacy payload seq was not numeric'; + } + elsif (!defined $p{payload_legacy_uptime}) { + $p{parse_warning} = 'legacy payload uptime was not numeric'; + } + + return \%p; + } + + $p{parse_warning} = 'unrecognized payload format'; + return \%p; +} + +sub update_trial_time_bounds { + my ($dbh, $trial_id) = @_; + + $dbh->do(q{ + UPDATE trial + SET trial_start_epoch_ms = ( + SELECT MIN(first_rx_epoch_ms) + FROM log_file + WHERE trial_id = ? + ), + trial_end_epoch_ms = ( + SELECT MAX(last_rx_epoch_ms) + FROM log_file + WHERE trial_id = ? + ) + WHERE trial_id = ? + }, undef, $trial_id, $trial_id, $trial_id); +} + +sub to_int_or_undef { + my ($value) = @_; + + return undef unless defined $value; + return undef if $value eq ''; + + $value =~ s/^\s+|\s+$//g; + + return undef unless $value =~ /^-?\d+$/; + + return int($value); +} + +sub to_num_or_undef { + my ($value) = @_; + + return undef unless defined $value; + return undef if $value eq ''; + + $value =~ s/^\s+|\s+$//g; + + return undef unless $value =~ /^-?(?:\d+(?:\.\d*)?|\.\d+)$/; + + return 0 + $value; +} diff --git a/exercises/26_Bluetooth_discover/src/main.cpp b/exercises/26_Bluetooth_discover/src/main.cpp index 9e66fe5..04bc8dd 100644 --- a/exercises/26_Bluetooth_discover/src/main.cpp +++ b/exercises/26_Bluetooth_discover/src/main.cpp @@ -65,13 +65,15 @@ using field_qa::GnssSample; static constexpr const char* kAppTitle = "BLE Discovery"; static constexpr const char* kProjectPrefix = "TBMSND"; static constexpr uint8_t kProtocolVersion = 1; +static constexpr const char* kTimePayloadPrefix = "B2"; static constexpr uint32_t kStaleMs = 20000; static constexpr uint32_t kDisplayPeriodMs = 1000; -static constexpr uint32_t kAdvertisePeriodMs = 2000; +static constexpr uint32_t kAdvertisePeriodMs = 1000; static constexpr uint32_t kScanPeriodMs = 2500; static constexpr uint32_t kScanWindowSeconds = 2; static constexpr uint32_t kLogFlushPeriodMs = 5000; static constexpr uint32_t kStartupStatusPeriodMs = 1000; +static constexpr uint32_t kGpsRefreshPeriodMs = 1000; static constexpr uint8_t kRssiWindow = 5; struct NodeState { @@ -87,6 +89,7 @@ struct NodeState { uint32_t seenCount = 0; uint32_t lastSeenMs = 0; uint32_t lastSeq = 0; + int64_t lastTxEpochMs = 0; }; XPowersLibInterface* g_pmu = nullptr; @@ -116,17 +119,22 @@ bool g_buttonWasPressed = false; uint8_t g_displayMode = 0; uint32_t g_sequence = 0; volatile uint32_t g_ppsEdgeCount = 0; +volatile uint32_t g_lastPpsMs = 0; uint32_t g_lastAdvertiseMs = 0; uint32_t g_lastScanMs = 0; uint32_t g_lastDisplayMs = 0; uint32_t g_lastFlushMs = 0; +uint32_t g_lastGpsRefreshMs = 0; int64_t g_epochBase = 0; uint32_t g_epochBaseMs = 0; double g_latitude = 0.0; double g_longitude = 0.0; +uint32_t g_gpsFixMs = 0; +bool g_hasLocation = false; char g_logPath[128] = {}; void IRAM_ATTR onPpsEdge() { + g_lastPpsMs = millis(); ++g_ppsEdgeCount; } @@ -168,11 +176,39 @@ bool freshEnough(const NodeState& node, uint32_t now) { return node.heard && (uint32_t)(now - node.lastSeenMs) <= kStaleMs; } +int64_t currentEpochMs(); + int64_t currentEpoch() { + return currentEpochMs() / 1000LL; +} + +int64_t currentEpochMs() { if (!g_disciplined || g_epochBase <= 0) { return 0; } - return g_epochBase + (int64_t)((millis() - g_epochBaseMs) / 1000UL); + return (g_epochBase * 1000LL) + (int64_t)(millis() - g_epochBaseMs); +} + +uint32_t gpsAgeMs(uint32_t now) { + if (!g_hasLocation || g_gpsFixMs == 0) { + return UINT32_MAX; + } + return now - g_gpsFixMs; +} + +void refreshGpsPosition(bool force = false) { + const uint32_t now = millis(); + if (!force && (uint32_t)(now - g_lastGpsRefreshMs) < kGpsRefreshPeriodMs) { + return; + } + g_lastGpsRefreshMs = now; + const GnssSample sample = g_gnss.makeSample(); + if (sample.validLocation && sample.validFix) { + g_latitude = sample.latitude; + g_longitude = sample.longitude; + g_gpsFixMs = sample.sampleMillis; + g_hasLocation = true; + } } void formatDateTime(int64_t epoch, char* out, size_t outSize) { @@ -311,9 +347,12 @@ bool disciplineStartupClock() { ++attemptCount; if (g_clock.disciplineFromGnss(sample, waitForPps, nullptr, disciplined, hadPriorRtc, driftSeconds)) { g_epochBase = ClockDiscipline::toEpochSeconds(disciplined); - g_epochBaseMs = millis(); + g_epochBaseMs = g_lastPpsMs > 0 ? g_lastPpsMs : millis(); g_latitude = sample.latitude; g_longitude = sample.longitude; + g_gpsFixMs = sample.sampleMillis; + g_hasLocation = true; + g_lastGpsRefreshMs = millis(); char iso[32]; ClockDiscipline::formatIsoUtc(disciplined, iso, sizeof(iso)); Serial.printf("clock_disciplined node=%s utc=%s prior_rtc=%u drift_s=%lld lat=%.7f lon=%.7f\n", @@ -338,7 +377,7 @@ bool openDatedLog() { } char stamp[24]; formatCompactDateTime(currentEpoch(), stamp, sizeof(stamp)); - snprintf(g_logPath, sizeof(g_logPath), "/logs/%s_%s_ble_seach.log", stamp, NODE_NAME); + snprintf(g_logPath, sizeof(g_logPath), "/logs/%s_%s_ble_search.log", stamp, NODE_NAME); if (!g_storage.ensureDirRecursive("/logs")) { Serial.printf("sd_log_dir_failed err=%s\n", g_storage.lastError()); return false; @@ -347,7 +386,7 @@ bool openDatedLog() { Serial.printf("sd_log_open_failed path=%s err=%s\n", g_logPath, g_storage.lastError()); return false; } - g_storage.println("human_time,epoch_ms,receiver,lat,lon,heard,rssi,avg_rssi,age_s,count,seq,payload"); + g_storage.println("human_time,rx_epoch_ms,receiver,rx_lat,rx_lon,rx_gps_age_ms,heard,rssi,avg_rssi,age_s,count,seq,tx_epoch_ms,payload"); g_storage.flush(); Serial.printf("sd_log_open path=%s\n", g_logPath); g_logReady = true; @@ -387,15 +426,14 @@ void startStorageAndWeb() { } void updateAdvertisement() { - char payload[30]; + char payload[32]; snprintf(payload, sizeof(payload), - "%s|%u|%s|%04lu|%04lu", - kProjectPrefix, - (unsigned)kProtocolVersion, + "%s|%s|%04lu|%lld", + kTimePayloadPrefix, NODE_NAME, (unsigned long)(g_sequence % 10000UL), - (unsigned long)((millis() / 1000UL) % 10000UL)); + (long long)currentEpochMs()); BLEAdvertising* advertising = BLEDevice::getAdvertising(); BLEAdvertisementData data; @@ -410,12 +448,14 @@ void updateAdvertisement() { g_lastAdvertiseMs = millis(); } -bool parsePayload(const std::string& data, char* outName, size_t outNameSize, uint32_t& outSeq, char* outPayload, size_t outPayloadSize) { +bool parsePayload(const std::string& data, char* outName, size_t outNameSize, uint32_t& outSeq, int64_t& outTxEpochMs, char* outPayload, size_t outPayloadSize) { if (outNameSize == 0 || outPayloadSize == 0) { return false; } outName[0] = '\0'; outPayload[0] = '\0'; + outSeq = 0; + outTxEpochMs = 0; if (data.empty() || data.size() >= outPayloadSize) { return false; } @@ -426,13 +466,26 @@ bool parsePayload(const std::string& data, char* outName, size_t outNameSize, ui strlcpy(work, outPayload, sizeof(work)); char* save = nullptr; const char* prefix = strtok_r(work, "|", &save); - const char* version = strtok_r(nullptr, "|", &save); - const char* name = strtok_r(nullptr, "|", &save); - const char* seq = strtok_r(nullptr, "|", &save); - if (!prefix || !version || !name || !seq) { + if (!prefix) { return false; } - if (strcmp(prefix, kProjectPrefix) != 0 || atoi(version) != kProtocolVersion) { + + const char* name = nullptr; + const char* seq = nullptr; + const char* txEpochMs = nullptr; + if (strcmp(prefix, kTimePayloadPrefix) == 0) { + name = strtok_r(nullptr, "|", &save); + seq = strtok_r(nullptr, "|", &save); + txEpochMs = strtok_r(nullptr, "|", &save); + } else { + const char* version = strtok_r(nullptr, "|", &save); + name = strtok_r(nullptr, "|", &save); + seq = strtok_r(nullptr, "|", &save); + if (strcmp(prefix, kProjectPrefix) != 0 || !version || atoi(version) != kProtocolVersion) { + return false; + } + } + if (!name || !seq) { return false; } if (nodeIndexFor(name) < 0 || isSelfName(name)) { @@ -440,19 +493,22 @@ bool parsePayload(const std::string& data, char* outName, size_t outNameSize, ui } strlcpy(outName, name, outNameSize); outSeq = (uint32_t)strtoul(seq, nullptr, 10); + if (txEpochMs && txEpochMs[0]) { + outTxEpochMs = (int64_t)strtoll(txEpochMs, nullptr, 10); + } return true; } void logAcceptedAdvertisement(const NodeState& node, const char* payload) { const int avg = averageRssi(node); const uint32_t age = ageSeconds(node, millis()); - const int64_t epoch = currentEpoch(); + const int64_t epochMs = currentEpochMs(); + const int64_t epoch = epochMs / 1000LL; + const uint32_t fixAge = gpsAgeMs(millis()); char human[32]; formatDateTime(epoch, human, sizeof(human)); - const uint32_t epochMsPart = millis() % 1000UL; - const long long epochMs = (long long)(epoch * 1000LL + epochMsPart); - Serial.printf("%lu,%s,%s,%d,%d,%lu,%lu,%lu,%s\n", + Serial.printf("%lu,%s,%s,%d,%d,%lu,%lu,%lu,%lld,%s\n", (unsigned long)millis(), NODE_NAME, node.name, @@ -461,30 +517,33 @@ void logAcceptedAdvertisement(const NodeState& node, const char* payload) { (unsigned long)age, (unsigned long)node.seenCount, (unsigned long)node.lastSeq, + (long long)node.lastTxEpochMs, payload); if (g_logReady && g_storage.isLogOpen()) { - char line[224]; + char line[256]; snprintf(line, sizeof(line), - "%s,%lld,%s,%.7f,%.7f,%s,%d,%d,%lu,%lu,%lu,%s", + "%s,%lld,%s,%.7f,%.7f,%lu,%s,%d,%d,%lu,%lu,%lu,%lld,%s", human, - epochMs, + (long long)epochMs, NODE_NAME, g_latitude, g_longitude, + (unsigned long)fixAge, node.name, node.lastRssi, avg, (unsigned long)age, (unsigned long)node.seenCount, (unsigned long)node.lastSeq, + (long long)node.lastTxEpochMs, payload); g_storage.println(line); } } -void acceptAdvertisement(const char* name, int rssi, uint32_t seq, const char* payload) { +void acceptAdvertisement(const char* name, int rssi, uint32_t seq, int64_t txEpochMs, const char* payload) { const int idx = nodeIndexFor(name); if (idx < 0) { return; @@ -500,6 +559,7 @@ void acceptAdvertisement(const char* name, int rssi, uint32_t seq, const char* p ++node.seenCount; node.lastSeenMs = millis(); node.lastSeq = seq; + node.lastTxEpochMs = txEpochMs; logAcceptedAdvertisement(node, payload); } @@ -512,10 +572,11 @@ class DiscoveryAdvertisedCallbacks : public BLEAdvertisedDeviceCallbacks { char name[8]; char payload[48]; uint32_t seq = 0; - if (!parsePayload(advertisedDevice.getManufacturerData(), name, sizeof(name), seq, payload, sizeof(payload))) { + int64_t txEpochMs = 0; + if (!parsePayload(advertisedDevice.getManufacturerData(), name, sizeof(name), seq, txEpochMs, payload, sizeof(payload))) { return; } - acceptAdvertisement(name, advertisedDevice.getRSSI(), seq, payload); + acceptAdvertisement(name, advertisedDevice.getRSSI(), seq, txEpochMs, payload); } }; @@ -689,6 +750,7 @@ void setup() { void loop() { g_gnss.poll(); + refreshGpsPosition(); pollButton(); pollStorageWeb(); if (g_bleStarted) {