kopia lustrzana https://github.com/openmaptiles/openmaptiles
More performance profiling details (#845)
Results now show a table of how long each step took, as well as the PG database size change. * use `time` to compute profiling for each step * call postgres to get database sizepull/846/head^2
Yuri Astrakhan
GitHub
rodzic
5445a70c30
commit
68911900c9
|
|
@ -20,6 +20,8 @@ jobs:
|
|||
- name: Run quickstart for a small area
|
||||
env:
|
||||
area: monaco
|
||||
QUICKSTART_MIN_ZOOM: 0
|
||||
QUICKSTART_MAX_ZOOM: 14
|
||||
run: |
|
||||
# For now, change the quickstart values directly in the .env file
|
||||
# TODO: We should probably use env vars instead
|
||||
|
|
@ -92,13 +94,50 @@ jobs:
|
|||
uses: actions/cache@v1
|
||||
with:
|
||||
path: perf_cache
|
||||
key: "${{ steps.calc.outputs.hash }}-${{ env.TEST_DATA_URL }}"
|
||||
# If profiling result cache has incompatible format, increase this "v" number
|
||||
key: "v10-${{ steps.calc.outputs.hash }}-${{ env.TEST_DATA_URL }}"
|
||||
|
||||
- name: Load test data into DB and run performance test
|
||||
id: main
|
||||
env:
|
||||
CACHE_SHA: "${{ steps.calc.outputs.hash }}"
|
||||
run: |
|
||||
profile() {
|
||||
TIME_FORMAT="# %C
|
||||
P\t%P\tPercentage of the CPU that this job got. This is just user + system times divided by the total running time. It also prints a percentage sign.
|
||||
x\t%x\tExit status of the command.
|
||||
-\t-----\t-- Time --------------------------------------------------------------------------------------------------
|
||||
e\t%e\tElapsed real (wall clock) time used by the process, in seconds.
|
||||
E\t%E\tElapsed real (wall clock) time used by the process, in [hours:]minutes:seconds.
|
||||
U\t%U\tTotal number of CPU-seconds that the process used directly (in user mode), in seconds.
|
||||
S\t%S\tTotal number of CPU-seconds used by the system on behalf of the process (in kernel mode), in seconds.
|
||||
-\t-----\t-- Context Switches --------------------------------------------------------------------------------------
|
||||
c\t%c\tNumber of times the process was context-switched involuntarily (because the time slice expired).
|
||||
w\t%w\tNumber of times that the program was context-switched voluntarily, for instance while waiting for an I/O operation to complete.
|
||||
-\t-----\t-- Page faults -------------------------------------------------------------------------------------------
|
||||
F\t%F\tNumber of major, or I/O-requiring, page faults that occurred while the process was running. These are faults where the page has actually migrated out of primary memory.
|
||||
R\t%R\tNumber of minor, or recoverable, page faults. These are pages that are not valid (so they fault) but which have not yet been claimed by other virtual pages. Thus the data in the page is still valid but the system tables must be updated.
|
||||
W\t%W\tNumber of times the process was swapped out of main memory.
|
||||
-\t-----\t-- Memory ------------------------------------------------------------------------------------------------
|
||||
K\t%K\tAverage total (data+stack+text) memory use of the process, in Kilobytes.
|
||||
t\t%t\tAverage resident set size of the process, in Kilobytes.
|
||||
p\t%p\tAverage unshared stack size of the process, in Kilobytes.
|
||||
M\t%M\tMaximum resident set size of the process during its lifetime, in Kilobytes.
|
||||
D\t%D\tAverage size of the process's unshared data area, in Kilobytes.
|
||||
X\t%X\tAverage amount of shared text in the process, in Kilobytes.
|
||||
Z\t%Z\tSystem's page size, in bytes. This is a per-system constant, but varies between systems.
|
||||
-\t-----\t-- Other -------------------------------------------------------------------------------------------------
|
||||
I\t%I\tNumber of file system inputs by the process.
|
||||
O\t%O\tNumber of file system outputs by the process.
|
||||
k\t%k\tNumber of signals delivered to the process.
|
||||
r\t%r\tNumber of socket messages received by the process.
|
||||
s\t%s\tNumber of socket messages sent by the process.
|
||||
"
|
||||
# Must use full path to get the full-featured version of time
|
||||
# profile-*.tsv filenames are parsed using ${file:8:-4} below
|
||||
/usr/bin/time --format "$TIME_FORMAT" --output "${PROFILE_DIR}/profile-${1}.tsv" "${@:2}"
|
||||
}
|
||||
|
||||
create_db() {
|
||||
make clean
|
||||
make init-dirs
|
||||
|
|
@ -106,11 +145,22 @@ jobs:
|
|||
make db-destroy
|
||||
make all
|
||||
make db-start
|
||||
time make import-data
|
||||
time make import-osm
|
||||
time make import-borders
|
||||
time make import-wikidata
|
||||
time make import-sql
|
||||
profile 1_data make import-data
|
||||
profile 2_osm make import-osm
|
||||
profile 3_borders make import-borders
|
||||
profile 4_wikidata make import-wikidata
|
||||
profile 5_sql make import-sql
|
||||
|
||||
# Get database total size, in MB
|
||||
# Once Makefile has a few more improvements, we can use this approach instead:
|
||||
# echo $'\\set QUIET on \\a \\x off \\t \\\\ select pg_database_size(current_database())/1024/1024;' | make -s psql
|
||||
if grep -qE '^ import-osm:$' docker-compose.yml; then
|
||||
# old version using dedicated import-osm docker image
|
||||
DB_SIZE_MB=$(docker-compose run --rm -u $(id -u):$(id -g) import-osm ./psql.sh -qtAc 'select pg_database_size(current_database())/1024/1024;')
|
||||
else
|
||||
DB_SIZE_MB=$(docker-compose run --rm -u $(id -u):$(id -g) openmaptiles-tools psql.sh -qtAc 'select pg_database_size(current_database())/1024/1024;')
|
||||
fi
|
||||
echo "$DB_SIZE_MB" > "${PROFILE_DIR}/db_size.tsv"
|
||||
}
|
||||
|
||||
mkdir -p perf_cache
|
||||
|
|
@ -126,11 +176,12 @@ jobs:
|
|||
git reset --hard ${CURRENT_SHA}^1
|
||||
fi
|
||||
|
||||
PROFILE_DIR=../perf_cache
|
||||
create_db
|
||||
|
||||
# Use latest tools version because these specific tests do not yet exist in the 4.1 tools version
|
||||
# Custom TOOLS_VERSION can be removed once OMT master is migrated to the next tools version
|
||||
TOOLS_VERSION=latest docker-compose run --rm openmaptiles-tools \
|
||||
TOOLS_VERSION=latest profile test-perf docker-compose run --rm openmaptiles-tools \
|
||||
test-perf openmaptiles.yaml $TEST_PERF_PARAMS \
|
||||
--record /tileset/results.json
|
||||
mv results.json ../perf_cache
|
||||
|
|
@ -143,21 +194,30 @@ jobs:
|
|||
echo "Found cached performance results"
|
||||
fi
|
||||
|
||||
pushd ../perf_cache
|
||||
if [ "$GITHUB_EVENT_NAME" = "pull_request" ]; then
|
||||
cp ../perf_cache/results.json ../artifacts/base-results.json
|
||||
cp results.json ../artifacts/base-results.json
|
||||
# Copy all tsv files, not just the ones with "profile-" prefix.
|
||||
for file in *.tsv; do
|
||||
cp "$file" "../artifacts/base-$file"
|
||||
done
|
||||
else
|
||||
cp ../perf_cache/results.json ../artifacts/results.json
|
||||
cp results.json ../artifacts/results.json
|
||||
# Copy all tsv files, not just the ones with "profile-" prefix.
|
||||
cp *.tsv ../artifacts
|
||||
fi
|
||||
popd
|
||||
|
||||
if [ "$GITHUB_EVENT_NAME" = "pull_request" ]; then
|
||||
echo "Comparing pull request results with the base..."
|
||||
|
||||
PROFILE_DIR=../artifacts
|
||||
create_db
|
||||
|
||||
# Use latest tools version because these specific tests do not yet exist in the 4.1 tools version
|
||||
# Custom TOOLS_VERSION can be removed once OMT master is migrated to the next tools version
|
||||
cp ../perf_cache/results.json .
|
||||
OUTPUT="$(TOOLS_VERSION=latest docker-compose run --rm openmaptiles-tools \
|
||||
OUTPUT="$(TOOLS_VERSION=latest profile test-perf docker-compose run --rm openmaptiles-tools \
|
||||
test-perf openmaptiles.yaml $TEST_PERF_PARAMS \
|
||||
--compare /tileset/results.json --record /tileset/pr-results.json)"
|
||||
rm results.json
|
||||
|
|
@ -167,8 +227,34 @@ jobs:
|
|||
OUT_SUMMARY="${OUTPUT##*========}"
|
||||
OUT_DETAILS="${OUTPUT%%========*}"
|
||||
|
||||
pushd ../artifacts
|
||||
PROFILING_MSG="step | total time | change | user time | change
|
||||
--- | --- | --- | --- | ---
|
||||
"
|
||||
for file in profile*.tsv; do
|
||||
new_total_time_fmt=$(grep -E '^E' "$file" | cut -d$'\t' -f 2)
|
||||
old_total_time=$(grep -E '^e' "base-$file" | cut -d$'\t' -f 2)
|
||||
new_total_time=$(grep -E '^e' "$file" | cut -d$'\t' -f 2)
|
||||
old_user_time=$(grep -E '^U' "base-$file" | cut -d$'\t' -f 2)
|
||||
new_user_time=$(grep -E '^U' "$file" | cut -d$'\t' -f 2)
|
||||
|
||||
PROFILING_MSG="${PROFILING_MSG}${file:8:-4} \
|
||||
| ${new_total_time_fmt} | $( echo "$old_total_time $new_total_time" | awk '{ if ($1 == 0) print "-"; else printf "%.1f%%", ($2-$1)*100/$1 }' ) \
|
||||
| $( echo "$old_user_time $new_user_time" | awk '{ if ($1 == 0) print "%s | -", $2 ; else printf "%s | %.1f%%", $2, ($2-$1)*100/$1 }' ) \
|
||||
"$'\n'
|
||||
done
|
||||
|
||||
DB_SIZE_CHANGE=$( echo "$(cat base-db_size.tsv) $(cat db_size.tsv)" | \
|
||||
awk '{ printf "PostgreSQL DB size in MB: %s ⇒ %s", $1, $2; if ($1 != 0) printf " (%.1f%% change)", ($2-$1)*100/$1 }' )
|
||||
|
||||
popd
|
||||
|
||||
cat > ../pr_message/message.md <<EOF
|
||||
Performance evaluation results for $GITHUB_SHA
|
||||
Results evaluating commit $(git log HEAD^2 -1 --format="%H") (merged with base $CACHE_SHA as $GITHUB_SHA). See [run details](https://github.com/$GITHUB_REPOSITORY/actions/runs/$GITHUB_RUN_ID).
|
||||
|
||||
$DB_SIZE_CHANGE
|
||||
|
||||
$PROFILING_MSG
|
||||
|
||||
\`\`\`
|
||||
$OUT_SUMMARY
|
||||
|
|
|
|||
Ładowanie…
Reference in New Issue