1 // Copyright 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 #include "chrome/browser/net/network_stats.h" 6 7 #include "base/bind.h" 8 #include "base/logging.h" 9 #include "base/message_loop/message_loop.h" 10 #include "base/metrics/field_trial.h" 11 #include "base/metrics/histogram.h" 12 #include "base/rand_util.h" 13 #include "base/strings/stringprintf.h" 14 #include "base/time/time.h" 15 #include "chrome/common/chrome_version_info.h" 16 #include "content/public/browser/browser_thread.h" 17 #include "net/base/net_errors.h" 18 #include "net/base/network_change_notifier.h" 19 #include "net/base/test_completion_callback.h" 20 #include "net/dns/single_request_host_resolver.h" 21 #include "net/proxy/proxy_service.h" 22 #include "net/socket/client_socket_factory.h" 23 #include "net/udp/datagram_client_socket.h" 24 #include "url/gurl.h" 25 26 using content::BrowserThread; 27 28 namespace chrome_browser_net { 29 30 // static 31 uint32 NetworkStats::maximum_tests_ = 8; 32 // static 33 uint32 NetworkStats::maximum_sequential_packets_ = 21; 34 // static 35 uint32 NetworkStats::maximum_NAT_packets_ = 2; 36 // static 37 uint32 NetworkStats::maximum_NAT_idle_seconds_ = 300; 38 // static 39 bool NetworkStats::start_test_after_connect_ = true; 40 41 // Specify the possible choices of probe packet sizes. 42 const uint32 kProbePacketBytes[] = {100, 500, 1200}; 43 const uint32 kPacketSizeChoices = arraysize(kProbePacketBytes); 44 45 // List of ports used for probing test. 46 const uint16 kPorts[] = {443, 80}; 47 48 // Number of first few packets that are recorded in a packet-correlation 49 // histogram, which shows exactly what sequence of packets were received. 50 // We use this to deduce specific packet loss correlation. 51 const uint32 kCorrelatedLossPacketCount = 6; 52 53 // This specifies the maximum message (payload) size of one packet. 54 const uint32 kMaxMessageSize = 1600; 55 56 // This specifies the maximum udp receiver buffer size. 57 const uint32 kMaxUdpReceiveBufferSize = 63000; 58 59 // This specifies the maximum udp receiver buffer size. 60 const uint32 kMaxUdpSendBufferSize = 4096; 61 62 // This should match TestType except for the last one. 63 const char* kTestName[] = {"TokenRequest", "StartPacket", "NonPacedPacket", 64 "PacedPacket", "NATBind", "PacketSizeTest"}; 65 66 // Perform Pacing/Non-pacing test only if at least 2 packets are received 67 // in the StartPacketTest. 68 const uint32 kMinimumReceivedPacketsForPacingTest = 2; 69 // Perform NAT binding test only if at least 10 packets are received. 70 const uint32 kMinimumReceivedPacketsForNATTest = 10; 71 72 // Maximum inter-packet pacing interval in microseconds. 73 const uint32 kMaximumPacingMicros = 1000000; 74 // Timeout value for getting the token. 75 const uint32 kGetTokenTimeoutSeconds = 10; 76 // Timeout value for StartPacket and NonPacedPacket if the client does not get 77 // reply. For PacedPacket test, the timeout value is this number plus the total 78 // pacing interval. 79 const uint32 kReadDataTimeoutSeconds = 30; 80 // This is the timeout for NAT without Idle periods. 81 // For NAT test with idle periods, the timeout is the Idle period + this value. 82 const uint32 kReadNATTimeoutSeconds = 10; 83 // This is the timeout for PACKET_SIZE_TEST. 84 const uint32 kReadPacketSizeTimeoutSeconds = 10; 85 // This is the maxmium number of packets we would send for PACKET_SIZE_TEST. 86 uint32 kMaximumPacketSizeTestPackets = 1; 87 88 // These helper functions are similar to UMA_HISTOGRAM_XXX except that they do 89 // not create a static histogram_pointer. 90 void DynamicHistogramEnumeration(const std::string& name, 91 uint32 sample, 92 uint32 boundary_value) { 93 base::HistogramBase* histogram_pointer = base::LinearHistogram::FactoryGet( 94 name, 95 1, 96 boundary_value, 97 boundary_value + 1, 98 base::HistogramBase::kUmaTargetedHistogramFlag); 99 histogram_pointer->Add(sample); 100 } 101 102 void DynamicHistogramTimes(const std::string& name, 103 const base::TimeDelta& sample) { 104 base::HistogramBase* histogram_pointer = base::Histogram::FactoryTimeGet( 105 name, 106 base::TimeDelta::FromMilliseconds(1), 107 base::TimeDelta::FromSeconds(30), 108 50, 109 base::HistogramBase::kUmaTargetedHistogramFlag); 110 histogram_pointer->AddTime(sample); 111 } 112 113 void DynamicHistogramCounts(const std::string& name, 114 uint32 sample, 115 uint32 min, 116 uint32 max, 117 uint32 bucket_count) { 118 base::HistogramBase* histogram_pointer = base::Histogram::FactoryGet( 119 name, min, max, bucket_count, 120 base::HistogramBase::kUmaTargetedHistogramFlag); 121 histogram_pointer->Add(sample); 122 } 123 124 NetworkStats::NetworkStats(net::ClientSocketFactory* socket_factory) 125 : socket_factory_(socket_factory), 126 histogram_port_(0), 127 has_proxy_server_(false), 128 probe_packet_bytes_(0), 129 bytes_for_packet_size_test_(0), 130 current_test_index_(0), 131 read_state_(READ_STATE_IDLE), 132 write_state_(WRITE_STATE_IDLE), 133 weak_factory_(this) { 134 ResetData(); 135 } 136 137 NetworkStats::~NetworkStats() {} 138 139 bool NetworkStats::Start(net::HostResolver* host_resolver, 140 const net::HostPortPair& server_host_port_pair, 141 uint16 histogram_port, 142 bool has_proxy_server, 143 uint32 probe_bytes, 144 uint32 bytes_for_packet_size_test, 145 const net::CompletionCallback& finished_callback) { 146 DCHECK(host_resolver); 147 histogram_port_ = histogram_port; 148 has_proxy_server_ = has_proxy_server; 149 probe_packet_bytes_ = probe_bytes; 150 bytes_for_packet_size_test_ = bytes_for_packet_size_test; 151 finished_callback_ = finished_callback; 152 test_sequence_.clear(); 153 test_sequence_.push_back(TOKEN_REQUEST); 154 155 ResetData(); 156 157 scoped_ptr<net::SingleRequestHostResolver> resolver( 158 new net::SingleRequestHostResolver(host_resolver)); 159 net::HostResolver::RequestInfo request(server_host_port_pair); 160 int rv = 161 resolver->Resolve(request, 162 net::DEFAULT_PRIORITY, 163 &addresses_, 164 base::Bind(base::IgnoreResult(&NetworkStats::DoConnect), 165 base::Unretained(this)), 166 net::BoundNetLog()); 167 if (rv == net::ERR_IO_PENDING) { 168 resolver_.swap(resolver); 169 return true; 170 } 171 return DoConnect(rv); 172 } 173 174 void NetworkStats::StartOneTest() { 175 if (test_sequence_[current_test_index_] == TOKEN_REQUEST) { 176 DCHECK_EQ(WRITE_STATE_IDLE, write_state_); 177 write_buffer_ = NULL; 178 SendHelloRequest(); 179 } else { 180 SendProbeRequest(); 181 } 182 } 183 184 void NetworkStats::ResetData() { 185 DCHECK_EQ(WRITE_STATE_IDLE, write_state_); 186 write_buffer_ = NULL; 187 packets_received_mask_.reset(); 188 first_arrival_time_ = base::TimeTicks(); 189 last_arrival_time_ = base::TimeTicks(); 190 191 packet_rtt_.clear(); 192 packet_rtt_.resize(maximum_sequential_packets_); 193 probe_request_time_ = base::TimeTicks(); 194 // Note: inter_arrival_time_ should not be reset here because it is used in 195 // subsequent tests. 196 } 197 198 bool NetworkStats::DoConnect(int result) { 199 if (result != net::OK) { 200 TestPhaseComplete(RESOLVE_FAILED, result); 201 return false; 202 } 203 204 scoped_ptr<net::DatagramClientSocket> udp_socket = 205 socket_factory_->CreateDatagramClientSocket( 206 net::DatagramSocket::DEFAULT_BIND, 207 net::RandIntCallback(), 208 NULL, 209 net::NetLog::Source()); 210 DCHECK(udp_socket); 211 DCHECK(!socket_); 212 socket_ = udp_socket.Pass(); 213 214 const net::IPEndPoint& endpoint = addresses_.front(); 215 int rv = socket_->Connect(endpoint); 216 if (rv < 0) { 217 TestPhaseComplete(CONNECT_FAILED, rv); 218 return false; 219 } 220 221 socket_->SetSendBufferSize(kMaxUdpSendBufferSize); 222 socket_->SetReceiveBufferSize(kMaxUdpReceiveBufferSize); 223 return ConnectComplete(rv); 224 } 225 226 bool NetworkStats::ConnectComplete(int result) { 227 if (result < 0) { 228 TestPhaseComplete(CONNECT_FAILED, result); 229 return false; 230 } 231 232 if (start_test_after_connect_) { 233 // Reads data for all HelloReply and all subsequent probe tests. 234 if (ReadData() != net::ERR_IO_PENDING) { 235 TestPhaseComplete(READ_FAILED, result); 236 return false; 237 } 238 SendHelloRequest(); 239 } else { 240 // For unittesting. Only run the callback, do not destroy it. 241 if (!finished_callback_.is_null()) 242 finished_callback_.Run(result); 243 } 244 return true; 245 } 246 247 void NetworkStats::SendHelloRequest() { 248 StartReadDataTimer(kGetTokenTimeoutSeconds, current_test_index_); 249 ProbePacket probe_packet; 250 probe_message_.SetPacketHeader(ProbePacket_Type_HELLO_REQUEST, &probe_packet); 251 probe_packet.set_group_id(current_test_index_); 252 std::string output = probe_message_.MakeEncodedPacket(probe_packet); 253 254 int result = SendData(output); 255 if (result < 0 && result != net::ERR_IO_PENDING) 256 TestPhaseComplete(WRITE_FAILED, result); 257 } 258 259 void NetworkStats::SendProbeRequest() { 260 ResetData(); 261 // Use default timeout except for the NAT bind test. 262 uint32 timeout_seconds = kReadDataTimeoutSeconds; 263 uint32 number_packets = maximum_sequential_packets_; 264 uint32 probe_bytes = probe_packet_bytes_; 265 pacing_interval_ = base::TimeDelta(); 266 switch (test_sequence_[current_test_index_]) { 267 case START_PACKET_TEST: 268 case NON_PACED_PACKET_TEST: 269 break; 270 case PACED_PACKET_TEST: { 271 pacing_interval_ = 272 std::min(inter_arrival_time_, 273 base::TimeDelta::FromMicroseconds(kMaximumPacingMicros)); 274 timeout_seconds += pacing_interval_.InMicroseconds() * 275 (maximum_sequential_packets_ - 1) / 1000000; 276 break; 277 } 278 case NAT_BIND_TEST: { 279 // Make sure no integer overflow. 280 DCHECK_LE(maximum_NAT_idle_seconds_, 4000U); 281 int nat_test_idle_seconds = base::RandInt(1, maximum_NAT_idle_seconds_); 282 pacing_interval_ = base::TimeDelta::FromSeconds(nat_test_idle_seconds); 283 timeout_seconds = nat_test_idle_seconds + kReadNATTimeoutSeconds; 284 number_packets = maximum_NAT_packets_; 285 break; 286 } 287 case PACKET_SIZE_TEST: { 288 number_packets = kMaximumPacketSizeTestPackets; 289 probe_bytes = bytes_for_packet_size_test_; 290 timeout_seconds = kReadPacketSizeTimeoutSeconds; 291 break; 292 } 293 default: 294 NOTREACHED(); 295 return; 296 } 297 DVLOG(1) << "NetworkStat: Probe pacing " << pacing_interval_.InMicroseconds() 298 << " microseconds. Time out " << timeout_seconds << " seconds"; 299 ProbePacket probe_packet; 300 probe_message_.GenerateProbeRequest(token_, 301 current_test_index_, 302 probe_bytes, 303 pacing_interval_.InMicroseconds(), 304 number_packets, 305 &probe_packet); 306 std::string output = probe_message_.MakeEncodedPacket(probe_packet); 307 308 StartReadDataTimer(timeout_seconds, current_test_index_); 309 probe_request_time_ = base::TimeTicks::Now(); 310 int result = SendData(output); 311 if (result < 0 && result != net::ERR_IO_PENDING) 312 TestPhaseComplete(WRITE_FAILED, result); 313 } 314 315 int NetworkStats::ReadData() { 316 if (!socket_.get()) 317 return 0; 318 319 if (read_state_ == READ_STATE_READ_PENDING) 320 return net::ERR_IO_PENDING; 321 322 int rv = 0; 323 do { 324 DCHECK(!read_buffer_.get()); 325 read_buffer_ = new net::IOBuffer(kMaxMessageSize); 326 327 rv = socket_->Read( 328 read_buffer_.get(), 329 kMaxMessageSize, 330 base::Bind(&NetworkStats::OnReadComplete, weak_factory_.GetWeakPtr())); 331 } while (rv > 0 && !ReadComplete(rv)); 332 if (rv == net::ERR_IO_PENDING) 333 read_state_ = READ_STATE_READ_PENDING; 334 return rv; 335 } 336 337 void NetworkStats::OnReadComplete(int result) { 338 DCHECK_NE(net::ERR_IO_PENDING, result); 339 DCHECK_EQ(READ_STATE_READ_PENDING, read_state_); 340 341 read_state_ = READ_STATE_IDLE; 342 if (!ReadComplete(result)) { 343 // Called ReadData() via PostDelayedTask() to avoid recursion. Added a delay 344 // of 1ms so that the time-out will fire before we have time to really hog 345 // the CPU too extensively (waiting for the time-out) in case of an infinite 346 // loop. 347 base::MessageLoop::current()->PostDelayedTask( 348 FROM_HERE, 349 base::Bind(base::IgnoreResult(&NetworkStats::ReadData), 350 weak_factory_.GetWeakPtr()), 351 base::TimeDelta::FromMilliseconds(1)); 352 } 353 } 354 355 bool NetworkStats::ReadComplete(int result) { 356 DCHECK(socket_.get()); 357 DCHECK_NE(net::ERR_IO_PENDING, result); 358 if (result < 0) { 359 // Something is wrong, finish the test. 360 read_buffer_ = NULL; 361 TestPhaseComplete(READ_FAILED, result); 362 return true; 363 } 364 365 std::string encoded_message(read_buffer_->data(), 366 read_buffer_->data() + result); 367 read_buffer_ = NULL; 368 ProbePacket probe_packet; 369 if (!probe_message_.ParseInput(encoded_message, &probe_packet)) 370 return false; 371 // Discard if the packet is for a different test. 372 if (probe_packet.group_id() != current_test_index_) 373 return false; 374 375 // Whether all packets in the current test have been received. 376 bool current_test_complete = false; 377 switch (probe_packet.header().type()) { 378 case ProbePacket_Type_HELLO_REPLY: 379 token_ = probe_packet.token(); 380 if (current_test_index_ == 0) 381 test_sequence_.push_back(START_PACKET_TEST); 382 current_test_complete = true; 383 break; 384 case ProbePacket_Type_PROBE_REPLY: 385 current_test_complete = UpdateReception(probe_packet); 386 break; 387 default: 388 DVLOG(1) << "Received unexpected packet type: " 389 << probe_packet.header().type(); 390 } 391 392 if (!current_test_complete) { 393 // All packets have not been received for the current test. 394 return false; 395 } 396 // All packets are received for the current test. 397 // Read completes if all tests are done. 398 bool all_tests_done = current_test_index_ >= maximum_tests_ || 399 current_test_index_ + 1 >= test_sequence_.size(); 400 TestPhaseComplete(SUCCESS, net::OK); 401 return all_tests_done; 402 } 403 404 bool NetworkStats::UpdateReception(const ProbePacket& probe_packet) { 405 uint32 packet_index = probe_packet.packet_index(); 406 if (packet_index >= packet_rtt_.size()) 407 return false; 408 packets_received_mask_.set(packet_index); 409 TestType test_type = test_sequence_[current_test_index_]; 410 uint32 received_packets = packets_received_mask_.count(); 411 412 // Now() has resolution ~1-15ms. HighResNow() has high resolution but it 413 // is warned not to use it unless necessary. 414 base::TimeTicks current_time = base::TimeTicks::Now(); 415 last_arrival_time_ = current_time; 416 if (first_arrival_time_.is_null()) 417 first_arrival_time_ = current_time; 418 419 // Need to do this after updating the last_arrival_time_ since NAT_BIND_TEST 420 // and PACKET_SIZE_TEST record the SendToLastRecvDelay. 421 if (test_type == NAT_BIND_TEST) { 422 return received_packets >= maximum_NAT_packets_; 423 } 424 if (test_type == PACKET_SIZE_TEST) { 425 return received_packets >= kMaximumPacketSizeTestPackets; 426 } 427 428 base::TimeDelta rtt = 429 current_time - probe_request_time_ - 430 base::TimeDelta::FromMicroseconds(std::max( 431 static_cast<int64>(0), probe_packet.server_processing_micros())); 432 base::TimeDelta min_rtt = base::TimeDelta::FromMicroseconds(1L); 433 packet_rtt_[packet_index] = (rtt >= min_rtt) ? rtt : min_rtt; 434 435 if (received_packets < maximum_sequential_packets_) 436 return false; 437 // All packets in the current test are received. 438 inter_arrival_time_ = (last_arrival_time_ - first_arrival_time_) / 439 std::max(1U, (received_packets - 1)); 440 if (test_type == START_PACKET_TEST) { 441 test_sequence_.push_back(PACKET_SIZE_TEST); 442 test_sequence_.push_back(TOKEN_REQUEST); 443 // No need to add TOKEN_REQUEST here when all packets are received. 444 test_sequence_.push_back(base::RandInt(0, 1) ? PACED_PACKET_TEST 445 : NON_PACED_PACKET_TEST); 446 test_sequence_.push_back(TOKEN_REQUEST); 447 test_sequence_.push_back(NAT_BIND_TEST); 448 test_sequence_.push_back(TOKEN_REQUEST); 449 } 450 return true; 451 } 452 453 int NetworkStats::SendData(const std::string& output) { 454 if (write_buffer_.get() || !socket_.get() || 455 write_state_ == WRITE_STATE_WRITE_PENDING) { 456 return net::ERR_UNEXPECTED; 457 } 458 scoped_refptr<net::StringIOBuffer> buffer(new net::StringIOBuffer(output)); 459 write_buffer_ = new net::DrainableIOBuffer(buffer.get(), buffer->size()); 460 461 int bytes_written = socket_->Write( 462 write_buffer_.get(), 463 write_buffer_->BytesRemaining(), 464 base::Bind(&NetworkStats::OnWriteComplete, weak_factory_.GetWeakPtr())); 465 if (bytes_written < 0) { 466 if (bytes_written == net::ERR_IO_PENDING) 467 write_state_ = WRITE_STATE_WRITE_PENDING; 468 return bytes_written; 469 } 470 UpdateSendBuffer(bytes_written); 471 return net::OK; 472 } 473 474 void NetworkStats::OnWriteComplete(int result) { 475 DCHECK_NE(net::ERR_IO_PENDING, result); 476 DCHECK_EQ(WRITE_STATE_WRITE_PENDING, write_state_); 477 write_state_ = WRITE_STATE_IDLE; 478 if (result < 0 || !socket_.get() || write_buffer_ == NULL) { 479 TestPhaseComplete(WRITE_FAILED, result); 480 return; 481 } 482 UpdateSendBuffer(result); 483 } 484 485 void NetworkStats::UpdateSendBuffer(int bytes_sent) { 486 write_buffer_->DidConsume(bytes_sent); 487 DCHECK_EQ(write_buffer_->BytesRemaining(), 0); 488 DCHECK_EQ(WRITE_STATE_IDLE, write_state_); 489 write_buffer_ = NULL; 490 } 491 492 void NetworkStats::StartReadDataTimer(uint32 seconds, uint32 test_index) { 493 base::MessageLoop::current()->PostDelayedTask( 494 FROM_HERE, 495 base::Bind(&NetworkStats::OnReadDataTimeout, 496 weak_factory_.GetWeakPtr(), 497 test_index), 498 base::TimeDelta::FromSeconds(seconds)); 499 } 500 501 void NetworkStats::OnReadDataTimeout(uint32 test_index) { 502 // If the current_test_index_ has changed since we set the timeout, 503 // the current test has been completed, so do nothing. 504 if (test_index != current_test_index_) 505 return; 506 // If test_type is TOKEN_REQUEST, it will do nothing but call 507 // TestPhaseComplete(). 508 TestType test_type = test_sequence_[current_test_index_]; 509 510 uint32 received_packets = packets_received_mask_.count(); 511 if (received_packets >= 2) { 512 inter_arrival_time_ = 513 (last_arrival_time_ - first_arrival_time_) / (received_packets - 1); 514 } 515 // Add other tests if this is START_PACKET_TEST. 516 if (test_type == START_PACKET_TEST) { 517 if (received_packets >= kMinimumReceivedPacketsForPacingTest) { 518 test_sequence_.push_back(TOKEN_REQUEST); 519 test_sequence_.push_back(PACKET_SIZE_TEST); 520 test_sequence_.push_back(TOKEN_REQUEST); 521 test_sequence_.push_back(base::RandInt(0, 1) ? PACED_PACKET_TEST 522 : NON_PACED_PACKET_TEST); 523 } 524 if (received_packets >= kMinimumReceivedPacketsForNATTest) { 525 test_sequence_.push_back(TOKEN_REQUEST); 526 test_sequence_.push_back(NAT_BIND_TEST); 527 test_sequence_.push_back(TOKEN_REQUEST); 528 } 529 } 530 TestPhaseComplete(READ_TIMED_OUT, net::ERR_FAILED); 531 } 532 533 void NetworkStats::TestPhaseComplete(Status status, int result) { 534 // If there is no valid token, do nothing and delete self. 535 // This includes all connection error, name resolve error, etc. 536 if (write_state_ == WRITE_STATE_WRITE_PENDING) { 537 UMA_HISTOGRAM_BOOLEAN("NetConnectivity5.TestFailed.WritePending", true); 538 } else if (token_.timestamp_micros() != 0 && 539 (status == SUCCESS || status == READ_TIMED_OUT)) { 540 TestType current_test = test_sequence_[current_test_index_]; 541 DCHECK_LT(current_test, TEST_TYPE_MAX); 542 if (current_test != TOKEN_REQUEST) { 543 RecordHistograms(current_test); 544 } else if (current_test_index_ > 0) { 545 if (test_sequence_[current_test_index_ - 1] == NAT_BIND_TEST) { 546 // We record the NATTestReceivedHistograms after the succeeding 547 // TokenRequest. 548 RecordNATTestReceivedHistograms(status); 549 } else if (test_sequence_[current_test_index_ - 1] == PACKET_SIZE_TEST) { 550 // We record the PacketSizeTestReceivedHistograms after the succeeding 551 // TokenRequest. 552 RecordPacketSizeTestReceivedHistograms(status); 553 } 554 } 555 556 // Move to the next test. 557 current_test = GetNextTest(); 558 if (current_test_index_ <= maximum_tests_ && current_test < TEST_TYPE_MAX) { 559 DVLOG(1) << "NetworkStat: Start Probe test: " << current_test; 560 base::MessageLoop::current()->PostTask( 561 FROM_HERE, 562 base::Bind(&NetworkStats::StartOneTest, weak_factory_.GetWeakPtr())); 563 return; 564 } 565 } 566 567 // All tests are done. 568 DoFinishCallback(result); 569 570 // Close the socket so that there are no more IO operations. 571 if (socket_.get()) 572 socket_->Close(); 573 574 DVLOG(1) << "NetworkStat: schedule delete self at test index " 575 << current_test_index_; 576 delete this; 577 } 578 579 NetworkStats::TestType NetworkStats::GetNextTest() { 580 ++current_test_index_; 581 if (current_test_index_ >= test_sequence_.size()) 582 return TEST_TYPE_MAX; 583 return test_sequence_[current_test_index_]; 584 } 585 586 void NetworkStats::DoFinishCallback(int result) { 587 if (!finished_callback_.is_null()) { 588 net::CompletionCallback callback = finished_callback_; 589 finished_callback_.Reset(); 590 callback.Run(result); 591 } 592 } 593 594 void NetworkStats::RecordHistograms(TestType test_type) { 595 switch (test_type) { 596 case START_PACKET_TEST: 597 case NON_PACED_PACKET_TEST: 598 case PACED_PACKET_TEST: { 599 RecordInterArrivalHistograms(test_type); 600 RecordPacketLossSeriesHistograms(test_type); 601 RecordPacketsReceivedHistograms(test_type); 602 // Only record RTT for these packet indices. 603 uint32 rtt_indices[] = {0, 1, 2, 9, 19}; 604 for (uint32 i = 0; i < arraysize(rtt_indices); ++i) { 605 if (rtt_indices[i] < packet_rtt_.size()) 606 RecordRTTHistograms(test_type, rtt_indices[i]); 607 } 608 RecordSendToLastRecvDelayHistograms(test_type); 609 return; 610 } 611 case NAT_BIND_TEST: 612 RecordSendToLastRecvDelayHistograms(test_type); 613 return; 614 case PACKET_SIZE_TEST: 615 // No need to record RTT for PacketSizeTest. 616 return; 617 default: 618 DVLOG(1) << "Unexpected test type " << test_type 619 << " in RecordHistograms."; 620 } 621 } 622 623 void NetworkStats::RecordInterArrivalHistograms(TestType test_type) { 624 DCHECK_NE(test_type, PACKET_SIZE_TEST); 625 std::string histogram_name = 626 base::StringPrintf("NetConnectivity5.%s.Sent%d.PacketDelay.%d.%dB", 627 kTestName[test_type], 628 maximum_sequential_packets_, 629 histogram_port_, 630 probe_packet_bytes_); 631 // Record the time normalized to 20 packet inter-arrivals. 632 DynamicHistogramTimes(histogram_name, inter_arrival_time_ * 20); 633 } 634 635 void NetworkStats::RecordPacketsReceivedHistograms(TestType test_type) { 636 DCHECK_NE(test_type, PACKET_SIZE_TEST); 637 const char* test_name = kTestName[test_type]; 638 std::string histogram_prefix = base::StringPrintf( 639 "NetConnectivity5.%s.Sent%d.", test_name, maximum_sequential_packets_); 640 std::string histogram_suffix = 641 base::StringPrintf(".%d.%dB", histogram_port_, probe_packet_bytes_); 642 std::string name = histogram_prefix + "GotAPacket" + histogram_suffix; 643 base::HistogramBase* histogram_pointer = base::BooleanHistogram::FactoryGet( 644 name, base::HistogramBase::kUmaTargetedHistogramFlag); 645 histogram_pointer->Add(packets_received_mask_.any()); 646 647 DynamicHistogramEnumeration( 648 histogram_prefix + "PacketsRecv" + histogram_suffix, 649 packets_received_mask_.count(), 650 maximum_sequential_packets_ + 1); 651 652 if (!packets_received_mask_.any()) 653 return; 654 655 base::HistogramBase* received_nth_packet_histogram = 656 base::Histogram::FactoryGet( 657 histogram_prefix + "RecvNthPacket" + histogram_suffix, 658 1, 659 maximum_sequential_packets_ + 1, 660 maximum_sequential_packets_ + 2, 661 base::HistogramBase::kUmaTargetedHistogramFlag); 662 663 int count = 0; 664 for (size_t j = 0; j < maximum_sequential_packets_; ++j) { 665 int packet_number = j + 1; 666 if (packets_received_mask_.test(j)) { 667 received_nth_packet_histogram->Add(packet_number); 668 ++count; 669 } 670 std::string histogram_name = 671 base::StringPrintf("%sNumRecvFromFirst%02dPackets%s", 672 histogram_prefix.c_str(), 673 packet_number, 674 histogram_suffix.c_str()); 675 DynamicHistogramEnumeration(histogram_name, count, packet_number + 1); 676 } 677 } 678 679 void NetworkStats::RecordNATTestReceivedHistograms(Status status) { 680 const char* test_name = kTestName[NAT_BIND_TEST]; 681 bool test_result = status == SUCCESS; 682 std::string middle_name = test_result ? "Connectivity.Success" 683 : "Connectivity.Failure"; 684 // Record whether the HelloRequest got reply successfully. 685 std::string histogram_name = 686 base::StringPrintf("NetConnectivity5.%s.Sent%d.%s.%d.%dB", 687 test_name, 688 maximum_NAT_packets_, 689 middle_name.c_str(), 690 histogram_port_, 691 probe_packet_bytes_); 692 uint32 bucket_count = std::min(maximum_NAT_idle_seconds_ + 2, 50U); 693 DynamicHistogramCounts(histogram_name, 694 pacing_interval_.InSeconds(), 695 1, 696 maximum_NAT_idle_seconds_ + 1, 697 bucket_count); 698 699 // Record the NAT bind result only if the HelloRequest successfully got the 700 // token and the first NAT test packet is received. 701 if (!test_result || !packets_received_mask_.test(0)) 702 return; 703 704 middle_name = packets_received_mask_.test(1) ? "Bind.Success" 705 : "Bind.Failure"; 706 histogram_name = base::StringPrintf("NetConnectivity5.%s.Sent%d.%s.%d.%dB", 707 test_name, 708 maximum_NAT_packets_, 709 middle_name.c_str(), 710 histogram_port_, 711 probe_packet_bytes_); 712 DynamicHistogramCounts(histogram_name, 713 pacing_interval_.InSeconds(), 714 1, 715 maximum_NAT_idle_seconds_ + 1, 716 bucket_count); 717 } 718 719 void NetworkStats::RecordPacketSizeTestReceivedHistograms(Status status) { 720 const char* test_name = kTestName[PACKET_SIZE_TEST]; 721 bool test_result = (status == SUCCESS && packets_received_mask_.test(0)); 722 std::string middle_name = test_result ? "Connectivity.Success" 723 : "Connectivity.Failure"; 724 // Record whether the HelloRequest got reply successfully. 725 std::string histogram_name = 726 base::StringPrintf("NetConnectivity5.%s.%s.%d", 727 test_name, 728 middle_name.c_str(), 729 histogram_port_); 730 base::HistogramBase* histogram_pointer = base::LinearHistogram::FactoryGet( 731 histogram_name, kProbePacketBytes[kPacketSizeChoices - 1], 732 ProbeMessage::kMaxProbePacketBytes, 60, 733 base::HistogramBase::kUmaTargetedHistogramFlag); 734 histogram_pointer->Add(bytes_for_packet_size_test_); 735 } 736 737 void NetworkStats::RecordPacketLossSeriesHistograms(TestType test_type) { 738 DCHECK_NE(test_type, PACKET_SIZE_TEST); 739 const char* test_name = kTestName[test_type]; 740 // Build "NetConnectivity5.<TestName>.First6.SeriesRecv.<port>.<probe_size>" 741 // histogram name. Total 3(tests) x 12 histograms. 742 std::string series_acked_histogram_name = 743 base::StringPrintf("NetConnectivity5.%s.First6.SeriesRecv.%d.%dB", 744 test_name, 745 histogram_port_, 746 probe_packet_bytes_); 747 uint32 histogram_boundary = 1 << kCorrelatedLossPacketCount; 748 uint32 correlated_packet_mask = 749 (histogram_boundary - 1) & packets_received_mask_.to_ulong(); 750 DynamicHistogramEnumeration( 751 series_acked_histogram_name, correlated_packet_mask, histogram_boundary); 752 753 // If we are running without a proxy, we'll generate an extra histogram with 754 // the ".NoProxy" suffix. 755 if (!has_proxy_server_) { 756 series_acked_histogram_name.append(".NoProxy"); 757 DynamicHistogramEnumeration(series_acked_histogram_name, 758 correlated_packet_mask, 759 histogram_boundary); 760 } 761 } 762 763 void NetworkStats::RecordRTTHistograms(TestType test_type, uint32 index) { 764 DCHECK_NE(test_type, PACKET_SIZE_TEST); 765 DCHECK_LT(index, packet_rtt_.size()); 766 767 if (!packets_received_mask_.test(index)) 768 return; // Probe packet never received. 769 770 std::string rtt_histogram_name = base::StringPrintf( 771 "NetConnectivity5.%s.Sent%d.Success.RTT.Packet%02d.%d.%dB", 772 kTestName[test_type], 773 maximum_sequential_packets_, 774 index + 1, 775 histogram_port_, 776 probe_packet_bytes_); 777 DynamicHistogramTimes(rtt_histogram_name, packet_rtt_[index]); 778 } 779 780 void NetworkStats::RecordSendToLastRecvDelayHistograms(TestType test_type) { 781 DCHECK_NE(test_type, PACKET_SIZE_TEST); 782 if (packets_received_mask_.count() < 2) 783 return; // Too few packets are received. 784 uint32 packets_sent = test_type == NAT_BIND_TEST 785 ? maximum_NAT_packets_ : maximum_sequential_packets_; 786 std::string histogram_name = base::StringPrintf( 787 "NetConnectivity5.%s.Sent%d.SendToLastRecvDelay.%d.%dB", 788 kTestName[test_type], 789 packets_sent, 790 histogram_port_, 791 probe_packet_bytes_); 792 base::TimeDelta send_to_last_recv_time = 793 std::max(last_arrival_time_ - probe_request_time_ - 794 pacing_interval_ * (packets_sent - 1), 795 base::TimeDelta::FromMilliseconds(0)); 796 DynamicHistogramTimes(histogram_name, send_to_last_recv_time); 797 } 798 799 // ProxyDetector methods and members. 800 ProxyDetector::ProxyDetector(net::ProxyService* proxy_service, 801 const net::HostPortPair& server_address, 802 OnResolvedCallback callback) 803 : proxy_service_(proxy_service), 804 server_address_(server_address), 805 callback_(callback), 806 has_pending_proxy_resolution_(false) {} 807 808 ProxyDetector::~ProxyDetector() { 809 CHECK(!has_pending_proxy_resolution_); 810 } 811 812 void ProxyDetector::StartResolveProxy() { 813 std::string url = 814 base::StringPrintf("https://%s", server_address_.ToString().c_str()); 815 GURL gurl(url); 816 817 has_pending_proxy_resolution_ = true; 818 DCHECK(proxy_service_); 819 int rv = proxy_service_->ResolveProxy( 820 gurl, 821 &proxy_info_, 822 base::Bind(&ProxyDetector::OnResolveProxyComplete, 823 base::Unretained(this)), 824 NULL, 825 net::BoundNetLog()); 826 if (rv != net::ERR_IO_PENDING) 827 OnResolveProxyComplete(rv); 828 } 829 830 void ProxyDetector::OnResolveProxyComplete(int result) { 831 has_pending_proxy_resolution_ = false; 832 bool has_proxy_server = 833 (result == net::OK && proxy_info_.proxy_server().is_valid() && 834 !proxy_info_.proxy_server().is_direct()); 835 836 OnResolvedCallback callback = callback_; 837 BrowserThread::PostTask( 838 BrowserThread::IO, FROM_HERE, base::Bind(callback, has_proxy_server)); 839 840 // TODO(rtenneti): Will we leak if ProxyResolve is cancelled (or proxy 841 // resolution never completes). 842 delete this; 843 } 844 845 void CollectNetworkStats(const std::string& network_stats_server, 846 IOThread* io_thread) { 847 if (network_stats_server.empty()) 848 return; 849 850 // If we are not on IO Thread, then post a task to call CollectNetworkStats on 851 // IO Thread. 852 if (!BrowserThread::CurrentlyOn(BrowserThread::IO)) { 853 BrowserThread::PostTask( 854 BrowserThread::IO, 855 FROM_HERE, 856 base::Bind(&CollectNetworkStats, network_stats_server, io_thread)); 857 return; 858 } 859 860 DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO)); 861 862 if (net::NetworkChangeNotifier::IsOffline()) { 863 return; 864 } 865 866 CR_DEFINE_STATIC_LOCAL(scoped_refptr<base::FieldTrial>, trial, ()); 867 static bool collect_stats = false; 868 869 if (!trial.get()) { 870 // Set up a field trial to collect network stats for UDP. 871 const base::FieldTrial::Probability kDivisor = 1000; 872 873 // Enable the connectivity testing for 0.5% of the users in stable channel. 874 base::FieldTrial::Probability probability_per_group = kDivisor / 200; 875 876 chrome::VersionInfo::Channel channel = chrome::VersionInfo::GetChannel(); 877 if (channel == chrome::VersionInfo::CHANNEL_CANARY) { 878 // Enable the connectivity testing for 50% of the users in canary channel. 879 probability_per_group = kDivisor / 2; 880 } else if (channel == chrome::VersionInfo::CHANNEL_DEV) { 881 // Enable the connectivity testing for 10% of the users in dev channel. 882 probability_per_group = kDivisor / 10; 883 } else if (channel == chrome::VersionInfo::CHANNEL_BETA) { 884 // Enable the connectivity testing for 1% of the users in beta channel. 885 probability_per_group = kDivisor / 100; 886 } 887 888 // TODO(rtenneti): Enable the experiment after fixing 889 // issue http://crbug.com/273917. 890 probability_per_group = 0; 891 892 // After July 31, 2014 builds, it will always be in default group 893 // (disable_network_stats). 894 trial = base::FieldTrialList::FactoryGetFieldTrial( 895 "NetworkConnectivity", kDivisor, "disable_network_stats", 896 2014, 7, 31, base::FieldTrial::SESSION_RANDOMIZED, NULL); 897 898 // Add option to collect_stats for NetworkConnectivity. 899 int collect_stats_group = 900 trial->AppendGroup("collect_stats", probability_per_group); 901 if (trial->group() == collect_stats_group) 902 collect_stats = true; 903 } 904 905 if (!collect_stats) 906 return; 907 908 // Run test kMaxNumberOfTests times. 909 const size_t kMaxNumberOfTests = INT_MAX; 910 static size_t number_of_tests_done = 0; 911 if (number_of_tests_done > kMaxNumberOfTests) 912 return; 913 ++number_of_tests_done; 914 915 net::HostResolver* host_resolver = io_thread->globals()->host_resolver.get(); 916 DCHECK(host_resolver); 917 918 uint32 port_index = base::RandInt(0, arraysize(kPorts) - 1); 919 uint16 histogram_port = kPorts[port_index]; 920 net::HostPortPair server_address(network_stats_server, histogram_port); 921 922 net::ProxyService* proxy_service = 923 io_thread->globals()->system_proxy_service.get(); 924 DCHECK(proxy_service); 925 926 ProxyDetector::OnResolvedCallback callback = base::Bind( 927 &StartNetworkStatsTest, host_resolver, server_address, histogram_port); 928 929 ProxyDetector* proxy_client = 930 new ProxyDetector(proxy_service, server_address, callback); 931 proxy_client->StartResolveProxy(); 932 } 933 934 void StartNetworkStatsTest(net::HostResolver* host_resolver, 935 const net::HostPortPair& server_address, 936 uint16 histogram_port, 937 bool has_proxy_server) { 938 int probe_choice = base::RandInt(0, kPacketSizeChoices - 1); 939 940 DCHECK_LE(ProbeMessage::kMaxProbePacketBytes, kMaxMessageSize); 941 // Pick a packet size between 1200 and kMaxProbePacketBytes bytes. 942 uint32 bytes_for_packet_size_test = 943 base::RandInt(kProbePacketBytes[kPacketSizeChoices - 1], 944 ProbeMessage::kMaxProbePacketBytes); 945 946 // |udp_stats_client| is owned and deleted in the class NetworkStats. 947 NetworkStats* udp_stats_client = 948 new NetworkStats(net::ClientSocketFactory::GetDefaultFactory()); 949 udp_stats_client->Start(host_resolver, 950 server_address, 951 histogram_port, 952 has_proxy_server, 953 kProbePacketBytes[probe_choice], 954 bytes_for_packet_size_test, 955 net::CompletionCallback()); 956 } 957 958 } // namespace chrome_browser_net 959
