Feb 17 01:31:38-932154 cadet-22350 INFO CADET started for peer 8DBE Feb 17 01:31:38-963649 cadet-api-22354 DEBUG GNUNET_CADET_connect() 0xe17e90 Feb 17 01:31:38-967485 cadet-api-22354 DEBUG Connecting to CADET Feb 17 01:31:38-969547 cadet-22350 DEBUG Client(0) connected Feb 17 01:31:38-969470 cadet-api-22359 DEBUG GNUNET_CADET_connecT() Feb 17 01:31:38-969648 cadet-api-22359 DEBUG Connecting to CADET Feb 17 01:31:38-969955 cadet-22350 DEBUG Client(1) connected Feb 17 01:31:38-975981 cadet-22350 DEBUG Open port X4QX93K5 requested by Client(1) Feb 17 01:31:38-997190 cadet-hll-22350 DEBUG Hello for KW6D (472 bytes), expires on Fri Feb 17 13:30:01 2017 Feb 17 01:31:38-997243 cadet-per-22350 DEBUG Creating peer P(KW6D) Feb 17 01:31:38-997264 cadet-per-22350 DEBUG Got 472 byte HELLO for peer P(KW6D) Feb 17 01:31:38-997981 cadet-hll-22350 DEBUG Hello for SH2B (160 bytes), expires on Fri Feb 17 13:28:53 2017 Feb 17 01:31:38-998008 cadet-per-22350 DEBUG Creating peer P(SH2B) Feb 17 01:31:38-998027 cadet-per-22350 DEBUG Got 160 byte HELLO for peer P(SH2B) Feb 17 01:31:39-032712 cadet-cor-22350 DEBUG CORE connection to peer 8DBE was established. Feb 17 01:31:39-032774 cadet-per-22350 DEBUG Creating peer P(8DBE) Feb 17 01:31:39-032797 cadet-per-22350 DEBUG Message queue for peer P(8DBE) is now 0x1bbf6d0 Feb 17 01:31:39-032824 cadet-per-22350 DEBUG Updating peer P(8DBE) activation state (0 connections) with CORE link Feb 17 01:31:39-042076 nat-22373 ERROR UPnP enabled in configuration, but UPnP client `upnpc` command not found, disabling UPnP Feb 17 01:31:39-091890 cadet-hll-22350 DEBUG Hello for KW6D (472 bytes), expires on Fri Feb 17 13:31:39 2017 Feb 17 01:31:39-091948 cadet-per-22350 DEBUG Got 472 byte HELLO for peer P(KW6D) Feb 17 01:31:39-092781 cadet-hll-22350 DEBUG Hello for KW6D (472 bytes), expires on Fri Feb 17 13:31:39 2017 Feb 17 01:31:39-092808 cadet-per-22350 DEBUG Got 472 byte HELLO for peer P(KW6D) Feb 17 01:31:39-132445 cadet-hll-22350 DEBUG Hello for KW6D (472 bytes), expires on Fri Feb 17 13:31:39 2017 Feb 17 01:31:39-132491 cadet-per-22350 DEBUG Got 472 byte HELLO for peer P(KW6D) Feb 17 01:31:39-133272 cadet-hll-22350 DEBUG Hello for KW6D (472 bytes), expires on Fri Feb 17 13:31:39 2017 Feb 17 01:31:39-133299 cadet-per-22350 DEBUG Got 472 byte HELLO for peer P(KW6D) Feb 17 01:31:39-155919 cadet-dht-22350 DEBUG Announcing my HELLO (472 bytes) in the DHT Feb 17 01:31:42-073152 cadet-22350 DEBUG Client(2) connected Feb 17 01:31:42-073470 cadet-22350 DEBUG New channel to KW6D at port PR96BHN5 requested by Client(2) Feb 17 01:31:42-073504 cadet-tun-22350 DEBUG Creating new ephemeral ratchet key (DHRs) Feb 17 01:31:42-081453 cadet-per-22350 DEBUG Updating peer P(KW6D) activation state (0 connections) with tunnel Feb 17 01:31:42-081528 cadet-dht-22350 DEBUG Starting DHT GET for peer KW6D (0x1bc0970) Feb 17 01:31:42-081601 cadet-tun-22350 DEBUG Adding Channel KW6D:PR96BHN5 ctn:0(80000000/0) to Tunnel KW6D Feb 17 01:31:42-081650 cadet-chn-22350 DEBUG Created channel to port PR96BHN5 at peer P(KW6D) for Client(2) using Tunnel KW6D Feb 17 01:31:42-083351 cadet-tun-22350 DEBUG Performing connection maintenance for Tunnel KW6D. Feb 17 01:31:42-083406 cadet-per-22350 DEBUG Iterating over paths to peer P(KW6D) Feb 17 01:31:55-241495 cadet-cor-22350 DEBUG CORE connection to peer KW6D was established. Feb 17 01:31:55-241597 cadet-per-22350 DEBUG Message queue for peer P(KW6D) is now 0x1bc1950 Feb 17 01:31:55-241633 cadet-per-22350 DEBUG Updating peer P(KW6D) activation state (0 connections) with tunnel with CORE link Feb 17 01:31:55-241670 cadet-dht-22350 DEBUG Stopping DHT GET 0x1bc0970 Feb 17 01:31:55-241733 cadet-per-22350 DEBUG Asked to look for paths at distance 0, but maximum for me is < 0 Feb 17 01:31:55-241775 cadet-per-22350 DEBUG Discovered that peer P(KW6D) is on path KW6D(0x1ba8960) at offset 0 Feb 17 01:31:55-241841 cadet-con-22350 DEBUG Creating Connection 8JZGJZ (Tunnel KW6D) using path KW6D(0x1ba8960) Feb 17 01:31:55-241882 cadet-pat-22350 DEBUG Adding connection Connection 8JZGJZ (Tunnel KW6D) to path KW6D(0x1ba8960) at offset 0 Feb 17 01:31:55-241918 cadet-per-22350 DEBUG Creating MQM 0x1bc11e0 for peer P(KW6D) Feb 17 01:31:55-241956 cadet-con-22350 DEBUG Core MQ for Connection 8JZGJZ (Tunnel KW6D) became available in state 0 Feb 17 01:31:55-242002 cadet-tun-22350 DEBUG Found interesting path KW6D(0x1ba8960) for Tunnel KW6D, created Connection 8JZGJZ (Tunnel KW6D) Feb 17 01:31:55-242038 cadet-pat-22350 DEBUG Created new path KW6D(0x1ba8960) to create inverse for incoming connection Feb 17 01:31:55-242075 cadet-per-22350 DEBUG Attaching path KW6D(0x1ba8960) to peer P(KW6D) (forced) Feb 17 01:31:55-242113 cadet-tun-22350 DEBUG Ignoring duplicate path KW6D(0x1ba8960). Feb 17 01:31:55-242217 cadet-con-22350 DEBUG Sending CADET_CONNECTION_CREATE message for Connection 8JZGJZ (Tunnel KW6D) Feb 17 01:31:55-242254 cadet-per-22350 DEBUG Queueing message to peer P(KW6D) in MQM 0x1bc11e0 Feb 17 01:31:55-242292 cadet-per-22350 DEBUG Sending to peer P(KW6D) from MQM 0x1bc11e0 Feb 17 01:31:55-242339 cadet-con-22350 DEBUG Core MQ for Connection 8JZGJZ (Tunnel KW6D) became available in state 2 Feb 17 01:31:55-244540 cadet-con-22350 DEBUG Sending CADET_CONNECTION_CREATE message for Connection 8JZGJZ (Tunnel KW6D) Feb 17 01:31:55-244600 cadet-per-22350 DEBUG Queueing message to peer P(KW6D) in MQM 0x1bc11e0 Feb 17 01:31:56-244712 cadet-api-22359 DEBUG CADET NOTIFY TRANSMIT READY on channel 80000000 allow_send is 0 to origin with 76 bytes Feb 17 01:31:56-245681 cadet-22350 DEBUG New channel to KW6D at port X4QX93K5 requested by Client(1) Feb 17 01:31:56-245755 cadet-tun-22350 DEBUG Adding Channel KW6D:X4QX93K5 ctn:0(80000000/0) to Tunnel KW6D Feb 17 01:31:56-245810 cadet-chn-22350 DEBUG Created channel to port X4QX93K5 at peer P(KW6D) for Client(1) using Tunnel KW6D Feb 17 01:31:58-574103 core-22355 WARNING Client waited 3330 ms for permission to transmit to `KW6D' (priority 1) Feb 17 01:31:58-575505 core-22355 WARNING Client waited 3332 ms for permission to transmit to `KW6D' (priority 1) Feb 17 01:31:58-575622 core-22355 WARNING Client waited 3332 ms for permission to transmit to `KW6D' (priority 1) Feb 17 01:31:58-576052 cadet-per-22350 DEBUG Sending to peer P(KW6D) completed Feb 17 01:31:58-576099 cadet-per-22350 DEBUG Sending to peer P(KW6D) from MQM 0x1bc11e0 Feb 17 01:31:58-576124 cadet-con-22350 DEBUG Core MQ for Connection 8JZGJZ (Tunnel KW6D) became available in state 2 Feb 17 01:31:58-576281 core-22355 WARNING Client waited 3332 ms for transmission of 104 bytes to `KW6D' (uncorked) Feb 17 01:31:58-577044 core-22355 WARNING Client waited 3333 ms for transmission of 348 bytes to `KW6D' (uncorked) Feb 17 01:31:58-577158 core-22355 WARNING Client waited 3333 ms for transmission of 160 bytes to `KW6D' (cork) Feb 17 01:31:58-578173 cadet-per-22350 DEBUG Sending to peer P(KW6D) completed Feb 17 01:31:58-580354 cadet-con-22350 DEBUG Sending CADET_CONNECTION_CREATE message for Connection 8JZGJZ (Tunnel KW6D) Feb 17 01:31:58-580424 cadet-per-22350 DEBUG Queueing message to peer P(KW6D) in MQM 0x1bc11e0 Feb 17 01:31:58-580466 cadet-per-22350 DEBUG Sending to peer P(KW6D) from MQM 0x1bc11e0 Feb 17 01:31:58-580512 cadet-con-22350 DEBUG Core MQ for Connection 8JZGJZ (Tunnel KW6D) became available in state 2 Feb 17 01:31:58-581355 cadet-per-22350 DEBUG Sending to peer P(KW6D) completed Feb 17 01:31:58-588688 cadet-con-22350 DEBUG Sending CADET_CONNECTION_CREATE message for Connection 8JZGJZ (Tunnel KW6D) Feb 17 01:31:58-588730 cadet-per-22350 DEBUG Queueing message to peer P(KW6D) in MQM 0x1bc11e0 Feb 17 01:31:58-588752 cadet-per-22350 DEBUG Sending to peer P(KW6D) from MQM 0x1bc11e0 Feb 17 01:31:58-588780 cadet-con-22350 DEBUG Core MQ for Connection 8JZGJZ (Tunnel KW6D) became available in state 2 Feb 17 01:31:58-589036 cadet-per-22350 DEBUG Sending to peer P(KW6D) completed Feb 17 01:31:58-604933 cadet-con-22350 DEBUG Sending CADET_CONNECTION_CREATE message for Connection 8JZGJZ (Tunnel KW6D) Feb 17 01:31:58-604975 cadet-per-22350 DEBUG Queueing message to peer P(KW6D) in MQM 0x1bc11e0 Feb 17 01:31:58-604997 cadet-per-22350 DEBUG Sending to peer P(KW6D) from MQM 0x1bc11e0 Feb 17 01:31:58-605022 cadet-con-22350 DEBUG Core MQ for Connection 8JZGJZ (Tunnel KW6D) became available in state 2 Feb 17 01:31:58-605260 cadet-per-22350 DEBUG Sending to peer P(KW6D) completed Feb 17 01:31:58-637237 cadet-con-22350 DEBUG Sending CADET_CONNECTION_CREATE message for Connection 8JZGJZ (Tunnel KW6D) Feb 17 01:31:58-637309 cadet-per-22350 DEBUG Queueing message to peer P(KW6D) in MQM 0x1bc11e0 Feb 17 01:31:58-637348 cadet-per-22350 DEBUG Sending to peer P(KW6D) from MQM 0x1bc11e0 Feb 17 01:31:58-637393 cadet-con-22350 DEBUG Core MQ for Connection 8JZGJZ (Tunnel KW6D) became available in state 2 Feb 17 01:31:58-637858 cadet-per-22350 DEBUG Sending to peer P(KW6D) completed Feb 17 01:31:58-701609 cadet-con-22350 DEBUG Sending CADET_CONNECTION_CREATE message for Connection 8JZGJZ (Tunnel KW6D) Feb 17 01:31:58-701676 cadet-per-22350 DEBUG Queueing message to peer P(KW6D) in MQM 0x1bc11e0 Feb 17 01:31:58-701699 cadet-per-22350 DEBUG Sending to peer P(KW6D) from MQM 0x1bc11e0 Feb 17 01:31:58-701727 cadet-con-22350 DEBUG Core MQ for Connection 8JZGJZ (Tunnel KW6D) became available in state 2 Feb 17 01:31:58-701943 cadet-per-22350 DEBUG Sending to peer P(KW6D) completed Feb 17 01:31:58-830032 cadet-con-22350 DEBUG Sending CADET_CONNECTION_CREATE message for Connection 8JZGJZ (Tunnel KW6D) Feb 17 01:31:58-830112 cadet-per-22350 DEBUG Queueing message to peer P(KW6D) in MQM 0x1bc11e0 Feb 17 01:31:58-830136 cadet-per-22350 DEBUG Sending to peer P(KW6D) from MQM 0x1bc11e0 Feb 17 01:31:58-830166 cadet-con-22350 DEBUG Core MQ for Connection 8JZGJZ (Tunnel KW6D) became available in state 2 Feb 17 01:31:58-830443 cadet-per-22350 DEBUG Sending to peer P(KW6D) completed Feb 17 01:31:59-086606 cadet-con-22350 DEBUG Sending CADET_CONNECTION_CREATE message for Connection 8JZGJZ (Tunnel KW6D) Feb 17 01:31:59-086705 cadet-per-22350 DEBUG Queueing message to peer P(KW6D) in MQM 0x1bc11e0 Feb 17 01:31:59-086743 cadet-per-22350 DEBUG Sending to peer P(KW6D) from MQM 0x1bc11e0 Feb 17 01:31:59-086789 cadet-con-22350 DEBUG Core MQ for Connection 8JZGJZ (Tunnel KW6D) became available in state 2 Feb 17 01:31:59-087383 cadet-per-22350 DEBUG Sending to peer P(KW6D) completed Feb 17 01:31:59-599453 cadet-con-22350 DEBUG Sending CADET_CONNECTION_CREATE message for Connection 8JZGJZ (Tunnel KW6D) Feb 17 01:31:59-599529 cadet-per-22350 DEBUG Queueing message to peer P(KW6D) in MQM 0x1bc11e0 Feb 17 01:31:59-599552 cadet-per-22350 DEBUG Sending to peer P(KW6D) from MQM 0x1bc11e0 Feb 17 01:31:59-599583 cadet-con-22350 DEBUG Core MQ for Connection 8JZGJZ (Tunnel KW6D) became available in state 2 Feb 17 01:31:59-600025 cadet-per-22350 DEBUG Sending to peer P(KW6D) completed Feb 17 01:31:59-711476 core-22355 ERROR Received EPHEMERAL_KEY from KW6D, but expected SH2BQDQR1QFWAPQ3B03QQC8PDAZ1FV3WAN6E0GDVR60JV5RQF3X0 Feb 17 01:31:59-711527 core-22355 WARNING External protocol violation detected at gnunet-service-core_kx.c:905. Feb 17 01:32:00-624804 cadet-con-22350 DEBUG Sending CADET_CONNECTION_CREATE message for Connection 8JZGJZ (Tunnel KW6D) Feb 17 01:32:00-624908 cadet-per-22350 DEBUG Queueing message to peer P(KW6D) in MQM 0x1bc11e0 Feb 17 01:32:00-624944 cadet-per-22350 DEBUG Sending to peer P(KW6D) from MQM 0x1bc11e0 Feb 17 01:32:00-624993 cadet-con-22350 DEBUG Core MQ for Connection 8JZGJZ (Tunnel KW6D) became available in state 2 Feb 17 01:32:00-625344 cadet-per-22350 DEBUG Sending to peer P(KW6D) completed Feb 17 01:32:02-675178 cadet-con-22350 DEBUG Sending CADET_CONNECTION_CREATE message for Connection 8JZGJZ (Tunnel KW6D) Feb 17 01:32:02-675293 cadet-per-22350 DEBUG Queueing message to peer P(KW6D) in MQM 0x1bc11e0 Feb 17 01:32:02-675318 cadet-per-22350 DEBUG Sending to peer P(KW6D) from MQM 0x1bc11e0 Feb 17 01:32:02-675351 cadet-con-22350 DEBUG Core MQ for Connection 8JZGJZ (Tunnel KW6D) became available in state 2 Feb 17 01:32:02-675746 cadet-per-22350 DEBUG Sending to peer P(KW6D) completed Feb 17 01:32:06-775581 cadet-con-22350 DEBUG Sending CADET_CONNECTION_CREATE message for Connection 8JZGJZ (Tunnel KW6D) Feb 17 01:32:06-775656 cadet-per-22350 DEBUG Queueing message to peer P(KW6D) in MQM 0x1bc11e0 Feb 17 01:32:06-775680 cadet-per-22350 DEBUG Sending to peer P(KW6D) from MQM 0x1bc11e0 Feb 17 01:32:06-775712 cadet-con-22350 DEBUG Core MQ for Connection 8JZGJZ (Tunnel KW6D) became available in state 2 Feb 17 01:32:06-776096 cadet-per-22350 DEBUG Sending to peer P(KW6D) completed Feb 17 01:32:09-716558 core-22355 ERROR Received EPHEMERAL_KEY from KW6D, but expected SH2BQDQR1QFWAPQ3B03QQC8PDAZ1FV3WAN6E0GDVR60JV5RQF3X0 Feb 17 01:32:09-716657 core-22355 WARNING External protocol violation detected at gnunet-service-core_kx.c:905. Feb 17 01:32:14-975413 cadet-con-22350 DEBUG Sending CADET_CONNECTION_CREATE message for Connection 8JZGJZ (Tunnel KW6D) Feb 17 01:32:14-975483 cadet-per-22350 DEBUG Queueing message to peer P(KW6D) in MQM 0x1bc11e0 Feb 17 01:32:14-975510 cadet-per-22350 DEBUG Sending to peer P(KW6D) from MQM 0x1bc11e0 Feb 17 01:32:14-975538 cadet-con-22350 DEBUG Core MQ for Connection 8JZGJZ (Tunnel KW6D) became available in state 2 Feb 17 01:32:14-975937 cadet-per-22350 DEBUG Sending to peer P(KW6D) completed Feb 17 01:32:19-717813 core-22355 ERROR Received EPHEMERAL_KEY from KW6D, but expected SH2BQDQR1QFWAPQ3B03QQC8PDAZ1FV3WAN6E0GDVR60JV5RQF3X0 Feb 17 01:32:19-717913 core-22355 WARNING External protocol violation detected at gnunet-service-core_kx.c:905. Feb 17 01:32:31-360175 cadet-con-22350 DEBUG Sending CADET_CONNECTION_CREATE message for Connection 8JZGJZ (Tunnel KW6D) Feb 17 01:32:31-360252 cadet-per-22350 DEBUG Queueing message to peer P(KW6D) in MQM 0x1bc11e0 Feb 17 01:32:31-360275 cadet-per-22350 DEBUG Sending to peer P(KW6D) from MQM 0x1bc11e0 Feb 17 01:32:31-360303 cadet-con-22350 DEBUG Core MQ for Connection 8JZGJZ (Tunnel KW6D) became available in state 2 Feb 17 01:32:31-360664 cadet-per-22350 DEBUG Sending to peer P(KW6D) completed