icecastliquidsoap

icecast - request parsing failed


all.
I have everything installed and running, however. The Icecast2 pages are not showing anything.
No Mountpoint List
No Server Status
No nothing?
Only shows: Admin Home & Version

This is the error from the Icecast log.

EROR connection/_handle_connection HTTP request parsing failed

Here is my icecast.xml file.

<icecast>
<!-- location and admin are two arbitrary strings that are e.g. visible
     on the server info page of the icecast web interface
     (server_version.xsl). -->
<location>earth</location>
<admin>iceman@domain.com</admin>

<!-- IMPORTANT!
     Especially for inexperienced users:
     Start out by ONLY changing all passwords and restarting Icecast.
     For detailed setup instructions please refer to the documentation.
     It's also available here: http://icecast.org/docs/
-->

<limits>
    <clients>100</clients>
    <sources>2</sources>
    <queue-size>524288</queue-size>
    <client-timeout>30</client-timeout>
    <header-timeout>15</header-timeout>
    <source-timeout>10</source-timeout>
    <!-- If enabled, this will provide a burst of data when a client 
         first connects, thereby significantly reducing the startup 
         time for listeners that do substantial buffering. However,
         it also significantly increases latency between the source
         client and listening client.  For low-latency setups, you
         might want to disable this. -->
    <burst-on-connect>1</burst-on-connect>
    <!-- same as burst-on-connect, but this allows for being more
         specific on how much to burst. Most people won't need to
         change from the default 64k. Applies to all mountpoints  -->
    <burst-size>65535</burst-size>
</limits>

<authentication>
    <!-- Sources log in with username 'source' -->
    <source-password>******</source-password>
    <!-- Relays log in with username 'relay' -->
    <relay-password>*****</relay-password>

    <!-- Admin logs in with the username given below -->
    <admin-user>admin</admin-user>
    <admin-password>*****</admin-password>
</authentication>

<hostname>192.168.2.20</hostname>

<!-- You may have multiple <listener> elements -->
<listen-socket>
    <port>8000</port>
    <!-- <bind-address>192.168.2.20</bind-address> -->
    <!-- <shoutcast-mount>/stream</shoutcast-mount> -->
</listen-socket>



<!-- Global header settings 
     Headers defined here will be returned for every HTTP request to Icecast.

     The ACAO header makes Icecast public content/API by default
     This will make streams easier embeddable (some HTML5 functionality needs it).
     Also it allows direct access to e.g. /status-json.xsl from other sites.
     If you don't want this, comment out the following line or read up on CORS. 
-->
<http-headers>
    <header name="Access-Control-Allow-Origin" value="*" />
</http-headers>

<mount type="normal">
    <mount-name>/example-complex.ogg</mount-name>
</mount>

<fileserve>1</fileserve>

<paths>
    <!-- basedir is only used if chroot is enabled -->
    <basedir>/usr/share/icecast2</basedir>

    <!-- Note that if <chroot> is turned on below, these paths must both
         be relative to the new root, not the original root -->
    <logdir>/var/log/icecast2</logdir>
    <webroot>/usr/share/icecast2/web</webroot>
    <adminroot>/usr/share/icecast2/admin</adminroot>
    <!-- <pidfile>/usr/share/icecast2/icecast.pid</pidfile> -->

    <!-- Aliases: treat requests for 'source' path as being for 'dest' path
         May be made specific to a port or bound address using the "port"
         and "bind-address" attributes.
      -->
    <!--
    <alias source="/foo" destination="/bar"/>
    -->
    <!-- Aliases: can also be used for simple redirections as well,
         this example will redirect all requests for http://server:port/ to
         the status page
    -->
    <alias source="/" destination="/status.xsl"/>
    <!-- The certificate file needs to contain both public and private part.
         Both should be PEM encoded.
    <ssl-certificate>/usr/share/icecast2/icecast.pem</ssl-certificate>
    -->
</paths>

<logging>
    <accesslog>access.log</accesslog>
    <errorlog>error.log</errorlog>
    <!-- <playlistlog>playlist.log</playlistlog> -->
    <loglevel>3</loglevel> <!-- 4 Debug, 3 Info, 2 Warn, 1 Error -->
    <logsize>10000</logsize> <!-- Max size of a logfile -->
    <!-- If logarchive is enabled (1), then when logsize is reached
         the logfile will be moved to [error|access|playlist].log.DATESTAMP,
         otherwise it will be moved to [error|access|playlist].log.old.
         Default is non-archive mode (i.e. overwrite)
    -->
    <!-- <logarchive>1</logarchive> -->
</logging>

<security>
    <chroot>0</chroot>
    <!--
    <changeowner>
        <user>nobody</user>
        <group>nogroup</group>
    </changeowner>
    -->
</security>

This is my radio.liq file.

 #!/usr/bin/liquidsoap
 # Log dir
set("log.file.path","/var/log/liquidsoap/radioliq.log")

 # Music
myplaylist = playlist("/home/UserName/music-store/")
 # Some jingles
jingles = playlist("/home/UserName/music-store/jingles/jingles.m3u")
 # If something goes wrong, we'll play this
security = single("/home/UserName/music-store/Sec.mp3")

 # Start building the feed with music
radio = myplaylist
 # Now add some jingles
radio = random(weights = [1, 4],[jingles, radio])
 # And finally the security
 radio = fallback(track_sensitive = false, [radio, security])

  # Stream it out
output.icecast(%vorbis,
  radio, host = "192.168.2.20", port = 8000,
  password = "********", mount = "test.ogg")

The output of the command provided is the following:
Command used:

curl -v localhost:8000 >/dev/null

output

TCP_NODELAY set
* connect to ::1 port 8000 failed: Connection refused
*   Trying 127.0.0.1...
* TCP_NODELAY set
* Connected to localhost (127.0.0.1) port 8000 (#0)
> GET / HTTP/1.1
> Host: localhost:8000
> User-Agent: curl/7.58.0
> Accept: */*
> 
* HTTP 1.0, assume close after body
< HTTP/1.0 200 OK
< Server: Icecast 2.4.3
< Date: Sat, 09 Jun 2018 08:22:56 GMT
< Content-Type: text/xml; charset=UTF-8
< Cache-Control: no-cache
< Expires: Mon, 26 Jul 1997 05:00:00 GMT
< Pragma: no-cache
< Access-Control-Allow-Origin: *
< Content-Length: 1144
< 
{ [1144 bytes data]
100  1144  100  1144    0     0  42370      0 --:--:-- --:--:-- --:--:-- 67294
* Closing connection 0

Access log including the command run.

192.168.2.12 - - [08/Jun/2018:15:36:05 -0400] "GET /style.css HTTP/1.1" 200 4141 "http://192.168.2.20:8000/admin/listmounts.xsl" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/66.0.3359.181 Safari/537.36" 0
192.168.2.12 - - [08/Jun/2018:15:36:06 -0400] "GET /admin/stats.xsl HTTP/1.1" 200 3106 "http://192.168.2.20:8000/admin/listmounts.xsl" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/66.0.3359.181 Safari/537.36" 0
192.168.2.12 - - [08/Jun/2018:15:36:06 -0400] "GET /style.css HTTP/1.1" 200 4141 "http://192.168.2.20:8000/admin/stats.xsl" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/66.0.3359.181 Safari/537.36" 0
127.0.0.1 - - [09/Jun/2018:04:18:38 -0400] "GET / HTTP/1.1" 200 1399 "-" "curl/7.58.0" 0

Here is the START of the Error.log file.

[2018-06-08  04:52:01] INFO main/main Icecast 2.4.3 server started
[2018-06-08  04:52:01] INFO connection/get_ssl_certificate No SSL capability
[2018-06-08  04:52:01] INFO yp/yp_update_thread YP update thread started
[2018-06-08  05:26:00] INFO sighandler/_sig_die Caught signal 15, shutting down...
[2018-06-08  05:26:00] INFO main/main Shutting down
[2018-06-08  05:26:00] INFO fserve/fserve_shutdown file serving stopped
[2018-06-08  05:26:00] INFO slave/_slave_thread shutting down current relays
[2018-06-08  05:26:00] INFO slave/_slave_thread Slave thread shutdown complete
[2018-06-08  05:26:00] INFO auth/auth_shutdown Auth shutdown
[2018-06-08  05:26:00] INFO yp/yp_shutdown YP thread down
[2018-06-08  05:26:00] INFO stats/stats_shutdown stats thread finished
[2018-06-08  05:26:01] INFO main/main Icecast 2.4.3 server started
[2018-06-08  05:26:01] INFO connection/get_ssl_certificate No SSL capability
[2018-06-08  05:26:01] INFO yp/yp_update_thread YP update thread started
[2018-06-08  05:26:09] EROR connection/_handle_connection HTTP request parsing failed

I did not notice this before, but it is giving me a bad or missing password, even though it is supplied in the icecast.xml. And it is supplied in the radio.liq files as well.
The Bad or missing password on admin only happens when I log in to the admin part of the web interface.

[2018-06-09  04:31:44] INFO admin/admin_handle_request Bad or missing password on admin command request (command: )
[2018-06-09  04:31:47] EROR connection/_handle_connection HTTP request parsing failed

Liquidsoap Status

liquidsoap.service - LSB: Starts the liquidsoap daemon
   Loaded: loaded (/etc/init.d/liquidsoap; generated)
   Active: active (exited) since Sat 2018-06-09 05:31:48 EDT; 1 day 7h ago
     Docs: man:systemd-sysv-generator(8)
  Process: 4244 ExecStop=/etc/init.d/liquidsoap stop (code=exited, status=0/SUCCESS)
  Process: 4246 ExecStart=/etc/init.d/liquidsoap start (code=exited, status=0/SUCCESS)

Jun 09 05:31:48 liquid-ice systemd[1]: Starting LSB: Starts the liquidsoap daemon...
Jun 09 05:31:48 liquid-ice liquidsoap[4246]: Starting liquidsoap channels: radio.liq radio1.liq OK
Jun 09 05:31:48 liquid-ice systemd[1]: Started LSB: Starts the liquidsoap daemon.

After a reboot, the status is now

Active: active (running) since Sun 2018-06-10 13:13:25 EDT; 1h 29min ago

And still Only shows: Admin Home & Version

UPDATED
Updated to point to the log file in the Var/
This is the output, after a Reboot.

2018/06/10 19:47:50 >>> LOG START
2018/06/10 19:47:48 [protocols.external:3] Found "/usr/bin/wget".
2018/06/10 19:47:48 [main:3] Liquidsoap 1.1.1
2018/06/10 19:47:48 [main:3] Using: graphics=[distributed with Ocaml] pcre=7.2.3 
dtools=0.3.1 duppy=0.5.1 duppy.syntax=0.5.1 cry=0.2.2 mm=0.2.1 xmlplaylist=0.1.3 
lastfm=0.3.0 ogg=0.4.5 vorbis=0.6.1 opus=0.1.0 speex=0.2.0 mad=0.4.4 flac=0.1.1 
flac.ogg=0.1.1 dynlink=[distributed with Ocaml] lame=0.3.2 shine=0.2.0 
gstreamer=0.2.0 frei0r=0.1.0 voaacenc=0.1.0 theora=0.3.0 gavl=0.1.5 bjack=0.1.4 
alsa=0.2.3 ao=0.2.0 samplerate=0.1.2 taglib=0.3.1 magic=0.7.3 camomile=0.8.4 
inotify=1.0 faad=0.3.2 soundtouch=0.1.7 portaudio=0.2.0 pulseaudio=0.1.2 
ladspa=0.1.4 dssi=0.1.1 sdl=0.9.1 camlimages=4.2.0 lo=0.1.0 yojson=1.3.2 
gd=1.0a5

2018/06/10 19:47:48 [dynamic.loader:3] Could not find dynamic module for fdkaac encoder.
2018/06/10 19:47:48 [dynamic.loader:3] Could not find dynamic module for aacplus encoder.
2018/06/10 19:47:48 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/cry.cmxs.
2018/06/10 19:47:48 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/faad.cmxs.
2018/06/10 19:47:48 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/mad.cmxs.
2018/06/10 19:47:48 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/gstreamer.cmxs.
2018/06/10 19:47:48 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/frei0r.cmxs.
2018/06/10 19:47:48 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/lo.cmxs.
2018/06/10 19:47:48 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/pulseaudio.cmxs.
2018/06/10 19:47:48 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/flac.cmxs.
2018/06/10 19:47:48 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/ogg.cmxs.
2018/06/10 19:47:48 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/ao.cmxs.
2018/06/10 19:47:48 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/theora.cmxs.
2018/06/10 19:47:48 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/ladspa.cmxs.
2018/06/10 19:47:48 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/speex.cmxs.
2018/06/10 19:47:48 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/soundtouch.cmxs.
2018/06/10 19:47:48 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/gd.cmxs.
2018/06/10 19:47:49 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/sdl.cmxs.
2018/06/10 19:47:49 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/xmlplaylist.cmxs.
2018/06/10 19:47:49 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/alsa.cmxs.
2018/06/10 19:47:49 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/opus.cmxs.
2018/06/10 19:47:49 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/bjack.cmxs.
2018/06/10 19:47:49 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/gavl.cmxs.
2018/06/10 19:47:49 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/samplerate.cmxs.
2018/06/10 19:47:49 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/lame.cmxs.
2018/06/10 19:47:49 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/portaudio.cmxs.
2018/06/10 19:47:49 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/voaacenc.cmxs.
2018/06/10 19:47:49 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/lastfm.cmxs.
2018/06/10 19:47:49 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/oss.cmxs.
2018/06/10 19:47:49 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/graphics.cmxs.
2018/06/10 19:47:49 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/taglib.cmxs.
2018/06/10 19:47:49 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/camlimages.cmxs.
2018/06/10 19:47:49 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/vorbis.cmxs.
2018/06/10 19:47:49 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/shine.cmxs.
2018/06/10 19:47:49 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/dssi.cmxs.
2018/06/10 19:47:49 [dynamic.loader:2] Loaded plugin file /usr/lib/liquidsoap/1.1.1/plugins/flac_ogg.cmxs.
2018/06/10 19:47:49 [frame:3] Using 44100Hz audio, 25Hz video, 44100Hz master.
2018/06/10 19:47:49 [frame:3] Frame size must be a multiple of 1764 ticks = 1764 audio samples = 1 video samples.
2018/06/10 19:47:49 [frame:3] Targetting 'frame.duration': 0.04s = 1764 audio samples = 1764 ticks.
2018/06/10 19:47:49 [frame:3] Frames last 0.04s = 1764 audio samples = 1 video samples = 1764 ticks.
2018/06/10 19:47:50 [decoder:3] Method "MAD" accepted "/home/username/music-store/username/song01.mp3".
2018/06/10 19:47:50 [single:3] "/home/username/music-store/username/song01.mp3" is static, resolving once for all...
2018/06/10 19:47:50 [threads:3] Created thread "generic queue #1".
2018/06/10 19:47:50 [threads:3] Created thread "generic queue #2".
2018/06/10 19:47:50 [threads:3] Created thread "non-blocking queue #1".
2018/06/10 19:47:50 [threads:3] Created thread "non-blocking queue #2".
2018/06/10 19:47:50 [jingles(dot)m3u:3] Loading playlist...
2018/06/10 19:47:50 [jingles(dot)m3u:3] No mime type specified, trying autodetection.
2018/06/10 19:47:50 [jingles(dot)m3u:3] Playlist treated as format application/x-mpegURL
2018/06/10 19:47:50 [jingles(dot)m3u:3] Successfully loaded a playlist of 1 tracks.
2018/06/10 19:47:50 [username(dot)m3u:3] Loading playlist...
2018/06/10 19:47:50 [decoder:3] Method "MAD" accepted "/home/username/music-store/username/song01.mp3".
2018/06/10 19:47:50 [username(dot)m3u:3] No mime type specified, trying autodetection.
2018/06/10 19:47:50 [username(dot)m3u:3] Playlist treated as format application/x-mpegURL
2018/06/10 19:47:50 [username(dot)m3u:3] Successfully loaded a playlist of 1 tracks.
2018/06/10 19:47:50 [jingles(dot)m3u:3] Prepared "/home/username/music-store/username/song01.mp3" (RID 2).
2018/06/10 19:47:50 [test:3] Connecting mount test for source@192.168.2.20...
2018/06/10 19:47:50 [test:3] Connection setup was successful.
2018/06/10 19:47:50 [threads:3] Created thread "wallclock_main" (1 total).
2018/06/10 19:47:50 [clock.wallclock_main:3] Streaming loop starts, synchronized with wallclock.
2018/06/10 19:47:50 [decoder:3] Method "MAD" accepted "/home/username/music-store/username/song01.mp3".
2018/06/10 19:47:50 [fallback_6368:3] Switch to random_6366.
2018/06/10 19:47:50 [random_6366:3] Switch to jingles(dot)m3u.
2018/06/10 19:47:50 [clock.wallclock_main:2] Source test failed while streaming: Ogg.Not_enough_data!
2018/06/10 19:47:50 [clock.wallclock_main:3] Raised by primitive operation at file "ogg.ml", line 114, characters 2-67
2018/06/10 19:47:50 [clock.wallclock_main:3] Called from file "ogg_formats/ogg_muxer.ml", line 158, characters 12-36
2018/06/10 19:47:50 [clock.wallclock_main:3] Re-raised at file "hashtbl.ml", line 257, characters 4-13
2018/06/10 19:47:50 [clock.wallclock_main:3] Called from file "ogg_formats/ogg_muxer.ml", line 271, characters 2-234
2018/06/10 19:47:50 [clock.wallclock_main:3] Called from file "encoder/ogg_encoder.ml", line 189, characters 6-37
2018/06/10 19:47:50 [clock.wallclock_main:3] Called from file "encoder/ogg_encoder.ml", line 198, characters 8-24
2018/06/10 19:47:50 [clock.wallclock_main:3] Called from file "outputs/output.ml", line 251, characters 10-21
2018/06/10 19:47:50 [clock.wallclock_main:3] Called from file "outputs/output.ml", line 259, characters 35-47
2018/06/10 19:47:50 [clock.wallclock_main:3] Called from file "outputs/output.ml", line 175, characters 6-22
2018/06/10 19:47:50 [clock.wallclock_main:3] Called from file "clock.ml", line 160, characters 17-25
2018/06/10 19:47:50 [test:3] Closing connection...
2018/06/10 19:47:50 [jingles(dot)m3u:3] Finished with "/home/username/music-store/username/song01.mp3".
2018/06/10 19:47:50 [clock.wallclock_main:3] Streaming loop stopped.
2018/06/10 19:47:50 [main:3] Shutdown started!
2018/06/10 19:47:50 [main:3] Waiting for threads to terminate...
2018/06/10 19:47:50 [threads:3] Thread "wallclock_main" terminated (0 remaining).
2018/06/10 19:47:50 [main:3] Cleaning downloaded files...
2018/06/10 19:47:50 [main:3] Freeing memory...
2018/06/10 19:47:50 >>> LOG END

Solution

  • OK, so Icecast itself seems to be running fine. (you can see it answering a simple request for '/' from localhost) If you don't see at least the very basic web interface, please check your firewall settings and browser. Consider adding <bind-address>::</bind-address> and restarting Icecast (sudo systemctl restart icecast2.service or sudo /etc/init.d/icecast2 restart) for improved compatibility. (That will bind to IPv6 and legacy-IP aka IPv4. It's mostly cosmetic though.)

    The EROR connection/_handle_connection HTTP request parsing failed is most likely unrelated to your problems. Possibly Liquidsoap or some other process doing something stupid, but not critical.

    Make sure that Liquidsoap is using the password specified here: <source-password>******</source-password>

    Please also examine /home/username/liquidsoap-daemon/log/radioliq.log for further hints.

    Update 1

    On Debian and its derivatives (Ubuntu, Mint, etc) Liquidsoap runs as the liquidsoap user. By default this user does not have write access to /home/username/liquidsoap-daemon/log/radioliq.log. Either that directory needs write access given to that user or one might elect to use /var/log/liquidsoap which is already set up appropriately.

    If Liquidsoap can not start logging, then it will refuse to start. Just what seems to have happened here.

    There may be other problems once that's corrected, please then refer to the log for details.