Icinga2: API user permissions sometimes not applied

[nbuchwitz]

I was testing a TLS related issue with one of our Icinga 2 server and ran an API request for every 1/10 second. The API user is restricted to certain service groups and should only the object within the restrictions:

object ApiUser "some-api-user" {
  password = "some-password"

  permissions = [
    {
      permission = "objects/query/Service"
      filter = {{ "some-servicegroup" in service.groups }}
    },
    {
      permission = "objects/query/Service"
      filter = {{ "another-servicegroup" in service.groups }}
    }
  ]
}

While testing the results of my API request, I figured out that in some cases I get object which should be restricted by the permissions above. This seems to be related to the load I put on the API.

Expected Behavior

The configured restrictions should be applied for every request.

Current Behavior

In some cases the restrictions aren't applied.

Steps to Reproduce (for bugs)

1. Configure API user with permissions
2. Put some load on the API (e.g with watch -n 0.1 'curl ...')
3. Fetch object from API and verify restrictions

Your Environment

• Version used (icinga2 --version): 2.10.2
• Operating System and version: CentOS 7
• Enabled features (icinga2 feature list):

Disabled features: command compatlog debuglog elasticsearch gelf graphite livestatus opentsdb perfdata statusdata syslog
Enabled features: api checker ido-mysql influxdb mainlog notification

• Config validation (icinga2 daemon -C):

[2018-11-19 17:01:40 +0100] information/cli: Icinga application loader (version: r2.10.2-1)
[2018-11-19 17:01:40 +0100] information/cli: Loading configuration file(s).
[2018-11-19 17:01:40 +0100] information/ConfigItem: Committing config item(s).
[2018-11-19 17:01:40 +0100] information/ApiListener: My API identity: mon01.prod.xxx.xxx
[2018-11-19 17:01:40 +0100] information/ConfigItem: Instantiated 2226 Services.
[2018-11-19 17:01:40 +0100] information/ConfigItem: Instantiated 1 InfluxdbWriter.
[2018-11-19 17:01:40 +0100] information/ConfigItem: Instantiated 1 IcingaApplication.
[2018-11-19 17:01:40 +0100] information/ConfigItem: Instantiated 127 Hosts.
[2018-11-19 17:01:40 +0100] information/ConfigItem: Instantiated 1 FileLogger.
[2018-11-19 17:01:40 +0100] information/ConfigItem: Instantiated 1 NotificationComponent.
[2018-11-19 17:01:40 +0100] information/ConfigItem: Instantiated 11 HostGroups.
[2018-11-19 17:01:40 +0100] information/ConfigItem: Instantiated 1 ApiListener.
[2018-11-19 17:01:40 +0100] information/ConfigItem: Instantiated 56 Comments.
[2018-11-19 17:01:40 +0100] information/ConfigItem: Instantiated 1 CheckerComponent.
[2018-11-19 17:01:40 +0100] information/ConfigItem: Instantiated 71 Zones.
[2018-11-19 17:01:40 +0100] information/ConfigItem: Instantiated 69 Endpoints.
[2018-11-19 17:01:40 +0100] information/ConfigItem: Instantiated 5 ApiUsers.
[2018-11-19 17:01:40 +0100] information/ConfigItem: Instantiated 1 IdoMysqlConnection.
[2018-11-19 17:01:40 +0100] information/ConfigItem: Instantiated 224 CheckCommands.
[2018-11-19 17:01:40 +0100] information/ConfigItem: Instantiated 6 ServiceGroups.
[2018-11-19 17:01:40 +0100] information/ConfigItem: Instantiated 2 TimePeriods.
[2018-11-19 17:01:40 +0100] information/ScriptGlobal: Dumping variables to file '/var/cache/icinga2/icinga2.vars'
[2018-11-19 17:01:40 +0100] information/cli: Finished validating the configuration file(s).

[nbuchwitz]

After running the test for a while the daemon crashes:

Nov 19 17:23:29 mon01.prod.xxx.xxx systemd[1]: icinga2.service: main process exited, code=killed, status=11/SEGV
Nov 19 17:23:29 mon01.prod.xxx.xxx systemd[1]: Unit icinga2.service entered failed state.
Nov 19 17:23:29 mon01.prod.xxx.xxx systemd[1]: icinga2.service failed.

[dnsmichi]

Which backtrace is generated from that segfault?

[nbuchwitz]

I tried to reconstruct the segfault, but was not able so far. So I guess it has it was caused by the load I put on the API. The problem with the permissions still exists.

The load and memory utilization on the server is normal (~ 0.8 with 4 cores / ~ 1 GB memory). Queries within a "normal" rate are filtered correctly, but if I start to increase to a unreasonable rate my restrictions are ignored an other objects are also served. Unfortunately, I can't find anything unusual in the logs - with enabled debuglog too.

[lippserd]

It will take us some time to investigate further here.

[dnsmichi]

I'd say this originates from the same ScriptFrame problem with namespaces as #6874 @Crunsher

[dnsmichi]

This definitely is a side effect of #6874.

[dnsmichi]

@nbuchwitz please test the snapshot packages / git master.