Solr (JVM) di picco ogni ora

Question

risolto

Nel nostro caso il problema è stato che per la SuggestRequestHandler (nome requestHandler = "/ suggerire") ora facelimit è stata impostata: 10 Inoltre v'è stato diverse richieste di ogni singola richiesta di suggerimento fatta dall'applicazione. Perché questo ha portato a un picco (solo) orario non è ancora chiaro ...

Grazie a tutti per suggerimenti e aiuto - ho apprezzato!

Ogni ora completa (12:00, 13:00, 14:00, ..., 20:00, 21:00, 22:00, 23:00) il nostro processo Solr/Java ha un picco - che significa che il processo Java in cui Solr è in esecuzione aumenta di 3 volte l'utilizzo della CPU e il tempo di risposta - che di solito richiede msec per rispondere, fino a 9 secondi. Sempre per 2 - 3 minuti e solo se c'è traffico sul nostro sito (esiste un'applicazione php che chiama Java). Crond è stato completamente disattivato, ma il problema persiste ogni ora. E in fondo penso che abbiamo provato quasi ogni combinazione GC e la memoria

Qualcuno qualche idea del perché questo accade - ecco alcuni dettagli (o forse no?):

• sistema: 32 GB di RAM, 24 core (per lo più condivisi con PHP-FPM, ma anche isolata proprio solr come prova lo stesso problema)
• Solr versione 3.6 (sul molo - temporaneamente anche Glassfish)
• OS: RHEL 5.7
• configurazione Multicore (4 indici con ogni 2 core)

gestori usati (solrconfig.xml):

<requestHandler name="standard" class="solr.SearchHandler" default="true"> 
<requestHandler name="dismax" class="solr.SearchHandler" > 
<requestHandler name="/suggest" class="solr.SearchHandler"> 
<requestHandler name="/update" class="solr.XmlUpdateRequestHandler" /> 
<requestHandler name="/analysis/document" class="solr.DocumentAnalysisRequestHandler" /> 
<requestHandler name="/analysis/field" class="solr.FieldAnalysisRequestHandler" /> 
<requestHandler name="/admin/" class="org.apache.solr.handler.admin.AdminHandlers" /> 
<requestHandler name="/admin/ping" class="PingRequestHandler"> 
<requestHandler name="/debug/dump" class="solr.DumpRequestHandler" > 
<requestHandler name="/replication" class="solr.ReplicationHandler" > 

(testati anche senza replica e ping)

filtri usati: dimensioni

<filter class="solr.StopFilterFactory" ignoreCase="true" words="stopwords.txt" enablePositionIncrements="true" /> 
<filter class="solr.WordDelimiterFilterFactory" generateWordParts="1" generateNumberParts="1" 
<filter class="solr.LowerCaseFilterFactory"/> 
<filter class="solr.PortugueseMinimalStemFilterFactory"/> 
<filter class="solr.ISOLatin1AccentFilterFactory"/> 
<filter class="solr.StopFilterFactory" ignoreCase="true" words="stopwords.txt" enablePositionIncrements="true"/> 
<filter class="solr.WordDelimiterFilterFactory" generateWordParts="1" generateNumberParts="1" 
<filter class="solr.LowerCaseFilterFactory"/> 
<filter class="solr.SynonymFilterFactory" synonyms="synonyms.txt" ignoreCase="true" expand="false"/> 
<filter class="solr.PortugueseMinimalStemFilterFactory"/> 
<filter class="solr.LowerCaseFilterFactory" /> 
<filter class="solr.EdgeNGramFilterFactory" maxGramSize="30" minGramSize="1"/> 
<filter class="solr.ASCIIFoldingFilterFactory"/> 
<filter class="solr.LowerCaseFilterFactory" /> 

Indice: ~ 100 MB (in realtà anche un po 'meno)

Opzioni Java correnti:

Le stesse opzioni ma con 1024, 2048, 8192 e 12 GB non hanno aiutato affatto.

Altro tentativo:

JAVA_OPTS="-server -Xmx2048m -XX:MaxPermSize=128m -XX:+UseParNewGC  -XX:+UseConcMarkSweepGC -XX:+UseTLAB -XX:+CMSIncrementalMode -XX:+CMSIncrementalPacing -XX:CMSIncrementalDutyCycleMin=0 -XX:CMSIncrementalDutyCycle=10 -XX:MaxTenuringThreshold=0 -XX:SurvivorRatio=256 -XX:CMSInitiatingOccupancyFraction=60 -XX:+DisableExplicitGC" 

Altro tentativo:

JAVA_OPTS="-Xmx2048m -Xms2048m -XX:+UseGCOverheadLimit -XX:+UseConcMarkSweepGC -XX:+UseTLAB -XX:MaxPermSize=128m -XX:+DisableExplicitGC -Djava.util.logging.config.file=/opt/solr-jetty/etc/jetty-logging.properties" 

Ecco un estratto del gc.log (di un tale problema ora piena):

2013-03-03T19:59:04.157-0300: 8087.754: [GC 3433559K->1788819K(3914560K), 0.0358190 secs] 
2013-03-03T19:59:12.031-0300: 8095.628: [GC 3437075K->1792088K(3914560K), 0.0365830 secs] 
2013-03-03T19:59:22.419-0300: 8106.016: [GC 3440344K->1803266K(3914560K), 0.0422040 secs] 
2013-03-03T19:59:29.044-0300: 8112.641: [GC 3451522K->1815743K(3914560K), 0.0439870 secs] 
2013-03-03T19:59:37.002-0300: 8120.599: [GC 3463999K->1821601K(3914560K), 0.0378990 secs] 
2013-03-03T19:59:45.468-0300: 8129.065: [GC 3469857K->1822911K(3914560K), 0.0386720 secs] 
2013-03-03T19:59:53.750-0300: 8137.347: [GC 3471167K->1829299K(3914560K), 0.0405040 secs] 
2013-03-03T20:00:01.829-0300: 8145.426: [GC 3477555K->1832046K(3914560K), 0.0383070 secs] 
2013-03-03T20:00:06.327-0300: 8149.924: [GC 3480302K->1831567K(3914560K), 0.0450550 secs] 
2013-03-03T20:00:11.123-0300: 8154.719: [GC 3479823K->1843283K(3914560K), 0.0401710 secs] 
2013-03-03T20:00:14.360-0300: 8157.957: [GC 3491539K->1854079K(3914560K), 0.0368560 secs] 
2013-03-03T20:00:17.419-0300: 8161.015: [GC 3502335K->1855130K(3914560K), 0.0375530 secs] 
2013-03-03T20:00:20.006-0300: 8163.603: [GC 3503386K->1861867K(3914560K), 0.0413470 secs] 
2013-03-03T20:00:22.726-0300: 8166.323: [GC 3510123K->1870292K(3914560K), 0.0360600 secs] 
2013-03-03T20:00:25.420-0300: 8169.017: [GC 3518548K->1872701K(3914560K), 0.0326970 secs] 
2013-03-03T20:00:27.138-0300: 8170.735: [GC 3520957K->1873446K(3914560K), 0.0381430 secs] 
2013-03-03T20:00:28.748-0300: 8172.345: [GC 3521702K->1889189K(3914560K), 0.0379160 secs] 
2013-03-03T20:00:30.404-0300: 8174.001: [GC 3537445K->1887193K(3914560K), 0.0407670 secs] 
2013-03-03T20:00:32.713-0300: 8176.309: [GC 3535449K->1892863K(3914560K), 0.0366880 secs] 
2013-03-03T20:00:34.791-0300: 8178.388: [GC 3541119K->1899095K(3914560K), 0.0398270 secs] 
2013-03-03T20:00:36.533-0300: 8180.129: [GC 3547351K->1910071K(3914560K), 0.0373960 secs] 
2013-03-03T20:00:39.037-0300: 8182.634: [GC 3558327K->1904198K(3914560K), 0.0393020 secs] 
2013-03-03T20:00:41.548-0300: 8185.144: [GC 3552454K->1912352K(3914560K), 0.0444060 secs] 
2013-03-03T20:00:43.771-0300: 8187.368: [GC 3560608K->1919304K(3914560K), 0.0427220 secs] 
2013-03-03T20:00:47.411-0300: 8191.008: [GC 3566354K->1918102K(3914560K), 0.0418150 secs] 
2013-03-03T20:00:50.925-0300: 8194.522: [GC 3564290K->1930888K(3914560K), 0.0414700 secs] 
2013-03-03T20:00:52.991-0300: 8196.588: [GC 3579144K->1933251K(3914560K), 0.0349600 secs] 
2013-03-03T20:00:53.027-0300: 8196.624: [GC 1939697K(3914560K), 0.0256300 secs] 
2013-03-03T20:00:54.208-0300: 8197.804: [GC 2780505K(3914560K), 0.1424860 secs] 
2013-03-03T20:00:55.684-0300: 8199.281: [GC 3029503K->1389766K(3914560K), 0.0370380 secs] 
2013-03-03T20:00:58.289-0300: 8201.886: [GC 2213458K->570843K(3914560K), 0.0413220 secs] 
2013-03-03T20:01:00.672-0300: 8204.268: [GC 1962741K->319619K(3914560K), 0.0410840 secs] 
2013-03-03T20:01:02.906-0300: 8206.503: [GC 1966833K->319605K(3914560K), 0.0453730 secs] 
2013-03-03T20:01:06.861-0300: 8210.458: [GC 1967861K->330864K(3914560K), 0.0425570 secs] 
2013-03-03T20:01:10.067-0300: 8213.664: [GC 1979120K->336541K(3914560K), 0.0479380 secs] 
2013-03-03T20:01:12.587-0300: 8216.184: [GC 1984797K->343203K(3914560K), 0.0376810 secs] 

Inoltre ci sono solo 2 voci (circa 1 giorno) maggiore di 1 secondo: grep -oP ", [1-9] .. *? secs] $"/shop/logs/live/solr/gc .log , 1.1727270 sec.] , 1.0390840 sec.]

Qualcuno ha qualche idea o ha già avuto questo fenomeno con solr/jvm?

Answer 1

se la dimensione indice è solo 100MB, e il problema è legato alla GC Vorrei iniziare:

1. riducendo -Xmx a meno di 1024, cominciano a circa 256m e vedere se è abbastanza
2. non uso alcun -XX agli inizi
3. uso più recente JDK

Answer 2

non crederete ai vostri log GC a meno che non si include -XX: + PrintGCApplicationStoppedTime nelle opzioni. Sospettalo anche allora. Ci sono pause e parti di pause che possono essere molto lunghe e non dichiarate se non includi questo flag. Per esempio. Ho visto pause causate dall'occasionale loop conteggiato di lunga durata che impiega 15 secondi per raggiungere un punto sicuro, dove GC ha riportato solo la parte di 0,20 secondi della pausa in cui effettivamente ha funzionato. Ci sono anche molte pause le cui cause non sono considerate parte di "GC" e quindi non possono essere segnalate dai flag di registrazione GC.

È possibile provare ad aggiungere jHiccup come agente per segnalare pause/glitch/stallo/singhiozzo osservati anziché affidarsi all'onestà dei log JVM. Se mostra glitch multi-sec, saprai che la tua JVM sta facendo una pausa. Se mostra un'operazione JVM scorrevole, allora sai di guardare le tue altre parti di configurazione.