RDP Service gets RESET from end device

Ziti Overlay
1

Hi,

Since few days, when I try to connect to my laptop via RDP over OpenZiti network, my laptop sends a RST packet after successfully logged and connected, It happens few seconds later the connection.
Before (weeks ago), It worked perfectly and I never touch any configuration of this service.

I performed a packet capture from my laptop I want to connect with RDP, without ziti overlay and with ziti overlay and I can't see the problem... Together use TLSv1.3 and same type of packets are sent.

I don't know what to do.

Best regards

2

Hi @Damien,

When you get disconnected, RDP takes a moment to realize it and try to reconnect. I would look at the router logs to see if there are any events in the logs that are helpful and maybe look at the client side logs and the logs at the offloading tunneler. There is probably a clue in there somewhere.

How long does the connection stay connected before you notice the disconnect? Is it consistent?

You haven't upgraded the overlay network, or the tunnelers lately have you? If not, I think it might be hard to track this down.

Let's start by looking at all three logs (client tunneler, router, server-side tunneler) and see if any errors are logged?

3

I stay connected like 10 seconds maximum and it disconnect me, even when RDP reconnect successfully, it instantly disconnect the service.

I haven't upgraded anything.
Note that all other services runs properly, only RDP fail.

Tunneler logs (android):

--------- beginning of main
06-17 21:06:16.782 26700 26737 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: made packet[988] flags[ACK] seq[154094] ack[3242631656] data[956]
06-17 21:06:16.782 26700 26790 V routing : got msg[(/100.64.0.0:49080, /100.64.1.4:3389)]: 118 bytes
06-17 21:06:16.782 26700 26737 D tcp:/100.64.0.0:49080 -> /100.64.1.4:3389: sending to peer packet_size[1008]
06-17 21:06:16.782 26700 26737 V ziti-conn[TtZPsc9q4/2]: reading
06-17 21:06:16.782 26700 26790 V routing : got msg[(/100.64.0.0:49080, /100.64.1.4:3389)]: 118 bytes
06-17 21:06:16.782 26700 26737 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: received flags[ACK] seq[3242631656] ack[154094] ws[957 (15679488)]
06-17 21:06:16.782 26700 26737 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: state[ESTABLISHED] <- ACK data[66]
06-17 21:06:16.782 26700 26737 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: peer sent 66 bytes
06-17 21:06:16.783 26700 26737 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: made packet[32] flags[ACK] seq[155050] ack[3242631722] data[null]
06-17 21:06:16.783 26700 26737 V tcp:/100.64.0.0:49080 -> /100.64.1.4:3389: sending 66 bytes to ziti backend
06-17 21:06:16.783 26700 26737 V ziti-conn[TtZPsc9q4/2]: sending ct: Data, seq: -1, repTo: -1, connId: 2, body 83 bytes
06-17 21:06:16.783 26700 26737 D tcp:/100.64.0.0:49080 -> /100.64.1.4:3389: sending to peer packet_size[52]
06-17 21:06:16.784 26700 26737 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: received flags[ACK] seq[3242631722] ack[154094] ws[957 (15679488)]
06-17 21:06:16.784 26700 26737 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: state[ESTABLISHED] <- ACK data[66]
06-17 21:06:16.784 26700 26737 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: peer sent 66 bytes
06-17 21:06:16.784 26700 27429 V C.1.2.171:48442]: sending m = ct: Data, seq: 1955, repTo: -1, connId: 2, body 83 bytes
06-17 21:06:16.784 26700 26737 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: made packet[32] flags[ACK] seq[155050] ack[3242631788] data[null]
06-17 21:06:16.784 26700 26737 V tcp:/100.64.0.0:49080 -> /100.64.1.4:3389: sending 66 bytes to ziti backend
06-17 21:06:16.784 26700 26737 V ziti-conn[TtZPsc9q4/2]: sending ct: Data, seq: -1, repTo: -1, connId: 2, body 83 bytes
06-17 21:06:16.785 26700 26737 D tcp:/100.64.0.0:49080 -> /100.64.1.4:3389: sending to peer packet_size[52]
06-17 21:06:16.786 26700 26790 V routing : got msg[(/100.64.0.0:49080, /100.64.1.4:3389)]: 118 bytes
06-17 21:06:16.786 26700 26790 V routing : got msg[(/100.64.0.0:49080, /100.64.1.4:3389)]: 118 bytes
06-17 21:06:16.786 26700 27429 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: received flags[ACK] seq[3242631788] ack[155050] ws[964 (15794176)]
06-17 21:06:16.786 26700 27429 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: state[ESTABLISHED] <- ACK data[66]
06-17 21:06:16.787 26700 27429 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: peer sent 66 bytes
06-17 21:06:16.787 26700 27429 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: made packet[32] flags[ACK] seq[155050] ack[3242631854] data[null]
06-17 21:06:16.787 26700 27429 V tcp:/100.64.0.0:49080 -> /100.64.1.4:3389: sending 66 bytes to ziti backend
06-17 21:06:16.788 26700 26737 V C.1.2.171:48442]: sending m = ct: Data, seq: 1956, repTo: -1, connId: 2, body 83 bytes
06-17 21:06:16.788 26700 26737 V ziti-conn[TtZPsc9q4/2]: sending ct: Data, seq: -1, repTo: -1, connId: 2, body 83 bytes
06-17 21:06:16.788 26700 26737 D tcp:/100.64.0.0:49080 -> /100.64.1.4:3389: sending to peer packet_size[52]
06-17 21:06:16.788 26700 26737 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: received flags[ACK] seq[3242631854] ack[155050] ws[964 (15794176)]
06-17 21:06:16.788 26700 26737 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: state[ESTABLISHED] <- ACK data[66]
06-17 21:06:16.789 26700 26737 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: peer sent 66 bytes
06-17 21:06:16.789 26700 26737 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: made packet[32] flags[ACK] seq[155050] ack[3242631920] data[null]
06-17 21:06:16.789 26700 26737 V tcp:/100.64.0.0:49080 -> /100.64.1.4:3389: sending 66 bytes to ziti backend
06-17 21:06:16.789 26700 27882 V ziti-conn[TtZPsc9q4/2]: sending ct: Data, seq: -1, repTo: -1, connId: 2, body 83 bytes
06-17 21:06:16.789 26700 27882 D tcp:/100.64.0.0:49080 -> /100.64.1.4:3389: sending to peer packet_size[52]
06-17 21:06:16.790 26700 27429 V C.1.2.171:48442]: sending m = ct: Data, seq: 1957, repTo: -1, connId: 2, body 83 bytes
06-17 21:06:16.791 26700 27429 V C.1.2.171:48442]: sending m = ct: Data, seq: 1958, repTo: -1, connId: 2, body 83 bytes
06-17 21:06:16.809 26700 27429 V C.1.2.171:48442]: got m = ct: Data, seq: 760, repTo: -1, connId: 2, body 236 bytes
06-17 21:06:16.809 26700 27429 V ziti-conn[TtZPsc9q4/2]: conn[2] received message[Data] with seq[228]
06-17 21:06:16.809 26700 27429 V ziti-conn[TtZPsc9q4/2]: received data(236 bytes) for conn[2]
06-17 21:06:16.810 26700 26737 V ziti-conn[TtZPsc9q4/2]: transferred 219
06-17 21:06:16.810 26700 26737 V ziti-conn[TtZPsc9q4/2]: read completed null
06-17 21:06:16.811 26700 26737 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: got from 219 from ziti
06-17 21:06:16.811 26700 26737 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: made packet[251] flags[ACK] seq[155050] ack[3242631920] data[219]
06-17 21:06:16.812 26700 26737 D tcp:/100.64.0.0:49080 -> /100.64.1.4:3389: sending to peer packet_size[271]
06-17 21:06:16.813 26700 26737 V ziti-conn[TtZPsc9q4/2]: reading
06-17 21:06:16.819 26700 26790 V routing : got msg[(/100.64.0.0:49080, /100.64.1.4:3389)]: 118 bytes
06-17 21:06:16.820 26700 26734 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: received flags[ACK] seq[3242631920] ack[155269] ws[964 (15794176)]
06-17 21:06:16.821 26700 26790 V routing : got msg[(/100.64.0.0:49080, /100.64.1.4:3389)]: 118 bytes
06-17 21:06:16.821 26700 26734 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: state[ESTABLISHED] <- ACK data[66]
06-17 21:06:16.821 26700 26734 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: peer sent 66 bytes
06-17 21:06:16.821 26700 26734 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: made packet[32] flags[ACK] seq[155269] ack[3242631986] data[null]
06-17 21:06:16.821 26700 26734 V tcp:/100.64.0.0:49080 -> /100.64.1.4:3389: sending 66 bytes to ziti backend
06-17 21:06:16.822 26700 26734 V ziti-conn[TtZPsc9q4/2]: sending ct: Data, seq: -1, repTo: -1, connId: 2, body 83 bytes
06-17 21:06:16.823 26700 26737 V C.1.2.171:48442]: sending m = ct: Data, seq: 1959, repTo: -1, connId: 2, body 83 bytes
06-17 21:06:16.823 26700 26734 D tcp:/100.64.0.0:49080 -> /100.64.1.4:3389: sending to peer packet_size[52]
06-17 21:06:16.823 26700 26734 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: received flags[ACK] seq[3242631986] ack[155269] ws[964 (15794176)]
06-17 21:06:16.823 26700 26734 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: state[ESTABLISHED] <- ACK data[66]
06-17 21:06:16.824 26700 26734 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: peer sent 66 bytes
06-17 21:06:16.825 26700 26734 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: made packet[32] flags[ACK] seq[155269] ack[3242632052] data[null]
06-17 21:06:16.825 26700 26734 V tcp:/100.64.0.0:49080 -> /100.64.1.4:3389: sending 66 bytes to ziti backend
06-17 21:06:16.825 26700 26734 V ziti-conn[TtZPsc9q4/2]: sending ct: Data, seq: -1, repTo: -1, connId: 2, body 83 bytes
06-17 21:06:16.826 26700 26734 D tcp:/100.64.0.0:49080 -> /100.64.1.4:3389: sending to peer packet_size[52]
06-17 21:06:16.826 26700 27882 V C.1.2.171:48442]: sending m = ct: Data, seq: 1960, repTo: -1, connId: 2, body 83 bytes
06-17 21:06:17.270 26700 26700 I ViewRootImpl@14a6899[ZitiMobileEdgeActivity]: onDisplayChanged oldDisplayState=2 newDisplayState=2
06-17 21:06:17.846 26700 26734 V C.1.2.171:48442]: got m = ct: Data, seq: 761, repTo: -1, connId: 2, body 61 bytes
06-17 21:06:17.846 26700 26734 V ziti-conn[TtZPsc9q4/2]: conn[2] received message[Data] with seq[229]
06-17 21:06:17.846 26700 26734 V ziti-conn[TtZPsc9q4/2]: received data(61 bytes) for conn[2]
06-17 21:06:17.847 26700 27882 V ziti-conn[TtZPsc9q4/2]: transferred 44
06-17 21:06:17.847 26700 27882 V ziti-conn[TtZPsc9q4/2]: read completed null
06-17 21:06:17.848 26700 27882 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: got from 44 from ziti
06-17 21:06:17.848 26700 27882 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: made packet[76] flags[ACK] seq[155269] ack[3242632052] data[44]
06-17 21:06:17.849 26700 27882 D tcp:/100.64.0.0:49080 -> /100.64.1.4:3389: sending to peer packet_size[96]
06-17 21:06:17.849 26700 27882 V ziti-conn[TtZPsc9q4/2]: reading
06-17 21:06:17.852 26700 26734 V C.1.2.171:48442]: got m = ct: Data, seq: 762, repTo: -1, connId: 2, body 186 bytes
06-17 21:06:17.852 26700 26734 V ziti-conn[TtZPsc9q4/2]: conn[2] received message[Data] with seq[230]
06-17 21:06:17.852 26700 26734 V ziti-conn[TtZPsc9q4/2]: received data(186 bytes) for conn[2]
06-17 21:06:17.853 26700 27882 V ziti-conn[TtZPsc9q4/2]: transferred 169
06-17 21:06:17.853 26700 27882 V ziti-conn[TtZPsc9q4/2]: read completed null
06-17 21:06:17.854 26700 26734 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: got from 169 from ziti
06-17 21:06:17.854 26700 26734 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: made packet[201] flags[ACK] seq[155313] ack[3242632052] data[169]
06-17 21:06:17.854 26700 26734 D tcp:/100.64.0.0:49080 -> /100.64.1.4:3389: sending to peer packet_size[221]
06-17 21:06:17.854 26700 26734 V ziti-conn[TtZPsc9q4/2]: reading
06-17 21:06:17.856 26700 26790 V routing : got msg[(/100.64.0.0:49080, /100.64.1.4:3389)]: 52 bytes
06-17 21:06:17.856 26700 26734 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: received flags[ACK] seq[3242632052] ack[155482] ws[964 (15794176)]
06-17 21:06:17.856 26700 26734 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: state[ESTABLISHED] <- ACK data[0]
06-17 21:06:17.858 26700 26790 V routing : got msg[(/100.64.0.0:49080, /100.64.1.4:3389)]: 118 bytes
06-17 21:06:17.858 26700 26790 V routing : got msg[(/100.64.0.0:49080, /100.64.1.4:3389)]: 118 bytes
06-17 21:06:17.858 26700 26734 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: received flags[ACK] seq[3242632052] ack[155482] ws[964 (15794176)]
06-17 21:06:17.858 26700 26734 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: state[ESTABLISHED] <- ACK data[66]
06-17 21:06:17.858 26700 26734 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: peer sent 66 bytes
06-17 21:06:17.858 26700 26734 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: made packet[32] flags[ACK] seq[155482] ack[3242632118] data[null]
06-17 21:06:17.858 26700 26734 V tcp:/100.64.0.0:49080 -> /100.64.1.4:3389: sending 66 bytes to ziti backend
06-17 21:06:17.859 26700 26734 V ziti-conn[TtZPsc9q4/2]: sending ct: Data, seq: -1, repTo: -1, connId: 2, body 83 bytes
06-17 21:06:17.859 26700 26734 D tcp:/100.64.0.0:49080 -> /100.64.1.4:3389: sending to peer packet_size[52]
06-17 21:06:17.860 26700 26737 V C.1.2.171:48442]: sending m = ct: Data, seq: 1961, repTo: -1, connId: 2, body 83 bytes
06-17 21:06:17.860 26700 26734 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: received flags[ACK] seq[3242632118] ack[155482] ws[964 (15794176)]
06-17 21:06:17.860 26700 26734 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: state[ESTABLISHED] <- ACK data[66]
06-17 21:06:17.860 26700 26734 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: peer sent 66 bytes
06-17 21:06:17.860 26700 26734 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: made packet[32] flags[ACK] seq[155482] ack[3242632184] data[null]
06-17 21:06:17.860 26700 26734 V tcp:/100.64.0.0:49080 -> /100.64.1.4:3389: sending 66 bytes to ziti backend
06-17 21:06:17.861 26700 26734 V ziti-conn[TtZPsc9q4/2]: sending ct: Data, seq: -1, repTo: -1, connId: 2, body 83 bytes
06-17 21:06:17.861 26700 26734 D tcp:/100.64.0.0:49080 -> /100.64.1.4:3389: sending to peer packet_size[52]
06-17 21:06:17.862 26700 27882 V C.1.2.171:48442]: sending m = ct: Data, seq: 1962, repTo: -1, connId: 2, body 83 bytes
06-17 21:06:17.971 26700 26790 V routing : got msg[(/100.64.0.0:49080, /100.64.1.4:3389)]: 83 bytes
06-17 21:06:17.971 26700 26790 V routing : got msg[(/100.64.0.0:49080, /100.64.1.4:3389)]: 52 bytes
06-17 21:06:17.972 26700 27882 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: received flags[ACK] seq[3242632184] ack[155482] ws[964 (15794176)]
06-17 21:06:17.972 26700 27882 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: state[ESTABLISHED] <- ACK data[31]
06-17 21:06:17.972 26700 27882 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: peer sent 31 bytes
06-17 21:06:17.972 26700 27882 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: made packet[32] flags[ACK] seq[155482] ack[3242632215] data[null]
06-17 21:06:17.973 26700 27882 V tcp:/100.64.0.0:49080 -> /100.64.1.4:3389: sending 31 bytes to ziti backend
06-17 21:06:17.975 26700 27882 V ziti-conn[TtZPsc9q4/2]: sending ct: Data, seq: -1, repTo: -1, connId: 2, body 48 bytes
06-17 21:06:17.975 26700 27882 D tcp:/100.64.0.0:49080 -> /100.64.1.4:3389: sending to peer packet_size[52]
06-17 21:06:17.975 26700 27429 V C.1.2.171:48442]: sending m = ct: Data, seq: 1963, repTo: -1, connId: 2, body 48 bytes
06-17 21:06:17.975 26700 27882 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: received flags[ACK,FIN] seq[3242632215] ack[155482] ws[964 (15794176)]
06-17 21:06:17.975 26700 27882 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: state[ESTABLISHED] <- ACK,FIN data[0]
06-17 21:06:17.976 26700 27882 D tcp-conn: tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389/ESTABLISHED transitioning to CLOSE_WAIT
06-17 21:06:17.976 26700 27882 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: made packet[32] flags[ACK,FIN] seq[155482] ack[3242632216] data[null]
06-17 21:06:17.976 26700 27882 D tcp:/100.64.0.0:49080 -> /100.64.1.4:3389: sending to peer packet_size[52]
06-17 21:06:17.977 26700 26790 V routing : got msg[(/100.64.0.0:49080, /100.64.1.4:3389)]: 52 bytes
06-17 21:06:17.977 26700 26737 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: received flags[ACK] seq[3242632216] ack[155483] ws[964 (15794176)]
06-17 21:06:17.977 26700 26737 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: state[CLOSE_WAIT] <- ACK data[0]
06-17 21:06:17.984 26700 26741 V C.1.2.171:48442]: got m = ct: StateClosed, seq: 763, repTo: -1, connId: 2, body 12 bytes
06-17 21:06:17.984 26700 26741 V ziti-conn[TtZPsc9q4/2]: conn[2] received message[StateClosed] with seq[231]
06-17 21:06:17.984 26700 26741 V ziti-conn[TtZPsc9q4/2]: signaling EOF
06-17 21:06:17.984 26700 26741 D ziti-conn[TtZPsc9q4/2]: sending FIN
06-17 21:06:17.984 26700 26741 D ziti-conn[TtZPsc9q4/2]: closing conn = 2
06-17 21:06:17.984 26700 27882 V ziti-conn[TtZPsc9q4/2]: read completed kotlinx.coroutines.channels.ClosedReceiveChannelException: Channel was closed
06-17 21:06:17.985 26700 26757 D tcp:/100.64.0.0:49080 -> /100.64.1.4:3389: ziti conn is closed
06-17 21:06:17.985 26700 26757 D tcp-conn: tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389/CLOSE_WAIT transitioning to LAST_ACK
06-17 21:06:17.985 26700 26757 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: made packet[32] flags[SYN,ACK,FIN] seq[155483] ack[3242632216] data[null]
06-17 21:06:17.985 26700 26757 D tcp:/100.64.0.0:49080 -> /100.64.1.4:3389: sending to peer packet_size[52]
06-17 21:06:17.985 26700 26757 D tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: got close() in LAST_ACK
06-17 21:06:17.985 26700 26757 I tcp:/100.64.0.0:49080 -> /100.64.1.4:3389: readZitiConn() is finished
06-17 21:06:17.988 26700 26737 V C.1.2.171:48442]: sending m = ct: Data, seq: 1964, repTo: -1, connId: 2, body 0 bytes
06-17 21:06:17.989 26700 26790 V routing : got msg[(/100.64.0.0:49080, /100.64.1.4:3389)]: 52 bytes
06-17 21:06:17.990 26700 27908 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: received flags[ACK] seq[3242632216] ack[155483] ws[964 (15794176)]
06-17 21:06:17.990 26700 27908 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: state[LAST_ACK] <- ACK data[0]
06-17 21:06:17.990 26700 27908 D tcp-conn: tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389/LAST_ACK transitioning to Closed
06-17 21:06:17.990 26700 26737 V C.1.2.171:48442]: sending m = ct: StateClosed, seq: 1965, repTo: -1, connId: 2, body 0 bytes
06-17 21:06:17.991 26700 26790 I routing : removing tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389
06-17 21:06:19.585 26700 26790 V routing : got msg[(/100.64.0.0:52218, /100.64.1.4:3389)]: 567 bytes
06-17 21:06:19.585 26700 26790 E routing : invalid state. No connection found for [(/100.64.0.0:52218, /100.64.1.4:3389)]. packet is dropped
06-17 21:06:19.701 26700 26700 I ViewRootImpl@14a6899[ZitiMobileEdgeActivity]: handleAppVisibility mAppVisible = false visible = true
06-17 21:06:19.704 26700 26700 I ViewRootImpl@14a6899[ZitiMobileEdgeActivity]: stopped(false) old = true
06-17 21:06:19.704 26700 26700 D ViewRootImpl@14a6899[ZitiMobileEdgeActivity]: WindowStopped on org.openziti.mobile/org.openziti.mobile.ZitiMobileEdgeActivity set to false
06-17 21:06:19.705 26700 26700 W WindowOnBackDispatcher: OnBackInvokedCallback is not enabled for the application.
06-17 21:06:19.705 26700 26700 W WindowOnBackDispatcher: Set 'android:enableOnBackInvokedCallback="true"' in the application manifest.
06-17 21:06:19.721 26700 26700 I BufferQueueProducer: [](id:684c00000002,api:0,p:114,c:26700) setDequeueTimeout:2077252342
06-17 21:06:19.722 26700 26700 I BLASTBufferQueue_Java: new BLASTBufferQueue, mName= ViewRootImpl@14a6899[ZitiMobileEdgeActivity] mNativeObject= 0xb40000721216bc00 sc.mNativeObject= 0xb40000720b340840 caller= android.view.ViewRootImpl.updateBlastSurfaceIfNeeded:3028 android.view.ViewRootImpl.relayoutWindow:10131 android.view.ViewRootImpl.performTraversals:4110 android.view.ViewRootImpl.doTraversal:3288 android.view.ViewRootImpl$TraversalRunnable.run:11344 android.view.Choreographer$CallbackRecord.run:1689 android.view.Choreographer$CallbackRecord.run:1698 android.view.Choreographer.doCallbacks:1153 android.view.Choreographer.doFrame:1079 android.view.Choreographer$FrameDisplayEventReceiver.run:1646 
06-17 21:06:19.722 26700 26700 I BLASTBufferQueue_Java: update, w= 1080 h= 2340 mName = ViewRootImpl@14a6899[ZitiMobileEdgeActivity] mNativeObject= 0xb40000721216bc00 sc.mNativeObject= 0xb40000720b340840 format= -1 caller= android.graphics.BLASTBufferQueue.<init>:89 android.view.ViewRootImpl.updateBlastSurfaceIfNeeded:3028 android.view.ViewRootImpl.relayoutWindow:10131 android.view.ViewRootImpl.performTraversals:4110 android.view.ViewRootImpl.doTraversal:3288 android.view.ViewRootImpl$TraversalRunnable.run:11344 
06-17 21:06:19.722 26700 26700 I ViewRootImpl@14a6899[ZitiMobileEdgeActivity]: Relayout returned: old=(0,0,1080,2340) new=(0,0,1080,2340) relayoutAsync=false req=(1080,2340)0 dur=10 res=0x403 s={true 0xb4000072be964000} ch=true seqId=0
06-17 21:06:19.722 26700 26700 D ViewRootImpl@14a6899[ZitiMobileEdgeActivity]: mThreadedRenderer.initialize() mSurface={isValid=true 0xb4000072be964000} hwInitialized=true
06-17 21:06:19.723 26700 26700 D ViewRootImpl@14a6899[ZitiMobileEdgeActivity]: reportNextDraw android.view.ViewRootImpl.performTraversals:4718 android.view.ViewRootImpl.doTraversal:3288 android.view.ViewRootImpl$TraversalRunnable.run:11344 android.view.Choreographer$CallbackRecord.run:1689 android.view.Choreographer$CallbackRecord.run:1698 
06-17 21:06:19.723 26700 26700 I ViewRootImpl@14a6899[ZitiMobileEdgeActivity]: Setup new sync=wmsSync-ViewRootImpl@14a6899[ZitiMobileEdgeActivity]#4
06-17 21:06:19.723 26700 26700 I ViewRootImpl@14a6899[ZitiMobileEdgeActivity]: Creating new active sync group ViewRootImpl@14a6899[ZitiMobileEdgeActivity]#5
06-17 21:06:19.723 26700 26700 I ViewRootImpl@14a6899[ZitiMobileEdgeActivity]: registerCallbacksForSync syncBuffer=false
06-17 21:06:19.725 26700 26755 I ViewRootImpl@14a6899[ZitiMobileEdgeActivity]: Received frameDrawingCallback syncResult=0 frameNum=1.
06-17 21:06:19.725 26700 26755 I ViewRootImpl@14a6899[ZitiMobileEdgeActivity]: mWNT: t=0xb40000727d521700 mBlastBufferQueue=0xb40000721216bc00 fn= 1 mRenderHdrSdrRatio=1.0 caller= android.view.ViewRootImpl$8.onFrameDraw:13841 android.view.ThreadedRenderer$1.onFrameDraw:792 <bottom of call stack> 
06-17 21:06:19.725 26700 26755 I ViewRootImpl@14a6899[ZitiMobileEdgeActivity]: Setting up sync and frameCommitCallback
06-17 21:06:19.726 26700 26744 I BLASTBufferQueue: [ViewRootImpl@14a6899[ZitiMobileEdgeActivity]#2](f:0,a:0,s:0) onFrameAvailable the first frame is available
06-17 21:06:19.727 26700 26744 I ViewRootImpl@14a6899[ZitiMobileEdgeActivity]: Received frameCommittedCallback lastAttemptedDrawFrameNum=1 didProduceBuffer=true
06-17 21:06:19.727 26700 26700 I ViewRootImpl@14a6899[ZitiMobileEdgeActivity]: reportDrawFinished seqId=0
06-17 21:06:19.727 26700 26700 I InsetsSourceConsumer: applyRequestedVisibilityToControl: visible=true, type=navigationBars, host=org.openziti.mobile/org.openziti.mobile.ZitiMobileEdgeActivity
06-17 21:06:19.727 26700 26700 I InsetsSourceConsumer: applyRequestedVisibilityToControl: visible=true, type=statusBars, host=org.openziti.mobile/org.openziti.mobile.ZitiMobileEdgeActivity
06-17 21:06:19.763 26700 26700 I ViewRootImpl@14a6899[ZitiMobileEdgeActivity]: handleWindowFocusChanged: 1 0 call from android.view.ViewRootImpl.-$$Nest$mhandleWindowFocusChanged:0
06-17 21:06:19.763 26700 26700 D ViewRootImpl@14a6899[ZitiMobileEdgeActivity]: mThreadedRenderer.initializeIfNeeded()#2 mSurface={isValid=true 0xb4000072be964000}
06-17 21:06:19.764 26700 26700 D InputMethodManagerUtils: startInputInner - Id : 0
06-17 21:06:19.764 26700 26700 I InputMethodManager: startInputInner - IInputMethodManagerGlobalInvoker.startInputOrWindowGainedFocus
06-17 21:06:19.773 26700 26700 I InsetsSourceConsumer: applyRequestedVisibilityToControl: visible=false, type=ime, host=org.openziti.mobile/org.openziti.mobile.ZitiMobileEdgeActivity
06-17 21:06:19.774 26700 26767 I ViewRootImpl@14a6899[ZitiMobileEdgeActivity]: Resizing android.view.ViewRootImpl@aa0ea60: frame = [0,0][1080,2340] reportDraw = false forceLayout = false syncSeqId = -1
06-17 21:06:19.774 26700 26700 I ViewRootImpl@14a6899[ZitiMobileEdgeActivity]: handleResized, msg = 4 frames=ClientWindowFrames{frame=[0,0][1080,2340] display=[0,0][1080,2340] parentFrame=[0,0][0,0]} forceNextWindowRelayout=false displayId=0 dragResizing=false compatScale=1.0 frameChanged=false attachedFrameChanged=false configChanged=false displayChanged=false compatScaleChanged=false
06-17 21:06:20.493 26700 26700 I ViewRootImpl@14a6899[ZitiMobileEdgeActivity]: ViewPostIme pointer 0
06-17 21:06:20.541 26700 26700 I ViewRootImpl@14a6899[ZitiMobileEdgeActivity]: ViewPostIme pointer 1
06-17 21:06:20.549 26700 26700 I ZitiVPNService: onStartCommand Intent { act=stop cmp=org.openziti.mobile/.ZitiVPNService }, 15
06-17 21:06:20.549 26700 26700 I ZitiVPNService: monitor=StandaloneCoroutine{Active}@769db87
06-17 21:06:20.550 26700 26763 I ZitiVPNService: received cmd[stop]
06-17 21:06:20.550 26700 26763 I Tunnel  : closing
06-17 21:06:20.577 26700 27094 I Tunnel  : reader() input was closed: java.nio.channels.AsynchronousCloseException
06-17 21:06:20.577 26700 26763 I ZitiVPNService: tunnel stop success
06-17 21:06:20.577 26700 26790 I Tunnel  : reader was cancelled
06-17 21:06:20.577 26700 26790 I Tunnel  : reader() finished StandaloneCoroutine was cancelled
06-17 21:06:20.577 26700 26790 I Tunnel  : writer() finished StandaloneCoroutine was cancelled
06-17 21:06:20.582 26700 26761 I ZitiVPNService: network: 216 is lost
06-17 21:06:20.607 26700 26761 I ZitiVPNService: network available: 203, caps:[ Transports: WIFI Capabilities: NOT_METERED&INTERNET&NOT_RESTRICTED&TRUSTED&NOT_VPN&VALIDATED&NOT_ROAMING&FOREGROUND&NOT_CONGESTED&NOT_SUSPENDED&NOT_VCN_MANAGED LinkUpBandwidth>=59816Kbps LinkDnBandwidth>=68191Kbps TransportInfo: <SSID: <unknown ssid>, BSSID: 02:00:00:00:00:00, MAC: 02:00:00:00:00:00, IP: /192.168.1.151, Security type: 2, Supplicant state: COMPLETED, Wi-Fi standard: 5, RSSI: -52, Link speed: 650Mbps, Tx Link speed: 650Mbps, Max Supported Tx Link speed: 866Mbps, Rx Link speed: 702Mbps, Max Supported Rx Link speed: 866Mbps, Frequency: 5240MHz, Net ID: -1, Metered hint: false, score: 60, isUsable: true, CarrierMerged: false, SubscriptionId: -1, IsPrimary: -1, Trusted: true, Restricted: false, Ephemeral: false, OEM paid: false, OEM private: false, OSU AP: false, FQDN: <none>, Provider friendly name: <none>, Requesting package name: <none><none>MLO Information: , Is TID-To-Link negotiation supported by the AP: false, AP MLD Address: <none>, AP MLO Link Id: <none>, AP MLO Affiliated links: <none>> SignalStrength: -52 UnderlyingNetworks: Null]
06-17 21:06:20.862 26700 26700 I ViewRootImpl@14a6899[ZitiMobileEdgeActivity]: ViewPostIme pointer 0
06-17 21:06:20.908 26700 26700 I ViewRootImpl@14a6899[ZitiMobileEdgeActivity]: ViewPostIme pointer 1
06-17 21:06:20.910 26700 26700 D AnimatorSet: mReversing is false. Don't call initChildren.
06-17 21:06:22.436 26700 26700 I ViewRootImpl@14a6899[ZitiMobileEdgeActivity]: ViewPostIme pointer 0
06-17 21:06:22.501 26700 26700 I ViewRootImpl@14a6899[ZitiMobileEdgeActivity]: ViewPostIme pointer 1
06-17 21:06:22.502 26700 26700 D AnimatorSet: mReversing is false. Don't call initChildren.
06-17 21:06:23.312 26700 26700 I ViewRootImpl@14a6899[ZitiMobileEdgeActivity]: ViewPostIme pointer 0
06-17 21:06:23.319 26700 26700 I ViewRootImpl@14a6899[ZitiMobileEdgeActivity]: onDisplayChanged oldDisplayState=2 newDisplayState=2
06-17 21:06:23.337 26700 26700 I ViewRootImpl@14a6899[ZitiMobileEdgeActivity]: onDisplayChanged oldDisplayState=2 newDisplayState=2
06-17 21:06:23.361 26700 26700 I ViewRootImpl@14a6899[ZitiMobileEdgeActivity]: ViewPostIme pointer 1
06-17 21:06:23.361 26700 26700 D AnimatorSet: mReversing is false. Don't call initChildren.
06-17 21:06:24.355 26700 26700 I ViewRootImpl@14a6899[ZitiMobileEdgeActivity]: ViewPostIme pointer 0
06-17 21:06:24.403 26700 26700 I ViewRootImpl@14a6899[ZitiMobileEdgeActivity]: ViewPostIme pointer 1
06-17 21:06:24.405 26700 26700 D AnimatorSet: mReversing is false. Don't call initChildren.

Router (tunneler mode) logs:


[480136.422] WARNING ziti/router/xgress.(*Xgress).rx [{c/y9Oz9UDIX|@/vKzO}<Terminator>]: read failed (read tcp 192.168.1.7:59278->192.168.1.138:3389: read: connection reset by peer)
[480150.926] WARNING ziti/router/xgress.(*Xgress).rx [{c/CeB4SUDIj|@/72GJ}<Terminator>]: read failed (read tcp 192.168.1.7:55602->192.168.1.138:3389: read: connection reset by peer)
[480162.866] WARNING ziti/router/xgress.(*Xgress).rx [{c/Qb.4SUDIX|@/7dXQ}<Terminator>]: read failed (read tcp 192.168.1.7:33050->192.168.1.138:3389: read: connection reset by peer)
[505634.287] WARNING ziti/router/xgress.(*Xgress).rx [{c/280t5xDTj|@/y9gM}<Terminator>]: read failed (read tcp 192.168.1.7:49432->192.168.1.138:3389: read: connection reset by peer)
[505645.384] WARNING ziti/router/xgress.(*Xgress).rx [{c/ufl8GnDIX|@/7B9X}<Terminator>]: read failed (read tcp 192.168.1.7:42948->192.168.1.138:3389: use of closed network connection)
[513770.388] WARNING ziti/router/xgress.(*Xgress).rx [{c/WB4eSnDIj|@/r80P}<Terminator>]: read failed (read tcp 192.168.1.7:56990->192.168.1.138:3389: read: connection reset by peer)
[513832.128] WARNING ziti/router/xgress.(*Xgress).rx [{c/2f43SxdIX|@/7PZe}<Terminator>]: read failed (read tcp 192.168.1.7:50328->192.168.1.138:3389: read: connection reset by peer)
[518098.422] WARNING ziti/router/xgress.(*Xgress).rx [{c/RAjA4xDIX|@/vemp}<Terminator>]: read failed (read tcp 192.168.1.7:36000->192.168.1.138:3389: read: connection reset by peer)
[518098.422]   ERROR ziti/router/handler_xgress.(*receiveHandler).HandleXgressReceive [{c/RAjA4xDIX|@/7Wl6}<Initiator>]: {circuitId=[RAjA4xDIX] seq=[1775] origin=[Initiator] error=[cannot forward payload, no destination for circuit=RAjA4xDIX src=7Wl6 dst=vemp]} unable to forward payload
[518104.109] WARNING ziti/router/xgress.(*Xgress).rx [{c/tmAAznDTj|@/74Jp}<Terminator>]: read failed (read tcp 192.168.1.7:56600->192.168.1.138:3389: read: connection reset by peer)
[518105.897] WARNING ziti/router/forwarder.(*Faulter).run: {circuitCount=[1] ctrlId=[PUBLIC_IP_HIDDEN]} reported forwarding faults
[518673.622] WARNING ziti/router/xgress.(*Xgress).rx [{c/VJLrNndTj|@/ykQG}<Terminator>]: read failed (read tcp 192.168.1.7:59848->192.168.1.138:3389: read: connection reset by peer)
[518686.998] WARNING ziti/router/xgress.(*Xgress).rx [{c/1KNPwxDIX|@/v3JK}<Terminator>]: read failed (read tcp 192.168.1.7:39860->192.168.1.138:3389: read: connection reset by peer)

And nothing on the controller

4

Interesting. This almost sounds like some kind of endpoint protection software sniping the connection but that log from the router: "cannot forward payload, no destination for circuit" that seems strange.

Maybe @plorenz will have an idea on that issue. Is your tunneller running android? You're RDP'ing from android through the edge router, right?

5

Yes that's weird. I haven't installed a new anti malware.

I use android tunneler with microsoft rdp app

6

Unfortunately there's nothing unusual here. First the router gets a read error from the server, which causes the circuit to be torn down. A payload arriving from the client at that time can't be delivered because the circuit was just torn down.

Hopefully @ekoby can take a look at the android tunneler log and report if there's anything that sticks out there.

7

For more details, this only happens from a RDP of a Windows device. There is no problem with an RDP of a Linux device.

8

I'm confused. Does that mean Android RDP -> Windows fails but Android RDP -> Linux succeeds? If so, it's the same android device?

Is the RDP through the router exclusively? It's not using a windows tunneler to offload towards the RDP server port?

9

I'll let you look at these diagrams:

ziti rdp reset issue
ziti rdp reset issue1024×768 71.3 KB

ziti rdp reset issue (1)
ziti rdp reset issue (1)1024×768 68.6 KB

ziti rdp reset issue (3)
ziti rdp reset issue (3)1024×768 64.1 KB

As we can see, there is a problem with my Android Tunneler.

Here are the logs of the android tunneler:

--------- beginning of main
06-18 19:12:34.846 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: Relayout returned: old=(0,0,1080,2340) new=(0,0,1080,2340) relayoutAsync=false req=(1080,2340)8 dur=8 res=0x402 s={false 0x0} ch=true seqId=0
06-18 19:12:34.851 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: stopped(true) old = false
06-18 19:12:34.851 12706 12706 D ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: WindowStopped on org.openziti.mobile/org.openziti.mobile.ZitiMobileEdgeActivity set to true
06-18 19:12:34.852 12706 12756 D OpenGLRenderer: CacheManager::trimMemory(20)
06-18 19:12:34.859 12706 12706 D InputTransport: Input channel destroyed: 'ClientS', fd=138
06-18 19:12:34.865 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: Relayout returned: old=(0,0,1080,2340) new=(0,0,1080,2340) relayoutAsync=false req=(1080,2340)8 dur=6 res=0x402 s={false 0x0} ch=false seqId=0
06-18 19:12:34.866 12706 12756 D OpenGLRenderer: CacheManager::trimMemory(20)
06-18 19:12:35.143 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: handleAppVisibility mAppVisible = false visible = true
06-18 19:12:35.145 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: stopped(false) old = true
06-18 19:12:35.145 12706 12706 D ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: WindowStopped on org.openziti.mobile/org.openziti.mobile.ZitiMobileEdgeActivity set to false
06-18 19:12:35.147 12706 12706 W WindowOnBackDispatcher: OnBackInvokedCallback is not enabled for the application.
06-18 19:12:35.147 12706 12706 W WindowOnBackDispatcher: Set 'android:enableOnBackInvokedCallback="true"' in the application manifest.
06-18 19:12:35.158 12706 12706 I BufferQueueProducer: [](id:31a200000004,api:0,p:114,c:12706) setDequeueTimeout:2077252342
06-18 19:12:35.158 12706 12706 I BLASTBufferQueue_Java: new BLASTBufferQueue, mName= ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity] mNativeObject= 0xb40000720a60bc00 sc.mNativeObject= 0xb40000720a61f600 caller= android.view.ViewRootImpl.updateBlastSurfaceIfNeeded:3028 android.view.ViewRootImpl.relayoutWindow:10131 android.view.ViewRootImpl.performTraversals:4110 android.view.ViewRootImpl.doTraversal:3288 android.view.ViewRootImpl$TraversalRunnable.run:11344 android.view.Choreographer$CallbackRecord.run:1689 android.view.Choreographer$CallbackRecord.run:1698 android.view.Choreographer.doCallbacks:1153 android.view.Choreographer.doFrame:1079 android.view.Choreographer$FrameDisplayEventReceiver.run:1646 
06-18 19:12:35.158 12706 12706 I BLASTBufferQueue_Java: update, w= 1080 h= 2340 mName = ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity] mNativeObject= 0xb40000720a60bc00 sc.mNativeObject= 0xb40000720a61f600 format= -1 caller= android.graphics.BLASTBufferQueue.<init>:89 android.view.ViewRootImpl.updateBlastSurfaceIfNeeded:3028 android.view.ViewRootImpl.relayoutWindow:10131 android.view.ViewRootImpl.performTraversals:4110 android.view.ViewRootImpl.doTraversal:3288 android.view.ViewRootImpl$TraversalRunnable.run:11344 
06-18 19:12:35.158 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: Relayout returned: old=(0,0,1080,2340) new=(0,0,1080,2340) relayoutAsync=false req=(1080,2340)0 dur=6 res=0x403 s={true 0xb40000728a2c6000} ch=true seqId=0
06-18 19:12:35.159 12706 12706 D ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: mThreadedRenderer.initialize() mSurface={isValid=true 0xb40000728a2c6000} hwInitialized=true
06-18 19:12:35.159 12706 12706 D ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: reportNextDraw android.view.ViewRootImpl.performTraversals:4718 android.view.ViewRootImpl.doTraversal:3288 android.view.ViewRootImpl$TraversalRunnable.run:11344 android.view.Choreographer$CallbackRecord.run:1689 android.view.Choreographer$CallbackRecord.run:1698 
06-18 19:12:35.159 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: Setup new sync=wmsSync-ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]#8
06-18 19:12:35.159 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: Creating new active sync group ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]#9
06-18 19:12:35.160 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: registerCallbacksForSync syncBuffer=false
06-18 19:12:35.165 12706 12768 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: Received frameDrawingCallback syncResult=0 frameNum=1.
06-18 19:12:35.165 12706 12768 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: mWNT: t=0xb4000072204c1b00 mBlastBufferQueue=0xb40000720a60bc00 fn= 1 mRenderHdrSdrRatio=1.0 caller= android.view.ViewRootImpl$8.onFrameDraw:13841 android.view.ThreadedRenderer$1.onFrameDraw:792 <bottom of call stack> 
06-18 19:12:35.165 12706 12768 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: Setting up sync and frameCommitCallback
06-18 19:12:35.166 12706 12756 I BLASTBufferQueue: [ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]#4](f:0,a:0,s:0) onFrameAvailable the first frame is available
06-18 19:12:35.166 12706 12756 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: Received frameCommittedCallback lastAttemptedDrawFrameNum=1 didProduceBuffer=true
06-18 19:12:35.167 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: reportDrawFinished seqId=0
06-18 19:12:35.176 12706 12706 I InsetsSourceConsumer: applyRequestedVisibilityToControl: visible=true, type=navigationBars, host=org.openziti.mobile/org.openziti.mobile.ZitiMobileEdgeActivity
06-18 19:12:35.176 12706 12706 I InsetsSourceConsumer: applyRequestedVisibilityToControl: visible=true, type=statusBars, host=org.openziti.mobile/org.openziti.mobile.ZitiMobileEdgeActivity
06-18 19:12:35.210 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: handleWindowFocusChanged: 1 0 call from android.view.ViewRootImpl.-$$Nest$mhandleWindowFocusChanged:0
06-18 19:12:35.210 12706 12706 D ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: mThreadedRenderer.initializeIfNeeded()#2 mSurface={isValid=true 0xb40000728a2c6000}
06-18 19:12:35.210 12706 12706 D InputMethodManagerUtils: startInputInner - Id : 0
06-18 19:12:35.210 12706 12706 I InputMethodManager: startInputInner - IInputMethodManagerGlobalInvoker.startInputOrWindowGainedFocus
06-18 19:12:35.218 12706 12706 I InsetsSourceConsumer: applyRequestedVisibilityToControl: visible=false, type=ime, host=org.openziti.mobile/org.openziti.mobile.ZitiMobileEdgeActivity
06-18 19:12:35.219 12706 12723 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: Resizing android.view.ViewRootImpl@4083ee2: frame = [0,0][1080,2340] reportDraw = false forceLayout = false syncSeqId = -1
06-18 19:12:35.226 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: handleResized, msg = 4 frames=ClientWindowFrames{frame=[0,0][1080,2340] display=[0,0][1080,2340] parentFrame=[0,0][0,0]} forceNextWindowRelayout=false displayId=0 dragResizing=false compatScale=1.0 frameChanged=false attachedFrameChanged=false configChanged=false displayChanged=false compatScaleChanged=false
06-18 19:12:36.834 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: ViewPostIme pointer 0
06-18 19:12:36.882 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: ViewPostIme pointer 1
06-18 19:12:36.883 12706 12706 D AnimatorSet: mReversing is false. Don't call initChildren.
06-18 19:12:38.652 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: ViewPostIme pointer 0
06-18 19:12:39.117 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: ViewPostIme pointer 1
06-18 19:12:44.744 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: ViewPostIme pointer 0
06-18 19:12:44.808 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: ViewPostIme pointer 1
06-18 19:12:44.809 12706 12706 D AnimatorSet: mReversing is false. Don't call initChildren.
06-18 19:12:45.677 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: ViewPostIme pointer 0
06-18 19:12:45.734 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: ViewPostIme pointer 1
06-18 19:12:45.735 12706 12706 D AnimatorSet: mReversing is false. Don't call initChildren.
06-18 19:12:46.679 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: ViewPostIme pointer 0
06-18 19:12:46.727 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: ViewPostIme pointer 1
06-18 19:12:46.730 12706 12706 D AnimatorSet: mReversing is false. Don't call initChildren.
06-18 19:12:47.129 12706 12744 D ziti    : log is 51122 bytes
06-18 19:12:48.574 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: ViewPostIme pointer 0
06-18 19:12:48.663 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: ViewPostIme pointer 1
06-18 19:12:49.878 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: handleWindowFocusChanged: 0 0 call from android.view.ViewRootImpl.-$$Nest$mhandleWindowFocusChanged:0
06-18 19:12:49.878 12706 12706 I ImeFocusController: onPreWindowFocus: skipped, hasWindowFocus=false mHasImeFocus=true
06-18 19:12:49.878 12706 12706 I ImeFocusController: onPostWindowFocus: skipped, hasWindowFocus=false mHasImeFocus=true
06-18 19:12:50.434 12706 15507 D routing : 0 active connections
06-18 19:12:53.409 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: onDisplayChanged oldDisplayState=2 newDisplayState=2
06-18 19:13:00.202 12706 15820 D o.o.i.ZitiContextImpl: [TtZPsc9q4] slept and restarting on t[DefaultDispatcher-worker-13]
06-18 19:13:00.203 12706 17628 D o.o.a.Controller: GET https://HIDDEN_IP/edge/client/v1/current-identity/edge-routers session=clxknr1mk1ninis20n9au6n3b t[OkHttp https://HIDDEN_IP/...]
06-18 19:13:00.203 12706 17629 D o.o.a.Controller: GET https://HIDDEN_IP/edge/client/v1/current-api-session/service-updates session=clxknr1mk1ninis20n9au6n3b t[OkHttp https://HIDDEN_IP/...]
06-18 19:13:00.204 12706 17628 D TrafficStats: tagSocket(6) with statsTag=0xffffffff, statsUid=-1
06-18 19:13:00.204 12706 17629 D TrafficStats: tagSocket(96) with statsTag=0xffffffff, statsUid=-1
06-18 19:13:00.306 12706 15820 D o.o.i.ZitiContextImpl: current edge routers = [EdgeRouter(name=Ubuntu-Server-edge-router, hostname=, supportedProtocols={tls=tls://HIDDEN_IP}, urls=null)]
06-18 19:13:00.306 12706 15820 D o.o.i.ZitiContextImpl: delaying service refresh for 60000ms
06-18 19:13:01.314 12706 12756 D OpenGLRenderer: CacheManager::trimMemory(10)
06-18 19:13:01.938 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: onDisplayChanged oldDisplayState=2 newDisplayState=2
06-18 19:13:02.521 12706 12706 I InsetsSourceConsumer: applyRequestedVisibilityToControl: visible=true, type=navigationBars, host=org.openziti.mobile/org.openziti.mobile.ZitiMobileEdgeActivity
06-18 19:13:02.522 12706 12706 I InsetsSourceConsumer: applyRequestedVisibilityToControl: visible=true, type=statusBars, host=org.openziti.mobile/org.openziti.mobile.ZitiMobileEdgeActivity
06-18 19:13:02.524 12706 12767 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: mWNT: t=0xb40000717ede5600 mBlastBufferQueue=0xb40000720a60bc00 fn= 190 mRenderHdrSdrRatio=1.0 caller= android.view.SyncRtSurfaceTransactionApplier.applyTransaction:96 android.view.SyncRtSurfaceTransactionApplier.lambda$scheduleApply$0:69 android.view.SyncRtSurfaceTransactionApplier.$r8$lambda$SgowXC58rj3PR958kHUfRgLZmvE:0 
06-18 19:13:02.527 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: handleWindowFocusChanged: 1 0 call from android.view.ViewRootImpl.-$$Nest$mhandleWindowFocusChanged:0
06-18 19:13:02.528 12706 12706 D ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: mThreadedRenderer.initializeIfNeeded()#2 mSurface={isValid=true 0xb40000728a2c6000}
06-18 19:13:02.529 12706 12706 D InputMethodManagerUtils: startInputInner - Id : 0
06-18 19:13:02.529 12706 12706 I InputMethodManager: startInputInner - IInputMethodManagerGlobalInvoker.startInputOrWindowGainedFocus
06-18 19:13:03.102 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: ViewPostIme pointer 0
06-18 19:13:03.121 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: ViewPostIme pointer 1
06-18 19:13:03.131 12706 12706 D CompatibilityChangeReporter: Compat change id reported: 147798919; UID 10330; state: ENABLED
06-18 19:13:03.135 12706 12706 I Toast   : show: caller = org.openziti.mobile.ZitiMobileEdgeActivity.onCreate$lambda$27:419 
06-18 19:13:03.136 12706 12706 I Toast   : show: isDexDualMode = false
06-18 19:13:03.136 12706 12706 I Toast   : show: contextDispId = 0 mCustomDisplayId = -1 focusedDisplayId = 0 isActivityContext = false
06-18 19:13:06.984 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: onDisplayChanged oldDisplayState=2 newDisplayState=2
06-18 19:13:07.158 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: onDisplayChanged oldDisplayState=2 newDisplayState=2
06-18 19:13:10.804 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: onDisplayChanged oldDisplayState=2 newDisplayState=2
06-18 19:13:11.200 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: onDisplayChanged oldDisplayState=2 newDisplayState=2
06-18 19:13:13.657 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: onDisplayChanged oldDisplayState=2 newDisplayState=2
06-18 19:13:13.814 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: onDisplayChanged oldDisplayState=2 newDisplayState=2
06-18 19:13:15.107 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: onDisplayChanged oldDisplayState=2 newDisplayState=2
06-18 19:13:20.435 12706 15507 D routing : 0 active connections
06-18 19:13:26.561 12706 12752 V C.1.2.171:48442]: sending m = ct: LatencyType, seq: 2534, repTo: -1, connId: null, body 0 bytes
06-18 19:13:26.593 12706 12752 V C.1.2.171:48442]: got m = ct: ResultType, seq: 5425, repTo: 2534, connId: null, body 0 bytes
06-18 19:13:26.594 12706 12752 V C.1.2.171:48442]: latency[Channel[tls://HIDDEN_IP]] is now 25
06-18 19:13:26.595 12706 12752 D C.1.2.171:48442]: transitioned to Connected(latency=33)
06-18 19:13:50.436 12706 15507 D routing : 0 active connections
06-18 19:14:00.307 12706 16306 D o.o.i.ZitiContextImpl: [TtZPsc9q4] slept and restarting on t[DefaultDispatcher-worker-5]
06-18 19:14:00.308 12706 18526 D o.o.a.Controller: GET https://HIDDEN_IP/edge/client/v1/current-api-session/service-updates session=clxknr1mk1ninis20n9au6n3b t[OkHttp https://HIDDEN_IP/...]
06-18 19:14:00.308 12706 18525 D o.o.a.Controller: GET https://HIDDEN_IP/edge/client/v1/current-identity/edge-routers session=clxknr1mk1ninis20n9au6n3b t[OkHttp https://HIDDEN_IP/...]
06-18 19:14:00.312 12706 18526 D TrafficStats: tagSocket(96) with statsTag=0xffffffff, statsUid=-1
06-18 19:14:00.312 12706 18525 D TrafficStats: tagSocket(6) with statsTag=0xffffffff, statsUid=-1
06-18 19:14:00.478 12706 16306 D o.o.i.ZitiContextImpl: current edge routers = [EdgeRouter(name=Ubuntu-Server-edge-router, hostname=, supportedProtocols={tls=tls://HIDDEN_IP}, urls=null)]
06-18 19:14:00.478 12706 12752 D o.o.i.ZitiContextImpl: delaying service refresh for 60000ms
06-18 19:14:20.435 12706 15507 D routing : 0 active connections
06-18 19:14:26.596 12706 12744 V C.1.2.171:48442]: sending m = ct: LatencyType, seq: 2535, repTo: -1, connId: null, body 0 bytes
06-18 19:14:26.628 12706 12744 V C.1.2.171:48442]: got m = ct: ResultType, seq: 5426, repTo: 2535, connId: null, body 0 bytes
06-18 19:14:26.629 12706 12744 V C.1.2.171:48442]: latency[Channel[tls://HIDDEN_IP]] is now 33
06-18 19:14:26.629 12706 12744 D C.1.2.171:48442]: transitioned to Connected(latency=32)
06-18 19:14:50.435 12706 15507 D routing : 0 active connections
06-18 19:15:00.479 12706 15820 D o.o.i.ZitiContextImpl: [TtZPsc9q4] slept and restarting on t[DefaultDispatcher-worker-2]
06-18 19:15:00.481 12706 18698 D o.o.a.Controller: GET https://HIDDEN_IP/edge/client/v1/current-api-session/service-updates session=clxknr1mk1ninis20n9au6n3b t[OkHttp https://HIDDEN_IP/...]
06-18 19:15:00.481 12706 18696 D o.o.a.Controller: GET https://HIDDEN_IP/edge/client/v1/current-identity/edge-routers session=clxknr1mk1ninis20n9au6n3b t[OkHttp https://HIDDEN_IP/...]
06-18 19:15:00.484 12706 18698 D TrafficStats: tagSocket(96) with statsTag=0xffffffff, statsUid=-1
06-18 19:15:00.484 12706 18696 D TrafficStats: tagSocket(6) with statsTag=0xffffffff, statsUid=-1
06-18 19:15:00.641 12706 12752 D o.o.i.ZitiContextImpl: current edge routers = [EdgeRouter(name=Ubuntu-Server-edge-router, hostname=, supportedProtocols={tls=tls://HIDDEN_IP}, urls=null)]
06-18 19:15:00.641 12706 12752 D o.o.i.ZitiContextImpl: delaying service refresh for 60000ms
06-18 19:15:20.436 12706 15507 D routing : 0 active connections
06-18 19:15:26.631 12706 12752 V C.1.2.171:48442]: sending m = ct: LatencyType, seq: 2536, repTo: -1, connId: null, body 0 bytes
06-18 19:15:26.659 12706 15819 V C.1.2.171:48442]: got m = ct: ResultType, seq: 5427, repTo: 2536, connId: null, body 0 bytes
06-18 19:15:26.660 12706 15819 V C.1.2.171:48442]: latency[Channel[tls://HIDDEN_IP]] is now 32
06-18 19:15:26.660 12706 15819 D C.1.2.171:48442]: transitioned to Connected(latency=28)
06-18 19:15:26.665 12706 12720 D InputTransport: Input channel destroyed: 'ClientS', fd=137
06-18 19:15:50.436 12706 15507 D routing : 0 active connections
06-18 19:16:00.643 12706 15819 D o.o.i.ZitiContextImpl: [TtZPsc9q4] slept and restarting on t[DefaultDispatcher-worker-8]
06-18 19:16:00.644 12706 18787 D o.o.a.Controller: GET https://HIDDEN_IP/edge/client/v1/current-identity/edge-routers session=clxknr1mk1ninis20n9au6n3b t[OkHttp https://HIDDEN_IP/...]
06-18 19:16:00.644 12706 18788 D o.o.a.Controller: GET https://HIDDEN_IP/edge/client/v1/current-api-session/service-updates session=clxknr1mk1ninis20n9au6n3b t[OkHttp https://HIDDEN_IP/...]
06-18 19:16:00.647 12706 18787 D TrafficStats: tagSocket(6) with statsTag=0xffffffff, statsUid=-1
06-18 19:16:00.647 12706 18788 D TrafficStats: tagSocket(96) with statsTag=0xffffffff, statsUid=-1
06-18 19:16:00.771 12706 15819 D o.o.i.ZitiContextImpl: current edge routers = [EdgeRouter(name=Ubuntu-Server-edge-router, hostname=, supportedProtocols={tls=tls://HIDDEN_IP}, urls=null)]
06-18 19:16:00.772 12706 15819 D o.o.i.ZitiContextImpl: delaying service refresh for 60000ms
06-18 19:16:20.436 12706 15507 D routing : 0 active connections
06-18 19:16:26.661 12706 15819 V C.1.2.171:48442]: sending m = ct: LatencyType, seq: 2537, repTo: -1, connId: null, body 0 bytes
06-18 19:16:26.696 12706 15819 V C.1.2.171:48442]: got m = ct: ResultType, seq: 5428, repTo: 2537, connId: null, body 0 bytes
06-18 19:16:26.697 12706 12752 V C.1.2.171:48442]: latency[Channel[tls://HIDDEN_IP]] is now 28
06-18 19:16:26.697 12706 12752 D C.1.2.171:48442]: transitioned to Connected(latency=35)
06-18 19:16:40.032 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: onDisplayChanged oldDisplayState=2 newDisplayState=2
06-18 19:16:42.229 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: onDisplayChanged oldDisplayState=2 newDisplayState=2
06-18 19:16:42.388 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: onDisplayChanged oldDisplayState=2 newDisplayState=2
06-18 19:16:43.910 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: onDisplayChanged oldDisplayState=2 newDisplayState=2
06-18 19:16:50.437 12706 15507 D routing : 0 active connections
06-18 19:17:00.773 12706 15819 D o.o.i.ZitiContextImpl: [TtZPsc9q4] slept and restarting on t[DefaultDispatcher-worker-8]
06-18 19:17:00.775 12706 18980 D o.o.a.Controller: GET https://HIDDEN_IP/edge/client/v1/current-identity/edge-routers session=clxknr1mk1ninis20n9au6n3b t[OkHttp https://HIDDEN_IP/...]
06-18 19:17:00.775 12706 18982 D o.o.a.Controller: GET https://HIDDEN_IP/edge/client/v1/current-api-session/service-updates session=clxknr1mk1ninis20n9au6n3b t[OkHttp https://HIDDEN_IP/...]
06-18 19:17:00.778 12706 18982 D TrafficStats: tagSocket(6) with statsTag=0xffffffff, statsUid=-1
06-18 19:17:00.778 12706 18980 D TrafficStats: tagSocket(96) with statsTag=0xffffffff, statsUid=-1
06-18 19:17:00.979 12706 12752 D o.o.i.ZitiContextImpl: current edge routers = [EdgeRouter(name=Ubuntu-Server-edge-router, hostname=, supportedProtocols={tls=tls://HIDDEN_IP}, urls=null)]
06-18 19:17:00.979 12706 12752 D o.o.i.ZitiContextImpl: delaying service refresh for 60000ms
06-18 19:17:20.436 12706 15507 D routing : 0 active connections
06-18 19:17:26.698 12706 12752 V C.1.2.171:48442]: sending m = ct: LatencyType, seq: 2538, repTo: -1, connId: null, body 0 bytes
06-18 19:17:26.722 12706 12752 V C.1.2.171:48442]: got m = ct: ResultType, seq: 5429, repTo: 2538, connId: null, body 0 bytes
06-18 19:17:26.722 12706 12752 V C.1.2.171:48442]: latency[Channel[tls://HIDDEN_IP]] is now 35
06-18 19:17:26.723 12706 12752 D C.1.2.171:48442]: transitioned to Connected(latency=24)
06-18 19:17:50.437 12706 15507 D routing : 0 active connections
06-18 19:18:00.980 12706 12744 D o.o.i.ZitiContextImpl: [TtZPsc9q4] slept and restarting on t[DefaultDispatcher-worker-1]
06-18 19:18:00.981 12706 19121 D o.o.a.Controller: GET https://HIDDEN_IP/edge/client/v1/current-identity/edge-routers session=clxknr1mk1ninis20n9au6n3b t[OkHttp https://HIDDEN_IP/...]
06-18 19:18:00.982 12706 19122 D o.o.a.Controller: GET https://HIDDEN_IP/edge/client/v1/current-api-session/service-updates session=clxknr1mk1ninis20n9au6n3b t[OkHttp https://HIDDEN_IP/...]
06-18 19:18:00.984 12706 19122 D TrafficStats: tagSocket(96) with statsTag=0xffffffff, statsUid=-1
06-18 19:18:00.985 12706 19121 D TrafficStats: tagSocket(6) with statsTag=0xffffffff, statsUid=-1
06-18 19:18:01.167 12706 12752 D o.o.i.ZitiContextImpl: current edge routers = [EdgeRouter(name=Ubuntu-Server-edge-router, hostname=, supportedProtocols={tls=tls://HIDDEN_IP}, urls=null)]
06-18 19:18:01.167 12706 12752 D o.o.i.ZitiContextImpl: delaying service refresh for 60000ms
06-18 19:18:20.437 12706 15507 D routing : 0 active connections
06-18 19:18:26.723 12706 12752 V C.1.2.171:48442]: sending m = ct: LatencyType, seq: 2539, repTo: -1, connId: null, body 0 bytes
06-18 19:18:26.757 12706 12744 V C.1.2.171:48442]: got m = ct: ResultType, seq: 5430, repTo: 2539, connId: null, body 0 bytes
06-18 19:18:26.757 12706 12744 V C.1.2.171:48442]: latency[Channel[tls://HIDDEN_IP]] is now 24
06-18 19:18:26.757 12706 12744 D C.1.2.171:48442]: transitioned to Connected(latency=33)
06-18 19:18:50.438 12706 15507 D routing : 0 active connections
06-18 19:19:01.168 12706 15819 D o.o.i.ZitiContextImpl: [TtZPsc9q4] slept and restarting on t[DefaultDispatcher-worker-8]
06-18 19:19:01.170 12706 19177 D o.o.a.Controller: GET https://HIDDEN_IP/edge/client/v1/current-identity/edge-routers session=clxknr1mk1ninis20n9au6n3b t[OkHttp https://HIDDEN_IP/...]
06-18 19:19:01.170 12706 19179 D o.o.a.Controller: GET https://HIDDEN_IP/edge/client/v1/current-api-session/service-updates session=clxknr1mk1ninis20n9au6n3b t[OkHttp https://HIDDEN_IP/...]
06-18 19:19:01.173 12706 19177 D TrafficStats: tagSocket(6) with statsTag=0xffffffff, statsUid=-1
06-18 19:19:01.173 12706 19179 D TrafficStats: tagSocket(96) with statsTag=0xffffffff, statsUid=-1
06-18 19:19:01.255 12706 15819 D o.o.i.ZitiContextImpl: current edge routers = [EdgeRouter(name=Ubuntu-Server-edge-router, hostname=, supportedProtocols={tls=tls://HIDDEN_IP}, urls=null)]
06-18 19:19:01.256 12706 15819 D o.o.i.ZitiContextImpl: delaying service refresh for 60000ms
06-18 19:19:20.438 12706 15507 D routing : 0 active connections
06-18 19:19:26.759 12706 15819 V C.1.2.171:48442]: sending m = ct: LatencyType, seq: 2540, repTo: -1, connId: null, body 0 bytes
06-18 19:19:26.790 12706 15819 V C.1.2.171:48442]: got m = ct: ResultType, seq: 5431, repTo: 2540, connId: null, body 0 bytes
06-18 19:19:26.791 12706 15819 V C.1.2.171:48442]: latency[Channel[tls://HIDDEN_IP]] is now 33
06-18 19:19:26.791 12706 15819 D C.1.2.171:48442]: transitioned to Connected(latency=32)
06-18 19:19:50.439 12706 15507 D routing : 0 active connections
06-18 19:20:01.257 12706 12744 D o.o.i.ZitiContextImpl: [TtZPsc9q4] slept and restarting on t[DefaultDispatcher-worker-1]
06-18 19:20:01.258 12706 19377 D o.o.a.Controller: GET https://HIDDEN_IP/edge/client/v1/current-identity/edge-routers session=clxknr1mk1ninis20n9au6n3b t[OkHttp https://HIDDEN_IP/...]
06-18 19:20:01.259 12706 19378 D o.o.a.Controller: GET https://HIDDEN_IP/edge/client/v1/current-api-session/service-updates session=clxknr1mk1ninis20n9au6n3b t[OkHttp https://HIDDEN_IP/...]
06-18 19:20:01.262 12706 19377 D TrafficStats: tagSocket(6) with statsTag=0xffffffff, statsUid=-1
06-18 19:20:01.262 12706 19378 D TrafficStats: tagSocket(96) with statsTag=0xffffffff, statsUid=-1
06-18 19:20:01.360 12706 12744 D o.o.i.ZitiContextImpl: current edge routers = [EdgeRouter(name=Ubuntu-Server-edge-router, hostname=, supportedProtocols={tls=tls://HIDDEN_IP}, urls=null)]
06-18 19:20:01.360 12706 12744 D o.o.i.ZitiContextImpl: delaying service refresh for 60000ms
06-18 19:20:20.438 12706 15507 D routing : 0 active connections
06-18 19:20:24.333 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: ViewPostIme pointer 0
06-18 19:20:24.376 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: onDisplayChanged oldDisplayState=2 newDisplayState=2
06-18 19:20:25.189 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: ViewPostIme pointer 1
06-18 19:20:25.756 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: ViewPostIme pointer 0
06-18 19:20:25.865 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: ViewPostIme pointer 1
06-18 19:20:26.424 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: ViewPostIme pointer 0
06-18 19:20:26.792 12706 12744 V C.1.2.171:48442]: sending m = ct: LatencyType, seq: 2541, repTo: -1, connId: null, body 0 bytes
06-18 19:20:26.817 12706 12744 V C.1.2.171:48442]: got m = ct: ResultType, seq: 5432, repTo: 2541, connId: null, body 0 bytes
06-18 19:20:26.818 12706 12744 V C.1.2.171:48442]: latency[Channel[tls://HIDDEN_IP]] is now 32
06-18 19:20:26.818 12706 12744 D C.1.2.171:48442]: transitioned to Connected(latency=25)
06-18 19:20:26.900 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: ViewPostIme pointer 1
06-18 19:20:27.517 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: ViewPostIme pointer 0
06-18 19:20:27.609 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: ViewPostIme pointer 1
06-18 19:20:27.610 12706 12706 D AnimatorSet: mReversing is false. Don't call initChildren.
06-18 19:20:28.898 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: ViewPostIme pointer 0
06-18 19:20:28.960 12706 12706 I ViewRootImpl@4ba2b95[ZitiMobileEdgeActivity]: ViewPostIme pointer 1
06-18 19:20:28.962 12706 12706 D AnimatorSet: mReversing is false. Don't call initChildren.

There is no tunneler windows' side

On android, I am using https://play.google.com/store/apps/details?id=com.microsoft.rdc.androidx as RDP client.

10

Ok. Thanks. I didn't understand you at first but the diagrams help clarify. I scanned through those android logs and this time I do see one error in there:

06-17 21:06:19.585 26700 26790 E routing : invalid state. No connection found for [(/100.64.0.0:52218, /100.64.1.4:3389)]. packet is dropped

@ekoby -- you see anything in here that gives us any clue as to what might be happening?

1 Like
11

Hi,
I had the same problem too. I use a android device remote desktop to a windows 10 and a win server 2k8 via openziti network.

  • android tunneler RDP to win server 2k8 work perfect.
  • android tunneler RDP to windows 10 disconnect after short time (10-20s).
    I also use remote desktop app on my android phone, i reinstall old version this app (10.0.18.1254) via file apk, now it work normal with 2 windows device.
12

Hi,

Okay, but I think the problem comes from the tunneler because I also tried to connect with the same RDP app without the Ziti overlay (port forwarding :grimacing:), and it worked perfectly without any disconnection.

13

Yes. It appears that two different people have confirmed there's some issue with the Android tunneler that will need to be looked into. (Thanks @vietdh for the confirmation that an older version works fine and welcome to the community and to OpenZiti!)

14

@vietdh I just want to clarify: the old version of Microsoft RDP for Android works fine. It is the latest version of RDP client that you have a problem with, did I get that right?

15

As we can see, yes.

I think it is a kind of change in the application's behavior from the old version of RDP to the current version that may disrupt the operation of the OpenZiti tunneler (because I have no disconnection problems without OpenZiti on the current version).

16

the connection close is initiated by the peer app (MS RDP) as far as I can see -- we get a TCP packet with FIN set:

...
06-17 21:06:17.975 26700 27882 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: received flags[ACK,FIN] seq[3242632215] ack[155482] ws[964 (15794176)]
06-17 21:06:17.975 26700 27882 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: state[ESTABLISHED] <- ACK,FIN data[0]
06-17 21:06:17.976 26700 27882 D tcp-conn: tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389/ESTABLISHED transitioning to CLOSE_WAIT
06-17 21:06:17.976 26700 27882 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: made packet[32] flags[ACK,FIN] seq[155482] ack[3242632216] data[null]
06-17 21:06:17.976 26700 27882 D tcp:/100.64.0.0:49080 -> /100.64.1.4:3389: sending to peer packet_size[52]
06-17 21:06:17.977 26700 26790 V routing : got msg[(/100.64.0.0:49080, /100.64.1.4:3389)]: 52 bytes
06-17 21:06:17.977 26700 26737 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: received flags[ACK] seq[3242632216] ack[155483] ws[964 (15794176)]
06-17 21:06:17.977 26700 26737 V tcp:/100.64.0.0:49080 -> acer-rdp.ziti/100.64.1.4:3389: state[CLOSE_WAIT] <- ACK data[0]
06-17 21:06:17.984 26700 26741 V C.1.2.171:48442]: got m = ct: StateClosed, seq: 763, repTo: -1, connId: 2, body 12 bytes
06-17 21:06:17.984 26700 26741 V ziti-conn[TtZPsc9q4/2]: conn[2] received message[StateClosed] with seq[231]
06-17 21:06:17.984 26700 26741 V ziti-conn[TtZPsc9q4/2]: signaling EOF
06-17 21:06:17.984 26700 26741 D ziti-conn[TtZPsc9q4/2]: sending FIN
06-17 21:06:17.984 26700 26741 D ziti-conn[TtZPsc9q4/2]: closing conn = 2
17

I also noticed that the old version of the RDP app on Android was using TLSv1.2 while the new version uses TLSv1.3.
This may be a cause of the malfunctioning of the OpenZiti network which may not be a compatible protocol?

18

it shouldn't matter to OpenZiti since we pass data (in this case TLS frames) as is.

Is it possible -- as an exercise -- to make RDP client use TLS 1.2?

19

This is very strange.

On my android phone, I use the RDP version 10.0.18.1254.
My RDP server have Windows 11 Pro up to date.

With the RDP version 10.0.18.1254, the encryption used is tls v1.2 and it works perfectly with this protocol (no interruption).

Following this tutorial to change the encryption on my windows 11 Pro: Forcing RDP to use TLS Encryption | Dispel
I also changed the encryption level to "compatible with client".
The encryption protocol changed from tls v1.2 to tls v1.3 (without updating my RDP phone).
And the problem I had with TLS 1.3 happened again (working with port forwarding, but not working with openziti).
So I updated the android RDP app, and it doesnt fix anything.

Now I changed the encryption layer (previously configure with GPO to SSL) to unconfigured to see if it works.
It always use TLS v1.3 (because I updated the android RDP app) even if encryption is set to "low". And the problem persists.

So I think there is definitely a problem with this TLS protocol from the old Android RDP client to the current client.

20

thank you for providing additional information, a few more questions:

  • what do you use on the RDP server(s) side - ziti-edge-tunnel?
  • is it one tunneler for your Windows and Linux server or are they separate?
  • what versions of it/them do you use?