Grafana wont load log lines after adding timestamp in promtail config

inftom1 · September 26, 2022, 1:07am

What Grafana version and what operating system are you using?
grafana/loki:2.6.1
grafana/promtail:2.6.1
grafana/grafana:9.1.6-ubuntu
What are you trying to achieve?
My log lines currently have time stamps in the following format 20/Sep/2022:09:52:57 +0000. Currently the timestamps on grafana are being read at scrape (default). I want them to populate with the actual time.
How are you trying to achieve it?
I am adding a timestamp stage with a custom format.
What happened?
Adding the timestamp stage causes logs to stop appearing when queried.
What did you expect to happen?
Logs would query all the same but with the correct timestamp.
Can you copy/paste the configuration(s) that you are having problems with?
promtail config

server:
  http_listen_port: 9080
  grpc_listen_port: 0
  log_level: debug

positions:
  filename: /tmp/positions.yaml

clients:
  - url: http://loki:3100/loki/api/v1/push

scrape_configs:

# local machine logs

- job_name: local
  static_configs:
  - targets:
      - localhost
    labels:
      job: varlogs
      __path__: /var/log/*.log
  pipeline_stages:
  - match:
      selector: '{job="varlogs"}'
      stages:
      - json:
          expressions:
            time: time_local
      - timestamp:
          source: time
          format: '02/Jan/2006:15:04:05 -0700'
          fallback_formats: ['02/Jan/2006:15:04:05 -0700', 'RFC3339']
          action_on_failure: skip

Loki Config

auth_enabled: false

server:
  http_listen_port: 3100
  grpc_listen_port: 9096
  log_level: debug

common:
  path_prefix: /tmp/loki
  storage:
    filesystem:
      chunks_directory: /tmp/loki/chunks
      rules_directory: /tmp/loki/rules
  replication_factor: 1
  ring:
    instance_addr: 127.0.0.1
    kvstore:
      store: inmemory

schema_config:
  configs:
    - from: 2020-10-24
      store: boltdb-shipper
      object_store: filesystem
      schema: v11
      index:
        prefix: index_
        period: 24h

ruler:
  alertmanager_url: http://localhost:9093

limits_config:
  #ingestion_rate_mb: 10
  #ingestion_burst_size_mb: 50
  reject_old_samples: false
  #per_stream_rate_limit: 10MB
  #per_stream_rate_limit_burst: 50MB

Promtail logs

level=debug ts=2022-09-26T01:38:19.527634648Z caller=manager.go:265 component=discovery msg="Starting provider" provider=static/0 subs=map[local:{}]
level=debug ts=2022-09-26T01:38:19.527901298Z caller=manager.go:299 component=discovery msg="Discoverer channel closed" provider=static/0
level=info ts=2022-09-26T01:38:19.529054758Z caller=server.go:288 http=[::]:9080 grpc=[::]:39077 msg="server listening on addresses"
level=info ts=2022-09-26T01:38:19.52931686Z caller=main.go:121 msg="Starting Promtail" version="(version=2.6.1, branch=HEAD, revision=6bd05c9a4)"
level=debug ts=2022-09-26T01:38:24.528096622Z caller=filetargetmanager.go:278 msg="new target" labels="{__address__=\"localhost\"}"
level=info ts=2022-09-26T01:38:24.528193572Z caller=filetargetmanager.go:338 msg="Adding target" key="/var/log/*.log:{job=\"varlogs\"}"
level=info ts=2022-09-26T01:38:24.534297631Z caller=filetarget.go:278 msg="watching new directory" directory=/var/log
level=debug ts=2022-09-26T01:38:24.534345771Z caller=filetarget.go:318 msg="tailing new file" filename=/var/log/test.log
ts=2022-09-26T01:38:24.535117494Z caller=log.go:168 level=info msg="Seeked /var/log/test.log - &{Offset:0 Whence:0}"
level=info ts=2022-09-26T01:38:24.53510711Z caller=tailer.go:143 component=tailer msg="tail routine: started" path=/var/log/test.log
level=debug ts=2022-09-26T01:38:24.536870553Z caller=json.go:182 component=file_pipeline component=stage type=json msg="extracted data debug in json stage" extracteddata="map[filename:/var/log/test.log job:varlogs timestamp:17/Sep/2022:09:52:57 +0000]"
level=debug ts=2022-09-26T01:38:24.537055305Z caller=json.go:182 component=file_pipeline component=stage type=json msg="extracted data debug in json stage" extracteddata="map[filename:/var/log/test.log job:varlogs timestamp:17/Sep/2022:09:52:58 +0000]"
level=debug ts=2022-09-26T01:38:24.537138191Z caller=json.go:182 component=file_pipeline component=stage type=json msg="extracted data debug in json stage" extracteddata="map[filename:/var/log/test.log job:varlogs timestamp:17/Sep/2022:09:52:58 +0000]"
level=debug ts=2022-09-26T01:38:24.537679344Z caller=json.go:182 component=file_pipeline component=stage type=json msg="extracted data debug in json stage" extracteddata="map[filename:/var/log/test.log job:varlogs timestamp:17/Sep/2022:09:52:58 +0000]"

Sample Log Line

{"time_local":"17/Sep/2022:09:52:57 +0000","request":"https://test.xyz/v1/client/relay","method":"POST","protocol":"HTTP/1.1","status":"200"}

Did you receive any errors in the Grafana UI or in related logs? If so, please tell us exactly what they were.
I did not spot any errors.
Did you follow any online instructions? If so, what is the URL?
timestamp | Grafana Loki documentation

yosiasz · September 26, 2022, 3:22am

Could you specify fhe exact timestamp format, the exact RFC?

github.com

grafana/loki/blob/main/docs/sources/clients/promtail/stages/timestamp.md

---
title: timestamp
---
# `timestamp` stage

The `timestamp` stage is an action stage that can change the timestamp of a log
line before it is sent to Loki. When a `timestamp` stage is not present, the
timestamp of a log line defaults to the time when the log entry is scraped.

## Schema

```yaml
timestamp:
  # Name from extracted data to use for the timestamp.
  source: <string>

  # Determines how to parse the time string. Can use
  # pre-defined formats by name: [ANSIC UnixDate RubyDate RFC822
  # RFC822Z RFC850 RFC1123 RFC1123Z RFC3339 RFC3339Nano Unix
  # UnixMs UnixUs UnixNs].

This file has been truncated. show original

inftom1 · September 26, 2022, 4:25pm

I’m using a custom timestamp format
02/Jan/2006:15:04:05 -0700

I tested here Go Playground - The Go Programming Language using this code

/ Golang program to illustrate the usage of
// time.Parse() function

// Including main package
package main

// Importing fmt and time
import (
	"fmt"
	"time"
)

// Calling main
func main() {

	// Declaring layout constant
	const layout = "02/Jan/2006:15:04:05 -0700"

	// Calling Parse() method with its parameters
	tm, _ := time.Parse(layout, "20/Sep/2022:09:52:57 +0000")

	// Returns output
	fmt.Println(tm)
}

inftom1 · September 27, 2022, 9:07am

heres something interesting when running this command, that specifies the config file, it actually shows the converted timestamp in blue.
cat /var/log/test.log | promtail --stdin -log.level=debug --dry-run --config.file=/etc/promtail/promtail-config.yml --client.url http://127.0.0.1:3100/loki/api/v1/push

this is what my docker compose is set to run. so not sure why its not populating the same inside of grafana/loki frontend.

armesh49 · November 18, 2022, 6:23am

I found that Grafana Loki has a huge delay on displaying logs with custom timestamp if the custom timestamp is older than 2 hours from “now”.

So just wait like 3 hours then check again in the UI. If it didn’t work you can restart Loki and wait another 3 hours.

I am running Grafana Enterprise, Loki & Promtail in Ubuntu 18 Virtual Machine.

Topic		Replies	Views
Promtail Config - Unable to overwrite the log line scrapped timestamp with the Log generated timestamp Dashboards loki , config-help , timestamp , promtail	1	434	July 28, 2023
Timestamp issue in Grafana logs Grafana Loki loki	4	761	November 29, 2023
SOLVED: Trouble parsing timestamp in promtail Grafana Loki loki	1	3028	May 19, 2020
Promtail scrapes the right logs, but loki doesn't show them Grafana Loki loki , promtail	7	29	November 15, 2024
Promtail Scrape config - Timestamp issue Grafana Loki loki , timestamp	2	972	May 7, 2024

Grafana wont load log lines after adding timestamp in promtail config

Related topics