From 22fa17a6164f108f4a2e9441ac8490ab2fcb1733 Mon Sep 17 00:00:00 2001 From: breichel Date: Thu, 4 Mar 2021 16:58:59 +0100 Subject: [PATCH] [EGD-5919] Fix logs from Service: Cellular, Fota Remove misleading error message(change to debug/info). Do not trace as error multiple retry. Minimize (to zero) error logs on cold and hot start of the phone. --- module-cellular/Modem/ATCommon.cpp | 13 +- module-cellular/Modem/TS0710/TS0710.cpp | 162 +- module-cellular/Modem/TS0710/TS0710.h | 18 +- module-cellular/at/Commands.hpp | 2 +- .../service-antenna/ServiceAntenna.cpp | 2 +- .../service-cellular/PacketData.cpp | 6 +- .../service-cellular/ServiceCellular.cpp | 4966 +++++++++-------- module-services/service-fota/ServiceFota.cpp | 6 +- 8 files changed, 2636 insertions(+), 2539 deletions(-) diff --git a/module-cellular/Modem/ATCommon.cpp b/module-cellular/Modem/ATCommon.cpp index 41bd2a648d740c703d449cae385e7472a898fbdd..04d5b31e9e1ad351a53b4b32cf07e96b2f6123a9 100644 --- a/module-cellular/Modem/ATCommon.cpp +++ b/module-cellular/Modem/ATCommon.cpp @@ -31,17 +31,16 @@ void Channel::cmd_log(std::string cmd, const Result &result, uint32_t timeout) cmd.erase(std::remove(cmd.begin(), cmd.end(), '\n'), cmd.end()); switch (result.code) { case Result::Code::TIMEOUT: { - LOG_ERROR("[AT]: >%s<, timeout %" PRIu32 - " - please check the value with Quectel_EC25&EC21_AT_Commands_Manual_V1.3.pdf", - cmd.c_str(), - timeout); + LOG_INFO("[AT]: >%s<, timeout %" PRIu32 + " - please check the value with Quectel_EC25&EC21_AT_Commands_Manual_V1.3.pdf", + cmd.c_str(), + timeout); } break; case Result::Code::ERROR: { - - LOG_ERROR("[AT]: >%s<, >%s<", cmd.c_str(), result.response.size() ? result.response.back().c_str() : ""); + LOG_INFO("[AT]: >%s<, >%s<", cmd.c_str(), result.response.size() ? result.response.back().c_str() : ""); } break; default: - LOG_DEBUG("[AT]: >%s<, >%s<", cmd.c_str(), result.response.size() ? result.response.back().c_str() : ""); + LOG_INFO("[AT]: >%s<, >%s<", cmd.c_str(), result.response.size() ? result.response.back().c_str() : ""); break; } #if DEBUG_MODEM_OUTPUT_RESPONSE diff --git a/module-cellular/Modem/TS0710/TS0710.cpp b/module-cellular/Modem/TS0710/TS0710.cpp index 2c999b8e8784066a4318b4a57925606db876f1bf..0e43fcab345b75de039ade3386c66219e9004a6d 100644 --- a/module-cellular/Modem/TS0710/TS0710.cpp +++ b/module-cellular/Modem/TS0710/TS0710.cpp @@ -1,4 +1,4 @@ -// Copyright (c) 2017-2021, Mudita Sp. z.o.o. All rights reserved. +// Copyright (c) 2017-2021, Mudita Sp. z.o.o. All rights reserved. // For licensing, see https://github.com/mudita/MuditaOS/LICENSE.md #include "TS0710.h" @@ -176,7 +176,7 @@ TS0710::ConfState TS0710::BaudDetectOnce() break; case BaudTestStep::baud_NotFound: pv_cellular->SetSpeed(ATPortSpeeds_text[PortSpeed_e::PS115200]); // set port speed to default 115200 - LOG_ERROR("No Baud found for modem."); + LOG_DEBUG("No Baud found for modem."); return ConfState::Failure; break; } @@ -199,7 +199,7 @@ TS0710::ConfState TS0710::BaudDetectProcedure(uint16_t timeout_s) } } pv_cellular->SetSpeed(ATPortSpeeds_text[PortSpeed_e::PS115200]); // set port speed to default 115200 - LOG_DEBUG("No Baud found."); + LOG_ERROR("No Baud found."); return ConfState::Failure; } @@ -223,6 +223,10 @@ TS0710::ConfState TS0710::ConfProcedure() LOG_INFO("%s", ret.response[i].c_str()); } } + else { + LOG_ERROR("Could not get modem firmware information"); + return ConfState::Failure; + } at::AT flowCmd; if (hardwareControlFlowEnable) { @@ -243,7 +247,6 @@ TS0710::ConfState TS0710::ConfProcedure() } } - LOG_WARN("TODO: determine while this retry loop is necessary"); bool timed_out = false; constexpr uint32_t qsclkTmeout = 30; const auto qsclkTmeoutTicks = @@ -252,7 +255,6 @@ TS0710::ConfState TS0710::ConfProcedure() if (parser->cmd(at::AT::QSCLK_ON)) { break; } - // if error then limit polling - 1 poll per sec modem normaly takes ~ 20 sec to start anyway vTaskDelay(pdMS_TO_TICKS(utils::time::milisecondsInSecond)); timed_out = cpp_freertos::Ticks::GetTicks() > qsclkTmeoutTicks; if (timed_out) { @@ -270,18 +272,23 @@ TS0710::ConfState TS0710::AudioConfProcedure() // Hence we are checking here for beginning of valid response for at::QDAI command. AudioConfProcedure // procedure will be invoked from AudioService's context as many times as needed. if (!ret) { - return ConfState ::Failure; + return ConfState::Failure; } else if (ret.response[0].compare("+QDAI: 1,0,0,3,0,1,1,1") == 0) { - parser->cmd(at::AT::QRXGAIN); - parser->cmd(at::AT::CLVL); - parser->cmd(at::AT::QMIC); - SetupEchoCalceller(EchoCancellerStrength::Tuned); - return ConfState ::Success; + if (!parser->cmd(at::AT::QRXGAIN)) { + return ConfState::Failure; + } + if (!parser->cmd(at::AT::CLVL)) { + return ConfState::Failure; + } + if (!parser->cmd(at::AT::QMIC)) { + return ConfState::Failure; + } + return SetupEchoCanceller(EchoCancellerStrength::Tuned); } else { if (!parser->cmd(at::AT::QDAI_INIT)) { - return ConfState ::Failure; + return ConfState::Failure; } else { pv_cellular->Restart(); @@ -396,10 +403,13 @@ TS0710::ConfState TS0710::StartMultiplexer() c->cmd(at::AT::SET_URC_CHANNEL); LOG_DEBUG("Sending test ATI"); auto res = c->cmd(at::AT::SW_INFO); - res = c->cmd(at::AT::CSQ); + if (!res) { + LOG_ERROR("Sending test ATI command failed"); + } + res = c->cmd(at::AT::CSQ); if (res) { - auto beg = res.response[0].find(" "); - auto end = res.response[0].find(",", 1); + auto beg = res.response[0].find(" "); + auto end = res.response[0].find(",", 1); auto input_val = res.response[0].substr(beg + 1, end - beg - 1); auto strength = 0; try { @@ -566,39 +576,82 @@ void TS0710::RegisterCellularDevice(void) auto deviceRegistrationMsg = std::make_shared(pv_cellular->GetCellularDevice()); pv_parent->bus.sendUnicast(std::move(deviceRegistrationMsg), service::name::system_manager); } - -void TS0710::SetupEchoCalceller(EchoCancellerStrength strength) +TS0710::ConfState TS0710::SetupEchoCanceller(EchoCancellerStrength strength) { + switch (strength) { case EchoCancellerStrength::LeastAggressive: // Aggressive settings - parser->cmd(at::factory(at::AT::QEEC) + "0,2048"); - parser->cmd(at::factory(at::AT::QEEC) + "5,14"); - parser->cmd(at::factory(at::AT::QEEC) + "10,140"); - parser->cmd(at::factory(at::AT::QEEC) + "21,16000"); - parser->cmd(at::factory(at::AT::QEEC) + "22,300"); - parser->cmd(at::factory(at::AT::QEEC) + "24,450"); - parser->cmd(at::factory(at::AT::QEEC) + "33,640"); + if (!parser->cmd(at::factory(at::AT::QEEC) + "0,2048")) { + return ConfState::Failure; + } + if (!parser->cmd(at::factory(at::AT::QEEC) + "5,14")) { + return ConfState::Failure; + } + if (!parser->cmd(at::factory(at::AT::QEEC) + "10,140")) { + return ConfState::Failure; + } + if (!parser->cmd(at::factory(at::AT::QEEC) + "21,16000")) { + return ConfState::Failure; + } + if (!parser->cmd(at::factory(at::AT::QEEC) + "22,300")) { + return ConfState::Failure; + } + if (!parser->cmd(at::factory(at::AT::QEEC) + "24,450")) { + return ConfState::Failure; + } + if (!parser->cmd(at::factory(at::AT::QEEC) + "33,640")) { + return ConfState::Failure; + } + break; case EchoCancellerStrength::Medium: // Aggressive settings - parser->cmd(at::factory(at::AT::QEEC) + "0,2048"); - parser->cmd(at::factory(at::AT::QEEC) + "5,14"); - parser->cmd(at::factory(at::AT::QEEC) + "10,160"); - parser->cmd(at::factory(at::AT::QEEC) + "21,19000"); - parser->cmd(at::factory(at::AT::QEEC) + "22,600"); - parser->cmd(at::factory(at::AT::QEEC) + "24,600"); - parser->cmd(at::factory(at::AT::QEEC) + "33,768"); + if (!parser->cmd(at::factory(at::AT::QEEC) + "0,2048")) { + return ConfState::Failure; + } + if (!parser->cmd(at::factory(at::AT::QEEC) + "5,14")) { + return ConfState::Failure; + } + if (!parser->cmd(at::factory(at::AT::QEEC) + "10,160")) { + return ConfState::Failure; + } + if (!parser->cmd(at::factory(at::AT::QEEC) + "21,19000")) { + return ConfState::Failure; + } + if (!parser->cmd(at::factory(at::AT::QEEC) + "22,600")) { + return ConfState::Failure; + } + if (!parser->cmd(at::factory(at::AT::QEEC) + "24,600")) { + return ConfState::Failure; + } + if (!parser->cmd(at::factory(at::AT::QEEC) + "33,768")) { + return ConfState::Failure; + } break; case EchoCancellerStrength::Aggressive: // Aggressive settings - parser->cmd(at::factory(at::AT::QEEC) + "0,2048"); - parser->cmd(at::factory(at::AT::QEEC) + "5,14"); - parser->cmd(at::factory(at::AT::QEEC) + "10,160"); - parser->cmd(at::factory(at::AT::QEEC) + "21,25000"); - parser->cmd(at::factory(at::AT::QEEC) + "22,12000"); - parser->cmd(at::factory(at::AT::QEEC) + "24,768"); - parser->cmd(at::factory(at::AT::QEEC) + "33,896"); + if (!parser->cmd(at::factory(at::AT::QEEC) + "0,2048")) { + return ConfState::Failure; + } + if (!parser->cmd(at::factory(at::AT::QEEC) + "5,14")) { + return ConfState::Failure; + } + if (!parser->cmd(at::factory(at::AT::QEEC) + "10,160")) { + return ConfState::Failure; + } + if (!parser->cmd(at::factory(at::AT::QEEC) + "21,25000")) { + return ConfState::Failure; + } + if (!parser->cmd(at::factory(at::AT::QEEC) + "22,12000")) { + return ConfState::Failure; + } + if (!parser->cmd(at::factory(at::AT::QEEC) + "24,768")) { + return ConfState::Failure; + } + if (!parser->cmd(at::factory(at::AT::QEEC) + "33,896")) { + return ConfState::Failure; + } break; case EchoCancellerStrength::Tuned: /* @@ -619,12 +672,31 @@ void TS0710::SetupEchoCalceller(EchoCancellerStrength strength) g) Increase the DENS_tail_portion in steps of 500, until 30000, and check the echo performance at each value. h) Set the parameter to the value that yielded the best echo performance. */ - parser->cmd(at::factory(at::AT::QEEC) + "0,2048"); - parser->cmd(at::factory(at::AT::QEEC) + "5,40"); // best performance on experiments in step 1 - parser->cmd(at::factory(at::AT::QEEC) + "10,160"); - parser->cmd(at::factory(at::AT::QEEC) + "21,26600"); // best performance on experiments in step 2c - parser->cmd(at::factory(at::AT::QEEC) + "22,20000"); // best performance on experiments in step 2g - parser->cmd(at::factory(at::AT::QEEC) + "24,768"); - parser->cmd(at::factory(at::AT::QEEC) + "33,896"); + if (!parser->cmd(at::factory(at::AT::QEEC) + "0,2048")) { + return ConfState::Failure; + } + // best performance on experiments in step 1 + if (!parser->cmd(at::factory(at::AT::QEEC) + "5,40")) { + return ConfState::Failure; + } + if (!parser->cmd(at::factory(at::AT::QEEC) + "10,160")) { + return ConfState::Failure; + } + // best performance on experiments in step 2c + if (!parser->cmd(at::factory(at::AT::QEEC) + "21,26600")) { + return ConfState::Failure; + } + // best performance on experiments in step 2g + if (!parser->cmd(at::factory(at::AT::QEEC) + "22,20000")) { + return ConfState::Failure; + } + if (!parser->cmd(at::factory(at::AT::QEEC) + "24,768")) { + return ConfState::Failure; + } + if (!parser->cmd(at::factory(at::AT::QEEC) + "33,896")) { + return ConfState::Failure; + } }; + + return ConfState::Success; } diff --git a/module-cellular/Modem/TS0710/TS0710.h b/module-cellular/Modem/TS0710/TS0710.h index 317add199a63f1ff72b3257cd1be5aba1fef3fe6..d17c385d4809c44564c07ffd4f4dbd8faf10aeba 100644 --- a/module-cellular/Modem/TS0710/TS0710.h +++ b/module-cellular/Modem/TS0710/TS0710.h @@ -255,6 +255,14 @@ class TS0710 }; void setMode(Mode mode); + enum class ConfState + { + Success, + Failure, + ModemNeedsReset, + PowerUp + }; + private: Mode mode = Mode::AT; std::vector channels; @@ -291,17 +299,9 @@ class TS0710 Aggressive, Tuned }; - void SetupEchoCalceller(EchoCancellerStrength strength); + TS0710::ConfState SetupEchoCanceller(EchoCancellerStrength strength); public: - enum class ConfState - { - Success, - Failure, - ModemNeedsReset, - PowerUp - }; - /// @brief get Channel by index /// @param channel enum Channel /// @return pointer to channel or nullptr if such channel doesn't exist (nullptr return should never happen how - diff --git a/module-cellular/at/Commands.hpp b/module-cellular/at/Commands.hpp index 17057253ba92d76eb206124f67538ed311f752e9..454e3e1f37930aa5b3a349c34e49a667f0d3737e 100644 --- a/module-cellular/at/Commands.hpp +++ b/module-cellular/at/Commands.hpp @@ -240,7 +240,7 @@ namespace at {AT::QRXGAIN, {"AT+QRXGAIN=40000", default_timeout}}, {AT::CLVL, {"AT+CLVL=3", default_timeout}}, {AT::QMIC, {"AT+QMIC=15000,15000", default_timeout}}, - {AT::QEEC, {"AT+QEEC=", default_timeout}}, + {AT::QEEC, {"AT+QEEC=", 3000ms}}, {AT::QNVFR, {"AT+QNVFR=", default_long_doc_timeout}}, {AT::QNVFW, {"AT+QNVFW=", default_long_doc_timeout}}, {AT::QMBNCFG, {"AT+QMBNCFG=", default_long_doc_timeout}}, diff --git a/module-services/service-antenna/ServiceAntenna.cpp b/module-services/service-antenna/ServiceAntenna.cpp index 2085dbe9330cfcc0240a8919a3ab7d7312020ffa..b503aa867233aca43480972cde3ab1c2da941d77 100644 --- a/module-services/service-antenna/ServiceAntenna.cpp +++ b/module-services/service-antenna/ServiceAntenna.cpp @@ -138,7 +138,7 @@ sys::MessagePointer ServiceAntenna::DataReceivedHandler(sys::DataMessage *msgl, } } break; case MessageType::AntennaCSQChange: - LOG_WARN("CSQChange message"); + LOG_DEBUG("CSQChange message"); if (state->get() == antenna::State::idle) { state->set(antenna::State::csqChange); } diff --git a/module-services/service-cellular/PacketData.cpp b/module-services/service-cellular/PacketData.cpp index cd2fc8fdd0d34ac004bb9fdb4acca6c9696df545..1688e75ad434f8af0f723dca53ce6e63d92f3ed1 100644 --- a/module-services/service-cellular/PacketData.cpp +++ b/module-services/service-cellular/PacketData.cpp @@ -216,7 +216,7 @@ namespace packet_data PDPContext pdpCtx(cellularService); std::shared_ptr apnConfig; std::shared_ptr modemApn; - if (!((modemApn = pdpCtx.getConfiguration(ctxId)) && (modemApn != nullptr))) { + if (!(modemApn = pdpCtx.getConfiguration(ctxId))) { return at::Result::Code::ERROR; } auto phoneApn = contextMap.find(ctxId); @@ -260,7 +260,9 @@ namespace packet_data void PacketData::setupAPNSettings() { for (std::uint8_t ctxId = MINContextId; ctxId <= MAXContextId; ctxId++) { - updateAPNSettings(ctxId); + if (updateAPNSettings(ctxId) != at::Result::Code::OK) { + LOG_ERROR("Failed update APN settings for context %d", ctxId); + } } } diff --git a/module-services/service-cellular/ServiceCellular.cpp b/module-services/service-cellular/ServiceCellular.cpp index e3f8a18223d1b0ff7b5a0f581d7cf6a4847fe782..fc8f75b7601b7b4b242331fac86be24affc1d0d3 100644 --- a/module-services/service-cellular/ServiceCellular.cpp +++ b/module-services/service-cellular/ServiceCellular.cpp @@ -1,2472 +1,2494 @@ -// Copyright (c) 2017-2021, Mudita Sp. z.o.o. All rights reserved. -// For licensing, see https://github.com/mudita/MuditaOS/LICENSE.md - -#include "endpoints/developerMode/event/ATRequest.hpp" -#include "handler/RawATHandler.hpp" -#include "CellularUrcHandler.hpp" -#include "service-cellular/CellularCall.hpp" -#include "service-cellular/CellularMessage.hpp" -#include "service-cellular/CellularServiceAPI.hpp" -#include "service-cellular/ServiceCellular.hpp" -#include "service-cellular/SignalStrength.hpp" -#include "service-cellular/State.hpp" -#include "service-cellular/USSD.hpp" -#include "service-cellular/MessageConstants.hpp" - -#include "SimCard.hpp" -#include "NetworkSettings.hpp" -#include "service-cellular/RequestFactory.hpp" -#include "service-cellular/CellularRequestHandler.hpp" -#include "SystemManager/messages/SentinelRegistrationMessage.hpp" - -#include