orignal
can you check what happened on your side after
orignal
18:07:21@566/debug - SSU2: HolePunch
orignal
because I receive SSU2: Unexpected message type 48 from [2a02:180:2:92:92:92:11:15]:16799
orignal
it seems SessionCreated but with wrong connid
orignal
are you sure you use one from SessionRequest?
orignal
get session created just now
zzz
here's the log from last night
zzz
I got both a relay request and a peer test at the same time
zzz
did the peer test and also sent a session created 3 times
zzz
never got session confirmed
zzz
06-30 00:07:21.789 INFO [ handler 1/1] nsport.udp.IntroductionManager: Send relay response 0 as charlie nonce 2044178236 to bob [2a05:4800:3:161:0:0:10:c]:11916 PeGQYG OB2 recvAge: 118s sendAge: 118s sendAttemptAge: 118s sendACKAge: 0ms lifetime: 31m RTT: 51 RTO: 1000 MTU: 1500 LMTU: 1500 cwin: 11625 acwin: 11625 SST: 2560 FRTX? false consecFail: 0 msgs rcvd: 1 msgs sent: 91 pkts rcvd OK/Dup: 97/0 pkts sent OK/Dup:
zzz
94/2 IBM: 0 OBQ: 0 OBL: 0 theyRelayToUsAs: 1439403143 with token -7221458421066406938 for alice [2001:470:1f06:405:0:0:0:2]:29948 [RouterInfo:
zzz
06-30 00:07:21.792 DEBUG [ handler 1/1] .transport.udp.PeerTestManager: Got peer test msg: 2 status: 0 hash: [Hash: cdoFbNTTgmjfUlL6M8BYQTGdq2QxGsAa7xkX5xnfW4o=] nonce: 143660527 time: Jun 30, 2022, 12:07 AM ip/port: [2001:470:1f06:405:0:0:0:2]:29948 from [2a05:4800:3:161:0:0:10:c]:11916 PeGQYG OB2 recvAge: 118s sendAge: 118s sendAttemptAge: 118s sendACKAge: 4ms lifetime: 31m RTT: 51 RTO: 1000 MTU: 1500 LMTU: 1500
zzz
cwin: 11625 acwin: 11625 SST: 2560 FRTX? false consecFail: 0 msgs rcvd: 1 msgs sent: 91 pkts rcvd OK/Dup: 98/0 pkts sent OK/Dup: 94/2 IBM: 0 OBQ: 0 OBL: 0 theyRelayToUsAs: 1439403143 state: null
zzz
06-30 00:07:21.793 DEBUG [ handler 1/1] .transport.udp.PeerTestManager: Send msg 3 response 0 nonce 143660527 to [2a05:4800:3:161:0:0:10:c]:11916 PeGQYG OB2 recvAge: 118s sendAge: 118s sendAttemptAge: 118s sendACKAge: 0ms lifetime: 31m RTT: 51 RTO: 1000 MTU: 1500 LMTU: 1500 cwin: 11625 acwin: 11625 SST: 2560 FRTX? false consecFail: 0 msgs rcvd: 1 msgs sent: 91 pkts rcvd OK/Dup: 98/0 pkts sent OK/Dup: 94/2 IBM: 0 OBQ:
zzz
0 OBL: 0 theyRelayToUsAs: 1439403143
zzz
06-30 00:07:21.793 DEBUG [ handler 1/1] .transport.udp.PeerTestManager: Send msg 5 to [2001:470:1f06:405:0:0:0:2]:29948 on PeerTest 143660527 IPv6 started Jun 30, 2022, 12:07 AM as CHARLIE; Alice: /2001:470:1f06:405:0:0:0:2:29948; Bob: [2a05:4800:3:161:0:0:10:c]:11916 PeGQYG OB2 recvAge: 118s sendAge: 118s sendAttemptAge: 118s sendACKAge: 0ms lifetime: 31m RTT: 51 RTO: 1000 MTU: 1500 LMTU: 1500 cwin: 11625 acwin:
zzz
11625 SST: 2560 FRTX? false consecFail: 0 msgs rcvd: 1 msgs sent: 91 pkts rcvd OK/Dup: 98/0 pkts sent OK/Dup: 94/2 IBM: 0 OBQ: 0 OBL: 0 theyRelayToUsAs: 1439403143; last send after 0; rcvd from Bob after 0; pkts relayed: 0
zzz
06-30 00:07:21.916 DEBUG [ handler 1/1] ort.udp.InboundEstablishState2: Processed 2 blocks on IES2 [2001:470:1f06:405:0:0:0:2]:29948 lifetime: 1ms Rcv ID: -835374891610634213 Send ID: 8190773521802199110 IB_STATE_UNKNOWN
zzz
06-30 00:07:21.916 DEBUG [ handler 1/1] ort.udp.InboundEstablishState2: New IES2 [2001:470:1f06:405:0:0:0:2]:29948 lifetime: 1ms Rcv ID: -835374891610634213 Send ID: 8190773521802199110 IB_STATE_REQUEST_RECEIVED
zzz
06-30 00:07:24.916 INFO [ Establisher] sport.udp.EstablishmentManager: Retransmit created to: IES2 [2001:470:1f06:405:0:0:0:2]:29948 lifetime: 3001ms Rcv ID: -835374891610634213 Send ID: 8190773521802199110 IB_STATE_CREATED_SENT
zzz
06-30 00:07:30.916 INFO [ Establisher] sport.udp.EstablishmentManager: Retransmit created to: IES2 [2001:470:1f06:405:0:0:0:2]:29948 lifetime: 9s Rcv ID: -835374891610634213 Send ID: 8190773521802199110 IB_STATE_CREATED_SENT
zzz
06-30 00:07:37.787 WARN [ Establisher] sport.udp.EstablishmentManager: Expired: IES2 [2001:470:1f06:405:0:0:0:2]:29948 lifetime: 15s Rcv ID: -835374891610634213 Send ID: 8190773521802199110 IB_STATE_CREATED_SENT
zzz
why are you doing a relay and a peer test at the same time?
orignal
why not?
orignal
I try connect to you when do peer test
orignal
yes, I see the problem now with session confirmed
zzz
the relaying will interfere with the peer test if it's happening at the same time
orignal
yes, I know
zzz
so that's why not :)
orignal
just want to test how two pending request work
orignal
the behaviour should be
orignal
peer test must be sent after session etablished
orignal
but let me fix
orignal
the problen is I shouldn't start peer test until I connected
zzz
here's the one from a few minutes ago
zzz
I never got an ack for a message I sent
zzz
06-30 14:01:51.295 DEBUG [ handler 1/1] ort.udp.InboundEstablishState2: Processed 2 blocks on IES2 [2001:470:1f06:405:0:0:0:2]:29948 lifetime: 139ms Rcv ID: -5008676941444568139 Send ID: 3733711688664186856 IB_STATE_CREATED_SENT
zzz
06-30 14:01:58.296 INFO [acket pusher] outer.transport.udp.PeerState2: [Hash: cdoFbNTTgmjfUlL6M8BYQTGdq2QxGsAa7xkX5xnfW4o=] Congestion, RTO: 4000 -> 8000 timer: 0 -> 8000 window: 1500 -> 1500 SST: 2560 -> 2560 FRTX? false BWE: 0 bps
zzz
06-30 14:02:01.464 WARN [acket pusher] outer.transport.udp.PeerState2: Unable to send a direct message: OB Message 1933671367 seq 0 type 1 size 1439 fragments: 2 volleys: 4 lifetime: 10169 unacked fragments: 0 1 sizes: 1197 242 send counts: 4 4 to: [2001:470:1f06:405:0:0:0:2]:29948 cdoFbN IB2 recvAge: 10s sendAge: 52y sendAttemptAge: 3168ms sendACKAge: 3168ms lifetime: 10s RTT: 138 RTO: 8000 MTU: 1280 LMTU: 1500
zzz
cwin: 1500 acwin: 2225 SST: 2560 FRTX? false consecFail: 0 msgs rcvd: 0 msgs sent: 1 pkts rcvd OK/Dup: 0/0 pkts sent OK/Dup: 8/6 IBM: 0 OBQ: 0 OBL: 0
zzz
two fragments, sent 4x each
orignal
few minutes ago?
zzz
yes
orignal
but my that router is down
orignal
or your are talking about something else
zzz
<orignal> get session created just now
zzz
52 minutes ago
orignal
yes, but it's not :few minutes"
zzz
ok, more than a few
zzz
please check what happened to that message
orignal
I couldn't decrypt
orignal
and found out why
orignal
let me try again
zzz
ok
orignal
any updates about fragments?
orignal
SSU2: RelayResponse status code=5
orignal
pity
orignal
⇒ -Akx: [2a02:180:2:92:92:92:11:15] [1089:1489]
orignal
voila
orignal
please check your side ))
zzz
yeah looks good, stayed up until idle timeout
zzz
06-30 14:59:49.611 DEBUG [ handler 1/1] ort.udp.InboundEstablishState2: Processed 2 blocks on IES2 [2001:470:1f06:405:0:0:0:2]:29948 lifetime: 137ms Rcv ID: 7560331333805291470 Send ID: 6455132438280272364 IB_STATE_CREATED_SENT
zzz
06-30 15:02:35.117 WARN [leTimer2 1/4] r.transport.udp.PacketBuilder2: Sending termination 2 to : [2001:470:1f06:405:0:0:0:2]:29948 cdoFbN IB2 recvAge: 165s sendAge: 165s sendAttemptAge: 165s sendACKAge: 165s lifetime: 165s RTT: 136 RTO: 1000 MTU: 1408 LMTU: 1500 cwin: 5282 acwin: 5282 SST: 524288 FRTX? false consecFail: 0 msgs rcvd: 1 msgs sent: 1 pkts rcvd OK/Dup: 3/0 pkts sent OK/Dup: 2/0 IBM: 0 OBQ: 0 OBL: 0
zzz
got 3 packets, sent 2 in data phase
orignal
finally
zzz
now let me look for fragments
orignal
so the last test is peer test
zzz
as of about 6 PM last night I hadn't gotten any
orignal
I want to send msg 1 once connection is estblished
orignal
let's wait more
zzz
In the last 24 hours I've received > 1000 fragments on one router, > 2000 on another router, I don't see any from i2pd
orignal
but do you see incomplete messages?
zzz
the only one I ever got was the one with the bad length yesterday
orignal
i2pd uses SSU2 rarely that's why
orignal
it perefers NTCP2
zzz
I log every follow-on fragment block I get, whether complete or not
orignal
uses SSU2 only if a session already
zzz
that's why one of my routers is ssu 1/2 only
orignal
you log floow-on fragments but they question is if you are even supposed to receive them
zzz
I suggest you do that too so we can get everything tested better
zzz
huh?
orignal
if you see peer tests only from i2pd it's hard to expext fragments
zzz
why?
orignal
because usually i2pd sends peer tests only
orignal
and terminates a session quicly
orignal
SSU2 has lst priority
orignal
and rarely chosen for tunnel
orignal
yes, I will try ssu only
zzz
all I know is I'm handling several thousand SSU2 messages a day java-to-java on the live net and I've speed tested it on the testnet to a few MB/sec. Java-to-i2pd is not getting that amount of testing
orignal
because SSU has higher priority
orignal
but I will try tio change
orignal
finally
orignal
I have changed the priority
orignal
SSU2 has higher priority than SSU now
orignal
should be more SSU2 connection
zzz
great, please ask everybody to update
orignal
R4SAS did it already
zzz
ok
orignal
but let me run for a day to make sure no severe creation rate degrdation etc.
orignal
and I keep connecting to you
orignal
at least from my router
zzz
lot of trouble with i2pd router I haven't seen before, ~GIB. lots of delays and lost packets. I got an ack for a packet I sent 1 minute 9 seconds before