Guest blog post by Guy Leech
The Script Engine that got me excited
I’ve been working as a techie in the EUC arena for over 23 years with a background before that as a software developer. I now work as a freelance consultant, with a particular penchant for troubleshooting and automation. So, when the guys at Controlup approached me about their vision to enhance the script based engine in their real time console, I was excited to take a key role in this project.
In case you’re not aware, the ControlUp Real-time Console can easily be extended via scripts allowing you to perform many additional queries and actions from within the ControlUp console, rather than having to switch to other tooling. This powerful capability is useful for troubleshooting, root cause analysis and in automation use cases.
I’ll write more about my work in this project in future blogs but for now it suffice to say that we are aiming to make the script based engine that is an integral part of ControlUp; smarter, more contextual and with a wide range of scripts execution modes that include manual, assisted and automatic execution for a single or multiple targets at a time.
As part of the project, I was challenged with the task of taking the beloved “Analyze Logon Duration” script that was mentioned here in the past, a very successful and popular script (as evident by the more than 15,000 downloads in the last 2.5 years) and make it even better.
After reviewing the script I decided to focus on a few improvements which I hope anyone of the thousands of regular users of the script would appreciate:
- Performance enhancements,
- Reliability enhancements and with a view to speeding it up and making it more reliable.
Fundamentally, the script works by pulling various related events from event logs in order to determine the duration of phases within the logon as well as the overall logon duration.
VE Analyze_Logon_Duration.ps1 (download link)
- The existing script performed the event log lookups sequentially so a quick win in terms of performance improvement was to make as many of these as possible run at the same time, i.e. in parallel. When security event logs get large, this drastically reduces the time to run the script – by as much as 50%. Running things in parallel can be achieved in PowerShell using a feature called RunSpaces which are a little more involved to use than Jobs, which are built into PowerShell, but their initialisation time is much quicker than Jobs which is why I used them.
In the example screenshot below, the upper window shows the results from the new script and the lower one from the original. We can see that exactly the same results are displayed but the updated script completed in 26 seconds compared with 37 seconds which in this particular instance is 30% faster.
- The specific events in the security event log that are used to time the various logon phases were cached in memory and the queries used to subsequently find the required events from this cache were optimised.
A number of changes to increase reliability were made, which resulted in improved performance too:
- Originally, an instance of event id 4624 (“An account was successfully logged on”) in the security event log for the user being queried was searched for. However, if a user disconnects and subsequently reconnects, this event is also logged which then causes the script to fail since the original logon time cannot be determined. The authoritative logon time can be obtained from LSASS (Local Security Authority Subsystem Service) which can be accessed via the win32_logonsession and win32_loggedonuser WMI/CIM classes. I therefore changed the script to cross reference instances of these classes to obtain the definitive logon time for the user so all event log searches are then relative to the time of this event. This also speeds up the script as the CIM query is generally much faster than an event log search.
- In addition to the above, it was observed that an event id 21 (“Remote Desktop Services: Session logon succeeded:”) in the TerminalServices-LocalSessionManager event log was logged when a user logged on so this event was used in place of the 4624 one from the security event log.
Better Error Reporting
It was reported that the original script would occasionally fail but without giving much in the way of detail as to the cause. Therefore, the following enhancements were made:
- If security events are not found then the date and time of the earliest event available is displayed as the failure, if auditing is enabled, is likely to be because the security event log has been overwritten, due to becoming full, after the user being queried logged on.
- The script requires that the following auditing is enabled:
- Process Creation
- Process Termination
If that is not the case then various event log queries will fail. The script, in the errors tab, will show what required auditing, if any, is not enabled.
It has been observed that sometimes the Local Security Policy tool (secpol.msc) reports that logon auditing is not enabled and yet logon events, id 4624, are raised in the Security event log and conversely it can also show that logon auditing is not enabled and logon events are not written to the Security event log. Group Policy Objects can affect this behaviour but the best way to check auditing settings for logon is to run the following command as an elevated user on the system where the SBA is to run, which is how the SBA checks these settings:
auditpol /get /category:logon/logoff
Citrix Virtual Desktops (formerly XenDesktop) Query
Another capability of the original script is to query a Citrix Virtual Apps and Desktops Delivery Controller to get additional Citrix session details, such as the brokering time, when credentials are specified on invocation of the SBA. These are required as SBAs run as local system on the targeted machine(s) which would not generally have Delivery Controller access:
However, the results output from this could be a little confusing as it intimated that the logon was longer than it was as it was calculating the logon duration as the total time from when the application or desktop icon was clicked in StoreFront/Receiver rather than the actual Windows portion of the logon. The code was therefore refactored so that the information obtained from the Delivery Controller is displayed before the logon information as can be seen below where the upper window is produced from the updated script and the lower from the original script:
Special Auditing Settings to Stop Event Log Flooding
On some Windows 10 and Server 2016 platforms, it has been observed that the security event log gets swamped with large numbers of event id 4703 instances (“A user right was adjusted”) after the audit settings were changed (in order for the script to be able to find the required logon and process creation and termination events).
A workaround for this was found which was to leave the top-level audit policies set to “no auditing”:
And then to set the following in the advanced audit policy settings:
We have received lots of feedback from many of you on the script based engine and this advanced logon duration script. This feedback is helping us to continually make this script more useful and powerful to troubleshoot and fix real world issues in Citrix environments. To see how this script can help you, please click on the link below and download it for your Citrix environment.
VE Analyze_Logon_Duration.ps1 (download link)
I wrote my first (Basic) program in 1980, was a Unix developer after graduation from Manchester University and then became a consultant, initially with Citrix WinFrame, in 1995 and later into Terminal Server/Services and more recently virtualisation. I have also had various stints in Technical Pre-Sales, Support and R&D. I work as an independent consultant, scripter and trainer, live in West Yorkshire, England; have a wife, three children and three dogs and am a keen competitive runner when not injured.
Citrix TechBytes – Created by Citrix Experts, made for Citrix Technologists! Learn from passionate Citrix Experts and gain technical insights into the latest Citrix Technologies.
Want specific TechBytes? Let us know! firstname.lastname@example.org