问题描述
每天早上,我工作中第一个尝试访问 Redmine 的人都会等待将近一分钟,以便 redmine 加载页面。之后,团队的其他成员都没有问题,几乎每个页面的加载时间都在 200 毫秒以内。
这是今天早上最后一次“良好”加载和第一次“不良”加载之间的日志:
App 103 output: I,[2021-04-16T00:19:24.965247 #103] INFO -- : Completed 200 OK in 829ms (Views: 553.2ms | ActiveRecord: 1.8ms)
App 103 output: I,[2021-04-16T03:09:12.511395 #103] INFO -- : Started GET "/login?back_url=https%3A%2F%2Fmyapp.com%2F" for WWW.XXX.YYY.ZZZ at 2021-04-16 03:09:12 +0000
App 103 output: I,[2021-04-16T03:09:12.532015 #103] INFO -- : Processing by AccountController#login as HTML
App 103 output: I,[2021-04-16T03:09:12.532084 #103] INFO -- : Parameters: {"back_url"=>"https://myapp.com/"}
App 103 output: I,[2021-04-16T03:09:12.694146 #103] INFO -- : Redirected to https://myapp.com/login?back_url=https%3A%2F%2Fmyapp.com%2Flogin%3Fback_url%3Dhttps%253A%252F%252Fmyapp.com%252F
App 103 output: I,[2021-04-16T03:09:12.694280 #103] INFO -- : Filter chain halted as :session_expiration rendered or redirected
App 103 output: I,[2021-04-16T03:09:12.694473 #103] INFO -- : Completed 302 Found in 162ms (ActiveRecord: 2.7ms)
App 103 output: I,[2021-04-16T03:09:13.201746 #103] INFO -- : Started GET "/login?back_url=https%3A%2F%2Fmyapp.com%2Flogin%3Fback_url%3Dhttps%253A%252F%252Fmyapp.com%252F" for WWW.XXX.YYY.ZZZ at 2021-04-16 03:09:13 +0000
App 103 output: I,[2021-04-16T03:09:13.205997 #103] INFO -- : Processing by AccountController#login as HTML
App 103 output: I,[2021-04-16T03:09:13.206088 #103] INFO -- : Parameters: {"back_url"=>"https://myapp.com/login?back_url=https%3A%2F%2Fmyapp.com%2F"}
App 103 output: I,[2021-04-16T03:09:13.283815 #103] INFO -- : Current user: anonymous
App 103 output: I,[2021-04-16T03:09:13.300562 #103] INFO -- : Rendering account/login.html.erb within layouts/base
App 103 output: I,[2021-04-16T03:09:13.304521 #103] INFO -- : Rendered account/login.html.erb within layouts/base (3.8ms)
App 103 output: I,[2021-04-16T03:09:13.526917 #103] INFO -- : Completed 200 OK in 321ms (Views: 242.1ms | ActiveRecord: 50.2ms)
App 103 output: I,[2021-04-16T03:09:15.396901 #103] INFO -- : Started POST "/login" for WWW.XXX.YYY.ZZZ at 2021-04-16 03:09:15 +0000
App 103 output: I,[2021-04-16T03:09:15.400666 #103] INFO -- : Processing by AccountController#login as HTML
App 103 output: I,[2021-04-16T03:09:15.400741 #103] INFO -- : Parameters: {"utf8"=>"✓","authenticity_token"=>"*********************************","username"=>"myuser","password"=>"[FILTERED]","login"=>"Connexion"}
App 103 output: I,[2021-04-16T03:09:15.461825 #103] INFO -- : Current user: anonymous
App 103 output: I,[2021-04-16T03:09:16.117981 #103] INFO -- : Successful authentication for 'myuser' from WWW.XXX.YYY.ZZZ at 2021-04-16 03:09:16 UTC
App 103 output: I,[2021-04-16T03:09:16.454431 #103] INFO -- : Redirected to https://myapp.com/my/page
App 103 output: I,[2021-04-16T03:09:16.454677 #103] INFO -- : Completed 302 Found in 1054ms (ActiveRecord: 778.5ms)
App 103 output: I,[2021-04-16T03:09:16.929227 #103] INFO -- : Started GET "/my/page" for WWW.XXX.YYY.ZZZ at 2021-04-16 03:09:16 +0000
App 103 output: I,[2021-04-16T03:09:17.650222 #103] INFO -- : Processing by MyController#page as HTML
App 103 output: I,[2021-04-16T03:09:18.625577 #103] INFO -- : Current user: myuser (id=208)
App 103 output: I,[2021-04-16T03:09:18.923542 #103] INFO -- : Rendering my/page.html.erb within layouts/base
App 103 output: I,[2021-04-16T03:09:35.622052 #103] INFO -- : Rendered queries/_columns.html.erb (509.9ms)
App 103 output: I,[2021-04-16T03:09:39.698459 #103] INFO -- : Rendered issues/_list.html.erb (3990.1ms)
App 103 output: I,[2021-04-16T03:09:39.736960 #103] INFO -- : Rendered my/blocks/_issues.erb (5549.7ms)
App 103 output: I,[2021-04-16T03:09:44.899092 #103] INFO -- : Rendered queries/_columns.html.erb (1643.8ms)
App 103 output: I,[2021-04-16T03:09:48.195990 #103] INFO -- : Rendered issues/_list.html.erb (3114.5ms)
App 103 output: I,[2021-04-16T03:09:48.238683 #103] INFO -- : Rendered my/blocks/_issues.erb (5564.4ms)
App 103 output: I,[2021-04-16T03:09:48.271494 #103] INFO -- : Rendered my/page.html.erb within layouts/base (29347.8ms)
App 103 output: I,[2021-04-16T03:10:17.568436 #103] INFO -- : Completed 200 OK in 59918ms (Views: 57311.4ms | ActiveRecord: 2235.3ms)
App 103 output: I,[2021-04-16T03:11:32.073474 #103] INFO -- : Started GET "/projects/myapp-v2?jump=my" for WWW.XXX.YYY.ZZZ at 2021-04-16 03:11:32 +0000
App 103 output: I,[2021-04-16T03:11:32.075240 #103] INFO -- : Processing by ProjectsController#show as HTML
App 103 output: I,[2021-04-16T03:11:32.075285 #103] INFO -- : Parameters: {"jump"=>"my","id"=>"myapp-v2"}
App 103 output: I,[2021-04-16T03:11:32.083287 #103] INFO -- : Current user: myuser (id=208)
App 103 output: I,[2021-04-16T03:11:34.636170 #103] INFO -- : Rendering projects/show.html.erb within layouts/base
App 103 output: I,[2021-04-16T03:11:36.682491 #103] INFO -- : Rendered projects/_members_Box.html.erb (157.3ms)
App 103 output: I,[2021-04-16T03:11:36.684234 #103] INFO -- : Rendered projects/show.html.erb within layouts/base (2048.0ms)
App 103 output: I,[2021-04-16T03:11:37.452800 #103] INFO -- : Completed 200 OK in 5377ms (Views: 2762.9ms | ActiveRecord: 620.0ms)
在 2021-04-16T03:10:17.568436,您可以在 59918 毫秒内看到 200 OK 响应。
我使用 docker-compose 文件运行 Remdine docker。 Redmine 正在连接到主机 MysqL 服务器并使用主机邮件服务器(没问题)。
这是 redmine-docker-compose.yml
文件内容:
version: '3.1'
services:
redmine:
image: redmine:4.2-passenger
user: "$UID:$GID"
logging:
driver: "journald"
options:
tag: "redmine-docker"
mode: "non-blocking"
max-buffer-size: "4m"
ports:
- 8792:3000
environment:
REDmine_DB_MysqL: 172.17.0.1
REDmine_DB_DATABASE: redmine
REDmine_DB_PORT: 3306
REDmine_DB_USERNAME: redmine
REDmine_DB_PASSWORD: ***************
REDmine_DB_ENCODING: utf8
REDmine_SECRET_KEY_BASE: *************************
volumes:
- ./redmine/files:/usr/src/redmine/files
- ./redmine/themes/Purplemine2-master:/usr/src/redmine/public/themes/Purplemine2-master
- ./redmine/config/configuration.yml:/usr/src/redmine/config/configuration.yml
- ./redmine/repos:/usr/src/redmine/repos
- ./redmine/etc/passwd:/etc/passwd:ro
- ./redmine/usr/src/redmine/Passengerfile.json:/usr/src/redmine/Passengerfile.json
networks:
default:
external:
name: br-redmine-docker
production:
email_delivery:
delivery_method: :smtp
smtp_settings:
address: 172.17.0.1
port: 25
enable_starttls_auto: false
还有 Passengerfile.json
内容:
{
"max_pool_size": 15,"pool_idle_time": 60,"min_instances": 4
}
请注意,我创建了Passengerfile.json 因为这个完全相同的问题,但它根本没有解决它。
这是 passwd
文件的内容(它只是 docker 镜像中文件的副本,末尾多一行):
root:x:0:0:root:/root:/bin/bash
daemon:x:1:1:daemon:/usr/sbin:/usr/sbin/nologin
bin:x:2:2:bin:/bin:/usr/sbin/nologin
sys:x:3:3:sys:/dev:/usr/sbin/nologin
sync:x:4:65534:sync:/bin:/bin/sync
games:x:5:60:games:/usr/games:/usr/sbin/nologin
man:x:6:12:man:/var/cache/man:/usr/sbin/nologin
lp:x:7:7:lp:/var/spool/lpd:/usr/sbin/nologin
mail:x:8:8:mail:/var/mail:/usr/sbin/nologin
news:x:9:9:news:/var/spool/news:/usr/sbin/nologin
uucp:x:10:10:uucp:/var/spool/uucp:/usr/sbin/nologin
proxy:x:13:13:proxy:/bin:/usr/sbin/nologin
www-data:x:33:33:www-data:/var/www:/usr/sbin/nologin
backup:x:34:34:backup:/var/backups:/usr/sbin/nologin
list:x:38:38:Mailing List Manager:/var/list:/usr/sbin/nologin
irc:x:39:39:ircd:/var/run/ircd:/usr/sbin/nologin
gnats:x:41:41:Gnats Bug-Reporting System (admin):/var/lib/gnats:/usr/sbin/nologin
nobody:x:65534:65534:nobody:/nonexistent:/usr/sbin/nologin
_apt:x:100:65534::/nonexistent:/usr/sbin/nologin
redmine:x:999:999::/home/redmine:/bin/sh
hostuser:x:998:996::/home/hostuser:/bin/sh
UID=998
GID=996
hostuser
是一个存在于我的主机上的用户(它在主机上的名字是 redmine
但我只需要分配正确的 UID 和 GID 以保持 redmine 文件的所有权到这个用户)。
我还检查了 wait_timeout
MysqL 变量,该变量在一段时间不活动后关闭连接,但它的默认值是 8 小时,我的问题在大约 4 小时内出现,因此不可能是原因。
我也想禁用 tini
以防万一,但我找不到任何方法来做到这一点。
任何帮助表示赞赏。
谢谢。
解决方法
作为一种解决方法,我最终编写了一个 cron 任务,通过每小时启动的 curl
命令使 redmine 保持清醒。这是我的 crontab 示例:
0 */1 * * * /usr/bin/curl "https://my.redmine.com/login?keep-redmine-awake-cron" >/dev/null 2>&1
- URL 参数
?keep-redmine-awake-cron
仅用于在网络服务器日志中识别这些请求。 - 使用
>/dev/null 2>&1
忽略命令的输出,因为我不希望 cron 发送包含此无用输出的电子邮件。
不过,在一些不活动之后,我无法找出那些长时间请求的真正原因。