Project

General

Profile

Bug #8439

ceph-osd crashing often

Added by Pierre Grandin over 5 years ago. Updated about 4 years ago.

Status:
Won't Fix
Priority:
Normal
Assignee:
-
Category:
-
Target version:
-
Start date:
05/26/2014
Due date:
% Done:

0%

Source:
Community (user)
Tags:
Backport:
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Pull request ID:

Description

We have most of our OSDs crashing at least twice a day since a couple of days.

Here's the logs of such a crash.

Versions of the binaries:

[ebuild   R   ] sys-fs/xfsprogs-3.1.10  USE="nls readline -libedit -static -static-libs" 
[ebuild  NS   ] sys-kernel/gentoo-sources-3.12.13 [3.11.10] USE="-build -deblob -experimental -symlink" 
[ebuild   R   ] sys-cluster/ceph-0.78  USE="xfs -btrfs -debug -fuse -gtk -libatomic -radosgw -static-libs -tcmalloc" 

I've also attached the binary as suggested in the dump.

Thanks for your help.

  -116> 2014-05-26 09:50:14.837087 7fc8e8ff9700  5 -- op tracker -- , seq: 1222096, time: 2014-05-26 09:50:14.837087, event: done, request: osd_sub_op(client.143277.0:177751 3.56 90520cd6/rbd_data.343571f3e82af.0000000000000116/head//3 [] v 7899'10109 snapset=0=[]:[] snapc=0=[]) v9
  -115> 2014-05-26 09:50:14.837101 7fc8d6ff5700  5 -- op tracker -- , seq: 1222255, time: 2014-05-26 09:50:14.837089, event: commit_queued_for_journal_write, request: osd_sub_op(client.142962.0:319787 3.1a fc9b109a/rbd_data.285be4fef98b3.0000000000000159/head//3 [] v 7899'133030 snapset=0=[]:[] snapc=0=[]) v9
  -114> 2014-05-26 09:50:14.837174 7fc8d6ff5700  5 -- op tracker -- , seq: 1222218, time: 2014-05-26 09:50:14.837151, event: reached_pg, request: osd_sub_op(client.157357.0:243216 3.3c 637643c/rbd_data.2bbf42620642.0000000000000200/head//3 [] v 7899'18490 snapset=0=[]:[] snapc=0=[]) v9
  -113> 2014-05-26 09:50:14.837195 7fc8d6ff5700  5 -- op tracker -- , seq: 1222218, time: 2014-05-26 09:50:14.837195, event: started, request: osd_sub_op(client.157357.0:243216 3.3c 637643c/rbd_data.2bbf42620642.0000000000000200/head//3 [] v 7899'18490 snapset=0=[]:[] snapc=0=[]) v9
  -112> 2014-05-26 09:50:14.837380 7fc8d6ff5700  5 -- op tracker -- , seq: 1222218, time: 2014-05-26 09:50:14.837380, event: started, request: osd_sub_op(client.157357.0:243216 3.3c 637643c/rbd_data.2bbf42620642.0000000000000200/head//3 [] v 7899'18490 snapset=0=[]:[] snapc=0=[]) v9
  -111> 2014-05-26 09:50:14.837396 7fc8d6ff5700  2 filestore(/var/lib/ceph/osd/ceph-0) waiting 51 > 50 ops || 21381983 > 104857600
  -110> 2014-05-26 09:50:14.839621 7fc8eaffd700  5 -- op tracker -- , seq: 1222147, time: 2014-05-26 09:50:14.839621, event: journaled_completion_queued, request: osd_sub_op(client.139840.0:287955 3.57 d0ed54d7/rbd_data.221dd64207aa8.0000000000000041/head//3 [] v 7899'9601 snapset=0=[]:[] snapc=0=[]) v9
  -109> 2014-05-26 09:50:14.839677 7fc8e3fff700  5 -- op tracker -- , seq: 1222147, time: 2014-05-26 09:50:14.839676, event: commit_sent, request: osd_sub_op(client.139840.0:287955 3.57 d0ed54d7/rbd_data.221dd64207aa8.0000000000000041/head//3 [] v 7899'9601 snapset=0=[]:[] snapc=0=[]) v9
  -108> 2014-05-26 09:50:14.839687 7fc8eb7fe700  5 -- op tracker -- , seq: 1222244, time: 2014-05-26 09:50:14.839687, event: write_thread_in_journal_buffer, request: osd_sub_op(client.142962.0:319785 3.72 f8867c72/rbd_data.285be4fef98b3.0000000000000160/head//3 [] v 7899'10189 snapset=0=[]:[] snapc=0=[]) v9
  -107> 2014-05-26 09:50:14.839695 7fc8e3fff700  1 -- 172.16.128.36:6801/22825 --> osd.6 172.16.128.39:6809/27164 -- osd_sub_op_reply(client.139840.0:287955 3.57 d0ed54d7/rbd_data.221dd64207aa8.0000000000000041/head//3 [] ondisk, result = 0) v2 -- ?+0 0x7fc71002cca0
  -106> 2014-05-26 09:50:14.839717 7fc8eb7fe700  5 -- op tracker -- , seq: 1222164, time: 2014-05-26 09:50:14.839717, event: write_thread_in_journal_buffer, request: osd_sub_op(client.160234.0:191783 3.26 35e29b26/rbd_data.2712433b32b6b.0000000000000125/head//3 [] v 7899'88753 snapset=0=[]:[] snapc=0=[]) v9
  -105> 2014-05-26 09:50:14.839746 7fc8eb7fe700  5 -- op tracker -- , seq: 1222205, time: 2014-05-26 09:50:14.839746, event: write_thread_in_journal_buffer, request: osd_sub_op(client.143149.0:140973 3.6e 8ab7446e/rbd_data.3992837b908ce.00000000000000f0/head//3 [] v 7899'92146 snapset=0=[]:[] snapc=0=[]) v9
  -104> 2014-05-26 09:50:14.839774 7fc8eb7fe700  5 -- op tracker -- , seq: 1222204, time: 2014-05-26 09:50:14.839774, event: write_thread_in_journal_buffer, request: osd_sub_op(client.143149.0:140970 3.6c a595f96c/rbd_data.3992837b908ce.0000000000000001/head//3 [] v 7899'15366 snapset=0=[]:[] snapc=0=[]) v9
  -103> 2014-05-26 09:50:14.839794 7fc8eb7fe700  5 -- op tracker -- , seq: 1222255, time: 2014-05-26 09:50:14.839794, event: write_thread_in_journal_buffer, request: osd_sub_op(client.142962.0:319787 3.1a fc9b109a/rbd_data.285be4fef98b3.0000000000000159/head//3 [] v 7899'133030 snapset=0=[]:[] snapc=0=[]) v9
  -102> 2014-05-26 09:50:14.841459 7fc8eaffd700  5 -- op tracker -- , seq: 1222244, time: 2014-05-26 09:50:14.841459, event: journaled_completion_queued, request: osd_sub_op(client.142962.0:319785 3.72 f8867c72/rbd_data.285be4fef98b3.0000000000000160/head//3 [] v 7899'10189 snapset=0=[]:[] snapc=0=[]) v9
  -101> 2014-05-26 09:50:14.841484 7fc8eaffd700  5 -- op tracker -- , seq: 1222164, time: 2014-05-26 09:50:14.841484, event: journaled_completion_queued, request: osd_sub_op(client.160234.0:191783 3.26 35e29b26/rbd_data.2712433b32b6b.0000000000000125/head//3 [] v 7899'88753 snapset=0=[]:[] snapc=0=[]) v9
  -100> 2014-05-26 09:50:14.841536 7fc8e3fff700  5 -- op tracker -- , seq: 1222244, time: 2014-05-26 09:50:14.841507, event: commit_sent, request: osd_sub_op(client.142962.0:319785 3.72 f8867c72/rbd_data.285be4fef98b3.0000000000000160/head//3 [] v 7899'10189 snapset=0=[]:[] snapc=0=[]) v9
   -99> 2014-05-26 09:50:14.841557 7fc8e3fff700  1 -- 172.16.128.36:6801/22825 --> osd.9 172.16.128.33:6810/1031764 -- osd_sub_op_reply(client.142962.0:319785 3.72 f8867c72/rbd_data.285be4fef98b3.0000000000000160/head//3 [] ondisk, result = 0) v2 -- ?+0 0x7fc710055770
   -98> 2014-05-26 09:50:14.841556 7fc8eaffd700  5 -- op tracker -- , seq: 1222205, time: 2014-05-26 09:50:14.841544, event: journaled_completion_queued, request: osd_sub_op(client.143149.0:140973 3.6e 8ab7446e/rbd_data.3992837b908ce.00000000000000f0/head//3 [] v 7899'92146 snapset=0=[]:[] snapc=0=[]) v9
   -97> 2014-05-26 09:50:14.841577 7fc8e3fff700  5 -- op tracker -- , seq: 1222164, time: 2014-05-26 09:50:14.841577, event: commit_sent, request: osd_sub_op(client.160234.0:191783 3.26 35e29b26/rbd_data.2712433b32b6b.0000000000000125/head//3 [] v 7899'88753 snapset=0=[]:[] snapc=0=[]) v9
   -96> 2014-05-26 09:50:14.841590 7fc8e3fff700  1 -- 172.16.128.36:6801/22825 --> osd.15 172.16.128.35:6811/10008850 -- osd_sub_op_reply(client.160234.0:191783 3.26 35e29b26/rbd_data.2712433b32b6b.0000000000000125/head//3 [] ondisk, result = 0) v2 -- ?+0 0x7fc710019d40
   -95> 2014-05-26 09:50:14.841590 7fc8eaffd700  5 -- op tracker -- , seq: 1222204, time: 2014-05-26 09:50:14.841578, event: journaled_completion_queued, request: osd_sub_op(client.143149.0:140970 3.6c a595f96c/rbd_data.3992837b908ce.0000000000000001/head//3 [] v 7899'15366 snapset=0=[]:[] snapc=0=[]) v9
   -94> 2014-05-26 09:50:14.841607 7fc8e3fff700  5 -- op tracker -- , seq: 1222205, time: 2014-05-26 09:50:14.841607, event: commit_sent, request: osd_sub_op(client.143149.0:140973 3.6e 8ab7446e/rbd_data.3992837b908ce.00000000000000f0/head//3 [] v 7899'92146 snapset=0=[]:[] snapc=0=[]) v9
   -93> 2014-05-26 09:50:14.841621 7fc8e3fff700  1 -- 172.16.128.36:6801/22825 --> osd.20 172.16.128.41:6801/18217 -- osd_sub_op_reply(client.143149.0:140973 3.6e 8ab7446e/rbd_data.3992837b908ce.00000000000000f0/head//3 [] ondisk, result = 0) v2 -- ?+0 0x7fc710028ef0
   -92> 2014-05-26 09:50:14.841620 7fc8eaffd700  5 -- op tracker -- , seq: 1222255, time: 2014-05-26 09:50:14.841612, event: journaled_completion_queued, request: osd_sub_op(client.142962.0:319787 3.1a fc9b109a/rbd_data.285be4fef98b3.0000000000000159/head//3 [] v 7899'133030 snapset=0=[]:[] snapc=0=[]) v9
   -91> 2014-05-26 09:50:14.841639 7fc8e3fff700  5 -- op tracker -- , seq: 1222204, time: 2014-05-26 09:50:14.841639, event: commit_sent, request: osd_sub_op(client.143149.0:140970 3.6c a595f96c/rbd_data.3992837b908ce.0000000000000001/head//3 [] v 7899'15366 snapset=0=[]:[] snapc=0=[]) v9
   -90> 2014-05-26 09:50:14.841656 7fc8e3fff700  1 -- 172.16.128.36:6801/22825 --> osd.21 172.16.128.41:6806/18691 -- osd_sub_op_reply(client.143149.0:140970 3.6c a595f96c/rbd_data.3992837b908ce.0000000000000001/head//3 [] ondisk, result = 0) v2 -- ?+0 0x7fc7100372e0
   -89> 2014-05-26 09:50:14.841683 7fc8e3fff700  5 -- op tracker -- , seq: 1222255, time: 2014-05-26 09:50:14.841683, event: commit_sent, request: osd_sub_op(client.142962.0:319787 3.1a fc9b109a/rbd_data.285be4fef98b3.0000000000000159/head//3 [] v 7899'133030 snapset=0=[]:[] snapc=0=[]) v9
   -88> 2014-05-26 09:50:14.841703 7fc8e3fff700  1 -- 172.16.128.36:6801/22825 --> osd.1 172.16.128.39:6814/27216 -- osd_sub_op_reply(client.142962.0:319787 3.1a fc9b109a/rbd_data.285be4fef98b3.0000000000000159/head//3 [] ondisk, result = 0) v2 -- ?+0 0x7fc710005df0
   -87> 2014-05-26 09:50:14.848624 7fc8e8ff9700  1 -- 172.16.128.36:6801/22825 --> 172.16.128.41:6801/18217 -- MOSDPGPushReply(3.67 7899 [PushReplyOp(a9997867/rbd_data.27d36b8b4567.0000000000018081/head//3),PushReplyOp(5f30a867/rbd_data.21efb4624c7dd.000000000000093f/head//3)]) v2 -- ?+0 0x7fc66d2f6590 con 0x7fc874000b30
   -86> 2014-05-26 09:50:14.848925 7fc8d6ff5700  5 -- op tracker -- , seq: 1222218, time: 2014-05-26 09:50:14.848924, event: commit_queued_for_journal_write, request: osd_sub_op(client.157357.0:243216 3.3c 637643c/rbd_data.2bbf42620642.0000000000000200/head//3 [] v 7899'18490 snapset=0=[]:[] snapc=0=[]) v9
   -85> 2014-05-26 09:50:14.849014 7fc8d6ff5700  5 -- op tracker -- , seq: 1222224, time: 2014-05-26 09:50:14.849014, event: reached_pg, request: osd_sub_op(client.142998.0:106879 3.36 4782a936/rbd_data.289153346db8b.00000000000000d2/head//3 [] v 7899'198539 snapset=0=[]:[] snapc=0=[]) v9
   -84> 2014-05-26 09:50:14.849034 7fc8d6ff5700  5 -- op tracker -- , seq: 1222224, time: 2014-05-26 09:50:14.849034, event: started, request: osd_sub_op(client.142998.0:106879 3.36 4782a936/rbd_data.289153346db8b.00000000000000d2/head//3 [] v 7899'198539 snapset=0=[]:[] snapc=0=[]) v9
   -83> 2014-05-26 09:50:14.849082 7fc8eb7fe700  5 -- op tracker -- , seq: 1222218, time: 2014-05-26 09:50:14.849081, event: write_thread_in_journal_buffer, request: osd_sub_op(client.157357.0:243216 3.3c 637643c/rbd_data.2bbf42620642.0000000000000200/head//3 [] v 7899'18490 snapset=0=[]:[] snapc=0=[]) v9
   -82> 2014-05-26 09:50:14.849213 7fc8d6ff5700  5 -- op tracker -- , seq: 1222224, time: 2014-05-26 09:50:14.849213, event: started, request: osd_sub_op(client.142998.0:106879 3.36 4782a936/rbd_data.289153346db8b.00000000000000d2/head//3 [] v 7899'198539 snapset=0=[]:[] snapc=0=[]) v9
   -81> 2014-05-26 09:50:14.849233 7fc8d6ff5700  2 filestore(/var/lib/ceph/osd/ceph-0) waiting 51 > 50 ops || 8794929 > 104857600
   -80> 2014-05-26 09:50:14.849289 7fc8e9ffb700  0 xfsfilestorebackend(/var/lib/ceph/osd/ceph-0) set_extsize: FSSETXATTR: (22) Invalid argument
   -79> 2014-05-26 09:50:14.849645 7fc8e8ff9700  5 -- op tracker -- , seq: 1222108, time: 2014-05-26 09:50:14.849645, event: sub_op_applied, request: osd_sub_op(client.142962.0:319782 3.a b7c3488a/rbd_data.285be4fef98b3.0000000000000129/head//3 [] v 7899'159068 snapset=0=[]:[] snapc=0=[]) v9
   -78> 2014-05-26 09:50:14.849678 7fc8d6ff5700  5 -- op tracker -- , seq: 1222224, time: 2014-05-26 09:50:14.849663, event: commit_queued_for_journal_write, request: osd_sub_op(client.142998.0:106879 3.36 4782a936/rbd_data.289153346db8b.00000000000000d2/head//3 [] v 7899'198539 snapset=0=[]:[] snapc=0=[]) v9
   -77> 2014-05-26 09:50:14.849715 7fc8e8ff9700  5 -- op tracker -- , seq: 1222108, time: 2014-05-26 09:50:14.849701, event: done, request: osd_sub_op(client.142962.0:319782 3.a b7c3488a/rbd_data.285be4fef98b3.0000000000000129/head//3 [] v 7899'159068 snapset=0=[]:[] snapc=0=[]) v9
   -76> 2014-05-26 09:50:14.849766 7fc8d6ff5700  5 -- op tracker -- , seq: 1222153, time: 2014-05-26 09:50:14.849736, event: reached_pg, request: osd_sub_op(client.153793.0:488591 3.9 fcf66089/rbd_data.2992641f122bd.0000000000000427/head//3 [] v 7899'179827 snapset=0=[]:[] snapc=0=[]) v9
   -75> 2014-05-26 09:50:14.849790 7fc8d6ff5700  5 -- op tracker -- , seq: 1222153, time: 2014-05-26 09:50:14.849790, event: started, request: osd_sub_op(client.153793.0:488591 3.9 fcf66089/rbd_data.2992641f122bd.0000000000000427/head//3 [] v 7899'179827 snapset=0=[]:[] snapc=0=[]) v9
   -74> 2014-05-26 09:50:14.849921 7fc8d6ff5700  5 -- op tracker -- , seq: 1222153, time: 2014-05-26 09:50:14.849921, event: started, request: osd_sub_op(client.153793.0:488591 3.9 fcf66089/rbd_data.2992641f122bd.0000000000000427/head//3 [] v 7899'179827 snapset=0=[]:[] snapc=0=[]) v9
   -73> 2014-05-26 09:50:14.849940 7fc8d6ff5700  2 filestore(/var/lib/ceph/osd/ceph-0) waiting 51 > 50 ops || 8782473 > 104857600
   -72> 2014-05-26 09:50:14.851851 7fc8eaffd700  5 -- op tracker -- , seq: 1222218, time: 2014-05-26 09:50:14.851850, event: journaled_completion_queued, request: osd_sub_op(client.157357.0:243216 3.3c 637643c/rbd_data.2bbf42620642.0000000000000200/head//3 [] v 7899'18490 snapset=0=[]:[] snapc=0=[]) v9
   -71> 2014-05-26 09:50:14.851907 7fc8e3fff700  5 -- op tracker -- , seq: 1222218, time: 2014-05-26 09:50:14.851907, event: commit_sent, request: osd_sub_op(client.157357.0:243216 3.3c 637643c/rbd_data.2bbf42620642.0000000000000200/head//3 [] v 7899'18490 snapset=0=[]:[] snapc=0=[]) v9
   -70> 2014-05-26 09:50:14.851929 7fc8eb7fe700  5 -- op tracker -- , seq: 1222224, time: 2014-05-26 09:50:14.851929, event: write_thread_in_journal_buffer, request: osd_sub_op(client.142998.0:106879 3.36 4782a936/rbd_data.289153346db8b.00000000000000d2/head//3 [] v 7899'198539 snapset=0=[]:[] snapc=0=[]) v9
   -69> 2014-05-26 09:50:14.851945 7fc8e3fff700  1 -- 172.16.128.36:6801/22825 --> osd.2 172.16.128.39:6801/19743 -- osd_sub_op_reply(client.157357.0:243216 3.3c 637643c/rbd_data.2bbf42620642.0000000000000200/head//3 [] ondisk, result = 0) v2 -- ?+0 0x7fc710069900
   -68> 2014-05-26 09:50:14.852456 7fc8e8ff9700  1 -- 172.16.128.36:6801/22825 --> 172.16.128.41:6801/18217 -- MOSDPGPushReply(3.67 7899 [PushReplyOp(c47ba867/rbd_data.204046b8b4567.0000000000002d20/head//3)]) v2 -- ?+0 0x7fc8de9cab20 con 0x7fc874000b30
   -67> 2014-05-26 09:50:14.852519 7fc8d6ff5700  5 -- op tracker -- , seq: 1222153, time: 2014-05-26 09:50:14.852518, event: commit_queued_for_journal_write, request: osd_sub_op(client.153793.0:488591 3.9 fcf66089/rbd_data.2992641f122bd.0000000000000427/head//3 [] v 7899'179827 snapset=0=[]:[] snapc=0=[]) v9
   -66> 2014-05-26 09:50:14.852589 7fc8d6ff5700  5 -- op tracker -- , seq: 1222256, time: 2014-05-26 09:50:14.852588, event: reached_pg, request: osd_sub_op(client.142944.0:209800 3.16 5f849196/rbd_data.270827459abfd.0000000000000042/head//3 [] v 7899'108013 snapset=0=[]:[] snapc=0=[]) v9
   -65> 2014-05-26 09:50:14.852615 7fc8d6ff5700  5 -- op tracker -- , seq: 1222256, time: 2014-05-26 09:50:14.852614, event: started, request: osd_sub_op(client.142944.0:209800 3.16 5f849196/rbd_data.270827459abfd.0000000000000042/head//3 [] v 7899'108013 snapset=0=[]:[] snapc=0=[]) v9
   -64> 2014-05-26 09:50:14.852796 7fc8d6ff5700  5 -- op tracker -- , seq: 1222256, time: 2014-05-26 09:50:14.852795, event: started, request: osd_sub_op(client.142944.0:209800 3.16 5f849196/rbd_data.270827459abfd.0000000000000042/head//3 [] v 7899'108013 snapset=0=[]:[] snapc=0=[]) v9
   -63> 2014-05-26 09:50:14.852818 7fc8d6ff5700  2 filestore(/var/lib/ceph/osd/ceph-0) waiting 51 > 50 ops || 4603959 > 104857600
   -62> 2014-05-26 09:50:14.853395 7fc8e9ffb700  0 xfsfilestorebackend(/var/lib/ceph/osd/ceph-0) set_extsize: FSSETXATTR: (22) Invalid argument
   -61> 2014-05-26 09:50:14.853662 7fc8d6ff5700  5 -- op tracker -- , seq: 1222256, time: 2014-05-26 09:50:14.853662, event: commit_queued_for_journal_write, request: osd_sub_op(client.142944.0:209800 3.16 5f849196/rbd_data.270827459abfd.0000000000000042/head//3 [] v 7899'108013 snapset=0=[]:[] snapc=0=[]) v9
   -60> 2014-05-26 09:50:14.853684 7fc8e8ff9700  5 -- op tracker -- , seq: 1222105, time: 2014-05-26 09:50:14.853671, event: sub_op_applied, request: osd_sub_op(client.230360.0:680229 3.51 f4760ad1/rbd_data.38e543be927fb.0000000000000110/head//3 [] v 7899'12340 snapset=0=[]:[] snapc=0=[]) v9
   -59> 2014-05-26 09:50:14.853709 7fc8d6ff5700  5 -- op tracker -- , seq: 1222165, time: 2014-05-26 09:50:14.853709, event: reached_pg, request: osd_sub_op(client.207743.0:153575 3.26 17e00226/rbd_data.32f4d3083f808.0000000000000125/head//3 [] v 7899'88754 snapset=0=[]:[] snapc=0=[]) v9
   -58> 2014-05-26 09:50:14.853726 7fc8d6ff5700  5 -- op tracker -- , seq: 1222165, time: 2014-05-26 09:50:14.853726, event: started, request: osd_sub_op(client.207743.0:153575 3.26 17e00226/rbd_data.32f4d3083f808.0000000000000125/head//3 [] v 7899'88754 snapset=0=[]:[] snapc=0=[]) v9
   -57> 2014-05-26 09:50:14.853739 7fc8e8ff9700  5 -- op tracker -- , seq: 1222105, time: 2014-05-26 09:50:14.853730, event: done, request: osd_sub_op(client.230360.0:680229 3.51 f4760ad1/rbd_data.38e543be927fb.0000000000000110/head//3 [] v 7899'12340 snapset=0=[]:[] snapc=0=[]) v9
   -56> 2014-05-26 09:50:14.853857 7fc8d6ff5700  5 -- op tracker -- , seq: 1222165, time: 2014-05-26 09:50:14.853857, event: started, request: osd_sub_op(client.207743.0:153575 3.26 17e00226/rbd_data.32f4d3083f808.0000000000000125/head//3 [] v 7899'88754 snapset=0=[]:[] snapc=0=[]) v9
   -55> 2014-05-26 09:50:14.853873 7fc8e8ff9700  5 -- op tracker -- , seq: 1222103, time: 2014-05-26 09:50:14.853861, event: sub_op_applied, request: osd_sub_op(client.143277.0:177747 3.67 c110a067/rbd_data.343571f3e82af.0000000000000001/head//3 [] v 7899'117915 snapset=0=[]:[] snapc=0=[]) v9
   -54> 2014-05-26 09:50:14.853893 7fc8d6ff5700  5 -- op tracker -- , seq: 1222165, time: 2014-05-26 09:50:14.853893, event: commit_queued_for_journal_write, request: osd_sub_op(client.207743.0:153575 3.26 17e00226/rbd_data.32f4d3083f808.0000000000000125/head//3 [] v 7899'88754 snapset=0=[]:[] snapc=0=[]) v9
   -53> 2014-05-26 09:50:14.853908 7fc8e8ff9700  5 -- op tracker -- , seq: 1222103, time: 2014-05-26 09:50:14.853908, event: done, request: osd_sub_op(client.143277.0:177747 3.67 c110a067/rbd_data.343571f3e82af.0000000000000001/head//3 [] v 7899'117915 snapset=0=[]:[] snapc=0=[]) v9
   -52> 2014-05-26 09:50:14.853943 7fc8d6ff5700  5 -- op tracker -- , seq: 1222230, time: 2014-05-26 09:50:14.853943, event: reached_pg, request: osd_sub_op(client.143241.0:143379 3.67 43caff67/rbd_data.32d432913a7a3.00000000000000e0/head//3 [] v 7899'117918 snapset=0=[]:[] snapc=0=[]) v9
   -51> 2014-05-26 09:50:14.853958 7fc8d6ff5700  5 -- op tracker -- , seq: 1222230, time: 2014-05-26 09:50:14.853958, event: started, request: osd_sub_op(client.143241.0:143379 3.67 43caff67/rbd_data.32d432913a7a3.00000000000000e0/head//3 [] v 7899'117918 snapset=0=[]:[] snapc=0=[]) v9
   -50> 2014-05-26 09:50:14.854031 7fc8eaffd700  5 -- op tracker -- , seq: 1222224, time: 2014-05-26 09:50:14.854031, event: journaled_completion_queued, request: osd_sub_op(client.142998.0:106879 3.36 4782a936/rbd_data.289153346db8b.00000000000000d2/head//3 [] v 7899'198539 snapset=0=[]:[] snapc=0=[]) v9
   -49> 2014-05-26 09:50:14.854048 7fc8e3fff700  5 -- op tracker -- , seq: 1222224, time: 2014-05-26 09:50:14.854048, event: commit_sent, request: osd_sub_op(client.142998.0:106879 3.36 4782a936/rbd_data.289153346db8b.00000000000000d2/head//3 [] v 7899'198539 snapset=0=[]:[] snapc=0=[]) v9
   -48> 2014-05-26 09:50:14.854070 7fc8e3fff700  1 -- 172.16.128.36:6801/22825 --> osd.5 172.16.128.31:6801/637 -- osd_sub_op_reply(client.142998.0:106879 3.36 4782a936/rbd_data.289153346db8b.00000000000000d2/head//3 [] ondisk, result = 0) v2 -- ?+0 0x7fc7100134c0
   -47> 2014-05-26 09:50:14.854086 7fc8eb7fe700  5 -- op tracker -- , seq: 1222153, time: 2014-05-26 09:50:14.854085, event: write_thread_in_journal_buffer, request: osd_sub_op(client.153793.0:488591 3.9 fcf66089/rbd_data.2992641f122bd.0000000000000427/head//3 [] v 7899'179827 snapset=0=[]:[] snapc=0=[]) v9
   -46> 2014-05-26 09:50:14.854142 7fc8eb7fe700  5 -- op tracker -- , seq: 1222256, time: 2014-05-26 09:50:14.854142, event: write_thread_in_journal_buffer, request: osd_sub_op(client.142944.0:209800 3.16 5f849196/rbd_data.270827459abfd.0000000000000042/head//3 [] v 7899'108013 snapset=0=[]:[] snapc=0=[]) v9
   -45> 2014-05-26 09:50:14.854176 7fc8d6ff5700  5 -- op tracker -- , seq: 1222230, time: 2014-05-26 09:50:14.854144, event: started, request: osd_sub_op(client.143241.0:143379 3.67 43caff67/rbd_data.32d432913a7a3.00000000000000e0/head//3 [] v 7899'117918 snapset=0=[]:[] snapc=0=[]) v9
   -44> 2014-05-26 09:50:14.854202 7fc8d6ff5700  2 filestore(/var/lib/ceph/osd/ceph-0) waiting 51 > 50 ops || 4598161 > 104857600
   -43> 2014-05-26 09:50:14.854199 7fc8eb7fe700  5 -- op tracker -- , seq: 1222165, time: 2014-05-26 09:50:14.854184, event: write_thread_in_journal_buffer, request: osd_sub_op(client.207743.0:153575 3.26 17e00226/rbd_data.32f4d3083f808.0000000000000125/head//3 [] v 7899'88754 snapset=0=[]:[] snapc=0=[]) v9
   -42> 2014-05-26 09:50:14.854431 7fc8e97fa700  0 xfsfilestorebackend(/var/lib/ceph/osd/ceph-0) set_extsize: FSSETXATTR: (22) Invalid argument
   -41> 2014-05-26 09:50:14.854696 7fc8e9ffb700  0 xfsfilestorebackend(/var/lib/ceph/osd/ceph-0) set_extsize: FSSETXATTR: (22) Invalid argument
   -40> 2014-05-26 09:50:14.854734 7fc8e8ff9700  5 -- op tracker -- , seq: 1222130, time: 2014-05-26 09:50:14.854734, event: sub_op_applied, request: osd_sub_op(client.229847.0:770798 3.5f 73c279df/rbd_data.38b33698779de.0000000000000157/head//3 [] v 7899'19413 snapset=0=[]:[] snapc=0=[]) v9
   -39> 2014-05-26 09:50:14.854776 7fc8e8ff9700  5 -- op tracker -- , seq: 1222130, time: 2014-05-26 09:50:14.854776, event: done, request: osd_sub_op(client.229847.0:770798 3.5f 73c279df/rbd_data.38b33698779de.0000000000000157/head//3 [] v 7899'19413 snapset=0=[]:[] snapc=0=[]) v9
   -38> 2014-05-26 09:50:14.854787 7fc8d6ff5700  5 -- op tracker -- , seq: 1222230, time: 2014-05-26 09:50:14.854787, event: commit_queued_for_journal_write, request: osd_sub_op(client.143241.0:143379 3.67 43caff67/rbd_data.32d432913a7a3.00000000000000e0/head//3 [] v 7899'117918 snapset=0=[]:[] snapc=0=[]) v9
   -37> 2014-05-26 09:50:14.854846 7fc8d6ff5700  5 -- op tracker -- , seq: 1222206, time: 2014-05-26 09:50:14.854846, event: reached_pg, request: osd_sub_op(client.143149.0:140971 3.6c a595f96c/rbd_data.3992837b908ce.0000000000000001/head//3 [] v 7899'15367 snapset=0=[]:[] snapc=0=[]) v9
   -36> 2014-05-26 09:50:14.854862 7fc8d6ff5700  5 -- op tracker -- , seq: 1222206, time: 2014-05-26 09:50:14.854862, event: started, request: osd_sub_op(client.143149.0:140971 3.6c a595f96c/rbd_data.3992837b908ce.0000000000000001/head//3 [] v 7899'15367 snapset=0=[]:[] snapc=0=[]) v9
   -35> 2014-05-26 09:50:14.854986 7fc8d6ff5700  5 -- op tracker -- , seq: 1222206, time: 2014-05-26 09:50:14.854986, event: started, request: osd_sub_op(client.143149.0:140971 3.6c a595f96c/rbd_data.3992837b908ce.0000000000000001/head//3 [] v 7899'15367 snapset=0=[]:[] snapc=0=[]) v9
   -34> 2014-05-26 09:50:14.855015 7fc8d6ff5700  2 filestore(/var/lib/ceph/osd/ceph-0) waiting 51 > 50 ops || 4597961 > 104857600
   -33> 2014-05-26 09:50:14.855134 7fc8e8ff9700  5 -- op tracker -- , seq: 1222199, time: 2014-05-26 09:50:14.855134, event: sub_op_applied, request: osd_sub_op(client.239894.0:80430 3.37 e758fc37/rbd_data.3a8c857389a05.000000000000021c/head//3 [] v 7899'21698 snapset=0=[]:[] snapc=0=[]) v9
   -32> 2014-05-26 09:50:14.855150 7fc8d6ff5700  5 -- op tracker -- , seq: 1222206, time: 2014-05-26 09:50:14.855150, event: commit_queued_for_journal_write, request: osd_sub_op(client.143149.0:140971 3.6c a595f96c/rbd_data.3992837b908ce.0000000000000001/head//3 [] v 7899'15367 snapset=0=[]:[] snapc=0=[]) v9
   -31> 2014-05-26 09:50:14.855181 7fc8e8ff9700  5 -- op tracker -- , seq: 1222199, time: 2014-05-26 09:50:14.855175, event: done, request: osd_sub_op(client.239894.0:80430 3.37 e758fc37/rbd_data.3a8c857389a05.000000000000021c/head//3 [] v 7899'21698 snapset=0=[]:[] snapc=0=[]) v9
   -30> 2014-05-26 09:50:14.855224 7fc8d6ff5700  5 -- op tracker -- , seq: 1222219, time: 2014-05-26 09:50:14.855201, event: reached_pg, request: osd_sub_op(client.157357.0:243217 3.3c 637643c/rbd_data.2bbf42620642.0000000000000200/head//3 [] v 7899'18491 snapset=0=[]:[] snapc=0=[]) v9
   -29> 2014-05-26 09:50:14.855247 7fc8d6ff5700  5 -- op tracker -- , seq: 1222219, time: 2014-05-26 09:50:14.855247, event: started, request: osd_sub_op(client.157357.0:243217 3.3c 637643c/rbd_data.2bbf42620642.0000000000000200/head//3 [] v 7899'18491 snapset=0=[]:[] snapc=0=[]) v9
   -28> 2014-05-26 09:50:14.855307 7fc8e97fa700  0 xfsfilestorebackend(/var/lib/ceph/osd/ceph-0) set_extsize: FSSETXATTR: (22) Invalid argument
   -27> 2014-05-26 09:50:14.855415 7fc8d6ff5700  5 -- op tracker -- , seq: 1222219, time: 2014-05-26 09:50:14.855415, event: started, request: osd_sub_op(client.157357.0:243217 3.3c 637643c/rbd_data.2bbf42620642.0000000000000200/head//3 [] v 7899'18491 snapset=0=[]:[] snapc=0=[]) v9
   -26> 2014-05-26 09:50:14.855433 7fc8d6ff5700  2 filestore(/var/lib/ceph/osd/ceph-0) waiting 51 > 50 ops || 4599976 > 104857600
   -25> 2014-05-26 09:50:14.855690 7fc8e8ff9700  5 -- op tracker -- , seq: 1222111, time: 2014-05-26 09:50:14.855690, event: sub_op_applied, request: osd_sub_op(client.206906.0:148849 3.56 a677b2d6/rbd_data.32b4b6a5e026e.0000000000000120/head//3 [] v 7899'10110 snapset=0=[]:[] snapc=0=[]) v9
   -24> 2014-05-26 09:50:14.855721 7fc8d6ff5700  5 -- op tracker -- , seq: 1222219, time: 2014-05-26 09:50:14.855695, event: commit_queued_for_journal_write, request: osd_sub_op(client.157357.0:243217 3.3c 637643c/rbd_data.2bbf42620642.0000000000000200/head//3 [] v 7899'18491 snapset=0=[]:[] snapc=0=[]) v9
   -23> 2014-05-26 09:50:14.855780 7fc8d6ff5700  5 -- op tracker -- , seq: 1222225, time: 2014-05-26 09:50:14.855780, event: reached_pg, request: osd_sub_op(client.5199.0:70552 3.62 91319462/rbd_data.2026f36be830c.00000000000000a0/head//3 [] v 7899'140681 snapset=0=[]:[] snapc=0=[]) v9
   -22> 2014-05-26 09:50:14.855798 7fc8d6ff5700  5 -- op tracker -- , seq: 1222225, time: 2014-05-26 09:50:14.855798, event: started, request: osd_sub_op(client.5199.0:70552 3.62 91319462/rbd_data.2026f36be830c.00000000000000a0/head//3 [] v 7899'140681 snapset=0=[]:[] snapc=0=[]) v9
   -21> 2014-05-26 09:50:14.855821 7fc8e9ffb700  0 xfsfilestorebackend(/var/lib/ceph/osd/ceph-0) set_extsize: FSSETXATTR: (22) Invalid argument
   -20> 2014-05-26 09:50:14.855868 7fc8eaffd700  5 -- op tracker -- , seq: 1222153, time: 2014-05-26 09:50:14.855868, event: journaled_completion_queued, request: osd_sub_op(client.153793.0:488591 3.9 fcf66089/rbd_data.2992641f122bd.0000000000000427/head//3 [] v 7899'179827 snapset=0=[]:[] snapc=0=[]) v9
   -19> 2014-05-26 09:50:14.855889 7fc8e3fff700  5 -- op tracker -- , seq: 1222153, time: 2014-05-26 09:50:14.855889, event: commit_sent, request: osd_sub_op(client.153793.0:488591 3.9 fcf66089/rbd_data.2992641f122bd.0000000000000427/head//3 [] v 7899'179827 snapset=0=[]:[] snapc=0=[]) v9
   -18> 2014-05-26 09:50:14.855910 7fc8eaffd700  5 -- op tracker -- , seq: 1222256, time: 2014-05-26 09:50:14.855894, event: journaled_completion_queued, request: osd_sub_op(client.142944.0:209800 3.16 5f849196/rbd_data.270827459abfd.0000000000000042/head//3 [] v 7899'108013 snapset=0=[]:[] snapc=0=[]) v9
   -17> 2014-05-26 09:50:14.855931 7fc8eaffd700  5 -- op tracker -- , seq: 1222165, time: 2014-05-26 09:50:14.855930, event: journaled_completion_queued, request: osd_sub_op(client.207743.0:153575 3.26 17e00226/rbd_data.32f4d3083f808.0000000000000125/head//3 [] v 7899'88754 snapset=0=[]:[] snapc=0=[]) v9
   -16> 2014-05-26 09:50:14.855927 7fc8e3fff700  1 -- 172.16.128.36:6801/22825 --> osd.6 172.16.128.39:6809/27164 -- osd_sub_op_reply(client.153793.0:488591 3.9 fcf66089/rbd_data.2992641f122bd.0000000000000427/head//3 [] ondisk, result = 0) v2 -- ?+0 0x7fc71001a470
   -15> 2014-05-26 09:50:14.855978 7fc8e3fff700  5 -- op tracker -- , seq: 1222256, time: 2014-05-26 09:50:14.855978, event: commit_sent, request: osd_sub_op(client.142944.0:209800 3.16 5f849196/rbd_data.270827459abfd.0000000000000042/head//3 [] v 7899'108013 snapset=0=[]:[] snapc=0=[]) v9
   -14> 2014-05-26 09:50:14.855997 7fc8d6ff5700  5 -- op tracker -- , seq: 1222225, time: 2014-05-26 09:50:14.855987, event: started, request: osd_sub_op(client.5199.0:70552 3.62 91319462/rbd_data.2026f36be830c.00000000000000a0/head//3 [] v 7899'140681 snapset=0=[]:[] snapc=0=[]) v9
   -13> 2014-05-26 09:50:14.856016 7fc8e3fff700  1 -- 172.16.128.36:6801/22825 --> osd.9 172.16.128.33:6810/1031764 -- osd_sub_op_reply(client.142944.0:209800 3.16 5f849196/rbd_data.270827459abfd.0000000000000042/head//3 [] ondisk, result = 0) v2 -- ?+0 0x7fc710011960
   -12> 2014-05-26 09:50:14.856032 7fc8eb7fe700  5 -- op tracker -- , seq: 1222230, time: 2014-05-26 09:50:14.856012, event: write_thread_in_journal_buffer, request: osd_sub_op(client.143241.0:143379 3.67 43caff67/rbd_data.32d432913a7a3.00000000000000e0/head//3 [] v 7899'117918 snapset=0=[]:[] snapc=0=[]) v9
   -11> 2014-05-26 09:50:14.856070 7fc8e3fff700  5 -- op tracker -- , seq: 1222165, time: 2014-05-26 09:50:14.856035, event: commit_sent, request: osd_sub_op(client.207743.0:153575 3.26 17e00226/rbd_data.32f4d3083f808.0000000000000125/head//3 [] v 7899'88754 snapset=0=[]:[] snapc=0=[]) v9
   -10> 2014-05-26 09:50:14.856079 7fc8d6ff5700  2 filestore(/var/lib/ceph/osd/ceph-0) waiting 51 > 50 ops || 4601517 > 104857600
    -9> 2014-05-26 09:50:14.856102 7fc8e3fff700  1 -- 172.16.128.36:6801/22825 --> osd.15 172.16.128.35:6811/10008850 -- osd_sub_op_reply(client.207743.0:153575 3.26 17e00226/rbd_data.32f4d3083f808.0000000000000125/head//3 [] ondisk, result = 0) v2 -- ?+0 0x7fc710067b80
    -8> 2014-05-26 09:50:14.856104 7fc8eb7fe700  5 -- op tracker -- , seq: 1222206, time: 2014-05-26 09:50:14.856086, event: write_thread_in_journal_buffer, request: osd_sub_op(client.143149.0:140971 3.6c a595f96c/rbd_data.3992837b908ce.0000000000000001/head//3 [] v 7899'15367 snapset=0=[]:[] snapc=0=[]) v9
    -7> 2014-05-26 09:50:14.856154 7fc8eb7fe700  5 -- op tracker -- , seq: 1222219, time: 2014-05-26 09:50:14.856154, event: write_thread_in_journal_buffer, request: osd_sub_op(client.157357.0:243217 3.3c 637643c/rbd_data.2bbf42620642.0000000000000200/head//3 [] v 7899'18491 snapset=0=[]:[] snapc=0=[]) v9
    -6> 2014-05-26 09:50:14.856249 7fc8e8ff9700  5 -- op tracker -- , seq: 1222111, time: 2014-05-26 09:50:14.856249, event: done, request: osd_sub_op(client.206906.0:148849 3.56 a677b2d6/rbd_data.32b4b6a5e026e.0000000000000120/head//3 [] v 7899'10110 snapset=0=[]:[] snapc=0=[]) v9
    -5> 2014-05-26 09:50:14.856272 7fc8d6ff5700  5 -- op tracker -- , seq: 1222225, time: 2014-05-26 09:50:14.856272, event: commit_queued_for_journal_write, request: osd_sub_op(client.5199.0:70552 3.62 91319462/rbd_data.2026f36be830c.00000000000000a0/head//3 [] v 7899'140681 snapset=0=[]:[] snapc=0=[]) v9
    -4> 2014-05-26 09:50:14.856315 7fc8d6ff5700  5 -- op tracker -- , seq: 1222172, time: 2014-05-26 09:50:14.856315, event: reached_pg, request: osd_sub_op(client.143259.0:154379 3.8 34f9b08/rbd_data.3310f751e7e75.000000000000001b/head//3 [] v 7899'10567 snapset=0=[]:[] snapc=0=[]) v9
    -3> 2014-05-26 09:50:14.856330 7fc8d6ff5700  5 -- op tracker -- , seq: 1222172, time: 2014-05-26 09:50:14.856330, event: started, request: osd_sub_op(client.143259.0:154379 3.8 34f9b08/rbd_data.3310f751e7e75.000000000000001b/head//3 [] v 7899'10567 snapset=0=[]:[] snapc=0=[]) v9
    -2> 2014-05-26 09:50:14.856342 7fc8e8ff9700  5 -- op tracker -- , seq: 1222106, time: 2014-05-26 09:50:14.856333, event: sub_op_applied, request: osd_sub_op(client.207743.0:153572 3.43 8728b643/rbd_data.32f4d3083f808.0000000000000124/head//3 [] v 7899'140172 snapset=0=[]:[] snapc=0=[]) v9
    -1> 2014-05-26 09:50:14.856399 7fc8e8ff9700  5 -- op tracker -- , seq: 1222106, time: 2014-05-26 09:50:14.856399, event: done, request: osd_sub_op(client.207743.0:153572 3.43 8728b643/rbd_data.32f4d3083f808.0000000000000124/head//3 [] v 7899'140172 snapset=0=[]:[] snapc=0=[]) v9
     0> 2014-05-26 09:50:14.856385 7fc8d77f6700 -1 *** Caught signal (Aborted) **
 in thread 7fc8d77f6700

 ceph version 0.78 (f6c746c314d7b87b8419b6e584c94bfe4511dbd4)
 1: /usr/bin/ceph-osd() [0xa884dd]
 2: (()+0x10b10) [0x7fc900ea7b10]
 3: (gsignal()+0x35) [0x7fc8ff329535]
 4: (abort()+0x148) [0x7fc8ff32a9b8]
 5: (__gnu_cxx::__verbose_terminate_handler()+0x11d) [0x7fc8ffc1596d]
 6: (()+0x63a66) [0x7fc8ffc13a66]
 7: (()+0x63a93) [0x7fc8ffc13a93]
 8: (()+0x63cbe) [0x7fc8ffc13cbe]
 9: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x42a) [0xb5d13a]
 10: (PG::RecoveryState::Crashed::Crashed(boost::statechart::state<PG::RecoveryState::Crashed, PG::RecoveryState::RecoveryMachine, boost::mpl::list<mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na>, (boost::statechart::history_mode)0>::my_context)+0x12f) [0x8e8aef]
 11: /usr/bin/ceph-osd() [0x918de9]
 12: (boost::statechart::detail::reaction_result boost::statechart::simple_state<PG::RecoveryState::Started, PG::RecoveryState::RecoveryMachine, PG::RecoveryState::Start, (boost::statechart::history_mode)0>::local_react_impl_non_empty::local_react_impl<boost::mpl::list2<boost::statechart::custom_reaction<PG::FlushedEvt>, boost::statechart::transition<boost::statechart::event_base, PG::RecoveryState::Crashed, boost::statechart::detail::no_context<boost::statechart::event_base>, &boost::statechart::detail::no_context<boost::statechart::event_base>::no_function> >, boost::statechart::simple_state<PG::RecoveryState::Started, PG::RecoveryState::RecoveryMachine, PG::RecoveryState::Start, (boost::statechart::history_mode)0> >(boost::statechart::simple_state<PG::RecoveryState::Started, PG::RecoveryState::RecoveryMachine, PG::RecoveryState::Start, (boost::statechart::history_mode)0>&, boost::statechart::event_base const&, void const*)+0xbf) [0x943b5f]
 13: (boost::statechart::detail::reaction_result boost::statechart::simple_state<PG::RecoveryState::Started, PG::RecoveryState::RecoveryMachine, PG::RecoveryState::Start, (boost::statechart::history_mode)0>::local_react_impl_non_empty::local_react_impl<boost::mpl::list4<boost::statechart::custom_reaction<PG::AdvMap>, boost::statechart::custom_reaction<PG::NullEvt>, boost::statechart::custom_reaction<PG::FlushedEvt>, boost::statechart::transition<boost::statechart::event_base, PG::RecoveryState::Crashed, boost::statechart::detail::no_context<boost::statechart::event_base>, &boost::statechart::detail::no_context<boost::statechart::event_base>::no_function> >, boost::statechart::simple_state<PG::RecoveryState::Started, PG::RecoveryState::RecoveryMachine, PG::RecoveryState::Start, (boost::statechart::history_mode)0> >(boost::statechart::simple_state<PG::RecoveryState::Started, PG::RecoveryState::RecoveryMachine, PG::RecoveryState::Start, (boost::statechart::history_mode)0>&, boost::statechart::event_base const&, void const*)+0x57) [0x943ce7]
 14: (boost::statechart::detail::reaction_result boost::statechart::simple_state<PG::RecoveryState::Started, PG::RecoveryState::RecoveryMachine, PG::RecoveryState::Start, (boost::statechart::history_mode)0>::local_react_impl_non_empty::local_react_impl<boost::mpl::list<boost::statechart::custom_reaction<PG::QueryState>, boost::statechart::custom_reaction<PG::AdvMap>, boost::statechart::custom_reaction<PG::NullEvt>, boost::statechart::custom_reaction<PG::FlushedEvt>, boost::statechart::transition<boost::statechart::event_base, PG::RecoveryState::Crashed, boost::statechart::detail::no_context<boost::statechart::event_base>, &boost::statechart::detail::no_context<boost::statechart::event_base>::no_function>, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na>, boost::statechart::simple_state<PG::RecoveryState::Started, PG::RecoveryState::RecoveryMachine, PG::RecoveryState::Start, (boost::statechart::history_mode)0> >(boost::statechart::simple_state<PG::RecoveryState::Started, PG::RecoveryState::RecoveryMachine, PG::RecoveryState::Start, (boost::statechart::history_mode)0>&, boost::statechart::event_base const&, void const*)+0x57) [0x943d97]
 15: (boost::statechart::state_machine<PG::RecoveryState::RecoveryMachine, PG::RecoveryState::Initial, std::allocator<void>, boost::statechart::null_exception_translator>::send_event(boost::statechart::event_base const&)+0x5b) [0x926c1b]
 16: (boost::statechart::state_machine<PG::RecoveryState::RecoveryMachine, PG::RecoveryState::Initial, std::allocator<void>, boost::statechart::null_exception_translator>::process_event(boost::statechart::event_base const&)+0x19) [0x926ca9]
 17: (PG::RecoveryState::handle_event(std::tr1::shared_ptr<PG::CephPeeringEvt>, PG::RecoveryCtx*)+0x31) [0x926d41]
 18: (PG::handle_peering_event(std::tr1::shared_ptr<PG::CephPeeringEvt>, PG::RecoveryCtx*)+0x338) [0x8dedd8]
 19: (OSD::process_peering_events(std::list<PG*, std::allocator<PG*> > const&, ThreadPool::TPHandle&)+0x400) [0x761110]
 20: (OSD::PeeringWQ::_process(std::list<PG*, std::allocator<PG*> > const&, ThreadPool::TPHandle&)+0x14) [0x7be7c4]
 21: (ThreadPool::worker(ThreadPool::WorkThread*)+0x68c) [0xb4ee1c]
 22: (ThreadPool::WorkThread::entry()+0x10) [0xb50070]
 23: (()+0x8f3a) [0x7fc900e9ff3a]
 24: (clone()+0x6d) [0x7fc8ff3dedad]
 NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

--- logging levels ---
   0/ 5 none
   0/ 1 lockdep
   0/ 1 context
   1/ 1 crush
   1/ 5 mds
   1/ 5 mds_balancer
   1/ 5 mds_locker
   1/ 5 mds_log
   1/ 5 mds_log_expire
   1/ 5 mds_migrator
   0/ 1 buffer
   0/ 1 timer
   0/ 1 filer
   0/ 1 striper
   0/ 1 objecter
   0/ 5 rados
   0/ 5 rbd
   0/ 5 journaler
   0/ 5 objectcacher
   0/ 5 client
   0/ 5 osd
   0/ 5 optracker
   0/ 5 objclass
   1/ 3 filestore
   1/ 3 keyvaluestore
   1/ 3 journal
   0/ 5 ms
   1/ 5 mon
   0/10 monc
   1/ 5 paxos
   0/ 5 tp
   1/ 5 auth
   1/ 5 crypto
   1/ 1 finisher
   1/ 5 heartbeatmap
   1/ 5 perfcounter
   1/ 5 rgw
   1/ 5 javaclient
   1/ 5 asok
   1/ 1 throttle
  -2/-2 (syslog threshold)
  -1/-1 (stderr threshold)
  max_recent     10000
  max_new         1000
  log_file /var/log/ceph/ceph-osd.0.log
--- end dump of recent events ---
2014-05-26 09:50:14.856801 7fc8e9ffb700  0 xfsfilestorebackend(/var/lib/ceph/osd/ceph-0) set_extsize: FSSETXATTR: (22) Invalid argument
2014-05-26 09:50:14.857217 7fc8e97fa700  0 xfsfilestorebackend(/var/lib/ceph/osd/ceph-0) set_extsize: FSSETXATTR: (22) Invalid argument
2014-05-26 09:50:14.859191 7fc8e9ffb700  0 xfsfilestorebackend(/var/lib/ceph/osd/ceph-0) set_extsize: FSSETXATTR: (22) Invalid argument
2014-05-26 09:50:14.860063 7fc8e97fa700  0 xfsfilestorebackend(/var/lib/ceph/osd/ceph-0) set_extsize: FSSETXATTR: (22) Invalid argument
2014-05-26 09:50:14.860219 7fc8e9ffb700  0 xfsfilestorebackend(/var/lib/ceph/osd/ceph-0) set_extsize: FSSETXATTR: (22) Invalid argument
2014-05-26 09:50:14.861188 7fc8e9ffb700  0 xfsfilestorebackend(/var/lib/ceph/osd/ceph-0) set_extsize: FSSETXATTR: (22) Invalid argument
2014-05-26 09:50:14.861881 7fc8e9ffb700  0 xfsfilestorebackend(/var/lib/ceph/osd/ceph-0) set_extsize: FSSETXATTR: (22) Invalid argument

ceph-osd (10.1 MB) Pierre Grandin, 05/26/2014 05:24 PM

History

#1 Updated by Pierre Grandin over 5 years ago

Adding my ceph.conf:

[global]
    fsid = 694ec86e-c121-42dd-97ee-807cb834d8e7
    auth_cluster_required = none
    auth_service_required = none
    auth_client_required = none
    filestore_xattr_use_omap = true
    cluster network = 172.16.128.0/22
    public network = 172.16.128.0/22
[mon.cn01a]
    host = cn01a
    mon addr = 172.16.128.38:6789
    mon data = /var/lib/ceph/mon/ceph-cn01a
[mon.cn02a]
    host = cn02a
    mon addr = 172.16.128.34:6789
    mon data = /var/lib/ceph/mon/ceph-cn01b
[mon.cn03a]
    host = cn03a
    mon addr = 172.16.128.40:6789
    mon data = /var/lib/ceph/mon/ceph-cn02a
[osd]
    osd mkfs type = xfs
    osd data = /var/lib/ceph/osd/ceph-$id
    devs = /dev/fioa1
[osd.0]
    host = cn01a
    osd addr = 172.16.128.38:6789
[osd.1]
    host = cn02a
    osd addr = 172.16.128.34:6789
[osd.2]
    host = cn03a
    osd addr = 172.16.128.40:6789
[osd.3]
    host = cn04a
    osd addr = 172.16.128.37:6789

#2 Updated by Pierre Grandin over 5 years ago

As noticed by Vacuity on IRC, it's possibly a dup of #8241

#3 Updated by Sage Weil over 5 years ago

  • Status changed from New to Need More Info
  • Source changed from other to Community (user)

Can you try upgrading to 0.80 and see if this is still present? There were so many things fixed between 78 and 80 it is hard to say if this is one of them.

#4 Updated by Sage Weil about 5 years ago

  • Project changed from rbd to Ceph
  • Status changed from Need More Info to Won't Fix

see 0.80.x

#5 Updated by Sheldon Mustard about 4 years ago

  • Regression set to No

Having some sporadic osd crashes with pretty much the same stack traces with 0.80.7.

2015-06-21 08:43:52.362567 7ff9d27d4700 -1 osd/PG.cc: In function 'PG::RecoveryState::Crashed::Crashed(boost::statechart::stat
e<PG::RecoveryState::Crashed, PG::RecoveryState::RecoveryMachine>::my_context)' thread 7ff9d27d4700 time 2015-06-21 08:43:52.3
38680
osd/PG.cc: 5424: FAILED assert(0 == "we got a bad state machine event")

ceph version 0.80.7 (6c0127fcb58008793d3c8b62d925bc91963672a3)
1: (PG::RecoveryState::Crashed::Crashed(boost::statechart::state&lt;PG::RecoveryState::Crashed, PG::RecoveryState::RecoveryMachi
ne, boost::mpl::list&lt;mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_:
:na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na>, (boost::statechart::history_mo
de)0>::my_context)+0x11b) [0x74dc5b]
2: /usr/bin/ceph-osd() [0x77b8f6]
3: (boost::statechart::simple_state&lt;PG::RecoveryState::Started, PG::RecoveryState::RecoveryMachine, PG::RecoveryState::Start,
(boost::statechart::history_mode)0>::react_impl(boost::statechart::event_base const&, void const*)+0x119) [0x7a7079]
4: (boost::statechart::simple_state&lt;PG::RecoveryState::ReplicaActive, PG::RecoveryState::Started, PG::RecoveryState::RepNotRe
covering, (boost::statechart::history_mode)0>::react_impl(boost::statechart::event_base const&, void const*)+0x171) [0x7a4911]
5: (boost::statechart::simple_state&lt;PG::RecoveryState::RepRecovering, PG::RecoveryState::ReplicaActive, boost::mpl::list&lt;mpl_
::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na,
mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na>, (boost::statechart::history_mode)0>::react_impl(boost::
statechart::event_base const&, void const*)+0xd0) [0x79a4d0]
6: (boost::statechart::state_machine&lt;PG::RecoveryState::RecoveryMachine, PG::RecoveryState::Initial, std::allocator&lt;void&gt;, bo
ost::statechart::null_exception_translator>::send_event(boost::statechart::event_base const&)+0x6b) [0x78f94b]
7: (PG::handle_peering_event(std::tr1::shared_ptr&lt;PG::CephPeeringEvt&gt;, PG::RecoveryCtx*)+0x1df) [0x73cbcf]
8: (OSD::process_peering_events(std::list&lt;PG*, std::allocator&lt;PG*&gt; > const&, ThreadPool::TPHandle&)+0x2a4) [0x64a8f4]
9: (OSD::PeeringWQ::_process(std::list&lt;PG*, std::allocator&lt;PG*&gt; > const&, ThreadPool::TPHandle&)+0x28) [0x6941d8]
10: (ThreadPool::worker(ThreadPool::WorkThread*)+0xb10) [0xa77cb0]
11: (ThreadPool::WorkThread::entry()+0x10) [0xa78ba0]
12: (()+0x7df3) [0x7ff9e9bd0df3]
13: (clone()+0x6d) [0x7ff9e88bb3dd]
NOTE: a copy of the executable, or `objdump -rdS &lt;executable&gt;` is needed to interpret this.

--- begin dump of recent events ---
-10000> 2015-06-20 18:55:59.749191 7ff9e63ef700 1 do_command 'config get' 'format:json var:fsid result is 47 bytes

Also available in: Atom PDF