portfwd: Fix handling the last UDP message

[nirs]

PacketCon.ReadFrom documentation says[1]:

Callers should always process the n > 0 bytes returned before
considering the error err.

But we handled err first, and dropped the last read bytes. Fixed by sending a message if n > 0, and handling the error after the send.

I'm not sure what how this bug affects the system. It was found while reviewing #2969.

stream.Recv() does is not documented, but the trivial implementation ensure that we get nil message on any error. Add comment to make it more clear.

[1] https://pkg.go.dev/net#PacketConn

Fixes #2970

Thanks: Tamir Duberstein [email protected]

[jandubois]

Thanks, LGTM

[nirs]

Thanks, LGTM

Note that I did not test yet, trying to setup UDP port forwarding now...

[nirs]

@balajiv113 is this fixed in tcpproxy that you want to use in #2985?

[nirs]

I tested this change and latest release (1.0.2) to make sure this is not a regression introduced recently and I see the same behavior.

• ssh forwarder: ok
  • iperf3: ok
  • copy file: ok
  • disconnect on host: detected in guest
• grpc forwarder/tcp:
  • iperf3: ok
  • copy file: ok
  • disconnect on host: not detected in guest
• grpc forwarder/udp:
  • iperf3: cannot test since udp usage is dynamic
    • @balajiv113 suggested a hack to listen to both tcp and udp for testing, I did not try yet
  • typing: nc disconnects after sending 2-3 lines to guest, or after few seconds
  • disconnect on host: not detect in guest - I think this is expected, since there is not connection involved, there is no way the host or the guest can detect a disconnect
  • copy file small: ok
  • copy file big: not all data transferred, maybe because port forwarding closed, or maybe macOS dropped packet because buffer space is not available (ENOBUFS).

Created test vm

_output/bin/limactl create --tty=0 --name=test

Enable UDP port forwarding:

portForwards:
 - guestIP: "127.0.0.1"
   hostIP: "127.0.0.1"
   proto: any

Testing SSH forwarder

setup:

_output/bin/limactl start test
_output/bin/limactl shell test sudo apt-get update
_output/bin/limactl shell test sudo apt-get install iperf3
_output/bin/limactl shell test sudo systemctl enable iperf3 --now

iperf3 (host to vm):

```console
% iperf3 -c 127.0.0.1     
Connecting to host 127.0.0.1, port 5201
[  5] local 127.0.0.1 port 63456 connected to 127.0.0.1 port 5201
[ ID] Interval           Transfer     Bitrate
[  5]   0.00-1.00   sec   319 MBytes  2.68 Gbits/sec                  
[  5]   1.00-2.00   sec   315 MBytes  2.64 Gbits/sec                  
[  5]   2.00-3.00   sec   314 MBytes  2.64 Gbits/sec                  
[  5]   3.00-4.00   sec   300 MBytes  2.52 Gbits/sec                  
[  5]   4.00-5.00   sec   323 MBytes  2.71 Gbits/sec                  
[  5]   5.00-6.00   sec   318 MBytes  2.67 Gbits/sec                  
[  5]   6.00-7.00   sec   301 MBytes  2.52 Gbits/sec                  
[  5]   7.00-8.00   sec   313 MBytes  2.62 Gbits/sec                  
[  5]   8.00-9.00   sec   310 MBytes  2.60 Gbits/sec                  
[  5]   9.00-10.00  sec   318 MBytes  2.66 Gbits/sec                  
- - - - - - - - - - - - - - - - - - - - - - - - -
[ ID] Interval           Transfer     Bitrate
[  5]   0.00-10.00  sec  3.06 GBytes  2.63 Gbits/sec                  sender
[  5]   0.00-10.01  sec  3.05 GBytes  2.62 Gbits/sec                  receiver

copy file - guest:

$ nc -l 127.0.0.1 6666 > test.data
(nc exits after file was host disconnected)
$ sha256sum test.data 
64e7339a0293f65863dbc88a052329e0b0666fffbc081c8e02cf90123a1aa20c  test.data

copy file - host:

% time nc 127.0.0.1 6666 < ~/Downloads/lima-1.0.1-Darwin-arm64.tar.gz
nc 127.0.0.1 6666 < ~/Downloads/lima-1.0.1-Darwin-arm64.tar.gz  0.02s user 0.20s system 90% cpu 0.254 total
% sha256sum ~/Downloads/lima-1.0.1-Darwin-arm64.tar.gz 
64e7339a0293f65863dbc88a052329e0b0666fffbc081c8e02cf90123a1aa20c  /Users/nsoffer/Downloads/lima-1.0.1-Darwin-arm64.tar.gz

Testing GRPC forwarder

setup:

LIMA_SSH_PORT_FORWARDER=false _output/bin/limactl start test

TCP

iperf3 (host to vm):

 % iperf3 -c 127.0.0.1                                                
Connecting to host 127.0.0.1, port 5201
[  5] local 127.0.0.1 port 63509 connected to 127.0.0.1 port 5201
[ ID] Interval           Transfer     Bitrate
[  5]   0.00-1.00   sec   454 MBytes  3.81 Gbits/sec                  
[  5]   1.00-2.00   sec   466 MBytes  3.91 Gbits/sec                  
[  5]   2.00-3.00   sec   468 MBytes  3.93 Gbits/sec                  
[  5]   3.00-4.00   sec   467 MBytes  3.92 Gbits/sec                  
[  5]   4.00-5.00   sec   464 MBytes  3.89 Gbits/sec                  
[  5]   5.00-6.00   sec   409 MBytes  3.43 Gbits/sec                  
[  5]   6.00-7.00   sec   439 MBytes  3.68 Gbits/sec                  
[  5]   7.00-8.00   sec   448 MBytes  3.75 Gbits/sec                  
[  5]   8.00-9.00   sec   466 MBytes  3.91 Gbits/sec                  
[  5]   9.00-10.00  sec   459 MBytes  3.85 Gbits/sec                  
- - - - - - - - - - - - - - - - - - - - - - - - -
[ ID] Interval           Transfer     Bitrate
[  5]   0.00-10.00  sec  4.43 GBytes  3.81 Gbits/sec                  sender
[  5]   0.00-10.00  sec  4.43 GBytes  3.81 Gbits/sec                  receiver

copy file - guest:

$ nc -l 127.0.0.1 6666 > test.data
^C
$ sha256sum test.data 
64e7339a0293f65863dbc88a052329e0b0666fffbc081c8e02cf90123a1aa20c  test.data

nc did not exit, had to interrupt it

copy file - host:

% time nc 127.0.0.1 6666 < ~/Downloads/lima-1.0.1-Darwin-arm64.tar.gz
^C
nc 127.0.0.1 6666 < ~/Downloads/lima-1.0.1-Darwin-arm64.tar.gz  0.02s user 0.16s system 1% cpu 14.849 total

nc did not exit, had to interrupt it

UDP

guest:

$ nc -u -l 127.0.0.1 6666
line 1
line 2

nc received only 2 lines

host

% nc -u 127.0.0.1 6666                                          
line 1
line 2
line 3

nc terminated after typing the third line.

ha.stderr.log:

{"level":"debug","msg":"guest agent event: local_ports_added:{protocol:\"udp\"  ip:\"127.0.0.1\"  port:6666}","time":"2024-12-07T02:01:37+02:00"}
{"level":"info","msg":"Forwarding UDP from 127.0.0.1:6666 to 127.0.0.1:6666","time":"2024-12-07T02:01:37+02:00"}
{"level":"debug","msg":"guest agent event: local_ports_removed:{protocol:\"udp\"  ip:\"127.0.0.1\"  port:6666}","time":"2024-12-07T02:02:01+02:00"}
{"level":"debug","msg":"removing listener for hostAddress: 127.0.0.1:6666, guestAddress: 127.0.0.1:6666","time":"2024-12-07T02:02:01+02:00"}
{"level":"debug","msg":"Port forwarding closed proto:udp host:127.0.0.1:6666 guest:127.0.0.1:6666","time":"2024-12-07T02:02:01+02:00"}

Looks like port forwarding was closed while the guest was listening.

Also host and guest agent clocks are not synchronized.

copy file small - guest:

$ nc -u -l 127.0.0.1 6666 > test.data
^C
$ sha256sum test.data 
289cc81bd1c1d86c89031bed62c3498e89124690794b42857a3d5ca86e89443b  test.data

nc did not exit, had to interrupt it.

copy file small - host:

% echo "testing small payload" | nc -u 127.0.0.1 6666 
^C
% echo "testing small payload" | sha256sum           
289cc81bd1c1d86c89031bed62c3498e89124690794b42857a3d5ca86e89443b  -

nc did not exit, had to interrupt it.

copy file big - guest:

$ nc -u -l 127.0.0.1 6666 > test.data
^C

$ ls -lh test.data 
-rw-rw-r-- 1 nsoffer nsoffer 28M Dec  7 02:19 test.data
$ sha256sum test.data 
0af76d53fef7e3b8c66d36df36db6117224f8291d276b55dba00d82fd8d8bb85  test.data

nc did not exit, had to interrupt it.

copy file small - host:

% nc -u 127.0.0.1 6666 < ~/Downloads/lima-1.0.1-Darwin-arm64.tar.gz
^C
% sha256sum ~/Downloads/lima-1.0.1-Darwin-arm64.tar.gz
64e7339a0293f65863dbc88a052329e0b0666fffbc081c8e02cf90123a1aa20c  /Users/nsoffer/Downloads/l

nc did not exit, had to interrupt it.

ha.stderr.log:

{"level":"debug","msg":"guest agent event: local_ports_added:{protocol:\"udp\"  ip:\"127.0.0.1\"  port:6666}","time":"2024-12-07T02:19:25+02:00"}
{"level":"info","msg":"Forwarding UDP from 127.0.0.1:6666 to 127.0.0.1:6666","time":"2024-12-07T02:19:25+02:00"}
{"level":"debug","msg":"guest agent event: local_ports_removed:{protocol:\"udp\"  ip:\"127.0.0.1\"  port:6666}","time":"2024-12-07T02:19:49+02:00"}
{"level":"debug","msg":"removing listener for hostAddress: 127.0.0.1:6666, guestAddress: 127.0.0.1:6666","time":"2024-12-07T02:19:49+02:00"}
{"level":"debug","msg":"Port forwarding closed proto:udp host:127.0.0.1:6666 guest:127.0.0.1:6666","time":"2024-12-07T02:19:49+02:00"}

port forwarding seems to close at the middle of the transfer.

[nirs]

@balajiv113 can you review? this conflicts with #2985 but I think it will take time until it is ready, and we can release this fix in 1.0.3.

[balajiv113]

LGTM 👍

But do we have a usecase which this change fixes ???

[nirs]

But do we have a usecase which this change fixes ???

No, I could not reproduce the issue. This came from: https://github.com/lima-vm/lima/pull/2969/files#r1868401701

[AkihiroSuda]

Thanks