Hi Google Team,
Please hep me in understanding what is going wrong here and how I can fix
this.
Is this a known issue please share some details.
Thanks
Manish Khandelwal
On Thursday, September 22, 2022 at 6:45:12 AM UTC+5:30 Manish Khandelwal
wrote:
> 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 eas...@google.com
> 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 grpc-io+unsubscr...@googlegroups.com.
To view this discussion on the web visit
https://groups.google.com/d/msgid/grpc-io/4fc0d91c-6b7b-4b51-a18f-5c1f7edf1e29n%40googlegroups.com.
