Skip to content

Commit

Permalink
Add access control logging (#14540)
Browse files Browse the repository at this point in the history 
Add a log statement in AccessControl::Check so we can see what
params are being used to do the check.

This looks like:
AccessControl: checking f=1 a=c s=0x0000000000BC5C01 t= c=0x0000_0030 e=0 p=o
AccessControl: checking f=1 a=c s=0x0000000000BC5C01 t=0xAAAA0001,0xBBBB0002 c=0x0000_0030 e=0 p=o

Where AccessControl::Check is called, if there's an error,
override it for now (grace period) but log it as an error.

This looks like:
AccessControl: overriding DENY (for now)

Progress toward issue #14454
  • Loading branch information
@mlepage-google @pull
mlepage-google authored and pull[bot] committed Nov 2, 2023
1 parent 7fb721c commit 1426652
Show file tree
Hide file tree
Showing 3 changed files with 123 additions and 7 deletions.
99 changes: 97 additions & 2 deletions src/access/AccessControl.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -61,6 +61,89 @@ bool CheckRequestPrivilegeAgainstEntryPrivilege(Privilege requestPrivilege, Priv
return false;
}

#if CHIP_DETAIL_LOGGING

char GetAuthModeStringForLogging(AuthMode authMode)
{
switch (authMode)
{
case AuthMode::kNone:
return 'n';
case AuthMode::kPase:
return 'p';
case AuthMode::kCase:
return 'c';
case AuthMode::kGroup:
return 'g';
}
return 'u';
}

constexpr int kCharsPerCatForLogging = 11; // including final null terminator

char * GetCatStringForLogging(char * buf, size_t size, const CATValues & cats)
{
if (size == 0)
{
return nullptr;
}
char * p = buf;
char * const end = buf + size;
*p = '\0';
// Format string chars needed:
// 1 for comma (optional)
// 2 for 0x prefix
// 8 for 32-bit hex value
// 1 for null terminator (at end)
constexpr char fmtWithoutComma[] = "0x%08" PRIX32;
constexpr char fmtWithComma[] = ",0x%08" PRIX32;
constexpr int countWithoutComma = 10;
constexpr int countWithComma = countWithoutComma + 1;
bool withComma = false;
for (auto cat : cats.values)
{
if (cat == chip::kUndefinedCAT)
{
break;
}
snprintf(p, static_cast<size_t>(end - p), withComma ? fmtWithComma : fmtWithoutComma, cat);
p += withComma ? countWithComma : countWithoutComma;
if (p >= end)
{
// Output was truncated.
p = end - ((size < 4) ? size : 4);
while (*p)
{
// Indicate truncation if possible.
*p++ = '.';
}
break;
}
withComma = true;
}
return buf;
}

char GetPrivilegeStringForLogging(Privilege privilege)
{
switch (privilege)
{
case Privilege::kView:
return 'v';
case Privilege::kProxyView:
return 'p';
case Privilege::kOperate:
return 'o';
case Privilege::kManage:
return 'm';
case Privilege::kAdminister:
return 'a';
}
return 'u';
}

#endif // CHIP_DETAIL_LOGGING

} // namespace

namespace chip {
Expand All @@ -72,13 +155,13 @@ AccessControl::Delegate AccessControl::mDefaultDelegate;

CHIP_ERROR AccessControl::Init()
{
ChipLogDetail(DataManagement, "AccessControl::Init");
ChipLogDetail(DataManagement, "AccessControl: initializing");
return mDelegate.Init();
}

CHIP_ERROR AccessControl::Finish()
{
ChipLogDetail(DataManagement, "AccessControl::Finish");
ChipLogDetail(DataManagement, "AccessControl: finishing");
return mDelegate.Finish();
}

Expand All @@ -88,6 +171,18 @@ CHIP_ERROR AccessControl::Check(const SubjectDescriptor & subjectDescriptor, con
// Don't check if using default delegate (e.g. test code that isn't testing access control)
ReturnErrorCodeIf(&mDelegate == &mDefaultDelegate, CHIP_NO_ERROR);

#if CHIP_DETAIL_LOGGING
{
char buf[6 * kCharsPerCatForLogging];
ChipLogDetail(DataManagement,
"AccessControl: checking f=%" PRIu8 " a=%c s=0x" ChipLogFormatX64 " t=%s c=" ChipLogFormatMEI " e=%" PRIu16
" p=%c",
subjectDescriptor.fabricIndex, GetAuthModeStringForLogging(subjectDescriptor.authMode),
ChipLogValueX64(subjectDescriptor.subject), GetCatStringForLogging(buf, sizeof(buf), subjectDescriptor.cats),
ChipLogValueMEI(requestPath.cluster), requestPath.endpoint, GetPrivilegeStringForLogging(requestPrivilege));
}
#endif

// Operational PASE not supported for v1.0, so PASE implies commissioning, which has highest privilege.
ReturnErrorCodeIf(subjectDescriptor.authMode == AuthMode::kPase, CHIP_NO_ERROR);

Expand Down
17 changes: 14 additions & 3 deletions src/app/CommandHandler.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -261,7 +261,12 @@ CHIP_ERROR CommandHandler::ProcessCommandDataIB(CommandDataIB::Parser & aCommand
Access::RequestPath requestPath{ .cluster = concretePath.mClusterId, .endpoint = concretePath.mEndpointId };
Access::Privilege requestPrivilege = RequiredPrivilege::ForInvokeCommand(concretePath);
err = Access::GetAccessControl().Check(subjectDescriptor, requestPath, requestPrivilege);
err = CHIP_NO_ERROR; // TODO: remove override
if (err != CHIP_NO_ERROR)
{
// Grace period until ACLs are in place
ChipLogError(DataManagement, "AccessControl: overriding DENY (for now)");
err = CHIP_NO_ERROR;
}
if (err != CHIP_NO_ERROR)
{
if (err != CHIP_ERROR_ACCESS_DENIED)
Expand Down Expand Up @@ -381,11 +386,17 @@ CHIP_ERROR CommandHandler::ProcessGroupCommandDataIB(CommandDataIB::Parser & aCo
{
Access::SubjectDescriptor subjectDescriptor = mpExchangeCtx->GetSessionHandle()->GetSubjectDescriptor();
Access::RequestPath requestPath{ .cluster = concretePath.mClusterId, .endpoint = concretePath.mEndpointId };
Access::Privilege requestPrivilege = Access::Privilege::kOperate; // TODO: get actual request privilege
Access::Privilege requestPrivilege = RequiredPrivilege::ForInvokeCommand(concretePath);
err = Access::GetAccessControl().Check(subjectDescriptor, requestPath, requestPrivilege);
err = CHIP_NO_ERROR; // TODO: remove override
if (err != CHIP_NO_ERROR)
{
// Grace period until ACLs are in place
ChipLogError(DataManagement, "AccessControl: overriding DENY (for now)");
err = CHIP_NO_ERROR;
}
if (err != CHIP_NO_ERROR)
{
// TODO: handle errors that aren't CHIP_ERROR_ACCESS_DENIED, etc.
continue;
}
}
Expand Down
14 changes: 12 additions & 2 deletions src/app/util/ember-compatibility-functions.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -389,7 +389,12 @@ CHIP_ERROR ReadSingleClusterData(const SubjectDescriptor & aSubjectDescriptor, b
Access::RequestPath requestPath{ .cluster = aPath.mClusterId, .endpoint = aPath.mEndpointId };
Access::Privilege requestPrivilege = RequiredPrivilege::ForReadAttribute(aPath);
CHIP_ERROR err = Access::GetAccessControl().Check(aSubjectDescriptor, requestPath, requestPrivilege);
err = CHIP_NO_ERROR; // TODO: remove override
if (err != CHIP_NO_ERROR)
{
// Grace period until ACLs are in place
ChipLogError(DataManagement, "AccessControl: overriding DENY (for now)");
err = CHIP_NO_ERROR;
}
if (err != CHIP_NO_ERROR)
{
ReturnErrorCodeIf(err != CHIP_ERROR_ACCESS_DENIED, err);
Expand Down Expand Up @@ -821,7 +826,12 @@ CHIP_ERROR WriteSingleClusterData(const SubjectDescriptor & aSubjectDescriptor,
Access::RequestPath requestPath{ .cluster = aPath.mClusterId, .endpoint = aPath.mEndpointId };
Access::Privilege requestPrivilege = RequiredPrivilege::ForWriteAttribute(aPath);
CHIP_ERROR err = Access::GetAccessControl().Check(aSubjectDescriptor, requestPath, requestPrivilege);
err = CHIP_NO_ERROR; // TODO: remove override
if (err != CHIP_NO_ERROR)
{
// Grace period until ACLs are in place
ChipLogError(DataManagement, "AccessControl: overriding DENY (for now)");
err = CHIP_NO_ERROR;
}
if (err != CHIP_NO_ERROR)
{
ReturnErrorCodeIf(err != CHIP_ERROR_ACCESS_DENIED, err);
Expand Down

0 comments on commit 1426652

Please sign in to comment.