AppSync: Dateisystemzuordnung schlägt mit "HeapDumpOnOutOfMemoryError" fehl

AppSync-Jobs bleiben hängen und nachfolgende Jobs können nicht ausgeführt werden.

Im AppSync-Serverprotokoll (C:\EMC\AppSync\jboss\logs\server.log auf dem AppSync-Server) wird der AppSync-Serverdienst hier neu gestartet …

07-30-2016 01:10:13.494 INFO [MSC service thread 1-1] [org.jboss.as.naming] [] [] JBAS011802: Starting Naming Service
07-30-2016 01:10:14.823 INFO [MSC service thread 1-7] [org.jboss.ws.common.management.AbstractServerConfig] [] [] JBoss Web Services - Stack CXF Server 4.0.2.GA

Im AppSync Executive-Protokoll (C:\EMC\AppSync\jboss\logs\executive.log auf dem AppSync-Server) wird der folgende Fehler angezeigt:

4098664,623: [Full GC
 [PSYoungGen: 384064K->384062K(404032K)] [ParOldGen: 1398143K->1398143K(1398144K)] 1782207K->1782205K(1802176K) [PSPermGen: 157954K->157954K(158272K)], 1.4650114 secs] [Times: user=5.06 sys=0.00, real=1.47 secs]
Shutdown failed: Timed out waiting for signal from JVM.
Enqueue Event 'jvm_kill'
4098666.090: [Full GC
JVM did not exit on request, terminated
Enqueue Event 'jvm_killed'
Enqueue Event 'jvm_stopped'
socket read failed. (Eine bestehende Verbindung wurde vom Remote-Host zwangsweise geschlossen. (0x2746))
Closing backend socket.
Preparing to restart with mode 4.
Die JVM lief nur für -547624 Sekunden, was zu einer fehlgeschlagenen Neustartanzahl von 1 führte.
Enqueue Event 'jvm_failed_invocation'
5 Sekunden warten, bevor Sie eine weitere JVM starten.
Server hört auf Port 32000.
Ping settings: wrapper.ping.interval=5, wrapper.ping.interval.logged=1, wrapper.ping.timeout=300
Enqueue Event 'jvm_restart'
Enqueue Event 'jvm_prelaunch'
Launching a JVM...
Command: "_jre\bin\java" -server -Xms1024m -Xmx2048m -XX:MaxPermSize=512m -XX:+HeapDumpOnOutOfMemoryError -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintCommandLineFlags -XX:+UseCompressedOops -Dsun.rmi.dgc.client.gcInterval=3600000 -Dsun.rmi.dgc.server.gcInterval=3600000 -Djava.net.preferIPv4Stack=false -Dorg.jboss.resolver.warning=true -Dorg.tanukisoftware.wrapper.WrapperManager.mbean=false -Djboss.modules.system.pkgs=org.jboss.byteman -Djboss.server.default.config=standalone.xml -Djava.util.logging.manager=org.jboss.logmanager.LogManager -Dorg.jboss.boot.log.file=logs/boot.log -Dlogging.configuration=file:standalone/configuration/logging.properties -Djboss.server.log.dir=logs -Dappsync.server=SVRAPPSYNC.PHYSIOCORP.COM -Dfile.encoding=UTF8 -Duser.language=en -Djava.library.path="executive;../CST/builds/win_vc100_x64_r/bin" -classpath "executive/wrapper.jar;./jboss-modules.jar" -Dwrapper.key="g6PkoEa65igOyT26W3eDRDQ6_Kektd7Q" -Dwrapper.port=32000 -Dwrapper.jvm.port.min=31000 -Dwrapper.jvm.port.max=31999 -Dwrapper.debug="TRUE" -Dwrapper.pid=3408 -Dwrapper.version="3.5.14-pro" -Dwrapper.native_library="wrapper" -Dwrapper.service="TRUE" -Dwrapper.cpu.timeout="10" -Dwrapper.jvmid=2 -Dwrapper.lang.domain=wrapper -Dwrapper.lang.folder=../lang org.tanukisoftware.wrapper.WrapperJarApp jboss-modules.jar -mp modules -jaxpmodule javax.xml.jaxp-provider org.jboss.as.standalone -Djboss.home.dir=.
JVM started (PID=7788)
Enqueue Event 'jvm_start'
-XX:+HeapDumpOnOutOfMemoryError -XX:InitialHeapSize=1073741824 -XX:MaxHeapSize=2147483648 -XX:MaxPermSize=536870912 -XX:+PrintCommandLineFlags -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCompressedOops -XX:-UseLargePagesIndividualAllocation -XX:+UseParallelGC
WrapperManager Debug: WrapperManager class initialized by thread: main   Using classloader: sun.misc.Launcher$AppClassLoader@78d5c653
WrapperManager: Initializing...
WrapperManager Debug: JVM #2
WrapperManager Debug: Running a 64-bit JVM.
WrapperManager Debug: org.tanukisoftware.wrapper.WrapperManager package information:
WrapperManager Debug:   Implementation Title: org.tanukisoftware.wrapper
WrapperManager Debug:   Implementation Vendor: Tanuki Software, Ltd.
WrapperManager Debug:   Implementation Version: 3.5.14
WrapperManager Debug:   Is Sealed?: False
WrapperManager Debug: org.tanukisoftware.wrapper.WrapperManager protection domain:
WrapperManager Debug:   Location: file:/C:/EMC/AppSync/jboss/executive/wrapper.jar
WrapperManager Debug:     Size: 117.262
WrapperManager Debug:     MD5: 3a16b23744071559f42f26c48b36e756
WrapperManager Debug: Registering shutdown hook
WrapperManager Debug: Using wrapper
WrapperManager Debug: Native Bibliothek laden.  Es gibt mehrere mögliche Dateinamen und der erste gefundene Dateiname wird verwendet.  Fehler beim Laden nicht vorhandener Dateien sind normal und stellen nur dann ein Problem dar, wenn alle fehlschlagen.
WrapperManager Debug:   Attempt to load native library with name: wrapper-windows-x86-64.dll  Result: no wrapper-windows-x86-64 in java.library.path
WrapperManager Debug:   Attempt to load native library with name: wrapper.dll  Result: Success!
WrapperManager Debug:   Successfully loaded native library.
WrapperManager Debug: Loaded localized resources.
WrapperManager Debug: Calling native initialization method.
WrapperJNI Debug: Initializing WrapperManager native library.
WrapperJNI Debug: Ausführbare Java-Datei: C:\EMC\AppSync\jboss\_jre\bin\java.exe
WrapperJNI Debug: Native Bibliothek: C:\EMC\AppSync\jboss\executive\wrapper.dll
WrapperJNI Debug: Windows-Version: 6.2.9200
WrapperManager Debug: Java-Version: 1.7.0_17-b02 Java HotSpot(TM) 64-Bit Server VM
WrapperManager Debug: Java-VM-Anbieter: Oracle Corporation
WrapperManager Debug: Betriebssystemname: Windows Server 2012
WrapperManager Debug: OS Arch        : amd64
WrapperManager Debug:
WrapperManager Debug: Control event monitor thread started.
WrapperManager Debug: Start-Runner-Thread gestartet.
WrapperJarApp-Debug: Jar Main-Class: org.jboss.modules.Main
WrapperJarApp Debug: JAR-Klassenpfad: Nicht angegeben.
WrapperJarApp-Debug:     Classpath[0]=file:C:/EMC/AppSync/jboss/jboss-modules.jar
WrapperManager Debug: WrapperManager.start(org.tanukisoftware.wrapper.WrapperJarApp@5bfa19ca, args["-mp", "modules", "-jaxpmodule", "javax.xml.jaxp-provider", "org.jboss.as.standalone", "-Djboss.home.dir=."]) called by thread: main
WrapperManager Debug: Kommunikations-Runner-Thread gestartet.
WrapperManager Debug: Sockel zum Wrapper öffnen … Wrapper-Verbindung
WrapperManager Debug: Geöffneter Sockel von 31.000 auf 32.000
WrapperManager Debug: Send a packet KEY : g6PkoEa65igOyT26W3eDRDQ6_Kektd7Q
WrapperManager Debug: handleBackend()
Sockel akzeptiert von 127.0.0.1 on port 31000
Back-end-Server schließen.
Paket-SCHLÜSSEL lesen: g6PkoEa65igOyT26W3eDRDQ6_Kektd7Q
Schlüssel von JVM erhalten: g6PkoEa65igOyT26W3eDRDQ6_Kektd7Q
Paket senden LOW_LOG_LEVEL : 1
Paket senden LOGFILE : logs\executive.log
Paket senden PROPERTIES : (Eigenschaftswerte)
Start Application.
send a packet START : start
WrapperManager Debug: Paket empfangen LOW_LOG_LEVEL : 1
WrapperManager Debug: LowLogLevel from Wrapper is 1
WrapperManager Debug: Paket empfangen LOGFILE : logs\executive.log
WrapperManager Debug: Paket empfangen PROPERTIES : (Eigenschaftswerte)
WrapperManager Debug: Paket empfangen START : start
WrapperManager Debug: Temporäres Java-Verzeichnis: C:\Windows\TEMP
WrapperManager Debug: calling WrapperListener.start()
WrapperManager Debug: WrapperListener.start Runner-Thread gestartet.
WrapperJarApp Debug: start(args) Wartet bis zu 2 Sekunden, bis die Hauptmethode abgeschlossen ist.
WrapperJarApp Debug: ruft Hauptmethode auf
WrapperManager Debug: Paket senden START_PENDING : 5000
Paket lesen START_PENDING : 5000
JVM signalisierte einen Start mit einer Wartezeit von 5000 Millisekunden.
WrapperManager Debug: Paket senden START_PENDING : 5000
WrapperJarApp Debug: start(args) end.  Main Completed=false, exitCode=null
WrapperManager Debug: returned from WrapperListener.start()
WrapperManager Debug: Paket senden STARTED :
WrapperManager Debug: WrapperListener.start Runner-Thread angehalten.
WrapperManager Debug: Startup Runner-Thread angehalten.
Paket lesen START_PENDING : 5000
JVM signalisierte einen Start mit einer Wartezeit von 5000 Millisekunden.
Paket lesen STARTED :
JVM signalisierte, dass sie gestartet wurde.
Enqueue Event 'jvm_started'
Paket senden PING : ping
WrapperManager Debug: Paket empfangen PING : ping
WrapperManager Debug: Paket senden PING : ping
read a packet PING : ping
INFO  (WrapperJarAppMain) 2016-07-30 01:10:02,400 [org.jboss.modules] Module JBoss Modules version 1.1.1.GA
Paket senden PING : ping
WrapperManager Debug: Paket empfangen PING : ping
WrapperManager Debug: Paket senden PING : ping
Paket lesen PING : ping
INFO  (WrapperJarAppMain) 2016-07-30 01:10:05,072 [org.jboss.msc] ServiceLogger_$logger JBoss MSC version 1.0.2.GA
INFO  (MSC service thread 1-4) 2016-07-30 01:10:05,151 [org.jboss.as] ApplicationServerService JBAS015899: JBoss AS 7.1.1.Final "Brontes" starting
WrapperJarApp Debug: main method completed
Paket senden PING : ping
WrapperManager Debug: Paket empfangen PING : ping
WrapperManager Debug: Send a packet PING : ping
read a packet PING : ping
INFO  (MSC service thread 1-3) 2016-07-30 01:10:11,057 [org.xnio] Xnio XNIO Version 3.0.3.GA
INFO  (Controller Boot Thread) 2016-07-30 01:10:11,057 [org.jboss.as.server] HttpManagementAddHandler JBAS015888: Erstellen eines HTTP-Verwaltungsdienstes mithilfe von Socket-Bindung (management-http)
INFO  (MSC service thread 1-3) 2016-07-30 01:10:11,213 [org.xnio.nio] NioXnio XNIO NIO Implementation Version 3.0.3.GA
INFO  (ServerService Thread Pool -- 25) 2016-07-30 01:10:11,651 [org.jboss.as.configadmin] ConfigAdminAdd JBAS016200: Activating ConfigAdmin Subsystem
21.020: [GC [PSYoungGen: 262208K->21745K(305856K)] 262263K->21808K(1004928K), 0.0279106 secs] [Times: user=0.05 sys=0.03, real=0.03 secs]
21.051: [GC [PSYoungGen: 82212K->21713K(305856K)] 82275K->21848K(1004928K), 0.0207127 secs] [Times: user=0.06 sys=0.00, real=0.02 secs]
INFO  (ServerService Thread Pool -- 30) 2016-07-30 01:10:11,713 [org.jboss.as.clustering.infinispan] InfinispanSubsystemAdd JBAS010280: Activating Infinispan subsystem.
INFO  (ServerService Thread Pool -- 46) 2016-07-30 01:10:

Während der Zuordnungsvorgang ausgeführt wurde, kam es aufgrund eines Problems mit unzureichendem Arbeitsspeicher zu einem Neustart des AppSync-Server-Dienstes. Dies führte zu einem veralteten Zuordnungseintrag in der internen AppSync-Datenbank.

Auflösung:

Mit dem Fix wird verhindert, dass der veraltete Eintrag auftritt, sodass es zu keinem Aufhängen mehr kommt und nachfolgende Jobs ausgeführt werden können.
Dieses Problem wurde in AppSync 2.2.3.1 behoben.