Feb 13 18:23:05-640628 cadet-27847 INFO CADET started for peer 7ER4 Feb 13 18:23:05-661816 gnunet-daemon-topology-27846 WARNING `write' failed on file `/home/culrich/environment/./test/.config/gnunet//topology/friends.txt' at friends.c:64 with error: No such file or directory Feb 13 18:23:05-695591 cadet-api-27852 DEBUG GNUNET_CADET_connect() 0x1a5d2b0 Feb 13 18:23:05-706138 cadet-api-27852 DEBUG Connecting to CADET Feb 13 18:23:05-706736 cadet-27847 DEBUG Client(0) connected Feb 13 18:23:05-707060 cadet-27847 DEBUG Open port X4QX93K5 requested by Client(0) Feb 13 18:23:05-734379 cadet-api-27858 DEBUG GNUNET_CADET_connect() 0x213bbb0 Feb 13 18:23:05-738829 cadet-cor-27847 DEBUG CORE connection to peer 7ER4 was established. Feb 13 18:23:05-739865 cadet-per-27847 DEBUG Creating peer P(7ER4) Feb 13 18:23:05-739892 cadet-per-27847 DEBUG Message queue for peer P(7ER4) is now 0x686d00 Feb 13 18:23:05-739915 cadet-per-27847 DEBUG Updating peer P(7ER4) activation state (0 connections) with CORE link Feb 13 18:23:05-739545 cadet-api-27858 DEBUG Connecting to CADET Feb 13 18:23:05-742801 cadet-27847 DEBUG Client(1) connected Feb 13 18:23:05-749737 nat-27862 ERROR UPnP enabled in configuration, but UPnP client `upnpc` command not found, disabling UPnP Feb 13 18:23:05-873431 cadet-dht-27847 DEBUG Announcing my HELLO (472 bytes) in the DHT Feb 13 18:23:36-150877 transport-27856 WARNING External protocol violation detected at plugin_transport_udp.c:1275. Feb 13 18:23:36-218273 cadet-hll-27847 DEBUG Hello for NB9P (64 bytes), expires on Tue Feb 14 06:23:36 2017 Feb 13 18:23:36-218333 cadet-per-27847 DEBUG Creating peer P(NB9P) Feb 13 18:23:36-218369 cadet-per-27847 DEBUG Got 64 byte HELLO for peer P(NB9P) Feb 13 18:23:36-252117 cadet-hll-27847 DEBUG Hello for NB9P (100 bytes), expires on Tue Feb 14 06:23:36 2017 Feb 13 18:23:36-252150 cadet-per-27847 DEBUG Got 100 byte HELLO for peer P(NB9P) Feb 13 18:23:36-297174 cadet-hll-27847 DEBUG Hello for NB9P (124 bytes), expires on Tue Feb 14 06:23:36 2017 Feb 13 18:23:36-297207 cadet-per-27847 DEBUG Got 124 byte HELLO for peer P(NB9P) Feb 13 18:23:36-297969 cadet-hll-27847 DEBUG Hello for NB9P (160 bytes), expires on Tue Feb 14 06:23:36 2017 Feb 13 18:23:36-297997 cadet-per-27847 DEBUG Got 160 byte HELLO for peer P(NB9P) Feb 13 18:23:52-297186 cadet-cor-27847 DEBUG CORE connection to peer NB9P was established. Feb 13 18:23:52-297283 cadet-per-27847 DEBUG Message queue for peer P(NB9P) is now 0x688100 Feb 13 18:23:52-297319 cadet-per-27847 DEBUG Updating peer P(NB9P) activation state (0 connections) with CORE link Feb 13 18:23:53-299203 cadet-api-27852 DEBUG Creating new channel to NB9P:851234184 at 0x1a77bc0 number 80000000 Feb 13 18:23:53-299496 cadet-api-27852 DEBUG CADET NOTIFY TRANSMIT READY on channel 80000000 allow_send is 0 to origin with 76 bytes Feb 13 18:23:53-299769 cadet-27847 DEBUG New channel to NB9P at port X4QX93K5 requested by Client(0) Feb 13 18:23:53-299812 cadet-tun-27847 DEBUG Creating new ephemeral ratchet key (DHRs) Feb 13 18:23:53-308424 cadet-per-27847 DEBUG Updating peer P(NB9P) activation state (0 connections) with tunnel with CORE link Feb 13 18:23:53-308617 cadet-tun-27847 DEBUG Adding Channel NB9P:X4QX93K5 ctn:0(80000000/0) to Tunnel NB9P Feb 13 18:23:53-308788 cadet-chn-27847 DEBUG Created channel to port X4QX93K5 at peer P(NB9P) for Client(0) using Tunnel NB9P Feb 13 18:23:53-310325 cadet-tun-27847 DEBUG Performing connection maintenance for Tunnel NB9P. Feb 13 18:23:53-310499 cadet-per-27847 DEBUG Iterating over paths to peer P(NB9P) including direct link Feb 13 18:23:53-310657 cadet-per-27847 DEBUG Asked to look for paths at distance 0, but maximum for me is < 0 Feb 13 18:23:53-310803 cadet-per-27847 DEBUG Discovered that peer P(NB9P) is on path NB9P(0x689180) at offset 0 Feb 13 18:23:53-310966 cadet-con-27847 DEBUG Creating Connection GE8FF7 (Tunnel NB9P) using path NB9P(0x689180) Feb 13 18:23:53-311110 cadet-pat-27847 DEBUG Adding connection Connection GE8FF7 (Tunnel NB9P) to path NB9P(0x689180) at offset 0 Feb 13 18:23:53-311251 cadet-per-27847 DEBUG Creating MQM 0x6897c0 for peer P(NB9P) Feb 13 18:23:53-311420 cadet-con-27847 DEBUG Core MQ for Connection GE8FF7 (Tunnel NB9P) became available in state 0 Feb 13 18:23:53-311574 cadet-tun-27847 DEBUG Found interesting path NB9P(0x689180) for Tunnel NB9P, created Connection GE8FF7 (Tunnel NB9P) Feb 13 18:23:53-311718 cadet-pat-27847 DEBUG Created new path NB9P(0x689180) to create inverse for incoming connection Feb 13 18:23:53-311866 cadet-per-27847 DEBUG Attaching path NB9P(0x689180) to peer P(NB9P) (forced) Feb 13 18:23:53-311918 cadet-tun-27847 DEBUG Ignoring duplicate path NB9P(0x689180). Feb 13 18:23:53-311956 cadet-tun-27847 DEBUG Ignoring duplicate path NB9P(0x689180). Feb 13 18:23:53-312013 cadet-con-27847 DEBUG Sending CADET_CONNECTION_CREATE message for Connection GE8FF7 (Tunnel NB9P) Feb 13 18:23:53-312054 cadet-per-27847 DEBUG Queueing message to peer P(NB9P) in MQM 0x6897c0 Feb 13 18:23:53-312097 cadet-per-27847 DEBUG Sending to peer P(NB9P) from MQM 0x6897c0 Feb 13 18:23:53-312158 cadet-con-27847 DEBUG Core MQ for Connection GE8FF7 (Tunnel NB9P) became available in state 2 Feb 13 18:23:53-314310 cadet-con-27847 DEBUG Sending CADET_CONNECTION_CREATE message for Connection GE8FF7 (Tunnel NB9P) Feb 13 18:23:53-314380 cadet-per-27847 DEBUG Queueing message to peer P(NB9P) in MQM 0x6897c0 Feb 13 18:23:55-606842 core-27851 WARNING Client waited 3308 ms for permission to transmit to `NB9P' (priority 1) Feb 13 18:23:55-608096 cadet-per-27847 DEBUG Sending to peer P(NB9P) completed Feb 13 18:23:55-608145 cadet-per-27847 DEBUG Sending to peer P(NB9P) from MQM 0x6897c0 Feb 13 18:23:55-608182 cadet-con-27847 DEBUG Core MQ for Connection GE8FF7 (Tunnel NB9P) became available in state 2 Feb 13 18:23:55-608908 core-27851 WARNING Client waited 3310 ms for transmission of 348 bytes to `NB9P' (uncorked) Feb 13 18:23:55-611301 cadet-per-27847 DEBUG Sending to peer P(NB9P) completed Feb 13 18:23:55-612442 cadet-con-27847 DEBUG Sending CADET_CONNECTION_CREATE message for Connection GE8FF7 (Tunnel NB9P) Feb 13 18:23:55-612486 cadet-per-27847 DEBUG Queueing message to peer P(NB9P) in MQM 0x6897c0 Feb 13 18:23:55-612516 cadet-per-27847 DEBUG Sending to peer P(NB9P) from MQM 0x6897c0 Feb 13 18:23:55-612552 cadet-con-27847 DEBUG Core MQ for Connection GE8FF7 (Tunnel NB9P) became available in state 2 Feb 13 18:23:55-613407 cadet-per-27847 DEBUG Sending to peer P(NB9P) completed Feb 13 18:23:55-620713 cadet-con-27847 DEBUG Sending CADET_CONNECTION_CREATE message for Connection GE8FF7 (Tunnel NB9P) Feb 13 18:23:55-620758 cadet-per-27847 DEBUG Queueing message to peer P(NB9P) in MQM 0x6897c0 Feb 13 18:23:55-620785 cadet-per-27847 DEBUG Sending to peer P(NB9P) from MQM 0x6897c0 Feb 13 18:23:55-620815 cadet-con-27847 DEBUG Core MQ for Connection GE8FF7 (Tunnel NB9P) became available in state 2 Feb 13 18:23:55-621029 cadet-per-27847 DEBUG Sending to peer P(NB9P) completed Feb 13 18:23:55-636968 cadet-con-27847 DEBUG Sending CADET_CONNECTION_CREATE message for Connection GE8FF7 (Tunnel NB9P) Feb 13 18:23:55-637013 cadet-per-27847 DEBUG Queueing message to peer P(NB9P) in MQM 0x6897c0 Feb 13 18:23:55-637038 cadet-per-27847 DEBUG Sending to peer P(NB9P) from MQM 0x6897c0 Feb 13 18:23:55-637068 cadet-con-27847 DEBUG Core MQ for Connection GE8FF7 (Tunnel NB9P) became available in state 2 Feb 13 18:23:55-637292 cadet-per-27847 DEBUG Sending to peer P(NB9P) completed Feb 13 18:23:55-669223 cadet-con-27847 DEBUG Sending CADET_CONNECTION_CREATE message for Connection GE8FF7 (Tunnel NB9P) Feb 13 18:23:55-669270 cadet-per-27847 DEBUG Queueing message to peer P(NB9P) in MQM 0x6897c0 Feb 13 18:23:55-669297 cadet-per-27847 DEBUG Sending to peer P(NB9P) from MQM 0x6897c0 Feb 13 18:23:55-669328 cadet-con-27847 DEBUG Core MQ for Connection GE8FF7 (Tunnel NB9P) became available in state 2 Feb 13 18:23:55-669617 cadet-per-27847 DEBUG Sending to peer P(NB9P) completed Feb 13 18:23:55-703261 cadet-hll-27847 DEBUG Hello for NB9P (472 bytes), expires on Tue Feb 14 06:23:36 2017 Feb 13 18:23:55-703304 cadet-per-27847 DEBUG Got 472 byte HELLO for peer P(NB9P) Feb 13 18:23:55-733524 cadet-con-27847 DEBUG Sending CADET_CONNECTION_CREATE message for Connection GE8FF7 (Tunnel NB9P) Feb 13 18:23:55-733607 cadet-per-27847 DEBUG Queueing message to peer P(NB9P) in MQM 0x6897c0 Feb 13 18:23:55-733631 cadet-per-27847 DEBUG Sending to peer P(NB9P) from MQM 0x6897c0 Feb 13 18:23:55-733662 cadet-con-27847 DEBUG Core MQ for Connection GE8FF7 (Tunnel NB9P) became available in state 2 Feb 13 18:23:55-733974 cadet-per-27847 DEBUG Sending to peer P(NB9P) completed Feb 13 18:23:55-760955 cadet-cor-27847 DEBUG Received CONNECTION_CREATE_ACK for connection GE8FF7. Feb 13 18:23:55-760995 cadet-con-27847 DEBUG Received CADET_CONNECTION_CREATE_ACK for Connection GE8FF7 (Tunnel NB9P) in state 2 (MQM ready) Feb 13 18:23:55-761025 cadet-tun-27847 DEBUG Connection GE8FF7 (Tunnel NB9P) now ready for Tunnel NB9P in state CADET_TUNNEL_KEY_UNINITIALIZED Feb 13 18:23:55-761051 cadet-tun-27847 DEBUG Sending KX on Tunnel NB9P via Connection GE8FF7 (Tunnel NB9P) using CADET_TUNNEL_KEY_UNINITIALIZED in state Feb 13 18:23:55-767599 cadet-tun-27847 DEBUG Tunnel NB9P estate changed from CADET_TUNNEL_KEY_UNINITIALIZED to CADET_TUNNEL_KEY_AX_SENT Feb 13 18:23:55-767657 cadet-con-27847 DEBUG Scheduling message for transmission on Connection GE8FF7 (Tunnel NB9P) Feb 13 18:23:55-767700 cadet-per-27847 DEBUG Queueing message to peer P(NB9P) in MQM 0x6897c0 Feb 13 18:23:55-767740 cadet-per-27847 DEBUG Sending to peer P(NB9P) from MQM 0x6897c0 Feb 13 18:23:55-767789 cadet-tun-27847 DEBUG Connection GE8FF7 (Tunnel NB9P) now ready for Tunnel NB9P in state CADET_TUNNEL_KEY_AX_SENT Feb 13 18:23:55-767834 cadet-con-27847 DEBUG Core MQ for Connection GE8FF7 (Tunnel NB9P) became available in state 4 Feb 13 18:23:55-767881 cadet-con-27847 DEBUG Scheduling keepalive for Connection GE8FF7 (Tunnel NB9P) in 5 m Feb 13 18:23:55-768063 cadet-cor-27847 DEBUG Received CONNECTION_CREATE_ACK for connection GE8FF7. Feb 13 18:23:55-768113 cadet-con-27847 DEBUG Received CADET_CONNECTION_CREATE_ACK for Connection GE8FF7 (Tunnel NB9P) in state 4 (MQM ready) Feb 13 18:23:55-768339 cadet-per-27847 DEBUG Sending to peer P(NB9P) completed Feb 13 18:23:55-769549 cadet-cor-27847 DEBUG Received CONNECTION_CREATE_ACK for connection GE8FF7. Feb 13 18:23:55-769668 cadet-con-27847 DEBUG Received CADET_CONNECTION_CREATE_ACK for Connection GE8FF7 (Tunnel NB9P) in state 4 (MQM ready) Feb 13 18:23:55-822138 cadet-tun-27847 DEBUG Handling KX_AUTH message for Tunnel NB9P Feb 13 18:23:55-831434 cadet-tun-27847 DEBUG Tunnel NB9P estate changed from CADET_TUNNEL_KEY_AX_SENT to CADET_TUNNEL_KEY_OK Feb 13 18:23:55-831496 cadet-chn-27847 DEBUG Tunnel up, sending CHANNEL_OPEN on Channel NB9P:X4QX93K5 ctn:0(80000000/0) now Feb 13 18:23:55-831560 cadet-chn-27847 DEBUG Sending CHANNEL_OPEN message for Channel NB9P:X4QX93K5 ctn:0(80000000/0) Feb 13 18:23:55-831608 cadet-tun-27847 DEBUG Encrypting 76 bytes for Tunnel NB9P Feb 13 18:23:55-831647 cadet-tun-27847 DEBUG Creating new ephemeral ratchet key (DHRs) Feb 13 18:23:55-842776 cadet-tun-27847 DEBUG Sending payload of Tunnel NB9P on Connection GE8FF7 (Tunnel NB9P) Feb 13 18:23:55-842832 cadet-con-27847 DEBUG Scheduling message for transmission on Connection GE8FF7 (Tunnel NB9P) Feb 13 18:23:55-842875 cadet-per-27847 DEBUG Queueing message to peer P(NB9P) in MQM 0x6897c0 Feb 13 18:23:55-842915 cadet-per-27847 DEBUG Sending to peer P(NB9P) from MQM 0x6897c0 Feb 13 18:23:55-842961 cadet-tun-27847 DEBUG Connection GE8FF7 (Tunnel NB9P) now ready for Tunnel NB9P in state CADET_TUNNEL_KEY_OK Feb 13 18:23:55-843004 cadet-tun-27847 DEBUG Not sending payload of Tunnel NB9P on ready Connection GE8FF7 (Tunnel NB9P) (nothing pending) Feb 13 18:23:55-843046 cadet-con-27847 DEBUG Core MQ for Connection GE8FF7 (Tunnel NB9P) became available in state 4 Feb 13 18:23:55-843095 cadet-con-27847 DEBUG Scheduling keepalive for Connection GE8FF7 (Tunnel NB9P) in 5 m Feb 13 18:23:55-843144 cadet-chn-27847 DEBUG Sent CADET_CHANNEL_OPEN on Channel NB9P:X4QX93K5 ctn:0(80000000/0), retrying in 500 ms Feb 13 18:23:55-843353 cadet-per-27847 DEBUG Sending to peer P(NB9P) completed Feb 13 18:23:55-887741 cadet-tun-27847 DEBUG Tunnel NB9P received 124 bytes of encrypted data in state 5 Feb 13 18:23:55-888749 cadet-tun-27847 DEBUG Received channel OPEN_ACK on channel Channel NB9P:X4QX93K5 ctn:0(80000000/0) from Tunnel NB9P Feb 13 18:23:55-888776 cadet-chn-27847 DEBUG Received CHANNEL_OPEN_ACK for waiting Channel NB9P:X4QX93K5 ctn:0(80000000/0), entering READY state Feb 13 18:23:55-888798 cadet-chn-27847 DEBUG Sending CADET_LOCAL_ACK to Client(0) (owner) at ccn 80000000 (0/4 pending) Feb 13 18:23:55-888820 cadet-chn-27847 DEBUG Sending CADET_LOCAL_ACK to Client(0) (owner) at ccn 80000000 (0/4 pending) Feb 13 18:23:55-888840 cadet-chn-27847 DEBUG Sending CADET_LOCAL_ACK to Client(0) (owner) at ccn 80000000 (0/4 pending) Feb 13 18:23:55-888859 cadet-chn-27847 DEBUG Sending CADET_LOCAL_ACK to Client(0) (owner) at ccn 80000000 (0/4 pending) Feb 13 18:23:55-889138 cadet-api-27852 DEBUG Requesting Data: 76 bytes (allow send is 2) Feb 13 18:23:55-889396 cadet-27847 DEBUG Received 76 bytes payload from Client(0) for Channel NB9P:X4QX93K5 ctn:0(80000000/0) Feb 13 18:23:55-889429 cadet-chn-27847 DEBUG Sending message 1 from local client to Channel NB9P:X4QX93K5 ctn:0(80000000/0) with 76 bytes Feb 13 18:23:55-889450 cadet-tun-27847 DEBUG Encrypting 88 bytes for Tunnel NB9P Feb 13 18:23:55-892975 cadet-tun-27847 DEBUG Sending payload of Tunnel NB9P on Connection GE8FF7 (Tunnel NB9P) Feb 13 18:23:55-892999 cadet-con-27847 DEBUG Scheduling message for transmission on Connection GE8FF7 (Tunnel NB9P) Feb 13 18:23:55-893023 cadet-per-27847 DEBUG Queueing message to peer P(NB9P) in MQM 0x6897c0 Feb 13 18:23:55-893043 cadet-per-27847 DEBUG Sending to peer P(NB9P) from MQM 0x6897c0 Feb 13 18:23:55-893069 cadet-tun-27847 DEBUG Connection GE8FF7 (Tunnel NB9P) now ready for Tunnel NB9P in state CADET_TUNNEL_KEY_OK Feb 13 18:23:55-893092 cadet-tun-27847 DEBUG Not sending payload of Tunnel NB9P on ready Connection GE8FF7 (Tunnel NB9P) (nothing pending) Feb 13 18:23:55-893112 cadet-con-27847 DEBUG Core MQ for Connection GE8FF7 (Tunnel NB9P) became available in state 4 Feb 13 18:23:55-893135 cadet-con-27847 DEBUG Scheduling keepalive for Connection GE8FF7 (Tunnel NB9P) in 5 m Feb 13 18:23:55-893171 cadet-chn-27847 DEBUG Message 1 sent, next transmission on Channel NB9P:X4QX93K5 ctn:0(80000000/0) in 74 ms Feb 13 18:23:55-893409 cadet-per-27847 DEBUG Sending to peer P(NB9P) completed Feb 13 18:23:55-932739 cadet-tun-27847 DEBUG Tunnel NB9P received 132 bytes of encrypted data in state 5 Feb 13 18:23:55-933826 cadet-chn-27847 DEBUG Got DATA_ACK with base 2 satisfying past message 1 on Channel NB9P:X4QX93K5 ctn:0(80000000/0) Feb 13 18:23:55-934018 cadet-chn-27847 DEBUG Received DATA_ACK on Channel NB9P:X4QX93K5 ctn:0(80000000/0) for message 1 (0 ACKs pending) Feb 13 18:23:55-934182 cadet-chn-27847 DEBUG Sending CADET_LOCAL_ACK to Client(0) (owner) at ccn 80000000 (0/4 pending) Feb 13 18:23:55-940720 cadet-tun-27847 DEBUG Tunnel NB9P received 182 bytes of encrypted data in state 5 Feb 13 18:23:55-941783 cadet-chn-27847 DEBUG Giving 58 bytes of payload with MID 1 from Channel NB9P:X4QX93K5 ctn:0(80000000/0) to client Client(0) Feb 13 18:23:55-941858 cadet-chn-27847 DEBUG Sending DATA_ACK 2:0 via Channel NB9P:X4QX93K5 ctn:0(80000000/0) Feb 13 18:23:55-941921 cadet-tun-27847 DEBUG Encrypting 20 bytes for Tunnel NB9P Feb 13 18:23:55-945470 cadet-api-27852 DEBUG Got a FWD data on channel NB9P [80000000] of type {UNK: 590} (590) Feb 13 18:23:55-945506 cadet-api-27852 DEBUG Sending ACK on channel 80000000 Feb 13 18:23:55-946144 cadet-api-27852 DEBUG CADET NOTIFY TRANSMIT READY on channel 80000000 allow_send is 4 to origin with 68 bytes Feb 13 18:23:55-946202 cadet-api-27852 DEBUG Requesting Data: 68 bytes (allow send is 4) Feb 13 18:23:55-946433 cadet-tun-27847 DEBUG Sending payload of Tunnel NB9P on Connection GE8FF7 (Tunnel NB9P) Feb 13 18:23:55-946485 cadet-con-27847 DEBUG Scheduling message for transmission on Connection GE8FF7 (Tunnel NB9P) Feb 13 18:23:55-946533 cadet-per-27847 DEBUG Queueing message to peer P(NB9P) in MQM 0x6897c0 Feb 13 18:23:55-946579 cadet-per-27847 DEBUG Sending to peer P(NB9P) from MQM 0x6897c0 Feb 13 18:23:55-946626 cadet-tun-27847 DEBUG Connection GE8FF7 (Tunnel NB9P) now ready for Tunnel NB9P in state CADET_TUNNEL_KEY_OK Feb 13 18:23:55-946668 cadet-tun-27847 DEBUG Not sending payload of Tunnel NB9P on ready Connection GE8FF7 (Tunnel NB9P) (nothing pending) Feb 13 18:23:55-946707 cadet-con-27847 DEBUG Core MQ for Connection GE8FF7 (Tunnel NB9P) became available in state 4 Feb 13 18:23:55-946749 cadet-con-27847 DEBUG Scheduling keepalive for Connection GE8FF7 (Tunnel NB9P) in 5 m Feb 13 18:23:55-946816 cadet-27847 DEBUG Got a local ACK from Client(0) for Channel NB9P:X4QX93K5 ctn:0(80000000/0) Feb 13 18:23:55-946861 cadet-chn-27847 DEBUG Got LOCAL_ACK, Client(0)-80000000 ready to receive more data, but none pending on Channel NB9P:X4QX93K5 ctn:0(80000000/0)-80000000(0x687b90)! Feb 13 18:23:55-947019 cadet-per-27847 DEBUG Sending to peer P(NB9P) completed Feb 13 18:23:55-947089 cadet-27847 DEBUG Received 68 bytes payload from Client(0) for Channel NB9P:X4QX93K5 ctn:0(80000000/0) Feb 13 18:23:55-947136 cadet-chn-27847 DEBUG Sending message 2 from local client to Channel NB9P:X4QX93K5 ctn:0(80000000/0) with 68 bytes Feb 13 18:23:55-947176 cadet-tun-27847 DEBUG Encrypting 80 bytes for Tunnel NB9P Feb 13 18:23:55-952117 cadet-tun-27847 DEBUG Sending payload of Tunnel NB9P on Connection GE8FF7 (Tunnel NB9P) Feb 13 18:23:55-952173 cadet-con-27847 DEBUG Scheduling message for transmission on Connection GE8FF7 (Tunnel NB9P) Feb 13 18:23:55-952223 cadet-per-27847 DEBUG Queueing message to peer P(NB9P) in MQM 0x6897c0 Feb 13 18:23:55-952262 cadet-per-27847 DEBUG Sending to peer P(NB9P) from MQM 0x6897c0 Feb 13 18:23:55-952302 cadet-tun-27847 DEBUG Connection GE8FF7 (Tunnel NB9P) now ready for Tunnel NB9P in state CADET_TUNNEL_KEY_OK Feb 13 18:23:55-952343 cadet-tun-27847 DEBUG Not sending payload of Tunnel NB9P on ready Connection GE8FF7 (Tunnel NB9P) (nothing pending) Feb 13 18:23:55-952388 cadet-con-27847 DEBUG Core MQ for Connection GE8FF7 (Tunnel NB9P) became available in state 4 Feb 13 18:23:55-952431 cadet-con-27847 DEBUG Scheduling keepalive for Connection GE8FF7 (Tunnel NB9P) in 5 m Feb 13 18:23:55-952481 cadet-chn-27847 DEBUG Message 2 sent, next transmission on Channel NB9P:X4QX93K5 ctn:0(80000000/0) in 74 ms Feb 13 18:23:55-952656 cadet-per-27847 DEBUG Sending to peer P(NB9P) completed Feb 13 18:23:55-991904 cadet-tun-27847 DEBUG Tunnel NB9P received 132 bytes of encrypted data in state 5 Feb 13 18:23:55-992948 cadet-chn-27847 DEBUG Got DATA_ACK with base 3 satisfying past message 2 on Channel NB9P:X4QX93K5 ctn:0(80000000/0) Feb 13 18:23:55-993002 cadet-chn-27847 DEBUG Received DATA_ACK on Channel NB9P:X4QX93K5 ctn:0(80000000/0) for message 2 (0 ACKs pending) Feb 13 18:23:55-993059 cadet-chn-27847 DEBUG Sending CADET_LOCAL_ACK to Client(0) (owner) at ccn 80000000 (0/4 pending) Feb 13 18:23:55-997301 cadet-tun-27847 DEBUG Tunnel NB9P received 128 bytes of encrypted data in state 5 Feb 13 18:23:55-998305 cadet-chn-27847 DEBUG Giving 4 bytes of payload with MID 2 from Channel NB9P:X4QX93K5 ctn:0(80000000/0) to client Client(0) Feb 13 18:23:55-998362 cadet-chn-27847 DEBUG Sending DATA_ACK 3:0 via Channel NB9P:X4QX93K5 ctn:0(80000000/0) Feb 13 18:23:55-998409 cadet-tun-27847 DEBUG Encrypting 20 bytes for Tunnel NB9P Feb 13 18:23:56-001992 cadet-api-27852 DEBUG Got a FWD data on channel NB9P [80000000] of type {UNK: 586} (586) Feb 13 18:23:56-002022 cadet-api-27852 DEBUG Sending ACK on channel 80000000 Feb 13 18:23:56-002045 cadet-api-27852 DEBUG CADET NOTIFY TRANSMIT READY on channel 80000000 allow_send is 4 to origin with 4 bytes Feb 13 18:23:56-002087 cadet-api-27852 DEBUG Requesting Data: 4 bytes (allow send is 4) Feb 13 18:23:56-002184 cadet-tun-27847 DEBUG Sending payload of Tunnel NB9P on Connection GE8FF7 (Tunnel NB9P) Feb 13 18:23:56-002228 cadet-con-27847 DEBUG Scheduling message for transmission on Connection GE8FF7 (Tunnel NB9P) Feb 13 18:23:56-002271 cadet-per-27847 DEBUG Queueing message to peer P(NB9P) in MQM 0x6897c0 Feb 13 18:23:56-002310 cadet-per-27847 DEBUG Sending to peer P(NB9P) from MQM 0x6897c0 Feb 13 18:23:56-002356 cadet-tun-27847 DEBUG Connection GE8FF7 (Tunnel NB9P) now ready for Tunnel NB9P in state CADET_TUNNEL_KEY_OK Feb 13 18:23:56-002398 cadet-tun-27847 DEBUG Not sending payload of Tunnel NB9P on ready Connection GE8FF7 (Tunnel NB9P) (nothing pending) Feb 13 18:23:56-002438 cadet-con-27847 DEBUG Core MQ for Connection GE8FF7 (Tunnel NB9P) became available in state 4 Feb 13 18:23:56-002480 cadet-con-27847 DEBUG Scheduling keepalive for Connection GE8FF7 (Tunnel NB9P) in 5 m Feb 13 18:23:56-002546 cadet-27847 DEBUG Got a local ACK from Client(0) for Channel NB9P:X4QX93K5 ctn:0(80000000/0) Feb 13 18:23:56-002590 cadet-chn-27847 DEBUG Got LOCAL_ACK, Client(0)-80000000 ready to receive more data, but none pending on Channel NB9P:X4QX93K5 ctn:0(80000000/0)-80000000(0x687b90)! Feb 13 18:23:56-002752 cadet-per-27847 DEBUG Sending to peer P(NB9P) completed Feb 13 18:23:56-002812 cadet-27847 DEBUG Received 4 bytes payload from Client(0) for Channel NB9P:X4QX93K5 ctn:0(80000000/0) Feb 13 18:23:56-002865 cadet-chn-27847 DEBUG Sending message 3 from local client to Channel NB9P:X4QX93K5 ctn:0(80000000/0) with 4 bytes Feb 13 18:23:56-002906 cadet-tun-27847 DEBUG Encrypting 16 bytes for Tunnel NB9P Feb 13 18:23:56-006470 cadet-tun-27847 DEBUG Sending payload of Tunnel NB9P on Connection GE8FF7 (Tunnel NB9P) Feb 13 18:23:56-006521 cadet-con-27847 DEBUG Scheduling message for transmission on Connection GE8FF7 (Tunnel NB9P) Feb 13 18:23:56-006562 cadet-per-27847 DEBUG Queueing message to peer P(NB9P) in MQM 0x6897c0 Feb 13 18:23:56-006601 cadet-per-27847 DEBUG Sending to peer P(NB9P) from MQM 0x6897c0 Feb 13 18:23:56-006642 cadet-tun-27847 DEBUG Connection GE8FF7 (Tunnel NB9P) now ready for Tunnel NB9P in state CADET_TUNNEL_KEY_OK Feb 13 18:23:56-006683 cadet-tun-27847 DEBUG Not sending payload of Tunnel NB9P on ready Connection GE8FF7 (Tunnel NB9P) (nothing pending) Feb 13 18:23:56-006722 cadet-con-27847 DEBUG Core MQ for Connection GE8FF7 (Tunnel NB9P) became available in state 4 Feb 13 18:23:56-006763 cadet-con-27847 DEBUG Scheduling keepalive for Connection GE8FF7 (Tunnel NB9P) in 5 m Feb 13 18:23:56-006816 cadet-chn-27847 DEBUG Message 3 sent, next transmission on Channel NB9P:X4QX93K5 ctn:0(80000000/0) in 74 ms Feb 13 18:23:56-009139 cadet-per-27847 DEBUG Sending to peer P(NB9P) completed Feb 13 18:23:56-050934 cadet-tun-27847 DEBUG Tunnel NB9P received 132 bytes of encrypted data in state 5 Feb 13 18:23:56-052927 cadet-chn-27847 DEBUG Got DATA_ACK with base 4 satisfying past message 3 on Channel NB9P:X4QX93K5 ctn:0(80000000/0) Feb 13 18:23:56-053228 cadet-chn-27847 DEBUG Received DATA_ACK on Channel NB9P:X4QX93K5 ctn:0(80000000/0) for message 3 (0 ACKs pending) Feb 13 18:23:56-053557 cadet-chn-27847 DEBUG Sending CADET_LOCAL_ACK to Client(0) (owner) at ccn 80000000 (0/4 pending) Feb 13 18:24:07-121138 cadet-27847 DEBUG Client(2) connected Feb 13 18:24:07-121293 cadet-27847 DEBUG Open port PR96BHN5 requested by Client(2) Feb 13 18:24:19-646592 cadet-tun-27847 DEBUG Tunnel NB9P received 188 bytes of encrypted data in state 5 Feb 13 18:24:19-647575 cadet-tun-27847 DEBUG Receicved duplicate channel OPEN on port PR96BHN5 from Tunnel NB9P (Channel NB9P:X4QX93K5 ctn:0(80000000/0)), resending ACK Feb 13 18:24:19-647601 cadet-chn-27847 DEBUG Ignoring duplicate channel OPEN on Channel NB9P:X4QX93K5 ctn:0(80000000/0): port is closed Feb 13 18:24:20-157381 cadet-tun-27847 DEBUG Tunnel NB9P received 188 bytes of encrypted data in state 5 Feb 13 18:24:20-159099 cadet-tun-27847 DEBUG Receicved duplicate channel OPEN on port PR96BHN5 from Tunnel NB9P (Channel NB9P:X4QX93K5 ctn:0(80000000/0)), resending ACK Feb 13 18:24:20-159142 cadet-chn-27847 DEBUG Ignoring duplicate channel OPEN on Channel NB9P:X4QX93K5 ctn:0(80000000/0): port is closed Feb 13 18:24:21-167548 cadet-tun-27847 DEBUG Tunnel NB9P received 188 bytes of encrypted data in state 5 Feb 13 18:24:21-169031 cadet-tun-27847 DEBUG Receicved duplicate channel OPEN on port PR96BHN5 from Tunnel NB9P (Channel NB9P:X4QX93K5 ctn:0(80000000/0)), resending ACK Feb 13 18:24:21-169239 cadet-chn-27847 DEBUG Ignoring duplicate channel OPEN on Channel NB9P:X4QX93K5 ctn:0(80000000/0): port is closed Feb 13 18:24:23-178220 cadet-tun-27847 DEBUG Tunnel NB9P received 188 bytes of encrypted data in state 5 Feb 13 18:24:23-180135 cadet-tun-27847 DEBUG Receicved duplicate channel OPEN on port PR96BHN5 from Tunnel NB9P (Channel NB9P:X4QX93K5 ctn:0(80000000/0)), resending ACK Feb 13 18:24:23-180189 cadet-chn-27847 DEBUG Ignoring duplicate channel OPEN on Channel NB9P:X4QX93K5 ctn:0(80000000/0): port is closed Feb 13 18:24:27-188063 cadet-tun-27847 DEBUG Tunnel NB9P received 188 bytes of encrypted data in state 5 Feb 13 18:24:27-189682 cadet-tun-27847 DEBUG Receicved duplicate channel OPEN on port PR96BHN5 from Tunnel NB9P (Channel NB9P:X4QX93K5 ctn:0(80000000/0)), resending ACK Feb 13 18:24:27-189723 cadet-chn-27847 DEBUG Ignoring duplicate channel OPEN on Channel NB9P:X4QX93K5 ctn:0(80000000/0): port is closed Feb 13 18:24:35-201155 cadet-tun-27847 DEBUG Tunnel NB9P received 188 bytes of encrypted data in state 5 Feb 13 18:24:35-202269 cadet-tun-27847 DEBUG Receicved duplicate channel OPEN on port PR96BHN5 from Tunnel NB9P (Channel NB9P:X4QX93K5 ctn:0(80000000/0)), resending ACK Feb 13 18:24:35-202297 cadet-chn-27847 DEBUG Ignoring duplicate channel OPEN on Channel NB9P:X4QX93K5 ctn:0(80000000/0): port is closed