Subject: [dtn-users] [Prophet] bundle/database errors

From: Tom Sparks <[email-masked]>
Date: Sun, 7 Jul 2013 20:19:15 -0700 (PDT)

I have just got around to connecting two computing
I am using ProphetRouter

I am getting these error messages:
"
[1373252007.147300 /dtn/storage/bundles error] update(98): bundle doesn't exist in table
[1373252007.147319 /dtn/bundle/actions critical] error updating bundle 98 in data store!!
"
I am running the bleeding edge version

---
tom_a_sparks "It's a nerdy thing I like to do"
Child of the Internet born 1983
PGP ID: A7EF6006
Please use ISO approved file formats excluding Office Open XML - http://www.gnu.org/philosophy/no-word-attachments.html
Ubuntu wiki page https://wiki.ubuntu.com/tomsparks

---

From: Lana Black <[email-masked]>
Date: Mon, 8 Jul 2013 19:56:37 +0000

> _______________________________________________
> dtn-users mailing list
> [email-masked]
> https://www.irtf.org/mailman/listinfo/dtn-users

Hi Tom,

Could you send me dtn.conf example to reproduce this error?

---

From: Tom Sparks <[email-masked]>
Date: Mon, 8 Jul 2013 13:34:22 -0700 (PDT)

>________________________________
> From: Lana Black <[email-masked]>
>To: Tom Sparks <[email-masked]> 
>Cc: "[email-masked]" <[email-masked]> 
>Sent: Tuesday, 9 July 2013 5:56 AM
>Subject: Re: [dtn-users] [Prophet] bundle/database errors
> 
>

see bellow

based on earlier thread <http://www.ietf.org/mail-archive/web/dtn-interest/current/msg04745.html>
I have installed IBR-DTN
---------- cut here----------

console set addr 127.0.0.1
console set port 5050
set shorthostname [lindex [split [info hostname] .] 0]
console set prompt "$shorthostname dtn% "
storage set type berkeleydb
storage set server_port 62345
storage set schema /etc/DS.xsd
set dbdir "./db"
storage set payloaddir "./db/bundles"
storage set dbname     DTN
storage set dbdir      $dbdir
route set type prophet
route local_eid "dtn://[info hostname].dtn"
interface add tcp0 tcp
discovery add bonjourd bonjour

log /logs/ info ""
# Rotate the log every 3600 seconds (1 hour)
# the initial call to rotate (after the proc) is required to
# start the proc running every hour.
#proc rotate {} {
#    set date [ clock format [ clock seconds ] -format "%Y-%m-%d-%H" ]
#    set new "./db/logs/[info hostname]/dtnd.$date.log"
#    file rename "./db/logs/dtnd.log" $new
#    log rotate
#    after 3600000 rotate
#}
#rotate
-------cut here----------------

---

From: Lana Black <[email-masked]>
Date: Tue, 9 Jul 2013 23:42:26 +0000

> -------cut here----------------

It looks like the PrOPHET code is written to handle bundles itself and
not through BundleDaemon. It doesn't call BundleActions::store_add() in
any way, which results in this problem.

I suppose the PrOPHET code should be rewritten to send bundles through
BundleDaemon, but I'd like a comment from somebody with better knowledge
of overall architecture.

---

From: Elwyn Davies <[email-masked]>
Date: Wed, 10 Jul 2013 13:24:43 +0100

Hi, Tom.

I regret to say that the PRoPHET code in DTN2 is not maintained and (as
Lana mentioned) not fully integrated into the DTN2 'ethos'.

I worked a fair bit with it some years ago but it had a number of
problems which made it essentially unusable (not helped by hardware
issues around the dreadful buggy implementations of ad hoc wi-fi on most
devices).

In principle, one of those problems is now fixed, but I haven't looked
to see what would be needed to allow PRoPHET to function correctly.  The
problem was that PRoPHET is much more dependent on the forwarding
history of bundles than some of the other routing protocols.  Up until
the end of 2011 the forwarding history was not saved to persistent
storage; this was in turn because there was no persistent storage of
link information.  I fixed this back in 2011.  Now after a restart of
the daemon, links that are recreated (whether static or opportunistic)
will be consistently named which makes the forwarding history usable.

However in order to get PRoPHET working at all across restarts before
2011 I put in some (extra) fudges which meant that bundles that hadn't
been forwarded by PRoPHET before the restart were effectively ignored
and never got forwarded.  This was never satisfactory but there was no
good way to fix the problem before 2011. [Table based routing made the
opposite decision and just decided that anything in the persistent store
should be treated as newly received.]

The structural problems of the code (partly due to an over-zealous usage
of a particular design pattern IMHO) and the fact that it implements
PRoPHET v1 rather than the current v2 indicated that a wholesale rewrite
was needed.  The original intention was that this should be done as part
of the N4C project, but for various reasons this never happened.  It is
still on my list of jobs to do and might actually happen sometime before
2020 ;-)

One final consideration was that the author of the code was originally
interested only in Bluetooth and, while using TCP shouldn't be a
problem, I have no idea if there are lurking gotchas around this area.

All this being said, I thought the system should work if you don't
restart the daemon or there are no bundles pending when the daemon is
restarted. 

Lana:
I don't think the analysis below is correct.  store_add is called via
add_to_pending in BundleDaemon:handle_bundle_received whatever router is
in use.  But clearly the bundle has disappeared when the forwarding log
is updated or some such.

Tom:
If you want more assistance on this one can you turn on debug level
logging on dtnd and send us the resulting log when you get this problem.
Life is a bit busy at the moment and I don't have time to set up the
relevant scenario. 

Regards,
Elwyn

---

From: Lana Black <[email-masked]>
Date: Wed, 10 Jul 2013 12:58:57 +0000

> in use.  But clearly the bundle has disappeared when the forwarding log

I have just checked again by setting breakpoints on store_add and
store_update, and my point seems to be correct. The error in question
arises when sending prophet hello bundles. See the stacktrace below.
Store_add() doesn't seem to be called at all.

(gdb) bt
#0  dtn::BundleActions::store_update (this=0x9c65d0, bundle=0x7fffe40163c0)
    at bundling/BundleActions.cc:314                                       
#1  0x00000000004a4994 in dtn::ForwardingLog::add_entry (this=0x7fffe4016ba8,
    link=..., action=dtn::ForwardingInfo::COPY_ACTION,                       
    state=dtn::ForwardingInfo::QUEUED, custody_timer=...)
    at bundling/ForwardingLog.cc:225                     
#2  0x000000000058d4b3 in dtn::BundleActions::queue_bundle (this=0x9c65d0,
    bundle=0x7fffe40163c0, link=..., action=dtn::ForwardingInfo::COPY_ACTION,
    custody_timer=...) at bundling/BundleActions.cc:204                      
#3  0x0000000000601ff8 in dtn::ProphetBundleCore::send_bundle (
    this=0x7fffe4000a50, bundle=0x7fffe4016e20, link=0x7fffe4000df0)
    at routing/ProphetBundleCore.cc:228                             
#4  0x00000000005be920 in prophet::Encounter::send_tlv (this=0x7fffe4016130,
    tlv=0x7fffe4016350) at prophet/Encounter.cc:1046                        
#5  0x00000000005b15f1 in prophet::Encounter::send_hello (this=0x7fffe4016130,
    hf=prophet::HelloTLV::SYN, hr=prophet::ProphetTLV::NoSuccessAck, tid=0)   
    at prophet/Encounter.cc:864                                            
#6  0x00000000005b09b7 in prophet::Encounter::Encounter (this=0x7fffe4016130,
    nexthop=0x7fffe4000df0, oracle=0x7fffe4000b90, instance=1)               
    at prophet/Encounter.cc:104                               
#7  0x00000000005ac3cc in prophet::Controller::new_neighbor (
    this=0x7fffe4000b90, link=0x7fffe4000df0) at prophet/Controller.cc:123
#8  0x0000000000542d6b in dtn::ProphetRouter::handle_contact_up (
    this=0x7fffe4000910, e=0x7fffe4002e10) at routing/ProphetRouter.cc:278
#9  0x00000000004846cc in dtn::BundleEventHandler::dispatch_event (
    this=0x7fffe4000910, e=0x7fffe4002e10)                         
    at bundling/BundleEventHandler.cc:145 
#10 0x0000000000541248 in dtn::ProphetRouter::handle_event (
    this=0x7fffe4000910, e=0x7fffe4002e10) at routing/ProphetRouter.cc:89
#11 0x000000000045fedd in dtn::BundleDaemon::handle_event (this=0x9b4cd0,
    event=0x7fffe4002e10, closeTransaction=true)                         
    at bundling/BundleDaemon.cc:2946            
#12 0x000000000045fe72 in dtn::BundleDaemon::handle_event (this=0x9b4cd0,
    event=0x7fffe4002e10) at bundling/BundleDaemon.cc:2935               
#13 0x0000000000461bd2 in dtn::BundleDaemon::run (this=0x9b4cd0)
    at bundling/BundleDaemon.cc:3255                            
#14 0x0000000000461fac in non-virtual thunk to dtn::BundleDaemon::run() (
    this=0x9b4d30) at bundling/BundleDaemon.cc:3305                      
---Type <return> to continue, or q <return> to quit---
#15 0x000000000066a0aa in oasys::Thread::thread_run (this=0x9b4d30,
    thread_name=0x9b4d4c "BundleDaemon", thread_id=140737281959680)
    at thread/Thread.cc:363                                        
#16 0x0000000000669cb3 in oasys::Thread::pre_thread_run (t=0x9b4d30)
    at thread/Thread.cc:308                                         
#17 0x00007ffff60a7f3b in start_thread () from /lib64/libpthread.so.0
#18 0x00007ffff5bcc65d in clone () from /lib64/libc.so.6

---

From: Elwyn Davies <[email-masked]>
Date: Wed, 10 Jul 2013 15:56:05 +0100

Hi, Lana.

Ah, yes.  I was forgetting that the choice was made to send hellos in
bundles with the DTN2 implementation (it can be done otherwise).

And yes the code should call (more accurately post an event on)
BundleDaemon::handle_bundle_received 
cf. PingRegistration::deliver_bundle which also creates bundles to send.

I am intrigued that I never hit this problem when I was using PRoPHET...
but thinking about it this is an artefact of the previous non-storing of
the forwarding log. Yes...

> diff -r 0400f64a34e4 -r c1c472ab77af servlib/bundling/BundleActions.cc
> --- a/servlib/bundling/BundleActions.cc Fri Apr 29 17:56:38 2011 +0100
> +++ b/servlib/bundling/BundleActions.cc Mon Aug 29 16:16:29 2011 +0100
> @@ -165,6 +165,8 @@
>      
>      bundle->fwdlog()->add_entry(link, action, ForwardingInfo::QUEUED,
>                                  custody_timer);
> +    BundleDaemon *daemon = BundleDaemon::instance();
> +    daemon->actions()->store_update(bundle);
>  
>      log_debug("adding *%p to link %s's queue (length %u)",
>                bundle, link->name(), link->bundles_queued());

Back when I was playing with PRoPHET the forwarding log wasn't being
updated, so this problem wouldn't have raised its ugly head.

Looking at this code, you are right that all the stuff in
ProphetBundleCore::send_bundle is an ugly hack to create a 'transient'
bundle that is sent immediately and never appears in the pending queue
etc. Yuck. Yes indeed. The PRoPHET implementation did not play by the
rules.  And after the bundle has been sent it gets deleted and that will
log an error but the return value is ignored - see
ProphetBundleCore::drop_bundle last statement - so the process will keep
running if it ever gets there - at the moment it will barf again when
the forwarding log gets updated.

A quick and dirty fix would probably be to build a BundleReceivedEvent
and add 
    BundleDaemon::post_and_wait(new BundleReceivedEvent(bundle,
EVENTSRC_ADMIN));
to ProphetBundleCore::send_bundle before all the link manipulation
starts, but with daemon_only_ set to True in the event so it doesn't get
fed to the router.

Regards,
Elwyn

---

From: Tom Sparks <[email-masked]>
Date: Wed, 10 Jul 2013 17:13:54 -0700 (PDT)

> From: Elwyn Davies <[email-masked]>
>To: Lana Black <[email-masked]> 
>Cc: Tom Sparks <[email-masked]>; "[email-masked]" <[email-masked]> 
>Sent: Wednesday, 10 July 2013 10:24 PM
ok, I am using IBR-DTN

<snip>

>Life is a bit busy at the moment and I don't have time to set up the

I'll let someone else do that

>Elwyn
tom