[20030321] Failed to acquire semaphore

[20030321] Failed to acquire semaphore

[Karol Kozimor]

Hi,
I recently managed to compile a (hopefully) stable 2.4.21-pre5 with latest
ACPI. Since this kernel required heavy loads of manual patching (the XFS
patch comes only for 2.4.20, swsusp-beta19 was for earlier ACPI, CPUfreq
doesn't get on well with the latter), and furthermore, I wasn't always sure
of what I was doing, I'm curious whether the error below is something
specific. I'm particularly interested in the following changes I made to
drivers/acpi/system.c. It was originally
#v+ (around line 340)
        /* disable interrupts and flush caches */
        ACPI_DISABLE_IRQS();
        ACPI_FLUSH_CPU_CACHE();

        /* perform OS-specific sleep actions */
        if(swsusp) { /* we just ignore acpi architecture for the moment */
                software_suspend_pending(); /* when we return, this is
resume */
                status = AE_OK;
        } else {
        status = acpi_system_suspend(state);

        /* Even if we failed to go to sleep, all of the devices are in an
 * suspended
         * mode. So, we run these unconditionaly to make sure we have a
         * usable system
         * no matter what.
         */
        acpi_leave_sleep_state(state);
        acpi_system_restore_state(state);

        /* make sure interrupts are enabled */
        ACPI_ENABLE_IRQS();
#v-

And what I changed was:
#v+
        if(swsusp) { /* we just ignore acpi architecture for the moment */
                software_suspend_pending(); /* when we return, this is
resume */
+                acpi_leave_sleep_state(state);
                status = AE_OK;
        } else {
        status = acpi_system_suspend(state);

        /* Even if we failed to go to sleep, all of the devices are in an
 * suspended
         * mode. So, we run these unconditionaly to make sure we have a
         * usable system
         * no matter what.
         */
        acpi_leave_sleep_state(state);
        acpi_system_restore_state(state);
+        }

        /* make sure interrupts are enabled */
#v-

Ad.1 swsusp-beta19 expects this, but since the patch is against a previous
version, and the code has changed, I had to do it that way. I don't know if
it's the right way...
Ad.2 The code won't compile without the bracket.

Well, the particular error I'm seeing at boot time is:
#v+
Mar 23 20:12:30 nadir kernel: Transparent bridge - Intel Corp. 82801BAM/CAM PCI Bridge
Mar 23 20:12:30 nadir kernel: schedule_task(): keventd has not started
Mar 23 20:12:30 nadir kernel: ACPI: PCI Interrupt Link [LNKE] enabled at IRQ 10
Mar 23 20:12:30 nadir kernel: ACPI: PCI Interrupt Link [LNKF] enabled at IRQ 11
Mar 23 20:12:30 nadir kernel: ACPI: PCI Interrupt Link [LNKG] enabled at IRQ 10
Mar 23 20:12:30 nadir kernel: ACPI: PCI Interrupt Link [LNKH] enabled at IRQ 5
Mar 23 20:12:30 nadir kernel: Initializing RT netlink socket
Mar 23 20:12:30 nadir kernel:      osl-0888 [24] os_wait_semaphore     : Failed to acquire semaphore[cfff74c0|1|0], AE_TIME
Mar 23 20:12:30 nadir kernel:   utmisc-0743 [23] ut_acquire_mutex      : Thread 0 could not acquire Mutex [ACPI_MTX_Events] AE_TIME
#v-

Occasionally (e.g. upon a notify or event), the two last lines reappear,
and ACPI events are not handled otherwise (i.e. acpid fails to notice
them). Furthermore, resuming from S1 floods the screen with the above
messages, but the system is working nonetheless. All the ACPI subsystem I
rely on (i.e. performance / cooling method switching, readings, etc.) seems
to be working fine besides that.
I'll be grateful for any help, TIA, best regards,

-- 
Karol 'sziwan' Kozimor
sziwan-DETuoxkZsSqrDJvtcaxF/A@public.gmane.org


-------------------------------------------------------
This SF.net email is sponsored by:Crypto Challenge is now open! 
Get cracking and register here for some mind boggling fun and 
the chance of winning an Apple iPod:
http://ads.sourceforge.net/cgi-bin/redirect.pl?thaw0031en

Re: [20030321] Failed to acquire semaphore

[Joshua Legbandt]

On Sun, 2003-03-23 at 12:30, Karol Kozimor wrote:
> Mar 23 20:12:30 nadir kernel:      osl-0888 [24] os_wait_semaphore     : Failed to acquire semaphore[cfff74c0|1|0], AE_TIME
> Mar 23 20:12:30 nadir kernel:   utmisc-0743 [23] ut_acquire_mutex      : Thread 0 could not acquire Mutex [ACPI_MTX_Events] AE_TIME
> #v-
> 
> Occasionally (e.g. upon a notify or event), the two last lines reappear,
> and ACPI events are not handled otherwise (i.e. acpid fails to notice
> them). 

I am seeing the same issue with 2.4.21-pre5, the 20030321 acpi patch and
no other patches. Since I run this on my laptop, my question is whether
this is going to negatively affect the lifespan of my laptop. On the
other hand, now even with the power plugged in my battery is always
recognized...

-Josh

-- 
Joshua Legbandt <jtlegbandt-ihVZJaRskl1bRRN4PJnoQQ@public.gmane.org>



-------------------------------------------------------
This SF.net email is sponsored by:Crypto Challenge is now open! 
Get cracking and register here for some mind boggling fun and 
the chance of winning an Apple iPod:
http://ads.sourceforge.net/cgi-bin/redirect.pl?thaw0031en

Re: [20030321] Failed to acquire semaphore

[Karol Kozimor]

Thus wrote Karol Kozimor:
>    osl-0888 [24] os_wait_semaphore     : Failed to acquire semaphore[cfff74c0|1|0], AE_TIME
> utmisc-0743 [23] ut_acquire_mutex      : Thread 0 could not acquire Mutex [ACPI_MTX_Events] AE_TIME

It is present in the 2.5.65-acpi-20030321 also, the same symptoms.
Best regards,

-- 
Karol 'sziwan' Kozimor
sziwan-DETuoxkZsSqrDJvtcaxF/A@public.gmane.org


-------------------------------------------------------
This SF.net email is sponsored by:
The Definitive IT and Networking Event. Be There!
NetWorld+Interop Las Vegas 2003 -- Register today!
http://ads.sourceforge.net/cgi-bin/redirect.pl?keyn0001en

RE: [20030321] Failed to acquire semaphore

[Grover, Andrew]

> From: Karol Kozimor [mailto:sziwan-DETuoxkZsSqrDJvtcaxF/A@public.gmane.org] 
> Thus wrote Karol Kozimor:
> >    osl-0888 [24] os_wait_semaphore     : Failed to acquire 
> semaphore[cfff74c0|1|0], AE_TIME
> > utmisc-0743 [23] ut_acquire_mutex      : Thread 0 could not 
> acquire Mutex [ACPI_MTX_Events] AE_TIME
> 
> It is present in the 2.5.65-acpi-20030321 also, the same symptoms.
> Best regards,

Hiya -- can you (or someone else experiencing the same problem - I know
there are a few) stick a WARN_ON(1) where that error message is
happening, and turn on CONFIG_KALLSYMS, so we can get a stack trace?

Thanks -- Andy


-------------------------------------------------------
This SF.net email is sponsored by:
The Definitive IT and Networking Event. Be There!
NetWorld+Interop Las Vegas 2003 -- Register today!
http://ads.sourceforge.net/cgi-bin/redirect.pl?keyn0001en

Re: [20030321] Failed to acquire semaphore

[bperkins-ooduxAEi7gVg9hUCZPvPmw]

Here's the stack trace from the error on bootup.
It's exaclty the same if I push a button, close a lid, chnage
brightness, etc.


Badness in acpi_os_wait_semaphore at drivers/acpi/osl.c:911
Call Trace:
 [<c0223a03>] acpi_os_wait_semaphore+0x125/0x20a
 [<c02470f4>] acpi_ut_acquire_mutex+0x92/0x164
 [<c022ad37>] acpi_disable_gpe+0x33/0x96
 [<c024cf63>] acpi_ec_gpe_handler+0x17/0x2a
 [<c022cc9d>] acpi_ev_gpe_dispatch+0x18f/0x1d0
 [<c022c9e6>] acpi_ev_gpe_detect+0x168/0x170
 [<c022a7e8>] acpi_ev_sci_xrupt_handler+0x38/0x50
 [<c0222f91>] acpi_irq+0xf/0x12
 [<c010b595>] handle_IRQ_event+0x37/0x5e
 [<c0222f82>] acpi_irq+0x0/0x12
 [<c010b7ff>] do_IRQ+0xc5/0x184
 [<c0109d9c>] common_interrupt+0x18/0x20
 [<c0223116>] acpi_os_write_port+0x2e/0x46
 [<c0237150>] acpi_hw_low_level_write+0xe6/0xee
 [<c0247120>] acpi_ut_acquire_mutex+0xbe/0x164
 [<c02362b5>] acpi_hw_enable_gpe+0x45/0x48
 [<c022abe3>] acpi_enable_gpe+0x6f/0x9c
 [<c024ced8>] acpi_ec_gpe_query+0xce/0x142
 [<c022346c>] acpi_os_execute_deferred+0x3a/0x6c
 [<c012f2cf>] worker_thread+0x1f9/0x2f4
 [<c0223432>] acpi_os_execute_deferred+0x0/0x6c
 [<c011b88a>] default_wake_function+0x0/0x12
 [<c0109306>] ret_from_fork+0x6/0x14
 [<c011b88a>] default_wake_function+0x0/0x12
 [<c012f0d6>] worker_thread+0x0/0x2f4
 [<c01072f1>] kernel_thread_helper+0x5/0xc

     osl-0913 [31] os_wait_semaphore     : Failed to acquire semaphore[cff62580|1|0], AE_TIME
  utmisc-0743 [30] ut_acquire_mutex      : Thread 0 could not acquire Mutex [ACPI_MTX_Events] AE_TIME


--
Pack my box with five dozen liquor jugs.
Brian Perkins                                bperkins-ooduxAEi7gVg9hUCZPvPmw@public.gmane.org


-------------------------------------------------------
This SF.net email is sponsored by:
The Definitive IT and Networking Event. Be There!
NetWorld+Interop Las Vegas 2003 -- Register today!
http://ads.sourceforge.net/cgi-bin/redirect.pl?keyn0001en

Re: [20030321] Failed to acquire semaphore

[Karol Kozimor]

Thus wrote Grover, Andrew:
> Hiya -- can you (or someone else experiencing the same problem - I know
> there are a few) stick a WARN_ON(1) where that error message is
> happening, and turn on CONFIG_KALLSYMS, so we can get a stack trace?

Sure, here it goes (WARN_ONs inserted before the coresponding functions):
#v+
Badness in acpi_os_wait_semaphore at drivers/acpi/osl.c:896
Call Trace:
 [<c01e6c8d>] acpi_os_wait_semaphore+0x10c/0x1de
 [<c020ae4a>] acpi_ut_acquire_mutex+0x94/0x18c
 [<c0209b9e>] acpi_ut_trace+0x28/0x2c
 [<c01ee2b2>] acpi_disable_gpe+0x31/0xa2
 [<c021190d>] acpi_ec_gpe_handler+0x15/0x27
 [<c01f030b>] acpi_ev_gpe_dispatch+0x19e/0x1df
 [<c01f0038>] acpi_ev_gpe_detect+0x174/0x17c
 [<c01edd43>] acpi_ev_sci_xrupt_handler+0x37/0x4d
 [<c01e6276>] acpi_irq+0xc/0xe
 [<c010a6aa>] handle_IRQ_event+0x38/0x5c
 [<c01e626a>] acpi_irq+0x0/0xe
 [<c010a81c>] do_IRQ+0x72/0xc8
 [<c0109148>] common_interrupt+0x18/0x20
 [<c01e63e3>] acpi_os_write_port+0x2d/0x47
 [<c01fab76>] acpi_hw_low_level_write+0xef/0xf9
 [<c020ae76>] acpi_ut_acquire_mutex+0xc0/0x18c
 [<c01f9c8b>] acpi_hw_enable_gpe+0x43/0x48
 [<c01ee14f>] acpi_enable_gpe+0x71/0xa7
 [<c0211895>] acpi_ec_gpe_query+0xbf/0x122
 [<c01e6763>] acpi_os_execute_deferred+0x39/0x75
 [<c0127907>] worker_thread+0x1a4/0x262
 [<c01e672a>] acpi_os_execute_deferred+0x0/0x75
 [<c0118364>] default_wake_function+0x0/0x12
 [<c0108eee>] ret_from_fork+0x6/0x14
 [<c0118364>] default_wake_function+0x0/0x12
 [<c0127763>] worker_thread+0x0/0x262
 [<c010720d>] kernel_thread_helper+0x5/0xb

     osl-0898 [24] os_wait_semaphore     : Failed to acquire semaphore[cffec740|1|0], AE_TIME
Badness in acpi_ut_acquire_mutex at drivers/acpi/utilities/utmisc.c:741
Call Trace:
 [<c020aeaa>] acpi_ut_acquire_mutex+0xf4/0x18c
 [<c0209b9e>] acpi_ut_trace+0x28/0x2c
 [<c01ee2b2>] acpi_disable_gpe+0x31/0xa2
 [<c021190d>] acpi_ec_gpe_handler+0x15/0x27
 [<c01f030b>] acpi_ev_gpe_dispatch+0x19e/0x1df
 [<c01f0038>] acpi_ev_gpe_detect+0x174/0x17c
 [<c01edd43>] acpi_ev_sci_xrupt_handler+0x37/0x4d
 [<c01e6276>] acpi_irq+0xc/0xe
 [<c010a6aa>] handle_IRQ_event+0x38/0x5c
 [<c01e626a>] acpi_irq+0x0/0xe
 [<c010a81c>] do_IRQ+0x72/0xc8
 [<c0109148>] common_interrupt+0x18/0x20
 [<c01e63e3>] acpi_os_write_port+0x2d/0x47
 [<c01fab76>] acpi_hw_low_level_write+0xef/0xf9
 [<c020ae76>] acpi_ut_acquire_mutex+0xc0/0x18c
 [<c01f9c8b>] acpi_hw_enable_gpe+0x43/0x48
 [<c01ee14f>] acpi_enable_gpe+0x71/0xa7
 [<c0211895>] acpi_ec_gpe_query+0xbf/0x122
 [<c01e6763>] acpi_os_execute_deferred+0x39/0x75
 [<c0127907>] worker_thread+0x1a4/0x262
 [<c01e672a>] acpi_os_execute_deferred+0x0/0x75
 [<c0118364>] default_wake_function+0x0/0x12
 [<c0108eee>] ret_from_fork+0x6/0x14
 [<c0118364>] default_wake_function+0x0/0x12
 [<c0127763>] worker_thread+0x0/0x262
 [<c010720d>] kernel_thread_helper+0x5/0xb

  utmisc-0744 [23] ut_acquire_mutex      : Thread 0 could not acquire Mutex [ACPI_MTX_Events] AE_TIME
#v-

As I said, it happens both on 2.4.21-pre5-acpi20030321, and 
2.5.65-acpi20030321. It doesn't neither on vanilla 2.5.65 (but there's the 
GPE bug), nor on acpi20021212. HTH.
Best regards,

-- 
Karol 'sziwan' Kozimor
sziwan-DETuoxkZsSqrDJvtcaxF/A@public.gmane.org


-------------------------------------------------------
This SF.net email is sponsored by:
The Definitive IT and Networking Event. Be There!
NetWorld+Interop Las Vegas 2003 -- Register today!
http://ads.sourceforge.net/cgi-bin/redirect.pl?keyn0001en

RE: [20030321] Failed to acquire semaphore

[Moore, Robert]

Thanks.

We understand what the problem is and we are working to fix it.  In the
meantime, it doesn't cause any issues other than a flurry of messages on
machines that use the EC heavily.

Bob


> -----Original Message-----
> From: bperkins-ooduxAEi7gVg9hUCZPvPmw@public.gmane.org [mailto:bperkins@netspace.org]
> Sent: Tuesday, March 25, 2003 1:53 PM
> To: acpi-devel-5NWGOfrQmneRv+LV9MX5uipxlwaOVQ5f@public.gmane.org
> Cc: Grover, Andrew
> Subject: Re: [ACPI] [20030321] Failed to acquire semaphore
> 
> Here's the stack trace from the error on bootup.
> It's exaclty the same if I push a button, close a lid, chnage
> brightness, etc.
> 
> 
> Badness in acpi_os_wait_semaphore at drivers/acpi/osl.c:911
> Call Trace:
>  [<c0223a03>] acpi_os_wait_semaphore+0x125/0x20a
>  [<c02470f4>] acpi_ut_acquire_mutex+0x92/0x164
>  [<c022ad37>] acpi_disable_gpe+0x33/0x96
>  [<c024cf63>] acpi_ec_gpe_handler+0x17/0x2a
>  [<c022cc9d>] acpi_ev_gpe_dispatch+0x18f/0x1d0
>  [<c022c9e6>] acpi_ev_gpe_detect+0x168/0x170
>  [<c022a7e8>] acpi_ev_sci_xrupt_handler+0x38/0x50
>  [<c0222f91>] acpi_irq+0xf/0x12
>  [<c010b595>] handle_IRQ_event+0x37/0x5e
>  [<c0222f82>] acpi_irq+0x0/0x12
>  [<c010b7ff>] do_IRQ+0xc5/0x184
>  [<c0109d9c>] common_interrupt+0x18/0x20
>  [<c0223116>] acpi_os_write_port+0x2e/0x46
>  [<c0237150>] acpi_hw_low_level_write+0xe6/0xee
>  [<c0247120>] acpi_ut_acquire_mutex+0xbe/0x164
>  [<c02362b5>] acpi_hw_enable_gpe+0x45/0x48
>  [<c022abe3>] acpi_enable_gpe+0x6f/0x9c
>  [<c024ced8>] acpi_ec_gpe_query+0xce/0x142
>  [<c022346c>] acpi_os_execute_deferred+0x3a/0x6c
>  [<c012f2cf>] worker_thread+0x1f9/0x2f4
>  [<c0223432>] acpi_os_execute_deferred+0x0/0x6c
>  [<c011b88a>] default_wake_function+0x0/0x12
>  [<c0109306>] ret_from_fork+0x6/0x14
>  [<c011b88a>] default_wake_function+0x0/0x12
>  [<c012f0d6>] worker_thread+0x0/0x2f4
>  [<c01072f1>] kernel_thread_helper+0x5/0xc
> 
>      osl-0913 [31] os_wait_semaphore     : Failed to acquire
> semaphore[cff62580|1|0], AE_TIME
>   utmisc-0743 [30] ut_acquire_mutex      : Thread 0 could not acquire
> Mutex [ACPI_MTX_Events] AE_TIME
> 
> 
> --
> Pack my box with five dozen liquor jugs.
> Brian Perkins                                bperkins-ooduxAEi7gVg9hUCZPvPmw@public.gmane.org
> 
> 
> -------------------------------------------------------
> This SF.net email is sponsored by:
> The Definitive IT and Networking Event. Be There!
> NetWorld+Interop Las Vegas 2003 -- Register today!
> http://ads.sourceforge.net/cgi-bin/redirect.pl?keyn0001en
> _______________________________________________
> Acpi-devel mailing list
> Acpi-devel-5NWGOfrQmneRv+LV9MX5uipxlwaOVQ5f@public.gmane.org
> https://lists.sourceforge.net/lists/listinfo/acpi-devel


-------------------------------------------------------
This SF.net email is sponsored by:
The Definitive IT and Networking Event. Be There!
NetWorld+Interop Las Vegas 2003 -- Register today!
http://ads.sourceforge.net/cgi-bin/redirect.pl?keyn0001en

Re: [20030321] Failed to acquire semaphore

[Karol Kozimor]

Thus wrote Moore, Robert:
> We understand what the problem is and we are working to fix it.  In the
> meantime, it doesn't cause any issues other than a flurry of messages on
> machines that use the EC heavily.

Well, it depends what do you mean by an "issue". On my machine, this
prevents the acpid from noticing any events / notifies. While I agree that 
it is not critical, yet it's certainly not a case of only generating
messages. Yet thank you very much for showing interest in that :)
Best regards,

-- 
Karol 'sziwan' Kozimor
sziwan-DETuoxkZsSqrDJvtcaxF/A@public.gmane.org


-------------------------------------------------------
This SF.net email is sponsored by:
The Definitive IT and Networking Event. Be There!
NetWorld+Interop Las Vegas 2003 -- Register today!
http://ads.sourceforge.net/cgi-bin/redirect.pl?keyn0001en