Deltachat-android: missing notifications

[webratte]

• Platform (android/blackberry/anbox): Android 7.0
• Device: Huawei nova
• Delta Chat Version: 0.500.0
• Expected behavior: notification for new message
• Actual behavior: no notification
• Steps to reproduce the problem:
• Screenshots:
• Logs: I will send a logfile to @r10s

[r10s]

Logs: I will send a logfile to @r10s

if possible, better create eg. a gist and link it from here. you can anonymize the log before posting.

[webratte]

Sorry, I don't know what's a gist 🤔
I have currently no PC and created this issue via smartphone.

If I'm home again I will to investigate to find out what's a gist and how to create it.

I've sendet the log already.

Maybe you also get no notification?!

[r10s]

Maybe you also get no notification?!

well, I've disabled most notifications :)

linking the log here, however, is better as
(a) someone else can pick up the problem and fix it
(b) others can compare if they have related problems
(c) I cannot lose the log :)

[webratte]

Good points 👍

But as I sayd before.
Currently I have only my Phone.
And anonymize the logfile with my phone is to fiddly for me 😉

[r10s]

thanks!

[webratte]

After tried to understand the logfile

(I found this lines: "06-29 15:55:37.157 10540 20995 W System.err: java.lang.NullPointerException: Attempt to invoke virtual method 'void android.media.Ringtone.play()' on a null object reference").

I have just disabled and enabled notifications.

Now it works for me.
Maybe it's related to the update of the DC version?!

[r10s]

@webratte thanks for figuring that out :)

@cyBerta can you please check this? maybe just wrap it by a try/catch block.

[csb0730]

Maybe related or same issue than #962 ?

[csb0730]

Described workaround from webratte doesn't help for #962.
I think these two issues are NOT related.

[adbenitez]

this problem is happening to some users, atm I got this log from one of them(will try to get logs for the others)

deltachat-log-20190704-094922.txt

some interesting lines of the log:

07-04 09:45:51.337 10687 10687 W SoundPool: Use of stream types is deprecated for operations other than volume control
07-04 09:45:51.337 10687 10687 W SoundPool: See the documentation of SoundPool() for what to use instead with android.media.AudioAttributes to qualify your playback use case
07-04 09:45:51.340 10687 10687 W SoundPoolThread: type=1400 audit(0.0:141666): avc: denied { read } for name="u:object_r:mtk_em_video_log_sf_postbuffer_prop:s0" dev="tmpfs" ino=212 scontext=u:r:untrusted_app:s0:c512,c768 tcontext=u:object_r:mtk_em_video_log_sf_postbuffer_prop:s0 tclass=file permissive=0
07-04 09:45:51.340 10687 10687 W SoundPoolThread: type=1400 audit(0.0:141667): avc: denied { read } for name="u:object_r:mtk_em_video_log_acodec_prop:s0" dev="tmpfs" ino=289 scontext=u:r:untrusted_app:s0:c512,c768 tcontext=u:object_r:mtk_em_video_log_acodec_prop:s0 tclass=file permissive=0
07-04 09:45:51.346 10687 10687 I DeltaChat: -------------------- on receive timer --------------------
07-04 09:45:51.349 10687 10716 E libc    : Access denied finding property "sf.postbuffer.prof"
07-04 09:45:51.349 10687 10716 E libc    : Access denied finding property "acodec.video.buflogging"

07-04 09:45:51.363 10687 10718 I MediaCodec: [onMessageReceived]line:1540 [][what=kWhatComponentAllocated][state 1]
07-04 09:45:51.364 10687 10708 I DeltaChat: SMTP-idle started...
07-04 09:45:51.364 10687 10716 I MediaCodec: [CreateByType]line:416 audio/raw
07-04 09:45:51.386 10687 10716 I MediaCodec: [getOutputFormat]line:1143 [OMX.MTK.AUDIO.DECODER.RAW]+++
07-04 09:45:51.389 10687 10716 I MediaCodec: [getOutputFormat]line:1143 [OMX.MTK.AUDIO.DECODER.RAW]+++
07-04 09:45:51.389 10687 10716 I MediaCodec: [stop]line:934 [OMX.MTK.AUDIO.DECODER.RAW]+++
07-04 09:45:51.390 10687 10687 W chat.delta: type=1400 audit(0.0:141668): avc: denied { read } for comm=4E444B204D65646961436F6465635F name="u:object_r:mtk_em_video_log_acodec_prop:s0" dev="tmpfs" ino=289 scontext=u:r:untrusted_app:s0:c512,c768 tcontext=u:object_r:mtk_em_video_log_acodec_prop:s0 tclass=file permissive=0
07-04 09:45:51.390 10687 10687 W SoundPoolThread: type=1400 audit(0.0:141669): avc: denied { read } for name="u:object_r:mtk_em_video_log_sf_postbuffer_prop:s0" dev="tmpfs" ino=212 scontext=u:r:untrusted_app:s0:c512,c768 tcontext=u:object_r:mtk_em_video_log_sf_postbuffer_prop:s0 tclass=file permissive=0
07-04 09:45:51.390 10687 10687 W SoundPoolThread: type=1400 audit(0.0:141670): avc: denied { read } for name="u:object_r:mtk_em_video_log_acodec_prop:s0" dev="tmpfs" ino=289 scontext=u:r:untrusted_app:s0:c512,c768 tcontext=u:object_r:mtk_em_video_log_acodec_prop:s0 tclass=file permissive=0
07-04 09:45:51.394 10687 10718 E libc    : Access denied finding property "acodec.video.buflogging"
07-04 09:45:51.395 10687 10716 I MediaCodec: [~MediaCodec]line:509 [][mState 0]+++
07-04 09:45:51.403 10687 10716 E libc    : Access denied finding property "sf.postbuffer.prof"
07-04 09:45:51.403 10687 10716 E libc    : Access denied finding property "acodec.video.buflogging"

[adbenitez]

log from another user:
user2.txt

interesting part:

07-04 11:23:27.678 22914 29571 W SingleRecipientNotificationBuilder:
07-04 11:23:27.678 22914 29571 W SingleRecipientNotificationBuilder: java.util.concurrent.ExecutionException: com.bumptech.glide.load.engine.GlideException: Failed to load resource
07-04 11:23:27.678 22914 29571 W SingleRecipientNotificationBuilder:     at com.bumptech.glide.request.RequestFutureTarget.doGet(RequestFutureTarget.java:212)
07-04 11:23:27.678 22914 29571 W SingleRecipientNotificationBuilder:     at com.bumptech.glide.request.RequestFutureTarget.get(RequestFutureTarget.java:115)
07-04 11:23:27.678 22914 29571 W SingleRecipientNotificationBuilder:     at org.thoughtcrime.securesms.notifications.SingleRecipientNotificationBuilder.setChat(SingleRecipientNotificationBuilder.java:78)
07-04 11:23:27.678 22914 29571 W SingleRecipientNotificationBuilder:     at org.thoughtcrime.securesms.notifications.MessageNotifier.createSingleChatNotification(MessageNotifier.java:243)
07-04 11:23:27.678 22914 29571 W SingleRecipientNotificationBuilder:     at org.thoughtcrime.securesms.notifications.MessageNotifier.sendSingleChatNotification(MessageNotifier.java:212)
07-04 11:23:27.678 22914 29571 W SingleRecipientNotificationBuilder:     at org.thoughtcrime.securesms.notifications.MessageNotifier.sendNotifications(MessageNotifier.java:188)
07-04 11:23:27.678 22914 29571 W SingleRecipientNotificationBuilder:     at org.thoughtcrime.securesms.notifications.MessageNotifier.updateNotification(MessageNotifier.java:104)
07-04 11:23:27.678 22914 29571 W SingleRecipientNotificationBuilder:     at org.thoughtcrime.securesms.notifications.MessageNotifierCompat.lambda$updateNotification$0$MessageNotifierCompat(MessageNotifierCompat.java:34)
07-04 11:23:27.678 22914 29571 W SingleRecipientNotificationBuilder:     at org.thoughtcrime.securesms.notifications.MessageNotifierCompat$$Lambda$0.run(Unknown Source)
07-04 11:23:27.678 22914 29571 W SingleRecipientNotificationBuilder:     at org.thoughtcrime.securesms.util.Util.runOnAnyBackgroundThread(Util.java:331)
07-04 11:23:27.678 22914 29571 W SingleRecipientNotificationBuilder:     at org.thoughtcrime.securesms.notifications.MessageNotifierCompat.updateNotification(MessageNotifierCompat.java:34)
07-04 11:23:27.678 22914 29571 W SingleRecipientNotificationBuilder:     at org.thoughtcrime.securesms.ApplicationContext$1.handleEvent(ApplicationContext.java:100)
07-04 11:23:27.678 22914 29571 W SingleRecipientNotificationBuilder:     at com.b44t.messenger.DcEventCenter.lambda$sendToObservers$1$DcEventCenter(DcEventCenter.java:77)
07-04 11:23:27.678 22914 29571 W SingleRecipientNotificationBuilder:     at com.b44t.messenger.DcEventCenter$$Lambda$1.run(Unknown Source)
07-04 11:23:27.678 22914 29571 W SingleRecipientNotificationBuilder:     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
07-04 11:23:27.678 22914 29571 W SingleRecipientNotificationBuilder:     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
07-04 11:23:27.678 22914 29571 W SingleRecipientNotificationBuilder:     at java.lang.Thread.run(Thread.java:761)
07-04 11:23:27.678 22914 29571 W SingleRecipientNotificationBuilder: Caused by: com.bumptech.glide.load.engine.GlideException: Failed to load resource
07-04 11:23:27.685 22914 29571 W NotificationState: Added chat: 42
07-04 11:23:27.685 22914 29571 W NotificationState: Added chat: 42
07-04 11:23:27.747 22914 29571 D MediaPlayer: setSubtitleAnchor in MediaPlayer
07-04 11:23:27.747 22914 22914 D MediaPlayer: setSubtitleAnchor in MediaPlayer
07-04 11:23:27.751 22914 29571 D Ringtone: Successfully created local player

[r10s]

@adbenitez thanks for filing the issue and pointing directly to the important part! thank you very much, this is very helpful!

@cyBerta i think this belongs to the new notifications, please have a look at this.

[STPKITT]

I'm suffering the same problem on two separate devices since updating to 0.500.0. The version that I had installed prior, 0.304.0, had notifications working fine whenever I tried.

Toggling notifications off and on again in Delta Chat's settings menu partly brought notifications back. I wrote "partly" because that only is the case when the ringtone volume of the device is unmuted. When a device is set to just vibrate nothing ever happens not even when I turn on the display and also not when solving the lockscreen. The user has to open up Delta Chat to see that there's a new unread message.

The devices I tested on are:
Samsung Galaxy S2 running LineageOS Android 7.1.2
Samsung Galaxy SIII mini running Cyanogenmod Android 5.1.1

[r10s]

k, i think there is an exception raised from somewhere in the glide code that does not crash the whole app, but results in the notification not being displayed.

i think we should just remove the complicated code there completely. it is not really needed for now that the group icon is displayed. also the reply-button, markseen-button and such high-level things seems to make more problems than they solve (see eg. #983)

i think it is more important to have reliable notifications than fancy features that tend to problems and are hard to maintain.

cc @cyBerta

[r10s]

analyzed the logs a bit, the first from @webratte indeed results in a missed system-notification (the message as such is received and a notification inside delta is shown)

the other two logs from @adbenitez should not result in missed notifications as no exception was raised unexpectedly (however, as logs are always excerpts only, the notification might be missing due to the same errors as in the first log)

[r10s]

k, after coming back to @cyBerta on irc, i think, this can be closed for now. it is pretty probable that the pr #995 fixes the core problem. otherwise, we can reopen.