btw, have a look @ /private/var/log/commerce.log to see the transactions as they've happened (MAS leaves lots of breadcrumbs <s>)
Thank you very much! That was really interesting. One of the entries in previous days is as follows:
Oct 20 11:18:31 MacPro storeassetd[365]: SoftwareMap: Preferring (on boot volume) app version /Users/PJH/Desktop/Programs/OS X Installers/Install OS X El Capitan.app at 1.7.28 over version /Volumes/Install OS X El Capitan/Install OS X El Capitan.app at 1.7.28
As you can see, it appears OS X keeps track (via Spotlight?) of where viable installers are located. In my case, the culprit seems to be in /Users/PJH/Desktop/Programs/OS X Installers/, which I didn't suppose the App Store would search in.
Seeing that, I've just renamed the relevant file and unmounted my installer and tried again, but it didn't work. Some of the generated entries on the log are as follows:
Oct 29 12:17:56 MacPro storedownloadd[777]: Installation check returns non-fatal error Error Domain=PKDistributionError Code=103 "OS X v10.11.1 is already installed on this computer. Use the Updates page to install the 10.11 update or if you would like to download the full OS X installer click Continue." UserInfo={NSLocalizedRecoveryOptions=(
Ignore
), message=OS X v10.11.1 is already installed on this computer. Use the Updates page to install the 10.11 update or if you would like to download the full OS X installer click Continue., type=Warn, NSLocalizedDescription=OS X v10.11.1 is already installed on this computer. Use the Updates page to install the 10.11 update or if you would like to download the full OS X installer click Continue.}
Oct 29 12:17:56 MacPro storedownloadd[777]: PKDistributionController: Performing disk space check with 2877254975488 bytes available on disk, 0 bytes alreay downloaded and 6492599296 required bytes (installSize=6986752 + fileSize=6171039744 + paddedSize=314572800)
Oct 29 12:17:56 MacPro storedownloadd[777]: CheckPreflightOperation: verified preflight success=1, error=Error Domain=PKDistributionError Code=103 "OS X v10.11.1 is already installed on this computer. Use the Updates page to install the 10.11 update or if you would like to download the full OS X installer click Continue." UserInfo={NSLocalizedRecoveryOptions=(
Ignore
), message=OS X v10.11.1 is already installed on this computer. Use the Updates page to install the 10.11 update or if you would like to download the full OS X installer click Continue., type=Warn, NSLocalizedDescription=OS X v10.11.1 is already installed on this computer. Use the Updates page to install the 10.11 update or if you would like to download the full OS X installer click Continue.}, distController=<PKDistributionController: 0x7fdf4954d9f0>
Oct 29 12:17:56 MacPro storedownloadd[777]: CheckPreflightOperation: Error found checking preflight - Error Domain=PKDistributionError Code=103 "OS X v10.11.1 is already installed on this computer. Use the Updates page to install the 10.11 update or if you would like to download the full OS X installer click Continue." UserInfo={NSLocalizedRecoveryOptions=(
Ignore
), message=OS X v10.11.1 is already installed on this computer. Use the Updates page to install the 10.11 update or if you would like to download the full OS X installer click Continue., type=Warn, NSLocalizedDescription=OS X v10.11.1 is already installed on this computer. Use the Updates page to install the 10.11 update or if you would like to download the full OS X installer click Continue.}
Et cetera
It would appear than when I tell it to go ahead and download anyway, the generated entries begin with
Oct 29 12:17:58 MacPro com.apple.WebKit.WebContent[5839]: FRJSInterface: Page requested a buy
Oct 29 12:17:58 MacPro com.apple.WebKit.WebContent[5839]: FRJSInterface: Forming purchase object of type software
Oct 29 12:17:58 MacPro com.apple.WebKit.WebContent[5839]: FRJSInterface: JS called buy for updates, handling as app updates via CKUpdateController for purchases (
"<SSPurchase: 0x7fa447874fe0 - itemIdentifier=1018109117, buyParams=productType=C&price=0&salableAdamId=1018109117&pricingParameters=SWUPD&appExtVrsId=813895899&origPage=Software-ES-Apple-OS%20X%20El%20Capitan-1018109117&origPageCh=Software%20Pages&origPageLocation=Buy&origPage2=Genre-ES-Desktop%20Applications-29562&origPageCh2=Desktop%20Apps-main, isUpdate=YES, accountIdentifier=1092836708, purchaseType=2>"
) that mapped to updates (
)
These blank entries, however, look suspicious to me:
Oct 29 12:17:58 MacPro storeassetd[446]: UpdateOperation: osUpdatedToInstallNow returned qualified updates: (
)
Oct 29 12:17:58 MacPro storeassetd[446]: UpdateOperation: appUpdatesToStageOrInstallNow returned qualified updates: (
)
Oct 29 12:17:58 MacPro storeassetd[446]: UpdateOperation: Starting app update purchases for (
)
Oct 29 12:17:58 MacPro storeassetd[446]: UpdateOperation: App updates to be installed/staged is (
)
Oct 29 12:17:58 MacPro com.apple.CommerceKit.TransactionService[671]: SSPurchase: purchasesGroupedByAccountIdentifierWithPurchases is returning
Oct 29 12:17:58 MacPro storeassetd[446]: UpdateOperation: Starting app update downloads for (
)
Oct 29 12:17:58 MacPro storeassetd[446]: UpdateOperation: There are no app updates that can be downloaded and/or installed at this time
Oct 29 12:17:58 MacPro storeassetd[446]: UpdateController: _availableUpdatesDidChange removing all updates available notifications because the badge count is 0
Oct 29 12:17:58 MacPro storeassetd[446]: UpdateOperation: Message tracing com.apple.MacAppStore.autoupdate.operation_run - {
"app_updates_available" = "";
"app_updates_available_count" = 0;
"app_updates_to_install" = "";
"app_updates_to_install_count" = 0;
"app_updates_to_install_later" = "";
"app_updates_to_install_later_count" = 0;
"darkwake_thermal_emergency_count" = 0;
"elapsed_time" = 0;
"is_time_to_autoupdate_and_notify" = no;
"is_time_to_stage" = no;
"now_is_later" = no;
"os_updates_available" = "";
"os_updates_available_count" = 0;
"os_updates_to_install" = "";
"os_updates_to_install_count" = 0;
"os_updates_to_install_later" = "";
"os_updates_to_install_later_count" = 0;
"os_updates_to_install_on_restart" = "";
result = pass;
"user_initiated" = yes;
"will_restart" = no;
}
And, finally,
Oct 29 12:17:58 MacPro com.apple.WebKit.WebContent[5839]: CKUpdateController: AssetService startAppUpdates:andOSUpdates:withReplyBlock replied with success=1 error=(null)
Oct 29 12:17:58 MacPro storeassetd[446]: UpdateOperation: Released BackgroundTask power assertion (returned 0)
Any ideas?