From mboxrd@z Thu Jan 1 00:00:00 1970 From: Felipe Balbi Subject: Re: [PATCH] i2c: omap: revert "i2c: omap: switch to threaded IRQ support" Date: Tue, 16 Oct 2012 16:33:56 +0300 Message-ID: <20121016133356.GG21801@arwen.pp.htv.fi> References: Reply-To: Mime-Version: 1.0 Content-Type: multipart/signed; micalg=pgp-sha1; protocol="application/pgp-signature"; boundary="doKZ0ri6bHmN2Q5y" Return-path: Content-Disposition: inline In-Reply-To: Sender: linux-omap-owner@vger.kernel.org To: Shubhrajyoti Datta Cc: Paul Walmsley , linux-i2c@vger.kernel.org, Felipe Balbi , Shubhrajyoti D , Wolfram Sang , Ben Dooks , linux-omap@vger.kernel.org, linux-arm-kernel@lists.infradead.org, Thomas Gleixner List-Id: linux-i2c@vger.kernel.org --doKZ0ri6bHmN2Q5y Content-Type: text/plain; charset=us-ascii Content-Disposition: inline Content-Transfer-Encoding: quoted-printable Hi, + Thomas Gleixner On Tue, Oct 16, 2012 at 06:28:13PM +0530, Shubhrajyoti Datta wrote: > On Mon, Oct 15, 2012 at 7:21 AM, Paul Walmsley wrote: > > > > Commit 3b2f8f82dad7d1f79cdc8fc05bd1c94baf109bde ("i2c: omap: switch to > > threaded IRQ support") causes communication with I2C devices to fail > > after system suspend/resume on all OMAP3 devices: > > > Could you tell me which omap3 platform >=20 > On Beagle Xm > after > mount /dev/mmcblk /mmcfs >=20 >=20 > # mount /dev/mmcblk0p2 /mmcfs/ > [ 412.480041] kjournald starting. Commit interval 5 seconds > [ 412.490020] EXT3-fs (mmcblk0p2): using internal journal > [ 412.495605] EXT3-fs (mmcblk0p2): mounted filesystem with ordered data = mode > # >=20 >=20 > # cd /mmcfs/ > # > # > # ls > bin omap3_usb_prcm.sh usb_prcm.sh > dev omap3_usbhs_off.sh usb_uhh_show.sh > etc omap3_usbhs_on.sh usb_uhh_tll.sh > init proc usbhs_clk_disable.sh > lib readmem.dat usbhs_clk_enable.sh > lost+found root usbhs_set_sm.sh > mnt sbin usbhs_show.sh > modules sys usr > msc tmp var > omap3_ehcidump.sh usb_omap3.sh > # > # > # echo mem > /sys/power/state > [ 464.785461] PM: Syncing filesystems ... done. > [ 464.791442] PM: Preparing system for mem sleep > [ 464.798034] Freezing user space processes ... (elapsed 0.02 seconds) d= one. > [ 464.827301] Freezing remaining freezable tasks ... (elapsed 0.02 > seconds) done. > [ 464.858703] PM: Entering mem sleep > [ 464.862304] Suspending console(s) (use no_console_suspend to debug) > [ 464.994415] PM: suspend of devices complete after 121.002 msecs > [ 464.998107] PM: late suspend of devices complete after 3.662 msecs > [ 465.003173] PM: noirq suspend of devices complete after 5.004 msecs > [ 465.003173] Disabling non-boot CPUs ... > [ 466.225585] Successfully put all powerdomains to target state > [ 466.228942] PM: noirq resume of devices complete after 3.051 msecs > [ 466.232421] PM: early resume of devices complete after 2.349 msecs > [ 467.492645] PM: resume of devices complete after 1260.131 msecs > [ 467.546936] PM: Finishing wakeup. > [ 467.550415] Restarting tasks ... done. > # > # > # cat /debug/pm_debug/count | grep per_pwrdm > per_pwrdm (ON),OFF:7,RET:0,INA:0,ON:8,RET-LOGIC-OFF:0,RET-MEMBANK1-OFF:0 > per_clkdm->per_pwrdm (17) > # echo mem > /sys/power/state > [ 1492.225311] PM: Syncing filesystems ... done. > [ 1492.232177] PM: Preparing system for mem sleep > [ 1492.238830] Freezing user space processes ... (elapsed 0.02 seconds) d= one. > [ 1492.268188] Freezing remaining freezable tasks ... (elapsed 0.02 > seconds) done. > [ 1492.299804] PM: Entering mem sleep > [ 1492.303375] Suspending console(s) (use no_console_suspend to debug) > [ 1492.435333] PM: suspend of devices complete after 120.880 msecs > [ 1492.439025] PM: late suspend of devices complete after 3.692 msecs > [ 1492.444091] PM: noirq suspend of devices complete after 5.004 msecs > [ 1492.444091] Disabling non-boot CPUs ... > [ 1493.745544] Successfully put all powerdomains to target state > [ 1493.748901] PM: noirq resume of devices complete after 3.051 msecs > [ 1493.752319] PM: early resume of devices complete after 2.319 msecs > [ 1494.794067] PM: resume of devices complete after 1041.625 msecs > [ 1494.848388] PM: Finishing wakeup. > [ 1494.851867] Restarting tasks ... done. > # > # > # cat /debug/pm_debug/count | grep per_pwrdm > per_pwrdm (ON),OFF:8,RET:0,INA:0,ON:9,RET-LOGIC-OFF:0,RET-MEMBANK1-OFF:0 > per_clkdm->per_pwrdm (17) > # >=20 > Anyways will retry with fs on mmc. rootfs has to be on MMC to trigger this. The problem happens because omap_hsmmc calls enable_irq() on its resume method. That IRQ line is actually a GPIO from TWL4030, so twl4030-irq.c::twl4030_sih_bus_sync_unlock() will be called, which will trigger an I2C transfer. The problem I see is that even though we properly return IRQ_WAKE_THREAD and wake_up_process() manages to wakeup the IRQ thread (it returns 1), the thread is never scheduled. To make things even worse, ouw irq thread runs once, but doesn't run on a consecutive call. Here's some (rather nasty) debug prints showing the problem: > [ 78.709381] omap_i2c omap_i2c.1: omap_i2c_isr_thread 913 > [ 78.715026] omap_i2c omap_i2c.1: omap_i2c_isr_thread 1038 > [ 78.720733] omap_i2c omap_i2c.1: omap_i2c_xfer 655 > [ 78.725769] omap_i2c omap_i2c.1: omap_i2c_xfer 659 > [ 78.730804] omap_i2c omap_i2c.1: omap_i2c_xfer 663 > [ 78.735870] omap_i2c omap_i2c.1: omap_i2c_xfer 668 > [ 78.850708] PM: suspend of devices complete after 1287.841 msecs > [ 78.860870] PM: late suspend of devices complete after 3.753 msecs > [ 78.872283] try_to_wake_up 1411 > [ 78.875701] try_to_wake_up 1411 > [ 78.879028] try_to_wake_up 1411 > [ 78.882537] omap_i2c omap_i2c.1: omap_i2c_runtime_suspend 1359 > [ 78.888763] omap_i2c omap_i2c.1: omap_i2c_low_level_suspend 1261 > [ 78.895416] PM: noirq suspend of devices complete after 28.015 msecs > [ 78.902160] Disabling non-boot CPUs ... > [ 88.568664] Powerdomain (per_pwrdm) didn't enter target state 1 > [ 88.574859] Powerdomain (core_pwrdm) didn't enter target state 1 > [ 88.581115] Could not enter target state in pm_suspend > [ 88.586975] omap_i2c omap_i2c.1: omap_i2c_runtime_resume 1373 > [ 88.592987] omap_i2c omap_i2c.1: omap_i2c_low_level_resume 1287 > [ 88.599243] try_to_wake_up 1411 > [ 88.602569] try_to_wake_up 1411 > [ 88.608459] PM: noirq resume of devices complete after 21.759 msecs > [ 88.615814] try_to_wake_up 1411 > [ 88.622497] PM: early resume of devices complete after 2.380 msecs > [ 88.632965] omap_i2c omap_i2c.1: omap_i2c_xfer 626 > [ 88.638092] omap_i2c omap_i2c.1: omap_i2c_xfer 632 > [ 88.643188] omap_i2c omap_i2c.1: omap_i2c_xfer 648 > [ 88.648193] omap_i2c omap_i2c.1: addr: 0x0049, len: 4, flags: 0x0, sto= p: 1 > [ 88.655456] omap_i2c omap_i2c.1: omap_i2c_xfer_msg 537 > [ 88.660858] omap_i2c omap_i2c.1: omap_i2c_isr 885 > [ 88.665802] omap_i2c omap_i2c.1: omap_i2c_isr 891: mask 601f stat 1510 > [ 88.672637] omap_i2c omap_i2c.1: omap_i2c_isr 894 > [ 88.677551] omap_i2c omap_i2c.1: omap_i2c_isr 899 > [ 88.682495] =3D=3D=3D> irq_wake_thread 139: IRQ 72 wake_up_process 1 > [ 88.688751] omap_i2c omap_i2c.1: omap_i2c_isr_thread 913 > [ 88.694335] omap_i2c omap_i2c.1: omap_i2c_isr_thread 1038 > [ 88.700347] omap_i2c omap_i2c.1: omap_i2c_isr 885 > [ 88.705291] omap_i2c omap_i2c.1: omap_i2c_isr 891: mask 601f stat 0104 > [ 88.712097] omap_i2c omap_i2c.1: omap_i2c_isr 894 > [ 88.717010] omap_i2c omap_i2c.1: omap_i2c_isr 899 > [ 88.721923] try_to_wake_up 1411 > [ 88.725189] =3D=3D=3D> irq_wake_thread 139: IRQ 72 wake_up_process 0 > [ 88.731292] [sched_delayed] sched: RT throttling activated > [ 88.737091] omap_i2c omap_i2c.1: omap_i2c_isr_thread 913 > [ 88.742706] omap_i2c omap_i2c.1: omap_i2c_isr_thread 1038 this is the last time our omap_i2c_isr_thread() runs. Note that the thread was already running when wake_up_process() was called. > [ 88.749206] omap_i2c omap_i2c.1: omap_i2c_xfer 655 > [ 88.754302] omap_i2c omap_i2c.1: omap_i2c_xfer 659 > [ 88.759368] omap_i2c omap_i2c.1: omap_i2c_xfer 663 > [ 88.764373] omap_i2c omap_i2c.1: omap_i2c_xfer 668 > [ 88.769531] omap_i2c omap_i2c.1: omap_i2c_xfer 626 > [ 88.774597] omap_i2c omap_i2c.1: omap_i2c_xfer 632 > [ 88.779602] omap_i2c omap_i2c.1: omap_i2c_xfer 648 > [ 88.784667] omap_i2c omap_i2c.1: addr: 0x004b, len: 1, flags: 0x0, sto= p: 0 > [ 88.791900] omap_i2c omap_i2c.1: omap_i2c_xfer_msg 537 > [ 88.797271] omap_i2c omap_i2c.1: omap_i2c_isr 885 > [ 88.802185] omap_i2c omap_i2c.1: omap_i2c_isr 891: mask 601f stat 1510 > [ 88.809020] omap_i2c omap_i2c.1: omap_i2c_isr 894 > [ 88.813934] omap_i2c omap_i2c.1: omap_i2c_isr 899 > [ 88.818847] =3D=3D=3D> irq_wake_thread 139: IRQ 72 wake_up_process 1 notice here that our omap_i2c_isr_thread() never runs. I'm still debugging, trying to pin point what the real issue is, but it's definitely not the fact that we have a threaded ISR, since it runs at least once. > [ 90.610107] try_to_wake_up 1411 > [ 93.821044] try_to_wake_up 1411 > [ 93.824768] omap_i2c omap_i2c.1: controller timed out > [ 93.830169] [] (unwind_backtrace+0x0/0xf0) from []= (omap_i2c_xfer_msg+0x314/0x360) > [ 93.839935] [] (omap_i2c_xfer_msg+0x314/0x360) from [] (omap_i2c_xfer+0xac/0x220) > [ 93.849639] [] (omap_i2c_xfer+0xac/0x220) from [] = (__i2c_transfer+0x40/0x80) > [ 93.858886] [] (__i2c_transfer+0x40/0x80) from [] = (i2c_transfer+0x1f8/0x26c) > [ 93.868103] [] (i2c_transfer+0x1f8/0x26c) from [] = (twl_i2c_read+0xc4/0x15c) > [ 93.877288] [] (twl_i2c_read+0xc4/0x15c) from [] (= twl4030ldo_get_voltage+0x28/0x60) > [ 93.887145] [] (twl4030ldo_get_voltage+0x28/0x60) from [] (_regulator_get_voltage+0x68/0x84) > [ 93.897827] [] (_regulator_get_voltage+0x68/0x84) from [] (regulator_get_voltage+0x20/0x38) > [ 93.908447] [] (regulator_get_voltage+0x20/0x38) from [] (mmc_regulator_set_ocr+0x40/0x12c) > [ 93.919036] [] (mmc_regulator_set_ocr+0x40/0x12c) from [] (omap_hsmmc_set_power+0xe4/0x11c) > [ 93.929626] [] (omap_hsmmc_set_power+0xe4/0x11c) from [] (omap_hsmmc_set_ios+0x140/0x150) > [ 93.940032] [] (omap_hsmmc_set_ios+0x140/0x150) from [] (mmc_power_up+0x80/0xc4) > [ 93.949615] [] (mmc_power_up+0x80/0xc4) from [] (m= mc_resume_host+0xd0/0x150) > [ 93.958862] [] (mmc_resume_host+0xd0/0x150) from [= ] (omap_hsmmc_resume+0x7c/0xc8) > [ 93.968536] [] (omap_hsmmc_resume+0x7c/0xc8) from [] (platform_pm_resume+0x2c/0x50) > [ 93.978424] [] (platform_pm_resume+0x2c/0x50) from [] (dpm_run_callback.isra.4+0x2c/0x64) > [ 93.988830] [] (dpm_run_callback.isra.4+0x2c/0x64) from [] (device_resume+0xdc/0x18c) > [ 93.998870] [] (device_resume+0xdc/0x18c) from [] = (dpm_resume+0xfc/0x21c) > [ 94.007812] [] (dpm_resume+0xfc/0x21c) from [] (dp= m_resume_end+0xc/0x18) > [ 94.016723] [] (dpm_resume_end+0xc/0x18) from [] (= suspend_devices_and_enter+0xe8/0x1b0) > [ 94.026947] [] (suspend_devices_and_enter+0xe8/0x1b0) from [= ] (enter_state+0x9c/0xdc) > [ 94.036987] [] (enter_state+0x9c/0xdc) from [] (pm= _suspend+0x14/0x70) > [ 94.045593] [] (pm_suspend+0x14/0x70) from [] (sta= te_store+0x30/0x3c) > [ 94.054199] [] (state_store+0x30/0x3c) from [] (ko= bj_attr_store+0x14/0x20) > [ 94.063262] [] (kobj_attr_store+0x14/0x20) from []= (sysfs_write_file+0x80/0xb4) > [ 94.072784] [] (sysfs_write_file+0x80/0xb4) from [= ] (vfs_write+0xa8/0x138) > [ 94.081817] [] (vfs_write+0xa8/0x138) from [] (sys= _write+0x40/0x68) > [ 94.090240] [] (sys_write+0x40/0x68) from [] (ret_= fast_syscall+0x0/0x3c) > [ 94.099334] omap_i2c omap_i2c.1: omap_i2c_xfer 655 > [ 94.104431] omap_i2c omap_i2c.1: omap_i2c_xfer 659 > [ 94.109466] omap_i2c omap_i2c.1: omap_i2c_xfer 663 > [ 94.114532] omap_i2c omap_i2c.1: omap_i2c_xfer 668 > [ 94.119567] twl: i2c_read failed to transfer all messages > [ 94.125244] omap_hsmmc omap_hsmmc.0: could not set regulator OCR (-110) > [ 94.286773] mmc0: error -110 during resume (card was removed?) --=20 balbi --doKZ0ri6bHmN2Q5y Content-Type: application/pgp-signature; name="signature.asc" Content-Description: Digital signature -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.12 (GNU/Linux) iQIcBAEBAgAGBQJQfWJEAAoJEIaOsuA1yqRE9h8QAIq6CoGCAx+XuZEzG9le1PRh 6UaE1mEOjR5cVCJzMb2IZ9xWfO3wH2BHSBK52AltYKm1U7OU1z7fv2oXszaiGWy1 2ej9Gqav2LC5ebfkqzX6d52kfkZd8MxNxdD7wiLzslYm9my/S1FPbYbJlnJyLsd0 j0Dqv1bIQPQr4+gmclW2Dxz3omzQ7MY46eDwNbzWV5PcrPnS49hRC2aQLGHVbUee cmkTpreuOOsxQX1Xu1LkkfpP5068bxLCFhGoG9YT7oIci6p7L4iXce7HwtJdMIKo p5ZRziTGGcVj1J8a9y/jpKHXqGzl2uQQTDqPJy85A3JODvY7oN351r1zBYxy6EGD qkjiQx33fWZq4qKGuAG6att3U0kLF8GM6wpiGM2MczelE3BgaF6NTj8k1q10NRT1 gXHIliyxa4xqTbBGIt/iXBZU7aD7JcUDP7/EI47u0U/jofjeHNKZv3j80gsRt8R7 cZhFIlHEVgkcaixL04XXYrF/kO0TdSDnq+BZNXQ/8mV6lLFr6wOf9V2cV+eeGM2u o/ciisvWPUIiSK3ATFirT3nxpJoW8cxvD+LpIEDgi9cyhh27iTro+Guymd+Dfwf7 VTQCCO0JmPFrmUFE3f3oQTluQNniEULh0TzN+xb3/9oHyKP95TPpSYE0lXJFQCYm NOd9R/W/QtC3zqhKOtyi =6OGg -----END PGP SIGNATURE----- --doKZ0ri6bHmN2Q5y-- From mboxrd@z Thu Jan 1 00:00:00 1970 From: balbi@ti.com (Felipe Balbi) Date: Tue, 16 Oct 2012 16:33:56 +0300 Subject: [PATCH] i2c: omap: revert "i2c: omap: switch to threaded IRQ support" In-Reply-To: References: Message-ID: <20121016133356.GG21801@arwen.pp.htv.fi> To: linux-arm-kernel@lists.infradead.org List-Id: linux-arm-kernel.lists.infradead.org Hi, + Thomas Gleixner On Tue, Oct 16, 2012 at 06:28:13PM +0530, Shubhrajyoti Datta wrote: > On Mon, Oct 15, 2012 at 7:21 AM, Paul Walmsley wrote: > > > > Commit 3b2f8f82dad7d1f79cdc8fc05bd1c94baf109bde ("i2c: omap: switch to > > threaded IRQ support") causes communication with I2C devices to fail > > after system suspend/resume on all OMAP3 devices: > > > Could you tell me which omap3 platform > > On Beagle Xm > after > mount /dev/mmcblk /mmcfs > > > # mount /dev/mmcblk0p2 /mmcfs/ > [ 412.480041] kjournald starting. Commit interval 5 seconds > [ 412.490020] EXT3-fs (mmcblk0p2): using internal journal > [ 412.495605] EXT3-fs (mmcblk0p2): mounted filesystem with ordered data mode > # > > > # cd /mmcfs/ > # > # > # ls > bin omap3_usb_prcm.sh usb_prcm.sh > dev omap3_usbhs_off.sh usb_uhh_show.sh > etc omap3_usbhs_on.sh usb_uhh_tll.sh > init proc usbhs_clk_disable.sh > lib readmem.dat usbhs_clk_enable.sh > lost+found root usbhs_set_sm.sh > mnt sbin usbhs_show.sh > modules sys usr > msc tmp var > omap3_ehcidump.sh usb_omap3.sh > # > # > # echo mem > /sys/power/state > [ 464.785461] PM: Syncing filesystems ... done. > [ 464.791442] PM: Preparing system for mem sleep > [ 464.798034] Freezing user space processes ... (elapsed 0.02 seconds) done. > [ 464.827301] Freezing remaining freezable tasks ... (elapsed 0.02 > seconds) done. > [ 464.858703] PM: Entering mem sleep > [ 464.862304] Suspending console(s) (use no_console_suspend to debug) > [ 464.994415] PM: suspend of devices complete after 121.002 msecs > [ 464.998107] PM: late suspend of devices complete after 3.662 msecs > [ 465.003173] PM: noirq suspend of devices complete after 5.004 msecs > [ 465.003173] Disabling non-boot CPUs ... > [ 466.225585] Successfully put all powerdomains to target state > [ 466.228942] PM: noirq resume of devices complete after 3.051 msecs > [ 466.232421] PM: early resume of devices complete after 2.349 msecs > [ 467.492645] PM: resume of devices complete after 1260.131 msecs > [ 467.546936] PM: Finishing wakeup. > [ 467.550415] Restarting tasks ... done. > # > # > # cat /debug/pm_debug/count | grep per_pwrdm > per_pwrdm (ON),OFF:7,RET:0,INA:0,ON:8,RET-LOGIC-OFF:0,RET-MEMBANK1-OFF:0 > per_clkdm->per_pwrdm (17) > # echo mem > /sys/power/state > [ 1492.225311] PM: Syncing filesystems ... done. > [ 1492.232177] PM: Preparing system for mem sleep > [ 1492.238830] Freezing user space processes ... (elapsed 0.02 seconds) done. > [ 1492.268188] Freezing remaining freezable tasks ... (elapsed 0.02 > seconds) done. > [ 1492.299804] PM: Entering mem sleep > [ 1492.303375] Suspending console(s) (use no_console_suspend to debug) > [ 1492.435333] PM: suspend of devices complete after 120.880 msecs > [ 1492.439025] PM: late suspend of devices complete after 3.692 msecs > [ 1492.444091] PM: noirq suspend of devices complete after 5.004 msecs > [ 1492.444091] Disabling non-boot CPUs ... > [ 1493.745544] Successfully put all powerdomains to target state > [ 1493.748901] PM: noirq resume of devices complete after 3.051 msecs > [ 1493.752319] PM: early resume of devices complete after 2.319 msecs > [ 1494.794067] PM: resume of devices complete after 1041.625 msecs > [ 1494.848388] PM: Finishing wakeup. > [ 1494.851867] Restarting tasks ... done. > # > # > # cat /debug/pm_debug/count | grep per_pwrdm > per_pwrdm (ON),OFF:8,RET:0,INA:0,ON:9,RET-LOGIC-OFF:0,RET-MEMBANK1-OFF:0 > per_clkdm->per_pwrdm (17) > # > > Anyways will retry with fs on mmc. rootfs has to be on MMC to trigger this. The problem happens because omap_hsmmc calls enable_irq() on its resume method. That IRQ line is actually a GPIO from TWL4030, so twl4030-irq.c::twl4030_sih_bus_sync_unlock() will be called, which will trigger an I2C transfer. The problem I see is that even though we properly return IRQ_WAKE_THREAD and wake_up_process() manages to wakeup the IRQ thread (it returns 1), the thread is never scheduled. To make things even worse, ouw irq thread runs once, but doesn't run on a consecutive call. Here's some (rather nasty) debug prints showing the problem: > [ 78.709381] omap_i2c omap_i2c.1: omap_i2c_isr_thread 913 > [ 78.715026] omap_i2c omap_i2c.1: omap_i2c_isr_thread 1038 > [ 78.720733] omap_i2c omap_i2c.1: omap_i2c_xfer 655 > [ 78.725769] omap_i2c omap_i2c.1: omap_i2c_xfer 659 > [ 78.730804] omap_i2c omap_i2c.1: omap_i2c_xfer 663 > [ 78.735870] omap_i2c omap_i2c.1: omap_i2c_xfer 668 > [ 78.850708] PM: suspend of devices complete after 1287.841 msecs > [ 78.860870] PM: late suspend of devices complete after 3.753 msecs > [ 78.872283] try_to_wake_up 1411 > [ 78.875701] try_to_wake_up 1411 > [ 78.879028] try_to_wake_up 1411 > [ 78.882537] omap_i2c omap_i2c.1: omap_i2c_runtime_suspend 1359 > [ 78.888763] omap_i2c omap_i2c.1: omap_i2c_low_level_suspend 1261 > [ 78.895416] PM: noirq suspend of devices complete after 28.015 msecs > [ 78.902160] Disabling non-boot CPUs ... > [ 88.568664] Powerdomain (per_pwrdm) didn't enter target state 1 > [ 88.574859] Powerdomain (core_pwrdm) didn't enter target state 1 > [ 88.581115] Could not enter target state in pm_suspend > [ 88.586975] omap_i2c omap_i2c.1: omap_i2c_runtime_resume 1373 > [ 88.592987] omap_i2c omap_i2c.1: omap_i2c_low_level_resume 1287 > [ 88.599243] try_to_wake_up 1411 > [ 88.602569] try_to_wake_up 1411 > [ 88.608459] PM: noirq resume of devices complete after 21.759 msecs > [ 88.615814] try_to_wake_up 1411 > [ 88.622497] PM: early resume of devices complete after 2.380 msecs > [ 88.632965] omap_i2c omap_i2c.1: omap_i2c_xfer 626 > [ 88.638092] omap_i2c omap_i2c.1: omap_i2c_xfer 632 > [ 88.643188] omap_i2c omap_i2c.1: omap_i2c_xfer 648 > [ 88.648193] omap_i2c omap_i2c.1: addr: 0x0049, len: 4, flags: 0x0, stop: 1 > [ 88.655456] omap_i2c omap_i2c.1: omap_i2c_xfer_msg 537 > [ 88.660858] omap_i2c omap_i2c.1: omap_i2c_isr 885 > [ 88.665802] omap_i2c omap_i2c.1: omap_i2c_isr 891: mask 601f stat 1510 > [ 88.672637] omap_i2c omap_i2c.1: omap_i2c_isr 894 > [ 88.677551] omap_i2c omap_i2c.1: omap_i2c_isr 899 > [ 88.682495] ===> irq_wake_thread 139: IRQ 72 wake_up_process 1 > [ 88.688751] omap_i2c omap_i2c.1: omap_i2c_isr_thread 913 > [ 88.694335] omap_i2c omap_i2c.1: omap_i2c_isr_thread 1038 > [ 88.700347] omap_i2c omap_i2c.1: omap_i2c_isr 885 > [ 88.705291] omap_i2c omap_i2c.1: omap_i2c_isr 891: mask 601f stat 0104 > [ 88.712097] omap_i2c omap_i2c.1: omap_i2c_isr 894 > [ 88.717010] omap_i2c omap_i2c.1: omap_i2c_isr 899 > [ 88.721923] try_to_wake_up 1411 > [ 88.725189] ===> irq_wake_thread 139: IRQ 72 wake_up_process 0 > [ 88.731292] [sched_delayed] sched: RT throttling activated > [ 88.737091] omap_i2c omap_i2c.1: omap_i2c_isr_thread 913 > [ 88.742706] omap_i2c omap_i2c.1: omap_i2c_isr_thread 1038 this is the last time our omap_i2c_isr_thread() runs. Note that the thread was already running when wake_up_process() was called. > [ 88.749206] omap_i2c omap_i2c.1: omap_i2c_xfer 655 > [ 88.754302] omap_i2c omap_i2c.1: omap_i2c_xfer 659 > [ 88.759368] omap_i2c omap_i2c.1: omap_i2c_xfer 663 > [ 88.764373] omap_i2c omap_i2c.1: omap_i2c_xfer 668 > [ 88.769531] omap_i2c omap_i2c.1: omap_i2c_xfer 626 > [ 88.774597] omap_i2c omap_i2c.1: omap_i2c_xfer 632 > [ 88.779602] omap_i2c omap_i2c.1: omap_i2c_xfer 648 > [ 88.784667] omap_i2c omap_i2c.1: addr: 0x004b, len: 1, flags: 0x0, stop: 0 > [ 88.791900] omap_i2c omap_i2c.1: omap_i2c_xfer_msg 537 > [ 88.797271] omap_i2c omap_i2c.1: omap_i2c_isr 885 > [ 88.802185] omap_i2c omap_i2c.1: omap_i2c_isr 891: mask 601f stat 1510 > [ 88.809020] omap_i2c omap_i2c.1: omap_i2c_isr 894 > [ 88.813934] omap_i2c omap_i2c.1: omap_i2c_isr 899 > [ 88.818847] ===> irq_wake_thread 139: IRQ 72 wake_up_process 1 notice here that our omap_i2c_isr_thread() never runs. I'm still debugging, trying to pin point what the real issue is, but it's definitely not the fact that we have a threaded ISR, since it runs at least once. > [ 90.610107] try_to_wake_up 1411 > [ 93.821044] try_to_wake_up 1411 > [ 93.824768] omap_i2c omap_i2c.1: controller timed out > [ 93.830169] [] (unwind_backtrace+0x0/0xf0) from [] (omap_i2c_xfer_msg+0x314/0x360) > [ 93.839935] [] (omap_i2c_xfer_msg+0x314/0x360) from [] (omap_i2c_xfer+0xac/0x220) > [ 93.849639] [] (omap_i2c_xfer+0xac/0x220) from [] (__i2c_transfer+0x40/0x80) > [ 93.858886] [] (__i2c_transfer+0x40/0x80) from [] (i2c_transfer+0x1f8/0x26c) > [ 93.868103] [] (i2c_transfer+0x1f8/0x26c) from [] (twl_i2c_read+0xc4/0x15c) > [ 93.877288] [] (twl_i2c_read+0xc4/0x15c) from [] (twl4030ldo_get_voltage+0x28/0x60) > [ 93.887145] [] (twl4030ldo_get_voltage+0x28/0x60) from [] (_regulator_get_voltage+0x68/0x84) > [ 93.897827] [] (_regulator_get_voltage+0x68/0x84) from [] (regulator_get_voltage+0x20/0x38) > [ 93.908447] [] (regulator_get_voltage+0x20/0x38) from [] (mmc_regulator_set_ocr+0x40/0x12c) > [ 93.919036] [] (mmc_regulator_set_ocr+0x40/0x12c) from [] (omap_hsmmc_set_power+0xe4/0x11c) > [ 93.929626] [] (omap_hsmmc_set_power+0xe4/0x11c) from [] (omap_hsmmc_set_ios+0x140/0x150) > [ 93.940032] [] (omap_hsmmc_set_ios+0x140/0x150) from [] (mmc_power_up+0x80/0xc4) > [ 93.949615] [] (mmc_power_up+0x80/0xc4) from [] (mmc_resume_host+0xd0/0x150) > [ 93.958862] [] (mmc_resume_host+0xd0/0x150) from [] (omap_hsmmc_resume+0x7c/0xc8) > [ 93.968536] [] (omap_hsmmc_resume+0x7c/0xc8) from [] (platform_pm_resume+0x2c/0x50) > [ 93.978424] [] (platform_pm_resume+0x2c/0x50) from [] (dpm_run_callback.isra.4+0x2c/0x64) > [ 93.988830] [] (dpm_run_callback.isra.4+0x2c/0x64) from [] (device_resume+0xdc/0x18c) > [ 93.998870] [] (device_resume+0xdc/0x18c) from [] (dpm_resume+0xfc/0x21c) > [ 94.007812] [] (dpm_resume+0xfc/0x21c) from [] (dpm_resume_end+0xc/0x18) > [ 94.016723] [] (dpm_resume_end+0xc/0x18) from [] (suspend_devices_and_enter+0xe8/0x1b0) > [ 94.026947] [] (suspend_devices_and_enter+0xe8/0x1b0) from [] (enter_state+0x9c/0xdc) > [ 94.036987] [] (enter_state+0x9c/0xdc) from [] (pm_suspend+0x14/0x70) > [ 94.045593] [] (pm_suspend+0x14/0x70) from [] (state_store+0x30/0x3c) > [ 94.054199] [] (state_store+0x30/0x3c) from [] (kobj_attr_store+0x14/0x20) > [ 94.063262] [] (kobj_attr_store+0x14/0x20) from [] (sysfs_write_file+0x80/0xb4) > [ 94.072784] [] (sysfs_write_file+0x80/0xb4) from [] (vfs_write+0xa8/0x138) > [ 94.081817] [] (vfs_write+0xa8/0x138) from [] (sys_write+0x40/0x68) > [ 94.090240] [] (sys_write+0x40/0x68) from [] (ret_fast_syscall+0x0/0x3c) > [ 94.099334] omap_i2c omap_i2c.1: omap_i2c_xfer 655 > [ 94.104431] omap_i2c omap_i2c.1: omap_i2c_xfer 659 > [ 94.109466] omap_i2c omap_i2c.1: omap_i2c_xfer 663 > [ 94.114532] omap_i2c omap_i2c.1: omap_i2c_xfer 668 > [ 94.119567] twl: i2c_read failed to transfer all messages > [ 94.125244] omap_hsmmc omap_hsmmc.0: could not set regulator OCR (-110) > [ 94.286773] mmc0: error -110 during resume (card was removed?) -- balbi -------------- next part -------------- A non-text attachment was scrubbed... Name: signature.asc Type: application/pgp-signature Size: 836 bytes Desc: Digital signature URL: