252 lines
8.0 KiB
Markdown
252 lines
8.0 KiB
Markdown
|
||
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ć 👍
|