Merge branch 'cronetfix' into status

6 files changed, 324 insertions, 28 deletions

diff --git a/test/core/iomgr/BUILD b/test/core/iomgr/BUILD
index 002671a5fa..675d9e6278 100644
--- a/test/core/iomgr/BUILD
+++ b/test/core/iomgr/BUILD
@@ -247,6 +247,19 @@ grpc_cc_test(
 )
 
 grpc_cc_test(
+    name = "buffer_list_test",
+    srcs = ["buffer_list_test.cc"],
+    language = "C++",
+    deps = [
+        "//:gpr",
+        "//:grpc",
+        "//test/core/util:gpr_test_util",
+        "//test/core/util:grpc_test_util",
+    ],
+)
+
+
+grpc_cc_test(
     name = "tcp_server_posix_test",
     srcs = ["tcp_server_posix_test.cc"],
     language = "C++",
diff --git a/test/core/iomgr/buffer_list_test.cc b/test/core/iomgr/buffer_list_test.cc
new file mode 100644
index 0000000000..c7f30fa092
--- /dev/null
+++ b/test/core/iomgr/buffer_list_test.cc
@@ -0,0 +1,111 @@
+/*
+ *
+ * Copyright 2018 gRPC authors.
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *     http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ *
+ */
+
+#include "src/core/lib/iomgr/port.h"
+
+#include "src/core/lib/iomgr/buffer_list.h"
+
+#include <grpc/grpc.h>
+
+#include "test/core/util/test_config.h"
+
+#ifdef GRPC_LINUX_ERRQUEUE
+
+static void TestShutdownFlushesListVerifier(void* arg,
+                                            grpc_core::Timestamps* ts,
+                                            grpc_error* error) {
+  GPR_ASSERT(error == GRPC_ERROR_NONE);
+  GPR_ASSERT(arg != nullptr);
+  gpr_atm* done = reinterpret_cast<gpr_atm*>(arg);
+  gpr_atm_rel_store(done, static_cast<gpr_atm>(1));
+}
+
+/** Tests that all TracedBuffer elements in the list are flushed out on
+ * shutdown.
+ * Also tests that arg is passed correctly.
+ */
+static void TestShutdownFlushesList() {
+  grpc_core::grpc_tcp_set_write_timestamps_callback(
+      TestShutdownFlushesListVerifier);
+  grpc_core::TracedBuffer* list = nullptr;
+#define NUM_ELEM 5
+  gpr_atm verifier_called[NUM_ELEM];
+  for (auto i = 0; i < NUM_ELEM; i++) {
+    gpr_atm_rel_store(&verifier_called[i], static_cast<gpr_atm>(0));
+    grpc_core::TracedBuffer::AddNewEntry(
+        &list, i, static_cast<void*>(&verifier_called[i]));
+  }
+  grpc_core::TracedBuffer::Shutdown(&list, GRPC_ERROR_NONE);
+  GPR_ASSERT(list == nullptr);
+  for (auto i = 0; i < NUM_ELEM; i++) {
+    GPR_ASSERT(gpr_atm_acq_load(&verifier_called[i]) ==
+               static_cast<gpr_atm>(1));
+  }
+}
+
+static void TestVerifierCalledOnAckVerifier(void* arg,
+                                            grpc_core::Timestamps* ts,
+                                            grpc_error* error) {
+  GPR_ASSERT(error == GRPC_ERROR_NONE);
+  GPR_ASSERT(arg != nullptr);
+  GPR_ASSERT(ts->acked_time.clock_type == GPR_CLOCK_REALTIME);
+  GPR_ASSERT(ts->acked_time.tv_sec == 123);
+  GPR_ASSERT(ts->acked_time.tv_nsec == 456);
+  gpr_atm* done = reinterpret_cast<gpr_atm*>(arg);
+  gpr_atm_rel_store(done, static_cast<gpr_atm>(1));
+}
+
+/** Tests that the timestamp verifier is called on an ACK timestamp.
+ */
+static void TestVerifierCalledOnAck() {
+  struct sock_extended_err serr;
+  serr.ee_data = 213;
+  serr.ee_info = grpc_core::SCM_TSTAMP_ACK;
+  struct grpc_core::scm_timestamping tss;
+  tss.ts[0].tv_sec = 123;
+  tss.ts[0].tv_nsec = 456;
+  grpc_core::grpc_tcp_set_write_timestamps_callback(
+      TestVerifierCalledOnAckVerifier);
+  grpc_core::TracedBuffer* list = nullptr;
+  gpr_atm verifier_called;
+  gpr_atm_rel_store(&verifier_called, static_cast<gpr_atm>(0));
+  grpc_core::TracedBuffer::AddNewEntry(&list, 213, &verifier_called);
+  grpc_core::TracedBuffer::ProcessTimestamp(&list, &serr, &tss);
+  GPR_ASSERT(gpr_atm_acq_load(&verifier_called) == static_cast<gpr_atm>(1));
+  GPR_ASSERT(list == nullptr);
+  grpc_core::TracedBuffer::Shutdown(&list, GRPC_ERROR_NONE);
+}
+
+static void TestTcpBufferList() {
+  TestVerifierCalledOnAck();
+  TestShutdownFlushesList();
+}
+
+int main(int argc, char** argv) {
+  grpc_test_init(argc, argv);
+  grpc_init();
+  TestTcpBufferList();
+  grpc_shutdown();
+  return 0;
+}
+
+#else /* GRPC_LINUX_ERRQUEUE */
+
+int main(int argc, char** argv) { return 0; }
+
+#endif /* GRPC_LINUX_ERRQUEUE */
diff --git a/test/core/iomgr/endpoint_tests.cc b/test/core/iomgr/endpoint_tests.cc
index 8db8ac5ed6..a9e8ba86c5 100644
--- a/test/core/iomgr/endpoint_tests.cc
+++ b/test/core/iomgr/endpoint_tests.cc
@@ -150,8 +150,8 @@ static void read_and_write_test_write_handler(void* data, grpc_error* error) {
                                &state->current_write_data);
       grpc_slice_buffer_reset_and_unref(&state->outgoing);
       grpc_slice_buffer_addn(&state->outgoing, slices, nslices);
-      grpc_endpoint_write(state->write_ep, &state->outgoing,
-                          &state->done_write);
+      grpc_endpoint_write(state->write_ep, &state->outgoing, &state->done_write,
+                          nullptr);
       gpr_free(slices);
       return;
     }
@@ -294,7 +294,8 @@ static void multiple_shutdown_test(grpc_endpoint_test_config config) {
   grpc_slice_buffer_add(&slice_buffer, grpc_slice_from_copied_string("a"));
   grpc_endpoint_write(f.client_ep, &slice_buffer,
                       GRPC_CLOSURE_CREATE(inc_on_failure, &fail_count,
-                                          grpc_schedule_on_exec_ctx));
+                                          grpc_schedule_on_exec_ctx),
+                      nullptr);
   wait_for_fail_count(&fail_count, 3);
   grpc_endpoint_shutdown(f.client_ep,
                          GRPC_ERROR_CREATE_FROM_STATIC_STRING("Test Shutdown"));
diff --git a/test/core/iomgr/ios/CFStreamTests/Podfile b/test/core/iomgr/ios/CFStreamTests/Podfile
index 630168a363..e6ec66d549 100644
--- a/test/core/iomgr/ios/CFStreamTests/Podfile
+++ b/test/core/iomgr/ios/CFStreamTests/Podfile
@@ -9,6 +9,7 @@ GRPC_LOCAL_SRC = '../../../../..'
 # Install the dependencies in the main target plus all test targets.
 target 'CFStreamTests' do
   pod 'gRPC-Core/CFStream-Implementation', :path => GRPC_LOCAL_SRC
+  pod 'BoringSSL-GRPC', :podspec => "#{GRPC_LOCAL_SRC}/src/objective-c", :inhibit_warnings => true
 end
 
 pre_install do |installer|
diff --git a/test/core/iomgr/tcp_posix_test.cc b/test/core/iomgr/tcp_posix_test.cc
index 3e87831e44..6447cc234d 100644
--- a/test/core/iomgr/tcp_posix_test.cc
+++ b/test/core/iomgr/tcp_posix_test.cc
@@ -36,6 +36,9 @@
 #include <grpc/support/time.h>
 
 #include "src/core/lib/gpr/useful.h"
+#include "src/core/lib/iomgr/buffer_list.h"
+#include "src/core/lib/iomgr/ev_posix.h"
+#include "src/core/lib/iomgr/sockaddr_posix.h"
 #include "src/core/lib/slice/slice_internal.h"
 #include "test/core/iomgr/endpoint_tests.h"
 #include "test/core/util/test_config.h"
@@ -68,6 +71,43 @@ static void create_sockets(int sv[2]) {
   GPR_ASSERT(fcntl(sv[1], F_SETFL, flags | O_NONBLOCK) == 0);
 }
 
+static void create_inet_sockets(int sv[2]) {
+  /* Prepare listening socket */
+  struct sockaddr_in addr;
+  memset(&addr, 0, sizeof(struct sockaddr_in));
+  addr.sin_family = AF_INET;
+  int sock = socket(AF_INET, SOCK_STREAM, 0);
+  GPR_ASSERT(sock);
+  GPR_ASSERT(bind(sock, (sockaddr*)&addr, sizeof(sockaddr_in)) == 0);
+  listen(sock, 1);
+
+  /* Prepare client socket and connect to server */
+  socklen_t len = sizeof(sockaddr_in);
+  GPR_ASSERT(getsockname(sock, (sockaddr*)&addr, &len) == 0);
+
+  int client = socket(AF_INET, SOCK_STREAM, 0);
+  GPR_ASSERT(client);
+  int ret;
+  do {
+    ret = connect(client, (sockaddr*)&addr, sizeof(sockaddr_in));
+  } while (ret == -1 && errno == EINTR);
+
+  /* Accept client connection */
+  len = sizeof(socklen_t);
+  int server;
+  do {
+    server = accept(sock, (sockaddr*)&addr, (socklen_t*)&len);
+  } while (server == -1 && errno == EINTR);
+  GPR_ASSERT(server != -1);
+
+  sv[0] = server;
+  sv[1] = client;
+  int flags = fcntl(sv[0], F_GETFL, 0);
+  GPR_ASSERT(fcntl(sv[0], F_SETFL, flags | O_NONBLOCK) == 0);
+  flags = fcntl(sv[1], F_GETFL, 0);
+  GPR_ASSERT(fcntl(sv[1], F_SETFL, flags | O_NONBLOCK) == 0);
+}
+
 static ssize_t fill_socket(int fd) {
   ssize_t write_bytes;
   ssize_t total_bytes = 0;
@@ -289,11 +329,10 @@ static grpc_slice* allocate_blocks(size_t num_bytes, size_t slice_size,
 
 static void write_done(void* user_data /* write_socket_state */,
                        grpc_error* error) {
+  GPR_ASSERT(error == GRPC_ERROR_NONE);
   struct write_socket_state* state =
       static_cast<struct write_socket_state*>(user_data);
-  gpr_log(GPR_INFO, "Write done callback called");
   gpr_mu_lock(g_mu);
-  gpr_log(GPR_INFO, "Signalling write done");
   state->write_done = 1;
   GPR_ASSERT(
       GRPC_LOG_IF_ERROR("pollset_kick", grpc_pollset_kick(g_pollset, nullptr)));
@@ -340,10 +379,24 @@ void drain_socket_blocking(int fd, size_t num_bytes, size_t read_size) {
   gpr_free(buf);
 }
 
+/* Verifier for timestamps callback for write_test */
+void timestamps_verifier(void* arg, grpc_core::Timestamps* ts,
+                         grpc_error* error) {
+  GPR_ASSERT(error == GRPC_ERROR_NONE);
+  GPR_ASSERT(arg != nullptr);
+  GPR_ASSERT(ts->sendmsg_time.clock_type == GPR_CLOCK_REALTIME);
+  GPR_ASSERT(ts->scheduled_time.clock_type == GPR_CLOCK_REALTIME);
+  GPR_ASSERT(ts->acked_time.clock_type == GPR_CLOCK_REALTIME);
+  gpr_atm* done_timestamps = (gpr_atm*)arg;
+  gpr_atm_rel_store(done_timestamps, static_cast<gpr_atm>(1));
+}
+
 /* Write to a socket using the grpc_tcp API, then drain it directly.
    Note that if the write does not complete immediately we need to drain the
-   socket in parallel with the read. */
-static void write_test(size_t num_bytes, size_t slice_size) {
+   socket in parallel with the read. If collect_timestamps is true, it will
+   try to get timestamps for the write. */
+static void write_test(size_t num_bytes, size_t slice_size,
+                       bool collect_timestamps) {
   int sv[2];
   grpc_endpoint* ep;
   struct write_socket_state state;
@@ -356,19 +409,27 @@ static void write_test(size_t num_bytes, size_t slice_size) {
       grpc_timespec_to_millis_round_up(grpc_timeout_seconds_to_deadline(20));
   grpc_core::ExecCtx exec_ctx;
 
+  if (collect_timestamps && !grpc_event_engine_can_track_errors()) {
+    return;
+  }
+
   gpr_log(GPR_INFO,
           "Start write test with %" PRIuPTR " bytes, slice size %" PRIuPTR,
           num_bytes, slice_size);
 
-  create_sockets(sv);
+  if (collect_timestamps) {
+    create_inet_sockets(sv);
+  } else {
+    create_sockets(sv);
+  }
 
   grpc_arg a[1];
   a[0].key = const_cast<char*>(GRPC_ARG_TCP_READ_CHUNK_SIZE);
   a[0].type = GRPC_ARG_INTEGER,
   a[0].value.integer = static_cast<int>(slice_size);
   grpc_channel_args args = {GPR_ARRAY_SIZE(a), a};
-  ep = grpc_tcp_create(grpc_fd_create(sv[1], "write_test", false), &args,
-                       "test");
+  ep = grpc_tcp_create(grpc_fd_create(sv[1], "write_test", collect_timestamps),
+                       &args, "test");
   grpc_endpoint_add_to_pollset(ep, g_pollset);
 
   state.ep = ep;
@@ -381,18 +442,26 @@ static void write_test(size_t num_bytes, size_t slice_size) {
   GRPC_CLOSURE_INIT(&write_done_closure, write_done, &state,
                     grpc_schedule_on_exec_ctx);
 
-  grpc_endpoint_write(ep, &outgoing, &write_done_closure);
+  gpr_atm done_timestamps;
+  gpr_atm_rel_store(&done_timestamps, static_cast<gpr_atm>(0));
+  grpc_endpoint_write(ep, &outgoing, &write_done_closure,
+                      grpc_event_engine_can_track_errors() && collect_timestamps
+                          ? (void*)&done_timestamps
+                          : nullptr);
   drain_socket_blocking(sv[0], num_bytes, num_bytes);
+  exec_ctx.Flush();
   gpr_mu_lock(g_mu);
   for (;;) {
     grpc_pollset_worker* worker = nullptr;
-    if (state.write_done) {
+    if (state.write_done &&
+        (!(grpc_event_engine_can_track_errors() && collect_timestamps) ||
+         gpr_atm_acq_load(&done_timestamps) == static_cast<gpr_atm>(1))) {
       break;
     }
     GPR_ASSERT(GRPC_LOG_IF_ERROR(
         "pollset_work", grpc_pollset_work(g_pollset, &worker, deadline)));
     gpr_mu_unlock(g_mu);
-
+    exec_ctx.Flush();
     gpr_mu_lock(g_mu);
   }
   gpr_mu_unlock(g_mu);
@@ -497,14 +566,21 @@ void run_tests(void) {
   large_read_test(8192);
   large_read_test(1);
 
-  write_test(100, 8192);
-  write_test(100, 1);
-  write_test(100000, 8192);
-  write_test(100000, 1);
-  write_test(100000, 137);
+  write_test(100, 8192, false);
+  write_test(100, 1, false);
+  write_test(100000, 8192, false);
+  write_test(100000, 1, false);
+  write_test(100000, 137, false);
+
+  write_test(100, 8192, true);
+  write_test(100, 1, true);
+  write_test(100000, 8192, true);
+  write_test(100000, 1, true);
+  write_test(100, 137, true);
 
   for (i = 1; i < 1000; i = GPR_MAX(i + 1, i * 5 / 4)) {
-    write_test(40320, i);
+    write_test(40320, i, false);
+    write_test(40320, i, true);
   }
 
   release_fd_test(100, 8192);
@@ -549,6 +625,7 @@ int main(int argc, char** argv) {
   grpc_closure destroyed;
   grpc_test_init(argc, argv);
   grpc_init();
+  grpc_core::grpc_tcp_set_write_timestamps_callback(timestamps_verifier);
   {
     grpc_core::ExecCtx exec_ctx;
     g_pollset = static_cast<grpc_pollset*>(gpr_zalloc(grpc_pollset_size()));
diff --git a/test/core/iomgr/timer_list_test.cc b/test/core/iomgr/timer_list_test.cc
index b1d919b292..fd65d1abf1 100644
--- a/test/core/iomgr/timer_list_test.cc
+++ b/test/core/iomgr/timer_list_test.cc
@@ -38,6 +38,8 @@ extern grpc_core::TraceFlag grpc_timer_trace;
 extern grpc_core::TraceFlag grpc_timer_check_trace;
 
 static int cb_called[MAX_CB][2];
+static const int64_t kMillisIn25Days = 2160000000;
+static const int64_t kHoursIn25Days = 600;
 
 static void cb(void* arg, grpc_error* error) {
   cb_called[(intptr_t)arg][error == GRPC_ERROR_NONE]++;
@@ -151,17 +153,108 @@ void destruction_test(void) {
   GPR_ASSERT(1 == cb_called[2][0]);
 }
 
-int main(int argc, char** argv) {
-  grpc_test_init(argc, argv);
-  grpc_core::ExecCtx::GlobalInit();
+/* Cleans up a list with pending timers that simulate long-running-services.
+   This test does the following:
+    1) Simulates grpc server start time to 25 days in the past (completed in
+        `main` using TestOnlyGlobalInit())
+    2) Creates 4 timers - one with a deadline 25 days in the future, one just
+        3 milliseconds in future, one way out in the future, and one using the
+        grpc_timespec_to_millis_round_up function to compute a deadline of 25
+        days in the future
+    3) Simulates 4 milliseconds of elapsed time by changing `now` (cached at
+        step 1) to `now+4`
+    4) Shuts down the timer list
+   https://github.com/grpc/grpc/issues/15904 */
+void long_running_service_cleanup_test(void) {
+  grpc_timer timers[4];
   grpc_core::ExecCtx exec_ctx;
-  grpc_determine_iomgr_platform();
-  grpc_iomgr_platform_init();
-  gpr_set_log_verbosity(GPR_LOG_SEVERITY_DEBUG);
-  add_test();
-  destruction_test();
-  grpc_iomgr_platform_shutdown();
+
+  gpr_log(GPR_INFO, "long_running_service_cleanup_test");
+
+  grpc_millis now = grpc_core::ExecCtx::Get()->Now();
+  GPR_ASSERT(now >= kMillisIn25Days);
+  grpc_timer_list_init();
+  grpc_core::testing::grpc_tracer_enable_flag(&grpc_timer_trace);
+  grpc_core::testing::grpc_tracer_enable_flag(&grpc_timer_check_trace);
+  memset(cb_called, 0, sizeof(cb_called));
+
+  grpc_timer_init(
+      &timers[0], now + kMillisIn25Days,
+      GRPC_CLOSURE_CREATE(cb, (void*)(intptr_t)0, grpc_schedule_on_exec_ctx));
+  grpc_timer_init(
+      &timers[1], now + 3,
+      GRPC_CLOSURE_CREATE(cb, (void*)(intptr_t)1, grpc_schedule_on_exec_ctx));
+  grpc_timer_init(
+      &timers[2], GRPC_MILLIS_INF_FUTURE - 1,
+      GRPC_CLOSURE_CREATE(cb, (void*)(intptr_t)2, grpc_schedule_on_exec_ctx));
+
+  gpr_timespec deadline_spec = grpc_millis_to_timespec(
+      now + kMillisIn25Days, gpr_clock_type::GPR_CLOCK_MONOTONIC);
+
+  /* grpc_timespec_to_millis_round_up is how users usually compute a millisecond
+    input value into grpc_timer_init, so we mimic that behavior here */
+  grpc_timer_init(
+      &timers[3], grpc_timespec_to_millis_round_up(deadline_spec),
+      GRPC_CLOSURE_CREATE(cb, (void*)(intptr_t)3, grpc_schedule_on_exec_ctx));
+
+  grpc_core::ExecCtx::Get()->TestOnlySetNow(now + 4);
+  GPR_ASSERT(grpc_timer_check(nullptr) == GRPC_TIMERS_FIRED);
+  grpc_core::ExecCtx::Get()->Flush();
+  GPR_ASSERT(0 == cb_called[0][0]);  // Timer 0 not called
+  GPR_ASSERT(0 == cb_called[0][1]);
+  GPR_ASSERT(0 == cb_called[1][0]);
+  GPR_ASSERT(1 == cb_called[1][1]);  // Timer 1 fired
+  GPR_ASSERT(0 == cb_called[2][0]);  // Timer 2 not called
+  GPR_ASSERT(0 == cb_called[2][1]);
+  GPR_ASSERT(0 == cb_called[3][0]);  // Timer 3 not called
+  GPR_ASSERT(0 == cb_called[3][1]);
+
+  grpc_timer_list_shutdown();
+  grpc_core::ExecCtx::Get()->Flush();
+  /* Timers 0, 2, and 3 were fired with an error during cleanup */
+  GPR_ASSERT(1 == cb_called[0][0]);
+  GPR_ASSERT(0 == cb_called[1][0]);
+  GPR_ASSERT(1 == cb_called[2][0]);
+  GPR_ASSERT(1 == cb_called[3][0]);
+}
+
+int main(int argc, char** argv) {
+  /* Tests with default g_start_time */
+  {
+    grpc_test_init(argc, argv);
+    grpc_core::ExecCtx::GlobalInit();
+    grpc_core::ExecCtx exec_ctx;
+    grpc_determine_iomgr_platform();
+    grpc_iomgr_platform_init();
+    gpr_set_log_verbosity(GPR_LOG_SEVERITY_DEBUG);
+    add_test();
+    destruction_test();
+    grpc_iomgr_platform_shutdown();
+  }
   grpc_core::ExecCtx::GlobalShutdown();
+
+  /* Begin long running service tests */
+  {
+    grpc_test_init(argc, argv);
+    /* Set g_start_time back 25 days. */
+    /* We set g_start_time here in case there are any initialization
+        dependencies that use g_start_time. */
+    gpr_timespec new_start =
+        gpr_time_sub(gpr_now(gpr_clock_type::GPR_CLOCK_MONOTONIC),
+                     gpr_time_from_hours(kHoursIn25Days,
+                                         gpr_clock_type::GPR_CLOCK_MONOTONIC));
+    grpc_core::ExecCtx::TestOnlyGlobalInit(new_start);
+    grpc_core::ExecCtx exec_ctx;
+    grpc_determine_iomgr_platform();
+    grpc_iomgr_platform_init();
+    gpr_set_log_verbosity(GPR_LOG_SEVERITY_DEBUG);
+    long_running_service_cleanup_test();
+    add_test();
+    destruction_test();
+    grpc_iomgr_platform_shutdown();
+  }
+  grpc_core::ExecCtx::GlobalShutdown();
+
   return 0;
 }