ABAP Tipp - Logging Performance
Wie sieht es eigentlich mit der Performance des BAL Logs in der ABAP Cloud Welt aus? Schauen wir uns dazu drei Lösungen an und messen die Performance in verschiedenen Szenarien.
Inhaltsverzeichnis
In diesem Artikel messen wir die Performance der aktuellen ABAP Cloud Logging Klassen und schauen uns an, welche Klasse sich für welche Szenarien lohnt. Der Artikel wurde inspiriert von einem Kommentar unter dem XCO Logging Artikel.
Einleitung
Ein paar Artikel zurück hatten wir uns die XCO Logging Klasse angeschaut und mit den bestehenden Klasse verglichen. Doch wie sieht es eigentlich bei der Nutzung der Klassen mit der Performance aus und welche Auswirkungen hat das auf unseren Betrieb von Anwendungen? Dazu schauen wir uns verschiedene Szenarien an und vergleichen diese am Ende des Artikels.
Szenario
In unserem Testszenario wollen wir uns die ABAP Cloud Klassen CL_BALI_LOG und XCO_CP_BAL anschauen. Zusätzlich messen wir auch das Verhalten für das Open Source Projekt ABAP Message Logger, welches mehr Fokus auf die Nachrichtenverarbeitung hat. Grundsätzlich basiert das Projekt auch auf der Klasse CL_BALI_LOG, verschalt die Logik noch einmal zusätzlich. Die folgenden Testfälle wollen wir uns anschauen:
- Ohne Speicherung (wenig) - Übernahme von 500 Meldungen ins Objekt
- Ohne Speicherung (viel) - Übernahme von 5000 Meldungen ins Objekt
- Speicherung (wenig) - Übernahme von 500 Meldungen ins Objekt und Speicherung des Application Logs
- Speicherung (viel) - Übernahme von 5000 Meldungen ins Objekt und Speicherung des Application Logs
- Zweite Verbindung (wenig) - Wir nutzen die zweite Datenbankverbindung zum Speichern und arbeiten mit 500 Meldungen
- Zweite Verbindung (viel) - Wir nutzen die zweite Datenbankverbindung zum Speichern und arbeiten mit 5000 Meldungen
Aufbau
Für den Testaufbau erstellen wir uns einige Methoden, die die verschiedenen Objekte für uns erzeugen und verwalten sollen. Zuerst einmal teilen wir die verschiedenen Logs auf Szenarien auf, die wir nacheinander ausführen:
- CL_BALI_LOG
- XCO_CP_BAL
- ABAP Message Logger (AML)
Start
Über die verschiedenen Hilfsmethoden verarbeiten wir die Daten, erstellen Logs und Speichern die Meldungen. Über die Methode START_SCENARIO starten wir später alle Tests. Dabei definieren wir die Art des Szenarios, die Nummer an Meldungen, die wir verwalten wollen, ob das Log gesichert werden soll und ob dazu eine zweite Datenbankverbindung genutzt wird.
METHODS start_scenario
IMPORTING scenario TYPE i
number_of_messages TYPE i
!save TYPE abap_boolean
db_connection TYPE abap_boolean.
Log erzeugen
Das Log erzeugen wir dann auf die verschiedenen vorgegebenen Weisen der Frameworks. Beim BALI erzeugen wir den Header und übergeben ihn dem Log Objekt. Bei der XCO Klasse müssen wir nur die Create Methode aufrufen und bei AML nutzen wir die Factory mit den Einstellungen. Für alle drei Szenarien verwenden wir eine UUID als externe ID.
METHOD create_log.
DATA(external_id) = CONV cl_bali_header_setter=>ty_external_id( xco_cp=>uuid( )->as( xco_cp_uuid=>format->c32 )->value ).
CASE scenario.
WHEN 1.
bali_log = cl_bali_log=>create( ).
bali_log->set_header( cl_bali_header_setter=>create( object = 'Z_AML_LOG'
subobject = 'TEST'
external_id = external_id ) ).
WHEN 2.
xco_log = xco_cp_bal=>for->database(
)->log->create( iv_object = 'Z_AML_LOG'
iv_subobject = 'TEST'
iv_external_id = external_id ).
WHEN 3.
aml_log = zcl_aml_log_factory=>create( VALUE #( object = 'Z_AML_LOG'
subobject = 'TEST'
external_id = external_id
use_2nd_db_connection = db_connection ) ).
ENDCASE.
ENDMETHOD.
Meldung übernehmen
Als Meldung erzeugen wir eine Nachricht über die Systemvariablen und übernehmen die Meldung so in die Klassen. Wir haben uns für diese Form entschieden, da alle Klassen sie gut unterstützen.
METHOD add_message.
CASE scenario.
WHEN 1.
bali_log->add_item( cl_bali_message_setter=>create_from_sy( ) ).
WHEN 2.
xco_log->add_message( xco_cp=>sy->message( )->value ).
WHEN 3.
aml_log->add_message_system( ).
ENDCASE.
ENDMETHOD.
Log speichern
Das Speichern der Logs fällt hier unterschiedlich aus. Bei BALI benötigen wir ein zusätzliches Objekt, um das Log zu speichern, XCO speichert die Meldungen sofort und bei AML müssen wir nur SAVE aufrufen, da die restliche Logik intern abstrahiert ist.
METHOD save_log.
CASE scenario.
WHEN 1.
cl_bali_log_db=>get_instance( )->save_log( log = bali_log
use_2nd_db_connection = db_connection ).
WHEN 2.
" Nothing to do
WHEN 3.
aml_log->save( ).
ENDCASE.
ENDMETHOD.
Testlauf
Führen wir im ersten Schritt einmal die Logik jeweils einmal durch. Dazu können wir die Konstante TIMES_TO_EXECUTE auf eins setzen und die Klasse starten. Dabei erhalten wir eine erste Indikation, wie die Laufzeiten der verschiedenen Komponenten sind.
Nach dem ersten Lauf mit jeweils einer Durchführung wird klar, dass die Architektur der XCO Klasse nicht für den Massentest gedacht ist. Die Laufzeit skaliert mit der Anzahl der Meldungen und beeinflusst die Gesamtlaufzeit negativ. Daher erhöhen wir im zweiten Lauf die Ausführungen auf 25, schließen aber die XCO Klasse aus. Das Ergebnis erhalten wir dieses Mal schneller und sehen bereits erste Unterschiede.
Vergleich
Anhand der Ergebnisse können wir nun die folgenden Aussagen zu den unterschiedlichen Klassen und Frameworks treffen:
- XCO_CP_BAL - Ist die langsamste Klasse und bietet kaum Einstellungen für die Aufnahme und Speicherung von Meldungen. Je mehr Meldungen gespeichert werden müssen, desto langsamer wird die Klasse.
- Logging - Beim reinen Logging ohne Speicherung der Meldungen ist AML schneller als CL_BALI_LOG, da nicht die BAL Funktionsbausteine verwendet werden, sondern die Daten intern verwaltet werden. Willst du die Meldungen gar nicht persistieren oder nur im Notfall, bietet sich ein eigenes Logging an.
- Speicherung - Beim Speichern ist CL_BALI_LOG etwas schneller, da die interne Verwaltung und Aufbereitung bei AML etwas Performance verbraucht.
- Direkt oder zweite Verbindung - Die zweite Datenbankverbindung bringt keine Performanceverbesserung. Es wird weiterhin auf das Speichern gewartet. Allerdings wird in der aktuellen Session kein Commit ausgelöst und selbst beim Rollback werden die Meldungen geschrieben.
XCO_CP_BAL ist im Test zwar sehr langsam, allerdings schreibt die Klasse die Meldungen fortlaufend ins Log. Bei einem Dump sind alle Meldungen bis zu diesem Zeitpunkt im Log verfügbar. Bei den anderen Lösungen wird kein Log geschrieben. Allerdings wurde die Funktion des "Emergency Loggings" mittlerweile auch in AML als Option implementiert, der charmante Vorteil eines Open Source Projekts.
Vollständiges Beispiel
Hier findest du das komplette Beispiel aus dem Artikel. Um die Klasse auszuführen, benötigst du allerdings eine Hilfsklasse zur Laufzeitmessung und die Open Source Komponente. Hier das gezeigte Beispiel:
CLASS zcl_bs_demo_performance_log DEFINITION
PUBLIC FINAL
CREATE PUBLIC.
PUBLIC SECTION.
INTERFACES if_oo_adt_classrun.
PRIVATE SECTION.
CONSTANTS times_to_execute TYPE i VALUE 1.
CONSTANTS messages_small TYPE i VALUE 500.
CONSTANTS messages_big TYPE i VALUE 5000.
DATA bali_log TYPE REF TO if_bali_log.
DATA xco_log TYPE REF TO if_xco_cp_bal_log.
DATA aml_log TYPE REF TO zif_aml_log.
METHODS create_log
IMPORTING scenario TYPE i
db_connection TYPE abap_boolean.
METHODS add_message
IMPORTING scenario TYPE i.
METHODS save_log
IMPORTING scenario TYPE i
db_connection TYPE abap_boolean.
METHODS start_scenario
IMPORTING scenario TYPE i
number_of_messages TYPE i
!save TYPE abap_boolean
db_connection TYPE abap_boolean.
ENDCLASS.
CLASS zcl_bs_demo_performance_log IMPLEMENTATION.
METHOD if_oo_adt_classrun~main.
DO 3 TIMES.
DATA(scenario) = sy-index.
* IF scenario = 2.
* CONTINUE.
* ENDIF.
DATA(lo_run) = NEW zcl_bs_demo_runtime( ).
DO times_to_execute TIMES.
start_scenario( scenario = scenario
number_of_messages = messages_small
save = abap_false
db_connection = abap_false ).
ENDDO.
out->write( |Small message { scenario } : { lo_run->get_diff( ) }| ).
lo_run = NEW zcl_bs_demo_runtime( ).
DO times_to_execute TIMES.
start_scenario( scenario = scenario
number_of_messages = messages_big
save = abap_false
db_connection = abap_false ).
ENDDO.
out->write( |Big message { scenario } : { lo_run->get_diff( ) }| ).
lo_run = NEW zcl_bs_demo_runtime( ).
DO times_to_execute TIMES.
start_scenario( scenario = scenario
number_of_messages = messages_small
save = abap_true
db_connection = abap_false ).
ENDDO.
out->write( |Small save { scenario } : { lo_run->get_diff( ) }| ).
lo_run = NEW zcl_bs_demo_runtime( ).
DO times_to_execute TIMES.
start_scenario( scenario = scenario
number_of_messages = messages_big
save = abap_true
db_connection = abap_false ).
ENDDO.
out->write( |Big save { scenario } : { lo_run->get_diff( ) }| ).
lo_run = NEW zcl_bs_demo_runtime( ).
DO times_to_execute TIMES.
start_scenario( scenario = scenario
number_of_messages = messages_small
save = abap_true
db_connection = abap_true ).
ENDDO.
out->write( |Small 2nd { scenario } : { lo_run->get_diff( ) }| ).
lo_run = NEW zcl_bs_demo_runtime( ).
DO times_to_execute TIMES.
start_scenario( scenario = scenario
number_of_messages = messages_big
save = abap_true
db_connection = abap_true ).
ENDDO.
out->write( |Big 2nd { scenario } : { lo_run->get_diff( ) }| ).
ENDDO.
ENDMETHOD.
METHOD start_scenario.
create_log( scenario = scenario
db_connection = db_connection ).
DO number_of_messages TIMES.
MESSAGE s001(zbs_demo_xco) WITH 'Test' sy-index INTO DATA(message) ##NEEDED.
add_message( scenario ).
ENDDO.
IF save = abap_true.
save_log( scenario = scenario
db_connection = db_connection ).
ENDIF.
ENDMETHOD.
METHOD create_log.
DATA(external_id) = CONV cl_bali_header_setter=>ty_external_id( xco_cp=>uuid( )->as( xco_cp_uuid=>format->c32 )->value ).
CASE scenario.
WHEN 1.
IF bali_log IS NOT INITIAL.
bali_log->release_memory( ).
ENDIF.
bali_log = cl_bali_log=>create( ).
bali_log->set_header( cl_bali_header_setter=>create( object = 'Z_AML_LOG'
subobject = 'TEST'
external_id = external_id ) ).
WHEN 2.
xco_log = xco_cp_bal=>for->database(
)->log->create( iv_object = 'Z_AML_LOG'
iv_subobject = 'TEST'
iv_external_id = external_id ).
WHEN 3.
aml_log = zcl_aml_log_factory=>create( VALUE #( object = 'Z_AML_LOG'
subobject = 'TEST'
external_id = external_id
use_2nd_db_connection = db_connection ) ).
ENDCASE.
ENDMETHOD.
METHOD add_message.
CASE scenario.
WHEN 1.
bali_log->add_item( cl_bali_message_setter=>create_from_sy( ) ).
WHEN 2.
xco_log->add_message( xco_cp=>sy->message( )->value ).
WHEN 3.
aml_log->add_message_system( ).
ENDCASE.
ENDMETHOD.
METHOD save_log.
CASE scenario.
WHEN 1.
cl_bali_log_db=>get_instance( )->save_log( log = bali_log
use_2nd_db_connection = db_connection ).
WHEN 2.
" Nothing to do
WHEN 3.
aml_log->save( ).
ENDCASE.
ENDMETHOD.
ENDCLASS.
Fazit
Die Laufzeit der XCO Klasse war sehr auffällig und unerwartet. Daher wurde im Laufe des Tests die Klasse ausgeschlossen, die aber trotzdem gewisse Vorteile mit sich bringt. Du solltest dir also immer Gedanken bei der Implementierung machen, welches Ziel du mit dem Logging hast.
