Subject: [dtn-users] DurableStore errors from dtnd with code from tip

From: Darren Long <[email-masked]>
Date: Wed, 09 Nov 2011 21:22:40 +0000

Hiya,

I've been having runtime problems with dtnd on Debian Squeeze.  I'm using libdb4.8 and the berkelydb store.  The logs pretty much carry on like the snippet below, usually culminating in epic fail.  I'd not seen this problem before the release of 2.8.0, but hadn't been keeping up with the tip.

Does anyone have any idea what's going on?

Cheers,

Darren

[1320873124.849271 /dtnd notice] random seed is 849265
[1320873124.850379 /dtnd notice] DTN daemon starting up... (pid 30444)
[1320873124.954349 /dtn/storage warning] DurableStoreImpl::endTransaction not implemented.
[1320873124.954662 /S10 notice] Lines marked "S10" are log lines added to make parsing
[1320873124.954687 /S10 notice] the logs easier after extended tests. These were added for
[1320873124.954707 /S10 notice] the summer 2010 N4C summer trial and are mainly new lines
[1320873124.954726 /S10 notice] that allow tracing bundles across multiple hops.
[1320873124.954745 /S10 notice] To extract these do the following...
[1320873124.954765 /S10 notice] 	 grep "S10 info" <dtnd-log-files> | grep -v grep | awk '{print $4,$5}' | sort -n
[1320873124.957788 /dtn/bundle/daemon notice] loading bundles from data store
[1320873124.961231 /dtn/storage warning] DurableStoreImpl::beginTransaction not implemented.
[1320873124.961255 /dtn/storage warning] error in beginTransaction; releasing lock and DS_ERR
[1320873124.961327 /dtn/storage warning] DurableStoreImpl::beginTransaction not implemented.
[1320873124.961349 /dtn/storage warning] error in beginTransaction; releasing lock and DS_ERR
[1320873124.961709 /dtn/storage warning] DurableStoreImpl::beginTransaction not implemented.

---

From: Mario F <[email-masked]>
Date: Wed, 9 Nov 2011 21:29:50 +0000

Hi:

I have the same problem but in Ubuntu. 

Thank you.

 

> From: [email-masked]
> Date: Wed, 9 Nov 2011 21:22:40 +0000
> To: [email-masked]
> Subject: [dtn-users] DurableStore errors from dtnd with code from tip
> 
> Hiya,
> 
> _______________________________________________
> dtn-users mailing list
> [email-masked]
> https://www.irtf.org/mailman/listinfo/dtn-users

---

From: Darren Long <[email-masked]>
Date: Wed, 09 Nov 2011 21:37:21 +0000

Hi Mario,

Does your dtnd  crash too, or do you just have the errors (actually  I suppose they are just warnings) in the log?  I'm not sure yet if the two are related.  My latest rebuild of dtnd hasn't crashed so far (I purged the /var/dtn directory by building a deb package and installing that) and is pinging dtn://bravo.grc.dtn/ping happily but I'm still getting all the log entries as below.

Darren

---

From: Darren Long <[email-masked]>
Date: Wed, 09 Nov 2011 22:39:54 +0000

Hi again Elwyn,

Thanks for the informative response. I've not touched the N4C repos so I don't think that is the issue, but my source tree has a long history so I might do a full hg clone from scratch and try that.  

As I mentioned the other minor complication on the x86 host in question is my tendency to build debs and install those and I have just realised that I had an old version of oasys-dev installed which may have gnarled up the build of the DTN2 debs I guess.  I'm rebuilding the DTN2 deb package as I type.

I've started experimenting on my arm box too, and that seems to be exhibiting similar behaviour, on this box I'm using old good old 'make install' with no packaging nonsense.  I've fallen down the rabbit hole of trying memorydb too and am still stuck down there at the mo.

I think the S10 stuff came in changeset 3504 from SF. I've pondered over the spreadsheets myself :P

BTW, would you recommend the new SQL storage? I've really only stuck with libdb as its the way I've always done it.

Cheers,

Darren

On 9 Nov 2011, at 22:29, Elwyn Davies wrote:

> Hi.
> 
> The 'error messages' you are getting are an artefact from the update
> that Keith Scott put in (DTN2 #3518 and oasys #2279, 2 months ago) which
> allows dtnd to use SQL databases for storage.  To do this he put in full
> transactional control for operations on the database.
> 
> The messages are coming from the DurableStoreImpl.cc base class default
> implementation in oasys v1.5.0.  In theory if the Berkeley DB durable
> store implementation is working correctly, these methods should be
> overridden and never called.
> 
> I am wondering whether you have a mixed installation?  Are you running
> oasys 1.5.0 from the main repository and the dtnd from an N4C
> repository?  The S10 messages come from the N4C branch and (I believe)
> they have not been merged into the main branch as yet. This would give
> the symptoms you are seeing because, conversely, Keith Scott's
> transactional updates have not been merged into th N4C branch.  The
> result would be (I suspect) that the DTN implementation doesn't provide
> the begin/end transaction implementations and the base class routines
> are called - I'm not quite sure what is happening but if my diagnosis is
> correct there would certainly be some sort of problems like you are
> seeing.
> 
> The moral is to make sure you are running consistent versions of oasys
> and DTN2 either both from the N4C repository or both from the main
> sourceforge repository. 
> 
> I am not surprised that there is eventually a major crash if my
> diagnosis is correct!  There probably needs to be a warning in the N4C
> repository about this issue - and we probably need to try and merge the
> stuff we did for N4C into the main branch asap.
> 
> Regards,
> Elwyn
> 
> 
> 
> 
> 
> On Wed, 2011-11-09 at 21:37 +0000, Darren Long wrote:
>> Hi Mario,
>> 
>> 
>> Does your dtnd  crash too, or do you just have the errors (actually  I
>> suppose they are just warnings) in the log?  I'm not sure yet if the
>> two are related.  My latest rebuild of dtnd hasn't crashed so far (I
>> purged the /var/dtn directory by building a deb package and installing
>> that) and is pinging dtn://bravo.grc.dtn/ping happily but I'm still
>> getting all the log entries as below.
>> 
>> 
>> Darren
>> 
>>>> I've been having runtime problems with dtnd on Debian Squeeze. I'm
>>> using libdb4.8 and the berkelydb store. The logs pretty much carry
>>> on like the snippet below, usually culminating in epic fail. I'd not
>>> seen this problem before the release of 2.8.0, but hadn't been
>>> keeping up with the tip.
>>>> 
>>>> [1320873124.954349 /dtn/storage warning]
>>> DurableStoreImpl::endTransaction not implemented.
>>>> [1320873124.954765 /S10 notice] grep "S10 info" <dtnd-log-files> |
>>> grep -v grep | awk '{print $4,$5}' | sort -n
>>>> [1320873124.961231 /dtn/storage warning]
>>> DurableStoreImpl::beginTransaction not implemented.
>>>> [1320873124.961255 /dtn/storage warning] error in
>>> beginTransaction; releasing lock and DS_ERR
>>>> [1320873124.961327 /dtn/storage warning]
>>> DurableStoreImpl::beginTransaction not implemented.
>>>> [1320873124.961349 /dtn/storage warning] error in
>>> beginTransaction; releasing lock and DS_ERR
>>>> [1320873124.961709 /dtn/storage warning]
>>> DurableStoreImpl::beginTransaction not implemented.

---

From: Stephen Farrell <[email-masked]>
Date: Wed, 09 Nov 2011 22:43:21 +0000

I'm pretty sure the S10 stuff is in 2.8.0 so its a mixed
build in that sense.

Sorry I've no other help to offer now;-)

S

On 11/09/2011 10:39 PM, Darren Long wrote:
>>>>> [1320873124.954765 /S10 notice] grep "S10 info"<dtnd-log-files>  |

---

From: "Scott, Keith L." <[email-masked]>
Date: Thu, 10 Nov 2011 02:01:03 +0000

Yeah, that's the DurableStore module complaining that the storage mechanism (BerkeleyDB?) doesn't support transactions (really that the oasys BerkeleyDB manager doesn't implement them, BerekeleyDB I think does support them).

These errors are safe to ignore for now, and should only show up at a higher debug level soon.

		--keith

-----Original Message-----
From: [email-masked] [mailto:[email-masked]] On Behalf Of Darren Long
Sent: Wednesday, November 09, 2011 4:23 PM
To: [email-masked]
Subject: [dtn-users] DurableStore errors from dtnd with code from tip

Hiya,

Cheers,

Darren

---

From: Alex McMahon <[email-masked]>
Date: Thu, 10 Nov 2011 10:15:13 +0000

Hi Darren,

While I can reproduce the DurableStore warning i'm unable to reproduce
runtime problems or an epic failure/crash (on 64bit Ubuntu 10.04.3) can
you provide any more detail/logs on this. 

also just to confirm that S10 logging stuff is in 2.8.0.

Thanks

Alex

---

From: Elwyn Davies <[email-masked]>
Date: Thu, 10 Nov 2011 18:03:39 +0000

Further to the bug report below...

I believe the attached updated files (and the patches to get there)
should fix the problem for the Berkeley DB store.  I'll check them out
shortly but they do compile OK.

However, we ought really to put some empty routines into memory and file
store classes to prevent them generating spurious warning messages.

Regards,
Elwyn

Hi, Alex/Darren/Keith.

There is a bug and it could well result in a crash.

The interface signatures of begin/endTransaction in the
BerkeleyDBStore.h do not match those in the DurableStoreImpl.h whereas
they do in ODBCstore.h.

This is why the base class routines are getting called and generating
the warnings.  The result is that the transaction id is not set up
correctly (it should be an 'out' parameter to beginTransaction but the
default code just leaves the value in the caller untouched).

Regards,
Elwyn

> > [1320873124.961709 /dtn/storage warning] DurableStoreImpl::beginTransaction not implemented.
diff -r e3c74c2b622a -r 44eef8479b95 storage/BerkeleyDBStore.cc
--- a/storage/BerkeleyDBStore.cc	Wed Aug 31 12:14:24 2011 +0100
+++ b/storage/BerkeleyDBStore.cc	Thu Nov 10 14:13:56 2011 +0000
@@ -213,35 +213,42 @@
 }
 
 //----------------------------------------------------------------------------
-void *
-BerkeleyDBStore::beginTransaction()
+int
+BerkeleyDBStore::beginTransaction(void **txid)
 {
-    DB_TXN *txid;
+    DB_TXN *txid_local;
     u_int32_t flags = 0x0;
     int ret;
 
-    log_debug("fooDBStore::beginTransaction.");
+    log_debug("BerkeleyDBStore::beginTransaction.");
 
-    ret = dbenv_->txn_begin(dbenv_, NULL, &txid, flags);
+    ret = dbenv_->txn_begin(dbenv_, NULL, &txid_local, flags);
     if ( ret!=0 ) {
         if ( ret==DB_RUNRECOVERY ) {
             PANIC("RUN DB Recovery on fooDB.");
         }
-        return((void *) NULL);
+        return(DS_ERR);
+    }
+    if ( txid != NULL ) {
+        *txid = (void *)txid_local;
     }
 
-    return((void *) txid);
+    return 0;
 }
 
 //----------------------------------------------------------------------------
 int
-BerkeleyDBStore::endTransaction(void *txid)
+BerkeleyDBStore::endTransaction(void *txid, bool be_durable)
 {
     int ret;
     u_int32_t flags = 0x0;
     DB_TXN *txp = (DB_TXN *) txid;
 
-    log_debug("fooDBStore::endTransaction");
+    log_debug("BerkeleyDBStore::endTransaction");
+
+    if ( be_durable ) {
+    	log_debug("BerkeleyDBStore::endTransaction called with be_durable TRUE");
+    }
 
     ret = txp->commit(txp, flags);
 
diff -r e3c74c2b622a -r 44eef8479b95 storage/BerkeleyDBStore.h
--- a/storage/BerkeleyDBStore.h	Wed Aug 31 12:14:24 2011 +0100
+++ b/storage/BerkeleyDBStore.h	Thu Nov 10 14:13:56 2011 +0000
@@ -67,8 +67,8 @@
 
     //! Primitive support for transactions (assumes ALL
     //! transactionalized accesses are single-threaded).
-    void* beginTransaction();
-    int   endTransaction(void *txid);
+    int   beginTransaction(void **txid);
+    int   endTransaction(void *txid, bool be_durable);
 
     //! Allow access to the underlying DB implementation
     void* getUnderlying();

---

From: Elwyn Davies <[email-masked]>
Date: Thu, 10 Nov 2011 18:03:02 +0000

Hi, Alex/Darren/Keith.

Regards,
Elwyn

---

From: Alex McMahon <[email-masked]>
Date: Thu, 10 Nov 2011 18:03:17 +0000

Hi Darren,

Elwyn has found a bug which might have caused runtime
problems/failure/crash (Although as yet I have been unable to
reproduce). I have tested the patch (oasys) and posted to
SourceForge[1] 

Grateful if other folks who have experienced the problem Darren
described could apply the oasys update and post to the list whether this
resolves the issue

Thanks

Alex  

[1] http://dtn.hg.sourceforge.net/hgweb/dtn/oasys

---

From: Darren Long <[email-masked]>
Date: Thu, 10 Nov 2011 19:21:55 +0000

Hi all,

I've not had much luck with the new tip, currently dtnd dies when run with --init-db

In GDB I'm getting this:

darren@delaytolerant:~/dtn$ gdb -args dtnd -c ./dtn.conf --init-db
GNU gdb (GDB) 7.0.1-debian
Copyright (C) 2009 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "i486-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from /usr/local/bin/dtnd...done.
(gdb) run
Starting program: /usr/local/bin/dtnd -c ./dtn.conf --init-db
[Thread debugging using libthread_db enabled]
[1320952483.531550 /dtnd notice] random seed is 531543
[1320952483.531634 /dtnd notice] DTN daemon starting up... (pid 5238)
[New Thread 0xb6a71b70 (LWP 5241)]
[1320952483.562681 /dtnd notice] initializing persistent data store
[1320952483.562900 /dtn/storage notice] creating new database directory /home/darren/dtn/db

Program received signal SIGSEGV, Segmentation fault.
0x0832836e in oasys::BerkeleyDBStore::endTransaction (this=0x84bcae8, txid=0x0, be_durable=true) at storage/BerkeleyDBStore.cc:253
253	    ret = txp->commit(txp, flags);
(gdb) bt
#0  0x0832836e in oasys::BerkeleyDBStore::endTransaction (this=0x84bcae8, txid=0x0, be_durable=true) at storage/BerkeleyDBStore.cc:253
#1  0x082fec74 in oasys::DurableStore::endTransaction (this=0x84bc930) at storage/DurableStore.cc:215
#2  0x080765c9 in dtn::DTNServer::init_datastore (this=0x84a0e58) at DTNServer.cc:153
#3  0x08064d57 in dtn::DTND::main (this=0xbffff200, argc=4, argv=0xbffff7b4) at dtnd.cc:188
#4  0x0806505c in main (argc=4, argv=0xbffff7b4) at dtnd.cc:263
(gdb) 

I thought I'd pass this on sooner rather than later. I'm gonna carry on sniffing around in GDB, but the storage side of things is a place I've never been before in DTN2.

Cheers,

Darren

---

From: Elwyn Davies <[email-masked]>
Date: Thu, 10 Nov 2011 22:04:26 +0000

Hmm.

It looks as if there is some more work to do.  I think init_datastore is
broken.  It doesn't seem to have a beginTransaction to match the
endTransaction.  This calls the endTransaction in DurableStore.cc so the
lack of parameters is right.

With ODBC txid isn't used in the actual database so it doesn't matter
but for BerkeleyDB it does.

If you want to try things further comment out the makeTransactionDurable
and endTransaction at lines 152/153 of DTN2/servlib/DTNserver.cc.

oasys/storage/DurableStore.cc needs some extra code to stop it barfing
when open_txid_ is NULL as it is if beginTransaction is not called
first.  As I said the ODBC case doesn't care.

I'll look at this further tomorrow.

Regards,
Elwyn

---

From: Darren Long <[email-masked]>
Date: Tue, 15 Nov 2011 17:58:53 +0000

Hi all,

Just wanted to give some feedback on the hacky fix.  So far so good with berekelydb storage.  I've been a bit distracted as I'm now playing with ION too :P

Darren