parse_grok failing on proper ISO8601 timestamp

[Djeezus]

'lo all,

I'm trying to parse a timestamp in a field at beginning of line, as such:
SOURCE is a kafka event:

{
  "@timestamp": "2023-01-04T14:22:22.22Z",
  "message": "2023-01-04 14:03:30.745 blah blah blah blah",
  "logtype": "flatlog"
 }

And my transform looks like this:

  transforms:
    parser:
      type: remap
      inputs: [kafka]
      source: |-
        if .logtype == "flatlog" {
          parse_grok!(.message, "^%{TIMESTAMP_ISO8601:@timestamp} %{GREEDYDATA:logline}")
          .message = del(.logline)
        }
        .fingerprint = md5(to_string(.) ?? .@timestamp)
        .timestamp = to_timestamp!(del(.@timestamp))

When this is processed by Vector, it gives following error:

...
2023-01-04T13:31:40.423554Z DEBUG transform{component_kind="transform" component_id=parser component_type=remap component_name=parser}: vector::utilization: utilization=0.0000435
2093853987604
2023-01-04T13:31:40.423655Z ERROR transform{component_kind="transform" component_id=parser component_type=remap component_name=parser}: vector::internal_events::remap: Mapping failed with event. error="function call error for \"parse_grok\" at (29:108): unable to parse input with grok pattern" error_type="conversion_failed" stage="processing" internal_log_rate_limit=true
...

What am I missing here ? It seems to be a valid ISO8601 timestamp, as mentioned here

Also, is this efficient, or should I try doing it with VRL conditions ?

I had also tried using the VRL playground , but it didn't recognize the parse_grok function

error[E105]: call to undefined function
  ┌─ :2:11
  │
2 │           parse_grok!(.message, "^%{TIMESTAMP_ISO8601:@timestamp} %{GREEDYDATA:logline}")
  │           ^^^^^^^^^^
  │           │
  │           undefined function
  │           did you mean "parse_glog"?
  │
  = learn more about error code 105 at https://errors.vrl.dev/105
  = see language documentation at https://vrl.dev
  = try your code in the VRL REPL, learn more at https://vrl.dev/examples

grtz & thnx
Gert

[jszwedko]

Hi @Djeezus ,

It looks like the timestamp in your message, 2023-01-04 14:03:30.745, is not an ISO8601 timestamp which is why the pattern is not matching. You can parse it as a DATE and TIME though: %{DATE:date} %{TIME:time} %{GREEDYDATA:logline}.

The playground doesn't currently support parse_grok. We need to improve that error message until we do. You can use the vector vrl REPL for testing though.

[Djeezus]

'lo @jszwedko,

thank you for looking into this.

I tried it on grokdebugger.com : click to see timestamp sample
It works just fine there and it has exactly the same regex_pattern for TIMESTAMP_ISO8601 as specified in vector docs

TIMESTAMP_ISO8601 %{YEAR}-%{MONTHNUM}-%{MONTHDAY}[T ]%{HOUR}:?%{MINUTE}(?::?%{SECOND})?%{ISO8601_TIMEZONE}?

I'm rather fond of grokdebugger, and I'd just like to know what the difference is ...

grtz & thnx

[jszwedko]

Aha, you are right, my mistake. The issue actually appears to be with the @ in the field name. This works in vector vrl:

$ .message = "2023-01-04 14:03:30.745 blah blah blah blah"
"2023-01-04 14:03:30.745 blah blah blah blah"

$ parse_grok!(.message, "^%{TIMESTAMP_ISO8601:timestamp} %{GREEDYDATA:logline}")
{ "logline": "blah blah blah blah", "timestamp": "2023-01-04 14:03:30.745" }

grokdebugger.com also doesn't seem to like the @ sign. Maybe you could rename the field to @timestamp after parsing?

[Djeezus]

Hi Jesse,

indeed, the @ character was the issue in this case ... but now it seems there is a difference in "to_timestamp" and "parse_grok" regarding what a TIMESTAMP_ISO8601 actually should look like.
"parse_grok" seems to honor TIMESTAMP_ISO8601, but "to_timestamp" does not, or am I missing something here ?

In VRL tested:

$ . = { "@timestamp": "2023-01-10T05:05:05.55Z", "@metadata": { "beat": "filebeat", "type": "_doc", "version": "7.9.2" }, "host": { "name": "somehostname" }, "message": "2023-01-10 10:03:30.745 blah blah blah blah" }
{ "@metadata": { "beat": "filebeat", "type": "_doc", "version": "7.9.2" }, "@timestamp": "2023-01-10T05:05:05.55Z", "host": { "name": "somehostname" }, "message": "2023-01-10 10:03:30.745 blah blah blah blah" }

$ .flat = parse_grok!(.message, "^%{TIMESTAMP_ISO8601:datestamp} %{GREEDYDATA:logline}")
{ "datestamp": "2023-01-10 10:03:30.745", "logline": "blah blah blah blah" }

$ .timestamp = to_timestamp!(.flat.datestamp)
function call error for "to_timestamp" at (13:43): No matching timestamp format found for "2023-01-10 10:03:30.745"

$ .timestamp = to_timestamp!(.@timestamp)
t'2023-01-10T05:05:05.550Z'

I don't mind not bloating "to_timestamp" with too many formats, but it should at least agree with "parse_grok" when it comes to formatting, no ?

thnx & grtz

[jszwedko]

I see to_timestamp does actually parse a similar timestamp, just not when fractional seconds are included:

$ .timestamp = to_timestamp!("2023-01-10 10:03:30")
t'2023-01-10T15:03:30Z' 

Would you want to open a feature request to update that?