Projet

Général

Rapports personnalisés

Profil

Actions

Anomalie #1176

fermé

redmine est a 100% de CPU depuis plusieurs heures

Ajouté par Loïc Dachary il y a presque 12 ans. Mis à jour il y a plus de 5 ans.

Statut:
Fermé
Priorité:
Immédiate
Assigné à:
Catégorie:
Task
Version cible:
Début:
Echéance:
% réalisé:

100%

Temps estimé:
Temps passé:
Difficulté:
2 Facile

Description

Hypothèse : il y a une URL dans redmine qui provoque un bug qui conduit à une boucle d'allocation infinie:

# strace -p 29712
Process 29712 attached - interrupt to quit
brk(0x505e9000)                         = 0x505e9000
brk(0x505e7000)                         = 0x505e7000
brk(0x50608000)                         = 0x50608000
brk(0x50606000)                         = 0x50606000
...

et donc un process qui utilise de plus en plus de RAM et 100% d'un CPU.

ssh -t -A root@pavot.april.org vserver amphetamine enter # redmine

29712 www-data  20   0 1047m 882m 2692 R  101  3.7 242:44.56 Rails: /usr/share/redmine

C'est arrivé au moment ou google a décidé de crawl tout le site. Il parait difficile de trouver quelle requete exactement a déclenché ce comportement. Les logs ne montrent pas d'erreurs portant sur une requete ayant duré plusieurs heures:

grep '^Completed' /var/log/redmine/default/production.log | grep -v '200 OK' 

et la granularité de munin ne permet pas de situer l'apparition du comportement de façon précise : il y a des centaines de requetes qui ont été faites entre 6am et 7am le 27 janvier 2013 ( voir les logs attaché au ticket )


Fichiers

redmine.png (22,8 ko) redmine.png Loïc Dachary, 27/01/2013 10:30
production.log.1.gz (404 ko) production.log.1.gz logs de prodution correspondant a la période d'apparition du problème Loïc Dachary, 27/01/2013 13:04
production.log.gz (164 ko) production.log.gz logs de prodution correspondant a la période d'apparition du problème ( apres 6:25) Loïc Dachary, 27/01/2013 13:06

Demandes liées 3 (0 ouverte3 fermées)

Lié à Admins - Anomalie #1178: surveiller la consomation CPU de agir.april.orgFerméLoïc Dachary27/01/2013

Actions
Lié à Admins - Anomalie #1179: agir.april.org out of memoryFerméLoïc Dachary31/01/2013

Actions
Lié à Admins - Anomalie #1234: oom killer sur pavotFerméLoïc Dachary14/03/201316/03/2013

Actions

Mis à jour par Loïc Dachary il y a presque 12 ans

  • Fichier signature.asc supprimé

Mis à jour par Loïc Dachary il y a presque 12 ans

  • Catégorie mis à Task
  • Statut changé de Nouveau à Confirmé
  • Assigné à mis à Loïc Dachary
  • Priorité changé de Normale à Immédiate
  • Version cible mis à Janvier 2013

Mis à jour par Loïc Dachary il y a presque 12 ans

 tail -f /var/log/redmine/default/production.log

Processing IssuesController#index (for 66.249.76.56 at 2013-01-27 10:32:20) [GET]
  Parameters: {"action"=>"index", "page"=>"3", "controller"=>"issues", "per_page"=>"xmsqozgry", "sort"=>"priority,assigned_to,tracker"}
Rendering template within layouts/base
Rendering issues/index.rhtml
Completed in 378ms (View: 118, DB: 46) | 200 OK [https://agir.april.org/issues?page=3&per_page=xmsqozgry&sort=priority%2Cassigned_to%2Ctracker]

Processing TimelogController#details (for 66.249.76.56 at 2013-01-27 10:32:32) [GET]
  Parameters: {"project_id"=>"admins", "action"=>"details", "page"=>"11", "controller"=>"timelog", "per_page"=>"100", "sort"=>"project,spent_on:desc,issue:desc"}
Rendering template within layouts/base
Rendering timelog/details
Completed in 583ms (View: 366, DB: 28) | 200 OK [https://agir.april.org/projects/admins/time_entries?page=11&per_page=100&sort=project%2Cspent_on%3Adesc%2Cissue%3Adesc]

Processing ProjectsController#activity (for 66.249.76.56 at 2013-01-27 10:32:33) [GET]
  Parameters: {"show_documents"=>"1", "from"=>"2012-10-24", "action"=>"activity", "id"=>"aprilcamp", "controller"=>"projects"}
Rendering template within layouts/base
Rendering projects/activity
Completed in 60ms (View: 33, DB: 7) | 200 OK [https://agir.april.org/projects/aprilcamp/activity?from=2012-10-24&show_documents=1]

Mis à jour par Loïc Dachary il y a presque 12 ans

On dirait bien que c'est google qui crawl.

# host 66.249.76.56
56.76.249.66.in-addr.arpa domain name pointer crawl-66-249-76-56.googlebot.com.

Mis à jour par Loïc Dachary il y a presque 12 ans

  • Sujet changé de redmine est a 100% de CPU à redmine est a 100% de CPU depuis plusieurs heures

Mis à jour par Loïc Dachary il y a presque 12 ans

apache2 stop et il reste un process ruby qui prend 100% de la CPU

root@amphetamine:/# strace -p 29712
Process 29712 attached - interrupt to quit
brk(0x505e9000)                         = 0x505e9000
brk(0x505e7000)                         = 0x505e7000
brk(0x50608000)                         = 0x50608000
brk(0x50606000)                         = 0x50606000
brk(0x50627000)                         = 0x50627000
brk(0x50625000)                         = 0x50625000
brk(0x50646000)                         = 0x50646000
brk(0x50644000)                         = 0x50644000
brk(0x50665000)                         = 0x50665000
brk(0x50663000)                         = 0x50663000
brk(0x50684000)                         = 0x50684000
brk(0x50682000)                         = 0x50682000
brk(0x506a3000)                         = 0x506a3000
brk(0x506a1000)                         = 0x506a1000
brk(0x506c2000)                         = 0x506c2000
brk(0x506c0000)                         = 0x506c0000
brk(0x506e1000)                         = 0x506e1000
...

Je le kill -15 et je relance apache

Mis à jour par Loïc Dachary il y a presque 12 ans

Les requetes google ne pouvaient pas générer cette consomation CPU : les logs disent qu'elle prennent au plus 500ms et les requetes google se font a plusieurs secondes d'intervalle. Donc ça ne peut pas manger 100% d'un cpu.

Mis à jour par Loïc Dachary il y a presque 12 ans

Mis à jour par Loïc Dachary il y a presque 12 ans

  • Statut changé de Confirmé à Résolu
  • % réalisé changé de 0 à 100

la remonté d'alerte se fait via munin-node qui est installé sur amphetamine et qui préviendra la prochaine fois que cela se produit

Mis à jour par Quentin Gibeaux il y a plus de 5 ans

  • Statut changé de Résolu à Fermé
Actions

Formats disponibles : Atom PDF