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 while (true) { 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 if (rv <= 0) 332 break; 333 if (ReadComplete(rv)) 334 return rv; 335 }; 336 if (rv == net::ERR_IO_PENDING) 337 read_state_ = READ_STATE_READ_PENDING; 338 return rv; 339 } 340 341 void NetworkStats::OnReadComplete(int result) { 342 DCHECK_NE(net::ERR_IO_PENDING, result); 343 DCHECK_EQ(READ_STATE_READ_PENDING, read_state_); 344 345 read_state_ = READ_STATE_IDLE; 346 if (!ReadComplete(result)) { 347 // Called ReadData() via PostDelayedTask() to avoid recursion. Added a delay 348 // of 1ms so that the time-out will fire before we have time to really hog 349 // the CPU too extensively (waiting for the time-out) in case of an infinite 350 // loop. 351 base::MessageLoop::current()->PostDelayedTask( 352 FROM_HERE, 353 base::Bind(base::IgnoreResult(&NetworkStats::ReadData), 354 weak_factory_.GetWeakPtr()), 355 base::TimeDelta::FromMilliseconds(1)); 356 } 357 } 358 359 bool NetworkStats::ReadComplete(int result) { 360 DCHECK(socket_.get()); 361 DCHECK_NE(net::ERR_IO_PENDING, result); 362 if (result < 0) { 363 // Something is wrong, finish the test. 364 read_buffer_ = NULL; 365 TestPhaseComplete(READ_FAILED, result); 366 return true; 367 } 368 369 std::string encoded_message(read_buffer_->data(), 370 read_buffer_->data() + result); 371 read_buffer_ = NULL; 372 ProbePacket probe_packet; 373 if (!probe_message_.ParseInput(encoded_message, &probe_packet)) 374 return false; 375 // Discard if the packet is for a different test. 376 if (probe_packet.group_id() != current_test_index_) 377 return false; 378 379 // Whether all packets in the current test have been received. 380 bool current_test_complete = false; 381 switch (probe_packet.header().type()) { 382 case ProbePacket_Type_HELLO_REPLY: 383 token_ = probe_packet.token(); 384 if (current_test_index_ == 0) 385 test_sequence_.push_back(START_PACKET_TEST); 386 current_test_complete = true; 387 break; 388 case ProbePacket_Type_PROBE_REPLY: 389 current_test_complete = UpdateReception(probe_packet); 390 break; 391 default: 392 DVLOG(1) << "Received unexpected packet type: " 393 << probe_packet.header().type(); 394 } 395 396 if (!current_test_complete) { 397 // All packets have not been received for the current test. 398 return false; 399 } 400 // All packets are received for the current test. 401 // Read completes if all tests are done (if TestPhaseComplete didn't start 402 // another test). 403 return TestPhaseComplete(SUCCESS, net::OK); 404 } 405 406 bool NetworkStats::UpdateReception(const ProbePacket& probe_packet) { 407 uint32 packet_index = probe_packet.packet_index(); 408 if (packet_index >= packet_rtt_.size()) 409 return false; 410 packets_received_mask_.set(packet_index); 411 TestType test_type = test_sequence_[current_test_index_]; 412 uint32 received_packets = packets_received_mask_.count(); 413 414 // Now() has resolution ~1-15ms. HighResNow() has high resolution but it 415 // is warned not to use it unless necessary. 416 base::TimeTicks current_time = base::TimeTicks::Now(); 417 last_arrival_time_ = current_time; 418 if (first_arrival_time_.is_null()) 419 first_arrival_time_ = current_time; 420 421 // Need to do this after updating the last_arrival_time_ since NAT_BIND_TEST 422 // and PACKET_SIZE_TEST record the SendToLastRecvDelay. 423 if (test_type == NAT_BIND_TEST) { 424 return received_packets >= maximum_NAT_packets_; 425 } 426 if (test_type == PACKET_SIZE_TEST) { 427 return received_packets >= kMaximumPacketSizeTestPackets; 428 } 429 430 base::TimeDelta rtt = 431 current_time - probe_request_time_ - 432 base::TimeDelta::FromMicroseconds(std::max( 433 static_cast<int64>(0), probe_packet.server_processing_micros())); 434 base::TimeDelta min_rtt = base::TimeDelta::FromMicroseconds(1L); 435 packet_rtt_[packet_index] = (rtt >= min_rtt) ? rtt : min_rtt; 436 437 if (received_packets < maximum_sequential_packets_) 438 return false; 439 // All packets in the current test are received. 440 inter_arrival_time_ = (last_arrival_time_ - first_arrival_time_) / 441 std::max(1U, (received_packets - 1)); 442 if (test_type == START_PACKET_TEST) { 443 test_sequence_.push_back(PACKET_SIZE_TEST); 444 test_sequence_.push_back(TOKEN_REQUEST); 445 // No need to add TOKEN_REQUEST here when all packets are received. 446 test_sequence_.push_back(base::RandInt(0, 1) ? PACED_PACKET_TEST 447 : NON_PACED_PACKET_TEST); 448 test_sequence_.push_back(TOKEN_REQUEST); 449 test_sequence_.push_back(NAT_BIND_TEST); 450 test_sequence_.push_back(TOKEN_REQUEST); 451 } 452 return true; 453 } 454 455 int NetworkStats::SendData(const std::string& output) { 456 if (write_buffer_.get() || !socket_.get() || 457 write_state_ == WRITE_STATE_WRITE_PENDING) { 458 return net::ERR_UNEXPECTED; 459 } 460 scoped_refptr<net::StringIOBuffer> buffer(new net::StringIOBuffer(output)); 461 write_buffer_ = new net::DrainableIOBuffer(buffer.get(), buffer->size()); 462 463 int bytes_written = socket_->Write( 464 write_buffer_.get(), 465 write_buffer_->BytesRemaining(), 466 base::Bind(&NetworkStats::OnWriteComplete, weak_factory_.GetWeakPtr())); 467 if (bytes_written < 0) { 468 if (bytes_written == net::ERR_IO_PENDING) 469 write_state_ = WRITE_STATE_WRITE_PENDING; 470 return bytes_written; 471 } 472 UpdateSendBuffer(bytes_written); 473 return net::OK; 474 } 475 476 void NetworkStats::OnWriteComplete(int result) { 477 DCHECK_NE(net::ERR_IO_PENDING, result); 478 DCHECK_EQ(WRITE_STATE_WRITE_PENDING, write_state_); 479 write_state_ = WRITE_STATE_IDLE; 480 if (result < 0 || !socket_.get() || write_buffer_ == NULL) { 481 TestPhaseComplete(WRITE_FAILED, result); 482 return; 483 } 484 UpdateSendBuffer(result); 485 } 486 487 void NetworkStats::UpdateSendBuffer(int bytes_sent) { 488 write_buffer_->DidConsume(bytes_sent); 489 DCHECK_EQ(write_buffer_->BytesRemaining(), 0); 490 DCHECK_EQ(WRITE_STATE_IDLE, write_state_); 491 write_buffer_ = NULL; 492 } 493 494 void NetworkStats::StartReadDataTimer(uint32 seconds, uint32 test_index) { 495 base::MessageLoop::current()->PostDelayedTask( 496 FROM_HERE, 497 base::Bind(&NetworkStats::OnReadDataTimeout, 498 weak_factory_.GetWeakPtr(), 499 test_index), 500 base::TimeDelta::FromSeconds(seconds)); 501 } 502 503 void NetworkStats::OnReadDataTimeout(uint32 test_index) { 504 // If the current_test_index_ has changed since we set the timeout, 505 // the current test has been completed, so do nothing. 506 if (test_index != current_test_index_) 507 return; 508 // If test_type is TOKEN_REQUEST, it will do nothing but call 509 // TestPhaseComplete(). 510 TestType test_type = test_sequence_[current_test_index_]; 511 512 uint32 received_packets = packets_received_mask_.count(); 513 if (received_packets >= 2) { 514 inter_arrival_time_ = 515 (last_arrival_time_ - first_arrival_time_) / (received_packets - 1); 516 } 517 // Add other tests if this is START_PACKET_TEST. 518 if (test_type == START_PACKET_TEST) { 519 if (received_packets >= kMinimumReceivedPacketsForPacingTest) { 520 test_sequence_.push_back(TOKEN_REQUEST); 521 test_sequence_.push_back(PACKET_SIZE_TEST); 522 test_sequence_.push_back(TOKEN_REQUEST); 523 test_sequence_.push_back(base::RandInt(0, 1) ? PACED_PACKET_TEST 524 : NON_PACED_PACKET_TEST); 525 } 526 if (received_packets >= kMinimumReceivedPacketsForNATTest) { 527 test_sequence_.push_back(TOKEN_REQUEST); 528 test_sequence_.push_back(NAT_BIND_TEST); 529 test_sequence_.push_back(TOKEN_REQUEST); 530 } 531 } 532 TestPhaseComplete(READ_TIMED_OUT, net::ERR_FAILED); 533 } 534 535 bool NetworkStats::TestPhaseComplete(Status status, int result) { 536 // If there is no valid token, do nothing and delete self. 537 // This includes all connection error, name resolve error, etc. 538 if (write_state_ == WRITE_STATE_WRITE_PENDING) { 539 UMA_HISTOGRAM_BOOLEAN("NetConnectivity5.TestFailed.WritePending", true); 540 } else if (status == SUCCESS || status == READ_TIMED_OUT) { 541 TestType current_test = test_sequence_[current_test_index_]; 542 DCHECK_LT(current_test, TEST_TYPE_MAX); 543 if (current_test != TOKEN_REQUEST) { 544 RecordHistograms(current_test); 545 } else if (current_test_index_ > 0) { 546 if (test_sequence_[current_test_index_ - 1] == NAT_BIND_TEST) { 547 // We record the NATTestReceivedHistograms after the succeeding 548 // TokenRequest. 549 RecordNATTestReceivedHistograms(status); 550 } else if (test_sequence_[current_test_index_ - 1] == PACKET_SIZE_TEST) { 551 // We record the PacketSizeTestReceivedHistograms after the succeeding 552 // TokenRequest. 553 RecordPacketSizeTestReceivedHistograms(status); 554 } 555 } 556 557 // Move to the next test. 558 current_test = GetNextTest(); 559 if (current_test_index_ <= maximum_tests_ && current_test < TEST_TYPE_MAX) { 560 DVLOG(1) << "NetworkStat: Start Probe test: " << current_test; 561 base::MessageLoop::current()->PostTask( 562 FROM_HERE, 563 base::Bind(&NetworkStats::StartOneTest, weak_factory_.GetWeakPtr())); 564 return false; 565 } 566 } 567 568 // All tests are done. 569 DoFinishCallback(result); 570 571 // Close the socket so that there are no more IO operations. 572 if (socket_.get()) 573 socket_->Close(); 574 575 DVLOG(1) << "NetworkStat: schedule delete self at test index " 576 << current_test_index_; 577 delete this; 578 return true; 579 } 580 581 NetworkStats::TestType NetworkStats::GetNextTest() { 582 ++current_test_index_; 583 if (current_test_index_ >= test_sequence_.size()) 584 return TEST_TYPE_MAX; 585 return test_sequence_[current_test_index_]; 586 } 587 588 void NetworkStats::DoFinishCallback(int result) { 589 if (!finished_callback_.is_null()) { 590 net::CompletionCallback callback = finished_callback_; 591 finished_callback_.Reset(); 592 callback.Run(result); 593 } 594 } 595 596 void NetworkStats::RecordHistograms(TestType test_type) { 597 switch (test_type) { 598 case START_PACKET_TEST: 599 case NON_PACED_PACKET_TEST: 600 case PACED_PACKET_TEST: { 601 RecordInterArrivalHistograms(test_type); 602 RecordPacketLossSeriesHistograms(test_type); 603 RecordPacketsReceivedHistograms(test_type); 604 // Only record RTT for these packet indices. 605 uint32 rtt_indices[] = {0, 1, 2, 9, 19}; 606 for (uint32 i = 0; i < arraysize(rtt_indices); ++i) { 607 if (rtt_indices[i] < packet_rtt_.size()) 608 RecordRTTHistograms(test_type, rtt_indices[i]); 609 } 610 RecordSendToLastRecvDelayHistograms(test_type); 611 return; 612 } 613 case NAT_BIND_TEST: 614 RecordSendToLastRecvDelayHistograms(test_type); 615 return; 616 case PACKET_SIZE_TEST: 617 // No need to record RTT for PacketSizeTest. 618 return; 619 default: 620 DVLOG(1) << "Unexpected test type " << test_type 621 << " in RecordHistograms."; 622 } 623 } 624 625 void NetworkStats::RecordInterArrivalHistograms(TestType test_type) { 626 DCHECK_NE(test_type, PACKET_SIZE_TEST); 627 std::string histogram_name = 628 base::StringPrintf("NetConnectivity5.%s.Sent%d.PacketDelay.%d.%dB", 629 kTestName[test_type], 630 maximum_sequential_packets_, 631 histogram_port_, 632 probe_packet_bytes_); 633 // Record the time normalized to 20 packet inter-arrivals. 634 DynamicHistogramTimes(histogram_name, inter_arrival_time_ * 20); 635 } 636 637 void NetworkStats::RecordPacketsReceivedHistograms(TestType test_type) { 638 DCHECK_NE(test_type, PACKET_SIZE_TEST); 639 const char* test_name = kTestName[test_type]; 640 std::string histogram_prefix = base::StringPrintf( 641 "NetConnectivity5.%s.Sent%d.", test_name, maximum_sequential_packets_); 642 std::string histogram_suffix = 643 base::StringPrintf(".%d.%dB", histogram_port_, probe_packet_bytes_); 644 std::string name = histogram_prefix + "GotAPacket" + histogram_suffix; 645 base::HistogramBase* histogram_pointer = base::BooleanHistogram::FactoryGet( 646 name, base::HistogramBase::kUmaTargetedHistogramFlag); 647 histogram_pointer->Add(packets_received_mask_.any()); 648 649 DynamicHistogramEnumeration( 650 histogram_prefix + "PacketsRecv" + histogram_suffix, 651 packets_received_mask_.count(), 652 maximum_sequential_packets_ + 1); 653 654 if (!packets_received_mask_.any()) 655 return; 656 657 base::HistogramBase* received_nth_packet_histogram = 658 base::Histogram::FactoryGet( 659 histogram_prefix + "RecvNthPacket" + histogram_suffix, 660 1, 661 maximum_sequential_packets_ + 1, 662 maximum_sequential_packets_ + 2, 663 base::HistogramBase::kUmaTargetedHistogramFlag); 664 665 int count = 0; 666 for (size_t j = 0; j < maximum_sequential_packets_; ++j) { 667 int packet_number = j + 1; 668 if (packets_received_mask_.test(j)) { 669 received_nth_packet_histogram->Add(packet_number); 670 ++count; 671 } 672 std::string histogram_name = 673 base::StringPrintf("%sNumRecvFromFirst%02dPackets%s", 674 histogram_prefix.c_str(), 675 packet_number, 676 histogram_suffix.c_str()); 677 DynamicHistogramEnumeration(histogram_name, count, packet_number + 1); 678 } 679 } 680 681 void NetworkStats::RecordNATTestReceivedHistograms(Status status) { 682 const char* test_name = kTestName[NAT_BIND_TEST]; 683 bool test_result = status == SUCCESS; 684 std::string middle_name = test_result ? "Connectivity.Success" 685 : "Connectivity.Failure"; 686 // Record whether the HelloRequest got reply successfully. 687 std::string histogram_name = 688 base::StringPrintf("NetConnectivity5.%s.Sent%d.%s.%d.%dB", 689 test_name, 690 maximum_NAT_packets_, 691 middle_name.c_str(), 692 histogram_port_, 693 probe_packet_bytes_); 694 uint32 bucket_count = std::min(maximum_NAT_idle_seconds_ + 2, 50U); 695 DynamicHistogramCounts(histogram_name, 696 pacing_interval_.InSeconds(), 697 1, 698 maximum_NAT_idle_seconds_ + 1, 699 bucket_count); 700 701 // Record the NAT bind result only if the HelloRequest successfully got the 702 // token and the first NAT test packet is received. 703 if (!test_result || !packets_received_mask_.test(0)) 704 return; 705 706 middle_name = packets_received_mask_.test(1) ? "Bind.Success" 707 : "Bind.Failure"; 708 histogram_name = base::StringPrintf("NetConnectivity5.%s.Sent%d.%s.%d.%dB", 709 test_name, 710 maximum_NAT_packets_, 711 middle_name.c_str(), 712 histogram_port_, 713 probe_packet_bytes_); 714 DynamicHistogramCounts(histogram_name, 715 pacing_interval_.InSeconds(), 716 1, 717 maximum_NAT_idle_seconds_ + 1, 718 bucket_count); 719 } 720 721 void NetworkStats::RecordPacketSizeTestReceivedHistograms(Status status) { 722 const char* test_name = kTestName[PACKET_SIZE_TEST]; 723 bool test_result = (status == SUCCESS && packets_received_mask_.test(0)); 724 std::string middle_name = test_result ? "Connectivity.Success" 725 : "Connectivity.Failure"; 726 // Record whether the HelloRequest got reply successfully. 727 std::string histogram_name = 728 base::StringPrintf("NetConnectivity5.%s.%s.%d", 729 test_name, 730 middle_name.c_str(), 731 histogram_port_); 732 base::HistogramBase* histogram_pointer = base::LinearHistogram::FactoryGet( 733 histogram_name, kProbePacketBytes[kPacketSizeChoices - 1], 734 ProbeMessage::kMaxProbePacketBytes, 60, 735 base::HistogramBase::kUmaTargetedHistogramFlag); 736 histogram_pointer->Add(bytes_for_packet_size_test_); 737 } 738 739 void NetworkStats::RecordPacketLossSeriesHistograms(TestType test_type) { 740 DCHECK_NE(test_type, PACKET_SIZE_TEST); 741 const char* test_name = kTestName[test_type]; 742 // Build "NetConnectivity5.<TestName>.First6.SeriesRecv.<port>.<probe_size>" 743 // histogram name. Total 3(tests) x 12 histograms. 744 std::string series_acked_histogram_name = 745 base::StringPrintf("NetConnectivity5.%s.First6.SeriesRecv.%d.%dB", 746 test_name, 747 histogram_port_, 748 probe_packet_bytes_); 749 uint32 histogram_boundary = 1 << kCorrelatedLossPacketCount; 750 uint32 correlated_packet_mask = 751 (histogram_boundary - 1) & packets_received_mask_.to_ulong(); 752 DynamicHistogramEnumeration( 753 series_acked_histogram_name, correlated_packet_mask, histogram_boundary); 754 755 // If we are running without a proxy, we'll generate an extra histogram with 756 // the ".NoProxy" suffix. 757 if (!has_proxy_server_) { 758 series_acked_histogram_name.append(".NoProxy"); 759 DynamicHistogramEnumeration(series_acked_histogram_name, 760 correlated_packet_mask, 761 histogram_boundary); 762 } 763 } 764 765 void NetworkStats::RecordRTTHistograms(TestType test_type, uint32 index) { 766 DCHECK_NE(test_type, PACKET_SIZE_TEST); 767 DCHECK_LT(index, packet_rtt_.size()); 768 769 if (!packets_received_mask_.test(index)) 770 return; // Probe packet never received. 771 772 std::string rtt_histogram_name = base::StringPrintf( 773 "NetConnectivity5.%s.Sent%d.Success.RTT.Packet%02d.%d.%dB", 774 kTestName[test_type], 775 maximum_sequential_packets_, 776 index + 1, 777 histogram_port_, 778 probe_packet_bytes_); 779 DynamicHistogramTimes(rtt_histogram_name, packet_rtt_[index]); 780 } 781 782 void NetworkStats::RecordSendToLastRecvDelayHistograms(TestType test_type) { 783 DCHECK_NE(test_type, PACKET_SIZE_TEST); 784 if (packets_received_mask_.count() < 2) 785 return; // Too few packets are received. 786 uint32 packets_sent = test_type == NAT_BIND_TEST 787 ? maximum_NAT_packets_ : maximum_sequential_packets_; 788 std::string histogram_name = base::StringPrintf( 789 "NetConnectivity5.%s.Sent%d.SendToLastRecvDelay.%d.%dB", 790 kTestName[test_type], 791 packets_sent, 792 histogram_port_, 793 probe_packet_bytes_); 794 base::TimeDelta send_to_last_recv_time = 795 std::max(last_arrival_time_ - probe_request_time_ - 796 pacing_interval_ * (packets_sent - 1), 797 base::TimeDelta::FromMilliseconds(0)); 798 DynamicHistogramTimes(histogram_name, send_to_last_recv_time); 799 } 800 801 // ProxyDetector methods and members. 802 ProxyDetector::ProxyDetector(net::ProxyService* proxy_service, 803 const net::HostPortPair& server_address, 804 OnResolvedCallback callback) 805 : proxy_service_(proxy_service), 806 server_address_(server_address), 807 callback_(callback), 808 has_pending_proxy_resolution_(false) {} 809 810 ProxyDetector::~ProxyDetector() { 811 CHECK(!has_pending_proxy_resolution_); 812 } 813 814 void ProxyDetector::StartResolveProxy() { 815 std::string url = 816 base::StringPrintf("https://%s", server_address_.ToString().c_str()); 817 GURL gurl(url); 818 819 has_pending_proxy_resolution_ = true; 820 DCHECK(proxy_service_); 821 int rv = proxy_service_->ResolveProxy( 822 gurl, 823 &proxy_info_, 824 base::Bind(&ProxyDetector::OnResolveProxyComplete, 825 base::Unretained(this)), 826 NULL, 827 net::BoundNetLog()); 828 if (rv != net::ERR_IO_PENDING) 829 OnResolveProxyComplete(rv); 830 } 831 832 void ProxyDetector::OnResolveProxyComplete(int result) { 833 has_pending_proxy_resolution_ = false; 834 bool has_proxy_server = 835 (result == net::OK && proxy_info_.proxy_server().is_valid() && 836 !proxy_info_.proxy_server().is_direct()); 837 838 OnResolvedCallback callback = callback_; 839 BrowserThread::PostTask( 840 BrowserThread::IO, FROM_HERE, base::Bind(callback, has_proxy_server)); 841 842 // TODO(rtenneti): Will we leak if ProxyResolve is cancelled (or proxy 843 // resolution never completes). 844 delete this; 845 } 846 847 void CollectNetworkStats(const std::string& network_stats_server, 848 IOThread* io_thread) { 849 if (network_stats_server.empty()) 850 return; 851 852 // If we are not on IO Thread, then post a task to call CollectNetworkStats on 853 // IO Thread. 854 if (!BrowserThread::CurrentlyOn(BrowserThread::IO)) { 855 BrowserThread::PostTask( 856 BrowserThread::IO, 857 FROM_HERE, 858 base::Bind(&CollectNetworkStats, network_stats_server, io_thread)); 859 return; 860 } 861 862 DCHECK(BrowserThread::CurrentlyOn(BrowserThread::IO)); 863 864 if (net::NetworkChangeNotifier::IsOffline()) { 865 return; 866 } 867 868 CR_DEFINE_STATIC_LOCAL(scoped_refptr<base::FieldTrial>, trial, ()); 869 static bool collect_stats = false; 870 871 if (!trial.get()) { 872 // Set up a field trial to collect network stats for UDP. 873 const base::FieldTrial::Probability kDivisor = 1000; 874 875 // Enable the connectivity testing for 0.5% of the users in stable channel. 876 base::FieldTrial::Probability probability_per_group = kDivisor / 200; 877 878 chrome::VersionInfo::Channel channel = chrome::VersionInfo::GetChannel(); 879 if (channel == chrome::VersionInfo::CHANNEL_CANARY) { 880 // Enable the connectivity testing for 50% of the users in canary channel. 881 probability_per_group = kDivisor / 2; 882 } else if (channel == chrome::VersionInfo::CHANNEL_DEV) { 883 // Enable the connectivity testing for 10% of the users in dev channel. 884 probability_per_group = kDivisor / 10; 885 } else if (channel == chrome::VersionInfo::CHANNEL_BETA) { 886 // Enable the connectivity testing for 1% of the users in beta channel. 887 probability_per_group = kDivisor / 100; 888 } 889 890 // After July 31, 2014 builds, it will always be in default group 891 // (disable_network_stats). 892 trial = base::FieldTrialList::FactoryGetFieldTrial( 893 "NetworkConnectivity", kDivisor, "disable_network_stats", 894 2014, 7, 31, base::FieldTrial::SESSION_RANDOMIZED, NULL); 895 896 // Add option to collect_stats for NetworkConnectivity. 897 int collect_stats_group = 898 trial->AppendGroup("collect_stats", probability_per_group); 899 if (trial->group() == collect_stats_group) 900 collect_stats = true; 901 } 902 903 if (!collect_stats) 904 return; 905 906 // Run test kMaxNumberOfTests times. 907 const size_t kMaxNumberOfTests = INT_MAX; 908 static size_t number_of_tests_done = 0; 909 if (number_of_tests_done > kMaxNumberOfTests) 910 return; 911 ++number_of_tests_done; 912 913 net::HostResolver* host_resolver = io_thread->globals()->host_resolver.get(); 914 DCHECK(host_resolver); 915 916 uint32 port_index = base::RandInt(0, arraysize(kPorts) - 1); 917 uint16 histogram_port = kPorts[port_index]; 918 net::HostPortPair server_address(network_stats_server, histogram_port); 919 920 net::ProxyService* proxy_service = 921 io_thread->globals()->system_proxy_service.get(); 922 DCHECK(proxy_service); 923 924 ProxyDetector::OnResolvedCallback callback = base::Bind( 925 &StartNetworkStatsTest, host_resolver, server_address, histogram_port); 926 927 ProxyDetector* proxy_client = 928 new ProxyDetector(proxy_service, server_address, callback); 929 proxy_client->StartResolveProxy(); 930 } 931 932 void StartNetworkStatsTest(net::HostResolver* host_resolver, 933 const net::HostPortPair& server_address, 934 uint16 histogram_port, 935 bool has_proxy_server) { 936 int probe_choice = base::RandInt(0, kPacketSizeChoices - 1); 937 938 DCHECK_LE(ProbeMessage::kMaxProbePacketBytes, kMaxMessageSize); 939 // Pick a packet size between 1200 and kMaxProbePacketBytes bytes. 940 uint32 bytes_for_packet_size_test = 941 base::RandInt(kProbePacketBytes[kPacketSizeChoices - 1], 942 ProbeMessage::kMaxProbePacketBytes); 943 944 // |udp_stats_client| is owned and deleted in the class NetworkStats. 945 NetworkStats* udp_stats_client = 946 new NetworkStats(net::ClientSocketFactory::GetDefaultFactory()); 947 udp_stats_client->Start(host_resolver, 948 server_address, 949 histogram_port, 950 has_proxy_server, 951 kProbePacketBytes[probe_choice], 952 bytes_for_packet_size_test, 953 net::CompletionCallback()); 954 } 955 956 } // namespace chrome_browser_net 957
