Error formatting NTFS when trying to restore image with a package

#1

I’m running into issues restoring a Windows 10 1809 bootcamp image from a 2018 Mac mini to a 2018 MBP.
I’ve created the image using the latest version of winclone on the Mac mini, then created a package and copied it over to the MBP. When I run the package it fails after about a minute. It looks like the issue is The volume could not be formatted as NTFS. Check the drive and try again.

I don’t really know why. The MBP is running 10.14.4 and has an APFS filesystem. I have tried the package several times.

Here are the logs
Executing script “./postflight” in /2019Lab_nosysprep.pkg/Contents/Resources
2019-05-10 11:22:21-04 BID27319 installd[481]: ./postflight: Creating or discovering bootcamp partition
2019-05-10 11:22:21-04 BID27319 installd[481]: ./postflight: Mode: Create Partition
2019-05-10 11:22:21-04 BID27319 installd[481]: ./postflight: checking for existing bootcamp partitions…
2019-05-10 11:22:21-04 BID27319 installd[481]: ./postflight: checking for core storage…
2019-05-10 11:22:21-04 BID27319 installd[481]: ./postflight: / is not a CoreStorage disk
2019-05-10 11:22:21-04 BID27319 installd[481]: ./postflight: checking for apfs…
2019-05-10 11:22:21-04 BID27319 installd[481]: ./postflight: Selected volume is apfs
2019-05-10 11:22:21-04 BID27319 installd[481]: ./postflight: checking size…
2019-05-10 11:22:22-04 BID27319 installd[481]: ./postflight: Making sure that the partition to split is JHFS+ or APFS
2019-05-10 11:22:22-04 BID27319 installd[481]: ./postflight: Filesystem is Journaled HFS+, core storage or apfs so we are good to try and split it…
2019-05-10 11:22:22-04 BID27319 installd[481]: ./postflight: Converting percentage from 50% to 50/100
2019-05-10 11:22:22-04 BID27319 installd[481]: ./postflight: New Mac size is 249981587456b
2019-05-10 11:22:22-04 BID27319 installd[481]: ./postflight: creating from APFS
2019-05-10 11:22:22-04 BID27319 diskmanagementd[350]: diskmanagement: [DMToolMountMisc DAOperation_performsync:disk:options:mountpoint:arguments:asEUID:asEGID:timeoutSec:dissenter:dissenterPID:]: [un]mount failed: err=-69888 un0mt1=0 timeout=0 dissenter=1 dissenterpid=0 dissenterstatus=-119930878=0xf8da0002
2019-05-10 11:22:22-04 BID27319 diskmanagementd[777]: diskmanagement: rawLaunch: execve(2) pid=777 /System/Library/Filesystems/apfs.fs/Contents/Resources/fsck_apfs -n -x -l -S /dev/disk0s2 .
2019-05-10 11:22:35-04 BID27319 diskmanagementd[350]: diskmanagement: rawLaunch_block_invoke: waitpid(2) pid=777 ret/errno=777/35 status=0x00000000 exit=0
2019-05-10 11:23:06-04 BID27319 diskmanagementd[350]: diskmanagement: [DMToolPartitionMap editMapAtPartition:newSize:mode:optionSize:newEntriesRequested:formatNewEntries:newEntriesCreated:lmbrOption:percentBegin:percentEnd:partitionDataDelegate:]: inSliceDisk=0x7f87477078f8=disk0s2 inPct=81…92 inNewSize=249981587456(B)=488245288(S) inMode=Normal inOptionSize=0(B)=0(S) inNewEntriesRequested=(
{
Erase = 0;
Existed = 0;
FilesystemName = “MS-DOS”;
Name = DOS;
Newfs = 1;
Size = 0;
}
) inFormatNewEntries=1 inLMBROption=(null) inDelegate=(null)
2019-05-10 11:23:06-04 BID27319 diskmanagementd[814]: diskmanagement: rawLaunch: execve(2) pid=814 /System/Library/Filesystems/msdos.fs/Contents/Resources/newfs_msdos -v DOS /dev/rdisk0s3 .
2019-05-10 11:23:07-04 BID27319 diskmanagementd[350]: diskmanagement: rawLaunch_block_invoke: waitpid(2) pid=814 ret/errno=814/35 status=0x00000000 exit=0
2019-05-10 11:23:07-04 BID27319 diskmanagementd[350]: diskmanagement: [DMToolPartitionMap editMapAtPartition:newSize:mode:optionSize:newEntriesRequested:formatNewEntries:newEntriesCreated:lmbrOption:percentBegin:percentEnd:partitionDataDelegate:]: outErr=0 outNewEntriesCreated=(
disk0s3
)
2019-05-10 11:23:07-04 BID27319 installd[481]: ./postflight: Completed resizing. New device is /dev/disk0s3
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: whole disk is disk0
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: ================================================================================
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: Restoring… Progress log is at /tmp/winclone_package.log
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: ================================================================================
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: checking to see if partition /dev/disk0s3 exists
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: Filesystem is msdos so we are good to restore to it…
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: 2019-05-10 11:23:08.221 winclone[836:8703] Starting Winclone command line tool…
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: 2019-05-10 11:23:08.221 winclone[836:8703] Showing disk info
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: /dev/disk0 (internal):
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: #: TYPE NAME SIZE IDENTIFIER
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: 0: GUID_partition_scheme 500.3 GB disk0
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: 1: EFI EFI 314.6 MB disk0s1
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: 2: Apple_APFS Container disk1 250.0 GB disk0s2
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: 3: Microsoft Basic Data DOS 250.0 GB disk0s3
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: /dev/disk1 (synthesized):
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: #: TYPE NAME SIZE IDENTIFIER
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: 0: APFS Container Scheme - +250.0 GB disk1
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: Physical Store disk0s2
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: 1: APFS Volume Macintosh HD 101.0 GB disk1s1
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: 2: APFS Volume Preboot 44.2 MB disk1s2
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: 3: APFS Volume Recovery 1.0 GB disk1s3
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: 4: APFS Volume VM 1.1 GB disk1s4
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: 2019-05-10 11:23:08.305 winclone[836:8703] Showing SIP info
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: System Integrity Protection status: disabled.
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: 2019-05-10 11:23:08.317 winclone[836:8703] Mac identifier is MacBookPro15,1
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: 2019-05-10 11:23:08.317 winclone[836:8703] The image contains an Windows 8 or later
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: 2019-05-10 11:23:08.317 winclone[836:8703] Based on Model identifier, this Mac can boot Windows in EFI mode
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: 2019-05-10 11:23:08.317 winclone[836:8703] Setting EFI Bootable
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: 2019-05-10 11:23:08.317 winclone[836:8703] WIM-based image detected.
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: 2019-05-10 11:23:08.317 winclone[836:8703] Using volume label of “BOOTCAMP”
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: 2019-05-10 11:23:08.317 winclone[836:8703] Unmounting /dev/disk0s3
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: 2019-05-10 11:23:08.586 winclone[836:8719] Executing “mkntfs --sectors-per-track 63 --heads 255 --partition-start 61107712 --quick -L BOOTCAMP /dev/disk0s3”
2019-05-10 11:23:08-04 BID27319 installd[481]: ./postflight: 2019-05-10 11:23:08.593 winclone[836:8722] ^^^^^^^^Could not open /dev/disk0s3: Resource busy ^^^^^^^^
2019-05-10 11:23:10-04 BID27319 installd[481]: ./postflight: 2019-05-10 11:23:10.624 winclone[836:8703] Mounting /dev/disk0s3
2019-05-10 11:23:10-04 BID27319 installd[481]: ./postflight: 2019-05-10 11:23:10.760 winclone[836:8703] The volume could not be formatted as NTFS. Check the drive and try again.
2019-05-10 11:23:10-04 BID27319 installd[481]: ./postflight: Failed restoring to /dev/disk0s3.
2019-05-10 11:23:10-04 BID27319 install_monitor[738]: Re-included: /Applications, /Library, /System, /bin, /private, /sbin, /usr
2019-05-10 11:23:11-04 BID27319 installd[481]: PackageKit: releasing backupd
2019-05-10 11:23:11-04 BID27319 installd[481]: PackageKit: allow user idle system sleep
2019-05-10 11:23:11-04 BID27319 installd[481]: PackageKit: Cleared permissions on Installer.app
2019-05-10 11:23:11-04 BID27319 installd[481]: PackageKit: Install Failed: Error Domain=PKInstallErrorDomain Code=112 “An error occurred while running scripts from the package “2019Lab_nosysprep.pkg”.” UserInfo={NSFilePath=./postflight, NSURL=file://localhost/2019Lab_nosysprep.pkg, PKInstallPackageIdentifier=com.twocanoes.winclone_1557499122, NSLocalizedDescription=An error occurred while running scripts from the package “2019Lab_nosysprep.pkg”.} {
NSFilePath = “./postflight”;
NSLocalizedDescription = “An error occurred while running scripts from the package \U201c2019Lab_nosysprep.pkg\U201d.”;
NSURL = “file://localhost/2019Lab_nosysprep.pkg”;
PKInstallPackageIdentifier = “com.twocanoes.winclone_1557499122”;
}
2019-05-10 11:23:11-04 BID27319 installd[481]: PackageKit: Running idle tasks
2019-05-10 11:23:11-04 BID27319 Installer[729]: install:didFailWithError:Error Domain=PKInstallErrorDomain Code=112 “An error occurred while running scripts from the package “2019Lab_nosysprep.pkg”.”

#2

The boot camp partition is unmounted prior to it being formatted, but something is still using it. I would look at anti virus or security software (or timemachine or other backup software) to see if it is preventing the unmount. I would also try the current Winclone 7 beta which has a delay of 5 seconds after the unmount.

tim