diff --git a/src/platform/silabs/silabs_utils.cpp b/src/platform/silabs/silabs_utils.cpp new file mode 100644 index 0000000000..c8a068a328 --- /dev/null +++ b/src/platform/silabs/silabs_utils.cpp @@ -0,0 +1,38 @@ +/* + * + * Copyright (c) 2020 Project CHIP Authors + * Copyright (c) 2022 Silabs. + * All rights reserved. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#include "silabs_utils.h" +#include "SoftwareFaultReports.h" +#include + +void appError(int err) +{ + char faultMessage[30] = { 0 }; // App Critical Error: + 10 digit + null character + snprintf(faultMessage, sizeof faultMessage, "App Critical Error:%d", err); + SILABS_LOG("!!!!!!!!!!!! %s !!!!!!!!!!!", faultMessage); + chip::DeviceLayer::Silabs::OnSoftwareFaultEventHandler(faultMessage); + vTaskSuspendAll(); + /* Force an assert. */ + chipAbort(); +} + +void appError(CHIP_ERROR error) +{ + appError(static_cast(error.AsInteger())); +} diff --git a/src/platform/silabs/silabs_utils.h b/src/platform/silabs/silabs_utils.h new file mode 100644 index 0000000000..93941fbf9c --- /dev/null +++ b/src/platform/silabs/silabs_utils.h @@ -0,0 +1,43 @@ +/* + * + * Copyright (c) 2020 Project CHIP Authors + * Copyright (c) 2022 Silabs. + * All rights reserved. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#pragma once + +// EFR Logging +#ifdef __cplusplus +extern "C" { +#endif + +void silabsInitLog(void); + +void silabsLog(const char * aFormat, ...); +#define SILABS_LOG(...) silabsLog(__VA_ARGS__); +void appError(int err); + +#ifdef __cplusplus +} + +// Output logs to RTT by defaults +#ifndef SILABS_LOG_OUT_UART +#define SILABS_LOG_OUT_UART 0 +#endif + +#include +void appError(CHIP_ERROR error); +#endif diff --git a/src/platform/silabs/tracing/SilabsTracing.cpp b/src/platform/silabs/tracing/SilabsTracing.cpp index f7f262cd81..5a6f0e6976 100644 --- a/src/platform/silabs/tracing/SilabsTracing.cpp +++ b/src/platform/silabs/tracing/SilabsTracing.cpp @@ -34,65 +34,33 @@ namespace chip { namespace Tracing { namespace Silabs { -// String mapping for TimeTraceOperation -const char * TimeTraceOperationToString(TimeTraceOperation operation) -{ - switch (operation) - { - case TimeTraceOperation::kSpake2p: - return "Spake2p"; - case TimeTraceOperation::kPake1: - return "Pake1"; - case TimeTraceOperation::kPake2: - return "Pake2"; - case TimeTraceOperation::kPake3: - return "Pake3"; - case TimeTraceOperation::kOperationalCredentials: - return "OperationalCredentials"; - case TimeTraceOperation::kAttestationVerification: - return "AttestationVerification"; - case TimeTraceOperation::kCSR: - return "CSR"; - case TimeTraceOperation::kNOC: - return "NOC"; - case TimeTraceOperation::kTransportLayer: - return "TransportLayer"; - case TimeTraceOperation::kTransportSetup: - return "TransportSetup"; - case TimeTraceOperation::kFindOperational: - return "FindOperational"; - case TimeTraceOperation::kCaseSession: - return "CaseSession"; - case TimeTraceOperation::kSigma1: - return "Sigma1"; - case TimeTraceOperation::kSigma2: - return "Sigma2"; - case TimeTraceOperation::kSigma3: - return "Sigma3"; - case TimeTraceOperation::kOTA: - return "OTA"; - case TimeTraceOperation::kImageUpload: - return "ImageUpload"; - case TimeTraceOperation::kImageVerification: - return "ImageVerification"; - case TimeTraceOperation::kAppApplyTime: - return "AppApplyTime"; - case TimeTraceOperation::kBootup: - return "Bootup"; - case TimeTraceOperation::kSilabsInit: - return "SilabsInit"; - case TimeTraceOperation::kMatterInit: - return "MatterInit"; - case TimeTraceOperation::kNumTraces: - return "NumTraces"; - case TimeTraceOperation::kBufferFull: - return "BufferFull"; - default: - return "Unknown"; - } -} +const char * TimeTraceOperationString[] = { + [static_cast(TimeTraceOperation::kSpake2p)] = "Spake2p", + [static_cast(TimeTraceOperation::kPake1)] = "Pake1", + [static_cast(TimeTraceOperation::kPake2)] = "Pake2", + [static_cast(TimeTraceOperation::kPake3)] = "Pake3", + [static_cast(TimeTraceOperation::kOperationalCredentials)] = "OperationalCredentials", + [static_cast(TimeTraceOperation::kAttestationVerification)] = "AttestationVerification", + [static_cast(TimeTraceOperation::kCSR)] = "CSR", + [static_cast(TimeTraceOperation::kNOC)] = "NOC", + [static_cast(TimeTraceOperation::kTransportLayer)] = "TransportLayer", + [static_cast(TimeTraceOperation::kTransportSetup)] = "TransportSetup", + [static_cast(TimeTraceOperation::kFindOperational)] = "FindOperational", + [static_cast(TimeTraceOperation::kCaseSession)] = "CaseSession", + [static_cast(TimeTraceOperation::kSigma1)] = "Sigma1", + [static_cast(TimeTraceOperation::kSigma2)] = "Sigma2", + [static_cast(TimeTraceOperation::kSigma3)] = "Sigma3", + [static_cast(TimeTraceOperation::kOTA)] = "OTA", + [static_cast(TimeTraceOperation::kImageUpload)] = "ImageUpload", + [static_cast(TimeTraceOperation::kImageVerification)] = "ImageVerification", + [static_cast(TimeTraceOperation::kAppApplyTime)] = "AppApplyTime", + [static_cast(TimeTraceOperation::kBootup)] = "Bootup", + [static_cast(TimeTraceOperation::kSilabsInit)] = "SilabsInit", + [static_cast(TimeTraceOperation::kMatterInit)] = "MatterInit", + [static_cast(TimeTraceOperation::kBufferFull)] = "BufferFull", + [static_cast(TimeTraceOperation::kNumTraces)] = "NumTraces", +}; -// String mapping for OperationType const char * OperationTypeToString(OperationType type) { switch (type) @@ -116,26 +84,27 @@ struct TimeTrackerStorage : public TimeTracker, PersistentData(buffer.data()), buffer.size(), + "TimeTracker - StartTime: %" PRIu32 ", Operation: %s, Type: %s, Error: 0x%" PRIx32, mStartTime.count(), + TimeTraceOperationString[to_underlying(mOperation)], OperationTypeToString(mType), mError.AsInteger()); + case OperationType::kEnd: + return snprintf(reinterpret_cast(buffer.data()), buffer.size(), "TimeTracker - StartTime: %" PRIu32 ", EndTime: %" PRIu32 ", Duration: %" PRIu32 " ms, Operation: %s, Type: %s, Error: 0x%" PRIx32, mStartTime.count(), mEndTime.count(), (mEndTime - mStartTime).count(), - TimeTraceOperationToString(mOperation), OperationTypeToString(mType), mError.AsInteger()); + TimeTraceOperationString[to_underlying(mOperation)], OperationTypeToString(mType), mError.AsInteger()); + case OperationType::kInstant: + return snprintf(reinterpret_cast(buffer.data()), buffer.size(), + "TimeTracker - EventTime: %" PRIu32 ", Operation: %s, Type: %s, Error: 0x%" PRIx32, mStartTime.count(), + TimeTraceOperationString[to_underlying(mOperation)], OperationTypeToString(mType), mError.AsInteger()); + default: + return snprintf(reinterpret_cast(buffer.data()), buffer.size(), "TimeTracker - Unknown operation type"); } - - // Instant operation - return snprintf(buffer, bufferSize, "TimeTracker - EventTime: %" PRIu32 ", Operation: %s, Type: %s, Error: 0x%" PRIx32, - mStartTime.count(), TimeTraceOperationToString(mOperation), OperationTypeToString(mType), mError.AsInteger()); } SilabsTracer SilabsTracer::sInstance; @@ -240,9 +209,9 @@ CHIP_ERROR SilabsTracer::OutputTimeTracker(const TimeTracker & tracker) { VerifyOrReturnError(isLogInitialized(), CHIP_ERROR_UNINITIALIZED); // Allocate a buffer to store the trace - char buffer[256]; - auto bufferSize = sizeof(buffer); - tracker.ToCharArray(buffer, bufferSize); + uint8_t buffer[kMaxTraceSize]; + MutableByteSpan span(buffer); + tracker.ToCharArray(span); ChipLogProgress(DeviceLayer, "%s", buffer); // Use format string literal return CHIP_NO_ERROR; } @@ -287,7 +256,7 @@ CHIP_ERROR SilabsTracer::OutputWaterMark(TimeTraceOperation aOperation) ChipLogProgress(DeviceLayer, "Operation: %s, TotalCount=%" PRIu32 ", SuccessFullCount=%" PRIu32 ", MaxTime=%" PRIu32 ", MinTime=%" PRIu32 ", AvgTime=%" PRIu32 ", CountAboveAvg=%" PRIu32 "", - TimeTraceOperationToString(aOperation), watermark.mTotalCount, watermark.mSuccessfullCount, + TimeTraceOperationString[to_underlying(aOperation)], watermark.mTotalCount, watermark.mSuccessfullCount, watermark.mMaxTimeMs.count(), watermark.mMinTimeMs.count(), watermark.mMovingAverage.count(), watermark.mCountAboveAvg); @@ -369,7 +338,7 @@ CHIP_ERROR SilabsTracer::LoadWatermarks() return CHIP_NO_ERROR; } -CHIP_ERROR SilabsTracer::GetTraceByOperation(TimeTraceOperation aOperation, char * buffer, size_t & size) const +CHIP_ERROR SilabsTracer::GetTraceByOperation(TimeTraceOperation aOperation, MutableByteSpan & buffer) const { auto * current = mTimeTrackerList.head; while (current != nullptr) @@ -377,20 +346,19 @@ CHIP_ERROR SilabsTracer::GetTraceByOperation(TimeTraceOperation aOperation, char if (current->mValue.mOperation == aOperation) { // Check if the buffer is large enough - auto requiredSize = current->mValue.ToCharArray(nullptr, 0); + auto requiredSize = current->mValue.GetSize(); if (requiredSize < 0) { return CHIP_ERROR_INTERNAL; } - if (static_cast(requiredSize) >= size) + if (static_cast(requiredSize) >= buffer.size()) { - size = static_cast(requiredSize + 1); // Include null terminator return CHIP_ERROR_BUFFER_TOO_SMALL; } - current->mValue.ToCharArray(buffer, size); + current->mValue.ToCharArray(buffer); return CHIP_NO_ERROR; } current = current->mpNext; diff --git a/src/platform/silabs/tracing/SilabsTracing.h b/src/platform/silabs/tracing/SilabsTracing.h index 9d377d7a9f..5bfc912f8c 100644 --- a/src/platform/silabs/tracing/SilabsTracing.h +++ b/src/platform/silabs/tracing/SilabsTracing.h @@ -21,6 +21,7 @@ #include #include #include +#include #include #include @@ -82,11 +83,20 @@ struct TimeTracker /** @brief Convert the TimeTracker to a string for logs * Behaves like snprintf, but formats the output differently based on the OperationType - * May be used with nullptr and 0 to get the required buffer size + * May be used with a buffer of size == 0 to get the required buffer size * @param buffer The buffer to write the string to - * @param bufferSize The size of the buffer + * @return The number of characters written to the buffer, or the size of the buffer required if the buffer is too small */ - int ToCharArray(char * buffer, size_t bufferSize) const; + int ToCharArray(MutableByteSpan & buffer) const; + + /** @brief Get the size of the string representation of the TimeTracker + * @return The size of the string representation of the TimeTracker + */ + int GetSize() const + { + MutableByteSpan temp; + return ToCharArray(temp); + } }; struct Watermark @@ -107,6 +117,7 @@ class SilabsTracer public: static constexpr size_t kNumTraces = to_underlying(TimeTraceOperation::kNumTraces); static constexpr size_t kMaxBufferedTraces = 64; + static constexpr size_t kMaxTraceSize = 256; /** @brief Get the singleton instance of SilabsTracer */ static SilabsTracer & Instance() { return sInstance; } @@ -211,7 +222,7 @@ class SilabsTracer */ Watermark GetWatermark(TimeTraceOperation aOperation) { return mWatermarks[to_underlying(aOperation)]; } size_t GetTimeTracesCount() { return mBufferedTrackerCount; } - CHIP_ERROR GetTraceByOperation(TimeTraceOperation aOperation, char * buffer, size_t & size) const; + CHIP_ERROR GetTraceByOperation(TimeTraceOperation aOperation, MutableByteSpan & buffer) const; private: struct TimeTrackerList diff --git a/src/platform/tests/TestSilabsTracing.cpp b/src/platform/tests/TestSilabsTracing.cpp index 669fbdd41c..1634b93191 100644 --- a/src/platform/tests/TestSilabsTracing.cpp +++ b/src/platform/tests/TestSilabsTracing.cpp @@ -661,27 +661,26 @@ TEST_F(TestSilabsTracing, TestLogs) EXPECT_EQ(traceCount, 4u); // 4 calls: 2 TimeTraceBegin and 2 TimeTraceEnd // Verify the output logs using GetTraceByOperation - char logBuffer[256]; - auto bufferSize = sizeof(logBuffer); + uint8_t logBuffer[256]; + MutableByteSpan span(logBuffer); // Verify OTA log - EXPECT_EQ(SilabsTracer::Instance().GetTraceByOperation(TimeTraceOperation::kOTA, logBuffer, bufferSize), CHIP_NO_ERROR); + EXPECT_EQ(SilabsTracer::Instance().GetTraceByOperation(TimeTraceOperation::kOTA, span), CHIP_NO_ERROR); const char * expectedOTALogFormat = "TimeTracker - StartTime: 0, EndTime: 100, Duration: 100 ms, Operation: OTA, Type: End, Error: 0x0"; - EXPECT_STREQ(logBuffer, expectedOTALogFormat); + EXPECT_STREQ(reinterpret_cast(span.data()), expectedOTALogFormat); // Verify Bootup log - EXPECT_EQ(SilabsTracer::Instance().GetTraceByOperation(TimeTraceOperation::kBootup, logBuffer, bufferSize), CHIP_NO_ERROR); + span = MutableByteSpan(logBuffer); + EXPECT_EQ(SilabsTracer::Instance().GetTraceByOperation(TimeTraceOperation::kBootup, span), CHIP_NO_ERROR); const char * expectedBootupLogFormat = "TimeTracker - StartTime: 100, EndTime: 300, Duration: 200 ms, Operation: Bootup, Type: End, Error: 0x0"; - EXPECT_STREQ(logBuffer, expectedBootupLogFormat); + EXPECT_STREQ(reinterpret_cast(span.data()), expectedBootupLogFormat); // Test buffer too small behavior - char smallBuffer[10]; - bufferSize = sizeof(smallBuffer); - EXPECT_EQ(SilabsTracer::Instance().GetTraceByOperation(TimeTraceOperation::kOTA, smallBuffer, bufferSize), - CHIP_ERROR_BUFFER_TOO_SMALL); - EXPECT_GT(bufferSize, sizeof(smallBuffer)); // Ensure the required size is greater than the small buffer + uint8_t smallBuffer[10]; + MutableByteSpan smallSpan(smallBuffer); + EXPECT_EQ(SilabsTracer::Instance().GetTraceByOperation(TimeTraceOperation::kOTA, smallSpan), CHIP_ERROR_BUFFER_TOO_SMALL); // Test TraceBufferFlushByOperation EXPECT_EQ(SilabsTracer::Instance().TraceBufferFlushByOperation(TimeTraceOperation::kOTA), CHIP_NO_ERROR); @@ -689,13 +688,13 @@ TEST_F(TestSilabsTracing, TestLogs) EXPECT_EQ(traceCount, 2u); // Only Bootup traces should remain // Verify Bootup log still exists - bufferSize = sizeof(logBuffer); - EXPECT_EQ(SilabsTracer::Instance().GetTraceByOperation(TimeTraceOperation::kBootup, logBuffer, bufferSize), CHIP_NO_ERROR); - EXPECT_STREQ(logBuffer, expectedBootupLogFormat); + span = MutableByteSpan(logBuffer); + EXPECT_EQ(SilabsTracer::Instance().GetTraceByOperation(TimeTraceOperation::kBootup, span), CHIP_NO_ERROR); + EXPECT_STREQ(reinterpret_cast(span.data()), expectedBootupLogFormat); // Verify OTA log is removed - bufferSize = sizeof(logBuffer); - EXPECT_EQ(SilabsTracer::Instance().GetTraceByOperation(TimeTraceOperation::kOTA, logBuffer, bufferSize), CHIP_ERROR_NOT_FOUND); + span = MutableByteSpan(logBuffer); + EXPECT_EQ(SilabsTracer::Instance().GetTraceByOperation(TimeTraceOperation::kOTA, span), CHIP_ERROR_NOT_FOUND); // Test TraceBufferFlushAll EXPECT_EQ(SilabsTracer::Instance().TraceBufferFlushAll(), CHIP_NO_ERROR); @@ -703,10 +702,10 @@ TEST_F(TestSilabsTracing, TestLogs) EXPECT_EQ(traceCount, 0u); // All traces should be flushed // Verify no logs exist - bufferSize = sizeof(logBuffer); - EXPECT_EQ(SilabsTracer::Instance().GetTraceByOperation(TimeTraceOperation::kBootup, logBuffer, bufferSize), - CHIP_ERROR_NOT_FOUND); - EXPECT_EQ(SilabsTracer::Instance().GetTraceByOperation(TimeTraceOperation::kOTA, logBuffer, bufferSize), CHIP_ERROR_NOT_FOUND); + span = MutableByteSpan(logBuffer); + EXPECT_EQ(SilabsTracer::Instance().GetTraceByOperation(TimeTraceOperation::kBootup, span), CHIP_ERROR_NOT_FOUND); + span = MutableByteSpan(logBuffer); + EXPECT_EQ(SilabsTracer::Instance().GetTraceByOperation(TimeTraceOperation::kOTA, span), CHIP_ERROR_NOT_FOUND); } TEST_F(TestSilabsTracing, TestBufferBusting) @@ -731,15 +730,14 @@ TEST_F(TestSilabsTracing, TestBufferBusting) // Verify an overflow operation is added (kBufferFull) EXPECT_EQ(SilabsTracer::kMaxBufferedTraces, SilabsTracer::Instance().GetTimeTracesCount()); - char logBuffer[256]; - auto bufferSize = sizeof(logBuffer); - EXPECT_EQ(SilabsTracer::Instance().GetTraceByOperation(TimeTraceOperation::kBufferFull, logBuffer, bufferSize), CHIP_NO_ERROR); + uint8_t logBuffer[256]; + MutableByteSpan logSpan(logBuffer); + EXPECT_EQ(SilabsTracer::Instance().GetTraceByOperation(TimeTraceOperation::kBufferFull, logSpan), CHIP_NO_ERROR); const char * expectedNumLogFormat = "TimeTracker - EventTime: 6200, Operation: BufferFull, Type: Instant, Error: 0x19"; - EXPECT_STREQ(logBuffer, expectedNumLogFormat); + EXPECT_STREQ(reinterpret_cast(logSpan.data()), expectedNumLogFormat); // Verify the kImageUpload operation was not added - EXPECT_EQ(SilabsTracer::Instance().GetTraceByOperation(TimeTraceOperation::kImageUpload, logBuffer, bufferSize), - CHIP_ERROR_NOT_FOUND); + EXPECT_EQ(SilabsTracer::Instance().GetTraceByOperation(TimeTraceOperation::kImageUpload, logSpan), CHIP_ERROR_NOT_FOUND); // Flush kOTA operation EXPECT_EQ(SilabsTracer::Instance().TraceBufferFlushByOperation(TimeTraceOperation::kOTA), CHIP_NO_ERROR); @@ -747,8 +745,7 @@ TEST_F(TestSilabsTracing, TestBufferBusting) // Verify that adding a new operation still results in a buffer full operation since we are at size -1 EXPECT_EQ(CHIP_ERROR_BUFFER_TOO_SMALL, SilabsTracer::Instance().TimeTraceBegin(TimeTraceOperation::kImageUpload)); - EXPECT_EQ(SilabsTracer::Instance().GetTraceByOperation(TimeTraceOperation::kImageUpload, logBuffer, bufferSize), - CHIP_ERROR_NOT_FOUND); + EXPECT_EQ(SilabsTracer::Instance().GetTraceByOperation(TimeTraceOperation::kImageUpload, logSpan), CHIP_ERROR_NOT_FOUND); // Flush the overflow operations EXPECT_EQ(SilabsTracer::Instance().TraceBufferFlushByOperation(TimeTraceOperation::kBufferFull), CHIP_NO_ERROR); @@ -756,12 +753,10 @@ TEST_F(TestSilabsTracing, TestBufferBusting) // Verify that adding a new operation now succeeds EXPECT_EQ(CHIP_NO_ERROR, SilabsTracer::Instance().TimeTraceBegin(TimeTraceOperation::kImageUpload)); - bufferSize = sizeof(logBuffer); - EXPECT_EQ(SilabsTracer::Instance().GetTraceByOperation(TimeTraceOperation::kImageUpload, logBuffer, bufferSize), CHIP_NO_ERROR); + EXPECT_EQ(SilabsTracer::Instance().GetTraceByOperation(TimeTraceOperation::kImageUpload, logSpan), CHIP_NO_ERROR); // Verify that the buffer full operation is removed - EXPECT_EQ(SilabsTracer::Instance().GetTraceByOperation(TimeTraceOperation::kBufferFull, logBuffer, bufferSize), - CHIP_ERROR_NOT_FOUND); + EXPECT_EQ(SilabsTracer::Instance().GetTraceByOperation(TimeTraceOperation::kBufferFull, logSpan), CHIP_ERROR_NOT_FOUND); // Flush all operations EXPECT_EQ(SilabsTracer::Instance().TraceBufferFlushAll(), CHIP_NO_ERROR);