Clicking "Logs" for host or service fails

csammons0x1c commented 5 years ago

Describe the bug Clicking on '(Logs)' next to "View Alert History For This Service" for a host or service fails with the following error:

nagios: ERROR: 400: The request contains an invalid header. - Filter: Unexpected escape character. (X.X.X.X:6557)

This issue appears to be similar to issues #894 and #917 although these only seem to have addressed an escaped character in history.pm. This fix is already in place in the 2.28-1 version of Thruk and has no impact on this particular issue.

Thruk Version Thruk 2.28-1 Livestatus 1.5.0p19 Nagios 4.4.3

To Reproduce Steps to reproduce the behavior:

Go to the page for any host or service.
Click on '(Logs)' next to "View Alert History For This Service".

Expected behavior This should display log history for the host or service.

Desktop Chrome 75.0.3770.142 Firefox 68.0.1 (64-bit)

Additional context

Livestatus log shows the following:

2019-07-17 16:09:52 [client 4] error: Filter: Unexpected escape character.
2019-07-17 16:09:52 [client 4] error: And: error combining filters for table 'log': expected 3 filters, but only 2 are on stack

Thruk debug log shows the following:

[2019/07/22 15:53:57][host1][DEBUG] livestatus: get_logs: 8e519
[2019/07/22 15:53:57][host1][DEBUG] selectall_arrayref("GET log\nColumns: class time type state host_name service_description plugin_output message options state_type contact_name\nFilter: time >= 1563771600\nFilter: time <= 1563858000\nFilter: host_name = wan-corpoffice\nFilter: service_description = ping\nAnd: 2\nFilter: type = EXTERNAL COMMAND\nFilter: message ~~ (\s|;)wan\-corpoffice;ping(;|$)\nAnd: 2\nOr: 2\nAnd: 3", {'addpeer' => 0,'slice' => {}}, 0)
[2019/07/22 15:53:57][host1][DEBUG] > $VAR1 = 'GET log
Columns: class time type state host_name service_description plugin_output message options state_type contact_name
Filter: time >= 1563771600
Filter: time <= 1563858000
Filter: host_name = wan-corpoffice
Filter: service_description = ping
And: 2
Filter: type = EXTERNAL COMMAND
Filter: message ~~ (\\s|;)wan\\-corpoffice;ping(;|$)
And: 2
Or: 2
And: 3
OutputFormat: json
ResponseHeader: fixed16
';
[2019/07/22 15:53:57][host1][DEBUG] using new connection
[2019/07/22 15:54:00][host1][DEBUG] header: 400          37
[2019/07/22 15:54:00][host1][DEBUG] query status 400
[2019/07/22 15:54:00][host1][DEBUG] selectall_arrayref("GET log\nColumns: class time type state host_name service_description plugin_output message options state_type contact_name\nFilter: time >= 1563771600\nFilter: time <= 1563858000\nFilter: host_name = wan-corpoffice\nFilter: service_description = ping\nAnd: 2\nFilter: type = EXTERNAL COMMAND\nFilter: message ~~ (\s|;)wan\-corpoffice;ping(;|$)\nAnd: 2\nOr: 2\nAnd: 3", {'addpeer' => 0,'slice' => {}}, 0)
[2019/07/22 15:54:00][host1][DEBUG] > $VAR1 = 'GET log
Columns: class time type state host_name service_description plugin_output message options state_type contact_name
Filter: time >= 1563771600
Filter: time <= 1563858000
Filter: host_name = wan-corpoffice
Filter: service_description = ping
And: 2
Filter: type = EXTERNAL COMMAND
Filter: message ~~ (\\s|;)wan\\-corpoffice;ping(;|$)
And: 2
Or: 2
And: 3
OutputFormat: json
ResponseHeader: fixed16
';
[2019/07/22 15:54:00][host1][INFO]  1666 Req: 237   mem:  67.89 MB   0.00 MB   dur: 3.196s  (3.154s/0.022s)   size:   30.001 kb   stat: 200   url: showlog.cgi?host=wan-corpoffice&service=ping
[2019/07/22 15:54:00][host1][DEBUG] Profile:
+----------------------------------------------------------------------------------+-------------+
| _dispatcher: https://dco-portal.ed.lan/thruk/cgi-bin/showlog.cgi?host=wan-       |    3.19397s |
|   time: Mon Jul 22 15:53:57 2019 - host: host1 - pid: 1666 - req: 237            |             |
|   Root begin                                                                     |    0.00523s |
|     Utils::read_cgi_cfg()                                                        |    0.00007s |
|     User::set_dynamic_attributes                                                 |    0.00078s |
|   Thruk::Controller::showlog::index                                              |    3.16104s |
|     AddDefaults::add_defaults                                                    |    0.10209s |
|       AddDefaults::get_proc_info                                                 |    0.10025s |
|         AddDefaults::set_processinfo                                             |    0.09983s |
|           AddDefaults::set_processinfo fetch                                     |    0.09952s |
|             _do_on_peers(get_processinfo)                                        |    0.09840s |
|               _get_result_serial(get_processinfo)                                |    0.09782s |
|               _merge_answer()                                                    |    0.00007s |
|     showlog::updatecache                                                         |    0.00007s |
|     showlog::fetch                                                               |    3.05814s |
|       _do_on_peers(get_logs)                                                     |    3.05781s |
|         _get_result_serial(get_logs)                                             |    3.05632s |
|         _merge_answer()                                                          |    0.00020s |
|         _sort()                                                                  |    0.00016s |
|   Root end                                                                       |    0.00036s |
|   render_tt: showlog.tt                                                          |    0.02216s |
|     render: showlog.tt                                                           |    0.02173s |
|   total time waited on backends:  3.15s                                          |             |
|   total time waited on rendering: 0.02s                                          |             |
|   render: _internal_stats.tt                                                     |    0.00120s |
|   _after_dispatch                                                                |    0.00002s |
+----------------------------------------------------------------------------------+-------------+

Sending the above query directly to the livestatus socket is successful and does not give the 400 error response code.

$ cat query.txt
GET log
Columns: class time type state host_name service_description plugin_output message options state_type contact_name
Filter: time >= 1563771600
Filter: time <= 1563858000
Filter: host_name = wan-corpoffice
Filter: service_description = ping
And: 2
Filter: type = EXTERNAL COMMAND
Filter: message ~~ (\\s|;)wan\\-corpoffice;ping(;|$)
And: 2
Or: 2
And: 3
OutputFormat: json
ResponseHeader: fixed16

$ unixcat < query.txt /usr/local/nagios/var/rw/live
200           3
[]

sni commented 5 years ago

this has been fixed meanwhile, please update to the latest stable release.

csammons0x1c commented 5 years ago

Thank you for your reply. Could you please tell me what the fix is? I've just updated to version 2.30-3 but testing displays the same behavior as before when clicking "(Logs)".

sni commented 5 years ago

let me double check, maybe its a new issue. Does this happen for all hosts and services?

csammons0x1c commented 5 years ago

I have two backends:

Nagios 4.4.3 / Livestatus 1.5.0p19
Nagios 3.5.1 / Livestatus 1.2.2p2

This issue happens for all hosts and services to backend 1.

sni commented 5 years ago

have you recently updated livestatus? I heard of some issues with livestatus 1.5. Cannot reproduce it right now with naemons livestatus anyway.

csammons0x1c commented 5 years ago

Yes, I updated from Livestatus 1.2.2p2 as that version was too old for Nagios v4. So far I have tried Livestatus 1.5.0p18 and 1.5.0p19.

sni commented 5 years ago

if i remember correclty, 1.4 worked ok.

csammons0x1c commented 5 years ago

I downgraded to Livestatus 1.4.0p38 and the issue was resolved.

Thank you for your help!

sni commented 5 years ago

great :-)

sni / Thruk

Clicking "Logs" for host or service fails #959