Pin Direction Change compiles but does not seem to be working and produces weird Info Log messages that I can not supress:

[joeatbayes]

The source-code below compiles but produces a informational log entry every time I try to change the pin direction
I tried to suppress it in the code with feature flags in the TOML and on the command line.

You can see logger config commented out. I also tried with the command line
RUST_LOG=none cargo run --release which had no affect.

If I understand the log message below it should be cycling state between inputEn:1 and OutputEN:1 as I toggle
the pin direction back and forth. Since it is not doing so I am guessing the change from input to output mode is
failing.

Please Help:

• How do I turn off these log messages the time to generate the messes up the algorithm?
• Where is the documentation on how to interpret these log messages?
• Why are the pin states shown in the log not changing as expected?
  • Should it be cycling between InputEn: 1 and OutputEn: 1
    as I use the csense_in.into_output()?; and cout.into_input()?;
• Where is a complete example showing changing pin direction change working as expected?
• Is there a single line watchdog reset?
  • On the ESP IDF Page It mentions esp_task_wdt_reset() I think this is what we need. I am hoping that somebody has either written the safe wrappers for this or can at least give me a quick main.rs that demonstrates it use through unsafe calls.

SAMPLE OF LOG MESSAGES I CAN NOT DISABLE

I (346) sleep: Configure to isolate all GPIO pins in sleep state
I (353) sleep: Enable automatic switching of GPIO sleep configuration
I (361) main_task: Started on CPU0
I (371) main_task: Calling app_main()
I (371) gpio: GPIO[11]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (381) gpio: GPIO[1]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (391) gpio: GPIO[1]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (411) gpio: GPIO[1]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (411) gpio: GPIO[1]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (411) gpio: GPIO[1]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (421) gpio: GPIO[1]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown

Sample Source

from https://github.com/joeatbayes/embedded-rust-examples/tree/main/ex-gpio-change-pin-direction-var-cap-read-1-pin

//! WARN: Broken until we can figure out how to 
//! turn of GPIO Direction Change Logging.
//! Use .... ../ex-gpio-measure-time-to-change-high-to-low)
// - It is similar but uses 2 pins to avoid the need to change pin direction.
//! 
//! Measure change in capacitance by measuring time to discharge a 
//! a capacitor from! VCC (3.3V) to logic 0 at approximately 0.7V
//! We Oversample and average this across a large number of passes 
//! to help filter out noise.
//! See readme.md for pin mapping and explanation
#![allow(unused_imports)]
#![allow(dead_code)]

use anyhow::Result;
use esp_idf_hal::gpio;
use esp_idf_hal::gpio::PinDriver;
use esp_idf_hal::delay::Delay;
use esp_idf_hal::peripherals::Peripherals;
use esp_idf_hal::prelude::*;
use std::time::{Duration, Instant};
//use env_logger::{Builder, Target};
//use esp_idf_sys;

fn main() -> anyhow::Result<()> {
    esp_idf_hal::sys::link_patches();

    // Disable informational log messages just in case
    // they are what is affecting our timing.
    //Builder::new()
    //.filter(None, log::LevelFilter::Off)
    //.target(Target::Stdout)
    //.init();

    let peripherals = Peripherals::take()?;

    let led_pin = peripherals.pins.gpio11;
    let sense_pin = peripherals.pins.gpio1;    
    let delay: Delay = Default::default();
    let mut led = PinDriver::output(led_pin)?;
    let mut csense_in = PinDriver::input(sense_pin)?;
    // must be mutable because we are assigning to it
    // latter to avoid moved rule violations.
    
    let num_pass = 1000;
      // Oversample number of passes more will
      // reduce variability but takes longer 
      
    let full_discharge_time_ms = 2; 
      // milliseconds to allow full discharge
      // any remaining charge in capacitor will add a 
      // uknown element to how much charging is accomplished
      // during charge_time_us which means it could leave the
      // pin higher for longer modifying the readings.

    let charge_time_us = 25; // micro seconds to allow pin to discharge
     // Charge time is to allow capacitor a level close to
     // VCC once pin drive is set high.  It Should
     // be fast since no resistor between capacitor and
     // sensor.  May consider adding 3.3K resistor between pin
     // and electrode to avoid excessive drain on the pin. 

    loop {                
        led.set_high()?;        
        let mut cout = csense_in.into_output()?; // Change our Pin into output mode
        cout.set_low()?;  // Start discharge cycle
        delay.delay_ms(full_discharge_time_ms); // Wait for long enough to ensure fully discharged          
        csense_in = cout.into_input()?; // have to Move back to keep move/borrow checker happy
        let mut sum = 0;          
        let start = Instant::now();                 
        for _pass in 1..1000 {
            cout = csense_in.into_output()?; // Change our Pin into output mode            
            cout.set_high()?; // Start charging the capacitor** 
            delay.delay_us(charge_time_us);           
            csense_in = cout.into_input()?;
              // places drive pin into high impedance mode.
              // stops charging capacitor leaving pin in 
              // input mode so we can sense hole long it takes
              // to drain.
            let mut cnt = 0;            
            // Wait for capacitor to drain to ground
            // Through bleed resistor.
            while csense_in.is_high() && cnt < 1000000 {
                cnt += 1;
            }
            sum += cnt;
        }
        // Average out our oversamples
        let elap1 = Instant::now().duration_since(start).as_nanos();  
        let tout = sum / num_pass;                
        println!("elap during pin state change cnt={:?} {:?}ms", tout, ((elap1 as f64 / num_pass as f64 ) / 1000000_f64));
        led.set_low()?;                
        
        delay.delay_ms(18); // Allow WDT to auto clear
          // TODO: TO RESET WATCHDOG IN TIGHT LOOP LIKE THIS
          // without depending on sleep time for auto reset

        delay.delay_ms(1000); // Slow things down so I can read them
    }
}

CARGO FILE

[package]
name = "ex-uart-non-block-rs485"
version = "0.1.0"
authors = ["joe ellsworth <[email protected]>"]
edition = "2021"
resolver = "2"
rust-version = "1.71"

[profile.release]
opt-level = "s"
debug = false
info = false

[profile.dev]
debug = true    # Symbols are nice and they don't increase the size on Flash
opt-level = "z"

[features]
default = ["std", "embassy", "esp-idf-svc/native"]

pio = ["esp-idf-svc/pio"]
std = ["alloc", "esp-idf-svc/binstart", "esp-idf-svc/std"]
alloc = ["esp-idf-svc/alloc"]
nightly = ["esp-idf-svc/nightly"]
experimental = ["esp-idf-svc/experimental"]
embassy = ["esp-idf-svc/embassy-sync", "esp-idf-svc/critical-section", "esp-idf-svc/embassy-time-driver"]

[dependencies]
#log = { version = "0.4", default-features = false }
log = { version = "0.4", features = ["release_max_level_off"] }
esp-idf-svc = { version = "0.48", default-features = false }
esp-idf-hal = "0.43.1"
anyhow = "1.0.82"
esp-idf-sys = "0.34.1"
#env_logger = "0.11.3"

[build-dependencies]
embuild = "0.31.3"

Arduino Sketch that works with Same Logic on Same Hardware and Same Circuit

/* Example of changing pin direction on ESP32
   Measuring capacitance by first Charing variable capacitor by driving pin
   high for a charging interval then converting pin into high inpedance input
   measuring time for it to drop below logic low. 

   Tested on RainAmp Soil Sensor Baord 2020-04-20
   ESPS3 Mini 1 - 4MB Flash, 2MB PSRAM

   Arduino Board Selected: ESP32S3 Dev Module
     USB CDC Enabled On Boot - Enabled
     CPU Frequency 80MHz
     CPU Debug Level WARN
     CPU Firmware 4MB
     CPU PSRAM - QSPI RAM 
  
  Wiring
    GPIO1 -> SENS_OSC
    GPIO1 -> 8M Resistor -> GND  
    GPIO11 -> 4K Reistor -> GND
*/

#define LED_PIN 11
#define SENSE_PIN 1
#define NUM_PASS 100
#define FULL_DISCHARGE_MS 2
#define CHARGE_US 2000
#define MAX_COUNT_DISCHARG 1000000

// the setup routine runs once when you press reset:
void setup() {
  // initialize serial communication at 9600 bits per second:
  Serial.begin(115200);
  pinMode(LED_PIN, OUTPUT);
  pinMode(SENSE_PIN, OUTPUT);
  digitalWrite(LED_PIN, HIGH);
  digitalWrite(SENSE_PIN, LOW);
}

// the loop routine runs over and over again forever:
void loop() {
  // Give Sense Pin Time to fully discharge
  pinMode(SENSE_PIN, OUTPUT);
  digitalWrite(SENSE_PIN, LOW);
  delay(FULL_DISCHARGE_MS);
  digitalWrite(LED_PIN, HIGH);

  // Oversample collection of time to discharge
  long start = micros();
  unsigned long sum = 0;
  for (int pass=0; pass < NUM_PASS; pass++)
  {
    pinMode(SENSE_PIN, OUTPUT);
    digitalWrite(SENSE_PIN, HIGH);     
    delayMicroseconds(CHARGE_US);
    pinMode(SENSE_PIN, INPUT);
    // Wait for capacitor to drain through
    // Bleed resistor
    unsigned long cnt = 0;
    while((digitalRead(SENSE_PIN) == HIGH) && (cnt < MAX_COUNT_DISCHARG)){
      cnt += 1;
    }
    sum  += cnt;
  }
  unsigned long avg = sum / NUM_PASS;  
  unsigned long elap = micros() - start;
  unsigned long elapDrop = elap - (NUM_PASS * CHARGE_US);
  float avgUs = (float)elapDrop / (float) NUM_PASS;
  digitalWrite(LED_PIN, LOW);

  Serial.printf("avg Cnt %ld  Elap Avg %8.5f us\n", avg, avgUs);
  
  delay(1500);  // delay in between reads for stability
}

[empirephoenix]

I can at least help you with the watchdog I think (if you are fine with slight jitter),
If you create the delay manually, eg
Delay::new(10), it will pause anything longer than 10us via the esp task delay, so basically do this (but convert time to clock cyles before):
unsafe { vTaskDelay(delay_for_at_minimum_clock_cycles) };
This will reset the task watchdog, as it does return controll FreeRTOS.

(Which you might need to do from time to time anyway to not fail out of wifi or other stuff that the os manages in background)

[Vollbrecht]

How do I turn off these log messages the time to generate the messes up the algorithm?

This messages come from the underlying esp-idf system and are hardcoded log messages. And for whatever reason they decided to have a info log level on a specifc api call we do. You can reduce the loglevel either at compile time via sdkconfig entry or in your code calling the esp-idf log api. The former is simpler and can be done via the different LOG options by either reducing the default log level or the maximum level. ( add CONFIG_LOG_MAXIMUM_LEVEL_WARN=y in your sdkconfig file).

Where is the documentation on how to interpret these log messages?

There are logs that come from our api and there are logs that come from the esp-idf system itself. In your case you are seeing esp-idf system logs. You can find out more in the offfical esp-idf doc

Why are the pin states shown in the log not changing as expected?

They are, you just don't see it in the logs. The reason is: on a state transition (for example from output -> input) we need to reset the pin to a known good state, than applying the new state. The logs only show you the "resetting" part where everything seams to be off but not the new state part. From memory you would see the other transaction if you would increase the log level to debug.

[joeatbayes]

empirephoenix

@empirephoenix Why is the unsafe function vTaskDelay any better than just having the delay.delay_ms(18); either way it has to be outside the tight loop or it would mess up our timing. Also do you have a complete main.rs showing how to use this along with the cargo changes. There is also FreeRtos::delay_ms(1000); which I think may call vTaskDelay. What I have found out of experimental testing is that anything less than 18ms yields timeouts and it doesn't seem to matter which delay function I call.

What I really want is what I had in TI MSP430 SDK and AVR SDK which was the equivalent to resetWatchDog() it is just a counter so it should not require any delay other than the time to change the counter value.

On the ESP IDF Page It mentions esp_task_wdt_reset() I think this is what we need. I am hoping that somebody has either written the safe wrappers for this or can at least give me a quick main.rs that demonstrates it use through unsafe calls.

[joeatbayes]

@Vollbrecht Thanks for the Hint. The actual CONFIG_LOG_MAXIMUM_LEVEL_WARN=y did not remove the offensive log entries but you got me looking in the right direction.

The code started working correctly when I updated the file sdkconfig.defaults with the following lines:
#CONFIG_LOG_MAXIMUM_LEVEL_WARN=y
CONFIG_LOG_DEFAULT_LEVEL_NONE=y
CONFIG_ESP_TASK_WDT_TIMEOUT_S=60
CONFIG_ESP_DEBUG_STUBS_ENABLE=n

Thanks for the help, I really appreciate it.

[empirephoenix]

empirephoenix

@empirephoenix Why is the unsafe function vTaskDelay any better than just having the delay.delay_ms(18);

It is not better, but basically there are only two ways for a delay, busy loop or suspending the task and returning to freertos. the delay object will switch between both ways, based on the threshold it has configured. Since you are using the default threshold, is why you need to use a rather long delay to feed the watchdog. You can either set that threshold lower, or just directly tell the os, that you want to delay for only as short as possible (vTaskDelay(1) , tho no guarantees that it will not be longer if some other task blocks the cpu). Also check what you use for CONFIG_FREERTOS_HZ as that determines the minimum delay you can archive

Anyway since you are on one of the dual core esp32 you can also just do
unsafe {esp_idf_sys::esp_task_wdt_reset()}
and hog the first core (but this might fail badly if you every switch to a single core one)

[Vollbrecht]

we go of topic here but i want to still clarify this: each core has its own IDLE task. Resetting the watchdog from a higher prio task than the idle task itself is fighting a symptom not a cause. You can increase the time till a watchdog will trigger, and you dont need to delay in every itteration of your hot loop. You just need to give up some cpu execution time in the total time intervall ( E.g every 5 sec on default iirc). The idle task itself has also some other housekeeping stuff todo besides just updating the watchdog, so its good practice to give it a chance to run, For further info you can read on the official docu in esp-idf about the IDLE task.

Also for general question please use the matrix chat channel we provide.