[mythtv-users] Channel scanner won't find a specific channel

Sun Feb 7 20:41:30 UTC 2016

On Sun, Feb 7, 2016 at 2:49 AM, HP-mini <blm-ubunet at slingshot.co.nz> wrote:

> On Sat, 2016-02-06 at 22:27 +0000, John Pilkington wrote:
> > A bit more info:
> >
> > ionice -c3 mythtranscode -m --video -i WFXVsample1.mpg -o
> > WFXVsample1_mtr.mpg
> >
> > A few complaints in the log (below) and no mention of text or
> > unidentified streams.
> >
> > Both play smoothly as videos in 0.28-beta, but with stuff like this:
> >
> > 2016-02-06 22:19:38.945840 I  AFD: Key frame distance changed from 12 to
> 30.
> > 2016-02-06 22:19:40.152658 I  AFD: Key frame distance changed from 30 to
> 12.
> > 2016-02-06 22:19:40.648977 I  AFD: Key frame distance changed from 12 to
> 30.
> > 2016-02-06 22:19:40.850891 I  AFD: Key frame distance changed from 30 to
> 12.
> > 2016-02-06 22:19:41.346665 I  AFD: Key frame distance changed from 12 to
> 30.
> > 2016-02-06 22:19:42.472599 I  Player(1): FPS:   59.82 Mean: 16717
> > Std.Dev:  5783 CPUs: 22% 24%
> >
> >
> >
> > 2016-02-06 21:43:32.058930 N  Transcoding from
> > /home/john/SGs/VideosSG1/WFXVsample1.mpg to WFXVsample1_mtr.mpg
> > 2016-02-06 21:43:32.061479 I  Opening
> > /home/john/SGs/VideosSG1/WFXVsample1.mpg
> > 2016-02-06 21:43:32.294504 I  PES packet size mismatch
> > 2016-02-06 21:43:32.301206 I  Input #0, mpegts, from
> > '/home/john/SGs/VideosSG1/WFXVsample1.mpg':
> > 2016-02-06 21:43:32.301222 I    Duration: 00:00:54.50, start:
> > 17800.699322, bitrate: 15030 kb/s
> > 2016-02-06 21:43:32.301363 I      Stream #0:0[0x6f]: Video: mpeg2video
> > (Main), yuv420p(tv), 1280x720 [SAR 1:1 DAR 16:9], max. 14950 kb/s, 59.94
> > fps, 59.94 tbr, 90k tbn, 119.88 tbc
> > 2016-02-06 21:43:32.301396 I      Stream #0:1[0x70](eng): Audio: ac3,
> > 48000 Hz, 5.1(side), fltp, 384 kb/s
> > 2016-02-06 21:43:32.301420 I      Stream #0:2[0x71](spa): Audio: ac3,
> > 48000 Hz, stereo, fltp, 192 kb/s
> > 2016-02-06 21:43:32.317029 I  #0 PTS:04:56:41.131 Delta: 0.0ms queue: 38
> > 2016-02-06 21:43:32.317060 I  #1 PTS:04:56:41.115 Delta: 15.8556ms
> queue: 2
> > 2016-02-06 21:43:32.317074 I  #2 PTS:04:56:41.100 Delta: 31.1222ms
> queue: 4
> > 2016-02-06 21:43:32.317107 N  MPEG2fixup::InitReplex(): High Definition
> > input, increasing replex buffers
> > 2016-02-06 21:43:32.343413 I  Mux rate: 15.78 Mbit/s
> > 2016-02-06 21:43:33.479178 I  AVFrame.format is not set
> > 2016-02-06 21:43:33.479186 I  AVFrame.width or height is not set
> > 2016-02-06 21:43:33.481505 I  AVFrame.format is not set
> > 2016-02-06 21:43:33.481514 I  AVFrame.width or height is not set
> > 2016-02-06 21:43:33.526941 I  Inserting 0 I-Frames after #26
> > 2016-02-06 21:43:34.051092 I  PES packet size mismatch
> > 2016-02-06 21:43:34.051111 I  PES packet size mismatch
> > 2016-02-06 21:43:34.067022 I  Generating Keyframe Index
> > 2016-02-06 21:43:34.067036 I  Opening WFXVsample1_mtr.mpg
> > 2016-02-06 21:43:34.104892 I  Input #0, mpeg, from 'WFXVsample1_mtr.mpg':
> > 2016-02-06 21:43:34.104910 I    Duration: 00:00:54.10, start: 0.360000,
> > bitrate: 14930 kb/s
> > 2016-02-06 21:43:34.104972 I      Stream #0:0[0x1e0]: Video: mpeg2video
> > (Main), yuv420p(tv), 1280x720 [SAR 1:1 DAR 16:9], max. 14950 kb/s, 59.94
> > fps, 59.94 tbr, 90k tbn, 119.88 tbc
> > 2016-02-06 21:43:34.104998 I      Stream #0:1[0x81]: Audio: ac3, 48000
> > Hz, stereo, fltp, 192 kb/s
> > 2016-02-06 21:43:34.105019 I      Stream #0:2[0x80]: Audio: ac3, 48000
> > Hz, 5.1(side), fltp, 384 kb/s
> > 2016-02-06 21:43:34.308263 N  Transcode Completed
> > 2016-02-06 21:43:34.335123 N  Transcoding
> > /home/john/SGs/VideosSG1/WFXVsample1.mpg done
> >
>
> That 60p sample plays fine here (Videos) in master with ffmpeg CPU &
> VDPAU.
> I did not try the file with dummy recorder.
> I noticed that the OP was using ffmpeg CPU decode.
> CPU decode here uses 35% on mid-range core2duo, no jitter problems (OSD
> playback meter).

Thanks for the info.  I just monitored the CPU usage on my MythTV box while
a few different videos were playing, and it was consistently in the 5%-10%
range except for the moment the video started.

This is what I see when I play the sample I posted, while it's being all
weird and choppy:

2016-02-07 15:28:16.094440 I  Player(2): FPS:   30.22 Mean: 33090 Std.Dev:
 1930 CPUs: 101% 100%
2016-02-07 15:28:22.128193 I  Player(2): FPS:   39.61 Mean: 25243 Std.Dev:
 8344 CPUs: 8% 9% 6%
2016-02-07 15:28:28.678682 I  Player(2): FPS:   36.49 Mean: 27405 Std.Dev:
 7991 CPUs: 7% 7% 8%
2016-02-07 15:28:35.579324 I  Player(2): FPS:   34.64 Mean: 28871 Std.Dev:
 7393 CPUs: 5% 6% 7%
2016-02-07 15:28:40.979659 I  Player(2): FPS:   44.26 Mean: 22593 Std.Dev:
 7991 CPUs: 8% 9% 9%
2016-02-07 15:28:46.680104 I  Player(2): FPS:   41.93 Mean: 23849 Std.Dev:
 8265 CPUs: 8% 8% 7%
2016-02-07 15:28:53.130608 I  Player(2): FPS:   37.05 Mean: 26987 Std.Dev:
 8102 CPUs: 8% 7% 9%
2016-02-07 15:28:59.281147 I  Player(2): FPS:   38.86 Mean: 25732 Std.Dev:
 8317 CPUs: 7% 9% 8%

Note the 30-40 FPS, when it's supposed to be 60.

This is what happens when I play the 30 FPS recording from a different
channel, which plays fine:

2016-02-07 15:29:20.983329 I  Player(2): FPS:   28.97 Mean: 34520 Std.Dev:
19131 CPUs: 266% 100% 100%
2016-02-07 15:29:25.017039 I  Player(2): FPS:   29.50 Mean: 33894 Std.Dev:
 3016 CPUs: 12% 8% 10%
2016-02-07 15:29:29.000619 I  Player(2): FPS:   29.88 Mean: 33472 Std.Dev:
 1534 CPUs: 8% 8% 9%
2016-02-07 15:29:33.101074 I  Player(2): FPS:   29.02 Mean: 34454 Std.Dev:
 4190 CPUs: 9% 7% 9%
2016-02-07 15:29:37.067977 I  Player(2): FPS:   30.00 Mean: 33332 Std.Dev:
   75 CPUs: 10% 9% 11%
2016-02-07 15:29:41.034890 I  Player(2): FPS:   30.00 Mean: 33332 Std.Dev:
   73 CPUs: 8% 9% 10%
2016-02-07 15:29:45.051846 I  Player(2): FPS:   29.63 Mean: 33753 Std.Dev:
 2633 CPUs: 10% 8% 10%
2016-02-07 15:29:49.118807 I  Player(2): FPS:   29.26 Mean: 34173 Std.Dev:
 3669 CPUs: 9% 8% 9%

And this is what happens when I play the transcoded version of the
problematic video:

2016-02-07 15:30:22.154231 I  Player(2): FPS:   59.51 Mean: 16803 Std.Dev:
 1911 CPUs: 100% 100% 100%
2016-02-07 15:30:26.137813 I  Player(2): FPS:   60.00 Mean: 16665 Std.Dev:
   95 CPUs: 11% 11% 10%
2016-02-07 15:30:30.138094 I  Player(2): FPS:   59.75 Mean: 16735 Std.Dev:
 1079 CPUs: 11% 12% 12%
2016-02-07 15:30:34.138641 I  Player(2): FPS:   59.75 Mean: 16736 Std.Dev:
 1064 CPUs: 10% 12% 13%
2016-02-07 15:30:38.122093 I  Player(2): FPS:   60.01 Mean: 16664 Std.Dev:
   96 CPUs: 11% 11% 11%
2016-02-07 15:30:42.105712 I  Player(2): FPS:   60.00 Mean: 16665 Std.Dev:
   97 CPUs: 11% 12% 13%
2016-02-07 15:30:46.089376 I  Player(2): FPS:   60.00 Mean: 16665 Std.Dev:
   92 CPUs: 12% 11% 16%
2016-02-07 15:30:50.073166 I  Player(2): FPS:   60.00 Mean: 16666 Std.Dev:
  140 CPUs: 15% 12% 12%

It maintains 60 FPS and there are no playback issues at all.  So there
seems to be something about recorded video from this channel which causes a
massive drop in framerate on this particular PC, and whatever this issue
is, it's corrected by mythtranscode.  Any thoughts?  Just a wild guess, but
is it possible the CPU in this PC is missing an instruction set which is
needed for efficiently decoding the video stream from this channel?

The continued help is much appreciated.

For the record, here's the CPU info for this box:

# cat /proc/cpuinfo
processor : 0
vendor_id : AuthenticAMD
cpu family : 16
model : 4
model name : AMD Phenom(tm) II X3 B73 Processor
stepping : 2
microcode : 0x10000db
cpu MHz : 2800.000
cache size : 512 KB
physical id : 0
siblings : 3
core id : 0
cpu cores : 3
apicid : 0
initial apicid : 0
fpu : yes
fpu_exception : yes
cpuid level : 5
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat
pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt pdpe1gb
rdtscp lm 3dnowext 3dnow constant_tsc rep_good nopl nonstop_tsc extd_apicid
pni monitor cx16 popcnt lahf_lm cmp_legacy svm extapic cr8_legacy abm sse4a
misalignsse 3dnowprefetch osvw ibs skinit wdt hw_pstate npt lbrv svm_lock
nrip_save
bogomips : 5585.95
TLB size : 1024 4K pages
clflush size : 64
cache_alignment : 64
address sizes : 48 bits physical, 48 bits virtual
power management: ts ttp tm stc 100mhzsteps hwpstate

processor : 1
vendor_id : AuthenticAMD
cpu family : 16
model : 4
model name : AMD Phenom(tm) II X3 B73 Processor
stepping : 2
microcode : 0x10000db
cpu MHz : 2800.000
cache size : 512 KB
physical id : 0
siblings : 3
core id : 1
cpu cores : 3
apicid : 1
initial apicid : 1
fpu : yes
fpu_exception : yes
cpuid level : 5
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat
pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt pdpe1gb
rdtscp lm 3dnowext 3dnow constant_tsc rep_good nopl nonstop_tsc extd_apicid
pni monitor cx16 popcnt lahf_lm cmp_legacy svm extapic cr8_legacy abm sse4a
misalignsse 3dnowprefetch osvw ibs skinit wdt hw_pstate npt lbrv svm_lock
nrip_save
bogomips : 5585.95
TLB size : 1024 4K pages
clflush size : 64
cache_alignment : 64
address sizes : 48 bits physical, 48 bits virtual
power management: ts ttp tm stc 100mhzsteps hwpstate

processor : 2
vendor_id : AuthenticAMD
cpu family : 16
model : 4
model name : AMD Phenom(tm) II X3 B73 Processor
stepping : 2
microcode : 0x10000db
cpu MHz : 2800.000
cache size : 512 KB
physical id : 0
siblings : 3
core id : 2
cpu cores : 3
apicid : 2
initial apicid : 2
fpu : yes
fpu_exception : yes
cpuid level : 5
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat
pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt pdpe1gb
rdtscp lm 3dnowext 3dnow constant_tsc rep_good nopl nonstop_tsc extd_apicid
pni monitor cx16 popcnt lahf_lm cmp_legacy svm extapic cr8_legacy abm sse4a
misalignsse 3dnowprefetch osvw ibs skinit wdt hw_pstate npt lbrv svm_lock
nrip_save
bogomips : 5585.95
TLB size : 1024 4K pages
clflush size : 64
cache_alignment : 64
address sizes : 48 bits physical, 48 bits virtual
power management: ts ttp tm stc 100mhzsteps hwpstate

    - Dave
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.mythtv.org/pipermail/mythtv-users/attachments/20160207/4ab9c521/attachment.html>