Loki: Push results in expecting IDENTIFIER

[Horkyze]

Describe the bug
When pushing data form fluent-plugin-grafana-loki the API call results in error:
parse error at line 1, col 2: syntax error: unexpected }, expecting IDENTIFIER

This also occurs when trying to replicate the API call via curl.

To Reproduce
Steps to reproduce the behavior:

1. Started Loki (FROM grafana/loki:master-eb7b495)
2. Started fluentd with loki plugin fluent-plugin-grafana-loki-1.2.3
3. Push some logs to loki (via fluentd or curl)

# test.json
{
  "streams": [
    {
      "labels": {
        "a": 123
      },
      "entries": [
        {
          "ts": "2019-12-02T11:16:12.000000Z",
          "line": "{\"OriginStatus\":100}"
        }
      ]
    }
  ]
}

# api call
curl -XPOST -u loki:PassWord  -H "Content-Type: application/json" --data-binary "@./test.json"  https://loki.example.com/loki/api/v1/push
parse error at line 1, col 2: syntax error: unexpected }, expecting IDENTIFIER

I also tried messing around with the test.json, giving different line and labels (escaping) but still the same error.

This is a shorter json, the actual json, which is causing the error originates from the fluentd pluign.

Expected behavior
I expected the data to be stored in loki -> successful API call

Environment:

• Infrastructure: docker, debian, baremetal
• Deployment tool: rancher, docker-compose

Loki logs just contain something like this:

today at 1:06 PM  level=info ts=2019-12-02T12:06:46.528852361Z caller=table_manager.go:363 msg="creating table" table=index_2555
today at 1:06 PM  level=info ts=2019-12-02T12:06:46.528931231Z caller=table_manager.go:363 msg="creating table" table=index_2559
today at 1:06 PM  level=info ts=2019-12-02T12:06:46.529055099Z caller=table_manager.go:363 msg="creating table" table=index_2585
today at 1:06 PM  level=info ts=2019-12-02T12:06:46.529134623Z caller=table_manager.go:363 msg="creating table" table=index_2589
today at 1:06 PM  level=info ts=2019-12-02T12:06:46.529261024Z caller=table_manager.go:363 msg="creating table" table=index_2523
today at 1:06 PM  level=info ts=2019-12-02T12:06:46.529339896Z caller=table_manager.go:363 msg="creating table" table=index_2530
today at 1:06 PM  level=info ts=2019-12-02T12:06:46.529557986Z caller=table_manager.go:409 msg="provisioned throughput on table, skipping" table=index_2604 read=0 write=0

The actual log error:

today at 1:07 PM  2019-12-02 12:07:50 +0000 [warn]: #0 {"streams":[{"labels":"{}","entries":[{"ts":"2019-12-02T12:07:39.000000Z","line":"{\"BackendName\":\"backend-loki-fluetd\",\"ClientHost\":\"10.42.53.79\",\"Duration\":1822,\"FrontendName\":\"Host-loki-example-net\",\"OriginContentSize\":79,\"OriginDuration\":1738717,\"OriginStatus\":400,\"Overhead\":83599,\"RequestAddr\":\"loki.example.net\",\"RequestContentSize\":3495,\"RequestCount\":2453697,\"RequestHost\":\"loki.example.net\",\"RequestLine\":\"POST /loki/api/v1/push HTTP/1.1\",\"RetryAttempts\":0,\"StartLocal\":\"2019-12-02T12:07:39.064023992Z\",\"downstream_Content-Length\":\"79\",\"downstream_Content-Type\":\"text/plain; charset=utf-8\",\"downstream_Date\":\"Mon, 02 Dec 2019 12:07:39 GMT\",\"downstream_X-Content-Type-Options\":\"nosniff\",\"level\":\"info\",\"msg\":\"\",\"origin_Content-Length\":\"79\",\"origin_Content-Type\":\"text/plain; charset=utf-8\",\"origin_Date\":\"Mon, 02 Dec 2019 12:07:39 GMT\",\"origin_X-Content-Type-Options\":\"nosniff\",\"request_Accept\":\"*/*\",\"request_Accept-Encoding\":\"gzip;q=1.0,deflate;q=0.6,identity;q=0.3\",\"request_Authorization\":\"Basic XXXXXXXXXXXXXXXXXX\",\"request_Content-Length\":\"3495\",\"request_Content-Type\":\"application/json\",\"request_User-Agent\":\"Ruby\"}"},{"ts":"2019-12-02T12:07:39.000000Z","line":"{\"BackendName\":\"backend-app-api-app-app-api-app-servicewithauth\",\"ClientHost\":\"82.119.96.82\",\"Duration\":2697,\"FrontendName\":\"app-api-app-app-api-app-servicewithauth\",\"OriginContentSize\":40,\"OriginDuration\":2586404,\"OriginStatus\":400,\"Overhead\":111158,\"RequestAddr\":\"app.example.net\",\"RequestContentSize\":0,\"RequestCount\":2453698,\"RequestHost\":\"app.example.net\",\"RequestLine\":\"GET /socket.io/?__sails_io_sdk_version=0.14.0&EIO=3&transport=polling HTTP/2.0\",\"RetryAttempts\":0,\"StartLocal\":\"2019-12-02T12:07:39.47041769Z\",\"downstream_Access-Control-Allow-Origin\":\"*\",\"downstream_Content-Type\":\"application/json\",\"downstream_Date\":\"Mon, 02 Dec 2019 12:07:39 GMT\",\"level\":\"info\",\"msg\":\"\",\"origin_Access-Control-Allow-Origin\":\"*\",\"origin_Content-Type\":\"application/json\",\"origin_Date\":\"Mon, 02 Dec 2019 12:07:39 GMT\",\"request_Accept\":\"*/*\",\"request_Accept-Encoding\":\"gzip\",\"request_Authorization\":\"Basic XXXXXXXXXXXXXXXXXX\",\"request_User-Agent\":\"okhttp/4.2.2\"}"},{"ts":"2019-12-02T12:07:45.000000Z","line":"{\"BackendName\":\"backend-app-api-app-app-api-app-servicewithauth\",\"ClientHost\":\"82.119.96.82\",\"Duration\":2375,\"FrontendName\":\"app-api-app-app-api-app-servicewithauth\",\"OriginContentSize\":40,\"OriginDuration\":2272545,\"OriginStatus\":400,\"Overhead\":102813,\"RequestAddr\":\"app.example.net\",\"RequestContentSize\":0,\"RequestCount\":2453699,\"RequestHost\":\"app.example.net\",\"RequestLine\":\"GET /socket.io/?__sails_io_sdk_version=0.14.0&EIO=3&transport=polling HTTP/2.0\",\"RetryAttempts\":0,\"StartLocal\":\"2019-12-02T12:07:45.234770579Z\",\"downstream_Access-Control-Allow-Origin\":\"*\",\"downstream_Content-Type\":\"application/json\",\"downstream_Date\":\"Mon, 02 Dec 2019 12:07:45 GMT\",\"level\":\"info\",\"msg\":\"\",\"origin_Access-Control-Allow-Origin\":\"*\",\"origin_Content-Type\":\"application/json\",\"origin_Date\":\"Mon, 02 Dec 2019 12:07:45 GMT\",\"request_Accept\":\"*/*\",\"request_Accept-Encoding\":\"gzip\",\"request_Authorization\":\"Basic XXXXXXXXXXXXXXXXXX\",\"request_User-Agent\":\"okhttp/4.2.2\"}"}]}]}
today at 1:08 PM  2019-12-02 12:08:01 +0000 [warn]: #0 failed to POST https://loki.example.net/loki/api/v1/push (400 Bad Request parse error at line 1, col 2: syntax error: unexpected }, expecting IDENTIFIER

[cyriltovena]

yes ! I see the issue, on it.

[omerlh]

I'm having the same error, when using 1.2.4 with the fix:

gem install fluent-plugin-grafana-loki --version 1.2.4

This is the error:

fluentd_1  | 2019-12-14 20:12:50.850269600 +0000 logs: {"labels":{"id":"84d27a55-41ab-4f15-8415-59e5e29b7966","version":"0.13.0"},"decision_id":"7699e298-9e97-49d0-b333-996efe1ba5b3","path":"opa/demo/c/allow","input":{"name":"joe"},"result":true,"requested_by":"127.0.0.1:56815","timestamp":"2019-12-14T20:12:50.230368Z","metrics":{"timer_rego_module_compile_ns":419,"timer_rego_module_parse_ns":392,"timer_rego_query_compile_ns":170740,"timer_rego_query_eval_ns":80596,"timer_rego_query_parse_ns":1722774,"timer_server_handler_ns":2527774}}
fluentd_1  | 2019-12-14 20:12:51 +0000 [warn]: #0 failed to POST http://loki:3100/loki/api/v1/push (400 Bad Request parse error at line 1, col 2: syntax error: unexpected }, expecting IDENTIFIER
fluentd_1  | )
fluentd_1  | 2019-12-14 20:12:51 +0000 [warn]: #0 {"streams":[{"stream":{},"values":[["1576354370850269600","{\"labels\":{\"id\":\"84d27a55-41ab-4f15-8415-59e5e29b7966\",\"version\":\"0.13.0\"},\"decision_id\":\"7699e298-9e97-49d0-b333-996efe1ba5b3\",\"path\":\"opa/demo/c/allow\",\"input\":{\"name\":\"joe\"},\"result\":true,\"requested_by\":\"127.0.0.1:56815\",\"timestamp\":\"2019-12-14T20:12:50.230368Z\",\"metrics\":{\"timer_rego_module_compile_ns\":419,\"timer_rego_module_parse_ns\":392,\"timer_rego_query_compile_ns\":170740,\"timer_rego_query_eval_ns\":80596,\"timer_rego_query_parse_ns\":1722774,\"timer_server_handler_ns\":2527774}}"]]}]}

This is. my config:

<source>
  @type http
  port 9880
  bind 0.0.0.0
  body_size_limit 32m
  keepalive_timeout 10s
</source>

<match logs>
  @type copy 
  <store>
    @type stdout
  </store>
  <store> 
    @type loki
    url "http://loki:3100"
    username "user"
    password "pass"
    flush_interval 1s
    line_format json
    flush_at_shutdown true
    buffer_chunk_limit 1m
  </store>
</match>

[dsbrng25b]

@omerlh I struggeld with the same problem and the error message does not really help. The problem is that you don't have any label in your push request ("stream":{}). You have to add lables and then this error should disappear. E.g. with:

...
<store>
  @type loki
  ...
  extra_labels {"env": "dev"}
  ...
</store>
...

[lianliange85]

I also have the same error, when using fluent-plugin-grafana-loki (1.2.11). And i have labels with push request.

[jgehrcke]

@omerlh @dsbrng25b @lianliange85 see https://github.com/grafana/loki/issues/1910