再起動が異常終了する原因は何ですか?

再起動が異常終了する原因は何ですか?

私の質問

異常終了の再開/終了ログはどこにありますか?

私の状況

redhat 7.9 (3.10.0-1160.62.1.el7.x86_64)アップグレードされたバージョンでは、redhat 6簡単なsudo reboot原因でVMがクラッシュしました。以下のログでは、2つの連続したSYSTEM_BOOTが原因で異常終了したために発生したことを確認できます。

[root@rsvsiesigmprd02 wasadmin]# ausearch -i -m system_boot,system_shutdown | tail -7
type=SYSTEM_BOOT msg=audit(11/07/2022 06:18:15.281:6) : pid=765 uid=root auid=unset ses=unset subj=system_u:system_r:init_t:s0 msg=' comm=systemd-update-utmp exe=/usr/lib/systemd/systemd-update-utmp hostname=? addr=? terminal=? res=success'
----
type=SYSTEM_SHUTDOWN msg=audit(15/07/2022 03:12:06.064:5192) : pid=10697 uid=root auid=unset ses=unset subj=system_u:system_r:init_t:s0 msg=' comm=systemd-update-utmp exe=/usr/lib/systemd/systemd-update-utmp hostname=? addr=? terminal=? res=success'
----
type=SYSTEM_BOOT msg=audit(15/07/2022 08:38:48.151:6) : pid=767 uid=root auid=unset ses=unset subj=system_u:system_r:init_t:s0 msg=' comm=systemd-update-utmp exe=/usr/lib/systemd/systemd-update-utmp hostname=? addr=? terminal=? res=success'
----
type=SYSTEM_BOOT msg=audit(18/07/2022 06:17:40.034:6) : pid=767 uid=root auid=unset ses=unset subj=system_u:system_r:init_t:s0 msg=' comm=systemd-update-utmp exe=/usr/lib/systemd/systemd-update-utmp hostname=? addr=? terminal=? res=success'

また、SSHを介してVMにアクセスできず、最後の手段はVMWareを介して再起動してハードシャットダウンを実行することでした。

ログにこの問題を引き起こしているものが見つかりません。私は次のことを確認しました:

    1. /var/log/メッセージ
    1. ログ制御

1. /var/log/messages

Jul 15 03:01:31 xxxxxxxxxx systemd: Started Session 722 of user ansible.
Jul 15 03:01:34 xxxxxxxxxx python: ansible-ansible.legacy.setup Invoked with filter=[] gather_subset=['all'] fact_path=/etc/ansible/facts.d gather_timeout=10
Jul 15 03:01:43 xxxxxxxxxx python: ansible-ansible.legacy.command Invoked with creates=None executable=None _uses_shell=False strip_empty_ends=True _raw_params=/usr/bin/package-cleanup -y --oldkernels --count=2 removes=None argv=None warn=False chdir=None stdin_add_newline=True stdin=None
Jul 15 03:01:53 xxxxxxxxxx python: ansible-ansible.legacy.yum Invoked with lock_timeout=30 update_cache=False conf_file=None exclude=[] allow_downgrade=False disable_gpg_check=False disable_excludes=None use_backend=auto state=latest disablerepo=[] skip_broken=False releasever=None autoremove=False download_dir=None enable_plugin=[] installroot=/ install_weak_deps=True name=['*'] download_only=False bugfix=False list=None install_repoquery=True update_only=False disable_plugin=[] enablerepo=[] security=True validate_certs=True
Jul 15 03:05:03 xxxxxxxxxx systemd-logind: New session 723 of user wasadmin.
Jul 15 03:05:03 xxxxxxxxxx systemd: Started Session 723 of user wasadmin.
Jul 15 03:05:04 xxxxxxxxxx systemd-logind: Removed session 723.
Jul 15 03:07:54 xxxxxxxxxx python: ansible-ansible.legacy.setup Invoked with filter=[] gather_subset=['all'] fact_path=/etc/ansible/facts.d gather_timeout=10
Jul 15 03:08:04 xxxxxxxxxx python: ansible-ansible.legacy.command Invoked with creates=None executable=None _uses_shell=False strip_empty_ends=True _raw_params=/sbin/shutdown -r +1 removes=None argv=None warn=False chdir=None stdin_add_newline=True stdin=None
Jul 15 03:08:04 xxxxxxxxxx systemd: Started Delayed Shutdown Service.
Jul 15 03:08:04 xxxxxxxxxx systemd-shutdownd: Shutting down at Fri 2022-07-15 03:09:04 CEST (reboot)...
Jul 15 03:08:04 xxxxxxxxxx systemd-shutdownd: Creating /run/nologin, blocking further logins...
Jul 15 03:09:04 xxxxxxxxxx systemd: Stopping Session 721 of user root.
Jul 15 03:09:04 xxxxxxxxxx systemd: Stopping NFS status monitor for NFSv2/3 locking....
Jul 15 03:09:04 xxxxxxxxxx systemd: Unmounting /opt/maximo/data...
Jul 15 03:09:04 xxxxxxxxxx systemd: Removed slice system-selinux\x2dpolicy\x2dmigrate\x2dlocal\x2dchanges.slice.
Jul 15 03:09:04 xxxxxxxxxx systemd: Unmounting /opt/maximo/sedif...
Jul 15 03:09:04 xxxxxxxxxx systemd: Stopped Dump dmesg to /var/log/dmesg.
Jul 15 03:09:04 xxxxxxxxxx systemd: Unmounting /opt/maximo/agora...
Jul 15 03:09:04 xxxxxxxxxx systemd: Stopping RPC bind service...
Jul 15 03:09:04 xxxxxxxxxx systemd: Stopped target RPC Port Mapper.
Jul 15 03:09:04 xxxxxxxxxx systemd: Stopping Session c2 of user wasadmin.
Jul 15 03:09:04 xxxxxxxxxx systemd: Stopped target rpc_pipefs.target.
Jul 15 03:09:04 xxxxxxxxxx systemd: Stopping Session 722 of user ansible.
Jul 15 03:09:04 xxxxxxxxxx systemd: Stopped target Timers.
Jul 15 03:09:04 xxxxxxxxxx systemd: Stopped Daily Cleanup of Temporary Directories.
Jul 15 03:09:04 xxxxxxxxxx systemd: Closed LVM2 poll daemon socket.
Jul 15 03:09:04 xxxxxxxxxx systemd: Stopping Session 2 of user wasadmin.
Jul 15 03:09:04 xxxxxxxxxx systemd: Stopped target Multi-User System.
Jul 15 03:09:04 xxxxxxxxxx systemd: Stopping LSB: Starts and stops WebSphere Application Server instances...
Jul 15 03:09:04 xxxxxxxxxx umount: umount.nfs: /opt/maximo/data: device is busy
Jul 15 03:09:04 xxxxxxxxxx journal: IBM Java[2311]: JVMDUMP039I Traitement de l'événement de vidage "user", détails "" à 2022/07/15 03:09:04 - Veuillez patienter.
Jul 15 03:09:04 xxxxxxxxxx systemd: Stopping LSB: Starts the Spacewalk Daemon...
Jul 15 03:09:04 xxxxxxxxxx journal: IBM Java[2311]: JVMDUMP032I La machine virtuelle Java a demandé un vidage Java en utilisant '/opt/dump/javacore.20220715.030904.2311.0001.txt' en réponse à un événement
Jul 15 03:09:04 xxxxxxxxxx systemd: Stopping Command Scheduler...
Jul 15 03:09:04 xxxxxxxxxx systemd: Stopped target Login Prompts.
Jul 15 03:09:04 xxxxxxxxxx systemd: Stopping Getty on tty1...
Jul 15 03:09:04 xxxxxxxxxx journal: IBM Java[3796]: JVMDUMP039I Traitement de l'événement de vidage "user", détails "" à 2022/07/15 03:09:04 - Veuillez patienter.
Jul 15 03:09:04 xxxxxxxxxx journal: IBM Java[2310]: JVMDUMP039I Traitement de l'événement de vidage "user", détails "" à 2022/07/15 03:09:04 - Veuillez patienter.
Jul 15 03:09:04 xxxxxxxxxx journal: IBM Java[3220]: JVMDUMP039I Traitement de l'événement de vidage "user", détails "" à 2022/07/15 03:09:04 - Veuillez patienter.
Jul 15 03:09:04 xxxxxxxxxx RSVSIESIGMPRD01ManagerNode_was.init: Stopping WebSphere Application Server - dmgr ...
Jul 15 03:09:04 xxxxxxxxxx journal: IBM Java[3796]: JVMDUMP032I La machine virtuelle Java a demandé un vidage Java en utilisant '/opt/IBM/WebSphere/AppServer/profiles/AppSrvUI01/javacore.20220715.030904.3796.0001.txt' en réponse à un événement
Jul 15 03:09:04 xxxxxxxxxx journal: IBM Java[3220]: JVMDUMP032I La machine virtuelle Java a demandé un vidage Java en utilisant '/opt/IBM/WebSphere/AppServer/profiles/dmgr/javacore.20220715.030904.3220.0001.txt' en réponse à un événement
Jul 15 03:09:04 xxxxxxxxxx journal: IBM Java[2310]: JVMDUMP032I La machine virtuelle Java a demandé un vidage Java en utilisant '/opt/dump/javacore.20220715.030904.2310.0001.txt' en réponse à un événement
Jul 15 03:09:04 xxxxxxxxxx systemd: Stopping LSB: Starts and stops IHS...
Jul 15 03:09:04 xxxxxxxxxx systemd: Stopping ACPI Event Daemon...
Jul 15 03:09:04 xxxxxxxxxx systemd: Stopped Resets System Activity Logs.
Jul 15 03:09:04 xxxxxxxxxx systemd: Stopping Zabbix Agent...
Jul 15 03:09:04 xxxxxxxxxx systemd: Stopping System Logging Service...
Jul 15 08:38:30 xxxxxxxxxx kernel: Initializing cgroup subsys cpuset
Jul 15 08:38:30 xxxxxxxxxx kernel: Initializing cgroup subsys cpu
Jul 15 08:38:30 xxxxxxxxxx kernel: Initializing cgroup subsys cpuacct
Jul 15 08:38:30 xxxxxxxxxx kernel: Linux version 3.10.0-1160.62.1.el7.x86_64 ([email protected]) (gcc version 4.8.5 20150623 (Red Hat 4.8.5-44) (GCC) ) #1 SMP Wed Mar 23 09:04:02 UTC 2022
Jul 15 08:38:30 xxxxxxxxxx kernel: Command line: root=/dev/mapper/vg_main-lv_root ro rd.luks=0 rd.lvm.lv=vg_main/lv_swap rd.md=0 rd.locale.LANG=fr_FR.UTF-8 vconsole.font=latarcyrheb-sun16 KEYBOARDTYPE=pc vconsole.keymap=fr-latin9 crashkernel=auto rd.lvm.lv=vg_main/lv_root rd.dm=0 rhgb quiet LANG=fr_FR.UTF-8
Jul 15 08:38:30 xxxxxxxxxx kernel: Disabled fast string operations
Jul 15 08:38:30 xxxxxxxxxx kernel: e820: BIOS-provided physical RAM map:
Jul 15 08:38:30 xxxxxxxxxx kernel: BIOS-e820: [mem 0x0000000000000000-0x000000000009f7ff] usable
Jul 15 08:38:30 xxxxxxxxxx kernel: BIOS-e820: [mem 0x000000000009f800-0x000000000009ffff] reserved
Jul 15 08:38:30 xxxxxxxxxx kernel: BIOS-e820: [mem 0x00000000000dc000-0x00000000000fffff] reserved
Jul 15 08:38:30 xxxxxxxxxx kernel: BIOS-e820: [mem 0x0000000000100000-0x00000000bfedffff] usable
Jul 15 08:38:30 xxxxxxxxxx kernel: BIOS-e820: [mem 0x00000000bfee0000-0x00000000bfefefff] ACPI data
Jul 15 08:38:30 xxxxxxxxxx kernel: BIOS-e820: [mem 0x00000000bfeff000-0x00000000bfefffff] ACPI NVS
Jul 15 08:38:30 xxxxxxxxxx kernel: BIOS-e820: [mem 0x00000000bff00000-0x00000000bfffffff] usable
Jul 15 08:38:30 xxxxxxxxxx kernel: BIOS-e820: [mem 0x00000000f0000000-0x00000000f7ffffff] reserved
Jul 15 08:38:30 xxxxxxxxxx kernel: BIOS-e820: [mem 0x00000000fec00000-0x00000000fec0ffff] reserved
Jul 15 08:38:30 xxxxxxxxxx kernel: BIOS-e820: [mem 0x00000000fee00000-0x00000000fee00fff] reserved
Jul 15 08:38:30 xxxxxxxxxx kernel: BIOS-e820: [mem 0x00000000fffe0000-0x00000000ffffffff] reserved
Jul 15 08:38:30 xxxxxxxxxx kernel: BIOS-e820: [mem 0x0000000100000000-0x000000063fffffff] usable
Jul 15 08:38:30 xxxxxxxxxx kernel: NX (Execute Disable) protection: active
Jul 15 08:38:30 xxxxxxxxxx kernel: SMBIOS 2.4 present.
Jul 15 08:38:30 xxxxxxxxxx kernel: DMI: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 12/12/2018
Jul 15 08:38:30 xxxxxxxxxx kernel: Hypervisor detected: VMware
Jul 15 08:38:30 xxxxxxxxxx kernel: vmware: TSC freq read from hypervisor : 2893.203 MHz
Jul 15 08:38:30 xxxxxxxxxx kernel: vmware: Host bus clock speed read from hypervisor : 66000000 Hz
Jul 15 08:38:30 xxxxxxxxxx kernel: vmware: using sched offset of 7222055233 ns
Jul 15 08:38:30 xxxxxxxxxx kernel: e820: last_pfn = 0x640000 max_arch_pfn = 0x400000000
Jul 15 08:38:30 xxxxxxxxxx kernel: PAT configuration [0-7]: WB  WC  UC- UC  WB  WP  UC- UC
Jul 15 08:38:30 xxxxxxxxxx kernel: total RAM covered: 31744M

==> ご覧のとおり、システムは3時から8時までダウンしています。

注:これを実行すると再起動sudo reboot -fが成功しました。

ありがとうございます。

ベストアンサー1

読みやすくするために、ログ行がラップされます。

Jul 15 03:08:04 xxxxxxxxxx python: ansible-ansible.legacy.command Invoked with creates=None \
    executable=None _uses_shell=False strip_empty_ends=True _raw_params=/sbin/shutdown -r +1 \
    removes=None argv=None warn=False chdir=None stdin_add_newline=True stdin=None

shutdown -r +1誰かまたは何かがAnsibleを使用して電話をかけているようです。

閉じる前の最後のメッセージは次のとおりです。

Jul 15 03:09:04 xxxxxxxxxx systemd: Stopping LSB: Starts and stops IHS...
Jul 15 03:09:04 xxxxxxxxxx systemd: Stopping ACPI Event Daemon...
Jul 15 03:09:04 xxxxxxxxxx systemd: Stopped Resets System Activity Logs.
Jul 15 03:09:04 xxxxxxxxxx systemd: Stopping Zabbix Agent...
Jul 15 03:09:04 xxxxxxxxxx systemd: Stopping System Logging Service...

...これは、制御された閉鎖によって多くの進展が行われたことを意味します。 syslogサービスが停止した後、再起動されるまでログエントリはありません/var/log/messages。永続システムロギングを有効にすると(ディレクトリを作成して/var/log/journal)、終了する前により多くのエントリを表示できますjournalctl

ジョブを終了する前にAnsibleジョブが実行されているようですyum

Jul 15 03:01:53 xxxxxxxxxx python: ansible-ansible.legacy.yum Invoked with lock_timeout=30 \
    update_cache=False conf_file=None exclude=[] allow_downgrade=False disable_gpg_check=False \
    disable_excludes=None use_backend=auto state=latest disablerepo=[] skip_broken=False \
    releasever=None autoremove=False download_dir=None enable_plugin=[] installroot=/ \
    install_weak_deps=True name=['*'] download_only=False bugfix=False list=None \
    install_repoquery=True update_only=False disable_plugin=[] enablerepo=[] security=True \
    validate_certs=True

yumこれがカーネルアップデートをインポートしたことを確認し、そうであればinitramfsの作成が成功したことを確認することをお勧めします。私は以前RHEL 7.xでinitramfsの生成が失敗した状況を見たことがあると思います。たとえば、yumパッケージキャッシュが原因でファイルシステムがいっぱいになり、新しいカーネルで起動できないためです。時には、ファイルシステムをルートとしてマウントする前に失敗します。読み書きモードにありました。これは明らかに、この起動試行についてログが記録されないことを意味します。

これはVMware仮想マシンであるため、ハイパーバイザー(および/または可能であればvSphere管理)ログは、システムのクラッシュ後に発生した状況を詳細に説明できます。おそらく、予定されたハイパーバイザーサービスの中断があり、VMware管理者は中断するまでVMの起動を防ぎました。完了しましたか?

また、システムがオンラインになり、NTP時刻同期が有効になるまで、再起動直後に記録された時刻値を盲目的に信頼しません。混合Windows / Linux VMware環境では、VMware時間同期を無効にすることを忘れている可能性があります。環境がWindows仮想マシンによって支配されている場合、VMwareホストはローカル時間でシステムクロックを実行でき、仮想マシン仮想時計は起動時にデフォルトでその時間に設定されます。

この場合、NTP同期サービスが開始されると、サイトの現在のUTC / DSTオフセットとほぼ同じである可能性がある開始時の時間ジャンプが表示されます。後でブート後にタイムスタンプが7月15日08:3x:xxから約7月15日03:xx:xxにジャンプする場合、VMは仮想ハードウェア時計がUTCでWindows Aを実行していると誤って仮定するように構成されていますです。 UTC+4(+DST、北半球)またはUTC+5(DSTなし)タイムゾーンにあるVMware中心環境。

2022年7月15日08:38:48.151:6のシステム開始と2022年7月18日06:17:40.034:6の次の開始の間に異常終了が発生しました。あなたの/var/log/messages抜粋はその時間間隔をカバーしません。

異常終了によって発生した状況を特定するには、次の項目を見つける必要があります。2022年7月18日06:17:40より前の最後のログエントリ

もしあれば/var/log/messages7月15日08:38:30以降はログインできなくなります。その後、仮想マシンがハッキングされ(不慣れに)ルートキットされた可能性を考えます。これが事実であることが判明した場合、シャットダウン時にクラッシュが発生するのは、仮想マシンのルートキットおよび/または他のマルウェアの副作用である可能性がありますが、現時点では心配する必要が最も少なくなります。

おすすめ記事