This was also discussed on Stack Overflow <https://stackoverflow.com/questions/76950718/after-the-channel-is-created-it-takes-1000ms-to-transition-from-idel-state-to>. I filed https://github.com/grpc/grpc-java/issues/10517 for the delayed transition to CONNECTING. It won't change performance any, though.
On Fri, Aug 25, 2023 at 9:55 AM 'Sanjay Pujare' via grpc.io < grpc-io@googlegroups.com> wrote: > Oh, I didn't realize your grpc java version was so old. Good to know your > issue is resolved. > > On Fri, Aug 25, 2023 at 1:23 AM '邹会江' via grpc.io < > grpc-io@googlegroups.com> wrote: > >> Thanks! >> I upgrade the grpc-java version from 1.3.3 to 1.51.0, and the IDLE time >> is reduced from 1000ms to 300ms. >> >> 在2023年8月25日星期五 UTC+8 13:05:56<sanjay...@google.com> 写道: >> >>> Instead of modifying and using the jre/lib logging.properties file can >>> you try using one for your application alone as described in my previous >>> message (use Java property java.util.logging.config.file and so on)? >>> >>> On Wednesday, August 23, 2023 at 7:49:39 PM UTC-7 邹会江 wrote: >>> >>>> 1. I modified the logging.properties file under jre/lib: >>>> handlers=java.util.logging.ConsoleHandler >>>> io.grpc.ChannelLogger.level=FINEST >>>> io.grpc.level=FINEST >>>> io.netty.level=FINEST >>>> java.util.logging.ConsoleHandler.level=ALL >>>> >>>> java.util.logging.ConsoleHandler.formatter=java.util.logging.SimpleFormatter >>>> but grpc doesn't have any log output to the console. >>>> >>>> 在2023年8月24日星期四 UTC+8 02:32:08<Sanjay Pujare> 写道: >>>> >>>>> On Wed, Aug 23, 2023 at 1:37 AM '邹会江' via grpc.io < >>>>> grp...@googlegroups.com> wrote: >>>>> >>>>>> Sanjay Pujare: >>>>>> Thank you for your reply! >>>>>> 1. How do i enable trace logging? >>>>>> >>>>> >>>>> It uses java util logging so to enable using JAVA_OPTS: >>>>> >>>>> export JAVA_OPTS="-Djava.util.logging.config.file=/logging.properties" >>>>> >>>>> And in /logging.properties have this: >>>>> >>>>> handlers=java.util.logging.ConsoleHandler >>>>> io.grpc.ChannelLogger.level=FINEST >>>>> io.grpc.level=FINEST >>>>> io.netty.level=FINEST >>>>> java.util.logging.ConsoleHandler.level=ALL >>>>> >>>>> java.util.logging.ConsoleHandler.formatter=java.util.logging.SimpleFormatter >>>>> >>>>> Or you can tweak it to your liking. >>>>> >>>>> >>>>>> 2. DNS resolution,TLS hanshake and TCP connection.In this case,the >>>>>> state of channel should be CONNECTING? >>>>> >>>>> >>>>> Yes. >>>>> >>>>> >>>>>> Therefore,the TCP connectio only affects the CONNECTING time, but not >>>>>> the IDLE time. >>>>>> >>>>> >>>>> Not sure I understand this comment/question. But when it is trying to >>>>> establish the TCP connection, yes the status is CONNECTING >>>>> >>>>> >>>>>> >>>>>> 在2023年8月23日星期三 UTC+8 14:23:02<Sanjay Pujare> 写道: >>>>>> >>>>>>> Most of the time is spent in IDLE -> CONNECTING transition. From >>>>>>> this doc >>>>>>> https://github.com/grpc/grpc/blob/master/doc/connectivity-semantics-and-api.md >>>>>>> which says for CONNECTING >>>>>>> >>>>>>> CONNECTING: The channel is trying to establish a connection and is >>>>>>> waiting to make progress on one of the steps involved in name >>>>>>> resolution, >>>>>>> TCP connection establishment or TLS handshake. This may be used as the >>>>>>> initial state for channels upon creation. >>>>>>> >>>>>>> DNS resolution and TLS handshake (since you are not calling >>>>>>> usePlaintext() on the builder) are possible culprits. Even TCP >>>>>>> connection >>>>>>> establishment is a possibility depending on where the target is. If you >>>>>>> enable trace logging you might be able to figure out. >>>>>>> >>>>>>> On Tue, Aug 22, 2023 at 10:08 PM '邹会江' via grpc.io < >>>>>>> grp...@googlegroups.com> wrote: >>>>>>> >>>>>>>> Thank you for your reply! >>>>>>>> 1. The first time: >>>>>>>> The transition from idle state to connecting takes: 3377 ms, >>>>>>>> The transition from idle state to ready takes: 3679 ms >>>>>>>> 2. The second time: >>>>>>>> The transition from idle state to connecting takes: 1643 ms, >>>>>>>> The transition from idle state to ready takes: 1797 ms >>>>>>>> 3.The third time: >>>>>>>> The transition from idle state to connecting takes: 1019 ms, >>>>>>>> The transition from idle state to ready takes: 1049 ms >>>>>>>> 4. What is my enviroment? >>>>>>>> MacBook Pro (16-inch, 2019) >>>>>>>> 2.6 GHz 6 core Intel Core i7 >>>>>>>> 16 GB 2667 MHz DDR4 >>>>>>>> >>>>>>>> 在2023年8月23日星期三 UTC+8 04:31:28<Larry Safran> 写道: >>>>>>>> >>>>>>>>> Another question is whether this is the same the second time you >>>>>>>>> create a channel. The first time, the JVM may be taking time doing >>>>>>>>> class >>>>>>>>> loading. >>>>>>>>> >>>>>>>>> On Tue, Aug 22, 2023 at 8:41 AM 'Yuri Golobokov' via grpc.io < >>>>>>>>> grp...@googlegroups.com> wrote: >>>>>>>>> >>>>>>>>>> Hello, >>>>>>>>>> What is the round-trip time? How much time does DNS resolution >>>>>>>>>> take? >>>>>>>>>> >>>>>>>>>> On Tuesday, August 22, 2023 at 12:02:21 AM UTC-7 邹会江 wrote: >>>>>>>>>> >>>>>>>>>>> ### JAVA Code >>>>>>>>>>> >>>>>>>>>>> ``` >>>>>>>>>>> channel = >>>>>>>>>>> ManagedChannelBuilder.forTarget(param.getTarget()).build(); >>>>>>>>>>> long channelStart = System.currentTimeMillis(); >>>>>>>>>>> asyncStub = ASRRouteGrpc.newStub(channel); >>>>>>>>>>> asrResponseStreamObserver = new >>>>>>>>>>> ASRResponseStreamObserver(speechTranscriberListener); >>>>>>>>>>> requestObserver = >>>>>>>>>>> asyncStub.route(asrResponseStreamObserver); >>>>>>>>>>> RouteRequest requestConf = newRequestHead(param); >>>>>>>>>>> traceId = requestConf.getAsrConfig().getTraceId(); >>>>>>>>>>> ConnectivityState currentChannelState = >>>>>>>>>>> channel.getState(true); >>>>>>>>>>> while (currentChannelState != >>>>>>>>>>> ConnectivityState.READY) { >>>>>>>>>>> CountDownLatch latchUntilChannelReady = new >>>>>>>>>>> CountDownLatch(1); >>>>>>>>>>> >>>>>>>>>>> channel.notifyWhenStateChanged(currentChannelState, >>>>>>>>>>> latchUntilChannelReady::countDown); >>>>>>>>>>> latchUntilChannelReady.await(); >>>>>>>>>>> currentChannelState = channel.getState(true); >>>>>>>>>>> if (currentChannelState == >>>>>>>>>>> ConnectivityState.CONNECTING) { >>>>>>>>>>> long channelConnecting = >>>>>>>>>>> System.currentTimeMillis(); >>>>>>>>>>> LOGGER.info("The transition from idle state >>>>>>>>>>> to connecting takes: {} ms", channelConnecting - channelStart); >>>>>>>>>>> } >>>>>>>>>>> } >>>>>>>>>>> long channelReady = System.currentTimeMillis(); >>>>>>>>>>> if (LOGGER.isInfoEnabled()) { >>>>>>>>>>> LOGGER.info("Trace id: {}, channel start time: >>>>>>>>>>> {}, channel ready time: {}, creating channel takes: {} ms", traceId, >>>>>>>>>>> channelStart, channelReady, >>>>>>>>>>> channelReady - channelStart); >>>>>>>>>>> } >>>>>>>>>>> ``` >>>>>>>>>>> ### LOGGER >>>>>>>>>>> >>>>>>>>>>> ``` >>>>>>>>>>> 2023-08-22 14:12:34,816 INFO client.ASRClient - The transition >>>>>>>>>>> from idle state to connecting takes: 1009 ms >>>>>>>>>>> 2023-08-22 14:12:34,841 INFO client.ASRClient - Trace id: >>>>>>>>>>> 6afd2c67-e8c5-4cea-bd5c-4b82591a52aa, channel start time: >>>>>>>>>>> 1692684753807, >>>>>>>>>>> channel ready time: 1692684754841, creating channel takes: 1034 ms >>>>>>>>>>> ``` >>>>>>>>>>> ### Description >>>>>>>>>>> #### code logic >>>>>>>>>>> 1. first create channel >>>>>>>>>>> 2. mark a time stamp(channelStart) after the channel is created >>>>>>>>>>> 3. get the state of channel ,the state is IDEL >>>>>>>>>>> 4. when the state of channel changes from IDEL to >>>>>>>>>>> CONNECTING,mark a time stamp(channelConnecting) >>>>>>>>>>> 5. when the state of channel changes from CONNECTING to READY, >>>>>>>>>>> mark a time stamp(channelReady) >>>>>>>>>>> >>>>>>>>>>> #### Log info >>>>>>>>>>> 1. It takes 1009ms for channel from IDLE state to CONNECTING >>>>>>>>>>> state. >>>>>>>>>>> 2. It takes 25ms for channel from CONNECTIONG state to READY >>>>>>>>>>> state. >>>>>>>>>>> ### What's i supposed >>>>>>>>>>> 1. Does it take too long for a channel to change from IDLE to >>>>>>>>>>> CONNECTING? >>>>>>>>>>> 2. I want to reduce the time it takes for a channel to go from >>>>>>>>>>> IDLE to CONNECTING. >>>>>>>>>>> >>>>>>>>>> -- >>>>>>>>>> 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+u...@googlegroups.com. >>>>>>>>>> To view this discussion on the web visit >>>>>>>>>> https://groups.google.com/d/msgid/grpc-io/8f2a15b8-1541-422e-ad66-9a5778e53882n%40googlegroups.com >>>>>>>>>> <https://groups.google.com/d/msgid/grpc-io/8f2a15b8-1541-422e-ad66-9a5778e53882n%40googlegroups.com?utm_medium=email&utm_source=footer> >>>>>>>>>> . >>>>>>>>>> >>>>>>>>> -- >>>>>>>> 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+u...@googlegroups.com. >>>>>>>> >>>>>>> To view this discussion on the web visit >>>>>>>> https://groups.google.com/d/msgid/grpc-io/8901e7bd-b684-462f-bf88-3607b6b01713n%40googlegroups.com >>>>>>>> <https://groups.google.com/d/msgid/grpc-io/8901e7bd-b684-462f-bf88-3607b6b01713n%40googlegroups.com?utm_medium=email&utm_source=footer> >>>>>>>> . >>>>>>>> >>>>>>> -- >>>>>> 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+u...@googlegroups.com. >>>>>> >>>>> To view this discussion on the web visit >>>>>> https://groups.google.com/d/msgid/grpc-io/76f2be33-959a-4bf3-9405-1b1748ba3ec0n%40googlegroups.com >>>>>> <https://groups.google.com/d/msgid/grpc-io/76f2be33-959a-4bf3-9405-1b1748ba3ec0n%40googlegroups.com?utm_medium=email&utm_source=footer> >>>>>> . >>>>>> >>>>> -- >> 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/421ab865-34bd-4753-99e9-01286cc513dbn%40googlegroups.com >> <https://groups.google.com/d/msgid/grpc-io/421ab865-34bd-4753-99e9-01286cc513dbn%40googlegroups.com?utm_medium=email&utm_source=footer> >> . >> > -- > 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/CA%2BPad6igrZcg4PO8gCjZSiDhaNxgwJ7EY8a4uU_vNSXTx3B7KQ%40mail.gmail.com > <https://groups.google.com/d/msgid/grpc-io/CA%2BPad6igrZcg4PO8gCjZSiDhaNxgwJ7EY8a4uU_vNSXTx3B7KQ%40mail.gmail.com?utm_medium=email&utm_source=footer> > . > -- 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/CA%2B4M1oNz%3DuWNjCGyGeoQYKd89466kVMEbDHWY6N5rG4X7VF9Zg%40mail.gmail.com.