Querying Loki using a defined timestamp in promtail returns zero rows

When querying a log file in Loki that was ingested by promtail with a defined timestamp, the resulting output is zero rows. I’m not sure why.

Promtail config:

scrape_configs:
- job_name: testjob
  pipeline_stages:
  - regex:
      expression: '^(?s)(?P<time>\S+?)\s+(?P<ip>\S+?)\s+(?P<content>.*?)+$'
  - timestamp:
      source: time
      format: Unix
  static_configs:
  - targets:
      - localhost
    labels:
      job: testjob
      __path__: /path/to/testlog

Log file contents:

user@servername: promtail$ cat /path/to/testlog
1623180833.246  192.168.0.1 POST    TLSv1.2 /domain.com/java/somepath/anotherpath/en/somemodule/someservice.asmx   200     75201   76955   75201   -       5568    "-"     "Java/1.8.0_281"        "-"     "domain.com"       "text/xml"      0       153     69      "306dd6ab"      -       "miss"  "origin"        1       1       192.168.0.1

Promtail configuration test showing the timestamp being correctly parsed:

user@servername: promtail$ cat /path/to/testlog | ./promtail-linux-amd64 -stdin -dry-run -config.file config.yml -log.level=error
Clients configured:
----------------------
url: http://localhost:3100/loki/api/v1/push
batchwait: 1s
batchsize: 1048576
backoff_config:
  min_period: 500ms
  max_period: 5m0s
  max_retries: 10
timeout: 10s
tenant_id: ""

2021-06-08T19:33:53	{__path__="/path/to/testlog", job="testjob"}	1623180833.246  192.168.0.1 POST    TLSv1.2 TLSv1.2 /domain.com/java/somepath/anotherpath/en/somemodule/someservice.asmx   200     75201   76955   75201   -       5568    "-"     "Java/1.8.0_281"        "-"     "domain.com"       "text/xml"      0       153     69      "306dd6ab"      -       "miss"  "origin"        1       1       192.168.0.1

Promtail startup with no errors:

user@servername: promtail$ ./promtail-linux-amd64 -config.file config.yml -log.level=debug
level=debug ts=2021-06-23T15:34:36.644561191Z caller=manager.go:195 component=discovery msg="Starting provider" provider=static/0 subs=[testjob]
level=debug ts=2021-06-23T15:34:36.645045056Z caller=manager.go:213 component=discovery msg="Discoverer channel closed" provider=static/0
level=info ts=2021-06-23T15:34:36.645210572Z caller=server.go:229 http=[::]:9080 grpc=[::]:43554 msg="server listening on addresses"
level=info ts=2021-06-23T15:34:36.645733248Z caller=main.go:112 msg="Starting Promtail" version="(version=2.2.1, branch=HEAD, revision=babea82e)"
level=debug ts=2021-06-23T15:34:41.645037307Z caller=filetargetmanager.go:200 msg="new target" labels="{__address__=\"localhost\"}"
level=info ts=2021-06-23T15:34:41.645211904Z caller=filetargetmanager.go:254 msg="Adding target" key="{job=\"testjob\"}"
level=debug ts=2021-06-23T15:34:41.655928548Z caller=filetarget.go:249 msg="watching new directory" directory=/path/to
level=debug ts=2021-06-23T15:34:41.656031336Z caller=filetarget.go:283 msg="tailing new file" filename=/path/to/testlog
level=info ts=2021-06-23T15:34:41.657476119Z caller=tailer.go:125 component=tailer msg="tail routine: started" path=/path/to/testlog
ts=2021-06-23T15:34:41.657633502Z caller=log.go:124 level=info msg="Seeked /path/to/testlog - &{Offset:0 Whence:0}"

Simple Loki query below, with the time picker set to ‘Last 90 days’:

{job="testjob"}

Loki log contents showing zero rows returned:

level=info ts=2021-06-23T15:34:57.351098343Z caller=metrics.go:91 org_id=fake traceID=56a382fbe2ffe4e6 latency=fast query="{job=\"testjob\"}" query_type=limited range_type=range length=720h0m1s step=20m0s duration=2.20676ms status=200 limit=1000 returned_lines=0 throughput=0B total_bytes=0B

When commenting out the following 3 lines in the promtail config, the log line shows up in Loki using the same query, but with an incorrect (ingested time) timestamp. What am I doing wrong?

  - timestamp:
      source: time
      format: Unix

Hi @emilechaiban
My quick thought is it has something to do with your time picker set Last 90 days.

My theory is your logql query is querying for wrong time range (may be its too short and out of range of your log timestamp?). I’m saying this because, you said log lines appears if you remove timestamp section. I think that’s because when you remove that, promtail ingest the current timestamp and your logql query can find it.

Just to confirm, can you try logcli query -from=xx and -to=xx. And see if you are getting those logs?

Thanks for the response. I tried ‘90 days ago’ and a few other combinations to try and catch the log line timestamp of 2021-06-08 without any luck.

Below is the logcli output when trying a couple of time ranges:

user@server: loki$ ./logcli-linux-amd64 query '{job="testjob"}' --from="2021-01-01T00:00:00Z" --to="2021-06-27T00:00:00Z"
http://localhost:3100/loki/api/v1/query_range?direction=BACKWARD&end=1624752000000000000&limit=30&query=%7Bjob%3D%22testjob%22%7D&start=1609459200000000000

user@server: loki$ ./logcli-linux-amd64 query '{job="testjob"}' --from="2021-06-01T00:00:00Z" --to="2021-06-09T00:00:00Z"
http://localhost:3100/loki/api/v1/query_range?direction=BACKWARD&end=1623196800000000000&limit=30&query=%7Bjob%3D%22testjob%22%7D&start=1622505600000000000

The issue appears to have been with my loki config file. Reverting to a vanilla config seems to have resolved the issue.