Oder ein wenig angewandte Tetris-Logik.
Alles Neue ist gut vergessenes Altes.
Episoden.
Problemstellung
Es ist erforderlich, regelmäßig die aktuelle PostgreSQL-Logdatei aus der AWS-Cloud auf einen lokalen Linux-Host herunterzuladen. Nicht in Echtzeit, aber sagen wir, mit einer kleinen Verzögerung.
Aktualisierungsintervall der Logdatei – 5 Minuten.
Die Logdatei in AWS wird jede Stunde rotiert.
Verwendete Tools
Für den Download der Logdatei auf den Host wird ein Bash-Skript verwendet, das die AWS-API „».
Parameter:
- —db-instance-identifier: Name der Instance in AWS;
- —log-file-name: Name der aktuell generierten Logdatei
- —max-item: Gesamtanzahl der Elemente, die in den Ausgaben des Befehls zurückgegeben werden.Größe des heruntergeladenen Dateiausschnitts.
- —starting-token: Startmarke des Ausschnitts
In diesem speziellen Fall entstand die Aufgabe, die Logs herunterzuladen, im Rahmen der Arbeiten an
Und einfach nur – eine interessante Aufgabe, um im Arbeitsalltag für Abwechslung und Übung zu sorgen.
Ich nehme an, dass die Aufgabe aufgrund ihrer Alltäglichkeit bereits gelöst wurde. Allerdings hat eine schnelle Google-Suche keine Lösung verraten, und eine tiefere Recherche war nicht besonders erwünscht. In jedem Fall – eine gute Übung.
Formalisierung der Aufgabe
Die endgültige Protokolldatei besteht aus einer Reihe von Zeilen variabler Länge. Grafisch lässt sich die Protokolldatei etwa so darstellen:
Erinnert das schon an etwas? Was hat das mit „Tetris“ zu tun? Nun, das hat es.
Wenn man die möglichen Varianten grafisch darstellt, die beim Hochladen einer Datei entstehen (zur Vereinfachung, in diesem Fall nehmen wir an, dass die Zeilen eine einheitliche Länge haben), erhält man die standardmäßigen Tetris-Figuren:
1) Die Datei wurde vollständig hochgeladen und ist abschließend. Die Größe des Uploads ist größer als die Größe der endgültigen Datei:
2) Die Datei hat eine Fortsetzung. Die Größe des Uploads ist kleiner als die Größe der endgültigen Datei:
3) Die Datei ist eine Fortsetzung der vorherigen Datei und hat eine Fortsetzung. Die Größe des Uploads ist kleiner als der Rest der endgültigen Datei:
4) Die Datei ist eine Fortsetzung der vorherigen Datei und ist abschließend. Die Größe des Uploads ist größer als der Rest der endgültigen Datei:
Die Aufgabe besteht darin, ein Rechteck zu bilden oder auf einem neuen Level Tetris zu spielen.
Probleme, die während der Lösung einer Aufgabe auftreten
1) Fügen Sie eine Zeichenkette aus 2 Portionen zusammen
Im Allgemeinen gab es keine besonderen Probleme. Standardaufgabe aus dem Einführungskurs Programmierung.
Optimale Portionsgröße
Das ist schon etwas interessanter.
Leider gibt es keine Möglichkeit, eine Verschiebung nach dem Starttoken zu verwenden:
Wie Sie bereits wissen, wird die Option —starting-token verwendet, um anzugeben, wo die Paginierung beginnen soll. Diese Option akzeptiert Zeichenfolgen, was bedeutet, dass, wenn Sie versuchen, einen Offset-Wert vor der nächsten Token-Zeichenfolge hinzuzufügen, die Option nicht als Offset berücksichtigt wird.
Deshalb muss ich in kleinen Portionen lesen.
Wenn man große Portionen liest, ist die Anzahl der Lesungen minimal, aber das Volumen maximal.
Wenn man kleine Portionen liest, ist die Anzahl der Lesungen maximal, das Volumen jedoch minimal.
Um den Datenverkehr zu reduzieren und die Lösung ansprechender zu gestalten, musste ich leider eine gewisse Lösung erdenken, die ein wenig wie ein Notbehelf aussieht.
Zur Veranschaulichung betrachten wir den Prozess des Ladens einer Logdatei in 2 stark vereinfachten Varianten. Die Anzahl der Lesungen hängt in beiden Fällen von der Portionsgröße ab.
1) Kleinere Portionen hochladen:
2) Wir laden in großen Mengen hoch:
Wie gewohnt ist die optimale Lösung ein Mittelweg..
Die Portionsgröße ist minimal, kann jedoch während des Lesens erhöht werden, um die Anzahl der Durchläufe zu reduzieren.
Es ist zu beachten, dass die vollständige Aufgabe der Auswahl der optimalen Größe der lesbaren Portionen bisher nicht gelöst ist und eine tiefere Bearbeitung und Analyse erfordert. Vielleicht später.
Allgemeine Beschreibung der Implementierung
Verwendete Servicetabellen
CREATE TABLE endpoint
(
id SERIAL ,
host text
);
TABLE database
(
id SERIAL ,
…
last_aws_log_time text ,
last_aws_nexttoken text ,
aws_max_item_size integer
);
last_aws_log_time — Zeitstempel der zuletzt hochgeladenen Logdatei im Format YYYY-MM-DD-HH24.
last_aws_nexttoken — Textmarke der zuletzt hochgeladenen Portion.
aws_max_item_size — empirisch bestimmter Ausgangsgrößenwert für die Portion.
Voller Text des Skripts
download_aws_piece.sh
#!/bin/bash
#########################################################
# download_aws_piece.sh
# downloan piece of log from AWS
# version HABR
let min_item_size=1024
let max_item_size=1048576
let growth_factor=3
let growth_counter=1
let growth_counter_max=3
echo $(date +%Y%m%d%H%M)': download_aws_piece.sh:''STARTED'
AWS_LOG_TIME=$1
echo $(date +%Y%m%d%H%M)': download_aws_piece.sh:AWS_LOG_TIME='$AWS_LOG_TIME
database_id=$2
echo $(date +%Y%m%d%H%M)': download_aws_piece.sh:database_id='$database_id
RESULT_FILE=$3
endpoint=`psql -h MONITOR_ENDPOINT.rds.amazonaws.com -U USER -d MONITOR_DATABASE_DATABASE -A -t -c "select e.host from endpoint e join database d on e.id = d.endpoint_id where d.id = $database_id "`
echo $(date +%Y%m%d%H%M)': download_aws_piece.sh:endpoint='$endpoint
db_instance=`echo $endpoint | awk -F"." '{print toupper($1)}'`
echo $(date +%Y%m%d%H%M)': download_aws_piece.sh:db_instance='$db_instance
LOG_FILE=$RESULT_FILE'.tmp_log'
TMP_FILE=$LOG_FILE'.tmp'
TMP_MIDDLE=$LOG_FILE'.tmp_mid'
TMP_MIDDLE2=$LOG_FILE'.tmp_mid2'
current_aws_log_time=`psql -h MONITOR_ENDPOINT.rds.amazonaws.com -U USER -d MONITOR_DATABASE -A -t -c "select last_aws_log_time from database where id = $database_id "`
echo $(date +%Y%m%d%H%M)': download_aws_piece.sh:current_aws_log_time='$current_aws_log_time
if [[ $current_aws_log_time != $AWS_LOG_TIME ]];
then
is_new_log='1'
if ! psql -h MONITOR_ENDPOINT.rds.amazonaws.com -U USER -d MONITOR_DATABASE -v ON_ERROR_STOP=1 -A -t -q -c "update database set last_aws_log_time = '$AWS_LOG_TIME' where id = $database_id "
then
echo $(date +%Y%m%d%H%M)': download_aws_piece.sh: FATAL_ERROR - update database set last_aws_log_time .'
exit 1
fi
else
is_new_log='0'
fi
echo $(date +%Y%m%d%H%M)': download_aws_piece.sh:is_new_log='$is_new_log
let last_aws_max_item_size=`psql -h MONITOR_ENDPOINT.rds.amazonaws.com -U USER -d MONITOR_DATABASE -A -t -c "select aws_max_item_size from database where id = $database_id "`
echo $(date +%Y%m%d%H%M)': download_aws_piece.sh: last_aws_max_item_size='$last_aws_max_item_size
let count=1
if [[ $is_new_log == '1' ]];
then
echo $(date +%Y%m%d%H%M)': download_aws_piece.sh: START DOWNLOADING OF NEW AWS LOG'
if ! aws rds download-db-log-file-portion
--max-items $last_aws_max_item_size
--region REGION
--db-instance-identifier $db_instance
--log-file-name error/postgresql.log.$AWS_LOG_TIME > $LOG_FILE
then
echo $(date +%Y%m%d%H%M)': download_aws_piece.sh: FATAL_ERROR - Could not get log from AWS .'
exit 2
fi
else
next_token=`psql -h MONITOR_ENDPOINT.rds.amazonaws.com -U USER -d MONITOR_DATABASE -v ON_ERROR_STOP=1 -A -t -c "select last_aws_nexttoken from database where id = $database_id "`
if [[ $next_token == '' ]];
then
next_token='0'
fi
echo $(date +%Y%m%d%H%M)': download_aws_piece.sh: CONTINUE DOWNLOADING OF AWS LOG'
if ! aws rds download-db-log-file-portion
--max-items $last_aws_max_item_size
--starting-token $next_token
--region REGION
--db-instance-identifier $db_instance
--log-file-name error/postgresql.log.$AWS_LOG_TIME > $LOG_FILE
then
echo $(date +%Y%m%d%H%M)': download_aws_piece.sh: FATAL_ERROR - Could not get log from AWS .'
exit 3
fi
line_count=`cat $LOG_FILE | wc -l`
let lines=$line_count-1
tail -$lines $LOG_FILE > $TMP_MIDDLE
mv -f $TMP_MIDDLE $LOG_FILE
fi
next_token_str=`cat $LOG_FILE | grep NEXTTOKEN`
next_token=`echo $next_token_str | awk -F" " '{ print $2}' `
grep -v NEXTTOKEN $LOG_FILE > $TMP_FILE
if [[ $next_token == '' ]];
then
cp $TMP_FILE $RESULT_FILE
echo $(date +%Y%m%d%H%M)': download_aws_piece.sh: NEXTTOKEN NOT FOUND - FINISH '
rm $LOG_FILE
rm $TMP_FILE
rm $TMP_MIDDLE
rm $TMP_MIDDLE2
exit 0
else
psql -h MONITOR_ENDPOINT.rds.amazonaws.com -U USER -d MONITOR_DATABASE -v ON_ERROR_STOP=1 -A -t -q -c "update database set last_aws_nexttoken = '$next_token' where id = $database_id "
fi
first_str=`tail -1 $TMP_FILE`
line_count=`cat $TMP_FILE | wc -l`
let lines=$line_count-1
head -$lines $TMP_FILE > $RESULT_FILE
###############################################
# MAIN CIRCLE
let count=2
while [[ $next_token != '' ]];
do
echo $(date +%Y%m%d%H%M)': download_aws_piece.sh: count='$count
echo $(date +%Y%m%d%H%M)': download_aws_piece.sh: START DOWNLOADING OF AWS LOG'
if ! aws rds download-db-log-file-portion
--max-items $last_aws_max_item_size
--starting-token $next_token
--region REGION
--db-instance-identifier $db_instance
--log-file-name error/postgresql.log.$AWS_LOG_TIME > $LOG_FILE
then
echo $(date +%Y%m%d%H%M)': download_aws_piece.sh: FATAL_ERROR - Could not get log from AWS .'
exit 4
fi
next_token_str=`cat $LOG_FILE | grep NEXTTOKEN`
next_token=`echo $next_token_str | awk -F" " '{ print $2}' `
TMP_FILE=$LOG_FILE'.tmp'
grep -v NEXTTOKEN $LOG_FILE > $TMP_FILE
last_str=`head -1 $TMP_FILE`
if [[ $next_token == '' ]];
then
concat_str=$first_str$last_str
echo $concat_str >> $RESULT_FILE
line_count=`cat $TMP_FILE | wc -l`
let lines=$line_count-1
tail -$lines $TMP_FILE >> $RESULT_FILE
echo $(date +%Y%m%d%H%M)': download_aws_piece.sh: NEXTTOKEN NOT FOUND - FINISH '
rm $LOG_FILE
rm $TMP_FILE
rm $TMP_MIDDLE
rm $TMP_MIDDLE2
exit 0
fi
if [[ $next_token != '' ]];
then
let growth_counter=$growth_counter+1
if [[ $growth_counter -gt $growth_counter_max ]];
then
let last_aws_max_item_size=$last_aws_max_item_size*$growth_factor
let growth_counter=1
fi
if [[ $last_aws_max_item_size -gt $max_item_size ]];
then
let last_aws_max_item_size=$max_item_size
fi
psql -h MONITOR_ENDPOINT.rds.amazonaws.com -U USER -d MONITOR_DATABASE -A -t -q -c "update database set last_aws_nexttoken = '$next_token' where id = $database_id "
concat_str=$first_str$last_str
echo $concat_str >> $RESULT_FILE
line_count=`cat $TMP_FILE | wc -l`
let lines=$line_count-1
#############################
#Get middle of file
head -$lines $TMP_FILE > $TMP_MIDDLE
line_count=`cat $TMP_MIDDLE | wc -l`
let lines=$line_count-1
tail -$lines $TMP_MIDDLE > $TMP_MIDDLE2
cat $TMP_MIDDLE2 >> $RESULT_FILE
first_str=`tail -1 $TMP_FILE`
fi
let count=$count+1
done
#
#################################################################
exit 0
Teile des Skripts mit einigen Erläuterungen:
Eingabeparameter des Skripts:
- Zeitstempel im Dateinamen des Logfiles im Format YYYY-MM-DD-HH24: AWS_LOG_TIME=$1
- Datenbank-ID: database_id=$2
- Name der generierten Logdatei: RESULT_FILE=$3
Zeitstempel der zuletzt hochgeladenen Logdatei abrufen:
current_aws_log_time=`psql -h MONITOR_ENDPOINT.rds.amazonaws.com -U USER -d MONITOR_DATABASE -A -t -c "select last_aws_log_time from database where id = $database_id "`Wenn der Zeitstempel der zuletzt geladenen Log-Datei nicht mit dem Eingabeparameter übereinstimmt, wird eine neue Log-Datei geladen:
if [[ $current_aws_log_time != $AWS_LOG_TIME ]];
then
is_new_log='1'
if ! psql -h ENDPOINT.rds.amazonaws.com -U USER -d MONITOR_DATABASE -v ON_ERROR_STOP=1 -A -t -c "update database set last_aws_log_time = '$AWS_LOG_TIME' where id = $database_id "
then
echo '***download_aws_piece.sh -FATAL_ERROR - update database set last_aws_log_time .'
exit 1
fi
else
is_new_log='0'
fi
Wir erhalten den Wert des nexttoken-Tags aus der geladenen Datei:
next_token_str=`cat $LOG_FILE | grep NEXTTOKEN`
next_token=`echo $next_token_str | awk -F" " '{ print $2}'`
Ein leeres nexttoken-Wert dient als Hinweis auf das Ende des Ladevorgangs.
Im Loop zählen wir die Portionen der Datei und fügen gleichzeitig die Zeilen zusammen, während wir die Größe der Portion erhöhen:
Hauptschleife
# MAIN CIRCLE
let count=2
while [[ $next_token != '' ]];
do
echo $(date +%Y%m%d%H%M)': download_aws_piece.sh: count='$count
echo $(date +%Y%m%d%H%M)': download_aws_piece.sh: START DOWNLOADING OF AWS LOG'
if ! aws rds download-db-log-file-portion
--max-items $last_aws_max_item_size
--starting-token $next_token
--region REGION
--db-instance-identifier $db_instance
--log-file-name error/postgresql.log.$AWS_LOG_TIME > $LOG_FILE
then
echo $(date +%Y%m%d%H%M)': download_aws_piece.sh: FATAL_ERROR - Could not get log from AWS .'
exit 4
fi
next_token_str=`cat $LOG_FILE | grep NEXTTOKEN`
next_token=`echo $next_token_str | awk -F" " '{ print $2}' `
TMP_FILE=$LOG_FILE'.tmp'
grep -v NEXTTOKEN $LOG_FILE > $TMP_FILE
last_str=`head -1 $TMP_FILE`
if [[ $next_token == '' ]];
then
concat_str=$first_str$last_str
echo $concat_str >> $RESULT_FILE
line_count=`cat $TMP_FILE | wc -l`
let lines=$line_count-1
tail -$lines $TMP_FILE >> $RESULT_FILE
echo $(date +%Y%m%d%H%M)': download_aws_piece.sh: NEXTTOKEN NOT FOUND - FINISH '
rm $LOG_FILE
rm $TMP_FILE
rm $TMP_MIDDLE
rm $TMP_MIDDLE2
exit 0
fi
if [[ $next_token != '' ]];
then
let growth_counter=$growth_counter+1
if [[ $growth_counter -gt $growth_counter_max ]];
then
let last_aws_max_item_size=$last_aws_max_item_size*$growth_factor
let growth_counter=1
fi
if [[ $last_aws_max_item_size -gt $max_item_size ]];
then
let last_aws_max_item_size=$max_item_size
fi
psql -h MONITOR_ENDPOINT.rds.amazonaws.com -U USER -d MONITOR_DATABASE -A -t -q -c "update database set last_aws_nexttoken = '$next_token' where id = $database_id "
concat_str=$first_str$last_str
echo $concat_str >> $RESULT_FILE
line_count=`cat $TMP_FILE | wc -l`
let lines=$line_count-1
#############################
#Get middle of file
head -$lines $TMP_FILE > $TMP_MIDDLE
line_count=`cat $TMP_MIDDLE | wc -l`
let lines=$line_count-1
tail -$lines $TMP_MIDDLE > $TMP_MIDDLE2
cat $TMP_MIDDLE2 >> $RESULT_FILE
first_str=`tail -1 $TMP_FILE`
fi
let count=$count+1
done
Was kommt als Nächstes?
Die erste Zwischenaufgabe – "Log-Datei aus der Cloud laden" – ist erfüllt. Was tun wir mit dem geladenen Log?
Zunächst müssen wir die Log-Datei analysieren und die eigentlichen Anforderungen herausfiltern.
Die Aufgabe ist nicht besonders kompliziert. Ein einfacher Bash-Script kann das gut bewältigen.
upload_log_query.sh
#!/bin/bash
#########################################################
# upload_log_query.sh
# Upload table table from dowloaded aws file
# version HABR
###########################################################
echo 'TIMESTAMP:'$(date +%c)' Upload log_query table '
source_file=$1
echo 'source_file='$source_file
database_id=$2
echo 'database_id='$database_id
beginer=' '
first_line='1'
let "line_count=0"
sql_line=' '
sql_flag=' '
space=' '
cat $source_file | while read line
do
line="$space$line"
if [[ $first_line == "1" ]]; then
beginer=`echo $line | awk -F" " '{ print $1}' `
first_line='0'
fi
current_beginer=`echo $line | awk -F" " '{ print $1}' `
if [[ $current_beginer == $beginer ]]; then
if [[ $sql_flag == '1' ]]; then
sql_flag='0'
log_date=`echo $sql_line | awk -F" " '{ print $1}' `
log_time=`echo $sql_line | awk -F" " '{ print $2}' `
duration=`echo $sql_line | awk -F" " '{ print $5}' `
#replace ' to ''
sql_modline=`echo "$sql_line" | sed 's/'''/''''''/g'`
sql_line=' '
################
#PROCESSING OF THE SQL-SELECT IS HERE
if ! psql -h ENDPOINT.rds.amazonaws.com -U USER -d DATABASE -v ON_ERROR_STOP=1 -A -t -c "select log_query('$ip_port',$database_id , '$log_date' , '$log_time' , '$duration' , '$sql_modline' )"
then
echo 'FATAL_ERROR - log_query '
exit 1
fi
################
fi #if [[ $sql_flag == '1' ]]; then
let "line_count=line_count+1"
check=`echo $line | awk -F" " '{ print $8}' `
check_sql=${check^^}
#echo 'check_sql='$check_sql
if [[ $check_sql == 'SELECT' ]]; then
sql_flag='1'
sql_line="$sql_line$line"
ip_port=`echo $sql_line | awk -F":" '{ print $4}' `
fi
else
if [[ $sql_flag == '1' ]]; then
sql_line="$sql_line$line"
fi
fi #if [[ $current_beginer == $beginer ]]; then
done
Jetzt, da wir die Anforderungen aus der Log-Datei extrahiert haben, können wir weiterarbeiten.
Es ergeben sich mehrere nützliche Möglichkeiten.
Die analysierten Anforderungen müssen irgendwo gespeichert werden. Dazu wird eine Servicetabelle verwendet. log_query
ERSTELLEN TABELLE log_query
(
id SERIAL ,
queryid bigint ,
query_md5hash text NOT NULL ,
database_id integer NOT NULL ,
timepoint timestamp ohne Zeitangabe NOT NULL,
duration double precision NOT NULL ,
query text NOT NULL ,
explained_plan text[],
plan_md5hash text ,
explained_plan_wo_costs text[],
plan_hash_value text ,
baseline_id integer ,
ip text ,
port text
);
ALTER TABLE log_query HINZUFÜGEN PRIMARY KEY (id);
ALTER TABLE log_query HINZUFÜGEN CONSTRAINT queryid_timepoint_unique_key EINZIG (queryid, timepoint );
ALTER TABLE log_query HINZUFÜGEN CONSTRAINT query_md5hash_timepoint_unique_key EINZIG (query_md5hash, timepoint );
CREATE INDEX log_query_timepoint_idx ON log_query (timepoint);
CREATE INDEX log_query_queryid_idx ON log_query (queryid);
ALTER TABLE log_query HINZUFÜGEN CONSTRAINT database_id_fk FOREIGN KEY (database_id) REFERENZEN database (id) ON DELETE CASCADE ;
Die Verarbeitung der analysierten Anfrage erfolgt in plpgsql Funktion „log_query».
log_query.sql
--log_query.sql
--Version HABR
CREATE OR REPLACE FUNCTION log_query( ip_port text ,log_database_id integer , log_date text , log_time text , duration text , sql_line text ) RETURNS boolean AS $$
DECLARE
result boolean ;
log_timepoint timestamp without time zone ;
log_duration double precision ;
pos integer ;
log_query text ;
activity_string text ;
log_md5hash text ;
log_explain_plan text[] ;
log_planhash text ;
log_plan_wo_costs text[] ;
database_rec record ;
pg_stat_query text ;
test_log_query text ;
log_query_rec record;
found_flag boolean;
pg_stat_history_rec record ;
port_start integer ;
port_end integer ;
client_ip text ;
client_port text ;
log_queryid bigint ;
log_query_text text ;
pg_stat_query_text text ;
BEGIN
result = TRUE ;
RAISE NOTICE '***log_query';
port_start = position('(' in ip_port);
port_end = position(')' in ip_port);
client_ip = substring( ip_port from 1 for port_start-1 );
client_port = substring( ip_port from port_start+1 for port_end-port_start-1 );
SELECT e.host , d.name , d.owner_pwd
INTO database_rec
FROM database d JOIN endpoint e ON e.id = d.endpoint_id
WHERE d.id = log_database_id ;
log_timepoint = to_timestamp(log_date||' '||log_time,'YYYY-MM-DD HH24-MI-SS');
log_duration = duration:: double precision;
pos = position ('SELECT' in UPPER(sql_line) );
log_query = substring( sql_line from pos for LENGTH(sql_line));
log_query = regexp_replace(log_query,' +',' ','g');
log_query = regexp_replace(log_query,';+','','g');
log_query = trim(trailing ' ' from log_query);
log_md5hash = md5( log_query::text );
--Erklärung des Ausführungsplans--
EXECUTE 'SELECT dblink_connect(''LINK1'',''host='||database_rec.host||' dbname='||database_rec.name||' user=DATABASE password='||database_rec.owner_pwd||' '')';
log_explain_plan = ARRAY ( SELECT * FROM dblink('LINK1', 'EXPLAIN '||log_query ) AS t (plan text) );
log_plan_wo_costs = ARRAY ( SELECT * FROM dblink('LINK1', 'EXPLAIN ( COSTS FALSE ) '||log_query ) AS t (plan text) );
PERFORM dblink_disconnect('LINK1');
--------------------------
BEGIN
INSERT INTO log_query
(
query_md5hash ,
database_id ,
timepoint ,
duration ,
query ,
explained_plan ,
plan_md5hash ,
explained_plan_wo_costs ,
plan_hash_value ,
ip ,
port
)
VALUES
(
log_md5hash ,
log_database_id ,
log_timepoint ,
log_duration ,
log_query ,
log_explain_plan ,
md5(log_explain_plan::text) ,
log_plan_wo_costs ,
md5(log_plan_wo_costs::text),
client_ip ,
client_port
);
activity_string = 'Neue Anfrage wurde protokolliert '||
' database_id = '|| log_database_id ||
' query_md5hash='||log_md5hash||
' , Zeitpunkt = '||to_char(log_timepoint,'YYYYMMDD HH24:MI:SS');
RAISE NOTICE '%',activity_string;
PERFORM pg_log( log_database_id , 'log_query' , activity_string);
EXCEPTION
WHEN unique_violation THEN
RAISE NOTICE '*** unique_violation *** Anfrage wurde bereits protokolliert';
END;
SELECT queryid
INTO log_queryid
FROM log_query
WHERE query_md5hash = log_md5hash AND
timepoint = log_timepoint;
IF log_queryid IS NOT NULL
THEN
RAISE NOTICE 'log_query mit query_md5hash = % und Zeitpunkt = % hat bereits einen QUERYID = %',log_md5hash,log_timepoint , log_queryid ;
RETURN result;
END IF;
------------------------------------------------
RAISE NOTICE 'Aktualisiere queryid';
SELECT *
INTO log_query_rec
FROM log_query
WHERE query_md5hash = log_md5hash AND timepoint = log_timepoint ;
log_query_rec.query=regexp_replace(log_query_rec.query,';+','','g');
FOR pg_stat_history_rec IN
SELECT
queryid ,
query
FROM
pg_stat_db_queries
WHERE
database_id = log_database_id AND
queryid is not null
LOOP
pg_stat_query = pg_stat_history_rec.query ;
pg_stat_query=regexp_replace(pg_stat_query,'n+',' ','g');
pg_stat_query=regexp_replace(pg_stat_query,'t+',' ','g');
pg_stat_query=regexp_replace(pg_stat_query,' +',' ','g');
pg_stat_query=regexp_replace(pg_stat_query,'$.','%','g');
log_query_text = trim(trailing ' ' from log_query_rec.query);
pg_stat_query_text = pg_stat_query;
--SELECT log_query_rec.query like pg_stat_query INTO found_flag ;
IF (log_query_text LIKE pg_stat_query_text) THEN
found_flag = TRUE ;
ELSE
found_flag = FALSE ;
END IF;
IF found_flag THEN
UPDATE log_query SET queryid = pg_stat_history_rec.queryid WHERE query_md5hash = log_md5hash AND timepoint = log_timepoint ;
activity_string = ' aktualisierte queryid = '||pg_stat_history_rec.queryid||
' für log_query mit id = '||log_query_rec.id
;
RAISE NOTICE '%',activity_string;
EXIT ;
END IF ;
END LOOP ;
RETURN result ;
END
$$ LANGUAGE plpgsql;
Bei der Verarbeitung wird eine Servicetabelle verwendet pg_stat_db_queries, die einen Snapshot der aktuellen Anfragen aus der Tabelle enthält pg_stat_history (Die Verwendung der Tabelle wird hier beschrieben — )
TABELLE pg_stat_db_queries
(
database_id integer,
queryid bigint ,
query text ,
max_time double precision
);
TABELLE pg_stat_history
(
…
database_id integer ,
…
queryid bigint ,
…
max_time double precision ,
…
);
Die Funktion ermöglicht eine Reihe nützlicher Möglichkeiten zur Verarbeitung von Anfragen aus der Protokolldatei. Insbesondere:
Möglichkeit Nr. 1 — Verlauf der Anfragen
Sehr hilfreich, um ein Leistungsproblem zu identifizieren. Zuerst den Verlauf überprüfen — wann begann die Verlangsamung?
Dann, klassisch — nach externen Ursachen suchen. Vielleicht ist die Last auf der Datenbank plötzlich gestiegen und die spezifische Anfrage ist nicht schuld daran.
Einen neuen Eintrag in die Tabelle log_query hinzufügen
port_start = position('(' in ip_port);
port_end = position(')' in ip_port);
client_ip = substring(ip_port from 1 for port_start-1);
client_port = substring(ip_port from port_start+1 for port_end-port_start-1);
SELECT e.host, d.name, d.owner_pwd
INTO database_rec
FROM database d JOIN endpoint e ON e.id = d.endpoint_id
WHERE d.id = log_database_id;
log_timepoint = to_timestamp(log_date||' '||log_time, 'YYYY-MM-DD HH24-MI-SS');
log_duration = to_number(duration, '99999999999999999999D9999999999');
pos = position('SELECT' in UPPER(sql_line));
log_query = substring(sql_line from pos for LENGTH(sql_line));
log_query = regexp_replace(log_query, ' +', ' ', 'g');
log_query = regexp_replace(log_query, ';+', '', 'g');
log_query = trim(trailing ' ' from log_query);
RAISE NOTICE 'log_query=%', log_query;
log_md5hash = md5(log_query::text);
--Explain execution plan--
EXECUTE 'SELECT dblink_connect(''LINK1'', ''host=' || database_rec.host || ' dbname=' || database_rec.name || ' user=DATABASE password=' || database_rec.owner_pwd || ' '')';
log_explain_plan = ARRAY (SELECT * FROM dblink('LINK1', 'EXPLAIN ' || log_query) AS t (plan text));
log_plan_wo_costs = ARRAY (SELECT * FROM dblink('LINK1', 'EXPLAIN (COSTS FALSE) ' || log_query) AS t (plan text));
PERFORM dblink_disconnect('LINK1');
--------------------------
BEGIN
INSERT INTO log_query
(
query_md5hash,
database_id,
timepoint,
duration,
query,
explained_plan,
plan_md5hash,
explained_plan_wo_costs,
plan_hash_value,
ip,
port
)
VALUES
(
log_md5hash,
log_database_id,
log_timepoint,
log_duration,
log_query,
log_explain_plan,
md5(log_explain_plan::text),
log_plan_wo_costs,
md5(log_plan_wo_costs::text),
client_ip,
client_port
);
Option Nr. 2 — Ausführungspläne der Anfragen speichern
An dieser Stelle könnte eine Anmerkung oder ein Kommentar aufkommen: „Aber es gibt doch schon autoexplain“. Es gibt es, aber was bringt es, wenn der Ausführungsplan im selben Logfile gespeichert wird und um ihn für die spätere Analyse zu sichern, das Logfile geparst werden muss?
Ich hingegen benötigte:
erstens: den Ausführungsplan in einer Servicetabelle der Überwachungsdatenbank zu speichern;
zweitens: die Möglichkeit zu haben, Ausführungspläne miteinander zu vergleichen, um sofort zu sehen, dass sich der Ausführungsplan der Abfrage geändert hat.
Es gibt eine Abfrage mit konkreten Ausführungsparametern. Den Ausführungsplan zu erhalten und zu speichern, indem man EXPLAIN verwendet, ist eine einfache Aufgabe.
Darüber hinaus kann man mit dem Ausdruck EXPLAIN (COSTS FALSE) ein Gerüst des Plans erhalten, das zur Ermittlung des Hash-Werts des Plans verwendet wird, was bei der späteren Analyse der Planänderung hilfreich ist.
Den Ausführungsplantemplate erhalten
--Erklären Sie den Ausführungsplan--
EXECUTE 'SELECT dblink_connect(''LINK1'',''host='||database_rec.host||' dbname='||database_rec.name||' user=DATABASE password='||database_rec.owner_pwd||' '')';
log_explain_plan = ARRAY ( SELECT * FROM dblink('LINK1', 'EXPLAIN '||log_query ) AS t (plan text) );
log_plan_wo_costs = ARRAY ( SELECT * FROM dblink('LINK1', 'EXPLAIN ( COSTS FALSE ) '||log_query ) AS t (plan text) );
PERFORM dblink_disconnect('LINK1');
Möglichkeit Nr. 3 — Verwendung des Abfrageprotokolls zur Überwachung
Da die Leistungsmetriken nicht auf den Text der Abfrage, sondern auf deren ID eingestellt sind, müssen die Abfragen aus der Protokolldatei mit den Abfragen verknüpft werden, für die Leistungsmetriken eingerichtet sind.
Mindestens um den genauen Zeitpunkt des Leistungsereignisses zu kennen.
Somit wird bei einem Leistungsereignis für die ID der Abfrage auf die spezifische Abfrage mit spezifischen Parameterwerten und dem genauen Zeitpunkt der Ausführung und der Dauer der Abfrage verwiesen. Diese Informationen können nicht nur über die Ansicht pg_stat_statements erhalten werden.
Finden Sie die queryid der Abfrage und aktualisieren Sie den Eintrag in der Tabelle log_query.
WÄHLE *
IN log_query_rec
VON log_query
WO query_md5hash = log_md5hash UND timepoint = log_timepoint ;
log_query_rec.query=regexp_replace(log_query_rec.query,';+',' ','g');
FÜR pg_stat_history_rec IN
WÄHLE
queryid ,
query
VON
pg_stat_db_queries
WO
database_id = log_database_id UND
queryid IST NICHT NULL
LOOP
pg_stat_query = pg_stat_history_rec.query ;
pg_stat_query=regexp_replace(pg_stat_query,'n+',' ','g');
pg_stat_query=regexp_replace(pg_stat_query,'t+',' ','g');
pg_stat_query=regexp_replace(pg_stat_query,' +',' ','g');
pg_stat_query=regexp_replace(pg_stat_query,'$.','%','g');
log_query_text = trim(trailing ' ' von log_query_rec.query);
pg_stat_query_text = pg_stat_query;
--WÄHLE log_query_rec.query wie pg_stat_query IN found_flag ;
WENN (log_query_text LIKE pg_stat_query_text) DANN
found_flag = TRUE ;
ANDERENFALLS
found_flag = FALSE ;
END IF;
WENN found_flag DANN
UPDATE log_query SET queryid = pg_stat_history_rec.queryid WO query_md5hash = log_md5hash UND timepoint = log_timepoint ;
activity_string = ' aktualisierte queryid = '||pg_stat_history_rec.queryid||
' für log_query mit id = '||log_query_rec.id
;
RAISE NOTICE '%',activity_string;
EXIT ;
END IF ;
END LOOP ;
Nachwort
Die beschriebene Methode fand letztendlich Anwendung in , wodurch mehr Informationen für die Analyse bei der Lösung von auftretenden Leistungsproblemen zur Verfügung stehen.
Natürlich, aus meinem persönlichen Autorenblickwinkel betrachtet, sind noch weitere Arbeiten am Algorithmus zur Auswahl und Anpassung der Ladegröße erforderlich. Die Aufgabe ist im Allgemeinen noch nicht gelöst. Es wird wahrscheinlich interessant sein.
Aber das ist eine ganz andere Geschichte …
Quelle: habr.com
