Constant connection drop after pausing and unpausing a Receive Encrypted folder

I’ve experienced this strange issue today after pausing and unpausing a Receive Encrypted folder on the remote device. While doing so, the previously working connection was dropped (as expected), but then it entered this strange cycle of constantly trying to reconnect, and then immediately dropping the connection.

The logs on the sending side are filled with

2021-10-27 12:38:57 Connection to TLFGVKC at [::]:22000-83.6.220.121:22000/quic-client/TLS1.3-TLS_CHACHA20_POLY1305_SHA256 closed: handling index-update for m9sjf-uzd7w: data too short

while on the receiving side they are filled with

2021-10-27 05:47:32 Connection to D4DZUGP at [::]:22000-xxx:22000/quic-server/TLS1.3-TLS_CHACHA20_POLY1305_SHA256 closed: reading message: Application error 0x0: closing
2021-10-27 05:47:38 Established secure connection to D4DZUGP at [::]:22000-xxx:22000/quic-server/TLS1.3-TLS_CHACHA20_POLY1305_SHA256
2021-10-27 05:47:38 Device D4DZUGP client is "syncthing v1.18.4-dev.6.g583db5b5-tomasz86-v1.18.3" named "xxx" at [::]:22000-xxx:22000/quic-server/TLS1.3-TLS_CHACHA20_POLY1305_SHA256
2021-10-27 05:47:41 Connection to D4DZUGP at [::]:22000-xxx:22000/quic-server/TLS1.3-TLS_CHACHA20_POLY1305_SHA256 closed: reading length: EOF

Restarting Syncthing on either device hasn’t brought any change. I’ve only managed to establish a stable connection after pausing the folder again and leaving it in this state for now.

Have you got any idea what is going on here?

Fascinating.

handling index-update for m9sjf-uzd7w: data too short

means we got an index update with a (supposedly) encrypted FileInfo entry, but the actual encrypted data was too short for decryption. (That is, shorter than it could possibly be given that there are some non-optional things like nonce.)

I can’t see how the other side can end up sending such a FileInfo. It’s constructed and encrypted on the fly, so it’s not something that can get permanently corrupted somewhere.

On the receiving side it’s already managed to decrypt the file name when it reaches the point that errors, so it’s not an unencrypted FileInfo it’s looking at either.

Maybe enable lots of debugging and see if anything stands out.

1 Like

I have finally managed to grab the logs. I did the following.

  1. Pause all folders on both devices.
  2. Pause all devices but the one involved on each side.
  3. Exit Syncthing on both sides.
  4. Delete all existing logs.
  5. Start Syncthing on both sides with db and model enabled.
  6. Wait for the two devices to connect with each other.
  7. Unpause the problematic folder on the sending side (D4DZUGP).
  8. Unpause the problematic folder on the receiving side (TLFGVKC).

After performing the last action, the connection began dropping in the same way as reported last time.

Below is the log from the receiving side. I’ve got the log from the sending side too, but this one isn’t encrypted, so I’ll have to obfuscate a lot of stuff before uploading it. It will likely take some time. I’d be very thankful if you can have a look at the file when you’ve got some free time.

syncthing_TLFGVKC_RE.zip (8.5 MB)

Finally had a look. However there’s nothing interesting I’d see. However it also doesn’t have protocol debug facility enabled, and this almost has to be a protocol level issue.

Thanks for looking into the logs :slightly_smiling_face:.

It’s too late, unfortunately, as I decided to drop using Receive Encrypted for now after experiencing this and the other issue (about “access denied”; still unsure what the culprit was).

I’ll come back later with proper logs if I ever experience the same problem again.

1 Like

Another instance of this bug with additional logs here: