Volumio 3 PI 3B+ restar every time, its a loop!

dglonsdale · December 9, 2021, 5:13pm

I’ve also encountered the issue on four separate devices, using different SDs.

gkkpch · December 9, 2021, 5:14pm

That would be weird, in case this were a general issue, we would have dozens of reports.
This must be a local/ individual configuration thing.
The log is your only chance.

mikand · December 21, 2021, 3:50pm

A have the same problem and it appears when I try to activate raspberry pi in premium. If I turn of activation it stops.
Works like a charm in Volumio 2.9

volumio · December 21, 2021, 7:06pm

Please guys try to send the logs as asked, this is the only way we can help…

I think that this might be caused by some firewalls, but we want to make Volumio 3 resilient to those kind of situations

dglonsdale · December 22, 2021, 7:07pm

$ less logondemand

Wed Dec 22 18:30:24 UTC 2021
Description="‘RPi3B restarting in a loop’"

cat /proc/version ---------------

Linux version 5.4.83-v7+ (dom@buildbot) (gcc version 8.4.0 (Ubuntu/Linaro 8.4.0-3ubuntu1)) #1379 SMP Mon Dec 14 13:08:57 GMT 2020

cat /etc/os-release ---------------

PRETTY_NAME=“Raspbian GNU/Linux 10 (buster)”
NAME=“Raspbian GNU/Linux”
VERSION_ID=“10”
VERSION=“10 (buster)”
VERSION_CODENAME=buster
ID=raspbian
ID_LIKE=debian
HOME_URL=“http://www.raspbian.org/”
SUPPORT_URL=“RaspbianForums - Raspbian”
BUG_REPORT_URL=“RaspbianBugs - Raspbian”
VOLUMIO_BUILD_VERSION=“682e0b17433cee9f9da31457f545345105e06e63”
VOLUMIO_FE_VERSION=“fba46add594d630e1b506bc42f1beddaad53fb64”
VOLUMIO_FE3_VERSION=“c23fef6dba8e02db978bd39bd8d26872e60ada6e”
VOLUMIO_BE_VERSION=“f7885966dee9f148ddf4f5050103a7d6734e1a10”
VOLUMIO_ARCH=“arm”
VOLUMIO_VARIANT=“volumio”
VOLUMIO_TEST=“FALSE”
VOLUMIO_BUILD_DATE=“Mon 20 Dec 2021 04:57:50 PM CET”
VOLUMIO_VERSION=“3.179”
VOLUMIO_HARDWARE=“pi”
VOLUMIO_DEVICENAME=“Raspberry Pi”
VOLUMIO_HASH=“6d5d4c489f0b1e608d9cefb791a9102d”

ifconfig ---------------

eth0: flags=4163<UP,BROADCAST,RUNNING,MULTICAST> mtu 1500
inet 192.168.1.53 netmask 255.255.255.0 broadcast 192.168.1.255
ether b8:27:eb:c3:2d:91 txqueuelen 1000 (Ethernet)
RX packets 9721 bytes 2187049 (2.0 MiB)
RX errors 0 dropped 0 overruns 0 frame 0
TX packets 5986 bytes 2869109 (2.7 MiB)
TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0

lo: flags=73<UP,LOOPBACK,RUNNING> mtu 65536
inet 127.0.0.1 netmask 255.0.0.0
loop txqueuelen 1000 (Local Loopback)
RX packets 2888 bytes 282174 (275.5 KiB)
RX errors 0 dropped 0 overruns 0 frame 0
TX packets 2888 bytes 282174 (275.5 KiB)
TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0

sudo iwconfig ---------------

eth0 no wireless extensions.

lo no wireless extensions.

wlan0 IEEE 802.11 ESSID:off/any

dglonsdale · December 22, 2021, 7:11pm

$ cat logondemand (part 1)

Dec 22 18:13:52 volumio sudo[749]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf

Dec 22 18:13:52 volumio sudo[749]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:13:52 volumio sudo[749]: pam_unix(sudo:session): session closed for user root

Dec 22 18:13:52 volumio sudo[751]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service

Dec 22 18:13:52 volumio sudo[751]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:13:52 volumio systemd[1]: Stopping Music Player Daemon…

Dec 22 18:13:52 volumio systemd[1]: mpd.service: Succeeded.

Dec 22 18:13:52 volumio systemd[1]: Stopped Music Player Daemon.

Dec 22 18:13:52 volumio systemd[1]: Starting Music Player Daemon…

Dec 22 18:13:52 volumio volumio[632]: info: Loading plugin “networkfs”…

Dec 22 18:13:53 volumio volumio[632]: info: Starting Udev Watcher for removable devices

Dec 22 18:13:53 volumio volumio[632]: info: Ignoring mount for partition: boot

Dec 22 18:13:53 volumio volumio[632]: info: Ignoring mount for partition: volumio

Dec 22 18:13:53 volumio volumio[632]: info: Ignoring mount for partition: volumio_data

Dec 22 18:13:53 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback

Dec 22 18:13:53 volumio volumio[632]: info: Loading plugin “alarm-clock”…

Dec 22 18:13:53 volumio systemd[1]: systemd-rfkill.service: Succeeded.

Dec 22 18:13:53 volumio volumio[632]: info: Loading plugin “airplay_emulation”…

Dec 22 18:13:53 volumio bthelper[673]: Changing power off succeeded

Dec 22 18:13:53 volumio volumio[632]: info: Starting Shairport Sync

Dec 22 18:13:53 volumio volumio[632]: info: Loading plugin “last_100”…

Dec 22 18:13:53 volumio volumio[632]: info: Loading plugin “webradio”…

Dec 22 18:13:53 volumio mpd[756]: Dec 22 18:13 : exception: Decoder plugin ‘wildmidi’ is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg

Dec 22 18:13:53 volumio mpd[756]: Dec 22 18:13 : exception: Input plugin ‘tidal’ is unavailable: No Tidal application token configured

Dec 22 18:13:53 volumio mpd[756]: Dec 22 18:13 : exception: Input plugin ‘qobuz’ is unavailable: No Qobuz app_id configured

Dec 22 18:13:53 volumio systemd[1]: Started Music Player Daemon.

Dec 22 18:13:53 volumio sudo[751]: pam_unix(sudo:session): session closed for user root

Dec 22 18:13:54 volumio bthelper[673]: [CHG] Controller B8:27:EB:69:87:3B Class: 0x0000041c

Dec 22 18:13:54 volumio bthelper[673]: Changing power on succeeded

Dec 22 18:13:54 volumio bthelper[673]: [CHG] Controller B8:27:EB:69:87:3B Powered: yes

Dec 22 18:13:54 volumio volumio[632]: info: Loading plugin “i2s_dacs”…

Dec 22 18:13:54 volumio volumio[632]: info: I2S DAC not set, start Auto-detection

Dec 22 18:13:54 volumio volumio[632]: info: Loading plugin “volumiodiscovery”…

Dec 22 18:13:54 volumio volumio[632]: *** WARNING *** The program ‘node’ uses the Apple Bonjour compatibility layer of Avahi.

Dec 22 18:13:54 volumio volumio[632]: *** WARNING *** Please fix your application to use the native API of Avahi!

Dec 22 18:13:54 volumio volumio[632]: *** WARNING *** For more information see http://0pointer.de/blog/projects/avahi-compat.html

Dec 22 18:13:54 volumio volumio[632]: *** WARNING *** The program ‘node’ called ‘DNSServiceRegister()’ which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.

Dec 22 18:13:54 volumio node[632]: *** WARNING *** The program ‘node’ uses the Apple Bonjour compatibility layer of Avahi.

Dec 22 18:13:54 volumio volumio[632]: *** WARNING *** Please fix your application to use the native API of Avahi!

Dec 22 18:13:54 volumio volumio[632]: *** WARNING *** For more information see http://0pointer.de/blog/projects/avahi-compat.html

Dec 22 18:13:54 volumio node[632]: *** WARNING *** Please fix your application to use the native API of Avahi!

Dec 22 18:13:54 volumio node[632]: *** WARNING *** For more information see http://0pointer.de/blog/projects/avahi-compat.html

Dec 22 18:13:54 volumio node[632]: *** WARNING *** The program ‘node’ called ‘DNSServiceRegister()’ which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.

Dec 22 18:13:54 volumio node[632]: *** WARNING *** Please fix your application to use the native API of Avahi!

Dec 22 18:13:54 volumio node[632]: *** WARNING *** For more information see http://0pointer.de/blog/projects/avahi-compat.html

Dec 22 18:13:54 volumio volumio[632]: info: Applying required configuration parameters for plugin volumiodiscovery

Dec 22 18:13:54 volumio volumio[632]: info: Discovery: Started advertising with name: Volumio

Dec 22 18:13:54 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback

Dec 22 18:13:54 volumio volumio[632]: info: Loading plugin “outputs”…

Dec 22 18:13:54 volumio volumio[632]: info: Loading plugin “albumart”…

Dec 22 18:13:54 volumio volumio[632]: info: Plugin example_plugin is not enabled

Dec 22 18:13:54 volumio volumio[632]: info: Loading plugin “inputs”…

Dec 22 18:13:54 volumio volumio[632]: info: Loading plugin “updater_comm”…

Dec 22 18:13:54 volumio volumio[632]: info: Plugin mpdemulation is not enabled

Dec 22 18:13:54 volumio volumio[632]: info: Loading plugin “rest_api”…

Dec 22 18:13:54 volumio volumio[632]: info: Loading plugin “websocket”…

Dec 22 18:13:54 volumio volumio[632]: info: Loading i18n strings for locale en

Dec 22 18:13:54 volumio volumio[632]: Updating browse sources language

Dec 22 18:13:54 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources

Dec 22 18:13:54 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam

Dec 22 18:13:54 volumio volumio[632]: info: CoreCommandRouter::initPlayerControls

Dec 22 18:13:54 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:13:54 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam

Dec 22 18:13:54 volumio volumio[632]: Express server listening on port 3000

Dec 22 18:13:54 volumio volumio[632]: [Metrics] WebUI: 6s 608.16ms

Dec 22 18:13:54 volumio volumio[632]: Forking 3 albumart workers

Dec 22 18:13:54 volumio volumio[632]: info: CoreStateMachine::resetVolumioState

Dec 22 18:13:54 volumio volumio[632]: info: CoreStateMachine::getcurrentVolume

Dec 22 18:13:54 volumio volumio[632]: info: CoreCommandRouter::volumioRetrievevolume

Dec 22 18:13:54 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:13:54 volumio volumio[632]: info: Cannot read play queue from file

Dec 22 18:13:54 volumio volumio[632]: info: MPD Permissions set

Dec 22 18:13:54 volumio volumio[632]: verbose: New Socket.io Connection to 192.168.1.53 from 192.168.1.46 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/96.0.4664.110 Safari/537.36 Total Clients: 1

Dec 22 18:13:54 volumio volumio[632]: verbose: New Socket.io Connection to 192.168.1.53 from 192.168.1.46 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/96.0.4664.110 Safari/537.36 Total Clients: 2

Dec 22 18:13:54 volumio volumio[632]: verbose: New Socket.io Connection to 192.168.1.53 from 192.168.1.46 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/96.0.4664.110 Safari/537.36 Total Clients: 3

Dec 22 18:13:54 volumio volumio[632]: info: MPD running with PID756

Dec 22 18:13:54 volumio volumio[632]: ,establishing connection

Dec 22 18:13:54 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:13:55 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:13:55 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:13:55 volumio volumio[632]: error: updateQueue error: null

Dec 22 18:13:55 volumio volumio[632]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory

Dec 22 18:13:55 volumio volumio[632]: info: CoreStateMachine::setRepeat null single undefined

Dec 22 18:13:55 volumio volumio[632]: info: CoreStateMachine::pushState

Dec 22 18:13:55 volumio volumio[632]: info: CorePlayQueue::getTrack 0

Dec 22 18:13:55 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo

Dec 22 18:13:55 volumio volumio[632]: info: CoreCommandRouter::volumioPushState

Dec 22 18:13:55 volumio volumio[632]: info: CoreStateMachine::setRandom null

Dec 22 18:13:55 volumio volumio[632]: info: CoreStateMachine::pushState

Dec 22 18:13:55 volumio volumio[632]: info: CorePlayQueue::getTrack 0

Dec 22 18:13:55 volumio volumio[632]: info: CoreCommandRouter::volumioPushState

Dec 22 18:13:55 volumio volumio[632]: info: Setting Device type: Raspberry PI

Dec 22 18:13:55 volumio volumio[632]: info: VolumeController:: Volume=86 Mute =false

Dec 22 18:13:55 volumio volumio[632]: info: CoreStateMachine::pushState

Dec 22 18:13:55 volumio volumio[632]: info: CorePlayQueue::getTrack 0

Dec 22 18:13:55 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo

Dec 22 18:13:55 volumio volumio[632]: info: CoreCommandRouter::volumioPushState

Dec 22 18:13:55 volumio volumio[632]: info: CoreStateMachine::updateTrackBlock

Dec 22 18:13:55 volumio volumio[632]: info: CorePlayQueue::getTrackBlock

Dec 22 18:13:55 volumio volumio[632]: info: CoreCommandRouter::volumioRetrievevolume

Dec 22 18:13:55 volumio volumio[632]: error: updateQueue error: null

Dec 22 18:13:55 volumio volumio[632]: info: Completed loading Core Plugins

Dec 22 18:13:55 volumio volumio[632]: info: Preparing to generate the ALSA configuration file

Dec 22 18:13:55 volumio volumio[632]: info: Discovery: adding 66c3ef45-2f5b-43a9-9ab2-b917f030ba41

Dec 22 18:13:55 volumio volumio[632]: info: mDNS: Found device Volumio

Dec 22 18:13:55 volumio volumio[632]: info: CoreCommandRouter::volumioGetState

Dec 22 18:13:55 volumio volumio[632]: info: CorePlayQueue::getTrack 0

Dec 22 18:13:55 volumio volumio[632]: info: Asound.conf file unchanged, so no further update is needed

Dec 22 18:13:55 volumio volumio[632]: info: Output device has changed, restarting MPD

Dec 22 18:13:55 volumio volumio[632]: info: Output device has changed, restarting Shairport Sync

Dec 22 18:13:55 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:13:55 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:13:55 volumio sudo[817]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf

Dec 22 18:13:55 volumio sudo[817]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:13:55 volumio sudo[817]: pam_unix(sudo:session): session closed for user root

Dec 22 18:13:55 volumio sudo[819]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service

Dec 22 18:13:55 volumio sudo[819]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:13:55 volumio volumio[632]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0

Dec 22 18:13:55 volumio volumio[632]: info: ___________ START PLUGINS ___________

Dec 22 18:13:55 volumio systemd[1]: Stopping Music Player Daemon…

Dec 22 18:13:55 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam

Dec 22 18:13:55 volumio volumio[632]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]

Dec 22 18:13:55 volumio volumio[632]: info: [1640196835431] CoreMusicLibrary::Adding element Media Servers

Dec 22 18:13:55 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources

Dec 22 18:13:55 volumio volumio[632]: Cannot find translation for sourceMedia Servers

Dec 22 18:13:55 volumio systemd[1]: mpd.service: Succeeded.

Dec 22 18:13:55 volumio systemd[1]: Stopped Music Player Daemon.

Dec 22 18:13:55 volumio systemd[1]: Starting Music Player Daemon…

Dec 22 18:13:55 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:13:55 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:13:55 volumio volumio[632]: Starting albumart workers

Dec 22 18:13:55 volumio volumio[632]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0

Dec 22 18:13:55 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:13:55 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:13:55 volumio volumio[632]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0

Dec 22 18:13:55 volumio volumio[632]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]

Dec 22 18:13:55 volumio volumio[632]: info: [1640196835706] CoreMusicLibrary::Adding element Last_100

Dec 22 18:13:55 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources

Dec 22 18:13:55 volumio volumio[632]: Cannot find translation for sourceMedia Servers

Dec 22 18:13:55 volumio volumio[632]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]

Dec 22 18:13:55 volumio volumio[632]: info: [1640196835711] CoreMusicLibrary::Adding element Webradio

Dec 22 18:13:55 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources

Dec 22 18:13:55 volumio volumio[632]: Cannot find translation for sourceMedia Servers

Dec 22 18:13:55 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion

Dec 22 18:13:55 volumio volumio[632]: info: Volumio Calling Home

Dec 22 18:13:55 volumio volumio[632]: info: Completed starting Core Plugins

Dec 22 18:13:55 volumio volumio[632]: info: -------------------------------------------

Dec 22 18:13:55 volumio volumio[632]: info: ----- MyVolumio plugins startup ----

Dec 22 18:13:55 volumio volumio[632]: info: -------------------------------------------

Dec 22 18:13:55 volumio volumio[632]: info: [MyVolumio PluginManager] Fetching plans data…

Dec 22 18:13:56 volumio volumio[632]: info: MPD Permissions set

Dec 22 18:13:56 volumio volumio[632]: info: VolumeController:: Volume=86 Mute =false

Dec 22 18:13:56 volumio volumio[632]: info: CoreStateMachine::pushState

Dec 22 18:13:56 volumio volumio[632]: info: CorePlayQueue::getTrack 0

Dec 22 18:13:56 volumio volumio[632]: info: CoreCommandRouter::volumioPushState

Dec 22 18:13:56 volumio volumio[632]: info: Volumio called home

Dec 22 18:13:56 volumio volumio[632]: error: error

Dec 22 18:13:56 volumio volumio[632]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 4

Dec 22 18:13:56 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:13:56 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:13:56 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:13:56 volumio volumio[632]: info: Starting Shairport Sync

Dec 22 18:13:56 volumio sudo[865]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync

Dec 22 18:13:56 volumio sudo[865]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:13:56 volumio sudo[867]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync

Dec 22 18:13:56 volumio sudo[867]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:13:56 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver…

Dec 22 18:13:56 volumio sudo[871]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync

Dec 22 18:13:56 volumio sudo[871]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:13:56 volumio systemd[1]: shairport-sync.service: Succeeded.

Dec 22 18:13:56 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver.

Dec 22 18:13:56 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver.

Dec 22 18:13:56 volumio sudo[865]: pam_unix(sudo:session): session closed for user root

Dec 22 18:13:56 volumio sudo[867]: pam_unix(sudo:session): session closed for user root

Dec 22 18:13:56 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver…

Dec 22 18:13:56 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM

Dec 22 18:13:56 volumio systemd[1]: shairport-sync.service: Succeeded.

Dec 22 18:13:56 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver.

Dec 22 18:13:56 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver.

Dec 22 18:13:56 volumio sudo[871]: pam_unix(sudo:session): session closed for user root

Dec 22 18:13:56 volumio volumio[632]: info: Shairport-Sync Started

Dec 22 18:13:56 volumio volumio[632]: Error adding Membership: Error: addMembership EINVAL

Dec 22 18:13:56 volumio volumio[632]: info: Shairport-Sync Started

Dec 22 18:13:56 volumio volumio[632]: info: CoreCommandRouter::volumioGetState

Dec 22 18:13:56 volumio volumio[632]: info: CorePlayQueue::getTrack 0

Dec 22 18:13:57 volumio mpd[832]: Dec 22 18:13 : exception: Decoder plugin ‘wildmidi’ is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg

Dec 22 18:13:57 volumio mpd[832]: Dec 22 18:13 : exception: Input plugin ‘tidal’ is unavailable: No Tidal application token configured

Dec 22 18:13:57 volumio mpd[832]: Dec 22 18:13 : exception: Input plugin ‘qobuz’ is unavailable: No Qobuz app_id configured

Dec 22 18:13:57 volumio systemd[1]: Started Music Player Daemon.

Dec 22 18:13:57 volumio sudo[819]: pam_unix(sudo:session): session closed for user root

Dec 22 18:13:57 volumio volumio[632]: error: updateQueue error: null

Dec 22 18:13:57 volumio sudo[880]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0

Dec 22 18:13:57 volumio sudo[880]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:13:57 volumio sudo[880]: pam_unix(sudo:session): session closed for user root

Dec 22 18:13:57 volumio sudo[882]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0

Dec 22 18:13:57 volumio sudo[882]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:13:57 volumio sudo[882]: pam_unix(sudo:session): session closed for user root

Dec 22 18:13:57 volumio volumio[632]: verbose: New Socket.io Connection to 192.168.1.53 from 192.168.1.46 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/96.0.4664.110 Safari/537.36 Total Clients: 5

Dec 22 18:13:58 volumio volumio[632]: info: CoreCommandRouter::getUIConfigOnPlugin

Dec 22 18:13:58 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam

Dec 22 18:13:58 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom

Dec 22 18:13:58 volumio volumio[632]: info: CoreCommandRouter::volumioGetState

Dec 22 18:13:58 volumio volumio[632]: info: CorePlayQueue::getTrack 0

Dec 22 18:13:58 volumio volumio[632]: info: CoreCommandRouter::volumioGetVisibleSources

Dec 22 18:13:58 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources

Dec 22 18:13:58 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings

Dec 22 18:13:58 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard

Dec 22 18:13:58 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard

Dec 22 18:13:58 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings

Dec 22 18:13:58 volumio volumio[632]: info: Received Get System Version

Dec 22 18:13:58 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion

Dec 22 18:14:00 volumio volumio-remote-updater[447]: [2021-12-22 18:14:00] [connect] Successful connection

Dec 22 18:14:00 volumio volumio-remote-updater[447]: [2021-12-22 18:14:00] [connect] WebSocket Connection 127.0.0.1:3000 v-2 “WebSocket++/0.8.2” /socket.io/?EIO=4&transport=websocket&t=1640196840 101

Dec 22 18:14:00 volumio volumio[632]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 6

Dec 22 18:14:00 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus

Dec 22 18:14:00 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken

Dec 22 18:14:01 volumio sudo[894]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0

Dec 22 18:14:01 volumio sudo[894]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:14:02 volumio sudo[894]: pam_unix(sudo:session): session closed for user root

Dec 22 18:14:02 volumio sudo[896]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0

Dec 22 18:14:02 volumio sudo[896]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:14:02 volumio sudo[896]: pam_unix(sudo:session): session closed for user root

Dec 22 18:14:02 volumio sudo[900]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service

Dec 22 18:14:02 volumio sudo[900]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:14:02 volumio systemd[1]: Started UPnP Renderer front-end to MPD.

Dec 22 18:14:02 volumio sudo[900]: pam_unix(sudo:session): session closed for user root

Dec 22 18:14:02 volumio volumio[632]: info: Upmpdcli Daemon Started

Dec 22 18:14:02 volumio volumio[902]: Generating RSA private key, 4096 bit long modulus (2 primes)

Dec 22 18:14:04 volumio volumio[632]: info: CoreCommandRouter::Close All Modals sent

Dec 22 18:14:04 volumio volumio[632]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium

Dec 22 18:14:04 volumio volumio[632]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium

Dec 22 18:14:04 volumio volumio[632]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium

Dec 22 18:14:04 volumio volumio[632]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium

Dec 22 18:14:04 volumio volumio[632]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium

Dec 22 18:14:04 volumio volumio[632]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium

Dec 22 18:14:04 volumio volumio[632]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium

Dec 22 18:14:04 volumio volumio[632]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium

Dec 22 18:14:04 volumio volumio[632]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium

Dec 22 18:14:04 volumio volumio[632]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar

Dec 22 18:14:04 volumio volumio[632]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar

Dec 22 18:14:04 volumio volumio[632]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar

Dec 22 18:14:04 volumio volumio[632]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar

Dec 22 18:14:04 volumio volumio[632]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar

Dec 22 18:14:04 volumio volumio[632]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar

Dec 22 18:14:04 volumio volumio[632]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar

Dec 22 18:14:04 volumio volumio[632]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar

Dec 22 18:14:04 volumio volumio[632]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar

Dec 22 18:14:04 volumio volumio[632]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso

Dec 22 18:14:04 volumio volumio[632]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso

Dec 22 18:14:04 volumio volumio[632]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso

Dec 22 18:14:04 volumio volumio[632]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso

Dec 22 18:14:04 volumio volumio[632]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso

Dec 22 18:14:04 volumio volumio[632]: info: Adding plugin bluetooth to MyMusic Plugins

Dec 22 18:14:04 volumio volumio[632]: info: Adding plugin multiroom to MyMusic Plugins

Dec 22 18:14:04 volumio volumio[632]: info: Adding plugin cd_controller to MyMusic Plugins

Dec 22 18:14:04 volumio volumio[632]: info: Adding plugin smart_inputs to MyMusic Plugins

Dec 22 18:14:04 volumio volumio[632]: info: Adding plugin tidalconnect to MyMusic Plugins

Dec 22 18:14:04 volumio volumio[632]: info: [MyVolumio PluginManager] Loading plugin “my_volumio”…

Dec 22 18:14:05 volumio volumio[632]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded

Dec 22 18:14:05 volumio volumio[632]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio

Dec 22 18:14:05 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:14:05 volumio volumio[632]: info: Starting MyVolumio Remote Streaming Endpoints

Dec 22 18:14:05 volumio volumio[632]: info: MyVolumio login type: Token

Dec 22 18:14:05 volumio volumio[632]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started

Dec 22 18:14:05 volumio volumio[632]: info: [MyVolumio PluginManager] Loading plugin “streaming_services”…

Dec 22 18:14:05 volumio volumio[632]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded

Dec 22 18:14:05 volumio volumio[632]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services

Dec 22 18:14:05 volumio volumio[632]: info: Streaming services startup

Dec 22 18:14:05 volumio volumio[632]: info: Starting Streaming Daemon

Dec 22 18:14:05 volumio sudo[919]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service

Dec 22 18:14:05 volumio sudo[919]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:14:05 volumio systemd[1]: Stopping Volumio Streaming Daemon…

Dec 22 18:14:05 volumio systemd[1]: volumio-streaming-daemon.service: Main process exited, code=killed, status=15/TERM

Dec 22 18:14:05 volumio systemd[1]: volumio-streaming-daemon.service: Succeeded.

Dec 22 18:14:05 volumio systemd[1]: Stopped Volumio Streaming Daemon.

Dec 22 18:14:05 volumio systemd[1]: Started Volumio Streaming Daemon.

Dec 22 18:14:05 volumio sudo[919]: pam_unix(sudo:session): session closed for user root

Dec 22 18:14:05 volumio volumio-streaming-daemon[925]: ############################

Dec 22 18:14:05 volumio volumio-streaming-daemon[925]: # Volumio Streaming Daemon #

Dec 22 18:14:05 volumio volumio-streaming-daemon[925]: # Running on port 7777 #

Dec 22 18:14:05 volumio volumio-streaming-daemon[925]: ############################

Dec 22 18:14:05 volumio volumio-streaming-daemon[925]: Environment: production

Dec 22 18:14:06 volumio volumio[902]: …++++

Dec 22 18:14:06 volumio volumio[632]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN

Dec 22 18:14:06 volumio volumio[632]: info: MYVOLUMIO: Adding device

Dec 22 18:14:06 volumio volumio[632]: info: MYVOLUMIO: Evaluating Server

Dec 22 18:14:08 volumio volumio-remote-updater[447]: No test mode

Dec 22 18:14:08 volumio volumio-remote-updater[447]: No alpha test mode

Dec 22 18:14:08 volumio volumio[632]: info: Update Ready: {“changeLogLink”:"",“description”:“You’re already on the latest version”,“title”:“No Updates Available”,“updateavailable”:false}

Dec 22 18:14:08 volumio volumio-streaming-daemon[925]: Environment: production

Dec 22 18:14:08 volumio volumio[632]: info: Fetching Streaming Services browse cache

Dec 22 18:14:10 volumio volumio[632]: info: CoreCommandRouter::Close All Modals sent

Dec 22 18:14:10 volumio systemd[1]: systemd-fsckd.service: Succeeded.

Dec 22 18:14:12 volumio volumio[632]: info: [MyVolumio PluginManager] Subscribed plan changed to superstar

Dec 22 18:14:12 volumio volumio[632]: info: Adding audio output:

Dec 22 18:14:12 volumio volumio[632]: info: MYVOLUMIO: Adding device

Dec 22 18:14:12 volumio volumio[632]: info: MYVOLUMIO: Evaluating Server

Dec 22 18:14:12 volumio volumio[632]: info: Remote config written successfully

Dec 22 18:14:12 volumio volumio[632]: info: Starting Tunnel 1

Dec 22 18:14:12 volumio volumio[632]: info: Starting Tunnel Connection Checker

Dec 22 18:14:12 volumio volumio[632]: info: Completed starting MyVolumio Plugin

Dec 22 18:14:12 volumio sudo[949]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service

Dec 22 18:14:12 volumio sudo[949]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:14:12 volumio systemd[1]: Started MyVolumio SSH Tunnel.

Dec 22 18:14:12 volumio sudo[949]: pam_unix(sudo:session): session closed for user root

Dec 22 18:14:12 volumio autossh[956]: port set to 0, monitoring disabled

Dec 22 18:14:12 volumio autossh[956]: starting ssh (count 1)

Dec 22 18:14:12 volumio autossh[956]: ssh child pid is 960

Dec 22 18:14:12 volumio volumio[632]: info: MyVolumio status changed

Dec 22 18:14:12 volumio volumio[632]: info: Streaming services startup

Dec 22 18:14:12 volumio volumio[632]: info: Re-Starting Streaming Daemon

Dec 22 18:14:12 volumio volumio[632]: info: Setting Geolocation for MyVolumio to eu3

Dec 22 18:14:12 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:14:12 volumio volumio[632]: info: Remote SSH Started

Dec 22 18:14:12 volumio volumio-streaming-daemon[925]: Restarting daemon

Dec 22 18:14:12 volumio volumio-streaming-daemon[925]: Environment: production

Dec 22 18:14:12 volumio volumio[632]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7

Dec 22 18:14:12 volumio volumio[632]: info: CoreCommandRouter::volumioGetState

Dec 22 18:14:12 volumio volumio[632]: info: CorePlayQueue::getTrack 0

Dec 22 18:14:13 volumio volumio-streaming-daemon[925]: Environment: production

Dec 22 18:14:13 volumio volumio[902]: …++++

Dec 22 18:14:13 volumio volumio[902]: e is 65537 (0x010001)

Dec 22 18:14:13 volumio volumio[632]: info: Updating MyVolumio device info

Dec 22 18:14:13 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:14:13 volumio volumio[902]: writing RSA key

Dec 22 18:14:13 volumio volumio[632]: info: Fetching Streaming Services browse cache

Dec 22 18:14:17 volumio volumio[632]: info: Setting Geolocation for MyVolumio to eu3

Dec 22 18:14:17 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:14:18 volumio volumio[632]: info: Updating MyVolumio device info

Dec 22 18:14:18 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:14:18 volumio volumio[632]: verbose: New Socket.io Connection to volumio.local from 192.168.1.46 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/96.0.4664.110 Safari/537.36 Total Clients: 7

Dec 22 18:14:19 volumio volumio[632]: info: CoreCommandRouter::volumioGetState

Dec 22 18:14:19 volumio volumio[632]: info: CorePlayQueue::getTrack 0

Dec 22 18:14:19 volumio volumio[632]: info: CoreCommandRouter::volumioGetQueue

Dec 22 18:14:19 volumio volumio[632]: info: CoreStateMachine::getQueue

Dec 22 18:14:19 volumio systemd[1]: systemd-hostnamed.service: Succeeded.

Dec 22 18:14:19 volumio volumio[632]: info: CorePlayQueue::getQueue

Dec 22 18:14:19 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: system , getHwuuid

Dec 22 18:14:22 volumio volumio[632]: info: CALLMETHOD: system_controller system enableSSH true

Dec 22 18:14:22 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: system , enableSSH

Dec 22 18:14:22 volumio sudo[984]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start ssh.service

Dec 22 18:14:22 volumio sudo[984]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:14:22 volumio systemd[1]: Starting OpenBSD Secure Shell server…

Dec 22 18:14:22 volumio sshd[987]: Server listening on 0.0.0.0 port 22.

Dec 22 18:14:22 volumio sshd[987]: Server listening on :: port 22.

Dec 22 18:14:22 volumio systemd[1]: Started OpenBSD Secure Shell server.

Dec 22 18:14:22 volumio sudo[984]: pam_unix(sudo:session): session closed for user root

Dec 22 18:14:22 volumio sudo[988]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl enable ssh.service

Dec 22 18:14:22 volumio sudo[988]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:14:22 volumio systemd[1]: Reloading.

Dec 22 18:14:23 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly.

Dec 22 18:14:23 volumio systemd[1]: getty@tty1.service: Current command vanished from the unit file, execution of the command list won’t be resumed.

Dec 22 18:14:23 volumio systemd[1]: Reloading.

Dec 22 18:14:23 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly.

Dec 22 18:14:24 volumio systemd[1]: Reloading.

Dec 22 18:14:24 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly.

Dec 22 18:14:24 volumio sudo[988]: pam_unix(sudo:session): session closed for user root

Dec 22 18:14:25 volumio volumio[632]: info: enable SSH service success

Dec 22 18:14:25 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion

Dec 22 18:14:25 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:14:33 volumio volumiossh-tunnel[955]: Warning: Permanently added ‘[eu1.myvolumio.org]:2222,[188.166.162.121]:2222’ (RSA) to the list of known hosts.

Dec 22 18:14:37 volumio volumio[632]: verbose: New Socket.io Connection to 192.168.1.53 from 192.168.1.46 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/96.0.4664.110 Safari/537.36 Total Clients: 7

Dec 22 18:14:37 volumio volumio[632]: info: CoreCommandRouter::getUIConfigOnPlugin

Dec 22 18:14:37 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam

Dec 22 18:14:38 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom

Dec 22 18:14:38 volumio volumio[632]: info: CoreCommandRouter::volumioGetState

Dec 22 18:14:38 volumio volumio[632]: info: CorePlayQueue::getTrack 0

Dec 22 18:14:38 volumio volumio[632]: info: CoreCommandRouter::volumioGetVisibleSources

Dec 22 18:14:38 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources

Dec 22 18:14:38 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings

Dec 22 18:14:38 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard

Dec 22 18:14:38 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard

Dec 22 18:14:38 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings

Dec 22 18:14:38 volumio volumio[632]: info: Received Get System Version

Dec 22 18:14:38 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion

Dec 22 18:14:40 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus

Dec 22 18:14:42 volumio volumio[632]: error: MyVolumio Plugins failed to start in a timely fashion

Dec 22 18:14:42 volumio volumio[632]: info: BOOT COMPLETED

Dec 22 18:14:42 volumio volumio[632]: [Metrics] CommandRouter: 53s 160.35ms

Dec 22 18:14:42 volumio volumio[632]: info: CoreCommandRouter::volumiosetStartupVolume

Dec 22 18:14:42 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:14:42 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:14:42 volumio volumio[632]: info: CoreCommandRouter::Close All Modals sent

Dec 22 18:14:43 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable

Dec 22 18:14:43 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus

Dec 22 18:14:43 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect

Dec 22 18:14:43 volumio volumio[632]: info: Version has changed, forcing UI Reload

Dec 22 18:14:43 volumio volumio[632]: info: CoreCommandRouter::Reload Ui

Dec 22 18:14:43 volumio sudo[1063]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0

Dec 22 18:14:43 volumio sudo[1063]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:14:43 volumio sudo[1063]: pam_unix(sudo:session): session closed for user root

Dec 22 18:14:43 volumio sudo[1065]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0

Dec 22 18:14:43 volumio sudo[1065]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:14:43 volumio sudo[1065]: pam_unix(sudo:session): session closed for user root

Dec 22 18:14:43 volumio volumio[632]: verbose: New Socket.io Connection to 192.168.1.53 from 192.168.1.46 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/96.0.4664.110 Safari/537.36 Total Clients: 7

Dec 22 18:14:44 volumio volumio[632]: info: CoreCommandRouter::getUIConfigOnPlugin

Dec 22 18:14:44 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam

Dec 22 18:14:44 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom

Dec 22 18:14:44 volumio volumio[632]: info: CoreCommandRouter::volumioGetState

Dec 22 18:14:44 volumio volumio[632]: info: CorePlayQueue::getTrack 0

Dec 22 18:14:44 volumio volumio[632]: info: CoreCommandRouter::volumioGetVisibleSources

Dec 22 18:14:44 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources

Dec 22 18:14:44 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings

Dec 22 18:14:44 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard

Dec 22 18:14:44 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard

Dec 22 18:14:44 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings

Dec 22 18:14:44 volumio volumio[632]: info: Received Get System Version

Dec 22 18:14:44 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion

Dec 22 18:14:45 volumio volumio[632]: error: error

Dec 22 18:14:46 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus

Dec 22 18:14:47 volumio ntpd[593]: Soliciting pool server 194.0.5.123

Dec 22 18:14:48 volumio ntpd[593]: Soliciting pool server 185.103.119.60

Dec 22 18:14:49 volumio ntpd[593]: Soliciting pool server 162.159.200.1

Dec 22 18:14:49 volumio ntpd[593]: Soliciting pool server 212.159.133.83

Dec 22 18:14:50 volumio ntpd[593]: Soliciting pool server 134.0.16.1

Dec 22 18:14:50 volumio ntpd[593]: Soliciting pool server 77.68.29.174

Dec 22 18:14:50 volumio ntpd[593]: Soliciting pool server 185.103.117.60

Dec 22 18:14:51 volumio ntpd[593]: Soliciting pool server 176.58.109.199

Dec 22 18:14:51 volumio ntpd[593]: Soliciting pool server 51.155.16.62

Dec 22 18:14:52 volumio ntpd[593]: Soliciting pool server 81.21.65.168

Dec 22 18:14:53 volumio ntpd[593]: Soliciting pool server 194.36.144.87

Dec 22 18:14:54 volumio ntpd[593]: Soliciting pool server 194.58.203.148

Dec 22 18:15:36 volumio ntpd[593]: receive: Unexpected origin timestamp 0xe56de99e.f0aa7d7f does not match aorg 0000000000.00000000 from server@162.159.200.1 xmt 0xe56de9c8.b78fd904

Dec 22 18:15:37 volumio ntpd[593]: Soliciting pool server 129.70.132.32

Dec 22 18:15:38 volumio ntpd[593]: Soliciting pool server 129.70.132.33

Dec 22 18:16:16 volumio sshd[1076]: Accepted password for volumio from 192.168.1.46 port 55608 ssh2

Dec 22 18:16:16 volumio sshd[1076]: pam_unix(sshd:session): session opened for user volumio by (uid=0)

Dec 22 18:16:16 volumio systemd[1]: Created slice User Slice of UID 1000.

Dec 22 18:16:16 volumio systemd[1]: Starting User Runtime Directory /run/user/1000…

Dec 22 18:16:16 volumio systemd-logind[417]: New session 1 of user volumio.

Dec 22 18:16:16 volumio systemd[1]: Started User Runtime Directory /run/user/1000.

Dec 22 18:16:16 volumio systemd[1]: Starting User Manager for UID 1000…

Dec 22 18:16:16 volumio systemd[1079]: pam_unix(systemd-user:session): session opened for user volumio by (uid=0)

Dec 22 18:16:17 volumio systemd[1079]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).

Dec 22 18:16:17 volumio systemd[1079]: Listening on GnuPG cryptographic agent and passphrase cache.

Dec 22 18:16:17 volumio systemd[1079]: Listening on Sound System.

Dec 22 18:16:17 volumio systemd[1079]: Listening on GnuPG network certificate management daemon.

Dec 22 18:16:17 volumio systemd[1079]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).

Dec 22 18:16:17 volumio systemd[1079]: Listening on GnuPG cryptographic agent (ssh-agent emulation).

Dec 22 18:16:17 volumio systemd[1079]: Reached target Timers.

Dec 22 18:16:17 volumio systemd[1079]: Starting D-Bus User Message Bus Socket.

Dec 22 18:16:17 volumio systemd[1079]: mpd.socket: Failed to create listening socket ([::]:6600): Address already in use

Dec 22 18:16:17 volumio systemd[1079]: mpd.socket: Failed to listen on sockets: Address already in use

Dec 22 18:16:17 volumio systemd[1079]: mpd.socket: Failed with result ‘resources’.

Dec 22 18:16:17 volumio systemd[1079]: Failed to listen on mpd.socket.

Dec 22 18:16:17 volumio systemd[1079]: Reached target Paths.

Dec 22 18:16:17 volumio systemd[1079]: Listening on D-Bus User Message Bus Socket.

Dec 22 18:16:17 volumio systemd[1079]: Reached target Sockets.

Dec 22 18:16:17 volumio systemd[1079]: Reached target Basic System.

Dec 22 18:16:17 volumio systemd[1]: Started User Manager for UID 1000.

Dec 22 18:16:17 volumio systemd[1079]: Starting Music Player Daemon…

Dec 22 18:16:17 volumio systemd[1]: Started Session 1 of user volumio.

Dec 22 18:16:17 volumio volumio[632]: error: error

Dec 22 18:16:17 volumio mpd[1090]: Dec 22 18:16 : exception: Failed to bind to ‘[::]:6600’

Dec 22 18:16:17 volumio mpd[1090]: Dec 22 18:16 : exception: nested: Failed to bind socket: Address already in use

Dec 22 18:16:17 volumio systemd[1079]: mpd.service: Main process exited, code=exited, status=1/FAILURE

Dec 22 18:16:17 volumio systemd[1079]: mpd.service: Failed with result ‘exit-code’.

Dec 22 18:16:17 volumio systemd[1079]: Failed to start Music Player Daemon.

Dec 22 18:16:17 volumio systemd[1079]: Reached target Default.

Dec 22 18:16:17 volumio systemd[1079]: Startup finished in 1.088s.

Dec 22 18:16:39 volumio sudo[1104]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0

Dec 22 18:16:39 volumio sudo[1104]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:16:39 volumio sudo[1104]: pam_unix(sudo:session): session closed for user root

Dec 22 18:16:39 volumio sudo[1106]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0

Dec 22 18:16:39 volumio sudo[1106]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:16:39 volumio sudo[1106]: pam_unix(sudo:session): session closed for user root

Dec 22 18:16:39 volumio volumio[632]: verbose: New Socket.io Connection to 192.168.1.53 from 192.168.1.46 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/96.0.4664.110 Safari/537.36 Total Clients: 5

Dec 22 18:16:39 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom

Dec 22 18:16:39 volumio volumio[632]: info: CoreCommandRouter::volumioGetState

Dec 22 18:16:39 volumio volumio[632]: info: CorePlayQueue::getTrack 0

Dec 22 18:16:39 volumio volumio[632]: info: CoreCommandRouter::volumioGetVisibleSources

Dec 22 18:16:39 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources

Dec 22 18:16:41 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus

Dec 22 18:16:46 volumio volumio[632]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins…

Dec 22 18:16:46 volumio volumio[632]: info: MyVolumio status changed

Dec 22 18:16:46 volumio volumio[632]: info: Streaming services startup

Dec 22 18:16:46 volumio volumio[632]: info: Re-Starting Streaming Daemon

Dec 22 18:16:46 volumio volumio-streaming-daemon[925]: Restarting daemon

Dec 22 18:16:46 volumio volumio-streaming-daemon[925]: Environment: production

Dec 22 18:16:46 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid

Dec 22 18:16:46 volumio volumio[632]: error: [MyVolumio PluginManager] Could not read cache data: Invalid IV length

Dec 22 18:16:46 volumio volumio-streaming-daemon[925]: Enabled services:

Dec 22 18:16:46 volumio volumio-streaming-daemon[925]: 1) tidal

Dec 22 18:16:46 volumio volumio-streaming-daemon[925]: 2) qobuz

Dec 22 18:16:47 volumio volumio-streaming-daemon[925]: Environment: production

Dec 22 18:16:47 volumio volumio[632]: info: Fetching Streaming Services browse cache

Dec 22 18:16:47 volumio volumio[632]: info: [MyVolumio PluginManager] Loading plugin “bluetooth”…

Dec 22 18:16:47 volumio volumio[632]: info: [1640197007965] Starting BluetoothController

Dec 22 18:16:48 volumio volumio[632]: info: [MyVolumio PluginManager] Loading plugin “multiroom”…

Dec 22 18:16:49 volumio volumio[632]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom

Dec 22 18:16:49 volumio sudo[1111]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod +x /myvolumio/plugins/audio_interface/multiroom/scripts/check_snapcast

Dec 22 18:16:49 volumio sudo[1111]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:16:49 volumio sudo[1111]: pam_unix(sudo:session): session closed for user root

Dec 22 18:16:49 volumio sudo[1113]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom

Dec 22 18:16:49 volumio sudo[1113]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:16:49 volumio sudo[1113]: pam_unix(sudo:session): session closed for user root

Dec 22 18:16:50 volumio volumio[632]: info: MultiRoom plugin initialized

Dec 22 18:16:50 volumio volumio[632]: STOPPING SNAPCLIENT

Dec 22 18:16:50 volumio volumio[632]: info: [MyVolumio PluginManager] Loading plugin “metavolumio”…

Dec 22 18:16:50 volumio sudo[1130]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient

Dec 22 18:16:50 volumio sudo[1130]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:16:50 volumio volumio[632]: info: [MyVolumio PluginManager] Loading plugin “cd_controller”…

Dec 22 18:16:50 volumio sudo[1130]: pam_unix(sudo:session): session closed for user root

Dec 22 18:16:50 volumio volumio[632]: info: [MyVolumio PluginManager] Loading plugin “smart_inputs”…

Dec 22 18:16:50 volumio volumio[632]: info: [MyVolumio PluginManager] Loading plugin “hi_res_audio”…

Dec 22 18:16:50 volumio volumio[632]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio

Dec 22 18:16:50 volumio volumio[632]: info: [MyVolumio PluginManager] Loading plugin “tidal”…

Dec 22 18:16:50 volumio volumio[632]: info: [MyVolumio PluginManager] Loading plugin “qobuz”…

Dec 22 18:16:50 volumio volumio[632]: info: [MyVolumio PluginManager] Loading plugin “tidalconnect”…

Dec 22 18:16:50 volumio volumio[632]: info: Preparing to generate the ALSA configuration file

Dec 22 18:16:50 volumio volumio[632]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid

Dec 22 18:16:50 volumio volumio[632]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||

Dec 22 18:16:50 volumio volumio[632]: TypeError [ERR_INVALID_URL]: Invalid URL: http://:50201/dial.xml

Dec 22 18:16:50 volumio volumio[632]: at onParseError (internal/url.js:259:9)

Dec 22 18:16:50 volumio volumio[632]: at new URL (internal/url.js:335:5)

Dec 22 18:16:50 volumio volumio[632]: at new ClientRequest (_http_client.js:95:28)

Dec 22 18:16:50 volumio volumio[632]: at request (http.js:50:10)

Dec 22 18:16:50 volumio volumio[632]: at Object.get (http.js:54:15)

Dec 22 18:16:50 volumio volumio[632]: at SsdpClient. (/myvolumio/plugins/audio_interface/multiroom/node_modules/chromecast-api/lib/client.js:120:12)

Dec 22 18:16:50 volumio volumio[632]: at SsdpClient.emit (events.js:315:20)

Dec 22 18:16:50 volumio volumio[632]: at SsdpClient.parseResponse [as _parseResponse] (/myvolumio/plugins/audio_interface/multiroom/node_modules/node-ssdp/lib/index.js:457:8)

Dec 22 18:16:50 volumio volumio[632]: at SsdpClient.SSDP._parseMessage (/myvolumio/plugins/audio_interface/multiroom/node_modules/node-ssdp/lib/index.js:298:10)

Dec 22 18:16:50 volumio volumio[632]: at Socket.onSocketMessage (/myvolumio/plugins/audio_interface/multiroom/node_modules/node-ssdp/lib/index.js:244:12)

Dec 22 18:16:50 volumio volumio[632]: at Socket.emit (events.js:315:20)

Dec 22 18:16:50 volumio volumio[632]: at UDP.onMessage [as onmessage] (dgram.js:919:8) {

Dec 22 18:16:50 volumio volumio[632]: input: ‘http://:50201/dial.xml’,

Dec 22 18:16:50 volumio volumio[632]: code: ‘ERR_INVALID_URL’

Dec 22 18:16:50 volumio volumio[632]: }

Dec 22 18:16:50 volumio volumio[632]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||

Dec 22 18:16:50 volumio sudo[1141]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2021-12-22 18:15

Dec 22 18:16:50 volumio sudo[1141]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:16:50 volumio sudo[1141]: pam_unix(sudo:session): session closed for user root

Dec 22 18:16:51 volumio volumio-remote-updater[447]: [2021-12-22 18:16:51] [error] handle_read_frame error: websocketpp.transport:7 (End of File)

Dec 22 18:16:51 volumio volumio-remote-updater[447]: [2021-12-22 18:16:51] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]

Dec 22 18:16:51 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE

Dec 22 18:16:51 volumio systemd[1]: volumio.service: Failed with result ‘exit-code’.

Dec 22 18:16:51 volumio systemd[1]: Started dynamicswap service.

Dec 22 18:16:51 volumio systemd[1]: dynamicswap.service: Succeeded.

Dec 22 18:16:51 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart.

Dec 22 18:16:51 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 1.

Dec 22 18:16:51 volumio systemd[1]: Stopped Volumio Backend Module.

Dec 22 18:16:51 volumio systemd[1]: Started Volumio Backend Module.

Dec 22 18:16:51 volumio systemd[1]: Started dynamicswap service.

Dec 22 18:16:51 volumio systemd[1]: dynamicswap.service: Succeeded.

Dec 22 18:16:53 volumio volumio[1154]: info: -------------------------------------------

Dec 22 18:16:53 volumio volumio[1154]: info: ----- Volumio3 ----

Dec 22 18:16:53 volumio volumio[1154]: info: -------------------------------------------

Dec 22 18:16:53 volumio volumio[1154]: info: ----- System startup ----

Dec 22 18:16:53 volumio volumio[1154]: info: -------------------------------------------

Dec 22 18:16:53 volumio volumio[1154]: info: MYVOLUMIO Environment detected

Dec 22 18:16:53 volumio volumio[1154]: info: Plugin folders cleanup

Dec 22 18:16:53 volumio volumio[1154]: info: Scanning into folder /volumio/app/plugins/

Dec 22 18:16:53 volumio volumio[1154]: info: Scanning category audio_interface

Dec 22 18:16:53 volumio volumio[1154]: info: Scanning category miscellanea

Dec 22 18:16:53 volumio volumio[1154]: info: Scanning category music_service

Dec 22 18:16:53 volumio volumio[1154]: info: Scanning category plugins.json

Dec 22 18:16:53 volumio volumio[1154]: info: Scanning category system_controller

Dec 22 18:16:53 volumio volumio[1154]: info: Scanning category user_interface

Dec 22 18:16:53 volumio volumio[1154]: info: Scanning into folder /data/plugins/

Dec 22 18:16:53 volumio volumio[1154]: info: Plugin folders cleanup completed

Dec 22 18:16:53 volumio volumio[1154]: info: -------------------------------------------

Dec 22 18:16:53 volumio volumio[1154]: info: ----- Core plugins startup ----

Dec 22 18:16:53 volumio volumio[1154]: info: -------------------------------------------

Dec 22 18:16:53 volumio volumio[1154]: info: Loading plugins from folder /volumio/app/plugins/

Dec 22 18:16:53 volumio volumio[1154]: info: Adding plugin upnp to MyMusic Plugins

Dec 22 18:16:53 volumio volumio[1154]: info: Adding plugin airplay_emulation to MyMusic Plugins

Dec 22 18:16:53 volumio volumio[1154]: info: Adding plugin upnp_browser to MyMusic Plugins

Dec 22 18:16:53 volumio volumio[1154]: info: Loading plugins from folder /data/plugins/

Dec 22 18:16:53 volumio volumio[1154]: info: Loading plugin “system”…

Dec 22 18:16:53 volumio volumio[1154]: info: Loading plugin “appearance”…

Dec 22 18:16:54 volumio volumio[1154]: info: Loading plugin “network”…

Dec 22 18:16:54 volumio volumio[1154]: info: Refreshing Cached IP Addresses

Dec 22 18:16:54 volumio sudo[1178]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0

Dec 22 18:16:54 volumio sudo[1178]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:16:54 volumio volumio[1154]: info: Loading plugin “services”…

Dec 22 18:16:54 volumio volumio[1154]: info: Loading plugin “alsa_controller”…

Dec 22 18:16:54 volumio sudo[1178]: pam_unix(sudo:session): session closed for user root

Dec 22 18:16:54 volumio sudo[1180]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0

Dec 22 18:16:54 volumio sudo[1180]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:16:54 volumio sudo[1180]: pam_unix(sudo:session): session closed for user root

Dec 22 18:16:54 volumio volumio[1154]: info: Loading plugin “wizard”…

Dec 22 18:16:54 volumio volumio[1154]: info: Loading plugin “volumio_command_line_client”…

Dec 22 18:16:54 volumio volumio[1154]: info: Loading plugin “upnp”…

Dec 22 18:16:54 volumio volumio[1154]: info: [1640197014974] Starting Upmpd Daemon

Dec 22 18:16:54 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback

Dec 22 18:16:54 volumio volumio[1154]: info: Loading plugin “my_music”…

Dec 22 18:16:54 volumio volumio[1154]: info: Loading plugin “mpd”…

Dec 22 18:16:55 volumio volumio[1154]: info: Creating MPD Configuration file

Dec 22 18:16:55 volumio volumio[1154]: info: Loading plugin “upnp_browser”…

Dec 22 18:16:55 volumio sudo[1188]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf

Dec 22 18:16:55 volumio sudo[1188]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:16:55 volumio sudo[1188]: pam_unix(sudo:session): session closed for user root

Dec 22 18:16:55 volumio sudo[1190]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service

Dec 22 18:16:55 volumio sudo[1190]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:16:55 volumio systemd[1]: Stopping Music Player Daemon…

Dec 22 18:16:55 volumio systemd[1]: mpd.service: Succeeded.

Dec 22 18:16:55 volumio systemd[1]: Stopped Music Player Daemon.

Dec 22 18:16:55 volumio systemd[1]: Starting Music Player Daemon…

Dec 22 18:16:55 volumio volumio[1154]: info: Loading plugin “networkfs”…

Dec 22 18:16:55 volumio volumio[1154]: info: Starting Udev Watcher for removable devices

Dec 22 18:16:56 volumio volumio[1154]: info: Ignoring mount for partition: boot

Dec 22 18:16:56 volumio volumio[1154]: info: Ignoring mount for partition: volumio

Dec 22 18:16:56 volumio volumio[1154]: info: Ignoring mount for partition: volumio_data

Dec 22 18:16:56 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback

Dec 22 18:16:56 volumio volumio[1154]: info: Loading plugin “alarm-clock”…

Dec 22 18:16:56 volumio volumio-remote-updater[447]: [2021-12-22 18:16:56] [connect] Successful connection

Dec 22 18:16:56 volumio volumio[1154]: info: Loading plugin “airplay_emulation”…

Dec 22 18:16:56 volumio volumio[1154]: info: Starting Shairport Sync

Dec 22 18:16:56 volumio volumio[1154]: info: Loading plugin “last_100”…

Dec 22 18:16:56 volumio volumio[1154]: info: Loading plugin “webradio”…

Dec 22 18:16:56 volumio volumio[1154]: info: Loading plugin “i2s_dacs”…

Dec 22 18:16:56 volumio volumio[1154]: info: I2S DAC not set, start Auto-detection

Dec 22 18:16:56 volumio volumio[1154]: info: Loading plugin “volumiodiscovery”…

Dec 22 18:16:56 volumio volumio[1154]: *** WARNING *** The program ‘node’ uses the Apple Bonjour compatibility layer of Avahi.

Dec 22 18:16:56 volumio volumio[1154]: *** WARNING *** Please fix your application to use the native API of Avahi!

Dec 22 18:16:56 volumio volumio[1154]: *** WARNING *** For more information see http://0pointer.de/blog/projects/avahi-compat.html

Dec 22 18:16:56 volumio node[1154]: *** WARNING *** The program ‘node’ uses the Apple Bonjour compatibility layer of Avahi.

Dec 22 18:16:56 volumio volumio[1154]: *** WARNING *** The program ‘node’ called ‘DNSServiceRegister()’ which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.

Dec 22 18:16:56 volumio volumio[1154]: *** WARNING *** Please fix your application to use the native API of Avahi!

Dec 22 18:16:56 volumio volumio[1154]: *** WARNING *** For more information see http://0pointer.de/blog/projects/avahi-compat.html

Dec 22 18:16:56 volumio node[1154]: *** WARNING *** Please fix your application to use the native API of Avahi!

Dec 22 18:16:56 volumio node[1154]: *** WARNING *** For more information see http://0pointer.de/blog/projects/avahi-compat.html

Dec 22 18:16:56 volumio node[1154]: *** WARNING *** The program ‘node’ called ‘DNSServiceRegister()’ which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.

Dec 22 18:16:56 volumio node[1154]: *** WARNING *** Please fix your application to use the native API of Avahi!

Dec 22 18:16:56 volumio node[1154]: *** WARNING *** For more information see http://0pointer.de/blog/projects/avahi-compat.html

Dec 22 18:16:56 volumio volumio[1154]: info: Applying required configuration parameters for plugin volumiodiscovery

Dec 22 18:16:56 volumio volumio[1154]: info: Discovery: Started advertising with name: Volumio

Dec 22 18:16:56 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback

Dec 22 18:16:56 volumio volumio[1154]: info: Loading plugin “outputs”…

dglonsdale · December 22, 2021, 7:12pm

$ cat logondemand (part 2)

Dec 22 18:16:56 volumio volumio[1154]: info: Loading plugin “albumart”…

Dec 22 18:16:56 volumio volumio[1154]: info: Plugin example_plugin is not enabled

Dec 22 18:16:56 volumio volumio[1154]: info: Loading plugin “inputs”…

Dec 22 18:16:56 volumio volumio[1154]: info: Loading plugin “updater_comm”…

Dec 22 18:16:56 volumio mpd[1195]: Dec 22 18:16 : exception: Decoder plugin ‘wildmidi’ is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg

Dec 22 18:16:56 volumio mpd[1195]: Dec 22 18:16 : exception: Input plugin ‘tidal’ is unavailable: No Tidal application token configured

Dec 22 18:16:56 volumio mpd[1195]: Dec 22 18:16 : exception: Input plugin ‘qobuz’ is unavailable: No Qobuz app_id configured

Dec 22 18:16:56 volumio systemd[1]: Started Music Player Daemon.

Dec 22 18:16:56 volumio sudo[1190]: pam_unix(sudo:session): session closed for user root

Dec 22 18:16:56 volumio volumio[1154]: info: Plugin mpdemulation is not enabled

Dec 22 18:16:56 volumio volumio[1154]: info: Loading plugin “rest_api”…

Dec 22 18:16:56 volumio volumio[1154]: info: Loading plugin “websocket”…

Dec 22 18:16:56 volumio volumio[1154]: info: Loading i18n strings for locale en

Dec 22 18:16:56 volumio volumio[1154]: Updating browse sources language

Dec 22 18:16:56 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources

Dec 22 18:16:56 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam

Dec 22 18:16:56 volumio volumio[1154]: info: CoreCommandRouter::initPlayerControls

Dec 22 18:16:56 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:16:56 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam

Dec 22 18:16:56 volumio volumio[1154]: Express server listening on port 3000

Dec 22 18:16:56 volumio volumio[1154]: [Metrics] WebUI: 4s 205.14ms

Dec 22 18:16:56 volumio volumio[1154]: info: CoreStateMachine::resetVolumioState

Dec 22 18:16:56 volumio volumio[1154]: info: CoreStateMachine::getcurrentVolume

Dec 22 18:16:56 volumio volumio[1154]: info: CoreCommandRouter::volumioRetrievevolume

Dec 22 18:16:56 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:16:56 volumio volumio[1154]: Forking 3 albumart workers

Dec 22 18:16:56 volumio volumio[1154]: info: Cannot read play queue from file

Dec 22 18:16:56 volumio volumio[1154]: info: MPD Permissions set

Dec 22 18:16:57 volumio volumio[1154]: verbose: New Socket.io Connection to 192.168.1.53 from 192.168.1.46 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/96.0.4664.110 Safari/537.36 Total Clients: 1

Dec 22 18:16:57 volumio volumio[1154]: verbose: New Socket.io Connection to 192.168.1.53 from 192.168.1.46 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/96.0.4664.110 Safari/537.36 Total Clients: 2

Dec 22 18:16:57 volumio volumio-remote-updater[447]: [2021-12-22 18:16:57] [connect] WebSocket Connection 127.0.0.1:3000 v-2 “WebSocket++/0.8.2” /socket.io/?EIO=4&transport=websocket&t=1640197016 101

Dec 22 18:16:57 volumio volumio[1154]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 3

Dec 22 18:16:57 volumio volumio[1154]: info: MPD running with PID1195

Dec 22 18:16:57 volumio volumio[1154]: ,establishing connection

Dec 22 18:16:57 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:16:57 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:16:57 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:16:57 volumio volumio[1154]: error: updateQueue error: null

Dec 22 18:16:57 volumio volumio[1154]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory

Dec 22 18:16:57 volumio volumio[1154]: info: CoreStateMachine::setRepeat null single undefined

Dec 22 18:16:57 volumio volumio[1154]: info: CoreStateMachine::pushState

Dec 22 18:16:57 volumio volumio[1154]: info: CorePlayQueue::getTrack 0

Dec 22 18:16:57 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo

Dec 22 18:16:57 volumio volumio[1154]: info: CoreCommandRouter::volumioPushState

Dec 22 18:16:57 volumio volumio[1154]: info: CoreStateMachine::setRandom null

Dec 22 18:16:57 volumio volumio[1154]: info: CoreStateMachine::pushState

Dec 22 18:16:57 volumio volumio[1154]: info: CorePlayQueue::getTrack 0

Dec 22 18:16:57 volumio volumio[1154]: info: CoreCommandRouter::volumioPushState

Dec 22 18:16:57 volumio volumio[1154]: info: Setting Device type: Raspberry PI

Dec 22 18:16:57 volumio volumio[1154]: info: VolumeController:: Volume=86 Mute =false

Dec 22 18:16:57 volumio volumio[1154]: info: CoreStateMachine::pushState

Dec 22 18:16:57 volumio volumio[1154]: info: CorePlayQueue::getTrack 0

Dec 22 18:16:57 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo

Dec 22 18:16:57 volumio volumio[1154]: info: CoreCommandRouter::volumioPushState

Dec 22 18:16:57 volumio volumio[1154]: info: CoreStateMachine::updateTrackBlock

Dec 22 18:16:57 volumio volumio[1154]: info: CorePlayQueue::getTrackBlock

Dec 22 18:16:57 volumio volumio[1154]: info: CoreCommandRouter::volumioRetrievevolume

Dec 22 18:16:57 volumio volumio[1154]: error: updateQueue error: null

Dec 22 18:16:57 volumio volumio[1154]: info: Completed loading Core Plugins

Dec 22 18:16:57 volumio volumio[1154]: info: Preparing to generate the ALSA configuration file

Dec 22 18:16:57 volumio volumio[1154]: info: Asound.conf file unchanged, so no further update is needed

Dec 22 18:16:57 volumio volumio[1154]: info: Output device has changed, restarting MPD

Dec 22 18:16:57 volumio sudo[1248]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf

Dec 22 18:16:57 volumio sudo[1248]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:16:57 volumio sudo[1248]: pam_unix(sudo:session): session closed for user root

Dec 22 18:16:57 volumio volumio[1154]: info: Output device has changed, restarting Shairport Sync

Dec 22 18:16:57 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:16:57 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:16:57 volumio sudo[1251]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service

Dec 22 18:16:57 volumio sudo[1251]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:16:57 volumio volumio[1154]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0

Dec 22 18:16:57 volumio systemd[1]: Stopping Music Player Daemon…

Dec 22 18:16:57 volumio volumio[1154]: info: ___________ START PLUGINS ___________

Dec 22 18:16:57 volumio systemd[1]: mpd.service: Succeeded.

Dec 22 18:16:57 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam

Dec 22 18:16:57 volumio systemd[1]: Stopped Music Player Daemon.

Dec 22 18:16:57 volumio volumio[1154]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]

Dec 22 18:16:57 volumio volumio[1154]: info: [1640197017679] CoreMusicLibrary::Adding element Media Servers

Dec 22 18:16:57 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources

Dec 22 18:16:57 volumio volumio[1154]: Cannot find translation for sourceMedia Servers

Dec 22 18:16:57 volumio systemd[1]: Starting Music Player Daemon…

Dec 22 18:16:57 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:16:57 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:16:57 volumio volumio[1154]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0

Dec 22 18:16:57 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:16:57 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:16:57 volumio volumio[1154]: Starting albumart workers

Dec 22 18:16:57 volumio volumio[1154]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0

Dec 22 18:16:57 volumio volumio[1154]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]

Dec 22 18:16:57 volumio volumio[1154]: info: [1640197017954] CoreMusicLibrary::Adding element Last_100

Dec 22 18:16:57 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources

Dec 22 18:16:57 volumio volumio[1154]: Cannot find translation for sourceMedia Servers

Dec 22 18:16:57 volumio volumio[1154]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]

Dec 22 18:16:57 volumio volumio[1154]: info: [1640197017960] CoreMusicLibrary::Adding element Webradio

Dec 22 18:16:57 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources

Dec 22 18:16:57 volumio volumio[1154]: Cannot find translation for sourceMedia Servers

Dec 22 18:16:57 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion

Dec 22 18:16:57 volumio volumio[1154]: Starting albumart workers

Dec 22 18:16:57 volumio volumio[1154]: info: Volumio Calling Home

Dec 22 18:16:58 volumio volumio[1154]: info: Completed starting Core Plugins

Dec 22 18:16:58 volumio volumio[1154]: info: -------------------------------------------

Dec 22 18:16:58 volumio volumio[1154]: info: ----- MyVolumio plugins startup ----

Dec 22 18:16:58 volumio volumio[1154]: info: -------------------------------------------

Dec 22 18:16:58 volumio volumio[1154]: info: [MyVolumio PluginManager] Fetching plans data…

Dec 22 18:16:58 volumio volumio[1154]: info: Discovery: adding 66c3ef45-2f5b-43a9-9ab2-b917f030ba41

Dec 22 18:16:58 volumio volumio[1154]: info: mDNS: Found device Volumio

Dec 22 18:16:58 volumio volumio[1154]: info: CoreCommandRouter::volumioGetState

Dec 22 18:16:58 volumio volumio[1154]: info: CorePlayQueue::getTrack 0

Dec 22 18:16:58 volumio volumio[1154]: info: MPD Permissions set

Dec 22 18:16:58 volumio volumio[1154]: info: VolumeController:: Volume=86 Mute =false

Dec 22 18:16:58 volumio volumio[1154]: info: CoreStateMachine::pushState

Dec 22 18:16:58 volumio volumio[1154]: info: CorePlayQueue::getTrack 0

Dec 22 18:16:58 volumio volumio[1154]: info: CoreCommandRouter::volumioPushState

Dec 22 18:16:58 volumio volumio[1154]: info: Volumio called home

Dec 22 18:16:58 volumio volumio[1154]: error: error

Dec 22 18:16:58 volumio volumio[1154]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 4

Dec 22 18:16:58 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:16:58 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:16:58 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:16:58 volumio volumio[1154]: info: Starting Shairport Sync

Dec 22 18:16:58 volumio sudo[1297]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync

Dec 22 18:16:58 volumio sudo[1297]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:16:58 volumio volumio[1154]: info: Starting Shairport Sync

Dec 22 18:16:58 volumio sudo[1300]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync

Dec 22 18:16:58 volumio sudo[1300]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:16:58 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver…

Dec 22 18:16:58 volumio systemd[1]: shairport-sync.service: Succeeded.

Dec 22 18:16:58 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver.

Dec 22 18:16:58 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver.

Dec 22 18:16:58 volumio sudo[1297]: pam_unix(sudo:session): session closed for user root

Dec 22 18:16:59 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver…

Dec 22 18:16:59 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM

Dec 22 18:16:59 volumio systemd[1]: shairport-sync.service: Succeeded.

Dec 22 18:16:59 volumio sudo[1302]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync

Dec 22 18:16:59 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver.

Dec 22 18:16:59 volumio sudo[1302]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:16:59 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver.

Dec 22 18:16:59 volumio sudo[1300]: pam_unix(sudo:session): session closed for user root

Dec 22 18:16:59 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver…

Dec 22 18:16:59 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM

Dec 22 18:16:59 volumio systemd[1]: shairport-sync.service: Succeeded.

Dec 22 18:16:59 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver.

Dec 22 18:16:59 volumio volumio[1154]: info: Shairport-Sync Started

Dec 22 18:16:59 volumio volumio[1154]: Error adding Membership: Error: addMembership EINVAL

Dec 22 18:16:59 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver.

Dec 22 18:16:59 volumio sudo[1302]: pam_unix(sudo:session): session closed for user root

Dec 22 18:16:59 volumio volumio[1154]: info: Shairport-Sync Started

Dec 22 18:16:59 volumio volumio[1154]: info: CoreCommandRouter::volumioGetState

Dec 22 18:16:59 volumio volumio[1154]: info: CorePlayQueue::getTrack 0

Dec 22 18:16:59 volumio mpd[1264]: Dec 22 18:16 : exception: Decoder plugin ‘wildmidi’ is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg

Dec 22 18:16:59 volumio mpd[1264]: Dec 22 18:16 : exception: Input plugin ‘tidal’ is unavailable: No Tidal application token configured

Dec 22 18:16:59 volumio mpd[1264]: Dec 22 18:16 : exception: Input plugin ‘qobuz’ is unavailable: No Qobuz app_id configured

Dec 22 18:16:59 volumio systemd[1]: Started Music Player Daemon.

Dec 22 18:16:59 volumio sudo[1251]: pam_unix(sudo:session): session closed for user root

Dec 22 18:16:59 volumio volumio[1154]: error: updateQueue error: null

Dec 22 18:16:59 volumio volumio[1154]: verbose: New Socket.io Connection to 192.168.1.53 from 192.168.1.46 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/96.0.4664.110 Safari/537.36 Total Clients: 5

Dec 22 18:16:59 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom

Dec 22 18:16:59 volumio volumio[1154]: info: CoreCommandRouter::volumioGetState

Dec 22 18:16:59 volumio volumio[1154]: info: CorePlayQueue::getTrack 0

Dec 22 18:16:59 volumio volumio[1154]: info: CoreCommandRouter::volumioGetVisibleSources

Dec 22 18:16:59 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources

Dec 22 18:16:59 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom

Dec 22 18:16:59 volumio volumio[1154]: info: CoreCommandRouter::volumioGetState

Dec 22 18:16:59 volumio volumio[1154]: info: CorePlayQueue::getTrack 0

Dec 22 18:16:59 volumio volumio[1154]: info: CoreCommandRouter::volumioGetVisibleSources

Dec 22 18:16:59 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources

Dec 22 18:17:05 volumio sudo[1313]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0

Dec 22 18:17:05 volumio sudo[1313]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:05 volumio sudo[1313]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:05 volumio sudo[1315]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0

Dec 22 18:17:05 volumio sudo[1315]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:05 volumio sudo[1315]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:05 volumio sudo[1319]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service

Dec 22 18:17:05 volumio sudo[1319]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:05 volumio sudo[1319]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:05 volumio volumio[1154]: info: Upmpdcli Daemon Started

Dec 22 18:17:06 volumio volumio[1154]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium

Dec 22 18:17:06 volumio volumio[1154]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium

Dec 22 18:17:06 volumio volumio[1154]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium

Dec 22 18:17:06 volumio volumio[1154]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium

Dec 22 18:17:06 volumio volumio[1154]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium

Dec 22 18:17:06 volumio volumio[1154]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium

Dec 22 18:17:06 volumio volumio[1154]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium

Dec 22 18:17:06 volumio volumio[1154]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium

Dec 22 18:17:06 volumio volumio[1154]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium

Dec 22 18:17:06 volumio volumio[1154]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar

Dec 22 18:17:06 volumio volumio[1154]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar

Dec 22 18:17:06 volumio volumio[1154]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar

Dec 22 18:17:06 volumio volumio[1154]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar

Dec 22 18:17:06 volumio volumio[1154]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar

Dec 22 18:17:06 volumio volumio[1154]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar

Dec 22 18:17:06 volumio volumio[1154]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar

Dec 22 18:17:06 volumio volumio[1154]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar

Dec 22 18:17:06 volumio volumio[1154]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar

Dec 22 18:17:06 volumio volumio[1154]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso

Dec 22 18:17:06 volumio volumio[1154]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso

Dec 22 18:17:06 volumio volumio[1154]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso

Dec 22 18:17:06 volumio volumio[1154]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso

Dec 22 18:17:06 volumio volumio[1154]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso

Dec 22 18:17:06 volumio volumio[1154]: info: Adding plugin bluetooth to MyMusic Plugins

Dec 22 18:17:06 volumio volumio[1154]: info: Adding plugin multiroom to MyMusic Plugins

Dec 22 18:17:06 volumio volumio[1154]: info: Adding plugin cd_controller to MyMusic Plugins

Dec 22 18:17:06 volumio volumio[1154]: info: Adding plugin smart_inputs to MyMusic Plugins

Dec 22 18:17:06 volumio volumio[1154]: info: Adding plugin tidalconnect to MyMusic Plugins

Dec 22 18:17:06 volumio volumio[1154]: info: [MyVolumio PluginManager] Loading plugin “my_volumio”…

Dec 22 18:17:07 volumio volumio[1154]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded

Dec 22 18:17:07 volumio volumio[1154]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio

Dec 22 18:17:07 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:17:07 volumio volumio[1154]: info: Starting MyVolumio Remote Streaming Endpoints

Dec 22 18:17:07 volumio volumio[1154]: info: MyVolumio login type: Token

Dec 22 18:17:07 volumio volumio[1154]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started

Dec 22 18:17:07 volumio volumio[1154]: info: [MyVolumio PluginManager] Loading plugin “streaming_services”…

Dec 22 18:17:07 volumio volumio[1154]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded

Dec 22 18:17:07 volumio volumio[1154]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services

Dec 22 18:17:07 volumio volumio[1154]: info: Streaming services startup

Dec 22 18:17:07 volumio volumio[1154]: info: Starting Streaming Daemon

Dec 22 18:17:07 volumio sudo[1323]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service

Dec 22 18:17:07 volumio sudo[1323]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:07 volumio systemd[1]: Stopping Volumio Streaming Daemon…

Dec 22 18:17:07 volumio systemd[1]: volumio-streaming-daemon.service: Main process exited, code=killed, status=15/TERM

Dec 22 18:17:07 volumio systemd[1]: volumio-streaming-daemon.service: Succeeded.

Dec 22 18:17:07 volumio systemd[1]: Stopped Volumio Streaming Daemon.

Dec 22 18:17:07 volumio systemd[1]: Started Volumio Streaming Daemon.

Dec 22 18:17:07 volumio sudo[1323]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:07 volumio volumio-streaming-daemon[1329]: ############################

Dec 22 18:17:07 volumio volumio-streaming-daemon[1329]: # Volumio Streaming Daemon #

Dec 22 18:17:07 volumio volumio-streaming-daemon[1329]: # Running on port 7777 #

Dec 22 18:17:07 volumio volumio-streaming-daemon[1329]: ############################

Dec 22 18:17:07 volumio volumio-streaming-daemon[1329]: Environment: production

Dec 22 18:17:08 volumio volumio[1154]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN

Dec 22 18:17:08 volumio volumio[1154]: info: MYVOLUMIO: Adding device

Dec 22 18:17:08 volumio volumio[1154]: info: MYVOLUMIO: Evaluating Server

Dec 22 18:17:09 volumio volumio[1154]: info: [MyVolumio PluginManager] Subscribed plan changed to superstar

Dec 22 18:17:09 volumio volumio[1154]: info: Adding audio output:

Dec 22 18:17:09 volumio volumio[1154]: info: MYVOLUMIO: Adding device

Dec 22 18:17:09 volumio volumio[1154]: info: MYVOLUMIO: Evaluating Server

Dec 22 18:17:09 volumio volumio[1154]: info: Remote config written successfully

Dec 22 18:17:09 volumio volumio[1154]: info: Starting Tunnel 1

Dec 22 18:17:09 volumio volumio[1154]: info: Starting Tunnel Connection Checker

Dec 22 18:17:09 volumio volumio[1154]: info: Completed starting MyVolumio Plugin

Dec 22 18:17:09 volumio sudo[1351]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service

Dec 22 18:17:09 volumio sudo[1351]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:09 volumio autossh[956]: received signal to exit (15)

Dec 22 18:17:09 volumio systemd[1]: Stopping MyVolumio SSH Tunnel…

Dec 22 18:17:09 volumio systemd[1]: sshtunnel.service: Main process exited, code=killed, status=15/TERM

Dec 22 18:17:09 volumio systemd[1]: sshtunnel.service: Succeeded.

Dec 22 18:17:09 volumio systemd[1]: Stopped MyVolumio SSH Tunnel.

Dec 22 18:17:09 volumio systemd[1]: Started MyVolumio SSH Tunnel.

Dec 22 18:17:09 volumio autossh[1355]: port set to 0, monitoring disabled

Dec 22 18:17:09 volumio autossh[1355]: starting ssh (count 1)

Dec 22 18:17:09 volumio autossh[1355]: ssh child pid is 1358

Dec 22 18:17:09 volumio sudo[1351]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:09 volumio volumio[1154]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins…

Dec 22 18:17:09 volumio volumio[1154]: info: MyVolumio status changed

Dec 22 18:17:09 volumio volumio[1154]: info: Streaming services startup

Dec 22 18:17:09 volumio volumio[1154]: info: Re-Starting Streaming Daemon

Dec 22 18:17:09 volumio volumio[1154]: info: Setting Geolocation for MyVolumio to eu3

Dec 22 18:17:09 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:17:09 volumio volumio[1154]: info: Remote SSH Started

Dec 22 18:17:09 volumio volumio[1154]: info: Setting Geolocation for MyVolumio to eu3

Dec 22 18:17:09 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:17:09 volumio volumio[1154]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 6

Dec 22 18:17:09 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid

Dec 22 18:17:09 volumio volumio[1154]: error: [MyVolumio PluginManager] Could not read cache data: Invalid IV length

Dec 22 18:17:09 volumio volumio[1154]: info: CoreCommandRouter::volumioGetState

Dec 22 18:17:09 volumio volumio[1154]: info: CorePlayQueue::getTrack 0

Dec 22 18:17:10 volumio volumio[1154]: error: Failed initialization of streaming services: Error: An error occurred while retrieving enabled services.

Dec 22 18:17:10 volumio volumio[1154]: info: [MyVolumio PluginManager] Loading plugin “bluetooth”…

Dec 22 18:17:10 volumio volumio[1154]: info: [1640197030515] Starting BluetoothController

Dec 22 18:17:10 volumio volumio[1154]: info: [MyVolumio PluginManager] Loading plugin “multiroom”…

Dec 22 18:17:11 volumio volumio-streaming-daemon[1329]: Enabled services:

Dec 22 18:17:11 volumio volumio-streaming-daemon[1329]: 1) tidal

Dec 22 18:17:11 volumio volumio-streaming-daemon[1329]: 2) qobuz

Dec 22 18:17:12 volumio volumio[1154]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom

Dec 22 18:17:12 volumio sudo[1367]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod +x /myvolumio/plugins/audio_interface/multiroom/scripts/check_snapcast

Dec 22 18:17:12 volumio sudo[1367]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:12 volumio sudo[1367]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:12 volumio sudo[1370]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom

Dec 22 18:17:12 volumio sudo[1370]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:12 volumio sudo[1370]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:12 volumio volumio[1154]: info: MultiRoom plugin initialized

Dec 22 18:17:12 volumio volumio[1154]: STOPPING SNAPCLIENT

Dec 22 18:17:12 volumio volumio[1154]: info: [MyVolumio PluginManager] Loading plugin “metavolumio”…

Dec 22 18:17:12 volumio sudo[1386]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient

Dec 22 18:17:12 volumio sudo[1386]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:12 volumio volumio[1154]: info: [MyVolumio PluginManager] Loading plugin “cd_controller”…

Dec 22 18:17:12 volumio sudo[1386]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:12 volumio volumio[1154]: info: [MyVolumio PluginManager] Loading plugin “smart_inputs”…

Dec 22 18:17:12 volumio volumio[1154]: info: [MyVolumio PluginManager] Loading plugin “hi_res_audio”…

Dec 22 18:17:12 volumio volumio[1154]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio

Dec 22 18:17:12 volumio volumio[1154]: info: [MyVolumio PluginManager] Loading plugin “tidal”…

Dec 22 18:17:12 volumio volumio[1154]: info: [MyVolumio PluginManager] Loading plugin “qobuz”…

Dec 22 18:17:12 volumio volumio[1154]: info: [MyVolumio PluginManager] Loading plugin “tidalconnect”…

Dec 22 18:17:12 volumio volumio[1154]: info: Preparing to generate the ALSA configuration file

Dec 22 18:17:12 volumio volumio[1154]: info: Updating MyVolumio device info

Dec 22 18:17:12 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:17:12 volumio volumio[1154]: info: Updating MyVolumio device info

Dec 22 18:17:12 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:17:12 volumio volumio[1154]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid

Dec 22 18:17:12 volumio volumio[1154]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||

Dec 22 18:17:12 volumio volumio[1154]: TypeError [ERR_INVALID_URL]: Invalid URL: http://:50201/dial.xml

Dec 22 18:17:12 volumio volumio[1154]: at onParseError (internal/url.js:259:9)

Dec 22 18:17:12 volumio volumio[1154]: at new URL (internal/url.js:335:5)

Dec 22 18:17:12 volumio volumio[1154]: at new ClientRequest (_http_client.js:95:28)

Dec 22 18:17:12 volumio volumio[1154]: at request (http.js:50:10)

Dec 22 18:17:12 volumio volumio[1154]: at Object.get (http.js:54:15)

Dec 22 18:17:12 volumio volumio[1154]: at SsdpClient. (/myvolumio/plugins/audio_interface/multiroom/node_modules/chromecast-api/lib/client.js:120:12)

Dec 22 18:17:12 volumio volumio[1154]: at SsdpClient.emit (events.js:315:20)

Dec 22 18:17:12 volumio volumio[1154]: at SsdpClient.parseResponse [as _parseResponse] (/myvolumio/plugins/audio_interface/multiroom/node_modules/node-ssdp/lib/index.js:457:8)

Dec 22 18:17:12 volumio volumio[1154]: at SsdpClient.SSDP._parseMessage (/myvolumio/plugins/audio_interface/multiroom/node_modules/node-ssdp/lib/index.js:298:10)

Dec 22 18:17:12 volumio volumio[1154]: at Socket.onSocketMessage (/myvolumio/plugins/audio_interface/multiroom/node_modules/node-ssdp/lib/index.js:244:12)

Dec 22 18:17:12 volumio volumio[1154]: at Socket.emit (events.js:315:20)

Dec 22 18:17:12 volumio volumio[1154]: at UDP.onMessage [as onmessage] (dgram.js:919:8) {

Dec 22 18:17:12 volumio volumio[1154]: input: ‘http://:50201/dial.xml’,

Dec 22 18:17:12 volumio volumio[1154]: code: ‘ERR_INVALID_URL’

Dec 22 18:17:12 volumio volumio[1154]: }

Dec 22 18:17:12 volumio volumio[1154]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||

Dec 22 18:17:13 volumio sudo[1397]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2021-12-22 18:16

Dec 22 18:17:13 volumio sudo[1397]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:13 volumio sudo[1397]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:13 volumio volumio-remote-updater[447]: [2021-12-22 18:17:13] [error] handle_read_frame error: websocketpp.transport:7 (End of File)

Dec 22 18:17:13 volumio volumio-remote-updater[447]: [2021-12-22 18:17:13] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]

Dec 22 18:17:13 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE

Dec 22 18:17:13 volumio systemd[1]: volumio.service: Failed with result ‘exit-code’.

Dec 22 18:17:13 volumio systemd[1]: Started dynamicswap service.

Dec 22 18:17:13 volumio systemd[1]: dynamicswap.service: Succeeded.

Dec 22 18:17:13 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart.

Dec 22 18:17:13 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 2.

Dec 22 18:17:13 volumio systemd[1]: Stopped Volumio Backend Module.

Dec 22 18:17:13 volumio systemd[1]: Started Volumio Backend Module.

Dec 22 18:17:13 volumio systemd[1]: Started dynamicswap service.

Dec 22 18:17:13 volumio systemd[1]: dynamicswap.service: Succeeded.

Dec 22 18:17:15 volumio volumio[1407]: info: -------------------------------------------

Dec 22 18:17:15 volumio volumio[1407]: info: ----- Volumio3 ----

Dec 22 18:17:15 volumio volumio[1407]: info: -------------------------------------------

Dec 22 18:17:15 volumio volumio[1407]: info: ----- System startup ----

Dec 22 18:17:15 volumio volumio[1407]: info: -------------------------------------------

Dec 22 18:17:15 volumio volumio[1407]: info: MYVOLUMIO Environment detected

Dec 22 18:17:15 volumio volumio[1407]: info: Plugin folders cleanup

Dec 22 18:17:15 volumio volumio[1407]: info: Scanning into folder /volumio/app/plugins/

Dec 22 18:17:15 volumio volumio[1407]: info: Scanning category audio_interface

Dec 22 18:17:15 volumio volumio[1407]: info: Scanning category miscellanea

Dec 22 18:17:15 volumio volumio[1407]: info: Scanning category music_service

Dec 22 18:17:15 volumio volumio[1407]: info: Scanning category plugins.json

Dec 22 18:17:15 volumio volumio[1407]: info: Scanning category system_controller

Dec 22 18:17:15 volumio volumio[1407]: info: Scanning category user_interface

Dec 22 18:17:15 volumio volumio[1407]: info: Scanning into folder /data/plugins/

Dec 22 18:17:15 volumio volumio[1407]: info: Plugin folders cleanup completed

Dec 22 18:17:15 volumio volumio[1407]: info: -------------------------------------------

Dec 22 18:17:15 volumio volumio[1407]: info: ----- Core plugins startup ----

Dec 22 18:17:15 volumio volumio[1407]: info: -------------------------------------------

Dec 22 18:17:15 volumio volumio[1407]: info: Loading plugins from folder /volumio/app/plugins/

Dec 22 18:17:15 volumio volumio[1407]: info: Adding plugin upnp to MyMusic Plugins

Dec 22 18:17:15 volumio volumio[1407]: info: Adding plugin airplay_emulation to MyMusic Plugins

Dec 22 18:17:15 volumio volumio[1407]: info: Adding plugin upnp_browser to MyMusic Plugins

Dec 22 18:17:15 volumio volumio[1407]: info: Loading plugins from folder /data/plugins/

Dec 22 18:17:15 volumio volumio[1407]: info: Loading plugin “system”…

Dec 22 18:17:15 volumio volumio[1407]: info: Loading plugin “appearance”…

Dec 22 18:17:16 volumio volumio[1407]: info: Loading plugin “network”…

Dec 22 18:17:16 volumio volumio[1407]: info: Refreshing Cached IP Addresses

Dec 22 18:17:16 volumio sudo[1431]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0

Dec 22 18:17:16 volumio sudo[1431]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:16 volumio volumio[1407]: info: Loading plugin “services”…

Dec 22 18:17:16 volumio sudo[1431]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:16 volumio volumio[1407]: info: Loading plugin “alsa_controller”…

Dec 22 18:17:16 volumio sudo[1434]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0

Dec 22 18:17:16 volumio sudo[1434]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:16 volumio sudo[1434]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:16 volumio volumio[1407]: info: Loading plugin “wizard”…

Dec 22 18:17:16 volumio volumio[1407]: info: Loading plugin “volumio_command_line_client”…

Dec 22 18:17:16 volumio volumio[1407]: info: Loading plugin “upnp”…

Dec 22 18:17:16 volumio volumio[1407]: info: [1640197036978] Starting Upmpd Daemon

Dec 22 18:17:16 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback

Dec 22 18:17:16 volumio volumio[1407]: info: Loading plugin “my_music”…

Dec 22 18:17:16 volumio volumio[1407]: info: Loading plugin “mpd”…

Dec 22 18:17:17 volumio volumio[1407]: info: Creating MPD Configuration file

Dec 22 18:17:17 volumio volumio[1407]: info: Loading plugin “upnp_browser”…

Dec 22 18:17:17 volumio sudo[1441]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf

Dec 22 18:17:17 volumio sudo[1441]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:17 volumio sudo[1441]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:17 volumio sudo[1443]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service

Dec 22 18:17:17 volumio sudo[1443]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:17 volumio systemd[1]: Stopping Music Player Daemon…

Dec 22 18:17:17 volumio systemd[1]: mpd.service: Succeeded.

Dec 22 18:17:17 volumio systemd[1]: Stopped Music Player Daemon.

Dec 22 18:17:17 volumio systemd[1]: Starting Music Player Daemon…

Dec 22 18:17:17 volumio volumio[1407]: info: Loading plugin “networkfs”…

Dec 22 18:17:17 volumio volumio[1407]: info: Starting Udev Watcher for removable devices

Dec 22 18:17:18 volumio volumio[1407]: info: Ignoring mount for partition: boot

Dec 22 18:17:18 volumio volumio[1407]: info: Ignoring mount for partition: volumio

Dec 22 18:17:18 volumio volumio[1407]: info: Ignoring mount for partition: volumio_data

Dec 22 18:17:18 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback

Dec 22 18:17:18 volumio volumio[1407]: info: Loading plugin “alarm-clock”…

Dec 22 18:17:18 volumio volumio-remote-updater[447]: [2021-12-22 18:17:18] [connect] Successful connection

Dec 22 18:17:18 volumio volumio[1407]: info: Loading plugin “airplay_emulation”…

Dec 22 18:17:18 volumio volumio[1407]: info: Starting Shairport Sync

Dec 22 18:17:18 volumio volumio[1407]: info: Loading plugin “last_100”…

Dec 22 18:17:18 volumio volumio[1407]: info: Loading plugin “webradio”…

Dec 22 18:17:18 volumio volumio[1407]: info: Loading plugin “i2s_dacs”…

Dec 22 18:17:18 volumio volumio[1407]: info: I2S DAC not set, start Auto-detection

Dec 22 18:17:18 volumio volumio[1407]: info: Loading plugin “volumiodiscovery”…

Dec 22 18:17:18 volumio volumio[1407]: *** WARNING *** The program ‘node’ uses the Apple Bonjour compatibility layer of Avahi.

Dec 22 18:17:18 volumio node[1407]: *** WARNING *** The program ‘node’ uses the Apple Bonjour compatibility layer of Avahi.

Dec 22 18:17:18 volumio volumio[1407]: *** WARNING *** Please fix your application to use the native API of Avahi!

Dec 22 18:17:18 volumio node[1407]: *** WARNING *** Please fix your application to use the native API of Avahi!

Dec 22 18:17:18 volumio volumio[1407]: *** WARNING *** For more information see http://0pointer.de/blog/projects/avahi-compat.html

Dec 22 18:17:18 volumio node[1407]: *** WARNING *** For more information see http://0pointer.de/blog/projects/avahi-compat.html

Dec 22 18:17:18 volumio volumio[1407]: *** WARNING *** The program ‘node’ called ‘DNSServiceRegister()’ which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.

Dec 22 18:17:18 volumio node[1407]: *** WARNING *** The program ‘node’ called ‘DNSServiceRegister()’ which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.

Dec 22 18:17:18 volumio volumio[1407]: *** WARNING *** Please fix your application to use the native API of Avahi!

Dec 22 18:17:18 volumio node[1407]: *** WARNING *** Please fix your application to use the native API of Avahi!

Dec 22 18:17:18 volumio volumio[1407]: *** WARNING *** For more information see http://0pointer.de/blog/projects/avahi-compat.html

Dec 22 18:17:18 volumio node[1407]: *** WARNING *** For more information see http://0pointer.de/blog/projects/avahi-compat.html

Dec 22 18:17:18 volumio volumio[1407]: info: Applying required configuration parameters for plugin volumiodiscovery

Dec 22 18:17:18 volumio volumio[1407]: info: Discovery: Started advertising with name: Volumio

Dec 22 18:17:18 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback

Dec 22 18:17:18 volumio volumio[1407]: info: Loading plugin “outputs”…

Dec 22 18:17:18 volumio volumio[1407]: info: Loading plugin “albumart”…

Dec 22 18:17:18 volumio volumio[1407]: info: Plugin example_plugin is not enabled

Dec 22 18:17:18 volumio volumio[1407]: info: Loading plugin “inputs”…

Dec 22 18:17:18 volumio volumio[1407]: info: Loading plugin “updater_comm”…

Dec 22 18:17:18 volumio mpd[1448]: Dec 22 18:17 : exception: Decoder plugin ‘wildmidi’ is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg

Dec 22 18:17:18 volumio mpd[1448]: Dec 22 18:17 : exception: Input plugin ‘tidal’ is unavailable: No Tidal application token configured

Dec 22 18:17:18 volumio mpd[1448]: Dec 22 18:17 : exception: Input plugin ‘qobuz’ is unavailable: No Qobuz app_id configured

Dec 22 18:17:18 volumio systemd[1]: Started Music Player Daemon.

Dec 22 18:17:18 volumio sudo[1443]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:18 volumio volumio[1407]: info: Plugin mpdemulation is not enabled

Dec 22 18:17:18 volumio volumio[1407]: info: Loading plugin “rest_api”…

Dec 22 18:17:18 volumio volumio[1407]: info: Loading plugin “websocket”…

Dec 22 18:17:18 volumio volumio[1407]: info: Loading i18n strings for locale en

Dec 22 18:17:18 volumio volumio[1407]: Updating browse sources language

Dec 22 18:17:18 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources

Dec 22 18:17:18 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam

Dec 22 18:17:18 volumio volumio[1407]: info: CoreCommandRouter::initPlayerControls

Dec 22 18:17:18 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:17:18 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam

Dec 22 18:17:18 volumio volumio[1407]: Express server listening on port 3000

Dec 22 18:17:18 volumio volumio[1407]: [Metrics] WebUI: 4s 239.67ms

Dec 22 18:17:18 volumio volumio[1407]: info: CoreStateMachine::resetVolumioState

Dec 22 18:17:18 volumio volumio[1407]: info: CoreStateMachine::getcurrentVolume

Dec 22 18:17:18 volumio volumio[1407]: info: CoreCommandRouter::volumioRetrievevolume

Dec 22 18:17:18 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:17:18 volumio volumio[1407]: info: Cannot read play queue from file

Dec 22 18:17:18 volumio volumio[1407]: Forking 3 albumart workers

Dec 22 18:17:19 volumio volumio[1407]: info: MPD Permissions set

Dec 22 18:17:19 volumio volumio[1407]: verbose: New Socket.io Connection to 192.168.1.53 from 192.168.1.46 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/96.0.4664.110 Safari/537.36 Total Clients: 1

Dec 22 18:17:19 volumio volumio[1407]: verbose: New Socket.io Connection to 192.168.1.53 from 192.168.1.46 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/96.0.4664.110 Safari/537.36 Total Clients: 2

Dec 22 18:17:19 volumio volumio-remote-updater[447]: [2021-12-22 18:17:19] [connect] WebSocket Connection 127.0.0.1:3000 v-2 “WebSocket++/0.8.2” /socket.io/?EIO=4&transport=websocket&t=1640197038 101

Dec 22 18:17:19 volumio volumio[1407]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 3

Dec 22 18:17:19 volumio volumio[1407]: info: MPD running with PID1448

Dec 22 18:17:19 volumio volumio[1407]: ,establishing connection

Dec 22 18:17:19 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:17:19 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:17:19 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:17:19 volumio volumio[1407]: error: updateQueue error: null

Dec 22 18:17:19 volumio volumio[1407]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory

Dec 22 18:17:19 volumio volumio[1407]: info: CoreStateMachine::setRepeat null single undefined

Dec 22 18:17:19 volumio volumio[1407]: info: CoreStateMachine::pushState

Dec 22 18:17:19 volumio volumio[1407]: info: CorePlayQueue::getTrack 0

Dec 22 18:17:19 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo

Dec 22 18:17:19 volumio volumio[1407]: info: CoreCommandRouter::volumioPushState

Dec 22 18:17:19 volumio volumio[1407]: info: CoreStateMachine::setRandom null

Dec 22 18:17:19 volumio volumio[1407]: info: CoreStateMachine::pushState

Dec 22 18:17:19 volumio volumio[1407]: info: CorePlayQueue::getTrack 0

Dec 22 18:17:19 volumio volumio[1407]: info: CoreCommandRouter::volumioPushState

Dec 22 18:17:19 volumio volumio[1407]: info: Setting Device type: Raspberry PI

Dec 22 18:17:19 volumio volumio[1407]: info: VolumeController:: Volume=86 Mute =false

Dec 22 18:17:19 volumio volumio[1407]: info: CoreStateMachine::pushState

Dec 22 18:17:19 volumio volumio[1407]: info: CorePlayQueue::getTrack 0

Dec 22 18:17:19 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo

Dec 22 18:17:19 volumio volumio[1407]: info: CoreCommandRouter::volumioPushState

Dec 22 18:17:19 volumio volumio[1407]: info: CoreStateMachine::updateTrackBlock

Dec 22 18:17:19 volumio volumio[1407]: info: CorePlayQueue::getTrackBlock

Dec 22 18:17:19 volumio volumio[1407]: info: CoreCommandRouter::volumioRetrievevolume

Dec 22 18:17:19 volumio volumio[1407]: error: updateQueue error: null

Dec 22 18:17:19 volumio volumio[1407]: info: Completed loading Core Plugins

Dec 22 18:17:19 volumio volumio[1407]: info: Preparing to generate the ALSA configuration file

Dec 22 18:17:19 volumio volumio[1407]: info: Asound.conf file unchanged, so no further update is needed

Dec 22 18:17:19 volumio volumio[1407]: info: Output device has changed, restarting MPD

Dec 22 18:17:19 volumio sudo[1501]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf

Dec 22 18:17:19 volumio volumio[1407]: info: Output device has changed, restarting Shairport Sync

Dec 22 18:17:19 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:17:19 volumio sudo[1501]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:19 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:17:19 volumio sudo[1501]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:19 volumio sudo[1503]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service

Dec 22 18:17:19 volumio sudo[1503]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:19 volumio volumio[1407]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0

Dec 22 18:17:19 volumio volumio[1407]: info: ___________ START PLUGINS ___________

Dec 22 18:17:19 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam

Dec 22 18:17:19 volumio volumio[1407]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]

Dec 22 18:17:19 volumio volumio[1407]: info: [1640197039671] CoreMusicLibrary::Adding element Media Servers

Dec 22 18:17:19 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources

Dec 22 18:17:19 volumio systemd[1]: Stopping Music Player Daemon…

Dec 22 18:17:19 volumio volumio[1407]: Cannot find translation for sourceMedia Servers

Dec 22 18:17:19 volumio systemd[1]: mpd.service: Succeeded.

Dec 22 18:17:19 volumio systemd[1]: Stopped Music Player Daemon.

Dec 22 18:17:19 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:17:19 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:17:19 volumio systemd[1]: Starting Music Player Daemon…

Dec 22 18:17:19 volumio volumio[1407]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0

Dec 22 18:17:19 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:17:19 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:17:19 volumio volumio[1407]: Starting albumart workers

Dec 22 18:17:20 volumio volumio[1407]: Starting albumart workers

Dec 22 18:17:20 volumio volumio[1407]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0

Dec 22 18:17:20 volumio volumio[1407]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]

Dec 22 18:17:20 volumio volumio[1407]: info: [1640197040016] CoreMusicLibrary::Adding element Last_100

Dec 22 18:17:20 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources

Dec 22 18:17:20 volumio volumio[1407]: Cannot find translation for sourceMedia Servers

Dec 22 18:17:20 volumio volumio[1407]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]

Dec 22 18:17:20 volumio volumio[1407]: info: [1640197040022] CoreMusicLibrary::Adding element Webradio

Dec 22 18:17:20 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources

Dec 22 18:17:20 volumio volumio[1407]: Starting albumart workers

Dec 22 18:17:20 volumio volumio[1407]: Cannot find translation for sourceMedia Servers

Dec 22 18:17:20 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion

Dec 22 18:17:20 volumio volumio[1407]: info: Volumio Calling Home

Dec 22 18:17:20 volumio volumio[1407]: info: Completed starting Core Plugins

Dec 22 18:17:20 volumio volumio[1407]: info: -------------------------------------------

Dec 22 18:17:20 volumio volumio[1407]: info: ----- MyVolumio plugins startup ----

Dec 22 18:17:20 volumio volumio[1407]: info: -------------------------------------------

Dec 22 18:17:20 volumio volumio[1407]: info: [MyVolumio PluginManager] Fetching plans data…

Dec 22 18:17:20 volumio volumio[1407]: info: MPD Permissions set

Dec 22 18:17:20 volumio volumio[1407]: info: VolumeController:: Volume=86 Mute =false

Dec 22 18:17:20 volumio volumio[1407]: info: CoreStateMachine::pushState

Dec 22 18:17:20 volumio volumio[1407]: info: CorePlayQueue::getTrack 0

Dec 22 18:17:20 volumio volumio[1407]: info: CoreCommandRouter::volumioPushState

Dec 22 18:17:20 volumio volumio[1407]: info: Volumio called home

Dec 22 18:17:20 volumio volumio[1407]: error: error

Dec 22 18:17:20 volumio volumio[1407]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 4

Dec 22 18:17:20 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:17:20 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:17:20 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:17:20 volumio volumio[1407]: info: Discovery: adding 66c3ef45-2f5b-43a9-9ab2-b917f030ba41

Dec 22 18:17:20 volumio volumio[1407]: info: mDNS: Found device Volumio

Dec 22 18:17:20 volumio volumio[1407]: info: CoreCommandRouter::volumioGetState

Dec 22 18:17:20 volumio volumio[1407]: info: CorePlayQueue::getTrack 0

Dec 22 18:17:21 volumio volumio[1407]: info: Starting Shairport Sync

Dec 22 18:17:21 volumio sudo[1550]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync

Dec 22 18:17:21 volumio sudo[1550]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:21 volumio sudo[1552]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync

Dec 22 18:17:21 volumio sudo[1552]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:21 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver…

Dec 22 18:17:21 volumio systemd[1]: shairport-sync.service: Succeeded.

Dec 22 18:17:21 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver.

Dec 22 18:17:21 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver.

Dec 22 18:17:21 volumio sudo[1550]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:21 volumio sudo[1556]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync

Dec 22 18:17:21 volumio sudo[1556]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:21 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver…

Dec 22 18:17:21 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM

Dec 22 18:17:21 volumio systemd[1]: shairport-sync.service: Succeeded.

Dec 22 18:17:21 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver.

Dec 22 18:17:21 volumio sudo[1552]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:21 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver.

Dec 22 18:17:21 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver…

Dec 22 18:17:21 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM

Dec 22 18:17:21 volumio systemd[1]: shairport-sync.service: Succeeded.

Dec 22 18:17:21 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver.

Dec 22 18:17:21 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver.

Dec 22 18:17:21 volumio sudo[1556]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:21 volumio volumio[1407]: info: Shairport-Sync Started

Dec 22 18:17:21 volumio volumio[1407]: Error adding Membership: Error: addMembership EINVAL

Dec 22 18:17:21 volumio volumio[1407]: info: Shairport-Sync Started

Dec 22 18:17:21 volumio volumio[1407]: info: CoreCommandRouter::volumioGetState

Dec 22 18:17:21 volumio volumio[1407]: info: CorePlayQueue::getTrack 0

Dec 22 18:17:21 volumio mpd[1517]: Dec 22 18:17 : exception: Decoder plugin ‘wildmidi’ is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg

Dec 22 18:17:21 volumio mpd[1517]: Dec 22 18:17 : exception: Input plugin ‘tidal’ is unavailable: No Tidal application token configured

Dec 22 18:17:21 volumio mpd[1517]: Dec 22 18:17 : exception: Input plugin ‘qobuz’ is unavailable: No Qobuz app_id configured

Dec 22 18:17:21 volumio systemd[1]: Started Music Player Daemon.

Dec 22 18:17:21 volumio sudo[1503]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:21 volumio volumio[1407]: error: updateQueue error: null

Dec 22 18:17:21 volumio volumio[1407]: verbose: New Socket.io Connection to 192.168.1.53 from 192.168.1.46 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/96.0.4664.110 Safari/537.36 Total Clients: 5

Dec 22 18:17:21 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom

Dec 22 18:17:21 volumio volumio[1407]: info: CoreCommandRouter::volumioGetState

Dec 22 18:17:21 volumio volumio[1407]: info: CorePlayQueue::getTrack 0

Dec 22 18:17:21 volumio volumio[1407]: info: CoreCommandRouter::volumioGetVisibleSources

Dec 22 18:17:21 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources

Dec 22 18:17:21 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom

Dec 22 18:17:21 volumio volumio[1407]: info: CoreCommandRouter::volumioGetState

mikand · December 23, 2021, 7:26am

Starting Live Log…
Started Volumio Streaming Daemon.
pam_unix(sudo:session): session closed for user root
############################

Volumio Streaming Daemon

Running on port 7777

############################
Environment: production
info: CALLMETHOD: system_controller system enableLiveLog true
info: CoreCommandRouter::executeOnPlugin: system , enableLiveLog
info: Launching a new LiveLog session
Enabled services:

tidal
qobuz
info: MYVOLUMIO SUCCESSFULLY LOGGED IN
info: MYVOLUMIO: Adding device
info: MYVOLUMIO: Evaluating Server
info: [MyVolumio PluginManager] Subscribed plan changed to premium
info: Removing browser output: myVolumio user plan is not superstar
info: Removing audio output:
info: MYVOLUMIO: Adding device
info: MYVOLUMIO: Evaluating Server
info: Remote config written successfully
info: Starting Tunnel 1
info: Starting Tunnel Connection Checker
info: Completed starting MyVolumio Plugin
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service
pam_unix(sudo:session): session opened for user root by (uid=0)
received signal to exit (15)
Stopping MyVolumio SSH Tunnel…
sshtunnel.service: Main process exited, code=killed, status=15/TERM
sshtunnel.service: Succeeded.
Stopped MyVolumio SSH Tunnel.
Started MyVolumio SSH Tunnel.
pam_unix(sudo:session): session closed for user root
info: Remote SSH Started
port set to 0, monitoring disabled
starting ssh (count 1)
ssh child pid is 2221
info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins…
info: MyVolumio status changed
info: Streaming services startup
info: Re-Starting Streaming Daemon
Starting Live Log…
info: mDNS: Found device Volumio3
info: CoreCommandRouter::volumioGetState
info: CorePlayQueue::getTrack 0
Started Shairport Sync - AirPlay Audio Receiver.
pam_unix(sudo:session): session closed for user root
error: updateQueue error: null
Stopping Shairport Sync - AirPlay Audio Receiver…
shairport-sync.service: Main process exited, code=killed, status=15/TERM
shairport-sync.service: Succeeded.
Stopped Shairport Sync - AirPlay Audio Receiver.
Started Shairport Sync - AirPlay Audio Receiver.
pam_unix(sudo:session): session closed for user root
Stopping Shairport Sync - AirPlay Audio Receiver…
shairport-sync.service: Main process exited, code=killed, status=15/TERM
shairport-sync.service: Succeeded.
Stopped Shairport Sync - AirPlay Audio Receiver.
Started Shairport Sync - AirPlay Audio Receiver.
info: Shairport-Sync Started
Error adding Membership: Error: addMembership EINVAL
pam_unix(sudo:session): session closed for user root
info: Shairport-Sync Started
info: CoreCommandRouter::volumioGetState
info: CorePlayQueue::getTrack 0
info: Shairport-Sync Started
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
pam_unix(sudo:session): session opened for user root by (uid=0)
pam_unix(sudo:session): session closed for user root
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
pam_unix(sudo:session): session opened for user root by (uid=0)
pam_unix(sudo:session): session closed for user root
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
pam_unix(sudo:session): session opened for user root by (uid=0)
pam_unix(sudo:session): session closed for user root
info: Upmpdcli Daemon Started
info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
info: Adding plugin bluetooth to MyMusic Plugins
info: Adding plugin multiroom to MyMusic Plugins
info: Adding plugin cd_controller to MyMusic Plugins
info: Adding plugin smart_inputs to MyMusic Plugins
info: Adding plugin tidalconnect to MyMusic Plugins
info: [MyVolumio PluginManager] Loading plugin “my_volumio”…
info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
info: Starting MyVolumio Remote Streaming Endpoints
info: MyVolumio login type: Token
info: [MyVolumio PluginManager] MyVolumio plugin successfully started
info: [MyVolumio PluginManager] Loading plugin “streaming_services”…
info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
info: Streaming services startup
info: Starting Streaming Daemon
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
pam_unix(sudo:session): session opened for user root by (uid=0)
Stopping Volumio Streaming Daemon…
volumio-streaming-daemon.service: Main process exited, code=killed, status=15/TERM
volumio-streaming-daemon.service: Succeeded.
Stopped Volumio Streaming Daemon.
Started Volumio Streaming Daemon.
pam_unix(sudo:session): session closed for user root
############################

Volumio Streaming Daemon

Running on port 7777

############################
Environment: production
Enabled services:

tidal
qobuz
info: MYVOLUMIO SUCCESSFULLY LOGGED IN
info: MYVOLUMIO: Adding device
info: MYVOLUMIO: Evaluating Server
info: [MyVolumio PluginManager] Subscribed plan changed to premium
info: Removing browser output: myVolumio user plan is not superstar
info: Removing audio output:
info: MYVOLUMIO: Adding device
info: MYVOLUMIO: Evaluating Server
info: Remote config written successfully
info: Starting Tunnel 1
info: Starting Tunnel Connection Checker
info: Completed starting MyVolumio Plugin
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service
pam_unix(sudo:session): session opened for user root by (uid=0)
received signal to exit (15)
Stopping MyVolumio SSH Tunnel…
sshtunnel.service: Main process exited, code=killed, status=15/TERM
sshtunnel.service: Succeeded.
Stopped MyVolumio SSH Tunnel.
Started MyVolumio SSH Tunnel.
pam_unix(sudo:session): session closed for user root
info: Remote SSH Started
port set to 0, monitoring disabled
starting ssh (count 1)
ssh child pid is 2716
info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins…
Starting Live Log…
pam_unix(sudo:session): session closed for user root
info: [MyVolumio PluginManager] Loading plugin “hi_res_audio”…
info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio
info: [MyVolumio PluginManager] Loading plugin “tidal”…
info: [MyVolumio PluginManager] Loading plugin “qobuz”…
info: [MyVolumio PluginManager] Loading plugin “tidalconnect”…
info: Preparing to generate the ALSA configuration file
info: CALLMETHOD: system_controller system enableLiveLog true
info: CoreCommandRouter::executeOnPlugin: system , enableLiveLog
info: Launching a new LiveLog session
Starting Live Log…
shairport-sync.service: Main process exited, code=killed, status=15/TERM
shairport-sync.service: Succeeded.
info: Discovery: adding 3fdd24c5-1493-49fe-92e6-a213b5ff03d6
info: mDNS: Found device Volumio3
Stopped Shairport Sync - AirPlay Audio Receiver.
pam_unix(sudo:session): session opened for user root by (uid=0)
info: CoreCommandRouter::volumioGetState
info: CorePlayQueue::getTrack 0
Started Shairport Sync - AirPlay Audio Receiver.
pam_unix(sudo:session): session closed for user root
Stopping Shairport Sync - AirPlay Audio Receiver…
shairport-sync.service: Main process exited, code=killed, status=15/TERM
shairport-sync.service: Succeeded.
Stopped Shairport Sync - AirPlay Audio Receiver.
Started Shairport Sync - AirPlay Audio Receiver.
error: updateQueue error: null
pam_unix(sudo:session): session closed for user root
info: Shairport-Sync Started
Error adding Membership: Error: addMembership EINVAL
info: Shairport-Sync Started
info: Shairport-Sync Started
info: CoreCommandRouter::volumioGetState
info: CorePlayQueue::getTrack 0
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
pam_unix(sudo:session): session opened for user root by (uid=0)
pam_unix(sudo:session): session closed for user root
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
pam_unix(sudo:session): session opened for user root by (uid=0)
pam_unix(sudo:session): session closed for user root
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
pam_unix(sudo:session): session opened for user root by (uid=0)
pam_unix(sudo:session): session closed for user root
info: Upmpdcli Daemon Started
info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
info: Adding plugin bluetooth to MyMusic Plugins
info: Adding plugin multiroom to MyMusic Plugins
info: Adding plugin cd_controller to MyMusic Plugins
info: Adding plugin smart_inputs to MyMusic Plugins
info: Adding plugin tidalconnect to MyMusic Plugins
info: [MyVolumio PluginManager] Loading plugin “my_volumio”…
info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
info: Starting MyVolumio Remote Streaming Endpoints
info: MyVolumio login type: Token
info: [MyVolumio PluginManager] MyVolumio plugin successfully started
info: [MyVolumio PluginManager] Loading plugin “streaming_services”…
info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
info: Streaming services startup
info: Starting Streaming Daemon
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
pam_unix(sudo:session): session opened for user root by (uid=0)
Stopping Volumio Streaming Daemon…
volumio-streaming-daemon.service: Main process exited, code=killed, status=15/TERM
volumio-streaming-daemon.service: Succeeded.
Stopped Volumio Streaming Daemon.
Started Volumio Streaming Daemon.
pam_unix(sudo:session): session closed for user root
############################

Volumio Streaming Daemon

Running on port 7777

############################
Environment: production
Enabled services:

tidal
qobuz
info: MYVOLUMIO SUCCESSFULLY LOGGED IN
info: MYVOLUMIO: Adding device
info: MYVOLUMIO: Evaluating Server
info: [MyVolumio PluginManager] Subscribed plan changed to premium
info: Removing browser output: myVolumio user plan is not superstar
info: Removing audio output:
info: MYVOLUMIO: Adding device
info: MYVOLUMIO: Evaluating Server
info: Remote config written successfully
info: Starting Tunnel 1
info: Starting Tunnel Connection Checker
info: Completed starting MyVolumio Plugin
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service
pam_unix(sudo:session): session opened for user root by (uid=0)
received signal to exit (15)
Stopping MyVolumio SSH Tunnel…
sshtunnel.service: Main process exited, code=killed, status=15/TERM
sshtunnel.service: Succeeded.
Stopped MyVolumio SSH Tunnel.
Started MyVolumio SSH Tunnel.
pam_unix(sudo:session): session closed for user root
info: Remote SSH Started
port set to 0, monitoring disabled
starting ssh (count 1)
ssh child pid is 3463

dglonsdale · December 23, 2021, 9:20am

$ cat logondemand (part 3 of 3)

Dec 22 18:17:21 volumio volumio[1407]: info: CorePlayQueue::getTrack 0

Dec 22 18:17:21 volumio volumio[1407]: info: CoreCommandRouter::volumioGetVisibleSources

Dec 22 18:17:21 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources

Dec 22 18:17:23 volumio volumio[1407]: error: error

Dec 22 18:17:27 volumio sudo[1566]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0

Dec 22 18:17:27 volumio sudo[1566]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:27 volumio sudo[1566]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:27 volumio sudo[1569]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0

Dec 22 18:17:27 volumio sudo[1569]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:27 volumio sudo[1569]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:27 volumio sudo[1573]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service

Dec 22 18:17:27 volumio sudo[1573]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:27 volumio sudo[1573]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:27 volumio volumio[1407]: info: Upmpdcli Daemon Started

Dec 22 18:17:28 volumio volumio[1407]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium

Dec 22 18:17:28 volumio volumio[1407]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium

Dec 22 18:17:28 volumio volumio[1407]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium

Dec 22 18:17:28 volumio volumio[1407]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium

Dec 22 18:17:28 volumio volumio[1407]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium

Dec 22 18:17:28 volumio volumio[1407]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium

Dec 22 18:17:28 volumio volumio[1407]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium

Dec 22 18:17:28 volumio volumio[1407]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium

Dec 22 18:17:28 volumio volumio[1407]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium

Dec 22 18:17:28 volumio volumio[1407]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar

Dec 22 18:17:28 volumio volumio[1407]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar

Dec 22 18:17:28 volumio volumio[1407]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar

Dec 22 18:17:28 volumio volumio[1407]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar

Dec 22 18:17:28 volumio volumio[1407]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar

Dec 22 18:17:28 volumio volumio[1407]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar

Dec 22 18:17:28 volumio volumio[1407]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar

Dec 22 18:17:28 volumio volumio[1407]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar

Dec 22 18:17:28 volumio volumio[1407]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar

Dec 22 18:17:28 volumio volumio[1407]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso

Dec 22 18:17:28 volumio volumio[1407]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso

Dec 22 18:17:28 volumio volumio[1407]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso

Dec 22 18:17:28 volumio volumio[1407]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso

Dec 22 18:17:28 volumio volumio[1407]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso

Dec 22 18:17:28 volumio volumio[1407]: info: Adding plugin bluetooth to MyMusic Plugins

Dec 22 18:17:28 volumio volumio[1407]: info: Adding plugin multiroom to MyMusic Plugins

Dec 22 18:17:28 volumio volumio[1407]: info: Adding plugin cd_controller to MyMusic Plugins

Dec 22 18:17:28 volumio volumio[1407]: info: Adding plugin smart_inputs to MyMusic Plugins

Dec 22 18:17:28 volumio volumio[1407]: info: Adding plugin tidalconnect to MyMusic Plugins

Dec 22 18:17:28 volumio volumio[1407]: info: [MyVolumio PluginManager] Loading plugin “my_volumio”…

Dec 22 18:17:29 volumio volumio[1407]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded

Dec 22 18:17:29 volumio volumio[1407]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio

Dec 22 18:17:29 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:17:29 volumio volumio[1407]: info: Starting MyVolumio Remote Streaming Endpoints

Dec 22 18:17:29 volumio volumio[1407]: info: MyVolumio login type: Token

Dec 22 18:17:29 volumio volumio[1407]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started

Dec 22 18:17:29 volumio volumio[1407]: info: [MyVolumio PluginManager] Loading plugin “streaming_services”…

Dec 22 18:17:29 volumio volumio[1407]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded

Dec 22 18:17:29 volumio volumio[1407]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services

Dec 22 18:17:29 volumio volumio[1407]: info: Streaming services startup

Dec 22 18:17:29 volumio volumio[1407]: info: Starting Streaming Daemon

Dec 22 18:17:29 volumio sudo[1576]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service

Dec 22 18:17:29 volumio sudo[1576]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:29 volumio systemd[1]: Stopping Volumio Streaming Daemon…

Dec 22 18:17:29 volumio systemd[1]: volumio-streaming-daemon.service: Main process exited, code=killed, status=15/TERM

Dec 22 18:17:29 volumio systemd[1]: volumio-streaming-daemon.service: Succeeded.

Dec 22 18:17:29 volumio systemd[1]: Stopped Volumio Streaming Daemon.

Dec 22 18:17:29 volumio systemd[1]: Started Volumio Streaming Daemon.

Dec 22 18:17:30 volumio sudo[1576]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:30 volumio volumio-streaming-daemon[1582]: ############################

Dec 22 18:17:30 volumio volumio-streaming-daemon[1582]: # Volumio Streaming Daemon #

Dec 22 18:17:30 volumio volumio-streaming-daemon[1582]: # Running on port 7777 #

Dec 22 18:17:30 volumio volumio-streaming-daemon[1582]: ############################

Dec 22 18:17:30 volumio volumio-streaming-daemon[1582]: Environment: production

Dec 22 18:17:30 volumio volumio-streaming-daemon[1582]: Enabled services:

Dec 22 18:17:30 volumio volumio-streaming-daemon[1582]: 1) tidal

Dec 22 18:17:30 volumio volumio-streaming-daemon[1582]: 2) qobuz

Dec 22 18:17:30 volumio volumio[1407]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN

Dec 22 18:17:30 volumio volumio[1407]: info: MYVOLUMIO: Adding device

Dec 22 18:17:30 volumio volumio[1407]: info: MYVOLUMIO: Evaluating Server

Dec 22 18:17:31 volumio volumio[1407]: info: [MyVolumio PluginManager] Subscribed plan changed to superstar

Dec 22 18:17:31 volumio volumio[1407]: info: Adding audio output:

Dec 22 18:17:31 volumio volumio[1407]: info: MYVOLUMIO: Adding device

Dec 22 18:17:31 volumio volumio[1407]: info: MYVOLUMIO: Evaluating Server

Dec 22 18:17:31 volumio volumio[1407]: info: Remote config written successfully

Dec 22 18:17:31 volumio volumio[1407]: info: Starting Tunnel 1

Dec 22 18:17:31 volumio volumio[1407]: info: Starting Tunnel Connection Checker

Dec 22 18:17:31 volumio volumio[1407]: info: Completed starting MyVolumio Plugin

Dec 22 18:17:31 volumio sudo[1604]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service

Dec 22 18:17:31 volumio sudo[1604]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:31 volumio autossh[1355]: received signal to exit (15)

Dec 22 18:17:31 volumio systemd[1]: Stopping MyVolumio SSH Tunnel…

Dec 22 18:17:31 volumio systemd[1]: sshtunnel.service: Main process exited, code=killed, status=15/TERM

Dec 22 18:17:31 volumio systemd[1]: sshtunnel.service: Succeeded.

Dec 22 18:17:31 volumio systemd[1]: Stopped MyVolumio SSH Tunnel.

Dec 22 18:17:31 volumio systemd[1]: Started MyVolumio SSH Tunnel.

Dec 22 18:17:31 volumio sudo[1604]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:31 volumio autossh[1608]: port set to 0, monitoring disabled

Dec 22 18:17:31 volumio autossh[1608]: starting ssh (count 1)

Dec 22 18:17:31 volumio autossh[1608]: ssh child pid is 1612

Dec 22 18:17:31 volumio volumio[1407]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins…

Dec 22 18:17:31 volumio volumio[1407]: info: MyVolumio status changed

Dec 22 18:17:31 volumio volumio[1407]: info: Streaming services startup

Dec 22 18:17:31 volumio volumio[1407]: info: Re-Starting Streaming Daemon

Dec 22 18:17:31 volumio volumio[1407]: info: Setting Geolocation for MyVolumio to eu3

Dec 22 18:17:31 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:17:31 volumio volumio[1407]: info: Remote SSH Started

Dec 22 18:17:31 volumio volumio[1407]: info: Setting Geolocation for MyVolumio to eu3

Dec 22 18:17:31 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:17:31 volumio volumio-streaming-daemon[1582]: Restarting daemon

Dec 22 18:17:31 volumio volumio-streaming-daemon[1582]: Environment: production

Dec 22 18:17:31 volumio volumio[1407]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 6

Dec 22 18:17:31 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid

Dec 22 18:17:31 volumio volumio[1407]: error: [MyVolumio PluginManager] Could not read cache data: Invalid IV length

Dec 22 18:17:31 volumio volumio[1407]: info: CoreCommandRouter::volumioGetState

Dec 22 18:17:31 volumio volumio[1407]: info: CorePlayQueue::getTrack 0

Dec 22 18:17:32 volumio volumio-streaming-daemon[1582]: Enabled services:

Dec 22 18:17:32 volumio volumio-streaming-daemon[1582]: 1) tidal

Dec 22 18:17:32 volumio volumio-streaming-daemon[1582]: 2) qobuz

Dec 22 18:17:32 volumio volumio[1407]: info: [MyVolumio PluginManager] Loading plugin “bluetooth”…

Dec 22 18:17:32 volumio volumio[1407]: info: [1640197052492] Starting BluetoothController

Dec 22 18:17:32 volumio volumio[1407]: info: [MyVolumio PluginManager] Loading plugin “multiroom”…

Dec 22 18:17:33 volumio volumio[1407]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom

Dec 22 18:17:33 volumio sudo[1621]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod +x /myvolumio/plugins/audio_interface/multiroom/scripts/check_snapcast

Dec 22 18:17:33 volumio sudo[1621]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:33 volumio sudo[1621]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:34 volumio sudo[1624]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom

Dec 22 18:17:34 volumio sudo[1624]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:34 volumio sudo[1624]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:34 volumio volumio[1407]: info: MultiRoom plugin initialized

Dec 22 18:17:34 volumio volumio[1407]: STOPPING SNAPCLIENT

Dec 22 18:17:34 volumio volumio[1407]: info: [MyVolumio PluginManager] Loading plugin “metavolumio”…

Dec 22 18:17:34 volumio sudo[1640]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient

Dec 22 18:17:34 volumio sudo[1640]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:34 volumio volumio[1407]: info: [MyVolumio PluginManager] Loading plugin “cd_controller”…

Dec 22 18:17:34 volumio sudo[1640]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:34 volumio volumio[1407]: info: [MyVolumio PluginManager] Loading plugin “smart_inputs”…

Dec 22 18:17:34 volumio volumio[1407]: info: [MyVolumio PluginManager] Loading plugin “hi_res_audio”…

Dec 22 18:17:34 volumio volumio[1407]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio

Dec 22 18:17:34 volumio volumio[1407]: info: [MyVolumio PluginManager] Loading plugin “tidal”…

Dec 22 18:17:34 volumio volumio[1407]: info: [MyVolumio PluginManager] Loading plugin “qobuz”…

Dec 22 18:17:34 volumio volumio[1407]: info: [MyVolumio PluginManager] Loading plugin “tidalconnect”…

Dec 22 18:17:34 volumio volumio[1407]: info: Preparing to generate the ALSA configuration file

Dec 22 18:17:34 volumio volumio[1407]: info: Updating MyVolumio device info

Dec 22 18:17:34 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:17:34 volumio volumio[1407]: info: Updating MyVolumio device info

Dec 22 18:17:34 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:17:34 volumio volumio[1407]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid

Dec 22 18:17:34 volumio volumio[1407]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||

Dec 22 18:17:34 volumio volumio[1407]: TypeError [ERR_INVALID_URL]: Invalid URL: http://:50201/dial.xml

Dec 22 18:17:34 volumio volumio[1407]: at onParseError (internal/url.js:259:9)

Dec 22 18:17:34 volumio volumio[1407]: at new URL (internal/url.js:335:5)

Dec 22 18:17:34 volumio volumio[1407]: at new ClientRequest (_http_client.js:95:28)

Dec 22 18:17:34 volumio volumio[1407]: at request (http.js:50:10)

Dec 22 18:17:34 volumio volumio[1407]: at Object.get (http.js:54:15)

Dec 22 18:17:34 volumio volumio[1407]: at SsdpClient. (/myvolumio/plugins/audio_interface/multiroom/node_modules/chromecast-api/lib/client.js:120:12)

Dec 22 18:17:34 volumio volumio[1407]: at SsdpClient.emit (events.js:315:20)

Dec 22 18:17:34 volumio volumio[1407]: at SsdpClient.parseResponse [as _parseResponse] (/myvolumio/plugins/audio_interface/multiroom/node_modules/node-ssdp/lib/index.js:457:8)

Dec 22 18:17:34 volumio volumio[1407]: at SsdpClient.SSDP._parseMessage (/myvolumio/plugins/audio_interface/multiroom/node_modules/node-ssdp/lib/index.js:298:10)

Dec 22 18:17:34 volumio volumio[1407]: at Socket.onSocketMessage (/myvolumio/plugins/audio_interface/multiroom/node_modules/node-ssdp/lib/index.js:244:12)

Dec 22 18:17:34 volumio volumio[1407]: at Socket.emit (events.js:315:20)

Dec 22 18:17:34 volumio volumio[1407]: at UDP.onMessage [as onmessage] (dgram.js:919:8) {

Dec 22 18:17:34 volumio volumio[1407]: input: ‘http://:50201/dial.xml’,

Dec 22 18:17:34 volumio volumio[1407]: code: ‘ERR_INVALID_URL’

Dec 22 18:17:34 volumio volumio[1407]: }

Dec 22 18:17:34 volumio volumio[1407]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||

Dec 22 18:17:34 volumio sudo[1651]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2021-12-22 18:16

Dec 22 18:17:34 volumio sudo[1651]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:35 volumio sudo[1651]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:35 volumio volumio-remote-updater[447]: [2021-12-22 18:17:35] [error] handle_read_frame error: websocketpp.transport:7 (End of File)

Dec 22 18:17:35 volumio volumio-remote-updater[447]: [2021-12-22 18:17:35] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]

Dec 22 18:17:35 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE

Dec 22 18:17:35 volumio systemd[1]: volumio.service: Failed with result ‘exit-code’.

Dec 22 18:17:35 volumio systemd[1]: Started dynamicswap service.

Dec 22 18:17:35 volumio systemd[1]: dynamicswap.service: Succeeded.

Dec 22 18:17:35 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart.

Dec 22 18:17:35 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 3.

Dec 22 18:17:35 volumio systemd[1]: Started dynamicswap service.

Dec 22 18:17:35 volumio systemd[1]: Stopped Volumio Backend Module.

Dec 22 18:17:35 volumio systemd[1]: Started Volumio Backend Module.

Dec 22 18:17:35 volumio systemd[1]: dynamicswap.service: Succeeded.

Dec 22 18:17:36 volumio volumio[1662]: info: -------------------------------------------

Dec 22 18:17:36 volumio volumio[1662]: info: ----- Volumio3 ----

Dec 22 18:17:36 volumio volumio[1662]: info: -------------------------------------------

Dec 22 18:17:36 volumio volumio[1662]: info: ----- System startup ----

Dec 22 18:17:36 volumio volumio[1662]: info: -------------------------------------------

Dec 22 18:17:37 volumio volumio[1662]: info: MYVOLUMIO Environment detected

Dec 22 18:17:37 volumio volumio[1662]: info: Plugin folders cleanup

Dec 22 18:17:37 volumio volumio[1662]: info: Scanning into folder /volumio/app/plugins/

Dec 22 18:17:37 volumio volumio[1662]: info: Scanning category audio_interface

Dec 22 18:17:37 volumio volumio[1662]: info: Scanning category miscellanea

Dec 22 18:17:37 volumio volumio[1662]: info: Scanning category music_service

Dec 22 18:17:37 volumio volumio[1662]: info: Scanning category plugins.json

Dec 22 18:17:37 volumio volumio[1662]: info: Scanning category system_controller

Dec 22 18:17:37 volumio volumio[1662]: info: Scanning category user_interface

Dec 22 18:17:37 volumio volumio[1662]: info: Scanning into folder /data/plugins/

Dec 22 18:17:37 volumio volumio[1662]: info: Plugin folders cleanup completed

Dec 22 18:17:37 volumio volumio[1662]: info: -------------------------------------------

Dec 22 18:17:37 volumio volumio[1662]: info: ----- Core plugins startup ----

Dec 22 18:17:37 volumio volumio[1662]: info: -------------------------------------------

Dec 22 18:17:37 volumio volumio[1662]: info: Loading plugins from folder /volumio/app/plugins/

Dec 22 18:17:37 volumio volumio[1662]: info: Adding plugin upnp to MyMusic Plugins

Dec 22 18:17:37 volumio volumio[1662]: info: Adding plugin airplay_emulation to MyMusic Plugins

Dec 22 18:17:37 volumio volumio[1662]: info: Adding plugin upnp_browser to MyMusic Plugins

Dec 22 18:17:37 volumio volumio[1662]: info: Loading plugins from folder /data/plugins/

Dec 22 18:17:37 volumio volumio[1662]: info: Loading plugin “system”…

Dec 22 18:17:37 volumio volumio[1662]: info: Loading plugin “appearance”…

Dec 22 18:17:38 volumio volumio[1662]: info: Loading plugin “network”…

Dec 22 18:17:38 volumio volumio[1662]: info: Refreshing Cached IP Addresses

Dec 22 18:17:38 volumio sudo[1685]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0

Dec 22 18:17:38 volumio sudo[1685]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:38 volumio volumio[1662]: info: Loading plugin “services”…

Dec 22 18:17:38 volumio sudo[1685]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:38 volumio volumio[1662]: info: Loading plugin “alsa_controller”…

Dec 22 18:17:38 volumio sudo[1687]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0

Dec 22 18:17:38 volumio sudo[1687]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:38 volumio sudo[1687]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:38 volumio volumio[1662]: info: Loading plugin “wizard”…

Dec 22 18:17:38 volumio volumio[1662]: info: Loading plugin “volumio_command_line_client”…

Dec 22 18:17:38 volumio volumio[1662]: info: Loading plugin “upnp”…

Dec 22 18:17:38 volumio volumio[1662]: info: [1640197058725] Starting Upmpd Daemon

Dec 22 18:17:38 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback

Dec 22 18:17:38 volumio volumio[1662]: info: Loading plugin “my_music”…

Dec 22 18:17:38 volumio volumio[1662]: info: Loading plugin “mpd”…

Dec 22 18:17:39 volumio volumio[1662]: info: Creating MPD Configuration file

Dec 22 18:17:39 volumio volumio[1662]: info: Loading plugin “upnp_browser”…

Dec 22 18:17:39 volumio sudo[1695]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf

Dec 22 18:17:39 volumio sudo[1695]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:39 volumio sudo[1695]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:39 volumio sudo[1697]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service

Dec 22 18:17:39 volumio sudo[1697]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:39 volumio systemd[1]: Stopping Music Player Daemon…

Dec 22 18:17:39 volumio systemd[1]: mpd.service: Succeeded.

Dec 22 18:17:39 volumio systemd[1]: Stopped Music Player Daemon.

Dec 22 18:17:39 volumio systemd[1]: Starting Music Player Daemon…

Dec 22 18:17:39 volumio volumio[1662]: info: Loading plugin “networkfs”…

Dec 22 18:17:39 volumio volumio[1662]: info: Starting Udev Watcher for removable devices

Dec 22 18:17:39 volumio volumio[1662]: info: Ignoring mount for partition: boot

Dec 22 18:17:39 volumio volumio[1662]: info: Ignoring mount for partition: volumio

Dec 22 18:17:39 volumio volumio[1662]: info: Ignoring mount for partition: volumio_data

Dec 22 18:17:39 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback

Dec 22 18:17:39 volumio volumio[1662]: info: Loading plugin “alarm-clock”…

Dec 22 18:17:40 volumio volumio[1662]: info: Loading plugin “airplay_emulation”…

Dec 22 18:17:40 volumio volumio-remote-updater[447]: [2021-12-22 18:17:40] [connect] Successful connection

Dec 22 18:17:40 volumio volumio[1662]: info: Starting Shairport Sync

Dec 22 18:17:40 volumio volumio[1662]: info: Loading plugin “last_100”…

Dec 22 18:17:40 volumio volumio[1662]: info: Loading plugin “webradio”…

Dec 22 18:17:40 volumio volumio[1662]: info: Loading plugin “i2s_dacs”…

Dec 22 18:17:40 volumio volumio[1662]: info: I2S DAC not set, start Auto-detection

Dec 22 18:17:40 volumio volumio[1662]: info: Loading plugin “volumiodiscovery”…

Dec 22 18:17:40 volumio volumio[1662]: *** WARNING *** The program ‘node’ uses the Apple Bonjour compatibility layer of Avahi.

Dec 22 18:17:40 volumio node[1662]: *** WARNING *** The program ‘node’ uses the Apple Bonjour compatibility layer of Avahi.

Dec 22 18:17:40 volumio volumio[1662]: *** WARNING *** Please fix your application to use the native API of Avahi!

Dec 22 18:17:40 volumio node[1662]: *** WARNING *** Please fix your application to use the native API of Avahi!

Dec 22 18:17:40 volumio volumio[1662]: *** WARNING *** For more information see http://0pointer.de/blog/projects/avahi-compat.html

Dec 22 18:17:40 volumio node[1662]: *** WARNING *** For more information see http://0pointer.de/blog/projects/avahi-compat.html

Dec 22 18:17:40 volumio volumio[1662]: *** WARNING *** The program ‘node’ called ‘DNSServiceRegister()’ which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.

Dec 22 18:17:40 volumio node[1662]: *** WARNING *** The program ‘node’ called ‘DNSServiceRegister()’ which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.

Dec 22 18:17:40 volumio volumio[1662]: *** WARNING *** Please fix your application to use the native API of Avahi!

Dec 22 18:17:40 volumio node[1662]: *** WARNING *** Please fix your application to use the native API of Avahi!

Dec 22 18:17:40 volumio volumio[1662]: *** WARNING *** For more information see http://0pointer.de/blog/projects/avahi-compat.html

Dec 22 18:17:40 volumio node[1662]: *** WARNING *** For more information see http://0pointer.de/blog/projects/avahi-compat.html

Dec 22 18:17:40 volumio volumio[1662]: info: Applying required configuration parameters for plugin volumiodiscovery

Dec 22 18:17:40 volumio volumio[1662]: info: Discovery: Started advertising with name: Volumio

Dec 22 18:17:40 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback

Dec 22 18:17:40 volumio volumio[1662]: info: Loading plugin “outputs”…

Dec 22 18:17:40 volumio volumio[1662]: info: Loading plugin “albumart”…

Dec 22 18:17:40 volumio volumio[1662]: info: Plugin example_plugin is not enabled

Dec 22 18:17:40 volumio volumio[1662]: info: Loading plugin “inputs”…

Dec 22 18:17:40 volumio volumio[1662]: info: Loading plugin “updater_comm”…

Dec 22 18:17:40 volumio mpd[1702]: Dec 22 18:17 : exception: Decoder plugin ‘wildmidi’ is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg

Dec 22 18:17:40 volumio mpd[1702]: Dec 22 18:17 : exception: Input plugin ‘tidal’ is unavailable: No Tidal application token configured

Dec 22 18:17:40 volumio mpd[1702]: Dec 22 18:17 : exception: Input plugin ‘qobuz’ is unavailable: No Qobuz app_id configured

Dec 22 18:17:40 volumio systemd[1]: Started Music Player Daemon.

Dec 22 18:17:40 volumio sudo[1697]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:40 volumio volumio[1662]: info: Plugin mpdemulation is not enabled

Dec 22 18:17:40 volumio volumio[1662]: info: Loading plugin “rest_api”…

Dec 22 18:17:40 volumio volumio[1662]: info: Loading plugin “websocket”…

Dec 22 18:17:40 volumio volumio[1662]: info: Loading i18n strings for locale en

Dec 22 18:17:40 volumio volumio[1662]: Updating browse sources language

Dec 22 18:17:40 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources

Dec 22 18:17:40 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam

Dec 22 18:17:40 volumio volumio[1662]: info: CoreCommandRouter::initPlayerControls

Dec 22 18:17:40 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:17:40 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam

Dec 22 18:17:40 volumio volumio[1662]: Express server listening on port 3000

Dec 22 18:17:40 volumio volumio[1662]: [Metrics] WebUI: 4s 210.62ms

Dec 22 18:17:40 volumio volumio[1662]: info: CoreStateMachine::resetVolumioState

Dec 22 18:17:40 volumio volumio[1662]: info: CoreStateMachine::getcurrentVolume

Dec 22 18:17:40 volumio volumio[1662]: info: CoreCommandRouter::volumioRetrievevolume

Dec 22 18:17:40 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:17:40 volumio volumio[1662]: info: Cannot read play queue from file

Dec 22 18:17:40 volumio volumio[1662]: Forking 3 albumart workers

Dec 22 18:17:40 volumio volumio[1662]: info: MPD Permissions set

Dec 22 18:17:40 volumio volumio[1662]: verbose: New Socket.io Connection to 192.168.1.53 from 192.168.1.46 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/96.0.4664.110 Safari/537.36 Total Clients: 1

Dec 22 18:17:40 volumio volumio[1662]: verbose: New Socket.io Connection to 192.168.1.53 from 192.168.1.46 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/96.0.4664.110 Safari/537.36 Total Clients: 2

Dec 22 18:17:40 volumio volumio-remote-updater[447]: [2021-12-22 18:17:40] [connect] WebSocket Connection 127.0.0.1:3000 v-2 “WebSocket++/0.8.2” /socket.io/?EIO=4&transport=websocket&t=1640197060 101

Dec 22 18:17:40 volumio volumio[1662]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 3

Dec 22 18:17:40 volumio volumio[1662]: info: MPD running with PID1702

Dec 22 18:17:40 volumio volumio[1662]: ,establishing connection

Dec 22 18:17:40 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:17:41 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:17:41 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:17:41 volumio volumio[1662]: error: updateQueue error: null

Dec 22 18:17:41 volumio volumio[1662]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory

Dec 22 18:17:41 volumio volumio[1662]: info: CoreStateMachine::setRepeat null single undefined

Dec 22 18:17:41 volumio volumio[1662]: info: CoreStateMachine::pushState

Dec 22 18:17:41 volumio volumio[1662]: info: CorePlayQueue::getTrack 0

Dec 22 18:17:41 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo

Dec 22 18:17:41 volumio volumio[1662]: info: CoreCommandRouter::volumioPushState

Dec 22 18:17:41 volumio volumio[1662]: info: CoreStateMachine::setRandom null

Dec 22 18:17:41 volumio volumio[1662]: info: CoreStateMachine::pushState

Dec 22 18:17:41 volumio volumio[1662]: info: CorePlayQueue::getTrack 0

Dec 22 18:17:41 volumio volumio[1662]: info: CoreCommandRouter::volumioPushState

Dec 22 18:17:41 volumio volumio[1662]: info: Setting Device type: Raspberry PI

Dec 22 18:17:41 volumio volumio[1662]: info: VolumeController:: Volume=86 Mute =false

Dec 22 18:17:41 volumio volumio[1662]: info: CoreStateMachine::pushState

Dec 22 18:17:41 volumio volumio[1662]: info: CorePlayQueue::getTrack 0

Dec 22 18:17:41 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo

Dec 22 18:17:41 volumio volumio[1662]: info: CoreCommandRouter::volumioPushState

Dec 22 18:17:41 volumio volumio[1662]: info: CoreStateMachine::updateTrackBlock

Dec 22 18:17:41 volumio volumio[1662]: info: CorePlayQueue::getTrackBlock

Dec 22 18:17:41 volumio volumio[1662]: info: CoreCommandRouter::volumioRetrievevolume

Dec 22 18:17:41 volumio volumio[1662]: error: updateQueue error: null

Dec 22 18:17:41 volumio volumio[1662]: info: Completed loading Core Plugins

Dec 22 18:17:41 volumio volumio[1662]: info: Preparing to generate the ALSA configuration file

Dec 22 18:17:41 volumio volumio[1662]: info: Asound.conf file unchanged, so no further update is needed

Dec 22 18:17:41 volumio volumio[1662]: info: Output device has changed, restarting MPD

Dec 22 18:17:41 volumio sudo[1753]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf

Dec 22 18:17:41 volumio sudo[1753]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:41 volumio volumio[1662]: info: Output device has changed, restarting Shairport Sync

Dec 22 18:17:41 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:17:41 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:17:41 volumio sudo[1753]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:41 volumio sudo[1756]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service

Dec 22 18:17:41 volumio sudo[1756]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:41 volumio systemd[1]: Stopping Music Player Daemon…

Dec 22 18:17:41 volumio systemd[1]: mpd.service: Succeeded.

Dec 22 18:17:41 volumio systemd[1]: Stopped Music Player Daemon.

Dec 22 18:17:41 volumio systemd[1]: Starting Music Player Daemon…

Dec 22 18:17:41 volumio volumio[1662]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0

Dec 22 18:17:41 volumio volumio[1662]: info: ___________ START PLUGINS ___________

Dec 22 18:17:41 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam

Dec 22 18:17:41 volumio volumio[1662]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]

Dec 22 18:17:41 volumio volumio[1662]: info: [1640197061342] CoreMusicLibrary::Adding element Media Servers

Dec 22 18:17:41 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources

Dec 22 18:17:41 volumio volumio[1662]: Cannot find translation for sourceMedia Servers

Dec 22 18:17:41 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:17:41 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:17:41 volumio volumio[1662]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0

Dec 22 18:17:41 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:17:41 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:17:41 volumio volumio[1662]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0

Dec 22 18:17:41 volumio volumio[1662]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]

Dec 22 18:17:41 volumio volumio[1662]: info: [1640197061614] CoreMusicLibrary::Adding element Last_100

Dec 22 18:17:41 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources

Dec 22 18:17:41 volumio volumio[1662]: Cannot find translation for sourceMedia Servers

Dec 22 18:17:41 volumio volumio[1662]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]

Dec 22 18:17:41 volumio volumio[1662]: info: [1640197061647] CoreMusicLibrary::Adding element Webradio

Dec 22 18:17:41 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources

Dec 22 18:17:41 volumio volumio[1662]: Cannot find translation for sourceMedia Servers

Dec 22 18:17:41 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion

Dec 22 18:17:41 volumio volumio[1662]: info: Volumio Calling Home

Dec 22 18:17:41 volumio volumio[1662]: Starting albumart workers

Dec 22 18:17:41 volumio volumio[1662]: info: Completed starting Core Plugins

Dec 22 18:17:41 volumio volumio[1662]: info: -------------------------------------------

Dec 22 18:17:41 volumio volumio[1662]: info: ----- MyVolumio plugins startup ----

Dec 22 18:17:41 volumio volumio[1662]: info: -------------------------------------------

Dec 22 18:17:41 volumio volumio[1662]: info: [MyVolumio PluginManager] Fetching plans data…

Dec 22 18:17:41 volumio volumio[1662]: Starting albumart workers

Dec 22 18:17:42 volumio volumio[1662]: info: MPD Permissions set

Dec 22 18:17:42 volumio volumio[1662]: info: Volumio called home

Dec 22 18:17:42 volumio volumio[1662]: error: error

Dec 22 18:17:42 volumio volumio[1662]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 4

Dec 22 18:17:42 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:17:42 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:17:42 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:17:42 volumio volumio[1662]: info: VolumeController:: Volume=86 Mute =false

Dec 22 18:17:42 volumio volumio[1662]: info: CoreStateMachine::pushState

Dec 22 18:17:42 volumio volumio[1662]: info: CorePlayQueue::getTrack 0

Dec 22 18:17:42 volumio volumio[1662]: info: CoreCommandRouter::volumioPushState

Dec 22 18:17:42 volumio volumio[1662]: info: Starting Shairport Sync

Dec 22 18:17:42 volumio sudo[1796]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync

Dec 22 18:17:42 volumio sudo[1796]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:42 volumio sudo[1800]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync

Dec 22 18:17:42 volumio sudo[1800]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:42 volumio sudo[1798]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync

Dec 22 18:17:42 volumio sudo[1798]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:42 volumio volumio[1662]: info: Discovery: adding 66c3ef45-2f5b-43a9-9ab2-b917f030ba41

Dec 22 18:17:42 volumio volumio[1662]: info: mDNS: Found device Volumio

Dec 22 18:17:42 volumio volumio[1662]: info: CoreCommandRouter::volumioGetState

Dec 22 18:17:42 volumio volumio[1662]: info: CorePlayQueue::getTrack 0

Dec 22 18:17:42 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver…

Dec 22 18:17:42 volumio systemd[1]: shairport-sync.service: Succeeded.

Dec 22 18:17:42 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver.

Dec 22 18:17:42 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver.

Dec 22 18:17:42 volumio sudo[1796]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:42 volumio sudo[1798]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:42 volumio sudo[1800]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:42 volumio volumio[1662]: info: Shairport-Sync Started

Dec 22 18:17:42 volumio volumio[1662]: Error adding Membership: Error: addMembership EINVAL

Dec 22 18:17:42 volumio volumio[1662]: info: Shairport-Sync Started

Dec 22 18:17:42 volumio volumio[1662]: info: CoreCommandRouter::volumioGetState

Dec 22 18:17:42 volumio volumio[1662]: info: CorePlayQueue::getTrack 0

Dec 22 18:17:42 volumio mpd[1769]: Dec 22 18:17 : exception: Decoder plugin ‘wildmidi’ is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg

Dec 22 18:17:42 volumio mpd[1769]: Dec 22 18:17 : exception: Input plugin ‘tidal’ is unavailable: No Tidal application token configured

Dec 22 18:17:42 volumio mpd[1769]: Dec 22 18:17 : exception: Input plugin ‘qobuz’ is unavailable: No Qobuz app_id configured

Dec 22 18:17:43 volumio systemd[1]: Started Music Player Daemon.

Dec 22 18:17:43 volumio sudo[1756]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:43 volumio volumio[1662]: error: updateQueue error: null

Dec 22 18:17:43 volumio volumio[1662]: verbose: New Socket.io Connection to 192.168.1.53 from 192.168.1.46 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/96.0.4664.110 Safari/537.36 Total Clients: 5

Dec 22 18:17:43 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom

Dec 22 18:17:43 volumio volumio[1662]: info: CoreCommandRouter::volumioGetState

Dec 22 18:17:43 volumio volumio[1662]: info: CorePlayQueue::getTrack 0

Dec 22 18:17:43 volumio volumio[1662]: info: CoreCommandRouter::volumioGetVisibleSources

Dec 22 18:17:43 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources

Dec 22 18:17:43 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom

Dec 22 18:17:43 volumio volumio[1662]: info: CoreCommandRouter::volumioGetState

Dec 22 18:17:43 volumio volumio[1662]: info: CorePlayQueue::getTrack 0

Dec 22 18:17:43 volumio volumio[1662]: info: CoreCommandRouter::volumioGetVisibleSources

Dec 22 18:17:43 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources

Dec 22 18:17:45 volumio volumio[1662]: error: error

Dec 22 18:17:48 volumio sudo[1819]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0

Dec 22 18:17:48 volumio sudo[1819]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:48 volumio sudo[1819]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:48 volumio sudo[1821]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0

Dec 22 18:17:48 volumio sudo[1821]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:48 volumio sudo[1821]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:48 volumio sudo[1825]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service

Dec 22 18:17:48 volumio sudo[1825]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:48 volumio sudo[1825]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:48 volumio volumio[1662]: info: Upmpdcli Daemon Started

Dec 22 18:17:50 volumio volumio[1662]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium

Dec 22 18:17:50 volumio volumio[1662]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium

Dec 22 18:17:50 volumio volumio[1662]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium

Dec 22 18:17:50 volumio volumio[1662]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium

Dec 22 18:17:50 volumio volumio[1662]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium

Dec 22 18:17:50 volumio volumio[1662]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium

Dec 22 18:17:50 volumio volumio[1662]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium

Dec 22 18:17:50 volumio volumio[1662]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium

Dec 22 18:17:50 volumio volumio[1662]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium

Dec 22 18:17:50 volumio volumio[1662]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar

Dec 22 18:17:50 volumio volumio[1662]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar

Dec 22 18:17:50 volumio volumio[1662]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar

Dec 22 18:17:50 volumio volumio[1662]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar

Dec 22 18:17:50 volumio volumio[1662]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar

Dec 22 18:17:50 volumio volumio[1662]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar

Dec 22 18:17:50 volumio volumio[1662]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar

Dec 22 18:17:50 volumio volumio[1662]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar

Dec 22 18:17:50 volumio volumio[1662]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar

Dec 22 18:17:50 volumio volumio[1662]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso

Dec 22 18:17:50 volumio volumio[1662]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso

Dec 22 18:17:50 volumio volumio[1662]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso

Dec 22 18:17:50 volumio volumio[1662]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso

Dec 22 18:17:50 volumio volumio[1662]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso

Dec 22 18:17:50 volumio volumio[1662]: info: Adding plugin bluetooth to MyMusic Plugins

Dec 22 18:17:50 volumio volumio[1662]: info: Adding plugin multiroom to MyMusic Plugins

Dec 22 18:17:50 volumio volumio[1662]: info: Adding plugin cd_controller to MyMusic Plugins

Dec 22 18:17:50 volumio volumio[1662]: info: Adding plugin smart_inputs to MyMusic Plugins

Dec 22 18:17:50 volumio volumio[1662]: info: Adding plugin tidalconnect to MyMusic Plugins

Dec 22 18:17:50 volumio volumio[1662]: info: [MyVolumio PluginManager] Loading plugin “my_volumio”…

Dec 22 18:17:51 volumio volumio[1662]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded

Dec 22 18:17:51 volumio volumio[1662]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio

Dec 22 18:17:51 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:17:51 volumio volumio[1662]: info: Starting MyVolumio Remote Streaming Endpoints

Dec 22 18:17:51 volumio volumio[1662]: info: MyVolumio login type: Token

Dec 22 18:17:51 volumio volumio[1662]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started

Dec 22 18:17:51 volumio volumio[1662]: info: [MyVolumio PluginManager] Loading plugin “streaming_services”…

Dec 22 18:17:51 volumio volumio[1662]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded

Dec 22 18:17:51 volumio volumio[1662]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services

Dec 22 18:17:51 volumio volumio[1662]: info: Streaming services startup

Dec 22 18:17:51 volumio volumio[1662]: info: Starting Streaming Daemon

Dec 22 18:17:51 volumio sudo[1828]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service

Dec 22 18:17:51 volumio sudo[1828]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:51 volumio systemd[1]: Stopping Volumio Streaming Daemon…

Dec 22 18:17:51 volumio systemd[1]: volumio-streaming-daemon.service: Main process exited, code=killed, status=15/TERM

Dec 22 18:17:51 volumio systemd[1]: volumio-streaming-daemon.service: Succeeded.

Dec 22 18:17:51 volumio systemd[1]: Stopped Volumio Streaming Daemon.

Dec 22 18:17:51 volumio systemd[1]: Started Volumio Streaming Daemon.

Dec 22 18:17:51 volumio sudo[1828]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:51 volumio volumio-streaming-daemon[1834]: ############################

Dec 22 18:17:51 volumio volumio-streaming-daemon[1834]: # Volumio Streaming Daemon #

Dec 22 18:17:51 volumio volumio-streaming-daemon[1834]: # Running on port 7777 #

Dec 22 18:17:51 volumio volumio-streaming-daemon[1834]: ############################

Dec 22 18:17:51 volumio volumio-streaming-daemon[1834]: Environment: production

Dec 22 18:17:51 volumio volumio[1662]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN

Dec 22 18:17:51 volumio volumio[1662]: info: MYVOLUMIO: Adding device

Dec 22 18:17:51 volumio volumio[1662]: info: MYVOLUMIO: Evaluating Server

Dec 22 18:17:52 volumio volumio[1662]: info: [MyVolumio PluginManager] Subscribed plan changed to superstar

Dec 22 18:17:52 volumio volumio[1662]: info: Adding audio output:

Dec 22 18:17:52 volumio volumio[1662]: info: MYVOLUMIO: Adding device

Dec 22 18:17:52 volumio volumio[1662]: info: MYVOLUMIO: Evaluating Server

Dec 22 18:17:52 volumio volumio[1662]: info: Remote config written successfully

Dec 22 18:17:52 volumio volumio[1662]: info: Starting Tunnel 1

Dec 22 18:17:52 volumio volumio[1662]: info: Starting Tunnel Connection Checker

Dec 22 18:17:52 volumio volumio[1662]: info: Completed starting MyVolumio Plugin

Dec 22 18:17:52 volumio sudo[1857]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service

Dec 22 18:17:52 volumio sudo[1857]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:17:52 volumio autossh[1608]: received signal to exit (15)

Dec 22 18:17:52 volumio systemd[1]: Stopping MyVolumio SSH Tunnel…

Dec 22 18:17:52 volumio systemd[1]: sshtunnel.service: Main process exited, code=killed, status=15/TERM

Dec 22 18:17:52 volumio systemd[1]: sshtunnel.service: Succeeded.

Dec 22 18:17:52 volumio systemd[1]: Stopped MyVolumio SSH Tunnel.

Dec 22 18:17:52 volumio systemd[1]: Started MyVolumio SSH Tunnel.

Dec 22 18:17:52 volumio sudo[1857]: pam_unix(sudo:session): session closed for user root

Dec 22 18:17:52 volumio autossh[1861]: port set to 0, monitoring disabled

Dec 22 18:17:52 volumio autossh[1861]: starting ssh (count 1)

Dec 22 18:17:52 volumio autossh[1861]: ssh child pid is 1865

Dec 22 18:17:52 volumio volumio[1662]: info: MyVolumio status changed

Dec 22 18:17:52 volumio volumio[1662]: info: Streaming services startup

Dec 22 18:17:52 volumio volumio[1662]: info: Re-Starting Streaming Daemon

Dec 22 18:17:52 volumio volumio[1662]: info: Setting Geolocation for MyVolumio to eu3

Dec 22 18:17:52 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:17:53 volumio volumio[1662]: info: Remote SSH Started

Dec 22 18:17:53 volumio volumio[1662]: info: Setting Geolocation for MyVolumio to eu3

Dec 22 18:17:53 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:17:53 volumio volumio-streaming-daemon[1834]: Restarting daemon

Dec 22 18:17:53 volumio volumio-streaming-daemon[1834]: Environment: production

Dec 22 18:17:53 volumio volumio[1662]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 6

Dec 22 18:17:53 volumio volumio[1662]: info: CoreCommandRouter::volumioGetState

Dec 22 18:17:53 volumio volumio[1662]: info: CorePlayQueue::getTrack 0

Dec 22 18:17:53 volumio volumio[1662]: info: Updating MyVolumio device info

Dec 22 18:17:53 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:17:54 volumio volumio-streaming-daemon[1834]: Environment: production

Dec 22 18:17:54 volumio volumio[1662]: info: Updating MyVolumio device info

Dec 22 18:17:54 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:17:54 volumio volumio[1662]: info: Fetching Streaming Services browse cache

Dec 22 18:17:54 volumio volumio-streaming-daemon[1834]: Environment: production

Dec 22 18:17:55 volumio volumio[1662]: info: Fetching Streaming Services browse cache

Dec 22 18:18:11 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion

Dec 22 18:18:11 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:18:18 volumio volumiossh-tunnel[1860]: Warning: Permanently added ‘[eu1.myvolumio.org]:2222,[188.166.162.121]:2222’ (RSA) to the list of known hosts.

Dec 22 18:18:22 volumio volumio[1662]: error: MyVolumio Plugins failed to start in a timely fashion

Dec 22 18:18:22 volumio volumio[1662]: info: BOOT COMPLETED

Dec 22 18:18:22 volumio volumio[1662]: [Metrics] CommandRouter: 45s 836.03ms

Dec 22 18:18:22 volumio volumio[1662]: info: CoreCommandRouter::volumiosetStartupVolume

Dec 22 18:18:22 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam

Dec 22 18:18:22 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam

Dec 22 18:18:22 volumio volumio[1662]: info: CoreCommandRouter::Close All Modals sent

Dec 22 18:18:23 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable

Dec 22 18:18:23 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus

Dec 22 18:18:23 volumio volumio[1662]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect

Dec 22 18:18:31 volumio volumio[1662]: error: error

Dec 22 18:19:21 volumio volumio[1662]: error: error

Dec 22 18:20:11 volumio volumio[1662]: error: error

Dec 22 18:21:01 volumio volumio[1662]: error: error

Dec 22 18:21:51 volumio volumio[1662]: error: error

Dec 22 18:21:52 volumio volumio[1662]: info: Tunnel connection is inactive, restarting it

Dec 22 18:21:52 volumio volumio[1662]: info: Starting Tunnel 1

Dec 22 18:21:52 volumio volumio[1662]: info: Starting Tunnel Connection Checker

Dec 22 18:21:52 volumio sudo[1902]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service

Dec 22 18:21:52 volumio sudo[1902]: pam_unix(sudo:session): session opened for user root by (uid=0)

Dec 22 18:21:52 volumio autossh[1861]: received signal to exit (15)

Dec 22 18:21:52 volumio systemd[1]: Stopping MyVolumio SSH Tunnel…

Dec 22 18:21:52 volumio systemd[1]: sshtunnel.service: Main process exited, code=killed, status=15/TERM

Dec 22 18:21:52 volumio systemd[1]: sshtunnel.service: Succeeded.

Dec 22 18:21:52 volumio systemd[1]: Stopped MyVolumio SSH Tunnel.

Dec 22 18:21:52 volumio systemd[1]: Started MyVolumio SSH Tunnel.

Dec 22 18:21:52 volumio sudo[1902]: pam_unix(sudo:session): session closed for user root

Dec 22 18:21:52 volumio volumio[1662]: info: Remote SSH Started

Dec 22 18:21:52 volumio autossh[1905]: port set to 0, monitoring disabled

Dec 22 18:21:52 volumio autossh[1905]: starting ssh (count 1)

Dec 22 18:21:52 volumio autossh[1905]: ssh child pid is 1908

Dec 22 18:21:52 volumio volumio[1662]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 5

Dec 22 18:21:53 volumio volumio[1662]: info: CoreCommandRouter::volumioGetState

Dec 22 18:21:53 volumio volumio[1662]: info: CorePlayQueue::getTrack 0

Dec 22 18:21:53 volumio volumiossh-tunnel[1904]: Warning: Permanently added ‘[eu3.myvolumio.org]:2222,[167.71.136.233]:2222’ (RSA) to the list of known hosts.

Dec 22 18:21:55 volumio volumio[1662]: error: error

Dec 22 18:22:19 volumio sshd[1076]: pam_unix(sshd:session): session closed for user volumio

Dec 22 18:22:19 volumio systemd[1]: session-1.scope: Succeeded.

Dec 22 18:22:19 volumio systemd-logind[417]: Session 1 logged out. Waiting for processes to exit.

Dec 22 18:22:19 volumio systemd-logind[417]: Removed session 1.

Dec 22 18:22:30 volumio systemd[1]: Stopping User Manager for UID 1000…

Dec 22 18:22:30 volumio systemd[1079]: Stopped target Default.

Dec 22 18:22:30 volumio systemd[1079]: Stopped target Basic System.

Dec 22 18:22:30 volumio systemd[1079]: Stopped target Paths.

Dec 22 18:22:30 volumio systemd[1079]: Stopped target Timers.

Dec 22 18:22:30 volumio systemd[1079]: Stopped target Sockets.

Dec 22 18:22:30 volumio systemd[1079]: pulseaudio.socket: Succeeded.

Dec 22 18:22:30 volumio systemd[1079]: Closed Sound System.

Dec 22 18:22:30 volumio systemd[1079]: gpg-agent-browser.socket: Succeeded.

Dec 22 18:22:30 volumio systemd[1079]: Closed GnuPG cryptographic agent and passphrase cache (access for web browsers).

Dec 22 18:22:30 volumio systemd[1079]: dbus.socket: Succeeded.

Dec 22 18:22:30 volumio systemd[1079]: Closed D-Bus User Message Bus Socket.

Dec 22 18:22:30 volumio systemd[1079]: gpg-agent-ssh.socket: Succeeded.

Dec 22 18:22:30 volumio systemd[1079]: Closed GnuPG cryptographic agent (ssh-agent emulation).

Dec 22 18:22:30 volumio systemd[1079]: gpg-agent-extra.socket: Succeeded.

Dec 22 18:22:30 volumio systemd[1079]: Closed GnuPG cryptographic agent and passphrase cache (restricted).

Dec 22 18:22:30 volumio systemd[1079]: gpg-agent.socket: Succeeded.

Dec 22 18:22:30 volumio systemd[1079]: Closed GnuPG cryptographic agent and passphrase cache.

Dec 22 18:22:30 volumio systemd[1079]: dirmngr.socket: Succeeded.

Dec 22 18:22:30 volumio systemd[1079]: Closed GnuPG network certificate management daemon.

Dec 22 18:22:30 volumio systemd[1079]: Reached target Shutdown.

Dec 22 18:22:30 volumio systemd[1079]: systemd-exit.service: Succeeded.

Dec 22 18:22:30 volumio systemd[1079]: Started Exit the Session.

Dec 22 18:22:30 volumio systemd[1079]: Reached target Exit the Session.

Dec 22 18:22:30 volumio systemd[1080]: pam_unix(systemd-user:session): session closed for user volumio

Dec 22 18:22:30 volumio systemd[1]: user@1000.service: Succeeded.

Dec 22 18:22:30 volumio systemd[1]: Stopped User Manager for UID 1000.

Dec 22 18:22:30 volumio systemd[1]: Stopping User Runtime Directory /run/user/1000…

Dec 22 18:22:30 volumio systemd[1]: run-user-1000.mount: Succeeded.

Dec 22 18:22:30 volumio systemd[1]: user-runtime-dir@1000.service: Succeeded.

Dec 22 18:22:30 volumio systemd[1]: Stopped User Runtime Directory /run/user/1000.

Dec 22 18:22:30 volumio systemd[1]: Removed slice User Slice of UID 1000.

Dec 22 18:22:41 volumio volumio[1662]: error: error

Dec 22 18:22:45 volumio volumio[1662]: error: error

Dec 22 18:23:31 volumio volumio[1662]: error: error

Dec 22 18:24:21 volumio volumio[1662]: error: error

Dec 22 18:24:51 volumio sshd[1937]: Accepted password for volumio from 192.168.1.46 port 56459 ssh2

Dec 22 18:24:51 volumio sshd[1937]: pam_unix(sshd:session): session opened for user volumio by (uid=0)

Dec 22 18:24:51 volumio systemd[1]: Created slice User Slice of UID 1000.

Dec 22 18:24:51 volumio systemd[1]: Starting User Runtime Directory /run/user/1000…

Dec 22 18:24:51 volumio systemd-logind[417]: New session 3 of user volumio.

Dec 22 18:24:51 volumio systemd[1]: Started User Runtime Directory /run/user/1000.

Dec 22 18:24:51 volumio systemd[1]: Starting User Manager for UID 1000…

Dec 22 18:24:51 volumio systemd[1941]: pam_unix(systemd-user:session): session opened for user volumio by (uid=0)

Dec 22 18:24:51 volumio systemd[1941]: Listening on Sound System.

Dec 22 18:24:51 volumio systemd[1941]: Reached target Timers.

Dec 22 18:24:51 volumio systemd[1941]: Listening on GnuPG network certificate management daemon.

Dec 22 18:24:51 volumio systemd[1941]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).

Dec 22 18:24:51 volumio systemd[1941]: Listening on GnuPG cryptographic agent and passphrase cache.

Dec 22 18:24:51 volumio systemd[1941]: mpd.socket: Failed to create listening socket ([::]:6600): Address already in use

Dec 22 18:24:51 volumio systemd[1941]: mpd.socket: Failed to listen on sockets: Address already in use

Dec 22 18:24:51 volumio systemd[1941]: mpd.socket: Failed with result ‘resources’.

Dec 22 18:24:51 volumio systemd[1941]: Failed to listen on mpd.socket.

Dec 22 18:24:51 volumio systemd[1941]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).

Dec 22 18:24:51 volumio systemd[1941]: Reached target Paths.

Dec 22 18:24:51 volumio systemd[1941]: Starting D-Bus User Message Bus Socket.

Dec 22 18:24:51 volumio systemd[1941]: Listening on GnuPG cryptographic agent (ssh-agent emulation).

Dec 22 18:24:51 volumio systemd[1941]: Listening on D-Bus User Message Bus Socket.

Dec 22 18:24:51 volumio systemd[1941]: Reached target Sockets.

Dec 22 18:24:51 volumio systemd[1941]: Reached target Basic System.

Dec 22 18:24:51 volumio systemd[1]: Started User Manager for UID 1000.

Dec 22 18:24:51 volumio systemd[1941]: Starting Music Player Daemon…

Dec 22 18:24:51 volumio systemd[1]: Started Session 3 of user volumio.

Dec 22 18:24:52 volumio mpd[1952]: Dec 22 18:24 : exception: Failed to bind to ‘[::]:6600’

Dec 22 18:24:52 volumio mpd[1952]: Dec 22 18:24 : exception: nested: Failed to bind socket: Address already in use

Dec 22 18:24:52 volumio systemd[1941]: mpd.service: Main process exited, code=exited, status=1/FAILURE

Dec 22 18:24:52 volumio systemd[1941]: mpd.service: Failed with result ‘exit-code’.

Dec 22 18:24:52 volumio systemd[1941]: Failed to start Music Player Daemon.

Dec 22 18:24:52 volumio systemd[1941]: Reached target Default.

Dec 22 18:24:52 volumio systemd[1941]: Startup finished in 1.019s.

Dec 22 18:25:11 volumio volumio[1662]: error: error

Dec 22 18:26:01 volumio volumio[1662]: error: error

Dec 22 18:26:51 volumio volumio[1662]: error: error

Dec 22 18:26:55 volumio volumio[1662]: error: error

Dec 22 18:27:41 volumio volumio[1662]: error: error

Dec 22 18:28:31 volumio volumio[1662]: error: error

Dec 22 18:28:34 volumio volumio[1662]: error: error

Dec 22 18:29:21 volumio systemd[1]: Starting Cleanup of Temporary Directories…

Dec 22 18:29:21 volumio systemd[1]: systemd-tmpfiles-clean.service: Succeeded.

Dec 22 18:29:21 volumio systemd[1]: Started Cleanup of Temporary Directories.

Dec 22 18:29:24 volumio volumio[1662]: error: error

Dec 22 18:30:11 volumio volumio[1662]: error: error

Dec 22 18:30:24 volumio sudo[2009]: volumio : TTY=pts/0 ; PWD=/home/volumio ; USER=root ; COMMAND=/sbin/iwconfig

Dec 22 18:30:24 volumio sudo[2009]: pam_unix(sudo:session): session opened for user root by volumio(uid=0)

Dec 22 18:30:24 volumio sudo[2009]: pam_unix(sudo:session): session closed for user root

Dec 22 18:30:24 volumio systemd[1941]: Starting Sound Service…

Dec 22 18:30:24 volumio dbus-daemon[408]: [system] Activating via systemd: service name=‘org.freedesktop.RealtimeKit1’ unit=‘rtkit-daemon.service’ requested by ‘:1.33’ (uid=1000 pid=2013 comm="/usr/bin/pulseaudio --daemonize=no ")

Dec 22 18:30:24 volumio systemd[1]: Starting RealtimeKit Scheduling Policy Service…

Dec 22 18:30:24 volumio dbus-daemon[408]: [system] Successfully activated service ‘org.freedesktop.RealtimeKit1’

Dec 22 18:30:24 volumio systemd[1]: Started RealtimeKit Scheduling Policy Service.

Dec 22 18:30:24 volumio rtkit-daemon[2022]: Successfully called chroot.

Dec 22 18:30:24 volumio rtkit-daemon[2022]: Successfully dropped privileges.

Dec 22 18:30:24 volumio rtkit-daemon[2022]: Successfully limited resources.

Dec 22 18:30:24 volumio rtkit-daemon[2022]: Running.

Dec 22 18:30:24 volumio rtkit-daemon[2022]: Canary thread running.

Dec 22 18:30:24 volumio dbus-daemon[408]: [system] Activating via systemd: service name=‘org.freedesktop.PolicyKit1’ unit=‘polkit.service’ requested by ‘:1.34’ (uid=0 pid=2022 comm="/usr/lib/rtkit/rtkit-daemon ")

Dec 22 18:30:24 volumio rtkit-daemon[2022]: Watchdog thread running.

Dec 22 18:30:24 volumio systemd[1]: Starting Authorization Manager…

Dec 22 18:30:24 volumio polkitd[2029]: started daemon version 0.105 using authority implementation local' version 0.105’

Dec 22 18:30:24 volumio dbus-daemon[408]: [system] Successfully activated service ‘org.freedesktop.PolicyKit1’

Dec 22 18:30:24 volumio systemd[1]: Started Authorization Manager.

Dec 22 18:30:25 volumio systemd[1941]: Started D-Bus User Message Bus.

Dec 22 18:30:25 volumio systemd[1941]: Started Sound Service.

Dec 22 18:30:25 volumio bluetoothd[693]: Endpoint registered: sender=:1.54 path=/MediaEndpoint/A2DPSource

Dec 22 18:30:25 volumio bluetoothd[693]: Endpoint registered: sender=:1.54 path=/MediaEndpoint/A2DPSink

Dec 22 18:30:25 volumio pulseaudio[2013]: E: [pulseaudio] backend-ofono.c: Failed to register as a handsfree audio agent with ofono: org.freedesktop.DBus.Error.ServiceUnknown: The name org.ofono was not provided by any .service files

Dec 22 18:30:25 volumio kernel: Bluetooth: RFCOMM TTY layer initialized

Dec 22 18:30:25 volumio kernel: Bluetooth: RFCOMM socket layer initialized

Dec 22 18:30:25 volumio kernel: Bluetooth: RFCOMM ver 1.11

Dec 22 18:30:38 volumio sudo[2068]: volumio : TTY=pts/0 ; PWD=/home/volumio ; USER=root ; COMMAND=/bin/journalctl -p 7

Dec 22 18:30:38 volumio sudo[2068]: pam_unix(sudo:session): session opened for user root by volumio(uid=0)

rwood03 · December 23, 2021, 11:58am

Can confirm same issue running fresh installs of both your v3.175 and v3.179 IMGs on 2 separate Pi 3B+ machines.

After activation there are continual prompts of:
“Configuration update
Player successfully restarted”.
Which renders the Pi 3B+ pretty much unusable on activation.

By deactivating the Pi 3B+ online and re-imaging, it returns to “normal” operations - normal for a deactivated machine.

Having just upgraded my account to premium specifically for the multi-room functionality provided by v3 - the upgrade and v3 are currently useless to me.

A Pi 4 running v2.917 is my only functional Volumio machine.

Hoping this can be resolved soon.

volumio · December 23, 2021, 6:27pm

Thanks! This helps pinpoint the issue!

mervinio · December 24, 2021, 9:00am

Hi @mikand @dglonsdale @juanj2099 @rwood03

We are now testing the fix for your issues, we will deploy a hotfix soon.

The problem seems to be related to chromecast devices. Can you please tell us what kind of chromecast enabled devices are on your network? Did you do any modifications to your volumio system?

mikand · December 24, 2021, 9:22am

I have a chromecast ultra 4k, a google Nest and a android tv with chromecast. But I usually not use them except for display för Roon. I also have a technics SL-G700 cd-player with built in chromecast.
/Mikael

dglonsdale · December 24, 2021, 9:30am

I have a number of Google Home/Nest devices, along with Sony TVs/soundbars with built in chromecast.

dglonsdale · December 24, 2021, 9:38am

No modifications to Volumio

mervinio · December 24, 2021, 10:30am

@mikand @dglonsdale

It would really help us if you could power off all chromecast devices one by one and let us know which device was the cause. Meanwhile a fix is on it’s way.

mikand · December 24, 2021, 11:08am

Hi I have powered of all Chromcast devices but it not seems to help
/Mikael

mikand · December 24, 2021, 11:39am

But I have many other devices who are capable of sending to chromecast devices so I may be some traffic without chromecast devices enabled I suppose?
/MIkael

dglonsdale · December 24, 2021, 12:37pm

I have turned off (at the mains) all the chromecast devices I can see on my network. Enabled myvolumio on one of the RPi devices and am not getting the restart problem; however, when I hit the “settings” button for the multiroom playback, I do not get any options. I will turn on the chromecast devices one-by-one, and let you know if I get the restart problem again.

dglonsdale · December 24, 2021, 12:47pm

I am now seeing the “group devices” option on multiroom (even though I’ve only got one device running at the moment). I’ll get back to testing that again once I’ve turned the other chromecast devices back on.