Yes, I do turn on the trace for api (and some other categories) and set the verbosity level to INFO.
I thought of the various GRPC_TRACE variables as simply the categories I can enable for logging. Are you suggesting if I don't turn anything on, I'll still get INFO/ERR logging at a much reduced level or you mean that "api" category itself is too verbose for production usage? What would be a typical logging configuration for prod in your opinion? Thanks. On Wednesday, October 4, 2017 at 4:05:22 PM UTC-7, Vijay Pai wrote: > > The amount of logging you're describing suggests that you have > GRPC_TRACE=api environment variable set; is that correct? I don't think > that the combination of api tracing and INFO level logging is intended for > production use. If you don't have the GRPC_TRACE environment variable set, > that much won't come out on INFO. > - Vijay > > On Wed, Oct 4, 2017 at 3:52 PM Arpit Baldeva <[email protected] > <javascript:>> wrote: > >> Hi, >> >> Tested on 1.4.2. >> >> Currently, grpc has 3 logging levels. >> >> GPR_LOG_SEVERITY_DEBUG, >> GPR_LOG_SEVERITY_INFO, >> GPR_LOG_SEVERITY_ERROR >> >> IMHO, currently GPR_LOG_SEVERITY_INFO logs too much and is unsuitable for >> use in prod scenario. INFO to me means that something interesting happened >> which is not an error but an important event to be noticed. So for example, >> if a client logs in, login/logout may be INFO log but if the client >> executes 5 rpcs, rpc handling generates DEBUG logs and not INFO log. >> >> Currently, for a single rpc call , it spews 20 lines when nothing out of >> ordinary happened. >> >> 2017/10/04-15:42:54.247 INFO RETURN_EVENT[000001DCD6DBA130]: >> OP_COMPLETE: tag:000001E6B6B60870 OK >> 2017/10/04-15:42:54.247 INFO >> grpc_call_start_batch(call=000001DCD713FBE8, ops=0000003515AFF510, nops=1, >> tag=000001E6B6B45180, reserved=0000000000000000) >> 2017/10/04-15:42:54.247 INFO ops[0]: RECV_CLOSE_ON_SERVER >> cancelled=000001E6B6B451F0 >> 2017/10/04-15:42:54.247 INFO >> grpc_completion_queue_next(cc=000001DCD6DBA130, deadline=gpr_timespec { >> tv_sec: 9223372036854775807, tv_nsec: 0, clock_type: 1 }, >> reserved=0000000000000000) >> 2017/10/04-15:42:54.247 INFO >> grpc_server_request_registered_call(server=000001DCD6CE1AA0, >> rmp=000001DCD7064460, call=000001E6B6B60A28, deadline=000001DDBA92F558, >> initial_metadata=000001DDBA92F590, optional_payload=000001E6B6B60A30, >> cq_bound_to_call=000001DCD6DBA130, cq_for_notification=000001DCD6DBA130, >> tag=000001E6B6B609F0) >> 2017/10/04-15:42:54.247 INFO grpc_call_get_peer(000001DCD713FBE8) >> 2017/10/04-15:42:54.247 INFO grpc_call_get_peer(000001DCD713FBE8) >> 2017/10/04-15:42:54.263 INFO >> grpc_call_start_batch(call=000001DCD713FBE8, ops=000000351C4FE5E0, nops=3, >> tag=000001DDB9ADCCC8, reserved=0000000000000000) >> 2017/10/04-15:42:54.263 INFO ops[0]: SEND_INITIAL_METADATA(nil) >> 2017/10/04-15:42:54.263 INFO ops[1]: SEND_MESSAGE ptr=000001DCD6C06700 >> 2017/10/04-15:42:54.263 INFO ops[2]: SEND_STATUS_FROM_SERVER status=0 >> details=(null)(nil) >> 2017/10/04-15:42:54.263 INFO >> cq_end_op_for_next(exec_ctx=000000351C4FE528, cc=000001DCD6DBA130, >> tag=000001DDB9ADCCC8, error="No Error", done=00007FF6349AFA90, >> done_arg=000001DCD71413E8, storage=000001DCD71413F0) >> 2017/10/04-15:42:54.263 INFO >> cq_end_op_for_next(exec_ctx=000000351C4FE528, cc=000001DCD6DBA130, >> tag=000001E6B6B45180, error="No Error", done=00007FF6349AFA90, >> done_arg=000001DCD7141308, storage=000001DCD7141310) >> 2017/10/04-15:42:54.263 INFO RETURN_EVENT[000001DCD6DBA130]: >> OP_COMPLETE: tag:000001DDB9ADCCC8 OK >> 2017/10/04-15:42:54.263 INFO >> grpc_completion_queue_next(cc=000001DCD6DBA130, deadline=gpr_timespec { >> tv_sec: 9223372036854775807, tv_nsec: 0, clock_type: 1 }, >> reserved=0000000000000000) >> 2017/10/04-15:42:54.263 INFO RETURN_EVENT[000001DCD6DBA130]: >> OP_COMPLETE: tag:000001E6B6B45180 OK >> 2017/10/04-15:42:54.263 INFO >> grpc_completion_queue_next(cc=000001DCD6DBA130, deadline=gpr_timespec { >> tv_sec: 9223372036854775807, tv_nsec: 0, clock_type: 1 }, >> reserved=0000000000000000) >> 2017/10/04-15:42:54.264 INFO grpc_call_unref(c=000001DCD713FBE8) >> 2017/10/04-15:42:54.264 INFO >> grpc_metadata_array_destroy(array=000001DCD71403D8) >> 2017/10/04-15:42:54.264 INFO >> grpc_metadata_array_destroy(array=000001DDB9ADCB40) >> >> >> >> Does this seem like reasonable for INFO log level? >> >> How about increasing the granularity of log levels? For example, SPAM, >> TRACE, INFO, WARN, ERROR so that different logs are handled appropriately? >> >> Thanks. >> >> >> -- >> 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] <javascript:>. >> To post to this group, send email to [email protected] >> <javascript:>. >> 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/3475a2c9-c3fd-4321-84a7-a04df7707970%40googlegroups.com >> >> <https://groups.google.com/d/msgid/grpc-io/3475a2c9-c3fd-4321-84a7-a04df7707970%40googlegroups.com?utm_medium=email&utm_source=footer> >> . >> For more options, visit https://groups.google.com/d/optout. >> > -- 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/6a722dac-17fe-4c49-a71b-a3c1e3e3ce35%40googlegroups.com. For more options, visit https://groups.google.com/d/optout.
