Exception occurred 'InstrProhibited' during TLS connection initilization

[aljazerzen]

I'm trying to make a HTTPS request using embedded-tls on ESP32.

I'm running into the following error:

INFO - esp-wifi configuration EspWifiConfig { rx_queue_size: 5, tx_queue_size: 3, static_rx_buf_num: 10, dynamic_rx_buf_num: 32, static_tx_buf_num: 0, dynamic_tx_buf_num: 32, csi_enable: false, ampdu_rx_enable: true, ampdu_tx_enable: true, amsdu_tx_enable: false, rx_ba_win: 6, max_burst_size: 1, country_code: "CN", country_code_operating_class: 0, mtu: 1492, tick_rate_hz: 100, listen_interval: 3, beacon_timeout: 6, ap_beacon_timeout: 300, failure_retry_cnt: 1, scan_method: 0 }
DEBUG - Wifi mode Sta set
WARN - esp_wifi_internal_tx 12290
start connection task
Device capabilities: Ok(EnumSet(Client))
Starting wifi
DEBUG - Unhandled event: HomeChannelChange
Wifi started!
About to connect...
DEBUG - Unhandled event: HomeChannelChange
Wifi connected!
Waiting to get IP address...
Got IP: 192.168.8.149/24
INFO - HTTP connect...
WARN - Read buffer is smaller than 16640 bytes, which may cause problems!
DEBUG - start_record(Handshake(false))



Exception occurred 'InstrProhibited'
Context
PC=0xe0002c00       PS=0x00060011
A0=0x8010aa4e       A1=0x3ffd85b0       A2=0xe0002c00       A3=0x3ffd8af8       A4=0x3ffd97a0
0x3ffd85b0 - g_cnxMgr
    at ??:??
0x3ffd8af8 - g_wifi_mac_time_delta
    at ??:??
A5=0x3ffd9620       A6=0x3ffd9838       A7=0x3ffd97e8       A8=0x8008bb3b       A9=0x3ffb4080
0x3ffb4080 - net::____embassy_main_task::{{closure}}::HEAP
    at ??:??
A10=0x3ffb41e0      A11=0x4010c4ac      A12=0x3ffc54bc      A13=0x3ffb41e0      A14=0x3ffc54c0
0x3ffb41e0 - net::____embassy_main_task::{{closure}}::HEAP
    at ??:??
0x4010c4ac - _critical_section_1_0_release
    at ??:??
0x3ffc54bc - esp_wifi::preempt::CTX_NOW.0
    at ??:??
0x3ffb41e0 - net::____embassy_main_task::{{closure}}::HEAP
    at ??:??
0x3ffc54c0 - esp_wifi::preempt::CTX_NOW.0
    at ??:??
A15=0x3ffb2188
0x3ffb2188 - net::____embassy_main_task::{{closure}}::HEAP
    at ??:??
SAR=00000020
EXCCAUSE=0x00000014 EXCVADDR=0xe0002c00
LBEG=0x4000c2e0     LEND=0x4000c2f6     LCOUNT=0x00000000
THREADPTR=0x00000000
SCOMPARE1=0x00000100
BR=0x00000000
ACCLO=0x00000000    ACCHI=0x00000000
M0=0x00000000       M1=0x00000000       M2=0x00000000       M3=0x00000000
F64R_LO=0x00000000  F64R_HI=0x00000000  F64S=0x00000000
FCR=0x00000000      FSR=0x00000000
F0=0x00000000       F1=0x00000000       F2=0x00000000       F3=0x00000000       F4=0x00000000
F5=0x00000000       F6=0x00000000       F7=0x00000000       F8=0x00000000       F9=0x00000000
F10=0x00000000      F11=0x00000000      F12=0x00000000      F13=0x00000000      F14=0x00000000
F15=0x00000000
0x40080a64
esp_hal::interrupt::xtensa::vectored::handle_interrupt
    at ??:??
0x40080a33
handle_interrupts
    at ??:??
0x40080dc2
.RestoreContext
    at ??:??
0x40040001
0x400f8c45
p256::arithmetic::field::field_impl::fe_mul
    at ??:??
0x400e4ec7
<primeorder::projective::ProjectivePoint<C> as core::ops::arith::Mul<S>>::mul
    at ??:??
0x400e7a39
elliptic_curve::public_key::PublicKey<C>::from_secret_scalar
    at ??:??
0x400e1227
embedded_tls::handshake::client_hello::ClientHello<CipherSuite>::encode
    at ??:??
0x400df47b
embedded_tls::buffer::CryptoBuffer::with_u24_length
    at ??:??
0x400e73e7
embedded_tls::record::ClientRecord<CipherSuite>::encode_payload
    at ??:??

This is my code:

async fn send_http(stack: embassy_net::Stack<'_>, url: &str, rng: &mut Rng) {
    let dns_socket = embassy_net::dns::DnsSocket::new(stack);
    let tcp_state = embassy_net::tcp::client::TcpClientState::<1, 4096, 4096>::new();
    let tcp_client = embassy_net::tcp::client::TcpClient::new(stack, &tcp_state);

    let mut buf_rx = [0; 16384];
    let mut buf_tx = [0; 16384];
    let tls_config = reqwless::client::TlsConfig::new(
        generate_u64(rng),
        &mut buf_rx,
        &mut buf_tx,
        reqwless::client::TlsVerify::None,
    );

    let mut client =
        reqwless::client::HttpClient::new_with_tls(&tcp_client, &dns_socket, tls_config);

    log::info!("HTTP connect...");
    let request = client.request(reqwless::request::Method::GET, url).await;
    let request = match request {
        Ok(r) => r,
        Err(e) => {
            log::error!("Cannot connect: {e:?}");
            panic!();
        }
    };
    log::info!("HTTP connection open");

    let mut request = request.content_type(reqwless::headers::ContentType::TextPlain);

    let mut header_buf = [0; 4096];
    let response = request.send(&mut header_buf).await.unwrap();
    println!(
        "response: {:?}, content-length: {:?}",
        response.status, response.content_length
    );

    let mut body = response.body().reader();

    let mut buf = [0; 4096];
    while let Ok(bytes_read) = body.read(&mut buf).await {
        println!("{}", core::str::from_utf8(&buf[0..bytes_read]).unwrap());
        if bytes_read == 0 {
            break;
        }
    }
}

fn generate_u64(rng: &mut Rng) -> u64 {
    (rng.random() as u64) << 32 | (rng.random() as u64)
}

I'm I doing something wildly wrong, or is this actually a bug?

I'm willing to spend more time on this, investigate, open a fix PR, but I'd need help on how to even debug this.

PS: not sure if this is the correct location for this issue

[ther0bster]

I'm getting the same error on a esp32 using embedded-tls, defmt, and embassy

Here with defmt TRACE level logging.

...
I (405) boot: Loaded app from partition at offset 0x10000
I (405) boot: Disabling RNG early entropy source...
TRACE [0]: adding
TRACE [1]: adding
TRACE DHCP reset
INFO IPv4: DOWN
TRACE Waiting for config up
INFO [wifi] attempting to connect to WIFI AP
INFO [wifi] connected to WIFI AP
TRACE Waiting for config up
DEBUG IPv4: UP
DEBUG    IP address:      10.0.0.144/24
DEBUG    Default gateway: Some(10.0.0.1)
DEBUG    DNS server:      10.0.0.1
INFO [wifi] IP address: 10.0.0.144/24
INFO Making HTTPS request...
ERROR [debug] Initializing RX buffer
ERROR [debug] Creating TLS buffers
ERROR [debug] Creating DNS socket
ERROR [debug] Initializing TCP client state
ERROR [debug] Creating TCP client
ERROR [debug] Generating random seed
ERROR [debug] Random seed: 2359456668908589977
ERROR [debug] Configuring TLS
ERROR [debug] Creating HTTPS client with TLS
ERROR [debug] Creating request: GET https://httpbin.org/get
TRACE sending 29 octets to 10.0.0.1 from port 28382
DEBUG address 10.0.0.1 not in neighbor cache, sending ARP request
TRACE SocketHandle(0): neighbor 10.0.0.1 missing, silencing until t+1.000s
TRACE filled 10.0.0.1 => Ethernet(<redacted>) (was empty)
TRACE SocketHandle(0): neighbor 10.0.0.1 discovered, unsilencing
TRACE sending 29 octets to 10.0.0.1 from port 28382
TRACE receiving 61 octets from 10.0.0.1:28382
TRACE A: 50.19.58.113
TRACE A: 52.203.38.8
TRACE too many addresses in response, ignoring 52.203.38.8
TRACE [2]: adding
TRACE state=Closed=>SynSent
TRACE outgoing segment will send data or flags
TRACE sending SYN
TRACE rtte: sampling at seq=1391800827
TRACE rtte: sample=322 rtt=303 dev=80 rto=623
TRACE received SYN|ACK
TRACE state=SynSent=>Established
TRACE outgoing segment will acknowledge
TRACE sending ACK
DEBUG start_record(Handshake(false))
ERROR

Exception occurred 'InstrProhibited'
ERROR Context { PC: 0, PS: 397072, A0: 0, A1: 1073439200, A2: 1073576224, A3: 1073576372, A4: 0, A5: 1073576228, A6: 0, A7: 0, A8: 2148022130, A9: 4294967288, A10: 2091618480, A11: 1073432332, A12: 72, A13: 200, A14: 1, A15: 1073432332, SAR: 4, EXCCAUSE: 20, EXCVADDR: 0, LBEG: 1073791817, LEND: 1073791851, LCOUNT: 4294967295, THREADPTR: 0, SCOMPARE1: 256, BR: 0, ACCLO: 0, ACCHI: 0, M0: 0, M1: 0, M2: 0, M3: 0, F64R_LO: 0, F64R_HI: 0, F64S: 0, FCR: 0, FSR: 128, F0: 1127972864, F1: 1114374144, F2: 1132462080, F3: 0, F4: 0, F5: 0, F6: 0, F7: 0, F8: 0, F9: 0, F10: 0, F11: 0, F12: 0, F13: 0, F14: 0, F15: 0 }

here the code snippet making the HTTPS GET request

const RX_BUFFER_SIZE: usize = 8192;
const TCP_BUFFER_SIZE: usize = 4096;
const TLS_BUFFER_SIZE: usize = 16640;
const MAX_TCP_CONNECTIONS: usize = 1;

pub struct HttpsClient<'a> {
    stack: Stack<'a>,
    rng: Rng,
    rx_buffer: [u8; RX_BUFFER_SIZE],
}

impl<'a> HttpsClient<'a> {
    pub fn new(stack: Stack<'a>, rng: Rng) -> Self {
        Self {
            stack,
            rng,
            rx_buffer: [0; RX_BUFFER_SIZE],
        }
    }

    async fn https_request(
        &mut self,
        method: Method,
        url: &str,
    ) -> Result<&[u8], reqwless::Error> {
        error!("[debug] Initializing RX buffer");
        self.rx_buffer = [0; RX_BUFFER_SIZE];

        error!("[debug] Creating TLS buffers");
        let mut tls_read_buffer = [0; TLS_BUFFER_SIZE];
        let mut tls_write_buffer = [0; TLS_BUFFER_SIZE];

        error!("[debug] Creating DNS socket");
        let dns_socket = DnsSocket::new(self.stack);

        error!("[debug] Initializing TCP client state");
        let tcp_client_state =
            TcpClientState::<MAX_TCP_CONNECTIONS, TCP_BUFFER_SIZE, TCP_BUFFER_SIZE>::new();

        error!("[debug] Creating TCP client");
        let tcp_client = TcpClient::new(self.stack, &tcp_client_state);

        error!("[debug] Generating random seed");
        let random_seed = (self.rng.random() as u64) << 32 | self.rng.random() as u64;
        error!("[debug] Random seed: {:?}", random_seed);

        error!("[debug] Configuring TLS");
        let tls_config = TlsConfig::new(
            random_seed,
            &mut tls_read_buffer,
            &mut tls_write_buffer,
            TlsVerify::None,
        );

        error!("[debug] Creating HTTPS client with TLS");
        let mut https_client = HttpClient::new_with_tls(&tcp_client, &dns_socket, tls_config);

        error!("[debug] Creating request: {} {}", method.as_str(), url);
        let mut request = https_client.request(method, url).await?;

        error!("[debug] Sending request");
        let response = request.send(&mut self.rx_buffer).await?;

        error!("[debug] Reading response body");
        let body = response.body().read_to_end().await?;
        error!("[debug] Received body length: {}", body.len());

        Ok(body)
    }
}

here relavant parts from `Cargo.toml`

[dependencies]
embassy-executor = { version = "0.7", features = ["task-arena-size-65536"] }
embassy-futures = "0.1"
embassy-net = { version = "0.6", features = [
    "defmt",
    "tcp",
    "udp",
    "dns",
    "dhcpv4",
    "dhcpv4-hostname",
    "medium-ethernet"
] }
embassy-sync = "0.6"
embassy-time = { version = "0.4", features = ["generic-queue-8"] }
esp-backtrace = { version = "0.15", features = [
    "esp32",
    "exception-handler",
    "panic-handler",
    "defmt",
] }
esp-hal = { version = "0.23", features = [ "esp32" ] }
esp-hal-embassy = { version = "0.6", features = [ "esp32" ] }
esp-println = { version = "0.13", features = [
    "esp32",
    "log",
    "defmt-espflash",
] }
log = { version = "0.4" }
esp-alloc = { version = "0.6" }
esp-wifi = { version = "0.12", features = [
    "esp32",
    "wifi",
] }
anyhow = { version = "1.0", default-features = false }
heapless = { version = "0.8", default-features = false }
static_cell = { version = "2.1" }
defmt = "0.3"
reqwless = { version = "0.13", features = [ "defmt" ] }
serde = { version = "1.0", default-features = false, features = ["derive"] }
serde-json-core = "0.6"

Is this issue related to reqwless?

I'm also willing to help debug, investigate, and come up with a fix.

[ther0bster]

I was able to resolve the issue by decreasing the embassy-executor task-arena-size in Cargo.toml from

embassy-executor = { version = "0.7", features = ["task-arena-size-65536"] }

to

embassy-executor = { version = "0.7", features = ["task-arena-size-49152"] }

[aljazerzen]

I was not able to increase the task arena size enough to contain the whole response. So I rewrote the thing in sync rust, without reqwless. The result was that it became apparent that I don't enough memory on the chip to make this HTTP request.

My solution now is not setup a proxy that translates HTTPS requests that return JSON to some binary protocol which should be much more memory efficient.

[aljazerzen]

As for this issue, this is not a bug/problem with reqwless or even embedded-tls, but a common problem users might face when making HTTP requests. It might be worth adding a note about this error somewhere in the README?