Bug 48221 - EC: input buffer is not empty, aborting transaction
EC: input buffer is not empty, aborting transaction
Status: CLOSED DUPLICATE of bug 14733
Product: ACPI
Classification: Unclassified
Component: EC
All Linux
: P1 normal
Assigned To: Lan Tianyu
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2012-10-02 22:43 UTC by Martin Wildam
Modified: 2013-04-13 03:31 UTC (History)
4 users (show)

See Also:
Kernel Version: 3.4.0-030400 - 3.6.0-030600
Tree: Mainline
Regression: Yes


Attachments
syslog cold boot (212.35 KB, application/zip)
2012-10-02 22:43 UTC, Martin Wildam
Details
lshw output on Dell Latitude E6530 (14.98 KB, text/plain)
2012-10-02 22:44 UTC, Martin Wildam
Details
several logs of booting kernel 3.6 attached (208.33 KB, application/zip)
2012-10-10 19:31 UTC, Martin Wildam
Details
cold boot kernel 3.4 logs including acpidump (299.55 KB, application/zip)
2012-10-16 17:05 UTC, Martin Wildam
Details
dmesg output in 3.8.5 after applying patch in comment 19 (120.23 KB, application/octet-stream)
2013-04-11 13:52 UTC, Jean-Christophe Dubacq
Details

Description Martin Wildam 2012-10-02 22:43:13 UTC
Created attachment 81861 [details]
syslog cold boot

This error in my syslog on Ubuntu 12.04 using the kernel 3.6 quantal build (did not build the kernel myself) is new with the 3.6 release (does not happen on 3.5.5):

ACPI: EC: input buffer is not empty, aborting transaction
ACPI Exception: AE_TIME, Returned by Handler for [EmbeddedControl] (20120711/evregion-501)
ACPI Error: Method parse/execution failed [\_SB_.PCI0.LPCB.ECDV.ECR1] (Node ffff88040bc6db68), AE_TIME (20120711/psparse-536)
ACPI Error: Method parse/execution failed [\ECRB] (Node ffff88040bc6dcd0), AE_TIME (20120711/psparse-536)
ACPI Error: Method parse/execution failed [\ECGB] (Node ffff88040bc6dfa0), AE_TIME (20120711/psparse-536)
ACPI Error: Method parse/execution failed [\_SB_.PCI0.VID_.LCD_._ADR] (Node ffff88040bc69488), AE_TIME (20120711/psparse-536)
cfg80211: Ignoring regulatory request Set by core since the driver uses its own custom regulatory domain

Processor temperature is 44-45°C, room temperature is about 22°C.
load average: 0.28, 0.40, 0.50
Currently running on battery.
Comment 1 Martin Wildam 2012-10-02 22:44:44 UTC
Created attachment 81871 [details]
lshw output on Dell Latitude E6530

BTW: I am on a Dell Latitude E6530
Comment 2 Len Brown 2012-10-09 02:17:14 UTC
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
Comment 3 Martin Wildam 2012-10-10 19:24:42 UTC
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.
Comment 4 Martin Wildam 2012-10-10 19:29:38 UTC
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.
Comment 5 Martin Wildam 2012-10-10 19:31:29 UTC
Created attachment 82831 [details]
several logs of booting kernel 3.6 attached

Sample log set experiencing the error message on kernel 3.6 boot.
Comment 6 Martin Wildam 2012-10-16 17:04:11 UTC
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.
Comment 7 Martin Wildam 2012-10-16 17:05:10 UTC
Created attachment 83681 [details]
cold boot kernel 3.4 logs including acpidump

This time acpidump included also.
Comment 8 Jean-Christophe Dubacq 2013-04-01 19:02:25 UTC
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.
Comment 9 Lan Tianyu 2013-04-08 08:54:39 UTC
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)
Comment 10 Jean-Christophe Dubacq 2013-04-09 10:00:21 UTC
Currently compiling. I'll report back as soon as it is tested.
Comment 11 Jean-Christophe Dubacq 2013-04-09 13:52:20 UTC
Done. Rebooted, nice battery icon in my display. So the patch works, apparently. Do you need some more tests ?
Comment 12 Lan Tianyu 2013-04-09 14:00:22 UTC
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 */
Comment 13 Jean-Christophe Dubacq 2013-04-09 16:01:47 UTC
(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.
Comment 14 Jean-Christophe Dubacq 2013-04-09 18:17:50 UTC
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!
Comment 15 Lan Tianyu 2013-04-10 05:08:48 UTC
Please try the first one. Thanks.
Comment 16 Lan Tianyu 2013-04-10 05:13:04 UTC
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.
Comment 17 Jean-Christophe Dubacq 2013-04-10 06:49:48 UTC
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.
Comment 18 Lan Tianyu 2013-04-10 06:52:27 UTC
:) No, problem. Thanks a lot for your test.
Comment 19 Lan Tianyu 2013-04-11 04:11:32 UTC
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>
Comment 20 Jean-Christophe Dubacq 2013-04-11 05:49:50 UTC
Sorry for the delay. I will test patch in comment #19 today... The patch #1 in comment 12 did not work. Patch #2 worked.
Comment 21 Jean-Christophe Dubacq 2013-04-11 13:52:17 UTC
Created attachment 98121 [details]
dmesg output in 3.8.5 after applying patch in comment 19
Comment 22 Jean-Christophe Dubacq 2013-04-11 13:53:05 UTC
(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.
Comment 23 Lan Tianyu 2013-04-12 01:27:09 UTC
OK. Thanks for test. I will upstream the patch as soon as possible. Mark this bug resolved as code_fix.
Comment 24 Lan Tianyu 2013-04-12 02:52:54 UTC
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 ***

Note You need to log in before you can comment on or make changes to this bug.