遅めのマシンでNFSの起動時マウントに失敗した話 » 履歴 » バージョン 2
  健二 酒井, 2019/12/08 18:04 
  
| 1 | 2 | # 遅めのマシンでNFSの起動時マウントに失敗した話  | 
|
|---|---|---|---|
| 2 | 2 | ||
| 3 | 2 | ## 概要  | 
|
| 4 | 2 | ||
| 5 | 2 | /etc/fstabの設定はあっている(mount -aしたら成功する)のに起動時にNFSのマウントに失敗したという話  | 
|
| 6 | 2 | ||
| 7 | 2 | ### 原因  | 
|
| 8 | 2 | ||
| 9 | 2 | ネットワークが立ち上がるのほうが後だった。  | 
|
| 10 | 2 | ||
| 11 | 2 | ### 対策  | 
|
| 12 | 2 | ||
| 13 | 2 | ネットワークの起動を待つサービスの待ち時間を長くする  | 
|
| 14 | 2 | ||
| 15 | 2 | ## 作業  | 
|
| 16 | 2 | ||
| 17 | 2 | とりあえずログでも見る  | 
|
| 18 | 2 | ||
| 19 | 2 | ```  | 
|
| 20 | 2 | ||
| 21 | 2 | # tac /var/log/messages | grep -ni nfs  | 
|
| 22 | 2 | 2819:Dec 7 23:21:30 ringo systemd: Unit mnt-nfs.mount entered failed state.  | 
|
| 23 | 2 | 2822:Dec 7 23:21:30 ringo systemd: Failed to mount /mnt/nfs.  | 
|
| 24 | 2 | 2823:Dec 7 23:21:30 ringo systemd: mnt-nfs.mount mount process exited, code=exited status=32  | 
|
| 25 | 2 | 2824:Dec 7 23:21:30 ringo mount: mount.nfs4: Network is unreachable  | 
|
| 26 | 2 | 2827:Dec 7 23:21:30 ringo kernel: NFS: Registering the id_resolver key type  | 
|
| 27 | 2 | 2829:Dec 7 23:21:30 ringo kernel: FS-Cache: Netfs 'nfs' registered for caching  | 
|
| 28 | 2 | 2834:Dec 7 23:21:30 ringo systemd: Started Notify NFS peers of a restart.  | 
|
| 29 | 2 | 2838:Dec 7 23:21:30 ringo systemd: Mounting /mnt/nfs...  | 
|
| 30 | 2 | 2845:Dec 7 23:21:30 ringo systemd: Starting Notify NFS peers of a restart...  | 
|
| 31 | 2 | ```  | 
|
| 32 | 2 | ||
| 33 | 2 | 2845行目付近を見ると  | 
|
| 34 | 2 | ||
| 35 | 2 | ```  | 
|
| 36 | 2 | # tac /var/log/messages | cat -n | head -n 3000 | tail -n 300  | 
|
| 37 | 2 | 2844 Dec 7 23:21:30 ringo systemd: Dependency failed for Remote File Systems.  | 
|
| 38 | 2 | 2845 Dec 7 23:21:30 ringo systemd: Failed to mount /mnt/nfs.  | 
|
| 39 | 2 | 2846 Dec 7 23:21:30 ringo systemd: mnt-nfs.mount mount process exited, code=exited status=32  | 
|
| 40 | 2 | 2847 Dec 7 23:21:30 ringo mount: mount.nfs4: Network is unreachable  | 
|
| 41 | 2 | 2848 Dec 7 23:21:30 ringo kernel: Key type id_legacy registered  | 
|
| 42 | 2 | 2849 Dec 7 23:21:30 ringo kernel: Key type id_resolver registered  | 
|
| 43 | 2 | 2850 Dec 7 23:21:30 ringo kernel: NFS: Registering the id_resolver key type  | 
|
| 44 | 2 | 2851 Dec 7 23:21:30 ringo kernel: Key type dns_resolver registered  | 
|
| 45 | 2 | 2852 Dec 7 23:21:30 ringo kernel: FS-Cache: Netfs 'nfs' registered for caching  | 
|
| 46 | 2 | 2853 Dec 7 23:21:30 ringo systemd: Started OpenSSH server daemon.  | 
|
| 47 | 2 | 2854 Dec 7 23:21:30 ringo kernel: FS-Cache: Loaded  | 
|
| 48 | 2 | 2855 Dec 7 23:21:30 ringo systemd: Started System Logging Service.  | 
|
| 49 | 2 | 2856 Dec 7 23:21:30 ringo rsyslogd: [origin software="rsyslogd" swVersion="8.24.0" x-pid="1053" x-info="http://www.rsyslog.com"] start  | 
|
| 50 | 2 | 2857 Dec 7 23:21:30 ringo systemd: Started Notify NFS peers of a restart.  | 
|
| 51 | 2 | 2858 Dec 7 23:21:30 ringo systemd: Starting Postfix Mail Transport Agent...  | 
|
| 52 | 2 | 2859 Dec 7 23:21:30 ringo systemd: Starting OpenSSH server daemon...  | 
|
| 53 | 2 | 2860 Dec 7 23:21:30 ringo systemd: Starting System Logging Service...  | 
|
| 54 | 2 | 2861 Dec 7 23:21:30 ringo systemd: Mounting /mnt/nfs...  | 
|
| 55 | 2 | ```  | 
|
| 56 | 2 | ||
| 57 | 2 | ネットワークに失敗してる…  | 
|
| 58 | 2 | ||
| 59 | 2 | ```  | 
|
| 60 | 2 | 2480 Dec 7 23:21:39 ringo NetworkManager[709]: <info> [1575728499.1356] device (enp1s0): Activation: successful, device activated.  | 
|
| 61 | 2 | 2481 Dec 7 23:21:39 ringo NetworkManager[709]: <info> [1575728499.1307] policy: set 'enp1s0' (enp1s0) as default for IPv4 routing and DNS  | 
|
| 62 | 2 | 2482 Dec 7 23:21:39 ringo NetworkManager[709]: <info> [1575728499.1304] manager: NetworkManager state is now CONNECTED_SITE  | 
|
| 63 | 2 | 2483 Dec 7 23:21:39 ringo dhclient[816]: bound to 192.168.0.20 -- renewal in 4294967295 seconds.  | 
|
| 64 | 2 | 2484 Dec 7 23:21:39 ringo NetworkManager[709]: <info> [1575728499.1209] manager: NetworkManager state is now CONNECTED_LOCAL  | 
|
| 65 | 2 | 2485 Dec 7 23:21:39 ringo NetworkManager[709]: <info> [1575728499.1202] device (enp1s0): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')  | 
|
| 66 | 2 | 2486 Dec 7 23:21:39 ringo NetworkManager[709]: <info> [1575728499.1191] device (enp1s0): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')  | 
|
| 67 | 2 | 2487 Dec 7 23:21:39 ringo NetworkManager[709]: <info> [1575728499.1161] device (enp1s0): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')  | 
|
| 68 | 2 | 2488 Dec 7 23:21:39 ringo NetworkManager[709]: <info> [1575728499.1090] dhcp4 (enp1s0): state changed unknown -> bound  | 
|
| 69 | 2 | 2489 Dec 7 23:21:39 ringo NetworkManager[709]: <info> [1575728499.1089] dhcp4 (enp1s0): domain name '**********'  | 
|
| 70 | 2 | 2490 Dec 7 23:21:39 ringo NetworkManager[709]: <info> [1575728499.1089] dhcp4 (enp1s0): nameserver '192.168.0.1'  | 
|
| 71 | 2 | 2491 Dec 7 23:21:39 ringo NetworkManager[709]: <info> [1575728499.1088] dhcp4 (enp1s0): lease time 4294967295  | 
|
| 72 | 2 | 2492 Dec 7 23:21:39 ringo NetworkManager[709]: <info> [1575728499.1087] dhcp4 (enp1s0): gateway 192.168.0.1  | 
|
| 73 | 2 | 2493 Dec 7 23:21:39 ringo NetworkManager[709]: <info> [1575728499.1086] dhcp4 (enp1s0): plen 24 (255.255.255.0)  | 
|
| 74 | 2 | 2494 Dec 7 23:21:39 ringo NetworkManager[709]: <info> [1575728499.1076] dhcp4 (enp1s0): address 192.168.0.20  | 
|
| 75 | 2 | 2495 Dec 7 23:21:39 ringo dhclient[816]: DHCPACK from 192.168.0.1 (xid=0x35f43909)  | 
|
| 76 | 2 | 2496 Dec 7 23:21:39 ringo dhclient[816]: DHCPOFFER from 192.168.0.1  | 
|
| 77 | 2 | ```  | 
|
| 78 | 2 | ||
| 79 | 2 | ネットワークデバイスの有効化のほうが後なのが原因っぽい。  | 
|
| 80 | 2 | 下記によるとネットワークの起動を待てばいいらしい。  | 
|
| 81 | 2 | ||
| 82 | 2 | > systemd-networkd で共有を自動マウント  | 
|
| 83 | 2 | >  | 
|
| 84 | 2 | > systemd-networkd を使っている場合、起動時に nfs がマウントされないことがあります。以下のようなエラーが表示されます:  | 
|
| 85 | 2 | >  | 
|
| 86 | 2 | >```  | 
|
| 87 | 2 | > mount[311]: mount.nfs4: Network is unreachable  | 
|
| 88 | 2 | >```  | 
|
| 89 | 2 | >  | 
|
| 90 | 2 | >解決方法は簡単です。systemd-networkd-wait-online.service を有効化して、ネットワークが完全に設定されるまで待機するように systemd を設定してください。サービスが平行して起動しなくなるので起動時間は多少長くなります。  | 
|
| 91 | 2 | ||
| 92 | 2 | 参考: https://wiki.archlinux.jp/index.php/NFS#systemd-networkd_.E3.81.A7.E5.85.B1.E6.9C.89.E3.82.92.E8.87.AA.E5.8B.95.E3.83.9E.E3.82.A6.E3.83.B3.E3.83.88  | 
|
| 93 | 2 | ||
| 94 | 2 | ||
| 95 | 2 | NetworkManager環境では「NetworkManager-wait-online.service」が該当するユニットだった。  | 
|
| 96 | 2 | さて、こいつを調べるとenabledだし、実行に失敗もしている。たぶん、これかなー。  | 
|
| 97 | 2 | ||
| 98 | 2 | > Fedora 29 のKVM仮想マシンで Failed to start Network Manager Wait Online. が発生する  | 
|
| 99 | 2 | >  | 
|
| 100 | 2 | > NetworkManager-wait-online サービスは、設定されているタイムアウト(–timeout=30 秒)を超えても NetworkManager の準備が完了していない場合にこのエラーを出力する。  | 
|
| 101 | 2 | ||
| 102 | 2 | 参考:https://www.tomoyan.net/linux/fedora_29_failed_to_start_network_manager_wait_online  | 
|
| 103 | 2 | ||
| 104 | 2 | あぁたぶんこれ。マシンの起動ちょっと時間かかるし。  | 
|
| 105 | 2 | 上記サイトの手順に従って設定していく  | 
|
| 106 | 2 | ||
| 107 | 2 | まず、  | 
|
| 108 | 2 | ||
| 109 | 2 | ```  | 
|
| 110 | 2 | # cp -p /usr/lib/systemd/system/NetworkManager-wait-online.service /etc/systemd/system/.  | 
|
| 111 | 2 | # vim /etc/systemd/system/NetworkManager-wait-online.service  | 
|
| 112 | 2 | ```  | 
|
| 113 | 2 | ||
| 114 | 2 | ExecStartの--timeoutオプションを30秒から120秒に変更してあげるとうまくいった。  | 
|
| 115 | 2 | ||
| 116 | 2 | おわり。  |