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

Originator:michalm.mac
Number:rdar://FB8940785 Date Originated:15.12.2020
Status:Open Resolved:
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


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!