Add %{{TIME_NOW}} pattern for sprintf #16906

kaisecheng · 2025-01-16T19:30:58Z

Release notes

Add support of %{{TIME_NOW}} syntax to sprinf format to generate a new current timestamp

What does this PR do?

This commit added %{{TIME_NOW}} syntax to event.sprintf() to generate a fresh timestamp as string

Example

input {
    heartbeat {
      add_field => { "heartbeat_time" => "%{{TIME_NOW}}" }
    }
}
filter {
    mutate {
      add_field => { "mutate_time" => "%{{TIME_NOW}}" }
    }
}

It gives two different timestamps.

Why is it important/What is the impact to the user?

When the incoming event has value in @timestamp, eg. event from agent, Logstash use the provided value instead of generating a new timestamp. Prior to the change, there is no way to force a new timestamp to generate during the execution of input plugins.

Previously, users often generate timestamp with ruby-filter code => "event.set('ruby_time', Time.now());", but this approach requires events to pass through PQ before the timestamp was assigned. It is not a good indicator of when the event actually arrived in Logstash.

With this change, all input and filter plugins can generate new timestamps

Checklist

My code follows the style guidelines of this project
I have commented my code, particularly in hard-to-understand areas
I have made corresponding changes to the documentation
I have made corresponding change to the default configuration files (and/or docker env variables)
I have added tests that prove my fix is effective or that my feature works

Author's Checklist

[ ]

How to test this PR locally

Related issues

Closes support custom setting of the name of timestamp field #15701

Use cases

Screenshots

Logs

…h timestamp. The timestamp is represented as a string in the default ISO 8601 format For example, ``` input { heartbeat { add_field => { "input_time" => "%{{TIME_NOW}}" } } }

github-actions · 2025-01-16T19:53:19Z

📃 DOCS PREVIEW ✨ https://logstash_bk_16906.docs-preview.app.elstc.co/diff

…o sprintf_time_now

github-actions · 2025-01-16T21:39:04Z

📃 DOCS PREVIEW ✨ https://logstash_bk_16906.docs-preview.app.elstc.co/diff

andsel

Left a couple of observations.

andsel · 2025-01-17T13:40:12Z

logstash-core/src/test/java/org/logstash/StringInterpolationTest.java

@@ -149,6 +151,24 @@ public void TestValueIsHash() throws IOException {
        assertEquals("{\"k1\":\"v\"}", StringInterpolation.evaluate(event, path));
    }

+    @Test
+    public void TestTimeNow() throws IOException {


I know that the other test methods starts with capital letter, but in Java methods starts with lowercase.
I would also suggest to rename:

TestTimeNow -> testGivenAnEventWithTimeNowSubstitutionVariableWhenEvaluatedReplaceWithCurrentTimestamp

TestBadTimeNow -> testGivenAnEventWithASubstitutionVariableThatContainsTheTimeNowMarkerWhenEvaluatedNoReplacementWithCurrentTimestampHappen

andsel · 2025-01-17T13:41:06Z

logstash-core/src/main/java/org/logstash/StringInterpolation.java

+                // A special pattern to generate a fresh current time
+                // - `%{{TIME_NOW}}` -> `2025-01-16T16:57:12.488955Z`
                close = close + 1; // consume extra closing squiggle
-                final Timestamp t =  event.getTimestamp();
-                if (t != null) {
-                    final String javaTimeFormatPattern = template.substring(open+3, close-1);
-                    final java.time.format.DateTimeFormatter javaDateTimeFormatter = DateTimeFormatter.ofPattern(javaTimeFormatPattern).withZone(ZoneOffset.UTC);
-                    final String formattedTimestamp = javaDateTimeFormatter.format(t.toInstant());
-                    builder.append(formattedTimestamp);
+                final String pattern = template.substring(open+3, close-1);
+                if (pattern.equals(TIME_NOW)) {
+                    final Timestamp now = new Timestamp();
+                    builder.append(now);
+                } else {
+                    final Timestamp t = event.getTimestamp();
+                    if (t != null) {
+                        final DateTimeFormatter javaDateTimeFormatter = DateTimeFormatter.ofPattern(pattern).withZone(ZoneOffset.UTC);
+                        final String formattedTimestamp = javaDateTimeFormatter.format(t.toInstant());
+                        builder.append(formattedTimestamp);
+                    }


Maybe all this time related logic could be extracted in separate helper method.

andsel · 2025-01-17T13:48:38Z

logstash-core/src/test/java/org/logstash/StringInterpolationTest.java

+        Timestamp before = new Timestamp();
+        Timestamp result = new Timestamp(StringInterpolation.evaluate(event, pattern));
+        Timestamp after = new Timestamp();


Secondary note, that you could leave out: I know that it's hard two creation of Instant falls into the same nanosecond, but without a minimal sleep we can't grant that the Timestamps a monotonically increasing, they could result in same value.

github-actions · 2025-01-17T15:58:46Z

📃 DOCS PREVIEW ✨ https://logstash_bk_16906.docs-preview.app.elstc.co/diff

andsel

Once fixed the issue with SonarCube and we get a 🟢 LGTM

andsel · 2025-01-17T15:57:12Z

logstash-core/src/test/java/org/logstash/StringInterpolationTest.java

+    public void testPatternTimeNowGenerateFreshTimestamp() throws IOException, InterruptedException {
+        Event event = getTestEvent();
+        Timestamp before = new Timestamp();
+        TimeUnit.NANOSECONDS.sleep(1);


It seems SonarCube is not happy with this

TimeUnit.NANOSECONDS.sleep(1);

elastic-sonarqube · 2025-01-17T16:37:22Z

Quality Gate passed

Issues
0 New issues
0 Fixed issues
0 Accepted issues

Measures
0 Security Hotspots
No data about Coverage
0.0% Duplication on New Code

See analysis details on SonarQube

elasticmachine · 2025-01-17T16:45:13Z

💚 Build Succeeded

Buildkite Build
Commit: 6fce423

History

💚 Build #2072 succeeded 6cbf6f8
💚 Build #2057 succeeded 5979511
💚 Build #2056 succeeded d26a7db

github-actions · 2025-01-17T16:46:11Z

📃 DOCS PREVIEW ✨ https://logstash_bk_16906.docs-preview.app.elstc.co/diff

kaisecheng · 2025-01-17T16:51:40Z

@logstashmachine backport 8.x

* Add a new pattern %{{TIME_NOW}} to `event.sprintf` to generate a fresh timestamp. The timestamp is represented as a string in the default ISO 8601 format For example, ``` input { heartbeat { add_field => { "heartbeat_time" => "%{{TIME_NOW}}" } } } ``` (cherry picked from commit cd729b7)

* Add a new pattern %{{TIME_NOW}} to `event.sprintf` to generate a fresh timestamp. The timestamp is represented as a string in the default ISO 8601 format For example, ``` input { heartbeat { add_field => { "heartbeat_time" => "%{{TIME_NOW}}" } } } ``` (cherry picked from commit cd729b7) Co-authored-by: kaisecheng <[email protected]>

kaisecheng added 3 commits January 16, 2025 19:14

Add a new pattern %{{TIME_NOW}} to event.sprintf to generate a fres…

5107f97

…h timestamp. The timestamp is represented as a string in the default ISO 8601 format For example, ``` input { heartbeat { add_field => { "input_time" => "%{{TIME_NOW}}" } } }

add doc

d26a7db

add doc

7496037

kaisecheng changed the title ~~Add TIME_NOW pattern for sprintf~~ Add %{{TIME_NOW}} pattern for sprintf Jan 16, 2025

kaisecheng added 2 commits January 16, 2025 21:14

use constant

2ad1905

Merge branch 'sprintf_time_now' of github.com:kaisecheng/logstash int…

5979511

…o sprintf_time_now

andsel requested changes Jan 17, 2025

View reviewed changes

rename & refactor

6cbf6f8

kaisecheng requested a review from andsel January 17, 2025 15:39

andsel approved these changes Jan 17, 2025

View reviewed changes

replace sleep with awaitility

6fce423

kaisecheng merged commit cd729b7 into elastic:main Jan 17, 2025
7 checks passed

github-actions bot mentioned this pull request Jan 17, 2025

Backport PR #16906 to 8.x: Add %{{TIME_NOW}} pattern for sprintf #16908

Merged

5 tasks

github-actions bot added the v8.18.0 label Jan 17, 2025

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add %{{TIME_NOW}} pattern for sprintf #16906

Add %{{TIME_NOW}} pattern for sprintf #16906

kaisecheng commented Jan 16, 2025 •

edited

Loading

github-actions bot commented Jan 16, 2025

github-actions bot commented Jan 16, 2025

andsel left a comment

andsel Jan 17, 2025

andsel Jan 17, 2025

andsel Jan 17, 2025

github-actions bot commented Jan 17, 2025

andsel left a comment

andsel Jan 17, 2025

elastic-sonarqube bot commented Jan 17, 2025

elasticmachine commented Jan 17, 2025

github-actions bot commented Jan 17, 2025

kaisecheng commented Jan 17, 2025

Add %{{TIME_NOW}} pattern for sprintf #16906

Add %{{TIME_NOW}} pattern for sprintf #16906

Conversation

kaisecheng commented Jan 16, 2025 • edited Loading

Release notes

What does this PR do?

Why is it important/What is the impact to the user?

Checklist

Author's Checklist

How to test this PR locally

Related issues

Use cases

Screenshots

Logs

github-actions bot commented Jan 16, 2025

github-actions bot commented Jan 16, 2025

andsel left a comment

Choose a reason for hiding this comment

andsel Jan 17, 2025

Choose a reason for hiding this comment

andsel Jan 17, 2025

Choose a reason for hiding this comment

andsel Jan 17, 2025

Choose a reason for hiding this comment

github-actions bot commented Jan 17, 2025

andsel left a comment

Choose a reason for hiding this comment

andsel Jan 17, 2025

Choose a reason for hiding this comment

elastic-sonarqube bot commented Jan 17, 2025

Quality Gate passed

elasticmachine commented Jan 17, 2025

💚 Build Succeeded

History

github-actions bot commented Jan 17, 2025

kaisecheng commented Jan 17, 2025

kaisecheng commented Jan 16, 2025 •

edited

Loading