Exception decode problem

[PeterR]

I am struggling to debug an exception. I do not believe that the exception log correctly reports the calling sequence. Often the log reports the execution line as being the functions closing brace. Often the log reports a function name on the left which does not match the line number.

Most importantly, I cannot find the bug!

The exception happens when my higher level logic attempts to open a device which failed its 'probe'. I believe that the following report causes an exception through my use of a UDP logger (see code below).
If I don't register the logger then I don't get the exception.
I added a semaphore to prevent multiple threads logging at the same time (but suspect that the log handler is already protected) but this does not help.
It would help to understand what 'find_value' is doing and why it might go wrong.

Commenting

Code: Select all

sendto(udpSocket, buffer, strlen(buffer), 0, (struct sockaddr *)&s, sizeof(struct sockaddr_in));

allows the application to work. I have used my UDP logger for a year or so without issue.

The exception (with Semaphore):

Code: Select all

Guru Meditation Error: Core  0 panic'ed (LoadProhibited). Exception was unhandled.
Core 0 register dump:
PC      : 0x4017b208  PS      : 0x00060c30  A0      : 0x800e50c0  A1      : 0x3ffefd80
0x4017b208: find_value at C:/msys32/home/Pete/esp/esp-idf/components/pthread/pthread_local_storage.c:192

A2      : 0x10293849  A3      : 0x00000003  A4      : 0x00000000  A5      : 0x00000001
A6      : 0x00060823  A7      : 0x00000005  A8      : 0x800896eb  A9      : 0x3ffefd60
A10     : 0x3ffe3a38  A11     : 0x00001800  A12     : 0x3ffae768  A13     : 0x00000001
A14     : 0x00000034  A15     : 0x3ffe3db0  SAR     : 0x00000004  EXCCAUSE: 0x0000001c
EXCVADDR: 0x10293849  LBEG    : 0x4000c2e0  LEND    : 0x4000c2f6  LCOUNT  : 0x00000000

ELF file SHA256: a4d49bc51be0af2cb1c901f96b0c2e0e595c9d89dc8ed319e311e0cb589017ea

Backtrace: 0x4017b208:0x3ffefd80 0x400e50bd:0x3ffefda0 0x401806c3:0x3ffefdc0 0x400866c6:0x3ffefde0 0x40086bad:0x3ffefe00 0x40086a3a:0x3ffefe40 0x40086ab6:0x3ffefea0 0x4
011dbb8:0x3ffefed0 0x40082925:0x3ffeff10 0x40174d6e:0x3ffeff60 0x40131f38:0x3ffeffa0 0x401324e0:0x3ffeffc0 0x40131a7e:0x3ffeffe0 0x401067fa:0x3fff0100 0x4008ad59:0x3fff
0130
0x4017b208: find_value at C:/msys32/home/Pete/esp/esp-idf/components/pthread/pthread_local_storage.c:192
0x400e50bd: pthread_getspecific at C:/msys32/home/Pete/esp/esp-idf/components/pthread/pthread_local_storage.c:206
0x401806c3: sys_thread_sem_get at C:/msys32/home/Pete/esp/esp-idf/components/lwip/port/esp32/freertos/sys_arch.c:491
0x400866c6: netconn_apimsg at C:/msys32/home/Pete/esp/esp-idf/components/lwip/lwip/src/api/api_lib.c:950 (discriminator 4)
0x40086bad: netconn_send at C:/msys32/home/Pete/esp/esp-idf/components/lwip/lwip/src/api/api_lib.c:950 (discriminator 4)
0x40086a3a: lwip_sendto at C:/msys32/home/Pete/esp/esp-idf/components/lwip/lwip/src/api/sockets.c:3532
0x40086ab6: lwip_sendto_r at C:/msys32/home/Pete/esp/esp-idf/components/lwip/lwip/src/api/sockets.c:3532
0x4011dbb8: sendto at C:/msys32/home/Pete/esp/esp-idf/components/lwip/lwip/src/include/lwip/sockets.h:591
 (inlined by) udp_log_vprintf at C:/msys32/home/.../src/udplogger.c:54
0x40082925: esp_log_write at C:/msys32/home/Pete/esp/esp-idf/components/log/log.c:412

The UDP logger code:

Code: Select all

static int udp_log_vprintf(const char *fmt, va_list arguments) 
{
    struct sockaddr_in s;

    printf("Taking..\n");
    xSemaphoreTake(udpLogSemaphore, portMAX_DELAY);
     printf("Taken..\n");
     
    memset(&s, '\0', sizeof(struct sockaddr_in));
    s.sin_family = AF_INET;
    s.sin_port = (in_port_t)htons(UDP_LOG_PORT);
    s.sin_addr.s_addr = htonl(INADDR_BROADCAST);
    
    vsnprintf((char*)buffer, UDP_LOG_BUFFER_SIZE, fmt, arguments);
    
    sendto(udpSocket, buffer, strlen(buffer), 0, (struct sockaddr *)&s, sizeof(struct sockaddr_in));

    int size = vprintf(fmt, arguments);
    
    xSemaphoreGive(udpLogSemaphore);
    
    return size;
} /*-- udp_log_vprintf() --*/

[PeterR]

Think I found it.
The library I was importing uses vTaskSetThreadLocalStoragePointer index 0 which is already used by pthread library.

I have not used local storage before but it seems strange that there appears to be a platform dependency i.e. the code I am porting uses index 0 for its storage whilst ESP uses index 0 for all freeRTOS threads.
Would be interested in the structural/portability thinking here.

Anyway, easy to change once known.

[JoeThibodeau]

Nice find!
I hit the same issue in my post previous to yours and you gave me insight into why.

The change you made was to make the ported code use index[1] correct?
A stroke of luck you had the same issue I did at the same time!

Thanks in advance!

[PeterR]

Yea, use index[1]. Saw you had the same issue, but forgot to link, lol.
Would love to discuss the esthetics of ESP using index[0] with the team (& or why a not null warning) but pragmatically I'm over it, its an easy change.