Device power saving feature

  Could you attach (or, better, upload to pastebin.com) the whole log
file. Are you running vdr with --log=3? I need to see 'idle timer' debug
messages and some other debug stuff. Could you also apply this change

--

Thanks for testing.

Best,
Sergey Chernyavskiy.

On Mon, May 30, 2016 at 09:59:46AM +0100, Richard F wrote:
> Thanks - I built it and and have had it running for about 24 hours:
> 
> A couple of observations:
> I'm seeing this about every 30 - 60 mins as expected, but the timeout
> seems to be short - not the PowerdownTimeoutM (I assume minutes?) set at
> 15 in the config file
> 
> ...
>
> I haven't had a chance to take the server down to insert the power
> monitor yet, but will do so at convenient time in the next few days
> 
> Thanks
> Richard
> 
> 
> On 27/05/2016 14:51, glenvt18 wrote:
> > Yes, sure. The patch against VDR-2.2.0:
> > http://pastebin.com/D4VQd1rG
> >
> > While testing set VDR log level to 3 (--log=3) and use this helper
> > script to monitor your frontends:
> > http://pastebin.com/uW4NW0rZ
> >
> > Don't forget to enable power saving in the Setup->LNB menu.
> >
> > If you don't have sudo (you're not on Debian or Ubuntu), remove it and
> > run the script as root. It would be great if you could measure the
> > power consumption of you tuners (at least the USB one).
> >
> > Best,
> > Sergey Chernyavskiy.
> >
> > On Fri, May 27, 2016 at 09:59:06AM +0100, Richard F wrote:
> >> I'd like to give it a go on DVB & DVBT-2 tuners (1 PCI, 1 USB)
> >> Would you be kind enough to post a version for VDR2.20 or advise changes
> >> necessary?
> >>
> >> Thanks
> >> Richard
> >>
> >>
> >> On 26/05/2016 18:44, glenvt18 wrote:
> >>> For about a month now. Tested with 3 different DVB-S/S2 tuners with
> >>> VDR 2.3.1 and VDR 2.2.0 (requires minor changes to the patch) - rock
> >>> solid.
> >>> I don't have VPS, so I can't test it. The same is about DVB-T/C
> >>> tuners. After all, if something doesn't work this feature can be
> >>> disabled (and it is disabled by default),
> >>>
> >>
> >> _______________________________________________
> >> vdr mailing list
> >> vdr@linuxtv.org
> >> http://www.linuxtv.org/cgi-bin/mailman/listinfo/vdr
> >
> 
> 
> _______________________________________________
> vdr mailing list
> vdr@linuxtv.org
> http://www.linuxtv.org/cgi-bin/mailman/listinfo/vdr
  

OK Sergey, I've posted a log with your patch applied + log level 3 -
about 3 hours worth
There was a recording 16:15 to 16:45, other than that idle
I can run it for longer if you need it, though it's creating a fair bit
of log.
I seem to get a lot of erroneous EPGsearch results at level 3, not sure why.
http://pastebin.com/8DbYQdTX

Let me know what it tells you
Thanks
Richard


On 30/05/2016 15:19, glenvt18 wrote:
> Could you attach (or, better, upload to pastebin.com) the whole log
> file. Are you running vdr with --log=3? I need to see 'idle timer' debug
> messages and some other debug stuff. Could you also apply this change
>
> diff --git a/eitscan.c b/eitscan.c
> index 3899e00..b1c8c13 100644
> --- a/eitscan.c
> +++ b/eitscan.c
> @@ -159,7 +159,7 @@ void cEITScanner::Process(void)
>                                             Skins.Message(mtInfo, tr("Starting EPG scan"));
>                                             }
>                                          }
> -                                     //dsyslog("EIT scan: device %d  source  %-8s tp %5d", Device->DeviceNumber() + 1, *cSource::ToString(Channel->Source()), Channel->Transponder());
> +                                     dsyslog("EIT scan: device %d  source  %-8s tp %5d", Device->DeviceNumber() + 1, *cSource::ToString(Channel->Source()), Channel->Transponder());
>                                       if (lastActivity == 0)
>                                          // forced scan - set idle timer for each channel switch;
>                                          // this prevents powering down while scanning a transponder
> --
>
> Thanks for testing.
>
> Best,
> Sergey Chernyavskiy.
  

From what I can see, everything works as expected. You can safely lessen
the power-down timeout to 3 minutes. This will be enough for EPG scan as
you have at most 8 transponders/multiplexes which gives 8 * 1/3 = 2m40s
- see 'EIT scan ...' messages.

As for those small intervals of activity you mentioned, it happens
because some 'preparation' work is done before a timer starts.  VDR
tries to switch to the timer's transponder and gather EPG data. For a
VPS timer this begins within VPS margin and an hour before the timer
start time.  For a non-VPS timer it begins one minute before the timer
start time.  I've added 30 seconds to the occupied timeout (see my
cDevice::SetOccupied() comment) to avoid frequent on/off switching. So,
you're likely to see 38-second (or, sometimes, a bit more) periods of
activity. If you still worry about it, keep you server idle for 2 hours
before a nearest VPS timer starts and paste the log.

I've removed 'sudo' from the monitor script:
http://pastebin.com/8JDffAXF

Run it as user 'vdr' for some time. It will draw you a nice 'map' of
your devices' activity.

If you notice channel switch failures, let me know.

Do your tuners get warm when active?

Thanks again for testing.

Best,
Sergey Chernyavskiy.

On Tue, May 31, 2016 at 08:43:01PM +0100, Richard F wrote:
> OK Sergey, I've posted a log with your patch applied + log level 3 -
> about 3 hours worth There was a recording 16:15 to 16:45, other than
> that idle I can run it for longer if you need it, though it's creating
> a fair bit of log.  I seem to get a lot of erroneous EPGsearch results
> at level 3, not sure why.  http://pastebin.com/8DbYQdTX
> 
> Let me know what it tells you Thanks Richard
> 
> 
> On 30/05/2016 15:19, glenvt18 wrote:
> > Could you attach (or, better, upload to pastebin.com) the whole log
> > file. Are you running vdr with --log=3? I need to see 'idle timer'
> > debug messages and some other debug stuff. Could you also apply this
> > change
> >
> > diff --git a/eitscan.c b/eitscan.c index 3899e00..b1c8c13 100644 ---
> > a/eitscan.c +++ b/eitscan.c @@ -159,7 +159,7 @@ void
> > cEITScanner::Process(void) Skins.Message(mtInfo, tr("Starting EPG
> > scan")); } } -                                     //dsyslog("EIT
> > scan: device %d  source  %-8s tp %5d", Device->DeviceNumber() + 1,
> > *cSource::ToString(Channel->Source()), Channel->Transponder()); +
> > dsyslog("EIT scan: device %d  source  %-8s tp %5d",
> > Device->DeviceNumber() + 1, *cSource::ToString(Channel->Source()),
> > Channel->Transponder()); if (lastActivity == 0) // forced scan - set
> > idle timer for each channel switch; // this prevents powering down
> > while scanning a transponder --
> >
> > Thanks for testing.
> >
> > Best, Sergey Chernyavskiy.
> 
> 
> 
> _______________________________________________ vdr mailing list
> vdr@linuxtv.org http://www.linuxtv.org/cgi-bin/mailman/listinfo/vdr
  

On 1/06/2016 03:49, glenvt18 wrote:
> >From what I can see, everything works as expected. You can safely lessen
> the power-down timeout to 3 minutes. This will be enough for EPG scan as
> you have at most 8 transponders/multiplexes which gives 8 * 1/3 = 2m40s
> - see 'EIT scan ...' messages.
I reduced it to 5 mins to give it some margin
> As for those small intervals of activity you mentioned, it happens
> because some 'preparation' work is done before a timer starts.  VDR
> tries to switch to the timer's transponder and gather EPG data. For a
> VPS timer this begins within VPS margin and an hour before the timer
> start time.  For a non-VPS timer it begins one minute before the timer
> start time.  I've added 30 seconds to the occupied timeout (see my
> cDevice::SetOccupied() comment) to avoid frequent on/off switching. So,
> you're likely to see 38-second (or, sometimes, a bit more) periods of
> activity. If you still worry about it, keep you server idle for 2 hours
> before a nearest VPS timer starts and paste the log.
OK, I'll keep an eye on it. No adverse effects yet - good work, thanks.

I'm doing some other testing and stuff atm so want to keep the server up -
I'll possibly take it down at the weekend, make some power measurements
and post them
> I've removed 'sudo' from the monitor script:
> http://pastebin.com/8JDffAXF
>
> Run it as user 'vdr' for some time. It will draw you a nice 'map' of
> your devices' activity.
>
> If you notice channel switch failures, let me know.
>
> Do your tuners get warm when active?
Yes, the TV tuners always did run warm, and I recall that when VDR is
stopped the power is several watts lower (not because of VDR/CPU load
itself according to stats, it's when the tuners go active - hence my
interest in your patch).

As the server also runs the home automation/lights/heating/security,
CCTV, mail server, and file storage/Owncloud it's not an option to shut
it down when not recording, and I have t choose when to take it down !

Richard
>
> Thanks again for testing.
>
> Best,
> Sergey Chernyavskiy.
>
> On Tue, May 31, 2016 at 08:43:01PM +0100, Richard F wrote:
>> OK Sergey, I've posted a log with your patch applied + log level 3 -
>> about 3 hours worth There was a recording 16:15 to 16:45, other than
>> that idle I can run it for longer if you need it, though it's creating
>> a fair bit of log.  I seem to get a lot of erroneous EPGsearch results
>> at level 3, not sure why.  http://pastebin.com/8DbYQdTX
>>
>> Let me know what it tells you Thanks Richard
>>
>>
>> On 30/05/2016 15:19, glenvt18 wrote:
>>> Could you attach (or, better, upload to pastebin.com) the whole log
>>> file. Are you running vdr with --log=3? I need to see 'idle timer'
>>> debug messages and some other debug stuff. Could you also apply this
>>> change
>>>
>>> diff --git a/eitscan.c b/eitscan.c index 3899e00..b1c8c13 100644 ---
>>> a/eitscan.c +++ b/eitscan.c @@ -159,7 +159,7 @@ void
>>> cEITScanner::Process(void) Skins.Message(mtInfo, tr("Starting EPG
>>> scan")); } } -                                     //dsyslog("EIT
>>> scan: device %d  source  %-8s tp %5d", Device->DeviceNumber() + 1,
>>> *cSource::ToString(Channel->Source()), Channel->Transponder()); +
>>> dsyslog("EIT scan: device %d  source  %-8s tp %5d",
>>> Device->DeviceNumber() + 1, *cSource::ToString(Channel->Source()),
>>> Channel->Transponder()); if (lastActivity == 0) // forced scan - set
>>> idle timer for each channel switch; // this prevents powering down
>>> while scanning a transponder --
>>>
>>> Thanks for testing.
>>>
>>> Best, Sergey Chernyavskiy.
>>
>>
>> _______________________________________________ vdr mailing list
>> vdr@linuxtv.org http://www.linuxtv.org/cgi-bin/mailman/listinfo/vdr
>
  

> As the server also runs the home automation/lights/heating/security,
> CCTV, mail server, and file storage/Owncloud ...

That's the main purpose of this feature. You don't have to switch off
your tuners physically, close your connections or put your server into
sleep (and ARM devices usually don't have a sleep mode at all). You can
stream your recordings, watch movies and do other stuff with your server
and, at the same time, keep your tuners cold.

> OK, I'll keep an eye on it. No adverse effects yet - good work, thanks.

I've modified the monitor script:
http://pastebin.com/DR4gUdZR

Now it prints timestamps and it's output can be searched and grep-ed.
Run it with '|tee' for several days.

Best,
Sergey Chernyavskiy.

On Thu, Jun 02, 2016 at 03:35:49PM +0100, Richard F wrote:
> On 1/06/2016 03:49, glenvt18 wrote:
> > >From what I can see, everything works as expected. You can safely lessen
> > the power-down timeout to 3 minutes. This will be enough for EPG scan as
> > you have at most 8 transponders/multiplexes which gives 8 * 1/3 = 2m40s
> > - see 'EIT scan ...' messages.
> I reduced it to 5 mins to give it some margin
> > As for those small intervals of activity you mentioned, it happens
> > because some 'preparation' work is done before a timer starts.  VDR
> > tries to switch to the timer's transponder and gather EPG data. For a
> > VPS timer this begins within VPS margin and an hour before the timer
> > start time.  For a non-VPS timer it begins one minute before the timer
> > start time.  I've added 30 seconds to the occupied timeout (see my
> > cDevice::SetOccupied() comment) to avoid frequent on/off switching. So,
> > you're likely to see 38-second (or, sometimes, a bit more) periods of
> > activity. If you still worry about it, keep you server idle for 2 hours
> > before a nearest VPS timer starts and paste the log.
> OK, I'll keep an eye on it. No adverse effects yet - good work, thanks.
> 
> I'm doing some other testing and stuff atm so want to keep the server up -
> I'll possibly take it down at the weekend, make some power measurements
> and post them
> > I've removed 'sudo' from the monitor script:
> > http://pastebin.com/8JDffAXF
> >
> > Run it as user 'vdr' for some time. It will draw you a nice 'map' of
> > your devices' activity.
> >
> > If you notice channel switch failures, let me know.
> >
> > Do your tuners get warm when active?
> Yes, the TV tuners always did run warm, and I recall that when VDR is
> stopped the power is several watts lower (not because of VDR/CPU load
> itself according to stats, it's when the tuners go active - hence my
> interest in your patch).
> 
> As the server also runs the home automation/lights/heating/security,
> CCTV, mail server, and file storage/Owncloud it's not an option to shut
> it down when not recording, and I have t choose when to take it down !
> 
> Richard
> >
> > Thanks again for testing.
> >
> > Best,
> > Sergey Chernyavskiy.
> >
> > On Tue, May 31, 2016 at 08:43:01PM +0100, Richard F wrote:
> >> OK Sergey, I've posted a log with your patch applied + log level 3 -
> >> about 3 hours worth There was a recording 16:15 to 16:45, other than
> >> that idle I can run it for longer if you need it, though it's creating
> >> a fair bit of log.  I seem to get a lot of erroneous EPGsearch results
> >> at level 3, not sure why.  http://pastebin.com/8DbYQdTX
> >>
> >> Let me know what it tells you Thanks Richard
> >>
> >>
> >> On 30/05/2016 15:19, glenvt18 wrote:
> >>> Could you attach (or, better, upload to pastebin.com) the whole log
> >>> file. Are you running vdr with --log=3? I need to see 'idle timer'
> >>> debug messages and some other debug stuff. Could you also apply this
> >>> change
> >>>
> >>> diff --git a/eitscan.c b/eitscan.c index 3899e00..b1c8c13 100644 ---
> >>> a/eitscan.c +++ b/eitscan.c @@ -159,7 +159,7 @@ void
> >>> cEITScanner::Process(void) Skins.Message(mtInfo, tr("Starting EPG
> >>> scan")); } } -                                     //dsyslog("EIT
> >>> scan: device %d  source  %-8s tp %5d", Device->DeviceNumber() + 1,
> >>> *cSource::ToString(Channel->Source()), Channel->Transponder()); +
> >>> dsyslog("EIT scan: device %d  source  %-8s tp %5d",
> >>> Device->DeviceNumber() + 1, *cSource::ToString(Channel->Source()),
> >>> Channel->Transponder()); if (lastActivity == 0) // forced scan - set
> >>> idle timer for each channel switch; // this prevents powering down
> >>> while scanning a transponder --
> >>>
> >>> Thanks for testing.
> >>>
> >>> Best, Sergey Chernyavskiy.
> >>
> >>
> >> _______________________________________________ vdr mailing list
> >> vdr@linuxtv.org http://www.linuxtv.org/cgi-bin/mailman/listinfo/vdr
> >
> 
> 
> _______________________________________________
> vdr mailing list
> vdr@linuxtv.org
> http://www.linuxtv.org/cgi-bin/mailman/listinfo/vdr
  

Sergey,

I took down the server at the weekend to install a newly built kernel
and insert the power monitor.

47W  - All services running at idle, tuner power saving disabled
44W - All services running at idle, tuner power saving enabled

As tuners are powered down most of the time, that's a handy 6% average
saving.

The hardware is an HP 8300CMT with high efficiency PSU, G2130 Ivy bridge
CPU and a 3 x 2T RAID + KMC4400R for CCTV video capture,  the tuners are
PCTV Nanostick 290e for HD/SD (USB2) and an old Leadtek DTV1000 T (PCI)
for SD - both of which are super-reliable BTW.

Obviously other tuners will vary, and if the PSU isn't the efficient 90%
one like this, the savings will be marginally more.

Richard


On 2/06/2016 17:15, glenvt18 wrote:
>> As the server also runs the home automation/lights/heating/security,
>> CCTV, mail server, and file storage/Owncloud ...
> That's the main purpose of this feature. You don't have to switch off
> your tuners physically, close your connections or put your server into
> sleep (and ARM devices usually don't have a sleep mode at all). You can
> stream your recordings, watch movies and do other stuff with your server
> and, at the same time, keep your tuners cold.
>
>> OK, I'll keep an eye on it. No adverse effects yet - good work, thanks.
> I've modified the monitor script:
> http://pastebin.com/DR4gUdZR
>
> Now it prints timestamps and it's output can be searched and grep-ed.
> Run it with '|tee' for several days.
>
> Best,
> Sergey Chernyavskiy.
>
  

Hi Richard,

Unlike DVB-S/S2 tuners your DVB-T/T2 ones don't have to supply power to
a LNB (which draws at least 2W). So, your 3W drop can be considered as
"normal". For your USB stick even 1W saving can be helpful.

Thanks again for testing.

Sergey.

On Mon, Jun 06, 2016 at 11:21:24AM +0100, Richard F wrote:
> Sergey,
> 
> I took down the server at the weekend to install a newly built kernel
> and insert the power monitor.
> 
> 47W  - All services running at idle, tuner power saving disabled
> 44W - All services running at idle, tuner power saving enabled
> 
> As tuners are powered down most of the time, that's a handy 6% average
> saving.
> 
> The hardware is an HP 8300CMT with high efficiency PSU, G2130 Ivy bridge
> CPU and a 3 x 2T RAID + KMC4400R for CCTV video capture,  the tuners are
> PCTV Nanostick 290e for HD/SD (USB2) and an old Leadtek DTV1000 T (PCI)
> for SD - both of which are super-reliable BTW.
> 
> Obviously other tuners will vary, and if the PSU isn't the efficient 90%
> one like this, the savings will be marginally more.
> 
> Richard
> 
> 
> On 2/06/2016 17:15, glenvt18 wrote:
> >> As the server also runs the home automation/lights/heating/security,
> >> CCTV, mail server, and file storage/Owncloud ...
> > That's the main purpose of this feature. You don't have to switch off
> > your tuners physically, close your connections or put your server into
> > sleep (and ARM devices usually don't have a sleep mode at all). You can
> > stream your recordings, watch movies and do other stuff with your server
> > and, at the same time, keep your tuners cold.
> >
> >> OK, I'll keep an eye on it. No adverse effects yet - good work, thanks.
> > I've modified the monitor script:
> > http://pastebin.com/DR4gUdZR
> >
> > Now it prints timestamps and it's output can be searched and grep-ed.
> > Run it with '|tee' for several days.
> >
> > Best,
> > Sergey Chernyavskiy.
> >
> 
> 
> _______________________________________________
> vdr mailing list
> vdr@linuxtv.org
> http://www.linuxtv.org/cgi-bin/mailman/listinfo/vdr
  

I'm happy with just a modest power saving.

Put in context, on my system, 3Wh ~ 25 mins SD content transcoding to
H264/AAC = 30-40% disk space reduction with no noticeable loss of
quality.  So ~70Wh saving / day pays for ongoing SD recording
compression and multi-TB historical library compression in about 3
months. I free up a 1TB or so of RAID :-)

Thanks
Richard


On 7/06/2016 14:45, glenvt18 wrote:
> Hi Richard,
>
> Unlike DVB-S/S2 tuners your DVB-T/T2 ones don't have to supply power to
> a LNB (which draws at least 2W). So, your 3W drop can be considered as
> "normal". For your USB stick even 1W saving can be helpful.
>
> Thanks again for testing.
>
> Sergey.
  

That's cool:)

On Wed, Jun 08, 2016 at 05:23:43PM +0100, Richard F wrote:
> I'm happy with just a modest power saving.
> 
> Put in context, on my system, 3Wh ~ 25 mins SD content transcoding to
> H264/AAC = 30-40% disk space reduction with no noticeable loss of
> quality.  So ~70Wh saving / day pays for ongoing SD recording
> compression and multi-TB historical library compression in about 3
> months. I free up a 1TB or so of RAID :-)
> 
> Thanks
> Richard
> 
> 
> On 7/06/2016 14:45, glenvt18 wrote:
> > Hi Richard,
> >
> > Unlike DVB-S/S2 tuners your DVB-T/T2 ones don't have to supply power to
> > a LNB (which draws at least 2W). So, your 3W drop can be considered as
> > "normal". For your USB stick even 1W saving can be helpful.
> >
> > Thanks again for testing.
> >
> > Sergey.
> 
> 
> _______________________________________________
> vdr mailing list
> vdr@linuxtv.org
> http://www.linuxtv.org/cgi-bin/mailman/listinfo/vdr
  

Hi,

I've tried this as well now.

I have two Cine S2 dual-tuner cards (an older 5.5 running on ngene driver
and a 6.5 running with the ddbridge driver) attached to a cascadable
multiswitch.

The VDR (2.2) runs as a headless server with the vnsi plugin to allow to
connect Kodi clients to the VDR.

With all adapters active, I see a power consumption of about 50W. When
your power-saving patch kicks in, this is reduced by about 7W to 43W.

So far this seems to work fine. Thanks for this patch!

+1 for including this into vanilla VDR.

bye,

Tobias
  

Hi Sergey,

My VDR setup started having a bit of a fit last night, and has been doing this for the last 8 hours (no changes my end)
Before I restart VDR, any tests I can do to diagnose?

It seems to have started after a live stream (Kodi/VNSI) + a recording stopped 
- here's the VDR-related log from where the connection started to where the problem seemed to start
It may be that the VNSI plugin is keeping the receiver active ?
(the VNSI-Error: cxSocket::read   error occurs 2 or 3 times a day - not unusual, nor is any other log entry)


Jun 24 01:12:59 ha-server vdr: [8690] loading /etc/vdr/plugins/vnsiserver/allowed_hosts.conf
Jun 24 01:12:59 ha-server vdr: [8690] VNSI: Client with ID 75 connected: 10.0.0.90:52606
Jun 24 01:12:59 ha-server vdr: [15789] VNSI: Welcome client 'XBMC Media Center' with protocol version '8'
Jun 24 01:12:59 ha-server vdr: [15789] VNSI: LiveStreamer::Close - close
Jun 24 01:12:59 ha-server vdr: [15789] VNSI: close video input ...
Jun 24 01:12:59 ha-server vdr: [15789] VNSI: Successfully found following device: 0x91cef0 (1) for receiving
Jun 24 01:12:59 ha-server vdr: [15789] dvb tuner: power-up - opening frontend 0/0
Jun 24 01:12:59 ha-server vdr: [15789] VNSI: activate live receiver: 1, pmt change: 1
Jun 24 01:12:59 ha-server vdr: [15789] VNSI: Successfully switched to channel 1 - BBC ONE Lon
Jun 24 01:12:59 ha-server vdr: [15789] VNSI: Started streaming of channel BBC ONE Lon (timeout 5 seconds)
Jun 24 01:12:59 ha-server vdr: [15793] VNSI: Created stream for pid=101 and type=7
Jun 24 01:12:59 ha-server vdr: [15793] VNSI: Created stream for pid=102 and type=2
Jun 24 01:12:59 ha-server vdr: [15793] VNSI: Created stream for pid=106 and type=2
Jun 24 01:12:59 ha-server vdr: [15793] VNSI: Created stream for pid=105 and type=9
Jun 24 01:13:00 ha-server vdr: [8686] channel 3 (BBC TWO) event Fri 24.06.2016 01:05-02:05 (VPS: 24.06. 01:05) 'The Big C & Me' status 4
Jun 24 01:13:05 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
Jun 24 01:13:10 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
Jun 24 01:13:46 ha-server vdr: [15789] VNSI-Error: cxSocket::read(fd=18): read() error at 0/4
Jun 24 01:13:46 ha-server vdr: [15793] VNSI: exit streamer thread
Jun 24 01:13:46 ha-server vdr: [15789] VNSI: LiveStreamer::Close - close
Jun 24 01:13:46 ha-server vdr: [15789] VNSI: close video input ...
Jun 24 01:13:46 ha-server vdr: [15789] VNSI: activate live receiver: 0, pmt change: 0
Jun 24 01:13:46 ha-server vdr: [15789] VNSI: close video input ...
Jun 24 01:13:46 ha-server vdr: [8692] VNSI: Client with ID 75 seems to be disconnected, removing from client list
Jun 24 01:13:49 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
Jun 24 01:13:51 ha-server vdr: [8690] loading /etc/vdr/plugins/vnsiserver/allowed_hosts.conf
Jun 24 01:13:51 ha-server vdr: [8690] VNSI: Client with ID 76 connected: 10.0.0.90:52610
Jun 24 01:13:51 ha-server vdr: [15824] VNSI: Welcome client 'XBMC Media Center' with protocol version '8'
Jun 24 01:13:51 ha-server vdr: [15824] VNSI: LiveStreamer::Close - close
Jun 24 01:13:51 ha-server vdr: [15824] VNSI: close video input ...
Jun 24 01:13:51 ha-server vdr: [15824] VNSI: Successfully found following device: 0x91cef0 (1) for receiving
Jun 24 01:13:51 ha-server vdr: [15824] VNSI: activate live receiver: 1, pmt change: 1
Jun 24 01:13:51 ha-server vdr: [15824] VNSI: Successfully switched to channel 1 - BBC ONE Lon
Jun 24 01:13:51 ha-server vdr: [15824] VNSI: Started streaming of channel BBC ONE Lon (timeout 5 seconds)
Jun 24 01:13:52 ha-server vdr: [15826] VNSI: Created stream for pid=101 and type=7
Jun 24 01:13:52 ha-server vdr: [15826] VNSI: Created stream for pid=102 and type=2
Jun 24 01:13:52 ha-server vdr: [15826] VNSI: Created stream for pid=106 and type=2
Jun 24 01:13:52 ha-server vdr: [15826] VNSI: Created stream for pid=105 and type=9
Jun 24 01:13:54 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
Jun 24 01:13:59 ha-server vdr: [7056] VNSI-Error: cxSocket::read(fd=6): read() error at 0/4
Jun 24 01:13:59 ha-server vdr: [8692] VNSI: Client with ID 72 seems to be disconnected, removing from client list
Jun 24 01:14:33 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
Jun 24 01:14:38 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
Jun 24 01:15:17 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
Jun 24 01:15:22 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
Jun 24 01:16:01 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
Jun 24 01:16:06 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
Jun 24 01:16:43 ha-server vdr: [15824] VNSI-Error: cxSocket::read(fd=8): read() error at 0/4
Jun 24 01:16:43 ha-server vdr: [15826] VNSI: exit streamer thread
Jun 24 01:16:43 ha-server vdr: [15824] VNSI: LiveStreamer::Close - close
Jun 24 01:16:43 ha-server vdr: [15824] VNSI: close video input ...
Jun 24 01:16:43 ha-server vdr: [15824] VNSI: activate live receiver: 0, pmt change: 0
Jun 24 01:16:43 ha-server vdr: [15824] VNSI: close video input ...
Jun 24 01:16:43 ha-server vdr: [8692] VNSI: Client with ID 76 seems to be disconnected, removing from client list
Jun 24 01:16:45 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
Jun 24 01:16:50 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
Jun 24 01:16:56 ha-server vdr: [8690] loading /etc/vdr/plugins/vnsiserver/allowed_hosts.conf
Jun 24 01:16:56 ha-server vdr: [8690] VNSI: Client with ID 77 connected: 10.0.0.90:52614
Jun 24 01:16:56 ha-server vdr: [16255] VNSI: Welcome client 'XBMC Media Center' with protocol version '8'
Jun 24 01:16:56 ha-server vdr: [16255] VNSI: LiveStreamer::Close - close
Jun 24 01:16:56 ha-server vdr: [16255] VNSI: close video input ...
Jun 24 01:16:56 ha-server vdr: [16255] VNSI: Successfully found following device: 0x91cef0 (1) for receiving
Jun 24 01:16:56 ha-server vdr: [16255] VNSI: activate live receiver: 1, pmt change: 1
Jun 24 01:16:56 ha-server vdr: [16255] VNSI: Successfully switched to channel 20 - ITV
Jun 24 01:16:56 ha-server vdr: [16255] VNSI: Started streaming of channel ITV (timeout 5 seconds)
Jun 24 01:16:57 ha-server vdr: [16257] VNSI: Created stream for pid=1701 and type=7
Jun 24 01:16:57 ha-server vdr: [16257] VNSI: Created stream for pid=1702 and type=2
Jun 24 01:16:57 ha-server vdr: [16257] VNSI: Created stream for pid=1703 and type=2
Jun 24 01:16:57 ha-server vdr: [16257] VNSI: Created stream for pid=1731 and type=9
Jun 24 01:17:29 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
Jun 24 01:35:42 ha-server vdr: [8686] channel 45 (Film4) event Fri 24.06.2016 01:35-03:50 (VPS: 24.06. 01:35) 'Greenberg' status 4
Jun 24 01:35:45 ha-server vdr: [8679] timer 1 (45 1635-1850 VPS '-Films~The Spy Who Came In from the Cold~2016.06.23-16:35-Thu') set to no event
Jun 24 01:36:11 ha-server vdr: [8679] deleting timer 1 (45 1635-1850 VPS '-Films~The Spy Who Came In from the Cold~2016.06.23-16:35-Thu')
Jun 24 01:36:11 ha-server vdr: [8692] VNSI: Timers state changed (71)
Jun 24 01:36:11 ha-server vdr: [8692] VNSI: Requesting clients to reload timers
Jun 24 02:15:32 ha-server vdr: [16255] VNSI-Error: cxSocket::read(fd=23): read() error at 0/4
Jun 24 02:15:33 ha-server vdr: [16257] VNSI: exit streamer thread
Jun 24 02:15:33 ha-server vdr: [16255] VNSI: LiveStreamer::Close - close
Jun 24 02:15:33 ha-server vdr: [16255] VNSI: close video input ...
Jun 24 02:15:33 ha-server vdr: [16255] VNSI: activate live receiver: 0, pmt change: 0
Jun 24 02:15:33 ha-server vdr: [16255] VNSI: close video input ...
Jun 24 02:15:33 ha-server vdr: [8692] VNSI: Client with ID 77 seems to be disconnected, removing from client list
Jun 24 02:15:40 ha-server vdr: [15117] VNSI: cxSocket::read(fd=17): eof, connection closed
Jun 24 02:15:40 ha-server vdr: [8692] VNSI: Client with ID 74 seems to be disconnected, removing from client list
Jun 24 02:20:34 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 0/0
Jun 24 02:20:38 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
Jun 24 02:21:17 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
Jun 24 02:21:22 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
Jun 24 02:22:01 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
Jun 24 02:22:06 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
.....

Jun 25 09:50:17 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
Jun 25 09:50:22 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
Jun 25 09:51:01 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
Jun 25 09:51:06 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
Jun 25 09:51:45 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
Jun 25 09:51:50 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
Jun 25 09:52:29 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0

Thanks
Richard


On 7/06/2016 14:45, glenvt18 wrote:
> Hi Richard,
>
> Unlike DVB-S/S2 tuners your DVB-T/T2 ones don't have to supply power to
> a LNB (which draws at least 2W). So, your 3W drop can be considered as
> "normal". For your USB stick even 1W saving can be helpful.
>
> Thanks again for testing.
>
> Sergey.
>
> On Mon, Jun 06, 2016 at 11:21:24AM +0100, Richard F wrote:
  

Hi Richard,

As there are no debug messages in your log I tried to reconstruct some
of them (power-related) - see my comments. Note that an extra second is
added to all timeouts due to the 'greater than' comparison. It was done
on purpose to add some save margin. Power-saving looks to work OK. But.
I don't see any 'timer ... start/stop' or 'record ...' messages in your
log. So, I have some questions:
1) Did you fail to record 'The Big C & Me' at 01:05 and 'Greenberg' at
01:35?
2) Did you cancel 'Greenberg'?
3) Was your streaming interrupted?
4) What is your vnsi streaming priority?
5) What is your recording priority?
6) Are the channels you recorded and the channels you streamed on the same
transponder? I'm asking this because I see device 1 being idle all that
time.
7) What happens with your VDR when a vnsi streaming is interrupted by a
higher priority recording on the same device but on another transponder?
8) What timers (their dates) did you have from Jun 24 00:00 to Jun 24
04:00? 
9) What is your Vps Margin setting?

> Jun 24 01:12:59 ha-server vdr: [8690] loading /etc/vdr/plugins/vnsiserver/allowed_hosts.conf
> Jun 24 01:12:59 ha-server vdr: [8690] VNSI: Client with ID 75 connected: 10.0.0.90:52606
> Jun 24 01:12:59 ha-server vdr: [15789] VNSI: Welcome client 'XBMC Media Center' with protocol version '8'
> Jun 24 01:12:59 ha-server vdr: [15789] VNSI: LiveStreamer::Close - close
> Jun 24 01:12:59 ha-server vdr: [15789] VNSI: close video input ...
> Jun 24 01:12:59 ha-server vdr: [15789] VNSI: Successfully found following device: 0x91cef0 (1) for receiving
> Jun 24 01:12:59 ha-server vdr: [15789] dvb tuner: power-up - opening frontend 0/0
streaming started on device 0, wake up device 0
> Jun 24 01:12:59 ha-server vdr: [15789] VNSI: activate live receiver: 1, pmt change: 1
> Jun 24 01:12:59 ha-server vdr: [15789] VNSI: Successfully switched to channel 1 - BBC ONE Lon
> Jun 24 01:12:59 ha-server vdr: [15789] VNSI: Started streaming of channel BBC ONE Lon (timeout 5 seconds)
> Jun 24 01:12:59 ha-server vdr: [15793] VNSI: Created stream for pid=101 and type=7
> Jun 24 01:12:59 ha-server vdr: [15793] VNSI: Created stream for pid=102 and type=2
> Jun 24 01:12:59 ha-server vdr: [15793] VNSI: Created stream for pid=106 and type=2
> Jun 24 01:12:59 ha-server vdr: [15793] VNSI: Created stream for pid=105 and type=9
> Jun 24 01:13:00 ha-server vdr: [8686] channel 3 (BBC TWO) event Fri 24.06.2016 01:05-02:05 (VPS: 24.06. 01:05) 'The Big C & Me' status 4
> Jun 24 01:13:05 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
> Jun 24 01:13:10 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
tune to a transponder on device 1 to refresh EPG before a (VPS) timer starts, call cDevice::SetOccupied(), set device 1 idle timer to 38 sec
> Jun 24 01:13:46 ha-server vdr: [15789] VNSI-Error: cxSocket::read(fd=18): read() error at 0/4
> Jun 24 01:13:46 ha-server vdr: [15793] VNSI: exit streamer thread
> Jun 24 01:13:46 ha-server vdr: [15789] VNSI: LiveStreamer::Close - close
> Jun 24 01:13:46 ha-server vdr: [15789] VNSI: close video input ...
> Jun 24 01:13:46 ha-server vdr: [15789] VNSI: activate live receiver: 0, pmt change: 0
> Jun 24 01:13:46 ha-server vdr: [15789] VNSI: close video input ...
> Jun 24 01:13:46 ha-server vdr: [8692] VNSI: Client with ID 75 seems to be disconnected, removing from client list
> Jun 24 01:13:49 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
device 1 has been idle for 38 sec - power it down
> Jun 24 01:13:51 ha-server vdr: [8690] loading /etc/vdr/plugins/vnsiserver/allowed_hosts.conf
> Jun 24 01:13:51 ha-server vdr: [8690] VNSI: Client with ID 76 connected: 10.0.0.90:52610
> Jun 24 01:13:51 ha-server vdr: [15824] VNSI: Welcome client 'XBMC Media Center' with protocol version '8'
> Jun 24 01:13:51 ha-server vdr: [15824] VNSI: LiveStreamer::Close - close
> Jun 24 01:13:51 ha-server vdr: [15824] VNSI: close video input ...
> Jun 24 01:13:51 ha-server vdr: [15824] VNSI: Successfully found following device: 0x91cef0 (1) for receiving
> Jun 24 01:13:51 ha-server vdr: [15824] VNSI: activate live receiver: 1, pmt change: 1
> Jun 24 01:13:51 ha-server vdr: [15824] VNSI: Successfully switched to channel 1 - BBC ONE Lon
> Jun 24 01:13:51 ha-server vdr: [15824] VNSI: Started streaming of channel BBC ONE Lon (timeout 5 seconds)
> Jun 24 01:13:52 ha-server vdr: [15826] VNSI: Created stream for pid=101 and type=7
> Jun 24 01:13:52 ha-server vdr: [15826] VNSI: Created stream for pid=102 and type=2
> Jun 24 01:13:52 ha-server vdr: [15826] VNSI: Created stream for pid=106 and type=2
> Jun 24 01:13:52 ha-server vdr: [15826] VNSI: Created stream for pid=105 and type=9
> Jun 24 01:13:54 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
tune to a transponder on device 1 to refresh EPG before a (VPS) timer starts, call cDevice::SetOccupied(), set device 1 idle timer to 38 sec
> Jun 24 01:13:59 ha-server vdr: [7056] VNSI-Error: cxSocket::read(fd=6): read() error at 0/4
> Jun 24 01:13:59 ha-server vdr: [8692] VNSI: Client with ID 72 seems to be disconnected, removing from client list
> Jun 24 01:14:33 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
device 1 has been idle for 38 sec - power it down
> Jun 24 01:14:38 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
tune to a transponder on device 1 to refresh EPG before a (VPS) timer starts, call cDevice::SetOccupied(), set device 1 idle timer to 38 sec
> Jun 24 01:15:17 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
device 1 has been idle for 38 sec - power it down
> Jun 24 01:15:22 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
tune to a transponder on device 1 to refresh EPG before a (VPS) timer starts, call cDevice::SetOccupied(), set device 1 idle timer to 38 sec
> Jun 24 01:16:01 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
device 1 has been idle for 38 sec - power it down
> Jun 24 01:16:06 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
tune to a transponder on device 1 to refresh EPG before a (VPS) timer starts, call cDevice::SetOccupied(), set device 1 idle timer to 38 sec
> Jun 24 01:16:43 ha-server vdr: [15824] VNSI-Error: cxSocket::read(fd=8): read() error at 0/4
> Jun 24 01:16:43 ha-server vdr: [15826] VNSI: exit streamer thread
> Jun 24 01:16:43 ha-server vdr: [15824] VNSI: LiveStreamer::Close - close
> Jun 24 01:16:43 ha-server vdr: [15824] VNSI: close video input ...
> Jun 24 01:16:43 ha-server vdr: [15824] VNSI: activate live receiver: 0, pmt change: 0
> Jun 24 01:16:43 ha-server vdr: [15824] VNSI: close video input ...
> Jun 24 01:16:43 ha-server vdr: [8692] VNSI: Client with ID 76 seems to be disconnected, removing from client list
> Jun 24 01:16:45 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
device 1 has been idle for 38 sec - power it down
> Jun 24 01:16:50 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
tune to a transponder on device 1 to refresh EPG before a (VPS) timer starts, call cDevice::SetOccupied(), set device 1 idle timer to 38 sec
> Jun 24 01:16:56 ha-server vdr: [8690] loading /etc/vdr/plugins/vnsiserver/allowed_hosts.conf
> Jun 24 01:16:56 ha-server vdr: [8690] VNSI: Client with ID 77 connected: 10.0.0.90:52614
> Jun 24 01:16:56 ha-server vdr: [16255] VNSI: Welcome client 'XBMC Media Center' with protocol version '8'
> Jun 24 01:16:56 ha-server vdr: [16255] VNSI: LiveStreamer::Close - close
> Jun 24 01:16:56 ha-server vdr: [16255] VNSI: close video input ...
> Jun 24 01:16:56 ha-server vdr: [16255] VNSI: Successfully found following device: 0x91cef0 (1) for receiving
> Jun 24 01:16:56 ha-server vdr: [16255] VNSI: activate live receiver: 1, pmt change: 1
> Jun 24 01:16:56 ha-server vdr: [16255] VNSI: Successfully switched to channel 20 - ITV
> Jun 24 01:16:56 ha-server vdr: [16255] VNSI: Started streaming of channel ITV (timeout 5 seconds)
> Jun 24 01:16:57 ha-server vdr: [16257] VNSI: Created stream for pid=1701 and type=7
> Jun 24 01:16:57 ha-server vdr: [16257] VNSI: Created stream for pid=1702 and type=2
> Jun 24 01:16:57 ha-server vdr: [16257] VNSI: Created stream for pid=1703 and type=2
> Jun 24 01:16:57 ha-server vdr: [16257] VNSI: Created stream for pid=1731 and type=9
> Jun 24 01:17:29 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
device 1 has been idle for 38 sec - power it down
> Jun 24 01:35:42 ha-server vdr: [8686] channel 45 (Film4) event Fri 24.06.2016 01:35-03:50 (VPS: 24.06. 01:35) 'Greenberg' status 4
> Jun 24 01:35:45 ha-server vdr: [8679] timer 1 (45 1635-1850 VPS '-Films~The Spy Who Came In from the Cold~2016.06.23-16:35-Thu') set to no event
> Jun 24 01:36:11 ha-server vdr: [8679] deleting timer 1 (45 1635-1850 VPS '-Films~The Spy Who Came In from the Cold~2016.06.23-16:35-Thu')
> Jun 24 01:36:11 ha-server vdr: [8692] VNSI: Timers state changed (71)
> Jun 24 01:36:11 ha-server vdr: [8692] VNSI: Requesting clients to reload timers
> Jun 24 02:15:32 ha-server vdr: [16255] VNSI-Error: cxSocket::read(fd=23): read() error at 0/4
> Jun 24 02:15:33 ha-server vdr: [16257] VNSI: exit streamer thread
> Jun 24 02:15:33 ha-server vdr: [16255] VNSI: LiveStreamer::Close - close
streaming on device 0 has ended, set device 0 idle timer to 5 min (your setting)
> Jun 24 02:15:33 ha-server vdr: [16255] VNSI: close video input ...
> Jun 24 02:15:33 ha-server vdr: [16255] VNSI: activate live receiver: 0, pmt change: 0
> Jun 24 02:15:33 ha-server vdr: [16255] VNSI: close video input ...
> Jun 24 02:15:33 ha-server vdr: [8692] VNSI: Client with ID 77 seems to be disconnected, removing from client list
> Jun 24 02:15:40 ha-server vdr: [15117] VNSI: cxSocket::read(fd=17): eof, connection closed
> Jun 24 02:15:40 ha-server vdr: [8692] VNSI: Client with ID 74 seems to be disconnected, removing from client list
> Jun 24 02:20:34 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 0/0
device 0 has been idle for 300 sec - power it down
> Jun 24 02:20:38 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
tune to a transponder on device 1 to refresh EPG before a (VPS) timer starts, call cDevice::SetOccupied(), set device 1 idle timer to 38 sec
> Jun 24 02:21:17 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
device 1 has been idle for 38 sec - power it down
> Jun 24 02:21:22 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
tune to a transponder on device 1 to refresh EPG before a (VPS) timer starts, call cDevice::SetOccupied(), set device 1 idle timer to 38 sec
> Jun 24 02:22:01 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
device 1 has been idle for 38 sec - power it down
> Jun 24 02:22:06 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
tune to a transponder on device 1 to refresh EPG before a (VPS) timer starts, call cDevice::SetOccupied(), set device 1 idle timer to 38 sec
> .....
> 
> Jun 25 09:50:17 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
> Jun 25 09:50:22 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
tune to a transponder on device 1 to refresh EPG before a (VPS) timer starts, call cDevice::SetOccupied(), set device 1 idle timer to 38 sec
> Jun 25 09:51:01 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
device 1 has been idle for 38 sec - power it down
> Jun 25 09:51:06 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
tune to a transponder on device 1 to refresh EPG before a (VPS) timer starts, call cDevice::SetOccupied(), set device 1 idle timer to 38 sec
> Jun 25 09:51:45 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
device 1 has been idle for 38 sec - power it down
> Jun 25 09:51:50 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
tune to a transponder on device 1 to refresh EPG before a (VPS) timer starts, call cDevice::SetOccupied(), set device 1 idle timer to 38 sec
> Jun 25 09:52:29 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
device 1 has been idle for 38 sec - power it down
  

On 28/06/2016 03:14, glenvt18 wrote:
> Hi Richard,
>
> As there are no debug messages in your log I tried to reconstruct some
> of them (power-related) - see my comments. Note that an extra second is
> added to all timeouts due to the 'greater than' comparison. It was done
> on purpose to add some save margin. Power-saving looks to work OK. But.
> I don't see any 'timer ... start/stop' or 'record ...' messages in your
> log. So, I have some questions:
Yes, I turned off debug as it's been running awhile.
> 1) Did you fail to record 'The Big C & Me' at 01:05 and 'Greenberg' at
> 01:35?
No, that was just a (standard) notification from VDR that the running
status of a program had changed
> 2) Did you cancel 'Greenberg'?
No, VDR was idle before I started up Kodi/VNSI at around 01:00.

Actually looking back through the log some more, it seems that Kodi had
one of it's regular hiccup startup problems here.
Basically it starts, then crashes, then starts, often 2 or 3 times. This
is a known issue - the Kodi devs say they've changed the startup
mechanism in newer versions, but these aren't stable enough for regular
use for various other reasons.
> 3) Was your streaming interrupted?
> 4) What is your vnsi streaming priority?
Not sure I have a VNSI priority, at least there isn't a setup variable
for it.
> 5) What is your recording priority?
Generally 50 or 99. But in this case it wasn't recording, just streaming.
> 6) Are the channels you recorded and the channels you streamed on the same
> transponder? I'm asking this because I see device 1 being idle all that
> time.
As above, there was only 1
> 7) What happens with your VDR when a vnsi streaming is interrupted by a
> higher priority recording on the same device but on another transponder?
Not tested.
> 8) What timers (their dates) did you have from Jun 24 00:00 to Jun 24
> 04:00? 
None
> 9) What is your Vps Margin setting?
600

On reflection I think this is really a VNSI problem, possibly a
side-effect of locking up the VNSI process.
I have had a similar situation in the past (before adding your patch)
where VNSI server plugin locks up after a client hiccup start, then any
client trying to connect keeps trying to attach and times out. This time
the client didn't time out (as I recall), but it was late, so I left it
and went to bed...!

I'll monitor for any other effects.

thanks
Richard
>> Jun 24 01:12:59 ha-server vdr: [8690] loading /etc/vdr/plugins/vnsiserver/allowed_hosts.conf
>> Jun 24 01:12:59 ha-server vdr: [8690] VNSI: Client with ID 75 connected: 10.0.0.90:52606
>> Jun 24 01:12:59 ha-server vdr: [15789] VNSI: Welcome client 'XBMC Media Center' with protocol version '8'
>> Jun 24 01:12:59 ha-server vdr: [15789] VNSI: LiveStreamer::Close - close
>> Jun 24 01:12:59 ha-server vdr: [15789] VNSI: close video input ...
>> Jun 24 01:12:59 ha-server vdr: [15789] VNSI: Successfully found following device: 0x91cef0 (1) for receiving
>> Jun 24 01:12:59 ha-server vdr: [15789] dvb tuner: power-up - opening frontend 0/0
> streaming started on device 0, wake up device 0
>> Jun 24 01:12:59 ha-server vdr: [15789] VNSI: activate live receiver: 1, pmt change: 1
>> Jun 24 01:12:59 ha-server vdr: [15789] VNSI: Successfully switched to channel 1 - BBC ONE Lon
>> Jun 24 01:12:59 ha-server vdr: [15789] VNSI: Started streaming of channel BBC ONE Lon (timeout 5 seconds)
>> Jun 24 01:12:59 ha-server vdr: [15793] VNSI: Created stream for pid=101 and type=7
>> Jun 24 01:12:59 ha-server vdr: [15793] VNSI: Created stream for pid=102 and type=2
>> Jun 24 01:12:59 ha-server vdr: [15793] VNSI: Created stream for pid=106 and type=2
>> Jun 24 01:12:59 ha-server vdr: [15793] VNSI: Created stream for pid=105 and type=9
>> Jun 24 01:13:00 ha-server vdr: [8686] channel 3 (BBC TWO) event Fri 24.06.2016 01:05-02:05 (VPS: 24.06. 01:05) 'The Big C & Me' status 4
>> Jun 24 01:13:05 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
>> Jun 24 01:13:10 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
> tune to a transponder on device 1 to refresh EPG before a (VPS) timer starts, call cDevice::SetOccupied(), set device 1 idle timer to 38 sec
>> Jun 24 01:13:46 ha-server vdr: [15789] VNSI-Error: cxSocket::read(fd=18): read() error at 0/4
>> Jun 24 01:13:46 ha-server vdr: [15793] VNSI: exit streamer thread
>> Jun 24 01:13:46 ha-server vdr: [15789] VNSI: LiveStreamer::Close - close
>> Jun 24 01:13:46 ha-server vdr: [15789] VNSI: close video input ...
>> Jun 24 01:13:46 ha-server vdr: [15789] VNSI: activate live receiver: 0, pmt change: 0
>> Jun 24 01:13:46 ha-server vdr: [15789] VNSI: close video input ...
>> Jun 24 01:13:46 ha-server vdr: [8692] VNSI: Client with ID 75 seems to be disconnected, removing from client list
>> Jun 24 01:13:49 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
> device 1 has been idle for 38 sec - power it down
>> Jun 24 01:13:51 ha-server vdr: [8690] loading /etc/vdr/plugins/vnsiserver/allowed_hosts.conf
>> Jun 24 01:13:51 ha-server vdr: [8690] VNSI: Client with ID 76 connected: 10.0.0.90:52610
>> Jun 24 01:13:51 ha-server vdr: [15824] VNSI: Welcome client 'XBMC Media Center' with protocol version '8'
>> Jun 24 01:13:51 ha-server vdr: [15824] VNSI: LiveStreamer::Close - close
>> Jun 24 01:13:51 ha-server vdr: [15824] VNSI: close video input ...
>> Jun 24 01:13:51 ha-server vdr: [15824] VNSI: Successfully found following device: 0x91cef0 (1) for receiving
>> Jun 24 01:13:51 ha-server vdr: [15824] VNSI: activate live receiver: 1, pmt change: 1
>> Jun 24 01:13:51 ha-server vdr: [15824] VNSI: Successfully switched to channel 1 - BBC ONE Lon
>> Jun 24 01:13:51 ha-server vdr: [15824] VNSI: Started streaming of channel BBC ONE Lon (timeout 5 seconds)
>> Jun 24 01:13:52 ha-server vdr: [15826] VNSI: Created stream for pid=101 and type=7
>> Jun 24 01:13:52 ha-server vdr: [15826] VNSI: Created stream for pid=102 and type=2
>> Jun 24 01:13:52 ha-server vdr: [15826] VNSI: Created stream for pid=106 and type=2
>> Jun 24 01:13:52 ha-server vdr: [15826] VNSI: Created stream for pid=105 and type=9
>> Jun 24 01:13:54 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
> tune to a transponder on device 1 to refresh EPG before a (VPS) timer starts, call cDevice::SetOccupied(), set device 1 idle timer to 38 sec
>> Jun 24 01:13:59 ha-server vdr: [7056] VNSI-Error: cxSocket::read(fd=6): read() error at 0/4
>> Jun 24 01:13:59 ha-server vdr: [8692] VNSI: Client with ID 72 seems to be disconnected, removing from client list
>> Jun 24 01:14:33 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
> device 1 has been idle for 38 sec - power it down
>> Jun 24 01:14:38 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
> tune to a transponder on device 1 to refresh EPG before a (VPS) timer starts, call cDevice::SetOccupied(), set device 1 idle timer to 38 sec
>> Jun 24 01:15:17 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
> device 1 has been idle for 38 sec - power it down
>> Jun 24 01:15:22 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
> tune to a transponder on device 1 to refresh EPG before a (VPS) timer starts, call cDevice::SetOccupied(), set device 1 idle timer to 38 sec
>> Jun 24 01:16:01 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
> device 1 has been idle for 38 sec - power it down
>> Jun 24 01:16:06 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
> tune to a transponder on device 1 to refresh EPG before a (VPS) timer starts, call cDevice::SetOccupied(), set device 1 idle timer to 38 sec
>> Jun 24 01:16:43 ha-server vdr: [15824] VNSI-Error: cxSocket::read(fd=8): read() error at 0/4
>> Jun 24 01:16:43 ha-server vdr: [15826] VNSI: exit streamer thread
>> Jun 24 01:16:43 ha-server vdr: [15824] VNSI: LiveStreamer::Close - close
>> Jun 24 01:16:43 ha-server vdr: [15824] VNSI: close video input ...
>> Jun 24 01:16:43 ha-server vdr: [15824] VNSI: activate live receiver: 0, pmt change: 0
>> Jun 24 01:16:43 ha-server vdr: [15824] VNSI: close video input ...
>> Jun 24 01:16:43 ha-server vdr: [8692] VNSI: Client with ID 76 seems to be disconnected, removing from client list
>> Jun 24 01:16:45 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
> device 1 has been idle for 38 sec - power it down
>> Jun 24 01:16:50 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
> tune to a transponder on device 1 to refresh EPG before a (VPS) timer starts, call cDevice::SetOccupied(), set device 1 idle timer to 38 sec
>> Jun 24 01:16:56 ha-server vdr: [8690] loading /etc/vdr/plugins/vnsiserver/allowed_hosts.conf
>> Jun 24 01:16:56 ha-server vdr: [8690] VNSI: Client with ID 77 connected: 10.0.0.90:52614
>> Jun 24 01:16:56 ha-server vdr: [16255] VNSI: Welcome client 'XBMC Media Center' with protocol version '8'
>> Jun 24 01:16:56 ha-server vdr: [16255] VNSI: LiveStreamer::Close - close
>> Jun 24 01:16:56 ha-server vdr: [16255] VNSI: close video input ...
>> Jun 24 01:16:56 ha-server vdr: [16255] VNSI: Successfully found following device: 0x91cef0 (1) for receiving
>> Jun 24 01:16:56 ha-server vdr: [16255] VNSI: activate live receiver: 1, pmt change: 1
>> Jun 24 01:16:56 ha-server vdr: [16255] VNSI: Successfully switched to channel 20 - ITV
>> Jun 24 01:16:56 ha-server vdr: [16255] VNSI: Started streaming of channel ITV (timeout 5 seconds)
>> Jun 24 01:16:57 ha-server vdr: [16257] VNSI: Created stream for pid=1701 and type=7
>> Jun 24 01:16:57 ha-server vdr: [16257] VNSI: Created stream for pid=1702 and type=2
>> Jun 24 01:16:57 ha-server vdr: [16257] VNSI: Created stream for pid=1703 and type=2
>> Jun 24 01:16:57 ha-server vdr: [16257] VNSI: Created stream for pid=1731 and type=9
>> Jun 24 01:17:29 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
> device 1 has been idle for 38 sec - power it down
>> Jun 24 01:35:42 ha-server vdr: [8686] channel 45 (Film4) event Fri 24.06.2016 01:35-03:50 (VPS: 24.06. 01:35) 'Greenberg' status 4
>> Jun 24 01:35:45 ha-server vdr: [8679] timer 1 (45 1635-1850 VPS '-Films~The Spy Who Came In from the Cold~2016.06.23-16:35-Thu') set to no event
>> Jun 24 01:36:11 ha-server vdr: [8679] deleting timer 1 (45 1635-1850 VPS '-Films~The Spy Who Came In from the Cold~2016.06.23-16:35-Thu')
>> Jun 24 01:36:11 ha-server vdr: [8692] VNSI: Timers state changed (71)
>> Jun 24 01:36:11 ha-server vdr: [8692] VNSI: Requesting clients to reload timers
>> Jun 24 02:15:32 ha-server vdr: [16255] VNSI-Error: cxSocket::read(fd=23): read() error at 0/4
>> Jun 24 02:15:33 ha-server vdr: [16257] VNSI: exit streamer thread
>> Jun 24 02:15:33 ha-server vdr: [16255] VNSI: LiveStreamer::Close - close
> streaming on device 0 has ended, set device 0 idle timer to 5 min (your setting)
>> Jun 24 02:15:33 ha-server vdr: [16255] VNSI: close video input ...
>> Jun 24 02:15:33 ha-server vdr: [16255] VNSI: activate live receiver: 0, pmt change: 0
>> Jun 24 02:15:33 ha-server vdr: [16255] VNSI: close video input ...
>> Jun 24 02:15:33 ha-server vdr: [8692] VNSI: Client with ID 77 seems to be disconnected, removing from client list
>> Jun 24 02:15:40 ha-server vdr: [15117] VNSI: cxSocket::read(fd=17): eof, connection closed
>> Jun 24 02:15:40 ha-server vdr: [8692] VNSI: Client with ID 74 seems to be disconnected, removing from client list
>> Jun 24 02:20:34 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 0/0
> device 0 has been idle for 300 sec - power it down
>> Jun 24 02:20:38 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
> tune to a transponder on device 1 to refresh EPG before a (VPS) timer starts, call cDevice::SetOccupied(), set device 1 idle timer to 38 sec
>> Jun 24 02:21:17 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
> device 1 has been idle for 38 sec - power it down
>> Jun 24 02:21:22 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
> tune to a transponder on device 1 to refresh EPG before a (VPS) timer starts, call cDevice::SetOccupied(), set device 1 idle timer to 38 sec
>> Jun 24 02:22:01 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
> device 1 has been idle for 38 sec - power it down
>> Jun 24 02:22:06 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
> tune to a transponder on device 1 to refresh EPG before a (VPS) timer starts, call cDevice::SetOccupied(), set device 1 idle timer to 38 sec
>> .....
>>
>> Jun 25 09:50:17 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
>> Jun 25 09:50:22 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
> tune to a transponder on device 1 to refresh EPG before a (VPS) timer starts, call cDevice::SetOccupied(), set device 1 idle timer to 38 sec
>> Jun 25 09:51:01 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
> device 1 has been idle for 38 sec - power it down
>> Jun 25 09:51:06 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
> tune to a transponder on device 1 to refresh EPG before a (VPS) timer starts, call cDevice::SetOccupied(), set device 1 idle timer to 38 sec
>> Jun 25 09:51:45 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
> device 1 has been idle for 38 sec - power it down
>> Jun 25 09:51:50 ha-server vdr: [8679] dvb tuner: power-up - opening frontend 1/0
> tune to a transponder on device 1 to refresh EPG before a (VPS) timer starts, call cDevice::SetOccupied(), set device 1 idle timer to 38 sec
>> Jun 25 09:52:29 ha-server vdr: [8679] dvb tuner: power-down - closing frontend 1/0
> device 1 has been idle for 38 sec - power it down
>
  

> No, that was just a (standard) notification from VDR that the running
> status of a program had changed
Sorry. I was a bit sleepy that night:) It was a false alarm.
> Not sure I have a VNSI priority, at least there isn't a setup variable
> for it.
It's under Settings->Add-ons->My add-ons->PVR clients->
VDR VNSI Client->Configure->General->Priority. I have it set to 0.
> > 8) What timers (their dates) did you have from Jun 24 00:00 to Jun 24
> > 04:00? 
> None
> > 9) What is your Vps Margin setting?
> 600
In this case your VDR might have been trying to update EPG for the
timers scheduled later, probably, next night. Anyway, it's all about
VDR's internal logic for updating timers' EPG events and has nothing to
do with power saving. Every time a VDR decides to update EPG for a
channel with a timer scheduled the device's frontend must be opened
prior to zapping and kept open for a while (38 sec as you see in the
log). If you have power-related issues you're likely to see ioctl()
errors in the log and emergency exits after a recording starts (VDR will
be restarted in this case).
> I'll monitor for any other effects.
Let me know.