PHP+nginx サービス 500 502 エラーのトラブルシューティングのアイデアの詳細な説明

概要

オンラインサービスへのアクセス中に 500 または 502 エラーが発生した場合、緊急処理とトラブルシューティングが必要です。どうすればよいでしょうか?いくつかのエラーログを分析したり、php-fpm プロセスを追跡したりすることで、問題を見つけることができます。

nginx エラーログ

nginx error_logはnginx設定ファイルで定義されます

サーバー{
 聞く 80;
 server_name ローカルホスト;
 ルート /var/www;

 アクセスログ /Users/jiao/logs/default.access.log;
 error_log /Users/jiao/logs/default.error.log;
 位置 / {
  インデックス index.html index.htm index.php;
  自動インデックスオン;
 }
 場所 = /情報 {
  127.0.0.1 を許可します。
  すべてを否定する;
  (.*) /.info.php を書き換えます。
 }
 場所 ~ \.php$ {
  ルート /var/www;
  127.0.0.1:9000; をデフォルトとして設定します。
  fastcgi_index インデックス.php;
  fastcgi_param SCRIPT_FILENAME /var/www$fastcgi_script_name;
  /usr/local/etc/nginx/fastcgi_params を含めます。
 }
}

error_log を表示

➜ /Users/jiao/logs/default.error.log を末尾に出力します
2019/07/17 11:08:18 [エラー] 77416#0: *76 kevent() は、アップストリームからの応答ヘッダーの読み取り中に、閉じられた接続 (54: ピアによって接続がリセットされました) について報告しました。クライアント: 127.0.0.1、サーバー: localhost、リクエスト: "GET / HTTP/1.1"、アップストリーム: "fastcgi://127.0.0.1:9000"、ホスト: "localhost"

Connection reset by peer が表示されることがわかります。接続がリセットされています。この時点で、php-fpm の error_log を確認して、問題をさらに分析できます。

php-fpm エラーログ

php-fpmのerror_logはphp-fpm.confファイルの設定で定義されます。

; エラーログファイル
; 「syslog」に設定されている場合、ログは書き込まれるのではなく、syslogdに送信されます。
; ローカルファイル内。
; 注意: デフォルトのプレフィックスは /usr/local/var です
; デフォルト値: log/php-fpm.log
エラーログ = log/php-fpm.log

error_logの内容は次のとおりです

➜ /usr/local/var/log/php-fpm.log を末尾に出力します
[2019年7月17日 10:49:54] 通知: [プール www] 子 81948 が開始されました
[2019 年 7 月 17 日 11:08:18] 警告: [プール www] 子 77537、スクリプト '/var/www/index.php' (リクエスト: "GET /index.php") の実行がタイムアウトしました (3.801267 秒)。終了します
[2019 年 7 月 17 日 11:08:18] 警告: [プール www] 子プロセス 77537 は開始から 1503.113967 秒後にシグナル 15 (SIGTERM) で終了しました
[2019年7月17日 11:08:18] 通知: [プール www] 子 94339 が開始されました

/var/www/index.php ファイルへのリクエストがタイムアウトしたことがわかります。

トラス

dtrussはPIDと名前に基づいてプロセスを追跡できる動的追跡コマンドです。

Mac環境ではdtruss、Linux環境ではstraceとpstackを使用する

➜ トラス 
使用方法: dtruss [-acdefholLs] [-t syscall] { -p PID | -n 名前 | コマンド | -W 名前 }

  -p PID # このPIDを調べる
  -n name # このプロセス名を調べる
  -t syscall # このシステムコールのみを調べる
  -W name # この名前に一致するプロセスを待機します
  -a # すべての詳細を印刷
  -c # システムコール数を出力
  -d # 相対時間（us）を出力
  -e # 経過時間（us）を出力
  -f # 子要素をフォロー
  -l # pid/lwpid を強制的に印刷する
  -o # CPU時間を表示
  -s # スタックバックトレースを印刷
  -L # pid/lwpid を印刷しない
  -b bufsize # 動的可変バッファサイズ

例えば、

 dtruss df -h # 「df -h」を実行して調べる
 dtruss -p 1871 # PID 1871 を調べる
 dtruss -n tar # 「tar」と呼ばれるすべてのプロセスを調べる
 dtruss -f test.sh # test.sh を実行して子プロセスを追跡する

php-fpm をトレースする: sudo dtruss -a -n php-fpm

この時点で、ウェブページにアクセスすると追跡コンテンツが表示されます

21416/0x3479b6: 1559 63 3 getrusage(0x0, 0x7FFEE1EC0760, 0x0) = 0 0
21416/0x3479b6: 1561 4 0 getrusage(0xFFFFFFFFFFFFFFFF, 0x7FFEE1EC0760, 0x0) = 0 0
21416/0x3479b6: 1627 77 17 ポーリング(0x7FFEE1EC08C0, 0x1, 0x1388) = 1 0
dtrace: 有効なプローブ ID 2174 (ID 159: syscall::read:return) でエラーが発生しました: DIF オフセット 68 のアクション #13 でカーネル アクセスが無効です
dtrace: 有効なプローブ ID 2174 (ID 159: syscall::read:return) でエラーが発生しました: DIF オフセット 68 のアクション #13 でカーネル アクセスが無効です
dtrace: 有効なプローブ ID 2174 (ID 159: syscall::read:return) でエラーが発生しました: DIF オフセット 68 のアクション #13 でカーネル アクセスが無効です
dtrace: 有効なプローブ ID 2174 (ID 159: syscall::read:return) でエラーが発生しました: DIF オフセット 68 のアクション #13 でカーネル アクセスが無効です
dtrace: 有効なプローブ ID 2174 (ID 159: syscall::read:return) でエラーが発生しました: DIF オフセット 68 のアクション #13 でカーネル アクセスが無効です
21416/0x3479b6: 1872 29 24 lstat64("/var/www/index.php\0", 0x7FFEE1ECFF38, 0x0) = 0 0
21416/0x3479b6: 1884 9 6 lstat64("/var/www\0", 0x7FFEE1ECFDF8, 0x0) = 0 0
21416/0x3479b6: 1889 6 3 lstat64("/var\0", 0x7FFEE1ECFCB8, 0x0) = 0 0
21416/0x3479b6: 1899 12 8 読み取りリンク("/var\0", 0x7FFEE1ED0090, 0x400) = 11 0
21416/0x3479b6: 1905 6 4 lstat64("/private/var\0", 0x7FFEE1ECFB78, 0x0) = 0 0
21416/0x3479b6: 1917 6 3 lstat64("/private\0", 0x7FFEE1ECFA38, 0x0) = 0 0
21416/0x3479b6: 2178 18 14 stat64("/var/www/.user.ini\0", 0x7FFEE1ED0240, 0x0) = -1 エラー#2
21416/0x3479b6: 2217 5 1 setitimer(0x2, 0x7FFEE1ED07E0, 0x0) = 0 0
21416/0x3479b6: 2225 4 0 シグナルアクション(0x1B, 0x7FFEE1ED0788, 0x7FFEE1ED07B0) = 0 0
21416/0x3479b6: 2237 5 1 シグナルプロマスク(0x2, 0x7FFEE1ED0804, 0x0) = 0x0 0
21416/0x3479b6: 3643 48 40 open_nocancel(".\0", 0x0, 0x1) = 5 0
21416/0x3479b6: 3648 7 3 fstat64(0x5, 0x7FFEE1ED0110, 0x0) = 0 0
21416/0x3479b6: 3653 7 2 fcntl_nocancel(0x5, 0x32, 0x10F252158) = 0 0
21416/0x3479b6: 3661 12 7 close_nocancel(0x5) = 0 0
21416/0x3479b6: 3670 10 7 stat64("/usr/local/var\0", 0x7FFEE1ED0080, 0x0) = 0 0
21416/0x3479b6: 3681 11 8 chdir("/var/www\0", 0x0, 0x0) = 0 0
21416/0x3479b6: 3698 4 0 セティマー(0x2, 0x7FFEE1ED02D0, 0x0) = 0 0
21416/0x3479b6: 3710 6 3 fcntl(0x3, 0x8, 0x10F3FD858) = 0 0
21416/0x3479b6: 3733 9 6 stat64("/private/var/www/index.php\0", 0x7FFEE1ECFF10, 0x0) = 0 0
74904/0x332630: 723125 1073381 19 kevent(0x9, 0x0, 0x0) = 0 0
74902/0x332629: 770666 1073387 17 kevent(0x8, 0x0, 0x0) = 0 0
74904/0x332630: 723165 1061954 20 kevent(0x9, 0x0, 0x0) = 0 0
74902/0x332629: 770709 1061954 20 kevent(0x8, 0x0, 0x0) = 0 0
74904/0x332630: 723201 1074786 16 kevent(0x9, 0x0, 0x0) = 0 0
74902/0x332629: 770747 1074783 16 kevent(0x8, 0x0, 0x0) = 0 0
74904/0x332630: 723229 1069141 13 kevent(0x9, 0x0, 0x0) = 0 0
74902/0x332629: 770777 1069145 11 kevent(0x8, 0x0, 0x0) = 0 0
21416/0x3479b6: 3942 3902233 7 __semwait_signal(0x703, 0x0, 0x1) = -1 エラー#4
74902/0x332629: 770814 103 25 キル(21416, 15) = 0 0
dtrace: 有効なプローブ ID 2172 (ID 161: syscall::write:return) でエラーが発生しました: DIF オフセット 68 のアクション #13 でカーネル アクセスが無効です
dtrace: 有効なプローブ ID 2172 (ID 161: syscall::write:return) でエラーが発生しました: DIF オフセット 68 のアクション #13 でカーネル アクセスが無効です
74902/0x332629: 771325 7 2 sigreturn(0x7FFEE1ECFC40, 0x1E, 0xC1A4B78E0404663A) = 0 Err#-2
74902/0x332629: 771336 7 3 kevent(0x8, 0x0, 0x0) = 1 0
dtrace: 有効なプローブ ID 2174 (ID 159: syscall::read:return) でエラーが発生しました: DIF オフセット 68 のアクション #13 でカーネル アクセスが無効です
74902/0x332629: 771352 11 7 wait4(0xFFFFFFFFFFFFFFFF, 0x7FFEE1ED0748, 0x3) = 21416 0
dtrace: 有効なプローブ ID 2172 (ID 161: syscall::write:return) でエラーが発生しました: DIF オフセット 68 のアクション #13 でカーネル アクセスが無効です
74902/0x332629: 773511 1957 1899 フォーク() = 28060 0
28060/0x3754c5: 125: 0: 0 フォーク() = 0 0
28060/0x3754c5: 128 9 2 bsdthread_register(0x7FFF6774C418, 0x7FFF6774C408, 0x2000) = -1 エラー#22
dtrace: 有効なプローブ ID 2172 (ID 161: syscall::write:return) でエラーが発生しました: DIF オフセット 68 のアクション #13 でカーネル アクセスが無効です
74902/0x332629: 773737 4 1 wait4(0xFFFFFFFFFFFFFFFF, 0x7FFEE1ED0748, 0x3) = 0 0
74902/0x332629: 773742 6 3 読み取り(0x5, "\0", 0x1) = -1 Err#35
28060/0x3754c5: 320 4 0 getpid(0x0, 0x0, 0x0) = 28060 0
28060/0x3754c5: 328 7 2 __mac_syscall(0x7FFF67758A17, 0x4, 0x7FFEE1ED0208) = -1 エラー#45
28060/0x3754c5: 332 5 2 csops(0x6D9C, 0xB, 0x7FFEE1ED0248) = -1 エラー#22
28060/0x3754c5: 755 14 11 重複2(0x1, 0x2, 0x0) = 2 0
28060/0x3754c5: 797 89 22 クローズ(0x4) = 0 0
28060/0x3754c5: 806 11 6 dup2(0x7, 0x0, 0x0) = 0 0
28060/0x3754c5: 817 4 0 geteuid(0x0, 0x0, 0x0) = 501 0
28060/0x3754c5: 820 3 0 閉じる(0x5) = 0 0
28060/0x3754c5: 821 3 0 閉じる(0x6) = 0 0
28060/0x3754c5: 824 5 1 シグナルアクション(0xF, 0x7FFEE1ED0688, 0x0) = 0 0
28060/0x3754c5: 825 3 0 シグナルアクション(0x2, 0x7FFEE1ED0688, 0x0) = 0 0
28060/0x3754c5: 827 3 0 シグナルアクション(0x1E, 0x7FFEE1ED0688, 0x0) = 0 0
28060/0x3754c5: 828 3 0 シグナルアクション(0x1F, 0x7FFEE1ED0688, 0x0) = 0 0
28060/0x3754c5: 829 3 0 シグナルアクション(0x14, 0x7FFEE1ED0688, 0x0) = 0 0
28060/0x3754c5: 830 3 0 シグナルアクション(0x3, 0x7FFEE1ED0688, 0x0) = 0 0
28060/0x3754c5: 1043 3 0 閉じる(0x7) = 0 0

ファイルの内容情報を取得する lstat64、php-fpm プロセスを強制終了する kill(21416, 15)、新しい php-fpm プロセスを作成する fork() など、システムの下部で実行される関数を確認できます。興味がある場合は、各命令の役割を詳しく調べることができます。

参照する

https://www.jb51.net/article/165773.htm

以上がこの記事の全内容です。皆様の勉強のお役に立てれば幸いです。また、123WORDPRESS.COM を応援していただければ幸いです。

以下もご興味があるかもしれません: