Thank you for your donation!


Cloudsmith graciously provides open-source package management and distribution for our project.


Problem: Not starting after reboot
#11
(03-08-2020, 08:40 AM)vinnn Wrote:
(03-07-2020, 10:27 PM)japumpy Wrote:  Just reporting back. Sorry it's taken a while. I've been struggling a bit with getting the database to build. I've made up 3 SD card images to test. The one that I'm using is a new-ish card that has the latest and greatest MoOde installed. Installation was perfect; I added my NAS to the system (Synology DS918+).
In the default settings, the system is able to mount the NAS and 'see's' the directory where my media is. It parses the first directory completely and then stops. When I try to look at what's been registered I can see the tracks and I can play them ok. However, later when I try and look at the NAS directory, the NAS has disappeared from the system. I've tried to 'REGEN' the database with the same results.
I have also tried experimenting with changing the mount flags with the following values:
-vers = 1.0 - NAS mounts ok but only parses one directory and on subsequent look, the NAS doesn't appear to be mounted.
-vers = 2.0 - as above
-vers =3.0/3.1 - NAS doesn't mount
-vers = default - NAS doesn't mount

Removing vers -  the NAS doesn't mount at all.

Please accept my apologies if I've posted this message in the wrong thread.

You haven't said what protocol you're mounting with, I'm guessing NFS?
Is the Pi's network connection wired or wireless?
Are you mounting the nas by hostname or IP address?

Did you read test your sd card?
My apologies. SMB mounting with IP address always.
I haven't done a read test as yet. Although I have experienced this on a number of cards now some of which are quite new with similar issues.
The connection is wireless at the moment. However, I take your point and I'll try and find a spare port ;-)
Thanks for educating me in what else to specify in future posts.
Cheers!
Reply
#12
(03-08-2020, 09:52 AM)TookaFace Wrote: I had those kind of problem since moOde 5 series, randomly when reboot or power failure, it failed to reboot, systemd goes to emergency mode.

I finally found the problem, im using SD CARD 200go, and when fsck run at boot, it take ~3 minutes to check the card, but Systemd, by default, goes to emergency mode after 90s of waiting. I tried with many sdcard (SANDISK, class 10) and pi, and each time same problem.

So the answer was this:
Code:
sudo nano /etc/fstab

Add x-systemd.device-timeout=10min to /boot partition
Code:
PARTUUID=6c586e13-01  /boot           vfat    defaults,x-systemd.device-timeout=10min          0       2

And problem was gone.

Im not sure it's the same for you, since you're using smaller SD CARD, but the symptoms match, so it could be worth trying.
Thanks for that. I'm ashamed to say that I'm having some issues in running ssh on my Win 10 machine. I'm getting some unexpected results when I try to log in. Still trying to understand (from my limited perspective) what I'm doing wrong :-) However, I will indeed try what you have discuovered once I've overcome my present issue. Thank you very much.
BTW I'm using Sandisk & Emtech cards all of differing sizes (not that it matters).
Cheers!
Reply
#13
Well it's 1.5 years later. ;-) Same RPi that I've been using for other things. Just recently built an amplifier and bought myself a new SMSL D0200 DAC. So I thought I'd give the latest MoOde a try! I programmed two different cards of differing sizes and booted. Once configured, the system starts to build it's library and then, for no apparent reason, it stops dead. I then notice that the NAS has disappeared from the library list. The same result happens upon rebuild even though the NAS isn't showing on the 'browse by folders' list.
  • RPi 3b
  • PSU 5Amps
  • Wired network
  • NAS configuration is with IP address and not domain
  • moode-r761-iso
  • Number of tracks ~73,000
Any help would be appreciated. I'm keen on using MoOde for all playback in the house and I have no wish to use Volumio. :-)

Just had a thought around file permissions. I'll recheck these in a min.

I've just noticed that the subject of this thread is inconsistent with this issue. If necessary I can create another thread with an appropriate subject header.

Cheers
Reply
#14
Post the Moode startup log.

Code:
moodeutl -l
Enjoy the Music!
moodeaudio.org | Mastodon Feed | GitHub
Reply
#15
(03-07-2022, 01:22 AM)Tim Curtis Wrote:
Code:
20220306 175531 worker: -- Start
20220306 175532 worker: Successfully daemonized
20220306 175532 worker: Integrity check (passed)
20220306 175534 worker: File check (OK)
20220306 175534 worker: Session vacuumed
20220306 175535 worker: Session loaded
20220306 175535 worker: Debug logging (OFF)
20220306 175535 worker: -- Audio debug
20220306 175535 worker: ALSA cards: (0:b1 | 1:Headphones | 2:empty | 3:empty
20220306 175535 worker: MPD config: (2:SMSL USB AUDIO | mixer:(PCM) | card:2)
20220306 175535 worker: WARNING: No device found at MPD configured card 2
20220306 175536 worker: -- System
20220306 175537 moode.php: MPD connect failed: cmd=(playlist)
20220306 175538 worker: Host     (moode)
20220306 175538 worker: moOde    (7.6.1 2021-12-17)
20220306 175538 worker: RaspiOS  (10.6)
20220306 175538 worker: Kernel   (5.4.77-v8+ #1371)
20220306 175538 worker: Platform (Pi-3B 1.2 1GB)
20220306 175538 worker: ARM arch (aarch64, 64-bit kernel)
20220306 175538 worker: MPD ver  (0.23.4_p0x3)
20220306 175538 worker: CPU gov  (performance)
20220306 175538 worker: USB boot enabled
20220306 175538 worker: File system expanded
20220306 175538 worker: HDMI port on
20220306 175538 worker: -- Network
20220306 175538 worker: IP address check timeout (90 secs)
20220306 175538 worker: eth0 adapter exists
20220306 175538 worker: eth0 IP address check (No)
20220306 175538 worker: IP addr (192.168.10.222)
20220306 175538 worker: Netmask (255.255.255.0)
20220306 175538 worker: Gateway (192.168.10.254)
20220306 175538 worker: Pri DNS (1.1.1.1)
20220306 175538 worker: Domain  (8.8.8.8)
20220306 175538 worker: wlan0 adapter exists
20220306 175538 worker: wifi country (NZ)
20220306 175538 worker: wlan0 trying SSID (Naseem Wifi)
20220306 175538 worker: wlan0 wait 0 for IP address
20220306 175540 worker: wlan0 wait 1 for IP address
20220306 175543 worker: wlan0 wait 2 for IP address
20220306 175545 worker: wlan0 wait 3 for IP address
20220306 175547 worker: wlan0 wait 4 for IP address
20220306 175604 worker: wlan0 wait 5 for IP address
20220306 175606 worker: wlan0 wait 6 for IP address
20220306 175608 worker: wlan0 wait 7 for IP address
20220306 175610 worker: wlan0 wait 8 for IP address
20220306 175612 worker: wlan0 wait 9 for IP address
20220306 175614 worker: wlan0 wait 10 for IP address
20220306 175616 worker: wlan0 wait 11 for IP address
20220306 175618 worker: wlan0 wait 12 for IP address
20220306 175621 worker: wlan0 wait 13 for IP address
20220306 175623 worker: wlan0 wait 14 for IP address
20220306 175625 worker: wlan0 wait 15 for IP address
20220306 175627 worker: wlan0 wait 16 for IP address
20220306 175629 worker: wlan0 wait 17 for IP address
20220306 175631 worker: wlan0 wait 18 for IP address
20220306 175633 worker: wlan0 wait 19 for IP address
20220306 175635 worker: wlan0 wait 20 for IP address
20220306 175637 worker: wlan0 wait 21 for IP address
20220306 175639 worker: wlan0 wait 22 for IP address
20220306 175641 worker: wlan0 wait 23 for IP address
20220306 175643 worker: wlan0 wait 24 for IP address
20220306 175645 worker: wlan0 wait 25 for IP address
20220306 175647 worker: wlan0 wait 26 for IP address
20220306 175649 worker: wlan0 wait 27 for IP address
20220306 175651 worker: wlan0 wait 28 for IP address
20220306 175653 worker: wlan0 wait 29 for IP address
20220306 175655 worker: wlan0 wait 30 for IP address
20220306 175657 worker: wlan0 wait 31 for IP address
20220306 175659 worker: wlan0 wait 32 for IP address
20220306 175701 worker: wlan0 wait 33 for IP address
20220306 175703 worker: wlan0 wait 34 for IP address
20220306 175705 worker: wlan0 wait 35 for IP address
20220306 175707 worker: wlan0 wait 36 for IP address
20220306 175709 worker: wlan0 wait 37 for IP address
20220306 175711 worker: wlan0 wait 38 for IP address
20220306 175713 worker: wlan0 wait 39 for IP address
20220306 175715 worker: wlan0 wait 40 for IP address
20220306 175717 worker: wlan0 wait 41 for IP address
20220306 175719 worker: wlan0 wait 42 for IP address
20220306 175722 worker: wlan0 wait 43 for IP address
20220306 175724 worker: wlan0 wait 44 for IP address
20220306 175726 worker: wlan0 no IP addr for SSID (Naseem Wifi)
20220306 175726 worker: eth0 address exists so AP mode not started
20220306 175726 worker: wlan0 address not assigned
20220306 175726 worker: Pi integrated wlan0 power save disabled
20220306 175726 worker: -- Audio config
20220306 175726 worker: MPD conf update skipped (USB device)
20220306 175726 worker: ALSA card number (2)
20220306 175726 worker: MPD audio output (SMSL USB AUDIO)
20220306 175726 worker: WARNING: No device found at MPD configured card 2
20220306 175726 worker: ALSA mixer name (PCM)
20220306 175726 worker: MPD mixer type (fixed 0dB)
20220306 175726 worker: Hdwr volume controller exists
20220306 175726 worker: Max ALSA volume (100%)
20220306 175726 worker: ALSA output mode (Default: plughw)
20220306 175726 worker: ALSA loopback (Off)
20220306 175726 worker: Reset renderer active flags
20220306 175726 worker: CamillaDSP (off)
20220306 175726 worker: -- MPD startup
20220306 175726 worker: MPD started
20220306 175727 worker: MPD accepting connections
20220306 175727 worker: MPD output 1 ALSA Default (on)
20220306 175727 worker: MPD output 2 ALSA Bluetooth (off)
20220306 175727 worker: MPD output 3 HTTP Server (off)
20220306 175727 worker: MPD crossfade (off)
20220306 175727 worker: MPD ignore CUE files (yes)
20220306 175727 worker: -- Feature availability
20220306 175727 worker: Source select (available)
20220306 175727 worker: Source select (source: MPD)
20220306 175727 worker: Source select (output: SMSL USB AUDIO)
20220306 175732 worker: Bluetooth (available: started)
20220306 175732 worker: Airplay renderer (available)
20220306 175732 worker: Spotify renderer (available: started)
20220306 175732 worker: Squeezelite (available)
20220306 175732 worker: RoonBridge renderer (not installed)
20220306 175732 worker: Multiroom sender (available)
20220306 175732 worker: Multiroom receiver (available)
20220306 175732 worker: UPnP renderer (available: started)
20220306 175732 worker: DLNA server (available)
20220306 175732 worker: UPnP browser (available)
20220306 175732 worker: GPIO button handler (available)
20220306 175732 worker: Stream recorder (n/a)
20220306 175732 worker: -- Music sources
20220306 175732 worker: USB sources (none attached)
20220306 175733 worker: NAS and UPnP sources (mountall initiated)
20220306 175733 worker: -- Other
20220306 175733 worker: USB volume knob (Off)
20220306 175733 worker: USB auto-mounter (udisks-glue)
20220306 175733 worker: LED0 (On)
20220306 175733 worker: LED1 (On)
20220306 175733 worker: Saved MPD vol level (0)
20220306 175733 worker: Preamp volume level (0)
20220306 175733 worker: MPD volume level (0) restored
20220306 175733 worker: ALSA PCM volume (Invalid card number.)
20220306 175733 worker: Auto-play (Off)
20220306 175733 worker: LocalUI started
20220306 175733 worker: Maintenance interval (3 hours)
20220306 175733 worker: Screen saver activation (Never)
20220306 175733 worker: Session permissions (OK)
20220306 175734 worker: Watchdog started
20220306 175734 worker: Ready
20220306 190251 watchdog: Info: Reducing PHP fpm worker pool
20220306 200813 watchdog: Info: Reducing PHP fpm worker pool
20220306 211336 watchdog: Info: Reducing PHP fpm worker pool
20220306 222900 watchdog: Info: Reducing PHP fpm worker pool
20220307 112643 watchdog: Info: Reducing PHP fpm worker pool
20220307 123142 watchdog: Info: Reducing PHP fpm worker pool
20220307 133858 worker: Job regen_library
20220307 133859 thmcache: Start
20220307 133859 thmcache: Priority: Embedded cover
20220307 133859 thmcache: Res,Qual: Auto
20220307 133859 thmcache: Px ratio: 1
20220307 133859 thmcache: Th width: 100
20220307 133859 thmcache: Thm qual: 75
20220307 133859 thmcache: Scanning: NAS, SDCARD, UPNP
20220307 134111 thmcache: Done: 1798 folders scanned, 7 thumbs created, 1791 already in cache.
20220307 135012 worker: Job regen_library
20220307 135017 thmcache: Start
20220307 135017 thmcache: Priority: Embedded cover
20220307 135017 thmcache: Res,Qual: Auto
20220307 135017 thmcache: Px ratio: 1
20220307 135017 thmcache: Th width: 100
20220307 135017 thmcache: Thm qual: 75
20220307 135017 thmcache: Scanning: NAS, SDCARD, UPNP
20220307 135017 watchdog: Info: Reducing PHP fpm worker pool
20220307 135233 thmcache: Done: 1798 folders scanned, 7 thumbs created, 1791 already in cache.
20220307 135544 watchdog: Error: MPD restarted (check syslog for errors)
20220307 135543 moode.php: MPD connect failed: cmd=(playlist)
20220307 135543 moode.php: MPD connect failed: cmd=(playlist)
20220307 135558 worker: Job regen_library done
20220307 135728 worker: Job update_library
20220307 135728 mpdindex: Start
20220307 135728 thmcache: Start
20220307 135728 thmcache: Priority: Embedded cover
20220307 135728 thmcache: Res,Qual: Auto
20220307 135728 thmcache: Px ratio: 1
20220307 135728 thmcache: Th width: 100
20220307 135728 thmcache: Thm qual: 75
20220307 135729 thmcache: Scanning: NAS, SDCARD, UPNP
20220307 135943 thmcache: Done: 1798 folders scanned, 7 thumbs created, 1791 already in cache.
20220307 141355 moode.php: MPD connect failed: cmd=(playlist)
20220307 141354 moode.php: MPD connect failed: cmd=(playlist)
20220307 141355 moode.php: MPD connect failed: cmd=(playlist)
20220307 141357 watchdog: Error: MPD restarted (check syslog for errors)
20220307 141357 mpdindex: Done: indexed  artists,  albums,  songs
20220307 141357 worker: Job update_library done
20220307 141400 moode.php: MPD connect failed: cmd=(loadlib)
20220307 141404 moode.php: MPD connect failed: cmd=(loadlib)
20220307 141404 moode.php: MPD connect failed: cmd=(loadlib)
20220307 143543 worker: Job sourcecfg
20220307 143554 worker: Job regen_library
20220307 143554 thmcache: Start
20220307 143555 thmcache: Priority: Embedded cover
20220307 143555 thmcache: Res,Qual: Auto
20220307 143555 thmcache: Px ratio: 1
20220307 143555 thmcache: Th width: 100
20220307 143555 thmcache: Thm qual: 75
20220307 143555 thmcache: Scanning: NAS, SDCARD, UPNP
20220307 143807 thmcache: Done: 1798 folders scanned, 7 thumbs created, 1791 already in cache.
20220307 144909 watchdog: Info: Reducing PHP fpm worker pool
20220307 145803 moode.php: MPD connect failed: cmd=(playlist)
20220307 145803 moode.php: MPD connect failed: cmd=(playlist)
20220307 145805 watchdog: Error: MPD restarted (check syslog for errors)
20220307 145807 worker: Job regen_library done
20220307 160352 worker: Job regen_library
20220307 160354 thmcache: Start
20220307 160354 thmcache: Priority: Embedded cover
20220307 160354 thmcache: Res,Qual: Auto
20220307 160354 thmcache: Px ratio: 1
20220307 160354 thmcache: Th width: 100
20220307 160354 thmcache: Thm qual: 75
20220307 160354 thmcache: Scanning: NAS, SDCARD, UPNP
20220307 160600 thmcache: Done: 1798 folders scanned, 7 thumbs created, 1791 already in cache.
Post the Moode startup log.

Code:
moodeutl -l
Hi Tim,

Thanks for responding so soon! Much appreciated.
The RPi is currently trying to update the library for the nth time ;-) This is the longest period so far. I did check the permissions on the Synology NAS and made some adjustments. Not sure if this has any bearing on things.
Thanks for your help! 

Cheers,

Kal.
Reply
#16
I've just restarted the device in 32bit to see if this solves anything.
Reply
#17
With 64-bit kernel there are reports that MPD crashes during database update.
Enjoy the Music!
moodeaudio.org | Mastodon Feed | GitHub
Reply
#18
(03-07-2022, 01:18 AM)japumpy Wrote: Well it's 1.5 years later. ;-) Same RPi that I've been using for other things. Just recently built an amplifier and bought myself a new SMSL D0200 DAC. So I thought I'd give the latest MoOde a try! I programmed two different cards of differing sizes and booted. Once configured, the system starts to build it's library and then, for no apparent reason, it stops dead. I then notice that the NAS has disappeared from the library list. The same result happens upon rebuild even though the NAS isn't showing on the 'browse by folders' list.
  • RPi 3b
  • PSU 5Amps
  • Wired network
  • NAS configuration is with IP address and not domain
  • moode-r761-iso
  • Number of tracks ~73,000
...

[Danger - bloviation lies ahead]

Preface: I'm assuming that moOde runs normally when you don't have any external Music Source defined in the Library. (AFAICT you never said.) If you can't boot a fresh image (no 64-bit kernel, please), configure for your DAC, and play the Stereo Test track and various radio stations, then there's a problem with your hardware and/or SD card.

Earlier on you mentioned a Synology NAS. I have a virtual DS3615XS instance running DSM 6.1 in my test environment. I have had no trouble mounting it in moOde using either SMB or NFS shares. With recent releases of moOde it is no longer necessary for me to fiddle with the SMB protocol version in the mount flags irrespective of the protocol setting on the NAS.

-----

Down to business:

Let's pull out some details from this post and your later post of the moOde log.

First, a general observation:

Quote:Number of tracks ~73,000

This is a huge collection for the software and low-powered hardware we're working with. I don't know that one can say with certainty there's an upper bound to what MPD can handle but generally once one gets into the multple tens of thousands of tracks everything gets sluggish even when it does work and several users have reported having various difficulties with collections exceeding 25000 to 50000 tracks.

-----

Next, the symptom 

Quote:Once configured, the system starts to build it's library and then, for no apparent reason, it stops dead

suggests that there is at least one track with corrupted metadata causing MPD to stop scanning. MPD is not very forthcoming with details but you can get a hint from the log file /var/log/mpd/log

When "Update library" is clicked, the MPD log begins accumulating entries like

Code:
Mar 07 07:45 : update: added NAS/OMV-Music/World/Ravi Shankar/In London/03 Ravi Shankar - Raga Ramkali.flac
 
The last such entry will be the last track successfully scanned by MPD, naturally. 

In the case of an abnormal scan, this will be the last track scanned by MPD before it tries to scann the track which caused the halt. If the scan stops in the middle of a particular directory (aka folder) then it should be pretty obvious what the next track is. If, however, the scanning has moved to the beginning of another directory, then some detective work is required to determine what that directory is. As you can imagine, this detective work could be very tedious with 73,000 tracks to sift through.

Once identified, the offending track(s) can then be examined with other tools (starting with mediainfo from the moOde player's command line).

There is a troubleshooting tip on the ArchLinux Wiki for dealing with this issue using a third-party tool such as EasyTAG or kid3. See MPD_hangs_on_first_startup . Again, this will be tedious with so many tracks. I've never looked at more than about 5000 tracks at once using EasyTAG (and it was, you guessed it, tedious).

Note: The presence of certain hidden files and directories (eg, with names beginning with a period, dot, or fullstop, depending on your background) can cause problems with the MPD scan but I'm not seeing typical symptoms.

---

Next

Quote:I then notice that the NAS has disappeared from the library list

Please keep in mind that the Library folder view is not the view of a file manager; it is MPD's view of the database it builds when it scans tracks. This disappearance means MPD has removed information about tracks on the NAS from that database. I expect the SMB share is still mounted in the Linux filesystem (which can be checked using the mount command from the moOde player's command line). 

---

Next, there are curious entries found in the moOde log

Code:
20220306 190251 watchdog: Info: Reducing PHP fpm worker pool
20220306 200813 watchdog: Info: Reducing PHP fpm worker pool
20220306 211336 watchdog: Info: Reducing PHP fpm worker pool
20220306 222900 watchdog: Info: Reducing PHP fpm worker pool
20220307 112643 watchdog: Info: Reducing PHP fpm worker pool
20220307 123142 watchdog: Info: Reducing PHP fpm worker pool

I have no idea what's going on here but maybe @Tim Curtis can comment.

Code:
20220307 145803 moode.php: MPD connect failed: cmd=(playlist)
20220307 145805 watchdog: Error: MPD restarted (check syslog for errors)

Entries like these imply MPD is dying during or after the library scan, which shouldn't be happening. Have you checked /var/log/syslog for errors? If nothing suggestive is found then you might set MPD logging to verbose (in MPD settings), try scanning again, and recheck the /var/log/mpd/log file. Note that this file can grow very large when logging verbosely.

---

Finally, as a test of your basic moOde / NAS connectivity, you could try creating a small Music Source entry from a subdirectory of the NAS's share. 

For example, the hostname of one of my NAS boxes is OMV-HC1. It publishes the music directory on the NAS as a share named Music. In moOde I normally create the Music source from the hostname/share pair OMV-HC1/Music with the MPD name OMV-Music. (That's what you see above in my example taken from the MPD log). This share contains about 6000 tracks.

However, instead of using the main share I can create a small Music Source using any subdirectory of it. For example, I can create the music source named, say, OMV-NewAge from OMV-HC1/Music/NewAge, which contains only 600 tracks. This is a much more convenient number of tracks to test with. BTW, this works with any level subdirectory within the main share.

If you're lucky and the chosen subdirectory contains only "good" tracks, then this source can be used to test that moOde and your NAS can work together. If you are unlucky enough to choose a subdirectory which still causes the MPD scan to fail, then at least you will have an easier time troubleshooting the problem given the smaller number of tracks to examine.

Actually, this divide-and-conquer strategy can be used to identify all offending subdirectories but, again, can be very tedious for big collections.

Good hunting.

Regards,
Kent

PS - I'm not aware of any FOSS tool which comprehensively validates a music library in all its aspects before subjecting MPD to it. I've thought several times about cobbling a script out of the various different tools I do know but it always felt like I would be building a Frankenstein monster. Anyone have a suggestion?
Reply
#19
@Tim Curtis @TheOldPresbyope My deepest thanks to you both for all your help and pointers. Since my last post, I changed the kernel to 32bit and 'divided' the subdirectories to see the result. So far all the different directories have been parsed and appear to be 'intact' - there's been no failure. I've left it running all night and it seems to be stable. I haven't restarted the RPi as yet to see if the original issue is there. I'm assuming all will be good.

It's playing Katie Melua as I type this and it sounds delicious! The DAC is operating as it should. No dropouts (I did notice some during the library update). So far so good.

My next project is to integrate a display and build my 'audiophile' system.

Again, my deepest thanks for your combined support. @TheOldPresbyope your thorough explanation I have taken note of; I'm still learning (at 60!). I will be checking the metadata as I'm a bit of a stickler when it comes down these sorts of things ;-)

If you're ever in the neighbourhood, drop in for a brew!
Reply
#20
@japumpy

Good to hear you're making substantive progress. Enjoying the music is the goal!

Quote:If you're ever in the neighbourhood, drop in for a brew!

I saw country code NZ in your log. If that's for real, would it be North or South Island? I've been to NZ only once, for a week vacationing around Aukland and surrounds (including a trip to Rotorua) plus a one-day business meeting in Wellington, and loved it all. That was decades ago. I'm still hoping to make it back.

Regards,
Kent
Reply


Forum Jump: