getWizPnP - Beyonwiz recording downloader

[raymondjpg]

So much for that idea I may give it a go anyway. Could you have a go at trying to track down where the Bad Request is being generated in getWizPnP and/or in the LWP modules?

I will look at it again tomorrow. I have no idea how to track down where the Bad Request is being generated. Maybe I have to run the Perl version.

I have been using the compiled version. Also tried v0.5.0 with the same result, and also turned off real time protection in Microsoft security essentials without success.

[prl]

So much for that idea I may give it a go anyway. Could you have a go at trying to track down where the Bad Request is being generated in getWizPnP and/or in the LWP modules?

I will look at it again tomorrow. I have no idea how to track down where the Bad Request is being generated. Maybe I have to run the Perl version.
...

Yes, you'll need to put some diagnostics into the Perl version, possibly in the library modules that are involved.

The error is happening in Beyonwiz::Recording::HTTPAccessor::getRecordingChunk(), which is in Beyonwiz/Recording/HTTPAccessor.pm under the main getWizPnP folder. The error message printout is coming from line 313. The error can't be the sysseek at line 277 or the syswrite at line 292, because in both cases the error case never reaches line 313. That leaves the call to the LWP user agent at 288. The actual implementation of the $ua->request() method is passed down through LWP::UserAgent::request() (in C:\Perl\lib\LWP.pm) to LWP::Protocol::http::request() (in c:\Perl\lib/LWP\Protocol\http.pm). The paths assume you've installed ActivePerl in the default location.

It also can't be BAD_REQUEST error at the start of LWP::Protocol::http::request(), because the error that you're seeing doesn't print out matching message from the status_line() in the error ("Library does not allow method ..."). In fact, the BAD_REQUEST response doesn't have any additional information about the reason, otherwise it would be printed in the error message after the "400 Bad Request" text.

The unnamed subroutine definition in Beyonwiz::Recording::HTTPAccessor::getRecordingChunk() is the callback function for the request(). It's there mainly so that the progress bar can be updated. It gets passed as a function reference to $ua->request(), and the reference is called through for the callback when data is received.

[raymondjpg]

Yes, you'll need to put some diagnostics into the Perl version, possibly in the library modules that are involved.

Aaaaaaaaaaaaargh. What you are suggesting is above my pay grade!

Now is the time to install my freshly downloaded copy of WindowsXPmode for Win7. I knew that the Professional edition of Win 7 would come in handy for something.

Or maybe it is time to ditch MS altogether and get a Mac (just kidding ).

[prl]

Yes, you'll need to put some diagnostics into the Perl version, possibly in the library modules that are involved.

Aaaaaaaaaaaaargh. What you are suggesting is above my pay grade!

No problem. I'll double what I'm paying you

By the way, earlier when you posted the error message you get when you use '-v', you wrote the error as "400 Bad Request". Could you check that it's not "400 Bad request" (lower case start to the second word). That may help identify where the error is being generated.

...
Or maybe it is time to ditch MS altogether and get a Mac (just kidding ).

Since that's what I develop and use getWizPnP on, that may not be such a bad choice

[raymondjpg]

By the way, earlier when you posted the error message you get when you use '-v', you wrote the error as "400 Bad Request". Could you check that it's not "400 Bad request" (lower case start to the second word). That may help identify where the error is being generated.

Indeed, "400 Bad request" lower case r.

(getwizpnp 0.5.1 compiled version run with -t -r options.)

[prl]

By the way, earlier when you posted the error message you get when you use '-v', you wrote the error as "400 Bad Request". Could you check that it's not "400 Bad request" (lower case start to the second word). That may help identify where the error is being generated.

Indeed, "400 Bad request" lower case r.

(getwizpnp 0.5.1 compiled version run with -t -r options.)

OK, thanks. That's interesting, because the only place I can find the 400 error given as "Bad request" (vs Bad Request") is in the shttpd code (which is used in the Beyonwiz's wizpnp application, which provides the WizPnP service in the Beyonwiz).

That message is only produced if the server gets a HTTP request that's non-zero length and less than 16 bytes long (less than the length of the request header string "GET / HTTP/1.1\n\n"). But I can't see why the Perl library code being called at that point could produce a header shorter than that, or why it only seems to happen on Win7, or why I can't replicate it!

[prl]

Version 0.5.2

A new version of getWizPnP is available from the GetWizPnP Release page on the OpenWiz Software Pages.

This version fixes two of the bugs in 0.5.1 that are mentioned in this topic - the Perl internal error when getWizPnP tries to print an error message while downloading, and the infinite recursion when getWizPnP tries to load a recording's bookmarks. A couple of other bugs discovered while fixing those problems have also been fixed. See the release notes for more details.

[prl]

Dennis/sub3r, could you try out the new 0.5.2 Windows compiled version and confirm that Symantec's SONAR still whinges about it? I'm expecting that it will. As soon as I get confirmation from you, I'll ask Symantec to whitelist it.

Raymondjpg, Unknown, could one or both of you check to see whether this version works any more reliably for you? I'm not expecting that it will, unfortunately. Any hints that would help me reproduce this problem would help greatly. I can also build a Windows compiled version that prints the HTTP requests. If you're willing to try it, it may give some hint about what's going on.

[raymondjpg]

Dennis/sub3r, could you try out the new 0.5.2 Windows compiled version and confirm that Symantec's SONAR still whinges about it? I'm expecting that it will. As soon as I get confirmation from you, I'll ask Symantec to whitelist it.

Raymondjpg, Unknown, could one or both of you check to see whether this version works any more reliably for you? I'm not expecting that it will, unfortunately. Any hints that would help me reproduce this problem would help greatly. I can also build a Windows compiled version that prints the HTTP requests. If you're willing to try it, it may give some hint about what's going on.

New Windows compiled version still aborts after transferring a part of a file with the same error - "400 Bad request" lower case r.

(getwizpnp 0.5.2 compiled version run with -t -r options.)

If Symantec does not like it, perhaps Microsoft Security Essentials doesn't either?

[prl]

..
If Symantec does not like it, perhaps Microsoft Security Essentials doesn't either?

I have that installed, and I can't reproduce the problem

[sub3R]

Dennis/sub3r, could you try out the new 0.5.2 Windows compiled version and confirm that Symantec's SONAR still whinges about it? I'm expecting that it will. As soon as I get confirmation from you, I'll ask Symantec to whitelist it.

Thanks Peter. Yes it complains about that version also, but Symantec?s exception for the version Luke submitted hasn?t come through yet ?. more info here.

Norton?s AntiVirus & Malwarebyte?s Anti-Malware both correctly give a clean scan on 0.5.2 (the same as with all versions of getWizPnP.exe).

[prl]

...
New Windows compiled version still aborts after transferring a part of a file with the same error - "400 Bad request" lower case r.
...

Could you try the same with a version of 0.5.2 with some added debugging code? It prints each HTTP request as it goes, and exits immediately on the Bad request error, so it's easy to see what the last request was. http://ozi4ums.homedns.org/prl/getWizPn ... -Debug.zip

Could you post or PM me the contents of the prints of the last 3-4 requests?

[raymondjpg]

Could you post or PM me the contents of the prints of the last 3-4 requests?

I sent you a PM - thought best to include the while log (not too long). The PM appears in my Outbox, not Sentbox. I hope you have it.

[prl]

... The PM appears in my Outbox, not Sentbox. I hope you have it.

I got it; thanks. I've just replied. PMs go into Outbox until they've been read, then they go to Sentbox.

[prl]

I have submitted getWizPnP 0.5.2 to Symantec for whitelisting.

If/when that goes through it should clear up problems that people are having with running getWizPnP on a PC with Symantec Anti-Virus (the SONAR component, specifically).

Edit:

For a Software White-list request, Symantec will target a response of advising you of our final determination within 3 weeks.

And that's only if they think I've given them enough information

[sub3R]

I have submitted getWizPnP 0.5.2 to Symantec for whitelisting.

If/when that goes through it should clear up problems that people are having with running getWizPnP on a PC with Symantec Anti-Virus (the SONAR component, specifically).
?.

This now works without upsetting Symantec Norton?s AntiVirus with SONAR on my system - see here.

?.
I just tried all versions of getWizPnP.exe 0.5.1 I previously tested (8 in total), plus getWizPnP.exe 0.5.2, all run from YARDWiz 0.3.1, & they now all work fine.
So obviously Symantec have done their bit.
I also ran Peter?s compiled versions of getWizPnP.exe 0.5.1 & 0.5.2 from the command line & they also now work fine.
?.

Some users may find the following Windows firewall message appearing when getWizPnP.exe 0.5.n is first run:
?To help protect your computer. Windows firewall has blocked some features of this program. Name: getWizPnP. <Continue blocking> <Unblock>?
This happened to me with each 0.5.n version, but after selecting the ?unblock? option when each different version was initially run the message hasn?t reappeared.

Thanks again Peter.

[prl]

...
Some users may find the following Windows firewall message appearing when getWizPnP.exe 0.5.n is first run:
?To help protect your computer. Windows firewall has blocked some features of this program. Name: getWizPnP. <Continue blocking> <Unblock>?
This happened to me with each 0.5.n version, but after selecting the ?unblock? option when each different version was initially run the message hasn?t reappeared.
...

I get this, too. I should add something about it to the release page.

[sub3R]

Maybe they've changed something that fixes the problem generically, because I don't think there's been time for 0.5.2 to have gone through their processes, and they haven't emailed me about any action they've taken on 0.5.2. If they have sorted SONAR so that it's happy with PAR::Packer programs, then that's great!

I'm tipping your first guess as being correct, but yes, the latter would be nice. I haven?t fiddled with any settings in Nortons so it is a definite fix.

[raymondjpg]

Could you post or PM me the contents of the prints of the last 3-4 requests?

PMs don't seem to be working.

This is reply to your PM of 19 June:

Somehow I either overlooked this private message or it only just arrived (dated 19 June). You may have sent it while while I was locked out of the forum for a day or two.

In answer to your question, I have the Win 7 firewall disabled and Outpost software firewall enabled. There is one specific application rule for getWizPnP, and a number of generic "Anti-Leak Controls" that might be hindering the process. I don't know, and I don't recall having disabled the Outpost firewall to see if that is the problem. I could try.

The specific application rule for getWizPnP is to allow outbound UDP to IP 239.255.255.250, remote port 1900. The IP address for the P2 on my intranet is 10.1.1.7, so I don't know where 239.255.255.250 comes from.

My LAN settings are to allow *all* communications to and from network IP 10.1.1.7. That includes the internet.

I don't have any packet sniffing programs, unless you count TCP Monitor which I rarely use.

Regards

[prl]

I got your PMs. If you get an error message about smtp and port 110, the PM or post has probably got through. If the PM is in your Outbox, then it's in the system.

[raymondjpg]

I got your PMs. If you get an error message about smtp and port 110, the PM or post has probably got through. If the PM is in your Outbox, then it's in the system.

OK. Regrets regarding multiple tries.

[prl]

...
In answer to your question, I have the Win 7 firewall disabled and Outpost software firewall enabled. There is one specific application rule for getWizPnP, and a number of generic "Anti-Leak Controls" that might be hindering the process. I don't know, and I don't recall having disabled the Outpost firewall to see if that is the problem. I could try.

That's definitely a point of difference between your setup and mine. I have only the Win 7 firewall on. It's probably worth trying disabling your Outpost firewall temporarily to see if that helps.

The specific application rule for getWizPnP is to allow outbound UDP to IP 239.255.255.250, remote port 1900. The IP address for the P2 on my intranet is 10.1.1.7, so I don't know where 239.255.255.250 comes from.
...

It's the multicast address used by the Simple Service Discovery Protocol in WizPnP to find the WizPnP servers on the network. If that's blocked WizPnP server discovery won't work, though connecting direct to a known WizPnP server IP address should still work.

[Luke]

prl, I'm having trouble with the getWizPnP syntax to convert tvwiz format to TS on the local computer when all I know is the name of the folder that contains the header and the rest of the associated files (this is for YARDWiz, I'm using a simple directory browser for the user to select the folder that contains the header). Obviously I can convert if I know the Beyonwiz index name for the recording, but I may not have that little piece of info a priori and the folder name may not bear any relation to the recording index.

For example, a user downloads a recording with getWizPnP via YARDWiz:

Code: Select all

getWizPnP --BWName -O "F:\WizDownloads" -T "Awesome Terry Pratchett Movie Part 1.tvwiz" "recordings/Going Postal Dec.17.2011_19.28"

Later on they want to convert "Awesome Terry Pratchett Movie Part 1.tvwiz" from tvwiz to TS. I can get a list of recordings that have been downloaded to the parent folder, but YARDWiz won't have any idea that "Awesome Terry Pratchett Movie Part 1.tvwiz" is the same as "Going Postal Dec.17.2011_19.28":

Code: Select all

dir /b
Awesome Terry Pratchett Movie Part 1.tvwiz
Some really cool show.ts
Movie for the kids.tvwiz
Something I recorded on Friday.ts

getWizPnP -L --inDir "F:\WizDownloads"
Use of uninitialized value $1 in lc at Beyonwiz/Recording/FileAccessor.pm line 329.
Going Postal Dec.17.2011_19.28
Some really cool show.ts
Movie_ Ice Age Nov.26.2011_18.58
Something I recorded on Friday.ts

This (and some other variations) doesn't work:

Code: Select all

getWizPnP --inDir "F:\WizDownloads\Awesome Terry Pratchett Movie Part 1.tvwiz" -O "F:\WizDownloads" --ts -T "Pratchett Movie"

Listing the tvwiz folder with getWizPnP just returns rubbish:

Code: Select all

getWizPnP --inDir "F:\WizDownloads\Awesome Terry Pratchett Movie Part 1.tvwiz" -l -vvvv
Use of uninitialized value $1 in lc at Beyonwiz/Recording/FileAccessor.pm line 329.
...
Use of uninitialized value $1 in lc at Beyonwiz/Recording/FileAccessor.pm line 329.
Content: header.tvwiz
    Index name: header.tvwiz
    Sun Jan  1 18:34:09 2012 - Sun Jan  1 18:34:08 2012
    playtime: ----:--    recording size:      0.3 MB    bit rate: ----- Mb/s

The following works, but as I mentioned I won't know the index name (and don't want to rely on pattern matching):

Code: Select all

getWizPnP --inDir "F:\WizDownloads" -O "F:\\WizDownloads" --ts -T "Pratchett Movie" Going Postal Dec.17.2011_19.28

Any suggestions?

[prl]

...
Any suggestions?

All the "Use of uninitialized value ..." errors strongly suggest a bug in getWizPnP. I'll have a look into it.

However, although it probably shouldn't be throwing up all the internal errors,

Code: Select all

getWizPnP --inDir "F:\WizDownloads\Awesome Terry Pratchett Movie Part 1.tvwiz? ...

was never going to work.

[Luke]

I didn't think so, I didn't bother putting in all the variations I tried. Any issue with simply concatenating the individual files?

[prl]

... Any issue with simply concatenating the individual files?

Not on unedited recordings, and on recordings that have just been topped & tailed (but the result will contain a bit more of the recording than the the exact edit). Won't work properly on any other kinds of edited files.

The trunc file really does contain useful information

My guess is that the problem is happening in the getWizPnP code that builds the objects that represent the index.txt file (which doesn't exist if you use the -I/--inDir option).

[prl]

getWizPnP is supposed to be used in as much the same way as possible whether the recordings/media are on the Beyonwiz or in a local (--inDir) folder. And in both cases, -L (--List) is supposed to return index names, which are intended for internal use by programs like YARDWiz and WizZilla (it wad added at the request of the WizZilla authors).

The following works for me:

Code: Select all

Cambyses:getWizPnP prl$ getWizPnP.pl --inDir /Volumes/Archive/Archive/Movies -L
MOVIE_ Apocalypse Now Redux_Nov.2.2008_23.48
Audrey Hepburn Season_ Breakfast At Tiffany_s_Aug.2.2008_20.28
MOVIE_ Bride & Prejudice_Jun.28.2008_21.23
MOVIE_ Crouching Tiger, Hidden Dragon_Aug.8.2008_22.3
MOVIE_ The Go-Between_May.10.2008_20.28
MOVIE_ Harry Potter And The Philosopher's Stone_Oct.24.2008_19.32
Harry Potter & the Prisoner of Azkaban.mpeg
The Interpreter.mpeg
MOVIE_ The Island_Oct.6.2007_21.30
Keating!-1.jpeg
Keating!-2-1-1.jpg
Keating!-2-1.jpg
Keating!-2.jpeg
Keating!.mpeg
Keating!.mpeg
MOVIE_ Kinsey_Jan.4.2008_22.58
MOVIE_ A Man For All Seasons_Nov.8.2008_20.28
MOVIE_ Murk_Jan.19.2009_23.23
MOVIE_ Pride & Prejudice_Feb.15.2008_20.28
MOVIE_ Return Of The Scarlet Pimpernel_Jan.10.2009_22.10
MOVIE_ The Score_Jan.11.2009_23.28
MOVIE_ Sophie Scholl_ The Final Days_May.18.2008_21.28
Stepfather Of The Bride_Feb.1.2009_20.28
MOVIE_ Thunderbirds_Oct.27.2007_19.28
MOVIE_ The Tiger Brigades_Jan.11.2009_22.8
MOVIE_ Twin Sisters_Feb.22.2009_21.28
MOVIE_ Vertigo_Oct.11.2008_21.0
A Very Long Engagement.mpeg
Cambyses:getWizPnP prl$ 

And then, making use of two of the index names:

Code: Select all

getWizPnP.pl --inDir /Volumes/Archive/Archive/Movies --list --BWName -vv "MOVIE_ Kinsey_Jan.4.2008_22.58" "MOVIE_ The Go-Between_May.10.2008_20.28"
ABC2: MOVIE: The Go-Between
    The romance between a young woman of the aristocracy and a lowly
    farmer is told through the eyes of the boy who is hired to deliver
    messages between them.
    Sat May 10 20:28:00 2008 - Sat May 10 22:40:00 2008
    playtime:  132:00    recording size:   4842.3 MB    bit rate:   4.9 Mb/s
    autoDelete: Never

PRIME Canberra: MOVIE: Kinsey
    Fri Jan  4 22:58:00 2008 - Sat Jan  5 01:45:10 2008
    playtime:  167:10    recording size:   9664.6 MB    bit rate:   7.7 Mb/s
    autoDelete: Never

Cambyses:getWizPnP prl$

I.e. just the same usage as though the recordings were on the Beyonwiz.

There is a bug (now fixed in my development copy) that causes the "uninitialised" errors that you're seeing, but it should not actually affect the operation of getWizPnP. It may cause problems with Yardwiz's parser if it's getting a combined stdout and stderr in its input, of course.

If there are parts of the documentation that should be changed to make this clearer, let me know and I'll try to fix it.

[prl]

Version 0.5.3 beta limited release

Version 0.5.3 released. Do not use the beta versions. Links to beta versions removed.

A new limited release beta version of getWizPnP is available. Only the canned Windows and OS X versions are currently available. If there is a call for canned versions for Cygwin or Linux for testing, I can make them available.

This beta version fixes the problem of recording offsets being printed as negative on Windows if they are greater than 2^31 in --debug=trunc listings, and improves the checking in --check - the trunc entry sizes and recording offsets are now tested for consistency. The bignum pragma (for integer arithmetic on numbers bigger than 32 bits) is also used more consistently through the modules. Fixes bug in the handling of file names without extensions when constructing the index.txt information for recordings and media on local filesystems.

[sub3R]

Peter, the good news so far: Norton’s SONAR likes it & it doesn’t go negative running ‘getwizpnp -a -H (fixed IP address) --verbose --debug=trunc’.

However, it shows this with that command:

Code: Select all

One HD SC10: Big Fish +/Escape to breathtaking and remote locations in the South
 Pacific, New Zealand and Australia in the hunt for some of the world's most fam
ous fish. *AC3
    Sun Feb 12 17:28:00 2012 - Sun Feb 12 19:56:41 2012
    playtime:  148:41    recording size:  13691.6 MB    bit rate:  12.3 Mb/s
    autoDelete: Never
    Recording start offset:              262144
    Recording end offset:           13691867136
    File  File Offset       Size     Rec Offset Dup Flags Start Time
    0095      2473984   31080448         262144             00:00:00
    0096            0   33554432       31342592             00:00:34
    ...
    ...
    0221            0   33554432     4225646592             00:46:07
    0222            0   33554432     4259201024             00:46:29
    0223            0   33554432     4292755456             00:46:51
    0224            0   33554432     4294967295             00:47:13
    0225            0   33554432     4294967295             00:47:35
    0226            0   33554432     4294967295             00:47:57
    ...
    ...
    0500            0   33554432     4294967295             02:27:49
    0501            0   33554432     4294967295             02:28:11
    0502            0   33554432     4294967295             02:28:32
    0503            0    3608576     4294967295             00:14:53

Note offsets after 4292755456 (4294967295).
File 0503 is the last file for that recording – note the time. It doesn’t get the last time wrong in every recording.
Another example with 0175 being the last file in another recording:

Code: Select all

    0172            0   33554432     2733072384             00:29:55
    0173            0   33554432     2766626816             00:30:17
    0174            0   33554432     2800181248             00:30:39
    0175            0     499712     2833735680             00:00:00

Also as you expected, the random inconsistent missing data files still show up with --check.
The above is ‘getWizPnP-0.5.3beta-Compiled-Windows’ on a Windows XP sp3 PC connected via Ethernet LAN to a DP-S1 running 01.05.350 f/w.

[prl]

Peter, the good news so far: Norton’s SONAR likes it & it doesn’t go negative running ‘getwizpnp -a -H (fixed IP address) --verbose --debug=trunc’.

However, it shows this with that command:

Code: Select all

One HD SC10: Big Fish +/Escape to breathtaking and remote locations in the South
 Pacific, New Zealand and Australia in the hunt for some of the world's most fam
ous fish. *AC3
    Sun Feb 12 17:28:00 2012 - Sun Feb 12 19:56:41 2012
    playtime:  148:41    recording size:  13691.6 MB    bit rate:  12.3 Mb/s
    autoDelete: Never
    Recording start offset:              262144
    Recording end offset:           13691867136                           <<< I think that this is the problem
    File  File Offset       Size     Rec Offset Dup Flags Start Time
    0095      2473984   31080448         262144             00:00:00
    0096            0   33554432       31342592             00:00:34
    ...
    ...
    0221            0   33554432     4225646592             00:46:07
    0222            0   33554432     4259201024             00:46:29
    0223            0   33554432     4292755456             00:46:51
    0224            0   33554432     4294967295             00:47:13
    0225            0   33554432     4294967295             00:47:35
    0226            0   33554432     4294967295             00:47:57
    ...
    ...
    0500            0   33554432     4294967295             02:27:49
    0501            0   33554432     4294967295             02:28:11
    0502            0   33554432     4294967295             02:28:32
    0503            0    3608576     4294967295             00:14:53

Note offsets after 4292755456 (4294967295).
File 0503 is the last file for that recording – note the time. It doesn’t get the last time wrong in every recording.
...

There are two problems here. One is that I clearly haven't fixed the printout bug (I hadn't tested --debug=trunc on a recording bigger than 4GB, only on one bigger than 2GB). 4294967295 = 0xffffffff The fact that the start time for 0502 is consistent with the recording length shows that the actual offset is OK, since that's used along with a table in the header.tvwiz file to estimate the file's start time.

The other is the calculation of the start time for 0503, and I've had a look at the code for that, and I can't see what the problem is. Estimating times near the end of the recording is a bit tricky, because the table that's used to estimate time from offset simply records the offset every 10 sec. For offsets between the last of those and the actual end of the recording, I use a field that is supposed to contain the number of seconds from the last entry in the time-to-offset table to the end of the recording.

I need to be able to create this locally.

Do you see this problem on recordings that haven't been edited? Big Fish looks as though it might have been, but I can't tell about the other one.

[sub3R]

Yes that recording ‘Big Fish +’ had been ‘keep A-B only’ edited.

This one hasn’t been ‘keep A-B only’ edited:

Code: Select all

7TWO Taree: Country/Jules Hudson is house hunting in Gloucestershire with a coup
le from Camberley who are after the country dream.
    Sun Feb 19 20:32:00 2012 - Mon Feb 20 00:12:01 2012
    playtime:  220:01    recording size:   8262.6 MB    bit rate:   5.0 Mb/s
    autoDelete: Never
    Recording start offset:              262144
    Recording end offset:            8262909952
    File  File Offset       Size     Rec Offset Dup Flags Start Time
    0000            0   33554432         262144             00:00:00
    0001            0   33554432       33816576             00:01:05
    ...
    0126            0   33554432     4228120576             01:52:55
    0127            0   33554432     4261675008             01:53:49
    0128            0   33554432     4294967295             01:54:43
    0129            0   33554432     4294967295             01:55:36
    ...
    0244            0   33554432     4294967295             03:38:10
    0245            0   33554432     4294967295             03:39:04
    0246            0    8257536     4294967295             03:39:58

And this one hasn’t been edited or played. You may still have this recording:

Code: Select all

ABC1: Dalziel And Pascoe/A detective partnership of opposites. Dalziel discovers
 something shocking after the death of the mother of a detective sergeant on the
 team. Warren Clarke, Colin Buchanan
    Fri Feb 17 12:32:00 2012 - Fri Feb 17 14:01:16 2012
    playtime:   89:16    recording size:   2887.0 MB    bit rate:   4.3 Mb/s
    autoDelete: Never
    Recording start offset:              262144
    Recording end offset:            2887254016
    File  File Offset       Size     Rec Offset Dup Flags Start Time
    0000            0   33554432         262144             00:00:00
    0001            0   33554432       33816576             00:01:25
    ...
    0084            0   33554432     2818834432             01:27:17
    0085            0   33554432     2852388864             01:28:26
    0086            0    1310720     2885943296             00:53:34

So it still can get the last file wrong in an unedited recording.

[prl]

I still have my recording of Dalziel & Pascoe, but I've edited it since, and it (now?) doesn't show an obviously wrong start time for the last chunk.

[sub3R]

Hmm, ok that didn’t work then. I just set that ‘Dalziel And Pascoe’ straight from the FTA EPG.

Just looking through the list it appeared if the last file was over a certain size it would be ok, edited or not.

Last file size: 3,526,656 is ok, 1,966,080 isn’t, but then I found a 534,288 that was ok. But is looks as if larger than 3,526,656 last file sizes are ok time wise. So I need to check a bit more.

The trouble is with ‘keep A-B only’ editing, I can tell if the ‘A’ marker wasn’t placed at the start, but I can’t tell where the ‘B’ marker was placed – some may have been at the very end. Also some ‘keep A-B only’ recordings may have had the ‘A’ marker placed at the very start but the ‘B’ marker may have been before the end.

[sub3R]

I don’t know if this helps or even if it means anything.

A sample of 25 last files starting from the beginning of the list & working down (last file size is at the beginning, ‘+4’ is if offset 4294967295 is reached, ‘wrong’ or ‘ok’ is if start time is wrong or correct, ‘edited’ or ‘no edit’ is if the recording has been edited or not).

Code: Select all

  499,712 wrong    edited.      7,356,416 ok    edited.
1,310,720 wrong    no edit.     7,471,104 ok    edited.
1,335,296 wrong +4 edited.      8,257,536 ok +4 no edit.
2,170,880 wrong +4 edited.     11,202,560 ok +4 edited.
2,441,216 ok    +4 edited.     15,065,088 ok    edited.
2,490,368 wrong    edited.     18,710,528 ok +4 edited.
2,981,888 wrong    edited.     18,796,544 ok +4 edited. 
3,526,656 ok    +4 edited.     18,808,832 ok +4 edited.
3,608,576 wrong +4 edited.     20,291,584 ok    edited. 
5,201,920 wrong +4 edited.     22,740,992 ok +4 edited.
6,774,784 wrong +4 edited.     24,248,320 ok +4 no edit.
7,217,152 wrong +4 edited.     29,962,240 ok +4 edited.
                               30,470,144 ok +4 edited.

The ones that were wrong were obvious, the ones that were correct appeared to be correct - I didn’t do any accurate calculations.
Out of that sample of 25 with a size of 7,356,416 or over (right column group) the start time is correct. Under that size (left column group), except for two, the start time is wrong.
Edit: To clarify - the above list was re-sorted from the original list.

[prl]

I've got three instances in my recordings of "time goes backwards" on the last entry in the --debug=trunc output. In two of them, the last file is less than 8MB, but in the other, the last entry is 32MiB. However, it does contain some entries that are less than 8MB.

Code: Select all

SBS TWO: Movie: Goya In Bordeaux
...
    0128            0   33554432     4295229440             02:15:57
    0129            0    3932160     4328783872             02:03:10

SBS TWO: Movie: Kurt Wallander: Castles in the Sky
...
    0127            0   33554432     4261675008             02:06:15
    0128            0    1966080     4295229440             01:54:15

PRIME Canberra: BHGtoptailedit1/The 80's Revisited - Deborah Conway, Jon Stevens and Richard Clapton / Piano Bar / The Rubik's Cube Bedroom / Ant Farms and Sea Monkeys / Crepe Suzette
...
    0023            0   33554432      499060736             00:12:33
    0024            0   33554432      532615168             00:01:19

The first two are unedited, the last is edited, both topped-and-tailed and with internal edits (from some other testing a long time ago). The printout is from OS X, so it's not affected by the limitation of printing 2^32 and above (>= 4294967296). However, I get the same timing errors on both Windows and OS X.

Now that I've found some cases, I should be able to find out what's causing the problem.

[sub3R]

Ahh that’s good. I haven’t seen any recordings with file sizes less than 33,554,432 bytes except at the start & the end – that last example may have had a part cut out of the recording somewhere using ‘delete A-B’, I don’t use that edit option so that’s probably the reason why I haven’t seen it.

Not knowing if what my list showed had any bearing on the problem I’ve been looking at a few more samples & found one more that appeared to be ok (the time didn’t jump backwards). The last file size was less than 7,356,416 bytes (6,533,120), had been ‘keep A-B only’ edited & had only got to 1,827,074,048 offset (this was a 5.2Mb/s 1833.6MB ‘Grand Designs’ recording from ABC1).

[prl]

Ahh that’s good. I haven’t seen any recordings with file sizes less than 33,554,432 bytes except at the start & the end – that last example may have had a part cut out of the recording somewhere using ‘delete A-B’, I don’t use that edit option so that’s probably the reason why I haven’t seen it.

Not knowing if what my list showed had any bearing on the problem I’ve been looking at a few more samples & found one more that appeared to be ok (the time didn’t jump backwards). The last file size was less than 7,356,416 bytes (6,533,120), had been ‘keep A-B only’ edited & had only got to 1,827,074,048 offset (this was a 5.2Mb/s 1833.6MB ‘Grand Designs’ recording from ABC1).

The sizes in the trunc file are not file sizes. They may give that impression in an unedited file. A trunc file entry is basically an instruction to the playback engine that says "play Size bytes from File starting at File Offset - the start of this entry corresponds to offset Rec Offset in the whole recording" (and the "whole recording" starts at offset 262144, which is the size of header.tvwiz, though that may be a coincidence).

When edits happen, the underlying file sizes are not changed. The whole file is kept if it appears in the trunc file, and is deleted if it's not in the trunc file.

Anyway, I've found the bug, and it's triggered when the last entry in the time-to-offset table points within the second-last entry in the trunc table. That means that normally if the last entry in the trunc table plays for more than 10 sec (the interval between entries in the time-to-offset table), you don't see the bug, but if it's shorter, then the bug appears. The fact that it's a time problem, and not a data volume problem may be the reason why most of these bugs appear when the last trunc entry size is < 7MB and sometimes it happens for larger trunc entries - the size that triggers the problem will depend on the recording bit rate, and especially, then, on whether the recording is SD or HD.

The interpolation code for offsets past the last entry in the time-to-offset table was simply very broken. And that's all I'm going to say about it.

Fixed now in my development code.

I still need to find a way to get large offsets to print correctly in Windows. I have a couple of ideas, but I haven't tried them yet.

[sub3R]

Well there ya go ... I always thought that was the file size (32,768kB as shown in Windows Explorer for the data files = 33,554,432 bytes as shown --debug=trunc). Thanks for the explanation, although it’s probably written somewhere that I’ve read, or probably read & forgotten.

I was trying to pin the <7MB vs >7MB down to bit rates but no luck so far. Anyway as you say it was a time problem. I'm glad you found it.

In regards to a ‘delete A-B’ edit. This is an instant manual recording I recently did, manually stopped & did a ‘delete A-B’ edit after about 5min:

Code: Select all

ABC News 24: *Australian Story/Exclusive. ... *AC3  Tue Feb 21 14:13:12 2012 - Tue Feb 21 14:32:39 2012
    playtime:   19:27    recording size:   1172.5 MB    bit rate:   8.0 Mb/s
    Recording start offset:              262144
    Recording end offset:            1172787200
    File  File Offset       Size     Rec Offset Dup Flags Start Time
    0000            0   33554432         262144             00:00:00
    ...
    0009            0   33554432      302252032             00:05:08    
    0010            0   32788480      335806464             00:05:40
    0019     32964608     589824      368594944             00:06:11
    0020            0   33554432      369184768             00:06:12
    ...
    0042            0   33554432     1107382272             00:18:31
    0043            0   32899072     1140936704             00:19:07

Now I've seen one.

[prl]

...
In regards to a ‘delete A-B’ edit. This is an instant manual recording I recently did, manually stopped & did a ‘delete A-B’ edit after about 5min:

Code: Select all

ABC News 24: *Australian Story/Exclusive. ... *AC3  Tue Feb 21 14:13:12 2012 - Tue Feb 21 14:32:39 2012
    playtime:   19:27    recording size:   1172.5 MB    bit rate:   8.0 Mb/s
    Recording start offset:              262144
    Recording end offset:            1172787200
    File  File Offset       Size     Rec Offset Dup Flags Start Time
    0000            0   33554432         262144             00:00:00
    ...
    0009            0   33554432      302252032             00:05:08    
    0010            0   32788480      335806464             00:05:40        <<< Don't play 0010 to the end
                                                                            <<< Skip files 0011-0018 (files 0011-1118 have been deleted)
    0019     32964608     589824      368594944             00:06:11        <<< Don't start 0019 at its beginning, but play it through to its end
                                                                            <<< (589824+32964608 = 33554432)
    0020            0   33554432      369184768             00:06:12
    ...
    0042            0   33554432     1107382272             00:18:31
    0043            0   32899072     1140936704             00:19:07

Now I've seen one.

[prl]

I've fixed the incorrect start time for the last trunc file entry in --debug=trunc, found a workaround for (IMO) a perl bug that was causing getWizPnP to print incorrect Rec Offset values in --debug=trunc, and found a workaround that was causing the initial sort of the recording index to fail with a fatal perl error on Cygwin (affected almost all important operations).

The problem with the offset printing was that in Windows ActivePerl, bignums (unlimited precision numbers) are printed as 32-bit numbers if the printf formatting codes %d (signed integer) or %u (unsigned integer) are used. If I print using %s (string format ) the numbers print correctly on Windows ActivePerl.

The sort problem in Cygwin perl was worked around by removing the "use bignum" pragma from the main program Perl file. Go figure.

I hope to be able to release OS X and Windows canned versions of 0.5.3beta2 with these fixes tomorrow (22 Beb).

[sub3R]

Thanks again for the explanation on the problem & fix Peter - though some of that went over my head.

In regards to the ‘delete A-B’ edited ‘ABCNews24’ recording, I gathered that is what happened & what is shown.

Something I noticed when I downloaded that recording to the PC:

When I downloaded it to the PC with YARDWiz 0.4.1, Windows Explorer shows file 0010 as 32,020kB (32,788,480 bytes) & file 0043 as 32,128kB (32,899,072 bytes). All other files are the normal 32,768kB. VideoRedo TVSuite shows file 0010 from 0.00 to 31.25 seconds & file 0043 from 0.00 to 33.48 seconds.

When I download it to the PC with WizFX 1.0.2.3, Windows Explorer shows file 0010 as the normal 32,768kB size (33,554,432 bytes), the same as the others except for File 0043 which is shown as 32,128kB (32,899,072 bytes). VideoReDo TVSuite shows file 0010 from 0.00 to 32.11 seconds & file 0043 from 0.00 to 33.48 seconds.

I think ‘Glow’ picked something like this up some time ago, but I think that was at the start or the end of the recording. Are the above results just the two different ways YARDWiz/getwizpnp & WizFX download?

[prl]

getWizPnP (used to do the actual downloads by YARDWiz and WizZilla as you know, but for general information) only downloads the part of recording data files up to their last used byte. I have though of optimising a bit more, and downloading only the parts that are actually used, but that would require tampering with the trunc file. I think WizFX always downloads the whole recording file (except in .ts mode where that would be wrong).

[sub3R]

I thought it may have been something like that. VideoReDo TVSuite plays back just that little bit extra at the end of file 0010 when downloaded with WizFX. But that’s being really picky, editing on the wiz isn’t that accurate anyway.

[prl]

Version 0.5.3 beta2 limited release

Version 0.5.3 released. Do not use the beta versions. Links to beta versions removed.

A new limited release beta version of getWizPnP is available. Only the canned versions are available:

• Windows
• OS X.
• Cygwin
• Linux

Changes from the last full release (0.5.2) are:

• Adds a consistency check to --check between the trunc entry sizes and the recording offsets in the trunc file. The recording offsets should be a running total of the sizes.
• Offsets printed in --debug=trunc and --debug=offsets now print correctly on Windows (this bug only appears to have affected ActivePerl on Windows, including the distributed "compiled" version for Windows).
• Fixes a bug that was causing an incorrect estimated start time for the last trunc entry printed by --debug=trunc if the last entry played for more than 10 sec.
• Changed the make_doc.sh (Unix shell script) to make_doc.pl (Perl script) to make documentation generation more portable to Windows, but the script has problems when run from within a Makefile on the Windows port of Gnu make. Some cosmetic improvements to the HTML output. These scripts are not included in"compiled" versions.
• Started on modifications to Makefile to make it usable on Windows using Windows ports of make and the Unix shell tools. Still not working correctly on Windows. Only affects developers. Not visible to users of "compiled" versions.
• Modified Makefile to include this file in the "compiled" ZIP files.

[sub3R]

‘GetWizPnP-0.5.3beta2-Compiled-Windows’ on my Windows XP sp3 PC shows the last file in all recordings on both S1s incrementing in start time from the previous file when ‘getwizpnp -a -H (fixed IP address) --list --verbose -x --debug=trunc’ is run.

For example the ABC1 ‘Dalziel And Pascoe’ recording here now shows:

Code: Select all

ABC1: Dalziel And Pascoe/A detective partnership of opposites. ...
    Index name: recordings/Dalziel And Pascoe Feb.17.2012_12.32
    Fri Feb 17 12:32:00 2012 - Fri Feb 17 14:01:16 2012
    playtime:   89:16    recording size:   2887.0 MB    bit rate:   4.3 Mb/s
    Recording start offset:              262144
    Recording end offset:            2887254016
    File  File Offset       Size     Rec Offset Dup Flags Start Time
    0000            0   33554432         262144             00:00:00
    0001            0   33554432       33816576             00:01:25
    0002            0   33554432       67371008             00:02:43
    ...
    0084            0   33554432     2818834432             01:27:17
    0085            0   33554432     2852388864             01:28:26
    0086            0    1310720     2885943296             01:29:14

The ABCNews24 ‘Australian Story/Exclusive’ shows the same as previously posted here .

As expected I still get the random ‘missing data file’ on both S1s when running --check. It doesn’t show any other problems though.

Rarely when I copy & paste a known command from ‘Notepad’ to the command line prompt, getwizpnp executes straight away, it doesn’t wait for me to hit <Enter>, but most of the time it does wait for me to hit <Enter>. I hadn’t noticed this with earlier versions, but it could be a Windows problem.

[prl]

...
Rarely when I copy & paste a known command from ‘Notepad’ to the command line prompt, getwizpnp executes straight away, it doesn’t wait for me to hit <Enter>, but most of the time it does wait for me to hit <Enter>. I hadn’t noticed this with earlier versions, but it could be a Windows problem.

That can't be a getWizPnP problem - it's just not possible, because getWizPnP doesn't run until cmd reads the end-of-line from its window, parses the command and only then runs getWizPnP. My best guess is that it depends on whether you cut/paste the end-of-line character from Notepad into the cmd window.

Good that you're seeing fixes to the problems I thought I'd fixed. I haven't changed anything that I think might address the missing files problem. I have thought of making the code that checks whether there recording file is there (and whether its size is consistent with the trunc entries that reference it) retry a couple of times on failure. But it's something I can't reproduce here.

[sub3R]

You were right. ‘NotePad++’ showed the space I normally put at the end of the command in ‘Notepad’ to avoid such problems was missing, so every now & again I had been copying the getwizpnp command plus the carriage return & line feed.

[sub3R]

... I haven't changed anything that I think might address the missing files problem. I have thought of making the code that checks whether there recording file is there (and whether its size is consistent with the trunc entries that reference it) retry a couple of times on failure. But it's something I can't reproduce here.

The strange thing with these reported ‘missing files’ is so far between the two S1s I have seen them appear in 13 different recordings but usually only in one recording per S1 per --check run. The next run may see the same recording list a different missing file. The same recording may list a missing file for that day & sometimes even the next couple of days, but then something changes on the wiz & a different recording starts listing a missing file & the previous recording stops listing a missing file. So far I haven’t pinned down what causes the change.

Because --check sits waiting for ages on the one recording before eventually reporting a missing file for that recording I thought it may be LAN problem. But every time I ping either wiz I get very good results.

[sub3R]

...
... But it's something I can't reproduce here.

And I now know why. Running ‘getwizpnp -a -H (fixed IP address) --verbose --check’, I found this ‘missing data file’ problem occurs 1min 30sec after getWizPnP finds the requested S1 & starts listing the recordings - the problem occurs at the same 1min 30sec when looking at either S1. At this point the cursor sits flashing on the next line for a period of 3 minutes before listing the ‘missing data file’. Once the missing file is listed the remaining recordings continue to be listed at the same rate as prior to the 3min stall point. The reason I was seeing different recordings show a ‘missing data file’ was because recordings were being added to both S1s & other recordings deleted.

After finding this I decided to do something I should have done when I first noticed this problem. I borrowed the Vista Notebook to see what happened when I ran the identical getWizPnP command from getWizPnp-0.5.3beta2 on the Notebook. This twice gave a perfect listing for both S1s without listing any missing data files - all listings taking considerably longer than 1min 30sec.

So the problem is with the XP PC seeing the Vista Notebook & the XP PC are on the same LAN using the same router (XP PC connected Ethernet to the router & the Notebook connected wireless to the router). Both the Notebook & the XP PC use the same version of Nortons 360 with the same Firewall.

Now I just need to find what’s causing the interruption at 1min 30 seconds for 3 minutes.