Bug 1225636 - Facetimehd firmware/driver fails to load
Summary: Facetimehd firmware/driver fails to load
Status: RESOLVED FIXED
Alias: None
Product: openSUSE Tumbleweed
Classification: openSUSE
Component: Kernel:Drivers (show other bugs)
Version: Current
Hardware: x86-64 openSUSE Tumbleweed
: P5 - None : Normal (vote)
Target Milestone: ---
Assignee: Patrik Jakobsson
QA Contact: E-mail List
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2024-05-30 00:08 UTC by Clayton Castro
Modified: 2024-07-04 20:27 UTC (History)
2 users (show)

See Also:
Found By: ---
Services Priority:
Business Priority:
Blocker: ---
Marketing QA Status: ---
IT Deployment: ---


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Clayton Castro 2024-05-30 00:08:42 UTC
Hardware is a late 2015 11" Macbook Air. The facetimehd-kmp-default package was installed by default and I installed the facetimehd-firmware manually, despite this the driver fails to load and the camera is not detected as a device.

[I] clayton@s-169-232-95-114 ~> dmesg -w | grep facetimehd
[    2.934906] [  T349] facetimehd 0000:02:00.0: Found FaceTime HD camera with device id: 1570
[    2.937304] [  T349] facetimehd 0000:02:00.0: Setting 64bit DMA mask
[    2.958735] [  T349] facetimehd 0000:02:00.0: S2 PCIe link init succeeded
[    2.958770] [  T349] facetimehd 0000:02:00.0: Refclk: 25MHz (0xa)
[    2.968787] [  T349] facetimehd 0000:02:00.0: PLL reset finished
[    2.968793] [  T349] facetimehd 0000:02:00.0: Waiting for S2 PLL to lock at 450 MHz
[    2.968808] [  T349] facetimehd 0000:02:00.0: S2 PLL is locked after 10 us
[    2.978828] [  T349] facetimehd 0000:02:00.0: S2 PLL is in bypass mode
[    2.998898] [  T349] facetimehd 0000:02:00.0: DDR40 PHY PLL locked on safe settings
[    2.998916] [  T349] facetimehd 0000:02:00.0: STRAP valid
[    2.998917] [  T349] facetimehd 0000:02:00.0: Configuring DDR PLLs for 450 MHz
[    2.998925] [  T349] facetimehd 0000:02:00.0: DDR40 PLL is locked after 0 us
[    2.998935] [  T349] facetimehd 0000:02:00.0: First DDR40 VDL calibration completed after 2 us
[    2.998943] [  T349] facetimehd 0000:02:00.0: Second DDR40 VDL calibration completed after 1 us
[    2.998944] [  T349] facetimehd 0000:02:00.0: Using step size 144
[    2.998950] [  T349] facetimehd 0000:02:00.0: VDL set to: coarse=0x10008, fine=0x10119
[    2.998955] [  T349] facetimehd 0000:02:00.0: Virtual VTT enabled
[    3.019479] [  T349] facetimehd 0000:02:00.0: S2 DRAM memory address: 0x22159559
[    3.019496] [  T349] facetimehd 0000:02:00.0: Rewrite DDR mode registers succeeded
[    3.019719] [  T349] facetimehd 0000:02:00.0: Full memory verification succeeded! (0)
[    3.019942] [  T349] facetimehd 0000:02:00.0: Direct firmware load for facetimehd/firmware.bin failed with error -2
[    3.020079] [  T349] facetimehd 0000:02:00.0: probe with driver facetimehd failed with error -2

I force reinstalled both and rebooted but still saw the same behavior.

additional context:
uname -a
Linux localhost.localdomain 6.9.1-1-default #1 SMP PREEMPT_DYNAMIC Fri May 17 11:59:46 UTC 2024 (0c0b0b5) x86_64 x86_64 x86_64 GNU/Linux
Comment 1 Takashi Iwai 2024-05-30 06:13:13 UTC
The error message:
  [    3.019942] [  T349] facetimehd 0000:02:00.0: Direct firmware load for facetimehd/firmware.bin failed with error -2
implies the file not found.  Do you have a file at /usr/lib/firmware/facetimehd/firmware.bin?

In anyway tossing to Patrik.
Comment 2 Patrik Jakobsson 2024-05-30 06:24:17 UTC
The facetimehd-firmware package requires you to be connected to the internet when installing the package. Perhaps this is the issue?

Do as Takashi says, check if the firmware file exists (/usr/lib/firmware/facetimehd/firmware.bin). If it doesn't, try reinstalling the facetimehd-firmware package and provide the output from that operation:

For me it looks like this:
Retrieving: facetimehd-firmware-1.0-1.8.noarch (Main Repository (OSS))
                                                            (1/1),   9,5 KiB    
Retrieving: facetimehd-firmware-1.0-1.8.noarch.rpm .......................[done]

Checking for file conflicts: .............................................[done]
(1/1) Installing: facetimehd-firmware-1.0-1.8.noarch .....................[done]
Running post-transaction scripts .........................................[done]
Running: facetimehd-firmware-1.0-1.8-facetimehd-firmware-install.sh.txt  (facetimehd-firmware, /var/adm/update-scripts)
FacetimeHD firmware download and installation script

Downloading driver...done
Extracting firmware...done
Installing firmware...done
Running: facetimehd-firmware-1.0-1.8-facetimehd-firmware-install.sh.txt  ([done]
Comment 3 Clayton Castro 2024-05-30 16:39:34 UTC
The package wouldn't have installed in the first place if I didn't have internet access. I've force reinstalled both the kernel driver and firmware multiple times and rebooted. The file indeed exists (check last line below). 

[I] clayton@s-169-232-95-114 ~> sudo zypper search facetimehd
Retrieving repository 'Packman' metadata ...............................................................[done]
Building repository 'Packman' cache ....................................................................[done]
Retrieving repository 'packman-essentials' metadata ....................................................[done]
Building repository 'packman-essentials' cache .........................................................[done]
Loading repository data...
Reading installed packages...

S  | Name                   | Summary                                          | Type
---+------------------------+--------------------------------------------------+--------
i+ | facetimehd-firmware    | FacetimeHD firmware download and extraction tool | package
i+ | facetimehd-kmp-default | Kernel driver for the Apple FacetimeHD webcams   | package


[I] clayton@s-169-232-95-114 ~> sudo zypper in -y --force facetimehd-firmware facetimehd-kmp-default
Loading repository data...
Reading installed packages...
Forcing installation of 'facetimehd-firmware-1.0-1.8.noarch' from repository 'openSUSE-Tumbleweed-Oss'.
Forcing installation of 'facetimehd-kmp-default-0.6.8.1_k6.9.1_1-1.2.x86_64' from repository 'openSUSE-Tumbleweed-Oss'.
Resolving package dependencies...

The following 2 packages are going to be reinstalled:
  facetimehd-firmware facetimehd-kmp-default-0.6.8.1_k6.9.1_1-1.2

2 packages to reinstall.
Overall download size: 74.3 KiB. Already cached: 0 B. No additional space will be used or freed after the
operation.

Backend:  classic_rpmtrans
Continue? [y/n/v/...? shows all options] (y): y
Retrieving: facetimehd-firmware-1.0-1.8.noarch (openSUSE-Tumbleweed-Oss)                  (1/2),   9.5 KiB
Retrieving: facetimehd-firmware-1.0-1.8.noarch.rpm .........................................[done (2.6 KiB/s)]
Retrieving: facetimehd-kmp-default-0.6.8.1_k6.9.1_1-1.2.x86_64 (openSUSE-Tumbleweed-Oss)  (2/2),  64.8 KiB
Retrieving: facetimehd-kmp-default-0.6.8.1_k6.9.1_1-1.2.x86_64.rpm .........................[done (2.8 KiB/s)]

Checking for file conflicts: ...........................................................................[done]
(1/2) Installing: facetimehd-firmware-1.0-1.8.noarch ...................................................[done]
(2/2) Installing: facetimehd-kmp-default-0.6.8.1_k6.9.1_1-1.2.x86_64 ...................................[done]
%posttrans(facetimehd-kmp-default-0.6.8.1_k6.9.1_1-1.2.x86_64) script output:
dracut[I]: Executing: /usr/bin/dracut -f --kver 6.9.1-1-default
dracut[I]: Module 'systemd-networkd' will not be installed, because command 'networkctl' could not be found!
dracut[I]: Module 'systemd-networkd' will not be installed, because command '/usr/lib/systemd/systemd-networkd' could not be found!
dracut[I]: Module 'systemd-networkd' will not be installed, because command '/usr/lib/systemd/systemd-networkd-wait-online' could not be found!
dracut[I]: Module 'systemd-pcrphase' will not be installed, because command '/usr/lib/systemd/systemd-pcrextend' could not be found!
dracut[I]: Module 'systemd-portabled' will not be installed, because command 'portablectl' could not be found!
dracut[I]: Module 'systemd-portabled' will not be installed, because command '/usr/lib/systemd/systemd-portabled' could not be found!
dracut[I]: Module 'systemd-resolved' will not be installed, because command 'resolvectl' could not be found!
dracut[I]: Module 'systemd-resolved' will not be installed, because command '/usr/lib/systemd/systemd-resolved' could not be found!
dracut[I]: Module 'dbus-broker' will not be installed, because command 'dbus-broker' could not be found!
dracut[I]: Module 'rngd' will not be installed, because command 'rngd' could not be found!
dracut[I]: Module 'connman' will not be installed, because command 'connmand' could not be found!
dracut[I]: Module 'connman' will not be installed, because command 'connmanctl' could not be found!
dracut[I]: Module 'connman' will not be installed, because command 'connmand-wait-online' could not be found!
dracut[I]: 35network-legacy: Could not find any command of 'dhclient wicked'!
dracut[I]: Module 'tpm2-tss' will not be installed, because command 'tpm2' could not be found!
dracut[I]: Module 'iscsi' will not be installed, because command 'iscsi-iname' could not be found!
dracut[I]: Module 'iscsi' will not be installed, because command 'iscsiadm' could not be found!
dracut[I]: Module 'iscsi' will not be installed, because command 'iscsid' could not be found!
dracut[I]: Module 'biosdevname' will not be installed, because command 'biosdevname' could not be found!
dracut[I]: Module 'memstrack' will not be installed, because command 'memstrack' could not be found!
dracut[I]: memstrack is not available
dracut[I]: If you need to use rd.memdebug>=4, please install memstrack and procps-ng
dracut[I]: Module 'systemd-pcrphase' will not be installed, because command '/usr/lib/systemd/systemd-pcrextend' could not be found!
dracut[I]: Module 'systemd-portabled' will not be installed, because command 'portablectl' could not be found!
dracut[I]: Module 'systemd-portabled' will not be installed, because command '/usr/lib/systemd/systemd-portabled' could not be found!
dracut[I]: Module 'systemd-resolved' will not be installed, because command 'resolvectl' could not be found!
dracut[I]: Module 'systemd-resolved' will not be installed, because command '/usr/lib/systemd/systemd-resolved' could not be found!
dracut[I]: Module 'dbus-broker' will not be installed, because command 'dbus-broker' could not be found!
dracut[I]: Module 'rngd' will not be installed, because command 'rngd' could not be found!
dracut[I]: Module 'connman' will not be installed, because command 'connmand' could not be found!
dracut[I]: Module 'connman' will not be installed, because command 'connmanctl' could not be found!
dracut[I]: Module 'connman' will not be installed, because command 'connmand-wait-online' could not be found!
dracut[I]: 35network-legacy: Could not find any command of 'dhclient wicked'!
dracut[I]: Module 'tpm2-tss' will not be installed, because command 'tpm2' could not be found!
dracut[I]: Module 'iscsi' will not be installed, because command 'iscsi-iname' could not be found!
dracut[I]: Module 'iscsi' will not be installed, because command 'iscsiadm' could not be found!
dracut[I]: Module 'iscsi' will not be installed, because command 'iscsid' could not be found!
dracut[I]: Module 'memstrack' will not be installed, because command 'memstrack' could not be found!
dracut[I]: memstrack is not available
dracut[I]: If you need to use rd.memdebug>=4, please install memstrack and procps-ng
dracut[I]: *** Including module: systemd ***
dracut[I]: *** Including module: systemd-initrd ***
dracut[I]: *** Including module: i18n ***
dracut[I]: *** Including module: drm ***
dracut[I]: *** Including module: plymouth ***
dracut[I]: *** Including module: btrfs ***
dracut[I]: *** Including module: kernel-modules ***
dracut[I]: *** Including module: kernel-modules-extra ***
dracut[I]: *** Including module: resume ***
dracut[I]: *** Including module: rootfs-block ***
dracut[I]: *** Including module: suse-btrfs ***
dracut[I]: *** Including module: suse-xfs ***
dracut[I]: *** Including module: terminfo ***
dracut[I]: *** Including module: udev-rules ***
dracut[I]: *** Including module: dracut-systemd ***
dracut[I]: *** Including module: ostree ***
dracut[I]: *** Including module: usrmount ***
dracut[I]: *** Including module: base ***
dracut[I]: *** Including module: fs-lib ***
dracut[I]: *** Including module: shutdown ***
dracut[I]: *** Including module: suse ***
dracut[I]: *** Including module: suse-initrd ***
dracut[I]: *** Including modules done ***
dracut[I]: *** Installing kernel module dependencies ***
dracut[I]: *** Installing kernel module dependencies done ***
dracut[I]: *** Resolving executable dependencies ***
dracut[I]: *** Resolving executable dependencies done ***
dracut[I]: *** Hardlinking files ***
dracut[I]: *** Hardlinking files done ***
dracut[I]: *** Generating early-microcode cpio image ***
dracut[I]: *** Constructing GenuineIntel.bin ***
dracut[I]: *** Store current command line parameters ***
dracut[I]: Stored kernel commandline:
dracut[I]:  rd.driver.pre=btrfs
dracut[I]:  resume=UUID=49208a23-802b-4c44-af75-a08f4f55c319
dracut[I]:  root=UUID=5b0a18d6-e820-48e9-934a-2e2e81819993 rootfstype=btrfs rootflags=rw,relatime,ssd,discard=async,space_cache=v2,subvolid=266,subvol=/@/.snapshots/1/snapshot,subvol=@/.snapshots/1/snapshot
dracut[I]: *** Stripping files ***
dracut[I]: *** Stripping files done ***
dracut[I]: *** Creating image file '/boot/initrd-6.9.1-1-default' ***
dracut[I]: *** Creating initramfs image file '/boot/initrd-6.9.1-1-default' done ***
Running post-transaction scripts .......................................................................[done]
Running: facetimehd-firmware-1.0-1.8-facetimehd-firmware-install.sh.txt  (facetimehd-firmware, /var/adm/update-scripts)
FacetimeHD firmware download and installation script

Downloading driver...done
Extracting firmware...done
Installing firmware...done
Running: facetimehd-firmware-1.0-1.8-facetimehd-firmware-install.sh.txt  (facetimehd-firmware, /var/adm/[done]


[I] clayton@s-169-232-95-114 ~> ll /lib/firmware/facetimehd/firmware.bin
-rw-r--r-- 1 root root 1425412 May 30 09:33 /lib/firmware/facetimehd/firmware.bin
Comment 4 Patrik Jakobsson 2024-05-31 06:37:51 UTC
(In reply to Clayton Castro from comment #3)
> The package wouldn't have installed in the first place if I didn't have
> internet access. 

Packages can be installed without internet access so I had to ask.

> I've force reinstalled both the kernel driver and firmware
> multiple times and rebooted. The file indeed exists (check last line below). 

Yes the firmware file is where it should be. What looks strange is that dracut is triggered to generate an initrd when installing the kmp. If the kmp but not the firmware is installed into the initrd it would be missing when the driver loads at boot. Do you have any special dracut configs?

Does the module load properly if you reload it with:
$ modprobe -r facetimehd
$ modprobe facetimehd
Comment 5 Takashi Iwai 2024-05-31 07:55:09 UTC
BTW, the proper path for firmware files after TW (and former ALP) are /usr/lib/firmware.  I guess /lib/firmware still works, but the package should manage the right path instead.
Comment 6 Clayton Castro 2024-05-31 18:28:18 UTC
(In reply to Patrik Jakobsson from comment #4)

> Packages can be installed without internet access so I had to ask.

Sorry, wasn't aware.

> Do you have any special dracut configs?

I haven't touched dracut.
 
> Does the module load properly

[I] clayton@localhost ~> sudo modprobe -r facetimehd
[I] clayton@localhost ~> sudo modprobe facetimehd
[I] clayton@localhost ~> lsmod | grep facetimehd
facetimehd            139264  0
videobuf2_v4l2         45056  1 facetimehd
videobuf2_dma_sg       20480  2 facetimehd
videodev              409600  2 videobuf2_v4l2,facetimehd
videobuf2_common       94208  4 videobuf2_v4l2,facetimehd,videobuf2_dma_sg,videobuf2_memops
[I] clayton@localhost ~ [127]> modinfo facetimehd
filename:       /usr/lib/modules/6.9.1-1-default/updates/facetimehd.ko
license:        GPL
description:    FacetimeHD camera driver
author:         Patrik Jakobsson <patrik.r.jakobsson@gmail.com>
suserelease:    openSUSE Tumbleweed
srcversion:     6AD55175D3B9C6B3A15A764
alias:          pci:v000014E4d00001570sv*sd*bc*sc*i*
depends:        videodev,videobuf2-v4l2,videobuf2-common,videobuf2-dma-sg
retpoline:      Y
name:           facetimehd
vermagic:       6.9.1-1-default SMP preempt mod_unload modversions
sig_id:         PKCS#7
signer:         openSUSE Secure Boot CA
sig_key:        FA:BE:D8:BF:40:9A:5E:65
sig_hashalgo:   sha256
signature:      17:0B:38:30:6E:93:2C:C5:5F:B7:C9:C7:9C:5D:ED:2F:9E:03:0C:61:
                B5:96:C0:5B:8F:0E:FB:60:15:36:0D:93:21:B6:38:13:B5:A6:51:08:
                B7:F4:70:0A:BF:0D:40:47:4A:BA:56:21:EC:CB:86:56:34:2F:D8:06:
                94:9F:4D:7D:08:25:42:C8:01:B2:18:52:6D:17:59:F4:4B:96:F0:D0:
                65:9F:A7:A2:62:C3:08:E8:21:D6:94:73:2C:84:AB:9E:24:74:DB:81:
                BB:23:07:FF:66:D0:D9:D1:13:F7:8F:CE:F0:01:D2:2A:2F:2C:68:99:
                F2:88:33:82:B5:BA:01:43:63:0F:F3:D3:24:AA:22:EF:71:E6:A2:12:
                2F:C4:F0:DF:EF:37:D9:00:71:21:63:36:6A:48:1F:35:AE:DE:AA:16:
                6C:B7:4E:F2:7D:A2:BB:BE:BE:25:BA:48:9E:26:C3:83:E3:BF:8A:7F:
                15:3D:3E:85:C5:AC:63:35:99:4D:95:4D:13:75:22:9B:FC:DF:CE:54:
                2C:4F:A2:D6:81:54:31:2D:E5:3C:38:1A:B1:DE:E7:40:E1:C6:99:39:
                F5:A4:D4:2F:E9:8F:65:42:2C:A1:F1:BA:ED:B5:69:82:DA:E9:49:D7:
                6E:0F:AD:31:C7:81:09:56:31:DE:F0:99:E9:97:A8:2E

I've been testing with cheese,

[I] clayton@localhost ~> cheese
(cheese:870): cheese-WARNING **: 11:22:06.914: stream error: can't negotiate buffers on port: ../src/gst/gstpipewiresrc.c(692): on_state_changed (): /GstCameraBin:camerabin/GstWrapperCameraBinSrc:camera_source/GstBin:bin36/GstPipeWireSrc:pipewiresrc1

Running without manually loading the module results in a no device found error, but that's to be expected.

> BTW, the proper path for firmware files after TW (and former ALP) are /usr/lib/firmware.  I guess /lib/firmware still works, but the package should manage the right path instead.

[I] clayton@localhost ~> ll /usr/lib/firmware/facetimehd/firmware.bin
-rw-r--r-- 1 root root 1425412 May 30 09:33 /usr/lib/firmware/facetimehd/firmware.bin
[I] clayton@localhost ~> ll /lib/firmware/facetimehd/firmware.bin
-rw-r--r-- 1 root root 1425412 May 30 09:33 /lib/firmware/facetimehd/firmware.bin

It seems to exist in both locations.
Comment 7 Patrik Jakobsson 2024-06-03 08:16:07 UTC
(In reply to Clayton Castro from comment #6)
> > Do you have any special dracut configs?
> 
> I haven't touched dracut.

When I try installing the driver it doesn't end up on the initrd so something is different in our configs. Maybe I've changed something on my end. Can you paste the output from the command:
$ cat /etc/dracut.conf.d/*

> I've been testing with cheese,

There is an issue with Cheese and the driver. Can you try some other application? I usually test with qv4l2.
Comment 8 Clayton Castro 2024-06-03 08:53:29 UTC
> Can you paste the output from the command:
> $ cat /etc/dracut.conf.d/*

# When dracut generates the initramfs, it must refer to disks and partitions to
# be mounted in a persistent manner, to make sure the system will boot
# correctly. By default, dracut uses /dev/mapper device names.
# For example, when dracut detects multipath devices, it will use the DM-MP
# device names such as
#
# /dev/mapper/3600a098000aad73f00000a3f5a275dc8-part1
#
# This is good if the system always runs in multipath mode. But if the system is
# started without multipathing, booting with such an initramfs will fail,
# because the /dev/mapper devices will not exist. The same problem can happen
# with multipath maps and cloned SAN LUNs.
#
# To prevent this from happening, the dracut policy for addressing disks
# and partitions is changed to use /dev/disk/by-uuid device names on all
# architectures except s390/s390x, which must be by-path (bsc#915218).
persistent_policy="by-uuid"
# Below adds additional tools to the initrd which are not urgently necessary to
# bring up the system, but help to debug problems.
# See /usr/lib/dracut/modules.d/95debug/module-setup.sh which additional tools
# are installed and add more if you need them. This specifically helps if you
# use:
# rd.break=[cmdline|pre-udev|pre-trigger|initqueue|pre-mount|
# mount|pre-pivot|cleanup]
# boot parameter or if you are forced to enter the dracut emergency shell.

# add_dracutmodules+=" debug "
# Copyright (C) 2013 Colin Walters <walters@verbum.org>
#
# This library is free software; you can redistribute it and/or
# modify it under the terms of the GNU Lesser General Public
# License as published by the Free Software Foundation; either
# version 2 of the License, or (at your option) any later version.
#
# This library is distributed in the hope that it will be useful,
# but WITHOUT ANY WARRANTY; without even the implied warranty of
# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
# Lesser General Public License for more details.
#
# You should have received a copy of the GNU Lesser General Public
# License along with this library. If not, see <https://www.gnu.org/licenses/>.

add_dracutmodules+=" ostree systemd "
reproducible=yes

> There is an issue with Cheese and the driver. Can you try some other
> application? I usually test with qv4l2.

So looks like it works if I manually reload the kernel module. On boot its loaded but there's no video device (/dev/video0). Once I unload and load I can get a video output from both ffplay and firefox.

Output from a fresh boot looks like so:

[I] clayton@localhost ~ [SIGINT]> dmesg -w | grep facetimehd
[    2.217575] [  T353] facetimehd: loading out-of-tree module taints kernel.
[    2.244464] [  T353] facetimehd 0000:02:00.0: Found FaceTime HD camera with device id: 1570
[    2.244757] [  T353] facetimehd 0000:02:00.0: Setting 64bit DMA mask
[    2.269670] [  T353] facetimehd 0000:02:00.0: S2 PCIe link init succeeded
[    2.269707] [  T353] facetimehd 0000:02:00.0: Refclk: 25MHz (0xa)
[    2.279738] [  T353] facetimehd 0000:02:00.0: PLL reset finished
[    2.279743] [  T353] facetimehd 0000:02:00.0: Waiting for S2 PLL to lock at 450 MHz
[    2.279759] [  T353] facetimehd 0000:02:00.0: S2 PLL is locked after 10 us
[    2.289767] [  T353] facetimehd 0000:02:00.0: S2 PLL is in bypass mode
[    2.309814] [  T353] facetimehd 0000:02:00.0: DDR40 PHY PLL locked on safe settings
[    2.309836] [  T353] facetimehd 0000:02:00.0: STRAP valid
[    2.309839] [  T353] facetimehd 0000:02:00.0: Configuring DDR PLLs for 450 MHz
[    2.309860] [  T353] facetimehd 0000:02:00.0: DDR40 PLL is locked after 0 us
[    2.309872] [  T353] facetimehd 0000:02:00.0: First DDR40 VDL calibration completed after 2 us
[    2.309882] [  T353] facetimehd 0000:02:00.0: Second DDR40 VDL calibration completed after 1 us
[    2.309885] [  T353] facetimehd 0000:02:00.0: Using step size 144
[    2.309891] [  T353] facetimehd 0000:02:00.0: VDL set to: coarse=0x10008, fine=0x10119
[    2.309910] [  T353] facetimehd 0000:02:00.0: Virtual VTT enabled
[    2.330449] [  T353] facetimehd 0000:02:00.0: S2 DRAM memory address: 0x22159559
[    2.330469] [  T353] facetimehd 0000:02:00.0: Rewrite DDR mode registers succeeded
[    2.330707] [  T353] facetimehd 0000:02:00.0: Full memory verification succeeded! (0)
[    2.333543] [  T353] facetimehd 0000:02:00.0: Direct firmware load for facetimehd/firmware.bin failed with error -2
[    2.333708] [  T353] facetimehd 0000:02:00.0: probe with driver facetimehd failed with error -2
[    3.286168] [  T355] Modules linked in: wl(POE+) hid_apple crct10dif_pclmul hid_generic crc32_pclmul polyval_clmulni polyval_generic gf128mul ghash_clmulni_intel sha512_ssse3 sha256_ssse3 sha1_ssse3 usbhid aesni_intel nvme crypto_simd i915(+) cfg80211 cryptd nvme_core facetimehd(O) rfkill videobuf2_dma_sg videobuf2_memops nvme_auth t10_pi videobuf2_v4l2 xhci_pci xhci_pci_renesas i2c_algo_bit drm_buddy videodev ttm xhci_hcd applespi spi_pxa2xx_platform dw_dmac videobuf2_common video mc drm_display_helper wmi usbcore cec rc_core btrfs blake2b_generic libcrc32c crc32c_intel xor raid6_pq msr efivarfs
Comment 9 Clayton Castro 2024-06-03 08:56:10 UTC
Whereas the output from manually reloading the module is:
[  680.755112] [T10959] facetimehd 0000:02:00.0: Found FaceTime HD camera with device id: 1570
[  680.755349] [T10959] facetimehd 0000:02:00.0: Setting 64bit DMA mask
[  680.762120] [T10959] facetimehd 0000:02:00.0: S2 PCIe link init succeeded
[  680.762157] [T10959] facetimehd 0000:02:00.0: Refclk: 25MHz (0xa)
[  680.772174] [T10959] facetimehd 0000:02:00.0: PLL reset finished
[  680.772177] [T10959] facetimehd 0000:02:00.0: Waiting for S2 PLL to lock at 450 MHz
[  680.772190] [T10959] facetimehd 0000:02:00.0: S2 PLL is locked after 10 us
[  680.782198] [T10959] facetimehd 0000:02:00.0: S2 PLL is in bypass mode
[  680.802238] [T10959] facetimehd 0000:02:00.0: DDR40 PHY PLL locked on safe settings
[  680.802255] [T10959] facetimehd 0000:02:00.0: STRAP valid
[  680.802257] [T10959] facetimehd 0000:02:00.0: Configuring DDR PLLs for 450 MHz
[  680.802264] [T10959] facetimehd 0000:02:00.0: DDR40 PLL is locked after 0 us
[  680.802274] [T10959] facetimehd 0000:02:00.0: First DDR40 VDL calibration completed after 2 us
[  680.802282] [T10959] facetimehd 0000:02:00.0: Second DDR40 VDL calibration completed after 1 us
[  680.802283] [T10959] facetimehd 0000:02:00.0: Using step size 144
[  680.802288] [T10959] facetimehd 0000:02:00.0: VDL set to: coarse=0x10008, fine=0x10119
[  680.802293] [T10959] facetimehd 0000:02:00.0: Virtual VTT enabled
[  680.822815] [T10959] facetimehd 0000:02:00.0: S2 DRAM memory address: 0x22159559
[  680.822832] [T10959] facetimehd 0000:02:00.0: Rewrite DDR mode registers succeeded
[  680.823028] [T10959] facetimehd 0000:02:00.0: Full memory verification succeeded! (0)
[  680.944702] [T10959] facetimehd 0000:02:00.0: Loaded firmware, size: 1392kb
[  681.101901] [T10959] facetimehd 0000:02:00.0: ISP woke up after 0ms
[  681.101911] [T10959] facetimehd 0000:02:00.0: Number of IPC channels: 7, queue size: 44865
[  681.101916] [T10959] facetimehd 0000:02:00.0: Firmware requested heap size: 3072kb
[  681.111937] [T10959] facetimehd 0000:02:00.0: ISP second int after 0ms
[  681.111944] [T10959] facetimehd 0000:02:00.0: Channel description table at 00800000
[  681.122222] [T10959] facetimehd 0000:02:00.0: magic value: 00000000 after 0 ms
[  681.122227] [T10959] facetimehd 0000:02:00.0: Enabling interrupts
[  681.196106] [T10959] facetimehd 0000:02:00.0: Direct firmware load for facetimehd/1871_01XX.dat failed with error -2
Comment 10 Patrik Jakobsson 2024-06-05 12:13:30 UTC
I've made a few changes to the driver and the package.

Can you try uninstalling the facetimehd-kmp-default and facetimehd-firmware packages and the reinstall from https://build.opensuse.org/package/show/home:patrikjakobsson:branches:hardware/facetimehd

This time you should only need to install facetimehd-kmp-default. The firmware package should be picked automatically.
Comment 11 Patrik Jakobsson 2024-07-03 12:04:30 UTC
Any update on the testing? I went ahead and pushed the changes to factory so they are probably already in Tumbleweed by now.
Comment 12 Clayton Castro 2024-07-04 01:00:46 UTC
Sorry lost track of this due to uni finals etc.

I just updated tumbleweed to and got the package updates. Unfortunately the module now refuses to work even if I manually reload it like before.

$ sudo zypper info facetimehd-firmware
Information for package facetimehd-firmware:
--------------------------------------------
Repository     : openSUSE-Tumbleweed-Oss
Name           : facetimehd-firmware
Version        : 1.0-1.8
Arch           : noarch
Vendor         : openSUSE
Installed Size : 1.6 KiB
Installed      : Yes (automatically)
Status         : up-to-date
Source package : facetimehd-firmware-1.0-1.8.src
Upstream URL   : https://github.com/patjak/facetimehd-firmware
Summary        : FacetimeHD firmware download and extraction tool
Description    :
    FacetimeHD firmware download and extraction tool

$ sudo zypper info facetimehd-kmp-default
Information for package facetimehd-kmp-default:
-----------------------------------------------
Repository     : openSUSE-Tumbleweed-Oss
Name           : facetimehd-kmp-default
Version        : 0.6.8.2_k6.9.7_1-1.3
Arch           : x86_64
Vendor         : openSUSE
Installed Size : 291.0 KiB
Installed      : Yes (automatically)
Status         : up-to-date
Source package : facetimehd-0.6.8.2-1.3.src
Upstream URL   : https://github.com/patjak/facetimehd
Summary        : Kernel driver for the Apple FacetimeHD webcams
Description    :
    Reverse engineered Linux driver for the FacetimeHD PCIe webcam

# output from fresh boot
$ sudo dmesg | grep facetimehd
[    3.198565] [    T360] facetimehd: loading out-of-tree module taints kernel.
[    3.201399] [    T360] facetimehd 0000:02:00.0: Found FaceTime HD camera with device id: 1570
[    3.202104] [    T360] facetimehd 0000:02:00.0: Setting 64bit DMA mask
[    3.208883] [    T360] facetimehd 0000:02:00.0: S2 PCIe link init succeeded
[    3.208929] [    T360] facetimehd 0000:02:00.0: Refclk: 25MHz (0xa)
[    3.218945] [    T360] facetimehd 0000:02:00.0: PLL reset finished
[    3.218950] [    T360] facetimehd 0000:02:00.0: Waiting for S2 PLL to lock at 450 MHz
[    3.218965] [    T360] facetimehd 0000:02:00.0: S2 PLL is locked after 10 us
[    3.228985] [    T360] facetimehd 0000:02:00.0: S2 PLL is in bypass mode
[    3.249039] [    T360] facetimehd 0000:02:00.0: DDR40 PHY PLL locked on safe settings
[    3.249071] [    T360] facetimehd 0000:02:00.0: STRAP valid
[    3.249073] [    T360] facetimehd 0000:02:00.0: Configuring DDR PLLs for 450 MHz
[    3.249082] [    T360] facetimehd 0000:02:00.0: DDR40 PLL is locked after 0 us
[    3.249093] [    T360] facetimehd 0000:02:00.0: First DDR40 VDL calibration completed after 2 us
[    3.249103] [    T360] facetimehd 0000:02:00.0: Second DDR40 VDL calibration completed after 1 us
[    3.249105] [    T360] facetimehd 0000:02:00.0: Using step size 145
[    3.249112] [    T360] facetimehd 0000:02:00.0: VDL set to: coarse=0x10008, fine=0x10119
[    3.249119] [    T360] facetimehd 0000:02:00.0: Virtual VTT enabled
[    3.269644] [    T360] facetimehd 0000:02:00.0: S2 DRAM memory address: 0x22159559
[    3.269664] [    T360] facetimehd 0000:02:00.0: Rewrite DDR mode registers succeeded
[    3.269906] [    T360] facetimehd 0000:02:00.0: Full memory verification succeeded! (0)
[    3.270390] [    T360] facetimehd 0000:02:00.0: Direct firmware load for facetimehd/firmware.bin failed with error -2
[    3.270531] [    T360] facetimehd 0000:02:00.0: probe with driver facetimehd failed with error -2
[    3.437014] [    T368] Modules linked in: wl(POE+) hid_apple crct10dif_pclmul crc32_pclmul polyval_clmulni polyval_generic gf128mul ghash_clmulni_intel sha512_ssse3 hid_generic sha256_ssse3 sha1_ssse3 facetimehd(O) usbhid aesni_intel videobuf2_dma_sg crypto_simd videobuf2_memops i915(+) cryptd videobuf2_v4l2 nvme cfg80211 xhci_pci videodev i2c_algo_bit drm_buddy applespi xhci_pci_renesas ttm videobuf2_common video drm_display_helper nvme_core xhci_hcd nvme_auth rfkill t10_pi mc wmi spi_pxa2xx_platform usbcore dw_dmac cec rc_core btrfs blake2b_generic libcrc32c crc32c_intel xor raid6_pq msr i2c_dev efivarfs

$ # output from reloading the module
$ sudo modprobe -r facetimehd
$ sudo modprobe facetimehd
$ sudo dmesg | grep facetimehd
[  103.905250] [   T4567] facetimehd 0000:02:00.0: Found FaceTime HD camera with device id: 1570
[  103.905485] [   T4567] facetimehd 0000:02:00.0: Setting 64bit DMA mask
[  103.911435] [   T4567] facetimehd 0000:02:00.0: S2 PCIe link init succeeded
[  103.911464] [   T4567] facetimehd 0000:02:00.0: Refclk: 25MHz (0xa)
[  103.921476] [   T4567] facetimehd 0000:02:00.0: PLL reset finished
[  103.921477] [   T4567] facetimehd 0000:02:00.0: Waiting for S2 PLL to lock at 450 MHz
[  103.921490] [   T4567] facetimehd 0000:02:00.0: S2 PLL is locked after 10 us
[  103.931496] [   T4567] facetimehd 0000:02:00.0: S2 PLL is in bypass mode
[  103.951531] [   T4567] facetimehd 0000:02:00.0: DDR40 PHY PLL locked on safe settings
[  103.951545] [   T4567] facetimehd 0000:02:00.0: STRAP valid
[  103.951546] [   T4567] facetimehd 0000:02:00.0: Configuring DDR PLLs for 450 MHz
[  103.951554] [   T4567] facetimehd 0000:02:00.0: DDR40 PLL is locked after 0 us
[  103.951563] [   T4567] facetimehd 0000:02:00.0: First DDR40 VDL calibration completed after 2 us
[  103.951572] [   T4567] facetimehd 0000:02:00.0: Second DDR40 VDL calibration completed after 1 us
[  103.951573] [   T4567] facetimehd 0000:02:00.0: Using step size 144
[  103.951578] [   T4567] facetimehd 0000:02:00.0: VDL set to: coarse=0x10008, fine=0x10118
[  103.951583] [   T4567] facetimehd 0000:02:00.0: Virtual VTT enabled
[  103.972104] [   T4567] facetimehd 0000:02:00.0: S2 DRAM memory address: 0x22159559
[  103.972120] [   T4567] facetimehd 0000:02:00.0: Rewrite DDR mode registers succeeded
[  103.972319] [   T4567] facetimehd 0000:02:00.0: Full memory verification succeeded! (0)
[  103.972563] [   T4567] facetimehd 0000:02:00.0: Direct firmware load for facetimehd/firmware.bin failed with error -2
[  103.972730] [   T4567] facetimehd 0000:02:00.0: probe with driver facetimehd failed with error -2
Comment 13 Patrik Jakobsson 2024-07-04 08:09:49 UTC
How did you update to the new version? Just zypper dup?
Perhaps you need to remove both packages first.

$ zypper remove facetimehd-kmp-default facetimehd-firmware

and then reinstall just the kmp with

$ zypper in facetimehd-kmp-default

This installs both the kmp and firmware for me on my tumbleweed system.
Comment 14 Clayton Castro 2024-07-04 19:55:44 UTC
> Just zypper dup?

Yea I assumed the packages would get upgraded along with the system upgrade, is it normal that they didn't?

After uninstalling both and reinstalling kmp everything seems to be working now. The firmware loads fine and the webcam is usable.

Thanks for the fix!
Comment 15 Patrik Jakobsson 2024-07-04 20:27:21 UTC
(In reply to Clayton Castro from comment #14)
> > Just zypper dup?
> 
> Yea I assumed the packages would get upgraded along with the system upgrade,
> is it normal that they didn't?

It did get updated but looks like the firmware package didn't get the firmware installed correctly. Not sure why.

> 
> After uninstalling both and reinstalling kmp everything seems to be working
> now. The firmware loads fine and the webcam is usable.
> 
> Thanks for the fix!

Let's hope this was all that is needed. Thanks for the report. Closing as resolved fixed.