[SOLVED] PINE 64 + Large library on NAS

Help and Support Help
1

I’m hoping someone can help me out here. Please bare with me as I am a total Volumio noob and pretty green when it comes to linux.
I bought some Pine 64 boards form Kickstarter for learning, and I love them. Been playing around with them for a bit and found Volumio. started to do some digging and found out that Volumio released a Pine 64 image. I was super pumped! Downloaded the image and in about 10 minutes it was running Volumio!

Step 1 - get Volumio running on Pine64 - DONE!
Step 2 - add my Qnap NAS with my all of my iTunes Music (12,057 files) setup on Volumio on my Pine 64.

Here is where the trouble begins.

After some troubles…mainly me being really dumb (kept putting in the Pine’s ip, not the NAS :unamused: ) I was able to get the NAS to mount with the following :

Volumio
Alias - TheHolocron
NAS IP - 10.0.0.100
Path - Multimedia/iTunes/iTunes Media/Music
File Share Type - cifs
Username - K2SO
pw - xxxxx
Option -

Qnap NAS
Created a new user K2SO and allowed access to multimedia RW

The mount works AWESOME…then it loads and gets to about 9000+ songs in the WebUI and then resets at 0.

I then ssh’d into the Pine and checked the mount in the /mnt/NAS/TheHolocron. All the artists were there, all of the songs were in the folders. I checked a bunch at random to see if the files were there.

I then decided to delete TheHolocron mount (all music) and try another one (test1) pointing to just one artist (Foo Fighters). Had a bunch of different albums and a few songs. Lets see if it will connect and play. It did / does.

I did some reading and even tried adding

max_playlist_length “65536”
max_command_list_size “4096”
max_output_buffer_size “4096”

into the /etc/mdp.conf file, but nothing changed when trying to mount the whole library again.

So here is where I am. I have a somewhat working Volumio client running on a Pine 64. If you have any suggestions please be patient with me as I’m not always 100% sure where things are located in the file structure in Volumio.

Here is the info for my boards, NAS etc.
Pine A64+ 1GB board hardwired ethernet, no bluetooth, no wifi, its just the board powered with a 5v 2.5A PS
Volumio is running on a 32GB SanDisk ultra HC class 10 micro SD card (verified) (it’s what I had…overkill I know)
Qnap NAS - T220 with file service of Microsoft Networking enabled, Apple Networking enabled and NFS v2/v3 service disabled.

Any help would be AWESOME! I really want to get this working with my whole library!

Thanks

  • Drew
2

Would you please reboot your device, and either:

(1) ssh in and run ‘sudo journalctl -f’. Scan your library and report errors in the journal’s output;

or

(2) scan your library until it fails, and then connect to the Volumio test player (//192.168.x.y/dev), fill in the ‘Send log’ field, including your username.

3

Thanks for the reply chsims1! Here is what i did. Before I did anything I powered on the Pine to see if the small one artist share would still mount & play. It did. booted up the Pine and there was all of my FF albums & music. No problems! I then made sure to remove everything in the queue, remove the test mount, rebooted the Pine and made sure it was a clean volumio with nothing loaded or added. OK, done. I then re-added my entire music library, checked that it was working and then rebooted the Pine once again. Once rebooted I ssh’d into it and ‘sudo journalctl -f’ then clicked on update. I’ve also truncated the file…it was a lot longer. I also have written down the following information just in case it’s needed. The webUI crashed around the 9500 file mark.

appears 713 times during update - Mar 16 14:XX:XX volumio mpd[567]: ffmpeg/mov,mp4,m4a,3gp,3g2,mj2: max_analyze_duration 5000000 reached
appears 136 times during update - Mar 16 14:XX:XX volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats

there are 8736 mp3 files
there are 2079 m4a files
there are 7 m4v files (music videos, iTunes keeps them with the albums)

if you need the entire file I’ve also got that saved but I didn’t see anything in the mass of the middle that looked like it was an error or anything.

Thanks for the help

  • Drew

OUTPUT from terminal

volumio@volumio:~$ sudo journalctl -f
– Logs begin at Thu 2017-03-16 14:33:26 UTC. –
Mar 16 14:34:27 volumio volumio[1045]: info: [1489674867268] InterfaceWebUI::pushState
Mar 16 14:34:27 volumio volumio[1045]: info: Pushing Favourites {“service”:“mpd”,“uri”:"",“favourite”:false}
Mar 16 14:34:28 volumio volumio[1045]: info: CoreCommandRouter::getUIConfigOnPlugin
Mar 16 14:34:28 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam
Mar 16 14:34:28 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam
Mar 16 14:34:29 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 16 14:34:29 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares
Mar 16 14:34:33 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 16 14:34:35 volumio sudo[1244]: volumio : TTY=pts/0 ; PWD=/home/volumio ; USER=root ; COMMAND=/bin/journalctl -f
Mar 16 14:34:35 volumio sudo[1244]: pam_unix(sudo:session): session opened for user root by volumio(uid=0)
Mar 16 14:34:37 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 16 14:34:41 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 16 14:34:41 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , updateDb
Mar 16 14:34:41 volumio volumio[1045]: info: [1489674881587] ControllerMpd::sendMpdCommand update
Mar 16 14:34:41 volumio volumio[1045]: info: [1489674881589] sending command…
Mar 16 14:34:41 volumio volumio[1045]: info: [1489674881602] ControllerMpd::sendMpdCommand status
Mar 16 14:34:41 volumio volumio[1045]: info: Mpd Status Update: update
Mar 16 14:34:41 volumio volumio[1045]: info:
Mar 16 14:34:41 volumio volumio[1045]: [1489674881607] ---------------------------- MPD announces state update
Mar 16 14:34:41 volumio volumio[1045]: info: [1489674881615] parsing response…
Mar 16 14:34:41 volumio volumio[1045]: info: [1489674881618] sending command…
Mar 16 14:34:41 volumio volumio[1045]: info: [1489674881620] ControllerMpd::getState
Mar 16 14:34:41 volumio volumio[1045]: info: [1489674881626] ControllerMpd::sendMpdCommand status
Mar 16 14:34:41 volumio volumio[1045]: info: [1489674881627] sending command…
Mar 16 14:34:41 volumio volumio[1045]: info: [1489674881652] parsing response…
Mar 16 14:34:41 volumio volumio[1045]: info: [1489674881653] parsing response…
Mar 16 14:34:41 volumio volumio[1045]: info: [1489674881657] ControllerMpd::parseState
Mar 16 14:34:41 volumio volumio[1045]: info: Command Router : Notfying DB Updatetrue
Mar 16 14:34:41 volumio volumio[1045]: info: [1489674881698] ControllerMpd::parseState
Mar 16 14:34:41 volumio volumio[1045]: info: [1489674881700] ControllerMpd::pushState
Mar 16 14:34:41 volumio volumio[1045]: info: CoreCommandRouter::servicePushState
Mar 16 14:34:41 volumio volumio[1045]: info: [1489674881708] CoreStateMachine::syncState
Mar 16 14:34:41 volumio volumio[1045]: info: [1489674881709] CorePlayQueue::getTrack 0
Mar 16 14:34:41 volumio volumio[1045]: info: STATE SERVICE {“status”:“stop”,“position”:null,“seek”:null,“duration”:null,“samplerate”:null,“bitdepth”:null,“channels”:null,“random”:false,“updatedb”:true,“repeat”:false,“isStreaming”:false,“title”:null,“artist”:null,“album”:null,“uri”:null}
Mar 16 14:34:41 volumio volumio[1045]: info: CURRENT POSITION 0
Mar 16 14:34:41 volumio volumio[1045]: info: [1489674881713] CoreStateMachine::syncState stateService stop
Mar 16 14:34:41 volumio volumio[1045]: info: [1489674881715] CoreStateMachine::syncState currentStatus stop
Mar 16 14:34:41 volumio volumio[1045]: info: [1489674881717] CoreStateMachine::pushState
Mar 16 14:34:41 volumio volumio[1045]: info: [1489674881725] CoreStateMachine::getState
Mar 16 14:34:41 volumio volumio[1045]: info: [1489674881727] CorePlayQueue::getTrack 0
Mar 16 14:34:41 volumio volumio[1045]: info: CoreCommandRouter::volumioPushState
Mar 16 14:34:41 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 16 14:34:41 volumio volumio[1045]: info: [1489674881731] interfaceApi::pushState
Mar 16 14:34:41 volumio volumio[1045]: info: [1489674881733] InterfaceWebUI::pushState
Mar 16 14:34:41 volumio volumio[1045]: info: [1489674881749] No code
Mar 16 14:34:41 volumio volumio[1045]: info: [1489674881752] CoreStateMachine::pushState
Mar 16 14:34:41 volumio volumio[1045]: info: [1489674881753] CoreStateMachine::getState
Mar 16 14:34:41 volumio volumio[1045]: info: [1489674881754] CorePlayQueue::getTrack 0
Mar 16 14:34:41 volumio volumio[1045]: info: CoreCommandRouter::volumioPushState
Mar 16 14:34:41 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 16 14:34:41 volumio volumio[1045]: info: [1489674881758] interfaceApi::pushState
Mar 16 14:34:41 volumio volumio[1045]: info: [1489674881759] InterfaceWebUI::pushState
Mar 16 14:34:41 volumio volumio[1045]: info: [1489674881776] ------------------------------ 171ms
Mar 16 14:34:41 volumio volumio[1045]: info: Pushing Favourites {“service”:“mpd”,“uri”:"",“favourite”:false}
Mar 16 14:34:41 volumio volumio[1045]: info: Pushing Favourites {“service”:“mpd”,“uri”:"",“favourite”:false}
Mar 16 14:34:42 volumio mpd[567]: update: added NAS/TheHolocron/A Perfect Circle/Mer De Noms/11 Breña.mp3
.
.
.
.
Mar 16 14:43:17 volumio mpd[567]: update: added NAS/TheHolocron/Jewel/Pieces Of You/14 Amen.m4a
Mar 16 14:43:17 volumio kernel: Unhandled fault: alignment fault (0x92000021) at 0x00000000eee4a9da
Mar 16 14:43:17 volumio systemd[1]: mpd.service: main process exited, code=killed, status=7/BUS
Mar 16 14:43:17 volumio systemd[1]: Unit mpd.service entered failed state.
Mar 16 14:43:18 volumio systemd[1]: mpd.service holdoff time over, scheduling restart.
Mar 16 14:43:18 volumio systemd[1]: Stopping Music Player Daemon…
Mar 16 14:43:18 volumio systemd[1]: Starting Music Player Daemon…
Mar 16 14:43:18 volumio systemd[1]: Started Music Player Daemon.
Mar 16 14:43:19 volumio mpd[1289]: zeroconf: No global port, disabling zeroconf
Mar 16 14:43:21 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 16 14:43:21 volumio volumio[1045]: error: MPD error: Error: This socket has been ended by the other party
Mar 16 14:43:21 volumio volumio[1045]: error: MPD error: Error: This socket has been ended by the other party
Mar 16 14:43:21 volumio volumio[1045]: error: MPD error: Error: This socket has been ended by the other party
Mar 16 14:43:25 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 16 14:43:25 volumio volumio[1045]: error: MPD error: Error: This socket has been ended by the other party
Mar 16 14:43:25 volumio volumio[1045]: error: MPD error: Error: This socket has been ended by the other party
Mar 16 14:43:25 volumio volumio[1045]: error: MPD error: Error: This socket has been ended by the other party
Mar 16 14:43:29 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 16 14:43:29 volumio volumio[1045]: assert.js:85
Mar 16 14:43:29 volumio volumio[1045]: throw new assert.AssertionError({
Mar 16 14:43:29 volumio volumio[1045]: ^
Mar 16 14:43:29 volumio volumio[1045]: AssertionError: false == true
Mar 16 14:43:29 volumio volumio[1045]: at MpdClient.sendCommand (/volumio/node_modules/mpd/index.js:86:10)
Mar 16 14:43:29 volumio volumio[1045]: at ControllerMpd.getMyCollectionStats (/volumio/app/plugins/music_service/mpd/index.js:2317:20)
Mar 16 14:43:29 volumio volumio[1045]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:954:29)
Mar 16 14:43:29 volumio volumio[1045]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1132:43)
Mar 16 14:43:29 volumio volumio[1045]: at emitTwo (events.js:106:13)
Mar 16 14:43:29 volumio volumio[1045]: at Socket.emit (events.js:191:7)
Mar 16 14:43:29 volumio volumio[1045]: at Socket.onevent (/volumio/node_modules/socket.io/lib/socket.js:348:8)
Mar 16 14:43:29 volumio volumio[1045]: at Socket.onpacket (/volumio/node_modules/socket.io/lib/socket.js:308:12)
Mar 16 14:43:29 volumio volumio[1045]: at /volumio/node_modules/socket.io/lib/client.js:195:16
Mar 16 14:43:29 volumio volumio[1045]: at _combinedTickCallback (internal/process/next_tick.js:67:7)
Mar 16 14:43:29 volumio volumio[1045]: at process._tickCallback (internal/process/next_tick.js:98:9)
Mar 16 14:43:29 volumio systemd[1]: volumio.service: main process exited, code=exited, status=1/FAILURE
Mar 16 14:43:29 volumio systemd[1]: Unit volumio.service entered failed state.
Mar 16 14:43:29 volumio systemd[1]: Starting dynamicswap.service…
Mar 16 14:43:29 volumio systemd[1]: Started dynamicswap.service.
Mar 16 14:43:29 volumio systemd[1]: volumio.service holdoff time over, scheduling restart.
Mar 16 14:43:29 volumio systemd[1]: Starting dynamicswap.service…
Mar 16 14:43:29 volumio systemd[1]: Started dynamicswap.service.
Mar 16 14:43:29 volumio systemd[1]: Stopping Volumio Backend Module…
Mar 16 14:43:29 volumio systemd[1]: Starting Volumio Backend Module…
Mar 16 14:43:29 volumio systemd[1]: Started Volumio Backend Module.
Mar 16 14:43:31 volumio mpd[1289]: client: [0] opened from 127.0.0.1:45706
Mar 16 14:43:31 volumio mpd[1289]: client: [1] opened from 127.0.0.1:45707
Mar 16 14:43:31 volumio mpd[1289]: client: [0] closed
Mar 16 14:43:31 volumio mpd[1289]: client: [2] opened from 127.0.0.1:45708
Mar 16 14:43:31 volumio mpd[1289]: client: [1] closed
Mar 16 14:43:31 volumio mpd[1289]: client: [2] closed
Mar 16 14:43:32 volumio volumio[1309]: info: -------------------------------------------
Mar 16 14:43:32 volumio volumio[1309]: info: ----- Volumio2 ----
Mar 16 14:43:32 volumio volumio[1309]: info: -------------------------------------------
Mar 16 14:43:32 volumio volumio[1309]: info: ----- System startup ----
Mar 16 14:43:32 volumio volumio[1309]: info: -------------------------------------------
Mar 16 14:43:32 volumio volumio[1309]: info: Plugin folders cleanup
Mar 16 14:43:32 volumio volumio[1309]: info: Scanning into folder /volumio/app/plugins/
Mar 16 14:43:32 volumio volumio[1309]: info: Scanning category audio_interface
Mar 16 14:43:32 volumio volumio[1309]: info: Scanning category miscellanea
Mar 16 14:43:32 volumio volumio[1309]: info: Scanning category music_service
Mar 16 14:43:32 volumio volumio[1309]: info: Scanning category plugins.json
Mar 16 14:43:32 volumio volumio[1309]: info: Scanning category system_controller
Mar 16 14:43:32 volumio volumio[1309]: info: Scanning category user_interface
Mar 16 14:43:32 volumio volumio[1309]: info: Scanning into folder /data/plugins/
Mar 16 14:43:32 volumio volumio[1309]: info: Plugin folders cleanup completed
Mar 16 14:43:32 volumio volumio[1309]: info: Loading plugins from folder /volumio/app/plugins/
Mar 16 14:43:32 volumio volumio[1309]: info: Loading plugins from folder /data/plugins/
Mar 16 14:43:32 volumio volumio[1309]: info: Loading plugin “system”…
Mar 16 14:43:32 volumio volumio[1309]: info: Loading plugin “appearance”…
Mar 16 14:43:33 volumio volumio[1309]: info: Loading plugin “network”…
Mar 16 14:43:33 volumio volumio[1309]: info: Loading plugin “services”…
Mar 16 14:43:33 volumio volumio[1309]: info: Loading plugin “alsa_controller”…
Mar 16 14:43:33 volumio volumio[1309]: info: Loading plugin “volumio_command_line_client”…
Mar 16 14:43:33 volumio volumio[1309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 16 14:43:33 volumio volumio[1309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 16 14:43:33 volumio volumio[1309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 16 14:43:33 volumio volumio[1309]: info: Loading plugin “upnp”…
Mar 16 14:43:33 volumio volumio[1309]: info: [1489675413430] Starting Upmpd Daemon
Mar 16 14:43:33 volumio volumio[1309]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Mar 16 14:43:33 volumio volumio[1309]: info: Loading plugin “mpd”…
Mar 16 14:43:33 volumio volumio[1309]: info: Loading plugin “networkfs”…
Mar 16 14:43:33 volumio volumio[1309]: Something is already mounted on /mnt/NAS/TheHolocron
Mar 16 14:43:33 volumio volumio[1309]: info: Cannot mount NAS TheHolocron at system boot, trial number 1 ,retrying in 5 seconds
Mar 16 14:43:33 volumio volumio[1309]: info: Loading plugin “alarm-clock”…
Mar 16 14:43:33 volumio volumio[1309]: info: Loading plugin “airplay_emulation”…
Mar 16 14:43:33 volumio volumio[1309]: info: [1489675413738] Starting Shairport Sync
Mar 16 14:43:33 volumio volumio[1309]: info: Loading plugin “last_100”…
Mar 16 14:43:33 volumio volumio[1309]: info: Loading plugin “webradio”…
Mar 16 14:43:34 volumio volumio[1309]: info: Loading plugin “i2s_dacs”…
Mar 16 14:43:34 volumio volumio[1309]: info: I2S DAC not set, start Auto-detection
Mar 16 14:43:34 volumio volumio[1309]: info: Loading plugin “my_volumio”…
Mar 16 14:43:34 volumio volumio[1309]: info: Loading plugin “volumiodiscovery”…
Mar 16 14:43:34 volumio volumio[1309]: *** WARNING *** The program ‘node’ uses the Apple Bonjour compatibility layer of Avahi.
Mar 16 14:43:34 volumio node[1309]: *** WARNING *** The program ‘node’ uses the Apple Bonjour compatibility layer of Avahi.
Mar 16 14:43:34 volumio node[1309]: *** WARNING *** Please fix your application to use the native API of Avahi!
Mar 16 14:43:34 volumio node[1309]: *** WARNING *** For more information see http://0pointer.de/avahi-compat?s=libdns_sd&e=node
Mar 16 14:43:34 volumio node[1309]: *** WARNING *** The program ‘node’ called ‘DNSServiceRegister()’ which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Mar 16 14:43:34 volumio node[1309]: *** WARNING *** Please fix your application to use the native API of Avahi!
Mar 16 14:43:34 volumio node[1309]: *** WARNING *** For more information see http://0pointer.de/avahi-compat?s=libdns_sd&e=node&f=DNSServiceRegister
Mar 16 14:43:34 volumio volumio[1309]: *** WARNING *** Please fix your application to use the native API of Avahi!
Mar 16 14:43:34 volumio volumio[1309]: *** WARNING *** For more information see http://0pointer.de/avahi-compat?s=libdns_sd&e=node
Mar 16 14:43:34 volumio volumio[1309]: *** WARNING *** The program ‘node’ called ‘DNSServiceRegister()’ which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Mar 16 14:43:34 volumio volumio[1309]: *** WARNING *** Please fix your application to use the native API of Avahi!
Mar 16 14:43:34 volumio volumio[1309]: *** WARNING *** For more information see http://0pointer.de/avahi-compat?s=libdns_sd&e=node&f=DNSServiceRegister
Mar 16 14:43:34 volumio volumio[1309]: info: Applying required configuration parameters for plugin volumiodiscovery
Mar 16 14:43:34 volumio volumio[1309]: Discovery: StartAdv! undefined
Mar 16 14:43:34 volumio volumio[1309]: Discovery: Started advertising… Volumio - undefined
Mar 16 14:43:35 volumio volumio[1309]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Mar 16 14:43:35 volumio volumio[1309]: info: Loading plugin “albumart”…
Mar 16 14:43:35 volumio volumio[1309]: info: Plugin example_plugin is not enabled
Mar 16 14:43:35 volumio volumio[1309]: info: Loading plugin “updater_comm”…
Mar 16 14:43:35 volumio volumio[1309]: info: Plugin mpdemulation is not enabled
Mar 16 14:43:35 volumio volumio[1309]: info: Loading plugin “rest_api”…
Mar 16 14:43:35 volumio volumio[1309]: info: Loading plugin “websocket”…
Mar 16 14:43:35 volumio volumio[1309]: info: ___________ START PLUGINS ___________
Mar 16 14:43:35 volumio volumio[1309]: PLUGIN START: appearance
Mar 16 14:43:35 volumio volumio[1309]: PLUGIN START: last_100
Mar 16 14:43:35 volumio volumio[1309]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Mar 16 14:43:35 volumio volumio[1309]: info: [1489675415293] CoreMusicLibrary::Adding element Last_100
Mar 16 14:43:35 volumio volumio[1309]: PLUGIN START: webradio
Mar 16 14:43:35 volumio volumio[1309]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Mar 16 14:43:35 volumio volumio[1309]: info: [1489675415307] CoreMusicLibrary::Adding element Webradio
Mar 16 14:43:35 volumio volumio[1309]: PLUGIN START: my_volumio
Mar 16 14:43:35 volumio volumio[1309]: info: Loading i18n strings for locale en
Mar 16 14:43:35 volumio volumio[1309]: Updating browse sources language
Mar 16 14:43:35 volumio volumio[1309]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Mar 16 14:43:35 volumio volumio[1309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 16 14:43:35 volumio volumio[1309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAlsaCards
Mar 16 14:43:35 volumio volumio[1309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 16 14:43:35 volumio volumio[1309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 16 14:43:35 volumio volumio[1309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 16 14:43:35 volumio volumio[1309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 16 14:43:35 volumio volumio[1309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 16 14:43:35 volumio volumio[1309]: info: BOOT COMPLETED
Mar 16 14:43:35 volumio volumio[1309]: Express server listening on port 3000
Mar 16 14:43:35 volumio volumio[1309]: Volumio Calling Home
Mar 16 14:43:35 volumio volumio[1309]: info: [1489675415435] CoreStateMachine::resetVolumioState
Mar 16 14:43:35 volumio volumio[1309]: info: [1489675415437] CoreStateMachine::getcurrentVolume
Mar 16 14:43:35 volumio volumio[1309]: info: CoreCommandRouter::volumioRetrievevolume
Mar 16 14:43:35 volumio volumio[1309]: info: [1489675415458] CoreStateMachine::updateTrackBlock
Mar 16 14:43:35 volumio volumio[1309]: info: [1489675415460] CorePlayQueue::getTrackBlock
Mar 16 14:43:35 volumio volumio[1309]: info: MPD running with PID1289 ,establishing connection
Mar 16 14:43:35 volumio volumio[1309]: info: Setting Device type: Pine64
Mar 16 14:43:35 volumio mpd[1289]: client: [3] opened from 127.0.0.1:45710
Mar 16 14:43:35 volumio sudo[1382]: pam_unix(sudo:auth): conversation failed
Mar 16 14:43:35 volumio sudo[1382]: pam_unix(sudo:auth): auth could not identify password for [volumio]
Mar 16 14:43:35 volumio volumio[1309]: info: Cannot read I2C interface or I2C interface not presentError: Command failed: /usr/bin/sudo /usr/sbin/i2cdetect -y 1
Mar 16 14:43:35 volumio volumio[1309]: sudo: no tty present and no askpass program specified
Mar 16 14:43:35 volumio volumio[1309]: info: Reloading queue from file
Mar 16 14:43:36 volumio volumio[1309]: info: [1489675416062] VolumeController:: Volume=undefined Mute =undefined
Mar 16 14:43:36 volumio volumio[1309]: info: [1489675416069] CoreStateMachine::pushState
Mar 16 14:43:36 volumio volumio[1309]: info: [1489675416077] CoreStateMachine::getState
Mar 16 14:43:36 volumio volumio[1309]: info: [1489675416082] CorePlayQueue::getTrack 0
Mar 16 14:43:36 volumio volumio[1309]: info: CoreCommandRouter::volumioPushState
Mar 16 14:43:36 volumio volumio[1309]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 16 14:43:36 volumio volumio[1309]: info: [1489675416098] interfaceApi::pushState
Mar 16 14:43:36 volumio volumio[1309]: info: [1489675416102] InterfaceWebUI::pushState
Mar 16 14:43:36 volumio volumio[1309]: info: Pushing Favourites {“service”:“mpd”,“uri”:"",“favourite”:false}
Mar 16 14:43:36 volumio volumio[1309]: info:
Mar 16 14:43:36 volumio sudo[1387]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Mar 16 14:43:36 volumio sudo[1387]: pam_unix(sudo:session): session opened for user root by (uid=0)
Mar 16 14:43:36 volumio systemd[1]: Starting UPnP Renderer front-end to MPD…
Mar 16 14:43:36 volumio systemd[1]: Started UPnP Renderer front-end to MPD.
Mar 16 14:43:36 volumio sudo[1387]: pam_unix(sudo:session): session closed for user root
Mar 16 14:43:36 volumio volumio[1309]: Discovery: adding 2dbe9171-a769-4a61-8111-b7d441a13ef5
Mar 16 14:43:36 volumio volumio[1309]: info: mDNS: Found device Volumio
Mar 16 14:43:36 volumio volumio[1309]: info: Upmpdcli Daemon Started
Mar 16 14:43:36 volumio sudo[1389]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart airplay
Mar 16 14:43:36 volumio sudo[1389]: pam_unix(sudo:session): session opened for user root by (uid=0)
Mar 16 14:43:36 volumio systemd[1]: Stopping ShairportSync AirTunes receiver…
Mar 16 14:43:36 volumio shairport-sync[1193]: exit…
Mar 16 14:43:36 volumio systemd[1]: Starting ShairportSync AirTunes receiver…
Mar 16 14:43:36 volumio systemd[1]: Started ShairportSync AirTunes receiver.
Mar 16 14:43:36 volumio sudo[1389]: pam_unix(sudo:session): session closed for user root
Mar 16 14:43:36 volumio volumio[1309]: info: [1489675416479] Shairport-Sync Started
Mar 16 14:43:36 volumio mpd[1289]: client: [4] opened from 127.0.0.1:45711
Mar 16 14:43:36 volumio mpd[1289]: alsa_mixer: Failed to read mixer for ‘alsa’: no such mixer control: PCM
Mar 16 14:43:36 volumio shairport-sync[1395]: startup
Mar 16 14:43:36 volumio volumio[1390]: pure virtual method called
Mar 16 14:43:36 volumio volumio[1390]: terminate called without an active exception
Mar 16 14:43:36 volumio systemd[1]: upmpdcli.service: main process exited, code=killed, status=6/ABRT
Mar 16 14:43:36 volumio systemd[1]: Unit upmpdcli.service entered failed state.
Mar 16 14:43:36 volumio mpd[1289]: client: [4] closed
Mar 16 14:43:36 volumio volumio[1309]: success!
Mar 16 14:43:38 volumio volumio[1309]: info: CoreCommandRouter::volumioGetState
Mar 16 14:43:38 volumio volumio[1309]: info: [1489675418016] CoreStateMachine::getState
Mar 16 14:43:38 volumio volumio[1309]: info: [1489675418019] CorePlayQueue::getTrack 0
Mar 16 14:43:38 volumio volumio[1309]: info:
Mar 16 14:43:38 volumio volumio[1309]: [1489675418022] ---------------------------- Client requests Volumio state
Mar 16 14:43:38 volumio volumio[1309]: info: [1489675418026] InterfaceWebUI::pushState
Mar 16 14:43:38 volumio volumio[1309]: info: [1489675418054] ------------------------------ 42ms
Mar 16 14:43:38 volumio volumio[1309]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Mar 16 14:43:38 volumio volumio[1309]: Plugin multiroom or method getMultiroom not found
Mar 16 14:43:38 volumio volumio[1309]: info:
Mar 16 14:43:38 volumio volumio[1309]: [1489675418107] ---------------------------- Client requests Menu Items
Mar 16 14:43:38 volumio volumio[1309]: info: [1489675418112] Listing playlists
Mar 16 14:43:38 volumio volumio[1309]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
Mar 16 14:43:38 volumio volumio[1309]: info: [1489675418176] ------------------------------ 69ms
Mar 16 14:43:38 volumio volumio[1309]: info: CoreCommandRouter::volumioGetState
Mar 16 14:43:38 volumio volumio[1309]: info: [1489675418457] CoreStateMachine::getState
Mar 16 14:43:38 volumio volumio[1309]: info: [1489675418457] CorePlayQueue::getTrack 0
Mar 16 14:43:38 volumio volumio[1309]: info:
Mar 16 14:43:38 volumio volumio[1309]: [1489675418458] ---------------------------- Client requests Volumio state
Mar 16 14:43:38 volumio volumio[1309]: info: [1489675418460] InterfaceWebUI::pushState
Mar 16 14:43:38 volumio volumio[1309]: info: [1489675418478] ------------------------------ 22ms
Mar 16 14:43:38 volumio volumio[1309]: Something is already mounted on /mnt/NAS/TheHolocron
Mar 16 14:43:38 volumio volumio[1309]: info: Cannot mount NAS TheHolocron at system boot, trial number 2 ,retrying in 5 seconds
Mar 16 14:43:39 volumio volumio[1309]: info:
Mar 16 14:43:39 volumio volumio[1309]: [1489675419287] ---------------------------- Client requests Volume 0
Mar 16 14:43:39 volumio volumio[1309]: info: [1489675419293] VolumeController::SetAlsaVolume0
Mar 16 14:43:39 volumio volumio[1309]: info: [1489675419310] ------------------------------ 23ms
Mar 16 14:43:39 volumio volumio[1309]: info: [1489675419322] VolumeController::Volume 0
Mar 16 14:43:39 volumio volumio[1309]: info: [1489675419326] CoreStateMachine::pushState
Mar 16 14:43:39 volumio volumio[1309]: info: [1489675419327] CoreStateMachine::getState
Mar 16 14:43:39 volumio volumio[1309]: info: [1489675419327] CorePlayQueue::getTrack 0
Mar 16 14:43:39 volumio volumio[1309]: info: CoreCommandRouter::volumioPushState
Mar 16 14:43:39 volumio volumio[1309]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 16 14:43:39 volumio volumio[1309]: info: [1489675419333] interfaceApi::pushState
Mar 16 14:43:39 volumio volumio[1309]: info: [1489675419335] InterfaceWebUI::pushState
Mar 16 14:43:39 volumio volumio[1309]: info: Pushing Favourites {“service”:“mpd”,“uri”:"",“favourite”:false}
Mar 16 14:43:41 volumio volumio[1309]: info: Volumio called home
Mar 16 14:43:43 volumio volumio[1309]: Something is already mounted on /mnt/NAS/TheHolocron
Mar 16 14:43:43 volumio volumio[1309]: info: Cannot mount NAS TheHolocron at system boot, trial number 3 ,retrying in 5 seconds
Mar 16 14:43:48 volumio volumio[1309]: Something is already mounted on /mnt/NAS/TheHolocron
Mar 16 14:43:48 volumio volumio[1309]: info: Cannot mount NAS TheHolocron at system boot, trial number 4 ,retrying in 5 seconds
Mar 16 14:43:53 volumio volumio[1309]: Something is already mounted on /mnt/NAS/TheHolocron
Mar 16 14:43:53 volumio volumio[1309]: info: Cannot mount NAS at system boot, trial number 4 ,stopping

END OUTPUT

4

I can’t see anything of interest in the part of the journal that you posted. The ffmpeg message seems to be complaining about m4a files … do you have a lot of them (more than 713)?

Can you try disabling ffmpeg and scanning again … add the following to the end of /etc/mpd.conf

decoder { plugin “ffmpeg” enabled “no” }

Edit: just looked at the terminal output again:

This has been reported for some other platforms, and is being investigated. It would still be interesting to see the result of disabling ffmpeg in mpd.

5

Thanks, I’ll take a look at it this weekend!

6

Well I don’t what to think now. So I added the lines to remove the m4a files, removed the share, rebooted, added the share again with a different name, rebooted again then ran sudo jouralctl -f (results below). But here is the strange thing. I did get an error, but after the error I rebooted and found that there are 14 artists that have seemed to “stick” in the webui of volumio. Normally they would have just gone back to 0. The total tracks is only 336 and they are in alphabetical order but some are skipped over. Example: I have 18 artists that start with A (on my NAS) and volumio shows me 5. Some are m4a and some are mp3. I’m going to try and mount an external HDD to see if it’s maybe a networking issue. I’d still like to see if we can get the NAS to work properly.

thanks

  • Drew

Occurs 14 times
Mar 22 03:33:43 volumio volumio[1063]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats

Did not appear (clearly because we removed them)
volumio mpd[567]: ffmpeg/mov,mp4,m4a,3gp,3g2,mj2: max_analyze_duration 5000000 reached

Here’s the mass output again (truncated)

volumio@volumio:~$ sudo journalctl -f
– Logs begin at Wed 2017-03-22 03:32:54 UTC. –
Mar 22 03:33:38 volumio volumio[1063]: info: [1490153618486] CoreStateMachine::pushState
Mar 22 03:33:38 volumio volumio[1063]: info: [1490153618490] CoreStateMachine::getState
Mar 22 03:33:38 volumio volumio[1063]: info: [1490153618490] CorePlayQueue::getTrack 0
Mar 22 03:33:38 volumio volumio[1063]: info: CoreCommandRouter::volumioPushState
Mar 22 03:33:38 volumio volumio[1063]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 22 03:33:38 volumio volumio[1063]: info: [1490153618495] interfaceApi::pushState
Mar 22 03:33:38 volumio volumio[1063]: info: [1490153618496] InterfaceWebUI::pushState
Mar 22 03:33:38 volumio volumio[1063]: info: Pushing Favourites {“service”:“mpd”,“uri”:"",“favourite”:false}
Mar 22 03:33:38 volumio sudo[1238]: volumio : TTY=pts/0 ; PWD=/home/volumio ; USER=root ; COMMAND=/bin/journalctl -f
Mar 22 03:33:38 volumio sudo[1238]: pam_unix(sudo:session): session opened for user root by volumio(uid=0)
Mar 22 03:33:38 volumio volumio[1063]: info: CoreCommandRouter::volumioGetState
Mar 22 03:33:38 volumio volumio[1063]: info: [1490153618856] CoreStateMachine::getState
Mar 22 03:33:38 volumio volumio[1063]: info: [1490153618858] CorePlayQueue::getTrack 0
Mar 22 03:33:38 volumio volumio[1063]: info:
Mar 22 03:33:38 volumio volumio[1063]: [1490153618860] ---------------------------- Client requests Volumio state
Mar 22 03:33:38 volumio volumio[1063]: info: [1490153618862] InterfaceWebUI::pushState
Mar 22 03:33:38 volumio volumio[1063]: info: [1490153618877] ------------------------------ 24ms
Mar 22 03:33:43 volumio volumio[1063]: info: CoreCommandRouter::getUIConfigOnPlugin
Mar 22 03:33:43 volumio volumio[1063]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam
Mar 22 03:33:43 volumio volumio[1063]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam
Mar 22 03:33:43 volumio volumio[1063]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 22 03:33:43 volumio volumio[1063]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares
Mar 22 03:33:46 volumio volumio[1063]: info: CoreCommandRouter::executeOnPlugin: mpd , updateDb
Mar 22 03:33:46 volumio volumio[1063]: info: [1490153626092] ControllerMpd::sendMpdCommand update
Mar 22 03:33:46 volumio volumio[1063]: info: [1490153626094] sending command…
Mar 22 03:33:46 volumio volumio[1063]: info: [1490153626098] ControllerMpd::sendMpdCommand status
Mar 22 03:33:46 volumio volumio[1063]: info: Mpd Status Update: update
Mar 22 03:33:46 volumio volumio[1063]: info:
Mar 22 03:33:46 volumio volumio[1063]: [1490153626108] ---------------------------- MPD announces state update
Mar 22 03:33:46 volumio volumio[1063]: info: [1490153626113] parsing response…
Mar 22 03:33:46 volumio volumio[1063]: info: [1490153626117] sending command…
Mar 22 03:33:46 volumio volumio[1063]: info: [1490153626122] ControllerMpd::getState
Mar 22 03:33:46 volumio volumio[1063]: info: [1490153626123] ControllerMpd::sendMpdCommand status
Mar 22 03:33:46 volumio volumio[1063]: info: [1490153626127] sending command…
Mar 22 03:33:46 volumio volumio[1063]: info: [1490153626150] parsing response…
Mar 22 03:33:46 volumio volumio[1063]: info: [1490153626153] parsing response…
Mar 22 03:33:46 volumio volumio[1063]: info: [1490153626156] ControllerMpd::parseState
Mar 22 03:33:47 volumio volumio[1063]: info: Command Router : Notfying DB Updatetrue
Mar 22 03:33:47 volumio volumio[1063]: info: [1490153627073] ControllerMpd::parseState
Mar 22 03:33:47 volumio volumio[1063]: info: [1490153627074] ControllerMpd::pushState
Mar 22 03:33:47 volumio volumio[1063]: info: CoreCommandRouter::servicePushState
Mar 22 03:33:47 volumio volumio[1063]: info: [1490153627083] CoreStateMachine::syncState
Mar 22 03:33:47 volumio volumio[1063]: info: [1490153627085] CorePlayQueue::getTrack 0
Mar 22 03:33:47 volumio volumio[1063]: info: STATE SERVICE {“status”:“stop”,“position”:null,“seek”:null,“duration”:null,“samplerate”:null,“bitdepth”:null,“channels”:null,“random”:false,“updatedb”:true,“repeat”:false,“isStreaming”:false,“title”:null,“artist”:null,“album”:null,“uri”:null}
Mar 22 03:33:47 volumio volumio[1063]: info: CURRENT POSITION 0
Mar 22 03:33:47 volumio volumio[1063]: info: [1490153627090] CoreStateMachine::syncState stateService stop
Mar 22 03:33:47 volumio volumio[1063]: info: [1490153627091] CoreStateMachine::syncState currentStatus stop
Mar 22 03:33:47 volumio volumio[1063]: info: [1490153627093] CoreStateMachine::pushState
Mar 22 03:33:47 volumio volumio[1063]: info: [1490153627094] CoreStateMachine::getState
Mar 22 03:33:47 volumio volumio[1063]: info: [1490153627096] CorePlayQueue::getTrack 0
Mar 22 03:33:47 volumio volumio[1063]: info: CoreCommandRouter::volumioPushState
Mar 22 03:33:47 volumio volumio[1063]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 22 03:33:47 volumio volumio[1063]: info: [1490153627101] interfaceApi::pushState
Mar 22 03:33:47 volumio volumio[1063]: info: [1490153627110] InterfaceWebUI::pushState
Mar 22 03:33:47 volumio volumio[1063]: info: [1490153627135] No code
Mar 22 03:33:47 volumio volumio[1063]: info: [1490153627141] CoreStateMachine::pushState
Mar 22 03:33:47 volumio volumio[1063]: info: [1490153627141] CoreStateMachine::getState
Mar 22 03:33:47 volumio volumio[1063]: info: [1490153627143] CorePlayQueue::getTrack 0
Mar 22 03:33:47 volumio volumio[1063]: info: CoreCommandRouter::volumioPushState
Mar 22 03:33:47 volumio volumio[1063]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 22 03:33:47 volumio volumio[1063]: info: [1490153627151] interfaceApi::pushState
Mar 22 03:33:47 volumio volumio[1063]: info: [1490153627152] InterfaceWebUI::pushState
Mar 22 03:33:47 volumio volumio[1063]: info: [1490153627177] ------------------------------ 1075ms
Mar 22 03:33:47 volumio volumio[1063]: info: Pushing Favourites {“service”:“mpd”,“uri”:"",“favourite”:false}
Mar 22 03:33:47 volumio mpd[547]: update: added NAS/test/Coldplay/Viva La Vida/09 Strawberry Swing.mp3
Mar 22 03:33:47 volumio volumio[1063]: info: Pushing Favourites {“service”:“mpd”,“uri”:"",“favourite”:false}
Mar 22 03:33:47 volumio mpd[547]: update: added NAS/test/Coldplay/Viva La Vida/11 The Escapist.mp3
Mar 22 03:33:47 volumio mpd[547]: update: added NAS/test/Coldplay/X&Y/01 Square One.mp3
Mar 22 03:33:47 volumio mpd[547]: update: added NAS/test/Coldplay/X&Y/02 What If_.mp3
Mar 22 03:33:47 volumio mpd[547]: update: added NAS/test/Coldplay/X&Y/03 White Shadows.mp3
Mar 22 03:33:47 volumio mpd[547]: update: added NAS/test/Coldplay/X&Y/04 Fix You.mp3
Mar 22 03:33:47 volumio mpd[547]: update: added NAS/test/Coldplay/X&Y/05 Talk.mp3
Mar 22 03:33:47 volumio mpd[547]: update: added NAS/test/Coldplay/X&Y/06 X&Y.mp3
Mar 22 03:33:47 volumio mpd[547]: update: added NAS/test/Coldplay/X&Y/07 Speed of Sound.mp3
Mar 22 03:33:47 volumio mpd[547]: update: added NAS/test/Coldplay/X&Y/08 A Message.mp3
Mar 22 03:33:47 volumio mpd[547]: update: added NAS/test/Coldplay/X&Y/09 Low.mp3
Mar 22 03:33:47 volumio volumio[1063]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
…
…
…
…
Mar 22 03:39:39 volumio mpd[547]: update: added NAS/test/Matt Mays & El Torpedo/Matt Mays & El Torpedo/11 It Don’t Matter.mp3
Mar 22 03:39:39 volumio mpd[547]: update: added NAS/test/Matt Mays & El Torpedo/Matt Mays & El Torpedo/12 On The Hood.mp3
Mar 22 03:39:39 volumio mpd[547]: update: added NAS/test/Matt Mays & El Torpedo/Matt Mays & El Torpedo/13 Time Of Your Life.mp3
Mar 22 03:39:39 volumio mpd[547]: update: added NAS/test/Matt Mays & El Torpedo/Matt Mays & El Torpedo/14 Wicked Come Winter.mp3
Mar 22 03:39:39 volumio kernel: Unhandled fault: alignment fault (0x92000021) at 0x00000000eec5768a
Mar 22 03:39:39 volumio systemd[1]: mpd.service: main process exited, code=killed, status=7/BUS
Mar 22 03:39:39 volumio systemd[1]: Unit mpd.service entered failed state.
Mar 22 03:39:39 volumio systemd[1]: mpd.service holdoff time over, scheduling restart.
Mar 22 03:39:39 volumio systemd[1]: Stopping Music Player Daemon…
Mar 22 03:39:39 volumio systemd[1]: Starting Music Player Daemon…
Mar 22 03:39:39 volumio systemd[1]: Started Music Player Daemon.
Mar 22 03:39:40 volumio mpd[1275]: zeroconf: No global port, disabling zeroconf

7

I also tried putting all of my music on an external HDD. Same thing. WebUI starts showing tracks and updating…then it all goes to 0 again! ARGH!!!

I’ve tried to bold any of the errors I could find.

I’m really discouraged now. I can’t even get it to work with an attached HDD.

Here is the truncated journalctl from the update library.

volumio@volumio:~$ sudo journalctl -f
– Logs begin at Wed 2017-03-22 05:50:04 UTC. –
Mar 22 14:21:36 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 22 14:21:40 volumio sudo[1413]: volumio : TTY=pts/0 ; PWD=/etc/samba ; USER=root ; COMMAND=/bin/journalctl -f
Mar 22 14:21:40 volumio sudo[1413]: pam_unix(sudo:session): session opened for user root by volumio(uid=0)
Mar 22 14:21:40 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 22 14:21:44 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 22 14:21:45 volumio sudo[1413]: pam_unix(sudo:session): session closed for user root
Mar 22 14:21:48 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 22 14:21:52 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 22 14:21:53 volumio sudo[1416]: volumio : TTY=pts/0 ; PWD=/home/volumio ; USER=root ; COMMAND=/bin/journalctl -f
Mar 22 14:21:53 volumio sudo[1416]: pam_unix(sudo:session): session opened for user root by volumio(uid=0)
Mar 22 14:21:56 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 22 14:21:57 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , updateDb
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517586] ControllerMpd::sendMpdCommand update
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517587] sending command…
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517590] ControllerMpd::sendMpdCommand status
Mar 22 14:21:57 volumio volumio[1056]: info: Mpd Status Update: update
Mar 22 14:21:57 volumio volumio[1056]: info:
Mar 22 14:21:57 volumio volumio[1056]: [1490192517591] ---------------------------- MPD announces state update
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517592] parsing response…
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517593] sending command…
Mar 22 14:21:57 volumio mpd[1400]: errno: Failed to open ‘USB/music/.fseventsd’: Permission denied
Mar 22 14:21:57 volumio mpd[1400]: errno: Failed to open ‘USB/music/.Spotlight-V100’: Permission denied
Mar 22 14:21:57 volumio mpd[1400]: errno: Failed to open ‘USB/music/.Trashes’: Permission denied
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517595] ControllerMpd::getState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517596] ControllerMpd::sendMpdCommand status
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517597] sending command…
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517600] ControllerMpd::sendMpdCommand status
Mar 22 14:21:57 volumio volumio[1056]: info: Mpd Status Update: update
Mar 22 14:21:57 volumio volumio[1056]: info:
Mar 22 14:21:57 volumio volumio[1056]: [1490192517602] ---------------------------- MPD announces state update
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517603] sending command…
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517605] ControllerMpd::getState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517606] ControllerMpd::sendMpdCommand status
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517607] sending command…
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517609] ControllerMpd::sendMpdCommand status
Mar 22 14:21:57 volumio volumio[1056]: info: Mpd Status Update: update
Mar 22 14:21:57 volumio volumio[1056]: info:
Mar 22 14:21:57 volumio volumio[1056]: [1490192517611] ---------------------------- MPD announces state update
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517613] sending command…
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517615] ControllerMpd::getState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517616] ControllerMpd::sendMpdCommand status
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517617] sending command…
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517619] ControllerMpd::sendMpdCommand status
Mar 22 14:21:57 volumio volumio[1056]: info: Mpd Status Update: update
Mar 22 14:21:57 volumio volumio[1056]: info:
Mar 22 14:21:57 volumio volumio[1056]: [1490192517621] ---------------------------- MPD announces state update
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517622] sending command…
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517624] ControllerMpd::getState
Mar 22 14:21:57 volumio systemd-journal[200]: Suppressed 424 messages from /system.slice/mpd.service
Mar 22 14:21:57 volumio mpd[1400]: update: added USB/music/A Perfect Circle/Mer De Noms/01 The Hollow.mp3
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517625] ControllerMpd::sendMpdCommand status
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517626] sending command…
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517629] ControllerMpd::sendMpdCommand status
Mar 22 14:21:57 volumio volumio[1056]: info: Mpd Status Update: update
Mar 22 14:21:57 volumio volumio[1056]: info:
Mar 22 14:21:57 volumio volumio[1056]: [1490192517636] ---------------------------- MPD announces state update
Mar 22 14:21:57 volumio mpd[1400]: alsa_mixer: Failed to read mixer for ‘alsa’: no such mixer control: PCM
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517638] sending command…
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517640] ControllerMpd::getState
Mar 22 14:21:57 volumio mpd[1400]: update: added USB/music/A Perfect Circle/Mer De Noms/02 Magdalena.mp3
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517641] ControllerMpd::sendMpdCommand status
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517642] sending command…
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517645] ControllerMpd::sendMpdCommand status
Mar 22 14:21:57 volumio volumio[1056]: info: Mpd Status Update: update
Mar 22 14:21:57 volumio volumio[1056]: info:
Mar 22 14:21:57 volumio volumio[1056]: [1490192517647] ---------------------------- MPD announces state update
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517648] sending command…
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517650] ControllerMpd::getState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517651] ControllerMpd::sendMpdCommand status
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517652] sending command…
Mar 22 14:21:57 volumio mpd[1400]: update: added USB/music/A Perfect Circle/Mer De Noms/03 Rose.mp3
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517656] parsing response…
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517657] parsing response…
Mar 22 14:21:57 volumio mpd[1400]: update: added USB/music/A Perfect Circle/Mer De Noms/04 Judith.mp3
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517659] parsing response…
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517668] parsing response…
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517669] parsing response…
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517673] parsing response…
Mar 22 14:21:57 volumio mpd[1400]: update: added USB/music/A Perfect Circle/Mer De Noms/05 Orestes.mp3
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517677] parsing response…
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517680] parsing response…
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517681] parsing response…
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517682] parsing response…
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517684] ControllerMpd::parseState
Mar 22 14:21:57 volumio mpd[1400]: update: added USB/music/A Perfect Circle/Mer De Noms/06 3 Libras.mp3
Mar 22 14:21:57 volumio mpd[1400]: update: added USB/music/A Perfect Circle/Mer De Noms/07 Sleeping Beauty.mp3
Mar 22 14:21:57 volumio mpd[1400]: update: added USB/music/A Perfect Circle/Mer De Noms/08 Thomas.mp3
Mar 22 14:21:57 volumio volumio[1056]: info: Command Router : Notfying DB Updatetrue
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517719] ControllerMpd::parseState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517720] ControllerMpd::parseState
Mar 22 14:21:57 volumio mpd[1400]: update: added USB/music/A Perfect Circle/Mer De Noms/09 Renholdër.mp3
Mar 22 14:21:57 volumio mpd[1400]: update: added USB/music/A Perfect Circle/Mer De Noms/10 Thinking of You.mp3
Mar 22 14:21:57 volumio volumio[1056]: info: Command Router : Notfying DB Updatetrue
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517736] ControllerMpd::parseState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517737] ControllerMpd::parseState
Mar 22 14:21:57 volumio mpd[1400]: update: added USB/music/A Perfect Circle/Mer De Noms/11 Breña.mp3
Mar 22 14:21:57 volumio volumio[1056]: info: Command Router : Notfying DB Updatetrue
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517752] ControllerMpd::parseState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517753] ControllerMpd::parseState
Mar 22 14:21:57 volumio mpd[1400]: update: added USB/music/A Perfect Circle/Mer De Noms/12 Over.mp3
Mar 22 14:21:57 volumio volumio[1056]: info: Command Router : Notfying DB Updatetrue
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517770] ControllerMpd::parseState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517771] ControllerMpd::parseState
Mar 22 14:21:57 volumio mpd[1400]: update: added USB/music/A Perfect Circle/Thirteenth Step/01 01 01-a_perfect_circle-the_package-fnt.mp3
Mar 22 14:21:57 volumio volumio[1056]: info: Command Router : Notfying DB Updatetrue
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517786] ControllerMpd::parseState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517790] ControllerMpd::pushState
Mar 22 14:21:57 volumio volumio[1056]: info: CoreCommandRouter::servicePushState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517791] CoreStateMachine::syncState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517792] CorePlayQueue::getTrack 0
Mar 22 14:21:57 volumio volumio[1056]: info: STATE SERVICE {“status”:“stop”,“position”:null,“seek”:null,“duration”:null,“samplerate”:null,“bitdepth”:null,“channels”:null,“random”:false,“updatedb”:true,“repeat”:false,“isStreaming”:false,“title”:null,“artist”:null,“album”:null,“uri”:null}
Mar 22 14:21:57 volumio volumio[1056]: info: CURRENT POSITION 0
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517793] CoreStateMachine::syncState stateService stop
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517795] CoreStateMachine::syncState currentStatus stop
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517796] CoreStateMachine::pushState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517797] CoreStateMachine::getState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517798] CorePlayQueue::getTrack 0
Mar 22 14:21:57 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState
Mar 22 14:21:57 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 22 14:21:57 volumio mpd[1400]: update: added USB/music/A Perfect Circle/Thirteenth Step/02 02 02-a_perfect_circle-weak_and_powerless-fnt.mp3
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517803] interfaceApi::pushState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517804] InterfaceWebUI::pushState
Mar 22 14:21:57 volumio mpd[1400]: update: added USB/music/A Perfect Circle/Thirteenth Step/03 03 03-a_perfect_circle-the_noose-fnt.mp3
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517821] No code
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517825] CoreStateMachine::pushState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517827] CoreStateMachine::getState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517829] CorePlayQueue::getTrack 0
Mar 22 14:21:57 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState
Mar 22 14:21:57 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517835] interfaceApi::pushState
Mar 22 14:21:57 volumio mpd[1400]: update: added USB/music/A Perfect Circle/Thirteenth Step/04 04 04-a_perfect_circle-blue-fnt.mp3
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517838] InterfaceWebUI::pushState
Mar 22 14:21:57 volumio mpd[1400]: update: added USB/music/A Perfect Circle/Thirteenth Step/05 05 05-a_perfect_circle-vanishing-fnt.mp3
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517852] ControllerMpd::pushState
Mar 22 14:21:57 volumio volumio[1056]: info: CoreCommandRouter::servicePushState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517853] CoreStateMachine::syncState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517853] CorePlayQueue::getTrack 0
Mar 22 14:21:57 volumio volumio[1056]: info: STATE SERVICE {“status”:“stop”,“position”:null,“seek”:null,“duration”:null,“samplerate”:null,“bitdepth”:null,“channels”:null,“random”:false,“updatedb”:true,“repeat”:false,“isStreaming”:false,“title”:null,“artist”:null,“album”:null,“uri”:null}
Mar 22 14:21:57 volumio volumio[1056]: info: CURRENT POSITION 0
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517854] CoreStateMachine::syncState stateService stop
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517855] CoreStateMachine::syncState currentStatus stop
Mar 22 14:21:57 volumio mpd[1400]: update: added USB/music/A Perfect Circle/Thirteenth Step/06 06 06-a_perfect_circle-a_stranger-fnt.mp3
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517855] CoreStateMachine::pushState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517855] CoreStateMachine::getState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517856] CorePlayQueue::getTrack 0
Mar 22 14:21:57 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState
Mar 22 14:21:57 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517858] interfaceApi::pushState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517859] InterfaceWebUI::pushState
Mar 22 14:21:57 volumio mpd[1400]: update: added USB/music/A Perfect Circle/Thirteenth Step/07 07 07-a_perfect_circle-the_outsider-fnt.mp3
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517880] No code
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517880] CoreStateMachine::pushState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517881] CoreStateMachine::getState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517881] CorePlayQueue::getTrack 0
Mar 22 14:21:57 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState
Mar 22 14:21:57 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517884] interfaceApi::pushState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517885] InterfaceWebUI::pushState
Mar 22 14:21:57 volumio mpd[1400]: update: added USB/music/A Perfect Circle/Thirteenth Step/08 08 08-a_perfect_circle-crimes-fnt.mp3
Mar 22 14:21:57 volumio mpd[1400]: update: added USB/music/A Perfect Circle/Thirteenth Step/09 09 09-a_perfect_circle-the_nurse_who_loved_me-fnt.mp3
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517907] ControllerMpd::pushState
Mar 22 14:21:57 volumio volumio[1056]: info: CoreCommandRouter::servicePushState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517909] CoreStateMachine::syncState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517910] CorePlayQueue::getTrack 0
Mar 22 14:21:57 volumio volumio[1056]: info: STATE SERVICE {“status”:“stop”,“position”:null,“seek”:null,“duration”:null,“samplerate”:null,“bitdepth”:null,“channels”:null,“random”:false,“updatedb”:true,“repeat”:false,“isStreaming”:false,“title”:null,“artist”:null,“album”:null,“uri”:null}
Mar 22 14:21:57 volumio volumio[1056]: info: CURRENT POSITION 0
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517912] CoreStateMachine::syncState stateService stop
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517913] CoreStateMachine::syncState currentStatus stop
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517914] CoreStateMachine::pushState
Mar 22 14:21:57 volumio mpd[1400]: update: added USB/music/A Perfect Circle/Thirteenth Step/10 10 10-a_perfect_circle-pet-fnt.mp3
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517914] CoreStateMachine::getState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517916] CorePlayQueue::getTrack 0
Mar 22 14:21:57 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState
Mar 22 14:21:57 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517919] interfaceApi::pushState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517921] InterfaceWebUI::pushState
Mar 22 14:21:57 volumio mpd[1400]: update: added USB/music/A Perfect Circle/Thirteenth Step/11 11 11-a_perfect_circle-lullaby-fnt.mp3
Mar 22 14:21:57 volumio mpd[1400]: update: added USB/music/A Perfect Circle/Thirteenth Step/13 13 12-a_perfect_circle-gravity-fnt.mp3
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517946] No code
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517947] CoreStateMachine::pushState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517947] CoreStateMachine::getState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517948] CorePlayQueue::getTrack 0
Mar 22 14:21:57 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState
Mar 22 14:21:57 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 22 14:21:57 volumio mpd[1400]: update: added USB/music/AC_DC/74 Jailbreak/01 Jailbreak.mp3
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517960] interfaceApi::pushState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517967] InterfaceWebUI::pushState
Mar 22 14:21:57 volumio mpd[1400]: update: added USB/music/AC_DC/74 Jailbreak/02 You Ain’t Got A Hold On Me.mp3
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517987] ControllerMpd::pushState
Mar 22 14:21:57 volumio volumio[1056]: info: CoreCommandRouter::servicePushState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517992] CoreStateMachine::syncState
Mar 22 14:21:57 volumio volumio[1056]: info: [1490192517993] CorePlayQueue::getTrack 0
Mar 22 14:21:57 volumio volumio[1056]: info: STATE SERVICE {“status”:“stop”,“position”:null,“seek”:null,“duration”:null,“samplerate”:null,“bitdepth”:null,“channels”:null,“random”:false,“updatedb”:true,“repeat”:false,“isStreaming”:false,“title”:null,“artist”:null,“album”:null,“uri”:null}
Mar 22 14:21:57 volumio mpd[1400]: update: added USB/music/AC_DC/74 Jailbreak/03 Show Bisiness.mp3
Mar 22 14:21:58 volumio volumio[1056]: info: CURRENT POSITION 0
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518001] CoreStateMachine::syncState stateService stop
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518002] CoreStateMachine::syncState currentStatus stop
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518003] CoreStateMachine::pushState
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518004] CoreStateMachine::getState
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518006] CorePlayQueue::getTrack 0
Mar 22 14:21:58 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState
Mar 22 14:21:58 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518012] interfaceApi::pushState
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518013] InterfaceWebUI::pushState
Mar 22 14:21:58 volumio mpd[1400]: update: added USB/music/AC_DC/74 Jailbreak/04 Soul Stripper.mp3
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518026] No code
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518028] CoreStateMachine::pushState
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518029] CoreStateMachine::getState
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518030] CorePlayQueue::getTrack 0
Mar 22 14:21:58 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState
Mar 22 14:21:58 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518033] interfaceApi::pushState
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518034] InterfaceWebUI::pushState
Mar 22 14:21:58 volumio mpd[1400]: update: added USB/music/AC_DC/74 Jailbreak/05 Baby, Please Don’t Go.mp3
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518047] ControllerMpd::pushState
Mar 22 14:21:58 volumio volumio[1056]: info: CoreCommandRouter::servicePushState
Mar 22 14:21:58 volumio mpd[1400]: update: added USB/music/AC_DC/Back In Black/01 Hells Bells.mp3
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518049] CoreStateMachine::syncState
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518049] CorePlayQueue::getTrack 0
Mar 22 14:21:58 volumio volumio[1056]: info: STATE SERVICE {“status”:“stop”,“position”:null,“seek”:null,“duration”:null,“samplerate”:null,“bitdepth”:null,“channels”:null,“random”:false,“updatedb”:true,“repeat”:false,“isStreaming”:false,“title”:null,“artist”:null,“album”:null,“uri”:null}
Mar 22 14:21:58 volumio volumio[1056]: info: CURRENT POSITION 0
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518052] CoreStateMachine::syncState stateService stop
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518053] CoreStateMachine::syncState currentStatus stop
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518054] CoreStateMachine::pushState
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518054] CoreStateMachine::getState
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518055] CorePlayQueue::getTrack 0
Mar 22 14:21:58 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState
Mar 22 14:21:58 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518058] interfaceApi::pushState
Mar 22 14:21:58 volumio mpd[1400]: update: added USB/music/AC_DC/Back In Black/02 Shoot To Thrill.mp3
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518059] InterfaceWebUI::pushState
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518074] No code
Mar 22 14:21:58 volumio mpd[1400]: update: added USB/music/AC_DC/Back In Black/03 What Do You Do For Money Honey.mp3
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518075] CoreStateMachine::pushState
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518076] CoreStateMachine::getState
Mar 22 14:21:58 volumio mpd[1400]: update: added USB/music/AC_DC/Back In Black/04 Given The Dog A Bone.mp3
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518087] CorePlayQueue::getTrack 0
Mar 22 14:21:58 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState
Mar 22 14:21:58 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518092] interfaceApi::pushState
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518094] InterfaceWebUI::pushState
Mar 22 14:21:58 volumio mpd[1400]: update: added USB/music/AC_DC/Back In Black/05 Let Me Put My Love Into You.mp3
Mar 22 14:21:58 volumio mpd[1400]: update: added USB/music/AC_DC/Back In Black/06 Back In Black.mp3
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518118] ------------------------------ 528ms
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518120] ------------------------------ 519ms
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518122] ------------------------------ 512ms
Mar 22 14:21:58 volumio mpd[1400]: update: added USB/music/AC_DC/Back In Black/07 You Shook Me All Night Long.mp3
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518124] ------------------------------ 504ms
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518126] ------------------------------ 490ms
Mar 22 14:21:58 volumio volumio[1056]: info: Pushing Favourites {“service”:“mpd”,“uri”:"",“favourite”:false}
Mar 22 14:21:58 volumio mpd[1400]: update: added USB/music/AC_DC/Back In Black/08 Have A Drink On Me.mp3
Mar 22 14:21:58 volumio volumio[1056]: info: Pushing Favourites {“service”:“mpd”,“uri”:"",“favourite”:false}
Mar 22 14:21:58 volumio volumio[1056]: info: Pushing Favourites {“service”:“mpd”,“uri”:"",“favourite”:false}
Mar 22 14:21:58 volumio volumio[1056]: info: Pushing Favourites {“service”:“mpd”,“uri”:"",“favourite”:false}
Mar 22 14:21:58 volumio mpd[1400]: update: added USB/music/AC_DC/Back In Black/09 Shake A Leg.mp3
Mar 22 14:21:58 volumio volumio[1056]: info: Pushing Favourites {“service”:“mpd”,“uri”:"",“favourite”:false}
Mar 22 14:21:58 volumio volumio[1056]: info: Pushing Favourites {“service”:“mpd”,“uri”:"",“favourite”:false}
Mar 22 14:21:58 volumio volumio[1056]: info: Pushing Favourites {“service”:“mpd”,“uri”:"",“favourite”:false}
Mar 22 14:21:58 volumio volumio[1056]: info: Pushing Favourites {“service”:“mpd”,“uri”:"",“favourite”:false}
Mar 22 14:21:58 volumio mpd[1400]: update: added USB/music/AC_DC/Back In Black/10 Rock And Roll Ain’t Noise Poll.mp3
Mar 22 14:21:58 volumio volumio[1056]: info: Pushing Favourites {“service”:“mpd”,“uri”:"",“favourite”:false}
Mar 22 14:21:58 volumio volumio[1056]: info: Pushing Favourites {“service”:“mpd”,“uri”:"",“favourite”:false}
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518168] parsing response…
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518169] parsing response…
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518170] ControllerMpd::parseState
Mar 22 14:21:58 volumio mpd[1400]: update: added USB/music/AC_DC/Ballbreaker/01 Hard As A Rock.mp3
Mar 22 14:21:58 volumio volumio[1056]: info: Command Router : Notfying DB Updatetrue
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518187] ControllerMpd::parseState
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518189] ControllerMpd::pushState
Mar 22 14:21:58 volumio volumio[1056]: info: CoreCommandRouter::servicePushState
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518190] CoreStateMachine::syncState
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518191] CorePlayQueue::getTrack 0
Mar 22 14:21:58 volumio volumio[1056]: info: STATE SERVICE {“status”:“stop”,“position”:null,“seek”:null,“duration”:null,“samplerate”:null,“bitdepth”:null,“channels”:null,“random”:false,“updatedb”:true,“repeat”:false,“isStreaming”:false,“title”:null,“artist”:null,“album”:null,“uri”:null}
Mar 22 14:21:58 volumio volumio[1056]: info: CURRENT POSITION 0
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518193] CoreStateMachine::syncState stateService stop
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518194] CoreStateMachine::syncState currentStatus stop
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518194] CoreStateMachine::pushState
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518195] CoreStateMachine::getState
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518195] CorePlayQueue::getTrack 0
Mar 22 14:21:58 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState
Mar 22 14:21:58 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518198] interfaceApi::pushState
Mar 22 14:21:58 volumio mpd[1400]: update: added USB/music/AC_DC/Ballbreaker/02 Cover You In Oil.mp3
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518199] InterfaceWebUI::pushState
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518214] No code
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518215] CoreStateMachine::pushState
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518216] CoreStateMachine::getState
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518216] CorePlayQueue::getTrack 0
Mar 22 14:21:58 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState
Mar 22 14:21:58 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518220] interfaceApi::pushState
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518221] InterfaceWebUI::pushState
Mar 22 14:21:58 volumio mpd[1400]: update: added USB/music/AC_DC/Ballbreaker/03 The Furor.mp3
Mar 22 14:21:58 volumio volumio[1056]: info: [1490192518241] ------------------------------ 595ms
Mar 22 14:21:58 volumio mpd[1400]: update: added USB/music/AC_DC/Ballbreaker/04 Boogie Man.mp3
Mar 22 14:21:58 volumio mpd[1400]: update: added USB/music/AC_DC/Ballbreaker/05 The Honey Roll.mp3
Mar 22 14:21:58 volumio mpd[1400]: update: added USB/music/AC_DC/Ballbreaker/06 Burnin’ Alive.mp3
Mar 22 14:21:58 volumio mpd[1400]: update: added USB/music/AC_DC/Ballbreaker/07 Hail Ceasar.mp3
Mar 22 14:21:58 volumio volumio[1056]: info: Pushing Favourites {“service”:“mpd”,“uri”:"",“favourite”:false}
Mar 22 14:21:58 volumio volumio[1056]: info: Pushing Favourites {“service”:“mpd”,“uri”:"",“favourite”:false}
Mar 22 14:21:58 volumio mpd[1400]: update: added USB/music/AC_DC/Ballbreaker/08 Love Bomb.mp3
Mar 22 14:21:58 volumio mpd[1400]: update: added USB/music/AC_DC/Ballbreaker/09 Caught With You Pants Down.mp3
.
.
.
.
Mar 22 14:22:12 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 22 14:22:16 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 22 14:22:20 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 22 14:22:24 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 22 14:22:27 volumio systemd-journal[200]: Suppressed 748 messages from /system.slice/mpd.service
.
.
.
.
Mar 22 14:22:44 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 22 14:22:48 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 22 14:22:52 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 22 14:22:56 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 22 14:22:57 volumio systemd-journal[200]: Suppressed 580 messages from /system.slice/mpd.service
.
.
.
.
Mar 22 14:23:13 volumio mpd[1400]: update: added USB/music/Compilations/Great Tunes Vol 3/19 Track 19 2.mp3
Mar 22 14:23:13 volumio mpd[1400]: update: added USB/music/Compilations/Great Tunes Vol 3/19 Track 19.mp3
Mar 22 14:23:16 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 22 14:23:20 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 22 14:23:25 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 22 14:23:27 volumio systemd-journal[200]: Suppressed 1006 messages from /system.slice/mpd.service
Mar 22 14:23:27 volumio mpd[1400]: update: added USB/music/Compilations/Now That’s What I Call Xmas/13 Frosty The Snowman.mp3
Mar 22 14:23:27 volumio mpd[1400]: update: added USB/music/Compilations/Now That’s What I Call Xmas/13 The Twelve Days Of Christmas.mp3
.
.
.
.
Mar 22 14:23:40 volumio mpd[1400]: update: added USB/music/Dropkick Murphys/Sing Loud, Sing Proud!/03 Which Side Are You On_.mp3
Mar 22 14:23:40 volumio mpd[1400]: update: added USB/music/Dropkick Murphys/Sing Loud, Sing Proud!/04 The Rocky Road To Dublin.mp3
Mar 22 14:23:40 volumio smbd[1220]: [2017/03/22 14:23:40.470545, 0] …/lib/util/debug.c:603(reopen_logs_internal)
Mar 22 14:23:40 volumio smbd[1220]: Unable to open new log file ‘/var/log/samba/log.smbd’: No such file or directory
Mar 22 14:23:40 volumio mpd[1400]: update: added USB/music/Dropkick Murphys/Sing Loud, Sing Proud!/05 Heroes From Our Past.mp3
.
.
.
.
Mar 22 14:23:43 volumio mpd[1400]: update: added USB/music/Eric Clapton/Crossroads/1-14 Rambling on My Mind.MP3
Mar 22 14:23:43 volumio mpd[1400]: update: added USB/music/Eric Clapton/Crossroads/1-15 Have You Ever Loved a Woman [Live].MP3
Mar 22 14:23:45 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 22 14:23:49 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 22 14:23:53 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 22 14:23:56 volumio kernel: Unhandled fault: alignment fault (0x92000021) at 0x00000000ef2e9c92
Mar 22 14:23:56 volumio systemd[1]: mpd.service: main process exited, code=killed, status=7/BUS
Mar 22 14:23:56 volumio systemd[1]: Unit mpd.service entered failed state.
Mar 22 14:23:56 volumio systemd[1]: mpd.service holdoff time over, scheduling restart.
Mar 22 14:23:56 volumio systemd[1]: Stopping Music Player Daemon…
Mar 22 14:23:56 volumio systemd[1]: Starting Music Player Daemon…
Mar 22 14:23:56 volumio systemd[1]: Started Music Player Daemon.
Mar 22 14:23:57 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 22 14:23:57 volumio volumio[1056]: error: MPD error: Error: This socket has been ended by the other party
Mar 22 14:23:57 volumio volumio[1056]: error: MPD error: Error: This socket has been ended by the other party
Mar 22 14:23:57 volumio volumio[1056]: error: MPD error: Error: This socket has been ended by the other party
Mar 22 14:23:58 volumio mpd[1469]: zeroconf: No global port, disabling zeroconf
Mar 22 14:23:58 volumio mpd[1469]: errno: Failed to register /var/lib/mpd/music/USB/music/.fseventsd: inotify_add_watch() has failed: Permission denied
Mar 22 14:23:58 volumio mpd[1469]: errno: Failed to register /var/lib/mpd/music/USB/music/.Spotlight-V100: inotify_add_watch() has failed: Permission denied
Mar 22 14:23:58 volumio mpd[1469]: errno: Failed to register /var/lib/mpd/music/USB/music/.Trashes: inotify_add_watch() has failed: Permission denied
Mar 22 14:24:01 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 22 14:24:01 volumio volumio[1056]: error: MPD error: Error: This socket has been ended by the other party
Mar 22 14:24:01 volumio volumio[1056]: error: MPD error: Error: This socket has been ended by the other party
Mar 22 14:24:01 volumio volumio[1056]: error: MPD error: Error: This socket has been ended by the other party
Mar 22 14:24:02 volumio systemd-journal[200]: Suppressed 1050 messages from /system.slice/mpd.service
Mar 22 14:24:02 volumio mpd[1469]: client: [0] opened from 127.0.0.1:38745
Mar 22 14:24:02 volumio mpd[1469]: client: [1] opened from 127.0.0.1:38746
Mar 22 14:24:02 volumio mpd[1469]: client: [2] opened from 127.0.0.1:38747
Mar 22 14:24:02 volumio volumio[1056]: info:
Mar 22 14:24:05 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 22 14:24:06 volumio mpd[1469]: client: [3] opened from 127.0.0.1:38748
Mar 22 14:24:06 volumio mpd[1469]: client: [4] opened from 127.0.0.1:38749
Mar 22 14:24:06 volumio mpd[1469]: client: [5] opened from 127.0.0.1:38750
Mar 22 14:24:06 volumio volumio[1056]: info:
Mar 22 14:24:09 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 22 14:24:13 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 22 14:24:17 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 22 14:24:21 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 22 14:24:25 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats

8

Sorry, I’m afraid that until a solution for the “alignment fault” is found, you are stuck with this problem. :angry:

9

Well thats horrible and super frustrating!!! :imp: :angry: :cry: :confused: (so many mixed emotions!)

Is this a problem with all boards? Or just with the Pine64?

Any advice on where I go to take a look / maybe try and help out / read about the problem?

Thanks again for the help

  • Drew
10

No, it’s not just Pine. It’s been reported mainly on Odroid C2, but also RPi.

11

So you are a Mac user.
Now you have a copy of your files on an external USB drive (assuming FAT32 formatted), you may want to try to clean-up all hidden Mac files with a tool such as CleanMyDrive 2 (or similar), and try again.

12

I have exactly the same problem: as soon as I scan my library (in my case on a windows server) it crashes with the alignment fault:

Mar 24 12:12:50 volumio kernel: Unhandled fault: alignment fault (0x92000021) at 0x00000000eed726f6

It is unpredictable when the error occurs, not after a certain amount of artist or tracks (this is suggested on other forums). If I edit the mpd.conf to disable ffmpeg, Volumio won’t start at all…
I have 2 raspberry pi’s (a B+ and 3) both with I2C DAC’s and the same Volumio version on it. They connect to the same share with the same settings and they didn’t crash scanning all files (about 80.000 tracks). So it seems a problem specific for the Pine64 (and some other boards I understand). My Pine64 is the model with 2gb memory. All my devices are wired connected on the same local network.

But I mentioned another difference: On the PI’s I don’t need to enter credentials to connect to my network share (this is the correct behaivior), but the Pine64 needs credentials. I does not matter or I use real or fake credentials; it allways connect to the share (it is shared to everyone on the local network).
Hopefully some one is able to find a solution; the pine64 is pretty useless without a fix.

13

Finally got around to trying your suggestion of formatting in FAT 32 and using clean my drive on the HDD. I still got the alignment fault. I also was looking around and saw that there was a newer version of volumio out for the Pine64. I was running 2.118-2017-03-07 and the one on the site is now 2.129-2017-03-26. The automatic updater would not work. So I refreshed my card with the new OS. Still got the same problem when attaching the external HDD (alignment fault). I also tried my to mount my NAS again too but no luck.

Is there any one out there who has got the Pine64 to work with a larger library?

14

Check your PM box please

15

Done! Sent you a PM

16

there is an experimental image for the scanning issue on http://oph.mdrjr.net/gkkpch, look for the pine64 image.
It is not a solution (other things may not work), it will only be there for 1-2 days.
Any feedback on changes in library scanning will be highly appreciated, it may help us finding the right way to fix it.

17

Awesome thanks!

I’ll make sure to ssh in and run ‘sudo journalctl -f’ and post the results this weekend. I’ll also make sure to do both my NAS and my external HDD

18

Great news fellow Pine64 volumio’ers!

gkkpch’s debian mpd image worked! My entire music library of 11020 files successfully loaded. :smiley: :astonished: :smiley: :astonished: :smiley: (I’m so happy it worked)

I haven’t messed around too much but I did try to play both mp3 & m4a files. Originally they both played fine, but I did get a crap ton of static overtop of the m4a files after a few reboots from trying to get the web volume control to work. So even though I’ve put everything back to the way I had it I can hear the song but its under a TON of static (m4a files only). But this is still a HUGE step forward in the right direction!

From what I have quickly tried out here’s what I’ve managed to check (briefly)

  1. loads library from NAS +10,000 songs --> YES :mrgreen:
    (mounted QNAP TS-220 with cifs share, user and creds from the first post in this thread)

  2. m4a playback --> worked orginally but seems to not be working now. I am going to refresh my card and see if that works to correct whatever I did

  3. webui volume control --> did not work (I believe this is what caused me to mess up the m4a playback when I was changing the mixer control type)

  4. web radio could not get to work with custom web radio station ( even though the url works in a browser ckno.streamon.fm/hls/CKNO.m3u8)

  5. certain web radio stations seem to work. Others are under that same static sound that the m4a files are under, or will not decode. I will see if the re-flashing fixes the static issue, but the decode problem I have no idea on where to start. Its the same error that I get when I try to add my custom web radio station

Even with this small issues I still have a working / workable Pine64 running volumio. I don’t want to down play that at all. The work that gkkpch (an everyone else) has put in to getting the Pine to this point is amazing! I am so happy that it is actually working now and not a SBC doing nothing on my desk.

I am hoping someone with more knowledge than I may be able to point me down a road I haven’t tried yet to help fix any of these issues mentioned above. I’ll test anything anyone sends my way. gkkpch just want me to mention that I’m using a debian mpd image.

Thanks again gkkpch a huge THUMBS UP to you for all your hard work!

19

The issue has been resolved, a big thank you to the people who helped testing/ verifying.
We will be releasing new images the next few days :smiley:

– Gé –

20

I experience the same issue with Odroid C2. What can I do?