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

custom nextcloud JSON log format fails: "file is not JSON-lines" #1196

Closed
meonkeys opened this issue Oct 16, 2023 · 3 comments
Closed

custom nextcloud JSON log format fails: "file is not JSON-lines" #1196

meonkeys opened this issue Oct 16, 2023 · 3 comments
Labels

Comments

@meonkeys
Copy link
Contributor

lnav version
v0.11.2

Describe the bug
I upgraded from v0.11.1 recently and my custom format stopped working. The debug log says: scan with format (nextcloud) does not match -- file is not JSON-lines. It falls back to bunyan.

To Reproduce
Install this log format:

{
  "$schema": "https://lnav.org/schemas/format-v1.schema.json",
  "nextcloud": {
    "title": "Nextcloud server logs",
    "description": "Nextcloud JSON server logs",
    "url": "https://docs.nextcloud.com/server/stable/admin_manual/configuration_server/logging_configuration.html?highlight=logging#log-field-breakdown",
    "json": true,
    "file-pattern": "(audit|flow|nextcloud)\\.log",
    "opid-field": "reqId",
    "level-field": "level",
    "body-field": "message",
    "hide-extra": true,
    "level" : {
      "debug" : "0",
      "info": "1",
      "warning" : "2",
      "error" : "3",
      "fatal" : "4"
    },
    "timestamp-field": "time",
    "convert-to-local-time": true,
    "multiline": false,
    "value": {
      "exception": {
        "kind": "json"
      },
      "app": {
        "kind": "string",
        "identifier": true
      },
      "reqId": {
        "kind": "string",
        "identifier": true
      },
      "remoteAddr": {
        "kind": "string",
        "identifier": true
      }
    },
    "line-format": [
      {
        "field": "__timestamp__",
        "timestamp-format": "%b %e %H:%M:%S"
      },
      " ",
      {
        "field": "reqId",
        "max-width": 3,
        "overflow": "truncate"
      },
      " ",
      {
        "field": "remoteAddr",
        "min-width": 15
      },
      " ",
      {
        "field": "__level__",
        "text-transform": "uppercase"
      },
      " ",
      {
        "field": "app"
      },
      " ",
      {
        "field": "message"
      }
    ],
    "sample": [
      {
        "line": "{\"reqId\":\"ztEUPOtzDmW7nQlsQPdT\",\"level\":2,\"time\":\"2022-04-13T19:15:10+00:00\",\"remoteAddr\":\"10.0.0.1\",\"user\":\"steve\",\"app\":\"OC\\\\Log\\\\Rotate\",\"method\":\"\",\"url\":\"--\",\"message\":\"Log file \\\"/var/www/html/data/nextcloud.log\\\" was over 104857600 bytes, moved to \\\"/var/www/html/data/nextcloud.log.1\\\"\",\"userAgent\":\"--\",\"version\":\"25.0.5.1\",\"data\":{\"app\":\"OC\\\\Log\\\\Rotate\"}}",
        "level": "info"
      }
    ]
  }
}

Save these log lines to nextcloud.log:

{"reqId":"twvbRFk1OwgHo2bqggnx","level":1,"time":"2023-10-01T02:39:09+00:00","remoteAddr":"10.0.0.1","user":"admin","app":"files_antivirus","method":"","url":"--","message":"Tried to scan non file","userAgent":"--","version":"29.1.1.0","data":{"app":"files_antivirus"}}
{"reqId":"twvbRFk1OwgHo2bqggnx","level":1,"time":"2023-10-01T02:39:09+00:00","remoteAddr":"","user":"--","app":"files_antivirus","method":"","url":"--","message":"Tried to scan non file","userAgent":"--","version":"29.1.1.0","data":{"app":"files_antivirus"}}
{"reqId":"pZpwRdWUcILeyKMZNPQt","level":1,"time":"2023-10-01T02:50:03+00:00","remoteAddr":"","user":"--","app":"fulltextsearch_elasticsearch","method":"","url":"--","message":"Request: PUT http://elasticsearch:9200/nextcloud/_doc/files%3A1780281","userAgent":"--","version":"29.1.1.0","data":{"app":"fulltextsearch_elasticsearch","request":"{\"[object] (GuzzleHttp\\Psr7\\Request)\":{\"GuzzleHttp\\Psr7\\Requestmethod\":\"PUT\",\"GuzzleHttp\\Psr7\\RequestrequestTarget\":null,\"GuzzleHttp\\Psr7\\Requesturi\":{\"[object] (GuzzleHttp\\Psr7\\Uri)\":{\"GuzzleHttp\\Psr7\\Urischeme\":\"http\",\"GuzzleHttp\\Psr7\\UriuserInfo\":\"\",\"GuzzleHttp\\Psr7\\Urihost\":\"elasticsearch\",\"GuzzleHttp\\Psr7\\Uriport\":9200,\"GuzzleHttp\\Psr7\\Uripath\":\"/nextcloud/_doc/files%3A1780281\",\"GuzzleHttp\\Psr7\\Uriquery\":\"\",\"GuzzleHttp\\Psr7\\Urifragment\":\"\",\"GuzzleHttp\\Psr7\\UricomposedComponents\":\"http://elasticsearch:9200/nextcloud/_doc/files%3A1780281\"}},\"GuzzleHttp\\Psr7\\Requestheaders\":{\"Host\":[\"elasticsearch:9200\"],\"Accept\":[\"application/vnd.elasticsearch+json; compatible-with=8\"],\"Content-Type\":[\"application/vnd.elasticsearch+json; compatible-with=8\"],\"User-Agent\":[\"elasticsearch-php/8.6.1 (Linux 5.15.0-84-generic; PHP 8.2.11)\"],\"x-elastic-client-meta\":[\"es=8.6.1,php=8.2.11,t=8.7.0,a=0,gu=7.8.0\"]},\"GuzzleHttp\\Psr7\\RequestheaderNames\":{\"accept\":\"Accept\",\"content-type\":\"Content-Type\",\"host\":\"Host\",\"user-agent\":\"User-Agent\",\"x-elastic-client-meta\":\"x-elastic-client-meta\"},\"GuzzleHttp\\Psr7\\Requestprotocol\":\"1.1\",\"GuzzleHttp\\Psr7\\Requeststream\":{\"[object] (GuzzleHttp\\Psr7\\Stream)\":{\"GuzzleHttp\\Psr7\\Streamstream\":\"[resource] Resource id #1635\",\"GuzzleHttp\\Psr7\\Streamsize\":null,\"GuzzleHttp\\Psr7\\Streamseekable\":true,\"GuzzleHttp\\Psr7\\Streamreadable\":true,\"GuzzleHttp\\Psr7\\Streamwritable\":true,\"GuzzleHttp\\Psr7\\Streamuri\":\"php://temp\",\"GuzzleHttp\\Psr7\\StreamcustomMetadata\":[]}}}}"}}
{"reqId":"WO0XBZZbefmkp8yHeptb","level":1,"time":"2023-10-16T01:47:44+00:00","remoteAddr":"192.168.1.1","user":"jeff","app":"memories","method":"PATCH","url":"--","message":"Memories: Updated item successfully","userAgent":"--","version":"29.1.2.1","data":{"app":"memories"}}
{"reqId":"SblFU0l19re9TAE2UQft","level":1,"time":"2023-10-16T01:50:18+00:00","remoteAddr":"192.168.1.1","user":"jeff","app":"files_versions","method":"","url":"--","message":"Mark to expire /Documents/phat.txt next version should be 1697407738 or smaller. (prevTimestamp: 1697411338; step: 3600","userAgent":"--","version":"29.1.2.1","data":{"app":"files_versions"}}

Open with lnav. v0.11.1 shows something like this:

LOG ❭2023-09-30T19:38:49.000❭nextcloud❭nextcloud.log[0]❭twv❭
┌Sep 30 19:38:49 twv                 WARNING OC\Log\Rotate Log file "/var/www/html/data/nextcloud.log" was over 104857600 bytes, moved to "│
│Sep 30 19:39:09 twv                 INFO files_antivirus Tried to scan non file                                                           │
│Sep 30 19:39:09 twv                 INFO files_antivirus Tried to scan non file                                                           │
│Sep 30 19:39:09 twv                 INFO files_antivirus Tried to scan non file                                                           │
│Sep 30 19:39:09 twv                 INFO files_antivirus Tried to scan non file                                                           │
│Sep 30 19:39:09 twv                 INFO files_antivirus Tried to scan non file                                                           │
│Sep 30 19:40:02 q5N                 INFO passwords Passwords runs /var/www/html/cron.php in global mode                                   │
│Sep 30 19:40:41 twv                 INFO memories Memories: Indexing completed successfully                                               │
│Sep 30 19:45:02 rET                 INFO passwords Passwords runs /var/www/html/cron.php in global mode                                   │
│Sep 30 19:45:03 8ny 10.0.0.1        INFO richdocuments Fetched capabilities endpoint from https://collabora.twobulb.com/hosting/capabiliti│
│Sep 30 19:45:08 rET                 INFO richdocuments Fetched capabilities endpoint from https://collabora.twobulb.com/hosting/capabiliti│

v0.11.2 shows something like this:

 LOG ❭2023-10-01T02:38:49.000❭bunyan❭nextcloud.log[0]❭
┌2023-10-01T02:38:49.000 -[-] INFO     -                                                                                                   │
│  reqId: twvbRFk1OwgHo2bqggnx                                                                                                             │
│  remoteAddr:                                                                                                                             │
│  user: --                                                                                                                                │
│  app: OC\Log\Rotate                                                                                                                      │
│  method:                                                                                                                                 │
│  url: --                                                                                                                                 │
│  message: Log file "/var/www/html/data/nextcloud.log" was over 104857600 bytes, moved to "/var/www/html/data/nextcloud.log.1"            │
│  userAgent: --                                                                                                                           │
│  version: 27.1.1.0                                                                                                                       │
│  data: {"app":"OC\\Log\\Rotate"}                                                                                                         │
│2023-10-01T02:39:09.000 -[-] INFO     -                                                                                                   │
│  reqId: twvbRFk1OwgHo2bqggnx                                                                                                             │
│  remoteAddr:                                                                                                                             │
│  user: --                                                                                                                                │
│  app: files_antivirus                                                                                                                    │
│  method:                                                                                                                                 │
│  url: --                                                                                                                                 │
│  message: Tried to scan non file                                                                                                         │
│  userAgent: --                                                                                                                           │
│  version: 27.1.1.0                                                                                                                       │
│  data: {"app":"files_antivirus"}                                                                                                         │
│2023-10-01T02:39:09.000 -[-] INFO     -                                                                                                   │
│  reqId: twvbRFk1OwgHo2bqggnx                                                                                                             │
│  remoteAddr:                                                                                                                             │
│  user: --                                                                                                                                │
│  app: files_antivirus                                                                                                                    │
│  method:                                                                                                                                 │
│  url: --                                                                                                                                 │
│  message: Tried to scan non file                                                                                                         │
│  userAgent: --                                                                                                                           │
│  version: 27.1.1.0                                                                                                                       │
│  data: {"app":"files_antivirus"}                                                                                                         │
(snipped)
@meonkeys meonkeys added the bug label Oct 16, 2023
@tstack
Copy link
Owner

tstack commented Oct 16, 2023

I think I ran into this myself and fixed it. Can you try a binary attached to this nightly build:

https://github.com/tstack/lnav/actions/runs/6473869622

@meonkeys
Copy link
Contributor Author

meonkeys commented Oct 16, 2023

Yes, that build works as expected. Output looks identical to v0.11.1. 🚀

@tstack
Copy link
Owner

tstack commented Oct 16, 2023

The check was a bit erroneous and removed here:

9663b1f#diff-1467956d44dcf132af623eff0ae084ee192ee7c5c8f3a123e13b5e88fadab4feL1094

@tstack tstack closed this as completed Oct 16, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

2 participants