Повышаем прозрачность аудита работы в Gitlab
Введение
Многие компании выбирающие для себя средства хранения кода и "комбайны" организации процессов CI/CD останавливают свой выбор на Gitlab. С точки зрения небольших и больших организаций, функционала Gitlab вполне хватает, чтоб решать повседневные задачи разработки. Продукт хорошо документирован, имеет платные подписки с расширением функционала (множество доменов для аутентификации, полнотекстный поиск, системные хуки и прочее).
Как показала практика использования продукта, основные проблемы начинаются при попытке кастомизировать или расширить внутренний функционал системы. В нашем случае в качестве расширения функционала рассматривается улучшение уровня аудита по работе с репозиториями в части соответствия требованиям ЦБ и ГОСТ Р 56939-2016.
Зачем всё это ?
В рамкам реализации требований по разработке безопасного программного обеспечения, необходимо обеспечить контроль за программными продуктами и средами используемыми в процессе создания кода.
Возникает закономерный вопрос "А зачем?"
Рассмотрим простой вариант многопользовательской разработки программных продуктов в рамках организации. В постковидный период многие компании по прежнему придерживаются идеологии и удобства удалённой работы. И здесь как правило возникает несколько проблем:
Организация должна обеспечить безопасное подключение пользователя к контуру разработки. Тут понятное дело настройка централизованного VPN/RDP/etc с политиками доступа.
Организация должна обеспечить сотрудника удалённым рабочим местом с необходимым набором программных продуктов, необходимых для работы сотрудника. Здесь у нас покупка лицензий на софт, возможно высокие требования к рабочему месту, поддержка рабочих мест инженерами и т.д.
Организация должна обеспечить комплекс мер направленных на обеспечение безопасности кода (закладки, порча кода, некачественный код). Комплексно: антивирусы, code review, SAST, DAST и т.д.
Организация должна обеспечить контроль за возможной утечкой кода. Здесь DPI, расширенный аудит в системах и т.д.
Из этого списка формируется новый комплекс вопросов:
Формировать инфраструктуру для удалённой разработки(VDI/RemotePC) или предоставлять доступ к контуру разработки(репозиторию) с удалённой машины пользователя. Первая часть может быть неприятной с точки зрения бюджета, вторая потенциально небезопасной.
Контроль/аудит работы пользователя при работе с кодом. Должны быть механизмы для контроля.
Контроль использования ключей безопасности(ssh, пароли) при работе с репозиториями. Должны быть механизмы для контроля. Основной вопрос в том, что мало кто смотрит "кто" читает репы и откуда.
Контроль процессов CI/CD и ограничение возможного влияния пользователя на эти процессы. Здесь планомерная работа по изоляции сборочных систем от внешних факторов, реп, возможности влияния на процессы сборки и деплоя.
Гипотетическая ситуация.
Организация «Н» использует для производства своего программного кода набор сервисов «смотрящих» напрямую в интернет, рассчитывая на безопасность сервисов. Всё это администрируется администраторами, всё вроде как безопасно, пишутся журналы работы и прочая. В определённый момент времени пользователи продукта понимают, что логика работы отличается от требуемой и творится что‑то непонятное. Начинается поиск изменений приведших к указанной проблеме и в конечном итоге находится коммит, в котором зафиксированы данные изменения. Коммит сделан «Васей Пупкиным» пару месяцев назад. При этом «Вася» всячески открещивается от сделанных изменений, ведь он был в Тае в отпуске, но с рабочим ноутом.
Но коммит же сформирован под его именем ?
Что произошло ?
Кто изменил код ?
Откуда пришли изменения ?
Произошла ли утечка кредов, ключей, сертификатов ?
Может быть malware в IDE ?
Случилось бы это, если пользователь был бы в локальной сети с локальными копиями репозиториев ?
Как найти "концы" ?
В случае с удалёнными машинами нет никакой возможности проконтролировать, что происходило на машине в этот момент. С каким программным обеспечением работал сотрудник. Что было запущено на машине и т.д.
Всё что необходимо для поиска проблемы должно быть в доступных логах, но не всегда там присутствует.
Система логирования Gitlab
Все кто работал с Gitlab, скорее всего встречались с его подсистемой журналов https://docs.gitlab.com/ee/administration/logs/.
Журналы существуют в виде json и plaintext log файлов, содержащих различные данные о происходящих событиях. В рамках решения наших задач, нас интересуют события связанные с активностью пользователя в репозиториях в рамках Gitlab:
WEB — подсистема пользовательского интерфейса(UI) сайта Gitlab, доступного через браузер
HTTP — подсистема интерфейса взаимодействия пользователя с Git репозиториями через http/https протоколы
SSH — подсистема интерфейса взаимодействия пользователя с Git репозиториями по протоколу SSH
В чём особенность?
При работе пользователя с различными подсистемами, очень сильно отличается механизм взаимодействия внутренних компонент. Основным интерфейсным компонентом ядра является gitaly, он обеспечивает работу с репозиториями по внутренним grpc интерфейсам взаимодействия. Все компоненты, которые «видит» пользователь по сути являются прокси‑компонентами для работы с gitaly. И поэтому в зависимости от того, как написан прокси‑компонент для gitaly, в процессе взаимодействия gitaly получает или не получает ключевые данные, которые нам нужны.
Существующий аудит действий пользователя
Аудит действий пользователя подразумевает журналирование действий при интерактивном взаимодействии пользователя с web интерфейсом сервера Gitlab или прямые вызовы API(если они разрешены). Так например окно активности пользователей в /admin/audit_logs, формируется только из данных веб интерфейса пользователя. Всё что мы видим в профиле пользователя тоже относится только к веб интерфейсу.
Как показали исследования, "gitlab-shell" не передаёт в сторону Gitaly IP адрес пользователя работающего с репозиторием и не журналирует такие данные, как текст коммита. В свою очередь web интерфейс gitlab не журналирует IP адрес пользователя при операциях связанных с помещением действий во внутреннюю очередь. Например при работах с merge_request в части слияния веток.
Это приводит к тому, что в логах коммит или mr есть, но адрес пользователя либо пустой, либо 127.0.0.1. Часть читателей наверное скажет: "Есть же correlation_id, используй его!"
Да. Он есть, но его значение действительно для одной конкретной операции в рамках сессии взаимодействия.
Ниже находятся разные виды "связок" механизмов в рамках операции коммита объединённые по correlation_id.
ssh сессия
/var/log/gitlab/gitaly/current:{"content_length_bytes":686,"correlation_id":"01H0HZP27961AEQFZCDR5925QP","duration_ms":84,"level":"info","method":"POST","msg":"Finished HTTP request","status":200,"time":"2023-05-16T09:53:54.631Z","url":"http://unix/api/v4/internal/allowed"}
/var/log/gitlab/gitaly/current:{"content_length_bytes":36,"correlation_id":"01H0HZP27961AEQFZCDR5925QP","duration_ms":32,"level":"info","method":"POST","msg":"Finished HTTP request","status":200,"time":"2023-05-16T09:53:54.723Z","url":"http://unix/api/v4/internal/pre_receive"}
/var/log/gitlab/gitaly/current:{"command.count":1,"command.cpu_time_ms":56,"command.inblock":0,"command.majflt":0,"command.maxrss":363712,"command.minflt":2839,"command.oublock":24,"command.real_time_ms":59,"command.spawn_token_wait_ms":0,"command.system_time_ms":24,"command.user_time_ms":32,"correlation_id":"01H0HZP27961AEQFZCDR5925QP","grpc.code":"OK","grpc.meta.client_name":"gitaly-hooks","grpc.meta.deadline_type":"none","grpc.meta.method_type":"bidi_stream","grpc.method":"PreReceiveHook","grpc.request.fullMethod":"/gitaly.HookService/PreReceiveHook","grpc.request.glProjectPath":"test/my-test","grpc.request.glRepository":"project-347","grpc.request.payload_bytes":2892,"grpc.request.repoPath":"@hashed/22/89/2289b221b39605c3494e7290856218e931c00af556cf7a07827108193b276511.git","grpc.request.repoStorage":"default","grpc.response.payload_bytes":1743,"grpc.service":"gitaly.HookService","grpc.start_time":"2023-05-16T12:53:54.546","grpc.time_ms":177.248,"level":"info","limit.concurrency_queue_ms":0,"msg":"finished streaming call with code OK","peer.address":"@","pid":1137,"span.kind":"server","system":"grpc","time":"2023-05-16T09:53:54.723Z","user_id":"key-11","username":"v.pupkin"}
/var/log/gitlab/gitaly/current:{"command.count":1,"command.cpu_time_ms":540,"command.inblock":0,"command.majflt":0,"command.maxrss":363712,"command.minflt":11713,"command.oublock":248,"command.real_time_ms":543,"command.spawn_token_wait_ms":0,"command.system_time_ms":399,"command.user_time_ms":141,"correlation_id":"01H0HZP27961AEQFZCDR5925QP","grpc.code":"OK","grpc.meta.client_name":"gitaly-hooks","grpc.meta.deadline_type":"none","grpc.meta.method_type":"server_stream","grpc.method":"UpdateHook","grpc.request.fullMethod":"/gitaly.HookService/UpdateHook","grpc.request.glProjectPath":"test/my-test","grpc.request.glRepository":"project-347","grpc.request.payload_bytes":2338,"grpc.request.repoPath":"@hashed/22/89/2289b221b39605c3494e7290856218e931c00af556cf7a07827108193b276511.git","grpc.request.repoStorage":"default","grpc.response.payload_bytes":4433,"grpc.service":"gitaly.HookService","grpc.start_time":"2023-05-16T12:53:54.747","grpc.time_ms":543.839,"level":"info","limit.concurrency_queue_ms":0,"msg":"finished streaming call with code OK","peer.address":"@","pid":1137,"span.kind":"server","system":"grpc","time":"2023-05-16T09:53:55.291Z","user_id":"key-11","username":"v.pupkin"}
/var/log/gitlab/gitaly/current:{"correlation_id":"01H0HZP27961AEQFZCDR5925QP","grpc.code":"OK","grpc.meta.client_name":"gitaly-hooks","grpc.meta.deadline_type":"none","grpc.meta.method_type":"bidi_stream","grpc.method":"ReferenceTransactionHook","grpc.request.fullMethod":"/gitaly.HookService/ReferenceTransactionHook","grpc.request.glProjectPath":"test/my-test","grpc.request.glRepository":"project-347","grpc.request.payload_bytes":2425,"grpc.request.repoPath":"@hashed/22/89/2289b221b39605c3494e7290856218e931c00af556cf7a07827108193b276511.git","grpc.request.repoStorage":"default","grpc.response.payload_bytes":2,"grpc.service":"gitaly.HookService","grpc.start_time":"2023-05-16T12:53:55.309","grpc.time_ms":0.173,"level":"info","limit.concurrency_queue_ms":0,"msg":"finished streaming call with code OK","peer.address":"@","pid":1137,"span.kind":"server","system":"grpc","time":"2023-05-16T09:53:55.309Z","user_id":"key-11","username":"v.pupkin"}
/var/log/gitlab/gitaly/current:{"correlation_id":"01H0HZP27961AEQFZCDR5925QP","grpc.code":"OK","grpc.meta.client_name":"gitaly-hooks","grpc.meta.deadline_type":"none","grpc.meta.method_type":"bidi_stream","grpc.method":"ReferenceTransactionHook","grpc.request.fullMethod":"/gitaly.HookService/ReferenceTransactionHook","grpc.request.glProjectPath":"test/my-test","grpc.request.glRepository":"project-347","grpc.request.payload_bytes":2427,"grpc.request.repoPath":"@hashed/22/89/2289b221b39605c3494e7290856218e931c00af556cf7a07827108193b276511.git","grpc.request.repoStorage":"default","grpc.response.payload_bytes":2,"grpc.service":"gitaly.HookService","grpc.start_time":"2023-05-16T12:53:55.327","grpc.time_ms":0.261,"level":"info","limit.concurrency_queue_ms":0,"msg":"finished streaming call with code OK","peer.address":"@","pid":1137,"span.kind":"server","system":"grpc","time":"2023-05-16T09:53:55.328Z","user_id":"key-11","username":"v.pupkin"}
/var/log/gitlab/gitaly/current:{"content_length_bytes":50,"correlation_id":"01H0HZP27961AEQFZCDR5925QP","duration_ms":31,"level":"info","method":"POST","msg":"Finished HTTP request","status":200,"time":"2023-05-16T09:53:55.378Z","url":"http://unix/api/v4/internal/post_receive"}
/var/log/gitlab/gitaly/current:{"command.count":1,"command.cpu_time_ms":25,"command.inblock":0,"command.majflt":0,"command.maxrss":363712,"command.minflt":2259,"command.oublock":16,"command.real_time_ms":31,"command.spawn_token_wait_ms":0,"command.system_time_ms":5,"command.user_time_ms":20,"correlation_id":"01H0HZP27961AEQFZCDR5925QP","grpc.code":"OK","grpc.meta.client_name":"gitaly-hooks","grpc.meta.deadline_type":"none","grpc.meta.method_type":"bidi_stream","grpc.method":"PostReceiveHook","grpc.request.fullMethod":"/gitaly.HookService/PostReceiveHook","grpc.request.glProjectPath":"test/my-test","grpc.request.glRepository":"project-347","grpc.request.payload_bytes":2362,"grpc.request.repoPath":"@hashed/22/89/2289b221b39605c3494e7290856218e931c00af556cf7a07827108193b276511.git","grpc.request.repoStorage":"default","grpc.response.payload_bytes":1922,"grpc.service":"gitaly.HookService","grpc.start_time":"2023-05-16T12:53:55.346","grpc.time_ms":63.596,"level":"info","limit.concurrency_queue_ms":0,"msg":"finished streaming call with code OK","peer.address":"@","pid":1137,"span.kind":"server","system":"grpc","time":"2023-05-16T09:53:55.410Z","user_id":"key-11","username":"v.pupkin"}
/var/log/gitlab/gitaly/current:{"correlation_id":"01H0HZP27961AEQFZCDR5925QP","diskcache":"5fa658f3-8d51-4f31-b199-1e1fd5f7bcca","grpc.meta.client_name":"gitlab-shell-git-receive-pack","grpc.meta.deadline_type":"none","grpc.meta.method_type":"bidi_stream","grpc.method":"SSHReceivePack","grpc.request.fullMethod":"/gitaly.SSHService/SSHReceivePack","grpc.request.glProjectPath":"test/my-test","grpc.request.glRepository":"project-347","grpc.request.repoPath":"@hashed/22/89/2289b221b39605c3494e7290856218e931c00af556cf7a07827108193b276511.git","grpc.request.repoStorage":"default","grpc.service":"gitaly.SSHService","grpc.start_time":"2023-05-16T12:53:54.512","level":"info","msg":"diskcache state change","peer.address":"@","pid":1137,"remote_ip":"192.168.22.8","span.kind":"server","system":"grpc","time":"2023-05-16T09:53:55.415Z","user_id":"user-18","username":"v.pupkin"}
/var/log/gitlab/gitaly/current:{"command.count":2,"command.cpu_time_ms":146,"command.inblock":0,"command.majflt":0,"command.maxrss":363712,"command.minflt":15981,"command.oublock":56,"command.real_time_ms":900,"command.spawn_token_wait_ms":0,"command.system_time_ms":46,"command.user_time_ms":100,"correlation_id":"01H0HZP27961AEQFZCDR5925QP","grpc.code":"OK","grpc.meta.client_name":"gitlab-shell-git-receive-pack","grpc.meta.deadline_type":"none","grpc.meta.method_type":"bidi_stream","grpc.method":"SSHReceivePack","grpc.request.fullMethod":"/gitaly.SSHService/SSHReceivePack","grpc.request.glProjectPath":"test/my-test","grpc.request.glRepository":"project-347","grpc.request.payload_bytes":1130,"grpc.request.repoPath":"@hashed/22/89/2289b221b39605c3494e7290856218e931c00af556cf7a07827108193b276511.git","grpc.request.repoStorage":"default","grpc.response.payload_bytes":9089,"grpc.service":"gitaly.SSHService","grpc.start_time":"2023-05-16T12:53:54.512","grpc.time_ms":903.121,"level":"info","limit.concurrency_queue_ms":0,"msg":"finished streaming call with code OK","peer.address":"@","pid":1137,"remote_ip":"192.168.22.8","span.kind":"server","system":"grpc","time":"2023-05-16T09:53:55.415Z","user_id":"user-18","username":"v.pupkin"}
/var/log/gitlab/gitlab-shell/gitlab-shell.log:{"command":"*receivepack.Command","correlation_id":"01H0HZP27961AEQFZCDR5925QP","env":{"GitProtocolVersion":"","IsSSHConnection":true,"OriginalCommand":"git-receive-pack 'test/my-test.git'","RemoteAddr":"192.168.22.8"},"level":"info","msg":"gitlab-shell: main: executing command","time":"2023-05-16T09:53:54Z"}
/var/log/gitlab/gitlab-shell/gitlab-shell.log:{"content_length_bytes":643,"correlation_id":"01H0HZP27961AEQFZCDR5925QP","duration_ms":100,"level":"info","method":"POST","msg":"Finished HTTP request","status":200,"time":"2023-05-16T09:53:54Z","url":"http://unix/api/v4/internal/allowed"}
/var/log/gitlab/gitlab-shell/gitlab-shell.log:{"command":"git-receive-pack","correlation_id":"01H0HZP27961AEQFZCDR5925QP","git_protocol":"","gl_key_id":11,"gl_key_type":"key","gl_project_path":"test/my-test","gl_repository":"project-347","level":"info","msg":"executing git command","remote_ip":"192.168.22.8","time":"2023-05-16T09:53:54Z","user_id":"user-18","username":"v.pupkin"}
/var/log/gitlab/gitlab-shell/gitlab-shell.log:{"correlation_id":"01H0HZP27961AEQFZCDR5925QP","level":"info","msg":"gitlab-shell: main: command executed successfully","time":"2023-05-16T09:53:55Z"}
web сессия
/var/log/gitlab/gitlab-workhorse/current:{"content_type":"text/html; charset=utf-8","correlation_id":"01H0HZQC62ED3N4ZX6SK7R31KM","duration_ms":854,"host":"192.168.138.10","level":"info","method":"POST","msg":"access","proto":"HTTP/1.1","referrer":"https://192.168.138.10/test/my-test/-/edit/main/date.text","remote_addr":"127.0.0.1:0","remote_ip":"127.0.0.1","route":"","status":302,"system":"http","time":"2023-05-16T12:54:38+03:00","ttfb_ms":854,"uri":"/test/my-test/-/update/main/date.text","user_agent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/112.0","written_bytes":127}
/var/log/gitlab/gitlab-rails/production_json.log:{"method":"PUT","path":"/test/my-test/-/update/main/date.text","format":"html","controller":"Projects::BlobController","action":"update","status":302,"location":"https://192.168.138.10/test/my-test/-/blob/main/date.text","time":"2023-05-16T09:54:38.229Z","params":[{"key":"_method","value":"put"},{"key":"authenticity_token","value":"[FILTERED]"},{"key":"file_path","value":"date.text"},{"key":"commit_message","value":"Update date.text"},{"key":"branch_name","value":"main"},{"key":"original_branch","value":"main"},{"key":"last_commit_sha","value":"d9bf7a90a552922b393be5968989b0769245108f"},{"key":"content","value":"[FILTERED]"},{"key":"from_merge_request_iid","value":""},{"key":"namespace_id","value":"test"},{"key":"project_id","value":"my-test"},{"key":"id","value":"main/date.text"}],"correlation_id":"01H0HZQC62ED3N4ZX6SK7R31KM","meta.caller_id":"Projects::BlobController#update","meta.remote_ip":"192.168.23.128","meta.feature_category":"source_code_management","meta.user":"v.pupkin","meta.user_id":18,"meta.project":"test/my-test","meta.root_namespace":"test","meta.client_id":"user/18","meta.subscription_plan":"default","remote_ip":"192.168.23.128","user_id":18,"username":"v.pupkin","ua":"Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/112.0","queue_duration_s":0.011339,"request_urgency":"low","target_duration_s":5,"gitaly_calls":6,"gitaly_duration_s":0.760967,"redis_calls":20,"redis_allowed_cross_slot_calls":1,"redis_duration_s":0.003534,"redis_read_bytes":2143,"redis_write_bytes":2001,"redis_cache_calls":9,"redis_cache_duration_s":0.001519,"redis_cache_read_bytes":1625,"redis_cache_write_bytes":563,"redis_repository_cache_calls":7,"redis_repository_cache_duration_s":0.00077,"redis_repository_cache_read_bytes":337,"redis_repository_cache_write_bytes":290,"redis_sessions_calls":3,"redis_sessions_allowed_cross_slot_calls":1,"redis_sessions_duration_s":0.001098,"redis_sessions_read_bytes":181,"redis_sessions_write_bytes":1094,"redis_shared_state_calls":1,"redis_shared_state_duration_s":0.000147,"redis_shared_state_write_bytes":54,"db_count":24,"db_write_count":0,"db_cached_count":4,"db_replica_count":0,"db_primary_count":24,"db_main_count":24,"db_main_replica_count":0,"db_replica_cached_count":0,"db_primary_cached_count":4,"db_main_cached_count":4,"db_main_replica_cached_count":0,"db_replica_wal_count":0,"db_primary_wal_count":0,"db_main_wal_count":0,"db_main_replica_wal_count":0,"db_replica_wal_cached_count":0,"db_primary_wal_cached_count":0,"db_main_wal_cached_count":0,"db_main_replica_wal_cached_count":0,"db_replica_duration_s":0.0,"db_primary_duration_s":0.013,"db_main_duration_s":0.013,"db_main_replica_duration_s":0.0,"cpu_s":0.084794,"mem_objects":36833,"mem_bytes":4723032,"mem_mallocs":10611,"mem_total_bytes":6196352,"pid":357535,"worker_id":"puma_2","rate_limiting_gates":[],"db_duration_s":0.00923,"view_duration_s":0.0,"duration_s":0.8232}
/var/log/gitlab/gitaly/current:{"catfile.duration_ms":0,"catfile.flush_count":1,"catfile.flush_ms":0,"catfile.read_object_count":1,"catfile.read_object_ms":0,"catfile.request_object_count":1,"catfile.request_object_ms":0,"command.count":1,"command.cpu_time_ms":1,"command.inblock":0,"command.majflt":0,"command.maxrss":363712,"command.minflt":156,"command.oublock":0,"command.real_time_ms":1,"command.spawn_token_wait_ms":0,"command.system_time_ms":1,"command.user_time_ms":0,"correlation_id":"01H0HZQC62ED3N4ZX6SK7R31KM","grpc.code":"OK","grpc.meta.auth_version":"v2","grpc.meta.client_name":"gitlab-web","grpc.meta.deadline_type":"regular","grpc.meta.method_type":"unary","grpc.method":"FindCommit","grpc.request.deadline":"2023-05-16T12:55:07.036","grpc.request.fullMethod":"/gitaly.CommitService/FindCommit","grpc.request.glProjectPath":"test/my-test","grpc.request.glRepository":"project-347","grpc.request.payload_bytes":133,"grpc.request.repoPath":"@hashed/22/89/2289b221b39605c3494e7290856218e931c00af556cf7a07827108193b276511.git","grpc.request.repoStorage":"default","grpc.response.payload_bytes":384,"grpc.service":"gitaly.CommitService","grpc.start_time":"2023-05-16T12:54:37.436","grpc.time_ms":2.52,"level":"info","limit.concurrency_queue_ms":0,"msg":"finished unary call with code OK","peer.address":"@","pid":1137,"remote_ip":"192.168.23.128","span.kind":"server","system":"grpc","time":"2023-05-16T09:54:37.439Z","user_id":"18","username":"v.pupkin"}
/var/log/gitlab/gitaly/current:{"catfile.duration_ms":0,"catfile.flush_count":4,"catfile.flush_ms":0,"catfile.read_info_count":2,"catfile.read_info_ms":0,"catfile.read_object_count":2,"catfile.read_object_ms":0,"catfile.request_info_count":2,"catfile.request_info_ms":0,"catfile.request_object_count":2,"catfile.request_object_ms":0,"command.count":1,"command.cpu_time_ms":0,"command.inblock":0,"command.majflt":0,"command.maxrss":363712,"command.minflt":155,"command.oublock":0,"command.real_time_ms":1,"command.spawn_token_wait_ms":0,"command.system_time_ms":0,"command.user_time_ms":0,"correlation_id":"01H0HZQC62ED3N4ZX6SK7R31KM","grpc.code":"OK","grpc.meta.auth_version":"v2","grpc.meta.client_name":"gitlab-web","grpc.meta.deadline_type":"regular","grpc.meta.method_type":"server_stream","grpc.method":"TreeEntry","grpc.request.deadline":"2023-05-16T12:55:07.040","grpc.request.fullMethod":"/gitaly.CommitService/TreeEntry","grpc.request.glProjectPath":"test/my-test","grpc.request.glRepository":"project-347","grpc.request.payload_bytes":185,"grpc.request.repoPath":"@hashed/22/89/2289b221b39605c3494e7290856218e931c00af556cf7a07827108193b276511.git","grpc.request.repoStorage":"default","grpc.response.payload_bytes":2374,"grpc.service":"gitaly.CommitService","grpc.start_time":"2023-05-16T12:54:37.440","grpc.time_ms":2.257,"level":"info","limit.concurrency_queue_ms":0,"msg":"finished streaming call with code OK","peer.address":"@","pid":1137,"remote_ip":"192.168.23.128","span.kind":"server","system":"grpc","time":"2023-05-16T09:54:37.442Z","user_id":"18","username":"v.pupkin"}
/var/log/gitlab/gitaly/current:{"catfile.duration_ms":0,"catfile.flush_count":1,"catfile.flush_ms":0,"catfile.read_object_count":1,"catfile.read_object_ms":0,"catfile.request_object_count":1,"catfile.request_object_ms":0,"command.count":1,"command.cpu_time_ms":0,"command.inblock":0,"command.majflt":0,"command.maxrss":363712,"command.minflt":152,"command.oublock":0,"command.real_time_ms":1,"command.spawn_token_wait_ms":0,"command.system_time_ms":0,"command.user_time_ms":0,"correlation_id":"01H0HZQC62ED3N4ZX6SK7R31KM","grpc.code":"OK","grpc.meta.auth_version":"v2","grpc.meta.client_name":"gitlab-web","grpc.meta.deadline_type":"regular","grpc.meta.method_type":"server_stream","grpc.method":"FindCommits","grpc.request.deadline":"2023-05-16T12:55:07.044","grpc.request.fullMethod":"/gitaly.CommitService/FindCommits","grpc.request.glProjectPath":"test/my-test","grpc.request.glRepository":"project-347","grpc.request.payload_bytes":152,"grpc.request.repoPath":"@hashed/22/89/2289b221b39605c3494e7290856218e931c00af556cf7a07827108193b276511.git","grpc.request.repoStorage":"default","grpc.response.payload_bytes":384,"grpc.service":"gitaly.CommitService","grpc.start_time":"2023-05-16T12:54:37.444","grpc.time_ms":3.245,"level":"info","limit.concurrency_queue_ms":0,"msg":"finished streaming call with code OK","peer.address":"@","pid":1137,"remote_ip":"192.168.23.128","span.kind":"server","system":"grpc","time":"2023-05-16T09:54:37.448Z","user_id":"18","username":"v.pupkin"}
/var/log/gitlab/gitaly/current:{"catfile.duration_ms":0,"catfile.flush_count":1,"catfile.flush_ms":0,"catfile.read_object_count":1,"catfile.read_object_ms":0,"catfile.request_object_count":1,"catfile.request_object_ms":0,"command.spawn_token_wait_ms":0,"correlation_id":"01H0HZQC62ED3N4ZX6SK7R31KM","grpc.code":"OK","grpc.meta.auth_version":"v2","grpc.meta.client_name":"gitlab-web","grpc.meta.deadline_type":"regular","grpc.meta.method_type":"server_stream","grpc.method":"FindCommits","grpc.request.deadline":"2023-05-16T12:55:07.069","grpc.request.fullMethod":"/gitaly.CommitService/FindCommits","grpc.request.glProjectPath":"test/my-test","grpc.request.glRepository":"project-347","grpc.request.payload_bytes":152,"grpc.request.repoPath":"@hashed/22/89/2289b221b39605c3494e7290856218e931c00af556cf7a07827108193b276511.git","grpc.request.repoStorage":"default","grpc.response.payload_bytes":384,"grpc.service":"gitaly.CommitService","grpc.start_time":"2023-05-16T12:54:37.469","grpc.time_ms":1.674,"level":"info","limit.concurrency_queue_ms":0,"msg":"finished streaming call with code OK","peer.address":"@","pid":1137,"remote_ip":"192.168.23.128","span.kind":"server","system":"grpc","time":"2023-05-16T09:54:37.471Z","user_id":"18","username":"v.pupkin"}
/var/log/gitlab/gitaly/current:{"catfile.duration_ms":0,"catfile.flush_count":1,"catfile.flush_ms":0,"catfile.read_object_count":1,"catfile.read_object_ms":0,"catfile.request_object_count":1,"catfile.request_object_ms":0,"command.spawn_token_wait_ms":0,"correlation_id":"01H0HZQC62ED3N4ZX6SK7R31KM","grpc.code":"OK","grpc.meta.auth_version":"v2","grpc.meta.client_name":"gitlab-web","grpc.meta.deadline_type":"regular","grpc.meta.method_type":"server_stream","grpc.method":"FindCommits","grpc.request.deadline":"2023-05-16T12:55:07.072","grpc.request.fullMethod":"/gitaly.CommitService/FindCommits","grpc.request.glProjectPath":"test/my-test","grpc.request.glRepository":"project-347","grpc.request.payload_bytes":188,"grpc.request.repoPath":"@hashed/22/89/2289b221b39605c3494e7290856218e931c00af556cf7a07827108193b276511.git","grpc.request.repoStorage":"default","grpc.response.payload_bytes":384,"grpc.service":"gitaly.CommitService","grpc.start_time":"2023-05-16T12:54:37.472","grpc.time_ms":1.538,"level":"info","limit.concurrency_queue_ms":0,"msg":"finished streaming call with code OK","peer.address":"@","pid":1137,"remote_ip":"192.168.23.128","span.kind":"server","system":"grpc","time":"2023-05-16T09:54:37.474Z","user_id":"18","username":"v.pupkin"}
/var/log/gitlab/gitaly/current:{"command.name":"gitaly-git2go","command.subcommand":"commit","correlation_id":"01H0HZQC62ED3N4ZX6SK7R31KM","disabled_feature_flags":null,"enabled_feature_flags":null,"level":"info","msg":"starting commit command","pid":371582,"time":"2023-05-16T09:54:37.489Z"}
/var/log/gitlab/gitaly/current:{"command.name":"gitaly-git2go","command.subcommand":"commit","correlation_id":"01H0HZQC62ED3N4ZX6SK7R31KM","disabled_feature_flags":null,"enabled_feature_flags":null,"level":"info","msg":"commit command finished","pid":371582,"time":"2023-05-16T09:54:37.493Z"}
/var/log/gitlab/gitaly/current:{"content_length_bytes":679,"correlation_id":"01H0HZQC62ED3N4ZX6SK7R31KM","duration_ms":80,"level":"info","method":"POST","msg":"Finished HTTP request","status":200,"time":"2023-05-16T09:54:37.578Z","url":"http://unix/api/v4/internal/allowed"}
/var/log/gitlab/gitaly/current:{"content_length_bytes":36,"correlation_id":"01H0HZQC62ED3N4ZX6SK7R31KM","duration_ms":17,"level":"info","method":"POST","msg":"Finished HTTP request","status":200,"time":"2023-05-16T09:54:37.736Z","url":"http://unix/api/v4/internal/pre_receive"}
/var/log/gitlab/gitaly/current:{"content_length_bytes":50,"correlation_id":"01H0HZQC62ED3N4ZX6SK7R31KM","duration_ms":33,"level":"info","method":"POST","msg":"Finished HTTP request","status":200,"time":"2023-05-16T09:54:38.188Z","url":"http://unix/api/v4/internal/post_receive"}
/var/log/gitlab/gitaly/current:{"correlation_id":"01H0HZQC62ED3N4ZX6SK7R31KM","diskcache":"7ae890e5-dc93-4db4-bed3-e4aa224899c1","grpc.meta.auth_version":"v2","grpc.meta.client_name":"gitlab-web","grpc.meta.deadline_type":"regular","grpc.meta.method_type":"client_stream","grpc.method":"UserCommitFiles","grpc.request.deadline":"2023-05-16T12:55:32.075","grpc.request.fullMethod":"/gitaly.OperationService/UserCommitFiles","grpc.service":"gitaly.OperationService","grpc.start_time":"2023-05-16T12:54:37.475","level":"info","msg":"diskcache state change","peer.address":"@","pid":1137,"remote_ip":"192.168.23.128","span.kind":"server","system":"grpc","time":"2023-05-16T09:54:38.217Z","user_id":"18","username":"v.pupkin"}
/var/log/gitlab/gitaly/current:{"command.count":12,"command.cpu_time_ms":602,"command.inblock":0,"command.majflt":0,"command.maxrss":363712,"command.minflt":19408,"command.oublock":248,"command.real_time_ms":660,"command.spawn_token_wait_ms":0,"command.system_time_ms":360,"command.user_time_ms":242,"correlation_id":"01H0HZQC62ED3N4ZX6SK7R31KM","grpc.code":"OK","grpc.meta.auth_version":"v2","grpc.meta.client_name":"gitlab-web","grpc.meta.deadline_type":"regular","grpc.meta.method_type":"client_stream","grpc.method":"UserCommitFiles","grpc.request.deadline":"2023-05-16T12:55:32.075","grpc.request.fullMethod":"/gitaly.OperationService/UserCommitFiles","grpc.request.payload_bytes":2958,"grpc.response.payload_bytes":44,"grpc.service":"gitaly.OperationService","grpc.start_time":"2023-05-16T12:54:37.475","grpc.time_ms":741.281,"level":"info","limit.concurrency_queue_ms":0,"msg":"finished streaming call with code OK","peer.address":"@","pid":1137,"remote_ip":"192.168.23.128","span.kind":"server","system":"grpc","time":"2023-05-16T09:54:38.217Z","user_id":"18","username":"v.pupkin"}
http сессия
/var/log/gitlab/gitlab-workhorse/current:{"content_type":"application/x-git-receive-pack-result","correlation_id":"01H0HZPR6CKZCANMG56HXD3WQD","duration_ms":980,"host":"192.168.138.10","level":"info","method":"POST","msg":"access","proto":"HTTP/1.1","referrer":"","remote_addr":"127.0.0.1:0","remote_ip":"127.0.0.1","route":"^/.+\\.git/git-receive-pack\\z","status":200,"system":"http","time":"2023-05-16T12:54:17+03:00","ttfb_ms":215,"uri":"/test/my-test.git/git-receive-pack","user_agent":"git/2.34.1.windows.1","written_bytes":9564}
/var/log/gitlab/gitlab-rails/production_json.log:{"method":"POST","path":"/test/my-test.git/git-receive-pack","format":null,"controller":"Repositories::GitHttpController","action":"git_receive_pack","status":200,"time":"2023-05-16T09:54:16.975Z","params":[{"key":"repository_path","value":"test/my-test.git"}],"correlation_id":"01H0HZPR6CKZCANMG56HXD3WQD","meta.caller_id":"Repositories::GitHttpController#git_receive_pack","meta.remote_ip":"192.168.23.128","meta.feature_category":"source_code_management","meta.user":"v.pupkin","meta.user_id":18,"meta.project":"test/my-test","meta.root_namespace":"test","meta.client_id":"user/18","remote_ip":"192.168.23.128","user_id":18,"username":"v.pupkin","ua":"git/2.34.1.windows.1","request_urgency":"default","target_duration_s":1,"redis_calls":1,"redis_duration_s":0.000274,"redis_read_bytes":107,"redis_write_bytes":45,"redis_repository_cache_calls":1,"redis_repository_cache_duration_s":0.000274,"redis_repository_cache_read_bytes":107,"redis_repository_cache_write_bytes":45,"db_count":17,"db_write_count":0,"db_cached_count":1,"db_replica_count":0,"db_primary_count":17,"db_main_count":17,"db_main_replica_count":0,"db_replica_cached_count":0,"db_primary_cached_count":1,"db_main_cached_count":1,"db_main_replica_cached_count":0,"db_replica_wal_count":0,"db_primary_wal_count":0,"db_main_wal_count":0,"db_main_replica_wal_count":0,"db_replica_wal_cached_count":0,"db_primary_wal_cached_count":0,"db_main_wal_cached_count":0,"db_main_replica_wal_cached_count":0,"db_replica_duration_s":0.0,"db_primary_duration_s":0.011,"db_main_duration_s":0.011,"db_main_replica_duration_s":0.0,"cpu_s":0.051404,"mem_objects":24822,"mem_bytes":2047088,"mem_mallocs":6899,"mem_total_bytes":3039968,"pid":357535,"worker_id":"puma_2","rate_limiting_gates":[],"db_duration_s":0.01012,"view_duration_s":0.00031,"duration_s":0.05654}
/var/log/gitlab/gitaly/current:{"content_length_bytes":651,"correlation_id":"01H0HZPR6CKZCANMG56HXD3WQD","duration_ms":115,"level":"info","method":"POST","msg":"Finished HTTP request","status":200,"time":"2023-05-16T09:54:17.122Z","url":"http://unix/api/v4/internal/allowed"}
/var/log/gitlab/gitaly/current:{"content_length_bytes":36,"correlation_id":"01H0HZPR6CKZCANMG56HXD3WQD","duration_ms":22,"level":"info","method":"POST","msg":"Finished HTTP request","status":200,"time":"2023-05-16T09:54:17.341Z","url":"http://unix/api/v4/internal/pre_receive"}
/var/log/gitlab/gitaly/current:{"command.count":1,"command.cpu_time_ms":198,"command.inblock":0,"command.majflt":0,"command.maxrss":363712,"command.minflt":7426,"command.oublock":48,"command.real_time_ms":195,"command.spawn_token_wait_ms":0,"command.system_time_ms":125,"command.user_time_ms":73,"correlation_id":"01H0HZPR6CKZCANMG56HXD3WQD","grpc.code":"OK","grpc.meta.client_name":"gitaly-hooks","grpc.meta.deadline_type":"none","grpc.meta.method_type":"bidi_stream","grpc.method":"PreReceiveHook","grpc.request.fullMethod":"/gitaly.HookService/PreReceiveHook","grpc.request.glProjectPath":"test/my-test","grpc.request.glRepository":"project-347","grpc.request.payload_bytes":2825,"grpc.request.repoPath":"@hashed/22/89/2289b221b39605c3494e7290856218e931c00af556cf7a07827108193b276511.git","grpc.request.repoStorage":"default","grpc.response.payload_bytes":3900,"grpc.service":"gitaly.HookService","grpc.start_time":"2023-05-16T12:54:17.006","grpc.time_ms":335.289,"level":"info","limit.concurrency_queue_ms":0,"msg":"finished streaming call with code OK","peer.address":"@","pid":1137,"span.kind":"server","system":"grpc","time":"2023-05-16T09:54:17.341Z","user_id":"user-18","username":"v.pupkin"}
/var/log/gitlab/gitaly/current:{"command.count":1,"command.cpu_time_ms":420,"command.inblock":0,"command.majflt":0,"command.maxrss":363712,"command.minflt":8820,"command.oublock":176,"command.real_time_ms":418,"command.spawn_token_wait_ms":0,"command.system_time_ms":297,"command.user_time_ms":123,"correlation_id":"01H0HZPR6CKZCANMG56HXD3WQD","grpc.code":"OK","grpc.meta.client_name":"gitaly-hooks","grpc.meta.deadline_type":"none","grpc.meta.method_type":"server_stream","grpc.method":"UpdateHook","grpc.request.fullMethod":"/gitaly.HookService/UpdateHook","grpc.request.glProjectPath":"test/my-test","grpc.request.glRepository":"project-347","grpc.request.payload_bytes":2271,"grpc.request.repoPath":"@hashed/22/89/2289b221b39605c3494e7290856218e931c00af556cf7a07827108193b276511.git","grpc.request.repoStorage":"default","grpc.response.payload_bytes":3442,"grpc.service":"gitaly.HookService","grpc.start_time":"2023-05-16T12:54:17.359","grpc.time_ms":418.711,"level":"info","limit.concurrency_queue_ms":0,"msg":"finished streaming call with code OK","peer.address":"@","pid":1137,"span.kind":"server","system":"grpc","time":"2023-05-16T09:54:17.777Z","user_id":"user-18","username":"v.pupkin"}
/var/log/gitlab/gitaly/current:{"correlation_id":"01H0HZPR6CKZCANMG56HXD3WQD","grpc.code":"OK","grpc.meta.client_name":"gitaly-hooks","grpc.meta.deadline_type":"none","grpc.meta.method_type":"bidi_stream","grpc.method":"ReferenceTransactionHook","grpc.request.fullMethod":"/gitaly.HookService/ReferenceTransactionHook","grpc.request.glProjectPath":"test/my-test","grpc.request.glRepository":"project-347","grpc.request.payload_bytes":2358,"grpc.request.repoPath":"@hashed/22/89/2289b221b39605c3494e7290856218e931c00af556cf7a07827108193b276511.git","grpc.request.repoStorage":"default","grpc.response.payload_bytes":2,"grpc.service":"gitaly.HookService","grpc.start_time":"2023-05-16T12:54:17.794","grpc.time_ms":0.3,"level":"info","limit.concurrency_queue_ms":0,"msg":"finished streaming call with code OK","peer.address":"@","pid":1137,"span.kind":"server","system":"grpc","time":"2023-05-16T09:54:17.794Z","user_id":"user-18","username":"v.pupkin"}
/var/log/gitlab/gitaly/current:{"correlation_id":"01H0HZPR6CKZCANMG56HXD3WQD","grpc.code":"OK","grpc.meta.client_name":"gitaly-hooks","grpc.meta.deadline_type":"none","grpc.meta.method_type":"bidi_stream","grpc.method":"ReferenceTransactionHook","grpc.request.fullMethod":"/gitaly.HookService/ReferenceTransactionHook","grpc.request.glProjectPath":"test/my-test","grpc.request.glRepository":"project-347","grpc.request.payload_bytes":2360,"grpc.request.repoPath":"@hashed/22/89/2289b221b39605c3494e7290856218e931c00af556cf7a07827108193b276511.git","grpc.request.repoStorage":"default","grpc.response.payload_bytes":2,"grpc.service":"gitaly.HookService","grpc.start_time":"2023-05-16T12:54:17.809","grpc.time_ms":0.178,"level":"info","limit.concurrency_queue_ms":0,"msg":"finished streaming call with code OK","peer.address":"@","pid":1137,"span.kind":"server","system":"grpc","time":"2023-05-16T09:54:17.809Z","user_id":"user-18","username":"v.pupkin"}
/var/log/gitlab/gitaly/current:{"content_length_bytes":50,"correlation_id":"01H0HZPR6CKZCANMG56HXD3WQD","duration_ms":32,"level":"info","method":"POST","msg":"Finished HTTP request","status":200,"time":"2023-05-16T09:54:17.858Z","url":"http://unix/api/v4/internal/post_receive"}
/var/log/gitlab/gitaly/current:{"command.count":1,"command.cpu_time_ms":22,"command.inblock":0,"command.majflt":0,"command.maxrss":363712,"command.minflt":1489,"command.oublock":24,"command.real_time_ms":25,"command.spawn_token_wait_ms":0,"command.system_time_ms":8,"command.user_time_ms":14,"correlation_id":"01H0HZPR6CKZCANMG56HXD3WQD","grpc.code":"OK","grpc.meta.client_name":"gitaly-hooks","grpc.meta.deadline_type":"none","grpc.meta.method_type":"bidi_stream","grpc.method":"PostReceiveHook","grpc.request.fullMethod":"/gitaly.HookService/PostReceiveHook","grpc.request.glProjectPath":"test/my-test","grpc.request.glRepository":"project-347","grpc.request.payload_bytes":2295,"grpc.request.repoPath":"@hashed/22/89/2289b221b39605c3494e7290856218e931c00af556cf7a07827108193b276511.git","grpc.request.repoStorage":"default","grpc.response.payload_bytes":1819,"grpc.service":"gitaly.HookService","grpc.start_time":"2023-05-16T12:54:17.826","grpc.time_ms":58.616,"level":"info","limit.concurrency_queue_ms":0,"msg":"finished streaming call with code OK","peer.address":"@","pid":1137,"span.kind":"server","system":"grpc","time":"2023-05-16T09:54:17.884Z","user_id":"user-18","username":"v.pupkin"}
/var/log/gitlab/gitaly/current:{"correlation_id":"01H0HZPR6CKZCANMG56HXD3WQD","diskcache":"d51baf96-1e50-4f12-8bdb-5167f54139c1","grpc.meta.auth_version":"v2","grpc.meta.client_name":"gitlab-workhorse","grpc.meta.deadline_type":"none","grpc.meta.method_type":"bidi_stream","grpc.method":"PostReceivePack","grpc.request.fullMethod":"/gitaly.SmartHTTPService/PostReceivePack","grpc.request.glProjectPath":"test/my-test","grpc.request.glRepository":"project-347","grpc.request.repoPath":"@hashed/22/89/2289b221b39605c3494e7290856218e931c00af556cf7a07827108193b276511.git","grpc.request.repoStorage":"default","grpc.service":"gitaly.SmartHTTPService","grpc.start_time":"2023-05-16T12:54:16.978","level":"info","msg":"diskcache state change","peer.address":"@","pid":1137,"remote_ip":"192.168.23.128","span.kind":"server","system":"grpc","time":"2023-05-16T09:54:17.888Z","user_id":"user-18","username":"v.pupkin"}
/var/log/gitlab/gitaly/current:{"command.count":2,"command.cpu_time_ms":143,"command.inblock":0,"command.majflt":0,"command.maxrss":363712,"command.minflt":15998,"command.oublock":32,"command.real_time_ms":907,"command.spawn_token_wait_ms":0,"command.system_time_ms":58,"command.user_time_ms":85,"correlation_id":"01H0HZPR6CKZCANMG56HXD3WQD","grpc.code":"OK","grpc.meta.auth_version":"v2","grpc.meta.client_name":"gitlab-workhorse","grpc.meta.deadline_type":"none","grpc.meta.method_type":"bidi_stream","grpc.method":"PostReceivePack","grpc.request.fullMethod":"/gitaly.SmartHTTPService/PostReceivePack","grpc.request.glProjectPath":"test/my-test","grpc.request.glRepository":"project-347","grpc.request.payload_bytes":728,"grpc.request.repoPath":"@hashed/22/89/2289b221b39605c3494e7290856218e931c00af556cf7a07827108193b276511.git","grpc.request.repoStorage":"default","grpc.response.payload_bytes":9941,"grpc.service":"gitaly.SmartHTTPService","grpc.start_time":"2023-05-16T12:54:16.978","grpc.time_ms":910.336,"level":"info","limit.concurrency_queue_ms":0,"msg":"finished streaming call with code OK","peer.address":"@","pid":1137,"remote_ip":"192.168.23.128","span.kind":"server","system":"grpc","time":"2023-05-16T09:54:17.888Z","user_id":"user-18","username":"v.pupkin"}
Как видно из логов, состоящих максимум из 14 строк на одну операцию, внутри находится огромное количество служебной информации, довольно сильно затрудняющей поиск данных. По своей сути прекрасно придуманный механизм корреляции оказался довольно бестолковым, т.к. по нему нельзя восстановить полную хронологию событий.
После пары итераций по оптимизации механизмов поиска «вручную», было принято решение сделать универсальный механизм и пересобрать все получаемые структуры в единый формат и отправить во внутреннюю поисковую систему.
Исправляем структуры данных
В качестве механизма для сбора логов и замены структур данных был выбран наиболее мощный, популярный и доступный продукт https://www.elastic.co/beats/filebeat
Путём поиска в журналах gitlab нужной информации, было выяснено, что 99% нужных действий находятся в 4х файлах. Сразу оговорюсь, что мы не рассматриваем в этой статье события аутентификации, блокировки пользователя по rate-limit и прочие.
Все шаблоны и файлы по статье находятся в репозитории указанном в конце.
Итак файлы с данными:
/var/log/gitlab/gitlab-rails/api_json.log
/var/log/gitlab/gitaly/current
/var/log/gitlab/gitlab-shell/gitlab-shell.log
/var/log/gitlab/gitlab-rails/production_json.log
Исправляемые структуры во всех журналах +- похожи, поэтому остановимся на общих принципах и мелких особенностях каждого из журналов.
Все исправляемые структуры представлены в формате JSON, поэтому первым делом нам необходимо распаковать данные для того, чтобы filebeat мог ими оперировать.
Убираем лишние строки содержащие 'allowed', включаем парсер для данных и перемещаем данные в корень нового объекта.
exclude_lines: ['allowed']
parsers:
- ndjson:
target: ""
message_key: message
json:
keys_under_root: true
Преобразование данных для api_json:
декодируем сообщение
удаляем часть служебных полей связанных метриками запроса
удаляем все события содержащие данные от ранеров
удаляем все события не содержащие интересующие нас методы "post_receive" и "merge_request/approve"
добавляем метаданные, формируем ветку в рамках которой будут данные об операции
в логе api_json и production_json, часть операций содержит опциональную ветку "params", в которой в виде массива [ { "key": "xxx", "value": "yyy"}, { "key": "xxx", "value": "yyy"}] находятся параметры операции. filebeat имеет встроенный интерпретатор языка ECMAScript 5.1 https://www.elastic.co/guide/en/beats/filebeat/current/processor-script.html, на котором можно писать код. При помощи небольшой функции переформатируем данные в формат key:value, но с правильными названиями полей и их значениями.
перемещаем необходимые поля в новую структуру
копируем и переименовываем существующие поля в нашу целевую структуру
повторно удаляем остатки данных
добавляем тэг "gitlab"
api_json
api_json.yml
processors:
- decode_json_fields:
fields: ["message"]
- drop_fields:
fields: ['graphql','/^db_(.*)$/','/^redis_(.*)$/','/^mem_/','/^duration_/','/^cpu_/','log','agent','/.*\_duration\_.*/','pid']
- drop_event:
when:
or:
- equals:
"meta.remote_ip": "192.168.11.14"
- equals:
"meta.remote_ip": "192.168.11.16"
- and:
- not.equals:
"meta.caller_id": "POST /api/:version/internal/post_receive"
- not.equals:
"meta.caller_id": "POST /api/:version/projects/:id/merge_requests/:merge_request_iid/approve"
- add_fields:
target: '@metadata'
fields:
log_source: "api_json-log"
- add_fields:
target: 'track'
fields:
log_source: "api_json"
repository: ""
msg: ""
- script:
lang: javascript
#file: ./remap.js
source: >
function process(event) {
var data = event.Get('params');
event.Rename('params','old_params')
for (var field in data) {
event.Put("params."+data[field].key, data[field].value)
}
event.Delete('old_params')
}
- move_fields:
from: ""
fields: ["meta.project","remote_ip","action","time","params","user_id","ua","controller","path","meta.user"]
to: "track."
ignore_missing: true
- copy_fields:
fields:
- from: "track.path"
to: "track.command"
- from: "track.meta.user"
to: "track.username"
fail_on_error: false
ignore_missing: true
- rename:
fields:
- from: "track.meta.project"
to: "track.project_path"
- from: "track.time"
to: "track.action_time"
- drop_fields:
fields: ['graphql','/^db_(.*)$/','/^redis_(.*)$/','/^mem_/','/^duration_/','/^cpu_/','log','agent','/.*\_duration\_.*/',
'pid','method','status','correlation_id',"meta.root_namespace","meta.client_id","request_urgency","format",
"meta.feature_category","meta.user","meta.caller_id","meta.remote_ip","track.meta"]
ignore_missing: true
- add_tags:
tags: [gitlab]
Обработка коммита в api_json
api_json
Исходные данные
{
"time": "2023-07-20T14:26:56.494Z",
"severity": "INFO",
"duration_s": 0.04175,
"db_duration_s": 0.00601,
"view_duration_s": 0.03574,
"status": 200,
"method": "POST",
"path": "/api/v4/internal/allowed",
"params": [
{
"key": "action",
"value": "git-receive-pack"
},
{
"key": "gl_repository",
"value": "project-465"
},
{
"key": "project",
"value": "/opt/gitlab-data/git-data/repositories/@hashed/ad/3b/ad3b83575249b68aab9602de378314fc221ab07a9b2ab0bb4a245ec649219f45.git"
},
{
"key": "changes",
"value": "fc192211792561b492261dfdbd82b44694b565ff 7b85fb31027e7531cf7e1c3ef48e8791a6a63025 refs/heads/feature/FT-1448\n"
},
{
"key": "protocol",
"value": "ssh"
},
{
"key": "env",
"value": "{\"GIT_ALTERNATE_OBJECT_DIRECTORIES_RELATIVE\":[\"objects\"],\"GIT_OBJECT_DIRECTORY_RELATIVE\":\"objects/incoming-cNKHbg\"}"
},
{
"key": "key_id",
"value": "262"
}
],
"host": "unix",
"remote_ip": "127.0.0.1",
"ua": "gitaly/14.9.2",
"route": "/api/:version/internal/allowed",
"queue_duration_s": 0.009287,
"gitaly_calls": 1,
"gitaly_duration_s": 0.004171,
"redis_calls": 3,
"redis_duration_s": 0.000442,
"redis_read_bytes": 328,
"redis_write_bytes": 646,
"redis_cache_calls": 3,
"redis_cache_duration_s": 0.000442,
"redis_cache_read_bytes": 326,
"redis_cache_write_bytes": 229,
"redis_rate_limiting_read_bytes": 2,
"redis_rate_limiting_write_bytes": 417,
"db_count": 14,
"db_write_count": 0,
"db_cached_count": 0,
"db_replica_count": 0,
"db_primary_count": 14,
"db_main_count": 14,
"db_main_replica_count": 0,
"db_replica_cached_count": 0,
"db_primary_cached_count": 0,
"db_main_cached_count": 0,
"db_main_replica_cached_count": 0,
"db_replica_wal_count": 0,
"db_primary_wal_count": 0,
"db_main_wal_count": 0,
"db_main_replica_wal_count": 0,
"db_replica_wal_cached_count": 0,
"db_primary_wal_cached_count": 0,
"db_main_wal_cached_count": 0,
"db_main_replica_wal_cached_count": 0,
"db_replica_duration_s": 0,
"db_primary_duration_s": 0.006,
"db_main_duration_s": 0.006,
"db_main_replica_duration_s": 0,
"cpu_s": 0.040102,
"mem_objects": 18343,
"mem_bytes": 1621584,
"mem_mallocs": 4653,
"mem_total_bytes": 2355304,
"pid": 2293730,
"correlation_id": "01H5SV4Q9TTZX9HMMBS5JW7EHC",
"meta.user": "p.vasin",
"meta.project": "prj-quotes/prj-quotes-picker",
"meta.root_namespace": "prj-quotes",
"meta.client_id": "user/42",
"meta.caller_id": "POST /api/:version/internal/allowed",
"meta.remote_ip": "127.0.0.1",
"meta.feature_category": "source_code_management",
"content_length": "482",
"request_urgency": "default",
"target_duration_s": 1
}
Итоговые данные
{
"@timestamp": "2023-07-24T11:51:52.308Z",
"@metadata": {
"beat": "filebeat",
"type": "_doc",
"version": "8.8.2",
"log_source": "api_json-log"
},
"track": {
"ua": "gitaly/14.9.2",
"command": "/api/v4/internal/post_receive",
"username": "p.vasin",
"action_time": "2023-07-20T14:26:56.628Z",
"log_source": "api_json",
"params": {
"identifier": "key-262",
"push_options": null,
"changes": "fc192211792561b492261dfdbd82b44694b565ff 7b85fb31027e7531cf7e1c3ef48e8791a6a63025 refs/heads/feature/FT-1448\n",
"gl_repository": "project-465"
},
"remote_ip": "127.0.0.1",
"path": "/api/v4/internal/post_receive",
"project_path": "prj-quotes/prj-quotes-picker",
"repository": "",
"msg": ""
},
"content_length": "199",
"ecs": {
"version": "8.0.0"
},
"tags": [
"gitlab"
],
"host": {
"name": "gitlab"
},
"route": "/api/:version/internal/post_receive",
"agent": {
"type": "filebeat",
"version": "8.8.2",
"ephemeral_id": "9ab64ac9-61e8-45ba-887c-730a181d4134",
"id": "87064c45-64c3-448b-b4ea-4ddfb6cdb553",
"name": "gitlab"
},
"input": {
"type": "filestream"
},
"severity": "INFO"
}
gitaly
gitaly.yml
processors:
- decode_json_fields:
fields: ["message"]
- add_fields:
target: '@metadata'
fields:
log_source: "gitaly-log"
- drop_event:
when:
or:
- not.has_fields: ['remote_ip','username']
- equals:
remote_ip: ["192.168.11.14","192.168.11.16"]
- move_fields:
from: ""
fields: ["grpc.request.glProjectPath","remote_ip","username","grpc.code","grpc.request.glRepository","msg","peer.address","grpc.method","grpc.meta.client_name","grpc.service","time"]
to: "track."
ignore_missing: true
- rename:
fields:
- from: "track.grpc.request.glProjectPath"
to: "track.project_path"
- from: "track.grpc.code"
to: "track.status_code"
- from: "track.grpc.request.glRepository"
to: "track.repository"
- from: "track.peer.address"
to: "track.peer_address"
- from: "track.grpc.method"
to: "track.command"
- from: "track.grpc.meta.client_name"
to: "track.client_name"
- from: "track.grpc.service"
to: "track.service"
- from: "track.time"
to: "track.action_time"
ignore_missing: true
fail_on_error: false
- drop_fields:
fields: ['graphql','/^db_(.*)$/','/^redis_(.*)$/','/^mem_/','/^duration_/','/^cpu_/','log','agent','/.*\_duration\_.*/','pid','/^grpc\.(.*)$/','/^command\.(.*)$/','track.grpc',"track.peer","system","span.kind","level","correlation_id"]
- drop_event:
when:
equals:
"track.client_name": "gitlab-sidekiq"
- add_fields:
target: 'track'
fields:
log_source: "gitaly"
- add_tags:
tags: [gitlab]
Обработка коммита в gitaly
gitaly
{
"command.count": 1,
"command.cpu_time_ms": 116,
"command.inblock": 0,
"command.majflt": 0,
"command.maxrss": 3579076,
"command.minflt": 14888,
"command.oublock": 16,
"command.real_time_ms": 302,
"command.system_time_ms": 41,
"command.user_time_ms": 75,
"correlation_id": "01H641KX08X3TXBWP74H0VK91W",
"grpc.code": "OK",
"grpc.meta.client_name": "gitlab-shell-git-receive-pack",
"grpc.meta.deadline_type": "none",
"grpc.meta.method_type": "bidi_stream",
"grpc.method": "SSHReceivePack",
"grpc.request.fullMethod": "/gitaly.SSHService/SSHReceivePack",
"grpc.request.glProjectPath": "prj/mytc",
"grpc.request.glRepository": "project-2134",
"grpc.request.payload_bytes": 1752,
"grpc.request.repoPath": "@hashed/da/ab/daab3aa68185b677bd3c8d63f12e48eacb0851d98d635137e531fd579a452486.git",
"grpc.request.repoStorage": "default",
"grpc.response.payload_bytes": 51415,
"grpc.service": "gitaly.SSHService",
"grpc.start_time": "2023-07-24T16:32:29.626",
"grpc.time_ms": 303.933,
"level": "info",
"msg": "finished streaming call with code OK",
"peer.address": "@",
"pid": 1790121,
"remote_ip": "192.168.11.152",
"span.kind": "server",
"system": "grpc",
"time": "2023-07-24T13:32:29.930Z",
"user_id": "user-116",
"username": "i.pechkin"
}
{
"@timestamp": "2023-07-24T13:38:40.608Z",
"@metadata": {
"beat": "filebeat",
"type": "_doc",
"version": "8.8.2",
"log_source": "gitaly-log"
},
"agent": {
"version": "8.8.2",
"ephemeral_id": "3082d330-a8ae-425f-9705-425a2eb1b86d",
"id": "87064c45-64c3-448b-b4ea-4ddfb6cdb553",
"name": "spb-gitlab",
"type": "filebeat"
},
"track": {
"log_source": "gitaly",
"remote_ip": "192.168.11.152",
"action_time": "2023-07-24T13:32:29.930Z",
"project_path": "prj/mytc",
"repository": "project-2134",
"peer_address": "@",
"client_name": "gitlab-shell-git-receive-pack",
"service": "gitaly.SSHService",
"username": "i.pechkin",
"msg": "finished streaming call with code OK",
"status_code": "OK",
"command": "SSHReceivePack"
},
"ecs": {
"version": "8.0.0"
},
"tags": [
"gitlab"
],
"input": {
"type": "filestream"
},
"host": {
"name": "gitlab"
},
"user_id": "user-116"
}
gitlab-shell
gitlab-shell.yml
processors:
- decode_json_fields:
fields: ["message"]
- add_fields:
target: '@metadata'
fields:
log_source: "gitlab-shell-log"
- drop_event:
when:
and:
- not.equals:
command: "git-upload-pack"
- not.equals:
command: "git-receive-pack"
- move_fields:
from: ""
fields: ["gl_repository","gl_key_id","git_protocol","gl_project_path","gl_key_type","remote_ip","msg","username","command","user_id","time"]
to: "track."
ignore_missing: true
- rename:
fields:
- from: "track.gl_repository"
to: "track.repository"
- from: "track.gl_key_id"
to: "track.user_key_id"
- from: "track.gl_project_path"
to: "track.project_path"
- from: "track.gl_key_type"
to: "track.user_key_type"
- from: "track.time"
to: "track.action_time"
ignore_missing: true
fail_on_error: false
- drop_fields:
fields: ["correlation_id","level"]
- add_fields:
target: 'track'
fields:
log_source: "gitlab-shell"
- add_tags:
tags: [gitlab]
Обработка коммита в gitlab-shell
gitlab-shell
{
"command": "git-receive-pack",
"correlation_id": "01H642GEXJDBS352NH9MD8FJ2G",
"git_protocol": "",
"gl_key_id": 129,
"gl_key_type": "key",
"gl_project_path": "my-prj/prj-sql",
"gl_repository": "project-164",
"level": "info",
"msg": "executing git command",
"remote_ip": "192.168.11.170",
"time": "2023-07-24T13:48:05Z",
"user_id": "user-47",
"username": "k.matroskin"
}
{
"@timestamp": "2023-07-24T13:48:58.917Z",
"@metadata": {
"beat": "filebeat",
"type": "_doc",
"version": "8.8.2",
"log_source": "gitlab-shell-log"
},
"agent": {
"name": "spb-gitlab",
"type": "filebeat",
"version": "8.8.2",
"ephemeral_id": "d9e46a60-8531-4907-9976-061a359eac36",
"id": "87064c45-64c3-448b-b4ea-4ddfb6cdb553"
},
"log": {
"offset": 5123721,
"file": {
"path": "/var/log/gitlab/gitlab-shell/gitlab-shell.log"
}
},
"input": {
"type": "filestream"
},
"track": {
"action_time": "2023-07-24T13:48:05Z",
"project_path": "my-prj/prj-sql",
"user_key_type": "key",
"remote_ip": "192.168.11.170",
"command": "git-receive-pack",
"repository": "project-164",
"user_id": "user-47",
"user_key_id": 129,
"log_source": "gitlab-shell",
"git_protocol": "",
"msg": "executing git command",
"username": "k.matroskin"
},
"ecs": {
"version": "8.0.0"
},
"host": {
"name": "gitlab"
},
"tags": [
"gitlab"
]
}
production_json
production_json.yml
processors:
- decode_json_fields:
fields: ["message"]
- drop_event:
when:
or:
- not.has_fields: ['remote_ip','username']
- equals:
remote_ip: ["192.168.11.14","192.168.11.16"]
- equals:
"meta.remote_ip": ["192.168.11.14","192.168.11.16"]
- and:
- not.contains:
controller: "Projects::MergeRequestsController"
action: "merge"
- not.contains:
controller: "Repositories::GitHttpController"
action: "git_receive_pack"
- not.contains:
controller: "Repositories::GitHttpController"
action: "info_refs"
- not.contains:
controller: "Projects::MergeRequests::CreationsController"
action: "create"
- not.equals:
"meta.caller_id": "POST /api/:version/internal/allowed"
"ua": "GitLab-Shell"
- contains:
"ua": "gitlab-runner"
- equals:
status: 401
- add_fields:
target: '@metadata'
fields:
log_source: "production_json-log"
- add_fields:
target: 'track'
fields:
log_source: "production_json"
repository: ""
msg: ""
- script:
lang: javascript
#file: ./remap.js
source: >
function process(event) {
var data = event.Get('params');
event.Rename('params','old_params')
for (var field in data) {
event.Put("params."+data[field].key, data[field].value)
}
event.Delete('old_params')
}
- move_fields:
from: ""
fields: ["meta.project","remote_ip","username","action","time","params","user_id","ua","controller","path"]
to: "track."
ignore_missing: true
- rename:
fields:
- from: "track.meta.project"
to: "track.project_path"
- from: "track.action"
to: "track.command"
- from: "track.time"
to: "track.action_time"
- drop_fields:
fields: ['graphql','/^db_(.*)$/','/^redis_(.*)$/','/^mem_/','/^duration_/','/^cpu_/','log','agent','/.*\_duration\_.*/',
'pid','method','status','correlation_id',"meta.root_namespace","meta.client_id","request_urgency","format",
"meta.feature_category","meta.user","meta.caller_id","meta.remote_ip","track.meta"]
ignore_missing: true
- add_tags:
tags: [gitlab]
Обработка коммита в production_json
production_json
{
"method": "POST",
"path": "/web/rest-service.git/git-receive-pack",
"format": null,
"controller": "Repositories::GitHttpController",
"action": "git_receive_pack",
"status": 200,
"time": "2023-07-24T11:17:39.851Z",
"params": [
{
"key": "repository_path",
"value": "web/rest-service.git"
}
],
"correlation_id": "01H63SX0RNCS2WMRJDSY9XP0N0",
"meta.user": "d.fedor",
"meta.project": "web/rest-service",
"meta.root_namespace": "web",
"meta.client_id": "user/79",
"meta.caller_id": "Repositories::GitHttpController#git_receive_pack",
"meta.remote_ip": "192.168.11.191",
"meta.feature_category": "source_code_management",
"remote_ip": "192.168.11.191",
"user_id": 79,
"username": "d.fedor",
"ua": "git/2.41.0.windows.1",
"request_urgency": "default",
"target_duration_s": 1,
"redis_calls": 1,
"redis_duration_s": 0.000217,
"redis_read_bytes": 109,
"redis_write_bytes": 67,
"redis_cache_calls": 1,
"redis_cache_duration_s": 0.000217,
"redis_cache_read_bytes": 109,
"redis_cache_write_bytes": 67,
"db_count": 19,
"db_write_count": 0,
"db_cached_count": 1,
"db_replica_count": 0,
"db_primary_count": 19,
"db_main_count": 19,
"db_main_replica_count": 0,
"db_replica_cached_count": 0,
"db_primary_cached_count": 1,
"db_main_cached_count": 1,
"db_main_replica_cached_count": 0,
"db_replica_wal_count": 0,
"db_primary_wal_count": 0,
"db_main_wal_count": 0,
"db_main_replica_wal_count": 0,
"db_replica_wal_cached_count": 0,
"db_primary_wal_cached_count": 0,
"db_main_wal_cached_count": 0,
"db_main_replica_wal_cached_count": 0,
"db_replica_duration_s": 0,
"db_primary_duration_s": 0.007,
"db_main_duration_s": 0.007,
"db_main_replica_duration_s": 0,
"cpu_s": 0.106401,
"mem_objects": 24147,
"mem_bytes": 1820184,
"mem_mallocs": 5998,
"mem_total_bytes": 2786064,
"pid": 3074267,
"db_duration_s": 0.00622,
"view_duration_s": 0.00026,
"duration_s": 0.1056
}
{
"@timestamp": "2023-07-24T14:06:26.674Z",
"@metadata": {
"beat": "filebeat",
"type": "_doc",
"version": "8.8.2",
"log_source": "production_json-log"
},
"host": {
"name": "gitlab"
},
"input": {
"type": "filestream"
},
"tags": [
"gitlab"
],
"agent": {
"id": "87064c45-64c3-448b-b4ea-4ddfb6cdb553",
"name": "spb-gitlab",
"type": "filebeat",
"version": "8.8.2",
"ephemeral_id": "31f53680-3bc3-4323-9e41-3ecedd578ece"
},
"track": {
"msg": "",
"action_time": "2023-07-24T11:17:39.851Z",
"user_id": 79,
"ua": "git/2.41.0.windows.1",
"path": "/web/rest-service.git/git-receive-pack",
"log_source": "production_json",
"remote_ip": "192.168.11.191",
"username": "d.fedor",
"repository": "",
"params": {
"repository_path": "web/rest-service.git"
},
"controller": "Repositories::GitHttpController",
"project_path": "web/rest-service",
"command": "git_receive_pack"
},
"ecs": {
"version": "8.0.0"
}
}
В конечном итоге всё это превращается в следующую картинку
Причём тут ГОСТ о безопасной разработке ?
На эти вопросы отвечает раздел 5.3.3.1 https://allgosts.ru/35/020/gost_r_56939-2016.pdf
5.3.3.1 Разработчик ПО должен идентифицировать каждое инструментальное средство, используемое при разработке ПО, и определить его настройки(опции). применяемые при создании программы.
При разработке ПО должны применять только идентифицированные инструментальные средства.
Разработчику ПО следует использовать последние доступные версии инструментальных средств и их возможности по проверке создаваемой программы на наличие проблем, имеющих отношение к разработке безопасного ПО.
Для организации работ, выполняемых в процессах жизненного цикла ПО. и подтверждения соответствия требованиям настоящего стандарта документация разработчика ПО для каждого идентифицированного инструментального средства должна содержать:
— наименование и идентификационные признаки инструментального средства;
— наименование разработчика инструментального средства;
— ссылку на эксплуатационные документы инструментального средства;
— значения применяемых при создании программы опций(настроек) инструментального средства.Примечание — К инструментальным средствам относятся, например, трансляторы, компиляторы, прикладные программы, используемые для проектирования и документирования, редакторы исходного кода программ, отладчики, интегрированные среды разработки.
В рамках исполнения указанных требований, разработчик ПО должен иметь срез версий инструментальных средств разработки на момент изменения программного кода(коммита), который предоставляется аудиторам. Поэтому без наличия IP адреса и данных о пользователе, врядли получится идентифицировать машину и софт на ней установленный. Как и чем собирать информацию о софте на машине разработчика каждый решает сам, благо вариантов много:
KSC
AIDA64
Everest и прочие
Поставить системный хук на PUSH/MR, который получит первичные данные о коммите, запросит лог из Gitlab и сходит в inventory больших проблем я думаю не составит.
Кстати о системных и локальных хуках. К сожалению Gitlab при обработке события не передаёт наружу IP адрес пользователя сделавшего изменения, поэтому хуки можно использовать только как триггер по инициации процесса.
Да, описываемое здесь решение не позволяет решить все проблемы связанные с идентификацией сотрудника и софта в различные моменты времени, т.к. всегда найдётся множество причин способных помешать процессу. Но описываемое решение помогает систематизировать данные для поиска и очень сильно снизить нагрузку на ручной поиск источников возможных проблем + автоматизировать часть механизмов по формированию материалов необходимых для аудиторов.
https://github.com/aborche/gitlab-repo-activity-audit
Всем безопасной разработки! :)
PS: обложка поста от Kandinsky 2.2