Any screen with supposed graphs times out with "Backend unavailable"

Hi I pulled the graphite module from github yesterday. For graphite-web and carbon I am using the RPMs.
python-carbon-0.9.16-1.el7.noarch
graphite-web-0.9.16-3.el7.noarch
Any page, that is supposed to show graphics, is timing out.

“Backend unavailable
It seems that the PHP FPM service is not running. Make sure to start PHP FPM service in order to access Icinga Web 2. If you upgraded Icinga Web 2 recently, make sure to read the docs regarding PHP FPM, also locally available under /usr/share/icingaweb2/doc/02-Installation.md.”

The listener.log of carbon is a little bit more informative:
16/09/2019 22:32:34 :: MetricLineReceiver connection with 127.0.0.1:37888 established
16/09/2019 22:32:34 :: invalid line (GET /metrics/expand?query=icinga2.vdb3.services.Galera.check-galera.perfdata.%2A.value HTTP/1.1^M) received from client 127.0.0.1:37888, ignoring
16/09/2019 22:32:34 :: invalid line (User-Agent: icingaweb2-module-graphite^M) received from client 127.0.0.1:37888, ignoring
16/09/2019 22:32:34 :: invalid line (Authorization: Basic aWNpbmdhOmljaXNjaGltbWVs^M) received from client 127.0.0.1:37888, ignoring
16/09/2019 22:32:34 :: invalid line (Host: 127.0.0.1:2003^M) received from client 127.0.0.1:37888, ignoring
16/09/2019 22:32:34 :: invalid line (^M) received from client 127.0.0.1:37888, ignoring
16/09/2019 22:32:41 :: MetricLineReceiver connection with 127.0.0.1:37902 established
16/09/2019 22:32:41 :: invalid line (GET /metrics/expand?query=icinga2.vdb3.services.Galera.check-galera.perfdata.%2A.value HTTP/1.1^M) received from client 127.0.0.1:37902, ignoring
16/09/2019 22:32:41 :: invalid line (User-Agent: icingaweb2-module-graphite^M) received from client 127.0.0.1:37902, ignoring
16/09/2019 22:32:41 :: invalid line (Authorization: Basic aWNpbmdhOmljaXNjaGltbWVs^M) received from client 127.0.0.1:37902, ignoring
16/09/2019 22:32:41 :: invalid line (Host: 127.0.0.1:2003^M) received from client 127.0.0.1:37902, ignoring
16/09/2019 22:32:41 :: invalid line (^M) received from client 127.0.0.1:37902, ignoring

Is there still a Problem with the backend configuration?
Any help will be appreciated.

Hi and welcome to the community,

just a shot in the blue as I don’t use the graphite module but it looks like you edited the configuration file from a Windows system and have the windows carriage return characters (^M) at the end of each config parameter.

Please remove them and see if that helps.

Cheers,
Marcel

2 Likes

dos2unix is a handy tool for this.

Actually I am all Linux.
[root@mo1 share]# cat -A /etc/icinga2/features-enabled/graphite.conf
/**$

  • The GraphiteWriter type writes check result metrics and$
  • performance data to a graphite tcp socket.$
    */$
    $
    library “perfdata”$
    $
    object GraphiteWriter “graphite” {$
    ^Ihost = “127.0.0.1”$
    ^Iport = 2003$
    enable_send_thresholds = true$
    }$
    That doesn’t look mircosoftish to me. I assume, that the problem is somewhere else.

Those ^M chars are carriage return line feed characters sourcing from Windows editors, an erroneous character interpreted by Linux. That happens when you edit the file on Windows and upload it e.g. via scp. Therefore it is advised to run dos2unix <filename> in your Linux terminal to convert these line feeds for the Linux world.

That’s something I understand. But I can guarantee you, that I never edited any file with Windows within the last 28 years.
The ^M also doesn’t come from a file directly. It is the communication with the carbon listener.
Checking config files and code:
I created a testfile in /etc/carbon as a false positive:
[root@mo1 etc]# for i in find . -type f ; do file $i | grep CRLF ; done
./trusted-key.key: ASCII text, with very long lines, with CRLF line terminators
./carbon/testfile: ASCII text, with CRLF line terminators
[root@mo1 etc]# for i in rpm -ql python-carbon; do file $i | grep CRLF; done
[root@mo1 etc]# for i in rpm -ql graphite-web; do file $i | grep CRLF; done
[root@mo1 etc]# for i in rpm -ql python-whisper; do file $i | grep CRLF; done
So none of the files in any RPM is in DOS format.
And neither is any of the module from github:
[root@mo1 etc]# for i in find /usr/share/icingaweb2/modules/graphite -type f ; do file $i | grep CRLF ; done

I also tried to feed two different data lines into carbon:
[root@mo1 ~]# cat -A dosfile
local.random.diceroll 4 1568742309^M$
[root@mo1 ~]# cat unixfile | nc 127.0.0.1 2003
[root@mo1 ~]# cat dosfile | nc 127.0.0.1 2003
[root@mo1 ~]#
unixfile is the same content without CRLF.
The corresponding listener log is:
17/09/2019 19:47:50 :: MetricLineReceiver connection with 127.0.0.1:54246 established
17/09/2019 19:47:50 :: MetricLineReceiver connection with 127.0.0.1:54246 closed cleanly
17/09/2019 19:47:59 :: MetricLineReceiver connection with 127.0.0.1:54248 established
17/09/2019 19:47:59 :: MetricLineReceiver connection with 127.0.0.1:54248 closed cleanly
Seems to be accepted with or without ^M
Nevertheless communication doesn’t work with the icinga module.

Ok, weird. Then lets focus on the FPM problem and leave graphite aside.

Depending on your distribution, try restarting the php-fpm service and check whether this solves the problem.

Hi Michael, many thanks for your help.
did so. Also increased log level to debug in php-fpm.conf.
When I click onto any entry that should create a graph, then there is an entry in the php-fm error log:
[18-Sep-2019 13:23:54.498233] DEBUG: pid 16940, fpm_children_make(), line 421: [pool www] child 17019 started
[18-Sep-2019 13:23:54.498268] DEBUG: pid 16940, fpm_pctl_perform_idle_server_maintenance(), line 427: [pool www] 1 child(ren) have been created dynamically
But nothing else and the Web Server responds again with the “Backend unavailable” page.

Ok, then you are one step further. PHP FPM is used to serve specific page requests, and this one looks into rendering the detail view including the Graphite.

FPM allows you to configure more verbose log levels, also php.ini in there should be increased. Maybe it is just a memory exhausted limit, or you’re hitting a crash - use dmesg and syslog for this specific entry. The icingaweb2 debug log would also be interesting.

Cheers,
Michael

php-fpm.ini: log_level = debug
php.ini:
error_reporting = E_ALL
log_errors = On
[root@mo1 icinga2]# icinga2 feature list
Disabled features: compatlog elasticsearch gelf influxdb livestatus opentsdb perfdata statusdata syslog
Enabled features: api checker command debuglog graphite ido-mysql mainlog notification
icingaweb2/config.ini:
[logging]
log = “syslog”
level = “DEBUG”
So still I get the “Backend unavailable” page.
The debug log from icinga2 shows lots of activity but nothing related to the error. At least I can see that GraphWriter does its job.
E.g.: [2019-09-18 18:49:33 +0200] debug/GraphiteWriter: Add to metric list:‘icinga2.wfe03.services.SMTP.smtp.perfdata.time.value 0.032765 1568825373’.
Syslog doesn’t list anything, which is strange, because there is no log from icingaweb2 at all.
I did restart httpd and php-fpm. Shouldn’t there be at least something in syslog from icingaweb2?
So the only location, where something is being logged seems to be the listener.log of carbon:
8/09/2019 18:44:48 :: MetricLineReceiver connection with 127.0.0.1:45622 established
18/09/2019 18:44:48 :: invalid line (GET /metrics/expand?query=icinga2.wfe02.services.lvs-kiss.http.perfdata.size.value HTTP/1.1^M) received from client 127.0.0.1:45622, ignoring
18/09/2019 18:44:48 :: invalid line (User-Agent: icingaweb2-module-graphite^M) received from client 127.0.0.1:45622, ignoring
18/09/2019 18:44:48 :: invalid line (Authorization: Basic aWNpbmdhOmljaXNjaGltbWVs^M) received from client 127.0.0.1:45622, ignoring
18/09/2019 18:44:48 :: invalid line (Host: 127.0.0.1:2003^M) received from client 127.0.0.1:45622, ignoring
18/09/2019 18:44:48 :: invalid line (^M) received from client 127.0.0.1:45622, ignoring
Which to me says: “I don’t speak your language”.
The www.access.log from php.ini just has entries of:
127.0.0.1 - 18/Sep/2019:18:44:43 +0200 “GET /icingaweb2/index.php” 200
The only entries in php-fpm/error.log look like this:
[18-Sep-2019 18:44:41.999692] DEBUG: pid 25136, fpm_pctl_perform_idle_server_maintenance(), line 378: [pool www] currently 1 active children, 6 spare children, 7 running children. Spawning rate 1

Just changed the logging of icingaweb2 to file:
logging]

log = “syslog”

log = “file”
file = “/var/log/icingaweb2/debug.log”
level = “DEBUG”
application = “icingaweb2”
facility = “user”
The file is being created but still nothing in it.
[root@mo1 icingaweb2]# ll
insgesamt 0
-rw-r–r--. 1 apache icingaweb2 0 18. Sep 19:17 debug.log

Okay, configuration issue.
Port 2003 is only there to feed data into graphite/carbon.
In order to retrieve it, you need to access Port 80 when using the RPM. It makes use of the root of the http server whereas icinga runs below icingaweb2.
The timeout is gone. Just the graphs are not being rendered, because of
SQLSTATE[42000]: Syntax error or access violation: 1253 COLLATION ‘latin1_general_ci’ is not valid for CHARACTER SET ‘utf8’
But that’s a different issue and I will research the forum and open a different topic if needed.

Many Thanks for helping!!!

Glad you’ve figured it out by yourself :+1:

One short note - Icinga 2 writes to Carbon-Cache via port 2003. The Icinga Web module for Graphite fetches the data from graphite-web and its render API. That’s two different things to debug, in case you run into this thing again.

The collation errors sources from the charset setting in your IDO database resource config. Change that to latin1 and if it doesn’t help, create a new topic :slight_smile:

Cheers,
Michael

Yep, that’s what I did. Many thanks again!

1 Like