doc-locale/fr-fr/administration/logs/log_parsing.md
{{< details >}}
{{< /details >}}
Nous recommandons d'utiliser des outils d'agrégation et de recherche de logs comme Kibana et Splunk dans la mesure du possible, mais s'ils ne sont pas disponibles, vous pouvez toujours analyser rapidement les logs GitLab au format JSON à l'aide de jq.
[!note] Spécifiquement pour résumer les événements d'erreur et les statistiques d'utilisation de base, l'équipe de support GitLab propose l'outil spécialisé
fast-statstool. Il peut généralement traiter des logs plus volumineux bien plus rapidement quejqet génère une sélection plus large d'informations statistiques.
Comme indiqué dans son manuel, jq est un processeur JSON en ligne de commande. Les exemples suivants incluent des cas d'utilisation ciblés pour l'analyse des fichiers de logs GitLab.
Les exemples listés ci-dessous font référence à leurs fichiers de logs respectifs par leurs chemins d'installation relatifs du package Linux et leurs noms de fichiers par défaut. Retrouvez les chemins complets respectifs dans les sections des logs GitLab.
Lorsque les fichiers de logs sont alternés, ils sont renommés au format d'horodatage Unix et compressés avec gzip. Le nom de fichier résultant ressemble à @40000000624492fa18da6f34.s. Ces fichiers doivent être traités différemment avant l'analyse, contrairement aux fichiers de logs plus récents :
gunzip -S .s @40000000624492fa18da6f34.s, en remplaçant le nom de fichier par le nom de votre fichier de log compressé.zcat ou zless.zgrep.jq vers less {#pipe-colorized-jq-output-into-less}jq . <FILE> -C | less -R
grep <TERM> <FILE> | jq .
jq -cR 'fromjson?' file.json | jq <COMMAND>
Par défaut, jq génère une erreur lorsqu'il rencontre une ligne qui n'est pas du JSON valide. Cette commande ignore toutes les lignes non valides et analyse le reste.
cat log.json | (head -1; tail -1) | jq '.time'
Utilisez zcat si le fichier a été alterné et compressé :
zcat @400000006026b71d1a7af804.s | (head -1; tail -1) | jq '.time'
zcat some_json.log.25.gz | (head -1; tail -1) | jq '.time'
grep -hR <correlationID> | jq -c -R 'fromjson?' | jq -C -s 'sort_by(.time)' | less -R
gitlab-rails/production_json.log et gitlab-rails/api_json.log {#parsing-gitlab-railsproduction_jsonlog-and-gitlab-railsapi_jsonlog}jq 'select(.status >= 500)' <FILE>
jq -s 'sort_by(-.duration_s) | limit(10; .[])' <FILE>
grep <PROJECT_NAME> <FILE> | jq .
jq 'select(.duration_s > 5000)' <FILE>
grep <PROJECT_NAME> <FILE> | jq 'select(.gitaly_calls > 5)'
jq 'select(.gitaly_duration_s > 10000)' <FILE>
jq 'select(.queue_duration_s > 10000)' <FILE>
jq -s 'map(select(.gitaly_calls != null)) | sort_by(-.gitaly_calls) | limit(10; .[])' <FILE>
jq 'select(.time >= "2023-01-10T00:00:00Z" and .time <= "2023-01-10T12:00:00Z")' <FILE>
gitlab-rails/production_json.log {#parsing-gitlab-railsproduction_jsonlog}jq -s -r 'group_by(.controller+.action) | sort_by(-length) | limit(3; .[]) | sort_by(-.duration_s) | "CT: \(length)\tMETHOD: \(.[0].controller)#\(.[0].action)\tDURS: \(.[0].duration_s), \(.[1].duration_s), \(.[2].duration_s)"' production_json.log
Exemple de sortie
CT: 2721 METHOD: SessionsController#new DURS: 844.06, 713.81, 704.66
CT: 2435 METHOD: MetricsController#index DURS: 299.29, 284.01, 158.57
CT: 1328 METHOD: Projects::NotesController#index DURS: 403.99, 386.29, 384.39
Vous pouvez également utiliser fast-stats :
fast-stats --verbose --limit=3 production_json.log
gitlab-rails/api_json.log {#parsing-gitlab-railsapi_jsonlog}jq -s -r 'group_by(.route) | sort_by(-length) | limit(3; .[]) | sort_by(-.duration_s) | "CT: \(length)\tROUTE: \(.[0].route)\tDURS: \(.[0].duration_s), \(.[1].duration_s), \(.[2].duration_s)"' api_json.log
Exemple de sortie
CT: 2472 ROUTE: /api/:version/internal/allowed DURS: 56402.65, 38411.43, 19500.41
CT: 297 ROUTE: /api/:version/projects/:id/repository/tags DURS: 731.39, 685.57, 480.86
CT: 190 ROUTE: /api/:version/projects/:id/repository/commits DURS: 1079.02, 979.68, 958.21
Vous pouvez également utiliser fast-stats :
fast-stats --verbose --limit=3 api_json.log
jq --raw-output '
select(.remote_ip != "127.0.0.1") | [
(.time | split(".")[0] | strptime("%Y-%m-%dT%H:%M:%S") | strftime("…%m-%dT%H…")),
."meta.caller_id", .username, .ua
] | @tsv' api_json.log | sort | uniq -c \
| grep --invert-match --extended-regexp '^\s+\d{1,3}\b'
Exemple de sortie :
1234 …01-12T01… GET /api/:version/projects/:id/pipelines some_user # plus browser details; OK
54321 …01-12T01… POST /api/:version/projects/:id/repository/files/:file_path/raw some_bot
5678 …01-12T01… PATCH /api/:version/jobs/:id/trace gitlab-runner # plus version details; OK
Cet exemple montre un outil ou un script personnalisé provoquant un taux de requêtes (>15 RPS) anormalement élevé. Les user agents dans cette situation peuvent être des clients tiers spécialisés, ou des outils généraux comme curl.
L'agrégation horaire permet de :
En complément de jq, utilisez fast-stats top pour examiner l'impact sur les performances de ces utilisateurs et bots :
fast-stats top --display=percentage --sort-by=cpu-s api_json.log
Une fréquence de requêtes élevée n'est pas automatiquement un problème en soi, mais utiliser un pourcentage important d'une ressource quelconque l'est.
gitlab-rails/importer.log {#parsing-gitlab-railsimporterlog}Pour résoudre les problèmes liés aux imports de projets ou aux migrations, exécutez cette commande :
jq 'select(.project_path == "<namespace>/<project>").error_messages' importer.log
Pour les problèmes courants, consultez la résolution des problèmes.
gitlab-workhorse/current {#parsing-gitlab-workhorsecurrent}jq --raw-output '
select(.remote_ip != "127.0.0.1") | [
(.time | split(".")[0] | strptime("%Y-%m-%dT%H:%M:%S") | strftime("…%m-%dT%H…")),
.remote_ip, .uri, .user_agent
] | @tsv' current |
sort | uniq -c
De même que dans l'exemple ua de l'API, de nombreux user agents inattendus dans cette sortie indiquent des scripts non optimisés. Les user agents attendus incluent gitlab-runner, GitLab-Shell et les navigateurs.
L'impact sur les performances des runners vérifiant la présence de nouveaux jobs peut être réduit en augmentant le paramètre check_interval, par exemple.
gitlab-rails/geo.log {#parsing-gitlab-railsgeolog}Si la tâche Rake gitlab:geo:status signale de manière répétée que certains éléments n'atteignent jamais 100 %, la commande suivante permet de se concentrer sur les erreurs les plus courantes.
jq --raw-output 'select(.severity == "ERROR") | [
(.time | split(".")[0] | strptime("%Y-%m-%dT%H:%M:%S") | strftime("…%m-%dT%H:%M…")),
.class, .id, .message, .error
] | @tsv' geo.log \
| sort | uniq -c
Consultez notre page de résolution des problèmes Geo pour obtenir des conseils sur les messages d'erreur spécifiques.
gitaly/current {#parsing-gitalycurrent}Utilisez les exemples suivants pour résoudre les problèmes de Gitaly.
jq 'select(."grpc.meta.client_name" == "gitlab-web")' current
jq 'select(."grpc.code" != null and ."grpc.code" != "OK")' current
jq 'select(."grpc.time_ms" > 30000)' current
jq --raw-output --slurp '
map(
select(
."grpc.request.glProjectPath" != null
and ."grpc.request.glProjectPath" != ""
and ."grpc.time_ms" != null
)
)
| group_by(."grpc.request.glProjectPath")
| sort_by(-length)
| limit(10; .[])
| sort_by(-."grpc.time_ms")
| [
length,
.[0]."grpc.time_ms",
.[1]."grpc.time_ms",
.[2]."grpc.time_ms",
.[0]."grpc.request.glProjectPath"
]
| @sh' current |
awk 'BEGIN { printf "%7s %10s %10s %10s\t%s\n", "CT", "MAX DURS", "", "", "PROJECT" }
{ printf "%7u %7u ms, %7u ms, %7u ms\t%s\n", $1, $2, $3, $4, $5 }'
Exemple de sortie
CT MAX DURS PROJECT
206 4898 ms, 1101 ms, 1032 ms 'groupD/project4'
109 1420 ms, 962 ms, 875 ms 'groupEF/project56'
663 106 ms, 96 ms, 94 ms 'groupABC/project123'
...
Vous pouvez également utiliser fast-stats :
fast-stats top --sort-by=duration current
jq --raw-output '[
(.time | split(".")[0] | strptime("%Y-%m-%dT%H:%M:%S") | strftime("…%m-%dT%H…")),
.username, ."grpc.method", ."grpc.request.glProjectPath"
] | @tsv' current | sort | uniq -c \
| grep --invert-match --extended-regexp '^\s+\d{1,3}\b'
Exemple de sortie :
5678 …01-12T01… ReferenceTransactionHook # Praefect operation; OK
54321 …01-12T01… some_bot GetBlobs namespace/subgroup/project
1234 …01-12T01… some_user FindCommit namespace/subgroup/project
Cet exemple montre un outil ou un script personnalisé provoquant un taux de requêtes (>15 RPS) anormalement élevé sur Gitaly. L'agrégation horaire permet de :
En complément de jq, utilisez fast-stats top pour examiner l'impact sur les performances de ces utilisateurs et bots :
fast-stats top --display=percentage --sort-by=cpu-s current
Une fréquence de requêtes élevée n'est pas automatiquement un problème en soi, mais utiliser un pourcentage important d'une ressource quelconque l'est.
grep "fatal: " current |
jq '."grpc.request.glProjectPath"' |
sort | uniq
gitlab-shell/gitlab-shell.log {#parsing-gitlab-shellgitlab-shelllog}Pour examiner les appels Git via SSH.
Trouver les 20 principaux appels par projet et utilisateur :
jq --raw-output --slurp '
map(
select(
.username != null and
.gl_project_path !=null
)
)
| group_by(.username+.gl_project_path)
| sort_by(-length)
| limit(20; .[])
| "count: \(length)\tuser: \(.[0].username)\tproject: \(.[0].gl_project_path)" ' \
gitlab-shell.log
Trouver les 20 principaux appels par projet, utilisateur et commande :
jq --raw-output --slurp '
map(
select(
.command != null and
.username != null and
.gl_project_path !=null
)
)
| group_by(.username+.gl_project_path+.command)
| sort_by(-length)
| limit(20; .[])
| "count: \(length)\tcommand: \(.[0].command)\tuser: \(.[0].username)\tproject: \(.[0].gl_project_path)" ' \
gitlab-shell.log