Messages in this thread Patch in this message | | | Date | Tue, 19 Feb 2008 10:20:43 +0100 | From | Pavel Machek <> | Subject | Re: tsc breaks atkbd suspend |
| |
On Mon 2008-02-18 16:12:40, Thomas Gleixner wrote: > On Mon, 18 Feb 2008, Pavel Machek wrote: > > > I do not understand, what you mean. When exactly is "sleeppy test" > > > running ? > > > > from late_initcall(). > > Has the system already switched to highres/nohz mode at this point ?
I guess so, as nohz=off makes the problem go away.
> > > Also the TSC unstable detection is in a 500ms timeframe, so you should > > > never get a 10s delay. > > > > I'd not expect TSC instability detection to be ran while system is > > suspending > > There is nothing which switches it off, except right at the point > where the machine is shutdown. It's definitely active during the > freeze period. > > > , plus "wrong for 500msec" is still wrong. > > To be wrong for 500ms, the TSC must freeze completely.
...which is still very possible with C3, and being wrong for <500msec is still wrong.
> > > > I believe fix is very simple: > > > > > > NAK. > > > > > > This kills TSC on machines which have a working TSC and never go into > > > suspend. > > > > Apart from OLPC, which machines have working TSC? > > > > Anything that has cpufreq does not. > > Wrong. Newer CPUs have TSCs which are not affected by cpu frequency.
Ok, so whitelist the newer CPUs.
> > Anything that enters C2 does not. > > Wrong. C3 stops the TSC everywhere. C2 should not, but it does > unfortunately due to stupid BIOS implementations and on a lot of AMD > CPUs.
Hmm, and C3 is rather common, right?
> > Anything that is SMP does not. > > Wrong. I'm writing this mail from a SMP machine with perfectly > sychronized TSCs.
While I'm writing this from thinkpad X60:
checking TSC synchronization [CPU#0 -> CPU#1]: Measured 580063 cycles TSC warp between CPUs, turning off TSC clock. Marking TSC unstable due to: check_tsc_sync_source failed.
> > So, how many machines do you have with working TSC? > > At least 5.
Out of?
I do not see what we are arguing about. TSC was not originally designed to provide time, and it does not provide time at least on machines with C3. We are using it by default, which is just wrong.
If it works for some systems, they should be whitelisted.
> One sensible solution would be to force TSC unstable before we > suspend, but I'd like to know why that 10sec delay happens at all. > > Can you please provide a dmesg log ?
(Detailed log in attachment).
... PM: Adding info for No Bus:cpu_dma_latency PM: Adding info for No Bus:network_latency PM: Adding info for No Bus:network_throughput PM: test RTC wakeup from 'mem' suspend PM: Syncing filesystems ... done. PM: Preparing system for mem sleep Freezing user space processes ... (elapsed 0.00 seconds) done. Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done. PM: Entering mem sleep ACPI: Preparing to enter system sleep state S3 coretemp coretemp.0: suspend serio serio1: suspend serio_suspend: starting serio_suspend: done atkbd serio0: suspend serio_suspend: starting ps2_command enter ps2_command get mutex ps2_command pause rx ps2_command synaptics ps2_command sending bytes ps2_command waiting event: 1000 wait_event returned: 998 ps2_command adjust timeout: 25 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ # here it hangs, for ~30 seconds, while it should be sleeping for 100msec. # ps2_command receiving ps2_command mostly done serio_suspend: done i8042 i8042: suspend i8042_suspend: starting i8042_suspend: done sd 0:0:0:0: suspend sd 0:0:0:0: [sda] Synchronizing SCSI cache sd 0:0:0:0: [sda] Stopping disk sd 0:0:0:0: suspended ahci: autosuspend disabled
Here's what I used to get those debug prints:
diff --git a/drivers/input/serio/i8042.c b/drivers/input/serio/i8042.c index 2763394..8115893 100644 --- a/drivers/input/serio/i8042.c +++ b/drivers/input/serio/i8042.c @@ -895,12 +895,14 @@ #ifdef CONFIG_PM static int i8042_suspend(struct platform_device *dev, pm_message_t state) { + printk("i8042_suspend: starting\n"); if (dev->dev.power.power_state.event != state.event) { if (state.event == PM_EVENT_SUSPEND) i8042_controller_reset(); dev->dev.power.power_state = state; } + printk("i8042_suspend: done\n"); return 0; } diff --git a/drivers/input/serio/libps2.c b/drivers/input/serio/libps2.c index b819239..81bd843 100644 --- a/drivers/input/serio/libps2.c +++ b/drivers/input/serio/libps2.c @@ -178,6 +178,7 @@ int ps2_command(struct ps2dev *ps2dev, u int rc = -1; int i; + printk("ps2_command enter\n"); if (receive > sizeof(ps2dev->cmdbuf)) { WARN_ON(1); return -1; @@ -188,8 +189,10 @@ int ps2_command(struct ps2dev *ps2dev, u return -1; } + printk("ps2_command get mutex\n"); mutex_lock(&ps2dev->cmd_mutex); + printk("ps2_command pause rx\n"); serio_pause_rx(ps2dev->serio); ps2dev->flags = command == PS2_CMD_GETID ? PS2_FLAG_WAITID : 0; ps2dev->cmdcnt = receive; @@ -198,6 +201,7 @@ int ps2_command(struct ps2dev *ps2dev, u ps2dev->cmdbuf[(receive - 1) - i] = param[i]; serio_continue_rx(ps2dev->serio); + printk("ps2_command synaptics\n"); /* * Some devices (Synaptics) peform the reset before * ACKing the reset command, and so it can take a long @@ -207,29 +211,51 @@ int ps2_command(struct ps2dev *ps2dev, u command == PS2_CMD_RESET_BAT ? 1000 : 200)) goto out; + printk("ps2_command sending bytes\n"); for (i = 0; i < send; i++) if (ps2_sendbyte(ps2dev, param[i], 200)) goto out; + /* * The reset command takes a long time to execute. */ timeout = msecs_to_jiffies(command == PS2_CMD_RESET_BAT ? 4000 : 500); +#if 0 + printk("ps2: testing timeouts\n"); + timeout = wait_event_timeout(ps2dev->wait, 0, 10); + printk("ps2: testing timeouts\n"); + timeout = wait_event_timeout(ps2dev->wait, 0, 10); + printk("ps2: testing timeouts\n"); + timeout = wait_event_timeout(ps2dev->wait, 0, 10); + printk("ps2: testing timeouts\n"); + timeout = wait_event_timeout(ps2dev->wait, 0, 10); + printk("ps2: testing timeouts\n"); + timeout = wait_event_timeout(ps2dev->wait, 0, 10); + printk("ps2: timeouts ok?\n"); +#endif + printk("ps2_command waiting event: %d\n", timeout); timeout = wait_event_timeout(ps2dev->wait, !(ps2dev->flags & PS2_FLAG_CMD1), timeout); if (ps2dev->cmdcnt && timeout > 0) { + printk("wait_event returned: %d\n", timeout); timeout = ps2_adjust_timeout(ps2dev, command, timeout); + + printk("ps2_command adjust timeout: %d\n", timeout); wait_event_timeout(ps2dev->wait, !(ps2dev->flags & PS2_FLAG_CMD), timeout); } + printk("ps2_command receiving\n"); if (param) for (i = 0; i < receive; i++) param[i] = ps2dev->cmdbuf[(receive - 1) - i]; + printk("ps2_command mostly done\n"); + if (ps2dev->cmdcnt && (command != PS2_CMD_RESET_BAT || ps2dev->cmdcnt != 1)) goto out; diff --git a/drivers/input/serio/serio.c b/drivers/input/serio/serio.c index 7f52938..cd320b1 100644 --- a/drivers/input/serio/serio.c +++ b/drivers/input/serio/serio.c @@ -912,12 +912,14 @@ #endif /* CONFIG_HOTPLUG */ #ifdef CONFIG_PM static int serio_suspend(struct device *dev, pm_message_t state) { + printk("serio_suspend: starting\n"); if (dev->power.power_state.event != state.event) { if (state.event == PM_EVENT_SUSPEND) serio_cleanup(to_serio_port(dev)); dev->power.power_state = state; } + printk("serio_suspend: done\n"); return 0; } Pavel -- (english) http://www.livejournal.com/~pavelmachek (cesky, pictures) http://atrey.karlin.mff.cuni.cz/~pavel/picture/horses/blog.html [unhandled content-type:application/octet-stream] | |