additional data(sorry, can't edit a post)

With opencensus-impl-lite as: implementation, api, runtimeOnly [ie 
client-side tracing enabled]

env var API_GRPC_SERVER_ADDRESS is not set: default: localhost:11043

 

INFO: env var API_GRPC_DB_POOL_SIZE is not set 

INFO: DbWorker2: nb_workers: 2 

API_GRPC_POSTGRES_URI: *** 

API_GRPC_POSTGRES_URI: *** 

D1005 18:09:23.033466067 7152 ev_posix.cc:170] Using polling engine: 
epollex 

D1005 18:09:23.033715624 7152 dns_resolver.cc:348] Using native dns 
resolver 

Server listening on localhost:11043 

I1005 18:09:25.520007955 7152 server_filter.cc:97] 
OnDoneRecvInitialMetadataCb: tracing_slice: 
0000004b562beaac41cd2d97f7fab19de57801dcbfdb506d4b1d270200 

I1005 18:09:25.520063817 7152 server_filter.cc:108] PrintSlice: 
tracing_slice 1 = 0000004b562beaac41cd2d97f7fab19de57801dcbfdb506d4b1d270200 

I1005 18:09:25.520071226 7152 server_filter.cc:140] 
OnDoneRecvInitialMetadataCb: tracing_str = , tracing_str_len = 29 

I1005 18:09:25.520075789 7152 server_filter.cc:151] 
OnDoneRecvInitialMetadataCb: census_str = , census_str_len = 0 

I1005 18:09:25.520085429 7152 context.cc:52] GenerateServerContext: tracing: 
0000004b562beaac41cd2d97f7fab19de57801dcbfdb506d4b1d270200 

I1005 18:09:25.520094241 7152 context.cc:56] GenerateServerContext: 
trace_ctxt.span_id: dcbfdb506d4b1d27 

I1005 18:09:25.520098174 7152 context.cc:58] GenerateServerContext: 
trace_ctxt.trace_id: 004b562beaac41cd2d97f7fab19de578 

I1005 18:09:25.520101802 7152 context.cc:60] GenerateServerContext: 
trace_ctxt.trace_options: 00 

D1005 18:09:25.520517309 7180 grpc_auth.h:45] DebugPrintAuthContext: 
transport_security_type = ssl 

D1005 18:09:25.520533911 7180 grpc_auth.h:45] DebugPrintAuthContext: 
x509_common_name = 5f457e1df42371574b417e7c8b0bce6d 

D1005 18:09:25.520542979 7180 grpc_auth.h:45] DebugPrintAuthContext: 
x509_pem_cert = -----BEGIN CERTIFICATE-----


With no runtime dependency on opencensus:

env var API_GRPC_SERVER_ADDRESS is not set: default: localhost:11043

 

INFO: env var API_GRPC_DB_POOL_SIZE is not set 

INFO: DbWorker2: nb_workers: 2 

API_GRPC_POSTGRES_URI: *** 

API_GRPC_POSTGRES_URI: *** 

D1005 18:14:19.863397659 13625 ev_posix.cc:170] Using polling engine: 
epollex 

D1005 18:14:19.863636976 13625 dns_resolver.cc:348] Using native dns 
resolver 

Server listening on localhost:11043 

I1005 18:14:24.985050778 13625 server_filter.cc:97] 
OnDoneRecvInitialMetadataCb: tracing_slice: 

I1005 18:14:24.985181932 13625 server_filter.cc:108] PrintSlice: 
tracing_slice 1 = 

I1005 18:14:24.985200299 13625 server_filter.cc:140] 
OnDoneRecvInitialMetadataCb: tracing_str = , tracing_str_len = 0 

I1005 18:14:24.985209776 13625 server_filter.cc:151] 
OnDoneRecvInitialMetadataCb: census_str = , census_str_len = 0 

I1005 18:14:24.985229555 13625 context.cc:52] GenerateServerContext: tracing
: 

I1005 18:14:24.985247689 13625 context.cc:56] GenerateServerContext: 
trace_ctxt.span_id: 0000000000000000 

I1005 18:14:24.985259110 13625 context.cc:58] GenerateServerContext: 
trace_ctxt.trace_id: 00000000000000000000000000000000 

I1005 18:14:24.985273832 13625 context.cc:60] GenerateServerContext: 
trace_ctxt.trace_options: 00 

D1005 18:14:24.985863180 13656 grpc_auth.h:45] DebugPrintAuthContext: 
transport_security_type = ssl 

D1005 18:14:24.985875911 13656 grpc_auth.h:45] DebugPrintAuthContext: 
x509_common_name = 5f457e1df42371574b417e7c8b0bce6d 

D1005 18:14:24.985883892 13656 grpc_auth.h:45] DebugPrintAuthContext: 
x509_pem_cert = -----BEGIN CERTIFICATE----- 

Both logs are after a fresh server start, and one client request(the same 
one in both cases).
It's grpc++ v1.1.5, with a few log statements added in server_filter.cc and 
context.cc

Only in the second case I get a trace:

*Name: Recv.skcapipb.SkcApi/DevicePinCreateTx*
>
> *TraceId-SpanId-Options: 
> 00000000000000000000000000000000-605b2c23170cd2bc-01*
>
> *Parent SpanId: 0000000000000000 (remote: true)*
>
> *Start time: 2018-10-05T18:14:24.985405404+02:00*
>
> *End time: 2018-10-05T18:14:25.029826624+02:00*
>
> *Attributes: (0 dropped)*
>
> *Annotations: (0 dropped)*
>
> *Message events: (0 dropped)*
>
> *Links: (0 dropped)*
>
> *Span ended: true*
>
> *Status: OK*
>
In the first one, nothing is logged nor exported to zipkin. 

On Friday, October 5, 2018 at 12:34:44 PM UTC+2, [email protected] 
wrote:
>
> I have not set up anything related to opencensus client-side, so I suppose 
> the client is not sending a trace/span ID.
> But in that case, the server should generate a new span no?
> Or if that's a requirement, at least assert there is a client span?
>
> edit: In fact the client(grpc-java) was indeed not sending a traceid, my 
> bad.[I was missing a dep on 'opencensus-impl-lite']
> In that case, why is the server using a fakeid?
>
> Should not the behavior be something like:
> Check if the client has sent a grpc-trace-bin:
> if yes create a child span
> if not create a new pan
>
> *OT: *As I'm also testing opentracing: is there a proper/clean way to add 
> a new context?
> Right now I'm hacking it in via grpc_census_call_set_context, using my 
> custom class based on the one used by census in server_filter.h.
> Is this possible to easily increase GRPC_CONTEXT_COUNT?
>
> On Friday, October 5, 2018 at 4:22:56 AM UTC+2, g-easy wrote:
>>
>> On Thursday, October 4, 2018 at 12:51:33 AM UTC+10, 
>> [email protected] wrote:
>>>
>>> Hello,
>>>
>>>
>>> I have some issues setting up grpc++ and Opencensus.
>>>
>>> Before anything else, I have built grpc_opencensus_plugin(and its 
>>> dependencies) with Cmake. Could I have missed something regarding some kind 
>>> of static init? Dynamic linking?
>>>
>>
>> There's no init other than registering exporters, which is sounds like 
>> you've done.
>>  
>>
>>>
>>> Anyway, the prometheus stats are correctly exported, but I can not get 
>>> the traces to work(both stdout and zipkin).
>>> The traces are correctly logged/exported, but they always have the same 
>>> “Parent SpanId: 30c6ffffff7f0000”.
>>>
>>>
>>> Based on the stacktrace below, I can confirm one of CensusContext’s 
>>> constructors is indeed called for each request, but it calls 
>>> StartSpanWithRemoteParent instead of StartSpan.
>>>
>>
>> That part makes sense. The server-side span is a child span of the 
>> client-side span.
>>  
>>
>>> The result is that in zipkin, I basically have only one “meta span” for 
>>> the whole duration of the server. That span is typically 200-300s, 
>>> depending on how often I restart the server(local dev server).
>>>
>>>
>>> Example: I start something in the client, a span with 2-3 requests 
>>> appears in zipkin. Then 5 minutes later, I do something else client side 
>>> and the same span will be modified, and now have a duration of 300s.
>>>
>>  
>>
>>>
>>> grpc::CensusContext::CensusContext(grpc::CensusContext * this, 
>>>> absl::string_view name, const opencensus::trace::SpanContext & 
>>>> parent_ctxt) 
>>>> (....grpc/src/cpp/ext/filters/census/context.h:54)
>>>>
>>>> grpc::GenerateServerContext(absl::string_view tracing, 
>>>> absl::string_view stats, absl::string_view primary_role, absl::string_view 
>>>> method, grpc::CensusContext * context) 
>>>> (....grpc/src/cpp/ext/filters/census/context.cc:34)
>>>>
>>>> grpc::CensusServerCallData::OnDoneRecvInitialMetadataCb(void * 
>>>> user_data, grpc_error * error) 
>>>> (....grpc/src/cpp/ext/filters/census/server_filter.cc:113)
>>>>
>>>> exec_ctx_run(grpc_closure * closure, grpc_error * error) 
>>>> (....grpc/src/core/lib/iomgr/exec_ctx.cc:40)
>>>>
>>>> grpc_closure_run(const char * file, int line, grpc_closure * c, 
>>>> grpc_error * error) (....grpc/src/core/lib/iomgr/closure.h:258)
>>>>
>>>> recv_initial_metadata_ready(void * arg, grpc_error * error) 
>>>> (....grpc/src/core/ext/filters/deadline/deadline_filter.cc:298)
>>>>
>>>> exec_ctx_run(grpc_closure * closure, grpc_error * error) 
>>>> (....grpc/src/core/lib/iomgr/exec_ctx.cc:40)
>>>>
>>>> grpc_closure_run(const char * file, int line, grpc_closure * c, 
>>>> grpc_error * error) (....grpc/src/core/lib/iomgr/closure.h:258)
>>>>
>>>> hs_recv_initial_metadata_ready(void * user_data, grpc_error * err) 
>>>> (....grpc/src/core/ext/filters/http/server/http_server_filter.cc:289)
>>>>
>>>> exec_ctx_run(grpc_closure * closure, grpc_error * error) 
>>>> (....grpc/src/core/lib/iomgr/exec_ctx.cc:40)
>>>>
>>>> grpc_core::ExecCtx::Flush(grpc_core::ExecCtx * this) 
>>>> (....grpc/src/core/lib/iomgr/exec_ctx.cc:134)
>>>>
>>>> pollset_work(grpc_pollset * pollset, grpc_pollset_worker ** worker_hdl, 
>>>> grpc_millis deadline) 
>>>> (....grpc/src/core/lib/iomgr/ev_epollex_linux.cc:1195)
>>>>
>>>> pollset_work(grpc_pollset * pollset, grpc_pollset_worker ** worker, 
>>>> grpc_millis deadline) (....grpc/src/core/lib/iomgr/ev_posix.cc:313)
>>>>
>>>> grpc_pollset_work(grpc_pollset * pollset, grpc_pollset_worker ** 
>>>> worker, grpc_millis deadline) (....grpc/src/core/lib/iomgr/pollset.cc:48)
>>>>
>>>> cq_next(grpc_completion_queue * cq, gpr_timespec deadline, void * 
>>>> reserved) (....grpc/src/core/lib/surface/completion_queue.cc:1030)
>>>>
>>>> grpc_completion_queue_next(grpc_completion_queue * cq, gpr_timespec 
>>>> deadline, void * reserved) 
>>>> (....grpc/src/core/lib/surface/completion_queue.cc:1106)
>>>>
>>>> grpc::CompletionQueue::AsyncNextInternal(grpc::CompletionQueue * this, 
>>>> void ** tag, bool * ok, gpr_timespec deadline) 
>>>> (....grpc/src/cpp/common/completion_queue_cc.cc:56)
>>>>
>>>> grpc::CompletionQueue::Next(grpc::CompletionQueue * this, void ** tag, 
>>>> bool * ok) (....grpc/include/grpcpp/impl/codegen/completion_queue.h:171)
>>>>
>>>> ServerImpl::HandleRpcs(ServerImpl * this) 
>>>> (.../grpc_servers/api_server_async.cpp:105)
>>>>
>>>> ServerImpl::Run(ServerImpl * this, const std::__cxx11::string & 
>>>> server_address) (.../grpc_servers/api_server_async.cpp:69)
>>>>
>>>
>>>
>>> What can I do to have 1 span per request? 
>>>
>>> Should I instrument the route manually? But in that case what is the 
>>> point of the census plugin?
>>>
>>> Should this come from the client?
>>>
>>>
>>> PS: I don’t know if that is relevant, but I’m using the async 
>>> routes(unary, not streaming).
>>>
>>> PS2: the stats(prometheus) works fine
>>>
>>> PS3: client is grpc-java, android
>>>
>>
>> What trace context is the client sending?
>>
>> The behavior you describe is consistent with the client always sending 
>> the same span id to the server (which would be a bug)
>>
>

-- 
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 post to this group, send email to [email protected].
Visit this group at https://groups.google.com/group/grpc-io.
To view this discussion on the web visit 
https://groups.google.com/d/msgid/grpc-io/b244e1f0-9095-41c2-820e-af9c0706bd12%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

Reply via email to