View Issue Details

Jump to NotesJump to History
IDProjectCategoryView StatusDate SubmittedLast Update
0005818GNUnetcadet servicepublic2019-07-23 14:402024-03-12 14:57
Reporterschanzen Assigned Toschanzen  
PrioritynormalSeverityminorReproducibilityhave not tried
Status closedResolutionnot fixable 
Fixed in Version0.21.0 
Summary0005818: test_cadet_2_keepalive needs rewrite WAS: test_cadet_2_keepalive always fails
DescriptionLooking at the test, it seems to run fine. But the success condition is odd:
/* Test is supposed to generate the following callbacks:
  * 1 incoming channel (@dest)
   * [wait]
    * 1 received channel destroy (@dest)
    */

This does not make sense as the test simply times out without incrementing the "ok" counter on channel destroy. Hence ok == 1 and never 2.
This should reliably fail though?
Steps To ReproduceJul 23 14:32:40-606276 test-92298 DEBUG DIRECT CONNECTIONs
Jul 23 14:32:40-609447 test_cadet_small-92298 DEBUG Starting HELPER process `/Users/schanzen/gnunet/build/lib//gnunet/libexec/gnunet-helper-testbed'
Jul 23 14:32:40-611112 test_cadet_small-92298 DEBUG Transmitted 4425 bytes to /Users/schanzen/gnunet/build/lib//gnunet/libexec/gnunet-helper-testbed
Jul 23 14:32:40-633349 test_cadet_small-92298 DEBUG Got 4522 bytes from helper `/Users/schanzen/gnunet/build/lib//gnunet/libexec/gnunet-helper-testbed'
Jul 23 14:32:40-872335 transport-92336 ERROR Assertion failed at nt.c:332.
Jul 23 14:32:40-873045 transport-udp-92336 WARNING Failed to join IPv6 multicast group: IPv6 broadcasting not running
Jul 23 14:32:40-873063 transport-92336 ERROR Assertion failed at nt.c:332.
Jul 23 14:32:40-873071 transport-udp-92336 WARNING Failed to join IPv6 multicast group: IPv6 broadcasting not running
Jul 23 14:32:40-879325 transport-92337 ERROR Assertion failed at nt.c:332.
Jul 23 14:32:40-879964 transport-udp-92337 WARNING Failed to join IPv6 multicast group: IPv6 broadcasting not running
Jul 23 14:32:40-880099 transport-92337 ERROR Assertion failed at nt.c:332.
Jul 23 14:32:40-880208 transport-udp-92337 WARNING Failed to join IPv6 multicast group: IPv6 broadcasting not running
Jul 23 14:32:40-885894 gnunet-rest-server-92326 ERROR `bind' failed at gnunet-rest-server.c:942 with error: Address already in use
Jul 23 14:32:40-890447 gnunet-rest-server-92327 ERROR `bind' failed at gnunet-rest-server.c:942 with error: Address already in use
Jul 23 14:32:40-901361 gnunet-rest-server-92327 ERROR `bind' failed at gnunet-rest-server.c:963 with error: Address already in use
Jul 23 14:32:40-901767 util-os-installation-92338 WARNING `access' failed on file `/Users/schanzen/gnunet/build/lib//gnunet/libexec/gnunet-helper-nat-server' at os_installation.c:938 with error: No such file or directory
Jul 23 14:32:40-902567 util-os-installation-92338 WARNING `access' failed on file `/Users/schanzen/gnunet/build/lib//gnunet/libexec/gnunet-helper-nat-server' at os_installation.c:938 with error: No such file or directory
Jul 23 14:32:40-907283 util-os-installation-92339 WARNING `access' failed on file `/Users/schanzen/gnunet/build/lib//gnunet/libexec/gnunet-helper-nat-server' at os_installation.c:938 with error: No such file or directory
Jul 23 14:32:40-907743 util-os-installation-92339 WARNING `access' failed on file `/Users/schanzen/gnunet/build/lib//gnunet/libexec/gnunet-helper-nat-server' at os_installation.c:938 with error: No such file or directory
Jul 23 14:32:40-927484 util-network-92337 WARNING `setsockopt' failed at network.c:355 with error: Invalid argument
Jul 23 14:32:40-927572 transport-udp-92337 WARNING UDP could not transmit message to `[fe80::1]:12035': `No route to host'
Jul 23 14:32:40-942732 transport-udp-92336 WARNING UDP could not transmit message to `[fe80::1c33:88ed:2960:3e2d]:12043': `No route to host'
Jul 23 14:32:40-942762 transport-udp-92336 WARNING UDP could not transmit message to `[fe80::aede:48ff:fe00:1122]:12043': `No route to host'
Jul 23 14:32:40-942774 transport-udp-92336 WARNING UDP could not transmit message to `[fe80::ed58:df6b:2fb6:8179]:12043': `No route to host'
Jul 23 14:32:40-942785 transport-udp-92336 WARNING UDP could not transmit message to `[fe80::74b5:23ff:fe6e:793d]:12043': `No route to host'
Jul 23 14:32:40-942795 transport-udp-92336 WARNING UDP could not transmit message to `[fe80::8d0:6427:a15d:80aa]:12043': `No route to host'
Jul 23 14:32:40-942806 transport-udp-92336 WARNING UDP could not transmit message to `[fe80::1]:12043': `No route to host'
Jul 23 14:32:40-942901 util-network-92336 WARNING `setsockopt' failed at network.c:355 with error: Invalid argument
Jul 23 14:32:40-969043 util-network-92336 WARNING `setsockopt' failed at network.c:355 with error: Invalid argument
Jul 23 14:32:40-970264 util-network-92337 WARNING `setsockopt' failed at network.c:355 with error: Invalid argument
Jul 23 14:32:40-970336 transport-udp-92337 WARNING UDP could not transmit message to `[fe80::1c33:88ed:2960:3e2d]:12035': `No route to host'
Jul 23 14:32:40-970358 transport-udp-92337 WARNING UDP could not transmit message to `[fe80::aede:48ff:fe00:1122]:12035': `No route to host'
Jul 23 14:32:40-970370 transport-udp-92337 WARNING UDP could not transmit message to `[fe80::ed58:df6b:2fb6:8179]:12035': `No route to host'
Jul 23 14:32:40-970381 transport-udp-92337 WARNING UDP could not transmit message to `[fe80::74b5:23ff:fe6e:793d]:12035': `No route to host'
Jul 23 14:32:40-970393 transport-udp-92337 WARNING UDP could not transmit message to `[fe80::8d0:6427:a15d:80aa]:12035': `No route to host'
Jul 23 14:32:40-975875 util-network-92336 WARNING `setsockopt' failed at network.c:355 with error: Invalid argument
Jul 23 14:32:40-991040 util-network-92336 WARNING `setsockopt' failed at network.c:355 with error: Invalid argument
Jul 23 14:32:40-998913 util-network-92337 WARNING `setsockopt' failed at network.c:355 with error: Invalid argument
Jul 23 14:32:41-008635 util-network-92337 WARNING `setsockopt' failed at network.c:355 with error: Invalid argument
Jul 23 14:32:41-031864 test_cadet_small-92298 DEBUG Testbed up, 2 peers and 1 links
Jul 23 14:32:41-031909 test_cadet_small-92298 INFO Connecting to cadet 0
Jul 23 14:32:41-031924 test_cadet_small-92298 INFO op handle 0x7fe6bdd00430
Jul 23 14:32:41-031928 test_cadet_small-92298 INFO Connecting to cadet 1
Jul 23 14:32:41-031934 test_cadet_small-92298 INFO op handle 0x7fe6bdd00620
Jul 23 14:32:41-038231 test_cadet_small-92298 DEBUG Listening to CADET port 38KQGBKV
Jul 23 14:32:41-038255 test_cadet_small-92298 INFO ...cadet 0 connected
Jul 23 14:32:41-038912 test_cadet_small-92298 DEBUG Listening to CADET port 38KQGBKV
Jul 23 14:32:41-038922 test_cadet_small-92298 INFO ...cadet 1 connected
Jul 23 14:32:41-038928 test_cadet_small-92298 DEBUG test main
Jul 23 14:32:41-038959 test_cadet_small-92298 DEBUG requested peer ids
Jul 23 14:32:41-039595 test_cadet_small-92298 DEBUG ID callback for 0
Jul 23 14:32:41-039613 test_cadet_small-92298 DEBUG id: 6DEV
Jul 23 14:32:41-040131 test_cadet_small-92298 DEBUG ID callback for 1
Jul 23 14:32:41-040154 test_cadet_small-92298 DEBUG id: 6YNB
Jul 23 14:32:41-040159 test_cadet_small-92298 DEBUG Got all IDs, starting test
Jul 23 14:32:41-040188 test_cadet_small-92298 DEBUG start_test: (null)
Jul 23 14:32:41-040196 test_cadet_small-92298 DEBUG Creating channel to peer 6YNB at port 38KQGBKV
Jul 23 14:32:42-090712 test_cadet_small-92298 INFO Incoming channel from 6DEV to 1: 0x7fe6bdc1f450
Jul 23 14:32:42-090777 test_cadet_small-92298 INFO ok: 1
Jul 23 14:33:02-096195 test_cadet_small-92298 INFO gathering statistics from line 952
Jul 23 14:33:02-096255 test_cadet_small-92298 INFO Destroying channel due to GNUNET_CADET_channel_destroy()
Jul 23 14:33:02-103272 test_cadet_small-92298 INFO STATS PEER 0 - cadet [# keepalives received]: 19
Jul 23 14:33:02-103337 test_cadet_small-92298 INFO STATS PEER 0 - cadet [# decrypted bytes]: 152
Jul 23 14:33:02-103374 test_cadet_small-92298 INFO STATS PEER 1 - cadet [# keepalives received]: 19
Jul 23 14:33:02-103389 test_cadet_small-92298 INFO STATS PEER 0 - cadet [# encrypted bytes]: 152
Jul 23 14:33:02-103414 test_cadet_small-92298 INFO STATS PEER 1 - cadet [# decrypted bytes]: 152
Jul 23 14:33:02-103426 test_cadet_small-92298 INFO STATS PEER 0 - cadet [# keepalives sent]: 19
Jul 23 14:33:02-103451 test_cadet_small-92298 INFO STATS PEER 1 - cadet [# encrypted bytes]: 152
Jul 23 14:33:02-103480 test_cadet_small-92298 INFO STATS PEER 1 - cadet [# keepalives sent]: 19
Jul 23 14:33:02-103509 test_cadet_small-92298 INFO STATS PEER 1 - cadet [# DHT announce]: 5
Jul 23 14:33:02-103777 test_cadet_small-92298 INFO STATS PEER 0 - cadet [# DHT announce]: 5
Jul 23 14:33:02-103858 test_cadet_small-92298 INFO STATS PEER 1 - cadet [# channels]: 2
Jul 23 14:33:02-103885 test_cadet_small-92298 INFO STATS PEER 0 - cadet [# KX_AUTH received]: 1
Jul 23 14:33:02-103897 test_cadet_small-92298 INFO STATS PEER 1 - cadet [# KX_AUTH transmitted]: 1
Jul 23 14:33:02-103916 test_cadet_small-92298 INFO STATS PEER 0 - cadet [# KX transmitted]: 1
Jul 23 14:33:02-103926 test_cadet_small-92298 INFO STATS PEER 1 - cadet [# Fresh KX setup]: 1
Jul 23 14:33:02-103942 test_cadet_small-92298 INFO STATS PEER 0 - cadet [# channels]: 1
Jul 23 14:33:02-103952 test_cadet_small-92298 INFO STATS PEER 1 - cadet [# KX received]: 1
Jul 23 14:33:02-103970 test_cadet_small-92298 INFO STATS PEER 0 - cadet [# DHT search]: 1
Jul 23 14:33:02-103981 test_cadet_small-92298 INFO STATS PEER 1 - cadet [# clients]: 1
Jul 23 14:33:02-104334 test_cadet_small-92298 DEBUG Cleaning all up
Jul 23 14:33:02-104644 test_cadet_small-92298 INFO STATS PEER 0 - cadet [# clients]: 1
Jul 23 14:33:02-104677 test_cadet_small-92298 INFO KA sent: 19, KA received: 19
Jul 23 14:33:02-105062 test_cadet_small-92298 DEBUG Cleaning all up
Jul 23 14:33:02-105275 test_cadet_small-92298 INFO disconnecting cadet service of peers, called from line 952
Jul 23 14:33:02-105293 test_cadet_small-92298 INFO Destroying channel due to GNUNET_CADET_channel_destroy()
Jul 23 14:33:02-106016 test_cadet_small-92298 DEBUG Ending test.
Jul 23 14:33:02-133134 test_cadet_small-92298 ERROR FAILED! (1/2)
TagsNo tags attached.
Attached Files

Activities

ch3

2019-07-23 15:41

developer   ~0014727

For me it looks like this:
Jul 23 15:31:40-907517 gnunet-rest-server-13886 ERROR `bind' failed at gnunet-rest-server.c:942 with error: Address already in use
Jul 23 15:31:40-907620 gnunet-rest-server-13886 ERROR `bind' failed at gnunet-rest-server.c:963 with error: Address already in use
Jul 23 15:31:40-934118 gnunet-rest-server-13882 ERROR `bind' failed at gnunet-rest-server.c:942 with error: Address already in use
Jul 23 15:31:40-946850 gnunet-rest-server-13882 ERROR `bind' failed at gnunet-rest-server.c:963 with error: Address already in use
Jul 23 15:32:02-479956 transport-api-core-13888 ERROR Error receiving from transport service (1), disconnecting temporarily.

Returning with a successful return value.

(I hat a gnunet peer running in parallel.)

ch3

2019-07-23 15:46

developer   ~0014728

Without running gnunet peer and debug messages enabled:

$ GNUNET_FORCE_LOG="test_cadet_small;;;;DEBUG" ./test_cadet_2_keepalive
Jul 23 15:42:10-346039 test-16447 DEBUG DIRECT CONNECTIONs
Jul 23 15:42:10-350543 test_cadet_small-16447 DEBUG Starting HELPER process `/home/gnunet/prefix_gn/lib//gnunet/libexec/gnunet-helper-testbed'
Jul 23 15:42:10-353270 test_cadet_small-16447 DEBUG Transmitted 5204 bytes to /home/gnunet/prefix_gn/lib//gnunet/libexec/gnunet-helper-testbed
Jul 23 15:42:10-371664 test_cadet_small-16447 DEBUG Got 5281 bytes from helper `/home/gnunet/prefix_gn/lib//gnunet/libexec/gnunet-helper-testbed'
Jul 23 15:42:10-493588 gnunet-rest-server-16482 ERROR `bind' failed at gnunet-rest-server.c:942 with error: Address already in use
Jul 23 15:42:10-493687 gnunet-rest-server-16482 ERROR `bind' failed at gnunet-rest-server.c:963 with error: Address already in use
Jul 23 15:42:10-521677 util-plugin-16475 ERROR `lt_dlopenext' failed for library `libgnunet_plugin_rest_identity_provider' with error: file not found
Jul 23 15:42:10-650032 test_cadet_small-16447 DEBUG Testbed up, 2 peers and 1 links
Jul 23 15:42:10-650094 test_cadet_small-16447 INFO Connecting to cadet 0
Jul 23 15:42:10-650131 test_cadet_small-16447 INFO op handle 0x55ecbc627f70
Jul 23 15:42:10-650151 test_cadet_small-16447 INFO Connecting to cadet 1
Jul 23 15:42:10-650173 test_cadet_small-16447 INFO op handle 0x55ecbc628390
Jul 23 15:42:10-657460 test_cadet_small-16447 DEBUG Listening to CADET port 38KQGBKV
Jul 23 15:42:10-657505 test_cadet_small-16447 INFO ...cadet 0 connected
Jul 23 15:42:10-659092 test_cadet_small-16447 DEBUG Listening to CADET port 38KQGBKV
Jul 23 15:42:10-659127 test_cadet_small-16447 INFO ...cadet 1 connected
Jul 23 15:42:10-659152 test_cadet_small-16447 DEBUG test main
Jul 23 15:42:10-659189 test_cadet_small-16447 DEBUG requested peer ids
Jul 23 15:42:10-661700 test_cadet_small-16447 DEBUG ID callback for 0
Jul 23 15:42:10-661739 test_cadet_small-16447 DEBUG id: 6DEV
Jul 23 15:42:10-661782 test_cadet_small-16447 DEBUG ID callback for 1
Jul 23 15:42:10-661803 test_cadet_small-16447 DEBUG id: 6YNB
Jul 23 15:42:10-661824 test_cadet_small-16447 DEBUG Got all IDs, starting test
Jul 23 15:42:10-661859 test_cadet_small-16447 DEBUG start_test: (null)
Jul 23 15:42:10-661887 test_cadet_small-16447 DEBUG Creating channel to peer 6YNB at port 38KQGBKV
Jul 23 15:42:11-736693 test_cadet_small-16447 INFO Incoming channel from 6DEV to 1: 0x55ecbc644900
Jul 23 15:42:11-736751 test_cadet_small-16447 INFO ok: 1
Jul 23 15:42:31-757008 test_cadet_small-16447 INFO gathering statistics from line 952
Jul 23 15:42:31-757164 test_cadet_small-16447 INFO Destroying channel due to GNUNET_CADET_channel_destroy()
Jul 23 15:42:31-772470 test_cadet_small-16447 INFO Channel disconnected at 1
Jul 23 15:42:31-772697 test_cadet_small-16447 INFO STATS PEER 0 - cadet [# encrypted bytes]: 164
Jul 23 15:42:31-772873 test_cadet_small-16447 INFO STATS PEER 1 - cadet [# decrypted bytes]: 164
Jul 23 15:42:31-772991 test_cadet_small-16447 INFO STATS PEER 0 - cadet [# keepalives received]: 19
Jul 23 15:42:31-773126 test_cadet_small-16447 INFO STATS PEER 0 - cadet [# decrypted bytes]: 152
Jul 23 15:42:31-773181 test_cadet_small-16447 INFO STATS PEER 1 - cadet [# keepalives received]: 19
Jul 23 15:42:31-773220 test_cadet_small-16447 INFO STATS PEER 0 - cadet [# keepalives sent]: 19
Jul 23 15:42:31-773270 test_cadet_small-16447 INFO STATS PEER 1 - cadet [# encrypted bytes]: 152
Jul 23 15:42:31-773307 test_cadet_small-16447 INFO STATS PEER 0 - cadet [# DHT announce]: 5
Jul 23 15:42:31-773356 test_cadet_small-16447 INFO STATS PEER 1 - cadet [# keepalives sent]: 19
Jul 23 15:42:31-773394 test_cadet_small-16447 INFO STATS PEER 0 - cadet [# KX_AUTH received]: 1
Jul 23 15:42:31-773442 test_cadet_small-16447 INFO STATS PEER 1 - cadet [# DHT announce]: 5
Jul 23 15:42:31-773480 test_cadet_small-16447 INFO STATS PEER 0 - cadet [# KX transmitted]: 1
Jul 23 15:42:31-773529 test_cadet_small-16447 INFO STATS PEER 1 - cadet [# channels]: 2
Jul 23 15:42:31-773565 test_cadet_small-16447 INFO STATS PEER 0 - cadet [# channels]: 1
Jul 23 15:42:31-773614 test_cadet_small-16447 INFO STATS PEER 1 - cadet [# KX_AUTH transmitted]: 1
Jul 23 15:42:31-773650 test_cadet_small-16447 INFO STATS PEER 0 - cadet [# DHT search]: 1
Jul 23 15:42:31-773698 test_cadet_small-16447 INFO STATS PEER 1 - cadet [# Fresh KX setup]: 1
Jul 23 15:42:31-773735 test_cadet_small-16447 INFO STATS PEER 0 - cadet [# clients]: 1
Jul 23 15:42:31-774011 test_cadet_small-16447 DEBUG Cleaning all up
Jul 23 15:42:31-774076 test_cadet_small-16447 INFO STATS PEER 1 - cadet [# KX received]: 1
Jul 23 15:42:31-774377 test_cadet_small-16447 INFO STATS PEER 1 - cadet [# clients]: 1
Jul 23 15:42:31-774439 test_cadet_small-16447 INFO KA sent: 19, KA received: 19
Jul 23 15:42:31-774700 test_cadet_small-16447 DEBUG Cleaning all up
Jul 23 15:42:31-774771 test_cadet_small-16447 INFO disconnecting cadet service of peers, called from line 952
Jul 23 15:42:31-775695 test_cadet_small-16447 DEBUG Ending test.
Jul 23 15:42:31-797608 test_cadet_small-16447 DEBUG success

schanzen

2019-07-23 16:44

administrator   ~0014730

Last edited: 2019-07-23 17:15

 test_cadet.c seems to think the CADET_channel_destroy() API still calls the disconnect callback. But it doesn't as of 7caba06019.
The whole test is thus build on a flawed assumption and probably must be rewritten.

schanzen

2019-07-23 16:59

administrator   ~0014731

This happens on both Debian 9 and macOS for me.

schanzen

2019-07-23 17:23

administrator   ~0014732

I shaved off the requirement of the disconnect ACKs in 91fa8e7cab1fdfcb4c52f79f459b899c7d9302f0 for now.
Still, this test needs be rewritten at some point...

xrs

2019-08-04 18:40

manager   ~0014771

test_cadet_2_keepalive only fails sometimes for me.

@schanzen: The success condition for this test is that keepalives have been seen by the receiving peer. This is done by asking gnunet-statistics. Thus, the two endpoints just have to establish a connection and do nothing and let cadet do the tunnel maintanance by processing keepalives.

Should we close this ticket?
test_cadet_2_keepalive.log (86,836 bytes)    
Aug 04 18:34:03-369674 test-21281 DEBUG DIRECT CONNECTIONs
Aug 04 18:34:03-372072 test_cadet_small-21281 DEBUG Starting HELPER process `/usr/local/lib//gnunet/libexec/gnunet-helper-testbed'
Aug 04 18:34:03-373575 test_cadet_small-21281 DEBUG Transmitted 4538 bytes to /usr/local/lib//gnunet/libexec/gnunet-helper-testbed
Aug 04 18:34:03-383651 test_cadet_small-21281 DEBUG Got 4561 bytes from helper `/usr/local/lib//gnunet/libexec/gnunet-helper-testbed'
Aug 04 18:34:03-427146 cadet-21302 INFO CADET started for peer 6YNB
Aug 04 18:34:03-432757 cadet-21308 INFO CADET started for peer 6DEV
Aug 04 18:34:03-439902 gnunet-rest-server-21309 ERROR `bind' failed at gnunet-rest-server.c:942 with error: Address in use
Aug 04 18:34:03-439963 gnunet-rest-server-21309 ERROR `bind' failed at gnunet-rest-server.c:963 with error: Address in use
Aug 04 18:34:03-467665 cadet-cor-21302 DEBUG CORE connection to peer 6YNB was established.
Aug 04 18:34:03-467706 cadet-per-21302 DEBUG Creating peer 6YNB
Aug 04 18:34:03-467725 cadet-per-21302 DEBUG Message queue for peer 6YNB is now 0x561205b82180
Aug 04 18:34:03-467745 cadet-per-21302 DEBUG Updating peer 6YNB activation state (0 connections) with CORE link
Aug 04 18:34:03-468104 cadet-cor-21308 DEBUG CORE connection to peer 6DEV was established.
Aug 04 18:34:03-468139 cadet-per-21308 DEBUG Creating peer 6DEV
Aug 04 18:34:03-468160 cadet-per-21308 DEBUG Message queue for peer 6DEV is now 0x55da60486180
Aug 04 18:34:03-468181 cadet-per-21308 DEBUG Updating peer 6DEV activation state (0 connections) with CORE link
Aug 04 18:34:03-469211 transport-udp-21310 WARNING UDP could not transmit message to `127.0.0.1:12037': `Operation not permitted'
Aug 04 18:34:03-469299 transport-udp-21310 WARNING UDP could not transmit message to `[fe80::90d5:8c2c:f50c:f9b0]:12037': `Operation not permitted'
Aug 04 18:34:03-469337 transport-udp-21310 WARNING UDP could not transmit message to `[fe80::d971:f2a:204c:7771]:12037': `Operation not permitted'
Aug 04 18:34:03-469371 transport-udp-21310 WARNING UDP could not transmit message to `[::1]:12037': `Operation not permitted'
Aug 04 18:34:03-476138 transport-udp-21317 WARNING UDP could not transmit message to `[fe80::90d5:8c2c:f50c:f9b0]:12045': `Operation not permitted'
Aug 04 18:34:03-476214 transport-udp-21317 WARNING UDP could not transmit message to `[fe80::d971:f2a:204c:7771]:12045': `Operation not permitted'
Aug 04 18:34:03-476259 transport-udp-21317 WARNING UDP could not transmit message to `[::1]:12045': `Operation not permitted'
Aug 04 18:34:03-481256 cadet-21302 DEBUG HELLO has 24 bytes of address data
Aug 04 18:34:03-481286 cadet-hll-21302 DEBUG Hello for 6DEV (64 bytes), expires on Mon Aug 05 06:34:03 2019
Aug 04 18:34:03-481306 cadet-per-21302 DEBUG Creating peer 6DEV
Aug 04 18:34:03-481330 cadet-per-21302 DEBUG Got 64 byte HELLO for peer 6DEV
Aug 04 18:34:03-481361 cadet-21302 DEBUG HELLO has 24 bytes of address data
Aug 04 18:34:03-483272 transport-udp-21317 WARNING UDP could not transmit message to `127.0.0.1:12045': `Operation not permitted'
Aug 04 18:34:03-489826 cadet-21302 DEBUG HELLO has 48 bytes of address data
Aug 04 18:34:03-489858 cadet-hll-21302 DEBUG Hello for 6DEV (88 bytes), expires on Mon Aug 05 06:34:03 2019
Aug 04 18:34:03-489876 cadet-per-21302 DEBUG Got 88 byte HELLO for peer 6DEV
Aug 04 18:34:03-489894 cadet-21302 DEBUG HELLO has 48 bytes of address data
Aug 04 18:34:03-489908 cadet-21302 DEBUG HELLO has 24 bytes of address data
Aug 04 18:34:03-489921 cadet-21302 DEBUG HELLO has 24 bytes of address data
Aug 04 18:34:03-489932 cadet-21302 DEBUG HELLO has 24 bytes of address data
Aug 04 18:34:03-489943 cadet-21302 DEBUG HELLO has 48 bytes of address data
Aug 04 18:34:03-489969 cadet-21302 DEBUG HELLO has 48 bytes of address data
Aug 04 18:34:03-501647 cadet-21308 DEBUG HELLO has 24 bytes of address data
Aug 04 18:34:03-501681 cadet-hll-21308 DEBUG Hello for 6YNB (64 bytes), expires on Mon Aug 05 06:34:03 2019
Aug 04 18:34:03-501702 cadet-per-21308 DEBUG Creating peer 6YNB
Aug 04 18:34:03-501727 cadet-per-21308 DEBUG Got 64 byte HELLO for peer 6YNB
Aug 04 18:34:03-501768 cadet-21308 DEBUG HELLO has 24 bytes of address data
Aug 04 18:34:03-511522 cadet-21308 DEBUG HELLO has 48 bytes of address data
Aug 04 18:34:03-511558 cadet-hll-21308 DEBUG Hello for 6YNB (88 bytes), expires on Mon Aug 05 06:34:03 2019
Aug 04 18:34:03-511577 cadet-per-21308 DEBUG Got 88 byte HELLO for peer 6YNB
Aug 04 18:34:03-511597 cadet-21308 DEBUG HELLO has 48 bytes of address data
Aug 04 18:34:03-511612 cadet-21308 DEBUG HELLO has 24 bytes of address data
Aug 04 18:34:03-511624 cadet-21308 DEBUG HELLO has 24 bytes of address data
Aug 04 18:34:03-511637 cadet-21308 DEBUG HELLO has 24 bytes of address data
Aug 04 18:34:03-511648 cadet-21308 DEBUG HELLO has 48 bytes of address data
Aug 04 18:34:03-511675 cadet-21308 DEBUG HELLO has 48 bytes of address data
Aug 04 18:34:03-531002 test_cadet_small-21281 DEBUG Testbed up, 2 peers and 1 links
Aug 04 18:34:03-531048 test_cadet_small-21281 INFO Connecting to cadet 0
Aug 04 18:34:03-531077 test_cadet_small-21281 INFO op handle 0x559a795b4ca0
Aug 04 18:34:03-531091 test_cadet_small-21281 INFO Connecting to cadet 1
Aug 04 18:34:03-531105 test_cadet_small-21281 INFO op handle 0x559a795b4d60
Aug 04 18:34:03-537050 cadet-api-21281 DEBUG GNUNET_CADET_connect()
Aug 04 18:34:03-537110 test_cadet_small-21281 DEBUG Listening to CADET port 38KQGBKV
Aug 04 18:34:03-537136 test_cadet_small-21281 INFO ...cadet 0 connected
Aug 04 18:34:03-537292 cadet-21308 DEBUG Client(0) connected
Aug 04 18:34:03-538490 cadet-api-21281 DEBUG GNUNET_CADET_connect()
Aug 04 18:34:03-538531 test_cadet_small-21281 DEBUG Listening to CADET port 38KQGBKV
Aug 04 18:34:03-538550 test_cadet_small-21281 INFO ...cadet 1 connected
Aug 04 18:34:03-538566 test_cadet_small-21281 DEBUG test main
Aug 04 18:34:03-538589 test_cadet_small-21281 DEBUG requested peer ids
Aug 04 18:34:03-538712 cadet-21308 DEBUG Open port 38KQGBKV requested by Client(0)
Aug 04 18:34:03-538733 cadet-21302 DEBUG Client(0) connected
Aug 04 18:34:03-538807 cadet-chn-21308 DEBUG Calculated port hash KG4KTP7M
Aug 04 18:34:03-538853 cadet-21302 DEBUG Open port 38KQGBKV requested by Client(0)
Aug 04 18:34:03-538955 cadet-chn-21302 DEBUG Calculated port hash Q16D1VZ8
Aug 04 18:34:03-541980 test_cadet_small-21281 DEBUG ID callback for 0
Aug 04 18:34:03-542033 test_cadet_small-21281 DEBUG id: 6DEV
Aug 04 18:34:03-542085 test_cadet_small-21281 DEBUG ID callback for 1
Aug 04 18:34:03-542112 test_cadet_small-21281 DEBUG id: 6YNB
Aug 04 18:34:03-542137 test_cadet_small-21281 DEBUG Got all IDs, starting test
Aug 04 18:34:03-542172 test_cadet_small-21281 DEBUG start_test: keepalive
Aug 04 18:34:03-542205 test_cadet_small-21281 DEBUG Creating channel to peer 6YNB at port 38KQGBKV
Aug 04 18:34:03-542293 cadet-21308 DEBUG New channel to 6YNB at port 38KQGBKV requested by Client(0)
Aug 04 18:34:03-542346 cadet-chn-21308 DEBUG Calculated port hash Q16D1VZ8
Aug 04 18:34:03-542377 cadet-tun-21308 DEBUG Creating new ephemeral ratchet key (DHRs)
Aug 04 18:34:03-547781 cadet-per-21308 DEBUG Updating peer 6YNB activation state (0 connections) with tunnel
Aug 04 18:34:03-547819 cadet-dht-21308 DEBUG Starting DHT GET for peer 6YNB (0x7f6099277240)
Aug 04 18:34:03-547843 cadet-tun-21308 DEBUG Adding Channel 6YNB:38KQGBKV ctn:0(80000000/0) to Tunnel 6YNB
Aug 04 18:34:03-547860 cadet-chn-21308 DEBUG Created channel to port 38KQGBKV at peer 6YNB for Client(0) using Tunnel 6YNB
Aug 04 18:34:03-547885 cadet-tun-21308 DEBUG Performing connection maintenance for Tunnel 6YNB.
Aug 04 18:34:03-547900 cadet-per-21308 DEBUG Iterating over paths to peer 6YNB
Aug 04 18:34:03-553915 cadet-21302 DEBUG HELLO has 180 bytes of address data
Aug 04 18:34:03-553971 cadet-dht-21302 DEBUG Announcing my HELLO (220 bytes) in the DHT
Aug 04 18:34:03-556260 cadet-21308 DEBUG HELLO has 180 bytes of address data
Aug 04 18:34:03-556293 cadet-dht-21308 DEBUG Announcing my HELLO (220 bytes) in the DHT
Aug 04 18:34:04-535120 cadet-cor-21302 DEBUG CORE connection to peer 6DEV was established.
Aug 04 18:34:04-535120 cadet-cor-21308 DEBUG CORE connection to peer 6YNB was established.
Aug 04 18:34:04-535264 cadet-per-21308 DEBUG Message queue for peer 6YNB is now 0x55da6047f5a0
Aug 04 18:34:04-535319 cadet-per-21308 DEBUG Updating peer 6YNB activation state (0 connections) with tunnel with CORE link
Aug 04 18:34:04-535379 cadet-dht-21308 DEBUG Stopping DHT GET 0x7f6099277240
Aug 04 18:34:04-535351 cadet-per-21302 DEBUG Message queue for peer 6DEV is now 0x561205b83920
Aug 04 18:34:04-535462 cadet-per-21308 DEBUG Asked to look for paths at distance 0, but maximum for me is < 0
Aug 04 18:34:04-535531 cadet-per-21308 DEBUG Discovered that peer 6YNB is on path 6YNB(0x55da60488c00) at offset 0
Aug 04 18:34:04-535549 cadet-per-21302 DEBUG Updating peer 6DEV activation state (0 connections) with CORE link
Aug 04 18:34:04-535598 cadet-tun-21308 DEBUG Considering 6YNB(0x55da60488c00) for Tunnel 6YNB (offset 0)
Aug 04 18:34:04-535665 cadet-tun-21308 DEBUG Evaluating proposed path 6YNB(0x55da60488c00) for target Tunnel 6YNB
Aug 04 18:34:04-535754 cadet-con-21308 DEBUG Creating Connection 8P5P2R (Tunnel 6YNB) using path 6YNB(0x55da60488c00) (offset: 0)
Aug 04 18:34:04-535822 cadet-pat-21308 DEBUG Adding Connection 8P5P2R (Tunnel 6YNB) to path 6YNB(0x55da60488c00) at offset 0
Aug 04 18:34:04-536883 cadet-per-21308 DEBUG Creating MQM 0x55da60488e60 for peer 6YNB
Aug 04 18:34:04-536996 cadet-con-21308 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6YNB) became available in state 0
Aug 04 18:34:04-537068 cadet-tun-21308 DEBUG Found interesting path 6YNB(0x55da60488c00) for Tunnel 6YNB, created Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:04-537246 cadet-pat-21308 DEBUG Created new path 6YNB(0x55da60488c00) to create inverse for incoming connection
Aug 04 18:34:04-537351 cadet-per-21308 DEBUG Attaching path 6YNB(0x55da60488c00) to peer 6YNB (forced)
Aug 04 18:34:04-537454 cadet-tun-21308 DEBUG Considering 6YNB(0x55da60488c00) for Tunnel 6YNB (offset 0)
Aug 04 18:34:04-537552 cadet-tun-21308 DEBUG Evaluating proposed path 6YNB(0x55da60488c00) for target Tunnel 6YNB
Aug 04 18:34:04-537655 cadet-tun-21308 DEBUG Evaluating path 6YNB(0x55da60488c00) of existing Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:04-537753 cadet-tun-21308 DEBUG Ignoring duplicate path 6YNB(0x55da60488c00).
Aug 04 18:34:04-537880 cadet-con-21308 DEBUG Sending CADET_CONNECTION_CREATE message for Connection 8P5P2R (Tunnel 6YNB) with 2 hops
Aug 04 18:34:04-537994 cadet-per-21308 DEBUG Queueing message to peer 6YNB in MQM 0x55da60488e60
Aug 04 18:34:04-538093 cadet-per-21308 DEBUG Sending to peer 6YNB from MQM 0x55da60488e60
Aug 04 18:34:04-538211 cadet-con-21308 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6YNB) became available in state 2
Aug 04 18:34:04-538824 cadet-per-21308 DEBUG Sending to peer 6YNB completed
Aug 04 18:34:04-540082 cadet-con-21308 DEBUG Sending CADET_CONNECTION_CREATE message for Connection 8P5P2R (Tunnel 6YNB) with 2 hops
Aug 04 18:34:04-540229 cadet-per-21308 DEBUG Queueing message to peer 6YNB in MQM 0x55da60488e60
Aug 04 18:34:04-540275 cadet-per-21308 DEBUG Sending to peer 6YNB from MQM 0x55da60488e60
Aug 04 18:34:04-540300 cadet-con-21308 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6YNB) became available in state 2
Aug 04 18:34:04-540384 cadet-per-21308 DEBUG Sending to peer 6YNB completed
Aug 04 18:34:04-540425 cadet-cor-21302 DEBUG Handling CADET_CONNECTION_CREATE from 6DEV for CID 8P5P2R with 2 hops
Aug 04 18:34:04-540462 cadet-cor-21302 DEBUG CADET_CONNECTION_CREATE has peer 6DEV at offset 0
Aug 04 18:34:04-540484 cadet-cor-21302 DEBUG CADET_CONNECTION_CREATE has peer 6YNB at offset 1
Aug 04 18:34:04-540510 cadet-cor-21302 DEBUG I am destination for CADET_CONNECTION_CREATE message from 6DEV for connection 8P5P2R, building inverse path
Aug 04 18:34:04-540531 cadet-per-21302 DEBUG Asked to look for paths at distance 0, but maximum for me is < 0
Aug 04 18:34:04-540557 cadet-per-21302 DEBUG Discovered that peer 6DEV is on path 6DEV(0x561205b7b600) at offset 0
Aug 04 18:34:04-540581 cadet-pat-21302 DEBUG Created new path 6DEV(0x561205b7b600) to create inverse for incoming connection
Aug 04 18:34:04-540605 cadet-per-21302 DEBUG Attaching path 6DEV(0x561205b7b600) to peer 6DEV (forced)
Aug 04 18:34:04-540666 cadet-tun-21302 DEBUG Creating new ephemeral ratchet key (DHRs)
Aug 04 18:34:04-544304 cadet-con-21308 DEBUG Sending CADET_CONNECTION_CREATE message for Connection 8P5P2R (Tunnel 6YNB) with 2 hops
Aug 04 18:34:04-544362 cadet-per-21308 DEBUG Queueing message to peer 6YNB in MQM 0x55da60488e60
Aug 04 18:34:04-544428 cadet-per-21308 DEBUG Sending to peer 6YNB from MQM 0x55da60488e60
Aug 04 18:34:04-544451 cadet-con-21308 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6YNB) became available in state 2
Aug 04 18:34:04-544529 cadet-per-21308 DEBUG Sending to peer 6YNB completed
Aug 04 18:34:04-548708 cadet-per-21302 DEBUG Updating peer 6DEV activation state (0 connections) with tunnel with CORE link
Aug 04 18:34:04-548766 cadet-con-21302 DEBUG Creating Connection 8P5P2R (Tunnel 6DEV) using path 6DEV(0x561205b7b600) (offset: 0)
Aug 04 18:34:04-548782 cadet-pat-21302 DEBUG Adding Connection 8P5P2R (Tunnel 6DEV) to path 6DEV(0x561205b7b600) at offset 0
Aug 04 18:34:04-548797 cadet-per-21302 DEBUG Creating MQM 0x561205b84ae0 for peer 6DEV
Aug 04 18:34:04-548844 cadet-con-21302 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6DEV) became available in state 3
Aug 04 18:34:04-548869 cadet-tun-21302 DEBUG Tunnel 6DEV has new Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:04-548906 cadet-tun-21302 DEBUG Performing connection maintenance for Tunnel 6DEV.
Aug 04 18:34:04-548926 cadet-tun-21302 DEBUG Evaluating path 6DEV(0x561205b7b600) of existing Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:04-548945 cadet-per-21302 DEBUG Iterating over paths to peer 6DEV including direct link
Aug 04 18:34:04-548964 cadet-pat-21302 DEBUG check_match found match with path 6DEV(0x561205b7b600)
Aug 04 18:34:04-548982 cadet-pat-21302 DEBUG Returning existing path 6DEV(0x561205b7b600) as inverse for incoming connection
Aug 04 18:34:04-549002 cadet-tun-21302 DEBUG Evaluating proposed path 6DEV(0x561205b7b600) for target Tunnel 6DEV
Aug 04 18:34:04-549021 cadet-tun-21302 DEBUG Evaluating path 6DEV(0x561205b7b600) of existing Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:04-549038 cadet-tun-21302 DEBUG Ignoring duplicate path 6DEV(0x561205b7b600).
Aug 04 18:34:04-549057 cadet-tun-21302 DEBUG Evaluating proposed path 6DEV(0x561205b7b600) for target Tunnel 6DEV
Aug 04 18:34:04-549076 cadet-tun-21302 DEBUG Evaluating path 6DEV(0x561205b7b600) of existing Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:04-549092 cadet-tun-21302 DEBUG Ignoring duplicate path 6DEV(0x561205b7b600).
Aug 04 18:34:04-549113 cadet-con-21302 DEBUG Sending CONNECTION_CREATE_ACK message for Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:04-549132 cadet-per-21302 DEBUG Queueing message to peer 6DEV in MQM 0x561205b84ae0
Aug 04 18:34:04-549150 cadet-per-21302 DEBUG Sending to peer 6DEV from MQM 0x561205b84ae0
Aug 04 18:34:04-549177 cadet-tun-21302 DEBUG Connection 8P5P2R (Tunnel 6DEV) now ready for Tunnel 6DEV in state CADET_TUNNEL_KEY_UNINITIALIZED
Aug 04 18:34:04-549194 cadet-con-21302 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6DEV) became available in state 4
Aug 04 18:34:04-549225 cadet-cor-21302 DEBUG Handling CADET_CONNECTION_CREATE from 6DEV for CID 8P5P2R with 2 hops
Aug 04 18:34:04-549240 cadet-cor-21302 DEBUG CADET_CONNECTION_CREATE has peer 6DEV at offset 0
Aug 04 18:34:04-549257 cadet-cor-21302 DEBUG CADET_CONNECTION_CREATE has peer 6YNB at offset 1
Aug 04 18:34:04-549277 cadet-cor-21302 DEBUG Received duplicate CADET_CONNECTION_CREATE message on connection 8P5P2R
Aug 04 18:34:04-549296 cadet-con-21302 DEBUG Got duplicate CREATE for Connection 8P5P2R (Tunnel 6DEV), scheduling another ACK (MQM ready)
Aug 04 18:34:04-549316 cadet-tun-21302 DEBUG Connection 8P5P2R (Tunnel 6DEV) no longer ready for Tunnel 6DEV
Aug 04 18:34:04-549348 cadet-cor-21302 DEBUG Handling CADET_CONNECTION_CREATE from 6DEV for CID 8P5P2R with 2 hops
Aug 04 18:34:04-549363 cadet-cor-21302 DEBUG CADET_CONNECTION_CREATE has peer 6DEV at offset 0
Aug 04 18:34:04-549381 cadet-cor-21302 DEBUG CADET_CONNECTION_CREATE has peer 6YNB at offset 1
Aug 04 18:34:04-549398 cadet-cor-21302 DEBUG Received duplicate CADET_CONNECTION_CREATE message on connection 8P5P2R
Aug 04 18:34:04-549427 cadet-con-21302 DEBUG Got duplicate CREATE for Connection 8P5P2R (Tunnel 6DEV), scheduling another ACK (MQM ready)
Aug 04 18:34:04-549457 cadet-per-21302 DEBUG Sending to peer 6DEV completed
Aug 04 18:34:04-550069 cadet-cor-21308 DEBUG Received CONNECTION_CREATE_ACK for connection 8P5P2R.
Aug 04 18:34:04-550115 cadet-con-21308 DEBUG Received CADET_CONNECTION_CREATE_ACK for Connection 8P5P2R (Tunnel 6YNB) in state 2 (MQM ready)
Aug 04 18:34:04-550215 cadet-tun-21308 DEBUG Connection 8P5P2R (Tunnel 6YNB) now ready for Tunnel 6YNB in state CADET_TUNNEL_KEY_UNINITIALIZED
Aug 04 18:34:04-551190 cadet-con-21302 DEBUG Sending CONNECTION_CREATE_ACK message for Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:04-551209 cadet-per-21302 DEBUG Queueing message to peer 6DEV in MQM 0x561205b84ae0
Aug 04 18:34:04-551236 cadet-per-21302 DEBUG Sending to peer 6DEV from MQM 0x561205b84ae0
Aug 04 18:34:04-551254 cadet-tun-21302 DEBUG Connection 8P5P2R (Tunnel 6DEV) now ready for Tunnel 6DEV in state CADET_TUNNEL_KEY_UNINITIALIZED
Aug 04 18:34:04-551269 cadet-con-21302 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6DEV) became available in state 4
Aug 04 18:34:04-551336 cadet-per-21302 DEBUG Sending to peer 6DEV completed
Aug 04 18:34:04-552313 cadet-tun-21308 DEBUG Sending KX message to Tunnel 6YNB with ephemeral R2V7NK on CID 8P5P2R
Aug 04 18:34:04-554552 cadet-tun-21308 DEBUG Tunnel 6YNB estate changed from CADET_TUNNEL_KEY_UNINITIALIZED to CADET_TUNNEL_KEY_AX_SENT
Aug 04 18:34:04-554580 cadet-con-21308 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:04-554596 cadet-per-21308 DEBUG Queueing message to peer 6YNB in MQM 0x55da60488e60
Aug 04 18:34:04-554618 cadet-per-21308 DEBUG P2P forwarding KX with ephemeral R2V7NK to 6YNB on CID 8P5P2R
Aug 04 18:34:04-554643 cadet-per-21308 DEBUG Sending to peer 6YNB from MQM 0x55da60488e60
Aug 04 18:34:04-554672 cadet-tun-21308 DEBUG Connection 8P5P2R (Tunnel 6YNB) now ready for Tunnel 6YNB in state CADET_TUNNEL_KEY_AX_SENT
Aug 04 18:34:04-554707 cadet-con-21308 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6YNB) became available in state 4
Aug 04 18:34:04-554734 cadet-con-21308 DEBUG Scheduling keepalive for Connection 8P5P2R (Tunnel 6YNB) in 1 s
Aug 04 18:34:04-554780 cadet-cor-21308 DEBUG Received CONNECTION_CREATE_ACK for connection 8P5P2R.
Aug 04 18:34:04-554800 cadet-con-21308 DEBUG Received CADET_CONNECTION_CREATE_ACK for Connection 8P5P2R (Tunnel 6YNB) in state 4 (MQM ready)
Aug 04 18:34:04-554828 cadet-per-21308 DEBUG Sending to peer 6YNB completed
Aug 04 18:34:04-555315 cadet-cor-21302 DEBUG Routing KX with ephemeral R2V7NK on CID 8P5P2R
Aug 04 18:34:04-555366 cadet-con-21302 DEBUG Received KX message with ephermal R2V7NK on CC 8P5P2R in state 4
Aug 04 18:34:04-555415 cadet-tun-21302 DEBUG Received KX message from Tunnel 6DEV with ephemeral R2V7NK from 6DEV on connection Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:04-555445 cadet-tun-21302 DEBUG Creating fresh unverified KX for Tunnel 6DEV
Aug 04 18:34:04-562945 cadet-tun-21302 DEBUG Tunnel 6DEV estate changed from CADET_TUNNEL_KEY_UNINITIALIZED to CADET_TUNNEL_KEY_AX_RECV
Aug 04 18:34:04-563001 cadet-tun-21302 DEBUG Trying to make KX progress on Tunnel 6DEV in state CADET_TUNNEL_KEY_AX_RECV
Aug 04 18:34:04-566160 cadet-tun-21302 DEBUG Sending KX_AUTH message to Tunnel 6DEV with ephemeral C231V0 on CID 8P5P2R
Aug 04 18:34:04-566180 cadet-tun-21302 DEBUG Tunnel 6DEV estate changed from CADET_TUNNEL_KEY_AX_RECV to CADET_TUNNEL_KEY_AX_AUTH_SENT
Aug 04 18:34:04-566194 cadet-con-21302 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:04-566205 cadet-per-21302 DEBUG Queueing message to peer 6DEV in MQM 0x561205b84ae0
Aug 04 18:34:04-566247 cadet-per-21302 DEBUG Sending to peer 6DEV from MQM 0x561205b84ae0
Aug 04 18:34:04-566271 cadet-tun-21302 DEBUG Connection 8P5P2R (Tunnel 6DEV) now ready for Tunnel 6DEV in state CADET_TUNNEL_KEY_AX_AUTH_SENT
Aug 04 18:34:04-566302 cadet-con-21302 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6DEV) became available in state 4
Aug 04 18:34:04-566327 cadet-con-21302 DEBUG Scheduling keepalive for Connection 8P5P2R (Tunnel 6DEV) in 1 s
Aug 04 18:34:04-566423 cadet-per-21302 DEBUG Sending to peer 6DEV completed
Aug 04 18:34:04-567717 cadet-con-21308 DEBUG Received KX AUTH message with ephermal C231V0 on CC 8P5P2R in state 4
Aug 04 18:34:04-567780 cadet-tun-21308 DEBUG Handling KX_AUTH message from Tunnel 6YNB with ephemeral C231V0
Aug 04 18:34:04-573097 cadet-tun-21308 DEBUG Tunnel 6YNB estate changed from CADET_TUNNEL_KEY_AX_SENT to CADET_TUNNEL_KEY_OK
Aug 04 18:34:04-573122 cadet-chn-21308 DEBUG Tunnel up, sending CHANNEL_OPEN on Channel 6YNB:38KQGBKV ctn:0(80000000/0) now
Aug 04 18:34:04-573158 cadet-chn-21308 DEBUG Sending CHANNEL_OPEN message for Channel 6YNB:38KQGBKV ctn:0(80000000/0)
Aug 04 18:34:04-573176 cadet-tun-21308 DEBUG Encrypting 76 bytes for Tunnel 6YNB
Aug 04 18:34:04-573192 cadet-tun-21308 DEBUG Creating new ephemeral ratchet key (DHRs)
Aug 04 18:34:04-579272 cadet-tun-21308 DEBUG Sending payload of Tunnel 6YNB on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:04-579300 cadet-con-21308 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:04-579326 cadet-per-21308 DEBUG Queueing message to peer 6YNB in MQM 0x55da60488e60
Aug 04 18:34:04-579338 cadet-per-21308 DEBUG Sending to peer 6YNB from MQM 0x55da60488e60
Aug 04 18:34:04-579356 cadet-tun-21308 DEBUG Connection 8P5P2R (Tunnel 6YNB) now ready for Tunnel 6YNB in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:04-579396 cadet-tun-21308 DEBUG Not sending payload of Tunnel 6YNB on ready Connection 8P5P2R (Tunnel 6YNB) (nothing pending)
Aug 04 18:34:04-579415 cadet-con-21308 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6YNB) became available in state 4
Aug 04 18:34:04-579466 cadet-con-21308 DEBUG Scheduling keepalive for Connection 8P5P2R (Tunnel 6YNB) in 1 s
Aug 04 18:34:04-579522 cadet-chn-21308 DEBUG Sent CADET_CHANNEL_OPEN on Channel 6YNB:38KQGBKV ctn:0(80000000/0), retrying in 500 ms
Aug 04 18:34:04-579670 cadet-per-21308 DEBUG Sending to peer 6YNB completed
Aug 04 18:34:04-580504 cadet-tun-21302 DEBUG Tunnel 6DEV received 188 bytes of encrypted data in state 4
Aug 04 18:34:04-580825 cadet-tun-21302 DEBUG Storing skipped keys [0, 0)
Aug 04 18:34:04-582781 cadet-tun-21302 DEBUG Tunnel 6DEV estate changed from CADET_TUNNEL_KEY_AX_AUTH_SENT to CADET_TUNNEL_KEY_OK
Aug 04 18:34:04-582867 cadet-tun-21302 DEBUG Received CHANNEL_OPEN on h_port Q16D1VZ8 from Tunnel 6DEV
Aug 04 18:34:04-582899 cadet-chn-21302 DEBUG Binding Channel 6DEV:00000000 ctn:0(0/0) from Tunnel 6DEV to port 00000000 of Client(0)
Aug 04 18:34:04-582925 cadet-21302 DEBUG Accepting incoming Channel 6DEV:38KQGBKV ctn:0(0/0) from 6DEV on open port 38KQGBKV (0), assigning ccn 0
Aug 04 18:34:04-582950 cadet-chn-21302 DEBUG Sending CADET_LOCAL_ACK to Client(0) (dest) at ccn 0 (0/4 pending)
Aug 04 18:34:04-582969 cadet-chn-21302 DEBUG Sending CADET_LOCAL_ACK to Client(0) (dest) at ccn 0 (0/4 pending)
Aug 04 18:34:04-582987 cadet-chn-21302 DEBUG Sending CADET_LOCAL_ACK to Client(0) (dest) at ccn 0 (0/4 pending)
Aug 04 18:34:04-583004 cadet-chn-21302 DEBUG Sending CADET_LOCAL_ACK to Client(0) (dest) at ccn 0 (0/4 pending)
Aug 04 18:34:04-583039 cadet-chn-21302 DEBUG Sending CHANNEL_OPEN_ACK on Channel 6DEV:38KQGBKV ctn:0(0/0)
Aug 04 18:34:04-583057 cadet-tun-21302 DEBUG Encrypting 76 bytes for Tunnel 6DEV
Aug 04 18:34:04-584959 cadet-tun-21302 DEBUG Sending payload of Tunnel 6DEV on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:04-584982 cadet-con-21302 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:04-585001 cadet-per-21302 DEBUG Queueing message to peer 6DEV in MQM 0x561205b84ae0
Aug 04 18:34:04-585019 cadet-per-21302 DEBUG Sending to peer 6DEV from MQM 0x561205b84ae0
Aug 04 18:34:04-585044 cadet-tun-21302 DEBUG Connection 8P5P2R (Tunnel 6DEV) now ready for Tunnel 6DEV in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:04-585046 cadet-api-21281 DEBUG Creating incoming channel 0 [38KQGBKV] 0x559a795d3f40
Aug 04 18:34:04-585068 cadet-tun-21302 DEBUG Not sending payload of Tunnel 6DEV on ready Connection 8P5P2R (Tunnel 6DEV) (nothing pending)
Aug 04 18:34:04-585096 cadet-con-21302 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6DEV) became available in state 4
Aug 04 18:34:04-585099 test_cadet_small-21281 INFO Incoming channel from 6DEV to 1: 0x559a795d3f40
Aug 04 18:34:04-585116 test_cadet_small-21281 INFO  ok: 1
Aug 04 18:34:04-585125 cadet-con-21302 DEBUG Scheduling keepalive for Connection 8P5P2R (Tunnel 6DEV) in 1 s
Aug 04 18:34:04-585178 cadet-api-21281 DEBUG Got an ACK on mq channel 0 (peer 6DEV); new window size is 1!
Aug 04 18:34:04-585221 cadet-api-21281 DEBUG Got an ACK on mq channel 0, allow send now 1!
Aug 04 18:34:04-585225 cadet-per-21302 DEBUG Sending to peer 6DEV completed
Aug 04 18:34:04-585258 cadet-api-21281 DEBUG Got an ACK on mq channel 0 (peer 6DEV); new window size is 2!
Aug 04 18:34:04-585277 cadet-api-21281 DEBUG Got an ACK on mq channel 0, allow send now 2!
Aug 04 18:34:04-585295 cadet-api-21281 DEBUG Got an ACK on mq channel 0 (peer 6DEV); new window size is 3!
Aug 04 18:34:04-585313 cadet-api-21281 DEBUG Got an ACK on mq channel 0, allow send now 3!
Aug 04 18:34:04-585330 cadet-api-21281 DEBUG Got an ACK on mq channel 0 (peer 6DEV); new window size is 4!
Aug 04 18:34:04-585348 cadet-api-21281 DEBUG Got an ACK on mq channel 0, allow send now 4!
Aug 04 18:34:04-586051 cadet-tun-21308 DEBUG Tunnel 6YNB received 188 bytes of encrypted data in state 5
Aug 04 18:34:04-586558 cadet-tun-21308 DEBUG Received channel OPEN_ACK on channel Channel 6YNB:38KQGBKV ctn:0(80000000/0) from Tunnel 6YNB
Aug 04 18:34:04-586593 cadet-chn-21308 DEBUG Received CHANNEL_OPEN_ACK for waiting Channel 6YNB:38KQGBKV ctn:0(80000000/0), entering READY state
Aug 04 18:34:04-586634 cadet-chn-21308 DEBUG Sending CADET_LOCAL_ACK to Client(0) (owner) at ccn 80000000 (0/4 pending)
Aug 04 18:34:04-586663 cadet-chn-21308 DEBUG Sending CADET_LOCAL_ACK to Client(0) (owner) at ccn 80000000 (0/4 pending)
Aug 04 18:34:04-586688 cadet-chn-21308 DEBUG Sending CADET_LOCAL_ACK to Client(0) (owner) at ccn 80000000 (0/4 pending)
Aug 04 18:34:04-586711 cadet-chn-21308 DEBUG Sending CADET_LOCAL_ACK to Client(0) (owner) at ccn 80000000 (0/4 pending)
Aug 04 18:34:04-586782 cadet-api-21281 DEBUG Got an ACK on mq channel 80000000 (peer 6YNB); new window size is 1!
Aug 04 18:34:04-586826 cadet-api-21281 DEBUG Got an ACK on mq channel 80000000, allow send now 1!
Aug 04 18:34:04-586869 cadet-api-21281 DEBUG Got an ACK on mq channel 80000000 (peer 6YNB); new window size is 2!
Aug 04 18:34:04-586890 cadet-api-21281 DEBUG Got an ACK on mq channel 80000000, allow send now 2!
Aug 04 18:34:04-586933 cadet-api-21281 DEBUG Got an ACK on mq channel 80000000 (peer 6YNB); new window size is 3!
Aug 04 18:34:04-586946 cadet-api-21281 DEBUG Got an ACK on mq channel 80000000, allow send now 3!
Aug 04 18:34:04-586966 cadet-api-21281 DEBUG Got an ACK on mq channel 80000000 (peer 6YNB); new window size is 4!
Aug 04 18:34:04-586979 cadet-api-21281 DEBUG Got an ACK on mq channel 80000000, allow send now 4!
Aug 04 18:34:05-579628 cadet-con-21308 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6YNB) via Tunnel 6YNB
Aug 04 18:34:05-579746 cadet-tun-21308 DEBUG Encrypting 4 bytes for Tunnel 6YNB
Aug 04 18:34:05-585345 cadet-tun-21308 DEBUG Sending payload of Tunnel 6YNB on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:05-585442 cadet-con-21308 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:05-585488 cadet-per-21308 DEBUG Queueing message to peer 6YNB in MQM 0x55da60488e60
Aug 04 18:34:05-585532 cadet-per-21308 DEBUG Sending to peer 6YNB from MQM 0x55da60488e60
Aug 04 18:34:05-585742 cadet-tun-21308 DEBUG Connection 8P5P2R (Tunnel 6YNB) now ready for Tunnel 6YNB in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:05-585798 cadet-tun-21308 DEBUG Not sending payload of Tunnel 6YNB on ready Connection 8P5P2R (Tunnel 6YNB) (nothing pending)
Aug 04 18:34:05-585836 cadet-con-21308 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6YNB) became available in state 4
Aug 04 18:34:05-586236 cadet-per-21308 DEBUG Sending to peer 6YNB completed
Aug 04 18:34:05-586268 cadet-con-21302 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6DEV) via Tunnel 6DEV
Aug 04 18:34:05-586492 cadet-tun-21302 DEBUG Encrypting 4 bytes for Tunnel 6DEV
Aug 04 18:34:05-592618 cadet-tun-21302 DEBUG Sending payload of Tunnel 6DEV on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:05-592662 cadet-con-21302 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:05-592701 cadet-per-21302 DEBUG Queueing message to peer 6DEV in MQM 0x561205b84ae0
Aug 04 18:34:05-592732 cadet-per-21302 DEBUG Sending to peer 6DEV from MQM 0x561205b84ae0
Aug 04 18:34:05-592787 cadet-tun-21302 DEBUG Connection 8P5P2R (Tunnel 6DEV) now ready for Tunnel 6DEV in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:05-592843 cadet-tun-21302 DEBUG Not sending payload of Tunnel 6DEV on ready Connection 8P5P2R (Tunnel 6DEV) (nothing pending)
Aug 04 18:34:05-592888 cadet-con-21302 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6DEV) became available in state 4
Aug 04 18:34:05-592948 cadet-tun-21302 DEBUG Tunnel 6DEV received 116 bytes of encrypted data in state 5
Aug 04 18:34:05-593510 cadet-tun-21302 DEBUG Received KEEPALIVE on Tunnel 6DEV
Aug 04 18:34:05-593694 cadet-per-21302 DEBUG Sending to peer 6DEV completed
Aug 04 18:34:05-594998 cadet-tun-21308 DEBUG Tunnel 6YNB received 116 bytes of encrypted data in state 5
Aug 04 18:34:05-595433 cadet-tun-21308 DEBUG Received KEEPALIVE on Tunnel 6YNB
Aug 04 18:34:06-587041 cadet-con-21308 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6YNB) via Tunnel 6YNB
Aug 04 18:34:06-587162 cadet-tun-21308 DEBUG Encrypting 4 bytes for Tunnel 6YNB
Aug 04 18:34:06-591588 cadet-tun-21308 DEBUG Sending payload of Tunnel 6YNB on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:06-591659 cadet-con-21308 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:06-591698 cadet-per-21308 DEBUG Queueing message to peer 6YNB in MQM 0x55da60488e60
Aug 04 18:34:06-591750 cadet-per-21308 DEBUG Sending to peer 6YNB from MQM 0x55da60488e60
Aug 04 18:34:06-591813 cadet-tun-21308 DEBUG Connection 8P5P2R (Tunnel 6YNB) now ready for Tunnel 6YNB in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:06-591843 cadet-tun-21308 DEBUG Not sending payload of Tunnel 6YNB on ready Connection 8P5P2R (Tunnel 6YNB) (nothing pending)
Aug 04 18:34:06-591872 cadet-con-21308 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6YNB) became available in state 4
Aug 04 18:34:06-592154 cadet-per-21308 DEBUG Sending to peer 6YNB completed
Aug 04 18:34:06-593423 cadet-con-21302 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6DEV) via Tunnel 6DEV
Aug 04 18:34:06-593520 cadet-tun-21302 DEBUG Encrypting 4 bytes for Tunnel 6DEV
Aug 04 18:34:06-598021 cadet-tun-21302 DEBUG Tunnel 6DEV received 116 bytes of encrypted data in state 5
Aug 04 18:34:06-598818 cadet-tun-21302 DEBUG Received KEEPALIVE on Tunnel 6DEV
Aug 04 18:34:06-598899 cadet-tun-21302 DEBUG Sending payload of Tunnel 6DEV on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:06-598963 cadet-con-21302 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:06-599003 cadet-per-21302 DEBUG Queueing message to peer 6DEV in MQM 0x561205b84ae0
Aug 04 18:34:06-599042 cadet-per-21302 DEBUG Sending to peer 6DEV from MQM 0x561205b84ae0
Aug 04 18:34:06-599107 cadet-tun-21302 DEBUG Connection 8P5P2R (Tunnel 6DEV) now ready for Tunnel 6DEV in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:06-599184 cadet-tun-21302 DEBUG Not sending payload of Tunnel 6DEV on ready Connection 8P5P2R (Tunnel 6DEV) (nothing pending)
Aug 04 18:34:06-599222 cadet-con-21302 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6DEV) became available in state 4
Aug 04 18:34:06-599415 cadet-per-21302 DEBUG Sending to peer 6DEV completed
Aug 04 18:34:06-600277 cadet-tun-21308 DEBUG Tunnel 6YNB received 116 bytes of encrypted data in state 5
Aug 04 18:34:06-600892 cadet-tun-21308 DEBUG Received KEEPALIVE on Tunnel 6YNB
Aug 04 18:34:07-593070 cadet-con-21308 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6YNB) via Tunnel 6YNB
Aug 04 18:34:07-593197 cadet-tun-21308 DEBUG Encrypting 4 bytes for Tunnel 6YNB
Aug 04 18:34:07-597904 cadet-tun-21308 DEBUG Sending payload of Tunnel 6YNB on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:07-597975 cadet-con-21308 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:07-598005 cadet-per-21308 DEBUG Queueing message to peer 6YNB in MQM 0x55da60488e60
Aug 04 18:34:07-598032 cadet-per-21308 DEBUG Sending to peer 6YNB from MQM 0x55da60488e60
Aug 04 18:34:07-598077 cadet-tun-21308 DEBUG Connection 8P5P2R (Tunnel 6YNB) now ready for Tunnel 6YNB in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:07-598109 cadet-tun-21308 DEBUG Not sending payload of Tunnel 6YNB on ready Connection 8P5P2R (Tunnel 6YNB) (nothing pending)
Aug 04 18:34:07-598133 cadet-con-21308 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6YNB) became available in state 4
Aug 04 18:34:07-598367 cadet-per-21308 DEBUG Sending to peer 6YNB completed
Aug 04 18:34:07-599362 cadet-con-21302 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6DEV) via Tunnel 6DEV
Aug 04 18:34:07-599454 cadet-tun-21302 DEBUG Encrypting 4 bytes for Tunnel 6DEV
Aug 04 18:34:07-603935 cadet-tun-21302 DEBUG Tunnel 6DEV received 116 bytes of encrypted data in state 5
Aug 04 18:34:07-604654 cadet-tun-21302 DEBUG Received KEEPALIVE on Tunnel 6DEV
Aug 04 18:34:07-604724 cadet-tun-21302 DEBUG Sending payload of Tunnel 6DEV on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:07-604773 cadet-con-21302 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:07-604799 cadet-per-21302 DEBUG Queueing message to peer 6DEV in MQM 0x561205b84ae0
Aug 04 18:34:07-604824 cadet-per-21302 DEBUG Sending to peer 6DEV from MQM 0x561205b84ae0
Aug 04 18:34:07-604861 cadet-tun-21302 DEBUG Connection 8P5P2R (Tunnel 6DEV) now ready for Tunnel 6DEV in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:07-604921 cadet-tun-21302 DEBUG Not sending payload of Tunnel 6DEV on ready Connection 8P5P2R (Tunnel 6DEV) (nothing pending)
Aug 04 18:34:07-604955 cadet-con-21302 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6DEV) became available in state 4
Aug 04 18:34:07-605089 cadet-per-21302 DEBUG Sending to peer 6DEV completed
Aug 04 18:34:07-606368 cadet-tun-21308 DEBUG Tunnel 6YNB received 116 bytes of encrypted data in state 5
Aug 04 18:34:07-607041 cadet-tun-21308 DEBUG Received KEEPALIVE on Tunnel 6YNB
Aug 04 18:34:08-555001 cadet-21302 DEBUG HELLO has 180 bytes of address data
Aug 04 18:34:08-555166 cadet-dht-21302 DEBUG Announcing my HELLO (220 bytes) in the DHT
Aug 04 18:34:08-557328 cadet-21308 DEBUG HELLO has 180 bytes of address data
Aug 04 18:34:08-559103 cadet-dht-21308 DEBUG Announcing my HELLO (220 bytes) in the DHT
Aug 04 18:34:08-598296 cadet-con-21308 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6YNB) via Tunnel 6YNB
Aug 04 18:34:08-598374 cadet-tun-21308 DEBUG Encrypting 4 bytes for Tunnel 6YNB
Aug 04 18:34:08-602618 cadet-tun-21308 DEBUG Sending payload of Tunnel 6YNB on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:08-602665 cadet-con-21308 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:08-602689 cadet-per-21308 DEBUG Queueing message to peer 6YNB in MQM 0x55da60488e60
Aug 04 18:34:08-602711 cadet-per-21308 DEBUG Sending to peer 6YNB from MQM 0x55da60488e60
Aug 04 18:34:08-602748 cadet-tun-21308 DEBUG Connection 8P5P2R (Tunnel 6YNB) now ready for Tunnel 6YNB in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:08-602843 cadet-tun-21308 DEBUG Not sending payload of Tunnel 6YNB on ready Connection 8P5P2R (Tunnel 6YNB) (nothing pending)
Aug 04 18:34:08-602890 cadet-con-21308 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6YNB) became available in state 4
Aug 04 18:34:08-603144 cadet-per-21308 DEBUG Sending to peer 6YNB completed
Aug 04 18:34:08-604368 cadet-tun-21302 DEBUG Tunnel 6DEV received 116 bytes of encrypted data in state 5
Aug 04 18:34:08-604994 cadet-tun-21302 DEBUG Received KEEPALIVE on Tunnel 6DEV
Aug 04 18:34:08-605083 cadet-con-21302 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6DEV) via Tunnel 6DEV
Aug 04 18:34:08-605135 cadet-tun-21302 DEBUG Encrypting 4 bytes for Tunnel 6DEV
Aug 04 18:34:08-609631 cadet-tun-21302 DEBUG Sending payload of Tunnel 6DEV on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:08-609681 cadet-con-21302 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:08-609721 cadet-per-21302 DEBUG Queueing message to peer 6DEV in MQM 0x561205b84ae0
Aug 04 18:34:08-609772 cadet-per-21302 DEBUG Sending to peer 6DEV from MQM 0x561205b84ae0
Aug 04 18:34:08-609823 cadet-tun-21302 DEBUG Connection 8P5P2R (Tunnel 6DEV) now ready for Tunnel 6DEV in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:08-609862 cadet-tun-21302 DEBUG Not sending payload of Tunnel 6DEV on ready Connection 8P5P2R (Tunnel 6DEV) (nothing pending)
Aug 04 18:34:08-609898 cadet-con-21302 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6DEV) became available in state 4
Aug 04 18:34:08-610020 cadet-per-21302 DEBUG Sending to peer 6DEV completed
Aug 04 18:34:08-610813 cadet-tun-21308 DEBUG Tunnel 6YNB received 116 bytes of encrypted data in state 5
Aug 04 18:34:08-611471 cadet-tun-21308 DEBUG Received KEEPALIVE on Tunnel 6YNB
Aug 04 18:34:09-604057 cadet-con-21308 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6YNB) via Tunnel 6YNB
Aug 04 18:34:09-604182 cadet-tun-21308 DEBUG Encrypting 4 bytes for Tunnel 6YNB
Aug 04 18:34:09-609569 cadet-tun-21308 DEBUG Sending payload of Tunnel 6YNB on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:09-609648 cadet-con-21308 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:09-609692 cadet-per-21308 DEBUG Queueing message to peer 6YNB in MQM 0x55da60488e60
Aug 04 18:34:09-609719 cadet-per-21308 DEBUG Sending to peer 6YNB from MQM 0x55da60488e60
Aug 04 18:34:09-609768 cadet-tun-21308 DEBUG Connection 8P5P2R (Tunnel 6YNB) now ready for Tunnel 6YNB in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:09-609913 cadet-tun-21308 DEBUG Not sending payload of Tunnel 6YNB on ready Connection 8P5P2R (Tunnel 6YNB) (nothing pending)
Aug 04 18:34:09-609951 cadet-con-21308 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6YNB) became available in state 4
Aug 04 18:34:09-610135 cadet-per-21308 DEBUG Sending to peer 6YNB completed
Aug 04 18:34:09-611093 cadet-con-21302 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6DEV) via Tunnel 6DEV
Aug 04 18:34:09-611166 cadet-tun-21302 DEBUG Encrypting 4 bytes for Tunnel 6DEV
Aug 04 18:34:09-616280 cadet-tun-21302 DEBUG Sending payload of Tunnel 6DEV on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:09-616314 cadet-con-21302 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:09-616340 cadet-per-21302 DEBUG Queueing message to peer 6DEV in MQM 0x561205b84ae0
Aug 04 18:34:09-616366 cadet-per-21302 DEBUG Sending to peer 6DEV from MQM 0x561205b84ae0
Aug 04 18:34:09-616402 cadet-tun-21302 DEBUG Connection 8P5P2R (Tunnel 6DEV) now ready for Tunnel 6DEV in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:09-616430 cadet-tun-21302 DEBUG Not sending payload of Tunnel 6DEV on ready Connection 8P5P2R (Tunnel 6DEV) (nothing pending)
Aug 04 18:34:09-616458 cadet-con-21302 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6DEV) became available in state 4
Aug 04 18:34:09-616496 cadet-tun-21302 DEBUG Tunnel 6DEV received 116 bytes of encrypted data in state 5
Aug 04 18:34:09-616928 cadet-tun-21302 DEBUG Received KEEPALIVE on Tunnel 6DEV
Aug 04 18:34:09-617044 cadet-per-21302 DEBUG Sending to peer 6DEV completed
Aug 04 18:34:09-617942 cadet-tun-21308 DEBUG Tunnel 6YNB received 116 bytes of encrypted data in state 5
Aug 04 18:34:09-618366 cadet-tun-21308 DEBUG Received KEEPALIVE on Tunnel 6YNB
Aug 04 18:34:10-611098 cadet-con-21308 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6YNB) via Tunnel 6YNB
Aug 04 18:34:10-611224 cadet-tun-21308 DEBUG Encrypting 4 bytes for Tunnel 6YNB
Aug 04 18:34:10-617242 cadet-tun-21308 DEBUG Sending payload of Tunnel 6YNB on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:10-617344 cadet-con-21308 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:10-617378 cadet-per-21308 DEBUG Queueing message to peer 6YNB in MQM 0x55da60488e60
Aug 04 18:34:10-617409 cadet-per-21308 DEBUG Sending to peer 6YNB from MQM 0x55da60488e60
Aug 04 18:34:10-617472 cadet-tun-21308 DEBUG Connection 8P5P2R (Tunnel 6YNB) now ready for Tunnel 6YNB in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:10-617548 cadet-tun-21308 DEBUG Not sending payload of Tunnel 6YNB on ready Connection 8P5P2R (Tunnel 6YNB) (nothing pending)
Aug 04 18:34:10-617603 cadet-con-21308 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6YNB) became available in state 4
Aug 04 18:34:10-617591 cadet-con-21302 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6DEV) via Tunnel 6DEV
Aug 04 18:34:10-617680 cadet-tun-21302 DEBUG Encrypting 4 bytes for Tunnel 6DEV
Aug 04 18:34:10-617977 cadet-per-21308 DEBUG Sending to peer 6YNB completed
Aug 04 18:34:10-623724 cadet-tun-21302 DEBUG Sending payload of Tunnel 6DEV on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:10-623788 cadet-con-21302 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:10-623830 cadet-per-21302 DEBUG Queueing message to peer 6DEV in MQM 0x561205b84ae0
Aug 04 18:34:10-623857 cadet-per-21302 DEBUG Sending to peer 6DEV from MQM 0x561205b84ae0
Aug 04 18:34:10-623909 cadet-tun-21302 DEBUG Connection 8P5P2R (Tunnel 6DEV) now ready for Tunnel 6DEV in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:10-623956 cadet-tun-21302 DEBUG Not sending payload of Tunnel 6DEV on ready Connection 8P5P2R (Tunnel 6DEV) (nothing pending)
Aug 04 18:34:10-624002 cadet-con-21302 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6DEV) became available in state 4
Aug 04 18:34:10-624081 cadet-tun-21302 DEBUG Tunnel 6DEV received 116 bytes of encrypted data in state 5
Aug 04 18:34:10-624765 cadet-tun-21302 DEBUG Received KEEPALIVE on Tunnel 6DEV
Aug 04 18:34:10-624945 cadet-per-21302 DEBUG Sending to peer 6DEV completed
Aug 04 18:34:10-626034 cadet-tun-21308 DEBUG Tunnel 6YNB received 116 bytes of encrypted data in state 5
Aug 04 18:34:10-626380 cadet-tun-21308 DEBUG Received KEEPALIVE on Tunnel 6YNB
Aug 04 18:34:11-618758 cadet-con-21308 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6YNB) via Tunnel 6YNB
Aug 04 18:34:11-618881 cadet-tun-21308 DEBUG Encrypting 4 bytes for Tunnel 6YNB
Aug 04 18:34:11-624511 cadet-tun-21308 DEBUG Sending payload of Tunnel 6YNB on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:11-624576 cadet-con-21308 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:11-624603 cadet-per-21308 DEBUG Queueing message to peer 6YNB in MQM 0x55da60488e60
Aug 04 18:34:11-624627 cadet-per-21308 DEBUG Sending to peer 6YNB from MQM 0x55da60488e60
Aug 04 18:34:11-624672 cadet-tun-21308 DEBUG Connection 8P5P2R (Tunnel 6YNB) now ready for Tunnel 6YNB in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:11-624707 cadet-tun-21308 DEBUG Not sending payload of Tunnel 6YNB on ready Connection 8P5P2R (Tunnel 6YNB) (nothing pending)
Aug 04 18:34:11-624741 cadet-con-21308 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6YNB) became available in state 4
Aug 04 18:34:11-624952 cadet-per-21308 DEBUG Sending to peer 6YNB completed
Aug 04 18:34:11-625145 cadet-con-21302 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6DEV) via Tunnel 6DEV
Aug 04 18:34:11-625214 cadet-tun-21302 DEBUG Encrypting 4 bytes for Tunnel 6DEV
Aug 04 18:34:11-630986 cadet-tun-21302 DEBUG Sending payload of Tunnel 6DEV on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:11-631049 cadet-con-21302 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:11-631093 cadet-per-21302 DEBUG Queueing message to peer 6DEV in MQM 0x561205b84ae0
Aug 04 18:34:11-631138 cadet-per-21302 DEBUG Sending to peer 6DEV from MQM 0x561205b84ae0
Aug 04 18:34:11-631188 cadet-tun-21302 DEBUG Connection 8P5P2R (Tunnel 6DEV) now ready for Tunnel 6DEV in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:11-631260 cadet-tun-21302 DEBUG Not sending payload of Tunnel 6DEV on ready Connection 8P5P2R (Tunnel 6DEV) (nothing pending)
Aug 04 18:34:11-631304 cadet-con-21302 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6DEV) became available in state 4
Aug 04 18:34:11-631357 cadet-tun-21302 DEBUG Tunnel 6DEV received 116 bytes of encrypted data in state 5
Aug 04 18:34:11-632188 cadet-tun-21302 DEBUG Received KEEPALIVE on Tunnel 6DEV
Aug 04 18:34:11-632413 cadet-per-21302 DEBUG Sending to peer 6DEV completed
Aug 04 18:34:11-633619 cadet-tun-21308 DEBUG Tunnel 6YNB received 116 bytes of encrypted data in state 5
Aug 04 18:34:11-634318 cadet-tun-21308 DEBUG Received KEEPALIVE on Tunnel 6YNB
Aug 04 18:34:12-625871 cadet-con-21308 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6YNB) via Tunnel 6YNB
Aug 04 18:34:12-625994 cadet-tun-21308 DEBUG Encrypting 4 bytes for Tunnel 6YNB
Aug 04 18:34:12-632433 cadet-con-21302 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6DEV) via Tunnel 6DEV
Aug 04 18:34:12-632551 cadet-tun-21302 DEBUG Encrypting 4 bytes for Tunnel 6DEV
Aug 04 18:34:12-633784 cadet-tun-21308 DEBUG Sending payload of Tunnel 6YNB on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:12-633852 cadet-con-21308 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:12-633886 cadet-per-21308 DEBUG Queueing message to peer 6YNB in MQM 0x55da60488e60
Aug 04 18:34:12-633942 cadet-per-21308 DEBUG Sending to peer 6YNB from MQM 0x55da60488e60
Aug 04 18:34:12-634006 cadet-tun-21308 DEBUG Connection 8P5P2R (Tunnel 6YNB) now ready for Tunnel 6YNB in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:12-634089 cadet-tun-21308 DEBUG Not sending payload of Tunnel 6YNB on ready Connection 8P5P2R (Tunnel 6YNB) (nothing pending)
Aug 04 18:34:12-634143 cadet-con-21308 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6YNB) became available in state 4
Aug 04 18:34:12-634424 cadet-per-21308 DEBUG Sending to peer 6YNB completed
Aug 04 18:34:12-637683 cadet-tun-21302 DEBUG Sending payload of Tunnel 6DEV on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:12-637782 cadet-con-21302 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:12-637839 cadet-per-21302 DEBUG Queueing message to peer 6DEV in MQM 0x561205b84ae0
Aug 04 18:34:12-637894 cadet-per-21302 DEBUG Sending to peer 6DEV from MQM 0x561205b84ae0
Aug 04 18:34:12-637967 cadet-tun-21302 DEBUG Connection 8P5P2R (Tunnel 6DEV) now ready for Tunnel 6DEV in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:12-638036 cadet-tun-21302 DEBUG Not sending payload of Tunnel 6DEV on ready Connection 8P5P2R (Tunnel 6DEV) (nothing pending)
Aug 04 18:34:12-638077 cadet-con-21302 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6DEV) became available in state 4
Aug 04 18:34:12-638137 cadet-tun-21302 DEBUG Tunnel 6DEV received 116 bytes of encrypted data in state 5
Aug 04 18:34:12-638658 cadet-tun-21302 DEBUG Received KEEPALIVE on Tunnel 6DEV
Aug 04 18:34:12-638739 cadet-per-21302 DEBUG Sending to peer 6DEV completed
Aug 04 18:34:12-639308 cadet-tun-21308 DEBUG Tunnel 6YNB received 116 bytes of encrypted data in state 5
Aug 04 18:34:12-639984 cadet-tun-21308 DEBUG Received KEEPALIVE on Tunnel 6YNB
Aug 04 18:34:13-556062 cadet-21302 DEBUG HELLO has 180 bytes of address data
Aug 04 18:34:13-556209 cadet-dht-21302 DEBUG Announcing my HELLO (220 bytes) in the DHT
Aug 04 18:34:13-559645 cadet-21308 DEBUG HELLO has 180 bytes of address data
Aug 04 18:34:13-559792 cadet-dht-21308 DEBUG Announcing my HELLO (220 bytes) in the DHT
Aug 04 18:34:13-634399 cadet-con-21308 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6YNB) via Tunnel 6YNB
Aug 04 18:34:13-634523 cadet-tun-21308 DEBUG Encrypting 4 bytes for Tunnel 6YNB
Aug 04 18:34:13-638265 cadet-con-21302 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6DEV) via Tunnel 6DEV
Aug 04 18:34:13-638368 cadet-tun-21302 DEBUG Encrypting 4 bytes for Tunnel 6DEV
Aug 04 18:34:13-640491 cadet-tun-21308 DEBUG Sending payload of Tunnel 6YNB on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:13-640586 cadet-con-21308 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:13-640646 cadet-per-21308 DEBUG Queueing message to peer 6YNB in MQM 0x55da60488e60
Aug 04 18:34:13-640735 cadet-per-21308 DEBUG Sending to peer 6YNB from MQM 0x55da60488e60
Aug 04 18:34:13-640797 cadet-tun-21308 DEBUG Connection 8P5P2R (Tunnel 6YNB) now ready for Tunnel 6YNB in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:13-640871 cadet-tun-21308 DEBUG Not sending payload of Tunnel 6YNB on ready Connection 8P5P2R (Tunnel 6YNB) (nothing pending)
Aug 04 18:34:13-640920 cadet-con-21308 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6YNB) became available in state 4
Aug 04 18:34:13-641289 cadet-per-21308 DEBUG Sending to peer 6YNB completed
Aug 04 18:34:13-644728 cadet-tun-21302 DEBUG Sending payload of Tunnel 6DEV on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:13-644793 cadet-con-21302 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:13-644826 cadet-per-21302 DEBUG Queueing message to peer 6DEV in MQM 0x561205b84ae0
Aug 04 18:34:13-644857 cadet-per-21302 DEBUG Sending to peer 6DEV from MQM 0x561205b84ae0
Aug 04 18:34:13-644911 cadet-tun-21302 DEBUG Connection 8P5P2R (Tunnel 6DEV) now ready for Tunnel 6DEV in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:13-644992 cadet-tun-21302 DEBUG Not sending payload of Tunnel 6DEV on ready Connection 8P5P2R (Tunnel 6DEV) (nothing pending)
Aug 04 18:34:13-645047 cadet-con-21302 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6DEV) became available in state 4
Aug 04 18:34:13-645113 cadet-tun-21302 DEBUG Tunnel 6DEV received 116 bytes of encrypted data in state 5
Aug 04 18:34:13-646173 cadet-tun-21302 DEBUG Received KEEPALIVE on Tunnel 6DEV
Aug 04 18:34:13-646432 cadet-per-21302 DEBUG Sending to peer 6DEV completed
Aug 04 18:34:13-646975 cadet-tun-21308 DEBUG Tunnel 6YNB received 116 bytes of encrypted data in state 5
Aug 04 18:34:13-647578 cadet-tun-21308 DEBUG Received KEEPALIVE on Tunnel 6YNB
Aug 04 18:34:14-642109 cadet-con-21308 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6YNB) via Tunnel 6YNB
Aug 04 18:34:14-642232 cadet-tun-21308 DEBUG Encrypting 4 bytes for Tunnel 6YNB
Aug 04 18:34:14-646175 cadet-con-21302 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6DEV) via Tunnel 6DEV
Aug 04 18:34:14-646284 cadet-tun-21302 DEBUG Encrypting 4 bytes for Tunnel 6DEV
Aug 04 18:34:14-648618 cadet-tun-21308 DEBUG Sending payload of Tunnel 6YNB on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:14-648682 cadet-con-21308 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:14-648719 cadet-per-21308 DEBUG Queueing message to peer 6YNB in MQM 0x55da60488e60
Aug 04 18:34:14-648839 cadet-per-21308 DEBUG Sending to peer 6YNB from MQM 0x55da60488e60
Aug 04 18:34:14-648909 cadet-tun-21308 DEBUG Connection 8P5P2R (Tunnel 6YNB) now ready for Tunnel 6YNB in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:14-648973 cadet-tun-21308 DEBUG Not sending payload of Tunnel 6YNB on ready Connection 8P5P2R (Tunnel 6YNB) (nothing pending)
Aug 04 18:34:14-649030 cadet-con-21308 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6YNB) became available in state 4
Aug 04 18:34:14-649385 cadet-per-21308 DEBUG Sending to peer 6YNB completed
Aug 04 18:34:14-652548 cadet-tun-21302 DEBUG Sending payload of Tunnel 6DEV on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:14-652616 cadet-con-21302 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:14-652677 cadet-per-21302 DEBUG Queueing message to peer 6DEV in MQM 0x561205b84ae0
Aug 04 18:34:14-652760 cadet-per-21302 DEBUG Sending to peer 6DEV from MQM 0x561205b84ae0
Aug 04 18:34:14-652808 cadet-tun-21302 DEBUG Connection 8P5P2R (Tunnel 6DEV) now ready for Tunnel 6DEV in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:14-652870 cadet-tun-21302 DEBUG Not sending payload of Tunnel 6DEV on ready Connection 8P5P2R (Tunnel 6DEV) (nothing pending)
Aug 04 18:34:14-652904 cadet-con-21302 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6DEV) became available in state 4
Aug 04 18:34:14-653045 cadet-tun-21302 DEBUG Tunnel 6DEV received 116 bytes of encrypted data in state 5
Aug 04 18:34:14-653794 cadet-tun-21302 DEBUG Received KEEPALIVE on Tunnel 6DEV
Aug 04 18:34:14-654041 cadet-per-21302 DEBUG Sending to peer 6DEV completed
Aug 04 18:34:14-654911 cadet-tun-21308 DEBUG Tunnel 6YNB received 116 bytes of encrypted data in state 5
Aug 04 18:34:14-655308 cadet-tun-21308 DEBUG Received KEEPALIVE on Tunnel 6YNB
Aug 04 18:34:15-650192 cadet-con-21308 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6YNB) via Tunnel 6YNB
Aug 04 18:34:15-650316 cadet-tun-21308 DEBUG Encrypting 4 bytes for Tunnel 6YNB
Aug 04 18:34:15-654096 cadet-con-21302 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6DEV) via Tunnel 6DEV
Aug 04 18:34:15-654217 cadet-tun-21302 DEBUG Encrypting 4 bytes for Tunnel 6DEV
Aug 04 18:34:15-659825 cadet-tun-21308 DEBUG Sending payload of Tunnel 6YNB on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:15-659910 cadet-con-21308 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:15-659960 cadet-per-21308 DEBUG Queueing message to peer 6YNB in MQM 0x55da60488e60
Aug 04 18:34:15-660007 cadet-per-21308 DEBUG Sending to peer 6YNB from MQM 0x55da60488e60
Aug 04 18:34:15-660106 cadet-tun-21308 DEBUG Connection 8P5P2R (Tunnel 6YNB) now ready for Tunnel 6YNB in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:15-660167 cadet-tun-21308 DEBUG Not sending payload of Tunnel 6YNB on ready Connection 8P5P2R (Tunnel 6YNB) (nothing pending)
Aug 04 18:34:15-660229 cadet-con-21308 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6YNB) became available in state 4
Aug 04 18:34:15-660533 cadet-per-21308 DEBUG Sending to peer 6YNB completed
Aug 04 18:34:15-662252 cadet-tun-21302 DEBUG Sending payload of Tunnel 6DEV on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:15-662322 cadet-con-21302 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:15-662355 cadet-per-21302 DEBUG Queueing message to peer 6DEV in MQM 0x561205b84ae0
Aug 04 18:34:15-662385 cadet-per-21302 DEBUG Sending to peer 6DEV from MQM 0x561205b84ae0
Aug 04 18:34:15-662442 cadet-tun-21302 DEBUG Connection 8P5P2R (Tunnel 6DEV) now ready for Tunnel 6DEV in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:15-662513 cadet-tun-21302 DEBUG Not sending payload of Tunnel 6DEV on ready Connection 8P5P2R (Tunnel 6DEV) (nothing pending)
Aug 04 18:34:15-662551 cadet-con-21302 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6DEV) became available in state 4
Aug 04 18:34:15-662579 cadet-tun-21302 DEBUG Tunnel 6DEV received 116 bytes of encrypted data in state 5
Aug 04 18:34:15-663132 cadet-tun-21302 DEBUG Received KEEPALIVE on Tunnel 6DEV
Aug 04 18:34:15-663247 cadet-per-21302 DEBUG Sending to peer 6DEV completed
Aug 04 18:34:15-664234 cadet-tun-21308 DEBUG Tunnel 6YNB received 116 bytes of encrypted data in state 5
Aug 04 18:34:15-664523 cadet-tun-21308 DEBUG Received KEEPALIVE on Tunnel 6YNB
Aug 04 18:34:16-661392 cadet-con-21308 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6YNB) via Tunnel 6YNB
Aug 04 18:34:16-661519 cadet-tun-21308 DEBUG Encrypting 4 bytes for Tunnel 6YNB
Aug 04 18:34:16-663513 cadet-con-21302 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6DEV) via Tunnel 6DEV
Aug 04 18:34:16-663628 cadet-tun-21302 DEBUG Encrypting 4 bytes for Tunnel 6DEV
Aug 04 18:34:16-668427 cadet-tun-21308 DEBUG Sending payload of Tunnel 6YNB on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:16-668494 cadet-con-21308 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:16-668527 cadet-per-21308 DEBUG Queueing message to peer 6YNB in MQM 0x55da60488e60
Aug 04 18:34:16-668574 cadet-per-21308 DEBUG Sending to peer 6YNB from MQM 0x55da60488e60
Aug 04 18:34:16-668638 cadet-tun-21308 DEBUG Connection 8P5P2R (Tunnel 6YNB) now ready for Tunnel 6YNB in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:16-668700 cadet-tun-21308 DEBUG Not sending payload of Tunnel 6YNB on ready Connection 8P5P2R (Tunnel 6YNB) (nothing pending)
Aug 04 18:34:16-668785 cadet-con-21308 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6YNB) became available in state 4
Aug 04 18:34:16-669170 cadet-per-21308 DEBUG Sending to peer 6YNB completed
Aug 04 18:34:16-669612 cadet-tun-21302 DEBUG Sending payload of Tunnel 6DEV on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:16-669641 cadet-con-21302 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:16-669666 cadet-per-21302 DEBUG Queueing message to peer 6DEV in MQM 0x561205b84ae0
Aug 04 18:34:16-669700 cadet-per-21302 DEBUG Sending to peer 6DEV from MQM 0x561205b84ae0
Aug 04 18:34:16-669738 cadet-tun-21302 DEBUG Connection 8P5P2R (Tunnel 6DEV) now ready for Tunnel 6DEV in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:16-669764 cadet-tun-21302 DEBUG Not sending payload of Tunnel 6DEV on ready Connection 8P5P2R (Tunnel 6DEV) (nothing pending)
Aug 04 18:34:16-669789 cadet-con-21302 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6DEV) became available in state 4
Aug 04 18:34:16-669928 cadet-per-21302 DEBUG Sending to peer 6DEV completed
Aug 04 18:34:16-670386 cadet-tun-21302 DEBUG Tunnel 6DEV received 116 bytes of encrypted data in state 5
Aug 04 18:34:16-670626 cadet-tun-21308 DEBUG Tunnel 6YNB received 116 bytes of encrypted data in state 5
Aug 04 18:34:16-670714 cadet-tun-21302 DEBUG Received KEEPALIVE on Tunnel 6DEV
Aug 04 18:34:16-671361 cadet-tun-21308 DEBUG Received KEEPALIVE on Tunnel 6YNB
Aug 04 18:34:17-669943 cadet-con-21308 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6YNB) via Tunnel 6YNB
Aug 04 18:34:17-670067 cadet-tun-21308 DEBUG Encrypting 4 bytes for Tunnel 6YNB
Aug 04 18:34:17-670918 cadet-con-21302 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6DEV) via Tunnel 6DEV
Aug 04 18:34:17-671097 cadet-tun-21302 DEBUG Encrypting 4 bytes for Tunnel 6DEV
Aug 04 18:34:17-677220 cadet-tun-21302 DEBUG Sending payload of Tunnel 6DEV on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:17-677304 cadet-con-21302 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:17-677306 cadet-tun-21308 DEBUG Sending payload of Tunnel 6YNB on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:17-677383 cadet-per-21302 DEBUG Queueing message to peer 6DEV in MQM 0x561205b84ae0
Aug 04 18:34:17-677389 cadet-con-21308 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:17-677445 cadet-per-21308 DEBUG Queueing message to peer 6YNB in MQM 0x55da60488e60
Aug 04 18:34:17-677443 cadet-per-21302 DEBUG Sending to peer 6DEV from MQM 0x561205b84ae0
Aug 04 18:34:17-677504 cadet-per-21308 DEBUG Sending to peer 6YNB from MQM 0x55da60488e60
Aug 04 18:34:17-677530 cadet-tun-21302 DEBUG Connection 8P5P2R (Tunnel 6DEV) now ready for Tunnel 6DEV in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:17-677567 cadet-tun-21308 DEBUG Connection 8P5P2R (Tunnel 6YNB) now ready for Tunnel 6YNB in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:17-677593 cadet-tun-21302 DEBUG Not sending payload of Tunnel 6DEV on ready Connection 8P5P2R (Tunnel 6DEV) (nothing pending)
Aug 04 18:34:17-677622 cadet-tun-21308 DEBUG Not sending payload of Tunnel 6YNB on ready Connection 8P5P2R (Tunnel 6YNB) (nothing pending)
Aug 04 18:34:17-677644 cadet-con-21302 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6DEV) became available in state 4
Aug 04 18:34:17-677672 cadet-con-21308 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6YNB) became available in state 4
Aug 04 18:34:17-677921 cadet-per-21302 DEBUG Sending to peer 6DEV completed
Aug 04 18:34:17-678023 cadet-per-21308 DEBUG Sending to peer 6YNB completed
Aug 04 18:34:17-679213 cadet-tun-21302 DEBUG Tunnel 6DEV received 116 bytes of encrypted data in state 5
Aug 04 18:34:17-679808 cadet-tun-21302 DEBUG Received KEEPALIVE on Tunnel 6DEV
Aug 04 18:34:17-679988 cadet-tun-21308 DEBUG Tunnel 6YNB received 116 bytes of encrypted data in state 5
Aug 04 18:34:17-680607 cadet-tun-21308 DEBUG Received KEEPALIVE on Tunnel 6YNB
Aug 04 18:34:18-556207 cadet-21302 DEBUG HELLO has 180 bytes of address data
Aug 04 18:34:18-556343 cadet-dht-21302 DEBUG Announcing my HELLO (220 bytes) in the DHT
Aug 04 18:34:18-560649 cadet-21308 DEBUG HELLO has 180 bytes of address data
Aug 04 18:34:18-560714 cadet-dht-21308 DEBUG Announcing my HELLO (220 bytes) in the DHT
Aug 04 18:34:18-677920 cadet-con-21302 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6DEV) via Tunnel 6DEV
Aug 04 18:34:18-677920 cadet-con-21308 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6YNB) via Tunnel 6YNB
Aug 04 18:34:18-678092 cadet-tun-21302 DEBUG Encrypting 4 bytes for Tunnel 6DEV
Aug 04 18:34:18-678103 cadet-tun-21308 DEBUG Encrypting 4 bytes for Tunnel 6YNB
Aug 04 18:34:18-684806 cadet-tun-21308 DEBUG Sending payload of Tunnel 6YNB on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:18-684896 cadet-con-21308 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:18-684943 cadet-per-21308 DEBUG Queueing message to peer 6YNB in MQM 0x55da60488e60
Aug 04 18:34:18-684991 cadet-per-21308 DEBUG Sending to peer 6YNB from MQM 0x55da60488e60
Aug 04 18:34:18-685055 cadet-tun-21308 DEBUG Connection 8P5P2R (Tunnel 6YNB) now ready for Tunnel 6YNB in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:18-685174 cadet-tun-21308 DEBUG Not sending payload of Tunnel 6YNB on ready Connection 8P5P2R (Tunnel 6YNB) (nothing pending)
Aug 04 18:34:18-685251 cadet-con-21308 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6YNB) became available in state 4
Aug 04 18:34:18-685618 cadet-per-21308 DEBUG Sending to peer 6YNB completed
Aug 04 18:34:18-686255 cadet-tun-21302 DEBUG Sending payload of Tunnel 6DEV on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:18-686347 cadet-con-21302 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:18-686400 cadet-per-21302 DEBUG Queueing message to peer 6DEV in MQM 0x561205b84ae0
Aug 04 18:34:18-686456 cadet-per-21302 DEBUG Sending to peer 6DEV from MQM 0x561205b84ae0
Aug 04 18:34:18-686521 cadet-tun-21302 DEBUG Connection 8P5P2R (Tunnel 6DEV) now ready for Tunnel 6DEV in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:18-686577 cadet-tun-21302 DEBUG Not sending payload of Tunnel 6DEV on ready Connection 8P5P2R (Tunnel 6DEV) (nothing pending)
Aug 04 18:34:18-686640 cadet-con-21302 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6DEV) became available in state 4
Aug 04 18:34:18-687413 cadet-per-21302 DEBUG Sending to peer 6DEV completed
Aug 04 18:34:18-687488 cadet-tun-21302 DEBUG Tunnel 6DEV received 116 bytes of encrypted data in state 5
Aug 04 18:34:18-688217 cadet-tun-21302 DEBUG Received KEEPALIVE on Tunnel 6DEV
Aug 04 18:34:18-689113 cadet-tun-21308 DEBUG Tunnel 6YNB received 116 bytes of encrypted data in state 5
Aug 04 18:34:18-689395 cadet-tun-21308 DEBUG Received KEEPALIVE on Tunnel 6YNB
Aug 04 18:34:19-686419 cadet-con-21308 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6YNB) via Tunnel 6YNB
Aug 04 18:34:19-686543 cadet-tun-21308 DEBUG Encrypting 4 bytes for Tunnel 6YNB
Aug 04 18:34:19-687798 cadet-con-21302 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6DEV) via Tunnel 6DEV
Aug 04 18:34:19-687950 cadet-tun-21302 DEBUG Encrypting 4 bytes for Tunnel 6DEV
Aug 04 18:34:19-694002 cadet-tun-21308 DEBUG Sending payload of Tunnel 6YNB on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:19-694084 cadet-con-21308 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:19-694117 cadet-per-21308 DEBUG Queueing message to peer 6YNB in MQM 0x55da60488e60
Aug 04 18:34:19-694158 cadet-per-21308 DEBUG Sending to peer 6YNB from MQM 0x55da60488e60
Aug 04 18:34:19-694226 cadet-tun-21308 DEBUG Connection 8P5P2R (Tunnel 6YNB) now ready for Tunnel 6YNB in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:19-694283 cadet-tun-21308 DEBUG Not sending payload of Tunnel 6YNB on ready Connection 8P5P2R (Tunnel 6YNB) (nothing pending)
Aug 04 18:34:19-694366 cadet-con-21308 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6YNB) became available in state 4
Aug 04 18:34:19-694505 cadet-tun-21302 DEBUG Sending payload of Tunnel 6DEV on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:19-694585 cadet-con-21302 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:19-694681 cadet-per-21302 DEBUG Queueing message to peer 6DEV in MQM 0x561205b84ae0
Aug 04 18:34:19-694733 cadet-per-21302 DEBUG Sending to peer 6DEV from MQM 0x561205b84ae0
Aug 04 18:34:19-694739 cadet-per-21308 DEBUG Sending to peer 6YNB completed
Aug 04 18:34:19-694841 cadet-tun-21302 DEBUG Connection 8P5P2R (Tunnel 6DEV) now ready for Tunnel 6DEV in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:19-694905 cadet-tun-21302 DEBUG Not sending payload of Tunnel 6DEV on ready Connection 8P5P2R (Tunnel 6DEV) (nothing pending)
Aug 04 18:34:19-694957 cadet-con-21302 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6DEV) became available in state 4
Aug 04 18:34:19-695378 cadet-per-21302 DEBUG Sending to peer 6DEV completed
Aug 04 18:34:19-696681 cadet-tun-21302 DEBUG Tunnel 6DEV received 116 bytes of encrypted data in state 5
Aug 04 18:34:19-697194 cadet-tun-21302 DEBUG Received KEEPALIVE on Tunnel 6DEV
Aug 04 18:34:19-697336 cadet-tun-21308 DEBUG Tunnel 6YNB received 116 bytes of encrypted data in state 5
Aug 04 18:34:19-697732 cadet-tun-21308 DEBUG Received KEEPALIVE on Tunnel 6YNB
Aug 04 18:34:20-695488 cadet-con-21308 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6YNB) via Tunnel 6YNB
Aug 04 18:34:20-695631 cadet-tun-21308 DEBUG Encrypting 4 bytes for Tunnel 6YNB
Aug 04 18:34:20-696103 cadet-con-21302 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6DEV) via Tunnel 6DEV
Aug 04 18:34:20-696217 cadet-tun-21302 DEBUG Encrypting 4 bytes for Tunnel 6DEV
Aug 04 18:34:20-701338 cadet-tun-21308 DEBUG Sending payload of Tunnel 6YNB on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:20-701399 cadet-con-21308 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:20-701433 cadet-per-21308 DEBUG Queueing message to peer 6YNB in MQM 0x55da60488e60
Aug 04 18:34:20-701482 cadet-per-21308 DEBUG Sending to peer 6YNB from MQM 0x55da60488e60
Aug 04 18:34:20-701600 cadet-tun-21308 DEBUG Connection 8P5P2R (Tunnel 6YNB) now ready for Tunnel 6YNB in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:20-701665 cadet-tun-21308 DEBUG Not sending payload of Tunnel 6YNB on ready Connection 8P5P2R (Tunnel 6YNB) (nothing pending)
Aug 04 18:34:20-701716 cadet-con-21308 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6YNB) became available in state 4
Aug 04 18:34:20-701901 cadet-tun-21302 DEBUG Sending payload of Tunnel 6DEV on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:20-701935 cadet-con-21302 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:20-701957 cadet-per-21302 DEBUG Queueing message to peer 6DEV in MQM 0x561205b84ae0
Aug 04 18:34:20-701992 cadet-per-21308 DEBUG Sending to peer 6YNB completed
Aug 04 18:34:20-702021 cadet-per-21302 DEBUG Sending to peer 6DEV from MQM 0x561205b84ae0
Aug 04 18:34:20-702064 cadet-tun-21302 DEBUG Connection 8P5P2R (Tunnel 6DEV) now ready for Tunnel 6DEV in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:20-702109 cadet-tun-21302 DEBUG Not sending payload of Tunnel 6DEV on ready Connection 8P5P2R (Tunnel 6DEV) (nothing pending)
Aug 04 18:34:20-702143 cadet-con-21302 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6DEV) became available in state 4
Aug 04 18:34:20-702285 cadet-per-21302 DEBUG Sending to peer 6DEV completed
Aug 04 18:34:20-703214 cadet-tun-21302 DEBUG Tunnel 6DEV received 116 bytes of encrypted data in state 5
Aug 04 18:34:20-703660 cadet-tun-21302 DEBUG Received KEEPALIVE on Tunnel 6DEV
Aug 04 18:34:20-703729 cadet-tun-21308 DEBUG Tunnel 6YNB received 116 bytes of encrypted data in state 5
Aug 04 18:34:20-704400 cadet-tun-21308 DEBUG Received KEEPALIVE on Tunnel 6YNB
Aug 04 18:34:21-703013 cadet-con-21308 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6YNB) via Tunnel 6YNB
Aug 04 18:34:21-703138 cadet-tun-21308 DEBUG Encrypting 4 bytes for Tunnel 6YNB
Aug 04 18:34:21-703299 cadet-con-21302 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6DEV) via Tunnel 6DEV
Aug 04 18:34:21-703684 cadet-tun-21302 DEBUG Encrypting 4 bytes for Tunnel 6DEV
Aug 04 18:34:21-709227 cadet-tun-21308 DEBUG Sending payload of Tunnel 6YNB on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:21-709336 cadet-con-21308 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:21-709371 cadet-per-21308 DEBUG Queueing message to peer 6YNB in MQM 0x55da60488e60
Aug 04 18:34:21-709409 cadet-per-21308 DEBUG Sending to peer 6YNB from MQM 0x55da60488e60
Aug 04 18:34:21-709480 cadet-tun-21302 DEBUG Sending payload of Tunnel 6DEV on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:21-709577 cadet-con-21302 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:21-709585 cadet-tun-21308 DEBUG Connection 8P5P2R (Tunnel 6YNB) now ready for Tunnel 6YNB in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:21-709680 cadet-per-21302 DEBUG Queueing message to peer 6DEV in MQM 0x561205b84ae0
Aug 04 18:34:21-709690 cadet-tun-21308 DEBUG Not sending payload of Tunnel 6YNB on ready Connection 8P5P2R (Tunnel 6YNB) (nothing pending)
Aug 04 18:34:21-709757 cadet-per-21302 DEBUG Sending to peer 6DEV from MQM 0x561205b84ae0
Aug 04 18:34:21-709762 cadet-con-21308 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6YNB) became available in state 4
Aug 04 18:34:21-709854 cadet-tun-21302 DEBUG Connection 8P5P2R (Tunnel 6DEV) now ready for Tunnel 6DEV in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:21-709917 cadet-tun-21302 DEBUG Not sending payload of Tunnel 6DEV on ready Connection 8P5P2R (Tunnel 6DEV) (nothing pending)
Aug 04 18:34:21-709969 cadet-con-21302 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6DEV) became available in state 4
Aug 04 18:34:21-710173 cadet-per-21308 DEBUG Sending to peer 6YNB completed
Aug 04 18:34:21-710342 cadet-per-21302 DEBUG Sending to peer 6DEV completed
Aug 04 18:34:21-712248 cadet-tun-21308 DEBUG Tunnel 6YNB received 116 bytes of encrypted data in state 5
Aug 04 18:34:21-712321 cadet-tun-21302 DEBUG Tunnel 6DEV received 116 bytes of encrypted data in state 5
Aug 04 18:34:21-713011 cadet-tun-21308 DEBUG Received KEEPALIVE on Tunnel 6YNB
Aug 04 18:34:21-713033 cadet-tun-21302 DEBUG Received KEEPALIVE on Tunnel 6DEV
Aug 04 18:34:22-710929 cadet-con-21308 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6YNB) via Tunnel 6YNB
Aug 04 18:34:22-711009 cadet-tun-21308 DEBUG Encrypting 4 bytes for Tunnel 6YNB
Aug 04 18:34:22-711070 cadet-con-21302 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6DEV) via Tunnel 6DEV
Aug 04 18:34:22-711121 cadet-tun-21302 DEBUG Encrypting 4 bytes for Tunnel 6DEV
Aug 04 18:34:22-714543 cadet-tun-21308 DEBUG Sending payload of Tunnel 6YNB on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:22-714610 cadet-tun-21302 DEBUG Sending payload of Tunnel 6DEV on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:22-714658 cadet-con-21302 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:22-714684 cadet-con-21308 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:22-714707 cadet-per-21308 DEBUG Queueing message to peer 6YNB in MQM 0x55da60488e60
Aug 04 18:34:22-714694 cadet-per-21302 DEBUG Queueing message to peer 6DEV in MQM 0x561205b84ae0
Aug 04 18:34:22-714728 cadet-per-21308 DEBUG Sending to peer 6YNB from MQM 0x55da60488e60
Aug 04 18:34:22-714759 cadet-tun-21308 DEBUG Connection 8P5P2R (Tunnel 6YNB) now ready for Tunnel 6YNB in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:22-714761 cadet-per-21302 DEBUG Sending to peer 6DEV from MQM 0x561205b84ae0
Aug 04 18:34:22-714784 cadet-tun-21308 DEBUG Not sending payload of Tunnel 6YNB on ready Connection 8P5P2R (Tunnel 6YNB) (nothing pending)
Aug 04 18:34:22-714813 cadet-con-21308 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6YNB) became available in state 4
Aug 04 18:34:22-714846 cadet-tun-21302 DEBUG Connection 8P5P2R (Tunnel 6DEV) now ready for Tunnel 6DEV in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:22-714893 cadet-tun-21302 DEBUG Not sending payload of Tunnel 6DEV on ready Connection 8P5P2R (Tunnel 6DEV) (nothing pending)
Aug 04 18:34:22-714929 cadet-con-21302 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6DEV) became available in state 4
Aug 04 18:34:22-714988 cadet-per-21308 DEBUG Sending to peer 6YNB completed
Aug 04 18:34:22-715109 cadet-per-21302 DEBUG Sending to peer 6DEV completed
Aug 04 18:34:22-715974 cadet-tun-21308 DEBUG Tunnel 6YNB received 116 bytes of encrypted data in state 5
Aug 04 18:34:22-716409 cadet-tun-21308 DEBUG Received KEEPALIVE on Tunnel 6YNB
Aug 04 18:34:22-716428 cadet-tun-21302 DEBUG Tunnel 6DEV received 116 bytes of encrypted data in state 5
Aug 04 18:34:22-716747 cadet-tun-21302 DEBUG Received KEEPALIVE on Tunnel 6DEV
Aug 04 18:34:23-557200 cadet-21302 DEBUG HELLO has 180 bytes of address data
Aug 04 18:34:23-557328 cadet-dht-21302 DEBUG Announcing my HELLO (220 bytes) in the DHT
Aug 04 18:34:23-560779 cadet-21308 DEBUG HELLO has 180 bytes of address data
Aug 04 18:34:23-560893 cadet-dht-21308 DEBUG Announcing my HELLO (220 bytes) in the DHT
Aug 04 18:34:23-715032 cadet-con-21308 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6YNB) via Tunnel 6YNB
Aug 04 18:34:23-715116 cadet-tun-21308 DEBUG Encrypting 4 bytes for Tunnel 6YNB
Aug 04 18:34:23-715167 cadet-con-21302 INFO Sending KEEPALIVE on behalf of Connection 8P5P2R (Tunnel 6DEV) via Tunnel 6DEV
Aug 04 18:34:23-715269 cadet-tun-21302 DEBUG Encrypting 4 bytes for Tunnel 6DEV
Aug 04 18:34:23-719988 cadet-tun-21308 DEBUG Sending payload of Tunnel 6YNB on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:23-720038 cadet-con-21308 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:23-720062 cadet-per-21308 DEBUG Queueing message to peer 6YNB in MQM 0x55da60488e60
Aug 04 18:34:23-720087 cadet-per-21308 DEBUG Sending to peer 6YNB from MQM 0x55da60488e60
Aug 04 18:34:23-720142 cadet-tun-21308 DEBUG Connection 8P5P2R (Tunnel 6YNB) now ready for Tunnel 6YNB in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:23-720174 cadet-tun-21308 DEBUG Not sending payload of Tunnel 6YNB on ready Connection 8P5P2R (Tunnel 6YNB) (nothing pending)
Aug 04 18:34:23-720205 cadet-con-21308 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6YNB) became available in state 4
Aug 04 18:34:23-720278 cadet-tun-21302 DEBUG Sending payload of Tunnel 6DEV on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:23-720322 cadet-con-21302 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6DEV)
Aug 04 18:34:23-720350 cadet-per-21302 DEBUG Queueing message to peer 6DEV in MQM 0x561205b84ae0
Aug 04 18:34:23-720377 cadet-per-21302 DEBUG Sending to peer 6DEV from MQM 0x561205b84ae0
Aug 04 18:34:23-720392 cadet-per-21308 DEBUG Sending to peer 6YNB completed
Aug 04 18:34:23-720413 cadet-tun-21302 DEBUG Connection 8P5P2R (Tunnel 6DEV) now ready for Tunnel 6DEV in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:23-720445 cadet-tun-21302 DEBUG Not sending payload of Tunnel 6DEV on ready Connection 8P5P2R (Tunnel 6DEV) (nothing pending)
Aug 04 18:34:23-720470 cadet-con-21302 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6DEV) became available in state 4
Aug 04 18:34:23-720600 cadet-per-21302 DEBUG Sending to peer 6DEV completed
Aug 04 18:34:23-721240 cadet-tun-21302 DEBUG Tunnel 6DEV received 116 bytes of encrypted data in state 5
Aug 04 18:34:23-721273 cadet-tun-21308 DEBUG Tunnel 6YNB received 116 bytes of encrypted data in state 5
Aug 04 18:34:23-721965 cadet-tun-21308 DEBUG Received KEEPALIVE on Tunnel 6YNB
Aug 04 18:34:23-721992 cadet-tun-21302 DEBUG Received KEEPALIVE on Tunnel 6DEV
Aug 04 18:34:24-605191 test_cadet_small-21281 INFO gathering statistics from line 952
Aug 04 18:34:24-605286 test_cadet_small-21281 INFO Destroying channel due to GNUNET_CADET_channel_destroy()
Aug 04 18:34:24-605323 cadet-api-21281 DEBUG Destroying channel 80000000 of 0x559a795b7d00
Aug 04 18:34:24-605512 cadet-21308 DEBUG Client(0) is destroying Channel 6YNB:38KQGBKV ctn:0(80000000/0)
Aug 04 18:34:24-605587 cadet-chn-21308 DEBUG Client(0) asks for destruction of Channel 6YNB:38KQGBKV ctn:0(80000000/0)
Aug 04 18:34:24-605640 cadet-tun-21308 DEBUG Sending DESTORY message for channel ID 0
Aug 04 18:34:24-605696 cadet-tun-21308 DEBUG Encrypting 12 bytes for Tunnel 6YNB
Aug 04 18:34:24-611685 cadet-tun-21308 DEBUG Removing Channel 6YNB:38KQGBKV ctn:0(0/0) from Tunnel 6YNB
Aug 04 18:34:24-611833 cadet-tun-21308 DEBUG Sending payload of Tunnel 6YNB on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:24-611898 cadet-con-21308 DEBUG Scheduling message for transmission on Connection 8P5P2R (Tunnel 6YNB)
Aug 04 18:34:24-611948 cadet-per-21308 DEBUG Queueing message to peer 6YNB in MQM 0x55da60488e60
Aug 04 18:34:24-612136 cadet-per-21308 DEBUG Sending to peer 6YNB from MQM 0x55da60488e60
Aug 04 18:34:24-612208 cadet-tun-21308 DEBUG Connection 8P5P2R (Tunnel 6YNB) now ready for Tunnel 6YNB in state CADET_TUNNEL_KEY_OK
Aug 04 18:34:24-612271 cadet-tun-21308 DEBUG Not sending payload of Tunnel 6YNB on ready Connection 8P5P2R (Tunnel 6YNB) (nothing pending)
Aug 04 18:34:24-612321 cadet-con-21308 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6YNB) became available in state 4
Aug 04 18:34:24-612392 cadet-con-21308 DEBUG Scheduling keepalive for Connection 8P5P2R (Tunnel 6YNB) in 1 s
Aug 04 18:34:24-612750 cadet-per-21308 DEBUG Sending to peer 6YNB completed
Aug 04 18:34:24-614364 cadet-tun-21302 DEBUG Tunnel 6DEV received 124 bytes of encrypted data in state 5
Aug 04 18:34:24-615521 cadet-tun-21302 DEBUG Received channel DESTROY on Channel 6DEV:38KQGBKV ctn:0(0/0) from Tunnel 6DEV
Aug 04 18:34:24-615599 cadet-chn-21302 DEBUG Received remote channel DESTROY for Channel 6DEV:38KQGBKV ctn:0(0/0)
Aug 04 18:34:24-615672 cadet-tun-21302 DEBUG Removing Channel 6DEV:38KQGBKV ctn:0(0/0) from Tunnel 6DEV
Aug 04 18:34:24-616545 cadet-api-21281 DEBUG Received channel destroy for channel 0 from CADET service
Aug 04 18:34:24-616572 cadet-api-21281 DEBUG Destroying channel 0 of 0x559a795d3520
Aug 04 18:34:24-616588 test_cadet_small-21281 INFO Channel disconnected at 1
Aug 04 18:34:24-616820 test_cadet_small-21281 INFO STATS PEER 0 - cadet [# encrypted bytes]: 164
Aug 04 18:34:24-616847 test_cadet_small-21281 INFO STATS PEER 1 - cadet [# decrypted bytes]: 164
Aug 04 18:34:24-616875 test_cadet_small-21281 INFO STATS PEER 0 - cadet [# keepalives received]: 19
Aug 04 18:34:24-616899 test_cadet_small-21281 INFO STATS PEER 1 - cadet [# keepalives received]: 19
Aug 04 18:34:24-616933 test_cadet_small-21281 INFO STATS PEER 0 - cadet [# decrypted bytes]: 152
Aug 04 18:34:24-616961 test_cadet_small-21281 INFO STATS PEER 1 - cadet [# encrypted bytes]: 152
Aug 04 18:34:24-616996 test_cadet_small-21281 INFO STATS PEER 0 - cadet [# keepalives sent]: 19
Aug 04 18:34:24-617027 test_cadet_small-21281 INFO STATS PEER 1 - cadet [# keepalives sent]: 19
Aug 04 18:34:24-617056 test_cadet_small-21281 INFO STATS PEER 0 - cadet [# DHT announce]: 5
Aug 04 18:34:24-617082 test_cadet_small-21281 INFO STATS PEER 1 - cadet [# DHT announce]: 5
Aug 04 18:34:24-617115 test_cadet_small-21281 INFO STATS PEER 0 - cadet [# KX_AUTH received]: 1
Aug 04 18:34:24-617144 test_cadet_small-21281 INFO STATS PEER 1 - cadet [# channels]: 2
Aug 04 18:34:24-617178 test_cadet_small-21281 INFO STATS PEER 0 - cadet [# KX transmitted]: 1
Aug 04 18:34:24-617211 test_cadet_small-21281 INFO STATS PEER 1 - cadet [# KX_AUTH transmitted]: 1
Aug 04 18:34:24-617247 test_cadet_small-21281 INFO STATS PEER 0 - cadet [# channels]: 1
Aug 04 18:34:24-617279 test_cadet_small-21281 INFO STATS PEER 1 - cadet [# Fresh KX setup]: 1
Aug 04 18:34:24-617318 test_cadet_small-21281 INFO STATS PEER 0 - cadet [# DHT search]: 1
Aug 04 18:34:24-617347 test_cadet_small-21281 INFO STATS PEER 1 - cadet [# KX received]: 1
Aug 04 18:34:24-617382 test_cadet_small-21281 INFO STATS PEER 0 - cadet [# clients]: 1
Aug 04 18:34:24-617417 test_cadet_small-21281 INFO STATS PEER 1 - cadet [# clients]: 1
Aug 04 18:34:24-617458 test_cadet_small-21281 INFO KA sent: 19, KA received: 19
Aug 04 18:34:24-617641 test_cadet_small-21281 DEBUG Cleaning all up
Aug 04 18:34:24-617827 test_cadet_small-21281 DEBUG Cleaning all up
Aug 04 18:34:24-617866 test_cadet_small-21281 INFO disconnecting cadet service of peers, called from line 952
Aug 04 18:34:24-618103 cadet-21308 DEBUG Client dropped: 0x55da60487240 (MQ: 0x55da60486ee0)
Aug 04 18:34:24-618136 cadet-21308 DEBUG Client(0) is disconnecting.
Aug 04 18:34:24-618174 cadet-21308 DEBUG Closing port 38KQGBKV due to Client(0) disconnect.
Aug 04 18:34:24-618338 cadet-21302 DEBUG Client dropped: 0x561205b83240 (MQ: 0x561205b82ee0)
Aug 04 18:34:24-618355 test_cadet_small-21281 DEBUG Ending test.
Aug 04 18:34:24-618370 cadet-21302 DEBUG Client(0) is disconnecting.
Aug 04 18:34:24-618398 cadet-21302 DEBUG Closing port 38KQGBKV due to Client(0) disconnect.
Aug 04 18:34:24-620464 cadet-21302 DEBUG Shutting down
Aug 04 18:34:24-620508 cadet-cor-21302 DEBUG CORE connection to peer 6DEV went down.
Aug 04 18:34:24-620526 cadet-per-21302 DEBUG Message queue for peer 6DEV is now 0
Aug 04 18:34:24-620547 cadet-con-21302 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6DEV) went down
Aug 04 18:34:24-620566 cadet-tun-21302 DEBUG Connection 8P5P2R (Tunnel 6DEV) no longer ready for Tunnel 6DEV
Aug 04 18:34:24-620584 cadet-per-21302 DEBUG Updating peer 6DEV activation state (0 connections) with tunnel
Aug 04 18:34:24-620611 cadet-dht-21302 DEBUG Starting DHT GET for peer 6DEV (0x561205b81fe0)
Aug 04 18:34:24-620634 cadet-cor-21302 DEBUG CORE connection to peer 6YNB went down.
Aug 04 18:34:24-620650 cadet-per-21302 DEBUG Message queue for peer 6YNB is now 0
Aug 04 18:34:24-620684 cadet-21302 DEBUG Cleaning all up
Aug 04 18:34:24-620711 cadet-tun-21302 DEBUG Destroying idle Tunnel 6DEV
Aug 04 18:34:24-620728 cadet-per-21302 DEBUG Destroying MQM 0x561205b84ae0 for peer 6DEV with last ditch transmission
Aug 04 18:34:24-620744 cadet-con-21302 DEBUG Destroying Connection 8P5P2R
Aug 04 18:34:24-620762 cadet-pat-21302 DEBUG Removing connection Connection 8P5P2R to path 6DEV(0x561205b7b600) at offset 0
Aug 04 18:34:24-620780 cadet-per-21302 DEBUG Dropping tunnel Tunnel 6DEV to peer 6DEV
Aug 04 18:34:24-620799 cadet-per-21302 DEBUG Destroying all paths to 6DEV
Aug 04 18:34:24-620815 cadet-pat-21302 DEBUG Owner releases path 6DEV(0x561205b7b600)
Aug 04 18:34:24-620831 cadet-per-21302 DEBUG Removing knowledge about peer 6DEV beging on path 6DEV(0x561205b7b600) at offset 0
Aug 04 18:34:24-620848 cadet-per-21302 DEBUG Destroying all paths to 6YNB
Aug 04 18:34:24-620861 cadet-per-21302 DEBUG Destroying all peers now
Aug 04 18:34:24-620875 cadet-per-21302 DEBUG Destroying state about peer 6DEV
Aug 04 18:34:24-620889 cadet-dht-21302 DEBUG Stopping DHT GET 0x561205b81fe0
Aug 04 18:34:24-620907 cadet-per-21302 DEBUG Destroying state about peer 6YNB
* Lost NATed local address 192.168.7.155, stopping NAT server
* Lost NATed local address 192.168.7.155, stopping NAT server
Aug 04 18:34:24-622168 transport-api-core-21311 ERROR Error receiving from transport service (1), disconnecting temporarily.
Aug 04 18:34:24-624972 cadet-21308 DEBUG Disconnecting from DHT service, will try to reconnect in 0 ms
Aug 04 18:34:24-625053 cadet-cor-21308 DEBUG CORE connection to peer 6DEV went down.
Aug 04 18:34:24-625076 cadet-per-21308 DEBUG Message queue for peer 6DEV is now 0
Aug 04 18:34:24-625104 cadet-cor-21308 DEBUG CORE connection to peer 6YNB went down.
Aug 04 18:34:24-625126 cadet-per-21308 DEBUG Message queue for peer 6YNB is now 0
Aug 04 18:34:24-625154 cadet-con-21308 DEBUG Core MQ for Connection 8P5P2R (Tunnel 6YNB) went down
Aug 04 18:34:24-625192 cadet-tun-21308 DEBUG Connection 8P5P2R (Tunnel 6YNB) no longer ready for Tunnel 6YNB
Aug 04 18:34:24-625209 cadet-per-21308 DEBUG Updating peer 6YNB activation state (0 connections) with tunnel
Aug 04 18:34:24-625234 cadet-dht-21308 DEBUG Starting DHT GET for peer 6YNB (0x55da60488400)
Aug 04 18:34:24-625320 cadet-21308 DEBUG Shutting down
Aug 04 18:34:24-625355 cadet-21308 DEBUG Cleaning all up
Aug 04 18:34:24-625390 cadet-tun-21308 DEBUG Destroying idle Tunnel 6YNB
Aug 04 18:34:24-625413 cadet-per-21308 DEBUG Destroying MQM 0x55da60488e60 for peer 6YNB with last ditch transmission
Aug 04 18:34:24-625439 cadet-con-21308 DEBUG Destroying Connection 8P5P2R
Aug 04 18:34:24-625470 cadet-pat-21308 DEBUG Removing connection Connection 8P5P2R to path 6YNB(0x55da60488c00) at offset 0
Aug 04 18:34:24-625502 cadet-per-21308 DEBUG Dropping tunnel Tunnel 6YNB to peer 6YNB
Aug 04 18:34:24-625548 cadet-per-21308 DEBUG Destroying all paths to 6DEV
Aug 04 18:34:24-625563 cadet-per-21308 DEBUG Destroying all paths to 6YNB
Aug 04 18:34:24-625583 cadet-pat-21308 DEBUG Owner releases path 6YNB(0x55da60488c00)
Aug 04 18:34:24-625603 cadet-per-21308 DEBUG Removing knowledge about peer 6YNB beging on path 6YNB(0x55da60488c00) at offset 0
Aug 04 18:34:24-625622 cadet-per-21308 DEBUG Destroying all peers now
Aug 04 18:34:24-625641 cadet-per-21308 DEBUG Destroying state about peer 6DEV
Aug 04 18:34:24-625659 cadet-per-21308 DEBUG Destroying state about peer 6YNB
Aug 04 18:34:24-625676 cadet-dht-21308 DEBUG Stopping DHT GET 0x55da60488400
Aug 04 18:34:24-630505 test_cadet_small-21281 DEBUG success
PASS test_cadet_2_keepalive (exit status: 0)
test_cadet_2_keepalive.log (86,836 bytes)   

schanzen

2019-08-04 18:41

administrator   ~0014772

No, because this test needs to be rewritten to reflect the API change (see above). It currently has broken logic.

schanzen

2024-03-12 14:50

administrator   ~0021869

Test does not exist anymore (testbed removed)

Issue History

Date Modified Username Field Change
2019-07-23 14:40 schanzen New Issue
2019-07-23 15:41 ch3 Note Added: 0014727
2019-07-23 15:46 ch3 Note Added: 0014728
2019-07-23 16:44 schanzen Note Added: 0014730
2019-07-23 16:59 schanzen Note Added: 0014731
2019-07-23 17:15 schanzen Note Edited: 0014730
2019-07-23 17:23 schanzen Note Added: 0014732
2019-07-23 17:23 schanzen Assigned To => schanzen
2019-07-23 17:23 schanzen Status new => confirmed
2019-08-01 10:36 schanzen Assigned To schanzen =>
2019-08-01 12:27 schanzen Target Version => 0.11.7
2019-08-04 18:40 xrs File Added: test_cadet_2_keepalive.log
2019-08-04 18:40 xrs Note Added: 0014771
2019-08-04 18:41 schanzen Note Added: 0014772
2019-10-27 19:26 schanzen Target Version 0.11.7 => 0.11.8
2019-11-04 23:05 schanzen Target Version 0.11.8 => 0.11.9
2020-10-29 11:11 schanzen Summary test_cadet_2_keepalive always fails => test_cadet_2_keepalive needs rewrite WAS: test_cadet_2_keepalive always fails
2024-03-12 14:50 schanzen Assigned To => schanzen
2024-03-12 14:50 schanzen Status confirmed => resolved
2024-03-12 14:50 schanzen Resolution open => not fixable
2024-03-12 14:50 schanzen Fixed in Version => 0.21.0
2024-03-12 14:50 schanzen Note Added: 0021869
2024-03-12 14:57 schanzen Status resolved => closed