I’ve posted quite a few blogs talking about troubleshooting Windows Autopilot (such as this one), with some additional posts (three separate ones here, here, and here) talking about a script named Get-AutopilotESPStatus that can help display information about what went on during an Autopilot provisioning process.  While initial versions of that script were designed to read information from the device itself, later versions added logic to extract information from a CAB file created by the standard “MDMDiagnosticsTool.exe -area Autopilot -cab c:\autopilot.cab” command line.  Even with that, I found myself still digging through more of the logs to figure out the timeline of events.  So back to Visual Studio Code to make some additional enhancements.

By the time I was done, it felt like the script went beyond the original name, so I’ve posted a new version under a new name:  Get-AutopilotDiagnostics.  (I’ll leave the old one around for a little while, but this one will replace it.)  So let’s go through an example execution, first for a user-driven Azure AD Join scenario.  The script can be installed directly from the PowerShell Gallery and then executed (make sure you enable script execution with “Set-ExecutionPolicy Bypass” or equivalent first).  Since I included the “-online” switch, it will retrieve details about the app and policy names from Intune using Graph API, just to make the later output more useful.

The first section of output provides details about the device, tenant, and Autopilot profile. 

After that, summary information about the items tracked by the Enrollment Status Page are displayed, broken down between device ESP (tracking device-targeted apps, certs, and policies during OOBE) and user ESP (tracking user-targeted apps, certs, and policies after the user has signed in).

Next is a new timeline view, showing not only ESP details but also important events from the process:

So you can see when the Autopilot profile was downloaded to the machine (right after internet connectivity was established), when the MDM enrollment completed (right after the user entered their Azure AD credentials in this case), the installation details for Intune Management Extensions (IME, a.k.a. sidecar), and then the tracking information for everything else.  A few points to call out on that:

• The times for profile download, sidecar installation, and (in Hybrid Azure AD Join cases) ODJ blob acquisition (more on that later) are exact times from event logs, while the times for the rest of the items are what ESP observed.  Since ESP isn’t watching real-time (it polls every so often), these times aren’t exact to the second, but they do give you a decent idea as to the ordering and progress of the various items.
• Notice how sidecar started to install about 39 seconds after the MDM enrollment?  The instructions for that came from the initial Intune MDM sync, along with plenty of other policies.  (For example, Office would have started installing at the same time.)  But we’re still in the “Device preparation” phase, waiting for “Preparing the device for mobile management” – that really means “waiting for IME to provide a list of Win32 apps to track.”  See this blog for more details on that.
• See the “Policy …EntDMID” line?  That’s really the point where the “Device setup” phase starts and ESP has started tracking.  So we know at that point that Intune and IME have provided ESP the list of items to track.  Since this is a “dummy” policy that is set right after enrollment, it is marked as “complete” immediately as ESP starts checking.
• See the gap in time between 21:17 and 21:24?  That’s the transition from device ESP to user ESP, where the time was spent first showing the first sign-in animation (FSIA) and then waiting for a list of user policies from Intune and IME. 

So if you do some math based on those results, you can see how long the process took:

• From enrollment through “Device preparation” took about 13 minutes.
• From “Device setup” (ESP tracking) through the end of OOBE took about 4.5 minutes.
• From user sign-in (which happened automatically) to the desktop took about 7 minutes.  (We think we can make that faster, more on that in a future blog.)

Let’s look at a similar result from a user-driven Hybrid Azure AD Join scenario, first with the summary details:

There are two additional lines at the bottom, which indicate that the device has already received an offline domain join blob (a good sign that your ODJ Connector processed a request, created a computer account, provided the details to Intune, and then that the device received those details from Intune), and that the new “Skip connectivity check” option (see this blog for details on that) was enabled.

And then the timeline includes more details on the offline domain join (ODJ) process:

So you can see when the device started waiting for the ODJ blob (relayed by Intune, from the ODJ connector), and when it was received and applied.  Only after that happens will the device reboot, display the ESP, and begin processing apps, certs, and policies.  So we can do similar time calculations here:

• It took just over a minute after the MDM enrollment to receive the ODJ blob.  The computer would have then rebooted almost immediately after that.
• There was then an almost 15-minute delay after the reboot before any additional policies were received from Intune, hence the installation of sidecar was delayed for that long as well.  (Yes, we’re working on eliminating that delay.)
• From when the “Device setup” phase started (with the EntDMID completion) to the end of device ESP took 10 minutes.  (This is a Hybrid Azure AD Join device where user ESP was disabled, hence no user ESP items are seen in the timeline).

One final thought on this to wrap up.  I was testing out this script with some logs sent to me by a customer (captured using the MDMDiagnosticsTool) and noticed an interesting output (with customer-specific identifiers erased):

See the problem?  The MDM enrollment and ODJ steps happened *after* everything else completed.  Obviously that’s impossible as the device can’t apply policies and install apps prior to being MDM enrollment or joined to AD.  So what happened?  Simple, the time changed because the real-time clock on the device was off by three hours (fairly common when you reimage a device, e.g. placing a PST [-8] image on a device that was running in EST [-5]).  As soon as the ODJ blob was applied, a time sync was forced (since Kerberos is very time-sensitive), and that fixed the clock, shifting it back three hours.  So to read through that timeline you need to remember that those 14:43 times were really 11:43 (matching up with the profile download, which recorded the *server* time that the profile was downloaded, not the client time).  More on that in a future blog as well (as if I don’t have enough blog posts about time and time zones).