Problème avec Aggregate

Bonjour,

J'ai un bug qui persiste en lien avec l'aggregate.

Description du problème initial : j'ai des logs de types request et d'autres de type response. Les logs ne se succèdent pas, entre ces deux requêtes il y a toujours d'autres logs. j'ai besoin de calculer la durée de traitement, qui est la date de la request - la date de la response.

La solution que j'ai mise en place est la suivante :

if [request]
{ aggregate 
                    { 
                        task_id => "%{RequestId}"
                        code =>  "  map['request-time'] = event.get('request-time')"
                        map_action => "create"
                    }
)

if [response]
{
aggregate 
	{                
	task_id => "%{RequestId}"
	code => "event.set('request-time', map['request-time'])"
	map_action => "update"
	end_of_task => true
	timeout => 30
   	timeout_tags => ['_aggregatetimeout']
	}
}

Je récupère la request-time et je l'ajoute au log de reponse pour ensuite faire un calcul simple à l'aide de ruby ( service-time = request-time - response-time)

les logs sont de ce format :

2020-01-17 00:04:01,259 INFO  [lean.kernel.impl.utils.PayloadLoggerImpl] (default task-91) 
LEAN-REQUEST > Service : LoginService {" RequestHeader" : { "Date" : "Fri Jan 17 00:04:01 WET 2020",  "SessionId" : "", "RequestId" : "157921" } 

2020-01-17 00:04:13,098 ERROR [lean.kernel.impl.dao.controls.MessageDaoImpl] (default task-91) WARNING/Error : FIND_BY_CODE  >> Table : MESSAGE >> Code = app_release_control  NOT FOUND 

2020-01-17 00:04:13,098 INFO  [lean.kernel.impl.utils.PayloadLoggerImpl] (default task-91) 
LEAN-RESPONSE > Service : LoginService {" ResponseHeader" : { "Date" : "Fri Jan 17 00:04:13 WET 2020",  "SessionId" : "", "RequestId" : "157921", "Response" : "Declined" } } 

Sauf que le problème est que sur des petites quantités de logs ça fonctionne très bien mais sur des grandes quantités, il arrive qu'un moment il ne calcule pas le service time parceque il ne récupère pas la request-time du map. J'ai une perte de presque 10% (c’est-à-dire que le calcul est fait correctement sur 90% des logs et n'est pas fait du tout sur les 10%).

Aussi quand j'ai varié le timeout, le nombre de logs non traités varie (parfois, c'est plus que 10% parfois c'est moins, 5%, 6% mais jamais moins)

Ps : quand j'isole les logs non traités et je les teste séparément le service-time est calculé, en sachant que la requestId est une clé unique.

Je vous remercie par avance pour vos réponses.

Je pense que @fbaligand peut t'aider comme il a écrit ce code. :grin:

Ne serait-ce pas dû au timeout ?

Je vais je crois lui demander parcque c'est un vrai casse tête pour moi :slight_smile:

Peut-être le timeout... mais du coup il faudrait le supprimer, (c'est ce que j'ai fait ... mais ça ne marche pas); mettre un timeout en particulier ? je ne pense pas que c'est aussi simple de définir le bon timeout..

Bonjour,

J'ai 2 conseils pour toi :

  • tout d'abord le "timeout" est le temps au bout duquel la map est purgée automatiquement (et donc perdue). Avec la valeur de "30", si tu as plus de 30s entre le log REQUEST et le log RESPONSE, tu perds l'info "request-time". Je t'invite donc à mettre plus que 30 comme timeout, pour ne rien louper.
  • pour que le plugin fonctionne bien, il faut que les logs soient traités dans l'ordre : d'abord le le log REQUEST, puis le log RESPONSE. Pour garantir cet ordonnancement, il faut que le nombre de workers de ton pipeline soit égal à 1. Donc soit avec le flag -w 1 au démarrage de logstash, soit avec pipeline.workers: 1 dans la configuration logstash.yml ou pipelines.yml
2 Likes

Petit bonus, n'hésites pas à utiliser mon extension vscode "Logstash Editor" pour avoir de la complétion, de la documentation intégrée et de l'auto-indentation pour ta configuration Logstash:
https://marketplace.visualstudio.com/items?itemName=fbaligand.vscode-logstash-editor

Et si tu veux en savoir plus sur cette extension, tu peux venir voir ma prez sur le sujet la semaine prochaine au ElasticFR meetup :slight_smile:

3 Likes

Sinon vous pouvez compter sur doc_as_upsert de logstash elasticsearch output et corréler directement dans Elasticsearch :slight_smile:

 output {
      elasticsearch {
        action => update
		doc_as_upsert => true
		document_id => "%{RequestId}"
      }
    }
1 Like

Merci à vous tous.
au final ça marche, j'ai juste ajouté le pipeline.workers: 1 dans logstash.yml.

sinon pour ta solution ylasri, je ne l'ai pas testé mais je le ferai ASAP.