Skip to content

Commit

Permalink
Correctly parse rfc3339 timezone and Nanosecond (#8346)
Browse files Browse the repository at this point in the history
* 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.
  • Loading branch information
ph authored Sep 24, 2018
1 parent 35068ee commit 6204fce
Show file tree
Hide file tree
Showing 4 changed files with 105 additions and 34 deletions.
1 change: 1 addition & 0 deletions CHANGELOG.asciidoc
Original file line number Diff line number Diff line change
Expand Up @@ -62,6 +62,7 @@ https://github.com/elastic/beats/compare/v6.4.0...master[Check the HEAD diff]
- 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*

Expand Down
16 changes: 9 additions & 7 deletions filebeat/input/syslog/event.go
Original file line number Diff line number Diff line change
Expand Up @@ -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))
}
}
Expand Down Expand Up @@ -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))
}
Expand Down
86 changes: 77 additions & 9 deletions filebeat/input/syslog/event_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -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) {
Expand Down
36 changes: 18 additions & 18 deletions filebeat/input/syslog/parser_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -63,7 +63,7 @@ func TestParseSyslog(t *testing.T) {
hour: 2,
minute: 13,
second: 38,
nanosecond: 4000,
nanosecond: 400000,
},
},
{
Expand All @@ -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),
},
},
{
Expand All @@ -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),
},
},
{
Expand All @@ -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),
},
},
{
Expand All @@ -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),
},
},
{
Expand All @@ -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),
},
},
{
Expand All @@ -176,7 +176,7 @@ func TestParseSyslog(t *testing.T) {
hour: 2,
minute: 13,
second: 38,
nanosecond: 6353220,
nanosecond: 635322000,
loc: time.UTC,
},
},
Expand All @@ -195,7 +195,7 @@ func TestParseSyslog(t *testing.T) {
hour: 2,
minute: 13,
second: 38,
nanosecond: 6353220,
nanosecond: 635322000,
loc: time.UTC,
},
},
Expand All @@ -214,7 +214,7 @@ func TestParseSyslog(t *testing.T) {
hour: 2,
minute: 13,
second: 38,
nanosecond: 6353220,
nanosecond: 635322000,
loc: time.UTC,
},
},
Expand All @@ -233,7 +233,7 @@ func TestParseSyslog(t *testing.T) {
hour: 2,
minute: 13,
second: 38,
nanosecond: 6353220,
nanosecond: 635322000,
loc: time.UTC,
},
},
Expand Down Expand Up @@ -304,7 +304,7 @@ func TestParseSyslog(t *testing.T) {
minute: 31,
second: 24,
year: 2016,
nanosecond: 4000,
nanosecond: 400000,
},
},
{
Expand Down Expand Up @@ -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 ---",
Expand Down Expand Up @@ -400,7 +400,7 @@ func TestParseSyslog(t *testing.T) {
hour: 22,
minute: 14,
second: 15,
nanosecond: 5764300,
nanosecond: 576430000,
},
},
{
Expand Down

0 comments on commit 6204fce

Please sign in to comment.