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