erfassung und monitoring des laufzeitverhaltens von sql

ERFASSUNG UND MONITORING DES
LAUFZEITVERHALTENS VON
SQL STATEMENTS
DOAG 2014 DATENBANK, DÜSSELDORF
3. JUNI 2014
FÉLIX CASTILLO SÁNCHEZ
[email protected]
Felix Castillo Sanchez
Email:
[email protected]
Internet: http://blog.oraconsult.de
- Oracle DBA seit 1991
- Freelancer seit1997
- Tätig als:
-
Consultant
Database Administrator
System Developer
Trainer
•
DOAG 2011
•
•
DOAG Regio 2012
•
•
Oracle Performance Analyse
Die Wiederentdeckung der Oracle Statistiken
DOAG 2012
•
•
Oracle Performance Analyse mit statistischen Methoden
Oracle Performance Analyse
Erweiterte Möglichkeiten mit Statistiken und Wartezeiten
DOAG SIG 2013
•
Oracle Performance Analyse
Quo Vadis, AWR?
• Hotsos Symposium, März 2013
•
The Oracle Performance Signature
• Frankfurter Datenbanktage, März 2013
• Die Oracle Performance Signatur
• DOAG 2013
• Die Oracle Performance Signatur
• DOAG SIG Database 2014
• Erfassung und Monitoring des Laufzeitverhaltens von SQL
Statements
PERFORMANCE
• Bei Datenbank-Performance geht es immer um die
Ausführung von SQL-Statements
• Identifikation problematischer SQL-Statements
•
•
•
•
Grid/Cloud Control – Top Activity
Nach Ressourcenverbrauch (CPU/Phys. I/O, etc.)
Lange Ausführungszeit
etc.
• Wenn das Problem nicht (allein) in der Art der Ausführung
selbst liegt (z.B. Plan)?
• Wenn der Grund nicht das WIE ausgeführt sondern
das WAS WANN ist?
Oracle Features und Tools decken fast alles ab, lassen jedoch den
wichtigsten Aspekt außen vor
PERFORMANCE-PROBLEME WERDEN I.A. VON DER
ANWENDUNG VERURSACHT!!
•
•
•
•
•
•
•
•
•
Ineffizientes Verbindungsmanagement
Ineffizientes Cursor Handling
Verwendung von Literalen
Verwendung gebundener Variablen
CBO ignorieren
CBO alles vorschreiben
Falsches/Fehlendes Design
Datenbank-neutrale Entwicklung
etc.
Oracle Features und Tools suggerieren uns*), dass jedes PerformanceProblem Datenbank-seitig gelöst werden kann!
*) Entwickler, Kunden, Management, DBAs (?)
Die Betrachtung der Ausführung als Ganzes verbirgt
wesentliche Informationen
• Problem vor allem bei langlaufendem SQL
• Eine Zusammenfassung von Wait Events am Ende vernachlässigt
ihren zeitliche Entstehung und somit potenziell eine
mögliche Ursache
• Die Reduzierung auf Physical/Logical I/O und CPU während der
Ausführung lässt viele Informationen außen vor.
Oracle Hilfsmittel
• Wait-Event Tracing
• Keine ausführlichen Statistiken, lediglich CPU/Elapsed, SLR, PIO
• tkprof erstellt nur Zusammenfassung
• SQL Tuning Advisor
• SQL Monitoring
doch häufig ist es nicht das richtige Statement
• Statements unter 5 Sekunden (CPU, I/O Time)
• anderer Cursor
• keine historisierte Daten
Laufzeitverhalten beschreibt
• Aktivitäten und den
• Ressourcenverbrauch
• während der Ausführung
Laufzeitverhalten beschreibt
• Aktivitäten und den
• Ressourcenverbrauch
• während der Ausführung
Erfassung durch die stetige Abfrage
• Sampling von Standard-Views, z.B.
• v$sesstat,
• v$session_event
• v$sess_time_model,
• etc.
Laufzeitverhalten beschreibt
• Aktivitäten und den
• Ressourcenverbrauch
• während der Ausführung
Erfassung durch die stetige Abfrage
• Sampling der Views
• v$sesstat,
• v$session_event
• v$sess_time_model,
• etc
Sampling vs. Tracing
• Sampling benötigt keine Code-Instrumentierung
• Erfassung des zeitlichen Verlaufs aller Werte möglich
• Genauigkeit weitgehend anpassbar
Die Datenabfrage und grafische Auswertung kann mit
verschiedenen Mitteln durchgeführt werden
• Excel, R, .., etc.
• Python
•
•
•
•
IPython als Umgebung
pandas zur Verarbeitung, Analyse, Plotting (Modul)
matplotlib für ausführlichere Graphen (Modul)
cx_Oracle zur Anbindung an Oracle (Modul)
Python und die verwendeten Module sind allesamt Open Source und können einzeln oder
im Rahmen von Distributionen sowohl unter Windows als auch unter Linux. Grundsätzlich
ist Python auf allen Betriebssystemen einsetzbar.
Python: http://www.python.org
pandas: http://pandas.pydata.org
matplotlib: http://matplotlib.org
cx_Oracle: http://matplotlib.org
IPython: http://ipython.org
Beispiel 1 – DBA_HIST_SQLSTAT
• Datenabfrage und -darstellung von historisierten AWRInformationen
Beispiel 2 – Separate Datensammlung
• Aufbereitung und Darstellung selbst gesammelter Daten
tpsCollector.py
Beispiel 3 –Entwicklung
• Möglichkeiten des Samplings in der Entwicklung
SqlExecutionProfiler.py /
SqlExecutionAnalyzer.py
Statement zu langsam
• Ausgangslage
• bekanntes Statement (SQL_ID) wird als zu
langsam beschrieben
• Mögliche Schritte
• Ausführungspläne vergleichen
• SQL Tuning Advisor
• Mögliche Hindernisse
• Statement < 5 sec => kein Monitoring
• Monitoring explizit ausgeschalten (Hint: NO_MONITORING)
• Keine entsprechenden Lizenzen
Wesentliche Frage:
• Ist das Statement im Vergleich zu vorherigen Ausführungen
tatsächlich langsamer?
Statement zu langsam
• Ohne historisierte Daten nicht lösbar!
• Abfrage DBA_HIST_SQLSTAT
• Spalten CPU_TIME_DELTA,
ELAPSED_TIME_DELTA, BUFFER_GETS_DELTA,
etc.
select *
from dba_hist_snapshot sn,
dba_hist_sqlstat sl
where sn.snap_id = sl.snap_id
and sql_id = ...
import
import
import
import
cx_Oracle
pandas
matplotlib.pyplot
re
dbh = cx_Oracle.Connection('system/orasys@ora11g')
stmt =
select
from
where
"""
"""
*
dba_hist_snapshot sn, dba_hist_sqlstat sl
sn.snap_id = sl.snap_id and sql_id = :sql_id
data = pandas.read_sql( stmt, dbh, index_col =
['BEGIN_INTERVAL_TIME'], params = {'sql_id': 'cm8cy7w3uwg0h'});
delta_cols = [x for x in df.columns if re.match('.*DELTA.*', x)]
df1 = data[delta_columns].resample(1H')
df2 = data[['VERSION_COUNT',]].resample('1H')
(df1.CPU_TIME_DELTA/10**6/1800).plot()
fig = plt.figure(figsize=[12,4])
axes = plt.subplot()
twinx = axes.twinx()
axes.set_ylabel('Time/sec')
twinx.set_ylabel('Number of Versions')
(df1.CPU_TIME_DELTA/10**6/1800).plot(ax=axes, c='r', lw=1)
(df1.ELAPSED_TIME_DELTA/10**6/1800).plot(ax=axes, c='g', lw=1)
(df2.VERSION_COUNT).plot(ax=twinx, c='b', lw=1, alpha=0.5)
plt.title(sql_id)
Datensammlung mit tpsCollector
python tpsCollector.py \
--until cancel \
--inifile dbconf.ini \
--configfile config.ini \
--logfile datacollection.log
select systimestamp as timestamp, parsing_schema_name, 'SQL_'||sql_id as SQL_ID, child_number,
parse_calls, users_executing, disk_reads, direct_writes, buffer_gets, rows_processed,
fetches, executions, cpu_time, elapsed_time, application_wait_time, concurrency_wait_time,
cluster_wait_time, user_io_wait_time, plsql_exec_time, java_exec_time, sorts,
io_cell_offload_eligible_bytes, io_interconnect_bytes, physical_read_requests,
physical_read_bytes, physical_write_requests, physical_write_bytes,
io_cell_uncompressed_bytes, io_cell_offload_returned_bytes
from v$sql
where ...
• Testen
• des Einflusses von Optimizer-Parametern und
• Veränderungen der Verbindungsparameter
SqlExecutionProfiler.py
High Frequency Sampling
v$sesstat, v$session_event
Sub Thread
(Executer)
Statistics
Statistics
Statistics
Events
Events
Events
Statement
query.sql
Bind Variables
bv.py
SqlExecutionAnalyzer.py
CBO
Environment
cboEnv.py
• query.sql
select
from
where
order
*
test_01
object_name like :obj_name
by object_name
• bv.py
bv = {
'obj_name': '%'
}
• cboEnv.py
cboEnv = {
'statistics_level':
'cursor_sharing':
'db_file_multiblock_read_count':
'_hash_multiblock_io_count':
'_sort_multiblock_read_count':
}
'ALL',
'exact',
32,
128,
32
• Aufruf
c:\python-3.3.3\python.exe SqlExecutionProfiler.py ^
--tnsExec system/orasys@ora11g ^
--tnsObserver system/orasys@ora11g ^
--script query.sql ^
--tag run_01 ^
--frequency 40 ^
--rows 100 ^
--thinktime 0.1 ^
--force
c:\python-3.3.3\python.exe SqlExecutionAnalyzer.py run_01
• Aufruf 1 – 1000 rows pro fetch / Think-Time 1.0 => 19.47s
• Aufruf 2 – 100 rows pro fetch / Think-Time 0.1 => 19,21s
• Aufruf 3 – 10 rows pro fetch / Think-Time 0.01 => 22,26s
• Aufruf 4 – 1 row pro fetch / Think-Time 0.001 => 44,65s
• Performance-Probleme werden i.A. durch die Anwendung
verursacht
• Die vorhandenen Analyse-Möglichkeiten reichen nicht in allen
Situationen aus
• Mit Hilfe geeigneter Hilfsmittel können Daten einfach
ausgelesen, aufbereitet und dargestellt werden
Die verwendeten Skripte können unter http://blog.oraconsult.de
geladen werden.