DRDA mit Remote SQL Befehl funktioniert nicht mehr

[BenderD]

... wenn ich das richtig verstehe, ist das zu spät, der debugger muss bereits vor dem open auf den Cursor gestartet sein.
Ich würde folgendes raten:
- Job auf Client (V5R2) unter debug starten, Breakpoint vor dem Connect
- Connect User und Kennwort auf dezidiertes Benutzerprofil ändern
- Step hinter den Connect
- WRKOBJLCK BenutzerProfil *USRPRF auf Server liefert den passenden SQL Server Job QRWTSRVR
- STRSRVJOB auf diesen Job
- STRDBG
- jetzt den Job auf dem Client weiter schnurren lassen und in dem Serverjob nachsehen was passiert, insbesondere sind die Diagnostics interessant (Zugriffsplan und estimated Dauer)

BTW wie groß ist die abgefragte Tabelle? Vielleicht dauert das nur fast ewig und Stunden später passiert noch was!

D*B

Habe den QRWTSRVR erneut debugged.
Es steht nichts nennenswertes im Log.
Außer das eine Verbindung von der V5R2 Maschine aufgemacht wurde.

Vielleicht mache ich auch was falsch?

Hier meine Vorgehensweise:

1. Ein funktionierende Remote SQL Abfrage (embedded laufen lassen).
2. Die Nummer des kurz erscheinenden Jobs notieren.
3. Nochmal ein funktionierendes laufen lassen.
4. Die Nummer des wieder erscheinenden QRWTSRVR Jobs ist die gleiche.
5. Das RPG mit der hängenbleibenden SQL Abfrage aufrufen.
6. In 5 Sekunden geht der RPG Job auf TIMW (auf der V5R2 Maschine)
7. innerhalb der 5 Sekunden strsrvjob und strdbg (ohne parms) auf den obigen Job aufrufen.

[cs400_de]

BTW wie groß ist die abgefragte Tabelle? Vielleicht dauert das nur fast ewig und Stunden später passiert noch was!

D*B

Ja das hatten wir auch schon gedacht.
Wir haben auch bei manchen Jobs / Tabellen schon 4 Tage gewartet und der TIMW status verschwindet nicht mehr.
Wenn man den Server Job beobachtet, sieht man bei funktionierenden langen Abfragen immer mal wieder, so alle 3-5 Minuten einen I/O und relativ wenig CPU Zeit. Bei den Jobs die auf der rufenden Maschine mit TIMW stehen bleiben gibt es auf der Zielmaschine keine I/Os mehr (tagelang) und doch einiges an CPU Zeit.

Gruß

[BenderD]

- wieviele Sätze haben die beteiligten Tabellen denn? 1 Mio, 10 Mio, 100 Mio oder einige 100 Mio?
- um hier Einblick zu bekommen sind die Messages beim open des Cursors wichtig, da sieht man, was die Query Engine vorhat und wie lange sie zu brauchen meint, und am einfachsten kommt man da halt im Debug dran.
- was die von Baldur angesprochenen Casts angeht, da ist der Cast in der Where Klausel möglicherweise tödlich - der führt zum full table scan, falls die Query Engine den ernster nimmt als den order by.

D*B

Ja das hatten wir auch schon gedacht.
Wir haben auch bei manchen Jobs / Tabellen schon 4 Tage gewartet und der TIMW status verschwindet nicht mehr.
Wenn man den Server Job beobachtet, sieht man bei funktionierenden langen Abfragen immer mal wieder, so alle 3-5 Minuten einen I/O und relativ wenig CPU Zeit. Bei den Jobs die auf der rufenden Maschine mit TIMW stehen bleiben gibt es auf der Zielmaschine keine I/Os mehr (tagelang) und doch einiges an CPU Zeit.

Gruß

[cs400_de]

- wieviele Sätze haben die beteiligten Tabellen denn? 1 Mio, 10 Mio, 100 Mio oder einige 100 Mio?
- um hier Einblick zu bekommen sind die Messages beim open des Cursors wichtig, da sieht man, was die Query Engine vorhat und wie lange sie zu brauchen meint, und am einfachsten kommt man da halt im Debug dran.
D*B

A.) Die Abgefragte Tabelle MARC hat 828.154 Sätze.

B.) Im Visual Explain steht, wenn ich auf Tablescan klicke (Es gibt ja 4 grafisch dargestellte Schritte) unten im grauen Feld: DECLARE C1 CURSOR FOR DYNAMIC_SQL_007

dazu hier die Daten aus der rechten Anzeige.

Table Scan - R3SIDDATA.MARC
Attribut Wert
Table name, base table name, in...
Name of Table Being Queried MARC
Library of Table Being Queried R3SIDDATA
Member of Table Being Queried MARC
Long Name of Table Being Queried MARC
Long Library of Table Being Que... R3SIDDATA
Estimated Time Information (Sta...
Processing Time(ms) 7,263
Cumulative Time(ms) 7,263
Additional Table Info
Total Rows in Table 828,081
Table Size(bytes) 1,209,863,237
Active Table Rows 828,081
Deleted Table Rows 0.0
Estimated rows selected and qu...
Rows Selected Per Plan Step Ite... 828,081
Rows Processed During Last Pl... 828,081
Plan Step Iterations 1
Total Rows Selected 828,081
Total Rows Processed 828,081
Optimize for N Rows All
Percent Selectivity 100
Cumulative Percent Selectivity 100
Fetch N Rows All
Estimated Cost Information Abo...
Processing Time(ms) 7,263
I/O Or CPU Bound I/O Bound
CPU Cost(ms) 113.368
I/O Cost(ms) 7,263
I/O Count 9,345
Table Scan - R3SIDDATA.MARC
Attribut Wert
PreLoad Relation No
Memory Used(bytes) 47,321,146
Memory Constrained No
Cumulative Memory Constrained No
Actual Runtime Information
Actual Rows Selected Per Plan ... 828,086
Actual Rows Processed Per Pla... 828,086
Actual Plan Step Iterations 2
Actual Total Rows Selected 1,656,173
Actual Total Rows Processed 1,656,173
Information About the Plan Perf...
Contains Predicate Yes
Scrollable Yes
Plan Name Table Scan
Plan Step Type Logic
Reason Code Table Scan Cost Is Better
Plan Step Name Node_13
Statement Text SELECT Cast(MARC_1.MATNR A...

[BenderD]

< 1 Mio Sätze => also nicht viel (es sei denn die Möhre pfeift auf dem letzten Loch.
laut Job Protokoll macht der einen full Table Scan (den ganzen Oops Nerv und Visual Explain Krams kannste getrost vergessen, das findet nicht in dem Job statt)
Die estimated Time müsste in den Messages in den Details zu finden sein, aber die 7,xyz Sekunden sind für die paar Sätze schon plausibel...
Ich gehe mal davon aus, dass die Meldungen alle schon nach dem open drin stehen und der erst beim fetch in den Wind düst. Sieht für mich heftig nach einem defect problem aus. Dir wird wohl nichts anderes übrig bleiben als zu versuchen das ganze auf der V6R1 Büchse only zu reproduzieren oder von einem höheren Release zuzugreifen - und selbst dann dürfte es schwierig werden die Coldline zur Arbeit zu tragen...

D*B

A.) Die Abgefragte Tabelle MARC hat 828.154 Sätze.

B.) Im Visual Explain steht, wenn ich auf Tablescan klicke (Es gibt ja 4 grafisch dargestellte Schritte) unten im grauen Feld: DECLARE C1 CURSOR FOR DYNAMIC_SQL_007

dazu hier die Daten aus der rechten Anzeige.

Table Scan - R3SIDDATA.MARC
Attribut Wert
Table name, base table name, in...
Name of Table Being Queried MARC
Library of Table Being Queried R3SIDDATA
Member of Table Being Queried MARC
Long Name of Table Being Queried MARC
Long Library of Table Being Que... R3SIDDATA
Estimated Time Information (Sta...
Processing Time(ms) 7,263
Cumulative Time(ms) 7,263
Additional Table Info
Total Rows in Table 828,081
Table Size(bytes) 1,209,863,237
Active Table Rows 828,081
Deleted Table Rows 0.0
Estimated rows selected and qu...
Rows Selected Per Plan Step Ite... 828,081
Rows Processed During Last Pl... 828,081
Plan Step Iterations 1
Total Rows Selected 828,081
Total Rows Processed 828,081
Optimize for N Rows All
Percent Selectivity 100
Cumulative Percent Selectivity 100
Fetch N Rows All
Estimated Cost Information Abo...
Processing Time(ms) 7,263
I/O Or CPU Bound I/O Bound
CPU Cost(ms) 113.368
I/O Cost(ms) 7,263
I/O Count 9,345
Table Scan - R3SIDDATA.MARC
Attribut Wert
PreLoad Relation No
Memory Used(bytes) 47,321,146
Memory Constrained No
Cumulative Memory Constrained No
Actual Runtime Information
Actual Rows Selected Per Plan ... 828,086
Actual Rows Processed Per Pla... 828,086
Actual Plan Step Iterations 2
Actual Total Rows Selected 1,656,173
Actual Total Rows Processed 1,656,173
Information About the Plan Perf...
Contains Predicate Yes
Scrollable Yes
Plan Name Table Scan
Plan Step Type Logic
Reason Code Table Scan Cost Is Better
Plan Step Name Node_13
Statement Text SELECT Cast(MARC_1.MATNR A...

[cs400_de]

- Job auf Client (V5R2) unter debug starten, Breakpoint vor dem Connect
- Connect User und Kennwort auf dezidiertes Benutzerprofil ändern
- Step hinter den Connect
- WRKOBJLCK BenutzerProfil *USRPRF auf Server liefert den passenden SQL Server Job QRWTSRVR
- STRSRVJOB auf diesen Job
- STRDBG
- jetzt den Job auf dem Client weiter schnurren lassen und in dem Serverjob nachsehen was passiert, insbesondere sind die Diagnostics interessant (Zugriffsplan und estimated Dauer)

Job 821926/QUSER/QRWTSRVR von Benutzer DVSCHULZ mit Angabe SPLFILE(*NO)
angehalten.
Job 821926/QUSER/QRWTSRVR freigegeben von Benutzer DVSCHULZ.
Job 821926/QUSER/QRWTSRVR durch DVSCHULZ geändert.
PREPARE für Anweisung STMT0001 beendet.
****: Debug-Nachrichten des Optimierungsprogramms für Abfrage werden
gestartet.
Alle Zugriffspfade wurden für Datei MARC berücksichtigt.
Zugriff nach Eingangsfolge für Datei MARC verwendet.
****: Debug-Nachrichten für Abfrage werden beendet.
ODP erstellt.
Blockung für Abfrage.
Cursor C1 eröffnet.
985 Zeilen von Cursor *N abgerufen.



Im iNAV zeigt er im Visual Explain 4 Steps an:

1 Table Scan
2 Tempory Sorted List
3 Sorted List Scan
4 Final Select



Beim Final Select steht:
Total Estimated Run Time (ms) 7,557

und beim Stement Text:
SELECT CAST(MATNR AS CHAR(18)) MATNR, CAST(GPNUM AS CHAR(9)) GPNUM FROM IASP144/R3EMPDATA/MARC WHERE CAST(MANDTAS CHAR(3)) = ? ORDER BY MATNR