java/lang/OutOfMemoryError in einem Zeitgesteuerten Agenten

[USmash]

Wir haben ein kleines, nein grosses Problem mit einem zeitgesteuerten Agenten.

Es wurde ein Java Agent erstellt, der eine ORACLE Datenbank abfragen soll. Nachdem der Agent gestartet ist läuft er scheinbar problemlos, stürzt dann aber irgendwann; mal nach 6 Durchgängen, mal nach 25 Durchgängen mit dem Fehler "java/lang/OutOfMemoryError" ab. Lediglich der Neustart des Servers behebt dann den Fehler.
Der Agent liest das erste Dokument aus einer Ansicht, und schreibt dann eine Adresse ins Dokument (String) und speichert das Dokument.
Im Fehlertext wird dann aber die Meldung 'Attempt to retrieve Java agent attachments failed' ausgegeben. Da wir aber gar keine Attachments verarbeiten ein Mysterium -oder- ?

HELP


Hier der Agentlog
19.01.2012 11:04:24   AMgr: Agent ('Test1' in 'bereiche\test\JDBCTest.nsf') error message: JVMDUMP006I Speicherauszugsereignis "systhrow" wird verarbeitet; Detail "java/lang/OutOfMemoryError" - Bitte warten.

19.01.2012 11:04:24   AMgr: Agent ('Test1' in 'bereiche\test\JDBCTest.nsf') error message: JVMDUMP007I JVM fordert Snap-Speicherauszug mit 'D:\Programme\Lotus\Domino\Prog\Snap.20120119.110424.1916.0005.trc' an.

19.01.2012 11:04:24   AMgr: Agent ('Test1' in 'bereiche\test\JDBCTest.nsf') error message: JVMDUMP010I Snap-Speicherauszug geschrieben auf D:\Programme\Lotus\Domino\Prog\Snap.20120119.110424.1916.0005.trc

19.01.2012 11:04:24   AMgr: Agent ('Test1' in 'bereiche\test\JDBCTest.nsf') error message: JVMDUMP007I JVM fordert Heap-Speicherauszug mit 'D:\Programme\Lotus\Domino\Prog\heapdump.20120119.110424.1916.0006.phd' an.

19.01.2012 11:04:24   AMgr: Agent ('Test1' in 'bereiche\test\JDBCTest.nsf') error message: JVMDUMP010I Heap-Speicherauszug geschrieben auf D:\Programme\Lotus\Domino\Prog\heapdump.20120119.110424.1916.0006.phd

19.01.2012 11:04:24   AMgr: Agent ('Test1' in 'bereiche\test\JDBCTest.nsf') error message: JVMDUMP013I Speicherauszugsereignis "systhrow" verarbeitet, Detail "java/lang/OutOfMemoryError".

19.01.2012 11:04:24   AMgr: Agent ('Test1' in 'bereiche\test\JDBCTest.nsf') error message: Ausnahmebedingung in Thread "main"
19.01.2012 11:04:24   AMgr: Agent ('Test1' in 'bereiche\test\JDBCTest.nsf') error message: java.lang.OutOfMemoryError
19.01.2012 11:04:24   JVM: The addAttachment (Ljava/lang/String;[B)V() method failed.
19.01.2012 11:05:22   AMgr: Agent 'Test1' in 'bereiche\test\JDBCTest.nsf' did not process all documents successfully.  Check the Agent Log for more information: JVM: Attempt to retrieve Java agent attachments failed.

[Ralf_M_Petter]

Ich nehme mal an, dass du kein recycle in deinem Agent verwendest. Das solltest du unbedingt verwenden.

Grüße

Ralf

[eknori]

jepp, recycle() sollte helfen. Der Fehler geistert schon seit version 4 im LDD rum und immer war es irgendein Object, das nicht vernünftig recycled wurde.

[USmash]

Danke für den Hinweis auf recycle(). Als guter Forumsleser hab ich natürlich vorher mal gesucht  .

Ich habe die Funktion schon benutzt. Wir haben an den Servereinstellungen für HTTPJavaMaxHeapSize=256M gesetzt; auf einem anderen Server auf 512M. Hat aber auch keinen Erfolg gebracht. 

[Ralf_M_Petter]

Eventuell postest du mal etwas code. Dann tut man sich sicher bei der Hilfe leichter.

Übrigens wie hast du denn den JDBC Treiber eingebunden. Hast du ihn in die NSF gepackt oder über die JVM eingebunden?

Grüße

Ralf

[USmash]

Hallo Ralf,

den JDBC Treiber hab ich in die "Archivieren" Sektion des Agenten importiert (classes12.jar)

hier der komplette Code :

import java.sql.Connection;
import java.sql.DriverManager;
import java.sql.ResultSet;
import java.sql.Statement;
import java.util.Enumeration;

import lotus.domino.*;
// import oracle.jdbc.*;

public class JavaAgent extends AgentBase {

   public void NotesMain() {

      try {
         // (Your code goes here)
         String employeeID;
         String Querry;
         int strStart;
         int strEnde;
         int doccount;
         String NewDocCount;
         // Start Verarbeitung
         Session session = getSession();
         Statement stmt;
         ResultSet rs; 
         // Initialisierung
         AgentContext agentContext = session.getAgentContext();         
         Database db = agentContext.getCurrentDatabase();
         View v = db.getView("Alle");         
         Document doc=v.getFirstDocument();
         //Dokument bearbeiten
         // Zähler hochsetzen
         doccount = Integer.parseInt(doc.getItemValueString("st_count"));
         doccount = doccount + 1;
         NewDocCount = Integer.toString(doccount);
         // und ins Dokument schreiben
         doc.replaceItemValue("st_count", NewDocCount);
         // Kundennumer lesen und aufbereiten
         employeeID= "0000000"+doc.getItemValueString("st_kundennr");
         strEnde = employeeID.length();
         strStart = strEnde-10;         
         employeeID = employeeID.substring(strStart, strEnde);

         System.out.println("Start Test1 mit KundenNummer "+ employeeID );
         // JDBC Abfrage
         Querry = "SELECT * FROM TRANSFER WHERE TRANSFER.STAMMNUMMER='"+employeeID+"'";
         // (Your code goes here)
         Class.forName("oracle.jdbc.driver.OracleDriver");
         System.out.println("Initialisierung des ORACLE ODBC Drivers");
         System.out.println("-----------------------------------------------");
         int j=0 ;
         for( Enumeration en = DriverManager.getDrivers() ; en.hasMoreElements() ; j++)
            System.out.println( en.nextElement().getClass().getName() );
         if (j==0)
            System.out.println("Treiberliste leer");
         System.out.println("-----------------------------------------------");
         String cStr = "jdbc:oracle:thin:@IP-Adr:1521:NAME";
         System.out.println( cStr );
         System.out.println("Anmeldung an DB");            
         Connection con = DriverManager.getConnection( cStr, "Test", "Test");
         stmt=con.createStatement();
         System.out.println("Anmeldung erfolgt");
         rs=stmt.executeQuery( Querry );
         System.out.println("Query >> " + Querry + " << is executed");

         while(rs.next())
         {
            doc.replaceItemValue("st_result", rs.getString("BODYTEXT"));
            doc.replaceItemValue("st_kundennr", employeeID);
            System.out.println ("Abfrage erfolgt. Ergebnis : Type --> " + rs.getString("TYPE"));
         }
         // abschliessende Tätigkeiten
         doc.save();

         rs.close();
         stmt.close();
         con.close();

         agentContext.recycle();
         db.recycle();
         v.recycle();
         doc.recycle();
         System.out.println("Ende");

      }
      catch(NotesException e){
         System.out.println(e.id + " " + e.text);
      }
      catch(Exception e){
         e.printStackTrace();
      }
   }   
}

[flaite]

Ralf meint mit "über die JVM eingebunden" : Du tust die jars für den Oracle Zugrieff in das Verzeichnis /lib/ext und hängst sie nicht an den Agenten. Ich hab immer 3rd-party jars in dieses Verzeichnis gepackt. Es ist nicht besonders beliebt bei Administratoren, aber es ist notwendig.

Stephan Wissel hat in einer kürzlichen Diskussion in codestore geschrieben:

[...] What I found in agents: if you have external jars and the agent runs multiple times it starts bleeding memory since a new classloader is instantiated every time.

The solution here is to deploy your jar into lib/ext so it isn't part of your agent, but on the general Java classpath (you can use an LS agent to do the deployment - see the patched updatesite.ntf on OpenNTF). That improves the situation quite a bit. You actually could put everything in the jar and use the agent only to hand over the collection for processing.

Du hast einen Memory Leak in dem Agenten. Ein Hochsetzen des Heap-Spaces verlängert nur ein wenig die Zeit, wann dieser auftritt.
In Agenten solltest du recycle() in Schleifen benutzen.

Typische Situation ist das:

Code

while (doc != null) {
 
....
Document oldDoc = doc;
doc = vw.getNextDocument();
oldDoc.recycle();
oldDoc = null;
}

Ansonsten alle Notes-Objekte recyclen, die Du mit dem Java Schlüsselwort new instantiierst.

Database, View und Doc unten werden NICHT mit new instantiiert, müssen folglich nicht recycled werden:

Code

Database db = agentContext.getCurrentDatabase();
View vw = db.getView("myView");
Document doc = vw.getFirstDocument();

Die Umgebung, in der der Domino Agent kümmert sich darum. Er recycled die Session und den gesammten Objekt-Tree, der mit der Session initiiert wurde.

Session ist Factory für agentContext
agentContext ist Factory für db
db ist Factory für vw
vw ist Factory für doc.

Der ganze Baum wird über session.recycle() rekursiv recycled und Session recycle wird automatisch am Ende des Domino Agenten aufgerufen.
Wenn Du zu viel recyclest findest Du eine Meldung in der log.nsf.

Gruß Axel  

[flaite]

Hallo Ralf,

den JDBC Treiber hab ich in die "Archivieren" Sektion des Agenten importiert (classes12.jar)

Ich bin zwar nicht Ralf,

Es sollte sich ausgehen, wenn Du classes12.jar in das lib/ext von den Server packst. Vermutlich mußt Du den Server neu starten. S. mein Stephan Wissel quote in meinem Posting oben.
Das ResultSet enthält immer nur einen Treffer, richtig?
Unter der Annahme ist recycle() nicht nötig!
Deine recycle() Aktivitäten am Ende nur zu einer Fehlermeldung im log.nsf. Schau da mal nach.

UND NOCH WAS:
Das folgende ist nicht persönlich gemeint. Ich finde Programmierer-Schwanz-Vergleiche absolut unmenschlich. Versteh das als konstruktive Kritik, nicht als persönliche Kritik.

So kann man heute keinen source code mehr schreiben!!!
Würd ich sowas auf der Arbeit einchecken, wär ich ziemlich schnell gefeuert.
Nun bin ich heute JEE Entwickler (Springframework inkludiert).
In Domino Umgebungen ist man da viiiiel permissiver. Aber dieses anything goes führt letztlich zu einer sinkenden Akzeptanz von Domino Anwendungen. Es existieren nämlich auf der Hand liegende Gründe, dass ein gewisser handwerklicher Selbstrespekt keine le art pour le art Schnörkel von weltfremden Codern sind, sondern das dem viel mehr klare ökonomische Argumente zugrunde liegen.
Ich werd das heute mal im Laufe des Tages refaktorieren, um das LESBARER und WIEDERVERWENDBARER zu machen.
Das ist eine Methode mit fast ca. 80 Zeilen, um 3 Werte aus einer Oracle-DB zu lesen und in ein Dokument zu schreiben.
Wiederverwendbarkeit rein über copy & paste.
Normal ist heute, das Methoden von einer Länge mit über 30 Zeilen von statischen Qualitäts-Check Tools markiert werden. Da brauchts nicht mal eine code-review.

[flaite]

Noch was:
Versuch den Oracle Treiber mal so zu instantiieren:

Code

java.sql.Driver d = (java.sql.Driver) 
Class.forName (
               "oracle.jdbc.driver.OracleDriver").newInstance ();

          DriverManager.registerDriver (d)

Mit der reinen Class.forName() hatte Domino mal Probleme. Mir nicht klar, ob heute noch.

Man sieht auch die Alternative:

Code

Class.forName (
               "oracle.jdbc.driver.OracleDriver").newInstance ();

Jedenfalls immer mit newInstance(). 

[USmash]

Hallo Pitiyankee,

hab den Drivermanager mal so instanziiert, wie Du geschrieben hast, und die Klasse auf dem Server ins Verzeichnis lib\ext\ abgelegt und aus dem Agenten entfernt.
Jetzt folgt der Neustart des Servers und dann mal sehn ...

Ich melde mich mit den Ergebnissen.
Danke

Uwe

[USmash]

So, die ersten 10 Durchläufe sind im Kasten. Mal sehen, wie es am Montag aussieht.
Bis dahin...
Uwe

[flaite]

Hallo Uwe,

kannst Du mir vielleicht mal diese Datei schicken
D:\Programme\Lotus\Domino\Prog\heapdump.20120119.110424.1916.0006.phd
axel punkt janssen klammeraffe gmail punkt com
Mich würde interessieren wie das aussieht.

Die Fehlermeldung "Attempt to retrieve Java agent attachments failed" würde btw. Sinn ergeben. Der Agenten ClassLoader holt sich ja seine Klassen aus Attachments. Die Meldung ist kryptisch, aber wenn man da drinsteckt wiederum nicht. Man kann das nicht wissen, wenn man zwischendurch mal einen Java Agenten entwickeln, also keine Kritik an dir.

Schon wirklich irre, dass Memory Leaks durch ClassLoader erzeugt werden. Also etwas, das 100% unter Kontrolle der Produkt-Entwickler steht. Nach fast 15 Jahren Java in Domino. ClassLoader können in komplexen Java Umgebungen komplex werden. In JBoss wurd das etwa in der 8er Version ganz neu gemacht. Die hatten da auch Leichen im Keller, aber sie führten nicht zu Memory Leaks. Es konnte nur bei mehreren Versionen von jars komplex werden, welche Version geladen wird. Websphere hat das btw. von Anfang an sehr transparent gelöst. Ich vermute, dass dieses Problem seit Domino 5 oder sogar 4.6 nie angegangen wurde. Nicht wichtig. Ich brabbel nur vor mich hin.


Liebe Grüße

Axel

[USmash]

Moin zusammen,

der Agent hat übers Wochenende wie geplant nigx gemacht und ab Montag bis jezt klaglos durchgehalten. 

Vielen Dank für die hilfreichen Tips, die jetzt zum Erfolg geführt haben.

[flaite]

Ich hab in den letzten 6 Jahren ja auf Domino weitgehend nur noch Spezial-Ausgaben mit Domino und Dojo/JavaScript gemacht.
Bei den Java Agenten hab ich immer darauf insistiert, dass die 3rd-party jars ins lib/ext kommen. Hab mit dem Anhängen an den Agenten einmal schlechte Erfahrung gemacht und bin dann der Ursache nie auf den Grund gegangen.
Die Diskussionen über dieses Vorgehen tendierten dazu, unangenehm zu sein, weil Domino-Administratoren und andere aficionados von Domino es für nicht richtig "professionell" hielten. Der praktische Kern ist, dass das lib/ext nicht repliziert wird. Für jeden neuen Server, auf die wo der Agent verteilt wird, muss das lib/ext händisch kopiert werden.
Nun hat Stephan Wissel kürzlich in einer codestore.net Diskussion darauf hingewiesen, dass die für den Classloader, der in den Agenten hereingehängten jars, der garbage collector von Java nicht wirklich funktioniert. Damit ist lib/ext die einzige Chance, um Memory Leaks zu verhindern!

Ich vermute, dass dies seit 4.6 broken ist. 13 Jahre wurd dieses fundamentale Problem von Lotus@IBM nicht angegangen.
Wie viele mühsam entwickelte Java Agenten werden wohl an diesem undokumentierten Bug gescheitert sein? Wie oft werden Entwickler gedacht haben, dass sie die im Grunde einfachen recycle() Regeln doch nicht endgültig kapiert haben und dass der Memory Leak darin begründet liegt?

Gruß Axel