Master and slave Fuel nodes get the time in future during boot

[Dmitry Tyzhnenko]

CI report - http://jenkins-product.srt.mirantis.net:8080/job/6.1.ubuntu.smoke_neutron/28

api: '1.0'
astute_sha: ed5270bf9c6c1234797e00bd7d4dd3213253a413
auth_required: true
build_id: 2015-02-03_22-55-01
build_number: '96'
feature_groups:
- mirantis
fuellib_sha: 2147da0c583a7944f440ceb51236e7cb2e6610c9
fuelmain_sha: ''
nailgun_sha: 62dd62897850795fa35d2f359cf4f310d33f65c5
ostf_sha: c9100263140008abfcc2704732e98fbdfd644068
production: docker
python-fuelclient_sha: 2ea7b3e91c1d2ff85110bf5abb161a6f4e537358
release: '6.1'
release_versions:
  2014.2-6.1:
    VERSION:
      api: '1.0'
      astute_sha: ed5270bf9c6c1234797e00bd7d4dd3213253a413
      build_id: 2015-02-03_22-55-01
      build_number: '96'
      feature_groups:
      - mirantis
      fuellib_sha: 2147da0c583a7944f440ceb51236e7cb2e6610c9
      fuelmain_sha: ''
      nailgun_sha: 62dd62897850795fa35d2f359cf4f310d33f65c5
      ostf_sha: c9100263140008abfcc2704732e98fbdfd644068
      production: docker
      python-fuelclient_sha: 2ea7b3e91c1d2ff85110bf5abb161a6f4e537358
      release: '6.1'

Failed test - 'Deploy cluster in ha mode with 1 controller and Neutron GRE'

        Scenario:
            1. Create cluster
            2. Add 1 node with controller role
            3. Add 2 nodes with compute role
            4. Deploy the cluster
            5. Run network verification
            6. Run OSTF

Node-3 have wrong time.

# ./run_all 'date'
# On node-3
Sat Aug 22 15:19:24 UTC 2037
# On node-1
Wed Feb 4 10:50:49 UTC 2015
# On node-2
Wed Feb 4 10:50:50 UTC 2015

# ./run_all 'grep ntp /var/log/syslog'

# On node-3
Feb 4 08:57:11 node-3 kernel: [ 0.036013] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes)
Feb 4 08:57:13 node-3 sntp[901]: sntp 4.2.8p1-beta2@1.3265 Wed Jan 28 20:32:29 UTC 2015 (1)
Feb 4 08:57:13 node-3 sntp[901]: 1970-01-01 00:00:03.941222 (+0000) +711520114.369985 +/- 474346743.135084 10.108.135.2 s3
Aug 22 13:25:47 node-3 ntpd[924]: ntpd 4.2.8p1-beta2@1.3265 Wed Jan 28 20:32:44 UTC 2015 (1): Starting
Aug 22 13:25:47 node-3 ntpd[924]: Command line: /usr/bin/ntpd -p /var/run/ntpd.pid
Aug 22 13:25:47 node-3 ntpd[925]: proto: precision = 0.103 usec (-23)
Aug 22 13:25:47 node-3 ntpd[925]: unable to bind to wildcard address :: - another process may be running - EXITING
Aug 22 13:25:55 node-3 ntpdate[764]: step time server 10.108.135.2 offset -0.240989 sec

# On node-1
Feb 4 08:57:06 node-1 kernel: [ 0.036015] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes)
Feb 4 08:57:08 node-1 sntp[885]: sntp 4.2.8p1-beta2@1.3265 Wed Jan 28 20:32:29 UTC 2015 (1)
Feb 4 08:57:08 node-1 sntp[885]: 1970-01-01 00:00:04.140498 (+0000) +711520112.462117 +/- 474346741.863111 10.108.135.2 s3
Aug 22 13:25:40 node-1 ntpd[910]: ntpd 4.2.8p1-beta2@1.3265 Wed Jan 28 20:32:44 UTC 2015 (1): Starting
Aug 22 13:25:40 node-1 ntpd[910]: Command line: /usr/bin/ntpd -p /var/run/ntpd.pid
Aug 22 13:25:40 node-1 ntpd[911]: proto: precision = 0.103 usec (-23)
Aug 22 13:25:40 node-1 ntpd[911]: unable to bind to wildcard address :: - another process may be running - EXITING
Feb 4 08:57:16 node-1 ntpdate[744]: step time server 10.108.135.2 offset -711520112.142803 sec

# On node-2
Feb 4 08:57:01 node-2 kernel: [ 0.032009] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes)
Feb 4 08:57:03 node-2 sntp[880]: sntp 4.2.8p1-beta2@1.3265 Wed Jan 28 20:32:29 UTC 2015 (1)
Feb 4 08:57:03 node-2 sntp[880]: 1970-01-01 00:00:04.323281 (+0000) +711520109.325351 +/- 474346739.771842 10.108.135.2 s3
Aug 22 13:25:33 node-2 ntpd[902]: ntpd 4.2.8p1-beta2@1.3265 Wed Jan 28 20:32:44 UTC 2015 (1): Starting
Aug 22 13:25:33 node-2 ntpd[902]: Command line: /usr/bin/ntpd -p /var/run/ntpd.pid
Aug 22 13:25:33 node-2 ntpd[903]: proto: precision = 0.102 usec (-23)
Aug 22 13:25:33 node-2 ntpd[903]: unable to bind to wildcard address :: - another process may be running - EXITING
Feb 4 08:57:10 node-2 ntpdate[739]: step time server 10.108.135.2 offset -711520109.676662 sec

[Dennis Dmitriev (ddmitriev)]

During boot, master and slave nodes get wrong time : Aug 22 2037

This time is set by the 'sntp' application, please see /var/log/messages in the attachment for details.

[root@nailgun log]# ls -la /var/log/docker*
-rw-r--r-- 1 root root 0 Feb 4 12:39 /var/log/docker
-rw-r--r-- 1 root root 2737 Aug 22 2037 /var/log/docker-20150204.gz
-rw-r--r-- 1 root root 88 Aug 22 2037 /var/log/docker-astute.log
-rw-r--r-- 1 root root 153 Aug 22 2037 /var/log/docker-cobbler.log
-rw-r--r-- 1 root root 2283 Aug 22 2037 /var/log/docker-keystone.log
-rw-r--r-- 1 root root 163 Feb 4 12:08 /var/log/docker-mcollective.log
-rw-r--r-- 1 root root 90 Aug 22 2037 /var/log/docker-nailgun.log
-rw-r--r-- 1 root root 86 Aug 22 2037 /var/log/docker-nginx.log
-rw-r--r-- 1 root root 500 Aug 22 2037 /var/log/docker-ostf.log
-rw-r--r-- 1 root root 92 Aug 22 2037 /var/log/docker-postgres.log
-rw-r--r-- 1 root root 92 Aug 22 2037 /var/log/docker-rabbitmq.log
-rw-r--r-- 1 root root 86 Aug 22 2037 /var/log/docker-rsync.log
-rw-r--r-- 1 root root 90 Aug 22 2037 /var/log/docker-rsyslog.log

[Dennis Dmitriev (ddmitriev)]

http://paste.openstack.org/show/166785/