Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add logs to debug Darwin CI failures #11005

Merged
merged 2 commits into from
Oct 28, 2021
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
32 changes: 32 additions & 0 deletions src/lib/support/logging/CHIPLogging.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -28,6 +28,7 @@
#include <lib/core/CHIPCore.h>
#include <lib/support/CodeUtils.h>
#include <lib/support/DLLUtil.h>
#include <lib/support/Span.h>

#include <stdarg.h>
#include <stdio.h>
Expand Down Expand Up @@ -142,6 +143,37 @@ DLL_EXPORT void Log(uint8_t module, uint8_t category, const char * msg, ...)
va_end(v);
}

DLL_EXPORT void LogByteSpan(uint8_t module, uint8_t category, const chip::ByteSpan & span)
{
// Maximum number of characters needed to print 8 byte buffer including formatting (0x)
// 8 bytes * (2 nibbles per byte + 4 character for ", 0x") + null termination.
// Rounding up to 50 bytes.
char output[50];
size_t offset = 0;
for (unsigned int i = 0; i < span.size(); i++)
{
if (i % 8 == 0 && offset != 0)
{
Log(module, category, "%s", output);
offset = 0;
}
int result = snprintf(&output[offset], sizeof(output) - offset, "0x%02x, ", (unsigned char) span.data()[i]);
if (result > 0)
{
offset += static_cast<size_t>(result);
}
else
{
Log(module, chip::Logging::kLogCategory_Error, "Failed to print ByteSpan buffer");
return;
}
}
if (offset != 0)
{
Log(module, category, "%s", output);
}
}

void LogV(uint8_t module, uint8_t category, const char * msg, va_list args)
{
if (!IsCategoryEnabled(category))
Expand Down
16 changes: 16 additions & 0 deletions src/lib/support/logging/CHIPLogging.h
Original file line number Diff line number Diff line change
Expand Up @@ -66,6 +66,11 @@
*/

namespace chip {

template <class T>
class Span;
using ByteSpan = Span<const uint8_t>;

namespace Logging {

using LogRedirectCallback_t = void (*)(const char * module, uint8_t category, const char * msg, va_list args);
Expand All @@ -88,6 +93,8 @@ void SetLogRedirectCallback(LogRedirectCallback_t callback);
void LogV(uint8_t module, uint8_t category, const char * msg, va_list args);
void Log(uint8_t module, uint8_t category, const char * msg, ...) ENFORCE_FORMAT(3, 4);

void LogByteSpan(uint8_t module, uint8_t category, const ByteSpan & span);

uint8_t GetLogFilter();
void SetLogFilter(uint8_t category);

Expand Down Expand Up @@ -158,6 +165,15 @@ void SetLogFilter(uint8_t category);
#define ChipLogDetail(MOD, MSG, ...) ((void) 0)
#endif

#if CHIP_DETAIL_LOGGING
#ifndef ChipLogByteSpan
#define ChipLogByteSpan(MOD, DATA) \
chip::Logging::LogByteSpan(chip::Logging::kLogModule_##MOD, chip::Logging::kLogCategory_Detail, DATA)
#endif
#else
#define ChipLogByteSpan(MOD, DATA) ((void) 0)
#endif

#if CHIP_ERROR_LOGGING || CHIP_PROGRESS_LOGGING || CHIP_DETAIL_LOGGING
#define _CHIP_USE_LOGGING 1
#else
Expand Down
17 changes: 17 additions & 0 deletions src/transport/FabricTable.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -187,7 +187,12 @@ CHIP_ERROR FabricInfo::GetCompressedId(FabricId fabricId, NodeId nodeId, PeerId
uint8_t compressedFabricIdBuf[sizeof(uint64_t)];
MutableByteSpan compressedFabricIdSpan(compressedFabricIdBuf);
P256PublicKey rootPubkey(GetRootPubkey());
ChipLogDetail(Inet, "Generating compressed fabric ID using uncompressed fabric ID 0x" ChipLogFormatX64 " and root pubkey",
ChipLogValueX64(fabricId));
ChipLogByteSpan(Inet, ByteSpan(rootPubkey.ConstBytes(), rootPubkey.Length()));
ReturnErrorOnFailure(GenerateCompressedFabricId(rootPubkey, fabricId, compressedFabricIdSpan));
ChipLogDetail(Inet, "Generated compressed fabric ID");
ChipLogByteSpan(Inet, compressedFabricIdSpan);

// Decode compressed fabric ID accounting for endianness, as GenerateCompressedFabricId()
// returns a binary buffer and is agnostic of usage of the output as an integer type.
Expand Down Expand Up @@ -325,12 +330,19 @@ CHIP_ERROR FabricInfo::GenerateDestinationID(const ByteSpan & ipk, const ByteSpa

Encoding::LittleEndian::BufferWriter bbuf(destinationMessage, sizeof(destinationMessage));

ChipLogDetail(Inet,
"Generating DestinationID. Fabric ID 0x" ChipLogFormatX64 ", Dest node ID 0x" ChipLogFormatX64 ", Random data",
ChipLogValueX64(mFabricId), ChipLogValueX64(destNodeId));
ChipLogByteSpan(Inet, random);

bbuf.Put(random.data(), random.size());
// TODO: In the current implementation this check is required because in some cases the
// GenerateDestinationID() is called before mRootCert is initialized and GetRootPubkey() returns
// empty Span.
if (!rootPubkeySpan.empty())
{
ChipLogDetail(Inet, "Root pubkey");
ChipLogByteSpan(Inet, rootPubkeySpan);
bbuf.Put(rootPubkeySpan.data(), rootPubkeySpan.size());
}
bbuf.Put64(mFabricId);
Expand All @@ -339,8 +351,13 @@ CHIP_ERROR FabricInfo::GenerateDestinationID(const ByteSpan & ipk, const ByteSpa
size_t written = 0;
VerifyOrReturnError(bbuf.Fit(written), CHIP_ERROR_BUFFER_TOO_SMALL);

ChipLogDetail(Inet, "IPK");
ChipLogByteSpan(Inet, ipk);

CHIP_ERROR err =
hmac.HMAC_SHA256(ipk.data(), ipk.size(), destinationMessage, written, destinationId.data(), destinationId.size());
ChipLogDetail(Inet, "Generated DestinationID output");
ChipLogByteSpan(Inet, destinationId);
return err;
}

Expand Down