178 lines
13 KiB
TeX
178 lines
13 KiB
TeX
|
\epigraph{\textit{Welcome to the real world.}}{--- Morpheus, \textit{The Matrix}}
|
||
|
|
|
||
|
|
\noindent Die in \autoref{sec:testsRequests} beschriebenen Requests wurden, nach der Verarbeitung durch die Kieker-Data-Bridge, mit dem Kommandozeilentool \emph{kieker-analysis.sh} aufbereitet. Hierbei wurden zunächst mit der Option \emph{-\--print-Execution-Traces} textuelle Beschreibungen der erstellten Traces erzeugt. Aus diesen Beschreibungen konnten dann das zeitliche Verhalten, welches in \autoref{sec:auswZeit} erläutert wird, und die Funktionsaufrufe, welche in \autoref{sec:auswFunCall} besprochen werden, abgelesen werden.
|
||
|
|
|
||
|
|
Anschließend wurde mit einem Perl-Script (siehe Anhang \ref{app:perlFunCnt}) die Aufrufhäufigkeit für jede Funktion gezählt. Die Ergebnisse dieser Untersuchung werden in \autoref{sec:auswFunCnt} vorgestellt. Schließlich wurden die Funktionsaufrufe mit einem weiteren Perl-Script (siehe Anhang \ref{app:perlFunAgg}) in ihre Pakete aggregiert und die Aufrufhäufigkeiten für diese bestimmt. Diese Daten werden in \autoref{sec:auswPackCnt} präsentiert und diskutiert.
|
||
|
|
|
||
|
|
Zur weiteren Veranschaulichung wurden dann auf den aggregierten Daten mit der Kommandozeilenoption \emph{-\--plot-Assembly-Component-Dependency-Graph} die in \autoref{sec:auswPackDep} präsentierten Abhängigkeitsgraphen erstellt, um die Verbindungen zwischen den Paketen zu visualisieren.
|
||
|
|
|
||
|
|
\section{Zeitliches Verhalten}\label{sec:auswZeit}
|
||
|
|
Zunächst wurde eine Zeitmessung für alle Requests ausgeführt. Die erhaltenen Daten sind in \autoref{tab:auswZeit} aufgetragen. Zunächst ist hierbei festzustellen, dass die Instrumentierung offenbar einen extremen Anstieg der Ausführungszeit verursacht hat. Als wahrscheinlichste Engstelle vermute ich hier das Versenden der Records an den JMS-Provider via TCP. Hier sollte in Zukunft auf eine asynchrone Kommunikation umgestellt werden um den Programmablauf nicht unnötig zu verzögern.
|
||
|
|
|
||
|
|
\begin{table}
|
||
|
|
\begin{tabular}{l|rrrrr}
|
||
|
|
Request & Nr. 1 & Nr. 2 & Nr. 3 & Nr. 4 & Nr. 5 \\
|
||
|
|
\hline
|
||
|
|
Eprints normal & 402 ms & 220 ms & 136 ms & 413 ms & 348 ms \\
|
||
|
|
EPrints instrumentiert & 15389 ms & 15043 ms & 18408 ms & \textbf{23430 ms} & \textbf{7066 ms} \\
|
||
|
|
\hline
|
||
|
|
\gls{kielpr} normal & 10270 ms & 227 ms & 166 ms & 13420 ms & 18890 ms \\
|
||
|
|
\gls{kielpr} instrumentiert & 28505 ms & 16623 ms & 17414 ms & \textbf{280927 ms} & \textbf{342662 ms} \\
|
||
|
|
\hline
|
||
|
|
Faktor normal & 25,5 & 1,0 & 1,2 & 32,5 & 54,3 \\
|
||
|
|
Faktor instrumentiert & 1,8 & 1,1 & 0,9 & 11,9 & 48,5
|
||
|
|
\end{tabular}
|
||
|
|
\caption{Zeitliches Verhalten von Eprints und Kielprints vor und nach Instrumentierung}
|
||
|
|
\label{tab:auswZeit}
|
||
|
|
\end{table}
|
||
|
|
|
||
|
|
Vergleicht man die Ausführungszeiten zwischen den instrumentierten Varianten, so ist auffällig, dass in den Request 2 und 3 mit Faktor 1,1 und 0,9 kaum Abweichungen auftreten, aber in Request 4 eine Steigerung der Ausführungszeit um den Faktor 11,9 und in Request 5 sogar eine Steigung um den Faktor 48,5 auftritt. Weiter ist auffällig, dass in EPrints die Zeit für Request 5 um 70\% geringer ausfällt als für Request 4, während in \gls{kielpr} hier noch eine Steigerung um 21\% von Request 4 zu Request 5 festzustellen ist. Der Request 1 liegt zwischen den beiden Verhalten, indem es zwar eine Steigerung aufweißt aber diese mit dem Faktor 1,85 deutlich geringer ausfällt als in Requests 4 und 5.
|
||
|
|
|
||
|
|
Diese Verhältnisse verschieben sich noch bei den nicht-instrumentierten Versionen. Die Requests 2 und 3 weisen auch bei diesen Messungen kaum Unterschiede auf, doch bei den Request 1, 4 und 5 steigt die Ausführungszeit um Faktoren zwischen 25,5 und 54,3. Die unterschiedlichen Verhältnisse zwischen den normalen und instrumentierten Versionen lassen sich auf den großen Einfluss des Monitorings, und hier speziell das Senden der Records, zurückführen.
|
||
|
|
|
||
|
|
\section{Funktionsaufrufe}\label{sec:auswFunCall}
|
||
|
|
Als nächstes kann die Anzahl protokollierter Funktionsaufrufe betrachtet werden. In \autoref{tab:auswFunCall} sind die einzelnen Requests sowie die Summe über alle 5 Requests aufgetragen. Die Ergebnisse bieten ähnliche Folgerungen, wie bereits bei der zeitlichen Betrachtung.
|
||
|
|
|
||
|
|
\begin{table}[h!tb]
|
||
|
|
\begin{tabular}{l|rrrrr|r}
|
||
|
|
Request & 1 & 2 & 3 & 4 & 5 & Summe \\
|
||
|
|
\hline
|
||
|
|
Eprints & 20875 & 28590 & 33171 & 43056 & 16980 & 142672 \\
|
||
|
|
% \hline
|
||
|
|
\gls{kielpr} & 31742 & 36681 & 40165 & 905580 & 934760 & 1948928 \\
|
||
|
|
% \hline
|
||
|
|
Faktor & 1,5 & 1,3 & 1,2 & 21,0 & 55,1 & 13,7
|
||
|
|
\end{tabular}
|
||
|
|
\caption{Funktionsaufrufe von EPrints und Kielprints}
|
||
|
|
\label{tab:auswFunCall}
|
||
|
|
\end{table}
|
||
|
|
|
||
|
|
\noindent Zwar sind die Funktionsaufrufe in den ersten drei Requests bei \gls{kielpr} höher als in EPrints, allerdings bewegen sich die beiden Systeme noch in den selben Größenordnungen. Als Abweichung zwischen dem zeitlichen Verhalten und den Funktionsaufrufen ist bei Request 3 festzustellen, dass trotz einer kürzeren Ausführungszeit eine Steigerung der Funktionsaufrufe auftritt. Bei Request 4 weißt \gls{kielpr} eine Steigerung um den Faktor 21,0 gegenüber dem unmodifizierten EPrints auf, bei Request 5 beträgt die Steigerung gar Faktor 55,1. In der Summe ergibt sich eine Steigerung um den Faktor 13,7 zwischen den Systemen.
|
||
|
|
|
||
|
|
\section{Aufrufhäufigkeiten für Funktionen}\label{sec:auswFunCnt}
|
||
|
|
Werden die Aufrufhäufigkeiten für die einzelnen Funktionen ausgewertet, zeigen sich auffällige Verschiebungen. Hierfür betrachte ich exemplarisch Request 4, für den ich in \autoref{tab:auswFunCnt4} jeweils die 10 häufigsten Funktionen angegeben habe.
|
||
|
|
|
||
|
|
\begin{table}[h!tb]
|
||
|
|
\begin{tabular}{lr}
|
||
|
|
\textbf{EPrints} & \textbf{Aufrufe} \\
|
||
|
|
EPrints.Script.Compiler.next\_is & 5873 \\
|
||
|
|
EPrints.Repository.xml & 2668 \\
|
||
|
|
EPrints.XML.is\_dom & 1690 \\
|
||
|
|
EPrints.XHTML.\_to\_xhtml & 1345 \\
|
||
|
|
EPrints.Utils.is\_set & 1230 \\
|
||
|
|
EPrints.XML.EPC.process & 1073 \\
|
||
|
|
EPrints.XML.clone\_node & 968 \\
|
||
|
|
EPrints.Repository.get\_repository & 943 \\
|
||
|
|
EPrints.Repository.clone\_for\_me & 923 \\
|
||
|
|
EPrints.XML.create\_element & 842 \\ \\
|
||
|
|
|
||
|
|
\textbf{\gls{kielpr}} & \textbf{Aufrufe} \\
|
||
|
|
EPrints.MetaField.Id.value\_from\_sql\_row & 75008 \\
|
||
|
|
EPrints.MetaField.property & 65202 \\
|
||
|
|
EPrints.Database.quote\_identifier & 52383 \\
|
||
|
|
EPrints.Utils.is\_set & 44571 \\
|
||
|
|
EPrints.MetaField.get\_sql\_names & 37258 \\
|
||
|
|
EPrints.DataSet.field & 31053 \\
|
||
|
|
EPrints.MetaField.get\_value & 30598 \\
|
||
|
|
EPrints.DataObj.get\_value\_raw & 30598 \\
|
||
|
|
EPrints.MetaField.get\_property & 27790 \\
|
||
|
|
EPrints.XML.is\_dom & 24304
|
||
|
|
\end{tabular}
|
||
|
|
\caption{Die 10 meistgenutzten Funktionen bei Request 4}
|
||
|
|
\label{tab:auswFunCnt4}
|
||
|
|
\end{table}
|
||
|
|
|
||
|
|
\noindent Die am häufigsten aufgerufene Funktion in EPrints ist \emph{EPrints.Script.Compiler.next\_is}, eine Funktion die zur Verarbeitung der EPrints-internen Scriptsprache EPscript benötigt wird. Die Funktionen aus den Paketen \emph{EPrints.XHTML} und \emph{EPrints.XML} dienen offenbar primär der Aufbereitung des XHTML Codes der aufgerufenen Seite. Die Funktion aus dem Paket \emph{EPrints.Repository} behandeln das zentrale Datenobjekt des EPrints-Systems, welches z.B. die Datenbankverbindung oder den aktuellen Request zum zentralen Zugriff kapselt.
|
||
|
|
|
||
|
|
Im Vergleich dazu sind die häufigsten Funktionen in \gls{kielpr} weitestgehend auf die Datenbank bezogen. Neben den direkten Datenbankfunktionen dienen die meisten Funktionen aus den \emph{EPrints.MetaField} Paketen zur Aufbereitung der erhaltenen Daten. Besonders ist hierbei zu beachten, dass die häufigste Funktion, \emph{EPrints.MetaField.Id.value\_from\_sql\_row}, in der Dokumentation als \emph{deprecated} und Relikt aus EPrints Version 2 ausgewiesen ist und nicht mehr verwendet werden sollte.
|
||
|
|
Wird eine Summe über alle 5 Requests gebildet ergibt sich ein ähnliches Bild, wie in \autoref{tab:auswFunCntSum} zu erkennen ist.
|
||
|
|
|
||
|
|
\begin{table}[h!tb]
|
||
|
|
\begin{tabular}{lr}
|
||
|
|
\textbf{EPrints} & \textbf{Aufrufe} \\
|
||
|
|
EPrints.Script.Compiler.next\_is & 17534 \\
|
||
|
|
EPrints.Repository.xml & 6428 \\
|
||
|
|
EPrints.XML.is\_dom & 5457 \\
|
||
|
|
EPrints.Utils.is\_set & 5361 \\
|
||
|
|
EPrints.MetaField.property & 4185 \\
|
||
|
|
EPrints.DataSet.field & 3310 \\
|
||
|
|
EPrints.Repository.get\_repository & 3181 \\
|
||
|
|
EPrints.XML.EPC.process & 3011 \\
|
||
|
|
EPrints.XML.clone\_node & 2682 \\
|
||
|
|
EPrints.Repository.clone\_for\_me & 2652 \\ \\
|
||
|
|
|
||
|
|
\textbf{\gls{kielpr}} & \textbf{Aufrufe} \\
|
||
|
|
EPrints.MetaField.Id.value\_from\_sql\_row & 155884 \\
|
||
|
|
EPrints.MetaField.property & 138063 \\
|
||
|
|
EPrints.Database.quote\_identifier & 111214 \\
|
||
|
|
EPrints.Utils.is\_set & 95232 \\
|
||
|
|
EPrints.MetaField.get\_sql\_names & 78938 \\
|
||
|
|
EPrints.DataSet.field & 66011 \\
|
||
|
|
EPrints.MetaField.get\_value & 64282 \\
|
||
|
|
EPrints.DataObj.get\_value\_raw & 64282 \\
|
||
|
|
EPrints.MetaField.get\_property & 59662 \\
|
||
|
|
EPrints.XML.is\_dom & 53005
|
||
|
|
\end{tabular}
|
||
|
|
\caption{Die 10 meistgenutzten Funktionen insgesamt}
|
||
|
|
\label{tab:auswFunCntSum}
|
||
|
|
\end{table}
|
||
|
|
|
||
|
|
\noindent Analog zu Request 4 dominieren hier in \gls{kielpr} die Funktionen zur Behandlung von Datenbankanfragen, während diese in EPrints nur eine untergeordnete Rolle spielen. In EPrints wird weiterhin die Funktion \emph{EPrints.Script.Compiler.next\_is} am häufigsten ausgeführt, welche bei der Ausführung von Scripten den Typ des nächsten Objektes bestimmt.
|
||
|
|
|
||
|
|
\section{Aufrufhäufigkeiten für Pakete}\label{sec:auswPackCnt}
|
||
|
|
Mit dem in Anhang \ref{app:perlFunAgg} angegebenen Skript wurden die individuellen Funktionsaufrufe auf ihre Paketzugehörigkeit reduziert, um Abhängigkeiten auf Paketebene analysieren zu können. Hierbei ergeben sich, über alle Requests zusammen, die in \autoref{tab:auswPack} angegebenen Werte.
|
||
|
|
|
||
|
|
\begin{table}[h!tb]
|
||
|
|
\begin{tabular}{lr}
|
||
|
|
\textbf{EPrints} & \textbf{Aufrufe} \\
|
||
|
|
EPrints.Script.Compiler & 30304 \\
|
||
|
|
EPrints.Repository & 25980 \\
|
||
|
|
EPrints.MetaField & 18374 \\
|
||
|
|
EPrints.XML & 12486 \\
|
||
|
|
EPrints.DataSet & 7488 \\
|
||
|
|
EPrints.Utils & 7220 \\
|
||
|
|
EPrints.XML.EPC & 5703 \\
|
||
|
|
EPrints.DataObj & 5439 \\
|
||
|
|
EPrints.Database & 3466 \\
|
||
|
|
EPrints.Script.Compiled & 3404 \\ \\
|
||
|
|
|
||
|
|
\textbf{\gls{kielpr}} & \textbf{Aufrufe} \\
|
||
|
|
EPrints.MetaField & 501872 \\
|
||
|
|
EPrints.DataSet & 253493 \\
|
||
|
|
EPrints.Repository & 243699 \\
|
||
|
|
EPrints.Database & 189624 \\
|
||
|
|
EPrints.DataObj & 156391 \\
|
||
|
|
EPrints.MetaField.Id & 155978 \\
|
||
|
|
EPrints.Utils & 118036 \\
|
||
|
|
EPrints.XML & 107939 \\
|
||
|
|
EPrints.MetaField.Multilang & 45312 \\
|
||
|
|
EPrints.Script.Compiler & 39550
|
||
|
|
\end{tabular}
|
||
|
|
\caption{Die 10 aktivsten Pakete}
|
||
|
|
\label{tab:auswPack}
|
||
|
|
\end{table}
|
||
|
|
|
||
|
|
Diese Daten spiegeln erneut die Ergebnisse der bisherigen Auswertungen. Die Datenbankanbindung ist in EPrints das neunte Paket in der Liste, während es auf den vierten Platz in \gls{kielpr} vorrückt. Das wichtigste Paket in EPrints, \emph{EPrints.Script.Compiler}, rückt in \gls{kielpr} auf den 10. Platz. Auch ist hier zu beachten, dass kaum zusätzliche Funktionsaufrufe in diesem Paket auftreten. Erneut ist hier das Paket \emph{EPrints.MetaField.Id} vertreten, dass seit dem Update auf Version 3 nicht mehr verwendet werden sollte.
|
||
|
|
|
||
|
|
\section{Paketabhängigkeiten}\label{sec:auswPackDep}
|
||
|
|
Mit den gleichen Daten wie in \autoref{sec:auswPackCnt} wurden die Abhängigkeiten in \gls{kielpr} sowie in EPrints mit dem Grafiktool Gephi visualisiert. Hier wurde als Layout-Algorithmus die Einstellung Fruchtermann Reingold gewählt und der Graph anschließend mit Standardeinstellungen gerendert.
|
||
|
|
|
||
|
|
\begin{figure}
|
||
|
|
\centering
|
||
|
|
\includegraphics[width=\textwidth]{images/Dependency-Graph-EPrints}
|
||
|
|
\caption{Visualisierung der Abhängigkeiten in EPrints}
|
||
|
|
\label{fig:dependenEPrints}
|
||
|
|
\end{figure}
|
||
|
|
|
||
|
|
Der in \autoref{fig:dependenEPrints} hellgrün markierte Knoten stellt das Paket EPrints.Repository dar, der hellrot markierte Knoten das Paket EPrints.PluginFactory. Die jeweils direkt mit diesen Paketen benachbarten Knoten sind in der entsprechenden gedämpften Farbe markiert. Aufgrund der hohen Anzahl Knoten und der starken Vernetzung untereinander ist die Analyse hierbei allerdings nur schwierig möglich.
|
||
|
|
|
||
|
|
Werden in den Daten funktional ähnliche Pakete zusammengefasst, also zum Beispiel die verschiedenen \emph{EPrints.MetaField.*} Pakete oder die Pakete \emph{EPrints.Database.Pg} und \emph{EPrints.Database}, so zeigen sich die Abhängigkeiten deutlicher. Ein Versuch dieser Visualisierung ist in \autoref{fig:dependenEPrintsConden} dargestellt.
|
||
|
|
|
||
|
|
\begin{figure}
|
||
|
|
\centering
|
||
|
|
\includegraphics[width=\textwidth]{images/Condensed-Dependency-Graph}
|
||
|
|
\caption{Visualisierung der Abhängigkeiten in EPrints}
|
||
|
|
\label{fig:dependenEPrintsConden}
|
||
|
|
\end{figure}
|
||
|
|
|
||
|
|
Es ergeben sich nur geringe Unterschiede zwischen den Abhängigkeitsgraphen von EPrints und \gls{kielpr}. Allerdings zeigt sich hier, dass auch in EPrints Probleme in der Schichtenarchitektur bestehen, denn auch hier greift zum Beispiel das Paket \emph{EPrints.ScreenProcessor} direkt auf die Datenbank zu.
|