orignal
basically what ack do you receive and what number do you restrans
orignal
the main question is
orignal
if you recive an Ack with still missing message after retransimmion or receive nothing
orignal
if will help me to understand the problem
zzz
seems to be inbound connections right after handshake
zzz
I'm not logging acks
zzz
07-07 00:42:24.198 DEBUG [ handler 1/1] ort.udp.InboundEstablishState2: New IES2 193.38.54.107:15110 lifetime: 1ms Rcv ID: 8293077990559914232 Send ID: -3482812418673117245 IB_STATE_REQUEST_RECEIVED
zzz
07-07 00:42:24.223 DEBUG [ handler 1/1] ort.udp.InboundEstablishState2: Processed 2 blocks on IES2 193.38.54.107:15110 lifetime: 26ms Rcv ID: 8293077990559914232 Send ID: -3482812418673117245 IB_STATE_CREATED_SENT
zzz
07-07 00:43:29.243 INFO [acket pusher] outer.transport.udp.PeerState2: [Hash: 2RRYXk4DLmwmsCwDaFcN1u88XPStZiIAi3eNGFMGyJI=] Congestion, RTO: 1000 -> 2000 timer: -9 -> 2000 window: 3909 -> 1500 SST: 524288 -> 2688 FRTX? false BWE: 44 bps
zzz
07-07 00:43:31.243 INFO [acket pusher] outer.transport.udp.PeerState2: [Hash: 2RRYXk4DLmwmsCwDaFcN1u88XPStZiIAi3eNGFMGyJI=] Congestion, RTO: 2000 -> 4000 timer: 0 -> 4000 window: 1500 -> 1500 SST: 2688 -> 2560 FRTX? false BWE: 30 bps
zzz
07-07 00:43:35.243 INFO [acket pusher] outer.transport.udp.PeerState2: [Hash: 2RRYXk4DLmwmsCwDaFcN1u88XPStZiIAi3eNGFMGyJI=] Congestion, RTO: 4000 -> 8000 timer: 0 -> 8000 window: 1500 -> 1500 SST: 2560 -> 2560 FRTX? false BWE: 13 bps
zzz
07-07 00:43:38.255 WARN [acket pusher] outer.transport.udp.PeerState2: Message expired: OB Message 3871723709 seq 1 type 19 size 87 volleys: 4 lifetime: 10021 unacked to: 193.38.54.107:15110 2RRYXk IB2 recvAge: 74s sendAge: 74s sendAttemptAge: 3012ms sendACKAge: 3012ms lifetime: 74s RTT: 24 RTO: 8000 MTU: 1280 LMTU: 1500 cwin: 1500 acwin: 2542 SST: 2560 FRTX? false consecFail: 1 msgs rcvd: 0 msgs sent: 2 pkts rcvd
zzz
OK/Dup: 1/0 pkts sent OK/Dup: 5/3 IBM: 0 OBQ: 0 OBL: 0
orignal
inbound to whom?
orignal
to you ?
orignal
if it's right after handshake it's not an ack problem
zzz
yeah, and I'm firewalled ofc. So this is after a relay?
zzz
no wait, it's not, this is ipv4
zzz
I'm not firewalled on v4
orignal
so, I send SessionConfirmed, then you send Ack
zzz
so basically I'm not getting any acks for things I send to i2pd after the handshake
orignal
I recieve Ack and assume sessiion established
zzz
for inbound connections
zzz
I think????
orignal
what happens after your Ack?
orignal
what do you send right after handshake?
zzz
not sure. you send me something. I ack it
zzz
then later, I send you something, it's never acked, I retransmit it 3x and give up
orignal
no no
orignal
I send SessionConfirmed, you Ack
zzz
right
orignal
then I send somemthing else
orignal
because that's what I create this session for
zzz
right
orignal
but what do you send from your side?
orignal
beside acks
zzz
one minute later, I send you somethign
zzz
type 19 size 87
zzz
and retx, and retx, and retx
orignal
so before you sent ack only
orignal
and when you send first message I don't ack it
zzz
I think?
orignal
how it looks from your side
zzz
thats all I know so far
orignal
do I keep sending data?
orignal
I'm trying to understand if you even receive acks from me
orignal
either you don't receive them at all or they just wrong
orignal
what is the packet num for your that message? 0 or 1?
zzz
I didn't get anything more
zzz
I sent a termination 3 minutes later
zzz
07-07 00:46:20.331 WARN [leTimer2 2/4] r.transport.udp.PacketBuilder2: Sending termination 2 to : 193.38.54.107:15110 2RRYXk IB2 recvAge: 3m sendAge: 3m sendAttemptAge: 165s sendACKAge: 165s lifetime: 3m RTT: 24 RTO: 8000 MTU: 1280 LMTU: 1500 cwin: 1500 acwin: 1500 SST: 2560 FRTX? false consecFail: 1 msgs rcvd: 0 msgs sent: 2 pkts rcvd OK/Dup: 1/0 pkts sent OK/Dup: 5/3 IBM: 0 OBQ: 0 OBL: 0
orignal
ok. you keep sending message and nothing back from me
zzz
not sure what packet num
orignal
what packet num do you start with?
zzz
would have been several since I sent it 4x
orignal
but you said you don't recieve ack for very first message
zzz
I don't have that logged
zzz
sure but I could have been sending you acks before that
zzz
I;m not logging the lowest level stuff right now
zzz
all I know is I'm sending a msg 4x and never getting it acked
orignal
does it happen with every incoming connection from i2pd or sometimes it works?
zzz
don't know
orignal
and ofc the second question whan happens if I keep sending data
orignal
e.g. this connection if part of a tunnel
orignal
anyway it's enough for me to start looking
orignal
another issue, I receive peer code 65 from Java Charlie too ofter
orignal
why is it?
zzz
don't know
zzz
sorry that's all the info I have right now, I'll tweak the logging and try to get you more info tomorrow
zzz
:)
orignal
65 seems really strange
orignal
SSU2: Peer test 4 error code 65 from PeGQ
orignal
for example
orignal
ok. I know what's the issue
orignal
Bob starts from seqn 0
orignal
and I always consider it as already received
zzz
seeing more issues, not just the first packets sent, not just inbound
orignal
fine
orignal
do you have an example?
zzz
still working on logging
orignal
fixed that problem with first packet anyway
zzz
the first message losses can be inbound or outbound, any size
orignal
can 65 be result that you don't like other tunnel addresses?
zzz
the losses later, after a connection has been up for a while, look like mostly fragmented messages
orignal
2a06:a004
orignal
don't your have this one in your filters?
zzz
65 is banned ip, banned port, too-close-to-my-ip, or can't find router address with intro key
orignal
it's 69
zzz
you said 65
orignal
65 is "address not found"
orignal
yes
orignal
so my question is
orignal
is it possible that you don't like range?
orignal
because only Java sends 65'
zzz
yes, I'm using 69 for banned-by-hash or banned-by-ip, 65 for invalid ip
orignal
in my case
zzz
2a06:: should be fine
orignal
since IP and RI is fine, I susppect it's range
orignal
then I'm worng
zzz
let me see what the too-close check is
orignal
it's another tunnel
orignal
nothing prevents me from using dufferent tunnel brokers in the same network
orignal
and btw it's another problem
orignal
from the same location
orignal
and no way to detect it
zzz
/16 for ipv4, /32 for ipv6
zzz
SSU doesn't know anything about tunnels :)
orignal
ofc
orignal
I mean IP ranges
orignal
lol. I have received 65 from 2RRY ))
orignal
let me investigate
zzz
On my router in about last 12 hours I've sent 14 0's, 2 67, 1 68
zzz
on other router, 6 0, 1 68
orignal
what is 67?
orignal
found it
zzz
ok, got 4 expired messages to ImQC, stand by for logs
orignal
expired?
orignal
what does it mean?
zzz
retransmitted I2NP message 4x and gave up
orignal
got it
zzz
ok., here we go:
zzz
inbound connection, got a packet, sent a packet:
zzz
07-07 14:23:02.493 DEBUG [ handler 1/1] ort.udp.InboundEstablishState2: New IES2 82.140.199.35:30305 lifetime: 0ms Rcv ID: -5404588203126340187 Send ID: -6604025666776426633 IB_STATE_REQUEST_RECEIVED
zzz
07-07 14:23:02.563 DEBUG [acket pusher] outer.transport.udp.PeerState2: New data pkt 1 sent with 1 fragments on 82.140.199.35:30305 ImQCa~ IB2 recvAge: 0ms sendAge: 52y sendAttemptAge: 0ms sendACKAge: 0ms lifetime: 0ms RTT: 69 RTO: 1000 MTU: 1280 LMTU: 1500 cwin: 3840 acwin: 2556 SST: 524288 FRTX? false consecFail: 0 msgs rcvd: 0 msgs sent: 1 pkts rcvd OK/Dup: 0/0 pkts sent OK/Dup: 0/0 IBM: 0 OBQ: 0 OBL: 1
zzz
07-07 14:23:02.630 DEBUG [ handler 1/1] outer.transport.udp.PeerState2: New 49 byte pkt 1 rcvd on 82.140.199.35:30305 ImQCa~ IB2 recvAge: 67ms sendAge: 52y sendAttemptAge: 67ms sendACKAge: 67ms lifetime: 67ms RTT: 69 RTO: 1000 MTU: 1280 LMTU: 1500 cwin: 3840 acwin: 2556 SST: 524288 FRTX? false consecFail: 0 msgs rcvd: 0 msgs sent: 1 pkts rcvd OK/Dup: 0/0 pkts sent OK/Dup: 1/0 IBM: 0 OBQ: 0 OBL: 1
zzz
07-07 14:23:02.630 DEBUG [ handler 1/1] outer.transport.udp.PeerState2: Got new ACK block from ImQCa~ ACK 1-0
zzz
^^^ and got an ack for that packet
zzz
then, two minutes later, I sent two packets, and retx, and retx, and retx, and never got anything back
zzz
07-07 14:25:04.288 DEBUG [acket pusher] outer.transport.udp.PeerState2: New data pkt 2 sent with 1 fragments on 82.140.199.35:30305 ImQCa~ IB2 recvAge: 121s sendAge: 121s sendAttemptAge: 0ms sendACKAge: 0ms lifetime: 121s RTT: 68 RTO: 1000 MTU: 1344 LMTU: 1500 cwin: 3912 acwin: 442 SST: 524288 FRTX? false consecFail: 0 msgs rcvd: 0 msgs sent: 2 pkts rcvd OK/Dup: 1/0 pkts sent OK/Dup: 1/0 IBM: 0 OBQ: 0 OBL: 1
zzz
07-07 14:25:04.288 DEBUG [acket pusher] outer.transport.udp.PeerState2: New data pkt 3 sent with 1 fragments on 82.140.199.35:30305 ImQCa~ IB2 recvAge: 121s sendAge: 121s sendAttemptAge: 0ms sendACKAge: 0ms lifetime: 121s RTT: 68 RTO: 1000 MTU: 1344 LMTU: 1500 cwin: 3912 acwin: 442 SST: 524288 FRTX? false consecFail: 0 msgs rcvd: 0 msgs sent: 2 pkts rcvd OK/Dup: 1/0 pkts sent OK/Dup: 1/0 IBM: 0 OBQ: 0 OBL: 1
zzz
07-07 14:25:05.288 INFO [acket pusher] outer.transport.udp.PeerState2: [Hash: ImQCa~41bzppySTUmrtpGpJekB4e5o9rHQG~7ylt4wE=] Congestion, RTO: 1000 -> 2000 timer: 0 -> 2000 window: 3912 -> 1500 SST: 524288 -> 2688 FRTX? false BWE: 46 bps
zzz
07-07 14:25:05.288 DEBUG [acket pusher] outer.transport.udp.PeerState2: New data pkt 4 sent with 1 fragments on 82.140.199.35:30305 ImQCa~ IB2 recvAge: 122s sendAge: 122s sendAttemptAge: 0ms sendACKAge: 1000ms lifetime: 122s RTT: 68 RTO: 2000 MTU: 1280 LMTU: 1500 cwin: 1500 acwin: 442 SST: 2688 FRTX? false consecFail: 0 msgs rcvd: 0 msgs sent: 2 pkts rcvd OK/Dup: 1/0 pkts sent OK/Dup: 3/2 IBM: 0 OBQ: 0 OBL: 1
zzz
07-07 14:25:05.288 DEBUG [acket pusher] outer.transport.udp.PeerState2: New data pkt 5 sent with 1 fragments on 82.140.199.35:30305 ImQCa~ IB2 recvAge: 122s sendAge: 122s sendAttemptAge: 0ms sendACKAge: 0ms lifetime: 122s RTT: 68 RTO: 2000 MTU: 1280 LMTU: 1500 cwin: 1500 acwin: 442 SST: 2688 FRTX? false consecFail: 0 msgs rcvd: 0 msgs sent: 2 pkts rcvd OK/Dup: 1/0 pkts sent OK/Dup: 3/2 IBM: 0 OBQ: 0 OBL: 1
zzz
07-07 14:25:07.288 INFO [acket pusher] outer.transport.udp.PeerState2: [Hash: ImQCa~41bzppySTUmrtpGpJekB4e5o9rHQG~7ylt4wE=] Congestion, RTO: 2000 -> 4000 timer: 0 -> 4000 window: 1500 -> 1500 SST: 2688 -> 2560 FRTX? false BWE: 31 bps
zzz
07-07 14:25:07.288 DEBUG [acket pusher] outer.transport.udp.PeerState2: New data pkt 6 sent with 1 fragments on 82.140.199.35:30305 ImQCa~ IB2 recvAge: 124s sendAge: 124s sendAttemptAge: 0ms sendACKAge: 2000ms lifetime: 124s RTT: 68 RTO: 4000 MTU: 1280 LMTU: 1500 cwin: 1500 acwin: 442 SST: 2560 FRTX? false consecFail: 0 msgs rcvd: 0 msgs sent: 2 pkts rcvd OK/Dup: 1/0 pkts sent OK/Dup: 5/4 IBM: 0 OBQ: 0 OBL: 1
zzz
07-07 14:25:07.288 DEBUG [acket pusher] outer.transport.udp.PeerState2: New data pkt 7 sent with 1 fragments on 82.140.199.35:30305 ImQCa~ IB2 recvAge: 124s sendAge: 124s sendAttemptAge: 0ms sendACKAge: 0ms lifetime: 124s RTT: 68 RTO: 4000 MTU: 1280 LMTU: 1500 cwin: 1500 acwin: 442 SST: 2560 FRTX? false consecFail: 0 msgs rcvd: 0 msgs sent: 2 pkts rcvd OK/Dup: 1/0 pkts sent OK/Dup: 5/4 IBM: 0 OBQ: 0 OBL: 1
zzz
07-07 14:25:11.288 INFO [acket pusher] outer.transport.udp.PeerState2: [Hash: ImQCa~41bzppySTUmrtpGpJekB4e5o9rHQG~7ylt4wE=] Congestion, RTO: 4000 -> 8000 timer: 0 -> 8000 window: 1500 -> 1500 SST: 2560 -> 2560 FRTX? false BWE: 13 bps
zzz
and so on and so on and so on. gave up and sent a termination
zzz
then connected outbound to ImQC 30 seconds later and successfully sent several packets and got acks
zzz
so like I said last night, something's not right with trying to send to i2pd on connections inbound to me
orignal
now please explain
orignal
you keep sending message and get nothing back?
zzz
correct
orignal
just no packets at all?
orignal
or you receive something without akc
orignal
like peer test etc.
zzz
i don't see anything, no
orignal
so we can say that the connection is stalled
orignal
not just about acks
zzz
I sent 0 and 1, got an ack, then two minutes later sent 2-14, got nothing
zzz
maybe got a dup ack? I don't log dup acks any more
orignal
I think that this connection doesn't exist on my side anymore
orignal
I have closed it
orignal
but you believe it still exists
zzz
didn't get a termination. it was only 122 seconds after I got the last ack
zzz
when I started sending more packets
orignal
120 seconds ))
orignal
maybe I have teminated it for another reason than timeout
orignal
rememmber that issue about relays "already connected"
orignal
I think that's the source of problem
orignal
maybe I send temination wrong way
zzz
this is IPv4, I'm not firewalled on IPv4, and ImQC is not firewalled
orignal
I know
orignal
it seems just termination issue
orignal
do you send Ack if termination block?
zzz
no, that's not part of the spec
orignal
I know
orignal
but how do I know if you have received my termination
zzz
same as SSU 1 - you don't.
zzz
I just checked - I don't think I ever receive termination from i2pd for inbound connections to me. only outbound
zzz
all my terminations for inbound connnections are from java
zzz
so I don't think it's just packet loss
zzz
please check
orignal
yes that's what I mean
orignal
probably I do something wrong with temination
orignal
have to go. will be back afternoon
zzz
ok
zzz
I'll look at how QUIC handles termination
zzz
ok...
zzz
QUIC says when you send a CONNECTION_CLOSE frame, you enter the "closing" state
zzz
An endpoint in the closing
zzz
state sends a packet containing a CONNECTION_CLOSE frame in response
zzz
to any incoming packet that it attributes to the connection.
zzz
An endpoint
zzz
that is closing is not required to process any received frame. An
zzz
endpoint MAY retain packet protection keys for incoming packets to
zzz
allow it to read and process a CONNECTION_CLOSE frame.
zzz
| Note: Allowing retransmission of a closing packet is an
zzz
| exception to the requirement that a new packet number be used
zzz
| for each packet; see Section 12.3. Sending new packet numbers
zzz
| is primarily of advantage to l | Note: Allowing retransmission of a closing packet is an
zzz
| exception to the requirement that a new packet number be used
zzz
| for each packet; see Section 12.3. Sending new packet numbers
zzz
| is primarily of advantage to loss recovery and congestion
zzz
| control, which are not expected to be relevant for a closed
zzz
| connection. Retransmitting the final packet requires less
zzz
| state.oss recovery and congestion
zzz
| control, which are not expected to be relevant for a closed
zzz
| connection. Retransmitting the final packet requires less
zzz
| state.
zzz
oops that got messed up, try again:
zzz
| Note: Allowing retransmission of a closing packet is an
zzz
| exception to the requirement that a new packet number be used
zzz
| for each packet; see Section 12.3. Sending new packet numbers
zzz
| is primarily of advantage to loss recovery and congestion
zzz
| control, which are not expected to be relevant for a closed
zzz
| connection. Retransmitting the final packet requires less
zzz
| state.
zzz
all that seems to make sense and be a good idea
zzz
I'll start a new section in the spec for it
orignal
so how it will work?
zzz
what QUIC does is very simple. wait for a while after sending termination, and if you get anything more, send termination again
orignal
but it's not our scenario
orignal
I sent termination nothin goes back
orignal
and then you try to send something after a while because you haven't received my termination
zzz
right. and then you get the termination that you didn't get before
orignal
but my session don't exist anymore on my side
zzz
we could, if we want, send a termination in response to termination. there's a reason code for that. QUIC has something similar and says it's optional. that's more complex
orignal
I forgot it
orignal
why can't we send just Ack?
zzz
we could. not sure if that's easier or not
zzz
both our spec and QUIC say that termination is not ack-eliciting
orignal
or you approach would also work
zzz
point is, responding with ack _or_ termination is not the full solution. you still need to wait for a while after sending termination, in a "closing" state
zzz
responding with ack or termination just gets you out of the closing state faster
orignal
so what I'm supposed to do now?
orignal
to fix the problem instantly
zzz
well, we haven't decided yet. But I don't think that's the problem with all the errors I'm seeing
orignal
I think I don't send termination at all now
orignal
but I want to implement it proporly
zzz
agreed, that's my guess. Not for (your) outbound connections. I do get them for (your inbound, my outbound) connections
orignal
you errors have the same scenario
orignal
you keep sending messages and receive nothing back
orignal
at the same time I see bunch of message in the log I can't decrypt
zzz
sure, but we've never bothered to fix it for SSU1 in 17 years
zzz
that's why I don't want to just invent an answer in 10 minutes
orignal
I think there were bunch of probelms like this in SSU1
zzz
actually, jrandom's SSU1 didn't have a destroy message at all. We added it later
orignal
then current behaviour is right
orignal
if you don't get ack for a message few times you assume that connection is dead
zzz
sure, it's "right", but not ideal. that was your point, what happens if destroy packet is lost
zzz
so we can do better
orignal
yes
orignal
let me implement termination message first))
orignal
found the source of 65 code
orignal
what's the bug