[Verse-dev] Verse and Packet Loss

[Emil Brink]

eskil at obsession.se wrote:
> Hi!
> 
>> I've spent quite some time lately testing Verse under degraded
>> network performance.
> 
> Good it needed to be done.

Yes, absolutely.

>> Anyway, I can say this, ainly to Eskil: when the network drops
>> packets, it becomes pretty hard to establish a Verse connection.
>> Once a connec- tion is up, it seems to work pretty well for my test
>> case (uploading a 5120x5120 bitmap), but it's really hard to get
>> there.
> 
> 
> This is interesting. The connection system worked quite differently
> form the rest of the connected protocol. The way it works is
> basically it tries to send the same packets over and over until it
> succeeds. I think it sends one every second or so. How does your
> algorithm work? if it removes x number of packets each second it
> would be very bad for connections since there are so few packets.

Yes, that is more or less how it works. I don't know another way
to simulate, either ... The filter is configured to drop x% of
the packets, and does so by "rolling the dice" for each packet.

It is true that the relatively low rate of resend during connect
really hurts in cases like this, I'm thinking it might be something
to look into.

I think other protocols use a technique called "backoff" to rapidly
decrease the rate of resends until something gets through. This should
have the benefit of quickly re-establishing the connection if the loss
was spurious, while not flooding the net uncontrollably if not.

Perhaps something to try out.

>> I'm also seeing plenty of "Aborting packet decode"-errors in the
>> server end, when trying to connect over a lossy net.
> 
> 
> Interesting, that error keeps popping up for some apps, I still don't
>  know why, and it looks like verse handles the errors very well.
> Still it would be nice to figure it out.

It would, indeed. Here is a packet dump I just did, of the error
occuring:

Client:
sending a 134-byte packet ]
sending a 9-byte packet: [ 00 00 00 02 09 00 00 00 08 ]
sending a 134-byte packet ]
read a 143-byte packet
  Handling connection, stage 1
sending a 70-byte packet: [ 00 00 00 01 00 02 ... ]
Loaded "/home/emil/data/graphics/test-images/Test5120.png", 5120x5120 
pixels, format 2
sending a 9-byte packet: [ 00 00 00 03 07 00 00 00 00 ]
read a 14-byte packet: [ 00 00 00 02 88 9D 01 6D 92 22 D5 55 57 8D ]
read a 73-byte packet
sending a 143-byte packet ]
sending a 16-byte packet: [ 00 00 00 04 18 FD ... 0F DA CA 18 12 FA BC ]
sending a 16-byte packet: [ 00 00 00 04 18 FD ... 0F DA CA 18 12 FA BC ]
read a 9-byte packet: [ 00 00 00 04 18 FD 51 CD 27 ]
sending a 19-byte packet: [ 00 00 00 05 22 35 ... 4D 26 67 DD 61 AD 71 ]
read a 29-byte packet
sending a 14-byte packet: [ 00 00 00 06 50 8D A9 5D 5E 5C FD 05 1F F5 ]

The ellipsis ("...") were inserted manually to keep the lines unwrapped.

The server's corresponding log is:
Verse Server r5p0 by Eskil Steenberg <http://www.blender.org/modules/verse/>
Loaded 512-bit host ID key successfully
read a 134-byte packet
  Handling connection, stage 0
sending a 143-byte packet ]
read a 9-byte packet: [ 00 00 00 02 09 00 00 00 08 ]
read a 70-byte packet
  Handling connection, stage 2
sending a 14-byte packet: [ 00 00 00 02 88 9D 01 6D 92 22 D5 55 57 8D ]
Connecting 'pngload'
vs_node_create(4294967295, 0)
sending a 73-byte packet: [ 00 00 00 01 ...38 75 41 E6 1D 19 2B 48 4A ]
read a 9-byte packet: [ 00 00 00 03 07 00 00 00 00 ]
sending a 14-byte packet: [ 00 00 00 03 94 25 D5 55 54 85 A9 5D 5B 57 ]

** Unknown command ID 148 (0x94) encountered--aborting packet decode 
len=9 pos=5 last=255
  decoded 4 bytes: 00 00 00 03
  (packet id=3) remaining 5 bytes: 94 25 D5 55 57

read a 16-byte packet: [ 00 00 00 04 18 ... CD 22 0F DA CA 18 12 FA BC ]
vs_node_create(0, 3)
sending a 9-byte packet: [ 00 00 00 04 18 FD 51 CD 27 ]
read a 16-byte packet: [ 00 00 00 04 18 ... CD 22 0F DA CA 18 12 FA BC ]
sending a 9-byte packet: [ 00 00 00 04 18 FD 51 CD 27 ]
read a 19-byte packet: [ 00 00 00 05 22 ... EB 35 4D 26 67 DD 61 AD 71 ]
sending a 29-byte packet: [ 00 00 00 05 ... 35 95 37 CE 01 9D 3B 95 5F ]

Again, "..." were inserted manually. I think the 9-byte packet with ID 3 
is the interesting bit, here. For some reason, it seems to be completely
messed up by the decryption? At least that would be my guess. I don't
understand why that particular packet should be hurt like that, though.

Note that the packet is sent out (the client print-out is right before
the sendto() call in v_network.c:v_n_send_data(), so there is no missing
encryption there) as "00 00 00 03 07 00 00 00 00", and the server re-
ceives that from the network (again, the print-out is right after the
recvfrom() in v_network.c:v_n_receive_data()), but *decodes* it as
"00 00 00 03 94 25 D5 55 57". This I just don't get, can you understand
it better, Eskil?

Regards,

/Emil