Dienstag, 7. Mai 2013

Langsame Abfrage in Oracle - was genau passiert da eigentlich?


Bei den testweise migrierten Abwasser Daten lassen sich die Haltungen nicht aktualisieren oder neue Haltungen erzeugen. Wird eine Haltung im Formular aktualisiert, "hängt" Map und muss über den TaskManager beendet werden.

Bei den anderen Featureklassen im Abwasser tritt dies nicht auf. Im Zusammenhang mit der Problematik stehen die Objektregeln zum Aktualisieren der Labels (RegenerateLabel_BD/BU/AD/AU/AI). Werden die Objektregeln ausgeschaltet, lassen sich die Datensätze ohne weiteres aktualisieren oder neue Haltungen erfassen.



Da der Autodesk Support mit unserem Datendump das Problem nicht nachvollziehen konnte, bleibt nichts anderes, als die Ursache selber weiter einzugrenzen. Allerdings habe ich kaum Kenntnisse, wie man in Oracle die Ausführung von SQL Abfragen analysiert. Hier meine in diesem Zusammenhang gesammelten Erkenntnisse:

Zunächst habe ich geschaut, ob eine Abfrage besonders lange dauert. Die dafür verwendete SQL Abfrage sieht so aus:

select
s.username,
s.sid,
s.serial#,
s.last_call_et/60 mins_running,
q.sql_text from v$session s
join v$sqltext_with_newlines q
on s.sql_address = q.address
where status='ACTIVE'
and type <>'BACKGROUND'
and last_call_et> 60
order by sid,serial#,q.piece

Als Ergebnis sollte man die SQL Abfragen erhalten, die länger als 60 sec. dauern. Zumindest war das meine Erwartung. Da mir vertiefte Kenntnisse in dem Bereich fehlen, habe ich im Internet nach entsprechenden SQL Statements gesucht – und anschliessend nicht weiter im Detail geschaut, wie das Ergebnis zu interpretieren ist. Denn anhand der Abfrage konnte ich sehen, dass folgende SQL Anweisung länger als 60 min läuft:

WITH CONNECTION AS ( SELECT * FROM WW_CONN C WHERE (C.FID_FROM IN (SELECT FID FROM WW_LINE WHERE FID_ATTR=:B1 ) AND C.F_CLASS_ID_FROM =22) OR (C.FID_TO IN (SELECT FID FROM WW_LINE WHERE FID_ATTR=:B1 ) AND C.F_CLASS_ID_TO =22) ) SELECT MIN(P.FID_ATTR) AS FID_FROM FROM CONNECTION C, WW_POINT P WHERE (P.FID = C.FID_FROM AND C.F_CLASS_ID_FROM = 32 AND C.FLOW = 1) OR (P.FID = C.FID_TO AND C.F_CLASS_ID_TO = 32 AND C.FLOW = 2)

Mit Map's SQLSpy liess sich auslesen, dass ":B1" der Feature-ID der Haltung entspricht, die aktualisiert werden soll.

Nimmt man die oben aufgeführte SQL Anweisung, ersetzt ":B1" mit einer Haltungs-Feature-ID und führt die Abfrage z.B. im SQLDeveloper aus, dann dauert die Ausführung weniger als 1 sec.

Wie entsteht nun der grosse Unterschied in der Ausführungszeit zwischen Map und SQLDeveloper? Zwei Erklärungsansätze vom Autodesk Support :
-         Drittapplikationen, die ev. die Objektregeln beeinflussen
-         Oracle Konfiguration

Drittapplikationen haben wir im Augenblick nicht im Einsatz. Die Oracle Konfiguration ist natürlich fast überall unterschiedlich – und damit eine potentielle Ursache. 

Als nächstes habe ich – dem Hinweis aus dem Oracle Forum folgend – die Ausführungspläne der beiden Statements angeschaut. Gibt es dort Unterschiede, die die unterschiedliche Laufzeit erklären?

Um den Ausführungsplan der Anweisungen zu erhalten benötigt man die SQL_ID. Diese kann man z.B. über folgende Anweisung erhalten:

SELECT sql_id, child_number
FROM v$sql
WHERE sql_text LIKE '%WITH CONNECTION%';

Den Ausführungsplan ruft man dann mit der ermittelten SQL_ID und der Child_Number auf, z.B.:

SELECT * FROM table(DBMS_XPLAN.DISPLAY_CURSOR(c7my737tshr9k,0));

Es hat sich jedoch gezeigt, dass die Ausführungspläne der SQL Anweisung aus Map und aus dem SQLDeveloper identisch sind.

Der entscheidende Hinweis kam wieder vom Oracle Forum: über die folgende Abfrage erhält man zur Ausführung einer SQL Anweisung weitere Informationen:

select sql_id
     , PLAN_HASH_VALUE
     , CHILD_NUMBER
     , EXECUTIONS
     , ELAPSED_TIME/1000000
     , USER_IO_WAIT_TIME
     , CONCURRENCY_WAIT_TIME
     , DISK_READS
     , BUFFER_GETS
     , ROWS_PROCESSED
  from v$sql
 where sql_id = c7my737tshr9k;

Bei dieser Abfrage sieht man, wie oft die SQL Anweisung ausgeführt wurde. Bei der Anweisung aus Map liegt die Zahl bei über 6000. Das Problem ist also nicht – wie ursprünglich gedacht – die unterschiedliche Ausführungszeit der fraglichen SQL Anweisung sondern der Umstand, dass die Anweisung bei aktivierten Objektregeln extrem häufig hintereinander ausgeführt wird. Die Ursache dafür ist im Augenblick noch unklar.

Die erste von mir verwendete SQL Abfrage zeigt Angaben bezogen auf die Session.
Dadurch entgeht die Information, dass die SQL Anweisung mehrfach ausgeführt wird – was zu dem falschen Rückschluss führte, das die SQL Anweisung extrem lange benötigt.

Aus dem Beispiel wurde mir deutlich, dass man nicht ohne weiteres SQL Abfragen aus dem Internet verwenden sollte, nur weil sie "zu passen" scheinen. Zudem sind "plausible" erscheinende Ergebnisse manchmal eben auch irreführend. Die andere Seite der Medaille ist natürlich, dass man ja irgendwann mal vor einem solchen Problem steht und sich damit beschäftigen muss.

Am Ende sei noch erwähnt, dass Map's SQLSpy schon in die richtige Richtung gezeigt hat. Lässt man den SQLSpy mitlaufen wenn die Haltung aktualisiert wird, dann erscheint die fragliche SQL Abfrage permanent neu in der Liste – hier wird also deutlich, dass die Abfrage immer wieder in Oracle ausgeführt wird. Ich hatte dem aber keine Bedeutung geschenkt – da ich zum SQLSpy keine Dokumentation gefunden habe, bleibt bei der Interpretation der Ergebnisse auch nur Raten übrig. Hier hatte ich dann nicht richtig geraten sondern gedacht, der SQLSpy erzeugt unsinnige Ergebnisse.

Jetzt gilt es "nur noch" herauszufinden, warum die Anweisung bei aktivierten Objektregeln bei uns so häufig ausgeführt wird.

Keine Kommentare:

Kommentar veröffentlichen