linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* Scheduler broken? sdhci issues with scheduling
@ 2008-02-29 11:52 Simon Huggins
  2008-02-29 13:34 ` Ingo Molnar
  2008-03-02 10:40 ` Pavel Machek
  0 siblings, 2 replies; 16+ messages in thread
From: Simon Huggins @ 2008-02-29 11:52 UTC (permalink / raw)
  To: linux-kernel

[ Please Cc me on replies ]

I had a bug with sdhci which Pierre Ossman looked at for me.

In the end essentially the fix was to use HZ=1000 and nothing else.
Pierre seemed to think that this was a bug in the scheduler.

I'm interested if someone who groks the scheduler could take a look at
the mmc/* code and see if it's abusing HZ or if there's anything
obviously wrong there.  If it's not then perhaps there really is a bug
in the scheduler?

See
http://list.drzeus.cx/pipermail/sdhci-devel/2008-February/002164.html
http://list.drzeus.cx/pipermail/sdhci-devel/2008-January/002142.html

Here's the log that caused him to suspect the scheduler:
http://list.drzeus.cx/pipermail/sdhci-devel/2007-December/002086.html
and his post saying so:
http://list.drzeus.cx/pipermail/sdhci-devel/2007-December/002087.html

Originally I tried to narrow it down:
http://list.drzeus.cx/pipermail/sdhci-devel/2007-November/002072.html
and shows a commit that seemed to "fix" it for me
http://list.drzeus.cx/pipermail/sdhci-devel/2007-November/002072.html
but apparently the commit I reverted was good
http://list.drzeus.cx/pipermail/sdhci-devel/2007-November/002078.html

I'm happy to provide more information or try different kernels/config
options etc (I really should upgrade the kernel on my laptop anyway).

Thanks,

-- 
----------(   "An excellent suggestion sir, with only two    )----------
Simon ----(            minor flaws...." - Kryten             )---- Nomis
                             Htag.pl 0.0.22

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: Scheduler broken? sdhci issues with scheduling
  2008-02-29 11:52 Scheduler broken? sdhci issues with scheduling Simon Huggins
@ 2008-02-29 13:34 ` Ingo Molnar
  2008-02-29 13:51   ` Ingo Molnar
  2008-03-02 10:40 ` Pavel Machek
  1 sibling, 1 reply; 16+ messages in thread
From: Ingo Molnar @ 2008-02-29 13:34 UTC (permalink / raw)
  To: huggie, linux-kernel; +Cc: Thomas Gleixner


* Simon Huggins <huggie@earth.li> wrote:

> [ Please Cc me on replies ]
> 
> I had a bug with sdhci which Pierre Ossman looked at for me.
> 
> In the end essentially the fix was to use HZ=1000 and nothing else. 
> Pierre seemed to think that this was a bug in the scheduler.

does the patch below help, even if you keep HZ=100? This doesnt look 
like a scheduler issue, it's more of a timer/timing issue. Different HZ 
means different msleep() results - and the mmc code does a loop of small 
msleep delays.

	Ingo

-------------->
---
 drivers/mmc/core/core.h |    7 +------
 1 file changed, 1 insertion(+), 6 deletions(-)

Index: linux/drivers/mmc/core/core.h
===================================================================
--- linux.orig/drivers/mmc/core/core.h
+++ linux/drivers/mmc/core/core.h
@@ -36,12 +36,7 @@ void mmc_set_timing(struct mmc_host *hos
 
 static inline void mmc_delay(unsigned int ms)
 {
-	if (ms < 1000 / HZ) {
-		cond_resched();
-		mdelay(ms);
-	} else {
-		msleep(ms);
-	}
+	mdelay(ms);
 }
 
 void mmc_rescan(struct work_struct *work);

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: Scheduler broken? sdhci issues with scheduling
  2008-02-29 13:34 ` Ingo Molnar
@ 2008-02-29 13:51   ` Ingo Molnar
  2008-02-29 14:00     ` Ingo Molnar
  0 siblings, 1 reply; 16+ messages in thread
From: Ingo Molnar @ 2008-02-29 13:51 UTC (permalink / raw)
  To: huggie, linux-kernel; +Cc: Thomas Gleixner


* Ingo Molnar <mingo@elte.hu> wrote:

> does the patch below help, even if you keep HZ=100? This doesnt look 
> like a scheduler issue, it's more of a timer/timing issue. Different 
> HZ means different msleep() results - and the mmc code does a loop of 
> small msleep delays.

alternatively, instead of applying the first patch, could you apply the 
patch below instead? This makes "msleep()" much more precise. Does this 
help in the HZ != 1000 case?

	Ingo

----------------------->
Subject: hrtimers: use hrtimers so that msleep() sleeps for the requested time
From: Jonathan Corbet <corbet@lwn.net>

The problem being addressed here is that the current msleep() will stop
for a minimum of two jiffies, meaning that, on a HZ=100 system,
msleep(1) delays for for about 20ms.  In a driver with one such delay
for each of 150 or so register setting operations, the extra time adds
up to a few seconds.

This patch addresses the situation by using hrtimers.  On tickless
systems with working timers, msleep(1) now sleeps for 1ms, even with
HZ=100.

Most comments last time were favorable.  The one dissenter was Roman,
who worries about the overhead of using hrtimers for this operation; my
understanding is that he would rather see a really_msleep() function for
those who actually want millisecond resolution.  I'm not sure how to
characterize what the cost could be, but it can only be buried by the
fact that every call sleeps for some number of milliseconds.  On my
system, the several hundred total msleep() calls can't cause any real
overhead, and almost all happen at initialization time.

I still think it would be useful for msleep() to do what it says it does
and not vastly oversleep with small arguments.  A quick grep turns up
450 msleep(1) calls in the current mainline.  Andrew, if you agree, can
you drop this into -mm?  If not, I guess I'll let it go.

Current msleep() snoozes for at least two jiffies, causing msleep(1) to
sleep for at least 20ms on HZ=100 systems.  Using hrtimers allows
msleep() to sleep for something much closer to the requested time.

Signed-off-by: Jonathan Corbet <corbet@lwn.net>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
---
 fs/proc/proc_misc.c  |    4 ++--
 fs/select.c          |    6 ++++--
 include/linux/time.h |    8 ++++----
 kernel/timer.c       |   47 ++++++++++++++++++++++++++++++++++++++---------
 4 files changed, 48 insertions(+), 17 deletions(-)

Index: linux/fs/proc/proc_misc.c
===================================================================
--- linux.orig/fs/proc/proc_misc.c
+++ linux/fs/proc/proc_misc.c
@@ -115,9 +115,9 @@ static int uptime_read_proc(char *page, 
 	cputime_to_timespec(idletime, &idle);
 	len = sprintf(page,"%lu.%02lu %lu.%02lu\n",
 			(unsigned long) uptime.tv_sec,
-			(uptime.tv_nsec / (NSEC_PER_SEC / 100)),
+			(uptime.tv_nsec / (unsigned long)(NSEC_PER_SEC / 100)),
 			(unsigned long) idle.tv_sec,
-			(idle.tv_nsec / (NSEC_PER_SEC / 100)));
+			(idle.tv_nsec / (unsigned long)(NSEC_PER_SEC / 100)));
 
 	return proc_calc_metrics(page, start, off, count, eof, len);
 }
Index: linux/fs/select.c
===================================================================
--- linux.orig/fs/select.c
+++ linux/fs/select.c
@@ -446,7 +446,8 @@ asmlinkage long sys_pselect7(int n, fd_s
 		if ((u64)ts.tv_sec >= (u64)MAX_INT64_SECONDS)
 			timeout = -1;	/* infinite */
 		else {
-			timeout = DIV_ROUND_UP(ts.tv_nsec, NSEC_PER_SEC/HZ);
+			timeout = DIV_ROUND_UP(ts.tv_nsec,
+					       (unsigned long)NSEC_PER_SEC/HZ);
 			timeout += ts.tv_sec * HZ;
 		}
 	}
@@ -777,7 +778,8 @@ asmlinkage long sys_ppoll(struct pollfd 
 		if ((u64)ts.tv_sec >= (u64)MAX_INT64_SECONDS)
 			timeout = -1;	/* infinite */
 		else {
-			timeout = DIV_ROUND_UP(ts.tv_nsec, NSEC_PER_SEC/HZ);
+			timeout = DIV_ROUND_UP(ts.tv_nsec,
+					       (unsigned long)NSEC_PER_SEC/HZ);
 			timeout += ts.tv_sec * HZ;
 		}
 	}
Index: linux/include/linux/time.h
===================================================================
--- linux.orig/include/linux/time.h
+++ linux/include/linux/time.h
@@ -31,11 +31,11 @@ struct timezone {
 /* Parameters used to convert the timespec values: */
 #define MSEC_PER_SEC	1000L
 #define USEC_PER_MSEC	1000L
-#define NSEC_PER_USEC	1000L
-#define NSEC_PER_MSEC	1000000L
+#define NSEC_PER_USEC	1000LL
+#define NSEC_PER_MSEC	1000000LL
 #define USEC_PER_SEC	1000000L
-#define NSEC_PER_SEC	1000000000L
-#define FSEC_PER_SEC	1000000000000000L
+#define NSEC_PER_SEC	1000000000LL
+#define FSEC_PER_SEC	1000000000000000LL
 
 static inline int timespec_equal(const struct timespec *a,
                                  const struct timespec *b)
Index: linux/kernel/timer.c
===================================================================
--- linux.orig/kernel/timer.c
+++ linux/kernel/timer.c
@@ -1368,18 +1368,43 @@ void __init init_timers(void)
 	open_softirq(TIMER_SOFTIRQ, run_timer_softirq, NULL);
 }
 
+
+
+
+static void do_msleep(unsigned int msecs, struct hrtimer_sleeper *sleeper,
+	int sigs)
+{
+	enum hrtimer_mode mode = HRTIMER_MODE_REL;
+	int state = sigs ? TASK_INTERRUPTIBLE : TASK_UNINTERRUPTIBLE;
+
+	/*
+	 * This is really just a reworked and simplified version
+	 * of do_nanosleep().
+	 */
+	hrtimer_init(&sleeper->timer, CLOCK_MONOTONIC, mode);
+	sleeper->timer.expires = ktime_set(0, msecs*NSEC_PER_MSEC);
+	hrtimer_init_sleeper(sleeper, current);
+
+	do {
+		set_current_state(state);
+		hrtimer_start(&sleeper->timer, sleeper->timer.expires, mode);
+		if (sleeper->task)
+			schedule();
+		hrtimer_cancel(&sleeper->timer);
+		mode = HRTIMER_MODE_ABS;
+	} while (sleeper->task && !(sigs && signal_pending(current)));
+}
+
 /**
  * msleep - sleep safely even with waitqueue interruptions
  * @msecs: Time in milliseconds to sleep for
  */
 void msleep(unsigned int msecs)
 {
-	unsigned long timeout = msecs_to_jiffies(msecs) + 1;
+	struct hrtimer_sleeper sleeper;
 
-	while (timeout)
-		timeout = schedule_timeout_uninterruptible(timeout);
+	do_msleep(msecs, &sleeper, 0);
 }
-
 EXPORT_SYMBOL(msleep);
 
 /**
@@ -1388,11 +1413,15 @@ EXPORT_SYMBOL(msleep);
  */
 unsigned long msleep_interruptible(unsigned int msecs)
 {
-	unsigned long timeout = msecs_to_jiffies(msecs) + 1;
+	struct hrtimer_sleeper sleeper;
+	ktime_t left;
 
-	while (timeout && !signal_pending(current))
-		timeout = schedule_timeout_interruptible(timeout);
-	return jiffies_to_msecs(timeout);
-}
+	do_msleep(msecs, &sleeper, 1);
 
+	if (!sleeper.task)
+		return 0;
+	left = ktime_sub(sleeper.timer.expires,
+			 sleeper.timer.base->get_time());
+	return max(((long) ktime_to_ns(left))/(long)NSEC_PER_MSEC, 1L);
+}
 EXPORT_SYMBOL(msleep_interruptible);

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: Scheduler broken? sdhci issues with scheduling
  2008-02-29 13:51   ` Ingo Molnar
@ 2008-02-29 14:00     ` Ingo Molnar
  2008-02-29 19:39       ` Simon Huggins
  0 siblings, 1 reply; 16+ messages in thread
From: Ingo Molnar @ 2008-02-29 14:00 UTC (permalink / raw)
  To: huggie, linux-kernel; +Cc: Thomas Gleixner


* Ingo Molnar <mingo@elte.hu> wrote:

> alternatively, instead of applying the first patch, could you apply 
> the patch below instead? This makes "msleep()" much more precise. Does 
> this help in the HZ != 1000 case?

ok, this had a build failure - use the one below instead.

	Ingo

-------------->
Subject: hrtimers: use hrtimers so that msleep() sleeps for the requested time
From: Jonathan Corbet <corbet@lwn.net>

The problem being addressed here is that the current msleep() will stop
for a minimum of two jiffies, meaning that, on a HZ=100 system,
msleep(1) delays for for about 20ms.  In a driver with one such delay
for each of 150 or so register setting operations, the extra time adds
up to a few seconds.

This patch addresses the situation by using hrtimers.  On tickless
systems with working timers, msleep(1) now sleeps for 1ms, even with
HZ=100.

Most comments last time were favorable.  The one dissenter was Roman,
who worries about the overhead of using hrtimers for this operation; my
understanding is that he would rather see a really_msleep() function for
those who actually want millisecond resolution.  I'm not sure how to
characterize what the cost could be, but it can only be buried by the
fact that every call sleeps for some number of milliseconds.  On my
system, the several hundred total msleep() calls can't cause any real
overhead, and almost all happen at initialization time.

I still think it would be useful for msleep() to do what it says it does
and not vastly oversleep with small arguments.  A quick grep turns up
450 msleep(1) calls in the current mainline.  Andrew, if you agree, can
you drop this into -mm?  If not, I guess I'll let it go.

Current msleep() snoozes for at least two jiffies, causing msleep(1) to
sleep for at least 20ms on HZ=100 systems.  Using hrtimers allows
msleep() to sleep for something much closer to the requested time.

Signed-off-by: Jonathan Corbet <corbet@lwn.net>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
---
 fs/proc/proc_misc.c |    4 ++--
 fs/select.c         |    6 ++++--
 kernel/timer.c      |   47 ++++++++++++++++++++++++++++++++++++++---------
 3 files changed, 44 insertions(+), 13 deletions(-)

Index: linux/fs/proc/proc_misc.c
===================================================================
--- linux.orig/fs/proc/proc_misc.c
+++ linux/fs/proc/proc_misc.c
@@ -115,9 +115,9 @@ static int uptime_read_proc(char *page, 
 	cputime_to_timespec(idletime, &idle);
 	len = sprintf(page,"%lu.%02lu %lu.%02lu\n",
 			(unsigned long) uptime.tv_sec,
-			(uptime.tv_nsec / (NSEC_PER_SEC / 100)),
+			(uptime.tv_nsec / (unsigned long)(NSEC_PER_SEC / 100)),
 			(unsigned long) idle.tv_sec,
-			(idle.tv_nsec / (NSEC_PER_SEC / 100)));
+			(idle.tv_nsec / (unsigned long)(NSEC_PER_SEC / 100)));
 
 	return proc_calc_metrics(page, start, off, count, eof, len);
 }
Index: linux/fs/select.c
===================================================================
--- linux.orig/fs/select.c
+++ linux/fs/select.c
@@ -446,7 +446,8 @@ asmlinkage long sys_pselect7(int n, fd_s
 		if ((u64)ts.tv_sec >= (u64)MAX_INT64_SECONDS)
 			timeout = -1;	/* infinite */
 		else {
-			timeout = DIV_ROUND_UP(ts.tv_nsec, NSEC_PER_SEC/HZ);
+			timeout = DIV_ROUND_UP(ts.tv_nsec,
+					       (unsigned long)NSEC_PER_SEC/HZ);
 			timeout += ts.tv_sec * HZ;
 		}
 	}
@@ -777,7 +778,8 @@ asmlinkage long sys_ppoll(struct pollfd 
 		if ((u64)ts.tv_sec >= (u64)MAX_INT64_SECONDS)
 			timeout = -1;	/* infinite */
 		else {
-			timeout = DIV_ROUND_UP(ts.tv_nsec, NSEC_PER_SEC/HZ);
+			timeout = DIV_ROUND_UP(ts.tv_nsec,
+					       (unsigned long)NSEC_PER_SEC/HZ);
 			timeout += ts.tv_sec * HZ;
 		}
 	}
Index: linux/kernel/timer.c
===================================================================
--- linux.orig/kernel/timer.c
+++ linux/kernel/timer.c
@@ -1368,18 +1368,43 @@ void __init init_timers(void)
 	open_softirq(TIMER_SOFTIRQ, run_timer_softirq, NULL);
 }
 
+
+
+
+static void do_msleep(unsigned int msecs, struct hrtimer_sleeper *sleeper,
+	int sigs)
+{
+	enum hrtimer_mode mode = HRTIMER_MODE_REL;
+	int state = sigs ? TASK_INTERRUPTIBLE : TASK_UNINTERRUPTIBLE;
+
+	/*
+	 * This is really just a reworked and simplified version
+	 * of do_nanosleep().
+	 */
+	hrtimer_init(&sleeper->timer, CLOCK_MONOTONIC, mode);
+	sleeper->timer.expires = ktime_set(0, msecs*NSEC_PER_MSEC);
+	hrtimer_init_sleeper(sleeper, current);
+
+	do {
+		set_current_state(state);
+		hrtimer_start(&sleeper->timer, sleeper->timer.expires, mode);
+		if (sleeper->task)
+			schedule();
+		hrtimer_cancel(&sleeper->timer);
+		mode = HRTIMER_MODE_ABS;
+	} while (sleeper->task && !(sigs && signal_pending(current)));
+}
+
 /**
  * msleep - sleep safely even with waitqueue interruptions
  * @msecs: Time in milliseconds to sleep for
  */
 void msleep(unsigned int msecs)
 {
-	unsigned long timeout = msecs_to_jiffies(msecs) + 1;
+	struct hrtimer_sleeper sleeper;
 
-	while (timeout)
-		timeout = schedule_timeout_uninterruptible(timeout);
+	do_msleep(msecs, &sleeper, 0);
 }
-
 EXPORT_SYMBOL(msleep);
 
 /**
@@ -1388,11 +1413,15 @@ EXPORT_SYMBOL(msleep);
  */
 unsigned long msleep_interruptible(unsigned int msecs)
 {
-	unsigned long timeout = msecs_to_jiffies(msecs) + 1;
+	struct hrtimer_sleeper sleeper;
+	ktime_t left;
 
-	while (timeout && !signal_pending(current))
-		timeout = schedule_timeout_interruptible(timeout);
-	return jiffies_to_msecs(timeout);
-}
+	do_msleep(msecs, &sleeper, 1);
 
+	if (!sleeper.task)
+		return 0;
+	left = ktime_sub(sleeper.timer.expires,
+			 sleeper.timer.base->get_time());
+	return max(((long) ktime_to_ns(left))/(long)NSEC_PER_MSEC, 1L);
+}
 EXPORT_SYMBOL(msleep_interruptible);

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: Scheduler broken? sdhci issues with scheduling
  2008-02-29 14:00     ` Ingo Molnar
@ 2008-02-29 19:39       ` Simon Huggins
  2008-02-29 20:39         ` Ingo Molnar
  0 siblings, 1 reply; 16+ messages in thread
From: Simon Huggins @ 2008-02-29 19:39 UTC (permalink / raw)
  To: Ingo Molnar; +Cc: linux-kernel, Thomas Gleixner

[-- Attachment #1: Type: text/plain, Size: 3892 bytes --]

Hi Ingo,

(please cc me again)

On Fri, Feb 29, 2008 at 02:34:33PM +0100, Ingo Molnar wrote:
> * Simon Huggins <huggie@earth.li> wrote:
> > [ Please Cc me on replies ]
> > I had a bug with sdhci which Pierre Ossman looked at for me.
> > In the end essentially the fix was to use HZ=1000 and nothing else. 
> > Pierre seemed to think that this was a bug in the scheduler.
> does the patch below help, even if you keep HZ=100? This doesnt look 
> like a scheduler issue, it's more of a timer/timing issue. Different HZ 
> means different msleep() results - and the mmc code does a loop of small 
> msleep delays.

Thanks for looking at it.

I did tests with 2.6.24.3 with HZ=1000 and HZ=100 and as expected the
latter didn't work.

> -------------->
> ---
>  drivers/mmc/core/core.h |    7 +------
>  1 file changed, 1 insertion(+), 6 deletions(-)

> Index: linux/drivers/mmc/core/core.h
> ===================================================================
> --- linux.orig/drivers/mmc/core/core.h
> +++ linux/drivers/mmc/core/core.h
> @@ -36,12 +36,7 @@ void mmc_set_timing(struct mmc_host *hos

>  static inline void mmc_delay(unsigned int ms)
>  {
> -	if (ms < 1000 / HZ) {
> -		cond_resched();
> -		mdelay(ms);
> -	} else {
> -		msleep(ms);
> -	}
> +	mdelay(ms);
>  }

>  void mmc_rescan(struct work_struct *work);

That doesn't work.  I did a test with HZ=100 and this patch.  I've
attached the log as patch1-log.

On Fri, Feb 29, 2008 at 03:00:24PM +0100, Ingo Molnar wrote:

> * Ingo Molnar <mingo@elte.hu> wrote:

> > alternatively, instead of applying the first patch, could you apply 
> > the patch below instead? This makes "msleep()" much more precise. Does 
> > this help in the HZ != 1000 case?

> ok, this had a build failure - use the one below instead.

That doesn't work either.  Again I did a test with HZ=100 and this
patch.  I've attached the log as patch2-log.

It had some fuzz but no rejects with 2.6.24.3.

> -------------->
> Subject: hrtimers: use hrtimers so that msleep() sleeps for the requested time
> From: Jonathan Corbet <corbet@lwn.net>

> The problem being addressed here is that the current msleep() will stop
> for a minimum of two jiffies, meaning that, on a HZ=100 system,
> msleep(1) delays for for about 20ms.  In a driver with one such delay
> for each of 150 or so register setting operations, the extra time adds
> up to a few seconds.

> This patch addresses the situation by using hrtimers.  On tickless
> systems with working timers, msleep(1) now sleeps for 1ms, even with
> HZ=100.

> Most comments last time were favorable.  The one dissenter was Roman,
> who worries about the overhead of using hrtimers for this operation; my
> understanding is that he would rather see a really_msleep() function for
> those who actually want millisecond resolution.  I'm not sure how to
> characterize what the cost could be, but it can only be buried by the
> fact that every call sleeps for some number of milliseconds.  On my
> system, the several hundred total msleep() calls can't cause any real
> overhead, and almost all happen at initialization time.

> I still think it would be useful for msleep() to do what it says it does
> and not vastly oversleep with small arguments.  A quick grep turns up
> 450 msleep(1) calls in the current mainline.  Andrew, if you agree, can
> you drop this into -mm?  If not, I guess I'll let it go.

> Current msleep() snoozes for at least two jiffies, causing msleep(1) to
> sleep for at least 20ms on HZ=100 systems.  Using hrtimers allows
> msleep() to sleep for something much closer to the requested time.

[snip]


Anything else I can try?

-- 
----------(  "There are times when I think Clint belongs in  )----------
----------( my RSS-hole" -- anonymous Debian Planet reader.  )----------
Simon ----(                                                  )---- Nomis
                             Htag.pl 0.0.22

[-- Attachment #2: patch1-log --]
[-- Type: text/plain, Size: 6156 bytes --]

[   15.052986] sdhci: SDHCI controller found at 0000:03:0b.3 [104c:803c] (rev 0)
[   15.053077] sdhci [sdhci_probe()]: found 1 slot(s)
[   15.053102] PCI: Enabling device 0000:03:0b.3 (0000 -> 0002)
[   15.053186] ACPI: PCI Interrupt 0000:03:0b.3[D] -> GSI 23 (level, low) -> IRQ 23
[   15.053340] sdhci [sdhci_probe_slot()]: slot 0 at 0x88089800, irq 23
[   15.054103] sdhci: ============== REGISTER DUMP ==============
[   15.054110] sdhci: Sys addr: 0x00000000 | Version:  0x00008900
[   15.054115] sdhci: Blk size: 0x00000000 | Blk cnt:  0x00000000
[   15.054120] sdhci: Argument: 0x00000000 | Trn mode: 0x00000000
[   15.054125] sdhci: Present:  0x000a0000 | Host ctl: 0x00000000
[   15.054129] sdhci: Power:    0x00000000 | Blk gap:  0x00000000
[   15.054134] sdhci: Wake-up:  0x00000000 | Clock:    0x00000000
[   15.054139] sdhci: Timeout:  0x00000000 | Int stat: 0x00000000
[   15.054144] sdhci: Int enab: 0x00ff00fb | Sig enab: 0x00ff00fb
[   15.054149] sdhci: AC12 err: 0x00000000 | Slot int: 0x00000000
[   15.054154] sdhci: Caps:     0x01e030b0 | Max curr: 0x00000000
[   15.054156] sdhci: ===========================================
[   15.054207] mmc0: clock 0Hz busmode 1 powermode 0 cs 0 Vdd 0 width 0 timing 0
[   15.054222] mmc0: SDHCI at 0x88089800 irq 23 DMA
[   15.054958] ACPI: PCI Interrupt 0000:02:00.0[A] -> GSI 18 (level, low) -> IRQ 18
[   15.055137] PCI: Setting latency timer of device 0000:02:00.0 to 64
[   15.055883] iwl4965: Detected Intel Wireless WiFi Link 4965AGN
[   15.056000] mmc0: clock 0Hz busmode 1 powermode 1 cs 0 Vdd 21 width 0 timing 0
[   15.058006] mmc0: clock 187500Hz busmode 1 powermode 2 cs 0 Vdd 21 width 0 timing 0
[   15.061014] mmc0: clock 187500Hz busmode 1 powermode 2 cs 1 Vdd 21 width 0 timing 0
[   15.062020] mmc0: starting CMD0 arg 00000000 flags 000000c0
[   15.062207] mmc0: req done (CMD0): -123: 00000000 00000000 00000000 00000000
[   15.062350] PCI: Enabling device 0000:00:1b.0 (0000 -> 0002)
[   15.062443] ACPI: PCI Interrupt 0000:00:1b.0[A] -> GSI 22 (level, low) -> IRQ 22
[   15.063326] PCI: Setting latency timer of device 0000:00:1b.0 to 64
[   15.064359] mmc0: clock 187500Hz busmode 1 powermode 2 cs 0 Vdd 21 width 0 timing 0
[   15.065366] mmc0: starting CMD8 arg 000001aa flags 000002f5
[   15.065403] mmc0: req done (CMD8): -123: 00000000 00000000 00000000 00000000
[   15.065408] mmc0: starting CMD5 arg 00000000 flags 000002e1
[   15.065441] mmc0: req failed (CMD5): -123, retrying...
[   15.065475] mmc0: req failed (CMD5): -123, retrying...
[   15.065498] mmc0: req failed (CMD5): -123, retrying...
[   15.065528] mmc0: req done (CMD5): -123: 00000000 00000000 00000000 00000000
[   15.065533] mmc0: starting CMD55 arg 00000000 flags 000000f5
[   15.065557] mmc0: req done (CMD55): -123: 00000000 00000000 00000000 00000000
[   15.065561] mmc0: starting CMD55 arg 00000000 flags 000000f5
[   15.065591] mmc0: req done (CMD55): -123: 00000000 00000000 00000000 00000000
[   15.065596] mmc0: starting CMD55 arg 00000000 flags 000000f5
[   15.065620] mmc0: req done (CMD55): -123: 00000000 00000000 00000000 00000000
[   15.065625] mmc0: starting CMD55 arg 00000000 flags 000000f5
[   15.065654] mmc0: req done (CMD55): -123: 00000000 00000000 00000000 00000000
[   15.065659] mmc0: starting CMD1 arg 00000000 flags 000000e1
[   15.065680] mmc0: req done (CMD1): -123: 00000000 00000000 00000000 00000000
[   15.065685] mmc0: clock 0Hz busmode 1 powermode 0 cs 0 Vdd 0 width 0 timing 0



[   33.923911] sdhci [sdhci_irq()]: *** sdhci:slot0 got interrupt: 0x00000040
[   33.936455] mmc0: clock 0Hz busmode 1 powermode 1 cs 0 Vdd 21 width 0 timing 0
[   33.938471] mmc0: clock 187500Hz busmode 1 powermode 2 cs 0 Vdd 21 width 0 timing 0
[   33.941487] mmc0: clock 187500Hz busmode 1 powermode 2 cs 1 Vdd 21 width 0 timing 0
[   33.942495] mmc0: starting CMD0 arg 00000000 flags 000000c0
[   33.942761] sdhci [sdhci_irq()]: *** sdhci:slot0 got interrupt: 0x00000001
[   33.942774] mmc0: req done (CMD0): 0: 00000000 00000000 00000000 00000000
[   33.943965] mmc0: clock 187500Hz busmode 1 powermode 2 cs 0 Vdd 21 width 0 timing 0
[   33.944976] mmc0: starting CMD8 arg 000001aa flags 000002f5
[   33.945148] sdhci [sdhci_irq()]: *** sdhci:slot0 got interrupt: 0x00018000
[   33.945163] mmc0: req done (CMD8): -110: 00000000 00000000 00000000 00000000
[   33.945341] mmc0: starting CMD5 arg 00000000 flags 000002e1
[   33.945585] sdhci [sdhci_irq()]: *** sdhci:slot0 got interrupt: 0x00018000
[   33.945602] mmc0: req failed (CMD5): -110, retrying...
[   33.946582] sdhci [sdhci_irq()]: *** sdhci:slot0 got interrupt: 0x00018000
[   33.946595] mmc0: req failed (CMD5): -110, retrying...
[   33.947572] sdhci [sdhci_irq()]: *** sdhci:slot0 got interrupt: 0x00018000
[   33.947584] mmc0: req failed (CMD5): -110, retrying...
[   33.947864] sdhci [sdhci_irq()]: *** sdhci:slot0 got interrupt: 0x00018000
[   33.947878] mmc0: req done (CMD5): -110: 00000000 00000000 00000000 00000000
[   33.947952] mmc0: starting CMD55 arg 00000000 flags 000000f5
[   33.948936] sdhci [sdhci_irq()]: *** sdhci:slot0 got interrupt: 0x00018000
[   33.948949] mmc0: req done (CMD55): -110: 00000000 00000000 00000000 00000000
[   33.949025] mmc0: starting CMD55 arg 00000000 flags 000000f5
[   33.950006] sdhci [sdhci_irq()]: *** sdhci:slot0 got interrupt: 0x00018000
[   33.950018] mmc0: req done (CMD55): -110: 00000000 00000000 00000000 00000000
[   33.950092] mmc0: starting CMD55 arg 00000000 flags 000000f5
[   33.950349] sdhci [sdhci_irq()]: *** sdhci:slot0 got interrupt: 0x00018000
[   33.950363] mmc0: req done (CMD55): -110: 00000000 00000000 00000000 00000000
[   33.950435] mmc0: starting CMD55 arg 00000000 flags 000000f5
[   33.951416] sdhci [sdhci_irq()]: *** sdhci:slot0 got interrupt: 0x00018000
[   33.951429] mmc0: req done (CMD55): -110: 00000000 00000000 00000000 00000000
[   33.951505] mmc0: starting CMD1 arg 00000000 flags 000000e1
[   33.952486] sdhci [sdhci_irq()]: *** sdhci:slot0 got interrupt: 0x00018000
[   33.952499] mmc0: req done (CMD1): -110: 00000000 00000000 00000000 00000000
[   33.952573] mmc0: clock 0Hz busmode 1 powermode 0 cs 0 Vdd 0 width 0 timing 0

[-- Attachment #3: patch2-log --]
[-- Type: text/plain, Size: 5874 bytes --]

[   18.258572] sdhci [sdhci_probe_slot()]: slot 0 at 0x88089800, irq 23
[   18.259443] sdhci: ============== REGISTER DUMP ==============
[   18.259451] sdhci: Sys addr: 0x00000000 | Version:  0x00008900
[   18.259456] sdhci: Blk size: 0x00000000 | Blk cnt:  0x00000000
[   18.259461] sdhci: Argument: 0x00000000 | Trn mode: 0x00000000
[   18.259466] sdhci: Present:  0x000a0000 | Host ctl: 0x00000000
[   18.259471] sdhci: Power:    0x00000000 | Blk gap:  0x00000000
[   18.259476] sdhci: Wake-up:  0x00000000 | Clock:    0x00000000
[   18.259481] sdhci: Timeout:  0x00000000 | Int stat: 0x00000000
[   18.259486] sdhci: Int enab: 0x00ff00fb | Sig enab: 0x00ff00fb
[   18.259490] sdhci: AC12 err: 0x00000000 | Slot int: 0x00000000
[   18.259495] sdhci: Caps:     0x01e030b0 | Max curr: 0x00000000
[   18.259498] sdhci: ===========================================
[   18.259548] mmc0: clock 0Hz busmode 1 powermode 0 cs 0 Vdd 0 width 0 timing 0
[   18.259564] mmc0: SDHCI at 0x88089800 irq 23 DMA
[   18.259820] mmc0: clock 0Hz busmode 1 powermode 1 cs 0 Vdd 21 width 0 timing 0
[   18.261828] mmc0: clock 187500Hz busmode 1 powermode 2 cs 0 Vdd 21 width 0 timing 0
[   18.262095] ACPI: PCI Interrupt 0000:02:00.0[A] -> GSI 18 (level, low) -> IRQ 18
[   18.262274] PCI: Setting latency timer of device 0000:02:00.0 to 64
[   18.263735] iwl4965: Detected Intel Wireless WiFi Link 4965AGN
[   18.265293] mmc0: clock 187500Hz busmode 1 powermode 2 cs 1 Vdd 21 width 0 timing 0
[   18.266300] mmc0: starting CMD0 arg 00000000 flags 000000c0
[   18.266319] mmc0: req done (CMD0): -123: 00000000 00000000 00000000 00000000
[   18.266477] PCI: Enabling device 0000:00:1b.0 (0000 -> 0002)
[   18.266570] ACPI: PCI Interrupt 0000:00:1b.0[A] -> GSI 22 (level, low) -> IRQ 22
[   18.267476] PCI: Setting latency timer of device 0000:00:1b.0 to 64
[   18.268512] mmc0: clock 187500Hz busmode 1 powermode 2 cs 0 Vdd 21 width 0 timing 0
[   18.269521] mmc0: starting CMD8 arg 000001aa flags 000002f5
[   18.269536] mmc0: req done (CMD8): -123: 00000000 00000000 00000000 00000000
[   18.269542] mmc0: starting CMD5 arg 00000000 flags 000002e1
[   18.269554] mmc0: req failed (CMD5): -123, retrying...
[   18.269564] mmc0: req failed (CMD5): -123, retrying...
[   18.269574] mmc0: req failed (CMD5): -123, retrying...
[   18.269585] mmc0: req done (CMD5): -123: 00000000 00000000 00000000 00000000
[   18.269590] mmc0: starting CMD55 arg 00000000 flags 000000f5
[   18.269601] mmc0: req done (CMD55): -123: 00000000 00000000 00000000 00000000
[   18.269606] mmc0: starting CMD55 arg 00000000 flags 000000f5
[   18.269617] mmc0: req done (CMD55): -123: 00000000 00000000 00000000 00000000
[   18.269622] mmc0: starting CMD55 arg 00000000 flags 000000f5
[   18.269634] mmc0: req done (CMD55): -123: 00000000 00000000 00000000 00000000
[   18.269639] mmc0: starting CMD55 arg 00000000 flags 000000f5
[   18.269650] mmc0: req done (CMD55): -123: 00000000 00000000 00000000 00000000
[   18.269655] mmc0: starting CMD1 arg 00000000 flags 000000e1
[   18.269667] mmc0: req done (CMD1): -123: 00000000 00000000 00000000 00000000
[   18.269672] mmc0: clock 0Hz busmode 1 powermode 0 cs 0 Vdd 0 width 0 timing 0




[   43.040586] sdhci [sdhci_irq()]: *** sdhci:slot0 got interrupt: 0x00000040
[   43.050979] mmc0: clock 0Hz busmode 1 powermode 1 cs 0 Vdd 21 width 0 timing 0
[   43.052997] mmc0: clock 187500Hz busmode 1 powermode 2 cs 0 Vdd 21 width 0 timing 0
[   43.056012] mmc0: clock 187500Hz busmode 1 powermode 2 cs 1 Vdd 21 width 0 timing 0
[   43.057021] mmc0: starting CMD0 arg 00000000 flags 000000c0
[   43.057241] sdhci [sdhci_irq()]: *** sdhci:slot0 got interrupt: 0x00000001
[   43.057254] mmc0: req done (CMD0): 0: 00000000 00000000 00000000 00000000
[   43.058443] mmc0: clock 187500Hz busmode 1 powermode 2 cs 0 Vdd 21 width 0 timing 0
[   43.059454] mmc0: starting CMD8 arg 000001aa flags 000002f5
[   43.059624] sdhci [sdhci_irq()]: *** sdhci:slot0 got interrupt: 0x00018000
[   43.059638] mmc0: req done (CMD8): -110: 00000000 00000000 00000000 00000000
[   43.059830] mmc0: starting CMD5 arg 00000000 flags 000002e1
[   43.060076] sdhci [sdhci_irq()]: *** sdhci:slot0 got interrupt: 0x00018000
[   43.060090] mmc0: req failed (CMD5): -110, retrying...
[   43.060428] sdhci [sdhci_irq()]: *** sdhci:slot0 got interrupt: 0x00018000
[   43.060451] mmc0: req failed (CMD5): -110, retrying...
[   43.061426] sdhci [sdhci_irq()]: *** sdhci:slot0 got interrupt: 0x00018000
[   43.061443] mmc0: req failed (CMD5): -110, retrying...
[   43.062415] sdhci [sdhci_irq()]: *** sdhci:slot0 got interrupt: 0x00018000
[   43.062431] mmc0: req done (CMD5): -110: 00000000 00000000 00000000 00000000
[   43.062472] mmc0: starting CMD55 arg 00000000 flags 000000f5
[   43.062777] sdhci [sdhci_irq()]: *** sdhci:slot0 got interrupt: 0x00018000
[   43.062792] mmc0: req done (CMD55): -110: 00000000 00000000 00000000 00000000
[   43.062804] mmc0: starting CMD55 arg 00000000 flags 000000f5
[   43.063182] sdhci [sdhci_irq()]: *** sdhci:slot0 got interrupt: 0x00018000
[   43.063207] mmc0: req done (CMD55): -110: 00000000 00000000 00000000 00000000
[   43.063222] mmc0: starting CMD55 arg 00000000 flags 000000f5
[   43.064209] sdhci [sdhci_irq()]: *** sdhci:slot0 got interrupt: 0x00018000
[   43.064226] mmc0: req done (CMD55): -110: 00000000 00000000 00000000 00000000
[   43.064237] mmc0: starting CMD55 arg 00000000 flags 000000f5
[   43.065207] sdhci [sdhci_irq()]: *** sdhci:slot0 got interrupt: 0x00018000
[   43.065222] mmc0: req done (CMD55): -110: 00000000 00000000 00000000 00000000
[   43.065261] mmc0: starting CMD1 arg 00000000 flags 000000e1
[   43.065596] sdhci [sdhci_irq()]: *** sdhci:slot0 got interrupt: 0x00018000
[   43.065612] mmc0: req done (CMD1): -110: 00000000 00000000 00000000 00000000
[   43.065625] mmc0: clock 0Hz busmode 1 powermode 0 cs 0 Vdd 0 width 0 timing 0

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: Scheduler broken? sdhci issues with scheduling
  2008-02-29 19:39       ` Simon Huggins
@ 2008-02-29 20:39         ` Ingo Molnar
  2008-03-01 12:42           ` Simon Huggins
  0 siblings, 1 reply; 16+ messages in thread
From: Ingo Molnar @ 2008-02-29 20:39 UTC (permalink / raw)
  To: Simon Huggins; +Cc: linux-kernel, Thomas Gleixner


* Simon Huggins <huggie@earth.li> wrote:

> Hi Ingo,
> 
> (please cc me again)
> 
> On Fri, Feb 29, 2008 at 02:34:33PM +0100, Ingo Molnar wrote:
> > * Simon Huggins <huggie@earth.li> wrote:
> > > [ Please Cc me on replies ]
> > > I had a bug with sdhci which Pierre Ossman looked at for me.
> > > In the end essentially the fix was to use HZ=1000 and nothing else. 
> > > Pierre seemed to think that this was a bug in the scheduler.
> > does the patch below help, even if you keep HZ=100? This doesnt look 
> > like a scheduler issue, it's more of a timer/timing issue. Different HZ 
> > means different msleep() results - and the mmc code does a loop of small 
> > msleep delays.
> 
> Thanks for looking at it.
> 
> I did tests with 2.6.24.3 with HZ=1000 and HZ=100 and as expected the
> latter didn't work.
> 
> > -------------->
> > ---
> >  drivers/mmc/core/core.h |    7 +------
> >  1 file changed, 1 insertion(+), 6 deletions(-)
> 
> > Index: linux/drivers/mmc/core/core.h
> > ===================================================================
> > --- linux.orig/drivers/mmc/core/core.h
> > +++ linux/drivers/mmc/core/core.h
> > @@ -36,12 +36,7 @@ void mmc_set_timing(struct mmc_host *hos
> 
> >  static inline void mmc_delay(unsigned int ms)
> >  {
> > -	if (ms < 1000 / HZ) {
> > -		cond_resched();
> > -		mdelay(ms);
> > -	} else {
> > -		msleep(ms);
> > -	}
> > +	mdelay(ms);
> >  }
> 
> >  void mmc_rescan(struct work_struct *work);
> 
> That doesn't work.  I did a test with HZ=100 and this patch.  I've 
> attached the log as patch1-log.

> Anything else I can try?

so neither precise, nor imprecise timings help??

	Ingo

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: Scheduler broken? sdhci issues with scheduling
  2008-02-29 20:39         ` Ingo Molnar
@ 2008-03-01 12:42           ` Simon Huggins
  2008-03-01 14:08             ` Pierre Ossman
  0 siblings, 1 reply; 16+ messages in thread
From: Simon Huggins @ 2008-03-01 12:42 UTC (permalink / raw)
  To: Ingo Molnar; +Cc: linux-kernel, Thomas Gleixner, Pierre Ossman

(please cc me)

On Fri, Feb 29, 2008 at 09:39:14PM +0100, Ingo Molnar wrote:
> * Simon Huggins <huggie@earth.li> wrote:
> > On Fri, Feb 29, 2008 at 02:34:33PM +0100, Ingo Molnar wrote:
> > > * Simon Huggins <huggie@earth.li> wrote:
> > > > [ Please Cc me on replies ]
> > > > I had a bug with sdhci which Pierre Ossman looked at for me.
> > > > In the end essentially the fix was to use HZ=1000 and nothing else. 
> > > > Pierre seemed to think that this was a bug in the scheduler.
> > > does the patch below help, even if you keep HZ=100? This doesnt look 
> > > like a scheduler issue, it's more of a timer/timing issue. Different HZ 
> > > means different msleep() results - and the mmc code does a loop of small 
> > > msleep delays.
> > Thanks for looking at it.
> > I did tests with 2.6.24.3 with HZ=1000 and HZ=100 and as expected the
> > latter didn't work.
[..]
> > That doesn't work.  I did a test with HZ=100 and this patch.  I've 
> > attached the log as patch1-log.

> > Anything else I can try?
> so neither precise, nor imprecise timings help??

I don't know.  I don't really understand the patches I applied I'm
afraid; I'm just reporting the results.

I've cc'd Pierre Ossman so he might have a look from the sdhci point of
view.

Pierre, the thread starts here:
http://lkml.org/lkml/2008/2/29/118

Simon.

-- 
Just another wannabie |  "It's so nice to have a big   |  Just another fool
----------------------+ strong spud around the house." +-------------------
This message was brought to you by the letter E and the number 13.
htag.pl 0.0.22 -- http://www.earth.li/projectpurple/progs/htag.html

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: Scheduler broken? sdhci issues with scheduling
  2008-03-01 12:42           ` Simon Huggins
@ 2008-03-01 14:08             ` Pierre Ossman
  0 siblings, 0 replies; 16+ messages in thread
From: Pierre Ossman @ 2008-03-01 14:08 UTC (permalink / raw)
  To: Simon Huggins; +Cc: Ingo Molnar, linux-kernel, Thomas Gleixner

On Sat, 1 Mar 2008 12:42:04 +0000
Simon Huggins <huggie@earth.li> wrote:

> > so neither precise, nor imprecise timings help??
> 
> I don't know.  I don't really understand the patches I applied I'm
> afraid; I'm just reporting the results.
> 
> I've cc'd Pierre Ossman so he might have a look from the sdhci point of
> view.
> 
> Pierre, the thread starts here:
> http://lkml.org/lkml/2008/2/29/118
> 

I'm afraid I can't add that much...

Ingo, the basic problem is this:

The sdhci controllers are not supposed to signal "card insertion" before they have a stable connection with the card. But most (all?) hardware ignores this and signals immediately. This means we need a delay to handle bouncing connectors. This delay is supposed to be 500 ms, but on Simon's system it is in the order of tens of milliseconds.

The mechanism is not msleep(), nor mdelay(), but a delayed work queue. That's why I told Simon to talk to you as that seems like scheduler territory.

The call chain is:

1. sdhci_irq()
2. sdhci_tasklet_card() <- delay is calculated here
3. mmc_detect_change()
4. mmc_schedule_delayed_work()
5. queue_delayed_work()

msleep() and mdelay() are also affected, but this is the major symptom.

Rgds

-- 
     -- Pierre Ossman

  Linux kernel, MMC maintainer        http://www.kernel.org
  PulseAudio, core developer          http://pulseaudio.org
  rdesktop, core developer          http://www.rdesktop.org

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: Scheduler broken? sdhci issues with scheduling
  2008-02-29 11:52 Scheduler broken? sdhci issues with scheduling Simon Huggins
  2008-02-29 13:34 ` Ingo Molnar
@ 2008-03-02 10:40 ` Pavel Machek
  2008-03-02 18:04   ` Simon Huggins
  2008-03-03 19:43   ` Pierre Ossman
  1 sibling, 2 replies; 16+ messages in thread
From: Pavel Machek @ 2008-03-02 10:40 UTC (permalink / raw)
  To: huggie, linux-kernel

On Fri 2008-02-29 11:52:57, Simon Huggins wrote:
> [ Please Cc me on replies ]
> 
> I had a bug with sdhci which Pierre Ossman looked at for me.
> 
> In the end essentially the fix was to use HZ=1000 and nothing else.
> Pierre seemed to think that this was a bug in the scheduler.
> 
> I'm interested if someone who groks the scheduler could take a look at
> the mmc/* code and see if it's abusing HZ or if there's anything
> obviously wrong there.  If it's not then perhaps there really is a bug
> in the scheduler?

Is mmc slow or does it just break down? Slow would be expected, but
breaking down should be fixed in MMC, too...

-- 
(english) http://www.livejournal.com/~pavelmachek
(cesky, pictures) http://atrey.karlin.mff.cuni.cz/~pavel/picture/horses/blog.html

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: Scheduler broken? sdhci issues with scheduling
  2008-03-02 10:40 ` Pavel Machek
@ 2008-03-02 18:04   ` Simon Huggins
  2008-03-03 19:43   ` Pierre Ossman
  1 sibling, 0 replies; 16+ messages in thread
From: Simon Huggins @ 2008-03-02 18:04 UTC (permalink / raw)
  To: Pavel Machek; +Cc: linux-kernel

Hiya Pavel,

(please cc me)

On Sun, Mar 02, 2008 at 11:40:31AM +0100, Pavel Machek wrote:
> On Fri 2008-02-29 11:52:57, Simon Huggins wrote:
> > [ Please Cc me on replies ]
> > I had a bug with sdhci which Pierre Ossman looked at for me.
> > In the end essentially the fix was to use HZ=1000 and nothing else.
> > Pierre seemed to think that this was a bug in the scheduler.
> > I'm interested if someone who groks the scheduler could take a look at
> > the mmc/* code and see if it's abusing HZ or if there's anything
> > obviously wrong there.  If it's not then perhaps there really is a bug
> > in the scheduler?
> Is mmc slow or does it just break down? Slow would be expected, but
> breaking down should be fixed in MMC, too...

It just doesn't work.  It won't detect that a card has been inserted and
doesn't create the device nodes for it though it does log lots of data
where it tries.

Pierre explained further up this thread on why it tries to do what it
does but for some reason he's not seeing the expected behaviour from the
scheduler.

As a user I don't care where the bug is fixed :)

-- 
Simon Huggins  \ "Ah.  So you're a waffle man!" - Talkie Toaster
                \
http://www.earth.li/~huggie/                                htag.pl 0.0.22

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: Scheduler broken? sdhci issues with scheduling
  2008-03-02 10:40 ` Pavel Machek
  2008-03-02 18:04   ` Simon Huggins
@ 2008-03-03 19:43   ` Pierre Ossman
  2008-03-03 20:38     ` Pavel Machek
  1 sibling, 1 reply; 16+ messages in thread
From: Pierre Ossman @ 2008-03-03 19:43 UTC (permalink / raw)
  To: Pavel Machek; +Cc: huggie, linux-kernel

On Sun, 2 Mar 2008 11:40:31 +0100
Pavel Machek <pavel@ucw.cz> wrote:

> 
> Is mmc slow or does it just break down? Slow would be expected, but
> breaking down should be fixed in MMC, too...
> 

The problem is that the kernel sleeps _less_ than asked for, not more. No hardware can be expected to work if its needed delays aren't respected.

-- 
     -- Pierre Ossman

  Linux kernel, MMC maintainer        http://www.kernel.org
  PulseAudio, core developer          http://pulseaudio.org
  rdesktop, core developer          http://www.rdesktop.org

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: Scheduler broken? sdhci issues with scheduling
  2008-03-03 19:43   ` Pierre Ossman
@ 2008-03-03 20:38     ` Pavel Machek
  2008-03-03 21:05       ` Pierre Ossman
  0 siblings, 1 reply; 16+ messages in thread
From: Pavel Machek @ 2008-03-03 20:38 UTC (permalink / raw)
  To: Pierre Ossman; +Cc: huggie, linux-kernel

On Mon 2008-03-03 20:43:00, Pierre Ossman wrote:
> On Sun, 2 Mar 2008 11:40:31 +0100
> Pavel Machek <pavel@ucw.cz> wrote:
> 
> > 
> > Is mmc slow or does it just break down? Slow would be expected, but
> > breaking down should be fixed in MMC, too...
> > 
> 
> The problem is that the kernel sleeps _less_ than asked for, not more. No hardware can be expected to work if its needed delays aren't respected.
> 

Oops, that's bad. Can you perhaps create small testcase for
scheduler/timer people to play with?

Also... you may want to switch timesources. notsc fixed "wait for much
too long" for me.
								Pavel
-- 
(english) http://www.livejournal.com/~pavelmachek
(cesky, pictures) http://atrey.karlin.mff.cuni.cz/~pavel/picture/horses/blog.html

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: Scheduler broken? sdhci issues with scheduling
  2008-03-03 20:38     ` Pavel Machek
@ 2008-03-03 21:05       ` Pierre Ossman
  2008-03-13 21:17         ` Simon Huggins
  0 siblings, 1 reply; 16+ messages in thread
From: Pierre Ossman @ 2008-03-03 21:05 UTC (permalink / raw)
  To: Pavel Machek; +Cc: huggie, linux-kernel

On Mon, 3 Mar 2008 21:38:08 +0100
Pavel Machek <pavel@ucw.cz> wrote:

> On Mon 2008-03-03 20:43:00, Pierre Ossman wrote:
> > The problem is that the kernel sleeps _less_ than asked for, not more. No hardware can be expected to work if its needed delays aren't respected.
> > 
> 
> Oops, that's bad. Can you perhaps create small testcase for
> scheduler/timer people to play with?
> 
> Also... you may want to switch timesources. notsc fixed "wait for much
> too long" for me.

I'm afraid I could never reproduce the problem. So it's Simon that will have to do the tests for now..


-- 
     -- Pierre Ossman

  Linux kernel, MMC maintainer        http://www.kernel.org
  PulseAudio, core developer          http://pulseaudio.org
  rdesktop, core developer          http://www.rdesktop.org

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: Scheduler broken? sdhci issues with scheduling
  2008-03-03 21:05       ` Pierre Ossman
@ 2008-03-13 21:17         ` Simon Huggins
  2008-03-15 15:04           ` Pierre Ossman
  0 siblings, 1 reply; 16+ messages in thread
From: Simon Huggins @ 2008-03-13 21:17 UTC (permalink / raw)
  To: Pierre Ossman; +Cc: Pavel Machek, linux-kernel

'ello Pierre

On Mon, Mar 03, 2008 at 10:05:30PM +0100, Pierre Ossman wrote:
> On Mon, 3 Mar 2008 21:38:08 +0100
> Pavel Machek <pavel@ucw.cz> wrote:
> > On Mon 2008-03-03 20:43:00, Pierre Ossman wrote:
> > > The problem is that the kernel sleeps _less_ than asked for, not more. No hardware can be expected to work if its needed delays aren't respected.
> > Oops, that's bad. Can you perhaps create small testcase for
> > scheduler/timer people to play with?
> > Also... you may want to switch timesources. notsc fixed "wait for much
> > too long" for me.
> I'm afraid I could never reproduce the problem. So it's Simon that
> will have to do the tests for now..

I'm happy to test bits.  What do I need to do to switch time sources for
instance?


Simon

-- 
... <ICv6> note pour plus tard... jamais paster un /quit dans un client irc
    =)

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: Scheduler broken? sdhci issues with scheduling
  2008-03-13 21:17         ` Simon Huggins
@ 2008-03-15 15:04           ` Pierre Ossman
  2008-04-20 21:07             ` Simon Huggins
  0 siblings, 1 reply; 16+ messages in thread
From: Pierre Ossman @ 2008-03-15 15:04 UTC (permalink / raw)
  To: Simon Huggins; +Cc: Pavel Machek, linux-kernel

On Thu, 13 Mar 2008 21:17:49 +0000
Simon Huggins <huggie@earth.li> wrote:

> 
> I'm happy to test bits.  What do I need to do to switch time sources for
> instance?
> 

I'm no expert, but you have the kernel parameter "clocksource" documented in Documentation/kernel-parameters. Also check the directory /sys/devices/system/clocksource for assorted runtime changes.

Rgds
-- 
     -- Pierre Ossman

  Linux kernel, MMC maintainer        http://www.kernel.org
  PulseAudio, core developer          http://pulseaudio.org
  rdesktop, core developer          http://www.rdesktop.org

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: Scheduler broken? sdhci issues with scheduling
  2008-03-15 15:04           ` Pierre Ossman
@ 2008-04-20 21:07             ` Simon Huggins
  0 siblings, 0 replies; 16+ messages in thread
From: Simon Huggins @ 2008-04-20 21:07 UTC (permalink / raw)
  To: Pierre Ossman; +Cc: Pavel Machek, linux-kernel

Hi Pierre,

On Sat, Mar 15, 2008 at 04:04:28PM +0100, Pierre Ossman wrote:
> On Thu, 13 Mar 2008 21:17:49 +0000
> Simon Huggins <huggie@earth.li> wrote:
> > I'm happy to test bits.  What do I need to do to switch time sources for
> > instance?
> I'm no expert, but you have the kernel parameter "clocksource" documented in Documentation/kernel-parameters. Also check the directory /sys/devices/system/clocksource for assorted runtime changes.

Sorry it took so long.

I'm defaulting to hpet but if I try changing clocksource to tsc, jiffies
or acpi_pm with any of the patches at runtime or rebooting it seems to
make no difference and sdhci doesn't work as before.

I tried 2.6.25 too and it's the same story.

I guess I'll just keep HZ=1000.

-- 
 ,--huggie-at-earth-dot-li--------stuff-thing-stuff----------DF5CE2B4--.
_|   "An excellent suggestion sir, with only two minor flaws...." -    |_
 |                               Kryten                                |
 `-------------------- http://www.earth.li/~huggie/ -------------------'

^ permalink raw reply	[flat|nested] 16+ messages in thread

end of thread, other threads:[~2008-04-20 21:38 UTC | newest]

Thread overview: 16+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2008-02-29 11:52 Scheduler broken? sdhci issues with scheduling Simon Huggins
2008-02-29 13:34 ` Ingo Molnar
2008-02-29 13:51   ` Ingo Molnar
2008-02-29 14:00     ` Ingo Molnar
2008-02-29 19:39       ` Simon Huggins
2008-02-29 20:39         ` Ingo Molnar
2008-03-01 12:42           ` Simon Huggins
2008-03-01 14:08             ` Pierre Ossman
2008-03-02 10:40 ` Pavel Machek
2008-03-02 18:04   ` Simon Huggins
2008-03-03 19:43   ` Pierre Ossman
2008-03-03 20:38     ` Pavel Machek
2008-03-03 21:05       ` Pierre Ossman
2008-03-13 21:17         ` Simon Huggins
2008-03-15 15:04           ` Pierre Ossman
2008-04-20 21:07             ` Simon Huggins

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).