test/core/end2end/tests/keepalive_timeout.cc

   1 /*
   2  *
   3  * Copyright 2017 gRPC authors.
   4  *
   5  * Licensed under the Apache License, Version 2.0 (the "License");
   6  * you may not use this file except in compliance with the License.
   7  * You may obtain a copy of the License at
   8  *
   9  *     http://www.apache.org/licenses/LICENSE-2.0
  10  *
  11  * Unless required by applicable law or agreed to in writing, software
  12  * distributed under the License is distributed on an "AS IS" BASIS,
  13  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  14  * See the License for the specific language governing permissions and
  15  * limitations under the License.
  16  *
  17  */
  18
  19 #include <stdio.h>
  20 #include <string.h>
  21
  22 #include <grpc/byte_buffer.h>
  23 #include <grpc/support/alloc.h>
  24 #include <grpc/support/log.h>
  25 #include <grpc/support/time.h>
  26
  27 #include "src/core/ext/transport/chttp2/transport/frame_ping.h"
  28 #include "src/core/lib/channel/channel_args.h"
  29 #include "src/core/lib/gpr/useful.h"
  30 #include "src/core/lib/iomgr/exec_ctx.h"
  31 #include "src/core/lib/iomgr/iomgr.h"
  32 #include "test/core/end2end/cq_verifier.h"
  33 #include "test/core/end2end/end2end_tests.h"
  34
  35 #ifdef GRPC_POSIX_SOCKET
  36 #include "src/core/lib/iomgr/ev_posix.h"
  37 #endif  // GRPC_POSIX_SOCKET
  38
  39 static void* tag(intptr_t t) { return reinterpret_cast<void*>(t); }
  40
  41 static grpc_end2end_test_fixture begin_test(grpc_end2end_test_config config,
  42                                             const char* test_name,
  43                                             grpc_channel_args* client_args,
  44                                             grpc_channel_args* server_args) {
  45   grpc_end2end_test_fixture f;
  46   gpr_log(GPR_INFO, "%s/%s", test_name, config.name);
  47   f = config.create_fixture(client_args, server_args);
  48   config.init_server(&f, server_args);
  49   config.init_client(&f, client_args);
  50   return f;
  51 }
  52
  53 static gpr_timespec n_seconds_from_now(int n) {
  54   return grpc_timeout_seconds_to_deadline(n);
  55 }
  56
  57 static gpr_timespec five_seconds_from_now(void) {
  58   return n_seconds_from_now(5);
  59 }
  60
  61 static void drain_cq(grpc_completion_queue* cq) {
  62   grpc_event ev;
  63   do {
  64     ev = grpc_completion_queue_next(cq, five_seconds_from_now(), nullptr);
  65   } while (ev.type != GRPC_QUEUE_SHUTDOWN);
  66 }
  67
  68 static void shutdown_server(grpc_end2end_test_fixture* f) {
  69   if (!f->server) return;
  70
  71   grpc_server_shutdown_and_notify(f->server, f->shutdown_cq, tag(1000));
  72   GPR_ASSERT(grpc_completion_queue_pluck(f->shutdown_cq, tag(1000),
  73                                          five_seconds_from_now(), nullptr)
  74                  .type == GRPC_OP_COMPLETE);
  75   grpc_server_destroy(f->server);
  76   f->server = nullptr;
  77 }
  78
  79 static void shutdown_client(grpc_end2end_test_fixture* f) {
  80   if (!f->client) return;
  81   grpc_channel_destroy(f->client);
  82   f->client = nullptr;
  83 }
  84
  85 static void end_test(grpc_end2end_test_fixture* f) {
  86   shutdown_server(f);
  87   shutdown_client(f);
  88
  89   grpc_completion_queue_shutdown(f->cq);
  90   drain_cq(f->cq);
  91   grpc_completion_queue_destroy(f->cq);
  92   grpc_completion_queue_destroy(f->shutdown_cq);
  93 }
  94
  95 /* Client sends a request, server replies with a payload, then waits for the
  96    keepalive watchdog timeouts before returning status. */
  97 static void test_keepalive_timeout(grpc_end2end_test_config config) {
  98   grpc_call* c;
  99   grpc_call* s;
 100   grpc_slice response_payload_slice =
 101       grpc_slice_from_copied_string("hello world");
 102   grpc_byte_buffer* response_payload =
 103       grpc_raw_byte_buffer_create(&response_payload_slice, 1);
 104
 105   grpc_arg keepalive_arg_elems[3];
 106   keepalive_arg_elems[0].type = GRPC_ARG_INTEGER;
 107   keepalive_arg_elems[0].key = const_cast<char*>(GRPC_ARG_KEEPALIVE_TIME_MS);
 108   keepalive_arg_elems[0].value.integer = 3500;
 109   keepalive_arg_elems[1].type = GRPC_ARG_INTEGER;
 110   keepalive_arg_elems[1].key = const_cast<char*>(GRPC_ARG_KEEPALIVE_TIMEOUT_MS);
 111   keepalive_arg_elems[1].value.integer = 0;
 112   keepalive_arg_elems[2].type = GRPC_ARG_INTEGER;
 113   keepalive_arg_elems[2].key = const_cast<char*>(GRPC_ARG_HTTP2_BDP_PROBE);
 114   keepalive_arg_elems[2].value.integer = 0;
 115   grpc_channel_args keepalive_args = {GPR_ARRAY_SIZE(keepalive_arg_elems),
 116                                       keepalive_arg_elems};
 117
 118   grpc_end2end_test_fixture f =
 119       begin_test(config, "keepalive_timeout", &keepalive_args, nullptr);
 120   cq_verifier* cqv = cq_verifier_create(f.cq);
 121   grpc_op ops[6];
 122   grpc_op* op;
 123   grpc_metadata_array initial_metadata_recv;
 124   grpc_metadata_array trailing_metadata_recv;
 125   grpc_metadata_array request_metadata_recv;
 126   grpc_byte_buffer* response_payload_recv = nullptr;
 127   grpc_call_details call_details;
 128   grpc_status_code status;
 129   grpc_call_error error;
 130   grpc_slice details;
 131
 132   /* Disable ping ack to trigger the keepalive timeout */
 133   grpc_set_disable_ping_ack(true);
 134
 135   gpr_timespec deadline = five_seconds_from_now();
 136   c = grpc_channel_create_call(f.client, nullptr, GRPC_PROPAGATE_DEFAULTS, f.cq,
 137                                grpc_slice_from_static_string("/foo"), nullptr,
 138                                deadline, nullptr);
 139   GPR_ASSERT(c);
 140
 141   grpc_metadata_array_init(&initial_metadata_recv);
 142   grpc_metadata_array_init(&trailing_metadata_recv);
 143   grpc_metadata_array_init(&request_metadata_recv);
 144   grpc_call_details_init(&call_details);
 145
 146   memset(ops, 0, sizeof(ops));
 147   op = ops;
 148   op->op = GRPC_OP_SEND_INITIAL_METADATA;
 149   op->data.send_initial_metadata.count = 0;
 150   op++;
 151   op->op = GRPC_OP_SEND_CLOSE_FROM_CLIENT;
 152   op++;
 153   op->op = GRPC_OP_RECV_INITIAL_METADATA;
 154   op->data.recv_initial_metadata.recv_initial_metadata = &initial_metadata_recv;
 155   op++;
 156   op->op = GRPC_OP_RECV_MESSAGE;
 157   op->data.recv_message.recv_message = &response_payload_recv;
 158   op++;
 159   error = grpc_call_start_batch(c, ops, static_cast<size_t>(op - ops), tag(1),
 160                                 nullptr);
 161   GPR_ASSERT(GRPC_CALL_OK == error);
 162
 163   GPR_ASSERT(GRPC_CALL_OK == grpc_server_request_call(
 164                                  f.server, &s, &call_details,
 165                                  &request_metadata_recv, f.cq, f.cq, tag(101)));
 166   CQ_EXPECT_COMPLETION(cqv, tag(101), 1);
 167   cq_verify(cqv);
 168
 169   memset(ops, 0, sizeof(ops));
 170   op = ops;
 171   op->op = GRPC_OP_SEND_INITIAL_METADATA;
 172   op->data.send_initial_metadata.count = 0;
 173   op++;
 174   op->op = GRPC_OP_SEND_MESSAGE;
 175   op->data.send_message.send_message = response_payload;
 176   op++;
 177   error = grpc_call_start_batch(s, ops, static_cast<size_t>(op - ops), tag(102),
 178                                 nullptr);
 179   GPR_ASSERT(GRPC_CALL_OK == error);
 180
 181   CQ_EXPECT_COMPLETION(cqv, tag(102), 1);
 182   CQ_EXPECT_COMPLETION(cqv, tag(1), 1);
 183   cq_verify(cqv);
 184
 185   memset(ops, 0, sizeof(ops));
 186   op = ops;
 187   op->op = GRPC_OP_RECV_STATUS_ON_CLIENT;
 188   op->data.recv_status_on_client.trailing_metadata = &trailing_metadata_recv;
 189   op->data.recv_status_on_client.status = &status;
 190   op->data.recv_status_on_client.status_details = &details;
 191   op++;
 192   error = grpc_call_start_batch(c, ops, static_cast<size_t>(op - ops), tag(3),
 193                                 nullptr);
 194   GPR_ASSERT(GRPC_CALL_OK == error);
 195
 196   CQ_EXPECT_COMPLETION(cqv, tag(3), 1);
 197   cq_verify(cqv);
 198
 199   char* details_str = grpc_slice_to_c_string(details);
 200   char* method_str = grpc_slice_to_c_string(call_details.method);
 201   GPR_ASSERT(status == GRPC_STATUS_UNAVAILABLE);
 202   GPR_ASSERT(0 == grpc_slice_str_cmp(details, "keepalive watchdog timeout"));
 203   GPR_ASSERT(0 == grpc_slice_str_cmp(call_details.method, "/foo"));
 204
 205   gpr_free(details_str);
 206   gpr_free(method_str);
 207
 208   grpc_slice_unref(details);
 209   grpc_metadata_array_destroy(&initial_metadata_recv);
 210   grpc_metadata_array_destroy(&trailing_metadata_recv);
 211   grpc_metadata_array_destroy(&request_metadata_recv);
 212   grpc_call_details_destroy(&call_details);
 213
 214   grpc_call_unref(c);
 215   grpc_call_unref(s);
 216
 217   cq_verifier_destroy(cqv);
 218
 219   grpc_byte_buffer_destroy(response_payload);
 220   grpc_byte_buffer_destroy(response_payload_recv);
 221
 222   end_test(&f);
 223   config.tear_down_data(&f);
 224 }
 225
 226 /* Verify that reads reset the keepalive ping timer. The client sends 30 pings
 227  * with a sleep of 10ms in between. It has a configured keepalive timer of
 228  * 200ms. In the success case, each ping ack should reset the keepalive timer so
 229  * that the keepalive ping is never sent. */
 230 static void test_read_delays_keepalive(grpc_end2end_test_config config) {
 231 #ifdef GRPC_POSIX_SOCKET
 232   grpc_core::UniquePtr<char> poller = GPR_GLOBAL_CONFIG_GET(grpc_poll_strategy);
 233   /* It is hard to get the timing right for the polling engine poll. */
 234   if ((0 == strcmp(poller.get(), "poll"))) {
 235     return;
 236   }
 237 #endif  // GRPC_POSIX_SOCKET
 238   const int kPingIntervalMS = 100;
 239   grpc_arg keepalive_arg_elems[3];
 240   keepalive_arg_elems[0].type = GRPC_ARG_INTEGER;
 241   keepalive_arg_elems[0].key = const_cast<char*>(GRPC_ARG_KEEPALIVE_TIME_MS);
 242   keepalive_arg_elems[0].value.integer = 20 * kPingIntervalMS;
 243   keepalive_arg_elems[1].type = GRPC_ARG_INTEGER;
 244   keepalive_arg_elems[1].key = const_cast<char*>(GRPC_ARG_KEEPALIVE_TIMEOUT_MS);
 245   keepalive_arg_elems[1].value.integer = 0;
 246   keepalive_arg_elems[2].type = GRPC_ARG_INTEGER;
 247   keepalive_arg_elems[2].key = const_cast<char*>(GRPC_ARG_HTTP2_BDP_PROBE);
 248   keepalive_arg_elems[2].value.integer = 0;
 249   grpc_channel_args keepalive_args = {GPR_ARRAY_SIZE(keepalive_arg_elems),
 250                                       keepalive_arg_elems};
 251   grpc_end2end_test_fixture f = begin_test(config, "test_read_delays_keepalive",
 252                                            &keepalive_args, nullptr);
 253   /* Disable ping ack to trigger the keepalive timeout */
 254   grpc_set_disable_ping_ack(true);
 255   grpc_call* c;
 256   grpc_call* s;
 257   cq_verifier* cqv = cq_verifier_create(f.cq);
 258   grpc_op ops[6];
 259   grpc_op* op;
 260   grpc_metadata_array initial_metadata_recv;
 261   grpc_metadata_array trailing_metadata_recv;
 262   grpc_metadata_array request_metadata_recv;
 263   grpc_call_details call_details;
 264   grpc_status_code status;
 265   grpc_call_error error;
 266   grpc_slice details;
 267   int was_cancelled = 2;
 268   grpc_byte_buffer* request_payload;
 269   grpc_byte_buffer* request_payload_recv;
 270   grpc_byte_buffer* response_payload;
 271   grpc_byte_buffer* response_payload_recv;
 272   int i;
 273   grpc_slice request_payload_slice =
 274       grpc_slice_from_copied_string("hello world");
 275   grpc_slice response_payload_slice =
 276       grpc_slice_from_copied_string("hello you");
 277
 278   gpr_timespec deadline = five_seconds_from_now();
 279   c = grpc_channel_create_call(f.client, nullptr, GRPC_PROPAGATE_DEFAULTS, f.cq,
 280                                grpc_slice_from_static_string("/foo"), nullptr,
 281                                deadline, nullptr);
 282   GPR_ASSERT(c);
 283
 284   grpc_metadata_array_init(&initial_metadata_recv);
 285   grpc_metadata_array_init(&trailing_metadata_recv);
 286   grpc_metadata_array_init(&request_metadata_recv);
 287   grpc_call_details_init(&call_details);
 288
 289   memset(ops, 0, sizeof(ops));
 290   op = ops;
 291   op->op = GRPC_OP_SEND_INITIAL_METADATA;
 292   op->data.send_initial_metadata.count = 0;
 293   op->flags = 0;
 294   op->reserved = nullptr;
 295   op++;
 296   op->op = GRPC_OP_RECV_INITIAL_METADATA;
 297   op->data.recv_initial_metadata.recv_initial_metadata = &initial_metadata_recv;
 298   op->flags = 0;
 299   op->reserved = nullptr;
 300   op++;
 301   op->op = GRPC_OP_RECV_STATUS_ON_CLIENT;
 302   op->data.recv_status_on_client.trailing_metadata = &trailing_metadata_recv;
 303   op->data.recv_status_on_client.status = &status;
 304   op->data.recv_status_on_client.status_details = &details;
 305   op->flags = 0;
 306   op->reserved = nullptr;
 307   op++;
 308   error = grpc_call_start_batch(c, ops, static_cast<size_t>(op - ops), tag(1),
 309                                 nullptr);
 310   GPR_ASSERT(GRPC_CALL_OK == error);
 311
 312   error =
 313       grpc_server_request_call(f.server, &s, &call_details,
 314                                &request_metadata_recv, f.cq, f.cq, tag(100));
 315   GPR_ASSERT(GRPC_CALL_OK == error);
 316   CQ_EXPECT_COMPLETION(cqv, tag(100), 1);
 317   cq_verify(cqv);
 318
 319   memset(ops, 0, sizeof(ops));
 320   op = ops;
 321   op->op = GRPC_OP_SEND_INITIAL_METADATA;
 322   op->data.send_initial_metadata.count = 0;
 323   op->flags = 0;
 324   op->reserved = nullptr;
 325   op++;
 326   op->op = GRPC_OP_RECV_CLOSE_ON_SERVER;
 327   op->data.recv_close_on_server.cancelled = &was_cancelled;
 328   op->flags = 0;
 329   op->reserved = nullptr;
 330   op++;
 331   error = grpc_call_start_batch(s, ops, static_cast<size_t>(op - ops), tag(101),
 332                                 nullptr);
 333   GPR_ASSERT(GRPC_CALL_OK == error);
 334
 335   for (i = 0; i < 30; i++) {
 336     request_payload = grpc_raw_byte_buffer_create(&request_payload_slice, 1);
 337     response_payload = grpc_raw_byte_buffer_create(&response_payload_slice, 1);
 338
 339     memset(ops, 0, sizeof(ops));
 340     op = ops;
 341     op->op = GRPC_OP_SEND_MESSAGE;
 342     op->data.send_message.send_message = request_payload;
 343     op->flags = 0;
 344     op->reserved = nullptr;
 345     op++;
 346     op->op = GRPC_OP_RECV_MESSAGE;
 347     op->data.recv_message.recv_message = &response_payload_recv;
 348     op->flags = 0;
 349     op->reserved = nullptr;
 350     op++;
 351     error = grpc_call_start_batch(c, ops, static_cast<size_t>(op - ops), tag(2),
 352                                   nullptr);
 353     GPR_ASSERT(GRPC_CALL_OK == error);
 354
 355     memset(ops, 0, sizeof(ops));
 356     op = ops;
 357     op->op = GRPC_OP_RECV_MESSAGE;
 358     op->data.recv_message.recv_message = &request_payload_recv;
 359     op->flags = 0;
 360     op->reserved = nullptr;
 361     op++;
 362     error = grpc_call_start_batch(s, ops, static_cast<size_t>(op - ops),
 363                                   tag(102), nullptr);
 364     GPR_ASSERT(GRPC_CALL_OK == error);
 365     CQ_EXPECT_COMPLETION(cqv, tag(102), 1);
 366     cq_verify(cqv);
 367
 368     memset(ops, 0, sizeof(ops));
 369     op = ops;
 370     op->op = GRPC_OP_SEND_MESSAGE;
 371     op->data.send_message.send_message = response_payload;
 372     op->flags = 0;
 373     op->reserved = nullptr;
 374     op++;
 375     error = grpc_call_start_batch(s, ops, static_cast<size_t>(op - ops),
 376                                   tag(103), nullptr);
 377     GPR_ASSERT(GRPC_CALL_OK == error);
 378     CQ_EXPECT_COMPLETION(cqv, tag(103), 1);
 379     CQ_EXPECT_COMPLETION(cqv, tag(2), 1);
 380     cq_verify(cqv);
 381
 382     grpc_byte_buffer_destroy(request_payload);
 383     grpc_byte_buffer_destroy(response_payload);
 384     grpc_byte_buffer_destroy(request_payload_recv);
 385     grpc_byte_buffer_destroy(response_payload_recv);
 386     /* Sleep for a short interval to check if the client sends any pings */
 387     gpr_sleep_until(grpc_timeout_milliseconds_to_deadline(kPingIntervalMS));
 388   }
 389
 390   grpc_slice_unref(request_payload_slice);
 391   grpc_slice_unref(response_payload_slice);
 392
 393   memset(ops, 0, sizeof(ops));
 394   op = ops;
 395   op->op = GRPC_OP_SEND_CLOSE_FROM_CLIENT;
 396   op->flags = 0;
 397   op->reserved = nullptr;
 398   op++;
 399   error = grpc_call_start_batch(c, ops, static_cast<size_t>(op - ops), tag(3),
 400                                 nullptr);
 401   GPR_ASSERT(GRPC_CALL_OK == error);
 402
 403   memset(ops, 0, sizeof(ops));
 404   op = ops;
 405   op->op = GRPC_OP_SEND_STATUS_FROM_SERVER;
 406   op->data.send_status_from_server.trailing_metadata_count = 0;
 407   op->data.send_status_from_server.status = GRPC_STATUS_UNIMPLEMENTED;
 408   grpc_slice status_details = grpc_slice_from_static_string("xyz");
 409   op->data.send_status_from_server.status_details = &status_details;
 410   op->flags = 0;
 411   op->reserved = nullptr;
 412   op++;
 413   error = grpc_call_start_batch(s, ops, static_cast<size_t>(op - ops), tag(104),
 414                                 nullptr);
 415   GPR_ASSERT(GRPC_CALL_OK == error);
 416
 417   CQ_EXPECT_COMPLETION(cqv, tag(1), 1);
 418   CQ_EXPECT_COMPLETION(cqv, tag(3), 1);
 419   CQ_EXPECT_COMPLETION(cqv, tag(101), 1);
 420   CQ_EXPECT_COMPLETION(cqv, tag(104), 1);
 421   cq_verify(cqv);
 422
 423   grpc_call_unref(c);
 424   grpc_call_unref(s);
 425
 426   cq_verifier_destroy(cqv);
 427
 428   grpc_metadata_array_destroy(&initial_metadata_recv);
 429   grpc_metadata_array_destroy(&trailing_metadata_recv);
 430   grpc_metadata_array_destroy(&request_metadata_recv);
 431   grpc_call_details_destroy(&call_details);
 432   grpc_slice_unref(details);
 433
 434   end_test(&f);
 435   config.tear_down_data(&f);
 436 }
 437
 438 void keepalive_timeout(grpc_end2end_test_config config) {
 439   test_keepalive_timeout(config);
 440   test_read_delays_keepalive(config);
 441 }
 442
 443 void keepalive_timeout_pre_init(void) {}