Mounted network drive not scanned

Help and Support Help
1

Hi !

I mounted my NAS via the web UI on the last version of volumio.
It properly appears under /media/NAS/ and all the files are there.
But it seems like mpd fails to scan the content.
Running mpc --wait update returns immediately, and there is no file scanned.
And the last scan date stays the same ( = the installation date)

I know I have accented characters everywhere in my disk file names, but I read this had been solved on volumio’s github.

Could anyone tell me how to produce logs that could lead us to a proper diagnosis ?

Thanks in advance !

2

Do

sudo journalctl -f

just before mounting your drive. Then paste the output here… thanks

3

Just before :
Before I mount my drive :


Sep 19 07:54:17 volumio systemd[1]: Started User Manager for UID 1000.
Sep 19 07:54:17 volumio sshd[1856]: pam_env(sshd:session): Unable to open env file: /etc/default/locale: No such file or directory
Sep 19 07:54:17 volumio sshd[1856]: lastlog_openseek: Couldn't stat /var/log/lastlog: No such file or directory
Sep 19 07:54:17 volumio sshd[1856]: lastlog_openseek: Couldn't stat /var/log/lastlog: No such file or directory
Sep 19 07:54:20 volumio volumio[596]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Sep 19 07:54:24 volumio volumio[596]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Sep 19 07:54:28 volumio volumio[596]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Sep 19 07:54:32 volumio volumio[596]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Sep 19 07:54:33 volumio sudo[1950]: volumio : TTY=pts/0 ; PWD=/home/volumio ; USER=root ; COMMAND=/bin/journalctl -f
Sep 19 07:54:33 volumio sudo[1950]: pam_unix(sudo:session): session opened for user root by volumio(uid=0)
Sep 19 07:54:37 volumio volumio[596]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Sep 19 07:54:40 volumio volumio[596]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Sep 19 07:54:44 volumio volumio[596]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats

And after :

Sep 19 07:55:17 volumio volumio[596]: info: [1474271717373] ------------------------------ 100ms Sep 19 07:55:17 volumio volumio[596]: info: [1474271717377] ------------------------------ 94ms Sep 19 07:55:17 volumio volumio[596]: info: Pushing Favourites {"service":"mpd","uri":"","favourite":false} Sep 19 07:55:17 volumio volumio[596]: info: Pushing Favourites {"service":"mpd","uri":"","favourite":false} Sep 19 07:55:17 volumio volumio[596]: info: Pushing Favourites {"service":"mpd","uri":"","favourite":false} Sep 19 07:55:17 volumio volumio[596]: info: Pushing Favourites {"service":"mpd","uri":"","favourite":false} Sep 19 07:55:18 volumio volumio[596]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Sep 19 07:55:20 volumio volumio[596]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 19 07:55:21 volumio sudo[2196]: volumio : TTY=pts/0 ; PWD=/home/volumio ; USER=root ; COMMAND=/bin/journalctl -f Sep 19 07:55:21 volumio sudo[2196]: pam_unix(sudo:session): session opened for user root by volumio(uid=0) Sep 19 07:55:24 volumio volumio[596]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 19 07:55:28 volumio volumio[596]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 19 07:55:32 volumio volumio[596]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats cSep 19 07:55:37 volumio volumio[596]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats

4

Forgot to say, but before I mount the drive, the volumio distribution is freshly flashed and nothing has been done (not even configuring the network).
I use the last release (august), the network drive is CIFS, and my pi is wired via ethernet to my router.

Also, in /mnt/NAS/Datastation/, the accented characters appear with question marks : “Ang??lo Debarre & Tchavolo Schmitt” (for Angélo).
When I plug my USB drive on my Volumio pi, everything works fine.
When I access my NAS with windows, all accented characters are fine.

5

I have a similar problem like you.

My Volumio setup picks up my NAS drive, starts to scan it but stops soon after, having scanned only a small part of my 4TB NAS.

At first I thought it might be some incompatibility issue with RPi3 and for that reason, I tried my luck with a RPi2.
Stability is better with RPi2 but the problem persists.

6

@gtj : not exactly the same problem as mine doesn’t scan anything :

[code]volumio@volumio:~$ mpc stats
Artists: 0
Albums: 0
Songs: 0

Play Time: 0 days, 0:00:00
Uptime: 0 days, 4:42:59
DB Updated: Sat Aug 20 16:39:30 2016
DB Play Time: 0 days, 0:00:00[/code]

7

You’re right. It’s a similar problem.
I just thought I’d post here instead of creating a new subject.
The strange thing in my case is that it stops scanning at the exact same point every time (232 artists).

If Angelo needs it, I can post my output here as well.

Sorry if I messed with your issue. Just did it for the economy of the forum.

I hope there will be a solution soon as Volumio is amazing and it’s a shame we can’t use it with our NAS servers.

8

I think the last issue is due to ffmpeg, we will solve it when new version of MPD will be available in debian Jessie repo…

As for the first one, do you use NFS or CIFS?

9

Nice one.
Hope it won’t be long now. I’ll keep my eyes peeled.

Thanks for the excellent work you have put on this great project!

10

CIFS :slight_smile:

11

Don’t know if it helps but my first folder is named :

°°°aaa°°°

and in the terminal it appears like this :

???aaa???
12

So sorry, I didn’t understand what you were asking for (printed the output before mounting, stopped the command and printed the output after mounting :stuck_out_tongue: ).
So here is a fresh new test with the command launched before mounting and all the output until the mounting stopped :

volumio@volumio:~$ sudo journalctl -f 
-- Logs begin at Sat 2016-08-20 16:39:20 UTC. --
Sep 20 13:22:06 volumio systemd[8747]: Reached target Basic System.
Sep 20 13:22:06 volumio systemd[8747]: Starting Default.
Sep 20 13:22:06 volumio systemd[8747]: Reached target Default.
Sep 20 13:22:06 volumio systemd[8747]: Startup finished in 31ms.
Sep 20 13:22:06 volumio systemd[1]: Started User Manager for UID 1000.
Sep 20 13:22:06 volumio sshd[8726]: pam_env(sshd:session): Unable to open env file: /etc/default/locale: No such file or directory
Sep 20 13:22:07 volumio sshd[8726]: lastlog_openseek: Couldn't stat /var/log/lastlog: No such file or directory
Sep 20 13:22:07 volumio sshd[8726]: lastlog_openseek: Couldn't stat /var/log/lastlog: No such file or directory
Sep 20 13:22:18 volumio sudo[8806]: volumio : TTY=pts/0 ; PWD=/home/volumio ; USER=root ; COMMAND=/bin/journalctl -f
Sep 20 13:22:18 volumio sudo[8806]: pam_unix(sudo:session): session opened for user root by volumio(uid=0)
Sep 20 13:22:31 volumio volumio[602]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
Sep 20 13:22:31 volumio volumio[602]: info: CoreCommandRouter::volumioGetState
Sep 20 13:22:31 volumio volumio[602]: info: [1474377751066] CoreStateMachine::getState
Sep 20 13:22:31 volumio volumio[602]: info: [1474377751068] CorePlayQueue::getTrack 0
Sep 20 13:22:31 volumio volumio[602]: info:
Sep 20 13:22:31 volumio volumio[602]: [1474377751070] ---------------------------- Client requests Volumio state
Sep 20 13:22:31 volumio volumio[602]: info: [1474377751075] Listing playlists
Sep 20 13:22:31 volumio volumio[602]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Sep 20 13:22:31 volumio volumio[602]: Plugin multiroom or method getMultiroom not found
Sep 20 13:22:31 volumio volumio[602]: info:
Sep 20 13:22:31 volumio volumio[602]: [1474377751081] ---------------------------- Client requests Menu Items
Sep 20 13:22:31 volumio volumio[602]: info: [1474377751082] InterfaceWebUI::pushState
Sep 20 13:22:31 volumio volumio[602]: info: [1474377751087] ------------------------------ 23ms
Sep 20 13:22:31 volumio volumio[602]: info: [1474377751095] ------------------------------ 14ms
Sep 20 13:22:38 volumio volumio[602]: info: CoreCommandRouter::getUIConfigOnPlugin
Sep 20 13:22:38 volumio volumio[602]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Sep 20 13:22:38 volumio volumio[602]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares
Sep 20 13:22:42 volumio volumio[602]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Sep 20 13:22:43 volumio volumio[602]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares
Sep 20 13:22:46 volumio volumio[602]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Sep 20 13:22:50 volumio volumio[602]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Sep 20 13:22:54 volumio volumio[602]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Sep 20 13:22:58 volumio volumio[602]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Sep 20 13:23:02 volumio volumio[602]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Sep 20 13:23:06 volumio volumio[602]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Sep 20 13:23:07 volumio volumio[602]: info: CoreCommandRouter::executeOnPlugin: networkfs , addShare
Sep 20 13:23:07 volumio volumio[602]: info: Adding a new share
Sep 20 13:23:07 volumio volumio[602]: info: No correspondence found in configuration for share Datastation on IP datastation.local
Sep 20 13:23:07 volumio sudo[9012]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto //datastation.local/Datastation Drives SMB /mnt/NAS/Datastation
Sep 20 13:23:07 volumio sudo[9012]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 20 13:23:07 volumio kernel: FS-Cache: Netfs 'cifs' registered for caching
Sep 20 13:23:07 volumio kernel: Key type cifs.spnego registered
Sep 20 13:23:07 volumio kernel: Key type cifs.idmap registered
Sep 20 13:23:07 volumio sudo[9012]: pam_unix(sudo:session): session closed for user root
Sep 20 13:23:07 volumio mpd[637]: client: [2] opened from local
Sep 20 13:23:07 volumio mpd[637]: client: [2] closed
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787566] ControllerMpd::sendMpdCommand status
Sep 20 13:23:07 volumio volumio[602]: info: Mpd Status Update: update
Sep 20 13:23:07 volumio volumio[602]: info:
Sep 20 13:23:07 volumio volumio[602]: [1474377787574] ---------------------------- MPD announces state update
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787579] sending command...
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787581] ControllerMpd::getState
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787583] ControllerMpd::sendMpdCommand status
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787583] sending command...
Sep 20 13:23:07 volumio mpd[637]: errno: Failed to open 'NAS/Datastation/Media': Permission denied
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787594] Database update started
Sep 20 13:23:07 volumio volumio[602]: COMMON.MY_MUSIC
Sep 20 13:23:07 volumio volumio[602]: [ 'COMMON', 'MY_MUSIC' ]
Sep 20 13:23:07 volumio volumio[602]: COMMON.SCAN_DB
Sep 20 13:23:07 volumio volumio[602]: [ 'COMMON', 'SCAN_DB' ]
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787610] ControllerMpd::sendMpdCommand status
Sep 20 13:23:07 volumio volumio[602]: info: Mpd Status Update: update
Sep 20 13:23:07 volumio volumio[602]: info:
Sep 20 13:23:07 volumio volumio[602]: [1474377787612] ---------------------------- MPD announces state update
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787614] sending command...
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787616] ControllerMpd::getState
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787617] ControllerMpd::sendMpdCommand status
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787618] sending command...
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787620] parsing response...
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787622] parsing response...
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787623] parsing response...
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787626] ControllerMpd::parseState
Sep 20 13:23:07 volumio volumio[602]: info: Command Router : Notfying DB Updatefalse
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787630] ControllerMpd::parseState
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787631] ControllerMpd::parseState
Sep 20 13:23:07 volumio volumio[602]: info: Command Router : Notfying DB Updatefalse
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787634] ControllerMpd::pushState
Sep 20 13:23:07 volumio volumio[602]: info: CoreCommandRouter::servicePushState
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787639] CoreStateMachine::syncState
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787640] CorePlayQueue::getTrack 0
Sep 20 13:23:07 volumio volumio[602]: info: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null}
Sep 20 13:23:07 volumio volumio[602]: info: CURRENT POSITION 0
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787642] CoreStateMachine::syncState   stateService stop
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787642] CoreStateMachine::syncState   currentStatus stop
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787643] CoreStateMachine::pushState
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787643] CoreStateMachine::getState
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787644] CorePlayQueue::getTrack 0
Sep 20 13:23:07 volumio volumio[602]: info: CoreCommandRouter::volumioPushState
Sep 20 13:23:07 volumio volumio[602]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787646] InterfaceWebUI::pushState
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787648] No code
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787649] CoreStateMachine::pushState
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787649] CoreStateMachine::getState
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787650] CorePlayQueue::getTrack 0
Sep 20 13:23:07 volumio volumio[602]: info: CoreCommandRouter::volumioPushState
Sep 20 13:23:07 volumio volumio[602]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787652] InterfaceWebUI::pushState
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787657] ------------------------------ 84ms
Sep 20 13:23:07 volumio volumio[602]: info: Pushing Favourites {"service":"mpd","uri":"","favourite":false}
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787663] parsing response...
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787664] ControllerMpd::parseState
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787665] ControllerMpd::pushState
Sep 20 13:23:07 volumio volumio[602]: info: CoreCommandRouter::servicePushState
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787666] CoreStateMachine::syncState
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787666] CorePlayQueue::getTrack 0
Sep 20 13:23:07 volumio volumio[602]: info: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null}
Sep 20 13:23:07 volumio volumio[602]: info: CURRENT POSITION 0
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787669] CoreStateMachine::syncState   stateService stop
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787669] CoreStateMachine::syncState   currentStatus stop
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787670] CoreStateMachine::pushState
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787670] CoreStateMachine::getState
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787671] CorePlayQueue::getTrack 0
Sep 20 13:23:07 volumio volumio[602]: info: CoreCommandRouter::volumioPushState
Sep 20 13:23:07 volumio volumio[602]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787672] InterfaceWebUI::pushState
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787675] No code
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787675] CoreStateMachine::pushState
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787676] CoreStateMachine::getState
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787676] CorePlayQueue::getTrack 0
Sep 20 13:23:07 volumio volumio[602]: info: CoreCommandRouter::volumioPushState
Sep 20 13:23:07 volumio volumio[602]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787684] InterfaceWebUI::pushState
Sep 20 13:23:07 volumio volumio[602]: info: [1474377787691] ------------------------------ 80ms
Sep 20 13:23:07 volumio volumio[602]: info: Pushing Favourites {"service":"mpd","uri":"","favourite":false}
Sep 20 13:23:07 volumio volumio[602]: info: Pushing Favourites {"service":"mpd","uri":"","favourite":false}
Sep 20 13:23:07 volumio volumio[602]: info: Pushing Favourites {"service":"mpd","uri":"","favourite":false}
Sep 20 13:23:08 volumio volumio[602]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares
Sep 20 13:23:10 volumio volumio[602]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Sep 20 13:23:14 volumio volumio[602]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Sep 20 13:23:18 volumio volumio[602]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Sep 20 13:23:22 volumio volumio[602]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats

So I think the relevant log here is :

Sep 20 13:23:07 volumio mpd[637]: errno: Failed to open 'NAS/Datastation/Media': Permission denied

Any idea why this happens ?

As user volumio I’m able to browse this folder with no problem, can’t understand why this happens to me but everyone seems to be able to mount his CIFS share :’(

Thanks for your attention !

13

On my other pi, I have my USB drive shared this way with samba :

[Datastation Drives SMB] comment=Raspberry Pi Share path=/media/pi/ browseable=Yes writeable=Yes only guest=no create mask=0777 directory mask=0777 public=yes force user=pi

With this configuration, I’m able to write and browse without login from Windows.
On my volumio pi, all my network drive folders have rights drwx------ 1 volumio volumio so everything is ok for user volumio, but other users have no rights on them.
Shouldn’t mpd be run by user volumio ?
Or maybe the mounting command should be different so that mpd could access the folders ?

Sep 20 13:23:07 volumio sudo[9012]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto //datastation.local/Datastation Drives SMB /mnt/NAS/Datastation

I still don’t understand why it seems I’m the only one to have this problem.

14

Ok, so my conclusion is that for Volumio to browse a network drive, it must expose proper rights to be browsable by anyone (maybe only volumio’s group, didn’t try that).
As my USB drive is NTFS and pcmanfm mounts it with 700 permissions on my raspbian, I have to unmount it and remount with the proper rights :

sudo su
umount /dev/sda2
mkdir /media/pi/Media
chmod 777 /media/pi/Media
mount -t ntfs-3g /dev/sda2 /media/pi/Media -o fmask=0000,dmask=0000,umask=0000

I understand this is not exactly a Volumio issue , for my experience it would have been better if it would have worked immediately, but I think it’s a very rare case :slight_smile:
It would be solved by making mpd run under volumio user, but I think there’s a good reason this is not done this way…?

Anyone knowing how make pcmanfm automount NTFS drives with custom permissions is welcome :wink:

15

I am noticing that mounting via NFS is also seeming to have some unusual permissions with Volumio 2. I am wondering if these are perhaps related to the library scanning problem here:
volumio-029-drops-connection-cubox-t5150.html

I notice that with the drive unmounted, I see “volumio” as the owner and group of the share directory, with 777 permissions.

Then, when I use the web UI to mount the drive, it gets mounted as read only even if I have the NFS export set as RW on my NAS. Also, instead of mounting the NFS drive under the volumio user, it shows the drive mounted as user “messagebus” in the “audio” group.

Scanning the library from there works - if you watch the journal it is parsing files and adding them. But, as others have reported, at some point the scan halts and locks up the system… if someone who knows how to configure Volumio’s mounting scripts that are used on boot and in the web UI, perhaps we can try some fixes to the mount commands that may address the problem?