Śledzenie aplikacji ABL to nie jest temat nowy – po raz pierwszy zostało zaimplementowane w wersji 9, a więc jeszcze w starym 4GL.
Śledzenie to nie zostało niestety uwzględnione ani w szkoleniu z podstaw języka, ani ze strojenia aplikacji i może dlatego nie wszystkim deweloperom aplikacji OpenEdge jest znane.
W ostatnich tygodniach klienci zgłaszali mi dwa problemy, przy rozwiązaniu których ta technika okazała się pomocna i dlatego postanowiłem o niej napisać.
Chodzi w niej o zrzut określonych danych do własnego pliku log. Dane te mogą dotyczyć np. szczegółów transakcji, łączności z bazą danych, uruchamiania obiektów dynamicznych itd. Można określić także ilość zrzucanych informacji.

Śledzenie można włączyć na różne sposoby. Jeśli chcemy mieć kompletny zapis działania aplikacji (gdy np. nie wiemy gdzie jest wadliwy fragment kodu) możemy uruchomić sesję z określonymi parametrami np.
prowin -p plik.p -db baza -debugalert -clientlog mylog.txt -logginglevel 3 -logentrytypes 4GLTrace,DynObjects.*
Na uwagę zasługują tutaj następujące parametry:

-clientlog – nazwa naszego pliku log

-logginglevel – poziom zapisu, 3 oznacza Verbose i taką wartość będę tutaj stosował

-logentrytypes – typ zrzucanej informacji.

Przyjrzyjmy się wybranym wartościom trzeciego parametru.

• 4GLMessages – zapisuje komunikaty VIEW-AS ALERT-BOX – jeśli włączony jest Debug Alert (parametr -debugalert), to zapisywane są także informacje stosu ABL
• 4GLTrace – chyba najczęściej stosowany typ informacji, rejestruje wywołanie procedur, funkcji, trygerów, metod, konstruktorów, destruktorów, zdarzeń PUBLISH/SUBSTRIBE itp.
• 4GLTrans – rejestrowanie przetwarzanych transakcji i podtransakcji w procedurach ABL
• DB.Connects – rejestrowanie przyłączania/odłączania baz danych
• DynObjects.* – rejestrowanie tworzenia i usuwania dynamicznych obiektów różnego typu (* dla wszystkich)
• QryInfo – rejestrowanie zapytań (OPEN QUERY oraz FOR EACH)
• Temp-tables – rejestrowanie informacji o tabelach tymczasowych wykorzystywanych w aplikacji
• TTStats – rejestrowanie statystyk tabel tymczasowych

Niektóre z tych wybranych wartości można stosować jedynie w sesji klienta inne także w sesji serwera aplikacji. Po kompletny wykaz zapraszam do dokumentacji dla konkretnej wersji.

Jest jeszcze inny sposób na uruchomienie tego procesu, szczególnie przydatny jeśli chcemy badać tylko określony fragment aplikacji, co zdarza się chyba o wiele częściej.

Wykorzystuje się do tego obiekt LOG-MANAGER, co pokażę na poniższych przykładach.

/* trace1.p */
DEFINE BUTTON btnCust LABEL "Show Customer".
DEFINE BUTTON btnExit LABEL "Exit".

LOG-MANAGER:LOGFILE-NAME = 'mylogmanager.txt'.
LOG-MANAGER:LOGGING-LEVEL = 3.
LOG-MANAGER:LOG-ENTRY-TYPES = '4GLTrace,4GLMessages'.

PROCEDURE ShowCust:
  FIND FIRST customer.
  MESSAGE name
  VIEW-AS ALERT-BOX.
END PROCEDURE.

SUBSCRIBE TO "FindCustomer" IN THIS-PROCEDURE RUN-PROCEDURE "ShowCust".

FORM btnCust btnExit WITH FRAME x.
ENABLE ALL WITH FRAME x.

ON CHOOSE OF btnCust PUBLISH "FindCustomer".

WAIT-FOR CHOOSE OF btnExit.

LOG-MANAGER:CLOSE-LOG.

Pierwszy przykład. Dane są zrzucane do pliku mylogmanager.txt, poziom = 3, a typ informacji to 4GLTrace oraz 4GLMessages. Przykładowa aplikacja GUI składa się z okna, dwóch przycisków i wewnętrznej procedury. Jest też prosta implementacja PUBLISH/SUBSCRIBE. Uruchamiam procedurę, naciskam przycisk btnCust (pojawia się nazwa pierwszego klienta) i następnie btnExit.
Zobaczmy zawartość pliku mylogmanager.txt (dla większej czytelności usunąłem z każdej linii dane czasowe).

1 4GL -- Logging level set to = 2
1 4GL -- No entry types are activated
1 4GL -- Logging level set to = 3
1 4GL -- Log entry types activated: 4GLTrace,4GLMessages
2 4GL 4GLTRACE       SUBSCRIBE FindCustomer "C:\WrkOpenEdge128\workspace\ABLProj\trace1.p" C:\WrkOpenEdge128\workspace\ABLProj\trace1.p [Main Block - C:\WrkOpenEdge128\workspace\ABLProj\trace1.p @ 14]
2 4GL 4GLTRACE       PUBLISH FindCustomer [USER-INTERFACE-TRIGGER - C:\WrkOpenEdge128\workspace\ABLProj\trace1.p @ 19]
2 4GL 4GLTRACE       RUN ShowCust in C:\WrkOpenEdge128\workspace\ABLProj\trace1.p [USER-INTERFACE-TRIGGER - C:\WrkOpenEdge128\workspace\ABLProj\trace1.p @ 19]
2 4GL 4GLMESSAGE     Lift Tours
2 4GL 4GLMESSAGE     ** ABL Debug-Alert Stack Trace **
2 4GL 4GLMESSAGE     --> ShowCust C:\WrkOpenEdge128\workspace\ABLProj\trace1.p at line 10  (C:\WrkOpenEdge128\workspace\ABLProj\trace1.r)
2 4GL 4GLMESSAGE         USER-INTERFACE-TRIGGER C:\WrkOpenEdge128\workspace\ABLProj\trace1.p at line 19  (C:\WrkOpenEdge128\workspace\ABLProj\trace1.r)
2 4GL 4GLMESSAGE         C:\WrkOpenEdge128\workspace\ABLProj\trace1.p at line 21  (C:\WrkOpenEdge128\workspace\ABLProj\trace1.r)
3 4GL 4GLTRACE       Return from ShowCust [C:\WrkOpenEdge128\workspace\ABLProj\trace1.p]
3 4GL 4GLTRACE       Return from PUBLISH FindCustomer [C:\WrkOpenEdge128\workspace\ABLProj\trace1.p]
1 4GL ----------     Log file closed at user's request

Z lewej strony widzimy którego typu wpis w danej linii dotyczy. Można np. prześledzić mechanizm PUBLISH/SUBSCRIBE. Widać też jaka wartość została wyświetlona w komunikacie (“Lift Tours”). Ponieważ parametr sesji DEBUG-ALERT jest ustawiony na ‘yes’ to zostaje wyświetlona również informacja stosu ABL (szczególnie przydatna w przypadku wystąpienia błędów). Mamy także informacje o wywołaniu procedury i trygera.

Weźmy teraz inny przykład. Tym razem będą interesować nas transakcje i sub-transakcje, dlatego jako typ informacji dodajemy 4GLTrans.

/* trace2.p */
LOG-MANAGER:LOGFILE-NAME = 'mylogmanager.txt'.
LOG-MANAGER:LOGGING-LEVEL = 3.
LOG-MANAGER:LOG-ENTRY-TYPES = '4GLTrace,4GLTrans'.

CustLab:
REPEAT:
   FIND LAST customer.
   DO TRANSACTION:
      country = "USA". 
   END.    
   UPDATE NAME.
   IF NAME BEGINS "x" THEN UNDO, RETRY.
   ELSE LEAVE.
END.   

LOG-MANAGER:CLOSE-LOG.
QUIT.

Przykład składa się tylko z bloku REPEAT wewnątrz którego jest zdefiniowana transakcja, polegająca na edycji pola Name. Jeśli nazwa będzie zaczynać się na literę “x” transakcja ma być wycofana, w przeciwnym razie zatwierdzona. Wewnątrz bloku transakcyjnego zdefiniowano sub-transakcję, w której ustawiany jest kraj “USA”.
Przetestuję procedurę wstawiając najpierw dwa razy nazwę zaczynającą się od “x”, a następnie od innej, poprawnej litery. Pierwsza i druga transakcja powinna zatem zostać wycofana, a trzecia zatwierdzona.

1 4GL -- Logging level set to = 2
1 4GL -- No entry types are activated
1 4GL -- Logging level set to = 3
1 4GL -- Log entry types activated: 4GLTrace,4GLTrans
3 4GL 4GLTRANS       BEGIN TRANS 28 [C:\WrkOpenEdge128\workspace\ABLProj\trace2.p @ 7]
3 4GL 4GLTRANS       BEGIN SUB-TRANS 29 [C:\WrkOpenEdge128\workspace\ABLProj\trace2.p @ 9]
3 4GL 4GLTRANS       END SUB-TRANS 29 [C:\WrkOpenEdge128\workspace\ABLProj\trace2.p @ 11]
3 4GL 4GLTRANS       UNDO TRANS 28 [C:\WrkOpenEdge128\workspace\ABLProj\trace2.p @ 15]
3 4GL 4GLTRANS       BEGIN TRANS 31 [C:\WrkOpenEdge128\workspace\ABLProj\trace2.p @ 15]
3 4GL 4GLTRANS       BEGIN SUB-TRANS 32 [C:\WrkOpenEdge128\workspace\ABLProj\trace2.p @ 9]
3 4GL 4GLTRANS       END SUB-TRANS 32 [C:\WrkOpenEdge128\workspace\ABLProj\trace2.p @ 11]
3 4GL 4GLTRANS       UNDO TRANS 31 [C:\WrkOpenEdge128\workspace\ABLProj\trace2.p @ 15]
3 4GL 4GLTRANS       BEGIN TRANS 34 [C:\WrkOpenEdge128\workspace\ABLProj\trace2.p @ 15]
3 4GL 4GLTRANS       BEGIN SUB-TRANS 35 [C:\WrkOpenEdge128\workspace\ABLProj\trace2.p @ 9]
3 4GL 4GLTRANS       END SUB-TRANS 35 [C:\WrkOpenEdge128\workspace\ABLProj\trace2.p @ 11]
3 4GL 4GLTRANS       END TRANS 34 [C:\WrkOpenEdge128\workspace\ABLProj\trace2.p @ 15]
1 4GL ----------     Log file closed at user's request

Sprawdzamy zapisy w pliku mylogmanager.txt. Widać, że pierwsze dwie transakcje (o numerach 28 i 31) zostały wycofane razem z sub-transakcjami (odpowiednio 29 i 32). Trzecia transakcja (nr 34) i sub-transakcja (nr 35) nie zostały wycofane, a więc są zatwierdzone.
Jak widać jest to bardzo użyteczne narzędzie do badania transakcji podczas runtime’u.
Dodam jeszcze, że numery transakcji maja tutaj wartości nadawane lokalnie dla odczytu pliku log i nie mają nic wspólnego z rzeczywistym id transakcji, które można podejrzeć np. w promonie: R&D ->Status Displays -> Processes/Clients… -> 3. Active Transactions