Decompose intermittent-power execution time into exec, checkpoint, and wait

docs/intermittent.md

@@ -26,9 +26,11 @@ of truth for this measurement setup's wiring and software.
   supply rail (anode toward the Otii, cathode at the board). It blocks
   back-feed into the Otii output while the ez-FET's 3V3 powers the board for
   flashing and readback.
-- **Saleae Logic** — wired to P3.4 as in [saleae.md](saleae.md). It captures
-  the benchmark start/stop pulses during the replay: completion detection
-  and execution time both come from this capture.
+- **Saleae Logic** — channel 0 wired to P3.4 as in [saleae.md](saleae.md),
+  channel 1 to P3.5. Channel 0 captures the benchmark start/stop pulses
+  during the replay: completion detection and execution time both come
+  from this capture. Channel 1 captures the wait pulses (below) that split
+  the recharge time out of it.
 
 ## Wiring Diagram
 
@@ -65,7 +67,7 @@ flowchart LR
     gpo2 -->|relay control| SB
     ezfet <-->|"J101 ez-FET side: 3V3, RST, TEST"| relay
     relay <-->|"J101 target side: 3V3, RST, TEST"| mcu
-    mcu -->|P3.4 pulse| saleae
+    mcu -->|P3.4 / P3.5 pulses| saleae
 ```
 
 ## Connections
@@ -82,6 +84,7 @@ flowchart LR
 | LaunchPad `GND` jumper (J101) | — | Left mounted: ground stays common at all times, not routed through the switchboard |
 | Host USB | ez-FET USB connector | Direct — the switchboard's USB interface is not used |
 | Saleae digital channel 0 | MSP430 `P3.4` | Start/stop pulses: completion detection + execution time |
+| Saleae digital channel 1 | MSP430 `P3.5` | Wait enter/exit pulses: recharge time |
 | Saleae GND | Board GND | |
 
 On the LaunchPad's J101 isolation block, only the `GND` jumper stays mounted.
@@ -130,9 +133,22 @@ For each (benchmark, capacitor, trace):
    early; no trigger by the end of the trace means `status=incomplete`.
    Execution time is the first start-pulse falling edge to the stop-pulse
    rising edge, outages included.
+
+   Every boundary or boot that finds the capacitor below the threshold
+   pulses P3.5 right before it sleeps and right after it wakes
+   (`passes/runtime/vcc_wait.c`): the enter pulse is one port write pair,
+   the exit pulse the same with four `nop`s in between, so the host tells
+   them apart by width (about 6 vs 11 CPU cycles high). The recharge time
+   of a run is the sum of enter-to-exit spans inside the execution-time
+   window. A wait cut short by a brownout has no exit pulse; the recovery
+   boot waits again, so its enter pulse follows directly and the span runs
+   on to that wait's exit, counting the outage and reboot as power-off
+   time. Pulses that coincide with a channel-0 pulse are the cold power-up
+   glitch (every floating pin follows the rising rail) and are dropped.
 4. **Readback** — main off, relays closed again, NVM read via `mspdebug`
    (`__nvm_done`, `__nvm_violation`, `cnt_wait` — boundaries/boots that found
-   the capacitor below the threshold and slept — `cnt_recovery`, and with
+   the capacitor below the threshold and slept, checked against the pulse
+   count — `cnt_recovery`, and with
    `--device-debug` — off by default, its counter updates and UART cost
    energy — also `cnt_boundary` and the result). Completed and violated
    runs park at boot, so their NVM state survives the reconnect.

docs/saleae.md

@@ -10,6 +10,8 @@ is the single source of truth for the hardware wiring and software setup.
 - Wire MSP430FR5994 **P3.4** to Saleae **digital channel 0**, and connect
   ground between the board and the analyzer.
 - The channel is sampled at 100 MHz.
+- `ckpt intermittent` additionally uses **P3.5** on **digital channel 1**
+  for the wait pulses; see [intermittent.md](intermittent.md).
 
 ## Software
 

passes/bb-energy-analyzer/BBEnergyAnalyzer.cpp

@@ -106,6 +106,29 @@ static cl::opt<double> StackAccessPenalty(
 static cl::opt<bool> DumpLineMap("dump-line-map", cl::init(false),
                                  cl::desc("Dump resolved address->BB line map and exit"));
 
+static cl::opt<unsigned> UnknownCopySize(
+    "unknown-copy-size", cl::init(0),
+    cl::desc("Byte count charged to a memcpy/memset call whose size is not a compile-time "
+             "constant (0: charge the call's base cost only)"));
+
+/// Size argument to charge for a `call memcpy/memset`: the immediate found
+/// by extractSizeArg, else --unknown-copy-size when set.
+static std::optional<unsigned> copySizeArg(const std::vector<Instruction> &instructions,
+                                           size_t callIdx) {
+    const auto &insn = instructions[callIdx];
+    std::optional<unsigned> sizeArg = extractSizeArg(instructions, callIdx);
+    if (sizeArg.has_value())
+        return sizeArg;
+    if (UnknownCopySize > 0) {
+        PLOGW << "WARNING: non-constant size for " << insn.callTarget << " at 0x"
+              << Twine::utohexstr(insn.address) << ", charging " << UnknownCopySize << " bytes";
+        return UnknownCopySize.getValue();
+    }
+    PLOGW << "WARNING: could not extract constant size for " << insn.callTarget << " at 0x"
+          << Twine::utohexstr(insn.address) << ", using base cost only";
+    return std::nullopt;
+}
+
 int main(int argc, char **argv) {
     cl::ParseCommandLineOptions(
         argc, argv,
@@ -226,15 +249,8 @@ int main(int argc, char **argv) {
                     if (insn.address >= range.start && insn.address < range.end) {
                         if (insn.mnemonic == "call") {
                             std::optional<unsigned> sizeArg;
-                            if (insn.callTarget == "memcpy" || insn.callTarget == "memset") {
-                                sizeArg = extractSizeArg(instructions, i);
-                                if (!sizeArg.has_value()) {
-                                    PLOGW << "WARNING: could not extract constant size for "
-                                          << insn.callTarget << " at 0x"
-                                          << Twine::utohexstr(insn.address)
-                                          << ", using base cost only";
-                                }
-                            }
+                            if (insn.callTarget == "memcpy" || insn.callTarget == "memset")
+                                sizeArg = copySizeArg(instructions, i);
                             bbEnergy +=
                                 model.getCallEnergy(insn.addrMode, insn.callTarget, sizeArg);
                         } else {
@@ -304,14 +320,8 @@ int main(int argc, char **argv) {
             unmappedCount++;
             if (insn.mnemonic == "call") {
                 std::optional<unsigned> sizeArg;
-                if (insn.callTarget == "memcpy" || insn.callTarget == "memset") {
-                    sizeArg = extractSizeArg(instructions, i);
-                    if (!sizeArg.has_value()) {
-                        PLOGW << "WARNING: could not extract constant size for " << insn.callTarget
-                              << " at 0x" << Twine::utohexstr(insn.address)
-                              << ", using base cost only";
-                    }
-                }
+                if (insn.callTarget == "memcpy" || insn.callTarget == "memset")
+                    sizeArg = copySizeArg(instructions, i);
                 unmappedEnergy += model.getCallEnergy(insn.addrMode, insn.callTarget, sizeArg);
             } else {
                 unmappedEnergy += model.getEnergy(insn.mnemonic, insn.addrMode);

passes/runtime/vcc_wait.c

@@ -14,6 +14,15 @@
  * ~150 uA combined, which would fight the capacitor's charging current),
  * so the sleeping board draws only LPM3-level current (~1 uA).
  *
+ * Each wait is bracketed by a pulse on P3.5 for the Saleae (channel 1,
+ * see docs/intermittent.md): one right before the sleep loop and one
+ * right after it, so the host can sum the recharge time out of the
+ * end-to-end measurement. The exit pulse is a few cycles wider than the
+ * enter pulse, which is how the host tells them apart. Each pulse is a
+ * handful of cycles in front of a >=10 ms sleep, and a boundary that
+ * does not wait never touches the pin. hw_init (boot_common.inc) has
+ * already driven every port output-low, so no pin setup is needed.
+ *
  * Called from the .crt_0010 boot path BEFORE data/BSS initialization,
  * so this file must not use .data/.bss variables; cnt_wait lives in the
  * .nvm section, which is programmed at flash time and never touched by
@@ -41,6 +50,19 @@ __attribute__((section(".nvm"))) uint32_t cnt_wait = 0;
 /* Sample period in VLO (~9.4 kHz) ticks: ~10 ms. */
 #define SAMPLE_PERIOD_TICKS 94
 
+#define WAIT_PIN BIT5
+
+static inline void pulse_wait_enter(void) {
+    P3OUT |= WAIT_PIN;
+    P3OUT &= ~WAIT_PIN;
+}
+
+static inline void pulse_wait_exit(void) {
+    P3OUT |= WAIT_PIN;
+    __asm__ volatile("nop\n\tnop\n\tnop\n\tnop");
+    P3OUT &= ~WAIT_PIN;
+}
+
 /* Power up REF + ADC, take one battery-monitor sample, power both down.
    The ~75 us reference settling cost per sample is negligible against
    the 10 ms sample period. Long sample time (256 clocks) accommodates
@@ -84,6 +106,7 @@ void wait_until_vcc_full(void) {
        samples read far below the threshold and VCC only rises while
        waiting, so early inaccuracy is harmless. */
     if (sample_avcc_half() < VCC_FULL_ADC_COUNTS) {
+        pulse_wait_enter();
         cnt_wait++;
         TA0CCR0 = SAMPLE_PERIOD_TICKS;
         TA0CCTL0 = CCIE;
@@ -97,6 +120,7 @@ void wait_until_vcc_full(void) {
         TA0CTL = MC__STOP;
         TA0CCTL0 = 0;
         TA0CTL |= TACLR;
+        pulse_wait_exit();
     }
 }
 

results/chunking_overhead/chunked.csv

@@ -8,7 +8,7 @@ activity_recognition,10uF,ok,3247,33693.67,1
 bitcount,10uF,ok,1377,4428974.03,1
 chacha20,10uF,ok,1575,50808.39,1
 sensor_fusion,10uF,ok,970,25134.98,1
-poly1305,10uF,ok,1083,475324.33,1
+poly1305,10uF,ok,807,475284.8,1
 cuckoo_filter,10uF,ok,726,42792.49,1
-sha256,10uF,ok,1451,90023.65,1
+sha256,10uF,ok,783,90004.1,1
 stringsearch,10uF,ok,699,36199.28,1

results/intermittent/activity_recognition/milp.csv

@@ -1,11 +1,11 @@
-benchmark,capacitor,trace,status,region_boundaries,compilation_time_ms,profiling_time_ms,replay_seconds,execution_time_us,runtime_region_boundary_calls,runtime_wait_count,runtime_recovery_boots,result
-activity_recognition,board,1,ok,4,75,854,2.29,144446.63,,11,0,64
-activity_recognition,board,2,ok,4,75,854,3.18,619516.3,,13,0,64
-activity_recognition,board,3,ok,4,75,854,4.15,167939.47,,12,0,64
-activity_recognition,board,4,ok,4,75,854,5.97,3390377.2,,12,0,64
-activity_recognition,board,5,ok,4,75,854,4.47,1891121.82,,13,0,64
-activity_recognition,board,6,ok,4,75,854,2.89,1047546.96,,14,0,64
-activity_recognition,board,7,ok,4,75,854,3.87,2073055.26,,14,0,64
-activity_recognition,board,8,ok,4,75,854,3.54,919204.1,,17,0,64
-activity_recognition,board,9,ok,4,75,854,5.46,2619196.79,,12,0,64
-activity_recognition,board,10,ok,4,75,854,1.88,144510.19,,11,0,64
+benchmark,capacitor,trace,status,region_boundaries,compilation_time_ms,profiling_time_ms,replay_seconds,execution_time_us,wait_time_us,saleae_wait_count,saleae_wait_deaths,runtime_region_boundary_calls,runtime_wait_count,runtime_recovery_boots,result
+activity_recognition,board,1,ok,4,53,777,2.11,144329.48,108491.28,10,0,,11,0,64
+activity_recognition,board,2,ok,4,53,777,3.18,619375.18,583534.73,12,0,,13,0,64
+activity_recognition,board,3,ok,4,53,777,4.09,178735.3,142892.93,12,0,,13,0,64
+activity_recognition,board,4,ok,4,53,777,5.79,3273059.98,3237218.48,11,0,,12,0,64
+activity_recognition,board,5,ok,4,53,777,4.4,1898731.9,1862891.17,13,0,,14,0,64
+activity_recognition,board,6,ok,4,53,777,2.88,1034359.34,998516.18,12,0,,13,0,64
+activity_recognition,board,7,ok,4,53,777,3.79,2058317.77,2022475.07,12,0,,13,0,64
+activity_recognition,board,8,ok,4,53,777,3.47,918125.61,882278.99,15,0,,17,0,64
+activity_recognition,board,9,ok,4,53,777,5.3,2629188.2,2593344.23,11,0,,12,0,64
+activity_recognition,board,10,ok,4,53,777,1.89,144436.16,108596.75,10,0,,11,0,64

results/intermittent/activity_recognition/rockclimb.csv

@@ -1,11 +1,11 @@
-benchmark,capacitor,trace,status,region_boundaries,compilation_time_ms,profiling_time_ms,replay_seconds,execution_time_us,runtime_region_boundary_calls,runtime_wait_count,runtime_recovery_boots,result
-activity_recognition,board,1,ok,8,206,0,5.47,3361451.1,,49,1,64
-activity_recognition,board,2,ok,8,206,0,7.08,4486138.49,,69,1,64
-activity_recognition,board,3,ok,8,206,0,7.97,4058981.48,,113,1,64
-activity_recognition,board,4,ok,8,206,0,19.17,16568583.2,,85,0,64
-activity_recognition,board,5,ok,8,206,0,15.1,12478355.63,,67,4,64
-activity_recognition,board,6,ok,8,206,0,7.65,5840294.08,,67,1,64
-activity_recognition,board,7,ok,8,206,0,11.79,10032553.09,,64,0,64
-activity_recognition,board,8,ok,8,206,0,17.24,14620159.3,,94,9,64
-activity_recognition,board,9,ok,8,206,0,16.17,13387959.07,,60,0,64
-activity_recognition,board,10,ok,8,206,0,13.71,11864780.35,,58,9,64
+benchmark,capacitor,trace,status,region_boundaries,compilation_time_ms,profiling_time_ms,replay_seconds,execution_time_us,wait_time_us,saleae_wait_count,saleae_wait_deaths,runtime_region_boundary_calls,runtime_wait_count,runtime_recovery_boots,result
+activity_recognition,board,1,ok,8,20,0,4.78,2736150.77,2576701.08,47,1,,49,1,64
+activity_recognition,board,2,ok,8,20,0,6.98,4483566.14,4324075.65,64,1,,66,1,64
+activity_recognition,board,3,ok,8,20,0,8.0,4056380.49,3896776.74,108,1,,110,1,64
+activity_recognition,board,4,ok,8,20,0,21.61,19127260.8,18967726.07,89,0,,90,0,64
+activity_recognition,board,5,ok,8,20,0,14.9,12464805.86,12305302.36,59,4,,64,4,64
+activity_recognition,board,6,ok,8,20,0,7.67,5828039.78,5668545.83,62,1,,64,1,64
+activity_recognition,board,7,ok,8,20,0,11.69,10027816.82,9868314.33,61,0,,62,0,64
+activity_recognition,board,8,ok,8,20,0,17.21,14619806.11,14460245.1,81,9,,92,9,64
+activity_recognition,board,9,ok,8,20,0,16.18,13384105.98,13224597.49,59,0,,60,0,64
+activity_recognition,board,10,ok,8,20,0,13.58,11860629.75,11701133.84,51,9,,61,9,64

results/intermittent/activity_recognition/schematic.csv

@@ -1,11 +1,11 @@
-benchmark,capacitor,trace,status,region_boundaries,compilation_time_ms,profiling_time_ms,replay_seconds,execution_time_us,runtime_region_boundary_calls,runtime_wait_count,runtime_recovery_boots,result
-activity_recognition,board,1,ok,6,241,744,4.82,2653896.37,,45,1,64
-activity_recognition,board,2,ok,6,241,744,6.59,3919015.07,,57,1,64
-activity_recognition,board,3,ok,6,241,744,5.25,1275635.68,,87,0,64
-activity_recognition,board,4,ok,6,241,744,16.49,13894732.87,,61,0,64
-activity_recognition,board,5,ok,6,241,744,11.98,9389915.15,,55,3,64
-activity_recognition,board,6,ok,6,241,744,5.71,3793546.7,,50,1,64
-activity_recognition,board,7,ok,6,241,744,10.58,8821280.86,,53,0,64
-activity_recognition,board,8,ok,6,241,744,12.79,10123364.13,,74,6,64
-activity_recognition,board,9,ok,6,241,744,13.7,10892632.04,,50,0,64
-activity_recognition,board,10,ok,6,241,744,9.9,8032189.47,,50,6,64
+benchmark,capacitor,trace,status,region_boundaries,compilation_time_ms,profiling_time_ms,replay_seconds,execution_time_us,wait_time_us,saleae_wait_count,saleae_wait_deaths,runtime_region_boundary_calls,runtime_wait_count,runtime_recovery_boots,result
+activity_recognition,board,1,ok,6,25,900,4.67,2654377.86,2545984.45,42,1,,44,1,64
+activity_recognition,board,2,ok,6,25,900,4.68,2088089.05,1979674.93,54,0,,55,0,64
+activity_recognition,board,3,ok,6,25,900,5.19,1276593.37,1168134.47,86,0,,87,0,64
+activity_recognition,board,4,ok,6,25,900,16.4,13900076.94,13791646.69,63,0,,64,0,64
+activity_recognition,board,5,ok,6,25,900,13.7,11138709.02,11030287.35,50,3,,54,3,64
+activity_recognition,board,6,ok,6,25,900,5.6,3779749.01,3671334.02,49,1,,51,1,64
+activity_recognition,board,7,ok,6,25,900,10.71,8983871.81,8875466.93,50,0,,51,0,64
+activity_recognition,board,8,ok,6,25,900,12.79,10120970.4,10012534.39,65,6,,73,6,64
+activity_recognition,board,9,ok,6,25,900,13.69,10880080.13,10771673.83,51,0,,52,0,64
+activity_recognition,board,10,ok,6,25,900,9.69,8026349.63,7917956.65,42,6,,49,6,64

results/intermittent/activity_recognition/schematicO3.csv

@@ -1,11 +1,11 @@
-benchmark,capacitor,trace,status,region_boundaries,compilation_time_ms,profiling_time_ms,replay_seconds,execution_time_us,runtime_region_boundary_calls,runtime_wait_count,runtime_recovery_boots,result
-activity_recognition,board,1,ok,3,6,733,2.28,180918.22,,14,0,64
-activity_recognition,board,2,ok,3,6,733,3.28,644444.22,,16,0,64
-activity_recognition,board,3,ok,3,6,733,4.3,258806.35,,21,0,64
-activity_recognition,board,4,ok,3,6,733,5.96,3449749.38,,17,0,64
-activity_recognition,board,5,ok,3,6,733,5.68,3127211.14,,19,1,64
-activity_recognition,board,6,ok,3,6,733,2.98,1092608.52,,19,0,64
-activity_recognition,board,7,ok,3,6,733,4.87,3049884.86,,18,0,64
-activity_recognition,board,8,ok,3,6,733,4.99,2332980.82,,22,1,64
-activity_recognition,board,9,ok,3,6,733,6.2,3358003.03,,15,0,64
-activity_recognition,board,10,ok,3,6,733,1.98,169684.72,,13,0,64
+benchmark,capacitor,trace,status,region_boundaries,compilation_time_ms,profiling_time_ms,replay_seconds,execution_time_us,wait_time_us,saleae_wait_count,saleae_wait_deaths,runtime_region_boundary_calls,runtime_wait_count,runtime_recovery_boots,result
+activity_recognition,board,1,ok,3,1,1310,2.28,180769.26,141478.39,13,0,,14,0,64
+activity_recognition,board,2,ok,3,1,1310,3.18,645011.06,605715.18,15,0,,16,0,64
+activity_recognition,board,3,ok,3,1,1310,4.18,258584.99,219281.03,20,0,,21,0,64
+activity_recognition,board,4,ok,3,1,1310,5.98,3449093.97,3409796.94,17,0,,18,0,64
+activity_recognition,board,5,ok,3,1,1310,5.69,3129336.38,3090036.2,16,1,,18,1,64
+activity_recognition,board,6,ok,3,1,1310,2.8,1095998.1,1056699.35,17,0,,18,0,64
+activity_recognition,board,7,ok,3,1,1310,4.78,3038113.82,2998815.84,16,0,,17,0,64
+activity_recognition,board,8,ok,3,1,1310,5.0,2338786.43,2299481.27,18,1,,21,1,64
+activity_recognition,board,9,ok,3,1,1310,6.1,3358607.96,3319309.29,14,1,,16,1,64
+activity_recognition,board,10,ok,3,1,1310,1.88,169828.47,130538.04,12,0,,13,0,64

results/intermittent/aes/milp.csv

@@ -1,11 +1,11 @@
-benchmark,capacitor,trace,status,region_boundaries,compilation_time_ms,profiling_time_ms,replay_seconds,execution_time_us,runtime_region_boundary_calls,runtime_wait_count,runtime_recovery_boots,result
-aes,board,1,ok,4,274,797,3.14,965024.04,,26,1,107
-aes,board,2,ok,4,274,797,3.46,892999.21,,25,0,107
-aes,board,3,ok,4,274,797,4.62,562577.45,,25,0,107
-aes,board,4,ok,4,274,797,8.69,6090705.01,,28,3,107
-aes,board,5,ok,4,274,797,8.79,6217378.17,,27,2,107
-aes,board,6,ok,4,274,797,3.2,1235151.42,,25,0,107
-aes,board,7,ok,4,274,797,7.27,5509520.23,,25,0,107
-aes,board,8,ok,4,274,797,8.18,5456901.95,,29,3,107
-aes,board,9,ok,4,274,797,8.65,5882944.0,,26,1,107
-aes,board,10,ok,4,274,797,5.86,4095920.08,,28,3,107
+benchmark,capacitor,trace,status,region_boundaries,compilation_time_ms,profiling_time_ms,replay_seconds,execution_time_us,wait_time_us,saleae_wait_count,saleae_wait_deaths,runtime_region_boundary_calls,runtime_wait_count,runtime_recovery_boots,result
+aes,board,1,ok,4,200,793,3.09,964416.81,856453.44,24,1,,26,1,107
+aes,board,2,ok,4,200,793,3.4,891711.75,783747.74,24,0,,25,0,107
+aes,board,3,ok,4,200,793,4.41,562560.75,454598.8,24,0,,25,0,107
+aes,board,4,ok,4,200,793,8.49,6093413.74,5985450.26,24,2,,27,2,107
+aes,board,5,ok,4,200,793,8.69,6203940.9,6095979.38,24,2,,27,2,107
+aes,board,6,ok,4,200,793,3.08,1247256.38,1139297.34,24,0,,25,0,107
+aes,board,7,ok,4,200,793,7.01,5329294.16,5221329.9,24,0,,25,0,107
+aes,board,8,ok,4,200,793,8.0,5429137.3,5321176.4,24,3,,29,3,107
+aes,board,9,ok,4,200,793,8.59,5868201.23,5760236.14,24,2,,27,2,107
+aes,board,10,ok,4,200,793,5.79,4080716.36,3972760.4,24,3,,28,3,107