systemdの”Start request repeated too quickly.”エラー対処

Wake On LANの設定をUbuntu起動時に自動で行うように設定をしています。

https://tarufu.info/tarufu.info/ubuntu-wake-on-lan/

この設定がうまくいかなくて少しハマったので対処しました。

環境
起こっている事象とその対処
1. ステータス確認
2. Start request repeated too quickly. の対処
再起動してみたらWOLが有効にならなかった
1. 対処

環境

Ubuntu 20.04.2 LTS

cat /etc/os-release 
NAME="Ubuntu"
VERSION="20.04.2 LTS (Focal Fossa)"
ID=ubuntu
ID_LIKE=debian
PRETTY_NAME="Ubuntu 20.04.2 LTS"
VERSION_ID="20.04"
HOME_URL="https://www.ubuntu.com/"
SUPPORT_URL="https://help.ubuntu.com/"
BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
VERSION_CODENAME=focal
UBUNTU_CODENAME=focal

端末：Aspire XC-603ベースの自作PC

パーツを集めてパソコンを組み立てる(自作PC?)
のブログではパソコンの分解をいくつか扱ってきました。分解して掃除して組み立てて、、、ということをやっていますが、今回はパソコンを組み立ててみました。パーツがいくつか余っていたので、不足したものだけ買い...
tarufu.info

起こっている事象とその対処

systemdに登録しているWake On LAN設定のサービス（/etc/systemd/system/wolg.service）が成功しない。

Ubuntu起動後にWake-onのステータスが”d”のままになっている。

$ sudo ethtool enp2s0 | grep -i wake
        Supports Wake-on: pumbg
        Wake-on: d

ステータス確認

systemctlでステータスを確認してみます。

$ sudo systemctl status wolg.service
● wolg.service - Enable Wake-On-Lan
     Loaded: loaded (/etc/systemd/system/wolg.service; enabled; vendor preset: enabled)
     Active: failed (Result: start-limit-hit) since Wed 2021-04-07 22:20:12 JST; 1min 3s ago
    Process: 845 ExecStart=/home/wolg (code=exited, status=0/SUCCESS)
   Main PID: 845 (code=exited, status=0/SUCCESS)

 4月 07 22:20:12 XXXXX systemd[1]: wolg.service: Scheduled restart job, restart counter is at 5.
 4月 07 22:20:12 XXXXX systemd[1]: Stopped Enable Wake-On-Lan.
 4月 07 22:20:12 XXXXX systemd[1]: wolg.service: Start request repeated too quickly.
 4月 07 22:20:12 XXXXX systemd[1]: wolg.service: Failed with result 'start-limit-hit'.
 4月 07 22:20:12 XXXXX systemd[1]: Failed to start Enable Wake-On-Lan.

なにやらメッセージが出ていました。

wolg.service: Start request repeated too quickly.

リクエスト（Wake On LAN設定のスクリプト）を高速で繰り返そうとしたため停止したみたいです。

Start request repeated too quickly. の対処

systemdに登録した/etc/systemd/system/wolg.service の記述を見直ししてみます。

# 修正前
$ cat /etc/systemd/system/wolg.service 
[Unit]
Description=Enable Wake-On-Lan
 
[Service]
Type=simple
ExecStart=/home/wolg
Restart=always
User=root
 
[Install]
WantedBy=multi-user.target

[Service]のRestart=alwaysが原因のようです。

WOLの設定プログラムは1回成功すればいいので、alwaysをnoに変更しました。

# 修正後
$ cat /etc/systemd/system/wolg.service
[Unit]
Description=Enable Wake-On-Lan
 
[Service]
Type=simple
ExecStart=/home/wolg
Restart=no
User=root
 
[Install]
WantedBy=multi-user.target

修正後、リロードしてスタートするとうまくいきました。

$ sudo systemctl daemon-reload 
$ sudo systemctl start wolg.service

sudo ethtool enp2s0 | grep -i wake
        Supports Wake-on: pumbg
        Wake-on: g

Restartの値について、以下のサイトが分かりやすかったです。
私は今回”no”を使用しましたが、他にもいくつかあるみたいです。

systemdでプロセス自動再起動

systemctl start でサービス起動したのに、OOM killer などによってプロセスが殺されたりすることは往々にあると思いますが、プロセスの死活監視をしてないと対策が遅れてしまうことがあ...

再起動してみたらWOLが有効にならなかった

再起動しても大丈夫か確認するため、Wake-onを”d”にしてからrebootしてみたら想定通りになっていませんでした。

ステータスを確認してみましたが、エラーは出ていませんでした。

$ sudo systemctl status wolg.service
● wolg.service - Enable Wake-On-Lan
     Loaded: loaded (/etc/systemd/system/wolg.service; enabled; vendor preset: enabled)
     Active: inactive (dead) since Wed 2021-04-07 22:26:29 JST; 40s ago
    Process: 785 ExecStart=/home/wolg (code=exited, status=0/SUCCESS)
   Main PID: 785 (code=exited, status=0/SUCCESS)

 4月 07 22:26:29 XXXXX wolg[785]: # ログ設定
 4月 07 22:26:29 XXXXX wolg[785]: echo   "/home/LOG/LOG.$(basename $0).$(date +%Y%m%d%H%M%S)" &> /dev/null
 4月 07 22:26:29 XXXXX wolg[796]: ++ basename /home/wolg
 4月 07 22:26:29 XXXXX wolg[801]: ++ date +%Y%m%d%H%M%S
 4月 07 22:26:29 XXXXX wolg[785]: + echo /home/LOG/LOG.wolg.20210407222629
 4月 07 22:26:29 XXXXX wolg[785]: exec 2> /home/LOG/LOG.$(basename $0).$(date +%Y%m%d%H%M%S)
 4月 07 22:26:29 XXXXX wolg[785]: + exec
 4月 07 22:26:29 XXXXX wolg[802]: ++ basename /home/wolg
 4月 07 22:26:29 XXXXX wolg[803]: ++ date +%Y%m%d%H%M%S
 4月 07 22:26:29 XXXXX systemd[1]: wolg.service: Succeeded.

対処

dmesgを見ててたまたま気が付いたのですが、イーサネットアダプタのリネームとリンクアップに若干時間がかかっていることが分かりました。

 dmesg | grep r8
[    0.047192] percpu: Embedded 56 pages/cpu s192512 r8192 d28672 u524288
[    0.047211] pcpu-alloc: s192512 r8192 d28672 u524288 alloc=1*2097152
[    2.061903] r8168: loading out-of-tree module taints kernel.
[    2.062323] r8168: module verification failed: signature and/or required key missing - tainting kernel
[    2.063305] r8168 Gigabit Ethernet driver 8.048.00-NAPI loaded
[    2.077854] r8168: This product is covered by one or more of the following patents: US6,570,884, US6,115,776, and US6,327,625.
[    2.079921] r8168  Copyright (C) 2019  Realtek NIC software team <nicfae@realtek.com> 
[    2.150406] r8168 0000:02:00.0 enp2s0: renamed from eth0
[   42.440675] r8168: enp2s0: link up

もしかするとイーサネットアダプタのリネームより、設定スクリプトのほうが先に起動してるのかな～と思い、起動スクリプトにsleepで20秒の待機時間を設定してみました。

$ cat /home/wolg
#!/bin/bash -xv

# ログ設定
echo   "/home/LOG/LOG.$(basename $0).$(date +%Y%m%d%H%M%S)" &> /dev/null
exec 2> /home/LOG/LOG.$(basename $0).$(date +%Y%m%d%H%M%S)

sleep 20　←20秒待たせる

ethtool -s enp2s0 wol g

exit

この設定を行って再起動したら想定通り、Wake-onが”g”になりました。

でも実際のところサービス起動とイーサネットのリネームの時間をしっかり確認してないので、今度確認してみようと思います。

今日はもう眠いので。。。