Long operations, full-text rules and statement activity
- Long operations: a one-minute collector reads operations with progress from sys.dm_exec_requests (BACKUP, RESTORE, DBCC, REORGANIZE, SHRINK, ROLLBACK): command, database, start, percent, expected end, login. Stored in insight.LongOperations (migration 0011, RawDays), shown on the instance page, in the time window analysis and its PDF. The last 10 durations per command and database survive restarts; SQLI-OPS-001 flags a backup/restore running over twice the median. - Full-text community rules COM-FT-001..005 (metadata only, 2005 syntax): disk-full or paused/throttled catalogs, stale manual/off change tracking indexes and disabled indexes. - Statement activity (CPU time / time in plan cache): column in top SQL and SQLI-CPU-002 when above SQLInsight:TopSql:ActivityThresholdPercent (default 50) for at least an hour. Never clears the plan cache. - BuiltInCollectors.Create takes a CollectorSettings record. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
This commit is contained in:
parent
7a908cc28b
commit
384e1f154f
25 changed files with 661 additions and 34 deletions
|
|
@ -4,7 +4,7 @@
|
|||
|
||||
SQLInsight Pro er et overvågningsværktøj til Microsoft SQL Server, skrevet i C# på .NET. Det kører hos kunden og forlader ikke netværket, medmindre kunden selv vælger det. Værktøjet nøjes ikke med at vise tal. Det forklarer, hvad der er galt, hvorfor det er et problem, og hvordan det løses. Rådene har samme niveau som dem, man får fra en erfaren DBA.
|
||||
|
||||
> **Status:** Fase 1–4 er implementeret: agent, 64 indbyggede regler plus community-regler, notifikationer, lokalt repository og web-UI, licenser, signerede opdateringer, SQLInsight Hub med portal, erfaring på tværs af kunder, PDF-rapporter og integration med Prometheus, Grafana og SCOM, plus MSI-installer, community-websted og Discourse-forum. Se [installation](docs/installation.md), [opdateringer](docs/opdatering.md), [integration](docs/integration.md), [rapporter](docs/rapporter.md), [egne regler](docs/regler.md), [databehandling](docs/databehandling.md), [community](docs/community.md), [Roadmap](#roadmap) og [CONTRIBUTING.md](CONTRIBUTING.md).
|
||||
> **Status:** Fase 1–4 er implementeret: agent, 66 indbyggede regler plus community-regler, notifikationer, lokalt repository og web-UI, licenser, signerede opdateringer, SQLInsight Hub med portal, erfaring på tværs af kunder, PDF-rapporter og integration med Prometheus, Grafana og SCOM, plus MSI-installer, community-websted og Discourse-forum. Se [installation](docs/installation.md), [opdateringer](docs/opdatering.md), [integration](docs/integration.md), [rapporter](docs/rapporter.md), [egne regler](docs/regler.md), [databehandling](docs/databehandling.md), [community](docs/community.md), [Roadmap](#roadmap) og [CONTRIBUTING.md](CONTRIBUTING.md).
|
||||
|
||||
---
|
||||
|
||||
|
|
|
|||
|
|
@ -93,3 +93,15 @@ Under hver graf på instanssiden og i analysen står en vurdering i farve – **
|
|||
| Disk, skrivning til log (drev kun med logfiler) | Over 5 ms | Over 15 ms |
|
||||
|
||||
Diske vurderes kun med mindst 100 læsninger/skrivninger i perioden. Logikken ligger ét sted (`MetricAssessment`), så siden og PDF'en siger det samme.
|
||||
|
||||
## Langvarige operationer
|
||||
|
||||
Hvert minut læser agenten de operationer, SQL Server viser fremskridt for (`percent_complete` i `sys.dm_exec_requests`): BACKUP, RESTORE, DBCC CHECKDB, ALTER INDEX REORGANIZE, SHRINK, ROLLBACK m.fl. med kommando, database, start, % færdig, forventet sluttid og login. De vises under **Igangværende og nylige langvarige operationer** på instanssiden og i analysen af et tidsrum, og gemmes i `RawDays`. Login er følsomt og vises kun lokalt.
|
||||
|
||||
Agenten husker varigheden af de seneste 10 kørsler af samme kommando på samme database (kørsler under et minut tæller ikke). Kører en backup eller restore mere end dobbelt så længe som medianen (og mindst 5 minutter længere), giver det fundet **SQLI-OPS-001** (Middel).
|
||||
|
||||
## Aktivitet: sætninger, der kører næsten uafbrudt
|
||||
|
||||
Kolonnen **Aktivitet** under tungeste forespørgsler er sætningens CPU-tid som andel af tidsrummet: 100 % betyder, at den har holdt én CPU-kerne beskæftiget hele tiden (over 100 % er parallelt).
|
||||
|
||||
Reglen **SQLI-CPU-002** (Middel) ser på sætninger, der har ligget i plan cache i mindst en time og stadig kører: er deres samlede CPU-tid over 50 % af tiden i cache, bruger de i praksis en CPU-kerne konstant. Grænsen sættes med `SQLInsight:TopSql:ActivityThresholdPercent` (standard 50). SQLInsight tømmer aldrig plan cache eller ændrer noget; fundet peger kun på sætningen.
|
||||
|
|
|
|||
|
|
@ -74,3 +74,11 @@ Når reglen virker, kopieres filen til `rules`-mappen i agentens datamappe. Den
|
|||
4. Opret en pull request på [git.seosoft.dk/seo/sqlinsight-pro](https://git.seosoft.dk/seo/sqlinsight-pro). Testen `Community_rules_in_the_repository_are_valid_and_ship_with_the_build` fanger format- og sikkerhedsfejl.
|
||||
|
||||
Efter review kommer reglen med i næste version og i næste regelpakke, så eksisterende installationer får den uden opdatering af programmet.
|
||||
|
||||
## Community-regler i pakken
|
||||
|
||||
| Fil | Regler |
|
||||
|---|---|
|
||||
| `dynamics-ax.json` | COM-AX-*: Dynamics AX-specifikke tjek (version, MAXDOP, …) |
|
||||
| `integrity.json`, `security.json` | Integritet og sikkerhed |
|
||||
| `fulltext.json` | COM-FT-001 katalog stoppet pga. fuld disk (Høj), COM-FT-002 katalog på pause eller droslet (Middel), COM-FT-003/004 fulltext-indeks med manuel eller slået-fra change tracking, ikke opdateret i 7/30 dage (Lav/Middel), COM-FT-005 deaktiveret fulltext-indeks (Middel). Kun metadata (`sys.fulltext_catalogs`, `sys.fulltext_indexes`, `FULLTEXTCATALOGPROPERTY`); SQL Server 2005-syntaks. |
|
||||
|
|
|
|||
75
rules/community/fulltext.json
Normal file
75
rules/community/fulltext.json
Normal file
|
|
@ -0,0 +1,75 @@
|
|||
// Full-text search: catalogs whose population has stopped, indexes that are out of date or disabled.
|
||||
//
|
||||
// Only metadata (sys.fulltext_catalogs, sys.fulltext_indexes, FULLTEXTCATALOGPROPERTY, OBJECTPROPERTY): no data is read,
|
||||
// and nothing is changed. Everything is SQL Server 2005 syntax. In databases without full-text the rules find nothing.
|
||||
//
|
||||
// FULLTEXTCATALOGPROPERTY(…, 'PopulateStatus'): 0 idle, 1 full population, 2 paused, 3 throttled, 4 recovering,
|
||||
// 5 shutdown, 6 incremental population, 7 building index, 8 disk full (paused), 9 change tracking.
|
||||
// 'PopulateCompletionAge' is seconds from 1990-01-01 to the last completed population.
|
||||
[
|
||||
{
|
||||
"id": "COM-FT-001",
|
||||
"title": "Fulltext-katalog er sat på pause, fordi disken er fuld",
|
||||
"severity": "High",
|
||||
"scope": "Database",
|
||||
"query": "SELECT c.name AS [catalog], FULLTEXTCATALOGPROPERTY(c.name, 'ItemCount') AS [items] FROM sys.fulltext_catalogs c WHERE FULLTEXTCATALOGPROPERTY(c.name, 'PopulateStatus') = 8",
|
||||
"subject": "fulltext: {database}/{catalog}",
|
||||
"findingTitle": "Fulltext-kataloget {catalog} i {database} er stoppet: disken er fuld",
|
||||
"explanation": "SQL Server har sat opbygningen af fulltext-kataloget {catalog} på pause, fordi der ikke er plads på disken. Søgninger med CONTAINS og FREETEXT bruger det indeks, der var bygget, så nye og ændrede rækker findes ikke. Det fortsætter ikke af sig selv, før der er plads.",
|
||||
"recommendation": "Frigør plads på drevet med databasens datafiler (eller fulltext-katalogets mappe på SQL Server 2005), og genoptag derefter: ALTER FULLTEXT CATALOG [{catalog}] REBUILD, eller start en fuld population af tabellernes fulltext-indexes (ALTER FULLTEXT INDEX ON … START FULL POPULATION).",
|
||||
"evidence": [ "catalog", "items" ],
|
||||
"author": "SQLInsight Pro"
|
||||
},
|
||||
{
|
||||
"id": "COM-FT-002",
|
||||
"title": "Fulltext-katalog er sat på pause eller drosles",
|
||||
"severity": "Medium",
|
||||
"scope": "Database",
|
||||
"query": "SELECT c.name AS [catalog], CASE FULLTEXTCATALOGPROPERTY(c.name, 'PopulateStatus') WHEN 2 THEN 'sat på pause' ELSE 'droslet' END AS [status] FROM sys.fulltext_catalogs c WHERE FULLTEXTCATALOGPROPERTY(c.name, 'PopulateStatus') IN (2, 3)",
|
||||
"subject": "fulltext: {database}/{catalog}",
|
||||
"findingTitle": "Fulltext-kataloget {catalog} i {database} er {status}",
|
||||
"explanation": "Opbygningen af fulltext-kataloget {catalog} er {status}. Mens den står stille, finder fulltext-søgninger ikke nye og ændrede rækker. 'Droslet' betyder, at SQL Server har bremset opbygningen på grund af ressourcemangel (hukommelse eller CPU); 'pause' kan være sat manuelt eller af SQL Server.",
|
||||
"recommendation": "Tjek status i SQL Server Management Studio under Storage > Full Text Catalogs og fulltext-loggen (SQLFT*.log i SQL Servers logmappe). Genoptag med ALTER FULLTEXT INDEX ON <tabel> RESUME POPULATION. Bliver den ved med at drosles, så se på hukommelse og CPU på serveren.",
|
||||
"evidence": [ "catalog", "status" ],
|
||||
"author": "SQLInsight Pro"
|
||||
},
|
||||
{
|
||||
"id": "COM-FT-003",
|
||||
"title": "Fulltext-indeks uden automatisk opdatering er ikke opdateret i over en uge",
|
||||
"severity": "Low",
|
||||
"scope": "Database",
|
||||
"query": "SELECT OBJECT_NAME(i.object_id) AS [table], c.name AS [catalog], CASE i.change_tracking_state WHEN 'M' THEN 'manuel' ELSE 'slået fra' END AS [change_tracking], CONVERT(varchar(16), DATEADD(second, FULLTEXTCATALOGPROPERTY(c.name, 'PopulateCompletionAge'), '19900101'), 120) AS [last_population] FROM sys.fulltext_indexes i JOIN sys.fulltext_catalogs c ON c.fulltext_catalog_id = i.fulltext_catalog_id WHERE i.change_tracking_state IN ('M', 'O') AND i.is_enabled = 1 AND FULLTEXTCATALOGPROPERTY(c.name, 'PopulateCompletionAge') > 0 AND DATEADD(second, FULLTEXTCATALOGPROPERTY(c.name, 'PopulateCompletionAge'), '19900101') < DATEADD(day, -7, GETDATE()) AND DATEADD(second, FULLTEXTCATALOGPROPERTY(c.name, 'PopulateCompletionAge'), '19900101') >= DATEADD(day, -30, GETDATE())",
|
||||
"subject": "fulltext: {database}/{table}",
|
||||
"findingTitle": "Fulltext-indekset på {table} i {database} er sidst opdateret {last_population}",
|
||||
"explanation": "Fulltext-indekset på {table} opdateres ikke automatisk (change tracking er {change_tracking}), og kataloget {catalog} blev sidst bygget {last_population}. Søgninger finder ikke rækker, der er oprettet eller ændret siden.",
|
||||
"recommendation": "Opdatér det regelmæssigt fra et job (ALTER FULLTEXT INDEX ON [{table}] START INCREMENTAL POPULATION, kræver en timestamp-kolonne, ellers START FULL POPULATION), eller slå automatisk opdatering til: ALTER FULLTEXT INDEX ON [{table}] SET CHANGE_TRACKING AUTO.",
|
||||
"evidence": [ "table", "catalog", "change_tracking", "last_population" ],
|
||||
"author": "SQLInsight Pro"
|
||||
},
|
||||
{
|
||||
"id": "COM-FT-004",
|
||||
"title": "Fulltext-indeks uden automatisk opdatering er ikke opdateret i over 30 dage",
|
||||
"severity": "Medium",
|
||||
"scope": "Database",
|
||||
"query": "SELECT OBJECT_NAME(i.object_id) AS [table], c.name AS [catalog], CASE i.change_tracking_state WHEN 'M' THEN 'manuel' ELSE 'slået fra' END AS [change_tracking], CONVERT(varchar(16), DATEADD(second, FULLTEXTCATALOGPROPERTY(c.name, 'PopulateCompletionAge'), '19900101'), 120) AS [last_population] FROM sys.fulltext_indexes i JOIN sys.fulltext_catalogs c ON c.fulltext_catalog_id = i.fulltext_catalog_id WHERE i.change_tracking_state IN ('M', 'O') AND i.is_enabled = 1 AND FULLTEXTCATALOGPROPERTY(c.name, 'PopulateCompletionAge') > 0 AND DATEADD(second, FULLTEXTCATALOGPROPERTY(c.name, 'PopulateCompletionAge'), '19900101') < DATEADD(day, -30, GETDATE())",
|
||||
"subject": "fulltext: {database}/{table}",
|
||||
"findingTitle": "Fulltext-indekset på {table} i {database} er ikke opdateret siden {last_population}",
|
||||
"explanation": "Fulltext-indekset på {table} opdateres ikke automatisk (change tracking er {change_tracking}), og kataloget {catalog} er ikke bygget i over 30 dage (sidst {last_population}). Søgninger med CONTAINS og FREETEXT giver derfor forældede resultater.",
|
||||
"recommendation": "Opdatér det regelmæssigt fra et job (ALTER FULLTEXT INDEX ON [{table}] START INCREMENTAL POPULATION, kræver en timestamp-kolonne, ellers START FULL POPULATION), eller slå automatisk opdatering til: ALTER FULLTEXT INDEX ON [{table}] SET CHANGE_TRACKING AUTO. Bruges indekset ikke, så overvej at fjerne det.",
|
||||
"evidence": [ "table", "catalog", "change_tracking", "last_population" ],
|
||||
"author": "SQLInsight Pro"
|
||||
},
|
||||
{
|
||||
"id": "COM-FT-005",
|
||||
"title": "Fulltext-indeks er deaktiveret",
|
||||
"severity": "Medium",
|
||||
"scope": "Database",
|
||||
"query": "SELECT OBJECT_NAME(i.object_id) AS [table], c.name AS [catalog] FROM sys.fulltext_indexes i JOIN sys.fulltext_catalogs c ON c.fulltext_catalog_id = i.fulltext_catalog_id WHERE i.is_enabled = 0",
|
||||
"subject": "fulltext: {database}/{table}",
|
||||
"findingTitle": "Fulltext-indekset på {table} i {database} er deaktiveret",
|
||||
"explanation": "Fulltext-indekset på {table} (kataloget {catalog}) er slået fra. Det opdateres ikke, og fulltext-søgninger mod tabellen fejler eller finder intet, afhængigt af hvordan applikationen søger.",
|
||||
"recommendation": "Var det ikke med vilje (fx under en dataindlæsning), så slå det til igen: ALTER FULLTEXT INDEX ON [{table}] ENABLE, og start en population. Bruges det ikke, så fjern det: DROP FULLTEXT INDEX ON [{table}].",
|
||||
"evidence": [ "table", "catalog" ],
|
||||
"author": "SQLInsight Pro"
|
||||
}
|
||||
]
|
||||
|
|
@ -22,6 +22,8 @@ public sealed class AgentOptions
|
|||
|
||||
public PrivilegeOptions Privileges { get; set; } = new();
|
||||
|
||||
public TopSqlOptions TopSql { get; set; } = new();
|
||||
|
||||
public IList<MonitoredInstance> Instances { get; } = [];
|
||||
}
|
||||
|
||||
|
|
@ -74,3 +76,13 @@ public sealed class PrivilegeOptions
|
|||
/// <summary>Unfold Windows groups with server rights to the people in them, by asking Active Directory (Windows only).</summary>
|
||||
public bool ExpandWindowsGroups { get; set; } = true;
|
||||
}
|
||||
|
||||
/// <summary>Top SQL (the heaviest statements).</summary>
|
||||
public sealed class TopSqlOptions
|
||||
{
|
||||
/// <summary>
|
||||
/// A statement whose CPU time is more than this share of the time it has been in the plan cache runs almost
|
||||
/// constantly (SQLI-PERF-…); 100 means one CPU core all the time.
|
||||
/// </summary>
|
||||
public double ActivityThresholdPercent { get; set; } = 50;
|
||||
}
|
||||
|
|
|
|||
|
|
@ -240,6 +240,12 @@ public sealed partial class InstanceMonitor(
|
|||
return await repository.GetSnapshotAsync<Core.Data.PrivilegeSnapshot>(instanceId, collector.Name, cancellationToken).ConfigureAwait(false);
|
||||
}
|
||||
|
||||
// Earlier backup durations survive a restart, so a slow backup is still recognised.
|
||||
if (collector is Collectors.Instance.LongOperationCollector)
|
||||
{
|
||||
return await repository.GetSnapshotAsync<Core.Data.LongOperationSnapshot>(instanceId, collector.Name, cancellationToken).ConfigureAwait(false);
|
||||
}
|
||||
|
||||
if (collector is not Collectors.Concurrency.DeadlockCollector)
|
||||
{
|
||||
return null;
|
||||
|
|
|
|||
|
|
@ -32,7 +32,7 @@ public sealed partial class MonitoringService(
|
|||
|
||||
var intervals = new Dictionary<string, TimeSpan>(settings.CollectorIntervals, StringComparer.OrdinalIgnoreCase);
|
||||
var monitors = settings.Instances
|
||||
.Select(i => new InstanceMonitor(i, BuiltInCollectors.Create(customRules, groupResolver, settings.Privileges.MaxSysadminAccounts), intervals, connectionFactory, ruleEngine, repository,
|
||||
.Select(i => new InstanceMonitor(i, BuiltInCollectors.Create(customRules, new CollectorSettings(groupResolver, settings.Privileges.MaxSysadminAccounts, settings.TopSql.ActivityThresholdPercent)), intervals, connectionFactory, ruleEngine, repository,
|
||||
loggerFactory.CreateLogger($"SQLInsight.Instance.{i.Name}"), notifications, notificationOptions.Value.WebUrl, hubOutbox))
|
||||
.ToList();
|
||||
if (monitors.Count == 0)
|
||||
|
|
|
|||
|
|
@ -8,22 +8,25 @@ namespace SQLInsight.Collectors;
|
|||
public static class BuiltInCollectors
|
||||
{
|
||||
/// <param name="custom">Community and local rules whose queries are run by the custom-rules collector.</param>
|
||||
/// <param name="groups">Unfolds Windows groups with server rights to the people in them (Active Directory).</param>
|
||||
/// <param name="maxSysadminAccounts">More people and accounts with sysadmin than this is a finding.</param>
|
||||
public static IReadOnlyList<ICollector> Create(Core.CustomRules.CustomRuleCatalog? custom = null, Core.Data.IGroupMemberResolver? groups = null, int maxSysadminAccounts = 3) =>
|
||||
/// <param name="settings">The customer's settings for collectors that need them; defaults when null.</param>
|
||||
public static IReadOnlyList<ICollector> Create(Core.CustomRules.CustomRuleCatalog? custom = null, CollectorSettings? settings = null)
|
||||
{
|
||||
settings ??= new CollectorSettings();
|
||||
return
|
||||
[
|
||||
new ServerCollector(),
|
||||
new ConfigurationCollector(),
|
||||
new TraceFlagCollector(),
|
||||
new InstanceConfigurationCollector(),
|
||||
new PrivilegeCollector(groups, maxSysadminAccounts),
|
||||
new PrivilegeCollector(settings.Groups, settings.MaxSysadminAccounts),
|
||||
new DatabaseCollector(),
|
||||
new SuspectPageCollector(),
|
||||
new PlanCacheCollector(),
|
||||
new WaitStatsCollector(),
|
||||
new FileIoCollector(),
|
||||
new QueryStatsCollector(),
|
||||
new QueryStatsCollector(settings.ActivityThresholdPercent),
|
||||
new WaitSamplingCollector(),
|
||||
new LongOperationCollector(),
|
||||
new PerformanceCounterCollector(),
|
||||
new CpuCollector(),
|
||||
new BlockingCollector(),
|
||||
|
|
@ -35,4 +38,14 @@ public static class BuiltInCollectors
|
|||
new AgentJobCollector(),
|
||||
.. custom is null ? Array.Empty<ICollector>() : [new Custom.CustomQueryCollector(custom)],
|
||||
];
|
||||
}
|
||||
}
|
||||
|
||||
/// <summary>Settings from the agent's configuration that some collectors need.</summary>
|
||||
/// <param name="Groups">Unfolds Windows groups with server rights to the people in them (Active Directory).</param>
|
||||
/// <param name="MaxSysadminAccounts">More people and accounts with sysadmin than this is a finding.</param>
|
||||
/// <param name="ActivityThresholdPercent">A statement using more CPU time than this share of its lifetime is a finding.</param>
|
||||
public sealed record CollectorSettings(
|
||||
Core.Data.IGroupMemberResolver? Groups = null,
|
||||
int MaxSysadminAccounts = 3,
|
||||
double ActivityThresholdPercent = 50);
|
||||
|
|
|
|||
39
src/SQLInsight.Collectors/Instance/LongOperationCollector.cs
Normal file
39
src/SQLInsight.Collectors/Instance/LongOperationCollector.cs
Normal file
|
|
@ -0,0 +1,39 @@
|
|||
using SQLInsight.Core.Data;
|
||||
using SQLInsight.Core.Instances;
|
||||
|
||||
namespace SQLInsight.Collectors.Instance;
|
||||
|
||||
/// <summary>
|
||||
/// Long operations SQL Server reports progress for (BACKUP, RESTORE, DBCC, ALTER INDEX REORGANIZE, SHRINK, ROLLBACK …):
|
||||
/// command, database, start, percent complete, expected end and login, every minute, and how long earlier runs of the
|
||||
/// same command took. Read only; SQL Server 2005+.
|
||||
/// </summary>
|
||||
public sealed class LongOperationCollector : Collector<LongOperationSnapshot>
|
||||
{
|
||||
// Times converted to UTC on the server; estimated_completion_time is in ms and may exceed int, so seconds.
|
||||
internal const string Sql = """
|
||||
SELECT r.session_id, r.command, DB_NAME(r.database_id), s.login_name,
|
||||
DATEADD(minute, DATEDIFF(minute, GETDATE(), GETUTCDATE()), r.start_time),
|
||||
CAST(r.percent_complete AS float),
|
||||
CASE WHEN r.estimated_completion_time > 0 THEN DATEADD(second, CAST(r.estimated_completion_time / 1000 AS int), GETUTCDATE()) END,
|
||||
GETUTCDATE()
|
||||
FROM sys.dm_exec_requests r
|
||||
LEFT JOIN sys.dm_exec_sessions s ON s.session_id = r.session_id
|
||||
WHERE r.percent_complete > 0 AND r.session_id <> @@SPID
|
||||
""";
|
||||
|
||||
public override string Name => "long-operations";
|
||||
public override TimeSpan DefaultInterval => TimeSpan.FromMinutes(1);
|
||||
public override IReadOnlyCollection<Capability> RequiredCapabilities => [Capability.DynamicManagementViews];
|
||||
|
||||
protected override async Task<LongOperationSnapshot> CollectAsync(CollectorContext context, LongOperationSnapshot? previous)
|
||||
{
|
||||
var running = await Db.QueryAsync(context.Connection, Sql, r => new LongOperation(
|
||||
r.Int(0), r.String(1).Trim(), r.NullableString(2), r.NullableString(3),
|
||||
Utc(r.DateTime(4)), r.Double(5), r.NullableDateTime(6) is { } end ? Utc(end) : null, Utc(r.DateTime(7))),
|
||||
context.CancellationToken).ConfigureAwait(false);
|
||||
return LongOperationHistory.Advance(previous, running, context.Now);
|
||||
}
|
||||
|
||||
private static DateTimeOffset Utc(DateTime value) => new(DateTime.SpecifyKind(value, DateTimeKind.Utc));
|
||||
}
|
||||
|
|
@ -10,7 +10,7 @@ namespace SQLInsight.Collectors.Performance;
|
|||
/// the heaviest <see cref="TopPerMeasure"/> statements by CPU, duration, reads and executions, their text cut to
|
||||
/// <see cref="QueryStat.MaxTextLength"/> characters, and no plan XML.
|
||||
/// </summary>
|
||||
public sealed class QueryStatsCollector : Collector<CumulativeSample<QueryStatsSnapshot, QueryStatsDelta>>
|
||||
public sealed class QueryStatsCollector(double activityThresholdPercent = 50) : Collector<CumulativeSample<QueryStatsSnapshot, QueryStatsDelta>>
|
||||
{
|
||||
public const int TopPerMeasure = 50;
|
||||
|
||||
|
|
@ -108,7 +108,11 @@ public sealed class QueryStatsCollector : Collector<CumulativeSample<QueryStatsS
|
|||
// No statement ran since the previous collection: the server clock still has to move forward.
|
||||
serverTime ??= (await Db.QueryAsync(context.Connection, "SELECT GETDATE()", r => r.DateTime(0), ct).ConfigureAwait(false))[0];
|
||||
|
||||
var fetched = new QueryStatsSnapshot { CapturedAt = context.Now, ServerTime = serverTime.Value, SqlServerStartTime = startTime, Queries = rows };
|
||||
var fetched = new QueryStatsSnapshot
|
||||
{
|
||||
CapturedAt = context.Now, ServerTime = serverTime.Value, SqlServerStartTime = startTime, Queries = rows,
|
||||
ActivityThresholdPercent = activityThresholdPercent,
|
||||
};
|
||||
var delta = QueryStatsDelta.Compute(previous?.Snapshot, fetched);
|
||||
var kept = fetched with { Queries = QueryStatsDelta.Remember(previous?.Snapshot, rows, startTime) };
|
||||
return new(kept, delta);
|
||||
|
|
|
|||
90
src/SQLInsight.Core/Data/LongOperations.cs
Normal file
90
src/SQLInsight.Core/Data/LongOperations.cs
Normal file
|
|
@ -0,0 +1,90 @@
|
|||
namespace SQLInsight.Core.Data;
|
||||
|
||||
/// <summary>
|
||||
/// An operation SQL Server reports progress for (percent_complete in sys.dm_exec_requests): BACKUP, RESTORE, DBCC,
|
||||
/// ALTER INDEX REORGANIZE, SHRINK, ROLLBACK and the like. Times are UTC. <see cref="LoginName"/> is sensitive.
|
||||
/// </summary>
|
||||
public sealed record LongOperation(
|
||||
int SessionId,
|
||||
string Command,
|
||||
string? DatabaseName,
|
||||
string? LoginName,
|
||||
DateTimeOffset StartedAt,
|
||||
double PercentComplete,
|
||||
DateTimeOffset? EstimatedEnd,
|
||||
DateTimeOffset LastSeenAt)
|
||||
{
|
||||
/// <summary>Identifies the operation across samples.</summary>
|
||||
public string Key => $"{SessionId}|{StartedAt.UtcTicks}|{Command}";
|
||||
|
||||
/// <summary>Operations compared with each other: the same command on the same database.</summary>
|
||||
public string Kind => $"{Command}|{DatabaseName}";
|
||||
|
||||
public TimeSpan Elapsed(DateTimeOffset now) => now - StartedAt;
|
||||
}
|
||||
|
||||
/// <summary>An operation that is no longer running, with how long it took (until it was last seen).</summary>
|
||||
public sealed record CompletedOperation(string Command, string? DatabaseName, DateTimeOffset StartedAt, TimeSpan Duration, double LastPercentComplete);
|
||||
|
||||
public sealed record LongOperationSnapshot
|
||||
{
|
||||
public required DateTimeOffset CapturedAt { get; init; }
|
||||
public required IReadOnlyList<LongOperation> Running { get; init; }
|
||||
|
||||
/// <summary>Operations that finished since the previous collection.</summary>
|
||||
public IReadOnlyList<CompletedOperation> Completed { get; init; } = [];
|
||||
|
||||
/// <summary>The latest <see cref="LongOperationHistory.Kept"/> durations per command and database, newest first.</summary>
|
||||
public IReadOnlyDictionary<string, IReadOnlyList<CompletedOperation>> History { get; init; } = new Dictionary<string, IReadOnlyList<CompletedOperation>>();
|
||||
}
|
||||
|
||||
public static class LongOperationHistory
|
||||
{
|
||||
/// <summary>Earlier runs kept per command and database.</summary>
|
||||
public const int Kept = 10;
|
||||
|
||||
/// <summary>Operations this short are not kept: a backup of an empty database says nothing about the next.</summary>
|
||||
public static readonly TimeSpan MinimumDuration = TimeSpan.FromMinutes(1);
|
||||
|
||||
/// <summary>Commands whose duration is compared with earlier runs.</summary>
|
||||
public static bool IsBackupOrRestore(string command)
|
||||
{
|
||||
ArgumentNullException.ThrowIfNull(command);
|
||||
return command.StartsWith("BACKUP", StringComparison.OrdinalIgnoreCase) || command.StartsWith("RESTORE", StringComparison.OrdinalIgnoreCase);
|
||||
}
|
||||
|
||||
/// <summary>The operations that are gone since the previous sample, and the history with them added.</summary>
|
||||
public static LongOperationSnapshot Advance(LongOperationSnapshot? previous, IReadOnlyList<LongOperation> running, DateTimeOffset now)
|
||||
{
|
||||
ArgumentNullException.ThrowIfNull(running);
|
||||
var still = running.Select(r => r.Key).ToHashSet(StringComparer.Ordinal);
|
||||
var completed = (previous?.Running ?? [])
|
||||
.Where(p => !still.Contains(p.Key))
|
||||
.Select(p => new CompletedOperation(p.Command, p.DatabaseName, p.StartedAt, p.LastSeenAt - p.StartedAt, p.PercentComplete))
|
||||
.ToList();
|
||||
var history = (previous?.History ?? new Dictionary<string, IReadOnlyList<CompletedOperation>>())
|
||||
.ToDictionary(h => h.Key, h => h.Value, StringComparer.Ordinal);
|
||||
foreach (var c in completed.Where(c => c.Duration >= MinimumDuration))
|
||||
{
|
||||
var key = $"{c.Command}|{c.DatabaseName}";
|
||||
history[key] = new[] { c }.Concat(history.GetValueOrDefault(key) ?? []).Take(Kept).ToList();
|
||||
}
|
||||
|
||||
return new LongOperationSnapshot { CapturedAt = now, Running = running, Completed = completed, History = history };
|
||||
}
|
||||
|
||||
/// <summary>The median duration of earlier runs of the same kind; null with fewer than three.</summary>
|
||||
public static TimeSpan? Median(LongOperationSnapshot snapshot, LongOperation operation)
|
||||
{
|
||||
ArgumentNullException.ThrowIfNull(snapshot);
|
||||
ArgumentNullException.ThrowIfNull(operation);
|
||||
if (!snapshot.History.TryGetValue(operation.Kind, out var runs) || runs.Count < 3)
|
||||
{
|
||||
return null;
|
||||
}
|
||||
|
||||
var sorted = runs.Select(r => r.Duration.Ticks).Order().ToList();
|
||||
var middle = sorted.Count / 2;
|
||||
return TimeSpan.FromTicks(sorted.Count % 2 == 1 ? sorted[middle] : (sorted[middle - 1] + sorted[middle]) / 2);
|
||||
}
|
||||
}
|
||||
|
|
@ -16,6 +16,9 @@ public sealed record QueryStatsSnapshot
|
|||
|
||||
public required DateTime SqlServerStartTime { get; init; }
|
||||
public required IReadOnlyList<QueryStat> Queries { get; init; }
|
||||
|
||||
/// <summary>A statement using more CPU time than this share of its time in the plan cache is a finding (SQLInsight:TopSql).</summary>
|
||||
public double ActivityThresholdPercent { get; init; } = 50;
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
|
|
@ -44,6 +47,12 @@ public sealed record QueryStat
|
|||
/// <summary>last_execution_time (server clock).</summary>
|
||||
public required DateTime LastExecutionAt { get; init; }
|
||||
|
||||
/// <summary>
|
||||
/// CPU time as a share of the time the statement has been in the plan cache (creation to last execution), in
|
||||
/// percent: 100 means one CPU core all the time, more is parallel. Null when it has been cached less than a minute.
|
||||
/// </summary>
|
||||
public double? ActivityPercent => LastExecutionAt - CreatedAt is { TotalSeconds: >= 60 } lifetime ? 100.0 * WorkerTimeUs / lifetime.TotalMicroseconds : null;
|
||||
|
||||
public const int MaxTextLength = 4000;
|
||||
}
|
||||
|
||||
|
|
|
|||
|
|
@ -22,6 +22,19 @@ public sealed record TimeWindowAnalysis
|
|||
|
||||
public required IReadOnlyList<StoredBlocking> Blocking { get; init; }
|
||||
public required IReadOnlyList<StoredDeadlock> Deadlocks { get; init; }
|
||||
|
||||
/// <summary>Backup, restore, DBCC and other operations with progress that ran in the window.</summary>
|
||||
public IReadOnlyList<StoredLongOperation> LongOperations { get; init; } = [];
|
||||
|
||||
/// <summary>
|
||||
/// A statement's CPU time as a share of the window, in percent of one CPU core: 100 means one core all the time.
|
||||
/// </summary>
|
||||
public double ActivityPercent(TopQuery query)
|
||||
{
|
||||
ArgumentNullException.ThrowIfNull(query);
|
||||
var seconds = (To - From).TotalSeconds;
|
||||
return seconds <= 0 ? 0 : 100.0 * query.WorkerTimeUs / (seconds * 1_000_000);
|
||||
}
|
||||
public required IReadOnlyList<StoredFinding> Findings { get; init; }
|
||||
public required TopQueryOrder QueryOrder { get; init; }
|
||||
|
||||
|
|
@ -42,7 +55,7 @@ public sealed record TimeWindowAnalysis
|
|||
metrics.FirstOrDefault(m => m.Metric == metric)?.Points ?? [];
|
||||
|
||||
public bool HasData => Metrics.Any(m => m.Points.Count > 0) || Waits.Count > 0 || Files.Count > 0 || Disks.Count > 0 || Blocking.Count > 0
|
||||
|| Deadlocks.Count > 0 || TopQueries.Count > 0;
|
||||
|| Deadlocks.Count > 0 || TopQueries.Count > 0 || LongOperations.Count > 0;
|
||||
|
||||
/// <summary>The metrics shown, in order: key, label, unit, decimals, lower-is-worse, fixed maximum.</summary>
|
||||
public static readonly IReadOnlyList<(string Metric, string Label, string Unit, int Decimals, bool LowerIsWorse, double? Max)> MetricDefinitions =
|
||||
|
|
@ -125,6 +138,7 @@ public sealed record TimeWindowAnalysis
|
|||
Disks = WindowBaseline.CompareDisks(windowDisks, earlierDisks),
|
||||
Blocking = await repository.GetBlockingAsync(id, from, to, cancellationToken).ConfigureAwait(false),
|
||||
Deadlocks = await repository.GetDeadlocksAsync(id, from, to, cancellationToken).ConfigureAwait(false),
|
||||
LongOperations = await repository.GetLongOperationsAsync(id, from, to, 100, cancellationToken).ConfigureAwait(false),
|
||||
Findings = await repository.GetFindingsActiveDuringAsync(id, from, to, cancellationToken).ConfigureAwait(false),
|
||||
QueryOrder = order,
|
||||
TopQueries = await repository.GetTopQueriesAsync(id, from, to, order, 25, cancellationToken).ConfigureAwait(false),
|
||||
|
|
|
|||
|
|
@ -67,6 +67,7 @@ public static class TimeWindowReport
|
|||
TopQueries(section, analysis);
|
||||
Disks(section, analysis);
|
||||
Files(section, analysis);
|
||||
LongOperations(section, analysis, zone);
|
||||
Blocking(section, analysis, zone);
|
||||
Deadlocks(section, analysis, zone);
|
||||
Findings(section, analysis);
|
||||
|
|
@ -203,6 +204,23 @@ public static class TimeWindowReport
|
|||
}
|
||||
}
|
||||
|
||||
private static void LongOperations(Section section, TimeWindowAnalysis analysis, TimeZoneInfo zone)
|
||||
{
|
||||
if (analysis.LongOperations.Count == 0)
|
||||
{
|
||||
return;
|
||||
}
|
||||
|
||||
section.AddParagraph("Langvarige operationer", StyleNames.Heading1);
|
||||
var table = Table(section, [3.4, 4.2, 3.2, 2.6, 2.4]);
|
||||
Header(table, "Kommando", "Database", "Startet", "Varighed", "Færdig");
|
||||
foreach (var o in analysis.LongOperations)
|
||||
{
|
||||
Row(table, false, o.Command, o.DatabaseName ?? "–", Time(new DateTimeOffset(o.StartedAt, TimeSpan.Zero), zone),
|
||||
Number(o.Duration.TotalMinutes, 0) + " min", Number(o.PercentComplete, 1) + " %");
|
||||
}
|
||||
}
|
||||
|
||||
private static void Blocking(Section section, TimeWindowAnalysis analysis, TimeZoneInfo zone)
|
||||
{
|
||||
section.AddParagraph("Blocking", StyleNames.Heading1);
|
||||
|
|
|
|||
|
|
@ -83,6 +83,7 @@ public sealed partial class InsightRepository
|
|||
await DeleteInBatchesAsync(connection, "insight.FileIoSamples", "SampledAt < @cutoff", raw).ConfigureAwait(false);
|
||||
await DeleteInBatchesAsync(connection, "insight.QueryStatSamples", "SampledAt < @cutoff", raw).ConfigureAwait(false);
|
||||
await DeleteInBatchesAsync(connection, "insight.ActiveWaitSamples", "SampledAt < @cutoff", raw).ConfigureAwait(false);
|
||||
await DeleteInBatchesAsync(connection, "insight.LongOperations", "LastSeenAt < @cutoff", raw).ConfigureAwait(false);
|
||||
await DeleteInBatchesAsync(connection, "insight.QueryTexts", "LastSeenAt < @cutoff", raw).ConfigureAwait(false);
|
||||
await DeleteInBatchesAsync(connection, "insight.MetricHourly", "[Hour] < @cutoff", hourly).ConfigureAwait(false);
|
||||
await DeleteInBatchesAsync(connection, "insight.WaitHourly", "[Hour] < @cutoff", hourly).ConfigureAwait(false);
|
||||
|
|
|
|||
68
src/SQLInsight.Repository/InsightRepository.Operations.cs
Normal file
68
src/SQLInsight.Repository/InsightRepository.Operations.cs
Normal file
|
|
@ -0,0 +1,68 @@
|
|||
using System.Globalization;
|
||||
using System.Text.Json;
|
||||
using Dapper;
|
||||
using Microsoft.Data.SqlClient;
|
||||
using SQLInsight.Core.Data;
|
||||
|
||||
namespace SQLInsight.Repository;
|
||||
|
||||
/// <summary>A long operation as stored; <see cref="LoginName"/> is sensitive (local UI only).</summary>
|
||||
public sealed record StoredLongOperation(int SessionId, DateTime StartedAt, string Command, string? DatabaseName, string? LoginName,
|
||||
double PercentComplete, DateTime? EstimatedEnd, DateTime LastSeenAt)
|
||||
{
|
||||
/// <summary>Still running at the latest sample (seen within the last two minutes).</summary>
|
||||
public bool IsRunning(DateTime utcNow) => utcNow - LastSeenAt < TimeSpan.FromMinutes(2);
|
||||
|
||||
public TimeSpan Duration => LastSeenAt - StartedAt;
|
||||
}
|
||||
|
||||
public sealed partial class InsightRepository
|
||||
{
|
||||
private static async Task SaveLongOperationsAsync(SqlConnection connection, int instanceId, LongOperationSnapshot snapshot)
|
||||
{
|
||||
if (snapshot.Running.Count == 0)
|
||||
{
|
||||
return;
|
||||
}
|
||||
|
||||
await connection.ExecuteAsync("""
|
||||
MERGE insight.LongOperations AS t
|
||||
USING (SELECT * FROM OPENJSON(@json) WITH (SessionId int, StartedAt datetime2(0), Command nvarchar(32), DatabaseName nvarchar(128),
|
||||
LoginName nvarchar(128), PercentComplete float, EstimatedEnd datetime2(0), LastSeenAt datetime2(0))) AS s
|
||||
ON t.InstanceId = @instanceId AND t.StartedAt = s.StartedAt AND t.SessionId = s.SessionId AND t.Command = s.Command
|
||||
WHEN MATCHED THEN UPDATE SET PercentComplete = s.PercentComplete, EstimatedEnd = s.EstimatedEnd, LastSeenAt = s.LastSeenAt
|
||||
WHEN NOT MATCHED THEN INSERT (InstanceId, SessionId, StartedAt, Command, DatabaseName, LoginName, PercentComplete, EstimatedEnd, LastSeenAt)
|
||||
VALUES (@instanceId, s.SessionId, s.StartedAt, s.Command, s.DatabaseName, s.LoginName, s.PercentComplete, s.EstimatedEnd, s.LastSeenAt);
|
||||
""", new
|
||||
{
|
||||
instanceId,
|
||||
json = JsonSerializer.Serialize(snapshot.Running.Select(o => new
|
||||
{
|
||||
o.SessionId,
|
||||
StartedAt = Iso(o.StartedAt),
|
||||
Command = o.Command.Length <= 32 ? o.Command : o.Command[..32],
|
||||
o.DatabaseName,
|
||||
o.LoginName,
|
||||
o.PercentComplete,
|
||||
EstimatedEnd = o.EstimatedEnd is { } end ? Iso(end) : null,
|
||||
LastSeenAt = Iso(o.LastSeenAt),
|
||||
}), Json),
|
||||
}).ConfigureAwait(false);
|
||||
|
||||
static string Iso(DateTimeOffset value) => Utc(value).ToString("yyyy-MM-ddTHH:mm:ss", CultureInfo.InvariantCulture);
|
||||
}
|
||||
|
||||
/// <summary>Long operations that ran at some point in [from, to], newest first.</summary>
|
||||
public async Task<IReadOnlyList<StoredLongOperation>> GetLongOperationsAsync(int instanceId, DateTimeOffset from, DateTimeOffset to, int top = 200,
|
||||
CancellationToken cancellationToken = default)
|
||||
{
|
||||
await using var connection = await OpenAsync(cancellationToken).ConfigureAwait(false);
|
||||
var rows = await connection.QueryAsync<StoredLongOperation>("""
|
||||
SELECT TOP (@top) SessionId, StartedAt, Command, DatabaseName, LoginName, PercentComplete, EstimatedEnd, LastSeenAt
|
||||
FROM insight.LongOperations
|
||||
WHERE InstanceId = @instanceId AND StartedAt <= @to AND LastSeenAt >= @from
|
||||
ORDER BY StartedAt DESC;
|
||||
""", new { instanceId, from = from.UtcDateTime, to = to.UtcDateTime, top }).ConfigureAwait(false);
|
||||
return rows.ToList();
|
||||
}
|
||||
}
|
||||
|
|
@ -260,6 +260,10 @@ public sealed partial class InsightRepository(string connectionString)
|
|||
// Never as a JSON snapshot: it holds statement texts.
|
||||
await SaveWaitSamplesAsync(connection, instanceId, samples).ConfigureAwait(false);
|
||||
return;
|
||||
case LongOperationSnapshot operations:
|
||||
await SaveLongOperationsAsync(connection, instanceId, operations).ConfigureAwait(false);
|
||||
await SaveSnapshotJsonAsync(connection, instanceId, kind, data).ConfigureAwait(false);
|
||||
return;
|
||||
case PrivilegeSnapshot privileges:
|
||||
await SavePrivilegeChangesAsync(connection, instanceId, privileges.Changes).ConfigureAwait(false);
|
||||
await SaveLatePrivilegeAuthorsAsync(connection, instanceId, privileges.RecentChanges).ConfigureAwait(false);
|
||||
|
|
|
|||
|
|
@ -0,0 +1,15 @@
|
|||
/* Long operations with progress (BACKUP, RESTORE, DBCC, ...): one row per operation, updated while it runs.
|
||||
LoginName is sensitive (local only). Kept as long as the other raw samples (Retention:RawDays). */
|
||||
CREATE TABLE insight.LongOperations
|
||||
(
|
||||
InstanceId int NOT NULL,
|
||||
SessionId int NOT NULL,
|
||||
StartedAt datetime2(0) NOT NULL,
|
||||
Command nvarchar(32) NOT NULL,
|
||||
DatabaseName nvarchar(128) NULL,
|
||||
LoginName nvarchar(128) NULL,
|
||||
PercentComplete float NOT NULL,
|
||||
EstimatedEnd datetime2(0) NULL,
|
||||
LastSeenAt datetime2(0) NOT NULL,
|
||||
CONSTRAINT PK_LongOperations PRIMARY KEY (InstanceId, StartedAt, SessionId, Command)
|
||||
);
|
||||
|
|
@ -54,6 +54,8 @@ public static class BuiltInRules
|
|||
new DataFileReadLatencyRule(),
|
||||
new LogFileWriteLatencyRule(),
|
||||
new CpuRule(),
|
||||
new ConstantActivityRule(),
|
||||
new SlowBackupRule(),
|
||||
new MemoryGrantsPendingRule(),
|
||||
new AnomalyRule(),
|
||||
new PlanRegressionRule(),
|
||||
|
|
|
|||
92
src/SQLInsight.Rules/Performance/OperationRules.cs
Normal file
92
src/SQLInsight.Rules/Performance/OperationRules.cs
Normal file
|
|
@ -0,0 +1,92 @@
|
|||
using System.Globalization;
|
||||
using SQLInsight.Core.Collection;
|
||||
using SQLInsight.Core.Data;
|
||||
using SQLInsight.Core.Findings;
|
||||
using SQLInsight.Core.Instances;
|
||||
using SQLInsight.Rules.Engine;
|
||||
|
||||
namespace SQLInsight.Rules.Performance;
|
||||
|
||||
/// <summary>
|
||||
/// A backup or restore that has run markedly longer than the same command on the same database usually takes: more
|
||||
/// than twice the median of the last runs. Often the first sign of slow backup storage, a network share, or a
|
||||
/// database that has grown.
|
||||
/// </summary>
|
||||
public sealed class SlowBackupRule : Rule
|
||||
{
|
||||
public const double Factor = 2;
|
||||
|
||||
public override string Id => "SQLI-OPS-001";
|
||||
public override string Title => "Backup eller restore kører markant længere end normalt";
|
||||
public override IReadOnlyCollection<Capability> RequiredCapabilities => [Capability.DynamicManagementViews];
|
||||
|
||||
public override RuleEvaluation Evaluate(RuleContext context)
|
||||
{
|
||||
ArgumentNullException.ThrowIfNull(context);
|
||||
var snapshot = context.Data.Get<LongOperationSnapshot>();
|
||||
return Result(snapshot.Running
|
||||
.Where(o => LongOperationHistory.IsBackupOrRestore(o.Command))
|
||||
.Select(o => (Operation: o, Median: LongOperationHistory.Median(snapshot, o), Elapsed: o.Elapsed(snapshot.CapturedAt)))
|
||||
.Where(x => x.Median is { } median && x.Elapsed > median * Factor && x.Elapsed - median >= TimeSpan.FromMinutes(5))
|
||||
.Select(x => CreateFinding(
|
||||
Severity.Medium,
|
||||
$"{x.Operation.Command} af {x.Operation.DatabaseName} har kørt {Format.Age(x.Elapsed)} (normalt {Format.Age(x.Median!.Value)})",
|
||||
$"{x.Operation.Command} af {x.Operation.DatabaseName} har kørt mere end dobbelt så længe som de seneste kørsler (median {Format.Age(x.Median.Value)}). "
|
||||
+ "Det kan være langsom backup-storage eller netværk, en database der er vokset, eller en backup der hænger og blokerer den næste.",
|
||||
"Se ventetypen for sessionen (BACKUPIO/ASYNC_IO_COMPLETION = backupmålet er langsomt), og tjek backupmålet og netværket. "
|
||||
+ "Følg med i forventet sluttid under Langvarige operationer på instansens side.",
|
||||
[
|
||||
new Evidence("Kommando", x.Operation.Command),
|
||||
new Evidence("Database", x.Operation.DatabaseName ?? "–"),
|
||||
new Evidence("Startet", x.Operation.StartedAt.UtcDateTime.ToString("yyyy-MM-dd HH:mm 'UTC'", CultureInfo.InvariantCulture)),
|
||||
new Evidence("Færdig", $"{Format.Number(x.Operation.PercentComplete, 1)} %"),
|
||||
new Evidence("Forventet slut", x.Operation.EstimatedEnd?.UtcDateTime.ToString("yyyy-MM-dd HH:mm 'UTC'", CultureInfo.InvariantCulture) ?? "ukendt"),
|
||||
new Evidence("Median af seneste kørsler", Format.Age(x.Median.Value)),
|
||||
new Evidence("Login", x.Operation.LoginName ?? "–", Sensitive: true),
|
||||
],
|
||||
subject: $"operation: {x.Operation.Command}/{x.Operation.DatabaseName}")));
|
||||
}
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// A statement that in practice keeps a CPU core busy all the time: its CPU time is more than the threshold
|
||||
/// (SQLInsight:TopSql:ActivityThresholdPercent, default 50 %) of the time it has been in the plan cache, for at least an
|
||||
/// hour. SQLInsight never clears the plan cache or changes anything; the finding says where to look.
|
||||
/// </summary>
|
||||
public sealed class ConstantActivityRule : Rule
|
||||
{
|
||||
public static readonly TimeSpan MinimumLifetime = TimeSpan.FromHours(1);
|
||||
|
||||
public override string Id => "SQLI-CPU-002";
|
||||
public override string Title => "Sætning kører næsten uafbrudt";
|
||||
public override IReadOnlyCollection<Capability> RequiredCapabilities => [Capability.DynamicManagementViews];
|
||||
|
||||
public override RuleEvaluation Evaluate(RuleContext context)
|
||||
{
|
||||
ArgumentNullException.ThrowIfNull(context);
|
||||
var snapshot = context.Data.Get<CumulativeSample<QueryStatsSnapshot, QueryStatsDelta>>().Snapshot;
|
||||
var threshold = snapshot.ActivityThresholdPercent;
|
||||
return Result(snapshot.Queries
|
||||
.Where(q => q.LastExecutionAt >= snapshot.ServerTime.AddMinutes(-15) && q.LastExecutionAt - q.CreatedAt >= MinimumLifetime
|
||||
&& q.ActivityPercent > threshold)
|
||||
.OrderByDescending(q => q.ActivityPercent)
|
||||
.Take(5)
|
||||
.Select(q => CreateFinding(
|
||||
Severity.Medium,
|
||||
$"En sætning har brugt {Format.Number(q.ActivityPercent!.Value)} % af en CPU-kerne i {Format.Age(q.LastExecutionAt - q.CreatedAt)}",
|
||||
"Sætningens samlede CPU-tid er mere end " + Format.Number(threshold) + " % af den tid, den har ligget i plan cache. "
|
||||
+ "Den bruger i praksis én CPU-kerne konstant (over 100 % betyder flere kerner). Det er typisk en sætning, der kaldes i en løkke "
|
||||
+ "fra en applikation eller et job, eller en tung forespørgsel, der kører hele tiden.",
|
||||
"Find sætningen under tungeste forespørgsler i analysen (sorteret efter CPU), og find ud af, hvem der kalder den så ofte. "
|
||||
+ "Se planen for manglende indexes. SQLInsight ændrer aldrig noget: tøm ikke plan cache for at få fundet væk – det skjuler kun tallet.",
|
||||
[
|
||||
new Evidence("Aktivitet", $"{Format.Number(q.ActivityPercent.Value)} % af en kerne"),
|
||||
new Evidence("I plan cache", Format.Age(q.LastExecutionAt - q.CreatedAt)),
|
||||
new Evidence("CPU i alt", $"{Format.Number(q.WorkerTimeUs / 1_000_000.0)} s"),
|
||||
new Evidence("Kørsler", Format.Number(q.Executions)),
|
||||
new Evidence("Database", q.DatabaseName ?? "–"),
|
||||
new Evidence("Sætning", q.Text is { Length: > 500 } t ? t[..500] + " …" : q.Text ?? "–", Sensitive: true),
|
||||
],
|
||||
subject: $"query: {q.Key}")));
|
||||
}
|
||||
}
|
||||
|
|
@ -99,7 +99,7 @@
|
|||
else
|
||||
{
|
||||
<table class="queries">
|
||||
<thead><tr><th>Forespørgsel</th><th class="num">CPU</th><th class="num">Varighed</th><th class="num">Læsninger</th><th class="num">Kørsler</th></tr></thead>
|
||||
<thead><tr><th>Forespørgsel</th><th class="num">CPU</th><th class="num">Varighed</th><th class="num">Læsninger</th><th class="num">Kørsler</th><th class="num" title="CPU-tid som andel af tidsrummet: 100 % = én CPU-kerne hele tiden">Aktivitet</th></tr></thead>
|
||||
<tbody>
|
||||
@foreach (var q in _analysis.TopQueries)
|
||||
{
|
||||
|
|
@ -109,6 +109,7 @@
|
|||
<td class="num nowrap">@Display.Number(q.ElapsedTimeUs / 1_000_000.0, 1) s</td>
|
||||
<td class="num">@Display.Number(q.LogicalReads)</td>
|
||||
<td class="num">@Display.Number(q.Executions)</td>
|
||||
<td class="num @(_analysis.ActivityPercent(q) > 50 ? "bad" : "")">@Display.Number(_analysis.ActivityPercent(q)) %</td>
|
||||
</tr>
|
||||
}
|
||||
</tbody>
|
||||
|
|
@ -149,6 +150,11 @@
|
|||
}
|
||||
</section>
|
||||
|
||||
<section class="card">
|
||||
<div class="card-head"><h2>Langvarige operationer</h2><span class="muted">backup, restore, DBCC m.m.</span></div>
|
||||
<LongOperationTable Operations="_analysis.LongOperations" Empty="Ingen operationer med fremskridt i tidsrummet." />
|
||||
</section>
|
||||
|
||||
<div class="grid2">
|
||||
<section class="card">
|
||||
<div class="card-head" id="blocking"><h2>Blocking</h2></div>
|
||||
|
|
|
|||
|
|
@ -130,6 +130,11 @@ else
|
|||
}
|
||||
</section>
|
||||
|
||||
<section class="card">
|
||||
<div class="card-head"><h2>Igangværende og nylige langvarige operationer</h2><span class="muted">seneste 24 timer</span></div>
|
||||
<LongOperationTable Operations="_operations" Empty="Ingen backup, restore, DBCC eller lignende med fremskridt de seneste 24 timer." />
|
||||
</section>
|
||||
|
||||
<div class="grid2">
|
||||
<section class="card">
|
||||
<div class="card-head"><h2>Blocking, seneste 24 timer</h2></div>
|
||||
|
|
@ -254,6 +259,7 @@ else
|
|||
private IReadOnlyList<SQLInsight.Reports.DiskComparison> _disks = [];
|
||||
private IReadOnlyList<DiskSeries> _diskSeries = [];
|
||||
private IReadOnlyList<StoredBlocking> _blocking = [];
|
||||
private IReadOnlyList<StoredLongOperation> _operations = [];
|
||||
private IReadOnlyList<StoredDeadlock> _deadlocks = [];
|
||||
|
||||
protected override async Task OnInitializedAsync()
|
||||
|
|
@ -285,6 +291,7 @@ else
|
|||
_disks = (await Repository.GetDiskActivityAsync(id, day, DateTimeOffset.UtcNow)).Select(d => new SQLInsight.Reports.DiskComparison(d, null)).ToList();
|
||||
_diskSeries = await Repository.GetDiskSeriesAsync(id, day);
|
||||
_blocking = await Repository.GetBlockingAsync(id, day);
|
||||
_operations = await Repository.GetLongOperationsAsync(id, day, DateTimeOffset.UtcNow, 50);
|
||||
_deadlocks = await Repository.GetDeadlocksAsync(id, DateTimeOffset.UtcNow.AddDays(-7));
|
||||
}
|
||||
|
||||
|
|
|
|||
|
|
@ -0,0 +1,37 @@
|
|||
@inject Display Display
|
||||
|
||||
@* Long operations with progress (BACKUP, RESTORE, DBCC …). Logins are shown locally only. *@
|
||||
@if (Operations.Count == 0)
|
||||
{
|
||||
<p class="muted">@Empty</p>
|
||||
}
|
||||
else
|
||||
{
|
||||
var now = DateTime.UtcNow;
|
||||
<table>
|
||||
<thead><tr><th>Kommando</th><th>Database</th><th>Startet</th><th class="num">Varighed</th><th class="num">Færdig</th><th>Forventet slut</th><th>Login</th></tr></thead>
|
||||
<tbody>
|
||||
@foreach (var o in Operations)
|
||||
{
|
||||
var running = o.IsRunning(now);
|
||||
<tr>
|
||||
<td>@o.Command</td>
|
||||
<td>@(o.DatabaseName ?? "–")</td>
|
||||
<td class="nowrap">@Display.Time(o.StartedAt)</td>
|
||||
<td class="num nowrap">@Duration(running ? now - o.StartedAt : o.Duration)</td>
|
||||
<td class="num">@(running ? $"{Display.Number(o.PercentComplete, 1)} %" : "afsluttet")</td>
|
||||
<td class="nowrap">@(running && o.EstimatedEnd is { } end ? Display.Time(end) : "–")</td>
|
||||
<td class="mono">@(o.LoginName ?? "–")</td>
|
||||
</tr>
|
||||
}
|
||||
</tbody>
|
||||
</table>
|
||||
<p class="muted">Operationer, som SQL Server viser fremskridt for (percent_complete): backup, restore, DBCC, indexvedligehold med REORGANIZE, shrink og rollback. Målt hvert minut; varigheden af afsluttede er til sidst set.</p>
|
||||
}
|
||||
|
||||
@code {
|
||||
[Parameter, EditorRequired] public IReadOnlyList<StoredLongOperation> Operations { get; set; } = [];
|
||||
[Parameter] public string Empty { get; set; } = "Ingen langvarige operationer.";
|
||||
|
||||
private static string Duration(TimeSpan value) => value.TotalHours >= 1 ? $"{(int)value.TotalHours} t {value.Minutes} min" : $"{Math.Max(0, (int)value.TotalMinutes)} min";
|
||||
}
|
||||
95
tests/SQLInsight.Rules.Tests/OperationRuleTests.cs
Normal file
95
tests/SQLInsight.Rules.Tests/OperationRuleTests.cs
Normal file
|
|
@ -0,0 +1,95 @@
|
|||
using SQLInsight.Core.Collection;
|
||||
using SQLInsight.Core.Data;
|
||||
using SQLInsight.Core.Findings;
|
||||
using SQLInsight.Rules.Engine;
|
||||
using SQLInsight.Rules.Performance;
|
||||
using static SQLInsight.Rules.Tests.TestInstances;
|
||||
|
||||
namespace SQLInsight.Rules.Tests;
|
||||
|
||||
public class OperationRuleTests
|
||||
{
|
||||
private static RuleResult Run(IRule rule, RuleContext context) => Assert.Single(new RuleEngine([rule]).Evaluate(context));
|
||||
|
||||
private static LongOperation Backup(DateTimeOffset started, DateTimeOffset seen, string db = "AX") =>
|
||||
new(61, "BACKUP DATABASE", db, @"KUNDE\svc-backup", started, 40, seen.AddMinutes(30), seen);
|
||||
|
||||
/// <summary>Earlier runs of 20, 22, 25, 21 and 60 minutes (median 22).</summary>
|
||||
private static LongOperationSnapshot WithHistory()
|
||||
{
|
||||
LongOperationSnapshot? snapshot = null;
|
||||
var day = Now.AddDays(-10);
|
||||
foreach (var minutes in new[] { 20, 22, 25, 21, 60 })
|
||||
{
|
||||
snapshot = LongOperationHistory.Advance(snapshot, [Backup(day, day.AddMinutes(minutes))], day.AddMinutes(minutes));
|
||||
snapshot = LongOperationHistory.Advance(snapshot, [], day.AddMinutes(minutes + 1));
|
||||
day = day.AddDays(1);
|
||||
}
|
||||
|
||||
return snapshot!;
|
||||
}
|
||||
|
||||
[Fact]
|
||||
public void History_keeps_finished_runs_per_command_and_database()
|
||||
{
|
||||
var snapshot = WithHistory();
|
||||
|
||||
Assert.Equal(5, snapshot.History["BACKUP DATABASE|AX"].Count);
|
||||
Assert.Equal(TimeSpan.FromMinutes(22), LongOperationHistory.Median(snapshot, Backup(Now, Now)));
|
||||
Assert.Null(LongOperationHistory.Median(snapshot, Backup(Now, Now, "Andet")));
|
||||
}
|
||||
|
||||
[Theory]
|
||||
[InlineData(40, RuleOutcome.Passed)] // under 2 × 22
|
||||
[InlineData(50, RuleOutcome.Findings)]
|
||||
public void Backups_running_more_than_twice_the_median_are_found(int minutes, RuleOutcome expected)
|
||||
{
|
||||
var running = WithHistory() with { CapturedAt = Now, Running = [Backup(Now.AddMinutes(-minutes), Now)] };
|
||||
|
||||
var result = Run(new SlowBackupRule(), With(running));
|
||||
|
||||
Assert.Equal(expected, result.Outcome);
|
||||
if (expected == RuleOutcome.Findings)
|
||||
{
|
||||
var finding = Assert.Single(result.Findings);
|
||||
Assert.Equal(Severity.Medium, finding.Severity);
|
||||
Assert.True(finding.Evidence.Single(e => e.Name == "Login").Sensitive);
|
||||
}
|
||||
}
|
||||
|
||||
[Fact]
|
||||
public void Other_operations_and_unknown_history_are_not_judged()
|
||||
{
|
||||
var dbcc = new LongOperation(62, "DBCC", "AX", null, Now.AddHours(-5), 10, null, Now);
|
||||
var snapshot = new LongOperationSnapshot { CapturedAt = Now, Running = [dbcc, Backup(Now.AddHours(-5), Now, "Ny")] };
|
||||
|
||||
Assert.Equal(RuleOutcome.Passed, Run(new SlowBackupRule(), With(snapshot)).Outcome);
|
||||
}
|
||||
|
||||
private static CumulativeSample<QueryStatsSnapshot, QueryStatsDelta> Queries(double threshold, params QueryStat[] queries) => new(
|
||||
new QueryStatsSnapshot { CapturedAt = Now, ServerTime = Now.UtcDateTime, SqlServerStartTime = Now.UtcDateTime.AddDays(-3), Queries = queries, ActivityThresholdPercent = threshold },
|
||||
null);
|
||||
|
||||
private static QueryStat Statement(string key, double hours, double cpuSeconds) => new()
|
||||
{
|
||||
Key = key, Executions = 1000, WorkerTimeUs = (long)(cpuSeconds * 1_000_000), ElapsedTimeUs = 0, LogicalReads = 0, PhysicalReads = 0, LogicalWrites = 0,
|
||||
CreatedAt = Now.UtcDateTime.AddHours(-hours), LastExecutionAt = Now.UtcDateTime.AddMinutes(-1), Text = "SELECT * FROM INVENTSUM",
|
||||
};
|
||||
|
||||
[Fact]
|
||||
public void A_statement_using_more_than_half_a_core_for_hours_is_found()
|
||||
{
|
||||
var busy = Statement("0xBUSY", 4, 4 * 3600 * 0.8); // 80 %
|
||||
var calm = Statement("0xCALM", 4, 4 * 3600 * 0.2); // 20 %
|
||||
var young = Statement("0xNEW", 0.5, 1800); // 100 %, but only half an hour
|
||||
|
||||
var result = Run(new ConstantActivityRule(), With(Queries(50, busy, calm, young)));
|
||||
|
||||
var finding = Assert.Single(result.Findings);
|
||||
Assert.Equal("query: 0xBUSY", finding.Subject);
|
||||
Assert.DoesNotContain("INVENTSUM", finding.Title, StringComparison.Ordinal);
|
||||
Assert.True(finding.Evidence.Single(e => e.Name == "Sætning").Sensitive);
|
||||
Assert.Equal(RuleOutcome.Passed, Run(new ConstantActivityRule(), With(Queries(90, busy))).Outcome); // configurable
|
||||
Assert.InRange(busy.ActivityPercent!.Value, 79, 82);
|
||||
}
|
||||
}
|
||||
|
|
@ -18,6 +18,6 @@ public class RuleCatalogTests
|
|||
[Fact]
|
||||
public void Rule_count()
|
||||
{
|
||||
Assert.Equal(64, BuiltInRules.Create().Count);
|
||||
Assert.Equal(66, BuiltInRules.Create().Count);
|
||||
}
|
||||
}
|
||||
|
|
|
|||
Loading…
Add table
Reference in a new issue