2018-04-07 14:06:25,944 START: bins/opt/bm_arena --benchmark_filter=BM_Arena_Batch/32768/64/1024$  GRPC_POLL_STRATEGY=none
2018-04-07 14:06:25,957 D0407 14:06:22.708157000 140735180988416 ev_posix.cc:142]              Using polling engine: poll
D0407 14:06:22.709048000 140735180988416 dns_resolver.cc:331]          Using native dns resolver
D0407 14:06:22.709141000 140735180988416 test_config.cc:391]           test slowdown factor: sanitizer=1, fixture=1, poller=1, total=1
Note: Google Test filter = UpdatesTest.ReresolveDeadBackend
[==========] Running 1 test from 1 test case.
[----------] Global test environment set-up.
[----------] 1 test from UpdatesTest
[ RUN      ] UpdatesTest.ReresolveDeadBackend
I0407 14:06:22.713782000 140735180988416 grpclb_end2end_test.cc:579]   starting backend server on port 31775
I0407 14:06:22.714012000 123145303912448 server_builder.cc:269]        Synchronous server. Num CQs: 1, Min pollers: 1, Max Pollers: 2, CQ timeout (msec): 10000
I0407 14:06:22.715046000 140735180988416 grpclb_end2end_test.cc:584]   backend server startup complete
I0407 14:06:22.716877000 140735180988416 grpclb_end2end_test.cc:579]   starting backend server on port 18713
I0407 14:06:22.716967000 123145304985600 server_builder.cc:269]        Synchronous server. Num CQs: 1, Min pollers: 1, Max Pollers: 2, CQ timeout (msec): 10000
I0407 14:06:22.717630000 140735180988416 grpclb_end2end_test.cc:584]   backend server startup complete
I0407 14:06:22.719194000 140735180988416 grpclb_end2end_test.cc:579]   starting backend server on port 9347
I0407 14:06:22.719279000 123145306058752 server_builder.cc:269]        Synchronous server. Num CQs: 1, Min pollers: 1, Max Pollers: 2, CQ timeout (msec): 10000
I0407 14:06:22.720044000 140735180988416 grpclb_end2end_test.cc:584]   backend server startup complete
I0407 14:06:22.721834000 140735180988416 grpclb_end2end_test.cc:579]   starting backend server on port 24895
I0407 14:06:22.721920000 123145307131904 server_builder.cc:269]        Synchronous server. Num CQs: 1, Min pollers: 1, Max Pollers: 2, CQ timeout (msec): 10000
I0407 14:06:22.722551000 140735180988416 grpclb_end2end_test.cc:584]   backend server startup complete
I0407 14:06:22.724531000 140735180988416 grpclb_end2end_test.cc:579]   starting balancer server on port 31018
I0407 14:06:22.724644000 123145308205056 server_builder.cc:269]        Synchronous server. Num CQs: 1, Min pollers: 1, Max Pollers: 2, CQ timeout (msec): 10000
I0407 14:06:22.725805000 140735180988416 grpclb_end2end_test.cc:584]   balancer server startup complete
I0407 14:06:22.728019000 140735180988416 grpclb_end2end_test.cc:579]   starting balancer server on port 20434
I0407 14:06:22.728157000 123145309278208 server_builder.cc:269]        Synchronous server. Num CQs: 1, Min pollers: 1, Max Pollers: 2, CQ timeout (msec): 10000
I0407 14:06:22.729256000 140735180988416 grpclb_end2end_test.cc:584]   balancer server startup complete
I0407 14:06:22.731303000 140735180988416 grpclb_end2end_test.cc:579]   starting balancer server on port 18759
I0407 14:06:22.731408000 123145310351360 server_builder.cc:269]        Synchronous server. Num CQs: 1, Min pollers: 1, Max Pollers: 2, CQ timeout (msec): 10000
I0407 14:06:22.732028000 140735180988416 grpclb_end2end_test.cc:584]   balancer server startup complete
I0407 14:06:22.732357000 140735180988416 grpclb_end2end_test.cc:1183]  ========= BEFORE FIRST BATCH ==========
I0407 14:06:22.733164000 140735180988416 subchannel.cc:608]            New connected subchannel at 0x7f9a217019a0 for subchannel 0x7f9a21504cb0
I0407 14:06:22.733525000 123145308741632 grpclb_end2end_test.cc:204]   LB[0x7f9a21500130]: BalanceLoad
I0407 14:06:22.734077000 123145308741632 grpclb_end2end_test.cc:212]   LB[0x7f9a21500130]: received initial message 'initial_request {
  name: "application_target_name"
}
'
test/cpp/end2end/grpclb_end2end_test.cc:558: Failure
Value of: status.ok()
  Actual: false
Expected: true
code=4 message=Deadline Exceeded
test/cpp/end2end/grpclb_end2end_test.cc:560: Failure
      Expected: response.message()
      Which is: ""
To be equal to: kRequestMessage_
      Which is: "Live long and prosper."
I0407 14:06:23.953910000 140735180988416 subchannel.cc:608]            New connected subchannel at 0x7f9a22b00ea0 for subchannel 0x7f9a21702380
test/cpp/end2end/grpclb_end2end_test.cc:558: Failure
Value of: status.ok()
  Actual: false
Expected: true
code=4 message=Deadline Exceeded
test/cpp/end2end/grpclb_end2end_test.cc:560: Failure
      Expected: response.message()
      Which is: ""
To be equal to: kRequestMessage_
      Which is: "Live long and prosper."
I0407 14:06:25.922751000 140735180988416 grpclb_end2end_test.cc:1185]  ========= DONE WITH FIRST BATCH ==========
test/cpp/end2end/grpclb_end2end_test.cc:1187: Failure
      Expected: 10U
      Which is: 10
To be equal to: backend_servers_[0].service_->request_count()
      Which is: 9
I0407 14:06:25.922847000 140735180988416 grpclb_end2end_test.cc:1190]  ********** ABOUT TO KILL BACKEND 0 *************
I0407 14:06:25.922856000 140735180988416 grpclb_end2end_test.cc:154]   Backend: shut down
I0407 14:06:25.922863000 140735180988416 grpclb_end2end_test.cc:604]   backend about to shutdown
I0407 14:06:25.923439000 140735180988416 grpclb_end2end_test.cc:607]   backend shutdown completed
I0407 14:06:25.923460000 140735180988416 grpclb_end2end_test.cc:1192]  ********** KILLED BACKEND 0 *************
I0407 14:06:25.923666000 140735180988416 subchannel.cc:646]            Connect failed: {"created":"@1523135185.923627000","description":"Failed to connect to remote host: OS Error","errno":61,"file":"src/core/lib/iomgr/tcp_client_posix.cc","file_line":201,"os_error":"Connection refused","syscall":"connect","target_address":"ipv4:127.0.0.1:31775"}
I0407 14:06:25.923912000 123145313034240 subchannel.cc:470]            Subchannel 0x7f9a21702380: Retry in 1000 milliseconds
I0407 14:06:25.924915000 140735180988416 subchannel.cc:608]            New connected subchannel at 0x7f9a2140c6f0 for subchannel 0x7f9a21507d70
I0407 14:06:25.925540000 140735180988416 grpclb_end2end_test.cc:1198]  ========= BEFORE SECOND BATCH ==========
I0407 14:06:25.928129000 140735180988416 grpclb_end2end_test.cc:1200]  ========= DONE WITH SECOND BATCH ==========
I0407 14:06:25.928178000 140735180988416 grpclb_end2end_test.cc:154]   Backend: shut down
I0407 14:06:25.928188000 123145308741632 grpclb_end2end_test.cc:270]   LB[0x7f9a21500130]: done
I0407 14:06:25.928197000 140735180988416 grpclb_end2end_test.cc:154]   Backend: shut down
I0407 14:06:25.928305000 140735180988416 grpclb_end2end_test.cc:604]   backend about to shutdown
I0407 14:06:25.928733000 140735180988416 grpclb_end2end_test.cc:607]   backend shutdown completed
I0407 14:06:25.928756000 140735180988416 grpclb_end2end_test.cc:154]   Backend: shut down
I0407 14:06:25.928771000 140735180988416 grpclb_end2end_test.cc:604]   backend about to shutdown
I0407 14:06:25.929077000 140735180988416 grpclb_end2end_test.cc:607]   backend shutdown completed
I0407 14:06:25.929094000 140735180988416 grpclb_end2end_test.cc:154]   Backend: shut down
I0407 14:06:25.929101000 140735180988416 grpclb_end2end_test.cc:604]   backend about to shutdown
I0407 14:06:25.929457000 140735180988416 grpclb_end2end_test.cc:607]   backend shutdown completed
I0407 14:06:25.929475000 140735180988416 grpclb_end2end_test.cc:285]   LB[0x7f9a21500130]: shut down
I0407 14:06:25.929482000 140735180988416 grpclb_end2end_test.cc:604]   balancer about to shutdown
I0407 14:06:25.929885000 140735180988416 grpclb_end2end_test.cc:607]   balancer shutdown completed
I0407 14:06:25.929902000 140735180988416 grpclb_end2end_test.cc:285]   LB[0x7f9a22803660]: shut down
I0407 14:06:25.929909000 140735180988416 grpclb_end2end_test.cc:604]   balancer about to shutdown
I0407 14:06:25.930138000 140735180988416 grpclb_end2end_test.cc:607]   balancer shutdown completed
I0407 14:06:25.930157000 140735180988416 grpclb_end2end_test.cc:285]   LB[0x7f9a2140b900]: shut down
I0407 14:06:25.930164000 140735180988416 grpclb_end2end_test.cc:604]   balancer about to shutdown
I0407 14:06:25.930189000 123145303375872 subchannel.cc:646]            Connect failed: {"created":"@1523135185.930164000","description":"Failed to connect to remote host: OS Error","errno":61,"file":"src/core/lib/iomgr/tcp_client_posix.cc","file_line":201,"os_error":"Connection refused","syscall":"connect","target_address":"ipv4:127.0.0.1:18713"}
I0407 14:06:25.930270000 123145303375872 subchannel.cc:470]            Subchannel 0x7f9a21507d70: Retry in 999 milliseconds
I0407 14:06:25.930443000 140735180988416 grpclb_end2end_test.cc:607]   balancer shutdown completed
[  FAILED  ] UpdatesTest.ReresolveDeadBackend (3221 ms)
[----------] 1 test from UpdatesTest (3221 ms total)

[----------] Global test environment tear-down
[==========] 1 test from 1 test case ran. (3221 ms total)
[  PASSED  ] 0 tests.
[  FAILED  ] 1 test, listed below:
[  FAILED  ] UpdatesTest.ReresolveDeadBackend

 1 FAILED TEST
D0407 14:06:25.931374000 140735180988416 ev_posix.cc:142]              Using polling engine: poll
D0407 14:06:25.931404000 140735180988416 dns_resolver.cc:331]          Using native dns resolver
real         3.25
user         1.58
sys          1.66

2018-04-07 14:06:25,958 FAILED: bins/opt/grpclb_end2end_test --gtest_filter=UpdatesTest.ReresolveDeadBackend  GRPC_POLL_STRATEGY=poll [ret=1, pid=17628, time=3.3sec]