Skip to content

Commit

Permalink
[logging] introduce LogWarnOnError() for standardized error logging (
Browse files Browse the repository at this point in the history
…#9996)

This commit adds `LogWarnOnError()` to emit warning-level logs on
errors. The emitted log includes the error code. This replaces custom
`LogError()` across modules, simplifying the code.
  • Loading branch information
abtink committed Apr 5, 2024
1 parent 65bc830 commit 223935b
Show file tree
Hide file tree
Showing 27 changed files with 95 additions and 158 deletions.
10 changes: 10 additions & 0 deletions src/core/common/log.cpp
Expand Up @@ -136,6 +136,16 @@ void Logger::LogVarArgs(const char *aModuleName, LogLevel aLogLevel, const char
return;
}

#if OT_SHOULD_LOG_AT(OT_LOG_LEVEL_WARN)
void Logger::LogOnError(const char *aModuleName, Error aError, const char *aText)
{
if (aError != kErrorNone)
{
LogAtLevel<kLogLevelWarn>(aModuleName, "Failed to %s: %s", aText, ErrorToString(aError));
}
}
#endif

#if OPENTHREAD_CONFIG_LOG_PKT_DUMP

template <LogLevel kLogLevel>
Expand Down
20 changes: 20 additions & 0 deletions src/core/common/log.hpp
Expand Up @@ -162,6 +162,22 @@ constexpr uint8_t kMaxLogModuleNameLength = 14; ///< Maximum module name length
#define LogDebg(...)
#endif

#if OT_SHOULD_LOG_AT(OT_LOG_LEVEL_WARN)
/**
* Emits an error log message at warning log level if there is an error.
*
* The emitted log will use the the following format "Failed to {aText}: {ErrorToString(aError)}", and will be emitted
* only if there is an error, i.e., @p aError is not `kErrorNone`.
*
* @param[in] aError The error to check and log.
* @param[in] aText The text to include in the log.
*
*/
#define LogWarnOnError(aError, aText) Logger::LogOnError(kLogModuleName, aError, aText)
#else
#define LogWarnOnError(aError, aText)
#endif

#if OT_SHOULD_LOG
/**
* Emits a log message at a given log level.
Expand Down Expand Up @@ -316,6 +332,10 @@ class Logger

static void LogVarArgs(const char *aModuleName, LogLevel aLogLevel, const char *aFormat, va_list aArgs);

#if OT_SHOULD_LOG_AT(OT_LOG_LEVEL_WARN)
static void LogOnError(const char *aModuleName, Error aError, const char *aText);
#endif

#if OPENTHREAD_CONFIG_LOG_PKT_DUMP
static constexpr uint8_t kStringLineLength = 80;
static constexpr uint8_t kDumpBytesPerLine = 16;
Expand Down
26 changes: 8 additions & 18 deletions src/core/meshcop/border_agent.cpp
Expand Up @@ -128,7 +128,7 @@ void BorderAgent::SendErrorMessage(const ForwardContext &aForwardContext, Error

exit:
FreeMessageOnError(message, error);
LogError("send error CoAP message", error);
LogWarnOnError(error, "send error CoAP message");
}

void BorderAgent::SendErrorMessage(const Coap::Message &aRequest, bool aSeparate, Error aError)
Expand Down Expand Up @@ -158,7 +158,7 @@ void BorderAgent::SendErrorMessage(const Coap::Message &aRequest, bool aSeparate

exit:
FreeMessageOnError(message, error);
LogError("send error CoAP message", error);
LogWarnOnError(error, "send error CoAP message");
}

Error BorderAgent::SendMessage(Coap::Message &aMessage)
Expand Down Expand Up @@ -347,7 +347,7 @@ template <> void BorderAgent::HandleTmf<kUriProxyTx>(Coap::Message &aMessage, co

exit:
FreeMessageOnError(message, error);
LogError("send proxy stream", error);
LogWarnOnError(error, "send proxy stream");
}

bool BorderAgent::HandleUdpReceive(void *aContext, const otMessage *aMessage, const otMessageInfo *aMessageInfo)
Expand Down Expand Up @@ -398,7 +398,7 @@ bool BorderAgent::HandleUdpReceive(const Message &aMessage, const Ip6::MessageIn
FreeMessageOnError(message, error);
if (error != kErrorDestinationAddressFiltered)
{
LogError("notify commissioner on ProxyRx (c/ur)", error);
LogWarnOnError(error, "notify commissioner on ProxyRx (c/ur)");
}

return error != kErrorDestinationAddressFiltered;
Expand Down Expand Up @@ -436,7 +436,7 @@ Error BorderAgent::ForwardToCommissioner(Coap::Message &aForwardMessage, const M
LogInfo("Sent to commissioner");

exit:
LogError("send to commissioner", error);
LogWarnOnError(error, "send to commissioner");
return error;
}

Expand Down Expand Up @@ -520,7 +520,7 @@ template <> void BorderAgent::HandleTmf<kUriRelayTx>(Coap::Message &aMessage, co

exit:
FreeMessageOnError(message, error);
LogError("send to joiner router request RelayTx (c/tx)", error);
LogWarnOnError(error, "send to joiner router request RelayTx (c/tx)");
}

Error BorderAgent::ForwardToLeader(const Coap::Message &aMessage, const Ip6::MessageInfo &aMessageInfo, Uri aUri)
Expand Down Expand Up @@ -576,7 +576,7 @@ Error BorderAgent::ForwardToLeader(const Coap::Message &aMessage, const Ip6::Mes
LogInfo("Forwarded request to leader on %s", PathForUri(aUri));

exit:
LogError("forward to leader", error);
LogWarnOnError(error, "forward to leader");

if (error != kErrorNone)
{
Expand Down Expand Up @@ -662,7 +662,7 @@ Error BorderAgent::Start(uint16_t aUdpPort, const uint8_t *aPsk, uint8_t aPskLen
LogInfo("Border Agent start listening on port %u", GetUdpPort());

exit:
LogError("start agent", error);
LogWarnOnError(error, "start agent");
return error;
}

Expand Down Expand Up @@ -802,16 +802,6 @@ void BorderAgent::HandleSecureAgentStopped(void)

#endif // OPENTHREAD_CONFIG_BORDER_AGENT_EPHEMERAL_KEY_ENABLE

#if OT_SHOULD_LOG_AT(OT_LOG_LEVEL_WARN)
void BorderAgent::LogError(const char *aActionText, Error aError)
{
if (aError != kErrorNone)
{
LogWarn("Failed to %s: %s", aActionText, ErrorToString(aError));
}
}
#endif

} // namespace MeshCoP
} // namespace ot

Expand Down
6 changes: 0 additions & 6 deletions src/core/meshcop/border_agent.hpp
Expand Up @@ -308,12 +308,6 @@ class BorderAgent : public InstanceLocator, private NonCopyable
static bool HandleUdpReceive(void *aContext, const otMessage *aMessage, const otMessageInfo *aMessageInfo);
bool HandleUdpReceive(const Message &aMessage, const Ip6::MessageInfo &aMessageInfo);

#if OT_SHOULD_LOG_AT(OT_LOG_LEVEL_WARN)
void LogError(const char *aActionText, Error aError);
#else
void LogError(const char *, Error) {}
#endif

using TimeoutTimer = TimerMilliIn<BorderAgent, &BorderAgent::HandleTimeout>;
#if OPENTHREAD_CONFIG_BORDER_AGENT_EPHEMERAL_KEY_ENABLE
using EphemeralKeyTimer = TimerMilliIn<BorderAgent, &BorderAgent::HandleEphemeralKeyTimeout>;
Expand Down
13 changes: 9 additions & 4 deletions src/core/meshcop/commissioner.cpp
Expand Up @@ -302,9 +302,9 @@ Error Commissioner::Start(StateCallback aStateCallback, JoinerCallback aJoinerCa
if ((error != kErrorNone) && (error != kErrorAlready))
{
Get<Tmf::SecureAgent>().Stop();
LogWarnOnError(error, "start commissioner");
}

LogError("start commissioner", error);
return error;
}

Expand Down Expand Up @@ -343,7 +343,11 @@ Error Commissioner::Stop(ResignMode aResignMode)
#endif

exit:
LogError("stop commissioner", error);
if (error != kErrorAlready)
{
LogWarnOnError(error, "stop commissioner");
}

return error;
}

Expand Down Expand Up @@ -405,7 +409,8 @@ void Commissioner::SendCommissionerSet(void)
error = SendMgmtCommissionerSetRequest(dataset, nullptr, 0);

exit:
LogError("send MGMT_COMMISSIONER_SET.req", error);
LogWarnOnError(error, "send MGMT_COMMISSIONER_SET.req");
OT_UNUSED_VARIABLE(error);
}

void Commissioner::ClearJoiners(void)
Expand Down Expand Up @@ -857,7 +862,7 @@ void Commissioner::SendKeepAlive(uint16_t aSessionId)

exit:
FreeMessageOnError(message, error);
LogError("send keep alive", error);
LogWarnOnError(error, "send keep alive");
}

void Commissioner::HandleLeaderKeepAliveResponse(void *aContext,
Expand Down
6 changes: 5 additions & 1 deletion src/core/meshcop/dataset_manager.cpp
Expand Up @@ -292,7 +292,11 @@ void DatasetManager::SendSet(void)
OT_FALL_THROUGH;

default:
LogError("send Dataset set to leader", error);
if (error != kErrorAlready)
{
LogWarnOnError(error, "send Dataset set to leader");
}

FreeMessage(message);
break;
}
Expand Down
6 changes: 3 additions & 3 deletions src/core/meshcop/joiner.cpp
Expand Up @@ -185,7 +185,7 @@ Error Joiner::Start(const char *aPskd,
FreeJoinerFinalizeMessage();
}

LogError("start joiner", error);
LogWarnOnError(error, "start joiner");
return error;
}

Expand Down Expand Up @@ -378,7 +378,7 @@ Error Joiner::Connect(JoinerRouter &aRouter)
SetState(kStateConnect);

exit:
LogError("start secure joiner connection", error);
LogWarnOnError(error, "start secure joiner connection");
return error;
}

Expand Down Expand Up @@ -543,7 +543,7 @@ template <> void Joiner::HandleTmf<kUriJoinerEntrust>(Coap::Message &aMessage, c
mTimer.Start(kConfigExtAddressDelay);

exit:
LogError("process joiner entrust", error);
LogWarnOnError(error, "process joiner entrust");
}

void Joiner::SendJoinerEntrustResponse(const Coap::Message &aRequest, const Ip6::MessageInfo &aRequestInfo)
Expand Down
2 changes: 1 addition & 1 deletion src/core/meshcop/joiner_router.cpp
Expand Up @@ -232,7 +232,7 @@ void JoinerRouter::DelaySendingJoinerEntrust(const Ip6::MessageInfo &aMessageInf

exit:
FreeMessageOnError(message, error);
LogError("schedule joiner entrust", error);
LogWarnOnError(error, "schedule joiner entrust");
}

void JoinerRouter::HandleTimer(void) { SendDelayedJoinerEntrust(); }
Expand Down
10 changes: 0 additions & 10 deletions src/core/meshcop/meshcop.cpp
Expand Up @@ -343,15 +343,5 @@ Error GeneratePskc(const char *aPassPhrase,
}
#endif // OPENTHREAD_FTD

#if OT_SHOULD_LOG_AT(OT_LOG_LEVEL_WARN)
void LogError(const char *aActionText, Error aError)
{
if (aError != kErrorNone && aError != kErrorAlready)
{
LogWarn("Failed to %s: %s", aActionText, ErrorToString(aError));
}
}
#endif

} // namespace MeshCoP
} // namespace ot
16 changes: 0 additions & 16 deletions src/core/meshcop/meshcop.hpp
Expand Up @@ -561,22 +561,6 @@ Error GeneratePskc(const char *aPassPhrase,
*/
void ComputeJoinerId(const Mac::ExtAddress &aEui64, Mac::ExtAddress &aJoinerId);

#if OT_SHOULD_LOG_AT(OT_LOG_LEVEL_WARN)
/**
* Emits a log message indicating an error during a MeshCoP action.
*
* Note that log message is emitted only if there is an error, i.e. @p aError is not `kErrorNone`. The log
* message will have the format "Failed to {aActionText} : {ErrorString}".
*
* @param[in] aActionText A string representing the failed action.
* @param[in] aError The error in sending the message.
*
*/
void LogError(const char *aActionText, Error aError);
#else
inline void LogError(const char *, Error) {}
#endif

} // namespace MeshCoP

DefineCoreType(otJoinerPskd, MeshCoP::JoinerPskd);
Expand Down
6 changes: 3 additions & 3 deletions src/core/meshcop/meshcop_leader.cpp
Expand Up @@ -125,7 +125,7 @@ void Leader::SendPetitionResponse(const Coap::Message &aRequest,

exit:
FreeMessageOnError(message, error);
LogError("send petition response", error);
LogWarnOnError(error, "send petition response");
}

template <> void Leader::HandleTmf<kUriLeaderKeepAlive>(Coap::Message &aMessage, const Ip6::MessageInfo &aMessageInfo)
Expand Down Expand Up @@ -192,7 +192,7 @@ void Leader::SendKeepAliveResponse(const Coap::Message &aRequest,

exit:
FreeMessageOnError(message, error);
LogError("send keep alive response", error);
LogWarnOnError(error, "send keep alive response");
}

void Leader::SendDatasetChanged(const Ip6::Address &aAddress)
Expand All @@ -211,7 +211,7 @@ void Leader::SendDatasetChanged(const Ip6::Address &aAddress)

exit:
FreeMessageOnError(message, error);
LogError("send dataset changed", error);
LogWarnOnError(error, "send dataset changed");
}

Error Leader::SetDelayTimerMinimal(uint32_t aDelayTimerMinimal)
Expand Down
12 changes: 1 addition & 11 deletions src/core/meshcop/tcat_agent.cpp
Expand Up @@ -94,7 +94,7 @@ Error TcatAgent::Start(const TcatAgent::VendorInfo &aVendorInfo,
mAlreadyCommissioned = false;

exit:
LogError("start TCAT agent", error);
LogWarnOnError(error, "start TCAT agent");
return error;
}

Expand Down Expand Up @@ -500,16 +500,6 @@ Error TcatAgent::HandleStartThreadInterface(void)
return error;
}

#if OT_SHOULD_LOG_AT(OT_LOG_LEVEL_WARN)
void TcatAgent::LogError(const char *aActionText, Error aError)
{
if (aError != kErrorNone)
{
LogWarn("Failed to %s: %s", aActionText, ErrorToString(aError));
}
}
#endif

} // namespace MeshCoP
} // namespace ot

Expand Down
6 changes: 0 additions & 6 deletions src/core/meshcop/tcat_agent.hpp
Expand Up @@ -325,12 +325,6 @@ class TcatAgent : public InstanceLocator, private NonCopyable
Error HandleSetActiveOperationalDataset(const Message &aIncommingMessage, uint16_t aOffset, uint16_t aLength);
Error HandleStartThreadInterface(void);

#if OT_SHOULD_LOG_AT(OT_LOG_LEVEL_WARN)
void LogError(const char *aActionText, Error aError);
#else
void LogError(const char *, Error) {}
#endif

bool CheckCommandClassAuthorizationFlags(CommandClassFlags aCommissionerCommandClassFlags,
CommandClassFlags aDeviceCommandClassFlags,
Dataset *aDataset) const;
Expand Down
2 changes: 1 addition & 1 deletion src/core/net/dhcp6_client.cpp
Expand Up @@ -288,7 +288,7 @@ void Client::Solicit(uint16_t aRloc16)
if (error != kErrorNone)
{
FreeMessage(message);
LogWarn("Failed to send DHCPv6 Solicit: %s", ErrorToString(error));
LogWarnOnError(error, "send DHCPv6 Solicit");
}
}

Expand Down
7 changes: 2 additions & 5 deletions src/core/net/dhcp6_server.cpp
Expand Up @@ -172,11 +172,8 @@ void Server::AddPrefixAgent(const Ip6::Prefix &aIp6Prefix, const Lowpan::Context
mPrefixAgentsCount++;

exit:

if (error != kErrorNone)
{
LogNote("Failed to add DHCPv6 prefix agent: %s", ErrorToString(error));
}
LogWarnOnError(error, "add DHCPv6 prefix agent");
OT_UNUSED_VARIABLE(error);
}

void Server::HandleUdpReceive(void *aContext, otMessage *aMessage, const otMessageInfo *aMessageInfo)
Expand Down
2 changes: 1 addition & 1 deletion src/core/net/dnssd_server.cpp
Expand Up @@ -170,7 +170,7 @@ void Server::ProcessQuery(Request &aRequest)
ExitNow();
}

LogWarn("Error forwarding to upstream: %s", ErrorToString(error));
LogWarnOnError(error, "forwarding to upstream");

rcode = Header::kResponseServerFailure;

Expand Down

0 comments on commit 223935b

Please sign in to comment.