From 1e87df4149c57f67fac358694fe5477ddb91b51c Mon Sep 17 00:00:00 2001 From: Pier-Hugues Pellerin Date: Mon, 24 Sep 2018 13:58:26 -0400 Subject: [PATCH] Correctly parse rfc3339 timezone and Nanosecond (#8346) * Correctly parse rfc3339 timezone and Nanosecond The code was not correctly creating the time and was isntead making events appear to be a few years in the future. The nanosecond extraction was not on the right scale for the time.Date, the commit fixes the behavior and do assertions with the go parser. (cherry picked from commit 6204fceaa4e51871401a5a997373f859840d4ea3) --- CHANGELOG.asciidoc | 2 + filebeat/input/syslog/event.go | 16 +++--- filebeat/input/syslog/event_test.go | 86 +++++++++++++++++++++++++--- filebeat/input/syslog/parser_test.go | 36 ++++++------ 4 files changed, 106 insertions(+), 34 deletions(-) diff --git a/CHANGELOG.asciidoc b/CHANGELOG.asciidoc index 8ffea1f4cc49..22aa8b46d168 100644 --- a/CHANGELOG.asciidoc +++ b/CHANGELOG.asciidoc @@ -56,6 +56,8 @@ https://github.com/elastic/beats/compare/v6.4.0...6.x[Check the HEAD diff] - Fix date format in Mongodb Ingest pipeline. {pull}7974[7974] - Fixed a docker input error due to the offset update bug in partial log join.{pull}8177[8177] - Update CRI format to support partial/full tags. {pull}8265[8265] +- Fix some errors happening when stopping syslog input. {pull}8347[8347] +- Fix RFC3339 timezone and nanoseconds parsing with the syslog input. {pull}8346[8346] *Heartbeat* diff --git a/filebeat/input/syslog/event.go b/filebeat/input/syslog/event.go index 9280118bc305..1ffcf074a756 100644 --- a/filebeat/input/syslog/event.go +++ b/filebeat/input/syslog/event.go @@ -102,18 +102,20 @@ func (s *event) SetTimeZone(b []byte) { } // +00 +00:00 or +0000 + // Use second value directly and don't use unecessary time.Duration. + // Time.FixedZone accepts number of seconds. var h, m int switch len(b[1:]) { case 2: - h = int(time.Hour * time.Duration(bytesToInt(skipLeadZero(b[1:])))) + h = 3600 * bytesToInt(skipLeadZero(b[1:])) s.loc = time.FixedZone("", d*h) case 4: - h = int(time.Hour * time.Duration(bytesToInt(skipLeadZero(b[1:3])))) - m = int(time.Minute * time.Duration(bytesToInt(skipLeadZero(b[3:5])))) + h = 3600 * bytesToInt(skipLeadZero(b[1:3])) + m = 60 * bytesToInt(skipLeadZero(b[3:5])) s.loc = time.FixedZone("", d*(h+m)) case 5: - h = int(time.Hour * time.Duration(bytesToInt(skipLeadZero(b[1:3])))) - m = int(time.Minute * time.Duration(bytesToInt(skipLeadZero(b[4:6])))) + h = 3600 * bytesToInt(skipLeadZero(b[1:3])) + m = 60 * bytesToInt(skipLeadZero(b[4:6])) s.loc = time.FixedZone("", d*(h+m)) } } @@ -271,8 +273,8 @@ func (s *event) HasPid() bool { func (s *event) SetNanosecond(b []byte) { // We assume that we receive a byte array representing a nanosecond, this might not be // always the case, so we have to pad it. - if len(b) < 7 { - s.nanosecond = bytesToInt(skipLeadZero(b)) * int(math.Pow10((7 - len(b)))) + if len(b) < 9 { + s.nanosecond = bytesToInt(skipLeadZero(b)) * int(math.Pow10((9 - len(b)))) } else { s.nanosecond = bytesToInt(skipLeadZero(b)) } diff --git a/filebeat/input/syslog/event_test.go b/filebeat/input/syslog/event_test.go index 912e3eb7cb0b..137538939f38 100644 --- a/filebeat/input/syslog/event_test.go +++ b/filebeat/input/syslog/event_test.go @@ -63,16 +63,84 @@ func TestHasPid(t *testing.T) { } func TestDateParsing(t *testing.T) { - now := time.Now() + // 2018-09-12T18:14:04.537585-07:00 e := newEvent() - e.SetDay(itb(now.Day())) - e.SetMonth([]byte(now.Month().String())) - e.SetHour(itb(now.Hour())) - e.SetMinute(itb(now.Minute())) - e.SetSecond(itb(now.Second())) - e.SetNanosecond(itb(now.Nanosecond())) - new := e.Timestamp(time.Local) - assert.Equal(t, now.UTC(), new) + e.SetYear([]byte("2018")) + e.SetDay(itb(12)) + e.SetMonth([]byte("Sept")) + e.SetHour(itb(18)) + e.SetMinute(itb(14)) + e.SetSecond(itb(04)) + e.SetNanosecond(itb(5555)) + + // Use google parser to compare. + t1, _ := time.Parse(time.RFC3339, "2018-09-12T18:14:04.5555-07:00") + t1 = t1.UTC() + t2, _ := time.Parse(time.RFC3339, "2018-09-12T18:14:04.5555+07:00") + t2 = t2.UTC() + alreadyutc := time.Date(2018, 9, 12, 18, 14, 04, 555500000, time.UTC) + + tests := []struct { + name string + tzBytes []byte + expected time.Time + }{ + {name: "-07:00", tzBytes: []byte("-07:00"), expected: t1}, + {name: "-0700", tzBytes: []byte("-0700"), expected: t1}, + {name: "-07", tzBytes: []byte("-07"), expected: t1}, + {name: "+07:00", tzBytes: []byte("+07:00"), expected: t2}, + {name: "+0700", tzBytes: []byte("+0700"), expected: t2}, + {name: "+07", tzBytes: []byte("+07"), expected: t2}, + {name: "z+00:00", tzBytes: []byte("z+00:00"), expected: alreadyutc}, + {name: "z+0000", tzBytes: []byte("z+0000"), expected: alreadyutc}, + {name: "z+00", tzBytes: []byte("z+00"), expected: alreadyutc}, + {name: "Z+00:00", tzBytes: []byte("Z+00:00"), expected: alreadyutc}, + {name: "Z+0000", tzBytes: []byte("Z+0000"), expected: alreadyutc}, + {name: "Z+00", tzBytes: []byte("Z+00"), expected: alreadyutc}, + } + + for _, test := range tests { + t.Run(test.name, func(t *testing.T) { + e.SetTimeZone(test.tzBytes) + new := e.Timestamp(nil) + assert.Equal(t, test.expected, new) + }) + } +} + +func TestNanosecondParsing(t *testing.T) { + e := newEvent() + e.SetYear([]byte("2018")) + e.SetDay(itb(12)) + e.SetMonth([]byte("Sept")) + e.SetHour(itb(18)) + e.SetMinute(itb(14)) + e.SetSecond(itb(04)) + + // Use google parser to compare. + dt := func(s string) int { + ti, _ := time.Parse(time.RFC3339, s) + return ti.UTC().Nanosecond() + } + + tests := []struct { + name string + nanosecond []byte + expected int + }{ + {nanosecond: []byte("5555"), expected: dt("2018-09-12T18:14:04.5555-07:00")}, + {nanosecond: []byte("5"), expected: dt("2018-09-12T18:14:04.5-07:00")}, + {nanosecond: []byte("0005"), expected: dt("2018-09-12T18:14:04.0005-07:00")}, + {nanosecond: []byte("000545"), expected: dt("2018-09-12T18:14:04.000545-07:00")}, + {nanosecond: []byte("00012345"), expected: dt("2018-09-12T18:14:04.00012345-07:00")}, + } + + for _, test := range tests { + t.Run(string(test.nanosecond), func(t *testing.T) { + e.SetNanosecond(test.nanosecond) + assert.Equal(t, test.expected, e.Nanosecond()) + }) + } } func TestIsValid(t *testing.T) { diff --git a/filebeat/input/syslog/parser_test.go b/filebeat/input/syslog/parser_test.go index 438fe96f269e..f64e012ab519 100644 --- a/filebeat/input/syslog/parser_test.go +++ b/filebeat/input/syslog/parser_test.go @@ -63,7 +63,7 @@ func TestParseSyslog(t *testing.T) { hour: 2, minute: 13, second: 38, - nanosecond: 4000, + nanosecond: 400000, }, }, { @@ -81,8 +81,8 @@ func TestParseSyslog(t *testing.T) { hour: 2, minute: 13, second: 38, - nanosecond: 6353220, - loc: time.FixedZone("", int(-7*time.Hour)), + nanosecond: 635322000, + loc: time.FixedZone("", -7*3600), }, }, { @@ -100,8 +100,8 @@ func TestParseSyslog(t *testing.T) { hour: 2, minute: 13, second: 38, - nanosecond: 6353220, - loc: time.FixedZone("", int(-7*time.Hour)), + nanosecond: 635322000, + loc: time.FixedZone("", -7*3600), }, }, { @@ -119,8 +119,8 @@ func TestParseSyslog(t *testing.T) { hour: 2, minute: 13, second: 38, - nanosecond: 6353220, - loc: time.FixedZone("", int(-7*time.Hour)+int(-30*time.Minute)), + nanosecond: 635322000, + loc: time.FixedZone("", -7*3600+-30*60), }, }, { @@ -138,8 +138,8 @@ func TestParseSyslog(t *testing.T) { hour: 2, minute: 13, second: 38, - nanosecond: 6353220, - loc: time.FixedZone("", int(-7*time.Hour)+int(-10*time.Minute)), + nanosecond: 635322000, + loc: time.FixedZone("", -7*3600+-10*60), }, }, { @@ -157,8 +157,8 @@ func TestParseSyslog(t *testing.T) { hour: 2, minute: 13, second: 38, - nanosecond: 6353220, - loc: time.FixedZone("", int(-7*time.Hour)), + nanosecond: 635322000, + loc: time.FixedZone("", -7*3600), }, }, { @@ -176,7 +176,7 @@ func TestParseSyslog(t *testing.T) { hour: 2, minute: 13, second: 38, - nanosecond: 6353220, + nanosecond: 635322000, loc: time.UTC, }, }, @@ -195,7 +195,7 @@ func TestParseSyslog(t *testing.T) { hour: 2, minute: 13, second: 38, - nanosecond: 6353220, + nanosecond: 635322000, loc: time.UTC, }, }, @@ -214,7 +214,7 @@ func TestParseSyslog(t *testing.T) { hour: 2, minute: 13, second: 38, - nanosecond: 6353220, + nanosecond: 635322000, loc: time.UTC, }, }, @@ -233,7 +233,7 @@ func TestParseSyslog(t *testing.T) { hour: 2, minute: 13, second: 38, - nanosecond: 6353220, + nanosecond: 635322000, loc: time.UTC, }, }, @@ -304,7 +304,7 @@ func TestParseSyslog(t *testing.T) { minute: 31, second: 24, year: 2016, - nanosecond: 4000, + nanosecond: 400000, }, }, { @@ -341,7 +341,7 @@ func TestParseSyslog(t *testing.T) { }, { title: "time with nanosecond", - log: []byte("Oct 11 22:14:15.0000005 --- last message repeated 1 time ---"), + log: []byte("Oct 11 22:14:15.000000005 --- last message repeated 1 time ---"), syslog: event{ priority: -1, message: "--- last message repeated 1 time ---", @@ -400,7 +400,7 @@ func TestParseSyslog(t *testing.T) { hour: 22, minute: 14, second: 15, - nanosecond: 5764300, + nanosecond: 576430000, }, }, {