Bug 48221

Created attachment 81871 [details]
lshw output on Dell Latitude E6530

BTW: I am on a Dell Latitude E6530

There are no changes to drivers/acpi/ec.c
between Linux-3.5 and Linux-3.6.
So possibly this issue is a result of a change
in the ACPICA core?

Please attach the output from acpidump

After a lot of boots I had this at startup on kernel 3.4 also. Maybe a problem during startup process because of timing issues and hence occurs more often on kernel 3.5 and later.

No, forget it, it's kernel 3.6 (did choose the wrong kernel on boot - checked kernel version). Booted a lot of times the 3.4 kernel during the last days and never had this message at boot. Once 3.6 and immediately shows up.

Created attachment 82831 [details]
several logs of booting kernel 3.6 attached

Sample log set experiencing the error message on kernel 3.6 boot.

Finally on a cold boot with kernel 3.4 (this time really) I got the same error. I imagine it could be a timing issue at boot that just far more probably occurs on 3.6 kernel than on 3.4.

Created attachment 83681 [details]
cold boot kernel 3.4 logs including acpidump

This time acpidump included also.

I have probably the same problem with a DELL latitude 5530 and the 3.8 kernel in debian experimental (linux-image-3.8-trunk-amd64).

When booting in 3.8 mode, /sys/class/power lists:
lrwxrwxrwx 1 root root 0 Apr  1 20:37 AC -> ../../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0003:00/power_supply/AC


When booting in 3.2 mode (debian testing-soon-stable):
lrwxrwxrwx 1 root root 0 Apr  1 20:40 AC -> ../../devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0003:00/power_supply/AC
lrwxrwxrwx 1 root root 0 Apr  1 20:40 BAT0 -> ../../devices/LNXSYSTM:00/LNXSYBUS:00/PNP0C0A:00/power_supply/BAT0


I have dmesg for both boots and acpidump too, if needed.
(acpidump is the same in both modes)

The diff between 3.8 dmesg (-) and 3.2 dmesg (+) shows (related to ACPI):

 ACPI: RSDP 00000000000f0490 00024 (v02 DELL  )
 ACPI: XSDT 00000000d6ff3080 0007C (v01 DELL    CBX3    01072009 AMI  00010013)
 ACPI: FACP 00000000d6ffd5d0 0010C (v05 DELL    CBX3    01072009 AMI  00010013)
+ACPI Warning: FADT (revision 5) is longer than ACPI 2.0 version, truncating length 268 to 244 (20110623/tbfadt-288)
 ACPI: DSDT 00000000d6ff3188 0A448 (v02 DELL    CBX3    00000021 INTL 20091112)
 ACPI: FACS 00000000d87fe080 00040
 ACPI: APIC 00000000d6ffd6e0 00072 (v03 DELL    CBX3    01072009 AMI  00010013)


-ACPI: Core revision 20121018
+ACPI: Core revision 20110623


-pci 0000:00:1c.6: PCI bridge to [bus 0c]
+pci 0000:00:1c.6: PCI bridge to [bus 0c-0c]
 pci 0000:00:1c.6:   bridge window [mem 0xf7c00000-0xf7cfffff]
+ACPI: PCI Interrupt Routing Table [\_SB_.PCI0._PRT]
 ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.RP01._PRT]
 ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.RP02._PRT]
 ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.RP06._PRT]
 ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.RP07._PRT]
 ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.RP03._PRT]
 ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.RP04._PRT]



-thermal LNXTHERM:00: registered as thermal_zone0
-ACPI: Thermal Zone [THM] (47 C)
-hub 4-0:1.0: USB hub found
-hub 4-0:1.0: 2 ports detected
+hub 2-0:1.0: 2 ports detected
 ahci 0000:00:1f.2: version 3.0
-ahci 0000:00:1f.2: irq 41 for MSI/MSI-X
+ahci 0000:00:1f.2: irq 40 for MSI/MSI-X
 ahci: SSS flag set, parallel bus scan disabled
 ahci 0000:00:1f.2: AHCI 0001.0300 32 slots 6 ports 6 Gbps 0x33 impl SATA mode
 ahci 0000:00:1f.2: flags: 64bit ncq stag pm led clo pio slum part ems sxs apst 
 ahci 0000:00:1f.2: setting latency timer to 64
+thermal LNXTHERM:00: registered as thermal_zone0
+ACPI: Thermal Zone [THM] (49 C)
 scsi0 : ahci
 scsi1 : ahci


...and various other things. When ACPI starts seriously we have:


-ACPI Error: [DCK9] Namespace lookup failure, AE_ALREADY_EXISTS (20121018/dswload2-330)
-ACPI Exception: AE_ALREADY_EXISTS, During name lookup/catalog (20121018/psloop-259)
-ACPI Error: Method parse/execution failed [\_SB_.PCI0.LPCB.LPTE.CLPS] (Node ffff880215491c18), AE_ALREADY_EXISTS (20121018/psparse-537)
-ACPI Error: Method parse/execution failed [\_SB_.PCI0.LPCB.LPTE._STA] (Node ffff880215491bf0), AE_ALREADY_EXISTS (20121018/psparse-537)
-ACPI Error: Method execution failed [\_SB_.PCI0.LPCB.LPTE._STA] (Node ffff880215491bf0), AE_ALREADY_EXISTS (20121018/uteval-103)


in the 3.8 kernel, which we don't have in the 3.2.

What can I do to help?

Sincerly,

PS: this laptop is not yet used for real serious work, so I can test many things for now without disrupting my main work. This may not be the case later.

Could you try the following patch?


--- drivers/acpi/ec.c    2011-01-05 01:50:19.000000000 +0100
+++ drivers/acpi/ec.c    2011-01-10 15:55:23.000000000 +0100
@@ -223,6 +223,7 @@
                 if (ec_transaction_done(ec))
                     return 0;
             } else {
+                msleep(1);
                 if (wait_event_timeout(ec->wait,
                         ec_transaction_done(ec),
                         msecs_to_jiffies(1)))
@@ -230,8 +231,8 @@
             }
             advance_transaction(ec, acpi_ec_read_status(ec));
         } while (time_before(jiffies, delay));
-        if (acpi_ec_read_status(ec) & ACPI_EC_FLAG_IBF)
-            break;
+//        if (acpi_ec_read_status(ec) & ACPI_EC_FLAG_IBF)
+//            break;
         pr_debug(PREFIX "controller reset, restart transaction\n");
         spin_lock_irqsave(&ec->curr_lock, flags);
         start_transaction(ec);
@@ -268,6 +269,15 @@
     return (status & ACPI_EC_FLAG_IBF) == 0;
 }

+/* try to clean input buffer with burst_disable transaction */
+static int acpi_ec_clean_buffer(struct acpi_ec *ec)
+{
+    struct transaction t = {.command = ACPI_EC_BURST_DISABLE,
+                .wdata = NULL, .rdata = NULL,
+                .wlen = 0, .rlen = 0};
+    return acpi_ec_transaction_unlocked(ec, &t);
+}
+
 static int ec_wait_ibf0(struct acpi_ec *ec)
 {
     unsigned long delay = jiffies + msecs_to_jiffies(ec_delay);
@@ -276,7 +286,8 @@
         if (wait_event_timeout(ec->wait, ec_check_ibf0(ec),
                     msecs_to_jiffies(1)))
             return 0;
-    return -ETIME;
+//    return -ETIME;
+    return acpi_ec_clean_buffer(ec);
 }

 static int acpi_ec_transaction(struct acpi_ec *ec, struct transaction *t)

Currently compiling. I'll report back as soon as it is tested.

Done. Rebooted, nice battery icon in my display. So the patch works, apparently. Do you need some more tests ?

Great. Thanks for your test. I'd like to find more better way.

How about the followling two patches.
(1)
diff --git a/drivers/acpi/ec.c b/drivers/acpi/ec.c
index 57c676a..d74fc63 100644
--- a/drivers/acpi/ec.c
+++ b/drivers/acpi/ec.c
@@ -666,16 +666,16 @@ acpi_ec_space_handler(u32 function, acpi_physical_address
address,
        if (function != ACPI_READ && function != ACPI_WRITE)
                return AE_BAD_PARAMETER;

-       if (EC_FLAGS_MSI || bits > 8)
-               acpi_ec_burst_enable(ec);
+//     if (EC_FLAGS_MSI || bits > 8)
+//             acpi_ec_burst_enable(ec);

        for (i = 0; i < bytes; ++i, ++address, ++value)
                result = (function == ACPI_READ) ?
                        acpi_ec_read(ec, address, value) :
                        acpi_ec_write(ec, address, *value);

-       if (EC_FLAGS_MSI || bits > 8)
-               acpi_ec_burst_disable(ec);
+//     if (EC_FLAGS_MSI || bits > 8)
+//             acpi_ec_burst_disable(ec);

        switch (result) {
        case -EINVAL:

(2)
diff --git a/drivers/acpi/ec.c b/drivers/acpi/ec.c
index 57c676a..12aea77 100644
--- a/drivers/acpi/ec.c
+++ b/drivers/acpi/ec.c
@@ -124,7 +124,7 @@ struct transaction {
 struct acpi_ec *boot_ec, *first_ec;
 EXPORT_SYMBOL(first_ec);

-static int EC_FLAGS_MSI; /* Out-of-spec MSI controller */
+static int EC_FLAGS_MSI = 1; /* Out-of-spec MSI controller */
 static int EC_FLAGS_VALIDATE_ECDT; /* ASUStec ECDTs need to be validated */
 static int EC_FLAGS_SKIP_DSDT_SCAN; /* Not all BIOS survive early DSDT scan */

(In reply to comment #12)
> Great. Thanks for your test. I'd like to find more better way.
> 
> How about the followling two patches.

I suppose this is not in addition to the previous one (in https://bugzilla.kernel.org/show_bug.cgi?id=48221#c9). I will launch a recompile, and test later tonight.

If this was a patch to be added on top of the previous one, just say it.

Tested patch #2 first (just changing default value of EC_FLAGS_MSI). It works (after the patch in comment #9, I had trouble having a reliable wifi connection, but it probably came from something else). So here I am, posting from a 2.38.5 with a nice battery display. There are still two ACPI errors flashing at boot (but they do not prevent the battery from being detected, apparently).

Here are the two messages flashing by (retrieved through dmesg):

[    4.633536] ACPI: EC: input buffer is not empty, aborting transaction
[    4.633638] ACPI Exception: AE_TIME, Returned by Handler for [EmbeddedControl] (20121018/evregion-501)
[    4.633652] ACPI Error: Method parse/execution failed [\_SB_.PCI0.LPCB.ECDV.ECR1] (Node ffff88021548f650), AE_TIME (20121018/psparse-537)
[    4.633668] ACPI Error: Method parse/execution failed [\ECRB] (Node ffff88021548f4e8), AE_TIME (20121018/psparse-537)
[    4.633678] ACPI Error: Method parse/execution failed [\ECG5] (Node ffff88021548f380), AE_TIME (20121018/psparse-537)
[    4.633688] ACPI Error: Method parse/execution failed [\_SB_.AC__._PSR] (Node ffff88021548fb00), AE_TIME (20121018/psparse-537)
[    4.633707] ACPI Exception: AE_TIME, Error reading AC Adapter state (20121018/ac-122)
[    6.234267] ACPI: EC: input buffer is not empty, aborting transaction
[    6.234371] ACPI Exception: AE_TIME, Returned by Handler for [EmbeddedControl] (20121018/evregion-501)
[    6.234387] ACPI Error: Method parse/execution failed [\_SB_.PCI0.LPCB.ECDV.ECR1] (Node ffff88021548f650), AE_TIME (20121018/psparse-537)
[    6.234401] ACPI Error: Method parse/execution failed [\ECRB] (Node ffff88021548f4e8), AE_TIME (20121018/psparse-537)
[    6.234409] ACPI Error: Method parse/execution failed [\ECGB] (Node ffff88021548f1c8), AE_TIME (20121018/psparse-537)
[    6.234418] ACPI Error: Method parse/execution failed [\_SB_.PCI0.VID_._DOD] (Node ffff88021548a308), AE_TIME (20121018/psparse-537)
[    6.234436] ACPI Exception: AE_TIME, Evaluating _DOD (20121018/video-1163)


Should I also test patch #1, since #2 works? I have the impression that #1 was more blunt than #2.

Thanks anyway!

Please try the first one. Thanks.

Could you test on the stalbe 3.8 or v3.9-rcX? Since there is a big gap between 2.38.5 and v3.9-rcX.

My (In reply to comment #16)
> Could you test on the stalbe 3.8 or v3.9-rcX? Since there is a big gap
> between
> 2.38.5 and v3.9-rcX.

My bad. It was 3.8.5, no 2.38.5 (too many years of Linux kernels beginning by 2.something, it's a habit difficult to lose).

I will test patch number 1 today on 3.8.5.

:) No, problem. Thanks a lot for your test.

Hi, Sorry please ignore previous patch. I find this bug is as same as bug 14733.
I have wrote a debug patch and pass through test. So please try the follow patch. and attach the dmesg with ec debug open.

diff --git a/drivers/acpi/ec.c b/drivers/acpi/ec.c
index d45b287..6376fd2 100644
--- a/drivers/acpi/ec.c
+++ b/drivers/acpi/ec.c
@@ -223,7 +223,7 @@ static int ec_check_sci_sync(struct acpi_ec *ec, u8 state)
 static int ec_poll(struct acpi_ec *ec)
 {
        unsigned long flags;
-       int repeat = 2; /* number of command restarts */
+       int repeat = 4; /* number of command restarts */
        while (repeat--) {
                unsigned long delay = jiffies +
                        msecs_to_jiffies(ec_delay);
@@ -241,8 +241,10 @@ static int ec_poll(struct acpi_ec *ec)
                        }
                        advance_transaction(ec, acpi_ec_read_status(ec));
                } while (time_before(jiffies, delay));
-               if (acpi_ec_read_status(ec) & ACPI_EC_FLAG_IBF)
-                       break;
+
+               //if (acpi_ec_read_status(ec) & ACPI_EC_FLAG_IBF)
+               //      break;
+               pr_info(PREFIX "%s: repeat %d \n", __func__, 4 - repeat);
                pr_debug(PREFIX "controller reset, restart transaction\n");
                spin_lock_irqsave(&ec->lock, flags);
                start_transaction(ec);


Open ec debug patch.
diff --git a/drivers/acpi/ec.c b/drivers/acpi/ec.c
index d45b287..34189f4 100644
--- a/drivers/acpi/ec.c
+++ b/drivers/acpi/ec.c
@@ -27,7 +27,7 @@
  */
 
 /* Uncomment next line to get verbose printout */
-/* #define DEBUG */
+#define DEBUG
 
 #include <linux/kernel.h>
 #include <linux/module.h>

Sorry for the delay. I will test patch in comment #19 today... The patch #1 in comment 12 did not work. Patch #2 worked.

Created attachment 98121 [details]
dmesg output in 3.8.5 after applying patch in comment 19

(In reply to comment #21)
> Created an attachment (id=98121) [details]
> dmesg output in 3.8.5 after applying patch in comment 19

And the battery is detected with this patch.

OK. Thanks for test. I will upstream the patch as soon as possible. Mark this bug resolved as code_fix.

The bug is as same as 14733 but on the different machine so mark it duplicate at first will be more reasonable. Sorry for noise.

*** This bug has been marked as a duplicate of bug 14733 ***