Logování Web API

Běh ABRA API je možné logovat. A to jednak jeho Java část pomocí konfiguračního souboru APIServer.yaml, který je v kořenovém adresáři instalace systému ABRA Gen, a pak dále na úrovni business logiky pomocí souboru NEXUS.CFG.

Součástí obou logů je tzv rid, generované pomocí hlavičky X-Request-ID, které umožňuje snadno identifikovat jak serverovou, tak BO část požadavku v obou takto vytvořených lozích.

Obecná konfigurace nastavení logování systému ABRA Gen viz kap. Logování běhu aplikace.

Doporučená konfigurace nastavení logování na úrovni v souboru NEXUS.CFG je následující: 

[Logs]
LogsDirectory=<lokální cesta, ideálně SSD>
Level=3

[Log.ExceptionHook]
Enabled=1
Level=6
ExcludedExceptionClasses=EAbort;NxHiddenError;EIdSocketError;EIdConnectTimeout;EIdNotASocket
ExcludedNxErrorCodes=

[Log.SysLog]
Enabled=1
Level=6

[Log.ProfilingSQL]
Enabled=0
Level=6
Threshold=1000
SQLOutputLength=0

[Log.WAProfilingRequest]
Enabled=1
Level=6
SQLText=1
SQLPlan=1

[Log.WASecurity]
Enabled=1
Level=6

[Log.WAMemory]
Enabled=0
Level=6

[Log.WAPool]
Enabled=0
Level=6

[Log.WASession]
Enabled=0
Level=6

Log ExceptionHook slouží k logování výjimek, je jediný který stojí za to mít zapnutý pořád. Ostatní logy je z důvodu výkonu a rychle rostoucí velikosti souboru s logy mít během provozu vypnuté a zapnout je dle příkladu až při potřebě.

Log SysLog loguje informace ze startu aplikace (tj. s jakými parametry byl program spuštěný, nastavení některých interních proměnný a pod.).

Log Profilingsql na aplikačním serveru loguje SQL dotazy, které překročí nastavený čas. Použitím tohoto logu se dá zjistit, jestli za případnou pomalostí API dotazů nestojí databáze. Threshold je čas v ms, při jehož překročení se dotaz zaloguje. SQLOutputLength je délka SQL dotazu, která se zaloguje, 0 znamená celý dotaz.

Log WAProfilingRequest je nejdůležitější. Je v něm zahrnut buď obsah požadavku i odpověď (Level=6) nebo jen základní informace bez těla požadavku a odpovědi (Level=5). V případě, že provádění požadavku zamrzne, loguje se zde callstack threadu, který požadavek provádí a může napovědět, kde je problém. Od verze 24.1 je log WAProfilingRequest upraven tak, že logování SQL generovaného API se provádí zapnutím přepínače SQLText a nově je možné zalogovat i SQL plán pomocí SQLPlan. SQL plán se nebere přímo z prováděného dotazu, ale požádá se o něj databázový engine v separátním dotazu (implementování na základě informace z AbraBI). Při ladění problémů s rychlostí SQL je doporučeno logování zapnout a vyhodnotit, viz příklady níže.

Log WASecurity umožňuje zjistit, které chráněné objekty byly použity pro získání dat požadavku a tudíž se hodí použít pro řešení problému s právy k objektům.

Příklad volání metody GET pro doklad faktury vydané: GET http://localhost/develop/issuedinvoices, uživatel nemá správně nastavena práva ke chráněným objektům

26.03.2025 11:57:42.847 [5] 00005CF0 (WAProfilingRequest) Request start(rid:API_b144e5342e5d46fe9049cb1494728cb2): GET http://localhost/develop/issuedinvoices
  
  X-Request-ID=API_b144e5342e5d46fe9049cb1494728cb2
  User-Agent=PostmanRuntime/7.43.2
  Host=localhost
  Connection=keep-alive
  Accept=*/*
  Accept-Encoding=gzip, deflate, br
  Postman-Token=20da25f8-eaa4-40ea-b696-f7150f496ce7
  
  
  
26.03.2025 11:57:42.875 [5] 00005CF0 (WASecurity) Add security condition: Field IssuedInvoices.DocQueue_ID(Zdrojová řada)
  Allowed IDs: 5600000101,
  
26.03.2025 11:57:42.877 [5] 00005CF0 (WASecurity) Add security condition: Field IssuedInvoices.AccDocQueue_ID(Účetní řada)
  Allowed IDs: No ID is allowed !!!
  
26.03.2025 11:57:42.879 [5] 00005CF0 (WASecurity) Add security condition: Field IssuedInvoices.BankAccount_ID(Vlastní účet)
  Allowed IDs: 2200000101,
  
26.03.2025 11:57:42.881 [5] 00005CF0 (WASecurity) Add security condition: Field Rows.Division_ID(Středisko)
  Allowed IDs: 2100000101,1200000101,2200000101,1300000101,1400000101,2400000101,3400000101,
  
26.03.2025 11:57:42.884 [5] 00005CF0 (WASecurity) Add security condition: Field Rows.Store_ID(Sklad)
  Allowed IDs: 2100000101,1500000101,2500000101,3500000101,
  
26.03.2025 11:57:42.886 [6] 00005CF0 (WAProfilingRequest) 
  Start read sql - InputParams: @{SelDocQueue_ID1Frag}=('5600000101');@{SelBankAccount_ID3Frag}=('2200000101');@{SelRowsDivision_ID4Frag}=('1300000101','1400000101','3400000101','2400000101','2200000101','1200000101','2100000101');@{SelRowsStore_ID5Frag}=('1500000101','2500000101','3500000101','2100000101');@{$IndexAndWhere}=;
  select T_1.AccDocQueue_ID as F_1$REFERENCE, T_1.AccPresetDef_ID as F_2$REFERENCE, T_1.Address_ID as F_3$REFERENCE, T_1.BankAccount_ID as F_4$REFERENCE, T_1.ClosingPeriod_ID as F_5$REFERENCE, T_1.ConstSymbol_ID as F_6$REFERENCE, T_1.CorrectedBy_ID as F_7$REFERENCE, T_1.Country_ID as F_8$REFERENCE, T_1.CreatedBy_ID as F_9$REFERENCE, T_1.Currency_ID as F_10$REFERENCE, T_1.DealerCategory_ID as F_11$REFERENCE, T_1.DeliveryAddress_ID as F_12$REFERENCE, T_1.DeliveryFirm_ID as F_13$REFERENCE, T_1.DeliveryFirmOffice_ID as F_14$REFERENCE, T_1.DeliveryTerms_ID as F_15$REFERENCE, T_1.DocQueue_ID as F_16$REFERENCE, T_1.Firm_ID as F_17$REFERENCE, T_1.FirmOffice_ID as F_18$REFERENCE, T_1.ID as ID, T_1.IEState_ID as F_19$REFERENCE, T_1.IntrastatDeliveryTerm_ID as F_20$REFERENCE, T_1.IntrastatTransactionType_ID as F_21$REFERENCE, T_1.IntrastatTransportationType_ID as F_22$REFERENCE, T_1.LastPaymentPeriod_ID as F_23$REFERENCE, T_1.LocalZone_ID as F_24$REFERENCE, T_1.ObjVersion as ObjVersion, T_1.PaymentType_ID as F_25$REFERENCE, T_1.Period_ID as F_26$REFERENCE, T_1.Person_ID as F_27$REFERENCE, T_1.PostAddress_ID as F_28$REFERENCE, T_1.PostFirm_ID as F_29$REFERENCE, T_1.PostFirmOffice_ID as F_30$REFERENCE, T_1.TransportationType_ID as F_31$REFERENCE, T_1.VATCountry_ID as F_32$REFERENCE, T_1.Zone_ID as F_33$REFERENCE
  from IssuedInvoices T_1
  where ((T_1.DocQueue_ID IN {SelDocQueue_ID1Frag})) and (((T_1.AccDocQueue_ID IS NULL) OR (T_1.AccDocQueue_ID = '0000000000') OR (T_1.AccDocQueue_ID = ' '))) and ((T_1.BankAccount_ID IN {SelBankAccount_ID3Frag})) and ((EXISTS(SELECT 1 FROM IssuedInvoices2 T_2 WHERE  T_2.Parent_ID =T_1.ID AND ((Division_ID IS NULL) OR (Division_ID = '0000000000') OR (Division_ID = ' ') OR (Division_ID IN {SelRowsDivision_ID4Frag})) AND ((Store_ID IS NULL) OR (Store_ID = '0000000000') OR (Store_ID = ' ') OR (Store_ID IN {SelRowsStore_ID5Frag}))) OR Not EXISTS(SELECT 1 FROM IssuedInvoices2 T_2 WHERE  T_2.Parent_ID =T_1.ID)))
  
26.03.2025 11:57:42.892 [6] 00005CF0 (WAProfilingRequest) Stop read sql duration: 16 ms
26.03.2025 11:57:42.893 [5] 00005CF0 (WAProfilingRequest) Request stop(rid:API_b144e5342e5d46fe9049cb1494728cb2): status 200  time: 0 ms
  
  Link=http://localhost:80/develop/api-docs/swagger.json#; rel="describedBy"
  Content-Type=application/json
  Access-Control-Allow-Credentials=true
  Access-Control-Allow-Origin=*
  Access-Control-Allow-Headers=Origin, X-Requested-With, Content-Type, Accept, Authorization, Cache-Control
  Access-Control-Allow-Methods=GET,PUT,POST,DELETE
  
  []

Logy WAPool, WAMemory a WASession jsou nízkoúrovňové a jejich zapnutí má smysl jen při řešení specifických problémů.

Od verze 24.1 je Log.WA/RESTApplication/ProfilingRequest upraven tak, že logování SQL generovaného api se provádí zapnutím přepínače SQLText a nově je možné zalogovat i SQL plán pomocí SQLPlan. SQL plán se nebere přímo z prováděného dotazu, ale požádá se o něj databázový engine v separátním dotazu (implementování na základě informace z AbraBI). Při ladění problémů s rychlostí SQL je doporučeno logování zapnout a vyhodnotit

[Log.WA/RESTApplication/ProfilingRequest]
Enabled=1
Level=6
SQLText=1
SQLPlan=1
Start read sql - InputParams: @{SelDivision_IDFrag}=('1300000101','1400000101','3400000101','2400000101','2200000101','1200000101','2100000101');@{SelStore_IDFrag}=('1300000101','2600000101','3400000101','1600000101','3200000101','4400000101','1500000101','2500000101','3500000101','2300000101','3300000101','2100000101');@{$IndexAndWhere}=;
				select T_1.StoreCard_ID as F_1$REFERENCE, T_1.Store_ID as F_2$REFERENCE, sum(T_1.Quantity) as F_3, sum(T_1.DeliveredQuantity) as F_4, T_1.StoreCard_ID as F_5, T_1.Store_ID as F_6
				from ReceivedOrders2 T_1
				left join ReceivedOrders T_2 on T_2.ID = T_1.Parent_ID
				where (T_1.Store_ID in ('2100000101', '2200000101') and T_1.RowType = 3 and T_2.Confirmed = 'A' and T_2.Closed = 'N' and T_1.Quantity > T_1.DeliveredQuantity) and (((T_1.Division_ID IS NULL) OR (T_1.Division_ID = '0000000000') OR (T_1.Division_ID = ' ') OR (T_1.Division_ID IN {SelDivision_IDFrag}))) and (((T_1.Store_ID IS NULL) OR (T_1.Store_ID = '0000000000') OR (T_1.Store_ID = ' ') OR (T_1.Store_ID IN {SelStore_IDFrag})))
				group by F_5, F_6
  
		SQL plan: PLAN JOIN (T_1 ORDER RECEIVEDORDERS2_SCARD INDEX (RECEIVEDORDERS2STOREFK, RECEIVEDORDERS2STOREFK), T_2 INDEX (RECEIVEDORDERSPK))