Web interface is constantly rebooting since 2.452

Volumio Development Bug reports
1

Hello,

Since I updated my RPi3 to Volumio version 2.452
I have the issue that the webinterface is constantly restarting. (loading circle appears, music stops playing and GUI is reset to default screen).
Anyone who experiences the same issue?

This is on my RPi3 where the official RPi touchscreen is connected to.

I updated today to V2.457, but the issue remains.
I re-installed/reflashed already my SD-card. But with no result.

I do have another RPi3, but I didn’t dare yet to upgrade that one too.

2

This is probably related to a plugin.
Which plugin do you have installed?
Can you send a log?
volumio.github.io/docs/User_Man … oting.html

3

Hello Michelangelo

If I want to send a log it hangs on “Sending log report, please wait”. Does it send the log through a non-casual networkport?

I first thought that it was caused by a plugin. So I completely formatted my SD card and installed latest version from scratch. Went through the initial setup wizard and that’s it. But the problem remains.

4

This new version of volumio is buggy. Constant reboot when accessing my huge collection of music in NAS.
Maybe they are gearing to integrate it with Myvolumio…

5

We’ve done some change in the mpd stack to allow for bigger collections to work.
Please guys, send us logs (use chrome browser if that does not work) that’s important to understand what fails

6

v2.459 is popping into my screen as test release. Is it safe to download now?

7

Can you just send logs please?

8

I’m sorry Michelangelo. I’m a busy man. So not always the time to get busy with this.
I tried to generate log through Chrome, but that is the same. Is there a way to copy log manually. Via Putty/CLI for example?

Attached you can find a screenshot of Volumio GUI, when it’s restarting. I get this every 30(-ish) seconds.
crashvolumio.jpg

9

You can manually get logs from the CLI by using:

sudo journalctl -f

which continually echos to the console. Hopefully you could get it running before a reboot occurs.

10

Sep 22 16:46:18 katana volumio[1034]: Wrong scontrol identifier:
Sep 22 16:46:19 katana volumio[1034]: Wrong scontrol identifier:
Sep 22 16:46:20 katana volumio[1034]: Wrong scontrol identifier:
Sep 22 16:46:21 katana volumio[1034]: Wrong scontrol identifier:
Sep 22 16:46:21 katana volumio[1034]: Wrong scontrol identifier:
Sep 22 16:46:22 katana volumio[1034]: Wrong scontrol identifier:
Sep 22 16:46:23 katana volumio[1034]: Wrong scontrol identifier:
Sep 22 16:46:23 katana volumio[1034]: Wrong scontrol identifier:
Sep 22 16:46:24 katana volumio[1034]: Wrong scontrol identifier:
Sep 22 16:46:24 katana volumio[22971]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Sep 22 16:46:24 katana volumio[1034]: Wrong scontrol identifier:
Sep 22 16:46:25 katana volumio[1034]: Wrong scontrol identifier:
Sep 22 16:46:26 katana volumio[1034]: Wrong scontrol identifier:
Sep 22 16:46:26 katana volumio[22971]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Sep 22 16:46:27 katana volumio[1034]: Wrong scontrol identifier:
Sep 22 16:46:27 katana volumio[1034]: Wrong scontrol identifier:
Sep 22 16:46:28 katana volumio[22971]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Sep 22 16:46:28 katana volumio[22971]: SyntaxError: Unexpected token < in JSON at position 0
Sep 22 16:46:28 katana volumio[22971]: at JSON.parse ()
Sep 22 16:46:28 katana volumio[22971]: at IncomingMessage. (/volumio/node_modules/album-art/index.js:30:22)
Sep 22 16:46:28 katana volumio[22971]: at emitNone (events.js:111:20)
Sep 22 16:46:28 katana volumio[22971]: at IncomingMessage.emit (events.js:208:7)
Sep 22 16:46:28 katana volumio[22971]: at endReadableNT (_stream_readable.js:1064:12)
Sep 22 16:46:28 katana volumio[22971]: at _combinedTickCallback (internal/process/next_tick.js:138:11)
Sep 22 16:46:28 katana volumio[22971]: at process._tickCallback (internal/process/next_tick.js:180:9)
Sep 22 16:46:28 katana volumio[22971]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Sep 22 16:46:29 katana sudo[873]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2018-09-22 16:45
Sep 22 16:46:29 katana sudo[873]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 22 16:46:29 katana sudo[873]: pam_unix(sudo:session): session closed for user root
Sep 22 16:46:29 katana volumio-remote-updater[550]: [2018-09-22 16:46:29] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Sep 22 16:46:29 katana volumio-remote-updater[550]: [2018-09-22 16:46:29] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Sep 22 16:46:29 katana systemd[1]: volumio.service: main process exited, code=exited, status=1/FAILURE
Sep 22 16:46:29 katana systemd[1]: Unit volumio.service entered failed state.
Sep 22 16:46:29 katana systemd[1]: Starting dynamicswap service…
Sep 22 16:46:29 katana systemd[1]: Started dynamicswap service.
Sep 22 16:46:29 katana systemd[1]: volumio.service holdoff time over, scheduling restart.
Sep 22 16:46:29 katana systemd[1]: Starting dynamicswap service…
Sep 22 16:46:29 katana systemd[1]: Started dynamicswap service.
Sep 22 16:46:29 katana systemd[1]: Stopping Volumio Backend Module…
Sep 22 16:46:29 katana systemd[1]: Starting Volumio Backend Module…
Sep 22 16:46:29 katana systemd[1]: Started Volumio Backend Module.
Sep 22 16:46:32 katana volumio[899]: info: -------------------------------------------
Sep 22 16:46:32 katana volumio[899]: info: ----- Volumio2 ----
Sep 22 16:46:32 katana volumio[899]: info: -------------------------------------------
Sep 22 16:46:32 katana volumio[899]: info: ----- System startup ----
Sep 22 16:46:32 katana volumio[899]: info: -------------------------------------------
Sep 22 16:46:32 katana volumio[899]: info: Plugin folders cleanup
Sep 22 16:46:32 katana volumio[899]: info: Scanning into folder /volumio/app/plugins/

11

reverted to version 2.444… problem solved.

12

So this is what the log says.

                       ___
                      /\_ \                        __
         __  __    ___\//\ \    __  __    ___ ___ /\_\    ___
        /\ \/\ \  / __`\\ \ \  /\ \/\ \ /' __` __`\/\ \  / __`\
        \ \ \_/ |/\ \L\ \\_\ \_\ \ \_\ \/\ \/\ \/\ \ \ \/\ \L\ \
         \ \___/ \ \____//\____\\ \____/\ \_\ \_\ \_\ \_\ \____/
          \/__/   \/___/ \/____/ \/___/  \/_/\/_/\/_/\/_/\/___/

             Free Audiophile Linux Music Player - Version 2.0

          C 2015 Michelangelo Guarise - Volumio Team - Volumio.org


Volumio Debian GNU/Linux comes with ABSOLUTELY NO WARRANTY, to the extent
permitted by applicable law.
volumio@volumiotouch:~$ sudo journalctl -f
-- Logs begin at Sun 2018-09-16 22:18:22 UTC. --
Sep 22 17:38:20 volumiotouch sudo[5030]: volumio : TTY=unknown ; PWD=/ ; USER=ro                                                                                                                                                             ot ; COMMAND=/sbin/ifconfig wlan0
Sep 22 17:38:20 volumiotouch sudo[5030]: pam_unix(sudo:session): session opened                                                                                                                                                              for user root by (uid=0)
Sep 22 17:38:20 volumiotouch sudo[5030]: pam_unix(sudo:session): session closed                                                                                                                                                              for user root
Sep 22 17:38:20 volumiotouch sudo[5034]: volumio : TTY=unknown ; PWD=/ ; USER=ro                                                                                                                                                             ot ; COMMAND=/bin/systemctl start upmpdcli.service
Sep 22 17:38:20 volumiotouch sudo[5034]: pam_unix(sudo:session): session opened                                                                                                                                                              for user root by (uid=0)
Sep 22 17:38:20 volumiotouch systemd[1]: Started UPnP Renderer front-end to MPD.
Sep 22 17:38:20 volumiotouch sudo[5034]: pam_unix(sudo:session): session closed                                                                                                                                                              for user root
Sep 22 17:38:20 volumiotouch volumio[4873]: info: Upmpdcli Daemon Started
Sep 22 17:38:21 volumiotouch sudo[5054]: volumio : TTY=pts/0 ; PWD=/home/volumio                                                                                                                                                              ; USER=root ; COMMAND=/bin/journalctl -f
Sep 22 17:38:21 volumiotouch sudo[5054]: pam_unix(sudo:session): session opened                                                                                                                                                              for user root by volumio(uid=0)
Sep 22 17:38:24 volumiotouch volumio-remote-updater[643]: [2018-09-22 17:38:24]                                                                                                                                                              [connect] Successful connection
Sep 22 17:38:24 volumiotouch volumio-remote-updater[643]: [2018-09-22 17:38:24]                                                                                                                                                              [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.5.1" /socket.io                                                                                                                                                             /?EIO=4&transport=websocket&t=1537637904 101
Sep 22 17:38:42 volumiotouch volumio[4873]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Sep 22 17:38:42 volumiotouch volumio[4873]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 22 17:38:42 volumiotouch volumio[4873]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Sep 22 17:38:42 volumiotouch volumio[4873]: TypeError: Cannot create property 'type' on string 'invalid server key'
Sep 22 17:38:42 volumiotouch volumio[4873]: at WebSocket.onError (/volumio/node_modules/ws/lib/WebSocket.js:450:16)
Sep 22 17:38:42 volumiotouch volumio[4873]: at emitOne (events.js:116:13)
Sep 22 17:38:42 volumiotouch volumio[4873]: at WebSocket.emit (events.js:211:7)
Sep 22 17:38:42 volumiotouch volumio[4873]: at ClientRequest.upgrade (/volumio/node_modules/ws/lib/WebSocket.js:738:12)
Sep 22 17:38:42 volumiotouch volumio[4873]: at Object.onceWrapper (events.js:319:30)
Sep 22 17:38:42 volumiotouch volumio[4873]: at emitThree (events.js:136:13)
Sep 22 17:38:42 volumiotouch volumio[4873]: at ClientRequest.emit (events.js:217:7)
Sep 22 17:38:42 volumiotouch volumio[4873]: at Socket.socketOnData (_http_client.js:472:11)
Sep 22 17:38:42 volumiotouch volumio[4873]: at emitOne (events.js:116:13)
Sep 22 17:38:42 volumiotouch volumio[4873]: at Socket.emit (events.js:211:7)
Sep 22 17:38:42 volumiotouch volumio[4873]: at addChunk (_stream_readable.js:263:12)
Sep 22 17:38:42 volumiotouch volumio[4873]: at readableAddChunk (_stream_readable.js:250:11)
Sep 22 17:38:42 volumiotouch volumio[4873]: at Socket.Readable.push (_stream_readable.js:208:10)
Sep 22 17:38:42 volumiotouch volumio[4873]: at TCP.onread (net.js:607:20)
Sep 22 17:38:42 volumiotouch volumio[4873]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Sep 22 17:38:43 volumiotouch sudo[5211]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2018-09-22 17:37
Sep 22 17:38:43 volumiotouch sudo[5211]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 22 17:38:43 volumiotouch sudo[5211]: pam_unix(sudo:session): session closed for user root
Sep 22 17:38:43 volumiotouch systemd[1]: volumio.service: main process exited, code=exited, status=1/FAILURE
Sep 22 17:38:43 volumiotouch volumio-remote-updater[643]: [2018-09-22 17:38:43] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Sep 22 17:38:43 volumiotouch volumio-remote-updater[643]: [2018-09-22 17:38:43] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Sep 22 17:38:43 volumiotouch systemd[1]: Unit volumio.service entered failed state.
Sep 22 17:38:43 volumiotouch systemd[1]: Starting dynamicswap service...
Sep 22 17:38:43 volumiotouch systemd[1]: Started dynamicswap service.
Sep 22 17:38:43 volumiotouch systemd[1]: volumio.service holdoff time over, scheduling restart.
Sep 22 17:38:43 volumiotouch systemd[1]: Starting dynamicswap service...
Sep 22 17:38:43 volumiotouch systemd[1]: Started dynamicswap service.
Sep 22 17:38:43 volumiotouch systemd[1]: Stopping Volumio Backend Module...
Sep 22 17:38:43 volumiotouch systemd[1]: Starting Volumio Backend Module...
Sep 22 17:38:43 volumiotouch systemd[1]: Started Volumio Backend Module.
Sep 22 17:38:45 volumiotouch volumio[5232]: info: -------------------------------------------
Sep 22 17:38:45 volumiotouch volumio[5232]: info: -----            Volumio2              ----
Sep 22 17:38:45 volumiotouch volumio[5232]: info: -------------------------------------------
Sep 22 17:38:45 volumiotouch volumio[5232]: info: -----          System startup          ----
Sep 22 17:38:45 volumiotouch volumio[5232]: info: -------------------------------------------
Sep 22 17:38:45 volumiotouch volumio[5232]: info: Plugin folders cleanup
Sep 22 17:38:45 volumiotouch volumio[5232]: info: Scanning into folder /volumio/app/plugins/
Sep 22 17:38:45 volumiotouch volumio[5232]: info: Scanning category audio_interface
Sep 22 17:38:45 volumiotouch volumio[5232]: info: Scanning category miscellanea
Sep 22 17:38:45 volumiotouch volumio[5232]: info: Scanning category music_service
Sep 22 17:38:45 volumiotouch volumio[5232]: info: Scanning category plugins.json
Sep 22 17:38:45 volumiotouch volumio[5232]: info: Scanning category system_controller
Sep 22 17:38:45 volumiotouch volumio[5232]: info: Scanning category user_interface
Sep 22 17:38:45 volumiotouch volumio[5232]: info: Scanning into folder /data/plugins/
Sep 22 17:38:45 volumiotouch volumio[5232]: info: Plugin folders cleanup completed
Sep 22 17:38:45 volumiotouch volumio[5232]: info: -------------------------------------------
Sep 22 17:38:45 volumiotouch volumio[5232]: info: -----      Core plugins startup        ----
Sep 22 17:38:45 volumiotouch volumio[5232]: info: -------------------------------------------
Sep 22 17:38:45 volumiotouch volumio[5232]: info: Loading plugins from folder /volumio/app/plugins/
Sep 22 17:38:45 volumiotouch volumio[5232]: info: Adding plugin upnp to MyMusic Plugins
Sep 22 17:38:45 volumiotouch volumio[5232]: info: Adding plugin airplay_emulation to MyMusic Plugins
Sep 22 17:38:45 volumiotouch volumio[5232]: info: Adding plugin upnp_browser to MyMusic Plugins
Sep 22 17:38:45 volumiotouch volumio[5232]: info: Loading plugins from folder /data/plugins/
Sep 22 17:38:45 volumiotouch volumio[5232]: info: Loading plugin "system"...
Sep 22 17:38:45 volumiotouch volumio[5232]: info: Loading plugin "appearance"...
Sep 22 17:38:46 volumiotouch volumio[5232]: info: Loading plugin "network"...
Sep 22 17:38:46 volumiotouch volumio[5232]: info: Loading plugin "services"...
Sep 22 17:38:46 volumiotouch volumio[5232]: info: Loading plugin "alsa_controller"...
Sep 22 17:38:46 volumiotouch volumio[5232]: info: Loading plugin "wizard"...
Sep 22 17:38:46 volumiotouch volumio[5232]: info: Loading plugin "volumio_command_line_client"...
Sep 22 17:38:46 volumiotouch volumio[5232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 22 17:38:46 volumiotouch volumio[5232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 22 17:38:46 volumiotouch volumio[5232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 22 17:38:46 volumiotouch volumio[5232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 22 17:38:46 volumiotouch volumio[5232]: info: Loading plugin "upnp"...
Sep 22 17:38:46 volumiotouch volumio[5232]: info: [1537637926534] Starting Upmpd Daemon
Sep 22 17:38:46 volumiotouch volumio[5232]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Sep 22 17:38:46 volumiotouch volumio[5232]: info: Loading plugin "my_music"...
Sep 22 17:38:46 volumiotouch volumio[5232]: info: Loading plugin "mpd"...
Sep 22 17:38:46 volumiotouch volumio[5232]: info: Loading plugin "upnp_browser"...
Sep 22 17:38:47 volumiotouch volumio[5232]: info: Loading plugin "networkfs"...
Sep 22 17:38:47 volumiotouch volumio[5232]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Sep 22 17:38:47 volumiotouch volumio[5232]: info: Loading plugin "alarm-clock"...
Sep 22 17:38:47 volumiotouch volumio[5232]: info: Loading plugin "airplay_emulation"...
Sep 22 17:38:47 volumiotouch volumio[5232]: info: Starting Shairport Sync
Sep 22 17:38:47 volumiotouch volumio[5232]: info: Loading plugin "last_100"...
Sep 22 17:38:47 volumiotouch volumio[5232]: info: Loading plugin "webradio"...
Sep 22 17:38:47 volumiotouch volumio[5232]: info: Loading plugin "i2s_dacs"...
Sep 22 17:38:47 volumiotouch volumio[5232]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 22 17:38:47 volumiotouch volumio[5232]: info: Loading plugin "volumiodiscovery"...
Sep 22 17:38:47 volumiotouch volumio[5232]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Sep 22 17:38:47 volumiotouch node[5232]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Sep 22 17:38:47 volumiotouch node[5232]: *** WARNING *** Please fix your application to use the native API of Avahi!
Sep 22 17:38:47 volumiotouch node[5232]: *** WARNING *** For more information see <http://0pointer.de/avahi-compat?s=libdns_sd&e=node>
Sep 22 17:38:47 volumiotouch node[5232]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Sep 22 17:38:47 volumiotouch node[5232]: *** WARNING *** Please fix your application to use the native API of Avahi!
Sep 22 17:38:47 volumiotouch node[5232]: *** WARNING *** For more information see <http://0pointer.de/avahi-compat?s=libdns_sd&e=node&f=DNSServiceRegister>
Sep 22 17:38:47 volumiotouch volumio[5232]: *** WARNING *** Please fix your application to use the native API of Avahi!
Sep 22 17:38:47 volumiotouch volumio[5232]: *** WARNING *** For more information see <http://0pointer.de/avahi-compat?s=libdns_sd&e=node>
Sep 22 17:38:47 volumiotouch volumio[5232]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Sep 22 17:38:47 volumiotouch volumio[5232]: *** WARNING *** Please fix your application to use the native API of Avahi!
Sep 22 17:38:47 volumiotouch volumio[5232]: *** WARNING *** For more information see <http://0pointer.de/avahi-compat?s=libdns_sd&e=node&f=DNSServiceRegister>
Sep 22 17:38:47 volumiotouch volumio[5232]: info: Applying required configuration parameters for plugin volumiodiscovery
Sep 22 17:38:47 volumiotouch volumio[5232]: Discovery: StartAdv! undefined
Sep 22 17:38:47 volumiotouch volumio[5232]: Discovery: Started advertising... Volumiotouch - undefined
Sep 22 17:38:47 volumiotouch volumio[5232]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Sep 22 17:38:47 volumiotouch volumio[5232]: info: Loading plugin "albumart"...
Sep 22 17:38:47 volumiotouch volumio[5232]: info: Plugin example_plugin is not enabled
Sep 22 17:38:47 volumiotouch volumio[5232]: info: Loading plugin "updater_comm"...
Sep 22 17:38:48 volumiotouch volumio[5232]: info: Plugin mpdemulation is not enabled
Sep 22 17:38:48 volumiotouch volumio[5232]: info: Loading plugin "rest_api"...
Sep 22 17:38:48 volumiotouch volumio[5232]: info: Loading plugin "websocket"...
Sep 22 17:38:48 volumiotouch volumio[5232]: info: ___________ START PLUGINS ___________
Sep 22 17:38:48 volumiotouch volumio[5232]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Sep 22 17:38:48 volumiotouch volumio[5232]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Sep 22 17:38:48 volumiotouch volumio[5232]: info: [1537637928150] CoreMusicLibrary::Adding element Media Servers
Sep 22 17:38:48 volumiotouch volumio[5232]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Sep 22 17:38:48 volumiotouch volumio[5232]: info: [1537637928180] CoreMusicLibrary::Adding element Last_100
Sep 22 17:38:48 volumiotouch volumio[5232]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Sep 22 17:38:48 volumiotouch volumio[5232]: info: [1537637928183] CoreMusicLibrary::Adding element Webradio
Sep 22 17:38:48 volumiotouch volumio[5232]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Sep 22 17:38:48 volumiotouch volumio[5232]: info: -------------------------------------------
Sep 22 17:38:48 volumiotouch volumio[5232]: info: -----    MyVolumio plugins startup     ----
Sep 22 17:38:48 volumiotouch volumio[5232]: info: -------------------------------------------
Sep 22 17:38:48 volumiotouch volumio[5232]: info: Loading plugins from folder /myvolumio/plugins
Sep 22 17:38:48 volumiotouch volumio[5232]: info: Loading plugins from folder /data/myvolumio/plugins
Sep 22 17:38:48 volumiotouch volumio[5232]: info: Loading i18n strings for locale nl
Sep 22 17:38:48 volumiotouch volumio[5232]: Updating browse sources language
Sep 22 17:38:48 volumiotouch volumio[5232]: Cannot find translation for sourceMedia Servers
Sep 22 17:38:48 volumiotouch volumio[5232]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Sep 22 17:38:48 volumiotouch volumio[5232]: info: CoreCommandRouter::initPlayerControls
Sep 22 17:38:48 volumiotouch volumio[5232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 22 17:38:48 volumiotouch volumio[5232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAlsaCards
Sep 22 17:38:48 volumiotouch volumio[5232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 22 17:38:48 volumiotouch volumio[5232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 22 17:38:48 volumiotouch volumio[5232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 22 17:38:48 volumiotouch volumio[5232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 22 17:38:48 volumiotouch volumio[5232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 22 17:38:48 volumiotouch volumio[5232]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Sep 22 17:38:48 volumiotouch volumio-remote-updater[643]: [2018-09-22 17:38:48] [connect] Successful connection
Sep 22 17:38:48 volumiotouch volumio[5232]: info: BOOT COMPLETED
Sep 22 17:38:48 volumiotouch volumio[5232]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 22 17:38:48 volumiotouch volumio[5232]: Forking 3 albumart workers
Sep 22 17:38:49 volumiotouch volumio[5232]: Starting albumart workers
Sep 22 17:38:49 volumiotouch volumio[5232]: Starting albumart workers
Sep 22 17:38:49 volumiotouch volumio[5232]: Starting albumart workers
Sep 22 17:38:53 volumiotouch volumio[5232]: Playing WAVE '/volumio/app/startup.wav' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo
Sep 22 17:38:53 volumiotouch volumio[5232]: info: CoreCommandRouter::Close All Modals sent
Sep 22 17:38:53 volumiotouch volumio[5232]: info: CoreCommandRouter::Close All Modals sent
Sep 22 17:38:53 volumiotouch volumio[5232]: Express server listening on port 3000
Sep 22 17:38:53 volumiotouch volumio[5232]: Volumio Calling Home
Sep 22 17:38:53 volumiotouch volumio[5232]: info: CoreStateMachine::resetVolumioState
Sep 22 17:38:53 volumiotouch volumio[5232]: info: CoreStateMachine::getcurrentVolume
Sep 22 17:38:53 volumiotouch volumio[5232]: info: CoreCommandRouter::volumioRetrievevolume
Sep 22 17:38:53 volumiotouch volumio[5232]: info: CoreStateMachine::updateTrackBlock
Sep 22 17:38:53 volumiotouch volumio[5232]: info: CorePlayQueue::getTrackBlock
Sep 22 17:38:53 volumiotouch volumio[5232]: info: Cannot read play queue from file
Sep 22 17:38:53 volumiotouch volumio[5232]: info: Setting Device type: Raspberry PI
Sep 22 17:38:53 volumiotouch volumio[5232]: info: MPD running with PID669 ,establishing connection
Sep 22 17:38:53 volumiotouch volumio[5232]: info: VolumeController:: Volume=40 Mute =false
Sep 22 17:38:53 volumiotouch volumio[5232]: info: CoreStateMachine::pushState
Sep 22 17:38:53 volumiotouch volumio[5232]: info: CoreStateMachine::getState
Sep 22 17:38:53 volumiotouch volumio[5232]: info: CorePlayQueue::getTrack 0
Sep 22 17:38:53 volumiotouch volumio[5232]: info: CoreCommandRouter::volumioPushState
Sep 22 17:38:53 volumiotouch volumio[5232]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 22 17:38:53 volumiotouch volumio[5232]: info: Volumio called home
Sep 22 17:38:54 volumiotouch volumio[5232]: info:
Sep 22 17:38:54 volumiotouch volumio[5232]: info:  message= [50@0] {} No such directory, stack=Error:  [50@0] {} No such directory
Sep 22 17:38:54 volumiotouch volumio[5232]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:63:14)
Sep 22 17:38:54 volumiotouch volumio[5232]: at Socket.<anonymous> (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:10)
Sep 22 17:38:54 volumiotouch volumio[5232]: at emitOne (events.js:116:13)
Sep 22 17:38:54 volumiotouch volumio[5232]: at Socket.emit (events.js:211:7)
Sep 22 17:38:54 volumiotouch volumio[5232]: at addChunk (_stream_readable.js:263:12)
Sep 22 17:38:54 volumiotouch volumio[5232]: at readableAddChunk (_stream_readable.js:246:13)
Sep 22 17:38:54 volumiotouch volumio[5232]: at Socket.Readable.push (_stream_readable.js:208:10)
Sep 22 17:38:54 volumiotouch volumio[5232]: at Pipe.onread (net.js:607:20)
Sep 22 17:38:54 volumiotouch volumio[5232]: info: CoreStateMachine::setRepeat null single undefined
Sep 22 17:38:54 volumiotouch volumio[5232]: info: CoreStateMachine::pushState
Sep 22 17:38:54 volumiotouch volumio[5232]: info: CoreStateMachine::getState
Sep 22 17:38:54 volumiotouch volumio[5232]: info: CorePlayQueue::getTrack 0
Sep 22 17:38:54 volumiotouch volumio[5232]: info: CoreCommandRouter::volumioPushState
Sep 22 17:38:54 volumiotouch volumio[5232]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 22 17:38:54 volumiotouch volumio[5232]: info: CoreStateMachine::setRandom null
Sep 22 17:38:54 volumiotouch volumio[5232]: info: CoreStateMachine::pushState
Sep 22 17:38:54 volumiotouch volumio[5232]: info: CoreStateMachine::getState
Sep 22 17:38:54 volumiotouch volumio[5232]: info: CorePlayQueue::getTrack 0
Sep 22 17:38:54 volumiotouch volumio[5232]: info: CoreCommandRouter::volumioPushState
Sep 22 17:38:54 volumiotouch volumio[5232]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 22 17:38:54 volumiotouch volumio[5232]: info: CoreCommandRouter::volumioGetState
Sep 22 17:38:54 volumiotouch volumio[5232]: info: CoreStateMachine::getState
Sep 22 17:38:54 volumiotouch volumio[5232]: info: CorePlayQueue::getTrack 0
Sep 22 17:38:54 volumiotouch volumio[5232]: info: CoreCommandRouter::volumioGetBrowseSources
Sep 22 17:38:54 volumiotouch volumio[5232]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Sep 22 17:38:54 volumiotouch volumio[5232]: info: Listing playlists
Sep 22 17:38:54 volumiotouch sudo[5303]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart airplay
Sep 22 17:38:54 volumiotouch sudo[5303]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 22 17:38:54 volumiotouch sudo[5305]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart airplay
Sep 22 17:38:54 volumiotouch systemd[1]: Stopping ShairportSync AirTunes receiver...
Sep 22 17:38:54 volumiotouch sudo[5305]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 22 17:38:54 volumiotouch systemd[1]: Starting ShairportSync AirTunes receiver...
Sep 22 17:38:54 volumiotouch systemd[1]: Started ShairportSync AirTunes receiver.
Sep 22 17:38:54 volumiotouch sudo[5303]: pam_unix(sudo:session): session closed for user root
Sep 22 17:38:54 volumiotouch shairport-sync[5314]: Successful Startup
Sep 22 17:38:54 volumiotouch systemd[1]: Stopping ShairportSync AirTunes receiver...
Sep 22 17:38:54 volumiotouch systemd[1]: Starting ShairportSync AirTunes receiver...
Sep 22 17:38:54 volumiotouch systemd[1]: Started ShairportSync AirTunes receiver.
Sep 22 17:38:54 volumiotouch sudo[5305]: pam_unix(sudo:session): session closed for user root
Sep 22 17:38:54 volumiotouch shairport-sync[5321]: Successful Startup
Sep 22 17:38:54 volumiotouch volumio[5232]: info: Shairport-Sync Started
Sep 22 17:38:54 volumiotouch volumio[5232]: Error adding Membership: Error: addMembership EINVAL
Sep 22 17:38:54 volumiotouch volumio[5232]: info: Shairport-Sync Started
Sep 22 17:38:54 volumiotouch volumio[5232]: Discovery: adding e785f54e-d36a-4ded-900b-ffa1692f9241
Sep 22 17:38:54 volumiotouch volumio[5232]: info: mDNS: Found device Volumiotouch
Sep 22 17:38:54 volumiotouch volumio[5232]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
Sep 22 17:38:54 volumiotouch sudo[5328]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 22 17:38:54 volumiotouch sudo[5328]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 22 17:38:54 volumiotouch sudo[5328]: pam_unix(sudo:session): session closed for user root
Sep 22 17:38:54 volumiotouch volumio[5232]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
Sep 22 17:38:54 volumiotouch volumio[5232]: Discovery: this is already registered,  e785f54e-d36a-4ded-900b-ffa1692f9241
Sep 22 17:38:54 volumiotouch volumio[5232]: info: mDNS: Found device Volumiotouch
Sep 22 17:38:54 volumiotouch sudo[5339]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 22 17:38:54 volumiotouch sudo[5339]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 22 17:38:54 volumiotouch sudo[5339]: pam_unix(sudo:session): session closed for user root
Sep 22 17:38:54 volumiotouch volumio[5232]: info: CoreCommandRouter::volumioGetState
Sep 22 17:38:54 volumiotouch volumio[5232]: info: CoreStateMachine::getState
Sep 22 17:38:54 volumiotouch volumio[5232]: info: CorePlayQueue::getTrack 0
Sep 22 17:38:54 volumiotouch sudo[5348]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 22 17:38:54 volumiotouch sudo[5348]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 22 17:38:54 volumiotouch sudo[5348]: pam_unix(sudo:session): session closed for user root
Sep 22 17:38:56 volumiotouch sudo[5371]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 22 17:38:56 volumiotouch sudo[5371]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 22 17:38:56 volumiotouch sudo[5371]: pam_unix(sudo:session): session closed for user root
Sep 22 17:38:56 volumiotouch sudo[5376]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Sep 22 17:38:56 volumiotouch sudo[5376]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 22 17:38:56 volumiotouch systemd[1]: Started UPnP Renderer front-end to MPD.
Sep 22 17:38:56 volumiotouch sudo[5376]: pam_unix(sudo:session): session closed for user root
Sep 22 17:38:56 volumiotouch volumio[5232]: info: Upmpdcli Daemon Started
Sep 22 17:39:00 volumiotouch volumio-remote-updater[643]: [2018-09-22 17:39:00] [connect] Successful connection
Sep 22 17:39:00 volumiotouch volumio-remote-updater[643]: [2018-09-22 17:39:00] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.5.1" /socket.io/?EIO=4&transport=websocket&t=1537637940 101
Sep 22 17:39:18 volumiotouch volumio[5232]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Sep 22 17:39:18 volumiotouch volumio[5232]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 22 17:39:18 volumiotouch volumio[5232]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Sep 22 17:39:18 volumiotouch volumio[5232]: TypeError: Cannot create property 'type' on string 'invalid server key'
Sep 22 17:39:18 volumiotouch volumio[5232]: at WebSocket.onError (/volumio/node_modules/ws/lib/WebSocket.js:450:16)
Sep 22 17:39:18 volumiotouch volumio[5232]: at emitOne (events.js:116:13)
Sep 22 17:39:18 volumiotouch volumio[5232]: at WebSocket.emit (events.js:211:7)
Sep 22 17:39:18 volumiotouch volumio[5232]: at ClientRequest.upgrade (/volumio/node_modules/ws/lib/WebSocket.js:738:12)
Sep 22 17:39:18 volumiotouch volumio[5232]: at Object.onceWrapper (events.js:319:30)
Sep 22 17:39:18 volumiotouch volumio[5232]: at emitThree (events.js:136:13)
Sep 22 17:39:18 volumiotouch volumio[5232]: at ClientRequest.emit (events.js:217:7)
Sep 22 17:39:18 volumiotouch volumio[5232]: at Socket.socketOnData (_http_client.js:472:11)
Sep 22 17:39:18 volumiotouch volumio[5232]: at emitOne (events.js:116:13)
Sep 22 17:39:18 volumiotouch volumio[5232]: at Socket.emit (events.js:211:7)
Sep 22 17:39:18 volumiotouch volumio[5232]: at addChunk (_stream_readable.js:263:12)
Sep 22 17:39:18 volumiotouch volumio[5232]: at readableAddChunk (_stream_readable.js:250:11)
Sep 22 17:39:18 volumiotouch volumio[5232]: at Socket.Readable.push (_stream_readable.js:208:10)
Sep 22 17:39:18 volumiotouch volumio[5232]: at TCP.onread (net.js:607:20)
Sep 22 17:39:18 volumiotouch volumio[5232]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Sep 22 17:39:19 volumiotouch sudo[5546]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2018-09-22 17:38
Sep 22 17:39:19 volumiotouch sudo[5546]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 22 17:39:19 volumiotouch sudo[5546]: pam_unix(sudo:session): session closed for user root
Sep 22 17:39:19 volumiotouch systemd[1]: volumio.service: main process exited, code=exited, status=1/FAILURE
Sep 22 17:39:19 volumiotouch volumio-remote-updater[643]: [2018-09-22 17:39:19] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Sep 22 17:39:19 volumiotouch volumio-remote-updater[643]: [2018-09-22 17:39:19] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Sep 22 17:39:19 volumiotouch systemd[1]: Unit volumio.service entered failed state.
Sep 22 17:39:19 volumiotouch systemd[1]: Starting dynamicswap service...
Sep 22 17:39:19 volumiotouch systemd[1]: Started dynamicswap service.
Sep 22 17:39:19 volumiotouch systemd[1]: volumio.service holdoff time over, scheduling restart.
Sep 22 17:39:19 volumiotouch systemd[1]: Starting dynamicswap service...
Sep 22 17:39:19 volumiotouch systemd[1]: Started dynamicswap service.
Sep 22 17:39:19 volumiotouch systemd[1]: Stopping Volumio Backend Module...
Sep 22 17:39:19 volumiotouch systemd[1]: Starting Volumio Backend Module...
Sep 22 17:39:19 volumiotouch systemd[1]: Started Volumio Backend Module.
Sep 22 17:39:21 volumiotouch volumio[5567]: info: -------------------------------------------
Sep 22 17:39:21 volumiotouch volumio[5567]: info: -----            Volumio2              ----
Sep 22 17:39:21 volumiotouch volumio[5567]: info: -------------------------------------------
Sep 22 17:39:21 volumiotouch volumio[5567]: info: -----          System startup          ----
Sep 22 17:39:21 volumiotouch volumio[5567]: info: -------------------------------------------
Sep 22 17:39:21 volumiotouch volumio[5567]: info: Plugin folders cleanup
Sep 22 17:39:21 volumiotouch volumio[5567]: info: Scanning into folder /volumio/app/plugins/
Sep 22 17:39:21 volumiotouch volumio[5567]: info: Scanning category audio_interface
Sep 22 17:39:21 volumiotouch volumio[5567]: info: Scanning category miscellanea
Sep 22 17:39:21 volumiotouch volumio[5567]: info: Scanning category music_service
Sep 22 17:39:21 volumiotouch volumio[5567]: info: Scanning category plugins.json
Sep 22 17:39:21 volumiotouch volumio[5567]: info: Scanning category system_controller
Sep 22 17:39:21 volumiotouch volumio[5567]: info: Scanning category user_interface
Sep 22 17:39:21 volumiotouch volumio[5567]: info: Scanning into folder /data/plugins/
Sep 22 17:39:21 volumiotouch volumio[5567]: info: Plugin folders cleanup completed
Sep 22 17:39:21 volumiotouch volumio[5567]: info: -------------------------------------------
Sep 22 17:39:21 volumiotouch volumio[5567]: info: -----      Core plugins startup        ----
Sep 22 17:39:21 volumiotouch volumio[5567]: info: -------------------------------------------
Sep 22 17:39:21 volumiotouch volumio[5567]: info: Loading plugins from folder /volumio/app/plugins/
Sep 22 17:39:21 volumiotouch volumio[5567]: info: Adding plugin upnp to MyMusic Plugins
Sep 22 17:39:21 volumiotouch volumio[5567]: info: Adding plugin airplay_emulation to MyMusic Plugins
Sep 22 17:39:21 volumiotouch volumio[5567]: info: Adding plugin upnp_browser to MyMusic Plugins
Sep 22 17:39:21 volumiotouch volumio[5567]: info: Loading plugins from folder /data/plugins/
Sep 22 17:39:21 volumiotouch volumio[5567]: info: Loading plugin "system"...
Sep 22 17:39:21 volumiotouch volumio[5567]: info: Loading plugin "appearance"...
Sep 22 17:39:22 volumiotouch volumio[5567]: info: Loading plugin "network"...
Sep 22 17:39:22 volumiotouch volumio[5567]: info: Loading plugin "services"...
Sep 22 17:39:22 volumiotouch volumio[5567]: info: Loading plugin "alsa_controller"...
Sep 22 17:39:22 volumiotouch volumio[5567]: info: Loading plugin "wizard"...
Sep 22 17:39:22 volumiotouch volumio[5567]: info: Loading plugin "volumio_command_line_client"...
Sep 22 17:39:22 volumiotouch volumio[5567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 22 17:39:22 volumiotouch volumio[5567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 22 17:39:22 volumiotouch volumio[5567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 22 17:39:22 volumiotouch volumio[5567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 22 17:39:22 volumiotouch volumio[5567]: info: Loading plugin "upnp"...
Sep 22 17:39:22 volumiotouch volumio[5567]: info: [1537637962594] Starting Upmpd Daemon
Sep 22 17:39:22 volumiotouch volumio[5567]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Sep 22 17:39:22 volumiotouch volumio[5567]: info: Loading plugin "my_music"...
Sep 22 17:39:22 volumiotouch volumio[5567]: info: Loading plugin "mpd"...
Sep 22 17:39:22 volumiotouch volumio[5567]: info: Loading plugin "upnp_browser"...
Sep 22 17:39:23 volumiotouch volumio[5567]: info: Loading plugin "networkfs"...
Sep 22 17:39:23 volumiotouch volumio[5567]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Sep 22 17:39:23 volumiotouch volumio[5567]: info: Loading plugin "alarm-clock"...
Sep 22 17:39:23 volumiotouch volumio[5567]: info: Loading plugin "airplay_emulation"...
Sep 22 17:39:23 volumiotouch volumio[5567]: info: Starting Shairport Sync
Sep 22 17:39:23 volumiotouch volumio[5567]: info: Loading plugin "last_100"...
Sep 22 17:39:23 volumiotouch volumio[5567]: info: Loading plugin "webradio"...
Sep 22 17:39:23 volumiotouch volumio[5567]: info: Loading plugin "i2s_dacs"...
Sep 22 17:39:23 volumiotouch volumio[5567]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 22 17:39:23 volumiotouch volumio[5567]: info: Loading plugin "volumiodiscovery"...
Sep 22 17:39:23 volumiotouch volumio[5567]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Sep 22 17:39:23 volumiotouch node[5567]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Sep 22 17:39:23 volumiotouch node[5567]: *** WARNING *** Please fix your application to use the native API of Avahi!
Sep 22 17:39:23 volumiotouch node[5567]: *** WARNING *** For more information see <http://0pointer.de/avahi-compat?s=libdns_sd&e=node>
Sep 22 17:39:23 volumiotouch node[5567]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Sep 22 17:39:23 volumiotouch node[5567]: *** WARNING *** Please fix your application to use the native API of Avahi!
Sep 22 17:39:23 volumiotouch node[5567]: *** WARNING *** For more information see <http://0pointer.de/avahi-compat?s=libdns_sd&e=node&f=DNSServiceRegister>
Sep 22 17:39:23 volumiotouch volumio[5567]: *** WARNING *** Please fix your application to use the native API of Avahi!
Sep 22 17:39:23 volumiotouch volumio[5567]: *** WARNING *** For more information see <http://0pointer.de/avahi-compat?s=libdns_sd&e=node>
Sep 22 17:39:23 volumiotouch volumio[5567]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Sep 22 17:39:23 volumiotouch volumio[5567]: *** WARNING *** Please fix your application to use the native API of Avahi!
Sep 22 17:39:23 volumiotouch volumio[5567]: *** WARNING *** For more information see <http://0pointer.de/avahi-compat?s=libdns_sd&e=node&f=DNSServiceRegister>
Sep 22 17:39:23 volumiotouch volumio[5567]: info: Applying required configuration parameters for plugin volumiodiscovery
Sep 22 17:39:23 volumiotouch volumio[5567]: Discovery: StartAdv! undefined
Sep 22 17:39:23 volumiotouch volumio[5567]: Discovery: Started advertising... Volumiotouch - undefined
Sep 22 17:39:24 volumiotouch volumio[5567]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Sep 22 17:39:24 volumiotouch volumio[5567]: info: Loading plugin "albumart"...
Sep 22 17:39:24 volumiotouch volumio[5567]: info: Plugin example_plugin is not enabled
Sep 22 17:39:24 volumiotouch volumio[5567]: info: Loading plugin "updater_comm"...
Sep 22 17:39:24 volumiotouch volumio[5567]: info: Plugin mpdemulation is not enabled
Sep 22 17:39:24 volumiotouch volumio[5567]: info: Loading plugin "rest_api"...
Sep 22 17:39:24 volumiotouch volumio[5567]: info: Loading plugin "websocket"...
Sep 22 17:39:24 volumiotouch volumio[5567]: info: ___________ START PLUGINS ___________
Sep 22 17:39:24 volumiotouch volumio[5567]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Sep 22 17:39:24 volumiotouch volumio[5567]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Sep 22 17:39:24 volumiotouch volumio[5567]: info: [1537637964219] CoreMusicLibrary::Adding element Media Servers
Sep 22 17:39:24 volumiotouch volumio[5567]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Sep 22 17:39:24 volumiotouch volumio[5567]: info: [1537637964250] CoreMusicLibrary::Adding element Last_100
Sep 22 17:39:24 volumiotouch volumio[5567]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Sep 22 17:39:24 volumiotouch volumio[5567]: info: [1537637964253] CoreMusicLibrary::Adding element Webradio
Sep 22 17:39:24 volumiotouch volumio[5567]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Sep 22 17:39:24 volumiotouch volumio[5567]: info: -------------------------------------------
Sep 22 17:39:24 volumiotouch volumio[5567]: info: -----    MyVolumio plugins startup     ----
Sep 22 17:39:24 volumiotouch volumio[5567]: info: -------------------------------------------
Sep 22 17:39:24 volumiotouch volumio[5567]: info: Loading plugins from folder /myvolumio/plugins
Sep 22 17:39:24 volumiotouch volumio[5567]: info: Loading plugins from folder /data/myvolumio/plugins
Sep 22 17:39:24 volumiotouch volumio[5567]: info: Loading i18n strings for locale nl
Sep 22 17:39:24 volumiotouch volumio[5567]: Updating browse sources language
Sep 22 17:39:24 volumiotouch volumio[5567]: Cannot find translation for sourceMedia Servers
Sep 22 17:39:24 volumiotouch volumio[5567]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Sep 22 17:39:24 volumiotouch volumio[5567]: info: CoreCommandRouter::initPlayerControls
Sep 22 17:39:24 volumiotouch volumio-remote-updater[643]: [2018-09-22 17:39:24] [connect] Successful connection
Sep 22 17:39:24 volumiotouch volumio[5567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 22 17:39:24 volumiotouch volumio[5567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAlsaCards
Sep 22 17:39:24 volumiotouch volumio[5567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 22 17:39:24 volumiotouch volumio[5567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 22 17:39:24 volumiotouch volumio[5567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 22 17:39:24 volumiotouch volumio[5567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 22 17:39:24 volumiotouch volumio[5567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 22 17:39:24 volumiotouch volumio[5567]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Sep 22 17:39:24 volumiotouch volumio[5567]: info: BOOT COMPLETED
Sep 22 17:39:24 volumiotouch volumio[5567]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 22 17:39:24 volumiotouch volumio[5567]: Forking 3 albumart workers
Sep 22 17:39:25 volumiotouch volumio[5567]: Starting albumart workers
Sep 22 17:39:25 volumiotouch volumio[5567]: Starting albumart workers
Sep 22 17:39:25 volumiotouch volumio[5567]: Starting albumart workers
Sep 22 17:39:29 volumiotouch volumio[5567]: Playing WAVE '/volumio/app/startup.wav' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo
Sep 22 17:39:29 volumiotouch volumio[5567]: info: CoreCommandRouter::Close All Modals sent
Sep 22 17:39:29 volumiotouch volumio[5567]: info: CoreCommandRouter::Close All Modals sent
Sep 22 17:39:29 volumiotouch volumio[5567]: Express server listening on port 3000
Sep 22 17:39:29 volumiotouch volumio[5567]: Volumio Calling Home
Sep 22 17:39:29 volumiotouch volumio[5567]: info: CoreStateMachine::resetVolumioState
Sep 22 17:39:29 volumiotouch volumio[5567]: info: CoreStateMachine::getcurrentVolume
Sep 22 17:39:29 volumiotouch volumio[5567]: info: CoreCommandRouter::volumioRetrievevolume
Sep 22 17:39:29 volumiotouch volumio[5567]: info: CoreStateMachine::updateTrackBlock
Sep 22 17:39:29 volumiotouch volumio[5567]: info: CorePlayQueue::getTrackBlock
Sep 22 17:39:29 volumiotouch volumio[5567]: info: Cannot read play queue from file
Sep 22 17:39:29 volumiotouch volumio[5567]: info: Setting Device type: Raspberry PI
Sep 22 17:39:29 volumiotouch volumio[5567]: info: MPD running with PID669 ,establishing connection
Sep 22 17:39:30 volumiotouch volumio[5567]: info: VolumeController:: Volume=40 Mute =false
Sep 22 17:39:30 volumiotouch volumio[5567]: info: CoreStateMachine::pushState
Sep 22 17:39:30 volumiotouch volumio[5567]: info: CoreStateMachine::getState
Sep 22 17:39:30 volumiotouch volumio[5567]: info: CorePlayQueue::getTrack 0
Sep 22 17:39:30 volumiotouch volumio[5567]: info: CoreCommandRouter::volumioPushState
Sep 22 17:39:30 volumiotouch volumio[5567]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 22 17:39:30 volumiotouch volumio[5567]: info: Volumio called home
Sep 22 17:39:30 volumiotouch volumio[5567]: info:
Sep 22 17:39:30 volumiotouch volumio[5567]: info:  message= [50@0] {} No such directory, stack=Error:  [50@0] {} No such directory
Sep 22 17:39:30 volumiotouch volumio[5567]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:63:14)
Sep 22 17:39:30 volumiotouch volumio[5567]: at Socket.<anonymous> (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:10)
Sep 22 17:39:30 volumiotouch volumio[5567]: at emitOne (events.js:116:13)
Sep 22 17:39:30 volumiotouch volumio[5567]: at Socket.emit (events.js:211:7)
Sep 22 17:39:30 volumiotouch volumio[5567]: at addChunk (_stream_readable.js:263:12)
Sep 22 17:39:30 volumiotouch volumio[5567]: at readableAddChunk (_stream_readable.js:246:13)
Sep 22 17:39:30 volumiotouch volumio[5567]: at Socket.Readable.push (_stream_readable.js:208:10)
Sep 22 17:39:30 volumiotouch volumio[5567]: at Pipe.onread (net.js:607:20)
Sep 22 17:39:30 volumiotouch volumio[5567]: info: CoreStateMachine::setRepeat null single undefined
Sep 22 17:39:30 volumiotouch volumio[5567]: info: CoreStateMachine::pushState
Sep 22 17:39:30 volumiotouch volumio[5567]: info: CoreStateMachine::getState
Sep 22 17:39:30 volumiotouch volumio[5567]: info: CorePlayQueue::getTrack 0
Sep 22 17:39:30 volumiotouch volumio[5567]: info: CoreCommandRouter::volumioPushState
Sep 22 17:39:30 volumiotouch volumio[5567]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 22 17:39:30 volumiotouch volumio[5567]: info: CoreStateMachine::setRandom null
Sep 22 17:39:30 volumiotouch volumio[5567]: info: CoreStateMachine::pushState
Sep 22 17:39:30 volumiotouch volumio[5567]: info: CoreStateMachine::getState
Sep 22 17:39:30 volumiotouch volumio[5567]: info: CorePlayQueue::getTrack 0
Sep 22 17:39:30 volumiotouch volumio[5567]: info: CoreCommandRouter::volumioPushState
Sep 22 17:39:30 volumiotouch volumio[5567]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 22 17:39:30 volumiotouch volumio[5567]: info: CoreCommandRouter::volumioGetState
Sep 22 17:39:30 volumiotouch volumio[5567]: info: CoreStateMachine::getState
Sep 22 17:39:30 volumiotouch volumio[5567]: info: CorePlayQueue::getTrack 0
Sep 22 17:39:30 volumiotouch sudo[5639]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart airplay
Sep 22 17:39:30 volumiotouch sudo[5639]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 22 17:39:30 volumiotouch sudo[5641]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart airplay
Sep 22 17:39:30 volumiotouch sudo[5641]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 22 17:39:30 volumiotouch systemd[1]: Stopping ShairportSync AirTunes receiver...
Sep 22 17:39:30 volumiotouch systemd[1]: Starting ShairportSync AirTunes receiver...
Sep 22 17:39:30 volumiotouch systemd[1]: Started ShairportSync AirTunes receiver.
Sep 22 17:39:30 volumiotouch sudo[5639]: pam_unix(sudo:session): session closed for user root
Sep 22 17:39:30 volumiotouch shairport-sync[5651]: Successful Startup
Sep 22 17:39:30 volumiotouch systemd[1]: Stopping ShairportSync AirTunes receiver...
Sep 22 17:39:30 volumiotouch systemd[1]: Starting ShairportSync AirTunes receiver...
Sep 22 17:39:30 volumiotouch systemd[1]: Started ShairportSync AirTunes receiver.
Sep 22 17:39:30 volumiotouch volumio[5567]: Discovery: adding e785f54e-d36a-4ded-900b-ffa1692f9241
Sep 22 17:39:30 volumiotouch sudo[5641]: pam_unix(sudo:session): session closed for user root
Sep 22 17:39:30 volumiotouch volumio[5567]: info: mDNS: Found device Volumiotouch
Sep 22 17:39:30 volumiotouch shairport-sync[5658]: Successful Startup
Sep 22 17:39:30 volumiotouch sudo[5664]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 22 17:39:30 volumiotouch sudo[5664]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 22 17:39:30 volumiotouch sudo[5664]: pam_unix(sudo:session): session closed for user root
Sep 22 17:39:30 volumiotouch volumio[5567]: info: CoreCommandRouter::volumioGetBrowseSources
Sep 22 17:39:30 volumiotouch volumio[5567]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Sep 22 17:39:30 volumiotouch volumio[5567]: info: Listing playlists
Sep 22 17:39:30 volumiotouch sudo[5674]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 22 17:39:30 volumiotouch sudo[5674]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 22 17:39:30 volumiotouch sudo[5674]: pam_unix(sudo:session): session closed for user root
Sep 22 17:39:30 volumiotouch volumio[5567]: info: Shairport-Sync Started
Sep 22 17:39:30 volumiotouch volumio[5567]: Error adding Membership: Error: addMembership EINVAL
Sep 22 17:39:30 volumiotouch volumio[5567]: Discovery: this is already registered,  e785f54e-d36a-4ded-900b-ffa1692f9241
Sep 22 17:39:30 volumiotouch volumio[5567]: info: mDNS: Found device Volumiotouch
Sep 22 17:39:30 volumiotouch sudo[5683]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 22 17:39:30 volumiotouch sudo[5683]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 22 17:39:30 volumiotouch sudo[5683]: pam_unix(sudo:session): session closed for user root
Sep 22 17:39:30 volumiotouch volumio[5567]: info: Shairport-Sync Started
Sep 22 17:39:30 volumiotouch volumio[5567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
Sep 22 17:39:30 volumiotouch volumio[5567]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
Sep 22 17:39:30 volumiotouch volumio[5567]: info: CoreCommandRouter::volumioGetState
Sep 22 17:39:30 volumiotouch volumio[5567]: info: CoreStateMachine::getState
Sep 22 17:39:30 volumiotouch volumio[5567]: info: CorePlayQueue::getTrack 0
Sep 22 17:39:30 volumiotouch sudo[5694]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 22 17:39:30 volumiotouch sudo[5694]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 22 17:39:30 volumiotouch sudo[5694]: pam_unix(sudo:session): session closed for user root
Sep 22 17:39:32 volumiotouch sudo[5717]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 22 17:39:32 volumiotouch sudo[5717]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 22 17:39:32 volumiotouch sudo[5717]: pam_unix(sudo:session): session closed for user root
Sep 22 17:39:32 volumiotouch sudo[5721]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Sep 22 17:39:32 volumiotouch sudo[5721]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 22 17:39:32 volumiotouch systemd[1]: Started UPnP Renderer front-end to MPD.
Sep 22 17:39:32 volumiotouch sudo[5721]: pam_unix(sudo:session): session closed for user root
Sep 22 17:39:32 volumiotouch volumio[5567]: info: Upmpdcli Daemon Started
Sep 22 17:39:36 volumiotouch volumio-remote-updater[643]: [2018-09-22 17:39:36] [connect] Successful connection
Sep 22 17:39:36 volumiotouch volumio-remote-updater[643]: [2018-09-22 17:39:36] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.5.1" /socket.io/?EIO=4&transport=websocket&t=1537637976 101
Sep 22 17:39:54 volumiotouch volumio[5567]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Sep 22 17:39:54 volumiotouch volumio[5567]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 22 17:39:54 volumiotouch volumio[5567]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||

and so on… and so on… in repeat

13

Very very very strange.
Can you explain your system configuration?
Plugins installed?

14

Hardware: RPi3 (not B+), attached to official 7" touchscreen.
Problem occured after updating from 2.444 to 2.452 and remained after updating to 2.457.

I then formatted the SD card completely and re-installed 2.457 with iso and win32diskimager.
I didn’t install any additional plugins or others. Just completed the initial setup wizard.

But unfortunately, the “fatal error” keeps showing up.

15

@michelangelo: did you find something in the logs what can cause this issue?

I’m surprised that no more people experience this problem? :confused:

16

I have the same problem.
RPi2 with IQaudIO Pi-DigiAMP+ and Volumio Version 2.457


ct 22 17:06:40 volumio volumio[1961]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Oct 22 17:06:51 volumio volumio[1961]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Oct 22 17:06:53 volumio volumio[1961]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Oct 22 17:06:53 volumio volumio[1961]: SyntaxError: Unexpected token < in JSON at position 0
Oct 22 17:06:53 volumio volumio[1961]: at JSON.parse (<anonymous>)
Oct 22 17:06:53 volumio volumio[1961]: at IncomingMessage.<anonymous> (/volumio/node_modules/album-art/index.js:30:22)
Oct 22 17:06:53 volumio volumio[1961]: at emitNone (events.js:111:20)
Oct 22 17:06:53 volumio volumio[1961]: at IncomingMessage.emit (events.js:208:7)
Oct 22 17:06:53 volumio volumio[1961]: at endReadableNT (_stream_readable.js:1064:12)
Oct 22 17:06:53 volumio volumio[1961]: at _combinedTickCallback (internal/process/next_tick.js:138:11)
Oct 22 17:06:53 volumio volumio[1961]: at process._tickCallback (internal/process/next_tick.js:180:9)
Oct 22 17:06:53 volumio volumio[1961]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Oct 22 17:06:54 volumio sudo[9299]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2018-10-22 17:05
Oct 22 17:06:54 volumio sudo[9299]: pam_unix(sudo:session): session opened for user root by (uid=0)
Oct 22 17:06:54 volumio sudo[9299]: pam_unix(sudo:session): session closed for user root
Oct 22 17:06:54 volumio volumio-remote-updater[514]: [2018-10-22 17:06:54] [info] asio async_read_at_least error: system:104 (Connection reset by peer)
Oct 22 17:06:54 volumio volumio-remote-updater[514]: [2018-10-22 17:06:54] [error] handle_read_frame error: websocketpp.transport:2 (Underlying Transport Error)
Oct 22 17:06:54 volumio volumio-remote-updater[514]: [2018-10-22 17:06:54] [disconnect] Disconnect close local:[1006,Underlying Transport Error] remote:[1006]
Oct 22 17:06:54 volumio systemd[1]: volumio.service: main process exited, code=exited, status=1/FAILURE
Oct 22 17:06:54 volumio systemd[1]: Unit volumio.service entered failed state.
Oct 22 17:06:54 volumio systemd[1]: Starting dynamicswap service...
Oct 22 17:06:54 volumio systemd[1]: Started dynamicswap service.
Oct 22 17:06:55 volumio systemd[1]: volumio.service holdoff time over, scheduling restart.
Oct 22 17:06:55 volumio systemd[1]: Starting dynamicswap service...
Oct 22 17:06:55 volumio systemd[1]: Started dynamicswap service.
Oct 22 17:06:55 volumio systemd[1]: Stopping Volumio Backend Module...
Oct 22 17:06:55 volumio systemd[1]: Starting Volumio Backend Module...
Oct 22 17:06:55 volumio systemd[1]: Started Volumio Backend Module.
Oct 22 17:06:58 volumio volumio[9325]: info: -------------------------------------------
Oct 22 17:06:58 volumio volumio[9325]: info: -----            Volumio2              ----
Oct 22 17:06:58 volumio volumio[9325]: info: -------------------------------------------
Oct 22 17:06:58 volumio volumio[9325]: info: -----          System startup          ----
Oct 22 17:06:58 volumio volumio[9325]: info: -------------------------------------------

with Volumio Version 2.443 everything works fine.

17

You probably did an npm install manually. can you confirm?

18

? No, I did not an npm install manually.
I have just downloaded the .img and did an fresh install without any plugins.
The problem occur when I try to connect to my Media Server on my FritzBox (7490 OS 7.01) via upnp.

19

Hi guys I also have this problem, is there a known fix?

20

Try the latest version (2.502 on a RPi) as a first step.