Actions
Bug #5782
closed
httpc stuck and 100% cpu, when connecting to http2 server
Status:
Fixed
Priority:
Normal
Assignee:
-
Category:
IPTV
Target version:
-
Start date:
2019-11-19
Due date:
% Done:
0%
Estimated time:
Found in version:
4.3-1855~gd453f5bef
Affected Versions:
Description
Hello,
When downloading iptv m3u file from an apache 2.4 with http2 module enabled,
httpc get stuck using 100% cpu.
It seems httpc does not like apache response with upgrade header.
I'm using Tvheadend version 4.3-1855~gd453f5bef on Debian Buster
- tvheadend.log when apache2 http2 module is enable :
Nov 19 17:07:57 nas tvheadend[63262]: httpc: 0000: Connected to tv.xxxxxxxxx.com:443 Nov 19 17:07:57 nas tvheadend[63262]: httpc: 0000: sending HTTP/1.1 cmd Nov 19 17:07:57 nas tvheadend[63262]: httpc: 47 45 54 20 2F 66 72 65 65 2E 6D 33 75 20 48 54 GET /free.m3u HT Nov 19 17:07:57 nas tvheadend[63262]: httpc: 54 50 2F 31 2E 31 0D 0A 48 6F 73 74 3A 20 74 76 TP/1.1..Host: tv Nov 19 17:07:57 nas tvheadend[63262]: httpc: 2E 78 78 78 78 78 78 78 78 78 2E 63 6F 6D 0D 0A .xxxxxxxxx.com.. Nov 19 17:07:57 nas tvheadend[63262]: httpc: 55 73 65 72 2D 41 67 65 6E 74 3A 20 4B 6F 64 69 User-Agent: Kodi Nov 19 17:07:57 nas tvheadend[63262]: httpc: 2F 31 38 2E 31 20 28 58 31 31 3B 20 4C 69 6E 75 /18.1 (X11; Linu Nov 19 17:07:57 nas tvheadend[63262]: httpc: 78 20 78 38 36 5F 36 34 29 20 44 65 62 69 61 6E x x86_64) Debian Nov 19 17:07:57 nas tvheadend[63262]: httpc: 20 47 4E 55 2F 4C 69 6E 75 78 20 41 70 70 5F 42 GNU/Linux App_B Nov 19 17:07:57 nas tvheadend[63262]: httpc: 69 74 6E 65 73 73 2F 36 34 20 56 65 72 73 69 6F itness/64 Versio Nov 19 17:07:57 nas tvheadend[63262]: httpc: 6E 2F 31 38 2E 31 0D 0A 43 6F 6E 6E 65 63 74 69 n/18.1..Connecti Nov 19 17:07:57 nas tvheadend[63262]: httpc: 6F 6E 3A 20 63 6C 6F 73 65 0D 0A 0D 0A on: close.... Nov 19 17:07:57 nas tvheadend[63262]: httpc: 0000: add poll for input (1) Nov 19 17:07:57 nas tvheadend[63262]: httpc: 0000: client flush 0 Nov 19 17:07:57 nas tvheadend[63262]: httpc: 0000: HTTP/1.1 answer 'HTTP/1.1 200 OK' (rcseq: 0) Nov 19 17:07:57 nas tvheadend[63262]: httpc: 48 54 54 50 2F 31 2E 31 20 32 30 30 20 4F 4B 00 HTTP/1.1 200 OK. Nov 19 17:07:57 nas tvheadend[63262]: httpc: 0A 64 61 74 65 3A 20 54 75 65 2C 20 31 39 20 4E .date: Tue, 19 N Nov 19 17:07:57 nas tvheadend[63262]: httpc: 6F 76 20 32 30 31 39 20 31 36 3A 30 37 3A 35 37 ov 2019 16:07:57 Nov 19 17:07:57 nas tvheadend[63262]: httpc: 20 47 4D 54 0D 0A 73 65 72 76 65 72 3A 20 41 70 GMT..server: Ap Nov 19 17:07:57 nas tvheadend[63262]: httpc: 61 63 68 65 0D 0A 75 70 67 72 61 64 65 3A 20 68 ache..upgrade: h Nov 19 17:07:57 nas tvheadend[63262]: httpc: 32 2C 68 32 63 0D 0A 63 6F 6E 6E 65 63 74 69 6F 2,h2c..connectio Nov 19 17:07:57 nas tvheadend[63262]: httpc: 6E 3A 20 55 70 67 72 61 64 65 0D 0A 6C 61 73 74 n: Upgrade..last Nov 19 17:07:57 nas tvheadend[63262]: httpc: 2D 6D 6F 64 69 66 69 65 64 3A 20 57 65 64 2C 20 -modified: Wed, Nov 19 17:07:57 nas tvheadend[63262]: httpc: 31 33 20 4E 6F 76 20 32 30 31 39 20 31 34 3A 33 13 Nov 2019 14:3 Nov 19 17:07:57 nas tvheadend[63262]: httpc: 37 3A 35 35 20 47 4D 54 0D 0A 65 74 61 67 3A 20 7:55 GMT..etag: Nov 19 17:07:57 nas tvheadend[63262]: httpc: 22 31 34 39 35 2D 35 39 37 33 62 34 66 37 31 30 "1495-5973b4f710 Nov 19 17:07:57 nas tvheadend[63262]: httpc: 31 63 31 22 0D 0A 61 63 63 65 70 74 2D 72 61 6E 1c1"..accept-ran Nov 19 17:07:57 nas tvheadend[63262]: httpc: 67 65 73 3A 20 62 79 74 65 73 0D 0A 63 6F 6E 74 ges: bytes..cont Nov 19 17:07:57 nas tvheadend[63262]: httpc: 65 6E 74 2D 6C 65 6E 67 74 68 3A 20 35 32 36 39 ent-length: 5269 Nov 19 17:07:57 nas tvheadend[63262]: httpc: 0D 0A 63 6F 6E 74 65 6E 74 2D 74 79 70 65 3A 20 ..content-type: Nov 19 17:07:57 nas tvheadend[63262]: httpc: 61 75 64 69 6F 2F 78 2D 6D 70 65 67 75 72 6C 0D audio/x-mpegurl. Nov 19 17:07:57 nas tvheadend[63262]: httpc: 0A 73 74 72 69 63 74 2D 74 72 61 6E 73 70 6F 72 .strict-transpor Nov 19 17:07:57 nas tvheadend[63262]: httpc: 74 2D 73 65 63 75 72 69 74 79 3A 20 6D 61 78 2D t-security: max- Nov 19 17:07:57 nas tvheadend[63262]: httpc: 61 67 65 3D 33 31 35 33 36 30 30 30 3B 20 69 6E age=31536000; in Nov 19 17:07:57 nas tvheadend[63262]: httpc: 63 6C 75 64 65 53 75 62 44 6F 6D 61 69 6E 73 3B cludeSubDomains; Nov 19 17:07:57 nas tvheadend[63262]: httpc: 20 70 72 65 6C 6F 61 64 3B 0D 0A 78 2D 66 72 61 preload;..x-fra Nov 19 17:07:57 nas tvheadend[63262]: httpc: 6D 65 2D 6F 70 74 69 6F 6E 73 3A 20 53 41 4D 45 me-options: SAME Nov 19 17:07:57 nas tvheadend[63262]: httpc: 4F 52 49 47 49 4E 0D 0A 78 2D 78 73 73 2D 70 72 ORIGIN..x-xss-pr Nov 19 17:07:57 nas tvheadend[63262]: httpc: 6F 74 65 63 74 69 6F 6E 3A 20 31 3B 20 6D 6F 64 otection: 1; mod Nov 19 17:07:57 nas tvheadend[63262]: httpc: 65 3D 62 6C 6F 63 6B 0D 0A 78 2D 63 6F 6E 74 65 e=block..x-conte Nov 19 17:07:57 nas tvheadend[63262]: httpc: 6E 74 2D 74 79 70 65 2D 6F 70 74 69 6F 6E 73 3A nt-type-options: Nov 19 17:07:57 nas tvheadend[63262]: httpc: 20 6E 6F 73 6E 69 66 66 0D 0A 78 2D 72 6F 62 6F nosniff..x-robo Nov 19 17:07:57 nas tvheadend[63262]: httpc: 74 73 2D 74 61 67 3A 20 6E 6F 6E 65 00 0A 0D 0A ts-tag: none.... Nov 19 17:07:57 nas tvheadend[63262]: httpc: 0000: client flush -22 Nov 19 17:07:57 nas tvheadend[63262]: httpc: 0000: shutdown
httpc get stuck using 100% cpu until i stop tvheadend
- log without http2 module :
Nov 19 17:10:16 nas tvheadend[63568]: httpc: 0000: Connected to tv.xxxxxxxxx.com:443 Nov 19 17:10:16 nas tvheadend[63568]: httpc: 0000: sending HTTP/1.1 cmd Nov 19 17:10:16 nas tvheadend[63568]: httpc: 47 45 54 20 2F 66 72 65 65 2E 6D 33 75 20 48 54 GET /free.m3u HT Nov 19 17:10:16 nas tvheadend[63568]: httpc: 54 50 2F 31 2E 31 0D 0A 48 6F 73 74 3A 20 74 76 TP/1.1..Host: tv Nov 19 17:10:16 nas tvheadend[63568]: httpc: 2E 78 78 78 78 78 78 78 78 78 2E 63 6F 6D 0D 0A .xxxxxxxxx.com.. Nov 19 17:10:16 nas tvheadend[63568]: httpc: 55 73 65 72 2D 41 67 65 6E 74 3A 20 4B 6F 64 69 User-Agent: Kodi Nov 19 17:10:16 nas tvheadend[63568]: httpc: 2F 31 38 2E 31 20 28 58 31 31 3B 20 4C 69 6E 75 /18.1 (X11; Linu Nov 19 17:10:16 nas tvheadend[63568]: httpc: 78 20 78 38 36 5F 36 34 29 20 44 65 62 69 61 6E x x86_64) Debian Nov 19 17:10:16 nas tvheadend[63568]: httpc: 20 47 4E 55 2F 4C 69 6E 75 78 20 41 70 70 5F 42 GNU/Linux App_B Nov 19 17:10:16 nas tvheadend[63568]: httpc: 69 74 6E 65 73 73 2F 36 34 20 56 65 72 73 69 6F itness/64 Versio Nov 19 17:10:16 nas tvheadend[63568]: httpc: 6E 2F 31 38 2E 31 0D 0A 43 6F 6E 6E 65 63 74 69 n/18.1..Connecti Nov 19 17:10:16 nas tvheadend[63568]: httpc: 6F 6E 3A 20 63 6C 6F 73 65 0D 0A 0D 0A on: close.... Nov 19 17:10:16 nas tvheadend[63568]: httpc: 0000: add poll for input and output (2) Nov 19 17:10:16 nas tvheadend[63568]: httpc: 0000: add poll for input (1) Nov 19 17:10:16 nas tvheadend[63568]: httpc: 0000: client flush 0 Nov 19 17:10:16 nas tvheadend[63568]: httpc: 0000: HTTP/1.1 answer 'HTTP/1.1 200 OK' (rcseq: 0) Nov 19 17:10:16 nas tvheadend[63568]: httpc: 48 54 54 50 2F 31 2E 31 20 32 30 30 20 4F 4B 00 HTTP/1.1 200 OK. Nov 19 17:10:16 nas tvheadend[63568]: httpc: 0A 64 61 74 65 3A 20 54 75 65 2C 20 31 39 20 4E .date: Tue, 19 N Nov 19 17:10:16 nas tvheadend[63568]: httpc: 6F 76 20 32 30 31 39 20 31 36 3A 31 30 3A 31 36 ov 2019 16:10:16 Nov 19 17:10:16 nas tvheadend[63568]: httpc: 20 47 4D 54 0D 0A 73 65 72 76 65 72 3A 20 41 70 GMT..server: Ap Nov 19 17:10:16 nas tvheadend[63568]: httpc: 61 63 68 65 0D 0A 6C 61 73 74 2D 6D 6F 64 69 66 ache..last-modif Nov 19 17:10:16 nas tvheadend[63568]: httpc: 69 65 64 3A 20 57 65 64 2C 20 31 33 20 4E 6F 76 ied: Wed, 13 Nov Nov 19 17:10:16 nas tvheadend[63568]: httpc: 20 32 30 31 39 20 31 34 3A 33 37 3A 35 35 20 47 2019 14:37:55 G Nov 19 17:10:16 nas tvheadend[63568]: httpc: 4D 54 0D 0A 65 74 61 67 3A 20 22 31 34 39 35 2D MT..etag: "1495- Nov 19 17:10:16 nas tvheadend[63568]: httpc: 35 39 37 33 62 34 66 37 31 30 31 63 31 22 0D 0A 5973b4f7101c1".. Nov 19 17:10:16 nas tvheadend[63568]: httpc: 61 63 63 65 70 74 2D 72 61 6E 67 65 73 3A 20 62 accept-ranges: b Nov 19 17:10:16 nas tvheadend[63568]: httpc: 79 74 65 73 0D 0A 63 6F 6E 74 65 6E 74 2D 6C 65 ytes..content-le Nov 19 17:10:16 nas tvheadend[63568]: httpc: 6E 67 74 68 3A 20 35 32 36 39 0D 0A 63 6F 6E 74 ngth: 5269..cont Nov 19 17:10:16 nas tvheadend[63568]: httpc: 65 6E 74 2D 74 79 70 65 3A 20 61 75 64 69 6F 2F ent-type: audio/ Nov 19 17:10:16 nas tvheadend[63568]: httpc: 78 2D 6D 70 65 67 75 72 6C 0D 0A 73 74 72 69 63 x-mpegurl..stric Nov 19 17:10:16 nas tvheadend[63568]: httpc: 74 2D 74 72 61 6E 73 70 6F 72 74 2D 73 65 63 75 t-transport-secu Nov 19 17:10:16 nas tvheadend[63568]: httpc: 72 69 74 79 3A 20 6D 61 78 2D 61 67 65 3D 33 31 rity: max-age=31 Nov 19 17:10:16 nas tvheadend[63568]: httpc: 35 33 36 30 30 30 3B 20 69 6E 63 6C 75 64 65 53 536000; includeS Nov 19 17:10:16 nas tvheadend[63568]: httpc: 75 62 44 6F 6D 61 69 6E 73 3B 20 70 72 65 6C 6F ubDomains; prelo Nov 19 17:10:16 nas tvheadend[63568]: httpc: 61 64 3B 0D 0A 78 2D 66 72 61 6D 65 2D 6F 70 74 ad;..x-frame-opt Nov 19 17:10:16 nas tvheadend[63568]: httpc: 69 6F 6E 73 3A 20 53 41 4D 45 4F 52 49 47 49 4E ions: SAMEORIGIN Nov 19 17:10:16 nas tvheadend[63568]: httpc: 0D 0A 78 2D 78 73 73 2D 70 72 6F 74 65 63 74 69 ..x-xss-protecti Nov 19 17:10:16 nas tvheadend[63568]: httpc: 6F 6E 3A 20 31 3B 20 6D 6F 64 65 3D 62 6C 6F 63 on: 1; mode=bloc Nov 19 17:10:16 nas tvheadend[63568]: httpc: 6B 0D 0A 78 2D 63 6F 6E 74 65 6E 74 2D 74 79 70 k..x-content-typ Nov 19 17:10:16 nas tvheadend[63568]: httpc: 65 2D 6F 70 74 69 6F 6E 73 3A 20 6E 6F 73 6E 69 e-options: nosni Nov 19 17:10:16 nas tvheadend[63568]: httpc: 66 66 0D 0A 78 2D 72 6F 62 6F 74 73 2D 74 61 67 ff..x-robots-tag Nov 19 17:10:16 nas tvheadend[63568]: httpc: 3A 20 6E 6F 6E 65 0D 0A 63 6F 6E 6E 65 63 74 69 : none..connecti Nov 19 17:10:16 nas tvheadend[63568]: httpc: 6F 6E 3A 20 63 6C 6F 73 65 00 0A 0D 0A on: close.... Nov 19 17:10:16 nas tvheadend[63568]: httpc: 0000: data complete, finishing Nov 19 17:10:16 nas tvheadend[63568]: httpc: 0000: finishing Nov 19 17:10:16 nas tvheadend[63568]: httpc: 0000: shutdown Nov 19 17:10:16 nas tvheadend[63568]: httpc: 0000: add poll for input (0) Nov 19 17:10:16 nas tvheadend[63568]: httpc: 0000: shutdown Nov 19 17:10:16 nas tvheadend[63568]: httpc: 0000: client flush 0 Nov 19 17:10:16 nas tvheadend[63568]: httpc: 0000: Closed
Updated by Pablo R. over 5 years ago
Could you try https://tvheadend.org/projects/tvheadend/wiki/Debugging#Mutex-profiling
It could give more information on where the problem is.
Updated by Jaroslav Kysela over 5 years ago
Error -22 means -EINVAL - something wrong in the header parser code probably.
Updated by Flole Systems over 5 years ago
The -EINVAL is at httpc.c:1099, try to change line 1096 to
if (strcasecmp(p, "close") == 0 || strcasecmp(p, "upgrade") == 0)
After you verified this I can provide a PR for that (we should add a comment to why this was necessary).
Updated by Laurent H. over 5 years ago
Pablo R. wrote:
Could you try https://tvheadend.org/projects/tvheadend/wiki/Debugging#Mutex-profiling
It could give more information on where the problem is.
nc -lu -p 7777 thread: mutex 0x56552f6bdca0 at src/main.c:1224 took 184ms thread: mutex 0x56552f6bdca0 at src/input/mpegts/linuxdvb/linuxdvb_adapter.c:606 took 1615ms
but nothing more.
Updated by Laurent H. over 5 years ago
Flole Systems wrote:
The -EINVAL is at httpc.c:1099, try to change line 1096 to
[...]
After you verified this I can provide a PR for that (we should add a comment to why this was necessary).
With your patch :
diff --git a/src/httpc.c b/src/httpc.c
index 6cb4798cc..178ecbe72 100644
--- a/src/httpc.c
+++ b/src/httpc.c
@@ -1093,7 +1093,7 @@ header:
}
p = http_arg_get(&hc->hc_args, "Connection");
if (p && ver != RTSP_VERSION_1_0) {
- if (strcasecmp(p, "close") == 0)
+ if (strcasecmp(p, "close") == 0 || strcasecmp(p, "upgrade") == 0)
hc->hc_keepalive = 0;
else if (strcasecmp(p, "keep-alive")) /* no change for keep-alive */
return http_client_flush(hc, -EINVAL);
I can confirm, it works with that patch, iptv m3u are downloaded and parsed ok.
Updated by Flole Systems over 5 years ago
PR is merged. Now we still need to figure out why an invalid value causes high CPU usage but your initial problem should be fixed.
Updated by Laurent H. over 5 years ago
Thanks, let me know if you need me to do some tests.
Actions