search

patjak / facetimehd

Reverse engineered Linux driver for the FacetimeHD (Broadcom 1570) PCIe webcam
GNU General Public License v2.0
1.36k stars 161 forks source link

Ratelimit firmware messages which can be quite spammy #94

Closed ronin13 closed 8 years ago

ronin13 commented 8 years ago

Otherwise, firmware messages can end up spamming dmesg much like:

        [  +0.033402] FWMSG: ERR: ./H4ISPCD/filters/IC/CImageCaptureH4.cpp, 777: FlowIC00: SIF errors: sifIrq = 0x8a!
        [  +0.033322] FWMSG: ERR: ./H4ISPCD/filters/IC/CImageCaptureH4.cpp, 777: FlowIC00: SIF errors: sifIrq = 0x8a!
        [  +0.033323] FWMSG: ERR: ./H4ISPCD/filters/IC/CImageCaptureH4.cpp, 777: FlowIC00: SIF errors: sifIrq = 0x8a!
        [  +0.033459] FWMSG: ERR: ./H4ISPCD/filters/IC/CImageCaptureH4.cpp, 777: FlowIC00: SIF errors: sifIrq = 0x8a!
        [  +0.033234] FWMSG: ERR: ./H4ISPCD/filters/IC/CImageCaptureH4.cpp, 777: FlowIC00: SIF errors: sifIrq = 0x8a!
        [  +0.033410] FWMSG: ERR: ./H4ISPCD/filters/IC/CImageCaptureH4.cpp, 777: FlowIC00: SIF errors: sifIrq = 0x8a!
        [  +0.033397] FWMSG: ERR: ./H4ISPCD/filters/IC/CImageCaptureH4.cpp, 777: FlowIC00: SIF errors: sifIrq = 0x8a!
        [  +0.034869] FWMSG: ERR: ./H4ISPCD/filters/IC/CImageCaptureH4.cpp, 777: FlowIC00: SIF errors: sifIrq = 0x8a!
        [  +0.031967] FWMSG: ERR: ./H4ISPCD/filters/IC/CImageCaptureH4.cpp, 777: FlowIC00: SIF errors: sifIrq = 0x8a!
        [  +0.033406] FWMSG: ERR: ./H4ISPCD/filters/IC/CImageCaptureH4.cpp, 777: FlowIC00: SIF errors: sifIrq = 0x8a!
        [  +0.033311] FWMSG: ERR: ./H4ISPCD/filters/IC/CImageCaptureH4.cpp, 777: FlowIC00: SIF errors: sifIrq = 0x8a!
        [  +0.033266] FWMSG: ERR: ./H4ISPCD/filters/IC/CImageCaptureH4.cpp, 777: FlowIC00: SIF errors: sifIrq = 0x8a!
        [  +0.033532] FWMSG: ERR: ./H4ISPCD/filters/IC/CImageCaptureH4.cpp, 777: FlowIC00: SIF errors: sifIrq = 0x8a!
        [  +0.033198] FWMSG: ERR: ./H4ISPCD/filters/IC/CImageCaptureH4.cpp, 777: FlowIC00: SIF errors: sifIrq = 0x8a!
        [  +0.034350] FWMSG: ERR: ./H4ISPCD/filters/IC/CImageCaptureH4.cpp, 777: FlowIC00: SIF errors: sifIrq = 0x8a!
        [  +0.032565] FWMSG: ERR: ./H4ISPCD/filters/IC/CImageCaptureH4.cpp, 777: FlowIC00: SIF errors: sifIrq = 0x8a!
        [  +0.033325] FWMSG: ERR: ./H4ISPCD/filters/IC/CImageCaptureH4.cpp, 777: FlowIC00: SIF errors: sifIrq = 0x8a!
        [  +0.033235] FWMSG: ERR: ./H4ISPCD/filters/IC/CImageCaptureH4.cpp, 777: FlowIC00: SIF errors: sifIrq = 0x8a!
        [  +0.033364] FWMSG: ERR: ./H4ISPCD/filters/IC/CImageCaptureH4.cpp, 777: FlowIC00: SIF errors: sifIrq = 0x8a!
        [  +0.033389] FWMSG: ERR: ./H4ISPCD/filters/IC/CImageCaptureH4.cpp, 777: FlowIC00: SIF errors: sifIrq = 0x8a!
        [  +0.033347] FWMSG: ERR: ./H4ISPCD/filters/IC/CImageCaptureH4.cpp, 777: FlowIC00: SIF errors: sifIrq = 0x8a!
        [  +0.033388] FWMSG: ERR: ./H4ISPCD/filters/IC/CImageCaptureH4.cpp, 777: FlowIC00: SIF errors: sifIrq = 0x8a!
        [  +0.033422] FWMSG: ERR: ./H4ISPCD/filters/IC/CImageCaptureH4.cpp, 777: FlowIC00: SIF errors: sifIrq = 0x8a!
        [  +0.033436] FWMSG: ERR: ./H4ISPCD/filters/IC/CImageCaptureH4.cpp, 777: FlowIC00: SIF errors: sifIrq = 0x8a!
        [  +0.033389] FWMSG: ERR: ./H4ISPCD/filters/IC/CImageCaptureH4.cpp, 777: FlowIC00: SIF errors: sifIrq = 0x8a!
        [  +0.034295] FWMSG: ERR: ./H4ISPCD/filters/IC/CImageCaptureH4.cpp, 777: FlowIC00: SIF errors: sifIrq = 0x8a!
        [  +0.032486] FWMSG: ERR: ./H4ISPCD/filters/IC/CImageCaptureH4.cpp, 777: FlowIC00: SIF errors: sifIrq = 0x8a!
        [  +0.033251] FWMSG: ERR: ./H4ISPCD/filters/IC/CImageCaptureH4.cpp, 777: FlowIC00: SIF errors: sifIrq = 0x8a!

This patch is used to ratelimit this.

patjak commented 8 years ago

Hmm, you shouldn't be seeing those errors. Which sha256 checksum does your firmware have?

ronin13 commented 8 years ago 
sha256sum firmware.bin
e3e6034a67dfdaa27672dd547698bbc5b33f47f1fc7f5572a2fb68ea09d32d3d  firmware.bin

Some other info:

 Sep 02 16:41:20 Yell kernel: facetimehd 0000:03:00.0: Loaded firmware, size: 1392kb
 Sep 02 16:41:20 Yell kernel: facetimehd 0000:03:00.0: ISP woke up after 0ms
 Sep 02 16:41:20 Yell kernel: facetimehd 0000:03:00.0: Number of IPC channels: 7, queue size: 44865
 Sep 02 16:41:20 Yell kernel: facetimehd 0000:03:00.0: Firmware requested heap size: 3072kb
 Sep 02 16:41:20 Yell kernel: facetimehd 0000:03:00.0: ISP second int after 0ms
 Sep 02 16:41:20 Yell kernel: facetimehd 0000:03:00.0: Channel description table at 00800000
 Sep 02 16:41:20 Yell kernel: facetimehd 0000:03:00.0: magic value: 00000000 after 0 ms
 Sep 02 16:41:20 Yell kernel: facetimehd 0000:03:00.0: Enabling interrupts
 Sep 02 16:41:20 Yell kernel: FWMSG:
 Sep 02 16:41:20 Yell kernel: FWMSG: - APOLLO-ISP-APPLE ------------------------------------------------------------
 Sep 02 16:41:20 Yell kernel: FWMSG:
 Sep 02 16:41:20 Yell kernel: FWMSG:   Restart count : 0
 Sep 02 16:41:20 Yell kernel: FWMSG:   Platform : mode = TARGET, ID = 0x00000000, HW = 00020018.00000000
 Sep 02 16:41:20 Yell kernel: FWMSG:   System Clock : 200000000 Hz
 Sep 02 16:41:20 Yell kernel: FWMSG:   Processor mode : SUPERVISOR
 Sep 02 16:41:20 Yell kernel: FWMSG:   Cache architecture type : SEPARATE
 Sep 02 16:41:20 Yell kernel: FWMSG:   Cache type : WRITEBACK
 Sep 02 16:41:20 Yell kernel: FWMSG:   Data Cache Line : 32 [0x20]
 Sep 02 16:41:20 Yell kernel: FWMSG:   Boot arguments entries : 2
 Sep 02 16:41:20 Yell kernel: FWMSG:     0000: 0x00000000 0x00000000
 Sep 02 16:41:20 Yell kernel: FWMSG:   Physical memory base : 0x00000000 [TLB base 0x00160000]
 Sep 02 16:41:20 Yell kernel: FWMSG:   Main memory :   base : 0x00000000
 Sep 02 16:41:20 Yell kernel: FWMSG:                   size : 8388608 [0x00800000] [8.0 MB]
 Sep 02 16:41:20 Yell kernel: FWMSG:   Extra heap :    base : 0x2080b000 [phy = 0x0080b000]
 Sep 02 16:41:20 Yell kernel: FWMSG:                   size : 3145728 [0x00300000] [3.0 MB]
 Sep 02 16:41:20 Yell kernel: FWMSG:   Shared window : base : 0x00800000 [static wiring]
 Sep 02 16:41:20 Yell kernel: FWMSG:                   size : 125829120 [0x07800000] [120.0 MB]
 Sep 02 16:41:20 Yell kernel: FWMSG:   Shared memory : base : 0x00800000
 Sep 02 16:41:20 Yell kernel: FWMSG:                   size : 260046848 [0x0f800000] [248.0 MB]
 Sep 02 16:41:20 Yell kernel: FWMSG:   TEXT : 1421992 [0x15b2a8] - text 667256, cstring  38749, const 715528
 Sep 02 16:41:20 Yell kernel: FWMSG:   DATA : 8076 [0x1f8c] - data 0, bss 460, common 1452, noinit 6144
 Sep 02 16:41:20 Yell kernel: FWMSG:   Heap free space : 10002626 [0x0098a0c2]
 Sep 02 16:41:20 Yell kernel: FWMSG:   Heap allocated space : 94656 [0x000171c0]
 Sep 02 16:41:20 Yell kernel: FWMSG:   Disclaimer : Copyright (c) APPLE Inc. All Rights Reserved.
 Sep 02 16:41:20 Yell kernel: FWMSG:   Application : adc [release]
 Sep 02 16:41:20 Yell kernel: FWMSG:   Linked on : Jul 25 2015 - 08:48:55
 Sep 02 16:41:20 Yell kernel: FWMSG:   Release : S2ISP-01.43.00
 Sep 02 16:41:20 Yell kernel: FWMSG:   H4ISPAPPLE : 11536
 Sep 02 16:41:20 Yell kernel: FWMSG:   H4ISPCD : 4081
 Sep 02 16:41:20 Yell kernel: FWMSG:   ffw : 4143
 Sep 02 16:41:20 Yell kernel: FWMSG:   Tool-chain : iPhone OS - 7.0.3 [clang/clang++]
 Sep 02 16:41:20 Yell kernel: FWMSG:
 Sep 02 16:41:20 Yell kernel: FWMSG: -------------------------------------------------------------------------------
 Sep 02 16:41:20 Yell kernel: FWMSG:
patjak commented 8 years ago

Thanks, you do have a known working firmware. What system is this? MacBook Air 6.x? Do you know when these errors occur?

ronin13 commented 8 years ago

System is:

DMI: Apple Inc. MacBookPro11,2/Mac-3CBD00234E554E41, BIOS MBP112.88Z.0138.B16.1509081314 09/08/2015

Regarding when, I need to verify this again, but I believe it is after resuming from suspend.

patjak commented 8 years ago

Sounds plausible that it is suspend related since the power off sequence isn't fully debugged yet. I'll try to fix it but if I can't we can ratelimit the error messages instead (or turn them off during suspend).

ronin13 commented 8 years ago

Sounds plausible that it is suspend related since the power off sequence isn't fully debugged yet. I'll try > to fix it but if I can't we can ratelimit the error messages instead (or turn them off during suspend).

Actually I found that ratelimiting doesn't help either. The firmware messages 'FWMSG' are too verbose and probably are being logged at INFO levels. Is there a way to set the verbosity of firmware messages.