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

[Enhancement] Adding logging to Matter to aid in debuggability #31804

Closed
woody-apple opened this issue Jan 31, 2024 · 9 comments · Fixed by #32053
Closed

[Enhancement] Adding logging to Matter to aid in debuggability #31804

woody-apple opened this issue Jan 31, 2024 · 9 comments · Fixed by #32053
Assignees
Labels
bug Something isn't working needs triage

Comments

@woody-apple
Copy link
Contributor

woody-apple commented Jan 31, 2024

Reproduction steps

In looking through Matter logging, we could use a little more detail to make it easier to triage networks with multiple devices, and generally associate logs together.

Collecting together a group of "simple" log enhancements that would help here.

@woody-apple woody-apple added bug Something isn't working needs triage labels Jan 31, 2024
@woody-apple
Copy link
Contributor Author

        ChipLogProgress(ExchangeManager,
                        "Retransmitting MessageCounter:" ChipLogFormatMessageCounter " on exchange " ChipLogFormatExchange
                        " Send Cnt %d",
                        messageCounter, ChipLogValueExchange(&entry->ec.Get()), entry->sendCount);

Let's add the nodeID and/or more context so we can figure out what this is retransmitting to

@woody-apple
Copy link
Contributor Author

    ChipLogError(Discovery, "Mdns: Resolve failure (%s)", errorStr);

We should log what we're trying to discover here.

@woody-apple
Copy link
Contributor Author

    ChipLogError(Controller, "Creating NSError from %" CHIP_ERROR_FORMAT, errorCode.Format());

Log which MTRDevice (and nodeID) this is for

@woody-apple
Copy link
Contributor Author

            ChipLogError(ExchangeManager,
                         "Failed to Send CHIP MessageCounter:" ChipLogFormatMessageCounter " on exchange " ChipLogFormatExchange
                         " sendCount: %u max retries: %d",
                         messageCounter, ChipLogValueExchange(&ec.Get()), sendCount, CHIP_CONFIG_RMP_DEFAULT_MAX_RETRANS);

Add nodeID to this

@woody-apple
Copy link
Contributor Author

    ChipLogError(SecureChannel, "CASESession timed out while waiting for a response from the peer. Current state was %u",
                 to_underlying(mState));

We should log the nodeID here.

@woody-apple
Copy link
Contributor Author

    if (err == CHIP_NO_ERROR)
    {
        ChipLogProgress(Controller, "Successfully finished commissioning step '%s'", StageToString(report.stageCompleted));
    }
    else
    {
        ChipLogProgress(Controller, "Error on commissioning step '%s': '%s'", StageToString(report.stageCompleted), err.AsString());
    }

    if (err != CHIP_NO_ERROR)
    {
        completionStatus.failedStage = MakeOptional(report.stageCompleted);
        ChipLogError(Controller, "Failed to perform commissioning step %d", static_cast<int>(report.stageCompleted));
        if (report.Is<AttestationErrorInfo>())
        {

This area in AutoCommissioner (and more down there) to allow us to know which device we're talking to (Could be vid/pid, etc)

@bzbarsky-apple
Copy link
Contributor

Let's add the nodeID and/or more context so we can figure out what this is retransmitting to

We could, but the message counter can be used to find the original transmission, which has that info...

Log which MTRDevice (and nodeID) this is for

That information is not currently available there. We could add another initializer which allows passing it in, and update all the callsites that have that info, of course.

@woody-apple
Copy link
Contributor Author

The key here is to have it on a single line, without manual humans reading through logs trying to associate things

@woody-apple woody-apple self-assigned this Feb 2, 2024
@carol-apple
Copy link
Contributor

carol-apple commented Feb 2, 2024

Logging NodeID would be great here too:

MTR_LOG_DEFAULT("Read attribute work item [%llu] report duplicate %@", workItemID, readItem);

Along with all other logging in MTRDevice.mm that begins with "Read attribute work item"

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working needs triage
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants