Out of disk space error (when disk space is available)

Begonnen von jesperl, Juni 13, 2012, 17:53:28

« vorheriges - nächstes »

jesperl

I am running TS Doctor in WinXP SP3 under Virtualbox 1.4.16 on Ubuntu 11.04 64-bit.

Recently I started getting "out of disk space errors" so that the last 30 seconds (approximately) of the corrected TS file is not written to disc. A log file is reproduced below.

This only happens when TS Doctor is writing the file to a vboxsvr volume (shared folders from the host computer running VirtualBox, which are mounted by the guest). It does not happen when TS Doctor is writing the file to a Samba share, even though the two volumes are mounted in the same way from within WinXP under Virtualbox (net use).

By the way, TS Doctor thinks that my vboxsvr volume (VBOXSHAREDFOLDERFS in the log file) is non-NTFS and that it cannot hold files greater than 4 GB, so there is a popup box about this. But until recently, you could just skip this warning (minor annoyance). Side note: it would be nice if TS Doctor could recognize vboxsvr volumes, so that this warning is not displayed. Also, I am not sure whether this is related to the problem that I am reporting?

I must admit that I am not 100% sure that this is a problem in TS Doctor... The problem occurred the first time after an upgrade to TS Doctor 1.2.22, but at the same time I had upgraded Virtualbox from 4.1.14 to 4.1.16. I downgraded TS Doctor to 1.2.16, which had worked on Virtualbox 4.1.14 (I didn't test precisely the same TS files), and I also got the out of disk space error here. But on the other hand, TS Doctor seems to be the only application that's getting out of disk space errors on the vboxsvr share. So maybe it is TS Doctor related after all...?

Also, I noticed this entry in the changelog for 1.2.29 (have others experienced this problem?)

    "Bug report for write errors (out of disk space error) with more detail in the log"

Indeed, there is now more detailed information in the log file.

In any case, here is a full log file. As far as I can read the error message, it says 0 bytes available, but in the next line free space is reported as approx 9 GB (which is correct for the free space).


*** START logfile ***

Opening file Y:\Dreambox HDTV\12-04-21 - TV2 HD - Basic.ts

OS: Windows XP Service Pack 3
TSDoctor.exe V 1.2.29 (Build 02399C)

Supported TS source filter found  : TS Doctor FileSource (on)
Supported splitter filter found   : [Haali Media Splitter]
Supported audio filter found      : ffdshow Audio Decoder
Supported Mpeg video filter found : ffdshow Video Decoder(3914)
Supported H264 video filter found : ffdshow Video Decoder(3914)
Supported video renderer found    : Video Renderer

File size: 9249437568
Packets  : 49199136


Scanning for TRP fill packets

Scanning for PIDs

Found 6 different PIDs

Identifying stream types

$0000: 0%   = PAT
$04B9: 0%   = PMT
$04B0: 90%  = H264 Video (PES_StreamID E0 = Video_Stream_0) [PCR,PTS,DTS]
$04B1: 2%   = MPEG1 Audio (PES_StreamID C2 = Audio_Stream_2) [PTS][PESLength]
$04B6: 5%   = AC3 Audio (PES_StreamID BD = Private_Stream_1) [PTS][PESLength]
$04B2: 3%   = Teletext (PES_StreamID BD = Private_Stream_1) [PTS][PESLength]


Scanning for PATs

----------- PAT 0 -----------
PacketCount              : 1
Table ID                 : 0
Section Syntax Indicator : 1
Reserved Bit 0           : 0
Reserved Bit 1           : 1
Reserved Bit 2           : 1
Pointer Field            : 0
Section Length           : 13
Transport Stream ID      : 2000
Reserved Bit 3           : 1
Reserved Bit 4           : 1
Version Number           : 8
Current Next Indicator   : 1
Section Number           : 0
Last Section Number      : 0

  Program Number : $04B0
  Map PID        : $04B9

CRC32                    : $57BD290B = $57BD290B
-----------------------------

Found 1 different PATs
Found 1 different PMT PIDs
Scanning for PMTs

----------- PMT 0 -----------
Packet                   : $00000002
PacketCount              : 1
PID                      : $04B9
Table ID                 : 2
Section Syntax Indicator : 1
PMT Size                 : 70
Pointer Field            : 0
Section Length           : 62
Program Number           : $04B0
Version Number           : 3
Current Next Indicator   : 1
Section Number           : 0
Last Section Number      : 0
PCR PID                  : $04B0

Program Info Length      : 0

  Stream Type    : 27
  Description    : AVC video stream as defined in ITU-T Rec. H.264 | ISO/IEC 14496-10 Video
  Elementary PID : $04B0
  ES Info Length : 0

  Stream Type    : 3
  Description    : ISO/IEC 11172 Audio
  Elementary PID : $04B1
  ES Info Length : 6
  ES Info        : $0A, $04, $64, $61, $6E, $00
  ES Info Text   : __dan_

  Stream Type    : 6
  Description    : ITU-T Rec. H.222.0 | ISO/IEC 13818-1 PES packets containing private data (Teletext)
  Elementary PID : $04B2
  ES Info Length : 7
  ES Info        : $56, $05, $64, $61, $6E, $09, $00
  ES Info Text   : V_dan__
  ES Info (teletext description) : 1. initial teletext page (dan) page 100

  Stream Type    : 6
  Description    : ITU-T Rec. H.222.0 | ISO/IEC 13818-1 PES packets containing private data (AC3)
  Elementary PID : $04B6
  ES Info Length : 16
  ES Info        : $0A, $04, $64, $61, $6E, $00, $6A, $02, $80, $44, $05, $04, $41, $43, $2D, $33
  ES Info Text   : __dan_j_€D__AC-3

CRC32                    : $14A63D73 = $14A63D73
-----------------------------

Found 1 different PMTs

Selecting PMT with PID 04B9 at position 00000002
CRC OK!

0.
  stream_type              : 27 = AVC video stream as defined in ITU-T Rec. H.264 | ISO/IEC 14496-10 Video
  elementary_pid           : 04B0
  ES_info_length           : 0

1.
  stream_type              : 3 = ISO/IEC 11172 Audio
  elementary_pid           : 04B1
  ES_info_length           : 6

2.
  stream_type              : 6 = ITU-T Rec. H.222.0 | ISO/IEC 13818-1 PES packets containing private data (Teletext)
  elementary_pid           : 04B2
  ES_info_length           : 7

3.
  stream_type              : 6 = ITU-T Rec. H.222.0 | ISO/IEC 13818-1 PES packets containing private data (AC3)
  elementary_pid           : 04B6
  ES_info_length           : 16

PCR PID is 04B0

Created PAT:

----------- PAT 0 -----------
PacketCount              : 0
Table ID                 : 0
Section Syntax Indicator : 1
Reserved Bit 0           : 0
Reserved Bit 1           : 1
Reserved Bit 2           : 1
Pointer Field            : 0
Section Length           : 13
Transport Stream ID      : 2000
Reserved Bit 3           : 1
Reserved Bit 4           : 1
Version Number           : 8
Current Next Indicator   : 1
Section Number           : 0
Last Section Number      : 0

  Program Number : $04B0
  Map PID        : $04B9

CRC32                    : $57BD290B = $57BD290B
-----------------------------



Created PMT:

----------- PMT 0 -----------
Packet                   : $00000002
PacketCount              : 1
PID                      : $04B9
Table ID                 : 2
Section Syntax Indicator : 1
PMT Size                 : 70
Pointer Field            : 0
Section Length           : 62
Program Number           : $04B0
Version Number           : 3
Current Next Indicator   : 1
Section Number           : 0
Last Section Number      : 0
PCR PID                  : $04B0

Program Info Length      : 0

  Stream Type    : 27
  Description    : AVC video stream as defined in ITU-T Rec. H.264 | ISO/IEC 14496-10 Video
  Elementary PID : $04B0
  ES Info Length : 0

  Stream Type    : 3
  Description    : ISO/IEC 11172 Audio
  Elementary PID : $04B1
  ES Info Length : 6
  ES Info        : $0A, $04, $64, $61, $6E, $00
  ES Info Text   : __dan_

  Stream Type    : 6
  Description    : ITU-T Rec. H.222.0 | ISO/IEC 13818-1 PES packets containing private data (Teletext)
  Elementary PID : $04B2
  ES Info Length : 7
  ES Info        : $56, $05, $64, $61, $6E, $09, $00
  ES Info Text   : V_dan__
  ES Info (teletext description) : 1. initial teletext page (dan) page 100

  Stream Type    : 6
  Description    : ITU-T Rec. H.222.0 | ISO/IEC 13818-1 PES packets containing private data (AC3)
  Elementary PID : $04B6
  ES Info Length : 16
  ES Info        : $0A, $04, $64, $61, $6E, $00, $6A, $02, $80, $44, $05, $04, $41, $43, $2D, $33
  ES Info Text   : __dan_j_€D__AC-3

CRC32                    : $14A63D73 = $14A63D73
-----------------------------


First video PTS is 828058007 02:33:20.645
Last video PTS  is 1557880607 04:48:29.785

First PCR  is 248386539900 02:33:19.501
Last PCR  is 467336921259 04:48:28.775
Duration of video stream is 729834605 02:15:09.273
Video PCR to PTS difference -1316 ms
$04B1: Delay to video stream = -961ms
$04B2: Delay to video stream = -1122ms
$04B6: Delay to video stream = -1010ms


The following PIDs will be imported into new stream: $04B0, 04B1, 04B2, 04B6

Scanning for video details

-------- H264 Video ---------
profile_idc                            : 100
constrained_set0_flag                  : 0
constrained_set1_flag                  : 0
constrained_set2_flag                  : 0
constrained_set3_flag                  : 0
reserved_zero_4bits                    : 0
level_idc                              : 40
seq_parameter_set_id                   : 0
chroma_format_idc                      : 1
bit_depth_luma_minus8                  : 0
bit_depth_chroma_minus8                : 0
qpprime_y_zero_transform_bypass_flag   : 0
seq_scaling_matrix_present_flag        : 1
seq_scaling_list_present_flag_0      : 1
seq_scaling_list_present_flag_1      : 1
seq_scaling_list_present_flag_2      : 0
seq_scaling_list_present_flag_3      : 0
seq_scaling_list_present_flag_4      : 1
seq_scaling_list_present_flag_5      : 0
seq_scaling_list_present_flag_6      : 1
seq_scaling_list_present_flag_7      : 0
log2_max_frame_num_minus4              : 2
pic_order_cnt_type                     : 0
log2_max_pic_order_cnt_lsb_minus4      : 4
num_ref_frames                         : 4
gaps_in_frame_num_value_allowed_flag   : 0
pic_width_in_mbs_minus1                : 79
pic_height_in_map_units_minus1         : 44
frame_mbs_only_flag                    : 1
direct_8x8_inference_flag              : 1
frame_cropping_flag                    : 0
vui_parameters_present_flag            : 1
aspect_ratio_info_present_flag         : 1
aspect_ratio_idv                       : 1
overscan_info_present_flag             : 1
overscan_appropriate_flag              : 1
video_signal_type_present_flag         : 1
video_format                           : 5
video_full_range_flag                  : 0
colour_description_present_flag        : 1
colour_primaries                       : 1
transfer_characteristics               : 1
matrix_coefficients                    : 1
chroma_loc_info_present_flag           : 1
chroma_sample_loc_type_top_field       : 0
chroma_sample_loc_type_bottom_field    : 0
timing_info_present_flag               : 1
num_units_in_tick                      : 1
time_scale                             : 100
fixed_frame_rate_flag                  : 1
nal_hrd_parameters_present_flag        : 0
vcl_hrd_parameters_present_flag        : 0
-----------------------------

Video format: H264 1280x720p/AR=16:9/50 fps/High@4.0
Colorimetry : ColourPrimaries=BT.709, TransferCharacteristics=BT.709, MatrixCoefficients=BT.709
First I-Frame PTS at 02:33:20.985 [00:00:00.340]
First GOP = 48 frames : I164 B156 B152 B150 B154 B160 B158 B162 P180 B172 B168 B166 B170 B176 B174 B178 P196 B188 B184 B182 B186 B192 B190 B194 P212 B204 B200 B198 B202 B208 B206 B210 P228 B220 B216 B214 B218 B224 B222 B226 P244 B236 B232 B230 B234 B240 B238 B242

Scanning for audio details
Audio stream 1: MPEG1 Audio
AC3 6 channels: 18 times
Audio stream 2: AC3 5.1 48000Hz (DAN)
Warning: Filesize > 4 GB but file system is VBOXSHAREDFOLDERFS

Cutting areas (I/P-Frame aligned)
Cut 1 In : 02:44:30.145 (AUD|SPS|PPS|SEI|I-SLICE|I-SLICE|I-SLICE|I-SLICE|I-SLICE|I-SLICE|FILL|)
Cut 1 Out: 04:15:58.305 (AUD|SPS|PPS|SEI|I-SLICE|I-SLICE|I-SLICE|I-SLICE|I-SLICE|I-SLICE|)
Cut 1 PCR/PTS/DTS offset: 00:00:00.000



Cut in  at PCR: 00:11:09.500 (02:44:29.001)
Cut out at PCR: 01:42:37.660 (04:15:57.161)
First packet  : 003DF6E8
Last packet   : 023A2770

Starting at paket 003DF6E8 PCR: 00:11:09.327 (02:44:28.828)
Cutting the end at paket 023A2771 PCR: 01:31:29.477 (04:15:58.306)
Error: Could not write all data to disk for file Y:\TS Doctor output\12-04-21 - TV2 HD - Basic_fixed.ts
       Write error at position 6053539464 , wanted to write 26012056 bytes, but only 0 are.
       Free disk space on destination drive: 9133871104

---------- ABORTED ----------


---------  NAL Unit Type Statistic  ---------
Slices                 : 1646808
    I-Slices           : 42966
    P-Slices           : 189576
    B-Slices           : 1414266
    SP-Slices          : 0
    SI-Slices          : 0
Data Partition A       : 0
Data Partition B       : 0
Data Partition A       : 0
IDR Picture            : 0
SEI                    : 274468
Sequence Parameter Set : 7161
Picture Parameter Set  : 7219
AUD                    : 274468
End of Sequence        : 0
End of Stream          : 0
Filler                 : 217726
Slices                 : 0
Seq. Param. Set Ext.   : 0

H264 filler data: 2.3% [Netto]

Cutted pakets at the beginning: 3943103
Cutted pakets at the end: 11833519
Discarded pakets (to synch audio/video): 7053
Discarded pakets (not needed): 1083889

PID stream sizes
$04B0: 5.2 GB
$04B1: 129.8 MB
$04B6: 307.5 MB

ERRORS : 0
WARNINGS : 0

Speed: 22.4 MBytes/sec
Duration: 00:04:27

Cypheros

For the file writing the file system is not relevant. The file system checking is just done as a precaution.
The error has nothing to do with the file system warning. The error is raised at position 6.053.539.464 what is beyond the 4GB FAT32 limitation.

It looks like the operating system just stopped writing any data to disk at a point. The new log entries are just to prove this behavior another user reported with VirtualBox.

jesperl

#2
Zitat von: Cypheros am Juni 13, 2012, 23:06:26
For the file writing the file system is not relevant. The file system checking is just done as a precaution.
The error has nothing to do with the file system warning. The error is raised at position 6.053.539.464 what is beyond the 4GB FAT32 limitation.

It looks like the operating system just stopped writing any data to disk at a point. The new log entries are just to prove this behavior another user reported with VirtualBox.

The strange thing is that this error seems to occur systematically when the last 30 seconds (approx) is written to the corrected TS file. It does not seem to be a function of the available disk space on the vboxsvr disk.

Just to be clear: are you saying that this is a bug in Virtualbox and not TS Doctor?

I did a small test where the same file with the same cut points was written to two different vboxsvr drives with different GBs of available space. The out-of-disk-space error occurred at exactly the same point in the two cases, see the log file entries below.

Starting at paket 00482289 PCR: 00:12:59.179 (15:50:28.458)
Cutting the end at paket 0219BB34 PCR: 01:23:49.340 (17:14:17.797)
Error: Could not write all data to disk for file V:\TS Doctor output\12-05-06 - DR HD - Blood Crime_fixed.ts
       Write error at position 5539677936 , wanted to write 29991640 bytes, but only 0 are.
       Free disk space on destination drive: 40338026496


Starting at paket 00482289 PCR: 00:12:59.179 (15:50:28.458)
Cutting the end at paket 0219BB34 PCR: 01:23:49.340 (17:14:17.797)
Error: Could not write all data to disk for file Y:\TS Doctor output\12-05-06 - DR HD - Blood Crime_fixed.ts
       Write error at position 5539677936 , wanted to write 29991640 bytes, but only 0 are.
       Free disk space on destination drive: 9447968768


Cypheros

It's a guess but I don't know for sure. This behaviour was not reported on any other OS or VM.

Look, this is the procedure creating the error message:



  BytesWritten := TSFile.Write(ThreadOwner.WriteBuffer[0], BytesToWrite);
  WriteResult  := (BytesToWrite = BytesWritten);


It's simple and it works for 6 GB but suddenly not. I see no reason why problem should be in this commands.



jesperl

#4
Zitat von: Cypheros am Juni 13, 2012, 23:41:04
It's a guess but I don't know for sure. This behaviour was not reported on any other OS or VM.

Look, this is the procedure creating the error message:



  BytesWritten := TSFile.Write(ThreadOwner.WriteBuffer[0], BytesToWrite);
  WriteResult  := (BytesToWrite = BytesWritten);


It's simple and it works for 6 GB but suddenly not. I see no reason why problem should be in this commands.

I agree... the only strange thing is that this only seems to happen when TS Doctor is writing the last block to the disk. In the last example I provided, TS Doctor wants to write 29991640 to disk, and this fails (the OS reports back that 0 bytes were written to disk). I have verified that the block with 29991640 bytes (which fails) is the last block by comparing file sizes of the failed and successful cases.

So the interesting question is what makes the last block so different from the previous ones? Size is obviously one thing (I assume that all blocks except the last one have a fixed size? In that case: what is BytesToWrite for the "normal" case?), but unless VirtualBox or WinXP with a vboxsvr mounted share imposes some strange limitation on the size of the block, this doesn't really explain things..

Any ideas? If I want to report this to the Virtualbox developers..

jesperl

#5
Zitat von: jesperl am Juni 14, 2012, 00:14:07
So the interesting question is what makes the last block so different from the previous ones? Size is obviously one thing (I assume that all blocks except the last one have a fixed size? In that case: what is BytesToWrite for the "normal" case?), but unless VirtualBox or WinXP with a vboxsvr mounted share imposes some strange limitation on the size of the block, this doesn't really explain things..

Ok, it is related to the blocksize. The c function fwrite() in Mingw calls the same Windows library function (WriteFile) as the Delphi (?) function Write (I presume?), so I created a small c program to re-produce the error.

The c program below can re-produce the error when compiled with Mingw.
Compile as 'gcc -o test.exe test.cpp', and run test <size>.

On my WinXP, it fails on a vboxsvr volume when size > 2^24.


#include <stdio.h>
#include <stdlib.h>
#include <string.h>

int main(int argc, char* argv[])
{
  FILE* fp;
  fp = fopen("test.bin", "wb");
 
  int s = (argc > 1 ? atoi(argv[1]) : 100);
  char* p = (char*) malloc(s);
  memset(p, 0, s);

  int bytes = fwrite(p, 1, s, fp);
  fclose(fp);
 
  printf("Number of bytes written: %d\n", bytes);
  return 0;
}



This is clearly not a TS Doctor problem, except that TS Doctor could create a work-around by limiting the block size to 2^24. :)

Cypheros

The file writing is done in a separate thread in smaller chunks but at the end the buffer is flushed and up to 37600000 Bytes are written to disk.

Next Beta 1.2.30 will have a registry key under HKEY_CURRENT_USER\Software\Cypheros\TSDoctor\Settings to change the maximum write buffer size.

If you create a DWord(32bit) "MaxWriteBufferSize" you can specify the maximum size of the write buffer.



jesperl

Zitat von: Cypheros am Juni 14, 2012, 09:50:14
Next Beta 1.2.30 will have a registry key under HKEY_CURRENT_USER\Software\Cypheros\TSDoctor\Settings to change the maximum write buffer size.

If you create a DWord(32bit) "MaxWriteBufferSize" you can specify the maximum size of the write buffer.

Thanks!

jesperl

Zitat von: Cypheros am Juni 14, 2012, 09:50:14
Next Beta 1.2.30 will have a registry key under HKEY_CURRENT_USER\Software\Cypheros\TSDoctor\Settings to change the maximum write buffer size.

If you create a DWord(32bit) "MaxWriteBufferSize" you can specify the maximum size of the write buffer.

Just tested 1.2.31 beta with 16,777,216 as MaxWriteBufferSize. Worked flawlessly on a VirtualBox share.

Cypheros


jesperl

Zitat von: Cypheros am Juni 24, 2012, 01:18:37
Nice  :D

One small suggestion: is it possible to skip the 4GB file size warning when the file system is a VirtualBox share?

From logfile

Warning: Filesize > 4 GB but file system is VBOXSHAREDFOLDERFS

Cypheros

Is "VirtualBox share" in any case without 4GB limitation? What if host has FAT32 file system?

jesperl

#12
Zitat von: Cypheros am Juni 24, 2012, 01:36:54
Is "VirtualBox share" in any case without 4GB limitation? What if host has FAT32 file system?

You are right that it depends on the host file system which could be FAT32 (in theory, unlikely in practice).

A simpler suggestion would be a registry setting to auto-ignore the warning (like clicking 'no' every time). Then it's clearly the user's responsibility that the file system can handle larger files.

It's not a major problem if you don't like doing anything that could cause TS Doctor to fail with a warning that the file cannot be written (I'm not sure what happens if you proceed on a FAT32 partition?).


www.cypheros.de