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/message_loop.h"
  27 #include "base/single_thread_task_runner.h"
  28 #include "base/strings/string_number_conversions.h"
  29 #include "base/strings/utf_string_conversions.h"
  30 #include "base/time/time.h"
  31 #include "base/values.h"
  32 #include "build/build_config.h"
  33 #include "net/base/net_errors.h"
  34 #include "net/http/http_response_headers.h"
  35 #include "net/log/net_log.h"
  36 #include "net/url_request/url_fetcher.h"
  37 #include "net/url_request/url_fetcher_delegate.h"
  38 #include "net/url_request/url_request_context.h"
  39 #include "net/url_request/url_request_context_builder.h"
  40 #include "net/url_request/url_request_context_getter.h"
  41 #include "net/url_request/url_request_status.h"
  42 #include "url/gurl.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 using base::UTF16ToUTF8;
  52
  53 namespace {
  54
  55 // base::TimeTicks::Now() is documented to have a resolution of
  56 // ~1-15ms.
  57 const int64 kTicksResolutionMs = 15;
  58
  59 // For the sources that are supported (HTTP date headers, TLS
  60 // handshake), the resolution of the server time is 1 second.
  61 const int64 kServerTimeResolutionMs = 1000;
  62
  63 // Assume base::Time::Now() has the same resolution as
  64 // base::TimeTicks::Now().
  65 //
  66 // TODO(akalin): Figure out the real resolution.
  67 const int64 kTimeResolutionMs = kTicksResolutionMs;
  68
  69 // Simply quits the current message loop when finished.  Used to make
  70 // URLFetcher synchronous.
  71 class QuitDelegate : public net::URLFetcherDelegate {
  72  public:
  73   QuitDelegate() {}
  74
  75   ~QuitDelegate() override {}
  76
  77   // net::URLFetcherDelegate implementation.
  78   void OnURLFetchComplete(const net::URLFetcher* source) override {
  79     base::MessageLoop::current()->Quit();
  80   }
  81
  82   void OnURLFetchDownloadProgress(const net::URLFetcher* source,
  83                                   int64 current,
  84                                   int64 total) override {
  85     NOTREACHED();
  86   }
  87
  88   void OnURLFetchUploadProgress(const net::URLFetcher* source,
  89                                 int64 current,
  90                                 int64 total) override {
  91     NOTREACHED();
  92   }
  93
  94  private:
  95   DISALLOW_COPY_AND_ASSIGN(QuitDelegate);
  96 };
  97
  98 // NetLog::ThreadSafeObserver implementation that simply prints events
  99 // to the logs.
 100 class PrintingLogObserver : public net::NetLog::ThreadSafeObserver {
 101  public:
 102   PrintingLogObserver() {}
 103
 104   ~PrintingLogObserver() override {
 105     // This is guaranteed to be safe as this program is single threaded.
 106     net_log()->DeprecatedRemoveObserver(this);
 107   }
 108
 109   // NetLog::ThreadSafeObserver implementation:
 110   void OnAddEntry(const net::NetLog::Entry& entry) override {
 111     // The log level of the entry is unknown, so just assume it maps
 112     // to VLOG(1).
 113     if (!VLOG_IS_ON(1))
 114       return;
 115
 116     const char* const source_type =
 117         net::NetLog::SourceTypeToString(entry.source().type);
 118     const char* const event_type =
 119         net::NetLog::EventTypeToString(entry.type());
 120     const char* const event_phase =
 121         net::NetLog::EventPhaseToString(entry.phase());
 122     scoped_ptr<base::Value> params(entry.ParametersToValue());
 123     std::string params_str;
 124     if (params.get()) {
 125       base::JSONWriter::Write(params.get(), &params_str);
 126       params_str.insert(0, ": ");
 127     }
 128
 129     VLOG(1) << source_type << "(" << entry.source().id << "): "
 130             << event_type << ": " << event_phase << params_str;
 131   }
 132
 133  private:
 134   DISALLOW_COPY_AND_ASSIGN(PrintingLogObserver);
 135 };
 136
 137 // Builds a URLRequestContext assuming there's only a single loop.
 138 scoped_ptr<net::URLRequestContext>
 139 BuildURLRequestContext(net::NetLog* net_log) {
 140   net::URLRequestContextBuilder builder;
 141 #if defined(OS_LINUX)
 142   // On Linux, use a fixed ProxyConfigService, since the default one
 143   // depends on glib.
 144   //
 145   // TODO(akalin): Remove this once http://crbug.com/146421 is fixed.
 146   builder.set_proxy_config_service(
 147       new net::ProxyConfigServiceFixed(net::ProxyConfig()));
 148 #endif
 149   scoped_ptr<net::URLRequestContext> context(builder.Build());
 150   context->set_net_log(net_log);
 151   return context.Pass();
 152 }
 153
 154 // Assuming that the time |server_time| was received from a server,
 155 // that the request for the server was started on |start_ticks|, and
 156 // that it ended on |end_ticks|, fills |server_now| with an estimate
 157 // of the current time and |server_now_uncertainty| with a
 158 // conservative estimate of the uncertainty.
 159 void EstimateServerTimeNow(base::Time server_time,
 160                            base::TimeTicks start_ticks,
 161                            base::TimeTicks end_ticks,
 162                            base::Time* server_now,
 163                            base::TimeDelta* server_now_uncertainty) {
 164   const base::TimeDelta delta_ticks = end_ticks - start_ticks;
 165   const base::TimeTicks mid_ticks = start_ticks + delta_ticks / 2;
 166   const base::TimeDelta estimated_elapsed = base::TimeTicks::Now() - mid_ticks;
 167
 168   *server_now = server_time + estimated_elapsed;
 169
 170   *server_now_uncertainty =
 171       base::TimeDelta::FromMilliseconds(kServerTimeResolutionMs) +
 172       delta_ticks + 3 * base::TimeDelta::FromMilliseconds(kTicksResolutionMs);
 173 }
 174
 175 // Assuming that the time of the server is |server_now| with
 176 // uncertainty |server_now_uncertainty| and that the local time is
 177 // |now|, fills |skew| with the skew of the local clock (i.e., add
 178 // |*skew| to a client time to get a server time) and
 179 // |skew_uncertainty| with a conservative estimate of the uncertainty.
 180 void EstimateSkew(base::Time server_now,
 181                   base::TimeDelta server_now_uncertainty,
 182                   base::Time now,
 183                   base::TimeDelta now_uncertainty,
 184                   base::TimeDelta* skew,
 185                   base::TimeDelta* skew_uncertainty) {
 186   *skew = server_now - now;
 187   *skew_uncertainty = server_now_uncertainty + now_uncertainty;
 188 }
 189
 190 }  // namespace
 191
 192 int main(int argc, char* argv[]) {
 193 #if defined(OS_MACOSX)
 194   base::mac::ScopedNSAutoreleasePool pool;
 195 #endif
 196
 197   base::AtExitManager exit_manager;
 198   base::CommandLine::Init(argc, argv);
 199   logging::LoggingSettings settings;
 200   settings.logging_dest = logging::LOG_TO_SYSTEM_DEBUG_LOG;
 201   logging::InitLogging(settings);
 202
 203   const base::CommandLine& parsed_command_line =
 204       *base::CommandLine::ForCurrentProcess();
 205   GURL url(parsed_command_line.GetSwitchValueASCII("url"));
 206   if (!url.is_valid() ||
 207       (url.scheme() != "http" && url.scheme() != "https")) {
 208     std::fprintf(
 209         stderr,
 210         "Usage: %s --url=[http|https]://www.example.com [--v=[1|2]]\n",
 211         argv[0]);
 212     return EXIT_FAILURE;
 213   }
 214
 215   base::MessageLoopForIO main_loop;
 216
 217   // NOTE: A NetworkChangeNotifier could be instantiated here, but
 218   // that interferes with the request that will be sent; some
 219   // implementations always send out an OnIPAddressChanged() message,
 220   // which causes the DNS resolution to abort.  It's simpler to just
 221   // not instantiate one, since only a single request is sent anyway.
 222
 223   // The declaration order for net_log and printing_log_observer is
 224   // important. The destructor of PrintingLogObserver removes itself
 225   // from net_log, so net_log must be available for entire lifetime of
 226   // printing_log_observer.
 227   net::NetLog net_log;
 228   PrintingLogObserver printing_log_observer;
 229   net_log.DeprecatedAddObserver(&printing_log_observer, net::NetLog::LOG_ALL);
 230
 231   QuitDelegate delegate;
 232   scoped_ptr<net::URLFetcher> fetcher(
 233       net::URLFetcher::Create(url, net::URLFetcher::HEAD, &delegate));
 234   scoped_ptr<net::URLRequestContext> url_request_context(
 235       BuildURLRequestContext(&net_log));
 236   fetcher->SetRequestContext(
 237       // Since there's only a single thread, there's no need to worry
 238       // about when the URLRequestContext gets created.
 239       // The URLFetcher will take a reference on the object, and hence
 240       // implicitly take ownership.
 241       new net::TrivialURLRequestContextGetter(url_request_context.get(),
 242                                               main_loop.message_loop_proxy()));
 243   const base::Time start_time = base::Time::Now();
 244   const base::TimeTicks start_ticks = base::TimeTicks::Now();
 245
 246   fetcher->Start();
 247   std::printf(
 248       "Request started at %s (ticks = %" PRId64 ")\n",
 249       UTF16ToUTF8(base::TimeFormatFriendlyDateAndTime(start_time)).c_str(),
 250       start_ticks.ToInternalValue());
 251
 252   // |delegate| quits |main_loop| when the request is done.
 253   main_loop.Run();
 254
 255   const base::Time end_time = base::Time::Now();
 256   const base::TimeTicks end_ticks = base::TimeTicks::Now();
 257
 258   std::printf(
 259       "Request ended at %s (ticks = %" PRId64 ")\n",
 260       UTF16ToUTF8(base::TimeFormatFriendlyDateAndTime(end_time)).c_str(),
 261       end_ticks.ToInternalValue());
 262
 263   const int64 delta_ticks_internal =
 264       end_ticks.ToInternalValue() - start_ticks.ToInternalValue();
 265   const base::TimeDelta delta_ticks = end_ticks - start_ticks;
 266
 267   std::printf(
 268       "Request took %" PRId64 " ticks (%.2f ms)\n",
 269       delta_ticks_internal, delta_ticks.InMillisecondsF());
 270
 271   const net::URLRequestStatus status = fetcher->GetStatus();
 272   if (status.status() != net::URLRequestStatus::SUCCESS) {
 273     LOG(ERROR) << "Request failed with error code: "
 274                << net::ErrorToString(status.error());
 275     return EXIT_FAILURE;
 276   }
 277
 278   const net::HttpResponseHeaders* const headers =
 279       fetcher->GetResponseHeaders();
 280   if (!headers) {
 281     LOG(ERROR) << "Response does not have any headers";
 282     return EXIT_FAILURE;
 283   }
 284
 285   void* iter = NULL;
 286   std::string date_header;
 287   while (headers->EnumerateHeader(&iter, "Date", &date_header)) {
 288     std::printf("Got date header: %s\n", date_header.c_str());
 289   }
 290
 291   base::Time server_time;
 292   if (!headers->GetDateValue(&server_time)) {
 293     LOG(ERROR) << "Could not parse time from server response headers";
 294     return EXIT_FAILURE;
 295   }
 296
 297   std::printf(
 298       "Got time %s from server\n",
 299       UTF16ToUTF8(base::TimeFormatFriendlyDateAndTime(server_time)).c_str());
 300
 301   base::Time server_now;
 302   base::TimeDelta server_now_uncertainty;
 303   EstimateServerTimeNow(server_time, start_ticks, end_ticks,
 304                         &server_now, &server_now_uncertainty);
 305   base::Time now = base::Time::Now();
 306
 307   std::printf(
 308       "According to the server, it is now %s with uncertainty %.2f ms\n",
 309       UTF16ToUTF8(base::TimeFormatFriendlyDateAndTime(server_now)).c_str(),
 310       server_now_uncertainty.InMillisecondsF());
 311
 312   base::TimeDelta skew;
 313   base::TimeDelta skew_uncertainty;
 314   EstimateSkew(server_now, server_now_uncertainty, now,
 315                base::TimeDelta::FromMilliseconds(kTimeResolutionMs),
 316                &skew, &skew_uncertainty);
 317
 318   std::printf(
 319       "An estimate for the local clock skew is %.2f ms with "
 320       "uncertainty %.2f ms\n",
 321       skew.InMillisecondsF(),
 322       skew_uncertainty.InMillisecondsF());
 323
 324   return EXIT_SUCCESS;
 325 }