search

savonet / liquidsoap

Liquidsoap is a statically typed scripting general-purpose language with dedicated operators and backend for all thing media, streaming, file generation, automation, HTTP backend and more.
http://liquidsoap.info
GNU General Public License v2.0
1.4k stars 130 forks source link

Single source fail on http request #62

Closed bla-ckbox closed 8 years ago

bla-ckbox commented 11 years ago

Single source fail on http request with message ' [request:3] Read permission denied for "URI"! '

#!/usr/local/bin/liquidsoap
set("log.level",3)
set("log.file.path","/var/log/liquidsoap/<script>.log")

secours = single(id="Secours", "/etc/liquidsoap/sounds/default.mp3")
chan_actu = single(id="chan_actu", timeout=5.0, 'http://xxx.youtaz.net/sched/3.ogg')

mystream = fallback(id="Fallback", track_sensitive = false, [chan_actu, secours])
output.dummy(id="output", mystream)
2013/04/23 15:03:45 >>> LOG START
2013/04/23 15:03:45 [protocols.external:3] Found "/usr/bin/wget".
2013/04/23 15:03:45 [main:3] Liquidsoap 1.1.0
2013/04/23 15:03:45 [main:3] Using: graphics=[distributed with Ocaml] pcre=6.2.5 dtools=0.3.0 duppy=0.5.0 duppy.syntax=0.5.0 cry=0.2.2 mm=0.2.1 xmlplaylist=0.1.3 lastfm=0.3.0 ogg=0.4.4 vorbis=0.6.1 speex=0.2.0 mad=0.4.4 flac=0.1.1 flac.ogg=0.1.1 dynlink=[distributed with Ocaml] lame=0.3.1 theora=0.3.0 ao=0.2.0 samplerate=0.1.2 taglib=0.3.0 camomile=0.8.3
2013/04/23 15:03:45 [decoder:3] Method "MAD" accepted "/etc/liquidsoap/sounds/default.mp3".
2013/04/23 15:03:45 [single:3] "/etc/liquidsoap/sounds/default.mp3" is static, resolving once for all...
2013/04/23 15:03:45 [frame:3] Using 44100Hz audio, 25Hz video, 44100Hz master.
2013/04/23 15:03:45 [frame:3] Frame size must be a multiple of 1764 ticks = 1764 audio samples = 1 video samples.
2013/04/23 15:03:45 [frame:3] Targetting 'frame.duration': 0.04s = 1764 audio samples = 1764 ticks.
2013/04/23 15:03:45 [frame:3] Frames last 0.04s = 1764 audio samples = 1 video samples = 1764 ticks.
2013/04/23 15:03:45 [single:3] "http://xxx.youtaz.net/sched/3.ogg" will be queued.
2013/04/23 15:03:45 [threads:3] Created thread "generic queue #1".
2013/04/23 15:03:45 [threads:3] Created thread "generic queue #2".
2013/04/23 15:03:45 [request:3] Read permission denied for "http://xxx.youtaz.net/sched/3.ogg"!
2013/04/23 15:03:45 [Secours:3] Prepared "/etc/liquidsoap/sounds/default.mp3" (RID 0).
2013/04/23 15:03:45 [request:3] Read permission denied for "http://a.youtaz.net/sched/3.ogg"!
2013/04/23 15:03:45 [threads:3] Created thread "wallclock_main" (1 total).
2013/04/23 15:03:45 [clock.wallclock_main:3] Streaming loop starts, synchronized with wallclock.
2013/04/23 15:03:45 [request:3] Read permission denied for "http://xxx.youtaz.net/sched/3.ogg"!
2013/04/23 15:03:45 [request:3] Read permission denied for "http://xxx.youtaz.net/sched/3.ogg"!
2013/04/23 15:03:45 [Fallback:3] Switch to Secours.
smimram commented 11 years ago

Hi,

Could please show us the log with set("log.level",5)? My first guess would be that the file is downloaded in /tmp but you don't have reading rights in this folder, or something like this...

bla-ckbox commented 11 years ago

There is no trace of the download in the http access log and no tmp file. The error is returned by "local_check" function called by "push_indicators" (request.ml).

Script with log level 5:

set("log.level",5)
chan_actu = mksafe(single(id="chan_actu", timeout=5.0, 'http://a.youtaz.net/sched/3.ogg'))
output.dummy(id="output", chan_actu)

Log

2013/04/24 15:04:21 >>> LOG START
2013/04/24 15:04:21 [protocols.external:3] Found "/usr/bin/wget".
2013/04/24 15:04:21 [main:3] Liquidsoap 1.1.0
2013/04/24 15:04:21 [main:3] Using: graphics=[distributed with Ocaml] pcre=6.2.5 dtools=0.3.0 duppy=0.5.0 duppy.syntax=0.5.0 cry=0.2.2 mm=0.2.1 xmlplaylist=0.1.3 lastfm=0.3.0 ogg=0.4.4 vorbis=0.6.1 speex=0.2.0 mad=0.4.4 flac=0.1.1 flac.ogg=0.1.1 dynlink=[distributed with Ocaml] lame=0.3.1 theora=0.3.0 ao=0.2.0 samplerate=0.1.2 taglib=0.3.0 camomile=0.8.3
2013/04/24 15:04:21 [single:3] "http://a.youtaz.net/sched/3.ogg" will be queued.
2013/04/24 15:04:21 [frame:3] Using 44100Hz audio, 25Hz video, 44100Hz master.
2013/04/24 15:04:21 [frame:3] Frame size must be a multiple of 1764 ticks = 1764 audio samples = 1 video samples.
2013/04/24 15:04:21 [frame:3] Targetting 'frame.duration': 0.04s = 1764 audio samples = 1764 ticks.
2013/04/24 15:04:21 [frame:3] Frames last 0.04s = 1764 audio samples = 1 video samples = 1764 ticks.
2013/04/24 15:04:21 [video.converter:4] Couldn't find preferred video converter: gavl.
2013/04/24 15:04:21 [audio.converter:4] Using preferred samplerate converter: libsamplerate.
2013/04/24 15:04:21 [threads:3] Created thread "generic queue #1".
2013/04/24 15:04:21 [threads:3] Created thread "generic queue #2".
2013/04/24 15:04:21 [clock:4] Currently 1 clocks allocated.
2013/04/24 15:04:21 [clock.wallclock_main:4] Starting 1 sources...
2013/04/24 15:04:21 [source:4] Source output gets up.
2013/04/24 15:04:21 [source:4] Source mksafe gets up.
2013/04/24 15:04:21 [source:4] Source chan_actu gets up.
2013/04/24 15:04:21 [chan_actu:4] Content kind is {audio=2;video=0;midi=0}.
2013/04/24 15:04:21 [chan_actu:4] Activations changed: static=[], dynamic=[mksafe:output:output].
2013/04/24 15:04:21 [request:3] Read permission denied for "http://a.youtaz.net/sched/3.ogg"!
2013/04/24 15:04:21 [source:4] Source safe_blank gets up.
2013/04/24 15:04:21 [safe_blank:4] Content kind is {audio=2;video=0;midi=0}.
2013/04/24 15:04:21 [safe_blank:4] Activations changed: static=[], dynamic=[mksafe:output:output].
2013/04/24 15:04:21 [request:3] Read permission denied for "http://a.youtaz.net/sched/3.ogg"!
2013/04/24 15:04:21 [request:3] Read permission denied for "http://a.youtaz.net/sched/3.ogg"!
2013/04/24 15:04:21 [mksafe:4] Activations changed: static=[output:output], dynamic=[].
2013/04/24 15:04:21 [request:3] Read permission denied for "http://a.youtaz.net/sched/3.ogg"!
2013/04/24 15:04:21 [chan_actu:5] Queue is empty!
2013/04/24 15:04:21 [chan_actu:5] Failed to prepare track: no file.
2013/04/24 15:04:21 [output:4] Activations changed: static=[output], dynamic=[].
2013/04/24 15:04:21 [output:4] Enabling caching mode: active source.
2013/04/24 15:04:21 [threads:3] Created thread "wallclock_main" (1 total).
2013/04/24 15:04:21 [clock.wallclock_main:3] Streaming loop starts, synchronized with wallclock.
2013/04/24 15:04:21 [clock:4] Main phase starts.
2013/04/24 15:04:21 [mksafe:3] Switch to safe_blank.
2013/04/24 15:04:21 [safe_blank:4] Activations changed: static=[mksafe:output:output], dynamic=[mksafe:output:output].
2013/04/24 15:04:21 [chan_actu:5] Queue is empty!
2013/04/24 15:04:21 [chan_actu:5] Failed to prepare track: no file.
2013/04/24 15:04:21 [chan_actu:5] Queue is empty!
2013/04/24 15:04:21 [chan_actu:5] Failed to prepare track: no file.
2013/04/24 15:04:21 [chan_actu:5] Queue is empty!
2013/04/24 15:04:21 [chan_actu:5] Failed to prepare track: no file.
2013/04/24 15:04:21 [chan_actu:5] Queue is empty!
...

No rights problems:

[root@ks3311886 tmp]# sudo -u 'liquidsoap' wget http://a.youtaz.net/sched/3.ogg
--2013-04-25 09:23:46--  http://a.youtaz.net/sched/3.ogg
Résolution de a.youtaz.net... 127.0.0.1
Connexion vers a.youtaz.net|127.0.0.1|:80...connecté.
requête HTTP transmise, en attente de la réponse...200 OK
Longueur: 3422894 (3,3M) [audio/ogg]
Sauvegarde en : «3.ogg»

100%[====================================================================================================================>] 3 422 894   --.-K/s   ds 0,03s

2013-04-25 09:23:46 (120 MB/s) - «3.ogg» sauvegardé [3422894/3422894]

[root@ks3311886 tmp]# ll 3.ogg
-rw-r--r-- 1 liquidsoap liquidsoap 3422894 23 avril 13:09 3.ogg
[root@ks3311886 tmp]# ls -la /tmp
drwxrwxrwt  5 root       root          4096 25 avril 09:25 .
toots commented 11 years ago

Hi,

That's indeed a weird issue.

Using telnet and request.all, request.trace, you should be able to obtain more information regarding the request resolution, including the temporary file it was downloaded into. Could you please post this information?

Also, what OS do you run?

Thanks!

bla-ckbox commented 11 years ago

the problem is identified, finally it was a rights issue: when liquidsoap is launched with sudo from a user homedir (or dir without liquidsoap read/execute rights), it can not write to tmp...

does not work: [blagrange@my-srv ~]# sudo -u 'liquidsoap' /usr/local/liquidsoap/bin/liquidsoap /etc/liquidsoap/youtaz.liq --debug --verbose

works (cd /tmp): [blagrange@my-srv tmp]$ sudo -u 'liquidsoap' /usr/local/liquidsoap/bin/liquidsoap /etc/liquidsoap/youtaz.liq --debug --verbose

or works in daemon [blagrange@my-srv ~]# sudo -u 'liquidsoap' /usr/local/liquidsoap/bin/liquidsoap /etc/liquidsoap/youtaz.liq --daemon

OS:

CentOS release 6.4 (Final)
Linux my-srv 3.2.13-grsec-xxxx-grs-ipv6-64 #1 SMP Thu Mar 29 09:48:59 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux

Request.trace provide no information:

request.all
402 401 400 399 398 397 396 395 394 393 392 391 390 389 388 387 386 385 384 383 382 381 380 379 378 377 376 375 374 373 372 371 370 369 368 367 366 365 364 363 362 361 360 359 358 357 356 355 354 353 352 351 350 349 348 347 346 345 344 343 342 341 340 339 338 337 336 335 334 333 332 331 330 329 328 327 326 325 324 323 322 321 320 319 318 317 316 315 314 313 312 311 310 309 308 307 306 305 304 303 302 301 300 299 298 297 296 295 294 293 292 291 290 289 288 287 286 285 284 283 282 281 280 279 278 277 276 275 274 273 272 271 270 269 268 267 266 265 264 263 262 261 260 259 258 257 256 255 254 253 252 251 250 249 248 247 246 245 244 243 242 241 240 239 238 237 236 235 234 233 232 231 230 229 228 227 226 225 224 223 222 221 220 219 218 217 216 215 214 213 212 211 210 209 208 207 206 205 204 203 202 201 200 199 198 197 196 195 194 193 192 191 190 189 188 187 186 185 184 183 182 181 180 583 179 582 178 581 177 580 176 579 175 578 174 577 173 576 172 575 171 574 170 573 169 572 168 571 167 570 166 569 165 568 164 567 163 566 162 565 161 564 160 563 159 562 158 561 157 560 156 559 155 558 154 557 153 556 152 555 151 554 150 553 149 552 148 551 147 550 146 549 145 548 144 547 143 546 142 545 141 544 140 543 139 542 138 541 137 540 136 539 135 538 134 537 133 536 132 535 131 534 130 533 129 532 128 531 127 530 126 529 125 528 124 527 123 526 122 525 121 524 120 523 119 522 118 521 117 520 116 519 115 518 114 517 113 516 112 515 111 514 110 513 109 512 108 511 107 510 106 509 105 508 104 507 103 506 102 505 101 504 100 503 99 502 98 501 97 500 96 499 95 498 94 497 93 496 92 495 91 494 90 493 89 492 88 491 87 490 86 489 85 488 84 487 83 486 82 485 81 484 80 483 79 482 78 481 77 480 76 479 75 478 74 477 73 476 72 475 71 474 70 473 69 472 68 471 67 470 66 469 65 468 64 467 63 466 62 465 61 464 60 463 59 462 58 461 57 460 56 459 55 458 54 457 53 456 52 455 51 454 50 453 49 452 48 451 47 450 46 449 45 448 44 447 43 446 42 445 41 444 40 443 39 442 38 441 37 440 36 439 35 438 34 437 33 436 32 435 31 434 30 433 29 432 28 431 27 430 26 429 25 428 24 427 23 426 22 425 21 424 20 423 19 422 18 421 17 420 16 419 15 418 14 417 13 416 12 415 11 414 10 413 9 412 8 411 7 410 6 409 5 408 4 407 3 406 2 405 1 404 0 403
END
request.resolving 571

END
[blagrange@my-srv ~]# sudo -u 'liquidsoap' /usr/local/liquidsoap/bin/liquidsoap -r http://a.youtaz.net/sched/Actu.mp3 --debug --verbose
Request resolution failed.
[blagrange@my-srv ~]# cd /
[blagrange@my-srv /]# sudo -u 'liquidsoap' /usr/local/liquidsoap/bin/liquidsoap -r http://a.youtaz.net/sched/Actu.mp3 --debug --verbose
Request resolved.
title="Firefly"
temporary="true"
decoder="MAD"
artist="The White Panda"
track="0"
kind="{audio=0+;video=0+;midi=0+}"
rid="0"
initial_uri="http://a.youtaz.net/sched/Actu.mp3"
year="0"
status="ready"
filename="/tmp/liqec67c0.mp3"
comment="ytid=371; http://hypem.com/track/1tqfv/"
Computing duration: 220.91 sec.
smimram commented 9 years ago

The issue is very old, please reopen if you still face it.