On Wed, 7 Dec 2016, mosto...@gmail.com wrote:

I'm still trying to reproduce/understand what is happening and building a test case for the github issue if needed.

Consider the following HTTP access lines:

  127.0.0.1 - - [17/Mar/2016:18:15:06 +0100] "GET /redacted HTTP/1.1"
  200 59506
  127.0.0.1 - - [17/Mar/2016:18:15:24 +0100] "OPTIONS / HTTP/1.1" 403
  205 "-" "-"

And the following rule:

  # This is just access_log. Perhaps literal is more efficient than
  whitespace?

a literal space is always more efficent than whitespace, only use whitespace if there can be more than one space, or tabs

  type=@apache_common:%[
       {"type":"ipv4", "name":"ip"},
       {"type":"whitespace"},
       {"type":"word", "name":"ident"},
       {"type":"whitespace"},
       {"type":"word", "name":"user"},
       {"type":"literal", "text":" ["},
       {"type":"char-to", "name":"date", "extradata":"]"},
       {"type":"literal", "text":"] \""},
       {"type":"word", "name":"method"},
       {"type":"whitespace"},
       {"type":"char-to", "name":"request", "extradata":" "},
       {"type":"literal", "text":" HTTP/"},
       {"type":"float", "name":"httpversion"},
       {"type":"literal", "text":"\""},
       {"type":"whitespace"},
       {"type":"number", "name":"response"},
       {"type":"whitespace"},
       {"type":"word", "name":"bytes"}
  ]%

just a note, the new syntax is not always better than the old syntax

127.0.0.1 - - [17/Mar/2016:18:15:06 +0100] "GET /redacted HTTP/1.1" 200 59506

type=@apache_common:%ip:ipv4% %ident:word% %user:word% [%date:char-to:]%] "%request:char-to:"%" %response:number% %bytes:rest%

note that bytes really should be type number, but that requires a trailiing space right now.


  #AFAIK this should accept null or apache combined log fields
  type=@apache_combined:-
  type=@apache_combined:%[
       {"type":"whitespace"},
       {"type":"quoted-string","name":"referrer"},
       {"type":"whitespace"},
       {"type":"quoted-string","name":"useragent"}
  ]%
  rule=access_combined:%[
       {"type":"@apache_common", "name":"."}
  ]%

*As expected*, the first line matches and the second doesn't:

  { "bytes": "59506", "response": "200", "httpversion": "1.1",
  "request": "\/redacted", "method": "GET", "date":
  "17\/Mar\/2016:18:15:06 +0100", "user": "-", "ident": "-", "ip":
  "127.0.0.1" }
  { "originalmsg": "127.0.0.1 - - [17\/Mar\/2016:18:15:24 +0100]
  \"OPTIONS \/ HTTP\/1.1\" 403 205 \"-\" \"-", "unparsed-data": "
  \"-\" \"-" }

But if we try:

  rule=access_combined:%[
       {"type":"@apache_common", "name":"."},
       {"type":"@apache_combined","name":"."}
  ]%

this is looking for one after the other, not either

you either use alternative or you have two different rule lines

Doesnt parse any of them properly, and we're getting:

  { "originalmsg": "127.0.0.1 - - [17\/Mar\/2016:18:15:06 +0100] \"GET
  \/redacted HTTP\/1.1\" 200 59506", "unparsed-data": "" }
  { "originalmsg": "127.0.0.1 - - [17\/Mar\/2016:18:15:24 +0100]
  \"OPTIONS \/ HTTP\/1.1\" 403 205 \"-\" \"-", "unparsed-data": "
  \"-\" \"-" }


Here's trace:



when looking at the trace, everything before the "To normalize:" is probably not that useful (it's needed if you think the ruleset isn't being parsed correctly, but not to try and figure out why the log line isn't being parsed correctly)

it would be nice if -v only showed you the part we normally care about, there may be a way to get just this portion, but I don't know how


  To normalize: '127.0.0.1 - - [17/Mar/2016:18:15:06 +0100] "GET
  /redacted HTTP/1.1" 200 59506'
  liblognorm: 0: enter parser, dag node 0x7f97c606d0a0, json
  0x7f97c6071590
  liblognorm: 0/0:trying 'USER-DEFINED' parser for field '.', data
  'UNKNOWN'
  liblognorm: calling custom parser '@apache_common'
  liblognorm: 0: enter parser, dag node 0x7f97c606e650, json
  0x7f97c60700f0
  liblognorm: 0/1:trying 'ipv4' parser for field 'ip', data 'UNKNOWN'
  liblognorm: parser lookup returns 0, pParsed 9
  liblognorm: 0: potential hit, trying subtree 0x7f97c606f050

found the ipv4 (9 bytes, now at position 9)

  liblognorm: 9: enter parser, dag node 0x7f97c606f050, json
  0x7f97c60700f0
  liblognorm: 9/1:trying 'whitespace' parser for field '(null)', data
  'UNKNOWN'
  liblognorm: parser lookup returns 0, pParsed 1
  liblognorm: 9: potential hit, trying subtree 0x7f97c606f180

found whitespace (1 byte, now at position 10)

  liblognorm: 10: enter parser, dag node 0x7f97c606f180, json
  0x7f97c60700f0
  liblognorm: 10/1:trying 'word' parser for field 'ident', data 'UNKNOWN'
  liblognorm: parser lookup returns 0, pParsed 1
  liblognorm: 10: potential hit, trying subtree 0x7f97c606f3e0

found ident (1 byte, now at position 11)

  liblognorm: 11: enter parser, dag node 0x7f97c606f3e0, json
  0x7f97c60700f0
  liblognorm: 11/1:trying 'whitespace' parser for field '(null)', data
  'UNKNOWN'
  liblognorm: parser lookup returns 0, pParsed 1
  liblognorm: 11: potential hit, trying subtree 0x7f97c606f610

found whitespace (1 byte, now at position 12)

  liblognorm: 12: enter parser, dag node 0x7f97c606f610, json
  0x7f97c60700f0
  liblognorm: 12/1:trying 'word' parser for field 'user', data 'UNKNOWN'
  liblognorm: parser lookup returns 0, pParsed 1
  liblognorm: 12: potential hit, trying subtree 0x7f97c606f780

found user (1 byte, now at position 13)

  liblognorm: 13: enter parser, dag node 0x7f97c606f780, json
  0x7f97c60700f0
  liblognorm: 13/1:trying 'literal' parser for field '(null)', data ' ['
  liblognorm: parser lookup returns 0, pParsed 2
  liblognorm: 13: potential hit, trying subtree 0x7f97c606f820

found literal (2 bytes, now at position 15)

  liblognorm: 15: enter parser, dag node 0x7f97c606f820, json
  0x7f97c60700f0
  liblognorm: 15/1:trying 'char-to' parser for field 'date', data
  'UNKNOWN'
  liblognorm: parser lookup returns 0, pParsed 26
  liblognorm: 15: potential hit, trying subtree 0x7f97c606fc30

found date (26 bytes, now at position 41)

  liblognorm: 41: enter parser, dag node 0x7f97c606fc30, json
  0x7f97c60700f0
  liblognorm: 41/1:trying 'literal' parser for field '(null)', data '] "'
  liblognorm: parser lookup returns 0, pParsed 3
  liblognorm: 41: potential hit, trying subtree 0x7f97c606fdc0

found lteral (3 bytes, now at position 44)

  liblognorm: 44: enter parser, dag node 0x7f97c606fdc0, json
  0x7f97c60700f0
  liblognorm: 44/1:trying 'word' parser for field 'method', data 'UNKNOWN'
  liblognorm: parser lookup returns 0, pParsed 3
  liblognorm: 44: potential hit, trying subtree 0x7f97c6070050

found method (3 bytes, now at position 47)

  liblognorm: 47: enter parser, dag node 0x7f97c6070050, json
  0x7f97c60700f0
  liblognorm: 47/1:trying 'whitespace' parser for field '(null)', data
  'UNKNOWN'
  liblognorm: parser lookup returns 0, pParsed 1
  liblognorm: 47: potential hit, trying subtree 0x7f97c60703c0

found whitespace (1 byte, now at position 48)

  liblognorm: 48: enter parser, dag node 0x7f97c60703c0, json
  0x7f97c60700f0
  liblognorm: 48/1:trying 'char-to' parser for field 'request', data
  'UNKNOWN'
  liblognorm: parser lookup returns 0, pParsed 9
  liblognorm: 48: potential hit, trying subtree 0x7f97c6070530

found request (9 bytes, now at position 57)

  liblognorm: 57: enter parser, dag node 0x7f97c6070530, json
  0x7f97c60700f0
  liblognorm: 57/1:trying 'literal' parser for field '(null)', data '
  HTTP/'
  liblognorm: parser lookup returns 0, pParsed 6
  liblognorm: 57: potential hit, trying subtree 0x7f97c6070bd0

found literal (6 bytes, now at posisition 63)

  liblognorm: 63: enter parser, dag node 0x7f97c6070bd0, json
  0x7f97c60700f0
  liblognorm: 63/1:trying 'float' parser for field 'httpversion', data
  'UNKNOWN'
  liblognorm: parser lookup returns 0, pParsed 3
  liblognorm: 63: potential hit, trying subtree 0x7f97c6070d50

found httpversion (3 bytes, now at position 66)

  liblognorm: 66: enter parser, dag node 0x7f97c6070d50, json
  0x7f97c60700f0
  liblognorm: 66/1:trying 'literal' parser for field '(null)', data '"'
  liblognorm: parser lookup returns 0, pParsed 1
  liblognorm: 66: potential hit, trying subtree 0x7f97c6070f90

found literal (1 byte, now at position 67)

  liblognorm: 67: enter parser, dag node 0x7f97c6070f90, json
  0x7f97c60700f0
  liblognorm: 67/1:trying 'whitespace' parser for field '(null)', data
  'UNKNOWN'
  liblognorm: parser lookup returns 0, pParsed 1
  liblognorm: 67: potential hit, trying subtree 0x7f97c6071200

found whitespace (1 byte, now at position 68)

  liblognorm: 68: enter parser, dag node 0x7f97c6071200, json
  0x7f97c60700f0
  liblognorm: 68/1:trying 'number' parser for field 'response', data
  'UNKNOWN'
  liblognorm: parser lookup returns 0, pParsed 3
  liblognorm: 68: potential hit, trying subtree 0x7f97c6071350

found response (3 bytes, now at position 71)

  liblognorm: 71: enter parser, dag node 0x7f97c6071350, json
  0x7f97c60700f0
  liblognorm: 71/1:trying 'whitespace' parser for field '(null)', data
  'UNKNOWN'
  liblognorm: parser lookup returns 0, pParsed 1
  liblognorm: 71: potential hit, trying subtree 0x7f97c60716e0

found whitespace (1 byte, now at position 72)

  liblognorm: 72: enter parser, dag node 0x7f97c60716e0, json
  0x7f97c60700f0
  liblognorm: 72/1:trying 'word' parser for field 'bytes', data 'UNKNOWN'
  liblognorm: parser lookup returns 0, pParsed 5
  liblognorm: 72: potential hit, trying subtree 0x7f97c6071a80

found bytes (5 bytes, now at poisition 77)

  liblognorm: 77: enter parser, dag node 0x7f97c6071a80, json
  0x7f97c60700f0
  liblognorm: offs 77, strLen 77, isTerm 1
  liblognorm: 77 returns 0, pParsedTo 0, parsedTo 0

this looks like it's undoing things, it may be an artifact of using a custom type (misleading at best)

  liblognorm: 72: subtree returns 0, parsedTo 77
  liblognorm: 72: parser matches at 72
  liblognorm: parsedTo 77, *pParsedTo 77
  liblognorm: offs 72, strLen 77, isTerm 0
  liblognorm: 72 returns 0, pParsedTo 77, parsedTo 77
  liblognorm: 71: subtree returns 0, parsedTo 72
  liblognorm: 71: parser matches at 71
  liblognorm: parsedTo 72, *pParsedTo 77
  liblognorm: offs 71, strLen 77, isTerm 0
  liblognorm: 71 returns 0, pParsedTo 77, parsedTo 72
  liblognorm: 68: subtree returns 0, parsedTo 71
  liblognorm: 68: parser matches at 68
  liblognorm: parsedTo 71, *pParsedTo 77
  liblognorm: offs 68, strLen 77, isTerm 0
  liblognorm: 68 returns 0, pParsedTo 77, parsedTo 71
  liblognorm: 67: subtree returns 0, parsedTo 68
  liblognorm: 67: parser matches at 67
  liblognorm: parsedTo 68, *pParsedTo 77
  liblognorm: offs 67, strLen 77, isTerm 0
  liblognorm: 67 returns 0, pParsedTo 77, parsedTo 68
  liblognorm: 66: subtree returns 0, parsedTo 67
  liblognorm: 66: parser matches at 66
  liblognorm: parsedTo 67, *pParsedTo 77
  liblognorm: offs 66, strLen 77, isTerm 0
  liblognorm: 66 returns 0, pParsedTo 77, parsedTo 67
  liblognorm: 63: subtree returns 0, parsedTo 66
  liblognorm: 63: parser matches at 63
  liblognorm: parsedTo 66, *pParsedTo 77
  liblognorm: offs 63, strLen 77, isTerm 0
  liblognorm: 63 returns 0, pParsedTo 77, parsedTo 66
  liblognorm: 57: subtree returns 0, parsedTo 63
  liblognorm: 57: parser matches at 57
  liblognorm: parsedTo 63, *pParsedTo 77
  liblognorm: offs 57, strLen 77, isTerm 0
  liblognorm: 57 returns 0, pParsedTo 77, parsedTo 63
  liblognorm: 48: subtree returns 0, parsedTo 57
  liblognorm: 48: parser matches at 48
  liblognorm: parsedTo 57, *pParsedTo 77
  liblognorm: offs 48, strLen 77, isTerm 0
  liblognorm: 48 returns 0, pParsedTo 77, parsedTo 57
  liblognorm: 47: subtree returns 0, parsedTo 48
  liblognorm: 47: parser matches at 47
  liblognorm: parsedTo 48, *pParsedTo 77
  liblognorm: offs 47, strLen 77, isTerm 0
  liblognorm: 47 returns 0, pParsedTo 77, parsedTo 48
  liblognorm: 44: subtree returns 0, parsedTo 47
  liblognorm: 44: parser matches at 44
  liblognorm: parsedTo 47, *pParsedTo 77
  liblognorm: offs 44, strLen 77, isTerm 0
  liblognorm: 44 returns 0, pParsedTo 77, parsedTo 47
  liblognorm: 41: subtree returns 0, parsedTo 44
  liblognorm: 41: parser matches at 41
  liblognorm: parsedTo 44, *pParsedTo 77
  liblognorm: offs 41, strLen 77, isTerm 0
  liblognorm: 41 returns 0, pParsedTo 77, parsedTo 44
  liblognorm: 15: subtree returns 0, parsedTo 41
  liblognorm: 15: parser matches at 15
  liblognorm: parsedTo 41, *pParsedTo 77
  liblognorm: offs 15, strLen 77, isTerm 0
  liblognorm: 15 returns 0, pParsedTo 77, parsedTo 41
  liblognorm: 13: subtree returns 0, parsedTo 15
  liblognorm: 13: parser matches at 13
  liblognorm: parsedTo 15, *pParsedTo 77
  liblognorm: offs 13, strLen 77, isTerm 0
  liblognorm: 13 returns 0, pParsedTo 77, parsedTo 15
  liblognorm: 12: subtree returns 0, parsedTo 13
  liblognorm: 12: parser matches at 12
  liblognorm: parsedTo 13, *pParsedTo 77
  liblognorm: offs 12, strLen 77, isTerm 0
  liblognorm: 12 returns 0, pParsedTo 77, parsedTo 13
  liblognorm: 11: subtree returns 0, parsedTo 12
  liblognorm: 11: parser matches at 11
  liblognorm: parsedTo 12, *pParsedTo 77
  liblognorm: offs 11, strLen 77, isTerm 0
  liblognorm: 11 returns 0, pParsedTo 77, parsedTo 12
  liblognorm: 10: subtree returns 0, parsedTo 11
  liblognorm: 10: parser matches at 10
  liblognorm: parsedTo 11, *pParsedTo 77
  liblognorm: offs 10, strLen 77, isTerm 0
  liblognorm: 10 returns 0, pParsedTo 77, parsedTo 11
  liblognorm: 9: subtree returns 0, parsedTo 10
  liblognorm: 9: parser matches at 9
  liblognorm: parsedTo 10, *pParsedTo 77
  liblognorm: offs 9, strLen 77, isTerm 0
  liblognorm: 9 returns 0, pParsedTo 77, parsedTo 10
  liblognorm: 0: subtree returns 0, parsedTo 9
  liblognorm: 0: parser matches at 0
  liblognorm: parsedTo 9, *pParsedTo 77
  liblognorm: offs 0, strLen 77, isTerm 0
  liblognorm: 0 returns 0, pParsedTo 77, parsedTo 9
  liblognorm: called CUSTOM PARSER '@apache_common', result 0, offs 0,
  *pParsed 0
  liblognorm: parser lookup returns 0, pParsed 77
  liblognorm: 0: potential hit, trying subtree 0x7f97c6071df0

and we've undone averything.

  liblognorm: 77: enter parser, dag node 0x7f97c6071df0, json
  0x7f97c6071590
  liblognorm: 77/0:trying 'USER-DEFINED' parser for field '.', data
  'UNKNOWN'
  liblognorm: calling custom parser '@apache_combined'

now it's going to try @apache_combined as the next thing in the rule

  liblognorm: 77: enter parser, dag node 0x7f97c6070de0, json
  0x7f97c606e9c0
  liblognorm: 77/1:trying 'literal' parser for field '(null)', data '-'
  liblognorm: parser lookup returns -1000, pParsed 0
  liblognorm: parsedTo 0, *pParsedTo 0

no match

  liblognorm: 77/1:trying 'whitespace' parser for field '(null)', data
  'UNKNOWN'
  liblognorm: parser lookup returns -1000, pParsed 0
  liblognorm: parsedTo 0, *pParsedTo 0
  liblognorm: offs 77, strLen 77, isTerm 0
  liblognorm: 77 returns -1000, pParsedTo 0, parsedTo 0

no match

  liblognorm: called CUSTOM PARSER '@apache_combined', result -1000,
  offs 77, *pParsed 0

@apache_combine failed

  liblognorm: parser lookup returns -1000, pParsed 18446744073709551539
  liblognorm: parsedTo 0, *pParsedTo 0
  liblognorm: offs 77, strLen 77, isTerm 0
  liblognorm: 77 returns -1000, pParsedTo 0, parsedTo 0
  liblognorm: 0: subtree returns -1000, parsedTo 77
  liblognorm: 0 nonmatch, backtracking required, parsed to=77
  liblognorm: parsedTo 77, *pParsedTo 77
  liblognorm: offs 0, strLen 77, isTerm 0
  liblognorm: 0 returns -1000, pParsedTo 77, parsedTo 77
  liblognorm: final result for normalizer: parsedTo 77, endNode (nil)
  liblognorm: DONE, final return is -1000

all this is backing up and saying that the parser failed, and how far it got in the message before it failed.

  normalized: '{ "originalmsg": "127.0.0.1 - - [17\/Mar\/2016:18:15:06
  +0100] \"GET \/redacted HTTP\/1.1\" 200 59506", "unparsed-data": "" }'

ok, now I understand this, it parsed the message with @apache_common and got to position 77 (the end of the message), but that wasn't the end of the rule, so the parsing failed, and it failed with nothing left to parse

  { "originalmsg": "127.0.0.1 - - [17\/Mar\/2016:18:15:06 +0100] \"GET
  \/redacted HTTP\/1.1\" 200 59506", "unparsed-data": "" }

now we look at the second message (it helps understand this if you only look at one at a time, one rule and one log message)

  To normalize: '127.0.0.1 - - [17/Mar/2016:18:15:24 +0100] "OPTIONS /
  HTTP/1.1" 403 205 "-" "-'
  liblognorm: 0: enter parser, dag node 0x7f97c606d0a0, json
  0x7f97c6071590
  liblognorm: 0/0:trying 'USER-DEFINED' parser for field '.', data
  'UNKNOWN'
  liblognorm: calling custom parser '@apache_common'
  liblognorm: 0: enter parser, dag node 0x7f97c606e650, json
  0x7f97c60700f0
  liblognorm: 0/1:trying 'ipv4' parser for field 'ip', data 'UNKNOWN'
  liblognorm: parser lookup returns 0, pParsed 9
  liblognorm: 0: potential hit, trying subtree 0x7f97c606f050
  liblognorm: 9: enter parser, dag node 0x7f97c606f050, json
  0x7f97c60700f0
  liblognorm: 9/1:trying 'whitespace' parser for field '(null)', data
  'UNKNOWN'
  liblognorm: parser lookup returns 0, pParsed 1
  liblognorm: 9: potential hit, trying subtree 0x7f97c606f180
  liblognorm: 10: enter parser, dag node 0x7f97c606f180, json
  0x7f97c60700f0
  liblognorm: 10/1:trying 'word' parser for field 'ident', data 'UNKNOWN'
  liblognorm: parser lookup returns 0, pParsed 1
  liblognorm: 10: potential hit, trying subtree 0x7f97c606f3e0
  liblognorm: 11: enter parser, dag node 0x7f97c606f3e0, json
  0x7f97c60700f0
  liblognorm: 11/1:trying 'whitespace' parser for field '(null)', data
  'UNKNOWN'
  liblognorm: parser lookup returns 0, pParsed 1
  liblognorm: 11: potential hit, trying subtree 0x7f97c606f610
  liblognorm: 12: enter parser, dag node 0x7f97c606f610, json
  0x7f97c60700f0
  liblognorm: 12/1:trying 'word' parser for field 'user', data 'UNKNOWN'
  liblognorm: parser lookup returns 0, pParsed 1
  liblognorm: 12: potential hit, trying subtree 0x7f97c606f780
  liblognorm: 13: enter parser, dag node 0x7f97c606f780, json
  0x7f97c60700f0
  liblognorm: 13/1:trying 'literal' parser for field '(null)', data ' ['
  liblognorm: parser lookup returns 0, pParsed 2
  liblognorm: 13: potential hit, trying subtree 0x7f97c606f820
  liblognorm: 15: enter parser, dag node 0x7f97c606f820, json
  0x7f97c60700f0
  liblognorm: 15/1:trying 'char-to' parser for field 'date', data
  'UNKNOWN'
  liblognorm: parser lookup returns 0, pParsed 26
  liblognorm: 15: potential hit, trying subtree 0x7f97c606fc30
  liblognorm: 41: enter parser, dag node 0x7f97c606fc30, json
  0x7f97c60700f0
  liblognorm: 41/1:trying 'literal' parser for field '(null)', data '] "'
  liblognorm: parser lookup returns 0, pParsed 3
  liblognorm: 41: potential hit, trying subtree 0x7f97c606fdc0
  liblognorm: 44: enter parser, dag node 0x7f97c606fdc0, json
  0x7f97c60700f0
  liblognorm: 44/1:trying 'word' parser for field 'method', data 'UNKNOWN'
  liblognorm: parser lookup returns 0, pParsed 7
  liblognorm: 44: potential hit, trying subtree 0x7f97c6070050
  liblognorm: 51: enter parser, dag node 0x7f97c6070050, json
  0x7f97c60700f0
  liblognorm: 51/1:trying 'whitespace' parser for field '(null)', data
  'UNKNOWN'
  liblognorm: parser lookup returns 0, pParsed 1
  liblognorm: 51: potential hit, trying subtree 0x7f97c60703c0
  liblognorm: 52: enter parser, dag node 0x7f97c60703c0, json
  0x7f97c60700f0
  liblognorm: 52/1:trying 'char-to' parser for field 'request', data
  'UNKNOWN'
  liblognorm: parser lookup returns 0, pParsed 1
  liblognorm: 52: potential hit, trying subtree 0x7f97c6070530
  liblognorm: 53: enter parser, dag node 0x7f97c6070530, json
  0x7f97c60700f0
  liblognorm: 53/1:trying 'literal' parser for field '(null)', data '
  HTTP/'
  liblognorm: parser lookup returns 0, pParsed 6
  liblognorm: 53: potential hit, trying subtree 0x7f97c6070bd0
  liblognorm: 59: enter parser, dag node 0x7f97c6070bd0, json
  0x7f97c60700f0
  liblognorm: 59/1:trying 'float' parser for field 'httpversion', data
  'UNKNOWN'
  liblognorm: parser lookup returns 0, pParsed 3
  liblognorm: 59: potential hit, trying subtree 0x7f97c6070d50
  liblognorm: 62: enter parser, dag node 0x7f97c6070d50, json
  0x7f97c60700f0
  liblognorm: 62/1:trying 'literal' parser for field '(null)', data '"'
  liblognorm: parser lookup returns 0, pParsed 1
  liblognorm: 62: potential hit, trying subtree 0x7f97c6070f90
  liblognorm: 63: enter parser, dag node 0x7f97c6070f90, json
  0x7f97c60700f0
  liblognorm: 63/1:trying 'whitespace' parser for field '(null)', data
  'UNKNOWN'
  liblognorm: parser lookup returns 0, pParsed 1
  liblognorm: 63: potential hit, trying subtree 0x7f97c6071200
  liblognorm: 64: enter parser, dag node 0x7f97c6071200, json
  0x7f97c60700f0
  liblognorm: 64/1:trying 'number' parser for field 'response', data
  'UNKNOWN'
  liblognorm: parser lookup returns 0, pParsed 3
  liblognorm: 64: potential hit, trying subtree 0x7f97c6071350
  liblognorm: 67: enter parser, dag node 0x7f97c6071350, json
  0x7f97c60700f0
  liblognorm: 67/1:trying 'whitespace' parser for field '(null)', data
  'UNKNOWN'
  liblognorm: parser lookup returns 0, pParsed 1
  liblognorm: 67: potential hit, trying subtree 0x7f97c60716e0
  liblognorm: 68: enter parser, dag node 0x7f97c60716e0, json
  0x7f97c60700f0
  liblognorm: 68/1:trying 'word' parser for field 'bytes', data 'UNKNOWN'
  liblognorm: parser lookup returns 0, pParsed 3
  liblognorm: 68: potential hit, trying subtree 0x7f97c6071a80

so far, same as above

  liblognorm: 71: enter parser, dag node 0x7f97c6071a80, json
  0x7f97c60700f0
  liblognorm: offs 71, strLen 78, isTerm 1
  liblognorm: 71 returns 0, pParsedTo 0, parsedTo 0
  liblognorm: 68: subtree returns 0, parsedTo 71
  liblognorm: 68: parser matches at 68
  liblognorm: parsedTo 71, *pParsedTo 71
  liblognorm: offs 68, strLen 78, isTerm 0
  liblognorm: 68 returns 0, pParsedTo 71, parsedTo 71
  liblognorm: 67: subtree returns 0, parsedTo 68
  liblognorm: 67: parser matches at 67
  liblognorm: parsedTo 68, *pParsedTo 71
  liblognorm: offs 67, strLen 78, isTerm 0
  liblognorm: 67 returns 0, pParsedTo 71, parsedTo 68
  liblognorm: 64: subtree returns 0, parsedTo 67
  liblognorm: 64: parser matches at 64
  liblognorm: parsedTo 67, *pParsedTo 71
  liblognorm: offs 64, strLen 78, isTerm 0
  liblognorm: 64 returns 0, pParsedTo 71, parsedTo 67
  liblognorm: 63: subtree returns 0, parsedTo 64
  liblognorm: 63: parser matches at 63
  liblognorm: parsedTo 64, *pParsedTo 71
  liblognorm: offs 63, strLen 78, isTerm 0
  liblognorm: 63 returns 0, pParsedTo 71, parsedTo 64
  liblognorm: 62: subtree returns 0, parsedTo 63
  liblognorm: 62: parser matches at 62
  liblognorm: parsedTo 63, *pParsedTo 71
  liblognorm: offs 62, strLen 78, isTerm 0
  liblognorm: 62 returns 0, pParsedTo 71, parsedTo 63
  liblognorm: 59: subtree returns 0, parsedTo 62
  liblognorm: 59: parser matches at 59
  liblognorm: parsedTo 62, *pParsedTo 71
  liblognorm: offs 59, strLen 78, isTerm 0
  liblognorm: 59 returns 0, pParsedTo 71, parsedTo 62
  liblognorm: 53: subtree returns 0, parsedTo 59
  liblognorm: 53: parser matches at 53
  liblognorm: parsedTo 59, *pParsedTo 71
  liblognorm: offs 53, strLen 78, isTerm 0
  liblognorm: 53 returns 0, pParsedTo 71, parsedTo 59
  liblognorm: 52: subtree returns 0, parsedTo 53
  liblognorm: 52: parser matches at 52
  liblognorm: parsedTo 53, *pParsedTo 71
  liblognorm: offs 52, strLen 78, isTerm 0
  liblognorm: 52 returns 0, pParsedTo 71, parsedTo 53
  liblognorm: 51: subtree returns 0, parsedTo 52
  liblognorm: 51: parser matches at 51
  liblognorm: parsedTo 52, *pParsedTo 71
  liblognorm: offs 51, strLen 78, isTerm 0
  liblognorm: 51 returns 0, pParsedTo 71, parsedTo 52
  liblognorm: 44: subtree returns 0, parsedTo 51
  liblognorm: 44: parser matches at 44
  liblognorm: parsedTo 51, *pParsedTo 71
  liblognorm: offs 44, strLen 78, isTerm 0
  liblognorm: 44 returns 0, pParsedTo 71, parsedTo 51
  liblognorm: 41: subtree returns 0, parsedTo 44
  liblognorm: 41: parser matches at 41
  liblognorm: parsedTo 44, *pParsedTo 71
  liblognorm: offs 41, strLen 78, isTerm 0
  liblognorm: 41 returns 0, pParsedTo 71, parsedTo 44
  liblognorm: 15: subtree returns 0, parsedTo 41
  liblognorm: 15: parser matches at 15
  liblognorm: parsedTo 41, *pParsedTo 71
  liblognorm: offs 15, strLen 78, isTerm 0
  liblognorm: 15 returns 0, pParsedTo 71, parsedTo 41
  liblognorm: 13: subtree returns 0, parsedTo 15
  liblognorm: 13: parser matches at 13
  liblognorm: parsedTo 15, *pParsedTo 71
  liblognorm: offs 13, strLen 78, isTerm 0
  liblognorm: 13 returns 0, pParsedTo 71, parsedTo 15
  liblognorm: 12: subtree returns 0, parsedTo 13
  liblognorm: 12: parser matches at 12
  liblognorm: parsedTo 13, *pParsedTo 71
  liblognorm: offs 12, strLen 78, isTerm 0
  liblognorm: 12 returns 0, pParsedTo 71, parsedTo 13
  liblognorm: 11: subtree returns 0, parsedTo 12
  liblognorm: 11: parser matches at 11
  liblognorm: parsedTo 12, *pParsedTo 71
  liblognorm: offs 11, strLen 78, isTerm 0
  liblognorm: 11 returns 0, pParsedTo 71, parsedTo 12
  liblognorm: 10: subtree returns 0, parsedTo 11
  liblognorm: 10: parser matches at 10
  liblognorm: parsedTo 11, *pParsedTo 71
  liblognorm: offs 10, strLen 78, isTerm 0
  liblognorm: 10 returns 0, pParsedTo 71, parsedTo 11
  liblognorm: 9: subtree returns 0, parsedTo 10
  liblognorm: 9: parser matches at 9
  liblognorm: parsedTo 10, *pParsedTo 71
  liblognorm: offs 9, strLen 78, isTerm 0
  liblognorm: 9 returns 0, pParsedTo 71, parsedTo 10
  liblognorm: 0: subtree returns 0, parsedTo 9
  liblognorm: 0: parser matches at 0
  liblognorm: parsedTo 9, *pParsedTo 71
  liblognorm: offs 0, strLen 78, isTerm 0
  liblognorm: 0 returns 0, pParsedTo 71, parsedTo 9
  liblognorm: called CUSTOM PARSER '@apache_common', result 0, offs 0,
  *pParsed 0
  liblognorm: parser lookup returns 0, pParsed 71
  liblognorm: 0: potential hit, trying subtree 0x7f97c6071df0
  liblognorm: 71: enter parser, dag node 0x7f97c6071df0, json
  0x7f97c6071590
  liblognorm: 71/0:trying 'USER-DEFINED' parser for field '.', data
  'UNKNOWN'
  liblognorm: calling custom parser '@apache_combined'

  liblognorm: 71: enter parser, dag node 0x7f97c6070de0, json
  0x7f97c6072650
  liblognorm: 71/1:trying 'literal' parser for field '(null)', data '-'
  liblognorm: parser lookup returns -1000, pParsed 0
  liblognorm: parsedTo 0, *pParsedTo 71

is it a '-', no

  liblognorm: 71/1:trying 'whitespace' parser for field '(null)', data
  'UNKNOWN'
  liblognorm: parser lookup returns 0, pParsed 1
  liblognorm: 71: potential hit, trying subtree 0x7f97c6070c80

found whitespece (1 byte, now at position 712

  liblognorm: 72: enter parser, dag node 0x7f97c6070c80, json
  0x7f97c6072650
  liblognorm: 72/1:trying 'quoted-string' parser for field 'referrer',
  data 'UNKNOWN'
  liblognorm: parser lookup returns 0, pParsed 3
  liblognorm: 72: potential hit, trying subtree 0x7f97c60713e0

found referrer (3 bytes, now at position 75)

  liblognorm: 75: enter parser, dag node 0x7f97c60713e0, json
  0x7f97c6072650
  liblognorm: 75/1:trying 'whitespace' parser for field '(null)', data
  'UNKNOWN'
  liblognorm: parser lookup returns 0, pParsed 1
  liblognorm: 75: potential hit, trying subtree 0x7f97c6071770

found whitespace (1 byte, now at position 76)

  liblognorm: 76: enter parser, dag node 0x7f97c6071770, json
  0x7f97c6072650
  liblognorm: 76/1:trying 'quoted-string' parser for field
  'useragent', data 'UNKNOWN'
  liblognorm: parser lookup returns -1000, pParsed 0

did not find the field useragent, so backing up (probably end-of-line problem)

  liblognorm: parsedTo 0, *pParsedTo 0
  liblognorm: offs 76, strLen 78, isTerm 0
  liblognorm: 76 returns -1000, pParsedTo 0, parsedTo 0
  liblognorm: 75: subtree returns -1000, parsedTo 76
  liblognorm: 75 nonmatch, backtracking required, parsed to=76
  liblognorm: parsedTo 76, *pParsedTo 76
  liblognorm: offs 75, strLen 78, isTerm 0
  liblognorm: 75 returns -1000, pParsedTo 76, parsedTo 76
  liblognorm: 72: subtree returns -1000, parsedTo 75
  liblognorm: 72 nonmatch, backtracking required, parsed to=75
  liblognorm: parsedTo 75, *pParsedTo 76
  liblognorm: offs 72, strLen 78, isTerm 0
  liblognorm: 72 returns -1000, pParsedTo 76, parsedTo 75
  liblognorm: 71: subtree returns -1000, parsedTo 72
  liblognorm: 71 nonmatch, backtracking required, parsed to=72
  liblognorm: parsedTo 72, *pParsedTo 76
  liblognorm: offs 71, strLen 78, isTerm 0
  liblognorm: 71 returns -1000, pParsedTo 76, parsedTo 72
  liblognorm: called CUSTOM PARSER '@apache_combined', result -1000,
  offs 71, *pParsed 0
  liblognorm: parser lookup returns -1000, pParsed 5
  liblognorm: parsedTo 0, *pParsedTo 0
  liblognorm: offs 71, strLen 78, isTerm 0
  liblognorm: 71 returns -1000, pParsedTo 0, parsedTo 0
  liblognorm: 0: subtree returns -1000, parsedTo 71
  liblognorm: 0 nonmatch, backtracking required, parsed to=71
  liblognorm: parsedTo 71, *pParsedTo 71
  liblognorm: offs 0, strLen 78, isTerm 0
  liblognorm: 0 returns -1000, pParsedTo 71, parsedTo 71
  liblognorm: final result for normalizer: parsedTo 71, endNode (nil)
  liblognorm: DONE, final return is -1000

undoing things.

  normalized: '{ "originalmsg": "127.0.0.1 - - [17\/Mar\/2016:18:15:24
  +0100] \"OPTIONS \/ HTTP\/1.1\" 403 205 \"-\" \"-", "unparsed-data":
  " \"-\" \"-" }'
  { "originalmsg": "127.0.0.1 - - [17\/Mar\/2016:18:15:24 +0100]
  \"OPTIONS \/ HTTP\/1.1\" 403 205 \"-\" \"-", "unparsed-data": "
  \"-\" \"-" }

so it matched @apache_common, but didn't match @apache_combined, so the text ' "-" "-"'' is the unparsed data.

when you use custom types, they are treated as a single entity in the reporting, this is why when you are testing things, you should undo the types so that you can more easily see what's happening

I would have changed the ruleset to be:

version=2
rule=:%[
      {"type":"ipv4", "name":"ip"},
      {"type":"whitespace"},
      {"type":"word", "name":"ident"},
      {"type":"whitespace"},
      {"type":"word", "name":"user"},
      {"type":"literal", "text":" ["},
      {"type":"char-to", "name":"date", "extradata":"]"},
      {"type":"literal", "text":"] \""},
      {"type":"word", "name":"method"},
      {"type":"whitespace"},
      {"type":"char-to", "name":"request", "extradata":" "},
      {"type":"literal", "text":" HTTP/"},
      {"type":"float", "name":"httpversion"},
      {"type":"literal", "text":"\""},
      {"type":"whitespace"},
      {"type":"number", "name":"response"},
      {"type":"whitespace"},
      {"type":"word", "name":"bytes"}
      {"type":"whitespace"},
      {"type":"quoted-string","name":"referrer"},
      {"type":"whitespace"},
      {"type":"quoted-string","name":"useragent"}
 ]%

and run the test against that

the following stuff is cleanup that you normally ignore

David Lang
_______________________________________________
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow https://twitter.com/rgerhards
NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad of 
sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you DON'T LIKE 
THAT.

Reply via email to