Package feature doesn't work in the GUI on Windows: Protocol not found

[JohnstonJ]

1. Install DVRescue GUI 24.07 using the normal setup program from https://mediaarea.net/download/binary/dvrescue-gui/24.07/dvrescue_GUI_24.07_Windows.exe
2. Run DVRescue from the Start menu. It is not running as an administrator.
3. Go to the Package section of the GUI.
4. Add a bare DV file as an input file.
5. Do not specify any segmenting rules.
6. Specify mkv output file. (But I think MOV is broken too)
7. Specify Package into same folder
8. Click Add to Queue.

The file will then fail to convert in the queue. Here are the debug logs. Note the error from mktemp, and subsequent errors where it's unable to write files:

beginning commands log
C:/Program Files/dvrescue/cygwin/bin/bash.exe C:/Program Files/dvrescue/tools/dvpackager -v -X /cygdrive/c/Program Files/dvrescue/scripts/xml.sh -O %FILENAME%_part%PARTNO% -a n -o /cygdrive/C/Users/JohnstonJ/AppData/Local/Temp/mpout/digitaltest -T /cygdrive/C/Users/JohnstonJ/AppData/Local/Temp/mpout/digitaltest/pass1.dv_merged.dv.dvrescue.xml /cygdrive/C/Users/JohnstonJ/AppData/Local/Temp/mpout/digitaltest/pass1.dv_merged.dv

00:00:00.000000|00:00:52.152100|0|1562|00:00:00;02|0|2024-07-08 19:55:56|720x480|30000/1001|4:1:1|4/3|32000|4||||-|187560000|-|/cygdrive/C/Users/JohnstonJ/AppData/Local/Temp/mpout/digitaltest/pass1.dv_merged_part1.mov

C:/Program Files/dvrescue/cygwin/bin/bash.exe C:/Program Files/dvrescue/tools/dvpackager -v -X /cygdrive/c/Program Files/dvrescue/scripts/xml.sh -O %FILENAME%_part%PARTNO% -a n -e mkv -o /cygdrive/C/Users/JohnstonJ/AppData/Local/Temp/mpout/digitaltest -T /cygdrive/C/Users/JohnstonJ/AppData/Local/Temp/mpout/digitaltest/pass1.dv_merged.dv.dvrescue.xml /cygdrive/C/Users/JohnstonJ/AppData/Local/Temp/mpout/digitaltest/pass1.dv_merged.dv

00:00:00.000000|00:00:52.152100|0|1562|00:00:00;02|0|2024-07-08 19:55:56|720x480|30000/1001|4:1:1|4/3|32000|4||||-|187560000|-|/cygdrive/C/Users/JohnstonJ/AppData/Local/Temp/mpout/digitaltest/pass1.dv_merged_part1.mkv

C:/Program Files/dvrescue/cygwin/bin/bash.exe C:/Program Files/dvrescue/tools/dvpackager -v -X /cygdrive/c/Program Files/dvrescue/scripts/xml.sh -F /cygdrive/c/Program Files/dvrescue/scripts/ffmpeg.sh -D /cygdrive/c/Program Files/dvrescue/scripts/dvrescue.sh -M /cygdrive/c/Program Files/dvrescue/scripts/mediainfo.sh -z -a n -e mkv -o /cygdrive/C/Users/JohnstonJ/AppData/Local/Temp/mpout/digitaltest -x /cygdrive/C/Users/JohnstonJ/AppData/Local/Temp/mpout/digitaltest/pass1.dv_merged.dv.dvrescue.xml /cygdrive/C/Users/JohnstonJ/AppData/Local/Temp/mpout/digitaltest/pass1.dv_merged.dv

#CONDENSE_OPTS is set to -s

#Using /cygdrive/c/Program Files/dvrescue/scripts/ffmpeg.sh for ffmpeg operations.

#No xmlstarlet error

#DV_FRAME_COUNT=(1563)

#SOURCE_FORMAT=(DV)

#Trying to present a table of ranges

The results will be written to /cygdrive/C/Users/JohnstonJ/AppData/Local/Temp/mpout/digitaltest

### Packaging started: /cygdrive/C/Users/JohnstonJ/AppData/Local/Temp/mpout/digitaltest/pass1.dv_merged_part1.mkv

#Reading from DV stream input at byte range 0-187560000

#The audio range sublist (from frame 0 to 1562) is

#00:00:00.000000|00:00:52.152100|0|1562|00:00:00;02|0|2024-07-08 19:55:56|720x480|30000/1001|4:1:1|4/3|32000|4||||0|187560000|187440000

#Prepping a mapping for 4 channel input ().

mktemp: too few X's in template 'dvpackager'

#Writing a chapter track at C:/Program Files/dvrescue/tools/dvpackager: Can't create temp file, exiting....ffmetadata.

C:/Program Files/dvrescue/tools/dvpackager: line 1257: C:/Program Files/dvrescue/tools/dvpackager: Can't create temp file, exiting....ffmetadata: Permission denied

#Trying to run: /cygdrive/c/Program Files/dvrescue/scripts/ffmpeg.sh  -y

[dv @ 0000014C969FDAC0] Estimating duration from bitrate, this may be inaccurate

Input #0, dv, from 'subfile,,start,0,end,187560000,,:C:\Users\JohnstonJ\AppData\Local\Temp\mpout\digitaltest\pass1.dv_merged.dv':
  Metadata:
    timecode        : 00:00:00;02
  Duration: 00:00:52.15, start: 0.000000, bitrate: 28771 kb/s
  Stream #0:0: Video: dvvideo, yuv411p, 720x480 [SAR 8:9 DAR 4:3], 25000 kb/s, 29.97 fps, 29.97 tbr, 29.97 tbn

  Stream #0:1: Audio: pcm_s16le, 32000 Hz, stereo, s16, 1024 kb/s
  Stream #0:2: Audio: pcm_s16le, 32000 Hz, stereo, s16, 1024 kb/s

19:55:56: Protocol not found

### Packaging error: file-missing

### Packaging error note: Tried to write an output to /cygdrive/C/Users/JohnstonJ/AppData/Local/Temp/mpout/digitaltest/pass1.dv_merged_part1.mkv but it's not there. :-/ 

### Packaging finished: /cygdrive/C/Users/JohnstonJ/AppData/Local/Temp/mpout/digitaltest/pass1.dv_merged_part1.mkv

ERROR: pass1.dv_merged.dv contained 1563 DV frames, but the outputs contain 0 frames of DV and 0 were skipped

Packaging pass1.dv_merged.dv
# Segmentation options. Split on: Recording_Start_Marker = 0, Recording_Timestamp_Jump = 0, Timecode_Jump = 0, Audio_characteristics_change = 0, Aspect_Ratio_change = 1
#         St='Flagged Start of a recording', ncTC='non-continuous timecode value', ncR='non-continuous recording timestamp value'
  # | PTS Range                         | Duration | Frame Range         | Byte Range                | Timecode    | Recording Timestamp    | Size      | Frame Rate | DAR   | ChSub | Audio     | St | ncTC | ncR |
  1 | 00:00:00.000000 - 00:00:52.152100 |   52.152 |        0 -     1562 |           0 -   187560000 | 00:00:00;02 | 2024-07-08 19:55:56    |   720x480 | 30000/1001 |   4/3 | 4:1:1 | 4ch 32000 |    |      |     |

[dericed]

Thanks for this. I believe the mktemp error you're mentioning was fixed in https://github.com/mipops/dvrescue/commit/1be1d83d7f536689d68a1acf72b22db930d592fe. Could you retry with the latest daily build at https://mediaarea.net/download/snapshots/binary/dvrescue/?

But I suspect the "protocol not found" message is indicating that the ffmpeg build bundled into the dvrescue app for windows is missing the subfile protocol which dvpackager depends on. @JeromeMartinez, could you confirm that the bundled windows ffmpeg build includes the subfile input protocol (it should be listed in ffmpeg -protocols

[JohnstonJ]

@dericed The daily snapshots don't seem to include the full Windows build with GUI for some reason.

Since these are text shell scripts, I have instead manually edited the shell scripts from the portable version of 24.07 using the changes at https://github.com/mipops/dvrescue/commit/1be1d83d7f536689d68a1acf72b22db930d592fe

This appears to have fixed the mktemp error. However, the conversion is still failing.

Here's the full debug log when I reran it:

``` beginning commands log C:/Users/JOHNST~1/AppData/Local/Temp/mpout/dvrescue_GUI_24.07_Windows_x64/cygwin/bin/bash.exe C:/Users/JOHNST~1/AppData/Local/Temp/mpout/dvrescue_GUI_24.07_Windows_x64/tools/dvpackager -v -X /cygdrive/c/Users/JOHNST~1/AppData/Local/Temp/mpout/dvrescue_GUI_24.07_Windows_x64/scripts/xml.sh -O %FILENAME%_part%PARTNO% -a n -o /cygdrive/C/Users/JohnstonJ/AppData/Local/Temp/mpout/digitaltest -T /cygdrive/C/Users/JohnstonJ/AppData/Local/Temp/mpout/digitaltest/pass1.dv_merged.dv.dvrescue.xml /cygdrive/C/Users/JohnstonJ/AppData/Local/Temp/mpout/digitaltest/pass1.dv_merged.dv 00:00:00.000000|00:00:52.152100|0|1562|00:00:00;02|0|2024-07-08 19:55:56|720x480|30000/1001|4:1:1|4/3|32000|4||||-|187560000|-|/cygdrive/C/Users/JohnstonJ/AppData/Local/Temp/mpout/digitaltest/pass1.dv_merged_part1.mov C:/Users/JOHNST~1/AppData/Local/Temp/mpout/dvrescue_GUI_24.07_Windows_x64/cygwin/bin/bash.exe C:/Users/JOHNST~1/AppData/Local/Temp/mpout/dvrescue_GUI_24.07_Windows_x64/tools/dvpackager -v -X /cygdrive/c/Users/JOHNST~1/AppData/Local/Temp/mpout/dvrescue_GUI_24.07_Windows_x64/scripts/xml.sh -O %FILENAME%_part%PARTNO% -a n -e mkv -o /cygdrive/C/Users/JohnstonJ/AppData/Local/Temp/mpout/digitaltest -T /cygdrive/C/Users/JohnstonJ/AppData/Local/Temp/mpout/digitaltest/pass1.dv_merged.dv.dvrescue.xml /cygdrive/C/Users/JohnstonJ/AppData/Local/Temp/mpout/digitaltest/pass1.dv_merged.dv 00:00:00.000000|00:00:52.152100|0|1562|00:00:00;02|0|2024-07-08 19:55:56|720x480|30000/1001|4:1:1|4/3|32000|4||||-|187560000|-|/cygdrive/C/Users/JohnstonJ/AppData/Local/Temp/mpout/digitaltest/pass1.dv_merged_part1.mkv C:/Users/JOHNST~1/AppData/Local/Temp/mpout/dvrescue_GUI_24.07_Windows_x64/cygwin/bin/bash.exe C:/Users/JOHNST~1/AppData/Local/Temp/mpout/dvrescue_GUI_24.07_Windows_x64/tools/dvpackager -v -X /cygdrive/c/Users/JOHNST~1/AppData/Local/Temp/mpout/dvrescue_GUI_24.07_Windows_x64/scripts/xml.sh -F /cygdrive/c/Users/JOHNST~1/AppData/Local/Temp/mpout/dvrescue_GUI_24.07_Windows_x64/scripts/ffmpeg.sh -D /cygdrive/c/Users/JOHNST~1/AppData/Local/Temp/mpout/dvrescue_GUI_24.07_Windows_x64/scripts/dvrescue.sh -M /cygdrive/c/Users/JOHNST~1/AppData/Local/Temp/mpout/dvrescue_GUI_24.07_Windows_x64/scripts/mediainfo.sh -z -a n -e mkv -o /cygdrive/C/Users/JohnstonJ/AppData/Local/Temp/mpout/digitaltest -x /cygdrive/C/Users/JohnstonJ/AppData/Local/Temp/mpout/digitaltest/pass1.dv_merged.dv.dvrescue.xml /cygdrive/C/Users/JohnstonJ/AppData/Local/Temp/mpout/digitaltest/pass1.dv_merged.dv #CONDENSE_OPTS is set to -s #Using /cygdrive/c/Users/JOHNST~1/AppData/Local/Temp/mpout/dvrescue_GUI_24.07_Windows_x64/scripts/ffmpeg.sh for ffmpeg operations. #No xmlstarlet error #DV_FRAME_COUNT=(1563) #SOURCE_FORMAT=(DV) #Trying to present a table of ranges The results will be written to /cygdrive/C/Users/JohnstonJ/AppData/Local/Temp/mpout/digitaltest ### Packaging started: /cygdrive/C/Users/JohnstonJ/AppData/Local/Temp/mpout/digitaltest/pass1.dv_merged_part1.mkv #Reading from DV stream input at byte range 0-187560000 #The audio range sublist (from frame 0 to 1562) is #00:00:00.000000|00:00:52.152100|0|1562|00:00:00;02|0|2024-07-08 19:55:56|720x480|30000/1001|4:1:1|4/3|32000|4||||0|187560000|187440000 #Prepping a mapping for 4 channel input (). #Writing a chapter track at /cygdrive/c/Users/JohnstonJ/AppData/Local/Temp/dvpackager.c9b2N2.ffmetadata. #Found 3 point(s) for chapter marks. #Chapter: 00:00:00.000000-00:00:16.549866 (0-1654986): 00:00:00;02 - 2024-07-08 19:55:56 #Chapter: 00:00:16.549866-00:00:32.565866 (1654986-3256586): 00:00:16;18 - 2024-07-08 19:56:23 #Chapter: 00:00:32.565866-00:00:52.152100 (3256586-5215210): 00:00:32;18 - 2024-07-08 19:56:47 #Trying to run: /cygdrive/c/Users/JOHNST~1/AppData/Local/Temp/mpout/dvrescue_GUI_24.07_Windows_x64/scripts/ffmpeg.sh -y [dv @ 000001906769C880] Estimating duration from bitrate, this may be inaccurate Input #0, dv, from 'subfile,,start,0,end,187560000,,:C:\Users\JohnstonJ\AppData\Local\Temp\mpout\digitaltest\pass1.dv_merged.dv': Metadata: timecode : 00:00:00;02 Duration: 00:00:52.15, start: 0.000000, bitrate: 28771 kb/s Stream #0:0: Video: dvvideo, yuv411p, 720x480 [SAR 8:9 DAR 4:3], 25000 kb/s, 29.97 fps, 29.97 tbr, 29.97 tbn Stream #0:1: Audio: pcm_s16le, 32000 Hz, stereo, s16, 1024 kb/s Stream #0:2: Audio: pcm_s16le, 32000 Hz, stereo, s16, 1024 kb/s Input #1, ffmetadata, from 'C:\Users\JohnstonJ\AppData\Local\Temp\dvpackager.c9b2N2.ffmetadata': Duration: 00:00:52.15, start: 0.000000, bitrate: 0 kb/s Chapters: Chapter #1:0: start 0.000000, end 16.549860 Metadata: title : 00:00:00;02 - 2024-07-08 19:55:56 Chapter #1:1: start 16.549860, end 32.565860 Metadata: title : 00:00:16;18 - 2024-07-08 19:56:23 Chapter #1:2: start 32.565860, end 52.152100 Metadata: title : 00:00:32;18 - 2024-07-08 19:56:47 19:55:56: Protocol not found ### Packaging error: file-missing ### Packaging error note: Tried to write an output to /cygdrive/C/Users/JohnstonJ/AppData/Local/Temp/mpout/digitaltest/pass1.dv_merged_part1.mkv but it's not there. :-/ ### Packaging finished: /cygdrive/C/Users/JohnstonJ/AppData/Local/Temp/mpout/digitaltest/pass1.dv_merged_part1.mkv ERROR: pass1.dv_merged.dv contained 1563 DV frames, but the outputs contain 0 frames of DV and 0 were skipped Packaging pass1.dv_merged.dv # Segmentation options. Split on: Recording_Start_Marker = 0, Recording_Timestamp_Jump = 0, Timecode_Jump = 0, Audio_characteristics_change = 0, Aspect_Ratio_change = 1 # St='Flagged Start of a recording', ncTC='non-continuous timecode value', ncR='non-continuous recording timestamp value' # | PTS Range | Duration | Frame Range | Byte Range | Timecode | Recording Timestamp | Size | Frame Rate | DAR | ChSub | Audio | St | ncTC | ncR | 1 | 00:00:00.000000 - 00:00:52.152100 | 52.152 | 0 - 1562 | 0 - 187560000 | 00:00:00;02 | 2024-07-08 19:55:56 | 720x480 | 30000/1001 | 4/3 | 4:1:1 | 4ch 32000 | | | | ```

I found a file ffmpeg.args, which I found had the following contents:

-y -nostdin -hide_banner -probesize 10M -i subfile,,start,0,end,187560000,,:C:\Users\JohnstonJ\AppData\Local\Temp\mpout\digitaltest\pass1.dv_merged.dv -i C:\Users\JohnstonJ\AppData\Local\Temp\dvpackager.c9b2N2.ffmetadata -map_metadata 1 -filter_complex [0:a:0]aresample=async=1:min_hard_comp=0.01[aud1];[0:a:1]aresample=async=1:min_hard_comp=0.01[aud2] -t 52.152100000 -c:a pcm_s16le -c:v:0 copy -f matroska -map 0:v:0 -map [aud1] -map [aud2] -metadata timecode=00:00:00;02 -metadata DATE_RECORDED=2024-07-08 19:55:56 -aspect 4/3 C:\Users\JohnstonJ\AppData\Local\Temp\mpout\digitaltest\pass1.dv_merged_part1.mkv

If I try manually running that command with the bundled FFmpeg included with Windows GUI, I get the same protocol error:

``` C:\Users\JOHNST~1\AppData\Local\Temp\mpout\dvrescue_GUI_24.07_Windows_x64>ffmpeg -y -nostdin -hide_banner -probesize 10M -i subfile,,start,0,end,187560000,,:C:\Users\JohnstonJ\AppData\Local\Temp\mpout\digitaltest\pass1.dv_merged.dv -i C:\Users\JohnstonJ\AppData\Local\Temp\dvpackager.c9b2N2.ffmetadata -map_metadata 1 -filter_complex [0:a:0]aresample=async=1:min_hard_comp=0.01[aud1];[0:a:1]aresample=async=1:min_hard_comp=0.01[aud2] -t 52.152100000 -c:a pcm_s16le -c:v:0 copy -f matroska -map 0:v:0 -map [aud1] -map [aud2] -metadata timecode=00:00:00;02 -metadata DATE_RECORDED=2024-07-08 19:55:56 -aspect 4/3 C:\Users\JohnstonJ\AppData\Local\Temp\mpout\digitaltest\pass1.dv_merged_part1.mkv [dv @ 000001D403ECCA00] Estimating duration from bitrate, this may be inaccurate Input #0, dv, from 'subfile,,start,0,end,187560000,,:C:\Users\JohnstonJ\AppData\Local\Temp\mpout\digitaltest\pass1.dv_merged.dv': Metadata: timecode : 00:00:00;02 Duration: 00:00:52.15, start: 0.000000, bitrate: 28771 kb/s Stream #0:0: Video: dvvideo, yuv411p, 720x480 [SAR 8:9 DAR 4:3], 25000 kb/s, 29.97 fps, 29.97 tbr, 29.97 tbn Stream #0:1: Audio: pcm_s16le, 32000 Hz, stereo, s16, 1024 kb/s Stream #0:2: Audio: pcm_s16le, 32000 Hz, stereo, s16, 1024 kb/s Input #1, ffmetadata, from 'C:\Users\JohnstonJ\AppData\Local\Temp\dvpackager.c9b2N2.ffmetadata': Duration: 00:00:52.15, start: 0.000000, bitrate: 0 kb/s Chapters: Chapter #1:0: start 0.000000, end 16.549860 Metadata: title : 00:00:00;02 - 2024-07-08 19:55:56 Chapter #1:1: start 16.549860, end 32.565860 Metadata: title : 00:00:16;18 - 2024-07-08 19:56:23 Chapter #1:2: start 32.565860, end 52.152100 Metadata: title : 00:00:32;18 - 2024-07-08 19:56:47 19:55:56: Protocol not found ```

Here is the result of running `ffmpeg -protocols`:

``` C:\Users\JOHNST~1\AppData\Local\Temp\mpout\dvrescue_GUI_24.07_Windows_x64>ffmpeg -protocols ffmpeg version 6.0 Copyright (c) 2000-2023 the FFmpeg developers built with Microsoft (R) C/C++ Optimizing Compiler Version 19.28.29913 for x64 configuration: --prefix=. --enable-gpl --enable-version3 --toolchain=msvc --extra-libs=libfreetype.a --enable-libfreetype --disable-securetransport --disable-videotoolbox --disable-autodetect --disable-doc --disable-debug --enable-static --disable-shared libavutil 58. 2.100 / 58. 2.100 libavcodec 60. 3.100 / 60. 3.100 libavformat 60. 3.100 / 60. 3.100 libavdevice 60. 1.100 / 60. 1.100 libavfilter 9. 3.100 / 9. 3.100 libswscale 7. 1.100 / 7. 1.100 libswresample 4. 10.100 / 4. 10.100 libpostproc 57. 1.100 / 57. 1.100 Supported file protocols: Input: async cache concat concatf crypto data fd ffrtmphttp file ftp gopher hls http httpproxy mmsh mmst pipe rtmp rtmpt rtp srtp subfile tcp udp udplite Output: crypto fd ffrtmphttp file ftp gopher http httpproxy icecast md5 pipe prompeg rtmp rtmpt rtp srtp tee tcp udp udplite ```

I have a copy of FFmpeg 7.0.1, so I tried temporarily swapping that in. This time, I got a more verbose error:

[out#0/matroska @ 000001e189c13400] Error opening output 19:55:56: Protocol not found
Error opening output file 19:55:56.
Error opening output files: Protocol not found

Is it trying to create files with : characters in them on Windows? Those filenames aren't allowed on Windows...

[JohnstonJ]

@dericed ah! I think the problem is that this part of the ffmpeg command line was not properly quoted:

-metadata DATE_RECORDED=2024-07-08 19:55:56

If I try running with -metadata "DATE_RECORDED=2024-07-08 19:55:56", then it works.

I do see that there is already some quoting at https://github.com/mipops/dvrescue/blob/b8354414cc18966be60def872d36057594e593b6/tools/dvpackager#L1226

so somehow it is being subsequently lost somewhere...

[JohnstonJ]

@dericed I think this is the problem: https://github.com/mipops/dvrescue/blob/b8354414cc18966be60def872d36057594e593b6/Source/GUI/dvrescue/dvrescue/windows-tools/scripts/ffmpeg.sh#L32

If I change it to:

ffmpeg "${args[@]}"

then it works, and I get the expected DATE_RECORDED value in the ffmpeg output:

Output #0, matroska, to 'C:\Users\JohnstonJ\AppData\Local\Temp\mpout\digitaltest\pass1.dv_merged_part1.mkv':
  Metadata:
    timecode        : 00:00:00;02
    DATE_RECORDED   : 2024-07-08 19:55:56
    encoder         : Lavf60.3.100

[ElderOrb]

https://github.com/mipops/dvrescue/pull/920

[dericed]

Thanks, I just merged https://github.com/mipops/dvrescue/pull/920, so @JohnstonJ please test the next windows daily build at https://old.mediaarea.net/download/snapshots/binary/dvrescue-gui/ (whatever comes after 0729)

[JohnstonJ]

@dericed just tried the packaging feature again. It's still broken, now with a different error. Looks to be the same as https://github.com/mipops/dvrescue/issues/925

I think the line endings in the shell scripts got messed up. Even though this is Windows, I think Cygwin's still going to expect Unix line endings.

[JohnstonJ]

@dericed I retested with the snapshot from https://mediaarea.net/download/snapshots/binary/dvrescue-gui/20240731/ .... I'm not encountering any of the errors mentioned in this issue any more, so I'll go ahead and close the issue....

The remaining problem is tracked in #927.

Thanks for the quick fixes!