Fiabilité de logstash en charge?

Elastic In Your Native Tongue Discussions en français
1

Bonjour,

un peu trop souvent, logstash n'arrive pas à traiter convenablement ce qu'il reçoit en entrée, et ainsi fausse les résultats dans elastic.
Par exemple, je lui donne ceci :

root@s00vl9925220:/apps/toolboxes/backup_restore/logs/temp # cat tiths532.crs.160210.csv
tiths532;TSM-ARZ203;2016/02/10;02:25:32;00:24:59;607319;10690;4;1226.82;0%;4884.48;Voir fichier d rreurs;;TSM_backup_INCR_APPLI_20160210_3378.log;;INCR_APPLI;dsm_BT.opt;v4.0.0
tiths532;TSM-ARZ203;2016/02/10;02:30:01;00:03:25;606922;90;3;33.41;0%;181.68;Voir fichier derreurs;;TSM_backup_INCR_APPLI_20160210_3378.log;;INCR_APPLI;dsm_BT.opt;v4.0.0

le filtre qui est appliqué :

 if [source] =~ "backup_restore" {
            if [type] == "crs" {
              # cas pour les fichiers crs
              csv {
                  separator => ";"
                    columns => [ "host","instance","date_injection","heure_injection","duree","inspected","backup","failed","transfert_time","taux_cp","volume","sauve","classarch","log","app_save","save_mode","dsm_opt","version_tbx" ]
              }
            }
    if [type] == "err" {
      # cas pour les fichiers err
      csv {
          separator => ";"
            columns => [ "host","instance","date_injection","heure_injection","codeans","poids","fichier_err" ]
      }
    }

  date {
              match => [ "date_injection", "YYYY/MM/DD", "YY/MM/DD" ]
    }
    if "_dateparsefailure" in [tags] {
      drop { }
    }

    mutate {
          lowercase => [ "host" ]
               gsub => [ "date_injection", "/", "-" ]
          add_field => { "timestamp" => "%{date_injection} %{heure_injection}" }
       remove_field => [ "date_injection","heure_injection" ]
    }
  }

  date {
             match => [ "timestamp", "YYYY-MM-dd HH:mm:ss" ]
          timezone => "Europe/Paris"
            target => "@timestamp"
      remove_field => [ "timestamp" ]
  }

  mutate {
      remove_field => [ "[beat]","input_type","offset" ]
  }

et la log debug :

{
       "message" => ".0.2",
      "@version" => "1",
    "@timestamp" => "2016-02-10T14:10:44.678Z",
         "count" => 1,
        "fields" => nil,
        "source" => "/apps/toolboxes/backup_restore/logs/s00va9933715.crs.160209.csv",
          "type" => "crs",
          "host" => ".0.2",
          "tags" => [
        [0] "beats_input_codec_plain_applied",
        [1] "_dateparsefailure"
    ],
     "timestamp" => "%{date_injection} %{heure_injection}"
}

Un traitement normal donnerait ceci :

{
"message" => "s00va9933715;TSM-ARZ108;2016/02/09;07:06:04;00:01:12;15;15;0;70.96;0%;0.285547;;ARCH01M;TSM_archive_MBA1FRP0_30J_ListOra_20160209_24838318.log;;Ora_MBA1FRP0;dsm.opt;v5.0.2",
          "@version" => "1",
        "@timestamp" => "2016-02-09T06:06:04.000Z",
             "count" => 1,
            "fields" => nil,
            "source" => "/apps/toolboxes/backup_restore/logs/s00va9933715.crs.160209.csv",
              "type" => "crs",
              "host" => "s00va9933715",
              "tags" => [
        [0] "beats_input_codec_plain_applied"
    ],
          "instance" => "TSM-ARZ108",
             "duree" => "00:01:12",
         "inspected" => "15",
            "backup" => "15",
            "failed" => "0",
    "transfert_time" => "70.96",
           "taux_cp" => "0%",
            "volume" => "0.285547",
             "sauve" => nil,
         "classarch" => "ARCH01M",
               "log" => "TSM_archive_MBA1FRP0_30J_ListOra_20160209_24838318.log",
          "app_save" => nil,
         "save_mode" => "Ora_MBA1FRP0",
           "dsm_opt" => "dsm.opt",
       "version_tbx" => "v5.0.2"
}

J'ai lotissé par lot de 2500/3000 logs environ, soit un total de 26847 logs en tout. J'ai 5% de rejet (+5000 hits). J'ai bien des logs dont le contenu ne matche pas, mais sur du contenu OK, je vois pas pourquoi ça devrait claquer.
La JVM pèse 500M, peut-être n'est pas assez ?

D'ailleurs j'ai beau avoir un drop dans le filter

if "_dateparsefailure" in [tags] {
  drop { }
}

ou un test dans l'output, c'est quand même envoyé à elastic ...

  if [type] == "crs" or [type] == "err" {
    if "_dateparsefailure" not in [tags] or "_csvparsefailure" not in [tags] {
      elasticsearch {
                hosts => "10.255.55.91"
               action => "index"
                index => "sibr"
        document_type => "%{[@metadata][type]}"
      }
    }

Any idea ??

2

Peux-tu formatter correctement ton code ? C'est dur à lire (et donne peu envie à vrai dire).

Souvent je le fais moi même mais là, y'en a trop.

3

J'ai du mal avec les balises :confused: Je fais ça de suite :wink:

Edit : voila c'est un peu plus lisible maintenant !

4

Étrange. Tu pourrais faire un cas de test complet avec une ligne qui ne passe pas ?

Je suppose que c'est systématique, non ?

5

Bonjour @dadoonet,
effectivement c'est systématique. Pour certaines logs qui passent pas j'ai bien une explication (log mal formatée et carrément le contenu de la log erroné), mais pour d'autres je n'ai pas d'explication.
Cela semble carrément aléatoire pour ce dernier cas qui plus est.

Je vais relancer un jeu de test avec seulement les fichiers en erreur, ça risque de me prendre un peu de temps par contre. Je tiens au courant bien évidemment.

6

C'est bien ce que je craignais, il est difficile d'obtenir 2 fois la même erreur sur la même log.
Si je reprends le fichier qont je parle dans le post initial, il est parfaitement passé ce matin.

{
            "message" => "tiths532;TSM-ARZ203;2016/02/10;02:25:32;00:24:59;607319;10690;4;1226.82;0%;4884.48;Voir fichier d erreurs;;TSM_backup_INCR_APPLI_20160210_3378.log;;INCR_APPLI;dsm_BT.opt;v4.0.0",
           "@version" => "1",
         "@timestamp" => "2016-02-10T01:25:32.000Z",
              "count" => 1,
             "fields" => nil,
             "source" => "/apps/toolboxes/backup_restore/logs/tiths532.crs.160210.csv",
               "type" => "crs",
               "host" => "tiths532",
               "tags" => [
        [0] "beats_input_codec_plain_applied"
    ],
           "instance" => "TSM-ARZ203",
     "date_injection" => "2016-02-10",
    "heure_injection" => "02:25:32",
              "duree" => "00:24:59",
          "inspected" => "607319",
             "backup" => "10690",
             "failed" => "4",
     "transfert_time" => "1226.82",
            "taux_cp" => "0%",
             "volume" => "4884.48",
              "sauve" => "Voir fichier d erreurs",
          "classarch" => nil,
                "log" => "TSM_backup_INCR_APPLI_20160210_3378.log",
           "app_save" => nil,
          "save_mode" => "INCR_APPLI",
            "dsm_opt" => "dsm_BT.opt",
        "version_tbx" => "v4.0.0",
          "timestamp" => "2016-02-10 02:25:32"
}
{
            "message" => "tiths532;TSM-ARZ203;2016/02/10;02:30:01;00:03:25;606922;90;3;33.41;0%;181.68;Voir fichier d erreurs;;TSM_backup_INCR_APPLI_20160210_3378.log;;INCR_APPLI;dsm_BT.opt;v4.0.0",
           "@version" => "1",
         "@timestamp" => "2016-02-10T01:30:01.000Z",
              "count" => 1,
             "fields" => nil,
             "source" => "/apps/toolboxes/backup_restore/logs/tiths532.crs.160210.csv",
               "type" => "crs",
               "host" => "tiths532",
               "tags" => [
        [0] "beats_input_codec_plain_applied"
    ],
           "instance" => "TSM-ARZ203",
     "date_injection" => "2016-02-10",
    "heure_injection" => "02:30:01",
              "duree" => "00:03:25",
          "inspected" => "606922",
             "backup" => "90",
             "failed" => "3",
     "transfert_time" => "33.41",
            "taux_cp" => "0%",
             "volume" => "181.68",
              "sauve" => "Voir fichier d erreurs",
          "classarch" => nil,
                "log" => "TSM_backup_INCR_APPLI_20160210_3378.log",
           "app_save" => nil,
          "save_mode" => "INCR_APPLI",
            "dsm_opt" => "dsm_BT.opt",
        "version_tbx" => "v4.0.0",
          "timestamp" => "2016-02-10 02:30:01"
}

Comment bien utiliser drop ? J'ai fait ceci pour ne pas injecter du contenu non pertinent :

    if "_csvparsefailure" in [tags] {
      drop { }
    }

    # Pour ne conserver que les lignes débutant par un nom de serveur
    if [message] =~ /^[^pts][\w]+$/ {
      drop { }
    }

    # Pour gerer les cas ou la date est au format YY/MM/DD au lieu de YYYY/MM/DD
    date {
              match => [ "date_injection", "YYYY/MM/DD", "YY/MM/DD" ]
    }

    if "_dateparsefailure" in [tags] {
      drop { }
    }

mais force est de constater que cela ne fonctionne pas :frowning:

Par exemple, je me retrouve avec des logs un peu naze et ça passe quand-même :

root@s00vl9925220:/apps/backup_restore/logs/temp # cat pars01015955.err.160208.csv


    Directory: C:\apps\backup_restore\tmp


Mode                LastWriteTime     Length Name
----                -------------     ------ ----
-a---        08/02/2016     03:01          0 err_ans.tmp


pars01015955;TSM-ERROR;2016/02/08;03:00:09;ANS????S;;;

Qui donne (je ne mets qu'une ligne traitée, sachant que la dernière est traitée) :

{
       "message" => "-a---        08/02/2016     03:01          0 err_ans.tmp                       ",
      "@version" => "1",
    "@timestamp" => "2016-02-11T09:23:51.820Z",
         "count" => 1,
        "fields" => nil,
        "source" => "/apps/toolboxes/backup_restore/logs/pars01015955.err.160208.csv",
          "type" => "err",
          "host" => "-a---        08/02/2016     03:01          0 err_ans.tmp                       ",
          "tags" => [
        [0] "beats_input_codec_plain_applied",
        [1] "_dateparsefailure"
    ],
     "timestamp" => "%{date_injection} %{heure_injection}"
}
7

Ping @colinsurprenant au cas où... :stuck_out_tongue: