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

API process-check-result fails in 2.10.0 #6682

Closed
mphilipps opened this Issue Oct 15, 2018 · 15 comments

Comments

Projects
None yet
2 participants
@mphilipps

mphilipps commented Oct 15, 2018

hi,
It appear that something has changed in 2.10.0 with regards to API process-check-results. The following config worked perfectly prior to 2.10.0.
I have double checked the upgrade documentation, but from what I can see I don't use any functions that would be affected by the namespace change nor am I using path constants.

Request:

curl --cacert /var/lib/icinga2/certs/ca.crt --cert /var/lib/icinga2/certs/server-name.domain.tld.crt --key /var/lib/icinga2/cert
s/server-name.domain.tld.key --connect-timeout 10 -H 'Accept: application/json' -X POST https://ip.v4.of.icingamaster:5665/v1/actions/pro
cess-check-result -d '{ "filter": "service.name==\"service_name\" && host.name==\"server-name.domain.tld\"", "type": "Service", "ex
it_status": 0, "plugin_output": "test" }'

Answer:

{"error":404.0,"status":"No objects found."}

master:

object Host "server-name.domain.tld" {
  address = "ip.v4.of.icingaclient"
  check_command = "hostalive"
  check_interval = 60
  retry_interval = 30
}

object ApiUser "server-name.domain.tld" {
  client_cn = "server-name.domain.tld"
  permissions = [
    {
      permission  = "actions/process-check-result"
      filter = {{ host.name=="server-name.domain.tld" }}
    }, ]
}
object Service "service_name" {
  display_name = "Test Service"
  check_command = "passive_dummy"
  host_name = "server-name.domain.tld"
  check_interval = 129600s
  max_check_attempts = 1
}
object CheckCommand "passive_dummy" {
  import "plugin-check-command"
  command = [ "/usr/lib/nagios/plugins/check_dummy", 3, "Missing check results.", ]
}

Your Environment

  • Version used (icinga2 --version): 2.10.0
  • Operating System and version: master is debian stretch, clients are ubuntus, debians and centos7
  • Enabled features (icinga2 feature list): master: api, checker, command, ido-pgsql, livestatus, mainlog, notifications
@mphilipps

This comment has been minimized.

mphilipps commented Oct 15, 2018

Icingaweb's process check results works. Presumably this means the issue is with the certificate authentication or the filter.

@dnsmichi

This comment has been minimized.

Member

dnsmichi commented Oct 15, 2018

Likely the permissions, without it works.

@dnsmichi

This comment has been minimized.

Member

dnsmichi commented Oct 15, 2018

I'm able to reproduce it, likely a regression from 1f4f628.

@dnsmichi dnsmichi added bug API labels Oct 15, 2018

@dnsmichi dnsmichi self-assigned this Oct 15, 2018

@dnsmichi

This comment has been minimized.

Member

dnsmichi commented Oct 15, 2018

2.9.2 should fail as well where this was backported to.

@dnsmichi

This comment has been minimized.

Member

dnsmichi commented Oct 15, 2018

Seems I made a programming mistake with emplace_back, std::move and pointers. Testing a fix atm, below is my lldb route.

[2018-10-15 10:10:09 +0200] information/ApiListener: New client connection from [::1]:50016 (no client certificate)
[2018-10-15 10:10:09 +0200] information/HttpServerConnection: Request: POST /v1/actions/process-check-result (from [::1]:50016), user: root)
Process 93109 stopped
* thread #12, stop reason = breakpoint 1.1
    frame #0: 0x000000010060b4d5 icinga2`icinga::FilterUtility::GetFilterTargets(qd=0x0000700005957080, query=0x0000700005957d50, user=0x00000001046bb5c8, variableName=0x0000700005956fe0) at filterutility.cpp:238
   235                  }
   236          }
   237
-> 238          if ((query && query->Contains("filter")) || result.empty()) {
   239                  if (!query->Contains("type"))
   240                          BOOST_THROW_EXCEPTION(std::invalid_argument("Type must be specified when using a filter."));
   241
Target 0: (icinga2) stopped.
(lldb) p query
(icinga::Dictionary::Ptr) $0 = {
  px = 0x00000001046e3a60
}
(lldb) * result
error: '*' is not a valid command.
error: Unrecognized command '*'.
(lldb) p result
(std::__1::vector<icinga::Value, std::__1::allocator<icinga::Value> >) $1 = size=0 {}
(lldb) n
[2018-10-15 10:10:30 +0200] information/Application: We jumped forward in time: 23.4158 seconds
[2018-10-15 10:10:30 +0200] information/WorkQueue: #13 (JsonRpcConnection, #3) items: 0, rate:  0/s (0/min 0/5min 0/15min);
[2018-10-15 10:10:30 +0200] information/WorkQueue: #7 (IdoMysqlConnection, ido-mysql) items: 1, rate: 772.533/s (46352/min 46352/5min 46352/15min);
[2018-10-15 10:10:30 +0200] information/WorkQueue: #10 (JsonRpcConnection, #0) items: 0, rate: 0.183333/s (11/min 11/5min 11/15min);
[2018-10-15 10:10:30 +0200] information/WorkQueue: #12 (JsonRpcConnection, #2) items: 0, rate:  0/s (0/min 0/5min 0/15min);
[2018-10-15 10:10:30 +0200] information/WorkQueue: #11 (JsonRpcConnection, #1) items: 0, rate:  0/s (0/min 0/5min 0/15min);
Process 93109 stopped
* thread #12, stop reason = step over
    frame #0: 0x000000010060b5c5 icinga2`icinga::FilterUtility::GetFilterTargets(qd=0x0000700005957080, query=0x0000700005957d50, user=0x00000001046bb5c8, variableName=0x0000700005956fe0) at filterutility.cpp:239
   236          }
   237
   238          if ((query && query->Contains("filter")) || result.empty()) {
-> 239                  if (!query->Contains("type"))
   240                          BOOST_THROW_EXCEPTION(std::invalid_argument("Type must be specified when using a filter."));
   241
   242                  String type = HttpUtility::GetLastParameter(query, "type");
Target 0: (icinga2) stopped.
(lldb) n
2018-10-15 10:10:33.297435+0200 icinga2[93109:10267002] Event call took 2.51486s
[2018-10-15 10:10:33 +0200] warning/ThreadPool: Event call took 2.51486s
2018-10-15 10:10:33.297601+0200 icinga2[93109:10267001] Event call took 2.52707s
[2018-10-15 10:10:33 +0200] warning/ThreadPool: Event call took 2.52707s
[2018-10-15 10:10:33 +0200] information/WorkQueue: #14 (HttpServerConnection) items: 2, rate:  0/s (0/min 0/5min 0/15min); empty in 17819 days, 8 hours, 10 minutes and 33 seconds
Process 93109 stopped
* thread #12, stop reason = step over
    frame #0: 0x000000010060b742 icinga2`icinga::FilterUtility::GetFilterTargets(qd=0x0000700005957080, query=0x0000700005957d50, user=0x00000001046bb5c8, variableName=0x0000700005956fe0) at filterutility.cpp:242
   239                  if (!query->Contains("type"))
   240                          BOOST_THROW_EXCEPTION(std::invalid_argument("Type must be specified when using a filter."));
   241
-> 242                  String type = HttpUtility::GetLastParameter(query, "type");
   243
   244                  if (!provider->IsValidType(type))
   245                          BOOST_THROW_EXCEPTION(std::invalid_argument("Invalid type specified."));
Target 0: (icinga2) stopped.
(lldb) n
2018-10-15 10:10:41.598468+0200 icinga2[93109:10267003] Event call took 2.53851s
[2018-10-15 10:10:33 +0200] warning/ThreadPool: Event call took 2.53851s
Process 93109 stopped
* thread #12, stop reason = step over
    frame #0: 0x000000010060b7c1 icinga2`icinga::FilterUtility::GetFilterTargets(qd=0x0000700005957080, query=0x0000700005957d50, user=0x00000001046bb5c8, variableName=0x0000700005956fe0) at filterutility.cpp:244
   241
   242                  String type = HttpUtility::GetLastParameter(query, "type");
   243
-> 244                  if (!provider->IsValidType(type))
   245                          BOOST_THROW_EXCEPTION(std::invalid_argument("Invalid type specified."));
   246
   247                  if (qd.Types.find(type) == qd.Types.end())
Target 0: (icinga2) stopped.
(lldb) p type
(icinga::String) $2 = (m_Data = "Service")
(lldb) n
Process 93109 stopped
* thread #12, stop reason = step over
    frame #0: 0x000000010060b911 icinga2`icinga::FilterUtility::GetFilterTargets(qd=0x0000700005957080, query=0x0000700005957d50, user=0x00000001046bb5c8, variableName=0x0000700005956fe0) at filterutility.cpp:247
   244                  if (!provider->IsValidType(type))
   245                          BOOST_THROW_EXCEPTION(std::invalid_argument("Invalid type specified."));
   246
-> 247                  if (qd.Types.find(type) == qd.Types.end())
   248                          BOOST_THROW_EXCEPTION(std::invalid_argument("Invalid type specified for this query."));
   249
   250                  ScriptFrame frame(true);
Target 0: (icinga2) stopped.
(lldb)
[2018-10-15 10:11:03 +0200] information/Application: We jumped forward in time: 21.5598 seconds
2018-10-15 10:11:03.166476+0200 icinga2[93109:10267001] Event call took 8.32798s
[2018-10-15 10:11:03 +0200] warning/ThreadPool: Event call took 8.32798s
2018-10-15 10:11:03.166566+0200 icinga2[93109:10267004] Event call took 29.8656s
[2018-10-15 10:11:03 +0200] warning/ThreadPool: Event call took 29.8656s
Process 93109 stopped
* thread #12, stop reason = step over
    frame #0: 0x000000010060bb4b icinga2`icinga::FilterUtility::GetFilterTargets(qd=0x0000700005957080, query=0x0000700005957d50, user=0x00000001046bb5c8, variableName=0x0000700005956fe0) at filterutility.cpp:250
   247                  if (qd.Types.find(type) == qd.Types.end())
   248                          BOOST_THROW_EXCEPTION(std::invalid_argument("Invalid type specified for this query."));
   249
-> 250                  ScriptFrame frame(true);
   251                  frame.Sandboxed = true;
   252                  Dictionary::Ptr uvars = new Dictionary();
   253
Target 0: (icinga2) stopped.
(lldb)
2018-10-15 10:11:05.042736+0200 icinga2[93109:10267002] Event call took 29.8623s
[2018-10-15 10:11:03 +0200] warning/ThreadPool: Event call took 29.8623s
Process 93109 stopped
* thread #12, stop reason = step over
    frame #0: 0x000000010060bb5a icinga2`icinga::FilterUtility::GetFilterTargets(qd=0x0000700005957080, query=0x0000700005957d50, user=0x00000001046bb5c8, variableName=0x0000700005956fe0) at filterutility.cpp:251
   248                          BOOST_THROW_EXCEPTION(std::invalid_argument("Invalid type specified for this query."));
   249
   250                  ScriptFrame frame(true);
-> 251                  frame.Sandboxed = true;
   252                  Dictionary::Ptr uvars = new Dictionary();
   253
   254                  if (query->Contains("filter")) {
Target 0: (icinga2) stopped.
(lldb)
Process 93109 stopped
* thread #12, stop reason = step over
    frame #0: 0x000000010060bb61 icinga2`icinga::FilterUtility::GetFilterTargets(qd=0x0000700005957080, query=0x0000700005957d50, user=0x00000001046bb5c8, variableName=0x0000700005956fe0) at filterutility.cpp:252
   249
   250                  ScriptFrame frame(true);
   251                  frame.Sandboxed = true;
-> 252                  Dictionary::Ptr uvars = new Dictionary();
   253
   254                  if (query->Contains("filter")) {
   255                          String filter = HttpUtility::GetLastParameter(query, "filter");
Target 0: (icinga2) stopped.
(lldb)
Process 93109 stopped
* thread #12, stop reason = step over
    frame #0: 0x000000010060bbbf icinga2`icinga::FilterUtility::GetFilterTargets(qd=0x0000700005957080, query=0x0000700005957d50, user=0x00000001046bb5c8, variableName=0x0000700005956fe0) at filterutility.cpp:254
   251                  frame.Sandboxed = true;
   252                  Dictionary::Ptr uvars = new Dictionary();
   253
-> 254                  if (query->Contains("filter")) {
   255                          String filter = HttpUtility::GetLastParameter(query, "filter");
   256                          std::unique_ptr<Expression> ufilter = ConfigCompiler::CompileText("<API query>", filter);
   257
Target 0: (icinga2) stopped.
(lldb)
2018-10-15 10:11:08.229358+0200 icinga2[93109:10270464] Event call took 4.2114s
[2018-10-15 10:11:07 +0200] warning/ThreadPool: Event call took 4.2114s
Process 93109 stopped
* thread #12, stop reason = step over
    frame #0: 0x000000010060bc27 icinga2`icinga::FilterUtility::GetFilterTargets(qd=0x0000700005957080, query=0x0000700005957d50, user=0x00000001046bb5c8, variableName=0x0000700005956fe0) at filterutility.cpp:255
   252                  Dictionary::Ptr uvars = new Dictionary();
   253
   254                  if (query->Contains("filter")) {
-> 255                          String filter = HttpUtility::GetLastParameter(query, "filter");
   256                          std::unique_ptr<Expression> ufilter = ConfigCompiler::CompileText("<API query>", filter);
   257
   258                          Dictionary::Ptr filter_vars = query->Get("filter_vars");
Target 0: (icinga2) stopped.
(lldb)
2018-10-15 10:11:14.311666+0200 icinga2[93109:10267095] Killing process group 93416 ('/usr/local/sbin/check_ping' '-4' '-H' '127.0.0.1' '-c' '200,15%' '-w' '100,5%') after timeout of 60 seconds
[2018-10-15 10:11:08 +0200] warning/Process: Killing process group 93416 ('/usr/local/sbin/check_ping' '-4' '-H' '127.0.0.1' '-c' '200,15%' '-w' '100,5%') after timeout of 60 seconds
[2018-10-15 10:11:08 +0200] information/WorkQueue: #7 (IdoMysqlConnection, ido-mysql) items: 1, rate: 0.3/s (18/min 46365/5min 46365/15min); empty in infinite time, your task handler isn't able to keep up
Process 93109 stopped
* thread #12, stop reason = step over
    frame #0: 0x000000010060bc9f icinga2`icinga::FilterUtility::GetFilterTargets(qd=0x0000700005957080, query=0x0000700005957d50, user=0x00000001046bb5c8, variableName=0x0000700005956fe0) at filterutility.cpp:256
   253
   254                  if (query->Contains("filter")) {
   255                          String filter = HttpUtility::GetLastParameter(query, "filter");
-> 256                          std::unique_ptr<Expression> ufilter = ConfigCompiler::CompileText("<API query>", filter);
   257
   258                          Dictionary::Ptr filter_vars = query->Get("filter_vars");
   259                          if (filter_vars) {
Target 0: (icinga2) stopped.
(lldb)
2018-10-15 10:11:15.534859+0200 icinga2[93109:10267097] Killing process group 93428 ('/usr/local/sbin/check_ping' '-4' '-H' '127.0.0.1' '-c' '200,15%' '-w' '100,5%') after timeout of 60 seconds
[2018-10-15 10:11:14 +0200] warning/Process: Killing process group 93428 ('/usr/local/sbin/check_ping' '-4' '-H' '127.0.0.1' '-c' '200,15%' '-w' '100,5%') after timeout of 60 seconds
2018-10-15 10:11:15.535183+0200 icinga2[93109:10267091] Invalid socket: Operation timed out
[2018-10-15 10:11:14 +0200] critical/TcpSocket: Invalid socket: Operation timed out
2018-10-15 10:11:15.553584+0200 icinga2[93109:10267095] Couldn't kill the process group 93416 ('/usr/local/sbin/check_ping' '-4' '-H' '127.0.0.1' '-c' '200,15%' '-w' '100,5%'): [errno 1] Operation not permitted
Process 93109 stopped
* thread #12, stop reason = step over
    frame #0: 0x000000010060bd69 icinga2`icinga::FilterUtility::GetFilterTargets(qd=0x0000700005957080, query=0x0000700005957d50, user=0x00000001046bb5c8, variableName=0x0000700005956fe0) at filterutility.cpp:258
   255                          String filter = HttpUtility::GetLastParameter(query, "filter");
   256                          std::unique_ptr<Expression> ufilter = ConfigCompiler::CompileText("<API query>", filter);
   257
-> 258                          Dictionary::Ptr filter_vars = query->Get("filter_vars");
   259                          if (filter_vars) {
   260                                  ObjectLock olock(filter_vars);
   261                                  for (const Dictionary::Pair& kv : filter_vars) {
Target 0: (icinga2) stopped.
(lldb)
[2018-10-15 10:11:15 +0200] warning/Process: Couldn't kill the process group 93416 ('/usr/local/sbin/check_ping' '-4' '-H' '127.0.0.1' '-c' '200,15%' '-w' '100,5%'): [errno 1] Operation not permitted
2018-10-15 10:11:16.413651+0200 icinga2[93109:10270600] Event call took 7.26785s
2018-10-15 10:11:16.421916+0200 icinga2[93109:10270464] Event call took 7.25807s
[2018-10-15 10:11:15 +0200] warning/ThreadPool: Event call took 7.26785s
[2018-10-15 10:11:15 +0200] warning/ThreadPool: Event call took 7.25807s
2018-10-15 10:11:16.442100+0200 icinga2[93109:10267091] Cannot connect to host '192.168.56.101' on port '5665'
Process 93109 stopped
* thread #12, stop reason = step over
    frame #0: 0x000000010060bdea icinga2`icinga::FilterUtility::GetFilterTargets(qd=0x0000700005957080, query=0x0000700005957d50, user=0x00000001046bb5c8, variableName=0x0000700005956fe0) at filterutility.cpp:259
   256                          std::unique_ptr<Expression> ufilter = ConfigCompiler::CompileText("<API query>", filter);
   257
   258                          Dictionary::Ptr filter_vars = query->Get("filter_vars");
-> 259                          if (filter_vars) {
   260                                  ObjectLock olock(filter_vars);
   261                                  for (const Dictionary::Pair& kv : filter_vars) {
   262                                          uvars->Set(kv.first, kv.second);
Target 0: (icinga2) stopped.
(lldb)
Process 93109 stopped
* thread #12, stop reason = step over
    frame #0: 0x000000010060c2c9 icinga2`icinga::FilterUtility::GetFilterTargets(qd=0x0000700005957080, query=0x0000700005957d50, user=0x00000001046bb5c8, variableName=0x0000700005956fe0) at filterutility.cpp:266
   263                                  }
   264                          }
   265
-> 266                          frame.Self = uvars;
   267
   268                          provider->FindTargets(type, std::bind(&FilteredAddTarget,
   269                                  std::ref(permissionFrame), permissionFilter,
Target 0: (icinga2) stopped.
(lldb)
2018-10-15 10:11:19.003601+0200 icinga2[93109:10267097] Couldn't kill the process group 93428 ('/usr/local/sbin/check_ping' '-4' '-H' '127.0.0.1' '-c' '200,15%' '-w' '100,5%'): [errno 1] Operation not permitted
[2018-10-15 10:11:15 +0200] critical/ApiListener: Cannot connect to host '192.168.56.101' on port '5665'
Process 93109 stopped
* thread #12, stop reason = step over
    frame #0: 0x000000010060c305 icinga2`icinga::FilterUtility::GetFilterTargets(qd=0x0000700005957080, query=0x0000700005957d50, user=0x00000001046bb5c8, variableName=0x0000700005956fe0) at filterutility.cpp:268
   265
   266                          frame.Self = uvars;
   267
-> 268                          provider->FindTargets(type, std::bind(&FilteredAddTarget,
   269                                  std::ref(permissionFrame), permissionFilter,
   270                                  std::ref(frame), &*ufilter, std::ref(result), variableName, _1));
   271                  } else {
Target 0: (icinga2) stopped.
(lldb) s
[2018-10-15 10:11:15 +0200] warning/Process: Couldn't kill the process group 93428 ('/usr/local/sbin/check_ping' '-4' '-H' '127.0.0.1' '-c' '200,15%' '-w' '100,5%'): [errno 1] Operation not permitted
2018-10-15 10:11:28.046265+0200 icinga2[93109:10267003] Event call took 34.8029s
Process 93109 stopped
* thread #12, stop reason = step in
    frame #0: 0x000000010060d910 icinga2`boost::intrusive_ptr<icinga::TargetProvider>::operator->(this=0x0000700005955988) const at intrusive_ptr.hpp:199
   196
   197      T * operator->() const BOOST_SP_NOEXCEPT_WITH_ASSERT
   198      {
-> 199          BOOST_ASSERT( px != 0 );
   200          return px;
   201      }
   202
Target 0: (icinga2) stopped.
(lldb)
Process 93109 stopped
* thread #12, stop reason = step in
    frame #0: 0x000000010060d955 icinga2`boost::intrusive_ptr<icinga::TargetProvider>::operator->(this=0x0000700005955988) const at intrusive_ptr.hpp:200
   197      T * operator->() const BOOST_SP_NOEXCEPT_WITH_ASSERT
   198      {
   199          BOOST_ASSERT( px != 0 );
-> 200          return px;
   201      }
   202
   203  // implicit conversion to "bool"
Target 0: (icinga2) stopped.
(lldb)
Process 93109 stopped
* thread #12, stop reason = step in
    frame #0: 0x000000010060c30a icinga2`icinga::FilterUtility::GetFilterTargets(qd=0x0000700005957080, query=0x0000700005957d50, user=0x00000001046bb5c8, variableName=0x0000700005956fe0) at filterutility.cpp:268
   265
   266                          frame.Self = uvars;
   267
-> 268                          provider->FindTargets(type, std::bind(&FilteredAddTarget,
   269                                  std::ref(permissionFrame), permissionFilter,
   270                                  std::ref(frame), &*ufilter, std::ref(result), variableName, _1));
   271                  } else {
Target 0: (icinga2) stopped.
(lldb)
Process 93109 stopped
* thread #12, stop reason = step in
    frame #0: 0x000000010060c346 icinga2`icinga::FilterUtility::GetFilterTargets(qd=0x0000700005957080, query=0x0000700005957d50, user=0x00000001046bb5c8, variableName=0x0000700005956fe0) at filterutility.cpp:269
   266                          frame.Self = uvars;
   267
   268                          provider->FindTargets(type, std::bind(&FilteredAddTarget,
-> 269                                  std::ref(permissionFrame), permissionFilter,
   270                                  std::ref(frame), &*ufilter, std::ref(result), variableName, _1));
   271                  } else {
   272                          /* Ensure to pass a nullptr as filter expression.
Target 0: (icinga2) stopped.
(lldb)
[2018-10-15 10:11:16 +0200] warning/ThreadPool: Event call took 34.8029s
Process 93109 stopped
* thread #12, stop reason = step in
    frame #0: 0x000000010060c3ab icinga2`icinga::FilterUtility::GetFilterTargets(qd=0x0000700005957080, query=0x0000700005957d50, user=0x00000001046bb5c8, variableName=0x0000700005956fe0) at filterutility.cpp:270
   267
   268                          provider->FindTargets(type, std::bind(&FilteredAddTarget,
   269                                  std::ref(permissionFrame), permissionFilter,
-> 270                                  std::ref(frame), &*ufilter, std::ref(result), variableName, _1));
   271                  } else {
   272                          /* Ensure to pass a nullptr as filter expression.
   273                           * GCC 8.1.1 on F28 causes problems, see GH #6533.
Target 0: (icinga2) stopped.
(lldb)
Process 93109 stopped
* thread #12, stop reason = step in
    frame #0: 0x000000010060c53c icinga2`icinga::FilterUtility::GetFilterTargets(qd=0x0000700005957080, query=0x0000700005957d50, user=0x00000001046bb5c8, variableName=0x0000700005956fe0) at filterutility.cpp:268
   265
   266                          frame.Self = uvars;
   267
-> 268                          provider->FindTargets(type, std::bind(&FilteredAddTarget,
   269                                  std::ref(permissionFrame), permissionFilter,
   270                                  std::ref(frame), &*ufilter, std::ref(result), variableName, _1));
   271                  } else {
Target 0: (icinga2) stopped.
(lldb)
[2018-10-15 10:11:16 +0200] information/WorkQueue: #10 (JsonRpcConnection, #0) items: 1, rate: 0.233333/s (14/min 23/5min 23/15min);
2018-10-15 10:11:33.947076+0200 icinga2[93109:10267095] Killing process group 93435 ('/usr/local/sbin/check_ping' '-4' '-H' '127.0.0.1' '-c' '200,15%' '-w' '100,5%') after timeout of 60 seconds
[2018-10-15 10:11:16 +0200] warning/Process: Killing process group 93435 ('/usr/local/sbin/check_ping' '-4' '-H' '127.0.0.1' '-c' '200,15%' '-w' '100,5%') after timeout of 60 seconds
2018-10-15 10:11:33.982904+0200 icinga2[93109:10270880] Event call took 2.56862s
Process 93109 stopped
* thread #12, stop reason = step in
    frame #0: 0x00000001006069d5 icinga2`icinga::ConfigObjectTargetProvider::FindTargets(this=0x000000010647b040, type=0x0000700005955678, addTarget=0x00000001063bd380)> const&) const at filterutility.cpp:49
   46
   47   void ConfigObjectTargetProvider::FindTargets(const String& type, const std::function<void (const Value&)>& addTarget) const
   48   {
-> 49           Type::Ptr ptype = Type::GetByName(type);
   50           auto *ctype = dynamic_cast<ConfigType *>(ptype.get());
   51
   52           if (ctype) {
Target 0: (icinga2) stopped.
(lldb) n
[2018-10-15 10:11:19 +0200] warning/ThreadPool: Event call took 2.56862s
Process 93109 stopped
* thread #12, stop reason = step over
    frame #0: 0x00000001006069eb icinga2`icinga::ConfigObjectTargetProvider::FindTargets(this=0x000000010647b040, type=0x0000700005955678, addTarget=0x00000001063bd380)> const&) const at filterutility.cpp:50
   47   void ConfigObjectTargetProvider::FindTargets(const String& type, const std::function<void (const Value&)>& addTarget) const
   48   {
   49           Type::Ptr ptype = Type::GetByName(type);
-> 50           auto *ctype = dynamic_cast<ConfigType *>(ptype.get());
   51
   52           if (ctype) {
   53                   for (const ConfigObject::Ptr& object : ctype->GetObjects()) {
Target 0: (icinga2) stopped.
(lldb)
2018-10-15 10:11:39.045473+0200 icinga2[93109:10267097] Killing process group 93432 ('/usr/local/sbin/check_ping' '-4' '-H' '127.0.0.1' '-c' '200,15%' '-w' '100,5%') after timeout of 60 seconds
[2018-10-15 10:11:32 +0200] warning/Process: Killing process group 93432 ('/usr/local/sbin/check_ping' '-4' '-H' '127.0.0.1' '-c' '200,15%' '-w' '100,5%') after timeout of 60 seconds
2018-10-15 10:11:39.045642+0200 icinga2[93109:10270401] Event call took 30.0393s
[2018-10-15 10:11:33 +0200] warning/ThreadPool: Event call took 30.0393s
2018-10-15 10:11:39.054044+0200 icinga2[93109:10270402] Event call took 30.0487s
Process 93109 stopped
* thread #12, stop reason = step over
    frame #0: 0x0000000100606a63 icinga2`icinga::ConfigObjectTargetProvider::FindTargets(this=0x000000010647b040, type=0x0000700005955678, addTarget=0x00000001063bd380)> const&) const at filterutility.cpp:52
   49           Type::Ptr ptype = Type::GetByName(type);
   50           auto *ctype = dynamic_cast<ConfigType *>(ptype.get());
   51
-> 52           if (ctype) {
   53                   for (const ConfigObject::Ptr& object : ctype->GetObjects()) {
   54                           addTarget(object);
   55                   }
Target 0: (icinga2) stopped.
(lldb) p ctype
(icinga::TypeImpl<icinga::Service> *) $3 = 0x0000000104005fa0
(lldb) n
Process 93109 stopped
* thread #12, stop reason = step over
    frame #0: 0x0000000100606a71 icinga2`icinga::ConfigObjectTargetProvider::FindTargets(this=0x000000010647b040, type=0x0000700005955678, addTarget=0x00000001063bd380)> const&) const at filterutility.cpp:53
   50           auto *ctype = dynamic_cast<ConfigType *>(ptype.get());
   51
   52           if (ctype) {
-> 53                   for (const ConfigObject::Ptr& object : ctype->GetObjects()) {
   54                           addTarget(object);
   55                   }
   56           }
@dnsmichi

This comment has been minimized.

Member

dnsmichi commented Oct 15, 2018

FindTargets() binds a function which gets called with addTarget(). Specifically this is FilteredAddTarget() here.

@dnsmichi

This comment has been minimized.

Member

dnsmichi commented Oct 15, 2018

Hm, seems this goes deeper into the ScriptFrame with GetGlobals().

@dnsmichi

This comment has been minimized.

Member

dnsmichi commented Oct 15, 2018

[2018-10-15 10:59:02 +0200] information/ApiListener: New client connection from [::1]:50733 (no client certificate)
[2018-10-15 10:59:02 +0200] information/HttpServerConnection: Request: POST /v1/actions/process-check-result (from [::1]:50733), user: root)
Process 34647 stopped
* thread #36, stop reason = breakpoint 2.2
    frame #0: 0x000000010060d9a9 icinga2`FilteredAddTarget(permissionFrame=0x00007000033d69d0, permissionFilter=0x00000001062cc1c0, frame=0x00007000033d6900, ufilter=0x0000000107f4b500, result=size=0, variableName=0x0000000107f653b8, target=0x00007000033d4e00) at filterutility.cpp:129
   126  static void FilteredAddTarget(ScriptFrame& permissionFrame, Expression *permissionFilter,
   127          ScriptFrame& frame, Expression *ufilter, std::vector<Value>& result, const String& variableName, const Object::Ptr& target)
   128  {
-> 129          if (FilterUtility::EvaluateFilter(permissionFrame, permissionFilter, target, variableName)) {
   130                  if (FilterUtility::EvaluateFilter(frame, ufilter, target, variableName)) {
   131                          /* Add the object pointer, don't use std::move here. */
   132                          result.emplace_back(target);
Target 0: (icinga2) stopped.
(lldb) s
Process 34647 stopped
* thread #36, stop reason = step in
    frame #0: 0x0000000100607035 icinga2`icinga::FilterUtility::EvaluateFilter(frame=0x00007000033d69d0, filter=0x00000001062cc1c0, target=0x00007000033d4e00, variableName=0x0000000107f653b8) at filterutility.cpp:87
   84   bool FilterUtility::EvaluateFilter(ScriptFrame& frame, Expression *filter,
   85           const Object::Ptr& target, const String& variableName)
   86   {
-> 87           if (!filter)
   88                   return true;
   89
   90           Type::Ptr type = target->GetReflectionType();
Target 0: (icinga2) stopped.
(lldb) n
Process 34647 stopped
* thread #36, stop reason = step over
    frame #0: 0x000000010060704f icinga2`icinga::FilterUtility::EvaluateFilter(frame=0x00007000033d69d0, filter=0x00000001062cc1c0, target=0x00007000033d4e00, variableName=0x0000000107f653b8) at filterutility.cpp:90
   87           if (!filter)
   88                   return true;
   89
-> 90           Type::Ptr type = target->GetReflectionType();
   91           String varName;
   92
   93           if (variableName.IsEmpty())
Target 0: (icinga2) stopped.
(lldb)
Process 34647 stopped
* thread #36, stop reason = step over
    frame #0: 0x0000000100607086 icinga2`icinga::FilterUtility::EvaluateFilter(frame=0x00007000033d69d0, filter=0x00000001062cc1c0, target=0x00007000033d4e00, variableName=0x0000000107f653b8) at filterutility.cpp:91
   88                   return true;
   89
   90           Type::Ptr type = target->GetReflectionType();
-> 91           String varName;
   92
   93           if (variableName.IsEmpty())
   94                   varName = type->GetName().ToLower();
Target 0: (icinga2) stopped.
(lldb)
Process 34647 stopped
* thread #36, stop reason = step over
    frame #0: 0x000000010060708b icinga2`icinga::FilterUtility::EvaluateFilter(frame=0x00007000033d69d0, filter=0x00000001062cc1c0, target=0x00007000033d4e00, variableName=0x0000000107f653b8) at filterutility.cpp:93
   90           Type::Ptr type = target->GetReflectionType();
   91           String varName;
   92
-> 93           if (variableName.IsEmpty())
   94                   varName = type->GetName().ToLower();
   95           else
   96                   varName = variableName;
Target 0: (icinga2) stopped.
(lldb)
2018-10-15 10:59:09.004003+0200 icinga2[34647:10428386] Event call took 1.64845s
[2018-10-15 10:59:09 +0200] warning/ThreadPool: Event call took 1.64845s
Process 34647 stopped
* thread #36, stop reason = step over
    frame #0: 0x00000001006070bc icinga2`icinga::FilterUtility::EvaluateFilter(frame=0x00007000033d69d0, filter=0x00000001062cc1c0, target=0x00007000033d4e00, variableName=0x0000000107f653b8) at filterutility.cpp:94
   91           String varName;
   92
   93           if (variableName.IsEmpty())
-> 94                   varName = type->GetName().ToLower();
   95           else
   96                   varName = variableName;
   97
Target 0: (icinga2) stopped.
(lldb)
2018-10-15 10:59:09.716273+0200 icinga2[34647:10428383] Event call took 1.64927s
[2018-10-15 10:59:09 +0200] warning/ThreadPool: Event call took 1.64927s
2018-10-15 10:59:09.740900+0200 icinga2[34647:10428385] Event call took 0.71186s
[2018-10-15 10:59:09 +0200] warning/ThreadPool: Event call took 0.71186s
Process 34647 stopped
* thread #36, stop reason = step over
    frame #0: 0x00000001006071bd icinga2`icinga::FilterUtility::EvaluateFilter(frame=0x00007000033d69d0, filter=0x00000001062cc1c0, target=0x00007000033d4e00, variableName=0x0000000107f653b8) at filterutility.cpp:98
   95           else
   96                   varName = variableName;
   97
-> 98           Dictionary::Ptr vars;
   99
   100          if (frame.Self.IsEmpty()) {
   101                  vars = new Dictionary();
Target 0: (icinga2) stopped.
(lldb) p varName
(icinga::String) $2 = (m_Data = "service")
(lldb) n
Process 34647 stopped
* thread #36, stop reason = step over
    frame #0: 0x00000001006071c2 icinga2`icinga::FilterUtility::EvaluateFilter(frame=0x00007000033d69d0, filter=0x00000001062cc1c0, target=0x00007000033d4e00, variableName=0x0000000107f653b8) at filterutility.cpp:100
   97
   98           Dictionary::Ptr vars;
   99
-> 100          if (frame.Self.IsEmpty()) {
   101                  vars = new Dictionary();
   102                  frame.Self = vars;
   103          } else
Target 0: (icinga2) stopped.
(lldb)
Process 34647 stopped
* thread #36, stop reason = step over
    frame #0: 0x00000001006072c7 icinga2`icinga::FilterUtility::EvaluateFilter(frame=0x00007000033d69d0, filter=0x00000001062cc1c0, target=0x00007000033d4e00, variableName=0x0000000107f653b8) at filterutility.cpp:104
   101                  vars = new Dictionary();
   102                  frame.Self = vars;
   103          } else
-> 104                  vars = frame.Self;
   105
   106          vars->Set("obj", target);
   107          vars->Set(varName, target);
Target 0: (icinga2) stopped.
(lldb) s
[2018-10-15 10:59:26 +0200] information/Application: We jumped forward in time: 18.3525 seconds
Process 34647 stopped
* thread #36, stop reason = step in
    frame #0: 0x00000001000a8eb6 icinga2`icinga::Value::operator boost::intrusive_ptr<icinga::Dictionary><icinga::Dictionary>(this=0x00007000033d69d8) const at value.hpp:110
   107          template<typename T>
   108          operator intrusive_ptr<T>() const
   109          {
-> 110                  if (IsEmpty() && !IsString())
   111                          return intrusive_ptr<T>();
   112
   113                  if (!IsObject())
Target 0: (icinga2) stopped.
(lldb) n
Process 34647 stopped
* thread #36, stop reason = step over
    frame #0: 0x00000001000a8f05 icinga2`icinga::Value::operator boost::intrusive_ptr<icinga::Dictionary><icinga::Dictionary>(this=0x00007000033d69d8) const at value.hpp:113
   110                  if (IsEmpty() && !IsString())
   111                          return intrusive_ptr<T>();
   112
-> 113                  if (!IsObject())
   114                          BOOST_THROW_EXCEPTION(std::runtime_error("Cannot convert value of type '" + GetTypeName() + "' to an object."));
   115
   116                  const auto& object = Get<Object::Ptr>();
Target 0: (icinga2) stopped.
(lldb)
Process 34647 stopped
* thread #36, stop reason = step over
    frame #0: 0x00000001000a9011 icinga2`icinga::Value::operator boost::intrusive_ptr<icinga::Dictionary><icinga::Dictionary>(this=0x00007000033d69d8) const at value.hpp:116
   113                  if (!IsObject())
   114                          BOOST_THROW_EXCEPTION(std::runtime_error("Cannot convert value of type '" + GetTypeName() + "' to an object."));
   115
-> 116                  const auto& object = Get<Object::Ptr>();
   117
   118                  ASSERT(object);
   119
Target 0: (icinga2) stopped.
(lldb)
Process 34647 stopped
* thread #36, stop reason = step over
    frame #0: 0x00000001000a9021 icinga2`icinga::Value::operator boost::intrusive_ptr<icinga::Dictionary><icinga::Dictionary>(this=0x00007000033d69d8) const at value.hpp:118
   115
   116                  const auto& object = Get<Object::Ptr>();
   117
-> 118                  ASSERT(object);
   119
   120                  intrusive_ptr<T> tobject = dynamic_pointer_cast<T>(object);
   121
Target 0: (icinga2) stopped.
(lldb)
[2018-10-15 10:59:45 +0200] information/Application: We jumped forward in time: 19.677 seconds
2018-10-15 10:59:46.835428+0200 icinga2[34647:10428386] Event call took 36.9117s
[2018-10-15 10:59:45 +0200] warning/ThreadPool: Event call took 36.9117s
Process 34647 stopped
* thread #36, stop reason = step over
    frame #0: 0x00000001000a905e icinga2`icinga::Value::operator boost::intrusive_ptr<icinga::Dictionary><icinga::Dictionary>(this=0x00007000033d69d8) const at value.hpp:120
   117
   118                  ASSERT(object);
   119
-> 120                  intrusive_ptr<T> tobject = dynamic_pointer_cast<T>(object);
   121
   122                  if (!tobject)
   123                          BOOST_THROW_EXCEPTION(std::bad_cast());
Target 0: (icinga2) stopped.
(lldb)
Process 34647 stopped
* thread #36, stop reason = step over
    frame #0: 0x00000001000a906b icinga2`icinga::Value::operator boost::intrusive_ptr<icinga::Dictionary><icinga::Dictionary>(this=0x00007000033d69d8) const at value.hpp:122
   119
   120                  intrusive_ptr<T> tobject = dynamic_pointer_cast<T>(object);
   121
-> 122                  if (!tobject)
   123                          BOOST_THROW_EXCEPTION(std::bad_cast());
   124
   125                  return tobject;
Target 0: (icinga2) stopped.
(lldb)
Process 34647 stopped
* thread #36, stop reason = step over
    frame #0: 0x00000001000a9084 icinga2`icinga::Value::operator boost::intrusive_ptr<icinga::Dictionary><icinga::Dictionary>(this=0x00007000033d69d8) const at value.hpp:123
   120                  intrusive_ptr<T> tobject = dynamic_pointer_cast<T>(object);
   121
   122                  if (!tobject)
-> 123                          BOOST_THROW_EXCEPTION(std::bad_cast());
   124
   125                  return tobject;
   126          }
Target 0: (icinga2) stopped.
(lldb) p *object.px
(icinga::Object) $3 = {
  m_References = 3
  m_Mutex = 4352731632
  m_LockOwner = 0x0000000000000000
  m_LockCount = 0
}
@dnsmichi

This comment has been minimized.

Member

dnsmichi commented Oct 15, 2018

Ok, so this is a silent failing exception.

frame.Self is expected to be a Dictionary, since we formerly used that everywhere, also for the globals and locals scope variables.

The thing done here with EvaluateFilter() is to populate the scriptframe with additional scoped variables, e.g. from a join, or to access host object attributes for the filter.

The problem now is that recently we've changed GetGlobals() to return a Namespace object, not a Dictionary. That's why this now fails with specific calls to EvaluateFilter() and a ScriptFrame which contains a Namespace within Self.

In order to fix this, each caller needs to provide a frame local new namespace for EvaluateFilter(). This is then properly initialized inside, instead of the previous dictionary.

@dnsmichi dnsmichi added this to the 2.10.1 milestone Oct 15, 2018

@dnsmichi

This comment has been minimized.

Member

dnsmichi commented Oct 15, 2018

Permissions.

object ApiUser "root" {
  password = "icinga"
  // client_cn = ""

  permissions = [
    {
      permission  = "actions/process-check-result"
      filter = {{ host.name=="mbmif.int.netways.de" }}
    }, ]
}

Normal call.

michi@mbmif ~/coding/icinga/icinga2 (master *=) $ curl -k -s -u root:icinga -H 'Accept: application/json' -X POST 'https://localhost:5665/v1/actions/process-check-result' -d '{ "type": "Service", "filter": "service.name==\"ping4\" && host.name==\"mbmif.int.netways.de\"", "exit_status": 1, "plugin_output": "rest api test" }'
{"results":[{"code":200.0,"status":"Successfully processed check result for object 'mbmif.int.netways.de!ping4'."}]}

filter_vars is affected by this change.

michi@mbmif ~/coding/icinga/icinga2 (master *=) $ curl -k -s -u root:icinga -H 'Accept: application/json' -X POST 'https://localhost:5665/v1/actions/process-check-result' -d '{ "type": "Service", "filter": "service.name==filter_var1 && host.name==\"mbmif.int.netways.de\"", "filter_vars": { "filter_var1": "ping4" }, "exit_status": 1, "plugin_output": "rest api test" }'
{"results":[{"code":200.0,"status":"Successfully processed check result for object 'mbmif.int.netways.de!ping4'."}]}
@dnsmichi

This comment has been minimized.

Member

dnsmichi commented Oct 16, 2018

@mphilipps please test the snapshot packages :)

@mphilipps

This comment has been minimized.

mphilipps commented Oct 16, 2018

API call works with 2.10.0+12.g3cccc9d9b.2018.10.16+1.stretch-0 on the master. All my icinga2 masters are on stretch, but presumably the code is distribution agnostic.

@dnsmichi

This comment has been minimized.

Member

dnsmichi commented Oct 16, 2018

I've tested it on macOS, it is a small bug code which has been overseen :)

@mphilipps

This comment has been minimized.

mphilipps commented Oct 17, 2018

When can we expect 2.10.1? I don't really want to include the snapshot repo on all production systems, but the lack of proper working API hurts a bit.

@dnsmichi

This comment has been minimized.

Member

dnsmichi commented Oct 17, 2018

Planning for tomorrow, still waiting for test feedback on the remaining issues targeting 2.10.1.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment