Weird monitor behaviour with printf on IDF 3.0

[ajcalderont]

Hi, I'm having issues with monitor output with ESP-IDF 3.0 on Windows 10. I'm using a Wemos Lolin32 and an Adafruit HUZZAH32, and with both boards I'm having the same issue. Consider this test program (using cpp):

Code: Select all

#include "freertos/FreeRTOS.h"
#include "freertos/task.h"

extern "C" {void app_main(void);}

void app_main(void)
{
	while(1)
	{
		for(int i = 0; i < 504; i++)
		{
			printf("%.2X ", i%256);
			if((i + 1) % 24 == 0) printf("\n");
		}
		printf("\n\n");
		vTaskDelay(5000 / portTICK_PERIOD_MS);
	}
}

The output should be two digits hex numbers separated by a space, on a 24x21 array like this:

Code: Select all

00 01 02 03 04 05 06 07 08 09 0A 0B 0C 0D 0E 0F 10 11 12 13 14 15 16 17
18 19 1A 1B 1C 1D 1E 1F 20 21 22 23 24 25 26 27 28 29 2A 2B 2C 2D 2E 2F
30 31 32 33 34 35 36 37 38 39 3A 3B 3C 3D 3E 3F 40 41 42 43 44 45 46 47
48 49 4A 4B 4C 4D 4E 4F 50 51 52 53 54 55 56 57 58 59 5A 5B 5C 5D 5E 5F
60 61 62 63 64 65 66 67 68 69 6A 6B 6C 6D 6E 6F 70 71 72 73 74 75 76 77
78 79 7A 7B 7C 7D 7E 7F 80 81 82 83 84 85 86 87 88 89 8A 8B 8C 8D 8E 8F
90 91 92 93 94 95 96 97 98 99 9A 9B 9C 9D 9E 9F A0 A1 A2 A3 A4 A5 A6 A7
A8 A9 AA AB AC AD AE AF B0 B1 B2 B3 B4 B5 B6 B7 B8 B9 BA BB BC BD BE BF
C0 C1 C2 C3 C4 C5 C6 C7 C8 C9 CA CB CC CD CE CF D0 D1 D2 D3 D4 D5 D6 D7
D8 D9 DA DB DC DD DE DF E0 E1 E2 E3 E4 E5 E6 E7 E8 E9 EA EB EC ED EE EF
F0 F1 F2 F3 F4 F5 F6 F7 F8 F9 FA FB FC FD FE FF 00 01 02 03 04 05 06 07
08 09 0A 0B 0C 0D 0E 0F 10 11 12 13 14 15 16 17 18 19 1A 1B 1C 1D 1E 1F
20 21 22 23 24 25 26 27 28 29 2A 2B 2C 2D 2E 2F 30 31 32 33 34 35 36 37
38 39 3A 3B 3C 3D 3E 3F 40 41 42 43 44 45 46 47 48 49 4A 4B 4C 4D 4E 4F
50 51 52 53 54 55 56 57 58 59 5A 5B 5C 5D 5E 5F 60 61 62 63 64 65 66 67
68 69 6A 6B 6C 6D 6E 6F 70 71 72 73 74 75 76 77 78 79 7A 7B 7C 7D 7E 7F
80 81 82 83 84 85 86 87 88 89 8A 8B 8C 8D 8E 8F 90 91 92 93 94 95 96 97
98 99 9A 9B 9C 9D 9E 9F A0 A1 A2 A3 A4 A5 A6 A7 A8 A9 AA AB AC AD AE AF
B0 B1 B2 B3 B4 B5 B6 B7 B8 B9 BA BB BC BD BE BF C0 C1 C2 C3 C4 C5 C6 C7
C8 C9 CA CB CC CD CE CF D0 D1 D2 D3 D4 D5 D6 D7 D8 D9 DA DB DC DD DE DF
E0 E1 E2 E3 E4 E5 E6 E7 E8 E9 EA EB EC ED EE EF F0 F1 F2 F3 F4 F5 F6 F7

But monitor randomly adds an extra digit or space to some of the numbers, like this (extra space after 05, extra space after 4F, 334 instead of 34):

Code: Select all

00 01 02 03 04 05  06 07 08 09 0A 0B 0C 0D 0E 0F 10 11 12 13 14 15 16 17
18 19 1A 1B 1C 1D 1E 1F 20 21 22 23 24 25 26 27 28 29 2A 2B 2C 2D 2E 2F
30 31 32 33 34 35 36 37 38 39 3A 3B 3C 3D 3E 3F 40 41 42 43 44 45 46 47
48 49 4A 4B 4C 4D 4E 4F  50 51 52 53 54 55 56 57 58 59 5A 5B 5C 5D 5E 5F
60 61 62 63 64 65 66 67 68 69 6A 6B 6C 6D 6E 6F 70 71 72 73 74 75 76 77
78 79 7A 7B 7C 7D 7E 7F 80 81 82 83 84 85 86 87 88 89 8A 8B 8C 8D 8E 8F
90 91 92 93 94 95 96 97 98 99 9A 9B 9C 9D 9E 9F A0 A1 A2 A3 A4 A5 A6 A7
A8 A9 AA AB AC AD AE AF B0 B1 B2 B3 B4 B5 B6 B7 B8 B9 BA BB BC BD BE BF
C0 C1 C2 C3 C4 C5 C6 C7 C8 C9 CA CB CC CD CE CF D0 D1 D2 D3 D4 D5 D6 D7
D8 D9 DA DB DC DD DE DF E0 E1 E2 E3 E4 E5 E6 E7 E8 E9 EA EB EC ED EE EF
F0 F1 F2 F3 F4 F5 F6 F7 F8 F9 FA FB FC FD FE FF 00 01 02 03 04 05 06 07
08 09 0A 0B 0C 0D 0E 0F 10 11 12 13 14 15 16 17 18 19 1A 1B 1C 1D 1E 1F
20 21 22 23 24 25 26 27 28 29 2A 2B 2C 2D 2E 2F 30 31 32 33 334 35 36 37
38 39 3A 3B 3C 3D 3E 3F 40 41 42 43 44 45 46 47 48 49 4A 4B 4C 4D 4E 4F
50 51 52 53 54 55 56 57 58 59 5A 5B 5C 5D 5E 5F 60 61 62 63 64 65 66 67
68 69 6A 6B 6C 6D 6E 6F 70 71 72 73 74 75 76 77 78 79 7A 7B 7C 7D 7E 7F
80 81 82 83 84 85 86 87 88 89 8A 8B 8C 8D 8E 8F 90 91 92 93 94 95 96 97
98 99 9A 9B 9C 9D 9E 9F A0 A1 A2 A3 A4 A5 A6 A7 A8 A9 AA AB AC AD AE AF
B0 B1 B2 B3 B4 B5 B6 B7 B8 B9 BA BB BC BD BE BF C0 C1 C2 C3 C4 C5 C6 C7
C8 C9 CA CB CC CD CE CF D0 D1 D2 D3 D4 D5 D6 D7 D8 D9 DA DB DC DD DE DF
E0 E1 E2 E3 E4 E5 E6 E7 E8 E9 EA EB EC ED EE EF F0 F1 F2 F3 F4 F5 F6 F7

Anyone else having this problem?

[ESP_Angus]

I may know what this is. For some reason, after the Fall Creators Update Windows 10 idf_monitor.py started sometimes randomly throwing an exception after writing to the "standard output" console. This is the OS telling us the write failed, for whatever reason.

On investigation, people noticed that a subsequent write nearly always succeeded so a kludge was added to retry the write:
https://github.com/espressif/esp-idf/bl ... or.py#L593

I'm not sure anyone verified whether the "failed" write actually appeared on the console. Might explain the doubled-up letters.

If you change around line 597 of idf_monitor.py function (I'm assuming release/v3.0 branch):

Code: Select all

                    except IOError:
                        # Windows 10 bug since the Fall Creators Update, sometimes writing to console randomly fails
                        # (but usually succeeds the second time, it seems.) Ref https://github.com/espressif/esp-idf/issues/1136
                        try:
                            self.output.write(b)
                        except IOError:
                            pass

To look like this:

Code: Select all

                    except IOError:
                        # Windows 10 bug since the Fall Creators Update, sometimes writing to console randomly fails
                        # (but usually succeeds the second time, it seems.) Ref https://github.com/espressif/esp-idf/issues/1136
                        pass

... does the duplicate output go away?

[ajcalderont]

Hi ESP_Angus, thanks for your reply. This is what I have:

Code: Select all

def _output_write(self, data):
            # Windows 10 bug since the Fall Creators Update, sometimes writing to console randomly fails
            # (but usually succeeds afterwards, it seems.)
            # Ref https://github.com/espressif/esp-idf/issues/1136
            for tries in range(3):
                try:
                    self.output.write(data)
                    return
                except IOError:
                    pass

What should I change?

[ajcalderont]

Hi again ESP_Angus, I just tried without the "for", like this:

Code: Select all

def _output_write(self, data):
            # Windows 10 bug since the Fall Creators Update, sometimes writing to console randomly fails
            # (but usually succeeds afterwards, it seems.)
            # Ref https://github.com/espressif/esp-idf/issues/1136
            #for tries in range(3):
            try:
				self.output.write(data)
				return
            except IOError:
				pass

And now is working, without repeated spaces or characters. Thank you very much!

[ESP_Angus]

And now is working, without repeated spaces or characters. Thank you very much!

Thanks for confirming this. Will put a proper fix into IDF ASAP.