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

C_H · January 29, 2016, 10:52am

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 · January 29, 2016, 11:08am

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 · January 29, 2016, 11:42am

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 · January 29, 2016, 1:23pm

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 · January 29, 2016, 2:09pm

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

C_H · January 29, 2016, 2:23pm

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 · January 29, 2016, 4:04pm

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 · January 29, 2016, 5:08pm

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

C_H · January 29, 2016, 7:06pm

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 · January 29, 2016, 7:25pm

Elasticsearch indexera la même chose.

Sans doute un pb d'input ?

C_H · January 29, 2016, 7:43pm

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

C_H · February 1, 2016, 8:32am

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 · February 1, 2016, 9:07am

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 · February 1, 2016, 10:08am

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 · February 1, 2016, 10:21am

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 · February 1, 2016, 10:32am

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 · February 1, 2016, 11:52am

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 · February 1, 2016, 12:39pm

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 · February 1, 2016, 1:14pm

Donc c'est bien.

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

C_H · February 1, 2016, 1:43pm

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!).