[v4.4 branch] [Serial JTAG console] calling esp_vfs_usb_serial_jtag_use_driver() causes device to freeze (IDFGH-8411)

[chipweinberger]

Edit: This freeze is due to the USB Serial JTAG "blocking" when no terminal is listening to the output.
This PR fixes the issue: #10208

Answers checklist.

• I have read the documentation ESP-IDF Programming Guide and the issue is not addressed there.
• I have updated my IDF branch (master or release) to the latest version and checked that the issue is present there.
• I have searched the issue tracker for a similar issue and not found a similar issue.

IDF version.

v4.4.2-312-g08fa67fe92, top of branch

commit 08fa67fe92ece5bf2b0df16a0075ce5feb379a58 (HEAD -> release/v4.4, origin/release/v4.4)
Merge: 1b70a08cc9 2da3035b52
Author: morris <[email protected]>
Date:   Wed Sep 21 22:01:12 2022 +0800

    Merge branch 'bugfix/i2s_receive_data_lost_v4.4' into 'release/v4.4'
    
    i2s: fix message queue overflow condition (v4.4)
    
    See merge request espressif/esp-idf!20209

Development Kit.

ESP32S3 Dev Kit C

What is the expected behavior?

I expect the USB Serial JTAG Console to function.

What is the actual behavior?

Approximately ~110 milliseconds after I call esp_vfs_usb_serial_jtag_use_driver(), the device locks up.

Steps to reproduce.

Code

void pd_console_api_init(pd_console_output_t output, pd_error_t* error)
{
    pd_err_unset(error);

    esp_err_t err;

    ESP_LOGI(TAG, "init");

    // initialize error
    pd_error_t* sharedError = pd_console_shared_error();
    if (sharedErrorInit == false) {
        pd_err_init_alloc(sharedError);
        sharedErrorInit = true;
    }

    // Drain stdout before reconfiguring it
    pd_fflush(stdout, error);
    if (is_fail(*error)){
        return;
    }

    pd_fsync(fileno(stdout), error);
    if (is_fail(*error)){
        return;
    }

    // Disable buffering on stdin 
    pd_setvbuf(stdin, NULL, _IONBF, 0, error);
    if (is_fail(*error)){
        return;
    }

    // serial JTAG
    if(output == PD_CONSOLE_SERIAL_JTAG) {

        // Minicom, screen, idf_monitor send CR when ENTER key is pressed
        esp_vfs_dev_usb_serial_jtag_set_rx_line_endings(ESP_LINE_ENDINGS_CR);

        // Move the caret to the beginning of the next line on '\n'
        esp_vfs_dev_usb_serial_jtag_set_tx_line_endings(ESP_LINE_ENDINGS_CRLF);

        // Enable non-blocking mode on stdin and stdout
        fcntl(fileno(stdout), F_SETFL, 0);
        fcntl(fileno(stdin), F_SETFL, 0);

        usb_serial_jtag_driver_config_t usb_serial_jtag_config {
            .tx_buffer_size = 1024,
            .rx_buffer_size = 1024,
        };

        // Install USB-SERIAL-JTAG driver for interrupt-driven reads and writes
        err = usb_serial_jtag_driver_install(&usb_serial_jtag_config);
        if (err != ESP_OK) {
            pd_err_fail(error, TAG, "usb_serial_jtag_driver_install() failed. %s", esp_err_to_name(err));
            return;
        }

        // Tell vfs to use usb-serial-jtag driver
        esp_vfs_usb_serial_jtag_use_driver();
    }
    
    // UART
    if(output == PD_CONSOLE_UART) {

        // Minicom, screen, idf_monitor send CR when ENTER key is pressed
        int rv = esp_vfs_dev_uart_port_set_rx_line_endings(CONSOLE_UART_NUM, ESP_LINE_ENDINGS_CR);
        if (rv != 0){
            pd_err_fail(error, TAG, "esp_vfs_dev_uart_port_set_rx_line_endings() failed. errno: %i", errno);
            return;
        }

        // Move the caret to the beginning of the next line on '\n' 
        rv = esp_vfs_dev_uart_port_set_tx_line_endings(CONSOLE_UART_NUM, ESP_LINE_ENDINGS_CRLF);
        if (rv != 0){
            pd_err_fail(error, TAG, "esp_vfs_dev_uart_port_set_tx_line_endings() failed. errno: %i", errno);
            return;
        }

        // Configure UART. Note that REF_TICK is used so that the baud rate remains
        // correct while APB frequency is changing in light sleep mode.
        const uart_config_t uart_config = {
                .baud_rate = 115200,
                .data_bits = UART_DATA_8_BITS,
                .parity = UART_PARITY_DISABLE,
                .stop_bits = UART_STOP_BITS_1,
                .flow_ctrl = UART_HW_FLOWCTRL_DISABLE,
                .rx_flow_ctrl_thresh = 0,
    #ifdef CONFIG_IDF_TARGET_ESP32S3
                .source_clk = UART_SCLK_XTAL,
    #else 
                .source_clk = UART_SCLK_APB,
    #endif
        };

        // Set UART pins(TX: IO4, RX: IO5, RTS: IO18, CTS: IO19)
        err = uart_set_pin(CONSOLE_UART_NUM, 
            pd_gpio_get(PD_GPIO_UART_TX), // tx
            pd_gpio_get(PD_GPIO_UART_RX), // rx
            UART_PIN_NO_CHANGE, //rts
            UART_PIN_NO_CHANGE); //cts
        if (err != ESP_OK){
            pd_err_fail(error, TAG, "uart_set_pin() failed. %s", esp_err_to_name(err));
            return;
        }

        // Install UART driver for interrupt-driven reads and writes
        err = uart_driver_install(CONSOLE_UART_NUM, 256, 0, 0, NULL, 0);
        if (err != ESP_OK){
            pd_err_fail(error, TAG, "uart_driver_install() failed. %s", esp_err_to_name(err));
            return;
        }

        err = uart_param_config(CONSOLE_UART_NUM, &uart_config);
        if (err != ESP_OK){
            pd_err_fail(error, TAG, "uart_param_config() failed. %s", esp_err_to_name(err));
            return;
        }

        // Tell VFS to use UART driver
        esp_vfs_dev_uart_use_driver(CONSOLE_UART_NUM);
    }

    // Initialize the console
    esp_console_config_t console_config = {
            .max_cmdline_length = 256,
            .max_cmdline_args = 8,
            .hint_color = atoi(LOG_COLOR_CYAN),
            .hint_bold = 0,
    };
    err = esp_console_init(&console_config);
    if (err != ESP_OK){
        pd_err_fail(error, TAG, "esp_console_init() failed. %s", esp_err_to_name(err));
        return;
    }

    // remember success
    esp_console_init_success = true;

    // Configure linenoise line completion library 
    // Enable multiline editing. If not set, long commands will scroll within a single line. 
    linenoiseSetMultiLine(1);

    // Tell linenoise where to get command completions and hints 
    linenoiseSetCompletionCallback(&esp_console_get_completion);
    linenoiseSetHintsCallback((linenoiseHintsCallback*) &esp_console_get_hint);

    // Set command history size
    linenoiseHistorySetMaxLen(100);

    // Set command maximum length
#ifdef ESP_IDF4v4
    linenoiseSetMaxLineLen(console_config.max_cmdline_length);
#endif

    // Don't return empty lines
    linenoiseAllowEmpty(false);

    err = esp_console_register_help_command();
    if (err != ESP_OK){
        pd_err_fail(error, TAG, "esp_console_register_help_command() failed. %s", esp_err_to_name(err));
        return;
    }

    //
    // Register All Commands
    //

    uint32_t count = pd_api_registry_count();
    pd_registered_api_t* apiList = pd_api_registry_list();

    ESP_LOGI(TAG, "registering %u uris", count);

    for (int i = 0; i < count; i++){

        pd_registered_api_t api = apiList[i];

        pd_console_register_cmd(api.uri, api.sig, error);

        if (is_fail(*error)) {
            pd_err_fail(error, TAG, "failed to register %s", api.uri);
            return;
        }

        // 
        // also, register a convenience API uri
        // that is just a number
        //

        // Note: we never deallocate this on purpose. it lives forever.
        char* apiIdxStr = (char*) malloc_safe(4, HERE);
        snprintf(apiIdxStr, 4, "%u", i);

        pd_console_register_cmd((const char*) apiIdxStr, api.sig, error);

        if (is_fail(*error)) {
            pd_err_fail(error, TAG, "failed to register %s", api.uri);
            return;
        }
    }

    pd_err_success(error);
    return;
}

Additional Details:

SDK Console Config:

[chipweinberger]

Wish I had more details to share.

[chipweinberger]

I can confirm that commenting out esp_vfs_usb_serial_jtag_use_driver(); causes the freeze to go away, but then the console goes crazy with UART noise:

jmx-console> 
Console: Unrecognized command: [26;1R[26;14R[26;1R[26;1R[26;14R[26;1R[26;1R[26;14R[26;1R[26;1R[26;14R[26;1R[26;1R[26;14R[26;1R[26;1R[26;14R[26;1R[26;1R[26;14R[26;1R[26;1R[26;14R[26;1R[26;1R[26;14R[26;1R[26;1R[26;14R

[chipweinberger]

My overall goal is to default to UART Console, but to switch to Serial JTAG Console when/if a USB-C Host PC is detected.

I'm not sure if this is possible.

@igrr we talked about something similar before.

[igrr]

I think the issue here is that the "secondary" console channel is output-only, and it doesn't work with the console (which requires input).
The solution here would be to reopen stdout with the usb-serial-jtag device, instead of using the secondary output channel. However I see now that if usb-serial-jtag is not selected in menuconfig, we don't even compile the usb-serial-jtag code. So this use case will require a couple changes in IDF.

[chipweinberger]

Thanks for the response.

Yes, not being able to compile without selecting Serial Jtag as a secondary console in menuconfig is an issue I've hit. I should have mentioned that.

Please keep me updated! Would love to be able to support this

[chipweinberger]

Is it possible to support 2 consoles at the same time? UART & USB Serial JTAG, both with input?

If not, then I need the ability to choose at runtime! =)

[chipweinberger]

Pull Request: #9877

Just a basic start to having more flexibility. Not as good as fully dynamic, but output only is a nice start.

[chipweinberger]

Also this PR fixes the freeze, and also fixes dynamic init & deinit of consoles: #9983

Other Changes:

• esp_vfs_usb_serial_jtag_use_driver_for_rx(); is now the default for the USB Serial JTAG console. Rx operations will block, but Tx operations will not, by default. (I should make this a KConfig, before merge)

[chipweinberger]

Closing. The fix was merged. https://github.com/espressif/espidf/commit/720b8d9c1a741784cdcf73ca3cef0afb3ef92208