[RESOLU] Aide sur Grok (problème d'encodage)

[C_H (Charles-Henri Boust)]

Bonjour,

comment feriez-vous pour parser une log dont la syntaxe est ainsi, avec grok :

[AAAA-MM-JJ HH:MM:SS][machine][host][login][userElevPrivs][nomTbx][entree] message

Ex. :

[2016-01-29 11:45:48][S00V09951584][parw00584571][l348579][root][flow][MENU_flow] Execution du menu flow
[2016-01-29 11:46:22][S00V09951584][parw00183663][l348579][was][database][SCRIPT] Execution de ld6fkve0.ksh
[2016-01-29 11:47:11][S00V09951584][parw00584571][l196920][was][ ][MENU] Execution du menu chapeau
[2016-01-29 11:47:28][S00V09951584][parw00183663][root][cft][backup_restore][MENU_backup_restore] Execution du menu backup_restore
[2016-01-29 11:47:41][S00V09951584][s00v0991584][root][root][scheduler][MENU_scheduler] Execution du menu scheduler
[2016-01-29 11:48:21][S00V09951584][parw00584571][root][cft][backup_restore][SCRIPT] Execution de btsauve.ksh

J'ai commencé à écrire ceci mais je bute sur les crochets, c'est bête mais je ne trouve pas les bons exemples

input {
file {
type => "log"
path => "D:/apps/toolboxes/logs/realtime.log"
start_position => "beginning"
}
}

filter {
grok {
match => ["message", "%{TIMESTAMP_ISO8601:log_timestamp} %{WORD:serveur} %{WORD:source} %{WORD:login} %{WORD:user} %{WORD:tbxname} %{WORD:entree} %{GREEDYDATA:log_message}"]
}
date {
match => [ "log_timestamp", "YYYY-MM-dd HH:mm:ss" ]
}
mutate {
remove_field => [ "log_timestamp"]
}
}

output {
stdout {}
elasticsearch {
host => "10.255.55.101"
protocol => "http"
port => 9200
}
}

Si vous avez une piste pour m'aider à mieux comprendre le fonctionnement de Grok

Merci !

CH

[dadoonet (David Pilato)]

Je n'ai pas la réponse mais j'adore utiliser ça quand je dois construire un pattern GROK: http://grokconstructor.appspot.com/

[C_H (Charles-Henri Boust)]

Merci @dadoonet pour le lien, je regarder ça.
Edit : voici ce que j'ai obtenu :

\[%{TIMESTAMP_ISO8601:log_timestamp}\](\[%{WORD:serveur}\])(\[%{WORD:host}\])(\[%{WORD:login}\])(\[%{WORD:user}\])(\[%{WORD:tbx_name}\])(\[%{WORD:entree}\])\s%{GREEDYDATA:log_message}

[C_H (Charles-Henri Boust)]

Pour une raison que j'ignore, tous les champs ne remontent pas dans Elastic.
Voici ce qui ce que je vois dans Kibana :

message:[2016-01-29 13:58:49][S00V09951584][parw00140289][l203333][was][database][MENU_database] Execution du menu database @version:1@timestamp:January 29th 2016, 14:04:43.496 host:s00v09951584 path:D:/apps/toolboxes/logs/realtime.logtype:logtags:_grokparsefailure_id:AVKNfGGlK2aDOvShGE2y_type:log_index:toolboxes_score:1

De plus, comment faire comprendre à ES que j'ai un timestamp dans ma log et donc que sa valeur de @timestamp soit celle-ci ?

[dadoonet (David Pilato)]

J'ignore ce que veut dire ce log mais en tout cas _grokparsefailure montre qu'à un moment le grok se passe mal.

[C_H (Charles-Henri Boust)]

Oui effectivement j'ai remarqué que mon pattern n'était pas 100% compatible, en effet j'ai un champ qui peut être NULL à un moment donné ([nomTbx]). Il faut que je revois cela.

C'est une "tracelog" pour suivre l'activité de menus/scripts que l'on développe, afin d'avoir un indicateur d'utilisation.

[C_H (Charles-Henri Boust)]

J'ai remédié à mon problème de log, tous les champs sont remplis, le pattern validé par les liens fournis au dessus, mais rien n'y fait, je n'arrive toujours pas à avoir plus d'information dans elastic, mes champs restent désespéremment vide.

[dadoonet (David Pilato)]

Et est-ce que tu vois passer des choses dans "stdout"?

[C_H (Charles-Henri Boust)]

Non rien de particulier, un timestamp, le nom de la machine sur lequel logstash tourne pour l'occasion (une VM en W2012 R2), et suivi de ça la ligne qui est lue de mon fichier de log (qui est alimentée en permanence par un script powershell dans le cadre de mon use-case).

[dadoonet (David Pilato)]

Elasticsearch indexera la même chose.

Sans doute un pb d'input ?

[C_H (Charles-Henri Boust)]

Probablement. Je testerais lundi une autre méthode de chargement pour débugger tout ça.
Bon week-end @dadoonet

[C_H (Charles-Henri Boust)]

Bonjour @dadoonet ,

pour compléter le sujet, vVoici ce que j'ai en ouput :

2016-02-01T08:10:47.650Z s00v09951584  [ 2 0 1 6 - 0 2 - 0 1   0 9 : 1 0 : 4 7 ] [ S 0 0 V 0 9 9 5 1 5 8 4 ] [ p a r w 0 0 6 37 4 2 5 ] [ l 3 4 8 5 7 9 ] [ r o o t ] [ e x p l o i t ] [ S C R I P T ]   E x e c u t i o n   d e   b e 3 m m c 6 0 . k s h

Et le rendu dans kibana :

Mais ça c'est depuis un serveur Windows où je génère cette log.
J'ai tenté une expérience, depuis un Linux, avec un LS configuré pour taper le même index Elastic, configuration identique au détail près, l'input (stdin). Voici le résultat :

logstash@s00vl9931488:/apps/logstash/logstash-2.1.1 # ^C       echo "[2016-02-01 09:28:54][S00V09951584][parw00637425][l468364][oracle][database][SCRIPT] Execution de kljskjbs.ksh" | bin/logstash -f conf/logstash_toolboxes.conf
Settings: Default filter workers: 1
Logstash startup completed
{
       "message" => [
        [0] "[2016-02-01 09:28:54][S00V09951584][parw00637425][l468364][oracle][database][SCRIPT] Execution de kljskjbs.ksh",
        [1] "Execution de kljskjbs.ksh"
    ],
      "@version" => "1",
    "@timestamp" => "2016-02-01T08:28:54.000Z",
          "type" => "log",
          "host" => "s00vl9931488.fr.net.intra",
     "timestamp" => "2016-02-01 09:28:54",
       "serveur" => "S00V09951584",
      "hostFrom" => "parw00637425",
         "login" => "l468364",
          "user" => "oracle",
      "tbx_name" => "database",
        "entree" => "SCRIPT"
}
Logstash shutdown completed

Et comme attendu, dans Kibana, je retrouve bien ce que j'attends :

Que faut-il en déduire ?

Bonne journée

Charles-Henri

[dadoonet (David Pilato)]

Ou la la! Y'a même pas un truc qui ressemble à:

Settings: Default filter workers: 1
Logstash startup completed
{

Dans l'output sous windows?

[C_H (Charles-Henri Boust)]

Si, heureusement !

D:\apps\toolboxes\chb\logstash-2.1.1\bin>logstash.bat -f ../conf/toolboxes.conf

io/console not supported; tty will not be manipulated
Settings: Default filter workers: 1
Logstash startup completed
2016-02-01T10:07:40.608Z s00v09951584  [ 2 0 1 6 - 0 2 - 0 1   1 1 : 0 6 : 0 3 ]
 [ S 0 0 V 0 9 9 5 1 5 8 4 ] [ p a r w 0 0 1 4 0 2 8 9 ] [ l 1 9 6 9 2 0 ] [ c f t ] [ f l o w ] [ M E N U _ f l o w ]   E x e c u t i o n   d u   m e n u   f l o w
2016-02-01T10:07:40.608Z s00v09951584  [ 2 0 1 6 - 0 2 - 0 1   1 1 : 0 6 : 4 7 ] [ S 0 0 V 0 9 9 5 1 5 8 4 ] [ s 0 0 v 0 9 9 1 5 8 4 ] [ l 4 6 8 3 6 4 ] [ o r a c l e ] [ d a t a b a s e ] [ M E N U _ d a t a b a s e ]   E x e c u t i o n d u   m e n u   d a t a b a s e
2016-02-01T10:07:40.608Z s00v09951584  [ 2 0 1 6 - 0 2 - 0 1   1 1 : 0 6 : 5 7 ] [ S 0 0 V 0 9 9 5 1 5 8 4 ] [ p a r w 0 0 1 4 0 2 8 9 ] [ l 4 6 8 3 6 4 ] [ r o o t ] [ e x p l o i t ] [ M E N U _ e x p l o i t ]   E x e c u t i o n   d u m e n u   e x p l o i t

[dadoonet (David Pilato)]

Mais le fichier ../conf/toolboxes.conf est différent du fichier que tu utilises sous Linux conf/logstash_toolboxes.conf, non? Il y a quoi dedans ?

[C_H (Charles-Henri Boust)]

La conf Linux :

logstash@s00vl9931488:/apps/logstash/logstash-2.1.1/conf # cat logstash_toolboxes.conf
input {
  stdin {
    type => "log"
  }
}

filter {
  grok {
    match => [ "message", "\[%{TIMESTAMP_ISO8601:timestamp}\](\[%{WORD:serveur}\])(\[%{WORD:hostFrom}\])(\[%{WORD:login}\])(\[%{WORD:user}\])(\[%{WORD:tbx_name}\])(\[%{WORD:entree}\])\s%{GREEDYDATA:message}" ]
  }
        date {
                match => [ "timestamp", "YYYY-MM-dd HH:mm:ss" ]
                timezone => "Europe/Paris"
                target => "@timestamp"
        }

}

output {
  elasticsearch {
    hosts => "10.255.55.101"
    action => "index"
    index => "toolboxes"
  }

  stdout {
    codec => rubydebug
  }
}

La conf sous Windows :

input {
    file {
        type => "log"
        path => "D:/apps/toolboxes/logs/realtime.log"
        start_position => "beginning"
    }
}

filter {
  grok {
    match => [ "message", "\[%{TIMESTAMP_ISO8601:timestamp}\](\[%{WORD:serveur}\])(\[%{WORD:hostFrom}\])(\[%{WORD:login}\])(\[%{WORD:user}\])(\[%{WORD:tbx_name}\])(\[%{WORD:entree}\])\s%{GREEDYDATA:message}" ]
  }
    date {
        match => [ "timestamp", "YYYY-MM-dd HH:mm:ss" ]
           timezone => "Europe/Paris"
            target => "@timestamp"
    }    

}

output {
    stdout {}
    elasticsearch {
        hosts => "10.255.55.101"
            action => "index"
            index => "toolboxes"
    }
}

Seul l'input est différent, d'ailleurs j'ai fait un copié/collé de la conf sous Windows vers celle sous Linux !

[dadoonet (David Pilato)]

On voit bien que c'est pas un copier-coller. Regarde l'ordre de l'output.

Peux-tu faire un test avec input stdin, filter vide et output stdout (codec json)?

Puis juste taper "Hello " et poster ce que ça donne?

[C_H (Charles-Henri Boust)]

Bien remarqué, il me semblait avoir fait le copié/collé, mais c'était seulement le filter ...

Le test, sous Linux :

logstash@s00vl9931488:/apps/logstash/logstash-2.1.1 # echo "Hello" | bin/logstash -f conf/test.conf
Settings: Default filter workers: 1
Logstash startup completed
{
"message":"Hello",
"@version":"1",
"@timestamp":"2016-02-01T12:31:20.494Z",
"host":"s00vl9931488.fr.net.intra"
}
Logstash shutdown completed

Sous Windows :

D:\apps\toolboxes\chb\logstash-2.1.1\bin>echo "Hello" | logstash -f ../conf/test.conf
io/console not supported; tty will not be manipulated
Settings: Default filter workers: 1
Logstash startup completed
{
"message":""Hello" \r",
"@version":"1",
"@timestamp":"2016-02-01T12:35:12.227Z",
"host":"s00v09951584"
}
Logstash shutdown completed

[dadoonet (David Pilato)]

Donc c'est bien.

Maintenant enrichis petit à petit cette structure avec le filtre sur Linux puis Windows.

[C_H (Charles-Henri Boust)]

Merci @dadoonet pour ton accompagnement !

Le problème ne vient pas du grok mais plutôt du fichier de log. Voici ce qui est lu par LS (codec rubydebug, j'ai tronqué volontairement "message" c'est interminable sinon.) :

(...)
{
       "message" => "\u0000[\u00002\u00000\u00001\u00006\u0000-\u00000\u00002\u0000-\u00000\u00001\u0000
      "@version" => "1",
    "@timestamp" => "2016-02-01T13:36:23.552Z",
          "host" => "s00v09951584",
          "path" => "D:/apps/toolboxes/logs/realtime.log",
          "type" => "log",
          "tags" => [
        [0] "_grokparsefailure"
    ]
}
(...)

Je n'ai plus qu'à regarder pourquoi LS ne lit pas le fichier correctement (le fichier est parfaitement lisible avec un notepad!).