Skip to content

Instantly share code, notes, and snippets.

Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save nupuruttarwar/62d6bcb277309fc878d7f348d57c3fb6 to your computer and use it in GitHub Desktop.
Save nupuruttarwar/62d6bcb277309fc878d7f348d57c3fb6 to your computer and use it in GitHub Desktop.
Trace logs with gRPC version 1.17.2 for successful gnmi client send request
[root@ea2298e003c9 scripts]# sudo gnmi-cli set "device:virtual-device,name:net_vhost0,host:host1,device-type:VIRTIO_NET,queues:1,socket-path:/tmp/vhost-user-0,port-type:LINK"
D1214 06:07:13.405633992 113724 ev_posix.cc:169] Using polling engine: epollex
D1214 06:07:13.405751865 113724 dns_resolver.cc:338] Using native dns resolver
I1214 06:07:13.405830682 113724 init.cc:154] grpc_init(void)
I1214 06:07:13.405861823 113724 init.cc:154] grpc_init(void)
I1214 06:07:13.405881237 113724 channel_create.cc:91] grpc_insecure_channel_create(target=127.0.0.1:9339, args=0x7fff1c760ae0, reserved=(nil))
I1214 06:07:13.405954787 113724 ev_epollex_linux.cc:1488] PSS:0x2401aa0: add pollset 0x240a510
I1214 06:07:13.405962870 113724 ev_epollex_linux.cc:558] (fd-trace) Pollable_create: created epfd: 5 (type: 0)
I1214 06:07:13.405970913 113724 ev_epollex_linux.cc:1303] PS:0x240a510 active pollable transition from empty to multi
I1214 06:07:13.405987853 113724 ev_epollex_linux.cc:1525] PSS: merge (0x2405270, 0x2401aa0)
I1214 06:07:13.406001259 113724 ev_epollex_linux.cc:1559] PSS: parent 0x2405270 to 0x2401aa0
I1214 06:07:13.406017403 113724 channel.cc:285] grpc_channel_get_target(channel=0x240aa20)
I1214 06:07:13.406034597 113724 init.cc:154] grpc_init(void)
I1214 06:07:13.406038783 113724 init.cc:159] grpc_shutdown(void)
I1214 06:07:13.406075122 113724 channel.cc:376] grpc_channel_register_call(channel=0x240aa20, method=/gnmi.gNMI/Capabilities, host=(null), reserved=(nil))
I1214 06:07:13.406084506 113724 channel.cc:376] grpc_channel_register_call(channel=0x240aa20, method=/gnmi.gNMI/Get, host=(null), reserved=(nil))
I1214 06:07:13.406090003 113724 channel.cc:376] grpc_channel_register_call(channel=0x240aa20, method=/gnmi.gNMI/Set, host=(null), reserved=(nil))
I1214 06:07:13.406094098 113724 channel.cc:376] grpc_channel_register_call(channel=0x240aa20, method=/gnmi.gNMI/Subscribe, host=(null), reserved=(nil))
I1214 06:07:13.406411822 113724 init.cc:154] grpc_init(void)
I1214 06:07:13.406424725 113724 completion_queue.cc:478] grpc_completion_queue_create_internal(completion_type=1, polling_type=0)
I1214 06:07:13.406465439 113724 channel.cc:403] grpc_channel_create_registered_call(channel=0x240aa20, parent_call=(nil), propagation_mask=ffff, completion_queue=0x240c940, registered_call_handle=0x2406c70, deadline=gpr_timespec { tv_sec: 9223372036854775807, tv_nsec: 0, clock_type: 1 }, reserved=(nil))
I1214 06:07:13.406501575 113724 grpc_context.cc:27] grpc_census_call_set_context(call=0x2419bc0, census_context=(nil))
I1214 06:07:13.406557900 113724 call.cc:1900] grpc_call_start_batch(call=0x2419bc0, ops=0x7fff1c7606c0, nops=6, tag=0x7fff1c7609e0, reserved=(nil))
I1214 06:07:13.406571401 113724 call.cc:1508] ops[0]: SEND_INITIAL_METADATA(nil)
I1214 06:07:13.406576731 113724 call.cc:1508] ops[1]: SEND_MESSAGE ptr=0x23e3840
I1214 06:07:13.406581708 113724 call.cc:1508] ops[2]: RECV_INITIAL_METADATA ptr=0x7fff1c761100
I1214 06:07:13.406588135 113724 call.cc:1508] ops[3]: RECV_MESSAGE ptr=0x7fff1c760a48
I1214 06:07:13.406591310 113724 call.cc:1508] ops[4]: SEND_CLOSE_FROM_CLIENT
I1214 06:07:13.406597999 113724 call.cc:1508] ops[5]: RECV_STATUS_ON_CLIENT metadata=0x7fff1c761150 status=0x7fff1c760a80 details=0x7fff1c760a88
I1214 06:07:13.406616885 113724 call_combiner.cc:69] ==> grpc_call_combiner_start() [0x2419bd0] closure=0x241ab08 [executing batch] error="No Error"
I1214 06:07:13.406624692 113724 call_combiner.cc:78] size: 0 -> 1
I1214 06:07:13.406630895 113724 call_combiner.cc:87] EXECUTING IMMEDIATELY
I1214 06:07:13.406649472 113724 call.cc:613] OP[client-channel:0x241a540]: SEND_INITIAL_METADATA{key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set'} SEND_MESSAGE:flags=0x00000000:len=86 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.406659492 113724 client_channel.cc:1204] chand=0x240aae8 calld=0x241a560: adding pending batch at index 0
I1214 06:07:13.406670557 113724 client_channel.cc:3197] chand=0x240aae8 calld=0x241a560: entering client_channel combiner
I1214 06:07:13.406682335 113724 client_channel.cc:243] chand=0x240aae8: starting name resolution
D1214 06:07:13.406689902 113724 dns_resolver.cc:279] Start resolving.
I1214 06:07:13.406700913 113724 executor.cc:242] EXECUTOR (resolver-executor) try to schedule 0x2407540 (short) to thread 0
I1214 06:07:13.406714163 113724 client_channel.cc:2951] chand=0x240aae8 calld=0x241a560: deferring pick pending resolver result
I1214 06:07:13.406722096 113724 call_combiner.cc:167] call_combiner=0x2419bd0: setting notify_on_cancel=0x2403820
I1214 06:07:13.406731030 113724 ev_epollex_linux.cc:1488] PSS:0x2401aa0: add pollset 0x240ca40
I1214 06:07:13.406737131 113724 ev_epollex_linux.cc:558] (fd-trace) Pollable_create: created epfd: 7 (type: 0)
I1214 06:07:13.406745443 113724 ev_epollex_linux.cc:1303] PS:0x240ca40 active pollable transition from empty to multi
I1214 06:07:13.406754163 113724 completion_queue.cc:1198] grpc_completion_queue_pluck(cq=0x240c940, tag=0x7fff1c7609e0, deadline=gpr_timespec { tv_sec: 9223372036854775807, tv_nsec: 0, clock_type: 1 }, reserved=(nil))
I1214 06:07:13.406761288 113724 ev_epollex_linux.cc:1176] PS:0x240ca40 work hdl=0x7fff1c7607a8 worker=0x7fff1c7606e0 now=1 deadline=9223372036854775807 kwp=0 pollable=0x241b2d0
I1214 06:07:13.406821416 113724 ev_epollex_linux.cc:994] POLLABLE:0x241b2d0[type=pollset epfd=7 wakeup=8] poll for -1ms
I1214 06:07:13.406736828 113726 executor.cc:188] EXECUTOR (resolver-executor) [0]: execute
I1214 06:07:13.406859930 113726 executor.cc:73] EXECUTOR (resolver-executor) run 0x2407540
I1214 06:07:13.406989271 113726 client_channel.cc:438] chand=0x240aae8: got resolver result: resolver_result=0x7f21e4000e80 error="No Error"
I1214 06:07:13.407022916 113726 pick_first.cc:161] Pick First 0x7f21e4001430 created.
I1214 06:07:13.407060679 113726 pick_first.cc:360] Pick First 0x7f21e4001430 received update with 1 addresses
I1214 06:07:13.407075295 113726 subchannel_list.h:501] [pick_first 0x7f21e4001430] Creating subchannel list 0x7f21e4001b20 for 1 subchannels
I1214 06:07:13.407235985 113726 subchannel_list.h:546] [pick_first 0x7f21e4001430] subchannel list 0x7f21e4001b20 index 0: Created subchannel 0x7f21e4002750 for address uri ipv4:127.0.0.1:9339
I1214 06:07:13.407254915 113726 client_channel.cc:340] chand=0x240aae8: created new LB policy "pick_first" (0x7f21e4001430)
I1214 06:07:13.407279477 113726 ev_epollex_linux.cc:1525] PSS: merge (0x7f21e40017f0, 0x2401aa0)
I1214 06:07:13.407290676 113726 ev_epollex_linux.cc:1559] PSS: parent 0x7f21e40017f0 to 0x2401aa0
I1214 06:07:13.407328566 113726 connectivity_state.cc:92] CONWATCH: 0x7f21e4001618 pick_first: get IDLE
I1214 06:07:13.407340269 113726 connectivity_state.cc:116] CONWATCH: 0x7f21e4001618 pick_first: from IDLE [cur=IDLE] notify=0x7f21e4001ec8
I1214 06:07:13.407358738 113726 client_channel.cc:196] chand=0x240aae8: setting connectivity state to IDLE
I1214 06:07:13.407372028 113726 connectivity_state.cc:164] SET: 0x240ab70 client_channel: IDLE --> IDLE [resolver_result] error=(nil) "No Error"
I1214 06:07:13.407384184 113726 client_channel.cc:3040] chand=0x240aae8 calld=0x241a560: resolver returned, doing LB pick
I1214 06:07:13.407394661 113726 client_channel.cc:2855] chand=0x240aae8 calld=0x241a560: applying service config to call
I1214 06:07:13.407407276 113726 connectivity_state.cc:81] CONWATCH: 0x240ab70 client_channel: get IDLE
I1214 06:07:13.407418577 113726 client_channel.cc:2763] chand=0x240aae8 calld=0x241a560: starting pick on lb_policy=0x7f21e4001430
I1214 06:07:13.407429089 113726 connectivity_state.cc:92] CONWATCH: 0x7f21e4002838 subchannel: get IDLE
I1214 06:07:13.407440579 113726 subchannel_list.h:332] [pick_first 0x7f21e4001430] subchannel list 0x7f21e4001b20 index 0 of 1 (subchannel 0x7f21e4002750): starting watch: requesting connectivity change notification (from IDLE)
I1214 06:07:13.407454029 113726 ev_epollex_linux.cc:1525] PSS: merge (0x7f21e4002950, 0x7f21e40017f0)
I1214 06:07:13.407463835 113726 ev_epollex_linux.cc:1559] PSS: parent 0x7f21e4002950 to 0x2401aa0
I1214 06:07:13.407474203 113726 connectivity_state.cc:116] CONWATCH: 0x7f21e4002838 subchannel: from IDLE [cur=IDLE] notify=0x7f21e4003c88
I1214 06:07:13.407489472 113726 connectivity_state.cc:164] SET: 0x7f21e4002838 subchannel: IDLE --> CONNECTING [connecting] error=(nil) "No Error"
I1214 06:07:13.407499025 113726 connectivity_state.cc:190] NOTIFY: 0x7f21e4002838 subchannel: 0x7f21e4003c88
I1214 06:07:13.407509906 113726 connectivity_state.cc:164] SET: 0x7f21e4002858 subchannel: IDLE --> CONNECTING [connecting] error=(nil) "No Error"
I1214 06:07:13.407612411 113726 socket_utils_common_posix.cc:346] Disabling AF_INET6 sockets because ::1 is not available.
I1214 06:07:13.407707078 113726 ev_posix.cc:249] (fd-trace) fd_create(9, tcp-client:ipv4:127.0.0.1:9339, 1)
I1214 06:07:13.407827704 113726 ev_epollex_linux.cc:1391] PSS:0x7f21e4002950: add fd 0x7f21e4003810 (9)
I1214 06:07:13.407840905 113726 ev_epollex_linux.cc:674] add fd 0x7f21e4003810 (9) to pollable 0x2408890
I1214 06:07:13.407859515 113726 ev_epollex_linux.cc:674] add fd 0x7f21e4003810 (9) to pollable 0x241b2d0
I1214 06:07:13.407881930 113724 ev_epollex_linux.cc:1013] POLLABLE:0x241b2d0 got 1 events
I1214 06:07:13.407929974 113724 ev_epollex_linux.cc:961] PS:0x240ca40 got fd 0x7f21e4003810: cancel=0 read=0 write=1
I1214 06:07:13.407884083 113726 tcp_client_posix.cc:332] CLIENT_CONNECT: ipv4:127.0.0.1:9339: asynchronously connecting fd 0x7f21e4003810
E1214 06:07:13.408013687 113724 lockfree_event.cc:213] LockfreeEvent::SetReady: 0x7f21e4003888 curr=(nil)
E1214 06:07:13.408053780 113726 lockfree_event.cc:98] LockfreeEvent::NotifyOn: 0x7f21e4003888 curr=(nil) closure=0x7f21e4000e20
I1214 06:07:13.408061010 113724 ev_epollex_linux.cc:722] PS:0x240ca40 (pollable:0x241b2d0) maybe_finish_shutdown sc=(nil) (target:!NULL) rw=(nil) (target:NULL) cpsc=1 (target:0)
I1214 06:07:13.408105193 113724 ev_epollex_linux.cc:1176] PS:0x240ca40 work hdl=0x7fff1c7607a8 worker=0x7fff1c7606e0 now=2 deadline=9223372036854775807 kwp=0 pollable=0x241b2d0
I1214 06:07:13.408143225 113724 ev_epollex_linux.cc:994] POLLABLE:0x241b2d0[type=pollset epfd=7 wakeup=8] poll for -1ms
E1214 06:07:13.408064664 113726 lockfree_event.cc:98] LockfreeEvent::NotifyOn: 0x7f21e4003888 curr=0x2 closure=0x7f21e4000e20
I1214 06:07:13.408183576 113726 call_combiner.cc:167] call_combiner=0x2419bd0: setting notify_on_cancel=0x241a728
I1214 06:07:13.408194710 113726 call_combiner.cc:176] call_combiner=0x2419bd0: scheduling old cancel callback=0x2403820
I1214 06:07:13.408215451 113726 tcp_client_posix.cc:150] CLIENT_CONNECT: ipv4:127.0.0.1:9339: on_writable: error="No Error"
I1214 06:07:13.408232796 113726 ev_epollex_linux.cc:1415] PSS:0x7f21e4002950: del fd 0x7f21e4003810
I1214 06:07:13.408261186 113726 tcp_client_posix.cc:113] CLIENT_CONNECT: ipv4:127.0.0.1:9339: on_alarm: error="Cancelled"
I1214 06:07:13.408296732 113726 handshaker.cc:141] handshake_manager 0x7f21e4004700: adding handshaker http_connect [0x7f21e4004850] at index 0
I1214 06:07:13.408315553 113726 ev_epollex_linux.cc:1391] PSS:0x7f21e4002950: add fd 0x7f21e4003810 (9)
I1214 06:07:13.408353161 113726 handshaker.cc:212] handshake_manager 0x7f21e4004700: error="No Error" shutdown=0 index=0, args={endpoint=0x7f21e4004260, args=0x7f21e4004070 {size=6: grpc.primary_user_agent=grpc-c++/1.17.1, grpc.client_channel_factory=0x7f21f2abb778, grpc.server_uri=dns:///127.0.0.1:9339, grpc.channelz_channel_node_creation_func=0x7f21f2a1ccc0, grpc.default_authority=127.0.0.1:9339, grpc.subchannel_address=ipv4:127.0.0.1:9339}, read_buffer=0x7f21e4003f40 (length=0), exit_early=0}
I1214 06:07:13.408367218 113726 handshaker.cc:258] handshake_manager 0x7f21e4004700: calling handshaker http_connect [0x7f21e4004850] at index 0
I1214 06:07:13.408392246 113726 handshaker.cc:212] handshake_manager 0x7f21e4004700: error="No Error" shutdown=0 index=1, args={endpoint=0x7f21e4004260, args=0x7f21e4004070 {size=6: grpc.primary_user_agent=grpc-c++/1.17.1, grpc.client_channel_factory=0x7f21f2abb778, grpc.server_uri=dns:///127.0.0.1:9339, grpc.channelz_channel_node_creation_func=0x7f21f2a1ccc0, grpc.default_authority=127.0.0.1:9339, grpc.subchannel_address=ipv4:127.0.0.1:9339}, read_buffer=0x7f21e4003f40 (length=0), exit_early=0}
I1214 06:07:13.408405838 113726 handshaker.cc:245] handshake_manager 0x7f21e4004700: handshaking complete -- scheduling on_handshake_done with error="No Error"
I1214 06:07:13.408416850 113726 ev_epollex_linux.cc:1415] PSS:0x7f21e4002950: del fd 0x7f21e4003810
I1214 06:07:13.408440201 113724 ev_epollex_linux.cc:1013] POLLABLE:0x241b2d0 got 1 events
I1214 06:07:13.408447531 113724 ev_epollex_linux.cc:961] PS:0x240ca40 got fd 0x7f21e4003810: cancel=0 read=1 write=1
E1214 06:07:13.408452394 113724 lockfree_event.cc:213] LockfreeEvent::SetReady: 0x7f21e4003880 curr=(nil)
E1214 06:07:13.408459057 113724 lockfree_event.cc:213] LockfreeEvent::SetReady: 0x7f21e4003888 curr=(nil)
I1214 06:07:13.408467959 113724 ev_epollex_linux.cc:722] PS:0x240ca40 (pollable:0x241b2d0) maybe_finish_shutdown sc=(nil) (target:!NULL) rw=(nil) (target:NULL) cpsc=1 (target:0)
I1214 06:07:13.408477178 113724 ev_epollex_linux.cc:1176] PS:0x240ca40 work hdl=0x7fff1c7607a8 worker=0x7fff1c7606e0 now=3 deadline=9223372036854775807 kwp=0 pollable=0x241b2d0
I1214 06:07:13.408486000 113724 ev_epollex_linux.cc:994] POLLABLE:0x241b2d0[type=pollset epfd=7 wakeup=8] poll for -1ms
I1214 06:07:13.408521693 113726 bdp_estimator.h:53] bdp[ipv4:127.0.0.1:9339]:sched acc=0 est=65536
I1214 06:07:13.408564562 113726 chttp2_transport.cc:849] W:0x7f21e4006400 CLIENT state IDLE -> WRITING [TRANSPORT_FLOW_CONTROL]
I1214 06:07:13.408577486 113726 chttp2_transport.cc:849] W:0x7f21e4006400 CLIENT state WRITING -> WRITING+MORE [INITIAL_WRITE]
I1214 06:07:13.408644995 113726 subchannel.cc:841] New connected subchannel at 0x7f21e4001310 for subchannel 0x7f21e4002750
I1214 06:07:13.408666191 113726 chttp2_transport.cc:1866] perform_transport_op[t=0x7f21e4006400]: ON_CONNECTIVITY_STATE_CHANGE:p=0x7f21e4004ab8:from=READY BIND_POLLSET_SET
I1214 06:07:13.408680050 113726 connectivity_state.cc:164] SET: 0x7f21e4002838 subchannel: CONNECTING --> READY [subchannel_connected] error=(nil) "No Error"
I1214 06:07:13.408691090 113726 connectivity_state.cc:164] SET: 0x7f21e4002858 subchannel: CONNECTING --> READY [subchannel_connected] error=(nil) "No Error"
I1214 06:07:13.408707002 113726 subchannel_list.h:447] [pick_first 0x7f21e4001430] subchannel list 0x7f21e4001b20 index 0 of 1 (subchannel 0x7f21e4002750): connectivity changed: state=CONNECTING, error="No Error", shutting_down=0
I1214 06:07:13.408719706 113726 connectivity_state.cc:164] SET: 0x7f21e4001618 pick_first: IDLE --> CONNECTING [connecting_changed] error=(nil) "No Error"
I1214 06:07:13.408730368 113726 connectivity_state.cc:190] NOTIFY: 0x7f21e4001618 pick_first: 0x7f21e4001ec8
I1214 06:07:13.408742001 113726 subchannel_list.h:354] [pick_first 0x7f21e4001430] subchannel list 0x7f21e4001b20 index 0 of 1 (subchannel 0x7f21e4002750): renewing watch: requesting connectivity change notification (from CONNECTING)
I1214 06:07:13.408755521 113726 ev_epollex_linux.cc:1525] PSS: merge (0x7f21e4002950, 0x7f21e40017f0)
I1214 06:07:13.408767271 113726 connectivity_state.cc:116] CONWATCH: 0x7f21e4002838 subchannel: from CONNECTING [cur=READY] notify=0x7f21e4004c88
I1214 06:07:13.408779297 113726 client_channel.cc:214] chand=0x240aae8: lb_policy=0x7f21e4001430 state changed to CONNECTING
I1214 06:07:13.408790357 113726 client_channel.cc:196] chand=0x240aae8: setting connectivity state to CONNECTING
I1214 06:07:13.408801848 113726 connectivity_state.cc:164] SET: 0x240ab70 client_channel: IDLE --> CONNECTING [lb_changed] error=(nil) "No Error"
I1214 06:07:13.408812701 113726 connectivity_state.cc:116] CONWATCH: 0x7f21e4001618 pick_first: from CONNECTING [cur=CONNECTING] notify=0x7f21e4003b98
I1214 06:07:13.408826264 113726 subchannel_list.h:447] [pick_first 0x7f21e4001430] subchannel list 0x7f21e4001b20 index 0 of 1 (subchannel 0x7f21e4002750): connectivity changed: state=READY, error="No Error", shutting_down=0
I1214 06:07:13.408839330 113726 connectivity_state.cc:164] SET: 0x7f21e4001618 pick_first: CONNECTING --> READY [subchannel_ready] error=(nil) "No Error"
I1214 06:07:13.408850801 113726 connectivity_state.cc:190] NOTIFY: 0x7f21e4001618 pick_first: 0x7f21e4003b98
I1214 06:07:13.408862727 113726 pick_first.cc:591] Pick First 0x7f21e4001430 selected subchannel 0x7f21e4002750
I1214 06:07:13.408872541 113726 pick_first.cc:599] Servicing pending pick with selected subchannel 0x7f21e4002750
I1214 06:07:13.408884789 113726 subchannel_list.h:354] [pick_first 0x7f21e4001430] subchannel list 0x7f21e4001b20 index 0 of 1 (subchannel 0x7f21e4002750): renewing watch: requesting connectivity change notification (from READY)
I1214 06:07:13.408895345 113726 ev_epollex_linux.cc:1525] PSS: merge (0x7f21e4002950, 0x7f21e40017f0)
I1214 06:07:13.408905679 113726 connectivity_state.cc:116] CONWATCH: 0x7f21e4002838 subchannel: from READY [cur=READY] notify=0x7f21e4005198
I1214 06:07:13.408916681 113726 client_channel.cc:214] chand=0x240aae8: lb_policy=0x7f21e4001430 state changed to READY
I1214 06:07:13.408926748 113726 client_channel.cc:196] chand=0x240aae8: setting connectivity state to READY
I1214 06:07:13.408937387 113726 connectivity_state.cc:164] SET: 0x240ab70 client_channel: CONNECTING --> READY [lb_changed] error=(nil) "No Error"
I1214 06:07:13.408960494 113726 connectivity_state.cc:116] CONWATCH: 0x7f21e4001618 pick_first: from READY [cur=READY] notify=0x7f21e4001ec8
I1214 06:07:13.408971205 113726 client_channel.cc:2819] chand=0x240aae8 calld=0x241a560: pick completed asynchronously
I1214 06:07:13.408984927 113726 ev_epollex_linux.cc:1436] PSS:0x2401aa0: del pollset 0x240ca40
I1214 06:07:13.408997143 113726 ev_epollex_linux.cc:722] PS:0x240ca40 (pollable:0x241b2d0) maybe_finish_shutdown sc=(nil) (target:!NULL) rw=0x7fff1c7606e0 (target:NULL) cpsc=0 (target:0)
I1214 06:07:13.409034823 113726 client_channel.cc:2669] chand=0x240aae8 calld=0x241a560: create subchannel_call=0x7f21e40082c0: error="No Error"
I1214 06:07:13.409045814 113726 client_channel.cc:1346] chand=0x240aae8 calld=0x241a560: starting 1 pending batches on subchannel_call=0x7f21e40082c0
I1214 06:07:13.409057560 113726 call_combiner.h:153] CallCombinerClosureList executing closure while already holding call_combiner 0x2419bd0: closure=0x241aab8 error="No Error" reason=pending_batches_resume
I1214 06:07:13.409082626 113726 subchannel.cc:1000] OP[authority:0x7f21e4008360]: SEND_INITIAL_METADATA{key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set'} SEND_MESSAGE:flags=0x00000000:len=86 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.409113506 113726 channel_stack.cc:226] OP[message_size:0x7f21e4008378]: SEND_INITIAL_METADATA{key=3a 61 75 74 68 6f 72 69 74 79 ':authority' value=31 32 37 2e 30 2e 30 2e 31 3a 39 33 33 39 '127.0.0.1:9339', key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set'} SEND_MESSAGE:flags=0x00000000:len=86 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.409142686 113726 channel_stack.cc:226] OP[http-client:0x7f21e4008390]: SEND_INITIAL_METADATA{key=3a 61 75 74 68 6f 72 69 74 79 ':authority' value=31 32 37 2e 30 2e 30 2e 31 3a 39 33 33 39 '127.0.0.1:9339', key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set'} SEND_MESSAGE:flags=0x00000000:len=86 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.409193283 113726 channel_stack.cc:226] OP[message_compress:0x7f21e40083a8]: SEND_INITIAL_METADATA{key=3a 73 63 68 65 6d 65 ':scheme' value=68 74 74 70 'http', key=3a 6d 65 74 68 6f 64 ':method' value=50 4f 53 54 'POST', key=3a 61 75 74 68 6f 72 69 74 79 ':authority' value=31 32 37 2e 30 2e 30 2e 31 3a 39 33 33 39 '127.0.0.1:9339', key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set', key=74 65 'te' value=74 72 61 69 6c 65 72 73 'trailers', key=63 6f 6e 74 65 6e 74 2d 74 79 70 65 'content-type' value=61 70 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 'application/grpc', key=75 73 65 72 2d 61 67 65 6e 74 'user-agent' value=67 72 70 63 2d 63 2b 2b 2f 31 2e 31 37 2e 31 20 67 72 70 63 2d 63 2f 37 2e 30 2e 30 20 28 6c 69 6e 75 78 3b 20 63 68 74 74 70 32 3b 20 67 69 7a 6d 6f 29 'grpc-c++/1.17.1 grpc-c/7.0.0 (linux; chttp2; gizmo)'} SEND_MESSAGE:flags=0x00000000:len=86 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.409248151 113726 channel_stack.cc:226] OP[connected:0x7f21e40083c0]: SEND_INITIAL_METADATA{key=3a 73 63 68 65 6d 65 ':scheme' value=68 74 74 70 'http', key=3a 6d 65 74 68 6f 64 ':method' value=50 4f 53 54 'POST', key=3a 61 75 74 68 6f 72 69 74 79 ':authority' value=31 32 37 2e 30 2e 30 2e 31 3a 39 33 33 39 '127.0.0.1:9339', key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set', key=74 65 'te' value=74 72 61 69 6c 65 72 73 'trailers', key=63 6f 6e 74 65 6e 74 2d 74 79 70 65 'content-type' value=61 70 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 'application/grpc', key=75 73 65 72 2d 61 67 65 6e 74 'user-agent' value=67 72 70 63 2d 63 2b 2b 2f 31 2e 31 37 2e 31 20 67 72 70 63 2d 63 2f 37 2e 30 2e 30 20 28 6c 69 6e 75 78 3b 20 63 68 74 74 70 32 3b 20 67 69 7a 6d 6f 29 'grpc-c++/1.17.1 grpc-c/7.0.0 (linux; chttp2; gizmo)', key=67 72 70 63 2d 61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'grpc-accept-encoding' value=69 64 65 6e 74 69 74 79 2c 64 65 66 6c 61 74 65 2c 67 7a 69 70 'identity,deflate,gzip', key=61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'accept-encoding' value=69 64 65 6e 74 69 74 79 2c 67 7a 69 70 'identity,gzip'} SEND_MESSAGE:flags=0x00000000:len=86 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.409308629 113726 chttp2_transport.cc:1702] perform_stream_op[s=0x7f21e4008d98]: SEND_INITIAL_METADATA{key=3a 73 63 68 65 6d 65 ':scheme' value=68 74 74 70 'http', key=3a 6d 65 74 68 6f 64 ':method' value=50 4f 53 54 'POST', key=3a 61 75 74 68 6f 72 69 74 79 ':authority' value=31 32 37 2e 30 2e 30 2e 31 3a 39 33 33 39 '127.0.0.1:9339', key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set', key=74 65 'te' value=74 72 61 69 6c 65 72 73 'trailers', key=63 6f 6e 74 65 6e 74 2d 74 79 70 65 'content-type' value=61 70 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 'application/grpc', key=75 73 65 72 2d 61 67 65 6e 74 'user-agent' value=67 72 70 63 2d 63 2b 2b 2f 31 2e 31 37 2e 31 20 67 72 70 63 2d 63 2f 37 2e 30 2e 30 20 28 6c 69 6e 75 78 3b 20 63 68 74 74 70 32 3b 20 67 69 7a 6d 6f 29 'grpc-c++/1.17.1 grpc-c/7.0.0 (linux; chttp2; gizmo)', key=67 72 70 63 2d 61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'grpc-accept-encoding' value=69 64 65 6e 74 69 74 79 2c 64 65 66 6c 61 74 65 2c 67 7a 69 70 'identity,deflate,gzip', key=61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'accept-encoding' value=69 64 65 6e 74 69 74 79 2c 67 7a 69 70 'identity,gzip'} SEND_MESSAGE:flags=0x00000000:len=86 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.409328890 113726 call_combiner.cc:106] ==> grpc_call_combiner_stop() [0x2419bd0] [passed batch to transport]
I1214 06:07:13.409339020 113726 call_combiner.cc:113] size: 1 -> 0
I1214 06:07:13.409348361 113726 call_combiner.cc:141] queue empty
I1214 06:07:13.409360918 113726 tcp_posix.cc:252] TCP:0x7f21e4004260 notify_on_read
E1214 06:07:13.409372268 113726 lockfree_event.cc:98] LockfreeEvent::NotifyOn: 0x7f21e4003880 curr=0x2 closure=0x7f21e4004400
I1214 06:07:13.409385568 113726 tcp_posix.cc:521] TCP:0x7f21e4004260 got_read: "No Error"
I1214 06:07:13.409396508 113726 tcp_posix.cc:506] TCP:0x7f21e4004260 alloc_slices
I1214 06:07:13.409410070 113726 resource_quota.cc:885] RQ anonymous_pool_7f21e4004090 ipv4:127.0.0.1:9339: alloc 8192; free_pool -> -8192
I1214 06:07:13.409421252 113726 ev_epollex_linux.cc:1391] PSS:0x7f21e4002950: add fd 0x7f21e4003810 (9)
I1214 06:07:13.409433361 113726 connectivity_state.cc:116] CONWATCH: 0x7f21e40066a8 client_transport: from READY [cur=READY] notify=0x7f21e4004ab8
I1214 06:07:13.409486031 113726 chttp2_transport.cc:1398] perform_stream_op_locked: SEND_INITIAL_METADATA{key=3a 73 63 68 65 6d 65 ':scheme' value=68 74 74 70 'http', key=3a 6d 65 74 68 6f 64 ':method' value=50 4f 53 54 'POST', key=3a 61 75 74 68 6f 72 69 74 79 ':authority' value=31 32 37 2e 30 2e 30 2e 31 3a 39 33 33 39 '127.0.0.1:9339', key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set', key=74 65 'te' value=74 72 61 69 6c 65 72 73 'trailers', key=63 6f 6e 74 65 6e 74 2d 74 79 70 65 'content-type' value=61 70 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 'application/grpc', key=75 73 65 72 2d 61 67 65 6e 74 'user-agent' value=67 72 70 63 2d 63 2b 2b 2f 31 2e 31 37 2e 31 20 67 72 70 63 2d 63 2f 37 2e 30 2e 30 20 28 6c 69 6e 75 78 3b 20 63 68 74 74 70 32 3b 20 67 69 7a 6d 6f 29 'grpc-c++/1.17.1 grpc-c/7.0.0 (linux; chttp2; gizmo)', key=67 72 70 63 2d 61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'grpc-accept-encoding' value=69 64 65 6e 74 69 74 79 2c 64 65 66 6c 61 74 65 2c 67 7a 69 70 'identity,deflate,gzip', key=61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'accept-encoding' value=69 64 65 6e 74 69 74 79 2c 67 7a 69 70 'identity,gzip'} SEND_MESSAGE:flags=0x00000000:len=86 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA; on_complete = 0x7f21e4008b58
I1214 06:07:13.409506829 113726 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: :scheme: http
I1214 06:07:13.409517381 113726 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: :method: POST
I1214 06:07:13.409526850 113726 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: :authority: 127.0.0.1:9339
I1214 06:07:13.409536502 113726 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: :path: /gnmi.gNMI/Set
I1214 06:07:13.409546124 113726 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: te: trailers
I1214 06:07:13.409556923 113726 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: content-type: application/grpc
I1214 06:07:13.409567823 113726 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: user-agent: grpc-c++/1.17.1 grpc-c/7.0.0 (linux; chttp2; gizmo)
I1214 06:07:13.409577574 113726 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: grpc-accept-encoding: identity,deflate,gzip
I1214 06:07:13.409587911 113726 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: accept-encoding: identity,gzip
I1214 06:07:13.409602791 113726 stream_lists.cc:125] 0x7f21e4006400[0][cli]: add to waiting_for_concurrency
I1214 06:07:13.409615237 113726 stream_lists.cc:71] 0x7f21e4006400[0][cli]: pop from waiting_for_concurrency
I1214 06:07:13.409625882 113726 chttp2_transport.cc:1186] HTTP:CLI: Allocating new grpc_chttp2_stream 0x7f21e4008d98 to id 1
I1214 06:07:13.409641588 113726 stream_lists.cc:125] 0x7f21e4006400[1][cli]: add to writable
D1214 06:07:13.409668271 113726 flow_control.cc:113] 0x7f21e4007a48[1][cli] | app st recv | trw: 65535, ttw: 4194304, taw: 65535, srw: 65535, slw: 65535 -> 65540, saw: 65535
I1214 06:07:13.409688071 113726 chttp2_transport.cc:1249] complete_closure_step: t=0x7f21e4006400 0x7f21e4008b58 refs=3 flags=0x0001 desc=op->on_complete err="No Error" write_state=WRITING+MORE
I1214 06:07:13.409707527 113726 stream_lists.cc:71] 0x7f21e4006400[1][cli]: pop from writable
I1214 06:07:13.409718719 113726 writing.cc:409] W:0x7f21e4006400 CLIENT[1] im-(sent,send)=(0,1) announce=5
I1214 06:07:13.409735897 113726 hpack_encoder.cc:473] Encode: ':authority: 127.0.0.1:9339', elem_interned=1 [1], k_interned=1, v_interned=1
I1214 06:07:13.409751713 113726 hpack_encoder.cc:473] Encode: ':path: /gnmi.gNMI/Set', elem_interned=1 [1], k_interned=1, v_interned=1
I1214 06:07:13.409763723 113726 hpack_encoder.cc:473] Encode: 'te: trailers', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.409777691 113726 hpack_encoder.cc:473] Encode: 'content-type: application/grpc', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.409789497 113726 hpack_encoder.cc:473] Encode: 'user-agent: grpc-c++/1.17.1 grpc-c/7.0.0 (linux; chttp2; gizmo)', elem_interned=1 [1], k_interned=1, v_interned=1
I1214 06:07:13.409802940 113726 hpack_encoder.cc:473] Encode: 'grpc-accept-encoding: identity,deflate,gzip', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.409814172 113726 hpack_encoder.cc:473] Encode: 'accept-encoding: identity,gzip', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.409827093 113726 chttp2_transport.cc:1249] complete_closure_step: t=0x7f21e4006400 0x7f21e4008b58 refs=2 flags=0x0001 desc=send_initial_metadata_finished err="No Error" write_state=WRITING+MORE
D1214 06:07:13.409843431 113726 flow_control.cc:113] 0x7f21e4007a48[1][cli] | s updt sent | trw: 65535, ttw: 4194304 -> 4194309, taw: 65535, srw: 65535, slw: 4194309, saw: 4194304 -> 4194309
D1214 06:07:13.409873779 113726 flow_control.cc:113] 0x7f21e4007a48[1][cli] | data sent | trw: 65535 -> 65444, ttw: 4194309, taw: 65535, srw: 65535 -> 65444, slw: 4194309, saw: 4194309
I1214 06:07:13.409890355 113726 chttp2_transport.cc:1249] complete_closure_step: t=0x7f21e4006400 0x7f21e4008b58 refs=1 flags=0x0001 desc=send_trailing_metadata_finished err="No Error" write_state=WRITING+MORE
I1214 06:07:13.409902583 113726 chttp2_transport.cc:1249] complete_closure_step: t=0x7f21e4006400 0x7f21e4008b58 refs=0 flags=0x0001 desc=on_write_finished_cb err="No Error" write_state=WRITING+MORE
I1214 06:07:13.409915085 113726 stream_lists.cc:125] 0x7f21e4006400[1][cli]: add to writing
D1214 06:07:13.409929298 113726 flow_control.cc:113] 0x7f21e4007a48[0][cli] | t updt sent | trw: 65444, ttw: 4194309, taw: 65535 -> 4194309, srw: , slw: , saw:
I1214 06:07:13.409943689 113726 writing.cc:110] CLIENT: Ping sent [0x7f21e4001f10]: 2/2
I1214 06:07:13.409966803 113726 chttp2_transport.cc:849] W:0x7f21e4006400 CLIENT state WRITING+MORE -> WRITING [begin write in current thread]
I1214 06:07:13.409981819 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 50 52 49 20 2a 20 48 54 54 50 2f 32 2e 30 0d 0a 0d 0a 53 4d 0d 0a 0d 0a 'PRI * HTTP/2.0....SM....'
I1214 06:07:13.409994395 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 00 00 24 04 00 00 00 00 00 00 02 00 00 00 00 00 03 00 00 00 00 00 04 00 40 00 00 00 05 00 40 00 00 00 06 00 00 20 00 fe 03 00 00 00 01 '..$.....................@.....@...... .......'
I1214 06:07:13.410006766 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 00 00 ea 01 04 00 00 00 01 86 83 40 0a '...........@.'
I1214 06:07:13.410017144 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 3a 61 75 74 68 6f 72 69 74 79 ':authority'
I1214 06:07:13.410027125 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 0e '.'
I1214 06:07:13.410037518 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 31 32 37 2e 30 2e 30 2e 31 3a 39 33 33 39 '127.0.0.1:9339'
I1214 06:07:13.410048022 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 40 05 '@.'
I1214 06:07:13.410059059 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 3a 70 61 74 68 ':path'
I1214 06:07:13.410069300 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 0e '.'
I1214 06:07:13.410079301 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set'
I1214 06:07:13.410089251 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 40 02 '@.'
I1214 06:07:13.410103279 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 74 65 'te'
I1214 06:07:13.410114025 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 08 '.'
I1214 06:07:13.410124154 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 74 72 61 69 6c 65 72 73 'trailers'
I1214 06:07:13.410134547 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 40 0c '@.'
I1214 06:07:13.410145442 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 63 6f 6e 74 65 6e 74 2d 74 79 70 65 'content-type'
I1214 06:07:13.410155572 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 10 '.'
I1214 06:07:13.410166508 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 61 70 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 'application/grpc'
I1214 06:07:13.410177247 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 40 0a '@.'
I1214 06:07:13.410188018 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 75 73 65 72 2d 61 67 65 6e 74 'user-agent'
I1214 06:07:13.410197770 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 33 '3'
I1214 06:07:13.410210657 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 67 72 70 63 2d 63 2b 2b 2f 31 2e 31 37 2e 31 20 67 72 70 63 2d 63 2f 37 2e 30 2e 30 20 28 6c 69 6e 75 78 3b 20 63 68 74 74 70 32 3b 20 67 69 7a 6d 6f 29 'grpc-c++/1.17.1 grpc-c/7.0.0 (linux; chttp2; gizmo)'
I1214 06:07:13.410221882 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 40 14 '@.'
I1214 06:07:13.410233595 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 67 72 70 63 2d 61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'grpc-accept-encoding'
I1214 06:07:13.410243993 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 15 '.'
I1214 06:07:13.410255292 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 69 64 65 6e 74 69 74 79 2c 64 65 66 6c 61 74 65 2c 67 7a 69 70 'identity,deflate,gzip'
I1214 06:07:13.410266144 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 40 0f '@.'
I1214 06:07:13.410277341 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'accept-encoding'
I1214 06:07:13.410286948 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 0d '.'
I1214 06:07:13.410298441 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 69 64 65 6e 74 69 74 79 2c 67 7a 69 70 'identity,gzip'
I1214 06:07:13.410309663 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 00 00 04 08 00 00 00 00 01 00 00 00 05 00 00 5b 00 01 00 00 00 01 00 '...............[.......'
I1214 06:07:13.410323024 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 00 00 00 56 '...V'
I1214 06:07:13.410336418 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 22 54 0a 49 1a 0c 0a 0a 69 6e 74 65 72 66 61 63 65 73 1a 27 0a 11 76 69 72 74 75 61 6c 2d 69 6e 74 65 72 66 61 63 65 12 12 0a 04 6e 61 6d 65 12 0a 6e 65 74 5f 76 68 6f 73 74 30 1a 08 0a 06 63 6f 6e 66 69 67 1a 06 0a 04 68 6f 73 74 1a 07 0a 05 68 6f 73 74 31 '"T.I....interfaces.'..virtual-interface....name..net_vhost0....config....host....host1'
I1214 06:07:13.410350443 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 00 00 04 08 00 00 00 00 00 00 3f 00 06 00 00 08 06 00 00 00 00 00 00 '..........?............'
I1214 06:07:13.410360892 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 00 00 00 00 00 00 00 '.......'
I1214 06:07:13.410432328 113726 tcp_posix.cc:964] write: "No Error"
I1214 06:07:13.410444298 113726 chttp2_transport.cc:2596] ipv4:127.0.0.1:9339: Start BDP ping err="No Error"
I1214 06:07:13.410455200 113726 bdp_estimator.h:66] bdp[ipv4:127.0.0.1:9339]:start acc=0 est=65536
I1214 06:07:13.410466456 113726 chttp2_transport.cc:849] W:0x7f21e4006400 CLIENT state WRITING -> IDLE [finish writing]
I1214 06:07:13.410480206 113726 stream_lists.cc:71] 0x7f21e4006400[1][cli]: pop from writing
I1214 06:07:13.410492033 113726 call_combiner.cc:69] ==> grpc_call_combiner_start() [0x2419bd0] closure=0x241ab30 [on_complete] error="No Error"
I1214 06:07:13.410502555 113726 call_combiner.cc:78] size: 0 -> 1
I1214 06:07:13.410513213 113726 call_combiner.cc:87] EXECUTING IMMEDIATELY
I1214 06:07:13.410524065 113726 call_combiner.cc:106] ==> grpc_call_combiner_stop() [0x2419bd0] [on_complete]
I1214 06:07:13.410534012 113726 call_combiner.cc:113] size: 1 -> 0
I1214 06:07:13.410543344 113726 call_combiner.cc:141] queue empty
I1214 06:07:13.410556191 113726 resource_quota.cc:320] RQ: check allocation for user 0x7f21e4004550 shutdown=0 free_pool=-8192
I1214 06:07:13.410568512 113726 resource_quota.cc:346] RQ anonymous_pool_7f21e4004090 ipv4:127.0.0.1:9339: grant alloc 8192 bytes; rq_free_pool -> 9223372036854767615
I1214 06:07:13.410587233 113726 tcp_posix.cc:488] TCP:0x7f21e4004260 read_allocation_done: "No Error"
I1214 06:07:13.410597404 113724 ev_epollex_linux.cc:1013] POLLABLE:0x241b2d0 got 1 events
I1214 06:07:13.410607111 113724 ev_epollex_linux.cc:961] PS:0x240ca40 got fd 0x7f21e4003810: cancel=0 read=1 write=1
I1214 06:07:13.410608754 113726 tcp_posix.cc:397] TCP:0x7f21e4004260 call_cb 0x7f21e4006540 0x7f21f29e3d30:0x7f21e4006400
E1214 06:07:13.410614246 113724 lockfree_event.cc:213] LockfreeEvent::SetReady: 0x7f21e4003880 curr=(nil)
E1214 06:07:13.410667830 113724 lockfree_event.cc:213] LockfreeEvent::SetReady: 0x7f21e4003888 curr=0x2
I1214 06:07:13.410653087 113726 tcp_posix.cc:400] read: error="No Error"
I1214 06:07:13.410680275 113724 ev_epollex_linux.cc:722] PS:0x240ca40 (pollable:0x241b2d0) maybe_finish_shutdown sc=(nil) (target:!NULL) rw=(nil) (target:NULL) cpsc=0 (target:0)
I1214 06:07:13.410721949 113724 ev_epollex_linux.cc:1176] PS:0x240ca40 work hdl=0x7fff1c7607a8 worker=0x7fff1c7606e0 now=5 deadline=9223372036854775807 kwp=0 pollable=0x241b2d0
I1214 06:07:13.410723965 113726 tcp_posix.cc:405] READ 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 00 00 12 04 00 00 00 00 00 00 04 00 40 00 00 00 05 00 40 00 00 fe 03 00 00 00 01 00 00 04 08 00 00 00 00 00 00 3f 00 01 00 00 08 06 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 08 06 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 04 01 00 00 00 00 00 00 04 08 00 00 00 00 00 00 00 00 5b '............@.....@..................?.........................................................['
I1214 06:07:13.410736692 113724 ev_epollex_linux.cc:994] POLLABLE:0x241b2d0[type=pollset epfd=7 wakeup=8] poll for -1ms
I1214 06:07:13.410774351 113726 frame_settings.cc:220] 0x7f21e4006400[cli] adding 4128769 for initial_window change
I1214 06:07:13.410785912 113726 frame_settings.cc:227] CHTTP2:CLI:ipv4:127.0.0.1:9339: got setting INITIAL_WINDOW_SIZE = 4194304
I1214 06:07:13.410798304 113726 frame_settings.cc:227] CHTTP2:CLI:ipv4:127.0.0.1:9339: got setting MAX_FRAME_SIZE = 4194304
I1214 06:07:13.410808748 113726 frame_settings.cc:227] CHTTP2:CLI:ipv4:127.0.0.1:9339: got setting GRPC_ALLOW_TRUE_BINARY_METADATA = 1
D1214 06:07:13.410826273 113726 flow_control.cc:113] 0x7f21e4007a48[0][cli] | t updt recv | trw: 65444 -> 4194213, ttw: 4194309, taw: 4194309, srw: , slw: , saw:
I1214 06:07:13.410840719 113726 chttp2_transport.cc:849] W:0x7f21e4006400 CLIENT state IDLE -> WRITING [PING_RESPONSE]
D1214 06:07:13.410858125 113726 flow_control.cc:113] 0x7f21e4007a48[0][cli] | t updt recv | trw: 4194213 -> 4194304, ttw: 4194309, taw: 4194309, srw: , slw: , saw:
I1214 06:07:13.410873040 113726 tcp_posix.cc:521] TCP:0x7f21e4004260 got_read: "No Error"
I1214 06:07:13.410882985 113726 tcp_posix.cc:512] TCP:0x7f21e4004260 do_read
I1214 06:07:13.410896120 113726 tcp_posix.cc:252] TCP:0x7f21e4004260 notify_on_read
E1214 06:07:13.410906157 113726 lockfree_event.cc:98] LockfreeEvent::NotifyOn: 0x7f21e4003880 curr=0x2 closure=0x7f21e4004400
I1214 06:07:13.410916550 113726 tcp_posix.cc:521] TCP:0x7f21e4004260 got_read: "No Error"
I1214 06:07:13.410926451 113726 tcp_posix.cc:512] TCP:0x7f21e4004260 do_read
I1214 06:07:13.410936588 113726 tcp_posix.cc:252] TCP:0x7f21e4004260 notify_on_read
E1214 06:07:13.410959041 113726 lockfree_event.cc:98] LockfreeEvent::NotifyOn: 0x7f21e4003880 curr=(nil) closure=0x7f21e4004400
I1214 06:07:13.410970663 113726 chttp2_transport.cc:2609] ipv4:127.0.0.1:9339: Complete BDP ping err="No Error"
I1214 06:07:13.410990973 113726 bdp_estimator.cc:50] bdp[ipv4:127.0.0.1:9339]:complete acc=96 est=65536 dt=0.000518 bw=1.483596Mbs bw_est=0.000000Mbs
D1214 06:07:13.411017446 113726 flow_control.cc:113] 0x7f21e4007a48[0][cli] | t updt sent | trw: 4194304, ttw: 4194309, taw: 4194309, srw: , slw: , saw:
I1214 06:07:13.411030194 113726 chttp2_transport.cc:849] W:0x7f21e4006400 CLIENT state WRITING -> WRITING [begin write in current thread]
I1214 06:07:13.411043105 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 00 00 08 06 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 04 01 00 '.......................'
I1214 06:07:13.411056001 113726 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 00 00 00 '...'
I1214 06:07:13.411088453 113726 tcp_posix.cc:964] write: "No Error"
I1214 06:07:13.411099057 113726 chttp2_transport.cc:849] W:0x7f21e4006400 CLIENT state WRITING -> IDLE [finish writing]
I1214 06:07:13.411110845 113726 executor.cc:166] EXECUTOR (resolver-executor) [0]: step (sub_depth=1)
I1214 06:07:13.413833827 113724 ev_epollex_linux.cc:1013] POLLABLE:0x241b2d0 got 1 events
I1214 06:07:13.413842417 113724 ev_epollex_linux.cc:961] PS:0x240ca40 got fd 0x7f21e4003810: cancel=0 read=1 write=1
E1214 06:07:13.413848161 113724 lockfree_event.cc:213] LockfreeEvent::SetReady: 0x7f21e4003880 curr=0x7f21e4004400
E1214 06:07:13.413854313 113724 lockfree_event.cc:213] LockfreeEvent::SetReady: 0x7f21e4003888 curr=0x2
I1214 06:07:13.413861070 113724 tcp_posix.cc:521] TCP:0x7f21e4004260 got_read: "No Error"
I1214 06:07:13.413868161 113724 tcp_posix.cc:512] TCP:0x7f21e4004260 do_read
I1214 06:07:13.413877415 113724 tcp_posix.cc:397] TCP:0x7f21e4004260 call_cb 0x7f21e4006540 0x7f21f29e3d30:0x7f21e4006400
I1214 06:07:13.413883033 113724 tcp_posix.cc:400] read: error="No Error"
I1214 06:07:13.413892459 113724 tcp_posix.cc:405] READ 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 00 00 6b 01 04 00 00 00 01 88 40 0c 63 6f 6e 74 65 6e 74 2d 74 79 70 65 10 61 70 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 40 14 67 72 70 63 2d 61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 15 69 64 65 6e 74 69 74 79 2c 64 65 66 6c 61 74 65 2c 67 7a 69 70 40 0f 61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 0d 69 64 65 6e 74 69 74 79 2c 67 7a 69 70 00 00 60 00 00 00 00 00 01 00 00 00 00 5b 0a 00 12 4d 12 49 1a 0c 0a 0a 69 6e 74 65 72 66 61 63 65 73 1a 27 0a 11 76 69 72 74 75 61 6c 2d 69 6e 74 65 72 66 61 63 65 12 12 0a 04 6e 61 6d 65 12 0a 6e 65 74 5f 76 68 6f 73 74 30 1a 08 0a 06 63 6f 6e 66 69 67 1a 06 0a 04 68 6f 73 74 20 03 20 d2 fe f6 e2 87 c1 a2 e0 16 00 00 0f 01 05 00 00 00 01 40 0b 67 72 70 63 2d 73 74 61 74 75 73 01 30 '..k.......@.content-type.application/grpc@.grpc-accept-encoding.identity,deflate,gzip@.accept-encoding.identity,gzip..`..........[...M.I....interfaces.'..virtual-interface....name..net_vhost0....config....host . ..................@.grpc-status.0'
I1214 06:07:13.413904612 113724 parsing.cc:656] parsing initial_metadata
I1214 06:07:13.413911760 113724 hpack_parser.cc:636] Decode: ':status: 200', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.413917590 113724 parsing.cc:407] HTTP:1:HDR:CLI: :status: 32 30 30 '200'
I1214 06:07:13.413926132 113724 hpack_parser.cc:636] Decode: 'content-type: application/grpc', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.413935761 113724 parsing.cc:407] HTTP:1:HDR:CLI: content-type: 61 70 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 'application/grpc'
I1214 06:07:13.413942211 113724 hpack_parser.cc:636] Decode: 'grpc-accept-encoding: identity,deflate,gzip', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.413950436 113724 parsing.cc:407] HTTP:1:HDR:CLI: grpc-accept-encoding: 69 64 65 6e 74 69 74 79 2c 64 65 66 6c 61 74 65 2c 67 7a 69 70 'identity,deflate,gzip'
I1214 06:07:13.413955098 113724 hpack_parser.cc:636] Decode: 'accept-encoding: identity,gzip', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.413960240 113724 parsing.cc:407] HTTP:1:HDR:CLI: accept-encoding: 69 64 65 6e 74 69 74 79 2c 67 7a 69 70 'identity,gzip'
I1214 06:07:13.413967509 113724 call_combiner.cc:69] ==> grpc_call_combiner_start() [0x2419bd0] closure=0x7f21e4008580 [recv_initial_metadata_ready] error="No Error"
I1214 06:07:13.413972448 113724 call_combiner.cc:78] size: 0 -> 1
I1214 06:07:13.413979132 113724 call_combiner.cc:87] EXECUTING IMMEDIATELY
D1214 06:07:13.413987021 113724 flow_control.cc:113] 0x7f21e4007a48[1][cli] | data recv | trw: 4194304, ttw: 4194309 -> 4194304, taw: 4194309 -> 4194213, srw: 4194213, slw: 4194309 -> 4194213, saw: 4194309 -> 4194213
I1214 06:07:13.414000525 113724 call_combiner.cc:69] ==> grpc_call_combiner_start() [0x2419bd0] closure=0x7f21e4008420 [recv_message_ready] error="No Error"
I1214 06:07:13.414005536 113724 call_combiner.cc:78] size: 1 -> 2
I1214 06:07:13.414008221 113724 call_combiner.cc:93] QUEUING
I1214 06:07:13.414012346 113724 parsing.cc:661] parsing trailing_metadata
I1214 06:07:13.414016871 113724 hpack_parser.cc:636] Decode: 'grpc-status: 0', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.414024294 113724 parsing.cc:503] HTTP:1:TRL:CLI: grpc-status: 30 '0'
I1214 06:07:13.414036649 113724 call_combiner.cc:106] ==> grpc_call_combiner_stop() [0x2419bd0] [recv_initial_metadata_ready]
I1214 06:07:13.414041628 113724 call_combiner.cc:113] size: 2 -> 1
I1214 06:07:13.414044447 113724 call_combiner.cc:120] checking queue
I1214 06:07:13.414068193 113724 call_combiner.cc:134] EXECUTING FROM QUEUE: closure=0x7f21e4008420 error="No Error"
I1214 06:07:13.414103812 113724 tcp_posix.cc:521] TCP:0x7f21e4004260 got_read: "No Error"
I1214 06:07:13.414131566 113724 tcp_posix.cc:512] TCP:0x7f21e4004260 do_read
I1214 06:07:13.414158354 113724 tcp_posix.cc:252] TCP:0x7f21e4004260 notify_on_read
E1214 06:07:13.414179594 113724 lockfree_event.cc:98] LockfreeEvent::NotifyOn: 0x7f21e4003880 curr=(nil) closure=0x7f21e4004400
I1214 06:07:13.414187656 113724 call_combiner.cc:106] ==> grpc_call_combiner_stop() [0x2419bd0] [recv_message_ready]
I1214 06:07:13.414194913 113724 call_combiner.cc:113] size: 1 -> 0
I1214 06:07:13.414201906 113724 call_combiner.cc:141] queue empty
I1214 06:07:13.414218911 113724 call_combiner.cc:69] ==> grpc_call_combiner_start() [0x2419bd0] closure=0x7f21e40085b8 [recv_trailing_metadata_ready] error="No Error"
I1214 06:07:13.414226237 113724 call_combiner.cc:78] size: 0 -> 1
I1214 06:07:13.414232393 113724 call_combiner.cc:87] EXECUTING IMMEDIATELY
I1214 06:07:13.414242766 113724 call_combiner.cc:106] ==> grpc_call_combiner_stop() [0x2419bd0] [recv_trailing_metadata_ready]
I1214 06:07:13.414249853 113724 call_combiner.cc:113] size: 1 -> 0
I1214 06:07:13.414256791 113724 call_combiner.cc:141] queue empty
D1214 06:07:13.414263437 113724 call.cc:719] set_final_status CLI
D1214 06:07:13.414270386 113724 call.cc:720] "No Error"
I1214 06:07:13.414284508 113724 completion_queue.cc:779] cq_end_op_for_pluck(cq=0x240c940, tag=0x7fff1c7609e0, error="No Error", done=0x7f21f29cd6f0, done_arg=0x241aa90, storage=0x241aae0)
I1214 06:07:13.414293181 113724 ev_epollex_linux.cc:788] PS:0x240ca40 kick 0x7fff1c7606e0 tls_pollset=0x240ca40 tls_worker=0x7fff1c7606e0 pollset.root_worker=0x7fff1c7606e0
I1214 06:07:13.414301838 113724 ev_epollex_linux.cc:754] PS:0x241b2d0 kicked_specific_but_awake
I1214 06:07:13.414311173 113724 ev_epollex_linux.cc:722] PS:0x240ca40 (pollable:0x241b2d0) maybe_finish_shutdown sc=(nil) (target:!NULL) rw=(nil) (target:NULL) cpsc=0 (target:0)
I1214 06:07:13.414323798 113724 completion_queue.cc:1299] RETURN_EVENT[0x240c940]: OP_COMPLETE: tag:0x7fff1c7609e0 OK
I1214 06:07:13.414373493 113724 completion_queue.cc:1395] grpc_completion_queue_destroy(cq=0x240c940)
I1214 06:07:13.414381684 113724 completion_queue.cc:1389] grpc_completion_queue_shutdown(cq=0x240c940)
I1214 06:07:13.414392342 113724 ev_epollex_linux.cc:722] PS:0x240ca40 (pollable:0x241b2d0) maybe_finish_shutdown sc=0x240c960 (target:!NULL) rw=(nil) (target:NULL) cpsc=0 (target:0)
I1214 06:07:13.414400477 113724 init.cc:159] grpc_shutdown(void)
I1214 06:07:13.414419948 113724 call.cc:561] grpc_call_unref(c=0x2419bc0)
I1214 06:07:13.414439583 113724 call_combiner.cc:167] call_combiner=0x2419bd0: setting notify_on_cancel=(nil)
I1214 06:07:13.414448311 113724 call_combiner.cc:176] call_combiner=0x2419bd0: scheduling old cancel callback=0x241a728
I1214 06:07:13.414458952 113724 ev_epollex_linux.cc:628] (fd-trace) pollable_unref: Closing epfd: 7
I1214 06:07:13.414501291 113724 metadata_array.cc:34] grpc_metadata_array_destroy(array=0x7fff1c761150)
I1214 06:07:13.414511116 113724 metadata_array.cc:34] grpc_metadata_array_destroy(array=0x7fff1c761100)
I1214 06:07:13.414527194 113724 channel.cc:376] grpc_channel_register_call(channel=0x240aa20, method=/gnmi.gNMI/Capabilities, host=(null), reserved=(nil))
I1214 06:07:13.414539402 113724 channel.cc:376] grpc_channel_register_call(channel=0x240aa20, method=/gnmi.gNMI/Get, host=(null), reserved=(nil))
I1214 06:07:13.414550293 113724 channel.cc:376] grpc_channel_register_call(channel=0x240aa20, method=/gnmi.gNMI/Set, host=(null), reserved=(nil))
I1214 06:07:13.414561089 113724 channel.cc:376] grpc_channel_register_call(channel=0x240aa20, method=/gnmi.gNMI/Subscribe, host=(null), reserved=(nil))
I1214 06:07:13.415019609 113724 init.cc:154] grpc_init(void)
I1214 06:07:13.415029352 113724 completion_queue.cc:478] grpc_completion_queue_create_internal(completion_type=1, polling_type=0)
I1214 06:07:13.415039131 113724 channel.cc:403] grpc_channel_create_registered_call(channel=0x240aa20, parent_call=(nil), propagation_mask=ffff, completion_queue=0x2419bd0, registered_call_handle=0x2403920, deadline=gpr_timespec { tv_sec: 9223372036854775807, tv_nsec: 0, clock_type: 1 }, reserved=(nil))
I1214 06:07:13.415057402 113724 grpc_context.cc:27] grpc_census_call_set_context(call=0x2419da0, census_context=(nil))
I1214 06:07:13.415075822 113724 call.cc:1900] grpc_call_start_batch(call=0x2419da0, ops=0x7fff1c7606c0, nops=6, tag=0x7fff1c7609e0, reserved=(nil))
I1214 06:07:13.415084325 113724 call.cc:1508] ops[0]: SEND_INITIAL_METADATA(nil)
I1214 06:07:13.415091157 113724 call.cc:1508] ops[1]: SEND_MESSAGE ptr=0x24045a0
I1214 06:07:13.415098714 113724 call.cc:1508] ops[2]: RECV_INITIAL_METADATA ptr=0x7fff1c761100
I1214 06:07:13.415104901 113724 call.cc:1508] ops[3]: RECV_MESSAGE ptr=0x7fff1c760a48
I1214 06:07:13.415110776 113724 call.cc:1508] ops[4]: SEND_CLOSE_FROM_CLIENT
I1214 06:07:13.415120716 113724 call.cc:1508] ops[5]: RECV_STATUS_ON_CLIENT metadata=0x7fff1c761150 status=0x7fff1c760a80 details=0x7fff1c760a88
I1214 06:07:13.415127693 113724 call_combiner.cc:69] ==> grpc_call_combiner_start() [0x2419db0] closure=0x241ace8 [executing batch] error="No Error"
I1214 06:07:13.415134558 113724 call_combiner.cc:78] size: 0 -> 1
I1214 06:07:13.415139975 113724 call_combiner.cc:87] EXECUTING IMMEDIATELY
I1214 06:07:13.415153463 113724 call.cc:613] OP[client-channel:0x241a720]: SEND_INITIAL_METADATA{key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set'} SEND_MESSAGE:flags=0x00000000:len=98 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.415161283 113724 client_channel.cc:1204] chand=0x240aae8 calld=0x241a740: adding pending batch at index 0
I1214 06:07:13.415171765 113724 client_channel.cc:3197] chand=0x240aae8 calld=0x241a740: entering client_channel combiner
I1214 06:07:13.415183092 113724 client_channel.cc:2855] chand=0x240aae8 calld=0x241a740: applying service config to call
I1214 06:07:13.415193384 113724 connectivity_state.cc:81] CONWATCH: 0x240ab70 client_channel: get READY
I1214 06:07:13.415203301 113724 client_channel.cc:2763] chand=0x240aae8 calld=0x241a740: starting pick on lb_policy=0x7f21e4001430
I1214 06:07:13.415213642 113724 client_channel.cc:2790] chand=0x240aae8 calld=0x241a740: pick completed synchronously
I1214 06:07:13.415227245 113724 ev_epollex_linux.cc:1217] PS:0x2419cd0 add fd 0x7f21e4003810 (9); transition pollable from empty to fd
I1214 06:07:13.415241100 113724 ev_epollex_linux.cc:558] (fd-trace) Pollable_create: created epfd: 7 (type: 1)
I1214 06:07:13.415257861 113724 ev_epollex_linux.cc:674] add fd 0x7f21e4003810 (9) to pollable 0x241c700
I1214 06:07:13.415270056 113724 client_channel.cc:2669] chand=0x240aae8 calld=0x241a740: create subchannel_call=0x241ad50: error="No Error"
I1214 06:07:13.415280171 113724 client_channel.cc:1346] chand=0x240aae8 calld=0x241a740: starting 1 pending batches on subchannel_call=0x241ad50
I1214 06:07:13.415295853 113724 call_combiner.h:153] CallCombinerClosureList executing closure while already holding call_combiner 0x2419db0: closure=0x241ac98 error="No Error" reason=pending_batches_resume
I1214 06:07:13.415314367 113724 subchannel.cc:1000] OP[authority:0x241adf0]: SEND_INITIAL_METADATA{key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set'} SEND_MESSAGE:flags=0x00000000:len=98 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.415337283 113724 channel_stack.cc:226] OP[message_size:0x241ae08]: SEND_INITIAL_METADATA{key=3a 61 75 74 68 6f 72 69 74 79 ':authority' value=31 32 37 2e 30 2e 30 2e 31 3a 39 33 33 39 '127.0.0.1:9339', key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set'} SEND_MESSAGE:flags=0x00000000:len=98 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.415359277 113724 channel_stack.cc:226] OP[http-client:0x241ae20]: SEND_INITIAL_METADATA{key=3a 61 75 74 68 6f 72 69 74 79 ':authority' value=31 32 37 2e 30 2e 30 2e 31 3a 39 33 33 39 '127.0.0.1:9339', key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set'} SEND_MESSAGE:flags=0x00000000:len=98 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.415402418 113724 channel_stack.cc:226] OP[message_compress:0x241ae38]: SEND_INITIAL_METADATA{key=3a 73 63 68 65 6d 65 ':scheme' value=68 74 74 70 'http', key=3a 6d 65 74 68 6f 64 ':method' value=50 4f 53 54 'POST', key=3a 61 75 74 68 6f 72 69 74 79 ':authority' value=31 32 37 2e 30 2e 30 2e 31 3a 39 33 33 39 '127.0.0.1:9339', key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set', key=74 65 'te' value=74 72 61 69 6c 65 72 73 'trailers', key=63 6f 6e 74 65 6e 74 2d 74 79 70 65 'content-type' value=61 70 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 'application/grpc', key=75 73 65 72 2d 61 67 65 6e 74 'user-agent' value=67 72 70 63 2d 63 2b 2b 2f 31 2e 31 37 2e 31 20 67 72 70 63 2d 63 2f 37 2e 30 2e 30 20 28 6c 69 6e 75 78 3b 20 63 68 74 74 70 32 3b 20 67 69 7a 6d 6f 29 'grpc-c++/1.17.1 grpc-c/7.0.0 (linux; chttp2; gizmo)'} SEND_MESSAGE:flags=0x00000000:len=98 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.415461188 113724 channel_stack.cc:226] OP[connected:0x241ae50]: SEND_INITIAL_METADATA{key=3a 73 63 68 65 6d 65 ':scheme' value=68 74 74 70 'http', key=3a 6d 65 74 68 6f 64 ':method' value=50 4f 53 54 'POST', key=3a 61 75 74 68 6f 72 69 74 79 ':authority' value=31 32 37 2e 30 2e 30 2e 31 3a 39 33 33 39 '127.0.0.1:9339', key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set', key=74 65 'te' value=74 72 61 69 6c 65 72 73 'trailers', key=63 6f 6e 74 65 6e 74 2d 74 79 70 65 'content-type' value=61 70 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 'application/grpc', key=75 73 65 72 2d 61 67 65 6e 74 'user-agent' value=67 72 70 63 2d 63 2b 2b 2f 31 2e 31 37 2e 31 20 67 72 70 63 2d 63 2f 37 2e 30 2e 30 20 28 6c 69 6e 75 78 3b 20 63 68 74 74 70 32 3b 20 67 69 7a 6d 6f 29 'grpc-c++/1.17.1 grpc-c/7.0.0 (linux; chttp2; gizmo)', key=67 72 70 63 2d 61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'grpc-accept-encoding' value=69 64 65 6e 74 69 74 79 2c 64 65 66 6c 61 74 65 2c 67 7a 69 70 'identity,deflate,gzip', key=61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'accept-encoding' value=69 64 65 6e 74 69 74 79 2c 67 7a 69 70 'identity,gzip'} SEND_MESSAGE:flags=0x00000000:len=98 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.415515164 113724 chttp2_transport.cc:1702] perform_stream_op[s=0x241b828]: SEND_INITIAL_METADATA{key=3a 73 63 68 65 6d 65 ':scheme' value=68 74 74 70 'http', key=3a 6d 65 74 68 6f 64 ':method' value=50 4f 53 54 'POST', key=3a 61 75 74 68 6f 72 69 74 79 ':authority' value=31 32 37 2e 30 2e 30 2e 31 3a 39 33 33 39 '127.0.0.1:9339', key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set', key=74 65 'te' value=74 72 61 69 6c 65 72 73 'trailers', key=63 6f 6e 74 65 6e 74 2d 74 79 70 65 'content-type' value=61 70 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 'application/grpc', key=75 73 65 72 2d 61 67 65 6e 74 'user-agent' value=67 72 70 63 2d 63 2b 2b 2f 31 2e 31 37 2e 31 20 67 72 70 63 2d 63 2f 37 2e 30 2e 30 20 28 6c 69 6e 75 78 3b 20 63 68 74 74 70 32 3b 20 67 69 7a 6d 6f 29 'grpc-c++/1.17.1 grpc-c/7.0.0 (linux; chttp2; gizmo)', key=67 72 70 63 2d 61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'grpc-accept-encoding' value=69 64 65 6e 74 69 74 79 2c 64 65 66 6c 61 74 65 2c 67 7a 69 70 'identity,deflate,gzip', key=61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'accept-encoding' value=69 64 65 6e 74 69 74 79 2c 67 7a 69 70 'identity,gzip'} SEND_MESSAGE:flags=0x00000000:len=98 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.415534117 113724 call_combiner.cc:106] ==> grpc_call_combiner_stop() [0x2419db0] [passed batch to transport]
I1214 06:07:13.415543741 113724 call_combiner.cc:113] size: 1 -> 0
I1214 06:07:13.415551723 113724 call_combiner.cc:141] queue empty
I1214 06:07:13.415597101 113724 chttp2_transport.cc:1398] perform_stream_op_locked: SEND_INITIAL_METADATA{key=3a 73 63 68 65 6d 65 ':scheme' value=68 74 74 70 'http', key=3a 6d 65 74 68 6f 64 ':method' value=50 4f 53 54 'POST', key=3a 61 75 74 68 6f 72 69 74 79 ':authority' value=31 32 37 2e 30 2e 30 2e 31 3a 39 33 33 39 '127.0.0.1:9339', key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set', key=74 65 'te' value=74 72 61 69 6c 65 72 73 'trailers', key=63 6f 6e 74 65 6e 74 2d 74 79 70 65 'content-type' value=61 70 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 'application/grpc', key=75 73 65 72 2d 61 67 65 6e 74 'user-agent' value=67 72 70 63 2d 63 2b 2b 2f 31 2e 31 37 2e 31 20 67 72 70 63 2d 63 2f 37 2e 30 2e 30 20 28 6c 69 6e 75 78 3b 20 63 68 74 74 70 32 3b 20 67 69 7a 6d 6f 29 'grpc-c++/1.17.1 grpc-c/7.0.0 (linux; chttp2; gizmo)', key=67 72 70 63 2d 61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'grpc-accept-encoding' value=69 64 65 6e 74 69 74 79 2c 64 65 66 6c 61 74 65 2c 67 7a 69 70 'identity,deflate,gzip', key=61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'accept-encoding' value=69 64 65 6e 74 69 74 79 2c 67 7a 69 70 'identity,gzip'} SEND_MESSAGE:flags=0x00000000:len=98 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA; on_complete = 0x241b5e8
I1214 06:07:13.415616246 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: :scheme: http
I1214 06:07:13.415626082 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: :method: POST
I1214 06:07:13.415634728 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: :authority: 127.0.0.1:9339
I1214 06:07:13.415644370 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: :path: /gnmi.gNMI/Set
I1214 06:07:13.415652854 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: te: trailers
I1214 06:07:13.415661056 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: content-type: application/grpc
I1214 06:07:13.415670130 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: user-agent: grpc-c++/1.17.1 grpc-c/7.0.0 (linux; chttp2; gizmo)
I1214 06:07:13.415680514 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: grpc-accept-encoding: identity,deflate,gzip
I1214 06:07:13.415691625 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: accept-encoding: identity,gzip
I1214 06:07:13.415701592 113724 stream_lists.cc:125] 0x7f21e4006400[0][cli]: add to waiting_for_concurrency
I1214 06:07:13.415709924 113724 stream_lists.cc:71] 0x7f21e4006400[0][cli]: pop from waiting_for_concurrency
I1214 06:07:13.415716361 113724 chttp2_transport.cc:1186] HTTP:CLI: Allocating new grpc_chttp2_stream 0x241b828 to id 3
I1214 06:07:13.415723266 113724 stream_lists.cc:125] 0x7f21e4006400[3][cli]: add to writable
I1214 06:07:13.415730253 113724 chttp2_transport.cc:849] W:0x7f21e4006400 CLIENT state IDLE -> WRITING [START_NEW_STREAM]
I1214 06:07:13.415738031 113724 chttp2_transport.cc:849] W:0x7f21e4006400 CLIENT state WRITING -> WRITING+MORE [SEND_MESSAGE]
D1214 06:07:13.415749579 113724 flow_control.cc:113] 0x7f21e4007a48[3][cli] | app st recv | trw: 4194304, ttw: 4194304, taw: 4194213, srw: 4194304, slw: 4194304 -> 4194309, saw: 4194304
I1214 06:07:13.415758965 113724 chttp2_transport.cc:1249] complete_closure_step: t=0x7f21e4006400 0x241b5e8 refs=3 flags=0x0001 desc=op->on_complete err="No Error" write_state=WRITING+MORE
I1214 06:07:13.415768142 113724 stream_lists.cc:71] 0x7f21e4006400[3][cli]: pop from writable
I1214 06:07:13.415781043 113724 writing.cc:409] W:0x7f21e4006400 CLIENT[3] im-(sent,send)=(0,1) announce=5
I1214 06:07:13.415790531 113724 hpack_encoder.cc:473] Encode: ':authority: 127.0.0.1:9339', elem_interned=1 [1], k_interned=1, v_interned=1
I1214 06:07:13.415797801 113724 hpack_encoder.cc:473] Encode: ':path: /gnmi.gNMI/Set', elem_interned=1 [1], k_interned=1, v_interned=1
I1214 06:07:13.415804444 113724 hpack_encoder.cc:473] Encode: 'te: trailers', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.415810717 113724 hpack_encoder.cc:473] Encode: 'content-type: application/grpc', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.415817337 113724 hpack_encoder.cc:473] Encode: 'user-agent: grpc-c++/1.17.1 grpc-c/7.0.0 (linux; chttp2; gizmo)', elem_interned=1 [1], k_interned=1, v_interned=1
I1214 06:07:13.415824019 113724 hpack_encoder.cc:473] Encode: 'grpc-accept-encoding: identity,deflate,gzip', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.415830695 113724 hpack_encoder.cc:473] Encode: 'accept-encoding: identity,gzip', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.415838048 113724 chttp2_transport.cc:1249] complete_closure_step: t=0x7f21e4006400 0x241b5e8 refs=2 flags=0x0001 desc=send_initial_metadata_finished err="No Error" write_state=WRITING+MORE
D1214 06:07:13.415847243 113724 flow_control.cc:113] 0x7f21e4007a48[3][cli] | s updt sent | trw: 4194304, ttw: 4194304 -> 4194309, taw: 4194213, srw: 4194304, slw: 4194309, saw: 4194304 -> 4194309
D1214 06:07:13.415859037 113724 flow_control.cc:113] 0x7f21e4007a48[3][cli] | data sent | trw: 4194304 -> 4194201, ttw: 4194309, taw: 4194213, srw: 4194304 -> 4194201, slw: 4194309, saw: 4194309
I1214 06:07:13.415867089 113724 chttp2_transport.cc:1249] complete_closure_step: t=0x7f21e4006400 0x241b5e8 refs=1 flags=0x0001 desc=send_trailing_metadata_finished err="No Error" write_state=WRITING+MORE
I1214 06:07:13.415875350 113724 chttp2_transport.cc:1249] complete_closure_step: t=0x7f21e4006400 0x241b5e8 refs=0 flags=0x0001 desc=on_write_finished_cb err="No Error" write_state=WRITING+MORE
I1214 06:07:13.415882017 113724 stream_lists.cc:125] 0x7f21e4006400[3][cli]: add to writing
D1214 06:07:13.415890188 113724 flow_control.cc:113] 0x7f21e4007a48[0][cli] | t updt sent | trw: 4194201, ttw: 4194309, taw: 4194213 -> 4194309, srw: , slw: , saw:
I1214 06:07:13.415898058 113724 chttp2_transport.cc:849] W:0x7f21e4006400 CLIENT state WRITING+MORE -> WRITING [begin write in current thread]
I1214 06:07:13.415906278 113724 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 00 00 09 01 04 00 00 00 03 86 83 c4 c3 c2 c1 c0 bf be 00 00 04 08 00 '.......................'
I1214 06:07:13.415913913 113724 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 00 00 00 03 00 00 00 05 00 00 67 00 01 00 00 00 03 00 00 00 00 62 '..........g..........b'
I1214 06:07:13.415922409 113724 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 22 60 0a 50 1a 0c 0a 0a 69 6e 74 65 72 66 61 63 65 73 1a 27 0a 11 76 69 72 74 75 61 6c 2d 69 6e 74 65 72 66 61 63 65 12 12 0a 04 6e 61 6d 65 12 0a 6e 65 74 5f 76 68 6f 73 74 30 1a 08 0a 06 63 6f 6e 66 69 67 1a 0d 0a 0b 64 65 76 69 63 65 2d 74 79 70 65 1a 0c 0a 0a 56 49 52 54 49 4f 5f 4e 45 54 '"`.P....interfaces.'..virtual-interface....name..net_vhost0....config....device-type....VIRTIO_NET'
I1214 06:07:13.415930268 113724 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 00 00 04 08 00 00 00 00 00 00 00 00 60 '............`'
I1214 06:07:13.415975984 113724 tcp_posix.cc:964] write: "No Error"
I1214 06:07:13.415983883 113724 chttp2_transport.cc:849] W:0x7f21e4006400 CLIENT state WRITING -> IDLE [finish writing]
I1214 06:07:13.415990555 113724 stream_lists.cc:71] 0x7f21e4006400[3][cli]: pop from writing
I1214 06:07:13.415997453 113724 call_combiner.cc:69] ==> grpc_call_combiner_start() [0x2419db0] closure=0x241ad10 [on_complete] error="No Error"
I1214 06:07:13.416003854 113724 call_combiner.cc:78] size: 0 -> 1
I1214 06:07:13.416009081 113724 call_combiner.cc:87] EXECUTING IMMEDIATELY
I1214 06:07:13.416015909 113724 call_combiner.cc:106] ==> grpc_call_combiner_stop() [0x2419db0] [on_complete]
I1214 06:07:13.416022331 113724 call_combiner.cc:113] size: 1 -> 0
I1214 06:07:13.416028328 113724 call_combiner.cc:141] queue empty
I1214 06:07:13.416037082 113724 completion_queue.cc:1198] grpc_completion_queue_pluck(cq=0x2419bd0, tag=0x7fff1c7609e0, deadline=gpr_timespec { tv_sec: 9223372036854775807, tv_nsec: 0, clock_type: 1 }, reserved=(nil))
I1214 06:07:13.416046215 113724 ev_epollex_linux.cc:1176] PS:0x2419cd0 work hdl=0x7fff1c7607a8 worker=0x7fff1c7606e0 now=10 deadline=9223372036854775807 kwp=0 pollable=0x241c700
I1214 06:07:13.416054944 113724 ev_epollex_linux.cc:994] POLLABLE:0x241c700[type=fd epfd=7 wakeup=8] poll for -1ms
I1214 06:07:13.416062972 113724 ev_epollex_linux.cc:1013] POLLABLE:0x241c700 got 1 events
I1214 06:07:13.416069400 113724 ev_epollex_linux.cc:961] PS:0x2419cd0 got fd 0x7f21e4003810: cancel=0 read=0 write=1
E1214 06:07:13.416075761 113724 lockfree_event.cc:213] LockfreeEvent::SetReady: 0x7f21e4003888 curr=0x2
I1214 06:07:13.416082951 113724 ev_epollex_linux.cc:722] PS:0x2419cd0 (pollable:0x241c700) maybe_finish_shutdown sc=(nil) (target:!NULL) rw=(nil) (target:NULL) cpsc=0 (target:0)
I1214 06:07:13.416091402 113724 ev_epollex_linux.cc:1176] PS:0x2419cd0 work hdl=0x7fff1c7607a8 worker=0x7fff1c7606e0 now=10 deadline=9223372036854775807 kwp=0 pollable=0x241c700
I1214 06:07:13.416097872 113724 ev_epollex_linux.cc:994] POLLABLE:0x241c700[type=fd epfd=7 wakeup=8] poll for -1ms
I1214 06:07:13.416179022 113724 ev_epollex_linux.cc:1013] POLLABLE:0x241c700 got 1 events
I1214 06:07:13.416186313 113724 ev_epollex_linux.cc:961] PS:0x2419cd0 got fd 0x7f21e4003810: cancel=0 read=1 write=1
E1214 06:07:13.416191989 113724 lockfree_event.cc:213] LockfreeEvent::SetReady: 0x7f21e4003880 curr=0x7f21e4004400
E1214 06:07:13.416198237 113724 lockfree_event.cc:213] LockfreeEvent::SetReady: 0x7f21e4003888 curr=0x2
I1214 06:07:13.416204919 113724 tcp_posix.cc:521] TCP:0x7f21e4004260 got_read: "No Error"
I1214 06:07:13.416211085 113724 tcp_posix.cc:512] TCP:0x7f21e4004260 do_read
I1214 06:07:13.416221897 113724 tcp_posix.cc:397] TCP:0x7f21e4004260 call_cb 0x7f21e4006540 0x7f21f29e3d30:0x7f21e4006400
I1214 06:07:13.416228114 113724 tcp_posix.cc:400] read: error="No Error"
I1214 06:07:13.416237407 113724 tcp_posix.cc:405] READ 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 00 00 04 01 04 00 00 00 03 88 c1 c0 bf 00 00 67 00 00 00 00 00 03 00 00 00 00 62 0a 00 12 54 12 50 1a 0c 0a 0a 69 6e 74 65 72 66 61 63 65 73 1a 27 0a 11 76 69 72 74 75 61 6c 2d 69 6e 74 65 72 66 61 63 65 12 12 0a 04 6e 61 6d 65 12 0a 6e 65 74 5f 76 68 6f 73 74 30 1a 08 0a 06 63 6f 6e 66 69 67 1a 0d 0a 0b 64 65 76 69 63 65 2d 74 79 70 65 20 03 20 80 fa 88 e4 87 c1 a2 e0 16 00 00 01 01 05 00 00 00 03 be 00 00 04 08 00 00 00 00 00 00 00 00 67 '...............g..........b...T.P....interfaces.'..virtual-interface....name..net_vhost0....config....device-type . ...............................g'
I1214 06:07:13.416246753 113724 parsing.cc:656] parsing initial_metadata
I1214 06:07:13.416254809 113724 hpack_parser.cc:636] Decode: ':status: 200', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.416261890 113724 parsing.cc:407] HTTP:3:HDR:CLI: :status: 32 30 30 '200'
I1214 06:07:13.416269089 113724 hpack_parser.cc:636] Decode: 'content-type: application/grpc', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.416276310 113724 parsing.cc:407] HTTP:3:HDR:CLI: content-type: 61 70 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 'application/grpc'
I1214 06:07:13.416285091 113724 hpack_parser.cc:636] Decode: 'grpc-accept-encoding: identity,deflate,gzip', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.416292474 113724 parsing.cc:407] HTTP:3:HDR:CLI: grpc-accept-encoding: 69 64 65 6e 74 69 74 79 2c 64 65 66 6c 61 74 65 2c 67 7a 69 70 'identity,deflate,gzip'
I1214 06:07:13.416299476 113724 hpack_parser.cc:636] Decode: 'accept-encoding: identity,gzip', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.416307521 113724 parsing.cc:407] HTTP:3:HDR:CLI: accept-encoding: 69 64 65 6e 74 69 74 79 2c 67 7a 69 70 'identity,gzip'
I1214 06:07:13.416314983 113724 call_combiner.cc:69] ==> grpc_call_combiner_start() [0x2419db0] closure=0x241b010 [recv_initial_metadata_ready] error="No Error"
I1214 06:07:13.416321923 113724 call_combiner.cc:78] size: 0 -> 1
I1214 06:07:13.416327770 113724 call_combiner.cc:87] EXECUTING IMMEDIATELY
D1214 06:07:13.416337545 113724 flow_control.cc:113] 0x7f21e4007a48[3][cli] | data recv | trw: 4194201, ttw: 4194309 -> 4194304, taw: 4194309 -> 4194206, srw: 4194201, slw: 4194309 -> 4194206, saw: 4194309 -> 4194206
I1214 06:07:13.416346928 113724 call_combiner.cc:69] ==> grpc_call_combiner_start() [0x2419db0] closure=0x241aeb0 [recv_message_ready] error="No Error"
I1214 06:07:13.416353447 113724 call_combiner.cc:78] size: 1 -> 2
I1214 06:07:13.416359072 113724 call_combiner.cc:93] QUEUING
I1214 06:07:13.416364551 113724 parsing.cc:661] parsing trailing_metadata
I1214 06:07:13.416371016 113724 hpack_parser.cc:636] Decode: 'grpc-status: 0', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.416377676 113724 parsing.cc:503] HTTP:3:TRL:CLI: grpc-status: 30 '0'
D1214 06:07:13.416388481 113724 flow_control.cc:113] 0x7f21e4007a48[0][cli] | t updt recv | trw: 4194201 -> 4194304, ttw: 4194304, taw: 4194206, srw: , slw: , saw:
I1214 06:07:13.416397538 113724 call_combiner.cc:106] ==> grpc_call_combiner_stop() [0x2419db0] [recv_initial_metadata_ready]
I1214 06:07:13.416403598 113724 call_combiner.cc:113] size: 2 -> 1
I1214 06:07:13.416409248 113724 call_combiner.cc:120] checking queue
I1214 06:07:13.416414961 113724 call_combiner.cc:134] EXECUTING FROM QUEUE: closure=0x241aeb0 error="No Error"
I1214 06:07:13.416422365 113724 tcp_posix.cc:521] TCP:0x7f21e4004260 got_read: "No Error"
I1214 06:07:13.416427918 113724 tcp_posix.cc:512] TCP:0x7f21e4004260 do_read
I1214 06:07:13.416436888 113724 tcp_posix.cc:252] TCP:0x7f21e4004260 notify_on_read
E1214 06:07:13.416443103 113724 lockfree_event.cc:98] LockfreeEvent::NotifyOn: 0x7f21e4003880 curr=(nil) closure=0x7f21e4004400
I1214 06:07:13.416449254 113724 call_combiner.cc:106] ==> grpc_call_combiner_stop() [0x2419db0] [recv_message_ready]
I1214 06:07:13.416455161 113724 call_combiner.cc:113] size: 1 -> 0
I1214 06:07:13.416461393 113724 call_combiner.cc:141] queue empty
I1214 06:07:13.416469865 113724 call_combiner.cc:69] ==> grpc_call_combiner_start() [0x2419db0] closure=0x241b048 [recv_trailing_metadata_ready] error="No Error"
I1214 06:07:13.416476220 113724 call_combiner.cc:78] size: 0 -> 1
I1214 06:07:13.416481927 113724 call_combiner.cc:87] EXECUTING IMMEDIATELY
I1214 06:07:13.416489115 113724 call_combiner.cc:106] ==> grpc_call_combiner_stop() [0x2419db0] [recv_trailing_metadata_ready]
I1214 06:07:13.416495042 113724 call_combiner.cc:113] size: 1 -> 0
I1214 06:07:13.416500548 113724 call_combiner.cc:141] queue empty
D1214 06:07:13.416505005 113724 call.cc:719] set_final_status CLI
D1214 06:07:13.416511190 113724 call.cc:720] "No Error"
I1214 06:07:13.416519746 113724 completion_queue.cc:779] cq_end_op_for_pluck(cq=0x2419bd0, tag=0x7fff1c7609e0, error="No Error", done=0x7f21f29cd6f0, done_arg=0x241ac70, storage=0x241acc0)
I1214 06:07:13.416527137 113724 ev_epollex_linux.cc:788] PS:0x2419cd0 kick 0x7fff1c7606e0 tls_pollset=0x2419cd0 tls_worker=0x7fff1c7606e0 pollset.root_worker=0x7fff1c7606e0
I1214 06:07:13.416532398 113724 ev_epollex_linux.cc:754] PS:0x241c700 kicked_specific_but_awake
I1214 06:07:13.416539626 113724 ev_epollex_linux.cc:722] PS:0x2419cd0 (pollable:0x241c700) maybe_finish_shutdown sc=(nil) (target:!NULL) rw=(nil) (target:NULL) cpsc=0 (target:0)
I1214 06:07:13.416548004 113724 completion_queue.cc:1299] RETURN_EVENT[0x2419bd0]: OP_COMPLETE: tag:0x7fff1c7609e0 OK
I1214 06:07:13.416567083 113724 completion_queue.cc:1395] grpc_completion_queue_destroy(cq=0x2419bd0)
I1214 06:07:13.416573369 113724 completion_queue.cc:1389] grpc_completion_queue_shutdown(cq=0x2419bd0)
I1214 06:07:13.416579917 113724 ev_epollex_linux.cc:722] PS:0x2419cd0 (pollable:0x241c700) maybe_finish_shutdown sc=0x2419bf0 (target:!NULL) rw=(nil) (target:NULL) cpsc=0 (target:0)
I1214 06:07:13.416586686 113724 init.cc:159] grpc_shutdown(void)
I1214 06:07:13.416598792 113724 call.cc:561] grpc_call_unref(c=0x2419da0)
I1214 06:07:13.416604897 113724 call_combiner.cc:167] call_combiner=0x2419db0: setting notify_on_cancel=(nil)
I1214 06:07:13.416615383 113724 metadata_array.cc:34] grpc_metadata_array_destroy(array=0x7fff1c761150)
I1214 06:07:13.416621784 113724 metadata_array.cc:34] grpc_metadata_array_destroy(array=0x7fff1c761100)
I1214 06:07:13.416630860 113724 channel.cc:376] grpc_channel_register_call(channel=0x240aa20, method=/gnmi.gNMI/Capabilities, host=(null), reserved=(nil))
I1214 06:07:13.416638888 113724 channel.cc:376] grpc_channel_register_call(channel=0x240aa20, method=/gnmi.gNMI/Get, host=(null), reserved=(nil))
I1214 06:07:13.416645799 113724 channel.cc:376] grpc_channel_register_call(channel=0x240aa20, method=/gnmi.gNMI/Set, host=(null), reserved=(nil))
I1214 06:07:13.416652834 113724 channel.cc:376] grpc_channel_register_call(channel=0x240aa20, method=/gnmi.gNMI/Subscribe, host=(null), reserved=(nil))
I1214 06:07:13.416997946 113724 init.cc:154] grpc_init(void)
I1214 06:07:13.417005933 113724 completion_queue.cc:478] grpc_completion_queue_create_internal(completion_type=1, polling_type=0)
I1214 06:07:13.417014966 113724 channel.cc:403] grpc_channel_create_registered_call(channel=0x240aa20, parent_call=(nil), propagation_mask=ffff, completion_queue=0x2405af0, registered_call_handle=0x241d2d0, deadline=gpr_timespec { tv_sec: 9223372036854775807, tv_nsec: 0, clock_type: 1 }, reserved=(nil))
I1214 06:07:13.417025642 113724 grpc_context.cc:27] grpc_census_call_set_context(call=0x2419da0, census_context=(nil))
I1214 06:07:13.417042288 113724 call.cc:1900] grpc_call_start_batch(call=0x2419da0, ops=0x7fff1c7606c0, nops=6, tag=0x7fff1c7609e0, reserved=(nil))
I1214 06:07:13.417050041 113724 call.cc:1508] ops[0]: SEND_INITIAL_METADATA(nil)
I1214 06:07:13.417056564 113724 call.cc:1508] ops[1]: SEND_MESSAGE ptr=0x241d4d0
I1214 06:07:13.417063259 113724 call.cc:1508] ops[2]: RECV_INITIAL_METADATA ptr=0x7fff1c761100
I1214 06:07:13.417069053 113724 call.cc:1508] ops[3]: RECV_MESSAGE ptr=0x7fff1c760a48
I1214 06:07:13.417075812 113724 call.cc:1508] ops[4]: SEND_CLOSE_FROM_CLIENT
I1214 06:07:13.417083500 113724 call.cc:1508] ops[5]: RECV_STATUS_ON_CLIENT metadata=0x7fff1c761150 status=0x7fff1c760a80 details=0x7fff1c760a88
I1214 06:07:13.417091960 113724 call_combiner.cc:69] ==> grpc_call_combiner_start() [0x2419db0] closure=0x241ace8 [executing batch] error="No Error"
I1214 06:07:13.417098427 113724 call_combiner.cc:78] size: 0 -> 1
I1214 06:07:13.417103776 113724 call_combiner.cc:87] EXECUTING IMMEDIATELY
I1214 06:07:13.417115786 113724 call.cc:613] OP[client-channel:0x241a720]: SEND_INITIAL_METADATA{key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set'} SEND_MESSAGE:flags=0x00000000:len=83 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.417123496 113724 client_channel.cc:1204] chand=0x240aae8 calld=0x241a740: adding pending batch at index 0
I1214 06:07:13.417129718 113724 client_channel.cc:3197] chand=0x240aae8 calld=0x241a740: entering client_channel combiner
I1214 06:07:13.417138273 113724 client_channel.cc:2855] chand=0x240aae8 calld=0x241a740: applying service config to call
I1214 06:07:13.417145205 113724 connectivity_state.cc:81] CONWATCH: 0x240ab70 client_channel: get READY
I1214 06:07:13.417151197 113724 client_channel.cc:2763] chand=0x240aae8 calld=0x241a740: starting pick on lb_policy=0x7f21e4001430
I1214 06:07:13.417158689 113724 client_channel.cc:2790] chand=0x240aae8 calld=0x241a740: pick completed synchronously
I1214 06:07:13.417167363 113724 ev_epollex_linux.cc:1217] PS:0x2405bf0 add fd 0x7f21e4003810 (9); transition pollable from empty to fd
I1214 06:07:13.417174808 113724 client_channel.cc:2669] chand=0x240aae8 calld=0x241a740: create subchannel_call=0x241ad50: error="No Error"
I1214 06:07:13.417181995 113724 client_channel.cc:1346] chand=0x240aae8 calld=0x241a740: starting 1 pending batches on subchannel_call=0x241ad50
I1214 06:07:13.417189042 113724 call_combiner.h:153] CallCombinerClosureList executing closure while already holding call_combiner 0x2419db0: closure=0x241ac98 error="No Error" reason=pending_batches_resume
I1214 06:07:13.417200992 113724 subchannel.cc:1000] OP[authority:0x241adf0]: SEND_INITIAL_METADATA{key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set'} SEND_MESSAGE:flags=0x00000000:len=83 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.417214750 113724 channel_stack.cc:226] OP[message_size:0x241ae08]: SEND_INITIAL_METADATA{key=3a 61 75 74 68 6f 72 69 74 79 ':authority' value=31 32 37 2e 30 2e 30 2e 31 3a 39 33 33 39 '127.0.0.1:9339', key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set'} SEND_MESSAGE:flags=0x00000000:len=83 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.417235130 113724 channel_stack.cc:226] OP[http-client:0x241ae20]: SEND_INITIAL_METADATA{key=3a 61 75 74 68 6f 72 69 74 79 ':authority' value=31 32 37 2e 30 2e 30 2e 31 3a 39 33 33 39 '127.0.0.1:9339', key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set'} SEND_MESSAGE:flags=0x00000000:len=83 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.417258500 113724 channel_stack.cc:226] OP[message_compress:0x241ae38]: SEND_INITIAL_METADATA{key=3a 73 63 68 65 6d 65 ':scheme' value=68 74 74 70 'http', key=3a 6d 65 74 68 6f 64 ':method' value=50 4f 53 54 'POST', key=3a 61 75 74 68 6f 72 69 74 79 ':authority' value=31 32 37 2e 30 2e 30 2e 31 3a 39 33 33 39 '127.0.0.1:9339', key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set', key=74 65 'te' value=74 72 61 69 6c 65 72 73 'trailers', key=63 6f 6e 74 65 6e 74 2d 74 79 70 65 'content-type' value=61 70 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 'application/grpc', key=75 73 65 72 2d 61 67 65 6e 74 'user-agent' value=67 72 70 63 2d 63 2b 2b 2f 31 2e 31 37 2e 31 20 67 72 70 63 2d 63 2f 37 2e 30 2e 30 20 28 6c 69 6e 75 78 3b 20 63 68 74 74 70 32 3b 20 67 69 7a 6d 6f 29 'grpc-c++/1.17.1 grpc-c/7.0.0 (linux; chttp2; gizmo)'} SEND_MESSAGE:flags=0x00000000:len=83 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.417292331 113724 channel_stack.cc:226] OP[connected:0x241ae50]: SEND_INITIAL_METADATA{key=3a 73 63 68 65 6d 65 ':scheme' value=68 74 74 70 'http', key=3a 6d 65 74 68 6f 64 ':method' value=50 4f 53 54 'POST', key=3a 61 75 74 68 6f 72 69 74 79 ':authority' value=31 32 37 2e 30 2e 30 2e 31 3a 39 33 33 39 '127.0.0.1:9339', key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set', key=74 65 'te' value=74 72 61 69 6c 65 72 73 'trailers', key=63 6f 6e 74 65 6e 74 2d 74 79 70 65 'content-type' value=61 70 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 'application/grpc', key=75 73 65 72 2d 61 67 65 6e 74 'user-agent' value=67 72 70 63 2d 63 2b 2b 2f 31 2e 31 37 2e 31 20 67 72 70 63 2d 63 2f 37 2e 30 2e 30 20 28 6c 69 6e 75 78 3b 20 63 68 74 74 70 32 3b 20 67 69 7a 6d 6f 29 'grpc-c++/1.17.1 grpc-c/7.0.0 (linux; chttp2; gizmo)', key=67 72 70 63 2d 61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'grpc-accept-encoding' value=69 64 65 6e 74 69 74 79 2c 64 65 66 6c 61 74 65 2c 67 7a 69 70 'identity,deflate,gzip', key=61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'accept-encoding' value=69 64 65 6e 74 69 74 79 2c 67 7a 69 70 'identity,gzip'} SEND_MESSAGE:flags=0x00000000:len=83 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.417324035 113724 chttp2_transport.cc:1702] perform_stream_op[s=0x241b828]: SEND_INITIAL_METADATA{key=3a 73 63 68 65 6d 65 ':scheme' value=68 74 74 70 'http', key=3a 6d 65 74 68 6f 64 ':method' value=50 4f 53 54 'POST', key=3a 61 75 74 68 6f 72 69 74 79 ':authority' value=31 32 37 2e 30 2e 30 2e 31 3a 39 33 33 39 '127.0.0.1:9339', key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set', key=74 65 'te' value=74 72 61 69 6c 65 72 73 'trailers', key=63 6f 6e 74 65 6e 74 2d 74 79 70 65 'content-type' value=61 70 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 'application/grpc', key=75 73 65 72 2d 61 67 65 6e 74 'user-agent' value=67 72 70 63 2d 63 2b 2b 2f 31 2e 31 37 2e 31 20 67 72 70 63 2d 63 2f 37 2e 30 2e 30 20 28 6c 69 6e 75 78 3b 20 63 68 74 74 70 32 3b 20 67 69 7a 6d 6f 29 'grpc-c++/1.17.1 grpc-c/7.0.0 (linux; chttp2; gizmo)', key=67 72 70 63 2d 61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'grpc-accept-encoding' value=69 64 65 6e 74 69 74 79 2c 64 65 66 6c 61 74 65 2c 67 7a 69 70 'identity,deflate,gzip', key=61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'accept-encoding' value=69 64 65 6e 74 69 74 79 2c 67 7a 69 70 'identity,gzip'} SEND_MESSAGE:flags=0x00000000:len=83 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.417335192 113724 call_combiner.cc:106] ==> grpc_call_combiner_stop() [0x2419db0] [passed batch to transport]
I1214 06:07:13.417341116 113724 call_combiner.cc:113] size: 1 -> 0
I1214 06:07:13.417346578 113724 call_combiner.cc:141] queue empty
I1214 06:07:13.417371856 113724 chttp2_transport.cc:1398] perform_stream_op_locked: SEND_INITIAL_METADATA{key=3a 73 63 68 65 6d 65 ':scheme' value=68 74 74 70 'http', key=3a 6d 65 74 68 6f 64 ':method' value=50 4f 53 54 'POST', key=3a 61 75 74 68 6f 72 69 74 79 ':authority' value=31 32 37 2e 30 2e 30 2e 31 3a 39 33 33 39 '127.0.0.1:9339', key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set', key=74 65 'te' value=74 72 61 69 6c 65 72 73 'trailers', key=63 6f 6e 74 65 6e 74 2d 74 79 70 65 'content-type' value=61 70 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 'application/grpc', key=75 73 65 72 2d 61 67 65 6e 74 'user-agent' value=67 72 70 63 2d 63 2b 2b 2f 31 2e 31 37 2e 31 20 67 72 70 63 2d 63 2f 37 2e 30 2e 30 20 28 6c 69 6e 75 78 3b 20 63 68 74 74 70 32 3b 20 67 69 7a 6d 6f 29 'grpc-c++/1.17.1 grpc-c/7.0.0 (linux; chttp2; gizmo)', key=67 72 70 63 2d 61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'grpc-accept-encoding' value=69 64 65 6e 74 69 74 79 2c 64 65 66 6c 61 74 65 2c 67 7a 69 70 'identity,deflate,gzip', key=61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'accept-encoding' value=69 64 65 6e 74 69 74 79 2c 67 7a 69 70 'identity,gzip'} SEND_MESSAGE:flags=0x00000000:len=83 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA; on_complete = 0x241b5e8
I1214 06:07:13.417383978 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: :scheme: http
I1214 06:07:13.417390139 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: :method: POST
I1214 06:07:13.417396019 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: :authority: 127.0.0.1:9339
I1214 06:07:13.417402023 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: :path: /gnmi.gNMI/Set
I1214 06:07:13.417408293 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: te: trailers
I1214 06:07:13.417415787 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: content-type: application/grpc
I1214 06:07:13.417421594 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: user-agent: grpc-c++/1.17.1 grpc-c/7.0.0 (linux; chttp2; gizmo)
I1214 06:07:13.417428848 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: grpc-accept-encoding: identity,deflate,gzip
I1214 06:07:13.417435895 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: accept-encoding: identity,gzip
I1214 06:07:13.417442876 113724 stream_lists.cc:125] 0x7f21e4006400[0][cli]: add to waiting_for_concurrency
I1214 06:07:13.417449034 113724 stream_lists.cc:71] 0x7f21e4006400[0][cli]: pop from waiting_for_concurrency
I1214 06:07:13.417455500 113724 chttp2_transport.cc:1186] HTTP:CLI: Allocating new grpc_chttp2_stream 0x241b828 to id 5
I1214 06:07:13.417461814 113724 stream_lists.cc:125] 0x7f21e4006400[5][cli]: add to writable
I1214 06:07:13.417468366 113724 chttp2_transport.cc:849] W:0x7f21e4006400 CLIENT state IDLE -> WRITING [START_NEW_STREAM]
I1214 06:07:13.417475625 113724 chttp2_transport.cc:849] W:0x7f21e4006400 CLIENT state WRITING -> WRITING+MORE [SEND_MESSAGE]
D1214 06:07:13.417485343 113724 flow_control.cc:113] 0x7f21e4007a48[5][cli] | app st recv | trw: 4194304, ttw: 4194304, taw: 4194206, srw: 4194304, slw: 4194304 -> 4194309, saw: 4194304
I1214 06:07:13.417494499 113724 chttp2_transport.cc:1249] complete_closure_step: t=0x7f21e4006400 0x241b5e8 refs=3 flags=0x0001 desc=op->on_complete err="No Error" write_state=WRITING+MORE
I1214 06:07:13.417502185 113724 stream_lists.cc:71] 0x7f21e4006400[5][cli]: pop from writable
I1214 06:07:13.417508908 113724 writing.cc:409] W:0x7f21e4006400 CLIENT[5] im-(sent,send)=(0,1) announce=5
I1214 06:07:13.417516396 113724 hpack_encoder.cc:473] Encode: ':authority: 127.0.0.1:9339', elem_interned=1 [1], k_interned=1, v_interned=1
I1214 06:07:13.417523527 113724 hpack_encoder.cc:473] Encode: ':path: /gnmi.gNMI/Set', elem_interned=1 [1], k_interned=1, v_interned=1
I1214 06:07:13.417530481 113724 hpack_encoder.cc:473] Encode: 'te: trailers', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.417537373 113724 hpack_encoder.cc:473] Encode: 'content-type: application/grpc', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.417544238 113724 hpack_encoder.cc:473] Encode: 'user-agent: grpc-c++/1.17.1 grpc-c/7.0.0 (linux; chttp2; gizmo)', elem_interned=1 [1], k_interned=1, v_interned=1
I1214 06:07:13.417551073 113724 hpack_encoder.cc:473] Encode: 'grpc-accept-encoding: identity,deflate,gzip', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.417557356 113724 hpack_encoder.cc:473] Encode: 'accept-encoding: identity,gzip', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.417564115 113724 chttp2_transport.cc:1249] complete_closure_step: t=0x7f21e4006400 0x241b5e8 refs=2 flags=0x0001 desc=send_initial_metadata_finished err="No Error" write_state=WRITING+MORE
D1214 06:07:13.417573334 113724 flow_control.cc:113] 0x7f21e4007a48[5][cli] | s updt sent | trw: 4194304, ttw: 4194304 -> 4194309, taw: 4194206, srw: 4194304, slw: 4194309, saw: 4194304 -> 4194309
D1214 06:07:13.417584878 113724 flow_control.cc:113] 0x7f21e4007a48[5][cli] | data sent | trw: 4194304 -> 4194216, ttw: 4194309, taw: 4194206, srw: 4194304 -> 4194216, slw: 4194309, saw: 4194309
I1214 06:07:13.417593028 113724 chttp2_transport.cc:1249] complete_closure_step: t=0x7f21e4006400 0x241b5e8 refs=1 flags=0x0001 desc=send_trailing_metadata_finished err="No Error" write_state=WRITING+MORE
I1214 06:07:13.417599919 113724 chttp2_transport.cc:1249] complete_closure_step: t=0x7f21e4006400 0x241b5e8 refs=0 flags=0x0001 desc=on_write_finished_cb err="No Error" write_state=WRITING+MORE
I1214 06:07:13.417606471 113724 stream_lists.cc:125] 0x7f21e4006400[5][cli]: add to writing
D1214 06:07:13.417614691 113724 flow_control.cc:113] 0x7f21e4007a48[0][cli] | t updt sent | trw: 4194216, ttw: 4194309, taw: 4194206 -> 4194309, srw: , slw: , saw:
I1214 06:07:13.417622501 113724 chttp2_transport.cc:849] W:0x7f21e4006400 CLIENT state WRITING+MORE -> WRITING [begin write in current thread]
I1214 06:07:13.417630349 113724 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 00 00 09 01 04 00 00 00 05 86 83 c4 c3 c2 c1 c0 bf be 00 00 04 08 00 '.......................'
I1214 06:07:13.417637620 113724 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 00 00 00 05 00 00 00 05 00 00 58 00 01 00 00 00 05 00 00 00 00 53 '..........X..........S'
I1214 06:07:13.417645751 113724 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 22 51 0a 4b 1a 0c 0a 0a 69 6e 74 65 72 66 61 63 65 73 1a 27 0a 11 76 69 72 74 75 61 6c 2d 69 6e 74 65 72 66 61 63 65 12 12 0a 04 6e 61 6d 65 12 0a 6e 65 74 5f 76 68 6f 73 74 30 1a 08 0a 06 63 6f 6e 66 69 67 1a 08 0a 06 71 75 65 75 65 73 1a 02 10 01 '"Q.K....interfaces.'..virtual-interface....name..net_vhost0....config....queues....'
I1214 06:07:13.417654847 113724 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 00 00 04 08 00 00 00 00 00 00 00 00 67 '............g'
I1214 06:07:13.417680073 113724 tcp_posix.cc:964] write: "No Error"
I1214 06:07:13.417686875 113724 chttp2_transport.cc:849] W:0x7f21e4006400 CLIENT state WRITING -> IDLE [finish writing]
I1214 06:07:13.417693792 113724 stream_lists.cc:71] 0x7f21e4006400[5][cli]: pop from writing
I1214 06:07:13.417700283 113724 call_combiner.cc:69] ==> grpc_call_combiner_start() [0x2419db0] closure=0x241ad10 [on_complete] error="No Error"
I1214 06:07:13.417706686 113724 call_combiner.cc:78] size: 0 -> 1
I1214 06:07:13.417712868 113724 call_combiner.cc:87] EXECUTING IMMEDIATELY
I1214 06:07:13.417718617 113724 call_combiner.cc:106] ==> grpc_call_combiner_stop() [0x2419db0] [on_complete]
I1214 06:07:13.417724349 113724 call_combiner.cc:113] size: 1 -> 0
I1214 06:07:13.417730161 113724 call_combiner.cc:141] queue empty
I1214 06:07:13.417737817 113724 completion_queue.cc:1198] grpc_completion_queue_pluck(cq=0x2405af0, tag=0x7fff1c7609e0, deadline=gpr_timespec { tv_sec: 9223372036854775807, tv_nsec: 0, clock_type: 1 }, reserved=(nil))
I1214 06:07:13.417746678 113724 ev_epollex_linux.cc:1176] PS:0x2405bf0 work hdl=0x7fff1c7607a8 worker=0x7fff1c7606e0 now=12 deadline=9223372036854775807 kwp=0 pollable=0x241c700
I1214 06:07:13.417753902 113724 ev_epollex_linux.cc:994] POLLABLE:0x241c700[type=fd epfd=7 wakeup=8] poll for -1ms
I1214 06:07:13.418184112 113724 ev_epollex_linux.cc:1013] POLLABLE:0x241c700 got 1 events
I1214 06:07:13.418191222 113724 ev_epollex_linux.cc:961] PS:0x2405bf0 got fd 0x7f21e4003810: cancel=0 read=1 write=1
E1214 06:07:13.418198108 113724 lockfree_event.cc:213] LockfreeEvent::SetReady: 0x7f21e4003880 curr=0x7f21e4004400
E1214 06:07:13.418204019 113724 lockfree_event.cc:213] LockfreeEvent::SetReady: 0x7f21e4003888 curr=0x2
I1214 06:07:13.418212198 113724 tcp_posix.cc:521] TCP:0x7f21e4004260 got_read: "No Error"
I1214 06:07:13.418218280 113724 tcp_posix.cc:512] TCP:0x7f21e4004260 do_read
I1214 06:07:13.418232308 113724 tcp_posix.cc:397] TCP:0x7f21e4004260 call_cb 0x7f21e4006540 0x7f21f29e3d30:0x7f21e4006400
I1214 06:07:13.418238495 113724 tcp_posix.cc:400] read: error="No Error"
I1214 06:07:13.418248254 113724 tcp_posix.cc:405] READ 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 00 00 04 01 04 00 00 00 05 88 c1 c0 bf 00 00 62 00 00 00 00 00 05 00 00 00 00 5d 0a 00 12 4f 12 4b 1a 0c 0a 0a 69 6e 74 65 72 66 61 63 65 73 1a 27 0a 11 76 69 72 74 75 61 6c 2d 69 6e 74 65 72 66 61 63 65 12 12 0a 04 6e 61 6d 65 12 0a 6e 65 74 5f 76 68 6f 73 74 30 1a 08 0a 06 63 6f 6e 66 69 67 1a 08 0a 06 71 75 65 75 65 73 20 03 20 ed b6 82 e5 87 c1 a2 e0 16 00 00 01 01 05 00 00 00 05 be 00 00 04 08 00 00 00 00 00 00 00 00 58 '...............b..........]...O.K....interfaces.'..virtual-interface....name..net_vhost0....config....queues . ...............................X'
I1214 06:07:13.418257277 113724 parsing.cc:656] parsing initial_metadata
I1214 06:07:13.418263384 113724 hpack_parser.cc:636] Decode: ':status: 200', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.418268291 113724 parsing.cc:407] HTTP:5:HDR:CLI: :status: 32 30 30 '200'
I1214 06:07:13.418276396 113724 hpack_parser.cc:636] Decode: 'content-type: application/grpc', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.418283350 113724 parsing.cc:407] HTTP:5:HDR:CLI: content-type: 61 70 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 'application/grpc'
I1214 06:07:13.418290700 113724 hpack_parser.cc:636] Decode: 'grpc-accept-encoding: identity,deflate,gzip', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.418297738 113724 parsing.cc:407] HTTP:5:HDR:CLI: grpc-accept-encoding: 69 64 65 6e 74 69 74 79 2c 64 65 66 6c 61 74 65 2c 67 7a 69 70 'identity,deflate,gzip'
I1214 06:07:13.418304524 113724 hpack_parser.cc:636] Decode: 'accept-encoding: identity,gzip', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.418310979 113724 parsing.cc:407] HTTP:5:HDR:CLI: accept-encoding: 69 64 65 6e 74 69 74 79 2c 67 7a 69 70 'identity,gzip'
I1214 06:07:13.418318280 113724 call_combiner.cc:69] ==> grpc_call_combiner_start() [0x2419db0] closure=0x241b010 [recv_initial_metadata_ready] error="No Error"
I1214 06:07:13.418324535 113724 call_combiner.cc:78] size: 0 -> 1
I1214 06:07:13.418330184 113724 call_combiner.cc:87] EXECUTING IMMEDIATELY
D1214 06:07:13.418339851 113724 flow_control.cc:113] 0x7f21e4007a48[5][cli] | data recv | trw: 4194216, ttw: 4194309 -> 4194304, taw: 4194309 -> 4194211, srw: 4194216, slw: 4194309 -> 4194211, saw: 4194309 -> 4194211
I1214 06:07:13.418348935 113724 call_combiner.cc:69] ==> grpc_call_combiner_start() [0x2419db0] closure=0x241aeb0 [recv_message_ready] error="No Error"
I1214 06:07:13.418356335 113724 call_combiner.cc:78] size: 1 -> 2
I1214 06:07:13.418362918 113724 call_combiner.cc:93] QUEUING
I1214 06:07:13.418369514 113724 parsing.cc:661] parsing trailing_metadata
I1214 06:07:13.418375711 113724 hpack_parser.cc:636] Decode: 'grpc-status: 0', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.418381960 113724 parsing.cc:503] HTTP:5:TRL:CLI: grpc-status: 30 '0'
D1214 06:07:13.418392011 113724 flow_control.cc:113] 0x7f21e4007a48[0][cli] | t updt recv | trw: 4194216 -> 4194304, ttw: 4194304, taw: 4194211, srw: , slw: , saw:
I1214 06:07:13.418401274 113724 call_combiner.cc:106] ==> grpc_call_combiner_stop() [0x2419db0] [recv_initial_metadata_ready]
I1214 06:07:13.418407401 113724 call_combiner.cc:113] size: 2 -> 1
I1214 06:07:13.418412632 113724 call_combiner.cc:120] checking queue
I1214 06:07:13.418419821 113724 call_combiner.cc:134] EXECUTING FROM QUEUE: closure=0x241aeb0 error="No Error"
I1214 06:07:13.418426610 113724 tcp_posix.cc:521] TCP:0x7f21e4004260 got_read: "No Error"
I1214 06:07:13.418432474 113724 tcp_posix.cc:512] TCP:0x7f21e4004260 do_read
I1214 06:07:13.418439362 113724 tcp_posix.cc:252] TCP:0x7f21e4004260 notify_on_read
E1214 06:07:13.418446019 113724 lockfree_event.cc:98] LockfreeEvent::NotifyOn: 0x7f21e4003880 curr=(nil) closure=0x7f21e4004400
I1214 06:07:13.418452392 113724 call_combiner.cc:106] ==> grpc_call_combiner_stop() [0x2419db0] [recv_message_ready]
I1214 06:07:13.418458487 113724 call_combiner.cc:113] size: 1 -> 0
I1214 06:07:13.418464692 113724 call_combiner.cc:141] queue empty
I1214 06:07:13.418472490 113724 call_combiner.cc:69] ==> grpc_call_combiner_start() [0x2419db0] closure=0x241b048 [recv_trailing_metadata_ready] error="No Error"
I1214 06:07:13.418478670 113724 call_combiner.cc:78] size: 0 -> 1
I1214 06:07:13.418483934 113724 call_combiner.cc:87] EXECUTING IMMEDIATELY
I1214 06:07:13.418490618 113724 call_combiner.cc:106] ==> grpc_call_combiner_stop() [0x2419db0] [recv_trailing_metadata_ready]
I1214 06:07:13.418496562 113724 call_combiner.cc:113] size: 1 -> 0
I1214 06:07:13.418501958 113724 call_combiner.cc:141] queue empty
D1214 06:07:13.418507475 113724 call.cc:719] set_final_status CLI
D1214 06:07:13.418514495 113724 call.cc:720] "No Error"
I1214 06:07:13.418522347 113724 completion_queue.cc:779] cq_end_op_for_pluck(cq=0x2405af0, tag=0x7fff1c7609e0, error="No Error", done=0x7f21f29cd6f0, done_arg=0x241ac70, storage=0x241acc0)
I1214 06:07:13.418529805 113724 ev_epollex_linux.cc:788] PS:0x2405bf0 kick 0x7fff1c7606e0 tls_pollset=0x2405bf0 tls_worker=0x7fff1c7606e0 pollset.root_worker=0x7fff1c7606e0
I1214 06:07:13.418536517 113724 ev_epollex_linux.cc:754] PS:0x241c700 kicked_specific_but_awake
I1214 06:07:13.418543127 113724 ev_epollex_linux.cc:722] PS:0x2405bf0 (pollable:0x241c700) maybe_finish_shutdown sc=(nil) (target:!NULL) rw=(nil) (target:NULL) cpsc=0 (target:0)
I1214 06:07:13.418552086 113724 completion_queue.cc:1299] RETURN_EVENT[0x2405af0]: OP_COMPLETE: tag:0x7fff1c7609e0 OK
I1214 06:07:13.418568041 113724 completion_queue.cc:1395] grpc_completion_queue_destroy(cq=0x2405af0)
I1214 06:07:13.418574244 113724 completion_queue.cc:1389] grpc_completion_queue_shutdown(cq=0x2405af0)
I1214 06:07:13.418580701 113724 ev_epollex_linux.cc:722] PS:0x2405bf0 (pollable:0x241c700) maybe_finish_shutdown sc=0x2405b10 (target:!NULL) rw=(nil) (target:NULL) cpsc=0 (target:0)
I1214 06:07:13.418585795 113724 init.cc:159] grpc_shutdown(void)
I1214 06:07:13.418596675 113724 call.cc:561] grpc_call_unref(c=0x2419da0)
I1214 06:07:13.418602913 113724 call_combiner.cc:167] call_combiner=0x2419db0: setting notify_on_cancel=(nil)
I1214 06:07:13.418612329 113724 metadata_array.cc:34] grpc_metadata_array_destroy(array=0x7fff1c761150)
I1214 06:07:13.418618585 113724 metadata_array.cc:34] grpc_metadata_array_destroy(array=0x7fff1c761100)
I1214 06:07:13.418626972 113724 channel.cc:376] grpc_channel_register_call(channel=0x240aa20, method=/gnmi.gNMI/Capabilities, host=(null), reserved=(nil))
I1214 06:07:13.418635088 113724 channel.cc:376] grpc_channel_register_call(channel=0x240aa20, method=/gnmi.gNMI/Get, host=(null), reserved=(nil))
I1214 06:07:13.418643712 113724 channel.cc:376] grpc_channel_register_call(channel=0x240aa20, method=/gnmi.gNMI/Set, host=(null), reserved=(nil))
I1214 06:07:13.418650528 113724 channel.cc:376] grpc_channel_register_call(channel=0x240aa20, method=/gnmi.gNMI/Subscribe, host=(null), reserved=(nil))
I1214 06:07:13.418989080 113724 init.cc:154] grpc_init(void)
I1214 06:07:13.418996538 113724 completion_queue.cc:478] grpc_completion_queue_create_internal(completion_type=1, polling_type=0)
I1214 06:07:13.419005240 113724 channel.cc:403] grpc_channel_create_registered_call(channel=0x240aa20, parent_call=(nil), propagation_mask=ffff, completion_queue=0x240d230, registered_call_handle=0x2407190, deadline=gpr_timespec { tv_sec: 9223372036854775807, tv_nsec: 0, clock_type: 1 }, reserved=(nil))
I1214 06:07:13.419015284 113724 grpc_context.cc:27] grpc_census_call_set_context(call=0x2419da0, census_context=(nil))
I1214 06:07:13.419032208 113724 call.cc:1900] grpc_call_start_batch(call=0x2419da0, ops=0x7fff1c7606c0, nops=6, tag=0x7fff1c7609e0, reserved=(nil))
I1214 06:07:13.419039525 113724 call.cc:1508] ops[0]: SEND_INITIAL_METADATA(nil)
I1214 06:07:13.419045564 113724 call.cc:1508] ops[1]: SEND_MESSAGE ptr=0x2420fa0
I1214 06:07:13.419052611 113724 call.cc:1508] ops[2]: RECV_INITIAL_METADATA ptr=0x7fff1c761100
I1214 06:07:13.419059522 113724 call.cc:1508] ops[3]: RECV_MESSAGE ptr=0x7fff1c760a48
I1214 06:07:13.419065411 113724 call.cc:1508] ops[4]: SEND_CLOSE_FROM_CLIENT
I1214 06:07:13.419073601 113724 call.cc:1508] ops[5]: RECV_STATUS_ON_CLIENT metadata=0x7fff1c761150 status=0x7fff1c760a80 details=0x7fff1c760a88
I1214 06:07:13.419081100 113724 call_combiner.cc:69] ==> grpc_call_combiner_start() [0x2419db0] closure=0x241ace8 [executing batch] error="No Error"
I1214 06:07:13.419087030 113724 call_combiner.cc:78] size: 0 -> 1
I1214 06:07:13.419093626 113724 call_combiner.cc:87] EXECUTING IMMEDIATELY
I1214 06:07:13.419105830 113724 call.cc:613] OP[client-channel:0x241a720]: SEND_INITIAL_METADATA{key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set'} SEND_MESSAGE:flags=0x00000000:len=105 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.419113543 113724 client_channel.cc:1204] chand=0x240aae8 calld=0x241a740: adding pending batch at index 0
I1214 06:07:13.419120076 113724 client_channel.cc:3197] chand=0x240aae8 calld=0x241a740: entering client_channel combiner
I1214 06:07:13.419128157 113724 client_channel.cc:2855] chand=0x240aae8 calld=0x241a740: applying service config to call
I1214 06:07:13.419134179 113724 connectivity_state.cc:81] CONWATCH: 0x240ab70 client_channel: get READY
I1214 06:07:13.419141640 113724 client_channel.cc:2763] chand=0x240aae8 calld=0x241a740: starting pick on lb_policy=0x7f21e4001430
I1214 06:07:13.419147781 113724 client_channel.cc:2790] chand=0x240aae8 calld=0x241a740: pick completed synchronously
I1214 06:07:13.419155739 113724 ev_epollex_linux.cc:1217] PS:0x240d330 add fd 0x7f21e4003810 (9); transition pollable from empty to fd
I1214 06:07:13.419162769 113724 client_channel.cc:2669] chand=0x240aae8 calld=0x241a740: create subchannel_call=0x241ad50: error="No Error"
I1214 06:07:13.419170394 113724 client_channel.cc:1346] chand=0x240aae8 calld=0x241a740: starting 1 pending batches on subchannel_call=0x241ad50
I1214 06:07:13.419177534 113724 call_combiner.h:153] CallCombinerClosureList executing closure while already holding call_combiner 0x2419db0: closure=0x241ac98 error="No Error" reason=pending_batches_resume
I1214 06:07:13.419189542 113724 subchannel.cc:1000] OP[authority:0x241adf0]: SEND_INITIAL_METADATA{key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set'} SEND_MESSAGE:flags=0x00000000:len=105 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.419203850 113724 channel_stack.cc:226] OP[message_size:0x241ae08]: SEND_INITIAL_METADATA{key=3a 61 75 74 68 6f 72 69 74 79 ':authority' value=31 32 37 2e 30 2e 30 2e 31 3a 39 33 33 39 '127.0.0.1:9339', key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set'} SEND_MESSAGE:flags=0x00000000:len=105 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.419216896 113724 channel_stack.cc:226] OP[http-client:0x241ae20]: SEND_INITIAL_METADATA{key=3a 61 75 74 68 6f 72 69 74 79 ':authority' value=31 32 37 2e 30 2e 30 2e 31 3a 39 33 33 39 '127.0.0.1:9339', key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set'} SEND_MESSAGE:flags=0x00000000:len=105 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.419244460 113724 channel_stack.cc:226] OP[message_compress:0x241ae38]: SEND_INITIAL_METADATA{key=3a 73 63 68 65 6d 65 ':scheme' value=68 74 74 70 'http', key=3a 6d 65 74 68 6f 64 ':method' value=50 4f 53 54 'POST', key=3a 61 75 74 68 6f 72 69 74 79 ':authority' value=31 32 37 2e 30 2e 30 2e 31 3a 39 33 33 39 '127.0.0.1:9339', key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set', key=74 65 'te' value=74 72 61 69 6c 65 72 73 'trailers', key=63 6f 6e 74 65 6e 74 2d 74 79 70 65 'content-type' value=61 70 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 'application/grpc', key=75 73 65 72 2d 61 67 65 6e 74 'user-agent' value=67 72 70 63 2d 63 2b 2b 2f 31 2e 31 37 2e 31 20 67 72 70 63 2d 63 2f 37 2e 30 2e 30 20 28 6c 69 6e 75 78 3b 20 63 68 74 74 70 32 3b 20 67 69 7a 6d 6f 29 'grpc-c++/1.17.1 grpc-c/7.0.0 (linux; chttp2; gizmo)'} SEND_MESSAGE:flags=0x00000000:len=105 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.419275147 113724 channel_stack.cc:226] OP[connected:0x241ae50]: SEND_INITIAL_METADATA{key=3a 73 63 68 65 6d 65 ':scheme' value=68 74 74 70 'http', key=3a 6d 65 74 68 6f 64 ':method' value=50 4f 53 54 'POST', key=3a 61 75 74 68 6f 72 69 74 79 ':authority' value=31 32 37 2e 30 2e 30 2e 31 3a 39 33 33 39 '127.0.0.1:9339', key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set', key=74 65 'te' value=74 72 61 69 6c 65 72 73 'trailers', key=63 6f 6e 74 65 6e 74 2d 74 79 70 65 'content-type' value=61 70 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 'application/grpc', key=75 73 65 72 2d 61 67 65 6e 74 'user-agent' value=67 72 70 63 2d 63 2b 2b 2f 31 2e 31 37 2e 31 20 67 72 70 63 2d 63 2f 37 2e 30 2e 30 20 28 6c 69 6e 75 78 3b 20 63 68 74 74 70 32 3b 20 67 69 7a 6d 6f 29 'grpc-c++/1.17.1 grpc-c/7.0.0 (linux; chttp2; gizmo)', key=67 72 70 63 2d 61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'grpc-accept-encoding' value=69 64 65 6e 74 69 74 79 2c 64 65 66 6c 61 74 65 2c 67 7a 69 70 'identity,deflate,gzip', key=61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'accept-encoding' value=69 64 65 6e 74 69 74 79 2c 67 7a 69 70 'identity,gzip'} SEND_MESSAGE:flags=0x00000000:len=105 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.419305971 113724 chttp2_transport.cc:1702] perform_stream_op[s=0x241b828]: SEND_INITIAL_METADATA{key=3a 73 63 68 65 6d 65 ':scheme' value=68 74 74 70 'http', key=3a 6d 65 74 68 6f 64 ':method' value=50 4f 53 54 'POST', key=3a 61 75 74 68 6f 72 69 74 79 ':authority' value=31 32 37 2e 30 2e 30 2e 31 3a 39 33 33 39 '127.0.0.1:9339', key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set', key=74 65 'te' value=74 72 61 69 6c 65 72 73 'trailers', key=63 6f 6e 74 65 6e 74 2d 74 79 70 65 'content-type' value=61 70 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 'application/grpc', key=75 73 65 72 2d 61 67 65 6e 74 'user-agent' value=67 72 70 63 2d 63 2b 2b 2f 31 2e 31 37 2e 31 20 67 72 70 63 2d 63 2f 37 2e 30 2e 30 20 28 6c 69 6e 75 78 3b 20 63 68 74 74 70 32 3b 20 67 69 7a 6d 6f 29 'grpc-c++/1.17.1 grpc-c/7.0.0 (linux; chttp2; gizmo)', key=67 72 70 63 2d 61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'grpc-accept-encoding' value=69 64 65 6e 74 69 74 79 2c 64 65 66 6c 61 74 65 2c 67 7a 69 70 'identity,deflate,gzip', key=61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'accept-encoding' value=69 64 65 6e 74 69 74 79 2c 67 7a 69 70 'identity,gzip'} SEND_MESSAGE:flags=0x00000000:len=105 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.419317326 113724 call_combiner.cc:106] ==> grpc_call_combiner_stop() [0x2419db0] [passed batch to transport]
I1214 06:07:13.419323308 113724 call_combiner.cc:113] size: 1 -> 0
I1214 06:07:13.419327477 113724 call_combiner.cc:141] queue empty
I1214 06:07:13.419352234 113724 chttp2_transport.cc:1398] perform_stream_op_locked: SEND_INITIAL_METADATA{key=3a 73 63 68 65 6d 65 ':scheme' value=68 74 74 70 'http', key=3a 6d 65 74 68 6f 64 ':method' value=50 4f 53 54 'POST', key=3a 61 75 74 68 6f 72 69 74 79 ':authority' value=31 32 37 2e 30 2e 30 2e 31 3a 39 33 33 39 '127.0.0.1:9339', key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set', key=74 65 'te' value=74 72 61 69 6c 65 72 73 'trailers', key=63 6f 6e 74 65 6e 74 2d 74 79 70 65 'content-type' value=61 70 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 'application/grpc', key=75 73 65 72 2d 61 67 65 6e 74 'user-agent' value=67 72 70 63 2d 63 2b 2b 2f 31 2e 31 37 2e 31 20 67 72 70 63 2d 63 2f 37 2e 30 2e 30 20 28 6c 69 6e 75 78 3b 20 63 68 74 74 70 32 3b 20 67 69 7a 6d 6f 29 'grpc-c++/1.17.1 grpc-c/7.0.0 (linux; chttp2; gizmo)', key=67 72 70 63 2d 61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'grpc-accept-encoding' value=69 64 65 6e 74 69 74 79 2c 64 65 66 6c 61 74 65 2c 67 7a 69 70 'identity,deflate,gzip', key=61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'accept-encoding' value=69 64 65 6e 74 69 74 79 2c 67 7a 69 70 'identity,gzip'} SEND_MESSAGE:flags=0x00000000:len=105 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA; on_complete = 0x241b5e8
I1214 06:07:13.419363699 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: :scheme: http
I1214 06:07:13.419370265 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: :method: POST
I1214 06:07:13.419376307 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: :authority: 127.0.0.1:9339
I1214 06:07:13.419383248 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: :path: /gnmi.gNMI/Set
I1214 06:07:13.419388857 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: te: trailers
I1214 06:07:13.419395176 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: content-type: application/grpc
I1214 06:07:13.419400900 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: user-agent: grpc-c++/1.17.1 grpc-c/7.0.0 (linux; chttp2; gizmo)
I1214 06:07:13.419409311 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: grpc-accept-encoding: identity,deflate,gzip
I1214 06:07:13.419415553 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: accept-encoding: identity,gzip
I1214 06:07:13.419422570 113724 stream_lists.cc:125] 0x7f21e4006400[0][cli]: add to waiting_for_concurrency
I1214 06:07:13.419429111 113724 stream_lists.cc:71] 0x7f21e4006400[0][cli]: pop from waiting_for_concurrency
I1214 06:07:13.419435905 113724 chttp2_transport.cc:1186] HTTP:CLI: Allocating new grpc_chttp2_stream 0x241b828 to id 7
I1214 06:07:13.419442577 113724 stream_lists.cc:125] 0x7f21e4006400[7][cli]: add to writable
I1214 06:07:13.419449177 113724 chttp2_transport.cc:849] W:0x7f21e4006400 CLIENT state IDLE -> WRITING [START_NEW_STREAM]
I1214 06:07:13.419456795 113724 chttp2_transport.cc:849] W:0x7f21e4006400 CLIENT state WRITING -> WRITING+MORE [SEND_MESSAGE]
D1214 06:07:13.419466930 113724 flow_control.cc:113] 0x7f21e4007a48[7][cli] | app st recv | trw: 4194304, ttw: 4194304, taw: 4194211, srw: 4194304, slw: 4194304 -> 4194309, saw: 4194304
I1214 06:07:13.419476549 113724 chttp2_transport.cc:1249] complete_closure_step: t=0x7f21e4006400 0x241b5e8 refs=3 flags=0x0001 desc=op->on_complete err="No Error" write_state=WRITING+MORE
I1214 06:07:13.419483916 113724 stream_lists.cc:71] 0x7f21e4006400[7][cli]: pop from writable
I1214 06:07:13.419490445 113724 writing.cc:409] W:0x7f21e4006400 CLIENT[7] im-(sent,send)=(0,1) announce=5
I1214 06:07:13.419497816 113724 hpack_encoder.cc:473] Encode: ':authority: 127.0.0.1:9339', elem_interned=1 [1], k_interned=1, v_interned=1
I1214 06:07:13.419504752 113724 hpack_encoder.cc:473] Encode: ':path: /gnmi.gNMI/Set', elem_interned=1 [1], k_interned=1, v_interned=1
I1214 06:07:13.419511263 113724 hpack_encoder.cc:473] Encode: 'te: trailers', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.419517895 113724 hpack_encoder.cc:473] Encode: 'content-type: application/grpc', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.419524597 113724 hpack_encoder.cc:473] Encode: 'user-agent: grpc-c++/1.17.1 grpc-c/7.0.0 (linux; chttp2; gizmo)', elem_interned=1 [1], k_interned=1, v_interned=1
I1214 06:07:13.419531996 113724 hpack_encoder.cc:473] Encode: 'grpc-accept-encoding: identity,deflate,gzip', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.419539561 113724 hpack_encoder.cc:473] Encode: 'accept-encoding: identity,gzip', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.419546478 113724 chttp2_transport.cc:1249] complete_closure_step: t=0x7f21e4006400 0x241b5e8 refs=2 flags=0x0001 desc=send_initial_metadata_finished err="No Error" write_state=WRITING+MORE
D1214 06:07:13.419554576 113724 flow_control.cc:113] 0x7f21e4007a48[7][cli] | s updt sent | trw: 4194304, ttw: 4194304 -> 4194309, taw: 4194211, srw: 4194304, slw: 4194309, saw: 4194304 -> 4194309
D1214 06:07:13.419565297 113724 flow_control.cc:113] 0x7f21e4007a48[7][cli] | data sent | trw: 4194304 -> 4194194, ttw: 4194309, taw: 4194211, srw: 4194304 -> 4194194, slw: 4194309, saw: 4194309
I1214 06:07:13.419573959 113724 chttp2_transport.cc:1249] complete_closure_step: t=0x7f21e4006400 0x241b5e8 refs=1 flags=0x0001 desc=send_trailing_metadata_finished err="No Error" write_state=WRITING+MORE
I1214 06:07:13.419581569 113724 chttp2_transport.cc:1249] complete_closure_step: t=0x7f21e4006400 0x241b5e8 refs=0 flags=0x0001 desc=on_write_finished_cb err="No Error" write_state=WRITING+MORE
I1214 06:07:13.419588258 113724 stream_lists.cc:125] 0x7f21e4006400[7][cli]: add to writing
D1214 06:07:13.419595719 113724 flow_control.cc:113] 0x7f21e4007a48[0][cli] | t updt sent | trw: 4194194, ttw: 4194309, taw: 4194211 -> 4194309, srw: , slw: , saw:
I1214 06:07:13.419603353 113724 chttp2_transport.cc:849] W:0x7f21e4006400 CLIENT state WRITING+MORE -> WRITING [begin write in current thread]
I1214 06:07:13.419611001 113724 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 00 00 09 01 04 00 00 00 07 86 83 c4 c3 c2 c1 c0 bf be 00 00 04 08 00 '.......................'
I1214 06:07:13.419618460 113724 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 00 00 00 07 00 00 00 05 00 00 6e 00 01 00 00 00 07 00 00 00 00 69 '..........n..........i'
I1214 06:07:13.419626375 113724 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 22 67 0a 50 1a 0c 0a 0a 69 6e 74 65 72 66 61 63 65 73 1a 27 0a 11 76 69 72 74 75 61 6c 2d 69 6e 74 65 72 66 61 63 65 12 12 0a 04 6e 61 6d 65 12 0a 6e 65 74 5f 76 68 6f 73 74 30 1a 08 0a 06 63 6f 6e 66 69 67 1a 0d 0a 0b 73 6f 63 6b 65 74 2d 70 61 74 68 1a 13 0a 11 2f 74 6d 70 2f 76 68 6f 73 74 2d 75 73 65 72 2d 30 '"g.P....interfaces.'..virtual-interface....name..net_vhost0....config....socket-path..../tmp/vhost-user-0'
I1214 06:07:13.419635262 113724 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 00 00 04 08 00 00 00 00 00 00 00 00 62 '............b'
I1214 06:07:13.419658437 113724 tcp_posix.cc:964] write: "No Error"
I1214 06:07:13.419665220 113724 chttp2_transport.cc:849] W:0x7f21e4006400 CLIENT state WRITING -> IDLE [finish writing]
I1214 06:07:13.419671714 113724 stream_lists.cc:71] 0x7f21e4006400[7][cli]: pop from writing
I1214 06:07:13.419678253 113724 call_combiner.cc:69] ==> grpc_call_combiner_start() [0x2419db0] closure=0x241ad10 [on_complete] error="No Error"
I1214 06:07:13.419684513 113724 call_combiner.cc:78] size: 0 -> 1
I1214 06:07:13.419690036 113724 call_combiner.cc:87] EXECUTING IMMEDIATELY
I1214 06:07:13.419695592 113724 call_combiner.cc:106] ==> grpc_call_combiner_stop() [0x2419db0] [on_complete]
I1214 06:07:13.419702163 113724 call_combiner.cc:113] size: 1 -> 0
I1214 06:07:13.419707930 113724 call_combiner.cc:141] queue empty
I1214 06:07:13.419715631 113724 completion_queue.cc:1198] grpc_completion_queue_pluck(cq=0x240d230, tag=0x7fff1c7609e0, deadline=gpr_timespec { tv_sec: 9223372036854775807, tv_nsec: 0, clock_type: 1 }, reserved=(nil))
I1214 06:07:13.419723992 113724 ev_epollex_linux.cc:1176] PS:0x240d330 work hdl=0x7fff1c7607a8 worker=0x7fff1c7606e0 now=14 deadline=9223372036854775807 kwp=0 pollable=0x241c700
I1214 06:07:13.419734987 113724 ev_epollex_linux.cc:994] POLLABLE:0x241c700[type=fd epfd=7 wakeup=8] poll for -1ms
I1214 06:07:13.420152341 113724 ev_epollex_linux.cc:1013] POLLABLE:0x241c700 got 1 events
I1214 06:07:13.420160055 113724 ev_epollex_linux.cc:961] PS:0x240d330 got fd 0x7f21e4003810: cancel=0 read=1 write=1
E1214 06:07:13.420165740 113724 lockfree_event.cc:213] LockfreeEvent::SetReady: 0x7f21e4003880 curr=0x7f21e4004400
E1214 06:07:13.420172075 113724 lockfree_event.cc:213] LockfreeEvent::SetReady: 0x7f21e4003888 curr=0x2
I1214 06:07:13.420179557 113724 tcp_posix.cc:521] TCP:0x7f21e4004260 got_read: "No Error"
I1214 06:07:13.420185436 113724 tcp_posix.cc:512] TCP:0x7f21e4004260 do_read
I1214 06:07:13.420196478 113724 tcp_posix.cc:397] TCP:0x7f21e4004260 call_cb 0x7f21e4006540 0x7f21f29e3d30:0x7f21e4006400
I1214 06:07:13.420202633 113724 tcp_posix.cc:400] read: error="No Error"
I1214 06:07:13.420212379 113724 tcp_posix.cc:405] READ 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 00 00 04 01 04 00 00 00 07 88 c1 c0 bf 00 00 67 00 00 00 00 00 07 00 00 00 00 62 0a 00 12 54 12 50 1a 0c 0a 0a 69 6e 74 65 72 66 61 63 65 73 1a 27 0a 11 76 69 72 74 75 61 6c 2d 69 6e 74 65 72 66 61 63 65 12 12 0a 04 6e 61 6d 65 12 0a 6e 65 74 5f 76 68 6f 73 74 30 1a 08 0a 06 63 6f 6e 66 69 67 1a 0d 0a 0b 73 6f 63 6b 65 74 2d 70 61 74 68 20 03 20 f7 f7 fb e5 87 c1 a2 e0 16 00 00 01 01 05 00 00 00 07 be 00 00 04 08 00 00 00 00 00 00 00 00 6e '...............g..........b...T.P....interfaces.'..virtual-interface....name..net_vhost0....config....socket-path . ...............................n'
I1214 06:07:13.420221355 113724 parsing.cc:656] parsing initial_metadata
I1214 06:07:13.420228291 113724 hpack_parser.cc:636] Decode: ':status: 200', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.420233437 113724 parsing.cc:407] HTTP:7:HDR:CLI: :status: 32 30 30 '200'
I1214 06:07:13.420240196 113724 hpack_parser.cc:636] Decode: 'content-type: application/grpc', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.420247109 113724 parsing.cc:407] HTTP:7:HDR:CLI: content-type: 61 70 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 'application/grpc'
I1214 06:07:13.420254170 113724 hpack_parser.cc:636] Decode: 'grpc-accept-encoding: identity,deflate,gzip', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.420261271 113724 parsing.cc:407] HTTP:7:HDR:CLI: grpc-accept-encoding: 69 64 65 6e 74 69 74 79 2c 64 65 66 6c 61 74 65 2c 67 7a 69 70 'identity,deflate,gzip'
I1214 06:07:13.420268210 113724 hpack_parser.cc:636] Decode: 'accept-encoding: identity,gzip', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.420274776 113724 parsing.cc:407] HTTP:7:HDR:CLI: accept-encoding: 69 64 65 6e 74 69 74 79 2c 67 7a 69 70 'identity,gzip'
I1214 06:07:13.420282033 113724 call_combiner.cc:69] ==> grpc_call_combiner_start() [0x2419db0] closure=0x241b010 [recv_initial_metadata_ready] error="No Error"
I1214 06:07:13.420289368 113724 call_combiner.cc:78] size: 0 -> 1
I1214 06:07:13.420294929 113724 call_combiner.cc:87] EXECUTING IMMEDIATELY
D1214 06:07:13.420303500 113724 flow_control.cc:113] 0x7f21e4007a48[7][cli] | data recv | trw: 4194194, ttw: 4194309 -> 4194304, taw: 4194309 -> 4194206, srw: 4194194, slw: 4194309 -> 4194206, saw: 4194309 -> 4194206
I1214 06:07:13.420312738 113724 call_combiner.cc:69] ==> grpc_call_combiner_start() [0x2419db0] closure=0x241aeb0 [recv_message_ready] error="No Error"
I1214 06:07:13.420319926 113724 call_combiner.cc:78] size: 1 -> 2
I1214 06:07:13.420325236 113724 call_combiner.cc:93] QUEUING
I1214 06:07:13.420331498 113724 parsing.cc:661] parsing trailing_metadata
I1214 06:07:13.420337342 113724 hpack_parser.cc:636] Decode: 'grpc-status: 0', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.420345038 113724 parsing.cc:503] HTTP:7:TRL:CLI: grpc-status: 30 '0'
D1214 06:07:13.420354332 113724 flow_control.cc:113] 0x7f21e4007a48[0][cli] | t updt recv | trw: 4194194 -> 4194304, ttw: 4194304, taw: 4194206, srw: , slw: , saw:
I1214 06:07:13.420362709 113724 call_combiner.cc:106] ==> grpc_call_combiner_stop() [0x2419db0] [recv_initial_metadata_ready]
I1214 06:07:13.420372813 113724 call_combiner.cc:113] size: 2 -> 1
I1214 06:07:13.420378225 113724 call_combiner.cc:120] checking queue
I1214 06:07:13.420383903 113724 call_combiner.cc:134] EXECUTING FROM QUEUE: closure=0x241aeb0 error="No Error"
I1214 06:07:13.420391151 113724 tcp_posix.cc:521] TCP:0x7f21e4004260 got_read: "No Error"
I1214 06:07:13.420397086 113724 tcp_posix.cc:512] TCP:0x7f21e4004260 do_read
I1214 06:07:13.420404251 113724 tcp_posix.cc:252] TCP:0x7f21e4004260 notify_on_read
E1214 06:07:13.420410612 113724 lockfree_event.cc:98] LockfreeEvent::NotifyOn: 0x7f21e4003880 curr=(nil) closure=0x7f21e4004400
I1214 06:07:13.420417382 113724 call_combiner.cc:106] ==> grpc_call_combiner_stop() [0x2419db0] [recv_message_ready]
I1214 06:07:13.420423574 113724 call_combiner.cc:113] size: 1 -> 0
I1214 06:07:13.420428947 113724 call_combiner.cc:141] queue empty
I1214 06:07:13.420437404 113724 call_combiner.cc:69] ==> grpc_call_combiner_start() [0x2419db0] closure=0x241b048 [recv_trailing_metadata_ready] error="No Error"
I1214 06:07:13.420443483 113724 call_combiner.cc:78] size: 0 -> 1
I1214 06:07:13.420448598 113724 call_combiner.cc:87] EXECUTING IMMEDIATELY
I1214 06:07:13.420456451 113724 call_combiner.cc:106] ==> grpc_call_combiner_stop() [0x2419db0] [recv_trailing_metadata_ready]
I1214 06:07:13.420462379 113724 call_combiner.cc:113] size: 1 -> 0
I1214 06:07:13.420467906 113724 call_combiner.cc:141] queue empty
D1214 06:07:13.420473623 113724 call.cc:719] set_final_status CLI
D1214 06:07:13.420479342 113724 call.cc:720] "No Error"
I1214 06:07:13.420487110 113724 completion_queue.cc:779] cq_end_op_for_pluck(cq=0x240d230, tag=0x7fff1c7609e0, error="No Error", done=0x7f21f29cd6f0, done_arg=0x241ac70, storage=0x241acc0)
I1214 06:07:13.420494500 113724 ev_epollex_linux.cc:788] PS:0x240d330 kick 0x7fff1c7606e0 tls_pollset=0x240d330 tls_worker=0x7fff1c7606e0 pollset.root_worker=0x7fff1c7606e0
I1214 06:07:13.420500530 113724 ev_epollex_linux.cc:754] PS:0x241c700 kicked_specific_but_awake
I1214 06:07:13.420508194 113724 ev_epollex_linux.cc:722] PS:0x240d330 (pollable:0x241c700) maybe_finish_shutdown sc=(nil) (target:!NULL) rw=(nil) (target:NULL) cpsc=0 (target:0)
I1214 06:07:13.420516205 113724 completion_queue.cc:1299] RETURN_EVENT[0x240d230]: OP_COMPLETE: tag:0x7fff1c7609e0 OK
I1214 06:07:13.420531730 113724 completion_queue.cc:1395] grpc_completion_queue_destroy(cq=0x240d230)
I1214 06:07:13.420537962 113724 completion_queue.cc:1389] grpc_completion_queue_shutdown(cq=0x240d230)
I1214 06:07:13.420544211 113724 ev_epollex_linux.cc:722] PS:0x240d330 (pollable:0x241c700) maybe_finish_shutdown sc=0x240d250 (target:!NULL) rw=(nil) (target:NULL) cpsc=0 (target:0)
I1214 06:07:13.420551029 113724 init.cc:159] grpc_shutdown(void)
I1214 06:07:13.420561645 113724 call.cc:561] grpc_call_unref(c=0x2419da0)
I1214 06:07:13.420567737 113724 call_combiner.cc:167] call_combiner=0x2419db0: setting notify_on_cancel=(nil)
I1214 06:07:13.420577316 113724 metadata_array.cc:34] grpc_metadata_array_destroy(array=0x7fff1c761150)
I1214 06:07:13.420583647 113724 metadata_array.cc:34] grpc_metadata_array_destroy(array=0x7fff1c761100)
I1214 06:07:13.420592814 113724 channel.cc:376] grpc_channel_register_call(channel=0x240aa20, method=/gnmi.gNMI/Capabilities, host=(null), reserved=(nil))
I1214 06:07:13.420600777 113724 channel.cc:376] grpc_channel_register_call(channel=0x240aa20, method=/gnmi.gNMI/Get, host=(null), reserved=(nil))
I1214 06:07:13.420611351 113724 channel.cc:376] grpc_channel_register_call(channel=0x240aa20, method=/gnmi.gNMI/Set, host=(null), reserved=(nil))
I1214 06:07:13.420618184 113724 channel.cc:376] grpc_channel_register_call(channel=0x240aa20, method=/gnmi.gNMI/Subscribe, host=(null), reserved=(nil))
I1214 06:07:13.420951914 113724 init.cc:154] grpc_init(void)
I1214 06:07:13.420959649 113724 completion_queue.cc:478] grpc_completion_queue_create_internal(completion_type=1, polling_type=0)
I1214 06:07:13.420969014 113724 channel.cc:403] grpc_channel_create_registered_call(channel=0x240aa20, parent_call=(nil), propagation_mask=ffff, completion_queue=0x2421bc0, registered_call_handle=0x240ae00, deadline=gpr_timespec { tv_sec: 9223372036854775807, tv_nsec: 0, clock_type: 1 }, reserved=(nil))
I1214 06:07:13.420979343 113724 grpc_context.cc:27] grpc_census_call_set_context(call=0x2419da0, census_context=(nil))
I1214 06:07:13.420992685 113724 call.cc:1900] grpc_call_start_batch(call=0x2419da0, ops=0x7fff1c7606c0, nops=6, tag=0x7fff1c7609e0, reserved=(nil))
I1214 06:07:13.420999801 113724 call.cc:1508] ops[0]: SEND_INITIAL_METADATA(nil)
I1214 06:07:13.421005484 113724 call.cc:1508] ops[1]: SEND_MESSAGE ptr=0x241d4d0
I1214 06:07:13.421013263 113724 call.cc:1508] ops[2]: RECV_INITIAL_METADATA ptr=0x7fff1c761100
I1214 06:07:13.421019512 113724 call.cc:1508] ops[3]: RECV_MESSAGE ptr=0x7fff1c760a48
I1214 06:07:13.421024932 113724 call.cc:1508] ops[4]: SEND_CLOSE_FROM_CLIENT
I1214 06:07:13.421033085 113724 call.cc:1508] ops[5]: RECV_STATUS_ON_CLIENT metadata=0x7fff1c761150 status=0x7fff1c760a80 details=0x7fff1c760a88
I1214 06:07:13.421041209 113724 call_combiner.cc:69] ==> grpc_call_combiner_start() [0x2419db0] closure=0x241ace8 [executing batch] error="No Error"
I1214 06:07:13.421047399 113724 call_combiner.cc:78] size: 0 -> 1
I1214 06:07:13.421053004 113724 call_combiner.cc:87] EXECUTING IMMEDIATELY
I1214 06:07:13.421064884 113724 call.cc:613] OP[client-channel:0x241a720]: SEND_INITIAL_METADATA{key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set'} SEND_MESSAGE:flags=0x00000000:len=90 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.421072439 113724 client_channel.cc:1204] chand=0x240aae8 calld=0x241a740: adding pending batch at index 0
I1214 06:07:13.421079536 113724 client_channel.cc:3197] chand=0x240aae8 calld=0x241a740: entering client_channel combiner
I1214 06:07:13.421086068 113724 client_channel.cc:2855] chand=0x240aae8 calld=0x241a740: applying service config to call
I1214 06:07:13.421092424 113724 connectivity_state.cc:81] CONWATCH: 0x240ab70 client_channel: get READY
I1214 06:07:13.421099154 113724 client_channel.cc:2763] chand=0x240aae8 calld=0x241a740: starting pick on lb_policy=0x7f21e4001430
I1214 06:07:13.421105245 113724 client_channel.cc:2790] chand=0x240aae8 calld=0x241a740: pick completed synchronously
I1214 06:07:13.421114618 113724 ev_epollex_linux.cc:1217] PS:0x2421cc0 add fd 0x7f21e4003810 (9); transition pollable from empty to fd
I1214 06:07:13.421121734 113724 client_channel.cc:2669] chand=0x240aae8 calld=0x241a740: create subchannel_call=0x241ad50: error="No Error"
I1214 06:07:13.421132320 113724 client_channel.cc:1346] chand=0x240aae8 calld=0x241a740: starting 1 pending batches on subchannel_call=0x241ad50
I1214 06:07:13.421139088 113724 call_combiner.h:153] CallCombinerClosureList executing closure while already holding call_combiner 0x2419db0: closure=0x241ac98 error="No Error" reason=pending_batches_resume
I1214 06:07:13.421151035 113724 subchannel.cc:1000] OP[authority:0x241adf0]: SEND_INITIAL_METADATA{key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set'} SEND_MESSAGE:flags=0x00000000:len=90 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.421165281 113724 channel_stack.cc:226] OP[message_size:0x241ae08]: SEND_INITIAL_METADATA{key=3a 61 75 74 68 6f 72 69 74 79 ':authority' value=31 32 37 2e 30 2e 30 2e 31 3a 39 33 33 39 '127.0.0.1:9339', key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set'} SEND_MESSAGE:flags=0x00000000:len=90 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.421182253 113724 channel_stack.cc:226] OP[http-client:0x241ae20]: SEND_INITIAL_METADATA{key=3a 61 75 74 68 6f 72 69 74 79 ':authority' value=31 32 37 2e 30 2e 30 2e 31 3a 39 33 33 39 '127.0.0.1:9339', key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set'} SEND_MESSAGE:flags=0x00000000:len=90 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.421206215 113724 channel_stack.cc:226] OP[message_compress:0x241ae38]: SEND_INITIAL_METADATA{key=3a 73 63 68 65 6d 65 ':scheme' value=68 74 74 70 'http', key=3a 6d 65 74 68 6f 64 ':method' value=50 4f 53 54 'POST', key=3a 61 75 74 68 6f 72 69 74 79 ':authority' value=31 32 37 2e 30 2e 30 2e 31 3a 39 33 33 39 '127.0.0.1:9339', key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set', key=74 65 'te' value=74 72 61 69 6c 65 72 73 'trailers', key=63 6f 6e 74 65 6e 74 2d 74 79 70 65 'content-type' value=61 70 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 'application/grpc', key=75 73 65 72 2d 61 67 65 6e 74 'user-agent' value=67 72 70 63 2d 63 2b 2b 2f 31 2e 31 37 2e 31 20 67 72 70 63 2d 63 2f 37 2e 30 2e 30 20 28 6c 69 6e 75 78 3b 20 63 68 74 74 70 32 3b 20 67 69 7a 6d 6f 29 'grpc-c++/1.17.1 grpc-c/7.0.0 (linux; chttp2; gizmo)'} SEND_MESSAGE:flags=0x00000000:len=90 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.421239932 113724 channel_stack.cc:226] OP[connected:0x241ae50]: SEND_INITIAL_METADATA{key=3a 73 63 68 65 6d 65 ':scheme' value=68 74 74 70 'http', key=3a 6d 65 74 68 6f 64 ':method' value=50 4f 53 54 'POST', key=3a 61 75 74 68 6f 72 69 74 79 ':authority' value=31 32 37 2e 30 2e 30 2e 31 3a 39 33 33 39 '127.0.0.1:9339', key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set', key=74 65 'te' value=74 72 61 69 6c 65 72 73 'trailers', key=63 6f 6e 74 65 6e 74 2d 74 79 70 65 'content-type' value=61 70 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 'application/grpc', key=75 73 65 72 2d 61 67 65 6e 74 'user-agent' value=67 72 70 63 2d 63 2b 2b 2f 31 2e 31 37 2e 31 20 67 72 70 63 2d 63 2f 37 2e 30 2e 30 20 28 6c 69 6e 75 78 3b 20 63 68 74 74 70 32 3b 20 67 69 7a 6d 6f 29 'grpc-c++/1.17.1 grpc-c/7.0.0 (linux; chttp2; gizmo)', key=67 72 70 63 2d 61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'grpc-accept-encoding' value=69 64 65 6e 74 69 74 79 2c 64 65 66 6c 61 74 65 2c 67 7a 69 70 'identity,deflate,gzip', key=61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'accept-encoding' value=69 64 65 6e 74 69 74 79 2c 67 7a 69 70 'identity,gzip'} SEND_MESSAGE:flags=0x00000000:len=90 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.421268338 113724 chttp2_transport.cc:1702] perform_stream_op[s=0x241b828]: SEND_INITIAL_METADATA{key=3a 73 63 68 65 6d 65 ':scheme' value=68 74 74 70 'http', key=3a 6d 65 74 68 6f 64 ':method' value=50 4f 53 54 'POST', key=3a 61 75 74 68 6f 72 69 74 79 ':authority' value=31 32 37 2e 30 2e 30 2e 31 3a 39 33 33 39 '127.0.0.1:9339', key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set', key=74 65 'te' value=74 72 61 69 6c 65 72 73 'trailers', key=63 6f 6e 74 65 6e 74 2d 74 79 70 65 'content-type' value=61 70 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 'application/grpc', key=75 73 65 72 2d 61 67 65 6e 74 'user-agent' value=67 72 70 63 2d 63 2b 2b 2f 31 2e 31 37 2e 31 20 67 72 70 63 2d 63 2f 37 2e 30 2e 30 20 28 6c 69 6e 75 78 3b 20 63 68 74 74 70 32 3b 20 67 69 7a 6d 6f 29 'grpc-c++/1.17.1 grpc-c/7.0.0 (linux; chttp2; gizmo)', key=67 72 70 63 2d 61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'grpc-accept-encoding' value=69 64 65 6e 74 69 74 79 2c 64 65 66 6c 61 74 65 2c 67 7a 69 70 'identity,deflate,gzip', key=61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'accept-encoding' value=69 64 65 6e 74 69 74 79 2c 67 7a 69 70 'identity,gzip'} SEND_MESSAGE:flags=0x00000000:len=90 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA
I1214 06:07:13.421279346 113724 call_combiner.cc:106] ==> grpc_call_combiner_stop() [0x2419db0] [passed batch to transport]
I1214 06:07:13.421285817 113724 call_combiner.cc:113] size: 1 -> 0
I1214 06:07:13.421291323 113724 call_combiner.cc:141] queue empty
I1214 06:07:13.421315312 113724 chttp2_transport.cc:1398] perform_stream_op_locked: SEND_INITIAL_METADATA{key=3a 73 63 68 65 6d 65 ':scheme' value=68 74 74 70 'http', key=3a 6d 65 74 68 6f 64 ':method' value=50 4f 53 54 'POST', key=3a 61 75 74 68 6f 72 69 74 79 ':authority' value=31 32 37 2e 30 2e 30 2e 31 3a 39 33 33 39 '127.0.0.1:9339', key=3a 70 61 74 68 ':path' value=2f 67 6e 6d 69 2e 67 4e 4d 49 2f 53 65 74 '/gnmi.gNMI/Set', key=74 65 'te' value=74 72 61 69 6c 65 72 73 'trailers', key=63 6f 6e 74 65 6e 74 2d 74 79 70 65 'content-type' value=61 70 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 'application/grpc', key=75 73 65 72 2d 61 67 65 6e 74 'user-agent' value=67 72 70 63 2d 63 2b 2b 2f 31 2e 31 37 2e 31 20 67 72 70 63 2d 63 2f 37 2e 30 2e 30 20 28 6c 69 6e 75 78 3b 20 63 68 74 74 70 32 3b 20 67 69 7a 6d 6f 29 'grpc-c++/1.17.1 grpc-c/7.0.0 (linux; chttp2; gizmo)', key=67 72 70 63 2d 61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'grpc-accept-encoding' value=69 64 65 6e 74 69 74 79 2c 64 65 66 6c 61 74 65 2c 67 7a 69 70 'identity,deflate,gzip', key=61 63 63 65 70 74 2d 65 6e 63 6f 64 69 6e 67 'accept-encoding' value=69 64 65 6e 74 69 74 79 2c 67 7a 69 70 'identity,gzip'} SEND_MESSAGE:flags=0x00000000:len=90 SEND_TRAILING_METADATA{} RECV_INITIAL_METADATA RECV_MESSAGE RECV_TRAILING_METADATA; on_complete = 0x241b5e8
I1214 06:07:13.421326719 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: :scheme: http
I1214 06:07:13.421332534 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: :method: POST
I1214 06:07:13.421338461 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: :authority: 127.0.0.1:9339
I1214 06:07:13.421344455 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: :path: /gnmi.gNMI/Set
I1214 06:07:13.421350419 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: te: trailers
I1214 06:07:13.421355960 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: content-type: application/grpc
I1214 06:07:13.421362457 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: user-agent: grpc-c++/1.17.1 grpc-c/7.0.0 (linux; chttp2; gizmo)
I1214 06:07:13.421368561 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: grpc-accept-encoding: identity,deflate,gzip
I1214 06:07:13.421374809 113724 chttp2_transport.cc:1376] HTTP:0:HDR:CLI: accept-encoding: identity,gzip
I1214 06:07:13.421382252 113724 stream_lists.cc:125] 0x7f21e4006400[0][cli]: add to waiting_for_concurrency
I1214 06:07:13.421388957 113724 stream_lists.cc:71] 0x7f21e4006400[0][cli]: pop from waiting_for_concurrency
I1214 06:07:13.421396204 113724 chttp2_transport.cc:1186] HTTP:CLI: Allocating new grpc_chttp2_stream 0x241b828 to id 9
I1214 06:07:13.421402601 113724 stream_lists.cc:125] 0x7f21e4006400[9][cli]: add to writable
I1214 06:07:13.421409669 113724 chttp2_transport.cc:849] W:0x7f21e4006400 CLIENT state IDLE -> WRITING [START_NEW_STREAM]
I1214 06:07:13.421416857 113724 chttp2_transport.cc:849] W:0x7f21e4006400 CLIENT state WRITING -> WRITING+MORE [SEND_MESSAGE]
D1214 06:07:13.421426542 113724 flow_control.cc:113] 0x7f21e4007a48[9][cli] | app st recv | trw: 4194304, ttw: 4194304, taw: 4194206, srw: 4194304, slw: 4194304 -> 4194309, saw: 4194304
I1214 06:07:13.421435734 113724 chttp2_transport.cc:1249] complete_closure_step: t=0x7f21e4006400 0x241b5e8 refs=3 flags=0x0001 desc=op->on_complete err="No Error" write_state=WRITING+MORE
I1214 06:07:13.421444695 113724 stream_lists.cc:71] 0x7f21e4006400[9][cli]: pop from writable
I1214 06:07:13.421451306 113724 writing.cc:409] W:0x7f21e4006400 CLIENT[9] im-(sent,send)=(0,1) announce=5
I1214 06:07:13.421458727 113724 hpack_encoder.cc:473] Encode: ':authority: 127.0.0.1:9339', elem_interned=1 [1], k_interned=1, v_interned=1
I1214 06:07:13.421465291 113724 hpack_encoder.cc:473] Encode: ':path: /gnmi.gNMI/Set', elem_interned=1 [1], k_interned=1, v_interned=1
I1214 06:07:13.421474162 113724 hpack_encoder.cc:473] Encode: 'te: trailers', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.421481321 113724 hpack_encoder.cc:473] Encode: 'content-type: application/grpc', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.421488508 113724 hpack_encoder.cc:473] Encode: 'user-agent: grpc-c++/1.17.1 grpc-c/7.0.0 (linux; chttp2; gizmo)', elem_interned=1 [1], k_interned=1, v_interned=1
I1214 06:07:13.421495501 113724 hpack_encoder.cc:473] Encode: 'grpc-accept-encoding: identity,deflate,gzip', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.421502130 113724 hpack_encoder.cc:473] Encode: 'accept-encoding: identity,gzip', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.421509519 113724 chttp2_transport.cc:1249] complete_closure_step: t=0x7f21e4006400 0x241b5e8 refs=2 flags=0x0001 desc=send_initial_metadata_finished err="No Error" write_state=WRITING+MORE
D1214 06:07:13.421518718 113724 flow_control.cc:113] 0x7f21e4007a48[9][cli] | s updt sent | trw: 4194304, ttw: 4194304 -> 4194309, taw: 4194206, srw: 4194304, slw: 4194309, saw: 4194304 -> 4194309
D1214 06:07:13.421529492 113724 flow_control.cc:113] 0x7f21e4007a48[9][cli] | data sent | trw: 4194304 -> 4194209, ttw: 4194309, taw: 4194206, srw: 4194304 -> 4194209, slw: 4194309, saw: 4194309
I1214 06:07:13.421537577 113724 chttp2_transport.cc:1249] complete_closure_step: t=0x7f21e4006400 0x241b5e8 refs=1 flags=0x0001 desc=send_trailing_metadata_finished err="No Error" write_state=WRITING+MORE
I1214 06:07:13.421544760 113724 chttp2_transport.cc:1249] complete_closure_step: t=0x7f21e4006400 0x241b5e8 refs=0 flags=0x0001 desc=on_write_finished_cb err="No Error" write_state=WRITING+MORE
I1214 06:07:13.421552415 113724 stream_lists.cc:125] 0x7f21e4006400[9][cli]: add to writing
D1214 06:07:13.421560509 113724 flow_control.cc:113] 0x7f21e4007a48[0][cli] | t updt sent | trw: 4194209, ttw: 4194309, taw: 4194206 -> 4194309, srw: , slw: , saw:
I1214 06:07:13.421568732 113724 chttp2_transport.cc:849] W:0x7f21e4006400 CLIENT state WRITING+MORE -> WRITING [begin write in current thread]
I1214 06:07:13.421577353 113724 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 00 00 09 01 04 00 00 00 09 86 83 c4 c3 c2 c1 c0 bf be 00 00 04 08 00 '.......................'
I1214 06:07:13.421584708 113724 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 00 00 00 09 00 00 00 05 00 00 5f 00 01 00 00 00 09 00 00 00 00 5a '.........._..........Z'
I1214 06:07:13.421592748 113724 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 22 58 0a 4e 1a 0c 0a 0a 69 6e 74 65 72 66 61 63 65 73 1a 27 0a 11 76 69 72 74 75 61 6c 2d 69 6e 74 65 72 66 61 63 65 12 12 0a 04 6e 61 6d 65 12 0a 6e 65 74 5f 76 68 6f 73 74 30 1a 08 0a 06 63 6f 6e 66 69 67 1a 0b 0a 09 70 6f 72 74 2d 74 79 70 65 1a 06 0a 04 4c 49 4e 4b '"X.N....interfaces.'..virtual-interface....name..net_vhost0....config....port-type....LINK'
I1214 06:07:13.421601487 113724 tcp_posix.cc:932] WRITE 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 00 00 04 08 00 00 00 00 00 00 00 00 67 '............g'
I1214 06:07:13.421625717 113724 tcp_posix.cc:964] write: "No Error"
I1214 06:07:13.421632914 113724 chttp2_transport.cc:849] W:0x7f21e4006400 CLIENT state WRITING -> IDLE [finish writing]
I1214 06:07:13.421639917 113724 stream_lists.cc:71] 0x7f21e4006400[9][cli]: pop from writing
I1214 06:07:13.421647469 113724 call_combiner.cc:69] ==> grpc_call_combiner_start() [0x2419db0] closure=0x241ad10 [on_complete] error="No Error"
I1214 06:07:13.421653986 113724 call_combiner.cc:78] size: 0 -> 1
I1214 06:07:13.421659310 113724 call_combiner.cc:87] EXECUTING IMMEDIATELY
I1214 06:07:13.421664263 113724 call_combiner.cc:106] ==> grpc_call_combiner_stop() [0x2419db0] [on_complete]
I1214 06:07:13.421670304 113724 call_combiner.cc:113] size: 1 -> 0
I1214 06:07:13.421676130 113724 call_combiner.cc:141] queue empty
I1214 06:07:13.421684381 113724 completion_queue.cc:1198] grpc_completion_queue_pluck(cq=0x2421bc0, tag=0x7fff1c7609e0, deadline=gpr_timespec { tv_sec: 9223372036854775807, tv_nsec: 0, clock_type: 1 }, reserved=(nil))
I1214 06:07:13.421692762 113724 ev_epollex_linux.cc:1176] PS:0x2421cc0 work hdl=0x7fff1c7607a8 worker=0x7fff1c7606e0 now=16 deadline=9223372036854775807 kwp=0 pollable=0x241c700
I1214 06:07:13.421700141 113724 ev_epollex_linux.cc:994] POLLABLE:0x241c700[type=fd epfd=7 wakeup=8] poll for -1ms
I1214 06:07:13.432535881 113724 ev_epollex_linux.cc:1013] POLLABLE:0x241c700 got 1 events
I1214 06:07:13.432543867 113724 ev_epollex_linux.cc:961] PS:0x2421cc0 got fd 0x7f21e4003810: cancel=0 read=1 write=1
E1214 06:07:13.432548904 113724 lockfree_event.cc:213] LockfreeEvent::SetReady: 0x7f21e4003880 curr=0x7f21e4004400
E1214 06:07:13.432554113 113724 lockfree_event.cc:213] LockfreeEvent::SetReady: 0x7f21e4003888 curr=0x2
I1214 06:07:13.432559507 113724 tcp_posix.cc:521] TCP:0x7f21e4004260 got_read: "No Error"
I1214 06:07:13.432564463 113724 tcp_posix.cc:512] TCP:0x7f21e4004260 do_read
I1214 06:07:13.432572570 113724 tcp_posix.cc:397] TCP:0x7f21e4004260 call_cb 0x7f21e4006540 0x7f21f29e3d30:0x7f21e4006400
I1214 06:07:13.432576799 113724 tcp_posix.cc:400] read: error="No Error"
I1214 06:07:13.432584198 113724 tcp_posix.cc:405] READ 0x7f21e4004260 (peer=ipv4:127.0.0.1:9339): 00 00 04 01 04 00 00 00 09 88 c1 c0 bf 00 00 65 00 00 00 00 00 09 00 00 00 00 60 0a 00 12 52 12 4e 1a 0c 0a 0a 69 6e 74 65 72 66 61 63 65 73 1a 27 0a 11 76 69 72 74 75 61 6c 2d 69 6e 74 65 72 66 61 63 65 12 12 0a 04 6e 61 6d 65 12 0a 6e 65 74 5f 76 68 6f 73 74 30 1a 08 0a 06 63 6f 6e 66 69 67 1a 0b 0a 09 70 6f 72 74 2d 74 79 70 65 20 03 20 95 de ee eb 87 c1 a2 e0 16 00 00 01 01 05 00 00 00 09 be 00 00 04 08 00 00 00 00 00 00 00 00 5f '...............e..........`...R.N....interfaces.'..virtual-interface....name..net_vhost0....config....port-type . ..............................._'
I1214 06:07:13.432591446 113724 parsing.cc:656] parsing initial_metadata
I1214 06:07:13.432596583 113724 hpack_parser.cc:636] Decode: ':status: 200', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.432601387 113724 parsing.cc:407] HTTP:9:HDR:CLI: :status: 32 30 30 '200'
I1214 06:07:13.432606315 113724 hpack_parser.cc:636] Decode: 'content-type: application/grpc', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.432612921 113724 parsing.cc:407] HTTP:9:HDR:CLI: content-type: 61 70 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 'application/grpc'
I1214 06:07:13.432618021 113724 hpack_parser.cc:636] Decode: 'grpc-accept-encoding: identity,deflate,gzip', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.432623470 113724 parsing.cc:407] HTTP:9:HDR:CLI: grpc-accept-encoding: 69 64 65 6e 74 69 74 79 2c 64 65 66 6c 61 74 65 2c 67 7a 69 70 'identity,deflate,gzip'
I1214 06:07:13.432664965 113724 hpack_parser.cc:636] Decode: 'accept-encoding: identity,gzip', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.432671284 113724 parsing.cc:407] HTTP:9:HDR:CLI: accept-encoding: 69 64 65 6e 74 69 74 79 2c 67 7a 69 70 'identity,gzip'
I1214 06:07:13.432676570 113724 call_combiner.cc:69] ==> grpc_call_combiner_start() [0x2419db0] closure=0x241b010 [recv_initial_metadata_ready] error="No Error"
I1214 06:07:13.432681109 113724 call_combiner.cc:78] size: 0 -> 1
I1214 06:07:13.432684642 113724 call_combiner.cc:87] EXECUTING IMMEDIATELY
D1214 06:07:13.432718667 113724 flow_control.cc:113] 0x7f21e4007a48[9][cli] | data recv | trw: 4194209, ttw: 4194309 -> 4194304, taw: 4194309 -> 4194208, srw: 4194209, slw: 4194309 -> 4194208, saw: 4194309 -> 4194208
I1214 06:07:13.432727519 113724 call_combiner.cc:69] ==> grpc_call_combiner_start() [0x2419db0] closure=0x241aeb0 [recv_message_ready] error="No Error"
I1214 06:07:13.432749569 113724 call_combiner.cc:78] size: 1 -> 2
I1214 06:07:13.432764171 113724 call_combiner.cc:93] QUEUING
I1214 06:07:13.432768199 113724 parsing.cc:661] parsing trailing_metadata
I1214 06:07:13.432800458 113724 hpack_parser.cc:636] Decode: 'grpc-status: 0', elem_interned=1 [3], k_interned=1, v_interned=1
I1214 06:07:13.432805297 113724 parsing.cc:503] HTTP:9:TRL:CLI: grpc-status: 30 '0'
D1214 06:07:13.432814213 113724 flow_control.cc:113] 0x7f21e4007a48[0][cli] | t updt recv | trw: 4194209 -> 4194304, ttw: 4194304, taw: 4194208, srw: , slw: , saw:
I1214 06:07:13.432822091 113724 call_combiner.cc:106] ==> grpc_call_combiner_stop() [0x2419db0] [recv_initial_metadata_ready]
I1214 06:07:13.432826332 113724 call_combiner.cc:113] size: 2 -> 1
I1214 06:07:13.432829911 113724 call_combiner.cc:120] checking queue
I1214 06:07:13.432833862 113724 call_combiner.cc:134] EXECUTING FROM QUEUE: closure=0x241aeb0 error="No Error"
I1214 06:07:13.432838846 113724 tcp_posix.cc:521] TCP:0x7f21e4004260 got_read: "No Error"
I1214 06:07:13.432867024 113724 tcp_posix.cc:512] TCP:0x7f21e4004260 do_read
I1214 06:07:13.432908602 113724 tcp_posix.cc:252] TCP:0x7f21e4004260 notify_on_read
E1214 06:07:13.432935797 113724 lockfree_event.cc:98] LockfreeEvent::NotifyOn: 0x7f21e4003880 curr=(nil) closure=0x7f21e4004400
I1214 06:07:13.432988005 113724 call_combiner.cc:106] ==> grpc_call_combiner_stop() [0x2419db0] [recv_message_ready]
I1214 06:07:13.432992244 113724 call_combiner.cc:113] size: 1 -> 0
I1214 06:07:13.432995886 113724 call_combiner.cc:141] queue empty
I1214 06:07:13.433035411 113724 call_combiner.cc:69] ==> grpc_call_combiner_start() [0x2419db0] closure=0x241b048 [recv_trailing_metadata_ready] error="No Error"
I1214 06:07:13.433041500 113724 call_combiner.cc:78] size: 0 -> 1
I1214 06:07:13.433047282 113724 call_combiner.cc:87] EXECUTING IMMEDIATELY
I1214 06:07:13.433051701 113724 call_combiner.cc:106] ==> grpc_call_combiner_stop() [0x2419db0] [recv_trailing_metadata_ready]
I1214 06:07:13.433055578 113724 call_combiner.cc:113] size: 1 -> 0
I1214 06:07:13.433059251 113724 call_combiner.cc:141] queue empty
D1214 06:07:13.433063003 113724 call.cc:719] set_final_status CLI
D1214 06:07:13.433070529 113724 call.cc:720] "No Error"
I1214 06:07:13.433091472 113724 completion_queue.cc:779] cq_end_op_for_pluck(cq=0x2421bc0, tag=0x7fff1c7609e0, error="No Error", done=0x7f21f29cd6f0, done_arg=0x241ac70, storage=0x241acc0)
I1214 06:07:13.433122609 113724 ev_epollex_linux.cc:788] PS:0x2421cc0 kick 0x7fff1c7606e0 tls_pollset=0x2421cc0 tls_worker=0x7fff1c7606e0 pollset.root_worker=0x7fff1c7606e0
I1214 06:07:13.433128611 113724 ev_epollex_linux.cc:754] PS:0x241c700 kicked_specific_but_awake
I1214 06:07:13.433137532 113724 ev_epollex_linux.cc:722] PS:0x2421cc0 (pollable:0x241c700) maybe_finish_shutdown sc=(nil) (target:!NULL) rw=(nil) (target:NULL) cpsc=0 (target:0)
I1214 06:07:13.433158214 113724 completion_queue.cc:1299] RETURN_EVENT[0x2421bc0]: OP_COMPLETE: tag:0x7fff1c7609e0 OK
I1214 06:07:13.433173550 113724 completion_queue.cc:1395] grpc_completion_queue_destroy(cq=0x2421bc0)
I1214 06:07:13.433179817 113724 completion_queue.cc:1389] grpc_completion_queue_shutdown(cq=0x2421bc0)
I1214 06:07:13.433187598 113724 ev_epollex_linux.cc:722] PS:0x2421cc0 (pollable:0x241c700) maybe_finish_shutdown sc=0x2421be0 (target:!NULL) rw=(nil) (target:NULL) cpsc=0 (target:0)
I1214 06:07:13.433195105 113724 init.cc:159] grpc_shutdown(void)
I1214 06:07:13.433205625 113724 call.cc:561] grpc_call_unref(c=0x2419da0)
I1214 06:07:13.433211583 113724 call_combiner.cc:167] call_combiner=0x2419db0: setting notify_on_cancel=(nil)
I1214 06:07:13.433221045 113724 metadata_array.cc:34] grpc_metadata_array_destroy(array=0x7fff1c761150)
I1214 06:07:13.433227230 113724 metadata_array.cc:34] grpc_metadata_array_destroy(array=0x7fff1c761100)
Set request, successful...!!!
I1214 06:07:13.433261133 113724 channel.cc:469] grpc_channel_destroy(channel=0x240aa20)
I1214 06:07:13.433270645 113724 client_channel.cc:196] chand=0x240aae8: setting connectivity state to SHUTDOWN
I1214 06:07:13.433285925 113724 connectivity_state.cc:164] SET: 0x240ab70 client_channel: READY --> SHUTDOWN [disconnect] error=0x2420030 {"created":"@1639462033.433267146","description":"Channel Destroyed","file":"src/core/lib/surface/channel.cc","file_line":471}
I1214 06:07:13.433302406 113724 pick_first.cc:195] Pick First 0x7f21e4001430 Shutting down
I1214 06:07:13.433314807 113724 connectivity_state.cc:164] SET: 0x7f21e4001618 pick_first: READY --> SHUTDOWN [shutdown] error=0x7f21e4000f40 {"created":"@1639462033.433301728","description":"Channel shutdown","file":"src/core/ext/filters/client_channel/lb_policy/pick_first/pick_first.cc","file_line":193}
I1214 06:07:13.433321842 113724 connectivity_state.cc:190] NOTIFY: 0x7f21e4001618 pick_first: 0x7f21e4001ec8
I1214 06:07:13.433328220 113724 subchannel_list.h:570] [pick_first 0x7f21e4001430] Shutting down subchannel_list 0x7f21e4001b20
I1214 06:07:13.433334038 113724 subchannel_list.h:390] [pick_first 0x7f21e4001430] subchannel list 0x7f21e4001b20 index 0 of 1 (subchannel 0x7f21e4002750): canceling connectivity watch (shutdown)
I1214 06:07:13.433339273 113724 connectivity_state.cc:113] CONWATCH: 0x7f21e4002838 subchannel: unsubscribe notify=0x7f21e4005198
I1214 06:07:13.433345329 113724 lb_policy.cc:47] pick_first 0x7f21e4001430: scheduling re-resolution closure with error="Cancelled".
I1214 06:07:13.433355630 113724 client_channel.cc:438] chand=0x240aae8: got resolver result: resolver_result=(nil) error={"created":"@1639462033.433294292","description":"Resolver Shutdown","file":"src/core/ext/filters/client_channel/resolver/dns/native/dns_resolver.cc","file_line":176} (resolver shutdown)
I1214 06:07:13.433362863 113724 client_channel.cc:257] chand=0x240aae8: shutting down
I1214 06:07:13.433383606 113724 ev_epollex_linux.cc:1436] PSS:0x2401aa0: del pollset 0x240a510
I1214 06:07:13.433391071 113724 ev_epollex_linux.cc:722] PS:0x240a510 (pollable:0x2408890) maybe_finish_shutdown sc=(nil) (target:!NULL) rw=(nil) (target:NULL) cpsc=0 (target:0)
I1214 06:07:13.433399010 113724 ev_epollex_linux.cc:722] PS:0x240a510 (pollable:0x2408890) maybe_finish_shutdown sc=0x240a4b8 (target:!NULL) rw=(nil) (target:NULL) cpsc=0 (target:0)
I1214 06:07:13.433409945 113724 ev_epollex_linux.cc:628] (fd-trace) pollable_unref: Closing epfd: 5
I1214 06:07:13.433425219 113724 subchannel_list.h:447] [pick_first 0x7f21e4001430] subchannel list 0x7f21e4001b20 index 0 of 1 (subchannel 0x7f21e4002750): connectivity changed: state=READY, error="Cancelled", shutting_down=1
I1214 06:07:13.433432695 113724 subchannel_list.h:307] [pick_first 0x7f21e4001430] subchannel list 0x7f21e4001b20 index 0 of 1 (subchannel 0x7f21e4002750): unreffing subchannel
I1214 06:07:13.433450254 113724 subchannel_list.h:374] [pick_first 0x7f21e4001430] subchannel list 0x7f21e4001b20 index 0 of 1 (subchannel (nil)): stopping connectivity watch
I1214 06:07:13.433456509 113724 pick_first.cc:169] Destroying Pick First 0x7f21e4001430
I1214 06:07:13.433465365 113724 subchannel_list.h:561] [pick_first 0x7f21e4001430] Destroying subchannel_list 0x7f21e4001b20
I1214 06:07:13.433478013 113724 chttp2_transport.cc:2790] set connectivity_state=4
I1214 06:07:13.433491718 113724 connectivity_state.cc:164] SET: 0x7f21e40066a8 client_transport: READY --> SHUTDOWN [close_transport] error=0x23e1b40 {"created":"@1639462033.433473419","description":"Transport destroyed","file":"src/core/ext/transport/chttp2/transport/chttp2_transport.cc","file_line":583,"grpc_status":14,"occurred_during_write":0}
I1214 06:07:13.433498998 113724 connectivity_state.cc:190] NOTIFY: 0x7f21e40066a8 client_transport: 0x7f21e4004ab8
I1214 06:07:13.433508306 113724 ev_posix.cc:269] (fd-trace) fd_shutdown(9)
E1214 06:07:13.433515585 113724 lockfree_event.cc:164] LockfreeEvent::SetShutdown: 0x7f21e4003880 curr=0x7f21e4004400 err={"created":"@1639462033.433473419","description":"Transport destroyed","file":"src/core/ext/transport/chttp2/transport/chttp2_transport.cc","file_line":583,"grpc_status":14,"occurred_during_write":0}
E1214 06:07:13.433543751 113724 lockfree_event.cc:164] LockfreeEvent::SetShutdown: 0x7f21e4003888 curr=0x2 err={"created":"@1639462033.433473419","description":"Transport destroyed","file":"src/core/ext/transport/chttp2/transport/chttp2_transport.cc","file_line":583,"grpc_status":14,"occurred_during_write":0}
E1214 06:07:13.433551096 113724 lockfree_event.cc:164] LockfreeEvent::SetShutdown: 0x7f21e4003890 curr=(nil) err={"created":"@1639462033.433473419","description":"Transport destroyed","file":"src/core/ext/transport/chttp2/transport/chttp2_transport.cc","file_line":583,"grpc_status":14,"occurred_during_write":0}
I1214 06:07:13.433568558 113724 tcp_posix.cc:521] TCP:0x7f21e4004260 got_read: {"created":"@1639462033.433521880","description":"FD Shutdown","file":"src/core/lib/iomgr/lockfree_event.cc","file_line":193,"referenced_errors":[{"created":"@1639462033.433473419","description":"Transport destroyed","file":"src/core/ext/transport/chttp2/transport/chttp2_transport.cc","file_line":583,"grpc_status":14,"occurred_during_write":0}]}
I1214 06:07:13.433578268 113724 resource_quota.cc:944] RQ anonymous_pool_7f21e4004090 ipv4:127.0.0.1:9339: free 8192; free_pool -> 8192
I1214 06:07:13.433586519 113724 tcp_posix.cc:397] TCP:0x7f21e4004260 call_cb 0x7f21e4006540 0x7f21f29e3d30:0x7f21e4006400
I1214 06:07:13.433592599 113724 tcp_posix.cc:400] read: error={"created":"@1639462033.433521880","description":"FD Shutdown","file":"src/core/lib/iomgr/lockfree_event.cc","file_line":193,"referenced_errors":[{"created":"@1639462033.433473419","description":"Transport destroyed","file":"src/core/ext/transport/chttp2/transport/chttp2_transport.cc","file_line":583,"grpc_status":14,"occurred_during_write":0}]}
I1214 06:07:13.433606113 113724 resource_quota.cc:544] RU shutdown 0x7f21e4004550
I1214 06:07:13.433618093 113724 ev_posix.cc:262] (fd-trace) grpc_fd_orphan, fd:9 closed
I1214 06:07:13.433641700 113724 ev_epollex_linux.cc:628] (fd-trace) pollable_unref: Closing epfd: 7
I1214 06:07:13.433655458 113724 init.cc:159] grpc_shutdown(void)
I1214 06:07:13.433663790 113724 init.cc:159] grpc_shutdown(void)
I1214 06:07:13.433809343 113724 executor.cc:388] EXECUTOR grpc_executor_shutdown() enter
I1214 06:07:13.433817083 113724 executor.cc:91] EXECUTOR (default-executor) SetThreading(0) begin
I1214 06:07:13.433847510 113725 executor.cc:178] EXECUTOR (default-executor) [0]: shutdown
I1214 06:07:13.433924758 113724 executor.cc:138] EXECUTOR (default-executor) Thread 1 of 1 joined
I1214 06:07:13.433935369 113724 executor.cc:153] EXECUTOR (default-executor) SetThreading(0) done
I1214 06:07:13.433940805 113724 executor.cc:91] EXECUTOR (resolver-executor) SetThreading(0) begin
I1214 06:07:13.434022108 113726 executor.cc:178] EXECUTOR (resolver-executor) [0]: shutdown
I1214 06:07:13.434116821 113724 executor.cc:138] EXECUTOR (resolver-executor) Thread 1 of 1 joined
I1214 06:07:13.434128541 113724 executor.cc:153] EXECUTOR (resolver-executor) SetThreading(0) done
I1214 06:07:13.434135026 113724 executor.cc:416] EXECUTOR grpc_executor_shutdown() done
I1214 06:07:13.434159077 113724 executor.cc:388] EXECUTOR grpc_executor_shutdown() enter
I1214 06:07:13.434178435 113724 ev_epollex_linux.cc:628] (fd-trace) pollable_unref: Closing epfd: 3
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment