InstallEnterpriseApplication package install gets cancelled when Setup Assistant is completed too quickly

Originator:michalm.mac
Number:rdar://FB8940785 Date Originated:15.12.2020
Status:Closed Resolved:Potential fix identified - In macOS 11.4
Product:macOS Product Version:11.1 (20C69)
Classification:Incorrect/Unexpected Behavior Reproducible:Always
 
Basic Information
Which area are you seeing an issue with?
Installation/Setup/Migration/Recovery
Please provide a descriptive title for your feedback:
InstallEnterpriseApplication package install gets cancelled when Setup Assistant is completed too quickly
What type of issue are you reporting?
Incorrect/Unexpected Behavior
Details
What does the installation/setup/migration/recovery issue you are seeing involve?
First boot after installation
What build of macOS were you upgrading from?
None. Fresh install of 11.1 (20C69)
What time was it when this last occurred? (Example: 12:00 pm EST 02/14/2018)
10:00 am CET 12/15/2020
Description
Please describe the issue and what steps we can take to reproduce it:
# Problem

We are testing Automated Device Enrollment with macOS 11.X Big Sur. Our MDM sends two InstallEnterpriseApplication commands right after the enrollment (before DeviceConfigured command) in the Remote Management pane of the Setup Assistant. Goal is to install two packages (33MB and 98MB). 

We encountered a problem where package installation gets cancelled and not a single one of these packages is installed.

# Reproducibility

I can reproduce this issue at will on a physical Mac (MacBook Air I am reporting from) or VMware Fusion VM. Issue occurs on both macOS public releases:

- 11.1 (20C69)
- 11.0.1 (20850)

# Steps to reproduce

There are video attachments where I reproduce this.

1. Prepare DEP cloud profile for device. All SetupAssistant panes are to be skipped except for the Create Computer Account and Location Services steps.
2. Erase the Mac and install macOS 11.1 (20C69) or 11.0.1 (20850). 
3. Boot up the Mac. Setup Assistant in presented.
4. Set Country or Region to Czechia (This might be very important since it initiates the locale change (to cs_CZ))
5. Hit "Continue on Written" and Spoken languages pane
6. Hit "Not Now" on Accessibility pane
7. Hit "Continue" on Remote Management pane. Classic (HTTP DIGEST) authentication is required
8. On Create a Computer Account pane all fields (except Hint) are prefilled (usernames from MDM, password by SetupAssistant since it knows it from previous step). Hit "Continue" (It is important to Hit continue as quickly as possible since the problem is time sensitive)
9. Location service pane is presented. Enable the location services and continue.
10. User is automatically logged into his account

Note: In my testing the problem occurs when I complete these steps as quickly as possible. Especially the step (8) Create c Computer Account. More on that later in Leads section.

# Expected result

Both packages sent via InstallEnterpriseApplication command get installed

# Actual result

1. Packages sent via InstallEnterpriseApplication are successfully downloaded to the cache directory /var/folder/zz/<randomstring>/C/com.apple.appstore/<UUID>/<UUID>.pkg,
2. Installation of first package is started. See in the /var/log/install.log:

> 2020-12-15 01:18:32-08 MacBook-Air installd[433]: PackageKit: ----- Begin install -----
> 2020-12-15 01:18:32-08 MacBook-Air installd[433]: PackageKit: request=PKInstallRequest <1 packages, destination=/, MDMManagedAppInstall=YES>
> 2020-12-15 01:18:32-08 MacBook-Air installd[433]: PackageKit: packages=(
	    "PKLeopardPackage <id=cz.logicworks.installapplications-logicworks-testing, version=2.2.0, url=file:///var/folders/zz/zyxvpxvq6csfxvn_n0000044000011/C/com.apple.appstore/07D77A4E-40E8-45B3-9D67-757C0D6E18D4/85225076-2ec7-42e2-ac93-cdd816d0dcdd.pkg#InstallApplications_LogicworksTesting-2.2.0.pkg>"

3. Installation of the first package gets cancelled. /var/log/install.log says:

> 2020-12-15 10:19:15+01 Johns-MacBook-Air installd[433]: PackageKit: Cleared responsibility for install from 775.
> 2020-12-15 10:19:15+01 Johns-MacBook-Air installd[433]: PackageKit: Failed to get responsibility for client 775. Will skip Installer.app check.
> 2020-12-15 10:19:16+01 Johns-MacBook-Air installd[433]: PackageKit: ----- Cancelled install -----

4. Installation of the second package is not even attempted. No mention of it in install.log.

# Workaround

- (100%) Do not complete the Create a Computer Account pane and wait until packages are installed. 
- (Most of time) Do ~10 second pause before completing the Create a Computer Account pane. Packages usually get installed if user does not advance quickly through this pane quickly. 

# Leads
## appstored stopped due to locale change

I think this is a root cause of the problem. At least if I read logs correctly.

There is this error in the system log:
> 2020-12-15 01:18:50.185966-0800 0x20db     Error       0x0                  775    14   appstored: [com.apple.appstored:Daemon] Received locale change, stopping appstored

When this happens during the early stage of the package install, install gets canceled. "Received locale change, stopping appstored" happens right after the Create a Computer Account pane. If there is a another pane after the Create a Computer Account for example Location Services problem happens during the transition in between these two.

When you compare /var/log/install.log and appstored output to system log you can see PID (775) is the same in both logs.

Let’s recap what’s happening

1. On Remote Management pane, Mac receives the InstallEnterpriseApplication commands and begins downloading the packages in the background and then installs them. appstored is critical process involved in this.
2. Right after Create computer account pane locale change is initiated which results in stopping the appstored.
3. If timing is correct (user is very fast) package install is cancelled possible due to the appstored stopping.

## Software update

macOS is also installing MRT and XProtect packages during the Setup Assistant. In my testing I leave them to be installed before the MDM enrolment on Remote Management pane so these installs don’t interfere.
File Uploads
11.0.1_install_works_with_different_user_timing.mov
97.49 MB Dec 15, 2020 at 10:59 AM
sysdiagnose_2020.12.15_10-33-26+0100_macOS_MacBookAir8-1_20C69.tar.gz
115.59 MB Dec 15, 2020 at 10:59 AM
11.0.1_install_gets_cancelled.mov
84.86 MB Dec 15, 2020 at 10:59 AM
11.1_install_gets_cancelled.mov
84.25 MB Dec 15, 2020 at 10:59 AM
all_log.txt
49.11 MB Dec 15, 2020 at 10:59 AM
System_Profile_full.spx
4.21 MB Dec 15, 2020 at 10:59 AM
Managed Applications.zip
2.03 KB Dec 15, 2020 at 10:59 AM
appstored_log.txt
145.96 KB Dec 15, 2020 at 10:59 AM
install.log
165.67 KB Dec 15, 2020 at 10:59 AM

Comments

11.4 Beta 1 20F5046g fixed the problem

It looks like Apple finally fixed this in 11.4 Beta 1 20F5046g:

• (Beta 1) Setup Assistant no longer skips Location Services when account creation is skipped.

From limited testing I can confirm this. I am going to continue testing until 11.4 final release. If the problem doesn't come back I will consider issue resolved.

By michalm.mac at April 29, 2021, 9:49 a.m. (reply...)

11.3 BETA 20E5172i also affected

A was able to reproduce the issue on macOS 11.3 Beta (20E5172i). It took attempts to reproduce it. During the first attempt it did not occur (<- it’s time sensitive issue as I described in original feedback). On the second attempt problem occurred same way as before.

By michalm.mac at Feb. 5, 2021, 1:39 p.m. (reply...)

11.2 also affected

I am able to reproduce this issue with macOS 11.2 20D64. I would test it with 11.3 beta but full installer is not yet available.

This time: - different computer - Wi-Fi instead of Ethernet - web view Automated Device Enrollment authentication instead of HTTP digest

Key lines in logs: - appstored.log: 2021-02-03 03:52:11.103566-0800 0x1f27 Error 0x0 609 14 appstored: [com.apple.appstored:Daemon] Received locale change, stopping appstored - install.log: 2021-02-03 03:52:12-08 Michal-MacBook-Pro installd[617]: PackageKit: Failed to get responsibility for client 609. Will skip Installer.app check. 2021-02-03 03:52:12-08 Michal-MacBook-Pro installd[617]: PackageKit: ----- Cancelled install

By michalm.mac at Feb. 3, 2021, 12:07 p.m. (reply...)

Please note: Reports posted here will not necessarily be seen by Apple. All problems should be submitted at bugreport.apple.com before they are posted here. Please only post information for Radars that you have filed yourself, and please do not include Apple confidential information in your posts. Thank you!