Bug 15106 - kacpi_notify_wq and kacpi_wq use a lot of cpu - hp-compaq 610 laptop
Summary: kacpi_notify_wq and kacpi_wq use a lot of cpu - hp-compaq 610 laptop
Status: REJECTED UNREPRODUCIBLE
Alias: None
Product: ACPI
Classification: Unclassified
Component: EC (show other bugs)
Hardware: All Linux
: P1 normal
Assignee: acpi_ec
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2010-01-22 19:11 UTC by Ali Gholami Rudi
Modified: 2011-03-21 07:48 UTC (History)
3 users (show)

See Also:
Kernel Version: 2.6.32-rc5
Subsystem:
Regression: No
Bisected commit-id:


Attachments
acpidump output (372.09 KB, application/octet-stream)
2010-01-22 19:49 UTC, Ali Gholami Rudi
Details

Description Ali Gholami Rudi 2010-01-22 19:11:14 UTC
Sometimes kacpi_notify_wq and kacpid_wq workqueues use a lot of cpu.

I'm using yesterday's tip on a hp-compaq 610 laptop.  At times
kacpi_notify_wq uses 30-50% of my cpu and kacpid_wq uses 3-5%:

# uptime
 12:49:54 up  4:16,  1 user,  load average: 0.52, 0.55, 0.40
# ps -e | grep kacpi
  189 ?        00:00:52 kacpid
  190 ?        00:10:26 kacpi_notify
  191 ?        00:00:00 kacpi_hotplug

This sometimes happens after a few hours of uptime; so this is
very hard to bisect (by the way, I think the same thing causes
the fans to work fullspeed sometimes when I reboot the machine).
I tried this patch to find out which of the callers of
acpi_os_execute() is the culprit:

=== patch ====
diff --git a/drivers/acpi/acpica/evgpe.c b/drivers/acpi/acpica/evgpe.c
index afacf44..eded044 100644
--- a/drivers/acpi/acpica/evgpe.c
+++ b/drivers/acpi/acpica/evgpe.c
@@ -504,6 +504,7 @@ static void ACPI_SYSTEM_XFACE acpi_ev_asynch_execute_gpe_method(void *context)
 	acpi_status status;
 	struct acpi_gpe_event_info local_gpe_event_info;
 	struct acpi_evaluate_info *info;
+	printk("acpi_ev_asynch_execute_gpe_method\n");
 
 	ACPI_FUNCTION_TRACE(ev_asynch_execute_gpe_method);
 
@@ -577,6 +578,7 @@ static void ACPI_SYSTEM_XFACE acpi_ev_asynch_execute_gpe_method(void *context)
 static void acpi_ev_asynch_enable_gpe(void *context)
 {
 	struct acpi_gpe_event_info *gpe_event_info = context;
+	printk("acpi_ev_asynch_enable_gpe\n");
 	acpi_status status;
 	if ((gpe_event_info->flags & ACPI_GPE_XRUPT_TYPE_MASK) ==
 	    ACPI_GPE_LEVEL_TRIGGERED) {
diff --git a/drivers/acpi/acpica/evmisc.c b/drivers/acpi/acpica/evmisc.c
index ce224e1..e2307d1 100644
--- a/drivers/acpi/acpica/evmisc.c
+++ b/drivers/acpi/acpica/evmisc.c
@@ -224,6 +224,7 @@ static void ACPI_SYSTEM_XFACE acpi_ev_notify_dispatch(void *context)
 	acpi_notify_handler global_handler = NULL;
 	void *global_context = NULL;
 	union acpi_operand_object *handler_obj;
+	printk("acpi_ev_notify_dispatch\n");
 
 	ACPI_FUNCTION_ENTRY();
 
diff --git a/drivers/acpi/ec.c b/drivers/acpi/ec.c
index fd1801b..f3d8cc1 100644
--- a/drivers/acpi/ec.c
+++ b/drivers/acpi/ec.c
@@ -514,6 +514,7 @@ static void acpi_ec_gpe_query(void *ec_cxt)
 	struct acpi_ec *ec = ec_cxt;
 	u8 value = 0;
 	struct acpi_ec_query_handler *handler, copy;
+	printk("acpi_ec_gpe_query\n");
 
 	if (!ec || acpi_ec_query(ec, &value))
 		return;
diff --git a/drivers/acpi/sbshc.c b/drivers/acpi/sbshc.c
index d933980..99f39db 100644
--- a/drivers/acpi/sbshc.c
+++ b/drivers/acpi/sbshc.c
@@ -217,6 +217,7 @@ EXPORT_SYMBOL_GPL(acpi_smbus_unregister_callback);
 static inline void acpi_smbus_callback(void *context)
 {
 	struct acpi_smb_hc *hc = context;
+	printk("acpi_smbus_callback\n");
 	if (hc->callback)
 		hc->callback(hc->context);
 }
=== patch ====

This was produced when the kacpi_notify high cpu usage happened:

=== dmesg ====
...
[12786.473794] acpi_ev_asynch_enable_gpe
[12786.473803] acpi_ev_notify_dispatch
[12786.476741] acpi_ev_asynch_execute_gpe_method
[12786.477109] acpi_ev_notify_dispatch
[12786.482973] acpi_ev_asynch_enable_gpe
[12786.482982] acpi_ev_notify_dispatch
[12786.483033] acpi_ev_asynch_execute_gpe_method
[12786.489049] acpi_ev_notify_dispatch
[12786.494038] acpi_ev_asynch_enable_gpe
[12786.494083] acpi_ev_asynch_execute_gpe_method
[12786.494434] acpi_ev_notify_dispatch
[12786.496798] acpi_ev_asynch_enable_gpe
[12786.496845] acpi_ev_asynch_execute_gpe_method
[12786.497210] acpi_ev_notify_dispatch
[12786.503034] acpi_ev_asynch_enable_gpe
[12786.503043] acpi_ev_notify_dispatch
[12786.504363] acpi_ev_asynch_execute_gpe_method
[12786.505198] acpi_ev_notify_dispatch
[12786.511051] acpi_ev_asynch_enable_gpe
[12786.511093] acpi_ev_notify_dispatch
[12786.511100] acpi_ev_asynch_execute_gpe_method
[12786.517091] acpi_ev_notify_dispatch
[12786.518697] acpi_ev_asynch_enable_gpe
[12786.518706] acpi_ev_notify_dispatch
[12786.524051] acpi_ev_asynch_execute_gpe_method
[12786.524409] acpi_ev_notify_dispatch
[12786.530079] acpi_ev_asynch_enable_gpe
[12786.530089] acpi_ev_notify_dispatch
[12786.530128] acpi_ev_asynch_execute_gpe_method
[12786.536094] acpi_ev_notify_dispatch
[12786.537761] acpi_ev_asynch_enable_gpe
[12786.537770] acpi_ev_notify_dispatch
[12786.537936] acpi_ev_asynch_execute_gpe_method
[12786.543131] acpi_ev_notify_dispatch
[12786.545642] acpi_ev_asynch_enable_gpe
[12786.545651] acpi_ev_notify_dispatch
[12786.545692] acpi_ev_asynch_execute_gpe_method
[12786.552133] acpi_ev_notify_dispatch
[12786.557167] acpi_ev_asynch_enable_gpe
[12786.557176] acpi_ev_notify_dispatch
[12786.557215] acpi_ev_asynch_execute_gpe_method
[12786.560062] acpi_ev_notify_dispatch
[12786.565185] acpi_ev_asynch_enable_gpe
[12786.565227] acpi_ev_notify_dispatch
[12786.565234] acpi_ev_asynch_execute_gpe_method
[12786.571202] acpi_ev_notify_dispatch
[12786.572811] acpi_ev_asynch_enable_gpe
[12786.575307] acpi_ev_asynch_execute_gpe_method
[12786.575664] acpi_ev_notify_dispatch
[12786.581250] acpi_ev_asynch_enable_gpe
[12786.581260] acpi_ev_notify_dispatch
[12786.581307] acpi_ev_asynch_execute_gpe_method
[12786.587251] acpi_ev_notify_dispatch
[12786.588854] acpi_ev_asynch_enable_gpe
[12786.588863] acpi_ev_notify_dispatch
[12786.822334] acpi_ev_asynch_execute_gpe_method
[12786.822710] acpi_ev_notify_dispatch
[12786.828829] acpi_ev_asynch_enable_gpe
[12786.828838] acpi_ev_notify_dispatch
[12786.828881] acpi_ev_asynch_execute_gpe_method
[12786.833867] acpi_ev_notify_dispatch
[12786.836233] acpi_ev_asynch_enable_gpe
[12786.836242] acpi_ev_notify_dispatch
[12786.957678] acpi_ev_asynch_execute_gpe_method
[12786.958065] acpi_ev_notify_dispatch
[12786.964196] acpi_ev_asynch_enable_gpe
[12786.964205] acpi_ev_notify_dispatch
[12786.964244] acpi_ev_asynch_execute_gpe_method
[12786.970213] acpi_ev_notify_dispatch
[12786.971816] acpi_ev_asynch_enable_gpe
[12786.971825] acpi_ev_notify_dispatch
[12786.997100] acpi_ev_asynch_execute_gpe_method
[12786.997472] acpi_ev_notify_dispatch
[12787.003279] acpi_ev_asynch_enable_gpe
[12787.003290] acpi_ev_notify_dispatch
[12787.003317] acpi_ev_asynch_execute_gpe_method
[12787.008331] acpi_ev_notify_dispatch
[12787.010682] acpi_ev_asynch_enable_gpe
[12787.010692] acpi_ev_notify_dispatch
[12787.309017] acpi_ev_asynch_execute_gpe_method
[12787.313035] acpi_ev_notify_dispatch
[12787.315300] acpi_ev_asynch_enable_gpe
[12787.319026] acpi_ev_asynch_execute_gpe_method
[12787.319387] acpi_ev_notify_dispatch
[12787.326065] acpi_ev_asynch_enable_gpe
[12787.326075] acpi_ev_notify_dispatch
[12787.326113] acpi_ev_asynch_execute_gpe_method
[12787.332078] acpi_ev_notify_dispatch
[12787.333685] acpi_ev_asynch_enable_gpe
[12787.333694] acpi_ev_notify_dispatch
[12788.338728] acpi_ev_asynch_execute_gpe_method
[12788.339140] acpi_ev_notify_dispatch
[12788.345606] acpi_ev_asynch_enable_gpe
[12788.345616] acpi_ev_notify_dispatch
[12788.345660] acpi_ev_asynch_execute_gpe_method
[12788.350599] acpi_ev_notify_dispatch
[12788.352955] acpi_ev_asynch_enable_gpe
[12788.352965] acpi_ev_notify_dispatch
[12789.646199] acpi_ev_asynch_execute_gpe_method
[12789.646595] acpi_ev_notify_dispatch
[12789.652861] acpi_ev_asynch_enable_gpe
[12789.652871] acpi_ev_notify_dispatch
[12789.652913] acpi_ev_asynch_execute_gpe_method
[12789.658870] acpi_ev_notify_dispatch
[12789.660495] acpi_ev_asynch_enable_gpe
[12789.660505] acpi_ev_notify_dispatch
[12791.535774] acpi_ev_asynch_execute_gpe_method
[12791.536210] acpi_ev_notify_dispatch
[12791.542525] acpi_ev_asynch_enable_gpe
[12791.542535] acpi_ev_notify_dispatch
[12791.542580] acpi_ev_asynch_execute_gpe_method
[12791.547545] acpi_ev_notify_dispatch
[12791.549935] acpi_ev_asynch_enable_gpe
[12791.549944] acpi_ev_notify_dispatch
[12791.593592] acpi_ev_asynch_execute_gpe_method
[12791.593976] acpi_ev_notify_dispatch
[12791.599677] acpi_ev_asynch_enable_gpe
[12791.599686] acpi_ev_notify_dispatch
[12791.599730] acpi_ev_asynch_execute_gpe_method
[12791.604667] acpi_ev_notify_dispatch
[12791.607042] acpi_ev_asynch_enable_gpe
[12791.607052] acpi_ev_notify_dispatch
[12791.672433] acpi_ev_asynch_execute_gpe_method
[12791.672801] acpi_ev_notify_dispatch
[12791.678850] acpi_ev_asynch_enable_gpe
[12791.678859] acpi_ev_notify_dispatch
[12791.678902] acpi_ev_asynch_execute_gpe_method
[12791.683884] acpi_ev_notify_dispatch
[12791.686249] acpi_ev_asynch_enable_gpe
[12791.686259] acpi_ev_notify_dispatch
[12791.689514] acpi_ev_asynch_execute_gpe_method
[12791.689868] acpi_ev_notify_dispatch
[12791.696055] acpi_ev_asynch_enable_gpe
[12791.696064] acpi_ev_notify_dispatch
[12791.696103] acpi_ev_asynch_execute_gpe_method
[12791.701927] acpi_ev_notify_dispatch
[12791.703545] acpi_ev_asynch_enable_gpe
[12791.703554] acpi_ev_notify_dispatch
[12791.705273] acpi_ev_asynch_execute_gpe_method
[12791.705698] acpi_ev_notify_dispatch
[12791.711953] acpi_ev_asynch_enable_gpe
[12791.711962] acpi_ev_notify_dispatch
[12791.712031] acpi_ev_asynch_execute_gpe_method
[12791.716945] acpi_ev_notify_dispatch
[12791.719313] acpi_ev_asynch_enable_gpe
[12791.719322] acpi_ev_notify_dispatch
=== dmesg ====
Comment 1 Ali Gholami Rudi 2010-01-22 19:49:37 UTC
Created attachment 24674 [details]
acpidump output
Comment 2 Alexey Starikovskiy 2010-01-22 22:09:02 UTC
please add gpe_event_info->gpe_number to printk in gpe functions...
please also try to insert an msleep() before call of acpi_os_execute in ev_asynch_execute_gpe_method()
Comment 3 Ali Gholami Rudi 2010-01-24 04:37:25 UTC
The high cpu-usage case didn't happen yet.  But, as
mentioned, sometimes when I reboot the machine the
fan works fullspeed while
/sys/devices/virtual/thermal/cooling*/cur_state
show that all fans are off (echoing 1 and the 0
to one of them fixes the problem).

With the debug messages, when I boot normally nothing
is printed and "dmesg | grep" returns nothing.  But
once when I rebooted I got:

=== cmd ====
# dmesg | grep gpe
[    1.421575] acpi_ev_asynch_execute_gpe_method: gpe=2
[    1.432020] acpi_ev_asynch_enable_gpe gpe=2
[    1.432069] acpi_ev_asynch_execute_gpe_method: gpe=2
[    1.443020] acpi_ev_asynch_enable_gpe gpe=2
[    1.514204] acpi_ev_asynch_execute_gpe_method: gpe=2
[    1.526017] acpi_ev_asynch_enable_gpe gpe=2
[    1.561500] acpi_ev_asynch_execute_gpe_method: gpe=2
[    1.573019] acpi_ev_asynch_enable_gpe gpe=2
[    1.579249] acpi_ev_asynch_execute_gpe_method: gpe=2
[    1.591020] acpi_ev_asynch_enable_gpe gpe=2
[    1.614070] acpi_ev_asynch_execute_gpe_method: gpe=2
[    1.626019] acpi_ev_asynch_enable_gpe gpe=2
[    1.664005] acpi_ev_asynch_execute_gpe_method: gpe=2
[    1.676019] acpi_ev_asynch_enable_gpe gpe=2
[    1.742839] acpi_ev_asynch_execute_gpe_method: gpe=2
[    1.755020] acpi_ev_asynch_enable_gpe gpe=2
[    2.213431] acpi_ev_asynch_execute_gpe_method: gpe=2
[    2.230083] acpi_ev_asynch_enable_gpe gpe=2
[    2.233125]  sda6acpi_ev_asynch_execute_gpe_method: gpe=2
[    2.247068] acpi_ev_asynch_enable_gpe gpe=2
[    2.263346] acpi_ev_asynch_execute_gpe_method: gpe=2
[    2.274348] acpi_ev_asynch_enable_gpe gpe=2
[    2.279730] acpi_ev_asynch_execute_gpe_method: gpe=2
[    2.294067] acpi_ev_asynch_enable_gpe gpe=2
[    2.296725] acpi_ev_asynch_execute_gpe_method: gpe=2
[    2.310094] acpi_ev_asynch_enable_gpe gpe=2
[    2.323665] acpi_ev_asynch_execute_gpe_method: gpe=2
[    2.337208] acpi_ev_asynch_enable_gpe gpe=2
[    2.339898] acpi_ev_asynch_execute_gpe_method: gpe=2
[    2.353080] acpi_ev_asynch_enable_gpe gpe=2
[    2.355600] acpi_ev_asynch_execute_gpe_method: gpe=2
[    2.369208] acpi_ev_asynch_enable_gpe gpe=2
[    2.371756] acpi_ev_asynch_execute_gpe_method: gpe=2
[    2.385080] acpi_ev_asynch_enable_gpe gpe=2
[    2.387613] acpi_ev_asynch_execute_gpe_method: gpe=2
[    2.401102] acpi_ev_asynch_enable_gpe gpe=2
[    2.403596] acpi_ev_asynch_execute_gpe_method: gpe=2
[    2.417079] acpi_ev_asynch_enable_gpe gpe=2
[    2.419548] acpi_ev_asynch_execute_gpe_method: gpe=2
[    2.433101] acpi_ev_asynch_enable_gpe gpe=2
[    2.435317] acpi_ev_asynch_execute_gpe_method: gpe=2
[    2.448226] acpi_ev_asynch_enable_gpe gpe=2
[    2.450326] acpi_ev_asynch_execute_gpe_method: gpe=2
[    2.463095] acpi_ev_asynch_enable_gpe gpe=2
[    2.465132] acpi_ev_asynch_execute_gpe_method: gpe=2
[    2.476213] acpi_ev_asynch_enable_gpe gpe=2
[    2.478265] acpi_ev_asynch_execute_gpe_method: gpe=2
[    2.495480] acpi_ev_asynch_enable_gpe gpe=2
[    2.497799] acpi_ev_asynch_execute_gpe_method: gpe=2
[    2.512067] acpi_ev_asynch_enable_gpe gpe=2
[    2.514293] acpi_ev_asynch_execute_gpe_method: gpe=2
[    2.527197] acpi_ev_asynch_enable_gpe gpe=2
[    2.529309] acpi_ev_asynch_execute_gpe_method: gpe=2
[    2.542080] acpi_ev_asynch_enable_gpe gpe=2
[    2.549565] acpi_ev_asynch_execute_gpe_method: gpe=2
[    2.563095] acpi_ev_asynch_enable_gpe gpe=2
=== cmd ====

But the fan problem didn't happen.  It might mean the
usleep() call fixed that problem or it was unrelated to
that bug.

I'll wait till that high-cpu usage case reappears (I'm
checking dmesg instead of the cpu-usage now, because
the usleep() call might prevent the high cpu usage).

Thanks.
Comment 4 Ali Gholami Rudi 2010-01-24 20:01:15 UTC
I'm almost sure the usleep() fixed the fan problem when
rebooting.  But today I noticed the cpu temperature is
sometimes wrong (a bios bug?)
/sys/virtual/thermal/thermal_zone3/temperature was 28
degrees in my four hours of uptime; but the wind coming
out was warm (I set the "turn on the fan when on AC power"
option in the bios).  Then I rebooted it, and it showed 42
degrees.  And now the fan is constantly on at one of the
lower speeds (a bit higher than the default on AC power
level) and the temperature fixed at 42 degrees.

Also sometime ago I experienced some delay in updating
the temperature when I used "therma.act=45"; the temperature
suddenly jumped from 45 to 53.  Then I tried using thermal.tzp,
but AFAIR it didn't help much but I'm not sure about it.
Is there something try to make the temperature more accurate?

Just to summarize, there are three problems:

* the high cpu usage of kacpi_wq (if it happens I'll submit the
  gpe values in dmesg trace)
* the fan turns on at full speed after rebooting while
  /sys/../cooling_device?/cur_state show fans are all off.  Seems
  to be fixed after inserting usleep() as you suggested, but not
  sure yet.
* the wrong temperature

Thanks.
Comment 5 Ali Gholami Rudi 2010-01-31 19:56:39 UTC
Hi,

Now my cpu temperature is not updated after boot; that's
strange.  I remember the temperature used to get updated,
though there were noticeable jumps.  I'm not sure if
anything in the mainline caused this behavior (I'll try
to find the time to try an older kernel).  Since I can't
rely on the temperature, when I feel the cpu is getting
warm, I turn on the fan manually by echoing in
cooling_deviceX/cur_state in sysfs.  I hope this gets
fixed :-)

Anyway, none of the gpe_methods were called in the last
week.  It might be related to the above problem.

Thanks.
Comment 6 Ali Gholami Rudi 2010-02-18 15:14:21 UTC
Hi Alexey,

Now I see kacpi_notify high cpu usage again.  I think the
reason is now I use the machine in a warmer environment
than the last few weeks.  The cpu temperature update delay
still exists: the reported temperature remains constant
after boot until it reaches acpi active cooling thermal zone.

As you suggested, I've added gpe_number to printk messages
and added a msleep(10) call in acpi_ev_asynch_execute_gpe_method().
I see a lot of included messages.  kacpi_notify cpu usage has
decreased to 10-20% (I think due to the msleep() call).

Thanks,
Ali

=== gpe_number debug messages ====
[ 6529.162788] acpi_ev_notify_dispatch
[ 6529.168096] acpi_ev_asynch_enable_gpe gpe=2
[ 6529.168177] acpi_ev_asynch_execute_gpe_method: gpe=2
[ 6529.168547] acpi_ev_notify_dispatch
[ 6529.170921] acpi_ev_notify_dispatch
[ 6529.179067] acpi_ev_asynch_enable_gpe gpe=2
[ 6529.187114] acpi_ev_asynch_execute_gpe_method: gpe=2
[ 6529.187479] acpi_ev_notify_dispatch
[ 6529.192863] acpi_ev_notify_dispatch
[ 6529.198095] acpi_ev_asynch_enable_gpe gpe=2
[ 6529.198175] acpi_ev_asynch_execute_gpe_method: gpe=2
[ 6529.198547] acpi_ev_notify_dispatch
[ 6529.209081] acpi_ev_asynch_enable_gpe gpe=2
[ 6529.209123] acpi_ev_asynch_execute_gpe_method: gpe=2
[ 6529.209484] acpi_ev_notify_dispatch
[ 6529.214917] acpi_ev_notify_dispatch
[ 6529.220082] acpi_ev_asynch_enable_gpe gpe=2
[ 6529.247565] acpi_ev_asynch_execute_gpe_method: gpe=2
[ 6529.247932] acpi_ev_notify_dispatch
[ 6529.254050] acpi_ev_notify_dispatch
[ 6529.259041] acpi_ev_asynch_enable_gpe gpe=2
[ 6529.259087] acpi_ev_asynch_execute_gpe_method: gpe=2
[ 6529.259447] acpi_ev_notify_dispatch
[ 6529.261819] acpi_ev_notify_dispatch
[ 6529.270082] acpi_ev_asynch_enable_gpe gpe=2
[ 6529.308007] acpi_ev_asynch_execute_gpe_method: gpe=2
[ 6529.308383] acpi_ev_notify_dispatch
[ 6529.314198] acpi_ev_notify_dispatch
[ 6529.319189] acpi_ev_asynch_enable_gpe gpe=2
[ 6529.319236] acpi_ev_asynch_execute_gpe_method: gpe=2
[ 6529.319598] acpi_ev_notify_dispatch
[ 6529.321966] acpi_ev_notify_dispatch
[ 6529.330082] acpi_ev_asynch_enable_gpe gpe=2
[ 6529.619435] acpi_ev_asynch_execute_gpe_method: gpe=2
[ 6529.619803] acpi_ev_notify_dispatch
[ 6529.625930] acpi_ev_notify_dispatch
[ 6529.630965] acpi_ev_asynch_enable_gpe gpe=2
[ 6529.631054] acpi_ev_asynch_execute_gpe_method: gpe=2
[ 6529.631418] acpi_ev_notify_dispatch
[ 6529.633790] acpi_ev_notify_dispatch
[ 6529.642083] acpi_ev_asynch_enable_gpe gpe=2
[ 6529.661485] acpi_ev_asynch_execute_gpe_method: gpe=2
[ 6529.661850] acpi_ev_notify_dispatch
[ 6529.667065] acpi_ev_notify_dispatch
[ 6529.672066] acpi_ev_asynch_enable_gpe gpe=2
[ 6529.672112] acpi_ev_asynch_execute_gpe_method: gpe=2
[ 6529.672473] acpi_ev_notify_dispatch
[ 6529.674840] acpi_ev_notify_dispatch
[ 6529.683067] acpi_ev_asynch_enable_gpe gpe=2
[ 6529.694340] acpi_ev_asynch_execute_gpe_method: gpe=2
[ 6529.694704] acpi_ev_notify_dispatch
[ 6529.700126] acpi_ev_notify_dispatch
[ 6529.705170] acpi_ev_asynch_enable_gpe gpe=2
[ 6529.705214] acpi_ev_asynch_execute_gpe_method: gpe=2
[ 6529.705575] acpi_ev_notify_dispatch
[ 6529.707946] acpi_ev_notify_dispatch
[ 6529.716081] acpi_ev_asynch_enable_gpe gpe=2
[ 6529.767924] acpi_ev_asynch_execute_gpe_method: gpe=2
[ 6529.768311] acpi_ev_notify_dispatch
[ 6529.774284] acpi_ev_notify_dispatch
[ 6529.779274] acpi_ev_asynch_enable_gpe gpe=2
[ 6529.779330] acpi_ev_asynch_execute_gpe_method: gpe=2
[ 6529.779691] acpi_ev_notify_dispatch
[ 6529.782081] acpi_ev_notify_dispatch
[ 6529.790081] acpi_ev_asynch_enable_gpe gpe=2
[ 6529.790126] acpi_ev_asynch_execute_gpe_method: gpe=2
[ 6529.790489] acpi_ev_notify_dispatch
[ 6529.801066] acpi_ev_asynch_enable_gpe gpe=2
[ 6529.838882] acpi_ev_asynch_execute_gpe_method: gpe=2
[ 6529.839272] acpi_ev_notify_dispatch
[ 6529.844494] acpi_ev_notify_dispatch
[ 6529.850057] acpi_ev_asynch_enable_gpe gpe=2
[ 6529.850135] acpi_ev_asynch_execute_gpe_method: gpe=2
[ 6529.850509] acpi_ev_notify_dispatch
[ 6529.852883] acpi_ev_notify_dispatch
[ 6529.861066] acpi_ev_asynch_enable_gpe gpe=2
[ 6529.867786] acpi_ev_asynch_execute_gpe_method: gpe=2
[ 6529.868167] acpi_ev_notify_dispatch
[ 6529.873553] acpi_ev_notify_dispatch
[ 6529.879095] acpi_ev_asynch_enable_gpe gpe=2
[ 6529.879174] acpi_ev_asynch_execute_gpe_method: gpe=2
[ 6529.879545] acpi_ev_notify_dispatch
[ 6529.881915] acpi_ev_notify_dispatch
[ 6529.890066] acpi_ev_asynch_enable_gpe gpe=2
[ 6530.079347] acpi_ev_asynch_execute_gpe_method: gpe=2
[ 6530.079718] acpi_ev_notify_dispatch
[ 6530.085094] acpi_ev_notify_dispatch
[ 6530.090116] acpi_ev_asynch_enable_gpe gpe=2
[ 6530.090159] acpi_ev_asynch_execute_gpe_method: gpe=2
[ 6530.090519] acpi_ev_notify_dispatch
[ 6530.092886] acpi_ev_notify_dispatch
[ 6530.101082] acpi_ev_asynch_enable_gpe gpe=2
[ 6530.108256] acpi_ev_asynch_execute_gpe_method: gpe=2
[ 6530.108622] acpi_ev_notify_dispatch
[ 6530.114163] acpi_ev_notify_dispatch
[ 6530.119165] acpi_ev_asynch_enable_gpe gpe=2
[ 6530.119212] acpi_ev_asynch_execute_gpe_method: gpe=2
[ 6530.119572] acpi_ev_notify_dispatch
[ 6530.121943] acpi_ev_notify_dispatch
[ 6530.130066] acpi_ev_asynch_enable_gpe gpe=2
Comment 7 Alexey Starikovskiy 2010-02-18 15:20:38 UTC
What kernel do you use now? Could you check if latest git version works any better?
Comment 8 Ali Gholami Rudi 2010-02-18 15:52:25 UTC
I'm using the latest git version (b0483e78).
Comment 9 Ali Gholami Rudi 2010-02-18 18:06:29 UTC
After observing it for some time, I think I know how it
happens (I don't know much about acpi, so sorry for
wrong conclusions):

The high cpu usage happens on 43^C.  That is the first
active cooling temperature.  It seems on this temperature
the bios generates lots of acpi events and at each event
the acpi driver does the same actions again.  Below or
above this temperature I can control the fan through /sys
but at 43^C, it is reset very fast (most of the time so
fast that I cannot notice a change in fan speed).

About the reported temperature change delay, I think the
bios reports the new temperature only when it thinks it
is useful to the driver, hence the temperature is not
updated till it reaches 43.  When it becomes cooler it
gets updated to 42 (it won't report a smaller number
since it thinks the driver should not care if the
temperature is 42^c or say 20^c, since both are lower
than the first trip point).  The same holds for higher
temperatures; it reports 43 till it reaches 53^c.

So I think the main bug is in the bios which generates
many acpi events when it is close to a trip point
temperature.  If so, how can it be fixed?  Is it
possible to ignore acpi events when they are very close
to the last one?  Or are there better solutions?

Thanks,
Ali
Comment 10 Alexey Starikovskiy 2010-02-18 23:37:30 UTC
hm, did you install latest BIOS too?
Comment 12 Zhang Rui 2010-10-22 03:12:46 UTC
does the problem still exist in the latest upstream kernel, say 2.6.35 or 2.6.36-rc?
Comment 13 Ali Gholami Rudi 2010-10-22 05:34:16 UTC
Not having windows to update the bios, I decided to pass
thermal.off=1 to the kernel and manage fan speed manually.
So I don't know if it is fixed or not.  I'll retry using
ACPI in a few days.  By the way, switching to x86 (I used
to use a 64-bit kernel) did fix one of my problems (I'm
afraid I don't remember what it was exactly, maybe something
related to the screen backlight), so it may be the bios
misbahaving in a 64-bit kernel.  But we'll see.
Comment 14 Ali Gholami Rudi 2010-10-22 16:15:10 UTC
I don't know if it's due to switching to a x86 kernel or
a change in acpi code, now the high cpu usage doesn't
happen after a day of testing.  The lazy temperature
updating still exists but I guess that's a bios issue
(it reports 42^C first and then stays at 43^C and the
fan speed changes to one).
Comment 15 Zhang Rui 2011-03-21 07:48:26 UTC
please feel free to re-open the bug if the problem can be reproduced.

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