Backend not available when generating reports

493 views
Skip to first unread message

Marco Musso

unread,
May 3, 2017, 4:22:08 AM5/3/17
to Thruk
Hi Sven,
I'm getting this strange error (Backend not available) when generating reports (web interface as well cli) for a BP.
Setup is Naemon 1.0.6 + livestatus 1.0.6 with Thruk 2.14-1 talking with lmd 1.0.3 (started externally and not with use_lmd_core).

-sh-4.2$ systemctl status lmd
● lmd.service - Livestatus Multitool Daemon
   Loaded: loaded (/etc/systemd/system/lmd.service; enabled; vendor preset: disabled)
   Active: active (running) since Wed 2017-04-26 22:18:15 UTC; 6 days ago
 Main PID: 1600 (lmd)
   CGroup: /system.slice/lmd.service
           └─1600 /usr/local/bin/lmd -v --config=/etc/lmd/lmd.ini -pidfile /run/lmd/lmd.pid


This is the verbose output (ran as apache):

-sh-4.2$ THRUK_VERBOSE=4 thruk -A thrukadmin -a 'url=avail.cgi?host=UAM&service=UAM&timeperiod=last7days&csvoutput=1'
reading config file: /etc/thruk/thruk.conf
reading config file: /etc/thruk/thruk_local.d/naemon.conf
reading config file: /etc/thruk/thruk_local.conf
reading config file: /etc/thruk/cgi.cfg
[07:46:51,973][DEBUG][Thruk] logging initialized
[07:46:51,987][DEBUG][Thruk] http://localhost/thruk/cgi-bin/remote.cgi
[07:46:51,988][DEBUG][Thruk] $VAR1 = {};
[07:46:51,988][DEBUG][Thruk] checking auth
[07:46:51,988][DEBUG][Thruk] remote.cgi does not use authentication
cnt percent clk   user    sys  cuser   csys template
  1     0 %   0   0.00   0.00   0.00   0.00 passthrough.tt
[07:46:51,991][INFO][Thruk] 20035 Req: 001   mem:  33.59 MB   0.00 MB   dur: 0.004s      ----   size:    0.003 kb   stat: 200   url: remote.cgi
[07:46:51,991][DEBUG][Thruk] Profile:
+----------------------------------------------------------------------------------+-------------+
| _dispatcher: http://localhost/thruk/cgi-bin/remote.cgi                           |    0.00326s |
|   Root begin                                                                     |    0.00088s |
|     Utils::read_cgi_cfg()                                                        |    0.00002s |
|   Root end                                                                       |    0.00004s |
|   render_tt: passthrough.tt                                                      |    0.00097s |
|     render: passthrough.tt                                                       |    0.00092s |
|   _after_dispatch                                                                |    0.00010s |
+----------------------------------------------------------------------------------+-------------+
[07:46:51,992][DEBUG][Thruk] can_submit_commands: 1
[07:46:51,992][DEBUG][Thruk] _set_enabled_backends() using defaults
[07:46:51,992][DEBUG][Thruk] disabled_backends: $VAR1 = {};
[07:46:51,992][DEBUG][Thruk] livestatus: get_contactgroups_by_contact: b888b
[07:46:51,993][DEBUG][Thruk] selectall_arrayref("GET contactgroups\nColumns: name\nFilter: members >= thrukadmin", {'addpeer' => 1,'slice' => {}}, 0)
[07:46:51,993][DEBUG][Thruk] > $VAR1 = 'GET contactgroups
Columns: name
Filter: members >= thrukadmin
OutputFormat: json
ResponseHeader: fixed16
';
[07:46:51,993][DEBUG][Thruk] using new connection
[07:46:51,994][DEBUG][Thruk] header: 200           3
[07:46:51,994][DEBUG][Thruk] query status 200
[07:46:51,994][DEBUG][Thruk] status: $VAR1 = 200;
[07:46:51,994][DEBUG][Thruk] msg:    $VAR1 = 'OK. Reponse contains the queried data.';
[07:46:51,995][DEBUG][Thruk] < $VAR1 = [];
[07:46:51,996][DEBUG][Thruk] creating new user cache for thrukadmin
[07:46:51,996][DEBUG][Thruk] livestatus: get_can_submit_commands: b888b
[07:46:51,996][DEBUG][Thruk] selectall_arrayref("GET contacts\nColumns: can_submit_commands alias\nFilter: name = thrukadmin", {'addpeer' => 1,'slice' => {}}, 0)
[07:46:51,997][DEBUG][Thruk] > $VAR1 = 'GET contacts
Columns: can_submit_commands alias
Filter: name = thrukadmin
OutputFormat: json
ResponseHeader: fixed16
';
[07:46:51,997][DEBUG][Thruk] using new connection
[07:46:51,997][DEBUG][Thruk] header: 200           3
[07:46:51,997][DEBUG][Thruk] query status 200
[07:46:51,998][DEBUG][Thruk] status: $VAR1 = 200;
[07:46:51,998][DEBUG][Thruk] msg:    $VAR1 = 'OK. Reponse contains the queried data.';
[07:46:51,998][DEBUG][Thruk] < $VAR1 = [];
[07:46:51,998][DEBUG][Thruk] can_submit_commands: 1
[07:46:52,003][DEBUG][Thruk] logging initialized
[07:46:52,005][DEBUG][Thruk] $VAR1 = {
          'csvoutput' => '1',
          'host' => 'UAM',
          'service' => 'UAM',
          'timeperiod' => 'last7days'
        };
[07:46:52,005][DEBUG][Thruk] checking auth
[07:46:52,005][DEBUG][Thruk] user not authenticated yet
[07:46:52,006][DEBUG][Thruk] user authenticated as: thrukadmin
[07:46:52,008][DEBUG][Thruk] _set_enabled_backends() using defaults
[07:46:52,008][DEBUG][Thruk] disabled_backends: $VAR1 = {};
[07:46:52,008][DEBUG][Thruk] livestatus: get_processinfo: b888b
[07:46:52,008][DEBUG][Thruk] selectall_arrayref("GET status\nColumns: accept_passive_host_checks accept_passive_service_checks check_external_commands check_host_freshness check_service_freshness enable_event_handlers enable_flap_detection enable_notifications execute_host_checks execute_service_checks last_command_check last_log_rotation livestatus_version nagios_pid obsess_over_hosts obsess_over_services process_performance_data program_start program_version interval_length", {'addpeer' => 1,'rename' => {'livestatus_version' => 'data_source_version'},'slice' => {},'wrapped_json' => 0}, 0)
[07:46:52,008][DEBUG][Thruk] > $VAR1 = 'GET status
Columns: accept_passive_host_checks accept_passive_service_checks check_external_commands check_host_freshness check_service_freshness enable_event_handlers enable_flap_detection enable_notifications execute_host_checks execute_service_checks last_command_check last_log_rotation livestatus_version nagios_pid obsess_over_hosts obsess_over_services process_performance_data program_start program_version interval_length
OutputFormat: json
ResponseHeader: fixed16
';
[07:46:52,009][DEBUG][Thruk] using new connection
[07:46:52,009][DEBUG][Thruk] header: 200          78
[07:46:52,009][DEBUG][Thruk] query status 200
[07:46:52,009][DEBUG][Thruk] status: $VAR1 = 200;
[07:46:52,009][DEBUG][Thruk] msg:    $VAR1 = 'OK. Reponse contains the queried data.';
[07:46:52,010][DEBUG][Thruk] < $VAR1 = [
          [
            1,
            1,
            1,
            0,
            1,
            1,
            1,
            1,
            1,
            1,
            0,
            0,
            '1.0.6',
            365,
            0,
            0,
            1,
            '1493793955',
            '1.0.6-pkg',
            60
          ]
        ];
[07:46:52,010][DEBUG][Thruk] livestatus: get_contactgroups_by_contact: b888b
[07:46:52,011][DEBUG][Thruk] selectall_arrayref("GET contactgroups\nColumns: name\nFilter: members >= thrukadmin", {'addpeer' => 1,'slice' => {}}, 0)
[07:46:52,011][DEBUG][Thruk] > $VAR1 = 'GET contactgroups
Columns: name
Filter: members >= thrukadmin
OutputFormat: json
ResponseHeader: fixed16
';
[07:46:52,011][DEBUG][Thruk] using new connection
[07:46:52,011][DEBUG][Thruk] header: 200           3
[07:46:52,012][DEBUG][Thruk] query status 200
[07:46:52,012][DEBUG][Thruk] status: $VAR1 = 200;
[07:46:52,012][DEBUG][Thruk] msg:    $VAR1 = 'OK. Reponse contains the queried data.';
[07:46:52,012][DEBUG][Thruk] < $VAR1 = [];
[07:46:52,012][DEBUG][Thruk] creating new user cache for thrukadmin
[07:46:52,013][DEBUG][Thruk] livestatus: get_can_submit_commands: b888b
[07:46:52,013][DEBUG][Thruk] selectall_arrayref("GET contacts\nColumns: can_submit_commands alias\nFilter: name = thrukadmin", {'addpeer' => 1,'slice' => {}}, 0)
[07:46:52,013][DEBUG][Thruk] > $VAR1 = 'GET contacts
Columns: can_submit_commands alias
Filter: name = thrukadmin
OutputFormat: json
ResponseHeader: fixed16
';
[07:46:52,013][DEBUG][Thruk] using new connection
[07:46:52,014][DEBUG][Thruk] header: 200           3
[07:46:52,014][DEBUG][Thruk] query status 200
[07:46:52,014][DEBUG][Thruk] status: $VAR1 = 200;
[07:46:52,014][DEBUG][Thruk] msg:    $VAR1 = 'OK. Reponse contains the queried data.';
[07:46:52,014][DEBUG][Thruk] < $VAR1 = [];
[07:46:52,015][DEBUG][Thruk] can_submit_commands: 1
[07:46:52,030][DEBUG][Thruk] start: 1493192812 - Wed Apr 26 07:46:52 2017
[07:46:52,030][DEBUG][Thruk] end  : 1493797612 - Wed May  3 07:46:52 2017
[07:46:52,030][DEBUG][Thruk] logstart: 1492847212 - Sat Apr 22 07:46:52 2017
[07:46:52,030][DEBUG][Thruk] livestatus: get_services: b888b
[07:46:52,031][DEBUG][Thruk] selectall_arrayref("GET services\nColumns: accept_passive_checks acknowledged action_url action_url_expanded active_checks_enabled check_command check_interval check_options check_period check_type checks_enabled comments current_attempt current_notification_number description event_handler event_handler_enabled custom_variable_names custom_variable_values execution_time first_notification_delay flap_detection_enabled groups has_been_checked high_flap_threshold host_acknowledged host_action_url_expanded host_active_checks_enabled host_address host_alias host_checks_enabled host_check_type host_latency host_plugin_output host_perf_data host_current_attempt host_check_command host_comments host_groups host_has_been_checked host_icon_image_expanded host_icon_image_alt host_is_executing host_is_flapping host_name host_notes_url_expanded host_notifications_enabled host_scheduled_downtime_depth host_state host_accept_passive_checks host_last_state_change icon_image icon_image_alt icon_image_expanded is_executing is_flapping last_check last_notification last_state_change latency low_flap_threshold max_check_attempts next_check notes notes_expanded notes_url notes_url_expanded notification_interval notification_period notifications_enabled obsess_over_service percent_state_change perf_data plugin_output process_performance_data retry_interval scheduled_downtime_depth state state_type modified_attributes_list last_time_critical last_time_ok last_time_unknown last_time_warning display_name host_display_name host_custom_variable_names host_custom_variable_values in_check_period in_notification_period host_parents\nFilter: host_name = UAM\nFilter: description = UAM\nAnd: 2", {'addpeer' => 0,'callbacks' => {'last_state_change_order' => sub { "DUMMY" },'state_order' => sub { "DUMMY" }},'slice' => {}}, 0)
[07:46:52,031][DEBUG][Thruk] > $VAR1 = 'GET services
Columns: accept_passive_checks acknowledged action_url action_url_expanded active_checks_enabled check_command check_interval check_options check_period check_type checks_enabled comments current_attempt current_notification_number description event_handler event_handler_enabled custom_variable_names custom_variable_values execution_time first_notification_delay flap_detection_enabled groups has_been_checked high_flap_threshold host_acknowledged host_action_url_expanded host_active_checks_enabled host_address host_alias host_checks_enabled host_check_type host_latency host_plugin_output host_perf_data host_current_attempt host_check_command host_comments host_groups host_has_been_checked host_icon_image_expanded host_icon_image_alt host_is_executing host_is_flapping host_name host_notes_url_expanded host_notifications_enabled host_scheduled_downtime_depth host_state host_accept_passive_checks host_last_state_change icon_image icon_image_alt icon_image_expanded is_executing is_flapping last_check last_notification last_state_change latency low_flap_threshold max_check_attempts next_check notes notes_expanded notes_url notes_url_expanded notification_interval notification_period notifications_enabled obsess_over_service percent_state_change perf_data plugin_output process_performance_data retry_interval scheduled_downtime_depth state state_type modified_attributes_list last_time_critical last_time_ok last_time_unknown last_time_warning display_name host_display_name host_custom_variable_names host_custom_variable_values in_check_period in_notification_period host_parents
Filter: host_name = UAM
Filter: description = UAM
And: 2
OutputFormat: json
ResponseHeader: fixed16
';
[07:46:52,032][DEBUG][Thruk] using new connection
[07:46:52,058][DEBUG][Thruk] header: 200         915
[07:46:52,059][DEBUG][Thruk] query status 200
[07:46:52,059][DEBUG][Thruk] status: $VAR1 = 200;
[07:46:52,059][DEBUG][Thruk] msg:    $VAR1 = 'OK. Reponse contains the queried data.';
[07:46:52,059][DEBUG][Thruk] < $VAR1 = [
          [
            1,
            0,
            '',
            '',
            0,
            'check:passive',
            5,
            0,
            '24x7',
            1,
            0,
            [],
            1,
            0,
            'UAM',
            '',
            0,
            [
              'THRUK_NODE_ID',
              'THRUK_BP_ID'
            ],
            [
              'node1',
              '109'
            ],
            0,
            0,
            1,
            [
              'tag:noc',
              'tag:business_process'
            ],
            1,
            0,
            0,
            '',
            0,
            'UAM',
            'Business Process: UAM',
            0,
            1,
            0,
            'OK - business process calculation of 22 nodes complete in 0.766s',
            'runtime=0.766s',
            1,
            'check:passive',
            [],
            [
              'tag:noc',
              'tag:business_process',
              'all_hosts'
            ],
            1,
            '',
            '',
            0,
            0,
            'UAM',
            '',
            0,
            0,
            0,
            1,
            '1492695942',
            '',
            '',
            '',
            0,
            0,
            '1493797599',
            0,
            '1493757760',
            0,
            0,
            3,
            '1493797709',
            'This object is autogenerated by Business Process.',
            'This object is autogenerated by Business Process.',
            1440,
            '24x7',
            1,
            1,
            0,
            '',
            'OK - everything is fine',
            1,
            2,
            0,
            0,
            1,
            [],
            '1493245186',
            '1493797599',
            0,
            '1493757760',
            'UAM',
            'UAM',
            [
              'THRUK_NODE_ID',
              'THRUK_BP_ID'
            ],
            [
              'node1',
              '109'
            ],
            1,
            1,
            []
          ]
        ];
[07:46:52,061][DEBUG][Thruk] livestatus: get_logs: b888b
[07:46:52,062][DEBUG][Thruk] selectall_arrayref("GET log\nColumns: time type message\nFilter: time >= 1492847212\nFilter: time <= 1493797612\nAnd: 2\nFilter: host_name = UAM\nFilter: type = HOST DOWNTIME ALERT\nAnd: 2\nFilter: host_name = UAM\nFilter: type = SERVICE ALERT\nFilter: state_type = HARD\nFilter: state = 0\nOr: 2\nFilter: type = INITIAL SERVICE STATE\nFilter: state_type = HARD\nFilter: state = 0\nOr: 2\nFilter: type = CURRENT SERVICE STATE\nFilter: state_type = HARD\nFilter: state = 0\nOr: 2\nFilter: type = SERVICE DOWNTIME ALERT\nOr: 7\nAnd: 2\nOr: 2", {'addpeer' => 0,'slice' => {}}, 0)
[07:46:52,062][DEBUG][Thruk] > $VAR1 = 'GET log
Columns: time type message
Filter: time >= 1492847212
Filter: time <= 1493797612
And: 2
Filter: host_name = UAM
Filter: type = HOST DOWNTIME ALERT
And: 2
Filter: host_name = UAM
Filter: type = SERVICE ALERT
Filter: state_type = HARD
Filter: state = 0
Or: 2
Filter: type = INITIAL SERVICE STATE
Filter: state_type = HARD
Filter: state = 0
Or: 2
Filter: type = CURRENT SERVICE STATE
Filter: state_type = HARD
Filter: state = 0
Or: 2
Filter: type = SERVICE DOWNTIME ALERT
Or: 7
And: 2
Or: 2
OutputFormat: json
ResponseHeader: fixed16
';
[07:46:52,062][DEBUG][Thruk] using new connection
[07:47:22,063][DEBUG][Thruk] header: 400          49
[07:47:22,064][DEBUG][Thruk] query status 400
[07:47:22,064][ERROR][Thruk] Error in: /thruk/cgi-bin/avail.cgi
[07:47:22,065][ERROR][Thruk] The request contains an invalid header. at /usr/share/thruk/lib/Monitoring/Livestatus/Class/Lite.pm line 378.
 at /usr/lib64/thruk/perl5/Plack/Test/MockHTTP.pm line 24.
  Plack::Test::MockHTTP::try {...} () called at /usr/lib64/thruk/perl5/Try/Tiny.pm line 98
  eval {...} called at /usr/lib64/thruk/perl5/Try/Tiny.pm line 94
  Try::Tiny::try('CODE(0x2f77cd0)', 'Try::Tiny::Catch=REF(0x307d138)') called at /usr/lib64/thruk/perl5/Plack/Test/MockHTTP.pm line 27
  Plack::Test::MockHTTP::request('Plack::Test::MockHTTP=HASH(0x2d89f20)', 'HTTP::Request=HASH(0x2d7dfd8)') called at /usr/share/thruk/lib/Thruk/Utils/CLI.pm line 451
  Thruk::Utils::CLI::_dummy_c(undef, '/thruk/cgi-bin/avail.cgi?host=UAM&service=UAM&timeperiod=last...') called at /usr/share/thruk/lib/Thruk/Utils/CLI.pm line 216
  Thruk::Utils::CLI::request_url('Thruk::Context=HASH(0x307d3c0)', '/thruk/cgi-bin/avail.cgi?host=UAM&service=UAM&timeperiod=last...') called at /usr/share/thruk/lib/Thruk/Utils/CLI.pm line 1241
  Thruk::Utils::CLI::_cmd_url('Thruk::Context=HASH(0x307d3c0)', undef, 'HASH(0x12bb000)') called at /usr/share/thruk/lib/Thruk/Utils/CLI.pm line 595
  Thruk::Utils::CLI::_run_command_action('Thruk::Context=HASH(0x307d3c0)', 'HASH(0x12bb000)', 'local', 'url=avail.cgi?host=UAM&service=UAM&timeperiod=last7days&csvou...') called at /usr/share/thruk/lib/Thruk/Utils/CLI.pm line 545
  Thruk::Utils::CLI::_run_commands('Thruk::Context=HASH(0x307d3c0)', 'HASH(0x12bb000)', 'local') called at /usr/share/thruk/lib/Thruk/Utils/CLI.pm line 465
  Thruk::Utils::CLI::_from_local('Thruk::Utils::CLI=HASH(0x12bafd0)', 'Thruk::Context=HASH(0x307d3c0)', 'HASH(0x12bb000)') called at /usr/share/thruk/lib/Thruk/Utils/CLI.pm line 362
  Thruk::Utils::CLI::_run('Thruk::Utils::CLI=HASH(0x12bafd0)') called at /bin/thruk line 84
[07:47:22,065][ERROR][Thruk] No Backend available
[07:47:22,065][ERROR][Thruk] Local Core: ERROR: The request contains an invalid header.. (/var/cache/naemon/lmd.sock)
[Wed May  3 07:47:22 2017][ERROR] No Backend available
[Wed May  3 07:47:22 2017][ERROR] None of the configured Backends could be reached, please have a look at the logfile for detailed information and make sure the core is up and running.
[Wed May  3 07:47:22 2017][ERROR] Local Core: ERROR: The request contains an invalid header.. (/var/cache/naemon/lmd.sock)
No Backend available at /usr/share/thruk/lib/Thruk/Controller/error.pm line 274.
  Thruk::Controller::error::index('Thruk::Context=HASH(0x2d899e0)', 13) called at /usr/share/thruk/lib/Thruk.pm line 305
  Thruk::_dispatcher('HASH(0x2d89a40)') called at /usr/lib64/thruk/perl5/Plack/Test/MockHTTP.pm line 24
  Plack::Test::MockHTTP::try {...} () called at /usr/lib64/thruk/perl5/Try/Tiny.pm line 98
  eval {...} called at /usr/lib64/thruk/perl5/Try/Tiny.pm line 94
  Try::Tiny::try('CODE(0x2f77cd0)', 'Try::Tiny::Catch=REF(0x307d138)') called at /usr/lib64/thruk/perl5/Plack/Test/MockHTTP.pm line 27
  Plack::Test::MockHTTP::request('Plack::Test::MockHTTP=HASH(0x2d89f20)', 'HTTP::Request=HASH(0x2d7dfd8)') called at /usr/share/thruk/lib/Thruk/Utils/CLI.pm line 451
  Thruk::Utils::CLI::_dummy_c(undef, '/thruk/cgi-bin/avail.cgi?host=UAM&service=UAM&timeperiod=last...') called at /usr/share/thruk/lib/Thruk/Utils/CLI.pm line 216
  Thruk::Utils::CLI::request_url('Thruk::Context=HASH(0x307d3c0)', '/thruk/cgi-bin/avail.cgi?host=UAM&service=UAM&timeperiod=last...') called at /usr/share/thruk/lib/Thruk/Utils/CLI.pm line 1241
  Thruk::Utils::CLI::_cmd_url('Thruk::Context=HASH(0x307d3c0)', undef, 'HASH(0x12bb000)') called at /usr/share/thruk/lib/Thruk/Utils/CLI.pm line 595
  Thruk::Utils::CLI::_run_command_action('Thruk::Context=HASH(0x307d3c0)', 'HASH(0x12bb000)', 'local', 'url=avail.cgi?host=UAM&service=UAM&timeperiod=last7days&csvou...') called at /usr/share/thruk/lib/Thruk/Utils/CLI.pm line 545
  Thruk::Utils::CLI::_run_commands('Thruk::Context=HASH(0x307d3c0)', 'HASH(0x12bb000)', 'local') called at /usr/share/thruk/lib/Thruk/Utils/CLI.pm line 465
  Thruk::Utils::CLI::_from_local('Thruk::Utils::CLI=HASH(0x12bafd0)', 'Thruk::Context=HASH(0x307d3c0)', 'HASH(0x12bb000)') called at /usr/share/thruk/lib/Thruk/Utils/CLI.pm line 362
  Thruk::Utils::CLI::_run('Thruk::Utils::CLI=HASH(0x12bafd0)') called at /bin/thruk line 84
cnt percent clk   user    sys  cuser   csys template
  1    50 %   0   0.01   0.00   0.00   0.00 side.tt
  1    49 %   0   0.01   0.00   0.00   0.00 _common_js.tt
  1     0 %   0   0.00   0.00   0.00   0.00 _side_js.tt
  1     0 %   0   0.00   0.00   0.00   0.00 _common_css.tt
  1     0 %   0   0.00   0.00   0.00   0.00 _ajax_search.tt
  1     0 %   0   0.00   0.00   0.00   0.00 _header_initial_states.tt
  1     0 %   0   0.00   0.00   0.00   0.00 _header_sites.tt
  1     0 %   0   0.00   0.00   0.00   0.00 extra_headers.tt
  1     0 %   0   0.00   0.01   0.00   0.00 _infobox.tt
  1     0 %   0   0.00   0.00   0.00   0.00 _common_js_files.tt
  1     0 %   0   0.00   0.00   0.00   0.00 _header.tt
  1     0 %   0   0.00   0.00   0.00   0.00 _common_js_bugs.tt
  1     0 %   0   0.00   0.00   0.00   0.00 _header_broadcast.tt
  1     0 %   0   0.00   0.00   0.00   0.00 _footer.tt
  1     0 %   0   0.00   0.00   0.00   0.00 error.tt
[07:47:22,095][INFO][Thruk] 20035 Req: 002   mem:  38.03 MB   4.19 MB   dur:30.091s (30.038s)   size:   54.733 kb   stat: 500   url: avail.cgi?host=UAM&service=UAM&timeperiod=last7days&csvoutput=1
[07:47:22,096][DEBUG][Thruk] Profile:
+----------------------------------------------------------------------------------+-------------+
|   Root begin                                                                     |    0.00141s |
|     Utils::read_cgi_cfg()                                                        |    0.00002s |
|   AddDefaults::add_defaults                                                      |    0.00958s |
|     AddDefaults::get_proc_info                                                   |    0.00485s |
|       AddDefaults::set_processinfo                                               |    0.00475s |
|         AddDefaults::set_processinfo fetch                                       |    0.00249s |
|           _do_on_peers(get_processinfo)                                          |    0.00212s |
|             _get_result_serial(get_processinfo)                                  |    0.00192s |
|             _merge_answer()                                                      |    0.00003s |
|         _do_on_peers(get_contactgroups_by_contact)                               |    0.00159s |
|           _get_result_serial(get_contactgroups_by_contact)                       |    0.00142s |
|           _merge_answer()                                                        |    0.00001s |
|     Thruk::Utils::set_dynamic_roles                                              |    0.00199s |
|       _do_on_peers(get_can_submit_commands)                                      |    0.00147s |
|         _get_result_serial(get_can_submit_commands)                              |    0.00131s |
|         _merge_answer()                                                          |    0.00001s |
|     Utils::Menu::read_navigation()                                               |    0.00224s |
|   _do_on_peers(get_services)                                                     |    0.03042s |
|     _get_result_serial(get_services)                                             |    0.03018s |
|     _merge_answer()                                                              |    0.00003s |
|   avail.pm updatecache                                                           |    0.00002s |
|   avail.pm fetchlogs                                                             |  ~30.03428s |
|     _do_on_peers(get_logs)                                                       |  ~30.03425s |
|       _get_result_serial(get_logs)                                               |   30.00321s |
|       Utils::Menu::read_navigation()                                             |    0.00251s |
|       Root end                                                                   |    0.00017s |
|       render_tt: error.tt                                                        |    0.02576s |
|         render: error.tt                                                         |    0.02544s |
|       total time waited on backends: 30.04s                                      |             |
|       _after_dispatch                                                            |    0.00010s |
+----------------------------------------------------------------------------------+-------------+
request failed: 500 - internal error, please consult your logfiles
-sh-4.2$ 

In thruk.log (job id may differ but the log is the same as the previous verbose output):

[2017/05/03 08:03:44][naemon.flatns.net][ERROR][Thruk] The request contains an invalid header. at /usr/share/thruk/lib/Monitoring/Livestatus/Class/Lite.pm line 378.
[2017/05/03 08:03:44][naemon.flatns.net][ERROR][Thruk] Background Job Failed

This is the same for non-BP reports of course.
I'm trying to replicate in our dev environment so maybe I can give you more info...

TIA

Marco Musso

unread,
May 3, 2017, 5:31:43 AM5/3/17
to Thruk
Same with Thruk 2.15-20170428. Seems triggered starting from "Last 7 days" but could be just be >3 days since "This week" works :)

Marco Musso

unread,
May 3, 2017, 8:15:03 AM5/3/17
to Thruk
Bypassing lmd and using livestatus directly seems to work.


On Wednesday, May 3, 2017 at 10:22:08 AM UTC+2, Marco Musso wrote:

Sven Nierlein

unread,
May 4, 2017, 3:50:51 AM5/4/17
to th...@googlegroups.com
On 03/05/17 14:15, Marco Musso wrote:
> Bypassing lmd and using livestatus directly seems to work.
>

Please have a look at your lmd logfile. It should contain some details about what is missing.

Cheers,
Sven

Marco Musso

unread,
May 4, 2017, 4:18:21 AM5/4/17
to Thruk
With log level Warn I only see normal incoming requests for the usual tables (host, services, ...) and switch to idle and so on, no evident errors.
I will test with an higher log level asap.

BTW: what is the correct way to logrotate the LMD logfile (to write a proper logrotate conf)?

Marco Musso

unread,
May 9, 2017, 9:40:47 AM5/9/17
to Thruk
Even with 

LogLevel        = "Trace"

(and "Debug") I only see Info lines and normal activity... and the usual:

[13:20:11,573][ERROR][Thruk] No Backend available
[13:20:11,573][ERROR][Thruk] Local Core: ERROR: The request contains an invalid header.. (/var/cache/naemon/lmd.sock)
No Backend available at /usr/share/thruk/lib/Thruk/Controller/error.pm line 274.
  Thruk::Controller::error::index('Thruk::Context=HASH(0x4369658)', 13) called at /usr/share/thruk/lib/Thruk.pm line 309
  Thruk::_dispatcher('HASH(0x4365328)') called at /usr/lib64/thruk/perl5/Plack/Test/MockHTTP.pm line 24
  Plack::Test::MockHTTP::try {...} () called at /usr/lib64/thruk/perl5/Try/Tiny.pm line 98
  eval {...} called at /usr/lib64/thruk/perl5/Try/Tiny.pm line 94
  Try::Tiny::try('CODE(0x4369898)', 'Try::Tiny::Catch=REF(0x411d7e0)') called at /usr/lib64/thruk/perl5/Plack/Test/MockHTTP.pm line 27
  Plack::Test::MockHTTP::request('Plack::Test::MockHTTP=HASH(0x4365310)', 'HTTP::Request=HASH(0x4365508)') called at /usr/share/thruk/lib/Thruk/Utils/CLI.pm line 480
  Thruk::Utils::CLI::_dummy_c(undef, '/thruk/cgi-bin/avail.cgi?host=PL_HD_H2&service=PL_HDTr...') called at /usr/share/thruk/lib/Thruk/Utils/CLI.pm line 216
  Thruk::Utils::CLI::request_url('Thruk::Context=HASH(0x411da08)', '/thruk/cgi-bin/avail.cgi?host=PL_HD_H2&service=PL_HDTr...') called at /usr/share/thruk/lib/Thruk/Utils/CLI.pm line 1270
  Thruk::Utils::CLI::_cmd_url('Thruk::Context=HASH(0x411da08)', undef, 'HASH(0x2522210)') called at /usr/share/thruk/lib/Thruk/Utils/CLI.pm line 624
  Thruk::Utils::CLI::_run_command_action('Thruk::Context=HASH(0x411da08)', 'HASH(0x2522210)', 'local', 'url=avail.cgi?host=PL_HD_H2&service=PL_HD_H2&ti...') called at /usr/share/thruk/lib/Thruk/Utils/CLI.pm line 574
  Thruk::Utils::CLI::_run_commands('Thruk::Context=HASH(0x411da08)', 'HASH(0x2522210)', 'local') called at /usr/share/thruk/lib/Thruk/Utils/CLI.pm line 494
  Thruk::Utils::CLI::_from_local('Thruk::Utils::CLI=HASH(0x25221e0)', 'Thruk::Context=HASH(0x411da08)', 'HASH(0x2522210)') called at /usr/share/thruk/lib/Thruk/Utils/CLI.pm line 383
  Thruk::Utils::CLI::_run('Thruk::Utils::CLI=HASH(0x25221e0)') called at /bin/thruk line 84
request failed: 500 - internal error, please consult your logfiles

Everything is fine if go directly to livestatus (even without STATEHIST if Thruk computes the availability)...

Sven Nierlein

unread,
May 9, 2017, 3:05:02 PM5/9/17
to th...@googlegroups.com
There should be something in the lmd logfile. Please also make sure you use the latest packages.

Cheers,
Sven
> --
> You received this message because you are subscribed to the Google Groups "Thruk" group.
> To unsubscribe from this group and stop receiving emails from it, send an email to thruk+un...@googlegroups.com <mailto:thruk+un...@googlegroups.com>.
> For more options, visit https://groups.google.com/d/optout.

Marco Musso

unread,
May 10, 2017, 4:01:50 AM5/10/17
to Thruk
Ok, I got something out of the logs.

First of all the setup:
- recompiled lmd from master with go1.8.1
- thruk-2.15-20170505.x86_64

Then I discovered that the LogLevel settings in the ini file isn't honored: I have to start lmd with -vv or -vvv to get Debug/Trace (I don't ).
Anyway, in debug mode (trace is too verbose but I can provide it via PM if needed):

[...]
[2017-05-10 07:46:42][Debug][peer.go:489] [Naemon] delta update complete in: 138.118768ms
[2017-05-10 07:46:44][Debug][peer.go:1023] [Naemon] connection error /var/cache/naemon/live: read unix @->/var/cache/naemon/live: i/o timeout
[2017-05-10 07:46:44][Debug][peer.go:1045] [Naemon] last online: 2017-05-10 07:46:42 +0000 UTC
[2017-05-10 07:46:44][Debug][response.go:562] waiting for passed through requests done
[2017-05-10 07:46:44][Warn][response.go:372] client error: read unix @->/var/cache/naemon/live: i/o timeout
[2017-05-10 07:46:47][Debug][peer.go:815] [Naemon] got status answer: size: 0 kB
[2017-05-10 07:46:47][Debug][peer.go:815] [Naemon] got hosts answer: size: 156 kB
[2017-05-10 07:46:47][Debug][peer.go:815] [Naemon] got hosts answer: size: 1278 kB
[2017-05-10 07:46:47][Debug][peer.go:542] [Naemon] updated 4105 hosts
[2017-05-10 07:46:47][Debug][peer.go:815] [Naemon] got services answer: size: 1101 kB
[2017-05-10 07:46:48][Debug][peer.go:815] [Naemon] got services answer: size: 10459 kB
[2017-05-10 07:46:49][Debug][peer.go:587] [Naemon] updated 15058 services
[2017-05-10 07:46:49][Debug][peer.go:815] [Naemon] got comments answer: size: 0 kB
[2017-05-10 07:46:49][Debug][peer.go:694] [Naemon] comments did not change
[2017-05-10 07:46:49][Debug][peer.go:815] [Naemon] got downtimes answer: size: 0 kB
[2017-05-10 07:46:49][Debug][peer.go:694] [Naemon] downtimes did not change
[2017-05-10 07:46:49][Debug][peer.go:489] [Naemon] delta update complete in: 1.71399742s
[2017-05-10 07:46:49][Info][peer.go:491] [Naemon] site soft recovered from short outage

and for the sake of completeness:

# systemctl status naemon| grep Active
   Active: active (running) since wo 2017-05-10 06:20:29 UTC; 1h 28min ago
# sestatus | grep Current
Current mode:                   permissive
# ll /var/cache/naemon/
total 0
srw-rw----. 1 naemon naemon 0 10 mei 06:20 live
srw-rw----. 1 naemon naemon 0 10 mei 07:46 lmd.sock
prw-rw----. 1 naemon naemon 0 10 mei 07:50 naemon.cmd

And apache is in the naemon group so access is granted.
Naemon wasn't restarted and the livestatus socket should have been accessible.

What could lead to the unix socket not being available in your opinion?

TIA

Sven Nierlein

unread,
May 11, 2017, 5:24:49 AM5/11/17
to th...@googlegroups.com
Hi,

I assume you are not using thruks logcache feature? If not, you probably have to increase the net timeout value in the lmd.ini because
log requests can take a while.

Cheers,
Sven


On 10.05.2017 10:01, Marco Musso wrote:
> Ok, I got something out of the logs.
>
> First of all the setup:
> - recompiled lmd from master with go1.8.1
> - thruk-2.15-20170505.x86_64
>
> Then I discovered that the LogLevel settings in the ini file isn't honored: I have to start lmd with -vv or -vvv to get Debug/Trace (I don't ).
> Anyway, in debug mode (trace is too verbose but I can provide it via PM if needed):
>
> [...]
> [2017-05-10 07:46:42][Debug][peer.go:489] [Naemon] delta update complete in: 138.118768ms
> *[2017-05-10 07:46:44][Debug][peer.go:1023] [Naemon] connection error /var/cache/naemon/live: read unix @->/var/cache/naemon/live: i/o timeout*
> [2017-05-10 07:46:44][Debug][peer.go:1045] [Naemon] last online: 2017-05-10 07:46:42 +0000 UTC
> [2017-05-10 07:46:44][Debug][response.go:562] waiting for passed through requests done
> *[2017-05-10 07:46:44][Warn][response.go:372] client error: read unix @->/var/cache/naemon/live: i/o timeout*
> > [13:20:11,573][ERROR][Thruk] on page: http://localhost/thruk/cgi-bin/avail.cgi?host=PL_HD_H2&service=PL_HD_H2&timeperiod=lastmonth&csvoutput=1 <http://localhost/thruk/cgi-bin/avail.cgi?host=PL_HD_H2&service=PL_HD_H2&timeperiod=lastmonth&csvoutput=1>
> > [13:20:11,573][ERROR][Thruk] Local Core: ERROR: The request contains an invalid header.. (/var/cache/naemon/lmd.sock)
> > No Backend available at /usr/share/thruk/lib/Thruk/Controller/error.pm <http://error.pm> line 274.
> > To unsubscribe from this group and stop receiving emails from it, send an email to thruk+un...@googlegroups.com <javascript:> <mailto:thruk+un...@googlegroups.com <javascript:>>.
> > For more options, visit https://groups.google.com/d/optout <https://groups.google.com/d/optout>.

Marco Musso

unread,
May 11, 2017, 5:30:58 AM5/11/17
to Thruk


On Thursday, May 11, 2017 at 11:24:49 AM UTC+2, Sven Nierlein wrote:
Hi,

I assume you are not using thruks logcache feature? If not, you probably have to increase the net timeout value in the lmd.ini because
log requests can take a while.


Well Thruk is using LMD locally installed and pointing to its socket file.

Thruk -> LMD (docket file) -> livestatus (socket file) -> Naemon

LMD is started as a separate service under systemd.

Sven Nierlein

unread,
May 11, 2017, 5:36:21 AM5/11/17
to th...@googlegroups.com
Whats the reason for LMD when you are using one local backend? Or does it connect multiple backends?
Anyway, when not using thruks logcache, you have to increase the nettimeout value in your lmd.ini.

Cheers,
Sven

Marco Musso

unread,
May 11, 2017, 5:40:39 AM5/11/17
to Thruk

Whats the reason for LMD when you are using one local backend? Or does it connect multiple backends?

Because when the backend restarts to pick up new config livestatus goes away for the time needed for Naemon to restart.
 
Anyway, when not using thruks logcache, you have to increase the nettimeout value in your lmd.ini.

Ok, I'll try to increase that from the actual 30s to something higher...

Marco Musso

unread,
May 12, 2017, 4:49:31 AM5/12/17
to Thruk
Increasing NetTimeout from 30 to 300 did the trick. The "No backend available" was misleading.

Marco Musso

unread,
Aug 28, 2017, 11:13:17 AM8/28/17
to Thruk
Hi Sven, 

I'm running into this problem again even after increasing NetTimeout to 600s.

The actual job terminates after about 180s which is also confirmed by the lmd log:

[2017-08-28 14:51:38][Warn][response.go:406] write error: write unix /var/cache/naemon/lmd.sock->@: use of closed network connection
[2017-08-28 14:51:38][Warn][response.go:414] write error: write unix /var/cache/naemon/lmd.sock->@: use of closed network connection
[2017-08-28 14:51:38][Warn][response.go:417] write error: written 0, size: 3857272
[2017-08-28 14:51:38][Info][listener.go:100] incoming log request from @ to /var/cache/naemon/lmd.sock finished in 3m6.580010007s, size: 3766.867 kB

LMD 1.1.1
Thruk 2.16-2

Any idea on why this happens?

TIA

Sven Nierlein

unread,
Aug 29, 2017, 6:21:47 AM8/29/17
to th...@googlegroups.com, Marco Musso
Well, i guess the answer here is using the logcache.

Marco Musso

unread,
Aug 29, 2017, 7:11:19 AM8/29/17
to Thruk, senp...@gmail.com
So that means that LMD is not suitable to be the only place to do livestatus queries and should be used only as a cache for Thruk?

Because we were ok in using livestatus caching a lot of messages (memory is not a problem) just during the report calculation and we hoped to use LMD to shield us from the core restarts...

If I should rephrase that I might say that Thruk+LMD without logcache isn't able to do availability reports for periods of more than a few days...

Cheers

Sven Nierlein

unread,
Aug 29, 2017, 7:19:00 AM8/29/17
to th...@googlegroups.com, Marco Musso
On 29/08/17 13:11, Marco Musso wrote:
> Because we were ok in using livestatus caching a lot of messages (memory is not a problem) just during the report calculation and we hoped to use LMD to shield us from the core restarts...


Lets say thay LMD is a cache for live data and the logcache is a cache for logfile data. So in bigger setups, you should use both.
Or you could just increase the timeout even more.

Cheers,
Sven

Marco Musso

unread,
Aug 29, 2017, 7:28:03 AM8/29/17
to Thruk, senp...@gmail.com
I'll try to increase the timeout which is already at 600s ...
Currently I can use a different &backend= to use livestatus instead of LMD and it works but then some reports will fail on livestatus unavailability, I can just rerun those (I did that as well with livestatus before naemon-livestatus).

Cheers,
Reply all
Reply to author
Forward
0 new messages