Ceph

   -29> 2015-09-20 19:08:35.311352 7fa3d96df700  1 -- 10.214.130.6:0/18965 <== osd.2 10.214.130.50:6808/17990 6 ==== osd_op_reply(6 image38.rbd [copy-get max 8388608] v0'0 uv0 ondisk = -2 ((2) No such file or directory)) v6 ==== 178+0+103 (649317446 0 1324605519) 0x7fa408d383c0 con 0x7fa407c8c260
   -28> 2015-09-20 19:08:35.311395 7fa3dee0c700 10 osd.0 pg_epoch: 116 pg[29.0( v 114'5 (0'0,114'5] local-les=110 n=2 ec=109 les/c 110/110 109/109/109) [0,1] r=0 lpr=109 crt=112'3 lcod 113'4 mlcod 113'4 active+clean NIBBLEWISE] process_copy_chunk 29/27aa9d90/image38.rbd/head tid 6 (2) No such file or directory
   -27> 2015-09-20 19:08:35.311414 7fa3dee0c700 20 osd.0 pg_epoch: 116 pg[29.0( v 114'5 (0'0,114'5] local-les=110 n=2 ec=109 les/c 110/110 109/109/109) [0,1] r=0 lpr=109 crt=112'3 lcod 113'4 mlcod 113'4 active+clean NIBBLEWISE] process_copy_chunk complete r = (2) No such file or directory
   -26> 2015-09-20 19:08:35.311423 7fa3dee0c700 10 osd.0 pg_epoch: 116 pg[29.0( v 114'5 (0'0,114'5] local-les=110 n=2 ec=109 les/c 110/110 109/109/109) [0,1] r=0 lpr=109 crt=112'3 lcod 113'4 mlcod 113'4 active+clean NIBBLEWISE] finish_promote 29/27aa9d90/image38.rbd/head r=-2 uv0
   -25> 2015-09-20 19:08:35.311430 7fa3dee0c700 10 osd.0 pg_epoch: 116 pg[29.0( v 114'5 (0'0,114'5] local-les=110 n=2 ec=109 les/c 110/110 109/109/109) [0,1] r=0 lpr=109 crt=112'3 lcod 113'4 mlcod 113'4 active+clean NIBBLEWISE] finish_promote whiteout 29/27aa9d90/image38.rbd/head
   -24> 2015-09-20 19:08:35.311437 7fa3dee0c700 20 osd.0 pg_epoch: 116 pg[29.0( v 114'5 (0'0,114'5] local-les=110 n=2 ec=109 les/c 110/110 109/109/109) [0,1] r=0 lpr=109 crt=112'3 lcod 113'4 mlcod 113'4 active+clean NIBBLEWISE] simple_repop_create 29/27aa9d90/image38.rbd/head
   -23> 2015-09-20 19:08:35.311451 7fa3dee0c700 10 osd.0 pg_epoch: 116 pg[29.0( v 114'5 (0'0,114'5] local-les=110 n=2 ec=109 les/c 110/110 109/109/109) [0,1] r=0 lpr=109 crt=112'3 lcod 113'4 mlcod 113'4 active+clean NIBBLEWISE] new_repop rep_tid 3420 (no op)
   -22> 2015-09-20 19:08:35.311465 7fa3dee0c700 20 osd.0 pg_epoch: 116 pg[29.0( v 114'5 (0'0,114'5] local-les=110 n=2 ec=109 les/c 110/110 109/109/109) [0,1] r=0 lpr=109 crt=112'3 lcod 113'4 mlcod 113'4 active+clean NIBBLEWISE] finish_promote creating whiteout on 29/27aa9d90/image38.rbd/head
   -21> 2015-09-20 19:08:35.311473 7fa3dee0c700 20 osd.0 pg_epoch: 116 pg[29.0( v 114'5 (0'0,114'5] local-les=110 n=2 ec=109 les/c 110/110 109/109/109) [0,1] r=0 lpr=109 crt=112'3 lcod 113'4 mlcod 113'4 active+clean NIBBLEWISE] finish_promote new_snapset 0=[]:[]+head
   -20> 2015-09-20 19:08:35.311480 7fa3dee0c700 20 osd.0 pg_epoch: 116 pg[29.0( v 114'5 (0'0,114'5] local-les=110 n=2 ec=109 les/c 110/110 109/109/109) [0,1] r=0 lpr=109 crt=112'3 lcod 113'4 mlcod 113'4 active+clean NIBBLEWISE] finish_promote took lock on obc, rwstate(write n=1 w=0)
   -19> 2015-09-20 19:08:35.311487 7fa3dee0c700 20 osd.0 pg_epoch: 116 pg[29.0( v 114'5 (0'0,114'5] local-les=110 n=2 ec=109 les/c 110/110 109/109/109) [0,1] r=0 lpr=109 crt=112'3 lcod 113'4 mlcod 113'4 active+clean NIBBLEWISE] finish_ctx 29/27aa9d90/image38.rbd/head 0x7fa408cfca00 op promote 
   -18> 2015-09-20 19:08:35.311499 7fa3dee0c700 10 osd.0 pg_epoch: 116 pg[29.0( v 114'5 (0'0,114'5] local-les=110 n=2 ec=109 les/c 110/110 109/109/109) [0,1] r=0 lpr=109 crt=112'3 lcod 113'4 mlcod 113'4 active+clean NIBBLEWISE]  set mtime to 2015-09-20 19:08:35.311450
   -17> 2015-09-20 19:08:35.311515 7fa3dee0c700 10 osd.0 pg_epoch: 116 pg[29.0( v 114'5 (0'0,114'5] local-les=110 n=2 ec=109 les/c 110/110 109/109/109) [0,1] r=0 lpr=109 crt=112'3 lcod 113'4 mlcod 113'4 active+clean NIBBLEWISE]  final snapset 0=[]:[]+head in 29/27aa9d90/image38.rbd/head
   -16> 2015-09-20 19:08:35.311533 7fa3dee0c700 20 osd.0 pg_epoch: 116 pg[29.0( v 114'5 (0'0,114'5] local-les=110 n=3 ec=109 les/c 110/110 109/109/109) [0,1] r=0 lpr=109 crt=112'3 lcod 113'4 mlcod 113'4 active+clean NIBBLEWISE] simple_repop_submit 0x7fa408404100
   -15> 2015-09-20 19:08:35.311541 7fa3dee0c700  7 osd.0 pg_epoch: 116 pg[29.0( v 114'5 (0'0,114'5] local-les=110 n=3 ec=109 les/c 110/110 109/109/109) [0,1] r=0 lpr=109 crt=112'3 lcod 113'4 mlcod 113'4 active+clean NIBBLEWISE] issue_repop rep_tid 3420 o 29/27aa9d90/image38.rbd/head
   -14> 2015-09-20 19:08:35.311569 7fa3dee0c700 20 osd.0 116 share_map_peer 0x7fa407658680 already has epoch 116
   -13> 2015-09-20 19:08:35.311572 7fa3dee0c700  1 -- 10.214.130.6:6810/18965 --> 10.214.130.6:6814/19138 -- osd_repop(osd.0.0:3420 29.0 29/27aa9d90/image38.rbd/head v 116'6) v1 -- ?+597 0x7fa408cfd000 con 0x7fa407658680
   -12> 2015-09-20 19:08:35.311588 7fa3dee0c700 10 osd.0 pg_epoch: 116 pg[29.0( v 114'5 (0'0,114'5] local-les=110 n=3 ec=109 les/c 110/110 109/109/109) [0,1] r=0 lpr=109 crt=112'3 lcod 113'4 mlcod 113'4 active+clean NIBBLEWISE] append_log log((0'0,114'5], crt=112'3) [116'6 (0'0) promote  29/27aa9d90/image38.rbd/hea
d by osd.0.0:3420 2015-09-20 19:08:35.311450]
   -11> 2015-09-20 19:08:35.311603 7fa3dee0c700 10 osd.0 pg_epoch: 116 pg[29.0( v 116'6 (0'0,116'6] local-les=110 n=3 ec=109 les/c 110/110 109/109/109) [0,1] r=0 lpr=109 luod=114'5 lua=114'5 crt=112'3 lcod 113'4 mlcod 113'4 active+clean NIBBLEWISE] add_log_entry 116'6 (0'0) promote  29/27aa9d90/image38.rbd/head by 
osd.0.0:3420 2015-09-20 19:08:35.311450
   -10> 2015-09-20 19:08:35.311617 7fa3dee0c700 10 osd.0 pg_epoch: 116 pg[29.0( v 116'6 (0'0,116'6] local-les=110 n=3 ec=109 les/c 110/110 109/109/109) [0,1] r=0 lpr=109 luod=114'5 lua=114'5 crt=113'4 lcod 113'4 mlcod 113'4 active+clean NIBBLEWISE] append_log: trimming to 113'4 entries 113'4 (0'0) promote  29/f9a5e
528/rbd_data.5e2e228aa145.0000000000000000/head by osd.0.0:3395 2015-09-20 19:08:30.701225
    -9> 2015-09-20 19:08:35.311640 7fa3dee0c700  5 write_log with: dirty_to: 0'0, dirty_from: 4294967295'18446744073709551615, dirty_divergent_priors: false, divergent_priors: 0, writeout_from: 116'6, trimmed: 
    -8> 2015-09-20 19:08:35.311680 7fa3dee0c700  5 filestore(/var/lib/ceph/osd/ceph-0) queue_transactions existing 0x7fa409503540 osr(29.0 0x7fa40602d170)
    -7> 2015-09-20 19:08:35.311690 7fa3dee0c700 10 journal _op_journal_transactions_prepare 0x7fa4085a3340,0x7fa40795df80
    -6> 2015-09-20 19:08:35.311695 7fa3dee0c700 10 journal op_submit_start 13914
    -5> 2015-09-20 19:08:35.311696 7fa3dee0c700  5 filestore(/var/lib/ceph/osd/ceph-0) queue_transactions (writeahead) 13914 0x7fa4085a3340,0x7fa40795df80
    -4> 2015-09-20 19:08:35.311699 7fa3dee0c700 10 journal op_journal_transactions 13914
    -3> 2015-09-20 19:08:35.311700 7fa3dee0c700  5 journal submit_entry seq 13914 len 1948 (0x7fa409564f90)
    -2> 2015-09-20 19:08:35.311703 7fa3dee0c700 10 journal op_submit_finish 13914
    -1> 2015-09-20 19:08:35.311705 7fa3dee0c700 10 osd.0 pg_epoch: 116 pg[29.0( v 116'6 (0'0,116'6] local-les=110 n=3 ec=109 les/c 110/110 109/109/109) [0,1] r=0 lpr=109 luod=114'5 lua=114'5 crt=113'4 lcod 113'4 mlcod 113'4 active+clean NIBBLEWISE] eval_repop repgather(0x7fa408404100 116'6 rep_tid=3420 committed?=0
 applied?=0 lock=0) (no op)
     0> 2015-09-20 19:08:35.314457 7fa3dee0c700 -1 osd/ReplicatedPG.cc: In function 'void ReplicatedPG::finish_promote(int, ReplicatedPG::CopyResults*, ObjectContextRef)' thread 7fa3dee0c700 time 2015-09-20 19:08:35.311723
osd/ReplicatedPG.cc: 7247: FAILED assert(agent_state)

 ceph version 9.0.3-1746-g5e8299f (5e8299f0121d07355aa7eddfe53297504fbcdcfe)
 1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x85) [0x7fa402bde315]
 2: (ReplicatedPG::finish_promote(int, ReplicatedPG::CopyResults*, std::shared_ptr<ObjectContext>)+0x161f) [0x7fa4027f77bf]
 3: (PromoteCallback::finish(boost::tuples::tuple<int, ReplicatedPG::CopyResults*, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type>)+0x50) [0x7fa402857560]
 4: (GenContext<boost::tuples::tuple<int, ReplicatedPG::CopyResults*, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type> >::complete(boost::tuples::tuple<int, 
ReplicatedPG::CopyResults*, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type>)+0x9) [0x7fa40282e5e9]
 5: (ReplicatedPG::process_copy_chunk(hobject_t, unsigned long, int)+0x5ec) [0x7fa4027f4dec]
 6: (C_Copyfrom::finish(int)+0xb1) [0x7fa4028574b1]
 7: (Context::complete(int)+0x9) [0x7fa4026562c9]
 8: (Finisher::finisher_thread_entry()+0x1b0) [0x7fa402b0d8f0]
 9: (()+0x7df3) [0x7fa400c59df3]
 10: (clone()+0x6d) [0x7fa3ff5023dd]
 NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

/a/sage-2015-09-20_18:23:58-upgrade:hammer-x-master---basic-vps/1063331