Project

General

Profile

Bug #2638

Inverto IP-LNB hangs again

Added by ullix tv almost 10 years ago. Updated almost 10 years ago.

Status:
Fixed
Priority:
Normal
Assignee:
-
Category:
-
Target version:
-
Start date:
2015-01-25
Due date:
% Done:

100%

Estimated time:
Found in version:
3.9.2410~g3077ffa~precise
Affected Versions:

Description

After 13 days of smooth usage ... there we go again ...

During a recording the iplnb showed the known symptom of hanging and no web access to the iplnb possible, only power shutdown helps. Failure occured between 14:37:01 and 14:38:04.

25.01.2015 14:37:01   ping_iplnb.py   6592       (tvheadend is running) returncode=0  wget
25.01.2015 14:38:04   ping_iplnb.py   6733       (tvheadend is running) returncode=4  wget

Different from before where the tvh status would show one or more "stalled entries" under stream and nothing at all under subscriptions, this time there is an entry under subscription (see screenshot) and nothing under stream.

And strange also that after stopping tvh by "sudo stop tvheadend" I don't see the "[ NOTICE]:STOP: Exiting HTS Tvheadend" entry in the log?

Also myterious entries in sub-millisec intervall about tune?

Full log attached

Files

tvh-status-subscription-2015-01-25.png (34 KB) tvh-status-subscription-2015-01-25.png ullix tv, 2015-01-25 14:57
tvh.log.zip (2.17 MB) tvh.log.zip ullix tv, 2015-01-25 14:58
tvh-2015-01-26.log.zip (8.31 MB) tvh-2015-01-26.log.zip ullix tv, 2015-01-26 17:18
tvh-2015-01-27.log.zip (11.6 MB) tvh-2015-01-27.log.zip ullix tv, 2015-01-27 14:53

History

#1

Updated by Jaroslav Kysela almost 10 years ago

  • Status changed from New to Fixed
  • % Done changed from 0 to 100

Applied in changeset commit:tvheadend|cde875ecb2296a42adc909b5336d4027734bc637.

#2

Updated by Jaroslav Kysela almost 10 years ago

The last "last tune diff" problem and the dead-lock and the tvh shutdown problem are fixed in v3.9-2427-gcde875e .

The IPLNB deadlock is similar like before:

2015-01-25 14:38:00.817 [  TRACE]:satip: Status string: 'ver=1.0;src=1;tuner=1,171,1,13,12421,h,dvbs,qpsk,,,27500,34;pids=0,1,16,17,18,5501,5502,5503,5504,5505,5506,5530'
2015-01-25 14:38:01.018 [  TRACE]:satip: Status string: 'ver=1.0;src=1;tuner=1,171,1,13,12421,h,dvbs,qpsk,,,27500,34;pids=0,1,16,17,18,5501,5502,5503,5504,5505,5506,5530'
2015-01-25 14:38:01.218 [  TRACE]:satip: Status string: 'ver=1.0;src=1;tuner=1,171,1,13,12421,h,dvbs,qpsk,,,27500,34;pids=0,1,16,17,18,5501,5502,5503,5504,5505,5506,5530'

... more status strings should be here .. between 14:38:01.218 and 2015-01-25 14:38:11.000 tvheadend didn't send any new command in this time

2015-01-25 14:38:11.000 [  TRACE]:subscription: 00BF: unlinking sub 0x2700a50 from svc 0x27683d0
2015-01-25 14:38:11.000 [  TRACE]:mpegts: table: mux 0x275e5a0 destroy pmt 02/FF (2) pid 159A (5530)
2015-01-25 14:38:11.000 [  DEBUG]:mpegts: 12421.5H in SATIP - close PID 159A (5530) [2/0x37bba30]
2015-01-25 14:38:11.000 [  TRACE]:mpegts: table: mux 0x275e5a0 free pmt 02/FF (2) pid 159A (5530)
2015-01-25 14:38:11.000 [  DEBUG]:mpegts: 12421.5H in SATIP - close PID 159A (5530) [1/0x27683d0]
2015-01-25 14:38:11.000 [  DEBUG]:mpegts: 12421.5H in SATIP - close PID 157D (5501) [1/0x27683d0]
2015-01-25 14:38:11.000 [  DEBUG]:mpegts: 12421.5H in SATIP - close PID 157E (5502) [1/0x27683d0]
2015-01-25 14:38:11.000 [  DEBUG]:mpegts: 12421.5H in SATIP - close PID 157F (5503) [1/0x27683d0]
2015-01-25 14:38:11.000 [  DEBUG]:mpegts: 12421.5H in SATIP - close PID 1580 (5504) [1/0x27683d0]
2015-01-25 14:38:11.000 [  DEBUG]:mpegts: 12421.5H in SATIP - close PID 1582 (5506) [1/0x27683d0]
2015-01-25 14:38:11.000 [  DEBUG]:mpegts: 12421.5H in SATIP - close PID 1581 (5505) [1/0x27683d0]
2015-01-25 14:38:11.000 [  DEBUG]:mpegts: 12421.5H in SATIP - stopping mux
2015-01-25 14:38:11.000 [  DEBUG]:satip: SAT>IP DVB-S Tuner #1 (10.0.0.71) - stopping 12421.5H in SATIP
#3

Updated by Jaroslav Kysela almost 10 years ago

About the subscription entry in the status tab - DVR subsystem tries to subscribe service again and again in the DVR time window.. It seems like this reason, becase IPLNB was dead since 15:38 and the tvheadend was restarted at 14:45 - so the recording was probably active.

#4

Updated by ullix tv almost 10 years ago

Well, that sure was fast!

Now running on 3.9.2427~gcde875e~precise

Is there any particularly good way to stress-test the iplnb for this problem?

#5

Updated by ullix tv almost 10 years ago

It hung again!

26.01.2015 12:05:01   ping_iplnb.py  23065       (tvheadend is running) returncode=0  wget 
26.01.2015 12:06:04   ping_iplnb.py  23083       (tvheadend is running) returncode=4  wget

Though I did put quite a bit of load on it with idle-scan and a bunch of recordings. Bitrate on the LAN topped at 150MBit/s.

log attached

#6

Updated by Jaroslav Kysela almost 10 years ago

This hang was independent from the tvheadend handshake:

2015-01-26 12:06:01.516 [  TRACE]:satip: Status string: 'ver=1.0;src=1;tuner=1,152,1,12,10891,h,dvbs2,8psk,on,0.35,22000,23;pids=0,1,16,17,18,5300,5320,5330,5331,5332,5333,5334,5335,5336,5340,5350'
2015-01-26 12:06:01.516 [  TRACE]:satip: Status string: 'ver=1.0;src=1;tuner=5,147,1,12,12480,v,dvbs,qpsk,,,27500,34;pids=0,16,17,18,38,97,98,99,100,101,102,103,104,106,107,108,109,110,1535,1536'
2015-01-26 12:06:01.516 [  TRACE]:satip: Status string: 'ver=1.0;src=1;tuner=2,137,1,11,11361,h,dvbs2,8psk,on,0.35,22000,23;pids=0,1,16,17,18,6100,6110,6120,6121,6122,6123,6130,6131,6300,6400,6410,6420,6421,6422,6423,6430'
2015-01-26 12:06:01.516 [  TRACE]:satip: Status string: 'ver=1.0;src=1;tuner=4,171,1,13,12421,h,dvbs,qpsk,,,27500,34;pids=0,1,16,17,18,300,400,500,600,700,800,1200,1500,5500,5510,5520,5530,5540,5550'
2015-01-26 12:06:01.516 [  TRACE]:satip: Status string: 'ver=1.0;src=1;tuner=6,142,1,12,11493,h,dvbs2,8psk,on,0.35,22000,23;pids=0,1,16,17,18,5100,5101,5102,5103,5104,5105,5106'
2015-01-26 12:06:01.516 [  TRACE]:satip: Status string: 'ver=1.0;src=1;tuner=8,142,1,11,11302,h,dvbs2,8psk,on,0.35,22000,23;pids=0,1,16,17,18,107,108,109,110,111,116'
2015-01-26 12:06:01.516 [  TRACE]:satip: Status string: 'ver=1.0;src=1;tuner=7,147,1,12,11052,h,dvbs2,8psk,on,0.35,22000,23;pids=0,1,16,17,18,5400,5401,5402,5404,5406,5410,5420'
2015-01-26 12:06:09.000 [  TRACE]:mpegts: 11582.25H in SATIP - starting for 'scan' (weight 2, flags 0042)

No tvheadend activity between 12:06:01.516 and 12:06:09.000 . There should be more 'Status string:' lines which mean that the server is live and streaming. These UDP packets are sent every 200ms.

#7

Updated by ullix tv almost 10 years ago

Another hang after only 6h of runtime, log attached

27.01.2015 14:34:01   ping_iplnb.py  11135       (tvheadend is running) returncode=0  wget 
27.01.2015 14:35:04   ping_iplnb.py  11170       (tvheadend is running) returncode=4  wget

I see a whole bunch error-imagecache and discontiuity even well before tha hang. Anything relevant?

When I start and exit tvh normally. I see the 

[ NOTICE]:STOP: Exiting HTS Tvheadend

Message at the end. But not so, when the IPLNB hangs. Some other issue elsewhere?

Also available in: Atom PDF