The only difference is that the wait channel on 2.4.x is listed as "lock_p"
but on 2.5.52 it's listed as "io_sch".
Linux stark.dyndns.tv 2.5.52 #5 Sat Dec 21 12:07:03 EST 2002 i686 unknown unknown GNU/Linux
The device it's reading from is /dev/hdd. DMA is enabled on all the ide
devices.
The following is output from ogle, combined with stracing the process that
blocks grepping for syscalls taking over a second to return, combined with
running ps on the same process grepping for it not blocking on msgrcv which is
the normal synchronization primitive ogle uses.
As you can see, every time ogle gets out of sync and prints the message about
"resyncing" it's following ogle_mpeg_ps blocking in a read syscall waiting on
"io_sch".
The only suggestion I've heard so far is that the DVD-Rom is bad. But to
confirm that I would need some data from the ide driver. As it is there are no
ide errors in the kernel log, no information from the driver on what operation
was being attempted and took inordinately long to complete. Nothing to report
to the vendor as evidence of a hardware defect.
Someone suggested I try raw devices. Is that possible for cdrom devices? Where
do I find the raw devices?
display: frame rate: 22.891 fps
0 T stark 18562 18559 2 76 0 - 2399 syscal 18:24 pts/6 00:00:07 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:07 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:07 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:07 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:07 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:07 ogle_mpeg_ps -m 32768
read(3, "\0\0\1\272D\32\334\253\345\231\1\211\303\370\0\0\1\340"..., 487424) = 487424 <1.596222>
Debug[ogle_audio]: 1.+084663240 s off, resyncing
!0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:07 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:07 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:07 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:07 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:07 ogle_mpeg_ps -m 32768
read(3, "\0\0\1\272D\33\16\373\364\241\1\211\303\370\0\0\1\340\7"..., 532480) = 532480 <1.602640>
Debug[ogle_audio]: 1.+297135680 s off, resyncing
display: frame rate: 18.582 fps
display: frame rate: 23.977 fps
display: frame rate: 24.000 fps
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
display: frame rate: 23.951 fps
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
read(3, "\0\0\1\272D\35^\321\f\361\1\211\303\370\0\0\1\340\7\354"..., 323584) = 323584 <1.287339>
Debug[ogle_audio]: 0.+879741440 s off, resyncing
0 T stark 18562 18559 2 76 0 - 2399 syscal 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
read(3, "\0\0\1\272D\35\214z\366I\1\211\303\370\0\0\1\340\7\354"..., 323584) = 323584 <1.171526>
Debug[ogle_audio]: 0.+485963520 s off, resyncing
read(3, "\0\0\1\272D\35\254\331\356E\1\211\303\370\0\0\1\340\7\354"..., 325632) = 325632 <0.109438>
0 T stark 18562 18559 2 76 0 - 2399 syscal 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
read(3, "\0\0\1\272D\35\277\375\324\235\1\211\303\370\0\0\1\340"..., 339968) = 339968 <1.068391>
Debug[ogle_audio]: 0.+381795280 s off, resyncing
0 R stark 18562 18559 2 76 0 - 2399 - 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
read(3, "\0\0\1\272D\35\356\21%\225\1\211\303\370\0\0\1\340\7\354"..., 421888) = 421888 <1.126259>
Debug[ogle_audio]: 0.+381624160 s off, resyncing
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
read(3, "\0\0\1\272D\36\6\10\315A\1\211\303\370\0\0\1\340\7\354"..., 423936) = 423936 <1.593315>
Debug[ogle_audio]: 1.+098514880 s off, resyncing
0 T stark 18562 18559 2 75 0 - 2399 syscal 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
display: frame rate: 17.287 fps
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
read(3, "\0\0\1\272D\36&%\\\225\1\211\303\370\0\0\1\340\7\354\201"..., 378880) = 378880 <1.295461>
##Debug[ogle_audio]: 0.+731835080 s off, resyncing
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
read(3, "\0\0\1\272D\36]\272}\231\1\211\303\370\0\0\1\340\7\354"..., 501760) = 501760 <1.071489>
##Debug[ogle_audio]: 0.+521272280 s off, resyncing
0 T stark 18562 18559 2 76 0 - 2399 syscal 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
read(3, "\0\0\1\272D\36tZ\275I\1\211\303\370\0\0\1\340\7\354\201"..., 362496) = 362496 <1.581139>
##Debug[ogle_audio]: 1.+038802240 s off, resyncing
Debug[ogle_audio]: 0.+024722640 s off, resyncing
0 R stark 18562 18559 2 76 0 - 2399 - 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
read(3, "\0\0\1\272D\36}\276\365\361\1\211\303\370\0\0\1\340\7\354"..., 356352) = 356352 <1.438772>
##Debug[ogle_audio]: 1.+115369160 s off, resyncing
read(3, "\0\0\1\272D\36\2070\346E\1\211\303\370\0\0\1\340\7\354"..., 354304) = 354304 <0.136682>
0 T stark 18562 18559 2 75 0 - 2399 syscal 18:24 pts/6 00:00:08 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:09 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:09 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:09 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:09 ogle_mpeg_ps -m 32768
0 D stark 18562 18559 2 75 0 - 2399 io_sch 18:24 pts/6 00:00:09 ogle_mpeg_ps -m 32768
read(3, "\0\0\1\272D\36\2472\6A\1\211\303\370\0\0\1\340\7\354\201"..., 561152) = 561152 <1.575937>
##Debug[ogle_audio]: 0.+879007520 s off, resyncing
-- greg- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/