1 Topic by amenex

  • amenex
  • Member
  • Offline

I originally posted this at the end of an earlier one ... but it seems to have been missed, so I've started a new topic and deleted the material from the earlier topic.

Running two video cameras simultaneously, I can make as many as a dozen trials in the same "go."  Afterwards, I transfer the ca. 350MB master videos to the PC and carve out the pairs of runs.  Keeping track of which is which is easy because Kinovea Expt'l keeps track of the run times accurately.

First, a minor problem arises: Even though I'm fairly careful to match the starting points and durations of each pair, and I'm successful in saving each separate video, when I open the pair in dual screen mode to review my work and select the pair that best matches my aims, the ending points of each video no longer match, as though the file save process loses track of where to truncate the original file. I can live with this little bug, as it's easy to re-do the ending points. The starting points are behaving OK.

Second: A major problem arises: When I open the pair ... in the present instance, starting from the last pair of the dozen pairs saved in the first editing go-round ... I fix up the ending points of each video and save one. That goes OK... But when I try to save the second re-edited video I get an error to the effect that the file format is wrong, and the original saved version becomes un-openable.  This has happened twice in a row, to two separate pairs. Kinovea Expt'l doesn't crash, but that second video disappears from the Preview screen and is replace by a blank box ... kinda like a silent migraine.

When I try to open the twelfth bad video, QuickTime says: "Error -2010: The movie contains some invalid data" and gives the filename. That's even after I've re-edited the master file and saved the matched pair again. When I look at the eleventh bad video with Windows xplorer, it's now 1.0KB long ... down from 33MB. Oh, oh. My data's gone, but the original master video is still OK, and I can re-do the editing, but not of all twelve videos. That was a three-hour job originally.

When QuickTime tried to open the twelfth bad video, it gave me the error message quoted above, but that same video can still be opened with Windows Media Player and runs without incident. That heightens the mystery. I'll re-start the PC and try QuickTime again after I send this message.

After re-starting Windows XP Pro SP3, I find that QuickTime won't open _any_ of the saved videos, even ones that I hadn't opened with Kinovea Expt'l in the present editing session. Same error as quoted in the immediately preceding update. I  may even be getting an occasional error from Windows Media Player ...

Best regards,
George Langford
amenex

Here's the log text for the eleventh pair; one file (Part11-030-Oil.MP4) is OK start to finish; the second file (Part11-462- H20.MP4) is the one that's history now; I had to snip out some repetitive stuff to reduce the post size:

1665937 - DEBUG - [22] - VideoReaderFFMpeg - Image aspect ratio: Auto
1665984 - DEBUG - [22] - VideoReaderFFMpeg - Switching decoding mode. NotInitialized -> OnDemand
1666031 - DEBUG - [22] - VideoReaderFFMpeg - Seeking to [74880] completed. Final position:[75075]
1666046 - DEBUG - [22] - VideoReaderFFMpeg - Seeking to [149760] completed. Final position:[150150]
1666062 - DEBUG - [22] - VideoReaderFFMpeg - Seeking to [224640] completed. Final position:[225225]
1666078 - DEBUG - [22] - VideoReaderFFMpeg - Seeking to [299520] completed. Final position:[300300]
1666078 - DEBUG - [22] - VideoReaderFFMpeg - Switching decoding mode. OnDemand -> NotInitialized
... snippage ...
1672953 - DEBUG - [Main] - PlayerScreen - Constructing a PlayerScreen.
1672953 - DEBUG - [Main] - PlayerScreenUserInterface - Constructing the PlayerScreen user interface.
1672953 - DEBUG - [Main] - AutoSaver - Autosave cleared. - 2061747180
1672953 - DEBUG - [Main] - Metadata - Metadata content hash reset:2061747180.
1672953 - DEBUG - [Main] - Metadata - Constructing new Metadata object.
1672984 - DEBUG - [Main] - Metadata - Dirty:False, reference hash:2061747180, current:2061747180.
1672984 - DEBUG - [Main] - LoaderVideo - Loading video C:\Documents and Settings\George\My Documents\AmenexReports\AA1408\VideoRetrial\DRTExperiment11\VideoPix02\Part11-030-Oil.MP4.
1673000 - DEBUG - [Main] - VideoReaderFFMpeg - Average Fps estimation method: libav.
1673000 - DEBUG - [Main] - VideoReaderFFMpeg - Ticks per frame: 1
1673000 - DEBUG - [Main] - VideoReaderFFMpeg - Display Aspect Ratio type: Square Pixels
1673000 - DEBUG - [Main] - VideoReaderFFMpeg - Image aspect ratio: Auto
1673000 - DEBUG - [Main] - VideoReaderFFMpeg - Switching decoding mode. NotInitialized -> OnDemand
1673000 - DEBUG - [Main] - VideoReaderFFMpeg - ---------------------------------------------------
1673000 - DEBUG - [Main] - VideoReaderFFMpeg - [File] - Filename : Part11-030-Oil.MP4
1673000 - DEBUG - [Main] - VideoReaderFFMpeg - [Container] - Name: mov,mp4,m4a,3gp,3g2,mj2 (QuickTime / MOV)
1673000 - DEBUG - [Main] - VideoReaderFFMpeg - [Container] - Number of streams: 1
1673000 - DEBUG - [Main] - VideoReaderFFMpeg - [Stream] #0, Type : AVMEDIA_TYPE_VIDEO, 990
1673000 - DEBUG - [Main] - VideoReaderFFMpeg - [Container] - Duration (s): 33.033
1673000 - DEBUG - [Main] - VideoReaderFFMpeg - [Container] - Bit rate: 55197806
1673000 - DEBUG - [Main] - VideoReaderFFMpeg - [Stream] - Duration (frames): 990
1673000 - DEBUG - [Main] - VideoReaderFFMpeg - [Stream] - PTS wrap bits: 64
1673000 - DEBUG - [Main] - VideoReaderFFMpeg - [Stream] - TimeBase: 30000:1
1673000 - DEBUG - [Main] - VideoReaderFFMpeg - [Stream] - Average timestamps per seconds: 30000
1673000 - DEBUG - [Main] - VideoReaderFFMpeg - [Container] - Start time (µs): 0
1673000 - DEBUG - [Main] - VideoReaderFFMpeg - [Container] - Start timestamp: 0
1673000 - DEBUG - [Main] - VideoReaderFFMpeg - [Codec] - Name: , id:13
1673000 - DEBUG - [Main] - VideoReaderFFMpeg - [Codec] - TimeBase: 30000:1
1673000 - DEBUG - [Main] - VideoReaderFFMpeg - [Codec] - Bit rate: 55196404
1673000 - DEBUG - [Main] - VideoReaderFFMpeg - Duration in timestamps: 990990
1673000 - DEBUG - [Main] - VideoReaderFFMpeg - Duration in seconds (computed): 33.033
1673000 - DEBUG - [Main] - VideoReaderFFMpeg - Average Fps: 29.97002997003
1673000 - DEBUG - [Main] - VideoReaderFFMpeg - Average Frame Interval (ms): 33.3666666666667
1673000 - DEBUG - [Main] - VideoReaderFFMpeg - Average Timestamps per frame: 1001
1673000 - DEBUG - [Main] - VideoReaderFFMpeg - [Codec] - Has B Frames: 0
1673000 - DEBUG - [Main] - VideoReaderFFMpeg - [Codec] - Width (pixels): 1280
1673000 - DEBUG - [Main] - VideoReaderFFMpeg - [Codec] - Height (pixels): 720
1673000 - DEBUG - [Main] - VideoReaderFFMpeg - [Codec] - Pixel Aspect Ratio: 1
1673000 - DEBUG - [Main] - VideoReaderFFMpeg - ---------------------------------------------------
1673015 - DEBUG - [Main] - AutoSaver - Autosave cleared. - -1718615561
1673015 - DEBUG - [Main] - Metadata - Metadata content hash reset:-1718615561.
1673015 - DEBUG - [Main] - FrameServerPlayer - Setup metadata.
1673015 - DEBUG - [Main] - AutoSaver - Autosave cleared. - -1718615561
1673015 - DEBUG - [Main] - Metadata - Metadata content hash reset:-1718615561.
1673015 - DEBUG - [Main] - AutoSaver - Autosave cleared. - -1718615561
1673015 - DEBUG - [Main] - AutoSaver - Autosaver started.
1673375 - DEBUG - [Main] - PreferencesManager - Exporting preferences.
1673390 - DEBUG - [6] - VideoReaderFFMpeg - Average Fps estimation method: libav.
1673390 - DEBUG - [6] - VideoReaderFFMpeg - Ticks per frame: 1
1673390 - DEBUG - [6] - VideoReaderFFMpeg - Display Aspect Ratio type: Square Pixels
1673390 - DEBUG - [6] - VideoReaderFFMpeg - Image aspect ratio: Auto
1673390 - DEBUG - [6] - VideoReaderFFMpeg - Switching decoding mode. NotInitialized -> OnDemand
1673437 - DEBUG - [6] - VideoReaderFFMpeg - Seeking to [2015013] completed. Final position:[2014012]
1673437 - DEBUG - [Main] - PlayerScreenUserInterface - Post load event.
1673437 - DEBUG - [Main] - VideoReaderFFMpeg - Switching decoding mode. OnDemand -> PreBuffering
1673437 - DEBUG - [Main] - VideoReaderFFMpeg - Starting prebuffering thread.
1673437 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - PreBuffering thread started.
1673453 - DEBUG - [6] - VideoReaderFFMpeg - Seeking to [4030026] completed. Final position:[4026022]
1673468 - DEBUG - [6] - VideoReaderFFMpeg - Seeking to [6045039] completed. Final position:[6038032]
1673500 - DEBUG - [6] - VideoReaderFFMpeg - Seeking to [8060052] completed. Final position:[8050042]
1673500 - DEBUG - [6] - VideoReaderFFMpeg - Switching decoding mode. OnDemand -> NotInitialized
1673546 - DEBUG - [Main] - VideoReaderFFMpeg - Update working zone request. [1001 --> 989989] to [1001 --> 989989]. Force reload:True
1673546 - DEBUG - [Main] - VideoReaderFFMpeg - Working zone update. Current:[1001 --> 989989], Asked:[1001 --> 989989]
1673546 - DEBUG - [Main] - VideoReaderFFMpeg - New working zone does not fit in memory.
1673546 - DEBUG - [Main] - VideoReaderFFMpeg - Changing decoding size from {Width=1280, Height=720} to {Width=824, Height=464}
1673546 - DEBUG - [Main] - VideoReaderFFMpeg - Stopping prebuffering thread.
1673546 - DEBUG - [Main] - PreBuffer - Unblocking prebuffering thread and making room for a non blocking addition.
1673546 - DEBUG - [6] - VideoReaderFFMpeg - Average Fps estimation method: libav.
1673546 - DEBUG - [6] - VideoReaderFFMpeg - Ticks per frame: 1
1673546 - DEBUG - [6] - VideoReaderFFMpeg - Display Aspect Ratio type: Square Pixels
1673546 - DEBUG - [6] - VideoReaderFFMpeg - Image aspect ratio: Auto
1673546 - DEBUG - [6] - VideoReaderFFMpeg - Switching decoding mode. NotInitialized -> OnDemand
1673546 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - PreBuffering thread, cancellation detected.
1673546 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - Exiting PreBuffering thread.
1673546 - DEBUG - [Main] - VideoReaderFFMpeg - Starting prebuffering thread.
1673546 - DEBUG - [Main] - VideoReaderFFMpeg - Stopping prebuffering thread.
1673546 - DEBUG - [Main] - PreBuffer - Unblocking prebuffering thread and making room for a non blocking addition.
1673546 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - PreBuffering thread started.
1673546 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - PreBuffering thread, cancellation detected.
1673546 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - Exiting PreBuffering thread.
1673546 - DEBUG - [Main] - VideoReaderFFMpeg - Out of segment jump, clearing cache. Asked 1001 in [-1 --> -1].
1673562 - DEBUG - [Main] - VideoReaderFFMpeg - [Seek] - First decoded frame [2002] already after target [1001]. Force seek 4 more seconds back to [-118999]
1673578 - DEBUG - [Main] - VideoReaderFFMpeg - Starting prebuffering thread.
1673593 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - PreBuffering thread started.
1673593 - DEBUG - [Main] - VideoReaderFFMpeg - Already decoding at the right size.
1673609 - DEBUG - [6] - VideoReaderFFMpeg - Seeking to [1972971] completed. Final position:[1968967]
... more snippage ...
1676937 - DEBUG - [Main] - PlayerScreen - Constructing a PlayerScreen.
1676937 - DEBUG - [Main] - PlayerScreenUserInterface - Constructing the PlayerScreen user interface.
1676937 - DEBUG - [Main] - AutoSaver - Autosave cleared. - 2061747180
1676937 - DEBUG - [Main] - Metadata - Metadata content hash reset:2061747180.
1676937 - DEBUG - [Main] - Metadata - Constructing new Metadata object.
1677062 - DEBUG - [Main] - VideoReaderFFMpeg - Changing decoding size from {Width=824, Height=464} to {Width=680, Height=381}
1677062 - DEBUG - [Main] - VideoReaderFFMpeg - Stopping prebuffering thread.
1677062 - DEBUG - [Main] - PreBuffer - Unblocking prebuffering thread and making room for a non blocking addition.
1677062 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - PreBuffering thread, cancellation detected.
1677062 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - Exiting PreBuffering thread.
1677078 - DEBUG - [Main] - VideoReaderFFMpeg - [Seek] - First decoded frame [2002] already after target [1001]. Force seek 4 more seconds back to [-118999]
1677093 - DEBUG - [Main] - VideoReaderFFMpeg - Starting prebuffering thread.
1677109 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - PreBuffering thread started.
1677203 - DEBUG - [Main] - VideoReaderFFMpeg - Already decoding at the right size.
1683468 - DEBUG - [Main] - Metadata - Dirty:False, reference hash:2061747180, current:2061747180.
1683468 - DEBUG - [Main] - LoaderVideo - Loading video C:\Documents and Settings\George\My Documents\AmenexReports\AA1408\VideoRetrial\DRTExperiment11\VideoPix02\Part11-462-H2O.MP4.
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - Average Fps estimation method: libav.
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - Ticks per frame: 1
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - Display Aspect Ratio type: Square Pixels
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - Image aspect ratio: Auto
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - Switching decoding mode. NotInitialized -> OnDemand
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - ---------------------------------------------------
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - [File] - Filename : Part11-462-H2O.MP4
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - [Container] - Name: mov,mp4,m4a,3gp,3g2,mj2 (QuickTime / MOV)
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - [Container] - Number of streams: 1
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - [Stream] #0, Type : AVMEDIA_TYPE_VIDEO, 240
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - [Container] - Duration (s): 8.008
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - [Container] - Bit rate: 22763894
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - [Stream] - Duration (frames): 240
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - [Stream] - PTS wrap bits: 64
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - [Stream] - TimeBase: 30000:1
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - [Stream] - Average timestamps per seconds: 30000
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - [Container] - Start time (µs): 0
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - [Container] - Start timestamp: 0
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - [Codec] - Name: , id:13
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - [Codec] - TimeBase: 30000:1
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - [Codec] - Bit rate: 22761999
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - Duration in timestamps: 240239
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - Duration in seconds (computed): 8.00796666666667
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - Average Fps: 29.97002997003
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - Average Frame Interval (ms): 33.3666666666667
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - Average Timestamps per frame: 1001
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - [Codec] - Has B Frames: 0
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - [Codec] - Width (pixels): 1280
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - [Codec] - Height (pixels): 720
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - [Codec] - Pixel Aspect Ratio: 1
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - ---------------------------------------------------
1683500 - DEBUG - [Main] - AutoSaver - Autosave cleared. - -1718615561
1683500 - DEBUG - [Main] - Metadata - Metadata content hash reset:-1718615561.
1683500 - DEBUG - [Main] - FrameServerPlayer - Setup metadata.
1683500 - DEBUG - [Main] - AutoSaver - Autosave cleared. - -1718615561
1683500 - DEBUG - [Main] - Metadata - Metadata content hash reset:-1718615561.
1683500 - DEBUG - [Main] - AutoSaver - Autosave cleared. - -1718615561
1683500 - DEBUG - [Main] - AutoSaver - Autosaver started.
1683812 - DEBUG - [Main] - PreferencesManager - Exporting preferences.
1683875 - DEBUG - [Main] - PlayerScreenUserInterface - Post load event.
1683875 - DEBUG - [Main] - VideoReaderFFMpeg - Switching decoding mode. OnDemand -> PreBuffering
1683875 - DEBUG - [Main] - VideoReaderFFMpeg - Starting prebuffering thread.
1683875 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - PreBuffering thread started.
1683984 - DEBUG - [Main] - VideoReaderFFMpeg - Update working zone request. [1001 --> 239238] to [1001 --> 239238]. Force reload:True
1683984 - DEBUG - [Main] - VideoReaderFFMpeg - Working zone update. Current:[1001 --> 239238], Asked:[1001 --> 239238]
1683984 - DEBUG - [Main] - VideoReaderFFMpeg - Just entering the cached mode, import everything.
1683984 - DEBUG - [Main] - VideoReaderFFMpeg - Switching decoding mode. PreBuffering -> Caching
1683984 - DEBUG - [Main] - VideoReaderFFMpeg - Stopping prebuffering thread.
1683984 - DEBUG - [Main] - PreBuffer - Unblocking prebuffering thread and making room for a non blocking addition.
1683984 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - PreBuffering thread, cancellation detected.
1683984 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - Exiting PreBuffering thread.
1683984 - DEBUG - [Main] - VideoReaderFFMpeg - New frames to cache needed:[1001 --> 239238]
1683984 - DEBUG - [CacheFilling] - VideoReaderFFMpeg - Caching section [1001 --> 239238], prepend:False
1684000 - DEBUG - [CacheFilling] - VideoReaderFFMpeg - [Seek] - First decoded frame [2002] already after target [1001]. Force seek 4 more seconds back to [-118999]
1686218 - DEBUG - [CacheFilling] - VideoReaderFFMpeg - Switching decoding mode. Caching -> PreBuffering
1686265 - DEBUG - [CacheFilling] - VideoReaderFFMpeg - Starting prebuffering thread.
1686281 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - PreBuffering thread started.
1686281 - DEBUG - [Main] - VideoReaderFFMpeg - Changing decoding size from {Width=1280, Height=720} to {Width=678, Height=379}
1686281 - DEBUG - [Main] - VideoReaderFFMpeg - Stopping prebuffering thread.
1686281 - DEBUG - [Main] - PreBuffer - Unblocking prebuffering thread and making room for a non blocking addition.
1686296 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - PreBuffering thread, cancellation detected.
1686296 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - Exiting PreBuffering thread.
1686296 - DEBUG - [Main] - VideoReaderFFMpeg - Starting prebuffering thread.
1686296 - DEBUG - [Main] - VideoReaderFFMpeg - Stopping prebuffering thread.
1686296 - DEBUG - [Main] - PreBuffer - Unblocking prebuffering thread and making room for a non blocking addition.
1686296 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - PreBuffering thread started.
1686296 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - PreBuffering thread, cancellation detected.
1686296 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - Exiting PreBuffering thread.
1686296 - DEBUG - [Main] - VideoReaderFFMpeg - Out of segment jump, clearing cache. Asked 1001 in [-1 --> -1].
1686296 - DEBUG - [Main] - VideoReaderFFMpeg - [Seek] - First decoded frame [2002] already after target [1001]. Force seek 4 more seconds back to [-118999]
1686312 - DEBUG - [Main] - VideoReaderFFMpeg - Starting prebuffering thread.
1686328 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - PreBuffering thread started.
1686328 - DEBUG - [Main] - VideoReaderFFMpeg - Already decoding at the right size.
1692296 - DEBUG - [Main] - AutoSaver - Autosaver stopped
1692296 - DEBUG - [Main] - AutoSaver - Autosaver stopped
1699593 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - Average prebuffering loop time: 8.504ms. (interval: 33.367ms).
1699609 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - [Seek] - First decoded frame [2002] already after target [1001]. Force seek 4 more seconds back to [-118999]
1700156 - DEBUG - [Main] - AutoSaver - Autosaver started.
1700156 - DEBUG - [Main] - PlayerScreenUserInterface - Rendering drops ratio: 0.03
1700156 - DEBUG - [Main] - PlayerScreenUserInterface - Average rendering loop time: 14.614ms
1711859 - DEBUG - [Main] - AutoSaver - Autosaver started.
1711859 - DEBUG - [Main] - PlayerScreenUserInterface - Rendering drops ratio: 0.02
1711859 - DEBUG - [Main] - PlayerScreenUserInterface - Average rendering loop time: 11.383ms
1711859 - DEBUG - [Main] - MessageToaster - Toasting message: Pause
1713250 - DEBUG - [Main] - VideoReaderFFMpeg - Stopping prebuffering thread.
1713250 - DEBUG - [Main] - PreBuffer - Unblocking prebuffering thread and making room for a non blocking addition.
1713250 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - PreBuffering thread, cancellation detected.
1713250 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - Exiting PreBuffering thread.
1713250 - DEBUG - [Main] - VideoReaderFFMpeg - Out of segment jump, clearing cache. Asked 1001 in [588588 --> 610610].
1713281 - DEBUG - [Main] - VideoReaderFFMpeg - [Seek] - First decoded frame [2002] already after target [1001]. Force seek 4 more seconds back to [-118999]
1713359 - DEBUG - [Main] - VideoReaderFFMpeg - Starting prebuffering thread.
1713359 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - PreBuffering thread started.
1716890 - DEBUG - [Main] - AutoSaver - Autosaver stopped
1716890 - DEBUG - [Main] - AutoSaver - Autosaver stopped
1724187 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - Average prebuffering loop time: 9.395ms. (interval: 33.367ms).
1724203 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - [Seek] - First decoded frame [2002] already after target [1001]. Force seek 4 more seconds back to [-118999]
1724250 - DEBUG - [Main] - AutoSaver - Autosaver started.
1724250 - DEBUG - [Main] - PlayerScreenUserInterface - Rendering drops ratio: 0.02
1724250 - DEBUG - [Main] - PlayerScreenUserInterface - Average rendering loop time: 14.691ms
1724250 - DEBUG - [Main] - MessageToaster - Toasting message: Pause
1724250 - DEBUG - [Main] - AutoSaver - Autosaver started.
1724250 - DEBUG - [Main] - PlayerScreenUserInterface - Rendering drops ratio: 0.02
1724250 - DEBUG - [Main] - PlayerScreenUserInterface - Average rendering loop time: 84.046ms
1724250 - DEBUG - [Main] - MessageToaster - Toasting message: Pause
1734859 - DEBUG - [Main] - VideoReaderFFMpeg - Update working zone request. [1001 --> 989989] to [1001 --> 224854]. Force reload:False
1734859 - DEBUG - [Main] - VideoReaderFFMpeg - Working zone update. Current:[1001 --> 989989], Asked:[1001 --> 224854]
1734859 - DEBUG - [Main] - VideoReaderFFMpeg - Just entering the cached mode, import everything.
1734859 - DEBUG - [Main] - VideoReaderFFMpeg - Switching decoding mode. PreBuffering -> Caching
1734875 - DEBUG - [Main] - VideoReaderFFMpeg - Stopping prebuffering thread.
1734875 - DEBUG - [Main] - PreBuffer - Unblocking prebuffering thread and making room for a non blocking addition.
1734875 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - PreBuffering thread, cancellation detected.
1734875 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - Exiting PreBuffering thread.
1734875 - DEBUG - [Main] - VideoReaderFFMpeg - New frames to cache needed:[1001 --> 224854]
1734875 - DEBUG - [CacheFilling] - VideoReaderFFMpeg - Caching section [1001 --> 224854], prepend:False
1734937 - DEBUG - [CacheFilling] - VideoReaderFFMpeg - [Seek] - First decoded frame [2002] already after target [1001]. Force seek 4 more seconds back to [-118999]
1736750 - DEBUG - [Main] - VideoReaderFFMpeg - Will not change decoding size because we are not prebuffering.
1743937 - DEBUG - [Main] - AutoSaver - Autosaver stopped
1743937 - DEBUG - [Main] - AutoSaver - Autosaver stopped
1751234 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - Average prebuffering loop time: 9.508ms. (interval: 33.367ms).
1751250 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - [Seek] - First decoded frame [2002] already after target [1001]. Force seek 4 more seconds back to [-118999]
1751312 - DEBUG - [Main] - AutoSaver - Autosaver started.
1751312 - DEBUG - [Main] - PlayerScreenUserInterface - Rendering drops ratio: 0.07
1751312 - DEBUG - [Main] - PlayerScreenUserInterface - Average rendering loop time: 110.486ms
1751312 - DEBUG - [Main] - MessageToaster - Toasting message: Pause
1751312 - DEBUG - [Main] - AutoSaver - Autosaver started.
1751312 - DEBUG - [Main] - PlayerScreenUserInterface - Rendering drops ratio: 0.07
1751312 - DEBUG - [Main] - PlayerScreenUserInterface - Average rendering loop time: 110.102ms
1751312 - DEBUG - [Main] - MessageToaster - Toasting message: Pause
1777062 - DEBUG - [Main] - AutoSaver - Autosaver stopped
1777062 - DEBUG - [Main] - AutoSaver - Autosaver stopped
1784359 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - Average prebuffering loop time: 11.529ms. (interval: 33.367ms).
1784359 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - [Seek] - First decoded frame [2002] already after target [1001]. Force seek 4 more seconds back to [-118999]
1784468 - DEBUG - [Main] - AutoSaver - Autosaver started.
1784468 - DEBUG - [Main] - PlayerScreenUserInterface - Rendering drops ratio: 0.10
1784468 - DEBUG - [Main] - PlayerScreenUserInterface - Average rendering loop time: 263.759ms
1784500 - DEBUG - [Main] - AutoSaver - Autosaver started.
1784500 - DEBUG - [Main] - PlayerScreenUserInterface - Rendering drops ratio: 0.10
1784500 - DEBUG - [Main] - PlayerScreenUserInterface - Average rendering loop time: 263.013ms
1784500 - DEBUG - [Main] - AutoSaver - Autosaver stopped
1784500 - DEBUG - [Main] - AutoSaver - Autosaver stopped
1786406 - DEBUG - [Main] - AutoSaver - Autosaver started.
1786406 - DEBUG - [Main] - PlayerScreenUserInterface - Rendering drops ratio: 0.05
1786406 - DEBUG - [Main] - PlayerScreenUserInterface - Average rendering loop time: 18.705ms
1786406 - DEBUG - [Main] - MessageToaster - Toasting message: Pause
1786406 - DEBUG - [Main] - AutoSaver - Autosaver started.
1786406 - DEBUG - [Main] - PlayerScreenUserInterface - Rendering drops ratio: 0.05
1786406 - DEBUG - [Main] - PlayerScreenUserInterface - Average rendering loop time: 18.933ms
1786406 - DEBUG - [Main] - MessageToaster - Toasting message: Pause
1788765 - DEBUG - [Main] - VideoReaderFFMpeg - Stopping prebuffering thread.
1788765 - DEBUG - [Main] - PreBuffer - Unblocking prebuffering thread and making room for a non blocking addition.
1788765 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - PreBuffering thread, cancellation detected.
1788765 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - Exiting PreBuffering thread.
1788765 - DEBUG - [Main] - VideoReaderFFMpeg - Out of segment jump, clearing cache. Asked 1001 in [53053 --> 75075].
1788781 - DEBUG - [Main] - VideoReaderFFMpeg - [Seek] - First decoded frame [2002] already after target [1001]. Force seek 4 more seconds back to [-118999]
1788796 - DEBUG - [Main] - VideoReaderFFMpeg - Starting prebuffering thread.
1788796 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - PreBuffering thread started.
1802000 - DEBUG - [Saving] - FrameServerPlayer - Saving selection [1001]->[225225] to: Part11-030-Oil.MP4
1802000 - DEBUG - [Saving] - FrameServerPlayer - interval:33.3666666666667, duplication:1, kf duplication:1
1802000 - DEBUG - [Saving] - VideoFileWriter - Opening the saving context.
1802000 - DEBUG - [Saving] - VideoFileWriter - Setting up the encoder.
1802000 - DEBUG - [Saving] - VideoFileWriter - Pushing special timebase: 30000:1001
1802031 - DEBUG - [Saving] - VideoFileWriter - VideoFileWriter sanity check warning: Codec does not use global headers but container format requires global headers
1811421 - DEBUG - [Saving] - VideoFileWriter - Closing the saving context.
1811421 - DEBUG - [Saving] - VideoFileWriter - Saving video completed.
1811437 - DEBUG - [Main] - PreferencesManager - Exporting preferences.
1823468 - DEBUG - [Saving] - FrameServerPlayer - Saving selection [1001]->[238238] to: Part11-462-H2O.MP4
1823468 - DEBUG - [Saving] - FrameServerPlayer - interval:33.3666666666667, duplication:1, kf duplication:1
1823468 - DEBUG - [Saving] - VideoReaderFFMpeg - Switching decoding mode. PreBuffering -> OnDemand
1823468 - DEBUG - [Saving] - VideoReaderFFMpeg - Stopping prebuffering thread.
1823468 - DEBUG - [Saving] - PreBuffer - Unblocking prebuffering thread and making room for a non blocking addition.
1823468 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - PreBuffering thread, cancellation detected.
1823468 - DEBUG - [PreBuffering] - VideoReaderFFMpeg - Exiting PreBuffering thread.
1823468 - DEBUG - [Saving] - VideoFileWriter - Opening the saving context.
1823468 - DEBUG - [Saving] - VideoFileWriter - Setting up the encoder.
1823468 - DEBUG - [Saving] - VideoFileWriter - Pushing special timebase: 30000:1001
1823656 - DEBUG - [Saving] - VideoFileWriter - VideoFileWriter sanity check warning: Codec does not use global headers but container format requires global headers
1823703 - ERROR - [Saving] - FrameServerPlayer - Unknown error while saving video.
1823703 - ERROR - [Saving] - FrameServerPlayer -    at System.Drawing.Graphics.FromImage(Image image)
   at Kinovea.ScreenManager.FrameServerPlayer.<FrameEnumerator>d__1.MoveNext()
   at Kinovea.Video.FFMpeg.VideoFileWriter.Save(SavingSettings _settings, VideoInfo _info, IEnumerable`1 _frames, BackgroundWorker _worker)
   at Kinovea.ScreenManager.FrameServerPlayer.bgWorkerSave_DoWork(Object sender, DoWorkEventArgs e)
1828578 - DEBUG - [Main] - PreferencesManager - Exporting preferences.
1828593 - ERROR - [Main] - PlayerScreenUserInterface - Painting screen - no image to display.
1833625 - DEBUG - [Main] - Metadata - Dirty:False, reference hash:-1718615561, current:-1718615561.
1833625 - DEBUG - [Main] - VideoReaderFFMpeg - Switching decoding mode. OnDemand -> NotInitialized
1833625 - DEBUG - [Main] - PlayerScreenUserInterface - Reset screen to empty state.
1833625 - DEBUG - [Main] - Metadata - Metadata Reset.
1833625 - DEBUG - [Main] - AutoSaver - Autosaver stopped
1833625 - DEBUG - [Main] - AutoSaver - Autosave cleared. - 2061747180
1833625 - DEBUG - [Main] - Metadata - Metadata content hash reset:2061747180.
1833687 - DEBUG - [Main] - VideoReaderFFMpeg - Will not change decoding size because we are not prebuffering.
1833718 - DEBUG - [Main] - VideoReaderFFMpeg - Will not change decoding size because we are not prebuffering.
1833734 - DEBUG - [Main] - VideoReaderFFMpeg - Will not change decoding size because we are not prebuffering.
1836609 - DEBUG - [Main] - Metadata - Dirty:False, reference hash:-1718615561, current:-1718615561.
1836609 - DEBUG - [Main] - VideoReaderFFMpeg - Switching decoding mode. Caching -> NotInitialized
1836734 - DEBUG - [Main] - PlayerScreenUserInterface - Reset screen to empty state.
1836734 - DEBUG - [Main] - Metadata - Metadata Reset.
1836734 - DEBUG - [Main] - AutoSaver - Autosaver stopped
1836734 - DEBUG - [Main] - AutoSaver - Autosave cleared. - 2061747180
1836734 - DEBUG - [Main] - Metadata - Metadata content hash reset:2061747180.
1836984 - DEBUG - [6] - VideoReaderFFMpeg - Average Fps estimation method: libav.
1836984 - DEBUG - [6] - VideoReaderFFMpeg - Ticks per frame: 1
1836984 - DEBUG - [6] - VideoReaderFFMpeg - Display Aspect Ratio type: Square Pixels
1836984 - DEBUG - [6] - VideoReaderFFMpeg - Image aspect ratio: Auto
1836984 - DEBUG - [6] - VideoReaderFFMpeg - Switching decoding mode. NotInitialized -> OnDemand
1837015 - DEBUG - [6] - VideoReaderFFMpeg - Seeking to [2015013] completed. Final position:[2014012]
... even more snippage ...
1839437 - DEBUG - [6] - VideoReaderFFMpeg - Seeking to [162162] completed. Final position:[163163]
1839453 - DEBUG - [6] - VideoReaderFFMpeg - Seeking to [216216] completed. Final position:[217217]
1839453 - DEBUG - [6] - VideoReaderFFMpeg - Switching decoding mode. OnDemand -> NotInitialized
1839468 - DEBUG - [6] - VideoReaderFFMpeg - Average Fps estimation method: libav.
1839468 - DEBUG - [6] - VideoReaderFFMpeg - Ticks per frame: 1
1839468 - DEBUG - [6] - VideoReaderFFMpeg - Display Aspect Ratio type: Square Pixels
1839468 - DEBUG - [6] - VideoReaderFFMpeg - Image aspect ratio: Auto
1839468 - DEBUG - [6] - VideoReaderFFMpeg - Switching decoding mode. NotInitialized -> OnDemand
1839500 - DEBUG - [6] - VideoReaderFFMpeg - Seeking to [59064] completed. Final position:[60060]
1839515 - DEBUG - [6] - VideoReaderFFMpeg - Seeking to [118128] completed. Final position:[119119]
1839531 - DEBUG - [6] - VideoReaderFFMpeg - Seeking to [177192] completed. Final position:[178178]
1839546 - DEBUG - [6] - VideoReaderFFMpeg - Seeking to [236256] completed. Final position:[237237]
1839546 - DEBUG - [6] - VideoReaderFFMpeg - Switching decoding mode. OnDemand -> NotInitialized
1868796 - DEBUG - [Main] - RootKernel - Root is closing. Call close on all sub modules.
1868812 - DEBUG - [Main] - PreferencesManager - Exporting preferences.
93 - INFO  - [1] - Software -
93 - INFO  - [1] - Software - --------------------------------------------------
93 - INFO  - [1] - Software - Kinovea version 0.8.23.
93 - INFO  - [1] - Software - .NET Framework Version : 2.0.50727.3655
93 - INFO  - [1] - Software - OS Version : Microsoft Windows NT 5.1.2600 Service Pack 3
93 - INFO  - [1] - Software - CLR bitness : x86
93 - INFO  - [1] - Software - Primary Screen : {Width=1366, Height=768}
93 - INFO  - [1] - Software - Virtual Screen : {X=0,Y=0,Width=1366,Height=768}
93 - DEBUG - [Main] - Program - Application level initialisations.
109 - DEBUG - [Main] - Program - Showing SplashScreen.
437 - DEBUG - [Main] - PreferencesManager - Importing preferences.
546 - INFO  - [Main] - VideoTypeManager - Registering extensions for VideoReaderBitmap : .jpg; .jpeg; .png; .bmp
546 - INFO  - [Main] - VideoTypeManager - Registering extensions for VideoReaderFFMpeg : .3gp; .asf; .avi; .dv; .flv; .f4v; .m1v; .m2p; .m2t; .m2ts; .mts; .m2v; .m4v; .ts; .ts1; .ts2; .avr; .mkv; .mod; .mov; .moov; .mpg; .mpeg; .tod; .mxf; .mp4; .mpv; .ogg; .ogm; .ogv; .qt; .rm; .swf; .vob; .webm; .wmv; *
546 - INFO  - [Main] - VideoTypeManager - Registering extensions for VideoReaderGIF : .gif
546 - INFO  - [Main] - VideoTypeManager - Registering extensions for VideoReaderSVG : .svg
546 - INFO  - [Main] - VideoTypeManager - Registering extensions for VideoReaderSynthetic : .ksv
671 - DEBUG - [Main] - RootKernel - Building the modules tree.
937 - DEBUG - [Main] - ScreenManagerKernel - Module Construction : ScreenManager.
953 - DEBUG - [Main] - ThumbnailViewerFiles - Constructing ThumbListView
953 - DEBUG - [Main] - ThumbnailViewerFiles - Constructing ThumbListView
953 - DEBUG - [Main] - ScreenManagerUserInterface - Constructing ScreenManagerUserInterface.
984 - DEBUG - [Main] - RootKernel - Modules tree built.
984 - DEBUG - [Main] - KinoveaMainWindow - Create main UI window.
1015 - DEBUG - [Main] - RootKernel - Plug sub modules at UI extension points (Menus, ToolBars, StatusBAr, Windows).
1093 - DEBUG - [Main] - RootKernel - Register global services offered at Root level.
1093 - DEBUG - [Main] - RootKernel - Setting current ui culture.
1093 - DEBUG - [Main] - RootKernel - RefreshUICulture - Reload localized strings for the whole tree.
1109 - DEBUG - [Main] - RootKernel - RefreshUICulture - Whole tree culture reloaded.
1109 - DEBUG - [Main] - Program - Closing splash screen.
1109 - DEBUG - [Main] - Program - Launching.
1109 - DEBUG - [Main] - RootKernel - Calling Application.Run() to boot up the UI.
1140 - DEBUG - [Main] - ScreenManagerUserInterface - In ScreenManager OnLoad
1156 - DEBUG - [Main] - PreferencesManager - Exporting preferences.
1187 - DEBUG - [Main] - FileBrowserUserInterface - Application is idle in FileBrowserUserInterface.

2 Reply by joan

  • joan
  • joan
  • Admin
  • Offline

First of all I'm very sorry for the lost file. Let's get to the bottom of this so that doesn't happen again.

I'll try to summarize my understanding of the issues, please correct me if I'm wrong.

1. Your workflow is to record video pairs with two Sony DSC-H20 using the internal memory cards. Then you transfer the files manually to the computer. (No live capture).
2. You record a single master video for each camera.
3. For each camera master video, you then create several sub sequences. You do this using Kinovea, setting a working zone and saving it.

Issue 1: When reopening a pair of sub-sequences, the endpoint and duration do not match, although the original working zones matched.

4. For each pair of sub-sequence, you open the files in Kinovea, create a new working zone to fix the endpoint from issue 1.
5. You save the fixed-up sub-sequences again.

Issue 2: When saving one of the video, the other video file becomes corrupted.
Issue 3: QuickTime cannot open any video after it has passed through Kinovea saving.

Please correct any misunderstanding.

Let's also name things:
1. Creation of master files A and B in the cameras.
2. Creation of files A1, A2, …, A12, and B1, B2, …, B12 in Kinovea.
3. Creation of files A1fix, A2fix, etc. and B1fix, B2fix, etc. in Kinovea.

The major issue is #2, file corruption.
There is one critical bug that can cause this, it happens when you overwrite an open file. For example, if you open A12 and B12, fix A12 endpoint, then in the Save File dialog you either save it back to A12 or B12. Please create a backup of your files before attempting a reproduction of the issue.

I'll add the necessary check to prevent this failure.

edit: analysing the log, I think it is indeed what happened:

1673000 - DEBUG - [Main] - VideoReaderFFMpeg - [File] - Filename : Part11-030-Oil.MP4
...
1683468 - DEBUG - [Main] - VideoReaderFFMpeg - [File] - Filename : Part11-462-H2O.MP4
...
1802000 - DEBUG - [Saving] - FrameServerPlayer - Saving selection [1001]->[225225] to: Part11-030-Oil.MP4
...
1823468 - DEBUG - [Saving] - FrameServerPlayer - Saving selection [1001]->[238238] to: Part11-462-H2O.MP4

3 Reply by amenex (edited by amenex 2015-02-01 14:07:47)

  • amenex
  • Member
  • Offline

Whoopeee ... I copied the subdivided videos to a new directory called Backups, opened each pair in turn, and saved them in another directory called completed. 

First thing: None of that fussiness about not knowing when to stop occurred this time.

Second thing: No corruption; I could play them back in pairs, do a screen capture with Movavi, and save them in a third directory called ScreenCaptures, from which QuickTime could view them without any error messages.

Your analysis was right on the money; thank you.  The whole process for a dozen pairs took less than an hour.

Incidentally, I discovered another feature while truncating the individual videos: At first, when I set the starting times for both videos to be equal by moving the sliders from left to right, my selected times would "stick" OK. But when I tried to set the durations by moving the sliders from right to left, the first (left half screen) would stay put OK, but the second (right half screen) would not stay put until I learned to hold the left mouse button down while simultaneously pressing the right mouse button. That did the trick; the end point would retain the intended setting.