==> /var/log/mythtv/backend.log <==
2008-02-13 16:45:51.624 MainServer::HandleAnnounce Monitor
2008-02-13 16:45:51.628 adding: teevee.elitemag.org as a client (events: 0)
2008-02-13 16:45:53.292 Scheduled 118 items in 2.9 = 0.03 match + 2.87 place
2008-02-13 16:45:53.302 TVRec(5): ASK_RECORDING 5 0 0 0
2008-02-13 16:45:53.362 TVRec(5): Changing from None to RecordingOnly
2008-02-13 16:45:53.367 TVRec(5): HW Tuner: 5->5
2008-02-13 16:45:53.381 DVBChan(5:2) Warning: Your frequency setting (12530180) is out of range. (min/max:950000/2150000)
2008-02-13 16:45:53.409 AutoExpire: CalcParams(): Max required Free Space: 2.0 GB w/freq: 8 min
2008-02-13 16:45:53.409 TVRec(6): ASK_RECORDING 6 0 0 0
2008-02-13 16:45:53.414 Started recording: test "Wed Feb 13 16:44:00 2008": channel 4112 on cardid 5, sourceid 2
2008-02-13 16:45:53.622 TVRec(7): ASK_RECORDING 7 0 0 0
2008-02-13 16:45:53.661 DTVSM(2) Error: Wrong PMT; pmt->pn(114) desired(112)
2008-02-13 16:45:53.706 DTVSM(2) Error: Wrong PMT; pmt->pn(115) desired(112)
2008-02-13 16:45:53.719 DTVSM(2) Error: Wrong PMT; pmt->pn(121) desired(112)
2008-02-13 16:45:53.751 DTVSM(2) Error: Wrong PMT; pmt->pn(127) desired(112)
2008-02-13 16:45:53.783 DTVSM(2) Error: Wrong PMT; pmt->pn(134) desired(112)
2008-02-13 16:45:53.806 DTVSM(2) Error: Wrong PMT; pmt->pn(138) desired(112)
2008-02-13 16:45:53.838 DTVSM(2) Error: Wrong PMT; pmt->pn(148) desired(112)
2008-02-13 16:45:53.839 TVRec(8): ASK_RECORDING 8 0 0 0
2008-02-13 16:45:53.880 DTVSM(2) Error: Wrong PMT; pmt->pn(152) desired(112)
2008-02-13 16:45:53.907 DTVSM(2) Error: Wrong PMT; pmt->pn(307) desired(112)
2008-02-13 16:45:53.939 DTVSM(2) Error: Wrong PMT; pmt->pn(399) desired(112)
2008-02-13 16:45:53.970 DTVSM(2) Error: Wrong PMT; pmt->pn(450) desired(112)
2008-02-13 16:45:53.992 DTVSM(2) Error: Wrong PMT; pmt->pn(953) desired(112)
2008-02-13 16:45:53.992 TVRec(2): ASK_RECORDING 2 0 0 0
2008-02-13 16:45:54.024 DTVSM(2) Error: Wrong PMT; pmt->pn(973) desired(112)
2008-02-13 16:45:54.059 DTVSM(2) Error: Wrong PMT; pmt->pn(974) desired(112)
2008-02-13 16:45:54.083 DTVSM(2) Error: Wrong PMT; pmt->pn(975) desired(112)
2008-02-13 16:45:54.128 DTVSM(2) Error: Wrong PMT; pmt->pn(976) desired(112)

==> /var/log/mythtv/sasc-ng.log <==
Feb 13 16:45:53.629 CSA: Got command(2): C idx: 0 pid: 4898
Feb 13 16:45:53.630 CAM(core.pids): 0: update SID 138 (zero=0 noshift=0)
Feb 13 16:45:53.631 CAM(core.pids): 0: pids typ5=1323
Feb 13 16:45:53.632 CAM(core.pids): 0: SID=138 zero=0 | sid=2/138/0 zero=-/-/- idle=-/-/-
Feb 13 16:45:53.633 CAM(core.pids): 0: found handler for SID 138 (0.2 idle=0 idx=2)
Feb 13 16:45:53.634 CAM(core.pids): 0.2: pids on entry typ5=1322 typ5=1323
Feb 13 16:45:53.635 CAM(core.pids): 0.2: pids after delete typ5=1323
Feb 13 16:45:53.636 CAM(core.pids): 0.2: pids after add typ5=1323
Feb 13 16:45:53.637 CSA: Got command(2): C idx: 0 pid: 4899
Feb 13 16:45:53.705 CAM(core.pids): 0: update SID 138 (zero=0 noshift=1)
Feb 13 16:45:53.642 CAM(core.ecm): 0.2: triggered SID 138/138 idx 2/2 mode 3/0 sync
Feb 13 16:45:53.708 CAM(core.pids): 0: SID=138 zero=0 | sid=2/138/0 zero=-/-/- idle=-/-/-
Feb 13 16:45:53.709 CAM(core.pids): 0: found handler for SID 138 (0.2 idle=0 idx=2)
Feb 13 16:45:53.710 CAM(core.pids): 0.2: pids on entry typ5=1323
Feb 13 16:45:53.711 CAM(core.pids): 0.2: pids after delete
Feb 13 16:45:53.712 CAM(core.pids): 0.2: pids after add
Feb 13 16:45:53.713 CAM(core.ecm): 0.2: is idle now
Feb 13 16:45:53.714 CAM(core.pids): 0: update SID 112 (zero=0 noshift=0)
Feb 13 16:45:53.714 CAM(core.pids): 0: pids typ5=1522 typ5=1523
Feb 13 16:45:53.715 CAM(core.pids): 0: SID=112 zero=0 | sid=-/-/- zero=-/-/- idle=2/138/1
Feb 13 16:45:53.716 CAM(core.pids): 0: found handler for SID 112 (0.2 idle=1 idx=2)
Feb 13 16:45:53.717 CAM(core.ecm): 0.2: setting new SID 112
Feb 13 16:45:53.718 CAM(core.pids): 0.2: pids on entry
Feb 13 16:45:53.719 CAM(core.pids): 0.2: pids after delete
Feb 13 16:45:53.720 CAM(core.pids): 0: descrambling pid 1522 on index 2
Called cSascDvbDevice::SetCaPid
Feb 13 16:45:53.723 CAM: CA_SET_PID failed (Invalid argument)
Feb 13 16:45:53.724 CSA: Got command(2): P idx: 2 pid: 5410
Feb 13 16:45:53.724 CAM(core.pids): 0: descrambling pid 1523 on index 2
Called cSascDvbDevice::SetCaPid
Feb 13 16:45:53.727 CAM: CA_SET_PID failed (Invalid argument)
Feb 13 16:45:53.728 CSA: Got command(2): P idx: 2 pid: 5411
Feb 13 16:45:53.728 CAM(core.pids): 0.2: pids after add typ5=1522 typ5=1523
Feb 13 16:45:53.729 CAM(core.ecm): 0.2: is no longer idle
Feb 13 16:45:53.730 MSG: Got unprocessed message type: 1
Feb 13 16:45:53.769 CAM(core.ecm): 0.2: triggered SID 138/112 idx 2/2 mode 3/0 sync
Feb 13 16:45:53.772 CAM(core.ecm): from cache: system Nagra2 (1234) id 0000 with ecm 2d/8e
Feb 13 16:45:53.773 CAM(core.ecm): 0.2: got CaDescriptors for SID 112 (len=36)
Feb 13 16:45:53.774 CAM(core.ecm): 0.2: descriptor 18 15 e0 4d
Feb 13 16:45:53.775 CAM(core.ecm): 0.2: found 1815 (Nagra2) id 0000 with ecm 4d (new)
Feb 13 16:45:53.775 CAM(core.ecm): 0.2: descriptor 12 34 e0 2d
Feb 13 16:45:53.776 CAM(core.ecm): 0.2: found 1234 (Nagra2) id 0000 with ecm 2d (already present)
Feb 13 16:45:53.777 CAM(core.ecm): 0.2: descriptor 18 01 e0 2d
Feb 13 16:45:53.778 CAM(core.ecm): 0.2: found 1801 (Nagra2) id 0000 with ecm 2d (dup) (new)
Feb 13 16:45:53.779 CAM(core.ecm): 0.2: descriptor 18 15 e0 4d
Feb 13 16:45:53.779 CAM(core.ecm): 0.2: found 1815 (Nagra2) id 0000 with ecm 4d (already present)
Feb 13 16:45:53.780 CAM(core.ecm): 0.2: descriptor 12 34 e0 2d
Feb 13 16:45:53.781 CAM(core.ecm): 0.2: found 1234 (Nagra2) id 0000 with ecm 2d (already present)
Feb 13 16:45:53.782 CAM(core.ecm): 0.2: descriptor 18 01 e0 2d
Feb 13 16:45:53.783 CAM(core.ecm): 0.2: found 1801 (Nagra2) id 0000 with ecm 2d (dup) (already present)
Feb 13 16:45:53.786 CAM(core.ecm): 0.2: try system Nagra2 (1234) id 0000 with ecm 2d (cached) (pri=-10)
Feb 13 16:45:53.842 CAM(nagra.key): missing 2be1 M1 key
Feb 13 16:45:53.843 CAM(core.ecm): system: no key found for N 2BE1 00
Feb 13 16:45:53.844 CAM(core.ecm): system: no key found for N 0101 00
Feb 13 16:45:53.846 CAM(nagra.ecm): provider 0901 capabilities MECM Bx Ex POSTPROCAU
Feb 13 16:45:53.847 CAM(nagra.emu): maprom: new map off=4000 size=18000
Feb 13 16:45:53.848 CAM(nagra.emu): maprom: new map off=8000 size=14000
Feb 13 16:45:53.848 CAM(nagra.emu): maprom: new map off=8000 size=c000
Feb 13 16:45:53.849 CAM(nagra.emu): maprom: new map off=8000 size=4000
Feb 13 16:45:53.850 CAM(nagra.emu): mapeeprom: new map off=3000 size=4800 otp=0080
Feb 13 16:45:53.851 CAM(nagra.emu): mapeeprom: new map off=8000 size=4000 otp=0000
Feb 13 16:45:53.852 CAM(nagra.emu): mapmemhw: new HW map off=0000 size=0020
Feb 13 16:45:53.853 CAM(nagra.emu): 6805: setting breakpoint at 0x537d
Feb 13 16:45:53.854 CAM(nagra.emu): 6805: setting breakpoint at 0x8992
Feb 13 16:45:53.855 CAM(nagra.emu): 6805: setting breakpoint at 0xa822
Feb 13 16:45:53.856 CAM(nagra.emu): 6805: breakpoint at 537d (count=3983)
Feb 13 16:45:53.857 CAM(nagra.emu): 0901: ROM init successfull
Feb 13 16:45:53.858 CAM(nagra.emu): 6805: setting breakpoint at 0x0000
Feb 13 16:45:53.859 CAM(nagra.emu): 6805: setting breakpoint at 0xa822
Feb 13 16:45:53.860 CAM(nagra.emu): 6805: setting breakpoint at 0x3840
Feb 13 16:45:53.861 CAM(nagra.emu): 6805: setting breakpoint at 0x3844
Feb 13 16:45:53.862 CAM(nagra.emu): 6805: setting breakpoint at 0xa23c
Feb 13 16:45:53.862 CAM(nagra.emu): 6805: setting breakpoint at 0xa2e9
Feb 13 16:45:53.863 CAM(nagra.emu): 6805: setting breakpoint at 0x70a6
Feb 13 16:45:53.864 CAM(nagra.emu): 6805: setting breakpoint at 0x7bfe
Feb 13 16:45:53.865 CAM(nagra.emu): 6805: setting breakpoint at 0x7cff
Feb 13 16:45:53.866 CAM(nagra.emu): 6805: setting breakpoint at 0x5f23
Feb 13 16:45:53.866 CAM(nagra.emu): 6805: setting breakpoint at 0x5f27
Feb 13 16:45:53.867 CAM(nagra.emu): 6805: setting breakpoint at 0x5f5e
Feb 13 16:45:53.868 CAM(nagra.emu): 6805: breakpoint at 3840 (count=44)
Feb 13 16:45:53.869 CAM(nagra.map): 0101: calling function 02
Feb 13 16:45:53.870 CAM(nagra.emu): n2timer: started latch=ff div=4 cycles=ff ctrl=143
Feb 13 16:45:53.871 CAM(nagra.emu): n2timer: started latch=ff div=16 cycles=ff ctrl=14b
Feb 13 16:45:53.872 CAM(nagra.emu): 6805: breakpoint at 3840 (count=20)
Feb 13 16:45:53.873 CAM(nagra.map): 0101: calling function 57
Feb 13 16:45:53.873 CAM(nagra.map): auxsrv: AUXserver is disabled!
Feb 13 16:45:53.880 CAM(nagra.emu): n2timer: stopped cycles=fb ctrl=41
Feb 13 16:45:53.881 CAM(nagra.emu): n2timer: stopped cycles=fe ctrl=49
Feb 13 16:45:53.884 CAM(nagra.emu): 6805: breakpoint at 0000 (count=371)
Feb 13 16:45:53.896 CAM(nagra.ecm): MECM: waiting for sync
Feb 13 16:45:53.897 CAM(core.ecm): system: using key N 0901 00 B013...
Called cSascDvbDevice::SetCaDescr
Feb 13 16:45:54.247 CSA: Got command(2): N idx: 2 pid: 0
Called cSascDvbDevice::SetCaDescr
Feb 13 16:45:54.250 CSA: Got command(2): N idx: 2 pid: 0
Feb 13 16:45:54.251 CAM(core.ecm): 0.2: correct key found

==> /var/log/mythtv/backend.log <==
2008-02-13 16:45:54.623 AutoExpire: CalcParams(): Max required Free Space: 2.0 GB w/freq: 8 min

==> /var/log/mythtv/sasc-ng.log <==
Feb 13 16:45:56.309 CAM(nagra.emu): 6805: setting breakpoint at 0x0000
Feb 13 16:45:56.311 CAM(nagra.emu): 6805: setting breakpoint at 0xa822
Feb 13 16:45:56.312 CAM(nagra.emu): 6805: setting breakpoint at 0x3840
Feb 13 16:45:56.313 CAM(nagra.emu): 6805: setting breakpoint at 0x3844
Feb 13 16:45:56.313 CAM(nagra.emu): 6805: setting breakpoint at 0xa23c
Feb 13 16:45:56.314 CAM(nagra.emu): 6805: setting breakpoint at 0xa2e9
Feb 13 16:45:56.315 CAM(nagra.emu): 6805: setting breakpoint at 0x70a6
Feb 13 16:45:56.316 CAM(nagra.emu): 6805: setting breakpoint at 0x7bfe
Feb 13 16:45:56.317 CAM(nagra.emu): 6805: setting breakpoint at 0x7cff
Feb 13 16:45:56.318 CAM(nagra.emu): 6805: setting breakpoint at 0x5f23
Feb 13 16:45:56.318 CAM(nagra.emu): 6805: setting breakpoint at 0x5f27
Feb 13 16:45:56.319 CAM(nagra.emu): 6805: setting breakpoint at 0x5f5e
Feb 13 16:45:56.320 CAM(nagra.emu): 6805: breakpoint at 3840 (count=44)
Feb 13 16:45:56.321 CAM(nagra.map): 0101: calling function 02
Feb 13 16:45:56.322 CAM(nagra.emu): n2timer: started latch=ff div=4 cycles=ff ctrl=143
Feb 13 16:45:56.323 CAM(nagra.emu): n2timer: started latch=ff div=16 cycles=ff ctrl=14b
Feb 13 16:45:56.324 CAM(nagra.emu): 6805: breakpoint at 3840 (count=20)
Feb 13 16:45:56.324 CAM(nagra.map): 0101: calling function 57
Feb 13 16:45:56.325 CAM(nagra.map): auxsrv: AUXserver is disabled!
Feb 13 16:45:56.332 CAM(nagra.emu): n2timer: stopped cycles=fb ctrl=41
Feb 13 16:45:56.333 CAM(nagra.emu): n2timer: stopped cycles=fe ctrl=49
Feb 13 16:45:56.334 CAM(nagra.emu): 6805: breakpoint at 0000 (count=371)
Feb 13 16:45:56.335 CAM(nagra.ecm): MECM: waiting for sync
Feb 13 16:45:56.420 MSG: Got unprocessed message type: 1
Feb 13 16:45:56.422 MSG: Got unprocessed message type: 1
Called cSascDvbDevice::SetCaDescr
Feb 13 16:45:56.711 CSA: Got command(2): N idx: 2 pid: 0
Called cSascDvbDevice::SetCaDescr
Feb 13 16:45:56.714 CSA: Got command(2): N idx: 2 pid: 0