Перейти к содержанию

Система логирования

Платформа обладает развитой системой логирования, что при необходимости позволяет анализировать различные аспекты ее работы.

Системные логи обычно представляют собой файлы в обычном текстовом формате.

Уровни логов

Каждое сообщение имеет свой уровень, который указывает на его важность подробность. Каждому регистратору соответствует минимальный уровень логов. Регистратор генерирует сообщение только в том случае, если его минимальный уровень соответствует или превышает минимальный уровень лога.

Поддерживаются следующие уровни логов:

Уровень Название
0 DEBUG
1 INFO
2 WARN
3 ERROR
4 FATAL
5 UNKNOWN

Регистраторы системы генерируют все сообщения логов, поскольку для них установлен уровень логирования DEBUG.

Переопределение уровня логов по умолчанию

Предусмотрена возможность переопределения уровня логов для регистраторов Системы с помощью переменной среды APPSECCODE_LOG_LEVEL. Валидными являются значения от 0 до 5 или соответствующие названия уровней.

Например:

APPSECCODE_LOG_LEVEL=info

Для некоторых сервисов предусмотрены другие уровни логов, на которые данные настройки не оказывают влияния. Для некоторых этих сервисов предусмотрены свои переменные среды, позволяющие переопределить уровень логов. Например:

Сервис Уровень логов Переменная среды
AppSec.Code API INFO  
AppSec.Code Cleanup INFO DEBUG
AppSec.Code Doctor INFO VERBOSE
AppSec.Code Export INFO EXPORT_DEBUG
AppSec.Code Geo INFO  
AppSec.Code Import INFO IMPORT_DEBUG
AppSec.Code QA Runtime INFO QA_LOG_LEVEL
Rack Timeout ERROR  
Sidekiq (server) INFO  
Snowplow Tracker FATAL  
LLM INFO LLM_DEBUG

Ротация логов

Логирование и обеспечение ротации логов для данных сервисов может осуществляться следующими сервисами:

  • logrotate;
  • svlogd (сервис ведения логов runit);
  • logrotate и svlogd;
  • или никаким.

В следующей таблице приведена информация о том, кто отвечает за ведение и ротацию логов для включенных сервисов. Логи, управляемые svlogd, записываются в файл под названием current. Встроенный сервис logrotate управляет всеми логами, кроме тех, которые перехватывает runit.

Тип логов Управляется
logrotate		 Управляется
svlogd/runit
Alertmanager logs Нет Да
crond logs Нет Да
AppSec.Code Exporter for Linux package installations Нет Да
AppSec.Code Pages logs Да Да
AppSec.Code Rails Да Нет
AppSec.Code Shell logs Да Нет
Grafana logs Нет Да
LogRotate logs Нет Да
Mailroom Да Да
NGINX Да Да
PgBouncer logs Нет Да
PostgreSQL logs Нет Да
Prometheus logs Нет Да
Puma Да Да
Redis logs Нет Да
Registry logs Нет Да

production_json.log

Содержит структурированный лог запросов к контроллеру Rails, получаемых из Системы благодаря lograge. Запросы из API записываются в отдельный файл api_json.log.

Каждая строка содержит JSON, который может быть получен такими сервисами, как Elasticsearch и Splunk. Для наглядности в примерах добавлены переносы строк:

{
    "method":"GET",
    "format":"html",
    "controller":"Projects::IssuesController",
    "action":"show",
    "status":200,
    "time":"2017-08-08T20:15:54.821Z",
    "params":[{"key":"param_key","value":"param_value"}],
    "remote_ip":"18.245.0.1",
    "user_id":1,
    "username":"admin",
    "queue_duration_s":0.0,
    "redis_calls":115,
    "redis_duration_s":0.13,
    "redis_read_bytes":1507378,
    "redis_write_bytes":2920,
    "correlation_id":"O1SdybnnIq7",
    "cpu_s":17.50,
    "db_duration_s":0.08,
    "view_duration_s":2.39,
    "duration_s":20.54,
    "pid": 81836,
    "worker_id":"puma_0"
}

В данном примере был GET-запрос определенной Issue. Каждая строка также содержит данные о производительности с указанием времени в секундах:

  • duration_s: общее время извлечения запроса;
  • queue_duration_s: общее время нахождения запроса в очереди;
  • view_duration_s: общее время работы с представлениями в Rails;
  • db_duration_s: общее время извлечения запроса из PostgreSQL;
  • cpu_s: общие затраты процессорного времени;
  • redis_calls: общее количество вызовов Redis;
  • redis_cross_slot_calls: общее количество кросс-слотовых запросов Redis;
  • redis_allowed_cross_slot_calls: общее количество разрешенных кросс-слотовых запросов Redis;
  • redis_duration_s: общее время получения данных от Redis;
  • redis_read_bytes: общее количество байт, считанных с Redis;
  • redis_write_bytes: общее количество байт, записанных в Redis;
  • redis_<instance>_calls: общее количество запросов, сделанных в инстанс Redis;
  • redis_<instance>_cross_slot_calls: общее количество кросс-слотовых запросов, сделанных в инстанс Redis;
  • redis_<instance>_allowed_cross_slot_calls: общее количество допустимых кросс-слотовых запросов, сделанных запросов, сделанных в инстанс Redis;
  • redis_<instance>_duration_s: общее время, затраченное на извлечение данных из инстанса Redis;
  • redis_<instance>_read_bytes: количество байт, считанных из инстанса Redis;
  • redis_<instance>_write_bytes: общее количество байт, записанных в инстанс Redis;
  • pid: идентификатор рабочего процесса в Linux (изменяется при перезапуске рабочего процесса).

Действия пользователя по клонированию (clone) и выборке (fetch) с использованием HTTP-транспорта отображаются в логе как действие.

Кроме того, в логе указывается IP-адрес источника (remote_ip), идентификатор пользователя (us-er_id) и его имя (username).

Некоторые методы (например, /search), при использовании расширенного поиска, могут выполнять запросы к Elasticsearch. Они логируются дополнительно как события elasticsearch_calls и elasticsearch_call_duration_s:

  • elasticsearch_calls: общее количество обращений к Elasticsearch;
  • elasticsearch_duration_s: общее время, затраченное на обращения к Elasticsearch;
  • elasticsearch_timed_out_count: общее количество обращений к Elasticsearch, на которые не был получен своевременный ответ и, соответственно, частичные результаты.

События подключения и подписки ActionCable также записываются в этот файл и повторяют предыдущий формат. Поля method, path и format не применяются — они всегда остаются пустыми. В качестве controller используется класс соединения или канала ActionCable.

{
    "method":null,
    "path":null,
    "format":null,
    "controller":"IssuesChannel",
    "action":"subscribe",
    "status":200,
    "time":"2020-05-14T19:46:22.008Z",
    "remote_ip":"127.0.0.1",
    "user_id":1,
    "username":"admin",
    "ua":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:76.0) Gecko/20100101 Firefox/76.0",
    "correlation_id":"jSOIEynHCUa",
    "duration_s":0.32566
}

production.log

Содержит информацию о все выполненных запросах. Можно просмотреть URL и тип запроса, IP-address и какие части кода были задействованы для обслуживания конкретного запроса. Кроме этого, можно просмотреть все выполненные SQL-запросы и какое время ушло на обработку каждого из них. Эта задача более полезна для разработчиков.

api_json.log

Помогает просмотреть запросы, сделанные непосредственно к API, например:

`{
    "time":"2018-10-29T12:49:42.123Z",
    "severity":"INFO",
    "duration":709.08,
    "db":14.59,
    "view":694.49,
    "status":200,
    "method":"GET",
    "path":"/api/v4/projects",
    "params":[{"key":"action","value":"upload-pack"},{"key":"changes","value":"\_any"},{"key":"key_id","value":"secret"},{"key":"secret_token","value":"[FILTERED]"}],
    "host":"localhost",
    "remote_ip":"::1",
    "ua":"Ruby",
    "route":"/api/:version/projects",
    "user_id":1,
    "username":"root",
    "queue_duration":100.31,

    "pid": 81836,
    ...
}

Эта запись показывает запрос к внутреннему методу с целью проверки, имеет ли право соответствующий SSH-ключ скачать проект. В этом примере мы можем видеть:

  • duration: общее время в миллисекундах на получение запроса;
  • queue_duration: общее время в миллисекундах, в течение которого запрос находился в очереди;
  • method: HTTP-метод, который использовался для запроса;
  • path: относительный путь запроса;
  • params: пары ключ-значение, передаваемый в строке запроса или в теле HTTP (конфиденциальные параметры, например, пароли или токены фильтруются);
  • ua: User-Agent запросчика.

application_json.log

Помогает отследить события, происходящие в вашем инстансе, например, создание пользователя и удаление проекта. Например:

{
    "severity":"INFO",
    "time":"2020-01-14T13:35:15.466Z",
    "correlation_id":"3823a1550b64417f9c9ed8ee0f48087e",
    "message":"User \\"Administrator\\" (<admin@example.com>) was created"
}

{
    "severity":"INFO",
    "time":"2020-01-14T13:35:15.466Z",
    "correlation_id":"78e3df10c9a18745243d524540bd5be4",
    "message":"Project \\"project133\\" was removed"
}

integrations_json.log

Он содержит информацию об активностях, связанных с интеграциями, например с сервисами Jira, Asana, и irker. Используется формат JSON, см. пример ниже:

{
    "severity":"ERROR",
    "time":"2018-09-06T14:56:20.439Z",
    "service_class":"Integrations::Jira",
    "project_id":8,
    "project_path":"h5bp/html5-boilerplate",
    "message":"Error sending message",
    "client_url":"<http://jira.company.com:8080>",
    "error":"execution expired"
}

{
    "severity":"INFO",
    "time":"2018-09-06T17:15:16.365Z",
    "service_class":"Integrations::Jira",
    "project_id":3,
    "project_path":"namespace2/project2",
    "message":"Successfully posted",
    "client_url":"<http://jira.example.com>"
}

git_json.log

Система взаимодействует с Git-репозиториями, но в редких случаях возможны сбои. В этом случае необходимо точно знать причину их возникновения. Этот лог-файл содержит все ошибочные запросы от Системы к Git-репозиториям. В большинстве случаев файл может быть полезен только разработчикам. Например:

{
    "severity":"ERROR",
    "time":"2019-07-19T22:16:12.528Z",
    "correlation_id":"FeGxww5Hj64"
}

audit_json.log

В этот файл регистрируются изменения в группах или проектах, а также изменение информации об их участниках (target_details). Например:

{
    "severity":"INFO",
    "time":"2018-10-17T17:38:22.523Z",
    "author_id":3,
    "entity_id":2,
    "entity_type":"Project",
    "change":"visibility",
    "from":"Private",
    "to":"Public",
    "author_name":"John Doe4",
    "target_id":2,
    "target_type":"Project",
    "target_details":"namespace2/project2"
}

Логи Sidekiq

При установке в Linux-пакета перечисленные ниже логи Sidekiq располагаются в /var/log/appsec-code/sidekiq/current.

sidekiq.log

Основной формат лога для Helm chart установок изменен с text на json.

Система использует фоновые задания для обработки долговременных задач. Вся информация об этих задачах записывается в этот файл. Например:

{
    "severity":"INFO",
    "time":"2018-04-03T22:57:22.071Z",
    "queue":"cronjob:update_all_mirrors",
    "args":[],
    "class":"UpdateAllMirrorsWorker",
    "retry":false,
    "queue_namespace":"cronjob",
    "jid":"06aeaa3b0aadacf9981f368e",
    "created_at":"2018-04-03T22:57:21.930Z",
    "enqueued_at":"2018-04-03T22:57:21.931Z",
    "pid":10077,
    "worker_id":"sidekiq_0",
    "message":"UpdateAllMirrorsWorker JID-06aeaa3b0aadacf9981f368e: done: 0.139 sec",
    "job_status":"done",
    "duration":0.139,
    "completed_at":"2018-04-03T22:57:22.071Z",
    "db_duration":0.05,
    "db_duration_s":0.0005
}

Вместо JSON можно выбрать генерацию логов Sidekiq в текстовом формате.

Для установки в качестве Linux-пакета добавьте в конфигурацию следующую опцию:

sidekiq['log_format'] = 'text'

Для самокомпилирующихся установок установите для Sidekiq log_format следующую опцию:

## Sidekiq
sidekiq:
    log_format: text

sidekiq_client.log

Файл содержит информацию о заданиях, прежде чем Sidekiq начнет обрабатывать их, например, перед постановкой в очередь.

Структура этого файла аналогична sidekiq.log — он представляет собой JSON-файл, если Sidekiq сконфигурирован указанным выше образом.

Puma logs

repocheck.log

Он логирует информацию о каждом запуске проверки репозитория в проекте.

importer.log

В этом логе регистрируется ход импорта и миграции проектов.

exporter.log

В этом логе регистрируется ход выполнения процесса экспорта.

features_json.log

В этом файле записываются события модификации от Feature-флагов при разработке системы. Например:

{"severity":"INFO","time":"2020-11-24T02:30:59.860Z","correlation_id":null,"key":"cd_auto_rollback","action":"enable","extra.thing":"true"}
{"severity":"INFO","time":"2020-11-24T02:31:29.108Z","correlation_id":null,"key":"cd_auto_rollback","action":"enable","extra.thing":"true"}
{"severity":"INFO","time":"2020-11-24T02:31:29.129Z","correlation_id":null,"key":"cd_auto_rollback","action":"disable","extra.thing":"false"}
{"severity":"INFO","time":"2020-11-24T02:31:29.177Z","correlation_id":null,"key":"cd_auto_rollback","action":"enable","extra.thing":"Project:1"}
{"severity":"INFO","time":"2020-11-24T02:31:29.183Z","correlation_id":null,"key":"cd_auto_rollback","action":"disable","extra.thing":"Project:1"}
{"severity":"INFO","time":"2020-11-24T02:31:29.188Z","correlation_id":null,"key":"cd_auto_rollback","action":"enable_percentage_of_time","extra.percentage":"50"}
{"severity":"INFO","time":"2020-11-24T02:31:29.193Z","correlation_id":null,"key":"cd_auto_rollback","action":"disable_percentage_of_time"}
{"severity":"INFO","time":"2020-11-24T02:31:29.198Z","correlation_id":null,"key":"cd_auto_rollback","action":"enable_percentage_of_actors","extra.percentage":"50"}
{"severity":"INFO","time":"2020-11-24T02:31:29.203Z","correlation_id":null,"key":"cd_auto_rollback","action":"disable_percentage_of_actors"}
{"severity":"INFO","time":"2020-11-24T02:31:29.329Z","correlation_id":null,"key":"cd_auto_rollback","action":"remove"}

ci_resource_groups_json.log

Содержит информацию о приобретении групповых ресурсов. Например:

{"severity":"INFO","time":"2023-02-10T23:02:06.095Z","correlation_id":"01GRYS10C2DZQ9J1G12ZVAD4YD","resource_group_id":1,"processable_id":288,"message":"attempted to assign resource to processable","success":true}

{"severity":"INFO","time":"2023-02-10T23:02:08.945Z","correlation_id":"01GRYS138MYEG32C0QEWMC4BDM","resource_group_id":1,"processable_id":288,"message":"attempted to release resource from processable","success":true}

В примере показаны поля resource_group_id, processable_id, message и success для каждой записи.

auth.log

В логе регистрируются:

  • Запросы, превышающие лимит на необработанных методах.
  • Идентификатор (ID) и имя пользователя (при наличии).

auth_json.log

Файл содержит JSON-версию логов auth.log, например:

{
    "severity":"ERROR",
    "time":"2023-04-19T22:14:25.893Z",
    "correlation_id":"01GYDSAKAN2SPZPAMJNRWW5H8S",
    "message":"Rack_Attack",
    "env":"blocklist",
    "remote_ip":"x.x.x.x",
    "request_method":"GET",
    "path":"/group/project/info/upload-pack"
}

graphql_json.log

Содержит запросы GraphQL, записанные в файл, например:

{"query_string":"query IntrospectionQuery{\__schema {queryType { name },mutationType { name }}}...(etc)","variables":{"a":1,"b":2},"complexity":181,"depth":1,"duration_s":7}

migrations.log

В данном файле регистрируется ход миграции базы данных.

mail_room_json.log (default)

Структурированный лог-файл фиксирует внутреннюю активность в gem-библиотеке mail_room. Ее имя и файл настраиваются, поэтому могут отличаться от приведенных выше.

web_hooks.log

В файл записываются события, связанные с веб-хуками, например:

{"severity":"INFO","time":"2020-11-24T02:30:59.860Z","hook_id":12,"action":"backoff","disabled_until":"2020-11-24T04:30:59.860Z","backoff_count":2,"recent_failures":2}
{"severity":"INFO","time":"2020-11-24T02:30:59.860Z","hook_id":12,"action":"disable","disabled_until":null,"backoff_count":5,"recent_failures":100}
{"severity":"INFO","time":"2020-11-24T02:30:59.860Z","hook_id":12,"action":"enable","disabled_until":null,"backoff_count":0,"recent_failures":0}

sidekiq_exporter.log и web_exporter.log

Если активированы и Prometheus metrics, и Sidekiq Exporter, Sidekiq запускает веб-сервер и прослушивает определенный порт (по умолчанию: 8082). По умолчанию логи доступа Sidekiq Exporter access отключены, но могут включаться.

Если активированы и Prometheus metrics, и Sidekiq Exporter, Puma запускает веб-сервер и прослушивает определенный порт (по умолчанию: 8083).

database_load_balancing.log

Содержит подробную информацию о балансировке нагрузки базы данных Системы.

zoekt.log

В файле регистрируется информация, связанная с функцией поиска по точному коду, которая функционирует на базе Zoekt.

elasticsearch.log

Этот лог-файл содержит информацию, имеющую отношение к интеграции с Elasticsearch, включая ошибки, возникающие в ходе индексации или выполнения поисковых запросов Elasticsearch.

Каждая строка содержит JSON, который может быть получен такими сервисами, как Elasticsearch и Splunk. Для наглядности в приведенном ниже примере добавлены разрывы строк:

{
    "severity":"DEBUG",
    "time":"2019-10-17T06:23:13.227Z",
    "correlation_id":null,
    "message":"redacted_search_result",
    "class_name":"Milestone",
    "id":2,
    "ability":"read_milestone",
    "current_user_id":2,
    "query":"project"
}

exceptions_json.log

Файл содержит информацию об исключениях, обеспечивает стандартный и последовательный способ обработки сохраненных исключений.

Каждая строка содержит JSON, который может быть получен Elasticsearch.

service_measurement.log

Файл содержит один структурированный лог с изменениями для каждого экземпляра сервиса. Он также содержит такие изменения, как количество SQL-запросов, execution_time, gc_stats и memory usage. Пример:

{ "severity":"INFO", "time":"2020-04-22T16:04:50.691Z","correlation_id":"04f1366e-57a1-45b8-88c1-b00b23dc3616","class":"Projects::ImportExport::ExportService","current_user":"John Doe","project_full_path":"group1/test-export","file_path":"/path/to/archive","gc_stats":{"count":{"before":127,"after":127,"diff":0},"heap_allocated_pages":{"before":10369,"after":10369,"diff":0},"heap_sorted_length":{"before":10369,"after":10369,"diff":0},"heap_allocatable_pages":{"before":0,"after":0,"diff":0},"heap_available_slots":{"before":4226409,"after":4226409,"diff":0},"heap_live_slots":{"before":2542709,"after":2641420,"diff":98711},"heap_free_slots":{"before":1683700,"after":1584989,"diff":-98711},"heap_final_slots":{"before":0,"after":0,"diff":0},"heap_marked_slots":{"before":2542704,"after":2542704,"diff":0},"heap_eden_pages":{"before":10369,"after":10369,"diff":0},"heap_tomb_pages":{"before":0,"after":0,"diff":0},"total_allocated_pages":{"before":10369,"after":10369,"diff":0},"total_freed_pages":{"before":0,"after":0,"diff":0},"total_allocated_objects":{"before":24896308,"after":24995019,"diff":98711},"total_freed_objects":{"before":22353599,"after":22353599,"diff":0},"malloc_increase_bytes":{"before":140032,"after":6650240,"diff":6510208},"malloc_increase_bytes_limit":{"before":25804104,"after":25804104,"diff":0},"minor_gc_count":{"before":94,"after":94,"diff":0},"major_gc_count":{"before":33,"after":33,"diff":0},"remembered_wb_unprotected_objects":{"before":34284,"after":34284,"diff":0},"remembered_wb_unprotected_objects_limit":{"before":68568,"after":68568,"diff":0},"old_objects":{"before":2404725,"after":2404725,"diff":0},"old_objects_limit":{"before":4809450,"after":4809450,"diff":0},"oldmalloc_increase_bytes":{"before":140032,"after":6650240,"diff":6510208},"oldmalloc_increase_bytes_limit":{"before":68537556,"after":68537556,"diff":0}},"time_to_finish":0.12298400001600385,"number_of_sql_calls":70,"memory_usage":"0.0 MiB","label":"process_48616"}

geo.log

Модуль Geo сохраняет структурированные сообщения лога в файле geo.log.

Файл содержит информацию о попытках Geo синхронизировать репозитории и файлы. Каждая строка в файле содержит отдельную JSON-запись, которая может передаваться, например в Elasticsearch или Splunk.

update_mirror_service_json.log

Файл содержит информации об ошибках LFS, произошедших в ходе зеркалирования проекта.

{
    "severity":"ERROR",
    "time":"2020-07-28T23:29:29.473Z",
    "correlation_id":"5HgIkCJsO53",
    "user_id":"x",
    "project_id":"x",
    "import_url":"<https://mirror-source/group/project>",
    "error_message":"The LFS objects download list couldn't be imported. Error: Unauthorized"
}

llm.log

Лог с информацией о функциональных возможностях, связанных с AI.

Логи NGINX

Ниже приводится формат лога NGINX по умолчанию:

'$remote_addr - $remote_user [$time_local] "$request" $status $body_bytes_sent "$http_referer" "$http_user_agent"'
$request и $http_referer фильтруются на наличие параметров запросов конфиденциальной информации, например, токенов.

Логи Pages

Пример:

{
    "gid": 998,
    "in-place": false,
    "level": "info",
    "msg": "running the daemon as unprivileged user",
    "time": "2020-04-22T17:53:12Z",
    "uid": 998
}

Логи Mattermost

При установке в качестве Linux-пакета логи Mattermost располагаются в следующих директориях:

  • /var/log/appsec-code/mattermost/mattermost.log;
  • /var/log/appsec-code/mattermost/current.

Логи PgBouncer

При установке в качестве Linux-пакета логи PgBouncer располагаются в директории /var/log/appsec-code/pgbouncer/current.

Логи PostgreSQL

При установке в качестве Linux-пакета логи PostgreSQL располагаются в директории /var/log/appsec-code/postgresql/current.

Логи Prometheus

При установке в качестве Linux-пакета логи Prometheus располагаются в директории /var/log/appsec-code/prometheus/current.

Логи Redis

При установке в качестве Linux-пакета логи Redis располагаются в директории /var/log/appsec-code/redis/current.

Логи Alertmanager

При установке в качестве Linux-пакета логи Alertmanager располагаются в директории /var/log/appsec-code/alertmanager/current.

Логи crond

При установке в качестве Linux-пакета логи crond располагаются в директории /var/log/appsec-code/crond/.

Логи Grafana

При установке в качестве Linux-пакета логи Grafana располагаются в директории /var/log/appsec-code/grafana/current.

Логи LogRotate

При установке в качестве Linux-пакета логи logrotate располагаются в директории /var/log/appsec-code/logrotate/current.

Логи резервного копирования

Данный лог пополняется при выполнении резервного копирования системы.