Ceph

I've also seen these Journal errors at times:
2013-02-13 12:45:55.029747 7f71cabfd700 1 journal check_for_full at 643530752 : JOURNAL FULL 643530752 >= 1048571903 (max_size 1048576000 start 643530752)
2013-02-13 12:45:55.029792 7f71cabfd700 0 journal JOURNAL TOO SMALL: continuing, but slow: item 1381216256 > journal 1048571904 (usable)

Would it be beneficial for me to increase the journal sizes?

Evan Felix wrote:

I've also seen these Journal errors at times:
2013-02-13 12:45:55.029747 7f71cabfd700 1 journal check_for_full at 643530752 : JOURNAL FULL 643530752 >= 1048571903 (max_size 1048576000 start 643530752)
2013-02-13 12:45:55.029792 7f71cabfd700 0 journal JOURNAL TOO SMALL: continuing, but slow: item 1381216256 > journal 1048571904 (usable)

Would it be beneficial for me to increase the journal sizes?

Hi Evan!

Yes... larger journal will help avoid the FULL messages, certainly. 1GB isn't particularly big. The default is 5 or 10 (i forget).

The heartbeat issue sounds very much like a bug that is fixed and going into 0.56.3 (releasing later today). Can you try that, or latest bobtail branch, and see if the issue goes away? Be warned that the first restart of the osd may take a while as it "catches up".

That JOURNAL TOO SMALL message indicates you're sending single operations which are larger than your journal. And indeed your journal is 1GB and that op is 1.3GB.

If you're doing a lot of stuff with gigabyte-scale objects, it could also explain why you're getting a bunch of suicide timeouts (which is the OSD complaining that it gave the filesystem something to do, and it went away and never came back). Ceph is in general optimized for megabyte-scale objects, and you can do larger ones but will need to tune things differently — I'd really recommend chunking of some sort instead.

the objects in question are about 1360713573, though i only do small updates inside the file. does changing the size in the ceph.conf file for the journal make it grow in size?

No, you'd have to shut down the OSD, do a journal flush, and then re-create the journal. It's sparsely documented at http://ceph.com/docs/master/man/8/ceph-osd/?highlight=flush-journal#cmdoption-ceph-osd--flush-journal

I'll try the new code when it is released. for now i've resized the journal on one of the problems osd's( osd 2) with these commands:

ceph-osd -i 2 --flush-journal
mv /var/lib/ceph/osd/ceph-2/journal /var/lib/ceph/osd/ceph-2/journal.old
ceph-osd -i 2 --mkjournal

whoops, grabbed the mtime, they are all about 13380480 bytes.

Evan Felix wrote:

the objects in question are about 1360713573, though i only do small updates inside the file. does changing the size in the ceph.conf file for the journal make it grow in size?

It looks like IndexedLog::caller_ops is growing without bound; trying to reproduce that, although it is likely unrelated to your problem here.

What are the other threads doing? It has a lot of old map epochs to process.. this is somewhat expected right after the upgrade to .3, but it shouldn't persist after an initial (slow) osd restart.

Also, how did you make gdb print the STL containers so nicely? :)

Hmm, it's not clear why it would get stuck there. Can you reproduce this with 'debug osd = 10'?

The earlier log you attached may have had it, but we just upgraded redmine and the attachments seem to be missing currently.

Woah, okay.. one of your pgs has a 1.3GB log object: 'read_log 0~1381204356'. That is what it is trying to write out when it hits the suicide timeout. The pg claims to have done 90 million updates over its lifetime (that last 10M of which are in the log). Other pgs in that pool have similar numbers, so that does seem to be real... that also explains why that hash_map was huge.

I'm not sure why the PG didn't trim its log before. At this point, tho, the simplest thing may be to just let it chew through the peering process (and then trim). You can increase the heartbeat timeouts with 'osd op thread timeout' (the suicide threshold is 10* that value).

is there a way to determine what object it is, i expect all my object to be about 13M, nowhere near a gig. i'll adjust timeout and let it run

It's not a user object; its the internal pg log of recent requests. No way to change it without surgery...

Let us know if a longer timeout doesn't let it recover and move on!

I've set it to 45... and its sucking up memory... and the oom killer got it... I'll see if i can add swap.. it was at 26G of mem before it died.

sage, the rados command i'm using have start responding again.. I had to move through a few osd's changing the time out, as one came up a couple others died.. but they are holding for now.

excellent. can you paste the output from 'ceph pg 4.0 query' so we can verify that that ginormous log got trimmed?

thanks!

I pushed a wip-4116-workaround branch with a workaround that will make it trim the log. It might be a painful restart (it'll load the log one last time) but it should trim it shortly after that. If you install that on and restart osd.8 first it'll get you back in business! Thanks for helping track this down. issue #4192 will track a permanent fix.

Yes the cluster has returned to a working state and osd's are staying up with the new code.