OSGi, Equinox, Exceptions werden "ignoriert"

[bananenkasper]

Hallo zusammen,

ich hab da mal eine Frage zu OSGi, speziell Eclipse Equinox.
Ich habe die Erfahrung gemacht, dass Exceptions, die während dem Ausführen meiner Bundles auftreten, irgendiwe "ignoriert" werden.
Soll heissen es gibt keinen Stack-Trace oder Ähnliches.
Ich bekomme keine Rückmeldung, wenn was schiefläuft.
(Ausser das mein Bundle nicht tut, was es soll... )

Mein aktuelles Workaround ist ein try-catch(Throwable)-Block um ganze Programmabschnitte, in dem ich mir dann explizit den StackTrace ausgeben lasse.

Meine Frage ist nun, wie stelle ich es an, dass mir OSGi im Fall einer Exception den entsprechenden StackTrace printet, wie man es "normalerweise" gewöhnt ist?

 

[maki]

Meine Frage ist nun, wie stelle ich es an, dass mir OSGi im Fall einer Exception den entsprechenden StackTrace printet, wie man es "normalerweise" gewöhnt ist?

Frage: Was heisst für dich "normalerweise"?
Oder anders gefragt: Welches Logging Framework nutzt du normalerweise?

 

[bananenkasper]

Frage: Was heisst für dich "normalerweise"?
Oder anders gefragt: Welches Logging Framework nutzt du normalerweise?

Also momentan handhabe ich es so, dass ich meine persönlichen debug-messages an den OSGi-Log-Service schicke.
An diesem "horcht" ein Bundle von mir, welches die Nachrichten dann an log4j weiterreicht, welcher wiederum in eine logfile bzw, auf STDOUT schreibt...

Das ist aber nicht das Problem, denke ich.
Exceptions, die nicht gefangen werden, printen ja per default ihren Stack-Trace zu STDOUT. Und da erscheint eben nichts....
Ich nehme an, OSGi fängt sie irgendwo und macht dann damit irgendetwas, von dem ich nix mitbekomme...

mein OSGi-config-file sieht momentan so aus:

org.eclipse.osgi/debug=true
org.eclipse.osgi/profile/debug = true
osgi.clean=true
eclipse.ignoreApp=true
osgi.console
osgi.bundles=\[..]

 

[maki]

Also momentan handhabe ich es so, dass ich meine persönlichen debug-messages an den OSGi-Log-Service schicke.
An diesem "horcht" ein Bundle von mir, welches die Nachrichten dann an log4j weiterreicht, welcher wiederum in eine logfile bzw, auf STDOUT schreibt...

Pax logging? (nur aus Neugier)

Das ist aber nicht das Problem, denke ich.
Exceptions, die nicht gefangen werden, printen ja per default ihren Stack-Trace zu STDOUT. Und da erscheint eben nichts....
Ich nehme an, OSGi fängt sie irgendwo und macht dann damit irgendetwas, von dem ich nix mitbekomme...

Hm... könnte es sein das ein Logging Service nicht richtig hochgefahren ist?
Was sagt denn die Equinox Konsole über den Status der Bundles?

 

[bananenkasper]

Pax logging? (nur aus Neugier)
Hm... könnte es sein das ein Logging Service nicht richtig hochgefahren ist?
Was sagt denn die Equinox Konsole über den Status der Bundles?

Pax Logging sagt mir nichts... dieses Logging-"Konstrukt" hab ich selber gebastelt...

osgi> ss

Framework is launched.

id      State       Bundle
0       ACTIVE      org.eclipse.osgi_3.4.0.v20080605-1900
1       ACTIVE      ...
2       ACTIVE      ...
3       ACTIVE      ...
4       ACTIVE      ...
5       ACTIVE      org.eclipse.equinox.ds_1.0.0.v20080427-0830
6       ACTIVE      org.eclipse.osgi.services_3.1.200.v20071203
7       ACTIVE      org.eclipse.equinox.log_1.1.0.v20080414
8       RESOLVED    org.eclipse.equinox.util_1.0.0.v20080414

osgi> diag 1
  No unresolved constraints.
osgi> diag 2
  No unresolved constraints.
osgi> diag 3
  No unresolved constraints.
osgi> diag 4
  No unresolved constraints.
osgi> diag 5
  No unresolved constraints.
osgi> diag 6 
initial@reference:file:org.eclipse.osgi.services_3.1.200.v20071203.jar/ [6]
  Direct constraints which are unresolved:
    Missing imported package javax.servlet_0.0.0.
    Missing imported package javax.servlet.http_0.0.0.
    Missing imported package javax.servlet_0.0.0.
    Missing imported package javax.servlet.http_0.0.0.
osgi> diag 7
  No unresolved constraints.
osgi> diag 8
  No unresolved constraints.

Aber ich meine die ganze Logging-Geschichte sollte damit auch eigentlich nichts zu tun haben...
Was passiert denn beispielsweise bei Dir, wenn du ein Bundle baust, und da folgendes reinsetzt:

throw new Exception("hey, das hier sollte eigentlich auf der Konsole erscheinen");

 

[maki]

Was passiert denn beispielsweise bei dir, wenn du ein Bundle baust, und da folgendes reinsetzt:

Im Activator in der start Methode?
Dann gibt es einen Stacktrace auf der Konsole sobald das Bundle gestartet wird.

 

[bananenkasper]

Im Activator in der start Methode?
Dann gibt es einen Stacktrace auf der Konsole sobald das Bundle gestartet wird.

genau, das ist es was ich unter "normales" Verhalten verstehe...
aber das klappt bei mir irgendwie nicht...
jedenfalls nicht in dem Bundle...

 

[maki]

komisch...

Stoppe doch mal das Bundle 7 und starte dann dein Bundle neu.

 

[bananenkasper]

Oh mann...
Also ich habe gemerkt, dass das momentane Problem (vermutlich) nicht mit den Exceptions zu tun hat.
Er hört an einer Stelle "einfach auf"... ka was da wieder los ist...

Bezüglich den Exceptions:
ich habe es mal reproduziert:

public Void call() throws Exception {
		try {
			waitForReqs();
			activate();
			// [..]
		} catch (InterruptedException e) {
			// [..]
		} finally {
			// [..]
			try {
			Thread.currentThread().notifyAll();
			}catch(Throwable t){
				t.printStackTrace();
			}
		}
		return null;
	}

Hier bekomme ich den StackTrace von der IllegalMonitorStateE... auf die Konsole...
Im Vergleich dazu folgendes, wo nichts ausgegeben wird:

public Void call() throws Exception {
		try {
			waitForReqs();
			activate();
			// [..]
		} catch (InterruptedException e) {
			// [..]
		} finally {
			// [..]
			// try {
			Thread.currentThread().notifyAll();
			// }catch(Throwable t){
			//	t.printStackTrace();
			// }
			
		}
		return null;
	}

 

[Wildcard]

Wenn du die Exception nicht fängst, dann wird sie nach oben durchgereicht, bis sie irgendjemand fängt und etwas damit anfängt, oder der Thread beendet wird.
Was macht der Aufrufer von call denn im Falle einer Exception?

 

[bananenkasper]

Hier nochmal ein relativ einfaches Beispiel was ich meine:

package de.kerner.osgi.commons.log.writer;

import org.osgi.framework.BundleActivator;
import org.osgi.framework.BundleContext;
import org.osgi.service.log.LogReaderService;
import org.osgi.util.tracker.ServiceTracker;

public class Activator implements BundleActivator {

	private final static int TIMEOUT = 1000;
	private LogReaderService logReaderService = null;
	private ServiceTracker tracker = null;

	public void start(BundleContext context) throws Exception {
		registerListener(context);
	}

	public void stop(BundleContext context) throws Exception {

	}

	private void registerListener(BundleContext context) throws Exception {
		System.err.println("ziemlich heiss hier...");
		tracker = new ServiceTracker(context, LogReaderService.class.getName(),
				null);
		tracker.open();
		logReaderService = (LogReaderService) tracker.waitForService(TIMEOUT);
		System.err.println("Durch... " + logReaderService);
		if (logReaderService != null) {
			logReaderService.addLogListener(new Listener());
			tracker.close();
			tracker = null;
			logReaderService = null;
		} else {
			System.err.println("Wo ist die ******* Exception??");
			throw new Exception("Wo ist der ******* LogService??");
		}
	}

}

Die Ausgabe:
osgi> ziemlich heiss hier...
Durch... null
Wo ist die ******* Exception??

 

[Wildcard]

Ich verstehe dein Problem nicht. Die API-Doc sagt doch ganz klar folgendes für die start Methode:

If this method throws an exception, this bundle is marked as stopped and the Framework will remove this bundle's listeners, unregister all services registered by this bundle, and release all services used by this bundle.

Da steht nirgends das der StackTrace auf System.err geprinted wird und das würde auch nicht viel Sinn machen.

 

[bananenkasper]

Beim Debuggen würde das schon Sinn machen.
OSGi ist stellenweise doch sehr störrisch...
Anderes Beispiel:
ClassCastException innerhalb einer for-each-Schleife.
Beim Aufruf ohne OSGi (direkt über die main) klappt alles.

class DataBean {

	private ArrayList<FASTASequence> sequences = new ArrayList<FASTASequence>();
	private ArrayList<GTFElement> elements = new ArrayList<GTFElement>();

	void addVerifiedGenesFasta(ArrayList<FASTASequence> sequences) {
		if (sequences == null)
			throw new NullPointerException();
		this.sequences.addAll(new ArrayList<FASTASequence>(sequences));
	}

	void addVerifiedGenesGtf(ArrayList<GTFElement> el) {
		if (el == null)
			throw new NullPointerException();
		this.elements.addAll(new ArrayList<GTFElement>(el));
	}

	ArrayList<? extends FASTASequence> getVerifiedGenesFasta() {
		return new ArrayList<FASTASequence>(sequences);
	}

	ArrayList<? extends GTFElement> getVerifiedGenesGtf() {
		return new ArrayList<GTFElement>(elements);
	}

	public String toString() {
		StringBuilder sb = new StringBuilder();
		sb.append("DataBean:");
		sb.append(Utils.NEW_LINE);
		sb.append("FASTAs:");
		sb.append(Utils.NEW_LINE);
		if (sequences.size() != 0) {
			System.err.println(sequences.getClass());
			System.err.println(sequences.get(0));
			System.err.println(sequences.get(0).getClass());
			for (FASTASequence seq : sequences) {
				sb.append(seq);
				// sb.append(Utils.NEW_LINE);
			}
		}
		sb.append("GTFs:");
		sb.append(Utils.NEW_LINE);
		if (elements.size() != 0)
			for (GTFElement e : elements) {
				sb.append(e);
				sb.append(Utils.NEW_LINE);
			}
		return sb.toString();
	}

	public static void main(String[] args) {

		DataBean data = new DataBean();
		FASTASequence seq = new FASTASequenceImpl("dumb header",
				new LazySequence("affe"));
		ArrayList<FASTASequence> list = new ArrayList<FASTASequence>();
		list.add(seq);
		data.addVerifiedGenesFasta(list);
		// FileUtils.objectToXML(data, file);
		// System.out.println(FileUtils.XMLToObject(DataBean.class, file));
		System.out.println(data);

	}
}

java.lang.ClassCastException: org.bioutils.fasta.FASTASequenceImpl
	at de.mpg.dataproxy.DataBean.toString(DataBean.java:35)

[EDIT:]
Nach einigem googlen denke ich, dass das Problem mit dem ClassLoader zu tun haben müsste:

BundleA liesst Daten ein und speichert sie in einem DataBean (eigenes Plugin).
BundleB hat Zugriff auf das DataBean und möchte die Daten wieder auslesen.
Wenn ich jetzt auf die Daten zugreifen will, bekomme ich die Exception... (Jedes Bundle hat eigenen ClassLoader)
So weit so gut.
Wie kann man das Problem umschiffen?

 

[Wildcard]

Beim Debuggen würde das schon Sinn machen.

Vielleicht wird es auch geprintet wenn du einen Debug Schalter setzt, keine Ahnung. Ein sinnvolles Default Verhalten ist es jedenfalls keinesfalls. Exceptions einfach auf std.err zu printen ist wenig hilfreich, dafür gibt es schließlich logging.

Nach einigem googlen denke ich, dass das Problem mit dem ClassLoader zu tun haben müsste:

BundleA liesst Daten ein und speichert sie in einem DataBean (eigenes Plugin).
BundleB hat Zugriff auf das DataBean und möchte die Daten wieder auslesen.
Wenn ich jetzt auf die Daten zugreifen will, bekomme ich die Exception... (Jedes Bundle hat eigenen ClassLoader)
So weit so gut.
Wie kann man das Problem umschiffen?

Wie kommst du darauf das es Classloader Problem ist? Die Beschreibung reicht nicht aus um viel sinnvolles dazu sagen zu können.
Wer kommuniziert wie mit wem und welcher Stelle genau bekommst du eine ClassCastException (von was auf was willst du casten)?

 

[faetzminator]

Wie wärs, wenn du in der aufzurufenden Methode von dir die Exception fängst, sie an deinen Logger reichst und weiterschmeisst?

 

[bananenkasper]

Vielleicht wird es auch geprintet wenn du einen Debug Schalter setzt, keine Ahnung. Ein sinnvolles Default Verhalten ist es jedenfalls keinesfalls. Exceptions einfach auf std.err zu printen ist wenig hilfreich, dafür gibt es schließlich logging.

Mit Logging kann ich aber auch nur Exceptions behandeln, die ich explizit fange.
"ungefangene" Exceptions, also RuntimeExceptions und Errors sollten auf jedenfall standardmässig irgendwo erscheinen.
Das Plugin in diesem Fall einfach zu disablen ohne jede Meldung ist alles andere als optimal.

Wie kommst du darauf das es Classloader Problem ist? Die Beschreibung reicht nicht aus um viel sinnvolles dazu sagen zu können.
Wer kommuniziert wie mit wem und welcher Stelle genau bekommst du eine ClassCastException (von was auf was willst du casten)?

Es scheint in der Tat ein Classloader Problem gewesen zu sein.
Nochmal eine kurze Erläuterung des Problems:

Drei Plugins: Producer, Consumer, DataProvider.

Producer liesst Daten ein, gibt sie an den DataProvider.
Der verwaltet diese, und gibt sie bei Bedarf weiter an Consumer.
Bei den Datan handelt es sich beispielsweise um eine ArrayList<SomeType>.
Die Liste wurde von Producer erstellt.
DataProvider nimmt nun diese Liste, und macht folgendes:

for(SomeType t : list){
// do something
}

In der ersten Zeile kommt es zu einer ClassCastException. (Ich selbst habe garnichts gecastet)
Problem:
ClassLoader von DataProvider "kennt" SomeType nicht.
Nicht etwa weil er die Klassen nicht im ClassPath hat, sondern weil er die Elemente in der Liste nicht selbst erstellt hat.
Wie sich das genau verhält, kann ich bis jetzt auch nicht sagen.
Jedenfalls kommt es zu einer ClassCastException in der Zeile

for(SomeType t : list){

genau wie

list.iterator().next().getClass()

Ich habe das Problem gelöst, indem ich vor dem Zugriff auf die Liste innherhalb von DataProvider eine "DeepCopy" mittels Serializierung erstellt habe.
Die Liste wird Element für Element serialisiert und deserialisiert, wobei bei der Deserialisierung eine neue Liste plus neue Elemente erstellt wird, und zwar vom ClassLoader von DataProvider.
Und siehe da, keine Exception mehr, alles läuft wie es soll.

public static <V> V deepCopy(Class<V> c, Serializable s) throws IOException, ClassNotFoundException{
		if(c == null || s == null)
			throw new NullPointerException();
		ByteArrayOutputStream bs = new ByteArrayOutputStream();
		new ObjectOutputStream(bs).writeObject(s);
		ByteArrayInputStream bi = new ByteArrayInputStream(bs.toByteArray());
		V v = c.cast(new ObjectInputStream(bi).readObject());
		bs.close();
		bi.close();
		return v;
	}

Wie wärs, wenn du in der aufzurufenden Methode von dir die Exception fängst, sie an deinen Logger reichst und weiterschmeisst?

So mache ich es momentan (zumindest solange ich noch "bastele").
Alle Aktion in der "activate()" bzw. "start()" sind in einem try catch Block.

try{
// everything
} catch(Throwable t){
t.printStackTrace();
}

Das ist aber sicher nicht die feine englische Art. Nicht zuletzt performance-technisch.
Ausserdem war es halt extrem nervig, als ich noch nicht verstanden habe, warum mein Plugin einfach aufhört und garnichts macht.
Ohne Fehlermeldung oder sonst was.

 

[maki]

In der Tat, nicht genug Info um zu sagen was los ist.
Würde mal deine Target Plattform neu erzeugen, bei mir werden Exceptions im Activator auf die Konsole geschrieben.

Zu deiner CLassCastException, woher kommen denn die Daten, aus Hibernate oder ähnlichem?
Könnte ja sein dass du nur Proxies bekommst... aber ohne StackTrace nur geraten.

 

[byte]

Ist evtl. ein UncaughtExceptionHandler konfiguriert, der einfach alles verschluckt?

 

[Wildcard]

Mit Logging kann ich aber auch nur Exceptions behandeln, die ich explizit fange.
"ungefangene" Exceptions, also RuntimeExceptions und Errors sollten auf jedenfall standardmässig irgendwo erscheinen.
Das Plugin in diesem Fall einfach zu disablen ohne jede Meldung ist alles andere als optimal.

Ich kann dir nicht sagen wie es bei rohem OSGi ist (vermutlich eine Konfigurationssache), aber bei Eclipse landet so etwas im Log und nicht auf der Konsole und genau dort würde ich auch suchen.

ClassLoader von DataProvider "kennt" SomeType nicht.
Nicht etwa weil er die Klassen nicht im ClassPath hat, sondern weil er die Elemente in der Liste nicht selbst erstellt hat.
Wie sich das genau verhält, kann ich bis jetzt auch nicht sagen.
Jedenfalls kommt es zu einer ClassCastException in der Zeile

Ich würde davon ausgehen das SomeType (wenn, wie du sagst, das DataProvider Bundle den Typ im Manifest importiert) in einer anderen Version vorliegt als dort wo es erstellt wurde. Das die Klasse also in verschiedenen Bibliotheken vorliegt und sich beide Bundles aus unterschiedlichen bedienen.

 

[bananenkasper]

Ich würde davon ausgehen das SomeType (wenn, wie du sagst, das DataProvider Bundle den Typ im Manifest importiert) in einer anderen Version vorliegt als dort wo es erstellt wurde. Das die Klasse also in verschiedenen Bibliotheken vorliegt und sich beide Bundles aus unterschiedlichen bedienen.

"SomeType" ist aus einer externen lib.
Das jar-File habe ich in allen Bundles, die mit "SomeType" arbeiten, im Manifest dem ClassPath hinzugefügt.

 

[Wildcard]

Das heißt jedes Bundle hat eine eigene Kopie davon? Warum? Da wird dein Problem wohl auch herkommen. Deploy das jar doch als Bundle, oder pack es in eins deiner Bundles und lass dieses die Packages exportieren.

 

[bananenkasper]

Bam! Ich sag nur Wald und Bäume...
Vielen Dank für den Hinweis, Wildcard, das sollte in der Tat einiges vereinfachen!