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 |