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

Log parent-field should wrap all logs #176

Closed
filex opened this issue Mar 31, 2021 · 3 comments · Fixed by #179
Closed

Log parent-field should wrap all logs #176

filex opened this issue Mar 31, 2021 · 3 comments · Fixed by #179
Labels
bug Something isn't working
Milestone

Comments

@filex
Copy link
Contributor

filex commented Mar 31, 2021

Couper offers two settings to wrap JSON log lines into a parent field. This is useful to avoid field clashes in the log db (e.g. ElasticSearch / ELK). I recently had that situation in a project running in Kubernetes where logs were supposed to ship via Logstash to a ES.

I have used these env vars:

COUPER_ACCESS_LOG_PARENT_FIELD=couper
COUPER_BACKEND_LOG_PARENT_FIELD=couper

As one would expect, this works for Couper's access log and backend log.

However, there are more log "types" that Couper uses. For example those with type":"couper_daemon. Those lines are used for startup messages and some generic errors that don't belong elsewhere.

I propose that we introduce a single setting that configures a wrapper object for all couper logs:

COUPER_LOG_PARENT_FIELD=couper

This way I

  • don't loose any less obvious loglines
  • have to write less env var settings
@filex
Copy link
Contributor Author

filex commented Mar 31, 2021

We can drop the two current log-parent settings mentioned above. I don't see a reason why we should ever configure separate wrapping fields. The use case is to disambiguate Couper's log fields from field mappings of other services in the same log index. There is no reason to separate our own log fields from each other.

@filex
Copy link
Contributor Author

filex commented Mar 31, 2021

There are more issues with the log wrapper. The backend log still writes fields to the top-level object.

couper.hcl

server "logs" {
  endpoint "/**" {
    proxy {
      backend {
        origin = "http://httpbin.org"
      }
    }
  }
}

run

COUPER_BACKEND_LOG_PARENT_FIELD=wrapper COUPER_ACCESS_LOG_PARENT_FIELD=wrapper couper run -log-format=json

call

curl :8080/ip

backend log (let's leave out the wrapper for brevitiy):

{
  "backend": "default",
  "build": "dev",
  "level": "info",
  "message": "",
  "timestamp": "2021-03-31T19:18:10+02:00",
  "type": "couper_daemon",
  "version": "0",
  "wrapper": {}
}

The shortened access log from the same request looks like this:

{
  "level": "info",
  "message": "",
  "timestamp": "2021-03-31T19:29:37+02:00",
  "wrapper":  {}
}
  • The backend field is clearly buggy. It belongs into the wrapper.
  • Where do version, build, type and level belong? I think it should be wrapped, too.
  • version, build and type missing in the access log. They should be present in all log envelopes. (They are also missing when not defining a parent-field).

full backend log:

{
  "backend": "default",
  "build": "dev",
  "level": "info",
  "message": "",
  "timestamp": "2021-03-31T19:18:10+02:00",
  "type": "couper_daemon",
  "version": "0",
  "wrapper": {
    "realtime": "178.652",
    "request": {
      "addr": "httpbin.org",
      "headers": {
        "accept": "*/*",
        "user-agent": "HTTPie/2.4.0"
      },
      "host": "httpbin.org",
      "method": "GET",
      "name": "default",
      "path": "/ip",
      "proto": "HTTP/1.1",
      "scheme": "http"
    },
    "response": {
      "headers": {
        "content-type": "application/json"
      },
      "proto": "HTTP/1.1",
      "tls": false
    },
    "status": 200,
    "timings": {
      "connect": "87.181",
      "dns": "1.440",
      "ttfb": "89.014"
    },
    "type": "couper_backend",
    "uid": "c1iatkgi7qkk5psg816g",
    "url": "http://httpbin.org:80/ip"
  }
}

full access log:

{
  "level": "info",
  "message": "",
  "timestamp": "2021-03-31T19:29:37+02:00",
  "wrapper": {
    "bytes": 236,
    "client_ip": "127.0.0.1",
    "endpoint": "/**",
    "handler": "endpoint",
    "method": "GET",
    "proto": "HTTP/1.1",
    "realtime": "316.251",
    "request": {
      "addr": "localhost:8080",
      "headers": {
        "accept": "*/*",
        "user-agent": "HTTPie/2.4.0"
      },
      "host": "localhost",
      "path": "/ip",
      "port": "8080",
      "tls": false
    },
    "response": {
      "bytes": 236,
      "headers": {
        "content-encoding": "gzip",
        "content-type": "application/json"
      }
    },
    "scheme": "http",
    "server": "logs",
    "status": 200,
    "type": "couper_access",
    "uid": "c1ib308i7qkk8ue01tug",
    "url": "http://localhost:8080/ip"
  }
}

@filex filex added the bug Something isn't working label Mar 31, 2021
@malud malud added this to the 1.0 milestone Apr 1, 2021
@malud malud mentioned this issue Apr 1, 2021
@malud
Copy link
Collaborator

malud commented Apr 1, 2021

all "data" fields can be moved to the wrapper. However, some basics like level, timestamp and message still remains at root level.

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

Successfully merging a pull request may close this issue.

2 participants