Problemi di prestazioni durante la chiamata java.beans.Introspector.getBeanInfo dopo inattività

Question

Sto utilizzando una libreria di terze parti che crea dinamicamente istanze di classi Java e popola tali istanze con l'aiuto di Introspector.getBeanInfo. Alcune richieste possono comportare 5 o 6 chiamate successive a Introspector.getBeanInfo. Ho scoperto che quando l'applicazione è inattiva per circa un'ora circa, la prima chiamata a Introspector.getBeanInfo richiede un tempo significativamente più lungo per l'esecuzione (20-60 secondi) rispetto alle chiamate successive (< 100 millisecondi). Le chiamate effettuate nei prossimi minuti continuano a prendere < 100 millisecondi, ma quando aspetto un'altra ora, la prima chiamata riprende tra 20 e 60 secondi.

Nel tentativo di ricreare il comportamento con una semplice applicazione di test, ho riscontrato un comportamento simile quando un'applicazione Java non viene eseguita per un'ora. Ad esempio, se eseguo la seguente app console, potrebbero essere necessari 15 millisecondi. Se poi aspetto un'ora e rieseguo l'applicazione, sono necessari 20 secondi.

long start = System.currentTimeMillis(); 
System.out.println("Start"); 
Introspector.getBeanInfo(MyClass.class, Object.class); 
long end = System.currentTimeMillis(); 
System.out.println("End: " + (end-start)); 

ho inizialmente pensato che il problema potrebbe essere legato al fatto che i tentativi di classe Introspector di creare istanze di classi sulla base di convenzioni di denominazione standard che non esistono nella mia applicazione (ad esempio, MyClassBeanInfo), ed è stato impiegare molto tempo per scansionare i file jar nel tentativo di trovare quelle classi (la mia applicazione java ha poco più di 100 file jar di riferimento), ma ho chiamato Introspector.getBeanInfo(MyClass.class, Object.class, Introspector.IGNORE_ALL_BEANINFO) usando il reflection (è un metodo privato in Sun's JRE che guardando il il codice sembra saltare la ricerca delle classi BeanInfo), e sono ancora in grado di riprodurre il ritardo.

Ho anche cercato informazioni riguardanti qualsiasi tipo di cache jar JRE/JVM, ma non ho ancora trovato nulla che sembra spiegare questo comportamento. Qualcuno ha idea del perché questo si comporta come fa e se c'è qualcosa che posso fare per risolverlo?

Come nota a margine sto usando JDK 1.6.0_21 su Windows XP. La libreria di terze parti che sto utilizzando è BlazeDS. La mia applicazione è ospitata in Tomcat utilizzando l'integrazione Spring/BlazeDS. Ho sovrascritto un certo numero di classi BlazeDS per individuare esattamente dove si trovava il ritardo (che è la chiamata a Introspector.getBeanInfo nel metodo getPropertyDescriptorCacheEntry di flex.messaging.io.BeanProxy). Inoltre, BlazeDS memorizza nella cache BeanInfo, quindi le chiamate a Introspector.getBeanInfo vengono eseguite solo quando Blaze deserializza un oggetto mappato su una classe Java che deve ancora essere elaborata. Quindi, ho altri modi per ovviare a questo problema, ma mi piacerebbe davvero sapere se esiste una spiegazione valida per questo comportamento.

MODIFICA: Ho eseguito jstack sul processo più volte durante la riproduzione del problema (grazie a @Tom) e ho confermato che è correlato al caricamento dei file jar. Buttai i fili 5 volte 20 secondi di tempo (tempo totale di ritardo) e ogni volta prodotto il seguente risultato:

"http-8080-exec-6" daemon prio=6 tid=0x65cae800 nid=0x1a50 runnable [0x67a3d000] 
    java.lang.Thread.State: RUNNABLE 
    at java.util.zip.ZipFile.open(Native Method) 
    at java.util.zip.ZipFile.<init>(Unknown Source) 
    at java.util.jar.JarFile.<init>(Unknown Source) 
    at java.util.jar.JarFile.<init>(Unknown Source) 
    at org.apache.catalina.loader.WebappClassLoader.openJARs(WebappClassLoader.java:2704) 
    at org.apache.catalina.loader.WebappClassLoader.findResourceInternal(WebappClassLoader.java:2945) 
    - locked <0x1804cc18> (a [Ljava.util.jar.JarFile;) 
    at org.apache.catalina.loader.WebappClassLoader.findClassInternal(WebappClassLoader.java:2739) 
    at org.apache.catalina.loader.WebappClassLoader.findClass(WebappClassLoader.java:1144) 
    at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1639) 
    - locked <0x1803dd38> (a org.apache.catalina.loader.WebappClassLoader) 
    at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1517) 
    at java.beans.Introspector.instantiate(Unknown Source) 
    at java.beans.Introspector.findExplicitBeanInfo(Unknown Source) 
    - locked <0x434649a0> (a java.lang.Class for java.beans.Introspector) 
    at java.beans.Introspector.<init>(Unknown Source) 
    at java.beans.Introspector.getBeanInfo(Unknown Source) 
    - locked <0x181bed70> (a java.lang.Object) 

non posso fare a meno che ci sia un qualche tipo di JRE/vaso JVM cache che scade dopo un'ora e costringendo i file jar a essere riesaminati, ma non riesco a trovare nulla online che delinea un simile comportamento.

MODIFICA: Come risulta il Tomcat WebappClassLoader memorizza nella cache i file JAR e periodicamente elimina tale cache. Ora per scoprire se la cache è configurabile in ogni caso ...

MODIFICA: Tomcat chiude tutti i file JAR 90 secondi dopo l'ultima volta che è stato effettuato l'accesso a un file jar. Ho sovrascritto lo WebappClassLoader per stampare quando i file jar sono stati chiusi. Dopo che i file jar sono stati chiusi, ho provato a riprodurre il ritardo, ma non ci sono riuscito.Quindi, questo mi dice che c'è una cache di file jar JRE/JVM, o solo qualcosa inerente al sistema operativo (o alla mia macchina, antivirus, ecc.) Che causa tempi di caricamento lenti dopo un lungo ritardo. Ci sto ancora lavorando ...

Answer 1

Nel mio datore di lavoro, anche noi facciamo molto affidamento su classi generate dinamicamente. Con i problemi del Introspector e come si comporta (ad esempio facendo affidamento sul comportamento di ClassLoader) e cercando di caricare molte classi *BeanInfo che non abbiamo, era un no-go per noi e abbiamo deciso di non utilizzare Introspector e reimplementare la funzionalità su il nostro

Non sei sicuro di quanto BeanInfo ti serva veramente, ma potrebbe essere più semplice utilizzare la riflessione e un componente di proprietà dei metadati di proprietà, che hai sotto controllo. E con più facilità, intendo anche i nervi che si saranno sicuri una volta distribuita l'app su altri server delle applicazioni, che hanno i loro comportamenti ClassLoader e che sono ancora più pesanti e non configurabili rispetto a quelli su Tomcat.

BeanInfo e i componenti correlati sono interfacce, quindi potrebbe essere necessario solo reimplementare l'Introspector stesso e non tutto il codice che lo utilizza.

Answer 2

Come già detto, lo WebAppClassLoader in Tomcat memorizza in cache i file JAR per 90 secondi. Quando ho chiamato lo Introspector.getBeanInfo dopo 90 secondi, ho verificato che Tomcat stava ricaricando i file JAR. Il ritardo era minimo dopo alcuni minuti di inattività, ma c'era ancora un ritardo. Non ho mai capito perché il ritardo fosse molto più lungo dopo un'ora di inattività.

In definitiva, la mia soluzione era di ignorare lo WebAppClassLoader e memorizzare i JAR in modo indefinito. Nel nostro scenario questo è perfettamente accettabile perché avvolgiamo Tomcat nella nostra applicazione, non ci sono altre applicazioni web che condividono la stessa istanza di Tomcat e non permettiamo che la nostra applicazione web venga ricaricata automaticamente. Tienilo a mente se stai pensando di implementare una soluzione simile.

ecco il codice per l'override del comportamento JAR caching (cacheJarFiles è un valore booleano personalizzato che ho aggiunto alla classe WebAppClassLoader):

private static boolean cacheJarFiles = true; 

...

public void closeJARs(boolean force) { 
    if (cacheJarFiles) { 
     return; 
    } 
    if (jarFiles.length > 0) { 
     synchronized (jarFiles) { 
     if (force || (System.currentTimeMillis() 

...

} 

In sostanza, interrompo la chiamata a closeJARs. L'aumento delle prestazioni che stiamo vedendo ora è abbastanza consistente. Dopo un'ora di inattività risparmiamo 10-60 + secondi sulle nuove chiamate a Introspector.getBeanInfo. Dopo alcuni minuti di inattività, risparmiamo 100-200 millisecondi.

Answer 3

java.beans.Introspector può essere un problema reale nell'ambiente OSGi dove la ricerca di classi non esistenti può essere particolarmente costosa. È particolarmente vero in Equinox a causa del caricamento in classe compagno: Eclipse-BuddyPolicy: depenent e Eclipse-BuddyPolicy: global può causare seri problemi di prestazioni.

java.beans.Introspector è utilizzato in alcuni luoghi inaspettati

• org.apache.log4j.config.PropertySetter
• org.springframework.beans.CachedIntrospectionResults
• org.hibernate.util.Cloneable#copyListeners

In generale, Introspector dovrebbe essere relativamente sicuro in Equinox quando si specifica Introspector.IGNORE_ALL_BEANINFO bandiera. Non è così, nell'attuale implementazione di Oracle JVM la cache di BeanInfo non viene utilizzata a meno che non sia specificato Introspector.USE_ALL_BEANINFO. Ovviamente, è in conflitto diretto con i javadoc, quindi direi che questo è in realtà un bug nell'implementazione (o documentazione) di Introspector.