GNOME Bugzilla – Bug 786782
Using to edit ogg vorbis file corrupts file, now won't play in rhythmbox and totem (but will play in vlc)
Last modified: 2017-09-21 14:55:26 UTC
easytag 2.4.3 on Ubuntu 17.04 Made an Ogg Vorbis file. Plays correctly in rhythmbox, vlc and totem. Used easytag to change artist tag. All seems to execute properly. Now file won't play using rhythmbox or totem but will play using vlc. Using rhythmbox with debug mode, at the point of trying to play the file the terminal returns: (11:51:08) [0x7f82d8005210] [bus_cb] rb-player-gst.c:524: got error from stream: Internal data stream error. (gstoggdemux.c(4851): gst_ogg_demux_loop (): /GstPlayBin:playbin0/GstURIDecodeBin:uridecodebin0/GstDecodeBin:decodebin0/GstOggDemux:oggdemux0: streaming stopped, reason error (-5)) Using totem, at the point of trying to play the file a dialogue box pops up that says: An error occurred. Internal data stream error. Using vlc, the debugging output when playing the file for a few seconds is (with file name changed to [file]): core debug: processing request item: [file], node: My Music, skip: 0 core debug: resyncing on [file] core debug: [file] is at 10 core debug: starting playback of the new playlist item core debug: resyncing on [file] core debug: [file] is at 10 core debug: creating new input thread core debug: Creating an input for '[file]' core debug: requesting art for [file] core debug: using timeshift granularity of 50 MiB, in path '/tmp' core debug: `[file]' gives access `file' demux `' path `[file]' core debug: specified demux `any' core debug: creating demux: access='file' demux='any' location='[file]' file='[file]' core debug: looking for meta fetcher module matching "any": 1 candidates core debug: looking for access_demux module matching "file": 16 candidates core debug: no access_demux modules matched core debug: creating access 'file' location='[file]', path='[file]' core debug: looking for access module matching "file": 25 candidates filesystem debug: opening file `[file]' core debug: using access module "filesystem" core debug: Using stream method for AStream* core debug: starting pre-buffering core debug: received first data after 0 ms core debug: pre-buffering done 1024 bytes in 0s - 25000 KiB/s core debug: looking for stream_filter module matching "any": 9 candidates core debug: no stream_filter modules matched core debug: looking for stream_filter module matching "record": 9 candidates core debug: using stream_filter module "record" core debug: creating demux: access='file' demux='any' location='[file]' file='[file]' core debug: looking for demux module matching "ogg": 67 candidates ogg debug: File length is 3634149 bytes ogg debug: found vorbis header ogg debug: beginning of a group of logical streams core debug: using demux module "ogg" core debug: looking for a subtitle file in [file] core debug: looking for meta reader module matching "any": 2 candidates core debug: using meta reader module "taglib" core debug: removing module "taglib" core debug: `[file]' successfully opened core debug: selecting program id=0 core debug: looking for decoder module matching "any": 41 candidates core debug: using decoder module "vorbis" vorbis debug: channels:2 samplerate:44100 bitrate:160000d qt4 debug: IM: Setting an input lua debug: Trying Lua scripts in /home/x/.local/share/vlc/lua/meta/fetcher lua debug: Trying Lua scripts in /usr/lib/x86_64-linux-gnu/vlc/lua/meta/fetcher lua debug: Trying Lua playlist script /usr/lib/x86_64-linux-gnu/vlc/lua/meta/fetcher/tvrage.luac core debug: Buffering 0% ogg warning: Consider increasing access caching variable from 300 to >438 core debug: Stream buffering done (438 ms in 0 ms) core debug: reusing audio output pulse debug: using stereo channel map lua debug: skipping script (unmatched scope) /usr/lib/x86_64-linux-gnu/vlc/lua/meta/fetcher/tvrage.luac lua debug: Trying Lua scripts in /usr/share/vlc/lua/meta/fetcher core debug: no meta fetcher modules matched core debug: found art for [file] in cache pulse debug: changed buffer metrics: maxlength=4194304, tlength=42336, prebuf=0, minreq=14112 pulse debug: connected to sink bluez_sink.FC_A8_9A_E1_9A_1D.a2dp_sink core debug: output 'f32l' 44100 Hz Stereo frame=1 samples/8 bytes pulse debug: changing sink 5: bluez_sink.FC_A8_9A_E1_9A_1D.a2dp_sink (JBL Charge 3) core debug: looking for audio volume module matching "any": 2 candidates core debug: using audio volume module "float_mixer" core debug: input 'f32l' 44100 Hz Stereo frame=1 samples/8 bytes core debug: looking for audio filter module matching "scaletempo": 14 candidates scaletempo debug: format: 44100 rate, 2 nch, 4 bps, fl32 scaletempo debug: params: 30 stride, 0.200 overlap, 14 search scaletempo debug: 1.000 scale, 1323.000 stride_in, 1323 stride_out, 1059 standing, 264 overlap, 617 search, 2204 queue, fl32 mode core debug: using audio filter module "scaletempo" core debug: conversion: 'f32l'->'f32l' 44100 Hz->44100 Hz Stereo->Stereo core debug: conversion pipeline complete core debug: conversion: 'f32l'->'f32l' 44100 Hz->44100 Hz Stereo->Stereo core debug: conversion pipeline complete core debug: looking for audio resampler module matching "any": 3 candidates core debug: using audio resampler module "samplerate" core debug: End of audio preroll core debug: Decoder wait done in 623 ms pulse debug: cannot synchronize start pulse debug: deferring start (30353 us) pulse debug: deferring start (3223 us) pulse warning: starting late (-21753 us) pulse debug: changing sink 5: bluez_sink.FC_A8_9A_E1_9A_1D.a2dp_sink (JBL Charge 3) pulse debug: started core warning: playback too late (76462): up-sampling core warning: timing screwed (drift: 169391 us): stopping resampling core warning: playback way too late (192312): flushing buffers pulse debug: deferring start (346304 us) pulse debug: changing sink 5: bluez_sink.FC_A8_9A_E1_9A_1D.a2dp_sink (JBL Charge 3) pulse debug: deferring start (321840 us) pulse debug: deferring start (297911 us) pulse debug: deferring start (284612 us) pulse debug: deferring start (281518 us) pulse debug: deferring start (278046 us) pulse debug: deferring start (274901 us) pulse debug: deferring start (271832 us) pulse debug: deferring start (268763 us) pulse debug: deferring start (264686 us) pulse debug: deferring start (250360 us) pulse debug: deferring start (225999 us) pulse debug: deferring start (201667 us) pulse debug: deferring start (177254 us) pulse debug: deferring start (153387 us) pulse debug: deferring start (152592 us) pulse debug: deferring start (127640 us) pulse debug: deferring start (103260 us) pulse debug: deferring start (79490 us) pulse debug: deferring start (66235 us) pulse debug: deferring start (63173 us) pulse debug: deferring start (59672 us) pulse debug: deferring start (45690 us) pulse debug: deferring start (21448 us) pulse warning: starting late (-3120 us) pulse debug: changing sink 5: bluez_sink.FC_A8_9A_E1_9A_1D.a2dp_sink (JBL Charge 3) core warning: playback too early (-48090): down-sampling pulse debug: started core debug: resampling stopped (drift: 1454 us) core warning: playback too early (-40069): down-sampling core debug: incoming request - stopping current input core debug: control: stopping input core debug: removing module "vorbis" core debug: killing decoder fourcc `vorb', 0 PES in FIFO core debug: removing module "samplerate" core debug: removing module "scaletempo" core debug: removing module "float_mixer" core debug: keeping audio output core debug: removing module "ogg" core debug: Program doesn't contain anymore ES core debug: removing module "record" core debug: removing module "filesystem" core debug: incoming request - stopping current input core debug: dead input pulse debug: changing sink 5: bluez_sink.FC_A8_9A_E1_9A_1D.a2dp_sink (JBL Charge 3) qt4 debug: IM: Deleting the input pulse debug: changing sink 5: bluez_sink.FC_A8_9A_E1_9A_1D.a2dp_sink (JBL Charge 3)
What is the output of?: /usr/bin/gst-launch-1.0 playbin uri=file:///home/username/filename.ogg
[username]@[computer name]:~$ /usr/bin/gst-launch-1.0 playbin uri=file:///home/[username]/[filename].ogg Setting pipeline to PAUSED ... Pipeline is PREROLLING ... ERROR: from element /GstPlayBin:playbin0/GstURIDecodeBin:uridecodebin0/GstDecodeBin:decodebin0/GstOggDemux:oggdemux0: Internal data stream error. Additional debug info: gstoggdemux.c(4851): gst_ogg_demux_loop (): /GstPlayBin:playbin0/GstURIDecodeBin:uridecodebin0/GstDecodeBin:decodebin0/GstOggDemux:oggdemux0: streaming stopped, reason error (-5) ERROR: pipeline doesn't want to preroll. Setting pipeline to NULL ... Freeing pipeline ...
I can confirm this. When playing such a file with ffplay, it says things along those lines: [ogg @ 0x7fc5b0000920] 6 bytes of comment header remain [ogg @ 0x7fc5b0000920] truncated comment header, 11289601 comments not found When adding images to the tag, this even screws up the timestamps. ffplay complains about invalid pts, and ogginfo says: Negative or zero granulepos (-335) on Vorbis stream outside of headers. This file was created by a buggy encoder mpd, when playing such a file, sometimes has a slight hiccup at the start of the file. I never really thought about it before. I really only noticed it because my old iriver MP3 player refuses to play these files, as does a new AGPtek player I bought recently. Removing the tags doesn't help. Neither does ffmpeg -codec copy. Nothing short of re-encoding seems to be able to fix this. Basically, my whole library of music, over 100GB, is completely broken now. This really makes me sad :(
For the sake of easy comparison, here's an Ogg Vorbis file of a 10 seconds sine wave. First, the original file, as created by oggenc 1.4.0. with -q8: https://drmccoy.de/zeugs/sine_orig.ogg Then, the same file, but added some tags with easytag 2.4.3: https://drmccoy.de/zeugs/sine_tags.ogg . ogginfo doesn't complain there yet, but ffplay 3.3.4 says: [ogg @ 0x7f7dd8000920] 6 bytes of comment header remain [ogg @ 0x7f7dd8000920] truncated comment header, 11289600 comments not found Then, I took the file with tags in it and also added an image with easytag, a 525K 500x500 PNG of random RGB noise: https://drmccoy.de/zeugs/sine_image.ogg . ogginfo 1.4.0 now complains there with: Negative or zero granulepos (-201) on Vorbis stream outside of headers. This file was created by a buggy encoder and ffplay also says: [ogg @ 0x7f2798000920] invalid pts -201 in addition to the thing about the comment header.
Oh, and here's the same original file, with tags, and with tags and image added, by the way of vorbiscomment, without touching the files with easytag: https://drmccoy.de/zeugs/sine_tags_vorbiscomment.ogg https://drmccoy.de/zeugs/sine_image_vorbiscomment.ogg Neither ogginfo nor ffplay complain with any of these two files.
*** This bug has been marked as a duplicate of bug 776110 ***