May 17, 2026, 11:40 PM
This commit is contained in:
Paweł Domański
@@ -0,0 +1,251 @@
|
||||
|
||||
Problem:
|
||||
INC0794075 - XMBILLING process is very slow in recent days
|
||||
|
||||
Dostałem od Użytkownika informację że zapisy do danych nie działają optymalnie jest bardzo mała przepustowość i kolejka zaległości rośnie.
|
||||
Informacje zawarte w INC
|
||||
|
||||
While reviewing the dashboard
|
||||
https://app.eu0.signalfx.com/#/dashboard/HCvOOb9AIAM?groupId=HAX-r3yAIAU&configId=HCvOOb9AIAQ&density=2&startTime=-12h&endTime=Now
|
||||
I noticed that the xmlbilling process, which transfers data from
|
||||
10.146.11.194 (XMLBILLING database) to
|
||||
10.146.11.103 (AboSystem_CH and AboSystem_DNB databases), is performing very slowly.
|
||||
Its current peak processing speed is approximately 30 times lower than the average expected speed.
|
||||
Could you please investigate this issue from the database side?
|
||||
|
||||
Niestety obciążenie bazy danych i sesji nie wskazywało na problem bezpośrednio z tym że coś na instancji nie są poprawnie ustawione, system utylizował zaledwie 40% swojej mocy, a sesji w bazie było zaledwie kilkadziesiąt, batch requestów było na poziomie 80 max.
|
||||
|
||||
[[r01.png]]
|
||||
|
||||
W trakcie analizy nie zidentyfikowałem żadnej sesji która wy próbowała wstawić dane do bazy. Zdiagnozowałem jednak że aplikacja uruchamia to zapytanie
|
||||
|
||||
select ol1_0.TransactionNo,ol1_0.AccessType,
|
||||
ol1_0.Amount,ol1_0.AmountIncludingVAT,ol1_0.BID,
|
||||
ol1_0.BillToCustomerNo,ol1_0.BookingDate,ol1_0.CampaignNo,
|
||||
ol1_0.Description,ol1_0.GlobalUsageID,ol1_0.LineDiscount,
|
||||
ol1_0.LineDiscountAmount,ol1_0.MasterSubscriptionNo,
|
||||
ol1_0.OrderDate,ol1_0.OrderLineNo,ol1_0.OrderNo,
|
||||
ol1_0.PricelistCode,ol1_0.ProductCode,
|
||||
ol1_0.Quantity,ol1_0.QuantityInvoiced,ol1_0.QuantityShipped,
|
||||
ol1_0.QuantityShippedNotInvoiced,
|
||||
ol1_0.QuantityToInvoice,
|
||||
ol1_0.QuantityToShip,
|
||||
ol1_0.SellToCustomerNo,
|
||||
ol1_0.ShipToCustomerNo,
|
||||
ol1_0.ShipmentDate,
|
||||
ol1_0.ShipmentNo,
|
||||
ol1_0.ShippedNotInvoiced,ol1_0.SubjectCity,
|
||||
ol1_0.SubjectCountryCode,ol1_0.SubjectName,
|
||||
ol1_0.SubjectNo,ol1_0.SubjectSupplierCountryCode,
|
||||
ol1_0.SubjectUserId,ol1_0.SubscriptionNo,
|
||||
ol1_0.UnitCost,ol1_0.UnitOfMeasure,ol1_0.UnitPrice,ol1_0.VAT
|
||||
from XML_SubscriptionOrderLine ol1_0 -- where ol1_0.OrderLineNo= @P0
|
||||
|
||||
|
||||
Po analizie kodu aplikacji aplkikacja zanim wstawi dane musi pobrać dane które wykonuje wczesniej opisane zapytanie co dawało wiele wait typu PAGEOLATCH jak wskazałem na screenach poniżej
|
||||
|
||||
[[r02.png]]
|
||||
|
||||
[[r03.png]]
|
||||
|
||||
Wskazuje to jednoznacznie że zapytanie działa nieoptymalnie. Plan zapytania zanim wstawi dane musi zeskanować ponad 200 mln recordów co pokazuje poniższy rysunek
|
||||
|
||||
[[r04.png]]
|
||||
|
||||
Jednoznacznie brakuje na tej tabeli indeksu który jest poniżej.
|
||||
|
||||
USE [AboSystem_xx]
|
||||
GO
|
||||
CREATE NONCLUSTERED INDEX [idx_tmp_XML_SubscriptionOrderLine]
|
||||
ON [dbo].[XML_SubscriptionOrderLine] ([OrderLineNo])
|
||||
|
||||
GO
|
||||
|
||||
Po symulacji i sprawdzeniu założyłem indeks na koluminie OrderLineNo. Po tym zabiegu zapytanie bezpośrednio sięga do rekordu w bazie i koszt zapytania spadł drastycznie co pokazuje plan poniżej.
|
||||
|
||||
[[r05.png]]
|
||||
|
||||
Po uruchomieniu aplikacji całość przyśpieszyła o kilka tysięcy procent co pokazuje poniższy rysunek
|
||||
|
||||
|
||||
[[r06.png]]]]
|
||||
|
||||
Kolejka wszystkich zapytań skończyła się do 19:00 zamiast po 4 dniach.
|
||||
|
||||
|
||||
ENG RCA
|
||||
|
||||
Poniżej masz **przeredagowaną, spójną i profesjonalną wersję w języku angielskim**, gotową do użycia w **INC / RCA / mailu technicznym**. Zachowałem sens techniczny, ale poprawiłem styl i klarowność.
|
||||
|
||||
***
|
||||
|
||||
### Incident Description and Root Cause Analysis
|
||||
|
||||
I received information from the user that **data write operations were not performing optimally**. The system throughput was very low, and the backlog queue was continuously increasing.
|
||||
|
||||
The details were described in the incident (INC).
|
||||
|
||||
***
|
||||
|
||||
### Initial Observations
|
||||
|
||||
While reviewing the monitoring dashboard:
|
||||
<https://app.eu0.signalfx.com/#/dashboard/HCvOOb9AIAM?groupId=HAX-r3yAIAU&configId=HCvOOb9AIAQ&density=2&startTime=-12h&endTime=Now>
|
||||
|
||||
I noticed that the **xmlbilling process**, responsible for transferring data from:
|
||||
|
||||
* **10.146.11.194** (XMLBILLING database)
|
||||
to
|
||||
* **10.146.11.103** (AboSystem\_CH and AboSystem\_DNB databases),
|
||||
|
||||
was performing **significantly slower than expected**.
|
||||
|
||||
The current peak processing speed was approximately **30 times lower than the normal average throughput**.
|
||||
As a result, I was asked to investigate the issue from the **database perspective**.
|
||||
|
||||
***
|
||||
|
||||
### Database Health Check
|
||||
|
||||
Unfortunately, the database instance itself did **not indicate any direct configuration or resource issues**:
|
||||
|
||||
* CPU utilization was only around **40%**
|
||||
* The number of active database sessions was relatively low (only several dozen)
|
||||
* Batch requests peaked at approximately **80**
|
||||
|
||||
This indicated that the instance was **far from resource saturation** and the problem was unlikely to be caused by general database load.
|
||||
|
||||
\[\[r01.png]]
|
||||
|
||||
***
|
||||
|
||||
### Query-Level Analysis
|
||||
|
||||
During the analysis, I did **not identify any active sessions inserting data into the target database**.
|
||||
|
||||
However, I discovered that the application was repeatedly executing the following SQL query:
|
||||
|
||||
```sql
|
||||
SELECT
|
||||
ol1_0.TransactionNo,
|
||||
ol1_0.AccessType,
|
||||
ol1_0.Amount,
|
||||
ol1_0.AmountIncludingVAT,
|
||||
ol1_0.BID,
|
||||
ol1_0.BillToCustomerNo,
|
||||
ol1_0.BookingDate,
|
||||
ol1_0.CampaignNo,
|
||||
ol1_0.Description,
|
||||
ol1_0.GlobalUsageID,
|
||||
ol1_0.LineDiscount,
|
||||
ol1_0.LineDiscountAmount,
|
||||
ol1_0.MasterSubscriptionNo,
|
||||
ol1_0.OrderDate,
|
||||
ol1_0.OrderLineNo,
|
||||
ol1_0.OrderNo,
|
||||
ol1_0.PricelistCode,
|
||||
ol1_0.ProductCode,
|
||||
ol1_0.Quantity,
|
||||
ol1_0.QuantityInvoiced,
|
||||
ol1_0.QuantityShipped,
|
||||
ol1_0.QuantityShippedNotInvoiced,
|
||||
ol1_0.QuantityToInvoice,
|
||||
ol1_0.QuantityToShip,
|
||||
ol1_0.SellToCustomerNo,
|
||||
ol1_0.ShipToCustomerNo,
|
||||
ol1_0.ShipmentDate,
|
||||
ol1_0.ShipmentNo,
|
||||
ol1_0.ShippedNotInvoiced,
|
||||
ol1_0.SubjectCity,
|
||||
ol1_0.SubjectCountryCode,
|
||||
ol1_0.SubjectName,
|
||||
ol1_0.SubjectNo,
|
||||
ol1_0.SubjectSupplierCountryCode,
|
||||
ol1_0.SubjectUserId,
|
||||
ol1_0.SubscriptionNo,
|
||||
ol1_0.UnitCost,
|
||||
ol1_0.UnitOfMeasure,
|
||||
ol1_0.UnitPrice,
|
||||
ol1_0.VAT
|
||||
FROM dbo.XML_SubscriptionOrderLine ol1_0
|
||||
-- WHERE ol1_0.OrderLineNo = @P0
|
||||
```
|
||||
|
||||
***
|
||||
|
||||
### Root Cause Identified
|
||||
|
||||
After reviewing the application logic, I confirmed that **before inserting any data**, the application was first reading data using the query shown above.
|
||||
|
||||
This query caused **significant PAGEIOLATCH waits**, as shown in the screenshots below:
|
||||
|
||||
\[\[r02.png]]
|
||||
\[\[r03.png]]
|
||||
|
||||
This clearly indicated that the query was **not optimized**.
|
||||
|
||||
Further analysis of the execution plan revealed that:
|
||||
|
||||
* The query was performing a **full scan of more than 200 million records**
|
||||
|
||||
* This resulted in excessive I/O and severely degraded performance
|
||||
|
||||
\[\[r04.png]]
|
||||
|
||||
***
|
||||
|
||||
### Resolution
|
||||
|
||||
The root cause was identified as a **missing index** on the `XML_SubscriptionOrderLine` table.
|
||||
|
||||
The following index was required but did not exist:
|
||||
|
||||
```sql
|
||||
USE [AboSystem_xx];
|
||||
GO
|
||||
|
||||
CREATE NONCLUSTERED INDEX idx_tmp_XML_SubscriptionOrderLine
|
||||
ON dbo.XML_SubscriptionOrderLine (OrderLineNo);
|
||||
GO
|
||||
```
|
||||
|
||||
After simulating the change and validating the execution plan, the index was created on the `OrderLineNo` column.
|
||||
|
||||
As a result:
|
||||
|
||||
* The query started performing **index seeks instead of full table scans**
|
||||
|
||||
* The query cost was reduced **drastically**, as shown below:
|
||||
|
||||
\[\[r05.png]]
|
||||
|
||||
***
|
||||
|
||||
### Result After Fix
|
||||
|
||||
After restarting the application, the overall system performance improved dramatically:
|
||||
|
||||
* Processing speed increased by **several thousand percent**
|
||||
|
||||
* The backlog queue was fully processed by **19:00**
|
||||
|
||||
* Without the fix, completion was estimated to take **approximately 4 days**
|
||||
|
||||
\[\[r06.png]]
|
||||
|
||||
***
|
||||
|
||||
### Summary
|
||||
|
||||
The performance issue was caused by a **missing nonclustered index**, which forced the application to perform full scans on a very large table before insert operations.
|
||||
Once the index was added, database access became efficient, the application throughput returned to normal, and the backlog was cleared within hours.
|
||||
|
||||
***
|
||||
|
||||
Jeśli chcesz:
|
||||
|
||||
* mogę przygotować **krótszą wersję executive summary**
|
||||
* albo wersję **strict RCA (Problem / Cause / Resolution / Prevention)**
|
||||
* albo **wersję pod post‑mortem lub ServiceNow**
|
||||
|
||||
Daj znać 👍
|
||||
Reference in New Issue
Block a user