Can't overwrite timestamp through pipeline-rule

[flatrick (Patrik)]

Hi all!
I’ve found plenty of posts about this, but for whatever reason, I just can’t get it to work following the instructions I’ve found.

I chose to use Filebeats to send my IIS-logs to Graylog2, and I’m using an extractor to pull the message apart into all of it’s separate fields, and this works just fine.
I also have a pipeline that goes through the field log_timestamp to change it into a correct timestamp (including timezone) and then save it with my local timezone, and this works just perfectly.

But the part of my pipeline that is supposed to modify timestamp to use the timestamp from the log, not from time of harvest/ingest/shipping, just doesn’t seem able to overwrite the field timestamp.
I’ve had it store the value in a third field just to see the output, and it looks correct (same format as the current timestamp) so the format should be ok. I haven’t found any errors implying a misconfiguration so I can’t figure out why it isn’t working.
I must be missing something since other people got it working, I hope someone can help out!
The pipeline looks like this: https://github.com/flatrick/graylog2_iis#set-timestamps-to-timestamps-from-log-not-from-time-of-harvest

I’m currently documenting the steps I’ve taken in this setup on my github, if I’ve missed to write down something important for you to help me, let me know!

flatrick/graylog2_iis

[jan (Jan Doberstein)]

did you see any messages in your graylog server.log that might be related to that - or in your elasticsearch logfile that the format is not correct or anything that might be related to the setting of this field?

[flatrick (Patrik)]

I can’t see anything of interest under /var/log/graylog/ about this failed attempt.

I searched for the time of indexing in the whole folder and it’s subfolders using grep (grep “09:07:2” * -R) but all I got out of that was a [INFO]-message about update_mapping, but nothing more.

[flatrick (Patrik)]

I changed the rules a bit and added debug()-statements to better understand what’s going on, here is the new pipeline:

rule "correct timestamp for logs from IIS"
when
    contains(
            value: to_string($message.type), 
            search: "iis",
            ignore_case: true)
    AND has_field(field: "log_timestamp")
then
    let log_timestamp = $message.log_timestamp;
    let timestamp = $message.timestamp;
    debug(value: concat(
                    first: "timestamp before changing: ",
                    second: to_string(timestamp)));
	debug(value: concat(
                    first: "log_timestamp: ",
                    second: to_string(log_timestamp)));
					
	set_field("timestamp", format_date(
								value: to_date(log_timestamp),
								format: "yyyy-MM-dd'T'HH:mm:ss.SSSZ"));
	
	debug(value: concat(
                    first: "After changing: ",
	                second: format_date(
								value: to_date(timestamp),
								format: "yyyy-MM-dd'T'HH:mm:ss.SSSZ")));
end

and here is the results from the log (sorry for picture instead of regular text)

It looks to be an issue with the format-settings, but I can’t see why? Isn’t it supposed to be SSSZ at the end of the format_date()-format?
I’ve also tried forcing the Z at the end by writing the format as yyyy-MM-dd’T’HH:mm:ss.SSS’Z

[jan (Jan Doberstein)]

You make it to complex:

rule "correct timestamp for logs from IIS"
when
    contains(
            value: to_string($message.type), 
            search: "iis",
            ignore_case: true)
    AND has_field(field: "log_timestamp")
then
    let log_timestamp = $message.log_timestamp;
    let timestamp = $message.timestamp;
   
    debug(value: concat(
                    first: "timestamp before changing: ",
                    second: to_string(timestamp)));
	debug(value: concat(
                    first: "log_timestamp: ",
                    second: to_string(log_timestamp)));
	
    let time = parse_date( value: to_string(log_timestamp),
                           pattern: "yyyy-MM-dd HH:mm:ss Z");
                           
    set_field("timestamp", time)

	debug(value: concat(
                    first: "After changing: ",
	                second: to_string(timestamp)));
end

just parse the date you want to have and then set the parsed as time - graylog/elasticsearch will take care that the time is formatted in the right way.

The above should work, not sure about the debug statements.

[flatrick (Patrik)]

@jan Hm, is it because I was so deadset on setting the specific format while passing the value to set_field that caused it?
I thought format_date returned a datetime object so I’m still curious as to why it failed (I prefer understanding why A or B is correct instead of just knowing which answer is correct )

Thank you so far for helping me getting this to work!

Interesting anecdote: the debug() actually doesn’t show the new value when being run again, I still see the first timestamp, even though the value clearly has been changed when I look in the stream

[jan (Jan Doberstein)]

the format_date just gives you the option to handover a date object and write it in a given format ( http://docs.graylog.org/en/2.4/pages/pipelines/functions.html#format-date ) while the parse_date actually reads the date and create a time object in the internal format of Graylog ( http://docs.graylog.org/en/2.4/pages/pipelines/functions.html#parse-date ).

The debug would work if you use to_string(time) as statement and not the first defined variable. It should also work if you would read the actuall field value and not use the variable that is initial written with the old value (as variables are not updated automatically. The second option wout be use to_string($message.timestamp) as second value in the last debug.

Jan