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