# Analyze Discourse performance using NGINX logs
**URL:** https://meta.discourse.org/t/analyze-discourse-performance-using-nginx-logs/30117
**Category:** Self-Hosting
**Tags:** how-to
**Created:** [2015 年 6 月 17 日午前 6:26 UTC](https://meta.discourse.org/t/analyze-discourse-performance-using-nginx-logs/30117 "2015-06-17T06:26:46Z")
**Posts on this page:** 20
**Page:** 1
### Author:  [@sam](https://meta.discourse.org/u/sam)
#### Post date: [2015 年 6 月 17 日午前 6:26 UTC](https://meta.discourse.org/t/analyze-discourse-performance-using-nginx-logs/30117/1 "2015-06-17T06:26:46Z")
> ⚠ this is stale and out-of-date historic information
Our official [Docker container](https://github.com/discourse/discourse_docker) ships with a custom [NGINX config](https://github.com/discourse/discourse/blob/master/config/nginx.sample.conf) that logs very rich information that can be used to debug server performance issues.
## Create a report
To run it (you will need to be on a very recent install, you must rebuild to update NGINX config):
```plaintext
cd /var/discourse
./launcher enter app
cd /var/www/discourse/plugins/discourse-nginx-performance-report/script
ruby nginx_analyze.rb
```
## Report contents
The report provides the following:
### Overview of request counts for the duration of the log
```plaintext
Total Requests: 11105 ( MessageBus: 6757 )
```
We can see that we processed 11105 requests total, 6757 were consumed by [message\_bus](https://github.com/SamSaffron/message_bus). To learn more about message bus see [this post](https://meta.discourse.org/t/how-discourse-stays-online-message-bus-faye-long-polling/3238/7) or search meta
### Top 30 IPs by server load
Which IPs are responsible for the largest amount of CPU time?
```plaintext
IP Address Duration
---------- --------
100.43.90.12 16.71
10.66.0.21 7.45
10.66.0.22 7.31
... etc ...
```
So in the above we can see that Yandex crawling is causing a fair amount of load. As well as a couple of private IP addresses.
### Top 30 Users by Server Load
```plaintext
Top 30 users by Server Load
Username Duration Reqs Routes
-------- -------- ---- ------
[Anonymous] 3746.81 132094 topics/show(1110.60) user_avatars/show(814.98)
user_avatars/show_letter(713.23)
forums/status(418.98) static/cdn_asset(206.63)
alep 232.11 1723 list/latest(232.11)
sam 36.82 518 topics/show(14.12) list/latest(6.86)
topics/timings(4.48) posts/create(1.69)
draft/update(1.09)
codinghorror 33.05 618 topics/wordpress(11.91) topics/show(11.14)
topics/timings(3.33) post_actions/create(1.88)
posts/create(1.75)
```
You can see counts of requests, total times and a breakdown by route cost.
For example … in this report @alep hit `list/latest` our front page 1723 times resulting in 232 seconds of processing time.
### Top 30 routes by Server Load
```plaintext
Route Duration
----- --------
topics/show 59.24
user_avatars/show_letter 21.07
user_avatars/show 14.92
forums/status 14.77
list/latest 4.94
topics/timings 4.10
static/cdn_asset 3.46
list/category_latest 0.98
topics/feed 0.97
```
This information is particularly useful for quite a few reasons and can be used for diagnostics.
Routes at the top of the list are ones that have the **most** impact on global performance so it makes sense for us to focus on improving them (or cutting down calls to them) first.
### Top 30 URLs by server load
```plaintext
Url Duration
--- --------
GET /srv/status HTTP/1.1 14.77
HEAD /t/what-do-user-trust-levels-do/4924 HTTP/1.1 5.34
POST /topics/timings HTTP/1.1 4.10
GET /t/what-do-user-trust-levels-do/4924 HTTP/1.1 2.68
GET / HTTP/1.1 2.16
```
This shows us which URL are responsible for the most amount of load on the server. Perhaps there is a topic that has performance issues? Perhaps there is a page that is visited too often by bots?
### Top 30 not found URLs (404)
```plaintext
Url Count
--- -----
GET //cdck-file-uploads-global.s3.dualstack.us-west-2.amazonaws.com/meta/original/3X/e/1/e1fc4c5714ea45bc473feea787021d39f7133d22.png HTTP/1.1 9
GET //cdck-file-uploads-global.s3.dualstack.us-west-2.amazonaws.com/meta/original/3X/7/2/72d2687d1d00c52c546727efbbc6d726f6e153de.png HTTP/1.1 2
GET /node/add HTTP/1.1 1
```
We can use this report to find broken links, in some cases it may make sense to place a redirect in place to help recover the traffic.
## Automatic daily performance reports
You can also enable automatic daily performance reports on your site by checking:
`daily performance report` in site settings.
This will give you daily reports delivered to a single discourse topic (under staff category)
You can shift it to another category and watch it and then you get the reports via email. I would strongly recommend not moving the topic to a public category as you will leak out ips and sensitive info.
These reports also enable you to discuss the results in a topic more easily
## How it works
To achieve rich diagnostics, Discourse adds 2 additional headers to all requests in [application\_controller.rb](https://github.com/discourse/discourse/blob/master/app/controllers/application_controller.rb)
```plaintext
def set_current_user_for_logs
if current_user
Logster.add_to_env(request.env,"username",current_user.username)
response.headers["X-Discourse-Username"] = current_user.username
end
response.headers["X-Discourse-Route"] = "#{controller_name}/#{action_name}"
end
```
Furthermore we define a custom [NGINX log format](https://github.com/discourse/discourse/blob/master/config/nginx.sample.conf):
```plaintext
log_format log_discourse '[$time_local] $remote_addr "$request" "$http_user_agent" "$sent_http_x_discourse_route" $status $bytes_sent "$http_referer" $upstream_response_time $request_time "$sent_http_x_discourse_username"';
```
This means that we track: User Agent, Duration, Status, Rails Duration, Referrer and more for every request.
Out of the box NGINX does not log the time it spends in the “upstream” proxy, this is added to our logs using `$upstream_response_time`
Given this rich information I took a stab at creating a “reporting tool” that analyzes the logs and gives you some interesting reports, the tool is early in development, but already useful: [https://github.com/discourse/discourse/blob/master/script/nginx\_analyze.rb](https://github.com/discourse/discourse/blob/master/script/nginx_analyze.rb)
---
### Author:  [@danwad](https://meta.discourse.org/u/danwad)
#### Post date: [2015 年 7 月 5 日午前 7:26 UTC](https://meta.discourse.org/t/analyze-discourse-performance-using-nginx-logs/30117/3 "2015-07-05T07:26:32Z")
I enabled daily performance report but this was the output in a topic in the staff category overnight:
> Report is only available in latest image, please run:
> ```
> cd /var/discourse
> ./launcher rebuild app
>
> ```
I did a `git pull; ./launcher rebuild app` yesterday and can confirm `/var/www/discourse/script/nginx_analyze.rb` exists and works.
This version is installed: v1.4.0.beta4 +19
Any ideas?
---
### Author:  [@riking](https://meta.discourse.org/u/riking)
#### Post date: [2015 年 7 月 6 日午後 9:01 UTC](https://meta.discourse.org/t/analyze-discourse-performance-using-nginx-logs/30117/4 "2015-07-06T21:01:49Z")
Has the report ran for you now? It’s been a day.
---
### Author:  [@danwad](https://meta.discourse.org/u/danwad)
#### Post date: [2015 年 7 月 6 日午後 9:21 UTC](https://meta.discourse.org/t/analyze-discourse-performance-using-nginx-logs/30117/5 "2015-07-06T21:21:16Z")
Nope - just more replies by system with:
> Report is only available in latest image, please run:
> ```
> cd /var/discourse
> ./launcher rebuild app
>
> ```
---
### Author:  [@sam](https://meta.discourse.org/u/sam)
#### Post date: [2015 年 7 月 6 日午後 11:23 UTC](https://meta.discourse.org/t/analyze-discourse-performance-using-nginx-logs/30117/6 "2015-07-06T23:23:50Z")
Hmm, is there anything custom about your setup?
---
### Author:  [@anon21958287](https://meta.discourse.org/u/anon21958287)
#### Post date: [2015 年 7 月 7 日午前 11:11 UTC](https://meta.discourse.org/t/analyze-discourse-performance-using-nginx-logs/30117/7 "2015-07-07T11:11:45Z")
Since this is reported in a normal reply, would it be possible to wrap the lines sooner to avoid horizontal scrollbars?
---
### Author:  [@Lee\_Ars](https://meta.discourse.org/u/Lee_Ars)
#### Post date: [2015 年 7 月 8 日午後 10:21 UTC](https://meta.discourse.org/t/analyze-discourse-performance-using-nginx-logs/30117/8 "2015-07-08T22:21:17Z")
Same thing with me—every day it’s “Report is only available in latest image,” in spite of having done a `launcher rebuild app` that morning. And same as with @danwad—actually running `nginx_analyze.rb` from within the container works without error.
---
### Author:  [@sam](https://meta.discourse.org/u/sam)
#### Post date: [2015 年 7 月 8 日午後 10:44 UTC](https://meta.discourse.org/t/analyze-discourse-performance-using-nginx-logs/30117/9 "2015-07-08T22:44:36Z")
Can you run from the command line and see what happens?
You just need to run “ruby /var/www/discourse/script/nginx\_analyze.rb” after entering container.
Is there anything in logs?
---
### Author:  [@Lee\_Ars](https://meta.discourse.org/u/Lee_Ars)
#### Post date: [2015 年 7 月 8 日午後 10:48 UTC](https://meta.discourse.org/t/analyze-discourse-performance-using-nginx-logs/30117/10 "2015-07-08T22:48:11Z")
@sam Yep, runs fine, produces [plenty of output](https://www.bigdinosaur.org/stats.txt).
---
### Author:  [@sam](https://meta.discourse.org/u/sam)
#### Post date: [2015 年 7 月 8 日午後 11:04 UTC](https://meta.discourse.org/t/analyze-discourse-performance-using-nginx-logs/30117/11 "2015-07-08T23:04:22Z")
what are permissions on /var/log/nginx/
---
### Author:  [@Lee\_Ars](https://meta.discourse.org/u/Lee_Ars)
#### Post date: [2015 年 7 月 8 日午後 11:08 UTC](https://meta.discourse.org/t/analyze-discourse-performance-using-nginx-logs/30117/12 "2015-07-08T23:08:53Z")
Looks like this:
```plaintext
drwxr-x--- 2 www-data www-data 4096 Jul 8 07:35 nginx/
```
---
### Author:  [@sam](https://meta.discourse.org/u/sam)
#### Post date: [2015 年 7 月 8 日午後 11:12 UTC](https://meta.discourse.org/t/analyze-discourse-performance-using-nginx-logs/30117/13 "2015-07-08T23:12:59Z")
on the files as well ?
any error in logs when running the job?
what does this do?
```plaintext
rails c
> Jobs:: DailyPerformanceReport.new.execute(nil)
```
---
### Author:  [@Lee\_Ars](https://meta.discourse.org/u/Lee_Ars)
#### Post date: [2015 年 7 月 8 日午後 11:18 UTC](https://meta.discourse.org/t/analyze-discourse-performance-using-nginx-logs/30117/14 "2015-07-08T23:18:27Z")
Looks like the contents of the directory are set variously:
```plaintext
root@frylock-app:/# ll /var/log/nginx/
total 8128
drwxr-x--- 2 www-data www-data 4096 Jul 8 07:35 ./
drwxrwxr-x 11 root syslog 4096 Jul 7 07:35 ../
-rw-r----- 1 www-data www-data 3144191 Jul 8 23:16 access.log
-rw-r----- 1 www-data www-data 5033222 Jul 8 07:34 access.log.1
-rw-r--r-- 1 root root 117436 Jul 7 07:34 access.log.2.gz
-rw-r----- 1 www-data www-data 1168 Jul 8 17:55 error.log
-rw-r--r-- 1 root root 802 Jul 6 17:49 error.log.1
```
No errors are being logged at the /logs URL, unfortunately.
However, running that command directly at the rails console gives a permission denied error, so that’s probably our issue!
```plaintext
root@frylock-app:/# rails c
[1] pry(main)> Jobs:: DailyPerformanceReport.new.execute(nil)
/var/www/discourse/script/nginx_analyze.rb:121:in `initialize': Permission denied - /var/log/nginx/access.log (Errno::EACCES)
from /var/www/discourse/script/nginx_analyze.rb:121:in `open'
from /var/www/discourse/script/nginx_analyze.rb:121:in `block in analyze'
from /var/www/discourse/script/nginx_analyze.rb:120:in `each'
from /var/www/discourse/script/nginx_analyze.rb:120:in `analyze'
from /var/www/discourse/script/nginx_analyze.rb:54:in `analyze'
from /var/www/discourse/script/nginx_analyze.rb:163:in `'
=> #Report is only available in latest image, pleas...", created_at: "2015-07-08 23:17:27", updated_at: "2015-07-08 23:17:27", reply_to_post_number: nil, reply_count: 0, quote_count: 0, deleted_at: nil, off_topic_count: 0, like_count: 0, incoming_link_count: 0, bookmark_count: 0, avg_time: nil, score: nil, reads: 0, post_type: 1, vote_count: 0, sort_order: 8, last_editor_id: -1, hidden: false, hidden_reason_id: nil, notify_moderators_count: 0, spam_count: 0, illegal_count: 0, inappropriate_count: 0, last_version_at: "2015-07-08 23:17:27", user_deleted: false, reply_to_user_id: nil, percent_rank: 1.0, notify_user_count: 0, like_score: 0, deleted_by_id: nil, edit_reason: nil, word_count: 16, version: 1, cook_method: 1, wiki: false, baked_at: "2015-07-08 23:17:27", baked_version: 1, hidden_at: nil, self_edits: 0, reply_quoted: false, via_email: false, raw_email: nil, public_version: 1>
```
I could chmod `access.log` so everyone has read access—that might do it.
edit - Well, chmodding it (along with the `nginx` subdirectory) to 644 didn’t do it (same error). Should I go more permissive?
---
### Author:  [@sam](https://meta.discourse.org/u/sam)
#### Post date: [2015 年 7 月 8 日午後 11:38 UTC](https://meta.discourse.org/t/analyze-discourse-performance-using-nginx-logs/30117/15 "2015-07-08T23:38:15Z")
Something is odd:
Why is this not running?
>
Also, it should work now according to perms (try again from /sidekiq/schedular)
cause of this:
>
(chpst -u discourse:www-data)
Are you on an old image? (fixed to an old image)
---
### Author:  [@Lee\_Ars](https://meta.discourse.org/u/Lee_Ars)
#### Post date: [2015 年 7 月 9 日午前 12:03 UTC](https://meta.discourse.org/t/analyze-discourse-performance-using-nginx-logs/30117/16 "2015-07-09T00:03:21Z")
> [@sam](#):
>
> Are you on an old image? (fixed to an old image)
I last updated yesterday AM, but I’ll run `launcher rebuild app` right now and try again. One moment.
Completed the rebuild, same error when executing from the rails console.
```plaintext
/var/www/discourse/script/nginx_analyze.rb:121:in `initialize': Permission denied - /var/log/nginx/access.log (Errno::EACCES)
```
The update also reset the permission changes I made (which I’d expect to happen).
Confirmed that my `web.template.yml` lines 36-42 and the `LD_PRELOAD` line both match yours exactly.
Tried triggering the job from the Sidekiq scheduler tab and got the same error ☹
edit -
I don’t know if this is entirely permission related. I just did a `chmod -R 777 /var/log/nginx` to just blow everythign wide open, and I get the exact same error in the rails console when executing the job:
```plaintext
/var/www/discourse/script/nginx_analyze.rb:121:in `initialize': Permission denied - /var/log/nginx/access.log (Errno::EACCES)
```
edit again:
`chpst -u discourse:www-data touch /var/log/nginx/` works. But `chpst -u discourse:www-data touch /var/log/nginx/access.log` yields access denied. What the heck seriously.
---
### Author:  [@sam](https://meta.discourse.org/u/sam)
#### Post date: [2015 年 7 月 9 日午前 12:49 UTC](https://meta.discourse.org/t/analyze-discourse-performance-using-nginx-logs/30117/17 "2015-07-09T00:49:58Z")
hmm … can you reset permissions recursively on that directory?
---
### Author:  [@Lee\_Ars](https://meta.discourse.org/u/Lee_Ars)
#### Post date: [2015 年 7 月 9 日午前 1:17 UTC](https://meta.discourse.org/t/analyze-discourse-performance-using-nginx-logs/30117/18 "2015-07-09T01:17:54Z")
Just nuked them all with another `launcher app rebuild`, so everything’s reset now (and I’m super-duper updated!).
---
### Author:  [@Lee\_Ars](https://meta.discourse.org/u/Lee_Ars)
#### Post date: [2015 年 7 月 16 日午後 4:00 UTC](https://meta.discourse.org/t/analyze-discourse-performance-using-nginx-logs/30117/19 "2015-07-16T16:00:34Z")
FYI @sam, still getting the same `Permission denied` message today after doing a `launcher rebuild app`.
---
### Author:  [@Lee\_Ars](https://meta.discourse.org/u/Lee_Ars)
#### Post date: [2015 年 7 月 18 日午前 12:56 UTC](https://meta.discourse.org/t/analyze-discourse-performance-using-nginx-logs/30117/20 "2015-07-18T00:56:01Z")
Sadly, still happening even this morning after an update to 1.4.0.beta5.
---
### Author:  [@Sander78](https://meta.discourse.org/u/Sander78)
#### Post date: [2015 年 9 月 13 日午後 2:45 UTC](https://meta.discourse.org/t/analyze-discourse-performance-using-nginx-logs/30117/21 "2015-09-13T14:45:01Z")
Just as a heads up: I’m still having this problem as well.
[次のページ](https://meta.discourse.org/t/analyze-discourse-performance-using-nginx-logs/30117.md?page=2)