View Issue Details

Jump to NotesJump to History
IDProjectCategoryView StatusDate SubmittedLast Update
0004896GNUnetcadet servicepublic2017-02-16 16:012018-06-07 00:24
Reporterlurchi Assigned ToChristian Grothoff  
PrioritynormalSeveritymajorReproducibilitysometimes
Status closedResolutionfixed 
OSDebian 
Product VersionGit master 
Target Version0.11.0pre66Fixed in Version0.11.0pre66 
Summary0004896: Received CADET_CONNECTION_CREATE from P(PRPZ) for 4XEANC, but PRPZ(0xea5b90) already has a connection. Sending BROKEN
DescriptionAt revision 12c6e135a7805aea9ed8cdecfa554b292d71b65a no connection with gnunet-cadet can be established sometimes. I think it doesn't happen at the first start of gnunet (fresh database), but at the second and further starts.
Steps To Reproducestarting with a clear gnunet directory (./test in my case)
-GNUNET_FORCE_LOG="cadet;;;;DEBUG" gnunet-arm -s on both peers
-exchanging hellos using gnunet-peerinfo -g and gnunet-peerinfo -p
-gnunet-arm -e
-GNUNET_FORCE_LOG="cadet;;;;DEBUG" gnunet-arm -s on both peers
-gnunet-cadet -o 9999
-gnunet-cadet 7ER4YGE848FA4MN5EDNEFAKB8N4VWX1N9SR9AMZ0HZ03GBNKM8W0 9999
Additional Information[arm]
SYSTEM_ONLY = NO
USER_ONLY = NO

[hostlist]
AUTOSTART = NO
FORCESTART = NO

#[topology]
#FRIENDS-ONLY = YES

[peerinfo]
USE_INCLUDED_HELLOS = NO

[transport-udp]
BROADCAST = NO

[fs]
AUTOSTART = NO
FORCESTART = NO

[nse]
FORCESTART = NO

[set]
FORCESTART = NO

[statistics]
FORCESTART = NO

[vpn]
FORCESTART = NO

[PATHS]
GNUNET_HOME = ./test

[conversation]
LINE = 2
TagsNo tags attached.
Attached Files
20160216.txt (11,777 bytes)    
Feb 16 15:44:55-231634 cadet-18038 INFO CADET started for peer 2VJ5
Feb 16 15:44:55-273633 cadet-api-18047 DEBUG GNUNET_CADET_connect() 0x2308570
Feb 16 15:44:55-285493 cadet-api-18047 DEBUG Connecting to CADET
Feb 16 15:44:55-286205 cadet-18038 DEBUG Client(0) connected
Feb 16 15:44:55-290679 cadet-18038 DEBUG Open port X4QX93K5 requested by Client(0)
Feb 16 15:44:55-280749 cadet-api-18044 DEBUG GNUNET_CADET_connect() 0x215fe90
Feb 16 15:44:55-302289 cadet-api-18044 DEBUG Connecting to CADET
Feb 16 15:44:55-304362 cadet-18038 DEBUG Client(1) connected
Feb 16 15:44:55-311428 cadet-hll-18038 DEBUG Hello for PRPZ (472 bytes), expires on Fri Feb 17 03:44:04 2017
Feb 16 15:44:55-311485 cadet-per-18038 DEBUG Creating peer P(PRPZ)
Feb 16 15:44:55-311522 cadet-per-18038 DEBUG Got 472 byte HELLO for peer P(PRPZ)
Feb 16 15:44:55-383939 cadet-cor-18038 DEBUG CORE connection to peer 2VJ5 was established.
Feb 16 15:44:55-384015 cadet-per-18038 DEBUG Creating peer P(2VJ5)
Feb 16 15:44:55-384052 cadet-per-18038 DEBUG Message queue for peer P(2VJ5) is now 0xebc690
Feb 16 15:44:55-384091 cadet-per-18038 DEBUG Updating peer P(2VJ5) activation state (0 connections) with CORE link
Feb 16 15:44:55-392742 nat-18057 ERROR UPnP enabled in configuration, but UPnP client `upnpc` command not found, disabling UPnP
Feb 16 15:44:55-501712 cadet-dht-18038 DEBUG Announcing my HELLO (472 bytes) in the DHT
Feb 16 15:44:56-836487 transport-18051 WARNING External protocol violation detected at plugin_transport_udp.c:1275.
Feb 16 15:44:58-812320 cadet-18038 DEBUG Client(2) connected
Feb 16 15:44:58-812807 cadet-18038 DEBUG Open port PR96BHN5 requested by Client(2)
Feb 16 15:44:59-020445 cadet-cor-18038 DEBUG CORE connection to peer PRPZ was established.
Feb 16 15:44:59-020523 cadet-per-18038 DEBUG Message queue for peer P(PRPZ) is now 0xebd070
Feb 16 15:44:59-020561 cadet-per-18038 DEBUG Updating peer P(PRPZ) activation state (0 connections) with CORE link
Feb 16 15:45:00-022624 cadet-api-18047 DEBUG Creating new channel to PRPZ:3861448488 at 0x2322e70 number 80000000
Feb 16 15:45:00-022889 cadet-api-18047 DEBUG CADET NOTIFY TRANSMIT READY on channel 80000000 allow_send is 0 to origin with 76 bytes
Feb 16 15:45:00-023314 cadet-18038 DEBUG New channel to PRPZ at port X4QX93K5 requested by Client(0)
Feb 16 15:45:00-023360 cadet-tun-18038 DEBUG Creating new ephemeral ratchet key (DHRs)
Feb 16 15:45:00-031731 cadet-per-18038 DEBUG Updating peer P(PRPZ) activation state (0 connections) with tunnel with CORE link
Feb 16 15:45:00-031824 cadet-tun-18038 DEBUG Adding Channel PRPZ:X4QX93K5 ctn:0(80000000/0) to Tunnel PRPZ
Feb 16 15:45:00-031886 cadet-chn-18038 DEBUG Created channel to port X4QX93K5 at peer P(PRPZ) for Client(0) using Tunnel PRPZ
Feb 16 15:45:00-032750 cadet-tun-18038 DEBUG Performing connection maintenance for Tunnel PRPZ.
Feb 16 15:45:00-032802 cadet-per-18038 DEBUG Iterating over paths to peer P(PRPZ) including direct link
Feb 16 15:45:00-032843 cadet-per-18038 DEBUG Asked to look for paths at distance 0, but maximum for me is < 0
Feb 16 15:45:00-032887 cadet-per-18038 DEBUG Discovered that peer P(PRPZ) is on path PRPZ(0xea5b90) at offset 0
Feb 16 15:45:00-032951 cadet-con-18038 DEBUG Creating Connection JX3TTW (Tunnel PRPZ) using path PRPZ(0xea5b90)
Feb 16 15:45:00-033007 cadet-pat-18038 DEBUG Adding connection Connection JX3TTW (Tunnel PRPZ) to path PRPZ(0xea5b90) at offset 0
Feb 16 15:45:00-033047 cadet-per-18038 DEBUG Creating MQM 0xebdee0 for peer P(PRPZ)
Feb 16 15:45:00-033091 cadet-con-18038 DEBUG Core MQ for Connection JX3TTW (Tunnel PRPZ) became available in state 0
Feb 16 15:45:00-033146 cadet-tun-18038 DEBUG Found interesting path PRPZ(0xea5b90) for Tunnel PRPZ, created Connection JX3TTW (Tunnel PRPZ)
Feb 16 15:45:00-033189 cadet-pat-18038 DEBUG Created new path PRPZ(0xea5b90) to create inverse for incoming connection
Feb 16 15:45:00-033230 cadet-per-18038 DEBUG Attaching path PRPZ(0xea5b90) to peer P(PRPZ) (forced)
Feb 16 15:45:00-033272 cadet-tun-18038 DEBUG Ignoring duplicate path PRPZ(0xea5b90).
Feb 16 15:45:00-033316 cadet-tun-18038 DEBUG Ignoring duplicate path PRPZ(0xea5b90).
Feb 16 15:45:00-033374 cadet-con-18038 DEBUG Sending CADET_CONNECTION_CREATE message for Connection JX3TTW (Tunnel PRPZ)
Feb 16 15:45:00-033422 cadet-per-18038 DEBUG Queueing message to peer P(PRPZ) in MQM 0xebdee0
Feb 16 15:45:00-033464 cadet-per-18038 DEBUG Sending to peer P(PRPZ) from MQM 0xebdee0
Feb 16 15:45:00-033514 cadet-con-18038 DEBUG Core MQ for Connection JX3TTW (Tunnel PRPZ) became available in state 2
Feb 16 15:45:00-035682 cadet-con-18038 DEBUG Sending CADET_CONNECTION_CREATE message for Connection JX3TTW (Tunnel PRPZ)
Feb 16 15:45:00-035739 cadet-per-18038 DEBUG Queueing message to peer P(PRPZ) in MQM 0xebdee0
Feb 16 15:45:01-878374 cadet-per-18038 DEBUG Sending to peer P(PRPZ) completed
Feb 16 15:45:01-878471 cadet-per-18038 DEBUG Sending to peer P(PRPZ) from MQM 0xebdee0
Feb 16 15:45:01-878516 cadet-con-18038 DEBUG Core MQ for Connection JX3TTW (Tunnel PRPZ) became available in state 2
Feb 16 15:45:01-879921 cadet-per-18038 DEBUG Sending to peer P(PRPZ) completed
Feb 16 15:45:01-882676 cadet-con-18038 DEBUG Sending CADET_CONNECTION_CREATE message for Connection JX3TTW (Tunnel PRPZ)
Feb 16 15:45:01-882741 cadet-per-18038 DEBUG Queueing message to peer P(PRPZ) in MQM 0xebdee0
Feb 16 15:45:01-882782 cadet-per-18038 DEBUG Sending to peer P(PRPZ) from MQM 0xebdee0
Feb 16 15:45:01-882827 cadet-con-18038 DEBUG Core MQ for Connection JX3TTW (Tunnel PRPZ) became available in state 2
Feb 16 15:45:01-883011 cadet-per-18038 DEBUG Sending to peer P(PRPZ) completed
Feb 16 15:45:01-891006 cadet-con-18038 DEBUG Sending CADET_CONNECTION_CREATE message for Connection JX3TTW (Tunnel PRPZ)
Feb 16 15:45:01-891073 cadet-per-18038 DEBUG Queueing message to peer P(PRPZ) in MQM 0xebdee0
Feb 16 15:45:01-891114 cadet-per-18038 DEBUG Sending to peer P(PRPZ) from MQM 0xebdee0
Feb 16 15:45:01-891162 cadet-con-18038 DEBUG Core MQ for Connection JX3TTW (Tunnel PRPZ) became available in state 2
Feb 16 15:45:01-891341 cadet-per-18038 DEBUG Sending to peer P(PRPZ) completed
Feb 16 15:45:01-907323 cadet-con-18038 DEBUG Sending CADET_CONNECTION_CREATE message for Connection JX3TTW (Tunnel PRPZ)
Feb 16 15:45:01-907391 cadet-per-18038 DEBUG Queueing message to peer P(PRPZ) in MQM 0xebdee0
Feb 16 15:45:01-907434 cadet-per-18038 DEBUG Sending to peer P(PRPZ) from MQM 0xebdee0
Feb 16 15:45:01-907479 cadet-con-18038 DEBUG Core MQ for Connection JX3TTW (Tunnel PRPZ) became available in state 2
Feb 16 15:45:01-907656 cadet-per-18038 DEBUG Sending to peer P(PRPZ) completed
Feb 16 15:45:01-939640 cadet-con-18038 DEBUG Sending CADET_CONNECTION_CREATE message for Connection JX3TTW (Tunnel PRPZ)
Feb 16 15:45:01-939708 cadet-per-18038 DEBUG Queueing message to peer P(PRPZ) in MQM 0xebdee0
Feb 16 15:45:01-939753 cadet-per-18038 DEBUG Sending to peer P(PRPZ) from MQM 0xebdee0
Feb 16 15:45:01-939796 cadet-con-18038 DEBUG Core MQ for Connection JX3TTW (Tunnel PRPZ) became available in state 2
Feb 16 15:45:01-939977 cadet-per-18038 DEBUG Sending to peer P(PRPZ) completed
Feb 16 15:45:02-003976 cadet-con-18038 DEBUG Sending CADET_CONNECTION_CREATE message for Connection JX3TTW (Tunnel PRPZ)
Feb 16 15:45:02-004039 cadet-per-18038 DEBUG Queueing message to peer P(PRPZ) in MQM 0xebdee0
Feb 16 15:45:02-004083 cadet-per-18038 DEBUG Sending to peer P(PRPZ) from MQM 0xebdee0
Feb 16 15:45:02-004126 cadet-con-18038 DEBUG Core MQ for Connection JX3TTW (Tunnel PRPZ) became available in state 2
Feb 16 15:45:02-004309 cadet-per-18038 DEBUG Sending to peer P(PRPZ) completed
Feb 16 15:45:02-132385 cadet-con-18038 DEBUG Sending CADET_CONNECTION_CREATE message for Connection JX3TTW (Tunnel PRPZ)
Feb 16 15:45:02-132461 cadet-per-18038 DEBUG Queueing message to peer P(PRPZ) in MQM 0xebdee0
Feb 16 15:45:02-132501 cadet-per-18038 DEBUG Sending to peer P(PRPZ) from MQM 0xebdee0
Feb 16 15:45:02-132550 cadet-con-18038 DEBUG Core MQ for Connection JX3TTW (Tunnel PRPZ) became available in state 2
Feb 16 15:45:02-132743 cadet-per-18038 DEBUG Sending to peer P(PRPZ) completed
Feb 16 15:45:02-373585 cadet-cor-18038 DEBUG Received CADET_CONNECTION_CREATE message from P(PRPZ) for connection 4XEANC, building inverse path
Feb 16 15:45:02-374266 cadet-pat-18038 DEBUG check_match found match with path PRPZ(0xea5b90)
Feb 16 15:45:02-374353 cadet-pat-18038 DEBUG Returning existing path PRPZ(0xea5b90) as inverse for incoming connection
Feb 16 15:45:02-375228 cadet-con-18038 DEBUG Got two connections on PRPZ(0xea5b90), keeping my existing Connection JX3TTW (Tunnel PRPZ)
Feb 16 15:45:02-375309 cadet-tun-18038 DEBUG Tunnel PRPZ refused inbound Connection(NULL) (duplicate)
Feb 16 15:45:02-375391 cadet-cor-18038 DEBUG Received CADET_CONNECTION_CREATE from P(PRPZ) for 4XEANC, but PRPZ(0xea5b90) already has a connection. Sending BROKEN
Feb 16 15:45:02-375470 cadet-per-18038 DEBUG Sending message to P(PRPZ) out of management
Feb 16 15:45:02-375600 cadet-cor-18038 DEBUG Received CONNECTION_DESTROY for connection 4XEANC. Destroying route.
Feb 16 15:45:02-375681 cadet-cor-18038 DEBUG Failed to route message of type 1003 from P(PRPZ) on connection 4XEANC: no route
Feb 16 15:45:02-375754 cadet-per-18038 DEBUG Sending message to P(PRPZ) out of management
Feb 16 15:45:02-375864 cadet-cor-18038 DEBUG Received CONNECTION_CREATE_ACK for connection JX3TTW.
Feb 16 15:45:02-375945 cadet-con-18038 DEBUG Received CADET_CONNECTION_CREATE_ACK for Connection JX3TTW (Tunnel PRPZ) in state 2 (MQM ready)
Feb 16 15:45:02-376032 cadet-tun-18038 DEBUG Connection JX3TTW (Tunnel PRPZ) now ready for Tunnel PRPZ in state CADET_TUNNEL_KEY_UNINITIALIZED
Feb 16 15:45:02-376120 cadet-tun-18038 DEBUG Sending KX on Tunnel PRPZ via Connection JX3TTW (Tunnel PRPZ) using CADET_TUNNEL_KEY_UNINITIALIZED in state ��
Feb 16 15:45:02-385406 cadet-tun-18038 DEBUG Tunnel PRPZ estate changed from CADET_TUNNEL_KEY_UNINITIALIZED to CADET_TUNNEL_KEY_AX_SENT
Feb 16 15:45:02-385500 cadet-con-18038 DEBUG Scheduling message for transmission on Connection JX3TTW (Tunnel PRPZ)
Feb 16 15:45:02-385570 cadet-per-18038 DEBUG Queueing message to peer P(PRPZ) in MQM 0xebdee0
Feb 16 15:45:02-385690 cadet-tun-18038 DEBUG Creating fresh unverified KX for Tunnel PRPZ.
Feb 16 15:45:02-400300 cadet-tun-18038 DEBUG Tunnel PRPZ estate changed from CADET_TUNNEL_KEY_AX_SENT to CADET_TUNNEL_KEY_AX_SENT_AND_RECV
Feb 16 15:45:02-400428 cadet-tun-18038 DEBUG Trying to make KX progress on Tunnel PRPZ in state CADET_TUNNEL_KEY_AX_SENT_AND_RECV
Feb 16 15:45:02-400515 cadet-tun-18038 DEBUG Wanted to send KX_AUTH on Tunnel PRPZ, but no connection is ready, deferring
Feb 16 15:45:02-608573 cadet-cor-18038 DEBUG Failed to route message of type 1002 from P(PRPZ) on connection 4XEANC: no route
Feb 16 15:45:02-608643 cadet-per-18038 DEBUG Sending message to P(PRPZ) out of management
Feb 16 15:45:02-612408 cadet-cor-18038 DEBUG Failed to route message of type 1002 from P(PRPZ) on connection 4XEANC: no route
Feb 16 15:45:02-612459 cadet-per-18038 DEBUG Sending message to P(PRPZ) out of management
Feb 16 15:45:02-815732 cadet-cor-18038 DEBUG Failed to route message of type 1002 from P(PRPZ) on connection 4XEANC: no route
Feb 16 15:45:02-815809 cadet-per-18038 DEBUG Sending message to P(PRPZ) out of management
Feb 16 15:45:02-820551 cadet-cor-18038 DEBUG Failed to route message of type 1002 from P(PRPZ) on connection 4XEANC: no route
Feb 16 15:45:02-820595 cadet-per-18038 DEBUG Sending message to P(PRPZ) out of management
Feb 16 15:45:02-880701 cadet-tun-18038 DEBUG Got duplicate unverified KX on Tunnel PRPZ. Fire back KX_AUTH again.
Feb 16 15:45:02-880746 cadet-tun-18038 DEBUG Wanted to send KX_AUTH on Tunnel PRPZ, but no connection is ready, deferring
20160216.txt (11,777 bytes)   

Activities

Christian Grothoff

2017-02-16 21:00

manager   ~0011768

6acad1349..f187f1b05 *might* fix this, the log is a bit short/truncated to be sure, but at least it should now behave quite differently.

lurchi

2017-02-17 01:38

developer   ~0011770

Last edited: 2017-02-17 01:39

 I don't get "Sending BROKEN" anymore and I don't see the messages from 0004897 anymore either. However, now I get the attached output sometimes. Only starting with fresh peers seems to help.
By fresh peers I mean deleting $GNUNET_HOME and restarting gnunet.

20160217.txt (14,170 bytes)    
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
20160217.txt (14,170 bytes)   

Christian Grothoff

2017-02-17 01:39

manager   ~0011771

What do you think is wrong about the attached output? What is the "wrong" behavior of CADET here?

lurchi

2017-02-17 21:27

developer   ~0011773

The wrong behaviour is, that no connection is being established. At least gnunet-cadet doesn't display anything. The two peers never had a connection before, so I guessed there shouldn't be confusion about the ephemeral keys, but maybe I'm misinterpreting the output.
Should I try to catch more debug output?

Christian Grothoff

2017-02-17 21:34

manager   ~0011774

Also ich hab heute abend viel herumgetested, und mehr obskure Probleme gefunden & gefixed. Eins hab ich noch auf der Liste, danach sollten wir mal schauen ob ich das hier genauer nachgestellt bekomme. Ggf. Mumble nachmittags am 18.2?

lurchi

2017-02-17 21:53

developer   ~0011775

Ja, können wir machen.

lurchi

2017-02-18 18:18

developer   ~0011780

Last edited: 2017-02-18 18:21

 something with duplicate connections occurred again (revision 0af32e03677ab1c8a819b376c8fa026d0ffa9144). The listening peer says

"Feb 18 18:05:56-081965 cadet-cor-21550 DEBUG Received CADET_CONNECTION_CREATE from P(6SMN) for M1AG3J, but 6SMN(0x206dad0) already has a connection. Sending BROKEN
"

and the connecting peer:

"Feb 18 18:05:56-197189 cadet-cor-4030 DEBUG Received duplicate CADET_CONNECTION_CREATE message on connection W4DHGD"

I attached both logs.

20160218.connecting.txt (13,235 bytes)    
Feb 18 18:05:50-114359 cadet-4030 INFO CADET started for peer 6SMN
Feb 18 18:05:50-141871 cadet-api-4037 DEBUG GNUNET_CADET_connect() 0x1ecae90
Feb 18 18:05:50-121763 cadet-api-4035 DEBUG GNUNET_CADET_connecT()
Feb 18 18:05:50-147414 cadet-api-4037 DEBUG Connecting to CADET
Feb 18 18:05:50-147756 cadet-4030 DEBUG Client(0) connected
Feb 18 18:05:50-148781 cadet-4030 DEBUG Client(1) connected
Feb 18 18:05:50-148861 cadet-4030 DEBUG Open port X4QX93K5 requested by Client(0)
Feb 18 18:05:50-178105 cadet-hll-4030 DEBUG Hello for W7ZF (472 bytes), expires on Sun Feb 19 06:05:32 2017
Feb 18 18:05:50-178159 cadet-per-4030 DEBUG Creating peer P(W7ZF)
Feb 18 18:05:50-178181 cadet-per-4030 DEBUG Got 472 byte HELLO for peer P(W7ZF)
Feb 18 18:05:50-187684 cadet-cor-4030 DEBUG CORE connection to peer 6SMN was established.
Feb 18 18:05:50-187733 cadet-per-4030 DEBUG Creating peer P(6SMN)
Feb 18 18:05:50-187754 cadet-per-4030 DEBUG Message queue for peer P(6SMN) is now 0x2091700
Feb 18 18:05:50-187775 cadet-per-4030 DEBUG Updating peer P(6SMN) activation state (0 connections) with CORE link
Feb 18 18:05:50-207577 nat-4048 ERROR UPnP enabled in configuration, but UPnP client `upnpc` command not found, disabling UPnP
Feb 18 18:05:50-228979 cadet-hll-4030 DEBUG Hello for W7ZF (472 bytes), expires on Sun Feb 19 06:05:50 2017
Feb 18 18:05:50-229017 cadet-per-4030 DEBUG Got 472 byte HELLO for peer P(W7ZF)
Feb 18 18:05:50-246240 cadet-hll-4030 DEBUG Hello for W7ZF (472 bytes), expires on Sun Feb 19 06:05:50 2017
Feb 18 18:05:50-246269 cadet-per-4030 DEBUG Got 472 byte HELLO for peer P(W7ZF)
Feb 18 18:05:50-270286 cadet-hll-4030 DEBUG Hello for W7ZF (472 bytes), expires on Sun Feb 19 06:05:50 2017
Feb 18 18:05:50-270316 cadet-per-4030 DEBUG Got 472 byte HELLO for peer P(W7ZF)
Feb 18 18:05:50-290061 cadet-hll-4030 DEBUG Hello for W7ZF (472 bytes), expires on Sun Feb 19 06:05:50 2017
Feb 18 18:05:50-290090 cadet-per-4030 DEBUG Got 472 byte HELLO for peer P(W7ZF)
Feb 18 18:05:50-311323 cadet-dht-4030 DEBUG Announcing my HELLO (472 bytes) in the DHT
Feb 18 18:05:51-904677 cadet-4030 DEBUG Client(2) connected
Feb 18 18:05:51-905271 cadet-4030 DEBUG New channel to W7ZF at port PR96BHN5 requested by Client(2)
Feb 18 18:05:51-905325 cadet-tun-4030 DEBUG Creating new ephemeral ratchet key (DHRs)
Feb 18 18:05:51-919190 cadet-per-4030 DEBUG Updating peer P(W7ZF) activation state (0 connections) with tunnel
Feb 18 18:05:51-919533 cadet-dht-4030 DEBUG Starting DHT GET for peer W7ZF (0x20915c0)
Feb 18 18:05:51-919836 cadet-tun-4030 DEBUG Adding Channel W7ZF:PR96BHN5 ctn:0(80000000/0) to Tunnel W7ZF
Feb 18 18:05:51-920110 cadet-chn-4030 DEBUG Created channel to port PR96BHN5 at peer P(W7ZF) for Client(2) using Tunnel W7ZF
Feb 18 18:05:51-925763 cadet-tun-4030 DEBUG Performing connection maintenance for Tunnel W7ZF.
Feb 18 18:05:51-926032 cadet-per-4030 DEBUG Iterating over paths to peer P(W7ZF)
Feb 18 18:05:53-063540 cadet-cor-4030 DEBUG CORE connection to peer W7ZF was established.
Feb 18 18:05:53-063613 cadet-per-4030 DEBUG Message queue for peer P(W7ZF) is now 0x2093610
Feb 18 18:05:53-063637 cadet-per-4030 DEBUG Updating peer P(W7ZF) activation state (0 connections) with tunnel with CORE link
Feb 18 18:05:53-063660 cadet-dht-4030 DEBUG Stopping DHT GET 0x20915c0
Feb 18 18:05:53-063700 cadet-per-4030 DEBUG Asked to look for paths at distance 0, but maximum for me is < 0
Feb 18 18:05:53-063724 cadet-per-4030 DEBUG Discovered that peer P(W7ZF) is on path W7ZF(0x207aad0) at offset 0
Feb 18 18:05:53-063767 cadet-con-4030 DEBUG Creating Connection M1AG3J (Tunnel W7ZF) using path W7ZF(0x207aad0)
Feb 18 18:05:53-063789 cadet-pat-4030 DEBUG Adding connection Connection M1AG3J (Tunnel W7ZF) to path W7ZF(0x207aad0) at offset 0
Feb 18 18:05:53-063812 cadet-per-4030 DEBUG Creating MQM 0x2090dd0 for peer P(W7ZF)
Feb 18 18:05:53-063833 cadet-con-4030 DEBUG Core MQ for Connection M1AG3J (Tunnel W7ZF) became available in state 0
Feb 18 18:05:53-063859 cadet-tun-4030 DEBUG Found interesting path W7ZF(0x207aad0) for Tunnel W7ZF, created Connection M1AG3J (Tunnel W7ZF)
Feb 18 18:05:53-063883 cadet-pat-4030 DEBUG Created new path W7ZF(0x207aad0) to create inverse for incoming connection
Feb 18 18:05:53-063906 cadet-per-4030 DEBUG Attaching path W7ZF(0x207aad0) to peer P(W7ZF) (forced)
Feb 18 18:05:53-063928 cadet-tun-4030 DEBUG Ignoring duplicate path W7ZF(0x207aad0).
Feb 18 18:05:53-063983 cadet-con-4030 DEBUG Sending CADET_CONNECTION_CREATE message for Connection M1AG3J (Tunnel W7ZF)
Feb 18 18:05:53-064003 cadet-per-4030 DEBUG Queueing message to peer P(W7ZF) in MQM 0x2090dd0
Feb 18 18:05:53-064026 cadet-per-4030 DEBUG Sending to peer P(W7ZF) from MQM 0x2090dd0
Feb 18 18:05:53-064053 cadet-con-4030 DEBUG Core MQ for Connection M1AG3J (Tunnel W7ZF) became available in state 2
Feb 18 18:05:53-066185 cadet-con-4030 DEBUG Sending CADET_CONNECTION_CREATE message for Connection M1AG3J (Tunnel W7ZF)
Feb 18 18:05:53-066220 cadet-per-4030 DEBUG Queueing message to peer P(W7ZF) in MQM 0x2090dd0
Feb 18 18:05:56-035353 cadet-per-4030 DEBUG Sending to peer P(W7ZF) completed
Feb 18 18:05:56-035428 cadet-per-4030 DEBUG Sending to peer P(W7ZF) from MQM 0x2090dd0
Feb 18 18:05:56-035454 cadet-con-4030 DEBUG Core MQ for Connection M1AG3J (Tunnel W7ZF) became available in state 2
Feb 18 18:05:56-036359 cadet-per-4030 DEBUG Sending to peer P(W7ZF) completed
Feb 18 18:05:56-039601 cadet-con-4030 DEBUG Sending CADET_CONNECTION_CREATE message for Connection M1AG3J (Tunnel W7ZF)
Feb 18 18:05:56-039631 cadet-per-4030 DEBUG Queueing message to peer P(W7ZF) in MQM 0x2090dd0
Feb 18 18:05:56-039650 cadet-per-4030 DEBUG Sending to peer P(W7ZF) from MQM 0x2090dd0
Feb 18 18:05:56-039672 cadet-con-4030 DEBUG Core MQ for Connection M1AG3J (Tunnel W7ZF) became available in state 2
Feb 18 18:05:56-039884 cadet-per-4030 DEBUG Sending to peer P(W7ZF) completed
Feb 18 18:05:56-047819 cadet-con-4030 DEBUG Sending CADET_CONNECTION_CREATE message for Connection M1AG3J (Tunnel W7ZF)
Feb 18 18:05:56-047855 cadet-per-4030 DEBUG Queueing message to peer P(W7ZF) in MQM 0x2090dd0
Feb 18 18:05:56-047875 cadet-per-4030 DEBUG Sending to peer P(W7ZF) from MQM 0x2090dd0
Feb 18 18:05:56-047898 cadet-con-4030 DEBUG Core MQ for Connection M1AG3J (Tunnel W7ZF) became available in state 2
Feb 18 18:05:56-048135 cadet-per-4030 DEBUG Sending to peer P(W7ZF) completed
Feb 18 18:05:56-064036 cadet-con-4030 DEBUG Sending CADET_CONNECTION_CREATE message for Connection M1AG3J (Tunnel W7ZF)
Feb 18 18:05:56-064072 cadet-per-4030 DEBUG Queueing message to peer P(W7ZF) in MQM 0x2090dd0
Feb 18 18:05:56-064092 cadet-per-4030 DEBUG Sending to peer P(W7ZF) from MQM 0x2090dd0
Feb 18 18:05:56-064114 cadet-con-4030 DEBUG Core MQ for Connection M1AG3J (Tunnel W7ZF) became available in state 2
Feb 18 18:05:56-064328 cadet-per-4030 DEBUG Sending to peer P(W7ZF) completed
Feb 18 18:05:56-096336 cadet-con-4030 DEBUG Sending CADET_CONNECTION_CREATE message for Connection M1AG3J (Tunnel W7ZF)
Feb 18 18:05:56-096417 cadet-per-4030 DEBUG Queueing message to peer P(W7ZF) in MQM 0x2090dd0
Feb 18 18:05:56-096439 cadet-per-4030 DEBUG Sending to peer P(W7ZF) from MQM 0x2090dd0
Feb 18 18:05:56-096466 cadet-con-4030 DEBUG Core MQ for Connection M1AG3J (Tunnel W7ZF) became available in state 2
Feb 18 18:05:56-096834 cadet-per-4030 DEBUG Sending to peer P(W7ZF) completed
Feb 18 18:05:56-159840 cadet-cor-4030 DEBUG Received CADET_CONNECTION_CREATE message from P(W7ZF) for connection W4DHGD, building inverse path
Feb 18 18:05:56-159912 cadet-pat-4030 DEBUG check_match found match with path W7ZF(0x207aad0)
Feb 18 18:05:56-159952 cadet-pat-4030 DEBUG Returning existing path W7ZF(0x207aad0) as inverse for incoming connection
Feb 18 18:05:56-160002 cadet-con-4030 DEBUG Got two connections on W7ZF(0x207aad0), dropping my existing Connection M1AG3J (Tunnel W7ZF)
Feb 18 18:05:56-160042 cadet-per-4030 DEBUG Destroying MQM 0x2090dd0 for peer P(W7ZF) with last ditch transmission
Feb 18 18:05:56-160085 cadet-con-4030 DEBUG Destroying Connection M1AG3J
Feb 18 18:05:56-160126 cadet-pat-4030 DEBUG Removing connection Connection M1AG3J to path W7ZF(0x207aad0) at offset 0
Feb 18 18:05:56-160169 cadet-con-4030 DEBUG Creating Connection W4DHGD (Tunnel W7ZF) using path W7ZF(0x207aad0)
Feb 18 18:05:56-160208 cadet-pat-4030 DEBUG Adding connection Connection W4DHGD (Tunnel W7ZF) to path W7ZF(0x207aad0) at offset 0
Feb 18 18:05:56-160245 cadet-per-4030 DEBUG Creating MQM 0x2090dd0 for peer P(W7ZF)
Feb 18 18:05:56-160282 cadet-con-4030 DEBUG Core MQ for Connection W4DHGD (Tunnel W7ZF) became available in state 3
Feb 18 18:05:56-160330 cadet-tun-4030 DEBUG Tunnel W7ZF has new Connection W4DHGD (Tunnel W7ZF)
Feb 18 18:05:56-160405 cadet-con-4030 DEBUG Sending CONNECTION_CREATE_ACK message for Connection W4DHGD (Tunnel W7ZF)
Feb 18 18:05:56-160442 cadet-per-4030 DEBUG Queueing message to peer P(W7ZF) in MQM 0x2090dd0
Feb 18 18:05:56-171123 cadet-cor-4030 DEBUG Failed to route message of type 1002 from P(W7ZF) on connection M1AG3J: no route
Feb 18 18:05:56-176356 cadet-cor-4030 DEBUG Failed to route message of type 1002 from P(W7ZF) on connection M1AG3J: no route
Feb 18 18:05:56-180477 cadet-cor-4030 DEBUG Failed to route message of type 1002 from P(W7ZF) on connection M1AG3J: no route
Feb 18 18:05:56-181007 cadet-cor-4030 DEBUG Failed to route message of type 1002 from P(W7ZF) on connection M1AG3J: no route
Feb 18 18:05:56-181281 cadet-cor-4030 DEBUG Failed to route message of type 1002 from P(W7ZF) on connection M1AG3J: no route
Feb 18 18:05:56-181761 cadet-cor-4030 DEBUG Failed to route message of type 1002 from P(W7ZF) on connection M1AG3J: no route
Feb 18 18:05:56-197189 cadet-cor-4030 DEBUG Received duplicate CADET_CONNECTION_CREATE message on connection W4DHGD
Feb 18 18:05:56-197258 cadet-con-4030 DEBUG Got duplicate CREATE for Connection W4DHGD (Tunnel W7ZF). MQ is busy, not queueing another ACK
Feb 18 18:05:56-197441 cadet-cor-4030 DEBUG Received duplicate CADET_CONNECTION_CREATE message on connection W4DHGD
Feb 18 18:05:56-197486 cadet-con-4030 DEBUG Got duplicate CREATE for Connection W4DHGD (Tunnel W7ZF). MQ is busy, not queueing another ACK
Feb 18 18:05:56-197691 cadet-cor-4030 DEBUG Received duplicate CADET_CONNECTION_CREATE message on connection W4DHGD
Feb 18 18:05:56-197735 cadet-con-4030 DEBUG Got duplicate CREATE for Connection W4DHGD (Tunnel W7ZF). MQ is busy, not queueing another ACK
Feb 18 18:05:56-206974 cadet-cor-4030 DEBUG Received duplicate CADET_CONNECTION_CREATE message on connection W4DHGD
Feb 18 18:05:56-207074 cadet-con-4030 DEBUG Got duplicate CREATE for Connection W4DHGD (Tunnel W7ZF). MQ is busy, not queueing another ACK
Feb 18 18:05:56-232675 cadet-cor-4030 DEBUG Received duplicate CADET_CONNECTION_CREATE message on connection W4DHGD
Feb 18 18:05:56-232735 cadet-con-4030 DEBUG Got duplicate CREATE for Connection W4DHGD (Tunnel W7ZF). MQ is busy, not queueing another ACK
Feb 18 18:05:56-303360 cadet-cor-4030 DEBUG Received duplicate CADET_CONNECTION_CREATE message on connection W4DHGD
Feb 18 18:05:56-303432 cadet-con-4030 DEBUG Got duplicate CREATE for Connection W4DHGD (Tunnel W7ZF). MQ is busy, not queueing another ACK
Feb 18 18:05:56-428215 cadet-cor-4030 DEBUG Received duplicate CADET_CONNECTION_CREATE message on connection W4DHGD
Feb 18 18:05:56-428280 cadet-con-4030 DEBUG Got duplicate CREATE for Connection W4DHGD (Tunnel W7ZF). MQ is busy, not queueing another ACK
Feb 18 18:05:56-684564 cadet-cor-4030 DEBUG Received duplicate CADET_CONNECTION_CREATE message on connection W4DHGD
Feb 18 18:05:56-684646 cadet-con-4030 DEBUG Got duplicate CREATE for Connection W4DHGD (Tunnel W7ZF). MQ is busy, not queueing another ACK
Feb 18 18:05:57-198342 cadet-cor-4030 DEBUG Received duplicate CADET_CONNECTION_CREATE message on connection W4DHGD
Feb 18 18:05:57-198454 cadet-con-4030 DEBUG Got duplicate CREATE for Connection W4DHGD (Tunnel W7ZF). MQ is busy, not queueing another ACK
Feb 18 18:05:58-219720 cadet-cor-4030 DEBUG Received duplicate CADET_CONNECTION_CREATE message on connection W4DHGD
Feb 18 18:05:58-219825 cadet-con-4030 DEBUG Got duplicate CREATE for Connection W4DHGD (Tunnel W7ZF). MQ is busy, not queueing another ACK
Feb 18 18:06:00-277384 cadet-cor-4030 DEBUG Received duplicate CADET_CONNECTION_CREATE message on connection W4DHGD
Feb 18 18:06:00-277491 cadet-con-4030 DEBUG Got duplicate CREATE for Connection W4DHGD (Tunnel W7ZF). MQ is busy, not queueing another ACK
Feb 18 18:06:04-370248 cadet-cor-4030 DEBUG Received duplicate CADET_CONNECTION_CREATE message on connection W4DHGD
Feb 18 18:06:04-370324 cadet-con-4030 DEBUG Got duplicate CREATE for Connection W4DHGD (Tunnel W7ZF). MQ is busy, not queueing another ACK
Feb 18 18:06:12-577371 cadet-cor-4030 DEBUG Received duplicate CADET_CONNECTION_CREATE message on connection W4DHGD
Feb 18 18:06:12-577460 cadet-con-4030 DEBUG Got duplicate CREATE for Connection W4DHGD (Tunnel W7ZF). MQ is busy, not queueing another ACK
Feb 18 18:06:28-979689 cadet-cor-4030 DEBUG Received duplicate CADET_CONNECTION_CREATE message on connection W4DHGD
Feb 18 18:06:28-979767 cadet-con-4030 DEBUG Got duplicate CREATE for Connection W4DHGD (Tunnel W7ZF). MQ is busy, not queueing another ACK
20160218.connecting.txt (13,235 bytes)   

lurchi

2017-02-18 18:19

developer   ~0011781

and the listening peer (mantis allows only one file per message)
20160218.listening.txt (16,914 bytes)    
Feb 18 18:05:47-434599 cadet-21550 INFO CADET started for peer W7ZF
Feb 18 18:05:47-463041 cadet-api-21556 DEBUG GNUNET_CADET_connect() 0x16c3e90
Feb 18 18:05:47-467689 cadet-api-21556 DEBUG Connecting to CADET
Feb 18 18:05:47-469686 cadet-21550 DEBUG Client(0) connected
Feb 18 18:05:47-471102 cadet-api-21560 DEBUG GNUNET_CADET_connecT()
Feb 18 18:05:47-472770 cadet-21550 DEBUG Client(1) connected
Feb 18 18:05:47-474323 cadet-21550 DEBUG Open port X4QX93K5 requested by Client(1)
Feb 18 18:05:47-488239 cadet-hll-21550 DEBUG Hello for 6SMN (472 bytes), expires on Sun Feb 19 05:58:00 2017
Feb 18 18:05:47-488338 cadet-per-21550 DEBUG Creating peer P(6SMN)
Feb 18 18:05:47-488381 cadet-per-21550 DEBUG Got 472 byte HELLO for peer P(6SMN)
Feb 18 18:05:47-510572 cadet-cor-21550 DEBUG CORE connection to peer W7ZF was established.
Feb 18 18:05:47-510637 cadet-per-21550 DEBUG Creating peer P(W7ZF)
Feb 18 18:05:47-510680 cadet-per-21550 DEBUG Message queue for peer P(W7ZF) is now 0x2084610
Feb 18 18:05:47-510723 cadet-per-21550 DEBUG Updating peer P(W7ZF) activation state (0 connections) with CORE link
Feb 18 18:05:47-519875 nat-21571 ERROR UPnP enabled in configuration, but UPnP client `upnpc` command not found, disabling UPnP
Feb 18 18:05:47-626948 cadet-dht-21550 DEBUG Announcing my HELLO (472 bytes) in the DHT
Feb 18 18:05:50-188965 transport-21563 WARNING External protocol violation detected at plugin_transport_udp.c:1275.
Feb 18 18:05:51-270695 cadet-21550 DEBUG Client(2) connected
Feb 18 18:05:51-271155 cadet-21550 DEBUG Open port PR96BHN5 requested by Client(2)
Feb 18 18:05:53-068215 cadet-cor-21550 DEBUG CORE connection to peer 6SMN was established.
Feb 18 18:05:53-068319 cadet-per-21550 DEBUG Message queue for peer P(6SMN) is now 0x2085060
Feb 18 18:05:53-068353 cadet-per-21550 DEBUG Updating peer P(6SMN) activation state (0 connections) with CORE link
Feb 18 18:05:54-070476 cadet-21550 DEBUG New channel to 6SMN at port X4QX93K5 requested by Client(1)
Feb 18 18:05:54-070564 cadet-tun-21550 DEBUG Creating new ephemeral ratchet key (DHRs)
Feb 18 18:05:54-079751 cadet-per-21550 DEBUG Updating peer P(6SMN) activation state (0 connections) with tunnel with CORE link
Feb 18 18:05:54-079824 cadet-tun-21550 DEBUG Adding Channel 6SMN:X4QX93K5 ctn:0(80000000/0) to Tunnel 6SMN
Feb 18 18:05:54-079860 cadet-chn-21550 DEBUG Created channel to port X4QX93K5 at peer P(6SMN) for Client(1) using Tunnel 6SMN
Feb 18 18:05:54-081072 cadet-tun-21550 DEBUG Performing connection maintenance for Tunnel 6SMN.
Feb 18 18:05:54-081104 cadet-per-21550 DEBUG Iterating over paths to peer P(6SMN) including direct link
Feb 18 18:05:54-081128 cadet-per-21550 DEBUG Asked to look for paths at distance 0, but maximum for me is < 0
Feb 18 18:05:54-081157 cadet-per-21550 DEBUG Discovered that peer P(6SMN) is on path 6SMN(0x206dad0) at offset 0
Feb 18 18:05:54-081199 cadet-con-21550 DEBUG Creating Connection W4DHGD (Tunnel 6SMN) using path 6SMN(0x206dad0)
Feb 18 18:05:54-081227 cadet-pat-21550 DEBUG Adding connection Connection W4DHGD (Tunnel 6SMN) to path 6SMN(0x206dad0) at offset 0
Feb 18 18:05:54-081251 cadet-per-21550 DEBUG Creating MQM 0x2085f40 for peer P(6SMN)
Feb 18 18:05:54-081277 cadet-con-21550 DEBUG Core MQ for Connection W4DHGD (Tunnel 6SMN) became available in state 0
Feb 18 18:05:54-081307 cadet-tun-21550 DEBUG Found interesting path 6SMN(0x206dad0) for Tunnel 6SMN, created Connection W4DHGD (Tunnel 6SMN)
Feb 18 18:05:54-081333 cadet-pat-21550 DEBUG Created new path 6SMN(0x206dad0) to create inverse for incoming connection
Feb 18 18:05:54-081358 cadet-per-21550 DEBUG Attaching path 6SMN(0x206dad0) to peer P(6SMN) (forced)
Feb 18 18:05:54-081385 cadet-tun-21550 DEBUG Ignoring duplicate path 6SMN(0x206dad0).
Feb 18 18:05:54-081407 cadet-tun-21550 DEBUG Ignoring duplicate path 6SMN(0x206dad0).
Feb 18 18:05:54-081446 cadet-con-21550 DEBUG Sending CADET_CONNECTION_CREATE message for Connection W4DHGD (Tunnel 6SMN)
Feb 18 18:05:54-081471 cadet-per-21550 DEBUG Queueing message to peer P(6SMN) in MQM 0x2085f40
Feb 18 18:05:54-081497 cadet-per-21550 DEBUG Sending to peer P(6SMN) from MQM 0x2085f40
Feb 18 18:05:54-081553 cadet-con-21550 DEBUG Core MQ for Connection W4DHGD (Tunnel 6SMN) became available in state 2
Feb 18 18:05:54-083696 cadet-con-21550 DEBUG Sending CADET_CONNECTION_CREATE message for Connection W4DHGD (Tunnel 6SMN)
Feb 18 18:05:54-083735 cadet-per-21550 DEBUG Queueing message to peer P(6SMN) in MQM 0x2085f40
Feb 18 18:05:56-055879 cadet-cor-21550 DEBUG Received CADET_CONNECTION_CREATE message from P(6SMN) for connection M1AG3J, building inverse path
Feb 18 18:05:56-055991 cadet-pat-21550 DEBUG check_match found match with path 6SMN(0x206dad0)
Feb 18 18:05:56-056035 cadet-pat-21550 DEBUG Returning existing path 6SMN(0x206dad0) as inverse for incoming connection
Feb 18 18:05:56-056089 cadet-con-21550 DEBUG Got two connections on 6SMN(0x206dad0), keeping my existing Connection W4DHGD (Tunnel 6SMN)
Feb 18 18:05:56-056130 cadet-tun-21550 DEBUG Tunnel 6SMN refused inbound Connection(NULL) (duplicate)
Feb 18 18:05:56-056174 cadet-cor-21550 DEBUG Received CADET_CONNECTION_CREATE from P(6SMN) for M1AG3J, but 6SMN(0x206dad0) already has a connection. Sending BROKEN
Feb 18 18:05:56-056216 cadet-per-21550 DEBUG Sending message to P(6SMN) out of management
Feb 18 18:05:56-056708 cadet-cor-21550 DEBUG Received CADET_CONNECTION_CREATE message from P(6SMN) for connection M1AG3J, building inverse path
Feb 18 18:05:56-056795 cadet-pat-21550 DEBUG check_match found match with path 6SMN(0x206dad0)
Feb 18 18:05:56-056820 cadet-pat-21550 DEBUG Returning existing path 6SMN(0x206dad0) as inverse for incoming connection
Feb 18 18:05:56-056849 cadet-con-21550 DEBUG Got two connections on 6SMN(0x206dad0), keeping my existing Connection W4DHGD (Tunnel 6SMN)
Feb 18 18:05:56-056872 cadet-tun-21550 DEBUG Tunnel 6SMN refused inbound Connection(NULL) (duplicate)
Feb 18 18:05:56-056896 cadet-cor-21550 DEBUG Received CADET_CONNECTION_CREATE from P(6SMN) for M1AG3J, but 6SMN(0x206dad0) already has a connection. Sending BROKEN
Feb 18 18:05:56-056919 cadet-per-21550 DEBUG Sending message to P(6SMN) out of management
Feb 18 18:05:56-059367 cadet-cor-21550 DEBUG Received CADET_CONNECTION_CREATE message from P(6SMN) for connection M1AG3J, building inverse path
Feb 18 18:05:56-059406 cadet-pat-21550 DEBUG check_match found match with path 6SMN(0x206dad0)
Feb 18 18:05:56-059429 cadet-pat-21550 DEBUG Returning existing path 6SMN(0x206dad0) as inverse for incoming connection
Feb 18 18:05:56-059456 cadet-con-21550 DEBUG Got two connections on 6SMN(0x206dad0), keeping my existing Connection W4DHGD (Tunnel 6SMN)
Feb 18 18:05:56-059478 cadet-tun-21550 DEBUG Tunnel 6SMN refused inbound Connection(NULL) (duplicate)
Feb 18 18:05:56-059501 cadet-cor-21550 DEBUG Received CADET_CONNECTION_CREATE from P(6SMN) for M1AG3J, but 6SMN(0x206dad0) already has a connection. Sending BROKEN
Feb 18 18:05:56-059523 cadet-per-21550 DEBUG Sending message to P(6SMN) out of management
Feb 18 18:05:56-071197 cadet-cor-21550 DEBUG Received CADET_CONNECTION_CREATE message from P(6SMN) for connection M1AG3J, building inverse path
Feb 18 18:05:56-071235 cadet-pat-21550 DEBUG check_match found match with path 6SMN(0x206dad0)
Feb 18 18:05:56-071258 cadet-pat-21550 DEBUG Returning existing path 6SMN(0x206dad0) as inverse for incoming connection
Feb 18 18:05:56-071284 cadet-con-21550 DEBUG Got two connections on 6SMN(0x206dad0), keeping my existing Connection W4DHGD (Tunnel 6SMN)
Feb 18 18:05:56-071306 cadet-tun-21550 DEBUG Tunnel 6SMN refused inbound Connection(NULL) (duplicate)
Feb 18 18:05:56-071329 cadet-cor-21550 DEBUG Received CADET_CONNECTION_CREATE from P(6SMN) for M1AG3J, but 6SMN(0x206dad0) already has a connection. Sending BROKEN
Feb 18 18:05:56-071351 cadet-per-21550 DEBUG Sending message to P(6SMN) out of management
Feb 18 18:05:56-081773 cadet-cor-21550 DEBUG Received CADET_CONNECTION_CREATE message from P(6SMN) for connection M1AG3J, building inverse path
Feb 18 18:05:56-081811 cadet-pat-21550 DEBUG check_match found match with path 6SMN(0x206dad0)
Feb 18 18:05:56-081835 cadet-pat-21550 DEBUG Returning existing path 6SMN(0x206dad0) as inverse for incoming connection
Feb 18 18:05:56-081886 cadet-con-21550 DEBUG Got two connections on 6SMN(0x206dad0), keeping my existing Connection W4DHGD (Tunnel 6SMN)
Feb 18 18:05:56-081942 cadet-tun-21550 DEBUG Tunnel 6SMN refused inbound Connection(NULL) (duplicate)
Feb 18 18:05:56-081965 cadet-cor-21550 DEBUG Received CADET_CONNECTION_CREATE from P(6SMN) for M1AG3J, but 6SMN(0x206dad0) already has a connection. Sending BROKEN
Feb 18 18:05:56-081987 cadet-per-21550 DEBUG Sending message to P(6SMN) out of management
Feb 18 18:05:56-119989 cadet-cor-21550 DEBUG Received CADET_CONNECTION_CREATE message from P(6SMN) for connection M1AG3J, building inverse path
Feb 18 18:05:56-120058 cadet-pat-21550 DEBUG check_match found match with path 6SMN(0x206dad0)
Feb 18 18:05:56-120082 cadet-pat-21550 DEBUG Returning existing path 6SMN(0x206dad0) as inverse for incoming connection
Feb 18 18:05:56-120111 cadet-con-21550 DEBUG Got two connections on 6SMN(0x206dad0), keeping my existing Connection W4DHGD (Tunnel 6SMN)
Feb 18 18:05:56-120133 cadet-tun-21550 DEBUG Tunnel 6SMN refused inbound Connection(NULL) (duplicate)
Feb 18 18:05:56-120157 cadet-cor-21550 DEBUG Received CADET_CONNECTION_CREATE from P(6SMN) for M1AG3J, but 6SMN(0x206dad0) already has a connection. Sending BROKEN
Feb 18 18:05:56-120179 cadet-per-21550 DEBUG Sending message to P(6SMN) out of management
Feb 18 18:05:56-147563 core-21554 WARNING Client waited 3078 ms for permission to transmit to `6SMN' (priority 1)
Feb 18 18:05:56-147925 cadet-per-21550 DEBUG Sending to peer P(6SMN) completed
Feb 18 18:05:56-147978 cadet-per-21550 DEBUG Sending to peer P(6SMN) from MQM 0x2085f40
Feb 18 18:05:56-148021 cadet-con-21550 DEBUG Core MQ for Connection W4DHGD (Tunnel 6SMN) became available in state 2
Feb 18 18:05:56-149687 core-21554 WARNING Client waited 3080 ms for transmission of 348 bytes to `6SMN' (uncorked)
Feb 18 18:05:56-152176 cadet-con-21550 DEBUG Sending CADET_CONNECTION_CREATE message for Connection W4DHGD (Tunnel 6SMN)
Feb 18 18:05:56-152234 cadet-per-21550 DEBUG Queueing message to peer P(6SMN) in MQM 0x2085f40
Feb 18 18:05:56-159404 cadet-per-21550 DEBUG Sending to peer P(6SMN) completed
Feb 18 18:05:56-159461 cadet-per-21550 DEBUG Sending to peer P(6SMN) from MQM 0x2085f40
Feb 18 18:05:56-159502 cadet-con-21550 DEBUG Core MQ for Connection W4DHGD (Tunnel 6SMN) became available in state 2
Feb 18 18:05:56-160942 cadet-per-21550 DEBUG Sending to peer P(6SMN) completed
Feb 18 18:05:56-167690 cadet-con-21550 DEBUG Sending CADET_CONNECTION_CREATE message for Connection W4DHGD (Tunnel 6SMN)
Feb 18 18:05:56-167755 cadet-per-21550 DEBUG Queueing message to peer P(6SMN) in MQM 0x2085f40
Feb 18 18:05:56-167794 cadet-per-21550 DEBUG Sending to peer P(6SMN) from MQM 0x2085f40
Feb 18 18:05:56-167839 cadet-con-21550 DEBUG Core MQ for Connection W4DHGD (Tunnel 6SMN) became available in state 2
Feb 18 18:05:56-168099 cadet-per-21550 DEBUG Sending to peer P(6SMN) completed
Feb 18 18:05:56-176314 cadet-cor-21550 DEBUG Received CONNECTION_DESTROY for connection M1AG3J. Destroying route.
Feb 18 18:05:56-176387 cadet-cor-21550 DEBUG Failed to route message of type 1003 from P(6SMN) on connection M1AG3J: no route
Feb 18 18:05:56-184027 cadet-con-21550 DEBUG Sending CADET_CONNECTION_CREATE message for Connection W4DHGD (Tunnel 6SMN)
Feb 18 18:05:56-184072 cadet-per-21550 DEBUG Queueing message to peer P(6SMN) in MQM 0x2085f40
Feb 18 18:05:56-184096 cadet-per-21550 DEBUG Sending to peer P(6SMN) from MQM 0x2085f40
Feb 18 18:05:56-184123 cadet-con-21550 DEBUG Core MQ for Connection W4DHGD (Tunnel 6SMN) became available in state 2
Feb 18 18:05:56-184280 cadet-per-21550 DEBUG Sending to peer P(6SMN) completed
Feb 18 18:05:56-216276 cadet-con-21550 DEBUG Sending CADET_CONNECTION_CREATE message for Connection W4DHGD (Tunnel 6SMN)
Feb 18 18:05:56-216312 cadet-per-21550 DEBUG Queueing message to peer P(6SMN) in MQM 0x2085f40
Feb 18 18:05:56-216335 cadet-per-21550 DEBUG Sending to peer P(6SMN) from MQM 0x2085f40
Feb 18 18:05:56-216361 cadet-con-21550 DEBUG Core MQ for Connection W4DHGD (Tunnel 6SMN) became available in state 2
Feb 18 18:05:56-216539 cadet-per-21550 DEBUG Sending to peer P(6SMN) completed
Feb 18 18:05:56-280536 cadet-con-21550 DEBUG Sending CADET_CONNECTION_CREATE message for Connection W4DHGD (Tunnel 6SMN)
Feb 18 18:05:56-280581 cadet-per-21550 DEBUG Queueing message to peer P(6SMN) in MQM 0x2085f40
Feb 18 18:05:56-280604 cadet-per-21550 DEBUG Sending to peer P(6SMN) from MQM 0x2085f40
Feb 18 18:05:56-280630 cadet-con-21550 DEBUG Core MQ for Connection W4DHGD (Tunnel 6SMN) became available in state 2
Feb 18 18:05:56-280797 cadet-per-21550 DEBUG Sending to peer P(6SMN) completed
Feb 18 18:05:56-408865 cadet-con-21550 DEBUG Sending CADET_CONNECTION_CREATE message for Connection W4DHGD (Tunnel 6SMN)
Feb 18 18:05:56-408908 cadet-per-21550 DEBUG Queueing message to peer P(6SMN) in MQM 0x2085f40
Feb 18 18:05:56-408932 cadet-per-21550 DEBUG Sending to peer P(6SMN) from MQM 0x2085f40
Feb 18 18:05:56-408958 cadet-con-21550 DEBUG Core MQ for Connection W4DHGD (Tunnel 6SMN) became available in state 2
Feb 18 18:05:56-409120 cadet-per-21550 DEBUG Sending to peer P(6SMN) completed
Feb 18 18:05:56-665387 cadet-con-21550 DEBUG Sending CADET_CONNECTION_CREATE message for Connection W4DHGD (Tunnel 6SMN)
Feb 18 18:05:56-665496 cadet-per-21550 DEBUG Queueing message to peer P(6SMN) in MQM 0x2085f40
Feb 18 18:05:56-665536 cadet-per-21550 DEBUG Sending to peer P(6SMN) from MQM 0x2085f40
Feb 18 18:05:56-665584 cadet-con-21550 DEBUG Core MQ for Connection W4DHGD (Tunnel 6SMN) became available in state 2
Feb 18 18:05:56-665951 cadet-per-21550 DEBUG Sending to peer P(6SMN) completed
Feb 18 18:05:57-178294 cadet-con-21550 DEBUG Sending CADET_CONNECTION_CREATE message for Connection W4DHGD (Tunnel 6SMN)
Feb 18 18:05:57-178413 cadet-per-21550 DEBUG Queueing message to peer P(6SMN) in MQM 0x2085f40
Feb 18 18:05:57-178456 cadet-per-21550 DEBUG Sending to peer P(6SMN) from MQM 0x2085f40
Feb 18 18:05:57-178505 cadet-con-21550 DEBUG Core MQ for Connection W4DHGD (Tunnel 6SMN) became available in state 2
Feb 18 18:05:57-178825 cadet-per-21550 DEBUG Sending to peer P(6SMN) completed
Feb 18 18:05:58-203689 cadet-con-21550 DEBUG Sending CADET_CONNECTION_CREATE message for Connection W4DHGD (Tunnel 6SMN)
Feb 18 18:05:58-203787 cadet-per-21550 DEBUG Queueing message to peer P(6SMN) in MQM 0x2085f40
Feb 18 18:05:58-203820 cadet-per-21550 DEBUG Sending to peer P(6SMN) from MQM 0x2085f40
Feb 18 18:05:58-203859 cadet-con-21550 DEBUG Core MQ for Connection W4DHGD (Tunnel 6SMN) became available in state 2
Feb 18 18:05:58-204238 cadet-per-21550 DEBUG Sending to peer P(6SMN) completed
Feb 18 18:06:00-254069 cadet-con-21550 DEBUG Sending CADET_CONNECTION_CREATE message for Connection W4DHGD (Tunnel 6SMN)
Feb 18 18:06:00-254168 cadet-per-21550 DEBUG Queueing message to peer P(6SMN) in MQM 0x2085f40
Feb 18 18:06:00-254195 cadet-per-21550 DEBUG Sending to peer P(6SMN) from MQM 0x2085f40
Feb 18 18:06:00-254228 cadet-con-21550 DEBUG Core MQ for Connection W4DHGD (Tunnel 6SMN) became available in state 2
Feb 18 18:06:00-254481 cadet-per-21550 DEBUG Sending to peer P(6SMN) completed
Feb 18 18:06:04-354052 cadet-con-21550 DEBUG Sending CADET_CONNECTION_CREATE message for Connection W4DHGD (Tunnel 6SMN)
Feb 18 18:06:04-354174 cadet-per-21550 DEBUG Queueing message to peer P(6SMN) in MQM 0x2085f40
Feb 18 18:06:04-354217 cadet-per-21550 DEBUG Sending to peer P(6SMN) from MQM 0x2085f40
Feb 18 18:06:04-354270 cadet-con-21550 DEBUG Core MQ for Connection W4DHGD (Tunnel 6SMN) became available in state 2
Feb 18 18:06:04-354651 cadet-per-21550 DEBUG Sending to peer P(6SMN) completed
Feb 18 18:06:12-554654 cadet-con-21550 DEBUG Sending CADET_CONNECTION_CREATE message for Connection W4DHGD (Tunnel 6SMN)
Feb 18 18:06:12-554776 cadet-per-21550 DEBUG Queueing message to peer P(6SMN) in MQM 0x2085f40
Feb 18 18:06:12-554816 cadet-per-21550 DEBUG Sending to peer P(6SMN) from MQM 0x2085f40
Feb 18 18:06:12-554864 cadet-con-21550 DEBUG Core MQ for Connection W4DHGD (Tunnel 6SMN) became available in state 2
Feb 18 18:06:12-555185 cadet-per-21550 DEBUG Sending to peer P(6SMN) completed
Feb 18 18:06:28-955401 cadet-con-21550 DEBUG Sending CADET_CONNECTION_CREATE message for Connection W4DHGD (Tunnel 6SMN)
Feb 18 18:06:28-955469 cadet-per-21550 DEBUG Queueing message to peer P(6SMN) in MQM 0x2085f40
Feb 18 18:06:28-955496 cadet-per-21550 DEBUG Sending to peer P(6SMN) from MQM 0x2085f40
Feb 18 18:06:28-955528 cadet-con-21550 DEBUG Core MQ for Connection W4DHGD (Tunnel 6SMN) became available in state 2
Feb 18 18:06:28-955757 cadet-per-21550 DEBUG Sending to peer P(6SMN) completed
20160218.listening.txt (16,914 bytes)   

Christian Grothoff

2017-02-18 19:04

manager   ~0011782

Ok, that indeed doesn't look right. Looking into it.

Christian Grothoff

2017-02-18 20:05

manager   ~0011783

2beedf90f..6f8fabef0 should fix it!

lurchi

2017-02-18 21:53

developer   ~0011784

yes, seems to be fixed. Much more stable now.

Issue History

Date Modified Username Field Change
2017-02-16 16:01 lurchi New Issue
2017-02-16 16:01 lurchi Status new => assigned
2017-02-16 16:01 lurchi Assigned To => Christian Grothoff
2017-02-16 16:01 lurchi File Added: 20160216.txt
2017-02-16 21:00 Christian Grothoff Note Added: 0011768
2017-02-16 21:01 Christian Grothoff Status assigned => feedback
2017-02-16 21:01 Christian Grothoff Target Version => 0.11.0pre66
2017-02-17 01:38 lurchi File Added: 20160217.txt
2017-02-17 01:38 lurchi Note Added: 0011770
2017-02-17 01:38 lurchi Status feedback => assigned
2017-02-17 01:38 lurchi Note Edited: 0011770
2017-02-17 01:39 lurchi Note Edited: 0011770
2017-02-17 01:39 Christian Grothoff Note Added: 0011771
2017-02-17 14:50 Christian Grothoff Status assigned => feedback
2017-02-17 21:27 lurchi Note Added: 0011773
2017-02-17 21:27 lurchi Status feedback => assigned
2017-02-17 21:34 Christian Grothoff Note Added: 0011774
2017-02-17 21:53 lurchi Note Added: 0011775
2017-02-18 18:18 lurchi File Added: 20160218.connecting.txt
2017-02-18 18:18 lurchi Note Added: 0011780
2017-02-18 18:19 lurchi File Added: 20160218.listening.txt
2017-02-18 18:19 lurchi Note Added: 0011781
2017-02-18 18:21 lurchi Note Edited: 0011780
2017-02-18 19:04 Christian Grothoff Note Added: 0011782
2017-02-18 20:05 Christian Grothoff Note Added: 0011783
2017-02-18 20:05 Christian Grothoff Status assigned => feedback
2017-02-18 21:53 lurchi Note Added: 0011784
2017-02-18 21:53 lurchi Status feedback => assigned
2017-02-18 22:11 lurchi Status assigned => resolved
2017-02-18 22:11 lurchi Resolution open => fixed
2017-02-19 00:09 Christian Grothoff Fixed in Version => 0.11.0pre66
2018-06-07 00:24 Christian Grothoff Status resolved => closed