"Setting oauth clockskew" messages on booting node; slows down boot

[Rod Smith]

On booting nodes for enlistment, commissioning, and starting, I sometimes see repeated errors like this:

2014-04-23 14:15:50,622 - DataSourceMAAS.py[WARNING]: Setting oauth clockskew to -2

(See attached screen shot, too.) These scroll by, once every second or so, for about a minute before the node continues booting. Although a minute here or there isn't all THAT big of a deal, it would be nice to see this delay go away, particularly for occasions when I have to repeatedly test a node.

Here's my version information:

$ dpkg -l '*maas*'|cat
Desired=Unknown/Install/Remove/Purge/Hold
| Status=Not/Inst/Conf-files/Unpacked/halF-conf/Half-inst/trig-aWait/Trig-pend
|/ Err?=(none)/Reinst-required (Status,Err: uppercase=bad)
||/ Name Version Architecture Description
+++-=====================================================-===================================================-============-===============================================================================
ii maas 1.5+bzr2252-0ubuntu1 all MAAS server all-in-one metapackage
ii maas-cli 1.5+bzr2252-0ubuntu1 all MAAS command line API tool
ii maas-cluster-controller 1.5+bzr2252-0ubuntu1 all MAAS server cluster controller
ii maas-common 1.5+bzr2252-0ubuntu1 all MAAS server common files
ii maas-dhcp 1.5+bzr2252-0ubuntu1 all MAAS DHCP server
ii maas-dns 1.5+bzr2252-0ubuntu1 all MAAS DNS server
ii maas-region-controller 1.5+bzr2252-0ubuntu1 all MAAS server complete region controller
ii maas-region-controller-min 1.5+bzr2252-0ubuntu1 all MAAS Server minimum region controller
ii python-django-maas 1.5+bzr2252-0ubuntu1 all MAAS server Django web framework
ii python-maas-client 1.5+bzr2252-0ubuntu1 all MAAS python API client
ii python-maas-provisioningserver 1.5+bzr2252-0ubuntu1 all MAAS server provisioning libraries

[Julian Edwards (julian-edwards)]

What makes you think this is slowing down the boot?

[Rod Smith (rodsmith)]

Because it sits there for a minute without doing anything but print those error messages. If that's normal, then the message should be changed to notify the user that a pause in the boot process is happening, and printed just once; as it is, it looks like an error.

[Julian Edwards (julian-edwards)]

Ok that message comes out of cloud-init. I've added a bugtask for Scott's comments to see if anything can be done in MAAS.

[Scott Moser (smoser)]

I can't come up with any reason that these messages should actually delay boot at all.
They're simply output of the following:
 * cloud-init tries to reach an OATH protected url (with timestamp from system clock)
 * cloud-init is given 403 with a timestamp indicating the *server*s time
 * cloud-init re-tries with timestamp from server (and tells you that it is doing this as it indicates your clock is potentially more than 5 minutes off).

I do not think it delays boot.

Updating the hardware clock during boot is somewhat problematic.
As is currently implemented the above procedure occurs each time cloud-init makes a request. We could fix that so that cloud-init remembered the offset across subsequent invocations. We could also look into having it attempt to set the hardware clock to what it views as "right". The issue with doing htat is that anything that has a timer set may be confused. ie:
  program runs and invokes: sleep 30
  cloud-init change clock back 3 days
  3 days and 30 seconds later, program returns from 'sleep 30'.

[LaMont Jones (lamont)]

This is a cloud-init bug.

[James Falcon (falcojr)]

Tracked in Github Issues as https://github.com/canonical/cloud-init/issues/2446