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

apple-dcp 231c00000.dcp: RTKit: syslog message adds newlines to the kernel logs #295

Open
jvoisin opened this issue May 23, 2024 · 0 comments

Comments

@jvoisin
Copy link

jvoisin commented May 23, 2024

This is a really minor-ish issue: when running dmesg -T -w, the syslog messages from apple-dcp' RTKIT are (sometimes) adding newlines, on an Apple M2 running 6.8.9-404.asahi.fc40.aarch64+16k #1 SMP PREEMPT_DYNAMIC Fri May 17 17:22:13 UTC 2024 aarch64 GNU/Linux, eg:

[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: dcp_poweron() starting
[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: nifiedPipeline.cpp:1356: set_device_enabled_gated: current state: 0, requested state: 1

[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: PPipeDCP_H13P.cpp:10468: set_run_mode_safe: no need to defer: 0 -> 1

[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: ock_Tunables_v1.cpp:651: IOMFB: Writing tunables with target 3

[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: PPipeDCP_H13P.cpp:10468: set_run_mode_safe: no need to defer: 1 -> 2

[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: eoInterfaceIOAV.cpp:237: bool VideoInterfaceIOAV::open_ioav_gated(): IOAVVideoInterface open failed

[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: eoInterfaceIOAV.cpp:296: IOMFB: VideoInterfaceIOAV::power_on: m_power_ctrl->setPower( 1 )

[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: AppleDCPDPTX.cpp:355: [AFK]powering nub 0x86ffc0
[Fri May 24 01:23:30 2024] 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
[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: set_digital_out_mode() color mode depth:8 format:0 colorimetry:16 eotf:0 range:0
[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: nifiedPipeline.cpp:7462: set_digital_out_mode: Modeset requested for colorID: 1, timingID: 2

[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: PPipeDCP_H13P.cpp:18011: Dual pipe disabled offset 0

[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: nifiedPipeline.cpp:7465: set_digital_out_mode returned 8000000b

[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: set_digital_out_mode finished:8500
[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: ileCDIDPDisplay.cpp:119: [AFK]SAC enable: DP=1 CDI=1
[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: DCPDP13Service.cpp:60: [AFK]version: 13
[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: DCPDPService.cpp:76: [AFK]version: 13
[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: eoInterfaceIOAV.cpp:135: IOMFB: IOAVVideoInterface published

[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: eoInterfaceIOAV.cpp:714: IOMFBStatus VideoInterfaceIOAV::plug_gated(IOAVVideoInterface *, bool): display HPD asserted

[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: PPipeDCP_H13P.cpp:10490: set_run_mode_safe: deferring: 2 -> 4

[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: PPipeDCP_H13P.cpp:10395: virtual IOMFBStatus IOMFB::UPPipeDCP_H13P::ready_for_run_mode_change(IOMFB::AppleRegisterStream *): initiating deferred run mod
[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: M3Hal_v1.cpp:197: IOMFB: load APT M3 IMem : size 0x7918

[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: M3Hal_v1.cpp:197: IOMFB: load APT M3 DMem : size 0x6f60

[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: CAHandler.cpp:188: IOMFB load_ca_data: Unrecognized data version 0 (expected 1 or 2)
[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: UPPipe.cpp:3767: IOMFB read_pmu_data_sync: pmu ram read error (e00800d8)

[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: PPipeDCP_H13P.cpp:14085: IOMFB Int RTBandwidth: program_M3_rt_config: Using Dashboard 23b3d05d8
[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: UPTSQManager.cpp:133: IOMFB: clearing M3 reset

[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: UPTSQ_Hal_v1.cpp:349: IOMFB: timebase_offset = 4

[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: UPTSQManager.cpp:105: IOMFB: switch to normal mode succeeded

[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: ock_PCC2DLTM_v1.cpp:910: IOMFBStatus IOMFB::UPBlock_PCC2DLTM_v1::set_mcpu_power(IOMFB::AppleRegisterStream *, bool) Loading M3 Hal
[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: M3Hal_v1.cpp:197: IOMFB: load LTM M3 IMem : size 0x8e70

[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: M3Hal_v1.cpp:197: IOMFB: load LTM M3 DMem : size 0xedd8

[Fri May 24 01:23:30 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: PPipeDCP_H13P.cpp:17179: handle_stage1_enable blm_en 0 ltm_en 1 
                            
[Fri May 24 01:23:30 2024] usb 1-1: usbfs: process 2561 (pcscd) did not claim interface 2 before use
[Fri May 24 01:23:31 2024] ieee80211 phy0: brcmf_p2p_set_firmware: failed to update device address ret -52

or

[Fri May 24 00:29:28 2024] macsmc-rtkit 23e400000.smc: RTKit: syslog message: aceElec.cpp:703: 	Elec: Elec Cause 0x0
[Fri May 24 00:29:28 2024] macsmc-power macsmc-power: Charging: 1
[Fri May 24 00:29:28 2024] macsmc-power macsmc-power: Port 1 state change (charge port: 255)
[Fri May 24 00:29:28 2024] macsmc-rtkit 23e400000.smc: RTKit: syslog message: aceElec.cpp:703: 	Elec: Elec Cause 0x200000
[Fri May 24 00:29:28 2024] macsmc-power macsmc-power: Charging: 0
[Fri May 24 00:29:28 2024] macsmc-power macsmc-power: Port 2 state change (charge port: 2)
[Fri May 24 00:29:28 2024] macsmc-power macsmc-power: Port 1 state change (charge port: 2)
[Fri May 24 00:29:28 2024] macsmc-power macsmc-power: Charging: 1
[Fri May 24 00:29:28 2024] macsmc-power macsmc-power: Port 1 state change (charge port: 2)
[Fri May 24 00:29:28 2024] macsmc-rtkit 23e400000.smc: RTKit: syslog message: aceElec.cpp:703: 	Elec: Elec Cause 0x8000
[Fri May 24 00:29:29 2024] macsmc-rtkit 23e400000.smc: RTKit: syslog message: aceElec.cpp:703: 	Elec: Elec Cause 0x20
[Fri May 24 00:29:29 2024] macsmc-rtkit 23e400000.smc: RTKit: syslog message: charger.cpp:2418: Not charging:0
[Fri May 24 00:29:35 2024] macsmc-rtkit 23e400000.smc: RTKit: syslog message: aceElec.cpp:703: 	Elec: Elec Cause 0x1000
[Fri May 24 00:38:24 2024] macsmc-rtkit 23e400000.smc: RTKit: syslog message: apComms.cpp:375: SMC HID Event: 03 01 00
[Fri May 24 00:38:24 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: PPipeDCP_H13P.cpp:10490: set_run_mode_safe: deferring: 4 -> 1

[Fri May 24 00:38:24 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: PPipeDCP_H13P.cpp:10395: virtual IOMFBStatus IOMFB::UPPipeDCP_H13P::ready_for_run_mode_change(IOMFB::AppleRegisterStream *): initiating deferred run mod
[Fri May 24 00:38:24 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: UPTSQManager.cpp:150: IOMFBStatus IOMFB::UPTSQManager::power_down_M3(IOMFB::AppleRegisterStream *, UPTSQManager::ModeChangeWaiter *): request mode ch
[Fri May 24 00:38:24 2024] brcmfmac: brcmf_msgbuf_delete_flowring: timed out waiting for txstatus
[Fri May 24 00:38:24 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: UPTSQManager.cpp:162: IOMFBStatus IOMFB::UPTSQManager::power_down_M3(IOMFB::AppleRegisterStream *, UPTSQManager::ModeChangeWaiter *): disabling M3
[Fri May 24 00:38:24 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: PPipeDCP_H13P.cpp:10468: set_run_mode_safe: no need to defer: 1 -> 0

[Fri May 24 00:38:24 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: eoInterfaceIOAV.cpp:433: IOMFB: VideoInterfaceIOAV::did_power_off: m_power_ctrl->setPower( 0 )
[Fri May 24 00:38:24 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: eoInterfaceIOAV.cpp:146: IOMFB: IOAVVideoInterface terminated

[Fri May 24 00:38:24 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: oInterfaceIOAV.cpp:1094: void VideoInterfaceIOAV::unplug_gated(IOAVVideoInterface *): display HPD removed

[Fri May 24 00:38:24 2024] apple-dcp 231c00000.dcp: RTKit: syslog message: nifiedPipeline.cpp:1356: set_device_enabled_gated: current state: 1, requested state: 0

[Fri May 24 00:38:24 2024] apple-dcp 231c00000.dcp: dcp_poweroff() done
[Fri May 24 00:38:24 2024] brcmfmac: brcmf_msgbuf_delete_flowring: timed out waiting for txstatus
[Fri May 24 00:38:25 2024] PM: suspend entry (s2idle)
[Fri May 24 00:38:25 2024] Filesystems sync: 0.008 seconds
[Fri May 24 00:38:25 2024] Freezing user space processes
[Fri May 24 00:38:25 2024] Freezing user space processes completed (elapsed 0.003 seconds)
[Fri May 24 00:38:25 2024] OOM killer disabled.
[Fri May 24 00:38:25 2024] Freezing remaining freezable tasks
[Fri May 24 00:38:25 2024] Freezing remaining freezable tasks completed (elapsed 0.001 seconds)
[Fri May 24 00:38:25 2024] printk: Suspending console(s) (use no_console_suspend to debug)
jannau pushed a commit that referenced this issue Oct 6, 2024
[ Upstream commit 18ec12c ]

Inject fault while probing of-fpga-region, if kasprintf() fails in
module_add_driver(), the second sysfs_remove_link() in exit path will cause
null-ptr-deref as below because kernfs_name_hash() will call strlen() with
NULL driver_name.

Fix it by releasing resources based on the exit path sequence.

	 KASAN: null-ptr-deref in range [0x0000000000000000-0x0000000000000007]
	 Mem abort info:
	   ESR = 0x0000000096000005
	   EC = 0x25: DABT (current EL), IL = 32 bits
	   SET = 0, FnV = 0
	   EA = 0, S1PTW = 0
	   FSC = 0x05: level 1 translation fault
	 Data abort info:
	   ISV = 0, ISS = 0x00000005, ISS2 = 0x00000000
	   CM = 0, WnR = 0, TnD = 0, TagAccess = 0
	   GCS = 0, Overlay = 0, DirtyBit = 0, Xs = 0
	 [dfffffc000000000] address between user and kernel address ranges
	 Internal error: Oops: 0000000096000005 [#1] PREEMPT SMP
	 Dumping ftrace buffer:
	    (ftrace buffer empty)
	 Modules linked in: of_fpga_region(+) fpga_region fpga_bridge cfg80211 rfkill 8021q garp mrp stp llc ipv6 [last unloaded: of_fpga_region]
	 CPU: 2 UID: 0 PID: 2036 Comm: modprobe Not tainted 6.11.0-rc2-g6a0e38264012 #295
	 Hardware name: linux,dummy-virt (DT)
	 pstate: 60000005 (nZCv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
	 pc : strlen+0x24/0xb0
	 lr : kernfs_name_hash+0x1c/0xc4
	 sp : ffffffc081f97380
	 x29: ffffffc081f97380 x28: ffffffc081f97b90 x27: ffffff80c821c2a0
	 x26: ffffffedac0be418 x25: 0000000000000000 x24: ffffff80c09d2000
	 x23: 0000000000000000 x22: 0000000000000000 x21: 0000000000000000
	 x20: 0000000000000000 x19: 0000000000000000 x18: 0000000000001840
	 x17: 0000000000000000 x16: 0000000000000000 x15: 1ffffff8103f2e42
	 x14: 00000000f1f1f1f1 x13: 0000000000000004 x12: ffffffb01812d61d
	 x11: 1ffffff01812d61c x10: ffffffb01812d61c x9 : dfffffc000000000
	 x8 : 0000004fe7ed29e4 x7 : ffffff80c096b0e7 x6 : 0000000000000001
	 x5 : ffffff80c096b0e0 x4 : 1ffffffdb990efa2 x3 : 0000000000000000
	 x2 : 0000000000000000 x1 : dfffffc000000000 x0 : 0000000000000000
	 Call trace:
	  strlen+0x24/0xb0
	  kernfs_name_hash+0x1c/0xc4
	  kernfs_find_ns+0x118/0x2e8
	  kernfs_remove_by_name_ns+0x80/0x100
	  sysfs_remove_link+0x74/0xa8
	  module_add_driver+0x278/0x394
	  bus_add_driver+0x1f0/0x43c
	  driver_register+0xf4/0x3c0
	  __platform_driver_register+0x60/0x88
	  of_fpga_region_init+0x20/0x1000 [of_fpga_region]
	  do_one_initcall+0x110/0x788
	  do_init_module+0x1dc/0x5c8
	  load_module+0x3c38/0x4cac
	  init_module_from_file+0xd4/0x128
	  idempotent_init_module+0x2cc/0x528
	  __arm64_sys_finit_module+0xac/0x100
	  invoke_syscall+0x6c/0x258
	  el0_svc_common.constprop.0+0x160/0x22c
	  do_el0_svc+0x44/0x5c
	  el0_svc+0x48/0xb8
	  el0t_64_sync_handler+0x13c/0x158
	  el0t_64_sync+0x190/0x194
	 Code: f2fbffe1 a90157f4 12000802 aa0003f5 (38e16861)
	 ---[ end trace 0000000000000000 ]---
	 Kernel panic - not syncing: Oops: Fatal exception

Fixes: 85d2b0a ("module: don't ignore sysfs_create_link() failures")
Signed-off-by: Jinjie Ruan <[email protected]>
Link: https://lore.kernel.org/r/[email protected]
Signed-off-by: Greg Kroah-Hartman <[email protected]>
Signed-off-by: Sasha Levin <[email protected]>
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

1 participant