1
0
Fork 0
mirror of https://github.com/imjasonh/esp32 synced 2026-07-06 23:52:24 +00:00

cloud_log: tolerate missing NVS, trim PEM, demote tick logs

- ESP_ERR_NVS_NOT_FOUND from EspNvs::new(gcp,...) is normal for devices
  without a [gcp] block; return Ok(None) rather than crashing.
- parse_signing_key trims trailing whitespace; jq -r appends a newline
  on top of the PEM's own trailing newline and pem-rfc7468 then errors
  trying to parse a second (empty) block.
- Demote per-poll OTA lines (sleeping / no change / manifest) and
  per-flush cloud_log lines (posted batch / minted token) from info to
  debug. They fire continuously without actionable info, and at INFO
  they flood Cloud Logging. INFO stays for OTA update + verify events.

Plus README GCP setup steps and .gitignore for SA key files.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
This commit is contained in:
Jason Hall 2026-05-02 17:56:32 -04:00
parent 1264ca7da1
commit 03b4b223a8
4 changed files with 87 additions and 9 deletions

4
.gitignore vendored
View file

@ -6,6 +6,10 @@ provisioning.toml
sdkconfig.defaults sdkconfig.defaults
tools/publisher/target tools/publisher/target
tools/provision/target tools/provision/target
# GCP service-account key + the PEM extracted from it. Referenced by
# provisioning.toml; never check in.
gcp-sa-key.json
gcp-sa-key.pem
# Cargo.lock IS tracked: all crates here are binaries (firmware, # Cargo.lock IS tracked: all crates here are binaries (firmware,
# publisher, provision), and binary Cargo.lock files should be # publisher, provision), and binary Cargo.lock files should be

View file

@ -74,3 +74,59 @@ PAT setup) and a real cosign OIDC flow the first time per ~10min window
— a browser pops to authenticate. CI does this automatically via the — a browser pops to authenticate. CI does this automatically via the
GitHub Actions workflow's ambient OIDC token. GitHub Actions workflow's ambient OIDC token.
## Optional: GCP Cloud Logging
The firmware can ship structured `tracing` events (both app and OTA) to
Google Cloud Logging. Cloud logging is **opt-in per device** — without
the `[gcp]` block in `provisioning.toml` the device boots normally and
just emits to serial. Full design in [`logs-plan.md`](logs-plan.md).
One-time GCP setup, using `gcloud`:
```bash
PROJECT_ID=<YOUR_PROJECT_ID>
SA_NAME=<YOUR_SA_NAME>
SA_EMAIL=$SA_NAME@$PROJECT_ID.iam.gserviceaccount.com
# Create the service account.
gcloud iam service-accounts create $SA_NAME \
--display-name="ESP32 device logger" \
--project=$PROJECT_ID
# Grant only logging.logWriter — least privilege. The device can write
# log entries; it cannot read, delete, or do anything else.
gcloud projects add-iam-policy-binding $PROJECT_ID \
--member="serviceAccount:$SA_EMAIL" \
--role="roles/logging.logWriter"
# Create + download a JSON key. Keep this file safe — anyone with it
# can write logs as this SA.
gcloud iam service-accounts keys create gcp-sa-key.json \
--iam-account=$SA_EMAIL \
--project=$PROJECT_ID
# Extract the RSA private key PEM and the key id into the forms
# `tools/provision/` wants.
jq -j .private_key gcp-sa-key.json > gcp-sa-key.pem # -j: no trailing newline
KEY_ID=$(jq -r .private_key_id gcp-sa-key.json)
echo "sa_key_id = $KEY_ID"
```
Then add a `[gcp]` block to `provisioning.toml` (template in
`provisioning.toml.example`) using `$PROJECT_ID`, `$SA_EMAIL`, the
printed `KEY_ID`, and the path `gcp-sa-key.pem`. Re-run `make provision`
and reboot the device.
Logs land in Cloud Logging under
`projects/kontaindotme/logs/esp32-firmware`. The device's MAC is in
`resource.labels.node_id` for fleet filtering; the originating tracing
target is in `jsonPayload.module` so you can split app vs OTA in the
Cloud Logging UI (e.g.
`jsonPayload.module = "esp32_blinky::ota"` or
`= "esp32_blinky::sig"`).
**Threat model**: the SA private key sits in NVS unencrypted. Anyone
with physical access to the chip can extract it. Mitigation is
strict scoping (only `roles/logging.logWriter`, only on a
logs-tolerant project). Real hardening = Flash Encryption + Secure
Boot v2 (deferred; see [`ota.md`](ota.md) Future work).

View file

@ -57,10 +57,22 @@ pub struct GcpConfig {
impl GcpConfig { impl GcpConfig {
/// Load from NVS. `Ok(None)` means the device is intentionally not /// Load from NVS. `Ok(None)` means the device is intentionally not
/// configured for cloud logging (cloud logging is opt-in, missing /// configured for cloud logging (cloud logging is opt-in, missing
/// keys = disabled, no error). /// keys or missing namespace = disabled, no error).
pub fn load(partition: EspDefaultNvsPartition) -> Result<Option<Self>> { pub fn load(partition: EspDefaultNvsPartition) -> Result<Option<Self>> {
let nvs = EspNvs::new(partition, NVS_GCP_NS, false) let nvs = match EspNvs::new(partition, NVS_GCP_NS, false) {
.map_err(|e| anyhow!("open NVS namespace {}: {:?}", NVS_GCP_NS, e))?; Ok(n) => n,
Err(e)
if e.code() == esp_idf_svc::sys::ESP_ERR_NVS_NOT_FOUND as i32 =>
{
// Namespace has never been written. Cloud logging is
// opt-in; this is the normal state for a device that
// wasn't provisioned with a [gcp] block.
return Ok(None);
}
Err(e) => {
return Err(anyhow!("open NVS namespace {}: {:?}", NVS_GCP_NS, e));
}
};
let project_id = read_str(&nvs, NVS_PROJECT_ID, 96)?; let project_id = read_str(&nvs, NVS_PROJECT_ID, 96)?;
let sa_email = read_str(&nvs, NVS_SA_EMAIL, 128)?; let sa_email = read_str(&nvs, NVS_SA_EMAIL, 128)?;
@ -349,7 +361,7 @@ pub fn run(cfg: GcpConfig, queue: LogQueue) -> ! {
if token.as_ref().map_or(true, |t| t.expired_or_close()) { if token.as_ref().map_or(true, |t| t.expired_or_close()) {
match mint_access_token(&cfg, &signing_key) { match mint_access_token(&cfg, &signing_key) {
Ok(t) => { Ok(t) => {
tracing::info!( tracing::debug!(
expires_in_secs = t.expires_at_unix.saturating_sub(now_unix_secs().unwrap_or(0)), expires_in_secs = t.expires_at_unix.saturating_sub(now_unix_secs().unwrap_or(0)),
"cloud_log: minted new access token", "cloud_log: minted new access token",
); );
@ -370,7 +382,7 @@ pub fn run(cfg: GcpConfig, queue: LogQueue) -> ! {
let bearer = &token.as_ref().unwrap().token; let bearer = &token.as_ref().unwrap().token;
match post_batch(&log_name, &cfg.project_id, &mac, bearer, &batch) { match post_batch(&log_name, &cfg.project_id, &mac, bearer, &batch) {
Ok(()) => { Ok(()) => {
tracing::info!( tracing::debug!(
entries = batch.len(), entries = batch.len(),
"cloud_log: posted batch", "cloud_log: posted batch",
); );
@ -409,7 +421,13 @@ impl CachedToken {
} }
fn parse_signing_key(pem_bytes: &[u8]) -> Result<SigningKey<sha2::Sha256>> { fn parse_signing_key(pem_bytes: &[u8]) -> Result<SigningKey<sha2::Sha256>> {
let pem_str = std::str::from_utf8(pem_bytes).context("SA key PEM is not UTF-8")?; // Trim trailing whitespace — jq -r adds a final newline on top of
// the PEM's own trailing newline, and pem-rfc7468 then tries to
// parse a second (empty) block and errors at "pre-encapsulation
// boundary". Tolerate both forms.
let pem_str = std::str::from_utf8(pem_bytes)
.context("SA key PEM is not UTF-8")?
.trim();
let key = RsaPrivateKey::from_pkcs8_pem(pem_str).context("parse SA PKCS#8 private key")?; let key = RsaPrivateKey::from_pkcs8_pem(pem_str).context("parse SA PKCS#8 private key")?;
Ok(SigningKey::<sha2::Sha256>::new(key)) Ok(SigningKey::<sha2::Sha256>::new(key))
} }

View file

@ -120,7 +120,7 @@ pub fn run(
} else { } else {
jittered(cfg.poll_interval) jittered(cfg.poll_interval)
}; };
tracing::info!( tracing::debug!(
sleep_secs = sleep_for.as_secs(), sleep_secs = sleep_for.as_secs(),
failures = consecutive_failures, failures = consecutive_failures,
"ota: sleeping", "ota: sleeping",
@ -129,7 +129,7 @@ pub fn run(
match poll_once(&mut nvs, &cfg, &trust) { match poll_once(&mut nvs, &cfg, &trust) {
Ok(PollOutcome::NoChange) => { Ok(PollOutcome::NoChange) => {
consecutive_failures = 0; consecutive_failures = 0;
tracing::info!("ota: no change"); tracing::debug!("ota: no change");
} }
Ok(PollOutcome::Updated(d)) => { Ok(PollOutcome::Updated(d)) => {
tracing::info!(digest = %d, "ota: applied, rebooting in 1s"); tracing::info!(digest = %d, "ota: applied, rebooting in 1s");
@ -193,7 +193,7 @@ fn poll_once(
if layer.media_type != "application/vnd.esp32.firmware.bin" { if layer.media_type != "application/vnd.esp32.firmware.bin" {
bail!("unexpected layer mediaType: {}", layer.media_type); bail!("unexpected layer mediaType: {}", layer.media_type);
} }
tracing::info!( tracing::debug!(
manifest_digest = %format!("sha256:{}", manifest_digest_hex), manifest_digest = %format!("sha256:{}", manifest_digest_hex),
layer_digest = %layer.digest, layer_digest = %layer.digest,
size = layer.size, size = layer.size,