[ceph-users] Radosgw (civetweb) hangs once around 850 established connections

Discussion:

s***@uchicago.edu

2016-03-17 00:03:41 UTC

I have a cluster of around 630 OSDs with 3 dedicated monitors and 2
dedicated gateways. The entire cluster is running hammer (0.94.5
(9764da52395923e0b32908d83a9f7304401fee43)).

(Both of my gateways have stopped responding to curl right now.
***@host:~# timeout 5 curl localhost ; echo $?
124

From here I checked and it looks like radosgw has over 1 million open
files:
***@host:~# grep -i rados whatisopen.files.list | wc -l
1151753

And around 750 open connections:
***@host:~# netstat -planet | grep radosgw | wc -l
752
***@host:~# ss -tnlap | grep rados | wc -l
752

I don't think that the backend storage is hanging based on the following
dump:

***@host:~# ceph daemon /var/run/ceph/ceph-client.rgw.kh11-9.asok
objecter_requests | grep -i mtime
"mtime": "0.000000",
"mtime": "0.000000",
"mtime": "0.000000",
"mtime": "0.000000",
"mtime": "0.000000",
"mtime": "0.000000",
[...]
"mtime": "0.000000",

The radosgw log is still showing lots of activity and so does strace
which makes me think this is a config issue or limit of some kind that
is not triggering a log. Of what I am not sure as the log doesn't seem
to show any open file limit being hit and I don't see any big errors
showing up in the logs.
(last 500 lines of /var/log/radosgw/client.radosgw.log)
http://pastebin.com/jmM1GFSA

Perf dump of radosgw
http://pastebin.com/rjfqkxzE

Radosgw objecter requests:
http://pastebin.com/skDJiyHb

After restarting the gateway with '/etc/init.d/radosgw restart' the old
process remains, no error is sent, and then I get connection refused via
curl or netcat::
***@kh11-9:~# curl localhost
curl: (7) Failed to connect to localhost port 80: Connection refused

Once I kill the old radosgw via sigkill the new radosgw instance
restarts automatically and starts responding::
***@kh11-9:~# curl localhost
<?xml version="1.0" encoding="UTF-8"?><ListAllMyBucketsResult
xmlns="http://s3.amazonaws.com/doc/2006-03-01/"><Owner><ID>anonymous</ID><DisplayName></DisplayName></Owner><Buckets></Buckets></ListAllMyB

What is going on here?

Ben Hines

2016-03-17 01:30:25 UTC

Permalink

What OS are you using?

I have a lot more open connections than that. (though i have some other
issues, where rgw sometimes returns 500 errors, it doesn't stop like yours)

You might try tuning civetweb's num_threads and 'rgw num rados handles':

rgw frontends = civetweb num_threads=125
error_log_file=/var/log/radosgw/civetweb.error.log
access_log_file=/var/log/radosgw/civetweb.access.log
rgw num rados handles = 32

You can also up civetweb loglevel:

debug civetweb = 20

-Ben

Post by s***@uchicago.edu
I have a cluster of around 630 OSDs with 3 dedicated monitors and 2
dedicated gateways. The entire cluster is running hammer (0.94.5
(9764da52395923e0b32908d83a9f7304401fee43)).
(Both of my gateways have stopped responding to curl right now.
124
From here I checked and it looks like radosgw has over 1 million open
1151753
752
752
I don't think that the backend storage is hanging based on the following
objecter_requests | grep -i mtime
"mtime": "0.000000",
"mtime": "0.000000",
"mtime": "0.000000",
"mtime": "0.000000",
"mtime": "0.000000",
"mtime": "0.000000",
[...]
"mtime": "0.000000",
The radosgw log is still showing lots of activity and so does strace which
makes me think this is a config issue or limit of some kind that is not
triggering a log. Of what I am not sure as the log doesn't seem to show any
open file limit being hit and I don't see any big errors showing up in the
logs.
(last 500 lines of /var/log/radosgw/client.radosgw.log)
http://pastebin.com/jmM1GFSA
Perf dump of radosgw
http://pastebin.com/rjfqkxzE
http://pastebin.com/skDJiyHb
After restarting the gateway with '/etc/init.d/radosgw restart' the old
process remains, no error is sent, and then I get connection refused via
curl: (7) Failed to connect to localhost port 80: Connection refused
Once I kill the old radosgw via sigkill the new radosgw instance restarts
<?xml version="1.0" encoding="UTF-8"?><ListAllMyBucketsResult xmlns="
http://s3.amazonaws.com/doc/2006-03-01/
"><Owner><ID>anonymous</ID><DisplayName></DisplayName></Owner><Buckets></Buckets></ListAllMyB
What is going on here?
_______________________________________________
ceph-users mailing list
http://lists.ceph.com/listinfo.cgi/ceph-users-ceph.com

Sean Sullivan

2016-03-17 01:42:59 UTC

Permalink

Hi Ben!

I'm using ubuntu 14.04
I have restarted the gateways with the numthreads line you suggested. I
hope this helps. I would think I would get some kind of throttle log or
something.

500 seems really strange as well. Do you have a thread for this? RGW still
has a weird race condition with multipart uploads where it garbage collects
the parts but I think I get a 404 for those which makes sense. I hope
you're not seeing something similar.

Thanks for the tip and good luck! I'll bump this thread when it happens again.

Sent from my pocket typo cannon.

Post by Ben Hines
What OS are you using?
I have a lot more open connections than that. (though i have some other
issues, where rgw sometimes returns 500 errors, it doesn't stop like yours)
rgw frontends = civetweb num_threads=125
error_log_file=/var/log/radosgw/civetweb.error.log
access_log_file=/var/log/radosgw/civetweb.access.log
rgw num rados handles = 32
debug civetweb = 20
-Ben

s***@uchicago.edu

2016-03-29 18:35:09 UTC

Permalink

So an update for anyone else having this issue. It looks like radosgw
either has a memory leak or it spools the whole object into ram or
something.

***@kh11-9:/etc/apt/sources.list.d# free -m
total used free shared buffers cached
Mem: 64397 63775 621 0 3 46
-/+ buffers/cache: 63725 671
Swap: 65499 17630 47869

***@kh11-9:/etc/apt/sources.list.d# ps faux | grep -iE "USE[R]|radosg[w]"
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
root 269910 134 95.2 90622120 62819128 ? Ssl 12:31 79:37
/usr/bin/radosgw --cluster=ceph --id rgw.kh11-9 -f

The odd things are 1.) the disk is fine. 2.) the rest of the server
seems very responsive. I can ssh into the server without any problems,
curl out, wget, etc but radosgw is stuck in the mud

This is after 150-300 wget requests to public objects, 2 radosgws freeze
like this. The cluster is health okay as well::

***@kh11-9:~# grep -iE "health" ceph_report.json
"health": {
"health": {
"health_services": [
"health": "HEALTH_OK"
"health": "HEALTH_OK"
"health": "HEALTH_OK"
"health": "HEALTH_OK"
"health": "HEALTH_OK"
"health": "HEALTH_OK"
"overall_status": "HEALTH_OK",

Has anyone seen this behavior before?

Dan van der Ster

2016-03-30 10:33:41 UTC

Permalink

Hi Sean,

Did you check that the process isn't hitting some ulimits? cat
/proc/`pidof radosgw`/limits and compare with the num processes/num
FDs in use.

Cheers, Dan

So an update for anyone else having this issue. It looks like radosgw either
has a memory leak or it spools the whole object into ram or something.
total used free shared buffers cached
Mem: 64397 63775 621 0 3 46
-/+ buffers/cache: 63725 671
Swap: 65499 17630 47869
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
root 269910 134 95.2 90622120 62819128 ? Ssl 12:31 79:37
/usr/bin/radosgw --cluster=ceph --id rgw.kh11-9 -f
The odd things are 1.) the disk is fine. 2.) the rest of the server seems
very responsive. I can ssh into the server without any problems, curl out,
wget, etc but radosgw is stuck in the mud
This is after 150-300 wget requests to public objects, 2 radosgws freeze
"health": {
"health": {
"health_services": [
"health": "HEALTH_OK"
"health": "HEALTH_OK"
"health": "HEALTH_OK"
"health": "HEALTH_OK"
"health": "HEALTH_OK"
"health": "HEALTH_OK"
"overall_status": "HEALTH_OK",
Has anyone seen this behavior before?
_______________________________________________
ceph-users mailing list
http://lists.ceph.com/listinfo.cgi/ceph-users-ceph.com

s***@uchicago.edu

2016-03-31 06:02:32 UTC

Permalink

Thanks Dan!

Thanks for this. I didn't know /proc/procid/limits was here! Super useful!!

Here are my limits::
***@kh11-9:~# cat /proc/419990/limits
Limit Soft Limit Hard Limit Units
Max cpu time unlimited unlimited seconds
Max file size unlimited unlimited bytes
Max data size unlimited unlimited bytes
Max stack size 8388608 unlimited bytes
Max core file size 0 unlimited bytes
Max resident set unlimited unlimited bytes
Max processes 515007 515007
processes
Max open files 1048576 1048576 files
Max locked memory 65536 65536 bytes
Max address space unlimited unlimited bytes
Max file locks unlimited unlimited locks
Max pending signals 515007 515007 signals
Max msgqueue size 819200 819200 bytes
Max nice priority 0 0
Max realtime priority 0 0
Max realtime timeout unlimited unlimited us

***@kh11-9:~# lsof -p 419990 | wc -l
600

***@kh11-9:~# ps -o nlwp 419990
NLWP
1251

***@kh11-9:~# ps -eo nlwp | tail -n +2 | awk '{ sum += $1 } END { print
sum }'
1585

***@kh11-9:~# ulimit -a
core file size (blocks, -c) 0
data seg size (kbytes, -d) unlimited
scheduling priority (-e) 0
file size (blocks, -f) unlimited
pending signals (-i) 515007
max locked memory (kbytes, -l) 64
max memory size (kbytes, -m) unlimited
open files (-n) 1048576
pipe size (512 bytes, -p) 8
POSIX message queues (bytes, -q) 819200
real-time priority (-r) 0
stack size (kbytes, -s) 8192
cpu time (seconds, -t) unlimited
max user processes (-u) 515007
virtual memory (kbytes, -v) unlimited
file locks (-x) unlimited

***@kh11-9:~# ls /proc/419990/fd/ | wc -l
536

I think this is a systemwide config issue as even after I restart
radosgw this issue doens't go away entirely and seems to linger, I just
have no idea what it could be.

Prior to this behavior happening I can almost fully saturate my network
link to near 10Gbps. After the behavior starts happening I can not even
wget a 100mb bin file. It ends up taking hours. Small wgets complete
though and I can curl a plain <html><body>test</body></html> webpage
without any issue. Speed is greatly reduced though.

The rest of the server seems to behave fine (sans the newly discovered
download issue)

Post by Dan van der Ster
Hi Sean,
Did you check that the process isn't hitting some ulimits? cat
/proc/`pidof radosgw`/limits and compare with the num processes/num
FDs in use.
Cheers, Dan