Closed neteroster closed 4 years ago
What's the output of docker inspect bitwarden
(when this problem happens)?
@jjlin Thank you! I'll do it when the problem happens next time.
@jjlin It happened again, here is the output:
$ docker inspect bitwarden
[
{
"Id": "7f998a652f2708a1c0abf1ef4f764f4a1b4e6f0bc8fb99940e4c46c674fc6421",
"Created": "2020-04-06T05:33:13.779368588Z",
"Path": "/bitwarden_rs",
"Args": [],
"State": {
"Status": "running",
"Running": true,
"Paused": false,
"Restarting": false,
"OOMKilled": false,
"Dead": false,
"Pid": 11289,
"ExitCode": 0,
"Error": "",
"StartedAt": "2020-04-06T05:33:14.955540962Z",
"FinishedAt": "0001-01-01T00:00:00Z",
"Health": {
"Status": "unhealthy",
"FailingStreak": 300,
"Log": [
{
"Start": "2020-04-08T07:51:18.928788869+08:00",
"End": "2020-04-08T07:51:28.932793656+08:00",
"ExitCode": -1,
"Output": "Health check exceeded timeout (10s)"
},
{
"Start": "2020-04-08T07:52:28.94079878+08:00",
"End": "2020-04-08T07:52:38.944804971+08:00",
"ExitCode": -1,
"Output": "Health check exceeded timeout (10s)"
},
{
"Start": "2020-04-08T07:53:38.952822069+08:00",
"End": "2020-04-08T07:53:48.956807167+08:00",
"ExitCode": -1,
"Output": "Health check exceeded timeout (10s)"
},
{
"Start": "2020-04-08T07:54:48.964785919+08:00",
"End": "2020-04-08T07:54:58.968809694+08:00",
"ExitCode": -1,
"Output": "Health check exceeded timeout (10s)"
},
{
"Start": "2020-04-08T07:55:58.976773359+08:00",
"End": "2020-04-08T07:56:08.980822058+08:00",
"ExitCode": -1,
"Output": "Health check exceeded timeout (10s)"
}
]
}
},
"Image": "sha256:c25bee30f4aa2cef351b09e78dfc5a38be68ccf61985580f8aee91fffbb655e0",
"ResolvConfPath": "/var/lib/docker/containers/7f998a652f2708a1c0abf1ef4f764f4a1b4e6f0bc8fb99940e4c46c674fc6421/resolv.conf",
"HostnamePath": "/var/lib/docker/containers/7f998a652f2708a1c0abf1ef4f764f4a1b4e6f0bc8fb99940e4c46c674fc6421/hostname",
"HostsPath": "/var/lib/docker/containers/7f998a652f2708a1c0abf1ef4f764f4a1b4e6f0bc8fb99940e4c46c674fc6421/hosts",
"LogPath": "/var/lib/docker/containers/7f998a652f2708a1c0abf1ef4f764f4a1b4e6f0bc8fb99940e4c46c674fc6421/7f998a652f2708a1c0abf1ef4f764f4a1b4e6f0bc8fb99940e4c46c674fc6421-json.log",
"Name": "/bitwarden",
"RestartCount": 0,
"Driver": "overlay2",
"Platform": "linux",
"MountLabel": "",
"ProcessLabel": "",
"AppArmorProfile": "docker-default",
"ExecIDs": [
"161648592acf0c72df17723f46647c95ee2974e2f47653f589b626c9fa4803e1"
],
"HostConfig": {
"Binds": [
"/root/certdir/:/ssl/",
"/bw-data/:/data/"
],
"ContainerIDFile": "",
"LogConfig": {
"Type": "json-file",
"Config": {}
},
"NetworkMode": "default",
"PortBindings": {
"80/tcp": [
{
"HostIp": "",
"HostPort": "443"
}
]
},
"RestartPolicy": {
"Name": "no",
"MaximumRetryCount": 0
},
"AutoRemove": false,
"VolumeDriver": "",
"VolumesFrom": null,
"CapAdd": null,
"CapDrop": null,
"Capabilities": null,
"Dns": [],
"DnsOptions": [],
"DnsSearch": [],
"ExtraHosts": null,
"GroupAdd": null,
"IpcMode": "private",
"Cgroup": "",
"Links": null,
"OomScoreAdj": 0,
"PidMode": "",
"Privileged": false,
"PublishAllPorts": false,
"ReadonlyRootfs": false,
"SecurityOpt": null,
"UTSMode": "",
"UsernsMode": "",
"ShmSize": 67108864,
"Runtime": "runc",
"ConsoleSize": [
0,
0
],
"Isolation": "",
"CpuShares": 0,
"Memory": 0,
"NanoCpus": 0,
"CgroupParent": "",
"BlkioWeight": 0,
"BlkioWeightDevice": [],
"BlkioDeviceReadBps": null,
"BlkioDeviceWriteBps": null,
"BlkioDeviceReadIOps": null,
"BlkioDeviceWriteIOps": null,
"CpuPeriod": 0,
"CpuQuota": 0,
"CpuRealtimePeriod": 0,
"CpuRealtimeRuntime": 0,
"CpusetCpus": "",
"CpusetMems": "",
"Devices": [],
"DeviceCgroupRules": null,
"DeviceRequests": null,
"KernelMemory": 0,
"KernelMemoryTCP": 0,
"MemoryReservation": 0,
"MemorySwap": 0,
"MemorySwappiness": null,
"OomKillDisable": false,
"PidsLimit": null,
"Ulimits": null,
"CpuCount": 0,
"CpuPercent": 0,
"IOMaximumIOps": 0,
"IOMaximumBandwidth": 0,
"MaskedPaths": [
"/proc/asound",
"/proc/acpi",
"/proc/kcore",
"/proc/keys",
"/proc/latency_stats",
"/proc/timer_list",
"/proc/timer_stats",
"/proc/sched_debug",
"/proc/scsi",
"/sys/firmware"
],
"ReadonlyPaths": [
"/proc/bus",
"/proc/fs",
"/proc/irq",
"/proc/sys",
"/proc/sysrq-trigger"
]
},
"GraphDriver": {
"Data": {
"LowerDir": "/var/lib/docker/overlay2/b6fe0de1e3d28fd658b0c48b74fe47c112016388eef46c380323ff39187e93c9-init/diff:/var/lib/docker/overlay2/2efcf6b38739acb3f16f1fc2b7b1dd607d5eca9444099a1ce575e3eab016269d/diff:/var/lib/docker/overlay2/b83ac4d6e0807f4d9cf8f171bceef08e90b32a056b4d71cc50a69d74ba0a52ce/diff:/var/lib/docker/overlay2/74a00754e1f166ed584f96f7dca37675847945b32b71decda2b104a9d758738f/diff:/var/lib/docker/overlay2/d8ec5e756f961cf6282fdc3e375ff96aee0a30bc4ca1c46f3a32f82362cb74a7/diff:/var/lib/docker/overlay2/ac4cac57311c2b82f203b2135b31166c50d517a3a2886aa322aa781e8705dac3/diff:/var/lib/docker/overlay2/40e224a1e779d42fd4f44daaf67a32a303ea935e1b0c98731eeb51f4be04e950/diff:/var/lib/docker/overlay2/50faa528ecbb047e1e8cd300194050f4c3f21a985770272a65acfe6b3c3979c1/diff",
"MergedDir": "/var/lib/docker/overlay2/b6fe0de1e3d28fd658b0c48b74fe47c112016388eef46c380323ff39187e93c9/merged",
"UpperDir": "/var/lib/docker/overlay2/b6fe0de1e3d28fd658b0c48b74fe47c112016388eef46c380323ff39187e93c9/diff",
"WorkDir": "/var/lib/docker/overlay2/b6fe0de1e3d28fd658b0c48b74fe47c112016388eef46c380323ff39187e93c9/work"
},
"Name": "overlay2"
},
"Mounts": [
{
"Type": "bind",
"Source": "/bw-data",
"Destination": "/data",
"Mode": "",
"RW": true,
"Propagation": "rprivate"
},
{
"Type": "bind",
"Source": "/root/certdir",
"Destination": "/ssl",
"Mode": "",
"RW": true,
"Propagation": "rprivate"
}
],
"Config": {
"Hostname": "7f998a652f27",
"Domainname": "",
"User": "",
"AttachStdin": false,
"AttachStdout": false,
"AttachStderr": false,
"ExposedPorts": {
"3012/tcp": {},
"80/tcp": {}
},
"Tty": false,
"OpenStdin": false,
"StdinOnce": false,
"Env": [
"ROCKET_TLS={certs=\"/ssl/fullchain.pem\",key=\"/ssl/privkey.pem\"}",
"SIGNUPS_ALLOWED=false",
"LOG_FILE=/data/bitwarden.log",
"PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin",
"ROCKET_ENV=staging",
"ROCKET_PORT=80",
"ROCKET_WORKERS=10"
],
"Cmd": [
"/bitwarden_rs"
],
"Healthcheck": {
"Test": [
"CMD",
"/healthcheck.sh"
],
"Interval": 60000000000,
"Timeout": 10000000000
},
"Image": "bitwardenrs/server:latest",
"Volumes": {
"/data": {}
},
"WorkingDir": "/",
"Entrypoint": null,
"OnBuild": null,
"Labels": {}
},
"NetworkSettings": {
"Bridge": "",
"SandboxID": "f91233bb368bd58c21f39bd39569bfe065c1f370c25925ac5ef7ac026066402d",
"HairpinMode": false,
"LinkLocalIPv6Address": "",
"LinkLocalIPv6PrefixLen": 0,
"Ports": {
"3012/tcp": null,
"80/tcp": [
{
"HostIp": "0.0.0.0",
"HostPort": "443"
}
]
},
"SandboxKey": "/var/run/docker/netns/f91233bb368b",
"SecondaryIPAddresses": null,
"SecondaryIPv6Addresses": null,
"EndpointID": "25061905f63661675ae1e3ee34f1fb9ca28546d634fc6b79ffeeccd00dc45744",
"Gateway": "172.17.0.1",
"GlobalIPv6Address": "",
"GlobalIPv6PrefixLen": 0,
"IPAddress": "172.17.0.2",
"IPPrefixLen": 16,
"IPv6Gateway": "",
"MacAddress": "02:42:ac:11:00:02",
"Networks": {
"bridge": {
"IPAMConfig": null,
"Links": null,
"Aliases": null,
"NetworkID": "fa7e22fd456b9291557c900f252df82ad34dedc886f321cb10863ab0702ea8eb",
"EndpointID": "25061905f63661675ae1e3ee34f1fb9ca28546d634fc6b79ffeeccd00dc45744",
"Gateway": "172.17.0.1",
"IPAddress": "172.17.0.2",
"IPPrefixLen": 16,
"IPv6Gateway": "",
"GlobalIPv6Address": "",
"GlobalIPv6PrefixLen": 0,
"MacAddress": "02:42:ac:11:00:02",
"DriverOpts": null
}
}
}
}
]
I suspect Docker is having issues on your system. What OS/version and Docker version are you running?
Check if you can upgrade to the latest (or at least recent) version of Docker. You might also consider disabling healthchecks and seeing if that helps. You can do that using docker run --no-healthcheck ...
or by adding
healthcheck:
disable: true
to your service definition if you use Docker Compose.
@jjlin I'm using Ubuntu 16.04
$ uname -a
Linux XXXX 4.15.0-88-generic #88-Ubuntu SMP Tue Feb 11 20:11:34 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux
Docker Engine is the latest version (19.03.8)
$ docker version
Client: Docker Engine - Community
Version: 19.03.8
API version: 1.40
Go version: go1.12.17
Git commit: afacb8b7f0
Built: Wed Mar 11 01:25:46 2020
OS/Arch: linux/amd64
Experimental: false
Server: Docker Engine - Community
Engine:
Version: 19.03.8
API version: 1.40 (minimum version 1.12)
Go version: go1.12.17
Git commit: afacb8b7f0
Built: Wed Mar 11 01:24:19 2020
OS/Arch: linux/amd64
Experimental: false
containerd:
Version: 1.2.13
GitCommit: 7ad184331fa3e55e52b890ea95e65ba581ae3429
runc:
Version: 1.0.0-rc10
GitCommit: dc9208a3303feef5b3839f4323d9beb36df0a9dd
docker-init:
Version: 0.18.0
GitCommit: fec3683
I'll try your suggestion, thank you!
I have exactly the same issue on CentOS 8 with latest image
The problem happened again. Disabling health-check doesn't help.
A few things to try:
docker exec -it bitwarden bash
and see if you can get any response from the server, e.g. by running curl -kv https://localhost:80/alive
. Check if ps -ef
shows anything unusual.strace -fp $(pgrep bitwarden_rs)
from the Docker host and see if there's any activity when you try to interact with the server.journalctl -u docker
from the Docker host and see if there's anything that looks unusual.@jjlin Thanks.
curl -kv https://127.0.0.1:80/alive
is:root@8c4432ba6973:/# curl -kv https://127.0.0.1:80/alive
* Expire in 0 ms for 6 (transfer 0x555e9fbcdf50)
* Trying 127.0.0.1...
* TCP_NODELAY set
* Expire in 200 ms for 4 (transfer 0x555e9fbcdf50)
^C
ps -ef
gives:root@8c4432ba6973:/# ps -ef
UID PID PPID C STIME TTY TIME CMD
root 1 0 0 Apr08 ? 00:00:02 /bitwarden_rs
root 31 0 0 09:46 pts/0 00:00:00 bash
root 365 31 0 09:51 pts/0 00:00:00 ps -ef
strace -fp $(pgrep bitwarden_rs)
gives:[pid 9349] epoll_wait(27, <unfinished ...>
[pid 9291] recvfrom(8, <unfinished ...>
[pid 9290] recvfrom(12, <unfinished ...>
[pid 9289] recvfrom(16, <unfinished ...>
[pid 9288] recvfrom(15, <unfinished ...>
[pid 9287] recvfrom(10, <unfinished ...>
[pid 9286] recvfrom(11, <unfinished ...>
[pid 9285] recvfrom(9, <unfinished ...>
[pid 9284] recvfrom(4, <unfinished ...>
[pid 9283] recvfrom(13, <unfinished ...>
[pid 9282] recvfrom(22, <unfinished ...>
[pid 9281] futex(0x55a78b675e38, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid 9280] restart_syscall(<... resuming interrupted restart_syscall ...> <unfinished ...>
[pid 9279] restart_syscall(<... resuming interrupted restart_syscall ...> <unfinished ...>
[pid 9278] restart_syscall(<... resuming interrupted restart_syscall ...> <unfinished ...>
[pid 9221] futex(0x7f2f85ab49d0, FUTEX_WAIT, 9, NULL
// Start to sync from my PC here
[pid 9280] <... restart_syscall resumed> ) = -1 ETIMEDOUT (Connection timed out)
[pid 9279] <... restart_syscall resumed> ) = -1 ETIMEDOUT (Connection timed out)
[pid 9278] <... restart_syscall resumed> ) = -1 ETIMEDOUT (Connection timed out)
[pid 9280] futex(0x7f2f860bd338, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 9279] futex(0x7f2f85cbb338, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 9278] futex(0x7f2f860bd338, FUTEX_WAIT_PRIVATE, 1, NULL <unfinished ...>
[pid 9280] <... futex resumed> ) = 0
[pid 9279] <... futex resumed> ) = 0
[pid 9280] lstat("data/db.sqlite3", <unfinished ...>
[pid 9279] futex(0x7f2f860bd338, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 9280] <... lstat resumed> {st_mode=S_IFREG|0644, st_size=176128, ...}) = 0
[pid 9279] <... futex resumed> ) = 1
[pid 9278] <... futex resumed> ) = 0
[pid 9280] getcwd( <unfinished ...>
[pid 9279] fstat(5, <unfinished ...>
[pid 9278] lstat("data/db.sqlite3", <unfinished ...>
[pid 9280] <... getcwd resumed> "/", 511) = 2
[pid 9279] <... fstat resumed> {st_mode=S_IFREG|0644, st_size=176128, ...}) = 0
[pid 9278] <... lstat resumed> {st_mode=S_IFREG|0644, st_size=176128, ...}) = 0
[pid 9280] getpid( <unfinished ...>
[pid 9279] stat("//data/db.sqlite3", <unfinished ...>
[pid 9278] getcwd( <unfinished ...>
[pid 9280] <... getpid resumed> ) = 1
[pid 9279] <... stat resumed> {st_mode=S_IFREG|0644, st_size=176128, ...}) = 0
[pid 9278] <... getcwd resumed> "/", 511) = 2
[pid 9280] stat("//data/db.sqlite3", <unfinished ...>
[pid 9279] futex(0x55a78a261eb0, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid 9278] getpid( <unfinished ...>
[pid 9280] <... stat resumed> {st_mode=S_IFREG|0644, st_size=176128, ...}) = 0
[pid 9278] <... getpid resumed> ) = 1
[pid 9280] futex(0x55a78a261eb0, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 9278] stat("//data/db.sqlite3", <unfinished ...>
[pid 9280] <... futex resumed> ) = 1
[pid 9279] <... futex resumed> ) = 0
[pid 9278] <... stat resumed> {st_mode=S_IFREG|0644, st_size=176128, ...}) = 0
[pid 9280] openat(AT_FDCWD, "//data/db.sqlite3", O_RDWR|O_CREAT|O_CLOEXEC, 0644 <unfinished ...>
[pid 9279] futex(0x55a78a261eb0, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid 9278] futex(0x55a78a261eb0, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 9280] <... openat resumed> ) = 25
[pid 9279] <... futex resumed> ) = -1 EAGAIN (Resource temporarily unavailable)
[pid 9278] <... futex resumed> ) = 0
[pid 9280] futex(0x55a78a261eb0, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid 9279] close(5 <unfinished ...>
[pid 9278] openat(AT_FDCWD, "//data/db.sqlite3", O_RDWR|O_CREAT|O_CLOEXEC, 0644 <unfinished ...>
[pid 9279] <... close resumed> ) = 0
[pid 9278] <... openat resumed> ) = 5
[pid 9279] futex(0x55a78a261eb0, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 9278] fstat(5, <unfinished ...>
[pid 9280] <... futex resumed> ) = 0
[pid 9279] <... futex resumed> ) = 1
[pid 9278] <... fstat resumed> {st_mode=S_IFREG|0644, st_size=176128, ...}) = 0
[pid 9280] futex(0x55a78a261eb0, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid 9279] fstat(6, <unfinished ...>
[pid 9278] futex(0x55a78a261eb0, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 9280] <... futex resumed> ) = -1 EAGAIN (Resource temporarily unavailable)
[pid 9279] <... fstat resumed> {st_mode=S_IFREG|0644, st_size=176128, ...}) = 0
[pid 9278] <... futex resumed> ) = 0
[pid 9280] fstat(25, <unfinished ...>
[pid 9279] stat("//data/db.sqlite3", <unfinished ...>
[pid 9280] <... fstat resumed> {st_mode=S_IFREG|0644, st_size=176128, ...}) = 0
[pid 9279] <... stat resumed> {st_mode=S_IFREG|0644, st_size=176128, ...}) = 0
[pid 9280] futex(0x55a78a261eb0, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 9279] close(6 <unfinished ...>
[pid 9280] <... futex resumed> ) = 0
[pid 9279] <... close resumed> ) = 0
[pid 9280] fstat(25, <unfinished ...>
[pid 9279] fstat(23, <unfinished ...>
[pid 9280] <... fstat resumed> {st_mode=S_IFREG|0644, st_size=176128, ...}) = 0
[pid 9279] <... fstat resumed> {st_mode=S_IFREG|0644, st_size=176128, ...}) = 0
[pid 9280] stat("//data/db.sqlite3", <unfinished ...>
[pid 9279] stat("//data/db.sqlite3", <unfinished ...>
[pid 9280] <... stat resumed> {st_mode=S_IFREG|0644, st_size=176128, ...}) = 0
[pid 9279] <... stat resumed> {st_mode=S_IFREG|0644, st_size=176128, ...}) = 0
[pid 9280] lseek(25, 0, SEEK_SET <unfinished ...>
[pid 9279] close(23 <unfinished ...>
[pid 9280] <... lseek resumed> ) = 0
[pid 9279] <... close resumed> ) = 0
[pid 9280] read(25, <unfinished ...>
[pid 9279] fstat(24, <unfinished ...>
[pid 9280] <... read resumed> "SQLite format 3\0\20\0\2\2\0@ \0\0\0\10\0\0\0+"..., 100) = 100
[pid 9280] lstat("data/db.sqlite3", <unfinished ...>
[pid 9279] <... fstat resumed> {st_mode=S_IFREG|0644, st_size=176128, ...}) = 0
[pid 9280] <... lstat resumed> {st_mode=S_IFREG|0644, st_size=176128, ...}) = 0
[pid 9280] getcwd("/", 511) = 2
[pid 9280] getpid() = 1
[pid 9280] stat("//data/db.sqlite3", {st_mode=S_IFREG|0644, st_size=176128, ...}) = 0
[pid 9280] openat(AT_FDCWD, "//data/db.sqlite3", O_RDWR|O_CREAT|O_CLOEXEC, 0644) = 6
[pid 9280] fstat(6, {st_mode=S_IFREG|0644, st_size=176128, ...}) = 0
[pid 9280] fstat(6, {st_mode=S_IFREG|0644, st_size=176128, ...}) = 0
[pid 9280] stat("//data/db.sqlite3", {st_mode=S_IFREG|0644, st_size=176128, ...}) = 0
[pid 9280] lseek(6, 0, SEEK_SET) = 0
[pid 9280] read(6, "SQLite format 3\0\20\0\2\2\0@ \0\0\0\10\0\0\0+"..., 100) = 100
[pid 9280] lstat("data/db.sqlite3", {st_mode=S_IFREG|0644, st_size=176128, ...}) = 0
[pid 9280] getcwd("/", 511) = 2
[pid 9280] getpid() = 1
[pid 9280] stat("//data/db.sqlite3", {st_mode=S_IFREG|0644, st_size=176128, ...}) = 0
[pid 9280] openat(AT_FDCWD, "//data/db.sqlite3", O_RDWR|O_CREAT|O_CLOEXEC, 0644) = 23
[pid 9280] fstat(23, {st_mode=S_IFREG|0644, st_size=176128, ...}) = 0
[pid 9280] fstat(23, {st_mode=S_IFREG|0644, st_size=176128, ...}) = 0
[pid 9280] stat("//data/db.sqlite3", {st_mode=S_IFREG|0644, st_size=176128, ...}) = 0
[pid 9280] lseek(23, 0, SEEK_SET) = 0
[pid 9280] read(23, "SQLite format 3\0\20\0\2\2\0@ \0\0\0\10\0\0\0+"..., 100) = 100
[pid 9280] futex(0x7f2f85cbb338, FUTEX_WAIT_PRIVATE, 1, NULL <unfinished ...>
[pid 9279] stat("//data/db.sqlite3", {st_mode=S_IFREG|0644, st_size=176128, ...}) = 0
[pid 9279] close(24) = 0
[pid 9279] futex(0x7f2f85cbb338, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 9280] <... futex resumed> ) = 0
[pid 9280] futex(0x7f2f85cbb338, FUTEX_WAIT_PRIVATE, 1, {tv_sec=29, tv_nsec=992731095} <unfinished ...>
[pid 9279] <... futex resumed> ) = 1
[pid 9279] futex(0x7f2f85ebc338, FUTEX_WAIT_PRIVATE, 1, {tv_sec=29, tv_nsec=992654822} <unfinished ...>
[pid 9278] fstat(5, {st_mode=S_IFREG|0644, st_size=176128, ...}) = 0
[pid 9278] stat("//data/db.sqlite3", {st_mode=S_IFREG|0644, st_size=176128, ...}) = 0
[pid 9278] lseek(5, 0, SEEK_SET) = 0
[pid 9278] read(5, "SQLite format 3\0\20\0\2\2\0@ \0\0\0\10\0\0\0+"..., 100) = 100
[pid 9278] futex(0x7f2f860bd338, FUTEX_WAIT_PRIVATE, 1, {tv_sec=29, tv_nsec=992278884}^Cstrace: Process 9221 detached
journalctl -u docker
seems to give nothing useful, except for a strange info:13651+08:00" level=info msg="Container 7f998a652f2708a1c0abf1ef4f764f4a1b4e6f0bc8fb99940e4c46c674fc6421 failed to exit within 10 seconds of signal 15 - using the force"
34914+08:00" level=info msg="ignoring event" module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
I have never started any container whose ID is 7f998a652f2708a1c0abf1ef4f764f4a1b4e6f0bc8fb99940e4c46c674fc6421
.
Your strace
log shows 10 threads (presumably the 10 Rocket workers) in the middle of receiving data, so I suspect that's why you can't make any new connections. The question is why they're stuck. Try running
$ docker exec -it bitwarden bash
$ apt update && apt install net-tools
$ netstat -ano
@jjlin
root@8c4432ba6973:/# netstat -ano
Active Internet connections (servers and established)
Proto Recv-Q Send-Q Local Address Foreign Address State Timer
tcp 129 0 0.0.0.0:80 0.0.0.0:* LISTEN off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :54416 CLOSE_WAIT off (0.00/0/0)
tcp 192 0 172.17.0.2:80 139.205.177.96:53888 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :57866 CLOSE_WAIT off (0.00/0/0)
tcp 123 0 172.17.0.2:80 83.97.20.33:54318 CLOSE_WAIT off (0.00/0/0)
tcp 0 0 172.17.0.2:80 106.12.155.146:43740 ESTABLISHED off (0.00/0/0)
tcp 309 0 172.17.0.2:80 49.7.21.76:52204 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :9878 CLOSE_WAIT off (0.00/0/0)
tcp 309 0 172.17.0.2:80 49.7.21.76:33161 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :59296 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :60116 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 111.202.100.82:41366 CLOSE_WAIT off (0.00/0/0)
tcp 273 0 172.17.0.2:80 106.120.173.142:40676 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :1096 CLOSE_WAIT off (0.00/0/0)
tcp 0 0 172.17.0.2:80 39.104.190.98:60692 ESTABLISHED off (0.00/0/0)
tcp 227 0 172.17.0.2:80 209.17.96.218:33837 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 49.7.20.28:37740 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 49.7.20.28:38251 CLOSE_WAIT off (0.00/0/0)
tcp 309 0 172.17.0.2:80 49.7.21.76:48193 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :5694 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :21546 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :41756 CLOSE_WAIT off (0.00/0/0)
tcp 17 0 172.17.0.2:80 83.97.20.33:59179 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :56382 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :28624 CLOSE_WAIT off (0.00/0/0)
tcp 192 0 172.17.0.2:80 139.205.177.96:53878 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :16598 CLOSE_WAIT off (0.00/0/0)
tcp 0 0 172.17.0.2:80 39.104.190.98:33752 ESTABLISHED off (0.00/0/0)
tcp 309 0 172.17.0.2:80 49.7.21.76:42194 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 5.196.87.134:62150 CLOSE_WAIT off (0.00/0/0)
tcp 273 0 172.17.0.2:80 106.120.173.142:39103 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 58.250.125.185:34265 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :32826 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :6638 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :19988 CLOSE_WAIT off (0.00/0/0)
tcp 0 0 172.17.0.2:55600 151.101.110.133:80 TIME_WAIT timewait (57.12/0/0)
tcp 0 0 172.17.0.2:80 106.15.194.1:49780 ESTABLISHED off (0.00/0/0)
tcp 123 0 172.17.0.2:80 83.97.20.33:62806 CLOSE_WAIT off (0.00/0/0)
tcp 139 0 172.17.0.2:80 119.23.139.140:42682 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :39394 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :54784 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :41716 CLOSE_WAIT off (0.00/0/0)
tcp 269 0 172.17.0.2:80 106.120.173.142:63663 CLOSE_WAIT off (0.00/0/0)
tcp 0 0 172.17.0.2:80 47.103.68.133:52222 ESTABLISHED off (0.00/0/0)
tcp 13 0 172.17.0.2:80 83.97.20.33:7379 CLOSE_WAIT off (0.00/0/0)
tcp 309 0 172.17.0.2:80 49.7.21.76:63372 CLOSE_WAIT off (0.00/0/0)
tcp 0 0 172.17.0.2:55286 151.101.192.204:80 TIME_WAIT timewait (54.43/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :43016 CLOSE_WAIT off (0.00/0/0)
tcp 309 0 172.17.0.2:80 49.7.21.76:45167 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :47972 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :1752 CLOSE_WAIT off (0.00/0/0)
tcp 160 0 172.17.0.2:80 176.58.124.134:38364 CLOSE_WAIT off (0.00/0/0)
tcp 273 0 172.17.0.2:80 106.120.173.142:63442 CLOSE_WAIT off (0.00/0/0)
tcp 143 0 172.17.0.2:80 128.14.209.226:37692 CLOSE_WAIT off (0.00/0/0)
tcp 123 0 172.17.0.2:80 83.97.20.33:54249 CLOSE_WAIT off (0.00/0/0)
tcp 269 0 172.17.0.2:80 106.120.173.142:44024 CLOSE_WAIT off (0.00/0/0)
tcp 309 0 172.17.0.2:80 49.7.21.76:59655 CLOSE_WAIT off (0.00/0/0)
tcp 273 0 172.17.0.2:80 106.120.173.142:38391 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :31518 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :45998 CLOSE_WAIT off (0.00/0/0)
tcp 273 0 172.17.0.2:80 106.120.173.142:36912 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 111.202.100.82:37807 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :41748 CLOSE_WAIT off (0.00/0/0)
tcp 123 0 172.17.0.2:80 83.97.20.33:13677 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :13022 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :35068 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :2762 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :63658 CLOSE_WAIT off (0.00/0/0)
tcp 139 0 172.17.0.2:80 88.80.189.24:55006 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :62034 CLOSE_WAIT off (0.00/0/0)
tcp 269 0 172.17.0.2:80 106.120.173.142:56525 CLOSE_WAIT off (0.00/0/0)
tcp 0 0 172.17.0.2:55840 151.101.198.133:80 TIME_WAIT timewait (54.58/0/0)
tcp 0 0 172.17.0.2:80 47.105.48.49:49022 ESTABLISHED off (0.00/0/0)
tcp 269 0 172.17.0.2:80 106.120.173.142:63116 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :3626 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :50120 CLOSE_WAIT off (0.00/0/0)
tcp 192 0 172.17.0.2:80 139.205.177.96:53852 CLOSE_WAIT off (0.00/0/0)
tcp 309 0 172.17.0.2:80 49.7.21.76:58881 CLOSE_WAIT off (0.00/0/0)
tcp 269 0 172.17.0.2:80 106.120.173.142:40162 CLOSE_WAIT off (0.00/0/0)
tcp 192 0 172.17.0.2:80 149.129.112.27:31016 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :57234 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :6336 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :13584 CLOSE_WAIT off (0.00/0/0)
tcp 273 0 172.17.0.2:80 106.120.173.142:39894 CLOSE_WAIT off (0.00/0/0)
tcp 269 0 172.17.0.2:80 106.120.173.142:53388 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :60108 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :52212 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :55448 CLOSE_WAIT off (0.00/0/0)
tcp 0 0 172.17.0.2:80 47.97.16.6:46514 ESTABLISHED off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :64868 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 58.250.125.185:40557 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :23542 CLOSE_WAIT off (0.00/0/0)
tcp 123 0 172.17.0.2:80 83.97.20.33:43025 CLOSE_WAIT off (0.00/0/0)
tcp 309 0 172.17.0.2:80 49.7.21.76:49766 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :62736 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :8610 CLOSE_WAIT off (0.00/0/0)
tcp 0 0 172.17.0.2:80 39.104.190.98:32948 ESTABLISHED off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :53276 CLOSE_WAIT off (0.00/0/0)
tcp 0 0 172.17.0.2:80 39.104.190.98:34416 ESTABLISHED off (0.00/0/0)
tcp 0 0 172.17.0.2:80 39.104.190.98:34762 ESTABLISHED off (0.00/0/0)
tcp 168 0 172.17.0.2:80 47.101.204.96:46959 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :50764 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :55500 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :25026 CLOSE_WAIT off (0.00/0/0)
tcp 269 0 172.17.0.2:80 106.120.173.142:60705 CLOSE_WAIT off (0.00/0/0)
tcp 269 0 172.17.0.2:80 106.120.173.142:53887 CLOSE_WAIT off (0.00/0/0)
tcp 178 0 172.17.0.2:80 198.108.66.208:1328 CLOSE_WAIT off (0.00/0/0)
tcp 0 0 172.17.0.2:80 39.104.190.98:34900 ESTABLISHED off (0.00/0/0)
tcp 68 0 172.17.0.2:80 83.97.20.33:34383 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :39652 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 94.212.232.156:53318 CLOSE_WAIT off (0.00/0/0)
tcp 273 0 172.17.0.2:80 106.120.173.142:33159 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :62256 CLOSE_WAIT off (0.00/0/0)
tcp 123 0 172.17.0.2:80 83.97.20.33:43513 CLOSE_WAIT off (0.00/0/0)
tcp 192 0 172.17.0.2:80 149.129.112.27:31210 CLOSE_WAIT off (0.00/0/0)
tcp 309 0 172.17.0.2:80 49.7.21.76:35242 CLOSE_WAIT off (0.00/0/0)
tcp 15 0 172.17.0.2:80 83.97.20.33:50773 CLOSE_WAIT off (0.00/0/0)
tcp 269 0 172.17.0.2:80 106.120.173.142:51901 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :17806 CLOSE_WAIT off (0.00/0/0)
tcp 123 0 172.17.0.2:80 83.97.20.33:29198 CLOSE_WAIT off (0.00/0/0)
tcp 123 0 172.17.0.2:80 83.97.20.33:13892 CLOSE_WAIT off (0.00/0/0)
tcp 123 0 172.17.0.2:80 83.97.20.33:9376 CLOSE_WAIT off (0.00/0/0)
tcp 269 0 172.17.0.2:80 106.120.173.142:52988 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :4784 CLOSE_WAIT off (0.00/0/0)
tcp 266 0 172.17.0.2:80 27.18.243.66:34843 CLOSE_WAIT off (0.00/0/0)
tcp 273 0 172.17.0.2:80 106.120.173.142:37137 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :46414 CLOSE_WAIT off (0.00/0/0)
tcp 0 0 172.17.0.2:80 39.104.173.109:54924 ESTABLISHED off (0.00/0/0)
tcp 123 0 172.17.0.2:80 83.97.20.33:23171 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :36216 CLOSE_WAIT off (0.00/0/0)
tcp 192 0 172.17.0.2:80 139.205.177.96:53856 CLOSE_WAIT off (0.00/0/0)
tcp 168 0 172.17.0.2:80 47.97.204.168:42021 CLOSE_WAIT off (0.00/0/0)
tcp 273 0 172.17.0.2:80 106.120.173.142:57891 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :27196 CLOSE_WAIT off (0.00/0/0)
tcp 273 0 172.17.0.2:80 106.120.173.142:54735 CLOSE_WAIT off (0.00/0/0)
tcp 123 0 172.17.0.2:80 83.97.20.33:39787 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :41718 CLOSE_WAIT off (0.00/0/0)
tcp 309 0 172.17.0.2:80 49.7.21.76:37709 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :52992 CLOSE_WAIT off (0.00/0/0)
tcp 123 0 172.17.0.2:80 83.97.20.33:29503 CLOSE_WAIT off (0.00/0/0)
tcp 518 0 172.17.0.2:80 #MyIP :5510 CLOSE_WAIT off (0.00/0/0)
tcp 143 0 172.17.0.2:80 169.197.108.6:56014 CLOSE_WAIT off (0.00/0/0)
I can't recognize most of these IP address, so maybe the service is being scanned by some automatic program from all over the world?
But it seems that some connections were not closed properly (they are always in CLOSE_WAIT
status). (I'm not sure when these connections were made. If they were made after the problem, that's probably reasonable because the service can't deal with the connections after it stuck.)
Running whois
on a sample of these IPs shows they're mostly Chinese, and it looks like you're running on Alibaba Cloud, so maybe this is "normal"? I'd be more concerned about the ESTABLISHED
connections; I don't know of a legitimate reason why these connections should be held open. It has the effect of a Slowloris-style attack, though I doubt it's intentional, since they could take you down much more quickly than every few hours or days if that was their goal.
In your original log, you can see messages like
[rustls::msgs::handshake][WARN] Illegal SNI hostname received [52, 55, 46, 55, 53, 46, 56, 50, 46, 56, 52]
This means someone is connecting to your bitwarden_rs by IP address rather than hostname. There are obviously people/companies out there continually scanning IPs to record what services are running and such, and typically this isn't a huge issue, but it's basically creating a denial of service in this case.
You could try increasing the number of Rocket workers (e.g., ROCKET_WORKERS=100
). If there end up not being 100 of these scanners or whatever holding connections open, then this should work fine, but otherwise it's just delaying the problem.
Better would be to cut off a lot of these connections by putting a reverse proxy in front of bitwarden_rs and configuring it such that it only responds to the hostname, not the IP address (personally, I use HAProxy with the strict-sni
option). In addition, you might consider putting your instance behind Cloudflare.
@jjlin I have put Caddy configured as a reverse proxy in front of bitwarden_rs. And now it no longer responds to the requests of IP address. I will see if this helps.
I truly appreciate your assistance all the time!
I believe that the problem is solved. Thanks again.
Subject of the issue
Hi!
I'm using docker to run bitwarden_rs. But every ~10Hours to ~2Days it crashes (no longer accessable), with nothing seems to be wrong in the log.
Is there any way I can trace the problem down?
Your environment
Steps to reproduce
I just start it with
Expected behaviour
Bitwarden_rs should not crash.
Actual behaviour
Bitwarden_rs crashes.
Relevant logs