Where are the log entries for improper disks disconnections?

[Wando64]

Just as from the title of the thread.
Whenever a disk is improperly disconnected we get a notification to say "disk not ejected properly".
However, the notification tells us nothing about WHEN did the disconnection happened.
Surely this error must be recorded in the Logs (with a timestamp), but I cannot find it.

Anyone able to help?
Thanks

 

[Brian33]

Try using the 'log' command. I don't fully understand it and had no idea what process or subsystem name to look for, so I just did a very wide-ranging query, looking for log messages from any process that contains "disk". This very crude query *maybe* gives you what you want (?) for the last 24 hours (for example):

log show --predicate 'processImagePath contains "disk"' --info --last 24h | grep unmounted

See 'man log' for many details. Maybe someone can supply a better query predicate...

 

[Wando64]

Try using the 'log' command. I don't fully understand it and had no idea what process or subsystem name to look for, so I just did a very wide-ranging query, looking for log messages from any process that contains "disk". This very crude query *maybe* gives you what you want (?) for the last 24 hours (for example):

log show --predicate 'processImagePath contains "disk"' --info --last 24h | grep unmounted

See 'man log' for many details. Maybe someone can supply a better query predicate...

Thanks.
I amended to look for the string "backups" (that's the name of the image) over the last 48h and it returns no results.

 

[bogdanw]

Try

log show --info --last 24h | grep 'disk disappeared'

 

[Brian33]

Thanks.
I amended to look for the string "backups" (that's the name of the image) over the last 48h and it returns no results.

I see. The grep command I gave was case-sensitive, so make sure to use "Backups" or "BACKUPS" if that's what you're looking for. Alternatively, add the "-i" option to grep to make it case-insensitive:

log show --predicate 'processImagePath contains "disk"' --info --last 24h | grep [B]-i[/B] "backups"

 

[Wando64]

Try

log show --info --last 24h | grep 'disk disappeared'

Thanks.
This is throwing out a lot of results from the TM backups, however I have not had any improper disconnection for 2 days now, so clearly these results are not specific to this event.

 

[Wando64]

I see. The grep command I gave was case-sensitive, so make sure to use "Backups" or "BACKUPS" if that's what you're looking for. Alternatively, add the "-i" option to grep to make it case-insensitive:

log show --predicate 'processImagePath contains "disk"' --info --last 24h | grep [B]-i[/B] "backups"

Thanks.
This also throws out loads of results relating to the TM backup (as expected as it uses the Backups volume). I will attempt after an improper disconnection to see if it gets captured by this.

 

[Wando64]

I see. The grep command I gave was case-sensitive, so make sure to use "Backups" or "BACKUPS" if that's what you're looking for. Alternatively, add the "-i" option to grep to make it case-insensitive:

log show --predicate 'processImagePath contains "disk"' --info --last 24h | grep [B]-i[/B] "backups"

Actually I have just run this changing the time to 96h and nothing in the results refers to an improper disconnection and searching for strings such as eject, disconnect, disconnected, properly, etc, does not highlight any results among the output of the log show command.

This is quite frustrating.
How can MacOS notify me about something without a timestamp on the notification? Insane.

 

[bogdanw]

I’ve removed an USB stick without ejecting it first and run

log show --info --last 1m > ~/Desktop/log.txt

These are the lines before the disk disappeared message:

2022-07-24 19:49:59.642789+0300 0x639      Default     0x0                  0      0    kernel: (IOUSBHostFamily) 000640.720234 AppleUSB20HubPort@01110000: AppleUSBHostPort::terminateDevice: destroying 0xabcd/1234/0100 (UDisk           ): connect change interrupt
2022-07-24 19:49:59.644046+0300 0x636      Default     0x0                  0      0    kernel: (IOUSBMassStorageDriver) USB device ABCD123401110000 - General , UDisk            - detected termination of interfaceNub, currentPowerState 1, provider is IOUSBMassStorageInterfaceNub
2022-07-24 19:49:59.644172+0300 0x636      Default     0x0                  0      0    kernel: (IOUSBMassStorageDriver) USB device ABCD123401110000 - Last CDBs 00000000:000|00000000:000|00000000:000|00000000:000|00000000:000|00000000:000|00000000:000|00000000:000|00000000:000|00000000:000|00000000:000|00000000:000|00000000:000|00000000:000|00000000:000|00000000:123
2022-07-24 19:49:59.644385+0300 0xe47      Default     0x0                  409    0    icdd: [com.apple.imagecapture:icdd]            [Removed] | [USB][    UDisk            ] ( 0, 0, 0) @ 0x1110000 |
2022-07-24 19:49:59.644419+0300 0xe47      Default     0x0                  409    0    icdd: [com.apple.imagecapture:icdd]            [Removed] | [USB][    UDisk            ] ( 8, 6,50) @ 0x1110000 |
2022-07-24 19:49:59.644784+0300 0x70b      Default     0x0                  108    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default] removed disk, id = /dev/disk5s1.
2022-07-24 19:49:59.645098+0300 0x70b      Info        0x0                  108    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default] diskarbitrationd [108] -> powerd [92]:37379
2022-07-24 19:49:59.645127+0300 0x70b      Info        0x0                  108    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default]   dispatched callback, id = 0000000000000002:0000000000000002, kind = disk disappeared, disk = /dev/disk5s1.

 

[Wando64]

I’ve removed an USB stick without ejecting it first and run

log show --info --last 1m > ~/Desktop/log.txt

These are the lines before the disk disappeared message:

2022-07-24 19:49:59.642789+0300 0x639      Default     0x0                  0      0    kernel: (IOUSBHostFamily) 000640.720234 AppleUSB20HubPort@01110000: AppleUSBHostPort::terminateDevice: destroying 0xabcd/1234/0100 (UDisk           ): connect change interrupt
2022-07-24 19:49:59.644046+0300 0x636      Default     0x0                  0      0    kernel: (IOUSBMassStorageDriver) USB device ABCD123401110000 - General , UDisk            - detected termination of interfaceNub, currentPowerState 1, provider is IOUSBMassStorageInterfaceNub
2022-07-24 19:49:59.644172+0300 0x636      Default     0x0                  0      0    kernel: (IOUSBMassStorageDriver) USB device ABCD123401110000 - Last CDBs 00000000:000|00000000:000|00000000:000|00000000:000|00000000:000|00000000:000|00000000:000|00000000:000|00000000:000|00000000:000|00000000:000|00000000:000|00000000:000|00000000:000|00000000:000|00000000:123
2022-07-24 19:49:59.644385+0300 0xe47      Default     0x0                  409    0    icdd: [com.apple.imagecapture:icdd]            [Removed] | [USB][    UDisk            ] ( 0, 0, 0) @ 0x1110000 |
2022-07-24 19:49:59.644419+0300 0xe47      Default     0x0                  409    0    icdd: [com.apple.imagecapture:icdd]            [Removed] | [USB][    UDisk            ] ( 8, 6,50) @ 0x1110000 |
2022-07-24 19:49:59.644784+0300 0x70b      Default     0x0                  108    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default] removed disk, id = /dev/disk5s1.
2022-07-24 19:49:59.645098+0300 0x70b      Info        0x0                  108    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default] diskarbitrationd [108] -> powerd [92]:37379
2022-07-24 19:49:59.645127+0300 0x70b      Info        0x0                  108    0    diskarbitrationd: [com.apple.DiskArbitration.diskarbitrationd:default]   dispatched callback, id = 0000000000000002:0000000000000002, kind = disk disappeared, disk = /dev/disk5s1.

Thanks.

This is useful and I will need to investigate further, however what is complicating matters in my case is that the disconnection is not caused by a physical disk, but rather by a remote disk image (a TM image in the sparsebundle on a remotely connected disk), so not easily replicated.

Actually, I might try to unplug the ethernet cable from the server Mac and see if that triggers anything.

 

[Wando64]

Actually, I might try to unplug the ethernet cable from the server Mac and see if that triggers anything.

It doesn't do anything improper. The disk simply disappear without any error.

 

[Wando64]

Basically, what I am trying to understand is when does the improper disconnection happen, so that I can establish if it is before, during or after a TM backup.

 

[bogdanw]

For a network-attached storage, the “Disk not ejected properly” message is probably only shown if the disconnection happens when the disk is in use, actively transferring data.

 

[Wando64]

For a network-attached storage, the “Disk not ejected properly” message is probably only shown if the disconnection happens when the disk is in use, actively transferring data.

I might have to try and force such an error just to confirm.