net/tools/get_server_time/get_server_time.cc

   1 // Copyright (c) 2012 The Chromium Authors. All rights reserved.
   2 // Use of this source code is governed by a BSD-style license that can be
   3 // found in the LICENSE file.
   4
   5 // This is a small utility that snarfs the server time from the
   6 // response headers of an http/https HEAD request and compares it to
   7 // the local time.
   8 //
   9 // TODO(akalin): Also snarf the server time from the TLS handshake, if
  10 // any (http://crbug.com/146090).
  11
  12 #include <cstdio>
  13 #include <cstdlib>
  14 #include <string>
  15
  16 #include "base/at_exit.h"
  17 #include "base/basictypes.h"
  18 #include "base/command_line.h"
  19 #include "base/compiler_specific.h"
  20 #include "base/format_macros.h"
  21 #include "base/i18n/time_formatting.h"
  22 #include "base/json/json_writer.h"
  23 #include "base/logging.h"
  24 #include "base/memory/ref_counted.h"
  25 #include "base/memory/scoped_ptr.h"
  26 #include "base/message_loop.h"
  27 #include "base/single_thread_task_runner.h"
  28 #include "base/string_number_conversions.h"
  29 #include "base/time.h"
  30 #include "base/utf_string_conversions.h"
  31 #include "base/values.h"
  32 #include "build/build_config.h"
  33 #include "googleurl/src/gurl.h"
  34 #include "net/base/net_errors.h"
  35 #include "net/base/net_log.h"
  36 #include "net/http/http_response_headers.h"
  37 #include "net/url_request/url_fetcher.h"
  38 #include "net/url_request/url_fetcher_delegate.h"
  39 #include "net/url_request/url_request_context.h"
  40 #include "net/url_request/url_request_context_builder.h"
  41 #include "net/url_request/url_request_context_getter.h"
  42 #include "net/url_request/url_request_status.h"
  43
  44 #if defined(OS_MACOSX)
  45 #include "base/mac/scoped_nsautorelease_pool.h"
  46 #elif defined(OS_LINUX)
  47 #include "net/proxy/proxy_config.h"
  48 #include "net/proxy/proxy_config_service_fixed.h"
  49 #endif
  50
  51 namespace {
  52
  53 // base::TimeTicks::Now() is documented to have a resolution of
  54 // ~1-15ms.
  55 const int64 kTicksResolutionMs = 15;
  56
  57 // For the sources that are supported (HTTP date headers, TLS
  58 // handshake), the resolution of the server time is 1 second.
  59 const int64 kServerTimeResolutionMs = 1000;
  60
  61 // Assume base::Time::Now() has the same resolution as
  62 // base::TimeTicks::Now().
  63 //
  64 // TODO(akalin): Figure out the real resolution.
  65 const int64 kTimeResolutionMs = kTicksResolutionMs;
  66
  67 // Simply quits the current message loop when finished.  Used to make
  68 // URLFetcher synchronous.
  69 class QuitDelegate : public net::URLFetcherDelegate {
  70  public:
  71   QuitDelegate() {}
  72
  73   virtual ~QuitDelegate() {}
  74
  75   // net::URLFetcherDelegate implementation.
  76   virtual void OnURLFetchComplete(const net::URLFetcher* source) OVERRIDE {
  77     MessageLoop::current()->Quit();
  78   }
  79
  80   virtual void OnURLFetchDownloadProgress(
  81       const net::URLFetcher* source,
  82       int64 current, int64 total) OVERRIDE {
  83     NOTREACHED();
  84   }
  85
  86   virtual void OnURLFetchDownloadData(
  87       const net::URLFetcher* source,
  88       scoped_ptr<std::string> download_data) OVERRIDE{
  89     NOTREACHED();
  90   }
  91
  92   virtual bool ShouldSendDownloadData() OVERRIDE {
  93     NOTREACHED();
  94     return false;
  95   }
  96
  97   virtual void OnURLFetchUploadProgress(const net::URLFetcher* source,
  98                                         int64 current, int64 total) OVERRIDE {
  99     NOTREACHED();
 100   }
 101
 102  private:
 103   DISALLOW_COPY_AND_ASSIGN(QuitDelegate);
 104 };
 105
 106 // NetLog implementation that simply prints events to the logs.
 107 class PrintingLog : public net::NetLog {
 108  public:
 109   PrintingLog() : next_id_(1) {}
 110
 111   virtual ~PrintingLog() {}
 112
 113   // NetLog implementation:
 114   virtual void OnAddEntry(const net::NetLog::Entry& entry) OVERRIDE {
 115     // The log level of the entry is unknown, so just assume it maps
 116     // to VLOG(1).
 117     if (!VLOG_IS_ON(1))
 118       return;
 119
 120     const char* const source_type =
 121         net::NetLog::SourceTypeToString(entry.source().type);
 122     const char* const event_type =
 123         net::NetLog::EventTypeToString(entry.type());
 124     const char* const event_phase =
 125         net::NetLog::EventPhaseToString(entry.phase());
 126     scoped_ptr<base::Value> params(entry.ParametersToValue());
 127     std::string params_str;
 128     if (params.get()) {
 129       base::JSONWriter::Write(params.get(), &params_str);
 130       params_str.insert(0, ": ");
 131     }
 132
 133     VLOG(1) << source_type << "(" << entry.source().id << "): "
 134             << event_type << ": " << event_phase << params_str;
 135   }
 136
 137   virtual uint32 NextID() OVERRIDE {
 138     return next_id_++;
 139   }
 140
 141   virtual LogLevel GetLogLevel() const OVERRIDE {
 142     const int vlog_level = logging::GetVlogLevel(__FILE__);
 143     if (vlog_level <= 0) {
 144       return LOG_BASIC;
 145     }
 146     if (vlog_level == 1) {
 147       return LOG_ALL_BUT_BYTES;
 148     }
 149     return LOG_ALL;
 150   }
 151
 152   virtual void AddThreadSafeObserver(ThreadSafeObserver* observer,
 153                                      LogLevel log_level) OVERRIDE {
 154     NOTIMPLEMENTED();
 155   }
 156
 157   virtual void SetObserverLogLevel(ThreadSafeObserver* observer,
 158                                    LogLevel log_level) OVERRIDE {
 159     NOTIMPLEMENTED();
 160   }
 161
 162   virtual void RemoveThreadSafeObserver(ThreadSafeObserver* observer) OVERRIDE {
 163     NOTIMPLEMENTED();
 164   }
 165
 166  private:
 167   uint32 next_id_;
 168
 169   DISALLOW_COPY_AND_ASSIGN(PrintingLog);
 170 };
 171
 172 // Builds a URLRequestContext assuming there's only a single loop.
 173 scoped_ptr<net::URLRequestContext> BuildURLRequestContext() {
 174   net::URLRequestContextBuilder builder;
 175 #if defined(OS_LINUX)
 176   // On Linux, use a fixed ProxyConfigService, since the default one
 177   // depends on glib.
 178   //
 179   // TODO(akalin): Remove this once http://crbug.com/146421 is fixed.
 180   builder.set_proxy_config_service(
 181       new net::ProxyConfigServiceFixed(net::ProxyConfig()));
 182 #endif
 183   scoped_ptr<net::URLRequestContext> context(builder.Build());
 184   context->set_net_log(new PrintingLog());
 185   return context.Pass();
 186 }
 187
 188 class SingleThreadRequestContextGetter : public net::URLRequestContextGetter {
 189  public:
 190   // Since there's only a single thread, there's no need to worry
 191   // about when |context_| gets created.
 192   explicit SingleThreadRequestContextGetter(
 193       const scoped_refptr<base::SingleThreadTaskRunner>& main_task_runner)
 194       : context_(BuildURLRequestContext()),
 195         main_task_runner_(main_task_runner) {}
 196
 197   virtual net::URLRequestContext* GetURLRequestContext() OVERRIDE {
 198     return context_.get();
 199   }
 200
 201   virtual scoped_refptr<base::SingleThreadTaskRunner>
 202   GetNetworkTaskRunner() const OVERRIDE {
 203     return main_task_runner_;
 204   }
 205
 206  private:
 207   virtual ~SingleThreadRequestContextGetter() {}
 208
 209   const scoped_ptr<net::URLRequestContext> context_;
 210   const scoped_refptr<base::SingleThreadTaskRunner> main_task_runner_;
 211 };
 212
 213 // Assuming that the time |server_time| was received from a server,
 214 // that the request for the server was started on |start_ticks|, and
 215 // that it ended on |end_ticks|, fills |server_now| with an estimate
 216 // of the current time and |server_now_uncertainty| with a
 217 // conservative estimate of the uncertainty.
 218 void EstimateServerTimeNow(base::Time server_time,
 219                            base::TimeTicks start_ticks,
 220                            base::TimeTicks end_ticks,
 221                            base::Time* server_now,
 222                            base::TimeDelta* server_now_uncertainty) {
 223   const base::TimeDelta delta_ticks = end_ticks - start_ticks;
 224   const base::TimeTicks mid_ticks = start_ticks + delta_ticks / 2;
 225   const base::TimeDelta estimated_elapsed = base::TimeTicks::Now() - mid_ticks;
 226
 227   *server_now = server_time + estimated_elapsed;
 228
 229   *server_now_uncertainty =
 230       base::TimeDelta::FromMilliseconds(kServerTimeResolutionMs) +
 231       delta_ticks + 3 * base::TimeDelta::FromMilliseconds(kTicksResolutionMs);
 232 }
 233
 234 // Assuming that the time of the server is |server_now| with
 235 // uncertainty |server_now_uncertainty| and that the local time is
 236 // |now|, fills |skew| with the skew of the local clock (i.e., add
 237 // |*skew| to a client time to get a server time) and
 238 // |skew_uncertainty| with a conservative estimate of the uncertainty.
 239 void EstimateSkew(base::Time server_now,
 240                   base::TimeDelta server_now_uncertainty,
 241                   base::Time now,
 242                   base::TimeDelta now_uncertainty,
 243                   base::TimeDelta* skew,
 244                   base::TimeDelta* skew_uncertainty) {
 245   *skew = server_now - now;
 246   *skew_uncertainty = server_now_uncertainty + now_uncertainty;
 247 }
 248
 249 }  // namespace
 250
 251 int main(int argc, char* argv[]) {
 252 #if defined(OS_MACOSX)
 253   base::mac::ScopedNSAutoreleasePool pool;
 254 #endif
 255
 256   base::AtExitManager exit_manager;
 257   CommandLine::Init(argc, argv);
 258   logging::InitLogging(
 259       NULL,
 260       logging::LOG_ONLY_TO_SYSTEM_DEBUG_LOG,
 261       logging::LOCK_LOG_FILE,
 262       logging::DELETE_OLD_LOG_FILE,
 263       logging::DISABLE_DCHECK_FOR_NON_OFFICIAL_RELEASE_BUILDS);
 264
 265   const CommandLine& parsed_command_line = *CommandLine::ForCurrentProcess();
 266   GURL url(parsed_command_line.GetSwitchValueASCII("url"));
 267   if (!url.is_valid() ||
 268       (url.scheme() != "http" && url.scheme() != "https")) {
 269     std::fprintf(
 270         stderr,
 271         "Usage: %s --url=[http|https]://www.example.com [--v=[1|2]]\n",
 272         argv[0]);
 273     return EXIT_FAILURE;
 274   }
 275
 276   MessageLoopForIO main_loop;
 277
 278   // NOTE: A NetworkChangeNotifier could be instantiated here, but
 279   // that interferes with the request that will be sent; some
 280   // implementations always send out an OnIPAddressChanged() message,
 281   // which causes the DNS resolution to abort.  It's simpler to just
 282   // not instantiate one, since only a single request is sent anyway.
 283
 284   scoped_refptr<SingleThreadRequestContextGetter> context_getter(
 285       new SingleThreadRequestContextGetter(main_loop.message_loop_proxy()));
 286
 287   QuitDelegate delegate;
 288   scoped_ptr<net::URLFetcher> fetcher(
 289       net::URLFetcher::Create(url, net::URLFetcher::HEAD, &delegate));
 290   fetcher->SetRequestContext(context_getter.get());
 291
 292   const base::Time start_time = base::Time::Now();
 293   const base::TimeTicks start_ticks = base::TimeTicks::Now();
 294
 295   fetcher->Start();
 296   std::printf(
 297       "Request started at %s (ticks = %"PRId64")\n",
 298       UTF16ToUTF8(base::TimeFormatFriendlyDateAndTime(start_time)).c_str(),
 299       start_ticks.ToInternalValue());
 300
 301   // |delegate| quits |main_loop| when the request is done.
 302   main_loop.Run();
 303
 304   const base::Time end_time = base::Time::Now();
 305   const base::TimeTicks end_ticks = base::TimeTicks::Now();
 306
 307   std::printf(
 308       "Request ended at %s (ticks = %"PRId64")\n",
 309       UTF16ToUTF8(base::TimeFormatFriendlyDateAndTime(end_time)).c_str(),
 310       end_ticks.ToInternalValue());
 311
 312   const int64 delta_ticks_internal =
 313       end_ticks.ToInternalValue() - start_ticks.ToInternalValue();
 314   const base::TimeDelta delta_ticks = end_ticks - start_ticks;
 315
 316   std::printf(
 317       "Request took %"PRId64" ticks (%.2f ms)\n",
 318       delta_ticks_internal, delta_ticks.InMillisecondsF());
 319
 320   const net::URLRequestStatus status = fetcher->GetStatus();
 321   if (status.status() != net::URLRequestStatus::SUCCESS) {
 322     LOG(ERROR) << "Request failed with error code: "
 323                << net::ErrorToString(status.error());
 324     return EXIT_FAILURE;
 325   }
 326
 327   const net::HttpResponseHeaders* const headers =
 328       fetcher->GetResponseHeaders();
 329   if (!headers) {
 330     LOG(ERROR) << "Response does not have any headers";
 331     return EXIT_FAILURE;
 332   }
 333
 334   void* iter = NULL;
 335   std::string date_header;
 336   while (headers->EnumerateHeader(&iter, "Date", &date_header)) {
 337     std::printf("Got date header: %s\n", date_header.c_str());
 338   }
 339
 340   base::Time server_time;
 341   if (!headers->GetDateValue(&server_time)) {
 342     LOG(ERROR) << "Could not parse time from server response headers";
 343     return EXIT_FAILURE;
 344   }
 345
 346   std::printf(
 347       "Got time %s from server\n",
 348       UTF16ToUTF8(base::TimeFormatFriendlyDateAndTime(server_time)).c_str());
 349
 350   base::Time server_now;
 351   base::TimeDelta server_now_uncertainty;
 352   EstimateServerTimeNow(server_time, start_ticks, end_ticks,
 353                         &server_now, &server_now_uncertainty);
 354   base::Time now = base::Time::Now();
 355
 356   std::printf(
 357       "According to the server, it is now %s with uncertainty %.2f ms\n",
 358       UTF16ToUTF8(base::TimeFormatFriendlyDateAndTime(server_now)).c_str(),
 359       server_now_uncertainty.InMillisecondsF());
 360
 361   base::TimeDelta skew;
 362   base::TimeDelta skew_uncertainty;
 363   EstimateSkew(server_now, server_now_uncertainty, now,
 364                base::TimeDelta::FromMilliseconds(kTimeResolutionMs),
 365                &skew, &skew_uncertainty);
 366
 367   std::printf(
 368       "An estimate for the local clock skew is %.2f ms with "
 369       "uncertainty %.2f ms\n",
 370       skew.InMillisecondsF(),
 371       skew_uncertainty.InMillisecondsF());
 372
 373   return EXIT_SUCCESS;
 374 }