O Log não está quebrado... você quem não sabe ler o código!

[ludarkstar99]

Olá, pessoal!

Espero que estejam todos bem. Hoje vou falar sobre algo que sempre me deixa intrigado: Logs. Mais especificamente, pesquisa em logs. 
Se você já precisou verificar as datas de autenticações de um usuário no log da VPN ou rastrear uma sessão "presa" na tela de states/sessions, deve ter se perguntado qual seria a melhor maneira de preencher a caixa de pesquisa para filtrar e encontrar rapidamente o que procura. 

Pois bem, como diria um famoso youtuber: "Vem comigo!"

COMEÇANDO PELO COMEÇO

A ideia é mostrar como funciona a pesquisa no OPNsense, para que isso possa servir de referência em futuras investigações. Precisei desse conhecimento e quase ninguém explicou como fazer. Então, deixo aqui o rastro para você não dizer que ninguém te ajudou.

Primeiro, vamos conferir como era a pesquisa em um firewall com a versão "OPNsense 24.1". É importante entender o passado para encarar o futuro. 

• Acesse VPN > OpenVPN > Log File.
• Na tela, você verá os logs mais recentes do OpenVPN em formato paginado.
• No canto superior direito, há uma barra de pesquisa para filtrar informações específicas.

Faça um teste: conecte-se à VPN, retorne a essa tela, pesquise pelo seu login e marque o nível de severidade como DEBUG para ver todas as mensagens. Você deve encontrar entradas de log relacionadas ao seu usuário, o que é bem útil.

Code Select Expand

Date                Severity    Process         Line
2025-02-19T20:41:27-03:00 Notice openvpn_server4 ludarkstar99/177.177.177.177:51645 SIGUSR1[soft,ping-restart] received, client-instance restarting
2025-02-19T20:41:27-03:00 Notice openvpn_server4 ludarkstar99/177.177.177.177:51645 [ludarkstar99] Inactivity timeout (--ping-restart), restarting
2025-02-19T08:16:14-03:00 Notice openvpn_server4 ludarkstar99/177.177.177.177:51645 Protocol options: protocol-flags cc-exit tls-ekm dyn-tls-crypt

Agora, imagine que você quer apenas as linhas de autenticação bem-sucedida do usuário ludarkstar99. Filtrar apenas pelo login traz várias outras mensagens (inatividade, criptografia, certificado etc.). Se quiser apenas a linha que indica conexão bem-sucedida — algo como:

Code Select Expand

177.177.177.177:51645 [ludarkstar99] Peer Connection Initiated with [AF_INET6]::ffff:177.177.239.204:51645 (via 177.39.39.39%vmx0_vlan301)

Talvez você tente "[ludarkstar99] Peer Connection Initiated with" na caixa de pesquisa... e não encontre nada! Isso acontece porque o OPNsense remove caracteres especiais como `[]`, `+`, `&`, `$` etc.  e isso quebra a correspondência exata dos termos em sequência, pois falta os caracteres "[" e "]".

Então, como pesquisar tanto pelo nome do usuário quanto pelo texto que indica autenticação bem-sucedida? Em geral, sistemas de log permitem expressões regulares ou curingas. De fato, o OPNsense suporta algo do tipo, mas com ressalvas.

OS PRUDENTES VEEM O PERIGO E SE ABRIGAM

Sempre que surge um problema, gosto de pensar que esses desafios nos fazem crescer. Se eu simplesmente entregasse a solução de bandeja, você talvez não entendesse todo o processo. Então, vamos explorar como o OPNsense faz essa busca nos logs.

• Abra as Ferramentas de Desenvolvedor do navegador (Ctrl+F12 ou Ctrl+Shift+I). 
  
• No campo de pesquisa, digite, por exemplo: [ludarkstar99] Peer Connection Initiated. 
  
• Observe a requisição na aba Rede: ela chama "/api/diagnostics/log/core/openvpn" com parâmetros searchPhrase e severity. 
  

A requisição chega ao servidor, que remove caracteres especiais e, em seguida, aciona o configd para executar a ação "system diag log", passando parâmetros como módulo (core), arquivo (openvpn) e severidades. Por fim, o configd chama o script /usr/local/opnsense/scripts/syslog/queryLog.py, que realiza a busca no arquivo de log. 

O ponto crucial é: esse script substitui o caractere "*" por ".*" (expressão regular) e, caso você não use "*", o script adiciona ".*" antes e depois do termo pesquisado. Isso significa que, na versão 24.1, se você quiser filtrar "ludarkstar99" + "Peer Connection Initiated" numa mesma linha, precisa usar o curinga "*". Por exemplo:

Code Select Expand

*ludarkstar99*Peer Connection Initiated

Dessa forma, o script consegue montar a expressão regular que "casa" com a linha completa, incluindo eventuais caracteres entre o usuário e o texto desejado.
Obs.: Repare que é é necessário antes do nome do usuário o caractere curinga (*) pois a linha de log não começa com o nome do usuário...

AS COISAS VELHAS JÁ PASSARAM, EIS QUE TUDO SE FEZ NOVO

Até aqui tudo bem para a versão 24.1. Mas e se você estiver na versão 24.7.3 em diante e nada funcionar? Pois é, houve mudanças!

Nessa versão, o script /usr/local/opnsense/scripts/syslog/queryLog.py foi alterado. Em vez de usar expressões regulares, a busca passou a ser literal, fazendo apenas "line.find(clause)". Ou seja, o conceito de "*" como coringa deixa de existir. Se você incluir vários termos, o sistema vai buscar todos eles na linha, mas não com curinga. 

Portanto, se quiser achar "ludarkstar99" e "Peer Connection Initiated" na mesma linha, basta digitar:

Code Select Expand

ludarkstar99 Peer Connection Initiated

Agora, o OPNsense procura cada palavra na linha. Se todas aparecerem, a linha é exibida. Se não, não aparece nada.


Conclusão: 

• Na versão 24.7.2 (ou anteriores), use "*" como coringa para junções. 
  
• Na versão 24.7.3 em diante, a busca se tornou literal e o "*" não tem mais efeito. Basta digitar todas as palavras que deseja encontrar na mesma linha. 
  

That's all folks.


Obs.: Esta mensagem foi melhorada com ajuda de I.A para trazer clareza e diminuir a densidade textual. o texto original possuía mais de 300 linhas, além de sarcasmo excessivo, piadas de mau gosto, e explicações profundamente duvidosas.
"O simples convence."

[ludarkstar99]

DIRECTOR CUT
TL;DR;

Resumindo, a partir da versão 24.7.3, para pesquisar múltiplos termos na caixa de pesquisa, como no exemplo de usuário autenticado na vpn, ficariam assim:
filtro: "ludarkstar99 Peer Connection Initiated".

*sem as aspas é claro.
Lembrando que Só haverá resultado se todas as palavras forem encontradas dentro da linha do log.


Olá,
espero que estejam todos bem.

Hoje pretendo falar sobre algo que me revira a cabeça, a lá Roberta Miranda. e é sobre LOGS.
Mais especificamente sobre pesquisa em LOGS.
Você já tentou pesquisar algo nos logs da VPN, como achar as datas de autenticações de um determinado usuário, ou mesmo procurar uma conexão presa através da tela de states (ou sessions)? Então você já deve ter se perguntado, como preencher a abençoada caixinha de pesquisa para filtrar "da melhor maneira" e trazer os dados na tela com um filtro apurado para encontrar rapidamente o que procura.
Pois bem, como diria um famoso youtuber (de mala e cuia): "Vem comigo!"

PARA COMEÇAR TEM QUE COMEÇAR DO COMEÇO
Eu pretendo lhe mostrar como funciona a pesquisa, e que lhe sirva de futuras referências quando precisar investigar esse tipo de problema. Eu precisei e ninguém me explicou como fazer, então estou deixando o rastro pra você não falar que ninguém te ajudou. A faca tá aí, corta o queijo quem quer!
Primeiro vamos ver como era a pesquisa em um firewall rodando a versão "OPNsense 24.1", sim, tem que ver o passado pra encarar o futuro. Larga de ser preguicinha e vai estudar rapaz...
Acessando o menu "VPN > OpenVPN > Log File" você é apresentado a tela de consulta aos logs mais recentes do openvpn. Esta tela apresenta uma listagem paginada dos logs, e se olhar no canto superior direito, vai ver que tem uma barrinha de pesquisa para procurar informações em específico. Tente conectar na VPN e voltar nesta tela e pesquisar pelo seu login de conexão openvpn. Não esqueça de marcar o nível de severidade como DEBUG para vermos todas as mensagens. Você verá que irá listar as entradas de log que contém o teu login. Até aí perfeito.

Date   Severity   Process   Line
2025-02-19T20:41:27-03:00   Notice   openvpn_server4   ludarkstar99/177.177.177.177:51645 SIGUSR1[soft,ping-restart] received, client-instance restarting
2025-02-19T20:41:27-03:00   Notice   openvpn_server4   ludarkstar99/177.177.177.177:51645 [ludarkstar99] Inactivity timeout (--ping-restart), restarting
2025-02-19T08:16:14-03:00   Notice   openvpn_server4   ludarkstar99/177.177.177.177:51645 Protocol options: protocol-flags cc-exit tls-ekm dyn-tls-crypt

Agora, vamos supor que você está buscando fazer uma auditoria nos acessos do ludarkstar99. Apenas filtrar pelo login do usuário vai trazer diversas mensagens (assumindo que está usando nível de log 3/4 no openvpn) e que não são exatamente do login. Algumas sobre inatividade, outras sobre criptografia ou mesmo certificado. E se você quiser trazer apenas as linhas de log de autenticação?
Bom então vamos atrás do filtro. Primeiro você precisa encontrar uma linha modelo. Desconecte e conecte na vpn novamente, atualize a tela rapidamente e irá conseguir localizar uma linha com o texto abaixo, indicando uma autenticação bem sucedida:
177.177.177.177:51645 [ludarkstar99] Peer Connection Initiated with [AF_INET6]::ffff:177.177.239.204:51645 (via 177.39.39.39%vmx0_vlan301)

Vamos dizer que você queira pesquisar os logins bem sucedidos. Então joga na caixa de pesquisa o termo "Peer Connection Initiated with". Logo virá o login de todos os usuários na VPN e não somente o usuário que você está buscando. Você deve estar pensando - é fácil, é só colocar o nome do usuário entre colchetes seguido da frase de conexão bem sucedida como em "[ludarkstar99] Peer Connection Initiated with". Tente aí então espertão, e verá que não trará resultado nenhum! Isso basicamente ocorre porque o opnsense substitui caracteres especiais como "+&$()[]" dentre vários outros. Então... como filtrar tanto pelo nome do usuário junto da frase ou termo que indica um login bem sucedido?
Santa Barbatana Batman! Como não pensei nisso antes. Se é pesquisa de logs, deve haver algum tipo de expressão regular, ou caracteres curingas, geralmente sempre tem! Pois bem. e realmente tem, mas não é tão simples assim.


OS PRUDENTES VEEM O PERIGO E SE ABRIGAM, MAS OS SIMPLES SEGUEM ADIANTE E PAGAM O PREÇO.
Sempre que algo ocorre, seja no trabalho ou durante as aulas que ministro, sempre paro, respiro fundo e digo a mim mesmo: Eu amo problemas! Problemas me fazem crescer! Quer uma frase mais inspiradora que essa? "Problema bom é problema resolvido".
Se eu simplesmente te entregasse o ouro, como um belo índio de cabelos negros e lisos, você faria como os portugueses, iria embora sem nem me dar um espelho.
Ao invés disso vamos malhar o cérebro um pouco.
Quero que você entenda como ocorre esse filtro dos logs e para isso precisaremos inspecionar desde a requisição do navegador com o filtro, até o momento que o opnsense consulta as linhas do log e verifica se há uma correspondência do filtro ou não.
Abra as ferramentas de desenvolvedor do navegador (control+F12 ou control+shift+i) e clique na guia Rede.
Agora volte no campo de pesquisa e digite o nome do usuário da vpn + o termo de login bem sucedido: exemplo: [ludarkstar99] Peer Connection Initiated.
Você verá na guia de captura de requisições de rede, que houve uma requisição para a URL "/api/diagnostics/log/core/openvpn" e que foram passados alguns parametros searchPhrase e severity. SearchPhrase contém as palavras pesquisadas e severity os níveis de log para corresponder.
Agora, quando o servidor web recebe essa requisição, o código php vai rotear para uma controller que está associada a API.
Em específico, para sermos breve, será usado a controller "/usr/local/opnsense/mvc/app/controllers/OPNsense/Diagnostics/Api/LogController.php".

Você pode ver o código que remove os caracteres especiais na seguinte seção:
CodeSelect
// create filter to sanitize input data
        $filter = new Filter([
            'query' => function ($value) {
                return preg_replace("/[^0-9,a-z,A-Z, ,*,\-,_,.,\#,\:]/", "", $value);
            }
        ]);


Ou seja, só serão aceitos na pesquisa os caracteres: De a-z maiúsculas e minúsculas, números, espaço, *, traço, underline, ponto, # e dois pontos.

Seguindo a lógico do código, essa função limita em 9999 a quantidade de linhas para não estourar a memória e em seguida chama o configd para executar a ação:
"system diag log" passando como parâmetros os termos de pesquisa, módulo (core), arquivo (openvpn) além das severities.

Bom, agora temos que saber o que o configd vai executar com esse comando, e agora vamos precisar consultar o arquivo "/usr/local/opnsense/service/conf/actions.d/actions_system.conf", no qual possui a definição da ação "diag log" conforme podemos ver abaixo.

CodeSelect
[diag.log]
command:/usr/local/opnsense/scripts/syslog/queryLog.py
parameters:--limit %s --offset %s --filter %s  --module %s --filename %s --severity %s
type:script_output
message:Show log

Pimba!

O configd está apenas chamando outro script (queryLog.py) e repassando os parâmetros para ele. Inclusive, podemos nós mesmos chamar o script python manualmente da seguinte forma:
CodeSelect
/usr/local/opnsense/scripts/syslog/queryLog.py --limit 10 --offset 0 --filter "ludarkstar99"  --module core --filename openvpn --severity ""

Pimba novamente!

A saída é um json contendo a linha do log com os metadados da pesquisa realizada:
CodeSelect
{"filters":"ludarkstar99","rows":[{"timestamp":"2025-02-20T00:15:39-03:00","parser":"SysLogFormatRFC5424","facility":3,"severity":"Notice","process_name":"openvpn_server4","pid":"703","rnum":3798,"line":" ludarkstar99\/177.177.177.177:64451 Protocol options: protocol-flags cc-exit tls-ekm dyn-tls-crypt"},....
[...SAÍDA OMITIDA...]

Nadamos, nadamos... E ainda não descobrimos como é feito o filtro.
Calma jovem padawan, já estamos em 99% aqui. segue o baile.

Vamos abrir o arquivo que faz a consulta bruta ao log, /usr/local/opnsense/scripts/syslog/queryLog.py.

Aqui já podemos ver mais um pouco sobre o que representa cada argumento do script:
CodeSelect
if __name__ == '__main__':
    # handle parameters
    parser = argparse.ArgumentParser()
    parser.add_argument('--output', help='output type [json/text]', default='json')
    parser.add_argument('--filter', help='filter results', default='')
    parser.add_argument('--limit', help='limit number of results', default='')
    parser.add_argument('--offset', help='begin at row number', default='')
    parser.add_argument('--filename', help='log file name (excluding .log extension)', default='')
    parser.add_argument('--module', help='module', default='core')
    parser.add_argument('--severity', help='comma separated list of severities', default='')
    inputargs = parser.parse_args()


Logo mais abaixo vemos a lógica para abrir o(s) arquivo(s) de log.
CodeSelect
    if inputargs.filename != "":
        log_filenames = list()
        if inputargs.module == 'core':
            log_basename = "/var/log/%s" % os.path.basename(inputargs.filename)
        else:
            log_basename = "/var/log/%s/%s" % (
                os.path.basename(inputargs.module), os.path.basename(inputargs.filename)
            )
        if os.path.isdir(log_basename):
            # new syslog-ng local targets use an extra directory level
            filenames = glob.glob("%s/%s_*.log" % (log_basename, log_basename.split('/')[-1].split('.')[0]))
            for filename in sorted(filenames, reverse=True):
                log_filenames.append(filename)


Aqui temos o ouro, as linhas relacionadas a correpondencia do filtro no texto. Repare que é usado expressão regular.
O que acontece aqui é o seguinte:
1. Seu filtro de pesquisa tem o caractere * substituído por .* (expressão regular que identificar qualquer caractere 0 ou mais vezes;
2. Se não houver o caractere curinga na sua pesquisa (*), seu filtro vai ser forçado a virar uma expressão regular, com .* antes da(s) palavra(s) e depois;
3. O Script lê cada linha dos logs e verifica se a expressão regular corresponde com o texto da linha.

Aqui podemos ver as partes informadas acima:

CodeSelect
[...]
        try:
            filter = inputargs.filter.replace('*', '.*').lower()
            if filter.find('*') == -1:
                # no wildcard operator, assume partial match
                filter = ".*%s.*" % filter
            filter_regexp = re.compile(filter)
        except re.error:
            # remove illegal expression
            filter_regexp = re.compile('.*')

        row_number = 0
        for filename in log_filenames:
            if os.path.exists(filename):
                format_container = FormatContainer(filename)
                for rec in reverse_log_reader(filename):
                    row_number += 1
                    if rec['line'] != "" and filter_regexp.match(('%s' % rec['line']).lower()):
[...]

Detalhe sórdido que o script vai ler todos os arquivos da pasta /var/log/openvpn/* até atingir o limite de linhas (9999 caso não especificado).


Então podemos tirar as seguintes conclusões:
Para pesquisar na versão 24.7.2 ou anterior do opnsense, você pode usar o caractere curinga * sim, mas tem um formato especial para usá-lo.
Exemplo de filtro: *ludarkstar99*Peer Connection Initiated

Basicamente você coloca um * antes do texto, e um * entre palavras que há caracteres ou termos desconhecidos, então o curinga faz seu papel de curinga (wildcard).

E se você perguntar: luciano, não bastaria colocar ludarkstar*Peer ? tem mesmo que botar o * antes do texto? Tem sim meu jovem, isso ocorre por conta que antes do nome do usuário tem outros caracteres, como data/hora, nome do processo, e tal. Se a linha do log começasse com ludarkstar99, aí sim iria funcionar, mas não é assim que começa e você agora sabe exatamente o porque.


AS COISAS VELHAS JÁ PASSARAM, EIS QUE TUDO SE FEZ NOVO.
Certo. Entendemos o rolê que é fazer uma simples pesquisa no OPNsense 24.1, e aí eu fui tentar em outro firewall com a versão 24.7.12 e não deu certo...
Sabe porque não deu certo? Porque D'us quis! Talvez ele só ame quem lê e carrega seu código.

Mas se eu puder ajudar em algo, fica a dica, leia o código. As tábuas com os 10 mandamentos não foram feitas atoa...

A partir da versão 24.7.3 foi alterado o código que faz a correspondência de filtros no log.
Abrindo o mesmo arquivo /usr/local/opnsense/scripts/syslog/queryLog.py na versão 24.7, vemos que foi criado uma classe específica para esta função - LogMatcher conforme o trecho de código abaixo.

CodeSelect
[...]
from log_matcher import LogMatcher
[...]
log_matcher = LogMatcher(inputargs.filter, inputargs.filename, inputargs.module, inputargs.severity)
        for record in log_matcher.match_records():
[...]

Dá pra ver que alguém entendeu o domínio da questão e encapsulou a complexidade do código. E como ainda estamos em busca das tábuas perdidas, vamos precisar investigar abrindo o arquivo que contém a definição da classe LogMatcher.

Abrindo o arquivo /usr/local/opnsense/scripts/syslog/log_matcher.py podemos ver a implementação do filtro na versão 24.7, e a lógica ainda é a mesma. Checa se a linha tem correspondência via regex com o termo de pesquisa. Seu texto da caixinha de pesquisa é tratado como uma coisa só, por isso a necessidade de usar curingas (*) para dizer que tem algo entre as palavras pesquisadas.

CodeSelect 
    if line != "" and self.filter_regexp.match(('%s' % line).lower()):
        record = self.parse_line(line, format_container)
        if len(self.severity) == 0 or record['severity'] is None or record['severity'] in self.severity:
            yield record



Já na versão 24.7.3, podemos ver que foi completamente alterado a forma de pesquisar. Agora ao invés de usar a correspondência via expressão regular, passou a ser usado a função find (linha tmp.find abaixo) que nada mais é que uma busca por termos literais. Então nada de * mais nas pesquisas. Além disso, o código quebra cada palavra para pesquisá-la individualmente e só retorna correspondência se todos os tokens (palavras individuais) forem encontradas na linha do log.

CodeSelect

    def _match_line(self, line):
        # matcher, checks if all clauses are matched.
        tmp = line.lower()
        for clause in self.filter_clauses:
            if tmp.find(clause) == -1:
                return False

        return line != ''


Resumindo, até a versão 24.7.2 se fossemos pesquisar as conexões vpn para um determinado usuário, iríamos filtrar da seguinte forma:
filtro: "*ludarkstar99*Peer Connection Initiated".

A partir da versão 24.7.3, para pesquisar múltiplos termos na caixa de pesquisa, como no exemplo de usuário autenticado na vpn, ficariam assim:
filtro: "ludarkstar99 Peer Connection Initiated".

*sem as aspas é claro.
Lembrando que para a versão 24.7.3+ Só haverá resultado se todas as palavras forem encontradas dentro da linha do log.