When I am running:
cat test.log | promtail-v2.3.0 -config.file /etc/promtail.yml -stdin -dry-run -inspect
with a config containing:
pipeline_stages:
- regex:
expression: '^(?P<ip>\S+) (?P<idp>\S+) (?P<id>\S+) \[(?P<time>[^\]]+)\] "(?P<method>\S+) (?P<path>\S+) (?P<http>[^\"]+)" (?P<status>\S+) (?P<size>\S+) (?P<referrer>(-|"[^\"]*")) (?P<agent>(-|"[^\"]*"))$'
- timestamp:
source: time
format: 02/Jan/2006:15:04:05 -0700
- pack:
labels: [ip, idp, id, time, method, path, http, status, size, referrer, agent]
with test.log
containing Apache-like log lines:
10.8.2.6 - undefined [16/Nov/2022:13:43:46 +0100] "GET /api/v1/domain/status HTTP/1.0" 200 530 "-" "okhttp/4.9.3"
10.8.2.6 - undefined [16/Nov/2022:13:43:49 +0100] "GET /api/v1/client/ping HTTP/1.0" 401 6 "-" "okhttp/4.9.3"
I can see the following output:
[inspect: regex stage]:
{stages.Entry}.Extracted["agent"]:
+: "okhttp/4.9.3"
{stages.Entry}.Extracted["http"]:
+: HTTP/1.0
{stages.Entry}.Extracted["id"]:
+: undefined
{stages.Entry}.Extracted["idp"]:
+: -
{stages.Entry}.Extracted["ip"]:
+: 10.8.2.6
{stages.Entry}.Extracted["method"]:
+: GET
{stages.Entry}.Extracted["path"]:
+: /api/v1/domain/status
{stages.Entry}.Extracted["referrer"]:
+: "-"
{stages.Entry}.Extracted["size"]:
+: 530
{stages.Entry}.Extracted["status"]:
+: 200
{stages.Entry}.Extracted["time"]:
+: 16/Nov/2022:13:43:46 +0100
[inspect: regex stage]:
{stages.Entry}.Extracted["agent"]:
+: "okhttp/4.9.3"
{stages.Entry}.Extracted["http"]:
+: HTTP/1.0
{stages.Entry}.Extracted["id"]:
+: undefined
{stages.Entry}.Extracted["idp"]:
+: -
{stages.Entry}.Extracted["ip"]:
+: 10.8.2.6
{stages.Entry}.Extracted["method"]:
+: GET
{stages.Entry}.Extracted["path"]:
+: /api/v1/client/ping
{stages.Entry}.Extracted["referrer"]:
+: "-"
{stages.Entry}.Extracted["size"]:
+: 6
{stages.Entry}.Extracted["status"]:
+: 401
{stages.Entry}.Extracted["time"]:
+: 16/Nov/2022:13:43:49 +0100
[inspect: timestamp stage]:
{stages.Entry}.Entry.Entry.Timestamp:
-: 2022-11-16 14:54:16.973451904 +0100 CET
+: 2022-11-16 13:43:46 +0100 CET
[inspect: timestamp stage]:
{stages.Entry}.Entry.Entry.Timestamp:
-: 2022-11-16 14:54:16.973453337 +0100 CET
+: 2022-11-16 13:43:49 +0100 CET
2022-11-16T14:54:16.975778393+0100 {...} {"agent":"\"okhttp/4.9.3\"","http":"HTTP/1.0","id":"undefined","idp":"-","ip":"10.8.2.6","method":"GET","path":"/api/v1/domain/status","referrer":"\"-\"","size":"530","status":"200","time":"16/Nov/2022:13:43:46 +0100","_entry":"10.8.2.6 - undefined [16/Nov/2022:13:43:46 +0100] \"GET /api/v1/domain/status HTTP/1.0\" 200 530 \"-\" \"okhttp/4.9.3\""}
2022-11-16T14:54:16.975791355+0100 {...} {"agent":"\"okhttp/4.9.3\"","http":"HTTP/1.0","id":"undefined","idp":"-","ip":"10.8.2.6","method":"GET","path":"/api/v1/client/ping","referrer":"\"-\"","size":"6","status":"401","time":"16/Nov/2022:13:43:49 +0100","_entry":"10.8.2.6 - undefined [16/Nov/2022:13:43:49 +0100] \"GET /api/v1/client/ping HTTP/1.0\" 401 6 \"-\" \"okhttp/4.9.3\""}
i.e. the Timestamp field seems to be updated correctly. The ts label is not shown in the final log lines (and I have removed some private ones that are), but it should have been correct.
However, when these lines are pushed to Loki they show up with a different ts field.
How can I continue debugging this?
PS: I have also tried setting a "location" label, with no clear purpose, as suggested at another question here, with no effect.