macbook pro dvd playback after suspend Buffer I/O error

Previous thread: Re: Access to struct file in scsi_request_fn()? by Robert Hancock on Thursday, April 3, 2008 - 9:20 pm. (1 message)

Next thread: [git patches] net driver fixes by Jeff Garzik on Thursday, April 3, 2008 - 11:33 pm. (3 messages)
From: Justin Mattock
Date: Thursday, April 3, 2008 - 10:07 pm

When playing a DVD and then suspending the system while the DVD is
still in play, upon wakeup I'm receiving a Buffer I/O error on device
sr0, logical block 356490.
the DVD will continue to play but then gmplayer complains: Warning!
FPS changed 23.976 -> 29.970 (-5.994005) [4] then the video becomes
very choppy. When looking at osx in the same test the DVD will be
paused until the cd player aligns itself, then playback will start.
With looking further at this I think this is an issue of a library or
codec, So with this in mind is there a package that I might look at to
see if this resolves the issue. Attached is dmesg of the Buffer I/O
regards;

-- 
Justin P. Mattock
From: Andrew Morton
Date: Friday, April 4, 2008 - 1:21 am

An ata thing, I assume.  Let's cc linux-ide.

> [  149.767228] hiddev0: US
From: Justin Mattock
Date: Friday, April 4, 2008 - 8:05 am

Hello; One thing that I noticed with previous kernels is when you put
in the DVD and press play(a few seconds after inserting a DVD), the
player will think for a few seconds then start playback(without a
Buffer error), but I noticed with 2.6.25-rc1 you have to wait for the
cd player to read the DVD then align itself and settle down before
pressing play to avoid the Buffer error.(in the past I was using
2.6.23, then moved to 2.6.24(for a few days and didnt notice,then
reverted to 2.6.23,then went to 2.6.25-rc1 once on 2.5.25-rc1, I
noticed the error. So with all honesty I'm not too sure where this
might be at)
regards;
                Justin P. Mattock

>  > [  148.668896] PM: Writing back config space on device 0000:03:00.0 at offset 1 (was 10000
From: Tejun Heo
Date: Tuesday, June 10, 2008 - 7:00 pm

This is due to UNIT ATTENTION condition triggered by reset during
resume.  The following patches should fix it.

http://marc.info/?l=linux-ide&m=121309016918976&w=2
http://marc.info/?l=linux-ide&m=121309016918979&w=2

Thanks.

-- 
tejun
--

From: Justin Mattock
Date: Wednesday, June 11, 2008 - 12:45 am

alright!! I'll give that a test and see; give me some time right now
it's midnight, and a couple of beer's in; so doing anything that
requires
thinking isn't going to happen, but tomorrow it will.
regards;

-- 
Justin P. Mattock
--

From: Justin Mattock
Date: Wednesday, June 11, 2008 - 11:31 am

O.K. I applied the patch here is what I'm seeing:

[  920.237141] end_request: I/O error, dev sr0, sector 2931560
[  920.237141] Buffer I/O error on device sr0, logical block 366445
[  920.237141] Buffer I/O error on device sr0, logical block 366446
[  920.237141] Buffer I/O error on device sr0, logical block 366447
[  920.237141] Buffer I/O error on device sr0, logical block 366448
[  920.237141] Buffer I/O error on device sr0, logical block 366449
[  920.237141] Buffer I/O error on device sr0, logical block 366450
[  920.237141] Buffer I/O error on device sr0, logical block 366451
[  920.237141] Buffer I/O error on device sr0, logical block 366452
[  920.237141] Buffer I/O error on device sr0, logical block 366453
[  920.237141] Buffer I/O error on device sr0, logical block 366454
[  925.431105] __ratelimit: 10100 messages suppressed
[  925.431118] Buffer I/O error on device sr0, logical block 371516
[  930.772658] __ratelimit: 2407 messages suppressed
[  930.772658] Buffer I/O error on device sr0, logical block 372720
[  935.674943] __ratelimit: 6995 messages suppressed
[  935.674955] Buffer I/O error on device sr0, logical block 376218
[  940.685317] __ratelimit: 16949 messages suppressed
[  940.685329] Buffer I/O error on device sr0, logical block 384693
[  945.770547] __ratelimit: 17881 messages suppressed
[  945.770558] Buffer I/O error on device sr0, logical block 393634
[  950.777243] __ratelimit: 19031 messages suppressed
[  950.777243] Buffer I/O error on device sr0, logical block 403150
[  955.788427] __ratelimit: 19035 messages suppressed
[  955.788439] Buffer I/O error on device sr0, logical block 412668
[  961.575327] __ratelimit: 16603 messages suppressed
[  961.575338] Buffer I/O error on device sr0, logical block 420970
[ 1006.919733] __ratelimit: 9315 messages suppressed

Almost as if the drive is taking to long to think, by then the cache
has run out, and the FPS changes,
the movie itself doesn't become choppy like before, just freezes.
If you have any ...
From: Tejun Heo
Date: Wednesday, June 11, 2008 - 2:51 pm

Eh.... strange.  Can you post full kernel log?  And does the dvd work if
you restart playing?

-- 
tejun
--

From: Justin Mattock
Date: Wednesday, June 11, 2008 - 3:27 pm

O.K. attached is dmesg of playing a dvd, then suspending and wakingup,
as well as starting after the buffer error.(audit messages)
This is interesting, even  pausing the dvd before suspending, causes
the same error.
I sent a post to mplayer-users to see if there is a way to have
mplayer pause and wait for the disk drive to align, but am still
waiting
for a response.
regards.
-- 
Justin P. Mattock
From: Tejun Heo
Date: Wednesday, June 11, 2008 - 6:18 pm

Can you please do the followings?

1. dd if=/dev/sr0 of=/dev/null bs=1M
2. suspend / resume
3. see whether dd fails and post the resulting dmesg.

Thanks.

-- 
tejun
--

From: Justin Mattock
Date: Wednesday, June 11, 2008 - 7:10 pm

Hello; I did what you had suggested(twice below is the first,same
results with second)
 upon wakeup dd just quits giving me this:

dd: reading `/dev/sr0': Input/output error
3+1 records in
3+1 records out
3276800 bytes (3.3 MB) copied, 21.834 seconds, 150 kB/s

And under dmesg:
[  329.596421] end_request: I/O error, dev sr0, sector 6400
[  329.596437] Buffer I/O error on device sr0, logical block 800
[  329.596903] Buffer I/O error on device sr0, logical block 833
[  329.596912] Buffer I/O error on device sr0, logical block 834
[  329.596919] Buffer I/O error on device sr0, logical block 835
[  329.596926] Buffer I/O error on device sr0, logical block 836
[  329.596934] Buffer I/O error on device sr0, logical block 837
[  329.596941] Buffer I/O error on device sr0, logical block 838
[  329.596949] Buffer I/O error on device sr0, logical block 839
[  329.596956] Buffer I/O error on device sr0, logical block 840
[  329.596963] Buffer I/O error on device sr0, logical block 841

regards;


-- 
Justin P. Mattock
--

From: Justin Mattock
Date: Wednesday, June 11, 2008 - 7:13 pm

Heres dmesg:
(forgot to attach)
-- 
Justin P. Mattock
From: Tejun Heo
Date: Wednesday, June 11, 2008 - 9:15 pm

Hello,

Please do the followings.

1. apply the attached patch
2. turn on device drivers -> SCSI -> SCSI verbose logging
3. rebuild the kernel and boot the new kernel.
4. run "sysctl -w dev.scsi.logging_level=1"
5. run the suspend/resume test w/ dd and report the result.

Thanks.

-- 
tejun
From: Justin Mattock
Date: Wednesday, June 11, 2008 - 10:22 pm

Alright; I'll let you know what happens.
regards;

-- 
Justin P. Mattock
--

From: Justin Mattock
Date: Wednesday, June 11, 2008 - 11:15 pm

O.K. applied the patch and did what you have described,(except for
sysctl -w / ended up inserting dev.scsi.logging_level=1 in
/etc/sysctl.conf)
This is what dd reported:(same as before)
dd: reading `/dev/sr0':Input/output error
41+1 records in
41+1 records out
43122688 bytes (43 MB) copied, 41.0967 seconds, 1.0 MB/s

Attached is dmesg of using dd on the first suspend, and playing a dvd
on the second.
regards;

-- 
Justin P. Mattock
From: Tejun Heo
Date: Wednesday, June 11, 2008 - 11:26 pm

Ah.. okay.  The drive was becoming ready and the read commands were
retried too fast.  The drive I tested on was fast enough to deliver the
data but yours wasn't.  Hmmm.... This is difficult.  This also poses
problems to live cd distros, I think.  We probably need to make sr wait
for device readiness.  Maybe it's best to put TUR waiting in read error
handling.  I'll think about it.

Thanks.

-- 
tejun
--

From: Justin Mattock
Date: Wednesday, June 11, 2008 - 11:36 pm

Yeah, take you're time. Maybe it's easier  to have mplayer or which
ever media player wait for the drive. i.g.
under OSX, the media player pauses until the drive does it's thing,
and then resumes.(but this would be for the suspend aspect)
As for the live distro part I'd have to think as well. Let me know
what you think.
regards;
-- 
Justin P. Mattock
--

From: Tejun Heo
Date: Wednesday, June 11, 2008 - 11:59 pm

For apps which know they're accessing cd or dvd (probably using sg
commands), asking for TUR test after resume could be acceptable but apps
getting -EIO on read(2) because of intervening suspend/resume cycle is
just not right.  The problem is that readiness waiting can take quite
some time and under the current architecture, that can make resume take
much longer or block IOs to other devices on the same port.  :-(

-- 
tejun
--

From: Justin Mattock
Date: Thursday, June 12, 2008 - 12:45 am

From what I could tell it's the whole start, think, move a little,
then start spinning, then slow down, then finally locate it's place,
that the drive
is doing that's causing the timing to be out of sync, with what's left
in the cache/or memory,  I'm wondering if its possible to have the
disk not do the whole cycle that it does once suspend/resume is
activated, just to see.
regards;

-- 
Justin P. Mattock
--

Previous thread: Re: Access to struct file in scsi_request_fn()? by Robert Hancock on Thursday, April 3, 2008 - 9:20 pm. (1 message)

Next thread: [git patches] net driver fixes by Jeff Garzik on Thursday, April 3, 2008 - 11:33 pm. (3 messages)