search

grafana / loki

Like Prometheus, but for logs.
https://grafana.com/loki
GNU Affero General Public License v3.0
24.09k stars 3.47k forks source link

The time promtail received file watcher event doesn't match the time that the log file was created. #7872

Open nutslove opened 1 year ago

nutslove commented 1 year ago

Describe the bug The time that promtail catches log files to send to Loki doesn't match the time that the log files was created. Promtail has been up without restart for about a month. What can be a cause for this? image

Expected behavior Logs are captured and sent by promtail to Loki when the logs were created.

Environment: ■os Red Hat Enterprise Linux 7.8

■promtail version 2.6.0

■how installed As a systemd.service

[root@AIPCCXAESAIHUB01 ~]# systemctl status promtail
● promtail.service - Promtail
   Loaded: loaded (/etc/systemd/system/promtail.service; enabled; vendor preset: disabled)
   Active: active (running) since Thu 2022-10-27 11:58:32 JST; 1 months 10 days ago
     Docs: https://grafana.com/docs/loki/latest/clients/promtail/
 Main PID: 23223 (promtail-linux-)
   CGroup: /system.slice/promtail.service
           mq23223 /usr/local/bin/promtail-linux-amd64 -config.file /opt/promtail/promtail-config.yaml

Screenshots, Promtail config, or terminal output ■promtail log related ※I attached the whole log file just in case ※Target log file（YYYY-MM-DD is the date that the log file was created） 　・/opt/AIHUB/log/error.log.web_waiting.2022-12-02 　・/opt/AIHUB/log/error.log.line_waiting.2022-11-25 　・/opt/AIHUB/log/error.log.2022-11-26 　・/opt/AIHUB/log/error.log.myau_waiting.2022-11-25 ※There are more logs that the same thing is happening.

Dec 06 22:01:20 AIPCCXAESAIHUB01 promtail-linux-amd64[23223]: level=info ts=2022-12-06T13:01:20.012758678Z caller=filetargetmanager.go:179 msg="received file watcher event" name=/opt/AIHUB/log/error.log.myau_waiting.2022-11-25 op=CREATE Dec 06 22:01:20 AIPCCXAESAIHUB01 promtail-linux-amd64[23223]: ts=2022-12-06T13:01:20.012979767Z caller=log.go:168 level=info msg="Seeked /opt/AIHUB/log/error.log.myau_waiting.2022-11-25 - &{Offset:0 Whence:0}" Dec 06 22:01:20 AIPCCXAESAIHUB01 promtail-linux-amd64[23223]: level=info ts=2022-12-06T13:01:20.013021311Z caller=tailer.go:143 component=tailer msg="tail routine: started" path=/opt/AIHUB/log/error.log.myau_waiting.2022-11-25 Dec 06 22:01:20 AIPCCXAESAIHUB01 promtail-linux-amd64[23223]: level=info ts=2022-12-06T13:01:20.01381797Z caller=filetargetmanager.go:179 msg="received file watcher event" name=/opt/AIHUB/log/error.log.myau_waiting op=CREATE Dec 06 22:01:20 AIPCCXAESAIHUB01 promtail-linux-amd64[23223]: level=info ts=2022-12-06T13:01:20.018893248Z caller=filetargetmanager.go:179 msg="received file watcher event" name=/opt/AIHUB/log/error.log.2022-11-26 op=CREATE Dec 06 22:01:20 AIPCCXAESAIHUB01 promtail-linux-amd64[23223]: ts=2022-12-06T13:01:20.019068349Z caller=log.go:168 level=info msg="Seeked /opt/AIHUB/log/error.log.2022-11-26 - &{Offset:0 Whence:0}" Dec 06 22:01:20 AIPCCXAESAIHUB01 promtail-linux-amd64[23223]: level=info ts=2022-12-06T13:01:20.019105566Z caller=tailer.go:143 component=tailer msg="tail routine: started" path=/opt/AIHUB/log/error.log.2022-11-26 Dec 06 22:01:20 AIPCCXAESAIHUB01 promtail-linux-amd64[23223]: level=info ts=2022-12-06T13:01:20.021773773Z caller=filetargetmanager.go:179 msg="received file watcher event" name=/opt/AIHUB/log/error.log op=CREATE Dec 06 22:01:20 AIPCCXAESAIHUB01 promtail-linux-amd64[23223]: level=info ts=2022-12-06T13:01:20.027419057Z caller=filetargetmanager.go:179 msg="received file watcher event" name=/opt/AIHUB/log/error.log.line_waiting.2022-11-25 op=CREATE Dec 06 22:01:20 AIPCCXAESAIHUB01 promtail-linux-amd64[23223]: level=info ts=2022-12-06T13:01:20.027731895Z caller=filetargetmanager.go:179 msg="received file watcher event" name=/opt/AIHUB/log/error.log.line_waiting op=CREATE Dec 06 22:01:20 AIPCCXAESAIHUB01 promtail-linux-amd64[23223]: level=info ts=2022-12-06T13:01:20.027796485Z caller=tailer.go:143 component=tailer msg="tail routine: started" path=/opt/AIHUB/log/error.log.line_waiting.2022-11-25 Dec 06 22:01:20 AIPCCXAESAIHUB01 promtail-linux-amd64[23223]: ts=2022-12-06T13:01:20.027820159Z caller=log.go:168 level=info msg="Seeked /opt/AIHUB/log/error.log.line_waiting.2022-11-25 - &{Offset:0 Whence:0}" Dec 06 22:01:20 AIPCCXAESAIHUB01 promtail-linux-amd64[23223]: ts=2022-12-06T13:01:20.034096967Z caller=log.go:168 level=info msg="Re-opening moved/deleted file /opt/AIHUB/log/error.log ..." Dec 06 22:01:20 AIPCCXAESAIHUB01 promtail-linux-amd64[23223]: ts=2022-12-06T13:01:20.034155857Z caller=log.go:168 level=info msg="Successfully reopened /opt/AIHUB/log/error.log" Dec 06 22:01:20 AIPCCXAESAIHUB01 promtail-linux-amd64[23223]: level=info ts=2022-12-06T13:01:20.073512192Z caller=filetargetmanager.go:179 msg="received file watcher event" name=/opt/AIHUB/log/error.log.web_waiting.2022-12-02 op=CREATE Dec 06 22:01:20 AIPCCXAESAIHUB01 promtail-linux-amd64[23223]: level=info ts=2022-12-06T13:01:20.073662137Z caller=filetargetmanager.go:179 msg="received file watcher event" name=/opt/AIHUB/log/error.log.lineuq_waiting.2022-12-03 op=CREATE Dec 06 22:01:20 AIPCCXAESAIHUB01 promtail-linux-amd64[23223]: ts=2022-12-06T13:01:20.073785743Z caller=log.go:168 level=info msg="Seeked /opt/AIHUB/log/error.log.web_waiting.2022-12-02 - &{Offset:0 Whence:0}" Dec 06 22:01:20 AIPCCXAESAIHUB01 promtail-linux-amd64[23223]: level=info ts=2022-12-06T13:01:20.073816387Z caller=tailer.go:143 component=tailer msg="tail routine: started" path=/opt/AIHUB/log/error.log.web_waiting.2022-12-02

■promtail config ※- job_name: application is where configured about target log.

server:
  http_listen_port: 9080
  grpc_listen_port: 0

positions:
  filename: /tmp/positions.yaml

clients:
  - url: http://*******.elb.ap-northeast-1.amazonaws.com/loki/api/v1/push
    external_labels:
      system: cschat-aih
      env: prd
      hostname: AIPCCXAESAIHUB01

limits_config:
[whole_promtail_log.txt](https://github.com/grafana/loki/files/10174974/whole_promtail_log.txt)

      readline_rate_enabled: true
      readline_rate: 1000
[log_file_timestamp, promtail-version, promtail-uptime.txt](https://github.com/grafana/loki/files/10174977/log_file_timestamp.promtail-version.promtail-uptime.txt)

      readline_burst: 1000
      readline_rate_drop: false

scrape_configs:
- job_name: os
  static_configs:
  - targets:
      - localhost
    labels:
      job: os_secure
      __path__: /var/log/secure
  - targets:
      - localhost
    labels:
      job: os_cron
      __path__: /var/log/cron
  - targets:
      - localhost
    labels:
      job: os_messages
      __path__: /var/log/messages
  pipeline_stages:
  - match:
      selector: '{job=~"os_secure|os_cron|os_messages"} !~ "(ERROR|Error|error|FAIL|Fail|fail|FATAL|fatal|ALERT|alert)"'
      action: drop
  - match:
      selector: '{job="os_messages"} |~ ".*error_handler.*"'
      action: drop

- job_name: td-agent
  static_configs:
  - targets:
      - localhost
    labels:
      job: td-agent_log
      __path__: /var/log/td-agent/td-agent.log

- job_name: ssm-agent
  static_configs:
  - targets:
      - localhost
    labels:
      job: ssm-agent_log
      __path__: /var/log/amazon/ssm/amazon-ssm-agent.log
  pipeline_stages:
  - multiline:
      firstline: '^\d{4}\-(0?[1-9]|1[012])\-(0?[1-9]|[12][0-9]|3[01])'
  - drop:
      expression: (?:INFO \[HealthCheck\])
  - drop:
      expression: (?:INFO \[MessagingDeliveryService\] \[Association\])
  - drop:
      expression: (?:INFO \[LongRunningPluginsManager\])

- job_name: application
  static_configs:
  - targets:
      - localhost
    labels:
      job: aihub
      __path__: /opt/AIHUB/log/error.log*
  pipeline_stages:
  - multiline:
      firstline: '^\['
  - drop:
      expression: 'NODE_APP_INSTANCE'
  - drop:
      expression: 'https://github.com/lorenwest/node-config/wiki/Strict-Mode'

- job_name: application-sdk
  static_configs:
  - targets:
      - localhost
    labels:
      job: aihub-mstbot-le-sdk-err
      __path__: /home/ec2-user/.pm2/logs/?????????-le-sdk-*-error.log
  pipeline_stages:
[log_file_timestamp, promtail-version, promtail-uptime.txt](https://github.com/grafana/loki/files/10175008/log_file_timestamp.promtail-version.promtail-uptime.txt)
[whole_promtail_log.txt](https://github.com/grafana/loki/files/10175009/whole_promtail_log.txt)

  - multiline:
      firstline: '\S'
  - drop:
      expression: 'NODE_APP_INSTANCE'
  - drop:
      expression: 'https://github.com/lorenwest/node-config/wiki/Strict-Mode'
  - replace:
      expression: "(TypeError)"
      replace: "(ERROR | TypeError)"

- job_name: application-sdk_2
  static_configs:
  - targets:
      - localhost
    labels:
      job: aihub-mstbot-err
      __path__: /home/ec2-user/.pm2/logs/?????????-error.log
  pipeline_stages:
  - multiline:
      firstline: '\S'
  - drop:
      expression: 'NODE_APP_INSTANCE'
  - drop:
      expression: 'https://github.com/lorenwest/node-config/wiki/Strict-Mode'
nutslove commented 1 year ago

log_file_timestamp, promtail-version, promtail-uptime.txt whole_promtail_log.txt