Serial monitor delay at ESP32 startup

When my ESP32 starts up, the first 2.5seconds of any serial output is lost.

Here is an experiment. The first lines of my setup() are:

    ESP_LOGE("kinimain", "App started!");
    uint32_t waitSome = millis();
    uint32_t nowMillis;
    while ((nowMillis = millis()) < waitSome + 3500) {
      ESP_LOGE("kinimain", "delay %ld", nowMillis - waitSome);

What I see in the VsCode/PIO monitor when I turn the device on:

Reconnecting to /dev/cu.usbmodem831401 ....      Connected!
[  2702][E][KiniMain.cpp:102] setup(): [kinimain] delay 2405
[  2802][E][KiniMain.cpp:102] setup(): [kinimain] delay 2506
[  2902][E][KiniMain.cpp:102] setup(): [kinimain] delay 2606
[  3002][E][KiniMain.cpp:102] setup(): [kinimain] delay 2706
[  3102][E][KiniMain.cpp:102] setup(): [kinimain] delay 2806
[  3202][E][KiniMain.cpp:102] setup(): [kinimain] delay 2906
[  3302][E][KiniMain.cpp:102] setup(): [kinimain] delay 3006
[  3402][E][KiniMain.cpp:102] setup(): [kinimain] delay 3106
[  3502][E][KiniMain.cpp:102] setup(): [kinimain] delay 3206
[  3602][E][KiniMain.cpp:102] setup(): [kinimain] delay 3306
[  3702][E][KiniMain.cpp:102] setup(): [kinimain] delay 3406

If I reset the device while it is plugged in and outputting to serial:

Disconnected (read failed: [Errno 6] Device not configured)
Reconnecting to /dev/cu.usbmodem831401 .         Connected!
[  1602][E][KiniMain.cpp:102] setup(): [kinimain] delay 1305
[  1702][E][KiniMain.cpp:102] setup(): [kinimain] delay 1406
[  1802][E][KiniMain.cpp:102] setup(): [kinimain] delay 1506
[  1902][E][KiniMain.cpp:102] setup(): [kinimain] delay 1606
[  2002][E][KiniMain.cpp:102] setup(): [kinimain] delay 1706
[  2102][E][KiniMain.cpp:102] setup(): [kinimain] delay 1806
[  2202][E][KiniMain.cpp:102] setup(): [kinimain] delay 1906
[  2302][E][KiniMain.cpp:102] setup(): [kinimain] delay 2006
[  2402][E][KiniMain.cpp:102] setup(): [kinimain] delay 2106
[  2502][E][KiniMain.cpp:102] setup(): [kinimain] delay 2206
[  2602][E][KiniMain.cpp:102] setup(): [kinimain] delay 2306
[  2702][E][KiniMain.cpp:102] setup(): [kinimain] delay 2406
[  2802][E][KiniMain.cpp:102] setup(): [kinimain] delay 2506

For some reason, it takes 2 seconds or more to start receiving serial output, when the device is first powered on, and 1 second if the device is restarted, severing the serial connection and reconnecting to it.

Why I think this is something that could be done better, is this command line hack:

while true; 
cu -l /dev/cu.usbmodem831401 -s 115200

When I turn the power on to the attached device:

cu: /dev/cu.usbmodem831401: Line in use
[   599][E][KiniMain.cpp:102] setup(): [kinimain] delay 299
[   699][E][KiniMain.cpp:102] setup(): [kinimain] delay 399
[   799][E][KiniMain.cpp:102] setup(): [kinimain] delay 499
[   899][E][KiniMain.cpp:102] setup(): [kinimain] delay 599
[   999][E][KiniMain.cpp:102] setup(): [kinimain] delay 699
[  1099][E][KiniMain.cpp:102] setup(): [kinimain] delay 799
[  1199][E][KiniMain.cpp:102] setup(): [kinimain] delay 899
[  1299][E][KiniMain.cpp:102] setup(): [kinimain] delay 999
[  1399][E][KiniMain.cpp:102] setup(): [kinimain] delay 1099

How can I get that better performance of about ~300ms?

What gets output during the first second is important, and right now I have to put in a delay of about 2.5seconds to ensure that I don’t miss anything. And sadly I miss anything output prior to my app getting started by the OS (If I do a esp_restart() or a crash, I get to see the initial output since there seems to be no serial port detach/reattach).

BTW, I am using a custom ESP32 board with JTAG.

Pinging to see if anyone can help.

What’s really weird is that it seems to be getting worse! Over the past few days it has taken 4 seconds or more to see the log messages start coming in.

I’m going to try and restart my computer and run nothing else to see if I can eliminate some of the delay. It’s odd though since every now and then, I see it manage to relay the logs in less than 500ms.