You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@solr.apache.org by "Shubanker (Jira)" <ji...@apache.org> on 2022/11/03 05:18:00 UTC
[jira] [Commented] (SOLR-16350) http response is delayed when solr is running in slow/restricted network environment
[ https://issues.apache.org/jira/browse/SOLR-16350?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17628120#comment-17628120 ]
Shubanker commented on SOLR-16350:
----------------------------------
[~krisden] Yes I did try accessing it over 127.0.0.1, the delay is not while making a connection to SOLR server but rather SOLR processing internally.
I saved the log of a simple GET Request of _/solr/admin/cores?wt=json_ and here is the part of log where you can see the time difference at
{_}QueuedThreadPool ran CEP:SocketChannelEndPoint@1177a867{_}:
{quote}2022-08-23 10:46:54.516 DEBUG (qtp156710276-24) [] o.e.j.i.ChannelEndPoint changeInterests p=false 0->1 for SocketChannelEndPoint@1177a867\{l=/172.17.0.2:8983,r=/172.17.0.1:63578,OPEN,fill=FI,flush=-,to=0/120000}{io=0/1,kio=0,kro=1}->HttpConnection@3c82c535[p=HttpParser\{s=START,0 of -1},g=HttpGenerator@28258fd1\{s=START}]=>HttpChannelOverHttp@a882b5b\{s=HttpChannelState@1d440803{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0}
2022-08-23 10:46:54.517 DEBUG (qtp156710276-24) [] o.e.j.i.ManagedSelector Queued change lazy=false org.eclipse.jetty.io.ChannelEndPoint$$Lambda$684/0x0000000800fc3ba0@67447191 on ManagedSelector@a5bbaec\{STARTED} id=1 keys=1 selected=0 updates=0
2022-08-23 10:46:54.517 DEBUG (qtp156710276-24) [] o.e.j.i.ManagedSelector Wakeup on submit ManagedSelector@a5bbaec\{STARTED} id=1 keys=1 selected=0 updates=1
2022-08-23 10:46:54.517 DEBUG (qtp156710276-19) [] o.e.j.i.ManagedSelector Selector sun.nio.ch.EPollSelectorImpl@373889ae woken with none selected
2022-08-23 10:46:54.517 DEBUG (qtp156710276-19) [] o.e.j.i.ManagedSelector Selector sun.nio.ch.EPollSelectorImpl@373889ae woken up from select, 0/0/1 selected
2022-08-23 10:46:54.517 DEBUG (qtp156710276-19) [] o.e.j.i.ManagedSelector Selector sun.nio.ch.EPollSelectorImpl@373889ae processing 0 keys, 1 updates
2022-08-23 10:46:54.517 DEBUG (qtp156710276-19) [] o.e.j.i.ManagedSelector updateable 1
2022-08-23 10:46:54.517 DEBUG (qtp156710276-19) [] o.e.j.i.ManagedSelector update org.eclipse.jetty.io.ChannelEndPoint$$Lambda$684/0x0000000800fc3ba0@67447191
2022-08-23 10:46:54.517 DEBUG (qtp156710276-19) [] o.e.j.i.ChannelEndPoint Key interests updated 0 -> 1 on SocketChannelEndPoint@1177a867\{l=/172.17.0.2:8983,r=/172.17.0.1:63578,OPEN,fill=FI,flush=-,to=1/120000}{io=1/1,kio=1,kro=1}->HttpConnection@3c82c535[p=HttpParser\{s=START,0 of -1},g=HttpGenerator@28258fd1\{s=START}]=>HttpChannelOverHttp@a882b5b\{s=HttpChannelState@1d440803{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0}
2022-08-23 10:46:54.517 DEBUG (qtp156710276-19) [] o.e.j.i.ManagedSelector updates 0
2022-08-23 10:46:54.517 DEBUG (qtp156710276-19) [] o.e.j.i.ManagedSelector Selector sun.nio.ch.EPollSelectorImpl@373889ae waiting with 1 keys
2022-08-23 10:46:54.518 DEBUG (qtp156710276-24) [] o.e.j.s.HttpConnection HttpConnection@3c82c535::SocketChannelEndPoint@1177a867\{l=/172.17.0.2:8983,r=/172.17.0.1:63578,OPEN,fill=FI,flush=-,to=1/120000}{io=1/1,kio=1,kro=1}->HttpConnection@3c82c535[p=HttpParser\{s=START,0 of -1},g=HttpGenerator@28258fd1\{s=START}]=>HttpChannelOverHttp@a882b5b\{s=HttpChannelState@1d440803{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0} onFillable exit HttpChannelState@1d440803\{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0} null
2022-08-23 10:46:54.518 DEBUG (qtp156710276-24) [] o.e.j.u.t.QueuedThreadPool ran CEP:SocketChannelEndPoint@1177a867\{l=/172.17.0.2:8983,r=/172.17.0.1:63578,OPEN,fill=FI,flush=-,to=2/120000}{io=1/1,kio=1,kro=1}->HttpConnection@3c82c535[p=HttpParser\{s=START,0 of -1},g=HttpGenerator@28258fd1\{s=START}]=>HttpChannelOverHttp@a882b5b\{s=HttpChannelState@1d440803{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0}:runFillable:BLOCKING in InstrumentedQueuedThreadPool[qtp156710276]@9573584\{STARTED,10<=10<=10000,i=4,r=-1,q=0}[ReservedThreadExecutor@2aa7399c\{reserved=1/6,pending=0}]
2022-08-23 10:47:01.442 DEBUG (qtp156710276-19) [] o.e.j.i.ManagedSelector Selector sun.nio.ch.EPollSelectorImpl@373889ae woken up from select, 1/1/1 selected
2022-08-23 10:47:01.442 DEBUG (qtp156710276-19) [] o.e.j.i.ManagedSelector Selector sun.nio.ch.EPollSelectorImpl@373889ae processing 1 keys, 0 updates
2022-08-23 10:47:01.442 DEBUG (qtp156710276-19) [] o.e.j.i.ManagedSelector selected 1 channel=java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8983 remote=/172.17.0.1:63578], selector=sun.nio.ch.EPollSelectorImpl@373889ae, interestOps=1, readyOps=1 SocketChannelEndPoint@1177a867\{l=/172.17.0.2:8983,r=/172.17.0.1:63578,OPEN,fill=FI,flush=-,to=6948/120000}{io=1/1,kio=1,kro=1}->HttpConnection@3c82c535[p=HttpParser\{s=START,0 of -1},g=HttpGenerator@28258fd1\{s=START}]=>HttpChannelOverHttp@a882b5b\{s=HttpChannelState@1d440803{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0}
2022-08-23 10:47:01.443 DEBUG (qtp156710276-19) [] o.e.j.i.ChannelEndPoint onSelected 1->0 r=true w=false for SocketChannelEndPoint@1177a867\{l=/172.17.0.2:8983,r=/172.17.0.1:63578,OPEN,fill=FI,flush=-,to=6948/120000}{io=1/0,kio=1,kro=1}->HttpConnection@3c82c535[p=HttpParser\{s=START,0 of -1},g=HttpGenerator@28258fd1\{s=START}]=>HttpChannelOverHttp@a882b5b\{s=HttpChannelState@1d440803{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0}
2022-08-23 10:47:01.443 DEBUG (qtp156710276-19) [] o.e.j.i.ChannelEndPoint task CEP:SocketChannelEndPoint@1177a867\{l=/172.17.0.2:8983,r=/172.17.0.1:63578,OPEN,fill=FI,flush=-,to=6949/120000}{io=1/0,kio=1,kro=1}->HttpConnection@3c82c535[p=HttpParser\{s=START,0 of -1},g=HttpGenerator@28258fd1\{s=START}]=>HttpChannelOverHttp@a882b5b\{s=HttpChannelState@1d440803{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0}:runFillable:BLOCKING
2022-08-23 10:47:01.443 DEBUG (qtp156710276-19) [] o.e.j.u.t.ReservedThreadExecutor ReservedThreadExecutor@2aa7399c\{reserved=1/6,pending=0} tryExecute EatWhatYouKill@708f018e/SelectorProducer@19a31b9d/PRODUCING/p=false/InstrumentedQueuedThreadPool[qtp156710276]@9573584\{STARTED,10<=10<=10000,i=5,r=-1,q=0}[ReservedThreadExecutor@2aa7399c\{reserved=1/6,pending=0}][pc=0,pic=0,pec=1,epc=0]@2022-08-23T10:47:01.443729322Z
2022-08-23 10:47:01.443 DEBUG (qtp156710276-19) [] o.e.j.u.t.ReservedThreadExecutor ReservedThreadExecutor@2aa7399c\{reserved=0/6,pending=1} startReservedThread p=1
2022-08-23 10:47:01.444 DEBUG (qtp156710276-19) [] o.e.j.u.t.QueuedThreadPool queue ReservedThread@3ee5c86f\{PENDING,thread=null} startThread=0
2022-08-23 10:47:01.444 DEBUG (qtp156710276-19) [] o.e.j.u.t.s.EatWhatYouKill EatWhatYouKill@708f018e/SelectorProducer@19a31b9d/IDLE/p=true/InstrumentedQueuedThreadPool[qtp156710276]@9573584\{STARTED,10<=10<=10000,i=4,r=-1,q=0}[ReservedThreadExecutor@2aa7399c\{reserved=0/6,pending=1}][pc=0,pic=0,pec=1,epc=0]@2022-08-23T10:47:01.444120052Z m=EXECUTE_PRODUCE_CONSUME t=CEP:SocketChannelEndPoint@1177a867\{l=/172.17.0.2:8983,r=/172.17.0.1:63578,OPEN,fill=FI,flush=-,to=6950/120000}{io=1/0,kio=1,kro=1}->HttpConnection@3c82c535[p=HttpParser\{s=START,0 of -1},g=HttpGenerator@28258fd1\{s=START}]=>HttpChannelOverHttp@a882b5b\{s=HttpChannelState@1d440803{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0}:runFillable:BLOCKING/BLOCKING
2022-08-23 10:47:01.444 DEBUG (qtp156710276-25) [] o.e.j.u.t.QueuedThreadPool run ReservedThread@3ee5c86f\{PENDING,thread=null} in InstrumentedQueuedThreadPool[qtp156710276]@9573584\{STARTED,10<=10<=10000,i=4,r=-1,q=0}[ReservedThreadExecutor@2aa7399c\{reserved=0/6,pending=1}]
2022-08-23 10:47:01.444 DEBUG (qtp156710276-23) [] o.e.j.u.t.ReservedThreadExecutor ReservedThread@1064c9f1\{RESERVED,thread=Thread[qtp156710276-23,5,main]} task=EatWhatYouKill@708f018e/SelectorProducer@19a31b9d/IDLE/p=true/InstrumentedQueuedThreadPool[qtp156710276]@9573584\{STARTED,10<=10<=10000,i=4,r=-1,q=0}[ReservedThreadExecutor@2aa7399c\{reserved=0/6,pending=1}][pc=0,pic=0,pec=1,epc=1]@2022-08-23T10:47:01.444537283Z ReservedThreadExecutor@2aa7399c\{reserved=0/6,pending=1}
2022-08-23 10:47:01.444 DEBUG (qtp156710276-23) [] o.e.j.u.t.s.EatWhatYouKill EatWhatYouKill@708f018e/SelectorProducer@19a31b9d/IDLE/p=true/InstrumentedQueuedThreadPool[qtp156710276]@9573584\{STARTED,10<=10<=10000,i=4,r=-1,q=0}[ReservedThreadExecutor@2aa7399c\{reserved=1/6,pending=0}][pc=0,pic=0,pec=1,epc=1]@2022-08-23T10:47:01.444714142Z tryProduce true
2022-08-23 10:47:01.444 DEBUG (qtp156710276-23) [] o.e.j.i.ManagedSelector updateable 0
2022-08-23 10:47:01.445 DEBUG (qtp156710276-23) [] o.e.j.i.ManagedSelector updates 0{quote}
> http response is delayed when solr is running in slow/restricted network environment
> ------------------------------------------------------------------------------------
>
> Key: SOLR-16350
> URL: https://issues.apache.org/jira/browse/SOLR-16350
> Project: Solr
> Issue Type: Bug
> Security Level: Public(Default Security Level. Issues are Public)
> Components: Admin UI
> Affects Versions: 9.0
> Environment: !image-2022-08-23-09-56-45-250.png|width=327,height=170!
> restrict/delay internet and DNS resolution time.
> Reporter: Shubanker
> Priority: Major
> Attachments: image-2022-08-23-09-56-45-250.png, image-2022-08-23-09-59-25-775.png, image-2022-08-23-10-01-40-456.png, image-2022-08-23-10-03-45-870.png
>
>
> While trying to setup SOLR 9 I noticed the response takes longer to complete if the internet is slow/restricted.
> I tried replicating in local by delaying DNS response and the request started taking over 4s while the query itself (QTime) is faster.
> !image-2022-08-23-10-03-45-870.png|width=429,height=150!
> !image-2022-08-23-09-59-25-775.png|width=301,height=188!
> even the static files of Admin UI take too long to load.
> related StackOverflow [question|https://stackoverflow.com/questions/73444575/solr-9-http-response-time-is-very-slow-while-query-itself-is-fast].
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
---------------------------------------------------------------------
To unsubscribe, e-mail: issues-unsubscribe@solr.apache.org
For additional commands, e-mail: issues-help@solr.apache.org