search

apache / solr-operator

Official Kubernetes operator for Apache Solr
https://solr.apache.org/operator
Apache License 2.0
243 stars 112 forks source link

Create Collection fails after Upgrade #627

Closed brickpattern closed 9 months ago

brickpattern commented 9 months ago

Setup: K8S cluster: AWS EKS 1.27 Solr Operator : 0.7.1 helm chart Solr cloud version: 9.3 ZK : inbuilt w/operator Nodes: 3 solr nodes ( pod solrcloud-0, solrcloud-1, solrcloud-2)

Cluster has been operational with a stanard collection setup of 1 shard : 3 replica .
Data was distributed evenly across solr nodes and solrcloud-0 being the leader. Performed an upgrade via "helm upgrade solr apache-solr/solr --version 0.7.1 --reuse-values --set image.tag=xx" This caused solrcloud-1 upgrade n recycled , followed by solrcloud-2 pod and followed by solrcloud-0 pod. By the time solrcloud-0 pod came up , the data was distributed within other 2 pods. After the upgrade, attempting to CREATE collection via curl v2 api endpoint. The collection create request timed out. Able to see the collection "grocery" in the Graph and that collection never comes up and gets "auto-cleaned" (collection disappears after a while)

See image ... grocery is the collection created after the upgrade . Other 2 existed before the upgrade.

image
brickpattern commented 9 months ago

the upgrade strategy used was Managed (which delegates the upgrades to operator)

HoustonPutman commented 9 months ago

Could you provide the Solr logs? The operator wouldn't be preventing the collection from being created, so it has to be something on the Solr side.

brickpattern commented 9 months ago

lot of logs. copying the just around the time frame i hit the create api


2023-09-21 15:45:28.561 DEBUG (qtp1479696465-21) [] o.e.j.s.HttpInput reopen HttpInput@1571163736 cs=HttpChannelState@11cf8c6{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0} cp=org.eclipse.jetty.server.BlockingContentProducer@69831042 eof=false
2023-09-21 15:45:28.561 DEBUG (qtp1479696465-21) [] o.e.j.s.BlockingContentProducer reopening org.eclipse.jetty.server.BlockingContentProducer@69831042
2023-09-21 15:45:28.561 DEBUG (qtp1479696465-21) [] o.e.j.s.AsyncContentProducer reopening AsyncContentProducer@409b7d86[r=null,t=null,i=null,error=false,c=HttpChannelOverHttp@6199d558{s=HttpChannelState@11cf8c6{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}]
2023-09-21 15:45:28.561 DEBUG (qtp1479696465-21) [] o.e.j.s.HttpChannel REQUEST for /solr/admin/collections?action=CREATE&name=xx.xy&numShards=1&replicationFactor=3&autoAddReplicas=true on HttpChannelOverHttp@6199d558{s=HttpChannelState@11cf8c6{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=http://localhost:8983/solr/admin/collections?action=CREATE&name=xx.xy&numShards=1&replicationFactor=3&autoAddReplicas=true,age=0}
GET /solr/admin/collections?action=CREATE&name=xx.xy&numShards=1&replicationFactor=3&autoAddReplicas=true HTTP/1.1
Host: localhost:8983
User-Agent: curl/8.1.2
Accept: */*

2023-09-21 15:45:28.561 DEBUG (qtp1479696465-21) [] o.e.j.s.HttpConnection HttpConnection@7382cbf::SocketChannelEndPoint@4cde13df[{l=/127.0.0.1:8983,r=/127.0.0.1:33236,OPEN,fill=-,flush=-,to=0/120000}{io=0/0,kio=0,kro=1}]->[HttpConnection@7382cbf[p=HttpParser{s=CONTENT,0 of -1},g=HttpGenerator@14d8b659{s=START}]=>HttpChannelOverHttp@6199d558{s=HttpChannelState@11cf8c6{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=http://localhost:8983/solr/admin/collections?action=CREATE&name=xx.xy&numShards=1&replicationFactor=3&autoAddReplicas=true,age=0}] parsed true HttpParser{s=CONTENT,0 of -1}
2023-09-21 15:45:28.561 DEBUG (qtp1479696465-21) [] o.e.j.s.HttpConnection releaseRequestBuffer HttpConnection@7382cbf::SocketChannelEndPoint@4cde13df[{l=/127.0.0.1:8983,r=/127.0.0.1:33236,OPEN,fill=-,flush=-,to=0/120000}{io=0/0,kio=0,kro=1}]->[HttpConnection@7382cbf[p=HttpParser{s=CONTENT,0 of -1},g=HttpGenerator@14d8b659{s=START}]=>HttpChannelOverHttp@6199d558{s=HttpChannelState@11cf8c6{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=http://localhost:8983/solr/admin/collections?action=CREATE&name=xx.xy&numShards=1&replicationFactor=3&autoAddReplicas=true,age=0}]
2023-09-21 15:45:28.561 DEBUG (qtp1479696465-21) [] o.e.j.s.HttpChannel handle http://localhost:8983/solr/admin/collections?action=CREATE&name=xx.xy&numShards=1&replicationFactor=3&autoAddReplicas=true HttpChannelOverHttp@6199d558{s=HttpChannelState@11cf8c6{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=http://localhost:8983/solr/admin/collections?action=CREATE&name=xx.xy&numShards=1&replicationFactor=3&autoAddReplicas=true,age=0} 
2023-09-21 15:45:28.561 DEBUG (qtp1479696465-21) [] o.e.j.s.HttpChannelState handling HttpChannelState@11cf8c6{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0}
2023-09-21 15:45:28.561 DEBUG (qtp1479696465-21) [] o.e.j.s.HttpChannel action DISPATCH HttpChannelOverHttp@6199d558{s=HttpChannelState@11cf8c6{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=HANDLING,uri=http://localhost:8983/solr/admin/collections?action=CREATE&name=xx.xy&numShards=1&replicationFactor=3&autoAddReplicas=true,age=0}
2023-09-21 15:45:28.561 DEBUG (qtp1479696465-21) [] o.e.j.s.Server REQUEST GET /solr/admin/collections ?action=CREATE&name=xx.xy&numShards=1&replicationFactor=3&autoAddReplicas=true on HttpChannelOverHttp@6199d558{s=HttpChannelState@11cf8c6{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=HANDLING,uri=http://localhost:8983/solr/admin/collections?action=CREATE&name=xx.xy&numShards=1&replicationFactor=3&autoAddReplicas=true,age=0}
2023-09-21 15:45:28.561 DEBUG (qtp1479696465-21) [] o.e.j.s.h.g.GzipHandler GzipHandler@39e3ea78{STARTED,min=2048,inflate=0} handle Request(GET http://localhost:8983/solr/admin/collections?action=CREATE&name=xx.xy&numShards=1&replicationFactor=3&autoAddReplicas=true)@18ff926d in null
2023-09-21 15:45:28.561 DEBUG (qtp1479696465-21) [] o.e.j.r.h.RuleContainer applied org.eclipse.jetty.rewrite.handler.HeaderPatternRule[ht][/solr/*][Content-Security-Policy,default-src 'none'; base-uri 'none'; connect-src 'self'; form-action 'self'; font-src 'self'; frame-ancestors 'none'; img-src 'self' data:; media-src 'self'; style-src 'self' 'unsafe-inline'; script-src 'self'; worker-src 'self';]
2023-09-21 15:45:28.561 DEBUG (qtp1479696465-21) [] o.e.j.r.h.RuleContainer rewrote /solr/admin/collections to /solr/admin/collections
2023-09-21 15:45:28.561 DEBUG (qtp1479696465-21) [] o.e.j.r.h.RuleContainer applied org.eclipse.jetty.rewrite.handler.HeaderPatternRule[ht][/solr/*][X-Content-Type-Options,nosniff]
2023-09-21 15:45:28.561 DEBUG (qtp1479696465-21) [] o.e.j.r.h.RuleContainer rewrote /solr/admin/collections to /solr/admin/collections
2023-09-21 15:45:28.561 DEBUG (qtp1479696465-21) [] o.e.j.r.h.RuleContainer applied org.eclipse.jetty.rewrite.handler.HeaderPatternRule[ht][/solr/*][X-Frame-Options,SAMEORIGIN]
2023-09-21 15:45:28.561 DEBUG (qtp1479696465-21) [] o.e.j.r.h.RuleContainer rewrote /solr/admin/collections to /solr/admin/collections
2023-09-21 15:45:28.561 DEBUG (qtp1479696465-21) [] o.e.j.r.h.RuleContainer applied org.eclipse.jetty.rewrite.handler.HeaderPatternRule[ht][/solr/*][X-XSS-Protection,1; mode=block]
2023-09-21 15:45:28.561 DEBUG (qtp1479696465-21) [] o.e.j.r.h.RuleContainer rewrote /solr/admin/collections to /solr/admin/collections
2023-09-21 15:45:28.561 DEBUG (qtp1479696465-21) [] o.e.j.s.h.ContextHandler scope null||/solr/admin/collections @ o.e.j.w.WebAppContext@5aceec94{solr-jetty-context.xml,/solr,file:///opt/solr-9.3.0/server/solr-webapp/webapp/,AVAILABLE}{/opt/solr-9.3.0/server/solr-webapp/webapp}
2023-09-21 15:45:28.561 DEBUG (qtp1479696465-21) [] o.e.j.s.h.ContextHandler context=/solr||/admin/collections @ o.e.j.w.WebAppContext@5aceec94{solr-jetty-context.xml,/solr,file:///opt/solr-9.3.0/server/solr-webapp/webapp/,AVAILABLE}{/opt/solr-9.3.0/server/solr-webapp/webapp}
2023-09-21 15:45:28.561 DEBUG (qtp1479696465-21) [] o.e.j.s.ServletHandler servlet /solr|/admin/collections|null|ServletPathMapping{matchValue=, pattern=/, servletName=default, mappingMatch=DEFAULT, servletPath=/admin/collections, pathInfo=null} -> default==org.eclipse.jetty.servlet.DefaultServlet@5c13d641{jsp=null,order=0,inst=true,async=false,src=DESCRIPTOR:file:///opt/solr-9.3.0/server/etc/webdefault.xml,STARTED}
2023-09-21 15:45:28.561 DEBUG (qtp1479696465-21) [] o.e.j.s.ServletHandler chain=Chain@61deb5ad(SolrRequestFilter==org.apache.solr.servlet.SolrDispatchFilter@478530cb{inst=true,async=false,src=DESCRIPTOR:file:///opt/solr-9.3.0/server/solr-webapp/webapp/WEB-INF/web.xml})->ChainEnd@16cb8739(default==org.eclipse.jetty.servlet.DefaultServlet@5c13d641{jsp=null,order=0,inst=true,async=false,src=DESCRIPTOR:file:///opt/solr-9.3.0/server/etc/webdefault.xml,STARTED})
2023-09-21 15:45:28.562 DEBUG (qtp1479696465-21) [] o.a.s.h.a.CollectionsHandler Invoked Collection Action: create with params replicationFactor=3&autoAddReplicas=true&name=xx.xy&action=CREATE&numShards=1
2023-09-21 15:45:28.879 DEBUG (main-EventThread) [] o.a.s.c.c.SolrZkClient Submitting job to respond to event WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections
2023-09-21 15:45:28.879 DEBUG (main-EventThread) [] o.a.s.c.c.SolrZkClient Submitting job to respond to event WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections
2023-09-21 15:45:28.879 DEBUG (zkCallback-13-thread-15) [] o.a.s.c.c.ZkStateReader A collections change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections], has occurred - updating...
2023-09-21 15:45:28.880 DEBUG (zkCallback-13-thread-15) [] o.a.s.c.c.ZkStateReader clusterStateSet: interesting [0] watched [0] lazy [3] total [3]
2023-09-21 15:45:36.154 DEBUG (qtp1479696465-19-acceptor-0@39a8e2fa-ServerConnector@dcfda20{HTTP/1.1, (http/1.1, h2c)}{0.0.0.0:8983}) [] o.e.j.i.ManagedSelector Queued change lazy=false Accept@49c02283[java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8983 remote=/172.31.161.29:60862]] on ManagedSelector@2e40fdbd{STARTED} id=0 keys=0 selected=0 updates=0
2023-09-21 15:45:36.154 DEBUG (qtp1479696465-19-acceptor-0@39a8e2fa-ServerConnector@dcfda20{HTTP/1.1, (http/1.1, h2c)}{0.0.0.0:8983}) [] o.e.j.i.ManagedSelector Wakeup on submit ManagedSelector@2e40fdbd{STARTED} id=0 keys=0 selected=0 updates=1
2023-09-21 15:45:36.154 DEBUG (qtp1479696465-74) [] o.e.j.i.ManagedSelector Selector sun.nio.ch.EPollSelectorImpl@71d829dd woken with none selected
2023-09-21 15:45:36.154 DEBUG (qtp1479696465-74) [] o.e.j.i.ManagedSelector Selector sun.nio.ch.EPollSelectorImpl@71d829dd woken up from select, 0/0/0 selected
2023-09-21 15:45:36.154 DEBUG (qtp1479696465-74) [] o.e.j.i.ManagedSelector Selector sun.nio.ch.EPollSelectorImpl@71d829dd processing 0 keys, 1 updates
2023-09-21 15:45:36.154 DEBUG (qtp1479696465-74) [] o.e.j.i.ManagedSelector updateable 1
2023-09-21 15:45:36.154 DEBUG (qtp1479696465-74) [] o.e.j.i.ManagedSelector update Accept@49c02283[java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8983 remote=/172.31.161.29:60862]]
2023-09-21 15:45:36.154 DEBUG (qtp1479696465-74) [] o.e.j.u.t.QueuedThreadPool queue Accept@49c02283[java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8983 remote=/172.31.161.29:60862]] startThread=0
2023-09-21 15:45:36.154 DEBUG (qtp1479696465-74) [] o.e.j.i.ManagedSelector updates 0
2023-09-21 15:45:36.154 DEBUG (qtp1479696465-74) [] o.e.j.i.ManagedSelector Selector sun.nio.ch.EPollSelectorImpl@71d829dd waiting with 1 keys
2023-09-21 15:45:36.154 DEBUG (qtp1479696465-73) [] o.e.j.u.t.QueuedThreadPool run Accept@49c02283[java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8983 remote=/172.31.161.29:60862]] in InstrumentedQueuedThreadPool[qtp1479696465]@58326051{STARTED,10<=10<=10000,i=2,r=-1,t=-3899999ms,q=0}[ReservedThreadExecutor@15cee630{reserved=3/4,pending=0}]
2023-09-21 15:45:36.154 DEBUG (qtp1479696465-73) [] o.e.j.i.IdleTimeout Setting idle timeout 0 -> 120000 on SocketChannelEndPoint@4fc1d21c[{l=/172.31.160.255:8983,r=/172.31.161.29:60862,OPEN,fill=-,flush=-,to=0/120000}{io=0/0,kio=0,kro=0}]->[<null>]
2023-09-21 15:45:36.154 DEBUG (qtp1479696465-73) [] o.e.j.i.IdleTimeout SocketChannelEndPoint@4fc1d21c[{l=/172.31.160.255:8983,r=/172.31.161.29:60862,OPEN,fill=-,flush=-,to=0/120000}{io=0/0,kio=0,kro=0}]->[<null>] idle timeout check, elapsed: 0 ms, remaining: 120000 ms
2023-09-21 15:45:36.154 DEBUG (qtp1479696465-73) [] o.e.j.s.HttpChannel new HttpChannelOverHttp@2363ba04{s=HttpChannelState@216b805c{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0} -> SocketChannelEndPoint@4fc1d21c[{l=/172.31.160.255:8983,r=/172.31.161.29:60862,OPEN,fill=-,flush=-,to=0/120000}{io=0/0,kio=0,kro=0}]->[<null>],null,HttpChannelState@216b805c{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0}
2023-09-21 15:45:36.154 DEBUG (qtp1479696465-73) [] o.e.j.s.HttpConnection New HTTP Connection HttpConnection@592e7f12::SocketChannelEndPoint@4fc1d21c[{l=/172.31.160.255:8983,r=/172.31.161.29:60862,OPEN,fill=-,flush=-,to=0/120000}{io=0/0,kio=0,kro=0}]->[<null>]
2023-09-21 15:45:36.154 DEBUG (qtp1479696465-73) [] o.e.j.i.ManagedSelector Queued change lazy=true org.eclipse.jetty.io.ManagedSelector$$Lambda$722/0x00007fac4857f228@183e0719 on ManagedSelector@2e40fdbd{STARTED} id=0 keys=1 selected=0 updates=0
2023-09-21 15:45:36.154 DEBUG (qtp1479696465-73) [] o.e.j.i.AbstractEndPoint onOpen SocketChannelEndPoint@4fc1d21c[{l=/172.31.160.255:8983,r=/172.31.161.29:60862,OPEN,fill=-,flush=-,to=0/120000}{io=0/0,kio=0,kro=0}]->[HttpConnection@592e7f12[p=HttpParser{s=START,0 of -1},g=HttpGenerator@26b33d80{s=START}]=>HttpChannelOverHttp@2363ba04{s=HttpChannelState@216b805c{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}]
2023-09-21 15:45:36.154 DEBUG (qtp1479696465-73) [] o.e.j.i.AbstractConnection onOpen HttpConnection@592e7f12::SocketChannelEndPoint@4fc1d21c[{l=/172.31.160.255:8983,r=/172.31.161.29:60862,OPEN,fill=-,flush=-,to=0/120000}{io=0/0,kio=0,kro=0}]->[HttpConnection@592e7f12[p=HttpParser{s=START,0 of -1},g=HttpGenerator@26b33d80{s=START}]=>HttpChannelOverHttp@2363ba04{s=HttpChannelState@216b805c{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}]
2023-09-21 15:45:36.154 DEBUG (qtp1479696465-73) [] o.e.j.i.AbstractConnection fillInterested HttpConnection@592e7f12::SocketChannelEndPoint@4fc1d21c[{l=/172.31.160.255:8983,r=/172.31.161.29:60862,OPEN,fill=-,flush=-,to=0/120000}{io=0/0,kio=0,kro=0}]->[HttpConnection@592e7f12[p=HttpParser{s=START,0 of -1},g=HttpGenerator@26b33d80{s=START}]=>HttpChannelOverHttp@2363ba04{s=HttpChannelState@216b805c{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}]
2023-09-21 15:45:36.154 DEBUG (qtp1479696465-73) [] o.e.j.i.FillInterest interested FillInterest@5b27206a{ReadCallback@715b12f3{HttpConnection@592e7f12::SocketChannelEndPoint@4fc1d21c[{l=/172.31.160.255:8983,r=/172.31.161.29:60862,OPEN,fill=FI,flush=-,to=0/120000}{io=0/0,kio=0,kro=0}]->[HttpConnection@592e7f12[p=HttpParser{s=START,0 of -1},g=HttpGenerator@26b33d80{s=START}]=>HttpChannelOverHttp@2363ba04{s=HttpChannelState@216b805c{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}]}}
2023-09-21 15:45:36.154 DEBUG (qtp1479696465-73) [] o.e.j.i.SelectableChannelEndPoint changeInterests p=false 0->1 for SocketChannelEndPoint@4fc1d21c[{l=/172.31.160.255:8983,r=/172.31.161.29:60862,OPEN,fill=FI,flush=-,to=0/120000}{io=0/1,kio=0,kro=0}]->[HttpConnection@592e7f12[p=HttpParser{s=START,0 of -1},g=HttpGenerator@26b33d80{s=START}]=>HttpChannelOverHttp@2363ba04{s=HttpChannelState@216b805c{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}]
2023-09-21 15:45:36.154 DEBUG (qtp1479696465-73) [] o.e.j.i.ManagedSelector Queued change lazy=false org.eclipse.jetty.io.SelectableChannelEndPoint$$Lambda$716/0x00007fac485710e0@1935c50e on ManagedSelector@2e40fdbd{STARTED} id=0 keys=1 selected=0 updates=1
2023-09-21 15:45:36.154 DEBUG (qtp1479696465-73) [] o.e.j.i.ManagedSelector Wakeup on submit ManagedSelector@2e40fdbd{STARTED} id=0 keys=1 selected=0 updates=2
2023-09-21 15:45:36.154 DEBUG (qtp1479696465-73) [] o.e.j.i.ManagedSelector Created SocketChannelEndPoint@4fc1d21c[{l=/172.31.160.255:8983,r=/172.31.161.29:60862,OPEN,fill=FI,flush=-,to=0/120000}{io=0/1,kio=0,kro=0}]->[HttpConnection@592e7f12[p=HttpParser{s=START,0 of -1},g=HttpGenerator@26b33d80{s=START}]=>HttpChannelOverHttp@2363ba04{s=HttpChannelState@216b805c{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}]
2023-09-21 15:45:36.154 DEBUG (qtp1479696465-73) [] o.e.j.u.t.QueuedThreadPool ran Accept@49c02283[java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8983 remote=/172.31.161.29:60862]] in InstrumentedQueuedThreadPool[qtp1479696465]@58326051{STARTED,10<=10<=10000,i=2,r=-1,t=-3900000ms,q=0}[ReservedThreadExecutor@15cee630{reserved=3/4,pending=0}]
2023-09-21 15:45:36.154 DEBUG (qtp1479696465-73) [] o.e.j.u.t.QueuedThreadPool Evict skipped, no excess threads InstrumentedQueuedThreadPool[qtp1479696465]@58326051{STARTED,10<=10<=10000,i=3,r=-1,t=-3900000ms,q=0}[ReservedThreadExecutor@15cee630{reserved=3/4,pending=0}]
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-74) [] o.e.j.i.ManagedSelector Selector sun.nio.ch.EPollSelectorImpl@71d829dd woken with none selected
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-74) [] o.e.j.i.ManagedSelector Selector sun.nio.ch.EPollSelectorImpl@71d829dd woken up from select, 0/0/1 selected
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-74) [] o.e.j.i.ManagedSelector Selector sun.nio.ch.EPollSelectorImpl@71d829dd processing 0 keys, 2 updates
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-74) [] o.e.j.i.ManagedSelector updateable 2
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-74) [] o.e.j.i.ManagedSelector update org.eclipse.jetty.io.ManagedSelector$$Lambda$722/0x00007fac4857f228@183e0719
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-74) [] o.e.j.i.ManagedSelector update org.eclipse.jetty.io.SelectableChannelEndPoint$$Lambda$716/0x00007fac485710e0@1935c50e
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-74) [] o.e.j.i.SelectableChannelEndPoint Key interests updated 0 -> 1 on SocketChannelEndPoint@4fc1d21c[{l=/172.31.160.255:8983,r=/172.31.161.29:60862,OPEN,fill=FI,flush=-,to=0/120000}{io=1/1,kio=1,kro=0}]->[HttpConnection@592e7f12[p=HttpParser{s=START,0 of -1},g=HttpGenerator@26b33d80{s=START}]=>HttpChannelOverHttp@2363ba04{s=HttpChannelState@216b805c{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}]
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-74) [] o.e.j.i.ManagedSelector updates 0
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-74) [] o.e.j.i.ManagedSelector Selector sun.nio.ch.EPollSelectorImpl@71d829dd waiting with 1 keys
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-74) [] o.e.j.i.ManagedSelector Selector sun.nio.ch.EPollSelectorImpl@71d829dd woken up from select, 1/1/1 selected
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-19-acceptor-0@39a8e2fa-ServerConnector@dcfda20{HTTP/1.1, (http/1.1, h2c)}{0.0.0.0:8983}) [] o.e.j.i.ManagedSelector Queued change lazy=false Accept@56c52211[java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8983 remote=/172.31.161.29:60860]] on ManagedSelector@7b79ff1c{STARTED} id=1 keys=1 selected=0 updates=0
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-74) [] o.e.j.i.ManagedSelector Selector sun.nio.ch.EPollSelectorImpl@71d829dd processing 1 keys, 0 updates
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-19-acceptor-0@39a8e2fa-ServerConnector@dcfda20{HTTP/1.1, (http/1.1, h2c)}{0.0.0.0:8983}) [] o.e.j.i.ManagedSelector Wakeup on submit ManagedSelector@7b79ff1c{STARTED} id=1 keys=1 selected=0 updates=1
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-18) [] o.e.j.i.ManagedSelector Selector sun.nio.ch.EPollSelectorImpl@858e902 woken with none selected
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-18) [] o.e.j.i.ManagedSelector Selector sun.nio.ch.EPollSelectorImpl@858e902 woken up from select, 0/0/1 selected
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-18) [] o.e.j.i.ManagedSelector Selector sun.nio.ch.EPollSelectorImpl@858e902 processing 0 keys, 1 updates
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-18) [] o.e.j.i.ManagedSelector updateable 1
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-18) [] o.e.j.i.ManagedSelector update Accept@56c52211[java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8983 remote=/172.31.161.29:60860]]
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-18) [] o.e.j.u.t.QueuedThreadPool queue Accept@56c52211[java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8983 remote=/172.31.161.29:60860]] startThread=0
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-18) [] o.e.j.i.ManagedSelector updates 0
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-18) [] o.e.j.i.ManagedSelector Selector sun.nio.ch.EPollSelectorImpl@858e902 waiting with 2 keys
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-26) [] o.e.j.u.t.QueuedThreadPool run Accept@56c52211[java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8983 remote=/172.31.161.29:60860]] in InstrumentedQueuedThreadPool[qtp1479696465]@58326051{STARTED,10<=10<=10000,i=2,r=-1,t=-3900000ms,q=0}[ReservedThreadExecutor@15cee630{reserved=3/4,pending=0}]
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-26) [] o.e.j.i.IdleTimeout Setting idle timeout 0 -> 120000 on SocketChannelEndPoint@5bdc21c6[{l=/172.31.160.255:8983,r=/172.31.161.29:60860,OPEN,fill=-,flush=-,to=0/120000}{io=0/0,kio=0,kro=0}]->[<null>]
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-26) [] o.e.j.i.IdleTimeout SocketChannelEndPoint@5bdc21c6[{l=/172.31.160.255:8983,r=/172.31.161.29:60860,OPEN,fill=-,flush=-,to=0/120000}{io=0/0,kio=0,kro=0}]->[<null>] idle timeout check, elapsed: 0 ms, remaining: 120000 ms
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-26) [] o.e.j.s.HttpChannel new HttpChannelOverHttp@7f621f7b{s=HttpChannelState@796aaf{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0} -> SocketChannelEndPoint@5bdc21c6[{l=/172.31.160.255:8983,r=/172.31.161.29:60860,OPEN,fill=-,flush=-,to=0/120000}{io=0/0,kio=0,kro=0}]->[<null>],null,HttpChannelState@796aaf{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0}
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-26) [] o.e.j.s.HttpConnection New HTTP Connection HttpConnection@3ac0bced::SocketChannelEndPoint@5bdc21c6[{l=/172.31.160.255:8983,r=/172.31.161.29:60860,OPEN,fill=-,flush=-,to=0/120000}{io=0/0,kio=0,kro=0}]->[<null>]
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-26) [] o.e.j.i.ManagedSelector Queued change lazy=true org.eclipse.jetty.io.ManagedSelector$$Lambda$722/0x00007fac4857f228@287862 on ManagedSelector@7b79ff1c{STARTED} id=1 keys=2 selected=0 updates=0
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-26) [] o.e.j.i.AbstractEndPoint onOpen SocketChannelEndPoint@5bdc21c6[{l=/172.31.160.255:8983,r=/172.31.161.29:60860,OPEN,fill=-,flush=-,to=0/120000}{io=0/0,kio=0,kro=0}]->[HttpConnection@3ac0bced[p=HttpParser{s=START,0 of -1},g=HttpGenerator@6f5e26db{s=START}]=>HttpChannelOverHttp@7f621f7b{s=HttpChannelState@796aaf{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}]
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-26) [] o.e.j.i.AbstractConnection onOpen HttpConnection@3ac0bced::SocketChannelEndPoint@5bdc21c6[{l=/172.31.160.255:8983,r=/172.31.161.29:60860,OPEN,fill=-,flush=-,to=0/120000}{io=0/0,kio=0,kro=0}]->[HttpConnection@3ac0bced[p=HttpParser{s=START,0 of -1},g=HttpGenerator@6f5e26db{s=START}]=>HttpChannelOverHttp@7f621f7b{s=HttpChannelState@796aaf{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}]
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-74) [] o.e.j.i.ManagedSelector selected 1 channel=java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8983 remote=/172.31.161.29:60862], selector=sun.nio.ch.EPollSelectorImpl@71d829dd, interestOps=1, readyOps=1 SocketChannelEndPoint@4fc1d21c[{l=/172.31.160.255:8983,r=/172.31.161.29:60862,OPEN,fill=FI,flush=-,to=0/120000}{io=1/1,kio=1,kro=1}]->[HttpConnection@592e7f12[p=HttpParser{s=START,0 of -1},g=HttpGenerator@26b33d80{s=START}]=>HttpChannelOverHttp@2363ba04{s=HttpChannelState@216b805c{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}] 
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-26) [] o.e.j.i.AbstractConnection fillInterested HttpConnection@3ac0bced::SocketChannelEndPoint@5bdc21c6[{l=/172.31.160.255:8983,r=/172.31.161.29:60860,OPEN,fill=-,flush=-,to=0/120000}{io=0/0,kio=0,kro=0}]->[HttpConnection@3ac0bced[p=HttpParser{s=START,0 of -1},g=HttpGenerator@6f5e26db{s=START}]=>HttpChannelOverHttp@7f621f7b{s=HttpChannelState@796aaf{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}]
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-74) [] o.e.j.i.SelectableChannelEndPoint onSelected 1->0 r=true w=false for SocketChannelEndPoint@4fc1d21c[{l=/172.31.160.255:8983,r=/172.31.161.29:60862,OPEN,fill=FI,flush=-,to=0/120000}{io=1/0,kio=1,kro=1}]->[HttpConnection@592e7f12[p=HttpParser{s=START,0 of -1},g=HttpGenerator@26b33d80{s=START}]=>HttpChannelOverHttp@2363ba04{s=HttpChannelState@216b805c{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}]
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-26) [] o.e.j.i.FillInterest interested FillInterest@2439058d{ReadCallback@1b21e233{HttpConnection@3ac0bced::SocketChannelEndPoint@5bdc21c6[{l=/172.31.160.255:8983,r=/172.31.161.29:60860,OPEN,fill=FI,flush=-,to=0/120000}{io=0/0,kio=0,kro=0}]->[HttpConnection@3ac0bced[p=HttpParser{s=START,0 of -1},g=HttpGenerator@6f5e26db{s=START}]=>HttpChannelOverHttp@7f621f7b{s=HttpChannelState@796aaf{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}]}}
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-26) [] o.e.j.i.SelectableChannelEndPoint changeInterests p=false 0->1 for SocketChannelEndPoint@5bdc21c6[{l=/172.31.160.255:8983,r=/172.31.161.29:60860,OPEN,fill=FI,flush=-,to=0/120000}{io=0/1,kio=0,kro=0}]->[HttpConnection@3ac0bced[p=HttpParser{s=START,0 of -1},g=HttpGenerator@6f5e26db{s=START}]=>HttpChannelOverHttp@7f621f7b{s=HttpChannelState@796aaf{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}]
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-26) [] o.e.j.i.ManagedSelector Queued change lazy=false org.eclipse.jetty.io.SelectableChannelEndPoint$$Lambda$716/0x00007fac485710e0@5889725d on ManagedSelector@7b79ff1c{STARTED} id=1 keys=2 selected=0 updates=1
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-26) [] o.e.j.i.ManagedSelector Wakeup on submit ManagedSelector@7b79ff1c{STARTED} id=1 keys=2 selected=0 updates=2
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-74) [] o.e.j.i.SelectableChannelEndPoint task SocketChannelEndPoint@4fc1d21c[{l=/172.31.160.255:8983,r=/172.31.161.29:60862,OPEN,fill=FI,flush=-,to=0/120000}{io=1/0,kio=1,kro=1}]->[HttpConnection@592e7f12[p=HttpParser{s=START,0 of -1},g=HttpGenerator@26b33d80{s=START}]=>HttpChannelOverHttp@2363ba04{s=HttpChannelState@216b805c{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}]:runFillable:BLOCKING
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-74) [] o.e.j.u.t.ReservedThreadExecutor ReservedThreadExecutor@15cee630{reserved=3/4,pending=0} tryExecute org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy$$Lambda$417/0x00007fac4839dbd8@9a04ddc
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-26) [] o.e.j.i.ManagedSelector Created SocketChannelEndPoint@5bdc21c6[{l=/172.31.160.255:8983,r=/172.31.161.29:60860,OPEN,fill=FI,flush=-,to=0/120000}{io=0/1,kio=0,kro=0}]->[HttpConnection@3ac0bced[p=HttpParser{s=START,0 of -1},g=HttpGenerator@6f5e26db{s=START}]=>HttpChannelOverHttp@7f621f7b{s=HttpChannelState@796aaf{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}]
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-26) [] o.e.j.u.t.QueuedThreadPool ran Accept@56c52211[java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8983 remote=/172.31.161.29:60860]] in InstrumentedQueuedThreadPool[qtp1479696465]@58326051{STARTED,10<=10<=10000,i=2,r=-1,t=-3900001ms,q=0}[ReservedThreadExecutor@15cee630{reserved=2/4,pending=0}]
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-26) [] o.e.j.u.t.QueuedThreadPool Evict skipped, no excess threads InstrumentedQueuedThreadPool[qtp1479696465]@58326051{STARTED,10<=10<=10000,i=3,r=-1,t=-3900001ms,q=0}[ReservedThreadExecutor@15cee630{reserved=2/4,pending=0}]
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-18) [] o.e.j.i.ManagedSelector Selector sun.nio.ch.EPollSelectorImpl@858e902 woken with none selected
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-18) [] o.e.j.i.ManagedSelector Selector sun.nio.ch.EPollSelectorImpl@858e902 woken up from select, 0/0/2 selected
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-18) [] o.e.j.i.ManagedSelector Selector sun.nio.ch.EPollSelectorImpl@858e902 processing 0 keys, 2 updates
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-18) [] o.e.j.i.ManagedSelector updateable 2
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-18) [] o.e.j.i.ManagedSelector update org.eclipse.jetty.io.ManagedSelector$$Lambda$722/0x00007fac4857f228@287862
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-18) [] o.e.j.i.ManagedSelector update org.eclipse.jetty.io.SelectableChannelEndPoint$$Lambda$716/0x00007fac485710e0@5889725d
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-74) [] o.e.j.u.t.s.AdaptiveExecutionStrategy ss=EXECUTE_PRODUCE_CONSUME t=SocketChannelEndPoint@4fc1d21c[{l=/172.31.160.255:8983,r=/172.31.161.29:60862,OPEN,fill=FI,flush=-,to=0/120000}{io=1/0,kio=1,kro=1}]->[HttpConnection@592e7f12[p=HttpParser{s=START,0 of -1},g=HttpGenerator@26b33d80{s=START}]=>HttpChannelOverHttp@2363ba04{s=HttpChannelState@216b805c{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}]:runFillable:BLOCKING/BLOCKING AdaptiveExecutionStrategy@1e0294a7/SelectorProducer@3041beb3/IDLE/p=true/InstrumentedQueuedThreadPool[qtp1479696465]@58326051{STARTED,10<=10<=10000,i=3,r=-1,t=-3900001ms,q=0}[ReservedThreadExecutor@15cee630{reserved=2/4,pending=0}][pc=0,pic=0,pec=35,epc=8107]@2023-09-21T15:45:36.155739083Z
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-18) [] o.e.j.i.SelectableChannelEndPoint Key interests updated 0 -> 1 on SocketChannelEndPoint@5bdc21c6[{l=/172.31.160.255:8983,r=/172.31.161.29:60860,OPEN,fill=FI,flush=-,to=0/120000}{io=1/1,kio=1,kro=0}]->[HttpConnection@3ac0bced[p=HttpParser{s=START,0 of -1},g=HttpGenerator@6f5e26db{s=START}]=>HttpChannelOverHttp@7f621f7b{s=HttpChannelState@796aaf{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}]
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-18) [] o.e.j.i.ManagedSelector updates 0
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-18) [] o.e.j.i.ManagedSelector Selector sun.nio.ch.EPollSelectorImpl@858e902 waiting with 2 keys
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-18) [] o.e.j.i.ManagedSelector Selector sun.nio.ch.EPollSelectorImpl@858e902 woken up from select, 1/1/2 selected
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-18) [] o.e.j.i.ManagedSelector Selector sun.nio.ch.EPollSelectorImpl@858e902 processing 1 keys, 0 updates
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-74) [] o.e.j.i.FillInterest fillable FillInterest@5b27206a{ReadCallback@715b12f3{HttpConnection@592e7f12::SocketChannelEndPoint@4fc1d21c[{l=/172.31.160.255:8983,r=/172.31.161.29:60862,OPEN,fill=FI,flush=-,to=1/120000}{io=1/0,kio=1,kro=1}]->[HttpConnection@592e7f12[p=HttpParser{s=START,0 of -1},g=HttpGenerator@26b33d80{s=START}]=>HttpChannelOverHttp@2363ba04{s=HttpChannelState@216b805c{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}]}}
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-18) [] o.e.j.i.ManagedSelector selected 1 channel=java.nio.channels.SocketChannel[connected local=localhost/127.0.0.1:8983 remote=/172.31.161.29:60860], selector=sun.nio.ch.EPollSelectorImpl@858e902, interestOps=1, readyOps=1 SocketChannelEndPoint@5bdc21c6[{l=/172.31.160.255:8983,r=/172.31.161.29:60860,OPEN,fill=FI,flush=-,to=0/120000}{io=1/1,kio=1,kro=1}]->[HttpConnection@3ac0bced[p=HttpParser{s=START,0 of -1},g=HttpGenerator@6f5e26db{s=START}]=>HttpChannelOverHttp@7f621f7b{s=HttpChannelState@796aaf{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}] 
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-74) [] o.e.j.s.HttpConnection HttpConnection@592e7f12::SocketChannelEndPoint@4fc1d21c[{l=/172.31.160.255:8983,r=/172.31.161.29:60862,OPEN,fill=-,flush=-,to=1/120000}{io=1/0,kio=1,kro=1}]->[HttpConnection@592e7f12[p=HttpParser{s=START,0 of -1},g=HttpGenerator@26b33d80{s=START}]=>HttpChannelOverHttp@2363ba04{s=HttpChannelState@216b805c{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}] onFillable enter HttpChannelState@216b805c{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0} null
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-18) [] o.e.j.i.SelectableChannelEndPoint onSelected 1->0 r=true w=false for SocketChannelEndPoint@5bdc21c6[{l=/172.31.160.255:8983,r=/172.31.161.29:60860,OPEN,fill=FI,flush=-,to=0/120000}{io=1/0,kio=1,kro=1}]->[HttpConnection@3ac0bced[p=HttpParser{s=START,0 of -1},g=HttpGenerator@6f5e26db{s=START}]=>HttpChannelOverHttp@7f621f7b{s=HttpChannelState@796aaf{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}]
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-74) [] o.e.j.i.SocketChannelEndPoint filled 129 DirectByteBuffer@7ffdcf98[p=0,l=129,c=8192,r=129]={<<<GET /solr/admin/info/syst...\r\nConnection: close\r\n\r\n>>>\r\nConnect...\x00\x00\x00\x00\x00\x00\x00}
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-18) [] o.e.j.i.SelectableChannelEndPoint task SocketChannelEndPoint@5bdc21c6[{l=/172.31.160.255:8983,r=/172.31.161.29:60860,OPEN,fill=FI,flush=-,to=0/120000}{io=1/0,kio=1,kro=1}]->[HttpConnection@3ac0bced[p=HttpParser{s=START,0 of -1},g=HttpGenerator@6f5e26db{s=START}]=>HttpChannelOverHttp@7f621f7b{s=HttpChannelState@796aaf{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}]:runFillable:BLOCKING
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-18) [] o.e.j.u.t.ReservedThreadExecutor ReservedThreadExecutor@15cee630{reserved=2/4,pending=0} tryExecute org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy$$Lambda$417/0x00007fac4839dbd8@4965e339
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-74) [] o.e.j.s.HttpConnection HttpConnection@592e7f12::SocketChannelEndPoint@4fc1d21c[{l=/172.31.160.255:8983,r=/172.31.161.29:60862,OPEN,fill=-,flush=-,to=0/120000}{io=1/0,kio=1,kro=1}]->[HttpConnection@592e7f12[p=HttpParser{s=START,0 of -1},g=HttpGenerator@26b33d80{s=START}]=>HttpChannelOverHttp@2363ba04{s=HttpChannelState@216b805c{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}] filled 129 RetainableByteBuffer@3d1cedb8{DirectByteBuffer@7ffdcf98[p=0,l=129,c=8192,r=129]={<<<GET /solr/admin/info/syst...\r\nConnection: close\r\n\r\n>>>\r\nConnect...\x00\x00\x00\x00\x00\x00\x00},r=1}
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-20) [] o.e.j.u.t.ReservedThreadExecutor ReservedThread@5b24b88b{RESERVED,thread=Thread[qtp1479696465-20,5,main]} task=org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy$$Lambda$417/0x00007fac4839dbd8@4965e339 ReservedThreadExecutor@15cee630{reserved=1/4,pending=0}
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-74) [] o.e.j.s.HttpConnection HttpConnection@592e7f12::SocketChannelEndPoint@4fc1d21c[{l=/172.31.160.255:8983,r=/172.31.161.29:60862,OPEN,fill=-,flush=-,to=0/120000}{io=1/0,kio=1,kro=1}]->[HttpConnection@592e7f12[p=HttpParser{s=START,0 of -1},g=HttpGenerator@26b33d80{s=START}]=>HttpChannelOverHttp@2363ba04{s=HttpChannelState@216b805c{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}] parse RetainableByteBuffer@3d1cedb8{DirectByteBuffer@7ffdcf98[p=0,l=129,c=8192,r=129]={<<<GET /solr/admin/info/syst...\r\nConnection: close\r\n\r\n>>>\r\nConnect...\x00\x00\x00\x00\x00\x00\x00},r=1}
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-74) [] o.e.j.h.HttpParser parseNext s=START DirectByteBuffer@7ffdcf98[p=0,l=129,c=8192,r=129]={<<<GET /solr/admin/info/syst...\r\nConnection: close\r\n\r\n>>>\r\nConnect...\x00\x00\x00\x00\x00\x00\x00}
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-74) [] o.e.j.h.HttpParser START --> SPACE1
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-74) [] o.e.j.h.HttpParser SPACE1 --> URI
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-74) [] o.e.j.h.HttpParser URI --> SPACE2
2023-09-21 15:45:36.155 DEBUG (qtp1479696465-20) [] o.e.j.u.t.s.AdaptiveExecutionStrategy AdaptiveExecutionStrategy@246de37e/SelectorProducer@19647566/IDLE/p=true/InstrumentedQueuedThreadPool[qtp1479696465]@58326051{STARTED,10<=10<=10000,i=3,r=-1,t=-3900001ms,q=0}[ReservedThreadExecutor@15cee630{reserved=1/4,pending=0}][pc=0,pic=0,pec=35,epc=8153]@2023-09-21T15:45:36.156002725Z tryProduce true
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-74) [] o.e.j.h.HttpParser SPACE2 --> REQUEST_VERSION
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-20) [] o.e.j.i.ManagedSelector updateable 0
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-20) [] o.e.j.i.ManagedSelector updates 0
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-74) [] o.e.j.h.HttpParser REQUEST_VERSION --> HEADER
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-25) [] o.e.j.u.t.ReservedThreadExecutor ReservedThread@4f686370{RESERVED,thread=Thread[qtp1479696465-25,5,main]} task=org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy$$Lambda$417/0x00007fac4839dbd8@9a04ddc ReservedThreadExecutor@15cee630{reserved=1/4,pending=0}
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-74) [] o.e.j.h.HttpParser HEADER:Host --> VALUE
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-74) [] o.e.j.h.HttpParser HEADER:Host --> IN_VALUE
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-74) [] o.e.j.h.HttpParser HEADER:Host --> FIELD
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-25) [] o.e.j.u.t.s.AdaptiveExecutionStrategy AdaptiveExecutionStrategy@1e0294a7/SelectorProducer@3041beb3/IDLE/p=true/InstrumentedQueuedThreadPool[qtp1479696465]@58326051{STARTED,10<=10<=10000,i=3,r=-1,t=-3900001ms,q=0}[ReservedThreadExecutor@15cee630{reserved=1/4,pending=0}][pc=0,pic=0,pec=35,epc=8108]@2023-09-21T15:45:36.156053841Z tryProduce true
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-74) [] o.e.j.h.HttpParser parsedHeader(Host: 172.31.160.255:8983) header=Host, headerString=[Host], valueString=[172.31.160.255:8983]
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-25) [] o.e.j.i.ManagedSelector updateable 0
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-25) [] o.e.j.i.ManagedSelector updates 0
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-74) [] o.e.j.h.HttpParser HEADER:User-Agent --> VALUE
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-74) [] o.e.j.h.HttpParser HEADER:User-Agent --> IN_VALUE
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-74) [] o.e.j.h.HttpParser HEADER:User-Agent --> FIELD
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-74) [] o.e.j.h.HttpParser parsedHeader(User-Agent: kube-probe/1.27+) header=User-Agent, headerString=[User-Agent], valueString=[kube-probe/1.27+]
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-74) [] o.e.j.h.HttpParser HEADER:Accept: */* --> IN_VALUE
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-74) [] o.e.j.h.HttpParser HEADER:Accept: */* --> FIELD
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-74) [] o.e.j.h.HttpParser parsedHeader(Accept: */*) header=Accept, headerString=[Accept], valueString=[*/*]
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-74) [] o.e.j.h.HttpParser HEADER:Connection: close --> IN_VALUE
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-74) [] o.e.j.h.HttpParser HEADER:Connection: close --> FIELD
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-74) [] o.e.j.h.HttpParser parsedHeader(Connection: close) header=Connection, headerString=[Connection], valueString=[close]
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-74) [] o.e.j.h.HttpParser HEADER --> CONTENT
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-74) [] o.e.j.s.HttpInput reopen HttpInput@811588147 cs=HttpChannelState@216b805c{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0} cp=org.eclipse.jetty.server.BlockingContentProducer@7603eb0f eof=false
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-74) [] o.e.j.s.BlockingContentProducer reopening org.eclipse.jetty.server.BlockingContentProducer@7603eb0f
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-74) [] o.e.j.s.AsyncContentProducer reopening AsyncContentProducer@19e591ae[r=null,t=null,i=null,error=false,c=HttpChannelOverHttp@2363ba04{s=HttpChannelState@216b805c{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}]
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-25) [] o.e.j.i.SelectableChannelEndPoint Key interests updated 1 -> 0 on SocketChannelEndPoint@4fc1d21c[{l=/172.31.160.255:8983,r=/172.31.161.29:60862,OPEN,fill=-,flush=-,to=0/120000}{io=0/0,kio=0,kro=1}]->[HttpConnection@592e7f12[p=HttpParser{s=CONTENT,0 of -1},g=HttpGenerator@26b33d80{s=START}]=>HttpChannelOverHttp@2363ba04{s=HttpChannelState@216b805c{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}]
2023-09-21 15:45:36.156 DEBUG (qtp1479696465-25) [] o.e.j.i.ManagedSelector Selector sun.nio.ch.EPollSelectorImpl@71d829dd waiting with 1 key
brickpattern commented 9 months ago

do I have to call Rebalance API on each solrcloud node ? i see issue #625 referring this

brickpattern commented 9 months ago

this is from Logging page of solr admin console (connecting thru solrcloud2 node)

image
brickpattern commented 9 months ago

scaled down the cluster to 2 node... it removed solrcloud-2 and did autoscalling back to 3. After it brought back solrcloud-2 node, this issue went away.

the root cause of original issue seems to be a TIMEOUT issue in solrcloud-1 and solrcloud-2 unable to reach ( or intermittent??) to solrcloud-0 . After the scaling activity... things were back to normal.

Still fingers crossed with the UPGRADE process. will test again. closing ticket for now.