osd/OSDMap.h: 330: FAILED assert(is_up(osd))

osd/OSDMap.h: 330: FAILED assert(is_up(osd))

[Jim Schutt]

Hi,

Recent master branch is asserting for me like this:

  ceph version 0.48argonaut-404-gabe05a3 (commit:abe05a3fbbb120d8d354623258d9104584db66f7)
  1: (OSDMap::get_cluster_inst(int) const+0xc9) [0x58cde9]
  2: (OSD::handle_osd_ping(MOSDPing*)+0x8cf) [0x5d4b4f]
  3: (OSD::heartbeat_dispatch(Message*)+0x71) [0x5d5491]
  4: (SimpleMessenger::DispatchQueue::entry()+0x583) [0x7d5683]
  5: (SimpleMessenger::dispatch_entry()+0x15) [0x7d6a05]
  6: (SimpleMessenger::DispatchThread::entry()+0xd) [0x7957bd]
  7: (()+0x77f1) [0x7ffff76507f1]
  8: (clone()+0x6d) [0x7ffff6aa1ccd]

gdb had this to say:

(gdb) bt
#0  0x00007ffff765836b in raise (sig=6) at ../nptl/sysdeps/unix/sysv/linux/pt-raise.c:42
#1  0x00000000007245b7 in reraise_fatal (signum=6) at global/signal_handler.cc:58
#2  handle_fatal_signal (signum=6) at global/signal_handler.cc:104
#3  <signal handler called>
#4  0x00007ffff69ee885 in raise (sig=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
#5  0x00007ffff69f0065 in abort () at abort.c:92
#6  0x0000003be84bea7d in __gnu_cxx::__verbose_terminate_handler() () from /usr/lib64/libstdc++.so.6
#7  0x0000003be84bcc06 in ?? () from /usr/lib64/libstdc++.so.6
#8  0x0000003be84bcc33 in std::terminate() () from /usr/lib64/libstdc++.so.6
#9  0x0000003be84bcd2e in __cxa_throw () from /usr/lib64/libstdc++.so.6
#10 0x000000000074b9e3 in ceph::__ceph_assert_fail (assertion=0x1488000 "\001", file=0x2d828a0 "\260m\"\003", line=330, func=0x8701e0 "entity_inst_t OSDMap::get_cluster_inst(int) const") at common/assert.cc:77
#11 0x000000000058cde9 in OSDMap::get_cluster_inst (this=<value optimized out>, osd=<value optimized out>) at osd/OSDMap.h:330
#12 0x00000000005d4b4f in OSD::handle_osd_ping (this=0x14d8000, m=<value optimized out>) at osd/OSD.cc:1717
#13 0x00000000005d5491 in OSD::heartbeat_dispatch (this=0x14d8000, m=0x24383100) at osd/OSD.cc:2784
#14 0x00000000007d5683 in ms_deliver_dispatch (this=0x1472960) at msg/Messenger.h:504
#15 SimpleMessenger::DispatchQueue::entry (this=0x1472960) at msg/SimpleMessenger.cc:367
#16 0x00000000007d6a05 in SimpleMessenger::dispatch_entry (this=0x1472880) at msg/SimpleMessenger.cc:384
#17 0x00000000007957bd in SimpleMessenger::DispatchThread::entry (this=<value optimized out>) at ./msg/SimpleMessenger.h:807
#18 0x00007ffff76507f1 in start_thread (arg=0x7fffe6ec6700) at pthread_create.c:301
#19 0x00007ffff6aa1ccd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115
(gdb) f 12
#12 0x00000000005d4b4f in OSD::handle_osd_ping (this=0x14d8000, m=<value optimized out>) at osd/OSD.cc:1717
1717		  _share_map_outgoing(service.get_osdmap()->get_cluster_inst(from));
(gdb) l
1712	      hbserver_messenger->send_message(r, m->get_connection());
1713	
1714	      if (osdmap->is_up(from)) {
1715		note_peer_epoch(from, m->map_epoch);
1716		if (locked && is_active())
1717		  _share_map_outgoing(service.get_osdmap()->get_cluster_inst(from));
1718	      }
1719	    }
1720	    break;
1721	
(gdb) f 11
#11 0x000000000058cde9 in OSDMap::get_cluster_inst (this=<value optimized out>, osd=<value optimized out>) at osd/OSDMap.h:330
330	    assert(is_up(osd));
(gdb) l
325	  entity_inst_t get_inst(int osd) const {
326	    assert(is_up(osd));
327	    return entity_inst_t(entity_name_t::OSD(osd), get_addr(osd));
328	  }
329	  entity_inst_t get_cluster_inst(int osd) const {
330	    assert(is_up(osd));
331	    return entity_inst_t(entity_name_t::OSD(osd), get_cluster_addr(osd));
332	  }
333	  entity_inst_t get_hb_inst(int osd) const {
334	    assert(is_up(osd));


Apparently osdmap member in class OSD don't have the
same map contents as the osdmap member in OSDService
in this instance?

Why are there two osdmaps?  Under what conditions is it
appropriate for them to have different contents?

Is this the appropriate fix?

@@ -1711,10 +1711,10 @@ void OSD::handle_osd_ping(MOSDPing *m)
  				m->stamp);
        hbserver_messenger->send_message(r, m->get_connection());

-      if (osdmap->is_up(from)) {
+      if (locked && osdmap->is_up(from)) {
  	note_peer_epoch(from, m->map_epoch);
-	if (locked && is_active())
-	  _share_map_outgoing(service.get_osdmap()->get_cluster_inst(from));
+	if (is_active())
+	  _share_map_outgoing(osdmap->get_cluster_inst(from));
        }
      }
      break;


Thanks -- Jim

Re: osd/OSDMap.h: 330: FAILED assert(is_up(osd))

[Samuel Just]

Not quite.  OSDService::get_osdmap() returns the most recently
published osdmap.  Generally, OSD::osdmap is safe to use when you are
holding the osd lock.  Otherwise, OSDService::get_osdmap() should be
used.  There are a few other things that should be fixed surrounding
this issue as well, I'll put some time into it today.  The map_lock
should probably be removed all together.
-Sam

On Tue, Jul 17, 2012 at 1:49 PM, Jim Schutt <jaschut@sandia.gov> wrote:
> Hi,
>
> Recent master branch is asserting for me like this:
>
>  ceph version 0.48argonaut-404-gabe05a3
> (commit:abe05a3fbbb120d8d354623258d9104584db66f7)
>  1: (OSDMap::get_cluster_inst(int) const+0xc9) [0x58cde9]
>  2: (OSD::handle_osd_ping(MOSDPing*)+0x8cf) [0x5d4b4f]
>  3: (OSD::heartbeat_dispatch(Message*)+0x71) [0x5d5491]
>  4: (SimpleMessenger::DispatchQueue::entry()+0x583) [0x7d5683]
>  5: (SimpleMessenger::dispatch_entry()+0x15) [0x7d6a05]
>  6: (SimpleMessenger::DispatchThread::entry()+0xd) [0x7957bd]
>  7: (()+0x77f1) [0x7ffff76507f1]
>  8: (clone()+0x6d) [0x7ffff6aa1ccd]
>
> gdb had this to say:
>
> (gdb) bt
> #0  0x00007ffff765836b in raise (sig=6) at
> ../nptl/sysdeps/unix/sysv/linux/pt-raise.c:42
> #1  0x00000000007245b7 in reraise_fatal (signum=6) at
> global/signal_handler.cc:58
> #2  handle_fatal_signal (signum=6) at global/signal_handler.cc:104
> #3  <signal handler called>
> #4  0x00007ffff69ee885 in raise (sig=6) at
> ../nptl/sysdeps/unix/sysv/linux/raise.c:64
> #5  0x00007ffff69f0065 in abort () at abort.c:92
> #6  0x0000003be84bea7d in __gnu_cxx::__verbose_terminate_handler() () from
> /usr/lib64/libstdc++.so.6
> #7  0x0000003be84bcc06 in ?? () from /usr/lib64/libstdc++.so.6
> #8  0x0000003be84bcc33 in std::terminate() () from /usr/lib64/libstdc++.so.6
> #9  0x0000003be84bcd2e in __cxa_throw () from /usr/lib64/libstdc++.so.6
> #10 0x000000000074b9e3 in ceph::__ceph_assert_fail (assertion=0x1488000
> "\001", file=0x2d828a0 "\260m\"\003", line=330, func=0x8701e0 "entity_inst_t
> OSDMap::get_cluster_inst(int) const") at common/assert.cc:77
> #11 0x000000000058cde9 in OSDMap::get_cluster_inst (this=<value optimized
> out>, osd=<value optimized out>) at osd/OSDMap.h:330
> #12 0x00000000005d4b4f in OSD::handle_osd_ping (this=0x14d8000, m=<value
> optimized out>) at osd/OSD.cc:1717
> #13 0x00000000005d5491 in OSD::heartbeat_dispatch (this=0x14d8000,
> m=0x24383100) at osd/OSD.cc:2784
> #14 0x00000000007d5683 in ms_deliver_dispatch (this=0x1472960) at
> msg/Messenger.h:504
> #15 SimpleMessenger::DispatchQueue::entry (this=0x1472960) at
> msg/SimpleMessenger.cc:367
> #16 0x00000000007d6a05 in SimpleMessenger::dispatch_entry (this=0x1472880)
> at msg/SimpleMessenger.cc:384
> #17 0x00000000007957bd in SimpleMessenger::DispatchThread::entry
> (this=<value optimized out>) at ./msg/SimpleMessenger.h:807
> #18 0x00007ffff76507f1 in start_thread (arg=0x7fffe6ec6700) at
> pthread_create.c:301
> #19 0x00007ffff6aa1ccd in clone () at
> ../sysdeps/unix/sysv/linux/x86_64/clone.S:115
> (gdb) f 12
> #12 0x00000000005d4b4f in OSD::handle_osd_ping (this=0x14d8000, m=<value
> optimized out>) at osd/OSD.cc:1717
> 1717
> _share_map_outgoing(service.get_osdmap()->get_cluster_inst(from));
> (gdb) l
> 1712          hbserver_messenger->send_message(r, m->get_connection());
> 1713
> 1714          if (osdmap->is_up(from)) {
> 1715            note_peer_epoch(from, m->map_epoch);
> 1716            if (locked && is_active())
> 1717
> _share_map_outgoing(service.get_osdmap()->get_cluster_inst(from));
> 1718          }
> 1719        }
> 1720        break;
> 1721
> (gdb) f 11
> #11 0x000000000058cde9 in OSDMap::get_cluster_inst (this=<value optimized
> out>, osd=<value optimized out>) at osd/OSDMap.h:330
> 330         assert(is_up(osd));
> (gdb) l
> 325       entity_inst_t get_inst(int osd) const {
> 326         assert(is_up(osd));
> 327         return entity_inst_t(entity_name_t::OSD(osd), get_addr(osd));
> 328       }
> 329       entity_inst_t get_cluster_inst(int osd) const {
> 330         assert(is_up(osd));
> 331         return entity_inst_t(entity_name_t::OSD(osd),
> get_cluster_addr(osd));
> 332       }
> 333       entity_inst_t get_hb_inst(int osd) const {
> 334         assert(is_up(osd));
>
>
> Apparently osdmap member in class OSD don't have the
> same map contents as the osdmap member in OSDService
> in this instance?
>
> Why are there two osdmaps?  Under what conditions is it
> appropriate for them to have different contents?
>
> Is this the appropriate fix?
>
> @@ -1711,10 +1711,10 @@ void OSD::handle_osd_ping(MOSDPing *m)
>                                 m->stamp);
>        hbserver_messenger->send_message(r, m->get_connection());
>
> -      if (osdmap->is_up(from)) {
> +      if (locked && osdmap->is_up(from)) {
>         note_peer_epoch(from, m->map_epoch);
> -       if (locked && is_active())
> -         _share_map_outgoing(service.get_osdmap()->get_cluster_inst(from));
> +       if (is_active())
> +         _share_map_outgoing(osdmap->get_cluster_inst(from));
>        }
>      }
>      break;
>
>
> Thanks -- Jim
>
> --
> To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: osd/OSDMap.h: 330: FAILED assert(is_up(osd))

[Jim Schutt]

On 07/17/2012 03:44 PM, Samuel Just wrote:
> Not quite.  OSDService::get_osdmap() returns the most recently
> published osdmap.  Generally, OSD::osdmap is safe to use when you are
> holding the osd lock.  Otherwise, OSDService::get_osdmap() should be
> used.  There are a few other things that should be fixed surrounding
> this issue as well, I'll put some time into it today.  The map_lock
> should probably be removed all together.

Thanks for taking a look.  Let me know when
you get something, and I'll take it for a spin.

Thanks -- Jim

> -Sam

Re: osd/OSDMap.h: 330: FAILED assert(is_up(osd))

[Samuel Just]

master should now have a fix for that, let me know how it goes.  I opened
bug #2798 for this issue.

Thanks for the info!
-Sam

On Tue, Jul 17, 2012 at 2:54 PM, Jim Schutt <jaschut@sandia.gov> wrote:
> On 07/17/2012 03:44 PM, Samuel Just wrote:
>>
>> Not quite.  OSDService::get_osdmap() returns the most recently
>> published osdmap.  Generally, OSD::osdmap is safe to use when you are
>> holding the osd lock.  Otherwise, OSDService::get_osdmap() should be
>> used.  There are a few other things that should be fixed surrounding
>> this issue as well, I'll put some time into it today.  The map_lock
>> should probably be removed all together.
>
>
> Thanks for taking a look.  Let me know when
> you get something, and I'll take it for a spin.
>
> Thanks -- Jim
>
>> -Sam
>
>
>

Re: osd/OSDMap.h: 330: FAILED assert(is_up(osd))

[Jim Schutt]

On 07/17/2012 06:03 PM, Samuel Just wrote:
> master should now have a fix for that, let me know how it goes.  I opened
> bug #2798 for this issue.
>

Hmmm, it seems handle_osd_ping() now runs into a case
where for the first ping it gets, service.osdmap can be empty?

      0> 2012-07-18 09:17:23.977497 7fffe6ec6700 -1 *** Caught signal (Segmentation fault) **
  in thread 7fffe6ec6700

  ceph version 0.48argonaut-419-g4e1d973 (commit:4e1d973e466cd45138f004e84ab8631d9b2a60fa)
  1: /usr/bin/ceph-osd() [0x723c39]
  2: (()+0xf4a0) [0x7ffff76584a0]
  3: (OSD::handle_osd_ping(MOSDPing*)+0x7d4) [0x5d7894]
  4: (OSD::heartbeat_dispatch(Message*)+0x71) [0x5d8111]
  5: (SimpleMessenger::DispatchQueue::entry()+0x583) [0x7d5103]
  6: (SimpleMessenger::dispatch_entry()+0x15) [0x7d6485]
  7: (SimpleMessenger::DispatchThread::entry()+0xd) [0x79523d]
  8: (()+0x77f1) [0x7ffff76507f1]
  9: (clone()+0x6d) [0x7ffff6aa1ccd]

gdb has this to say:

(gdb) bt
#0  0x00007ffff765836b in raise (sig=11) at ../nptl/sysdeps/unix/sysv/linux/pt-raise.c:42
#1  0x0000000000724067 in reraise_fatal (signum=11) at global/signal_handler.cc:58
#2  handle_fatal_signal (signum=11) at global/signal_handler.cc:104
#3  <signal handler called>
#4  get_epoch (this=0x15d0000, m=0x1587000) at ./osd/OSDMap.h:210
#5  OSD::handle_osd_ping (this=0x15d0000, m=0x1587000) at osd/OSD.cc:1711
#6  0x00000000005d8111 in OSD::heartbeat_dispatch (this=0x15d0000, m=0x1587000) at osd/OSD.cc:2769
#7  0x00000000007d5103 in ms_deliver_dispatch (this=0x1472960) at msg/Messenger.h:504
#8  SimpleMessenger::DispatchQueue::entry (this=0x1472960) at msg/SimpleMessenger.cc:367
#9  0x00000000007d6485 in SimpleMessenger::dispatch_entry (this=0x1472880) at msg/SimpleMessenger.cc:384
#10 0x000000000079523d in SimpleMessenger::DispatchThread::entry (this=<value optimized out>) at ./msg/SimpleMessenger.h:807
#11 0x00007ffff76507f1 in start_thread (arg=0x7fffe6ec6700) at pthread_create.c:301
#12 0x00007ffff6aa1ccd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115
(gdb) f 5
#5  OSD::handle_osd_ping (this=0x15d0000, m=0x1587000) at osd/OSD.cc:1711
1711					m->stamp);
(gdb) l
1706		}
1707	      }
1708	      Message *r = new MOSDPing(monc->get_fsid(),
1709					curmap->get_epoch(),
1710					MOSDPing::PING_REPLY,
1711					m->stamp);
1712	      hbserver_messenger->send_message(r, m->get_connection());
1713	
1714	      if (curmap->is_up(from)) {
1715		note_peer_epoch(from, m->map_epoch);
(gdb) p curmap
$1 = std::tr1::shared_ptr (empty) 0x0

-- Jim

> Thanks for the info!
> -Sam
>
> On Tue, Jul 17, 2012 at 2:54 PM, Jim Schutt<jaschut@sandia.gov>  wrote:
>> On 07/17/2012 03:44 PM, Samuel Just wrote:
>>>
>>> Not quite.  OSDService::get_osdmap() returns the most recently
>>> published osdmap.  Generally, OSD::osdmap is safe to use when you are
>>> holding the osd lock.  Otherwise, OSDService::get_osdmap() should be
>>> used.  There are a few other things that should be fixed surrounding
>>> this issue as well, I'll put some time into it today.  The map_lock
>>> should probably be removed all together.
>>
>>
>> Thanks for taking a look.  Let me know when
>> you get something, and I'll take it for a spin.
>>
>> Thanks -- Jim
>>
>>> -Sam
>>
>>
>>
>
>

Re: osd/OSDMap.h: 330: FAILED assert(is_up(osd))

[Samuel Just]

Sorry, master has a fix now for that also.
76efd9772c60b93bbf632e3ecc3b9117dc081427
-Sam

On Wed, Jul 18, 2012 at 8:29 AM, Jim Schutt <jaschut@sandia.gov> wrote:
> On 07/17/2012 06:03 PM, Samuel Just wrote:
>>
>> master should now have a fix for that, let me know how it goes.  I opened
>> bug #2798 for this issue.
>>
>
> Hmmm, it seems handle_osd_ping() now runs into a case
> where for the first ping it gets, service.osdmap can be empty?
>
>      0> 2012-07-18 09:17:23.977497 7fffe6ec6700 -1 *** Caught signal
> (Segmentation fault) **
>  in thread 7fffe6ec6700
>
>  ceph version 0.48argonaut-419-g4e1d973
> (commit:4e1d973e466cd45138f004e84ab8631d9b2a60fa)
>  1: /usr/bin/ceph-osd() [0x723c39]
>  2: (()+0xf4a0) [0x7ffff76584a0]
>  3: (OSD::handle_osd_ping(MOSDPing*)+0x7d4) [0x5d7894]
>  4: (OSD::heartbeat_dispatch(Message*)+0x71) [0x5d8111]
>  5: (SimpleMessenger::DispatchQueue::entry()+0x583) [0x7d5103]
>  6: (SimpleMessenger::dispatch_entry()+0x15) [0x7d6485]
>  7: (SimpleMessenger::DispatchThread::entry()+0xd) [0x79523d]
>  8: (()+0x77f1) [0x7ffff76507f1]
>  9: (clone()+0x6d) [0x7ffff6aa1ccd]
>
> gdb has this to say:
>
> (gdb) bt
> #0  0x00007ffff765836b in raise (sig=11) at
> ../nptl/sysdeps/unix/sysv/linux/pt-raise.c:42
> #1  0x0000000000724067 in reraise_fatal (signum=11) at
> global/signal_handler.cc:58
> #2  handle_fatal_signal (signum=11) at global/signal_handler.cc:104
> #3  <signal handler called>
> #4  get_epoch (this=0x15d0000, m=0x1587000) at ./osd/OSDMap.h:210
> #5  OSD::handle_osd_ping (this=0x15d0000, m=0x1587000) at osd/OSD.cc:1711
> #6  0x00000000005d8111 in OSD::heartbeat_dispatch (this=0x15d0000,
> m=0x1587000) at osd/OSD.cc:2769
> #7  0x00000000007d5103 in ms_deliver_dispatch (this=0x1472960) at
> msg/Messenger.h:504
> #8  SimpleMessenger::DispatchQueue::entry (this=0x1472960) at
> msg/SimpleMessenger.cc:367
> #9  0x00000000007d6485 in SimpleMessenger::dispatch_entry (this=0x1472880)
> at msg/SimpleMessenger.cc:384
> #10 0x000000000079523d in SimpleMessenger::DispatchThread::entry
> (this=<value optimized out>) at ./msg/SimpleMessenger.h:807
> #11 0x00007ffff76507f1 in start_thread (arg=0x7fffe6ec6700) at
> pthread_create.c:301
> #12 0x00007ffff6aa1ccd in clone () at
> ../sysdeps/unix/sysv/linux/x86_64/clone.S:115
> (gdb) f 5
> #5  OSD::handle_osd_ping (this=0x15d0000, m=0x1587000) at osd/OSD.cc:1711
> 1711                                    m->stamp);
> (gdb) l
> 1706            }
> 1707          }
> 1708          Message *r = new MOSDPing(monc->get_fsid(),
> 1709                                    curmap->get_epoch(),
> 1710                                    MOSDPing::PING_REPLY,
> 1711                                    m->stamp);
>
> 1712          hbserver_messenger->send_message(r, m->get_connection());
> 1713
> 1714          if (curmap->is_up(from)) {
> 1715            note_peer_epoch(from, m->map_epoch);
> (gdb) p curmap
> $1 = std::tr1::shared_ptr (empty) 0x0
>
> -- Jim
>
>
>> Thanks for the info!
>> -Sam
>>
>> On Tue, Jul 17, 2012 at 2:54 PM, Jim Schutt<jaschut@sandia.gov>  wrote:
>>>
>>> On 07/17/2012 03:44 PM, Samuel Just wrote:
>>>>
>>>>
>>>> Not quite.  OSDService::get_osdmap() returns the most recently
>>>> published osdmap.  Generally, OSD::osdmap is safe to use when you are
>>>> holding the osd lock.  Otherwise, OSDService::get_osdmap() should be
>>>> used.  There are a few other things that should be fixed surrounding
>>>> this issue as well, I'll put some time into it today.  The map_lock
>>>> should probably be removed all together.
>>>
>>>
>>>
>>> Thanks for taking a look.  Let me know when
>>> you get something, and I'll take it for a spin.
>>>
>>> Thanks -- Jim
>>>
>>>> -Sam
>>>
>>>
>>>
>>>
>>
>>
>
>

Re: osd/OSDMap.h: 330: FAILED assert(is_up(osd))

[Jim Schutt]

On 07/18/2012 12:03 PM, Samuel Just wrote:
> Sorry, master has a fix now for that also.
> 76efd9772c60b93bbf632e3ecc3b9117dc081427
> -Sam

That got things running for me.

Thanks for the quick reply.

-- Jim