Consumo excesivo de JAVA al cabo de 10 días

[rublape]

Buenas tardes,

Tengo alfresco 5.1 community montado sobre un centos 6.5 y según arranco la máquina va perfectamente. La CPU y memoria de Java va sobre un 15%. Al pasar unos 10 días noto como cada vez se hace más lento y al final incluso ya no se puede usar.

Cuando está en esta fase veo que la memoria HEAP está al 100%, pero con más que subo la memoria termina pasando los mismo... He configurado tweaks de los parámetros de JAVA que he visto en los foros pero sigo sin solucionar el problema... 

Adjunto los datos que he sacado con jconsole cuando la máquina estaba a tope y por lo tanto iba lentísima.

¿Alguien sabe si se puede realizar alguna configuración para que vaya liberando memoria JAVA?

Muchas gracias por adelantado!

Un saludo

[cristinamr]

Buenas.

Tenemos que conocer el entorno del que nos hablas:

• ¿Qué tipo de arquitectura tenéis?
• ¿Volumen de content store, base de datos e indices?
• ¿Qué recursos tiene la máquina?
• ¿Qué uso le dais a Alfresco?
• ¿Le metéis mucha carga de subida de documentos os similar?
• ¿Tienes personalizaciones instaladas?

Cuéntanos un poco y vamos viendo porque de algún lado tiene que venir esa subida y la cuestión no es subir el heap, es ver de dónde viene el problema. Hace tiempo me ocurrió algo parecido y provenía de un desarrollo mal elaborado porque no cerraba los resultSets y terminaban por consumir la máquina. De ahí a todas estas preguntas a ver si vemos algo.

Un saludo,

Cris.

[rublape]

Buenas tardes Cristina,

Te respondo a las preguntas.

• ¿Qué tipo de arquitectura tenéis? - Es un Centos 6.5 con alfresco 5.1 community y base de datos postgresql. Además para el acceso SSL tenemos un apache montado con el mod_jk
• ¿Volumen de content store, base de datos e indices? - El content store tenemos un total de 9 GB, indices de Solr4 son 864,4 MB y Postgresql DB - 122 MB
• ¿Qué recursos tiene la máquina? - 14 GB de memoria, 4 CPU
• ¿Qué uso le dais a Alfresco? - Le damos un uso sobretodo viendo documentos ya almacenados unas 20 personas como máximo a la vez
• ¿Le metéis mucha carga de subida de documentos os similar? - No solemos cargar documentos en estos momentos.
• ¿Tienes personalizaciones instaladas? - Ninguna que yo sepa. ¿Alguna forma de saberlo?

La configuración de la VM de java que tengo es:

more setenv.sh

# Load Tomcat Native Library
LD_LIBRARY_PATH=/alfresco/alfresco-community/common/lib:$LD_LIBRARY_PATH

JAVA_HOME=/alfresco/alfresco-community/java
JRE_HOME=$JAVA_HOME
JAVA_OPTS="-XX:+DisableExplicitGC -XX:+UseConcMarkSweepGC -XX:+UseParNewGC -Djava.awt.headless=true -Dalfresco.home=/alfresco/alfresc
o-community -XX:ReservedCodeCacheSize=128m $JAVA_OPTS "
JAVA_OPTS="-Xms9G -Xmx10G $JAVA_OPTS " # java-memory-settings
# Opciones para gestion JMX
export CATALINA_OPTS="$CATALINA_OPTS -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.port=9999 -Dcom.sun.management.jmx
remote.authenticate=false -Dcom.sun.management.jmxremote.ssl=false -Djava.rmi.server.hostname=172.16.29.171"
export CATALINA_OPTS

# Exports de Java
export JAVA_HOME
export JRE_HOME
export JAVA_OPTS
export LD_LIBRARY_PATH

Esa es la información que así a primera vista te puedo dar. Si necesitaras alguna más en detalle me tendrías que guiar un poco sobre qué comando necesitas o qué fichero necesitas ver

Muchas gracias por la rápida respuesta.

Un saludo

Rubén

[cristinamr]

Buenos días.

En lo que pones no veo nada raro ni en uso ni en asignaciones ¿En el catalina.out o alfresco.log ves algún error o warn cuando el servidor está a tope?

Vamos a tirar por los desarrollos a ver. Comprueba lo siguiente:

• Lista los amps de las carpeta alfresco/amps y alfresco/amps_share

Haz lo siguiente:

• cd alfresco/bin
• java -jar alfresco-mmt.jar list ../tomcat/webapps/alfresco.war
• java -jar alfresco-mmt.jar list ../tomcat/webapps/share.war

De estas dos últimas, dime qué te aparece.

Además, mira a ver qué tienes en alfresco/tomcat/shared/classes/alfresco/extension y web-extension De estas dos, quita todos los .sample que solo son ejemplos.

También se pueden desplegar personalizaciones dinamicamente: Con alfresco funcionando, mira en:

• Repositorio > Diccionario de Datos > Models
• Repositorio > Diccionario de Datos > Web Script Extensions

Y en general haz un repaso por si pudiera haber algo que fuera vuestro dentro de la carpeta Data Dictionary.

Coméntanos  ver si damos con la clave.

Un saludo,

Cris.

[cesarista]

Hola:

Además de las consideraciones de Cristina, te recomiendo que instales el módulo de OOTB Support tools, te va a proporcionar mejor información que Jconsole (threads, conexiones de bbdd, heap usada...). Pinta a memory leak. Puede ser relevante además hacer un jstack en el momento que está a tope para ver que threads están activos/esperando.

El repositorio no es especialmente grande y aunque es mas significativo el numero de documentos que el tamaño total de los mismos, no debería tener problemas de rendimiento si tu entorno tiene recursos dedicados, aunque tengas la bbdd en el mismo server. Lo de los 10 días podría estar relacionado con alguna tarea programada. Si eres capaz de detectar o reproducir la hora en el que sube la memoria (o mejor dicho, en la que el diente de sierra no baja) seria de utilidad. 

Saludos.

--C. 

[rublape]

Buenas tardes Cristina,

• En el catalina.out de ayer a la hora que fallaba aparecieron estos errores:

2017-09-05 12:13:30,311 WARN [content.metadata.AbstractMappingMetadataExtracter] [http-apr-8080-exec-60] Metadata extraction failed (turn on DEBUG for full error):
org.alfresco.error.AlfrescoRuntimeException: 080556118 Creation of thumbnail 'doclib' failed
org.alfresco.error.AlfrescoRuntimeException: 080556223 Creation of thumbnail 'doclib' failed
org.alfresco.error.AlfrescoRuntimeException: 080557875 Creation of thumbnail 'doclib' failed
org.alfresco.error.AlfrescoRuntimeException: 080557882 Creation of thumbnail 'doclib' failed
org.alfresco.error.AlfrescoRuntimeException: 080557883 Creation of thumbnail 'doclib' failed
org.alfresco.error.AlfrescoRuntimeException: 080557884 Creation of thumbnail 'doclib' failed
org.alfresco.error.AlfrescoRuntimeException: 080557885 Creation of thumbnail 'doclib' failed
2017-09-05 14:19:51,386 WARN [content.metadata.AbstractMappingMetadataExtracter] [http-apr-8080-exec-53] Metadata extraction failed (turn on DEBUG for full error):
org.alfresco.error.AlfrescoRuntimeException: 080557896 Creation of thumbnail 'doclib' failed
org.alfresco.error.AlfrescoRuntimeException: 08050001 api/solr/aclchangesets return status:503
org.alfresco.error.AlfrescoRuntimeException: 08050000 api/solr/aclchangesets return status:503
org.alfresco.error.AlfrescoRuntimeException: 08050002 GetTransactions return status is 503
org.alfresco.error.AlfrescoRuntimeException: 08050003 api/solr/aclchangesets return status:503
org.alfresco.error.AlfrescoRuntimeException: 08050004 api/solr/aclchangesets return status:503
org.alfresco.error.AlfrescoRuntimeException: 08061175 Creation of thumbnail 'doclib' failed
org.alfresco.error.AlfrescoRuntimeException: 08061196 Creation of thumbnail 'doclib' failed

y estos que veo que parece que la caché se llena:

2017-09-05 15:52:00,624 WARN [org.alfresco.userToAuthorityTransactionalCache] [LocalFeedGenerator1] Transactional update cache 'org.alfresco.userToAuthorityTransactionalCache' is full (100).
log4j:WARN No appenders could be found for logger (aoservices-trc.AbstractSoapService).
log4j:WARN Please initialize the log4j system properly.
log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info.
2017-09-05 16:20:30,231 WARN [org.alfresco.userToAuthorityTransactionalCache] [LocalFeedGenerator1] Transactional update cache 'org.alfresco.userToAuthorityTransactionalCache' is full (100).
2017-09-05 16:36:00,325 WARN [org.alfresco.userToAuthorityTransactionalCache] [LocalFeedGenerator1] Transactional update cache 'org.alfresco.userToAuthorityTransactionalCache' is full (100).
2017-09-05 16:37:00,164 WARN [org.alfresco.userToAuthorityTransactionalCache] [LocalFeedGenerator1] Transactional update cache 'org.alfresco.userToAuthorityTransactionalCache' is full (100).
2017-09-05 16:38:00,210 WARN [org.alfresco.userToAuthorityTransactionalCache] [LocalFeedGenerator1] Transactional update cache 'org.alfresco.userToAuthorityTransactionalCache' is full (100).
2017-09-05 16:47:00,645 WARN [solr.component.AsyncBuildSuggestComponent] [Suggestor-alfresco-1] Solr suggester temp file found matching file pattern: WFSTInputIterator*.{input,sorted}, path: /alfresco/alfresco-community/tomcat/temp/WFSTInputIterator7353038735798153610.input
2017-09-05 16:47:00,645 WARN [solr.component.AsyncBuildSuggestComponent] [Suggestor-alfresco-1] Reported first suggester temp file found, others may exist.
2017-09-05 16:47:44,708 WARN [solr.component.AsyncBuildSuggestComponent] [Suggestor-alfresco-1] Solr suggester temp file found matching file pattern: WFSTInputIterator*.{input,sorted}, path: /alfresco/alfresco-community/tomcat/temp/WFSTInputIterator7353038735798153610.input
2017-09-05 16:47:44,708 WARN [solr.component.AsyncBuildSuggestComponent] [Suggestor-alfresco-1] Reported first suggester temp file found, others may exist.
2017-09-05 16:48:00,150 WARN [org.alfresco.userToAuthorityTransactionalCache] [LocalFeedGenerator1] Transactional update cache 'org.alfresco.userToAuthorityTransactionalCache' is full (100).
2017-09-05 16:51:00,170 WARN [org.alfresco.userToAuthorityTransactionalCache] [LocalFeedGenerator1] Transactional update cache 'org.alfresco.userToAuthorityTransactionalCache' is full (100).
2017-09-05 17:16:00,201 WARN [org.alfresco.userToAuthorityTransactionalCache] [LocalFeedGenerator1] Transactional update cache 'org.alfresco.userToAuthorityTransactionalCache' is full (100).

• Lo mismo para el log de alfresco.log:

2017-09-05 15:52:00,624 WARN [org.alfresco.repo.cache.TransactionalCache.org.alfresco.userToAuthorityTransactionalCache] [LocalFeedGenerator1] Transactional update cache 'org.alfresco.userToAuthorityTransactionalCache' is full (100).
2017-09-05 16:20:30,231 WARN [org.alfresco.repo.cache.TransactionalCache.org.alfresco.userToAuthorityTransactionalCache] [LocalFeedGenerator1] Transactional update cache 'org.alfresco.userToAuthorityTransactionalCache' is full (100).
2017-09-05 16:36:00,325 WARN [org.alfresco.repo.cache.TransactionalCache.org.alfresco.userToAuthorityTransactionalCache] [LocalFeedGenerator1] Transactional update cache 'org.alfresco.userToAuthorityTransactionalCache' is full (100).
2017-09-05 16:37:00,164 WARN [org.alfresco.repo.cache.TransactionalCache.org.alfresco.userToAuthorityTransactionalCache] [LocalFeedGenerator1] Transactional update cache 'org.alfresco.userToAuthorityTransactionalCache' is full (100).
2017-09-05 16:38:00,210 WARN [org.alfresco.repo.cache.TransactionalCache.org.alfresco.userToAuthorityTransactionalCache] [LocalFeedGenerator1] Transactional update cache 'org.alfresco.userToAuthorityTransactionalCache' is full (100).
2017-09-05 16:48:00,150 WARN [org.alfresco.repo.cache.TransactionalCache.org.alfresco.userToAuthorityTransactionalCache] [LocalFeedGenerator1] Transactional update cache 'org.alfresco.userToAuthorityTransactionalCache' is full (100).
2017-09-05 16:51:00,170 WARN [org.alfresco.repo.cache.TransactionalCache.org.alfresco.userToAuthorityTransactionalCache] [LocalFeedGenerator1] Transactional update cache 'org.alfresco.userToAuthorityTransactionalCache' is full (100).
2017-09-05 17:16:00,201 WARN [org.alfresco.repo.cache.TransactionalCache.org.alfresco.userToAuthorityTransactionalCache] [LocalFeedGenerator1] Transactional update cache 'org.alfresco.userToAuthorityTransactionalCache' is full (100).
2017-09-05 18:07:30,203 WARN [org.alfresco.repo.cache.TransactionalCache.org.alfresco.userToAuthorityTransactionalCache] [LocalFeedGenerator1] Transactional update cache 'org.alfresco.userToAuthorityTransactionalCache' is full (100).
2017-09-05 23:35:00,155 WARN [org.alfresco.repo.cache.TransactionalCache.org.alfresco.userToAuthorityTransactionalCache] [LocalFeedGenerator1] Transactional update cache 'org.alfresco.userToAuthorityTransactionalCache' is full (100).

¿Esto que es la cache de la VM de Java? ¿Hay manera de subir la caché o es recomendable?

• Ahora te muestro los desarollos en alfreso/amps:
  -rw-r--r-- 1 root root 515446 Jan 27 2016 alfresco-aos-module-1.1.amp
  -rw-r--r-- 1 root root 782737 Feb 16 2016 alfresco-googledocs-repo-3.0.3.amp
  -rw-r--r-- 1 root root 15503806 Feb 16 2016 alfresco-share-services.amp
  -rw-r--r-- 1 root root 21372002 Feb 16 2016 alfresco-wcmqs.amp

• y en alfresco/share_amps:

-rw-r--r-- 1 root root 60286 Feb 16 2016 alfresco-googledocs-share-3.0.3.amp
-rw-r--r-- 1 root root 48938 Feb 16 2016 alfresco-wcmqs-share.amp

No tenemos nada en especia ;-)

• Te sigo mostrando los amps instalados con el comando de java para alfresco:

[root@nocmsralfresco1 bin]# /opt/jdk1.8.0_111/bin/java -jar alfresco-mmt.jar list ../tomcat/webapps/alfresco.war
Module 'create-link-repo' installed in '../tomcat/webapps/alfresco.war'
- Title: create-link-repo AMP project
- Version: 1.0.0.1410011040
- Install Date: Thu May 04 13:46:03 CEST 2017
- Description: Manages the lifecycle of the create-link-repo AMP (Alfresco Module Package)
Module 'alfresco-share-services' installed in '../tomcat/webapps/alfresco.war'
- Title: Alfresco Share Services AMP
- Version: 5.1.0
- Install Date: Thu Jul 28 13:16:04 CEST 2016
- Description: Module to be applied to alfresco.war, containing APIs for Alfresco Share
Module 'org_alfresco_module_wcmquickstart' installed in '../tomcat/webapps/alfresco.war'
- Title: Web Quick Start
- Version: 1.0
- Install Date: Thu Jul 28 13:16:04 CEST 2016
- Description: Web Quick Start
Module 'org.alfresco.integrations.google.docs' installed in '../tomcat/webapps/alfresco.war'
- Title: Alfresco / Google Docs Integration
- Version: 3.0.3
- Install Date: Thu Jul 28 13:16:03 CEST 2016
- Description: The Repository side artifacts of the Alfresco / Google Docs Integration.
Module 'alfresco-aos-module' installed in '../tomcat/webapps/alfresco.war'
- Title: Alfresco Office Services Module
- Version: 1.1
- Install Date: Thu Jul 28 13:16:01 CEST 2016
- Description: Allows applications that can talk to a SharePoint server to talk to your Alfresco installation

• Información de los amps instalados en SHARE:

[root@nocmsralfresco1 bin]# /opt/jdk1.8.0_111/bin/java -jar alfresco-mmt.jar list ../tomcat/webapps/share.war
Module 'create-link-share' installed in '../tomcat/webapps/share.war'
- Title: create-link-share AMP project
- Version: 1.0.0.1410011042
- Install Date: Thu May 04 13:46:19 CEST 2017
- Description: Manages the lifecycle of the create-link-share AMP (Alfresco Module Package)
Module 'org.alfresco.integrations.share.google.docs' installed in '../tomcat/webapps/share.war'
- Title: Alfresco / Google Docs Share Module
- Version: 3.0.3
- Install Date: Thu Jul 28 13:16:09 CEST 2016
- Description: The Share side artifacts of the Alfresco / Google Docs Integration.
Module 'org_alfresco_module_wcmquickstartshare' installed in '../tomcat/webapps/share.war'
- Title: Web Quick Start Share
- Version: 1.1
- Install Date: Thu Jul 28 13:16:07 CEST 2016
- Description: Web Quick Start Share Module

• Archivos en /alfresco/extensions:

drwxr-xr-x 2 root root 4096 Jul 28 2016 audit
drwxr-xr-x 2 root root 4096 Jul 28 2016 bootstrap
-rw-r--r-- 1 root root 11675 May 4 10:57 custom-log4j.properties
drwxr-xr-x 2 root root 4096 Jul 28 2016 mimetype
-rw-r--r-- 1 root root 102 Jul 28 2016 wqsapi-custom.properties

¿se pueden eliminar los .sample o pueden servir para algo?

• Archivos en /alfresco/web-extensions

drwxr-xr-x 2 root root 4096 Jul 14 11:22 .
drwxr-xr-x 5 root root 4096 Aug 4 2016 ..
-rw-r--r-- 1 root root 11412 Feb 16 2016 awe-config-custom.xml
-rw-r--r-- 1 root root 2156 Feb 16 2016 custom-slingshot-application-context.xml.sample
-rw-r--r-- 1 root root 20354 Jul 28 2016 share-config-custom.xml
-rw-r--r-- 1 root root 20354 Sep 13 2016 share-config-custom.xml.ori
-rw-r--r-- 1 root root 2188 Feb 16 2016 smartfolders-amp-actions-config.xml

Dentro de Alfresco / Repository:

• Repositorio > Diccionario de Datos > Models: Aquí no tengo nada, ni scripts ni documentos.
• Repositorio > Diccionario de Datos > Web Script Extensions: Aquí solo tengo un archivo que se llama readme.html que te indica cómo customizar un Web Script.

He repasado todo el Repository y no tengo nada...

Espero que con los logs obtenidos puedas ayudarme a sacar algo en claro. 

Muchas gracias por tu ayuda!

Un saludo

Rubén

[rublape]

Buenas Cesar,

Muchas gracias por el aporte de la herramienta ya que me viene muy bien para tener monitorizado todo el sistema. Ya he descargado el amp, pero tengo la duda de si se instala en el alfresco.war o en el share.war o en ¿ambos?

He mirado varios links de github y de zylk.net referidos en este post   pero no encuentro cómo instalarlo. Por lo menos en que war está situado.

Por otro lado digo 10 días por aproximar, a veces tarda un poco más o un poco menos, como máximo cada dos semanas tengo que reiniciar. Yo creo que hay parte de memoria que JAVA ni libera y sube y sube hasta que se llena...pero no soy capaz de identificarlo...

Esperemos que con el programa pueda sacar más luz sobre tanta oscuridad...

Muchas gracias!

Un saludo

[cesarista]

Buenas:

El proyecto debería compilar un AMP para el repo y otro para Share, pero el relevante para tu caso es el del repositorio. La monitorización está en la consola del repositorio (/alfresco/)

Saludos.

--C.

[cristinamr]

Te cuento lo que veo:

A modo informativo: Tienes un addon instalado que no es nativo pero no lo tienes desplegado en amps/ y amps_share/:

create-link-repo AMP project y create-link-share AMP project

Pertenecen a este desarrollo: GitHub - skomarica/alfresco-share-create-link: "Create Link" is a custom Alfresco Share Document Lib... 

Para que lo tengas en cuenta en un futuro: Esta funcionalidad ya existe en Alfresco 5.2.

Por otra parte, dado esto:

2017-09-05 15:52:00,624 WARN [org.alfresco.repo.cache.TransactionalCache.org.alfresco.userToAuthorityTransactionalCache] [LocalFeedGenerator1] Transactional update cache 'org.alfresco.userToAuthorityTransactionalCache' is full (100).

Creo que aquí tenemos la pista sobre qué está ocurriendo. Si echamos un vistazo a qué hace esta caché:

Normally you shouldn't see this particular warning though, unless you are creating / manipulating more than 100 Alfresco users per transaction

Sacado de aquí.

En tu Alfresco debes tener "algo" que manipula usuarios más de 100 por transacción (de ahí a que está completa la caché) y relentice el sistema porque siga manipulando usuarios en transacciones. Deberías analizar en profundidad qué tienes desplegado en webapps/alfresco y webapps/share por si tienes algún paquete o personalizaciones (mira en esta ruta a ver si ves algo: alfresco-5.1/tomcat/webapps/alfresco/WEB-INF/classes/), me da que no va a ser en Share, pero echa un vistazo igualmente.

Aquí te dejo sobre cómo debes aumentar la variable de la TransactionalCache :  Individual cache settings | Alfresco Documentation  ¡Ojo!: Esto no es una solución, solo es paliativo hasta que demos con el proceso que la consume.

Ve comentándonos.

Cris.

[douglascrp]

Quizás la sincronización LDAP tratando de recrear los usuários?