lnav icon indicating copy to clipboard operation
lnav copied to clipboard
verified publisher icon tstack

Q: How to get timestamp from json body?

Open loeffel-io opened this issue 9 months ago • 4 comments 

{
  "$schema": "https://lnav.org/schemas/format-v1.schema.json",
  "k8s": {
    "title": "k8s",
    "description": "Parses logs with a Kubernetes pod prefix (extracting service name) and a JSON body.",
    "url": "https://lnav.org/docs/format.html",
    "regex": {
      "main": {
        "pattern": "^\\[pod\\/[^\\/]+\\/(?<service_name>[^\\/\\]]+)\\]\\s+(?<body>\\{.*\\})$"
      }
    },
    "level-field": "body.severity",
    "timestamp-field": "body.time",
    "body-field": "body.message",
    "value": {
      "service_name": {
        "kind": "string",
        "identifier": true
      },
      "body": {
        "kind": "json"
      }
    },
    "sample": [
      {
        "line": "[pod/earth-resourcemanager-service-loeffel-io-75ff987878-kh56q/earth-resourcemanager-service-loeffel-io] {\"severity\":\"INFO\",\"time\":\"2025-05-26T11:29:18Z\",\"caller\":\"logger_v1/zap.go:77\",\"message\":\"started call\",\"protocol\":\"grpc\",\"grpc.component\":\"server\",\"grpc.service\":\"grpc.health.v1.Health\",\"grpc.method\":\"Check\",\"grpc.method_type\":\"unary\",\"peer.address\":\"127.0.0.6:47583\",\"grpc.start_time\":\"2025-05-26T11:29:18Z\",\"grpc.request.deadline\":\"2025-05-26T11:29:19Z\",\"grpc.time_ms\":\"0.035\"}"
      },
      {
        "line": "[pod/earth-resourcemanager-service-loeffel-io-75ff987878-kh56q/earth-resourcemanager-service-loeffel-io] {\"severity\":\"INFO\",\"time\":\"2025-05-26T11:29:18Z\",\"caller\":\"logger_v1/zap.go:77\",\"message\":\"finished call\",\"protocol\":\"grpc\",\"grpc.component\":\"server\",\"grpc.service\":\"grpc.health.v1.Health\",\"grpc.method\":\"Check\",\"grpc.method_type\":\"unary\",\"peer.address\":\"127.0.0.6:47583\",\"grpc.start_time\":\"2025-05-26T11:29:18Z\",\"grpc.request.deadline\":\"2025-05-26T11:29:19Z\",\"grpc.code\":\"OK\",\"grpc.time_ms\":\"0.126\"}"
      }
    ]
  }
}

✘ error: invalid pattern: “/k8s/regex/main”
 reason: no timestamp capture found in the pattern
 --> /Users/loeffel/.lnav/formats/installed/k8s.json:3
 = help: all log messages need a timestamp
✘ error: invalid value for property “/k8s/timestamp-field”
 reason: “body.time” was not found in the pattern at /k8s/regex/main
 --> /Users/loeffel/.lnav/formats/installed/k8s.json:3
 = note: the following captures are available:
           body, service_name
✘ error: invalid sample log message: "[pod/earth-resourcemanager-service-loeffel-io-75ff987878-kh56q/earth-resourcemanager-service-loeffel-io] {\"severity\":\"INFO\",\"time\":\"2025-05-26T11:29:18Z\",\"caller\":\"logger_v1/zap.go:77\",\"message\":\"started call\",\"protocol\":\"grpc\",\"grpc.component\":\"server\",\"grpc.service\":\"grpc.health.v1.Health\",\"grpc.method\":\"Check\",\"grpc.method_type\":\"unary\",\"peer.address\":\"127.0.0.6:47583\",\"grpc.start_time\":\"2025-05-26T11:29:18Z\",\"grpc.request.deadline\":\"2025-05-26T11:29:19Z\",\"grpc.time_ms\":\"0.035\"}"
 reason: timestamp was not captured
 --> /Users/loeffel/.lnav/formats/installed/k8s.json:26
 = help: A timestamp needs to be captured in order for a line to be recognized as a log message
✘ error: invalid sample log message: "[pod/earth-resourcemanager-service-loeffel-io-75ff987878-kh56q/earth-resourcemanager-service-loeffel-io] {\"severity\":\"INFO\",\"time\":\"2025-05-26T11:29:18Z\",\"caller\":\"logger_v1/zap.go:77\",\"message\":\"finished call\",\"protocol\":\"grpc\",\"grpc.component\":\"server\",\"grpc.service\":\"grpc.health.v1.Health\",\"grpc.method\":\"Check\",\"grpc.method_type\":\"unary\",\"peer.address\":\"127.0.0.6:47583\",\"grpc.start_time\":\"2025-05-26T11:29:18Z\",\"grpc.request.deadline\":\"2025-05-26T11:29:19Z\",\"grpc.code\":\"OK\",\"grpc.time_ms\":\"0.126\"}"
 reason: timestamp was not captured
 --> /Users/loeffel/.lnav/formats/installed/k8s.json:29
 = help: A timestamp needs to be captured in order for a line to be recognized as a log message

loeffel-io avatar May 26 '25 12:05 loeffel-io

getting pretty crazy with this - added timestamp to the log line - which now make my first issue obsolete but

how can i get [prefix] [timestamp] [json body] to work? i don't understand how to access the body parsed json fields etc

{
  "$schema": "https://lnav.org/schemas/format-v1.schema.json",
  "k8s": {
    "title": "k8s",
    "description": "Parses logs with a Kubernetes pod prefix (extracting service name) and a JSON body.",
    "url": "https://lnav.org/docs/format.html",
    "regex": {
      "main": {
        "pattern": "^\\[pod\\/[^\\/]+\\/(?<service_name>[^\\/\\]]+)\\]\\s+(?<timestamp>[0-9\\-\\:\\.TZ]+)\\s+(?<body>\\{.*\\})$"
      }
    },
    "level-field": "body.severity",
    "level": {
      "info": "INFO",
      "error": "ERROR"
    },
    "line-format": [
      {
        "field": "body/message"
      }
    ],
    "opid-field": "body/grpc.request_id",
    "value": {
      "service_name": {
        "kind": "string",
        "identifier": true
      },
      "body": {
        "kind": "json"
      }
    },
    "sample": [
      {
        "line": "[pod/earth-resourcemanager-service-loeffel-io-75ff987878-kh56q/earth-resourcemanager-service-loeffel-io] 2025-05-26T11:28:16.946530606Z {\"severity\":\"INFO\",\"time\":\"2025-05-26T11:29:18Z\",\"caller\":\"logger_v1/zap.go:77\",\"message\":\"started call\",\"protocol\":\"grpc\",\"grpc.component\":\"server\",\"grpc.service\":\"grpc.health.v1.Health\",\"grpc.method\":\"Check\",\"grpc.method_type\":\"unary\",\"peer.address\":\"127.0.0.6:47583\",\"grpc.start_time\":\"2025-05-26T11:29:18Z\",\"grpc.request.deadline\":\"2025-05-26T11:29:19Z\",\"grpc.time_ms\":\"0.035\"}"
      },
      {
        "line": "[pod/earth-resourcemanager-service-loeffel-io-75ff987878-kh56q/earth-resourcemanager-service-loeffel-io] 2025-05-26T11:28:16.946530606Z {\"severity\":\"INFO\",\"time\":\"2025-05-26T11:29:18Z\",\"caller\":\"logger_v1/zap.go:77\",\"message\":\"finished call\",\"protocol\":\"grpc\",\"grpc.component\":\"server\",\"grpc.service\":\"grpc.health.v1.Health\",\"grpc.method\":\"Check\",\"grpc.method_type\":\"unary\",\"peer.address\":\"127.0.0.6:47583\",\"grpc.start_time\":\"2025-05-26T11:29:18Z\",\"grpc.request.deadline\":\"2025-05-26T11:29:19Z\",\"grpc.code\":\"OK\",\"grpc.time_ms\":\"0.126\"}"
      }
    ]
  }
}

loeffel-io avatar May 26 '25 14:05 loeffel-io

does not work in any way - any help is appriciated

{
  "$schema": "https://lnav.org/schemas/format-v1.schema.json",
  "k8s": {
    "title": "k8s",
    "description": "Parses logs with a Kubernetes pod prefix (extracting service name) and a JSON body.",
    "url": "https://lnav.org/docs/format.html",
    "regex": {
      "main": {
        "pattern": "^\\[pod\\/[^\\/]+\\/(?<service_name>[^\\/\\]]+)\\]\\s+(?<timestamp>[0-9\\-\\:\\.TZ]+)\\s+(?<body>\\{.*\\})$"
      }
    },
    "line-format": [
      {
        "field": "body/message"
      }
    ],
    "value": {
      "service_name": {
        "kind": "string",
        "identifier": true
      },
      "body": {
        "kind": "json",
        "hidden": true
      },
      "body/message": {
        "kind": "string"
      }
    },
    "sample": [
      {
        "line": "[pod/earth-resourcemanager-service-loeffel-io-75ff987878-kh56q/earth-resourcemanager-service-loeffel-io] 2025-05-26T11:28:16.946530606Z {\"severity\":\"INFO\",\"time\":\"2025-05-26T11:29:18Z\",\"caller\":\"logger_v1/zap.go:77\",\"message\":\"started call\",\"protocol\":\"grpc\",\"grpc.component\":\"server\",\"grpc.service\":\"grpc.health.v1.Health\",\"grpc.method\":\"Check\",\"grpc.method_type\":\"unary\",\"peer.address\":\"127.0.0.6:47583\",\"grpc.start_time\":\"2025-05-26T11:29:18Z\",\"grpc.request.deadline\":\"2025-05-26T11:29:19Z\",\"grpc.time_ms\":\"0.035\"}"
      },
      {
        "line": "[pod/earth-resourcemanager-service-loeffel-io-75ff987878-kh56q/earth-resourcemanager-service-loeffel-io] 2025-05-26T11:28:16.946530606Z {\"severity\":\"INFO\",\"time\":\"2025-05-26T11:29:18Z\",\"caller\":\"logger_v1/zap.go:77\",\"message\":\"finished call\",\"protocol\":\"grpc\",\"grpc.component\":\"server\",\"grpc.service\":\"grpc.health.v1.Health\",\"grpc.method\":\"Check\",\"grpc.method_type\":\"unary\",\"peer.address\":\"127.0.0.6:47583\",\"grpc.start_time\":\"2025-05-26T11:29:18Z\",\"grpc.request.deadline\":\"2025-05-26T11:29:19Z\",\"grpc.code\":\"OK\",\"grpc.time_ms\":\"0.126\"}"
      }
    ]
  }
}

loeffel-io avatar May 26 '25 14:05 loeffel-io

There's kinda two options:

  1. Make the input file a proper JSON-Lines file where there is only a single JSON object per line. Would you be able to move the "prefix" into the JSON object itself?
  2. Use the demultiplexing feature that will split the input into separate files based on the prefix and strip the prefix.

In either case, you'll need to write a format file that defines how to process the JSON objects. The github_events_log format can be a good reference.

One note about the format file:

"level-field": "body.severity",

lnav uses JSON Pointer, so referencing a nested field would use forward slashes instead of dots (i.e. "body/severity" instead of "body.severity").

tstack avatar May 27 '25 20:05 tstack

Make the input file a proper JSON-Lines file where there is only a single JSON object per line. Would you be able to move the "prefix" into the JSON object itself?

not really, i use the kubectl bazel run //deployments/$1:kubectl -- logs -f -l app=earth-$2-service --all-containers --prefix --timestamps cmd

Use the demultiplexing feature that will split the input into separate files based on the prefix and strip the prefix.

will check this

thank you very much for the informations

loeffel-io avatar May 28 '25 07:05 loeffel-io