RFC 1: Add Source location information to Logs, Diagnoses, and Errors

[dhawkes]

Abstract

Today, the OCP Test and Validation Output specification doesn’t contain source location information, making it difficult to identify and debug issues. This is especially problematic for dynamic logs, which are generated at runtime and don’t have a fixed error string to search for in the codebase. We propose adding a source location artifact to the OCP Diag specification in order to address these concerns.

Motivation

Adding source location information would greatly improve the usefulness of logs and make it easier to identify and resolve issues. It would allow users to quickly locate the relevant code location and understand the context in which the log was generated. To do this, we propose a new source location artifact to be added to the preexisting Diagnosis, Log, and Error artifacts.

Proposed Changes

This would result in the following spec changes:

SourceLocation

Attributes	Type	Required	Description
filepath	string	Yes	A string indicates a part or the full path in the source code.
line	number	Yes	An integer indicates the line number in the file path.

Diagnosis

Attributes	Type	Required	Description
verdict	string	Yes	A short string describing the overall determination of the diagnostic (e.g. cpu-good, hdd-overtemp, etc). These short human readable strings are typically used to aggregate counts of observed symptoms.
type	JSON: stringMessage: enum Diagnosis Type	Yes	The overall assessment of the result of the diagnostic execution, expressed as a DiagnosisType message.
message	string	No	Detailed explanation why the Diagnosis gives the above verdict of the hardware health.
hardwareInfoId	string	No	Hardware identifier to which the diagnosis applies. The referenced info ID information can be found in the DutInfo of TestRunStart.
subcomponent	JSON: objectMessage: Subcomponent	No	Provides additional information about a specific functional subcomponent of the hardware referenced by ID. If present, the diagnosis applies to this subcomponent instead of the parent hardware component.
sourceLocation	JSON: objectMessage: SourceLocation	No	A SourceLocation information for debugging or tracing program execution.

Log

Attribute	Type	Required	Description
severity	JSON: stringMessage: enum Severity	Yes	Indicates the significance of the log message.
message	String	Yes	Text string intended to aid in debugging or tracing of diagnostic execution.
sourceLocation	JSON: objectMessage: SourceLocation	No	A SourceLocation information for debugging or tracing program execution.

Error

Attribute	Type	Required	Description
symptom	string	Yes	A short string of the software issued verdict.
message	string	No	Detailed explanation why the Error gives the above symptom.
softwareInfoIds	JSON: array Message: list of string	No	A list of software components or firmware components to which the Error is associated. The software ID information can be found in the DutInfo field of TestRunStart.
sourceLocation	JSON: objectMessage: SourceLocation	No	A SourceLocation information for debugging or tracing program execution.

Examples

Diagnosis

{
  "testStepArtifact": {
    "diagnosis": {
      "verdict": "mlc-intranode-bandwidth-pass",
      "type": "PASS",
      "message": "intranode bandwidth within threshold.",
      "hardwareInfoId": "1",
      "subcomponent": {
        "type": "BUS",
        "name": "QPI1",
        "location": "CPU-3-2-3",
        "version": "1",
        "revision": "0"
      },
      "sourceLocation": {
        "filepath": "examples/simple/simple_main.cc",
        "line": 90
      }
    },
    "testStepId": "1"
  },
  "sequenceNumber": 1,
  "timestamp": "2022-07-25T02:15:58.296032Z"
}

Log

{
  "testStepArtifact": {
    "log": {
      "message": "file operation completed successfully.",
      "severity": "INFO",
      "sourceLocation": {
        "filepath": "examples/simple/simple_main.cc",
        "line": 90
      }
    },
    "testStepId": "1"
  },
  "sequenceNumber": 1,
  "timestamp": "2022-07-25T03:19:01.274584Z"
}

Error

{
  "testStepArtifact": {
    "error": {
      "symptom": "bad-return-code",
      "message": "software exited abnormally.",
      "softwareInfoIds": [
        "3",
        "4"
      ],
      "sourceLocation": {
        "filepath": "examples/simple/simple_main.cc",
        "line": 90
      }
    },
    "testStepId": "1"
  },
  "sequenceNumber": 1,
  "timestamp": "2022-07-25T03:06:11.254865Z"
}

[dhawkes]

@mimir-d Ready for you to take a look

[mimir-d]

i have to say, for the first rfc, this format looks very nice. if we get a linked PR to it, i think the structure of rfcs looks rather final.

as for the content of this rfc, my comments are:

1. i think sourceLocation is too specialized as a name. There's also some collision with the agreement of having softwareInfoId 0 as the self-referential software info, the diagnostic itself. From what i gather here, this sourceLocation is always relative to the diag software package, so i would rather propose, for more generality, something like "emitter" (doesnt have to be this exact name, but the correct abstraction semantics). This emitter structure can have source coordinates and a link to a software info id (which says that the diag itself has emitted said error/log/diagnostic or some other software component emitted the error/log entry. think fio as a dependency being executed with logging). This being a structure also allows for further extension later on, as the case may be when we discover more usages that are unknown right now. To note, the error artifact already references a software info; we'd need to clarify the distinction.
2. filepath should just be file (or path, but file is preferred). The description field should also be more specific, looks ambiguous to me right now as to what file it's actually referencing (or storage for said file, though this shouldnt be an issue here if the referee is clear)
3. at least for the log/error objects, we are collaborating with a different OCP project regarding the internal representation for logging. if you're not aware of that intersection, I can pull in the right people for a discussion. It might be that they've already gone through this, what essentially is a, structured logging aspect.

waiting for other comments in the meantime: @dframe-google @njordr @dalwise @20100M @yuanlinw-google

[njordr]

I agree with the sourceLocation (and up vote for emitter)

[dhawkes]

@mimir-d I'm not familiar with the idea that software info id 0 is the diag itself and don't see this in the spec anywhere. If we want there to be a software info id associated with the souce location, then in what cases would it not be zero (referring to the diag)? If there aren't any then we just shouldn't include that info. Note that diagnoses and errors already have software info associated with them... I think having source lline be it's own thing makes sense, no need to conflate it with the idea of software source when that's already communicated in the spec. Also sourcelocation isn't a specialized name, it's used in the the C++ standard library: https://en.cppreference.com/w/cpp/utility/source_location.

2. Agreed.

3. I'm not sure what you're referring to.

[20100M]

Since the intent is to ease debugging and troubleshooting would it be more beneficial to expand sourceLocation to a more generic stackTrace or stdErr element to trace where the error was emitted. This would satisfy the needs of tracking source location while providing more general-purpose traceability of an error in execution.

[dhawkes]

I think we'd need a separate RFC that would describe how we implement that and what that would look like. Would it just be another string field called stack trace? Since it's an addition could we separate that discussion from this?

[dhawkes]

Summarizing what we discussed in the meeting on Wednesday:

Software Info Id is meant to capture the "emitter" idea of saying where something comes from. Right now Logs and Diagnoses do not have this, so it's implied that they are always produced by the diagnostic itself. This is fine for Diagnoses as they are meant to be hardware related, but we may want to add software info ID to logs for when logs are "re-logged" from other software.

Ultimately though, this question is not related to the source location and can be explored in a future RFC.

Let me know if this is accurate @mimir-d

Also @mimir-d, @20100M are we ready to approve this and discuss other additions in future RFCs or do we feel like there needs to be more discussion?

[dhawkes]

When we're ready I can get the PR updating the JSON spec and markdown put together as well.

[mimir-d]

yes; went thru the PR and posted comments

[mimir-d]

PR #637 was merged 🎉

@ckchen-google would be great if you could give us some feedback around your experience of proposing a spec change, in #631