ClickHouse+Python+Nginx: Tutorial rápido como lidar com seus logs

Motivação

Não há nada mais importante do que ter um bom nível de observabilidade do serviço e isso não é possível sem um armazenamento confiável e rápido dos logs da aplicação. Uma das soluções mais populares hoje em dia é o ELK ( E lasticSearch- Logstash- K ibana), mas não é tão universal quanto pode parecer.

Declaração do problema

ELK é uma solução flexível, conveniente e complexa para coletar e analisar logs. É uma filtragem de consulta escalonável, robusta, flexível e universal. No entanto, existem desvantagens em usar ELK:

• alto consumo de memória e recursos de CPU
• Degradação da velocidade de índice e pesquisa junto com o aumento do número de registros
• sobrecarga do índice de pesquisa de texto completo
• QueryDSL complicado

Tudo isso me faz pensar: existe uma alternativa ao ELK quando falamos em toras?

Aqui está minha lista de requisitos para a solução de manipulação de logs:

• agregação rápida e flexível
• inserção rápida, seleção rápida
• fácil de configurar e com recursos mínimos
• solução compatível com grafana

No entanto, é bom ter uma ferramenta flexível e rápida para fazer análises regulares e ad hoc. Vamos ser mais específicos sobre o sistema que vou implementar:

• Processe mais de 20 milhões de linhas de log que são log de acesso Nginx
• Obtenha o número de respostas HTTP incorretas (4xx, 5xx)
• Obtenha contadores de bot e rastreadores e o URL que eles visitam
• Obtenha os 5 principais endereços IP que são bots suspeitos

O que é ClickHouse e por que decidi usá-lo

ClickHouse é um sistema de gerenciamento de banco de dados SQL orientado a colunas de alto desempenho para processamento analítico online conforme declarado.

Os recursos mais importantes para mim foram:

• O armazenamento orientado a colunas significa que o ClickHouse lerá o disco somente se necessário.
• ClickHouse pode aproveitar todos os recursos disponíveis (núcleos de CPU e discos) para executar até mesmo uma única consulta.
• Compressão de dados
• Suporte SQL, por último, mas não menos importante

Solução técnica

Tutorial de repositório do Github

Você pode encontrar o tutorial junto com um gerador de log no GitHub .

Configure o ClickHouse e conecte-se

Primeiro de tudo, vamos criar docker-compose.yml para definir ambos os serviços. ( https://github.com/bp72/nginxlogprocessor/blob/init-commit/docker-compose.yml )

 version: '3.6' services: ch: image: clickhouse/clickhouse-server container_name: clickhouse restart: always volumes: - clickhousedata:/var/lib/clickhouse/ ports: - '8123:8123' - '9000:9000' ulimits: memlock: soft: -1 hard: -1 nofile: soft: 262144 hard: 262144 # This capabilities prevents Docker from complaining about lack of those cap_add: - SYS_NICE - NET_ADMIN - IPC_LOCK volumes: clickhousedata:

Vamos executá-lo e verificar se tudo está funcionando: conecte-se à instância ClickHouse usando o cliente ClickHouse do contêiner docker e verifique se está disponível via localhost e porta

 > docker-compose up -d [+] Running 3/3 ⠿ Network nginxlogprocessor_default Created 0.1s ⠿ Container clickhouse Started 0.6s

Para conectar à instância prefiro o cliente ClickHouse

 docker-compose exec ch clickhouse-client ClickHouse client version 23.9.1.1854 (official build). Connecting to localhost:9000 as user default. Connected to ClickHouse server version 23.9.1 revision 54466. a8c8da069d94 :)

Crie bancos de dados e tabelas

Agora, quando tudo estiver configurado, vamos criar bancos de dados e tabelas: banco de dados para rastrear logs processados e banco de dados para serviços específicos, por exemplo, nginx , e a primeira tabela nginx.access .

Uma das vantagens significativas do ClickHouse é a sintaxe SQL para definições e consultas. Não é estritamente padrão SQL, mas muito próximo disso.

 CREATE DATABASE IF NOT EXISTS nginx CREATE DATABASE IF NOT EXISTS logs CREATE TABLE IF NOT EXISTS nginx.access ( reqid String, ts DateTime64(3), level Enum(''=0, 'debug'=1, 'info'=2, 'warn'=3 ,'error'=4), domain String, uri String, ua String, ref String, is_bot Boolean, is_mobile Boolean, is_tablet Boolean, is_pc Boolean, client String, duration Float32, response_code UInt16, addrIPv4 Nullable(IPv4), addrIPv6 Nullable(IPv6), upstream_connect_time Float32, upstream_header_time Float32, upstream_response_time Float32 ) ENGINE MergeTree PRIMARY KEY reqid ORDER BY reqid CREATE TABLE IF NOT EXISTS logs.logfiles ( filename String ) ENGINE MergeTree PRIMARY KEY filename ORDER BY filename

Olhando mais de perto a instrução CREATE TABLE , você pode ver tipos ligeiramente diferentes e tipos completamente novos, como Enum e IPv4. ClickHouse tenta reduzir o uso de recursos e para isso o otimiza com recursos interessantes como Enum. É basicamente um mapeamento de valor-chave de uma string para um int de 8 bits ou 16 bits, que converte automaticamente na inserção, converte o valor da string em int e na seleção converte o caminho oposto ( link ).

IPv4, IPv6 são os tipos especiais para armazenar endereços da maneira mais ideal (como unsigned int) e representá-los de uma forma legível por humanos, então basicamente no momento da inserção você fornece uma representação de string do endereço IP e o ClickHouse faz tudo para você: armazena-o como int e o servidor é descompactado na seleção.

Inserção de registro

A ideologia da ClickHouse é inserir rápido. Para fazer isso, ClickHouse lida melhor com inserções em lote do que uma por uma.

Portanto o script de inserção não é muito complicado. A função readFile produz blocos de dados de 50 mil registros no máximo para o cliente ClickHouse inserir. Cada item de bloco representa a lista de valores relativos aos nomes das colunas na lista de colunas

 # it's not an actual code. # the working implementation you can find at https://github.com/bp72/nginxlogprocessor import clickhouse_connect from config import CLICKHOUSE_HOST, CLICKHOUSE_PORT from log import log client = clickhouse_connect.get_client(host=CLICKHOUSE_HOST, port=CLICKHOUSE_PORT) def loadToClickHouse(client, chunk): cols = [ 'reqid', 'ts', 'level', 'domain', 'uri', 'ua', 'ref', 'is_bot', 'is_mobile', 'is_tablet', 'is_pc', 'client', 'duration', 'response_code', 'addrIPv4', 'addrIPv6', 'upstream_connect_time', 'upstream_header_time', 'upstream_response_time', ] client.insert('nginx.access', chunk, column_names=cols) def processFeed(feed, client, chunk_size=10_000): total = 0 for chunk in readFile(feed, chunk_size=chunk_size): total += len(chunk) loadToClickHouse(client, chunk=chunk) log.info(f'process {feed=} inserted={len(chunk)} {total=}')

A execução e o tempo reais que tenho no meu PC, você pode ver que a análise e a inserção do arquivo de registros de 800k levaram 21s do tempo de execução do Python. Nada mal!

 > .venv/bin/python ./main.py I:2023-10-15 12:44:02 [18764] f=transport.py:1893 Connected (version 2.0, client OpenSSH_8.9p1) I:2023-10-15 12:44:02 [18764] f=transport.py:1893 Authentication (publickey) successful! I:2023-10-15 12:44:02 [18764] f=fetcher.py:14 connect host='*.*.*.*' port=22 user='root' password=None I:2023-10-15 12:44:02 [18764] f=fetcher.py:18 run cmd='ls /var/log/nginx/*access*.log-*' I:2023-10-15 12:44:02 [18764] f=fetcher.py:34 download src=/var/log/nginx/access.log-2023100812.gz dst=/tmp/access.log-2023100812.gz I:2023-10-15 12:44:07 [18764] f=main.py:20 process feed='/tmp/access.log-2023100812.gz' inserted=50000 total=50000 I:2023-10-15 12:44:08 [18764] f=main.py:20 process feed='/tmp/access.log-2023100812.gz' inserted=50000 total=100000 I:2023-10-15 12:44:10 [18764] f=main.py:20 process feed='/tmp/access.log-2023100812.gz' inserted=50000 total=150000 I:2023-10-15 12:44:11 [18764] f=main.py:20 process feed='/tmp/access.log-2023100812.gz' inserted=50000 total=200000 I:2023-10-15 12:44:13 [18764] f=main.py:20 process feed='/tmp/access.log-2023100812.gz' inserted=50000 total=250000 I:2023-10-15 12:44:14 [18764] f=main.py:20 process feed='/tmp/access.log-2023100812.gz' inserted=50000 total=300000 I:2023-10-15 12:44:15 [18764] f=main.py:20 process feed='/tmp/access.log-2023100812.gz' inserted=50000 total=350000 I:2023-10-15 12:44:17 [18764] f=main.py:20 process feed='/tmp/access.log-2023100812.gz' inserted=50000 total=400000 I:2023-10-15 12:44:18 [18764] f=main.py:20 process feed='/tmp/access.log-2023100812.gz' inserted=50000 total=450000 I:2023-10-15 12:44:20 [18764] f=main.py:20 process feed='/tmp/access.log-2023100812.gz' inserted=50000 total=500000 I:2023-10-15 12:44:21 [18764] f=main.py:20 process feed='/tmp/access.log-2023100812.gz' inserted=50000 total=550000 I:2023-10-15 12:44:23 [18764] f=main.py:20 process feed='/tmp/access.log-2023100812.gz' inserted=50000 total=600000 I:2023-10-15 12:44:24 [18764] f=main.py:20 process feed='/tmp/access.log-2023100812.gz' inserted=50000 total=650000 I:2023-10-15 12:44:25 [18764] f=main.py:20 process feed='/tmp/access.log-2023100812.gz' inserted=50000 total=700000 I:2023-10-15 12:44:27 [18764] f=main.py:20 process feed='/tmp/access.log-2023100812.gz' inserted=50000 total=750000 I:2023-10-15 12:44:28 [18764] f=main.py:20 process feed='/tmp/access.log-2023100812.gz' inserted=50000 total=800000 I:2023-10-15 12:44:28 [18764] f=main.py:20 process feed='/tmp/access.log-2023100812.gz' inserted=2190 total=802190 I:2023-10-15 12:44:28 [18764] f=fetcher.py:34 download src=/var/log/nginx/access.log-2023100814.gz dst=/tmp/access.log-2023100814.gz I:2023-10-15 12:44:31 [18764] f=main.py:20 process feed='/tmp/access.log-2023100814.gz' inserted=50000 total=50000 I:2023-10-15 12:44:32 [18764] f=main.py:20 process feed='/tmp/access.log-2023100814.gz' inserted=50000 total=100000 I:2023-10-15 12:44:33 [18764] f=main.py:20 process feed='/tmp/access.log-2023100814.gz' inserted=30067 total=130067

Análise de log e detecção de problemas

ClickHouse usa SQL para consultar o banco de dados, o que é muito confortável para a maioria dos engenheiros de software e intuitivamente simples.

Vamos começar verificando o número de registros que temos, são 22 milhões.

 a8c8da069d94 :) select count(1) from nginx.access; SELECT count(1) FROM nginx.access Query id: f94881f3-2a7d-4039-9646-a6f614adb46c ┌──count()─┐ │ 22863822 │ └──────────┘

É fácil ter consultas com diferentes detalhamentos, o que pode ser útil para detecção e solução de problemas, por exemplo, gostaria de saber de qual endereço IP o host está sendo verificado em busca de vulnerabilidade.

Esta consulta demonstra como as consultas de dados flexíveis podem ser comparadas ao ELK. A instrução WITH .. AS e IN / NOT IN, subconsulta, agregação e filtragem tornam o ClickHouse muito conveniente.

 a8c8da069d94 :) with baduri as (select uri, count(1) from nginx.access where response_code = 404 and uri not in ('/about/', '/favicon.ico') group by 1 having count(1) > 3 order by 2 desc limit 10) select IPv4NumToStringClassC(addrIPv4), count(1) from nginx.access where uri in (select uri from baduri) and addrIPv4 is not null group by 1 order by 2 desc limit 5 WITH baduri AS ( SELECT uri, count(1) FROM nginx.access WHERE (response_code = 404) AND (uri NOT IN ('/about/', '/favicon.ico')) GROUP BY 1 HAVING count(1) > 3 ORDER BY 2 DESC LIMIT 10 ) SELECT IPv4NumToStringClassC(addrIPv4), count(1) FROM nginx.access WHERE (uri IN ( SELECT uri FROM baduri )) AND (addrIPv4 IS NOT NULL) GROUP BY 1 ORDER BY 2 DESC LIMIT 5 Query id: cf9bea33-212b-4c58-b6af-8e0aaae50b83 ┌─IPv4NumToStringClassC(addrIPv4)─┬─count()─┐ │ 8.219.64.xxx │ 961 │ │ 178.128.220.xxx │ 378 │ │ 103.231.78.xxx │ 338 │ │ 157.245.200.xxx │ 324 │ │ 116.203.28.xxx │ 260 │ └─────────────────────────────────┴─────────┘ 5 rows in set. Elapsed: 0.150 sec. Processed 45.73 million rows, 1.81 GB (303.88 million rows/s., 12.01 GB/s.) Peak memory usage: 307.49 MiB.

Vamos obter os 5 uri mais populares por domínio. Esta consulta usa a útil função LIMIT x BY <field>.

 a8c8da069d94 :) select domain, uri, count(1) from nginx.access where domain in ('example.com', 'nestfromthebest.com', 'az.org') group by 1, 2 order by 1, 3 desc limit 5 by domain SELECT domain, uri, count(1) FROM nginx.access WHERE domain IN ('example.com', 'nestfromthebest.com', 'az.org') GROUP BY 1, 2 ORDER BY 1 ASC, 3 DESC LIMIT 5 BY domain Query id: 2acd328c-ed82-4d36-916b-8f2ecf764a9d ┌─domain──────┬─uri────────────┬─count()─┐ │ az.org │ /about/ │ 382543 │ │ az.org │ /contacts/ │ 42066 │ │ az.org │ /category/id7 │ 2722 │ │ az.org │ /category/id14 │ 2704 │ │ az.org │ /category/id2 │ 2699 │ │ example.com │ /about/ │ 381653 │ │ example.com │ /contacts/ │ 42023 │ │ example.com │ /category/id2 │ 2694 │ │ example.com │ /category/id8 │ 2688 │ │ example.com │ /category/id13 │ 2670 │ └─────────────┴────────────────┴─────────┘ ┌─domain──────────────┬─uri────────────┬─count()─┐ │ nestfromthebest.com │ /about/ │ 383377 │ │ nestfromthebest.com │ /contacts/ │ 42100 │ │ nestfromthebest.com │ /category/id8 │ 2726 │ │ nestfromthebest.com │ /category/id14 │ 2700 │ │ nestfromthebest.com │ /category/id4 │ 2696 │ └─────────────────────┴────────────────┴─────────┘ 15 rows in set. Elapsed: 0.062 sec. Processed 23.97 million rows, 918.43 MB (388.35 million rows/s., 14.88 GB/s.) Peak memory usage: 98.67 MiB.

Conclusão

ClickHouse é uma ótima ferramenta para armazenar e manipular dados específicos, como logs, em grande escala. Definitivamente, vale a pena aprender mais e compreender, por exemplo, estrutura de dados aninhada, ferramentas de amostragem, funções de janela e outros

Espero que tenha gostado deste pequeno artigo e que tenha sido útil para você!