search

sadr0b0t / yashlang

PeerTube and YouTube player for Android with local playlists and whitelisted recommendations
GNU General Public License v3.0
50 stars 3 forks source link

Фантомные уведомления с управлением плеера #194

Open sadr0b0t opened 1 year ago

sadr0b0t commented 1 year ago

Фантомные уведомления:

Если клинкуть на кнопках уведомления несколько раз подряд а потом быстро нажать кнопку "стоп" (остановить сервис), уведомление исчезнет, а потом сразу появится снова, при этом кнопки на нем работать не будут.

отсюда отдельно https://github.com/sadr0b0t/yashlang/issues/7#issuecomment-1454026694

Кнопки не работают, т.к. сервис, судя по всему, в этот момент уже не запущен. И уведомление можно смахнуть вручную из панели (в ситуации, когда запущен сервис, оно так не смахивается).

Дело, судя по всему, в том, что команда создать уведомления вызывается/выполняется уже после того, как сервис остановлен, или где-то в процессе остановки сервиса.

При том, что сейчас для защиты от этого в месте создания уведомления стоит вот такой код:

    private void updateNotification() {
        if (!isBound && _isRunning) {
            // проверяем _isRunning тоже, т.к. может произойти ситуация, когда пльзователь
            // оставновил сервис командой stoSelf, но команда добавить обновление уже отправлена
            // и уведомление добавляется после того, как сервис остановлен
            final NotificationManagerCompat notificationManager = NotificationManagerCompat.from(this);
            notificationManager.notify(ConfigOptions.NOTIFICATION_ID_PLAYER, buildNotification());
        }
    }

Флаг _isRunning выставляется в onDestroy. Но это всё равно не помогает.

Варианты решения:

sadr0b0t commented 1 year ago

Добавил отладочной печати в разные события в код. Вот лог при фантоме (открыл видео подлиннее, перевел в фон, на уведомлении кликнул много раз подряд на "играть/пауза" и потом сразу "стоп" - текущее уведомление с панелькой сразу исчезло, а потом плавно появилось в неработающем и смахимаемом виде):

2023-03-06 21:48:17.521 32526-32526/su.sadrobot.yashlang I/System.out: PlayerService:updateNotification: isBound=false _isRunning=true, do update=true
2023-03-06 21:48:17.521 32526-32526/su.sadrobot.yashlang I/System.out: PlayerService:updateNotification -> notificationManager.notify
2023-03-06 21:48:17.962 32526-32526/su.sadrobot.yashlang I/System.out: PlayerService:onStartComman: PARAM_CMD=STOP
2023-03-06 21:48:17.969 32526-32554/su.sadrobot.yashlang D/EGL_emulation: eglMakeCurrent: 0xe4f851e0: ver 2 0 (tinfo 0xe4f83650)
2023-03-06 21:48:18.045 32526-32526/su.sadrobot.yashlang I/System.out: PlayerService:playVideoStream: video=null audio=null seekTo=0 paused=true
2023-03-06 21:48:18.065 32526-32526/su.sadrobot.yashlang I/System.out: PlayerService:updateNotification: isBound=false _isRunning=true, do update=true
2023-03-06 21:48:18.066 32526-32526/su.sadrobot.yashlang I/System.out: PlayerService:updateNotification -> notificationManager.notify
2023-03-06 21:48:18.124 32526-32526/su.sadrobot.yashlang I/System.out: PlayerService:onDestroy: _isRunning=false
2023-03-06 21:48:18.140 32526-32526/su.sadrobot.yashlang I/System.out: PlayerService:updateNotification: isBound=false _isRunning=false, do update=false
2023-03-06 21:48:18.140 32526-32526/su.sadrobot.yashlang I/ExoPlayerImpl: Release fe190c9 [ExoPlayerLib/2.18.1] [generic_x86, Android SDK built for x86, Google, 28] [goog.exo.core, goog.exo.ui, goog.exo.exoplayer, goog.exo.decoder, goog.exo.datasource, goog.exo.extractor]
2023-03-06 21:48:18.877 32526-32554/su.sadrobot.yashlang D/EGL_emulation: eglMakeCurrent: 0xe4f851e0: ver 2 0 (tinfo 0xe4f83650)
2023-03-06 21:48:18.982 32526-32538/su.sadrobot.yashlang I/drobot.yashlan: Background concurrent copying GC freed 116694(5MB) AllocSpace objects, 30(3MB) LOS objects, 45% free, 7MB/13MB, paused 79.645ms total 460.088ms
2023-03-06 21:48:20.179 32526-32526/su.sadrobot.yashlang I/System.out: PlayerService:playVideoStream: video=null audio=https://rr1---sn-wnj045oxu-bvwe.googlevideo.com/videoplayback?expire=1678150100&ei=dDUGZPHFKMXz7QTj9IyYAg&ip=136.169.214.191&id=o-AJvxIk9swypcWEbswNm0k2bgtHZS6Lvs1eDhD9Q7l10I&itag=140&source=youtube&requiressl=yes&mh=Tl&mm=31%2C29&mn=sn-wnj045oxu-bvwe%2Csn-n8v7znz7&ms=au%2Crdu&mv=m&mvi=1&pl=25&spc=H3gIhr5vceBxbeyuT-D6VWSeSmiCaXM&vprv=1&svpuc=1&mime=audio%2Fmp4&gir=yes&clen=134382868&dur=8303.455&lmt=1649601940751996&mt=1678128083&fvip=10&keepalive=yes&fexp=24007246&c=ANDROID&txp=6211224&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cgir%2Cclen%2Cdur%2Clmt&sig=AOq0QJ8wRQIgOzO7YWRMDCLEsiNpY_2ub_bP5BDAwhWXNUekqGm34wQCIQDWNyOqdk9Vp2QHhsZfJ_q5t4Fbdf3gj1ove5qK4r86GA%3D%3D&lsparams=mh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl&lsig=AG3C_xAwRQIgUHO4QPmu8lTCN-lbqLK4STPAj27O4--ZIszUvxGLa60CIQDy4MoN0VpVBdSlFXdIiBxwAgYEl_4KynZKW0BMrNxlig%3D%3D&cpn=c35n8Zu7kP2YrTti seekTo=24606 paused=false
2023-03-06 21:48:20.181 32526-32526/su.sadrobot.yashlang W/MessageQueue: Handler (android.os.Handler) {452dca8} sending message to a Handler on a dead thread
    java.lang.IllegalStateException: Handler (android.os.Handler) {452dca8} sending message to a Handler on a dead thread
        at android.os.MessageQueue.enqueueMessage(MessageQueue.java:546)
        at android.os.Handler.enqueueMessage(Handler.java:745)
        at android.os.Handler.sendMessageAtTime(Handler.java:697)
        at android.os.Handler.sendMessageDelayed(Handler.java:667)
        at android.os.Handler.sendMessage(Handler.java:604)
        at android.os.Message.sendToTarget(Message.java:436)
        at com.google.android.exoplayer2.util.SystemHandlerWrapper$SystemMessage.sendToTarget(SystemHandlerWrapper.java:153)
        at com.google.android.exoplayer2.ExoPlayerImplInternal.setMediaSources(ExoPlayerImplInternal.java:346)
        at com.google.android.exoplayer2.ExoPlayerImpl.setMediaSourcesInternal(ExoPlayerImpl.java:2156)
        at com.google.android.exoplayer2.ExoPlayerImpl.setMediaSources(ExoPlayerImpl.java:586)
        at com.google.android.exoplayer2.ExoPlayerImpl.setMediaSources(ExoPlayerImpl.java:580)
        at com.google.android.exoplayer2.ExoPlayerImpl.setMediaSource(ExoPlayerImpl.java:561)
        at com.google.android.exoplayer2.SimpleExoPlayer.setMediaSource(SimpleExoPlayer.java:839)
        at su.sadrobot.yashlang.service.PlayerService.playVideoStream(PlayerService.java:1390)
        at su.sadrobot.yashlang.service.PlayerService.access$1000(PlayerService.java:102)
        at su.sadrobot.yashlang.service.PlayerService$14.run(PlayerService.java:1224)
        at android.os.Handler.handleCallback(Handler.java:873)
        at android.os.Handler.dispatchMessage(Handler.java:99)
        at android.os.Looper.loop(Looper.java:193)
        at android.app.ActivityThread.main(ActivityThread.java:6669)
        at java.lang.reflect.Method.invoke(Native Method)
        at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:493)
        at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:858)
2023-03-06 21:48:20.183 32526-32526/su.sadrobot.yashlang W/MessageQueue: Handler (android.os.Handler) {452dca8} sending message to a Handler on a dead thread
    java.lang.IllegalStateException: Handler (android.os.Handler) {452dca8} sending message to a Handler on a dead thread
        at android.os.MessageQueue.enqueueMessage(MessageQueue.java:546)
        at android.os.Handler.enqueueMessage(Handler.java:745)
        at android.os.Handler.sendMessageAtTime(Handler.java:697)
        at android.os.Handler.sendMessageDelayed(Handler.java:667)
        at android.os.Handler.sendMessage(Handler.java:604)
        at android.os.Message.sendToTarget(Message.java:436)
        at com.google.android.exoplayer2.util.SystemHandlerWrapper$SystemMessage.sendToTarget(SystemHandlerWrapper.java:153)
        at com.google.android.exoplayer2.ExoPlayerImplInternal.prepare(ExoPlayerImplInternal.java:295)
        at com.google.android.exoplayer2.ExoPlayerImpl.prepare(ExoPlayerImpl.java:518)
        at com.google.android.exoplayer2.SimpleExoPlayer.prepare(SimpleExoPlayer.java:779)
        at su.sadrobot.yashlang.service.PlayerService.playVideoStream(PlayerService.java:1391)
        at su.sadrobot.yashlang.service.PlayerService.access$1000(PlayerService.java:102)
        at su.sadrobot.yashlang.service.PlayerService$14.run(PlayerService.java:1224)
        at android.os.Handler.handleCallback(Handler.java:873)
        at android.os.Handler.dispatchMessage(Handler.java:99)
        at android.os.Looper.loop(Looper.java:193)
        at android.app.ActivityThread.main(ActivityThread.java:6669)
        at java.lang.reflect.Method.invoke(Native Method)
        at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:493)
        at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:858)
2023-03-06 21:48:20.193 32526-32526/su.sadrobot.yashlang W/MessageQueue: Handler (android.os.Handler) {452dca8} sending message to a Handler on a dead thread
    java.lang.IllegalStateException: Handler (android.os.Handler) {452dca8} sending message to a Handler on a dead thread
        at android.os.MessageQueue.enqueueMessage(MessageQueue.java:546)
        at android.os.Handler.enqueueMessage(Handler.java:745)
        at android.os.Handler.sendMessageAtTime(Handler.java:697)
        at android.os.Handler.sendMessageDelayed(Handler.java:667)
        at android.os.Handler.sendMessage(Handler.java:604)
        at android.os.Message.sendToTarget(Message.java:436)
        at com.google.android.exoplayer2.util.SystemHandlerWrapper$SystemMessage.sendToTarget(SystemHandlerWrapper.java:153)
        at com.google.android.exoplayer2.ExoPlayerImplInternal.seekTo(ExoPlayerImplInternal.java:322)
        at com.google.android.exoplayer2.ExoPlayerImpl.seekTo(ExoPlayerImpl.java:830)
        at com.google.android.exoplayer2.SimpleExoPlayer.seekTo(SimpleExoPlayer.java:959)
        at com.google.android.exoplayer2.BasePlayer.seekTo(BasePlayer.java:131)
        at su.sadrobot.yashlang.service.PlayerService.playVideoStream(PlayerService.java:1404)
        at su.sadrobot.yashlang.service.PlayerService.access$1000(PlayerService.java:102)
        at su.sadrobot.yashlang.service.PlayerService$14.run(PlayerService.java:1224)
        at android.os.Handler.handleCallback(Handler.java:873)
        at android.os.Handler.dispatchMessage(Handler.java:99)
        at android.os.Looper.loop(Looper.java:193)
        at android.app.ActivityThread.main(ActivityThread.java:6669)
        at java.lang.reflect.Method.invoke(Native Method)
        at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:493)
        at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:858)
2023-03-06 21:48:20.195 32526-32526/su.sadrobot.yashlang W/MessageQueue: Handler (android.os.Handler) {452dca8} sending message to a Handler on a dead thread
    java.lang.IllegalStateException: Handler (android.os.Handler) {452dca8} sending message to a Handler on a dead thread
        at android.os.MessageQueue.enqueueMessage(MessageQueue.java:546)
        at android.os.Handler.enqueueMessage(Handler.java:745)
        at android.os.Handler.sendMessageAtTime(Handler.java:697)
        at android.os.Handler.sendMessageDelayed(Handler.java:667)
        at android.os.Handler.sendMessage(Handler.java:604)
        at android.os.Message.sendToTarget(Message.java:436)
        at com.google.android.exoplayer2.util.SystemHandlerWrapper$SystemMessage.sendToTarget(SystemHandlerWrapper.java:153)
        at com.google.android.exoplayer2.ExoPlayerImplInternal.setPlayWhenReady(ExoPlayerImplInternal.java:302)
        at com.google.android.exoplayer2.ExoPlayerImpl.updatePlayWhenReady(ExoPlayerImpl.java:2552)
        at com.google.android.exoplayer2.ExoPlayerImpl.setPlayWhenReady(ExoPlayerImpl.java:744)
        at com.google.android.exoplayer2.SimpleExoPlayer.setPlayWhenReady(SimpleExoPlayer.java:905)
        at su.sadrobot.yashlang.service.PlayerService.playVideoStream(PlayerService.java:1406)
        at su.sadrobot.yashlang.service.PlayerService.access$1000(PlayerService.java:102)
        at su.sadrobot.yashlang.service.PlayerService$14.run(PlayerService.java:1224)
        at android.os.Handler.handleCallback(Handler.java:873)
        at android.os.Handler.dispatchMessage(Handler.java:99)
        at android.os.Looper.loop(Looper.java:193)
        at android.app.ActivityThread.main(ActivityThread.java:6669)
        at java.lang.reflect.Method.invoke(Native Method)
        at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:493)
        at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:858)
2023-03-06 21:48:20.215 32526-32532/su.sadrobot.yashlang I/drobot.yashlan: JIT allocated 54KB for compiled code of java.lang.Object org.mozilla.javascript.Interpreter.interpretLoop(org.mozilla.javascript.Context, org.mozilla.javascript.Interpreter$CallFrame, java.lang.Object)
2023-03-06 21:48:20.290 32526-32538/su.sadrobot.yashlang I/drobot.yashlan: Background concurrent copying GC freed 77434(3MB) AllocSpace objects, 18(2MB) LOS objects, 46% free, 6MB/12MB, paused 5.428ms total 91.863ms

На эксепшен "sending message to a Handler on a dead thread" можно не обращать внимания - это не вылет, а ругается ExoPlayer за то, что к нему пытаются обращаться из убитого потока (в интернетах пишут, что можно игнорировать).

Вариант с фильтром по "PlayerService", чтобы было видно только напечатанные новые отладки:

2023-03-06 21:48:16.666 32526-32526/su.sadrobot.yashlang I/System.out: PlayerService:updateNotification -> notificationManager.notify
2023-03-06 21:48:16.918 32526-32526/su.sadrobot.yashlang I/System.out: PlayerService:onStartComman: PARAM_CMD=PLAY
2023-03-06 21:48:17.521 32526-32526/su.sadrobot.yashlang I/System.out: PlayerService:updateNotification: isBound=false _isRunning=true, do update=true
2023-03-06 21:48:17.521 32526-32526/su.sadrobot.yashlang I/System.out: PlayerService:updateNotification -> notificationManager.notify
2023-03-06 21:48:17.962 32526-32526/su.sadrobot.yashlang I/System.out: PlayerService:onStartComman: PARAM_CMD=STOP
2023-03-06 21:48:18.045 32526-32526/su.sadrobot.yashlang I/System.out: PlayerService:playVideoStream: video=null audio=null seekTo=0 paused=true
2023-03-06 21:48:18.065 32526-32526/su.sadrobot.yashlang I/System.out: PlayerService:updateNotification: isBound=false _isRunning=true, do update=true
2023-03-06 21:48:18.066 32526-32526/su.sadrobot.yashlang I/System.out: PlayerService:updateNotification -> notificationManager.notify
2023-03-06 21:48:18.124 32526-32526/su.sadrobot.yashlang I/System.out: PlayerService:onDestroy: _isRunning=false
2023-03-06 21:48:18.140 32526-32526/su.sadrobot.yashlang I/System.out: PlayerService:updateNotification: isBound=false _isRunning=false, do update=false
2023-03-06 21:48:20.179 32526-32526/su.sadrobot.yashlang I/System.out: PlayerService:playVideoStream: video=null audio=https://rr1---sn-wnj045oxu-bvwe.googlevideo.com/videoplayback?expire=1678150100&ei=dDUGZPHFKMXz7QTj9IyYAg&ip=136.169.214.191&id=o-AJvxIk9swypcWEbswNm0k2bgtHZS6Lvs1eDhD9Q7l10I&itag=140&source=youtube&requiressl=yes&mh=Tl&mm=31%2C29&mn=sn-wnj045oxu-bvwe%2Csn-n8v7znz7&ms=au%2Crdu&mv=m&mvi=1&pl=25&spc=H3gIhr5vceBxbeyuT-D6VWSeSmiCaXM&vprv=1&svpuc=1&mime=audio%2Fmp4&gir=yes&clen=134382868&dur=8303.455&lmt=1649601940751996&mt=1678128083&fvip=10&keepalive=yes&fexp=24007246&c=ANDROID&txp=6211224&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cgir%2Cclen%2Cdur%2Clmt&sig=AOq0QJ8wRQIgOzO7YWRMDCLEsiNpY_2ub_bP5BDAwhWXNUekqGm34wQCIQDWNyOqdk9Vp2QHhsZfJ_q5t4Fbdf3gj1ove5qK4r86GA%3D%3D&lsparams=mh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl&lsig=AG3C_xAwRQIgUHO4QPmu8lTCN-lbqLK4STPAj27O4--ZIszUvxGLa60CIQDy4MoN0VpVBdSlFXdIiBxwAgYEl_4KynZKW0BMrNxlig%3D%3D&cpn=c35n8Zu7kP2YrTti seekTo=24606 paused=false

здесь видно, что попытка вызвать updateNotification после onDestroy происходит, но она отклоняется из--за выставленных флагов. Т.е. в этом месте всё ок по расчету. Но уведомление всё равно появилось.

В onDestroy уведомление должно убиваться из stopForeground(true). Попробовал вывести больше отладок вокруг этого вызова:

        if (ConfigOptions.DEVEL_MODE_ON) {
            System.out.println("PlayerService:onDestroy:stopForeground...");
        }
        stopForeground(true);
        if (ConfigOptions.DEVEL_MODE_ON) {
            System.out.println("PlayerService:onDestroy:stopForeground...DONE");
        }

И в таком варианте поймать фантом вообще не получается. После того, как закомментировал эти принты, фантом опять ловится относительно легко. Коментил сначала первый, потом второй. Фантом получается только если нет обоих.

sadr0b0t commented 1 year ago

здесь пишут, что уведомление отображается секунд 5 после того, как сервис остановлен https://stackoverflow.com/questions/63940662/foreground-notification-still-appearing-after-intent-service-destroyed

но этот фантом, если появляется, то вообще не исчезает, в т.ч. и через 5 секунд.

и еще что-то про сервисы и уведомления: https://sharetechnotes.com/technotes/android-allow-notification-to-be-cancelled-after-calling-stopforegroundfalse/