buffer starvation when recording DVDs

Alexander Best alexbestms at uni-muenster.de
Wed Jul 14 21:57:19 UTC 2010


2010/7/14 Paul B Mahol <onemda at gmail.com>:
> On 7/14/10, Alexander Best <alexbestms at uni-muenster.de> wrote:
>> 2010/7/14 Paul B Mahol <onemda at gmail.com>:
>>> On Wed, Jul 14, 2010 at 1:25 PM, Alexander Best
>>> <alexbestms at uni-muenster.de> wrote:
>>>> 2010/7/14 Paul B Mahol <onemda at gmail.com>:
>>>>> On Wed, Jul 14, 2010 at 12:46 PM, Alexander Best
>>>>> <alexbestms at uni-muenster.de> wrote:
>>>>>> 2010/7/14 Alexander Best <alexbestms at uni-muenster.de>:
>>>>>>> hi there,
>>>>>>>
>>>>>>> my dvdr drive supports recording DVDs (both DVD-Rs and DVD+Rs) at a
>>>>>>> maximum speed of 16x. however at speeds of more than ~12x the burner's
>>>>>>> buffer get's filled only ~20%. probably that's why the burner's speed
>>>>>>> get's reduced by `growisofs` (to prevent buffer starvation?). how can
>>>>>>> this happen? the iso i am using lies on my HDD which is quite fast
>>>>>>> (connected via SATA 2.0).
>>>>>>>
>>>>>>> this is the output of `camcontrol devlist -v`:
>>>>>>>
>>>>>>> scbus0 on ahcich0 bus 0:
>>>>>>> <>                                 at scbus0 target -1 lun -1 ()
>>>>>>> scbus1 on ahcich1 bus 0:
>>>>>>> <>                                 at scbus1 target -1 lun -1 ()
>>>>>>> scbus2 on ata2 bus 0:
>>>>>>> <HL-DT-ST DVDRAM GSA-H10N JL12>    at scbus2 target 0 lun 0
>>>>>>> (cd0,pass0)
>>>>>>> <>                                 at scbus2 target -1 lun -1 ()
>>>>>>> scbus3 on ahcich2 bus 0:
>>>>>>> <SAMSUNG SP2504C VT100-50>         at scbus3 target 0 lun 0
>>>>>>> (ada0,pass1)
>>>>>>> <>                                 at scbus3 target -1 lun -1 ()
>>>>>>> scbus4 on ahcich3 bus 0:
>>>>>>> <>                                 at scbus4 target -1 lun -1 ()
>>>>>>> scbus5 on ahcich4 bus 0:
>>>>>>> <>                                 at scbus5 target -1 lun -1 ()
>>>>>>> scbus6 on ahcich5 bus 0:
>>>>>>> <>                                 at scbus6 target -1 lun -1 ()
>>>>>>> scbus7 on ahcich6 bus 0:
>>>>>>> <>                                 at scbus7 target -1 lun -1 ()
>>>>>>> scbus8 on ahcich7 bus 0:
>>>>>>> <>                                 at scbus8 target -1 lun -1 ()
>>>>>>> scbus-1 on xpt0 bus 0:
>>>>>>> <>                                 at scbus-1 target -1 lun -1 (xpt0)
>>>>>>>
>>>>>>> as you can see cd0 and ada0 don't share the same cable (cd0 is PATA,
>>>>>>> ada0 is SATA). the PATA and SATA controllers are:
>>>>>>>
>>>>>>> atapci0: <JMicron JMB363 UDMA133 controller> port
>>>>>>> 0xd000-0xd007,0xd100-0xd103,0xd200-0xd207,0xd300-0xd303,0xd400-0xd40f
>>>>>>> irq 16 at device 0.1 on pci3
>>>>>>>
>>>>>>> ahci0: <JMicron JMB363 AHCI SATA controller> mem 0xf8000000-0xf8001fff
>>>>>>> irq 19 at device 0.0 on pci3
>>>>>>
>>>>>> sorry for the wrong information. just realized my HDD is connected to
>>>>>> the intel controller!
>>>>>>
>>>>>>>
>>>>>>> this is the output of `growisofs`:
>>>>>>>
>>>>>>> Executing 'builtin_dd if=new.iso of=/dev/pass0 obs=32k seek=0'
>>>>>>> /dev/pass0: "Current Write Speed" is 16.4x1352KBps.
>>>>>>>          0/4695924736 ( 0.0%) @0x, remaining ??:?? RBU 100.0% UBU
>>>>>>> 0.0%
>>>>>>>          0/4695924736 ( 0.0%) @0x, remaining ??:?? RBU 100.0% UBU
>>>>>>> 0.0%
>>>>>>>          0/4695924736 ( 0.0%) @0x, remaining ??:?? RBU 100.0% UBU
>>>>>>> 0.0%
>>>>>>>          0/4695924736 ( 0.0%) @0x, remaining ??:?? RBU 100.0% UBU
>>>>>>> 0.0%
>>>>>>>          0/4695924736 ( 0.0%) @0x, remaining ??:?? RBU 100.0% UBU
>>>>>>> 0.0%
>>>>>>>          0/4695924736 ( 0.0%) @0x, remaining ??:?? RBU 100.0% UBU
>>>>>>> 0.0%
>>>>>>>          0/4695924736 ( 0.0%) @0x, remaining ??:?? RBU 100.0% UBU
>>>>>>> 0.0%
>>>>>>>    1114112/4695924736 ( 0.0%) @0.2x, remaining 2036:44 RBU 100.0% UBU
>>>>>>>   2.9%
>>>>>>>    1114112/4695924736 ( 0.0%) @0.0x, remaining 2247:26 RBU 100.0% UBU
>>>>>>> 100.0%
>>>>>>>   19365888/4695924736 ( 0.4%) @4.0x, remaining 144:53 RBU 100.0% UBU
>>>>>>> 100.0%
>>>>>>>   52789248/4695924736 ( 1.1%) @7.2x, remaining 57:10 RBU  99.9% UBU
>>>>>>> 100.0%
>>>>>>>   86736896/4695924736 ( 1.8%) @7.4x, remaining 37:11 RBU 100.0% UBU
>>>>>>> 100.0%
>>>>>>>  121241600/4695924736 ( 2.6%) @7.5x, remaining 28:55 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  156336128/4695924736 ( 3.3%) @7.6x, remaining 23:42 RBU  99.9% UBU
>>>>>>>  97.1%
>>>>>>>  191954944/4695924736 ( 4.1%) @7.7x, remaining 20:20 RBU 100.0% UBU
>>>>>>> 100.0%
>>>>>>>  228130816/4695924736 ( 4.9%) @7.8x, remaining 18:16 RBU 100.0% UBU
>>>>>>> 100.0%
>>>>>>>  264863744/4695924736 ( 5.6%) @8.0x, remaining 16:27 RBU 100.0% UBU
>>>>>>> 100.0%
>>>>>>>  298352640/4695924736 ( 6.4%) @7.3x, remaining 15:13 RBU 100.0% UBU
>>>>>>> 100.0%
>>>>>>>  336134144/4695924736 ( 7.2%) @8.2x, remaining 14:16 RBU 100.0% UBU
>>>>>>> 100.0%
>>>>>>>  374505472/4695924736 ( 8.0%) @8.3x, remaining 13:16 RBU 100.0% UBU
>>>>>>> 100.0%
>>>>>>>  413401088/4695924736 ( 8.8%) @8.4x, remaining 12:25 RBU  99.9% UBU
>>>>>>> 100.0%
>>>>>>>  452886528/4695924736 ( 9.6%) @8.6x, remaining 11:52 RBU 100.0% UBU
>>>>>>> 100.0%
>>>>>>>  492896256/4695924736 (10.5%) @8.7x, remaining 11:13 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  533495808/4695924736 (11.4%) @8.8x, remaining 10:39 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  574619648/4695924736 (12.2%) @8.9x, remaining 10:16 RBU  99.7% UBU
>>>>>>> 100.0%
>>>>>>>  616333312/4695924736 (13.1%) @9.0x, remaining 9:49 RBU  99.9% UBU
>>>>>>>  97.1%
>>>>>>>  658538496/4695924736 (14.0%) @9.1x, remaining 9:24 RBU 100.0% UBU
>>>>>>>  94.1%
>>>>>>>  701366272/4695924736 (14.9%) @9.3x, remaining 9:06 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  744751104/4695924736 (15.9%) @9.4x, remaining 8:45 RBU  99.9% UBU
>>>>>>>  97.1%
>>>>>>>  788660224/4695924736 (16.8%) @9.5x, remaining 8:25 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  833159168/4695924736 (17.7%) @9.6x, remaining 8:11 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  878182400/4695924736 (18.7%) @9.8x, remaining 7:53 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  923762688/4695924736 (19.7%) @9.9x, remaining 7:37 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  969932800/4695924736 (20.7%) @10.0x, remaining 7:25 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  1011908608/4695924736 (21.5%) @9.1x, remaining 7:13 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  1059094528/4695924736 (22.6%) @10.2x, remaining 6:58 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  1106903040/4695924736 (23.6%) @10.4x, remaining 6:48 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  1155203072/4695924736 (24.6%) @10.5x, remaining 6:35 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  1204092928/4695924736 (25.6%) @10.6x, remaining 6:22 RBU  99.9% UBU
>>>>>>>  97.1%
>>>>>>>  1253507072/4695924736 (26.7%) @10.7x, remaining 6:13 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  1303511040/4695924736 (27.8%) @10.8x, remaining 6:01 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  1354039296/4695924736 (28.8%) @10.9x, remaining 5:50 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  1405124608/4695924736 (29.9%) @11.1x, remaining 5:41 RBU 100.0% UBU
>>>>>>>  91.2%
>>>>>>>  1456832512/4695924736 (31.0%) @11.2x, remaining 5:31 RBU  99.9% UBU
>>>>>>>  97.1%
>>>>>>>  1509031936/4695924736 (32.1%) @11.3x, remaining 5:21 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  1561821184/4695924736 (33.3%) @11.4x, remaining 5:13 RBU  99.9% UBU
>>>>>>>  97.1%
>>>>>>>  1615134720/4695924736 (34.4%) @11.6x, remaining 5:03 RBU 100.0% UBU
>>>>>>>  91.2%
>>>>>>>  1669005312/4695924736 (35.5%) @11.7x, remaining 4:53 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  1723465728/4695924736 (36.7%) @11.8x, remaining 4:46 RBU 100.0% UBU
>>>>>>>  91.2%
>>>>>>>  1778417664/4695924736 (37.9%) @11.9x, remaining 4:37 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  1834024960/4695924736 (39.1%) @12.0x, remaining 4:28 RBU  99.5% UBU
>>>>>>>  97.1%
>>>>>>>  1884389376/4695924736 (40.1%) @10.9x, remaining 4:22 RBU 100.0% UBU
>>>>>>>  47.1%
>>>>>>>  1941012480/4695924736 (41.3%) @12.3x, remaining 4:14 RBU  99.9% UBU
>>>>>>>  97.1%
>>>>>>>  1998159872/4695924736 (42.6%) @12.4x, remaining 4:05 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  2055897088/4695924736 (43.8%) @12.5x, remaining 3:58 RBU  96.6% UBU
>>>>>>>  94.1%
>>>>>>>  2113961984/4695924736 (45.0%) @12.6x, remaining 3:50 RBU 100.0% UBU
>>>>>>>  82.4%
>>>>>>>  2172977152/4695924736 (46.3%) @12.8x, remaining 3:42 RBU 100.0% UBU
>>>>>>>  79.4%
>>>>>>>  2232188928/4695924736 (47.5%) @12.8x, remaining 3:36 RBU 100.0% UBU
>>>>>>>  79.4%
>>>>>>>  2292154368/4695924736 (48.8%) @13.0x, remaining 3:28 RBU 100.0% UBU
>>>>>>>  73.5%
>>>>>>>  2352218112/4695924736 (50.1%) @13.0x, remaining 3:21 RBU  99.9% UBU
>>>>>>>  41.2%
>>>>>>>  2406875136/4695924736 (51.3%) @11.8x, remaining 3:15 RBU 100.0% UBU
>>>>>>>  23.5%
>>>>>>>  2462351360/4695924736 (52.4%) @12.0x, remaining 3:09 RBU 100.0% UBU
>>>>>>>  20.6%
>>>>>>>  2512650240/4695924736 (53.5%) @10.9x, remaining 3:04 RBU 100.0% UBU
>>>>>>>  20.6%
>>>>>>>  2568781824/4695924736 (54.7%) @12.2x, remaining 2:58 RBU  99.8% UBU
>>>>>>>  20.6%
>>>>>>>  2625634304/4695924736 (55.9%) @12.3x, remaining 2:52 RBU  99.9% UBU
>>>>>>>  20.6%
>>>>>>>  2682814464/4695924736 (57.1%) @12.4x, remaining 2:46 RBU 100.0% UBU
>>>>>>>  20.6%
>>>>>>>  2740486144/4695924736 (58.4%) @12.5x, remaining 2:41 RBU  99.9% UBU
>>>>>>>  20.6%
>>>>>>>  2785411072/4695924736 (59.3%) @9.7x, remaining 2:37 RBU  99.5% UBU
>>>>>>>  20.6%
>>>>>>>  2840920064/4695924736 (60.5%) @12.0x, remaining 2:31 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  2896461824/4695924736 (61.7%) @12.0x, remaining 2:26 RBU 100.0% UBU
>>>>>>>  94.1%
>>>>>>>  2951970816/4695924736 (62.9%) @12.0x, remaining 2:21 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  3007479808/4695924736 (64.0%) @12.0x, remaining 2:15 RBU  99.9% UBU
>>>>>>>  97.1%
>>>>>>>  3063021568/4695924736 (65.2%) @12.0x, remaining 2:11 RBU  99.8% UBU
>>>>>>>  88.2%
>>>>>>>  3118497792/4695924736 (66.4%) @12.0x, remaining 2:05 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  3174039552/4695924736 (67.6%) @12.0x, remaining 2:00 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  3229581312/4695924736 (68.8%) @12.0x, remaining 1:56 RBU  99.9% UBU
>>>>>>>  97.1%
>>>>>>>  3285090304/4695924736 (70.0%) @12.0x, remaining 1:51 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  3340599296/4695924736 (71.1%) @12.0x, remaining 1:46 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  3396141056/4695924736 (72.3%) @12.0x, remaining 1:41 RBU  99.9% UBU
>>>>>>>  97.1%
>>>>>>>  3451682816/4695924736 (73.5%) @12.0x, remaining 1:36 RBU  99.9% UBU
>>>>>>>  97.1%
>>>>>>>  3507191808/4695924736 (74.7%) @12.0x, remaining 1:32 RBU 100.0% UBU
>>>>>>>  94.1%
>>>>>>>  3562733568/4695924736 (75.9%) @12.0x, remaining 1:27 RBU 100.0% UBU
>>>>>>>  91.2%
>>>>>>>  3618242560/4695924736 (77.1%) @12.0x, remaining 1:23 RBU 100.0% UBU
>>>>>>>  91.2%
>>>>>>>  3673784320/4695924736 (78.2%) @12.0x, remaining 1:18 RBU 100.0% UBU
>>>>>>>  94.1%
>>>>>>>  3729293312/4695924736 (79.4%) @12.0x, remaining 1:14 RBU 100.0% UBU
>>>>>>>  94.1%
>>>>>>>  3784835072/4695924736 (80.6%) @12.0x, remaining 1:09 RBU 100.0% UBU
>>>>>>>  94.1%
>>>>>>>  3840344064/4695924736 (81.8%) @12.0x, remaining 1:05 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  3895885824/4695924736 (83.0%) @12.0x, remaining 1:00 RBU 100.0% UBU
>>>>>>>  70.6%
>>>>>>>  3951427584/4695924736 (84.1%) @12.0x, remaining 0:56 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  4006936576/4695924736 (85.3%) @12.0x, remaining 0:51 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  4062478336/4695924736 (86.5%) @12.0x, remaining 0:47 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  4118020096/4695924736 (87.7%) @12.0x, remaining 0:43 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  4173529088/4695924736 (88.9%) @12.0x, remaining 0:39 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  4229103616/4695924736 (90.1%) @12.0x, remaining 0:34 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  4284579840/4695924736 (91.2%) @12.0x, remaining 0:30 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  4340154368/4695924736 (92.4%) @12.0x, remaining 0:26 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  4395663360/4695924736 (93.6%) @12.0x, remaining 0:22 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  4451237888/4695924736 (94.8%) @12.0x, remaining 0:18 RBU  99.9% UBU
>>>>>>>  97.1%
>>>>>>>  4506779648/4695924736 (96.0%) @12.0x, remaining 0:13 RBU  99.9% UBU
>>>>>>>  97.1%
>>>>>>>  4562321408/4695924736 (97.2%) @12.0x, remaining 0:09 RBU  99.9% UBU
>>>>>>>  97.1%
>>>>>>>  4617830400/4695924736 (98.3%) @12.0x, remaining 0:05 RBU 100.0% UBU
>>>>>>>  97.1%
>>>>>>>  4673372160/4695924736 (99.5%) @12.0x, remaining 0:01 RBU  67.3% UBU
>>>>>>>  97.1%
>>>>>>> builtin_dd: 2292944*2KB out @ average 9.9x1352KBps
>>>>>>> /dev/pass0: flushing cache
>>>>>>> /dev/pass0: closing track
>>>>>>> /dev/pass0: closing disc
>>>>>>>
>>>>>>> i also noticed this output (console):
>>>>>>>
>>>>>>> (cd0:ata2:0:0:0): READ TOC/PMA/ATIP. CDB: 43 0 0 0 0 0 0 0 4 0
>>>>>>> (cd0:ata2:0:0:0): CAM status: SCSI Status Error
>>>>>>> (cd0:ata2:0:0:0): SCSI status: Check Condition
>>>>>>> (cd0:ata2:0:0:0): SCSI sense: ILLEGAL REQUEST csi:43,0,0,e asc:24,0
>>>>>>> (Invalid field in CDB): Command byte 6 is invalid
>>>>>>> (cd0:ata2:0:0:0): READ TOC/PMA/ATIP. CDB: 43 0 0 0 0 0 0 0 4 0
>>>>>>> (cd0:ata2:0:0:0): CAM status: SCSI Status Error
>>>>>>> (cd0:ata2:0:0:0): SCSI status: Check Condition
>>>>>>> (cd0:ata2:0:0:0): SCSI sense: ILLEGAL REQUEST csi:43,0,0,e asc:24,0
>>>>>>> (Invalid field in CDB): Command byte 6 is invalid
>>>>>>>
>>>>>>> my motherboard features a second SATA controller:
>>>>>>>
>>>>>>> ahci1: <Intel ICH9 AHCI SATA controller> port
>>>>>>> 0xe600-0xe607,0xe700-0xe703,0xe800-0xe807,0xe900-0xe903,0xea00-0xea1f
>>>>>>> mem 0xf8206000-0xf82067ff irq 19 at device 31.2 on pci0
>>>>>>
>>>>>> this one!
>>>>>>
>>>>>>>
>>>>>>> should i consider moving my hdd to this controller? i heard the
>>>>>>> jmicron controllers don't work very well under freebsd.
>>>>>>>
>>>>>>> i'm running
>>>>>>>
>>>>>>> FreeBSD otaku 9.0-CURRENT FreeBSD 9.0-CURRENT #4 r209884: Sat Jul 10
>>>>>>> 19:25:16 CEST 2010     root at otaku:/usr/obj/usr/src/sys/ARUNDEL  amd64
>>>>>>>
>>>>>>> with
>>>>>>>
>>>>>>> options         ATA_CAM
>>>>>>>
>>>>>>> in my kernel config.
>>>>>>>
>>>>>>> cheers.
>>>>>>>
>>>>>>> ps: during the `growisofs` session i made sure that no other
>>>>>>> application was causing heavy HDD activity!!!
>>>>>
>>>>> How much is your HDD really fast(when reading that iso file)?
>>>>
>>>> dd if=/dev/ada0 of=/dev/null bs=1M count=4482
>>>> 4482+0 records in
>>>> 4482+0 records out
>>>> 4699717632 bytes transferred in 66.619926 secs (70545224 bytes/sec)
>>>>
>>>
>>> ISO file != start of disk
>>
>> oh sorry. here're a couple of different tests. i'm not sure if they
>> are useful because of the effects of caching:
>>
>> dd if=/dev/cd0 of=./test.iso bs=2048
>> 2293232+0 records in
>> 2293232+0 records out
>> 4696539136 bytes transferred in 1581.225780 secs (2970189 bytes/sec)
>>
>> dd if=test.iso of=/dev/null bs=1M
>> 4478+1 records in
>> 4478+1 records out
>> 4696539136 bytes transferred in 101.192359 secs (46411994 bytes/sec)
>>
>> time cp test.iso /dev/null
>> cp test.iso /dev/null  0,00s user 7,98s system 7% cpu 1:39,78 total
>>
>>>
>>>>>
>>>>> Usually when I use growisofs, files I burn are located on tmpfs or are
>>>>> completly cached in VM (yes, that is hardcore)
>>>>
>>>> thanks for the hint. although i use tmpfs i only have 2GB of RAM.
>>>> that's why an entire DVD image (4.377 GiB) cannot reside inside tmpfs
>>>> (or any other memory backed fs) on my machine.
>>>>
>>>>>
>>>>
>>>>
>>>>
>>>> --
>>>> Alexander Best
>>>>
>>>
>
> I'm not really expert in those things, perhaps firmware for your
> burner is not up to date or have some limitations.
>
> Can be anything from flaky disc being burned to cdrecord.
> You are burning DVD-R or DVD+R?
> You tested with other disc vendors to see if there is anything different ....

i'm using DVD+Rs. unfortunately i don't have any DVD-Rs available
right now. this might be an issue with growisofs. i'm not using
cdrecord. i don't think it's capable of burning DVDs, but i might be
wrong there.

i guess i'll have to bite the bullet and run more tests. just thought
this was a common issue and somebody already came up with a solution.

thanks for your help.

ps: i've added freebew-questions@

>



-- 
Alexander Best


More information about the freebsd-questions mailing list