QA » openQA Project » openQA Infrastructure

It happened again. I've been adding a silence now.

The alert was triggered again and my silence didn't work. I don't know why. It matches the alert exactly and it is really always the same alert.

Now using the rule_uid in the silence. Maybe it works better but I doubt it.

please be aware about my MR https://gitlab.suse.de/openqa/salt-states-openqa/-/merge_requests/844 to handle NoData gracefully also affecting the alert mentioned here.

In the data i'm not seeing an obvious connection to #127985, there is very little overlap between the no data events. It appears much more random in the other ticket.

My idea based on your suggestions: https://github.com/os-autoinst/openQA/pull/5092

EDIT: 2023-04-25: Created https://gitlab.suse.de/openqa/salt-states-openqa/-/merge_requests/849 to use the lightweight "/health" check

okurz wrote:

My idea based on your suggestions: https://github.com/os-autoinst/openQA/pull/5092

For context, i noticed that our workers are DDoS-ing the OSD webui a little bit by requesting /changelog for monitoring, that PR is a solution:

**IP_ADDRESS1** - - [21/Apr/2023:00:50:00 +0200] "GET /changelog HTTP/1.1" 200 134226 "-" "Go-http-client/1.1" 1639
**IP_ADDRESS2** - - [21/Apr/2023:00:50:00 +0200] "GET /changelog HTTP/1.1" 200 134227 "-" "Go-http-client/1.1" 1784
**IP_ADDRESS3** - - [21/Apr/2023:00:50:00 +0200] "GET /changelog HTTP/1.1" 200 134227 "-" "Go-http-client/1.1" 1913
**IP_ADDRESS4** - - [21/Apr/2023:00:50:00 +0200] "GET /changelog HTTP/1.1" 200 134226 "-" "Go-http-client/1.1" 2010
**IP_ADDRESS5** - - [21/Apr/2023:00:50:00 +0200] "GET /changelog HTTP/1.1" 200 134226 "-" "Go-http-client/1.1" 2010
...

The request frequency seems a bit too low to be the cause for this ticket though, despite the response size. So i'll keep looking for more in the Apache logs.

It looks like this might have started with the switch from inputs.logparser to inputs.tail. Because the data before the change has no holes. https://gitlab.suse.de/openqa/salt-states-openqa/-/commit/c4e978078c285f5712265347889057ff32ab9bfe

Actually, i think it might have started with this change for Apache log rotate the day before: https://gitlab.suse.de/openqa/salt-states-openqa/-/commit/659769de466389a844c77f1a4023bd2dc449a092

Also worth mentioning that there does not appear to be any data missing in the rotated logs. There's countless requests logged during the time influxdb has no data. And the logrotate config already uses copytruncate, which would seem like the correct mode for telegraf inputs.tail. Wonder what else there is that we could try.

https://gitlab.suse.de/openqa/salt-states-openqa/-/merge_requests/849

okurz wrote:

salt-key -y -d openqa.suse.de
sed -i 's/^./#&/' /etc/logrotate.d/openqa-apache

And reverted.

Now we are going to need ideas for what to change in the logrotate config, theoretically copytruncate should have been correct for our use case:

/var/log/apache2/openqa.access_log {
    compress
    hourly
    maxage 30
    rotate 20
    size=+300000k
    notifempty
    missingok
    copytruncate
    compresscmd /usr/bin/xz
    uncompresscmd /usr/bin/xzdec
}

There's also a few options to try for the telegraf config:

[[inputs.tail]]
  files = ["/var/log/apache2/openqa.access_log"]
  interval = "30s"
  from_beginning = false
  name_override = "apache_log"
  ## For parsing logstash-style "grok" patterns:
  data_format = "grok"
  grok_patterns = ["%{CUSTOM_LOG}"]
  grok_custom_pattern_files = []
  grok_custom_patterns = '''
      CUSTOM_LOG %{COMBINED_LOG_FORMAT} %{NUMBER:response_time_us:int}
  '''

For example we could try changing the watch method, which defaults to inotify:

  ## Method used to watch for file updates.  Can be either "inotify" or "poll".
  # watch_method = "inotify"

I added another silence lasting over the weekend. I can't really tell if the missing series was a problem (wrongly calculated values therefore) or if me need to adjust the alert too. For now it is a good idea anyway to wait for stable metrics before adjusting the alert.