🔧
「invalid character '.' after top-level value」エラーでalpの出力がうまくいかない
ISUCON本のprivate-isuに取り組んでいて、nginxのアクセスログをalpでうまく出力できずにプチはまりしたのでメモとして残しておきます。
エラーの内容
alpで結果を見ようとすると次のようなエラーが出ました
$ cat logs/nginx/access.log | alp json
invalid character '.' after top-level value
解消方法
私の場合、ログファイル内にJSON化前のログが混ざっていたことが原因でした。
その中でも大きく2パターン踏みました😭
原因①：JSON化は上手くいっているけれどログファイルにJSON化前のログが混ざっているパターン
ログファイル内にJSON化前のものが混ざっていると結果の出力に失敗します。
1度ログファイルを削除してから試してみるとうまくいくかも？
# docker環境の場合
$ rm logs/nginx/access.log
$ docker compose down
$ docker compose up -d # nginxを再起動しないと新しいログファイルが作られない
$ cat logs/nginx/access.log | alp json
原因②：nginxの設定がうまくいっていないパターン(デフォルト形式とJSON形式の出力が混ざっている)
webapp/etc/nginx/conf.d/default.conf
log_format json escape=json '{"time":"$time_iso8601",'
'"host":"$remote_addr",'
'"port":$remote_port,'
'"method":"$request_method",'
'"uri":"$request_uri",'
'"status":"$status",'
'"body_bytes":$body_bytes_sent,'
'"referer":"$http_referer",'
'"ua":"$http_user_agent",'
'"request_time":"$request_time",'
'"response_time":"$upstream_response_time"}';
access_log /var/log/nginx/access.log json; # server {}の外に記述
server {
listen 80;
client_max_body_size 10m;
root /public/;
location / {
proxy_set_header Host $host;
proxy_pass http://app:8080;
}
}
上記のような設定をして、デフォルト形式とJSON形式のログが交互に出力されていました。
$ cat logs/nginx/access.log
172.18.0.1 - - [15/Nov/2024:02:17:03 +0000] "GET /image/9990.jpg HTTP/1.1" 200 102371 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36" "-"
{"time":"2024-11-15T02:17:03+00:00","host":"172.18.0.1","port":56870,"method":"GET","uri":"/image/9990.jpg","status":"200","body_bytes":102371,"referer":"http://localhost/","ua":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36","request_time":"0.011","response_time":"0.011"}
172.18.0.1 - - [15/Nov/2024:02:17:03 +0000] "GET /image/9989.jpg HTTP/1.1" 200 107460 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36" "-"
{"time":"2024-11-15T02:17:03+00:00","host":"172.18.0.1","port":56854,"method":"GET","uri":"/image/9989.jpg","status":"200","body_bytes":107460,"referer":"http://localhost/","ua":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36","request_time":"0.006","response_time":"0.007"}
172.18.0.1 - - [15/Nov/2024:02:17:03 +0000] "GET /image/9988.jpg HTTP/1.1" 200 111515 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36" "-"
{"time":"2024-11-15T02:17:03+00:00","host":"172.18.0.1","port":56856,"method":"GET","uri":"/image/9988.jpg","status":"200","body_bytes":111515,"referer":"http://localhost/","ua":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36","request_time":"0.003","response_time":"0.004"}
172.18.0.1 - - [15/Nov/2024:02:17:03 +0000] "GET /image/9987.jpg HTTP/1.1" 200 367388 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36" "-"
{"time":"2024-11-15T02:17:03+00:00","host":"172.18.0.1","port":56836,"method":"GET","uri":"/image/9987.jpg","status":"200","body_bytes":367388,"referer":"http://localhost/","ua":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36","request_time":"0.013","response_time":"0.013"}
172.18.0.1 - - [15/Nov/2024:02:17:03 +0000] "GET /image/9986.jpg HTTP/1.1" 200 86624 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36" "-"
{"time":"2024-11-15T02:17:03+00:00","host":"172.18.0.1","port":56882,"method":"GET","uri":"/image/9986.jpg","status":"200","body_bytes":86624,"referer":"http://localhost/","ua":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36","request_time":"0.012","response_time":"0.011"}
172.18.0.1 - - [15/Nov/2024:02:17:03 +0000] "GET /image/9985.jpg HTTP/1.1" 200 83264 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36" "-"
{"time":"2024-11-15T02:17:03+00:00","host":"172.18.0.1","port":56870,"method":"GET","uri":"/image/9985.jpg","status":"200","body_bytes":83264,"referer":"http://localhost/","ua":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36","request_time":"0.013","response_time":"0.013"}
172.18.0.1 - - [15/Nov/2024:02:17:03 +0000] "GET /image/9983.jpg HTTP/1.1" 200 98082 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36" "-"
{"time":"2024-11-15T02:17:03+00:00","host":"172.18.0.1","port":56848,"method":"GET","uri":"/image/9983.jpg","status":"200","body_bytes":98082,"referer":"http://localhost/","ua":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36","request_time":"0.011","response_time":"0.011"}
172.18.0.1 - - [15/Nov/2024:02:17:03 +0000] "GET /image/9982.jpg HTTP/1.1" 200 149874 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36" "-"
{"time":"2024-11-15T02:17:03+00:00","host":"172.18.0.1","port":56856,"method":"GET","uri":"/image/9982.jpg","status":"200","body_bytes":149874,"referer":"http://localhost/","ua":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36","request_time":"0.012","response_time":"0.011"}
172.18.0.1 - - [15/Nov/2024:02:17:03 +0000] "GET /image/9981.jpg HTTP/1.1" 200 81386 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36" "-"
{"time":"2024-11-15T02:17:03+00:00","host":"172.18.0.1","port":56854,"method":"GET","uri":"/image/9981.jpg","status":"200","body_bytes":81386,"referer":"http://localhost/","ua":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36","request_time":"0.015","response_time":"0.016"}
172.18.0.1 - - [15/Nov/2024:02:17:03 +0000] "GET /image/9980.jpg HTTP/1.1" 200 95919 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36" "-"
{"time":"2024-11-15T02:17:03+00:00","host":"172.18.0.1","port":56882,"method":"GET","uri":"/image/9980.jpg","status":"200","body_bytes":95919,"referer":"http://localhost/","ua":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36","request_time":"0.010","response_time":"0.011"}
access_log /var/log/nginx/access.log json;
この1行はserver {} 内に記述してあげる必要があるようです
webapp/etc/nginx/conf.d/default.conf
log_format json escape=json '{"time":"$time_iso8601",'
'"host":"$remote_addr",'
'"port":$remote_port,'
'"method":"$request_method",'
'"uri":"$request_uri",'
'"status":"$status",'
'"body_bytes":$body_bytes_sent,'
'"referer":"$http_referer",'
'"ua":"$http_user_agent",'
'"request_time":"$request_time",'
'"response_time":"$upstream_response_time"}';
server {
listen 80;
access_log /var/log/nginx/access.log json; # server {}の中に記述
client_max_body_size 10m;
root /public/;
location / {
proxy_set_header Host $host;
proxy_pass http://app:8080;
}
}
無事に結果を出力することができました..！よかった
$ cat logs/nginx/access.log|alp json
+-------+-----+-----+-----+-----+-----+--------+------------------+-------+-------+-------+-------+-------+-------+-------+--------+-------------+-------------+-------------+-------------+
| COUNT | 1XX | 2XX | 3XX | 4XX | 5XX | METHOD | URI | MIN | MAX | SUM | AVG | P90 | P95 | P99 | STDDEV | MIN(BODY) | MAX(BODY) | SUM(BODY) | AVG(BODY) |
+-------+-----+-----+-----+-----+-----+--------+------------------+-------+-------+-------+-------+-------+-------+-------+--------+-------------+-------------+-------------+-------------+
| 1 | 0 | 1 | 0 | 0 | 0 | GET | / | 0.743 | 0.743 | 0.743 | 0.743 | 0.743 | 0.743 | 0.743 | 0.000 | 34549.000 | 34549.000 | 34549.000 | 34549.000 |
| 1 | 0 | 1 | 0 | 0 | 0 | GET | /image/10001.jpg | 0.061 | 0.061 | 0.061 | 0.061 | 0.061 | 0.061 | 0.061 | 0.000 | 951082.000 | 951082.000 | 951082.000 | 951082.000 |
| 1 | 0 | 1 | 0 | 0 | 0 | GET | /image/10000.png | 0.106 | 0.106 | 0.106 | 0.106 | 0.106 | 0.106 | 0.106 | 0.000 | 1056749.000 | 1056749.000 | 1056749.000 | 1056749.000 |
| 1 | 0 | 1 | 0 | 0 | 0 | GET | /image/9999.jpg | 0.107 | 0.107 | 0.107 | 0.107 | 0.107 | 0.107 | 0.107 | 0.000 | 89928.000 | 89928.000 | 89928.000 | 89928.000 |
| 1 | 0 | 1 | 0 | 0 | 0 | GET | /image/9998.jpg | 0.114 | 0.114 | 0.114 | 0.114 | 0.114 | 0.114 | 0.114 | 0.000 | 61656.000 | 61656.000 | 61656.000 | 61656.000 |
| 1 | 0 | 1 | 0 | 0 | 0 | GET | /image/9996.jpg | 0.142 | 0.142 | 0.142 | 0.142 | 0.142 | 0.142 | 0.142 | 0.000 | 374805.000 | 374805.000 | 374805.000 | 374805.000 |
| 1 | 0 | 1 | 0 | 0 | 0 | GET | /image/9997.jpg | 0.149 | 0.149 | 0.149 | 0.149 | 0.149 | 0.149 | 0.149 | 0.000 | 176404.000 | 176404.000 | 176404.000 | 176404.000 |
| 1 | 0 | 1 | 0 | 0 | 0 | GET | /image/9995.jpg | 0.055 | 0.055 | 0.055 | 0.055 | 0.055 | 0.055 | 0.055 | 0.000 | 123364.000 | 123364.000 | 123364.000 | 123364.000 |
| 1 | 0 | 1 | 0 | 0 | 0 | GET | /image/9994.jpg | 0.035 | 0.035 | 0.035 | 0.035 | 0.035 | 0.035 | 0.035 | 0.000 | 105154.000 | 105154.000 | 105154.000 | 105154.000 |
| 1 | 0 | 1 | 0 | 0 | 0 | GET | /image/9993.jpg | 0.025 | 0.025 | 0.025 | 0.025 | 0.025 | 0.025 | 0.025 | 0.000 | 85546.000 | 85546.000 | 85546.000 | 85546.000 |
| 1 | 0 | 1 | 0 | 0 | 0 | GET | /image/9991.jpg | 0.018 | 0.018 | 0.018 | 0.018 | 0.018 | 0.018 | 0.018 | 0.000 | 153465.000 | 153465.000 | 153465.000 | 153465.000 |
| 1 | 0 | 1 | 0 | 0 | 0 | GET | /image/9990.jpg | 0.021 | 0.021 | 0.021 | 0.021 | 0.021 | 0.021 | 0.021 | 0.000 | 102371.000 | 102371.000 | 102371.000 | 102371.000 |
| 1 | 0 | 1 | 0 | 0 | 0 | GET | /image/9989.jpg | 0.021 | 0.021 | 0.021 | 0.021 | 0.021 | 0.021 | 0.021 | 0.000 | 107460.000 | 107460.000 | 107460.000 | 107460.000 |
| 1 | 0 | 1 | 0 | 0 | 0 | GET | /image/9988.jpg | 0.022 | 0.022 | 0.022 | 0.022 | 0.022 | 0.022 | 0.022 | 0.000 | 111515.000 | 111515.000 | 111515.000 | 111515.000 |
| 1 | 0 | 1 | 0 | 0 | 0 | GET | /image/9987.jpg | 0.021 | 0.021 | 0.021 | 0.021 | 0.021 | 0.021 | 0.021 | 0.000 | 367388.000 | 367388.000 | 367388.000 | 367388.000 |
| 1 | 0 | 1 | 0 | 0 | 0 | GET | /image/9986.jpg | 0.016 | 0.016 | 0.016 | 0.016 | 0.016 | 0.016 | 0.016 | 0.000 | 86624.000 | 86624.000 | 86624.000 | 86624.000 |
| 1 | 0 | 1 | 0 | 0 | 0 | GET | /image/9985.jpg | 0.019 | 0.019 | 0.019 | 0.019 | 0.019 | 0.019 | 0.019 | 0.000 | 83264.000 | 83264.000 | 83264.000 | 83264.000 |
| 1 | 0 | 1 | 0 | 0 | 0 | GET | /image/9983.jpg | 0.023 | 0.023 | 0.023 | 0.023 | 0.023 | 0.023 | 0.023 | 0.000 | 98082.000 | 98082.000 | 98082.000 | 98082.000 |
| 1 | 0 | 1 | 0 | 0 | 0 | GET | /image/9982.jpg | 0.023 | 0.023 | 0.023 | 0.023 | 0.023 | 0.023 | 0.023 | 0.000 | 149874.000 | 149874.000 | 149874.000 | 149874.000 |
| 1 | 0 | 1 | 0 | 0 | 0 | GET | /image/9981.jpg | 0.021 | 0.021 | 0.021 | 0.021 | 0.021 | 0.021 | 0.021 | 0.000 | 81386.000 | 81386.000 | 81386.000 | 81386.000 |
| 1 | 0 | 1 | 0 | 0 | 0 | GET | /image/9980.jpg | 0.013 | 0.013 | 0.013 | 0.013 | 0.013 | 0.013 | 0.013 | 0.000 | 95919.000 | 95919.000 | 95919.000 | 95919.000 |
+-------+-----+-----+-----+-----+-----+--------+------------------+-------+-------+-------+-------+-------+-------+-------+--------+-------------+-------------+-------------+-------------+
Discussion