Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Centos 8 Unable to start service "AdGuardHome.service: Systemd exits with status=209/STDOUT #3579

Closed
3 tasks done
hirale opened this issue Sep 11, 2021 · 14 comments
Closed
3 tasks done

Comments

@hirale
Copy link

hirale commented Sep 11, 2021

Have a question or an idea? Please search it on our forum to make sure it was not yet asked. If you cannot find what you had in mind, please submit it here.

Prerequisites

Please answer the following questions for yourself before submitting an issue. YOU MAY DELETE THE PREREQUISITES SECTION.

  • I am running the latest version
  • I checked the documentation and found no answer
  • I checked to make sure that this issue has not already been filed

Issue Details

  • Version of AdGuard Home server:
    • AdGuard Home
      Version: v0.106.3
      Channel: release
      Go version: go1.15.11
      Build time: 2021-05-19T13:25:09Z+0000
      GOOS: linux
      GOARCH: amd64
  • How did you install AdGuard Home:
  • How did you setup DNS configuration:
    • System
  • CPU architecture:
    • AMD64
  • Operating system and version:
    • Centos 8

Expected Behavior

Starting the AdGuard Home server with systemctl start AdGuardHome.service

Actual Behavior

[root@instance AdGuardHome]# systemctl start AdGuardHome.service 
[root@instance AdGuardHome]# systemctl status AdGuardHome.service 
● AdGuardHome.service - AdGuard Home: Network-level blocker
   Loaded: loaded (/etc/systemd/system/AdGuardHome.service; enabled; vendor preset: disabled)
   Active: activating (auto-restart) (Result: exit-code) since Sat 2021-09-11 19:04:40 GMT; 552ms ago
  Process: 666356 ExecStart=/opt/AdGuardHome/AdGuardHome -s run (code=exited, status=209/STDOUT)
 Main PID: 666356 (code=exited, status=209/STDOUT)

Sep 11 19:04:40 instance systemd[1]: AdGuardHome.service: Main process exited, code=exited, status=209/STDOUT
Sep 11 19:04:40 instance systemd[1]: AdGuardHome.service: Failed with result 'exit-code'.

Additional Information

After some researches I figured out the cause with code 209/STDOUT.
In my case, it can work after removing these 2 lines .

StandardOutput=file:/var/log/AdGuardHome.out
StandardError=file:/var/log/AdGuardHome.err
[root@instance AdGuardHome]# vi /etc/systemd/system/AdGuardHome.service 
[root@instance AdGuardHome]# systemctl daemon-reload
[root@instance AdGuardHome]# systemctl start AdGuardHome.service 
[root@instance AdGuardHome]# systemctl status AdGuardHome.service 
● AdGuardHome.service - AdGuard Home: Network-level blocker
   Loaded: loaded (/etc/systemd/system/AdGuardHome.service; enabled; vendor preset: disabled)
   Active: active (running) since Sat 2021-09-11 19:14:39 GMT; 2s ago
 Main PID: 667072 (AdGuardHome)
    Tasks: 8 (limit: 4562)
   Memory: 11.6M
   CGroup: /system.slice/AdGuardHome.service
           └─667072 /opt/AdGuardHome/AdGuardHome -s run

Sep 11 19:14:39 instance AdGuardHome[667072]: 2021/09/11 19:14:39.753585 [info] AdGuard Home can bind to port 53
Sep 11 19:14:39 instance AdGuardHome[667072]: 2021/09/11 19:14:39.754719 [info] Initializing auth module: /opt/AdGuardHome/data/s>
Sep 11 19:14:39 instance AdGuardHome[667072]: 2021/09/11 19:14:39.756675 [info] auth: initialized.  users:0  sessions:0
Sep 11 19:14:39 instance AdGuardHome[667072]: 2021/09/11 19:14:39.756689 [info] Initialize web module
Sep 11 19:14:39 instance AdGuardHome[667072]: 2021/09/11 19:14:39.756713 [info] This is the first launch of AdGuard Home, redirec>
Sep 11 19:14:39 instance AdGuardHome[667072]: 2021/09/11 19:14:39.756751 [info] AdGuard Home is available on the following addres>
Sep 11 19:14:39 instance AdGuardHome[667072]: 2021/09/11 19:14:39.757133 [info] Go to http://127.0.0.1:3000
Sep 11 19:14:39 instance AdGuardHome[667072]: 2021/09/11 19:14:39.757140 [info] Go to http://[::1]:3000
Sep 11 19:14:39 instance AdGuardHome[667072]: 2021/09/11 19:14:39.757144 [info] Go to http://10.0.0.77:3000
Sep 11 19:14:39 instance AdGuardHome[667072]: 2021/09/11 19:14:39.757147 [info] Go to http://172.17.0.1:3000

Doubts

I checked changelog of systemctl https://lists.freedesktop.org/archives/systemd-devel/2017-December/039996.html,

        * StandardInput=, StandardOutput= and StandardError= may now be used to
          connect stdin/stdout/stderr of executed processes directly with a
          file or AF_UNIX socket in the file system, using the new "file:" option.

this file: option works with version newer than 236, but it didn't work on my instance.

[root@instance AdGuardHome]# systemctl --version
systemd 239 (239-45.el8_4.3)
+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy
@ainar-g ainar-g added the needs investigation Needs to be reproduced reliably. label Sep 13, 2021
@ainar-g ainar-g self-assigned this Sep 13, 2021
@ainar-g ainar-g added compatibility enhancement P3: Medium and removed needs investigation Needs to be reproduced reliably. labels Sep 13, 2021
@ainar-g ainar-g added this to the v0.107.0 milestone Sep 13, 2021
adguard pushed a commit that referenced this issue Sep 13, 2021
Updates #3579.

Squashed commit of the following:

commit 9bb4512
Author: Ainar Garipov <A.Garipov@AdGuard.COM>
Date:   Mon Sep 13 16:57:43 2021 +0300

    all: imp chlog

commit d2285cb
Author: Ainar Garipov <A.Garipov@AdGuard.COM>
Date:   Mon Sep 13 16:41:54 2021 +0300

    home: imp systemd unit script
@ainar-g
Copy link
Contributor

ainar-g commented Sep 13, 2021

We have made some improvements to our systemd scripts on the edge channel as of snapshot 53f7c0b. Can you please check if our improvements fix the issue for you?

@hirale
Copy link
Author

hirale commented Sep 18, 2021

We have made some improvements to our systemd scripts on the edge channel as of snapshot 53f7c0b. Can you please check if our improvements fix the issue for you?

I tested on fresh CentOS-8.4.2105-x86_64. The same result, i have to remove these.

StandardOutput=file:/var/log/AdGuardHome.out
StandardError=file:/var/log/AdGuardHome.err

Here is log.

[root@centos8 opt]# curl -s -S -L https://raw.githubusercontent.com/AdguardTeam/AdGuardHome/master/scripts/install.sh | sh -s -- -v -c edge
starting AdGuard Home installation script
channel: edge
operating system: linux
cpu type: amd64
AdGuard Home will be installed into /opt/AdGuardHome
checking curl
checking tar
script is executed with root privileges
no need to uninstall
downloading package from https://static.adguard.com/adguardhome/edge/AdGuardHome_linux_amd64.tar.gz -> AdGuardHome_linux_amd64.tar.gz
unpacking package from AdGuardHome_linux_amd64.tar.gz into /opt
2021/09/18 09:36:20 [info] Service control action: install
2021/09/18 09:36:21 [fatal] Failed to start the service: Failed to start AdGuard Home service: exit status 1
cannot install AdGuardHome as a service
[root@centos8 opt]# systemctl status AdGuardHome
● AdGuardHome.service - AdGuard Home: Network-level blocker
   Loaded: loaded (/etc/systemd/system/AdGuardHome.service; enabled; vendor preset: disabled)
   Active: inactive (dead) (Result: exit-code) since Sat 2021-09-18 09:36:31 CEST; 59s ago
Condition: start condition failed at Sat 2021-09-18 09:36:31 CEST; 59s ago
           └─ ConditionFileIsExecutable=/opt/AdGuardHome/AdGuardHome was not met
  Process: 14056 ExecStartPre=/usr/bin/mkdir -p /var/log/ (code=exited, status=209/STDOUT)

Sep 18 09:36:21 centos8 systemd[1]: AdGuardHome.service: Control process exited, code=exited status=209
Sep 18 09:36:21 centos8 systemd[1]: AdGuardHome.service: Failed with result 'exit-code'.
Sep 18 09:36:21 centos8 systemd[1]: Failed to start AdGuard Home: Network-level blocker.
Sep 18 09:36:31 centos8 systemd[1]: AdGuardHome.service: Service RestartSec=10s expired, scheduling restart.
Sep 18 09:36:31 centos8 systemd[1]: AdGuardHome.service: Scheduled restart job, restart counter is at 5.
Sep 18 09:36:31 centos8 systemd[1]: Stopped AdGuard Home: Network-level blocker.
[root@centos8 opt]# ls -al /opt
total 0
drwxr-xr-x.  2 root root   6 Sep 18 09:36 .
dr-xr-xr-x. 17 root root 224 Sep 18 09:22 ..
[root@centos8 opt]# uname -r
4.18.0-305.19.1.el8_4.x86_64
[root@centos8 opt]# systemctl --version
systemd 239 (239-45.el8_4.3)
+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=legacy
[root@centos8 opt]# wget https://static.adguard.com/adguardhome/edge/AdGuardHome_linux_amd64.tar.gz && tar xvzf AdGuardHome_linux_amd64.tar.gz
--2021-09-18 09:41:28--  https://static.adguard.com/adguardhome/edge/AdGuardHome_linux_amd64.tar.gz
Resolving static.adguard.com (static.adguard.com)... 104.20.91.49, 104.20.90.49, 172.67.3.157, ...
Connecting to static.adguard.com (static.adguard.com)|104.20.91.49|:443... connected.
HTTP request sent, awaiting response... 200 OK
Length: 10543248 (10M) [application/octet-stream]
Saving to: ‘AdGuardHome_linux_amd64.tar.gz’

AdGuardHome_linux_amd64.tar. 100%[==============================================>]  10.05M  7.31MB/s    in 1.4s

2021-09-18 09:41:30 (7.31 MB/s) - ‘AdGuardHome_linux_amd64.tar.gz’ saved [10543248/10543248]

./AdGuardHome/
./AdGuardHome/AdGuardHome
./AdGuardHome/LICENSE.txt
./AdGuardHome/AdGuardHome.sig
./AdGuardHome/README.md
./AdGuardHome/CHANGELOG.md
[root@centos8 opt]# systemctl restart AdGuardHome && systemctl status AdGuardHome
Job for AdGuardHome.service failed because the control process exited with error code.
See "systemctl status AdGuardHome.service" and "journalctl -xe" for details.
[root@centos8 opt]# systemctl status AdGuardHome
● AdGuardHome.service - AdGuard Home: Network-level blocker
   Loaded: loaded (/etc/systemd/system/AdGuardHome.service; enabled; vendor preset: disabled)
   Active: activating (auto-restart) (Result: exit-code) since Sat 2021-09-18 09:42:04 CEST; 1s ago
  Process: 14073 ExecStartPre=/usr/bin/mkdir -p /var/log/ (code=exited, status=209/STDOUT)

Sep 18 09:42:04 centos8 systemd[1]: AdGuardHome.service: Control process exited, code=exited status=209
Sep 18 09:42:04 centos8 systemd[1]: AdGuardHome.service: Failed with result 'exit-code'.
Sep 18 09:42:04 centos8 systemd[1]: Failed to start AdGuard Home: Network-level blocker.
[root@centos8 opt]# vi /etc/systemd/system/AdGuardHome.service
[root@centos8 opt]# cat /etc/systemd/system/AdGuardHome.service
[Unit]
Description=AdGuard Home: Network-level blocker
ConditionFileIsExecutable=/opt/AdGuardHome/AdGuardHome

After=syslog.target network-online.target

[Service]
StartLimitInterval=5
StartLimitBurst=10
ExecStartPre=mkdir -p /var/log/
ExecStart=/opt/AdGuardHome/AdGuardHome "-s" "run"

WorkingDirectory=/opt/AdGuardHome




Restart=always

RestartSec=10
EnvironmentFile=-/etc/sysconfig/AdGuardHome

[Install]
WantedBy=multi-user.target
[root@centos8 opt]# systemctl daemon-reload
[root@centos8 opt]# systemctl restart AdGuardHome && systemctl status AdGuardHome
● AdGuardHome.service - AdGuard Home: Network-level blocker
   Loaded: loaded (/etc/systemd/system/AdGuardHome.service; enabled; vendor preset: disabled)
   Active: active (running) since Sat 2021-09-18 09:44:42 CEST; 3min 32s ago
  Process: 14147 ExecStartPre=/usr/bin/mkdir -p /var/log/ (code=exited, status=0/SUCCESS)
 Main PID: 14148 (AdGuardHome)
    Tasks: 6 (limit: 11390)
   Memory: 10.6M
   CGroup: /system.slice/AdGuardHome.service
           └─14148 /opt/AdGuardHome/AdGuardHome -s run

Sep 18 09:44:43 centos8 AdGuardHome[14148]: 2021/09/18 09:44:43.014024 [info] auth: initialized.  users:0  sessions:0
Sep 18 09:44:43 centos8 AdGuardHome[14148]: 2021/09/18 09:44:43.014049 [info] Initialize web module
Sep 18 09:44:43 centos8 AdGuardHome[14148]: 2021/09/18 09:44:43.014066 [info] This is the first launch of AdGuard Home, redirecting everything to /install.html
Sep 18 09:44:43 centos8 AdGuardHome[14148]: 2021/09/18 09:44:43.014101 [info] AdGuard Home is available at the following addresses:
Sep 18 09:44:43 centos8 AdGuardHome[14148]: 2021/09/18 09:44:43.014329 [info] Go to http://127.0.0.1:3000
Sep 18 09:44:43 centos8 AdGuardHome[14148]: 2021/09/18 09:44:43.014341 [info] Go to http://127.0.0.1:3001 (BETA)
Sep 18 09:44:43 centos8 AdGuardHome[14148]: 2021/09/18 09:44:43.014351 [info] Go to http://[::1]:3000
Sep 18 09:44:43 centos8 AdGuardHome[14148]: 2021/09/18 09:44:43.014360 [info] Go to http://[::1]:3001 (BETA)
Sep 18 09:44:43 centos8 AdGuardHome[14148]: 2021/09/18 09:44:43.014370 [info] Go to http://10.0.2.7:3000
Sep 18 09:44:43 centos8 AdGuardHome[14148]: 2021/09/18 09:44:43.014391 [info] Go to http://10.0.2.7:3001 (BETA)

@ainar-g
Copy link
Contributor

ainar-g commented Sep 21, 2021

@hirale, it seems like you haven't deleted the old AGH. Which means that the unit file is still the one installed by the old version. Can you please backup your data and configuration, uninstall AdGuard Home fully, and install again from edge?

@hirale
Copy link
Author

hirale commented Sep 21, 2021

@hirale, it seems like you haven't deleted the old AGH. Which means that the unit file is still the one installed by the old version. Can you please backup your data and configuration, uninstall AdGuard Home fully, and install again from edge?

I tried it on a new centos 8 vm.

@ainar-g
Copy link
Contributor

ainar-g commented Sep 21, 2021

@hirale, surely it's not the full log then? The unit file must only appear once you call AdGuardHome -s install.

@hirale
Copy link
Author

hirale commented Sep 21, 2021

@hirale, surely it's not the full log then? The unit file must only appear once you call AdGuardHome -s install.

I didn't call AdGuardHome -s install because the command curl -s -S -L https://raw.githubusercontent.com/AdguardTeam/AdGuardHome/master/scripts/install.sh | sh -s -- -v -c edge didn't download file into /opt/ directory. I'm creating a new vm, will upload screenshot soon.

@hirale
Copy link
Author

hirale commented Sep 21, 2021

Missing /opt/AdGuardHome/AdGuardHome

image

@ainar-g
Copy link
Contributor

ainar-g commented Sep 21, 2021

Thanks for the full log, it's really helpful!

ls doesn't show anything because /opt/AdGuardHome is deleted by the installation script if the installation fails at that point. We should probably add more logs about that, as well as maybe call ls ourselves and print the result when -v is used to make sure it's actually there.

(While we're at it, we can probably use wget if it is installed on the system instead of requiring curl, but that's a separate issue.)

The ConditionFileIsExecutable failure is interesting. Perhaps the binary is unpacked without preserving the executable bit. Again, we'll add more debugging logs to diagnose that.

adguard pushed a commit that referenced this issue Sep 21, 2021
Updates #3579.

Squashed commit of the following:

commit 0fe83fb
Author: Ainar Garipov <A.Garipov@AdGuard.COM>
Date:   Tue Sep 21 14:36:04 2021 +0300

    all: imp install script logs
@ainar-g
Copy link
Contributor

ainar-g commented Sep 21, 2021

@hirale, we've added some additional logging in the recent commits to the main branch. When you have the time, could you try and reproduce the issue with -s install? Thanks.

@hirale
Copy link
Author

hirale commented Sep 22, 2021

  1. Tried with curl -s -S -L https://raw.githubusercontent.com/AdguardTeam/AdGuardHome/master/scripts/install.sh | sh -s -- -v -c edge
    image
  2. Downloaded package manually to reproduce the issue
    image

adguard pushed a commit that referenced this issue Sep 22, 2021
Updates #3579.

Squashed commit of the following:

commit 9a25fe1
Author: Ainar Garipov <A.Garipov@AdGuard.COM>
Date:   Wed Sep 22 18:09:25 2021 +0300

    all: imp install script logs, systemd unit file
@ainar-g
Copy link
Contributor

ainar-g commented Sep 22, 2021

@hirale, thanks again for the logs. We have pushed another couple of changes to the edge channel. Could you please retry the first one, with -c edge, when you have the time? Thanks.

@hirale
Copy link
Author

hirale commented Sep 23, 2021

image

@ainar-g
Copy link
Contributor

ainar-g commented Sep 27, 2021

I'm honestly stumped at this point. This question on StackOverflow says that it might be a SELinux thing and provides some ways to detect that in the comments. Besides that, I don't have any ideas currently.

@hirale
Copy link
Author

hirale commented Sep 27, 2021

Yes, caused by SELinux.
image
Thanks.

@hirale hirale closed this as completed Sep 27, 2021
heyxkhoa pushed a commit to heyxkhoa/AdGuardHome that referenced this issue Mar 20, 2023
Updates AdguardTeam#3579.

Squashed commit of the following:

commit 9bb4512
Author: Ainar Garipov <A.Garipov@AdGuard.COM>
Date:   Mon Sep 13 16:57:43 2021 +0300

    all: imp chlog

commit d2285cb
Author: Ainar Garipov <A.Garipov@AdGuard.COM>
Date:   Mon Sep 13 16:41:54 2021 +0300

    home: imp systemd unit script
heyxkhoa pushed a commit to heyxkhoa/AdGuardHome that referenced this issue Mar 20, 2023
Updates AdguardTeam#3579.

Squashed commit of the following:

commit 0fe83fb
Author: Ainar Garipov <A.Garipov@AdGuard.COM>
Date:   Tue Sep 21 14:36:04 2021 +0300

    all: imp install script logs
heyxkhoa pushed a commit to heyxkhoa/AdGuardHome that referenced this issue Mar 20, 2023
Updates AdguardTeam#3579.

Squashed commit of the following:

commit 9a25fe1
Author: Ainar Garipov <A.Garipov@AdGuard.COM>
Date:   Wed Sep 22 18:09:25 2021 +0300

    all: imp install script logs, systemd unit file
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

2 participants