Opened 11 years ago

Closed 11 years ago

#11293 closed Bug Report - General (Fixed)

Stuttery playback for some AVI file

Reported by: JYA Owned by:
Priority: major Milestone: unknown
Component: MythTV - General Version: 0.26-fixes
Severity: medium Keywords:
Cc: Ticket locked: no

Description (last modified by JYA)

Since the upgrade of 0.26, some of my AVI rip stop playing.

The reasons is a change in ffmpeg that detects the video as being non-interleaved. This in itself isn't a problem.

Myth will play the file just fine if the file is local, but over a 100Mbit/s (or wireless link) network link via Storage Group, it will stutter very quickly

Running mythfrontend with -n network --loglevel debug shows that the frontend starts to pull from the backend read of 1MB in size which takes too long and cause the playback thread to starve for data.

What need to be investigated is why the ringbuffer starts to pull so much data as opposed to when the file is interleaved. When the file is detected as interleaved, block size stay at 32kB.

Limiting the size of the block size to not exceed 128kB does help a little bit, but doesn't fully fix the issue.

sample of a file: http://www.avenard.org/files/media/mediatest/bolt.avi

log:

2012-12-15 19:06:55.191563 C  mythavtest version: fixes/0.26 [v0.26.0-51-ged7b577] www.mythtv.org
2012-12-15 19:06:55.191586 C  Qt version: compile: 4.8.1, runtime: 4.8.1
2012-12-15 19:06:55.191591 N  Enabled verbose msgs:  general
2012-12-15 19:06:55.191606 N  Setting Log Level to LOG_INFO
2012-12-15 19:06:55.192077 I  Added logging to the console
2012-12-15 19:06:55.192282 N  Using runtime prefix = /usr
2012-12-15 19:06:55.192298 N  Using configuration directory = /home/myth/.mythtv
2012-12-15 19:06:55.192409 I  Assumed character encoding: en_AU.UTF-8
2012-12-15 19:06:55.193870 N  Empty LocalHostName.
2012-12-15 19:06:55.193879 I  Using localhost value of mythtv-Macmini
2012-12-15 19:06:55.193918 I  Testing network connectivity to '192.168.10.11'
2012-12-15 19:06:55.196369 I  Starting process manager
2012-12-15 19:06:55.196388 I  Starting process signal handler
2012-12-15 19:06:55.196509 I  Starting IO manager (read)
2012-12-15 19:06:55.196526 I  Starting IO manager (write)
2012-12-15 19:06:55.328657 N  Setting QT default locale to en_AU
2012-12-15 19:06:55.328766 I  Current locale en_AU
2012-12-15 19:06:55.329217 E  No locale defaults file for en_AU, skipping
2012-12-15 19:06:55.397104 I  ScreenSaverX11Private: XScreenSaver support enabled
2012-12-15 19:06:55.398183 I  ScreenSaverX11Private: DPMS is disabled.
2012-12-15 19:06:55.417446 I  Added logging to mythlogserver at TCP:35327
2012-12-15 19:06:55.438991 N  Desktop video mode: 1920x1080 23.976 Hz
2012-12-15 19:06:55.526700 N  Desktop video mode: 1920x1080 23.976 Hz
2012-12-15 19:06:55.592390 I  Trying 1920x1080 0.000 Hz
2012-12-15 19:06:55.937191 I  SwitchToGUI: Switched to 1920x1080 0.000 Hz
2012-12-15 19:06:55.980368 I  LIRC: Successfully initialized '/dev/lircd' using '/home/myth/.mythtv/lircrc' config
2012-12-15 19:06:55.980495 E  JoystickMenuThread: Joystick disabled - Failed to read /home/myth/.mythtv/joystickmenurc
2012-12-15 19:06:56.054850 E  CECAdapter: Failed to find any CEC devices.
2012-12-15 19:06:56.054930 I  CECAdapter: Closing down CEC.
2012-12-15 19:06:56.054951 I  UDPListener: Enabling
2012-12-15 19:06:56.074875 E  Failed binding to UDP 127.0.0.1:6948 - Error 8: The bound address is already in use
2012-12-15 19:06:56.074932 E  Failed binding to UDP 192.168.10.123:6948 - Error 8: The bound address is already in use
2012-12-15 19:06:56.074993 E  Failed binding to UDP [::1]:6948 - Error 8: The bound address is already in use
2012-12-15 19:06:56.075049 E  Failed binding to UDP [fd87:41a7:4138:10::33]:6948 - Error 8: The bound address is already in use
2012-12-15 19:06:56.075116 E  Failed binding to UDP [fe80::5ab0:35ff:fe82:f46f%eth1]:6948 - Error 8: The bound address is already in use
2012-12-15 19:06:56.075202 E  Failed binding to UDP 192.168.10.255:6948 - Error 8: The bound address is already in use
2012-12-15 19:06:56.292567 W  Key Esc is bound to multiple actions in context Main Menu.
2012-12-15 19:06:56.328574 I  Using Frameless Window
2012-12-15 19:06:56.328645 I  Using Full Screen Window
2012-12-15 19:06:56.423338 I  Trying the OpenGL painter
2012-12-15 19:06:56.467246 I  OpenGL: Sync to VBlank is enabled (good!)
2012-12-15 19:06:56.538029 I  OpenGL1: Fragment program support available
2012-12-15 19:06:56.538101 I  OpenGL: OpenGL vendor  : NVIDIA Corporation
2012-12-15 19:06:56.538108 I  OpenGL: OpenGL renderer: GeForce 320M/integrated/SSE2
2012-12-15 19:06:56.538113 I  OpenGL: OpenGL version : 3.3.0 NVIDIA 295.40
2012-12-15 19:06:56.538122 I  OpenGL: Max texture size: 8192 x 8192
2012-12-15 19:06:56.538127 I  OpenGL: Max texture units: 4
2012-12-15 19:06:56.538143 I  OpenGL: Direct rendering: Yes
2012-12-15 19:06:56.538148 I  OpenGL: PixelBufferObject support available
2012-12-15 19:06:56.538152 I  OpenGL: Initialised MythRenderOpenGL
2012-12-15 19:06:56.725969 E  'buttontext' (base.xml:1998): <scroll> and <cutdown> are not combinable.
2012-12-15 19:06:56.733129 E  'buttontext' (base.xml:2243): <scroll> and <cutdown> are not combinable.
2012-12-15 19:06:56.868798 I  Setup Interrupt handler
2012-12-15 19:06:56.868808 I  Setup Terminated handler
2012-12-15 19:06:56.868816 I  Setup Segmentation fault handler
2012-12-15 19:06:56.868823 I  Setup Aborted handler
2012-12-15 19:06:56.868831 I  Setup Bus error handler
2012-12-15 19:06:56.868839 I  Setup Floating point exception handler
2012-12-15 19:06:56.868847 I  Setup Illegal instruction handler
2012-12-15 19:06:56.868857 I  Setup Real-time signal 0 handler
2012-12-15 19:06:57.362551 I  Current MythTV Schema Version (DBSchemaVer): 1307
2012-12-15 19:06:57.370307 I  TV: Creating TV object
2012-12-15 19:06:57.466718 N  Suspending idle timer
2012-12-15 19:06:57.486178 I  TV: Created TvPlayWindow.
2012-12-15 19:06:57.673426 I  MythCoreContext: Connecting to backend server: 192.168.10.11:6543 (try 1 of 1)
2012-12-15 19:06:57.676104 I  Using protocol version 75
2012-12-15 19:06:57.698988 I  TV: Attempting to change from None to WatchingVideo
2012-12-15 19:06:57.725494 I  Using protocol version 75
2012-12-15 19:06:57.729069 I  Using protocol version 75
2012-12-15 19:06:57.971642 N  AudioPlayer: Enabling Audio
libva: VA-API version 0.32.0
Xlib:  extension "XFree86-DRI" missing on display ":0.0".
libva: va_getDriverName() returns 0
libva: Trying to open /usr/lib/x86_64-linux-gnu/dri/nvidia_drv_video.so
libva: va_openDriver() returns -1
2012-12-15 19:06:59.554788 I  VDPAU: Version 1
2012-12-15 19:06:59.554805 I  VDPAU: Information NVIDIA VDPAU Driver Shared Library  295.40  Thu Apr  5 22:02:06 PDT 2012
2012-12-15 19:06:59.556528 E  VAAPI: Error at vaapicontext.cpp:144 (#-1, unknown libva error)
2012-12-15 19:06:59.556761 E  VAAPI: Invalid display
2012-12-15 19:06:59.557315 I  AFD: Opened codec 0x2980100, id(MPEG4) type(Video)
2012-12-15 19:06:59.557327 I  AFD: codec MP3 has 2 channels
2012-12-15 19:06:59.557406 I  AFD: Opened codec 0x2bb5d60, id(MP3) type(Audio)
2012-12-15 19:06:59.584233 I  AO: Opening audio device 'hdmi:CARD=NVidia,DEV=2' ch 2(2) sr 48000 sf signed 16 bit reenc 0
2012-12-15 19:06:59.627104 E  ALSA: Requested 500000us got 341333 buffer time
2012-12-15 19:06:59.627331 E  ALSA: Try to manually increase audio buffer with: echo 128 | sudo tee /proc/asound/card0/pcm8p/sub0/prealloc
2012-12-15 19:07:00.334564 I  Clearing OpenGL painter cache.
2012-12-15 19:07:00.779031 I  VDPAU: Created 2 output surfaces.
2012-12-15 19:07:00.779055 I  VDPAU: Created VDPAU render device 1920x1080
2012-12-15 19:07:01.054114 I  Player(0): Video timing method: USleep with busy wait
2012-12-15 19:07:01.055200 I  TV: Created player.
2012-12-15 19:07:01.055246 I  TV: Changing from None to WatchingVideo
2012-12-15 19:07:01.139657 I  TV: Main UI disabled.
2012-12-15 19:07:01.139674 I  TV: Entering main playback loop.
2012-12-15 19:07:01.167635 I  VDPAU: Added 2 output surfaces (total 4, max 4)
2012-12-15 19:07:03.306510 N  Player(0): Waited 102ms for video buffers AAAAAAAAAAAAAAAAAAAAAAALLfff
2012-12-15 19:07:03.462303 N  Player(0): Waited 103ms for video buffers LAAAAAAAAAAAAAAAAAAAAAALffff
2012-12-15 19:07:03.614884 N  Player(0): Waited 103ms for video buffers LLAAAAAAAAAAAAAAAAAAAAAffAAf
2012-12-15 19:07:03.769998 N  Player(0): Waited 102ms for video buffers LfLAAAAAAAAAAAAAAAAAAAAffAAf
2012-12-15 19:07:03.921878 N  Player(0): Waited 102ms for video buffers LffLAAAAAAAAAAAAAAAAAAAfAAAA
2012-12-15 19:07:04.079599 N  Player(0): Waited 103ms for video buffers fffLLAAAAAAAAAAAAAAAAAAfAAAA
2012-12-15 19:07:04.231478 N  Player(0): Waited 102ms for video buffers fAfLfLAAAAAAAAAAAAAAAAAfAAAA
2012-12-15 19:07:04.333820 N  Player(0): Waited 204ms for video buffers fAfLfLAAAAAAAAAAAAAAAAAfAAAA
2012-12-15 19:07:04.523947 N  Player(0): Waited 102ms for video buffers FAAuFFuUuLLAAAAAAAAAAAAAAAAA
2012-12-15 19:07:08.704877 N  Player(0): Waited 102ms for video buffers AAAAAAfAAfAALAAAAAAfLAAAAAAA
2012-12-15 19:07:08.857160 N  Player(0): Waited 103ms for video buffers AAAAAAfAAfAAfAAAAAAfLALAAAAA
2012-12-15 19:07:09.009453 N  Player(0): Waited 102ms for video buffers AAAAAAAAAfAAfAAAAAAAfALAALAA
2012-12-15 19:07:09.112250 N  Player(0): Waited 205ms for video buffers AAAAAAAAAfAAfAAAAAAAfALAALAA
2012-12-15 19:07:09.323931 N  Player(0): Waited 102ms for video buffers AAAAAAAAAFAAFAAuAAAAfALAAfAL
2012-12-15 19:07:09.471705 N  Player(0): Waited 103ms for video buffers AAAAAAAAAAAAAAAfAAAAfAuALfAL
2012-12-15 19:07:09.618445 N  Player(0): Waited 102ms for video buffers AAAAAAAAAAAAAAAfAALAfAfAuFAL
2012-12-15 19:07:09.906426 N  Player(0): Waited 102ms for video buffers AALAAAAAAAAAAAAAAAfAAAfLfAAu
2012-12-15 19:07:10.053518 N  Player(0): Waited 102ms for video buffers AAuAAAAAAAAAAAAAAAfAALfLFAAf
2012-12-15 19:07:10.200683 N  Player(0): Waited 102ms for video buffers AAfAAAAAAAAAAAAAAAfAALfLAAAf
2012-12-15 19:07:10.352449 N  Player(0): Waited 102ms for video buffers AAfALAAAAAAAAAAAAAAAAfALAAAf
2012-12-15 19:07:10.505174 N  Player(0): Waited 103ms for video buffers AAFALuAAAAAAAAAAAAAAAfAfAALf
2012-12-15 19:07:10.651808 N  Player(0): Waited 102ms for video buffers AAAALfAAAAAAAAAAAAAAAfAfAALf
2012-12-15 19:07:10.804094 N  Player(0): Waited 103ms for video buffers AAAAufALLAAAAAAAAAAAAAAfAAfA
2012-12-15 19:07:10.950960 N  Player(0): Waited 102ms for video buffers AAAAffALLAAAAAAAAAAAAAAfAAfA
2012-12-15 19:07:11.110150 N  Player(0): Waited 102ms for video buffers ALAAfAALfAAAAAAAAAAAAAAFAAFA
2012-12-15 19:07:11.257853 N  Player(0): Waited 102ms for video buffers AfAAfAAufALLAAAAAAAAAAAAAAAA
2012-12-15 19:07:11.405099 N  Player(0): Waited 103ms for video buffers AfAAfAAffALLAAAAAAAAAAAAAAAA
2012-12-15 19:07:11.563380 N  Player(0): Waited 103ms for video buffers LfAAfAAfAALfAAAAAAAAAAAAAAAA
2012-12-15 19:07:11.665492 N  Player(0): Waited 205ms for video buffers LfAAfAAfAALfAAAAAAAAAAAAAAAA
2012-12-15 19:07:11.996263 N  Player(0): Waited 102ms for video buffers fAAAAAAfAAfFALuALAAAAAAAAAAA
2012-12-15 19:07:12.143604 N  Player(0): Waited 103ms for video buffers FAALAAAFAAfAALfAuAAAAAAAAAAA
2012-12-15 19:07:12.430777 N  Player(0): Waited 102ms for video buffers AAALAALAAAfAAfFAfuAAAAAAAAAA
2012-12-15 19:07:13.006503 N  Player(0): Waited 103ms for video buffers AAAfAAAAAfAAfAAAAAALAAAAALAA
2012-12-15 19:07:13.300351 N  Player(0): Waited 103ms for video buffers AAAfAAAAAAAAfAALAAAffAAAALAA
2012-12-15 19:07:13.450178 N  Player(0): Waited 103ms for video buffers AAAAAAAAAAAAAAAfAAAffALALuAA
2012-12-15 19:07:13.597267 N  Player(0): Waited 103ms for video buffers AAAAAAAAAAAAAAAfAAAffALALfAA
2012-12-15 19:07:13.750297 N  Player(0): Waited 103ms for video buffers AAAAAAAAAAAAAAAfAALfAAfALfAA
2012-12-15 19:07:13.852658 N  Player(0): Waited 205ms for video buffers AAAAAAAAAAAAAAAfAALfAAfALfAA
2012-12-15 19:07:14.046026 N  Player(0): Waited 102ms for video buffers AALAAAAAAAAAAAAAAAfAAAfALfAA
2012-12-15 19:07:14.209038 N  Player(0): Waited 102ms for video buffers AALAAAAAAAAAAAAAAAfAAAfAffAL
2012-12-15 19:07:14.362054 N  Player(0): Waited 102ms for video buffers AALAAAAAAAAAAAAAAAfAALAAffAf
2012-12-15 19:07:14.515649 N  Player(0): Waited 103ms for video buffers AAuAALAAAAAAAAAAAAAAAfALfAAf
2012-12-15 19:07:14.663368 N  Player(0): Waited 103ms for video buffers AAfAALAAAAAAAAAAAAAAAfAufALF
^C2012-12-15 19:07:14.785909 C  Received Interrupt: Code 128, PID 0, UID 0, Value 0x7f123c7a1c50
2012-12-15 19:07:14.785938 I  TV: Exiting main playback loop.
2012-12-15 19:07:14.896845 W  Player(0): Waited 100ms for decoder to pause
2012-12-15 19:07:14.978260 W  MythPainter: 41 images not yet de-allocated.
2012-12-15 19:07:14.978326 I  VDPAU Painter: Clearing VDPAU painter cache.
2012-12-15 19:07:15.065390 I  Trying 1920x1080 0.000 Hz
2012-12-15 19:07:15.065408 I  SwitchToGUI: Switched to 1920x1080 0.000 Hz

Attachments (3)

non-interleaved.log (281.4 KB) - added by JYA 11 years ago.
non-interleaved.2.log (281.4 KB) - added by JYA 11 years ago.
interleaved.log (188.6 KB) - added by JYA 11 years ago.

Download all attachments as: .zip

Change History (6)

comment:1 Changed 11 years ago by JYA

Description: modified (diff)

Changed 11 years ago by JYA

Attachment: non-interleaved.log added

Changed 11 years ago by JYA

Attachment: non-interleaved.2.log added

Changed 11 years ago by JYA

Attachment: interleaved.log added

comment:2 Changed 11 years ago by JYA

Playing the file detected as non-interleaved show a great amount of seek before reading, which the ringbuffer code doesn't handle well at all as it keeps pre-fetching data

Note that playing the same file over http, works just as well, you can seek just the same...

comment:3 Changed 11 years ago by JYA

Resolution: Fixed
Status: newclosed

got fixed a while ago (though not a very nice patch)

Note: See TracTickets for help on using tickets.