How to debug TLS Handshake error?

That’s a very outdated branch compared to master, why are you using that one?

Step 2 of what nutomic told me todo

If I build master I end up with:

> Task :core:compileKotlin FAILED
Putting task artifact state for task ':core:compileKotlin' into context took 0.0 secs.
file or directory 'C:\Go\src\github.com\Nutomic\a-sync\core\src\main\java', not found
file or directory 'C:\Go\src\github.com\Nutomic\a-sync\core\build\generated\source\proto\main\javalite', not found
Up-to-date check for task ':core:compileKotlin' took 0.021 secs. It is not up-to-date because:
  Task has failed previously.
All input files are considered out-of-date for incremental task ':core:compileKotlin'.
file or directory 'C:\Go\src\github.com\Nutomic\a-sync\core\src\main\java', not found
file or directory 'C:\Go\src\github.com\Nutomic\a-sync\core\build\generated\source\proto\main\javalite', not found
file or directory 'C:\Go\src\github.com\Nutomic\a-sync\core\src\main\java', not found
file or directory 'C:\Go\src\github.com\Nutomic\a-sync\core\build\generated\source\proto\main\javalite', not found
Using Kotlin incremental compilation
Caught an exception trying to connect to Kotlin Daemon
java.lang.ClassNotFoundException: com.sun.tools.javac.util.Context
        at java.net.URLClassLoader.findClass(Unknown Source)

As usual, building Java is it’s own fucking university degree.

1 Like

Sorry, I said the wrong branch :confused:

Correct branch is change-client-api.

I can run the java, but I can’t get it to connect to anything. Neither -a 192.168.57.3:22000, -a tcp://192.168.57.3:22000 nor -a $someDeviceID results in any action on the receiving side. There’s also no output about it from the java side so I have no idea if it even tries.

I can connect to it on port 12345, but it fails the handshake by attempting to be the client side when it’s the server side.

Can you try with this command: ./gradlew syncthing-java:run -Pargs="-a $deviceId -L". Note the -Pargs and -L.

You should see some output on the java side about running discovery and connecting to devices (this may take a minute or so). Global discovery works fine, and local discovery works as long as there is no other Syncthing instance running on the same host.

There is currently no functionality to run as server, or pass an IP address. But you can apply this patch to connect to a specific IP:

diff --git a/client/src/main/kotlin/net/syncthing/java/client/SyncthingClient.kt b/client/src/main/kotlin/net/syncthing/java/client/SyncthingClient.kt
index cb7eaa7..6195142 100644
--- a/client/src/main/kotlin/net/syncthing/java/client/SyncthingClient.kt
+++ b/client/src/main/kotlin/net/syncthing/java/client/SyncthingClient.kt
@@ -60,6 +60,7 @@ class SyncthingClient(private val configuration: Configuration) : Closeable {
         }.start()
         //val deviceAddress = DeviceAddress.Builder().setAddress("tcp://localhost:${serverSocket.localPort}").setDeviceId(configuration.localDeviceId.deviceId).build()
         //ConnectionHandler(configuration, deviceAddress, indexHandler, { _, _ -> }, {}).connect()
+        openConnection(DeviceAddress("$deviceId", "tcp://127.0.0.1:22000"))
         connectDevicesScheduler.scheduleAtFixedRate(this::updateIndexFromPeers, 0, 15, TimeUnit.SECONDS)
     }

Edit: Then run it with ./gradlew syncthing-java:run -Pargs="-L".

If I patch it like that, it connects, gets some data, then crashes:

10:26:35.317 [pool-8-thread-1] INFO net.syncthing.java.bep.ConnectionHandler - connecting to tcp://192.168.57.3:22000
10:26:35.318 [pool-8-thread-1] DEBUG net.syncthing.java.bep.ConnectionHandler - opening tcp ssl connection
10:26:35.376 [pool-8-thread-1] DEBUG net.syncthing.java.bep.ConnectionHandler - receiving hello message
10:26:35.376 [pool-10-thread-1] DEBUG net.syncthing.java.bep.ConnectionHandler - sending hello message
10:26:35.377 [pool-8-thread-1] INFO net.syncthing.java.bep.ConnectionHandler - Received hello message, deviceName=ubuntu, clientName=syncthing, clientVersion=v0.14.44-rc.2+33-g6361471c-dirty-varblocks
10:26:35.378 [pool-8-thread-1] DEBUG net.syncthing.java.core.security.KeystoreHandler - remote ssl certificate match deviceId = DeviceId(deviceId=NRMEDHY-MTBW4XA-ZW37V5Y-3GI5PZX-F7X4VBI-DRNHLKV-DOQIGBE-37S6IAM)
10:26:35.378 [HandshakeCompletedNotify-Thread] DEBUG net.syncthing.java.core.security.KeystoreHandler - cipherSuite=TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384, peerCertificateChain=[[
[
  Version: V3
  Subject: CN=syncthing
  Signature Algorithm: SHA384withECDSA, OID = 1.2.840.10045.4.3.3

  Key:  Sun EC public key, 384 bits
  public x coord: 17534918768666827907461042776646095702798479836029054739360478557952954447194536718976129570232826488478588170227752
  public y coord: 3215538896734720369883453584891936718603318747992825732371709613701104501532803404190149224666228700300110727039778
  parameters: secp384r1 [NIST P-384] (1.3.132.0.34)
  Validity: [From: Wed Feb 07 09:35:37 CET 2018,
               To: Sat Jan 01 00:59:59 CET 2050]
  Issuer: CN=syncthing
  SerialNumber: [    3f7514b1 9bc7fa9d]

Certificate Extensions: 3
[1]: ObjectId: 2.5.29.19 Criticality=true
BasicConstraints:[
  CA:false
  PathLen: undefined
]

[2]: ObjectId: 2.5.29.37 Criticality=false
ExtendedKeyUsages [
  serverAuth
  clientAuth
]

[3]: ObjectId: 2.5.29.15 Criticality=true
KeyUsage [
  DigitalSignature
  Key_Encipherment
]

]
  Algorithm: [SHA384withECDSA]
  Signature:
0000: 30 64 02 30 69 AA 43 4A   50 81 95 D3 40 D7 B4 50  0d.0i.CJP...@..P
0010: 38 CB 4A 7D DA 3C DF DD   55 62 69 BE F4 42 FF 9E  8.J..<..Ubi..B..
0020: C5 C4 9A C4 D2 E9 0B 4C   BD 1D D6 42 EF B2 7B 03  .......L...B....
0030: D6 A8 70 E6 02 30 4D A6   DF 79 6B 32 7C 43 C0 76  ..p..0M..yk2.C.v
0040: 7B 17 6D C3 C4 BE D5 0A   A7 BB C0 27 E3 61 C9 F4  ..m........'.a..
0050: 3E 07 82 23 D3 A2 CA 69   C5 0D 79 7B 1A 31 36 E6  >..#...i..y..16.
0060: 23 0B 90 DE F4 51                                  #....Q

]], peerCertificates=[Ljava.security.cert.X509Certificate;@6b1f2074, peerPrincipal=CN=syncthing
10:26:35.381 [pool-8-thread-1] INFO net.syncthing.java.repository.repo.SqlRepository - loaded index info from db, index_id = 9847912120723946, current_sequence = 5167202693127920065
10:26:35.384 [pool-10-thread-1] DEBUG net.syncthing.java.bep.ConnectionHandler - sending message type = CLUSTER_CONFIG 457810415
10:26:35.384 [pool-8-thread-1] DEBUG net.syncthing.java.bep.ConnectionHandler - wait for cluster config
10:26:35.384 [pool-11-thread-1] DEBUG net.syncthing.java.bep.ConnectionHandler - receiving message, isClosed=false
10:26:35.419 [pool-11-thread-1] DEBUG net.syncthing.java.bep.ConnectionHandler - message type = CLUSTER_CONFIG compression = LZ4
10:26:35.419 [pool-11-thread-1] WARN net.syncthing.java.bep.ConnectionHandler - received readInt() == 0, expecting 'bep message header length' (int >0), ignoring (keepalive?)
10:26:35.420 [pool-11-thread-1] DEBUG net.syncthing.java.bep.ConnectionHandler - receiving message, isClosed=false
10:26:35.420 [pool-12-thread-1] DEBUG net.syncthing.java.bep.ConnectionHandler - received message type = CLUSTER_CONFIG 501685659
10:26:35.424 [pool-12-thread-1] INFO net.syncthing.java.bep.ConnectionHandler - folder shared from device = NRMEDHY-MTBW4XA-ZW37V5Y-3GI5PZX-F7X4VBI-DRNHLKV-DOQIGBE-37S6IAM folder = ClusterConfigFolderInfo(folderId=default, label=Default Folder, isAnnounced=true, isShared=true)
writing config to /Users/jb/.config/syncthing-java/config.json
10:26:35.425 [pool-12-thread-1] DEBUG net.syncthing.java.bep.IndexHandler - aquired folder info from cluster config = FolderInfo(folderId=default, label=Default Folder)
10:26:35.428 [pool-11-thread-1] DEBUG net.syncthing.java.bep.ConnectionHandler - message type = INDEX compression = NONE
10:26:35.429 [pool-11-thread-1] WARN net.syncthing.java.bep.ConnectionHandler - received readInt() == 0, expecting 'bep message header length' (int >0), ignoring (keepalive?)
10:26:35.430 [pool-10-thread-1] DEBUG net.syncthing.java.bep.ConnectionHandler - sending message type = INDEX 1437706717
10:26:35.432 [pool-11-thread-1] DEBUG net.syncthing.java.bep.ConnectionHandler - receiving message, isClosed=false
10:26:35.432 [pool-12-thread-1] DEBUG net.syncthing.java.bep.ConnectionHandler - received message type = INDEX 1437706717
10:26:35.432 [pool-12-thread-1] INFO net.syncthing.java.bep.IndexHandler - received index message event, preparing (queued records = 0 event record count = 0)
10:26:35.435 [pool-8-thread-1] INFO net.syncthing.java.bep.ConnectionHandler - new folder shared = ClusterConfigFolderInfo(folderId=default, label=Default Folder, isAnnounced=true, isShared=true)
10:26:35.436 [pool-8-thread-1] DEBUG net.syncthing.java.bep.IndexHandler - aquired folder info from cluster config = FolderInfo(folderId=default, label=Default Folder)
10:26:35.437 [pool-12-thread-1] DEBUG net.syncthing.java.bep.IndexHandler - received index message event, queuing for processing
10:26:35.439 [pool-2-thread-1] INFO net.syncthing.java.bep.IndexHandler - processing index message with 0 records (queue size: messages = 1 records = 0)
10:26:35.439 [pool-2-thread-1] DEBUG net.syncthing.java.bep.IndexHandler - processing 0 index records for folder default
10:26:35.442 [pool-2-thread-1] ERROR java.util.concurrent.ExecutorService - 
kotlin.KotlinNullPointerException: null
        at net.syncthing.java.bep.IndexHandler.updateIndexInfo(IndexHandler.kt:182)
        at net.syncthing.java.bep.IndexHandler.access$updateIndexInfo(IndexHandler.kt:34)
        at net.syncthing.java.bep.IndexHandler$IndexMessageProcessor$ProcessingRunnable.doHandleIndexMessageReceivedEvent(IndexHandler.kt:411)
        at net.syncthing.java.bep.IndexHandler$IndexMessageProcessor$processBg$1.runProcess(IndexHandler.kt:326)
        at net.syncthing.java.bep.IndexHandler$IndexMessageProcessor$ProcessingRunnable.run(IndexHandler.kt:353)
        at net.syncthing.java.core.utils.ExecutorUtilsKt$submitLogging$1.invoke(ExecutorUtils.kt:31)
        at net.syncthing.java.core.utils.ExecutorUtilsKt$submitLogging$1.invoke(ExecutorUtils.kt)
        at net.syncthing.java.core.utils.ExecutorUtilsKt$submitLogging$2.call(ExecutorUtils.kt:40)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
        at java.base/java.lang.Thread.run(Thread.java:844)


FAILURE: Build failed with an exception.

The other side is generally happy with it, until it suddenly disconnects due to the crash. LGTM, connection wise.

Not sure what that crash means, haven’t seen that before. Did you accept the java device on the other device? The connection seems to work correctly sometimes, but if you try it again, it will fail to connect sooner or later.

I tried it a few times and it worked. I think the crash is because it didn’t expect a zero sized index.

I assume you didn’t have any folders shared with the java node? I’m starting to think that the problem is some kind of race condition in the index handler. I will try to figure out if there’s anything wrong in that part. Anyway the error message was probably misleading.

Okay I finally figured it out. Turns out I was opening multiple connections to the same device. I never thought to check that because I was only going by the error message.

Also, I just noticed that the java implementation never sent any close messages, so the other side would keep the connection open for some time (making subsequent connections fail too).

Thanks for your help figuring this out!