search

signalapp / Signal-Desktop

A private messenger for Windows, macOS, and Linux.
https://signal.org/download
GNU Affero General Public License v3.0
14.52k stars 2.63k forks source link

macOS: If first updated as root user, Signal will not update as non-root user #3552

Open alexdean opened 5 years ago

alexdean commented 5 years ago

Bug Description

Signal desktop v1.26.1 on OSX shows me a dialog stating "There is a new version of Signal available. Press Restart Signal to apply the updates."

When I click "Restart Signal" the app does not restart. When I start it again manually, I am again presented with the "a new version is available" dialog. I don't know how to break this cycle. If I click "Later" in the dialog, I can only go about 15 minutes before I'm prompted again - this makes Signal very distracting.

Filesystem info:

$ ls -lah ~/Applications
total 16
drwxr-xr-x   10 alex  staff   320B Aug 14 14:05 .
drwxr-xr-x@   3 alex  staff    96B Aug 14 11:32 Signal.app
drwxr-xr-x@   3 alex  staff    96B Jul 18 18:47 Slack.app

Steps to Reproduce

  1. Start Signal desktop.
  2. Observe the "updates are available" dialog.
  3. Click "Restart Signal".

Actual Result:

Signal does not restart. Updates are not applied.

Expected Result:

Signal should restart and apply the available updates.

Screenshots

20190830-0908-22d47fc5

Platform Info

Link to Debug Log

https://debuglogs.org/b875ea96717ddfd05837a24161ca2559f2a6f627c9fdef1f54a7a4f90996e1b0

kenpowers-signal commented 5 years ago

I'm not seeing anything suspect in your debug log. Can you try seeing if you see anything suspect in Console.app when you try to update Electron-based applications? You can also try replacing the Signal.app download with a fresh download from https://signal.org (data is kept safe in ~/Library/Application Support/Signal).

alexdean commented 5 years ago

@kenpowers-signal thanks. having a problem downloading the update manually, too.

  1. i visit https://signal.org/download/
  2. i click 'Signal for Mac'
  3. link takes me to https://signal.org/download/ (the page i'm already on).

So i'm currently unable to download a new build.

alexdean commented 5 years ago

here are the logs from Console.app from the time I clicked 'Restart Signal' until the process seemed to be fully terminated. I filtered to only log entries for Signal since it was too noisy otherwise. (lmk if there are other ways I should be searching console output.)

i removed the names of other running apps in the final log message. lmk if you really need them.

default 18:08:28.069139 -0500   Signal  AggregateDictionary is not supported on this platform
default 18:08:28.132735 -0500   mobileassetd    handleCopyAssetAttributes: [Signal] HANDLER - copyAssetAttributes [com.apple.MobileAsset.LinguisticData]: com_apple_MobileAsset_LinguisticData/e8e80538455c568e103fa74012258977e16fe73e.zip
default 18:08:28.133347 -0500   mobileassetd    handleCopyAssetAttributes: [Signal] HANDLER - copyAssetAttributes [com.apple.MobileAsset.LinguisticData]: com_apple_MobileAsset_LinguisticData/e8e80538455c568e103fa74012258977e16fe73e.zip
default 18:08:28.134509 -0500   mobileassetd    handleCopyAssetAttributes: [Signal] HANDLER - copyAssetAttributes [com.apple.MobileAsset.LinguisticData]: com_apple_MobileAsset_LinguisticData/8cddb9a22ae4ece031b7917f22c612d7e8e7ca34.zip
default 18:08:28.134957 -0500   mobileassetd    handleCopyAssetAttributes: [Signal] HANDLER - copyAssetAttributes [com.apple.MobileAsset.LinguisticData]: com_apple_MobileAsset_LinguisticData/8cddb9a22ae4ece031b7917f22c612d7e8e7ca34.zip
default 18:08:28.135642 -0500   mobileassetd    handleCopyAssetAttributes: [Signal] HANDLER - copyAssetAttributes [com.apple.MobileAsset.LinguisticData]: com_apple_MobileAsset_LinguisticData/8aa09218d5b31b5a88f593943881f087c1c5e315.zip
default 18:08:28.136153 -0500   mobileassetd    handleCopyAssetAttributes: [Signal] HANDLER - copyAssetAttributes [com.apple.MobileAsset.LinguisticData]: com_apple_MobileAsset_LinguisticData/8aa09218d5b31b5a88f593943881f087c1c5e315.zip
default 18:08:28.136877 -0500   mobileassetd    handleCopyAssetAttributes: [Signal] HANDLER - copyAssetAttributes [com.apple.MobileAsset.LinguisticData]: com_apple_MobileAsset_LinguisticData/c642c9bc76d0fc187da6e7bd9159b0e03832f905.zip
default 18:08:28.136955 -0500   mobileassetd    handleCopyAssetAttributes: [Signal] unable to get asset attributes[com.apple.MobileAsset.LinguisticData]: 1 [com_apple_MobileAsset_LinguisticData/c642c9bc76d0fc187da6e7bd9159b0e03832f905.zip]
default 18:08:28.137073 -0500   Signal  _MobileAssetSendCopyAssetAttributesCommand: [MobileAssetError:1] Unable to copy asset attributes
default 18:08:29.627584 -0500   Signal  27366555: RECEIVED OUT-OF-SEQUENCE NOTIFICATION: 3188 vs 6384, 512, <private>
default 18:08:29.973863 -0500   Signal  Read options: ffffffff80000001 -- URL: <private> -- purposeID: 54C2E07B-716B-48FA-91C1-6CA0901D562E -- claimID: 8C2CBC19-08EF-4540-A24D-BB5315F9E11B
default 18:08:29.974723 -0500   Signal  Claim 8C2CBC19-08EF-4540-A24D-BB5315F9E11B granted in client
default 18:08:29.974740 -0500   Signal  Claim 8C2CBC19-08EF-4540-A24D-BB5315F9E11B invoked in client
default 18:08:29.975662 -0500   powerd  Process Signal.91089 Created PreventSystemSleep "Preparing to relaunch" age:00:00:00  id:30064805852 [System: DeclUser kDisp]
default 18:08:29.976097 -0500   Signal  Write options: 0 -- URL: <private> -- purposeID: D463795A-AF5E-4D10-AF26-2E7FD42318D3 -- claimID: 903E2526-B71D-486D-8C69-DF70C648CF71
default 18:08:29.976709 -0500   Signal  Claim 903E2526-B71D-486D-8C69-DF70C648CF71 granted in client
default 18:08:29.976725 -0500   Signal  Claim 903E2526-B71D-486D-8C69-DF70C648CF71 invoked in client
default 18:08:29.977737 -0500   powerd  Process Signal.91089 Released PreventSystemSleep "Preparing to relaunch" age:00:00:00  id:30064805852 [System: DeclUser kDisp]
default 18:08:29.992741 -0500   kernel  AGC:: [Signal Helper pid 91091 mux-aware] exiting, non-mux-aware app count 0, runtime: 0:01:03.032
default 18:08:30.025543 -0500   hidd    Connection removed: IOHIDEventSystemConnection uuid:4F8F576C-6E84-4C8C-83FF-78B240410823 pid:91089 process:Signal type:Monitor entitlements:0x0 caller:GameController: _GCHIDEventCallback + 86 attributes:(null) inactive:0
default 18:08:30.025506 -0500   hidd    Connection removed: IOHIDEventSystemConnection uuid:5DED5269-5373-4B89-85C6-E386067E698E pid:91089 process:Signal type:Passive entitlements:0x0 caller:HIToolbox: ___GetIOHIDEventSystemClient_block_invoke + 26 attributes:(null) inactive:0
default 18:08:30.054695 -0500   loginwindow -[PersistentAppsSupport applicationQuit:] | for app:Signal, _appTrackingState = 2
default 18:08:30.054724 -0500   loginwindow -[PersistentAppsSupport applicationQuit:] | App: Signal, quit, updating active tracking timer
default 18:08:35.057511 -0500   loginwindow -[PersistentAppsSupport saveLogoutPersistentState:finalSnapshot:] |      previouslyRunningApps: (
        {
        BackgroundState = 2;
        BundleID = "com.apple.console";
        Hide = 0;
        Path = "/Applications/Utilities/Console.app";
    },
        {
        BackgroundState = 2;
        BundleID = "org.whispersystems.signal-desktop";
        Hide = 0;
        Path = "/Users/alex/Applications/Signal.app";
    },
        {
        BackgroundState = 2;
        BundleID = "...";
        Hide = 0;
        Path = "...";
    },
        {
        BackgroundState = 2;
        BundleID = "...";
        Hide = 0;
        Path = "...";
    },
        {
        BackgroundState = 2;
        BundleID = "...";
        Hide = 0;
        Path = "...";
    },
        {
        BackgroundState = 2;
        BundleID = "...";
        Hide = 0;
        Path = "...";
    },
        {
        BackgroundState = 2;
        BundleID = "...";
        Hide = 0;
        Path = "...";
    },
        {
        BackgroundState = 2;
        BundleID = "...";
        Hide = 0;
        Path = "...";
    },
        {
        BackgroundState = 2;
        BundleID = "...";
        Hide = 0;
        Path = "...";
    },
        {
        BackgroundState = 2;
        BundleID = "...";
        Hide = 0;
        Path = "...";
    },
        {
        BackgroundState = 2;
        BundleID = "...";
        Hide = 0;
        Path = "...";
    }
)
scottnonnenberg-signal commented 5 years ago

@alexdean It seems like you're not running javascript in your browser? That's how our download page determines the newest build.

On the logging front, you might search for 'Squirrel' in your system logs. That's the subsystem underneath us doing the updates at the system level after we hand it a new .zip file.

You can help us brainstorm about this - what have you done to your system that could cause it to have these kinds of low-level problems. You seem like a customizer, if you've turned off javascript in your browser.

alexdean commented 5 years ago

It seems like you're not running javascript in your browser? That's how our download page determines the newest build.

i haven't disabled JS in my browser. it looks like this was due to the Decentraleyes extension. when i disable that extension i'm able to get a link to https://updates.signal.org/desktop/signal-desktop-mac-1.26.2.zip.

i will download the newest build and see if i can find any more useful information.

alexdean commented 5 years ago

maybe this helps? it's from a few weeks ago, but probably represents the last time the app tried to update itself.

$ cat ~/Library/Caches/org.whispersystems.signal-desktop.ShipIt/ShipIt_stderr.log 

... snipped out some previous failed attempts ...

2019-08-12 15:03:35.983 ShipIt[65741:2163739] Beginning installation
2019-08-12 15:03:36.609 ShipIt[65741:2163589] Moved bundle from file:///Applications/Signal.app/ to file:///var/folders/zz/zyxvpxvq6csfxvn_n0000000000000/T/org.whispersystems.signal-desktop.ShipIt.288PP6TI/Signal.app
2019-08-12 15:03:36.609 ShipIt[65741:2163589] Moved bundle from file:///var/folders/zz/zyxvpxvq6csfxvn_n0000000000000/T/org.whispersystems.signal-desktop.ShipIt.lgtWCsrr/Signal.app to file:///Applications/Signal.app/
2019-08-12 15:03:36.651 ShipIt[65741:2163589] Couldn't remove owned bundle at location file:///var/folders/zz/zyxvpxvq6csfxvn_n0000000000000/T/org.whispersystems.signal-desktop.ShipIt.lgtWCsrr/Signal.app, error NSError { domain: NSCocoaErrorDomain, code: 4, description: "“Signal.app” couldn’t be removed.", failureReason: "The file doesn’t exist.", underlying error: NSError { domain: NSPOSIXErrorDomain, code: 2, description: "The operation couldn’t be completed. No such file or directory" }, userInfo: {
    NSFilePath = "/var/folders/zz/zyxvpxvq6csfxvn_n0000000000000/T/org.whispersystems.signal-desktop.ShipIt.lgtWCsrr/Signal.app";
    NSUserStringVariant =     (
        Remove
    );
} }
2019-08-12 15:03:36.686 ShipIt[65741:2163589] Installation completed successfully
2019-08-12 15:03:36.710 ShipIt[65741:2163739] Application launched at file:///Applications/Signal.app/
2019-08-12 15:03:36.710 ShipIt[65741:2163739] ShipIt quitting

is the updater assuming it has root permissions? i think it would have to in order to complete this operation, because it's trying to move the old app to a root-owned directory.

$ ls -lh /var/folders/zz/zyxvpxvq6csfxvn_n0000000000000/
total 0
drwxr-xr-x@  6 root  wheel   192B Sep  5 09:34 0
drwx------  19 root  wheel   608B Aug 27 08:41 C
drwxr-xr-x   4 root  wheel   128B Sep  5 10:03 Cleanup At Startup
drwx------  21 root  wheel   672B Sep  5 08:57 T

UPDATE: i think these logs are from when I was still had Signal installed in /Applications/Signal.app (so using a root-only tmp directory wasn't a problem). See below for notes on ownership of this log file.

alexdean commented 5 years ago

reminder: i am running Signal from ~/Applications/Signal.app, not from /Applications/Signal.app.

background: i was tired of being frequently interrupted to enter an admin username & password, and was hoping that running from a directory I owned would make the update process easier.

alexdean commented 5 years ago

I had Console.app open, and watching for 'squirrel' messages. (thanks for the tip there.) i saw a message that a Signal update was ready to install. As before, i clicked 'Restart Signal'. The app quit and did not re-launch, just like before.

This time I noticed that ShipIt_stderr.log was owned by root (probably from when I was still running Signal in the standard way). I suspect that might be why no log messages had been written there in a few weeks - my user account couldn't write to the root-owned file.

root# cd /Users/alex//Library/Caches/org.whispersystems.signal-desktop.ShipIt
root# ls -lh
total 64
-rw-r--r--  1 alex  staff   311B Sep  5 14:06 ShipItState.plist
-rw-r--r--  1 root  staff    25K Aug 12 15:03 ShipIt_stderr.log
-rw-r--r--  1 root  staff     0B Dec 11  2018 ShipIt_stdout.log
drwx------  3 alex  staff    96B Sep  5 14:05 update.2bnvOlf

root# chown alex ShipIt*
root# ls -lh
total 64
-rw-r--r--  1 alex  staff   311B Sep  5 14:06 ShipItState.plist
-rw-r--r--  1 alex  staff    25K Sep  5 14:09 ShipIt_stderr.log
-rw-r--r--  1 alex  staff     0B Dec 11  2018 ShipIt_stdout.log
drwx------  3 alex  staff    96B Sep  5 14:05 update.2bnvOlf

immediately after I ran the chown command, Signal launched itself and is now the latest version (1.27.1). so maybe ownership of this log file was the problem all along?

the logs of the latest update operation still show an error, though the overall process seems to have been successful. (It did update me to the latest Signal release...)

root# tail -12 /Users/alex/Library/Caches/org.whispersystems.signal-desktop.ShipIt/ShipIt_stderr.log 
2019-09-05 14:09:13.247 ShipIt[72364:17317233] Beginning installation
2019-09-05 14:09:13.855 ShipIt[72364:17317241] Moved bundle from file:///Users/alex/Applications/Signal.app/ to file:///var/folders/mw/2clb_qn576d3nyhkbk6t0g4m0000gp/T/org.whispersystems.signal-desktop.ShipIt.Io5uTqsd/Signal.app
2019-09-05 14:09:13.856 ShipIt[72364:17317241] Moved bundle from file:///var/folders/mw/2clb_qn576d3nyhkbk6t0g4m0000gp/T/org.whispersystems.signal-desktop.ShipIt.Ni9TYadI/Signal.app to file:///Users/alex/Applications/Signal.app/
2019-09-05 14:09:13.907 ShipIt[72364:17317241] Couldn't remove owned bundle at location file:///var/folders/mw/2clb_qn576d3nyhkbk6t0g4m0000gp/T/org.whispersystems.signal-desktop.ShipIt.Ni9TYadI/Signal.app, error NSError { domain: NSCocoaErrorDomain, code: 4, description: "“Signal.app” couldn’t be removed.", failureReason: "The file doesn’t exist.", underlying error: NSError { domain: NSPOSIXErrorDomain, code: 2, description: "The operation couldn’t be completed. No such file or directory" }, userInfo: {
    NSFilePath = "/var/folders/mw/2clb_qn576d3nyhkbk6t0g4m0000gp/T/org.whispersystems.signal-desktop.ShipIt.Ni9TYadI/Signal.app";
    NSUserStringVariant =     (
        Remove
    );
} }
2019-09-05 14:09:13.953 ShipIt[72364:17317241] Installation completed successfully
2019-09-05 14:09:14.033 ShipIt[72364:17317245] Application launched at file:///Users/alex/Applications/Signal.app/
2019-09-05 14:09:14.033 ShipIt[72364:17317245] ShipIt quitting
alexdean commented 5 years ago

fwiw i just made the same change for Slack (cd /Users/alex/Library/Caches/com.tinyspeck.slackmacgap.ShipIt && chown alex ShipIt_stderr.log) and Slack immediately launched the latest version.

scottnonnenberg-signal commented 5 years ago

Thanks for your additional investigation here. Now we know what workarounds to suggest, and what changes to request of the Electron/Squirrel folks. :0)

winstonwolff commented 3 years ago

I had this problem too, on MacOS. As soon as I ran sudo chown MY_USER_NAME ~/Library/Caches/org.whispersystems.signal-desktop.ShipIt/*, Signal launched, and it's now updated to the next version.

justlurking commented 3 years ago

I had this problem too, on MacOS. As soon as I ran sudo chown MY_USER_NAME ~/Library/Caches/org.whispersystems.signal-desktop.ShipIt/*, Signal launched, and it's now updated to the next version.

@winstonwolff Thanks for the tip! I've had a user whose Signal desktop app has refused to update for months on both macOS Mojave and Catalina. (I've periodically updated it manually downloading and dragging it over the old app in /Applications.)

Your suggestion fixed it right away. Two of the files in that directory were owned by root instead of by the User. Thanks again.