erfassung und monitoring des laufzeitverhaltens von sql
Werbung
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.
