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