onair icon indicating copy to clipboard operation
onair copied to clipboard

Facetime HD cameras of new M1 macs not detecting onAir() state

Open chrsvgt opened this issue 4 years ago • 26 comments

Great approach and tool, super useful during WFH to respect family member's privacy, @wouterdebie, thanks for sharing!

After upgrading to an MBP with Apple silicon the built-in camera is no longer evaluated properly in isOn().

Printing out debug code just after https://github.com/wouterdebie/onair/blob/0e5d1386d2a75564fa9aa81edf0c41e624d90e68/Sources/onair/Camera.swift#L39 is showing the following, camera is hence always on and it does not toggle when actually activating and deactivating it: capture device: <AVCaptureDALDevice: 0x144611770 [FaceTime HD Camera][EAB7A68FEC2B4487AADFD8A91C1CB782]>, data pointee: 1

I am neither an expert in AVFoundation and CoreMedia and could not find any hints after some intense research so far on what has effectively changed for the new camera hardware and how to detect its state properly. Maybe someone here does have the expertise to judge on how this could be fixed, happy to contribute then.

chrsvgt avatar Jan 22 '21 08:01 chrsvgt

Hi!

I'm not an expert either.. I think I found that piece of code a while ago and seemed to work, but it's obviously quite a hack. If there's anybody else that knows more about this, I'd love to hear it.

wouterdebie avatar Jan 26 '21 20:01 wouterdebie

I dug a bit in the code and I'll take back that this is a hack :) It's a bit convoluted getting the status of the camera, but I actually figured out how this works and it seems to be a legit way of getting status from the AVCaptureDevice

That said, what this code does is it checks for a property called kCMIODevicePropertyDeviceIsRunningSomewhere in a CMIOObjectPropertyAddress. In #2 it is the case that this property is always set to 1, since it's hardcoded in the virtual camera code. Could it be that your camera is actually accessed by another process?

wouterdebie avatar Jan 26 '21 23:01 wouterdebie

Thanks for digging! I completely agree that this code for checking does actually look good. I did follow your pointer to check on my machine if camera is used elsewhere (which would have been a scary surprise, though): lsof | grep VDC showed Google and Slack as output, closed both Chrome and Slack then the output was empty. Behavior did not change of the onair check, the pointee is still always "1".

Interestingly, when adding a bit more logging right after this line https://github.com/wouterdebie/onair/blob/7dd134e2f4866e03b2b2d0ba7dd567e02129a998/Sources/onair/CameraChecker.swift#L47 locally, logger.info(" - \(camera) - connected: - \(device.isConnected) - isInUseByAnotherApplication: \(device.isInUseByAnotherApplication)"), the output when starting onair is always

- Apple Inc./FaceTime HD Camera - connected: - true - isInUseByAnotherApplication: false

Unfortunately, there were two changes at once for my hardware: upgrade to M1 MacBook Pro which also brought in BigSur.

Don't have an older MacOS system at hand right now. Does it work on BigSur or could this even be the problem? This would help so that I can dig deeper into one of the two directions.

chrsvgt avatar Jan 27 '21 08:01 chrsvgt

I just tested it on BigSur (11.1) on a 2017 MacBook Pro and it seems to work. I normally run on Catalina (10.15.7) on a 2018 MacBook Pro and that also works. So I guess we can rule out the OS.

Secondly, I there's a difference between isInUseByAnotherApplication and kCMIODevicePropertyDeviceIsRunningSomewhere. If I look at output from lsof | grep VCD, I see that a bunch of applications use the camera, but none of them have it running.

wouterdebie avatar Jan 27 '21 17:01 wouterdebie

Thanks for testing and yes, all correct regarding observations on the differences between the two properties and lsof. Big Sur is good then. Btw. my USB cam is working properly. My strong hunch is that it has sth. to do with the lastest Apple hardware change for the camera. I will keep watching out - not deep enough at all myself in CoreMediaIO to figure it out what may cause the change and how to fix it.

Maybe there is someone out here with an M1 MBP who can share her or his experience.

chrsvgt avatar Jan 27 '21 21:01 chrsvgt

I've added some reporting functionality on the report branch. Running this on Catalina on a 2018 MBP shows:

2021-01-27T16:11:34-0600 info nl.evenflow.onair : Apple Inc./FaceTime HD Camera (Built-in)
2021-01-27T16:11:34-0600 info nl.evenflow.onair :   kCMIODevicePropertyDeviceIsAlive: 1
2021-01-27T16:11:34-0600 info nl.evenflow.onair :   kCMIODevicePropertyCanProcessAVCCommand: 0
2021-01-27T16:11:34-0600 info nl.evenflow.onair :   kCMIODevicePropertyCanProcessRS422Command: 0
2021-01-27T16:11:34-0600 info nl.evenflow.onair :   kCMIODevicePropertyDeviceIsRunningSomewhere: 0
2021-01-27T16:11:34-0600 info nl.evenflow.onair :   kCMIODevicePropertySuspendedByUser: 0
2021-01-27T16:11:34-0600 info nl.evenflow.onair :   kCMIODevicePropertyDeviceIsRunning: 0
2021-01-27T16:11:34-0600 info nl.evenflow.onair :   kCMIODevicePropertyDeviceMaster: 255
2021-01-27T16:11:34-0600 info nl.evenflow.onair :   kCMIODevicePropertyDeviceUID: 240
2021-01-27T16:11:34-0600 info nl.evenflow.onair :   kCMIODevicePropertyDeviceHasChanged: 0
2021-01-27T16:11:34-0600 info nl.evenflow.onair :   kCMIODevicePropertyPlugIn: 35
2021-01-27T16:11:34-0600 info nl.evenflow.onair :   kCMIODevicePropertyModelUID: 128
2021-01-27T16:11:34-0600 info nl.evenflow.onair :   kCMIODevicePropertyHogMode: 255
2021-01-27T16:11:34-0600 info nl.evenflow.onair :   kCMIODevicePropertyLocation: 1
2021-01-27T16:11:34-0600 info nl.evenflow.onair :   kCMIODevicePropertyTransportType: 32
2021-01-27T16:11:34-0600 info nl.evenflow.onair :   kCMIODevicePropertyExcludeNonDALAccess: 0
2021-01-27T16:11:34-0600 info nl.evenflow.onair :
2021-01-27T16:11:34-0600 info nl.evenflow.onair : Report:
2021-01-27T16:11:34-0600 info nl.evenflow.onair : Unknown/HD Pro Webcam C920
2021-01-27T16:11:34-0600 info nl.evenflow.onair :   kCMIODevicePropertyModelUID: 16
2021-01-27T16:11:34-0600 info nl.evenflow.onair :   kCMIODevicePropertyCanProcessRS422Command: 0
2021-01-27T16:11:34-0600 info nl.evenflow.onair :   kCMIODevicePropertyDeviceIsRunningSomewhere: 0
2021-01-27T16:11:34-0600 info nl.evenflow.onair :   kCMIODevicePropertyDeviceIsAlive: 1
2021-01-27T16:11:34-0600 info nl.evenflow.onair :   kCMIODevicePropertyHogMode: 255
2021-01-27T16:11:34-0600 info nl.evenflow.onair :   kCMIODevicePropertyDeviceMaster: 255
2021-01-27T16:11:34-0600 info nl.evenflow.onair :   kCMIODevicePropertyExcludeNonDALAccess: 0
2021-01-27T16:11:34-0600 info nl.evenflow.onair :   kCMIODevicePropertyLocation: 3
2021-01-27T16:11:34-0600 info nl.evenflow.onair :   kCMIODevicePropertyCanProcessAVCCommand: 0
2021-01-27T16:11:34-0600 info nl.evenflow.onair :   kCMIODevicePropertyPlugIn: 35
2021-01-27T16:11:34-0600 info nl.evenflow.onair :   kCMIODevicePropertyDeviceIsRunning: 0
2021-01-27T16:11:34-0600 info nl.evenflow.onair :   kCMIODevicePropertyTransportType: 32
2021-01-27T16:11:34-0600 info nl.evenflow.onair :   kCMIODevicePropertyDeviceHasChanged: 0
2021-01-27T16:11:34-0600 info nl.evenflow.onair :   kCMIODevicePropertyDeviceUID: 96

Maybe you can compare?

wouterdebie avatar Jan 27 '21 22:01 wouterdebie

Of course! Could it be that the branch report was not yet pushed?

Btw. I asked a colleague to run the tool also on his MacBook Pro 13, M1, 2020. Same result there, Facetime HD evaluated as on always. Seems it can be ruled out that it is subject to my individual setup and MBP.

chrsvgt avatar Jan 28 '21 10:01 chrsvgt

You're right :) Sorry, just pushed it.

On Thu, Jan 28, 2021 at 4:06 AM chrsvgt [email protected] wrote:

Of course! Could it be that the branch report was not yet pushed?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/wouterdebie/onair/issues/3#issuecomment-768942949, or unsubscribe https://github.com/notifications/unsubscribe-auth/AABKABTUEBGFZI4QRSV6S73S4EZI5ANCNFSM4WOEV3GQ .

wouterdebie avatar Jan 28 '21 14:01 wouterdebie

This is how my report looks like:

2021-01-28T17:42:42+0100 info nl.evenflow.onair : Report:
2021-01-28T17:42:42+0100 info nl.evenflow.onair : Unknown/USB-Kamera
2021-01-28T17:42:42+0100 info nl.evenflow.onair :   kCMIODevicePropertyPlugIn: 32
2021-01-28T17:42:42+0100 info nl.evenflow.onair :   kCMIODevicePropertyExcludeNonDALAccess: 0
2021-01-28T17:42:42+0100 info nl.evenflow.onair :   kCMIODevicePropertyDeviceIsAlive: 1
2021-01-28T17:42:42+0100 info nl.evenflow.onair :   kCMIODevicePropertyLocation: 3
2021-01-28T17:42:42+0100 info nl.evenflow.onair :   kCMIODevicePropertyTransportType: 32
2021-01-28T17:42:42+0100 info nl.evenflow.onair :   kCMIODevicePropertyDeviceMaster: 255
2021-01-28T17:42:42+0100 info nl.evenflow.onair :   kCMIODevicePropertyDeviceUID: 16
2021-01-28T17:42:42+0100 info nl.evenflow.onair :   kCMIODevicePropertyDeviceIsRunning: 0
2021-01-28T17:42:42+0100 info nl.evenflow.onair :   kCMIODevicePropertyCanProcessAVCCommand: 0
2021-01-28T17:42:42+0100 info nl.evenflow.onair :   kCMIODevicePropertyModelUID: 64
2021-01-28T17:42:42+0100 info nl.evenflow.onair :   kCMIODevicePropertyCanProcessRS422Command: 0
2021-01-28T17:42:42+0100 info nl.evenflow.onair :   kCMIODevicePropertyDeviceHasChanged: 0
2021-01-28T17:42:42+0100 info nl.evenflow.onair :   kCMIODevicePropertyDeviceIsRunningSomewhere: 0
2021-01-28T17:42:42+0100 info nl.evenflow.onair :   kCMIODevicePropertyHogMode: 255
2021-01-28T17:42:42+0100 info nl.evenflow.onair :
2021-01-28T17:42:42+0100 info nl.evenflow.onair : Report:
2021-01-28T17:42:42+0100 info nl.evenflow.onair : Apple Inc./FaceTime HD Camera
2021-01-28T17:42:42+0100 info nl.evenflow.onair :   kCMIODevicePropertyHogMode: 255
2021-01-28T17:42:42+0100 info nl.evenflow.onair :   kCMIODevicePropertyModelUID: 48
2021-01-28T17:42:42+0100 info nl.evenflow.onair :   kCMIODevicePropertyTransportType: 32
2021-01-28T17:42:42+0100 info nl.evenflow.onair :   kCMIODevicePropertyDeviceHasChanged: 0
2021-01-28T17:42:42+0100 info nl.evenflow.onair :   kCMIODevicePropertySuspendedByUser: 0
2021-01-28T17:42:42+0100 info nl.evenflow.onair :   kCMIODevicePropertyDeviceIsAlive: 1
2021-01-28T17:42:42+0100 info nl.evenflow.onair :   kCMIODevicePropertyDeviceUID: 96
2021-01-28T17:42:42+0100 info nl.evenflow.onair :   kCMIODevicePropertyCanProcessAVCCommand: 0
2021-01-28T17:42:42+0100 info nl.evenflow.onair :   kCMIODevicePropertyCanProcessRS422Command: 0
2021-01-28T17:42:42+0100 info nl.evenflow.onair :   kCMIODevicePropertyExcludeNonDALAccess: 0
2021-01-28T17:42:42+0100 info nl.evenflow.onair :   kCMIODevicePropertyDeviceIsRunningSomewhere: 1
2021-01-28T17:42:42+0100 info nl.evenflow.onair :   kCMIODevicePropertyDeviceIsRunning: 0
2021-01-28T17:42:42+0100 info nl.evenflow.onair :   kCMIODevicePropertyDeviceMaster: 255
2021-01-28T17:42:42+0100 info nl.evenflow.onair :   kCMIODevicePropertyPlugIn: 47

Differences:

  • kCMIODevicePropertyModelUID: 48 (your value: 128. Ok, it's a UID)
  • kCMIODevicePropertyDeviceUID: 96 (your value: 240. Ok, it's a UID)
  • kCMIODevicePropertyPlugIn: 47 (your value: 35)
  • kCMIODevicePropertyDeviceIsRunningSomewhere: 1 (your value: 0)

So the question now is why it reports the cam is running somewhere...

chrsvgt avatar Jan 28 '21 16:01 chrsvgt

Does this value go to 2 if you start something like Photobooth? I'm trying to figure out if there's a way to see what processes use it, but a quick hack might be to test for pointee >1 instead of pointee>0 .

wouterdebie avatar Jan 28 '21 17:01 wouterdebie

Following observations after a few more tests:

1/ PhotoBooth does not trigger anything (I know it triggered on my old MBP).

2/ Ran it with Rosetta2 arch -x86_6, no difference. Just for the sake of ruling this path out also for sure.

3/ Same behaviour for MS Teams and Google Meet: a) MS Teams starts without camera enabled, Meet starts with camera enabled: tool is not triggered. b) Switching the camera to off in any of the two - Teams or Meet - does not trigger checkCameras c) Switching the camera to on triggers checkCameras. But checkCameras is triggered two times: first to off and then in fast sequence to on.

I added your report capability to the camera check for my test:

diff --git a/Sources/onair/CameraChecker.swift b/Sources/onair/CameraChecker.swift
index ba1436f..f6e644c 100644
--- a/Sources/onair/CameraChecker.swift
+++ b/Sources/onair/CameraChecker.swift
@@ -77,6 +77,10 @@ class CameraChecker: NSObject, USBWatcherDelegate, URLSessionDelegate {
             event = offEvent
         }

+        for camera in cameras {
+            camera.report()
+        }
+
         let url = URL(string: String(format: templateURL, event, key))!
         let session = URLSession.shared
         let task = session.dataTask(with: url) {(data, response, error) in

The report when enabling the camera in either Meet or Teams is the following. Note that despite camera is switched on, first it is detected as off and two seconds later it is detected as on.

2021-01-28T19:46:54+0100 info nl.evenflow.onair : Report:
2021-01-28T19:46:54+0100 info nl.evenflow.onair : Apple Inc./FaceTime HD Camera
2021-01-28T19:46:54+0100 info nl.evenflow.onair :   kCMIODevicePropertyPlugIn: 32
2021-01-28T19:46:54+0100 info nl.evenflow.onair :   kCMIODevicePropertyModelUID: 160
2021-01-28T19:46:54+0100 info nl.evenflow.onair :   kCMIODevicePropertySuspendedByUser: 0
2021-01-28T19:46:54+0100 info nl.evenflow.onair :   kCMIODevicePropertyDeviceIsAlive: 1
2021-01-28T19:46:54+0100 info nl.evenflow.onair :   kCMIODevicePropertyTransportType: 32
2021-01-28T19:46:54+0100 info nl.evenflow.onair :   kCMIODevicePropertyDeviceIsRunning: 0
2021-01-28T19:46:54+0100 info nl.evenflow.onair :   kCMIODevicePropertyHogMode: 255
2021-01-28T19:46:54+0100 info nl.evenflow.onair :   kCMIODevicePropertyDeviceIsRunningSomewhere: 0
2021-01-28T19:46:54+0100 info nl.evenflow.onair :   kCMIODevicePropertyExcludeNonDALAccess: 0
2021-01-28T19:46:54+0100 info nl.evenflow.onair :   kCMIODevicePropertyCanProcessRS422Command: 0
2021-01-28T19:46:54+0100 info nl.evenflow.onair :   kCMIODevicePropertyCanProcessAVCCommand: 0
2021-01-28T19:46:54+0100 info nl.evenflow.onair :   kCMIODevicePropertyDeviceMaster: 155
2021-01-28T19:46:54+0100 info nl.evenflow.onair :   kCMIODevicePropertyDeviceHasChanged: 0
2021-01-28T19:46:54+0100 info nl.evenflow.onair :   kCMIODevicePropertyDeviceUID: 128
2021-01-28T19:46:54+0100 info nl.evenflow.onair :
2021-01-28T19:46:55+0100 info nl.evenflow.onair : IFTTT off called successfully
2021-01-28T19:46:55+0100 info nl.evenflow.onair : Notification: All cameras off
2021-01-28T19:46:56+0100 info nl.evenflow.onair : Report:
2021-01-28T19:46:56+0100 info nl.evenflow.onair : Apple Inc./FaceTime HD Camera
2021-01-28T19:46:56+0100 info nl.evenflow.onair :   kCMIODevicePropertyPlugIn: 32
2021-01-28T19:46:56+0100 info nl.evenflow.onair :   kCMIODevicePropertyModelUID: 160
2021-01-28T19:46:56+0100 info nl.evenflow.onair :   kCMIODevicePropertySuspendedByUser: 0
2021-01-28T19:46:56+0100 info nl.evenflow.onair :   kCMIODevicePropertyDeviceIsAlive: 1
2021-01-28T19:46:56+0100 info nl.evenflow.onair :   kCMIODevicePropertyTransportType: 32
2021-01-28T19:46:56+0100 info nl.evenflow.onair :   kCMIODevicePropertyDeviceIsRunning: 0
2021-01-28T19:46:56+0100 info nl.evenflow.onair :   kCMIODevicePropertyHogMode: 255
2021-01-28T19:46:56+0100 info nl.evenflow.onair :   kCMIODevicePropertyDeviceIsRunningSomewhere: 1
2021-01-28T19:46:56+0100 info nl.evenflow.onair :   kCMIODevicePropertyExcludeNonDALAccess: 0
2021-01-28T19:46:56+0100 info nl.evenflow.onair :   kCMIODevicePropertyCanProcessRS422Command: 0
2021-01-28T19:46:56+0100 info nl.evenflow.onair :   kCMIODevicePropertyCanProcessAVCCommand: 0
2021-01-28T19:46:56+0100 info nl.evenflow.onair :   kCMIODevicePropertyDeviceMaster: 255
2021-01-28T19:46:56+0100 info nl.evenflow.onair :   kCMIODevicePropertyDeviceHasChanged: 0
2021-01-28T19:46:56+0100 info nl.evenflow.onair :   kCMIODevicePropertyDeviceUID: 128
2021-01-28T19:46:56+0100 info nl.evenflow.onair :
2021-01-28T19:46:56+0100 info nl.evenflow.onair : IFTTT on called successfully
2021-01-28T19:46:56+0100 info nl.evenflow.onair : Notification: Camera(s) Apple Inc./FaceTime HD Camera are on

It does not leave the on state from here again. Switching the camera actually off does not trigger checkCameras.

chrsvgt avatar Jan 28 '21 19:01 chrsvgt

Interesting.. I'm not sure if I completely follow what's going on here.. does this show what at some point onair detects all cameras to be off?

wouterdebie avatar Jan 28 '21 20:01 wouterdebie

Updated my previous comment to state more precisely what is going on. This test was exclusively on the MBP, no USB-cam attached. If, however, I switch to the USB cam in Meets/Teams, this camera is detected properly. I'll keep thinking.

chrsvgt avatar Jan 28 '21 21:01 chrsvgt

Ha! This is even stranger behavior it seems. Am I correct to say that the camera is reported to be off when starting onair, then turning it on will cause it to first switch to off and then to on and any subsequent toggles will not do anything anymore?

wouterdebie avatar Jan 28 '21 22:01 wouterdebie

No, the camera is reported to be on when starting onair. From here, PhotoBooth does not trigger the change listener at all. Meet/Teams, when starting, does not trigger the listener. Meet starts with camera on, i.e. the camera is here switched from off to on, onair is already in on state and no change is triggered which is ok but the initial on state is wrong. Now, when toggling inside either Teams or Meet the camera to off -> no change listener is triggered, it remains in on state in onair. When toggling to on, change listener is triggered twice: first to off, then to on about 1-2 seconds later.

I am puzzled why a) it is initially detected as on b) switching to off in Meet/Teams has no effect, no change listener is triggered. (and its state is on in onair)

chrsvgt avatar Jan 28 '21 22:01 chrsvgt

Yes, I don't understand this at all either. What happens when you turn the camera off after it's state has been identified correctly?

wouterdebie avatar Jan 28 '21 22:01 wouterdebie

Could it be a bug in macOS?

wouterdebie avatar Jan 28 '21 22:01 wouterdebie

Nothing happens in onair when I turn the camera off after it has been correctly detected as being on. I guess I will now wait for the final release of 11.2 where RC3 came out just yesterday, cannot be too far out. If this does not magically fix it, I'll try to find a way / place where can submit an incident more closely to Apple / CoreMedia / Mac OS.

chrsvgt avatar Jan 29 '21 07:01 chrsvgt

Interim update, there was no magic fix by jumping to Big Sur 11.2 (as expected).

chrsvgt avatar Feb 04 '21 11:02 chrsvgt

@chrsvgt thanks for checking!

wouterdebie avatar Feb 04 '21 14:02 wouterdebie

Reason for this bug : "The M1 MacBooks include a hardware-based Image Signal Processor (ISP) for the webcam to enhance the image. appleh13camerad is Apple's software driver for the Image Signal Processor. It's supposed to be loaded. It doesn't do anything when your camera isn't turned on." Ref.: https://www.reddit.com/r/mac/comments/l9xfnl/apple13camerad/

So with an M1 MacBook machine, the kCMIODevicePropertyDeviceIsRunningSomewhere will always be true .

I didn't find any workaround yet for this issue. I am reporting it to Apple now because this is a documented public API that should work.

szigetics avatar Jun 08 '21 12:06 szigetics

Came across a tool, https://objective-see.com/products/oversight.html, which introduced and implements the special handling for M1 hardware.

https://github.com/objective-see/OverSight/blob/680dd2cc70e8ef590f93212bd1d1ae9e1bc0b93b/Application/Application/AVMonitor.m#L151

Seems the approach here is to monitor the camera daemon log and fish for appropriate messages.

chrsvgt avatar Jun 09 '21 07:06 chrsvgt

@chrsvgt interesting! Thanks for sharing this! I don't have much time the next few weeks to implement something like this and since I don't own an M1, I can't test it either. Maybe there's someone else who could try to implement this?

wouterdebie avatar Jun 09 '21 14:06 wouterdebie

Has there been any progress on this? :)

CLNMR avatar Oct 05 '22 10:10 CLNMR

I still don't have a M1/M2, but I might get one in a few months or so. Once I do, I'll work on this.

wouterdebie avatar Oct 05 '22 17:10 wouterdebie

Thanks for the reply! Not quite sure what went wrong the first day, but now it seems to work just fine on my mac with a M1 chip. Thanks for the tool!

CLNMR avatar Oct 07 '22 07:10 CLNMR

I got an M3 yesterday and could FINALLY test this :) And I figured out what was wrong! On arm laptops, all cameras are "virtual", since they seem to run through that appleh13camerad and onair would not add listeners to virtual cameras. I'm pushing a fix in a few minutes that completely removes all the virtual camera differentiation, since there already is functionality to ignore cameras you don't want onair to act on.

wouterdebie avatar Apr 06 '24 21:04 wouterdebie