Ticket #11961: mythfrontend-log-20131128.txt

File mythfrontend-log-20131128.txt, 17.8 KB (added by Jay Jaeger <cube1@…>, 6 years ago)

Front end log with -v libav --loglevel debug [Captured via script command]

Line 
1Script started on Thu 28 Nov 2013 12:46:24 PM CST
2]0;jay@mythtemp: ~/uploadjay@mythtemp:~/upload$ exitntpq -pservice ntp restartd restart[1P restart[12Pntpq -p[3Pexit[Kmythfreont[K[K[K[Kontend -v libav --loglevel debug
3QGtkStyle was unable to detect the current GTK+ theme.
42013-11-28 12:46:40.003891 I  Setup Interrupt handler
52013-11-28 12:46:40.003919 I  Setup Terminated handler
62013-11-28 12:46:40.003929 I  Setup Segmentation fault handler
72013-11-28 12:46:40.003937 I  Setup Aborted handler
82013-11-28 12:46:40.003950 I  Setup Bus error handler
92013-11-28 12:46:40.003959 I  Setup Floating point exception handler
102013-11-28 12:46:40.003969 I  Setup Illegal instruction handler
112013-11-28 12:46:40.003978 I  Setup Real-time signal 0 handler
122013-11-28 12:46:40.003990 I  Setup User defined signal 1 handler
132013-11-28 12:46:40.004000 I  Setup User defined signal 2 handler
142013-11-28 12:46:40.004139 C  mythfrontend version: fixes/0.27 [v0.27-108-ge5acf0c] www.mythtv.org
152013-11-28 12:46:40.004148 C  Qt version: compile: 4.8.1, runtime: 4.8.1
162013-11-28 12:46:40.004153 N  Enabled verbose msgs:  general libav
172013-11-28 12:46:40.004169 N  Setting Log Level to LOG_DEBUG
182013-11-28 12:46:40.014671 N  Using runtime prefix = /usr
192013-11-28 12:46:40.014691 N  Using configuration directory = /home/jay/.mythtv
202013-11-28 12:46:40.014780 I  Assumed character encoding: en_US.UTF-8
212013-11-28 12:46:40.015307 N  Empty LocalHostName.
222013-11-28 12:46:40.015324 I  Using localhost value of mythtemp
232013-11-28 12:46:40.016216 I  Added logging to the console
242013-11-28 12:46:40.027845 D  FindDatabase() - Success!
252013-11-28 12:46:40.030218 N  Setting QT default locale to EN_US
262013-11-28 12:46:40.030312 I  Current locale EN_US
272013-11-28 12:46:40.030373 N  Reading locale defaults from /usr/share/mythtv//locales/en_us.xml
282013-11-28 12:46:40.035878 I  Starting process manager
292013-11-28 12:46:40.036001 I  Starting IO manager (read)
302013-11-28 12:46:40.035985 I  Starting process signal handler
312013-11-28 12:46:40.037283 I  Starting IO manager (write)
322013-11-28 12:46:40.117875 I  New Client:  (#1)
332013-11-28 12:46:40.117922 I  Added syslogging
342013-11-28 12:46:40.136287 I  ScreenSaverX11Private: XScreenSaver support enabled
352013-11-28 12:46:40.136765 I  ScreenSaverX11Private: DPMS is disabled.
362013-11-28 12:46:40.145015 N  Desktop video mode: 1024x768 59.920 Hz
372013-11-28 12:46:40.285548 D  Adding IPv4 loopback to address list.
382013-11-28 12:46:40.285564 D  Adding BackendServerIP6 to address list.
392013-11-28 12:46:40.285576 D  Adding BackendServerIP to address list.
402013-11-28 12:46:40.285617 D  Adding link-local 'FE80::21D:9FF:FE89:7BBB%eth0' to address list.
412013-11-28 12:46:40.285824 I  Listening on TCP 127.0.0.1:6547
422013-11-28 12:46:40.285913 I  Listening on TCP 192.168.42.21:6547
432013-11-28 12:46:40.285989 I  Listening on TCP [::1]:6547
442013-11-28 12:46:40.286074 I  Listening on TCP [fe80::21d:9ff:fe89:7bbb%eth0]:6547
452013-11-28 12:46:40.780192 D  MMulticastSocketDevice(:25): setsockopt - IP_MULTICAST_IF
46                        eno: Cannot assign requested address (99)
47cannot find libcec.solibcec.so: cannot open shared object file: No such file or directory
482013-11-28 12:46:41.001944 D  MMulticastSocketDevice(:25): setsockopt - IP_MULTICAST_IF
49                        eno: Cannot assign requested address (99)
502013-11-28 12:46:41.013688 I  Loading en_us translation for module mythfrontend
512013-11-28 12:46:41.017967 E  LIRC: Failed to connect to Unix socket '/dev/lircd'
52                        eno: No such file or directory (2)
532013-11-28 12:46:41.018029 E  JoystickMenuThread: Joystick disabled - Failed to read /home/jay/.mythtv/joystickmenurc
542013-11-28 12:46:41.022948 E  CECAdapter: Failed to load libcec.
552013-11-28 12:46:41.022983 I  UDPListener: Enabling
562013-11-28 12:46:41.023479 I  Binding to UDP 127.0.0.1:6948
572013-11-28 12:46:41.023535 I  Binding to UDP 192.168.42.21:6948
582013-11-28 12:46:41.023604 I  Binding to UDP [::1]:6948
592013-11-28 12:46:41.023679 I  Binding to UDP [fe80::21d:9ff:fe89:7bbb%eth0]:6948
602013-11-28 12:46:41.023741 I  Binding to UDP 192.168.42.255:6948
612013-11-28 12:46:41.050856 I  Using Frameless Window
622013-11-28 12:46:41.050903 I  Using Full Screen Window
632013-11-28 12:46:41.139486 I  Using the Qt painter
642013-11-28 12:46:41.229736 I  MythCoreContext: Connecting to backend server: 192.168.42.21:6543 (try 1 of 1)
652013-11-28 12:46:41.242311 I  Using protocol version 77
662013-11-28 12:46:41.305850 D  Copying DLManager's Cookie Jar
672013-11-28 12:46:41.366403 D  MythCookieJar: loading cookies from: /home/jay/.mythtv/MythBrowser/cookiejar.txt
682013-11-28 12:46:41.367909 I  MythUIWebBrowser: Loading css from - file:///usr/share/mythtv/themes/default/htmls/mythbrowser.css
692013-11-28 12:46:41.368321 E  MythUIWebBrowser: failed to find our parent screen
702013-11-28 12:46:41.369635 I  MythUIWebBrowser: enabling plugins
712013-11-28 12:46:41.414406 I  AirPlay: Created airplay objects.
722013-11-28 12:46:41.414465 E  RAOP Device: Aborting startup - no key found.
732013-11-28 12:46:41.414556 I  Listening on TCP 127.0.0.1:5100
742013-11-28 12:46:41.414617 I  Listening on TCP 192.168.42.21:5100
752013-11-28 12:46:41.414692 I  Listening on TCP [::1]:5100
762013-11-28 12:46:41.414757 I  Listening on TCP [fe80::21d:9ff:fe89:7bbb%eth0]:5100
772013-11-28 12:46:41.416359 I  Current MythTV Schema Version (DBSchemaVer): 1317
782013-11-28 12:46:41.452173 W  ThemeInfo: Unable to open themeinfo.xml for /usr/share/mythtv/themes/BlackCurves-OSD/themeinfo.xml
792013-11-28 12:46:41.452184 E  ThemeInfo: The theme (/usr/share/mythtv/themes/BlackCurves-OSD) is missing a themeinfo.xml file.
802013-11-28 12:46:41.452804 W  ThemeInfo: Unable to open themeinfo.xml for /usr/share/mythtv/themes/Gray-OSD/themeinfo.xml
812013-11-28 12:46:41.452813 E  ThemeInfo: The theme (/usr/share/mythtv/themes/Gray-OSD) is missing a themeinfo.xml file.
822013-11-28 12:46:41.544805 N  Registering Internal as a media playback plugin.
832013-11-28 12:46:41.583665 D  MonitorRegisterExtensions(0x100, bmp,gif,ico,jpeg,jpg,mng,pbm,pgm,png,ppm,tga,tif,tiff,xbm,xpm)
842013-11-28 12:46:41.583778 I  Loading en_us translation for module mythgallery
852013-11-28 12:46:41.587200 I  Current MythMusic Schema Version (MusicDBSchemaVer): 1020
862013-11-28 12:46:41.593250 D  MonitorRegisterExtensions(0x40, mp3,mp2,ogg,oga,flac,wma,wav,ac3,oma,omg,atp,ra,dts,aac,m4a,aa3,tta,mka,aiff,swa,wv)
872013-11-28 12:46:41.595111 I  Loading en_us translation for module mythmusic
882013-11-28 12:46:41.631124 N  Found mainmenu.xml for theme 'Mythbuntu'
892013-11-28 12:46:41.634904 I  Registering HouseKeeperTask 'HardwareProfiler'.
902013-11-28 12:46:41.635906 I  Starting HouseKeeper.
912013-11-28 12:46:41.881130 I  Bonjour: Service registration complete: name 'Mythfrontend on mythtemp' type '_mythfrontend._tcp.' domain: 'local.'
922013-11-28 12:46:42.289151 I  Bonjour: Service registration complete: name 'MythTV on mythtemp' type '_airplay._tcp.' domain: 'local.'
932013-11-28 12:46:44.357313 D  SendReceiveStringList(GET_FREE_RECORDER_COUNT) called from UI thread
942013-11-28 12:46:44.359166 I  TV: Creating TV object
952013-11-28 12:46:44.381280 N  Suspending idle timer
962013-11-28 12:46:44.383372 I  TV: Created TvPlayWindow.
972013-11-28 12:46:44.391409 D  SendReceiveStringList(GET_FREE_RECORDER_COUNT) called from UI thread
982013-11-28 12:46:44.393203 D  SendReceiveStringList(GET_NEXT_FREE_RECORDER,-1) called from UI thread
992013-11-28 12:46:44.394613 D  LiveTVChain(): ctor
1002013-11-28 12:46:44.395264 I  TV: Attempting to change from None to WatchingLiveTV
1012013-11-28 12:46:44.396321 I  MythCoreContext: Connecting to backend server: 192.168.42.21:6543 (try 1 of 1)
1022013-11-28 12:46:44.402316 D  SendReceiveStringList(QUERY_RECORDER 1,GET_FREE_INPUTS...) called from UI thread
1032013-11-28 12:46:44.402900 D  SendReceiveStringList(QUERY_RECORDER 2,GET_FREE_INPUTS...) called from UI thread
1042013-11-28 12:46:44.403527 D  SendReceiveStringList(QUERY_RECORDER 3,GET_FREE_INPUTS...) called from UI thread
1052013-11-28 12:46:44.404341 D  SendReceiveStringList(QUERY_RECORDER 1,GET_FREE_INPUTS...) called from UI thread
1062013-11-28 12:46:44.404837 D  SendReceiveStringList(QUERY_RECORDER 2,GET_FREE_INPUTS...) called from UI thread
1072013-11-28 12:46:44.406558 D  SendReceiveStringList(QUERY_RECORDER 1,GET_FREE_INPUTS) called from UI thread
1082013-11-28 12:46:44.407050 D  SendReceiveStringList(QUERY_RECORDER 2,GET_FREE_INPUTS) called from UI thread
1092013-11-28 12:46:44.407652 D  SendReceiveStringList(QUERY_RECORDER 3,GET_FREE_INPUTS) called from UI thread
1102013-11-28 12:46:44.408253 D  SendReceiveStringList(GET_RECORDER_FROM_NUM,2) called from UI thread
1112013-11-28 12:46:44.408708 I  MythCoreContext: Connecting to backend server: 192.168.42.21:6543 (try 1 of 1)
1122013-11-28 12:46:44.413723 N  TV: Spawning LiveTV Recorder -- begin
1132013-11-28 12:46:44.865454 N  TV: Spawning LiveTV Recorder -- end
1142013-11-28 12:46:44.868785 I  TV: playbackURL(/video1/livetv/2031_20131128184644.mpg) cardtype(DUMMY)
1152013-11-28 12:46:44.903026 E  ALSA: snd_pcm_info_get_card: Operation not permitted
1162013-11-28 12:46:44.915116 N  AudioPlayer: Enabling Audio
1172013-11-28 12:46:44.928232 I  Setup Interrupt handler
1182013-11-28 12:46:44.928243 I  Setup Terminated handler
1192013-11-28 12:46:44.928303 I  VideoOutputXv: XVideo Adaptor Name: 'Radeon Textured Video'
1202013-11-28 12:46:44.949705 I  OSD: Base theme size: 1280x720
1212013-11-28 12:46:44.949733 I  OSD: Scaling factors: 0.5625x0.8
122greedyhdeint: size changed from 0 x 0 -> 720 x 576
1232013-11-28 12:46:44.994593 I  OSD: Base theme size: 1280x720
1242013-11-28 12:46:44.994609 I  OSD: Scaling factors: 0.5625x0.8
1252013-11-28 12:46:45.023138 I  Player(0): Video timing method: DRM
1262013-11-28 12:46:45.039662 I  TV: Created player.
1272013-11-28 12:46:45.039712 I  TV: Changing from None to WatchingLiveTV
1282013-11-28 12:46:45.039722 I  TV: State is LiveTV & mctx == ctx
1292013-11-28 12:46:45.040812 I  TV: UpdateOSDInput done
1302013-11-28 12:46:45.040826 I  TV: UpdateLCD done
1312013-11-28 12:46:45.040997 I  TV: ITVRestart done
1322013-11-28 12:46:45.050322 I  TV: Main UI disabled.
1332013-11-28 12:46:45.051597 I  TV: Entering main playback loop.
1342013-11-28 12:46:45.123542 I  VideoOutput: Created YV12 OSD.
1352013-11-28 12:46:46.682827 D  mpegts_read_header: TS packet size = 188
1362013-11-28 12:46:46.682889 D  mpegts_add_stream: at pid 0x402 with type 2
1372013-11-28 12:46:46.683605 D  [mpegts @ 0x7f711b528220] stream=0 stream_type=2 pid=402 prog_reg_desc=
1382013-11-28 12:46:46.683622 D  mpegts_add_stream: stream #0, has id 0x402 and codec MPEG2VIDEO, type Video at 0x3176640
1392013-11-28 12:46:46.683629 D  mpegts_add_stream: at pid 0x403 with type 129
1402013-11-28 12:46:46.684251 D  [mpegts @ 0x7f711b528220] stream=1 stream_type=81 pid=403 prog_reg_desc=
1412013-11-28 12:46:46.684272 D  mpegts_add_stream: stream #1, has id 0x403 and codec AC3, type Audio at 0x3134a80
1422013-11-28 12:46:46.684279 D  mpegts_add_stream: at pid 0x404 with type 129
1432013-11-28 12:46:46.684883 D  [mpegts @ 0x7f711b528220] stream=2 stream_type=81 pid=404 prog_reg_desc=
1442013-11-28 12:46:46.684893 D  mpegts_add_stream: stream #2, has id 0x404 and codec AC3, type Audio at 0x31c6760
1452013-11-28 12:46:46.684917 D  [mpegts @ 0x7f711b528220] File position before avformat_find_stream_info() is 0
1462013-11-28 12:46:46.704098 D  [mpegts @ 0x7f711b528220] Continuity check failed for pid 0 expected 12 got 14
1472013-11-28 12:46:46.704117 D  [mpegts @ 0x7f711b528220] Continuity check failed for pid 1025 expected 12 got 14
1482013-11-28 12:46:47.328076 D  [mpegts @ 0x7f711b528220] All info found
1492013-11-28 12:46:47.328205 D  [mpegts @ 0x7f711b528220] Estimating duration from bitrate, this may be inaccurate
1502013-11-28 12:46:47.328223 D  [mpegts @ 0x7f711b528220] File position after avformat_find_stream_info() is 1525808
1512013-11-28 12:46:47.328256 I  AFD: codec AC3 has 6 channels
1522013-11-28 12:46:47.328707 I  AFD: Opened codec 0x312b260, id(AC3) type(Audio)
1532013-11-28 12:46:47.328929 I  AFD: codec AC3 has 2 channels
1542013-11-28 12:46:47.329322 I  AFD: Opened codec 0x313ffc0, id(AC3) type(Audio)
1552013-11-28 12:46:47.333557 I  Setup Interrupt handler
1562013-11-28 12:46:47.333569 I  Setup Terminated handler
1572013-11-28 12:46:47.338080 I  Setup Interrupt handler
1582013-11-28 12:46:47.338090 I  Setup Terminated handler
1592013-11-28 12:46:47.338145 I  VideoOutputXv: XVideo Adaptor Name: 'Radeon Textured Video'
1602013-11-28 12:46:47.425450 I  OSD: Base theme size: 1280x720
1612013-11-28 12:46:47.425520 I  OSD: Scaling factors: 1.12422x1.5
1622013-11-28 12:46:47.468778 I  AFD: Opened codec 0x314a6a0, id(MPEG2VIDEO) type(Video)
1632013-11-28 12:46:47.583767 I  AOBase: Opening audio device 'default' ch 2(6) sr 48000 sf 32 bit floating point reenc 0
1642013-11-28 12:46:47.598996 E  ALSA: no playback control PCM found on mixer device default
1652013-11-28 12:46:47.599007 E  ALSA: Unable to open audio mixer. Volume control disabled
1662013-11-28 12:46:47.601265 D  Input #0, mpegts, from '/video1/livetv/2031_20131128184645.mpg':
1672013-11-28 12:46:47.601283 D  Duration: N/A, start: 61659.342433, bitrate: 480 kb/s
1682013-11-28 12:46:47.601352 D  Stream #0:0[0x402], 21, 1/90000: Video: mpeg2video (Main), yuv420p, 1920x1080 [SAR 1:1 DAR 16:9], 1001/60000, 500 kb/s, 29.97 fps, 29.97 tbr, 90k tbn, 59.94 tbc
1692013-11-28 12:46:47.601390 D  Stream #0:1[0x403](eng), 22, 1/90000: Audio: ac3 (AC-3 / 0x332D4341), 48000 Hz, 5.1(side), fltp, 384 kb/s
1702013-11-28 12:46:47.601430 D  Stream #0:2[0x404](spa), 23, 1/90000: Audio: ac3 (AC-3 / 0x332D4341), 48000 Hz, stereo, fltp, 96 kb/s
1712013-11-28 12:46:47.763147 N  Player(0): Waited 111ms for video buffers AAAAAAAAAAAAAAAAAAAUUUUUUUUUuLLP
1722013-11-28 12:46:47.880025 I  VideoOutput: Created YV12 OSD.
1732013-11-28 12:46:51.202934 D  SendReceiveStringList(QUERY_RECORDER 1,GET_FREE_INPUTS...) called from UI thread
1742013-11-28 12:46:51.203762 D  SendReceiveStringList(QUERY_RECORDER 2,GET_FREE_INPUTS...) called from UI thread
1752013-11-28 12:46:51.206089 D  SendReceiveStringList(QUERY_RECORDER 3,GET_FREE_INPUTS...) called from UI thread
1762013-11-28 12:46:51.207579 D  SendReceiveStringList(QUERY_RECORDER 1,GET_FREE_INPUTS...) called from UI thread
1772013-11-28 12:46:51.208192 D  SendReceiveStringList(QUERY_RECORDER 2,GET_FREE_INPUTS...) called from UI thread
1782013-11-28 12:46:51.209571 D  SendReceiveStringList(QUERY_RECORDER 3,GET_FREE_INPUTS...) called from UI thread
1792013-11-28 12:46:51.232578 D  SendReceiveStringList(QUERY_RECORDER 1,GET_FREE_INPUTS...) called from UI thread
1802013-11-28 12:46:51.233531 D  SendReceiveStringList(QUERY_RECORDER 2,GET_FREE_INPUTS...) called from UI thread
1812013-11-28 12:46:51.234957 D  SendReceiveStringList(QUERY_RECORDER 3,GET_FREE_INPUTS...) called from UI thread
1822013-11-28 12:46:51.235696 D  SendReceiveStringList(GET_RECORDER_FROM_NUM,1) called from UI thread
1832013-11-28 12:46:51.352308 D  Closing PAT Filter: pid=0x0
1842013-11-28 12:46:51.352321 D  Closing PMT Filter: pid=0x401
1852013-11-28 12:46:51.360105 I  Setup Interrupt handler
1862013-11-28 12:46:51.360119 I  Setup Terminated handler
1872013-11-28 12:46:51.382723 W  MythPainter: 25 images not yet de-allocated.
1882013-11-28 12:46:51.626829 I  MythCoreContext: Connecting to backend server: 192.168.42.21:6543 (try 1 of 1)
1892013-11-28 12:46:52.683662 E  ALSA: snd_pcm_info_get_card: Operation not permitted
1902013-11-28 12:46:52.694221 N  AudioPlayer: Enabling Audio
1912013-11-28 12:46:53.916012 W  RingBuf(/video1/livetv/1011_20131128184652.mpg): Taking too long to be allowed to read..
1922013-11-28 12:46:54.221376 W  RingBuf(/video1/livetv/1011_20131128184652.mpg): Taking too long to be allowed to read..
1932013-11-28 12:46:54.526751 W  RingBuf(/video1/livetv/1011_20131128184652.mpg): Taking too long to be allowed to read..
1942013-11-28 12:46:54.832123 W  RingBuf(/video1/livetv/1011_20131128184652.mpg): Taking too long to be allowed to read..
1952013-11-28 12:46:55.137493 W  RingBuf(/video1/livetv/1011_20131128184652.mpg): Taking too long to be allowed to read..
1962013-11-28 12:46:55.202764 W  RingBuf(/video1/livetv/1011_20131128184652.mpg): Taking too long to be allowed to read..
1972013-11-28 12:46:55.208374 E  Player(1): Couldn't find an A/V decoder for: '/video1/livetv/1011_20131128184652.mpg'
1982013-11-28 12:46:55.208401 E  Player(1): Unable to open video file.
1992013-11-28 12:46:55.208408 E  playCtx: StartPlaying() Failed to start player
2002013-11-28 12:46:55.508897 E  TV: LiveTV not successfully started
2012013-11-28 12:46:55.512593 E  LiveTVChain(live-mythtemp-2013-11-28T18:46:44Z): SwitchTo() not switching to current
202^C2013-11-28 12:47:18.235539 C  Received Interrupt: Code 128, PID 0, UID 0, Value 0x00000000
2032013-11-28 12:47:18.235564 I  TV: Exiting main playback loop.
2042013-11-28 12:47:18.523440 D  LiveTVChain(live-mythtemp-2013-11-28T18:46:44Z): dtor
2052013-11-28 12:47:18.525544 N  Resuming idle timer
2062013-11-28 12:47:18.527115 N  Resuming idle timer
2072013-11-28 12:47:18.527156 N  Resuming idle timer
2082013-11-28 12:47:21.626320 I  Bonjour: De-registering service '_mythfrontend._tcp.' on 'Mythfrontend on mythtemp'
2092013-11-28 12:47:21.626529 I  RAOP Device: Cleaning up.
2102013-11-28 12:47:21.626541 I  AirPlay: Cleaning up.
2112013-11-28 12:47:21.628072 I  Bonjour: De-registering service '_airplay._tcp.' on 'MythTV on mythtemp'
2122013-11-28 12:47:21.628381 I  Shutting down UPnP client...
2132013-11-28 12:47:22.198513 D  Refreshing DLManager's Cookie Jar
2142013-11-28 12:47:22.199569 D  Updating DLManager's Cookie Jar
2152013-11-28 12:47:22.200676 D  MythCookieJar: saving cookies to: /home/jay/.mythtv/MythBrowser/cookiejar.txt
2162013-11-28 12:47:22.201633 I  Waiting for threads to exit.
2172013-11-28 12:47:22.295764 I  Removing syslogging
218]0;jay@mythtemp: ~/uploadjay@mythtemp:~/upload$ ls -l
219total 20
220drwxrwxr-x 2 jay jay  4096 Nov 28 09:36 [0m[01;34m20131128[0m
221-rw-rw-r-- 1 jay jay 16384 Nov 28 12:46 log.out
222]0;jay@mythtemp: ~/uploadjay@mythtemp:~/upload$ pwd
223/home/jay/upload
224]0;jay@mythtemp: ~/uploadjay@mythtemp:~/upload$ exit
225exit
226
227Script done on Thu 28 Nov 2013 12:53:24 PM CST