[SOLVED] Problems with new router

Help and Support Help
1

Hi

I have just changed my router (to Vodafone H500-s). I have Volumio on a Raspberry Pi Zero and on an Intel Atom netbook. After the change I can no longer play BBC radio streams. I can play other radio streams on Volumio, and I can play the BBC radio streams on other computers connected to the new router.

I also noticed that the ‘Check Updates’ button doesn’t work on either of the Volumio machines (I had previously used it on the Pi, so it used to work there).

In case it related to issues that had been fixed, I flashed the Raspberry Pi SD Card with Volumio 2.310, with the same results.

The router has an option called SecureDNS, which appears to block DNS lookups from alternative DNS servers. I have turned this off and Volumio is using the OpenDNS servers, but the results are the same.

Here are the logs from trying to playing a BBC Radio 1 stream that doesn’t work. In the GUI I see a red box that says “error: failed to decode http:…: got HTTP Status 0”. EDIT: The radio stream is: bbcmedia.ic.llnwd.net/stream/bbc … adio1_mf_p

2017-11-16T09:04:34.238Z - info: CoreCommandRouter::volumioAddQueueItems
2017-11-16T09:04:34.247Z - info: [1510823074240] CoreStateMachine::addQueueItems
2017-11-16T09:04:34.253Z - info: [1510823074248] CorePlayQueue::addQueueItems
2017-11-16T09:04:34.259Z - info: Adding Item to queue: http://bbcmedia.ic.llnwd.net/stream/bbcmedia_radio1_mf_p
2017-11-16T09:04:34.263Z - info: [1510823074261] CorePlayQueue::saveQueue
2017-11-16T09:04:34.276Z - info: CoreCommandRouter::volumioPushQueue
2017-11-16T09:04:34.283Z - info: [1510823074278] interfaceApi::pushQueue
2017-11-16T09:04:34.290Z - info: [1510823074285] InterfaceWebUI::pushQueue
2017-11-16T09:04:34.322Z - info: [1510823074316] CoreStateMachine::updateTrackBlock
2017-11-16T09:04:34.328Z - info: [1510823074323] CorePlayQueue::getTrackBlock
2017-11-16T09:04:34.336Z - info: CoreCommandRouter::volumioPlay
2017-11-16T09:04:34.343Z - info: [1510823074341] CoreStateMachine::play index 20
2017-11-16T09:04:34.346Z - info: [1510823074343] CoreStateMachine::setConsumeUpdateService undefined
2017-11-16T09:04:34.356Z - info: [1510823074347] CoreStateMachine::stop
2017-11-16T09:04:34.362Z - info: [1510823074357] CoreStateMachine::setConsumeUpdateService undefined
2017-11-16T09:04:34.367Z - info: [1510823074364] CoreStateMachine::play index undefined
2017-11-16T09:04:34.379Z - info: [1510823074367] CoreStateMachine::setConsumeUpdateService undefined
2017-11-16T09:04:34.383Z - info: [1510823074381] CorePlayQueue::getTrack 20
2017-11-16T09:04:34.386Z - info: [1510823074384] CoreStateMachine::startPlaybackTimer
2017-11-16T09:04:34.398Z - info: [1510823074387] CorePlayQueue::getTrack 20
2017-11-16T09:04:34.402Z - info: [1510823074400] ControllerWebradio::clearAddPlayTrack
2017-11-16T09:04:34.405Z - info: [1510823074403] ControllerMpd::sendMpdCommand stop
2017-11-16T09:04:34.431Z - info: [1510823074425] sending command...
2017-11-16T09:04:34.452Z - info: [1510823074446] parsing response...
2017-11-16T09:04:34.459Z - info: [1510823074453] ControllerMpd::sendMpdCommand clear
2017-11-16T09:04:34.462Z - info: [1510823074460] sending command...
2017-11-16T09:04:34.498Z - info: 
[1510823074493] ---------------------------- MPD announces system state update
2017-11-16T09:04:34.502Z - info: Mpd Status Update: playlist
2017-11-16T09:04:34.505Z - info: 
[1510823074503] ---------------------------- MPD announces state update
2017-11-16T09:04:34.521Z - info: [1510823074519] parsing response...
2017-11-16T09:04:34.525Z - info: [1510823074523] ControllerMpd::getState
2017-11-16T09:04:34.540Z - info: [1510823074526] ControllerMpd::sendMpdCommand status
2017-11-16T09:04:34.543Z - info: [1510823074541] ControllerMpd::sendMpdCommand load "http://bbcmedia.ic.llnwd.net/stream/bbcmedia_radio1_mf_p"
2017-11-16T09:04:34.556Z - info: [1510823074554] sending command...
2017-11-16T09:04:34.570Z - info: [1510823074564] sending command...
2017-11-16T09:04:34.586Z - info: 
2017-11-16T09:04:34.603Z - info: [1510823074591] ------------------------------ 98ms
2017-11-16T09:04:34.610Z - info: [1510823074604] parsing response...
2017-11-16T09:04:34.618Z - info: [1510823074613] ControllerMpd::parseState
2017-11-16T09:04:34.625Z - info: [1510823074620] ControllerMpd::pushState
2017-11-16T09:04:34.632Z - info: CoreCommandRouter::servicePushState
2017-11-16T09:04:34.636Z - info: [1510823074632] CoreStateMachine::syncState
2017-11-16T09:04:34.641Z - info: [1510823074637] CorePlayQueue::getTrack 20
2017-11-16T09:04:34.643Z - info: [1510823074642] Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd
2017-11-16T09:04:34.652Z - info: [1510823074648] ------------------------------ 148ms
2017-11-16T09:04:34.668Z - info: [1510823074664] ControllerMpd::sendMpdCommand add "http://bbcmedia.ic.llnwd.net/stream/bbcmedia_radio1_mf_p"
2017-11-16T09:04:34.673Z - info: [1510823074669] sending command...
2017-11-16T09:04:34.687Z - info: 
[1510823074680] ---------------------------- MPD announces system state update
2017-11-16T09:04:34.692Z - info: Mpd Status Update: playlist
2017-11-16T09:04:34.694Z - info: 
[1510823074692] ---------------------------- MPD announces state update
2017-11-16T09:04:34.700Z - info: [1510823074698] parsing response...
2017-11-16T09:04:34.703Z - info: [1510823074701] ControllerMpd::getState
2017-11-16T09:04:34.705Z - info: [1510823074704] ControllerMpd::sendMpdCommand status
2017-11-16T09:04:34.708Z - info: [1510823074706] CoreStateMachine::setConsumeUpdateService mpd
2017-11-16T09:04:34.720Z - info: [1510823074719] ControllerMpd::sendMpdCommand play
2017-11-16T09:04:34.731Z - info: [1510823074727] sending command...
2017-11-16T09:04:34.739Z - info: [1510823074734] sending command...
2017-11-16T09:04:34.775Z - info: [1510823074771] ------------------------------ 91ms
2017-11-16T09:04:34.780Z - info: [1510823074776] parsing response...
2017-11-16T09:04:34.785Z - info: [1510823074781] parsing response...
2017-11-16T09:04:34.790Z - info: [1510823074786] ControllerMpd::parseState
2017-11-16T09:04:34.796Z - info: [1510823074792] ControllerMpd::pushState
2017-11-16T09:04:34.800Z - info: CoreCommandRouter::servicePushState
2017-11-16T09:04:34.805Z - info: [1510823074801] CoreStateMachine::syncState
2017-11-16T09:04:34.810Z - info: [1510823074806] CorePlayQueue::getTrack 20
2017-11-16T09:04:34.815Z - info: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null}
2017-11-16T09:04:34.820Z - info: CURRENT POSITION 20
2017-11-16T09:04:34.825Z - info: [1510823074821] CoreStateMachine::syncState   stateService stop
2017-11-16T09:04:34.827Z - info: [1510823074825] CoreStateMachine::syncState   currentStatus stop
2017-11-16T09:04:34.832Z - info: [1510823074827] CoreStateMachine::pushState
2017-11-16T09:04:34.834Z - info: [1510823074832] CoreStateMachine::getState
2017-11-16T09:04:34.836Z - info: CoreCommandRouter::volumioPushState
2017-11-16T09:04:34.838Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2017-11-16T09:04:34.854Z - info: [1510823074850] interfaceApi::pushState
2017-11-16T09:04:34.859Z - info: [1510823074855] InterfaceWebUI::pushState
2017-11-16T09:04:34.914Z - info: [1510823074910] No code
2017-11-16T09:04:34.919Z - info: [1510823074915] CoreStateMachine::pushState
2017-11-16T09:04:34.923Z - info: [1510823074919] CoreStateMachine::getState
2017-11-16T09:04:34.928Z - info: CoreCommandRouter::volumioPushState
2017-11-16T09:04:34.933Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2017-11-16T09:04:34.940Z - info: [1510823074936] interfaceApi::pushState
2017-11-16T09:04:34.945Z - info: [1510823074940] InterfaceWebUI::pushState
2017-11-16T09:04:35.007Z - info: [1510823075003] ------------------------------ 315ms
2017-11-16T09:04:35.035Z - info: Pushing Favourites {"service":"webradio","uri":"http://51.15.169.131:80/stream/2/","favourite":false}
2017-11-16T09:04:35.056Z - info: Pushing Favourites {"service":"webradio","uri":"http://51.15.169.131:80/stream/2/","favourite":false}
2017-11-16T09:04:35.072Z - info: Mpd Status Update: player
2017-11-16T09:04:35.078Z - info: 
[1510823075073] ---------------------------- MPD announces state update
2017-11-16T09:04:35.086Z - info: [1510823075082] ControllerMpd::getState
2017-11-16T09:04:35.091Z - info: [1510823075087] ControllerMpd::sendMpdCommand status
2017-11-16T09:04:35.096Z - info: [1510823075092] sending command...
2017-11-16T09:04:35.159Z - info: [1510823075154] parsing response...
2017-11-16T09:04:35.177Z - info: [1510823075171] ControllerMpd::sendMpdCommand clearerror
2017-11-16T09:04:35.183Z - info: [1510823075179] sending command...
2017-11-16T09:04:35.190Z - info: [1510823075186] ControllerMpd::parseState
2017-11-16T09:04:35.194Z - info: [1510823075190] ControllerMpd::sendMpdCommand playlistinfo
2017-11-16T09:04:35.200Z - info: [1510823075196] sending command...
2017-11-16T09:04:35.228Z - info: [1510823075212] parsing response...
2017-11-16T09:04:35.238Z - info: [1510823075229] parsing response...
2017-11-16T09:04:35.249Z - info: [1510823075240] ControllerMpd::parseTrackInfo
2017-11-16T09:04:35.254Z - info: [1510823075250] ControllerMpd::pushState
2017-11-16T09:04:35.269Z - info: CoreCommandRouter::servicePushState
2017-11-16T09:04:35.273Z - info: [1510823075269] CoreStateMachine::syncState
2017-11-16T09:04:35.278Z - info: [1510823075274] CorePlayQueue::getTrack 20
2017-11-16T09:04:35.283Z - info: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"isStreaming":false,"title":"bbcmedia_radio1_mf_p","artist":null,"album":null,"uri":"http://bbcmedia.ic.llnwd.net/stream/bbcmedia_radio1_mf_p","trackType":"net/stream/bbcmedia_radio1_mf_p"}
2017-11-16T09:04:35.288Z - info: CURRENT POSITION 20
2017-11-16T09:04:35.298Z - info: [1510823075289] CoreStateMachine::syncState   stateService stop
2017-11-16T09:04:35.303Z - info: [1510823075299] CoreStateMachine::syncState   currentStatus stop
2017-11-16T09:04:35.305Z - info: [1510823075304] CoreStateMachine::pushState
2017-11-16T09:04:35.307Z - info: [1510823075306] CoreStateMachine::getState
2017-11-16T09:04:35.320Z - info: CoreCommandRouter::volumioPushState
2017-11-16T09:04:35.322Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2017-11-16T09:04:35.326Z - info: [1510823075324] interfaceApi::pushState
2017-11-16T09:04:35.348Z - info: [1510823075327] InterfaceWebUI::pushState
2017-11-16T09:04:35.430Z - info: [1510823075425] No code
2017-11-16T09:04:35.434Z - info: [1510823075430] CoreStateMachine::pushState
2017-11-16T09:04:35.439Z - info: [1510823075435] CoreStateMachine::getState
2017-11-16T09:04:35.444Z - info: CoreCommandRouter::volumioPushState
2017-11-16T09:04:35.450Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2017-11-16T09:04:35.457Z - info: [1510823075453] interfaceApi::pushState
2017-11-16T09:04:35.462Z - info: [1510823075458] InterfaceWebUI::pushState
2017-11-16T09:04:35.525Z - info: [1510823075521] ------------------------------ 452ms
2017-11-16T09:04:35.587Z - info: Pushing Favourites {"service":"webradio","uri":"http://51.15.169.131:80/stream/2/","favourite":false}
2017-11-16T09:04:35.606Z - info: Pushing Favourites {"service":"webradio","uri":"http://51.15.169.131:80/stream/2/","favourite":false}

I tried to upload the log from the DEV page but this does not complete. Here is the relavent message from the logs

2017-11-16T09:12:04.616Z - info: CALLMETHOD: system_controller system sendBugReport [object Object]
2017-11-16T09:12:04.625Z - info: CoreCommandRouter::executeOnPlugin: system , sendBugReport
2017-11-16T09:12:09.698Z - info: Log sent successfully, reply: Cannot send bug report: Error: Command failed: /usr/bin/curl -X POST -H 'Content-Type: multipart/form-data' -F 'logFile=@/tmp/logondemand' -F desc='Sending log report, please wait' -F 'variant=volumio' 'http://logs.volumio.org:7171/logs/v1'
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0curl: (7) Failed to connect to logs.volumio.org port 7171: Connection refused

The update button is completely inactive at the moment (no logs), but I have previously seen it blink, and the log message was the same as I have seen in a couple of other posts

- info: Sending updateCheck to server
- info: Update Check error: [object Object]

Thanks

Adrian.

2

When I start up the Pi I notice a tracking call that is failing. I try to run it manually with a verbosity option and it fails like this

/usr/bin/curl -v -X POST --data-binary "device=pi&variante=volumio&version=2.310&uuid=4f3121af44b27d6f7fe125d11a5d7dcd" http://updates.volumio.org:7070/downloader-v1/track-device
* Hostname was NOT found in DNS cache
*   Trying 192.168.0.1...
* connect to 192.168.0.1 port 7070 failed: Connection refused
* Failed to connect to updates.volumio.org port 7070: Connection refused
* Closing connection 0
curl: (7) Failed to connect to updates.volumio.org port 7070: Connection refused

EDIT: 192.168.0.1 is the router.

I cut and paste the same command into a terminal on a PC running Ubuntu, connected to the same router, also by wifi, and it succeeds like this

/usr/bin/curl -v -X POST --data-binary "device=pi&variante=volumio&version=2.310&uuid=4f3121af44b27d6f7fe125d11a5d7dcd" http://updates.volumio.org:7070/downloader-v1/track-device
Note: Unnecessary use of -X or --request, POST is already inferred.
*   Trying 149.210.234.235...
* Connected to updates.volumio.org (149.210.234.235) port 7070 (#0)

Does anyone have any thoughts? I guess this is the same issue that is disabling “Check Updates”, but could it also be what is stopping the BBC Radio streams from working?

Adrian.

3

Yes it seems your PI cannot access the internet. Did you set up manual IP address?

4

The Pi is assigned an address by the router. It can access some sites on the internet, but not others, e.g. it can access volumio.org, but not updates.volumio.org

volumio@volumio:~$ wget www.volumio.org
converted 'http://www.volumio.org' (ANSI_X3.4-1968) -> 'http://www.volumio.org' (UTF-8)
--2017-11-16 21:20:17--  http://www.volumio.org/
Resolving www.volumio.org (www.volumio.org)... 80.69.77.195
Connecting to www.volumio.org (www.volumio.org)|80.69.77.195|:80... connected.
HTTP request sent, awaiting response... 301 Moved Permanently
Location: https://volumio.org/ [following]
converted 'https://volumio.org/' (ANSI_X3.4-1968) -> 'https://volumio.org/' (UTF-8)
--2017-11-16 21:20:18--  https://volumio.org/
Resolving volumio.org (volumio.org)... 80.69.77.195
Connecting to volumio.org (volumio.org)|80.69.77.195|:443... connected.
HTTP request sent, awaiting response... 200 OK
Length: unspecified [text/html]
Saving to: 'index.html.5'

index.html.5            [     <=>              ] 666.67K   677KB/s   in 1.0s   

2017-11-16 21:20:20 (677 KB/s) - 'index.html.5' saved [682670]

volumio@volumio:~$ wget updates.volumio.orgconverted 'http://updates.volumio.org' (ANSI_X3.4-1968) -> 'http://updates.volumio.org' (UTF-8)
--2017-11-16 21:20:28--  http://updates.volumio.org/
Resolving updates.volumio.org (updates.volumio.org)... 192.168.0.1
Connecting to updates.volumio.org (updates.volumio.org)|192.168.0.1|:80... connected.
HTTP request sent, awaiting response... 200 No headers, assuming HTTP/0.9
Length: unspecified
Saving to: 'index.html.6'

index.html.6            [ <=>                  ]     588  --.-KB/s   in 0s     

2017-11-16 21:20:29 (7.28 MB/s) - 'index.html.6' saved [588]

Adrian.

5

The following looks like the same issue (although appears to be reported as fixed): github.com/volumio/Volumio2/issues/791

EDIT: As per the bug report, the Pi can resolve updates.volumio.org on the command line with the host command

volumio@volumio:~$ host updates.volumio.org    
updates.volumio.org has address 149.210.234.235

I get the same results for my Intel netbook running Volumio when trying to wget volumio.org and updates.volumio.org that I posted for the Pi in my last message.

Testing on the Pi… Invalid names will resolve. E.g.

wget invalid.xinvalid   
converted 'http://invalid.xinvalid' (ANSI_X3.4-1968) -> 'http://invalid.xinvalid' (UTF-8)
--2017-11-17 06:37:49--  http://invalid.xinvalid/
Resolving invalid.xinvalid (invalid.xinvalid)... 192.168.0.1
Connecting to invalid.xinvalid (invalid.xinvalid)|192.168.0.1|:80... connected.
HTTP request sent, awaiting response... 200 No headers, assuming HTTP/0.9
Length: unspecified
Saving to: 'index.html.9'

index.html.9            [ <=>                  ]     588  --.-KB/s   in 0s     

2017-11-17 06:37:50 (6.03 MB/s) - 'index.html.9' saved [588]

Here is the file that is returned

UNKNOWN 400 Bad Request
Server: 
Date: Fri, 17 Nov 2017 07:37:52 GMT
Cache-Control: no-cache,no-store,max-age=0
Prama: no-cache
X-Frame-Options: DENY
Expires: 0
X-Content-Type-Options: nosniff
X-XSS-Protection: 1; mode=block
Content-Security-Policy: default-src 'self' 'unsafe-inline' 'unsafe-eval'
Content-Language: en
Content-Type: text/html
Connection: close

            <HTML>
            <HEAD><TITLE>400 Bad Request</TITLE></HEAD>
            <BODY BGCOLOR="#cc9999" TEXT="#000000" LINK="#2020ff" VLINK="#4040cc">
            <H4>400 Bad Request</H4>
Invalid Request

On an Ubuntu machine connected to the same router the invalid domain simply fails to resolve:

wget invalid.xinvalid
--2017-11-17 07:41:35--  http://invalid.xinvalid/
Resolving invalid.xinvalid (invalid.xinvalid)... failed: Name or service not known.
wget: unable to resolve host address ‘invalid.xinvalid’

The DNS resolution is the issue for the BBC Radio stations not working. If I use the IP address of the BBC streaming site rather than the domain name then the radio streams work.

Adrian.

6

I managed to find a solution. I changed the hosts line in /etc/nsswitch.conf and moved dns from last to second position, so it looks like

hosts:          files dns mdns4_minimal [NOTFOUND=return] wins

The BBC Radio streams now work, and the Check Updates button now works.

Here is wget updates.volumio.org now working

[code]volumio@volumio:~$ wget updates.volumio.org
converted ‘http://updates.volumio.org’ (ANSI_X3.4-1968) -> ‘http://updates.volumio.org’ (UTF-8)
–2017-11-17 10:29:14-- http://updates.volumio.org/
Resolving updates.volumio.org (updates.volumio.org)… 149.210.234.235
Connecting to updates.volumio.org (updates.volumio.org)|149.210.234.235|:80… connected.
HTTP request sent, awaiting response… 200 OK
Length: unspecified [text/html]
Saving to: ‘index.html.1’

index.html.1 [ <=> ] 5 --.-KB/s in 0s

2017-11-17 10:29:15 (30.7 KB/s) - ‘index.html.1’ saved [5]
[/code]
This change fixed the problems on the Pi and on the Intel Atom netbook.

Adrian.

7

Very interesting! Thanks for sharing !