[Ovmsdev] v3 hardware disconnecting from v2 server

Stephen Casner casner at acm.org
Tue Mar 27 00:06:13 HKT 2018 

Please be warned that there may be false entries like 0x40000000 in
this crude stack trace because my code is simply scanning through the
stack looking for 0x80xxxxxx values and subtracting 0x40000000 from
them to print.  The reason for that translation is that the system
uses the high bits of the address field to encode some information
about the size of the register field in the stack frame.

But to Mark's point about the deep stack, we chose to concentrate the
work in the NetManTask with one large stack allocation rather than
having multiple tasks with perhaps somewhat less allocation.

                                                        -- Steve

On Mon, 26 Mar 2018, Mark Webb-Johnson wrote:

> Now that we can now see this, it is quite scary:
>
> Number of Tasks = 17      Stack:  Now   Max Total    Heap 32-bit SPIRAM
> 3FFF2658 23 Rdy NetManTask       3116  5340  7168   12152  27488      0
>
> $ ~/esp/xtensa-esp32-elf/bin/xtensa-esp32-elf-addr2line -pfiaC -e build/ovms3.elf 0x40000000  0x40000000  0x400ffe7c  0x400f2466  0x400f45f6  0x400f4726  0x400d8335  0x40152cdd  0x40151b95  0x400d81ee  0x400d830e  0x400e9d20  0x400e2e7d  0x400e2f94  0x400e2f86  0x400e2f86  0x400e2fbc  0x400edbab  0x400f11e4  0x400f124b  0x400edbda  0x40152976  0x401529e9  0x402050ee  0x400d8ded  0x400e5b4c  0x400d8474  0x400f6d25  0x400f6f1d  0x4008c604  0x40081374  0x400da5bb  0x400da622  0x400f647e  0x401e58d8  0x401d12f6  0x400ffe7c  0x401d1d8c  0x400f2466  0x400f45f6  0x400f777a  0x400f778d  0x400f778d  0x400f7801  0x400f7a59  0x400f7ce8  0x400f4494  0x400f4494  0x400eaf4d  0x400eaf8c
> 0x40000000: ?? ??:0
> 0x40000000: ?? ??:0
> 0x400ffe7c: gettimeofday at /Users/ivan/e/newlib_xtensa-2.2.0-bin/newlib_xtensa-2.2.0/xtensa-esp32-elf/newlib/libc/syscalls/../../../.././newlib/libc/syscalls/sysgettod.c:13
> 0x400f2466: cs_time at vehicle/OVMS.V3/components/mongoose/mongoose/mongoose.c:11373
> 0x400f45f6: mg_time at vehicle/OVMS.V3/components/mongoose/mongoose/mongoose.c:11373
> 0x400f4726: mg_send at vehicle/OVMS.V3/components/mongoose/mongoose/mongoose.c:11373
> 0x400d8335: SendCallback(WOLFSSH*, void*, unsigned int, void*) at vehicle/OVMS.V3/components/console_ssh/src/console_ssh.cpp:976
> 0x40152cdd: HighwaterCheck at vehicle/OVMS.V3/components/wolfssh/src/internal.c:4194
>  (inlined by) SendBuffered at vehicle/OVMS.V3/components/wolfssh/src/internal.c:849
> 0x40151b95: wolfSSH_stream_send at vehicle/OVMS.V3/components/wolfssh/src/ssh.c:635
> 0x400d81ee: ConsoleSSH::write(void const*, unsigned int) at vehicle/OVMS.V3/components/console_ssh/src/console_ssh.cpp:926
> 0x400d830e: ConsoleSSH::printf(char const*, ...) at vehicle/OVMS.V3/components/console_ssh/src/console_ssh.cpp:897
> 0x400e9d20: module_tasks(int, OvmsWriter*, OvmsCommand*, int, char const* const*) at vehicle/OVMS.V3/main/./ovms_module.cpp:823
> 0x400e2e7d: OvmsCommand::Execute(int, OvmsWriter*, int, char const* const*) at vehicle/OVMS.V3/main/./ovms_command.cpp:94
> 0x400e2f94: OvmsCommand::Execute(int, OvmsWriter*, int, char const* const*) at vehicle/OVMS.V3/main/./ovms_command.cpp:94
> 0x400e2f86: OvmsCommand::Execute(int, OvmsWriter*, int, char const* const*) at vehicle/OVMS.V3/main/./ovms_command.cpp:94
> 0x400e2f86: OvmsCommand::Execute(int, OvmsWriter*, int, char const* const*) at vehicle/OVMS.V3/main/./ovms_command.cpp:94
> 0x400e2fbc: OvmsCommandApp::Execute(int, OvmsWriter*, int, char const* const*) at vehicle/OVMS.V3/main/./ovms_command.cpp:94
> 0x400edbab: Execute(microrl*, int, char const* const*) at vehicle/OVMS.V3/main/./ovms_shell.cpp:49
> 0x400f11e4: print_prompt at vehicle/OVMS.V3/components/microrl/./microrl.c:281
>  (inlined by) new_line_handler at vehicle/OVMS.V3/components/microrl/./microrl.c:621
> 0x400f124b: microrl_insert_char at vehicle/OVMS.V3/components/microrl/./microrl.c:669
> 0x400edbda: OvmsShell::ProcessChar(char) at vehicle/OVMS.V3/main/./ovms_shell.cpp:70
> 0x40152976: GrowBuffer at vehicle/OVMS.V3/components/wolfssh/src/internal.c:4194
> 0x401529e9: GetInputData at vehicle/OVMS.V3/components/wolfssh/src/internal.c:4194
> 0x402050ee: OvmsShell::ProcessChars(char const*, int) at vehicle/OVMS.V3/main/./ovms_shell.cpp:75 (discriminator 2)
> 0x400d8ded: ConsoleSSH::HandleDeviceEvent(void*) at vehicle/OVMS.V3/components/console_ssh/src/console_ssh.cpp:479
> 0x400e5b4c: OvmsConsole::Poll(unsigned int, void*) at vehicle/OVMS.V3/main/./ovms_console.cpp:153
> 0x400d8474: ConsoleSSH::Receive() at vehicle/OVMS.V3/components/console_ssh/src/console_ssh.cpp:308
> 0x400f6d25: mg_http_handler2 at vehicle/OVMS.V3/components/mongoose/mongoose/mongoose.c:11373
> 0x400f6f1d: mg_http_handler at vehicle/OVMS.V3/components/mongoose/mongoose/mongoose.c:11373
> 0x4008c604: vTaskExitCritical at /Users/mark/esp/esp-idf/components/freertos/./tasks.c:4837
> 0x40081374: esp_crosscore_int_send at /Users/mark/esp/esp-idf/components/esp32/./crosscore_int.c:103
> 0x400da5bb: OvmsSSH::EventHandler(mg_connection*, int, void*) at vehicle/OVMS.V3/components/console_ssh/src/console_ssh.cpp:110
> 0x400da622: MongooseHandler(mg_connection*, int, void*) at vehicle/OVMS.V3/components/console_ssh/src/console_ssh.cpp:61
> 0x400f647e: mg_call at vehicle/OVMS.V3/components/mongoose/mongoose/mongoose.c:11373
> 0x401e58d8: netconn_recved at /Users/mark/esp/esp-idf/components/lwip/api/api_lib.c:830 (discriminator 4)
> 0x401d12f6: lwip_recvfrom at /Users/mark/esp/esp-idf/components/lwip/api/sockets.c:3229
> 0x400ffe7c: gettimeofday at /Users/ivan/e/newlib_xtensa-2.2.0-bin/newlib_xtensa-2.2.0/xtensa-esp32-elf/newlib/libc/syscalls/../../../.././newlib/libc/syscalls/sysgettod.c:13
> 0x401d1d8c: lwip_recvfrom_r at /Users/mark/esp/esp-idf/components/lwip/api/sockets.c:3229
> 0x400f2466: cs_time at vehicle/OVMS.V3/components/mongoose/mongoose/mongoose.c:11373
> 0x400f45f6: mg_time at vehicle/OVMS.V3/components/mongoose/mongoose/mongoose.c:11373
> 0x400f777a: mg_recv_common at vehicle/OVMS.V3/components/mongoose/mongoose/mongoose.c:11373
> 0x400f778d: mg_if_recv_tcp_cb at vehicle/OVMS.V3/components/mongoose/mongoose/mongoose.c:11373
> 0x400f778d: mg_if_recv_tcp_cb at vehicle/OVMS.V3/components/mongoose/mongoose/mongoose.c:11373
> 0x400f7801: mg_handle_tcp_read at vehicle/OVMS.V3/components/mongoose/mongoose/mongoose.c:11373
> 0x400f7a59: mg_mgr_handle_conn at vehicle/OVMS.V3/components/mongoose/mongoose/mongoose.c:11373
> 0x400f7ce8: mg_socket_if_poll at vehicle/OVMS.V3/components/mongoose/mongoose/mongoose.c:11373
> 0x400f4494: mg_mgr_poll at vehicle/OVMS.V3/components/mongoose/mongoose/mongoose.c:11373
> 0x400f4494: mg_mgr_poll at vehicle/OVMS.V3/components/mongoose/mongoose/mongoose.c:11373
> 0x400eaf4d: OvmsNetManager::MongooseTask() at vehicle/OVMS.V3/main/./ovms_netmanager.cpp:380
> 0x400eaf8c: MongooseRawTask(void*) at vehicle/OVMS.V3/main/./ovms_netmanager.cpp:370
>
> That is a huge stack for a little box.
>
> Regards, Mark.
>
> > On 26 Mar 2018, at 3:31 PM, Mark Webb-Johnson <mark at webb-johnson.net> wrote:
> >
> >
> > That is pretty cool. The ‘make monitor’ auto-magic address discovery makes the output useful:
> >
> > 3FFC8BAC 16 Blk tiT               484   692  6144       0      0    128
> > 0x401fe551  0x4008ebfd  0x401f23f8  0x401ebd0c  0x401e978e  0x401e978e
> > 0x401fe551: sys_arch_mbox_fetch at /Users/mark/esp/esp-idf/components/lwip/port/freertos/sys_arch.c:548
> > 0x4008ebfd: xQueueGenericReceive at /Users/mark/esp/esp-idf/components/freertos/./queue.c:2037
> > 0x401f23f8: sys_timeouts_mbox_fetch at /Users/mark/esp/esp-idf/components/lwip/core/timers.c:551
> > 0x401ebd0c: netif_poll at /Users/mark/esp/esp-idf/components/lwip/core/netif.c:440
> > 0x401e978e: tcpip_thread at /Users/mark/esp/esp-idf/components/lwip/api/tcpip.c:474
> > 0x401e978e: tcpip_thread at /Users/mark/esp/esp-idf/components/lwip/api/tcpip.c:474
> >
> > Now, the only issue is recreating the problem in a manner where I can get in with ‘make monitor’. Or, maybe not…
> >
> > $ ~/esp/xtensa-esp32-elf/bin/xtensa-esp32-elf-addr2line -pfiaC -e build/ovms3.elf 0x401fe551  0x4008ebfd  0x401f23f8  0x401ebd0c  0x401e978e  0x401e978e
> > 0x401fe551: sys_arch_mbox_fetch at /Users/mark/esp/esp-idf/components/lwip/port/freertos/sys_arch.c:548
> > 0x4008ebfd: xQueueGenericReceive at /Users/mark/esp/esp-idf/components/freertos/./queue.c:2037
> > 0x401f23f8: sys_timeouts_mbox_fetch at /Users/mark/esp/esp-idf/components/lwip/core/timers.c:551
> > 0x401ebd0c: netif_poll at /Users/mark/esp/esp-idf/components/lwip/core/netif.c:440
> > 0x401e978e: tcpip_thread at /Users/mark/esp/esp-idf/components/lwip/api/tcpip.c:474
> > 0x401e978e: tcpip_thread at /Users/mark/esp/esp-idf/components/lwip/api/tcpip.c:474
> >
> > It seems that I only need the ‘.elf’ file that was used to build the .bin that went on the module.
> >
> > This might be workable. I will try to keep the .elf and .bin files, and see if I can get something the next time it locks up (although I think my watchdog reboot may now avoid that).
> >
> > I’m 99.9% certain the issue is in the TiT tcpip task. Both wifi and pppos go down, while other parts of the system still seem to be running ok.
> >
> > Regards, Mark.
> >
> >> On 26 Mar 2018, at 2:33 PM, Stephen Casner <casner at acm.org <mailto:casner at acm.org>> wrote:
> >>
> >> On Sun, 25 Mar 2018, Stephen Casner wrote:
> >>
> >>> I might be able to add an option on the command to print each task's
> >>> PC, which the python code would look up to translate to a source
> >>> line number.
> >>
> >> I have now done this.  "module tasks" works as before, but "module
> >> tasks stack" shows a crude stack trace for each task.
> >>
> >>                                                        -- Steve
> >> _______________________________________________
> >> OvmsDev mailing list
> >> OvmsDev at lists.teslaclub.hk <mailto:OvmsDev at lists.teslaclub.hk>
> >> http://lists.teslaclub.hk/mailman/listinfo/ovmsdev
> >
>
>

More information about the OvmsDev mailing list