servalproject / serval-dna

The Serval Project's core daemon that implements Distributed Numbering Architecture (DNA), MDP, VoMP, Rhizome, MeshMS, etc.
http://servalproject.org
Other
170 stars 81 forks source link

Caught signal SIGSEGV (11) Segmentation fault in overlay_fill_send_packet?? #117

Closed b0661 closed 6 years ago

b0661 commented 7 years ago

Trying to do some rhizome tests I get segmentation faults:

Any ideas?

Servald A: Adds the bundle to rhizome Servald B: Should get it

Debug & logging configuration:

INFO: [ 1657] 20:09:54.855 Serval DNA version: START-3692-gc05775a+b0661n0e17e@gmail.com-20161126194410
INFO: [ 1657] 20:09:54.855 Current configuration:
INFO: [ 1657] 20:09:54.855    debug.http_server=true
INFO: [ 1657] 20:09:54.855    debug.httpd=true
INFO: [ 1657] 20:09:54.855    debug.msp=true
INFO: [ 1657] 20:09:54.855    debug.packetrx=true
INFO: [ 1657] 20:09:54.855    debug.packettx=true
INFO: [ 1657] 20:09:54.855    debug.rhizome=true
INFO: [ 1657] 20:09:54.855    debug.rhizome_ads=true
INFO: [ 1657] 20:09:54.855    debug.rhizome_manifest=true
INFO: [ 1657] 20:09:54.855    debug.rhizome_rx=true
INFO: [ 1657] 20:09:54.855    debug.rhizome_sync_keys=true
INFO: [ 1657] 20:09:54.855    debug.rhizome_tx=true
INFO: [ 1657] 20:09:54.855    log.console.level=debug
INFO: [ 1657] 20:09:54.855    log.console.show_pid=true
INFO: [ 1657] 20:09:54.855    log.console.show_time=true

Servald A Log:

INFO: [ 1647] 20:09:54.814 Serval DNA version: START-3692-gc05775a+b0661n0e17e@gmail.com-20161126194410
...
DEBUG:[ 1732] 20:09:56.703 overlay_interface.c:957:overlay_broadcast_ensemble()  {packettx} Sending this packet via interface /home/bernhard/servalpy.git/testlog/daemon.test_rhizome_inject/interfaces/dummy1 (len=78)
DEBUG:[ 1732] 20:09:56.703 overlay_interface.c:958:overlay_broadcast_ensemble()  <no message>: Packet body of 78 (0x4e) bytes:
DEBUG:[ 1732] 20:09:56.703 overlay_interface.c:958:overlay_broadcast_ensemble()      0000: 01 01 02 16 2e 01 07 06 00 44 23 00 01 7b 0c 43    .........D#..{.C
DEBUG:[ 1732] 20:09:56.703 overlay_interface.c:958:overlay_broadcast_ensemble()      0010: 1a 36 9f 21 1e f9 39 f7 1a af 30 cb 00 00 01 58    .6.!..9...0....X
DEBUG:[ 1732] 20:09:56.703 overlay_interface.c:958:overlay_broadcast_ensemble()      0020: a2 0b 3f b1 00 00 00 00 ff f0 ff f0 00 00 00 00    ..?.............
DEBUG:[ 1732] 20:09:56.703 overlay_interface.c:958:overlay_broadcast_ensemble()      0030: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00    ................
DEBUG:[ 1732] 20:09:56.703 overlay_interface.c:958:overlay_broadcast_ensemble()      0040: 00 00 00 00 00 00 00 00 00 00 00 00 00 00          ..............
DEBUG:[ 1732] 20:09:56.703 overlay_interface.c:958:overlay_broadcast_ensemble()    Packet Structure:
DEBUG:[ 1732] 20:09:56.703 overlay_interface.c:958:overlay_broadcast_ensemble()      Packet version 1 (0x01)
DEBUG:[ 1732] 20:09:56.703 overlay_interface.c:958:overlay_broadcast_ensemble()      Encapsulation (0x01); OVERLAY
DEBUG:[ 1732] 20:09:56.703 overlay_interface.c:958:overlay_broadcast_ensemble()      Sender; (0x02) 162E*
DEBUG:[ 1732] 20:09:56.703 overlay_interface.c:958:overlay_broadcast_ensemble()      Flags (0x01); UNICAST
DEBUG:[ 1732] 20:09:56.703 overlay_interface.c:958:overlay_broadcast_ensemble()        Flags (0x07); SENDER_SAME TO_BROADCAST ONE_HOP
DEBUG:[ 1732] 20:09:56.703 overlay_interface.c:958:overlay_broadcast_ensemble()        MDP Sequence; 0x06
DEBUG:[ 1732] 20:09:56.703 overlay_interface.c:958:overlay_broadcast_ensemble()        Payload length; 0x0044
DEBUG:[ 1732] 20:09:56.703 overlay_interface.c:958:overlay_broadcast_ensemble()          Destination Port (0x0023); 17 RHIZOME_SYNC
DEBUG:[ 1732] 20:09:56.703 overlay_interface.c:958:overlay_broadcast_ensemble()          Source Port; SAME
DEBUG:[ 1732] 20:09:56.703 overlay_interface.c:958:overlay_broadcast_ensemble()          Payload body;
DEBUG:[ 1732] 20:09:56.703 overlay_interface.c:958:overlay_broadcast_ensemble()            0000: 00 01 7b 0c 43 1a 36 9f 21 1e f9 39 f7 1a af 30    ..{.C.6.!..9...0
DEBUG:[ 1732] 20:09:56.703 overlay_interface.c:958:overlay_broadcast_ensemble()            0010: cb 00 00 01 58 a2 0b 3f b1 00 00 00 00 ff f0 ff    ....X..?........
DEBUG:[ 1732] 20:09:56.703 overlay_interface.c:958:overlay_broadcast_ensemble()            0020: f0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00    ................
DEBUG:[ 1732] 20:09:56.703 overlay_interface.c:958:overlay_broadcast_ensemble()            0030: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00    ................
DEBUG:[ 1732] 20:09:56.703 overlay_interface.c:958:overlay_broadcast_ensemble()            0040: 00 00 00                                           ...
DEBUG:[ 1732] 20:09:56.703 overlay_interface.c:970:overlay_broadcast_ensemble()  {overlayinterfaces} Sending 78 byte overlay frame on /home/bernhard/servalpy.git/testlog/daemon.test_rhizome_inject/interfaces/dummy1 to AF_INET:127.0.1.2:4110 [010102162E01070600442300017B0C431A369F211EF939F71AAF30CB00000158A20B3FB100000000FFF0FFF00000000000000000000000000000000000000000]
DEBUG:[ 1732] 20:09:56.703 overlay_interface.c:957:overlay_broadcast_ensemble()  {packettx} Sending this packet via interface /home/bernhard/servalpy.git/testlog/daemon.test_rhizome_inject/interfaces/dummy1 (len=78)
FATAL:[ 1732] 20:09:56.703 servald_main.c:61:crash_handler()  Caught signal SIGSEGV (11) Segmentation fault
FATAL:[ 1732] 20:09:56.703 servald_main.c:62:crash_handler()  The following clue may help: no clue
FATAL:[ 1732] 20:09:56.703 performance_timing.c:227:dump_stack()  overlay_fill_send_packet
FATAL:[ 1732] 20:09:56.703 performance_timing.c:227:dump_stack()  overlay_send_packet
FATAL:[ 1732] 20:09:56.703 performance_timing.c:227:dump_stack()  call_alarm
FATAL:[ 1732] 20:09:56.703 performance_timing.c:227:dump_stack()  fd_poll2
FATAL:[ 1732] 20:09:56.703 performance_timing.c:227:dump_stack()  server
FATAL:[ 1732] 20:09:56.703 performance_timing.c:227:dump_stack()  app_server_start
FATAL:[ 1732] 20:09:56.703 performance_timing.c:227:dump_stack()  cli_invoke
FATAL:[ 1732] 20:09:56.703 performance_timing.c:227:dump_stack()  commandline_main
FATAL:[ 1732] 20:09:56.703 servald_main.c:64:crash_handler()  GDB BACKTRACE
FATAL:[ 1732] 20:09:56.782 GDB Could not attach to process.  If your uid matches the uid of the target
FATAL:[ 1732] 20:09:56.782 GDB process, check the setting of /proc/sys/kernel/yama/ptrace_scope, or try
FATAL:[ 1732] 20:09:56.782 GDB again as the root user.  For more details, see /etc/sysctl.d/10-ptrace.conf
FATAL:[ 1732] 20:09:56.782 GDB ptrace: Operation not permitted.
FATAL:[ 1732] 20:09:56.782 GDB /tmp/tmpgut40aor/0/1732: No such file or directory.
FATAL:[ 1732] 20:09:56.782 GDB /tmp/tmpgut40aor/0/svld/servalgdb.YhDF3J:1: Error in sourced command file:
FATAL:[ 1732] 20:09:56.782 GDB No stack.
FATAL:[ 1732] 20:09:56.787 gdb exited normally with status 0
INFO: [ 1732] 20:09:56.788 servald_main.c:74:crash_handler()  Re-sending signal 11 to self

Servald B Log:

INFO: [ 1659] 20:09:54.860 Serval DNA version: START-3692-gc05775a+b0661n0e17e@gmail.com-20161126194410
...
DEBUG:[ 1716] 20:09:56.010 overlay_interface.c:957:overlay_broadcast_ensemble()  {packettx} Sending this packet via interface /home/bernhard/servalpy.git/testlog/daemon.test_rhizome_inject/interfaces/dummy1 (len=6)
DEBUG:[ 1716] 20:09:56.010 overlay_interface.c:958:overlay_broadcast_ensemble()  <no message>: Packet body of 6 (0x6) bytes:
DEBUG:[ 1716] 20:09:56.010 overlay_interface.c:958:overlay_broadcast_ensemble()      0000: 00 01 02 a6 e0 01                                  ......
DEBUG:[ 1716] 20:09:56.010 overlay_interface.c:958:overlay_broadcast_ensemble()    Packet Structure:
DEBUG:[ 1716] 20:09:56.010 overlay_interface.c:958:overlay_broadcast_ensemble()      Packet version 0 (0x00)
DEBUG:[ 1716] 20:09:56.010 overlay_interface.c:958:overlay_broadcast_ensemble()      Encapsulation (0x01); OVERLAY
DEBUG:[ 1716] 20:09:56.010 overlay_interface.c:958:overlay_broadcast_ensemble()      Sender; (0x02) A6E0*
DEBUG:[ 1716] 20:09:56.010 overlay_interface.c:958:overlay_broadcast_ensemble()      Flags (0x01); UNICAST
DEBUG:[ 1716] 20:09:56.010 overlay_interface.c:970:overlay_broadcast_ensemble()  {overlayinterfaces} Sending 6 byte overlay frame on /home/bernhard/servalpy.git/testlog/daemon.test_rhizome_inject/interfaces/dummy1 to AF_INET:127.0.1.1:4110 [000102A6E001]
...
DEBUG:[ 1716] 20:09:56.023 overlay_interface.c:957:overlay_broadcast_ensemble()  {packettx} Sending this packet via interface /home/bernhard/servalpy.git/testlog/daemon.test_rhizome_inject/interfaces/dummy1 (len=131)
FATAL:[ 1716] 20:09:56.023 servald_main.c:61:crash_handler()  Caught signal SIGSEGV (11) Segmentation fault
FATAL:[ 1716] 20:09:56.023 servald_main.c:62:crash_handler()  The following clue may help: no clue
FATAL:[ 1716] 20:09:56.023 performance_timing.c:227:dump_stack()  overlay_fill_send_packet
FATAL:[ 1716] 20:09:56.023 performance_timing.c:227:dump_stack()  overlay_send_packet
FATAL:[ 1716] 20:09:56.023 performance_timing.c:227:dump_stack()  call_alarm
FATAL:[ 1716] 20:09:56.023 performance_timing.c:227:dump_stack()  fd_poll2
FATAL:[ 1716] 20:09:56.023 performance_timing.c:227:dump_stack()  server
FATAL:[ 1716] 20:09:56.023 performance_timing.c:227:dump_stack()  app_server_start
FATAL:[ 1716] 20:09:56.023 performance_timing.c:227:dump_stack()  cli_invoke
FATAL:[ 1716] 20:09:56.023 performance_timing.c:227:dump_stack()  commandline_main
FATAL:[ 1716] 20:09:56.023 servald_main.c:64:crash_handler()  GDB BACKTRACE
FATAL:[ 1716] 20:09:56.152 GDB Could not attach to process.  If your uid matches the uid of the target
FATAL:[ 1716] 20:09:56.152 GDB process, check the setting of /proc/sys/kernel/yama/ptrace_scope, or try
FATAL:[ 1716] 20:09:56.152 GDB again as the root user.  For more details, see /etc/sysctl.d/10-ptrace.conf
FATAL:[ 1716] 20:09:56.152 GDB ptrace: Operation not permitted.
FATAL:[ 1716] 20:09:56.152 GDB /tmp/tmpgut40aor/1/1716: No such file or directory.
FATAL:[ 1716] 20:09:56.152 GDB /tmp/tmpgut40aor/1/svld/servalgdb.gCPc5S:1: Error in sourced command file:
FATAL:[ 1716] 20:09:56.154 GDB No stack.
FATAL:[ 1716] 20:09:56.164 gdb exited normally with status 0
INFO: [ 1716] 20:09:56.164 servald_main.c:74:crash_handler()  Re-sending signal 11 to self
b0661 commented 7 years ago

To find out the reason for the segfault I added the following test to rhizomeprotocol tests and it fails.

The only difference to test_FileTransfer is that the daemons are started before the bundle is added.

Am I doing something wrong here?

rhizomeprotocol:

doc_FileTransferRunningDaemon="Add bundle to running daemon and update transfer to one node"
setup_FileTransferRunningDaemon() {
   setup_common
   start_servald_instances +A +B
   foreach_instance +A assert_peers_are_instances +B
   foreach_instance +B assert_peers_are_instances +A
   set_instance +A
   rhizome_add_file file1 250000
   set_instance +B
}
test_FileTransferRunningDaemon() {
   receive_and_update_bundle
}

log.txt:

Name:     FileTransferRunningDaemon (rhizomeprotocol)
Result:   FAIL
Started:  2016-12-01 09:27:09.461
Finished: 2016-12-01 09:28:13.652
++++++++++ log.stdout ++++++++++
09:27:09.469 # SETUP
09:27:09.473 # call setup_FileTransferRunningDaemon()
09:27:09.487 # set instance = Z, number = 26
09:27:09.501 # assert no servald process(es) running
09:27:09.504 # set instance = A, number = 1
09:27:09.509 # executeOk --core-backtrace --executable=/tmp/_tfw-8855/var/servald/servald keyring add ''
09:27:09.537 # assert exit status (0) of (servald keyring add '') is 0
09:27:09.552 # assert stderr of () contains no error messages
09:27:09.556 # assert '[' -e /tmp/_tfw-8855/var/servald/instance/A/servald/serval.keyring ']'
09:27:09.563 SIDA1=C6EB33867C7D2AA584F61A4103D1501FB7AAC9792DA5085BD6DFB6B4D41CCA1E
09:27:09.566 # assert stdout of () contains valid 'sid:' line
09:27:09.573 IDA1=50D3FD5F70EE8779A16B80C3A766DBCFFA102609E864E92211747B7B44EBC37F
09:27:09.576 # assert stdout of () contains valid 'identity:' line
09:27:09.578 SIDA1=C6EB33867C7D2AA584F61A4103D1501FB7AAC9792DA5085BD6DFB6B4D41CCA1E
09:27:09.583 # executeOk --core-backtrace --executable=/tmp/_tfw-8855/var/servald/servald keyring set did C6EB33867C7D2AA584F61A4103D1501FB7AAC9792DA5085BD6DFB6B4D41CCA1E 5550001 'Agent A Smith'
09:27:09.625 # assert exit status (0) of (servald keyring set did C6EB33867C7D2AA584F61A4103D1501FB7AAC9792DA5085BD6DFB6B4D41CCA1E 5550001 'Agent A Smith') is 0
09:27:09.641 # assert stderr of () contains no error messages
09:27:09.644 DIDA1=5550001
09:27:09.648 NAMEA1='Agent A Smith'
09:27:09.651 # executeOk --core-backtrace --executable=/tmp/_tfw-8855/var/servald/servald keyring list
09:27:09.674 # assert exit status (0) of (servald keyring list) is 0
09:27:09.690 # assert stderr of () contains no error messages
09:27:09.700 # assert stdout of (servald keyring list) contains exactly 1 line matching "^C6EB33867C7D2AA584F61A4103D1501FB7AAC9792DA5085BD6DFB6B4D41CCA1E:50D3FD5F70EE8779A16B80C3A766DBCFFA102609E864E92211747B7B44EBC37F:5550001:Agent A Smith$"
09:27:09.704 SIDA=C6EB33867C7D2AA584F61A4103D1501FB7AAC9792DA5085BD6DFB6B4D41CCA1E
09:27:09.707 IDA=50D3FD5F70EE8779A16B80C3A766DBCFFA102609E864E92211747B7B44EBC37F
09:27:09.711 DIDA=5550001
09:27:09.714 NAMEA='Agent A Smith'
09:27:09.717 # set instance = B, number = 2
09:27:09.722 # executeOk --core-backtrace --executable=/tmp/_tfw-8855/var/servald/servald keyring add ''
09:27:09.750 # assert exit status (0) of (servald keyring add '') is 0
09:27:09.766 # assert stderr of () contains no error messages
09:27:09.770 # assert '[' -e /tmp/_tfw-8855/var/servald/instance/B/servald/serval.keyring ']'
09:27:09.777 SIDB1=38751DFC36B14322FCA6B6DCCC37B53BF3D97BFBDB8FF469675F01D00F347D2D
09:27:09.781 # assert stdout of () contains valid 'sid:' line
09:27:09.788 IDB1=5CD496109E694DBD1DBECB6BC6C0AB98AA1FA8597DEE8195CF3A5EA2DCA04B08
09:27:09.790 # assert stdout of () contains valid 'identity:' line
09:27:09.793 SIDB1=38751DFC36B14322FCA6B6DCCC37B53BF3D97BFBDB8FF469675F01D00F347D2D
09:27:09.797 # executeOk --core-backtrace --executable=/tmp/_tfw-8855/var/servald/servald keyring set did 38751DFC36B14322FCA6B6DCCC37B53BF3D97BFBDB8FF469675F01D00F347D2D 5550002 'Agent B Smith'
09:27:09.819 # assert exit status (0) of (servald keyring set did 38751DFC36B14322FCA6B6DCCC37B53BF3D97BFBDB8FF469675F01D00F347D2D 5550002 'Agent B Smith') is 0
09:27:09.836 # assert stderr of () contains no error messages
09:27:09.839 DIDB1=5550002
09:27:09.843 NAMEB1='Agent B Smith'
09:27:09.847 # executeOk --core-backtrace --executable=/tmp/_tfw-8855/var/servald/servald keyring list
09:27:09.869 # assert exit status (0) of (servald keyring list) is 0
09:27:09.885 # assert stderr of () contains no error messages
09:27:09.895 # assert stdout of (servald keyring list) contains exactly 1 line matching "^38751DFC36B14322FCA6B6DCCC37B53BF3D97BFBDB8FF469675F01D00F347D2D:5CD496109E694DBD1DBECB6BC6C0AB98AA1FA8597DEE8195CF3A5EA2DCA04B08:5550002:Agent B Smith$"
09:27:09.899 SIDB=38751DFC36B14322FCA6B6DCCC37B53BF3D97BFBDB8FF469675F01D00F347D2D
09:27:09.903 IDB=5CD496109E694DBD1DBECB6BC6C0AB98AA1FA8597DEE8195CF3A5EA2DCA04B08
09:27:09.906 DIDB=5550002
09:27:09.909 NAMEB='Agent B Smith'
09:27:09.912 # set instance = Z, number = 26
09:27:09.916 # set instance = B, number = 2
09:27:09.920 # start servald instances +A +B
09:27:09.923 # set instance = A, number = 1
09:27:09.929 # executeOk --core-backtrace --executable=/tmp/_tfw-8855/var/servald/servald config set server.interface_path /tmp/_tfw-8855/var/servald set interfaces.1.socket_type dgram set interfaces.1.file dummy1/A set interfaces.1.type wifi set interfaces.1.idle_tick_ms 500
09:27:09.947 # assert exit status (0) of (servald config set server.interface_path /tmp/_tfw-8855/var/servald set interfaces.1.socket_type dgram set interfaces.1.file dummy1/A set interfaces.1.type wifi set interfaces.1.idle_tick_ms 500) is 0
09:27:09.963 # assert stderr of () contains no error messages
09:27:09.967 # executeOk --core-backtrace --executable=/tmp/_tfw-8855/var/servald/servald config set log.console.level debug set log.console.show_pid on set log.console.show_time on set debug.rhizome on set debug.http_server on set debug.httpd on set debug.rhizome_manifest on set debug.rhizome_ads on set debug.rhizome_tx on set debug.rhizome_rx on set debug.rhizome_sync_keys on set debug.msp on
09:27:09.983 # assert exit status (0) of (servald config set log.console.level debug set log.console.show_pid on set log.console.show_time on set debug.rhizome on set debug.http_server on set debug.httpd on set debug.rhizome_manifest on set debug.rhizome_ads on set debug.rhizome_tx on set debug.rhizome_rx on set debug.rhizome_sync_keys on set debug.msp on) is 0
09:27:09.999 # assert stderr of () contains no error messages
09:27:10.010 # before_pids=
09:27:10.014 # executeOk --core-backtrace servald_start
09:27:10.239 # assert exit status (0) of (servald_start) is 0
09:27:10.255 start_instance_path=/tmp/_tfw-8855/var/servald/instance/A/servald
09:27:10.258 # assert stdout of () contains valid 'instancepath:' line
09:27:10.266 start_pid=9390
09:27:10.269 # assert stdout of () contains valid 'pid:' line
09:27:10.274 # assert '[' /tmp/_tfw-8855/var/servald/instance/A/servald = /tmp/_tfw-8855/var/servald/instance/A/servald ']'
09:27:10.286 # after_pids=9390
09:27:10.291 # set instance = A, number = 1
09:27:10.297 # assert get_servald_server_pidfile servald_pid
09:27:10.301 # assert servald pidfile was created
09:27:10.306 # assert servald pidfile contains a valid pid
09:27:10.311 # assert servald start command returned correct pid
09:27:10.314 # started servald process: pid=9390
09:27:10.318 # assert a new servald process is running
09:27:10.322 # assert servald pidfile process is running
09:27:10.326 # assert servald log file /tmp/_tfw-8855/var/servald/instance/A/servald.log is present
09:27:10.330 # Started servald server process A, pid=9390
09:27:10.334 # set instance = A, number = 1
09:27:10.338 # set instance = B, number = 2
09:27:10.345 # executeOk --core-backtrace --executable=/tmp/_tfw-8855/var/servald/servald config set server.interface_path /tmp/_tfw-8855/var/servald set interfaces.1.socket_type dgram set interfaces.1.file dummy1/B set interfaces.1.type wifi set interfaces.1.idle_tick_ms 500
09:27:10.360 # assert exit status (0) of (servald config set server.interface_path /tmp/_tfw-8855/var/servald set interfaces.1.socket_type dgram set interfaces.1.file dummy1/B set interfaces.1.type wifi set interfaces.1.idle_tick_ms 500) is 0
09:27:10.376 # assert stderr of () contains no error messages
09:27:10.382 # executeOk --core-backtrace --executable=/tmp/_tfw-8855/var/servald/servald config set log.console.level debug set log.console.show_pid on set log.console.show_time on set debug.rhizome on set debug.http_server on set debug.httpd on set debug.rhizome_manifest on set debug.rhizome_ads on set debug.rhizome_tx on set debug.rhizome_rx on set debug.rhizome_sync_keys on set debug.msp on
09:27:10.413 # assert exit status (0) of (servald config set log.console.level debug set log.console.show_pid on set log.console.show_time on set debug.rhizome on set debug.http_server on set debug.httpd on set debug.rhizome_manifest on set debug.rhizome_ads on set debug.rhizome_tx on set debug.rhizome_rx on set debug.rhizome_sync_keys on set debug.msp on) is 0
09:27:10.432 # assert stderr of () contains no error messages
09:27:10.444 # before_pids=9390
09:27:10.448 # executeOk --core-backtrace servald_start
09:27:10.670 # assert exit status (0) of (servald_start) is 0
09:27:10.686 start_instance_path=/tmp/_tfw-8855/var/servald/instance/B/servald
09:27:10.689 # assert stdout of () contains valid 'instancepath:' line
09:27:10.698 start_pid=9593
09:27:10.702 # assert stdout of () contains valid 'pid:' line
09:27:10.707 # assert '[' /tmp/_tfw-8855/var/servald/instance/B/servald = /tmp/_tfw-8855/var/servald/instance/B/servald ']'
09:27:10.718 # after_pids=9390
09:27:10.724 # set instance = B, number = 2
09:27:10.731 # assert get_servald_server_pidfile servald_pid
09:27:10.736 # assert servald pidfile was created
09:27:10.740 # assert servald pidfile contains a valid pid
09:27:10.745 # assert servald start command returned correct pid
09:27:10.748 # started servald process: pid=9593
09:27:10.753 # assert a new servald process is running
09:27:10.757 # assert servald pidfile process is running
09:27:10.761 # assert servald log file /tmp/_tfw-8855/var/servald/instance/B/servald.log is present
09:27:10.765 # Started servald server process B, pid=9593
09:27:10.768 # set instance = B, number = 2
09:27:10.773 # set instance = B, number = 2
09:27:10.778 # set instance = A, number = 1
09:27:10.783 # wait_until --sleep=0.25 has_seen_instances +A +B
09:27:10.790 # executeOk --core-backtrace --executable=/tmp/_tfw-8855/var/servald/servald route print
09:27:10.809 # assert exit status (0) of (servald route print) is 0
09:27:10.826 # assert stderr of () contains no error messages
09:27:11.834 # executeOk --core-backtrace --executable=/tmp/_tfw-8855/var/servald/servald route print
09:27:11.851 # assert exit status (0) of (servald route print) is 0
09:27:11.867 # assert stderr of () contains no error messages
38751DFC36B14322FCA6B6DCCC37B53BF3D97BFBDB8FF469675F01D00F347D2D:UNICAST:dummy1/A::
09:27:11.871 # waited for 1 seconds
09:27:11.874 # set instance = B, number = 2
09:27:11.879 # wait_until --sleep=0.25 has_seen_instances +A +B
09:27:11.886 # executeOk --core-backtrace --executable=/tmp/_tfw-8855/var/servald/servald route print
09:27:11.903 # assert exit status (0) of (servald route print) is 0
09:27:11.918 # assert stderr of () contains no error messages
C6EB33867C7D2AA584F61A4103D1501FB7AAC9792DA5085BD6DFB6B4D41CCA1E:UNICAST:dummy1/B::
09:27:11.922 # waited for 0 seconds
09:27:11.926 # set instance = B, number = 2
09:27:11.930 # set instance = B, number = 2
09:27:11.935 # set instance = A, number = 1
09:27:11.939 # executeOk --core-backtrace --executable=/tmp/_tfw-8855/var/servald/servald id allpeers
09:27:11.957 # assert exit status (0) of (servald id allpeers) is 0
09:27:11.972 # assert stderr of () contains no error messages
09:27:11.983 # assert stdout of (servald id allpeers) contains a line matching "38751DFC36B14322FCA6B6DCCC37B53BF3D97BFBDB8FF469675F01D00F347D2D"
09:27:11.986 # set instance = B, number = 2
09:27:11.991 # set instance = B, number = 2
09:27:11.996 # executeOk --core-backtrace --executable=/tmp/_tfw-8855/var/servald/servald id allpeers
09:27:12.013 # assert exit status (0) of (servald id allpeers) is 0
09:27:12.029 # assert stderr of () contains no error messages
09:27:12.039 # assert stdout of (servald id allpeers) contains a line matching "C6EB33867C7D2AA584F61A4103D1501FB7AAC9792DA5085BD6DFB6B4D41CCA1E"
09:27:12.042 # set instance = B, number = 2
09:27:12.046 # set instance = A, number = 1
09:27:12.052 # executeOk --core-backtrace --executable=/tmp/_tfw-8855/var/servald/servald rhizome add file C6EB33867C7D2AA584F61A4103D1501FB7AAC9792DA5085BD6DFB6B4D41CCA1E file1 file1.manifest
09:27:12.123 # assert exit status (0) of (servald rhizome add file C6EB33867C7D2AA584F61A4103D1501FB7AAC9792DA5085BD6DFB6B4D41CCA1E file1 file1.manifest) is 0
09:27:12.139 # assert stderr of () contains no error messages
09:27:12.143 # executeOk --core-backtrace --executable=/tmp/_tfw-8855/var/servald/servald rhizome list
09:27:12.166 # assert exit status (0) of (servald rhizome list) is 0
09:27:12.183 # assert stderr of () contains no error messages
09:27:12.190 # assert line 1 of stdout of (servald rhizome list) is -e '13\n'
09:27:12.197 # assert line 2 of stdout of (servald rhizome list) is -e '_id:service:id:version:date:.inserttime:.author:.fromhere:filesize:filehash:sender:recipient:name\n'
09:27:12.224 # assert stdout of (servald rhizome list) contains exactly 1 line matching "^[0-9]\{1,\}:file:49C1A206BA27DD317EE17920779B0012709DAC4AAA321B366319FAE781E0169B:1480580832065:1480580832065:[0-9]\{1,\}:C6EB33867C7D2AA584F61A4103D1501FB7AAC9792DA5085BD6DFB6B4D41CCA1E:1:250000:CEE03736CF975FAC42067551D468AE8C041D9B85A5D6E6C7ED4B694F2C40928451CF525FF2828F10C8213DEE183F7446C58261A07E01ADC3F58BB01DACF49CA8:::file1$"
09:27:12.236 # set instance = B, number = 2
09:27:12.240 # END SETUP
09:27:12.242 # CALL test_FileTransferRunningDaemon()
09:27:12.246 # wait_until bundle_received_by 49C1A206BA27DD317EE17920779B0012709DAC4AAA321B366319FAE781E0169B:1480580832065 +B
09:28:12.793 FAIL: timeout after 60 seconds
09:28:12.796 #----- shell backtrace -----
[0] wait_until() called from receive_and_update_bundle() at line 67 of ./rhizomeprotocol
[1] receive_and_update_bundle() called from test_FileTransferRunningDaemon() at line 105 of ./rhizomeprotocol
09:28:12.799 #-----
09:28:12.802 # FINALISE
09:28:12.806 # CALL finally(FileTransferRunningDaemon)
09:28:12.809 # set instance = A, number = 1
09:28:12.813 # set instance = A, number = 1
09:28:12.819 # set instance = B, number = 2
09:28:12.822 # set instance = B, number = 2
09:28:12.828 # set instance = Z, number = 26
09:28:12.832 # set instance = Z, number = 26
09:28:12.838 # missing pidfile /tmp/_tfw-8855/var/servald/instance/Z/servald/servald.pid
09:28:12.841 # set instance = B, number = 2
09:28:12.846 # set instance = A, number = 1
09:28:12.850 # set instance = A, number = 1
09:28:12.864 # before_pids=9390
09:28:12.868 # execute --core-backtrace /tmp/_tfw-8855/var/servald/servald stop
09:28:13.087 # exit status of (servald stop) = 0
09:28:13.102 stop_instance_path=/tmp/_tfw-8855/var/servald/instance/A/servald
09:28:13.105 # assert stdout of () contains valid 'instancepath:' line
09:28:13.110 # assert '[' /tmp/_tfw-8855/var/servald/instance/A/servald = /tmp/_tfw-8855/var/servald/instance/A/servald ']'
09:28:13.114 # assert exit status (0) of (servald stop) == 0
09:28:13.123 stop_pid=9390
09:28:13.126 # assert stdout of () contains valid 'pid:' line
09:28:13.132 # assert '[' 9390 = 9390 ']'
09:28:13.135 # Stopped servald server process A, pid=9390
09:28:13.146 # after_pids=9593
09:28:13.150 # assert servald pidfile was removed
09:28:13.154 # assert servald process still running
09:28:13.157 # ended servald process: pid=9390
09:28:13.160 # set instance = A, number = 1
09:28:13.164 # set instance = B, number = 2
09:28:13.169 # set instance = B, number = 2
09:28:13.185 # before_pids=9593
09:28:13.188 # execute --core-backtrace /tmp/_tfw-8855/var/servald/servald stop
09:28:13.403 # exit status of (servald stop) = 0
09:28:13.419 stop_instance_path=/tmp/_tfw-8855/var/servald/instance/B/servald
09:28:13.423 # assert stdout of () contains valid 'instancepath:' line
09:28:13.428 # assert '[' /tmp/_tfw-8855/var/servald/instance/B/servald = /tmp/_tfw-8855/var/servald/instance/B/servald ']'
09:28:13.433 # assert exit status (0) of (servald stop) == 0
09:28:13.441 stop_pid=9593
09:28:13.444 # assert stdout of () contains valid 'pid:' line
09:28:13.449 # assert '[' 9593 = 9593 ']'
09:28:13.452 # Stopped servald server process B, pid=9593
09:28:13.463 # after_pids=
09:28:13.467 # assert servald pidfile was removed
09:28:13.470 # ended servald process: pid=9593
09:28:13.474 # set instance = B, number = 2
09:28:13.478 # set instance = B, number = 2
09:28:13.483 # fork_terminate_all
09:28:13.487 # fork_wait_all
09:28:13.490 # END FINALLY
09:28:13.493 # TEARDOWN
09:28:13.496 # CALL teardown(FileTransferRunningDaemon)
09:28:13.517 # assert no servald process(es) running
09:28:13.520 # set instance = A, number = 1
09:28:13.524 #----- var/servald/instance/A/servald.log -----
INFO: [ 9388] 09:27:10.022 Local date/time: 2016-12-01 09:27:10 +0100
INFO: [ 9388] 09:27:10.022 Serval DNA version: START-3692-gc05775a+b0661n0e17e@gmail.com-20161127072751
INFO: [ 9388] 09:27:10.022 Current configuration:
INFO: [ 9388] 09:27:10.022    debug.http_server=true
INFO: [ 9388] 09:27:10.022    debug.httpd=true
INFO: [ 9388] 09:27:10.022    debug.msp=true
INFO: [ 9388] 09:27:10.022    debug.rhizome=true
INFO: [ 9388] 09:27:10.022    debug.rhizome_ads=true
INFO: [ 9388] 09:27:10.022    debug.rhizome_manifest=true
INFO: [ 9388] 09:27:10.022    debug.rhizome_rx=true
INFO: [ 9388] 09:27:10.022    debug.rhizome_sync_keys=true
INFO: [ 9388] 09:27:10.022    debug.rhizome_tx=true
INFO: [ 9388] 09:27:10.022    interfaces.1.file=dummy1/A
INFO: [ 9388] 09:27:10.022    interfaces.1.idle_tick_ms=500
INFO: [ 9388] 09:27:10.022    interfaces.1.socket_type=dgram
INFO: [ 9388] 09:27:10.022    log.console.level=debug
INFO: [ 9388] 09:27:10.022    log.console.show_pid=true
INFO: [ 9388] 09:27:10.022    log.console.show_time=true
INFO: [ 9388] 09:27:10.022    server.interface_path=/tmp/_tfw-8855/var/servald
INFO: [ 9388] 09:27:10.022 Logging to /tmp/_tfw-8855/var/servald/instance/A/servald.log (fd 0)
INFO: [ 9388] 09:27:10.022 server.c:791:app_server_start()  Starting background server without exec
INFO: [ 9390] 09:27:10.029 Local date/time: 2016-12-01 09:27:10 +0100
INFO: [ 9390] 09:27:10.029 Serval DNA version: START-3692-gc05775a+b0661n0e17e@gmail.com-20161127072751
INFO: [ 9390] 09:27:10.029 Current configuration:
INFO: [ 9390] 09:27:10.029    debug.http_server=true
INFO: [ 9390] 09:27:10.029    debug.httpd=true
INFO: [ 9390] 09:27:10.029    debug.msp=true
INFO: [ 9390] 09:27:10.029    debug.rhizome=true
INFO: [ 9390] 09:27:10.029    debug.rhizome_ads=true
INFO: [ 9390] 09:27:10.029    debug.rhizome_manifest=true
INFO: [ 9390] 09:27:10.029    debug.rhizome_rx=true
INFO: [ 9390] 09:27:10.029    debug.rhizome_sync_keys=true
INFO: [ 9390] 09:27:10.029    debug.rhizome_tx=true
INFO: [ 9390] 09:27:10.029    interfaces.1.file=dummy1/A
INFO: [ 9390] 09:27:10.029    interfaces.1.idle_tick_ms=500
INFO: [ 9390] 09:27:10.029    interfaces.1.socket_type=dgram
INFO: [ 9390] 09:27:10.029    log.console.level=debug
INFO: [ 9390] 09:27:10.029    log.console.show_pid=true
INFO: [ 9390] 09:27:10.029    log.console.show_time=true
INFO: [ 9390] 09:27:10.029    server.interface_path=/tmp/_tfw-8855/var/servald
INFO: [ 9390] 09:27:10.029 Logging to /tmp/_tfw-8855/var/servald/instance/A/servald.log (fd 8)
INFO: [ 9390] 09:27:10.029 overlay_mdp.c:223:mdp_bind_socket()  Socket mdp.socket: fd=4 AF_UNIX:abstract "\0tmp/_tfw-8855/var/servald/instance/A/servald/mdp.socket"
INFO: [ 9390] 09:27:10.030 overlay_mdp.c:223:mdp_bind_socket()  Socket mdp.2.socket: fd=9 AF_UNIX:abstract "\0tmp/_tfw-8855/var/servald/instance/A/servald/mdp.2.socket"
INFO: [ 9390] 09:27:10.030 monitor.c:140:monitor_setup_sockets()  Monitor socket: fd=10 AF_UNIX:abstract "\0tmp/_tfw-8855/var/servald/instance/A/servald/monitor.socket"
DEBUG:[ 9390] 09:27:10.030 httpd.c:122:httpd_server_start()  {httpd} Starting HTTP server
INFO: [ 9390] 09:27:10.030 httpd.c:191:httpd_server_start()  HTTP SERVER START port=4110 fd=11 services=RESTful,Rhizome
INFO: [ 9390] 09:27:10.030 server.c:455:server_write_proc_state()  mkdir `/tmp/_tfw-8855/var/servald/instance/A/servald/proc` (mode 0700)
INFO: [ 9390] 09:27:10.030 dna_helper.c:183:dna_helper_start()  DNAHELPER none configured
INFO: [ 9390] 09:27:10.030 overlay_interface.c:648:overlay_interface_init()  Interface dummy1/A addr AF_UNIX:"/tmp/_tfw-8855/var/servald/dummy1/A\0", is up
INFO: [ 9390] 09:27:10.030 overlay_interface.c:651:overlay_interface_init()  Allowing a maximum of 7 packets every 5ms
DEBUG:[ 9390] 09:27:10.030 rhizome_database.c:42:create_rhizome_store_dir()  {rhizome} Rhizome datastore path = `/tmp/_tfw-8855/var/servald/instance/A/servald/`
INFO: [ 9390] 09:27:10.030 rhizome_database.c:213:rhizome_opendb()  mkdir `/tmp/_tfw-8855/var/servald/instance/A/servald/blob` (mode 0700)
INFO: [ 9390] 09:27:10.030 rhizome_database.c:217:rhizome_opendb()  mkdir `/tmp/_tfw-8855/var/servald/instance/A/servald/hash` (mode 0700)
INFO: [ 9390] 09:27:10.030 rhizome_database.c:222:rhizome_opendb()  mkdir `/tmp/_tfw-8855/var/servald/instance/A/servald/sqlite3tmp` (mode 0700)
DEBUG:[ 9390] 09:27:10.030 rhizome_database.c:245:rhizome_opendb()  {rhizome} Rhizome will use 18446744073709551615B of storage for its database.
DEBUG:[ 9390] 09:27:10.030 rhizome_database.c:250:rhizome_opendb()  PRAGMA user_version;
DEBUG:[ 9390] 09:27:10.030 rhizome_database.c:250:rhizome_opendb()  rowcount=1 changes=0 result=0
DEBUG:[ 9390] 09:27:10.030 rhizome_database.c:257:rhizome_opendb()  PRAGMA auto_vacuum=2;
DEBUG:[ 9390] 09:27:10.055 rhizome_database.c:257:rhizome_opendb()  rowcount=0 changes=0
DEBUG:[ 9390] 09:27:10.056 rhizome_database.c:274:rhizome_opendb()  CREATE TABLE IF NOT EXISTS MANIFESTS(id text not null primary key, version integer, inserttime integer, filesize integer, filehash text, author text, bar blob, manifest blob, service text, name text, sender text collate nocase, recipient text collate nocase, tail integer, manifest_hash text collate nocase);
DEBUG:[ 9390] 09:27:10.077 rhizome_database.c:274:rhizome_opendb()  rowcount=0 changes=0
DEBUG:[ 9390] 09:27:10.077 rhizome_database.c:282:rhizome_opendb()  CREATE TABLE IF NOT EXISTS FILES(id text not null primary key, length integer, datavalid integer, inserttime integer, last_verified integer);
DEBUG:[ 9390] 09:27:10.099 rhizome_database.c:282:rhizome_opendb()  rowcount=0 changes=0
DEBUG:[ 9390] 09:27:10.099 rhizome_database.c:287:rhizome_opendb()  CREATE TABLE IF NOT EXISTS FILEBLOBS(id text not null primary key, data blob);
DEBUG:[ 9390] 09:27:10.121 rhizome_database.c:287:rhizome_opendb()  rowcount=0 changes=0
DEBUG:[ 9390] 09:27:10.121 rhizome_database.c:291:rhizome_opendb()  CREATE TABLE IF NOT EXISTS IDENTITY(uuid text not null);
DEBUG:[ 9390] 09:27:10.153 rhizome_database.c:291:rhizome_opendb()  rowcount=0 changes=0
DEBUG:[ 9390] 09:27:10.153 rhizome_database.c:296:rhizome_opendb()  CREATE INDEX IF NOT EXISTS bundlesizeindex ON manifests (filesize);
DEBUG:[ 9390] 09:27:10.175 rhizome_database.c:296:rhizome_opendb()  rowcount=0 changes=0
DEBUG:[ 9390] 09:27:10.176 rhizome_database.c:297:rhizome_opendb()  CREATE INDEX IF NOT EXISTS IDX_MANIFESTS_HASH ON MANIFESTS(filehash);
DEBUG:[ 9390] 09:27:10.215 rhizome_database.c:297:rhizome_opendb()  rowcount=0 changes=0
DEBUG:[ 9390] 09:27:10.215 rhizome_database.c:298:rhizome_opendb()  PRAGMA user_version=1;
DEBUG:[ 9390] 09:27:10.262 rhizome_database.c:298:rhizome_opendb()  rowcount=0 changes=0
DEBUG:[ 9390] 09:27:10.262 rhizome_database.c:308:rhizome_opendb()  CREATE INDEX IF NOT EXISTS IDX_MANIFESTS_ID_VERSION ON MANIFESTS(id, version);
DEBUG:[ 9390] 09:27:10.324 rhizome_database.c:308:rhizome_opendb()  rowcount=0 changes=0
DEBUG:[ 9390] 09:27:10.324 rhizome_database.c:309:rhizome_opendb()  PRAGMA user_version=3;
DEBUG:[ 9390] 09:27:10.424 rhizome_database.c:309:rhizome_opendb()  rowcount=0 changes=0
DEBUG:[ 9390] 09:27:10.424 rhizome_database.c:334:rhizome_opendb()  CREATE INDEX IF NOT EXISTS IDX_MANIFEST_HASH ON MANIFESTS(manifest_hash);
DEBUG:[ 9390] 09:27:10.458 rhizome_database.c:334:rhizome_opendb()  rowcount=0 changes=0
DEBUG:[ 9390] 09:27:10.458 rhizome_database.c:140:verify_bundles()  SELECT ROWID, MANIFEST FROM MANIFESTS ORDER BY ROWID DESC;
DEBUG:[ 9390] 09:27:10.458 rhizome_database.c:340:rhizome_opendb()  PRAGMA user_version=8;
DEBUG:[ 9390] 09:27:10.489 rhizome_database.c:340:rhizome_opendb()  rowcount=0 changes=0
DEBUG:[ 9390] 09:27:10.489 rhizome_database.c:350:rhizome_opendb()  SELECT uuid from IDENTITY LIMIT 1;
DEBUG:[ 9390] 09:27:10.489 rhizome_database.c:365:rhizome_opendb()  INSERT INTO IDENTITY (uuid) VALUES ('9baae83d-2743-4c38-a98f-37bb5fb98dea');
DEBUG:[ 9390] 09:27:10.527 rhizome_database.c:365:rhizome_opendb()  rowcount=0 changes=1
DEBUG:[ 9390] 09:27:10.527 rhizome_database.c:367:rhizome_opendb()  {rhizome} Set Rhizome database UUID to 9baae83d-2743-4c38-a98f-37bb5fb98dea
INFO: [ 9390] 09:27:10.527 rhizome_database.c:373:rhizome_opendb()  Opened Rhizome database /tmp/_tfw-8855/var/servald/instance/A/servald/rhizome.db, UUID=9baae83d-2743-4c38-a98f-37bb5fb98dea
INFO: [ 9390] 09:27:10.527 server.c:309:server_loop()  Server initialised, entering main loop
DEBUG:[ 9390] 09:27:10.891 rhizome_sync_keys.c:870:sync_neighbour_changed()  {rhizome_sync_keys} Queueing next message now
DEBUG:[ 9390] 09:27:10.891 rhizome_sync_keys.c:505:build_tree()  SELECT manifest_hash FROM manifests WHERE manifests.filehash IS NULL OR EXISTS(SELECT 1 FROM files WHERE files.id = manifests.filehash);
DEBUG:[ 9390] 09:27:10.891 rhizome_sync_keys.c:531:sync_send_keys()  {rhizome_sync_keys} Sending message
DEBUG:[ 9390] 09:27:10.891 rhizome_sync_keys.c:555:sync_send_keys()  {rhizome_sync_keys} Queueing next message for 5s
DEBUG:[ 9390] 09:27:10.896 rhizome_sync_keys.c:815:sync_keys_recv()  {rhizome_sync_keys} Processing message from 38751DFC36B14322FCA6B6DCCC37B53BF3D97BFBDB8FF469675F01D00F347D2D
DEBUG:[ 9390] 09:27:10.942 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:11.443 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:11.896 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:11.943 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:12.444 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:12.445 rhizome_database.c:1922:is_interesting()  SELECT filehash FROM MANIFESTS WHERE id LIKE '49C1A206BA27DD317EE17920779B00%' AND version >= 1480580832065
DEBUG:[ 9390] 09:27:12.445 rhizome_store.c:47:rhizome_exists()  SELECT COUNT(*) FROM FILES WHERE id = 'CEE03736CF975FAC42067551D468AE8C041D9B85A5D6E6C7ED4B694F2C40928451CF525FF2828F10C8213DEE183F7446C58261A07E01ADC3F58BB01DACF49CA8' and datavalid = 1;
DEBUG:[ 9390] 09:27:12.445 rhizome_store.c:47:rhizome_exists()  rowcount=1 changes=1 result=1
DEBUG:[ 9390] 09:27:12.445 rhizome_store.c:55:rhizome_exists()  SELECT rowid FROM FILEBLOBS WHERE id = 'CEE03736CF975FAC42067551D468AE8C041D9B85A5D6E6C7ED4B694F2C40928451CF525FF2828F10C8213DEE183F7446C58261A07E01ADC3F58BB01DACF49CA8'
DEBUG:[ 9390] 09:27:12.445 rhizome_store.c:55:rhizome_exists()  rowcount=0 changes=1 result=130
DEBUG:[ 9390] 09:27:12.896 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:12.946 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:13.047 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:13.047 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:13.047 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:13.047 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:13.047 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:13.047 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:13.448 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:13.896 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:13.948 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:14.449 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:14.897 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:14.950 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:15.450 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:15.898 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:15.898 rhizome_sync_keys.c:531:sync_send_keys()  {rhizome_sync_keys} Sending message
DEBUG:[ 9390] 09:27:15.898 rhizome_sync_keys.c:555:sync_send_keys()  {rhizome_sync_keys} Queueing next message for 5s
DEBUG:[ 9390] 09:27:15.939 rhizome_sync_keys.c:815:sync_keys_recv()  {rhizome_sync_keys} Processing message from 38751DFC36B14322FCA6B6DCCC37B53BF3D97BFBDB8FF469675F01D00F347D2D
DEBUG:[ 9390] 09:27:15.950 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:16.051 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:16.051 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:16.051 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:16.051 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:16.051 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:16.051 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:16.450 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:16.899 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:16.951 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:17.452 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:17.900 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:17.952 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:18.453 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:18.900 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:18.956 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:19.055 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:19.055 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:19.055 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:19.055 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:19.055 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:19.055 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:19.456 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:19.900 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:19.956 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:20.456 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:20.900 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:20.900 rhizome_sync_keys.c:531:sync_send_keys()  {rhizome_sync_keys} Sending message
DEBUG:[ 9390] 09:27:20.900 rhizome_sync_keys.c:555:sync_send_keys()  {rhizome_sync_keys} Queueing next message for 5s
DEBUG:[ 9390] 09:27:20.945 rhizome_sync_keys.c:815:sync_keys_recv()  {rhizome_sync_keys} Processing message from 38751DFC36B14322FCA6B6DCCC37B53BF3D97BFBDB8FF469675F01D00F347D2D
DEBUG:[ 9390] 09:27:20.957 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:21.459 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:21.901 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:21.960 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:22.056 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:22.056 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:22.056 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:22.056 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:22.056 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:22.056 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:22.460 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:22.901 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:22.960 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:23.460 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:23.906 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:23.960 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:24.460 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:24.906 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:24.961 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:25.056 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:25.056 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:25.056 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:25.056 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:25.056 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:25.056 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:25.461 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:25.907 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:25.907 rhizome_sync_keys.c:531:sync_send_keys()  {rhizome_sync_keys} Sending message
DEBUG:[ 9390] 09:27:25.907 rhizome_sync_keys.c:555:sync_send_keys()  {rhizome_sync_keys} Queueing next message for 5s
DEBUG:[ 9390] 09:27:25.946 rhizome_sync_keys.c:815:sync_keys_recv()  {rhizome_sync_keys} Processing message from 38751DFC36B14322FCA6B6DCCC37B53BF3D97BFBDB8FF469675F01D00F347D2D
DEBUG:[ 9390] 09:27:25.962 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:26.462 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:26.908 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:26.963 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:27.463 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:27.908 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:27.963 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:28.080 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:28.080 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:28.080 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:28.080 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:28.080 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:28.080 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:28.464 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:28.908 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:28.964 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:29.464 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:29.909 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:29.965 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:30.466 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:30.909 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:30.909 rhizome_sync_keys.c:531:sync_send_keys()  {rhizome_sync_keys} Sending message
DEBUG:[ 9390] 09:27:30.909 rhizome_sync_keys.c:555:sync_send_keys()  {rhizome_sync_keys} Queueing next message for 5s
DEBUG:[ 9390] 09:27:30.946 rhizome_sync_keys.c:815:sync_keys_recv()  {rhizome_sync_keys} Processing message from 38751DFC36B14322FCA6B6DCCC37B53BF3D97BFBDB8FF469675F01D00F347D2D
DEBUG:[ 9390] 09:27:30.966 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:31.437 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:31.437 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:31.437 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:31.437 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:31.437 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:31.437 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:31.467 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:31.910 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:31.967 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:32.469 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:32.910 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:32.970 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:33.470 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:33.910 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:33.971 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:34.440 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:34.440 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:34.440 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:34.440 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:34.440 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:34.440 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:34.471 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:34.910 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:34.971 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:35.472 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:35.911 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:35.911 rhizome_sync_keys.c:531:sync_send_keys()  {rhizome_sync_keys} Sending message
DEBUG:[ 9390] 09:27:35.911 rhizome_sync_keys.c:555:sync_send_keys()  {rhizome_sync_keys} Queueing next message for 5s
DEBUG:[ 9390] 09:27:35.948 rhizome_sync_keys.c:815:sync_keys_recv()  {rhizome_sync_keys} Processing message from 38751DFC36B14322FCA6B6DCCC37B53BF3D97BFBDB8FF469675F01D00F347D2D
DEBUG:[ 9390] 09:27:35.972 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:36.472 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:36.912 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:36.972 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:37.444 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:37.444 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:37.444 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:37.444 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:37.444 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:37.444 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:37.472 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:37.913 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:37.972 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:38.473 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:38.913 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:38.975 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:39.475 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:39.913 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:39.975 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:40.450 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:40.450 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:40.450 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:40.450 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:40.450 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:40.450 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:40.476 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:40.913 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:40.913 rhizome_sync_keys.c:531:sync_send_keys()  {rhizome_sync_keys} Sending message
DEBUG:[ 9390] 09:27:40.913 rhizome_sync_keys.c:555:sync_send_keys()  {rhizome_sync_keys} Queueing next message for 5s
DEBUG:[ 9390] 09:27:40.945 rhizome_sync_keys.c:815:sync_keys_recv()  {rhizome_sync_keys} Processing message from 38751DFC36B14322FCA6B6DCCC37B53BF3D97BFBDB8FF469675F01D00F347D2D
DEBUG:[ 9390] 09:27:40.976 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:41.476 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:41.914 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:41.979 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:42.479 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:42.915 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:42.979 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:43.453 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:43.453 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:43.453 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:43.453 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:43.453 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:43.453 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:43.480 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:43.915 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:43.980 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:44.480 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:44.916 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:44.980 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:45.480 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:45.917 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:45.917 rhizome_sync_keys.c:531:sync_send_keys()  {rhizome_sync_keys} Sending message
DEBUG:[ 9390] 09:27:45.917 rhizome_sync_keys.c:555:sync_send_keys()  {rhizome_sync_keys} Queueing next message for 5s
DEBUG:[ 9390] 09:27:45.946 rhizome_sync_keys.c:815:sync_keys_recv()  {rhizome_sync_keys} Processing message from 38751DFC36B14322FCA6B6DCCC37B53BF3D97BFBDB8FF469675F01D00F347D2D
DEBUG:[ 9390] 09:27:45.981 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:46.457 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:46.457 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:46.457 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:46.457 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:46.457 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:46.457 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:46.481 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:46.917 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:46.981 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:47.483 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:47.918 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:47.983 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:48.483 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:48.918 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:48.983 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:49.461 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:49.461 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:49.461 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:49.461 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:49.461 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:49.461 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:49.484 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:49.918 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:49.985 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:50.486 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:50.918 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:50.918 rhizome_sync_keys.c:531:sync_send_keys()  {rhizome_sync_keys} Sending message
DEBUG:[ 9390] 09:27:50.919 rhizome_sync_keys.c:555:sync_send_keys()  {rhizome_sync_keys} Queueing next message for 5s
DEBUG:[ 9390] 09:27:50.946 rhizome_sync_keys.c:815:sync_keys_recv()  {rhizome_sync_keys} Processing message from 38751DFC36B14322FCA6B6DCCC37B53BF3D97BFBDB8FF469675F01D00F347D2D
DEBUG:[ 9390] 09:27:50.987 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:51.487 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:51.918 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:51.987 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:52.464 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:52.464 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:52.464 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:52.464 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:52.464 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:52.464 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:52.487 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:52.919 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:52.987 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:53.487 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:53.919 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:53.987 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:54.487 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:54.921 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:54.988 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:55.466 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:55.466 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:55.466 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:55.466 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:55.466 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:55.466 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:55.488 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:55.921 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:55.921 rhizome_sync_keys.c:531:sync_send_keys()  {rhizome_sync_keys} Sending message
DEBUG:[ 9390] 09:27:55.921 rhizome_sync_keys.c:555:sync_send_keys()  {rhizome_sync_keys} Queueing next message for 5s
DEBUG:[ 9390] 09:27:55.947 rhizome_sync_keys.c:815:sync_keys_recv()  {rhizome_sync_keys} Processing message from 38751DFC36B14322FCA6B6DCCC37B53BF3D97BFBDB8FF469675F01D00F347D2D
DEBUG:[ 9390] 09:27:55.989 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:56.489 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:56.921 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:56.990 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:57.491 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:57.921 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:57.991 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:58.469 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:58.469 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:58.469 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:58.469 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:58.469 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:58.469 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:27:58.492 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:58.922 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:58.992 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:59.493 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:27:59.922 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:27:59.994 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:28:00.494 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:28:00.923 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:28:00.923 rhizome_sync_keys.c:531:sync_send_keys()  {rhizome_sync_keys} Sending message
DEBUG:[ 9390] 09:28:00.923 rhizome_sync_keys.c:555:sync_send_keys()  {rhizome_sync_keys} Queueing next message for 5s
DEBUG:[ 9390] 09:28:00.949 rhizome_sync_keys.c:815:sync_keys_recv()  {rhizome_sync_keys} Processing message from 38751DFC36B14322FCA6B6DCCC37B53BF3D97BFBDB8FF469675F01D00F347D2D
DEBUG:[ 9390] 09:28:00.995 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:28:01.470 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:28:01.470 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:28:01.470 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:28:01.470 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:28:01.470 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:28:01.470 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:28:01.496 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:28:01.923 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:28:01.996 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:28:02.497 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:28:02.924 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:28:02.997 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:28:03.498 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:28:03.925 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:28:03.998 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:28:04.474 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:28:04.474 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:28:04.474 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:28:04.474 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:28:04.474 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:28:04.474 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:28:04.499 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:28:04.925 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:28:05.000 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:28:05.501 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:28:05.927 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:28:05.927 rhizome_sync_keys.c:531:sync_send_keys()  {rhizome_sync_keys} Sending message
DEBUG:[ 9390] 09:28:05.927 rhizome_sync_keys.c:555:sync_send_keys()  {rhizome_sync_keys} Queueing next message for 5s
DEBUG:[ 9390] 09:28:05.951 rhizome_sync_keys.c:815:sync_keys_recv()  {rhizome_sync_keys} Processing message from 38751DFC36B14322FCA6B6DCCC37B53BF3D97BFBDB8FF469675F01D00F347D2D
DEBUG:[ 9390] 09:28:06.002 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:28:06.503 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:28:06.927 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:28:07.003 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:28:07.479 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:28:07.479 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:28:07.479 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:28:07.479 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:28:07.479 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:28:07.479 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:28:07.504 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:28:07.927 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:28:08.004 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:28:08.505 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:28:08.927 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:28:09.006 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:28:09.506 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:28:09.927 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:28:10.006 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:28:10.480 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:28:10.480 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:28:10.480 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:28:10.480 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:28:10.480 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:28:10.480 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9390] 09:28:10.508 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:28:10.927 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:28:10.927 rhizome_sync_keys.c:531:sync_send_keys()  {rhizome_sync_keys} Sending message
DEBUG:[ 9390] 09:28:10.927 rhizome_sync_keys.c:555:sync_send_keys()  {rhizome_sync_keys} Queueing next message for 5s
DEBUG:[ 9390] 09:28:10.951 rhizome_sync_keys.c:815:sync_keys_recv()  {rhizome_sync_keys} Processing message from 38751DFC36B14322FCA6B6DCCC37B53BF3D97BFBDB8FF469675F01D00F347D2D
DEBUG:[ 9390] 09:28:11.009 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:28:11.510 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:28:11.927 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9390] 09:28:12.010 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9390] 09:28:12.510 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
INFO: [ 9390] 09:28:12.874 server.c:689:signal_handler()  Caught signal SIGHUP (1) Hangup -- attempting clean shutdown
INFO: [ 9390] 09:28:12.874 server.c:315:server_loop()  Server finished, exiting main loop
INFO: [ 9390] 09:28:12.874 server.c:668:serverCleanUp()  Server cleaning up
INFO: [ 9390] 09:28:12.875 overlay_interface.c:96:overlay_interface_close()  Interface dummy1/A addr AF_UNIX:"/tmp/_tfw-8855/var/servald/dummy1/A\0" is down
DEBUG:[ 9390] 09:28:12.875 rhizome_sync_keys.c:874:sync_neighbour_changed()  {rhizome_sync_keys} Stop queueing messages
09:28:13.530 #-----
09:28:13.533 # set instance = B, number = 2
09:28:13.537 #----- var/servald/instance/B/servald.log -----
INFO: [ 9590] 09:27:10.456 Local date/time: 2016-12-01 09:27:10 +0100
INFO: [ 9590] 09:27:10.456 Serval DNA version: START-3692-gc05775a+b0661n0e17e@gmail.com-20161127072751
INFO: [ 9590] 09:27:10.456 Current configuration:
INFO: [ 9590] 09:27:10.456    debug.http_server=true
INFO: [ 9590] 09:27:10.456    debug.httpd=true
INFO: [ 9590] 09:27:10.456    debug.msp=true
INFO: [ 9590] 09:27:10.456    debug.rhizome=true
INFO: [ 9590] 09:27:10.456    debug.rhizome_ads=true
INFO: [ 9590] 09:27:10.456    debug.rhizome_manifest=true
INFO: [ 9590] 09:27:10.456    debug.rhizome_rx=true
INFO: [ 9590] 09:27:10.456    debug.rhizome_sync_keys=true
INFO: [ 9590] 09:27:10.456    debug.rhizome_tx=true
INFO: [ 9590] 09:27:10.456    interfaces.1.file=dummy1/B
INFO: [ 9590] 09:27:10.456    interfaces.1.idle_tick_ms=500
INFO: [ 9590] 09:27:10.456    interfaces.1.socket_type=dgram
INFO: [ 9590] 09:27:10.456    log.console.level=debug
INFO: [ 9590] 09:27:10.456    log.console.show_pid=true
INFO: [ 9590] 09:27:10.456    log.console.show_time=true
INFO: [ 9590] 09:27:10.456    server.interface_path=/tmp/_tfw-8855/var/servald
INFO: [ 9590] 09:27:10.456 Logging to /tmp/_tfw-8855/var/servald/instance/B/servald.log (fd 0)
INFO: [ 9590] 09:27:10.456 server.c:791:app_server_start()  Starting background server without exec
INFO: [ 9593] 09:27:10.463 Local date/time: 2016-12-01 09:27:10 +0100
INFO: [ 9593] 09:27:10.463 Serval DNA version: START-3692-gc05775a+b0661n0e17e@gmail.com-20161127072751
INFO: [ 9593] 09:27:10.463 Current configuration:
INFO: [ 9593] 09:27:10.463    debug.http_server=true
INFO: [ 9593] 09:27:10.463    debug.httpd=true
INFO: [ 9593] 09:27:10.463    debug.msp=true
INFO: [ 9593] 09:27:10.463    debug.rhizome=true
INFO: [ 9593] 09:27:10.463    debug.rhizome_ads=true
INFO: [ 9593] 09:27:10.463    debug.rhizome_manifest=true
INFO: [ 9593] 09:27:10.463    debug.rhizome_rx=true
INFO: [ 9593] 09:27:10.463    debug.rhizome_sync_keys=true
INFO: [ 9593] 09:27:10.463    debug.rhizome_tx=true
INFO: [ 9593] 09:27:10.463    interfaces.1.file=dummy1/B
INFO: [ 9593] 09:27:10.463    interfaces.1.idle_tick_ms=500
INFO: [ 9593] 09:27:10.463    interfaces.1.socket_type=dgram
INFO: [ 9593] 09:27:10.463    log.console.level=debug
INFO: [ 9593] 09:27:10.463    log.console.show_pid=true
INFO: [ 9593] 09:27:10.463    log.console.show_time=true
INFO: [ 9593] 09:27:10.463    server.interface_path=/tmp/_tfw-8855/var/servald
INFO: [ 9593] 09:27:10.463 Logging to /tmp/_tfw-8855/var/servald/instance/B/servald.log (fd 8)
INFO: [ 9593] 09:27:10.463 overlay_mdp.c:223:mdp_bind_socket()  Socket mdp.socket: fd=4 AF_UNIX:abstract "\0tmp/_tfw-8855/var/servald/instance/B/servald/mdp.socket"
INFO: [ 9593] 09:27:10.463 overlay_mdp.c:223:mdp_bind_socket()  Socket mdp.2.socket: fd=9 AF_UNIX:abstract "\0tmp/_tfw-8855/var/servald/instance/B/servald/mdp.2.socket"
INFO: [ 9593] 09:27:10.463 monitor.c:140:monitor_setup_sockets()  Monitor socket: fd=10 AF_UNIX:abstract "\0tmp/_tfw-8855/var/servald/instance/B/servald/monitor.socket"
DEBUG:[ 9593] 09:27:10.463 httpd.c:122:httpd_server_start()  {httpd} Starting HTTP server
INFO: [ 9593] 09:27:10.463 httpd.c:191:httpd_server_start()  HTTP SERVER START port=4111 fd=11 services=RESTful,Rhizome
INFO: [ 9593] 09:27:10.463 server.c:455:server_write_proc_state()  mkdir `/tmp/_tfw-8855/var/servald/instance/B/servald/proc` (mode 0700)
INFO: [ 9593] 09:27:10.463 dna_helper.c:183:dna_helper_start()  DNAHELPER none configured
INFO: [ 9593] 09:27:10.463 overlay_interface.c:648:overlay_interface_init()  Interface dummy1/B addr AF_UNIX:"/tmp/_tfw-8855/var/servald/dummy1/B\0", is up
INFO: [ 9593] 09:27:10.463 overlay_interface.c:651:overlay_interface_init()  Allowing a maximum of 7 packets every 5ms
DEBUG:[ 9593] 09:27:10.463 rhizome_database.c:42:create_rhizome_store_dir()  {rhizome} Rhizome datastore path = `/tmp/_tfw-8855/var/servald/instance/B/servald/`
INFO: [ 9593] 09:27:10.463 rhizome_database.c:213:rhizome_opendb()  mkdir `/tmp/_tfw-8855/var/servald/instance/B/servald/blob` (mode 0700)
INFO: [ 9593] 09:27:10.463 rhizome_database.c:217:rhizome_opendb()  mkdir `/tmp/_tfw-8855/var/servald/instance/B/servald/hash` (mode 0700)
INFO: [ 9593] 09:27:10.463 rhizome_database.c:222:rhizome_opendb()  mkdir `/tmp/_tfw-8855/var/servald/instance/B/servald/sqlite3tmp` (mode 0700)
DEBUG:[ 9593] 09:27:10.463 rhizome_database.c:245:rhizome_opendb()  {rhizome} Rhizome will use 18446744073709551615B of storage for its database.
DEBUG:[ 9593] 09:27:10.463 rhizome_database.c:250:rhizome_opendb()  PRAGMA user_version;
DEBUG:[ 9593] 09:27:10.463 rhizome_database.c:250:rhizome_opendb()  rowcount=1 changes=0 result=0
DEBUG:[ 9593] 09:27:10.464 rhizome_database.c:257:rhizome_opendb()  PRAGMA auto_vacuum=2;
DEBUG:[ 9593] 09:27:10.504 rhizome_database.c:257:rhizome_opendb()  rowcount=0 changes=0
DEBUG:[ 9593] 09:27:10.504 rhizome_database.c:274:rhizome_opendb()  CREATE TABLE IF NOT EXISTS MANIFESTS(id text not null primary key, version integer, inserttime integer, filesize integer, filehash text, author text, bar blob, manifest blob, service text, name text, sender text collate nocase, recipient text collate nocase, tail integer, manifest_hash text collate nocase);
DEBUG:[ 9593] 09:27:10.543 rhizome_database.c:274:rhizome_opendb()  rowcount=0 changes=0
DEBUG:[ 9593] 09:27:10.543 rhizome_database.c:282:rhizome_opendb()  CREATE TABLE IF NOT EXISTS FILES(id text not null primary key, length integer, datavalid integer, inserttime integer, last_verified integer);
DEBUG:[ 9593] 09:27:10.565 rhizome_database.c:282:rhizome_opendb()  rowcount=0 changes=0
DEBUG:[ 9593] 09:27:10.565 rhizome_database.c:287:rhizome_opendb()  CREATE TABLE IF NOT EXISTS FILEBLOBS(id text not null primary key, data blob);
DEBUG:[ 9593] 09:27:10.615 rhizome_database.c:287:rhizome_opendb()  rowcount=0 changes=0
DEBUG:[ 9593] 09:27:10.615 rhizome_database.c:291:rhizome_opendb()  CREATE TABLE IF NOT EXISTS IDENTITY(uuid text not null);
DEBUG:[ 9593] 09:27:10.640 rhizome_database.c:291:rhizome_opendb()  rowcount=0 changes=0
DEBUG:[ 9593] 09:27:10.640 rhizome_database.c:296:rhizome_opendb()  CREATE INDEX IF NOT EXISTS bundlesizeindex ON manifests (filesize);
DEBUG:[ 9593] 09:27:10.667 rhizome_database.c:296:rhizome_opendb()  rowcount=0 changes=0
DEBUG:[ 9593] 09:27:10.667 rhizome_database.c:297:rhizome_opendb()  CREATE INDEX IF NOT EXISTS IDX_MANIFESTS_HASH ON MANIFESTS(filehash);
DEBUG:[ 9593] 09:27:10.700 rhizome_database.c:297:rhizome_opendb()  rowcount=0 changes=0
DEBUG:[ 9593] 09:27:10.700 rhizome_database.c:298:rhizome_opendb()  PRAGMA user_version=1;
DEBUG:[ 9593] 09:27:10.738 rhizome_database.c:298:rhizome_opendb()  rowcount=0 changes=0
DEBUG:[ 9593] 09:27:10.738 rhizome_database.c:308:rhizome_opendb()  CREATE INDEX IF NOT EXISTS IDX_MANIFESTS_ID_VERSION ON MANIFESTS(id, version);
DEBUG:[ 9593] 09:27:10.771 rhizome_database.c:308:rhizome_opendb()  rowcount=0 changes=0
DEBUG:[ 9593] 09:27:10.771 rhizome_database.c:309:rhizome_opendb()  PRAGMA user_version=3;
DEBUG:[ 9593] 09:27:10.805 rhizome_database.c:309:rhizome_opendb()  rowcount=0 changes=0
DEBUG:[ 9593] 09:27:10.806 rhizome_database.c:334:rhizome_opendb()  CREATE INDEX IF NOT EXISTS IDX_MANIFEST_HASH ON MANIFESTS(manifest_hash);
DEBUG:[ 9593] 09:27:10.841 rhizome_database.c:334:rhizome_opendb()  rowcount=0 changes=0
DEBUG:[ 9593] 09:27:10.841 rhizome_database.c:140:verify_bundles()  SELECT ROWID, MANIFEST FROM MANIFESTS ORDER BY ROWID DESC;
DEBUG:[ 9593] 09:27:10.841 rhizome_database.c:340:rhizome_opendb()  PRAGMA user_version=8;
DEBUG:[ 9593] 09:27:10.862 rhizome_database.c:340:rhizome_opendb()  rowcount=0 changes=0
DEBUG:[ 9593] 09:27:10.862 rhizome_database.c:350:rhizome_opendb()  SELECT uuid from IDENTITY LIMIT 1;
DEBUG:[ 9593] 09:27:10.862 rhizome_database.c:365:rhizome_opendb()  INSERT INTO IDENTITY (uuid) VALUES ('17d10591-bc2f-496b-a7db-92447f86def0');
DEBUG:[ 9593] 09:27:10.884 rhizome_database.c:365:rhizome_opendb()  rowcount=0 changes=1
DEBUG:[ 9593] 09:27:10.884 rhizome_database.c:367:rhizome_opendb()  {rhizome} Set Rhizome database UUID to 17d10591-bc2f-496b-a7db-92447f86def0
INFO: [ 9593] 09:27:10.884 rhizome_database.c:373:rhizome_opendb()  Opened Rhizome database /tmp/_tfw-8855/var/servald/instance/B/servald/rhizome.db, UUID=17d10591-bc2f-496b-a7db-92447f86def0
INFO: [ 9593] 09:27:10.884 server.c:309:server_loop()  Server initialised, entering main loop
DEBUG:[ 9593] 09:27:10.891 rhizome_sync_keys.c:870:sync_neighbour_changed()  {rhizome_sync_keys} Queueing next message now
DEBUG:[ 9593] 09:27:10.891 rhizome_sync_keys.c:505:build_tree()  SELECT manifest_hash FROM manifests WHERE manifests.filehash IS NULL OR EXISTS(SELECT 1 FROM files WHERE files.id = manifests.filehash);
DEBUG:[ 9593] 09:27:10.891 rhizome_sync_keys.c:531:sync_send_keys()  {rhizome_sync_keys} Sending message
DEBUG:[ 9593] 09:27:10.891 rhizome_sync_keys.c:555:sync_send_keys()  {rhizome_sync_keys} Queueing next message for 5s
DEBUG:[ 9593] 09:27:10.896 rhizome_sync_keys.c:815:sync_keys_recv()  {rhizome_sync_keys} Processing message from C6EB33867C7D2AA584F61A4103D1501FB7AAC9792DA5085BD6DFB6B4D41CCA1E
DEBUG:[ 9593] 09:27:10.941 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:11.441 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:11.897 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:11.941 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:12.441 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:12.898 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:12.942 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:13.442 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:13.549 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:13.549 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:13.549 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:13.549 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:13.549 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:13.549 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:13.900 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:13.942 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:14.442 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:14.901 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:14.942 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:15.442 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:15.902 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:15.902 rhizome_sync_keys.c:531:sync_send_keys()  {rhizome_sync_keys} Sending message
DEBUG:[ 9593] 09:27:15.902 rhizome_sync_keys.c:555:sync_send_keys()  {rhizome_sync_keys} Queueing next message for 5s
DEBUG:[ 9593] 09:27:15.939 rhizome_sync_keys.c:815:sync_keys_recv()  {rhizome_sync_keys} Processing message from C6EB33867C7D2AA584F61A4103D1501FB7AAC9792DA5085BD6DFB6B4D41CCA1E
DEBUG:[ 9593] 09:27:15.943 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:16.444 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:16.550 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:16.550 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:16.550 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:16.551 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:16.551 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:16.551 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:16.903 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:16.945 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:17.445 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:17.903 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:17.946 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:18.447 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:18.905 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:18.951 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:19.451 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:19.556 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:19.556 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:19.556 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:19.556 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:19.556 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:19.556 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:19.909 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:19.951 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:20.451 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:20.910 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:20.910 rhizome_sync_keys.c:531:sync_send_keys()  {rhizome_sync_keys} Sending message
DEBUG:[ 9593] 09:27:20.910 rhizome_sync_keys.c:555:sync_send_keys()  {rhizome_sync_keys} Queueing next message for 5s
DEBUG:[ 9593] 09:27:20.945 rhizome_sync_keys.c:815:sync_keys_recv()  {rhizome_sync_keys} Processing message from C6EB33867C7D2AA584F61A4103D1501FB7AAC9792DA5085BD6DFB6B4D41CCA1E
DEBUG:[ 9593] 09:27:20.951 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:21.451 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:21.910 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:21.952 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:22.453 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:22.578 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:22.578 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:22.578 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:22.578 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:22.578 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:22.578 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:22.911 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:22.954 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:23.454 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:23.911 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:23.955 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:24.455 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:24.911 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:24.956 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:25.457 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:25.579 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:25.579 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:25.579 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:25.579 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:25.579 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:25.579 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:25.912 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:25.912 rhizome_sync_keys.c:531:sync_send_keys()  {rhizome_sync_keys} Sending message
DEBUG:[ 9593] 09:27:25.912 rhizome_sync_keys.c:555:sync_send_keys()  {rhizome_sync_keys} Queueing next message for 5s
DEBUG:[ 9593] 09:27:25.946 rhizome_sync_keys.c:815:sync_keys_recv()  {rhizome_sync_keys} Processing message from C6EB33867C7D2AA584F61A4103D1501FB7AAC9792DA5085BD6DFB6B4D41CCA1E
DEBUG:[ 9593] 09:27:25.958 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:26.459 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:26.912 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:26.959 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:27.459 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:27.913 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:27.959 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:28.460 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:28.914 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:28.914 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:28.914 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:28.914 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:28.914 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:28.914 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:28.914 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:28.960 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:29.461 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:29.915 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:29.961 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:30.462 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:30.917 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:30.917 rhizome_sync_keys.c:531:sync_send_keys()  {rhizome_sync_keys} Sending message
DEBUG:[ 9593] 09:27:30.917 rhizome_sync_keys.c:555:sync_send_keys()  {rhizome_sync_keys} Queueing next message for 5s
DEBUG:[ 9593] 09:27:30.946 rhizome_sync_keys.c:815:sync_keys_recv()  {rhizome_sync_keys} Processing message from C6EB33867C7D2AA584F61A4103D1501FB7AAC9792DA5085BD6DFB6B4D41CCA1E
DEBUG:[ 9593] 09:27:30.962 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:31.463 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:31.918 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:31.918 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:31.918 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:31.918 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:31.918 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:31.918 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:31.918 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:31.964 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:32.465 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:32.919 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:32.965 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:33.465 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:33.920 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:33.965 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:34.466 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:34.920 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:34.920 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:34.920 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:34.920 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:34.920 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:34.920 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:34.920 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:34.967 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:35.467 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:35.921 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:35.921 rhizome_sync_keys.c:531:sync_send_keys()  {rhizome_sync_keys} Sending message
DEBUG:[ 9593] 09:27:35.921 rhizome_sync_keys.c:555:sync_send_keys()  {rhizome_sync_keys} Queueing next message for 5s
DEBUG:[ 9593] 09:27:35.948 rhizome_sync_keys.c:815:sync_keys_recv()  {rhizome_sync_keys} Processing message from C6EB33867C7D2AA584F61A4103D1501FB7AAC9792DA5085BD6DFB6B4D41CCA1E
DEBUG:[ 9593] 09:27:35.967 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:36.470 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:36.922 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:36.970 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:37.471 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:37.923 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:37.923 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:37.923 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:37.923 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:37.923 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:37.923 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:37.923 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:37.972 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:38.473 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:38.924 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:38.975 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:39.476 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:39.925 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:39.976 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:40.476 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:40.927 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:40.927 rhizome_sync_keys.c:531:sync_send_keys()  {rhizome_sync_keys} Sending message
DEBUG:[ 9593] 09:27:40.927 rhizome_sync_keys.c:555:sync_send_keys()  {rhizome_sync_keys} Queueing next message for 5s
DEBUG:[ 9593] 09:27:40.927 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:40.927 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:40.927 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:40.927 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:40.927 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:40.927 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:40.950 rhizome_sync_keys.c:815:sync_keys_recv()  {rhizome_sync_keys} Processing message from C6EB33867C7D2AA584F61A4103D1501FB7AAC9792DA5085BD6DFB6B4D41CCA1E
DEBUG:[ 9593] 09:27:40.976 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:41.476 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:41.928 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:41.976 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:42.476 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:42.928 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:42.977 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:43.477 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:43.930 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:43.930 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:43.930 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:43.930 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:43.930 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:43.930 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:43.930 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:43.978 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:44.478 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:44.932 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:44.979 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:45.479 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:45.933 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:45.933 rhizome_sync_keys.c:531:sync_send_keys()  {rhizome_sync_keys} Sending message
DEBUG:[ 9593] 09:27:45.933 rhizome_sync_keys.c:555:sync_send_keys()  {rhizome_sync_keys} Queueing next message for 5s
DEBUG:[ 9593] 09:27:45.949 rhizome_sync_keys.c:815:sync_keys_recv()  {rhizome_sync_keys} Processing message from C6EB33867C7D2AA584F61A4103D1501FB7AAC9792DA5085BD6DFB6B4D41CCA1E
DEBUG:[ 9593] 09:27:45.980 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:46.481 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:46.935 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:46.935 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:46.935 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:46.935 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:46.935 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:46.935 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:46.935 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:46.982 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:47.483 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:47.939 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:47.983 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:48.483 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:48.940 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:48.983 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:49.484 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:49.940 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:49.940 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:49.940 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:49.940 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:49.940 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:49.940 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:49.940 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:49.985 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:50.486 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:50.941 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:50.941 rhizome_sync_keys.c:531:sync_send_keys()  {rhizome_sync_keys} Sending message
DEBUG:[ 9593] 09:27:50.941 rhizome_sync_keys.c:555:sync_send_keys()  {rhizome_sync_keys} Queueing next message for 5s
DEBUG:[ 9593] 09:27:50.949 rhizome_sync_keys.c:815:sync_keys_recv()  {rhizome_sync_keys} Processing message from C6EB33867C7D2AA584F61A4103D1501FB7AAC9792DA5085BD6DFB6B4D41CCA1E
DEBUG:[ 9593] 09:27:50.986 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:51.487 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:51.942 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:51.987 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:52.489 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:52.942 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:52.942 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:52.942 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:52.942 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:52.942 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:52.942 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:52.942 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:52.990 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:53.490 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:53.942 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:53.990 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:54.491 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:54.943 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:54.991 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:55.493 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:55.942 rhizome_sync_keys.c:531:sync_send_keys()  {rhizome_sync_keys} Sending message
DEBUG:[ 9593] 09:27:55.942 rhizome_sync_keys.c:555:sync_send_keys()  {rhizome_sync_keys} Queueing next message for 5s
DEBUG:[ 9593] 09:27:55.942 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:55.942 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:55.942 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:55.942 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:55.942 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:55.942 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:55.945 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:55.951 rhizome_sync_keys.c:815:sync_keys_recv()  {rhizome_sync_keys} Processing message from C6EB33867C7D2AA584F61A4103D1501FB7AAC9792DA5085BD6DFB6B4D41CCA1E
DEBUG:[ 9593] 09:27:55.994 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:56.494 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:56.945 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:56.996 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:57.496 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:57.945 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:57.996 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:58.496 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:58.946 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:58.947 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:58.947 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:58.947 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:58.947 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:58.947 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:58.947 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:27:58.996 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:59.496 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:27:59.947 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:27:59.996 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:28:00.497 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:28:00.943 rhizome_sync_keys.c:531:sync_send_keys()  {rhizome_sync_keys} Sending message
DEBUG:[ 9593] 09:28:00.943 rhizome_sync_keys.c:555:sync_send_keys()  {rhizome_sync_keys} Queueing next message for 5s
DEBUG:[ 9593] 09:28:00.947 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:28:00.951 rhizome_sync_keys.c:815:sync_keys_recv()  {rhizome_sync_keys} Processing message from C6EB33867C7D2AA584F61A4103D1501FB7AAC9792DA5085BD6DFB6B4D41CCA1E
DEBUG:[ 9593] 09:28:00.997 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:28:01.497 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:28:01.948 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:28:01.948 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:28:01.948 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:28:01.948 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:28:01.948 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:28:01.948 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:28:01.948 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:28:01.997 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:28:02.498 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:28:02.949 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:28:02.999 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:28:03.500 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:28:03.950 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:28:04.001 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:28:04.501 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:28:04.951 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:28:04.951 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:28:04.951 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:28:04.951 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:28:04.951 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:28:04.951 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:28:04.951 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:28:05.001 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:28:05.501 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:28:05.945 rhizome_sync_keys.c:531:sync_send_keys()  {rhizome_sync_keys} Sending message
DEBUG:[ 9593] 09:28:05.945 rhizome_sync_keys.c:555:sync_send_keys()  {rhizome_sync_keys} Queueing next message for 5s
DEBUG:[ 9593] 09:28:05.951 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:28:05.951 rhizome_sync_keys.c:815:sync_keys_recv()  {rhizome_sync_keys} Processing message from C6EB33867C7D2AA584F61A4103D1501FB7AAC9792DA5085BD6DFB6B4D41CCA1E
DEBUG:[ 9593] 09:28:06.002 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:28:06.503 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:28:06.952 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:28:07.003 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:28:07.504 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:28:07.953 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:28:07.953 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:28:07.953 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:28:07.953 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:28:07.953 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:28:07.953 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:28:07.953 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:28:08.004 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:28:08.505 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:28:08.954 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:28:09.006 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:28:09.506 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:28:09.954 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:28:10.006 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:28:10.507 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:28:10.945 rhizome_sync_keys.c:531:sync_send_keys()  {rhizome_sync_keys} Sending message
DEBUG:[ 9593] 09:28:10.945 rhizome_sync_keys.c:555:sync_send_keys()  {rhizome_sync_keys} Queueing next message for 5s
DEBUG:[ 9593] 09:28:10.951 rhizome_sync_keys.c:815:sync_keys_recv()  {rhizome_sync_keys} Processing message from C6EB33867C7D2AA584F61A4103D1501FB7AAC9792DA5085BD6DFB6B4D41CCA1E
DEBUG:[ 9593] 09:28:10.955 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:28:10.955 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 0, candidates 0 of 10 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:28:10.955 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 1, candidates 0 of 8 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:28:10.955 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 2, candidates 0 of 6 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:28:10.955 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 3, candidates 0 of 4 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:28:10.955 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 4, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:28:10.955 rhizome_fetch.c:181:rhizome_fetch_status()  {rhizome_rx} Fetch slot 5, candidates 0 of 2 0 bytes, FREE 0 of 0
DEBUG:[ 9593] 09:28:11.008 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:28:11.508 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:28:11.955 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:28:12.008 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:28:12.509 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
DEBUG:[ 9593] 09:28:12.955 rhizome_sync_keys.c:188:sync_keys_status()  {rhizome_sync_keys} Sync state;
DEBUG:[ 9593] 09:28:13.009 rhizome_sync.c:493:sync_send_response()  SELECT rowid, bar FROM manifests WHERE rowid <= 9223372036854775807 ORDER BY rowid DESC
INFO: [ 9593] 09:28:13.194 server.c:689:signal_handler()  Caught signal SIGHUP (1) Hangup -- attempting clean shutdown
INFO: [ 9593] 09:28:13.194 server.c:315:server_loop()  Server finished, exiting main loop
INFO: [ 9593] 09:28:13.194 server.c:668:serverCleanUp()  Server cleaning up
INFO: [ 9593] 09:28:13.194 overlay_interface.c:96:overlay_interface_close()  Interface dummy1/B addr AF_UNIX:"/tmp/_tfw-8855/var/servald/dummy1/B\0" is down
DEBUG:[ 9593] 09:28:13.194 rhizome_sync_keys.c:874:sync_neighbour_changed()  {rhizome_sync_keys} Stop queueing messages
09:28:13.542 #-----
09:28:13.545 # set instance = C, number = 3
09:28:13.549 # set instance = D, number = 4
09:28:13.554 # set instance = E, number = 5
09:28:13.558 # set instance = F, number = 6
09:28:13.562 # set instance = G, number = 7
09:28:13.566 # set instance = H, number = 8
09:28:13.570 # set instance = I, number = 9
09:28:13.574 # set instance = J, number = 10
09:28:13.578 # set instance = K, number = 11
09:28:13.583 # set instance = L, number = 12
09:28:13.587 # set instance = M, number = 13
09:28:13.591 # set instance = N, number = 14
09:28:13.595 # set instance = O, number = 15
09:28:13.599 # set instance = P, number = 16
09:28:13.603 # set instance = Q, number = 17
09:28:13.608 # set instance = R, number = 18
09:28:13.612 # set instance = S, number = 19
09:28:13.616 # set instance = T, number = 20
09:28:13.620 # set instance = U, number = 21
09:28:13.624 # set instance = V, number = 22
09:28:13.628 # set instance = W, number = 23
09:28:13.633 # set instance = X, number = 24
09:28:13.637 # set instance = Y, number = 25
09:28:13.641 # set instance = Z, number = 26
09:28:13.645 # set instance = B, number = 2
09:28:13.649 # END TEARDOWN
++++++++++
++++++++++ log.stderr ++++++++++
++++++++++
lakeman commented 7 years ago

Looks like this function is not doing it's job when the rhizome store was empty; https://github.com/servalproject/serval-dna/blob/30aa1c16b85a8c8362403d92d9d62b698e461333/rhizome_sync.c#L255

But that seems unrelated to your initial crash

b0661 commented 7 years ago

Thank you, I go on testing.

As valgrind and gdb bt sometimes indicated sqlite I tried sqlite 3.15.2. But it did not help in my case.

Here are the test results of 3.15.02 on X86_64. At least SQLite3 3.15.02 seems to be as good as the current SQLite 3.14.02 in servald-dna.

I had to remove -DSQLITE_OMIT_VIRTUALTABLE from the Makefile.

Non PASS test results :

Current - Current+SQLite3 3.15.02

109.crowded_mess: FAIL - PASS 117.forward: ERROR - ERROR 118.tcp_tunnel: ERROR - ERROR 121.terminate: ERROR - ERROR 220.DeleteManifest: FAIL - FAIL

b0661 commented 7 years ago

Managed to get a backtrace. Segmentation fault is in isOverlayPacket->(_dump->)xprintf->.

To make logBacktrace work on Ubuntu (normal user) I added gdb to the allowed commands for the user and changed the logBacktrace call to gdb to:

    execlp("sudo", "sudo", "gdb", "-n", "-batch", "-x", tempfile, "-p", pidstr, (void*)NULL);

Here are the logs: servald.A.txt servald.B.txt

b0661 commented 7 years ago

My current work around:

The fixes break rhizomeprotocol test [FAIL.] A missing payload should be re-fetched.

Don't know why a corrupted payload is re-fetched but a missing one not.

Hope that helps Bobby

b0661 commented 7 years ago

Added pull request #120 that replaces all patches mentioned above.