-
Notifications
You must be signed in to change notification settings - Fork 11.1k
cpp_protobuf_async_client_unary_1channel_64wide_128Breq_8MBresp_secure_low_thread_count failing consistently (on TSAN) #13178
Copy link
Copy link
Closed
Labels
disposition/BUILDNURSEFor all buildnurse related build/test failures and flakesFor all buildnurse related build/test failures and flakesinfra/New Failurepriority/P0
Description
2017-10-27 18:15:47,801 I1027 18:13:42.458881161 4904 ev_epollsig_linux.cc:75] epoll engine will be using signal: 40
D1027 18:13:42.459048049 4904 ev_posix.cc:135] Using polling engine: epollsig
D1027 18:13:42.459924398 4904 dns_resolver.cc:306] Using native dns resolver
D1027 18:13:42.476728917 4904 ev_posix.cc:135] Using polling engine: epollsig
D1027 18:13:42.476848263 4904 dns_resolver.cc:306] Using native dns resolver
I1027 18:13:42.516949711 4909 ev_epollsig_linux.cc:75] epoll engine will be using signal: 40
D1027 18:13:42.517128829 4909 ev_posix.cc:135] Using polling engine: epollsig
D1027 18:13:42.517222312 4909 dns_resolver.cc:306] Using native dns resolver
I1027 18:13:42.518349364 4909 server_builder.cc:269] Synchronous server. Num CQs: 1, Min pollers: 1, Max Pollers: 2, CQ timeout (msec): 10000
I1027 18:13:42.526790888 4914 ev_epollsig_linux.cc:75] epoll engine will be using signal: 40
D1027 18:13:42.526950095 4914 ev_posix.cc:135] Using polling engine: epollsig
D1027 18:13:42.527048716 4914 dns_resolver.cc:306] Using native dns resolver
I1027 18:13:42.527900239 4914 server_builder.cc:269] Synchronous server. Num CQs: 1, Min pollers: 1, Max Pollers: 2, CQ timeout (msec): 10000
RUNNING SCENARIO: cpp_protobuf_async_client_unary_1channel_64wide_128Breq_8MBresp_secure
I1027 18:13:42.543960882 4917 driver.cc:273] Starting server on localhost:9543 (worker #0)
I1027 18:13:42.547842349 4917 ev_epollsig_linux.cc:75] epoll engine will be using signal: 40
D1027 18:13:42.548316365 4917 ev_posix.cc:135] Using polling engine: epollsig
D1027 18:13:42.548424249 4917 dns_resolver.cc:306] Using native dns resolver
I1027 18:13:42.561185421 4925 qps_worker.cc:231] RunServerBody: about to create server
I1027 18:13:42.571473724 4925 qps_worker.cc:69] Starting server of type ASYNC_SERVER
I1027 18:13:42.576121976 4925 server_async.cc:94] Sizing async server to 32 threads
I1027 18:14:07.837324342 4925 qps_worker.cc:239] RunServerBody: server created
I1027 18:14:07.837800840 4925 qps_worker.cc:246] RunServerBody: creation status reported
I1027 18:14:07.838381734 4917 driver.cc:329] Starting client on localhost:25854 (worker #1)
D1027 18:14:07.839937325 4917 driver.cc:351] Client 0 gets 1 channels
I1027 18:14:07.848938651 4928 qps_worker.cc:188] RunClientBody: about to create client
I1027 18:14:07.858831155 4928 qps_worker.cc:50] Starting client of type ASYNC_CLIENT UNARY 0
I1027 18:14:07.861585000 4928 client.h:427] Connecting to localhost:1152
I1027 18:14:08.132607440 4928 qps_worker.cc:193] RunClientBody: client created
I1027 18:14:08.133047638 4928 qps_worker.cc:198] RunClientBody: creation status reported
I1027 18:14:08.133485063 4917 driver.cc:372] Initiating
I1027 18:14:08.133886542 4928 qps_worker.cc:200] RunClientBody: Message read
I1027 18:14:08.139762534 4928 qps_worker.cc:209] RunClientBody: Mark response given
I1027 18:14:08.143236127 4917 driver.cc:393] Warming up
I1027 18:14:08.143282859 4917 driver.cc:399] Starting
I1027 18:14:08.143745349 4925 qps_worker.cc:248] RunServerBody: Message read
I1027 18:14:08.143770172 4928 qps_worker.cc:200] RunClientBody: Message read
I1027 18:14:08.148946705 4928 qps_worker.cc:209] RunClientBody: Mark response given
I1027 18:14:08.150397200 4925 qps_worker.cc:257] RunServerBody: Mark response given
I1027 18:14:08.156328952 4917 driver.cc:426] Running
I1027 18:14:09.143493492 4917 driver.cc:440] Finishing clients
I1027 18:14:09.144280150 4928 qps_worker.cc:200] RunClientBody: Message read
I1027 18:14:09.149161372 4928 qps_worker.cc:209] RunClientBody: Mark response given
I1027 18:14:09.149242851 4928 qps_worker.cc:212] RunClientBody: Awaiting Threads Completion
I1027 18:14:09.152483490 4917 driver.cc:454] Received final status from client 0
D1027 18:14:09.206467730 12083 writing.cc:142] ipv6:[::1]:34016:0x7da40000f000 stream 1 stalled by transport [fc:pending=0:flowed=0:peer_initwin=4194304:t_win=0:s_win=0:s_delta=-4194304]
E1027 18:14:09.638315415 12082 call.cc:2034] assertion failed: grpc_cq_begin_op(call->cq, notify_tag)
D1027 18:14:09.639733833 12045 writing.cc:142] ipv6:[::1]:34016:0x7da40000f000 stream 1 stalled by stream [fc:pending=0:flowed=0:peer_initwin=4194304:t_win=4194304:s_win=0:s_delta=-4194304]
E1027 18:14:09.816502216 4917 driver.cc:473] Client 0 had an error Stream removed
I1027 18:14:09.816924002 4917 driver.cc:486] Finishing servers
I1027 18:14:09.817364543 4925 qps_worker.cc:248] RunServerBody: Message read
I1027 18:14:09.821729519 4925 qps_worker.cc:257] RunServerBody: Mark response given
I1027 18:14:09.821808964 4925 qps_worker.cc:260] RunServerBody: Returning
I1027 18:14:09.825686611 4917 driver.cc:500] Received final status from server 0
D1027 18:15:42.483047111 12091 server.cc:721] Waiting for 0 channels and 1/1 listeners to be destroyed before shutting down server
I1027 18:15:46.856162292 4925 qps_worker.cc:127] RunServer: Returning
I1027 18:15:46.876697109 4917 report.cc:82] QPS: 0.0
D1027 18:15:46.878204786 4917 report.cc:106] CLIENT[0].client_calls_created = 1
D1027 18:15:46.878222960 4917 report.cc:106] CLIENT[0].server_calls_created = 1
D1027 18:15:46.878231582 4917 report.cc:106] CLIENT[0].cqs_created = 12
D1027 18:15:46.878239277 4917 report.cc:106] CLIENT[0].client_channels_created = 1
D1027 18:15:46.878246662 4917 report.cc:106] CLIENT[0].client_subchannels_created = 2
D1027 18:15:46.878253932 4917 report.cc:106] CLIENT[0].server_channels_created = 1
D1027 18:15:46.878261069 4917 report.cc:106] CLIENT[0].syscall_poll = 23
D1027 18:15:46.878268003 4917 report.cc:106] CLIENT[0].syscall_wait = 0
D1027 18:15:46.878274753 4917 report.cc:106] CLIENT[0].pollset_kick = 16
D1027 18:15:46.878281712 4917 report.cc:106] CLIENT[0].pollset_kicked_without_poller = 0
D1027 18:15:46.878288865 4917 report.cc:106] CLIENT[0].pollset_kicked_again = 0
D1027 18:15:46.878295762 4917 report.cc:106] CLIENT[0].pollset_kick_wakeup_fd = 0
D1027 18:15:46.878302572 4917 report.cc:106] CLIENT[0].pollset_kick_wakeup_cv = 0
D1027 18:15:46.878309385 4917 report.cc:106] CLIENT[0].pollset_kick_own_thread = 0
D1027 18:15:46.878316180 4917 report.cc:106] CLIENT[0].histogram_slow_lookups = 2
D1027 18:15:46.878323053 4917 report.cc:106] CLIENT[0].syscall_write = 10
D1027 18:15:46.878329906 4917 report.cc:106] CLIENT[0].syscall_read = 190
D1027 18:15:46.878336652 4917 report.cc:106] CLIENT[0].tcp_backup_pollers_created = 0
D1027 18:15:46.878343418 4917 report.cc:106] CLIENT[0].tcp_backup_poller_polls = 0
D1027 18:15:46.878350159 4917 report.cc:106] CLIENT[0].http2_op_batches = 12
D1027 18:15:46.878359595 4917 report.cc:106] CLIENT[0].http2_op_cancel = 1
D1027 18:15:46.878366771 4917 report.cc:106] CLIENT[0].http2_op_send_initial_metadata = 2
D1027 18:15:46.878373706 4917 report.cc:106] CLIENT[0].http2_op_send_message = 4
D1027 18:15:46.878380619 4917 report.cc:106] CLIENT[0].http2_op_send_trailing_metadata = 1
D1027 18:15:46.878387585 4917 report.cc:106] CLIENT[0].http2_op_recv_initial_metadata = 2
D1027 18:15:46.878394397 4917 report.cc:106] CLIENT[0].http2_op_recv_message = 5
D1027 18:15:46.878401318 4917 report.cc:106] CLIENT[0].http2_op_recv_trailing_metadata = 2
D1027 18:15:46.878431546 4917 report.cc:106] CLIENT[0].http2_settings_writes = 2
D1027 18:15:46.878438338 4917 report.cc:106] CLIENT[0].http2_pings_sent = 4
D1027 18:15:46.878444670 4917 report.cc:106] CLIENT[0].http2_writes_begun = 8
D1027 18:15:46.878450856 4917 report.cc:106] CLIENT[0].http2_writes_offloaded = 0
D1027 18:15:46.878457052 4917 report.cc:106] CLIENT[0].http2_writes_continued = 0
D1027 18:15:46.878463248 4917 report.cc:106] CLIENT[0].http2_partial_writes = 0
D1027 18:15:46.878471702 4917 report.cc:106] CLIENT[0].http2_initiate_write_due_to_initial_write = 0
D1027 18:15:46.878478472 4917 report.cc:106] CLIENT[0].http2_initiate_write_due_to_start_new_stream = 1
D1027 18:15:46.878497831 4917 report.cc:106] CLIENT[0].http2_initiate_write_due_to_send_message = 2
D1027 18:15:46.878504729 4917 report.cc:106] CLIENT[0].http2_initiate_write_due_to_send_initial_metadata = 1
D1027 18:15:46.878511692 4917 report.cc:106] CLIENT[0].http2_initiate_write_due_to_send_trailing_metadata = 0
D1027 18:15:46.878518229 4917 report.cc:106] CLIENT[0].http2_initiate_write_due_to_retry_send_ping = 0
D1027 18:15:46.878524763 4917 report.cc:106] CLIENT[0].http2_initiate_write_due_to_continue_pings = 0
D1027 18:15:46.878531239 4917 report.cc:106] CLIENT[0].http2_initiate_write_due_to_goaway_sent = 0
D1027 18:15:46.878537819 4917 report.cc:106] CLIENT[0].http2_initiate_write_due_to_rst_stream = 0
D1027 18:15:46.878544220 4917 report.cc:106] CLIENT[0].http2_initiate_write_due_to_close_from_api = 0
D1027 18:15:46.878550797 4917 report.cc:106] CLIENT[0].http2_initiate_write_due_to_stream_flow_control = 1
D1027 18:15:46.878557297 4917 report.cc:106] CLIENT[0].http2_initiate_write_due_to_transport_flow_control = 2
D1027 18:15:46.878563598 4917 report.cc:106] CLIENT[0].http2_initiate_write_due_to_send_settings = 0
D1027 18:15:46.878569958 4917 report.cc:106] CLIENT[0].http2_initiate_write_due_to_bdp_estimator_ping = 0
D1027 18:15:46.878576548 4917 report.cc:106] CLIENT[0].http2_initiate_write_due_to_flow_control_unstalled_by_setting = 0
D1027 18:15:46.878583266 4917 report.cc:106] CLIENT[0].http2_initiate_write_due_to_flow_control_unstalled_by_update = 0
D1027 18:15:46.878589657 4917 report.cc:106] CLIENT[0].http2_initiate_write_due_to_application_ping = 0
D1027 18:15:46.878595997 4917 report.cc:106] CLIENT[0].http2_initiate_write_due_to_keepalive_ping = 0
D1027 18:15:46.878602357 4917 report.cc:106] CLIENT[0].http2_initiate_write_due_to_transport_flow_control_unstalled = 0
D1027 18:15:46.878608783 4917 report.cc:106] CLIENT[0].http2_initiate_write_due_to_ping_response = 2
D1027 18:15:46.878615178 4917 report.cc:106] CLIENT[0].http2_initiate_write_due_to_force_rst_stream = 0
D1027 18:15:46.878621563 4917 report.cc:106] CLIENT[0].http2_spurious_writes_begun = 0
D1027 18:15:46.878627992 4917 report.cc:106] CLIENT[0].hpack_recv_indexed = 0
D1027 18:15:46.878634422 4917 report.cc:106] CLIENT[0].hpack_recv_lithdr_incidx = 0
D1027 18:15:46.878640913 4917 report.cc:106] CLIENT[0].hpack_recv_lithdr_incidx_v = 13
D1027 18:15:46.878647255 4917 report.cc:106] CLIENT[0].hpack_recv_lithdr_notidx = 0
D1027 18:15:46.878653532 4917 report.cc:106] CLIENT[0].hpack_recv_lithdr_notidx_v = 0
D1027 18:15:46.878659899 4917 report.cc:106] CLIENT[0].hpack_recv_lithdr_nvridx = 0
D1027 18:15:46.878666177 4917 report.cc:106] CLIENT[0].hpack_recv_lithdr_nvridx_v = 0
D1027 18:15:46.878672533 4917 report.cc:106] CLIENT[0].hpack_recv_uncompressed = 26
D1027 18:15:46.878678778 4917 report.cc:106] CLIENT[0].hpack_recv_huffman = 0
D1027 18:15:46.878688803 4917 report.cc:106] CLIENT[0].hpack_recv_binary = 0
D1027 18:15:46.878695473 4917 report.cc:106] CLIENT[0].hpack_recv_binary_base64 = 0
D1027 18:15:46.878701857 4917 report.cc:106] CLIENT[0].hpack_send_indexed = 0
D1027 18:15:46.878708148 4917 report.cc:106] CLIENT[0].hpack_send_lithdr_incidx = 0
D1027 18:15:46.878721017 4917 report.cc:106] CLIENT[0].hpack_send_lithdr_incidx_v = 13
D1027 18:15:46.878728499 4917 report.cc:106] CLIENT[0].hpack_send_lithdr_notidx = 0
D1027 18:15:46.878735028 4917 report.cc:106] CLIENT[0].hpack_send_lithdr_notidx_v = 0
D1027 18:15:46.878741291 4917 report.cc:106] CLIENT[0].hpack_send_lithdr_nvridx = 0
D1027 18:15:46.878747575 4917 report.cc:106] CLIENT[0].hpack_send_lithdr_nvridx_v = 0
D1027 18:15:46.878753971 4917 report.cc:106] CLIENT[0].hpack_send_uncompressed = 26
D1027 18:15:46.878760172 4917 report.cc:106] CLIENT[0].hpack_send_huffman = 0
D1027 18:15:46.878766369 4917 report.cc:106] CLIENT[0].hpack_send_binary = 0
D1027 18:15:46.878772609 4917 report.cc:106] CLIENT[0].hpack_send_binary_base64 = 0
D1027 18:15:46.878778869 4917 report.cc:106] CLIENT[0].combiner_locks_initiated = 51
D1027 18:15:46.878785348 4917 report.cc:106] CLIENT[0].combiner_locks_scheduled_items = 254
D1027 18:15:46.878792122 4917 report.cc:106] CLIENT[0].combiner_locks_scheduled_final_items = 15
D1027 18:15:46.878798629 4917 report.cc:106] CLIENT[0].combiner_locks_offloaded = 0
D1027 18:15:46.878805097 4917 report.cc:106] CLIENT[0].call_combiner_locks_initiated = 26
D1027 18:15:46.878811643 4917 report.cc:106] CLIENT[0].call_combiner_locks_scheduled_items = 30
D1027 18:15:46.878818083 4917 report.cc:106] CLIENT[0].call_combiner_set_notify_on_cancel = 0
D1027 18:15:46.878824517 4917 report.cc:106] CLIENT[0].call_combiner_cancelled = 1
D1027 18:15:46.878831049 4917 report.cc:106] CLIENT[0].executor_scheduled_short_items = 2
D1027 18:15:46.878837495 4917 report.cc:106] CLIENT[0].executor_scheduled_long_items = 0
D1027 18:15:46.878843762 4917 report.cc:106] CLIENT[0].executor_scheduled_to_self = 0
D1027 18:15:46.878850438 4917 report.cc:106] CLIENT[0].executor_wakeup_initiated = 2
D1027 18:15:46.878856858 4917 report.cc:106] CLIENT[0].executor_queue_drained = 2
D1027 18:15:46.878863162 4917 report.cc:106] CLIENT[0].executor_push_retries = 0
D1027 18:15:46.878869509 4917 report.cc:106] CLIENT[0].server_requested_calls = 6
D1027 18:15:46.878875938 4917 report.cc:106] CLIENT[0].server_slowpath_requests_queued = 0
D1027 18:15:46.878882389 4917 report.cc:106] CLIENT[0].cq_ev_queue_trylock_failures = 0
D1027 18:15:46.878888866 4917 report.cc:106] CLIENT[0].cq_ev_queue_trylock_successes = 34
D1027 18:15:46.878925418 4917 report.cc:106] CLIENT[0].cq_ev_queue_transient_pop_failures = 0
D1027 18:15:46.878951628 4917 report.cc:110] CLIENT[0].call_initial_size = 3620.5/6560.0/6645.6 (50/95/99%-ile)
D1027 18:15:46.878973003 4917 report.cc:110] CLIENT[0].poll_events_returned = 0.0/0.0/0.0 (50/95/99%-ile)
D1027 18:15:46.878993783 4917 report.cc:110] CLIENT[0].tcp_write_size = 143.7/16049.5/16790.7 (50/95/99%-ile)
D1027 18:15:46.879012149 4917 report.cc:110] CLIENT[0].tcp_write_iov_size = 2.5/21.0/21.8 (50/95/99%-ile)
D1027 18:15:46.879026339 4917 report.cc:110] CLIENT[0].tcp_read_size = 9173.1/10265.1/10362.2 (50/95/99%-ile)
D1027 18:15:46.879037978 4917 report.cc:110] CLIENT[0].tcp_read_offer = 9373.7/15215.6/16623.9 (50/95/99%-ile)
D1027 18:15:46.879053451 4917 report.cc:110] CLIENT[0].tcp_read_offer_iov_size = 1.6/2.5/2.9 (50/95/99%-ile)
D1027 18:15:46.879065383 4917 report.cc:110] CLIENT[0].http2_send_message_size = 6695.5/16605.4/16901.9 (50/95/99%-ile)
D1027 18:15:46.879074772 4917 report.cc:110] CLIENT[0].http2_send_initial_metadata_per_write = 0.0/0.0/0.0 (50/95/99%-ile)
D1027 18:15:46.879084122 4917 report.cc:110] CLIENT[0].http2_send_message_per_write = 0.0/0.0/0.0 (50/95/99%-ile)
D1027 18:15:46.879093531 4917 report.cc:110] CLIENT[0].http2_send_trailing_metadata_per_write = 0.0/0.0/0.0 (50/95/99%-ile)
D1027 18:15:46.879102731 4917 report.cc:110] CLIENT[0].http2_send_flowctl_per_write = 0.0/0.0/0.0 (50/95/99%-ile)
D1027 18:15:46.879111266 4917 report.cc:110] CLIENT[0].server_cqs_checked = 0.5/0.9/1.0 (50/95/99%-ile)
D1027 18:15:46.880561284 4917 report.cc:106] SERVER[0].client_calls_created = 0
D1027 18:15:46.880579638 4917 report.cc:106] SERVER[0].server_calls_created = 2
D1027 18:15:46.880587619 4917 report.cc:106] SERVER[0].cqs_created = 39
D1027 18:15:46.880594592 4917 report.cc:106] SERVER[0].client_channels_created = 0
D1027 18:15:46.880601442 4917 report.cc:106] SERVER[0].client_subchannels_created = 0
D1027 18:15:46.880608177 4917 report.cc:106] SERVER[0].server_channels_created = 2
D1027 18:15:46.880614778 4917 report.cc:106] SERVER[0].syscall_poll = 56
D1027 18:15:46.880621221 4917 report.cc:106] SERVER[0].syscall_wait = 0
D1027 18:15:46.880627534 4917 report.cc:106] SERVER[0].pollset_kick = 12
D1027 18:15:46.880634118 4917 report.cc:106] SERVER[0].pollset_kicked_without_poller = 0
D1027 18:15:46.880640598 4917 report.cc:106] SERVER[0].pollset_kicked_again = 0
D1027 18:15:46.880647034 4917 report.cc:106] SERVER[0].pollset_kick_wakeup_fd = 0
D1027 18:15:46.880653567 4917 report.cc:106] SERVER[0].pollset_kick_wakeup_cv = 0
D1027 18:15:46.880660094 4917 report.cc:106] SERVER[0].pollset_kick_own_thread = 0
D1027 18:15:46.880666496 4917 report.cc:106] SERVER[0].histogram_slow_lookups = 11
D1027 18:15:46.880673105 4917 report.cc:106] SERVER[0].syscall_write = 18
D1027 18:15:46.880679544 4917 report.cc:106] SERVER[0].syscall_read = 27
D1027 18:15:46.880685897 4917 report.cc:106] SERVER[0].tcp_backup_pollers_created = 1
D1027 18:15:46.880692351 4917 report.cc:106] SERVER[0].tcp_backup_poller_polls = 2
D1027 18:15:46.880698718 4917 report.cc:106] SERVER[0].http2_op_batches = 12
D1027 18:15:46.880705196 4917 report.cc:106] SERVER[0].http2_op_cancel = 1
D1027 18:15:46.880711791 4917 report.cc:106] SERVER[0].http2_op_send_initial_metadata = 2
D1027 18:15:46.880726557 4917 report.cc:106] SERVER[0].http2_op_send_message = 3
D1027 18:15:46.880733526 4917 report.cc:106] SERVER[0].http2_op_send_trailing_metadata = 1
D1027 18:15:46.880740129 4917 report.cc:106] SERVER[0].http2_op_recv_initial_metadata = 2
D1027 18:15:46.880746650 4917 report.cc:106] SERVER[0].http2_op_recv_message = 4
D1027 18:15:46.880753156 4917 report.cc:106] SERVER[0].http2_op_recv_trailing_metadata = 2
D1027 18:15:46.880759603 4917 report.cc:106] SERVER[0].http2_settings_writes = 2
D1027 18:15:46.880766204 4917 report.cc:106] SERVER[0].http2_pings_sent = 5
D1027 18:15:46.880772683 4917 report.cc:106] SERVER[0].http2_writes_begun = 11
D1027 18:15:46.880779066 4917 report.cc:106] SERVER[0].http2_writes_offloaded = 1
D1027 18:15:46.880785611 4917 report.cc:106] SERVER[0].http2_writes_continued = 0
D1027 18:15:46.880792035 4917 report.cc:106] SERVER[0].http2_partial_writes = 1
D1027 18:15:46.880804424 4917 report.cc:106] SERVER[0].http2_initiate_write_due_to_initial_write = 0
D1027 18:15:46.880811596 4917 report.cc:106] SERVER[0].http2_initiate_write_due_to_start_new_stream = 0
D1027 18:15:46.880818398 4917 report.cc:106] SERVER[0].http2_initiate_write_due_to_send_message = 1
D1027 18:15:46.880825030 4917 report.cc:106] SERVER[0].http2_initiate_write_due_to_send_initial_metadata = 2
D1027 18:15:46.880831918 4917 report.cc:106] SERVER[0].http2_initiate_write_due_to_send_trailing_metadata = 0
D1027 18:15:46.880838600 4917 report.cc:106] SERVER[0].http2_initiate_write_due_to_retry_send_ping = 0
D1027 18:15:46.880845115 4917 report.cc:106] SERVER[0].http2_initiate_write_due_to_continue_pings = 0
D1027 18:15:46.880851747 4917 report.cc:106] SERVER[0].http2_initiate_write_due_to_goaway_sent = 0
D1027 18:15:46.880861433 4917 report.cc:106] SERVER[0].http2_initiate_write_due_to_rst_stream = 0
D1027 18:15:46.880873177 4917 report.cc:106] SERVER[0].http2_initiate_write_due_to_close_from_api = 0
D1027 18:15:46.880885118 4917 report.cc:106] SERVER[0].http2_initiate_write_due_to_stream_flow_control = 0
D1027 18:15:46.880892838 4917 report.cc:106] SERVER[0].http2_initiate_write_due_to_transport_flow_control = 2
D1027 18:15:46.880899306 4917 report.cc:106] SERVER[0].http2_initiate_write_due_to_send_settings = 0
D1027 18:15:46.880907131 4917 report.cc:106] SERVER[0].http2_initiate_write_due_to_bdp_estimator_ping = 0
D1027 18:15:46.880919221 4917 report.cc:106] SERVER[0].http2_initiate_write_due_to_flow_control_unstalled_by_setting = 0
D1027 18:15:46.880930157 4917 report.cc:106] SERVER[0].http2_initiate_write_due_to_flow_control_unstalled_by_update = 0
D1027 18:15:46.880940227 4917 report.cc:106] SERVER[0].http2_initiate_write_due_to_application_ping = 0
D1027 18:15:46.880951070 4917 report.cc:106] SERVER[0].http2_initiate_write_due_to_keepalive_ping = 0
D1027 18:15:46.880961713 4917 report.cc:106] SERVER[0].http2_initiate_write_due_to_transport_flow_control_unstalled = 1
D1027 18:15:46.880968461 4917 report.cc:106] SERVER[0].http2_initiate_write_due_to_ping_response = 4
D1027 18:15:46.880974910 4917 report.cc:106] SERVER[0].http2_initiate_write_due_to_force_rst_stream = 0
D1027 18:15:46.880981469 4917 report.cc:106] SERVER[0].http2_spurious_writes_begun = 1
D1027 18:15:46.880987971 4917 report.cc:106] SERVER[0].hpack_recv_indexed = 0
D1027 18:15:46.880994503 4917 report.cc:106] SERVER[0].hpack_recv_lithdr_incidx = 0
D1027 18:15:46.881001113 4917 report.cc:106] SERVER[0].hpack_recv_lithdr_incidx_v = 18
D1027 18:15:46.881007495 4917 report.cc:106] SERVER[0].hpack_recv_lithdr_notidx = 0
D1027 18:15:46.881013916 4917 report.cc:106] SERVER[0].hpack_recv_lithdr_notidx_v = 0
D1027 18:15:46.881020281 4917 report.cc:106] SERVER[0].hpack_recv_lithdr_nvridx = 0
D1027 18:15:46.881026711 4917 report.cc:106] SERVER[0].hpack_recv_lithdr_nvridx_v = 0
D1027 18:15:46.881033077 4917 report.cc:106] SERVER[0].hpack_recv_uncompressed = 36
D1027 18:15:46.881039400 4917 report.cc:106] SERVER[0].hpack_recv_huffman = 0
D1027 18:15:46.881045897 4917 report.cc:106] SERVER[0].hpack_recv_binary = 0
D1027 18:15:46.881052421 4917 report.cc:106] SERVER[0].hpack_recv_binary_base64 = 0
D1027 18:15:46.881058811 4917 report.cc:106] SERVER[0].hpack_send_indexed = 0
D1027 18:15:46.881065177 4917 report.cc:106] SERVER[0].hpack_send_lithdr_incidx = 0
D1027 18:15:46.881071586 4917 report.cc:106] SERVER[0].hpack_send_lithdr_incidx_v = 8
D1027 18:15:46.881077923 4917 report.cc:106] SERVER[0].hpack_send_lithdr_notidx = 0
D1027 18:15:46.881088623 4917 report.cc:106] SERVER[0].hpack_send_lithdr_notidx_v = 0
D1027 18:15:46.881095250 4917 report.cc:106] SERVER[0].hpack_send_lithdr_nvridx = 0
D1027 18:15:46.881101617 4917 report.cc:106] SERVER[0].hpack_send_lithdr_nvridx_v = 0
D1027 18:15:46.881108018 4917 report.cc:106] SERVER[0].hpack_send_uncompressed = 16
D1027 18:15:46.881114343 4917 report.cc:106] SERVER[0].hpack_send_huffman = 0
D1027 18:15:46.881120526 4917 report.cc:106] SERVER[0].hpack_send_binary = 0
D1027 18:15:46.881126810 4917 report.cc:106] SERVER[0].hpack_send_binary_base64 = 0
D1027 18:15:46.881133257 4917 report.cc:106] SERVER[0].combiner_locks_initiated = 50
D1027 18:15:46.881139870 4917 report.cc:106] SERVER[0].combiner_locks_scheduled_items = 86
D1027 18:15:46.881146681 4917 report.cc:106] SERVER[0].combiner_locks_scheduled_final_items = 21
D1027 18:15:46.881153189 4917 report.cc:106] SERVER[0].combiner_locks_offloaded = 0
D1027 18:15:46.881159704 4917 report.cc:106] SERVER[0].call_combiner_locks_initiated = 23
D1027 18:15:46.881166250 4917 report.cc:106] SERVER[0].call_combiner_locks_scheduled_items = 29
D1027 18:15:46.881172831 4917 report.cc:106] SERVER[0].call_combiner_set_notify_on_cancel = 1
D1027 18:15:46.881179387 4917 report.cc:106] SERVER[0].call_combiner_cancelled = 1
D1027 18:15:46.881185997 4917 report.cc:106] SERVER[0].executor_scheduled_short_items = 4
D1027 18:15:46.881192509 4917 report.cc:106] SERVER[0].executor_scheduled_long_items = 2
D1027 18:15:46.881198967 4917 report.cc:106] SERVER[0].executor_scheduled_to_self = 3
D1027 18:15:46.881205233 4917 report.cc:106] SERVER[0].executor_wakeup_initiated = 6
D1027 18:15:46.881211590 4917 report.cc:106] SERVER[0].executor_queue_drained = 6
D1027 18:15:46.881218071 4917 report.cc:106] SERVER[0].executor_push_retries = 1
D1027 18:15:46.881224560 4917 report.cc:106] SERVER[0].server_requested_calls = 640039
D1027 18:15:46.881230937 4917 report.cc:106] SERVER[0].server_slowpath_requests_queued = 0
D1027 18:15:46.881237446 4917 report.cc:106] SERVER[0].cq_ev_queue_trylock_failures = 0
D1027 18:15:46.881243877 4917 report.cc:106] SERVER[0].cq_ev_queue_trylock_successes = 55
D1027 18:15:46.881250353 4917 report.cc:106] SERVER[0].cq_ev_queue_transient_pop_failures = 0
D1027 18:15:46.881263826 4917 report.cc:110] SERVER[0].call_initial_size = 6132.0/7813.6/7915.5 (50/95/99%-ile)
D1027 18:15:46.881275580 4917 report.cc:110] SERVER[0].poll_events_returned = 0.0/0.0/0.0 (50/95/99%-ile)
D1027 18:15:46.881287963 4917 report.cc:110] SERVER[0].tcp_write_size = 205.0/3934886.8/4704565.4 (50/95/99%-ile)
D1027 18:15:46.881299307 4917 report.cc:110] SERVER[0].tcp_write_iov_size = 2.5/489.8/517.2 (50/95/99%-ile)
D1027 18:15:46.881309936 4917 report.cc:110] SERVER[0].tcp_read_size = 65.0/495.7/528.7 (50/95/99%-ile)
D1027 18:15:46.881321469 4917 report.cc:110] SERVER[0].tcp_read_offer = 14891.4/16767.5/16934.3 (50/95/99%-ile)
D1027 18:15:46.881331713 4917 report.cc:110] SERVER[0].tcp_read_offer_iov_size = 2.4/2.9/3.0 (50/95/99%-ile)
D1027 18:15:46.881361143 4917 report.cc:110] SERVER[0].http2_send_message_size = 11821.5/9916186.8/10184741.3 (50/95/99%-ile)
D1027 18:15:46.881385847 4917 report.cc:110] SERVER[0].http2_send_initial_metadata_per_write = 0.0/0.0/0.0 (50/95/99%-ile)
D1027 18:15:46.881394667 4917 report.cc:110] SERVER[0].http2_send_message_per_write = 0.0/0.0/0.0 (50/95/99%-ile)
D1027 18:15:46.881403287 4917 report.cc:110] SERVER[0].http2_send_trailing_metadata_per_write = 0.0/0.0/0.0 (50/95/99%-ile)
D1027 18:15:46.881415384 4917 report.cc:110] SERVER[0].http2_send_flowctl_per_write = 0.0/0.0/0.0 (50/95/99%-ile)
D1027 18:15:46.881423471 4917 report.cc:110] SERVER[0].server_cqs_checked = 0.5/0.9/1.0 (50/95/99%-ile)
I1027 18:15:46.881435899 4917 report.cc:119] QPS: 0.0 (0.0/server core)
I1027 18:15:46.881447590 4917 report.cc:124] Latencies (50/90/95/99/99.9%-ile): 0.0/0.0/0.0/0.0/0.0 us
I1027 18:15:46.881457587 4917 report.cc:134] Server system time: 3.11%
I1027 18:15:46.881469029 4917 report.cc:136] Server user time: 43.73%
I1027 18:15:46.881481874 4917 report.cc:138] Client system time: 0.00%
I1027 18:15:46.881492264 4917 report.cc:140] Client user time: 24.38%
I1027 18:15:46.881501776 4917 report.cc:145] Server CPU usage: 14.61%
I1027 18:15:46.881518858 4917 report.cc:150] Client Polls per Request: -nan
I1027 18:15:46.881530736 4917 report.cc:152] Server Polls per Request: inf
I1027 18:15:46.881552737 4917 report.cc:157] Server Queries/CPU-sec: 0.00
I1027 18:15:46.881559977 4917 report.cc:159] Client Queries/CPU-sec: 0.00
I1027 18:15:46.885313080 4904 json_run_localhost.cc:67] driver: subprocess exited with status 1
D1027 18:15:47.558942434 4909 ev_posix.cc:135] Using polling engine: epollsig
D1027 18:15:47.559042252 4909 dns_resolver.cc:306] Using native dns resolver
I1027 18:15:47.680932580 4904 json_run_localhost.cc:70] worker: subprocess terminated with signal 6
E1027 18:15:47.680976480 4904 json_run_localhost.cc:129] assertion failed: driver_join_status == 0
2017-10-27 18:15:47,801 FAILED: json_run_localhost:cpp_protobuf_async_client_unary_1channel_64wide_128Breq_8MBresp_secure_low_thread_count GRPC_POLL_STRATEGY=epollsig [ret=-6, pid=4904, time=125.4sec]
I suspect #13084 might be at fault.
Reactions are currently unavailable
Metadata
Metadata
Assignees
Labels
disposition/BUILDNURSEFor all buildnurse related build/test failures and flakesFor all buildnurse related build/test failures and flakesinfra/New Failurepriority/P0