Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[FLAKE] RBE UBSAN //test/cpp/qps:json_run_localhost_cpp_protobuf_async_streaming_ping_pong_insecure@poller=epollex #20309

Closed
lidizheng opened this issue Sep 19, 2019 · 2 comments
Closed

[FLAKE] RBE UBSAN //test/cpp/qps:json_run_localhost_cpp_protobuf_async_streaming_ping_pong_insecure@poller=epollex #20309

lidizheng opened this issue Sep 19, 2019 · 2 comments
Assignees
@vjpai
Labels
disposition/stale kind/bug lang/c++ priority/P2

Comments

@lidizheng
Copy link
Contributor

https://source.cloud.google.com/results/invocations/58c5acbd-d5bb-45e9-a023-03e2a13c0f9e/targets
@lidizheng lidizheng mentioned this issue Sep 19, 2019
Merged
@veblush
Copy link
Contributor

veblush commented Sep 23, 2019

Log for a failed test:

+ export GRPC_POLL_STRATEGY=epollex
+ shift
+ test/cpp/qps/json_run_localhost_cpp_protobuf_async_streaming_ping_pong_insecure --scenarios_json {scenarios : [{"name": "cpp_protobuf_async_streaming_ping_pong_insecure", "warmup_seconds": 0, "benchmark_seconds": 1, "num_servers": 1, "server_config": {"security_params": null, "server_type": "ASYNC_SERVER", "async_server_threads": 1, "threads_per_cq": 0, "channel_args": [{"str_value": "latency", "name": "grpc.optimization_target"}, {"int_value": 1, "name": "grpc.minimal_stack"}]}, "client_config": {"security_params": null, "channel_args": [{"str_value": "latency", "name": "grpc.optimization_target"}, {"int_value": 1, "name": "grpc.minimal_stack"}], "async_client_threads": 1, "outstanding_rpcs_per_channel": 1, "rpc_type": "STREAMING", "load_params": {"closed_loop": {}}, "histogram_params": {"resolution": 0.01, "max_possible": 60000000000.0}, "client_type": "ASYNC_CLIENT", "payload_config": {"simple_params": {"resp_size": 0, "req_size": 0}}, "client_channels": 1, "threads_per_cq": 0}, "num_clients": 1}]}
D0917 22:33:39.452329668      19 ev_posix.cc:174]            Using polling engine: epollex
D0917 22:33:39.452896577      19 dns_resolver_ares.cc:485]   Using ares dns resolver
I0917 22:33:39.453274486      19 server_builder.cc:309]      Synchronous server. Num CQs: 1, Min pollers: 1, Max Pollers: 2, CQ timeout (msec): 10000
D0917 22:33:39.453180631      18 ev_posix.cc:174]            Using polling engine: epollex
D0917 22:33:39.453779843      18 dns_resolver_ares.cc:485]   Using ares dns resolver
I0917 22:33:39.454223187      18 server_builder.cc:309]      Synchronous server. Num CQs: 1, Min pollers: 1, Max Pollers: 2, CQ timeout (msec): 10000
RUNNING SCENARIO: cpp_protobuf_async_streaming_ping_pong_insecure
I0917 22:33:39.467882786      20 driver.cc:283]              Starting server on localhost:21429 (worker #0)
D0917 22:33:39.468704054      20 ev_posix.cc:174]            Using polling engine: epollex
D0917 22:33:39.469047795      20 dns_resolver_ares.cc:485]   Using ares dns resolver
D0917 22:33:39.470739160      20 tcp_posix.cc:1253]          cannot set inq fd=9 errno=92
I0917 22:33:39.471088185      20 subchannel.cc:1086]         New connected subchannel at 0x51af150 for subchannel 0x51ff950
D0917 22:33:39.471352451      28 tcp_posix.cc:1253]          cannot set inq fd=8 errno=92
I0917 22:33:39.472693732      28 qps_worker.cc:236]          RunServerBody: about to create server
I0917 22:33:39.474694075      28 qps_worker.cc:72]           Starting server of type ASYNC_SERVER
I0917 22:33:39.782744805      28 qps_worker.cc:244]          RunServerBody: server created
I0917 22:33:39.783377876      28 qps_worker.cc:251]          RunServerBody: creation status reported
I0917 22:33:39.783761775      20 driver.cc:343]              Starting client on localhost:21430 (worker #1)
D0917 22:33:39.784005365      20 driver.cc:367]              Client 0 gets 1 channels
D0917 22:33:39.785076054      20 tcp_posix.cc:1253]          cannot set inq fd=12 errno=92
I0917 22:33:39.785335375      20 subchannel.cc:1086]         New connected subchannel at 0x520d730 for subchannel 0x520afc0
D0917 22:33:39.785605294      35 tcp_posix.cc:1253]          cannot set inq fd=16 errno=92
E0917 22:33:39.786675514      20 driver.cc:382]              Client 0 did not yield initial status
I0917 22:33:39.786694796      20 driver.cc:388]              Initiating
E0917 22:33:39.786887868      20 driver.cc:398]              Couldn't write mark to client 0
E0917 22:33:39.787053753      20 driver.cc:404]              Couldn't get status from client 0
I0917 22:33:39.787099185      20 driver.cc:409]              Warming up
I0917 22:33:39.787137151      20 driver.cc:415]              Starting
E0917 22:33:39.787460216      20 driver.cc:425]              Couldn't write mark to client 0
I0917 22:33:39.787559519      28 qps_worker.cc:253]          RunServerBody: Message read
I0917 22:33:39.788766653      28 qps_worker.cc:262]          RunServerBody: Mark response given
E0917 22:33:39.789701436      20 driver.cc:437]              Couldn't get status from client 0
I0917 22:33:39.789719113      20 driver.cc:442]              Running
I0917 22:33:40.787306310      20 driver.cc:456]              Finishing clients
E0917 22:33:40.787513223      20 driver.cc:460]              Couldn't write mark to client 0
E0917 22:33:40.787569962      20 driver.cc:481]              Couldn't get final status from client 0
E0917 22:33:40.787675394      20 driver.cc:489]              Client 0 had an error
I0917 22:33:40.787913080      20 driver.cc:502]              Finishing servers
I0917 22:33:40.788340875      28 qps_worker.cc:253]          RunServerBody: Message read
I0917 22:33:40.789661931      28 qps_worker.cc:262]          RunServerBody: Mark response given
I0917 22:33:40.789702809      28 qps_worker.cc:265]          RunServerBody: Returning
I0917 22:33:40.790891583      20 driver.cc:516]              Received final status from server 0
I0917 22:33:40.812637964      36 chttp2_transport.cc:1823]   ipv6:[::1]:59704: Sending goaway err={"created":"@1568759620.812497916","description":"Server shutdown","file":"src/core/lib/surface/server.cc","file_line":325,"grpc_status":0}
I0917 22:33:40.874421353      28 qps_worker.cc:132]          RunServer: Returning
I0917 22:33:40.875901384      20 report.cc:82]               QPS: -nan
D0917 22:33:40.876489789      20 report.cc:106]              SERVER[0].client_calls_created = 0
D0917 22:33:40.876523040      20 report.cc:106]              SERVER[0].server_calls_created = 0
D0917 22:33:40.876528456      20 report.cc:106]              SERVER[0].cqs_created = 0
D0917 22:33:40.876532588      20 report.cc:106]              SERVER[0].client_channels_created = 0
D0917 22:33:40.876536733      20 report.cc:106]              SERVER[0].client_subchannels_created = 0
D0917 22:33:40.876540568      20 report.cc:106]              SERVER[0].server_channels_created = 0
D0917 22:33:40.876544603      20 report.cc:106]              SERVER[0].syscall_poll = 0
D0917 22:33:40.876548279      20 report.cc:106]              SERVER[0].syscall_wait = 0
D0917 22:33:40.876551927      20 report.cc:106]              SERVER[0].pollset_kick = 0
D0917 22:33:40.876555831      20 report.cc:106]              SERVER[0].pollset_kicked_without_poller = 0
D0917 22:33:40.876559398      20 report.cc:106]              SERVER[0].pollset_kicked_again = 0
D0917 22:33:40.876563543      20 report.cc:106]              SERVER[0].pollset_kick_wakeup_fd = 0
D0917 22:33:40.876566996      20 report.cc:106]              SERVER[0].pollset_kick_wakeup_cv = 0
D0917 22:33:40.876571211      20 report.cc:106]              SERVER[0].pollset_kick_own_thread = 0
D0917 22:33:40.876575119      20 report.cc:106]              SERVER[0].syscall_epoll_ctl = 0
D0917 22:33:40.876579144      20 report.cc:106]              SERVER[0].pollset_fd_cache_hits = 0
D0917 22:33:40.876582719      20 report.cc:106]              SERVER[0].histogram_slow_lookups = 0
D0917 22:33:40.876586674      20 report.cc:106]              SERVER[0].syscall_write = 0
D0917 22:33:40.876590160      20 report.cc:106]              SERVER[0].syscall_read = 0
D0917 22:33:40.876593949      20 report.cc:106]              SERVER[0].tcp_backup_pollers_created = 0
D0917 22:33:40.876597624      20 report.cc:106]              SERVER[0].tcp_backup_poller_polls = 0
D0917 22:33:40.876601437      20 report.cc:106]              SERVER[0].http2_op_batches = 0
D0917 22:33:40.876605665      20 report.cc:106]              SERVER[0].http2_op_cancel = 0
D0917 22:33:40.876609984      20 report.cc:106]              SERVER[0].http2_op_send_initial_metadata = 0
D0917 22:33:40.876614400      20 report.cc:106]              SERVER[0].http2_op_send_message = 0
D0917 22:33:40.876618846      20 report.cc:106]              SERVER[0].http2_op_send_trailing_metadata = 0
D0917 22:33:40.876623332      20 report.cc:106]              SERVER[0].http2_op_recv_initial_metadata = 0
D0917 22:33:40.876627620      20 report.cc:106]              SERVER[0].http2_op_recv_message = 0
D0917 22:33:40.876631847      20 report.cc:106]              SERVER[0].http2_op_recv_trailing_metadata = 0
D0917 22:33:40.876635741      20 report.cc:106]              SERVER[0].http2_settings_writes = 0
D0917 22:33:40.876639379      20 report.cc:106]              SERVER[0].http2_pings_sent = 0
D0917 22:33:40.876643094      20 report.cc:106]              SERVER[0].http2_writes_begun = 0
D0917 22:33:40.876772726      20 report.cc:106]              SERVER[0].http2_writes_offloaded = 0
D0917 22:33:40.876778775      20 report.cc:106]              SERVER[0].http2_writes_continued = 0
D0917 22:33:40.876783084      20 report.cc:106]              SERVER[0].http2_partial_writes = 0
D0917 22:33:40.876788648      20 report.cc:106]              SERVER[0].http2_initiate_write_due_to_initial_write = 0
D0917 22:33:40.876793501      20 report.cc:106]              SERVER[0].http2_initiate_write_due_to_start_new_stream = 0
D0917 22:33:40.876798315      20 report.cc:106]              SERVER[0].http2_initiate_write_due_to_send_message = 0
D0917 22:33:40.876802161      20 report.cc:106]              SERVER[0].http2_initiate_write_due_to_send_initial_metadata = 0
D0917 22:33:40.876806191      20 report.cc:106]              SERVER[0].http2_initiate_write_due_to_send_trailing_metadata = 0
D0917 22:33:40.876810217      20 report.cc:106]              SERVER[0].http2_initiate_write_due_to_retry_send_ping = 0
D0917 22:33:40.876814455      20 report.cc:106]              SERVER[0].http2_initiate_write_due_to_continue_pings = 0
D0917 22:33:40.876819057      20 report.cc:106]              SERVER[0].http2_initiate_write_due_to_goaway_sent = 0
D0917 22:33:40.876823479      20 report.cc:106]              SERVER[0].http2_initiate_write_due_to_rst_stream = 0
D0917 22:33:40.876827856      20 report.cc:106]              SERVER[0].http2_initiate_write_due_to_close_from_api = 0
D0917 22:33:40.876832304      20 report.cc:106]              SERVER[0].http2_initiate_write_due_to_stream_flow_control = 0
D0917 22:33:40.876837498      20 report.cc:106]              SERVER[0].http2_initiate_write_due_to_transport_flow_control = 0
D0917 22:33:40.876841950      20 report.cc:106]              SERVER[0].http2_initiate_write_due_to_send_settings = 0
D0917 22:33:40.876846649      20 report.cc:106]              SERVER[0].http2_initiate_write_due_to_bdp_estimator_ping = 0
D0917 22:33:40.876851697      20 report.cc:106]              SERVER[0].http2_initiate_write_due_to_flow_control_unstalled_by_setting = 0
D0917 22:33:40.876856234      20 report.cc:106]              SERVER[0].http2_initiate_write_due_to_flow_control_unstalled_by_update = 0
D0917 22:33:40.876860793      20 report.cc:106]              SERVER[0].http2_initiate_write_due_to_application_ping = 0
D0917 22:33:40.876865625      20 report.cc:106]              SERVER[0].http2_initiate_write_due_to_keepalive_ping = 0
D0917 22:33:40.876870334      20 report.cc:106]              SERVER[0].http2_initiate_write_due_to_transport_flow_control_unstalled = 0
D0917 22:33:40.876875066      20 report.cc:106]              SERVER[0].http2_initiate_write_due_to_ping_response = 0
D0917 22:33:40.876879857      20 report.cc:106]              SERVER[0].http2_initiate_write_due_to_force_rst_stream = 0
D0917 22:33:40.876884651      20 report.cc:106]              SERVER[0].http2_spurious_writes_begun = 0
D0917 22:33:40.876888415      20 report.cc:106]              SERVER[0].hpack_recv_indexed = 0
D0917 22:33:40.876892585      20 report.cc:106]              SERVER[0].hpack_recv_lithdr_incidx = 0
D0917 22:33:40.876896247      20 report.cc:106]              SERVER[0].hpack_recv_lithdr_incidx_v = 0
D0917 22:33:40.876900210      20 report.cc:106]              SERVER[0].hpack_recv_lithdr_notidx = 0
D0917 22:33:40.876962898      20 report.cc:106]              SERVER[0].hpack_recv_lithdr_notidx_v = 0
D0917 22:33:40.876967906      20 report.cc:106]              SERVER[0].hpack_recv_lithdr_nvridx = 0
D0917 22:33:40.876971572      20 report.cc:106]              SERVER[0].hpack_recv_lithdr_nvridx_v = 0
D0917 22:33:40.876975780      20 report.cc:106]              SERVER[0].hpack_recv_uncompressed = 0
D0917 22:33:40.876980144      20 report.cc:106]              SERVER[0].hpack_recv_huffman = 0
D0917 22:33:40.876984604      20 report.cc:106]              SERVER[0].hpack_recv_binary = 0
D0917 22:33:40.876989655      20 report.cc:106]              SERVER[0].hpack_recv_binary_base64 = 0
D0917 22:33:40.876995810      20 report.cc:106]              SERVER[0].hpack_send_indexed = 0
D0917 22:33:40.877021980      20 report.cc:106]              SERVER[0].hpack_send_lithdr_incidx = 0
D0917 22:33:40.877026471      20 report.cc:106]              SERVER[0].hpack_send_lithdr_incidx_v = 0
D0917 22:33:40.877030574      20 report.cc:106]              SERVER[0].hpack_send_lithdr_notidx = 0
D0917 22:33:40.877034197      20 report.cc:106]              SERVER[0].hpack_send_lithdr_notidx_v = 0
D0917 22:33:40.877043367      20 report.cc:106]              SERVER[0].hpack_send_lithdr_nvridx = 0
D0917 22:33:40.877047237      20 report.cc:106]              SERVER[0].hpack_send_lithdr_nvridx_v = 0
D0917 22:33:40.877051376      20 report.cc:106]              SERVER[0].hpack_send_uncompressed = 0
D0917 22:33:40.877055202      20 report.cc:106]              SERVER[0].hpack_send_huffman = 0
D0917 22:33:40.877059107      20 report.cc:106]              SERVER[0].hpack_send_binary = 0
D0917 22:33:40.877062620      20 report.cc:106]              SERVER[0].hpack_send_binary_base64 = 0
D0917 22:33:40.877066376      20 report.cc:106]              SERVER[0].combiner_locks_initiated = 0
D0917 22:33:40.877069956      20 report.cc:106]              SERVER[0].combiner_locks_scheduled_items = 0
D0917 22:33:40.877074465      20 report.cc:106]              SERVER[0].combiner_locks_scheduled_final_items = 0
D0917 22:33:40.877078683      20 report.cc:106]              SERVER[0].combiner_locks_offloaded = 0
D0917 22:33:40.877083129      20 report.cc:106]              SERVER[0].call_combiner_locks_initiated = 0
D0917 22:33:40.877087151      20 report.cc:106]              SERVER[0].call_combiner_locks_scheduled_items = 0
D0917 22:33:40.877091571      20 report.cc:106]              SERVER[0].call_combiner_set_notify_on_cancel = 0
D0917 22:33:40.877095494      20 report.cc:106]              SERVER[0].call_combiner_cancelled = 0
D0917 22:33:40.877099463      20 report.cc:106]              SERVER[0].executor_scheduled_short_items = 0
D0917 22:33:40.877103463      20 report.cc:106]              SERVER[0].executor_scheduled_long_items = 0
D0917 22:33:40.877107609      20 report.cc:106]              SERVER[0].executor_scheduled_to_self = 0
D0917 22:33:40.877111841      20 report.cc:106]              SERVER[0].executor_wakeup_initiated = 0
D0917 22:33:40.877116243      20 report.cc:106]              SERVER[0].executor_queue_drained = 0
D0917 22:33:40.877120433      20 report.cc:106]              SERVER[0].executor_push_retries = 0
D0917 22:33:40.877124785      20 report.cc:106]              SERVER[0].server_requested_calls = 0
D0917 22:33:40.877129168      20 report.cc:106]              SERVER[0].server_slowpath_requests_queued = 0
D0917 22:33:40.877133731      20 report.cc:106]              SERVER[0].cq_ev_queue_trylock_failures = 0
D0917 22:33:40.877138056      20 report.cc:106]              SERVER[0].cq_ev_queue_trylock_successes = 0
D0917 22:33:40.877142408      20 report.cc:106]              SERVER[0].cq_ev_queue_transient_pop_failures = 0
D0917 22:33:40.877158283      20 report.cc:110]              SERVER[0].call_initial_size = 0.0/0.0/0.0 (50/95/99%-ile)
D0917 22:33:40.877176045      20 report.cc:110]              SERVER[0].poll_events_returned = 0.0/0.0/0.0 (50/95/99%-ile)
D0917 22:33:40.877187742      20 report.cc:110]              SERVER[0].tcp_write_size = 0.0/0.0/0.0 (50/95/99%-ile)
D0917 22:33:40.877199537      20 report.cc:110]              SERVER[0].tcp_write_iov_size = 0.0/0.0/0.0 (50/95/99%-ile)
D0917 22:33:40.877211296      20 report.cc:110]              SERVER[0].tcp_read_size = 0.0/0.0/0.0 (50/95/99%-ile)
D0917 22:33:40.877222695      20 report.cc:110]              SERVER[0].tcp_read_offer = 0.0/0.0/0.0 (50/95/99%-ile)
D0917 22:33:40.877234412      20 report.cc:110]              SERVER[0].tcp_read_offer_iov_size = 0.0/0.0/0.0 (50/95/99%-ile)
D0917 22:33:40.877246108      20 report.cc:110]              SERVER[0].http2_send_message_size = 0.0/0.0/0.0 (50/95/99%-ile)
D0917 22:33:40.877257982      20 report.cc:110]              SERVER[0].http2_send_initial_metadata_per_write = 0.0/0.0/0.0 (50/95/99%-ile)
D0917 22:33:40.877269821      20 report.cc:110]              SERVER[0].http2_send_message_per_write = 0.0/0.0/0.0 (50/95/99%-ile)
D0917 22:33:40.877280897      20 report.cc:110]              SERVER[0].http2_send_trailing_metadata_per_write = 0.0/0.0/0.0 (50/95/99%-ile)
D0917 22:33:40.877292654      20 report.cc:110]              SERVER[0].http2_send_flowctl_per_write = 0.0/0.0/0.0 (50/95/99%-ile)
D0917 22:33:40.877300568      20 report.cc:110]              SERVER[0].server_cqs_checked = 0.0/0.0/0.0 (50/95/99%-ile)
I0917 22:33:40.877310100      20 report.cc:122]              QPS: -nan (-nan/server core)
I0917 22:33:40.877316856      20 report.cc:127]              Latencies (50/90/95/99/99.9%-ile): 0.0/0.0/0.0/0.0/0.0 us
I0917 22:33:40.877322822      20 report.cc:137]              Server system time: 0.03%
I0917 22:33:40.877327603      20 report.cc:139]              Server user time:   0.17%
I0917 22:33:40.877398662      20 report.cc:141]              Client system time: -nan%
I0917 22:33:40.877404086      20 report.cc:143]              Client user time:   -nan%
I0917 22:33:40.877410589      20 report.cc:148]              Server CPU usage: 1.02%
I0917 22:33:40.877415626      20 report.cc:153]              Client Polls per Request: -nan
I0917 22:33:40.877419298      20 report.cc:155]              Server Polls per Request: -nan
I0917 22:33:40.877424368      20 report.cc:160]              Server Queries/CPU-sec: 0.00
I0917 22:33:40.877428298      20 report.cc:162]              Client Queries/CPU-sec: -nan
I0917 22:33:40.879766157      17 json_run_localhost.cc:71]   driver: subprocess exited with status 1
E0917 22:33:44.461328672      17 json_run_localhost.cc:133]  assertion failed: driver_join_status == 0
Aborted (core dumped)

@veblush veblush removed their assignment Sep 24, 2019
@stale
Copy link

stale bot commented Mar 22, 2020

This issue/PR has been automatically marked as stale because it has not had any update (including commits, comments, labels, milestones, etc) for 180 days. It will be closed automatically if no further update occurs in 1 day. Thank you for your contributions!

@stale stale bot closed this as completed Mar 29, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@vjpai vjpai

Labels
disposition/stale kind/bug lang/c++ priority/P2
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@veblush @lidizheng @vjpai