From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org X-Spam-Level: X-Spam-Status: No, score=-0.6 required=3.0 tests=DKIM_INVALID,DKIM_SIGNED, HEADER_FROM_DIFFERENT_DOMAINS,MAILING_LIST_MULTI,SPF_HELO_NONE,SPF_PASS autolearn=no autolearn_force=no version=3.4.0 Received: from mail.kernel.org (mail.kernel.org [198.145.29.99]) by smtp.lore.kernel.org (Postfix) with ESMTP id F22EBC47255 for ; Sat, 9 May 2020 12:11:55 +0000 (UTC) Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by mail.kernel.org (Postfix) with ESMTP id C862D21473 for ; Sat, 9 May 2020 12:11:55 +0000 (UTC) Authentication-Results: mail.kernel.org; dkim=fail reason="signature verification failed" (2048-bit key) header.d=goldelico.com header.i=@goldelico.com header.b="Kr4+NAVB" Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1728488AbgEIMLz (ORCPT ); Sat, 9 May 2020 08:11:55 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:52814 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-FAIL-OK-FAIL) by vger.kernel.org with ESMTP id S1726782AbgEIMLy (ORCPT ); Sat, 9 May 2020 08:11:54 -0400 Received: from mo6-p02-ob.smtp.rzone.de (mo6-p02-ob.smtp.rzone.de [IPv6:2a01:238:20a:202:5302::6]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id B1C0AC061A0C; Sat, 9 May 2020 05:11:53 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; t=1589026311; s=strato-dkim-0002; d=goldelico.com; h=To:Message-Id:Cc:Date:From:Subject:X-RZG-CLASS-ID:X-RZG-AUTH:From: Subject:Sender; bh=5gGUHy+PDoNdP9nHLRYt4+OcwQoLGo/lTP0Ip+T5Vwk=; b=Kr4+NAVBtAFz/pNxlNgrdDG0x/qNwrpDaJ1/dGMM5/rn7uL3r9T2z3KmvknyUhKj3p anAUpuEe4FgAnfiuUML1zN+6ln6lxf0RH1FncFFRmws9IsQDXPkd0yp75WgCPwo10e/j WSRIBVlFCt63FEu0b7DIAdOgOiUQ1Ex+7jhkYJtHlRXtj+qgAxfVAYvEt1taTGHNTD5E 4C0mfo0Btfsk1KRpiFJZzM9fx7/SyEuXzJfql+JXskPXBb6f2AawGWMJk/PTI3It+zwm ImWH8x7y0k/7MpyLNldPiOir3lZrO3QohMqzdlsHgTr3pUR1f/hmpxrLoE0ztqAvowCk +iIw== X-RZG-AUTH: ":JGIXVUS7cutRB/49FwqZ7WcJeFKiMgPgp8VKxflSZ1P34KBp5hRw/qOxWRk4dCygUY/lNGxpoFHLuGRFsv7A7BXaBhsYgwirVBs0" X-RZG-CLASS-ID: mo00 Received: from [IPv6:2001:16b8:2653:2400:c8f5:8c00:203b:568b] by smtp.strato.de (RZmta 46.6.2 AUTH) with ESMTPSA id R0acebw49CBi7oT (using TLSv1 with cipher ECDHE-RSA-AES256-SHA (curve X9_62_prime256v1 with 256 ECDH bits, eq. 3072 bits RSA)) (Client did not present a certificate); Sat, 9 May 2020 14:11:44 +0200 (CEST) Content-Type: text/plain; charset=us-ascii Mime-Version: 1.0 (Mac OS X Mail 9.3 \(3124\)) Subject: Bug with omap3-isp - 30 seconds delay for probe success From: "H. Nikolaus Schaller" Date: Sat, 9 May 2020 14:11:37 +0200 Cc: Discussions about the Letux Kernel , linux-omap , Linux Kernel Mailing List Content-Transfer-Encoding: quoted-printable Message-Id: To: Tony Lindgren X-Mailer: Apple Mail (2.3124) Sender: linux-kernel-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org resend from correct mail address --- Hi Tony, I am observing an issue with omap3-isp for a while. It seems to have started with v5.6 but I have preferred to invest some time into analysis of the problem instead of trying a bisect. The problem is that there is a [ 32.483703] WARNING: CPU: 0 PID: 2052 at drivers/base/dd.c:270 = driver_deferred_probe_check_state+0x44/0x5c [ 32.498809] omap3isp 480bc000.isp: deferred probe timeout, ignoring = dependency from the driver, just after exactly 30 seconds. This is when driver_deferred_probe_timeout had timed out (chaning = driver_deferred_probe_timeout makes it take more or less time). So something is requested for by the omap3-isp driver which never = becomes available. Some analysis shows that the omap3-isp is the only device calling = of_iommu_xlate() with a NULL opp table which ends up in = driver_deferred_probe_check_state() to return -EPROBE_DEFER until 30 seconds have passed. Well, it seems to be resonable that there are no ops returned by = iommu_ops_from_fwnode() since there is no firmware for the ISP. But there should be no timeout. This of_iommu_xlate() is called from of_iommu_configure() in the loop to = handle all "iommus" references. There is one for omap34xx and omap36xx.dtsi and = the mmu_isp is defined in omap3.dtsi. They refer to compatible =3D "ti,omap2-iommu"; = and ti,hwmods =3D "mmu_isp"; Are there any ideas what in the iommu or hwmods or firmware loading for = the mmu_isp may have changed recently? Anyways the omap3-isp seems to be initialized after this 30 seconds = timeout and responds to media-ctl. A more complete log attached. BR, Nikolaus [ 32.478759] ------------[ cut here ]------------ [ 32.483703] WARNING: CPU: 0 PID: 2052 at drivers/base/dd.c:270 = driver_deferred_probe_check_state+0x44/0x5c [ 32.498809] omap3isp 480bc000.isp: deferred probe timeout, ignoring = dependency [ 32.498840] Modules linked in: omapdrm libertas_sdio libertas = cfg80211 panel_tpo_td028ttec1 snd_soc_simple_card = snd_soc_simple_card_utils snd_soc_omap_twl4030 simple_bridge wwan_on_off = pvrsrvkm_omap3630_sgx530_125 snd_soc_gtm601 pwm_omap_dmtimer = omap_aes_driver crypto_engine omap_crypto omap_sham omap3_isp = videobuf2_dma_contig videobuf2_memops videobuf2_v4l2 videobuf2_common = bq27xxx_battery_hdq bq27xxx_battery omap_hdq omap2430 bmp280_spi = bmp280_i2c itg3200 bmp280 at24 tsc2007 leds_tca6507 bma180 = phy_twl4030_usb musb_hdrc twl4030_pwrbutton hci_uart snd_soc_twl4030 = twl4030_vibra btbcm ov9655 twl4030_madc v4l2_fwnode twl4030_charger = videodev hmc5843_i2c bluetooth hmc5843_core gnss_sirf = industrialio_triggered_buffer mc kfifo_buf ecdh_generic snd_soc_si47xx = ecc gnss snd_soc_omap_mcbsp snd_soc_ti_sdma ehci_omap omapdss = omapdss_base drm_kms_helper syscopyarea sysfillrect sysimgblt = fb_sys_fops cec display_connector generic_adc_battery drm industrialio = drm_panel_orientation_quirks input_polldev [ 32.509704] pwm_bl ip_tables x_tables ipv6 nf_defrag_ipv6 autofs4 [ 32.612792] CPU: 0 PID: 2052 Comm: kworker/0:5 Not tainted = 5.7.0-rc4-letux+ #2570 [ 32.620758] Hardware name: Generic OMAP36xx (Flattened Device Tree) [ 32.627471] Workqueue: events deferred_probe_work_func [ 32.632995] [] (unwind_backtrace) from [] = (show_stack+0x10/0x14) [ 32.641235] [] (show_stack) from [] = (dump_stack+0x88/0xa8) [ 32.648925] [] (dump_stack) from [] = (__warn+0xc8/0xf4) [ 32.656249] [] (__warn) from [] = (warn_slowpath_fmt+0x70/0x9c) [ 32.664215] [] (warn_slowpath_fmt) from [] = (driver_deferred_probe_check_state+0x44/0x5c) [ 32.674652] [] (driver_deferred_probe_check_state) from = [] (of_iommu_configure+0x98/0x1b4) [ 32.685302] [] (of_iommu_configure) from [] = (of_dma_configure+0x1d8/0x234) [ 32.694458] [] (of_dma_configure) from [] = (really_probe+0x104/0x324) [ 32.703063] [] (really_probe) from [] = (driver_probe_device+0x10c/0x154) [ 32.711944] [] (driver_probe_device) from [] = (bus_for_each_drv+0x90/0xb8) [ 32.721008] [] (bus_for_each_drv) from [] = (__device_attach+0x90/0x120) [ 32.729797] [] (__device_attach) from [] = (bus_probe_device+0x28/0x80) [ 32.738494] [] (bus_probe_device) from [] = (deferred_probe_work_func+0x5c/0x80) [ 32.748016] [] (deferred_probe_work_func) from [] = (process_one_work+0x1e4/0x394) [ 32.757720] [] (process_one_work) from [] = (process_scheduled_works+0x28/0x30) [ 32.767150] [] (process_scheduled_works) from [] = (worker_thread+0x210/0x2d8) [ 32.776489] [] (worker_thread) from [] = (kthread+0x138/0x148) [ 32.784362] [] (kthread) from [] = (ret_from_fork+0x14/0x2c) [ 32.792022] Exception stack(0xda649fb0 to 0xda649ff8) [ 32.797393] 9fa0: 00000000 = 00000000 00000000 00000000 [ 32.806091] 9fc0: 00000000 00000000 00000000 00000000 00000000 = 00000000 00000000 00000000 [ 32.814788] 9fe0: 00000000 00000000 00000000 00000000 00000013 = 00000000 [ 32.842346] omap3isp 480bc000.isp: supply vdd-csiphy1 not found, = using dummy regulator [ 32.855133] omap3isp 480bc000.isp: supply vdd-csiphy2 not found, = using dummy regulator [ 32.864746] omap3isp 480bc000.isp: Revision 15.0 found [ 32.870971] omap-iommu 480bd400.mmu: 480bd400.mmu: version 1.1 [ 32.879913] omap3isp 480bc000.isp: Entity type for entity OMAP3 ISP = CCP2 was not initialized! [ 32.897247] omap3isp 480bc000.isp: Entity type for entity OMAP3 ISP = CSI2a was not initialized! [ 32.917999] omap3isp 480bc000.isp: Entity type for entity OMAP3 ISP = CCDC was not initialized! [ 32.938446] omap3isp 480bc000.isp: Entity type for entity OMAP3 ISP = preview was not initialized! [ 32.966888] omap3isp 480bc000.isp: Entity type for entity OMAP3 ISP = resizer was not initialized! [ 32.987548] omap3isp 480bc000.isp: Entity type for entity OMAP3 ISP = AEWB was not initialized! [ 33.010803] omap3isp 480bc000.isp: Entity type for entity OMAP3 ISP = AF was not initialized! [ 33.026519] omap3isp 480bc000.isp: Entity type for entity OMAP3 ISP = histogram was not initialized! [ 33.052062] ov9655 1-0030: ov9655_probe [ 33.064910] ov9655 1-0030: supply dvdd not found, using dummy = regulator [ 33.075714] ov9655 1-0030: supply dovdd not found, using dummy = regulator [ 33.097900] ov9655 1-0030: __ov9655_set_power on=3D1 [ 33.206787] ov9655 1-0030: OV9655 read register 1c : 7f [ 33.212707] ov9655 1-0030: OV9655 read register 1d : a2 [ 33.220336] ov9655 1-0030: OV9655 read register 0a : 96 [ 33.226104] ov9655 1-0030: OV9655 read register 0b : 57 [ 33.231872] ov9655 1-0030: __ov9655_set_power on=3D0 [ 33.238586] ov9655 1-0030: OV9655 REV5 detected at address 0x30 [ 33.258605] platform sound_bluetooth: deferred probe pending [ 35.915588] omap-iommu 480bd400.mmu: 480bd400.mmu: version 1.1 [ 36.040069] ov9655 1-0030: ov9655_open=