SQL Stored Procedures u. ThreadSafety

[BenderD]

auch der in deinem link beschriebene Fall ist eine grob fehlerhafte Implementierung in Java und kein Bug in der Datenbank:
private static PreparedStatement ps = null;
dieses Konstrukt ist Java seitig nicht Threadsafe!!!

mit solch einem Konstrukt kann ich soviele Connections verwenden, wie ich will - das preparedStatement wird unterm Hintern weg ausgetauscht, und das nicht nur über Threads, sondern über alle Objekte in der JVM, da schüttelts mich, und wenn ich in den Sandalen Socken anhätte, dann hätten meine sich hochrollenden Fußnägel Löcher hinterlassen.

Dieter Bender

Vielen Dank nochmals für die vielen Anregungen. Mittlerweile habe ich auf Connectionpools umgestellt. Wobei ich aber noch nicht nach jedem SQL eine 'neue' Connection verwende. Zumindest wird jetzt eine Connection auch nur von einem Thread verwendet.

Das Phänomen mit manchmal unsinnigen zurückgegeben Resultsets habe ich aber nach wie vor.

Unter: IBM - SE25763 - OSP-DB-MSGCPD4373 OR EMPTY RESULT SET
habe ich aber folgendes gefunden, wovon ich ausgehe, dass dies unser Phänomen genau beschreibt. Leider haben wir keine AS400 mit höherem Releasestand um dies auch bestätigen zu können.

[axl]

Der Link auf die Fehlerbeschreibung war eigentlich mehr wegen der Ähnlichkeit des Fehlers drin. Die Implementierung bei uns sieht anders aus. Wir verwenden auch keine static PreparedStatement Variablen, wie in dem Link beschrieben.

Mittlerweile kann ich (nach sehr mühsamer Arbeit) den Fehler mit Minimalcode und mit nur einem Thread reproduzieren.

Die Exception ist:
java.sql.SQLException: [SQL0901] SQL-Systemfehler.ErrorCode -901

at com.ibm.as400.access.JDError.throwSQLException(JDE rror.java:650)
at com.ibm.as400.access.JDError.throwSQLException(JDE rror.java:621)
at com.ibm.as400.access.AS400JDBCStatement.commonExec ute(AS400JDBCStatement.java:896)
at com.ibm.as400.access.AS400JDBCPreparedStatement.ex ecuteQuery(AS400JDBCPreparedStatement.java:1108)
at testpackage.TestGleicheAbfrage2.main(TestGleicheAb frage2.java:65)
Message [SQL0901] SQL-Systemfehler.
SQLState 58004

und der Code:

package testpackage;

import java.sql.CallableStatement;
import java.sql.Connection;
import java.sql.DriverManager;
import java.sql.ResultSet;
import java.sql.SQLException;
import java.sql.Types;

import com.ibm.as400.access.AS400;


public class TestGleicheAbfrage2 {

private static Connection connection;

public static void main(String args) {
try {

try {
Class.forName("com.ibm.as400.access.AS400JDBCDriver",true, AS400.class.getClassLoader());
} catch (ClassNotFoundException e) {
e.printStackTrace();
}
connection = DriverManager.getConnection("jdbc:as400://zedv.erl.firma.com;libraries=VOGTJ, *LIBL", "XXX", "YYY");

CallableStatement cs1 = callsptunnel("JFDKNR = 18");
ResultSet rs1 = cs1.executeQuery();
rs1.next();

// ----

CallableStatement cs2 = callsptunnel("JFDKNR is null");
ResultSet rs2 = cs2.executeQuery();
rs2.next();

rs1.close();
rs2.close();

// ----

CallableStatement cs3 = callsptunnel("JFDKNR is null");
ResultSet rs3 = cs3.executeQuery();
rs3.next();
rs3.close();

// ---

CallableStatement cs4 = callsptunnel("JFDKNR = 18");
ResultSet rs4 = cs4.executeQuery();
rs4.next();

// ----

CallableStatement cs5 = callsptunnel("JFDKNR is null");
ResultSet rs5 = cs5.executeQuery();
rs5.next();

rs4.close();
rs5.close();

// ----

CallableStatement cs6 = callsptunnel("JFDKNR is null");
ResultSet rs6 = cs6.executeQuery();
rs6.next();
rs6.close();

connection.close();

} catch (SQLException e) {
// TODO Auto-generated catch block
e.printStackTrace();
System.out.println("ErrorCode \t" + e.getErrorCode());
System.out.println("Message \t" + e.getMessage());
System.out.println("SQLState \t" + e.getSQLState());
try {
connection.close();
} catch (SQLException e1) {
// TODO Auto-generated catch block
e1.printStackTrace();
}
}

}





private static CallableStatement callsptunnel(String wherestatement) throws SQLException {

String command = "{call SPTUNNEL" +"(?, ?, ?, ?, ?, ?, ?, ?, ?, ?)}";
CallableStatement callablestatement = connection.prepareCall(command);

callablestatement.registerOutParameter(7, Types.CHAR);
callablestatement.registerOutParameter(8, Types.CHAR);

callablestatement.setString(1, "JFDK");
callablestatement.setString(2, "TEST");
callablestatement.setString(3, "4711");

callablestatement.setDouble(4, new Double(0));
callablestatement.setString(5, "MY");
callablestatement.setString(6, "0");

callablestatement.setString(7, "");
callablestatement.setString(8, "");

callablestatement.setString(9, wherestatement);
callablestatement.setString(10, "");

return callablestatement;

}

}

[BenderD]

Hallo,

das sieht auf den ersten Blick erstmal unverdächtig aus, ich sehe zwar nicht auf den ersten Blick wo Zeile 65 ist (wo er wohl rausdüst). Aufgefallen ist mir allenfalls, dass die CallableStatements nicht geschlossen werden.
Zusätzliche Info könnte man noch bekommen, wenn man den Database Server Job unter debug nimmt (mit separatem User connecten und nach dem Connect WRKOBJLCK MYUSR *USRPRF Job lokalisieren, STRSRVJOB und STRDBG) da müsste man sogar bis in die stored Procedure reinkommen.
Was sagt denn so euer GRPPTF Stand der Database (und den Treiber könnte man mal tauschen.
Für die wohl fällige Fehlermeldung bei IBM wäre es wohl ganz gut, wenn man den Fehler auch in RPG hinbekommt, dann haben die nur noch eine Ausrede.

mfg

Dieter Bender

[axl]

Also rausfliegen tut er hier:

CallableStatement cs6 = callsptunnel("JFDKNR is null");
ResultSet rs6 = cs6.executeQuery();
rs6.next();
rs6.close();

Die CallableStatements werden nur hier im Demoprogramm nicht geschlossen um den Code kürzer zu halten.

In der StoredProcedure war ich auch schon mit dem Debugger drin, konnte aber keine (zumindest für mich) hilfreichen Infos bekommen. Was den GRPPTF-Stand anbelangt werde ich mal mit unserem Sysadmin reden.

Würde es was bringen den Fehler in RPG hinzubekommen? IBM unterstützt (lt. unserem Sysdamin) solche alten Releasestände eh nicht mehr?

[BenderD]

... was habt ihr denn für einen Releasestand?
- dann wirds mit dem PTF Stand wohl auch Essig sein
- und die Treiberfrage wird interessant, soweit ich mich erinere, gab es da früher mit CallableStatements Probleme (und es gibt da auch Versionsabhängigkeiten von Treiber und OS)

mfg

Dieter Bender

Also rausfliegen tut er hier:

CallableStatement cs6 = callsptunnel("JFDKNR is null");
ResultSet rs6 = cs6.executeQuery();
rs6.next();
rs6.close();

Die CallableStatements werden nur hier im Demoprogramm nicht geschlossen um den Code kürzer zu halten.

In der StoredProcedure war ich auch schon mit dem Debugger drin, konnte aber keine (zumindest für mich) hilfreichen Infos bekommen. Was den GRPPTF-Stand anbelangt werde ich mal mit unserem Sysadmin reden.

Würde es was bringen den Fehler in RPG hinzubekommen? IBM unterstützt (lt. unserem Sysdamin) solche alten Releasestände eh nicht mehr?

[axl]

Unser Versionsstand ist V5R2.

[BenderD]

PTFs is wohl nichmehr...

bist du denn sicher, ob das von der Datenbank kommt, oder vom Treiber? Debug müsste dann den SQL0901 im Joblog outen (vielleicht sogar ohne debug), dann wäre Ende der Fahnenstange. Beim Treiber könnte man immerhin mal einen anderen (neueren) probieren.

D*B

Unser Versionsstand ist V5R2.

[Fuerchau]

Die Frage die sich mir stellt ist, ob deine Prozedur aufgerufen wird und der Fehler dort passiert oder der Fehler bereits vorher ausgelöst wird.

Testen kann man das Miniprogramm ja auch von einem PC-Client über eine Java-Testumgebung (Eclipse), so dass man den SQL-Job (QZDASOINIT) mal in Debugmode setzen kann und ggf. im Joblog den Fehler sieht.

Auch läßt sich vielleicht die Prozedure per STRSRVJOB/STRDBG dann mal untersuchen.

[axl]

Genauso haben wir auch versucht den Fehler irgendwie greifen zu können.

Habe nach dem Auslösen der Exception 'nen Breakpoint gesetzt u. unseren Sysadmin dann beauftragt den AS400 Job näher zu analysieren (Log befindet sich am Ende).

Durch die Nachrichten-ID CPD4373 (unten rot markiert) ist er dann eben auf diesen Link aufmerksam geworden: IBM - SE25763 - OSP-DB-MSGCPD4373 OR EMPTY RESULT SET


Mittlerweile habe ich herausgefunden, dass dieser Effekt nur dann auftritt, wenn periodisch identische SQLs generiert werden. Ich schätze mal, dass hier der Optimizer etwas Probleme hat. Wenn ich in der Stored-Procedure dafür Sorge, dass kein SQL dem anderen gleich (Konstantes Feld mit wechselnden Feldnamen anhängen z.B. 'XXX' as Feld1, 'XXX' as Feld2, ...) läuft alles ohne Probleme. Allerdings kann auch dann der Optimizer nicht mehr so richtig optimieren u. man erkauft sich hierdurch einen Geschwindigkeitsnachteil.


SATZNR *...+... 1 ...+... 2 ...+... 3 ...+... 4 ...+... 5 ...+... 6 ...+... 7 ...+... 8 ...+... 9 ...+... 0
1 Speicherauszug für Benutzertrace für Job 541654/QUSER/QZDASOINIT. Größe: 300 K, Anzahl Umläufe: 0
2
3 --- 08/19/2008 10:50:26 ---
4 000000BF:479976 SQ Run Time Dump of SQLCA section:
5 000000BF:480032 C4F0A25367:0012B0 L:0008 EyeCatch:
6 000000BF:480064 C4F0A25367:0012B0 E2D8D3C3 C1404048 *SQLCA ........
.*
7 000000BF:480080 C4F0A25367:0012B8 L:0004 Length of SQLCA:
8 000000BF:480104 C4F0A25367:0012B0 00000088 *...........h...
.*
5722SS1 V5R2M0 020719 DATEI KOPIEREN QTEMP/QAP0ZDMP QP0Z541654 19.08.08 10:50:27 S.
SATZNR *...+... 1 ...+... 2 ...+... 3 ...+... 4 ...+... 5 ...+... 6 ...+... 7 ...+... 8 ...+... 9 ...+... 0
9 000000BF:480112 C4F0A25367:0012BC L:0004 SQL return code:
10 000000BF:480136 C4F0A25367:0012B0 FFFFFC7B *...............
#*
11 000000BF:480144 C4F0A25367:0012C0 L:0048 SQL error message:
12 000000BF:480176 C4F0A25367:0012C0 000BC3D7 C4F4F3F7 F300000C 21000000 *..CPD4373......
.*
13 000000BF:480208 C4F0A25367:0012D0 00000000 00000000 00000000 00000000 *...............
.*
14 000000BF:480240 C4F0A25367:0012E0 00000000 00000000 00000000 00000000 *...............
.*
15 000000BF:480272 C4F0A25367:0012F0 00000000 00000000 00000000 00000000 *...............
.*
16 000000BF:480296 C4F0A25367:001300 00000000 00000000 *...............
.*
17 000000BF:480312 C4F0A25367:001308 L:0008 Program name:
5722SS1 V5R2M0 020719 DATEI KOPIEREN QTEMP/QAP0ZDMP QP0Z541654 19.08.08 10:50:27 S.
SATZNR *...+... 1 ...+... 2 ...+... 3 ...+... 4 ...+... 5 ...+... 6 ...+... 7 ...+... 8 ...+... 9 ...+... 0
18 000000BF:480336 C4F0A25367:001300 D8E2D8D6 D7C5D540 *........QSQOPEN
*
19 000000BF:480344 C4F0A25367:001310 L:0018 Diag information:
20 000000BF:480376 C4F0A25367:001310 F4F2F7F8 F4F3F7F3 00000000 00000000 *42784373.......
.*
21 000000BF:480400 C4F0A25367:001320 00000000 00000000 *...............
.*
22 000000BF:480416 C4F0A25367:001328 L:000B Warning flag:
23 000000BF:480440 C4F0A25367:001320 40404040 40404040 *........
*
24 000000BF:480456 C4F0A25367:001330 404040 * ............
.*
25 000000BF:480472 C4F0A25367:001333 L:0005 SQL state:
26 000000BF:480496 C4F0A25367:001330 F5 F8F0F0F4 *...58004.......
.*
5722SS1 V5R2M0 020719 DATEI KOPIEREN QTEMP/QAP0ZDMP QP0Z541654 19.08.08 10:50:27 S.
SATZNR *...+... 1 ...+... 2 ...+... 3 ...+... 4 ...+... 5 ...+... 6 ...+... 7 ...+... 8 ...+... 9 ...+... 0
27
27 Datensätze nach Teildatei bzw. Kennsatz *N nach Datei QSYSPRT in Bibliothek QSYS kopiert. 0 Datensätze ausgeschlossen.

[Fuerchau]

Dann liegts ggf. an der Prozedurdefinition.
Der Optimizer muss auch bei Prozeduren erkennen können, ob sich ein Aufruf lohnt (deterministic).
Ist die Definition so, dass bei gleichen Parametern das gleiche Ergebnis geliefert wird, spart sich SQL normalerweise den Aufruf und nimmt das Ergebnis des letzten.
Dies führt dann halt zu Problemen.
"not determinstic" sollte das Problem lösen, so dass wenigstens die Prozedur aufgerufen wird.

Die Prozedur sollte aber auf jeden Fall (so hats nicht den Anschein) einen Cursor liefern, auch wenn keine Daten ermittelbar sind.
Vielleicht liegt hier ja der Designfehler.

Die Prozedur soll ein Resultset liefern (ggf. auch leer), tuts aber nicht !