Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

the sequoia t8103/t8112 display brightness workaround results in black screen on some devices #406

Closed
jannau opened this issue Sep 24, 2024 · 5 comments

Comments

@jannau
Copy link
Member

jannau commented Sep 24, 2024

There are two reports m1n1 with cdb6d41 not working as expected. Display configuration in m1n1 results in a black screen.

  1. 1st report luna in #asahi:fedoraproject.org (2024-09-20 21:25+0) Macbook Air M2, OS firmware 13.5. Black screen after Apple and Asahi logo. "fixed" by downgrading to m1n1-1.4.14 / boot.bin.old.
  2. @tobhe #asahi-dev@oftc .net (2024-09-23 12:05+0) Macbook Air M2
  3. reddit post Macbook Air M2
@tobhe
Copy link
Contributor

tobhe commented Sep 24, 2024

Some more details on my installation:

  • iBoot 11881.1.1
  • macOS 12.4 stub
  • m1n1 stage1 v1.4.14

The bug does not seem to be entirely deterministically. When I first rebooted after installing the new version it worked fine. On the next day when I booted (with almost entirely empty battery) the screen stayed dark. Trying again now after a few days the backlight stays off during boot but comes back once Linux is up.

I now have m1n1 built with #399 and try to collect logs next time it happens.

EDIT: here is a first log from a run where the backlight stayed off during boot but came back later
m1n1.log

@jannau
Copy link
Member Author

jannau commented Sep 24, 2024

I think there's a set brightness for the dcp iboot protocol. Trying to set brightness during display configure might worth a try. Annoying (for debugging) that this doesn't reproduce.

@tobhe
Copy link
Contributor

tobhe commented Sep 24, 2024

Some dmesg output from previous boots below.

Broken:

2024-09-23T12:09:10.814654+02:00 m2 kernel: apple-dcp 231c00000.dcp: Adding to iommu group 5
2024-09-23T12:09:10.814673+02:00 m2 kernel: apple-dcp 231c00000.dcp: Detected display with notch of 64 pixel
2024-09-23T12:09:10.814676+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: Initializing (protocol version 12)
2024-09-23T12:09:10.814676+02:00 m2 kernel: apple-dcp 231c00000.dcp: shmem_setup: iova: 880220000 -> pa: be178c000 -> iomem: ffff800082070000
2024-09-23T12:09:10.814676+02:00 m2 kernel: apple-dcp 231c00000.dcp: shmem_setup: iova: ffffec000, buffer: ffff800082064000
2024-09-23T12:09:10.814676+02:00 m2 kernel: apple-dcp 231c00000.dcp: shmem_setup: iova: ffffe8000, buffer: ffff800082094000
2024-09-23T12:09:10.814678+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: ap_link.c:289: shared memory dva: 0xfffe00000 0xffffffff00433000
2024-09-23T12:09:10.814678+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: ap_link.c:266: ap_link: IOMFB: DCP heap size: 0x1030000 [iBoot:0x1030000] [LinkService:0x0]
2024-09-23T12:09:10.814679+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: nifiedPipeline.cpp:3685: IOMFB: Could not find Backlight service
2024-09-23T12:09:10.814679+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: nifiedPipeline.cpp:1643: virtual bool UnifiedPipeline::start_ios_gated(): Created AP Services
2024-09-23T12:09:10.814679+02:00 m2 kernel: apple-dcp 231c00000.dcp: AFK[ep:20]: new service system on channel 2
2024-09-23T12:09:10.814679+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: nifiedPipeline.cpp:1653: virtual bool UnifiedPipeline::start_ios_gated(): Flushed RTPs
2024-09-23T12:09:10.814680+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: UPPipeDCP_H13P.cpp:8102: IOMFB updateFrequencies: no timing set
2024-09-23T12:09:10.814680+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: UPPipeDCP_H13P.cpp:1142: IOMFB: videoClock is zero, defaulting to 138521000
2024-09-23T12:09:10.814681+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: UPPipeDCP_H13P.cpp:8102: IOMFB updateFrequencies: no timing set
2024-09-23T12:09:10.814683+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: UPPipeDCP_H13P.cpp:7498: set_run_mode_safe: deferring: 2 -> 4
2024-09-23T12:09:10.814684+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: UPPipeDCP_H13P.cpp:7403: virtual IOMFBStatus IOMFB::UPPipeDCP_H13P::ready_for_run_mode_change(IOMFB::AppleRegisterStr
eam *): initiating deferred run mod
2024-09-23T12:09:10.814684+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: M3Hal_v1.cpp:196: IOMFB: load APT M3 IMem : size 0x71d4
2024-09-23T12:09:10.814684+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: M3Hal_v1.cpp:196: IOMFB: load APT M3 DMem : size 0x6e04
2024-09-23T12:09:10.814684+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: CAHandler.cpp:163: IOMFB load_ca_data: Unrecognized data version 0 (expected 1 or 2)
2024-09-23T12:09:10.814685+02:00 m2 kernel: apple-dcp 231c00000.dcp: AFK[ep:20]: new service powerlog-service on channel 3
2024-09-23T12:09:10.814685+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: UPPipe.cpp:3456: IOMFB read_pmu_data_sync: pmu ram read error (e00800d8)
2024-09-23T12:09:10.814686+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: PPipeDCP_H13P.cpp:10100: IOMFB Int RTBandwidth: program_M3_rt_config: Using Dashboard 23b3d05d8
2024-09-23T12:09:10.814687+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: UPTSQManager.cpp:133: IOMFB: clearing M3 reset
2024-09-23T12:09:10.814687+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: UPTSQ_Hal_v1.cpp:250: IOMFB: timebase_offset = 4
2024-09-23T12:09:10.814744+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: UPTSQManager.cpp:101: IOMFBStatus IOMFB::UPTSQManager::request_normal_mode(IOMFB::AppleRegisterStream *, IOMFB::UPTSQ
Manager::ModeChangeWaiter *): sw
2024-09-23T12:09:10.814744+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: UPPipeDCP_H13P.cpp:7411: virtual IOMFBStatus IOMFB::UPPipeDCP_H13P::ready_for_run_mode_change(IOMFB::AppleRegisterStr
eam *): set_run_mode failed with 0x
2024-09-23T12:09:13.415919+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: UPPipeDCP_H13P.cpp:7526: set_run_mode_safe: run mode change timed out
2024-09-23T12:09:13.417929+02:00 m2 kernel: apple-dcp 231c00000.dcp: DCP booted
2024-09-23T12:09:13.417941+02:00 m2 kernel: apple-dcp 231c00000.dcp: DCP is_main_display: 1
2024-09-23T12:09:13.417944+02:00 m2 kernel: apple-dcp 231c00000.dcp: dcp_hotplug() connected:1 valid_mode:0 nr_modes:1
2024-09-23T12:09:13.587908+02:00 m2 kernel: apple-dcp 231c00000.dcp: dcp_poweron() starting
2024-09-23T12:09:13.587915+02:00 m2 kernel: apple-dcp 231c00000.dcp: set_digital_out_mode(color:1 timing:2) "2560x1600": 60 277042 2560 2568 2600 2640 1600 1633 1705 1749 0x48 0x0
2024-09-23T12:09:13.587918+02:00 m2 kernel: apple-dcp 231c00000.dcp: set_digital_out_mode() color mode depth:8 format:0 colorimetry:16 eotf:0 range:0
2024-09-23T12:09:13.587918+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: nifiedPipeline.cpp:6553: set_digital_out_mode returned 8000000b
2024-09-23T12:09:13.587919+02:00 m2 kernel: apple-dcp 231c00000.dcp: set_digital_out_mode finished:8500

Working:

2024-09-25T01:02:43.915839+02:00 m2 kernel: apple-dcp 231c00000.dcp: Adding to iommu group 5
2024-09-25T01:02:43.915874+02:00 m2 kernel: apple-dcp 231c00000.dcp: Detected display with notch of 64 pixel
2024-09-25T01:02:43.915881+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: Initializing (protocol version 12)
2024-09-25T01:02:43.915882+02:00 m2 kernel: apple-dcp 231c00000.dcp: shmem_setup: iova: 880220000 -> pa: be178c000 -> iomem: ffff800082070000
2024-09-25T01:02:43.915882+02:00 m2 kernel: apple-dcp 231c00000.dcp: shmem_setup: iova: ffffec000, buffer: ffff800082064000
2024-09-25T01:02:43.915883+02:00 m2 kernel: apple-dcp 231c00000.dcp: shmem_setup: iova: ffffe8000, buffer: ffff800082084000
2024-09-25T01:02:43.915884+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: ap_link.c:289: shared memory dva: 0xfffe00000 0xffffffff00433000
2024-09-25T01:02:43.915884+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: ap_link.c:266: ap_link: IOMFB: DCP heap size: 0x1030000 [iBoot:0x1030000] [LinkService:0x0]
2024-09-25T01:02:43.915885+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: nifiedPipeline.cpp:3685: IOMFB: Could not find Backlight service
2024-09-25T01:02:43.915886+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: nifiedPipeline.cpp:1643: virtual bool UnifiedPipeline::start_ios_gated(): Created AP Services
2024-09-25T01:02:43.915886+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: nifiedPipeline.cpp:1647: virtual bool UnifiedPipeline::start_ios_gated(): trigger pending HPD notification
2024-09-25T01:02:43.915887+02:00 m2 kernel: apple-dcp 231c00000.dcp: cb_hotplug() connected:1, valid_mode:0
2024-09-25T01:02:43.915887+02:00 m2 kernel: apple-dcp 231c00000.dcp: dcp_hotplug() connected:1 valid_mode:0 nr_modes:0
2024-09-25T01:02:43.915888+02:00 m2 kernel: apple-dcp 231c00000.dcp: AFK[ep:20]: new service system on channel 2
2024-09-25T01:02:43.915888+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: nifiedPipeline.cpp:1653: virtual bool UnifiedPipeline::start_ios_gated(): Flushed RTPs
2024-09-25T01:02:43.915889+02:00 m2 kernel: apple-dcp 231c00000.dcp: AFK[ep:20]: new service powerlog-service on channel 3
2024-09-25T01:02:43.915891+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: UPPipeDCP_H13P.cpp:8146: IOMFB updateFrequencies: minimum-frequency property not found, using getClockFrequency(0) in
stead.
2024-09-25T01:02:43.915891+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: UPPipeDCP_H13P.cpp:8146: IOMFB updateFrequencies: minimum-frequency property not found, using getClockFrequency(0) in
stead.
2024-09-25T01:02:43.915892+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: UPPipeDCP_H13P.cpp:7498: set_run_mode_safe: deferring: 2 -> 4
2024-09-25T01:02:43.915893+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: UPPipeDCP_H13P.cpp:7403: virtual IOMFBStatus IOMFB::UPPipeDCP_H13P::ready_for_run_mode_change(IOMFB::AppleRegisterStr
eam *): initiating deferred run mod
2024-09-25T01:02:43.915893+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: M3Hal_v1.cpp:196: IOMFB: load APT M3 IMem : size 0x71d4
2024-09-25T01:02:43.915896+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: M3Hal_v1.cpp:196: IOMFB: load APT M3 DMem : size 0x6e04
2024-09-25T01:02:43.915897+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: CAHandler.cpp:163: IOMFB load_ca_data: Unrecognized data version 0 (expected 1 or 2)
2024-09-25T01:02:43.915898+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: UPPipe.cpp:3456: IOMFB read_pmu_data_sync: pmu ram read error (e00800d8)
2024-09-25T01:02:43.915898+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: PPipeDCP_H13P.cpp:10100: IOMFB Int RTBandwidth: program_M3_rt_config: Using Dashboard 23b3d05d8
2024-09-25T01:02:43.915899+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: UPTSQManager.cpp:133: IOMFB: clearing M3 reset
2024-09-25T01:02:43.915900+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: UPTSQ_Hal_v1.cpp:250: IOMFB: timebase_offset = 4
2024-09-25T01:02:43.915901+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: UPTSQManager.cpp:105: IOMFB: switch to normal mode succeeded
2024-09-25T01:02:43.915901+02:00 m2 kernel: apple-dcp 231c00000.dcp: DCP booted
2024-09-25T01:02:43.915902+02:00 m2 kernel: apple-dcp 231c00000.dcp: DCP is_main_display: 1
2024-09-25T01:02:43.915902+02:00 m2 kernel: apple-dcp 231c00000.dcp: dcp_hotplug() connected:1 valid_mode:0 nr_modes:1
2024-09-25T01:02:45.738007+02:00 m2 kernel: apple-dcp 231c00000.dcp: dcp_poweron() starting
2024-09-25T01:02:45.738012+02:00 m2 kernel: apple-dcp 231c00000.dcp: set_digital_out_mode(color:1 timing:2) "2560x1600": 60 277042 2560 2568 2600 2640 1600 1633 1705 1749 0x48 0x0
2024-09-25T01:02:45.738013+02:00 m2 kernel: apple-dcp 231c00000.dcp: set_digital_out_mode() color mode depth:8 format:0 colorimetry:16 eotf:0 range:0
2024-09-25T01:02:45.738970+02:00 m2 kernel: apple-dcp 231c00000.dcp: RTKit: syslog message: nifiedPipeline.cpp:6553: set_digital_out_mode returned 8000000b
2024-09-25T01:02:45.738973+02:00 m2 kernel: apple-dcp 231c00000.dcp: set_digital_out_mode finished:8500

One obvious difference is switch to normal mode succeeded vs run mode change timed out

@marcan
Copy link
Member

marcan commented Sep 28, 2024

Both reports are on j413 and I just confirmed that that model does not need the workaround, so let's change the logic. How about !has_notch && firmware_sfw_in_range(V15_0B1, FW_MAX) && os_firmware.version < V15_0B1? That should cover j313, j293, j493, and the M1 iMacs.

I'll also add a delay to the poweroff/on sequence since it happening too quickly is the most obvious explanation for why this breaks (DCP is full of stupid races...).

@marcan marcan closed this as completed in 8fa2bf0 Sep 28, 2024
marcan added a commit that referenced this issue Sep 28, 2024
It seems this model does not need it *and* it somehow causes
nondeterministic problems.

Also add a delay to the poweroff/on sequence to be more conservative.

Fixes: #406
Signed-off-by: Hector Martin <[email protected]>
@tobhe
Copy link
Contributor

tobhe commented Sep 29, 2024

Thanks for the fix @marcan! That seems reasonable.

Just for future reference let me dump some more logs here, maybe it helps if similar issues do appear again on other hardware.
m1n1.log
dmesg.log

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants