Troubleshooting exercise Nginx part ii #57

berkeli · 2022-12-05T12:16:02Z

The exercise requires troubleshooting of MySQL and NGINX to get an output in the following format when we run curl http://127.0.01/:

“My name is <name> and my ID is <id>”

To start the exerice, I ssh into the instance and ran the following command:

curl -iv http://127.0.0.1
* Trying 127.0.0.1:80...
* connect to 127.0.0.1 port 80 failed: Connection refused
* Failed to connect to 127.0.0.1 port 80 after 0 ms: Connection refused
* Closing connection 0
curl: (7) Failed to connect to 127.0.0.1 port 80 after 0 ms: Connection refused

There doesn't seem to be any service running on port 80. I checked the status of the services using systemctl status and found that the nginx service was not running. I started the service using systemctl restart nginx and ran the curl command again:

systemctl status nginx
● nginx.service - The nginx HTTP and reverse proxy server
   Loaded: loaded (/usr/lib/systemd/system/nginx.service; disabled; vendor preset: disabled)
   Active: inactive (dead)
sudo systemctl restart nginx
curl -iv http://127.0.0.1
*   Trying 127.0.0.1:80...
* Connected to 127.0.0.1 (127.0.0.1) port 80 (#0)
> GET / HTTP/1.1
> Host: 127.0.0.1
> User-Agent: curl/7.79.1
> Accept: */*
>
* Mark bundle as not supporting multiuse
< HTTP/1.1 500 Internal Server Error
HTTP/1.1 500 Internal Server Error
< Server: nginx/1.22.0
Server: nginx/1.22.0
< Date: Mon, 12 Dec 2022 11:13:25 GMT
Date: Mon, 12 Dec 2022 11:13:25 GMT
< Content-Type: text/html
Content-Type: text/html
< Transfer-Encoding: chunked
Transfer-Encoding: chunked
< Connection: keep-alive
Connection: keep-alive
< X-Powered-By: PHP/5.4.16
X-Powered-By: PHP/5.4.16

<
* Connection #0 to host 127.0.0.1 left intact

Now we get a response but there's an error. I checked the error log of nginx using sudo cat /var/log/nginx/error.log and found the following error:

2022/12/12 11:13:25 [error] 7095#7095: *1 FastCGI sent in stderr: "PHP message: PHP Warning:  mysqli::mysqli(): (HY000/2002): No such file or directory in /usr/share/nginx/html/index.php on line 8
PHP message: PHP Warning:  mysqli::query(): Couldn't fetch mysqli in /usr/share/nginx/html/index.php on line 11
PHP message: PHP Fatal error:  Call to a member function fetch_assoc() on a non-object in /usr/share/nginx/html/index.php on line 13" while reading response header from upstream, client: 127.0.0.1, server: _, request: "GET / HTTP/1.1", upstream: "fastcgi://127.0.0.1:9000", host: "127.0.0.1"

The error indicates fetch_assoc() function doesn't exist on $result. I checked the index.php file and found the following code:

cat /usr/share/nginx/html/index.php
<?php

	$servername = 'localhost';
	$username = 'cyf';
	$password = 'Eix#ah6aib0u';

	// Create connection
	$conn = new mysqli($servername, $username, $password);

	$sql = "SELECT * from cyf_user";
	$result = $conn->query($sql);

	while($row = $result->fetch_assoc()){
		echo "My name is: " . $row["Name"] . "<br/>";
	}

?>

After some googling on this php error, I found that it is usually caused by an error in the connection. Which makes sense, as an error response wouldn't have fetch_assoc() method. At this point I decided to try and connect to the mysql database from the terminal, to see if I can establish a connection. I ran the following command:

mysql -u cyf -p
Enter password:
ERROR 2002 (HY000): Can't connect to local MySQL server through socket '/var/lib/mysql/mysql.sock' (2)

I checked the status of the mysql service using systemctl status mysqld and found that it is in an error state.

systemctl status mysqld
● mysqld.service - MySQL Server
   Loaded: loaded (/usr/lib/systemd/system/mysqld.service; enabled; vendor preset: disabled)
   Active: failed (Result: exit-code) since Mon 2022-12-12 10:19:38 UTC; 1h 4min ago
     Docs: man:mysqld(8)
           http://dev.mysql.com/doc/refman/en/using-systemd.html
  Process: 3009 ExecStart=/usr/sbin/mysqld $MYSQLD_OPTS (code=exited, status=1/FAILURE)
  Process: 2955 ExecStartPre=/usr/bin/mysqld_pre_systemd (code=exited, status=0/SUCCESS)
 Main PID: 3009 (code=exited, status=1/FAILURE)
   Status: "Server shutdown complete"
    Error: 13 (Permission denied)

Dec 12 10:19:27 ip-172-31-85-83.ec2.internal systemd[1]: Starting MySQL Server...
Dec 12 10:19:38 ip-172-31-90-110.ec2.internal systemd[1]: mysqld.service: main process exited, code=exited, status...LURE
Dec 12 10:19:38 ip-172-31-90-110.ec2.internal systemd[1]: Failed to start MySQL Server.
Dec 12 10:19:38 ip-172-31-90-110.ec2.internal systemd[1]: Unit mysqld.service entered failed state.
Dec 12 10:19:38 ip-172-31-90-110.ec2.internal systemd[1]: mysqld.service failed.
Hint: Some lines were ellipsized, use -l to show in full.

I decided to check journalctl for any errors related to mysql. I found the following error:

journalctl -xe
....
-- Subject: Unit mysqld.service has begun start-up
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit mysqld.service has begun starting up.
Dec 12 11:25:51 ip-172-31-90-110.ec2.internal systemd[1]: mysqld.service: main process exited, code=exited, status=1/FAIL
Dec 12 11:25:51 ip-172-31-90-110.ec2.internal systemd[1]: Failed to start MySQL Server.
.....

Doesn't look like much, it's not giving me any useful information. I decided to check the mysql error log using sudo cat /var/log/mysqld.log and found the following error:

2022-12-12T11:25:50.262624Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel.
2022-12-12T11:25:50.262890Z 0 [ERROR] [MY-010262] [Server] Can't start server: Bind on TCP/IP port: Permission denied
2022-12-12T11:25:50.262903Z 0 [ERROR] [MY-010257] [Server] Do you already have another mysqld server running on port: 616 ?
2022-12-12T11:25:50.263406Z 0 [ERROR] [MY-010119] [Server] Aborting

There seems to be something blocking mysql from running on the port 616. I decided to check what's running on that port with lsof command

lsof -i :616
sudo lsof -i :616

Hmm, nothing is running on that port. I decided to check if the port is open using netcat command to listen on that port

sudo nc -l 616

No issues there. At this point I think it might have to do with permissions that mysql server is trying to start with. I decided to check the config file for mysql server:

cat /etc/my.cnf
[mysqld]
datadir=/var/lib/mysql
socket=/var/lib/mysql/mysql.sock
port=616

symbolic-links=0

log-error=/var/log/mysqld.log
pid-file=/var/run/mysqld/mysqld.pid

[client]
default-character-set=utf8

[mysql]
default-character-set=utf8

[mysqld]
collation-server = utf8_unicode_ci
character-set-server = utf8

Everything seems normal, except for the port. From all of the configuration files I was able to find, mysql is usually ran on port 3306. I decided to change the port to 3306 and restart the mysql service.

sudo systemctl restart mysqld

This time the mysql service started successfully. I decided to check the database by connecting to it via CLI:

mysql -u cyf -p
Enter password:
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 12
Server version: 8.0.31 MySQL Community Server - GPL

Copyright (c) 2000, 2022, Oracle and/or its affiliates.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> SHOW DATABASES;
+--------------------+
| Database           |
+--------------------+
| information_schema |
| performance_schema |
| users              |
+--------------------+
3 rows in set (0.00 sec)

mysql> USE users;
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Database changed
mysql> SHOW TABLES;
+-----------------+
| Tables_in_users |
+-----------------+
| cyf_user        |
+-----------------+
1 row in set (0.00 sec)

mysql> SELECT * FROM cyf_user;
+-----------+------+
| Name      | ID   |
+-----------+------+
| Margarita |  123 |
| Berkeli   |  345 |
+-----------+------+
2 rows in set (0.01 sec)

mysql>

Everything seems to be working fine. I decided to check if localhost is giving a different result with curl command:

curl -iv http://127.0.0.1
*   Trying 127.0.0.1:80...
* Connected to 127.0.0.1 (127.0.0.1) port 80 (#0)
> GET / HTTP/1.1
> Host: 127.0.0.1
> User-Agent: curl/7.79.1
> Accept: */*
>
* Mark bundle as not supporting multiuse
< HTTP/1.1 500 Internal Server Error
HTTP/1.1 500 Internal Server Error
< Server: nginx/1.22.0
Server: nginx/1.22.0
< Date: Mon, 12 Dec 2022 12:06:30 GMT
Date: Mon, 12 Dec 2022 12:06:30 GMT
< Content-Type: text/html
Content-Type: text/html
< Transfer-Encoding: chunked
Transfer-Encoding: chunked
< Connection: keep-alive
Connection: keep-alive
< X-Powered-By: PHP/5.4.16
X-Powered-By: PHP/5.4.16

<
* Connection #0 to host 127.0.0.1 left intact

Still getting the same error. I decided to check the nginx error log:

sudo cat /var/log/nginx/error.log
........
2022/12/12 12:06:30 [error] 7095#7095: *5 FastCGI sent in stderr: "PHP message: PHP Warning:  mysqli::mysqli(): The server requested authentication method unknown to the client [caching_sha2_password] in /usr/share/nginx/html/index.php on line 8
......

This time it's giving me a different error. It seems like the authentication method is not supported by the client. After some googling, I found that this issue can be resolved one of 2 ways:

Update the MySQL USERS table to use the old authentication method
Update the PHP to v7.4 or higher where the new authentication method is supported

I decided to go with the second option. I decided to check the PHP version:

php -v
PHP 5.4.16 (cli) (built: Oct 31 2019 18:34:05)
Copyright (c) 1997-2013 The PHP Group
Zend Engine v2.4.0, Copyright (c) 1998-2013 Zend Technologies

I decided to update the PHP version to v7.4. I decided to check the PHP versions available on the system:

sudo amazon-linux-extras | grep php
 42  php7.4                   available    [ =stable ]
 51  php8.0                   available    [ =stable ]
 66  php8.1                   available    [ =stable ]

Then ran the command to install it via amazon-linux-extras

sudo amazon-linux-extras install php7.4

After the installation was complete, I decided to check the PHP version again:

php -v
PHP 7.4.33 (cli) (built: Nov 19 2022 00:22:13) ( NTS )
Copyright (c) The PHP Group
Zend Engine v3.4.0, Copyright (c) Zend Technologies

I decided to restart the nginx and php-fpm services:

sudo systemctl restart nginx
sudo systemctl restart php-fpm

I decided to check the localhost again:

curl -iv http://127.0.0.1
*   Trying 127.0.0.1:80...
* Connected to 127.0.0.1 (127.0.0.1) port 80 (#0)
> GET / HTTP/1.1
> Host: 127.0.0.1
> User-Agent: curl/7.79.1
> Accept: */*
>
* Mark bundle as not supporting multiuse
< HTTP/1.1 502 Bad Gateway
HTTP/1.1 502 Bad Gateway
< Server: nginx/1.22.0
Server: nginx/1.22.0
< Date: Mon, 12 Dec 2022 12:49:08 GMT
Date: Mon, 12 Dec 2022 12:49:08 GMT
< Content-Type: text/html
Content-Type: text/html
< Content-Length: 3708
Content-Length: 3708
< Connection: keep-alive
Connection: keep-alive
< ETag: "63777a94-e7c"
ETag: "63777a94-e7c"

Seems this made it worse, as now I'm getting a 502 error. I decided to check the nginx error log again:

sudo cat /var/log/nginx/error.log
2022/12/12 12:41:06 [crit] 1546#1546: *3 connect() to unix:/run/php-fpm/www.sock failed (2: No such file or directory) while connecting to upstream, client: 127.0.0.1, server: _, request: "GET / HTTP/1.1", upstream: "fastcgi://unix:/run/php-fpm/www.sock:", host: "127.0.0.1"
2022/12/12 12:41:14 [crit] 1546#1546: *5 connect() to unix:/run/php-fpm/www.sock failed (2: No such file or directory) while connecting to upstream, client: 127.0.0.1, server: _, request: "GET / HTTP/1.1", upstream: "fastcgi://unix:/run/php-fpm/www.sock:", host: "127.0.0.1"

It seems like the php-fpm service is not running. I decided to check the status of the php-fpm service:

sudo systemctl status php-fpm
● 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 Mon 2022-12-12 13:11:18 UTC; 2min 6s ago
 Main PID: 2953 (php-fpm)
   Status: "Processes active: 0, idle: 5, Requests: 3, slow: 0, Traffic: 0req/sec"
   CGroup: /system.slice/php-fpm.service
           ├─2953 php-fpm: master process (/etc/php-fpm.conf)
           ├─3013 php-fpm: pool www
           ├─3014 php-fpm: pool www
           ├─3015 php-fpm: pool www
           ├─3016 php-fpm: pool www
           └─3017 php-fpm: pool www

Dec 12 13:11:18 ip-172-31-90-110.ec2.internal systemd[1]: Starting The PHP FastCGI Process Manager...
Dec 12 13:11:18 ip-172-31-90-110.ec2.internal systemd[1]: Started The PHP FastCGI Process Manager.

It seems like the php-fpm service is running. I decided to check the php-fpm log:

sudo cat /var/log/php-fpm/www-error.log
[12-Dec-2022 12:42:35] NOTICE: fpm is running, pid 2601
[12-Dec-2022 12:42:35] NOTICE: ready to handle connections
[12-Dec-2022 12:42:35] NOTICE: systemd monitor interval set to 10000ms
[12-Dec-2022 13:00:59] NOTICE: configuration file /etc/php-fpm.conf test is successful

[12-Dec-2022 13:02:00] NOTICE: Terminating ...
[12-Dec-2022 13:02:00] NOTICE: exiting, bye-bye!
[12-Dec-2022 13:02:00] NOTICE: fpm is running, pid 13914
[12-Dec-2022 13:02:00] NOTICE: ready to handle connections
[12-Dec-2022 13:02:00] NOTICE: systemd monitor interval set to 10000ms
[12-Dec-2022 13:04:50] NOTICE: Terminating ...
[12-Dec-2022 13:04:50] NOTICE: exiting, bye-bye!
[12-Dec-2022 13:04:50] NOTICE: fpm is running, pid 15227
[12-Dec-2022 13:04:50] NOTICE: ready to handle connections
[12-Dec-2022 13:04:50] NOTICE: systemd monitor interval set to 10000ms
[12-Dec-2022 13:08:30] NOTICE: Terminating ...
[12-Dec-2022 13:08:30] NOTICE: exiting, bye-bye!
[12-Dec-2022 13:11:18] NOTICE: fpm is running, pid 2953
[12-Dec-2022 13:11:18] NOTICE: ready to handle connections
[12-Dec-2022 13:11:18] NOTICE: systemd monitor interval set to 10000ms

There doesn't seem to be anything useful here, everything seems fine. I decided to look into the nginx configuration file so at least nginx and php-fpm are talking to each other:

sudo ls -al /etc/nginx/conf.d/
total 8
drwxr-xr-x 2 root root   26 Dec 12 13:36 .
drwxr-xr-x 4 root root 4096 Dec 12 13:35 ..
-rw-r--r-- 1 root root  124 Dec 12 13:36 php-fpm.conf

I decided to check the php-fpm configuration file:

sudo cat /etc/nginx/conf.d/php-fpm.conf
upstream php-handler {
    server unix:/run/php-fpm/www.sock;
}

As suspected, it's configured to use the unix socket. I updated the php-fpm configuration file to use the TCP socket 9000 and restarted the php-fpm service:

sudo systemctl restart php-fpm

Check localhost again with curl:

curl -iv http://localhost
*   Trying 127.0.0.1:80...
* Connected to localhost (127.0.0.1) port 80 (#0)
> GET / HTTP/1.1
> Host: localhost
> User-Agent: curl/7.79.1
> Accept: */*
>
* Mark bundle as not supporting multiuse
< HTTP/1.1 500 Internal Server Error
HTTP/1.1 500 Internal Server Error
< Server: nginx/1.22.0
Server: nginx/1.22.0
< Date: Mon, 12 Dec 2022 13:37:07 GMT
Date: Mon, 12 Dec 2022 13:37:07 GMT
< Content-Type: text/html
Content-Type: text/html
< Content-Length: 3708
Content-Length: 3708
< Connection: close
Connection: close
< ETag: "63777a94-e7c"
ETag: "63777a94-e7c"

500 Internal Server Error. Slightly better than the 502 status code. I decided to check the nginx error log:

sudo cat /var/log/nginx/error.log
....
2022/12/12 13:37:07 [error] 14793#14793: *1 FastCGI sent in stderr: "PHP message: PHP Fatal error:  Uncaught Error: Call to a member function fetch_assoc() on bool in /usr/share/nginx/html/index.php:13
Stack trace:
#0 {main}
....

It seems like the database connection is not working still. I decided to edit the index.php file to add the following:

Add database name
Add error handling

sudo vim /usr/share/nginx/html/index.php
sudo cat /usr/share/nginx/html/index.php
<?php

	$servername = 'localhost';
	$username = 'cyf';
	$password = 'Eix#ah6aib0u';
 	$db = 'users';

	// Create connection
	$conn = new mysqli($servername, $username, $password, $db);

	if ($conn -> connect_errno) {
 		echo "Failed to connect to MySQL: " . $mysqli -> connect_error;
  		exit();
	}	

	$sql = "SELECT * from cyf_user";
	$result = $conn->query($sql);

	while($row = $result->fetch_assoc()){
		echo "My name is: " . $row["Name"] . "<br/>";
	}

?>

Then check localhost again with curl:

curl -iv http://localhost
*   Trying 127.0.0.1:80...
* Connected to localhost (127.0.0.1) port 80 (#0)
> GET / HTTP/1.1
> Host: localhost
> User-Agent: curl/7.79.1
> Accept: */*
>
* Mark bundle as not supporting multiuse
< HTTP/1.1 200 OK
HTTP/1.1 200 OK
< Server: nginx/1.22.0
Server: nginx/1.22.0
< Date: Mon, 12 Dec 2022 13:48:42 GMT
Date: Mon, 12 Dec 2022 13:48:42 GMT
< Content-Type: text/html; charset=UTF-8
Content-Type: text/html; charset=UTF-8
< Transfer-Encoding: chunked
Transfer-Encoding: chunked
< Connection: keep-alive
Connection: keep-alive
< X-Powered-By: PHP/7.4.33
X-Powered-By: PHP/7.4.33

<
My name is: Margarita<br/>My name is: Berkeli<br/>

* Connection #0 to host localhost left intact

It works, but the exercise description is requesting a slightly different output than the one I got: The goal of this exercise is - when you run “curl http://127.0.0.1/” in the terminal you get “My name is and my ID is ” (do not display both names) with HTTP response code 200. This exercise is a mix of system and service troubleshooting.

I decided to edit the index.php file again to get the desired output:

sudo vim /usr/share/nginx/html/index.php
sudo cat /usr/share/nginx/html/index.php
<?php

	$servername = 'localhost';
	$username = 'cyf';
	$password = 'Eix#ah6aib0u';
 	$db = 'users';

	// Create connection
	$conn = new mysqli($servername, $username, $password, $db);

	if ($conn -> connect_errno) {
 		echo "Failed to connect to MySQL: " . $mysqli -> connect_error;
  		exit();
	}	

	$sql = "SELECT * from cyf_user WHERE Name='Berkeli'";
	$result = $conn->query($sql);

	while($row = $result->fetch_assoc()){
		echo "My name is: " . $row["Name"] . " and my id is: " . $row["ID"];
	}		

?>

Then check localhost again with curl:

curl -iv http://localhost
*   Trying 127.0.0.1:80...
* Connected to localhost (127.0.0.1) port 80 (#0)
> GET / HTTP/1.1
> Host: localhost
> User-Agent: curl/7.79.1
> Accept: */*
>
* Mark bundle as not supporting multiuse
< HTTP/1.1 200 OK
HTTP/1.1 200 OK
< Server: nginx/1.22.0
Server: nginx/1.22.0
< Date: Mon, 12 Dec 2022 14:03:33 GMT
Date: Mon, 12 Dec 2022 14:03:33 GMT
< Content-Type: text/html; charset=UTF-8
Content-Type: text/html; charset=UTF-8
< Transfer-Encoding: chunked
Transfer-Encoding: chunked
< Connection: keep-alive
Connection: keep-alive
< X-Powered-By: PHP/7.4.33
X-Powered-By: PHP/7.4.33

<
My name is: Berkeli and my id is: 345

* Connection #0 to host localhost left intact

It works as per the requirements.

The text was updated successfully, but these errors were encountered:

berkeli · 2022-12-15T09:35:48Z

SUMMARY

Problems:

MySQL is not able to start on the configured port 616
NGINX configuration for php-fpm doesn't match the configuration for php-fpm. Nginx config is setup to listen on a unix socket whilst php-fpm is configured to run on port 9000.
PHP version doesn't support caching_sha2_password authentication method which has been setup in the MySQL database
PHP code doesn't specify which database to connect to.
PHP code doesn't have error handling in case connection fails.

Solutions:

Reconfigure MySQL to run on port 3306, which is the default port for MySQL
This can be resolved one of 2 ways:
- Update nginx config for upstream php-fpm (/etc/nginx/conf.d/php-fpm.conf) and specify that php-fpm is running on port 9000 - server 127.0.0.1:9000
- Update php-fpm configuration to listen on a unix socket instead of port 9000
This can also be resolved one of 2 ways:
- Update MySQL database users table to use native password (ALTER USER 'root'@'localhost' IDENTIFIED WITH mysql_native_password BY '';). But this will have to be done for every new user on insert as well.
- Update PHP version to 7.4 which supports caching_sha2_password
Update PHP code to specify database name in the connection
Update PHP code to handle errors if connection fails

berkeli added this to Immersive Go Course Dec 5, 2022

berkeli converted this from a draft issue Dec 5, 2022

berkeli self-assigned this Dec 5, 2022

berkeli added Large day or more priority-high labels Dec 5, 2022

berkeli added this to the Sprint 4 milestone Dec 5, 2022

berkeli moved this from Todo to Done in Immersive Go Course Dec 12, 2022

berkeli moved this from Done to In Review in Immersive Go Course Dec 12, 2022

berkeli moved this from In Review to Done in Immersive Go Course Dec 20, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Troubleshooting exercise Nginx part ii #57

Troubleshooting exercise Nginx part ii #57

berkeli commented Dec 5, 2022 •

edited

Loading

berkeli commented Dec 15, 2022

Troubleshooting exercise Nginx part ii #57

Troubleshooting exercise Nginx part ii #57

Comments

berkeli commented Dec 5, 2022 • edited Loading

berkeli commented Dec 15, 2022

SUMMARY

Problems:

Solutions:

berkeli commented Dec 5, 2022 •

edited

Loading