Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Logs display incorrect #27485

Open
kouled opened this issue Jan 2, 2025 · 6 comments · May be fixed by #28047
Open

Logs display incorrect #27485

kouled opened this issue Jan 2, 2025 · 6 comments · May be fixed by #28047

Comments

@kouled
Copy link

kouled commented Jan 2, 2025

Wazuh version Component Install type Install method Platform
v4.9.2 Wazuh Manager/Dashboard Packages Ubuntu 22.04

The time on my Wazuh server:
Image

The setting on the Dashboard server (colocated on the same Wazuh server):
Image

And the time of the logs on the dashboard server:
Image

the time is clearly incorrect in this view: Server management > Logs. --> It show time in the future for log should be in the past....

Many thanks for resolving this issue this look like and old behavior: Logger displaying incorrect time #12679

#timezone #Dashboard #Logs

@daniel-pixelgrube
Copy link

I can confirm this issue on Wazuh 4.9.2 (Dashboard, Manager, Indexer on seperated machines - OS: Ubuntu24.04) and a Allonone-Wazuh-Server 4.7.4 (OS: Ubuntu 22.04).

Dashbord and Management server shows the same time and time zone:

wazdash1:~$ timedatectl
Local time: Wed 2025-01-08 16:37:56 CET
Universal time: Wed 2025-01-08 15:37:56 UTC
RTC time: Wed 2025-01-08 15:37:56
Time zone: Europe/Berlin (CET, +0100)
System clock synchronized: yes
NTP service: active
RTC in local TZ: no

wazmasterman:~$ timedatectl
Local time: Wed 2025-01-08 16:38:12 CET
Universal time: Wed 2025-01-08 15:38:12 UTC
RTC time: Wed 2025-01-08 15:38:12
Time zone: Europe/Berlin (CET, +0100)
System clock synchronized: yes
NTP service: active
RTC in local TZ: no

The ossec.log on the Wazuh Managament server shows the correct time:

2025/01/08 15:35:29 wazuh-modulesd:vulnerability-scanner: INFO: Vulnerability scanner module started.
2025/01/08 15:35:56 rootcheck: INFO: Ending rootcheck scan.
2025/01/08 16:20:48 wazuh-analysisd: WARNING: Rootcheck decoder queue is full.

But the WUI log viewer shows the time plus one hour in the future:

Image

Timezone for date formatting on the WUI is configured with browser:

Image

I changed this value to Europe/Berlin but it did not fix the problem.

@kouled
Copy link
Author

kouled commented Jan 14, 2025

For a tool where the timestamp is very important getting wrong data displayed is not good

So I'm not alone :-D

@Desvelao
Copy link
Member

Desvelao commented Jan 22, 2025

Analysis

The dateFormat:tz setting of the Wazuh dashboard indicates how to format the dates related to Wazuh indexer documents (Wazuh alerts, Wazuh archives, Wazuh statistics, Wazuh monitoring data) and this value is used too to format the dates coming from Wazuh server API responses.

Note: the settings of Dashboard management > Dashboard Management > Advanced settings are related to the selected tenant (if multitenancy is enabled) or the default tenant (if multitenancy is disabled), this means you can configure different values for the same setting depeding on the selected tenant. Set the dateFormat:tz setting defines how to format the date to the selected timezone. For example, if this is set to Browser, depending on the timezone set in the browser, you can see a different value if comparing with a browser with another timezone, this allows to users with different browser timezone can see the dates according to his timezone.

I was doing some tests:

  • Wazuh stack 4.9.2

Wazuh server timezone: UTC0 and dateFormat:tz sets to Europe/Berlin

# date "+%H:%M %Z%z"
11:03 UTC+0000
# tail -n3 /var/ossec/logs/ossec.log 
2025/01/22 10:30:02 wazuh-modulesd:vulnerability-scanner: INFO: Database decompression finished.
2025/01/22 10:30:15 wazuh-modulesd:vulnerability-scanner: INFO: Vulnerability scanner module started.
2025/01/22 10:50:48 wazuh-modulesd:vulnerability-scanner: INFO: Initiating update feed process

Fetching manager logs through Wazuh server API sorted in descendant order by the timestamp field:

GET /manager/logs?sort=-timestamp&limit=5

This request is done when Wazuh server cluster mode is disabled. If the cluster mode is enabled, this uses /cluster/{wazuh-server-node}/logs where {wazuh-server-node} is the selected Wazuh server node in the UI of Server management > Logs application.

You can run this request through the Server management > Dev tools

Response:

{
  "data": {
    "affected_items": [
      {
        "timestamp": "2025-01-22T10:50:48Z",
        "tag": "wazuh-modulesd:vulnerability-scanner",
        "level": "info",
        "description": " Initiating update feed process."
      },
      {
        "timestamp": "2025-01-22T10:30:15Z",
        "tag": "wazuh-modulesd:vulnerability-scanner",
        "level": "info",
        "description": " Vulnerability scanner module started."
      },
      {
        "timestamp": "2025-01-22T10:30:02Z",
        "tag": "wazuh-modulesd:vulnerability-scanner",
        "level": "info",
        "description": " Database decompression finished."
      },
      {
        "timestamp": "2025-01-22T10:29:07Z",
        "tag": "indexer-connector",
        "level": "info",
        "description": " IndexerConnector initialized successfully for index: wazuh-states-vulnerabilities-wazuh.manager."
      },
      {
        "timestamp": "2025-01-22T10:28:01Z",
        "tag": "wazuh-rootcheck",
        "level": "info",
        "description": " Ending rootcheck scan."
      }
    ],
    "total_affected_items": 80,
    "total_failed_items": 0,
    "failed_items": []
  },
  "message": "Logs were successfully read",
  "error": 0
}

In the Wazuh server API response, the timestamp field has no information about the timezone (after Z) so this is supposed to set in UTC0.

In the Wazuh dashboard, go to Dashboard management > Logs and you can see the events has +1 hour related as expected to the Europe/Berlin timezone set in the dateFormat:tz:

Image

Wazuh server timezone: Europe/Berlin and dateFormat:tz sets to Europe/Berlin

# date "+%H:%M %Z%z"
12:20 CET+0100
# tail -n3 /var/ossec/logs/ossec.log 
2025/01/22 12:18:46 sca: INFO: Security Configuration Assessment scan finished. Duration: 7 seconds.
2025/01/22 12:19:02 rootcheck: INFO: Ending rootcheck scan.
2025/01/22 12:20:48 indexer-connector: INFO: IndexerConnector initialized successfully for index: wazuh-states-vulnerabilities-wazuh.manager.

The logs in the Wazuh server logs seems to use the timezone of the host.

Fetching manager logs through Wazuh server API sorted in descendant order by the timestamp field:

GET /manager/logs?sort=-timestamp&limit=5

This request is done when Wazuh server cluster mode is disabled. If the cluster mode is enabled, this uses /cluster/{wazuh-server-node}/logs where {wazuh-server-node} is the selected Wazuh server node in the UI of Server management > Logs application.

You can run this request through the Server management > Dev tools

Response:

{
  "data": {
    "affected_items": [
      {
        "timestamp": "2025-01-22T12:20:48Z",
        "tag": "indexer-connector",
        "level": "info",
        "description": " IndexerConnector initialized successfully for index: wazuh-states-vulnerabilities-wazuh.manager."
      },
      {
        "timestamp": "2025-01-22T12:19:02Z",
        "tag": "wazuh-rootcheck",
        "level": "info",
        "description": " Ending rootcheck scan."
      },
      {
        "timestamp": "2025-01-22T12:18:46Z",
        "tag": "sca",
        "level": "info",
        "description": " Evaluation finished for policy '/var/ossec/ruleset/sca/cis_amazon_linux_2023.yml'"
      },
      {
        "timestamp": "2025-01-22T12:18:46Z",
        "tag": "sca",
        "level": "info",
        "description": " Security Configuration Assessment scan finished. Duration: 7 seconds."
      },
      {
        "timestamp": "2025-01-22T12:18:39Z",
        "tag": "wazuh-modulesd:router",
        "level": "info",
        "description": " Loaded router module."
      }
    ],
    "total_affected_items": 77,
    "total_failed_items": 0,
    "failed_items": []
  },
  "message": "Logs were successfully read",
  "error": 0
}

In the Wazuh server API response, the timestamp field has no information about the timezone (after Z) and this should include it because it is set to Europe/Berlin that is different to UTC0. I think the problem is located here. If the timestamp field included the timezone, I guess the date formatter of Server management > Logs of Wazuh dashboard could format the date correctly. With the current retrieved values of the timestamp, the date formatter of Server management > Logs interprets the value is set to UTC0 that could cause to display a wrong date applying the Wazuh dashboard timezone (dateFormat:tz).

In the Wazuh dashboard, go to Dashboard management > Logs and you can see the events has +1 hour (timestamp difference from the retrieved data) and it is not expected to the Europe/Berlin timezone set in the dateFormat:tz:

Image

Conclusion

If the timezone of the Wazuh server host is different to UTC0, this will cause the dates in the Wazuh server logs (/var/ossec/logs/ossec.log) and the response of this data through the Wazuh API have dates(hour, miinutes, etc..) in the selected timezone. The problem is located that the timestamp of the logs retrieved through the Wazuh API has no information about the timezone, returning a date in UTC despite this could be related to a diferent timezone. So if in the Wazuh dashboard, the dateFormat:tz setting is set to a value that increase or decrease the UTC0, for example Europe/Berlin (UTC+1), this could cause the date is represented with UTC +2.

For example, if the Wazuh server timezone is Europe/Berlin (UTC +1), the response of the timestamp field from the Wazuh server API returns the date such as 2025-01-22T12:20:48Z (note the timezone is not defined so this value represents a date in UTC0) but the hour/minutes are represented in the defined timezone (UTC+1), this means the date in UTC0 should be 2025-01-22T11:20:48Z. Then in the Wazuh dashboard, assuming the dateFormat:tz is set to Europe/Berlin the retrieved date (2025-01-22T12:20:48Z) adds the timezone difference (UTC0 againts UTC+1 Europe/Beling resulting in +1), resulting in 2025-01-22T13:20:48Z that is not the expected value.

@JuanGarriuz
Copy link
Member

JuanGarriuz commented Jan 29, 2025

Research

Adding to the investigation, the API returns the information with the manager's local date but falsifies the time zone, causing the dashboard, when trying to format the date to the corresponding time zone, to reformat it based on the date returned by the manager.

In these code snippets, the mentioned behavior can be observed:

..../user/wazuh/framework/wazuh/core/manager.py

Here it mentions that the timestamp is sent in UTC format (referring to +0) and formatted according to this DATE_FORMAT value:
DATE_FORMAT: Literal['%Y-%m-%dT%H:%M:%SZ']

The timezone is not included.

log_fields = get_ossec_log_fields(line, log_format=log_format)
        if log_fields:
            date, tag, level, description = log_fields

            # We transform local time (ossec.log) to UTC with ISO8601 maintaining time integrity
            log_line = {'timestamp': date.strftime(common.DATE_FORMAT), 'tag': tag,
                        'level': level, 'description': description}

..../user/wazuh/framework/wazuh/core/utils.py

This is where the timezone is replaced, but the date remains based on the local timezone, not UTC +0.

def get_utc_strptime(date: str, datetime_format: str) -> datetime:
    """Function to transform str to date.

    Parameters
    ----------
    date: str
        String to be transformed.
    datetime_format: str
        Datetime pattern.

    Returns
    -------
    date: datetime
        The current date.
    """
    return datetime.strptime(date, datetime_format).replace(tzinfo=timezone.utc)

plugins/main/public/react-services/time-service.js

In the dashboard repository, we added the date formatting as expected. By doing this, the date is formatted twice: first by the API and then by the Dashboard.

export const formatUIDate = date => {
  if (typeof date !== 'string') {
    return '-';
  }
  const dateFormat = getUiSettings().get('dateFormat');
  const timezone = getTimeZone();
  const momentDate = moment(date);
  momentDate.tz(timezone);
  return momentDate.format(dateFormat);
};
const getTimeZone = () => {
  const dateFormatTZ = getUiSettings().get('dateFormat:tz');
  const detectedTimezone = moment.tz.guess();
  return dateFormatTZ === 'Browser' ? detectedTimezone : dateFormatTZ;
};

A possible solution would be to include the time zone formatting value or the actual UTC+0 value in the API response.

@wazuhci wazuhci moved this to Backlog in XDR+SIEM/Release 4.12.0 Feb 4, 2025
@GGP1 GGP1 self-assigned this Feb 5, 2025
@GGP1 GGP1 linked a pull request Feb 5, 2025 that will close this issue
@GGP1 GGP1 linked a pull request Feb 5, 2025 that will close this issue
@GGP1
Copy link
Member

GGP1 commented Feb 5, 2025

Update

Converted the timestamps to UTC so the dashboard receives them always in the same timezone.

@wazuhci wazuhci moved this from Backlog to In progress in XDR+SIEM/Release 4.12.0 Feb 5, 2025
@GGP1
Copy link
Member

GGP1 commented Feb 6, 2025

Update

Tested the changes using a timezone in America/New_York and verified that the logs were displayed using UTC time.

@wazuhci wazuhci moved this from In progress to Pending review in XDR+SIEM/Release 4.12.0 Feb 6, 2025
@wazuhci wazuhci moved this from Pending review to In review in XDR+SIEM/Release 4.12.0 Feb 6, 2025
@wazuhci wazuhci moved this from In review to Pending final review in XDR+SIEM/Release 4.12.0 Feb 6, 2025
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
Status: Pending final review
Development

Successfully merging a pull request may close this issue.

7 participants