search

pachli / pachli-android

The Pachli Android app
https://pachli.app
GNU General Public License v3.0
134 stars 15 forks source link

App Crashes #662

Open SevenFactors opened 7 months ago

SevenFactors commented 7 months ago

Describe the bug

This is on a Pixel 5a running GrapheneOS (latest) which is based on Android 14

Pachli crashes and in such a way that it lags, it comes non-responsive and there are times that right after that, when trying to interact with the app, this becomes black/blank. When I open the view which shows all the open apps, the pachli icon is show but the app is not shown at all. I guess this would be a full app crash.

To get it working I again, I wipe the pachli off said running apps list and restart it. I would say 95% of the times, after rebooting the pachli, I instantly start getting notification from pachli.

Perhaps the app crashing during use has to do something with incoming pachli notifications?

To Reproduce Steps to reproduce the behavior:

Normal app use. The app doesn't crash all the time but when it does is during use. I've been using Pachli for 2 weeks and while I've gone days with no crash, I've had days when pachli crashing more often than not.

I don't know if the app crashes while int he background. The only thing I can offer on this area is that there are times I get notifications 60 to 90 minutes after said Toot was made while there are times I get notification 15 after the said Toot was made.

The 15m notification is in part with my Tusky experience.

Expected behavior No app crashing, at least not at this level and as often.

Versions 2.4.0

On the error logs the following repeats many times. BpfNetMapsReader: getDataSaverEnabled is not expected to be called on pre-V devices

nikclayton commented 7 months ago

Hi, thanks for the report, sorry you're seeing this.

After a bit of research I think this is an ongoing issue with recent changes in Graphene. Their issue tracker shows a number of issues that look related, like:

Are you able to get full logs from your device when this happens?

For the general issue of slow notification delivery, can you take a look at https://pachli.app/pachli/2024/02/17/debugging-notifications.html and see if the steps there resolve the issue for you.

SevenFactors commented 7 months ago

Hi, thanks for the report, sorry you're seeing this.

After a bit of research I think this is an ongoing issue with recent changes in Graphene. Their issue tracker shows a number of issues that look related, like:

* [Error in System UI, not responding. Several times within an hour. GrapheneOS/os-issue-tracker#3446](https://github.com/GrapheneOS/os-issue-tracker/issues/3446)

* [system-server: crash when running YT Revanced video and opening Discord GrapheneOS/os-issue-tracker#3449](https://github.com/GrapheneOS/os-issue-tracker/issues/3449)

Are you able to get full logs from your device when this happens?

For the general issue of slow notification delivery, can you take a look at https://pachli.app/pachli/2024/02/17/debugging-notifications.html and see if the steps there resolve the issue for you.

Thank you for your very informative reply. The notification article should be a must read for every user.

I've not experienced any other apps crashing or GOS GUI crashing on me. I don't use the youtube app so I can't comment on that issue either.

After Pachli crashes, GOS keeps working as smooth as usual. After pachli crashes (becomes black then blank) I'm able to just swipe the app off and restart it. Sometimes the app works well for a couple of hours till it crashes again. Other times after the restarting, pachli can go into a crashing chain (2-5 crashes in a road) at which point I give up and let it be for a while.

-- EDIT -- In regards to Notifications For Patchli under Patchli/App Info/App Battery Usage/Manage Battery Usage/ I have had Background usage enabled. Yet under Patchli/About/Notification/Pull Notifications with Periodic Workers "Pachli is exempt from battery optimization?" is not showing a check mark. The commentary under it confirms it. It reads" Pachli is not exempt from battery optimization. Android maybe delaying notifications whenever the screen is off.

During my first setup of Pachli I'd already enabled android notifications. I even went ahead and enabled "Background Activity" which originally was off. NOTE: This did not enable a silent notification.
-- /EDIT --

This log were taken right after a crash. Hopefully this can bring light to the issue.

Pachli log f8e0cf857880.txt

nikclayton commented 7 months ago

Thanks for the log. That shows video playback (I think). Does this problem only happen when you're playing videos?

nikclayton commented 7 months ago

Looks like an ExoPlayer ANR. From the log:

At ...722 seconds, resumes ViewMediaActivity

         1714450722.442 19971 19971 I view_enqueue_input_event: [eventType=Motion - Cancel,action=app.pachli/app.pachli.components.viewthread.ViewThreadActivity]
         1714450722.517 19971 19971 I wm_on_top_resumed_lost_called: [Token=152381796,Component Name=app.pachli.components.viewthread.ViewThreadActivity,Reason=topStateChangedWhenResumed]
         1714450722.517 19971 19971 I wm_on_paused_called: [Token=152381796,Component Name=app.pachli.components.viewthread.ViewThreadActivity,Reason=performPause,time=0ms]
         1714450722.526 19971 19971 I wm_on_restart_called: [Token=33026327,Component Name=app.pachli.ViewMediaActivity,Reason=performRestart,time=0ms]
         1714450722.532 19971 19971 I wm_on_start_called: [Token=33026327,Component Name=app.pachli.ViewMediaActivity,Reason=handleStartActivity,time=6ms]
         1714450722.533 19971 19971 I wm_on_resume_called: [Token=33026327,Component Name=app.pachli.ViewMediaActivity,Reason=RESUME_ACTIVITY,time=0ms]
         1714450722.533 19971 19971 I wm_on_top_resumed_gained_called: [Token=33026327,Component Name=app.pachli.ViewMediaActivity,Reason=topWhenResuming]

Creates media decoder

         1714450722.535 19971 19971 D VRI[ViewMediaActivity]: applyTransactionOnDraw applyImmediately
         1714450722.807 19971 26567 D CCodec  : allocate(c2.qti.avc.decoder)
         1714450722.810 19971 26567 I CCodec  : setting up 'default' as default (vendor) store
         1714450722.819 19971 26567 I CCodec  : Created component [c2.qti.avc.decoder]
         1714450722.820 19971 26567 D CCodecConfig: read media type: video/avc
         1714450722.824 19971 26567 D ReflectedParamUpdater: ignored struct field vendor.qti-ext-dec-panscan.window
         1714450722.824 19971 26567 D ReflectedParamUpdater: extent() != 1 for single value type: output.buffers.pool-ids.values
         1714450722.824 19971 26567 D ReflectedParamUpdater: extent() != 1 for single value type: vendor.qti-ext-dec-info-misr.misr_info_top_field.misr_dpb_luma
         1714450722.824 19971 26567 D ReflectedParamUpdater: extent() != 1 for single value type: vendor.qti-ext-dec-info-misr.misr_info_top_field.misr_dpb_chroma
         1714450722.824 19971 26567 D ReflectedParamUpdater: extent() != 1 for single value type: vendor.qti-ext-dec-info-misr.misr_info_top_field.misr_opb_luma
         1714450722.824 19971 26567 D ReflectedParamUpdater: extent() != 1 for single value type: vendor.qti-ext-dec-info-misr.misr_info_top_field.misr_opb_chroma
         1714450722.825 19971 26567 D ReflectedParamUpdater: extent() != 1 for single value type: vendor.qti-ext-dec-info-misr.misr_info_bottom_field.misr_dpb_luma
         1714450722.825 19971 26567 D ReflectedParamUpdater: extent() != 1 for single value type: vendor.qti-ext-dec-info-misr.misr_info_bottom_field.misr_dpb_chroma
         1714450722.825 19971 26567 D ReflectedParamUpdater: extent() != 1 for single value type: vendor.qti-ext-dec-info-misr.misr_info_bottom_field.misr_opb_luma
         1714450722.825 19971 26567 D ReflectedParamUpdater: extent() != 1 for single value type: vendor.qti-ext-dec-info-misr.misr_info_bottom_field.misr_opb_chroma
         1714450722.827 19971 26567 D CCodecConfig: ignoring local param raw.size (0xd2001800) as it is already supported
         1714450722.827 19971 26567 D CCodecConfig: ignoring local param default.color (0x5200180b) as it is already supported
         1714450722.827 19971 26567 D CCodecConfig: ignoring local param raw.hdr-static-info (0xd200180a) as it is already supported
         1714450722.828 19971 26567 I CCodecConfig: query failed after returning 17 values (BAD_INDEX)
         1714450722.829 19971 26567 D CCodecConfig: c2 config diff is Dict {
         1714450722.829 19971 26567 D CCodecConfig:   c2::i32 algo.priority.value = -1
         1714450722.829 19971 26567 D CCodecConfig:   c2::float algo.rate.value = 30
         1714450722.829 19971 26567 D CCodecConfig:   c2::u32 algo.secure-mode.value = 0
         1714450722.829 19971 26567 D CCodecConfig:   c2::float coded.frame-rate.value = 30
         1714450722.829 19971 26567 D CCodecConfig:   c2::u32 coded.pl.level = 0
         1714450722.829 19971 26567 D CCodecConfig:   c2::u32 coded.pl.profile = 20484
         1714450722.829 19971 26567 D CCodecConfig:   c2::u32 coded.vui.color.matrix = 255
         1714450722.829 19971 26567 D CCodecConfig:   c2::u32 coded.vui.color.primaries = 0
         1714450722.829 19971 26567 D CCodecConfig:   c2::u32 coded.vui.color.range = 0
         1714450722.829 19971 26567 D CCodecConfig:   c2::u32 coded.vui.color.transfer = 255
         1714450722.829 19971 26567 D CCodecConfig:   c2::u32 default.color.matrix = 255
         1714450722.829 19971 26567 D CCodecConfig:   c2::u32 default.color.primaries = 0
         1714450722.829 19971 26567 D CCodecConfig:   c2::u32 default.color.range = 0
         1714450722.829 19971 26567 D CCodecConfig:   c2::u32 default.color.transfer = 255
         1714450722.829 19971 26567 D CCodecConfig:   c2::u32 input.buffers.max-size.value = 13271040
         1714450722.829 19971 26567 D CCodecConfig:   c2::u32 input.delay.value = 0
         1714450722.829 19971 26567 D CCodecConfig:   string input.media-type.value = "video/avc"
         1714450722.829 19971 26567 D CCodecConfig:   c2::u32 output.delay.value = 18
         1714450722.829 19971 26567 D CCodecConfig:   string output.media-type.value = "video/raw"
         1714450722.829 19971 26567 D CCodecConfig:   c2::u32 raw.color.matrix = 255
         1714450722.829 19971 26567 D CCodecConfig:   c2::u32 raw.color.primaries = 0
         1714450722.829 19971 26567 D CCodecConfig:   c2::u32 raw.color.range = 0
         1714450722.829 19971 26567 D CCodecConfig:   c2::u32 raw.color.transfer = 255
         1714450722.829 19971 26567 D CCodecConfig:   c2::float raw.hdr-static-info.mastering.blue.x = 0
         1714450722.829 19971 26567 D CCodecConfig:   c2::float raw.hdr-static-info.mastering.blue.y = 0
         1714450722.829 19971 26567 D CCodecConfig:   c2::float raw.hdr-static-info.master
         1714450722.829 19971 26567 W ColorUtils: expected specified color aspects (0:0:255:255)
         1714450722.833 19971 26566 I MediaCodec: MediaCodec will operate in async mode
         1714450722.833 19971 26566 D SurfaceUtils: connecting to surface 0xb400cc2066577010, reason connectToSurface
         1714450722.833 19971 26566 I MediaCodec: [c2.qti.avc.decoder] setting surface generation to 20450307
         1714450722.833 19971 26566 D SurfaceUtils: disconnecting from surface 0xb400cc2066577010, reason connectToSurface(reconnect)
         1714450722.833 19971 26566 D SurfaceUtils: connecting to surface 0xb400cc2066577000, reason connectToSurface(reconnect-with-listener)
         1714450722.834 19971 26567 D CCodec  : [c2.qti.avc.decoder] buffers are bound to CCodec for this session
         1714450722.834 19971 26567 D CCodecConfig: no c2 equivalents for log-session-id
         1714450722.834 19971 26567 D CCodecConfig: no c2 equivalents for color-standard
         1714450722.834 19971 26567 D CCodecConfig: no c2 equivalents for csd-1
         1714450722.834 19971 26567 D CCodecConfig: no c2 equivalents for native-window
         1714450722.834 19971 26567 D CCodecConfig: no c2 equivalents for native-window-generation
         1714450722.834 19971 26567 D CCodecConfig: no c2 equivalents for flags
         1714450722.835 19971 26567 D CCodecConfig: c2 config diff is   c2::i32 algo.priority.value = 0
         1714450722.835 19971 26567 D CCodecConfig:   c2::float algo.rate.value = 30.002
         1714450722.835 19971 26567 D CCodecConfig:   c2::float coded.frame-rate.value = 30.002
         1714450722.835 19971 26567 D CCodecConfig:   c2::u32 default.color.matrix = 1
         1714450722.835 19971 26567 D CCodecConfig:   c2::u32 default.color.primaries = 1
         1714450722.835 19971 26567 D CCodecConfig:   c2::u32 default.color.range = 2
         1714450722.835 19971 26567 D CCodecConfig:   c2::u32 default.color.transfer = 3
         1714450722.835 19971 26567 D CCodecConfig:   c2::u32 input.buffers.max-size.value = 884736
         1714450722.835 19971 26567 D CCodecConfig:   c2::u32 raw.max-size.height = 1024
         1714450722.835 19971 26567 D CCodecConfig:   c2::u32 raw.max-size.width = 576
         1714450722.835 19971 26567 D CCodecConfig:   c2::u32 raw.size.height = 1024
         1714450722.835 19971 26567 D CCodecConfig:   c2::u32 raw.size.width = 576
         1714450722.836 19971 26567 W Codec2Client: query -- param skipped: index = 1107298332.
         1714450722.836 19971 26567 D CCodec  : client requested max input size 35934, which is smaller than what component recommended (884736); overriding with component recommendation.
         1714450722.836 19971 26567 W CCodec  : This behavior is subject to change. It is recommended that app developers double check whether the requested max input size is in reasonable range.
         1714450722.836 19971 26567 D CCodec  : encoding statistics level = 0
         1714450722.837 19971 26567 D CCodec  : setup formats input: AMessage(what = 0x00000000) = {
         1714450722.837 19971 26567 D CCodec  :   int32_t feature-secure-playback = 0
         1714450722.837 19971 26567 D CCodec  :   int32_t frame-rate = 30
         1714450722.837 19971 26567 D CCodec  :   int32_t height = 1024
         1714450722.837 19971 26567 D CCodec  :   int32_t max-input-size = 884736
         1714450722.837 19971 26567 D CCodec  :   string mime = "video/avc"
         1714450722.837 19971 26567 D CCodec  :   int32_t priority = 0
         1714450722.837 19971 26567 D CCodec  :   int32_t profile = 8
         1714450722.837 19971 26567 D CCodec  :   int32_t width = 576
         1714450722.837 19971 26567 D CCodec  :   Rect crop(0, 0, 575, 1023)
         1714450722.837 19971 26567 D CCodec  : }
         1714450722.837 19971 26567 D CCodec  : setup formats output: AMessage(what = 0x00000000) = {
         1714450722.837 19971 26567 D CCodec  :   int32_t android._color-format = 0
         1714450722.837 19971 26567 D CCodec  :   int32_t android._video-scaling = 1
         1714450722.837 19971 26567 D CCodec  :   int32_t android._dataspace = 260
         1714450722.837 19971 26567 D CCodec  :   int32_t color-standard = 130817
         1714450722.837 19971 26567 D CCodec  :   int32_t color-range = 2
         1714450722.837 19971 26567 D CCodec  :   int32_t color-transfer = 65791
         1714450722.837 19971 26567 D CCodec  :   int32_t sar-height = 1
         1714450722.837 19971 26567 D CCodec  :   int32_t rotation-degrees = 0
         1714450722.837 19971 26567 D CCodec  :   Buffer hdr-static-info = {
         1714450722.837 19971 26567 D CCodec  :     00000000:  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
         1714450722.837 19971 26567 D CCodec  :     00000010:  00 00 00 00 00 00 00 00  00                       .........
         1714450722.837 19971 26567 D CCodec  :   }
         1714450722.837 19971 26567 D CCodec  :   int32_t sar-width = 1
         1714450722.837 19971 26567 D CCodec  :   Rect crop(0, 0, 575, 1023)
         1714450722.837 19971 26567 D CCodec  :   int32_t width = 576
         1714450722.837 19971 26567 D CCodec  :   int32_t feature-secure-playback = 0
         1714450722.837 19971 26567 D CCodec  :   int32_t frame-rate = 30
         1714450722.837 19971 26567 D CCodec  :   int32_t height = 1024
         1714450722.837 19971 26567 D CCodec  :   int32_t max-height = 1024
         1714450722.837 19971 26567 D CCodec  :   int32_t max-width = 576
         1714450722.837 19971 26567 D CCodec  :   string mime = "video/raw"
         1714450722.837 19971 26567 D CCodec  :   int32_t priority = 0
         1714450722.837 19971 26567 D CCodec  :   int32_t color-format = 2130708361
         1714450722.837 19971 26567 D CCodec  : }
         1714450722.837 19971 26567 I CCodecConfig: query failed after returning 17 values (BAD_INDEX)
         1714450722.838 19971 26564 D MediaCodec: keep callback message for reclaim
         1714450722.849 19971 26567 W Codec2Client: query -- param skipped: index = 1342179345.
         1714450722.849 19971 26567 W Codec2Client: query -- param skipped: index = 2415921170.
         1714450722.849 19971 26567 W Codec2Client: query -- param skipped: index = 1610614798.
         1714450722.850 19971 26567 D CCodecBufferChannel: [c2.qti.avc.decoder#668] Query input allocators returned 0 params => BAD_INDEX (6)
         1714450722.850 19971 26567 D CCodecBufferChannel: [c2.qti.avc.decoder#668] Created input block pool with allocatorID 16 => poolID 19 - OK (0)
         1714450722.850 19971 26567 D CCodecBufferChannel: [c2.qti.avc.decoder#668] Query output allocators returned 0 params => BAD_INDEX (6)
         1714450722.850 19971 26567 D CCodecBufferChannel: [c2.qti.avc.decoder#668] Query output surface allocator returned 0 params => BAD_INDEX (6)
         1714450722.850 19971 26567 I CCodecBufferChannel: [c2.qti.avc.decoder#668] Created output block pool with allocatorID 18 => poolID 443 - OK
         1714450722.851 19971 26567 D CCodecBufferChannel: [c2.qti.avc.decoder#668] Configured output block pool ids 443 => OK
         1714450722.851 19971 26567 D Codec2-OutputBufferQueue: remote graphic buffer migration 0/0
         1714450722.851 19971 26567 D Codec2Client: setOutputSurface -- failed to set consumer usage (6/BAD_INDEX)
         1714450722.851 19971 26567 D Codec2Client: setOutputSurface -- generation=20450307 consumer usage=0x900
         1714450722.852 19971 26567 D Codec2Client: Surface configure completed
         1714450722.856 19971 26572 D CCodec  : allocate(c2.android.aac.decoder)
         1714450722.859 19971 26572 I CCodec  : setting up 'default' as default (vendor) store
         1714450722.866 19971 26518 D CCodecBufferChannel: [c2.qti.avc.decoder#668] Ignoring stale input buffer done callback: last flush index = 0, frameIndex = 0
         1714450722.872 19971 26572 D CCodecConfig: read media type: audio/mp4a-latm
         1714450722.875 19971 26572 D ReflectedParamUpdater: extent() != 1 for single value type: algo.buffers.max-count.values
         1714450722.875 19971 26572 D ReflectedParamUpdater: extent() != 1 for single value type: output.subscribed-indices.values
         1714450722.875 19971 26572 D ReflectedParamUpdater: extent() != 1 for single value type: input.buffers.allocator-ids.values
         1714450722.875 19971 26572 D ReflectedParamUpdater: extent() != 1 for single value type: output.buffers.allocator-ids.values
         1714450722.875 19971 26572 D ReflectedParamUpdater: extent() != 1 for single value type: algo.buffers.allocator-ids.values
         1714450722.875 19971 26572 D ReflectedParamUpdater: extent() != 1 for single value type: output.buffers.pool-ids.values
         1714450722.876 19971 26572 D ReflectedParamUpdater: extent() != 1 for single value type: algo.buffers.pool-ids.values
         1714450722.879 19971 26572 I CCodecConfig: query failed after returning 20 values (BAD_INDEX)
         1714450722.879 19971 26572 D CCodecConfig: c2 config diff is Dict {
         1714450722.879 19971 26572 D CCodecConfig:   c2::u32 coded.aac-packaging.value = 0
         1714450722.879 19971 26572 D CCodecConfig:   c2::u32 coded.bitrate.value = 64000
         1714450722.879 19971 26572 D CCodecConfig:   c2::u32 coded.pl.level = 0
         1714450722.879 19971 26572 D CCodecConfig:   c2::u32 coded.pl.profile = 8192
         1714450722.879 19971 26572 D CCodecConfig:   c2::i32 coding.drc.album-mode.value = 0
         1714450722.879 19971 26572 D CCodecConfig:   c2::float coding.drc.attenuation-factor.value = 1
         1714450722.879 19971 26572 D CCodecConfig:   c2::float coding.drc.boost-factor.value = 1
         1714450722.879 19971 26572 D CCodecConfig:   c2::i32 coding.drc.compression-mode.value = 3
         1714450722.879 19971 26572 D CCodecConfig:   c2::i32 coding.drc.effect-type.value = 3
         1714450722.879 19971 26572 D CCodecConfig:   c2::float coding.drc.encoded-level.value = 0.25
         1714450722.879 19971 26572 D CCodecConfig:   c2::float coding.drc.reference-level.value = -16
         1714450722.879 19971 26572 D CCodecConfig:   c2::u32 input.buffers.max-size.value = 8192
         1714450722.879 19971 26572 D CCodecConfig:   c2::u32 input.delay.value = 0
         1714450722.879 19971 26572 D CCodecConfig:   string input.media-type.value = "audio/mp4a-latm"
         1714450722.879 19971 26572 D CCodecConfig:   c2::u32 output.delay.value = 2
         1714450722.879 19971 26572 D CCodecConfig:   c2::float output.drc.output-loudness.value = 0.25
         1714450722.879 19971 26572 D CCodecConfig:   string output.media-type.value = "audio/raw"
         1714450722.879 19971 26572 D CCodecConfig:   c2::u32 raw.channel-count.value = 1
         1714450722.879 19971 26572 D CCodecConfig:   c2::u32 raw.channel-mask.value = 0
         1714450722.879 19971 26572 D CCodecConfig:   c2::u32 raw.max-channel-count.value = 8
         1714450722.879 19971 26572 D CCodecConfig:   c2::u32 raw.sample-rate.value = 44100
         1714450722.879 19971 26572 D CCodecConfig: }
         1714450722.881 19971 26572 I MediaCodec: MediaCodec will operate in async mode
         1714450722.881 19971 26572 D CCodec  : [c2.android.aac.decoder] buffers are bound to CCodec for this session
         1714450722.882 19971 26572 D CCodecConfig: no c2 equivalents for log-session-id
         1714450722.882 19971 26572 D CCodecConfig: no c2 equivalents for flags
         1714450722.882 19971 26572 D CCodecConfig: config failed => CORRUPTED
         1714450722.882 19971 26572 D CCodecConfig: c2 config diff is   c2::u32 raw.channel-count.value = 2
         1714450722.882 19971 26572 D CCodecConfig:   c2::u32 raw.sample-rate.value = 48000
         1714450722.883 19971 26572 W Codec2Client: query -- param skipped: index = 1107298332.
         1714450722.883 19971 26572 D CCodec  : client requested max input size 529, which is smaller than what component recommended (8192); overriding with component recommendation.
         1714450722.883 19971 26572 W CCodec  : This behavior is subject to change. It is recommended that app developers double check whether the requested max input size is in reasonable range.
         1714450722.883 19971 26572 D CCodec  : encoding statistics level = 0
         1714450722.883 19971 26572 D CCodec  : setup formats input: AMessage(what = 0x00000000) = {
         1714450722.883 19971 26572 D CCodec  :   int32_t aac-drc-album-mode = 0
         1714450722.883 19971 26572 D CCodec  :   int32_t aac-drc-boost-level = 127
         1714450722.883 19971 26572 D CCodec  :   int32_t aac-drc-cut-level = 127
         1714450722.883 19971 26572 D CCodec  :   int32_t aac-drc-effect-type = 3
         1714450722.883 19971 26572 D CCodec  :   int32_t aac-encoded-target-level = -1
         1714450722.883 19971 26572 D CCodec  :   int32_t aac-max-output-channel_count = 8
         1714450722.883 19971 26572 D CCodec  :   int32_t aac-target-ref-level = 64
         1714450722.883 19971 26572 D CCodec  :   int32_t bitrate = 64000
         1714450722.883 19971 26572 D CCodec  :   int32_t channel-count = 2
         1714450722.883 19971 26572 D CCodec  :   int32_t channel-mask = 0
         1714450722.883 19971 26572 D CCodec  :   int32_t level = 0
         1714450722.883 19971 26572 D CCodec  :   int32_t max-input-size = 8192
         1714450722.883 19971 26572 D CCodec  :   int32_t max-output-channel-count = 8
         1714450722.883 19971 26572 D CCodec  :   string mime = "audio/mp4a-latm"
         1714450722.883 19971 26572 D CCodec  :   int32_t profile = 2
         1714450722.883 19971 26572 D CCodec  :   int32_t sample-rate = 48000
         1714450722.883 19971 26572 D CCodec  : }
         1714450722.883 19971 26572 D CCodec  : setup formats output: AMessage(what = 0x00000000) = {
         1714450722.883 19971 26572 D CCodec  :   int32_t aac-drc-album-mode = 0
         1714450722.883 19971 26572 D CCodec  :   int32_t aac-drc-boost-level = 127
         1714450722.883 19971 26572 D CCodec  :   int32_t aac-drc-cut-level = 127
         1714450722.883 19971 26572 D CCodec  :   int32_t aac-drc-effect-type = 3
         1714450722.883 19971 26572 D CCodec  :   int32_t aac-drc-output-loudness = -1
         1714450722.883 19971 26572 D CCodec  :   int32_t aac-encoded-target-level = -1
         1714450722.883 19971 26572 D CCodec  :   int32_t aac-max-output-channel_count = 8
         1714450722.883 19971 26572 D CCodec  :   int32_t aac-target-ref-level = 64
         1714450722.883 19971 26572 D CCodec  :   int32_t channel-count = 2
         1714450722.883 19971 26572 D CCodec  :   int32_t channel-mask = 0
         1714450722.883 19971 26572 D CCodec  :   int32_t max-output-channel-count = 8
         1714450722.883 19971 26572 D CCodec  :   string mime = "audio/raw"
         1714450722.883 19971 26572 D CCodec  :   int32_t sample-rate = 48000
         1714450722.883 19971 26572 D CCodec  :   int32_t android._config-pcm-encoding = 2
         1714450722.883 19971 26572 D CCodec  : }
         1714450722.884 19971 26572 I CCodecConfig: query failed after returning 20 values (BAD_INDEX)
         1714450722.884 19971 26564 D MediaCodec: keep callback message for reclaim
         1714450722.886 19971 26572 W Codec2Client: query -- param skipped: index = 1342179345.
         1714450722.886 19971 26572 W Codec2Client: query -- param skipped: index = 2415921170.
         1714450722.886 19971 26572 W Codec2Client: query -- param skipped: index = 1610614798.
         1714450722.887 19971 26572 D CCodecBufferChannel: [c2.android.aac.decoder#952] Created input block pool with allocatorID 16 => poolID 20 - OK (0)
         1714450722.888 19971 26572 I CCodecBufferChannel: [c2.android.aac.decoder#952] Created output block pool with allocatorID 16 => poolID 818 - OK
         1714450722.888 19971 26572 D CCodecBufferChannel: [c2.android.aac.decoder#952] Configured output block pool ids 818 => OK
         1714450722.899 19971 26567 D CCodecConfig: c2 config diff is   c2::u32 raw.color.matrix = 1
         1714450722.899 19971 26567 D CCodecConfig:   c2::u32 raw.color.primaries = 1
         1714450722.899 19971 26567 D CCodecConfig:   c2::u32 raw.color.range = 2
         1714450722.899 19971 26567 D CCodecConfig:   c2::u32 raw.color.transfer = 3
         1714450722.899 19971 26567 D CCodecConfig:   c2::u32 raw.crop.height = 1024
         1714450722.899 19971 26567 D CCodecConfig:   c2::u32 raw.crop.left = 0
         1714450722.899 19971 26567 D CCodecConfig:   c2::u32 raw.crop.top = 0
         1714450722.899 19971 26567 D CCodecConfig:   c2::u32 raw.crop.width = 576
         1714450722.900 19971 26567 D Codec2-OutputBufferQueue: set max dequeue count 25 from update
         1714450722.900 19971 26567 D CCodecBuffers: [c2.qti.avc.decoder#668:2D-Output] popFromStashAndRegister: at 1000000000000us, output format changed to AMessage(what = 0x00000000) = {
         1714450722.900 19971 26567 D CCodecBuffers:   int32_t android._color-format = 0
         1714450722.900 19971 26567 D CCodecBuffers:   int32_t android._video-scaling = 1
         1714450722.900 19971 26567 D CCodecBuffers:   int32_t android._dataspace = 260
         1714450722.900 19971 26567 D CCodecBuffers:   int32_t color-standard = 1
         1714450722.900 19971 26567 D CCodecBuffers:   int32_t color-range = 2
         1714450722.900 19971 26567 D CCodecBuffers:   int32_t color-transfer = 3
         1714450722.900 19971 26567 D CCodecBuffers:   int32_t sar-height = 1
         1714450722.900 19971 26567 D CCodecBuffers:   int32_t rotation-degrees = 0
         1714450722.900 19971 26567 D CCodecBuffers:   Buffer hdr-static-info = {
         1714450722.900 19971 26567 D CCodecBuffers:     00000000:  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
         1714450722.900 19971 26567 D CCodecBuffers:     00000010:  00 00 00 00 00 00 00 00  00                       .........
         1714450722.900 19971 26567 D CCodecBuffers:   }
         1714450722.900 19971 26567 D CCodecBuffers:   int32_t sar-width = 1
         1714450722.900 19971 26567 D CCodecBuffers:   Rect crop(0, 0, 575, 1023)
         1714450722.900 19971 26567 D CCodecBuffers:   int32_t width = 576
         1714450722.900 19971 26567 D CCodecBuffers:   int32_t feature-secure-playback = 0
         1714450722.900 19971 26567 D CCodecBuffers:   int32_t frame-rate = 30
         1714450722.900 19971 26567 D CCodecBuffers:   int32_t height = 1024
         1714450722.900 19971 26567 D CCodecBuffers:   int32_t max-height = 1024
         1714450722.900 19971 26567 D CCodecBuffers:   int32_t max-width = 576
         1714450722.900 19971 26567 D CCodecBuffers:   string mime = "video/raw"
         1714450722.900 19971 26567 D CCodecBuffers:   int32_t priority = 0
         1714450722.900 19971 26567 D CCodecBuffers:   int32_t color-format = 2130708361
         1714450722.900 19971 26567 D CCodecBuffers: }
         1714450722.911 19971 26572 D CCodecConfig: c2 config diff is   c2::u32 raw.channel-mask.value = 12
         1714450722.911 19971 26572 D CCodecBuffers: [c2.android.aac.decoder#952:Output[N]] popFromStashAndRegister: at 1000000000000us, output format changed to AMessage(what = 0x00000000) = {
         1714450722.911 19971 26572 D CCodecBuffers:   int32_t aac-drc-album-mode = 0
         1714450722.911 19971 26572 D CCodecBuffers:   int32_t aac-drc-boost-level = 127
         1714450722.911 19971 26572 D CCodecBuffers:   int32_t aac-drc-cut-level = 127
         1714450722.911 19971 26572 D CCodecBuffers:   int32_t aac-drc-effect-type = 3
         1714450722.911 19971 26572 D CCodecBuffers:   int32_t aac-drc-output-loudness = -1
         1714450722.911 19971 26572 D CCodecBuffers:   int32_t aac-encoded-target-level = -1
         1714450722.911 19971 26572 D CCodecBuffers:   int32_t aac-max-output-channel_count = 8
         1714450722.911 19971 26572 D CCodecBuffers:   int32_t aac-target-ref-level = 64
         1714450722.911 19971 26572 D CCodecBuffers:   int32_t channel-count = 2
         1714450722.911 19971 26572 D CCodecBuffers:   int32_t channel-mask = 12
         1714450722.911 19971 26572 D CCodecBuffers:   int32_t max-output-channel-count = 8
         1714450722.911 19971 26572 D CCodecBuffers:   string mime = "audio/raw"
         1714450722.911 19971 26572 D CCodecBuffers:   int32_t sample-rate = 48000
         1714450722.911 19971 26572 D CCodecBuffers:   int32_t android._config-pcm-encoding = 2
         1714450722.911 19971 26572 D CCodecBuffers: }

Then nothing for almost three seconds, then

         1714450725.252 19971 26517 D BufferPoolAccessor2.0: bufferpool2 0xb400cb101235e828 : 0(0 size) total buffers - 0(0 size) used buffers - 573/578 (recycle/alloc) - 5/568 (fetch/transfer)
         1714450725.252 19971 26517 D BufferPoolAccessor2.0: evictor expired: 1, evicted: 1
         1714450726.253 19971 26517 D BufferPoolAccessor2.0: bufferpool2 0xb400cb1012379228 : 0(0 size) total buffers - 0(0 size) used buffers - 373/379 (recycle/alloc) - 6/375 (fetch/transfer)
         1714450726.253 19971 26517 D BufferPoolAccessor2.0: evictor expired: 1, evicted: 1

Then a second later, an ANR because it's been 5 seconds with no response:

         1714450727.844 19971 19971 D VRI[ViewThreadActivity]: visibilityChanged oldVisibility=true newVisibility=false
         1714450727.871 19971 19971 D VRI[ViewThreadActivity]: Not drawing due to not visible
         1714450728.637 19971 19984 I app.pachli: Thread[6,tid=19984,WaitingInMainSignalCatcherLoop,Thread*=0xb400cbfae09f9c00,peer=0x155801d0,"Signal Catcher"]: reacting to signal 3

Possibly https://github.com/androidx/media/issues/767 or https://github.com/google/ExoPlayer/issues/11138 (?)

SevenFactors commented 7 months ago

Thanks for the log. That shows video playback (I think). Does this problem only happen when you're playing videos?

I do watch plenty of videos, "gif" and images that show on my timeline. While pachli has gone ANR during video playback, the majority of ANRs I've experienced happen while navigating the app (up and down the time line, changing tabs, etc, which highly likely happen after exiting a video or the like.

SevenFactors commented 7 months ago

Looks like an ExoPlayer ANR. From the log:

Possibly androidx/media#767 or google/ExoPlayer#11138 (?)

Should I report this to the above projects and/or GrapheneOS team?

SevenFactors commented 7 months ago

I regards of Pachli not recognizing being exempt from battery optimization. Does that show on the logs?

Does that show on the patchli notification logs? Is this an issue for GrapheneOS?

nikclayton commented 7 months ago

Looks like an ExoPlayer ANR. From the log: Possibly androidx/media#767 or google/ExoPlayer#11138 (?)

Should I report this to the above projects and/or GrapheneOS team?

I think they're already aware. https://github.com/androidx/media/issues/1336 looks relevant (someone having the same problem and wanting to move the media handling to a separate thread), so I'll look in to that.

But not for a few weeks I'm afraid, as I'll be on vacation. for a couple of weeks.

As for why the Pachli UI tells you Pachli is not exempt from battery optimisation; https://github.com/pachli/pachli-android/blob/main/feature/about/src/main/kotlin/app/pachli/feature/about/NotificationViewModel.kt#L129 is the code that checks to see if Pachli is exempt from battery optimisation.

If you can take a screen recording on the device that shows (a) Pachli is exempt from battery optimisation in the Graphene settings UI, and (b) Pachli's notification debug view shows that it is not exempt then I imagine the Graphene developers would be interested in that.