[ad_1]
It started off as a simple change: I was annoyed that the “Observed Timeline” in the output from the Get-AutopilotDiagnosticsCommunity (and the older Get-AutopilotDiagnostics script too) had events in the wrong order. For example, it would show that app #2 had started downloading before app #1 had finished, but that’s not what Intune Management Extension ever does. The reasoning for this was pretty simple: the output is sorted by the time stamp, but the time stamp is based on when ESP observed the change in state, and it typically sees both of those at the exact same time because it’s polling “every so often” (measured in seconds, not minutes — there was some more-complex logic involved in the exact frequency).
As a quick fix for that problem, I just added one simple line of code to artificially change the “Downloading / Installing” event to be one second later (the times aren’t exact anyway) so the order ends up as expected:
And that’s where I entered the rabbit hole: “while I’m here” I’ll look at a few other enhancements. First, I wanted the MSI install details, including the actual name of the MSI being installed without always having to specify “-online” to look it up from Intune. When not using log files, that’s easy enough to pull from the registry, so now I see what I’m installing:
But that also reminded me that MSIs install differently from Win32 apps: the Desktop App CSP will download install files in parallel and then kick off the installs when each one finishes, but will only install one at a time. That’s how you end up with sequences like this:
Two downloads started in parallel, the first finishes and starts installing, the second finishes, and then the second installs after the first finishes installing. It’s really quite well done, making the best use of time by downloading and installing in parallel.
But that then pointed out a limitation in the Win32 app (Intune Management Extension, a.k.a. IME) details: It only shows a single “Downloading / Installing” event so you don’t know how much time is spent downloading and how much is spent installing. That sort of makes sense because we’re seeing the details from the perspective of the ESP, not from IME. And getting that detail from IME would require parsing logs (which can be done with something like Petri’s script if you want to).
What I really want to see is the Delivery Optimization download details which show the download starting and finishing. That’s available (at least with newer Windows 10 and 11 builds) via the Get-DeliveryOptimizationLog cmdlet, looking for events related to IME downloads (since IME uses DO, unlike the Desktop App CSP which uses BITS). So I added logic to merge that in:
But you remember the problem I originally had wanted to solve with the ordering of events? Well, this reintroduced it, and there was no simple solution to fix that so I just left it that way. The basic problem: the ESP events are approximate (since it’s based on polling for the current status) while the DO events are exact, and fudging them to make them line up in order is a bit messy. But it’s safe to say that in the above example the “Downloading / Installing” event at 01:09:37 actually occurred before the “DO DownloadStart” event at 01:09:33, but ESP didn’t see that. That really means that IME really started working on the app closer to 01:09:33. So yes, things can be off a few seconds.
OK, but why did I want to see that information again? So that I could see how much time was spent downloading versus installing. We can pretty much get the exact download times (the delta between the “DO DownloadStart” and “DO DownloadCompleted” events for a particular app), and we can get approximate total times (the delta between the “Downloading / Installing” and “Success / Installed” events, again somewhat inaccurate because it’s when ESP sees these status changes), so we can then figure out how much time was spent executing by looking at the difference between the two.
Let’s look at this as an example:
We’ll ignore the “out of order” success event for the app that ends with _11 and focus on the events for app _15. We can calculate that:
- The “real” start time was 01:09:33.
- The download completed at 01:09:45, so it took 12 seconds. (Yes, it’s not a big app — it’s the “UpdateOS” script.)
- The execution completed somewhere around 01:24:26 (perhaps a little earlier), so it took just under 15 minutes to install. (Yes, that’s a long time, but in this case it was installing Windows updates.)
It’s worth noting that IME doesn’t do what the Desktop App CSP does: It doesn’t work in parallel, so it will download app #1, install app #1, download app #2, install app #2, etc. That’s unfortunate because it makes the whole installation time longer — it could be downloading the next app while installing the previous one, but there’s no logic to do that.
One last “while I’m at it” change: I changed the “Sidecar” app name in the timeline output to instead display the “real” name, so you’ll now see “Intune Management Extension”:
Try it out and see what you think. And thanks again to Andrew Taylor for quickly merging the changes into his GitHub repo, signing the module, and getting it published to the PowerShell Gallery faster than I could even write up the details about what I changed 🙂
[ad_2]
Source link
