crickets
Dear Friends of Volumio,
first of all I want to describe my problem: After having used a TEAC WAP AX-100 sytem for streaming music and listening to webradio I am more and more disappointed due to many interruptions of the stream. This is a well known problem to all TEAC streaming solutions and it might be the reason for not manufacturing these devices any more. After each and any interruption you are forced to switch off the device, wait for ten seconds and then switch it on again. Then it takes about two minutes before you can connect your handheld device to the TEAC streamer again. Very frustrating.
So I thought about setting up my Paspberry Pi 3 / HiFiBerry light / 7" original display as a music streaming system. After testing some other distributions I have chosen Volumio. All works fine after setting up. Only one thing is bugging me. I made a clean install of ‘volumio-2.378-2018-03-13-pi’ and then logged in at the Raspi by volumio/volumio. On the console I typed
sudo apt-get install keyboard-configuration (as described earlier)
and got the following message on screen:
Reading package lists… Done
Building dependency tree
Reading state information… Done
E: Unable to locate package keyboard-configuration
So when I ignore this error and try to install the touchscreen, it hangs at the keyboard-configuration as also described before.
Please let me know what I am doing wrong. Any help is welcome!
Gunter
Do a “sudo apt-get update” before “sudo apt-get install keyboard-configuration”
Hello,
Trying to install the Touch display plugin on a freshly install RPI3, version 2.513 (2 weeks ago). . Everythings goes fine but stops at 70%. I have not seen any error during installation.
Last messages in volumio.log are:
volumio@volumio:/var/log$ tail -f volumio.log
2019-01-07T12:05:57.430Z - info: Creating chromium kiosk start script
2019-01-07T12:05:57.438Z - info: Creating Systemd Unit for Kiosk
2019-01-07T12:05:57.442Z - info: Allowing volumio to start an xsession
2019-01-07T12:05:57.457Z - info: Install script completed
2019-01-07T12:05:57.462Z - info: Adding reference to registry
2019-01-07T12:05:57.468Z - info: Done installing plugin.
2019-01-07T12:05:57.487Z - info: Folder /tmp/plugins removed
2019-01-07T12:05:57.488Z - info: Folder /tmp/downloaded_plugin.zip removed
2019-01-07T12:05:57.491Z - info: Disabling Kiosk Service
2019-01-07T12:05:57.527Z - info: Folder /data/temp removedDoes not seem that anything is running, but the web UI is still stuck on 70%. Should I simply reboot?
Thanks for your help
Rebootting solved the issue. Something missing in the install script?
Well, things go bad… I am not sure it is related to the Display plugin, but I used volumio for 2 weeks without this plugin and never had this problem before.
I noticed that the volume control did not work, so I rebooted again, just to be sure I had not changed something.
Now, everything hangs up after a while. The PI boots, the display come up on the touch screen but nothing happens then (I cannot see my lybrary of music). Worst, everything is frozen on the screen, the touch screen does not respond and a web client won’t work either.
Ping replies work (!). I was able to connect through ssh before having the problem. Here is the result of the “top” command:
Tasks: 133 total, 3 running, 83 sleeping, 0 stopped, 1 zombie
%Cpu(s): 0.0 us, 11.8 sy, 0.0 ni, 46.6 id, 41.5 wa, 0.0 hi, 0.1 si, 0.0 st
KiB Mem: 994104 total, 977272 used, 16832 free, 1324 buffers
KiB Swap: 0 total, 0 used, 0 free. 71388 cached Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
44 root 20 0 0 0 0 S 9.8 0.0 0:14.14 kswapd0
108 root 0 -20 0 0 0 S 4.6 0.0 0:06.85 loop0
1015 root 20 0 509388 20760 5164 D 3.7 2.1 0:12.60 chromium-browse
574 volumio 20 0 31380 708 0 S 3.2 0.1 0:02.90 volumio-remote-
874 root 20 0 6612 388 0 D 3.0 0.0 0:02.74 wpa_supplicant
711 ntp 20 0 23476 1440 0 D 2.9 0.1 0:04.02 ntpd
166 root 20 0 8028 1216 940 R 2.8 0.1 0:04.32 systemd-journal
1 root 20 0 5708 1328 0 S 2.6 0.1 0:09.26 systemd
949 volumio 20 0 779764 649828 0 D 2.6 65.4 2:07.33 node
810 root 20 0 21304 1232 28 R 2.5 0.1 0:03.54 nmbd
91 root 20 0 0 0 0 S 2.4 0.0 0:03.93 mmcqd/0
984 root 19 -1 112396 10640 3000 S 2.4 1.1 0:03.72 Xorg
1296 volumio 20 0 5036 420 0 R 2.3 0.0 0:04.45 top
1100 root 20 0 426136 95388 58828 D 1.8 9.6 0:20.10 chromium-browse
1300 root 20 0 21304 1204 0 D 1.3 0.1 0:00.77 nmbd
342 systemd+ 20 0 30088 1248 0 S 1.2 0.1 0:02.71 systemd-timesyn
697 root 20 0 1800 88 0 S 1.1 0.0 0:01.49 ifplugd
873 root 20 0 34028 1816 140 S 1.1 0.2 0:00.86 smbd
1014 root 20 0 19488 1572 0 D 0.9 0.2 0:00.90 openbox
589 root 20 0 3764 244 0 S 0.8 0.0 0:01.08 systemd-logind
1289 volumio 20 0 26384 1664 0 S 0.8 0.2 0:01.61 sshd
3 root 20 0 0 0 0 I 0.7 0.0 0:01.27 kworker/0:0
1010 root 20 0 3616 204 0 S 0.5 0.0 0:00.61 ssh-agent
826 root 20 0 27116 1432 0 S 0.4 0.1 0:00.50 winbindd
877 root 20 0 27120 1424 8 S 0.4 0.1 0:00.35 winbindd
878 root 20 0 27120 1436 0 S 0.3 0.1 0:00.34 winbindd
623 avahi 20 0 3896 264 0 S 0.3 0.0 0:00.68 avahi-daemon
31 root 20 0 0 0 0 I 0.3 0.0 0:00.42 kworker/2:1
879 root 20 0 34028 1684 8 S 0.3 0.2 0:00.30 smbd Seems to me that a lot of memory is used… Is it normal?
What can I do except flash a new fresh image?
It seems I have a power supply problem. I have installed a “ifi audio” 5V 2,5A for the device. It looks like 2,5 is not enough for the RPI + screen. I have moved to a standard 3A supply, and things are better now.
I’ve had a few issues with my iFi PSU too.
I have the 3B+, 7" touchscreen and an Allo DigiOne and experienced under-voltage errors on the Pi. Having read in many places about the length of cable, poor quality USB leads etc I made the ‘brave’ decision to cut the iFi power lead (leaving only 15cm of cable) and remove all the adaptor plugs etc and simply solder the USB A female plug on to, allowing me to choose the ‘right’ USB lead. I’m still not 100% happy but the iFi seems to be bedding in, the under-voltage messages are now quite rare and I haven’t had one in the last 24 hours.
I’ve also disabled all the LEDs, disabled USB and switched off the HDMI output in a further attempt to reduce power consumption.
Setting the cpu governor to ‘ondemand’ will no doubt help.
Thanks for the advice.
I have now splitted the RPI alone on one side (ifi audio power supply), and the screen on a separate “standard” usb plug. Seems to work fine now.
Hello all,
Yesterday night, I ran again hopelessly into the swapping issue… I was obliged to unplug the PSU and restart. It ran OK after that
When booting, I have three cases:
- the nice one: process “node” takes almost all the CPU and RAM memory during 1 or 2 mn, and after that time, everything works OK. This is the “nice situation”. When the system is ready, it takes approx 50% of the RAM memory (see below)
top - 11:49:38 up 18 min, 1 user, load average: 0.00, 0.06, 0.17
Tasks: 128 total, 1 running, 84 sleeping, 0 stopped, 1 zombie
%Cpu(s): 0.1 us, 0.1 sy, 0.0 ni, 99.8 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st
KiB Mem: 994104 total, 491000 used, 503104 free, 14920 buffers
KiB Swap: 0 total, 0 used, 0 free. 128852 cached Mem-
the touchy one: while “node” is running, I can see also kswap0 (not enough memory, so swapping), but after a while (let’s say another couple of minutes), everything is fine.
-
the bad one: kswap0 never ends, and I can’t do anything, except hard rebbot with the PSU…
Tasks: 133 total, 3 running, 83 sleeping, 0 stopped, 1 zombie
%Cpu(s): 0.0 us, 11.8 sy, 0.0 ni, 46.6 id, 41.5 wa, 0.0 hi, 0.1 si, 0.0 st
KiB Mem: 994104 total, 977272 used, 16832 free, 1324 buffers
KiB Swap: 0 total, 0 used, 0 free. 71388 cached Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
44 root 20 0 0 0 0 S 9.8 0.0 0:14.14 kswapd0
108 root 0 -20 0 0 0 S 4.6 0.0 0:06.85 loop0
1015 root 20 0 509388 20760 5164 D 3.7 2.1 0:12.60 chromium-browse
574 volumio 20 0 31380 708 0 S 3.2 0.1 0:02.90 volumio-remote-
874 root 20 0 6612 388 0 D 3.0 0.0 0:02.74 wpa_supplicant
When this situation occurs: the touch display is frozen, I cannot open any new ssh connection. Ping works. So better open an ssh connection before to be able to see something. Anyway, the system is very slow. Is there any command I should use (apart from top) to understand what happens?
Obviously, it seems that, sometimes, “node” needs too much memory, more than available, at least. The question is: why does this happen only sometimes? Booting twice in the same conditions, sometimes it works, sometines it doesn’t. This looks strange to me.
Can I reduce the memory needed for “node”? Anything in the configuration, or in the way to use volumio?
I am using the 2.513 image, installed only the display plugin on it, plus “iftop”, to check network transfers, that’s all. But “iftop” is not running at boot time. I don’t see “extra” process running that would take some CPU/MEM while booting. So the problem seems to be on the “node” process.
I could add a swap file on an external USB stick. Would it help? Swapping on the SD card will kill it shortly, I think. I have read somewhere that Volumio manages swap when needed. Am I in this case? How could I check it?
Access to the log file is almost impossible due to the poor performance. And on reboot, the log disappears… I could put the log file on a usb stick to make it persistant?
Any help will be appreciated
Again the same problem today:
result of “top”:
top - 14:07:16 up 4 min, 1 user, load average: 1.99, 1.14, 0.51
Tasks: 133 total, 3 running, 82 sleeping, 0 stopped, 1 zombie
%Cpu(s): 1.8 us, 13.2 sy, 0.0 ni, 56.7 id, 28.3 wa, 0.0 hi, 0.1 si, 0.0 st
KiB Mem: 994104 total, 974708 used, 19396 free, 880 buffers
KiB Swap: 0 total, 0 used, 0 free. 49844 cached Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
944 volumio 20 0 794636 665336 0 D 42.7 66.9 3:44.44 node
1011 root 20 0 486684 30100 5100 D 10.9 3.0 0:04.98 chromium-browse
44 root 20 0 0 0 0 R 10.3 0.0 0:01.34 kswapd0
108 root 0 -20 0 0 0 R 3.3 0.0 0:01.05 loop0
1375 volumio 20 0 5036 1020 600 R 2.7 0.1 0:00.46 top
709 ntp 20 0 23476 1440 0 S 2.4 0.1 0:00.34 ntpd
90 root 20 0 0 0 0 S 1.8 0.0 0:01.02 mmcqd/0
690 root 20 0 1800 88 0 S 0.9 0.0 0:00.08 ifplugd
29 root 20 0 0 0 0 I 0.6 0.0 0:00.46 kworker/0:1
8 root 20 0 0 0 0 I 0.3 0.0 0:00.19 rcu_sched
32 root 20 0 0 0 0 I 0.3 0.0 0:00.11 kworker/3:1
65 root -51 0 0 0 0 S 0.3 0.0 0:00.11 irq/92-mmc1
115 root 0 -20 0 0 0 I 0.3 0.0 0:00.04 kworker/3:1H
234 root 20 0 0 0 0 S 0.3 0.0 0:00.22 ft5406
1006 root 20 0 3616 204 0 S 0.3 0.0 0:00.01 ssh-agent
1 root 20 0 5596 1272 4 S 0.0 0.1 0:04.79 systemd
2 root 20 0 0 0 0 S 0.0 0.0 0:00.00 kthreadd All the memoty is in use. Apparently, no swap, but kswapd0 is present.
I quitted top. Trying to relaunch it:
volumio@volumio:~$ top
-bash: fork: Cannot allocate memory…
Here is the content of /var/log/volumio.log after a restart (unplug and replug PSU). I do not see any remarkable error in it, nothing explaining the memory problem, to my undestanding. If anybody could find anything that can explain the problem in this logfile, I will be happy to learn.
Hint: you will see that the time/date is updated just after 12:23:38.385, this is because /etc/rc.local makes this update in parrallel, jumping to 13:45, as NTP does work through wifi (see my other recent post for details)
And the confirmation that swap is not allowed:
sudo free -h
[sudo] password for volumio:
total used free shared buffers cached
Mem: 970M 932M 37M 124M 34M 522M
-/+ buffers/cache: 376M 594M
Swap: 0B 0B 0B
Volumio.log:
2019-01-09T12:23:35.566Z - info: -------------------------------------------
2019-01-09T12:23:35.570Z - info: ----- Volumio2 ----
2019-01-09T12:23:35.570Z - info: -------------------------------------------
2019-01-09T12:23:35.571Z - info: ----- System startup ----
2019-01-09T12:23:35.571Z - info: -------------------------------------------
2019-01-09T12:23:35.800Z - info: Plugin folders cleanup
2019-01-09T12:23:35.802Z - info: Scanning into folder /volumio/app/plugins/
2019-01-09T12:23:35.804Z - info: Scanning category audio_interface
2019-01-09T12:23:35.807Z - info: Scanning category miscellanea
2019-01-09T12:23:35.809Z - info: Scanning category music_service
2019-01-09T12:23:35.811Z - info: Scanning category plugins.json
2019-01-09T12:23:35.813Z - info: Scanning category system_controller
2019-01-09T12:23:35.815Z - info: Scanning category user_interface
2019-01-09T12:23:35.818Z - info: Scanning into folder /data/plugins/
2019-01-09T12:23:35.819Z - info: Scanning category miscellanea
2019-01-09T12:23:35.822Z - info: Plugin folders cleanup completed
2019-01-09T12:23:35.825Z - info: -------------------------------------------
2019-01-09T12:23:35.826Z - info: ----- Core plugins startup ----
2019-01-09T12:23:35.828Z - info: -------------------------------------------
2019-01-09T12:23:35.830Z - info: Loading plugins from folder /volumio/app/plugins/
2019-01-09T12:23:35.835Z - info: Adding plugin upnp to MyMusic Plugins
2019-01-09T12:23:35.839Z - info: Adding plugin airplay_emulation to MyMusic Plugins
2019-01-09T12:23:35.842Z - info: Adding plugin upnp_browser to MyMusic Plugins
2019-01-09T12:23:35.845Z - info: Loading plugins from folder /data/plugins/
2019-01-09T12:23:35.848Z - info: Loading plugin "system"...
2019-01-09T12:23:35.895Z - info: Loading plugin "appearance"...
2019-01-09T12:23:37.508Z - info: Loading plugin "network"...
2019-01-09T12:23:38.165Z - info: Loading plugin "services"...
2019-01-09T12:23:38.172Z - info: Loading plugin "alsa_controller"...
2019-01-09T12:23:38.314Z - info: Loading plugin "wizard"...
2019-01-09T12:23:38.338Z - info: Loading plugin "volumio_command_line_client"...
2019-01-09T12:23:38.349Z - info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
2019-01-09T12:23:38.350Z - info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
2019-01-09T12:23:38.351Z - info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
2019-01-09T12:23:38.351Z - info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
2019-01-09T12:23:38.384Z - info: Plugin upnp is not enabled
2019-01-09T12:23:38.385Z - info: Loading plugin "my_music"...
2019-01-09T13:45:41.007Z - info: Loading plugin "mpd"...
2019-01-09T13:45:41.581Z - info: Plugin upnp_browser is not enabled
2019-01-09T13:45:41.582Z - info: Loading plugin "networkfs"...
2019-01-09T13:45:41.652Z - info: CoreCommandRouter::executeOnPlugin: system , registerCallback
2019-01-09T13:45:41.654Z - info: Loading plugin "alarm-clock"...
2019-01-09T13:45:42.019Z - info: Plugin airplay_emulation is not enabled
2019-01-09T13:45:42.021Z - info: Loading plugin "last_100"...
2019-01-09T13:45:42.029Z - info: Loading plugin "webradio"...
2019-01-09T13:45:42.941Z - info: Loading plugin "i2s_dacs"...
2019-01-09T13:45:42.958Z - info: I2S DAC not set, start Auto-detection
2019-01-09T13:45:42.976Z - info: Loading plugin "volumiodiscovery"...
2019-01-09T13:45:43.059Z - info: Applying required configuration parameters for plugin volumiodiscovery
2019-01-09T13:45:43.115Z - info: CoreCommandRouter::executeOnPlugin: system , registerCallback
2019-01-09T13:45:43.118Z - info: Loading plugin "albumart"...
2019-01-09T13:45:43.167Z - info: Plugin example_plugin is not enabled
2019-01-09T13:45:43.169Z - info: Loading plugin "updater_comm"...
2019-01-09T13:45:43.346Z - info: Plugin mpdemulation is not enabled
2019-01-09T13:45:43.347Z - info: Loading plugin "rest_api"...
2019-01-09T13:45:43.363Z - info: Loading plugin "websocket"...
2019-01-09T13:45:43.393Z - info: Plugin touch_display is not enabled
2019-01-09T13:45:43.395Z - info: ___________ START PLUGINS ___________
2019-01-09T13:45:43.399Z - info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
2019-01-09T13:45:43.401Z - info: [1547041543400] CoreMusicLibrary::Adding element Last_100
2019-01-09T13:45:43.409Z - info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
2019-01-09T13:45:43.409Z - info: [1547041543409] CoreMusicLibrary::Adding element Webradio
2019-01-09T13:45:43.412Z - info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
2019-01-09T13:45:43.416Z - info: -------------------------------------------
2019-01-09T13:45:43.416Z - info: ----- MyVolumio plugins startup ----
2019-01-09T13:45:43.416Z - info: -------------------------------------------
2019-01-09T13:45:43.418Z - info: Loading plugins from folder /myvolumio/plugins
2019-01-09T13:45:43.446Z - info: Loading plugins from folder /data/myvolumio/plugins
2019-01-09T13:45:43.449Z - info: Loading plugin "my_volumio"...
2019-01-09T13:45:44.118Z - info: Loading plugin "streaming_services"...
2019-01-09T13:45:44.639Z - info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
2019-01-09T13:45:44.640Z - info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
2019-01-09T13:45:44.679Z - info: Streaming services startup
2019-01-09T13:45:44.708Z - info: Loading i18n strings for locale fr
2019-01-09T13:45:44.746Z - info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
2019-01-09T13:45:44.750Z - info: CoreCommandRouter::initPlayerControls
2019-01-09T13:45:44.762Z - info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
2019-01-09T13:45:44.763Z - info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAlsaCards
2019-01-09T13:45:44.801Z - info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
2019-01-09T13:45:44.801Z - info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
2019-01-09T13:45:44.802Z - info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
2019-01-09T13:45:44.803Z - info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
2019-01-09T13:45:44.804Z - info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
2019-01-09T13:45:44.815Z - info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
2019-01-09T13:45:44.819Z - info: BOOT COMPLETED
2019-01-09T13:45:44.820Z - info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
2019-01-09T13:45:44.821Z - info: CoreCommandRouter::Close All Modals sent
2019-01-09T13:45:44.823Z - info: CoreCommandRouter::Close All Modals sent
2019-01-09T13:45:44.948Z - info: MyVolumio not started
2019-01-09T13:45:44.952Z - info: CoreStateMachine::resetVolumioState
2019-01-09T13:45:44.955Z - info: CoreStateMachine::getcurrentVolume
2019-01-09T13:45:44.958Z - info: CoreCommandRouter::volumioRetrievevolume
2019-01-09T13:45:44.977Z - info: CoreStateMachine::updateTrackBlock
2019-01-09T13:45:44.980Z - info: CorePlayQueue::getTrackBlock
2019-01-09T13:45:45.179Z - info: Setting Device type: Raspberry PI
2019-01-09T13:45:45.202Z - info: MPD running with PID622 ,establishing connection
2019-01-09T13:45:45.343Z - info: VolumeController:: Volume=49 Mute =false
2019-01-09T13:45:45.347Z - info: CoreStateMachine::pushState
2019-01-09T13:45:45.350Z - info: CoreStateMachine::getState
2019-01-09T13:45:45.351Z - info: CorePlayQueue::getTrack 0
2019-01-09T13:45:45.353Z - info: CoreCommandRouter::volumioPushState
2019-01-09T13:45:45.353Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2019-01-09T13:45:45.363Z - info: Volumio called home
2019-01-09T13:45:45.428Z - info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
2019-01-09T13:45:45.438Z - info: Reloading queue from file
2019-01-09T13:45:45.464Z - info:
2019-01-09T13:45:45.471Z - info: message= [50@0] {} No such directory, stack=Error: [50@0] {} No such directory
at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:63:14)
at Socket.<anonymous> (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:10)
at emitOne (events.js:116:13)
at Socket.emit (events.js:211:7)
at addChunk (_stream_readable.js:263:12)
at readableAddChunk (_stream_readable.js:246:13)
at Socket.Readable.push (_stream_readable.js:208:10)
at Pipe.onread (net.js:607:20)
2019-01-09T13:45:45.546Z - info: CoreStateMachine::setRepeat null single undefined
2019-01-09T13:45:45.547Z - info: CoreStateMachine::pushState
2019-01-09T13:45:45.549Z - info: CoreStateMachine::getState
2019-01-09T13:45:45.550Z - info: CorePlayQueue::getTrack 0
2019-01-09T13:45:45.552Z - info: CoreCommandRouter::volumioPushState
2019-01-09T13:45:45.553Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2019-01-09T13:45:45.557Z - info: CoreStateMachine::setRandom null
2019-01-09T13:45:45.557Z - info: CoreStateMachine::pushState
2019-01-09T13:45:45.558Z - info: CoreStateMachine::getState
2019-01-09T13:45:45.559Z - info: CorePlayQueue::getTrack 0
2019-01-09T13:45:45.560Z - info: CoreCommandRouter::volumioPushState
2019-01-09T13:45:45.560Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2019-01-09T13:45:45.723Z - info: mDNS: Found device Volumio
2019-01-09T13:45:45.847Z - info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
2019-01-09T13:45:45.897Z - info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
2019-01-09T13:45:46.274Z - info:
---------------------------- Client requests Volume 50
2019-01-09T13:45:46.278Z - info: VolumeController::SetAlsaVolume50
2019-01-09T13:45:46.295Z - info: CoreStateMachine::pushState
2019-01-09T13:45:46.296Z - info: CoreStateMachine::getState
2019-01-09T13:45:46.298Z - info: CorePlayQueue::getTrack 0
2019-01-09T13:45:46.300Z - info: CoreCommandRouter::volumioPushState
2019-01-09T13:45:46.300Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2019-01-09T13:45:46.417Z - info: Setting volume on startup at 50
2019-01-09T13:45:46.604Z - info: CoreCommandRouter::volumioGetState
2019-01-09T13:45:46.605Z - info: CoreStateMachine::getState
2019-01-09T13:45:46.605Z - info: CorePlayQueue::getTrack 0
2019-01-09T13:45:50.913Z - info: CoreCommandRouter::volumioGetBrowseSources
2019-01-09T13:45:50.925Z - info: CoreCommandRouter::volumioGetState
2019-01-09T13:45:50.925Z - info: CoreStateMachine::getState
2019-01-09T13:45:50.926Z - info: CorePlayQueue::getTrack 0
2019-01-09T13:45:50.961Z - info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
2019-01-09T13:45:50.984Z - info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
2019-01-09T13:45:50.985Z - info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
2019-01-09T13:45:51.025Z - info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
2019-01-09T13:45:51.028Z - info: Listing playlists
2019-01-09T13:45:55.004Z - info: CoreCommandRouter::volumioGetBrowseSources
2019-01-09T13:45:55.012Z - info: CoreCommandRouter::volumioGetState
2019-01-09T13:45:55.013Z - info: CoreStateMachine::getState
2019-01-09T13:45:55.014Z - info: CorePlayQueue::getTrack 0
2019-01-09T13:45:55.053Z - info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
2019-01-09T13:45:55.055Z - info: Listing playlists
2019-01-09T13:46:13.750Z - info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
2019-01-09T13:46:13.752Z - info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
2019-01-09T13:58:53.461Z - info: CoreCommandRouter::volumioGetBrowseSources
2019-01-09T13:58:53.471Z - info: CoreCommandRouter::volumioGetState
2019-01-09T13:58:53.471Z - info: CoreStateMachine::getState
2019-01-09T13:58:53.471Z - info: CorePlayQueue::getTrack 0
2019-01-09T13:58:53.685Z - info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
2019-01-09T13:58:53.685Z - info: Listing playlists
2019-01-09T13:58:56.965Z - info: CoreCommandRouter::volumioGetBrowseSources
2019-01-09T13:58:56.972Z - info: CoreCommandRouter::volumioGetState
2019-01-09T13:58:56.973Z - info: CoreStateMachine::getState
2019-01-09T13:58:56.973Z - info: CorePlayQueue::getTrack 0
2019-01-09T13:58:57.091Z - info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
2019-01-09T13:58:57.094Z - info: Listing playlists
2019-01-09T14:06:16.743Z - info: CoreCommandRouter::volumioGetQueue
2019-01-09T14:06:16.744Z - info: CoreStateMachine::getQueue
2019-01-09T14:06:16.745Z - info: CorePlayQueue::getQueue
2019-01-09T14:37:23.496Z - info: CoreCommandRouter::volumioGetBrowseSources
2019-01-09T14:37:23.497Z - info: CoreCommandRouter::volumioGetState
2019-01-09T14:37:23.497Z - info: CoreStateMachine::getState
2019-01-09T14:37:23.498Z - info: CorePlayQueue::getTrack 0
2019-01-09T14:37:23.523Z - info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
2019-01-09T14:37:23.525Z - info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
2019-01-09T14:37:23.525Z - info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
2019-01-09T14:37:23.556Z - info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
2019-01-09T14:37:23.557Z - info: Listing playlists
2019-01-09T14:37:31.663Z - info: CoreCommandRouter::volumioGetBrowseSources
2019-01-09T14:37:31.666Z - info: CoreCommandRouter::volumioGetState
2019-01-09T14:37:31.666Z - info: CoreStateMachine::getState
2019-01-09T14:37:31.666Z - info: CorePlayQueue::getTrack 0
2019-01-09T14:37:31.706Z - info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
2019-01-09T14:37:31.727Z - info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
2019-01-09T14:37:31.728Z - info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
2019-01-09T14:37:31.776Z - info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
2019-01-09T14:37:31.778Z - info: Listing playlists
2019-01-09T14:37:33.873Z - info: CoreCommandRouter::volumioGetQueue
2019-01-09T14:37:33.874Z - info: CoreStateMachine::getQueue
2019-01-09T14:37:33.874Z - info: CorePlayQueue::getQueue
2019-01-09T14:37:35.610Z - info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
2019-01-09T14:37:35.611Z - info: CURURI: music-library
2019-01-09T14:37:37.224Z - info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
2019-01-09T14:37:37.224Z - info: CURURI: music-library/NAS
2019-01-09T14:37:44.082Z - info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
2019-01-09T14:37:44.083Z - info: CURURI: music-library/NAS/RPI1
2019-01-09T14:37:44.088Z - info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
2019-01-09T14:37:44.089Z - info: CURURI: music-library/NAS/RPI1
2019-01-09T14:37:47.434Z - info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
2019-01-09T14:37:47.434Z - info: CURURI: music-library/NAS/RPI1/Rock
2019-01-09T14:37:51.129Z - info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
2019-01-09T14:37:51.129Z - info: CURURI: music-library/NAS/RPI1/Rock/000_NEWS_2018
2019-01-09T14:37:53.513Z - info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
2019-01-09T14:37:53.514Z - info: CURURI: music-library/NAS/RPI1/Rock/000_NEWS_2018/2018-12-17-Rory Gallagher
2019-01-09T14:37:58.533Z - info: CoreCommandRouter::volumioReplaceandPlayItems
2019-01-09T14:37:58.534Z - info: CoreStateMachine::ClearQueue
2019-01-09T14:37:58.535Z - info: CoreStateMachine::stop
2019-01-09T14:37:58.536Z - info: CoreStateMachine::setConsumeUpdateService undefined
2019-01-09T14:37:58.544Z - info: CorePlayQueue::clearPlayQueue
2019-01-09T14:37:58.545Z - info: CorePlayQueue::saveQueue
2019-01-09T14:37:58.547Z - info: CoreStateMachine::pushEmptyState
2019-01-09T14:37:58.548Z - info: CoreCommandRouter::volumioPushState
2019-01-09T14:37:58.548Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2019-01-09T14:37:58.578Z - info: CoreCommandRouter::volumioPushQueue
2019-01-09T14:37:58.581Z - info: CoreStateMachine::addQueueItems
2019-01-09T14:37:58.582Z - info: CorePlayQueue::addQueueItems
2019-01-09T14:37:58.583Z - info: Adding Item to queue: music-library/NAS/RPI1/Rock/000_NEWS_2018/2018-12-17-Rory Gallagher/Rory_Gallagher-Top_Priority
2019-01-09T14:37:58.584Z - info: Exploding uri music-library/NAS/RPI1/Rock/000_NEWS_2018/2018-12-17-Rory Gallagher/Rory_Gallagher-Top_Priority in service mpd
2019-01-09T14:37:58.634Z - info: ALBUMART /albumart?cacheid=385&web=Rory%20Gallagher/Top%20Priority/extralarge&path=%2Fmnt%2FNAS%2FRPI1%2FRock%2F000_NEWS_2018%2F2018-12-17-Rory%20Gallagher%2FRory_Gallagher-
Top_Priority%2F01-Follow_Me.flac&metadata=false
2019-01-09T14:37:58.634Z - info: URI /mnt/NAS/RPI1/Rock/000_NEWS_2018/2018-12-17-Rory Gallagher/Rory_Gallagher-Top_Priority/01-Follow_Me.flac
2019-01-09T14:37:58.640Z - info: ALBUMART /albumart?cacheid=385&web=Rory%20Gallagher/Top%20Priority/extralarge&path=%2Fmnt%2FNAS%2FRPI1%2FRock%2F000_NEWS_2018%2F2018-12-17-Rory%20Gallagher%2FRory_Gallagher-
Top_Priority%2F02-Philby.flac&metadata=false
2019-01-09T14:37:58.641Z - info: URI /mnt/NAS/RPI1/Rock/000_NEWS_2018/2018-12-17-Rory Gallagher/Rory_Gallagher-Top_Priority/02-Philby.flac
2019-01-09T14:37:58.642Z - info: ALBUMART /albumart?cacheid=385&web=Rory%20Gallagher/Top%20Priority/extralarge&path=%2Fmnt%2FNAS%2FRPI1%2FRock%2F000_NEWS_2018%2F2018-12-17-Rory%20Gallagher%2FRory_Gallagher-
Top_Priority%2F03-Wayward_Child.flac&metadata=false
2019-01-09T14:37:58.643Z - info: URI /mnt/NAS/RPI1/Rock/000_NEWS_2018/2018-12-17-Rory Gallagher/Rory_Gallagher-Top_Priority/03-Wayward_Child.flac
2019-01-09T14:37:58.644Z - info: ALBUMART /albumart?cacheid=385&web=Rory%20Gallagher/Top%20Priority/extralarge&path=%2Fmnt%2FNAS%2FRPI1%2FRock%2F000_NEWS_2018%2F2018-12-17-Rory%20Gallagher%2FRory_Gallagher-
Top_Priority%2F04-Keychain.flac&metadata=false
2019-01-09T14:37:58.645Z - info: URI /mnt/NAS/RPI1/Rock/000_NEWS_2018/2018-12-17-Rory Gallagher/Rory_Gallagher-Top_Priority/04-Keychain.flac
2019-01-09T14:37:58.645Z - info: ALBUMART /albumart?cacheid=385&web=Rory%20Gallagher/Top%20Priority/extralarge&path=%2Fmnt%2FNAS%2FRPI1%2FRock%2F000_NEWS_2018%2F2018-12-17-Rory%20Gallagher%2FRory_Gallagher-
Top_Priority%2F05-At_The_Depot.flac&metadata=false
2019-01-09T14:37:58.646Z - info: URI /mnt/NAS/RPI1/Rock/000_NEWS_2018/2018-12-17-Rory Gallagher/Rory_Gallagher-Top_Priority/05-At_The_Depot.flac
2019-01-09T14:37:58.646Z - info: ALBUMART /albumart?cacheid=385&web=Rory%20Gallagher/Top%20Priority/extralarge&path=%2Fmnt%2FNAS%2FRPI1%2FRock%2F000_NEWS_2018%2F2018-12-17-Rory%20Gallagher%2FRory_Gallagher-
Top_Priority%2F06-Bad_Penny.flac&metadata=false
2019-01-09T14:37:58.647Z - info: URI /mnt/NAS/RPI1/Rock/000_NEWS_2018/2018-12-17-Rory Gallagher/Rory_Gallagher-Top_Priority/06-Bad_Penny.flac
2019-01-09T14:37:58.647Z - info: ALBUMART /albumart?cacheid=385&web=Rory%20Gallagher/Top%20Priority/extralarge&path=%2Fmnt%2FNAS%2FRPI1%2FRock%2F000_NEWS_2018%2F2018-12-17-Rory%20Gallagher%2FRory_Gallagher-
Top_Priority%2F07-Just_Hit_Town.flac&metadata=false
2019-01-09T14:37:58.648Z - info: URI /mnt/NAS/RPI1/Rock/000_NEWS_2018/2018-12-17-Rory Gallagher/Rory_Gallagher-Top_Priority/07-Just_Hit_Town.flac
2019-01-09T14:37:58.650Z - info: ALBUMART /albumart?cacheid=385&web=Rory%20Gallagher/Top%20Priority/extralarge&path=%2Fmnt%2FNAS%2FRPI1%2FRock%2F000_NEWS_2018%2F2018-12-17-Rory%20Gallagher%2FRory_Gallagher-
Top_Priority%2F08-Off_The_Handle.flac&metadata=false
2019-01-09T14:37:58.651Z - info: URI /mnt/NAS/RPI1/Rock/000_NEWS_2018/2018-12-17-Rory Gallagher/Rory_Gallagher-Top_Priority/08-Off_The_Handle.flac
2019-01-09T14:37:58.652Z - info: ALBUMART /albumart?cacheid=385&web=Rory%20Gallagher/Top%20Priority/extralarge&path=%2Fmnt%2FNAS%2FRPI1%2FRock%2F000_NEWS_2018%2F2018-12-17-Rory%20Gallagher%2FRory_Gallagher-
Top_Priority%2F10-Nothing_But_The_Devil.flac&metadata=false
2019-01-09T14:37:58.653Z - info: URI /mnt/NAS/RPI1/Rock/000_NEWS_2018/2018-12-17-Rory Gallagher/Rory_Gallagher-Top_Priority/10-Nothing_But_The_Devil.flac
2019-01-09T14:37:58.965Z - info: CorePlayQueue::saveQueue
2019-01-09T14:37:58.966Z - info: CoreCommandRouter::volumioPushQueue
2019-01-09T14:37:58.973Z - info: CoreStateMachine::updateTrackBlock
2019-01-09T14:37:58.974Z - info: CorePlayQueue::getTrackBlock
2019-01-09T14:37:58.975Z - info: CoreCommandRouter::volumioPlay
2019-01-09T14:37:58.977Z - info: CoreStateMachine::play index 0
2019-01-09T14:37:58.977Z - info: CoreStateMachine::setConsumeUpdateService undefined
2019-01-09T14:37:58.979Z - info: CoreStateMachine::stop
2019-01-09T14:37:58.979Z - info: CoreStateMachine::setConsumeUpdateService undefined
2019-01-09T14:37:58.980Z - info: CoreStateMachine::play index undefined
2019-01-09T14:37:58.980Z - info: CoreStateMachine::setConsumeUpdateService undefined
2019-01-09T14:37:58.981Z - info: CorePlayQueue::getTrack 0
2019-01-09T14:37:58.982Z - info: CoreStateMachine::startPlaybackTimer
2019-01-09T14:37:58.982Z - info: CorePlayQueue::getTrack 0
2019-01-09T14:37:58.984Z - info: ControllerMpd::clearAddPlayTracks NAS/RPI1/Rock/000_NEWS_2018/2018-12-17-Rory Gallagher/Rory_Gallagher-Top_Priority/01-Follow_Me.flac
2019-01-09T14:37:58.986Z - info: ControllerMpd::sendMpdCommand stop
2019-01-09T14:37:58.989Z - info: sending command...
2019-01-09T14:37:58.990Z - info: parsing response...
2019-01-09T14:37:58.992Z - info: ControllerMpd::sendMpdCommand clear
2019-01-09T14:37:58.993Z - info: sending command...
2019-01-09T14:37:58.996Z - info:
---------------------------- MPD announces system playlist update
2019-01-09T14:37:58.997Z - info: Ignoring MPD Status Update
2019-01-09T14:37:58.997Z - info: parsing response...
2019-01-09T14:37:58.998Z - info: ControllerMpd::sendMpdCommand add "NAS/RPI1/Rock/000_NEWS_2018/2018-12-17-Rory Gallagher/Rory_Gallagher-Top_Priority/01-Follow_Me.flac"
2019-01-09T14:37:58.999Z - info: sending command...
2019-01-09T14:37:59.004Z - info:
2019-01-09T14:37:59.006Z - info: ------------------------------ 11ms
2019-01-09T14:37:59.010Z - info:
---------------------------- MPD announces system playlist update
2019-01-09T14:37:59.011Z - info: Ignoring MPD Status Update
2019-01-09T14:37:59.012Z - info: parsing response...
2019-01-09T14:37:59.013Z - info: ControllerMpd::sendMpdCommand play
2019-01-09T14:37:59.014Z - info: sending command...
2019-01-09T14:37:59.017Z - info: ------------------------------ 7ms
2019-01-09T14:37:59.037Z - info: parsing response...
2019-01-09T14:37:59.826Z - info:
---------------------------- MPD announces state update: player
2019-01-09T14:37:59.828Z - info: ControllerMpd::getState
2019-01-09T14:37:59.829Z - info: ControllerMpd::sendMpdCommand status
2019-01-09T14:37:59.830Z - info: sending command...
2019-01-09T14:38:00.097Z - info: parsing response...
2019-01-09T14:38:00.102Z - info: ControllerMpd::parseState
2019-01-09T14:38:00.103Z - info: ControllerMpd::sendMpdCommand playlistinfo
2019-01-09T14:38:00.104Z - info: sending command...
2019-01-09T14:38:00.106Z - info:
---------------------------- MPD announces state update: player
2019-01-09T14:38:00.108Z - info: ControllerMpd::getState
2019-01-09T14:38:00.108Z - info: ControllerMpd::sendMpdCommand status
2019-01-09T14:38:00.109Z - info: parsing response...
2019-01-09T14:38:00.111Z - info: sending command...
2019-01-09T14:38:00.114Z - info: ControllerMpd::parseTrackInfo
2019-01-09T14:38:00.116Z - info: ControllerMpd::pushState
2019-01-09T14:38:00.117Z - info: CoreCommandRouter::servicePushState
2019-01-09T14:38:00.122Z - info: CoreStateMachine::syncState
2019-01-09T14:38:00.122Z - info: CorePlayQueue::getTrack 0
2019-01-09T14:38:00.123Z - info: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":279,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"
isStreaming":false,"title":"Follow Me","artist":"Rory Gallagher","album":"Top Priority","uri":"NAS/RPI1/Rock/000_NEWS_2018/2018-12-17-Rory Gallagher/Rory_Gallagher-Top_Priority/01-Follow_Me.flac","trackType
":"flac"}
2019-01-09T14:38:00.124Z - info: CURRENT POSITION 0
2019-01-09T14:38:00.124Z - info: CoreStateMachine::syncState stateService play
2019-01-09T14:38:00.124Z - info: CoreStateMachine::syncState currentStatus stop
2019-01-09T14:38:00.125Z - info: CoreStateMachine::pushState
2019-01-09T14:38:00.125Z - info: CoreStateMachine::getState
2019-01-09T14:38:00.125Z - info: CorePlayQueue::getTrack 0
2019-01-09T14:38:00.126Z - info: CoreCommandRouter::volumioPushState
2019-01-09T14:38:00.126Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2019-01-09T14:38:00.191Z - info: ------------------------------ 365ms
2019-01-09T14:38:00.194Z - info: parsing response...
2019-01-09T14:38:00.195Z - info: ControllerMpd::parseState
2019-01-09T14:38:00.196Z - info: ControllerMpd::sendMpdCommand playlistinfo
2019-01-09T14:38:00.197Z - info: sending command...
2019-01-09T14:38:00.245Z - info: parsing response...
2019-01-09T14:38:00.247Z - info: ControllerMpd::parseTrackInfo
2019-01-09T14:38:00.250Z - info: ControllerMpd::pushState
2019-01-09T14:38:00.250Z - info: CoreCommandRouter::servicePushState
2019-01-09T14:38:00.251Z - info: CoreStateMachine::syncState
2019-01-09T14:38:00.252Z - info: CorePlayQueue::getTrack 0
2019-01-09T14:38:00.253Z - info: STATE SERVICE {"status":"play","position":0,"seek":464,"duration":279,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false
,"isStreaming":false,"title":"Follow Me","artist":"Rory Gallagher","album":"Top Priority","uri":"NAS/RPI1/Rock/000_NEWS_2018/2018-12-17-Rory Gallagher/Rory_Gallagher-Top_Priority/01-Follow_Me.flac","trackTy
pe":"flac"}
2019-01-09T14:38:00.254Z - info: CURRENT POSITION 0
2019-01-09T14:38:00.255Z - info: CoreStateMachine::syncState stateService play
2019-01-09T14:38:00.255Z - info: CoreStateMachine::syncState currentStatus play
2019-01-09T14:38:00.256Z - info: Received an update from plugin. extracting info from payload
2019-01-09T14:38:00.256Z - info: CoreStateMachine::pushState
2019-01-09T14:38:00.257Z - info: CoreStateMachine::getState
2019-01-09T14:38:00.258Z - info: CorePlayQueue::getTrack 0
2019-01-09T14:38:00.259Z - info: CoreCommandRouter::volumioPushState
2019-01-09T14:38:00.259Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2019-01-09T14:38:00.312Z - info: CoreStateMachine::pushState
2019-01-09T14:38:00.312Z - info: CoreStateMachine::getState
2019-01-09T14:38:00.313Z - info: CorePlayQueue::getTrack 0
2019-01-09T14:38:00.313Z - info: CoreCommandRouter::volumioPushState
2019-01-09T14:38:00.314Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2019-01-09T14:38:00.382Z - info: ------------------------------ 273ms
2019-01-09T14:42:33.835Z - info: CorePlayQueue::getTrack 0
2019-01-09T14:42:33.837Z - info: CorePlayQueue::getTrack 1
2019-01-09T14:42:33.837Z - info: Prefetching next song
2019-01-09T14:42:33.838Z - info: DOING PREFETCH IN MPD
2019-01-09T14:42:33.838Z - info: ControllerMpd::sendMpdCommand add "NAS/RPI1/Rock/000_NEWS_2018/2018-12-17-Rory Gallagher/Rory_Gallagher-Top_Priority/02-Philby.flac"
2019-01-09T14:42:33.839Z - info: sending command...
2019-01-09T14:42:33.842Z - info:
---------------------------- MPD announces system playlist update
2019-01-09T14:42:33.843Z - info: Ignoring MPD Status Update
2019-01-09T14:42:33.843Z - info: parsing response...
2019-01-09T14:42:33.844Z - info: ControllerMpd::sendMpdCommand consume 1
2019-01-09T14:42:33.845Z - info: sending command...
2019-01-09T14:42:33.847Z - info:
---------------------------- MPD announces state update: options
2019-01-09T14:42:33.847Z - info: ------------------------------ 6ms
2019-01-09T14:42:33.848Z - info: parsing response...
2019-01-09T14:42:33.848Z - info: ControllerMpd::getState
2019-01-09T14:42:33.849Z - info: ControllerMpd::sendMpdCommand status
2019-01-09T14:42:33.849Z - info: sending command...
2019-01-09T14:42:33.850Z - info: parsing response...
2019-01-09T14:42:33.851Z - info: ControllerMpd::parseState
2019-01-09T14:42:33.852Z - info: ControllerMpd::sendMpdCommand playlistinfo
2019-01-09T14:42:33.853Z - info: sending command...
2019-01-09T14:42:33.854Z - info: parsing response...
2019-01-09T14:42:33.855Z - info: ControllerMpd::parseTrackInfo
2019-01-09T14:42:33.855Z - info: ControllerMpd::pushState
2019-01-09T14:42:33.856Z - info: CoreCommandRouter::servicePushState
2019-01-09T14:42:33.856Z - info: CoreStateMachine::syncState
2019-01-09T14:42:33.856Z - info: CorePlayQueue::getTrack 0
2019-01-09T14:42:33.857Z - info: STATE SERVICE {"status":"play","position":0,"seek":273809,"duration":279,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":fa
lse,"isStreaming":false,"title":"Follow Me","artist":"Rory Gallagher","album":"Top Priority","uri":"NAS/RPI1/Rock/000_NEWS_2018/2018-12-17-Rory Gallagher/Rory_Gallagher-Top_Priority/01-Follow_Me.flac","trac
kType":"flac"}
2019-01-09T14:42:33.857Z - info: CURRENT POSITION 0
2019-01-09T14:42:33.857Z - info: CoreStateMachine::syncState stateService play
2019-01-09T14:42:33.857Z - info: CoreStateMachine::syncState currentStatus play
2019-01-09T14:42:33.858Z - info: Received an update from plugin. extracting info from payload
2019-01-09T14:42:33.858Z - info: CoreStateMachine::pushState
2019-01-09T14:42:33.859Z - info: CoreStateMachine::getState
2019-01-09T14:42:33.859Z - info: CorePlayQueue::getTrack 0
2019-01-09T14:42:33.859Z - info: CoreCommandRouter::volumioPushState
2019-01-09T14:42:33.860Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2019-01-09T14:42:33.893Z - info: CoreStateMachine::pushState
2019-01-09T14:42:33.894Z - info: CoreStateMachine::getState
2019-01-09T14:42:33.894Z - info: CorePlayQueue::getTrack 0
2019-01-09T14:42:33.894Z - info: CoreCommandRouter::volumioPushState
2019-01-09T14:42:33.895Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2019-01-09T14:42:33.941Z - info: ------------------------------ 93ms
2019-01-09T14:42:38.347Z - info: CoreStateMachine::startPlaybackTimer
2019-01-09T14:42:38.347Z - info: CorePlayQueue::getTrack 1
2019-01-09T14:42:39.281Z - info:
---------------------------- MPD announces system playlist update
2019-01-09T14:42:39.282Z - info: Ignoring MPD Status Update
2019-01-09T14:42:39.282Z - info:
---------------------------- MPD announces state update: player
2019-01-09T14:42:39.283Z - info: ControllerMpd::getState
2019-01-09T14:42:39.283Z - info: ControllerMpd::sendMpdCommand status
2019-01-09T14:42:39.284Z - info: sending command...
2019-01-09T14:42:39.285Z - info: ------------------------------ 4ms
2019-01-09T14:42:39.286Z - info: parsing response...
2019-01-09T14:42:39.287Z - info: ControllerMpd::parseState
2019-01-09T14:42:39.288Z - info: ControllerMpd::sendMpdCommand playlistinfo
2019-01-09T14:42:39.288Z - info: sending command...
2019-01-09T14:42:39.289Z - info: parsing response...
2019-01-09T14:42:39.290Z - info: ControllerMpd::parseTrackInfo
2019-01-09T14:42:39.290Z - info: ControllerMpd::pushState
2019-01-09T14:42:39.290Z - info: CoreCommandRouter::servicePushState
2019-01-09T14:42:39.291Z - info: CoreStateMachine::syncState
2019-01-09T14:42:39.291Z - info: CorePlayQueue::getTrack 1
2019-01-09T14:42:39.292Z - info: STATE SERVICE {"status":"play","position":0,"seek":23,"duration":230,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,
"isStreaming":false,"title":"Philby","artist":"Rory Gallagher","album":"Top Priority","uri":"NAS/RPI1/Rock/000_NEWS_2018/2018-12-17-Rory Gallagher/Rory_Gallagher-Top_Priority/02-Philby.flac","trackType":"fl
ac"}
2019-01-09T14:42:39.292Z - info: CURRENT POSITION 1
2019-01-09T14:42:39.292Z - info: CoreStateMachine::syncState stateService play
2019-01-09T14:42:39.293Z - info: CoreStateMachine::syncState currentStatus play
2019-01-09T14:42:39.293Z - info: Received an update from plugin. extracting info from payload
2019-01-09T14:42:39.293Z - info: CoreStateMachine::pushState
2019-01-09T14:42:39.294Z - info: CoreStateMachine::getState
2019-01-09T14:42:39.294Z - info: CorePlayQueue::getTrack 1
2019-01-09T14:42:39.294Z - info: CoreCommandRouter::volumioPushState
2019-01-09T14:42:39.295Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2019-01-09T14:42:39.329Z - info: CoreStateMachine::pushState
2019-01-09T14:42:39.329Z - info: CoreStateMachine::getState
2019-01-09T14:42:39.330Z - info: CorePlayQueue::getTrack 1
2019-01-09T14:42:39.330Z - info: CoreCommandRouter::volumioPushState
2019-01-09T14:42:39.331Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2019-01-09T14:42:39.383Z - info: ------------------------------ 100ms
2019-01-09T14:46:24.224Z - info: CorePlayQueue::getTrack 1
2019-01-09T14:46:24.224Z - info: CorePlayQueue::getTrack 2
2019-01-09T14:46:24.225Z - info: Prefetching next song
2019-01-09T14:46:24.225Z - info: DOING PREFETCH IN MPD
2019-01-09T14:46:24.225Z - info: ControllerMpd::sendMpdCommand add "NAS/RPI1/Rock/000_NEWS_2018/2018-12-17-Rory Gallagher/Rory_Gallagher-Top_Priority/03-Wayward_Child.flac"
2019-01-09T14:46:24.226Z - info: sending command...
2019-01-09T14:46:24.228Z - info:
---------------------------- MPD announces system playlist update
2019-01-09T14:46:24.229Z - info: Ignoring MPD Status Update
2019-01-09T14:46:24.229Z - info: parsing response...
2019-01-09T14:46:24.231Z - info: ControllerMpd::sendMpdCommand consume 1
2019-01-09T14:46:24.232Z - info: sending command...
2019-01-09T14:46:24.234Z - info: ------------------------------ 6ms
2019-01-09T14:46:24.235Z - info: parsing response...
2019-01-09T14:46:28.734Z - info: CoreStateMachine::startPlaybackTimer
2019-01-09T14:46:28.735Z - info: CorePlayQueue::getTrack 2
2019-01-09T14:46:29.051Z - info:
---------------------------- MPD announces system playlist update
2019-01-09T14:46:29.052Z - info: Ignoring MPD Status Update
2019-01-09T14:46:29.052Z - info:
---------------------------- MPD announces state update: player
2019-01-09T14:46:29.054Z - info: ControllerMpd::getState
2019-01-09T14:46:29.054Z - info: ControllerMpd::sendMpdCommand status
2019-01-09T14:46:29.055Z - info: sending command...
2019-01-09T14:46:29.058Z - info: ------------------------------ 7ms
2019-01-09T14:46:29.059Z - info: parsing response...
2019-01-09T14:46:29.060Z - info: ControllerMpd::parseState
2019-01-09T14:46:29.061Z - info: ControllerMpd::sendMpdCommand playlistinfo
2019-01-09T14:46:29.061Z - info: sending command...
2019-01-09T14:46:29.066Z - info: parsing response...
2019-01-09T14:46:29.067Z - info: ControllerMpd::parseTrackInfo
2019-01-09T14:46:29.067Z - info: ControllerMpd::pushState
2019-01-09T14:46:29.068Z - info: CoreCommandRouter::servicePushState
2019-01-09T14:46:29.068Z - info: CoreStateMachine::syncState
2019-01-09T14:46:29.069Z - info: CorePlayQueue::getTrack 2
2019-01-09T14:46:29.069Z - info: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":210,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"
isStreaming":false,"title":"Wayward Child","artist":"Rory Gallagher","album":"Top Priority","uri":"NAS/RPI1/Rock/000_NEWS_2018/2018-12-17-Rory Gallagher/Rory_Gallagher-Top_Priority/03-Wayward_Child.flac","t
rackType":"flac"}
2019-01-09T14:46:29.070Z - info: CURRENT POSITION 2
2019-01-09T14:46:29.070Z - info: CoreStateMachine::syncState stateService play
2019-01-09T14:46:29.070Z - info: CoreStateMachine::syncState currentStatus play
2019-01-09T14:46:29.071Z - info: Received an update from plugin. extracting info from payload
2019-01-09T14:46:29.071Z - info: CoreStateMachine::pushState
2019-01-09T14:46:29.071Z - info: CoreStateMachine::getState
2019-01-09T14:46:29.071Z - info: CorePlayQueue::getTrack 2
2019-01-09T14:46:29.072Z - info: CoreCommandRouter::volumioPushState
2019-01-09T14:46:29.072Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2019-01-09T14:46:29.107Z - info: CoreStateMachine::pushState
2019-01-09T14:46:29.108Z - info: CoreStateMachine::getState
2019-01-09T14:46:29.109Z - info: CorePlayQueue::getTrack 2
2019-01-09T14:46:29.110Z - info: CoreCommandRouter::volumioPushState
2019-01-09T14:46:29.110Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2019-01-09T14:46:29.184Z - info: ------------------------------ 130ms
2019-01-09T14:49:54.042Z - info: CorePlayQueue::getTrack 2
2019-01-09T14:49:54.042Z - info: CorePlayQueue::getTrack 3
2019-01-09T14:49:54.043Z - info: Prefetching next song
2019-01-09T14:49:54.043Z - info: DOING PREFETCH IN MPD
2019-01-09T14:49:54.043Z - info: ControllerMpd::sendMpdCommand add "NAS/RPI1/Rock/000_NEWS_2018/2018-12-17-Rory Gallagher/Rory_Gallagher-Top_Priority/04-Keychain.flac"
2019-01-09T14:49:54.044Z - info: sending command...
2019-01-09T14:49:54.046Z - info:
---------------------------- MPD announces system playlist update
2019-01-09T14:49:54.046Z - info: Ignoring MPD Status Update
2019-01-09T14:49:54.047Z - info: parsing response...
2019-01-09T14:49:54.047Z - info: ControllerMpd::sendMpdCommand consume 1
2019-01-09T14:49:54.049Z - info: sending command...
2019-01-09T14:49:54.051Z - info: ------------------------------ 4ms
2019-01-09T14:49:54.051Z - info: parsing response...
2019-01-09T14:49:58.553Z - info: CoreStateMachine::startPlaybackTimer
2019-01-09T14:49:58.554Z - info: CorePlayQueue::getTrack 3
2019-01-09T14:49:58.693Z - info:
---------------------------- MPD announces system playlist update
2019-01-09T14:49:58.694Z - info: Ignoring MPD Status Update
2019-01-09T14:49:58.694Z - info:
---------------------------- MPD announces state update: player
2019-01-09T14:49:58.695Z - info: ControllerMpd::getState
2019-01-09T14:49:58.695Z - info: ControllerMpd::sendMpdCommand status
2019-01-09T14:49:58.696Z - info: sending command...
2019-01-09T14:49:58.699Z - info: ------------------------------ 5ms
2019-01-09T14:49:58.700Z - info: parsing response...
2019-01-09T14:49:58.700Z - info: ControllerMpd::parseState
2019-01-09T14:49:58.701Z - info: ControllerMpd::sendMpdCommand playlistinfo
2019-01-09T14:49:58.702Z - info: sending command...
2019-01-09T14:49:58.704Z - info: parsing response...
2019-01-09T14:49:58.705Z - info: ControllerMpd::parseTrackInfo
2019-01-09T14:49:58.705Z - info: ControllerMpd::pushState
2019-01-09T14:49:58.706Z - info: CoreCommandRouter::servicePushState
2019-01-09T14:49:58.706Z - info: CoreStateMachine::syncState
2019-01-09T14:49:58.707Z - info: CorePlayQueue::getTrack 3
2019-01-09T14:49:58.707Z - info: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":249,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"
isStreaming":false,"title":"Keychain","artist":"Rory Gallagher","album":"Top Priority","uri":"NAS/RPI1/Rock/000_NEWS_2018/2018-12-17-Rory Gallagher/Rory_Gallagher-Top_Priority/04-Keychain.flac","trackType":
"flac"}
2019-01-09T14:49:58.708Z - info: CURRENT POSITION 3
2019-01-09T14:49:58.708Z - info: CoreStateMachine::syncState stateService play
2019-01-09T14:49:58.709Z - info: CoreStateMachine::syncState currentStatus play
2019-01-09T14:49:58.709Z - info: Received an update from plugin. extracting info from payload
2019-01-09T14:49:58.709Z - info: CoreStateMachine::pushState
2019-01-09T14:49:58.710Z - info: CoreStateMachine::getState
2019-01-09T14:49:58.710Z - info: CorePlayQueue::getTrack 3
2019-01-09T14:49:58.710Z - info: CoreCommandRouter::volumioPushState
2019-01-09T14:49:58.710Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2019-01-09T14:49:58.747Z - info: CoreStateMachine::pushState
2019-01-09T14:49:58.748Z - info: CoreStateMachine::getState
2019-01-09T14:49:58.749Z - info: CorePlayQueue::getTrack 3
2019-01-09T14:49:58.750Z - info: CoreCommandRouter::volumioPushState
2019-01-09T14:49:58.751Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2019-01-09T14:49:58.805Z - info: ------------------------------ 109ms
2019-01-09T14:54:02.702Z - info: CorePlayQueue::getTrack 3
2019-01-09T14:54:02.704Z - info: CorePlayQueue::getTrack 4
2019-01-09T14:54:02.705Z - info: Prefetching next song
2019-01-09T14:54:02.706Z - info: DOING PREFETCH IN MPD
2019-01-09T14:54:02.708Z - info: ControllerMpd::sendMpdCommand add "NAS/RPI1/Rock/000_NEWS_2018/2018-12-17-Rory Gallagher/Rory_Gallagher-Top_Priority/05-At_The_Depot.flac"
2019-01-09T14:54:02.709Z - info: sending command...
2019-01-09T14:54:02.713Z - info:
---------------------------- MPD announces system playlist update
2019-01-09T14:54:02.714Z - info: Ignoring MPD Status Update
2019-01-09T14:54:02.716Z - info: parsing response...
2019-01-09T14:54:02.716Z - info: ControllerMpd::sendMpdCommand consume 1
2019-01-09T14:54:02.717Z - info: sending command...
2019-01-09T14:54:02.719Z - info: ------------------------------ 7ms
2019-01-09T14:54:02.719Z - info: parsing response...
2019-01-09T14:54:07.216Z - info: CoreStateMachine::startPlaybackTimer
2019-01-09T14:54:07.217Z - info: CorePlayQueue::getTrack 4
2019-01-09T14:54:07.964Z - info:
---------------------------- MPD announces system playlist update
2019-01-09T14:54:07.964Z - info: Ignoring MPD Status Update
2019-01-09T14:54:07.965Z - info:
---------------------------- MPD announces state update: player
2019-01-09T14:54:07.965Z - info: ControllerMpd::getState
2019-01-09T14:54:07.966Z - info: ControllerMpd::sendMpdCommand status
2019-01-09T14:54:07.966Z - info: sending command...
2019-01-09T14:54:07.968Z - info: ------------------------------ 5ms
2019-01-09T14:54:07.969Z - info: parsing response...
2019-01-09T14:54:07.970Z - info: ControllerMpd::parseState
2019-01-09T14:54:07.970Z - info: ControllerMpd::sendMpdCommand playlistinfo
2019-01-09T14:54:07.971Z - info: sending command...
2019-01-09T14:54:07.973Z - info: parsing response...
2019-01-09T14:54:07.974Z - info: ControllerMpd::parseTrackInfo
2019-01-09T14:54:07.974Z - info: ControllerMpd::pushState
2019-01-09T14:54:07.974Z - info: CoreCommandRouter::servicePushState
2019-01-09T14:54:07.975Z - info: CoreStateMachine::syncState
2019-01-09T14:54:07.975Z - info: CorePlayQueue::getTrack 4
2019-01-09T14:54:07.976Z - info: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":177,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"
isStreaming":false,"title":"At The Depot","artist":"Rory Gallagher","album":"Top Priority","uri":"NAS/RPI1/Rock/000_NEWS_2018/2018-12-17-Rory Gallagher/Rory_Gallagher-Top_Priority/05-At_The_Depot.flac","tra
ckType":"flac"}
2019-01-09T14:54:07.976Z - info: CURRENT POSITION 4
2019-01-09T14:54:07.976Z - info: CoreStateMachine::syncState stateService play
2019-01-09T14:54:07.977Z - info: CoreStateMachine::syncState currentStatus play
2019-01-09T14:54:07.977Z - info: Received an update from plugin. extracting info from payload
2019-01-09T14:54:07.978Z - info: CoreStateMachine::pushState
2019-01-09T14:54:07.978Z - info: CoreStateMachine::getState
2019-01-09T14:54:07.978Z - info: CorePlayQueue::getTrack 4
2019-01-09T14:54:07.978Z - info: CoreCommandRouter::volumioPushState
2019-01-09T14:54:07.979Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2019-01-09T14:54:08.018Z - info: CoreStateMachine::pushState
2019-01-09T14:54:08.020Z - info: CoreStateMachine::getState
2019-01-09T14:54:08.020Z - info: CorePlayQueue::getTrack 4
2019-01-09T14:54:08.021Z - info: CoreCommandRouter::volumioPushState
2019-01-09T14:54:08.021Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2019-01-09T14:54:08.070Z - info: ------------------------------ 106ms
2019-01-09T14:57:00.221Z - info: CorePlayQueue::getTrack 4
2019-01-09T14:57:00.226Z - info: CorePlayQueue::getTrack 5
2019-01-09T14:57:00.227Z - info: Prefetching next song
2019-01-09T14:57:00.227Z - info: DOING PREFETCH IN MPD
2019-01-09T14:57:00.228Z - info: ControllerMpd::sendMpdCommand add "NAS/RPI1/Rock/000_NEWS_2018/2018-12-17-Rory Gallagher/Rory_Gallagher-Top_Priority/06-Bad_Penny.flac"
2019-01-09T14:57:00.228Z - info: sending command...
2019-01-09T14:57:00.230Z - info:
---------------------------- MPD announces system playlist update
2019-01-09T14:57:00.231Z - info: Ignoring MPD Status Update
2019-01-09T14:57:00.231Z - info: parsing response...
2019-01-09T14:57:00.232Z - info: ControllerMpd::sendMpdCommand consume 1
2019-01-09T14:57:00.241Z - info: sending command...
2019-01-09T14:57:00.243Z - info: ------------------------------ 12ms
2019-01-09T14:57:00.243Z - info: parsing response...
2019-01-09T14:57:04.487Z - info: CoreStateMachine::startPlaybackTimer
2019-01-09T14:57:04.489Z - info: CorePlayQueue::getTrack 5
2019-01-09T14:57:04.603Z - info:
---------------------------- MPD announces system playlist update
2019-01-09T14:57:04.604Z - info: Ignoring MPD Status Update
2019-01-09T14:57:04.605Z - info:
---------------------------- MPD announces state update: player
2019-01-09T14:57:04.605Z - info: ControllerMpd::getState
2019-01-09T14:57:04.606Z - info: ControllerMpd::sendMpdCommand status
2019-01-09T14:57:04.606Z - info: sending command...
2019-01-09T14:57:04.613Z - info: ------------------------------ 9ms
2019-01-09T14:57:04.613Z - info: parsing response...
2019-01-09T14:57:04.614Z - info: ControllerMpd::parseState
2019-01-09T14:57:04.614Z - info: ControllerMpd::sendMpdCommand playlistinfo
2019-01-09T14:57:04.615Z - info: sending command...
2019-01-09T14:57:04.616Z - info: parsing response...
2019-01-09T14:57:04.617Z - info: ControllerMpd::parseTrackInfo
2019-01-09T14:57:04.618Z - info: ControllerMpd::pushState
2019-01-09T14:57:04.618Z - info: CoreCommandRouter::servicePushState
2019-01-09T14:57:04.618Z - info: CoreStateMachine::syncState
2019-01-09T14:57:04.619Z - info: CorePlayQueue::getTrack 5
2019-01-09T14:57:04.619Z - info: STATE SERVICE {"status":"play","position":0,"seek":23,"duration":241,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,
"isStreaming":false,"title":"Bad Penny","artist":"Rory Gallagher","album":"Top Priority","uri":"NAS/RPI1/Rock/000_NEWS_2018/2018-12-17-Rory Gallagher/Rory_Gallagher-Top_Priority/06-Bad_Penny.flac","trackTyp
e":"flac"}
2019-01-09T14:57:04.619Z - info: CURRENT POSITION 5
2019-01-09T14:57:04.620Z - info: CoreStateMachine::syncState stateService play
2019-01-09T14:57:04.620Z - info: CoreStateMachine::syncState currentStatus play
2019-01-09T14:57:04.620Z - info: Received an update from plugin. extracting info from payload
2019-01-09T14:57:04.620Z - info: CoreStateMachine::pushState
2019-01-09T14:57:04.621Z - info: CoreStateMachine::getState
2019-01-09T14:57:04.621Z - info: CorePlayQueue::getTrack 5
2019-01-09T14:57:04.621Z - info: CoreCommandRouter::volumioPushState
2019-01-09T14:57:04.622Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2019-01-09T14:57:04.662Z - info: CoreStateMachine::pushState
2019-01-09T14:57:04.663Z - info: CoreStateMachine::getState
2019-01-09T14:57:04.664Z - info: CorePlayQueue::getTrack 5
2019-01-09T14:57:04.665Z - info: CoreCommandRouter::volumioPushState
2019-01-09T14:57:04.665Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2019-01-09T14:57:04.715Z - info: ------------------------------ 109ms
2019-01-09T15:01:00.565Z - info: CorePlayQueue::getTrack 5
2019-01-09T15:01:00.566Z - info: CorePlayQueue::getTrack 6
2019-01-09T15:01:00.566Z - info: Prefetching next song
2019-01-09T15:01:00.566Z - info: DOING PREFETCH IN MPD
2019-01-09T15:01:00.567Z - info: ControllerMpd::sendMpdCommand add "NAS/RPI1/Rock/000_NEWS_2018/2018-12-17-Rory Gallagher/Rory_Gallagher-Top_Priority/07-Just_Hit_Town.flac"
2019-01-09T15:01:00.567Z - info: sending command...
2019-01-09T15:01:00.573Z - info:
---------------------------- MPD announces system playlist update
2019-01-09T15:01:00.573Z - info: Ignoring MPD Status Update
2019-01-09T15:01:00.576Z - info: parsing response...
2019-01-09T15:01:00.576Z - info: ControllerMpd::sendMpdCommand consume 1
2019-01-09T15:01:00.577Z - info: sending command...
2019-01-09T15:01:00.578Z - info: ------------------------------ 6ms
2019-01-09T15:01:00.578Z - info: parsing response...
2019-01-09T15:01:05.076Z - info: CoreStateMachine::startPlaybackTimer
2019-01-09T15:01:05.076Z - info: CorePlayQueue::getTrack 6
2019-01-09T15:01:05.874Z - info:
---------------------------- MPD announces system playlist update
2019-01-09T15:01:05.874Z - info: Ignoring MPD Status Update
2019-01-09T15:01:05.875Z - info:
---------------------------- MPD announces state update: player
2019-01-09T15:01:05.875Z - info: ControllerMpd::getState
2019-01-09T15:01:05.876Z - info: ControllerMpd::sendMpdCommand status
2019-01-09T15:01:05.876Z - info: sending command...
2019-01-09T15:01:05.881Z - info: ------------------------------ 8ms
2019-01-09T15:01:05.882Z - info: parsing response...
2019-01-09T15:01:05.883Z - info: ControllerMpd::parseState
2019-01-09T15:01:05.883Z - info: ControllerMpd::sendMpdCommand playlistinfo
2019-01-09T15:01:05.884Z - info: sending command...
2019-01-09T15:01:05.886Z - info: parsing response...
2019-01-09T15:01:05.887Z - info: ControllerMpd::parseTrackInfo
2019-01-09T15:01:05.887Z - info: ControllerMpd::pushState
2019-01-09T15:01:05.888Z - info: CoreCommandRouter::servicePushState
2019-01-09T15:01:05.888Z - info: CoreStateMachine::syncState
2019-01-09T15:01:05.888Z - info: CorePlayQueue::getTrack 6
2019-01-09T15:01:05.889Z - info: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":216,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"
isStreaming":false,"title":"Just Hit Town","artist":"Rory Gallagher","album":"Top Priority","uri":"NAS/RPI1/Rock/000_NEWS_2018/2018-12-17-Rory Gallagher/Rory_Gallagher-Top_Priority/07-Just_Hit_Town.flac","t
rackType":"flac"}
2019-01-09T15:01:05.889Z - info: CURRENT POSITION 6
2019-01-09T15:01:05.889Z - info: CoreStateMachine::syncState stateService play
2019-01-09T15:01:05.890Z - info: CoreStateMachine::syncState currentStatus play
2019-01-09T15:01:05.890Z - info: Received an update from plugin. extracting info from payload
2019-01-09T15:01:05.890Z - info: CoreStateMachine::pushState
2019-01-09T15:01:05.891Z - info: CoreStateMachine::getState
2019-01-09T15:01:05.891Z - info: CorePlayQueue::getTrack 6
2019-01-09T15:01:05.891Z - info: CoreCommandRouter::volumioPushState
2019-01-09T15:01:05.892Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2019-01-09T15:01:05.934Z - info: CoreStateMachine::pushState
2019-01-09T15:01:05.935Z - info: CoreStateMachine::getState
I’m thinking about disabling nmbd/smbd (no use of samba here), and ntp (does not work). Would it help?
EDIT: not completely sure yet, but it seems to help. I have made 4 successive reboots after suspending these services, and no blocking situation yet…
I see kswapd0 from time to time, but it does not remain. Looks better, maybe. Cross fingers!
I have also disabled timesyncd which does not work better than ntp on wifi…