Hi Easwar,
Below is the code snippets.
std::shared_ptr<grpc::ChannelCredentials>
ConnectionManager::createChannelCredentials()
{
grpc::SslCredentialsOptions sslCredOptions;
std::string
rootCertPath("/var/security/x509/trustedCerts/RSA_2048_SHA_512_root.crt");
std::string
clientKeyPath("/var/security/x509/keys/RSA_2048_SHA_512_client.key");
std::string
clientCertPath("/var/security/x509/certs/RSA_2048_SHA_512_client.crt");
//Here caCert, clientCert, ClientKey is of type string
getFileData(rootCertPath, caCert);//getFileData() will read and
populate cert/key from the provided loc
sslCredOptions.pem_root_certs = caCert;
getFileData(clientKeyPath, clientKey);
sslCredOptions.pem_private_key = clientKey;
getFileData(clientCertPath, clientCert);
sslCredOptions.pem_cert_chain = clientCert;
return grpc::SslCredentials(sslCredOptions);
}
//Here server
std::shared_ptr<grpc::Channel> ConnectionManager::createChannel(const
std::string &serverAddress, std::shared_ptr<grpc::Channel>& channel_)
{
std::shared_ptr<grpc::ChannelCredentials> channelCreds =
::grpc::InsecureChannelCredentials();
channelCreds = createChannelCredentials();
ChannelArguments channelArg;
std::string san("<CertSANName>");
channelArg.SetInt(GRPC_ARG_KEEPALIVE_TIME_MS, keepAliveTime_);
channelArg.SetInt(GRPC_ARG_KEEPALIVE_TIMEOUT_MS, keepAliveTime_);
channelArg.SetSslTargetNameOverride(san);
channel_ = grpc::CreateCustomChannel(serverAddress_, channelCreds,
channelArg);
std::chrono::time_point<std::chrono::system_clock> deadline =
std::chrono::system_clock::now() + std::chrono::seconds(10);
//if(!channel_->WaitForConnected(gpr_time_add(gpr_now(GPR_CLOCK_REALTIME),
gpr_time_from_seconds(600, GPR_TIMESPAN))) || channel_->GetState(false) !=
grpc_connectivity_state::GRPC_CHANNEL_READY)
if(*!channel_->WaitForConnected(deadline*) || channel_->GetState(false) !=
grpc_connectivity_state::GRPC_CHANNEL_READY)*//It is crashing here *
{
//notify and start some backoff logic
}
else
{
//Secure connection established
....
....
....
}
return channel_;
}
Tested the same with below openssl utility and I can see in the pcap that
handshake is happening successfully.
"sudo openssl s_client -connect <ip>:<port>-cert
/var/security/x509/certs/RSA_2048_SHA_512_client.crt -key
/var/security/x509/keys/RSA_2048_SHA_512_client.key -CAfile
/var/security/x509/trusted_certs/RSA_2048_SHA_512_root.crt -state -debug"
Thanks
Manish Khandelwal
On Wednesday, September 14, 2022 at 11:31:16 PM UTC+5:30 [email protected]
wrote:
> Could you also provide some code snippets from what you are trying to do.
> Thanks.
>
> On Tuesday, September 13, 2022 at 10:21:02 AM UTC-7 Manish Khandelwal
> wrote:
>
>> 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/fae3a061-891c-49b4-b0a3-6470ae3577b1n%40googlegroups.com.
