Signal-Android icon indicating copy to clipboard operation
Signal-Android copied to clipboard

Standalone Android APK: "Signal failed to update - We will try again later."

Open kimimaru4000 opened this issue 2 years ago • 21 comments

  • [x] I have searched open and closed issues for duplicates
  • [x] I am submitting a bug report for existing functionality that does not work as intended
  • [x] I have read https://github.com/signalapp/Signal-Android/wiki/Submitting-useful-bug-reports
  • [x] This isn't a feature request or a discussion topic

Bug description

Signal Android v6.39.1 fails to auto-update with the notification message:

Signal failed to update We will try again later.

Steps to reproduce

  • Download Signal from https://www.signal.org/download/android/
  • When an auto-update should occur, observe how it fails to update and sends the notification

Actual result: Signal fails to update itself. Tapping the notification just opens Signal. It does not say what was wrong. Expected result: Signal's auto-updater works and prompts to install the update when tapping the notification.

Screenshots

Device info

Device: Sony Xperia XA 2 Android version: 10 (LineageOS 17.1) Signal version: 6.39.1

Link to debug log

https://debuglogs.org/android/6.39.1/54db8b98eeff9becb03295d555837b7aca50b268c10e2448074fe42c69500d74

kimimaru4000 avatar Nov 13 '23 16:11 kimimaru4000

Strange, it's saying that it can't find the downloaded file? Not sure what's going on just yet.

greyson-signal avatar Nov 13 '23 20:11 greyson-signal

Not sure if it's the same issue/related, but when I try to update a standalone signal v6.39.1 from the update notification then it also fails but the logs say:

ApkUpdateNotificationRe: Got action to install.
ApkUpdateInstaller: DownloadId doesn't match the one we're waiting for! We likely have newer data. Ignoring.

One difference is that I don't get any feedback at all, after clicking the update notification then signal opens/shows in the foreground but that's it.

pimlie avatar Nov 16 '23 12:11 pimlie

@pimlie Interestingly I get a different message:

ApkUpdateInstaller: DownloadId matches, but digest does not! Bad download or inconsistent state. Failing and clearing state.

The update notification has the same action for me.

@greyson-signal Any updates on the root cause?

kimimaru4000 avatar Nov 16 '23 15:11 kimimaru4000

Regarding the downloadId not matching, I believe I have a fix in 6.41.1, which is currently in beta. For the digest not matching, that's an actual problem. I'd have to have a log and see what it says. Likely a bad download or other issue with something on disk.

greyson-signal avatar Nov 17 '23 14:11 greyson-signal

Just to chime in on a possible related symptom - I noticed that in recent versions of either Android or Signal, the persistent background connection notification for the websocket connection could be cleared, whereas before at least one active Signal notification was always visible; around the same time that I noticed that no notifications were required for Signal to remain operational in the background, the updating process became broken for Signal. The only successful update I've had in the last few months was when the application itself was in the foreground + the persistent notification was still actively on-screen and hadn't been cleared. Might just be noise, but possibly a related data point.

quinndiggity avatar Nov 17 '23 20:11 quinndiggity

update worked now -> 6.40.5

Edit: on my other device it failed with wrong download id again. I manually updated the apk now

woheller69 avatar Nov 18 '23 06:11 woheller69

Hello.

I am also on 6.39.1 and the app won't auto-update anymore as well.

The debug log shows two kind or errors alternating on the ApkUpdateJob:

  • java.io.InterruptedIOException: read interrupted
  • java.io.IOException: read failed: EBADF (Bad file descriptor)

(see attachment for the full stack: signal-6.39.1-ApkUpdateJob-failure.txt)

Regardless, the job reports a SUCCESS result. I think on some occasions it did not, as I remember seeing a failure UI message a few times.

seranpion avatar Dec 02 '23 16:12 seranpion

I get this error on 6.40.5 though I'm not sure what version it's trying to upgrade to.

hsanjuan avatar Dec 06 '23 02:12 hsanjuan

I see the same issue on signal 6.41.3. Here is an excerpt from the logs:

[6.41.3] [91   ] 2024-01-05 11:27:18.008 GMT+01:00 I IncomingMessageObserver: Making websocket connection....
[6.41.3] [91   ] 2024-01-05 11:27:18.008 GMT+01:00 D IncomingMessageObserver: WebSocket State: DISCONNECTED
[6.41.3] [91   ] 2024-01-05 11:27:18.009 GMT+01:00 I WebSocketConnection: [normal:200218131] connect()
[6.41.3] [main ] 2024-01-05 11:27:18.011 GMT+01:00 I JobManager: onConstraintMet(NetworkConstraintObserv)
[6.41.3] [main ] 2024-01-05 11:27:18.024 GMT+01:00 I JobManager: onConstraintMet(NetworkConstraintObserv)
[6.41.3] [90   ] 2024-01-05 11:27:18.042 GMT+01:00 D IncomingMessageObserver: WebSocket State: CONNECTING
[6.41.3] [91   ] 2024-01-05 11:27:18.045 GMT+01:00 I WebSocketConnection: [unidentified:24115802] connect()
[6.41.3] [91   ] 2024-01-05 11:27:18.079 GMT+01:00 D IncomingMessageObserver: [Needs Connection] Network: true, Foreground: false, Time Since Last Interaction: 2090937 ms (over limit), FCM: false, Stay open requests: [], Registered: true, Proxy: false, Force websocket: false
[6.41.3] [91   ] 2024-01-05 11:27:18.079 GMT+01:00 D IncomingMessageObserver: Reading message...
[6.41.3] [4080 ] 2024-01-05 11:27:18.131 GMT+01:00 W SequentialDns: Failed to resolve chat.signal.org using . Continuing. Network Type: WIFI
[6.41.3] [4080 ] 2024-01-05 11:27:18.135 GMT+01:00 W SequentialDns: Failed to resolve chat.signal.org using CustomDns. Continuing. Network Type: WIFI
[6.41.3] [4081 ] 2024-01-05 11:27:18.172 GMT+01:00 W SequentialDns: Failed to resolve chat.signal.org using . Continuing. Network Type: WIFI
[6.41.3] [4081 ] 2024-01-05 11:27:18.173 GMT+01:00 W SequentialDns: Failed to resolve chat.signal.org using CustomDns. Continuing. Network Type: WIFI
[6.41.3] [main ] 2024-01-05 11:27:18.326 GMT+01:00 I ApkUpdateDownloadManage: onReceive()
[6.41.3] [main ] 2024-01-05 11:27:18.333 GMT+01:00 W ApkUpdateInstaller: 
[6.41.3] [main ] 2024-01-05 11:27:18.333 GMT+01:00 W ApkUpdateInstaller: java.io.FileNotFoundException: No filename found.
[6.41.3] [main ] 2024-01-05 11:27:18.333 GMT+01:00 W ApkUpdateInstaller: 	at android.database.DatabaseUtils.readExceptionWithFileNotFoundExceptionFromParcel(DatabaseUtils.java:151)
[6.41.3] [main ] 2024-01-05 11:27:18.333 GMT+01:00 W ApkUpdateInstaller: 	at android.content.ContentProviderProxy.openTypedAssetFile(ContentProviderNative.java:780)
[6.41.3] [main ] 2024-01-05 11:27:18.333 GMT+01:00 W ApkUpdateInstaller: 	at android.content.ContentResolver.openTypedAssetFileDescriptor(ContentResolver.java:2027)
[6.41.3] [main ] 2024-01-05 11:27:18.333 GMT+01:00 W ApkUpdateInstaller: 	at android.content.ContentResolver.openAssetFileDescriptor(ContentResolver.java:1842)
[6.41.3] [main ] 2024-01-05 11:27:18.333 GMT+01:00 W ApkUpdateInstaller: 	at android.content.ContentResolver.openFileDescriptor(ContentResolver.java:1675)
[6.41.3] [main ] 2024-01-05 11:27:18.333 GMT+01:00 W ApkUpdateInstaller: 	at android.content.ContentResolver.openFileDescriptor(ContentResolver.java:1622)
[6.41.3] [main ] 2024-01-05 11:27:18.333 GMT+01:00 W ApkUpdateInstaller: 	at android.app.DownloadManager.openDownloadedFile(DownloadManager.java:1187)
[6.41.3] [main ] 2024-01-05 11:27:18.333 GMT+01:00 W ApkUpdateInstaller: 	at org.thoughtcrime.securesms.apkupdate.ApkUpdateInstaller.isMatchingDigest(ApkUpdateInstaller.kt:136)
[6.41.3] [main ] 2024-01-05 11:27:18.333 GMT+01:00 W ApkUpdateInstaller: 	at org.thoughtcrime.securesms.apkupdate.ApkUpdateInstaller.installOrPromptForInstall(ApkUpdateInstaller.kt:56)
[6.41.3] [main ] 2024-01-05 11:27:18.333 GMT+01:00 W ApkUpdateInstaller: 	at org.thoughtcrime.securesms.apkupdate.ApkUpdateDownloadManagerReceiver.onReceive(ApkUpdateDownloadManagerReceiver.kt:40)
[6.41.3] [main ] 2024-01-05 11:27:18.333 GMT+01:00 W ApkUpdateInstaller: 	at android.app.ActivityThread.handleReceiver(ActivityThread.java:4307)
[6.41.3] [main ] 2024-01-05 11:27:18.333 GMT+01:00 W ApkUpdateInstaller: 	at android.app.ActivityThread.-$$Nest$mhandleReceiver(Unknown Source:0)
[6.41.3] [main ] 2024-01-05 11:27:18.333 GMT+01:00 W ApkUpdateInstaller: 	at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2153)
[6.41.3] [main ] 2024-01-05 11:27:18.333 GMT+01:00 W ApkUpdateInstaller: 	at android.os.Handler.dispatchMessage(Handler.java:106)
[6.41.3] [main ] 2024-01-05 11:27:18.333 GMT+01:00 W ApkUpdateInstaller: 	at android.os.Looper.loopOnce(Looper.java:201)
[6.41.3] [main ] 2024-01-05 11:27:18.333 GMT+01:00 W ApkUpdateInstaller: 	at android.os.Looper.loop(Looper.java:288)
[6.41.3] [main ] 2024-01-05 11:27:18.333 GMT+01:00 W ApkUpdateInstaller: 	at android.app.ActivityThread.main(ActivityThread.java:7924)
[6.41.3] [main ] 2024-01-05 11:27:18.333 GMT+01:00 W ApkUpdateInstaller: 	at java.lang.reflect.Method.invoke(Native Method)
[6.41.3] [main ] 2024-01-05 11:27:18.333 GMT+01:00 W ApkUpdateInstaller: 	at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:548)
[6.41.3] [main ] 2024-01-05 11:27:18.333 GMT+01:00 W ApkUpdateInstaller: 	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:936)
[6.41.3] [main ] 2024-01-05 11:27:18.333 GMT+01:00 W ApkUpdateInstaller: 
[6.41.3] [main ] 2024-01-05 11:27:18.333 GMT+01:00 W ApkUpdateInstaller: DownloadId matches, but digest does not! Bad download or inconsistent state. Failing and clearing state.
[6.41.3] [main ] 2024-01-05 11:27:18.333 GMT+01:00 D ApkUpdateValues: Clearing download attributes.
[6.41.3] [main ] 2024-01-05 11:27:18.334 GMT+01:00 D ApkUpdateNotifications: Showing failed notification. Reason: UNKNOWN
[6.41.3] [4081 ] 2024-01-05 11:27:21.865 GMT+01:00 I WebSocketConnection: [unidentified:24115802] onOpen() connected
[6.41.3] [4080 ] 2024-01-05 11:27:21.865 GMT+01:00 I WebSocketConnection: [normal:200218131] onOpen() connected
[6.41.3] [90   ] 2024-01-05 11:27:21.866 GMT+01:00 D IncomingMessageObserver: WebSocket State: CONNECTED
[6.41.3] [4086 ] 2024-01-05 11:27:21.868 GMT+01:00 D AlarmSleepTimer: Setting an exact alarm to wake up in 30000ms.
[6.41.3] [91   ] 2024-01-05 11:27:21.871 GMT+01:00 I IncomingMessageObserver: Decryptions newly-drained.
[6.41.3] [91   ] 2024-01-05 11:27:21.871 GMT+01:00 I JobManager: onConstraintMet(DecryptionsDrainedConst)
[6.41.3] [91   ] 2024-01-05 11:27:21.875 GMT+01:00 D IncomingMessageObserver: [Needs Connection] Network: true, Foreground: false, Time Since Last Interaction: 2094751 ms (over limit), FCM: false, Stay open requests: [], Registered: true, Proxy: false, Force websocket: false

paulmueller avatar Jan 07 '24 08:01 paulmueller

I experienced this issue with previous versions (e.g. v6.41.3). After having manually updated (adb install ...) to the latest version v6.43.3 earlier this week, the issue is still present.

Logcat :

01-23 00:47:54.432  4436  5367 W DownloadManager: [136] Stop requested with status HTTP_DATA_ERROR: Failed to connect to updates.signal.org/104.18.3.166:443
01-23 00:47:54.432  4436  5367 D DownloadManager: [136] Finished with status HTTP_DATA_ERROR
01-23 00:47:54.446 15922 15922 I ApkUpdateDownloadManage: onReceive()
01-23 00:47:54.452 15922 15922 W ApkUpdateInstaller: null
01-23 00:47:54.452 15922 15922 W ApkUpdateInstaller: java.io.FileNotFoundException: No filename found.
01-23 00:47:54.452 15922 15922 W ApkUpdateInstaller: 	at android.database.DatabaseUtils.readExceptionWithFileNotFoundExceptionFromParcel(DatabaseUtils.java:151)
01-23 00:47:54.452 15922 15922 W ApkUpdateInstaller: 	at android.content.ContentProviderProxy.openTypedAssetFile(ContentProviderNative.java:780)
01-23 00:47:54.452 15922 15922 W ApkUpdateInstaller: 	at android.content.ContentResolver.openTypedAssetFileDescriptor(ContentResolver.java:2027)
01-23 00:47:54.452 15922 15922 W ApkUpdateInstaller: 	at android.content.ContentResolver.openAssetFileDescriptor(ContentResolver.java:1842)
01-23 00:47:54.452 15922 15922 W ApkUpdateInstaller: 	at android.content.ContentResolver.openFileDescriptor(ContentResolver.java:1675)
01-23 00:47:54.452 15922 15922 W ApkUpdateInstaller: 	at android.content.ContentResolver.openFileDescriptor(ContentResolver.java:1622)
01-23 00:47:54.452 15922 15922 W ApkUpdateInstaller: 	at android.app.DownloadManager.openDownloadedFile(DownloadManager.java:1187)
01-23 00:47:54.452 15922 15922 W ApkUpdateInstaller: 	at org.thoughtcrime.securesms.apkupdate.ApkUpdateInstaller.isMatchingDigest(ApkUpdateInstaller.kt:136)
01-23 00:47:54.452 15922 15922 W ApkUpdateInstaller: 	at org.thoughtcrime.securesms.apkupdate.ApkUpdateInstaller.installOrPromptForInstall(ApkUpdateInstaller.kt:56)
01-23 00:47:54.452 15922 15922 W ApkUpdateInstaller: 	at org.thoughtcrime.securesms.apkupdate.ApkUpdateDownloadManagerReceiver.onReceive(ApkUpdateDownloadManagerReceiver.kt:40)
01-23 00:47:54.452 15922 15922 W ApkUpdateInstaller: 	at android.app.ActivityThread.handleReceiver(ActivityThread.java:4307)
01-23 00:47:54.452 15922 15922 W ApkUpdateInstaller: 	at android.app.ActivityThread.-$$Nest$mhandleReceiver(Unknown Source:0)
01-23 00:47:54.452 15922 15922 W ApkUpdateInstaller: 	at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2153)
01-23 00:47:54.452 15922 15922 W ApkUpdateInstaller: 	at android.os.Handler.dispatchMessage(Handler.java:106)
01-23 00:47:54.452 15922 15922 W ApkUpdateInstaller: 	at android.os.Looper.loopOnce(Looper.java:201)
01-23 00:47:54.452 15922 15922 W ApkUpdateInstaller: 	at android.os.Looper.loop(Looper.java:288)
01-23 00:47:54.452 15922 15922 W ApkUpdateInstaller: 	at android.app.ActivityThread.main(ActivityThread.java:7924)
01-23 00:47:54.452 15922 15922 W ApkUpdateInstaller: 	at java.lang.reflect.Method.invoke(Native Method)
01-23 00:47:54.452 15922 15922 W ApkUpdateInstaller: 	at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:548)
01-23 00:47:54.452 15922 15922 W ApkUpdateInstaller: 	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:936)
01-23 00:47:54.452 15922 15922 W ApkUpdateInstaller: DownloadId matches, but digest does not! Bad download or inconsistent state. Failing and clearing state.
01-23 00:47:54.452 15922 15922 D ApkUpdateValues: Clearing download attributes.
01-23 00:47:54.455 15922 15922 D ApkUpdateNotifications: Showing failed notification. Reason: UNKNOWN

Process 4436 turns out to be com.android.providers.media, which was being blocked from internet access in my firewall app (AFWall+).

didierm avatar Jan 23 '24 00:01 didierm

FYI I am also using AFWall+ and in addition to that, have disabled captive portal checks.

I have allowed com.android.providers.media, Download-Manager, Downloads, MTP-Host, Töne in AFWall+ (does this make sense?). Maybe that was the issue, let's see.

[EDIT: Allowing com.android.providers.media in AFWall+ allowed signal to update. Are there any side-effects to this?]

paulmueller avatar Jan 23 '24 07:01 paulmueller

With whitelisted com.android.providers.media in the firewall app (AFWall+), Signal just successfully updated automatically to v6.44.2. (this covers my issue ; not sure whether it matches the TS, as the debug log is not accessible anymore)

didierm avatar Jan 23 '24 13:01 didierm

Since some update circles suddenly same problem with Signal update, same error message "failed to update..we will try again." They do, but no success. Phone: Fairphone 4. CalyxOS including newest updates. Signal apk.file downloaded from website signal.org for installaion some time ago and now again since the errors occured. Any ideas what's going wrong?

herod839 avatar Jan 24 '24 17:01 herod839

If the cause is indeed network access, that means that a change was made on this feature at version 6.39.1. But I don't see anything specific in the related commits.

Couldn't it be a change on the update server side? Can anyone report success in auto-updating since that version?

seranpion avatar Feb 07 '24 23:02 seranpion

@seranpion While I struggled with this issue some months ago, updates have worked fine since then. I'm currently on version 6.46.7.

codethief avatar Feb 10 '24 21:02 codethief

@codethief well, no me. I have manually updated to version 6.45.2 a few days ago, and now it still fails to update from there. So, unless this was fixed afterward, I don't expect a resolution yet. And I don't see any commit message related to the issue.

I'll take some time to review the log to see if the messages are the same now.

seranpion avatar Feb 12 '24 08:02 seranpion

Ok, I have checked again, and the exact same symptom I described here for 6.39.1 is still in 6.42.2.

Five out of six occurrences (all are I/O read exceptions) are interrupted read, and the sixth one is a bad file descriptor.

Since it's I/O read operation, I don't know what to think. I doubt that my local network is causing this.

Plus I see multiple occurences of failed to connect to jdwp control socket: Connection refused. But that's a debugging (unsecure remote execution, at that) protocol. Why would it be attempted on live instances?

seranpion avatar Feb 18 '24 17:02 seranpion

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

stale[bot] avatar Jan 26 '25 08:01 stale[bot]

I've installed LineageOS 22.1 on a OnePlus 5 three weeks ago and at first the Signal updates worked but now I'm seeing the same error for a week. The Signal version is 7.29.4.

In the log I also see: W ApkUpdateInstaller: java.io.FileNotFoundException: No filename found.

and [7.29.4] [main ] 2025-01-27 12:47:52.294 GMT+01:00 W ApkUpdateInstaller: DownloadId matches, but digest does not! Bad download or inconsistent state. Failing and clearing state. [7.29.4] [main ] 2025-01-27 12:47:52.294 GMT+01:00 D ApkUpdateValues: Clearing download attributes. [7.29.4] [main ] 2025-01-27 12:47:52.296 GMT+01:00 D ApkUpdateNotifications: Showing failed notification. Reason: UNKNOWN

karhima avatar Jan 29 '25 14:01 karhima

Yesterday it suddenly updated normally. There is certainly something going on, but it doesn't seem to be a big problem. Sorry for interrupting the closing of the issue.

karhima avatar Jan 31 '25 09:01 karhima

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

stale[bot] avatar Apr 01 '25 21:04 stale[bot]

This issue has been closed due to inactivity.

stale[bot] avatar Apr 11 '25 00:04 stale[bot]

FYI I am also using AFWall+ and in addition to that, have disabled captive portal checks.

I have allowed com.android.providers.media, Download-Manager, Downloads, MTP-Host, Töne in AFWall+ (does this make sense?). Maybe that was the issue, let's see.

[EDIT: Allowing com.android.providers.media in AFWall+ allowed signal to update. Are there any side-effects to this?]

This fixed it for me too, thanks guys ❤️

Caveman-Dan avatar Apr 16 '25 09:04 Caveman-Dan