[Nfd-dev] [Operators] "No buffer space available"

[Dehart, John]

> On Sep 5, 2017, at 11:36 AM, Davide Pesavento <davide.pesavento at lip6.fr> wrote:
> 
> On Tue, Sep 5, 2017 at 5:23 PM, Dehart, John <jdd at wustl.edu> wrote:
>> 
>> nfd.log file has not been touched in 11 hours:
> 
> So nfd is up but not doing anything meaningful? Can you run strace -p
> on the stuck nfd?

Too late. I restarted with my updates to change to DEBUG and capture log files.
Yes, it was stuck and not responding to anything. Did attach to it with gdb
to see if that would tell me anything but not sure this really tells us anything:

(gdb) bt
#0  malloc_consolidate (av=av at entry=0x7f6a6de53760 <main_arena>) at malloc.c:4165
#1  0x00007f6a6db1072d in _int_free (av=0x7f6a6de53760 <main_arena>, p=<optimized out>, have_lock=0) at malloc.c:4059
#2  0x00007f6a6f50baf7 in std::_Sp_counted_ptr<ndn::Buffer*, (__gnu_cxx::_Lock_policy)2>::_M_dispose() () from /usr/lib/x86_64-linux-gnu/libndn-cxx.so.0.5.1
#3  0x000000000045b639 in std::_Sp_counted_base<(__gnu_cxx::_Lock_policy)2>::_M_release() ()
#4  0x0000000000472e44 in ?? ()
#5  0x000000000047c267 in ?? ()
#6  0x000000000047c393 in ?? ()
#7  0x000000000047a567 in ?? ()
#8  0x000000000044eff4 in boost::asio::detail::task_io_service::run(boost::system::error_code&) ()
#9  0x0000000000450576 in ?? ()
#10 0x00000000004363ff in ?? ()
#11 0x00007f6a6dab2f45 in __libc_start_main (main=0x436060, argc=3, argv=0x7ffff81bf138, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffff81bf128) at libc-start.c:287
#12 0x0000000000449399 in ?? ()
(gdb)

When I see it again, I will try strace.

John

> 
>> ndnops at mccoy:/var/log/ndn$ date; ls -l nfd.log
>> Tue Sep  5 09:22:28 MDT 2017
>> -rw-r--r-- 1 root root 9852417 Sep  4 20:15 nfd.log
>> ndnops at mccoy:/var/log/ndn$
>> 
>> 
>> And here is a snippet from the end of the nfd.log file:
>> 
>> 1504529452.792695 INFO: [FaceTable] Removed face id=3636 remote=fd://41
>> local=unix:///run/nfd.sock
>> 1504529584.024639 ERROR: [Forwarder] onInterestReject
>> interest=/localhop/ndn/NLSR/LSA/fr/lip6/%C1.Router/ndnhub/name/%00%04K%0F
>> cannot reject forwarded Interest
>> 1504529584.279773 ERROR: [Forwarder] onInterestReject
>> interest=/localhop/ndn/NLSR/LSA/fr/lip6/%C1.Router/ndnhub/name/%00%04K%0F
>> cannot reject forwarded Interest
>> 1504529584.628634 ERROR: [Forwarder] onInterestReject
>> interest=/localhop/ndn/NLSR/LSA/fr/lip6/%C1.Router/ndnhub/name/%00%04K%0F
>> cannot reject forwarded Interest
>> 1504529584.661140 ERROR: [Forwarder] onInterestReject
>> interest=/localhop/ndn/NLSR/LSA/fr/lip6/%C1.Router/ndnhub/coordinate/%00%036%0B
>> cannot reject forwarded Interest
>> 1504529652.749651 WARNING: [TcpTransport]
>> [id=296,local=tcp4://129.82.138.48:48451,remote=tcp4://128.187.81.12:6363]
>> Send or receive operation failed: Connection reset by peer
>> 1504529652.749688 INFO: [Transport]
>> [id=296,local=tcp4://129.82.138.48:48451,remote=tcp4://128.187.81.12:6363]
>> setState UP -> FAILED
>> 1504529652.773699 WARNING: [TcpTransport]
>> [id=297,local=tcp4://129.82.138.48:6363,remote=tcp4://128.187.81.12:50395]
>> Send or receive operation failed: Connection reset by peer
>> 1504529652.773718 INFO: [Transport]
>> [id=297,local=tcp4://129.82.138.48:6363,remote=tcp4://128.187.81.12:50395]
>> setState UP -> FAILED
>> 1504576945.509068 INFO: [Transport]
>> [id=296,local=tcp4://129.82.138.48:48451,remote=tcp4://128.187.81.12:6363]
>> setState FAILED -> CLOSED
>> 1504577758.141391 INFO: [FaceTable] Removed face id=296
>> remote=tcp4://128.187.81.12:6363 local=tcp4://129.82.138.48:48451