«排查一个让我气哭的 BUG»
by pluvet on Dec 7, 2019

我是如何排查一个让我气哭的 BUG 的

事情要从半年前说起。在当时发布那篇文章中,我在评论区提到“邮件配置一直不成功”,是的,当时我开启了防火墙的所有和邮件有关的端口,但就是发不出去邮件,甚至连转发也不能。当时调了好几天,都没有解决。最后,我只好放弃,选择了用别人设置好的虚拟主机。

时间到了二零一九年年末。由于有记笔记的好习惯,我很快搭建好了 LAMP 环境。但是却发现,博客的附件无法上传。博客的附件,通过cosUploadV5插件,应该被上传到我的腾讯云储存桶。但是试了几次,一直无限转圈圈。等等,现在还在转:

image-20191206225701689.png

自然,应该是哪里出了问题。我想到了看错误信息。打开 Chrome 自带的控制台,果不其然有报错:

Uncaught SyntaxError: Unexpected token < in JSON at position 0
    at JSON.parse (<anonymous>)
    at Function.jQuery.parseJSON (jquery.js?v=18.10.23:7490)
    at plupload.Uploader.FileUploaded (write-post.php:1070)
    at plupload.Uploader.dispatchEvent (plupload.js?v=18.10.23:2205)
    at plupload.Uploader.trigger (moxie.js?v=18.10.23:2240)
    at XMLHttpRequest.xhr.onload (plupload.js?v=18.10.23:1585)
    at XMLHttpRequest.<anonymous> (moxie.js?v=18.10.23:2256)
    at Array.<anonymous> (moxie.js?v=18.10.23:2172)
    at callNext (moxie.js?v=18.10.23:374)
    at Object.inSeries (moxie.js?v=18.10.23:380)

通过一系列追踪,我定位到了插件源代码 201 行:

/usr/plugins/cosUploadV5/src/Guzzle/Http/Curl/CurlHandle.php

这里通过 curl 发起了请求。然而遇到错误:

curl (6) couldn't resolve host

第一反应,是 DNS 服务器设置有误。执行 sudo vi /etc/resolv.conf,可以发现是谷歌的 Public DNS,谷歌基本不可能出错,而且我服务器在魔法触及不到的地方,不存在墙的问题,但是以防万一,我把首选 DNS 改成了 CloudFlare 家的 1.1.1.1

然后再次尝试上传:

没用。一直无限转圈圈:

image-20191206225701689.png

这就奇怪了。是不是 DNS 没生效呢?我执行:

sudo service network restart
sudo service httpd restart

然后再次尝试上传:

没用。还是一直无限转圈圈:

image-20191206225701689.png

难道要重启不成?

sudo reboot

然后再次尝试上传:

没用。还是一直无限转圈圈:

image-20191206225701689.png

那么,我直接 ping 会怎样?

$ ping www.google.com
PING www.google.com (172.217.31.228) 56(84) bytes of data.
64 bytes from hkg07s28-in-f4.1e100.net (172.217.31.228): icmp_seq=1 ttl=54 time=1.68 ms
64 bytes from hkg07s28-in-f4.1e100.net (172.217.31.228): icmp_seq=2 ttl=54 time=1.77 ms
64 bytes from hkg07s28-in-f4.1e100.net (172.217.31.228): icmp_seq=3 ttl=54 time=1.73 ms
64 bytes from hkg07s28-in-f4.1e100.net (172.217.31.228): icmp_seq=4 ttl=54 time=1.69 ms
64 bytes from hkg07s28-in-f4.1e100.net (172.217.31.228): icmp_seq=5 ttl=54 time=1.95 ms
64 bytes from hkg07s28-in-f4.1e100.net (172.217.31.228): icmp_seq=6 ttl=54 time=1.72 ms
64 bytes from hkg07s28-in-f4.1e100.net (172.217.31.228): icmp_seq=7 ttl=54 time=1.75 ms
64 bytes from hkg07s28-in-f4.1e100.net (172.217.31.228): icmp_seq=8 ttl=54 time=1.67 ms
^C
--- www.google.com ping statistics ---
8 packets transmitted, 8 received, 0% packet loss, time 7012ms
rtt min/avg/max/mdev = 1.677/1.750/1.957/0.094 ms

显然,十分正常,并且说明我的 DNS 服务器运转良好。

在 Stackoverflow 某帖子的启发下,我写了一个文件

<?php
$ch = curl_init('www.google.com');
curl_setopt($ch, CURLOPT_IPRESOLVE, CURL_IPRESOLVE_V4);
curl_setopt($ch, CURLOPT_RETURNTRANSFER, false);
curl_setopt($ch, CURLOPT_HEADER, true);
curl_exec($ch);

通过浏览器访问其 url,自然,发生了域名解析错误。

然后我通过 php 的交互模式执行:

$ php
<?php
$ch = curl_init('www.google.com');
curl_setopt($ch, CURLOPT_IPRESOLVE, CURL_IPRESOLVE_V4);
curl_setopt($ch, CURLOPT_RETURNTRANSFER, false);
curl_setopt($ch, CURLOPT_HEADER, true);
curl_exec($ch);
HTTP/1.1 200 OK
Date: Fri, 06 Dec 2019 15:09:45 GMT
Expires: -1
Cache-Control: private, max-age=0
Content-Type: text/html; charset=ISO-8859-1
P3P: CP="This is not a P3P policy! See g.co/p3phelp for more info."
Server: gws
X-XSS-Protection: 0
X-Frame-Options: SAMEORIGIN
Set-Cookie: 1P_JAR=2019-12-06-15; expires=Sun, 05-Jan-2020 15:09:45 GMT; path=/; domain=.google.com
Set-Cookie: NID=193=Dma_WfgEDig7HlMLDpRAFZa7y7GIQlqC_SwBhfMnJausKKGw45c4TMPACIXitQU_rRoCk-AQfVH_4wK57B5ano3hQPU8fezAhO_Ou5qgpa8nw8fqG8P3hMLdwLaacmN8NB8HT-FFI3r3NKOwu-POo0V29j5F08UNXYLaA4obQ94; expires=Sat, 06-Jun-2020 15:09:45 GMT; path=/; domain=.google.com; HttpOnly
Accept-Ranges: none
Vary: Accept-Encoding
Transfer-Encoding: chunked

这没问题呀。所以奇怪之处就是:在网站脚本中写这些代码,Not Working。但是在 shell 中以交互模式执行,就没毛病。同时,也排除了防火墙的问题。

这时候首先想到的就是权限问题。

我通过 chown 更改文件权限,无效。

我通过 sudo 切换到 apache 用户视角,交互模式执行,没毛病。

这说明不是用户权限的问题。

但是知道和权限有关之后,大概有了 Google 的方向。然而在国内网站搜到的,清一色是关闭防火墙或者关闭 SELINUX 这样的不负责任的操作。

一时间解决不了,我向网友提问。不过没有人回答。

PHP curl 无法解析域名这个问题下,说是关闭 chroot 解决的。于是我仔细研读了 chroot 的相关资料,得出结论是这个方法对我们 Apache 服务器不适用。同时,关闭 chroot 和关闭 SELinux 一样,都是不负责任的行为,会给服务器带来很大的危险。

image-20191206231739776.png

我一时间真的不知道该怎么办了。

一番思索后,我考虑:会不会是 CURL 的问题呢?

于是我编写了这个文件:

<?php
$ip = gethostbyname('www.example.com');
echo $ip;

结果,在交互模式执行,返回的是 ip,在浏览器打开,返回的是域名。

怎么回事?查询php文档得知:

Returns the IPv4 address or a string containing the unmodified hostname on failure.

当失败的时候,返回的是不经修改的原域名。

这排除了 CURL 的问题。并且更加确定是权限的问题。我把 CURL GETHOSTBYNAME SELINUX CHROOT APACHE CENTOS 这些关键词变着花样地搜索,都没有找到满意的答案。

不过,倒是有很多人建议这么做:

setsebool -P httpd_can_network_connect 1

这里是允许 Apache 连接网络。言外之意,SELinux 开启的状态下,默认的设置下,Apache 无法接触到外部网络。我照此执行。然而结果毫无变化。但是考虑到 SELinux 让我吃过那么多苦头,我觉得和 SELinux 关系很大。

不情愿地,我尝试性地执行:

setenforce 0

这里的作用,根据 Manuel,是将 SELinux 设为被动模式。

问题消失了。

可是,这并不是我想要的答案,这么做和关闭 SELinux 没有区别,都是不负责任的行为。

不过,可以肯定,问题必然和 SELinux 有关。我开始大量搜集和 SELinux 有关的资料。其中,比较重要的是“SELinux User's and Administrator's Guide”。

我觉得和 httpd 有关的那些 bool 值很可能是罪魁祸首。

根据:

  1. https://wiki.centos.org/TipsAndTricks/SelinuxBooleans
  2. https://access.redhat.com/documentation/en-us/red_hat_enterprise_linux/7/html/selinux_users_and_administrators_guide/sect-managing_confined_services-the_apache_http_server-booleans

我试着开启了几个,但是无用。

然后我遇到了这篇文章 How To Enable Or Disable SELinux In CentOS/RHEL 7

他提到,安装 setroubleshoot-server 可以帮忙排查问题。

However when I try to view the index file in Firefox, the index.html page content does not display and I get the below error in the /var/log/messages file.

cat /var/log/messages,没有找到任何线索。

从头仔细阅读这篇文章后,我注意到他说:

于是,我暂时性地设为被动模式:

sudo setenforce 0

然后刷新那个测试页面。

然后less /var/log/messages

果然找到了问题。

不要被这令人作呕的日志吓跑。我们慢慢读。

tmp_t, man2html_content_t, man2html_htaccess_t, man2html_ra_content_t, man2html_rw_content_t, man2html_script_exec_t, man_cache_t, man_t, mandb_cache_t, mcelog_exec_t, mdadm_tmp_t, mediawiki_content_t, mediawiki_htaccess_t, mediawiki_ra_content_t, mediawiki_rw_content_t, mediawiki_script_exec_t, mediawiki_tmp_t, mencoder_exe
c_t, mirrormanager_exec_t, mirrormanager_log_t, mirrormanager_var_lib_t, mirrormanager_var_run_t, mock_build_exec_t, mock_exec_t, mock_tmp_t, modemman             Dec  6 22:45:42 Yecaoyun-2019126515 /usr/bin/sealert: LogfileAnalyzer.open(): Permission denied                                                                    Dec  6 22:45:49 Yecaoyun-2019126515 /bin/sealert: failed to retrieve rpm info for /etc/sysconfig/network-scripts/ifcfg-eth0                                        Dec  6 22:46:50 Yecaoyun-2019126515 dbus[489]: [system] Activating service name='org.fedoraproject.Setroubleshootd' (using servicehelper)                          Dec  6 22:46:51 Yecaoyun-2019126515 dbus[489]: [system] Successfully activated service 'org.fedoraproject.Setroubleshootd'                                         Dec  6 22:46:51 Yecaoyun-2019126515 setroubleshoot: failed to retrieve rpm info for /etc/resolv.conf                                                               Dec  6 22:46:52 Yecaoyun-2019126515 setroubleshoot: SELinux is preventing /usr/sbin/httpd from getattr access on the file /etc/resolv.conf. For complete SELinux me
ssages run: sealert -l f11038bf-3fc9-4611-9d21-0b38b6dd63e5                                                                                                        Dec  6 22:46:52 Yecaoyun-2019126515 python: SELinux is preventing /usr/sbin/httpd from getattr access on the file /etc/resolv.conf.#012#012*****  Plugin restorecon (82.4 confidence) suggests   ************************#012#012If you want to fix the label. #012/etc/resolv.conf default label should be net_conf_t.#012Then you can run restorecon. The access attempt may have been stopped due to insufficient permissions to access a parent directory in which case try to change the following command accordingly.#012Do#012# /sbin/restorecon -v /etc/resolv.conf#012#012*****  Plugin file (7.05 confidence) suggests   ******************************#012#012If you think this is caused by a badly mislabeled machine.#012Then you need to fully relabel.#012Do#012touch /.autorelabel; reboot#012#012*****  Plugin file (7.05 confidence) suggests   ******************************#012#012If you think this is caused by a badly mislabeled machine.#012Then you need to fully relabel.#012Do#012touch /.autorelabel; reboot#012#012*****  Plugin catchall_labels (4.59 confidence) suggests   *******************#012#012If you want to allow httpd to have getattr access on the resolv.conf file#012Then you need to change the label on /etc/resolv.conf#012Do#012# semanage fcontext -a -t FILE_TYPE '/etc/resolv.conf'#012where FILE_TYPE is one of the following: NetworkManager_exec_t, NetworkManager_log_t, NetworkManager_tmp_t, abrt_dump_oops_exec_t, abrt_etc_t, abrt_exec_t, abrt_handle_event_exec_t, abrt_helper_exec_t, abrt_retrace_coredump_exec_t, abrt_retrace_spool_t, abrt_retrace_worker_exec_t, abrt_tmp_t, abrt_upload_watch_tmp_t, abrt_var_cache_t, abrt_var_log_t, abrt_var_run_t, accountsd_exec_t, acct_data_t, acct_exec_t, admin_crontab_tmp_t, admin_passwd_exec_t, afs_logfile_t, aide_exec_t, aide_log_t, alsa_exec_t, alsa_tmp_t, amanda_exec_t, amanda_log_t, amanda_recover_exec_t, amanda_tmp_t, amtu_exec_t, anacron_exec_t, anon_inodefs_t, antivirus_exec_t, antivirus_log_t, antivirus_tmp_t, apcupsd_cgi_content_t, apcupsd_cgi_htaccess_t, apcupsd_cgi_ra_content_t, apcupsd_cgi_rw_content_t, apcupsd_cgi_script_exec_t, apcupsd_log_t, apcupsd_tmp_t, apm_exec_t, apmd_log_t, apmd_tmp_t, arpwatch_tmp_t, asterisk_log_t, asterisk_tmp_t, audisp_exec_t, auditadm_sudo_tmp_t, auditctl_exec_t, auth_cache_t, authconfig_exec_t, automount_tmp_t, avahi_exec_t, awstats_content_t, awstats_htaccess_t, awstats_ra_content_t, awstats_rw_content_t, awstats_script_exec_t, awstats_tmp_t, bacula_admin_exec_t, bacula_log_t, bacula_tmp_t, bacula_unconfined_script_exec_t, bin_t, bitlbee_log_t, bitlbee_tmp_t, blueman_exec_t, bluetooth_helper_exec_t, bluetooth_helper_tmp_t, bluetooth_helper_tmpfs_t, bluetooth_tmp_t, boinc_log_t, boinc_project_tmp_t, boinc_tmp_t, boot_t, bootloader_exec_t, bootloader_tmp_t, brctl_exec_t, brltty_log_t, bugzilla_content_t, bugzilla_htaccess_t, bugzilla_ra_content_t, bugzilla_rw_content_t, bugzilla_script_exec_t, bugzilla_tmp_t, calamaris_exec_t, calamaris_log_t, calamaris_www_t, callweaver_log_t, canna_log_t, cardctl_exec_t, cardmgr_dev_t, ccs_tmp_t, ccs_var_lib_t, ccs_var_log_t, cdcc_exec_t
, cdcc_tmp_t, cdrecord_exec_t, cert_t, certmaster_var_log_t, certmonger_unconfined_exec_t, certwatch_exec_t, cfengine_log_t, cgred_log_t, checkpc_exec_t, checkpc_log_t, checkpolicy_exec_t, chfn_exec_t, chkpwd_exec_t, chrome_sandbox_exec_t, chrome_sandbox_nacl_exec_t, chrome_sandbox_tmp_t, chronyc_exec_t, chronyd_tmp_t, chronyd_var_log_t, cinder_api_tmp_t, cinder_backup_tmp_t, cinder_log_t, cinder_scheduler_tmp_t, cinder_volume_tmp_t, cloud_init_tmp_t, cloud_log_t, cluster_conf_t, cluster_tmp_t, cluster_var_lib_t, cluster_var_log_t, cluster_var_run_t, cobbler_etc_t, cobbler_tmp_t, cobbler_var_lib_t, cobbler_var_log_t, cockpit_tmp_t, collectd_con
tent_t, collectd_htaccess_t, collectd_ra_content_t, collectd_rw_content_t, collectd_script_exec_t, collectd_script_tmp_t, colord_exec_t, colord_tmp_t, comsat_tmp_t, condor_log_t, condor_master_tmp_t, condor_schedd_tmp_t, condor_startd_tmp_t, conman_log_t, conman_tmp_t, conman_unconfined_script_exec_t, consolehelper_exec_t, consolekit_exec_t, consolekit_log_t, container_log_t, container_runtime_tmp_t, couchdb_log_t, couchdb_tmp_t, courier_exec_t, cpu_online_t, cpucontrol_exec_t, cpufreqselector_exec_t, cpuspeed_exec_t, crack_exec_t, crack_tmp_t, cron_log_t, crond_tmp_t, crontab_exec_t, crontab_tmp_t, ctdbd_log_t, ctdbd_tmp_t, cups_pdf_tmp_t, cupsd_config_exec_t, cupsd_log_t, cupsd_lpd_tmp_t, cupsd_tmp_t, cvs_content_t, cvs_data_t, cvs_exec_t, cvs_htaccess_t, cvs_ra_content_t, cvs_rw_content_t, cvs_script_exec_t, cvs_tmp_t, cyphesis_exec_t, cyphesis_log_t, cyphesis_tmp_t, cyrus_tmp_t, dbadm_sudo_tmp_t, dbskkd_tmp_t, dbusd_etc_t, dbusd_exec_t, dcc_client_exec_t, dcc_client_tmp_t, dcc_dbclean_exec_t, dcc_dbclean_tmp_t, dccd_tmp_t, dccifd_tmp_t, dccm_tmp_t, ddclient_log_t, ddclient_tmp_t, debuginfo_exec_t, deltacloudd_log_t, del
:

我们可以看到几个关键:

  1. failed to retrieve rpm info for /etc/resolv.conf
  2. For complete SELinux messages run: sealert -l f11038bf-3fc9-4611-9d21-0b38b6dd63e5
  3. If you think this is caused by a badly mislabeled machine. Then you need to fully relabel.
    Do touch /.autorelabel; reboot

我执行 sealert -l f11038bf-3fc9-4611-9d21-0b38b6dd63e5

结果:

image-20191206234210576.png

前面还有好几页。

其中,最为关键的是:

allow this access for now by executing:

ausearch -c 'httpd' --raw | audit2allow -M my-httpd

执行

sudo ausearch -c 'httpd' --raw | less

结果中好像还是一团乱。容易发现:

type=AVC msg=audit(1575613783.791:925): avc:  denied  { getattr } for  pid=12038 comm="httpd" path="/etc/resolv.conf" dev="vda1" ino=4086 scontext=system_u:system_r:httpd_t:s0 tcontext=system_u:object_r:unlabeled_t:s0 tclass=file permissive=0

通过这些文字,我找到了红帽的一个 BUG 汇报。顺着读下去可以看到:

Ok,
/etc/resolv.conf has definitely bad labeling.
If you execute

restorecon -R -v /etc/resolv.con

does it happen again? We need to find a reason why is mislabeled.

他的意思是,文件被错误地标记了。

我执行:

ls -laZ /etc/resolv.conf 
-rw-r--r--. root root system_u:object_r:unlabeled_t:s0 /etc/resolv.conf

查询 restorecon 的 Manuel:

restorecon(8)
NAME
    restorecon - restore file(s) default SELinux security contexts

执行:

sudo restorecon -R -v /etc/resolv.conf

貌似什么也没有发生。不过此时 ls -laZ 的话可以发现它的标签变了。

怎么样了?来试试吧。

最后开启 SElinux 为完全状态:

sudo setenforce 1

重新访问测试地址

image-20191206235059411.png

重新上传图片

image-20191206235306130.png

成功了(☆-v-)

悬 案 就 此 告 破。

同样解决的还有半年前的那个问题。

谁能想到,博客的图片附件不能上传,通知邮件发不出去,竟是因为一个系统文件被打上了错误的标签。

而解决这个问题,只需一句短短的

sudo restorecon -R -v /etc/resolv.conf

而你永远不知道获得这一最终答案的路途,会是多么的艰辛。

结语

做这样的工作,需要极大的耐心,而且,英语还要好(你以为我读长篇英语技术文章不会头大吗::>_<::)。

哎,我竟然这么有耐心(崩溃)。我没有疯,我没有!!!!

添加新评论