search

livekit / server-sdk-kotlin

Apache License 2.0
31 stars 15 forks source link

Sending data to a room always causes an exception to fire #59

Closed Perondas closed 1 month ago

Perondas commented 4 months ago

When using io.livekit.server.RoomService.sendData to send any data to a exisintg room an exception is raised. The data does however end up being sent, meaning that members of the room receive the data. The exception being:

kotlin.KotlinNullPointerException: Response from io.livekit.server.RoomService.sendData was null but response body type was declared as non-null
at retrofit2.KotlinExtensions$await$2$2.onResponse(KotlinExtensions.kt:43)
at retrofit2.OkHttpCall$1.onResponse(OkHttpCall.java:161)
at okhttp3.internal.connection.RealCall$AsyncCall.run(RealCall.kt:519)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
at java.base/java.lang.Thread.run(Thread.java:1583)

Steps to reproduce the behavior:

  1. Use io.livekit.server.RoomService.sendData to send any data

Expected behavior No exception is thrown if the request was a success

Device Info:

Perondas commented 4 months ago

May be related to https://github.com/square/retrofit/issues/3595

davidliu commented 2 months ago

Can you turn on logging in your client and post the logs?

PhilippKolmann commented 2 months ago

If needed we can try to dive deeper, hope this helps...

We call this via:

  logger.debug { "Sending call info to LiveKit: $data" }
  roomService.sendData(id.toString(), data.encodeToByteArray(), LivekitModels.DataPacket.Kind.RELIABLE)
    .await()

and this is the output

09:40:06.806 [DefaultDispatcher-worker-3] DEBUG at.xxx.telephony.call.Call session= - Sending call info to LiveKit: {"type":"newCallInfo","info":{"id":"c9574502-a945-4b70-9665-144a1d45d7ec","owner":"6cfaaa4c-eac7-4858-b968-c468a71cb2cc","participants":[{"id":"6cfaaa4c-eac7-4858-b968-c468a71cb2cc","state":"ACTIVE"},{"id":"9c716d48-8916-42d5-a840-2c66789946c0","state":"INVITED"}],"state":"WAITING","startTime":1718790005,"participantEvents":[{"userId":"6cfaaa4c-eac7-4858-b968-c468a71cb2cc","action":"created","timeStamp":1718790005000,"initiator":"6cfaaa4c-eac7-4858-b968-c468a71cb2cc"},{"userId":"6cfaaa4c-eac7-4858-b968-c468a71cb2cc","action":"joined","timeStamp":1718790006000,"initiator":null},{"userId":"9c716d48-8916-42d5-a840-2c66789946c0","action":"invited","timeStamp":1718790006000,"initiator":"6cfaaa4c-eac7-4858-b968-c468a71cb2cc"}]}}
09:40:06.811 [DefaultDispatcher-worker-3] ERROR at.xxx.telephony.call.Call session= - Could not send call info to LiveKit: Response from io.livekit.server.RoomService.sendData was null but response body type was declared as non-null
kotlin.KotlinNullPointerException: Response from io.livekit.server.RoomService.sendData was null but response body type was declared as non-null
    at retrofit2.KotlinExtensions$await$2$2.onResponse(KotlinExtensions.kt:43)
    at retrofit2.OkHttpCall$1.onResponse(OkHttpCall.java:161)
    at okhttp3.internal.connection.RealCall$AsyncCall.run(RealCall.kt:519)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
    at java.base/java.lang.Thread.run(Thread.java:1583)
davidliu commented 2 months ago

Turn on logging by passing true to the logging parameter when creating the RoomServiceClient.

PhilippKolmann commented 2 months ago

Thanks for your understanding. I have taken over from my collegue and I have not so much knowledge on livekit so far....

Here are the logs:

06:01:51.862 [DefaultDispatcher-worker-3] DEBUG at.xxx.telephony.call.Call session= - Sending call info to LiveKit: {"type":"newCallInfo","info":{"id":"458b5e6c-3146-4506-b3ec-a3116a4444ef","owner":"6cfaaa4c-eac7-4858-b968-c468a71cb2cc","participants":[{"id":"6cfaaa4c-eac7-4858-b968-c468a71cb2cc","state":"ACTIVE"},{"id":"9c716d48-8916-42d5-a840-2c66789946c0","state":"ACCEPTED"}],"state":"STARTED","startTime":1718863307,"participantEvents":[{"userId":"6cfaaa4c-eac7-4858-b968-c468a71cb2cc","action":"CREATED","timeStamp":1718863307000,"initiator":"6cfaaa4c-eac7-4858-b968-c468a71cb2cc"},{"userId":"6cfaaa4c-eac7-4858-b968-c468a71cb2cc","action":"JOINED","timeStamp":1718863309000,"initiator":null},{"userId":"9c716d48-8916-42d5-a840-2c66789946c0","action":"INVITED","timeStamp":1718863309000,"initiator":"6cfaaa4c-eac7-4858-b968-c468a71cb2cc"},{"userId":"9c716d48-8916-42d5-a840-2c66789946c0","action":"ACCEPTED","timeStamp":1718863311000,"initiator":null}]}}
Jun 20, 2024 6:01:51 AM okhttp3.internal.platform.Platform log
INFO: --> POST https://lk.exp.xxx.at/twirp/livekit.RoomService/SendData
Jun 20, 2024 6:01:51 AM okhttp3.internal.platform.Platform log
INFO: Content-Type: application/protobuf
Jun 20, 2024 6:01:51 AM okhttp3.internal.platform.Platform log
INFO: Content-Length: 887
Jun 20, 2024 6:01:51 AM okhttp3.internal.platform.Platform log
INFO: Authorization: Bearer XXX
Jun 20, 2024 6:01:51 AM okhttp3.internal.platform.Platform log
INFO: 
Jun 20, 2024 6:01:51 AM okhttp3.internal.platform.Platform log
INFO: 
$458b5e6c-3146-4506-b3ec-a3116a4444ef�{"type":"newCallInfo","info":{"id":"458b5e6c-3146-4506-b3ec-a3116a4444ef","owner":"6cfaaa4c-eac7-4858-b968-c468a71cb2cc","participants":[{"id":"6cfaaa4c-eac7-4858-b968-c468a71cb2cc","state":"ACTIVE"},{"id":"9c716d48-8916-42d5-a840-2c66789946c0","state":"ACCEPTED"}],"state":"STARTED","startTime":1718863307,"participantEvents":[{"userId":"6cfaaa4c-eac7-4858-b968-c468a71cb2cc","action":"CREATED","timeStamp":1718863307000,"initiator":"6cfaaa4c-eac7-4858-b968-c468a71cb2cc"},{"userId":"6cfaaa4c-eac7-4858-b968-c468a71cb2cc","action":"JOINED","timeStamp":1718863309000,"initiator":null},{"userId":"9c716d48-8916-42d5-a840-2c66789946c0","action":"INVITED","timeStamp":1718863309000,"initiator":"6cfaaa4c-eac7-4858-b968-c468a71cb2cc"},{"userId":"9c716d48-8916-42d5-a840-2c66789946c0","action":"ACCEPTED","timeStamp":1718863311000,"initiator":null}]}}
Jun 20, 2024 6:01:51 AM okhttp3.internal.platform.Platform log
INFO: --> END POST (887-byte body)
Jun 20, 2024 6:01:51 AM okhttp3.internal.platform.Platform log
INFO: <-- 200 OK https://lk.exp.xxx.at/twirp/livekit.RoomService/SendData (3ms)
06:01:51.870 [DefaultDispatcher-worker-3] ERROR at.xxx.telephony.call.Call session= - Could not send call info to LiveKit: Response from io.livekit.server.RoomService.sendData was null but response body type was declared as non-null
kotlin.KotlinNullPointerException: Response from io.livekit.server.RoomService.sendData was null but response body type was declared as non-null
    at retrofit2.KotlinExtensions$await$2$2.onResponse(KotlinExtensions.kt:43)
    at retrofit2.OkHttpCall$1.onResponse(OkHttpCall.java:161)
    at okhttp3.internal.connection.RealCall$AsyncCall.run(RealCall.kt:519)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
    at java.base/java.lang.Thread.run(Thread.java:1583)
Jun 20, 2024 6:01:51 AM okhttp3.internal.platform.Platform log
INFO: Content-Length: 0
Jun 20, 2024 6:01:51 AM okhttp3.internal.platform.Platform log
INFO: Content-Type: application/protobuf
Jun 20, 2024 6:01:51 AM okhttp3.internal.platform.Platform log
INFO: Vary: Origin
Jun 20, 2024 6:01:51 AM okhttp3.internal.platform.Platform log
INFO: Date: Thu, 20 Jun 2024 06:01:51 GMT
Jun 20, 2024 6:01:51 AM okhttp3.internal.platform.Platform log
INFO: <-- END HTTP (0-byte body)

This is with Version: v1.5.3 I am upgrading to V1.6 right now and will test again.

V1.6.2 has the same issue. I am trying to catch the network traffic between the nodes now.

PhilippKolmann commented 2 months ago

We had the implementation as follows:

                roomService.sendData(id.toString(), data.encodeToByteArray(), LivekitModels.DataPacket.Kind.RELIABLE)
                    .await()

After looking at the server-sdk-kotlin and the livekit server I saw that the call returns nothing (https://github.com/livekit/livekit/blob/master/pkg/service/roommanager.go#L778).

Now I removed the .await() from the call and at first glance I don't get the exception anymore.

Is this the proper usage?

davidliu commented 2 months ago

Calling await (or execute if running in a non-coroutine world) is required to actually make the call to the server.

Looks like the problem here is using await though. Since this is a void call, await can't return void as a value. Use awaitResponse instead, which doesn't need to check the type to make sure it can return the response.

PhilippKolmann commented 2 months ago

Thanks a lot for clearifing the issue for me. Seems it works now with awaitResponse.

Would it be possible to change https://github.com/livekit/server-sdk-kotlin/blob/c893a050650aefe9d867acec768616e539454c17/src/main/kotlin/io/livekit/server/RoomService.kt#L94

from fun sendData(@Body request: LivekitRoom.SendDataRequest, @Header("Authorization") authorization: String): Call<Void>

to fun sendData(@Body request: LivekitRoom.SendDataRequest, @Header("Authorization") authorization: String): Call<Void?> (return Call<Void?>)

so it would trigger https://github.com/square/retrofit/blob/ed2c6c9f1840ace8b2f49bc6de51a099ac2b5059/retrofit/src/main/java/retrofit2/KotlinExtensions.kt#L65

Thanks