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

status of one service cannot be successfully got by other service #138

Open
amy119-happy opened this issue Feb 25, 2022 · 3 comments
Open

Comments

@amy119-happy
Copy link

Hi,

I have service1 that can be started without any problems. But service2 can only be started if service1 is up. The problem is that service2 cannot start because it detected the inactive status of service1, which is actually started already. Blow is the detail. Can you give me some ideas why is that? thanks.

jtcx@ganlu-XPS-15-9560:~$ sudo systemctl status roscore
roscore.service - roscore launcher
    Loaded: loaded (/etc/systemd/system/roscore.service, enabled)
    Active: inactive (dead)
jtcx@ganlu-XPS-15-9560:~$ sudo systemctl start roscore
jtcx@ganlu-XPS-15-9560:~$ sudo systemctl status roscore
roscore.service - roscore launcher
    Loaded: loaded (/etc/systemd/system/roscore.service, enabled)
    Active: active (running)
jtcx@ganlu-XPS-15-9560:~$ sudo systemctl start control_master
ERROR:systemctl:the ExecStartPre control process exited with error code
jtcx@ganlu-XPS-15-9560:~$ cat /etc/systemd/system/control_master.service 
[Unit]
Description=control_master launcher
PartOf=roscore.service

[Service]
User=jtcx
Type=simple
KillMode=process
TimeoutStopSec=1
KillSignal=SIGTERM
ExecStartPre=/bin/systemctl is-active roscore
ExecStart=/usr/local/share/health_monitor/ros_wrapper.sh roslaunch jtcx_robot control_master.launch
Restart=always
RestartSec=3s

[Install]
WantedBy=multi-user.target
jtcx@ganlu-XPS-15-9560:~$ cat /var/log/journal/control_master.service.log 
inactive
inactive
jtcx@ganlu-XPS-15-9560:~$ 
@gdraheim
Copy link
Owner

Please check what the logging says - you can use "-vvv" for the direct logging level or you create a /var/log/systemctl.debug.log before running a systemctl command.

I don't see hown "is-active roscore" can make for a dependency as the command does not wait. And PartOf represents an inverse relationship.

@amy119-happy
Copy link
Author

Hi, thanks for your reply.
What i am understanding is that ExecStartPrre need to checks the active status of roscore. Only if roscore is active, will the control_master service execute the ExecStart. But it cannot find the active status of roscore, control master starts failed. This is somethong I have already tried on my host ubuntu, it shows no problem.
I have already activates the logging level, it shows belows, i cannot see anything difference from this. Can you give me some ideas, thank you very much. Actually there is another problem. I have enabled roscore, but it cannot start automatically. I still need to start it manually.

jtcx@ganlu-XPS-15-9560:/var/log$ sudo systemctl status roscore
[sudo] password for jtcx: 
INFO:systemctl:EXEC BEGIN /usr/bin/systemctl status roscore --system
DEBUG:systemctl:======= systemctl.py status roscore
DEBUG:systemctl:found 197 sysd files
DEBUG:systemctl:found 7 sysv files
roscore.service - roscore launcher
    Loaded: loaded (/etc/systemd/system/roscore.service, enabled)
    Active: inactive (dead)
jtcx@ganlu-XPS-15-9560:/var/log$ cat /var/log/systemctl.debug.log 
2022-02-26 02:40:21,471 INFO EXEC BEGIN /usr/bin/systemctl status roscore --system
2022-02-26 02:40:21,472 DEBUG ======= systemctl.py status roscore
2022-02-26 02:40:21,474 DEBUG found 197 sysd files
2022-02-26 02:40:21,475 DEBUG found 7 sysv files
jtcx@ganlu-XPS-15-9560:/var/log$ sudo systemctl start roscore
INFO:systemctl:EXEC BEGIN /usr/bin/systemctl start roscore --system
DEBUG:systemctl:======= systemctl.py start roscore
DEBUG:systemctl:found 197 sysd files
DEBUG:systemctl:found 7 sysv files
INFO:systemctl:system is offline
DEBUG:systemctl:'/etc/systemd/system/roscore.service' no --user mode >> accept
DEBUG:systemctl: start unit roscore.service => '/etc/systemd/system/roscore.service'
DEBUG:systemctl:extra-vars []
INFO:systemctl: pre-start '/bin/systemctl' 'is-active' 'network-online.target'
DEBUG:systemctl: pre-start done (OK) <->
DEBUG:systemctl:ExecStart[0]: /usr/local/share/health_monitor/ros_wrapper.sh roscore
INFO:systemctl:simple start '/usr/local/share/health_monitor/ros_wrapper.sh' 'roscore'
DEBUG:systemctl:writing to /run/roscore.service.status
	MainPID=629
INFO:systemctl:simple started PID 629
jtcx@ganlu-XPS-15-9560:/var/log$ cat /var/log/systemctl.debug.log 
2022-02-26 02:40:21,471 INFO EXEC BEGIN /usr/bin/systemctl status roscore --system
2022-02-26 02:40:21,472 DEBUG ======= systemctl.py status roscore
2022-02-26 02:40:21,474 DEBUG found 197 sysd files
2022-02-26 02:40:21,475 DEBUG found 7 sysv files
2022-02-26 02:40:47,077 INFO EXEC BEGIN /usr/bin/systemctl start roscore --system
2022-02-26 02:40:47,077 DEBUG ======= systemctl.py start roscore
2022-02-26 02:40:47,079 DEBUG found 197 sysd files
2022-02-26 02:40:47,080 DEBUG found 7 sysv files
2022-02-26 02:40:47,581 INFO system is offline
2022-02-26 02:40:47,583 DEBUG '/etc/systemd/system/roscore.service' no --user mode >> accept
2022-02-26 02:40:47,584 DEBUG  start unit roscore.service => '/etc/systemd/system/roscore.service'
2022-02-26 02:40:47,584 DEBUG extra-vars []
2022-02-26 02:40:47,586 INFO  pre-start '/bin/systemctl' 'is-active' 'network-online.target'
2022-02-26 02:40:47,587 DEBUG setgid 1000 for user 'jtcx'
2022-02-26 02:40:47,588 DEBUG setgroups [27] > ['sudo'] 
2022-02-26 02:40:47,588 DEBUG setuid 1000 for user 'jtcx'
2022-02-26 02:40:47,667 DEBUG  pre-start done (OK) <->
2022-02-26 02:40:47,667 DEBUG ExecStart[0]: /usr/local/share/health_monitor/ros_wrapper.sh roscore
2022-02-26 02:40:47,668 INFO simple start '/usr/local/share/health_monitor/ros_wrapper.sh' 'roscore'
2022-02-26 02:40:47,668 DEBUG writing to /run/roscore.service.status
	MainPID=629
2022-02-26 02:40:47,669 INFO simple started PID 629
2022-02-26 02:40:47,669 DEBUG setgid 1000 for user 'jtcx'
2022-02-26 02:40:47,669 DEBUG setgroups [27] > ['sudo'] 
2022-02-26 02:40:47,669 DEBUG setuid 1000 for user 'jtcx'
jtcx@ganlu-XPS-15-9560:/var/log$ sudo systemctl status roscore
INFO:systemctl:EXEC BEGIN /usr/bin/systemctl status roscore --system
DEBUG:systemctl:======= systemctl.py status roscore
DEBUG:systemctl:found 197 sysd files
DEBUG:systemctl:found 7 sysv files
roscore.service - roscore launcher
    Loaded: loaded (/etc/systemd/system/roscore.service, enabled)
    Active: active (running)
jtcx@ganlu-XPS-15-9560:/var/log$ rosnode list
/rosout
jtcx@ganlu-XPS-15-9560:/var/log$ sudo systemctl start control_master
INFO:systemctl:EXEC BEGIN /usr/bin/systemctl start control_master --system
DEBUG:systemctl:======= systemctl.py start control_master
DEBUG:systemctl:found 197 sysd files
DEBUG:systemctl:found 7 sysv files
INFO:systemctl:system is offline
DEBUG:systemctl:'/etc/systemd/system/control_master.service' no --user mode >> accept
DEBUG:systemctl: start unit control_master.service => '/etc/systemd/system/control_master.service'
DEBUG:systemctl:extra-vars []
INFO:systemctl: pre-start '/bin/systemctl' 'is-active' 'roscore'
DEBUG:systemctl: pre-start done (3) <->
ERROR:systemctl:the ExecStartPre control process exited with error code
DEBUG:systemctl:writing to /run/control_master.service.status
	ActiveState=failed
jtcx@ganlu-XPS-15-9560:/var/log$ cat /var/log/systemctl.debug.log 
2022-02-26 02:40:21,471 INFO EXEC BEGIN /usr/bin/systemctl status roscore --system
2022-02-26 02:40:21,472 DEBUG ======= systemctl.py status roscore
2022-02-26 02:40:21,474 DEBUG found 197 sysd files
2022-02-26 02:40:21,475 DEBUG found 7 sysv files
2022-02-26 02:40:47,077 INFO EXEC BEGIN /usr/bin/systemctl start roscore --system
2022-02-26 02:40:47,077 DEBUG ======= systemctl.py start roscore
2022-02-26 02:40:47,079 DEBUG found 197 sysd files
2022-02-26 02:40:47,080 DEBUG found 7 sysv files
2022-02-26 02:40:47,581 INFO system is offline
2022-02-26 02:40:47,583 DEBUG '/etc/systemd/system/roscore.service' no --user mode >> accept
2022-02-26 02:40:47,584 DEBUG  start unit roscore.service => '/etc/systemd/system/roscore.service'
2022-02-26 02:40:47,584 DEBUG extra-vars []
2022-02-26 02:40:47,586 INFO  pre-start '/bin/systemctl' 'is-active' 'network-online.target'
2022-02-26 02:40:47,587 DEBUG setgid 1000 for user 'jtcx'
2022-02-26 02:40:47,588 DEBUG setgroups [27] > ['sudo'] 
2022-02-26 02:40:47,588 DEBUG setuid 1000 for user 'jtcx'
2022-02-26 02:40:47,667 DEBUG  pre-start done (OK) <->
2022-02-26 02:40:47,667 DEBUG ExecStart[0]: /usr/local/share/health_monitor/ros_wrapper.sh roscore
2022-02-26 02:40:47,668 INFO simple start '/usr/local/share/health_monitor/ros_wrapper.sh' 'roscore'
2022-02-26 02:40:47,668 DEBUG writing to /run/roscore.service.status
	MainPID=629
2022-02-26 02:40:47,669 INFO simple started PID 629
2022-02-26 02:40:47,669 DEBUG setgid 1000 for user 'jtcx'
2022-02-26 02:40:47,669 DEBUG setgroups [27] > ['sudo'] 
2022-02-26 02:40:47,669 DEBUG setuid 1000 for user 'jtcx'
2022-02-26 02:41:35,651 INFO EXEC BEGIN /usr/bin/systemctl status roscore --system
2022-02-26 02:41:35,651 DEBUG ======= systemctl.py status roscore
2022-02-26 02:41:35,654 DEBUG found 197 sysd files
2022-02-26 02:41:35,655 DEBUG found 7 sysv files
2022-02-26 02:41:57,169 INFO EXEC BEGIN /usr/bin/systemctl start control_master --system
2022-02-26 02:41:57,169 DEBUG ======= systemctl.py start control_master
2022-02-26 02:41:57,172 DEBUG found 197 sysd files
2022-02-26 02:41:57,172 DEBUG found 7 sysv files
2022-02-26 02:41:57,674 INFO system is offline
2022-02-26 02:41:57,676 DEBUG '/etc/systemd/system/control_master.service' no --user mode >> accept
2022-02-26 02:41:57,676 DEBUG  start unit control_master.service => '/etc/systemd/system/control_master.service'
2022-02-26 02:41:57,677 DEBUG extra-vars []
2022-02-26 02:41:57,678 INFO  pre-start '/bin/systemctl' 'is-active' 'roscore'
2022-02-26 02:41:57,680 DEBUG setgid 1000 for user 'jtcx'
2022-02-26 02:41:57,680 DEBUG setgroups [27] > ['sudo'] 
2022-02-26 02:41:57,680 DEBUG setuid 1000 for user 'jtcx'
2022-02-26 02:41:57,759 DEBUG  pre-start done (3) <->
2022-02-26 02:41:57,759 ERROR the ExecStartPre control process exited with error code
2022-02-26 02:41:57,759 DEBUG writing to /run/control_master.service.status
	ActiveState=failed
jtcx@ganlu-XPS-15-9560:/var/log$ 

@gdraheim
Copy link
Owner

I wonder why "systemctl status roscore" says "active" but "systemctl is-active roscore" may return inactive. You did run "is-active" manually.

Automatic start is documented - enable services are run when systemctl is on PID 1 through CMD.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants