Problems Since Latest Update

dtougas · April 9, 2018, 7:15pm

So, Volumio was working great for me up until the last update. The first problem I encountered is the CIFS mount version defaulting to 3.0, and my NAS not having that version enabled. I finally fixed that by enabling 3.0 on my NAS, and I can now mount my network file share.

The next problem I have is that it will not scan my whole library. I only have about 7K songs, and the scan process starts, but never finishes. It will start, I will see things start to appear in my library, but then after a while during the scan process, my library will go blank. Also, during the scan process in my music settings, I will see the numbers of artists/albums/songs gradually tick upwards, then everything will report zero and stay at zero.

Once the blank/zero problem happens, my library will be empty. I am also unable to browse anything, as Browse/Music Library just shows a blank page.

For fun, I decided to try putting my music library on a thumb-drive, to see if it was a problem with my network. I have exactly the same problem… it will start scanning my music on USB, then crash, report zero, and show a blank library.

I can still play muisc via the media server on my NAS, but I cannot get Volumio to build a library. I have tried re-imaging my MicroSD card and starting fresh a couple time, and always the same result.

Any thoughts on what might be going on here?

chsims1 · April 9, 2018, 7:24pm

Can you produce a system log or generate an online log with ssh and “sudo journalctl -f” while the indexing is taking place?

dtougas · April 9, 2018, 11:05pm

OK, I ran journalctl via an SSH session while it happened, this is what the output shows when it fails:

...
Apr 09 23:00:07 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Apr 09 23:00:08 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares
Apr 09 23:00:11 volumio systemd[1]: mpd.service: main process exited, code=killed, status=11/SEGV
Apr 09 23:00:11 volumio systemd[1]: Unit mpd.service entered failed state.
Apr 09 23:00:11 volumio volumio[869]: error: Upnp client error: Error: This socket has been ended by the other party
Apr 09 23:00:11 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Apr 09 23:00:11 volumio volumio[869]: error: MPD error: Error: This socket has been ended by the other party
Apr 09 23:00:11 volumio volumio[869]: error: MPD error: Error: This socket has been ended by the other party
Apr 09 23:00:11 volumio volumio[869]: error: MPD error: Error: This socket has been ended by the other party
Apr 09 23:00:15 volumio kernel: Voltage normalised (0x00000000)
Apr 09 23:00:15 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Apr 09 23:00:15 volumio volumio[869]: error: MPD error: Error: This socket has been ended by the other party
Apr 09 23:00:15 volumio volumio[869]: error: MPD error: Error: This socket has been ended by the other party
Apr 09 23:00:15 volumio volumio[869]: error: MPD error: Error: This socket has been ended by the other party
Apr 09 23:00:16 volumio systemd[1]: Starting Music Player Daemon...
Apr 09 23:00:19 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Apr 09 23:00:21 volumio kernel: Under-voltage detected! (0x00050005)
Apr 09 23:00:23 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Apr 09 23:00:25 volumio kernel: Voltage normalised (0x00000000)
Apr 09 23:00:38 volumio systemd[1]: Started Music Player Daemon.
...

I am not familiar enough with Raspberry Pi, are those voltage messages normal? Part of the problem?

dtougas · April 10, 2018, 12:37am

OK, I have done some more troubleshooting. I replaced the power supply, I am no longer getting the low voltage error. I also turned-off the media server on my NAS to eliminate that as a variable (I thought it might be trying to scan the media server, which is why it was getting socket errors?)

I am getting the problem consistently, and it is happening when it gets to the 81st artist in my NAS collection. Could there be a file issue, that is causing mpd to crash? Here is another log message from journalctl, with a little more info:

...
Apr 10 00:32:20 volumio volumio[882]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Apr 10 00:32:22 volumio volumio[882]: error: Upnp client error: Error: read ECONNRESET
Apr 10 00:32:22 volumio systemd[1]: mpd.service: main process exited, code=killed, status=11/SEGV
Apr 10 00:32:22 volumio systemd[1]: Unit mpd.service entered failed state.
Apr 10 00:32:24 volumio volumio[882]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
...

chsims1 · April 10, 2018, 12:43pm

mpd can be a bit picky with file type/problems. Have you tried temporarily removing files to see if the indexing continues.

fafa · May 26, 2018, 10:09am

Since upgrade to 2.389 , I have a similar trouble that I am unable to reach music on the USB drive ( plugged since 1,5 year on my RPi3 where I put all my music) .

lsub do not see the drive

And dmesg returns “low voltage”

[12238.773418] Under-voltage detected! (0x00050005) [12241.268502] scsi 0:0:0:0: Direct-Access HGST 0000 PQ: 0 ANSI: 6 [12241.282689] sd 0:0:0:0: Attached scsi generic sg0 type 0 [12253.387728] sd 0:0:0:0: [sda] Spinning up disk... [12264.533508] . [12277.733555] . [12290.933664] . [12304.133700] . [12317.333757] . [12330.533829] . [12343.733899] . [12356.933963] . [12370.134035] . [12370.134045] not responding... [12400.333016] sd 0:0:0:0: [sda] Read Capacity(10) failed: Result: hostbyte=0x00 driverbyte=0x08 [12400.333036] sd 0:0:0:0: [sda] Sense Key : 0x2 [current] [12400.333047] sd 0:0:0:0: [sda] ASC=0x4 ASCQ=0x1 [12400.333064] sd 0:0:0:0: [sda] 0 512-byte logical blocks: (0 B/0 B) [12400.333074] sd 0:0:0:0: [sda] 0-byte physical blocks [12410.432234] sd 0:0:0:0: [sda] Test WP failed, assume Write Enabled [12420.531547] sd 0:0:0:0: [sda] Asking for cache data failed [12420.531560] sd 0:0:0:0: [sda] Assuming drive cache: write through [12438.710352] sd 0:0:0:0: [sda] Spinning up disk... [12459.974489] . [12484.214630] . [12500.374706] . [12513.574763] . [12526.774885] . [12539.974901] . [12553.174982] . [12566.375036] . [12566.375044] not responding... [12596.663858] sd 0:0:0:0: [sda] Read Capacity(10) failed: Result: hostbyte=0x00 driverbyte=0x08

As well : I changed PSU and plug it in another place in home and got the same.
I also tested with another USB and test on other USB ports : no progress
I also tested the USB disk on other devices ( TV, PC, Xbox,… ) : no issue

here is system log:

logs.volumio.org/volumio/oClBO1T.html

I really hope it helps !