diff --git a/chapters/thesis/appendix02_timing.sh b/chapters/thesis/appendix02_timing.sh index d6d2e3f..7273e5a 100644 --- a/chapters/thesis/appendix02_timing.sh +++ b/chapters/thesis/appendix02_timing.sh @@ -4,7 +4,6 @@ # Activate Bash Strict Mode set -euo pipefail - main() { { local maxLen=0 @@ -30,14 +29,20 @@ get_statistics() { local dur=0 local durQ=0 local spin=0 + local activeSpinner=0 local spiner=('-' '\' '|' '/') - printf "%-${maxLen}s " $1 + printf "%-${maxLen}s " $1 + if [[ $activeSpinner -ne 0 ]] + then printf " " + fi #echo -ne "$1\t " # repeat for the defined counts the url calling for i in $(seq 1 $2); do - echo -ne "\b${spiner[$spin]}" + if [[ $activeSpinner -ne 0 ]] + then echo -ne "\b${spiner[$spin]}" + fi spin=$(( (spin+1) % 4 )) local gp=$(($(get_posts $1)/1000000)) # from ns to ms if [[ $first -lt 0 ]] @@ -58,7 +63,10 @@ get_statistics() { local stdev=$( echo "sqrt(($durQ / $2) - $avgPow)" | bc ) # output the statistic values - printf "\b%+4s %+5s %+9s %+9s %+9s %+9s\n" $2 $stdev $min $avg $max $first + if [[ $activeSpinner -ne 0 ]] + then echo -ne "\b" + fi + printf "%+4s %+5s %+9s %+9s %+9s %+9s\n" $2 $stdev $min $avg $max $first #echo -e "\b$2\t$stdev\t$min\t$avg\t$max\t$first" } @@ -88,8 +96,8 @@ hostname="http://localhost:8080/WedekindJSF-1.0.0" # the Array of the Urls url_arr=( "$hostname/index.xhtml" - #"$hostname/view/document/list.xhtml" - "$hostname/view/document/listsearch.xhtml" + "$hostname/view/document/list.xhtml" + #"$hostname/view/document/listsearch.xhtml" #"$hostname/view/correspondent/list.xhtml" #"$hostname/view/person/list.xhtml" ) diff --git a/chapters/thesis/appendix04.tex b/chapters/thesis/appendix04.tex index 3a98ae1..276594f 100644 --- a/chapters/thesis/appendix04.tex +++ b/chapters/thesis/appendix04.tex @@ -10,8 +10,8 @@ Um die Messungen etwas zu vereinfachen wurde ein Skript erstellt um die Aufrufe gesammelt durchzuführen. Um die Messungen durchzuführen werden die Befehl, wie in \ref{lst:calling_script_exec} dargestellt aufgerufen. -Durch die nummerierten Präfixe können im Nachgang über die pgBadger-Berichte die SQL-Abfragen verglichen werden. -Wichtig hierbei ist noch, dass vor dem ersten \textit{meascall}-Aufruf überprüft wird, ob die Docker-Container +Durch die nummerierten Präfixe können im Nachgang über die \textit{pgBadger}"=Berichte die SQL-Abfragen verglichen +werden. Wichtig hierbei ist noch, dass vor dem ersten \textit{meascall}-Aufruf überprüft wird, ob die Docker-Container gestartet und initialisiert sind. Wenn dies nicht der Fall ist, laufen die Abfragen ins leere. Am einfachsten ist das über die Statistik von Docker zu ermitteln, ob die CPU-Auslastung auf einen niedrigen Level gefallen ist. diff --git a/chapters/thesis/appendix05.tex b/chapters/thesis/appendix05.tex new file mode 100644 index 0000000..08504df --- /dev/null +++ b/chapters/thesis/appendix05.tex @@ -0,0 +1,27 @@ +% !TeX root = ../../thesis.tex + +%******************************************************************** +% Appendix +%******************************************************* +% If problems with the headers: get headings in appendix etc. right +%\markboth{\spacedlowsmallcaps{Appendix}}{\spacedlowsmallcaps{Appendix}} +\chapter{JSF Performance Measure} +\label{ap:jsf_performance_measure} + +Für die Protokollierung der Abläufe im \ac{JSF} werden zwei Klassen benötigt. Die Factory \ref{lst:logger_factory}, +wird die Wrapper"=Klasse in die Bearbeitungsschicht eingeschleust. Diese Wrapper"=Klasse \ref{lst:logger} beinhaltet +dann die eigentliche Performance-Messung, inklusive der Ausgabe in die Log"=Datei des \textit{Glassfish}"=Servers. +Zusätzlich muss in der Konfiguration \textbf{faces-config.xml} noch angepasst werden, wie in +\ref{lst:logger_factory_activate}, um die Factory durch das System aufrufen zu lassen. + +\includecode[java]{chapters/thesis/appendix05_Logger.java}{lst:logger}{Vdi Logger} + +\includecode[java]{chapters/thesis/appendix05_LoggerFactory.java}{lst:logger_factory}{Vdi Logger Factory} + +\begin{lstlisting}[language=xml,caption={Einbindung Factory},label=lst:logger_factory_activate] + + + de.wedekind.utils.VdlLoggerFactory + + +\end{lstlisting} diff --git a/chapters/thesis/appendix05_Logger.java b/chapters/thesis/appendix05_Logger.java new file mode 100644 index 0000000..9e31987 --- /dev/null +++ b/chapters/thesis/appendix05_Logger.java @@ -0,0 +1,45 @@ +public class VdlLogger extends ViewDeclarationLanguageWrapper { + private static final Logger logger_= Logger.getLogger(VdlLogger.class.getName()); + private final ViewDeclarationLanguage wrapped; + + public VdlLogger(ViewDeclarationLanguage wrapped) { + this.wrapped = wrapped;; + } + + @Override + public UIViewRoot createView(FacesContext context, String viewId) { + long start = System.nanoTime(); + UIViewRoot view = super.createView(context, viewId); + long end = System.nanoTime(); + logger_.severe(String.format("PerformanceCounter-create %s: %.6f ms", viewId, (end - start) / 1e6)); + return view; + } + + @Override + public void buildView(FacesContext context, UIViewRoot view) throws FacesException, IOException { + long start = System.nanoTime(); + super.buildView(context, view); + long end = System.nanoTime(); + logger_.severe(String.format("PerformanceCounter-build %s: %.6f ms", view.getViewId(), (end - start) / 1e6)); + } + + @Override + public void renderView(FacesContext context, UIViewRoot view) throws FacesException, IOException { + long start = System.nanoTime(); + super.renderView(context, view); + long end = System.nanoTime(); + logger_.severe(String.format("PerformanceCounter-render %s: %.6f ms", view.getViewId(), (end - start) / 1e6)); + } + + @Override + public UIComponent createComponent(FacesContext context, String taglibURI, String tagName, Map attributes) { + long start = System.nanoTime(); + UIComponent component = super.createComponent(context, taglibURI, tagName, attributes); + long end = System.nanoTime(); + logger_.severe(String.format("PerformanceCounter-creatc $s: %.6f ms", taglibURI, (end - start) / 1e6)); + return component; + } + + @Override + public ViewDeclarationLanguage getWrapped() { return wrapped; } +} diff --git a/chapters/thesis/appendix05_LoggerFactory.java b/chapters/thesis/appendix05_LoggerFactory.java new file mode 100644 index 0000000..edb6992 --- /dev/null +++ b/chapters/thesis/appendix05_LoggerFactory.java @@ -0,0 +1,15 @@ +public class VdlLoggerFactory extends ViewDeclarationLanguageFactory { + private final ViewDeclarationLanguageFactory wrapped_; + + public VdlLoggerFactory(ViewDeclarationLanguageFactory viewDeclarationLanguage) { + wrapped_ = viewDeclarationLanguage; + } + + @Override + public ViewDeclarationLanguage getViewDeclarationLanguage(String viewId) { + return new VdlLogger(wrapped_.getViewDeclarationLanguage(viewId)); + } + + @Override + public ViewDeclarationLanguageFactory getWrapped() { return wrapped_; } +} diff --git a/chapters/thesis/chapter04.tex b/chapters/thesis/chapter04.tex index 2c992e8..de16609 100644 --- a/chapters/thesis/chapter04.tex +++ b/chapters/thesis/chapter04.tex @@ -29,12 +29,10 @@ werden. In den überschriebenen Funktionen werden nun Laufzeiten gemessen und di in die Log"=Datei eingetragen. Durch die Kennung, können die Zeiten im Nachgang über ein Script ermittelt und ausgewertet werden. -\mytodos{die VdlLogger und VdlLoggerFactory-Klasse als Appendix anhängen} - Zusätzlich wird noch eine Implementierung der zugehörigen Factory"=Klasse \textbf{ViewDeclarationLanguageFactory} benötigt. Durch diese Factory"=Klasse wird der eigentlichen Wrapper mit der Performance-Messung in die Bearbeitungsschicht eingehängt. Diese Implementierung wird dann noch in der \textbf{faces-config.xml} eingetragen, wie das in -\ref{lst:activate-fatory} gezeigt wird, damit die Factory durch das System aufgerufen wird. +\ref{lst:activate-factory} gezeigt wird, damit die Factory durch das System aufgerufen wird. \begin{lstlisting}[language=xml,caption={Einbindung Factory},label=lst:activate-factory] @@ -44,4 +42,38 @@ eingehängt. Diese Implementierung wird dann noch in der \textbf{faces-config.xm \end{lstlisting} -\mytodos{Einstellung am postgresql um die queries mit zu loggen} +Der Quellcode der Klassen ist im Anhang zu finden, unter \ref{ap:jsf_performance_measure} zu finden. + +Um die Abfragen im \textit{PostgreSQL} untersuchen zu können, ist es am leichtesten, wenn man die Konfiguration so +anpasst, dass alle Abfragen mit entsprechenden Zeitmessungen in die Log"=Datei des ausgegeben werden. +Zu erst werden über die Einstellungen unter \ref{lst:postgresql_logfile} die Datei und das Format definiert. + +\begin{lstlisting}[language=yaml,caption={PostgreSQL Dateikonfiguration},label=lst:postgresql_logfile] +log_destination = 'jsonlog' +logging_collector = on +log_directory = 'log' +log_filename = 'postgresql-%Y-%m-%d_%H%M%S.log' +log_file_mode = 0640 +log_rotation_size = 100MB +\end{lstlisting} + +Über die Konfiguration unter \ref{lst:postgresql_logconf} wird definiert welche Werte mit protokolliert werden. Die +wichtigste Einstellung ist \textit{log\_min\_duration\_statement}, diese definiert ab welcher Laufzeit eine Abfrage +protokolliert werden soll. Mit dem Wert 0 werden alle Abfragen protokolliert. Alle weitere Einstellungen sind so +gesetzt, dass nicht unnötige Abfragen für die spätere Auswertung mit \textit{pgBadger} protokolliert werden. + +\begin{lstlisting}[language=yaml,caption={PostgreSQL Ausgabekonfiguration},label=lst:postgresql_logconf] +log_min_duration_statement = 0 +log_autovacuum_min_duration = 10 +log_checkpoints = off +log_connections = on +log_disconnections = on +log_disconnections = on +log_duration = off +log_error_verbosity = default +log_hostname = on +log_lock_waits = on +log_statement = 'none' +log_temp_files = -1 +log_timezone = 'Europe/Berlin' +\end{lstlisting} diff --git a/chapters/thesis/chapter05.tex b/chapters/thesis/chapter05.tex index fbbcc80..438bf0d 100644 --- a/chapters/thesis/chapter05.tex +++ b/chapters/thesis/chapter05.tex @@ -85,21 +85,27 @@ Hierzu zählt die Hauptabfrage der Dokumenten"=-Tabelle, die Ermittlung des letz die Ermittlung der Adressen des Autors, die Ermittlung der CoAutoren, die Ermittlung der Faksimile, sowie die Ermittlung der Anzahl aller vorhandenen Dokumente. -\begin{table}[h!] +Zusätzlich wird die Zeit des Rendern der Sicht gemessen. Hierbei wird zum einen die komplette Zeit des Renderns +ermittelt. Innerhalb des Rendern wird dann noch die Zeit gemessen, wie lange es benötigt, die Daten aus der Datenbank +zu laden, und in die Java-Objekte umzuformen. + +\begin{table}[h] \centering - \begin{tabular}{|r|r|r|r|r|r|r|r|r|} + \resizebox{\textwidth}{!}{ + \begin{tabular}{|r|r|r|r|r|r|r|r|r|r|r|r|r|r|r|} \hline - & \multicolumn{3}{c|}{Aufrufzeit (ms)} & \multicolumn{2}{c|}{Queries} & \multicolumn{3}{c|}{Memory (MB)} \\ + & \multicolumn{3}{c|}{Aufrufzeit (ms)} & \multicolumn{2}{c|}{Queries (ms)} & \multicolumn{3}{c|}{Memory (MB)} & \multicolumn{3}{c|}{Render (ms)} & \multicolumn{3}{c|}{DB-load (ms)} \\ \hline - \# & min & avg & max & \#-avg & avg(ms) & davor & danach & diff \\ + \# & min & avg & max & \#"=avg & avg & start & stop & diff & min & avg & max & min & avg & max \\ \hline - 1 & 360 & 623 & 2079 & 1224.0 & 30.3 & 872.8 & 914.1 & 41.3 \\ % 12240 - 303 ms (135+ 79+ 39+ 22+17+11) (#2-6,8) - 2 & 331 & 372 & 430 & 1208.0 & 31.2 & 914.5 & 1008.0 & 93.5 \\ % 24320 - 615 ms (270+156+ 78+ 56+34+21) (#2-7) - 3 & 291 & 428 & 815 & 1208.0 & 33.5 & 1030.0 & 1297.0 & 267.0 \\ % 36400 - 950 ms (406+256+118+ 79+55+36) (#2-7) - 4 & 288 & 357 & 433 & 1208.0 & 33.7 & 1299.0 & 1461.0 & 162.0 \\ % 48480 - 1287 ms (564+334+167+105+72+45) (#2-7) - 5 & 294 & 404 & 499 & 1208.0 & 32.9 & 1462.0 & 1638.0 & 176.0 \\ % 60560 - 1616 ms (699+428+210+128+92+59) (#2-7) + 1 & 451 & 682 & 1931 & 1223.0 & 30.3 & 931.3 & 986.1 & 54.8 & 440 & 666 & 1859 & 290 & 399 & 710 \\ % 12230 - 303 ms (135+ 79+ 39+ 22+17+11) (#2-6,8) + 2 & 341 & 389 & 478 & 1208.0 & 31.2 & 986.5 & 1159.0 & 172.5 & 331 & 378 & 468 & 235 & 282 & 367 \\ % 24310 - 615 ms (270+156+ 78+ 56+34+21) (#2-7) + 3 & 299 & 407 & 682 & 1208.0 & 33.5 & 1163.0 & 1273.0 & 110.0 & 290 & 398 & 672 & 207 & 307 & 579 \\ % 36390 - 950 ms (406+256+118+ 79+55+36) (#2-7) + 4 & 278 & 359 & 424 & 1208.0 & 33.7 & 1272.0 & 1465.0 & 193.0 & 270 & 351 & 415 & 198 & 269 & 342 \\ % 48470 - 1287 ms (564+334+167+105+72+45) (#2-7) + 5 & 264 & 317 & 356 & 1208.0 & 32.9 & 1467.0 & 1574.0 & 107.0 & 256 & 309 & 348 & 184 & 235 & 276 \\ % 60560 - 1616 ms (699+428+210+128+92+59) (#2-7) \hline \end{tabular} + } \caption{Messung ohne Caches im Docker} \label{tbl:measure-without-cache-docker} \end{table} @@ -141,19 +147,21 @@ erklärt werden. \begin{table}[h!] \centering - \begin{tabular}{|r|r|r|r|r|r|r|r|r|} + \resizebox{\textwidth}{!}{ + \begin{tabular}{|r|r|r|r|r|r|r|r|r|r|r|r|r|r|r|} \hline - & \multicolumn{3}{c|}{Aufrufzeit (ms)} & \multicolumn{2}{c|}{Queries} & \multicolumn{3}{c|}{Memory (MB)} \\ + & \multicolumn{3}{c|}{Aufrufzeit (ms)} & \multicolumn{2}{c|}{Queries (ms)} & \multicolumn{3}{c|}{Memory (MB)} & \multicolumn{3}{c|}{Render (ms)} & \multicolumn{3}{c|}{DB-load (ms)} \\ \hline - \# & min & avg & max & \#-avg & avg(ms) & davor & danach & diff \\ + \# & min & avg & max & \#"=avg & avg & start & stop & diff & min & avg & max & min & avg & max \\ \hline - 1 & 338 & 567 & 1853 & 741.8 & 28.8 & 874.8 & 923.5 & 48.7 \\ % 7418 - 288 ms (145+ 42+ 40+ 24+18+ 8+ 7+ 4) (#2-8,12) - 2 & 235 & 290 & 460 & 685.2 & 25.8 & 923.5 & 926.4 & 2.9 \\ % 14270 - 546 ms (282+ 81+ 70+ 47+33+14+11+ 8) (#2-9) - 3 & 225 & 254 & 313 & 683.6 & 27.6 & 927.4 & 1018.0 & 90.6 \\ % 21106 - 822 ms (430+120+ 99+ 77+49+20+16+11) (#2-9) - 4 & 235 & 289 & 403 & 683.9 & 27.6 & 1018.0 & 1018.0 & 0.0 \\ % 27945 - 1098 ms (569+160+137+ 99+68+26+22+17) (#2-9) - 5 & 193 & 265 & 359 & 687.9 & 27.6 & 1025.0 & 1140.0 & 115.0 \\ % 34824 - 1374 ms (704+202+171+128+86+34+27+22) (#2-9) + 1 & 291 & 611 & 2347 & 730.2 & 28.8 & 852.7 & 891.9 & 39.2 & 282 & 595 & 2286 & 172 & 284 & 770 \\ % 7302 - 288 ms (145+ 42+ 40+ 24+18+ 8+ 7+ 4) (#2-8,12) + 2 & 278 & 319 & 422 & 667.3 & 25.8 & 892.7 & 1010.0 & 117.3 & 266 & 309 & 411 & 173 & 195 & 220 \\ % 13975 - 546 ms (282+ 81+ 70+ 47+33+14+11+ 8) (#2-9) + 3 & 229 & 281 & 329 & 680.6 & 27.6 & 1011.0 & 1067.0 & 56.0 & 220 & 271 & 313 & 134 & 180 & 222 \\ % 20781 - 822 ms (430+120+ 99+ 77+49+20+16+11) (#2-9) + 4 & 222 & 280 & 321 & 671.3 & 27.6 & 1067.0 & 1122.0 & 55.0 & 213 & 271 & 310 & 131 & 189 & 238 \\ % 27494 - 1098 ms (569+160+137+ 99+68+26+22+17) (#2-9) + 5 & 206 & 272 & 388 & 683.6 & 27.6 & 1122.0 & 1219.0 & 97.0 & 199 & 264 & 380 & 122 & 175 & 291 \\ % 34330 - 1374 ms (704+202+171+128+86+34+27+22) (#2-9) \hline \end{tabular} + } \caption{Messung mit OpenJPA-Cache und Größe auf 1000} \label{tbl:measure-ojpa-active} \end{table} @@ -166,24 +174,51 @@ beschleunigt werden konnte. \begin{table}[h!] \centering - \begin{tabular}{|r|r|r|r|r|r|r|r|r|} + \resizebox{\textwidth}{!}{ + \begin{tabular}{|r|r|r|r|r|r|r|r|r|r|r|r|r|r|r|} \hline - & \multicolumn{3}{c|}{Aufrufzeit (ms)} & \multicolumn{2}{c|}{Queries} & \multicolumn{3}{c|}{Memory (MB)} \\ + & \multicolumn{3}{c|}{Aufrufzeit (ms)} & \multicolumn{2}{c|}{Queries (ms)} & \multicolumn{3}{c|}{Memory (MB)} & \multicolumn{3}{c|}{Render (ms)} & \multicolumn{3}{c|}{DB-load (ms)} \\ \hline - \# & min & avg & max & \#-avg & avg(ms) & davor & danach & diff \\ + \# & min & avg & max & \#"=avg & avg & start & stop & diff & min & avg & max & min & avg & max \\ \hline - 1 & 151 & 368 & 1904 & 142.2 & 20.8 & 878.1 & 919.9 & 41.8 \\ % 1422 - 208 ms (133+ 40+ 23+9+2+1) (#2,4-6,10,12) - 2 & 133 & 143 & 159 & 6.0 & 20.5 & 919.8 & 921.0 & 1.2 \\ % 1482 - 413 ms (274+ 80+ 47+9+2+1) (#2-3,5,6,10,12) - 3 & 120 & 126 & 132 & 6.0 & 19.9 & 922.8 & 924.1 & 1.3 \\ % 1542 - 612 ms (412+119+ 69+9+2+1) (#2,3,5,6,10,12) - 4 & 120 & 124 & 128 & 6.0 & 21.4 & 924.1 & 925.4 & 1.3 \\ % 1602 - 826 ms (550+168+ 96+9+2+1) (#2-4,6,10,12) - 5 & 109 & 114 & 131 & 6.0 & 19.7 & 926.1 & 926.8 & 0.7 \\ % 1662 - 1023 ms (683+209+119+9+2+1) (#2-4,6,10,12) + 1 & 151 & 368 & 1904 & 141.2 & 20.8 & 906.3 & 936.8 & 30.5 & 164 & 404 & 2232 & 39 & 124 & 847 \\ % 1412 - 208 ms (133+ 40+ 23+9+2+1) (#2,4-6,10,12) + 2 & 133 & 143 & 159 & 6.0 & 20.5 & 935.7 & 939.3 & 3.6 & 121 & 136 & 146 & 32 & 36 & 44 \\ % 1472 - 413 ms (274+ 80+ 47+9+2+1) (#2-3,5,6,10,12) + 3 & 120 & 126 & 132 & 6.0 & 19.9 & 939.4 & 942.7 & 3.3 & 116 & 136 & 256 & 32 & 47 & 167 \\ % 1532 - 612 ms (412+119+ 69+9+2+1) (#2,3,5,6,10,12) + 4 & 120 & 124 & 128 & 6.0 & 21.4 & 944.3 & 945.4 & 1.1 & 105 & 113 & 125 & 30 & 32 & 39 \\ % 1592 - 826 ms (550+168+ 96+9+2+1) (#2-4,6,10,12) + 5 & 109 & 114 & 131 & 6.0 & 19.7 & 945.5 & 946.7 & 1.2 & 101 & 107 & 112 & 30 & 32 & 35 \\ % 1652 - 1023 ms (683+209+119+9+2+1) (#2-4,6,10,12) \hline \end{tabular} + } \caption{Messung mit OpenJPA-Cache und Größe auf 10000} \label{tbl:measure-ojpa-active-bigger} \end{table} -\mytodos{Untersuchung mit deaktivieren SoftReference fehlt noch} +Bei dem deaktivieren der \textit{SoftReference} und dem kleineren Cache zeigt sich keine große Differenz. Somit scheint +die \textit{SoftReference} nicht das Problem für den steigenden Arbeitsspeicher zu sein, wie in Tabelle +\ref{tbl:measure-ojpa-active-bigger-no-softref} zu sehen. + +% document, documentaddresseeperson, first/last, documentcoauthorperson, count und documentfacsimile +\begin{table}[h!] + \centering + \resizebox{\textwidth}{!}{ + \begin{tabular}{|r|r|r|r|r|r|r|r|r|r|r|r|r|r|r|} + \hline + & \multicolumn{3}{c|}{Aufrufzeit (ms)} & \multicolumn{2}{c|}{Queries (ms)} & \multicolumn{3}{c|}{Memory (MB)} & \multicolumn{3}{c|}{Render (ms)} & \multicolumn{3}{c|}{DB-load (ms)} \\ + \hline + \# & min & avg & max & \#"=avg & avg & start & stop & diff & min & avg & max & min & avg & max \\ + \hline + 1 & 339 & 659 & 2435 & 880.8 & 33.2 & 909.6 & 960.2 & 50.6 & 330 & 644 & 2375 & 218 & 343 & 815 \\ % 8808 - 332 ms (168+ 63+ 44+ 32+21+ 4) (#1,3-6,10) + 2 & 267 & 332 & 388 & 832.1 & 28.1 & 959.7 & 1000.0 & 40.3 & 259 & 323 & 377 & 178 & 229 & 280 \\ % 17129 - 613 ms (313+111+ 82+ 48+42+17) (#1-3,5-6,8) + 3 & 265 & 397 & 350 & 830.3 & 27.3 & 1001.0 & 1107.0 & 106.0 & 256 & 288 & 241 & 172 & 204 & 252 \\ % 25432 - 886 ms (455+156+125+ 64+63+23) (#1-3,5-6,8) + 4 & 249 & 311 & 401 & 727.8 & 27.1 & 1108.0 & 1234.0 & 126.0 & 240 & 303 & 392 & 165 & 225 & 317 \\ % 32710 - 1157 ms (594+205+163+ 85+80+30) (#1-5,8) + 5 & 268 & 296 & 325 & 931.9 & 28.0 & 1236.0 & 1239.0 & 3.0 & 260 & 288 & 318 & 192 & 217 & 244 \\ % 42029 - 1437 ms (738+254+204+106+97+38) (#1-5,8) + \hline + \end{tabular} + } + \caption{Messung mit OpenJPA-Cache und Größe auf 1000 und 0 SoftReference} + \label{tbl:measure-ojpa-active-bigger-no-softref} +\end{table} + Die Vergleich zeigt, dass der Cache eine gute Optimierung bringt, aber dies nur dann gut funktioniert, wenn immer wieder die gleichen Objekte ermittelt werden. Sobald die Anfragen im Wechsel gerufen werden oder einfach nur der Menge @@ -198,20 +233,24 @@ Parameter verwenden. Das sieht man auch entsprechend der Auswertung der Aufrufe dass hier keine Veränderung der Aufrufzeiten stattgefunden hat. Gleich ob man mit \ac{JPQL} oder mit der Criteria API abfragt. +% document, documentaddresseeperson, first/last, documentcoauthorperson, count und documentfacsimile \begin{table}[h!] \centering - \begin{tabular}{|r|r|r|r|r|r|r|r|} + \resizebox{\textwidth}{!}{ + \begin{tabular}{|r|r|r|r|r|r|r|r|r|r|r|r|r|r|r|} \hline - & \multicolumn{3}{|c|}{Aufrufzeit (ms)} & & \multicolumn{3}{|c|}{RSS (MB)} \\ + & \multicolumn{3}{c|}{Aufrufzeit (ms)} & \multicolumn{2}{c|}{Queries (ms)} & \multicolumn{3}{c|}{Memory (MB)} & \multicolumn{3}{c|}{Render (ms)} & \multicolumn{3}{c|}{DB-load (ms)} \\ \hline - \# & min & avg & max & Queries & davor & danach & diff \\ + \# & min & avg & max & \#"=avg & avg & start & stop & diff & min & avg & max & min & avg & max \\ \hline - 1 & 391 & 593 & 1533 & 12256 & 843.63 & 1009.79 & 116.16 \\ - 2 & 281 & 365 & 584 & 12080 & 996.28 & 1114.60 & 118.32 \\ - 3 & 295 & 353 & 464 & 12080 & 1103.30 & 1201.47 & 98.17 \\ - 4 & 280 & 292 & 324 & 12080 & 1191.56 & 1298.46 & 106.90 \\ + 1 & 409 & 771 & 2660 & 1222.4 & xxx & 850.4 & 982.8 & 132.4 & 366 & 633 & 2019 & 254 & 364 & 758 \\ % 12224 - 332 ms (168+ 63+ 44+ 32+21+ 4) (#1,3-6,10) + 2 & 336 & 387 & 504 & 1208.0 & xxx & 982.9 & 1113.0 & 130.1 & 310 & 374 & 433 & 221 & 268 & 345 \\ % 24304 - + 3 & 312 & 373 & 422 & 1208.0 & xxx & 1114.0 & 1221.0 & 107.0 & 295 & 401 & 658 & 216 & 320 & 570 \\ % 36384 - + 4 & 288 & 363 & 471 & 1208.0 & xxx & 1239.0 & 1474.0 & 235.0 & 269 & 356 & 486 & 200 & 279 & 405 \\ % 48464 - + 5 & 325 & 398 & 535 & 1208.0 & xxx & 1474.0 & 1666.0 & 192.0 & 280 & 466 & 804 & 208 & 390 & 725 \\ % 60544 - \hline \end{tabular} + } \caption{Messung mit aktiviertem Cached Queries} \label{tbl:measure-cached-queries} \end{table} @@ -266,11 +305,12 @@ Die Cache-Einstellungen des \ac{EJB} sind in der Admin-Oberfläche des Payara-Se \begin{table}[h!] \centering - \begin{tabular}{|r|r|r|r|r|r|r|r|} + \resizebox{\textwidth}{!}{ + \begin{tabular}{|r|r|r|r|r|r|r|r|r|r|r|r|r|r|r|} \hline - & \multicolumn{3}{|c|}{Aufrufzeit (ms)} & & \multicolumn{3}{|c|}{RSS (MB)} \\ + & \multicolumn{3}{c|}{Aufrufzeit (ms)} & \multicolumn{2}{c|}{Queries (ms)} & \multicolumn{3}{c|}{Memory (MB)} & \multicolumn{3}{c|}{Render (ms)} & \multicolumn{3}{c|}{DB-load (ms)} \\ \hline - \# & min & avg & max & Queries & davor & danach & diff \\ + \# & min & avg & max & \#"=avg & avg & start & stop & diff & min & avg & max & min & avg & max \\ \hline 1 & 416 & 554 & 1269 & 12237 & 840.31 & 998.07 & 157.76 \\ 2 & 299 & 394 & 749 & 12080 & 973.20 & 1101.37 & 128.17 \\ @@ -278,6 +318,7 @@ Die Cache-Einstellungen des \ac{EJB} sind in der Admin-Oberfläche des Payara-Se 4 & 281 & 318 & 398 & 12080 & 1191.25 & 1305.29 & 114.04 \\ \hline \end{tabular} + } \caption{Messung mit \ac{EJB}-Cache} \label{tbl:measure-ejb-cache-active} \end{table} @@ -361,11 +402,12 @@ in den Java-Objekten fast identisch sind. Und in der Datenbank sind die Anfragen \begin{table}[h!] \centering - \begin{tabular}{|r|r|r|r|r|r|r|r|} + \resizebox{\textwidth}{!}{ + \begin{tabular}{|r|r|r|r|r|r|r|r|r|r|r|r|r|r|r|} \hline - & \multicolumn{3}{|c|}{Aufrufzeit (ms)} & & \multicolumn{3}{|c|}{RSS (MB)} \\ + & \multicolumn{3}{c|}{Aufrufzeit (ms)} & \multicolumn{2}{c|}{Queries (ms)} & \multicolumn{3}{c|}{Memory (MB)} & \multicolumn{3}{c|}{Render (ms)} & \multicolumn{3}{c|}{DB-load (ms)} \\ \hline - \# & min & avg & max & Queries & davor & danach & diff \\ + \# & min & avg & max & \#"=avg & avg & start & stop & diff & min & avg & max & min & avg & max \\ \hline 1 & 396 & 572 & 1535 & 12173 & 796.59 & 970.10 & 173.51 \\ 2 & 333 & 366 & 397 & 12080 & 982.28 & 1064.12 & 81.84 \\ @@ -373,6 +415,7 @@ in den Java-Objekten fast identisch sind. Und in der Datenbank sind die Anfragen 4 & 293 & 317 & 388 & 12080 & 1150.43 & 1263.77 & 113.34 \\ \hline \end{tabular} + } \caption{Messung mit Criteria-API ohne Cache} \label{tbl:measure-criteria-api} \end{table} @@ -482,11 +525,12 @@ LEFT JOIN sitecity sc ON sc.id = d.city_id; % document, count, first/last \begin{table}[h!] \centering - \begin{tabular}{|r|r|r|r|r|r|r|r|r|} + \resizebox{\textwidth}{!}{ + \begin{tabular}{|r|r|r|r|r|r|r|r|r|r|r|r|r|r|r|} \hline - & \multicolumn{3}{c|}{Aufrufzeit (ms)} & \multicolumn{2}{c|}{Queries} & \multicolumn{3}{c|}{Memory (MB)} \\ + & \multicolumn{3}{c|}{Aufrufzeit (ms)} & \multicolumn{2}{c|}{Queries (ms)} & \multicolumn{3}{c|}{Memory (MB)} & \multicolumn{3}{c|}{Render (ms)} & \multicolumn{3}{c|}{DB-load (ms)} \\ \hline - \# & min & avg & max & \#-avg & avg(ms) & davor & danach & diff \\ + \# & min & avg & max & \#"=avg & avg & start & stop & diff & min & avg & max & min & avg & max \\ \hline 1 & 203 & 315 & 808 & 17.8 & 3.0 & 851.4 & 883.9 & 32.5 \\ % 178 - 30 ms (19+11+0) (#2,4,8) 2 & 154 & 172 & 187 & 9.0 & 2.2 & 883.2 & 887.0 & 3.8 \\ % 268 - 52 ms (33+18+1) (#2,3,8) @@ -495,6 +539,7 @@ LEFT JOIN sitecity sc ON sc.id = d.city_id; 5 & 121 & 125 & 132 & 9.0 & 2.4 & 900.6 & 901.0 & 0.4 \\ % 538 - 132 ms (85+46+1) (#2,3,8) \hline \end{tabular} + } \caption{Messung mit Materialized View} \label{tbl:measure-materialized-view} \end{table} @@ -521,18 +566,21 @@ Nach dem Anpassungen haben sich dann die Werte aus \ref{tbl:measure-materialized \begin{table}[h!] \centering - \begin{tabular}{|r|r|r|r|r|r|r|r|} + \resizebox{\textwidth}{!}{ + \begin{tabular}{|r|r|r|r|r|r|r|r|r|r|r|r|r|r|r|} \hline - & \multicolumn{3}{|c|}{Aufrufzeit (ms)} & & \multicolumn{3}{|c|}{RSS (MB)} \\ + & \multicolumn{3}{c|}{Aufrufzeit (ms)} & \multicolumn{2}{c|}{Queries (ms)} & \multicolumn{3}{c|}{Memory (MB)} & \multicolumn{3}{c|}{Render (ms)} & \multicolumn{3}{c|}{DB-load (ms)} \\ \hline - \# & min & avg & max & Queries & davor & danach & diff \\ + \# & min & avg & max & \#"=avg & avg & start & stop & diff & min & avg & max & min & avg & max \\ \hline - 1 & 348 & 419 & 869 & 178 & 792.11 & 846.29 & 54.18 \\ - 2 & 340 & 347 & 367 & 90 & 810.77 & 832.57 & 21.80 \\ - 3 & 296 & 353 & 491 & 90 & 840.39 & 867.92 & 27.53 \\ - 4 & 294 & 315 & 392 & 90 & 876.19 & 885.31 & 9.12 \\ + 1 & 241 & 348 & 859 & 16.8 & xxx & 896.0 & 932.4 & xxxx & 232 & 331 & 803 & 132 & 174 & 334 \\ % 168 - + 2 & 164 & 194 & 225 & 9.0 & xxx & 933.3 & 935.9 & xxxx & 154 & 185 & 215 & 79 & 99 & 117 \\ % 258 - + 3 & 147 & 161 & 179 & 9.0 & xxx & 935.8 & 938.8 & 3.0 & 139 & 152 & 167 & 68 & 77 & 86 \\ % 348 - + 4 & 135 & 145 & 183 & 9.0 & xxx & 939.4 & 936.0 & -3.4 & 127 & 137 & 174 & 70 & 73 & 75 \\ % 438 - + 5 & 126 & 137 & 154 & 9.0 & xxx & 936.1 & 939.1 & 3.0 & 118 & 129 & 143 & 66 & 72 & 79 \\ % 528 - \hline \end{tabular} + } \caption{Messung mit erweiterter Materialized View} \label{tbl:measure-materialized-view-ext} \end{table} @@ -542,30 +590,6 @@ Nach dem Anpassungen haben sich dann die Werte aus \ref{tbl:measure-materialized \mytodos{Hier könnte man auch den Query-Cache nochmal verwenden, da die anfragen nun fix wären} \mytodos{Grundlagen zur Materialized-View noch hinterlegen} -\section{Java Server Faces} -\label{sec:performance-investigation-application:java-server-faces} - -%\mytodos{Zeitmessungen innerhalb der Anwendung über einen Flamegraphs darstellten https://www.brendangregg.com/flamegraphs.html} -%\mytodos{Diese Zeitmessung vielleicht noch ins Obere Kapitel ala Ausgangspunkt verschieben} - -Wie in \ref{sec:performance-checking:performance-measure} beschrieben wurde, ist die Protokollierung für das erstellen -einer Webseite aktiviert. Bei komplett deaktivierten Cache sieht man, dass bei der Dokumentenliste der größte Zeitfaktor -beim Render der Sicht auftritt. Wenn man nun noch die Abfrage auf die Materialized-View umstellt, ist es noch -auffälliger. - -\begin{table}[h!] - \centering - \begin{tabular}{|l|r|r|r|} - \hline - Art & min (ms) & avg (ms) & max (ms) \\ - \hline - create & 0.030 & 0.048 & 0.081 \\ - build & 1.637 & 2.004 & 2.113 \\ - render & 116.338 & 148.975 & 156.875 \\ - \hline - \end{tabular} -\end{table} - \section{Statische Webseiten} \label{sec:performance-investigation-application:static-website} diff --git a/thesis.pdf b/thesis.pdf index ff1c3ab..7ff6b00 100644 Binary files a/thesis.pdf and b/thesis.pdf differ diff --git a/thesis.tex b/thesis.tex index 5edb054..d0cffc8 100644 --- a/thesis.tex +++ b/thesis.tex @@ -100,6 +100,7 @@ \include{chapters/thesis/appendix02} \include{chapters/thesis/appendix03} \include{chapters/thesis/appendix04} +\include{chapters/thesis/appendix05} %\include{chapters/examples/appendix02} %************************************************************************* % Other Stuff in the Back