slimserver icon indicating copy to clipboard operation
slimserver copied to clipboard

Could not navigate inside folder

Open ioguix opened this issue 2 years ago • 30 comments

Hi all,

First of all, thank you all, very, very very much for your work on LMS ecosystem.

I bought a never used Squeezebox boom (firmware 57) to integrate it in my existing LMS network (v8.3.1, 1676361197, Fri 17 Feb 2023 06:37:09 AM CET and Debian 11 on server side). I faced various bugs I never faced before with my squeezebox touch. So far, I've been able to fix some weirdies on my side (embedded cue sheets) or live with some strange logging bugs and location. I might open a discussion on logging later.

The latest bug is tricky though. I couldn't find what's happening so far.

For some reasons, without any warning, we can not navigate inside a folder anymore, neither from the Boom, nor from the Web UI. When selecting the folder, both are showing details about it, but refuse to navigate inside it. It behaves like the folder was actually a song or a playlist. On the web UI, it shows:

Save to Favorites
File Format: Directory
File Length: 12
Location: /srv/music/Augustin
Date Modified: Sunday, December 31, 2023, 20:14
Local artwork
Lyrics 

Here are what I can find in the logs when this happen:

Jan 02 09:39:28 LMS squeezeboxserver[1158259]: [24-01-02 09:39:28.6120] Slim::Formats::loadTagFormatForType (120) Error: Couldn't load module:  (dir) : [syntax error at (eval 1156) line 1, at EOF
                                                 ]
Jan 02 09:39:28 LMS squeezeboxserver[1158259]: [24-01-02 09:39:28.6135] Slim::Formats::loadTagFormatForType (120) Backtrace:
                                                 
                                                    frame 0: Slim::Utils::Log::logBacktrace (/usr/share/perl5/Slim/Formats.pm line 120)
                                                    frame 1: Slim::Formats::loadTagFormatForType (/usr/share/perl5/Slim/Player/Protocols/File.pm line 409)
                                                    frame 2: Slim::Player::Protocols::File::canSeek (/usr/share/perl5/Slim/Player/Song.pm line 840)
                                                    frame 3: Slim::Player::Song::canDoSeek (/usr/share/perl5/Slim/Player/Song.pm line 810)
                                                    frame 4: Slim::Player::Song::canSeek (/usr/share/perl5/Slim/Player/Song.pm line 393)
                                                    frame 5: Slim::Player::Song::open (/usr/share/perl5/Slim/Player/StreamingController.pm line 1229)
                                                    frame 6: Slim::Player::StreamingController::_Stream (/usr/share/perl5/Slim/Player/StreamingController.pm line 287)
                                                    frame 7: Slim::Player::StreamingController::_eventAction (/usr/share/perl5/Slim/Player/StreamingController.pm line 746)
                                                    frame 8: Slim::Player::StreamingController::_nextTrackReady (/usr/share/perl5/Slim/Player/StreamingController.pm line 700)
                                                    frame 9: Slim::Player::StreamingController::__ANON__ (/usr/share/perl5/Slim/Player/Song.pm line 336)
                                                    frame 10: Slim::Player::Song::getNextSong (/usr/share/perl5/Slim/Player/StreamingController.pm line 705)
                                                    frame 11: Slim::Player::StreamingController::_getNextTrack (/usr/share/perl5/Slim/Player/StreamingController.pm line 961)
                                                    frame 12: Slim::Player::StreamingController::_StopGetNext (/usr/share/perl5/Slim/Player/StreamingController.pm line 287)
                                                    frame 13: Slim::Player::StreamingController::_eventAction (/usr/share/perl5/Slim/Player/StreamingController.pm line 2124)
                                                    frame 14: Slim::Player::StreamingController::play (/usr/share/perl5/Slim/Control/Commands.pm line 1052)
                                                    frame 15: Slim::Control::Commands::playlistJumpCommand (/usr/share/perl5/Slim/Control/Request.pm line 1880)
                                                    frame 16: (eval) (/usr/share/perl5/Slim/Control/Request.pm line 1880)
                                                    frame 17: Slim::Control::Request::execute (/usr/share/perl5/Slim/Control/Request.pm line 877)
                                                    frame 18: Slim::Control::Request::executeRequest (/usr/share/perl5/Slim/Player/Client.pm line 635)
                                                    frame 19: Slim::Player::Client::execute (/usr/share/perl5/Slim/Buttons/Playlist.pm line 231)
                                                    frame 20: Slim::Buttons::Playlist::__ANON__ (/usr/share/perl5/Slim/Hardware/IR.pm line 1103)
                                                    frame 21: Slim::Hardware::IR::executeButton (/usr/share/perl5/Slim/Control/Commands.pm line 288)
                                                    frame 22: Slim::Control::Commands::buttonCommand (/usr/share/perl5/Slim/Control/Request.pm line 1880)
                                                    frame 23: (eval) (/usr/share/perl5/Slim/Control/Request.pm line 1880)
                                                    frame 24: Slim::Control::Request::execute (/usr/share/perl5/Slim/Control/Request.pm line 877)
                                                    frame 25: Slim::Control::Request::executeRequest (/usr/share/perl5/Slim/Player/Client.pm line 635)
                                                    frame 26: Slim::Player::Client::execute (/usr/share/perl5/Slim/Hardware/IR.pm line 1124)
                                                    frame 27: Slim::Hardware::IR::processCode (/usr/share/perl5/Slim/Hardware/IR.pm line 872)
                                                    frame 28: Slim::Hardware::IR::processFrontPanel (/usr/share/perl5/Slim/Hardware/IR.pm line 703)
                                                    frame 29: Slim::Hardware::IR::processIR (/usr/share/perl5/Slim/Control/Commands.pm line 525)
                                                    frame 30: Slim::Control::Commands::irCommand (/usr/share/perl5/Slim/Control/Request.pm line 1880)
                                                    frame 31: (eval) (/usr/share/perl5/Slim/Control/Request.pm line 1880)
                                                    frame 32: Slim::Control::Request::execute (/usr/share/perl5/Slim/Control/Request.pm line 877)
                                                    frame 33: Slim::Control::Request::executeRequest (/usr/share/perl5/Slim/Player/Client.pm line 635)
                                                    frame 34: Slim::Player::Client::execute (/usr/share/perl5/Slim/Hardware/IR.pm line 122)
                                                    frame 35: Slim::Hardware::IR::idle (/usr/sbin/squeezeboxserver line 698)
                                                    frame 36: main::idle (/usr/sbin/squeezeboxserver line 671)
                                                    frame 37: main::main (/usr/sbin/squeezeboxserver line 1210)
Jan 02 09:39:28 LMS squeezeboxserver[1158259]: [24-01-02 09:39:28.6153] Slim::Player::Song::open (424) Error: Couldn't create command line for dir playback for [tmp:///srv/music/Augustin]

We were able to navigate inside the folder few minutes before this exact error shows up. I'm not sure how to reproduce it.

I have decent skills in perl and system. We can go technical if needed. I just need directions.

Thanks!

ioguix avatar Jan 02 '24 09:01 ioguix

First of all: check permissions on that folder. Second please try to restart the server and see whether it would work again.

michaelherger avatar Jan 02 '24 12:01 michaelherger

Hi Michael!

Permissions seems fine. The whole folder and subfolders are 0755, owned by my system user and group users, files are 0644. LMS is running as system user squeezeboxserver (as defined in the debian package) which I added to group users.

The following command didn't show anything surprising:

find /srv/music/ -type f ! -perm 0644 -exec ls -l {} \;

For the sake of certitude, I just ran the following commands:

$ chown -R ioguix:users /srv/music
$ chmod -R g+rx /srv/music/
$ id squeezeboxserver
uid=109(squeezeboxserver) gid=65534(nogroup) groups=65534(nogroup),100(users)

I did restart the server multiple times since few days, this is the 4th time this problem appears. I usually restart the server and rescan the music folder.

I just restarted the server without rescanning: no luck, I still can not navigate the folder.

Thanks,

ioguix avatar Jan 02 '24 15:01 ioguix

Can you please confirm:

  • After a restart and NO rescan, you can NOT navigate down those disk folders, not even on first attempt?
  • We are talking about Browse Music Folder, not Browse Filesystem?
  • A rescan would be able to scan those folder?

And could you please give 8.3.2 a try?

michaelherger avatar Jan 03 '24 04:01 michaelherger

After a restart and NO rescan, you can NOT navigate down those disk folders, not even on first attempt?

Confirmed.

We are talking about Browse Music Folder, not Browse Filesystem?

Confirmed. The full navigation is My Music > Music Folder > Augustin.

Augustin is a folder with subfolders, readable by system user squeezeboxserver:

A rescan would be able to scan those folder?

Yes. A rescan work fine. No errors in logs, all folders and files become browsable again.

ioguix avatar Jan 03 '24 08:01 ioguix

A rescan work fine. No errors in logs, all folders and files become browsable again.

That's the part I don't understand yet: are you saying there's a link between browsability, and whether you had run a scan before trying to browse a folder? No scan, no browsing. After scan, successful browsing?

michaelherger avatar Jan 03 '24 08:01 michaelherger

Here are the steps:

step1 step2 step3

After scan: successful browsing. Step 3 becomes normal, I can navigate through subfolders and files.

Then, later, I don't know how and why, the folder is not browsable again, until I run a rescan.

wash, repeat.

Note that when this folder is not browsable, I can still hit "play" on it and it loads... 824 songs to the playing list...

ioguix avatar Jan 03 '24 08:01 ioguix

And could you please give 8.3.2 a try?

I could, but I can't find it:

  • software update in the UI doesn't find it
  • there's no 8.3.2 tag in the git repo

Is it the current HEAD of public/8.3 branch ?

ioguix avatar Jan 03 '24 08:01 ioguix

I understand such a behavior is hard to debug, especially since we don't exactly know when/how/what triggers this situation.

Is there a debug mode or some debug patch I could apply on the scanner or the server to show some meaningful messages when the type an entry change? Anything I can check in the sqlite database that would be suspicious?

ioguix avatar Jan 03 '24 09:01 ioguix

You can find builds on https://lms-community.github.io/lms-server-repository/ - and yes, it's the head of public/8.3. 8.3.2 is the released 8.3.1 plus some more bug fixes.

Your issue actually rings a bell. I believe there was an issue with browsing folders which would fail under some conditions. But I thought I had fixed this. Alas: I can't find the relevant commit, thus don't know whether it was before or after 8.3.1 release. I would have thought it was before 8.3.1.

As BMF is based on filesystem content rather than the database, SQLite wouldn't help.

michaelherger avatar Jan 03 '24 10:01 michaelherger

As for the logging, I believe os.files could be helpful, and/or os.paths, scan.scanner.

michaelherger avatar Jan 03 '24 10:01 michaelherger

Hi Michael,

Thank you for pointing me to the Stable Nightly Build!

I just:

  1. installed 8.3.2
  2. set os.files, os.paths and scan.scanner to debug
  3. restarted service logitechmediaserver
  4. force rescan

Because of the rescan, I can currently browse the folder.

As BMF is based on filesystem content rather than the database, SQLite wouldn't help

I though the database could have metadata that could misdirect the server.

I'm looking at the logs for surprising debug message.

ioguix avatar Jan 03 '24 16:01 ioguix

Well, that was fast, while looking at the logs, my son came to me to tell me the folder is not browsable anymore...

On the squeezebox boom, the screen shows a note in front of the folder, instead of showing a right arrow.

I'm still looking at the logs.

ioguix avatar Jan 03 '24 16:01 ioguix

From the server.log file, these lines seem relevant:

[24-01-03 17:05:31.8152] Slim::Utils::Misc::stripRel (606) Original: /srv/music/Augustin
[24-01-03 17:05:31.8158] Slim::Utils::Misc::stripRel (612) Stripped: /srv/music/Augustin
[24-01-03 17:05:31.8166] Slim::Utils::Misc::fixPath (589) Fixed: Augustin to file:///srv/music/Augustin
[24-01-03 17:05:31.8171] Slim::Utils::Misc::fixPath (591) Base: /srv/music
[24-01-03 17:05:31.8179] Slim::Utils::Misc::pathFromFileURL (262) Got /srv/music/Augustin from file url file:///srv/music/Augustin
[24-01-03 17:05:31.8186] Slim::Utils::Misc::pathFromFileURL (277) Extracted: /srv/music/Augustin from file:///srv/music/Augustin
[24-01-03 17:05:35.2599] Slim::Utils::Misc::readDirectory (1004) Reading directory: /srv/music/Augustin
[24-01-03 17:05:35.2615] Slim::Utils::Misc::readDirectory (1033) Directory contains 10 items

So it found the 10 sub-folders.

Then later:

[24-01-03 17:14:11.3138] Slim::Utils::Misc::pathFromFileURL (277) Extracted: /var/lib/squeezeboxserver/prefs/clientplaylist_0004201e6ff4.m3u from file:///var/lib/squeezeboxserver/prefs/clientplaylist_0004201e6ff4.m3u
[24-01-03 17:14:11.3219] Slim::Formats::loadTagFormatForType (120) Error: Couldn't load module:  (dir) : [syntax error at (eval 1180) line 1, at EOF#012]
[24-01-03 17:14:11.3235] Slim::Formats::loadTagFormatForType (120) Backtrace: [...]
[24-01-03 17:14:11.3253] Slim::Player::Song::open (424) Error: Couldn't create command line for dir playback for [tmp:///srv/music/Augustin]
[24-01-03 17:14:18.2781] Slim::Formats::loadTagFormatForType (120) Error: Couldn't load module:  (dir) : [syntax error at (eval 1181) line 1, at EOF#012]
[24-01-03 17:14:18.2796] Slim::Formats::loadTagFormatForType (120) Backtrace: [...]
[24-01-03 17:14:18.2814] Slim::Player::Song::open (424) Error: Couldn't create command line for dir playback for [tmp:///srv/music/Augustin]

Why the path becomes suddenly tmp:///srv/music/Augustin? Any clue of what could trigger this?

From the scanner.log file:

# grep -c 'Found /srv/music/Augustin' /var/log/squeezeboxserver/scanner.log
913
# grep -Pc 'Found /srv/music/Augustin/.*(flac|mp3|wav|opus)$' /var/log/squeezeboxserver/scanner.log
826

And these kind of messages for various sub-folders:

[24-01-03 17:02:44.8378] Slim::Utils::Scanner::Local::changed (1117) Handling changed playlist file:///srv/music/Augustin
[24-01-03 17:02:44.8382] Slim::Utils::Scanner::Local::deleted (833) Handling deleted playlist file:///srv/music/Augustin

ioguix avatar Jan 03 '24 16:01 ioguix

Hi there !

This morning, the problem moved one folder deeper! Folder file:///srv/music/Augustin is accessible, but two out of ten folders in there became non browsable.

The change seems to trigger after we browsed the folder once, but I'm not sure. Below is an example of what the log file shows for one of these folders, I have similar messages for the other one:

24-01-04 08:56:29.1230 Slim::Utils::Scanner::scanPathOrURL (94) Finding valid files in: /srv/music/Augustin/Harry Potter
24-01-04 08:56:29.1330 Slim::Utils::Misc::findAndScanDirectoryTree (1116) findAndScanDirectoryTree( /srv/music/Augustin/Harry Potter ): fsMTime: 1671378361, dbMTime: 1671378361
24-01-04 08:56:29.1396 Slim::Utils::Misc::readDirectory (1033) Directory contains 20 items
24-01-04 08:56:29.1415 Slim::Utils::Misc::pathFromFileURL (262) Got /srv/music/Augustin/Harry%20Potter/[...]
24-01-04 08:56:29.2246 Slim::Utils::Misc::pathFromFileURL (277) Extracted: /srv/music/Augustin/Harry Potter/[...]
[...]

scanPathOrURL and readDirectory found 20 items in /srv/music/Augustin/Harry Potter and Got/Extracted a bunch of audio files from there. Fine.

But then this happen:

24-01-04 08:56:29.2400 Slim::Utils::Scanner::Local::scanPlaylistFileHandle (1219) Will scan file:///srv/music/Augustin/Harry%20Potter, base: file:///srv/music/Augustin
24-01-04 08:56:29.2482 Slim::Utils::Scanner::Local::scanPlaylistFileHandle (1270) Playlist item file:///srv/music/Augustin/Harry%20Potter changed from dir to ssp content-type
24-01-04 08:56:29.2505 Slim::Utils::Scanner::Local::scanPlaylistFileHandle (1295) Found 0 items in playlist: 

Why file:///srv/music/Augustin/Harry%20Potter changed from dir to ssp? (what is ssp ?)

And then later, I suppose when trying to play it anyway, even when not able to browse it:

24-01-04 10:26:35.7352 Slim::Formats::loadTagFormatForType (120) Error: Couldn't load module:  (dir) : [syntax error at (eval 1187) line 1, at EOF#012]
24-01-04 10:26:35.7367 Slim::Formats::loadTagFormatForType (120) Backtrace:[...]
24-01-04 10:26:35.7385 Slim::Player::Song::open (424) Error: Couldn't create command line for dir playback for [tmp:///srv/music/Augustin/Harry%20Potter]

URL schemes became tmp:/// again. Moreover, when trying to "play" this specific non-browsable folder, it actually add to the playing list the two folders that became non browsable.

I found 4 m3u files in theses folders, all were in dos format ending lines, and one m3u was referencing bad file names. From the log, I guess the scanner and server might have to fix some path, maybe related to the ones found in playlists with bad path, special chars and dos-EOL format. So I changed the file format of these m3u to unix, fixed the audio file paths and launched a rescan... Wait and see now.

On a side note, I'm not sure how this could be related, but I did some housecleaning yesterday:

  • removed some playlists (cue and m3u) referencing [re]moved songs
  • cleaned [re]moved songs from the favorites

ioguix avatar Jan 04 '24 10:01 ioguix

The /srv/music/Augustin is not browsable again. There's 3 changed from dir to ssp content-type messages in logs:

24-01-04 11:35:49.5938 Slim::Utils::Scanner::Local::scanPlaylistFileHandle (1219) Will scan file:///srv/music/Augustin, base: file:///srv/music
24-01-04 11:35:49.5948 Slim::Utils::Scanner::Local::scanPlaylistFileHandle (1270) Playlist item file:///srv/music/Augustin changed from dir to ssp content-type
24-01-04 11:35:49.5954 Slim::Utils::Scanner::Local::scanPlaylistFileHandle (1295) Found 0 items in playlist: 
24-01-04 11:35:49.5974 Slim::Utils::Scanner::Local::scanPlaylistFileHandle (1219) Will scan file:///srv/music/Augustin, base: file:///srv/music
24-01-04 11:35:49.5986 Slim::Utils::Scanner::Local::scanPlaylistFileHandle (1270) Playlist item file:///srv/music/Augustin changed from dir to ssp content-type
24-01-04 11:35:49.5992 Slim::Utils::Scanner::Local::scanPlaylistFileHandle (1295) Found 0 items in playlist: 
24-01-04 11:35:49.6012 Slim::Utils::Scanner::Local::scanPlaylistFileHandle (1219) Will scan file:///srv/music/Augustin, base: file:///srv/music
24-01-04 11:35:49.6023 Slim::Utils::Scanner::Local::scanPlaylistFileHandle (1270) Playlist item file:///srv/music/Augustin changed from dir to ssp content-type
24-01-04 11:35:49.6029 Slim::Utils::Scanner::Local::scanPlaylistFileHandle (1295) Found 0 items in playlist: 

ioguix avatar Jan 04 '24 11:01 ioguix

I keep finding playlists in dos EOL format in there, I'll try to fix'em all.

As the boom is quite old and its firmware unmaintained, could it be related to some incompatibilities with spaces in path or playlists? Unicode?

ioguix avatar Jan 04 '24 11:01 ioguix

Hi @ioguix - I'm sorry for the slow feedback. I'm a bit busy with some emergency work...

Just FYI: the devices have nothing to do with this. It's all in LMS. The Boom (and Classic/Transporter/older) are particularly dumb devices. They really only can deal with audio output and displaying on screen whatever LMS tells them to display. Everything else is in LMS.

Could you please try with 8.4, too? This issue is really odd, as I believe we've had this (as I mentioned), but I haven't seen complaints about this for a long time. Is anything special about your installation? Are you running from git or the .deb file? What 3rd party plugins are you using?

michaelherger avatar Jan 04 '24 13:01 michaelherger

Hi @ioguix - I'm sorry for the slow feedback. I'm a bit busy with some emergency work...

Are you kidding me ? I'm already impressed you keep answering and maintaining the project for such great and durable products... Thank you so much!

Could you please try with 8.4, too?

I can. I suppose rollback is just a matter of reinstalling 8.3.2 package on top of 8.4?

Is anything special about your installation

I don't think so:

  • Debian 11
  • squeezeboxserver 8.3.2 installed by DEB packages, 8.3.1 was already installed with the DEB package
  • /srv filesystem is ZFS (2.1.11)
  • /srv/music is just an aborescence of folders/audio files mostly organized by artist, one folder per artist, one sub-folder per album.
  • a ten or more years old SB Touch in wifi connected to a DAC
  • a brand new SB Boom

The only thing that changed in this setup since many years is the new Boom I just added. But my son is using it MUCH much more from his bedroom than before from the leaving room. So maybe this probability changed or smth...

Or maybe this was triggered by a previous update. Before having this bug, I updated to 8.3.1 full of hope to fix another bug (it did not) with embeded cue metadata that are triggering gigabytes of binary dumps to the log file (this seems correlated with the boom activity as well)...

Are you running from git or the .deb file?

DEB file

What 3rd party plugins are you using?

  • Band's Campout (v1.9.2)
  • Drag & drop music files to play (v0.1)
  • Info Browser (v1.0)
  • Line In (v1.0)
  • Music and Artist Information (v1.10.6)
  • Music Information Screen (v4.5.0)
  • Online Music Library Integration (v1.0)
  • Podcasts (v2.0)
  • PowerSave (v7.4.1)
  • Presets Editor (v1.0)
  • Radio (v1.0)
  • Radio France (v0.4.8)
  • Radio Paradise (v3.1.1)
  • Random Mix (v1.0)
  • Remote Music Libraries (v1.0)
  • Song Scanner (v2.0)
  • SoundCloud (v0.15) 
  • Title Switcher (v1.3.23)
  • Visualizer Screensaver (v1.0)

ioguix avatar Jan 04 '24 15:01 ioguix

Just FTR, I just found a playlist I created from the webUI few days agos (2023-12-31 according to the file mtime) where all path starts as:

tmp:///srv/music/Augustin/[...]

ioguix avatar Jan 04 '24 16:01 ioguix

Also, where such a file/string comes from in such a log messages?

Cracked: /music/-94698258463080/cover with [],[80],[/]
Cracked: /music/-94698258502888/cover with [],[80],[/]
Cracked: /music/-94698258502888/cover with [],[80],[/]
Cracked: /music/-94698258503776/cover with [],[80],[/]
Cracked: /music/-94698258503776/cover with [],[80],[/]
Cracked: html/images/artists.png with [],[80],[/]
   user: [htm]
Cracked: html/images/newmusic.png with [],[80],[/]
   user: [htm]
Cracked: /plugins/TuneIn/html/images/podcasts.png with [],[80],[/]
   user: [htm]
Cracked: /plugins/TuneIn/html/images/radiosearch.png with [],[80],[/]
   user: [htm]
Cracked: /plugins/TuneIn/html/images/radiosearch.png with [],[80],[/]
   user: [htm]
Cracked: html/images/ServiceProviders/tuneinurl.png with [],[80],[/]
   user: [htm]
Cracked: html/images/ServiceProviders/tuneinurl.png with [],[80],[/]
   user: [htm]
Cracked: plugins/Bandcamp/html/images/logo.png with [],[80],[/]
   user: [htm]

I have a bunch of them, but the path/string/output seems suspicious...

The code tries to parse an URI from the string, but none of them looks like an URI or valid local path...

ioguix avatar Jan 04 '24 17:01 ioguix

I found something interesting while looking at the code here: https://github.com/Logitech/slimserver/blob/3f9d34d2761f2d2bf4da161c95495371517f584d/Slim/Utils/Scanner/Local.pm#L1278C17-L1278C17

if (Slim::Music::Info::isFileURL($url) && Slim::Utils::Misc::inPlaylistFolder($url)) {
	main::DEBUGLOG && $log->is_debug && $log->debug( "Playlist item $url changed from $ct to ssp content-type" );
	$ct = 'ssp';
}

It seems this conditional block change the dir content-type to ssp if the folder is in the playlist folder. And indeed, I set the playlist folder to /srv/music few days ago. I'm not sure exactly when this code is triggered though, so I don't have a clear path to trigger the bug yet.

For now, I set the playlist folder to /srv/music/.playlists and rescanned, let's see what happen next.

ioguix avatar Jan 05 '24 00:01 ioguix

Oh wow... you might be up to something! I believe the comment above those lines suggests that content type ssp was some custom type to treat certain playlists differently. I don't remember the details, TBH. That's from before I really got involved with this part of the code. But those lines suggest that there could be conflicting behavior if the music folder overlapped the playlist folder. I know that this generally is recommended not to do for other reasons, too. So please let me know about your finding (I have no doubts you will 😁). Thanks!

It's still not clear to me why that would fail growing folder sometimes but not all the time though.

As for those tmp:// URLs: that's being used for "volatile files". They're basically the same as file:// URLs, except that LMS would not add them to the database. They're used in various cases: eg. when browsing the file system outside the music folder, when playing content while a scan was going on, when using the d'n'd plugin etc.

michaelherger avatar Jan 05 '24 05:01 michaelherger

But those lines suggest that there could be conflicting behavior if the music folder overlapped the playlist folder. I know that this generally is recommended not to do for other reasons, too

Do you mean I should move my new .playlists folder outside of /srv/music/.playlists so it's not even included in my music folder at all?

It's still not clear to me why that would fail growing folder sometimes but not all the time though

Indeed... and I'm not sure why/in what condition a folder goes through scanPlaylistFileHandle in the first place. Does all folders are considered like virtual playlist internally?

Plus, I wonder how fresh is this page: https://wiki.slimdevices.com/index.php/SlimServerDatabaseStructure.html

It says the content_type field of the tracks table could have playlist as value, but my table have no such value. They are all 3 letters wide extensions (including ssp, cue, etc).

ioguix avatar Jan 05 '24 09:01 ioguix

Do you mean I should move my new .playlists folder outside of /srv/music/.playlists so it's not even included in my music folder at all?

Yes. Make sure the playlist folder is outside the music folder.

Plus, I wonder how fresh is this page: https://wiki.slimdevices.com/index.php/SlimServerDatabaseStructure.html

The wiki has been frozen years ago. You can consider most of it outdated... In particular MySQL hasn't been used any more for over a decade 🤦🏻.

It says the content_type field of the tracks table could have playlist as value, but my table have no such value. They are all 3 letters wide extensions (including ssp, cue, etc).

That's correct, it uses those extension type strings.

mherger avatar Jan 05 '24 10:01 mherger

Yes. Make sure the playlist folder is outside the music folder.

OK, thanks!

The wiki has been frozen years ago. You can consider most of it outdated... In particular MySQL hasn't been used any more for over a decade 🤦🏻.

ok :)

Any clue about my previous question: does all folders are considered like virtual playlist internally?

ioguix avatar Jan 05 '24 16:01 ioguix

Any clue about my previous question: does all folders are considered like virtual playlist internally?

No. BMF is one way to actually add new tracks/albums to your library without running a scan. "volatile" files are only being used when using "Browse Filesystem" (not "Browse Musicfolder"!), or when a scan is running.

michaelherger avatar Jan 07 '24 19:01 michaelherger

Did moving the playlist folder "fix" the issue?

michaelherger avatar Jan 18 '24 07:01 michaelherger

Hi Michael,

Sorry for the silence, I've been busy away from slimserver code...

Did moving the playlist folder "fix" the issue?

Yes, it did! I now have:

  • /srv/music/audios setup as "Media Folders"
  • /srv/music/playlists setup as "Playlists Folder"

I hadn't time to keep investigating so far. Neither for this bug or the previous one about binary data sent to log files... sorry. I'll try to get back on this as soon as I can.

If you have any tips/clues/theories that could help in my discovery/investigation, please, brain dump here as this code base is really new to me :)

Have a good day,

ioguix avatar Jan 18 '24 09:01 ioguix

Would you have more information about what binary data is being logged? Could this be some data in custom tags? Eg. additional artwork, or PDFs with reviews or the like? As it's with CUE sheets you should be able to extract the CUE sheets and investigate them?

mherger avatar Jan 18 '24 09:01 mherger

Would you have more information about what binary data is being logged?

I should probably open another issue about this.

Unfortunately, log has been rotated since then, so I lost symptoms of the bugs... I think this was coming from Slim::Formats::Playlists::Base::playlistEntryIsValid(), this block:

if (!Slim::Music::Info::isFile($entry)) {

    logWarning("$entry found in playlist:\n\t$url doesn't exist on disk - skipping!");
    return 0;
}

But don't trust too much my memory.

I remember that looking at the header and string appearing here and there in the middle of the binary flood in logs, I suspected this was flac files. I don't remember if these flac files were injected from $entry or $url though.

ioguix avatar Jan 18 '24 10:01 ioguix