Spurious Duplicacy-web launches

saspus · 21 May 2021 11:00

When running duplicacy-web under root via launchd another instance of dupliacy-web keeps launching under current user account, and either disappearing shortly:

or getting stuck with 100% CPU usage, while logging exceptions into the system log (see matched pid to confirm the message is coming from a stuck spurious one):

To reproduce:
/Library/LaunchDaemons/com.acrosync.duplicacy-web.plist

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
<plist version="1.0">
    <dict>
        <key>Label</key>
        <string>com.acrosync.duplicacy-web</string>
        <key>KeepAlive</key>
        <dict>
            <key>Crashed</key>
            <true/>
            <key>SuccessfulExit</key>
            <false/>
        </dict>

        <key>EnvironmentVariables</key>
        <dict>
            <key>HOME</key>
            <string>/Library/Duplicacy</string>
        </dict>

        <key>Program</key>
        <string>/Applications/Duplicacy Web Edition.app/Contents/MacOS/duplicacy_web_osx_x64</string>
        <key>RunAtLoad</key>
        <true/>
        <key>WorkingDirectory</key>
        <string>/Library/Duplicacy</string>
    </dict>
</plist>

sudo mkdir /Library/Duplicacy
sudo launchctl load -w /Library/LaunchDaemons/com.acrosync.duplicacy-web.plist

log stream --predicate 'process contains "duplicacy_web"'

and start backup.

Watch the Activity monitor. Note the correct one is running under Root and the spurious is being launched as local user account – alex on my screenshots.

Killing the spurious one results in it re-launching anyways and continuing to log exceptions. It probably has to do with it being ran as daemon and attempting to interact whit the current user desktop.

If this is not a supported scenario – how can I backup All users using Duplicacy Web otherwise?

Edit:

Example of the log messages spurious one keeps dumping to the system log:

2021-05-21 11:31:51.422177-0700 0x43f9b2   Error       0x0                  77375  0    duplicacy_web_osx_x64: (AppKit) [com.apple.AppKit:General] (
	0   CoreFoundation                      0x00007fff206db98b __exceptionPreprocess + 242
	1   libobjc.A.dylib                     0x00007fff20413d92 objc_exception_throw + 48
	2   AppKit                              0x00007fff22e5aed6 -[NSApplication(NSEvent) _nextEventMatchingEventMask:untilDate:inMode:dequeue:] + 4389
	3   AppKit                              0x00007fff22e4c679 -[NSApplication run] + 586
	4   duplicacy_web_osx_x64               0x00000000049473a1 nativeLoop + 161
	5   duplicacy_web_osx_x64               0x0000000004946252 _cgo_67d7e7d56c36_Cfunc_nativeLoop + 34
	6   duplicacy_web_osx_x64               0x000000000405b3f0 runtime.asmcgocall + 112
)

See the matching pid to confirm the log is actually coming from the spurious instance.

gchen · 22 May 2021 02:46

Do you have the start on login option enabled? If this option is enabled (in the right-click menu from the menu bar icon), then ~/Library/LaunchAgents/duplicacy-web.plist will be created. If this file doesn’t exist then the local user instance shouldn’t be launched.

saspus · 22 May 2021 06:53

That was unchecked, and no duplicacy in LaunchAgents either.

I’ve deiced to reboot to disable SIP in order to use dtrace to see who is launching the spurious instance, but upon reboot the issues does not reproduce anymore, with or without SIP.

However I"m now consistently (across reboots) reproduce another issue: when booted the only Duplicacy process is consuming 100% CPU, does not respon on UI port, icon is missing from the command bar, and logs are streaming with this repeatedly:

2021-05-21 23:49:19.524284-0700 0x6bb      Error       0x0                  103    0    duplicacy_web_osx_x64: (AppKi^Ct) [com.apple.AppKit:General] nextEventMatchingMask should only be called from the Main Thread!
2021-05-21 23:49:19.524789-0700 0x6bb      Error       0x0                  103    0    duplicacy_web_osx_x64: (AppKit) [com.apple.AppKit:General] (
	0   CoreFoundation                      0x00007fff2080b98b __exceptionPreprocess + 242
	1   libobjc.A.dylib                     0x00007fff20543d92 objc_exception_throw + 48
	2   AppKit                              0x00007fff22f8aed6 -[NSApplication(NSEvent) _nextEventMatchingEventMask:untilDate:inMode:dequeue:] + 4389
	3   AppKit                              0x00007fff22f7c679 -[NSApplication run] + 586
	4   duplicacy_web_osx_x64               0x00000000049473a1 nativeLoop + 161
	5   duplicacy_web_osx_x64               0x0000000004946252 _cgo_67d7e7d56c36_Cfunc_nativeLoop + 34
	6   duplicacy_web_osx_x64               0x000000000405b3f0 runtime.asmcgocall + 112
)

Stopping and restarting the daemon fixes this. (launchctl stop/ launchctl start)

It looks duplciacy is trying to start way too early before desktop is ready perhaps and gets stuck.

I’'ll try to find a workaround and post it here later.

saspus · 22 May 2021 07:42

Hmm… Sometimes stopping and immediately starting the service with launchctl gets duplicacy into that eat-100%-CPU-being-stuck mode, so it is not specifc to system boot time per-se. It does not always happen with start/stop but does always happen on boot.

saspus · 22 May 2021 19:55

Is there a way to enable verbose logging for the web version to see at which point does it get into that bad state?

saspus · 22 May 2021 21:52

Ok, so this is what I observe:

Boot: duplicacy does not respond to UI port 100% of cases. Sometimes while consuming 100% cpu, other times idle.
sudo launchctl stop com.acrosync.duplicacy-web && sudo launchctl start com.acrosync.duplicacy-web – gets it unstuck most of the time. Other times it gets it into bad state.

This bug does not affect me terribly since I rarely reboot my Macs; but it is still worth it to get to the bottom of it.

@gchen, if you can share the version with generous amount of logging around startup I’ll be happy to reproduce and collect logs.

For reference, this is my current launchd daemon plist:

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
<plist version="1.0">
    <dict>
        <key>Label</key>
        <string>com.acrosync.duplicacy-web</string>

        <key>EnvironmentVariables</key>
        <dict>
            <key>HOME</key>
            <string>/Library/Duplicacy</string>
        </dict>

        <key>ProgramArguments</key>
        <array>
        <string>/Applications/Duplicacy Web Edition.app/Contents/MacOS/duplicacy_web_osx_x64</string>
        <string>-background</string>
        <string>-no-tray-icon</string>
        </array>
        <key>RunAtLoad</key>
        <true/>
        <key>WorkingDirectory</key>
        <string>/Library/Duplicacy</string>
    </dict>
</plist>

SIP status seem to make no difference.

There are no duplicacy related plists anywhere:

% ls -l /Library/LaunchDaemons /Library/LaunchAgents ~/Library/LaunchAgents ~/Library/LaunchAgents |grep -i duplic
acy
-rw-r--r--  1 root  wheel  753 May 22 00:38 com.acrosync.duplicacy-web.plist
% sw_vers -buildVersion
20E232 
%

saspus · 23 May 2021 04:46

Another issue: on start Duplicacy Web writes:

2021/05/22 21:42:54 Temporary directory set to /Library/Caches/Duplicacy
2021/05/22 21:42:54 Checking if Full Disk Access is enabled: open /Library/Duplicacy/Library/Safari/CloudTabs.db: no such file or directory

That path (/Library/Duplicacy/Library/Safari/CloudTabs.db) never exists. Why does it check that path?

This makes me think, maybe it requires more environment variables besides HOME?

gchen · 24 May 2021 04:20

I’ll try to reproduce the bug.

As the log message indicates, it was trying to open this file to check if FDA is enabled. Apple doesn’t provide an API for checking FDA so the only way is to open a few files that are usually present but can’t be opened by default.

saspus · 24 May 2021 04:49

Oh, I’ve just realized it is checking ${HOME}/Library/Safari/CloudTabs.db.

In case when it is running under root there cannot be such file… so I’ll have to put a fake one there to fool duplicacy_web into accepting that it has full access. (Because it does). Or can I just ignore it?

gchen · 25 May 2021 17:25

I was able to reproduce the bug and found a fix. The bug occurs in the systray icon library that the web GUI uses, but in this case the -no-tray-icon option is always needed, so the fix is to completely bypass the library when -no-tray-icon is specified.

I’ll get you a new build tomorrow.

gchen · 26 May 2021 20:20

Can you test this build: https://acrosync.com/duplicacy-web/duplicacy_web_osx_x64_1.5.1.dmg?

saspus · 26 May 2021 20:42

Awesome! Rebooted twice, works just fine. Thank you!

system · 5 June 2021 20:42

This topic was automatically closed 10 days after the last reply. New replies are no longer allowed.