Bug 1255098
| Summary: | ntpdate.service start failed after set NTP server on TUI | ||
|---|---|---|---|
| Product: | Red Hat Enterprise Virtualization Manager | Reporter: | Chaofeng Wu <cwu> |
| Component: | ovirt-node | Assignee: | Douglas Schilling Landgraf <dougsland> |
| Status: | CLOSED WONTFIX | QA Contact: | Virtualization Bugs <virt-bugs> |
| Severity: | high | Docs Contact: | |
| Priority: | medium | ||
| Version: | 3.5.4 | CC: | cshao, cwu, dougsland, ecohen, fdeutsch, gklein, huiwa, huzhao, lsurette, mgoldboi, yaniwang, ycui |
| Target Milestone: | --- | ||
| Target Release: | 3.5.6 | ||
| Hardware: | Unspecified | ||
| OS: | Unspecified | ||
| Whiteboard: | node | ||
| Fixed In Version: | ovirt-node-3.3.0-0.4.20150906git14a6024.el7ev | Doc Type: | Bug Fix |
| Doc Text: | Story Points: | --- | |
| Clone Of: | Environment: | ||
| Last Closed: | 2015-09-24 15:21:32 UTC | Type: | Bug |
| Regression: | --- | Mount Type: | --- |
| Documentation: | --- | CRM: | |
| Verified Versions: | Category: | --- | |
| oVirt Team: | Node | RHEL 7.3 requirements from Atomic Host: | |
| Cloudforms Team: | --- | Target Upstream Version: | |
| Embargoed: | |||
|
Description
Chaofeng Wu
2015-08-19 15:32:01 UTC
Hi Douglas,
Can reproduce this issue with the latest build(rhev-hypervisor7-7.1-20150827.1) follow the steps:
Steps to Reproduce:
1. Install rhev-hypervisor7-7.1-20150827.1, configure the network with dhcp mode.
2. Configure the NTP server with "clock.redhat.com", then save.
3. Drop into shell, check ntpdate.service status.
Actual results:
The ntpdate service status is failed.
Additional info:
After step1, configure SSH with root, login RHEV-H7.1 via SSH from another host, run the command:
[root@dhcp-8-172 ~]# systemctl status ntpdate.service
ntpdate.service - Set time via NTP
Loaded: loaded (/usr/lib/systemd/system/ntpdate.service; enabled)
Active: failed (Result: exit-code) since Wed 2015-09-02 06:01:31 UTC; 2min 25s ago
Process: 24614 ExecStart=/usr/libexec/ntpdate-wrapper (code=exited, status=1/FAILURE)
Main PID: 24614 (code=exited, status=1/FAILURE)
CGroup: /system.slice/ntpdate.service
Sep 02 06:01:31 dhcp-8-172.nay.redhat.com systemd[1]: ntpdate.service: main process exited, code=exited, status=1/FAILURE
Sep 02 06:01:31 dhcp-8-172.nay.redhat.com systemd[1]: Failed to start Set time via NTP.
Sep 02 06:01:31 dhcp-8-172.nay.redhat.com systemd[1]: Unit ntpdate.service entered failed state.
After step2，run the following command, we can find that the ntpdate.service has been restarted between the two steps, please notice the "Active" time:
[root@dhcp-8-172 ~]# systemctl status ntpdate.service
ntpdate.service - Set time via NTP
Loaded: loaded (/usr/lib/systemd/system/ntpdate.service; enabled)
Active: failed (Result: exit-code) since Wed 2015-09-02 06:05:48 UTC; 8s ago
Process: 24744 ExecStart=/usr/libexec/ntpdate-wrapper (code=exited, status=1/FAILURE)
Main PID: 24744 (code=exited, status=1/FAILURE)
CGroup: /system.slice/ntpdate.service
Sep 02 06:05:48 dhcp-8-172.nay.redhat.com systemd[1]: ntpdate.service: main process exited, code=exited, status=1/FAILURE
Sep 02 06:05:48 dhcp-8-172.nay.redhat.com systemd[1]: Failed to start Set time via NTP.
Sep 02 06:05:48 dhcp-8-172.nay.redhat.com systemd[1]: Unit ntpdate.service entered failed state.
Also we can find that ovirt-node try to start the ntpdate.service during ovirt-node TUI configure NTP server from the following commands:
[root@dhcp-8-172 tmp]# pstree -al
├─libvirtd --listen
│ └─10*[{libvirtd}]
├─login
│ └─ovirt-admin-she /usr/libexec/ovirt-admin-shell
│ └─sudo /usr/bin/ovirt-node-setup
│ └─ovirt-node-setu /usr/bin/ovirt-node-setup
│ └─python -m ovirt.node.setup.__main__
│ └─systemctl start ntpdate.service
│ └─systemd-tty-ask --watch
├─mcelog --ignorenodev --daemon --syslog
[root@dhcp-8-172 ~]# journalctl -f
Sep 02 06:05:04 dhcp-8-172.nay.redhat.com systemd[1]: Stopping Network Time Service...
Sep 02 06:05:04 dhcp-8-172.nay.redhat.com systemd-journal[7430]: Forwarding to syslog missed 2 messages.
Sep 02 06:05:04 dhcp-8-172.nay.redhat.com ntpd[24682]: ntpd exiting on signal 15
Sep 02 06:05:04 dhcp-8-172.nay.redhat.com systemd[1]: Stopped Network Time Service.
Sep 02 06:05:04 dhcp-8-172.nay.redhat.com systemd[1]: Starting Set time via NTP...
Sep 02 06:05:09 dhcp-8-172.nay.redhat.com ntpdate[24750]: no server suitable for synchronization found
Sep 02 06:05:24 dhcp-8-172.nay.redhat.com ntpdate[24752]: no server suitable for synchronization found
Sep 02 06:05:32 dhcp-8-172.nay.redhat.com python[1372]: Error in communication with subscription manager, trying to recover:
... ...
Sep 02 06:05:49 dhcp-8-172.nay.redhat.com ntpd[24767]: Listening on routing socket on fd #22 for interface updates
Sep 02 06:05:49 dhcp-8-172.nay.redhat.com ntpd[24767]: 0.0.0.0 c016 06 restart
Sep 02 06:05:49 dhcp-8-172.nay.redhat.com ntpd[24767]: 0.0.0.0 c012 02 freq_set kernel 0.000 PPM
Sep 02 06:05:49 dhcp-8-172.nay.redhat.com ntpd[24767]: 0.0.0.0 c011 01 freq_not_set
Sep 02 06:05:50 dhcp-8-172.nay.redhat.com ntpd[24767]: 0.0.0.0 c614 04 freq_mode
... ...
Hi Chaofeng Wu,
I was able to reproduce your report. Basically, it should not affect RHEV-H sync date with clock.redhat.com as we do the sync with ntpdate and ntpd.
Before we move forward with this bug, could you please confirm that RHEV-H has the clock correctly even with the ntpdate failure you mentioned?
Additionally to the above info, in 3.6 we disabled ntpdate service in favor of ntpd which adjusts the clock continuously instead of once as ntpdate does.
Thanks!
===== The failure you reported ========
# /bin/systemctl status ntpdate.service -l
ntpdate.service - Set time via NTP
Loaded: loaded (/usr/lib/systemd/system/ntpdate.service; enabled)
Active: failed (Result: exit-code) since Wed 2015-09-23 19:05:06 UTC; 121ms ago
Process: 18900 ExecStart=/usr/libexec/ntpdate-wrapper (code=exited, status=1/FAILURE)
Main PID: 18900 (code=exited, status=1/FAILURE)
Sep 23 19:04:36 localhost systemd[1]: Starting Set time via NTP...
Sep 23 19:05:06 localhost systemd[1]: ntpdate.service: main process exited, code=exited, status=1/FAILURE
Sep 23 19:05:06 localhost systemd[1]: Failed to start Set time via NTP.
Sep 23 19:05:06 localhost systemd[1]: Unit ntpdate.service entered failed state.
====== ntpd service OK=================
# /bin/systemctl status ntpd.service -l
ntpd.service - Network Time Service
Loaded: loaded (/usr/lib/systemd/system/ntpd.service; enabled)
Active: active (running) since Wed 2015-09-23 19:04:26 UTC; 44s ago
Process: 18896 ExecStart=/usr/sbin/ntpd -u ntp:ntp $OPTIONS (code=exited, status=0/SUCCESS)
Main PID: 18897 (ntpd)
CGroup: /system.slice/ntpd.service
└─18897 /usr/sbin/ntpd -u ntp:ntp -g
Sep 23 19:04:26 localhost ntpd[18897]: Listen normally on 3 ens3 192.168.122.186 UDP 123
Sep 23 19:04:26 localhost ntpd[18897]: Listen normally on 4 ens3 2000:aabb:ccdd:a:5054:ff:fe14:a335 UDP 123
Sep 23 19:04:26 localhost ntpd[18897]: Listen normally on 5 lo ::1 UDP 123
Sep 23 19:04:26 localhost ntpd[18897]: Listen normally on 6 ens3 fe80::5054:ff:fe14:a335 UDP 123
Sep 23 19:04:26 localhost ntpd[18897]: Listening on routing socket on fd #23 for interface updates
Sep 23 19:04:26 localhost systemd[1]: Started Network Time Service.
Sep 23 19:04:26 localhost ntpd[18897]: 0.0.0.0 c016 06 restart
Sep 23 19:04:26 localhost ntpd[18897]: 0.0.0.0 c012 02 freq_set kernel 0.000 PPM
Sep 23 19:04:26 localhost ntpd[18897]: 0.0.0.0 c011 01 freq_not_set
Sep 23 19:04:27 localhost ntpd[18897]: 0.0.0.0 c614 04 freq_mode
=========== Synced with ntpq ================
# ntpq -p
remote refid st t when poll reach delay offset jitter
==============================================================================
*clock.util.phx2 .CDMA. 1 u 48 64 1 78.751 -2.315 0.000
66.220.10.2 .INIT. 16 u - 64 0 0.000 0.000 0.000
=========== timedtectl output ==============
# timedatectl
Local time: Wed 2015-09-23 19:07:38 UTC
Universal time: Wed 2015-09-23 19:07:38 UTC
RTC time: Wed 2015-09-23 19:07:37
Timezone: UTC (UTC, +0000)
NTP enabled: yes
NTP synchronized: yes
RTC in local TZ: no
DST active: n/a
Hi Douglas, Confirmed that RHEV-H could sync clock correctly by ntpd when ntpdate service status is failed. Test steps: 1. Install rhev-hypervisor7-7.1-20150917.0.iso, configure the network with dhcp mode, reboot the system. 2. Login RHEV-H, press "F2" drop into shell, check ntpdate service and ntpd service status, then set incorrect time by command: [root@dhcp-10-87 admin]# date 010112002000 3. Configure the NTP server with "clock.redhat.com", then save. 4. Drop into shell, check ntpdate service, ntpd service status and time. Result: After step2: ---------------------------- ntpdate service status is failed, ntpd service status is active, and the incorrected time is: [root@dhcp-10-87 admin]# date Sat Jan 1 12:02:33 UTC 2000 After step4: ---------------------------- ntpdate service status is failed, ntpd service status is active, and the corrected time is: [root@dhcp-10-87 admin]# date Thu Sep 24 09:01:28 UTC 2015 Additional info: The time can be corrected by ntpd service, not by ntpdate service(status is failed), so the ntpdate service failure does not impact the clock sync to the NTP server. Hi Chaofeng Wu, Thanks for your feedback, as the ntpdate failure doesn't affect RHEV-H because ntpd service is up and working and ntpd is a replace for ntpdate I am going to close this report as WONTFIX. For future reference, ntpdate is a disabled service in 3.6 in favor of ntpd. Thanks! |