| OLD | NEW |
| (Empty) |
| 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 ~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()->RemoveThreadSafeObserver(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(), ¶ms_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.AddThreadSafeObserver(&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 } | |
| OLD | NEW |