Test that Added plus symbol to macOS ULS timestamp works

72nomada commented 1 year ago

Target version	Related issue	Related PR
4.4.2	https://github.com/wazuh/wazuh/issues/15669	https://github.com/wazuh/wazuh/pull/16530

Description

Added support in analysisd to decode timestamps with the '+' symbol typically used in macOS logs timestamp.

Proposed checks

[ ] use an ini content like this:

  [plus symbol on timestamp]
  log 1 pass = 2023-04-13 22:02:51.837266+0200  localhost loginwindow[164]: [com.apple.loginwindow.logging:Standard] -[SessionAgentNotificationCenter sendBSDNotification:forUserID:] | sendBSDNotification: com.apple.sessionagent.screenIsLocked, with userID:501
  rule = 89609
  alert = 3
  decoder = macOS_loginwindow

Expected results

when using a log line like the one in the test, an alert should be generated like this

      #wazuh-logtest
      Starting wazuh-logtest v4.6.0
      Type one log per line

      2022-12-13 14:19:30.429319+0200  localhost sshd[1115]: Failed password for invalid user hacker from 192.168.56.1 port 50384 ssh2

      **Phase 1: Completed pre-decoding.
          full event: '2022-12-13 14:19:30.429319+0200  localhost sshd[1115]: Failed password for invalid user hacker from 192.168.56.1 port 50384 ssh2'
          timestamp: '2022-12-13 14:19:30.429319+0200'
          program_name: 'sshd'

      **Phase 2: Completed decoding.
          name: 'sshd'
          parent: 'sshd'
          srcip: '192.168.56.1'
          srcuser: 'hacker'

      **Phase 3: Completed filtering (rules).
          id: '5710'
          level: '5'
          description: 'sshd: Attempt to login using a non-existent user'
          groups: '['syslog', 'sshd', 'authentication_failed', 'invalid_login']'
          firedtimes: '1'
          gdpr: '['IV_35.7.d', 'IV_32.2']'
          gpg13: '['7.1']'
          hipaa: '['164.312.b']'
          mail: 'False'
          mitre.id: '['T1110.001', 'T1021.004', 'T1078']'
          mitre.tactic: '['Credential Access', 'Lateral Movement', 'Defense Evasion', 'Persistence', 'Privilege Escalation', 'Initial Access']'
          mitre.technique: '['Password Guessing', 'SSH', 'Valid Accounts']'
          nist_800_53: '['AU.14', 'AC.7', 'AU.6']'
          pci_dss: '['10.2.4', '10.2.5', '10.6.1']'
          tsc: '['CC6.1', 'CC6.8', 'CC7.2', 'CC7.3']'
      **Alert to be generated.

Rebits commented 1 year ago

Tester review

Tester	PR commit
@Rebits	https://github.com/wazuh/wazuh/pull/16530/commits/ae4be0992921cdd4a0f52e73c687b0cebdc45560

Testing environment

OS	OS version	Deployment	Image/AMI	Notes
Ubuntu	Ubuntu 20.04	EC2	ami-003530de8839921c4

Tested packages

`wazuh-manager`	`wazuh-agent`
wazuh-manager	wazuh-agent

Status

[x] In progress
[x] Pending Review
[x] QA Manager approved (@juliamagan)
[x] Development team leader approved (@72nomada)

Conclusion :green_circle:

ULS macOS events with positive timezone are now correctly parsed.

Rebits commented 1 year ago

Testing results :green_circle:

Replicate detected issue

In a manager 4.4.1, ULS events with positive timestamp are not parsed correectly ``` 2023-04-18 11:58:10.591934+0200 localhost findmydeviced[249]: [com.apple.icloud.findmydeviced:_] UCRT state - [3]. Error getting UCRT state - (null) **Phase 1: Completed pre-decoding. full event: '2023-04-18 11:58:10.591934+0200 localhost findmydeviced[249]: [com.apple.icloud.findmydeviced:_] UCRT state - [3]. Error getting UCRT state - (null)' **Phase 2: Completed decoding. No decoder matched. **Phase 3: Completed filtering (rules). id: '1002' level: '2' description: 'Unknown problem somewhere in the system.' groups: '['syslog', 'errors']' firedtimes: '1' gpg13: '['4.3']' mail: 'False' ``` No timestamp field was parsed.

Preconditions

No errors detected during the installation process

macOS Agent
``` sh-3.2# launchctl setenv WAZUH_MANAGER "192.168.10.120" && installer -pkg wazuh-agent-4.4.2-0.commitae4be09.pkg -target / installer: Package name is Wazuh Agent installer: Installing at base path / installer: The install was successful. ```

Manager
``` Transaction test succeeded Running transaction Instalando : wazuh-manager-4.4.2-0.commitae4be09. [######################### ] 1/1 Instalando : wazuh-manager-4.4.2-0.commitae4be09.x86_64 1/1 Comprobando : wazuh-manager-4.4.2-0.commitae4be09.x86_64 1/1 Instalado: wazuh-manager.x86_64 0:4.4.2-0.commitae4be09 ¡Listo! ```

Check positive timestamp events are correctly parsed :green_circle:

Suggested developers events :green_circle:
- `2022-12-13 14:19:30.429319+0200 localhost sshd[1115]: Failed password for invalid user hacker from 192.168.56.1 port 50384 ssh2` ``` 2022-12-13 14:19:30.429319+0200 localhost sshd[1115]: Failed password for invalid user hacker from 192.168.56.1 port 50384 ssh2 **Phase 1: Completed pre-decoding. full event: '2022-12-13 14:19:30.429319+0200 localhost sshd[1115]: Failed password for invalid user hacker from 192.168.56.1 port 50384 ssh2' timestamp: '2022-12-13 14:19:30.429319+0200' program_name: 'sshd' **Phase 2: Completed decoding. name: 'sshd' parent: 'sshd' srcip: '192.168.56.1' srcuser: 'hacker' **Phase 3: Completed filtering (rules). id: '5710' level: '5' description: 'sshd: Attempt to login using a non-existent user' groups: '['syslog', 'sshd', 'authentication_failed', 'invalid_login']' firedtimes: '2' gdpr: '['IV_35.7.d', 'IV_32.2']' gpg13: '['7.1']' hipaa: '['164.312.b']' mail: 'False' mitre.id: '['T1110.001', 'T1021.004', 'T1078']' mitre.tactic: '['Credential Access', 'Lateral Movement', 'Defense Evasion', 'Persistence', 'Privilege Escalation', 'Initial Access']' mitre.technique: '['Password Guessing', 'SSH', 'Valid Accounts']' nist_800_53: '['AU.14', 'AC.7', 'AU.6']' pci_dss: '['10.2.4', '10.2.5', '10.6.1']' tsc: '['CC6.1', 'CC6.8', 'CC7.2', 'CC7.3']' **Alert to be generated. ``` - `2023-04-13 22:02:51.837266+0200 localhost loginwindow[164]: [com.apple.loginwindow.logging:Standard] -[SessionAgentNotificationCenter sendBSDNotification:forUserID:] | sendBSDNotification: com.apple.sessionagent.screenIsLocked, with userID:501` ``` 2023-04-13 22:02:51.837266+0200 localhost loginwindow[164]: [com.apple.loginwindow.logging:Standard] -[SessionAgentNotificationCenter sendBSDNotification:forUserID:] | sendBSDNotification: com.apple.sessionagent.screenIsLocked, with userID:501 **Phase 1: Completed pre-decoding. full event: '2023-04-13 22:02:51.837266+0200 localhost loginwindow[164]: [com.apple.loginwindow.logging:Standard] -[SessionAgentNotificationCenter sendBSDNotification:forUserID:] | sendBSDNotification: com.apple.sessionagent.screenIsLocked, with userID:501' timestamp: '2023-04-13 22:02:51.837266+0200' program_name: 'loginwindow' **Phase 2: Completed decoding. No decoder matched. ```

Real ULS collected events :green_circle:
- `2023-04-18 11:58:10.591934+0200 localhost findmydeviced[249]: [com.apple.icloud.findmydeviced:_] UCRT state - [3]. Error getting UCRT state - (null)` ``` 2023-04-18 11:58:10.591934+0200 localhost findmydeviced[249]: [com.apple.icloud.findmydeviced:_] UCRT state - [3]. Error getting UCRT state - (null) **Phase 1: Completed pre-decoding. full event: '2023-04-18 11:58:10.591934+0200 localhost findmydeviced[249]: [com.apple.icloud.findmydeviced:_] UCRT state - [3]. Error getting UCRT state - (null)' timestamp: '2023-04-18 11:58:10.591934+0200' program_name: 'findmydeviced' **Phase 2: Completed decoding. No decoder matched. **Phase 3: Completed filtering (rules). id: '1002' level: '2' description: 'Unknown problem somewhere in the system.' groups: '['syslog', 'errors']' firedtimes: '2' gpg13: '['4.3']' mail: 'False' ``` - `2023-04-13 22:02:51.837266+0200 localhost loginwindow[164]: [com.apple.loginwindow.logging:Standard] -[SessionAgentNotificationCenter sendBSDNotification:forUserID:] | sendBSDNotification: com.apple.sessionagent.screenIsLocked, with userID:501` ``` **Phase 1: Completed pre-decoding. full event: '2023-04-13 22:02:51.837266+0200 localhost loginwindow[164]: [com.apple.loginwindow.logging:Standard] -[SessionAgentNotificationCenter sendBSDNotification:forUserID:] | sendBSDNotification: com.apple.sessionagent.screenIsLocked, with userID:501' timestamp: '2023-04-13 22:02:51.837266+0200' program_name: 'loginwindow' **Phase 2: Completed decoding. No decoder matched. ```

Negative timezone events are parsed correctly :green_circle:

- `2023-04-12 01:36:42.792314-0700 localhost loginwindow[155]: [com.apple.loginwindow.logging:Standard] -[SessionAgentNotificationCenter sendBSDNotification:forUserID:] | sendBSDNotification: com.apple.sessionagent.screenIsLocked, with userID:501` - Negative time zone ``` 2023-04-12 01:36:42.792314-0700 localhost loginwindow[155]: [com.apple.loginwindow.logging:Standard] -[SessionAgentNotificationCenter sendBSDNotification:forUserID:] | sendBSDNotification: com.apple.sessionagent.screenIsLocked, with userID:501 **Phase 1: Completed pre-decoding. full event: '2023-04-12 01:36:42.792314-0700 localhost loginwindow[155]: [com.apple.loginwindow.logging:Standard] -[SessionAgentNotificationCenter sendBSDNotification:forUserID:] | sendBSDNotification: com.apple.sessionagent.screenIsLocked, with userID:501' timestamp: '2023-04-12 01:36:42.792314-0700' program_name: 'loginwindow' **Phase 2: Completed decoding. No decoder matched. ``` - `2023-04-13 22:02:51.837266-0200 localhost loginwindow[164]: [com.apple.loginwindow.logging:Standard] -[SessionAgentNotificationCenter sendBSDNotification:forUserID:] | sendBSDNotification: com.apple.sessionagent.screenIsLocked, with userID:501` ``` 2023-04-13 22:02:51.837266-0200 localhost loginwindow[164]: [com.apple.loginwindow.logging:Standard] -[SessionAgentNotificationCenter sendBSDNotification:forUserID:] | sendBSDNotification: com.apple.sessionagent.screenIsLocked, with userID:501 **Phase 1: Completed pre-decoding. full event: '2023-04-13 22:02:51.837266-0200 localhost loginwindow[164]: [com.apple.loginwindow.logging:Standard] -[SessionAgentNotificationCenter sendBSDNotification:forUserID:] | sendBSDNotification: com.apple.sessionagent.screenIsLocked, with userID:501' timestamp: '2023-04-13 22:02:51.837266-0200' program_name: 'loginwindow' **Phase 2: Completed decoding. No decoder matched. ```

Manager Upgrade :green_circle:

After the manager upgrade, ULS events with positive timezone are correctly parsed. ``` [root@localhost ~]# /var/ossec/bin/wazuh-logtest Starting wazuh-logtest v4.4.1 Type one log per line 2023-04-18 11:58:10.591934+0200 localhost findmydeviced[249]: [com.apple.icloud.findmydeviced:_] UCRT state - [3]. Error getting UCRT state - (null) **Phase 1: Completed pre-decoding. full event: '2023-04-18 11:58:10.591934+0200 localhost findmydeviced[249]: [com.apple.icloud.findmydeviced:_] UCRT state - [3]. Error getting UCRT state - (null)' **Phase 2: Completed decoding. No decoder matched. **Phase 3: Completed filtering (rules). id: '1002' level: '2' description: 'Unknown problem somewhere in the system.' groups: '['syslog', 'errors']' firedtimes: '1' gpg13: '['4.3']' mail: 'False' (reverse-i-search)`':]^C [root@localhost ~]# yum install ./wazuh-manager-4.4.2-0.commitae4be09.x86_64.rpm Complementos cargados:fastestmirror Examinando ./wazuh-manager-4.4.2-0.commitae4be09.x86_64.rpm: wazuh-manager-4.4.2-0.commitae4be09.x86_64 Marcando ./wazuh-manager-4.4.2-0.commitae4be09.x86_64.rpm como una actualización de wazuh-manager-4.4.1-1.x86_64 Resolviendo dependencias --> Ejecutando prueba de transacción ---> Paquete wazuh-manager.x86_64 0:4.4.1-1 debe ser actualizado ---> Paquete wazuh-manager.x86_64 0:4.4.2-0.commitae4be09 debe ser una actualización --> Resolución de dependencias finalizada Dependencias resueltas ================================================================================================== Package Arquitectura Versión Repositorio Tamaño ================================================================================================== Actualizando: wazuh-manager x86_64 4.4.2-0.commitae4be09 /wazuh-manager-4.4.2-0.commitae4be09.x86_64 450 M Resumen de la transacción ================================================================================================== Actualizar 1 Paquete Tamaño total: 450 M Is this ok [y/d/N]: y Downloading packages: Running transaction check Running transaction test Transaction test succeeded Running transaction Actualizando : wazuh-manager-4.4.2-0.commitae4be09. [############################# ] 1/2 Actualizando : wazuh-manager-4.4.2-0.commitae4be09.x86_64 1/2 Limpieza : wazuh-manager-4.4.1-1.x86_64 2/2 Comprobando : wazuh-manager-4.4.2-0.commitae4be09.x86_64 1/2 Comprobando : wazuh-manager-4.4.1-1.x86_64 2/2 Actualizado: wazuh-manager.x86_64 0:4.4.2-0.commitae4be09 ¡Listo! [root@localhost ~]# [root@localhost ~]# [root@localhost ~]# [root@localhost ~]# [root@localhost ~]# [root@localhost ~]# systemctl restart wazuh-manager [root@localhost ~]# /var/ossec/bin/wazuh-logtest Starting wazuh-logtest v4.4.2 Type one log per line 2023-04-18 11:58:10.591934+0200 localhost findmydeviced[249]: [com.apple.icloud.findmydeviced:_] UCRT state - [3]. Error getting UCRT state - (null) **Phase 1: Completed pre-decoding. full event: '2023-04-18 11:58:10.591934+0200 localhost findmydeviced[249]: [com.apple.icloud.findmydeviced:_] UCRT state - [3]. Error getting UCRT state - (null)' timestamp: '2023-04-18 11:58:10.591934+0200' program_name: 'findmydeviced' **Phase 2: Completed decoding. No decoder matched. **Phase 3: Completed filtering (rules). id: '1002' level: '2' description: 'Unknown problem somewhere in the system.' groups: '['syslog', 'errors']' firedtimes: '1' gpg13: '['4.3']' mail: 'False' ```

Incorrect timestamp are not parsed :green_circle:

- Multiple + symbols ``` 2023-04-18 11:58:10.591934++0200 localhost findmydeviced[249]: [com.apple.icloud.findmydeviced:_] UCRT state - [3]. Error getting UCRT state - (null) **Phase 1: Completed pre-decoding. full event: '2023-04-18 11:58:10.591934++0200 localhost findmydeviced[249]: [com.apple.icloud.findmydeviced:_] UCRT state - [3]. Error getting UCRT state - (null)' **Phase 2: Completed decoding. No decoder matched. **Phase 3: Completed filtering (rules). id: '1002' level: '2' description: 'Unknown problem somewhere in the system.' groups: '['syslog', 'errors']' firedtimes: '3' gpg13: '['4.3']' mail: 'False' ``` - No + or - symbols ``` 2023-04-18 11:58:10.5919340200 localhost findmydeviced[249]: [com.apple.icloud.findmydeviced:_] UCRT state - [3]. Error getting UCRT state - (null) **Phase 1: Completed pre-decoding. full event: '2023-04-18 11:58:10.5919340200 localhost findmydeviced[249]: [com.apple.icloud.findmydeviced:_] UCRT state - [3]. Error getting UCRT state - (null)' **Phase 2: Completed decoding. No decoder matched. **Phase 3: Completed filtering (rules). id: '1002' level: '2' description: 'Unknown problem somewhere in the system.' groups: '['syslog', 'errors']' firedtimes: '2' gpg13: '['4.3']' mail: 'False' ```

juliamagan commented 1 year ago

Closing conclusion 👍🏼

Everything seems to be working properly

wazuh / wazuh-qa