[Ovmsdev] OVMS going comatose
Michael Balzer
dexter at expeedo.de
Sun Mar 28 17:08:51 HKT 2021
Steve,
I haven't seen any lockups like yours recently. A single report on a
forum about 4 weeks ago was due to a corrupted config store partition,
and I'm not sure that was already with the new WolfSSL code.
I've just scanned the current crash reports on my server (updated
hourly: https://dexters-web.de/f/firmware/developer/crashreport.csv) for
anything WolfSSL related and found only one crash clearly originating
within WolfSSL (decoded backtrace attached). That seems to be unlocking
a mutex from the wrong task.
What's more often now is the abort from the failed assertion in
lock_acquire_generic, which seems to be caused by an ESP_LOG call from
within a critical section. According to this info…
https://github.com/espressif/esp-idf/issues/4412#issuecomment-559208996
…that could be the source for our primary issue of unexplained WDTs. But
I think that can only either trigger the dog or trigger an abort
immediately, not freeze the module.
So… sorry, no clue here.
Regards,
Michael
Am 28.03.21 um 04:31 schrieb Stephen Casner:
> On Thu, 25 Mar 2021, Stephen Casner wrote:
>> Since updating my in-car OVMS with a build from the master branch
>> after my WolfSSL update I've experienced a couple of instances where
>> connectivity from app was lost. The first time I needed a quick
>> resolution so I just reset OVMS. It happened again during the night
>> while charging, and this time I connected to the console to check
>> conditions before resetting. What I found was that the async console
>> was not responding at all. Since I have OVMS configured to drop into
>> gdb on a crash, I should have seen something. I've turned on logging
>> to file to see if that sheds any light.
> I had another apparent crash today, now with file logging enabled.
> This occurred while on a drive, so away from the home wifi. The last
> log messages indicate that the crash happened when bringing up
> networking via the modem connection:
>
> 2021-03-27 12:48:39.688 PDT I (176007218) netmanager: MODEM up (with WIFI client down): starting network with MODEM
> 2021-03-27 12:48:39.698 PDT I (176007228) time: Starting SNTP client
> 2021-03-27 12:48:39.708 PDT I (176007238) webserver: Launching Web Server
> 2021-03-27 12:48:39.708 PDT I (176007238) webserver: Binding to port 80 (http)
> 2021-03-27 12:48:39.708 PDT I (176007238) webserver: Binding to port 443 (https)
> 2021-03-27 12:48:39.768 PDT I (176007298) telnet: Launching Telnet Server
> 2021-03-27 12:48:39.768 PDT I (176007298) ssh: Launching SSH Server
> 2021-03-27 12:48:39.788 PDT I (176007318) ovms-server-v2: Status: Network is up, so attempt network connection
>
> The last logged activity is to start server v2, and I do have TLS
> enabled, so this may indicate a problem with the new WolfSSL
> integration. Does this sound similar to any of the other crashes seen
> recently?
>
> -- Steve
> _______________________________________________
> OvmsDev mailing list
> OvmsDev at lists.openvehicles.com
> http://lists.openvehicles.com/mailman/listinfo/ovmsdev
--
Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal
Fon 02333 / 833 5735 * Handy 0176 / 206 989 26
-------------- next part --------------
Using elf file: tmp/3.2.016-46-gf7523a8a-elf/ovms3.elf
0x4008e58e is in invoke_abort (/home/balzer/esp/esp-idf/components/esp32/panic.c:156).
151 #endif
152 while (1) {
153 if (esp_cpu_in_ocd_debug_mode()) {
154 __asm__ ("break 0,0");
155 }
156 *((int *) 0) = 0;
157 }
158 }
159
160 void abort()
0x4008e829 is in abort (/home/balzer/esp/esp-idf/components/esp32/panic.c:171).
166 * don't overwrite that.
167 */
168 if (esp_reset_reason_get_hint() == ESP_RST_UNKNOWN) {
169 esp_reset_reason_set_hint(ESP_RST_PANIC);
170 }
171 invoke_abort();
172 }
173
174
175 static const char *edesc[] = {
0x40090e7f is in xTaskPriorityDisinherit (/home/balzer/esp/esp-idf/components/freertos/tasks.c:4116).
4111 BaseType_t xReturn = pdFALSE;
4112 taskENTER_CRITICAL(&xTaskQueueMutex);
4113
4114 if( pxMutexHolder != NULL )
4115 {
4116 configASSERT( pxTCB->uxMutexesHeld );
4117 ( pxTCB->uxMutexesHeld )--;
4118
4119 if( pxTCB->uxPriority != pxTCB->uxBasePriority )
4120 {
0x400912f3 is in prvCopyDataToQueue (/home/balzer/esp/esp-idf/components/freertos/queue.c:1876).
1871 #if ( configUSE_MUTEXES == 1 )
1872 {
1873 if( pxQueue->uxQueueType == queueQUEUE_IS_MUTEX )
1874 {
1875 /* The mutex is no longer being held. */
1876 xReturn = xTaskPriorityDisinherit( ( void * ) pxQueue->pxMutexHolder );
1877 pxQueue->pxMutexHolder = NULL;
1878 }
1879 else
1880 {
0x400915e9 is in xQueueGenericSend (/home/balzer/esp/esp-idf/components/freertos/queue.c:743).
738 the head item in the queue is to be overwritten then it does
739 not matter if the queue is full. */
740 if( ( pxQueue->uxMessagesWaiting < pxQueue->uxLength ) || ( xCopyPosition == queueOVERWRITE ) )
741 {
742 traceQUEUE_SEND( pxQueue );
743 xYieldRequired = prvCopyDataToQueue( pxQueue, pvItemToQueue, xCopyPosition );
744
745 #if ( configUSE_QUEUE_SETS == 1 )
746 {
747 if( pxQueue->pxQueueSetContainer != NULL )
0x401faa62 is in wc_UnLockMutex (/home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/components/wolfssl/wolfcrypt/src/wc_port.c:983).
978 return 0;
979 }
980
981 int wc_UnLockMutex(wolfSSL_Mutex* m)
982 {
983 xSemaphoreGive( *m );
984 return 0;
985 }
986
987 #elif defined(RTTHREAD)
0x401f3f29 is in esp_CryptHwMutexUnLock (/home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/components/wolfssl/wolfcrypt/src/port/Espressif/esp32_util.c:43).
38 return ((xSemaphoreTake( *mutex, xBlockTime ) == pdTRUE) ? 0 : BAD_MUTEX_E);
39 #endif
40 }
41
42 int esp_CryptHwMutexUnLock(wolfSSL_Mutex* mutex) {
43 return wc_UnLockMutex(mutex);
44 }
45
46 #endif
47
0x401f3d6f is in esp_sha_hw_unlock (/home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/components/wolfssl/wolfcrypt/src/port/Espressif/esp32_sha.c:183).
178 periph_module_disable(PERIPH_SHA_MODULE);
179 #if defined(SINGLE_THREADED)
180 InUse = 0;
181 #else
182 /* unlock hw engine for next use */
183 esp_CryptHwMutexUnLock(&sha_mutex);
184 #endif
185 ESP_LOGV(TAG, "leave esp_sha_hw_unlock");
186 }
187 /*
0x401fa20d is in wc_InitSha512_ex (/home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/components/wolfssl/wolfcrypt/src/sha512.c:224).
219 sha512->ctx.sha_type = SHA2_512;
220 /* always start firstblock = 1 when using hw engine */
221 sha512->ctx.isfirstblock = 1;
222 if(sha512->ctx.mode == ESP32_SHA_HW) {
223 /* release hw */
224 esp_sha_hw_unlock();
225 }
226 /* always set mode as INIT
227 * whether using HW or SW is determined at first call of update()
228 */
0x401fa2f1 is in wc_InitSha512 (/home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/components/wolfssl/wolfcrypt/src/sha512.c:900).
895 return InitSha512(sha512); /* reset state */
896 }
897
898 int wc_InitSha512(wc_Sha512* sha512)
899 {
900 return wc_InitSha512_ex(sha512, NULL, INVALID_DEVID);
901 }
902
903 void wc_Sha512Free(wc_Sha512* sha512)
904 {
0x401eed2a is in wc_Sha512Hash (/home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/components/wolfssl/wolfcrypt/src/hash.c:1169).
1164 DYNAMIC_TYPE_TMP_BUFFER);
1165 if (sha512 == NULL)
1166 return MEMORY_E;
1167 #endif
1168
1169 if ((ret = wc_InitSha512(sha512)) != 0) {
1170 WOLFSSL_MSG("InitSha512 failed");
1171 }
1172 else {
1173 if ((ret = wc_Sha512Update(sha512, data, len)) != 0) {
0x401eedf9 is in wc_Hash (/home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/components/wolfssl/wolfcrypt/src/hash.c:497).
492 ret = wc_Sha384Hash(data, data_len, hash);
493 #endif
494 break;
495 case WC_HASH_TYPE_SHA512:
496 #ifdef WOLFSSL_SHA512
497 ret = wc_Sha512Hash(data, data_len, hash);
498 #endif
499 break;
500 case WC_HASH_TYPE_MD5_SHA:
501 #if !defined(NO_MD5) && !defined(NO_SHA)
0x401d8d35 is in DoServerKeyExchange (/home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/components/wolfssl/src/internal.c:22493).
22488 if (ssl->buffers.digest.buffer == NULL) {
22489 ERROR_OUT(MEMORY_E, exit_dske);
22490 }
22491
22492 /* Perform hash */
22493 ret = wc_Hash(hashType, ssl->buffers.sig.buffer,
22494 ssl->buffers.sig.length,
22495 ssl->buffers.digest.buffer,
22496 ssl->buffers.digest.length);
22497 if (ret != 0) {
0x401dc9d5 is in DoHandShakeMsgType (/home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/components/wolfssl/src/internal.c:12885).
12880 break;
12881 #endif
12882
12883 case server_key_exchange:
12884 WOLFSSL_MSG("processing server key exchange");
12885 ret = DoServerKeyExchange(ssl, input, inOutIdx, size);
12886 break;
12887
12888 #ifdef HAVE_SESSION_TICKET
12889 case session_ticket:
0x401ddc9c is in ProcessReply (/home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/components/wolfssl/src/internal.c:13112).
13107 ssl->arrays->pendingMsgOffset = inputLength;
13108 *inOutIdx += inputLength - HANDSHAKE_HEADER_SZ;
13109 return 0;
13110 }
13111
13112 ret = DoHandShakeMsgType(ssl, input, inOutIdx, type, size, totalSz);
13113 }
13114 else {
13115 word32 pendSz =
13116 ssl->arrays->pendingMsgSz - ssl->arrays->pendingMsgOffset;
0x401e0532 is in wolfSSL_connect (/home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/components/wolfssl/src/ssl.c:12506).
12501 while (ssl->options.serverState < neededState) {
12502 #ifdef WOLFSSL_TLS13
12503 if (ssl->options.tls1_3)
12504 return wolfSSL_connect_TLSv13(ssl);
12505 #endif
12506 if ( (ssl->error = ProcessReply(ssl)) < 0) {
12507 WOLFSSL_ERROR(ssl->error);
12508 return WOLFSSL_FATAL_ERROR;
12509 }
12510 /* if resumption failed, reset needed state */
0x401099d3 is in mg_ssl_if_handshake (/home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/components/mongoose/mongoose/mongoose.c:4534).
4529 int res;
4530 /* If descriptor is not yet set, do it now. */
4531 if (SSL_get_fd(ctx->ssl) < 0) {
4532 if (SSL_set_fd(ctx->ssl, nc->sock) != 1) return MG_SSL_ERROR;
4533 }
4534 res = server_side ? SSL_accept(ctx->ssl) : SSL_connect(ctx->ssl);
4535 if (res != 1) return mg_ssl_if_ssl_err(nc, res);
4536 return MG_SSL_OK;
4537 }
4538
0x4010b13d is in mg_ssl_begin (/home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/components/mongoose/mongoose/mongoose.c:3765).
3760 }
3761
3762 #if MG_ENABLE_SSL
3763 static void mg_ssl_begin(struct mg_connection *nc) {
3764 int server_side = (nc->listener != NULL);
3765 enum mg_ssl_if_result res = mg_ssl_if_handshake(nc);
3766 DBG(("%p %d res %d", nc, server_side, res));
3767
3768 if (res == MG_SSL_OK) {
3769 nc->flags |= MG_F_SSL_HANDSHAKE_DONE;
0x4010ca32 is in mg_mgr_handle_conn (/home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/components/mongoose/mongoose/mongoose.c:3820).
3815 */
3816 err = nc->err;
3817 #endif
3818 #if MG_ENABLE_SSL
3819 if ((nc->flags & MG_F_SSL) && err == 0) {
3820 mg_ssl_begin(nc);
3821 } else {
3822 mg_if_connect_cb(nc, err);
3823 }
3824 #else
0x4010cf86 is in mg_socket_if_poll (/home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/components/mongoose/mongoose/mongoose.c:4042).
4037 fd_flags |= _MG_F_FD_CAN_WRITE;
4038 }
4039 #endif
4040 }
4041 tmp = nc->next;
4042 mg_mgr_handle_conn(nc, fd_flags, now);
4043 }
4044
4045 for (nc = mgr->active_connections; nc != NULL; nc = tmp) {
4046 tmp = nc->next;
0x401091c2 is in mg_mgr_poll (/home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/components/mongoose/mongoose/mongoose.c:2538).
2533 LOG(LL_ERROR, ("cannot poll: no interfaces"));
2534 return 0;
2535 }
2536
2537 for (i = 0; i < m->num_ifaces; i++) {
2538 now = m->ifaces[i]->vtable->poll(m->ifaces[i], timeout_ms);
2539 }
2540 return now;
2541 }
2542
0x400f3427 is in OvmsNetManager::MongooseTask() (/home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/main/ovms_netmanager.cpp:751).
746
747 // Main event loop
748 while (m_mongoose_running)
749 {
750 // poll interfaces:
751 if (mg_mgr_poll(&m_mongoose_mgr, 250) == 0)
752 {
753 ESP_LOGD(TAG, "MongooseTask: no interfaces available => exit");
754 break;
755 }
0x400f34d5 is in MongooseRawTask(void*) (/home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/main/ovms_netmanager.cpp:733).
728 #ifdef CONFIG_OVMS_SC_GPL_MONGOOSE
729
730 static void MongooseRawTask(void *pvParameters)
731 {
732 OvmsNetManager* me = (OvmsNetManager*)pvParameters;
733 me->MongooseTask();
734 }
735
736 void OvmsNetManager::MongooseTask()
737 {
-------------- next part --------------
A non-text attachment was scrubbed...
Name: OpenPGP_signature
Type: application/pgp-signature
Size: 203 bytes
Desc: OpenPGP digital signature
URL: <http://lists.openvehicles.com/pipermail/ovmsdev/attachments/20210328/bfa37d94/attachment.sig>
More information about the OvmsDev
mailing list