diskarbitrationd cpu usage after reboot or snapshot

0

Hi,

I am seeing something weird with mac2.metal instances - after snapshotting both the snapshotted instance or any new ec2 instances booted from the ami have diskarbitrationd process taking a lot of CPU (up to 100%, one full core), and log stream --predicate 'process == "diskarbitrationd"' --debug shows that diskarbitrationd is trying to unmount all disks but is getting rejected and just loops. A snippet from the logs:

2025-04-02 16:10:03.763035+0000 0xc1a0     Info        0x0                  196    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default] diskarbitrationd [196] -> storagekitd [445]:38423
2025-04-02 16:10:03.763071+0000 0xc1a0     Info        0x0                  196    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default]   dispatched callback, id = 0000000000000007:0000000000000007, kind = disk eject, disk = /dev/disk0, status = 0x0000C010.
... <approval requests for all running apps> ... 
2025-04-02 16:10:04.732484+0000 0xc1a0     Default     0x0                  196    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default] unmounted disk, id = /dev/disk1s1, ongoing.
2025-04-02 16:10:04.732773+0000 0xc1a0     Default     0x0                  196    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default] unmounted disk, id = /dev/disk1s1, failure.
2025-04-02 16:10:04.732816+0000 0xc1a0     Info        0x0                  196    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default] unable to unmount /dev/disk1s1 (status code 0x00000001).
2025-04-02 16:10:04.732849+0000 0xc1a0     Error       0x0                  196    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default] unable to unmount /dev/disk1s1 (status code 0x00000001).
2025-04-02 16:10:05.038192+0000 0xc1a0     Info        0x0                  196    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default] diskarbitrationd [196] -> storagekitd [445]:38423
2025-04-02 16:10:05.038227+0000 0xc1a0     Info        0x0                  196    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default]   dispatched callback, id = 0000000000000007:0000000000000007, kind = disk unmount, disk = /dev/disk1s1, status = 0x0000C010.
...
2025-04-02 16:10:05.075522+0000 0xc1a0     Default     0x0                  196    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default] unmounted disk, id = /dev/disk1s2, ongoing.
2025-04-02 16:10:05.075611+0000 0xc1a0     Default     0x0                  196    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default] unmounted disk, id = /dev/disk1s2, failure.
2025-04-02 16:10:05.075628+0000 0xc1a0     Info        0x0                  196    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default] unable to unmount /dev/disk1s2 (status code 0x00000010).
2025-04-02 16:10:05.075640+0000 0xc1a0     Error       0x0                  196    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default] unable to unmount /dev/disk1s2 (status code 0x00000010).
2025-04-02 16:10:05.385911+0000 0xc1a0     Default     0x0                  196    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default] unmounted disk, id = /dev/disk1s3, ongoing.
2025-04-02 16:10:05.386046+0000 0xc1a0     Default     0x0                  196    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default] unmounted disk, id = /dev/disk1s3, failure.
2025-04-02 16:10:05.386063+0000 0xc1a0     Info        0x0                  196    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default] unable to unmount /dev/disk1s3 (status code 0x00000001).
2025-04-02 16:10:05.386074+0000 0xc1a0     Error       0x0                  196    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default] unable to unmount /dev/disk1s3 (status code 0x00000001).
2025-04-02 16:10:05.386744+0000 0xc1a0     Info        0x0                  196    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default] diskarbitrationd [196] -> storagekitd [445]:38423
2025-04-02 16:10:05.386759+0000 0xc1a0     Info        0x0                  196    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default]   dispatched callback, id = 0000000000000007:0000000000000007, kind = disk unmount, disk = /dev/disk1s3, status = 0x0000C010.
...
2025-04-02 16:10:06.078030+0000 0xc1a0     Default     0x0                  196    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default] ejected disk, id = /dev/disk2, ongoing.
2025-04-02 16:10:06.078161+0000 0xc1a0     Default     0x0                  196    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default] ejected disk, id = /dev/disk2, failure.
2025-04-02 16:10:06.078177+0000 0xc1a0     Default     0x0                  196    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default] unable to eject /dev/disk2 (status code 0x00000001).

This is what is see if i run log stream --debug | grep eject:

2025-04-02 16:17:58.737073+0000 0x118b1    Debug       0xd4932              289    0    trustd: [com.apple.securityd:reject] non ev score: 1107 <private>
2025-04-02 16:17:58.737086+0000 0x118b1    Debug       0xd4932              289    0    trustd: [com.apple.securityd:reject] non ev score: 112 lower than 1107 <private>
2025-04-02 16:17:58.737096+0000 0x118b1    Debug       0xd4932              289    0    trustd: [com.apple.securityd:reject] non ev score: 111 lower than 1107 <private>
2025-04-02 16:17:58.859845+0000 0x118b1    Debug       0xd4933              289    0    trustd: [com.apple.securityd:reject] non ev score: 1107 <private>
2025-04-02 16:17:58.859858+0000 0x118b1    Debug       0xd4933              289    0    trustd: [com.apple.securityd:reject] non ev score: 112 lower than 1107 <private>
2025-04-02 16:17:58.859867+0000 0x118b1    Debug       0xd4933              289    0    trustd: [com.apple.securityd:reject] non ev score: 111 lower than 1107 <private>
2025-04-02 16:17:58.904700+0000 0x1130a    Info        0x0                  196    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default]   dispatched callback, id = 0000000000000007:0000000000000007, kind = disk eject, disk = /dev/disk0, status = 0x0000C010.
2025-04-02 16:17:58.912117+0000 0x11a27    Default     0x0                  8375   0    diskutil: (StorageKit) [com.apple.storagekit:general] Reached XPC reply for 385FA3D6-5E55-4DF5-8B32-0D764632F88A -[SKHelperClient ejectDisk:blocking:withCompletionBlock:]
2025-04-02 16:17:59.278937+0000 0x118b1    Debug       0xc3fad              289    0    trustd: [com.apple.securityd:reject] non ev score: 1107 <private>
2025-04-02 16:17:59.278967+0000 0x118b1    Debug       0xc3fad              289    0    trustd: [com.apple.securityd:reject] non ev score: 112 lower than 1107 <private>
2025-04-02 16:17:59.278994+0000 0x118b1    Debug       0xc3fad              289    0    trustd: [com.apple.securityd:reject] non ev score: 111 lower than 1107 <private>
2025-04-02 16:17:59.297915+0000 0x118b1    Debug       0xc3fae              289    0    trustd: [com.apple.securityd:reject] non ev score: 1107 <private>
2025-04-02 16:17:59.297934+0000 0x118b1    Debug       0xc3fae              289    0    trustd: [com.apple.securityd:reject] non ev score: 112 lower than 1107 <private>
2025-04-02 16:17:59.297949+0000 0x118b1    Debug       0xc3fae              289    0    trustd: [com.apple.securityd:reject] non ev score: 111 lower than 1107 <private>
2025-04-02 16:17:59.301375+0000 0x118b1    Debug       0xc3faf              289    0    trustd: [com.apple.securityd:reject] non ev score: 1107 <private>
2025-04-02 16:17:59.301392+0000 0x118b1    Debug       0xc3faf              289    0    trustd: [com.apple.securityd:reject] non ev score: 112 lower than 1107 <private>
2025-04-02 16:17:59.301408+0000 0x118b1    Debug       0xc3faf              289    0    trustd: [com.apple.securityd:reject] non ev score: 111 lower than 1107 <private>
2025-04-02 16:17:59.333015+0000 0x118b1    Debug       0xd5600              289    0    trustd: [com.apple.securityd:reject] non ev score: 1107 <private>
2025-04-02 16:17:59.333036+0000 0x118b1    Debug       0xd5600              289    0    trustd: [com.apple.securityd:reject] non ev score: 112 lower than 1107 <private>
2025-04-02 16:17:59.333052+0000 0x118b1    Debug       0xd5600              289    0    trustd: [com.apple.securityd:reject] non ev score: 111 lower than 1107 <private>
2025-04-02 16:17:59.388251+0000 0x118b1    Debug       0xd5601              289    0    trustd: [com.apple.securityd:reject] non ev score: 1107 <private>
2025-04-02 16:17:59.388286+0000 0x118b1    Debug       0xd5601              289    0    trustd: [com.apple.securityd:reject] non ev score: 112 lower than 1107 <private>
2025-04-02 16:17:59.388301+0000 0x118b1    Debug       0xd5601              289    0    trustd: [com.apple.securityd:reject] non ev score: 111 lower than 1107 <private>
2025-04-02 16:17:59.393414+0000 0x118b1    Debug       0xd5602              289    0    trustd: [com.apple.securityd:reject] non ev score: 1107 <private>
2025-04-02 16:17:59.393429+0000 0x118b1    Debug       0xd5602              289    0    trustd: [com.apple.securityd:reject] non ev score: 112 lower than 1107 <private>
2025-04-02 16:17:59.393441+0000 0x118b1    Debug       0xd5602              289    0    trustd: [com.apple.securityd:reject] non ev score: 111 lower than 1107 <private>
2025-04-02 16:17:59.405766+0000 0x11e7b    Default     0x0                  8527   0    diskutil: (StorageKit) [com.apple.storagekit:general] Setting sync completion callback for ( -[SKHelperClient ejectDisk:blocking:withCompletionBlock:] ) to: 3B6FF27E-F203-4292-84EA-CDC6FA31A114
2025-04-02 16:17:59.405870+0000 0x11506    Default     0x0                  445    0    storagekitd: [com.apple.storagekit:general] Preflight for <private> at -[SKDaemonConnection ejectDisk:withCompletionUUID:] with UUID: 3B6FF27E-F203-4292-84EA-CDC6FA31A114
2025-04-02 16:17:59.491187+0000 0x118b1    Debug       0xccb9e              289    0    trustd: [com.apple.securityd:reject] non ev score: 1107 <private>
2025-04-02 16:17:59.491219+0000 0x118b1    Debug       0xccb9e              289    0    trustd: [com.apple.securityd:reject] non ev score: 112 lower than 1107 <private>
2025-04-02 16:17:59.491245+0000 0x118b1    Debug       0xccb9e              289    0    trustd: [com.apple.securityd:reject] non ev score: 111 lower than 1107 <private>
2025-04-02 16:17:59.494631+0000 0x118b1    Debug       0xccb9f              289    0    trustd: [com.apple.securityd:reject] non ev score: 1107 <private>
2025-04-02 16:17:59.494662+0000 0x118b1    Debug       0xccb9f              289    0    trustd: [com.apple.securityd:reject] non ev score: 112 lower than 1107 <private>
2025-04-02 16:17:59.494689+0000 0x118b1    Debug       0xccb9f              289    0    trustd: [com.apple.securityd:reject] non ev score: 111 lower than 1107 <private>
2025-04-02 16:18:00.265419+0000 0x118b1    Debug       0xd5603              289    0    trustd: [com.apple.securityd:reject] non ev score: 1107 <private>
2025-04-02 16:18:00.265449+0000 0x118b1    Debug       0xd5603              289    0    trustd: [com.apple.securityd:reject] non ev score: 112 lower than 1107 <private>
2025-04-02 16:18:00.265480+0000 0x118b1    Debug       0xd5603              289    0    trustd: [com.apple.securityd:reject] non ev score: 111 lower than 1107 <private>
2025-04-02 16:18:00.271475+0000 0x118b1    Debug       0xd5604              289    0    trustd: [com.apple.securityd:reject] non ev score: 1107 <private>
2025-04-02 16:18:00.271505+0000 0x118b1    Debug       0xd5604              289    0    trustd: [com.apple.securityd:reject] non ev score: 112 lower than 1107 <private>
2025-04-02 16:18:00.271533+0000 0x118b1    Debug       0xd5604              289    0    trustd: [com.apple.securityd:reject] non ev score: 111 lower than 1107 <private>
2025-04-02 16:18:01.391733+0000 0x1130a    Info        0x0                  196    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default]   queued solicitation, id = 0000000000000007:0000000000000007, kind = disk eject, disk = /dev/disk1, options = 0x00000000.
2025-04-02 16:18:01.391833+0000 0x1130a    Info        0x0                  196    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default]   dispatched callback, id = 0000000000000006:0000000000000006, kind = disk eject approval, disk = /dev/disk1.
2025-04-02 16:18:01.391917+0000 0x1130a    Info        0x0                  196    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default]   dispatched callback, id = 0000000000000006:0000000000000006, kind = disk eject approval, disk = /dev/disk1.
2025-04-02 16:18:01.392277+0000 0x1130a    Info        0x0                  196    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default]   dispatched callback, id = 0000000000000001:0000000000000001, kind = disk eject approval, disk = /dev/disk1.
2025-04-02 16:18:01.392704+0000 0x1130a    Info        0x0                  196    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default]   dispatched response, id = 0000000000000001:0000000000000001, kind = disk eject approval, disk = /dev/disk1, approved.
2025-04-02 16:18:01.393570+0000 0x1130a    Info        0x0                  196    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default]   dispatched response, id = 0000000000000006:0000000000000006, kind = disk eject approval, disk = /dev/disk1, approved.

Could this be caused by the initial "UnmountLocalSSD" step done by the init step? (https://github.com/aws/ec2-macos-init/blob/master/configuration/init.toml) somehow not completing and then blocking?

This seems to be happening on an ec2 instance created from the Sonoma 14.7.4, i booted and older AMI from Ventura, that does not exhibit this, even though the disk layout seems the same.

asked 2 months ago49 views
1 Answer
0

Hello Rudolfs, Based on your description, this appears to be a specific issue with macOS Sonoma 14.7.4 instances on mac2.metal and the disk arbitration system. Let's break down the issue into individual sections in an attempt to find root cause:

Potential Root Causes:

There might be a race condition between ec2-macos-init's UnmountLocalSSD step and macOS Sonoma's disk arbitration system
The disk state information might not be properly cleared during the AMI creation process
Sonoma might have stricter disk arbitration policies that are conflicting with the EC2 initialization process

To troubleshoot:

Check the ec2-macos-init logs:

sudo cat /var/log/ec2-macos-init.log

Examine the disk setup:

diskutil list diskutil info disk0

Try manually resetting the disk arbitration daemon:

sudo killall diskarbitrationd

As a workaround, you might want to:

Add a delay before the UnmountLocalSSD step in init.toml
Create a new AMI after performing a clean shutdown with all disk operations completed
Consider filing an issue with AWS support as this might be a broader compatibility issue with Sonoma

The symptoms you're describing suggest a potential issue with the disk unmounting process:

High CPU usage from diskarbitrationd (100% on one core)
Continuous loop of unmount attempts and rejections
Issue persists across snapshots and new instances
Only affects Sonoma 14.7.4, not Ventura

The UnmountLocalSSD step in ec2-macos-init is designed to handle the initial unmounting of local SSDs during instance initialization. Here's what I suggest to troubleshoot and potentially resolve this:

First, check the current disk layout and mount status:

diskutil list diskutil info /dev/disk0 mount

Check the ec2-macos-init logs:

sudo cat /var/log/ec2-macos-init.log

Try manually running the disk arbitration debug command:

sudo log show --predicate 'subsystem == "com.apple.diskarbitrationd"' --last 1h

You can try to reset the disk arbitration daemon:

sudo launchctl unload /System/Library/LaunchDaemons/com.apple.diskarbitrationd.plist sudo launchctl load /System/Library/LaunchDaemons/com.apple.diskarbitrationd.plist

If this is indeed related to the UnmountLocalSSD step, you could try:

Create a custom AMI with a modified init.toml that comments out the UnmountLocalSSD step to test if this is the root cause.

Check if there are any stuck mount points:

lsof | grep /Volumes

Examine the system.log for any related errors:

sudo log show --predicate 'eventMessage CONTAINS "disk"' --last 30m

I recommend opening a support case with AWS as this might be a specific issue with the Sonoma 14.7.4 AMI that needs to be addressed at the platform level. Include:

The AMI ID you're using
Logs from diskarbitrationd
The ec2-macos-init logs
The results of the disk layout commands above

This could also be a timing issue with the initialization sequence in Sonoma 14.7.4 or a change in how macOS handles disk unmounting in this version.

Hopefully this provides some direction towards resolving this issue.

Thank you for using AWS! Brian

profile pictureAWS
answered a month ago
  • Thanks for the answer, yeah we just went with commenting out the unmounting step since that was the easiest way forward.

You are not logged in. Log in to post an answer.

A good answer clearly answers the question and provides constructive feedback and encourages professional growth in the question asker.

Guidelines for Answering Questions