Troubleshooting Gitlist configuration errors

After a power outage that resulted in our customer’s virtual machines undergoing a controlled reboot, I have noticed that the Gitlist repository for our projects has become unavailable.

I have turned to lighttpd logs to see what may be causing the error:

tail -f /var/log/lighttpd/error.log
[]# tail -f /var/log/lighttpd/error.log
2018-10-03 09:41:21: (response.c.679) — handling subrequest
2018-10-03 09:41:21: (response.c.680) Path : /var/www/gitlist/index.php
2018-10-03 09:41:21: (response.c.681) URI : /gitlist/index.php
2018-10-03 09:41:21: (response.c.682) Pathinfo : /
2018-10-03 09:41:21: (mod_access.c.159) — mod_access_uri_handler called
2018-10-03 09:41:21: (gw_backend.c.2444) handling it in mod_gw
2018-10-03 09:41:22: (gw_backend.c.245) establishing connection failed: Connection refused socket: tcp:127.0.0.1:9000
2018-10-03 09:41:22: (gw_backend.c.960) all handlers for /gitlist/index.php? on .php are down.
2018-10-03 09:41:24: (gw_backend.c.324) gw-server re-enabled: tcp:127.0.0.1:9000 127.0.0.1 9000
2018-10-03 09:41:28: (server.c.1827) connection closed – keep-alive timeout: 8

To confirm that there aren’t any other errors I ran thought about running strace on the lighttpd process. First, found the PID of the service:

Then run strace itself:

write(5, “2018-10-03 09:55:27: (response.c.672) Path : /var/www/gitlist/index.php/ \n”, 82) = 82
stat(“/var/www/gitlist/index.php/”, 0x7fffa0247fa0) = -1 ENOTDIR (Not a directory)
stat(“/var/www”, {st_mode=S_IFDIR|0755, st_size=88, …}) = 0
stat(“/var/www/gitlist”, {st_mode=S_IFDIR|0755, st_size=4096, …}) = 0
stat(“/var/www/gitlist/index.php”, {st_mode=S_IFREG|0644, st_size=690, …}) = 0
open(“/var/www/gitlist/index.php”, O_RDONLY) = 9
close(9) = 0
write(5, “2018-10-03 09:55:27: (response.c.679) — handling subrequest \n”, 62) = 62
write(5, “2018-10-03 09:55:27: (response.c.680) Path : /var/www/gitlist/index.php \n”, 81) = 81
write(5, “2018-10-03 09:55:27: (response.c.681) URI : /gitlist/index.php \n”, 73) = 73
write(5, “2018-10-03 09:55:27: (response.c.682) Pathinfo : / \n”, 56) = 56
write(5, “2018-10-03 09:55:27: (mod_access.c.159) — mod_access_uri_handler called \n”, 74) = 74
write(5, “2018-10-03 09:55:27: (gw_backend.c.2444) handling it in mod_gw \n”, 64) = 64
socket(AF_INET, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, IPPROTO_IP) = 9
connect(9, {sa_family=AF_INET, sin_port=htons(9000), sin_addr=inet_addr(“127.0.0.1”)}, 16) = -1 EINPROGRESS (Operation now in progress)
epoll_ctl(7, EPOLL_CTL_ADD, 9, {EPOLLOUT|EPOLLERR|EPOLLHUP, {u32=9, u64=9}}) = 0
epoll_ctl(7, EPOLL_CTL_MOD, 8, {EPOLLERR|EPOLLHUP|EPOLLRDHUP, {u32=8, u64=8}}) = 0
epoll_wait(7, [{EPOLLOUT|EPOLLERR|EPOLLHUP, {u32=9, u64=9}}], 2049, 1000) = 1
getsockopt(9, SOL_SOCKET, SO_ERROR, [111], [4]) = 0
write(5, “2018-10-03 09:55:27: (gw_backend.c.245) establishing connection failed: Connection refused socket: tcp:127.0.0.1:9000 \n”, 119) = 119
epoll_ctl(7, EPOLL_CTL_DEL, 9, 0x7fffa0248120) = 0
write(5, “2018-10-03 09:55:27: (gw_backend.c.960) all handlers for /gitlist/index.php? on .php are down. \n”, 96) = 96
close(9) = 0

epoll_wait(7, ^Cstrace: Process 46362 detached

So lighttpd expects a service on port 9000 to handle the PHP request. This looks a lot like PHP-FPM, which happens to be in a failed state:

[]# systemctl status php-fpm -l
● php-fpm.service – The PHP FastCGI Process Manager
Loaded: loaded (/usr/lib/systemd/system/php-fpm.service; enabled; vendor preset: disabled)
Active: failed (Result: exit-code) since Wed 2018-10-03 09:49:51 BST; 8min ago
Process: 48552 ExecStart=/usr/sbin/php-fpm –nodaemonize (code=exited, status=1/FAILURE)
Main PID: 48552 (code=exited, status=1/FAILURE)

Oct 03 09:49:51 php-fpm[48552]: /usr/sbin/php-fpm: /lib64/libxml2.so.2: version `LIBXML2_2.9.0′ not found (required by /usr/sbin/php-fpm)

Oct 03 09:49:51 systemd[1]: php-fpm.service: main process exited, code=exited, status=1/FAILURE
Oct 03 09:49:51 systemd[1]: Failed to start The PHP FastCGI Process Manager.
Oct 03 09:49:51 systemd[1]: Unit php-fpm.service entered failed state.
Oct 03 09:49:51 systemd[1]: php-fpm.service failed.

Let’s confirm that PHP FPM is indeed the service configured to be running on port 9000. We can see path to PHP FPM configuration file path by running php -i but we get an error:

[]# php -i
php: /lib64/libxml2.so.2: version `LIBXML2_2.9.0′ not found (required by php)

So looks like we will have to fix this problem first.

yum install libxml2

Now we can run php -i. Sadly, I couldn’t find any pointers to php-fpm config file, so I had to find it manually in

[etc]# nano /etc/php-fpm.conf

Inside the file we see an include:

include=/etc/php-fpm.d/*.conf

Let’s check this file:

[www]

; The address on which to accept FastCGI requests.
; Valid syntaxes are:
; ‘ip.add.re.ss:port’ – to listen on a TCP socket to a specific address on
; a specific port;
; ‘port’ – to listen on a TCP socket to all addresses on a
; specific port;
; ‘/path/to/unix/socket’ – to listen on a unix socket.
; Note: This value is mandatory.
listen = 127.0.0.1:9000

Bingo. That’s our service. Now, we have fixed PHP’s error, so let’s try starting the service:

[php-fpm.d]# systemctl start php-fpm -l
[php-fpm.d]# systemctl status php-fpm -l
● php-fpm.service – The PHP FastCGI Process Manager
Loaded: loaded (/usr/lib/systemd/system/php-fpm.service; enabled; vendor preset: disabled)
Active: active (running) since Wed 2018-10-03 10:10:56 BST; 1s ago
Main PID: 52185 (php-fpm)
Status: “Ready to handle connections”
CGroup: /system.slice/php-fpm.service
├─52185 php-fpm: master process (/etc/php-fpm.conf
├─52186 php-fpm: pool www
├─52187 php-fpm: pool www
├─52188 php-fpm: pool www
├─52189 php-fpm: pool www
└─52190 php-fpm: pool www

And the Gitlist is now.. running!