We are seeing an issue with login delays for users, whereby it sometimes takes many minutes for a user to be presented with a desktop.
As part of troubleshooting this issue, I'd like to create a KQL query that will generate data showing the amount of time that passes from a user clicking the relevant hostpool icon to getting to a desktop. Reading the following MS article Monitor Azure Virtual Desktop glossary - Azure | Microsoft Learn I've gained some understanding on the logon stages and how information is logged.
Amending scripts I've found on the web, I'm able to generate a report which shows login times :
WVDConnections
| where Type =~"WVDConnections" and State =~ "Started"
| project SessionHostName , UserName ,CorrelationId, TimeLogonStarted=TimeGenerated
| join kind = leftsemi
(
// Only include connections that actually reached the host to prevent short (failed) attempts from skewing the data
WVDCheckpoints
| where Source == "RDStack"
and Name == "RdpStackConnectionEstablished"
)
on CorrelationId
| join kind= leftouter (
WVDCheckpoints
) on CorrelationId
| extend DurationFromLogon=datetime_diff("Second",TimeGenerated, TimeLogonStarted)
| where Name=~"ShellReady"
// exclude diviations where ShellReady occurs at start of WVDCheckPoints
and TimeGenerated > TimeLogonStarted
| project UserName, SessionHost=SessionHostName, TimeLogonStarted, TimeLogonEnded=TimeGenerated, DurationFromLogon
| order by SessionHost, TimeLogonEnded desc
Within AVD Monitoring, under the Connection Performance section of Insights, there is a section for the Top 20 instances of highest time to connect. I've amended the KQL of this to show all connection times within a time period:
let newSessions = {NewSessions};
WVDConnections
| where _ResourceId =~ "{HostPool}"
| as ConnectionData
| where State == "Started"
| where TimeGenerated {timedrilldown}
| join kind = leftsemi
(
// Only include connections that actually reached the host to prevent short (failed) attempts from skewing the data
WVDCheckpoints
| where Source == "RDStack" and Name == "RdpStackConnectionEstablished" and _ResourceId =~ "{HostPool}"
) on CorrelationId
| join kind=leftsemi // remove connections that do not have LogonDelay as we cannot show details
( WVDCheckpoints
| where _ResourceId =~ "{HostPool}" and Name == "LogonDelay"
| extend LogonType = tostring(Parameters.LogonType)
| where (newSessions and LogonType == "DirectSession") or (not(newSessions) and LogonType =="TemporarySession")
| project LogonDelay= TimeGenerated, CorrelationId
) on CorrelationId
| join kind = leftsemi
(
WVDCheckpoints
| where _ResourceId =~ "{HostPool}"
| where Name == "LoadBalancedNewConnection"
| extend LoadBalanceOutcome=Parameters.LoadBalanceOutcome
| where (newSessions and LoadBalanceOutcome == "NewSession") or (not(newSessions) and LoadBalanceOutcome in ('Disconnected', 'Active'))
) on CorrelationId
| join kind = inner
(
WVDCheckpoints // new session
| where newSessions
| where _ResourceId =~ "{HostPool}"
| where Name =~ "ShellReady" or
( Name =~ "LaunchExecutable" and Parameters.connectionStage == "RdpShellAppExecuted" or Name=~"RdpShellAppExecuted")
| project ProductiveTime=TimeGenerated, CorrelationId
| summarize ProductiveTime=min(ProductiveTime) by CorrelationId
| union (
ConnectionData // existent Sessions
| where not(newSessions)
| where State == "Connected"
| project ProductiveTime=TimeGenerated, CorrelationId
)
) on CorrelationId
| join kind = leftouter
(
WVDCheckpoints
| where _ResourceId =~ "{HostPool}"
| where Name =~ "OnCredentialsAcquisitionCompleted"
| project CorrelationId, credaquire = Parameters.DurationMS
//OnCredentialsAcquisitionCompleted 2021-09-13T16:48:50.4440000Z Client {"CredentialType":"SavedPassword","DurationMS":"9","Success":"True"}
) on CorrelationId
| join kind = leftouter
(
WVDCheckpoints
| where _ResourceId =~ "{HostPool}"
| where Name =~ "SSOTokenRetrieval"
| project CorrelationId, ssotokeretrieval = Parameters.DurationMS
) on CorrelationId
| extend ProductiveTime = (ProductiveTime - TimeGenerated) / 1s - (coalesce(credaquire,0)/1000) - (coalesce(ssotokeretrieval,0)/1000)
| where ProductiveTime > 0
| project UserName, TimeGenerated, Hostname = trim_end("[.].*", SessionHostName), ProductiveTime, CorrelationId
| order by TimeGenerated
However, reviewing the data generated by the above queries, there are inconsistencies between the data that is returned.
For example, the first KQL query will return user logins that are not shown in the AVD Insights KQL.
Could anyone advise on why this may be, or perhaps someone has some KQL that achieves my aim?
