Custom decoder for Open Connect VPN

[Romano Ricci]

Hello, colleagues!

I have a problem with creating a custom decoder for Open Connect VPN logs. I've developed a decoder, but it doesn't work properly. If I remove part of the log, the decoder starts working, but with the full log, an error occurs.

Could you please help me figure out the situation? I need to understand what the problem might be and how to refine the decoder so that it correctly processes all the data.

Thank you in advance for your help!

Custom decoder

<decoder name="ocserv">
   <prematch type="pcre2">main: added IP (.*)</prematch>
</decoder>

<decoder name="ocserv_fields">
    <parent>ocserv</parent>
    <regex type="pcre2">added IP '(\d{1,3}\.\d{1,3}\.\d{1,3}\.\d{1,3})' \(with score (\d+)\) to ban list, will be reset at: (.+)$</regex>
    <order>srcip, score, reset_time</order>
</decoder>

Full log

May 29 15:33:03 off-vpn-new ocserv[7116852]: main: added IP '11.11.11.11' (with score 80) to ban list, will be reset at: Thu May 29 15:38:03 2025

**Messages: WARNING: (7003): 'eacfb16c' token expires INFO: (7202): Session initialized with token '36acc0f6' **Phase 1: Completed pre-decoding. full event: 'May 29 15:33:03 off-vpn-new ocserv[7116852]: main: added IP '11.11.11.11' (with score 80) to ban list, will be reset at: Thu May 29 15:38:03 2025' timestamp: 'May 29 15:33:03' hostname: 'off-vpn-new' program_name: 'ocserv' **Phase 2: Completed decoding. No decoder matched.

Incomplete log

main: added IP '11.11.11.11' (with score 80) to ban list, will be reset at: Thu May 29 15:38:03 2025

**Messages: WARNING: (7003): 'eacfb16c' token expires INFO: (7202): Session initialized with token '3208685b' **Phase 1: Completed pre-decoding. full event: 'main: added IP '11.11.11.11' (with score 80) to ban list, will be reset at: Thu May 29 15:38:03 2025' **Phase 2: Completed decoding. name: 'ocserv' reset_time: 'Thu May 29 15:38:03 2025' score: '80' srcip: '11.11.11.11' **Phase 3: Completed filtering (rules). id: '100011' level: '3' description: 'added IP 11.11.11.11 to ban list' groups: '["ocserv"]' firedtimes: '1' mail: 'false' **Alert to be generated.

How can I modify the decoder?

[Hossam El Amraoui]

Hi Romano Ricci,

Let me replicate this and I will get back to you as soon as possible.

[Hossam El Amraoui]

The problem is that while the full log has a `program_name` value that is pre-decoded, the incomplete log does not. To decode logs with a `program_name` field, you should indicate it in the decoder. For this, you have two solutions:

1. Use different decoders. You create a decoder for the incomplete log and a decoder for the full log. The decoders should look like:

```
<decoder name="ocserv_incomplete">

   <prematch type="pcre2">main: added IP (.*)</prematch>

   <regex type="pcre2">added IP '(\d{1,3}\.\d{1,3}\.\d{1,3}\.\d{1,3})' \(with score (\d+)\) to ban list, will be reset at: (.+)$</regex>
   <order>srcip, score, reset_time</order>
</decoder>

<decoder name="ocserv_full">
    <program_name>ocserv</program_name>

    <regex type="pcre2">added IP '(\d{1,3}\.\d{1,3}\.\d{1,3}\.\d{1,3})' \(with score (\d+)\) to ban list, will be reset at: (.+)$</regex>
    <order>srcip, score, reset_time</order>
</decoder>

```

You can see that it is working successfully with both logs using the `wazuh-logtest` tool:

```
root@ubuntu22:/home/vagrant# /var/ossec/bin/wazuh-logtest
Starting wazuh-logtest v4.12.0
Type one log per line

May 29 15:33:03 off-vpn-new ocserv[7116852]: main: added IP '11.11.11.11' (with score 80) to ban list, will be reset at: Thu May 29 15:38:03 2025

**Phase 1: Completed pre-decoding.
        full event: 'May 29 15:33:03 off-vpn-new ocserv[7116852]: main: added IP '11.11.11.11' (with score 80) to ban list, will be reset at: Thu May 29 15:38:03 2025'
        timestamp: 'May 29 15:33:03'
        hostname: 'off-vpn-new'
        program_name: 'ocserv'

**Phase 2: Completed decoding.

        name: 'ocserv_full'

        reset_time: 'Thu May 29 15:38:03 2025'
        score: '80'
        srcip: '11.11.11.11'

main: added IP '11.11.11.11' (with score 80) to ban list, will be reset at: Thu May 29 15:38:03 2025

**Phase 1: Completed pre-decoding.
        full event: 'main: added IP '11.11.11.11' (with score 80) to ban list, will be reset at: Thu May 29 15:38:03 2025'

**Phase 2: Completed decoding.

        name: 'ocserv_incomplete'

        reset_time: 'Thu May 29 15:38:03 2025'
        score: '80'
        srcip: '11.11.11.11'

```





2. The other solution consists of changing the log format. To do this, you should make Wazuh read the log from a custom file, adding to the configuration (/var/ossec/etc/ossec.conf) the following:

```
  <localfile>
    <location>/home/vagrant/custom.log</location>
    <log_format>syslog</log_format>
    <out_format>$(timestamp) - custom: $(log)</out_format>
  </localfile>
```

Where `<location>` is the file where the original logs should be stored.

After that, if you enable the `<logall>` option in the manager's configuration, you will be able to see the logs with the new format in the `/var/ossec/logs/archives/archives.log` file. The new logs will have this format:

```
Jun  5 11:50:37 - custom: main: added IP '11.11.11.11' (with score 80) to ban list, will be reset at: Thu May 29 15:38:03 2025
Jun  5 11:50:37 - custom: May 29 15:33:03 off-vpn-new ocserv[7116852]: main: added IP '11.11.11.11' (with score 80) to ban list, will be reset at: Thu May 29 15:38:03 2025
```

For these logs, you can use the following decoder, maintaining the same decoder for both logs with minimum changes, only adding the `program_name` field:

```
<decoder name="ocserv">
   <program_name>custom</program_name>

   <prematch type="pcre2">main: added IP (.*)</prematch>
</decoder>

<decoder name="ocserv_fields">
    <parent>ocserv</parent>
    <regex type="pcre2">added IP '(\d{1,3}\.\d{1,3}\.\d{1,3}\.\d{1,3})' \(with score (\d+)\) to ban list, will be reset at: (.+)$</regex>
    <order>srcip, score, reset_time</order>
</decoder>

```

`wazuh-logtest` output:

```
root@ubuntu22:/home/vagrant# /var/ossec/bin/wazuh-logtest
Starting wazuh-logtest v4.12.0
Type one log per line

Jun  5 11:50:37 - custom: main: added IP '11.11.11.11' (with score 80) to ban list, will be reset at: Thu May 29 15:38:03 2025

**Phase 1: Completed pre-decoding.
        full event: 'Jun  5 11:50:37 - custom: main: added IP '11.11.11.11' (with score 80) to ban list, will be reset at: Thu May 29 15:38:03 2025'
        timestamp: 'Jun  5 11:50:37'
        hostname: '-'
        program_name: 'custom'

**Phase 2: Completed decoding.
        name: 'ocserv'
        reset_time: 'Thu May 29 15:38:03 2025'
        score: '80'
        srcip: '11.11.11.11'

Jun  5 11:50:37 - custom: May 29 15:33:03 off-vpn-new ocserv[7116852]: main: added IP '11.11.11.11' (with score 80) to ban list, will be reset at: Thu May 29 15:38:03 2025

**Phase 1: Completed pre-decoding.
        full event: 'Jun  5 11:50:37 - custom: May 29 15:33:03 off-vpn-new ocserv[7116852]: main: added IP '11.11.11.11' (with score 80) to ban list, will be reset at: Thu May 29 15:38:03 2025'
        timestamp: 'Jun  5 11:50:37'
        hostname: '-'
        program_name: 'custom'

**Phase 2: Completed decoding.
        name: 'ocserv'
        reset_time: 'Thu May 29 15:38:03 2025'
        score: '80'
        srcip: '11.11.11.11'

```

[Romano Ricci]

Thank you, everything worked out!

четверг, 5 июня 2025 г. в 13:58:34 UTC+2, Hossam El Amraoui: