libbeat fmtstr tests fail outside of UTC

[hinchliff]

Flaky Test

• Test Name:
  • TestEventFormatString
  • TestTimestampFormatString
• Link:

  • beats/libbeat/common/fmtstr/formatevents_test.go

    Lines 108 to 131 in b3991d4

    	{
    	"test timestamp formatter",
    	"%{[key]}: %{+YYYY.MM.dd}",
    	beat.Event{
    	Timestamp: time.Date(2015, 5, 1, 20, 12, 34, 0, time.Local),
    	Fields: common.MapStr{
    	"key": "timestamp",
    	},
    	},
    	"timestamp: 2015.05.01",
    	[]string{"key"},
    	},
    	{
    	"test timestamp formatter",
    	"%{[@timestamp]}: %{+YYYY.MM.dd}",
    	beat.Event{
    	Timestamp: time.Date(2015, 5, 1, 20, 12, 34, 0, time.Local),
    	Fields: common.MapStr{
    	"key": "timestamp",
    	},
    	},
    	"2015-05-01T20:12:34.000Z: 2015.05.01",
    	[]string{"@timestamp"},
    	},

  • beats/libbeat/common/fmtstr/formattimestamp_test.go

    Lines 72 to 85 in b3991d4

    	{
    	"test timestamp formatter",
    	"%{[key]}: %{+YYYY.MM.dd}",
    	common.MapStr{"key": "timestamp"},
    	time.Date(2015, 5, 1, 20, 12, 34, 0, time.Local),
    	"timestamp: 2015.05.01",
    	},
    	{
    	"test timestamp formatter",
    	"%{[@timestamp]}: %{+YYYY.MM.dd}",
    	common.MapStr{"key": "timestamp"},
    	time.Date(2015, 5, 1, 20, 12, 34, 0, time.Local),
    	"2015-05-01T20:12:34.000Z: 2015.05.01",
    	},

• Branch: main
• Artifact Link: n/a
• Notes: There are four unit tests that seem to be about re-formatting a timestamp in UTC. However, the unit tests generate the expected time using time.Local, which produces inconsistent results based on the local timezone used by e.g. the developer. If my understanding of the purpose of the test cases is correct, then using time.UTC should resolve any potential inconsistencies.

Stack Trace

command [go test -cover -coverprofile /tmp/gotestcover-1560318489 github.com/elastic/beats/v7/libbeat/common/fmtstr]: exit status 1
--- FAIL: TestEventFormatString (0.00s)
    formatevents_test.go:135: test(0): empty string
    formatevents_test.go:135: test(1): no fields configured
    formatevents_test.go:135: test(2): expand event field
    formatevents_test.go:135: test(3): expand with default
    formatevents_test.go:135: test(4): expand nested event field
    formatevents_test.go:135: test(5): expand nested event field (alt. syntax)
    formatevents_test.go:135: test(6): multiple event fields
    formatevents_test.go:135: test(7): same fields
    formatevents_test.go:135: test(8): same fields with default (first)
    formatevents_test.go:135: test(9): same fields with default (second)
    formatevents_test.go:135: test(10): test timestamp formatter
    formatevents_test.go:135: test(11): test timestamp formatter
    formatevents_test.go:146: 
        	Error Trace:	formatevents_test.go:146
        	Error:      	Not equal: 
        	            	expected: "2015-05-01T20:12:34.000Z: 2015.05.01"
        	            	actual  : "2015-05-02T00:12:34.000Z: 2015.05.01"
        	            	
        	            	Diff:
        	            	--- Expected
        	            	+++ Actual
        	            	@@ -1 +1 @@
        	            	-2015-05-01T20:12:34.000Z: 2015.05.01
        	            	+2015-05-02T00:12:34.000Z: 2015.05.01
        	Test:       	TestEventFormatString
--- FAIL: TestTimestampFormatString (0.00s)
    formattimestamp_test.go:89: test(0): empty string
    formattimestamp_test.go:89: test(1): no fields configured
    formattimestamp_test.go:89: test(2): expand field
    formattimestamp_test.go:89: test(3): expand with default
    formattimestamp_test.go:89: test(4): expand nested field
    formattimestamp_test.go:89: test(5): test timestamp formatter
    formattimestamp_test.go:89: test(6): test timestamp formatter
    formattimestamp_test.go:106: 
        	Error Trace:	formattimestamp_test.go:106
        	Error:      	Not equal: 
        	            	expected: "2015-05-01T20:12:34.000Z: 2015.05.01"
        	            	actual  : "2015-05-02T00:12:34.000Z: 2015.05.01"
        	            	
        	            	Diff:
        	            	--- Expected
        	            	+++ Actual
        	            	@@ -1 +1 @@
        	            	-2015-05-01T20:12:34.000Z: 2015.05.01
        	            	+2015-05-02T00:12:34.000Z: 2015.05.01
        	Test:       	TestTimestampFormatString
FAIL
coverage: 83.9% of statements
FAIL	github.com/elastic/beats/v7/libbeat/common/fmtstr	0.442s
FAIL

command [go test -cover -coverprofile /tmp/gotestcover-165778516 github.com/elastic/beats/v7/libbeat/common/fmtstr]: exit status 1
--- FAIL: TestTimestampFormatString (0.00s)
    formattimestamp_test.go:89: test(0): empty string
    formattimestamp_test.go:89: test(1): no fields configured
    formattimestamp_test.go:89: test(2): expand field
    formattimestamp_test.go:89: test(3): expand with default
    formattimestamp_test.go:89: test(4): expand nested field
    formattimestamp_test.go:89: test(5): test timestamp formatter
    formattimestamp_test.go:89: test(6): test timestamp formatter
    formattimestamp_test.go:106: 
        	Error Trace:	formattimestamp_test.go:106
        	Error:      	Not equal: 
        	            	expected: "2015-05-01T20:12:34.000Z: 2015.05.01"
        	            	actual  : "2015-05-02T00:12:34.000Z: 2015.05.01"
        	            	
        	            	Diff:
        	            	--- Expected
        	            	+++ Actual
        	            	@@ -1 +1 @@
        	            	-2015-05-01T20:12:34.000Z: 2015.05.01
        	            	+2015-05-02T00:12:34.000Z: 2015.05.01
        	Test:       	TestTimestampFormatString
FAIL
coverage: 83.9% of statements
FAIL	github.com/elastic/beats/v7/libbeat/common/fmtstr	0.327s
FAIL

See Also

https://discuss.elastic.co/t/test-suite-error-time-local-vs-time-utc/286735

[elasticmachine]

Pinging @elastic/elastic-agent-data-plane (Team:Elastic-Agent-Data-Plane)