Arch Linux

ectospasm

Member

Registered: 2015-08-28

Posts: 296

[SOLVED] unifi, systemd, and poweroff/reboot targets

[SOLVED] It turns out if mongodb.service is running, the mongodb instance launched by unifi.service considers the WiredTiger storage engine to be corrupted.  Running systemctl disable mongodb.service prevents the systemd version from interfering with the unifi version.  Now rebooting the system doesn't force a repair of the MongoDB database.  Noting that my /usr/lib/systemd/system-shutdown/unifi.shutdown script may be involved here, I removed it and tried rebooting again.  This is met with SUCCESS!  So it was the mongodb.service all along!

Original post:
I'm running the Ubiquity UniFi Controller (version 5.11.46) to control my UniFi access point (AP-AC-LR).  It works great, when it works.  However, I'm constantly fighting with the MongoDB dependency (mongodb-bin-4.0, v4.0.12-2) unifi.service has.  It seems every time I reboot the workstation where this is installed, the WiredTiger engine component of MongoDB gets corrupted, forcing me to issue the following command:

sudo mongod --repair --config /etc/mongodb.conf

I need to make sure unifi.service is cleanly shutdown before the system reboots or powers off.  I figure the reboot.target and poweroff.target systemd targets are the way to go.  The Arch Wiki on systemd#Targets is scant on details of how to do this. 

The answer (I think):  After reading the `systemd-reboot` man page, it looks like the executable, /usr/lib/systemd/systemd-shutdown executes all the commands in /usr/lib/systemd/system-shutdown in parallel.  The system won't begin the shutdown (halt, poweroff, reboot, etc.) until all of those commands finish executing.  On my system, the only file that was in there was mdadm.shutdown, which is a POSIX (Bourne-shell) script.  I created unifi.shutdown:

#!/bin/sh
/usr/bin/systemctl stop unifi.service

Now, all I have to do is test it.

EDIT:  It did NOT work, when I rebooted mongod.log is saying that I need to run --repair again.  It's curious, why didn't the above work?

Last edited by ectospasm (2019-10-06 13:42:19)

V1del

Forum Moderator

Registered: 2012-10-16

Posts: 24,013

Re: [SOLVED] unifi, systemd, and poweroff/reboot targets

I'd not expect it to work, systemd will properly shutdown services under it's control without you explicitly having to do so. how does the unifi service file  look like? What journal entries does it produce on shutdown/stop? Does the corruption not happen if you stop the service during active system use (I doubt that?)

ectospasm

Member

Registered: 2015-08-28

Posts: 296

Re: [SOLVED] unifi, systemd, and poweroff/reboot targets

Here's the service file:

[Unit]
Description=Ubiquiti UniFi Server
After=network.target
                                                                                                                                                                                             
[Service]
User=unifi
WorkingDirectory=/usr/lib/unifi
ExecStart=/usr/bin/java -jar /usr/lib/unifi/lib/ace.jar start
ExecStop=/usr/bin/java -jar /usr/lib/unifi/lib/ace.jar stop
                                                                                                                                                                                             
[Install]
WantedBy=multi-user.target

So as soon as the process for isolating reboot.target or poweroff.target executes ExecStop, the Java command should be executed.  Here's the output of the previous boot (before --boot 0, the current boot):

-- Logs begin at Tue 2018-12-25 18:48:56 EST, end at Mon 2019-09-30 17:20:08 EDT. --
Sep 22 14:18:02 osmium systemd[1]: Started Ubiquiti UniFi Server.
-- Subject: A start job for unit unifi.service has finished successfully
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/l … temd-devel
--
-- A start job for unit unifi.service has finished successfully.
--
-- The job identifier is 94.
Sep 27 19:02:32 osmium systemd[1]: Stopping Ubiquiti UniFi Server...
-- Subject: A stop job for unit unifi.service has begun execution
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/l … temd-devel
--
-- A stop job for unit unifi.service has begun execution.
--
-- The job identifier is 132747.
Sep 27 19:02:34 osmium java[423]: org.tuckey.web.filters.urlrewrite.UrlRewriteFilter INFO: destroy called
Sep 27 19:02:39 osmium systemd[1]: unifi.service: Main process exited, code=exited, status=143/n/a
-- Subject: Unit process exited
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/l … temd-devel
--
-- An ExecStart= process belonging to unit unifi.service has exited.
--
-- The process' exit code is 'exited' and its exit status is 143.
Sep 27 19:02:39 osmium systemd[1]: unifi.service: Failed with result 'exit-code'.
-- Subject: Unit failed
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/l … temd-devel
--
-- The unit unifi.service has entered the 'failed' state with result 'exit-code'.
Sep 27 19:02:39 osmium systemd[1]: Stopped Ubiquiti UniFi Server.
-- Subject: A stop job for unit unifi.service has finished
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/l … temd-devel
--
-- A stop job for unit unifi.service has finished.
--
-- The job identifier is 132747 and the job result is done.
Sep 27 19:02:39 osmium systemd[1]: Started Ubiquiti UniFi Server.
-- Subject: A start job for unit unifi.service has finished successfully
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/l … temd-devel
--
-- A start job for unit unifi.service has finished successfully.
--
-- The job identifier is 132747.
Sep 27 22:53:33 osmium systemd[1]: Stopping Ubiquiti UniFi Server...
-- Subject: A stop job for unit unifi.service has begun execution
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/l … temd-devel
--
-- A stop job for unit unifi.service has begun execution.
--
-- The job identifier is 136865.
Sep 27 22:53:35 osmium java[575362]: org.tuckey.web.filters.urlrewrite.UrlRewriteFilter INFO: destroy called
Sep 27 22:53:39 osmium systemd[1]: unifi.service: Main process exited, code=exited, status=143/n/a
-- Subject: Unit process exited
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/l … temd-devel
--
-- An ExecStart= process belonging to unit unifi.service has exited.
--
-- The process' exit code is 'exited' and its exit status is 143.
Sep 27 22:53:39 osmium systemd[1]: unifi.service: Failed with result 'exit-code'.
-- Subject: Unit failed
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/l … temd-devel
--
-- The unit unifi.service has entered the 'failed' state with result 'exit-code'.
Sep 27 22:53:39 osmium systemd[1]: Stopped Ubiquiti UniFi Server.
-- Subject: A stop job for unit unifi.service has finished
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/l … temd-devel
--
-- A stop job for unit unifi.service has finished.
--
-- The job identifier is 136865 and the job result is done.

If I shut the Unifi Controller down with systemctl stop unifi.service, it looks like the stop job gets the exit code 143.  It is strange, in the /var/log/unifi/mongod.log it says it exits with exit code 0, so I'm not sure where that 143 is coming from.  It appears to be coming from systemd itself, if I stop unifi.service (systemctl stop unifi.service), it gets the exit code 143.  If I run the ExecStop job manually (sudo -u unifi /usr/bin/java -jar /usr/lib/unifi/lib/ace.jar stop), it exits with code 0, and the systemd status is inactive, as expected, with exit status 0/Success.

It does not appear that I can reproduce the WiredTiger database corruption simply by stopping and starting unifi.service.  It must come from an unclean shutdown of the Java executable.  I have a related question, do the scripts in /usr/lib/systemd/system-shutdown/ get executed before or after all units have been stopped?  I could simply place the --repair command there, if they're executed after all units have been shutdown.  The systemd-reboot.service manual page suggests these scripts are executed immediately before the final halt/power off/reboot/kexec command.  I'll try placing it there and see what happens.

EDIT:  Removed extra whitespace from the end of lines in the unit file.

Last edited by ectospasm (2019-09-30 23:11:15)

ectospasm

Member

Registered: 2015-08-28

Posts: 296

Re: [SOLVED] unifi, systemd, and poweroff/reboot targets

jHere's the script I wrote (/usr/lib/systemd/system-shutdown/unifi.shutdown):

#!/bin/bash                                                                                                                                                                                   
# This script ensures the Ubiquiti UniFi Controller (and it's corresponding WiredTiger/MongoDB instance) is shutdown cleanly                                                                  
mylog=/var/log/unifi.shutdown.log                                                                                                                                                             
                                                                                                                                                                                              
echo "$(date +%FT%T):  Execuitng /usr/lib/systemd/system-shutdown/unifi.shutdown" >> $mylog                                                                                                   
if ps -eaf | grep "/usr/bin/mongo[d] " &> /dev/null; then                                                                                                                                     
    echo "$(date +%FT%T):  mongodb running!  Stopping Unifi controller manually..." >> $mylog                                                                                                 
    sudo -u unifi /usr/bin/java -jar /usr/lib/unifi/lib/ace.jar stop && \                                                                                                                     
        echo "$(date +%FT%T):  Unifi Controller shut down cleanly." >> $mylog || \                                                                                                            
        echo "$(date +%FT%T):  Unifi Controller *NOT* shut down cleanly, repair required." >> $mylog && \                                                                                     
        sudo -u unifi /bin/rm /var/lib/unifi/data/db/WiredTiger.lock && \                                                                                                                     
        sudo -u unifi /usr/bin/mongod --repair --config /etc/mongodb.conf >> $mylog                                                                                                           
fi                                                                                                                    

Upon reboot, the log file /var/log/unifi.shutdown.log did not get created, so it appears systemd isn't executing the scripts found in /usr/lib/systemd/system-shutdown.  Here are the permissions/ownership of /usr/lib/systemd/system-shutdown/unifi.shutdown: 

-rwxr-xr-x 1 root root 841 Sep 30 18:43 /usr/lib/systemd/system-shutdown/unifi.shutdown

If I execute the script manually as root, it does work (shuts down Unifi and creates/appends to the log file).  So now I have two issues:  the final reboot command is occurring before unifi.service shuts down completely, thereby hosing the WiredTiger database (which forces a --repair operation if the Unifi Controller is to be functional in the future);  and my custom shutdown script isn't being executed (even though the systemd-reboot manual page suggests it should).

Both of these problems appear to be related to systemd not behaving as documented, instead of issues with the Unifi Controller itself. 

EDIT:  Fixed typo in the unifi.shutdown permissions output.

Last edited by ectospasm (2019-09-30 23:06:54)

ectospasm

Member

Registered: 2015-08-28

Posts: 296

Re: [SOLVED] unifi, systemd, and poweroff/reboot targets

I did a little digging on what "systemd exit status 143" means, and I found this ServerFault post.  It's for Minecraft, not Unifi Controller, but it's another Java server application.  It suggests placing the following line in the unifi.service file:

[Service]
SuccessExitStatus=143

I tried that, and I see this now in journalctl: 

Sep 30 19:25:50 osmium systemd[1]: Started Ubiquiti UniFi Server.
-- Subject: A start job for unit unifi.service has finished successfully
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- A start job for unit unifi.service has finished successfully.
-- 
-- The job identifier is 704.
Sep 30 19:26:09 osmium systemd[1]: Stopping Ubiquiti UniFi Server...
-- Subject: A stop job for unit unifi.service has begun execution
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- A stop job for unit unifi.service has begun execution.
-- 
-- The job identifier is 826.
Sep 30 19:26:11 osmium java[2926]: org.tuckey.web.filters.urlrewrite.UrlRewriteFilter INFO: destroy called
Sep 30 19:26:15 osmium systemd[1]: unifi.service: Succeeded.
-- Subject: Unit succeeded
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- The unit unifi.service has successfully entered the 'dead' state.
Sep 30 19:26:15 osmium systemd[1]: Stopped Ubiquiti UniFi Server.
-- Subject: A stop job for unit unifi.service has finished
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- A stop job for unit unifi.service has finished.
-- 
-- The job identifier is 826 and the job result is done.

So now the unit is stopping cleanly (with Success), but the WiredTiger database is still being corrupted.  It must be that the Java application exits before the WiredTiger component has shutdown cleanly, and systemd is dutifully killing it before WiredTiger shuts down, forcing the repair.  If I could add a pause on shutdown in the unit file, that may acceptably work around this problem (which now I see in the Unifi Controller).

progandy

Member

Registered: 2012-05-17

Posts: 5,280

Re: [SOLVED] unifi, systemd, and poweroff/reboot targets

Maybe the unifi service should also depend on mongodb to ensure the shutdown order. You could also try setting KillMode and the stop timeout. This way, systemd sends SIGTERM only to the main process and then waits 30 seconds. Only then all subprocesses will get a SIGKILL signal.

KillMode=mixed
TimeoutStopSec=30s

Last edited by progandy (2019-10-01 06:46:11)

---

| alias CUTF='LANG=en_XX.UTF-8@POSIX ' |

ectospasm

Member

Registered: 2015-08-28

Posts: 296

Re: [SOLVED] unifi, systemd, and poweroff/reboot targets

Maybe the unifi service should also depend on mongodb to ensure the shutdown order.

.
MongoDB isn't managed by systemd (starting the ace.jar file spins up a Unifi-specific instance of MongoDB [/etc/mongodb.conf is specific to Unifi, but starting the mongodb.service unit causes problems for the unifi.service unit]).  Perhaps this shouldn't be this way, but it's part of Ubiquity's upstream design.

You could also try setting KillMode and the stop timeout. This way, systemd sends SIGTERM only to the main process and then waits 30 seconds. Only then all subprocesses will get a SIGKILL signal.

KillMode=mixed
TimeoutStopSec=30s

I'll try KillMode and setting TimeoutStopSec=30s and see what happens.  That... didn't work.  The WiredTiger database was still corrupted, and I've been having to delete the WiredTiger.lock file manually.  If my unifi.shutdown script worked the way it's supposed to, this problem would be worked around.

I'll try setting the TimeoutStopSec=90s, and see if that makes a difference.  That... didn't work either.  Judging by the sound of the system fans (which spin up to full bore during POST), systemd didn't wait 90 seconds to actually reboot.

Maybe I should seek help upstream.  I'll try that later this week.

ectospasm

Member

Registered: 2015-08-28

Posts: 296

Re: [SOLVED] unifi, systemd, and poweroff/reboot targets

It turns out if MongoDB is launched by systemd, it interferes with the Unifi-specific MongoDB instance launched by the Unifi Controller.  Running the following ultimately fixed the problem:

systemctl disable mongodb.service

I've marked this problem as solved in the original post, and left a complete description of the solution in the original post (so no one needs to scroll this rather lengthy topic).

progandy

Member

Registered: 2012-05-17

Posts: 5,280

Re: [SOLVED] unifi, systemd, and poweroff/reboot targets

Congratulations. If you want to run mongodb as a systemd service, then you can configure the unifi controller to use an external database:
https://community.ui.com/questions/Exte … fec9dc1bbc

---

| alias CUTF='LANG=en_XX.UTF-8@POSIX ' |