前言
前几天有个朋友突然发我个图片，说是nginx的日志记录，问问我是不是被漏洞利用了。印象中是接触过的，但是突然给我一张图片有点懵。处理完事情之后想了想，好像还没有仔细去分析过这些中间件的日志文件，还是做一下记录的比较好。
我们应该清楚，日志文件不但可以帮助我们溯源，找到入侵者攻击路径，而且在平常的运维中，日志也可以反应出很多的安全攻击行为。
环境
用的是win10虚拟机，工具是phpstudy pro，里面自带nginx和apache两个中间件，iis是微软的，一般在系统设置中都能找到
nginx日志
在linux中nginx的日志文件在 /var/log/nginx/access.log
access.log
在默认配置中，是开启了记录以下几个值
- • remote_addr #客户端地址
- • remote_user #用于HTTP基础认证服务的用户名
- • [time_local] #服务器时间
- • request #客户端的请求地址 url
- • status #HTTP响应代码
- • body_bytes_sent #传输给客户端的字节数，响应头不计算在内
- • http_referer #url跳转来源,用来记录从那个页面链接访问过来的
- • http_user_agent #用户终端浏览器等信息 UA
- • http_x_forwarded_for #获取到的IP地址
在日志文件里面，并不会标明字段的名称，只是由引号包含的一个值，依次排成一行记录
当然了，记录哪些值可以在是修改的，详情见nginx之日志设置
下面是我测试的nginx的日志记录
127.0.0.1 - - [18/Jul/2022:10:59:03 +0800] "GET / HTTP/1.1" 200 2307 "-" "Mozilla/5.0 (Windows NT 10.0; WOW64; Trident/7.0; Touch; rv:11.0) like Gecko" 127.0.0.1 - - [18/Jul/2022:10:59:06 +0800] "GET /pikachu/ HTTP/1.1" 200 35436 "-" "Mozilla/5.0 (Windows NT 10.0; WOW64; Trident/7.0; Touch; rv:11.0) like Gecko" 127.0.0.1 - - [18/Jul/2022:10:59:09 +0800] "GET /pikachu/vul/burteforce/bf_form.php HTTP/1.1" 200 34721 "http://localhost/pikachu/" "Mozilla/5.0 (Windows NT 10.0; WOW64; Trident/7.0; Touch; rv:11.0) like Gecko" 127.0.0.1 - - [18/Jul/2022:10:59:12 +0800] "POST /pikachu/vul/burteforce/bf_form.php HTTP/1.1" 200 31138 "http://localhost/pikachu/vul/burteforce/bf_form.php" "Mozilla/5.0 (Windows NT 10.0; WOW64; Trident/7.0; Touch; rv:11.0) like Gecko" 127.0.0.1 - - [18/Jul/2022:11:00:17 +0800] "GET / HTTP/1.1" 304 0 "-" "Mozilla/5.0 (Windows NT 10.0; WOW64; Trident/7.0; Touch; rv:11.0) like Gecko" 127.0.0.1 - - [18/Jul/2022:11:00:22 +0800] "GET /pikachu/ HTTP/1.1" 200 35436 "-" "Mozilla/5.0 (Windows NT 10.0; WOW64; Trident/7.0; Touch; rv:11.0) like Gecko" 127.0.0.1 - - [18/Jul/2022:11:00:24 +0800] "GET /pikachu/vul/burteforce/burteforce.php HTTP/1.1" 200 35005 "http://localhost/pikachu/" "Mozilla/5.0 (Windows NT 10.0; WOW64; Trident/7.0; Touch; rv:11.0) like Gecko" 127.0.0.1 - - [18/Jul/2022:11:00:25 +0800] "GET /pikachu/vul/burteforce/bf_form.php HTTP/1.1" 200 34721 "http://localhost/pikachu/vul/burteforce/burteforce.php" "Mozilla/5.0 (Windows NT 10.0; WOW64; Trident/7.0; Touch; rv:11.0) like Gecko" 127.0.0.1 - - [18/Jul/2022:11:00:30 +0800] "POST /pikachu/vul/burteforce/bf_form.php HTTP/1.1" 200 31138 "http://localhost/pikachu/vul/burteforce/bf_form.php" "Mozilla/5.0 (Windows NT 10.0; WOW64; Trident/7.0; Touch; rv:11.0) like Gecko" 127.0.0.1 - - [18/Jul/2022:11:00:40 +0800] "GET /pikachu/vul/burteforce/bf_server.php HTTP/1.1" 200 34982 "http://localhost/pikachu/vul/burteforce/bf_form.php" "Mozilla/5.0 (Windows NT 10.0; WOW64; Trident/7.0; Touch; rv:11.0) like Gecko" 127.0.0.1 - - [18/Jul/2022:11:00:40 +0800] "GET /pikachu/inc/showvcode.php HTTP/1.1" 200 1059 "http://localhost/pikachu/vul/burteforce/bf_server.php" "Mozilla/5.0 (Windows NT 10.0; WOW64; Trident/7.0; Touch; rv:11.0) like Gecko" 127.0.0.1 - - [18/Jul/2022:11:00:43 +0800] "GET /pikachu/pkxss/index.php HTTP/1.1" 200 579 "http://localhost/pikachu/vul/burteforce/bf_server.php" "Mozilla/5.0 (Windows NT 10.0; WOW64; Trident/7.0; Touch; rv:11.0) like Gecko" 127.0.0.1 - - [18/Jul/2022:11:00:45 +0800] "GET /pikachu/pkxss/pkxss_install.php HTTP/1.1" 200 726 "http://localhost/pikachu/pkxss/index.php" "Mozilla/5.0 (Windows NT 10.0; WOW64; Trident/7.0; Touch; rv:11.0) like Gecko" 127.0.0.1 - - [18/Jul/2022:11:00:46 +0800] "POST /pikachu/pkxss/pkxss_install.php HTTP/1.1" 200 74 "http://localhost/pikachu/pkxss/pkxss_install.php" "Mozilla/5.0 (Windows NT 10.0; WOW64; Trident/7.0; Touch; rv:11.0) like Gecko" 127.0.0.1 - - [18/Jul/2022:11:01:41 +0800] "GET /pikachu/ HTTP/1.1" 200 35436 "-" "Mozilla/5.0 (Windows NT 10.0; WOW64; Trident/7.0; Touch; rv:11.0) like Gecko"
第二个值，用户名，大多数情况下都是空的，不会记录用户名
我这里是没有开启记录http_x_forwarded_for字段，不过建议还是开启的，可以记录一些通过代理访问的原始ip。详细见下面几篇文章：
HTTP_X_FORWARDED_FOR获取到的IP地址：https://www.iteye.com/blog/gong1208-1559835
使用nginx后如何在web应用中获取用户ip及原理解释：https://www.iteye.com/blog/gong1208-1559835
如何正確的取得使用者 IP？ https://devco.re/blog/2014/06/19/client-ip-detection/
error.log
2022/07/18 15:40:58 [error] 11076#11580: *151 CreateFile() "C:/phpstudy_pro/WWW/favicon.ico" failed (2: The system cannot find the file specified), client: 192.168.186.1, server: localhost, request: "GET /favicon.ico HTTP/1.1", host: "192.168.186.128", referrer: "http://192.168.186.128/pikachu/vul/sqli/sqli_id.php" 2022/07/18 15:52:25 [error] 11076#11580: *176 FastCGI sent in stderr: "PHP Parse error: syntax error, unexpected end of file in C:\phpstudy_pro\WWW\pikachu\vul\rce\rce_eval.php(19) : eval()'d code on line 1" while reading response header from upstream, client: 192.168.186.1, server: localhost, request: "POST /pikachu/vul/rce/rce_eval.php HTTP/1.1", upstream: "fastcgi://127.0.0.1:9000", host: "192.168.186.128", referrer: "http://192.168.186.128/pikachu/vul/rce/rce_eval.php" 2022/07/18 15:52:30 [error] 11076#11580: *176 FastCGI sent in stderr: "PHP Parse error: syntax error, unexpected end of file in C:\phpstudy_pro\WWW\pikachu\vul\rce\rce_eval.php(19) : eval()'d code on line 1" while reading response header from upstream, client: 192.168.186.1, server: localhost, request: "POST /pikachu/vul/rce/rce_eval.php HTTP/1.1", upstream: "fastcgi://127.0.0.1:9000", host: "192.168.186.128", referrer: "http://192.168.186.128/pikachu/vul/rce/rce_eval.php" 2022/07/18 15:57:36 [error] 11076#11580: *192 FastCGI sent in stderr: "PHP Parse error: syntax error, unexpected end of file in C:\phpstudy_pro\WWW\pikachu\vul\rce\rce_eval.php(19) : eval()'d code on line 1" while reading response header from upstream, client: 192.168.186.1, server: localhost, request: "POST /pikachu/vul/rce/rce_eval.php HTTP/1.1", upstream: "fastcgi://127.0.0.1:9000", host: "192.168.186.128", referrer: "http://192.168.186.128/pikachu/vul/rce/rce_eval.php" 2022/07/21 22:00:32 [error] 11076#11580: *223 CreateFile() "C:/phpstudy_pro/WWW/pikachu/assets/js/jquery.min.map" failed (2: The system cannot find the file specified), client: 192.168.186.1, server: localhost, request: "GET /pikachu/assets/js/jquery.min.map HTTP/1.1", host: "192.168.186.128" 2022/07/21 22:00:32 [error] 11076#11580: *224 CreateFile() "C:/phpstudy_pro/WWW/pikachu/assets/css/bootstrap.min.css.map" failed (2: The system cannot find the file specified), client: 192.168.186.1, server: localhost, request: "GET /pikachu/assets/css/bootstrap.min.css.map HTTP/1.1", host: "192.168.186.128" 2022/07/21 22:00:33 [error] 11076#11580: *224 CreateFile() "C:/phpstudy_pro/WWW/favicon.ico" failed (2: The system cannot find the file specified), client: 192.168.186.1, server: localhost, request: "GET /favicon.ico HTTP/1.1", host: "192.168.186.128", referrer: "http://192.168.186.128/pikachu/" 2022/07/31 15:09:28 [error] 8812#8188: *3 CreateFile() "C:/phpstudy_pro/WWW/123" failed (2: The system cannot find the file specified), client: 192.168.186.1, server: localhost, request: "GET /123 HTTP/1.1", host: "192.168.186.128" 2022/07/31 15:10:47 [error] 8812#8188: *11 FastCGI sent in stderr: "PHP Warning: Unexpected character in input: '' (ASCII=1) state=0 in C:\phpstudy_pro\WWW\123.php(2) : eval()'d code on line 1 PHP Warning: Unexpected character in input: '' (ASCII=1) state=0 in C:\phpstudy_pro\WWW\123.php(2) : eval()'d code on line 1 PHP Fatal error: Uncaught Error: Call to undefined function set_magic_quotes_runtime() in C:\phpstudy_pro\WWW\123.php(2) : eval()'d code(1) : eval()'d code:1 Stack trace: #0 C:\phpstudy_pro\WWW\123.php(2) : eval()'d code(1): eval() #1 C:\phpstudy_pro\WWW\123.php(2): eval() #2 {main} thrown in C:\phpstudy_pro\WWW\123.php(2) : eval()'d code(1) : eval()'d code on line 1" while reading response header from upstream, client: 192.168.186.1, server: localhost, request: "POST /123.php HTTP/1.1", upstream: "fastcgi://127.0.0.1:9000", host: "192.168.186.128", referrer: "http://192.168.186.128/"
这个报错日志里面，会有一些报错的详细信息，并标明了值的名称
Nginx错误日志（error_log）配置及信息详解：https://blog.csdn.net/czlun/article/details/73251714
Apache日志
access.log
跟上面nginx的类似，大致看一下就知道是哪个参数了，就不过多介绍了，这个也是可以自己设置记录哪些信息的
192.168.186.1 - - [31/Jul/2022:15:16:13 +0800] "GET /pikachu/vul/unsafedownload/download/kb.png HTTP/1.1" 200 21651 192.168.186.1 - - [31/Jul/2022:15:16:13 +0800] "GET /pikachu/vul/unsafedownload/download/ai.png HTTP/1.1" 200 28747 192.168.186.1 - - [31/Jul/2022:15:16:13 +0800] "GET /pikachu/vul/unsafedownload/download/ns.png HTTP/1.1" 200 30459 192.168.186.1 - - [31/Jul/2022:15:16:13 +0800] "GET /pikachu/vul/unsafedownload/download/mbl.png HTTP/1.1" 200 23514 192.168.186.1 - - [31/Jul/2022:15:16:13 +0800] "GET /pikachu/vul/unsafedownload/download/camby.png HTTP/1.1" 200 20220 192.168.186.1 - - [31/Jul/2022:15:16:13 +0800] "GET /pikachu/vul/unsafedownload/download/bigben.png HTTP/1.1" 200 23875 192.168.186.1 - - [31/Jul/2022:15:16:13 +0800] "GET /pikachu/vul/unsafedownload/download/pj.png HTTP/1.1" 200 24798 192.168.186.1 - - [31/Jul/2022:15:16:13 +0800] "GET /pikachu/vul/unsafedownload/download/oldfish.png HTTP/1.1" 200 19766 192.168.186.1 - - [31/Jul/2022:15:16:13 +0800] "GET /pikachu/vul/unsafedownload/download/lmx.png HTTP/1.1" 200 24597 192.168.186.1 - - [31/Jul/2022:15:16:13 +0800] "GET /pikachu/vul/unsafedownload/download/rayal.png HTTP/1.1" 200 23034 192.168.186.1 - - [31/Jul/2022:15:16:13 +0800] "GET /pikachu/vul/unsafedownload/download/smallane.png HTTP/1.1" 200 21210 192.168.186.1 - - [31/Jul/2022:15:16:13 +0800] "GET /pikachu/vul/unsafedownload/download/sks.png HTTP/1.1" 200 21481 192.168.186.1 - - [31/Jul/2022:15:16:16 +0800] "GET /pikachu/vul/unsafeupload/clientcheck.php HTTP/1.1" 200 34427 192.168.186.1 - - [31/Jul/2022:15:16:19 +0800] "GET /pikachu/vul/unsafeupload/servercheck.php HTTP/1.1" 200 33702 192.168.186.1 - - [31/Jul/2022:15:16:20 +0800] "GET /pikachu/vul/unsafeupload/getimagesize.php HTTP/1.1" 200 33707 192.168.186.1 - - [31/Jul/2022:15:16:21 +0800] "GET /pikachu/vul/unsafeupload/clientcheck.php HTTP/1.1" 200 34427 192.168.186.1 - - [31/Jul/2022:15:16:35 +0800] "POST /pikachu/vul/unsafeupload/clientcheck.php HTTP/1.1" 200 34529 192.168.186.1 - - [31/Jul/2022:15:17:05 +0800] "POST /pikachu/uploads/1.jpg HTTP/1.1" 404 2659 192.168.186.1 - - [31/Jul/2022:15:17:07 +0800] "POST /pikachu/uploads/1.jpg HTTP/1.1" 404 2659 192.168.186.1 - - [31/Jul/2022:15:17:16 +0800] "GET /pikachu/uploads/1.jpg HTTP/1.1" 404 2659 192.168.186.1 - - [31/Jul/2022:15:17:55 +0800] "GET /pikachu/vul/unsafeupload/uploads/1.jpg HTTP/1.1" 200 11549 192.168.186.1 - - [31/Jul/2022:15:18:10 +0800] "POST /pikachu/vul/unsafeupload/uploads/1.jpg HTTP/1.1" 200 11549 192.168.186.1 - - [31/Jul/2022:15:18:12 +0800] "POST /pikachu/vul/unsafeupload/uploads/1.jpg HTTP/1.1" 200 11549 192.168.186.1 - - [31/Jul/2022:15:18:14 +0800] "POST /pikachu/vul/unsafeupload/uploads/1.jpg HTTP/1.1" 200 11549 192.168.186.1 - - [31/Jul/2022:15:18:17 +0800] "POST /pikachu/vul/unsafeupload/uploads/1.jpg HTTP/1.1" 200 11549 192.168.186.1 - - [31/Jul/2022:15:18:21 +0800] "POST /pikachu/vul/unsafeupload/uploads/1.jpg HTTP/1.1" 200 11549 192.168.186.1 - - [31/Jul/2022:15:18:30 +0800] "GET /pikachu/vul/unsafeupload/servercheck.php HTTP/1.1" 200 33702 192.168.186.1 - - [31/Jul/2022:15:18:31 +0800] "GET /pikachu/vul/unsafeupload/getimagesize.php HTTP/1.1" 200 33707 192.168.186.1 - - [31/Jul/2022:15:18:32 +0800] "GET /pikachu/vul/unsafeupload/getimagesize.php HTTP/1.1" 200 33707 192.168.186.1 - - [31/Jul/2022:15:18:33 +0800] "GET /pikachu/vul/unsafeupload/upload.php HTTP/1.1" 200 34593 192.168.186.1 - - [31/Jul/2022:15:18:36 +0800] "POST /pikachu/vul/unsafeupload/uploads/1.jpg HTTP/1.1" 200 11549 192.168.186.1 - - [31/Jul/2022:15:18:46 +0800] "POST /pikachu/vul/unsafeupload/uploads/1.jpg HTTP/1.1" 200 11549
error.log
[Sun Jul 31 13:48:06.239225 2022] [core:warn] [pid 760:tid 560] AH00098: pid file C:/phpstudy_pro/Extensions/Apache2.4.39/logs/httpd.pid overwritten -- Unclean shutdown of previous Apache run? [Sun Jul 31 13:48:06.255160 2022] [mpm_winnt:notice] [pid 760:tid 560] AH00455: Apache/2.4.39 (Win64) OpenSSL/1.1.1b mod_fcgid/2.3.9a mod_log_rotate/1.02 configured -- resuming normal operations [Sun Jul 31 13:48:06.255160 2022] [mpm_winnt:notice] [pid 760:tid 560] AH00456: Server built: Mar 27 2019 11:06:20 [Sun Jul 31 13:48:06.255160 2022] [core:notice] [pid 760:tid 560] AH00094: Command line: 'C:\\phpstudy_pro\\COM\\..\\Extensions\\Apache2.4.39\\\\bin\\httpd.exe -d C:/phpstudy_pro/Extensions/Apache2.4.39' [Sun Jul 31 13:48:06.255160 2022] [mpm_winnt:notice] [pid 760:tid 560] AH00418: Parent: Created child process 10112 [Sun Jul 31 13:48:06.598686 2022] [mpm_winnt:notice] [pid 10112:tid 632] AH00354: Child: Starting 1024 worker threads. [Sun Jul 31 15:12:07.933886 2022] [core:warn] [pid 300:tid 548] AH00098: pid file C:/phpstudy_pro/Extensions/Apache2.4.39/logs/httpd.pid overwritten -- Unclean shutdown of previous Apache run? [Sun Jul 31 15:12:07.933886 2022] [mpm_winnt:notice] [pid 300:tid 548] AH00455: Apache/2.4.39 (Win64) OpenSSL/1.1.1b mod_fcgid/2.3.9a mod_log_rotate/1.02 configured -- resuming normal operations [Sun Jul 31 15:12:07.933886 2022] [mpm_winnt:notice] [pid 300:tid 548] AH00456: Server built: Mar 27 2019 11:06:20 [Sun Jul 31 15:12:07.933886 2022] [core:notice] [pid 300:tid 548] AH00094: Command line: 'C:\\phpstudy_pro\\COM\\..\\Extensions\\Apache2.4.39\\\\bin\\httpd.exe -d C:/phpstudy_pro/Extensions/Apache2.4.39' [Sun Jul 31 15:12:07.949393 2022] [mpm_winnt:notice] [pid 300:tid 548] AH00418: Parent: Created child process 12192 [Sun Jul 31 15:12:08.262789 2022] [mpm_winnt:notice] [pid 12192:tid 628] AH00354: Child: Starting 1024 worker threads. [Sun Jul 31 15:51:59.766582 2022] [core:warn] [pid 12212:tid 568] AH00098: pid file C:/phpstudy_pro/Extensions/Apache2.4.39/logs/httpd.pid overwritten -- Unclean shutdown of previous Apache run? [Sun Jul 31 15:51:59.766582 2022] [mpm_winnt:notice] [pid 12212:tid 568] AH00455: Apache/2.4.39 (Win64) OpenSSL/1.1.1b mod_fcgid/2.3.9a mod_log_rotate/1.02 configured -- resuming normal operations [Sun Jul 31 15:51:59.766582 2022] [mpm_winnt:notice] [pid 12212:tid 568] AH00456: Server built: Mar 27 2019 11:06:20 [Sun Jul 31 15:51:59.766582 2022] [core:notice] [pid 12212:tid 568] AH00094: Command line: 'C:\\phpstudy_pro\\COM\\..\\Extensions\\Apache2.4.39\\\\bin\\httpd.exe -d C:/phpstudy_pro/Extensions/Apache2.4.39' [Sun Jul 31 15:51:59.766582 2022] [mpm_winnt:notice] [pid 12212:tid 568] AH00418: Parent: Created child process 9848 [Sun Jul 31 15:52:00.094706 2022] [mpm_winnt:notice] [pid 9848:tid 184] AH00354: Child: Starting 1024 worker threads.
apache的错误日志里面，会记录报错的pid和tid、和错误类型，跟其他的还是略有不同的
nginx和apache日志区别
nginx
log_format main '$remote_addr - $remote_user [$time_local] "$request" '
'$status $body_bytes_sent "$http_referer" '
'"$http_user_agent" $request_time';
日志格式说明：
$remote_addr 远程请求使用的IP地址 $remote_user 远端登录名
$time_local 时间，用普通日志时间格式(标准英语格式)
$request 请求的第一行 $status 状态。
$body_bytes_sent 请求返回的字节数，包括请求头的数据
$http_referer 请求头Referer的内容
$http_user_agent 请求头User-Agent的内容
$request_time 处理完请求所花时间，以秒为单位
apache
LogFormat "%h %l %u %t "%r" %>s %b "%{Referer}i" "%{User-Agent}i" %T " combined
CustomLog log/access_log combined
日志格式说明： %h 请求使用的IP地址 %l 远端登录名(由identd而来，如果支持的话)，除非IdentityCheck设为"On"，否则将得到一个"-"。
%u 远程用户名(根据验证信息而来；如果返回status(%s)为401，可能是假的)
%t 时间，用普通日志时间格式(标准英语格式) %r 请求的第一行
%s 状态。对于内部重定向的请求，这个状态指的是原始请求的状态，%>s则指的是最后请求的状态。
%b 以CLF格式显示的除HTTP头以外传送的字节数，也就是当没有字节传送时显示'-'而不是0。 "%{Referer}i" 发送到服务器的请求头Referer的内容。 "%{User-Agent}i" 发送到服务器的请求头User-Agent的内容。
%T处理完请求所花时间，以秒为单位。
%I 接收的字节数，包括请求头的数据，并且不能为零。要使用这个指令你必须启用mod_logio模块。 %O 发送的字节数，包括请求头的数据，并且不能为零。要使用这个指令你必须启用mod_logio模块。
摘选自 nginx和apache日志格式详解：https://blog.51cto.com/shenliyang/1364883
详细的一些web攻击方法的日志，有位大佬做了一些整理，可以参考：https://blog.csdn.net/weixin_44578334/article/details/110919323
