CC Errors

[estimadarocha]

Hi @perexg:

do you also have these kind of issues?

I know i am pulling a lot (tvheadend) but i already played with STV6210_BAMP values (8 now) and even so CC Errors are always incresing... cpu is around 60%.

Signal is perfect if i connect cables direct on enigma box!

[estimadarocha]

with STV6210_BAMP on 16

[estimadarocha]

i am using satipaxe to tvheadend on same network and forcing play of 15 channels, one of them is UHD!

there's somethings working bad...

1. The cc errors always increasing
2. Sometimes when i get cc errors and the client thats is pushing from tvheadend stops and restart's i cannot recover to a working state. (picture) Only solution is restart satipaxe or own tvheadend.
3. A small apart to be able to grab all of this i had to disable fe support (image 2)

[estimadarocha]

minisatip.log

[estimadarocha]

start point:

after 60mins:

[estimadarocha]

stucked again:

[perexg]

Try to find a minimal configuration where things hangs. Do not unset 'FE supported' - otherwise the problem is just migrated to another tuner. Provide minisatip logs for 'general,http,stream,adapter,dvb,axe' subsystems. I have very little time to look into, so it depends on your description quality, if I can fix something.

Anyway high tt values means usually that minisatip is under high load.

[estimadarocha]

so.... back to work...

i will set again FE supported (but if i remember well with that option unset i was not able to run it) i will look further... give me some mins!

i am forcing this channels:

second frequency:

added 2 more channels of 12399 frequency to force pids=all also on this tuner:

first problem i found:

every time i force one more channel to play i got "cc errors" is this the expected behaviour? because if i already have 1 or 2 channels playing on that frequency every time tvheadend requests one more channel the cc errors force channels to stop and start again.

[catalinii]

Hi,

Just commenting on a trend here:

1. at 15M tt is over 1000ms (which would mean cpu is at 100%)
2. the CC errors is what the hardware reports (not minisatip)
3. the number of cc errors (in percentage) are very low.

Thanks

[estimadarocha]

65% last time I checked... Or am I checking wrong?

[catalinii]

My point was that cpu spikes to 100%, the question is can you reproduce the issue lets say with few channels under 7MB/s (15M/2)?

Basically we would like to know if the issue happens not because potentially the CPU is overloaded....

PS. I never had an axe myself so I cannot comment on the CPu capabilities. I had an amiko with similar CPU the fact that it can get to 15M shows how much work @perexg has put into it.

[estimadarocha]

I will see with half of bw. Regarding the cc errors everytime one new stream is added do you thinks that's normal? I don't think I see same behavior on minisatip... Maybe a specific axe problem!

[perexg]

Try '-W 1'.

[estimadarocha]

Try '-W 1'.

Tried already... And behavior is equal every new tune the playing channels go down because of cc errors

...

new find... the cc errors that appear on adding streams also happen if subtracting streams... and this just happen after some amount of streams already playing.

I am now with 6 + 6 streams and everything is fine for one hour but as soon as i try to add/remove any stream cc errors appear and tvheaend unsubscribe and them subscribe again all the forced streams!

[estimadarocha]

so 1st log....

3 streams running and when increasing one by one.... satipaxe stops suddendly streaming

minisatip (1).log

[catalinii]

The stream stopped because of this:

[31/10 15:17:19.945 main]: read RTSP (from handle 16 sock 10, len: 0, sid 0):
[31/10 15:17:19.945 main]:
[31/10 15:17:19.946 main]: Most likely not an RTSP packet sock_id: 10 sid: 0 rlen: 0, dropping ....
[31/10 15:17:19.946 main]: select_and_execute[10]: Close on socket 16 (sid:0) from 192.168.1.200:56420 - type rtsp errno 0
[31/10 15:17:19.946 main]: Requested stream close 0 timeout 30000 type 3
[31/10 15:17:19.946 main]: closing stream 0

Which I assume is because for some reason the tvh closed the connection. I would check tvh logs and also make sure the client (kodi ?) did not close the connection to tvh.

[perexg]

@catalinii : tvh always sends teardown when the client closes the streaming. It looks like a serious issue somewhere.

[perexg]

@estimaradocha: This minisatip8 binary should fix the rlen = 0 log issue : http://s000.tinyupload.com/?file_id=85686441378171183817

Anyway, you should check, who/what breaks the TCP RTSP connection.

[catalinii]

Yes but the socket is closed (read returns 0) not some connection issue where read would return -1

…

On Wed, Oct 31, 2018, 11:30 Jaroslav Kysela ***@***.***> wrote: @estimaradocha: This minisatip8 binary should fix the rlen = 0 log issue : http://s000.tinyupload.com/?file_id=85686441378171183817 Anyway, you should check, who/what breaks the TCP RTSP connection. — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#130 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AH0gEaqc0KSDyGvy0x8ZZFYgqG-Q_V3Uks5uqewygaJpZM4X8bZJ> .

[perexg]

@catalinii : I do not see confirmed read() == 0 in the log. The "read RTSP (from handle 16 sock 10, len: 0, sid 0)" prints always zero because of this bug (the last change): catalinii/minisatip#473 .

[estimadarocha]

@perexg i saw you made a new commit catalinii/minisatip@215747c the last binary link already have all the fixes?

Thanks for everything

[perexg]

No, but you don't need this fix (the code is not used in your config). Just test this with the provided binary to check, if there are some data received from the socket or something closed the connection unexpectly.

[estimadarocha]

with last binary its very unstable

2018-11-01 16:09:00.751 satip: SAT>IP DVB-S Tuner #2 (192.168.1.67@TCP) - RTSP error -5 (I/O error) [9874-0]
2018-11-01 16:09:00.753 satip: SAT>IP DVB-S Tuner #1 (192.168.1.67@TCP) - RTSP error -5 (I/O error) [9874-0]
2018-11-01 16:09:01.918 subscription: 2820: service instance is bad, reason: Tuning failed

and

2018-11-01 16:09:05.067 satip: SAT>IP DVB-S Tuner #1 (192.168.1.67@TCP) - RTSP error -111 (Connection refused) [6-0]

and

2018-11-01 16:21:07.847 satip: SAT>IP DVB-S Tuner #2 (192.168.1.67@TCP) - RTSP error -90 (Message too large) [9874-0]

[perexg]

logs from minisatip ?

[estimadarocha]

I will grab them tonight when my son goes to bed... And paste them here

[estimadarocha]

minisatip1.log

i got a lot of testing / bad on tvh on the startup let's see if log have something

[estimadarocha]

most of the time (90%) i have less than 600ms on tt, but time to time it spikes to 1000-1100 with exact same channels playing and without any operation (add/subtract channels).

i don't see any variation on cpu % when tt spikes

is it normal so have such variation on constant play?

[perexg]

Ok, so we have confirmed the TCP connection close (read() == 0):

[02/11 08:55:03.010 main]: read RTSP (from handle 17 sock 12, len: 0, sid 1):
[02/11 08:55:03.010 main]: 
[02/11 08:55:03.011 main]: Most likely not an RTSP packet sock_id: 12 sid: 1 rlen: 0, dropping ....
[02/11 08:55:03.012 main]: select_and_execute[12]: Close on socket 17 (sid:1) from 192.168.1.200:40532 - type rtsp errno 0
[02/11 08:55:03.012 main]: Requested stream close 1 timeout 30000 type 3
[02/11 08:55:03.012 main]: closing stream 1

I would start with this. Who or what closes the connection? Could you show tvh log and minisatip log around time what you see 'read RTSP .. len: 0 ... closing stream' lines? Also, tcpdump/wireshark RTSP TCP port 554 socket analysis might help.

[estimadarocha]

@perexg will try my best!

[estimadarocha]

have some time now to grab logs... what traces do you need from the tvh side?

[perexg]

tvh: --trace satip,mpegts

[estimadarocha]

tcpdump something like this:

tcpdump -i ens3 -nn -s0 -v port 554??

[perexg]

write the output to a file for the further analysis: -w /filename/

[9000h]

is there something like, to see if it's the signal/kernel or application
echo 1 > /sys/module/dvb_core/parameters/dvb_demux_tscheck

to check the system logs for messages like:
"TS packet counter mismatch...."

[perexg]

@9000h : the kernel drivers are really different than used on the enigma2 machines and there's 4MB ring buffer per MPEG-TS input. I don't know about this check in axe drivers (the hardware CC errors /reception,signal decoding/ are displayed in minisatip webif for axe).

[estimadarocha]

@estimaradocha: This minisatip8 binary should fix the rlen = 0 log issue : http://s000.tinyupload.com/?file_id=85686441378171183817

Anyway, you should check, who/what breaks the TCP RTSP connection.

@perexg is it possible to release a beta build with this fix? its anoying that have to upload it everytime satipaxe reboots! Thanks!

[perexg]

@estimadarocha : The fix is only for logging, it does not affect the operation. You stopped providing of logs and try to determine who closes the TCP connection, so I don't care.

[estimadarocha]

@estimadarocha : The fix is only for logging, it does not affect the operation. You stopped providing of logs and try to determine who closes the TCP connection, so I don't care.

i tought it was something that affects the operation... about logging i tought i would have time on past december but i was not sucessfull.... much because i need to add some external storage maybe... i run out of space in few time.

small apart is there any limitation of pids for total amount of adapters? i mean... for example can i get pids=all at same time on all adapters (internally of course not wan)?

[estimadarocha]

@perexg how do i debug satipaxe sudendly dying?

minisatip.log

[9000h]

there is also another open issue in minisatip, where http/rstp reply's get messed up

[09/01 12:36:07.053 main]: RTSP/1.0 404 Not Found
Date: Wed, Jan 9 12:36:07 2019 GMT
Public: OPTIONS, DESCRIBE, SETUP, PLAY, TEARDOWN
Server: minisatip/0.7.16-axe215

catalinii/minisatip#517

[estimadarocha]

that ip ... 128.1.84.138 is from outside maybe really a wrong call, possible?

[perexg]

@perexg how do i debug satipaxe sudendly dying?

Run very verbose log through ssh like (expand your arguments):

ARGS="$ARGS -l general,http,stream,adapter,dvb,axe"
ssh -t root@${HOST} minisatip8 $ARGS | tee out.txt

It seems that the TCP sockets stuck for a reason (minisatip8 cannot flush all read data to the TCP socket, so it started buffering at the end of the log).

[estimadarocha]

@perexg i am using the old tweaked settings from you "-b 4042752 -B 10000" it seens like it exausts memory to limit and them minisatip8 crash, is it possible?

[catalinii]

@estimadrocha,

That means that every adapter will allocate up to 4042752 *10000 bytes if there is not enough network bandwidth. If minisatip would crash the memory would be freed and you would be able to use the system again, but from my tests minisatip does not crash when out of memory.

Use lower memory settings based on available memory and number od adapters (4 for axe).

Eg if you have free 100M, you need 25M for each adapter which means -b 188000 -B 140.

-b should be multiple of 188.

[estimadarocha]

@catalinii thanks... First i need only 2 adapters I can't get more than 2 adapters with pids=all because the CPU Max's out. So I need to split the free space for only 2 sockets. What's better use -b and -B or for example use only a bigger value on -b?

Thanks again

[catalinii]

Bigger -b might be better.

[estimadarocha]

i set -b to 1880000 and no -B

if i look at memory the consume its always slowly increasing... doesn't buffers get cleared sometime?

~ # free -m
total used free shared buffers cached
Mem: 392 189 202 0 0 23
-/+ buffers/cache: 166 225
Swap: 0 0 0
~ # free -m
total used free shared buffers cached
Mem: 392 189 202 0 0 23
-/+ buffers/cache: 166 225
Swap: 0 0 0
~ # free -m
total used free shared buffers cached
Mem: 392 189 202 0 0 23
-/+ buffers/cache: 166 225
Swap: 0 0 0
~ # free -m
total used free shared buffers cached
Mem: 392 191 201 0 0 23
-/+ buffers/cache: 167 224
Swap: 0 0 0
~ # free -m
total used free shared buffers cached
Mem: 392 191 201 0 0 23
-/+ buffers/cache: 167 224
Swap: 0 0 0
~ # free -m
total used free shared buffers cached
Mem: 392 191 200 0 0 23
-/+ buffers/cache: 167 224
Swap: 0 0 0
~ # free -m
total used free shared buffers cached
Mem: 392 191 200 0 0 23
-/+ buffers/cache: 167 224
Swap: 0 0 0
~ # free -m
total used free shared buffers cached
Mem: 392 191 200 0 0 23
-/+ buffers/cache: 168 223
Swap: 0 0 0
~ # free -m
total used free shared buffers cached
Mem: 392 239 152 0 0 23
-/+ buffers/cache: 216 175
Swap: 0 0 0
~ # free -m
total used free shared buffers cached
Mem: 392 254 137 0 0 23
-/+ buffers/cache: 231 160
Swap: 0 0 0
~ # free -m
total used free shared buffers cached
Mem: 392 268 123 0 0 23
-/+ buffers/cache: 245 146
Swap: 0 0 0
~ # free -m
total used free shared buffers cached
Mem: 392 296 95 0 0 23
-/+ buffers/cache: 273 118
Swap: 0 0 0

[9000h]

you set ?

i set -b to 1880000 and no -B
@catalinii did suggest

Eg if you have free 100M, you need 25M for each adapter which means -b 188000 -B 140.

[estimadarocha]

@9000h and them he said

Bigger -b might be better.

so i tried last option

added few more free -m lines to previous post... still increasing!

[estimadarocha]

after 6 hours playing 2 full mux's not even a single CC (that's impossible when adding/removing pids).

memory

[9000h]

I'm unsure if the CC counter is right under all conditions.

[perexg]

Unless the client does not see any issues (video/audio CC errors / corruptions), it's fine. We don't know the exact metering of those CC errors. Perhaps, the CC error increases when the PID filter is changed, which might not be a problem. It should not increase massively.