search

livekit / rust-sdks

LiveKit realtime and server SDKs for Rust
https://livekit.io
Apache License 2.0
212 stars 57 forks source link

'NSInvalidArgumentException', reason: '-[RTCVideoCodecInfo nativeSdpVideoFormat]: unrecognized selector sent to instance 0x600001ef0340' #340

Closed Tails closed 6 months ago

Tails commented 6 months ago

I have a relatively simple handler (Mac M2) that starts livekit-server in dev as a child process, and then uses the SDK to create a room, and finally tries to connect to the room and listen for room events. However, in the last step I get some trace error that seems to be coming from the PeerConnectionFactory ffi code running in the webrtc lib. I'm running 0.3.2 of livekit and livekit_api, and 1.6.1 of livekit-server (installed from brew).

Here is the code:

const ENDPOINT: &str = "http://localhost:7880";

pub async fn run() -> anyhow::Result<()> {
    let mut child = Command::new("livekit-server")
        .arg("--dev")
        .spawn()
        .context("error starting LiveKit")?;

    thread::sleep(Duration::from_secs(3));

    let room_service = RoomClient::new(ENDPOINT).unwrap();

    let test_room_name = "test-room";

    let room_options = CreateRoomOptions::default();

    // for testing
    let room = room_service
        .create_room(test_room_name, room_options)
        .await
        .unwrap();

    println!("Created room: {:?}", room);

    thread::sleep(Duration::from_secs(3));

    let api_key = env::var("LIVEKIT_API_KEY").expect("LIVEKIT_API_KEY is not set");
    let api_secret = env::var("LIVEKIT_API_SECRET").expect("LIVEKIT_API_SECRET is not set");

    let token = access_token::AccessToken::with_api_key(&api_key, &api_secret)
        .with_identity("rust-bot")
        .with_name("Rust Bot")
        .with_grants(access_token::VideoGrants {
            room_create: true,
            room_join: true,
            room: test_room_name.to_string(),
            ..Default::default()
        })
        .to_jwt()?;

    // breaks with 'unrecognized selector sent to instance'
    let (_, mut room_events) = Room::connect(&ENDPOINT, &token, RoomOptions::default()).await?;
}

And here is the trace:

2024-05-22T09:14:34.879+0200    INFO    livekit server/main.go:208  starting in development mode
2024-05-22T09:14:34.880+0200    INFO    livekit server/main.go:211  no keys provided, using placeholder keys    {"API Key": "devkey", "API Secret": "secret"}
2024-05-22T09:14:34.881+0200    INFO    livekit routing/interfaces.go:110   using single-node routing
2024-05-22T09:14:34.913+0200    INFO    livekit service/server.go:243   starting LiveKit server {"portHttp": 7880, "nodeID": "ND_HrFnydhmQnUW", "nodeIP": "192.168.81.155", "version": "1.6.1", "bindAddresses": ["127.0.0.1", "::1"], "rtc.portTCP": 7881, "rtc.portUDP": {"Start":7882,"End":0}}
2024-05-22T09:14:34.914+0200    DEBUG   livekit service/signal.go:122   starting relay signal server    {"topic": "ND_HrFnydhmQnUW"}
2024-05-22T09:14:37.790+0200    DEBUG   livekit routing/signal.go:100   starting signal connection  {"room": "test-room", "reqNodeID": "ND_HrFnydhmQnUW", "participant": "", "connID": "CO_UqLX8t9msHB5"}
2024-05-22T09:14:37.791+0200    DEBUG   livekit routing/signal.go:136   signal stream closed    {"room": "test-room", "reqNodeID": "ND_HrFnydhmQnUW", "participant": "", "connID": "CO_UqLX8t9msHB5", "error": "stream closed"}
2024-05-22T09:14:37.791+0200    DEBUG   livekit service/signal.go:175   signal stream closed    {"room": "test-room", "participant": "", "connID": "CO_UqLX8t9msHB5", "error": "stream closed"}
2024-05-22T09:14:37.791+0200    INFO    livekit.api service/twirp.go:124    API RoomService.CreateRoom  {"service": "RoomService", "method": "CreateRoom", "room": "test-room", "request": "name:\"test-room\"", "duration": "1.827334ms", "status": "200"}
Created room: Room { sid: "RM_KDWcqEcKLuHm", name: "test-room", empty_timeout: 300, max_participants: 0, creation_time: 1716362077, turn_password: "fiVxv9dolJ0e6D9QHcV87wpw1A6C0BEfXs9tmNsjfCXC", enabled_codecs: [Codec { mime: "audio/opus", fmtp_line: "" }, Codec { mime: "audio/red", fmtp_line: "" }, Codec { mime: "video/VP8", fmtp_line: "" }, Codec { mime: "video/H264", fmtp_line: "" }, Codec { mime: "video/VP9", fmtp_line: "" }, Codec { mime: "video/AV1", fmtp_line: "" }], metadata: "", num_participants: 0, num_publishers: 0, active_recording: false, version: None }
connecting to ws://localhost:7880/rtc?sdk=rust&protocol=9&auto_subscribe=1&adaptive_stream=0&access_token=...
received JoinResponse: JoinResponse { room: Some(Room { sid: "RM_KDWcqEcKLuHm", name: "test-room", empty_timeout: 300, max_participants: 0, creation_time: 1716362077, turn_password: "fiVxv9dolJ0e6D9QHcV87wpw1A6C0BEfXs9tmNsjfCXC", enabled_codecs: [Codec { mime: "audio/opus", fmtp_line: "" }, Codec { mime: "audio/red", fmtp_line: "" }, Codec { mime: "video/VP8", fmtp_line: "" }, Codec { mime: "video/H264", fmtp_line: "" }, Codec { mime: "video/VP9", fmtp_line: "" }, Codec { mime: "video/AV1", fmtp_line: "" }], metadata: "", num_participants: 0, num_publishers: 0, active_recording: false, version: None }), participant: Some(ParticipantInfo { sid: "PA_djXQVfE24hm9", identity: "rust-bot", state: Joining, tracks: [], metadata: "", joined_at: 1716362080, name: "Rust Bot", version: 0, permission: Some(ParticipantPermission { can_subscribe: true, can_publish: true, can_publish_data: true, can_publish_sources: [], hidden: false, recorder: false, can_update_metadata: false, agent: false }), region: "", is_publisher: false, kind: Standard }), other_participants: [], server_version: "1.6.1", ice_servers: [IceServer { urls: ["stun:global.stun.twilio.com:3478", "stun:stun.l.google.com:19302", "stun:stun1.l.google.com:19302"], username: "", credential: "" }], subscriber_primary: true, alternative_url: "", client_configuration: None, server_region: "", ping_timeout: 15, ping_interval: 5, server_info: Some(ServerInfo { edition: Standard, version: "1.6.1", protocol: 13, region: "", node_id: "ND_HrFnydhmQnUW", debug_info: "" }), sif_trailer: [78, 121, 83, 78, 108, 53, 80, 69, 120, 51, 119, 88, 122, 79, 111, 79, 114, 78, 90, 114, 51, 74, 77, 87, 111, 66, 69, 101, 77, 120, 83, 111, 115, 108, 79, 74, 81, 119, 72, 115, 56, 81, 66] }
2024-05-22T09:14:40.797+0200    DEBUG   livekit routing/signal.go:100   starting signal connection  {"room": "test-room", "reqNodeID": "ND_HrFnydhmQnUW", "participant": "rust-bot", "connID": "CO_2w2VRgsX3UGR"}
2024-05-22T09:14:40.797+0200    DEBUG   livekit service/roommanager.go:356  starting RTC session    {"room": "test-room", "nodeID": "ND_HrFnydhmQnUW", "participant": "rust-bot", "clientInfo": {"sdk": 8, "protocol": 9, "address": "::1"}, "reconnect": false, "reconnectReason": "RR_UNKNOWN", "adaptiveStream": false, "numParticipants": 0}
2024-05-22T09:14:40.801+0200    DEBUG   livekit.room    rtc/room.go:412 new participant joined  {"room": "test-room", "roomID": "RM_KDWcqEcKLuHm", "pID": "PA_djXQVfE24hm9", "participant": "rust-bot", "clientInfo": {"sdk": 8, "protocol": 9, "address": "::1"}, "options": {"AutoSubscribe":true}, "numParticipants": 0}
2024-05-22T09:14:40.801+0200    DEBUG   livekit rtc/participant.go:1399 updating participant state  {"room": "test-room", "roomID": "RM_KDWcqEcKLuHm", "participant": "rust-bot", "pID": "PA_djXQVfE24hm9", "remote": false, "state": "JOINED"}
2024-05-22T09:14:40.801+0200    DEBUG   livekit rtc/participant.go:978  SetMigrateState {"room": "test-room", "roomID": "RM_KDWcqEcKLuHm", "participant": "rust-bot", "pID": "PA_djXQVfE24hm9", "remote": false, "state": "MIGRATE_STATE_COMPLETE"}
2024-05-22T09:14:40.802+0200    DEBUG   livekit service/rtcservice.go:300   new client WS connected {"room": "test-room", "roomID": "RM_KDWcqEcKLuHm", "participant": "rust-bot", "pID": "PA_djXQVfE24hm9", "remote": false, "connID": "CO_2w2VRgsX3UGR", "reconnect": false, "reconnectReason": "RR_UNKNOWN", "adaptiveStream": false, "selectedNodeID": "ND_HrFnydhmQnUW", "nodeSelectionReason": ""}
2024-05-22T09:14:40.802+0200    DEBUG   livekit.transport   rtc/transport.go:594    ice gathering state change  {"room": "test-room", "roomID": "RM_KDWcqEcKLuHm", "participant": "rust-bot", "pID": "PA_djXQVfE24hm9", "remote": false, "transport": "SUBSCRIBER", "state": "gathering"}
2024-05-22T09:14:40.802+0200    DEBUG   livekit.sub rtc/participant.go:1432 sending offer   {"room": "test-room", "roomID": "RM_KDWcqEcKLuHm", "participant": "rust-bot", "pID": "PA_djXQVfE24hm9", "remote": false, "transport": "SUBSCRIBER"}
2024-05-22T09:14:40.803+0200    DEBUG   livekit service/rtcservice.go:340   sending offer   {"room": "test-room", "roomID": "RM_KDWcqEcKLuHm", "participant": "rust-bot", "pID": "PA_djXQVfE24hm9", "remote": false, "offer": {"Offer":{"type":"offer","sdp":"v=0\r\no=- 4065197064993440530 1716362080 IN IP4 0.0.0.0\r\ns=-\r\nt=0 0\r\na=msid-semantic:WMS*\r\na=fingerprint:sha-256 0F:39:44:79:E3:60:F6:02:53:DA:8B:84:0A:3D:64:D0:C1:AF:62:07:E6:84:1B:30:3E:04:xx:xx:xx:xx:xx\r\na=extmap-allow-mixed\r\na=group:BUNDLE 0\r\nm=application 9 UDP/DTLS/SCTP webrtc-datachannel\r\nc=IN IP4 0.0.0.0\r\na=setup:actpass\r\na=mid:0\r\na=sendrecv\r\na=sctp-port:5000\r\na=ice-ufrag:tdvOwtPFoUMUKnpP\r\na=ice-pwd:lWFwcpaGOdTRyxfCeOjKJgbrTgvzzQcJ\r\n"}}}
2024-05-22T09:14:40.803+0200    DEBUG   livekit rtc/participant_signal.go:259   sending ICE candidate   {"room": "test-room", "roomID": "RM_KDWcqEcKLuHm", "participant": "rust-bot", "pID": "PA_djXQVfE24hm9", "remote": false, "transport": "SUBSCRIBER", "trickle": {"candidateInit": "{\"candidate\":\"candidate:2373575680 1 udp 2130706431 192.168.81.155 7882 typ host\",\"sdpMid\":\"\",\"sdpMLineIndex\":0,\"usernameFragment\":null}", "target": 1}}
2024-05-22T09:14:40.803+0200    DEBUG   livekit rtc/participant_signal.go:259   sending ICE candidate   {"room": "test-room", "roomID": "RM_KDWcqEcKLuHm", "participant": "rust-bot", "pID": "PA_djXQVfE24hm9", "remote": false, "transport": "SUBSCRIBER", "trickle": {"candidateInit": "{\"candidate\":\"candidate:814388704 1 tcp 1671430143 192.168.81.155 7881 typ host tcptype passive\",\"sdpMid\":\"\",\"sdpMLineIndex\":0,\"usernameFragment\":null}", "target": 1}}
*** Terminating app due to uncaught exception 'NSInvalidArgumentException', reason: '-[RTCVideoCodecInfo nativeSdpVideoFormat]: unrecognized selector sent to instance 0x600003bc6660'
*** First throw call stack:
(
    0   CoreFoundation                      0x0000000184466800 __exceptionPreprocess + 176
    1   libobjc.A.dylib                     0x0000000183f5deb4 objc_exception_throw + 60
    2   CoreFoundation                      0x00000001845183bc -[NSObject(NSObject) __retain_OA] + 0
    3   CoreFoundation                      0x00000001843d0a84 ___forwarding___ + 1572
    4   CoreFoundation                      0x00000001843d03a0 _CF_forwarding_prep_0 + 96
    5   parture-node                        0x00000001052d2064 _ZNK6webrtc23ObjCVideoEncoderFactory19GetSupportedFormatsEv + 220
    6   parture-node                        0x000000010551a3dc _ZNK7livekit19VideoEncoderFactory15InternalFactory19GetSupportedFormatsEv + 184
    7   parture-node                        0x000000010551b814 _ZNK7livekit19VideoEncoderFactory19GetSupportedFormatsEv + 52
    8   parture-node                        0x00000001054aed64 _ZNK7cricket17WebRtcVideoEngine11send_codecsEb + 104
    9   parture-node                        0x0000000104c70594 _ZN7cricket30MediaSessionDescriptionFactoryC1EPNS_20MediaEngineInterfaceEbPN3rtc23UniqueRandomIdGeneratorEPKNS_27TransportDescriptionFactoryE + 284
    10  parture-node                        0x0000000104cb3b4c _ZN6webrtc31WebRtcSessionDescriptionFactoryC2EPNS_17ConnectionContextEPKNS_16SdpStateProviderERKNSt3__112basic_stringIcNS6_11char_traitsIcEENS6_9allocatorIcEEEEbNS6_10unique_ptrIN3rtc32RTCCertifi  11  parture-node                        0x0000000104c1a030 _ZN6webrtc21SdpOfferAnswerHandler10InitializeERKNS_23PeerConnectionInterface16RTCConfigurationERNS_26PeerConnectionDependenciesEPNS_17ConnectionContextE + 316
    12  parture-node                        0x0000000104cd5e8c _ZN6webrtc14PeerConnection10InitializeERKNS_23PeerConnectionInterface16RTCConfigurationENS_26PeerConnectionDependenciesE + 836
    13  parture-node                        0x0000000104cd59fc _ZN6webrtc14PeerConnection6CreateEN3rtc13scoped_refptrINS_17ConnectionContextEEERKNS_30PeerConnectionFactoryInterface7OptionsENSt3__110unique_ptrINS_11RtcEventLogENS9_14default_deleteISB_EEEENSA_  14  parture-node                        0x0000000104c8284c _ZN6webrtc21PeerConnectionFactory27CreatePeerConnectionOrErrorERKNS_23PeerConnectionInterface16RTCConfigurationENS_26PeerConnectionDependenciesE + 416
    15  parture-node                        0x0000000104c840a4 _ZN6webrtc10ReturnTypeINS_10RTCErrorOrIN3rtc13scoped_refptrINS_23PeerConnectionInterfaceEEEEEE6InvokeINS_30PeerConnectionFactoryInterfaceEMS9_FS6_RKNS4_16RTCConfigurationENS_26PeerConnectionDepen  16  parture-node                        0x0000000104c8415c _ZN4absl22internal_any_invocable12LocalInvokerILb0EvOZN6webrtc10MethodCallINS2_30PeerConnectionFactoryInterfaceENS2_10RTCErrorOrIN3rtc13scoped_refptrINS2_23PeerConnectionInterfaceEEEEEJRKNS8_16RT  17  parture-node                        0x0000000104d90928 _ZN3rtc6Thread8DispatchEN4absl12AnyInvocableIFvvOEEE + 172
    18  parture-node                        0x0000000104d8f698 _ZN3rtc6Thread15ProcessMessagesEi + 200
    19  parture-node                        0x0000000104d90e44 _ZN3rtc6Thread6PreRunEPv + 116
    20  libsystem_pthread.dylib             0x0000000184315034 _pthread_start + 136
    21  libsystem_pthread.dylib             0x000000018430fe3c thread_start + 8
)
libc++abi: terminating due to uncaught exception of type NSException
2024-05-22T09:14:40.817+0200    DEBUG   livekit service/rtcservice.go:263   finishing WS connection {"room": "test-room", "roomID": "RM_KDWcqEcKLuHm", "participant": "rust-bot", "pID": "PA_djXQVfE24hm9", "remote": false, "connID": "CO_2w2VRgsX3UGR", "closedByClient": true}
2024-05-22T09:14:40.817+0200    DEBUG   livekit service/rtcservice.go:327   nothing to read from response source    {"room": "test-room", "roomID": "RM_KDWcqEcKLuHm", "participant": "rust-bot", "pID": "PA_djXQVfE24hm9", "remote": false, "connID": "CO_2w2VRgsX3UGR"}
make: 2024-05-22T09:14:40.817+0200  DEBUG   livekit routing/signal.go:136   signal stream closed    {"room": "test-room", "reqNodeID": "ND_HrFnydhmQnUW", "participant": "rust-bot", "connID": "CO_2w2VRgsX3UGR", "error": "stream closed"}
2024-05-22T09:14:40.817+0200    DEBUG   livekit service/signal.go:175   signal stream closed    {"room": "test-room", "participant": "rust-bot", "connID": "CO_2w2VRgsX3UGR", "error": null}
*** [run] Abort trap: 6
2024-05-22T09:14:40.817+0200    DEBUG   livekit.transport   rtc/transportmanager.go:718 signal source valid {"room": "test-room", "roomID": "RM_KDWcqEcKLuHm", "participant": "rust-bot", "pID": "PA_djXQVfE24hm9", "remote": false, "valid": false}
2024-05-22T09:14:40.817+0200    INFO    livekit rtc/participant.go:829  participant closing {"room": "test-room", "roomID": "RM_KDWcqEcKLuHm", "participant": "rust-bot", "pID": "PA_djXQVfE24hm9", "remote": false, "sendLeave": false, "reason": "SIGNAL_SOURCE_CLOSE", "isExpectedToResume": false}
2024-05-22T09:14:40.817+0200    DEBUG   livekit rtc/participant.go:1399 updating participant state  {"room": "test-room", "roomID": "RM_KDWcqEcKLuHm", "participant": "rust-bot", "pID": "PA_djXQVfE24hm9", "remote": false, "state": "DISCONNECTED"}
2024-05-22T09:14:40.817+0200    DEBUG   livekit service/roommanager.go:604  RTC session finishing   {"room": "test-room", "roomID": "RM_KDWcqEcKLuHm", "participant": "rust-bot", "pID": "PA_djXQVfE24hm9", "remote": false, "connID": "CO_2w2VRgsX3UGR"}
2024-05-22T09:14:40.817+0200    DEBUG   livekit.transport   rtc/transport.go:645    peer connection state change    {"room": "test-room", "roomID": "RM_KDWcqEcKLuHm", "participant": "rust-bot", "pID": "PA_djXQVfE24hm9", "remote": false, "transport": "PUBLISHER", "state": "closed"}
2024-05-22T09:14:40.817+0200    INFO    livekit rtc/room.go:590 removing participant without connection {"room": "test-room", "roomID": "RM_KDWcqEcKLuHm", "participant": "rust-bot", "pID": "PA_djXQVfE24hm9", "remote": false, "subscriberCandidates": ["[local] udp4 host 192.168.81.155:7882", "[local] tcp4 host 192.168.81.155:7881"], "connectionType": "unknown", "reason": "NONE"}

What do you think this could be? It seems to be a problem in some signalling trying to inform a process about a codec (requirement) that is unrecognized, but I'm not sure.

Tails commented 6 months ago

Specifically, the native trace seems to point to here:

https://github.com/JumpingYang001/webrtc/blob/c03d6e965e1f54aeadd670e491eabe5fdb8db968/sdk/objc/native/src/objc_video_encoder_factory.mm#L156

theomonnom commented 6 months ago

Hey, we're currently linking libwebrtc statically. It has the drawback that you need to manually add the -ObjC linker flag, the simplest way is to use this .cargo/config here.

We're working on adding the ability to dynamically link libwebrtc so the onboarding/devex will be much easier/better

Tails commented 6 months ago

Wizard! I had been wrecking my brain for nights. Thank you a lot for the quick response.

For future reference, for anyone running 'cargo run' from the command line, be sure to prefix with RUSTFLAGS="-C link-args=-ObjC" because it won't pick up the config from the Cargo.toml, also not after cleaning.