Missing notifications because of a memory leak in NSE

manuroe commented 11 months ago

Steps to reproduce

Do not open the app
Received10 messages that should trigger a notification for each
Count notifications you receive

Outcome

What did you expect?

I should get 10 notifications

What happened instead?

Sometimes I get only 2

Your phone model

No response

Operating system version

No response

Application version

No response

Homeserver

No response

Will you send logs?

Yes

manuroe commented 11 months ago

The issue is probably only on nightlies. We need to check memory leaks on the App Store version

Possible reasons:

could be room avatar cache
could be a change how to the sync or NSE logic
could be a change in process lock between NSE & app
could be last UniFFI updates on async
could be whatever changed since https://github.com/vector-im/element-x-ios/releases/tag/1.3.3
...

Velin92 commented 10 months ago

The room avatar cache existed way before the release 1.3.3 so is likely to be something of the other causes, adding a needs rust tag to see if @bnjbvr might have any idea about this. I am going to double check when I am not too busy with pills also on the iOS side.

Velin92 commented 10 months ago

This seems to be caused sometimes when fetching the room/user avatars or any kind of media content that is in the message (like images and videos) Specifically the get_media_content function from the Rust Client API sometimes exceeds the NSE memory.

Seems that the UniFFI signature of this function changed from [UInt8] to Data very recently (since the 1.1.22 SDK update).. However my gut feeling is that this creates some kind inefficient memory usage which leads to the memory limit of NSE getting overflown (maybe since [UInt8] is just a pointer to data, it performs better than the Data struct in this limited memory usage case? ) @bnjbvr @jplatte

bnjbvr commented 10 months ago

Out of curiosity, if it's easy to get this information: could we get a full heap snapshot, with live allocations correlated to call sites? I wonder if the media content copy is just the final straw that broke the camel's back, and there's a memory leak somewhere else.

Velin92 commented 10 months ago

Tried with the latest uniFFI main commit and the issue is still happening, however the issue seems that now has been triggered by the instantiation of the NotificationClient precisely on the restore_session function Here is the call hierarchy:

#0  0x000000021fa9cf48 in _platform_memmove ()
#1  0x0000000106c34f7c in alloc::boxed::Box$LT$T$GT$::new::h327d0a5271f5b501 [inlined] at /rustc/cc66ad468955717ab92600c770da8c1601a4ff33/library/alloc/src/boxed.rs:217
#2  0x0000000106c34f50 in alloc::sync::Arc$LT$T$GT$::new::ha7895854c4fd88f7 [inlined] at /rustc/cc66ad468955717ab92600c770da8c1601a4ff33/library/alloc/src/sync.rs:388
#3  0x0000000106c34f18 in eyeball::shared::SharedObservable$LT$T$GT$::new::h04650d04bd20b45a at /Users/mauroromito/.cargo/registry/src/index.crates.io-6f17d22bba15001f/eyeball-0.8.7/src/shared.rs:49
#4  0x0000000106d7246c in matrix_sdk_base::rooms::normal::Room::restore::h36020136bad5094e at /Users/mauroromito/Documents/Xworkspace/matrix-rust-sdk/crates/matrix-sdk-base/src/rooms/normal.rs:157
#5  0x0000000104a8ef24 in matrix_sdk_base::store::Store::set_session_meta::_$u7b$$u7b$closure$u7d$$u7d$::h415685bacee46bb3 [inlined] at /Users/mauroromito/Documents/Xworkspace/matrix-rust-sdk/crates/matrix-sdk-base/src/store/mod.rs:180
#6  0x0000000104a8ecf0 in matrix_sdk_base::client::BaseClient::set_session_meta::_$u7b$$u7b$closure$u7d$$u7d$::h09f87ed34a64cac4 [inlined] at /Users/mauroromito/Documents/Xworkspace/matrix-rust-sdk/crates/matrix-sdk-base/src/client.rs:194
#7  0x0000000104a8ecec in matrix_sdk::client::Client::set_session_meta::_$u7b$$u7b$closure$u7d$$u7d$::h094fec148be593af at /Users/mauroromito/Documents/Xworkspace/matrix-rust-sdk/crates/matrix-sdk/src/client/mod.rs:939
#8  0x0000000104a6dcd0 in matrix_sdk::matrix_auth::MatrixAuth::set_session::_$u7b$$u7b$closure$u7d$$u7d$::h02d8eec3784bd065 at /Users/mauroromito/Documents/Xworkspace/matrix-rust-sdk/crates/matrix-sdk/src/matrix_auth/mod.rs:828
#9  0x0000000104a6e6bc in matrix_sdk::matrix_auth::MatrixAuth::restore_session::_$u7b$$u7b$closure$u7d$$u7d$::_$u7b$$u7b$closure$u7d$$u7d$::hab028a0328664e43 at /Users/mauroromito/Documents/Xworkspace/matrix-rust-sdk/crates/matrix-sdk/src/matrix_auth/mod.rs:804
#10 0x0000000104bb9f70 in _$LT$tracing..instrument..Instrumented$LT$T$GT$$u20$as$u20$core..future..future..Future$GT$::poll::h8d143b4191edc218 at /Users/mauroromito/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tracing-0.1.40/src/instrument.rs:321
#11 0x0000000104a6e138 in matrix_sdk::matrix_auth::MatrixAuth::restore_session::_$u7b$$u7b$closure$u7d$$u7d$::hbcc13c37411c120c at /Users/mauroromito/Documents/Xworkspace/matrix-rust-sdk/crates/matrix-sdk/src/matrix_auth/mod.rs:801
#12 0x0000000104bad8f8 in matrix_sdk::client::Client::restore_session::_$u7b$$u7b$closure$u7d$$u7d$::_$u7b$$u7b$closure$u7d$$u7d$::h69fa11fb2201ae6b [inlined] at /Users/mauroromito/Documents/Xworkspace/matrix-rust-sdk/crates/matrix-sdk/src/client/mod.rs:932
#13 0x0000000104bad7f8 in _$LT$tracing..instrument..Instrumented$LT$T$GT$$u20$as$u20$core..future..future..Future$GT$::poll::h6477c412df376522 at /Users/mauroromito/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tracing-0.1.40/src/instrument.rs:321
#14 0x0000000104d35c9c in matrix_sdk::client::Client::restore_session::_$u7b$$u7b$closure$u7d$$u7d$::h27c89d379f51c299 [inlined] at /Users/mauroromito/Documents/Xworkspace/matrix-rust-sdk/crates/matrix-sdk/src/client/mod.rs:928
#15 0x0000000104d359b4 in matrix_sdk_ffi::client::Client::restore_session_inner::_$u7b$$u7b$closure$u7d$$u7d$::h7dc2e01a45f405b8 [inlined] at /Users/mauroromito/Documents/Xworkspace/matrix-rust-sdk/bindings/matrix-sdk-ffi/src/client.rs:309
#16 0x0000000104d35970 in tokio::runtime::park::CachedParkThread::block_on::_$u7b$$u7b$closure$u7d$$u7d$::h1115300993837d1b [inlined] at /Users/mauroromito/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/park.rs:282
#17 0x0000000104d35970 in tokio::runtime::coop::with_budget::hb0eec17531e88976 [inlined] at /Users/mauroromito/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/coop.rs:107
#18 0x0000000104d35948 in tokio::runtime::coop::budget::h7a9193dca9a64420 [inlined] at /Users/mauroromito/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/coop.rs:73
#19 0x0000000104d35924 in tokio::runtime::park::CachedParkThread::block_on::hbb9022f253fce7f6 at /Users/mauroromito/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/park.rs:282
#20 0x000000010569b91c in tokio::runtime::context::blocking::BlockingRegionGuard::block_on::h34c390970bb6cf4e [inlined] at /Users/mauroromito/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/context/blocking.rs:66
#21 0x000000010569b8f4 in tokio::runtime::scheduler::multi_thread::MultiThread::block_on::_$u7b$$u7b$closure$u7d$$u7d$::hfdbe255c24875c5d [inlined] at /Users/mauroromito/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/scheduler/multi_thread/mod.rs:87
#22 0x000000010569b8f4 in tokio::runtime::context::runtime::enter_runtime::h0ef73b70e62ee780 at /Users/mauroromito/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/context/runtime.rs:65
#23 0x000000010558215c in tokio::runtime::scheduler::multi_thread::MultiThread::block_on::h50a87cbb02ef9446 [inlined] at /Users/mauroromito/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/scheduler/multi_thread/mod.rs:86
#24 0x0000000105582144 in tokio::runtime::runtime::Runtime::block_on::hf366a648a8fc0795 at /Users/mauroromito/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.33.0/src/runtime/runtime.rs:350
#25 0x0000000105336a4c in matrix_sdk_ffi::client::Client::restore_session_inner::ha4218fdf92445e19 at /Users/mauroromito/Documents/Xworkspace/matrix-rust-sdk/bindings/matrix-sdk-ffi/src/client.rs:308
#26 0x0000000104927620 in matrix_sdk_ffi::client::Client::restore_session::h37d9caa9e45e36fb at /Users/mauroromito/Documents/Xworkspace/matrix-rust-sdk/bindings/matrix-sdk-ffi/src/client.rs:289
#27 0x00000001049e7070 in matrix_sdk_ffi::client::uniffi_matrix_sdk_ffi_fn_method_client_restore_session::_$u7b$$u7b$closure$u7d$$u7d$::h2fa13d5d7ed53c21 [inlined] at /Users/mauroromito/Documents/Xworkspace/matrix-rust-sdk/bindings/matrix-sdk-ffi/src/client.rs:234
#28 0x00000001049e6fa0 in uniffi_core::ffi::rustcalls::rust_call_with_out_status::_$u7b$$u7b$closure$u7d$$u7d$::hcef2eaf38bae1e44 [inlined] at /Users/mauroromito/.cargo/git/checkouts/uniffi-rs-6f89edd2a1ffa4bd/10caead/uniffi_core/src/ffi/rustcalls.rs:144
#29 0x00000001049e6fa0 in std::panicking::try::do_call::hb47d72d0825b75e9 [inlined] at /rustc/cc66ad468955717ab92600c770da8c1601a4ff33/library/std/src/panicking.rs:502
#30 0x00000001049e6fa0 in std::panicking::try::h52ebfdd2490aef04 at /rustc/cc66ad468955717ab92600c770da8c1601a4ff33/library/std/src/panicking.rs:466
#31 0x00000001055b4f00 in std::panic::catch_unwind::hf22b3723aeb689db [inlined] at /rustc/cc66ad468955717ab92600c770da8c1601a4ff33/library/std/src/panic.rs:142
#32 0x00000001055b4ef4 in uniffi_core::ffi::rustcalls::rust_call_with_out_status::h739b70c177d187b5 [inlined] at /Users/mauroromito/.cargo/git/checkouts/uniffi-rs-6f89edd2a1ffa4bd/10caead/uniffi_core/src/ffi/rustcalls.rs:142
#33 0x00000001055b4ee4 in uniffi_core::ffi::rustcalls::rust_call::h49e624b0194c00a7 at /Users/mauroromito/.cargo/git/checkouts/uniffi-rs-6f89edd2a1ffa4bd/10caead/uniffi_core/src/ffi/rustcalls.rs:126
#34 0x0000000104927b04 in uniffi_matrix_sdk_ffi_fn_method_client_restore_session at /Users/mauroromito/Documents/Xworkspace/matrix-rust-sdk/bindings/matrix-sdk-ffi/src/client.rs:234
#35 0x0000000104194710 in closure #1 in Client.restoreSession(session:) at /Users/mauroromito/Documents/Xworkspace/matrix-rust-sdk/bindings/apple/generated/swift/matrix_sdk_ffi.swift:917
#36 0x00000001041893c0 in makeRustCall<τ_0_0>(_:errorHandler:) at /Users/mauroromito/Documents/Xworkspace/matrix-rust-sdk/bindings/apple/generated/swift/matrix_sdk_ffi.swift:257
#37 0x0000000104189550 in rustCallWithError<τ_0_0>(_:_:) at /Users/mauroromito/Documents/Xworkspace/matrix-rust-sdk/bindings/apple/generated/swift/matrix_sdk_ffi.swift:248
#38 0x000000010419450c in Client.restoreSession(session:) at /Users/mauroromito/Documents/Xworkspace/matrix-rust-sdk/bindings/apple/generated/swift/matrix_sdk_ffi.swift:916
#39 0x000000010411bf84 in NSEUserSession.init(credentials:clientSessionDelegate:) at /Users/mauroromito/Documents/Xworkspace/element-x-ios/NSE/Sources/Other/NSEUserSession.swift:39
#40 0x000000010411bb50 in NSEUserSession.__allocating_init(credentials:clientSessionDelegate:) ()
#41 0x000000010412d8d0 in NotificationServiceExtension.run(with:roomId:eventId:unreadCount:) at /Users/mauroromito/Documents/Xworkspace/element-x-ios/NSE/Sources/NotificationServiceExtension.swift:78
#42 0x000000010412cf54 in closure #2 in NotificationServiceExtension.didReceive(_:withContentHandler:) at /Users/mauroromito/Documents/Xworkspace/element-x-ios/NSE/Sources/NotificationServiceExtension.swift:57
#43 0x000000010412fc68 in partial apply for closure #2 in NotificationServiceExtension.didReceive(_:withContentHandler:) ()
#44 0x000000010413079c in thunk for @escaping @callee_guaranteed @Sendable @async () -> (@out τ_0_0) ()
#45 0x00000001041308f8 in partial apply for thunk for @escaping @callee_guaranteed @Sendable @async () -> (@out τ_0_0) ()

Velin92 commented 10 months ago

I was also able to reproduce the Data issue, can be reproduced by sending some media content like an image or a video, and sometimes this happens.

#0  0x000000021fa9cef8 in _platform_memmove ()
#1  0x00000001b5988d0c in __DataStorage.init(bytes:length:) ()
#2  0x00000001b5988dec in specialized Data.InlineSlice.init(_:) ()
#3  0x00000001b5eaee30 in closure #1 in Data.init<τ_0_0>(_:) ()
#4  0x00000001b5bc1300 in specialized Array.withUnsafeBytes<τ_0_0>(_:) ()
#5  0x00000001b5bc12cc in protocol witness for ContiguousBytes.withUnsafeBytes<τ_0_0>(_:) in conformance <τ_0_0> [τ_0_0] ()
#6  0x00000001b59bf59c in specialized Data.init<τ_0_0>(_:) ()
#7  0x00000001b5ea9850 in Data.init<τ_0_0>(_:) ()
#8  0x000000010013459c in static FfiConverterData.read(from:) at /Users/mauroromito/Documents/Xworkspace/matrix-rust-sdk/bindings/apple/generated/swift/matrix_sdk_ffi.swift:455
#9  0x00000001001347bc in protocol witness for static FfiConverter.read(from:) in conformance FfiConverterData ()
#10 0x0000000100130c0c in static FfiConverterRustBuffer.lift(_:) ()
#11 0x0000000100139d70 in Client.getMediaContent(mediaSource:) at /Users/mauroromito/Documents/Xworkspace/matrix-rust-sdk/bindings/apple/generated/swift/matrix_sdk_ffi.swift:784
#12 0x000000010013f3b0 in protocol witness for ClientProtocol.getMediaContent(mediaSource:) in conformance Client ()
#13 0x00000001000b47bc in closure #1 in MediaLoader.loadMediaContentForSource(_:) at /Users/mauroromito/Documents/Xworkspace/element-x-ios/ElementX/Sources/Services/Media/Provider/MediaLoader.swift:39
#14 0x00000001000b4bb0 in partial apply for closure #1 in MediaLoader.loadMediaContentForSource(_:) ()
#15 0x00000001000b6bf0 in closure #2 in MediaLoader.enqueueLoadMediaRequest(forSource:operation:) at /Users/mauroromito/Documents/Xworkspace/element-x-ios/ElementX/Sources/Services/Media/Provider/MediaLoader.swift:75
#16 0x00000001000b7424 in partial apply for closure #2 in MediaLoader.enqueueLoadMediaRequest(forSource:operation:) ()
#17 0x000000010011c7fc in closure #1 in closure #1 in static Task<>.dispatch<τ_0_0>(on:function:_:) at /Users/mauroromito/Documents/Xworkspace/element-x-ios/ElementX/Sources/Other/Extensions/Task.swift:56
#18 0x000000010011c080 in thunk for @escaping @callee_guaranteed @Sendable () -> () ()
#19 0x00000001be8856a8 in _dispatch_call_block_and_release ()
#20 0x00000001be887300 in _dispatch_client_callout ()
#21 0x00000001be898dbc in _dispatch_root_queue_drain ()
#22 0x00000001be8993ec in _dispatch_worker_thread2 ()
#23 0x000000021fb46928 in _pthread_wqthread ()

element-hq / element-x-ios