我需要另一双眼睛来帮助调试问题。这将是一条很长的消息。我将提供大量背景信息,因为我不确定哪些细节可能很重要。
我们有两台服务器:开发服务器和生产服务器。现有服务器正在运行 RHEL7,并且由于生命周期已结束。我正在构建两个新的 RHEL9 VM 来取代它们。
服务器托管各种应用程序。它们彼此独立,并且每个都驻留在文档根目录之外的自己的子目录中。文档根目录位于/var/www/html。
给我带来麻烦的是全新、闪亮的 Drupal 10.2 安装。我使用 Composer 将其安装到 /var/www/drupal,然后在 /var/www/html/databases 创建了一个指向 /var/www/drupal/web 的符号链接。我必须稍微调整一下权限,以确保 Apache 用户可以执行所需的所有操作,但很快我就在开发和生产环境中安装了 Drupal 的功能。
然后,在我将自定义主题的副本克隆到主题文件夹后不久,开发人员就停止工作了。当我访问时,我收到以下错误消息:
The website encountered an unexpected error. Try again later.
ssl_access_log 显示此错误:
10.133.0.30 - - [21/Feb/2024:13:55:07 -0600] "GET /databases/ HTTP/1.1" 500 61
天啊,500 错误消息。该错误消息实际上可能意味着任何内容,因此根本没有任何意义。了不起。
我将 LogLevel 设置为调试,重现了问题并检查了 ssl_error_log,其中报告了以下内容:
[Wed Feb 21 13:55:07.118063 2024] [ssl:info] [pid 7769:tid 7944] [client 10.133.0.30:64845] AH01964: Connection to child 81 established (server undcflwebdev0.und.edu:443)
[Wed Feb 21 13:55:07.118300 2024] [ssl:debug] [pid 7769:tid 7944] ssl_engine_kernel.c(2391): [client 10.133.0.30:64845] AH02043: SSL virtual host for servername undcflwebdev0.und.edu found
[Wed Feb 21 13:55:07.118492 2024] [core:debug] [pid 7769:tid 7944] protocol.c(2460): [client 10.133.0.30:64845] AH03155: select protocol from , choices=h2,http/1.1 for server undcflwebdev0.und.edu
[Wed Feb 21 13:55:07.120744 2024] [ssl:debug] [pid 7769:tid 7944] ssl_engine_kernel.c(2251): [client 10.133.0.30:64845] AH02041: Protocol: TLSv1.3, Cipher: TLS_AES_256_GCM_SHA384 (256/256 bits)
[Wed Feb 21 13:55:07.120862 2024] [socache_shmcb:debug] [pid 7769:tid 7944] mod_socache_shmcb.c(508): AH00831: socache_shmcb_store (0x16 -> subcache 22)
[Wed Feb 21 13:55:07.120889 2024] [socache_shmcb:debug] [pid 7769:tid 7944] mod_socache_shmcb.c(745): AH00842: expiring 11 and reclaiming 0 removed socache entries
[Wed Feb 21 13:55:07.120901 2024] [socache_shmcb:debug] [pid 7769:tid 7944] mod_socache_shmcb.c(765): AH00843: we now have 0 socache entries
[Wed Feb 21 13:55:07.120911 2024] [socache_shmcb:debug] [pid 7769:tid 7944] mod_socache_shmcb.c(862): AH00847: insert happened at idx=0, data=(0:32)
[Wed Feb 21 13:55:07.120917 2024] [socache_shmcb:debug] [pid 7769:tid 7944] mod_socache_shmcb.c(865): AH00848: finished insert, subcache: idx_pos/idx_used=0/1, data_pos/data_used=0/230
[Wed Feb 21 13:55:07.120923 2024] [socache_shmcb:debug] [pid 7769:tid 7944] mod_socache_shmcb.c(530): AH00834: leaving socache_shmcb_store successfully
[Wed Feb 21 13:55:07.121011 2024] [ssl:debug] [pid 7769:tid 7944] ssl_engine_kernel.c(415): [client 10.133.0.30:64845] AH02034: Initial (No.1) HTTPS request received for child 81 (server undcflwebdev0.und.edu:443)
[Wed Feb 21 13:55:07.121357 2024] [authz_core:debug] [pid 7769:tid 7944] mod_authz_core.c(815): [client 10.133.0.30:64845] AH01626: authorization result of Require all granted: granted
[Wed Feb 21 13:55:07.121390 2024] [authz_core:debug] [pid 7769:tid 7944] mod_authz_core.c(815): [client 10.133.0.30:64845] AH01626: authorization result of <RequireAny>: granted
[Wed Feb 21 13:55:07.121491 2024] [authz_core:debug] [pid 7769:tid 7944] mod_authz_core.c(815): [client 10.133.0.30:64845] AH01626: authorization result of Require all granted: granted
[Wed Feb 21 13:55:07.121514 2024] [authz_core:debug] [pid 7769:tid 7944] mod_authz_core.c(815): [client 10.133.0.30:64845] AH01626: authorization result of <RequireAny>: granted
[Wed Feb 21 13:55:07.121680 2024] [proxy:debug] [pid 7769:tid 7944] mod_proxy.c(1520): [client 10.133.0.30:64845] AH01143: Running scheme unix handler (attempt 0)
[Wed Feb 21 13:55:07.121703 2024] [proxy_ajp:debug] [pid 7769:tid 7944] mod_proxy_ajp.c(795): [client 10.133.0.30:64845] AH00894: declining URL fcgi://localhost/var/www/html/databases/index.php
[Wed Feb 21 13:55:07.121719 2024] [proxy_fcgi:debug] [pid 7769:tid 7944] mod_proxy_fcgi.c(1069): [client 10.133.0.30:64845] AH01076: url: fcgi://localhost/var/www/html/databases/index.php proxyname: (null) proxyport: 0
[Wed Feb 21 13:55:07.121736 2024] [proxy_fcgi:debug] [pid 7769:tid 7944] mod_proxy_fcgi.c(1078): [client 10.133.0.30:64845] AH01078: serving URL fcgi://localhost/var/www/html/databases/index.php
[Wed Feb 21 13:55:07.121758 2024] [proxy:debug] [pid 7769:tid 7944] proxy_util.c(2568): AH00942: FCGI: has acquired connection for (*:80)
[Wed Feb 21 13:55:07.121776 2024] [proxy:debug] [pid 7769:tid 7944] proxy_util.c(2626): [client 10.133.0.30:64845] AH00944: connecting fcgi://localhost/var/www/html/databases/index.php to localhost:8000
[Wed Feb 21 13:55:07.121792 2024] [proxy:debug] [pid 7769:tid 7944] proxy_util.c(2662): [client 10.133.0.30:64845] AH02545: fcgi: has determined UDS as /run/php-fpm/www.sock
[Wed Feb 21 13:55:07.122008 2024] [proxy:debug] [pid 7769:tid 7944] proxy_util.c(2852): [client 10.133.0.30:64845] AH00947: connected /var/www/html/databases/index.php to httpd-UDS:0
[Wed Feb 21 13:55:07.122082 2024] [proxy:debug] [pid 7769:tid 7944] proxy_util.c(3222): AH02823: FCGI: connection established with Unix domain socket /run/php-fpm/www.sock (*:80)
[Wed Feb 21 13:55:07.150902 2024] [proxy:debug] [pid 7769:tid 7944] proxy_util.c(2584): AH00943: FCGI: has released connection for (*:80)
[Wed Feb 21 13:55:07.151140 2024] [ssl:debug] [pid 7769:tid 7944] ssl_engine_io.c(1151): [client 10.133.0.30:64845] AH02001: Connection closed to child 81 with standard shutdown (server undcflwebdev0.und.edu:443)
没有任何明显的确凿证据,但我认为问题可能出在这一行:
[Wed Feb 21 13:55:07.121703 2024] [proxy_ajp:debug] [pid 7769:tid 7944] mod_proxy_ajp.c(795): [client 10.133.0.30:64845] AH00894: declining URL fcgi://localhost/var/www/html/databases/index.php
如果我理解正确的话,FCGI是Apache和PHP之间的接口。如果 FCGI 拒绝连接,则 PHP 脚本将不会被解释,一切都会停止。
我们安装了SELinux,它经常引起问题,所以我暂时将其关闭。但这并没有帮助——即使将 SELinux 置于宽容模式下也会出现问题。所以我不认为这是 SELinux 问题。
服务器上的其他一切都工作正常。我有多个 PHP 应用程序位于它们自己的文件夹中,可以顺利运行。所以我推测这可能与符号链接有关。我删除了该链接,并将其替换为一个名为“databases”的普通文件夹,其中包含一个名为“Hello world”的index.html 文件。效果很好。我将index.html 重命名为index.php,它立即失败,并显示与上面相同的错误消息。一时兴起,我将该 index.php 文件复制到“test.php”并访问它。而且效果很好!
与此同时,计算机上的所有其他 PHP 应用程序都可以继续顺利运行。此外,尽管处于符号链接中,但在生产服务器上安装的 Drupal 仍运行良好。据我所知,问题仅发生在确切路径 /var/www/html/databases/index.php 上,无论数据库是实际文件夹还是符号链接。从字面上看,服务器上的所有其他 PHP 文件都工作正常。
我做了一些谷歌搜索。我没有找到遇到完全相同问题的人。我确实发现有些人在安装了反向代理的服务器上报告了错误代码 AH00894。这让我犹豫了,因为我确实设置了反向代理。服务器上的其他应用程序之一是古老的、粗糙的并且令人烦恼的是不可替代的。它不会在 PHP 5.6 之后的任何版本中运行。所以我有一个运行的 docker 容器提供 PHP 5.6 环境。Apache 配置为通过反向代理与 docker 实例通信,因此:
# Listen to all traffic on port 80.
<VirtualHost *:80>
# Keep the original host name.
ProxyPreserveHost On
# Redirect all traffic for the /archon folder to :8080 instead.
ProxyPass /archon http://localhost:8080/
ProxyPassReverse /archon http://localhost:8080/
</VirtualHost>
再次在 ssl.conf 中我有以下内容:
SSLProxyEngine On
ProxyPreserveHost On
# Prevent SSL offloading
RequestHeader set X-Forwarded-Proto "https"
RequestHeader set X-Forwarded-Port "443"
# Redirect all traffic for the /archon folder to :8080 instead.
ProxyPass /archon http://localhost:8080/
ProxyPassReverse /archon http://localhost:8080/
代理应用程序运行良好。我可以访问https://dev.example.com/archon/它会加载。但我想知道代理是否会以某种方式干扰 drupal 实例。
所以我禁用了所有代理的东西。我注释掉了 ssl.conf 中的虚拟主机和所有代理配置行,然后重新启动了 Apache。我确认 archon 按预期停止工作,然后尝试了我的 Drupal。它产生了完全相同的错误。所以我重新打开了所有代理的东西。
至此,我已经为这个问题绞尽脑汁两天了。如果我正确读取日志,问题是 FCGI 拒绝连接。但不知道为什么拒绝。为什么服务器上的所有其他 PHP 应用程序都工作正常?生产服务器的配置与开发服务器相同,但生产可以运行,而开发则不能。为什么?服务器上的所有其他 PHP 文件都非常有用。为什么?当其他一切都正常时,这个 URL 却总是死掉,这是怎么回事?
我也许可以将index.php 文件重命名为其他文件,然后使用.htaccess 文件将该文件名标识为文件夹的索引。这可能是一个解决方法。但这非常尴尬,而且我担心重命名 Drupal 的核心文件会导致意想不到的问题。我不知道 Drupal 的代码是否在任何地方硬编码了该文件名。
我被困住了。我不知道还有什么办法可以弄清楚这个可怜的东西到底出了什么问题。新服务器预计于 26 日星期一上线。我的时间很快就用完了,这是我的最后一个障碍。任何建议,将不胜感激。
500
Apache 仅在日志中显示,因为您正在使用php-fpm
并且 Apache 不知道问题的详细信息。它只是转发错误代码。php-fpm
有自己的日志文件,应显示详细的错误消息。