Hi All,
Created a custom channel and populated SslCredentials with ca cert, client
cert and client key. Below assertion is observed once
channel.WaitForConnected is called.
I0913 17:07:25.303815824 17165 init.cc:165] grpc_init(void)
I0913 17:07:25.303940980 17165 init.cc:212]
grpc_shutdown(void)
I0913 17:07:25.304056078 17165 init.cc:212]
grpc_shutdown(void)
I0913 17:07:25.304331812 17165 init.cc:165] grpc_init(void)
I0913 17:07:25.304439088 17165 secure_channel_create.cc:201]
grpc_secure_channel_create(creds=0x7fa6ec010d80, target=10.220.6.50:50058,
args=0x7fa705760590, reserved=(nil))
I0913 17:07:25.304579888 17165 init.cc:165] grpc_init(void)
I0913 17:07:25.305033297 17165 ev_posix.cc:352] (polling-api)
pollset_set_create(0x7fa6ec00fc70)
I0913 17:07:25.305103697 17165 ref_counted.h:92]
subchannel_pool:0x7fa6ec00b9c8 ref 1 -> 2
I0913 17:07:25.305229970 17165 client_channel.cc:1402]
chand=0x7fa6ec00fa08: creating client_channel for channel stack
0x7fa6ec00f958
I0913 17:07:25.305320485 17165 ev_posix.cc:304] (polling-api)
pollset_init(0x7fa6ec011c70)
I0913 17:07:25.305436421 17165 ref_counted.h:103]
pollable_refcount:0x7fa6ec00ac08
/home/rcheppudira/new_grpc/grpc/src/core/lib/iomgr/ev_epollex_linux.cc:796
ref 1 -> 2 pollset
I0913 17:07:25.305555151 17165 timer_generic.cc:364] TIMER
0x7fa6ec00e4d0: SET 5003 now 3 call 0x7fa6ec00e508[0x7fa70b4823cd]
I0913 17:07:25.305665221 17165 timer_generic.cc:401] .. add to
shard 0 with queue_deadline_cap=0 => is_first_timer=false
I0913 17:07:25.305775850 17165 ev_posix.cc:364] (polling-api)
pollset_set_add_pollset(0x7fa6ec00fc70, 0x7fa6ec011c70)
I0913 17:07:25.305887875 17165 ev_epollex_linux.cc:1450]
PSS:0x7fa6ec00fc70: add pollset 0x7fa6ec011c70
I0913 17:07:25.306001577 17165 ref_counted.h:103]
pollable_refcount:0x7fa6ec00ac08
/home/rcheppudira/new_grpc/grpc/src/core/lib/iomgr/ev_epollex_linux.cc:1241
ref 2 -> 3 pollset_as_multipollable
I0913 17:07:25.306742453 17165 ref_counted.h:199]
pollable_refcount:0x7fa6ec00ac08
/home/rcheppudira/new_grpc/grpc/src/core/lib/iomgr/ev_epollex_linux.cc:1244
unref 3 -> 2 pollset
I0913 17:07:25.306846936 17165 ev_epollex_linux.cc:569] (fd-trace)
Pollable_create: created epfd: 16 (type: 0)
I0913 17:07:25.306956168 17165 ev_epollex_linux.cc:1249]
PS:0x7fa6ec011c70 active pollable transition from empty to multi
I0913 17:07:25.307059253 17165 ref_counted.h:103]
pollable_refcount:0x7fa6ec011dc8
/home/rcheppudira/new_grpc/grpc/src/core/lib/iomgr/ev_epollex_linux.cc:1280
ref 1 -> 2 pollset_set
I0913 17:07:25.307174631 17165 ref_counted.h:199]
pollable_refcount:0x7fa6ec00ac08
/home/rcheppudira/new_grpc/grpc/src/core/lib/iomgr/ev_epollex_linux.cc:1281
unref 2 -> 1 pollset_as_multipollable
I0913 17:07:25.307288891 17165 ref_counted.h:199]
pollable_refcount:0x7fa6ec011dc8
/home/rcheppudira/new_grpc/grpc/src/core/lib/iomgr/ev_epollex_linux.cc:1478
unref 2 -> 1 pollset_set
I0913 17:07:25.307496739 17165 init.cc:165] grpc_init(void)
I0913 17:07:25.334856920 17165 init.cc:212]
grpc_shutdown(void)
I0913 17:07:25.335164222 17165 channel_connectivity.cc:43]
grpc_channel_check_connectivity_state(channel=0x7fa6ec00f8c0,
try_to_connect=1)
I0913 17:07:25.335212831 17165 connectivity_state.cc:174]
ConnectivityStateTracker client_channel[0x7fa6ec00fac8]: get current
state: IDLE
I0913 17:07:25.335308933 17165 ref_counted.h:133]
stream_refcount:0x7fa6ec00f958
/home/rcheppudira/new_grpc/grpc/src/core/lib/transport/transport.h:88 ref 1
-> 2 TryToConnect
I0913 17:07:25.335442749 17165 work_serializer.cc:55]
WorkSerializer::Run() 0x7fa6ec00bf80 Scheduling callback
[/home/rcheppudira/new_grpc/grpc/src/core/ext/filters/client_channel/client_channel.cc:1926]
I0913 17:07:25.335517898 17165 work_serializer.cc:65] Executing
immediately
I0913 17:07:25.335660933 17165 ref_counted.h:133]
stream_refcount:0x7fa6ec00f958
/home/rcheppudira/new_grpc/grpc/src/core/lib/transport/transport.h:88 ref 2
-> 3 ClientChannelControlHelper
I0913 17:07:25.335822965 17165 ev_posix.cc:352] (polling-api)
pollset_set_create(0x7fa6ec0105f0)
I0913 17:07:25.335905657 17165 ref_counted.h:92]
lb_policy_refcount:0x7fa6ec001688 ref 1 -> 2
I0913 17:07:25.336194241 17165 ev_posix.cc:352] (polling-api)
pollset_set_create(0x7fa6ec010670)
I0913 17:07:25.336355155 17165 ev_posix.cc:377] (polling-api)
pollset_set_add_pollset_set(0x7fa6ec010670, 0x7fa6ec0105f0)
I0913 17:07:25.336457682 17165 ev_epollex_linux.cc:1487] PSS: merge
(0x7fa6ec010670, 0x7fa6ec0105f0)
I0913 17:07:25.307856561 17166 executor.cc:224] EXECUTOR
(default-executor) [0]: step (sub_depth=0)
I0913 17:07:25.307920536 17167 executor.cc:224] EXECUTOR
(resolver-executor) [0]: step (sub_depth=0)
I0913 17:07:25.336576133 17165 ev_epollex_linux.cc:1521] PSS: parent
0x7fa6ec010670 to 0x7fa6ec0105f0
I0913 17:07:25.337203867 17165 resolving_lb_policy.cc:163]
resolving_lb=0x7fa6ec001680: starting name resolution
I0913 17:07:25.337258063 17165 ref_counted.h:92]
lb_policy_refcount:0x7fa6ec001688 ref 2 -> 3
I0913 17:07:25.337429314 17165 client_channel.cc:1306]
chand=0x7fa6ec00fa08: update: state=CONNECTING picker=0x7fa6ec0127e0
I0913 17:07:25.337497200 17165 connectivity_state.cc:152]
ConnectivityStateTracker client_channel[0x7fa6ec00fac8]: IDLE ->
CONNECTING (helper)
I0913 17:07:25.337667613 17165 ref_counted.h:103]
resolver_refcount:0x7fa6ec0129d8
/home/rcheppudira/new_grpc/grpc/src/core/ext/filters/client_channel/resolver/dns/c_ares/dns_resolver_ares.cc:434
ref 1 -> 2 dns-resolving
I0913 17:07:25.338277467 17165 grpc_ares_wrapper.cc:128] (c-ares
resolver) request:0x7fa6ec012b80 c-ares address sorting:
input[0]=10.220.6.50:50058
I0913 17:07:25.338486711 17165 grpc_ares_wrapper.cc:128] (c-ares
resolver) request:0x7fa6ec012b80 c-ares address sorting:
output[0]=10.220.6.50:50058
I0913 17:07:25.338643994 17165 ev_posix.cc:377] (polling-api)
pollset_set_add_pollset_set(0x7fa6ec0105f0, 0x7fa6ec00fc70)
I0913 17:07:25.338706851 17165 ev_epollex_linux.cc:1487] PSS: merge
(0x7fa6ec0105f0, 0x7fa6ec00fc70)
I0913 17:07:25.338813848 17165 ev_epollex_linux.cc:1521] PSS: parent
0x7fa6ec0105f0 to 0x7fa6ec00fc70
I0913 17:07:25.339155232 17165 client_channel.cc:1581]
chand=0x7fa6ec00fa08: creat[4173222.493507] serial8250: too much work for
irq4
ed resolving_lb_policy=0x7fa6ec001680
I0913 17:07:25.339274241 17165 ref_counted.h:199]
stream_refcount:0x7fa6ec00f958
/home/rcheppudira/new_grpc/grpc/src/core/lib/transport/transport.h:105
unref 3 -> 2 TryToConnect
I0913 17:07:25.339380121 17165 work_serializer.cc:102]
WorkSerializer::DrainQueue() 0x7fa6ec00bf80
I0913 17:07:25.339499410 17165 work_serializer.cc:117] Queue Drained
I0913 17:07:25.339617022 17165 work_serializer.cc:55]
WorkSerializer::Run() 0x7fa6ec00bf80 Scheduling callback
[/home/rcheppudira/new_grpc/grpc/src/core/ext/filters/client_channel/resolver/dns/c_ares/dns_resolver_ares.cc:327]
I0913 17:07:25.339708934 17165 work_serializer.cc:65] Executing
immediately
I0913 17:07:25.339876553 17165 resolving_lb_policy.cc:293]
resolving_lb=0x7fa6ec001680: got resolver result
I0913 17:07:25.340316832 17165 ref_counted.h:92]
lb_policy_refcount:0x7fa6ec001688 ref 3 -> 4
I0913 17:07:25.340460426 17165 ev_posix.cc:352] (polling-api)
pollset_set_create(0x7fa6ec012e20)
I0913 17:07:25.340571334 17165 resolving_lb_policy.cc:258]
resolving_lb=0x7fa6ec001680: created new LB policy 0x7fa6ec012b80
I0913 17:07:25.340654584 17165 ev_posix.cc:377] (polling-api)
pollset_set_add_pollset_set(0x7fa6ec012e20, 0x7fa6ec0105f0)
I0913 17:07:25.380510767 17165 ev_epollex_linux.cc:1487] PSS: merge
(0x7fa6ec012e20, 0x7fa6ec0105f0)
I0913 17:07:25.380744037 17165 ev_epollex_linux.cc:1521] PSS: parent
0x7fa6ec012e20 to 0x7fa6ec00fc70
I0913 17:07:25.380469980 17168 timer_generic.cc:716] TIMER CHECK
BEGIN: now=78 next=9223372036854775807 tls_min=0 glob_min=0
I0913 17:07:25.385597447 17168 timer_generic.cc:611] ..
shard[0]->min_deadline = 1
I0913 17:07:25.386931416 17168 timer_generic.cc:534] .. shard[0]:
heap_empty=true
I0913 17:07:25.391432826 17168 timer_generic.cc:509] ..
shard[0]->queue_deadline_cap --> 1078
I0913 17:07:25.391458807 17168 timer_generic.cc:574] .. shard[0]
popped 0
I0913 17:07:25.392370096 17168 timer_generic.cc:629] .. result
--> 1, shard[0]->min_deadline 1 --> 1079, now=78
I0913 17:07:25.393245905 17168 timer_generic.cc:534] .. shard[1]:
heap_empty=true
I0913 17:07:25.394042375 17168 timer_generic.cc:509] ..
shard[1]->queue_deadline_cap --> 1078
I0913 17:07:25.394793309 17168 timer_generic.cc:574] .. shard[1]
popped 0
I0913 17:07:25.395162909 17168 timer_generic.cc:629] .. result
--> 1, shard[1]->min_deadline 1 --> 1079, now=78
I0913 17:07:25.384528317 17165 resolving_lb_policy.cc:240]
resolving_lb=0x7fa6ec001680: Updating child policy 0x7fa6ec012b80
I0913 17:07:25.396767303 17165 child_policy_handler.cc:211]
[child_policy_handler 0x7fa6ec012b80] creating new child policy pick_first
I0913 17:07:25.397911862 17165 ref_counted.h:103]
lb_policy_refcount:0x7fa6ec012b88
/home/rcheppudira/new_grpc/grpc/src/core/ext/filters/client_channel/lb_policy/child_policy_handler.cc:258
ref 1 -> 2 Helper
I0913 17:07:25.397978351 17165 ev_posix.cc:352] (polling-api)
pollset_set_create(0x7fa6ec0130c0)
I0913 17:07:25.398036179 17165 pick_first.cc:146] Pick First
0x7fa6ec010af0 created.
I0913 17:07:25.399215100 17165 child_policy_handler.cc:272]
[child_policy_handler 0x7fa6ec012b80] created new LB policy "pick_first"
(0x7fa6ec010af0)
I0913 17:07:25.399387189 17165 ev_posix.cc:377] (polling-api)
pollset_set_add_pollset_set(0x7fa6ec0130c0, 0x7fa6ec012e20)
I0913 17:07:25.399397525 17165 ev_epollex_linux.cc:1487] PSS: merge
(0x7fa6ec0130c0, 0x7fa6ec012e20)
I0913 17:07:25.399502008 17165 ev_epollex_linux.cc:1521] PSS: parent
0x7fa6ec0130c0 to 0x7fa6ec00fc70
I0913 17:07:25.399616268 17165 child_policy_handler.cc:230]
[child_policy_handler 0x7fa6ec012b80] updating child policy 0x7fa6ec010af0
I0913 17:07:25.399732763 17165 pick_first.cc:265] Pick First
0x7fa6ec010af0 received update with 1 addresses
I0913 17:07:25.399861830 17165 subchannel_list.h:361] [pick_first
0x7fa6ec010af0] Creating subchannel list 0x7fa6ec00ed40 for 1 subchannels
I0913 17:07:25.400047329 17165 ref_counted.h:92]
subchannel_pool:0x7fa6ec00b9c8 ref 2 -> 3
I0913 17:07:25.400099011 17165 ref_counted.h:92]
subchannel_pool:0x7fa6ec00b9c8 ref 3 -> 4
I0913 17:07:25.407755012 17168 timer_generic.cc:534] .. shard[2]:
heap_empty=true
I0913 17:07:25.407776244 17168 timer_generic.cc:509] ..
shard[2]->queue_deadline_cap --> 1078
I0913 17:07:25.407922352 17168 timer_generic.cc:574] .. shard[2]
popped 0
I0913 17:07:25.408062314 17168 timer_generic.cc:629] .. result
--> 1, shard[2]->min_deadline 1 --> 1079, now=78
I0913 17:07:25.408211215 17168 timer_generic.cc:534] .. shard[3]:
heap_empty=true
I0913 17:07:25.408946504 17168 timer_generic.cc:509] ..
shard[3]->queue_deadline_cap --> 1078
I0913 17:07:25.409368625 17168 timer_generic.cc:574] .. shard[3]
popped 0
I0913 17:07:25.409511939 17168 timer_generic.cc:629] .. result
--> 1, shard[3]->min_deadline 1 --> 1079, now=78
I0913 17:07:25.409652739 17168 timer_generic.cc:739] TIMER CHECK
END: r=1; next=1079
I0913 17:07:25.409791304 17168 timer_manager.cc:188] sleep for a
1001 milliseconds
I0913 17:07:25.410554530 17165 ref_counted.h:92]
subchannel_pool:0x7fa6ec00b9c8 ref 4 -> 5
I0913 17:07:25.410646720 17165 ref_counted.h:92]
subchannel_pool:0x7fa6ec00b9c8 ref 5 -> 6
I0913 17:07:25.410764054 17165 ref_counted.h:103]
security_connector_refcount:0x7fa6ec013038
/home/rcheppudira/new_grpc/grpc/src/core/lib/security/security_connector/security_connector.cc:92
ref 1 -> 2 connector_arg_copy
I0913 17:07:25.410875800 17165 ref_counted.h:199]
security_connector_refcount:0x7fa6ec013038
/home/rcheppudira/new_grpc/grpc/src/core/ext/transport/chttp2/client/secure/secure_channel_create.cc:144
unref 2 -> 1 lb_channel_create
I0913 17:07:25.410993133 17165 ref_counted.h:183]
subchannel_pool:0x7fa6ec00b9c8 unref 6 -> 5
I0913 17:07:25.411102086 17165 ref_counted.h:183]
subchannel_pool:0x7fa6ec00b9c8 unref 5 -> 4
I0913 17:07:25.411285908 17165 ref_counted.h:103]
security_connector_refcount:0x7fa6ec013038
/home/rcheppudira/new_grpc/grpc/src/core/lib/security/security_connector/security_connector.cc:92
ref 1 -> 2 connector_arg_copy
I0913 17:07:25.411333959 17165 ref_counted.h:92]
subchannel_pool:0x7fa6ec00b9c8 ref 4 -> 5
I0913 17:07:25.411511914 17165 ev_posix.cc:352] (polling-api)
pollset_set_create(0x7fa6ec03d640)
I0913 17:07:25.411604943 17165 ref_counted.h:92]
subchannel_pool:0x7fa6ec00b9c8 ref 5 -> 6
I0913 17:07:25.411669755 17165 ref_counted.h:103]
security_connector_refcount:0x7fa6ec013038
/home/rcheppudira/new_grpc/grpc/src/core/lib/security/security_connector/security_connector.cc:92
ref 2 -> 3 connector_arg_copy
I0913 17:07:25.413236714 17165 ref_counted.h:103]
security_connector_refcount:0x7fa6ec013038
/home/rcheppudira/new_grpc/grpc/src/core/lib/security/security_connector/security_connector.cc:92
ref 3 -> 4 connector_arg_copy
I0913 17:07:25.413338403 17165 ref_counted.h:92]
subchannel_pool:0x7fa6ec00b9c8 ref 6 -> 7
I0913 17:07:25.413450429 17165 ref_counted.h:92]
subchannel_pool:0x7fa6ec00b9c8 ref 7 -> 8
I0913 17:07:25.413561895 17165 ref_counted.h:183]
subchannel_pool:0x7fa6ec00b9c8 unref 8 -> 7
I0913 17:07:25.413666937 17165 ref_counted.h:199]
security_connector_refcount:0x7fa6ec013038
/home/rcheppudira/new_grpc/grpc/src/core/lib/security/security_connector/security_connector.cc:86
unref 4 -> 3 connector_arg_destroy
I0913 17:07:25.413773375 17165 ref_counted.h:183]
subchannel_pool:0x7fa6ec00b9c8 unref 7 -> 6
I0913 17:07:25.414899775 17165 client_channel.cc:868]
chand=0x7fa6ec00fa08: creating subchannel wrapper 0x7fa6ec03da30 for
subchannel 0x7fa6ec033280
I0913 17:07:25.414985540 17165 ref_counted.h:133]
stream_refcount:0x7fa6ec00f958
/home/rcheppudira/new_grpc/grpc/src/core/lib/transport/transport.h:88 ref 2
-> 3 SubchannelWrapper
I0913 17:07:25.415218810 17165 subchannel_list.h:404] [pick_first
0x7fa6ec010af0] subchannel list 0x7fa6ec00ed40 index 0: Created subchannel
0x7fa6ec03da30 for address uri ipv4:10.220.6.50:50058
I0913 17:07:25.415344245 17165 ref_counted.h:103]
lb_policy_refcount:0x7fa6ec010af8
/home/rcheppudira/new_grpc/grpc/src/core/ext/filters/client_channel/lb_policy/pick_first/pick_first.cc:93
ref 1 -> 2 subchannel_list
I0913 17:07:25.415441464 17165 subchannel_list.h:308] [pick_first
0x7fa6ec010af0] subchannel list 0x7fa6ec00ed40 index 0 of 1 (subchannel
0x7fa6ec03da30): starting watch (from IDLE)
I0913 17:07:25.415542035 17165 ref_counted.h:103]
pick_first:0x7fa6ec00ed48
/home/rcheppudira/new_grpc/grpc/src/core/ext/filters/client_channel/lb_policy/subchannel_list.h:317
ref 1 -> 2 Watcher
I0913 17:07:25.415705464 17165 ref_counted.h:103]
client_channel_routing:0x7fa6ec03da38
/home/rcheppudira/new_grpc/grpc/src/core/ext/filters/client_channel/client_channel.cc:921
ref 1 -> 2 WatcherWrapper
I0913 17:07:25.443438598 17165 ev_posix.cc:377] (polling-api)
pollset_set_add_pollset_set(0x7fa6ec03d640, 0x7fa6ec0130c0)
I0913 17:07:25.443463740 17165 ev_epollex_linux.cc:1487] PSS: merge
(0x7fa6ec03d640, 0x7fa6ec0130c0)
I0913 17:07:25.443569620 17165 ev_epollex_linux.cc:1521] PSS: parent
0x7fa6ec03d640 to 0x7fa6ec00fc70
I0913 17:07:25.443969391 17165 socket_utils_common_posix.cc:320] Enabling
TCP_USER_TIMEOUT with a timeout of 10000 ms
I0913 17:07:25.445888071 17165 ev_posix.cc:254] (polling-api)
fd_create(18, tcp-client:ipv4:10.220.6.50:50058, 1)
I0913 17:07:25.446187550 17165 ev_posix.cc:255] (fd-trace)
fd_create(18, tcp-client:ipv4:10.220.6.50:50058, 1)
I0913 17:07:25.446316058 17165 ev_posix.cc:394] (polling-api)
pollset_set_add_fd(0x7fa6ec03d640, 18)
I0913 17:07:25.446402382 17165 ev_epollex_linux.cc:1353]
PSS:0x7fa6ec03d640: add fd 0x7fa6ec03e720 (18)
I0913 17:07:25.446514687 17165 ev_epollex_linux.cc:616] add fd
0x7fa6ec03e720 (18) to pollable 0x7fa6ec011dc0
I0913 17:07:25.446658560 17165 ref_counted.h:92]
subchannel_pool:0x7fa6ec00b9c8 ref 6 -> 7
I0913 17:07:25.446745163 17165 ref_counted.h:103]
security_connector_refcount:0x7fa6ec013038
/home/rcheppudira/new_grpc/grpc/src/core/lib/security/security_connector/security_connector.cc:92
ref 3 -> 4 connector_arg_copy
I0913 17:07:25.446854395 17165 tcp_client_posix.c[4173222.577355]
serial8250: too much work for irq4
c:329] CLIENT_CONNECT: ipv4:10.220.6.50:50058: asynchronously connecting
fd 0x7fa6ec03e720
I0913 17:07:25.446979271 17165 timer_generic.cc:364] TIMER
0x7fa6ec012c20: SET 20036 now 36 call 0x7fa6ec012c58[0x7fa70b61f33b]
I0913 17:07:25.447319258 17165 timer_generic.cc:401] .. add to
shard 0 with queue_deadline_cap=1078 => is_first_timer=false
I0913 17:07:25.447601138 17165 ref_counted.h:199]
resolver_refcount:0x7fa6ec0129d8
/home/rcheppudira/new_grpc/grpc/src/core/ext/filters/client_channel/resolver/dns/c_ares/dns_resolver_ares.cc:396
unref 2 -> 1 dns-resolving
I0913 17:07:25.447646674 17165 work_serializer.cc:102]
WorkSerializer::DrainQueue() 0x7fa6ec00bf80
I0913 17:07:25.447753112 17165 work_serializer.cc:117] Queue Drained
I0913 17:07:25.447868211 17165 client_channel.cc:1033]
chand=0x7fa6ec00fa08: connectivity change for subchannel wrapper
0x7fa6ec03da30 subchannel 0x7fa6ec033280; hopping into work_serializer
I0913 17:07:25.447979119 17165 work_serializer.cc:55]
WorkSerializer::Run() 0x7fa6ec00bf80 Scheduling callback
[/home/rcheppudira/new_grpc/grpc/src/core/ext/filters/client_channel/client_channel.cc:1044]
I0913 17:07:25.448078573 17165 work_serializer.cc:65] Executing
immediately
I0913 17:07:25.448185570 17165 client_channel.cc:1066]
chand=0x7fa6ec00fa08: processing connectivity change in work serializer for
subchannel wrapper 0x7fa6ec03da30 subchannel 0x7fa6ec033280
watcher=0x7fa6ec03ba20
I0913 17:07:25.448334751 17165 subchannel_list.h:241] [pick_first
0x7fa6ec010af0] subchannel list 0x7fa6ec00ed40 index 0 of 1 (subchannel
0x7fa6ec03da30): connectivity changed: state=CONNECTING, shutting_down=0,
pending_watcher=0x7fa6ec03ba20
I0913 17:07:25.448437557 17165 ref_counted.h:103]
lb_policy_refcount:0x7fa6ec010af8
/home/rcheppudira/new_grpc/grpc/src/core/ext/filters/client_channel/lb_policy/pick_first/pick_first.cc:410
ref 2 -> 3 QueuePicker
I0913 17:07:25.448549582 17165 client_channel.cc:1306]
chand=0x7fa6ec00fa08: update: state=CONNECTING picker=0x7fa6ec013ac0
I0913 17:07:25.448671944 17165 ref_counted.h:199]
lb_policy_refcount:0x7fa6ec001688
/home/rcheppudira/new_grpc/grpc/src/core/ext/filters/client_channel/lb_policy.h:375
unref 4 -> 3 QueuePicker
I0913 17:07:25.448745697 17165 work_serializer.cc:102]
WorkSerializer::DrainQueue() 0x7fa6ec00bf80
I0913 17:07:25.449227881 17165 work_serializer.cc:117] Queue Drained
I0913 17:07:25.449335436 17165 init.cc:165] grpc_init(void)
I0913 17:07:25.449470928 17165 completion_queue.cc:526]
grpc_completion_queue_create_internal(completion_type=0, polling_type=0)
I0913 17:07:25.449589100 17165 ev_posix.cc:304] (polling-api)
pollset_init(0x7fa6ec03f298)
I0913 17:07:25.449735767 17165 ref_counted.h:103]
pollable_refcount:0x7fa6ec00ac08
/home/rcheppudira/new_grpc/grpc/src/core/lib/iomgr/ev_epollex_linux.cc:796
ref 1 -> 2 pollset
I0913 17:07:25.480508672 17165 channel_connectivity.cc:232]
grpc_channel_watch_connectivity_state(channel=0x7fa6ec00f8c0,
last_observed_state=0, deadline=gpr_timespec { tv_sec: 1663089445, tv_nsec:
335137682, clock_type: 1 }, cq=0x7fa6ec03f190, tag=0x7fa6ec013a50)
I0913 17:07:25.480579072 17165 ref_counted.h:133]
stream_refcount:0x7fa6ec00f958
/home/rcheppudira/new_grpc/grpc/src/core/lib/transport/transport.h:88 ref 3
-> 4 watch_channel_connectivity
I0913 17:07:25.480707859 17165 ev_posix.cc:364] (polling-api)
pollset_set_add_pollset(0x7fa6ec00fc70, 0x7fa6ec03f298)
I0913 17:07:25.480900901 17165 ev_epollex_linux.cc:1450]
PSS:0x7fa6ec00fc70: add pollset 0x7fa6ec03f298
I0913 17:07:25.481010971 17165 ref_counted.h:103]
pollable_refcount:0x7fa6ec00ac08
/home/rcheppudira/new_grpc/grpc/src/core/lib/iomgr/ev_epollex_linux.cc:1241
ref 2 -> 3 pollset_as_multipollable
I0913 17:07:25.481119085 17165 ref_counted.h:199]
pollable_refcount:0x7fa6ec00ac08
/home/rcheppudira/new_grpc/grpc/src/core/lib/iomgr/ev_epollex_linux.cc:1244
unref 3 -> 2 pollset
I0913 17:07:25.481230272 17165 ev_epollex_linux.cc:569] (fd-trace)
Pollable_create: created epfd: 19 (type: 0)
I0913 17:07:25.481345650 17165 ev_epollex_linux.cc:1249]
PS:0x7fa6ec03f298 active pollable transition from empty to multi
I0913 17:07:25.481428063 17165 ref_counted.h:103]
pollable_refcount:0x7fa6ec03f638
/home/rcheppudira/new_grpc/grpc/src/core/lib/iomgr/ev_epollex_linux.cc:1280
ref 1 -> 2 pollset_set
I0913 17:07:25.481534501 17165 ref_counted.h:199]
pollable_refcount:0x7fa6ec00ac08
/home/rcheppudira/new_grpc/grpc/src/core/lib/iomgr/ev_epollex_linux.cc:1281
unref 2 -> 1 pollset_as_multipollable
I0913 17:07:25.481642056 17165 ev_epollex_linux.cc:616] add fd
0x7fa6ec03e720 (18) to pollable 0x7fa6ec03f630
I0913 17:07:25.481755758 17165 ref_counted.h:199]
pollable_refcount:0x7fa6ec03f638
/home/rcheppudira/new_grpc/grpc/src/core/lib/iomgr/ev_epollex_linux.cc:1478
unref 2 -> 1 pollset_set
I0913 17:07:25.481859402 17165 ref_counted.h:133]
stream_refcount:0x7fa6ec00f958
/home/rcheppudira/new_grpc/grpc/src/core/lib/transport/transport.h:88 ref 4
-> 5 ExternalConnectivityWatcher
I0913 17:07:25.482000482 17165 work_serializer.cc:55]
WorkSerializer::Run() 0x7fa6ec00bf80 Scheduling callback
[/home/rcheppudira/new_grpc/grpc/src/core/ext/filters/client_channel/client_channel.cc:1155]
I0913 17:07:25.482080380 17165 work_serializer.cc:65] Executing
immediately
I0913 17:07:25.482211402 17165 timer_generic.cc:364] TIMER
0x7fa6ec03f418: SET 600034 now 180 call 0x7fa6ec03f388[0x7fa70b482e3b]
I0913 17:07:25.482299402 17165 timer_generic.cc:401] .. add to
shard 0 with queue_deadline_cap=1078 => is_first_timer=false
I0913 17:07:25.482430983 17165 connectivity_state.cc:118]
ConnectivityStateTracker client_channel[0x7fa6ec00fac8]: add watcher
0x7fa6ec03f130
I0913 17:07:25.482516190 17165 connectivity_state.cc:124]
ConnectivityStateTracker client_channel[0x7fa6ec00fac8]: notifying watcher
0x7fa6ec03f130: IDLE -> CONNECTING
I0913 17:07:25.482647771 17165 work_serializer.cc:55]
WorkSerializer::Run() 0x7fa6ec00bf80 Scheduling callback
[/home/rcheppudira/new_grpc/grpc/src/core/ext/filters/client_channel/client_channel.cc:1175]
I0913 17:07:25.482732139 17165 work_serializer.cc:76] Scheduling
on queue : item 0x7fa6ec03ec80
I0913 17:07:25.482900317 17165 work_serializer.cc:102]
WorkSerializer::DrainQueue() 0x7fa6ec00bf80
I0913 17:07:25.482950044 17165 work_serializer.cc:134] Running item
0x7fa6ec03ec80 : callback scheduled at
[/home/rcheppudira/new_grpc/grpc/src/core/ext/filters/client_channel/client_channel.cc:1175]
I0913 17:07:25.483054526 17165 connectivity_state.cc:141]
ConnectivityStateTracker client_channel[0x7fa6ec00fac8]: remove watcher
0x7fa6ec03f130
I0913 17:07:25.483184711 17165 ev_posix.cc:371] (polling-api)
pollset_set_del_pollset(0x7fa6ec00fc70, 0x7fa6ec03f298)
I0913 17:07:25.483269917 17165 ev_epollex_linux.cc:1398]
PSS:0x7fa6ec00fc70: del pollset 0x7fa6ec03f298
I0913 17:07:25.483379707 17165 ev_epollex_linux.cc:664]
PS:0x7fa6ec03f298 (pollable:0x7fa6ec03f630) maybe_finish_shutdown sc=(nil)
(target:!NULL) rw=(nil) (target:NULL) cpsc=0 (target:0)
I0913 17:07:25.511424054 17165 ref_counted.h:199]
stream_refcount:0x7fa6ec00f958
/home/rcheppudira/new_grpc/grpc/src/core/lib/transport/transport.h:105
unref 5 -> 4 ExternalConnectivityWatcher
I0913 17:07:25.511541387 17165 work_serializer.cc:102]
WorkSerializer::DrainQueue() 0x7fa6ec00bf80
I0913 17:07:25.511615978 17165 work_serializer.cc:117] Queue Drained
I0913 17:07:25.511634695 17165 timer_generic.cc:467] TIMER
0x7fa6ec03f418: CANCEL pending=true
I0913 17:07:25.511748397 17165 completion_queue.cc:707]
cq_end_op_for_next(cq=0x7fa6ec03f190, tag=0x7fa6ec013a50, error="No
Error", done=0x7fa70b482a2e, done_arg=0x7fa6ec03f310,
storage=0x7fa6ec03f460)
I0913 17:07:25.511850644 17165 ev_posix.cc:331] (polling-api)
pollset_kick(0x7fa6ec03f298, (nil))
I0913 17:07:25.511959597 1[4173222.646290] serial8250: too much work for
irq4
7165 ev_epollex_linux.cc:731] PS:0x7fa6ec03f298 kick (nil)
tls_pollset=(nil) tls_worker=(nil) pollset.root_worker=(nil)
I0913 17:07:25.512064638 17165 ev_epollex_linux.cc:741]
PS:0x7fa6ec03f298 kicked_any_without_poller
I0913 17:07:25.512201248 17165 completion_queue.cc:982]
grpc_completion_queue_next(cq=0x7fa6ec03f190, deadline=gpr_timespec {
tv_sec: 9223372036854775807, tv_nsec: 0, clock_type: 1 }, reserved=(nil))
I0913 17:07:25.512371381 17165 ref_counted.h:199]
stream_refcount:0x7fa6ec00f958
/home/rcheppudira/new_grpc/grpc/src/core/lib/transport/transport.h:105
unref 4 -> 3 watch_channel_connectivity
I0913 17:07:25.512474746 17165 completion_queue.cc:1083]
RETURN_EVENT[0x7fa6ec03f190]: OP_COMPLETE: tag:0x7fa6ec013a50 OK
I0913 17:07:25.512537882 17165 completion_queue.cc:1425]
grpc_completion_queue_destroy(cq=0x7fa6ec03f190)
I0913 17:07:25.512637895 17165 completion_queue.cc:1419]
grpc_completion_queue_shutdown(cq=0x7fa6ec03f190)
I0913 17:07:25.512750200 17165 ev_posix.cc:309] (polling-api)
pollset_shutdown(0x7fa6ec03f298)
I0913 17:07:25.512975648 17165 ev_epollex_linux.cc:664]
PS:0x7fa6ec03f298 (pollable:0x7fa6ec03f630) maybe_finish_shutdown
sc=0x7fa6ec03f1d0 (target:!NULL) rw=(nil) (target:NULL) cpsc=0 (target:0)
I0913 17:07:25.513091305 17165 ev_posix.cc:314] (polling-api)
pollset_destroy(0x7fa6ec03f298)
I0913 17:07:25.513200816 17165 ref_counted.h:199]
pollable_refcount:0x7fa6ec03f638
/home/rcheppudira/new_grpc/grpc/src/core/lib/iomgr/ev_epollex_linux.cc:927
unref 1 -> 0 pollset
I0913 17:07:25.513311165 17165 ev_epollex_linux.cc:149] (fd-trace)
pollable_unref: Closing epfd: 19
I0913 17:07:25.513445540 17165 init.cc:212]
grpc_shutdown(void)
I0913 17:07:25.513544994 17165 channel_connectivity.cc:43]
grpc_channel_check_connectivity_state(channel=0x7fa6ec00f8c0,
try_to_connect=1)
I0913 17:07:25.513658695 17165 connectivity_state.cc:174]
ConnectivityStateTracker client_channel[0x7fa6ec00fac8]: get current
state: CONNECTING
I0913 17:07:25.513767368 17165 init.cc:165] grpc_init(void)
I0913 17:07:25.513882746 17165 completion_queue.cc:526]
grpc_completion_queue_create_internal(completion_type=0, polling_type=0)
I0913 17:07:25.513992257 17165 ev_posix.cc:304] (polling-api)
pollset_init(0x7fa6ec03f738)
I0913 17:07:25.514111267 17165 ref_counted.h:103]
pollable_refcount:0x7fa6ec00ac08
/home/rcheppudira/new_grpc/grpc/src/core/lib/iomgr/ev_epollex_linux.cc:796
ref 1 -> 2 pollset
I0913 17:07:25.514229997 17165 channel_connectivity.cc:232]
grpc_channel_watch_connectivity_state(channel=0x7fa6ec00f8c0,
last_observed_state=1, deadline=gpr_timespec { tv_sec: 1663089445, tv_nsec:
335137682, clock_type: 1 }, cq=0x7fa6ec03f630, tag=0x7fa6ec013b20)
I0913 17:07:25.514340067 17165 ref_counted.h:133]
stream_refcount:0x7fa6ec00f958
/home/rcheppudira/new_grpc/grpc/src/core/lib/transport/transport.h:88 ref 3
-> 4 watch_channel_connectivity
I0913 17:07:25.514452930 17165 ev_posix.cc:364] (polling-api)
pollset_set_add_pollset(0x7fa6ec00fc70, 0x7fa6ec03f738)
I0913 17:07:25.514564397 17165 ev_epollex_linux.cc:1450]
PSS:0x7fa6ec00fc70: add pollset 0x7fa6ec03f738
I0913 17:07:25.514675584 17165 ref_counted.h:103]
pollable_refcount:0x7fa6ec00ac08
/home/rcheppudira/new_grpc/grpc/src/core/lib/iomgr/ev_epollex_linux.cc:1241
ref 2 -> 3 pollset_as_multipollable
I0913 17:07:25.542637797 17165 ref_counted.h:199]
pollable_refcount:0x7fa6ec00ac08
/home/rcheppudira/new_grpc/grpc/src/core/lib/iomgr/ev_epollex_linux.cc:1244
unref 3 -> 2 pollset
I0913 17:07:25.542729429 17165 ev_epollex_linux.cc:569] (fd-trace)
Pollable_create: created epfd: 19 (type: 0)
I0913 17:07:25.542869950 17165 ev_epollex_linux.cc:1249]
PS:0x7fa6ec03f738 active pollable transition from empty to multi
I0913 17:07:25.542934483 17165 ref_counted.h:103]
pollable_refcount:0x7fa6ec03fdd8
/home/rcheppudira/new_grpc/grpc/src/core/lib/iomgr/ev_epollex_linux.cc:1280
ref 1 -> 2 pollset_set
I0913 17:07:25.543148477 17165 ref_counted.h:199]
pollable_refcount:0x7fa6ec00ac08
/home/rcheppudira/new_grpc/grpc/src/core/lib/iomgr/ev_epollex_linux.cc:1281
unref 2 -> 1 pollset_as_multipollable
I0913 17:07:25.543274750 17165 ev_epollex_linux.cc:616] add fd
0x7fa6ec03e720 (18) to pollable 0x7fa6ec03fdd0
I0913 17:07:25.543391245 17165 ref_counted.h:199]
pollable_refcount:0x7fa6ec03fdd8
/home/rcheppudira/new_grpc/grpc/src/core/lib/iomgr/ev_epollex_linux.cc:1478
unref 2 -> 1 pollset_set
I0913 17:07:25.543491817 17165 ref_counted.h:133]
stream_refcount:0x7fa6ec00f958
/home/rcheppudira/new_grpc/grpc/src/core/lib/transport/transport.h:88 ref 4
-> 5 ExternalConnectivityWatcher
I0913 17:07:25.543632617 17165 work_serializer.cc:55]
WorkSerializer::Run() 0x7fa6ec00bf80 Scheduling callback
[/home/rcheppudira/new_grpc/grpc/src/core/ext/filters/client_channel/client_channel.cc:1155]
I0913 17:07:25.543722572 17165 work_serializer.cc:65] Executing
immediately
I0913 17:07:25.543974280 17165 timer_generic.cc:364] TIMER
0x7fa6ec03f418: SET 600034 now 242 call 0x7fa6ec03f388[0x7fa70b482e3b]
I0913 17:07:25.544049988 17165 timer_generic.cc:401] .. add to
shard 0 with queue_deadline_cap=1078 => is_first_timer=false
I0913 17:07:25.544172909 17165 connectivity_state.cc:118]
ConnectivityStateTracker client_channel[0x7fa6ec00fac8]: add watcher
0x7fa6ec03f5d0
I0913 17:07:25.544299461 17165 work_serializer.cc:102]
WorkSerializer::DrainQueue() 0x7fa6ec00bf80
I0913 17:07:25.544386902 17165 work_serializer.cc:117] Queue Drained
I0913 17:07:25.544504236 17165 completion_queue.cc:982]
grpc_completion_queue_next(cq=0x7fa6ec03f630, deadline=gpr_timespec {
tv_sec: 9223372036854775807, tv_nsec: 0, clock_type: 1 }, reserved=(nil))
I0913 17:07:25.544651741 17165 ev_posix.cc:322] (polling-api)
pollset_work(0x7fa6ec03f738, 9223372036854775807) begin
I0913 17:07:25.544765442 17165 ev_epollex_linux.cc:1120]
PS:0x7fa6ec03f738 work hdl=(nil) worker=0x7fa7057602f0 now=243
deadline=9223372036854775807 kwp=0 pollable=0x7fa6ec03fdd0
I0913 17:07:25.544948147 17165 ref_counted.h:103]
pollable_refcount:0x7fa6ec03fdd8
/home/rcheppudira/new_grpc/grpc/src/core/lib/iomgr/ev_epollex_linux.cc:1018
ref 1 -> 2 pollset_worker
I0913 17:07:25.545075537 17165 ev_epollex_linux.cc:938]
POLLABLE:0x7fa6ec03fdd0[type=pollset epfd=19 wakeup=20] poll for -1ms
I0913 17:07:25.571483922 17165 ev_epollex_linux.cc:957]
POLLABLE:0x7fa6ec03fdd0 got 1 events
I0913 17:07:25.571542309 17165 ev_epollex_linux.cc:905]
PS:0x7fa6ec03f738 got fd 0x7fa6ec03e720: cancel=0 read=0 write=1
I0913 17:07:25.571681153 17165 tcp_client_posix.cc:142]
CLIENT_CONNECT: ipv4:10.220.6.50:50058: on_writable: error="No Error"
I0913 17:07:25.571790944 17165 timer_generic.cc:467] TIMER
0x7fa6ec012c20: CANCEL pending=true
I0913 17:07:25.571914423 17165 ev_posix.cc:400] (polling-api)
pollset_set_del_fd(0x7fa6ec03d640, 18)
I0913 17:07:25.572013319 17165 ev_epollex_linux.cc:1377]
PSS:0x7fa6ec03d640: del fd 0x7fa6ec03e720
I0913 17:07:25.572390182 17165 combiner.cc:61]
C:0x7fa6ec03f4f0 create
I0913 17:07:25.572544950 17165 ref_counted.h:103]
tcp:0x7fa6ec0403d8
/home/rcheppudira/new_grpc/grpc/src/core/lib/iomgr/tcp_posix.cc:1823 ref 1
-> 2 error-tracking
I0913 17:07:25.572643566 17165 tcp_client_posix.cc:105]
CLIENT_CONNECT: ipv4:10.220.6.50:50058: on_alarm: error="Cancelled"
I0913 17:07:25.572758665 17165 ref_counted.h:183]
subchannel_pool:0x7fa6ec00b9c8 unref 7 -> 6
I0913 17:07:25.572988862 17165 ref_counted.h:199]
security_connector_refcount:0x7fa6ec013038
/home/rcheppudira/new_grpc/grpc/src/core/lib/security/security_connector/security_connector.cc:86
unref 4 -> 3 connector_arg_destroy
I0913 17:07:25.573173801 17165 handshaker.cc:99]
handshake_manager 0x7fa6ec038720: adding handshaker http_connect
[0x7fa6ec040f40] at index 0
I0913 17:07:25.573545916 17165 ssl_transport_security.cc:220]
HANDSHAKE START - before SSL initialization - PINIT
I0913 17:07:25.573650398 17165 ssl_transport_security.cc:220]
LOOP - before SSL initialization - PINIT
I0913 17:07:25.573789243 17165 ssl_transport_security.cc:220]
LOOP - SSLv3/TLS write client hello - TWCH
I0913 17:07:25.573852379 17165 ref_counted.h:103]
security_connector_refcount:0x7fa6ec013038
/home/rcheppudira/new_grpc/grpc/src/core/lib/security/transport/security_handshaker.cc:113
ref 3 -> 4 handshake
I0913 17:07:25.573949878 17165 handshaker.cc:99]
handshake_manager 0x7fa6ec038720: adding handshaker security
[0x7fa6ec05c6e0] at index 1
I0913 17:07:25.574059668 17165 ev_posix.cc:394] (polling-api)
pollset_set_add_fd(0x7fa6ec03d640, 18)
I0913 17:07:25.574176722 17165 ev_epollex_linux.cc:1353]
PSS:0x7fa6ec03d640: add fd 0x7fa6ec03e720 (18)
I0913 17:07:25.574290144 17165 ev_epollex_linux.cc:616] add fd
0x7fa6ec03e720 (18) to pollable 0x7fa6ec011dc0
I0913 17:07:25.574407198 17165 ev_epollex_linux.cc:616] add fd
0x7fa6ec03e720 (18) to pollable 0x7fa6ec03fdd0
I0913 17:07:25.574524252 17165 ref_counted.h:92]
subchannel_pool:0x7fa6ec00b9c8 ref 6 -> 7
I0913 17:07:25.574623148 17165 ref_counted.h:103]
security_connector_refcount:0x7fa6ec013038
/home/rcheppudira/new_grpc/grpc/src/core/lib/security/security_connector/security_connector.cc:92
ref 4 -> 5 connector_arg_copy
I0913 17:07:25.574756125 17165 timer_generic.cc:364] TIMER
0x7fa6ec0387d8: SET 20036 now 273 call 0x7fa6ec038810[0x7fa70b5f12d2]
I0913 17:07:25.574843287 17165 timer_generic.cc:401] .. add to
shard 0 with queue_deadline_cap=1078 => is_first_timer=false
I0913 17:07:25.575114551 17165 handshaker.cc:129]
handshake_manager 0x7fa6ec038720: error="No Error" shutdown=0 index=0,
args={endpoint=0x7fa6ec0403b0, args=0x7fa6ec012830 {size=12:
grpc.primary_user_agent=grpc-c++/1.30.0, grpc.keepalive_time_ms=10000,
grpc.keepalive_timeout_ms=10000,
grpc.ssl_target_name_override=Infinera.com,
grpc.client_channel_factory=0x7fa6ec00e9f0,
grpc.channel_credentials=0x7fa6ec010d80,
grpc.server_uri=dns:///10.220.6.50:50058,
grpc.default_authority=Infinera.com, grpc.subchannel_pool=0x7fa6ec00b9c0,
grpc.http2_scheme=https, grpc.security_connector=0x7fa6ec013030,
grpc.subchannel_address=ipv4:10.220.6.50:50058}, read_buffer=0x7fa6ec012bf0
(length=0), exit_early=0}
I0913 17:07:25.575178246 17165 handshaker.cc:176]
handshake_manager 0x7fa6ec038720: calling handshaker http_connect
[0x7fa6ec040f40] at index 0
I0913 17:07:25.575312900 17165 handshaker.cc:129]
handshake_manager 0x7fa6ec038720: error="No Error" shutdown=0 index=1,
args={endpoint=0x7fa6ec0403b0, args=0x7fa6ec012830 {size=12:
grpc.primary_user_agent=grpc-c++/1.30.0, grpc.keepalive_time_ms=10000,
grpc.keepalive_timeout_ms=10000,
grpc.ssl_target_name_override=Infinera.com,
grpc.client_channel_factory=0x7fa6ec00e9f0,
grpc.channel_credentials=0x7fa6ec010d80,
grpc.server_uri=dns:///10.220.6.50:50058,
grpc.default_authority=Infinera.com, grpc.subchannel_pool=0x7fa6ec00b9c0,
grpc.http2_scheme=https, grpc.security_connector=0x7fa6ec013030,
grpc.subchannel_address=ipv4:10.220.6.50:50058}, read_buffer=0x7fa6ec012bf0
(length=0), exit_early=0}
I0913 17:07:25.603279024 17165 handshaker.cc:176]
handshake_manager 0x7fa6ec038720: calling handshaker security
[0x7fa6ec05c6e0] at index 1
I0913 17:07:25.603416192 17165 tcp_posix.cc:1566] WRITE
0x7fa6ec0403b0 (peer=ipv4:10.220.6.50:50058)
I0913 17:07:25.603619012 17165 tcp_posix.cc:1616] write: "No
Error"
I0913 17:07:25.603753386 17165 ref_counted.h:103]
tcp:0x7fa6ec0403d8
/home/rcheppudira/new_grpc/grpc/src/core/lib/iomgr/tcp_posix.cc:908 ref 2
-> 3 read
I0913 17:07:25.604010961 17165 tcp_posix.cc:541]
TCP:0x7fa6ec0403b0 notify_on_read
I0913 17:07:25.604401513 17165 ref_counted.h:199]
pollable_refcount:0x7fa6ec03fdd8
/home/rcheppudira/new_grpc/grpc/src/core/lib/iomgr/ev_epollex_linux.cc:1085
unref 2 -> 1 pollset_worker
I0913 17:07:25.604615228 17165 ev_epollex_linux.cc:664]
PS:0x7fa6ec03f738 (pollable:0x7fa6ec03fdd0) maybe_finish_shutdown sc=(nil)
(target:!NULL) rw=(nil) (target:NULL) cpsc=1 (target:0)
I0913 17:07:25.604730047 17165 ev_posix.cc:325] (polling-api)
pollset_work(0x7fa6ec03f738, 9223372036854775807) end
I0913 17:07:25.604973653 17165 ev_posix.cc:322] (polling-api)
pollset_work(0x7fa6ec03f738, 9223372036854775807) begin
I0913 17:07:25.605089869 17165 ev_epollex_linux.cc:1120]
PS:0x7fa6ec03f738 work hdl=(nil) worker=0x7fa7057602f0 now=273
deadline=9223372036854775807 kwp=0 pollable=0x7fa6ec03fdd0
I0913 17:07:25.605204967 17165 ref_counted.h:103]
pollable_refcount:0x7fa6ec03fdd8
/home/rcheppudira/new_grpc/grpc/src/core/lib/iomgr/ev_epollex_linux.cc:1018
ref 1 -> 2 pollset_worker
I0913 17:07:25.605318669 17165 ev_epollex_linux.cc:938]
POLLABLE:0x7fa6ec03fdd0[type=pollset epfd=19 wakeup=20] poll for -1ms
I0913 17:07:25.624281973 17165 ev_epollex_linux.cc:957]
POLLABLE:0x7fa6ec03fdd0 got 1 events
I0913 17:07:25.625191306 17165 ev_epollex_linux.cc:905]
PS:0x7fa6ec03f738 got fd 0x7fa6ec03e720: cancel=0 read=1 write=1
I0913 17:07:25.626231103 17165 tcp_posix.cc:887]
TCP:0x7fa6ec0403b0 got_read: "No Error"
I0913 17:07:25.627087357 17165 tcp_posix.cc:869]
TCP:0x7fa6ec0403b0 alloc_slices
I0913 17:07:25.627883827 17165 resource_quota.cc:890] RQ
anonymous_pool_7fa6ec03f7b0 ipv4:10.220.6.50:50058: alloc 8192; free_pool
-> -8192
I0913 17:07:25.629396031 17165 combiner.cc:135]
C:0x7fa6ec03f4f0 grpc_combiner_execute c=0x7fa6ec040cf8 last=1
I0913 17:07:25.630779167 17165 combiner.cc:199]
C:0x7fa6ec03f4f0 grpc_combiner_continue_exec_ctx contended=0
exec_ctx_ready_to_finish=0 time_to_execute_final_list=0
I0913 17:07:25.633678419 17165 combiner.cc:222]
C:0x7fa6ec03f4f0 maybe_finish_one n=0x7fa6ec040cf8
I0913 17:07:25.635280857 17165 combiner.cc:308]
C:0x7fa6ec03f4f0 grpc_combiner_execute_finally c=0x7fa6ec03f820;
ac=0x7fa6ec03f4f0
I0913 17:07:25.636448324 17165 combiner.cc:264]
C:0x7fa6ec03f4f0 finish old_state=5
I0913 17:07:25.637369670 17165 combiner.cc:199]
C:0x7fa6ec03f4f0 grpc_combiner_continue_exec_ctx contended=0
exec_ctx_ready_to_finish=0 time_to_execute_final_list=1
I0913 17:07:25.638760349 17165 combiner.cc:246]
C:0x7fa6ec03f4f0 execute_final[0] c=0x7fa6ec03f820
I0913 17:07:25.639790648 17165 resource_quota.cc:321] RQ: check
allocation for user 0x7fa6ec040cf0 shutdown=0 free_pool=-8192
I0913 17:07:25.640919004 17165 resource_quota.cc:347] RQ
anonymous_pool_7fa6ec03f7b0 ipv4:10.220.6.50:50058: grant alloc 8192 bytes;
rq_free_pool -> 9223372036854767615
I0913 17:07:25.642398521 17165 combiner.cc:264]
C:0x7fa6ec03f4f0 finish old_state=3
I0913 17:07:25.643722712 17165 tcp_posix.cc:850]
TCP:0x7fa6ec0403b0 read_allocation_done: "No Error"
I0913 17:07:25.644955550 17165 tcp_posix.cc:680]
TCP:0x7fa6ec0403b0 call_cb 0x7fa6ec05c8d8 0x7fa70b65e450:0x7fa6ec05c6e0
I0913 17:07:25.646910547 17165 tcp_posix.cc:683] READ
0x7fa6ec0403b0 (peer=ipv4:10.220.6.50:50058) error="No Error"
I0913 17:07:25.648767487 17165 ref_counted.h:199]
tcp:0x7fa6ec0403d8
/home/rcheppudira/new_grpc/grpc/src/core/lib/iomgr/tcp_posix.cc:844 unref 3
-> 2 read
I0913 17:07:25.650205100 17165 ssl_transport_security.cc:220]
LOOP - SSLv3/TLS write client hello - TWCH
I0913 17:07:25.652048630 17165 ssl_transport_security.cc:220]
LOOP - SSLv3/TLS read server hello - TRSH
I0913 17:07:25.653957812 17165 ssl_transport_security.cc:220]
LOOP - SSLv3/TLS read server certific - TRSC
I0913 17:07:25.655300999 17165 ssl_transport_security.cc:220]
LOOP - SSLv3/TLS read server key exch - TRSKE
I0913 17:07:25.656334650 17165 ssl_transport_security.cc:220]
LOOP - SSLv3/TLS read server done - TRSD
I0913 17:07:25.659340898 17165 ssl_transport_security.cc:220]
LOOP - SSLv3/TLS write client key exc - TWCKE
I0913 17:07:25.660446066 17165 ssl_transport_security.cc:220]
LOOP - SSLv3/TLS write change cipher - TWCCS
I0913 17:07:25.661612974 17165 ssl_transport_security.cc:220]
LOOP - SSLv3/TLS write finished - TWFIN
I0913 17:07:25.662694117 17165 tcp_posix.cc:1566] WRITE
0x7fa6ec0403b0 (peer=ipv4:10.220.6.50:50058)
I0913 17:07:25.664612238 17165 tcp_posix.cc:1616] write: "No
Error"
I0913 17:07:25.665905140 17165 ref_counted.h:103]
tcp:0x7fa6ec0403d8
/home/rcheppudira/new_grpc/grpc/src/core/lib/iomgr/tcp_posix.cc:908 ref 2
-> 3 read
I0913 17:07:25.667535235 17165 tcp_posix.cc:887]
TCP:0x7fa6ec0403b0 got_read: "No Error"
I0913 17:07:25.668567210 17165 tcp_posix.cc:879]
TCP:0x7fa6ec0403b0 do_read
I0913 17:07:25.669521521 17165 tcp_posix.cc:680]
TCP:0x7fa6ec0403b0 call_cb 0x7fa6ec05c8d8 0x7fa70b65e450:0x7fa6ec05c6e0
I0913 17:07:25.670683960 17165 tcp_posix.cc:683] READ
0x7fa6ec0403b0 (peer=ipv4:10.220.6.50:50058) error="No Error"
I0913 17:07:25.671891934 17165 ref_counted.h:199]
tcp:0x7fa6ec0403d8
/home/rcheppudira/new_grpc/grpc/src/core/lib/iomgr/tcp_posix.cc:844 unref 3
-> 2 read
I0913 17:07:25.673510017 17165 ssl_transport_security.cc:220]
LOOP - SSLv3/TLS write finished - TWFIN
I0913 17:07:25.674696760 17165 ssl_transport_security.cc:220]
LOOP - SSLv3/TLS read server session - TRST
I0913 17:07:25.675933230 17165 ssl_transport_security.cc:220]
LOOP - SSLv3/TLS read change cipher s - TRCCS
I0913 17:07:25.677194564 17165 ssl_transport_security.cc:220]
LOOP - SSLv3/TLS read finished - TRFIN
I0913 17:07:25.678290792 17165 ssl_transport_security.cc:220]
HANDSHAKE DONE - SSL negotiation finished succe - SSLOK
E0913 17:07:25.680856761 17165 ssl_transport_security.cc:470] assertion
failed: (int)peer->property_count == current_insert_index
signal 6[SIGABRT] caught by process
[/opt/infinera/thanos/local/bin/tunnelclient]
#####DumpStacktrace ########
#0 /opt/infinera/thanos/local/lib/libBaseSystem.so unsigned long
backward::details::unwind<backward::StackTraceImpl<backward::system_tag::linux_tag>::callback>(backward::StackTraceImpl<backward::system_tag::linux_tag>::callback,
unsigned long) [0x7fa709dd4c72]
#1 /opt/infinera/thanos/local/lib/libBaseSystem.so
backward::StackTraceImpl<backward::system_tag::linux_tag>::load_here(unsigned
long) [0x7fa709dd4008]
#2 /opt/infinera/thanos/local/lib/libBaseSystem.so
util::Backtrace::DumpStacktrace() [0x7fa709dd2c5e]
#3 /opt/infinera/thanos/local/lib/libBaseSystem.so
OsProcess::MyFailureHandler(int) [0x7fa709db54e7]
#4 /lib/x86_64-linux-gnu/libc.so.6 [0x7fa70988683f]
#5 /lib/x86_64-linux-gnu/libc.so.6 gsignal [0x7fa7098867bb]
#6 /lib/x86_64-linux-gnu/libc.so.6 abort [0x7fa709871534]
#7 /opt/infinera/thanos/local/lib/libgrpc.so.10 [0x7fa70b6a1dfd]
#8 /opt/infinera/thanos/local/lib/libgrpc.so.10 [0x7fa70b6a3acf]
#9 /opt/infinera/thanos/local/lib/libgrpc.so.10
tsi_handshaker_result_extract_peer(tsi_handshaker_result const*, tsi_peer*)
[0x7fa70b6a6db1]
#10 /opt/infinera/thanos/local/lib/libgrpc.so.10 [0x7fa70b65df19]
#11 /opt/infinera/thanos/local/lib/libgrpc.so.10 [0x7fa70b65e2b2]
#12 /opt/infinera/thanos/local/lib/libgrpc.so.10 [0x7fa70b65e44b]
#13 /opt/infinera/thanos/local/lib/libgrpc.so.10 [0x7fa70b65e5fe]
#14 /opt/infinera/thanos/local/lib/libgrpc.so.10 [0x7fa70b6117ac]
#15 /opt/infinera/thanos/local/lib/libgrpc.so.10
grpc_core::ExecCtx::Flush() [0x7fa70b611cdc]
#16 /opt/infinera/thanos/local/lib/libgrpc.so.10 [0x7fa70b6098b7]
#17 /opt/infinera/thanos/local/lib/libgrpc.so.10 [0x7fa70b6110bd]
#18 /opt/infinera/thanos/local/lib/libgrpc.so.10
grpc_pollset_work(grpc_pollset*, grpc_pollset_worker**, long)
[0x7fa70b61859f]
#19 /opt/infinera/thanos/local/lib/libgrpc.so.10 [0x7fa70b674c8f]
#20 /opt/infinera/thanos/local/lib/libgrpc.so.10 grpc_completion_queue_next
[0x7fa70b675154]
#21 /opt/infinera/thanos/local/lib/libgrpc++.so.1
grpc_impl::CompletionQueue::AsyncNextInternal(void**, bool*, gpr_timespec)
[0x7fa70b09a675]
#22 /opt/infinera/thanos/local/lib/libgrpc++.so.1
grpc_impl::CompletionQueue::Next(void**, bool*) [0x7fa70b088ff6]
#23 /opt/infinera/thanos/local/lib/libgrpc++.so.1
grpc_impl::Channel::WaitForStateChangeImpl(grpc_connectivity_state,
gpr_timespec) [0x7fa70b0883b4]
#24 /opt/infinera/thanos/local/bin/tunnelclient bool
grpc::ChannelInterface::WaitForStateChange<gpr_timespec>(grpc_connectivity_state,
gpr_timespec) [0x55d52d47a6e3]
#25 /opt/infinera/thanos/local/bin/tunnelclient bool
grpc::ChannelInterface::WaitForConnected<gpr_timespec>(gpr_timespec)
[0x55d52d4797fe]
#26 /opt/infinera/thanos/local/bin/tunnelclient
ConnectionManager::createChannel(std::__cxx11::basic_string<char,
std::char_traits<char>, std::allocator<char> > const&,
std::shared_ptr<grpc_impl::Channel>&) [0x55d52d472e6f]
#27 /opt/infinera/thanos/local/bin/tunnelclient
ConnectionManager::connectToServer() [0x55d52d473b81]
#28 /opt/infinera/thanos/local/bin/tunnelclient boost::_mfi::mf0<void,
ConnectionManager>::operator()(ConnectionManager*) const [0x55d52d47d4bc]
#29 /opt/infinera/thanos/local/bin/tunnelclient void
boost::_bi::list1<boost::_bi::value<ConnectionManager*>
>::operator()<boost::_mfi::mf0<void, ConnectionManager>,
boost::_bi::list0>(boost::_bi::type<void>, boost::_mfi::mf0<void,
ConnectionManager>&, boost::_bi::list0&, int) [0x55d52d47d41e]
#30 /opt/infinera/thanos/local/bin/tunnelclient boost::_bi::bind_t<void,
boost::_mfi::mf0<void, ConnectionManager>,
boost::_bi::list1<boost::_bi::value<ConnectionManager*> > >::operator()()
[0x55d52d47d2cc]
#31 /opt/infinera/thanos/local/bin/tunnelclient
boost::detail::thread_data<boost::_bi::bind_t<void, boost::_mfi::mf0<void,
ConnectionManager>, boost::_bi::list1<boost::_bi::value<ConnectionManager*>
> > >::run() [0x55d52d47d0f3]
#####End DumpStacktrace ########
Please help me out in fixing the same. Is there any fix already available?
Thanks
Manish Khandelwal
--
You received this message because you are subscribed to the Google Groups
"grpc.io" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to [email protected].
To view this discussion on the web visit
https://groups.google.com/d/msgid/grpc-io/05cc21a8-ca20-4009-8299-dc6d99dda7aan%40googlegroups.com.