Feb 20 16:32:57-124842 cadet-9478 INFO CADET started for peer W4JC Feb 20 16:32:57-173863 cadet-api-9483 DEBUG GNUNET_CADET_connecT() Feb 20 16:32:57-190398 cadet-9478 DEBUG Client(0) connected Feb 20 16:32:57-192259 cadet-9478 DEBUG Open port X4QX93K5 requested by Client(0) Feb 20 16:32:57-209494 cadet-api-9486 DEBUG GNUNET_CADET_connect() 0x7b8bb0 Feb 20 16:32:57-218094 cadet-api-9486 DEBUG Connecting to CADET Feb 20 16:32:57-220120 cadet-9478 DEBUG Client(1) connected Feb 20 16:32:57-222999 cadet-hll-9478 DEBUG Hello for W2KF (472 bytes), expires on Tue Feb 21 04:29:33 2017 Feb 20 16:32:57-223084 cadet-per-9478 DEBUG Creating peer P(W2KF) Feb 20 16:32:57-223120 cadet-per-9478 DEBUG Got 472 byte HELLO for peer P(W2KF) Feb 20 16:32:57-275305 cadet-cor-9478 DEBUG CORE connection to peer W4JC was established. Feb 20 16:32:57-275396 cadet-per-9478 DEBUG Creating peer P(W4JC) Feb 20 16:32:57-275433 cadet-per-9478 DEBUG Message queue for peer P(W4JC) is now 0xd95ad0 Feb 20 16:32:57-275469 cadet-per-9478 DEBUG Updating peer P(W4JC) activation state (0 connections) with CORE link Feb 20 16:32:57-286852 nat-9497 ERROR UPnP enabled in configuration, but UPnP client `upnpc` command not found, disabling UPnP Feb 20 16:32:57-312587 cadet-hll-9478 DEBUG Hello for W2KF (472 bytes), expires on Tue Feb 21 04:32:57 2017 Feb 20 16:32:57-312654 cadet-per-9478 DEBUG Got 472 byte HELLO for peer P(W2KF) Feb 20 16:32:57-321648 cadet-dht-9478 DEBUG Announcing my HELLO (472 bytes) in the DHT Feb 20 16:32:57-348233 cadet-hll-9478 DEBUG Hello for W2KF (472 bytes), expires on Tue Feb 21 04:32:57 2017 Feb 20 16:32:57-348280 cadet-per-9478 DEBUG Got 472 byte HELLO for peer P(W2KF) Feb 20 16:32:57-349963 cadet-hll-9478 DEBUG Hello for W2KF (472 bytes), expires on Tue Feb 21 04:32:57 2017 Feb 20 16:32:57-350009 cadet-per-9478 DEBUG Got 472 byte HELLO for peer P(W2KF) Feb 20 16:32:57-454219 cadet-dht-9478 DEBUG Announcing my HELLO (472 bytes) in the DHT Feb 20 16:32:58-388479 cadet-cor-9478 DEBUG CORE connection to peer W2KF was established. Feb 20 16:32:58-388575 cadet-per-9478 DEBUG Message queue for peer P(W2KF) is now 0xd95d90 Feb 20 16:32:58-388611 cadet-per-9478 DEBUG Updating peer P(W2KF) activation state (0 connections) with CORE link Feb 20 16:32:58-713317 cadet-9478 DEBUG Client(2) connected Feb 20 16:32:58-713872 cadet-9478 DEBUG Open port PR96BHN5 requested by Client(2) Feb 20 16:32:59-352268 cadet-cor-9478 DEBUG Failed to route message of type 1008 from P(W2KF) on connection D0HEMY: no route Feb 20 16:32:59-352364 cadet-per-9478 DEBUG Sending message to P(W2KF) out of management Feb 20 16:32:59-858123 cadet-cor-9478 DEBUG Failed to route message of type 1008 from P(W2KF) on connection D0HEMY: no route Feb 20 16:32:59-858194 cadet-per-9478 DEBUG Sending message to P(W2KF) out of management Feb 20 16:33:00-866712 cadet-cor-9478 DEBUG Failed to route message of type 1008 from P(W2KF) on connection D0HEMY: no route Feb 20 16:33:00-866816 cadet-per-9478 DEBUG Sending message to P(W2KF) out of management Feb 20 16:33:02-092939 core-9482 WARNING Client waited 3703 ms for permission to transmit to `W2KF' (priority 1) Feb 20 16:33:02-093536 cadet-per-9478 DEBUG Sending to peer P(W2KF) completed Feb 20 16:33:02-093830 core-9482 WARNING Client waited 3703 ms for transmission of 348 bytes to `W2KF' (uncorked) Feb 20 16:33:02-097331 cadet-per-9478 DEBUG Sending to peer P(W2KF) completed Feb 20 16:33:02-099235 cadet-per-9478 DEBUG Sending to peer P(W2KF) completed Feb 20 16:33:02-879089 cadet-cor-9478 DEBUG Failed to route message of type 1008 from P(W2KF) on connection D0HEMY: no route Feb 20 16:33:02-879156 cadet-per-9478 DEBUG Sending message to P(W2KF) out of management Feb 20 16:33:02-879435 cadet-per-9478 DEBUG Sending to peer P(W2KF) completed Feb 20 16:33:06-879678 cadet-cor-9478 DEBUG Failed to route message of type 1008 from P(W2KF) on connection D0HEMY: no route Feb 20 16:33:06-879755 cadet-per-9478 DEBUG Sending message to P(W2KF) out of management Feb 20 16:33:06-880025 cadet-per-9478 DEBUG Sending to peer P(W2KF) completed Feb 20 16:33:14-888953 cadet-cor-9478 DEBUG Failed to route message of type 1008 from P(W2KF) on connection D0HEMY: no route Feb 20 16:33:14-889046 cadet-per-9478 DEBUG Sending message to P(W2KF) out of management Feb 20 16:33:14-889321 cadet-per-9478 DEBUG Sending to peer P(W2KF) completed Feb 20 16:33:47-884452 cadet-cor-9478 DEBUG Received CADET_CONNECTION_CREATE message from P(W2KF) for connection Z6RT7C, building inverse path Feb 20 16:33:47-884528 cadet-per-9478 DEBUG Asked to look for paths at distance 0, but maximum for me is < 0 Feb 20 16:33:47-884553 cadet-per-9478 DEBUG Discovered that peer P(W2KF) is on path W2KF(0xd7f690) at offset 0 Feb 20 16:33:47-884580 cadet-pat-9478 DEBUG Created new path W2KF(0xd7f690) to create inverse for incoming connection Feb 20 16:33:47-884602 cadet-per-9478 DEBUG Attaching path W2KF(0xd7f690) to peer P(W2KF) (forced) Feb 20 16:33:47-884625 cadet-tun-9478 DEBUG Creating new ephemeral ratchet key (DHRs) Feb 20 16:33:47-893587 cadet-per-9478 DEBUG Updating peer P(W2KF) activation state (0 connections) with tunnel with CORE link Feb 20 16:33:47-893665 cadet-con-9478 DEBUG Creating Connection Z6RT7C (Tunnel W2KF) using path W2KF(0xd7f690) Feb 20 16:33:47-893710 cadet-pat-9478 DEBUG Adding connection Connection Z6RT7C (Tunnel W2KF) to path W2KF(0xd7f690) at offset 0 Feb 20 16:33:47-893751 cadet-per-9478 DEBUG Creating MQM 0xd97e40 for peer P(W2KF) Feb 20 16:33:47-893794 cadet-con-9478 DEBUG Core MQ for Connection Z6RT7C (Tunnel W2KF) became available in state 3 Feb 20 16:33:47-893837 cadet-tun-9478 DEBUG Tunnel W2KF has new Connection Z6RT7C (Tunnel W2KF) Feb 20 16:33:47-894029 cadet-cor-9478 DEBUG Received duplicate CADET_CONNECTION_CREATE message on connection Z6RT7C Feb 20 16:33:47-894079 cadet-con-9478 DEBUG Got duplicate CREATE for Connection Z6RT7C (Tunnel W2KF), scheduling another ACK (MQM ready) Feb 20 16:33:47-894123 cadet-tun-9478 DEBUG Performing connection maintenance for Tunnel W2KF. Feb 20 16:33:47-894177 cadet-per-9478 DEBUG Iterating over paths to peer P(W2KF) including direct link Feb 20 16:33:47-894218 cadet-pat-9478 DEBUG check_match found match with path W2KF(0xd7f690) Feb 20 16:33:47-894258 cadet-pat-9478 DEBUG Returning existing path W2KF(0xd7f690) as inverse for incoming connection Feb 20 16:33:47-894297 cadet-tun-9478 DEBUG Ignoring duplicate path W2KF(0xd7f690). Feb 20 16:33:47-894345 cadet-tun-9478 DEBUG Ignoring duplicate path W2KF(0xd7f690). Feb 20 16:33:47-894399 cadet-con-9478 DEBUG Sending CONNECTION_CREATE_ACK message for Connection Z6RT7C (Tunnel W2KF) Feb 20 16:33:47-894445 cadet-per-9478 DEBUG Queueing message to peer P(W2KF) in MQM 0xd97e40 Feb 20 16:33:47-894485 cadet-per-9478 DEBUG Sending to peer P(W2KF) from MQM 0xd97e40 Feb 20 16:33:47-894542 cadet-tun-9478 DEBUG Connection Z6RT7C (Tunnel W2KF) now ready for Tunnel W2KF in state CADET_TUNNEL_KEY_UNINITIALIZED Feb 20 16:33:47-894587 cadet-con-9478 DEBUG Core MQ for Connection Z6RT7C (Tunnel W2KF) became available in state 4 Feb 20 16:33:47-894631 cadet-con-9478 DEBUG Scheduling keepalive for Connection Z6RT7C (Tunnel W2KF) in 5 m Feb 20 16:33:47-894797 cadet-per-9478 DEBUG Sending to peer P(W2KF) completed Feb 20 16:33:47-898926 cadet-cor-9478 DEBUG Received duplicate CADET_CONNECTION_CREATE message on connection Z6RT7C Feb 20 16:33:47-898990 cadet-con-9478 DEBUG Got duplicate CREATE for Connection Z6RT7C (Tunnel W2KF), scheduling another ACK (MQM ready) Feb 20 16:33:47-899034 cadet-tun-9478 DEBUG Connection Z6RT7C (Tunnel W2KF) no longer ready for Tunnel W2KF Feb 20 16:33:47-899092 cadet-con-9478 DEBUG Sending CONNECTION_CREATE_ACK message for Connection Z6RT7C (Tunnel W2KF) Feb 20 16:33:47-899139 cadet-per-9478 DEBUG Queueing message to peer P(W2KF) in MQM 0xd97e40 Feb 20 16:33:47-899178 cadet-per-9478 DEBUG Sending to peer P(W2KF) from MQM 0xd97e40 Feb 20 16:33:47-899232 cadet-tun-9478 DEBUG Connection Z6RT7C (Tunnel W2KF) now ready for Tunnel W2KF in state CADET_TUNNEL_KEY_UNINITIALIZED Feb 20 16:33:47-899273 cadet-con-9478 DEBUG Core MQ for Connection Z6RT7C (Tunnel W2KF) became available in state 4 Feb 20 16:33:47-899317 cadet-con-9478 DEBUG Scheduling keepalive for Connection Z6RT7C (Tunnel W2KF) in 5 m Feb 20 16:33:47-899476 cadet-per-9478 DEBUG Sending to peer P(W2KF) completed Feb 20 16:33:47-908703 cadet-cor-9478 DEBUG Received duplicate CADET_CONNECTION_CREATE message on connection Z6RT7C Feb 20 16:33:47-908766 cadet-con-9478 DEBUG Got duplicate CREATE for Connection Z6RT7C (Tunnel W2KF), scheduling another ACK (MQM ready) Feb 20 16:33:47-908808 cadet-tun-9478 DEBUG Connection Z6RT7C (Tunnel W2KF) no longer ready for Tunnel W2KF Feb 20 16:33:47-908865 cadet-con-9478 DEBUG Sending CONNECTION_CREATE_ACK message for Connection Z6RT7C (Tunnel W2KF) Feb 20 16:33:47-908914 cadet-per-9478 DEBUG Queueing message to peer P(W2KF) in MQM 0xd97e40 Feb 20 16:33:47-908950 cadet-per-9478 DEBUG Sending to peer P(W2KF) from MQM 0xd97e40 Feb 20 16:33:47-908993 cadet-tun-9478 DEBUG Connection Z6RT7C (Tunnel W2KF) now ready for Tunnel W2KF in state CADET_TUNNEL_KEY_UNINITIALIZED Feb 20 16:33:47-909039 cadet-con-9478 DEBUG Core MQ for Connection Z6RT7C (Tunnel W2KF) became available in state 4 Feb 20 16:33:47-909079 cadet-con-9478 DEBUG Scheduling keepalive for Connection Z6RT7C (Tunnel W2KF) in 5 m Feb 20 16:33:47-909232 cadet-per-9478 DEBUG Sending to peer P(W2KF) completed Feb 20 16:33:47-915182 cadet-tun-9478 DEBUG Tunnel W2KF received 188 bytes of encrypted data in state 0 Feb 20 16:33:47-915257 cadet-tun-9478 DEBUG Sending KX on Tunnel W2KF via Connection Z6RT7C (Tunnel W2KF) in state CADET_TUNNEL_KEY_UNINITIALIZED Feb 20 16:33:47-920496 cadet-tun-9478 DEBUG Tunnel W2KF estate changed from CADET_TUNNEL_KEY_UNINITIALIZED to CADET_TUNNEL_KEY_AX_SENT Feb 20 16:33:47-920546 cadet-con-9478 DEBUG Scheduling message for transmission on Connection Z6RT7C (Tunnel W2KF) Feb 20 16:33:47-920593 cadet-per-9478 DEBUG Queueing message to peer P(W2KF) in MQM 0xd97e40 Feb 20 16:33:47-920635 cadet-per-9478 DEBUG Sending to peer P(W2KF) from MQM 0xd97e40 Feb 20 16:33:47-920676 cadet-tun-9478 DEBUG Connection Z6RT7C (Tunnel W2KF) now ready for Tunnel W2KF in state CADET_TUNNEL_KEY_AX_SENT Feb 20 16:33:47-920729 cadet-con-9478 DEBUG Core MQ for Connection Z6RT7C (Tunnel W2KF) became available in state 4 Feb 20 16:33:47-920768 cadet-con-9478 DEBUG Scheduling keepalive for Connection Z6RT7C (Tunnel W2KF) in 5 m Feb 20 16:33:47-921075 cadet-per-9478 DEBUG Sending to peer P(W2KF) completed Feb 20 16:33:48-421148 cadet-tun-9478 DEBUG Trying to make KX progress on Tunnel W2KF in state CADET_TUNNEL_KEY_AX_SENT Feb 20 16:33:48-421550 cadet-tun-9478 DEBUG Sending KX on Tunnel W2KF via Connection Z6RT7C (Tunnel W2KF) in state CADET_TUNNEL_KEY_AX_SENT Feb 20 16:33:48-430683 cadet-con-9478 DEBUG Scheduling message for transmission on Connection Z6RT7C (Tunnel W2KF) Feb 20 16:33:48-431019 cadet-per-9478 DEBUG Queueing message to peer P(W2KF) in MQM 0xd97e40 Feb 20 16:33:48-431277 cadet-per-9478 DEBUG Sending to peer P(W2KF) from MQM 0xd97e40 Feb 20 16:33:48-431524 cadet-tun-9478 DEBUG Connection Z6RT7C (Tunnel W2KF) now ready for Tunnel W2KF in state CADET_TUNNEL_KEY_AX_SENT Feb 20 16:33:48-431763 cadet-con-9478 DEBUG Core MQ for Connection Z6RT7C (Tunnel W2KF) became available in state 4 Feb 20 16:33:48-432003 cadet-con-9478 DEBUG Scheduling keepalive for Connection Z6RT7C (Tunnel W2KF) in 5 m Feb 20 16:33:48-432480 cadet-per-9478 DEBUG Sending to peer P(W2KF) completed Feb 20 16:33:48-459876 cadet-tun-9478 DEBUG Handling KX_AUTH message for Tunnel W2KF Feb 20 16:33:48-474866 cadet-tun-9478 DEBUG Tunnel W2KF estate changed from CADET_TUNNEL_KEY_AX_SENT to CADET_TUNNEL_KEY_OK Feb 20 16:34:19-942178 cadet-tun-9478 DEBUG Tunnel W2KF received 188 bytes of encrypted data in state 5 Feb 20 16:34:19-942535 cadet-tun-9478 DEBUG Trying skipped keys Feb 20 16:34:19-942566 cadet-9478 WARNING External protocol violation detected at gnunet-service-cadet-new_tunnels.c:3138. Feb 20 16:34:19-942591 cadet-tun-9478 WARNING Tunnel W2KF failed to decrypt and validate encrypted data Feb 20 16:34:47-905662 cadet-tun-9478 DEBUG Performing connection maintenance for Tunnel W2KF. Feb 20 16:34:47-905730 cadet-per-9478 DEBUG Iterating over paths to peer P(W2KF) including direct link Feb 20 16:34:47-905753 cadet-pat-9478 DEBUG check_match found match with path W2KF(0xd7f690) Feb 20 16:34:47-905774 cadet-pat-9478 DEBUG Returning existing path W2KF(0xd7f690) as inverse for incoming connection Feb 20 16:34:47-905795 cadet-tun-9478 DEBUG Ignoring duplicate path W2KF(0xd7f690). Feb 20 16:34:47-905813 cadet-tun-9478 DEBUG Ignoring duplicate path W2KF(0xd7f690). Feb 20 16:35:23-949649 cadet-tun-9478 DEBUG Tunnel W2KF received 188 bytes of encrypted data in state 5 Feb 20 16:35:23-950233 cadet-tun-9478 DEBUG Trying skipped keys Feb 20 16:35:23-950267 cadet-9478 WARNING External protocol violation detected at gnunet-service-cadet-new_tunnels.c:3138. Feb 20 16:35:23-950302 cadet-tun-9478 WARNING Tunnel W2KF failed to decrypt and validate encrypted data Feb 20 16:35:47-927254 cadet-tun-9478 DEBUG Performing connection maintenance for Tunnel W2KF. Feb 20 16:35:47-927372 cadet-per-9478 DEBUG Iterating over paths to peer P(W2KF) including direct link Feb 20 16:35:47-927413 cadet-pat-9478 DEBUG check_match found match with path W2KF(0xd7f690) Feb 20 16:35:47-927450 cadet-pat-9478 DEBUG Returning existing path W2KF(0xd7f690) as inverse for incoming connection Feb 20 16:35:47-927490 cadet-tun-9478 DEBUG Ignoring duplicate path W2KF(0xd7f690). Feb 20 16:35:47-927522 cadet-tun-9478 DEBUG Ignoring duplicate path W2KF(0xd7f690). Feb 20 16:36:47-950068 cadet-tun-9478 DEBUG Performing connection maintenance for Tunnel W2KF. Feb 20 16:36:47-950147 cadet-per-9478 DEBUG Iterating over paths to peer P(W2KF) including direct link Feb 20 16:36:47-950171 cadet-pat-9478 DEBUG check_match found match with path W2KF(0xd7f690) Feb 20 16:36:47-950191 cadet-pat-9478 DEBUG Returning existing path W2KF(0xd7f690) as inverse for incoming connection Feb 20 16:36:47-950211 cadet-tun-9478 DEBUG Ignoring duplicate path W2KF(0xd7f690). Feb 20 16:36:47-950229 cadet-tun-9478 DEBUG Ignoring duplicate path W2KF(0xd7f690).