Seeking while session is connected to Airplay crashes the SDK and the app

kjoneandrei commented 6 years ago

Prerequisites

[x] Which Player version are you using: issue first encountered on version 3.3.5 and after updating to 3.4.1 issue still persists
[x] Can you reproduce the issue with our latest release version: Can be reproduced with 3.4.1 (latest version at the current time)
[x] Can you reproduce the issue with the latest code from master: Issue can be reproduce with code from master
[x] What devices and OS versions are you using:
- iPhone X running iOS 11.3.4
- iPhone X running iOS 11.4
- iPhone 6S running iOS 10.3.1
- iPhone 8 Plus
- iPhone 7 running iOS 11

In order to trigger the crash it is needed to enable Airplay and play a video content with Airplay while seeking back and forth from the player

Expected behavior

Video should seek to the desired position selected (seeking more than 1 time is probably needed as this seems to happen at random)

Actual behavior

Player tries to seek to position but crashes

Console output

Output in console ->

***** set current time to2: 1228.6467246747
2018-06-05 14:05:17.308375+0200 APPNAME[1165:317788] CMTimeMakeWithSeconds(1228.647 seconds, timescale 1): warning: error of -0.647 introduced due to very low timescale
[2018-06-05 14:05:17.309] AVPlayerEngine.swift:77 DEBUG: set currentPosition: nan
2018-06-05 14:05:17.309992+0200 APPNAME[1165:317788] *** Terminating app due to uncaught exception 'NSInvalidArgumentException', reason: '*** -[AVPlayerItem seekToTime:toleranceBefore:toleranceAfter:completionHandler:] Seeking is not possible to time {INVALID}'
*** First throw call stack:
(0x183966d8c 0x182b205ec 0x1893ded54 0x1893c8fb0 0x105bdd1a8 0x105be15c4 0x104703728 0x1046f9330 0x18d7526e8 0x18dcbf3b4 0x18d8b4e38 0x18d751740 0x18dcb0bd4 0x18d74b4d8 0x18d74b010 0x18d74a874 0x18d7491d0 0x18df2ad1c 0x18df2d2c8 0x18df26368 0x18390f404 0x18390ec2c 0x18390c79c 0x18382cda8 0x185811020 0x18d849758 0x104620890 0x1832bdfc0)
libc++abi.dylib: terminating with uncaught exception of type NSException

Output in crash logs ->

Application Specific Information:
*** Terminating app due to uncaught exception 'NSInvalidArgumentException', reason: '*** -[AVPlayerItem seekToTime:toleranceBefore:toleranceAfter:completionHandler:] Seeking is not possible to time {INVALID}'

Last Exception Backtrace:
0   CoreFoundation                       0x000000018393ed8c __exceptionPreprocess + 228
1   libobjc.A.dylib                      0x0000000182af85ec objc_exception_throw + 52
2   AVFoundation                         0x00000001893a2fa0 -[AVPlayerItem seekToTime:toleranceBefore:toleranceAfter:completionHandler:] + 1364
3   AVFoundation                         0x000000018938d1fc -[AVPlayer seekToTime:toleranceBefore:toleranceAfter:completionHandler:] + 124
4   PlayKit                              0x0000000105645338 0x105620000 + 152376
5   PlayKit                              0x00000001056496a0 0x105620000 + 169632
6   AppName                          0x000000010509c54c 0x104fb4000 + 951628
7   AppName                          0x0000000105091c98 0x104fb4000 + 908440
8   UIKit                                0x000000018d66e6c8 -[UIApplication sendAction:to:from:forEvent:] + 92
9   UIKit                                0x000000018d78f8a4 -[UIControl sendAction:to:forEvent:] + 76
10  UIKit                                0x000000018d67477c -[UIControl _sendActionsForEvents:withEvent:] + 436
11  UIKit                                0x000000018da3b008 -[UISlider continueTrackingWithTouch:withEvent:] + 416
12  UIKit                                0x000000018d850acc -[UIControl touchesMoved:withEvent:] + 140
13  UIKit                                0x000000018d6f18c4 -[UIWindow _sendTouchesForEvent:] + 2036
14  UIKit                                0x000000018d6e68f8 -[UIWindow sendEvent:] + 3156
15  UIKit                                0x000000018d6e5238 -[UIApplication sendEvent:] + 336
16  UIKit                                0x000000018dec6c0c __dispatchPreprocessedEventFromEventQueue + 2336
17  UIKit                                0x000000018dec91b8 __handleEventQueueInternal + 4740
18  UIKit                                0x000000018dec2258 __handleHIDEventFetcherDrain + 148
19  CoreFoundation                       0x00000001838e7404 __CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE0_PERFORM_FUNCTION__ + 20
20  CoreFoundation                       0x00000001838e6c2c __CFRunLoopDoSources0 + 272
21  CoreFoundation                       0x00000001838e479c __CFRunLoopRun + 1200
22  CoreFoundation                       0x0000000183804da8 CFRunLoopRunSpecific + 548
23  GraphicsServices                     0x00000001857e7020 GSEventRunModal + 96
24  UIKit                                0x000000018d7e578c UIApplicationMain + 232
25  AppName                         0x0000000104fba0ac 0x104fb4000 + 24748
26  libdyld.dylib                        0x0000000183295fc0 start + 0

Thread 0 Crashed:
0   libsystem_kernel.dylib               0x00000001833c52ec __pthread_kill + 8
1   libsystem_pthread.dylib              0x000000018356a6a8 pthread_kill$VARIANT$armv81 + 356
2   libsystem_c.dylib                    0x0000000183333d0c abort + 136
3   HockeySDK                            0x0000000105821878 0x1057ac000 + 481400
4   CoreFoundation                       0x000000018393f1c8 __handleUncaughtException + 824
5   libobjc.A.dylib                      0x0000000182af88c8 _objc_terminate() + 108
6   HockeySDK                            0x000000010580b24c 0x1057ac000 + 389708
7   libc++abi.dylib                      0x0000000182ae937c std::__terminate(void (*)()) + 12
8   libc++abi.dylib                      0x0000000182ae8f78 __cxa_rethrow + 140
9   libobjc.A.dylib                      0x0000000182af87ac objc_exception_rethrow + 40
10  CoreFoundation                       0x0000000183804e18 CFRunLoopRunSpecific + 660
11  GraphicsServices                     0x00000001857e7020 GSEventRunModal + 96
12  UIKit                                0x000000018d7e578c UIApplicationMain + 232
13  AppName                          0x0000000104fba0ac 0x104fb4000 + 24748
14  libdyld.dylib                        0x0000000183295fc0 start + 0

Thread 1:
0   libsystem_kernel.dylib               0x00000001833a3e08 mach_msg_trap + 8
1   CoreFoundation                       0x00000001838e6e40 __CFRunLoopServiceMachPort + 192
2   CoreFoundation                       0x00000001838e4908 __CFRunLoopRun + 1564
3   CoreFoundation                       0x0000000183804da8 CFRunLoopRunSpecific + 548
4   Foundation                           0x0000000184279674 -[NSRunLoop(NSRunLoop) runMode:beforeDate:] + 300
5   Foundation                           0x000000018427951c -[NSRunLoop(NSRunLoop) runUntilDate:] + 144
6   UIKit                                0x000000018d4ca7e4 -[UIEventFetcher threadMain] + 132
7   Foundation                           0x0000000184389efc __NSThread__start__ + 1036
8   libsystem_pthread.dylib              0x0000000183565220 _pthread_body + 268
9   libsystem_pthread.dylib              0x0000000183565110 _pthread_start + 288
10  libsystem_pthread.dylib              0x0000000183563b10 thread_start + 0

Thread 2:
0   libsystem_kernel.dylib               0x00000001833a3e08 mach_msg_trap + 8
1   CoreFoundation                       0x00000001838e6e40 __CFRunLoopServiceMachPort + 192
2   CoreFoundation                       0x00000001838e4908 __CFRunLoopRun + 1564
3   CoreFoundation                       0x0000000183804da8 CFRunLoopRunSpecific + 548
4   CFNetwork                            0x00000001841124b0 -[__CoreSchedulingSetRunnable runForever] + 216
5   Foundation                           0x0000000184389efc __NSThread__start__ + 1036
6   libsystem_pthread.dylib              0x0000000183565220 _pthread_body + 268
7   libsystem_pthread.dylib              0x0000000183565110 _pthread_start + 288
8   libsystem_pthread.dylib              0x0000000183563b10 thread_start + 0

Thread 3:
0   libsystem_kernel.dylib               0x00000001833a3e08 mach_msg_trap + 8
1   CoreFoundation                       0x00000001838e6e40 __CFRunLoopServiceMachPort + 192
2   CoreFoundation                       0x00000001838e4908 __CFRunLoopRun + 1564
3   CoreFoundation                       0x0000000183804da8 CFRunLoopRunSpecific + 548
4   AVFAudio                             0x00000001892ea424 GenericRunLoopThread::Entry(void*) + 160
5   AVFAudio                             0x0000000189314834 CAPThread::Entry(CAPThread*) + 84
6   libsystem_pthread.dylib              0x0000000183565220 _pthread_body + 268
7   libsystem_pthread.dylib              0x0000000183565110 _pthread_start + 288
8   libsystem_pthread.dylib              0x0000000183563b10 thread_start + 0

Thread 4:
0   libsystem_kernel.dylib               0x00000001833c5538 __select + 8
1   libsystem_pthread.dylib              0x0000000183565220 _pthread_body + 268
2   libsystem_pthread.dylib              0x0000000183565110 _pthread_start + 288
3   libsystem_pthread.dylib              0x0000000183563b10 thread_start + 0

Thread 5:
0   libsystem_pthread.dylib              0x0000000183563b04 start_wqthread + 0

Thread 6:
0   libsystem_kernel.dylib               0x00000001833c5d84 __workq_kernreturn + 8
1   libsystem_pthread.dylib              0x0000000183563b08 start_wqthread + 0

Thread 7:
0   libsystem_kernel.dylib               0x00000001833c50f4 __psynch_cvwait + 8
1   libc++.1.dylib                       0x0000000182a7c25c std::__1::condition_variable::wait(std::__1::unique_lock<std::__1::mutex>&) + 20
2   JavaScriptCore                       0x000000018af5b1a4 void std::__1::condition_variable_any::wait<std::__1::unique_lock<bmalloc::Mutex> >(std::__1::unique_lock<bmalloc::Mutex>&) + 100
3   JavaScriptCore                       0x000000018af5adb8 bmalloc::Scavenger::threadRunLoop() + 160
4   JavaScriptCore                       0x000000018af5ab60 bmalloc::Scavenger::threadEntryPoint(bmalloc::Scavenger*) + 8
5   JavaScriptCore                       0x000000018af5af7c void* std::__1::__thread_proxy<std::__1::tuple<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct> >, void (*)(bmalloc::Scavenger*), bmalloc::Scavenger*> >(void*) + 40
6   libsystem_pthread.dylib              0x0000000183565220 _pthread_body + 268
7   libsystem_pthread.dylib              0x0000000183565110 _pthread_start + 288
8   libsystem_pthread.dylib              0x0000000183563b10 thread_start + 0

Thread 8:
0   libsystem_kernel.dylib               0x00000001833a3e08 mach_msg_trap + 8
1   CoreFoundation                       0x00000001838e6e40 __CFRunLoopServiceMachPort + 192
2   CoreFoundation                       0x00000001838e4908 __CFRunLoopRun + 1564
3   CoreFoundation                       0x0000000183804da8 CFRunLoopRunSpecific + 548
4   WebCore                              0x000000018ba91d9c RunWebThread(void*) + 588
5   libsystem_pthread.dylib              0x0000000183565220 _pthread_body + 268
6   libsystem_pthread.dylib              0x0000000183565110 _pthread_start + 288
7   libsystem_pthread.dylib              0x0000000183563b10 thread_start + 0

Thread 9:
0   libsystem_kernel.dylib               0x00000001833a3e5c semaphore_timedwait_trap + 8
1   libdispatch.dylib                    0x0000000183262a00 _dispatch_semaphore_wait_slow + 68
2   libdispatch.dylib                    0x00000001832737e4 _dispatch_worker_thread + 244
3   libsystem_pthread.dylib              0x0000000183565220 _pthread_body + 268
4   libsystem_pthread.dylib              0x0000000183565110 _pthread_start + 288
5   libsystem_pthread.dylib              0x0000000183563b10 thread_start + 0

Thread 10:
0   libsystem_kernel.dylib               0x00000001833a3e5c semaphore_timedwait_trap + 8
1   libdispatch.dylib                    0x0000000183262a00 _dispatch_semaphore_wait_slow + 68
2   libdispatch.dylib                    0x00000001832737e4 _dispatch_worker_thread + 244
3   libsystem_pthread.dylib              0x0000000183565220 _pthread_body + 268
4   libsystem_pthread.dylib              0x0000000183565110 _pthread_start + 288
5   libsystem_pthread.dylib              0x0000000183563b10 thread_start + 0

Thread 11:
0   libsystem_kernel.dylib               0x00000001833a3e5c semaphore_timedwait_trap + 8
1   libdispatch.dylib                    0x0000000183262a00 _dispatch_semaphore_wait_slow + 68
2   libdispatch.dylib                    0x00000001832737e4 _dispatch_worker_thread + 244
3   libsystem_pthread.dylib              0x0000000183565220 _pthread_body + 268
4   libsystem_pthread.dylib              0x0000000183565110 _pthread_start + 288
5   libsystem_pthread.dylib              0x0000000183563b10 thread_start + 0

Thread 0 crashed with ARM-64 Thread State:
    pc: 0x00000001833c52ec     fp: 0x000000016ae4b2b0     sp: 0x000000016ae4b280     x0: 0x0000000000000000 
    x1: 0x0000000000000000     x2: 0x0000000000000000     x3: 0xffffffffffffffff     x4: 0x0000000000000010 
    x5: 0x0000000000000a1d     x6: 0x00000001c81a32c0     x7: 0x0000000000000a1e     x8: 0x0000000008000000 
    x9: 0x0000000004000000    x10: 0x0000000183566110    x11: 0x00000001b80b5f04    x12: 0x00000001b80b5f04 
   x13: 0x0000000000000018    x14: 0x0000000000000001    x15: 0x0000000000000881    x16: 0x0000000000000148 
   x17: 0x0000000000000000    x18: 0x0000000000000000    x19: 0x0000000000000006    x20: 0x00000001b5d00b40 
   x21: 0x00000001ae253098    x22: 0x0000000000000303    x23: 0x00000001b5d00c20    x24: 0x000000010ae2b2e0 
   x25: 0x00000001b5d0e000    x26: 0x00000001b440a000    x27: 0x00000001cc10ccc0    x28: 0x00000001839d539f 
    lr: 0x000000018356a6a8   cpsr: 0x0000000000000000

Note that ***** set current time to2: 1228.6467246747 is printed before calling player.seek(to: player.duration * Double(slider.value)) additionally tried replacing the above call to player.currentTime = player.duration * Double(slider.value) but crash still occurred

x-NR-x commented 6 years ago

Hi,

I ran tests on our sample apps, but couldn't reproduced the crash. Can you please provide me with a sample app that the crash can be seen. Is there any specific Media that it occurs?

Thanks.

kjoneandrei commented 6 years ago

Hi,

I was able to reproduce the crash in the playkit app with the existing video urls.

I created this pull request so you can have the exact same conditions where i recreated the crash

https://github.com/kaltura/playkit-ios-samples/pull/28

Note: You will need to slide back and forth several times, even if the video didn't finish buffering between slides

Thanks

TheoBendixson commented 6 years ago

I am the lead iOS developer from the Motor Trend team. We were also able to reproduce this crash when airplaying the Kaltura player from an iPhone 6S running iOS 11.4 to an Apple T.V. (4th generation) running tvOS 11.4.1.

To reproduce, we simply airplay a VOD from the Kaltura player to the Apple T.V. and start seeking either forward or backward. The crash happens consistently every time, and we get the exact same exception reported above (cannot seek to time INVALID).

Our team has yet to propose a solution to the crash, but I just wanted to add our voice to the issue. We will update you when we decide upon a course of action.

TheoBendixson commented 6 years ago

I should also point out that we tested this issue on two separate versions of PlayKit.

On the older version (3.1.x-dev), the crash happens the moment you start seeking during an Apple T.V. airplay session.

On the newer version (3.5.0), it takes a little longer for the crash to happen. In our testing experience, you had to seek back and forth several times before the crash would trigger.

So it's pretty clear that the library keeps getting better, but there's still an underlying issue here.

x-NR-x commented 6 years ago

Hi Anho and Theodore,

First of all thank you. I performed a fix on branch FEM-2097. I still need to check that this fix works correctly with all kinds of medias. You are more than welcome to try it out.

TheoBendixson commented 6 years ago

Thank you! We'll give it a try.

x-NR-x commented 6 years ago

Merged to develop. Will be included in our next release.

kjoneandrei commented 6 years ago

@x-NR-x do you know when the next release will be?

x-NR-x commented 6 years ago

Hi @kjoneandrei ,

The version including the fix has been released, v3.5.0.

kjoneandrei commented 6 years ago

@x-NR-x thank you :), it just seems like FEM-2097. was only merged on Jul 25, 2018 and version 3.5.0 released released this on 13 Jun

I got this dates when checking this log here https://github.com/kaltura/playkit-ios/compare/v3.5.0...develop

kaltura / playkit-ios