Active response don't work for firewall-drop

[Cyprien Chapelle]

Hello,

I tried setting up wazuh's "Firewall-drop", but it doesn't work.

Here is my ossec.conf file:

`  <command>
    <name>firewall-drop</name>
    <executable>firewall-drop</executable>
    <expect>srcip</expect>
    <timeout_allowed>yes</timeout_allowed>
  </command>

....

  <active-response>
    <command>firewall-drop</command>
    <location>all</location>
    <rules_id>5710,5712,5716,100100</rules_id>
    <timeout>1800</timeout>
  </active-response>

`

I noticed with the command : `/var/ossec/active-response/bin/firewall-drop add - 192.168.x.x` that the script provided was not good, because the command was going around in circles, doing nothing.
So I installed the firewall-drop.sh script, old version and I ran : `/var/ossec/active-response/bin/firewall-drop.sh add - 192.168.x.x`
And when I do iptables -L, I get my blocked IP fine.
However, after replacing this:

`<executable>firewall-drop.sh</executable>`

that doesn't work either.

I did a lot of research on the problem, I tried to "debug" via the "internal_options.conf" file. I could see that active response was not even executed, whatever the type of rule sought (after having attempted an ssh attack: ```for i in `seq 1 10`; do sshpass -p 'wrong_password' ssh -o StrictHostKeyChecking=no 192.168.x.x; done``` )

Then I tried to do the same having "pf-block". And this worked :

`<command>
  <name>pf-block</name>
  <executable>pf</executable>
</command>

....

<active-response>
  <command>pf-block</command>
  <location>defined-agent</location>
  <agent_id>001</agent_id>
  <rules_group>authentication_failed|authentication_failures</rules_group>
</active-response>`

It worked with an error, but active response was enabled! Here are the logs: active-response.log

`2022/01/17 15:28:50 active-response/bin/pf: Cannot read 'srcip' from data
2022/01/17 15:51:22 active-response/bin/pf: Starting`

I tried firewall with the same syntax, still nothing.

I'm a little lost... Could someone help me?

--------

Wazuh version : 4.2.0-5.1

[Cyprien Chapelle]

I found a problem: when I create an alert (by ssh connection), it says in /var/ossec/etc/alerts/alerts.log that the alert message comes from /var/log/auth.log. However, there is no alert concerning the IP 192.168.x.x in this file. Anyone know why?

/var/ossec/etc/alerts/alerts.log :

** Alert 1642523930.19766: mail  - local,syslog,sshd,invalid_login,authentication_failed,pci_dss_10.2.4,pci_dss_10.2.5,pci_dss_10.6.1,gpg13_7.1,gdpr_IV_35.7.d,gdpr_IV_32.2,hipaa_164.312.b,nist_800_53_AU.14,nist_800_53_AC.7,nist_800_53_AU.6,tsc_CC6.1,tsc_CC6.8,tsc_CC7.2,tsc_CC7.3,
2022 Jan 18 16:38:50 (cible) 192.168.1.20->/var/log/auth.log
Rule: 5710 (level 13) -> 'sshd: Attempt to login using a non-existent user'
Src IP: 192.168.x.x
Jan 18 16:38:49 cible sshd[14465]: Failed password for invalid user user from 192.168.x.x port 56616 ssh2

[victor....@wazuh.com]

Hello cyprien,

Regarding the firewall-drop active response, take in mind that the command’s expect option is deprecated since 4.2. https://documentation.wazuh.com/current/user-manual/reference/ossec-conf/commands.html?highlight=command#expect.

I have tested this active response command in my local environment and it seems it works correctly if we use the following configuration:

<command>
  <name>firewall-drop</name>
  <executable>firewall-drop</executable>
  <timeout_allowed>yes</timeout_allowed>
</command>

....

 <active-response>
  <command>firewall-drop</command>
  <location>all</location>
  <rules_id>5710,5712,5716,100100</rules_id>
  <timeout>1800</timeout>
 </active-response>

Check this configuration, and in case this does not work, please share your logs with execd and remoted debug activated.

Regarding your log coming from /var/log/auth.log, please activate temporally the logall option in your configuration, restart your manager, and ensure you are getting the related log.
If that is not the case, activate logcollector.debug=2 in your local_internal_options.confand share with us your ossec.log

If you have any doubt do not hesitate to ask

​

[Cyprien Chapelle]

Hello, thank you for your help!

I replaced the configurations you suggest, indeed <expect> is obsolete, but you should know that I tried all types of configurations in order to try to find the problem.

So, I perform the following attack on the host containing a wazuh agent :

ssh us...@192.168.x.x
us...@192.168.x.x's password:

In debug mode, this is what I get for ossec.log :

2022/01/19 08:18:58 wazuh-remoted[3014] manager.c:1058 at lookfor_agent_group(): DEBUG: Agent '010' group is 'default'
2022/01/19 08:18:58 wazuh-remoted[3014] manager.c:1144 at read_controlmsg(): DEBUG: read_controlmsg(): reading 'Linux |cible |5.4.128-1-pve |#1 SMP PVE 5.4.128-2 (Wed, 18 Aug 2021 16:20:02 +0200) |x86_64 [Debian GNU/Linux|debian: 10 (buster)] - Wazuh v4.2.5 / ab73af41699f13fdd81903b5f23d8d00
1715fb875296f5082db84216d4a850f8 merged.mg
#"_agent_ip":192.168.x.x
'
2022/01/19 08:18:59 wazuh-remoted[3014] state.c:59 at rem_write_state(): DEBUG: Updating state file.
2022/01/19 08:19:04 wazuh-remoted[3014] secure.c:314 at rem_keyupdate_main(): DEBUG: Checking for keys file changes.
2022/01/19 08:19:04 wazuh-remoted[3014] state.c:59 at rem_write_state(): DEBUG: Updating state file.
2022/01/19 08:19:04 wazuh-remoted[3014] manager.c:677 at c_files(): DEBUG: Updating shared files sums.
2022/01/19 08:19:04 wazuh-remoted[3014] manager.c:912 at c_files(): DEBUG: End updating shared files sums.
2022/01/19 08:19:08 wazuh-remoted[3014] secure.c:521 at HandleSecureMessage(): DEBUG: TCP socket 10 already in keystore. Updating...
2022/01/19 08:19:08 wazuh-remoted[3014] manager.c:242 at save_controlmsg(): DEBUG: save_controlmsg(): inserting 'Linux |cible |5.4.128-1-pve |#1 SMP PVE 5.4.128-2 (Wed, 18 Aug 2021 16:20:02 +0200) |x86_64 [Debian GNU/Linux|debian: 10 (buster)] - Wazuh v4.2.5 / ab73af41699f13fdd81903b5f23d8d00
1715fb875296f5082db84216d4a850f8 merged.mg
#"_agent_ip":192.168.x.x

And for the alerts.log :

** Alert 1642580325.8320: mail  - local,syslog,sshd,invalid_login,authentication_failed,pci_dss_10.2.4,pci_dss_10.2.5,pci_dss_10.6.1,gpg13_7.1,gdpr_IV_35.7.d,gdpr_IV_32.2,hipaa_164.312.b,nist_800_53_AU.14,nist_800_53_AC.7,nist_800_53_AU.6,tsc_CC6.1,tsc_CC6.8,tsc_CC7.2,tsc_CC7.3,
2022 Jan 19 08:18:45 (cible) 192.168.1.20->/var/log/auth.log

Rule: 5710 (level 13) -> 'sshd: Attempt to login using a non-existent user'
Src IP: 192.168.x.x

Src Port: 42444
Jan 19 08:18:45 cible sshd[1001]: Invalid user user from 192.168.x.x port 42444

"Regarding your log coming from /var/log/auth.log, please activate temporally the logall option in your configuration, restart your manager, and ensure you are getting the related log.
If that is not the case, activate logcollector.debug=2 in your local_internal_options.confand share with us your ossec.log"

Ok, done, I still have nothing in auth.log during an ssh attack

ossec.log :

2022/01/19 08:23:55 wazuh-remoted[4196] state.c:59 at rem_write_state(): DEBUG: Updating state file.
2022/01/19 08:24:00 wazuh-remoted[4196] secure.c:314 at rem_keyupdate_main(): DEBUG: Checking for keys file changes.
2022/01/19 08:24:00 wazuh-remoted[4196] state.c:59 at rem_write_state(): DEBUG: Updating state file.
2022/01/19 08:24:00 wazuh-remoted[4196] manager.c:677 at c_files(): DEBUG: Updating shared files sums.
2022/01/19 08:24:00 wazuh-remoted[4196] manager.c:912 at c_files(): DEBUG: End updating shared files sums.
2022/01/19 08:24:03 wazuh-logcollector[4230] read_syslog.c:104 at read_syslog(): DEBUG: Reading syslog message: 'Jan 19 08:24:02 wazuh-manager filebeat[110]: 2022-01-19T08:24:02'...
2022/01/19 08:24:03 wazuh-logcollector[4230] read_syslog.c:148 at read_syslog(): DEBUG: Read 1 lines from /var/log/syslog
2022/01/19 08:24:04 wazuh-remoted[4196] secure.c:521 at HandleSecureMessage(): DEBUG: TCP socket 11 already in keystore. Updating...
2022/01/19 08:24:04 wazuh-remoted[4196] manager.c:242 at save_controlmsg(): DEBUG: save_controlmsg(): inserting 'Linux |cible |5.4.128-1-pve |#1 SMP PVE 5.4.128-2 (Wed, 18 Aug 2021 16:20:02 +0200) |x86_64 [Debian GNU/Linux|debian: 10 (buster)] - Wazuh v4.2.5 / ab73af41699f13fdd81903b5f23d8d00
1715fb875296f5082db84216d4a850f8 merged.mg
#"_agent_ip":192.168.1.20

I don't understand why the alerts.log file shows the path /var/log/auth.log when there is not the alert in this file, but in another...

While waiting for your answer, I studied an answer made here (the one at 13:39:42) https://groups.google.com/g/wazuh/c/pgfBgn4WaNQ/m/uWGDPfSFAAAJ

By you, Victor, haha.

So I created a new one:

<rule id="100010" level="13">
  <match>test</match>
  <description>Testing active_response</description>
</rule>
</group>

With this conf :

  <active-response>
    <command>firewall-drop</command>
    <location>Local</location>
    <level>13</level>                        
    <timeout>1800</timeout>
  </active-response>

And if I run this command :

echo "Nov  8 11:16:26 centos-manager1 sshd[20046]: test from 172.17.1.1 port 39588" >> /tmp/testing.log

I have in active-response.log :

2022/01/19 08:42:56 active-response/bin/firewall-drop: Starting
2022/01/19 08:42:56 active-response/bin/firewall-drop: {"version":1,"origin":{"name":"node01","module":"wazuh-execd"},"command":"add","parameters":{"extra_args":[],"alert":{"timestamp":"2022-01-19T08:42:56.529+0000","rule":{"level":13,"description":"sshd: Attempt to login using a non-existent user","id":"5710","mitre":{"id":["T1110"],"tactic":["Credential Access"],"technique":["Brute Force"]},"firedtimes":1,"mail":true,"groups":["local","syslog","sshd","invalid_login","authentication_failed"],"pci_dss":["10.2.4","10.2.5","10.6.1"],"gpg13":["7.1"],"gdpr":["IV_35.7.d","IV_32.2"],"hipaa":["164.312.b"],"nist_800_53":["AU.14","AC.7","AU.6"],"tsc":["CC6.1","CC6.8","CC7.2","CC7.3"]},"agent":{"id":"000","name":"wazuh-manager"},"manager":{"name":"wazuh-manager"},"id":"1642581776.30257","full_log":"Nov  8 11:16:26 centos-manager1 sshd[20046]: invalid user from 172.17.1.1 port 39588","predecoder":{"program_name":"sshd","timestamp":"Nov  8 11:16:26","hostname":"centos-manager1"},"decoder":{"parent":"sshd","name":"sshd"},"data":{"srcport":"39588"},"location":"/tmp/testing.log"},"program":"active-response/bin/firewall-drop"}}

2022/01/19 08:42:56 active-response/bin/firewall-drop: Cannot read 'srcip' from data

and in alerts.log :

** Alert 1642581954.33783: mail  - local,syslog,sshd,
2022 Jan 19 08:45:54 centos-manager1->/tmp/testing.log
Rule: 100010 (level 13) -> 'Testing active_response'
Nov  8 11:16:26 centos-manager1 sshd[20046]: test from 172.17.1.1 port 39588

** Alert 1642581954.34023: - ossec,active_response,pci_dss_11.4,gpg13_4.13,gdpr_IV_35.7.d,nist_800_53_SI.4,tsc_CC6.1,tsc_CC6.8,tsc_CC7.2,tsc_CC7.3,tsc_CC7.4,
2022 Jan 19 08:45:54 wazuh-manager->/var/ossec/logs/active-responses.log
Rule: 651 (level 3) -> 'Host Blocked by firewall-drop Active Response'
2022/01/19 08:45:54 active-response/bin/firewall-drop: {"version":1,"origin":{"name":"node01","module":"wazuh-execd"},"command":"add","parameters":{"extra_args":[],"alert":{"timestamp":"2022-01-19T08:45:54.653+0000","rule":{"level":13,"description":"Testing active_response","id":"100010","firedtimes":1,"mail":true,"groups":["local","syslog","sshd"]},"agent":{"id":"000","name":"wazuh-manager"},"manager":{"name":"wazuh-manager"},"id":"1642581954.33783","full_log":"Nov  8 11:16:26 centos-manager1 sshd[20046]: test from 172.17.1.1 port 39588","predecoder":{"program_name":"sshd","timestamp":"Nov  8 11:16:26","hostname":"centos-manager1"},"decoder":{"name":"sshd"},"location":"/tmp/testing.log"},"program":"active-response/bin/firewall-drop"}}
version: 1
origin.name: node01
origin.module: wazuh-execd
command: add
parameters.extra_args: []
parameters.alert.timestamp: 2022-01-19T08:45:54.653+0000
parameters.alert.rule.level: 13
parameters.alert.rule.description: Testing active_response
parameters.alert.rule.id: 100010
parameters.alert.rule.firedtimes: 1
parameters.alert.rule.mail: true
parameters.alert.rule.groups: ["local", "syslog", "sshd"]
parameters.alert.agent.id: 000
parameters.alert.agent.name: wazuh-manager
parameters.alert.manager.name: wazuh-manager
parameters.alert.id: 1642581954.33783
parameters.alert.full_log: Nov  8 11:16:26 centos-manager1 sshd[20046]: test from 172.17.1.1 port 39588
parameters.alert.predecoder.program_name: sshd
parameters.alert.predecoder.timestamp: Nov  8 11:16:26
parameters.alert.predecoder.hostname: centos-manager1
parameters.alert.decoder.name: sshd
parameters.alert.location: /tmp/testing.log
parameters.program: active-response/bin/firewall-drop

So it works, but now you have to create an alert with an SRCIP field !

And if I try with an alert activating level 13 also:

echo "Nov  8 11:16:26 centos-manager1 sshd[20046]: invalid user from 172.17.1.1 port 39588" >> /tmp/testing.log

it also works !

Anf for auth.log :

echo "Nov  8 11:16:26 centos-manager1 sshd[20046]: invalid user from 172.17.1.1 port 39588" >> /var/log/auth.log

Is the same :

2022/01/19 08:50:26 active-response/bin/firewall-drop: Starting
2022/01/19 08:50:26 active-response/bin/firewall-drop: {"version":1,"origin":{"name":"node01","module":"wazuh-execd"},"command":"add","parameters":{"extra_args":[],"alert":{"timestamp":"2022-01-19T08:50:26.912+0000","rule":{"level":13,"description":"sshd: Attempt to login using a non-existent user","id":"5710","mitre":{"id":["T1110"],"tactic":["Credential Access"],"technique":["Brute Force"]},"firedtimes":3,"mail":true,"groups":["local","syslog","sshd","invalid_login","authentication_failed"],"pci_dss":["10.2.4","10.2.5","10.6.1"],"gpg13":["7.1"],"gdpr":["IV_35.7.d","IV_32.2"],"hipaa":["164.312.b"],"nist_800_53":["AU.14","AC.7","AU.6"],"tsc":["CC6.1","CC6.8","CC7.2","CC7.3"]},"agent":{"id":"000","name":"wazuh-manager"},"manager":{"name":"wazuh-manager"},"id":"1642582226.39554","full_log":"Nov  8 11:16:26 centos-manager1 sshd[20046]: invalid user from 172.17.1.1 port 39588","predecoder":{"program_name":"sshd","timestamp":"Nov  8 11:16:26","hostname":"centos-manager1"},"decoder":{"parent":"sshd","name":"sshd"},"data":{"srcport":"39588"},"location":"/var/log/auth.log"},"program":"active-response/bin/firewall-drop"}}

2022/01/19 08:50:26 active-response/bin/firewall-drop: Cannot read 'srcip' from data

But with a real alert (ssh):

** Alert 1642582342.43083: mail  - local,syslog,sshd,invalid_login,authentication_failed,pci_dss_10.2.4,pci_dss_10.2.5,pci_dss_10.6.1,gpg13_7.1,gdpr_IV_35.7.d,gdpr_IV_32.2,hipaa_164.312.b,nist_800_53_AU.14,nist_800_53_AC.7,nist_800_53_AU.6,tsc_CC6.1,tsc_CC6.8,tsc_CC7.2,tsc_CC7.3,
2022 Jan 19 08:52:22 (cible) 192.168.1.20->/var/log/auth.log

Rule: 5710 (level 13) -> 'sshd: Attempt to login using a non-existent user'
Src IP: 192.168.x.x

Src Port: 51852
Jan 19 08:52:22 cible sshd[1079]: Invalid user user from 192.168.x.xport 51852

No active response.

That's why I think the error comes from the log file, it is not filled in the right one, right?

How do you put your code between <code>? It would be more visible, sorry

[victor....@wazuh.com]

First, regarding the path shown in your rule:

** Alert 1642580325.8320: mail - local,syslog,sshd,invalid_login,authentication_failed,pci_dss_10.2.4,pci_dss_10.2.5,pci_dss_10.6.1,gpg13_7.1,gdpr_IV_35.7.d,gdpr_IV_32.2,hipaa_164.312.b,nist_800_53_AU.14,nist_800_53_AC.7,nist_800_53_AU.6,tsc_CC6.1,tsc_CC6.8,tsc_CC7.2,tsc_CC7.3,
2022 Jan 19 08:18:45 (cible) 192.168.1.20->/var/log/auth.log

Checking your logs, the event shown in your /var/log/syslog file seems not to be related to your ssh alerts:
We are expecting Jan 19 08:18:45 cible sshd[1001]: Invalid user user from 192.168.x.x port 42444 and logcollector is reading
Jan 19 08:24:02 wazuh-manager filebeat[110]: 2022-01-19T08:24:02.

Taking that into account, follow these steps:

- Activate the logall option

<ossec_config>
  <global>
...
    <logall>yes</logall>
...

- Set the following content in your /var/ossec/etc/local_internal_options.conf

logcollector.debug=2
logcollector.sample_log_length=500

- Restart your manager
- Perform an ssh connection with an invalid user
- Check the content of your /var/ossec/logs/archives/archives.log

You should have gotten something similar to

2022 Jan 19 12:34:53 ubuntu-bionic->/var/log/auth.log Jan 19 12:34:52 ubuntu-bionic sshd[13919]: Invalid user invalid-user from 172.17.1.1 port 44298

- Check if the file specified in archives.log has that event
- Check the content of your ossec.log. You should get something similar to

2022/01/19 12:34:53 wazuh-logcollector[12963] read_syslog.c:104 at read_syslog(): DEBUG: Reading syslog message: 'Jan 19 12:34:52 ubuntu-bionic sshd[13919]: Invalid user invalid-user from 172.17.1.1 port 44298'
...
2022/01/19 12:34:53 wazuh-logcollector[12963] read_syslog.c:148 at read_syslog(): DEBUG: Read 2 lines from /var/log/auth.log

- Do the same by inserting your event in a custom file.

Send back your results. In case of showing in archives/alerts/ossec.log a file in which the event has not occurred, please send back any related logs and your OS and we will research this issue.

About, your AR configuration, my fault. The location value all only affects agents. So, yes, you should use something similar to the solution presented in https://groups.google.com/g/wazuh/c/pgfBgn4WaNQ/m/uWGDPfSFAAAJ.
However, as you said, is not recommended to use level as an AR condition for a firewall-drop command due to this required srcip field. Maybe the best approach is to use your original configuration, but using local as  location

 <active-response>
  <command>firewall-drop</command>
  <location>local</location>
  <rules_id>5710,5712,5716,100100</rules_id>
  <timeout>1800</timeout>
 </active-response>

Restart your manager, and in case it does not work, please send back:

- active-response.log
- ossec.log
- alert.log

Also, to format text block as code, I use the extension Markdown Here.

​

[Cyprien Chapelle]

• Activate the logall option

• Set the following content in your /var/ossec/etc/local_internal_options.conf /var/ossec/etc/local_internal_options.conf /var/ossec/etc/local_internal_options.conf

​

It's OK !

• Check the content of your /var/ossec/logs/archives/archives.log

​

Ok, I have :

2022 Jan 19 16:56:36 (cible) 192.168.1.20->/var/log/auth.log Jan 19 16:56:34 cible sshd[1936]: Invalid user user from 192.168.1.17 port 53072

​

• Check if the file specified in archives.log has that event

No, he doesn't have it

• Check the content of your ossec.log. You should get something similar to

​

I don't have the corresponding message !

---

Now, with the alert created in the custom file (echo “Nov 8 11:16:26 centos-manager1 sshd[20046]: test from 172.17.1.1 port 39588” >> /tmp/testing.log)
/var/ossec/logs/archives/archives.log :

​

2022 Jan 19 17:08:32 centos-manager1->/tmp/testing.log Nov 8 11:16:26 centos-manager1 sshd[20046]: test from 172.17.1.1 port 39588

It's OK

ossec.log :

2022/01/19 17:08:32 wazuh-logcollector[17041] read_syslog.c:104 at read_syslog(): DEBUG: Reading syslog message: 'Nov  8 11:16:26 centos-manager1 sshd[20046]: test from 17
2.17.1.1 port 39588'
2022/01/19 17:08:32 wazuh-logcollector[17041] read_syslog.c:148 at read_syslog(): DEBUG: Read 1 lines from /tmp/testing.log

​

It's OK !

---

​

- active-response.log
- ossec.log
- alert.log

I'll send you these files tomorrow, it's late here, thank you very much for your help!

[Cyprien Chapelle]

So ....

  <active-response>   
    <command>firewall-drop</command>   

    <location>local</location>   
    <rules_id>5710,5712,5716,100100</rules_id>   
    <timeout>1800</timeout> 
 </active-response>

​

It's OK

- active-response.log :

root@wazuh-manager:~# tail -f /var/ossec/logs/archives/archives.log 
reboot   system boot  5.4.128-1-pve    Thu Jan 13 15:40 - 17:10  (01:30)
root     tty1                          Wed Jan 12 08:25 - down   (08:37)
reboot   system boot  5.4.128-1-pve    Wed Jan 12 08:25 - 17:03  (08:38)
root     tty1                          Tue Jan 11 09:15 - down   (07:51)
reboot   system boot  5.4.128-1-pve    Tue Jan 11 09:15 - 17:06  (07:51)
wtmp begins Tue Jan 11 09:15:10 2022
2022 Jan 20 08:06:29 wazuh-manager->/var/log/syslog Jan 20 08:06:28 wazuh-manager filebeat[110]: 2022-01-20T08:06:28.553Z#011INFO#011[monitoring]#011log/log.go:184#011Non-zero metrics in the last 30s#011{"monitoring": {"metrics": {"beat":{"cgroup":{"memory":{"mem":{"usage":{"bytes":-36864}}}},"cpu":{"system":{"ticks":760,"time":{"ms":3}},"total":{"ticks":2360,"time":{"ms":36},"value":2360},"user":{"ticks":1600,"time":{"ms":33}}},"handles":{"limit":{"hard":524288,"soft":1024},"open":13},"info":{"ephemeral_id":"8f585e8d-2f19-4096-b9aa-6d6ede58b979","uptime":{"ms":1413468},"version":"8.0.0-alpha2"},"memstats":{"gc_next":12459984,"memory_alloc":6517600,"memory_total":269517000,"rss":87449600},"runtime":{"goroutines":168}},"filebeat":{"events":{"added":1,"done":1},"harvester":{"open_files":3,"running":3}},"libbeat":{"config":{"module":{"running":4},"scans":2},"output":{"events":{"acked":1,"active":0,"batches":1,"total":1},"read":{"bytes":6},"write":{"bytes":996}},"pipeline":{"clients":29,"events":{"active":0,"published":1,"total":1},"queue":{"acked":1}}},"registrar":{"states":{"current":14,"update":1},"writes":{"success":1,"total":1}},"system":{"load":{"1":1.25,"15":1.43,"5":1.32,"norm":{"1":0.3125,"15":0.3575,"5":0.33}}}}}}
2022 Jan 20 08:06:55 (cible) 192.168.1.20->/var/log/auth.log Jan 20 08:06:54 cible sshd[992]: Connection closed by invalid user user 192.168.x.x port 58816 [preauth]
2022 Jan 20 08:06:56 (cible) 192.168.1.20->/var/log/auth.log Jan 20 08:06:54 cible sshd[994]: Invalid user user from 192.168.x.x port 59172
2022 Jan 20 08:06:59 wazuh-manager->/var/log/syslog Jan 20 08:06:58 wazuh-manager filebeat[110]: 2022-01-20T08:06:58.553Z#011INFO#011[monitoring]#011log/log.go:184#011Non-zero metrics in the last 30s#011{"monitoring": {"metrics": {"beat":{"cgroup":{"memory":{"mem":{"usage":{"bytes":8192}}}},"cpu":{"system":{"ticks":770,"time":{"ms":9}},"total":{"ticks":2370,"time":{"ms":13},"value":2370},"user":{"ticks":1600,"time":{"ms":4}}},"handles":{"limit":{"hard":524288,"soft":1024},"open":13},"info":{"ephemeral_id":"8f585e8d-2f19-4096-b9aa-6d6ede58b979","uptime":{"ms":1443469},"version":"8.0.0-alpha2"},"memstats":{"gc_next":12459984,"memory_alloc":9044160,"memory_total":272043560,"rss":87449600},"runtime":{"goroutines":168}},"filebeat":{"events":{"added":1,"done":1},"harvester":{"open_files":3,"running":3}},"libbeat":{"config":{"module":{"running":4},"scans":2},"output":{"events":{"acked":1,"active":0,"batches":1,"total":1},"read":{"bytes":6},"write":{"bytes":981}},"pipeline":{"clients":29,"events":{"active":0,"published":1,"total":1},"queue":{"acked":1}}},"registrar":{"states":{"current":14,"update":1},"writes":{"success":1,"total":1}},"system":{"load":{"1":1.11,"15":1.42,"5":1.29,"norm":{"1":0.2775,"15":0.355,"5":0.3225}}}}}}

​

- ossec.log :

root@wazuh-manager:~# tail -f /var/ossec/logs/ossec.log 
2022/01/20 08:05:42 wazuh-remoted[1809] manager.c:242 at save_controlmsg(): DEBUG: save_controlmsg(): inserting 'Linux |cible |5.4.128-1-pve |#1 SMP PVE 5.4.128-2 (Wed, 18 Aug 2021 16:20:02 +0200) |x86_64 [Debian GNU/Linux|debian: 10 (buster)] - Wazuh v4.2.5 / ab73af41699f13fdd81903b5f23d8d00
1715fb875296f5082db84216d4a850f8 merged.mg
#"_agent_ip":192.168.1.20
'
2022/01/20 08:05:42 wazuh-remoted[1809] manager.c:1058 at lookfor_agent_group(): DEBUG: Agent '010' group is 'default'
2022/01/20 08:05:42 wazuh-remoted[1809] manager.c:1144 at read_controlmsg(): DEBUG: read_controlmsg(): reading 'Linux |cible |5.4.128-1-pve |#1 SMP PVE 5.4.128-2 (Wed, 18 Aug 2021 16:20:02 +0200) |x86_64 [Debian GNU/Linux|debian: 10 (buster)] - Wazuh v4.2.5 / ab73af41699f13fdd81903b5f23d8d00
1715fb875296f5082db84216d4a850f8 merged.mg
#"_agent_ip":192.168.1.20
'
2022/01/20 08:05:43 wazuh-remoted[1809] state.c:59 at rem_write_state(): DEBUG: Updating state file.
2022/01/20 08:05:48 wazuh-remoted[1809] secure.c:314 at rem_keyupdate_main(): DEBUG: Checking for keys file changes.
2022/01/20 08:05:48 wazuh-remoted[1809] state.c:59 at rem_write_state(): DEBUG: Updating state file.
2022/01/20 08:05:48 wazuh-remoted[1809] manager.c:677 at c_files(): DEBUG: Updating shared files sums.
2022/01/20 08:05:48 wazuh-remoted[1809] manager.c:912 at c_files(): DEBUG: End updating shared files sums.
2022/01/20 08:05:52 wazuh-remoted[1809] secure.c:521 at HandleSecureMessage(): DEBUG: TCP socket 11 already in keystore. Updating...
2022/01/20 08:05:52 wazuh-remoted[1809] manager.c:242 at save_controlmsg(): DEBUG: save_controlmsg(): inserting 'Linux |cible |5.4.128-1-pve |#1 SMP PVE 5.4.128-2 (Wed, 18 Aug 2021 16:20:02 +0200) |x86_64 [Debian GNU/Linux|debian: 10 (buster)] - Wazuh v4.2.5 / ab73af41699f13fdd81903b5f23d8d00
1715fb875296f5082db84216d4a850f8 merged.mg
#"_agent_ip":192.168.1.20

​

Nothing ...

- alert.log :

root@wazuh-manager:~# tail -f /var/ossec/logs/alerts/alerts.log     
Src IP: 192.168.1.17
Jan 20 08:05:42 cible sshd[992]: Failed password for invalid user user from 192.168.x.x port 58816 ssh2

** Alert 1642666016.2126: mail  - local,syslog,sshd,invalid_login,authentication_failed,pci_dss_10.2.4,pci_dss_10.2.5,pci_dss_10.6.1,gpg13_7.1,gdpr_IV_35.7.d,gdpr_IV_32.2,hipaa_164.312.b,nist_800_53_AU.14,nist_800_53_AC.7,nist_800_53_AU.6,tsc_CC6.1,tsc_CC6.8,tsc_CC7.2,tsc_CC7.3,
2022 Jan 20 08:06:56 (cible) 192.168.1.20->/var/log/auth.log
Rule: 5710 (level 13) -> 'sshd: Attempt to login using a non-existent user'
Src IP: 192.168.1.17
Src Port: 59172
Jan 20 08:06:54 cible sshd[994]: Invalid user user from 192.168.x.xport 59172

​

Regards.

[victor....@wazuh.com]

Reviewing your archives.log

2022 Jan 20 08:06:55 (cible) 192.168.1.20->/var/log/auth.log Jan 20 08:06:54 cible sshd[992]: Connection closed by invalid user user 192.168.x.x port 58816 [preauth]

And your alert.log

...
2022 Jan 20 08:06:56 (cible) 192.168.1.20->/var/log/auth.log
Rule: 5710 (level 13) -> 'sshd: Attempt to login using a non-existent user'
Src IP: 192.168.1.17
Src Port: 59172
Jan 20 08:06:54 cible sshd[994]: Invalid user user from 192.168.x.xport 59172

It seems that the event is coming from your agent cible. The file shown in your alerts is relative to the agent in which your alerts occur. Please, if you are generating the failed ssh login attempt in an agent, ensure the event is placed in the agent file /var/log/auth.log. If that is not the case, follow the steps specified in my last message https://groups.google.com/g/wazuh/c/Q-H4oiQRD-c/m/_EZgWbfZAQAJ  in your agent and send back your ossec.log

​

[Cyprien Chapelle]

Ok, indeed sorry I send the ssh alert to another agent, not the one located on the wazuh-manager machine. So now I have my ssh alert in /var/log/auth.log !

So I did some tests.

Here is the content of : /var/ossec/etc/rules/local_rules.xml

<group name="local,syslog,sshd,">
  <rule id="5710" level="13" overwrite="yes">
    <if_sid>5700</if_sid>
    <match>illegal user|invalid user</match>
    <description>sshd: Attempt to login using a non-existent user</description>

<group>invalid_login,authentication_failed,pci_dss_10.2.4,pci_dss_10.2.5,pci_dss_10.6.1,gpg13_7.1,gdpr_IV_35.7.d,gdpr_IV_32.2,hipaa_164.312.b,nist_800_53_AU.14,nist$
    <mitre>
      <id>T1110</id>
    </mitre>
  </rule>

<rule id="100010" level="13">
  <match>test</match>
  <description>Testing active_response</description>
</rule>
</group>

If I do : echo "Nov 8 11:16:26 centos-manager1 sshd[20046]: test from 172.17.1.1 port 39588" >> /var/log/auth.log

Active response work, and the same for : echo "Nov 8 11:16:26 centos-manager1 sshd[20046]: invalid user from 172.17.1.1 port 39588" >> /var/log/auth.log

but with ssh alert it doesn’t work, the alert received is like this :

** Alert 1642779185.36837: mail  - local,syslog,sshd,invalid_login,authentication_failed,pci_dss_10.2.4,pci_dss_10.2.5,pci_dss_10.6.1,gpg13_7.1,gdpr_IV_35.7.d,gdpr_IV_32.2,hipaa_164.312.b,nist_800_53_AU.14,nist_800_53_AC.7,nist_800_53_AU.6,tsc_CC6.1,tsc_CC6.8,tsc_CC7.2,tsc_CC7.3,
2022 Jan 21 15:33:05 wazuh-manager->/var/log/auth.log
Rule: 5710 (level 13) -> 'sshd: Attempt to login using a non-existent user'
Src IP: 192.168.1.17
Src Port: 36752
Jan 21 15:33:05 wazuh-manager sshd[7976]: Invalid user test from 192.168.1.17 port 36752

And if I do: echo "Nov 8 11:16:26 centos-manager1 sshd[20046]: test anUser from 172.17.1.1 port 39588" >> /var/log/auth.log

It doesn’t work ! So this is because of the syntxate of the sent alert, how to fix this?

​

[victor....@wazuh.com]

It looks that now your AR module is working correctly, but there are some troubles with your ruleset. Let’s take a look.
In these situations, I strongly recommend using the wazuh-logtest tool. This will help us to know how the events are decoded:

Using your custom rules we run the wazuh-logtest for all your events:

• Nov 8 11:16:26 centos-manager1 sshd[20046]: test from 172.17.1.1 port 39588

**Phase 1: Completed pre-decoding.
    full event: 'Nov  8 11:16:26 centos-manager1 sshd[20046]: test from 172.17.1.1 port 39588'
    timestamp: 'Nov  8 11:16:26'
    hostname: 'centos-manager1'
    program_name: 'sshd'

**Phase 2: Completed decoding.
    name: 'sshd'

**Phase 3: Completed filtering (rules).
    id: '100010'
    level: '13'
    description: 'Testing active_response'
    groups: '['local', 'syslog', 'sshd']'
    firedtimes: '1'
    mail: 'True'
**Alert to be generated.

We can see that your custom rule 100010 has been triggered, however, this will never trigger your firewall-drop AR correctly, due to it is required the decoded srcip value. Also, this maybe is not the best syntax due to this will trigger any event containing the word test, for example:

Jan 24 08:24:56 AR test 

**Phase 1: Completed pre-decoding.
    full event: 'Jan 24 08:24:56 AR test '
    timestamp: 'Jan 24 08:24:56'
    hostname: 'AR'

**Phase 2: Completed decoding.
    No decoder matched.

**Phase 3: Completed filtering (rules).
    id: '100010'
    level: '13'
    description: 'Testing active_response'
    groups: '['local', 'syslog', 'sshd']'
    firedtimes: '2'
    mail: 'True'
**Alert to be generated.

If this rule is triggered after configuring AR for it, this will be the expected behavior.

2022/01/24 08:58:59 active-response/bin/firewall-drop: {"version":1,"origin":{"name":"node01","module":"wazuh-execd"},"command":"add","parameters":{"extra_args":[],"alert":{"timestamp":"2022-01-24T08:58:59.416+0000","rule":{"level":13,"description":"Testing active_response","id":"100010","firedtimes":1,"mail":true,"groups":["local","syslog","sshd"]},"agent":{"id":"000","name":"centos-manager2"},"manager":{"name":"centos-manager2"},"id":"1643014739.623530","full_log":"test example","decoder":{},"location":"/var/log/secure"},"program":"active-response/bin/firewall-drop"}}

2022/01/24 08:58:59 active-response/bin/firewall-drop: Cannot read 'srcip' from data

• Nov 8 11:16:26 centos-manager1 sshd[20046]: invalid user from 172.17.1.1 port 39588

**Phase 1: Completed pre-decoding.
    full event: 'Nov  8 11:16:26 centos-manager1 sshd[20046]: invalid user from 172.17.1.1 port 39588'
    timestamp: 'Nov  8 11:16:26'
    hostname: 'centos-manager1'
    program_name: 'sshd'

**Phase 2: Completed decoding.
    name: 'sshd'
    parent: 'sshd'
    srcport: '39588'

**Phase 3: Completed filtering (rules).
    id: '5710'
    level: '13'
    description: 'sshd: Attempt to login using a non-existent user'
    groups: '['local', 'syslog', 'sshd', 'invalid_login', 'authentication_failed', 'nist$']'
    firedtimes: '1'

If we use this event, 5710 will trigger. However, the event was not the expected due to srcip it is not being decoded (again, this will produce your AR does not work). If we check the event and we compare it with the generated for ssh:

Jan 24 08:24:56 centos-manager2 sshd[8823]: Invalid user invalid-user from 172.17.1.1 port 47916
Nov  8 11:16:26 centos-manager1 sshd[20046]: invalid user from 172.17.1.1 port 39588

The event has not included the invalid-user. If we use the correct syntax:

**Phase 1: Completed pre-decoding.
    full event: 'Nov  8 11:16:26 centos-manager1 sshd[20046]: invalid user invalid-user from 172.17.1.1 port 39588'
    timestamp: 'Nov  8 11:16:26'
    hostname: 'centos-manager1'
    program_name: 'sshd'

**Phase 2: Completed decoding.
    name: 'sshd'
    parent: 'sshd'
    srcip: '172.17.1.1'
    srcport: '39588'
    srcuser: 'invalid-user'

**Phase 3: Completed filtering (rules).
    id: '5710'
    level: '13'
    description: 'sshd: Attempt to login using a non-existent user'

The srcip is correctly decoded, and AR is working.

Also, take in mind that an overwrite rule can not contain if_sid, if_group or if_level https://github.com/wazuh/wazuh/pull/8210. In wazuh 4.3 this will not be allowed.

If you have any doubt about how to overwrite a custom rule with if_sidtaking in mind this limitation, I recommend you this approach https://github.com/wazuh/wazuh/issues/11596#issuecomment-1002630602

Also, I recommend you change the 100010 rule. If you specified what do you expect to alert we can help you with your custom rules.

Let me know if this solves your questions. Send back your logs and outputs if some of the logs are not the expected.

​

[Cyprien Chapelle]

Hello, thank you for your message.

Sorry but I block from the first line, I have this error message when I send an alert to logtest : (debug mode)

2022-01-24 09:39:00,687 wazuh-logtest[ERROR] ** Wazuh-logtest error when connecting with wazuh-analysisd

​

[Cyprien Chapelle]

Ok, I tested the configuration on another machine, it works. So I have a problem with the current wazuh. This may just be due to the error I cited above... I don't know

[Cyprien Chapelle]

So I uninstalled wazuh, then reinstalled. It works, however it annoys me that I didn't find the error, I hope it won't happen again!

Thank you very much for the time you gave me, you are a great team !