PDA

View Full Version : LMS Stops after a couple of seconds of playback, restarts the server, then plays fine



pyoorkate
2018-05-01, 11:47
Hi folks,

I had a search of the forums and can't see anything similar (although my google-fu may have failed). Since 7.9.0 I've had an odd problem with LMS. If I add tracks to the queue or start playing a track then LMS will crash and restart. The queue is retained, and the second time I press play it'll work fine. It'll keep playing happily to the end of the playlist and if I restart it, it'll play fine.

But as soon as I change the play queue (for example, add a track) then the same thing will happen again. It'll die within a few seconds, then restart, then be 'fine'.

It does this whether I start it from one of the squeezebox devices or from the web interface. It also does it regardless of filetime (most of my newer stuff is FLAC except for some downloaded stuff that's only available as MP3, older files are MP3 for the most part).

Today I upgraded to 7.9.1 to see if that'd fix it, but it hasn't, so I thought I'd ask on here :)

All that's recorded in the log is:

2018-05-01 11:23:44 Logitech Media Server died. Restarting.
[18-05-01 11:23:45.7166] main::init (387) Starting Logitech Media Server (v7.9.1, 1522157629, Fri Mar 30 12:28:01 CEST 2018) perl 5.022001 - x86_64-linux-gnu-thread-multi
[18-05-01 11:23:45.8489] Slim::Utils::Misc::msg (1252) Warning: [11:23:45.8487] DBIx::Class::ResultSet::update_or_create(): Query returned more than one row. SQL that returns multiple rows is DEPRECATED for ->find and ->single at /usr/share/perl5/Slim/Schema.pm line 1877
2018-05-01 11:37:09 Logitech Media Server died. Restarting.
[18-05-01 11:37:09.9725] main::init (387) Starting Logitech Media Server (v7.9.1, 1522157629, Fri Mar 30 12:28:01 CEST 2018) perl 5.022001 - x86_64-linux-gnu-thread-multi
[18-05-01 11:37:10.1031] Slim::Utils::Misc::msg (1252) Warning: [11:37:10.1029] DBIx::Class::ResultSet::update_or_create(): Query returned more than one row. SQL that returns multiple rows is DEPRECATED for ->find and ->single at /usr/share/perl5/Slim/Schema.pm line 1877

I'm running:

Logitech Media Server Version: 7.9.1 - 1522157629 @ Fri Mar 30 12:28:01 CEST 2018
Operating system: Debian - EN - utf8
Platform Architecture: x86_64-linux
Perl Version: 5.22.1 - x86_64-linux-gnu-thread-multi
Audio::Scan: 0.95
Database Version: DBD::SQLite 1.34_01 (sqlite 3.7.7.1)
Total Players Recognized: 1

At the moment I've only got one of my players hooked up - but they're all Squeezebox 2s:

Player Model: Squeezebox2
Player Type: squeezebox2
Firmware: 137

Any suggestions on what might be up would be greatly appreciated!

Paul Webster
2018-05-02, 10:16
A lot of time but not much logging between these two points



[18-05-01 11:23:45.8489] Slim::Utils::Misc::msg (1252) Warning: [11:23:45.8487] DBIx::Class::ResultSet::update_or_create(): Query returned more than one row. SQL that returns multiple rows is DEPRECATED for ->find and ->single at /usr/share/perl5/Slim/Schema.pm line 1877


2018-05-01 11:37:09 Logitech Media Server died. Restarting.


To diagnose further probably need to increase the logging level via Settings/Advanced/Logging and pick a few to set at a more detailed level.
Perhaps the database.* and "server" set to Info.

pyoorkate
2018-05-02, 19:13
A lot of time but not much logging between these two points

To diagnose further probably need to increase the logging level via Settings/Advanced/Logging and pick a few to set at a more detailed level.
Perhaps the database.* and "server" set to Info.

Thanks! Wasn't sure which logging would be useful. So, tweaked those logging settings up which has had the very weird effect of making the problem less reliable. It still occurs under the same circumstances, but not as frequently.

The logging output doesn't seem terribly helpful, though:

[18-05-02 18:52:56.3917] Slim::Schema::Debug::query_start (23) SELECT me.id, me.urlmd5, me.url, me.content_type, me.title, me.titlesort, me.titlesearch, me.album, me.primary_artist, me.tracknum, me.timestamp, me.added_time, me.updated_time, me.filesize, me.disc, me.remote, me.audio, me.audio_size, me.audio_offset, me.year, me.secs, me.cover, me.cover_cached, me.vbr_scale, me.bitrate, me.samplerate, me.samplesize, me.channels, me.block_alignment, me.endian, me.bpm, me.tagversion, me.drm, me.musicmagic_mixable, me.dlna_profile, me.musicbrainz_id, me.lossless, me.lyrics, me.replay_gain, me.replay_peak, me.extid, me.virtual, me.coverid FROM tracks me WHERE ( url = ? ): 'file:///mnt/3f0284dc-d785-4eeb-b1f2-7b0843b4d930/Audio/Digital%20Downloads/CN%20Lester/04%20Fractals%20MP3.mp3'
[18-05-02 18:52:56.3931] Slim::Schema::Debug::query_start (23) SELECT me.id, me.urlmd5, me.url, me.content_type, me.title, me.titlesort, me.titlesearch, me.album, me.primary_artist, me.tracknum, me.timestamp, me.added_time, me.updated_time, me.filesize, me.disc, me.remote, me.audio, me.audio_size, me.audio_offset, me.year, me.secs, me.cover, me.cover_cached, me.vbr_scale, me.bitrate, me.samplerate, me.samplesize, me.channels, me.block_alignment, me.endian, me.bpm, me.tagversion, me.drm, me.musicmagic_mixable, me.dlna_profile, me.musicbrainz_id, me.lossless, me.lyrics, me.replay_gain, me.replay_peak, me.extid, me.virtual, me.coverid FROM tracks me WHERE ( url = ? ): 'file:///mnt/3f0284dc-d785-4eeb-b1f2-7b0843b4d930/Audio/Digital%20Downloads/CN%20Lester/08%20Aether.mp3'
[18-05-02 18:52:56.3946] Slim::Schema::Debug::query_start (23) SELECT me.id, me.urlmd5, me.url, me.content_type, me.title, me.titlesort, me.titlesearch, me.album, me.primary_artist, me.tracknum, me.timestamp, me.added_time, me.updated_time, me.filesize, me.disc, me.remote, me.audio, me.audio_size, me.audio_offset, me.year, me.secs, me.cover, me.cover_cached, me.vbr_scale, me.bitrate, me.samplerate, me.samplesize, me.channels, me.block_alignment, me.endian, me.bpm, me.tagversion, me.drm, me.musicmagic_mixable, me.dlna_profile, me.musicbrainz_id, me.lossless, me.lyrics, me.replay_gain, me.replay_peak, me.extid, me.virtual, me.coverid FROM tracks me WHERE ( url = ? ): 'file:///mnt/3f0284dc-d785-4eeb-b1f2-7b0843b4d930/Audio/Digital%20Downloads/CN%20Lester/Do%20it%20like%20a%20Dude.mp3'
[18-05-02 18:52:56.3962] Slim::Schema::Debug::query_start (23) SELECT me.id, me.urlmd5, me.url, me.content_type, me.title, me.titlesort, me.titlesearch, me.album, me.primary_artist, me.tracknum, me.timestamp, me.added_time, me.updated_time, me.filesize, me.disc, me.remote, me.audio, me.audio_size, me.audio_offset, me.year, me.secs, me.cover, me.cover_cached, me.vbr_scale, me.bitrate, me.samplerate, me.samplesize, me.channels, me.block_alignment, me.endian, me.bpm, me.tagversion, me.drm, me.musicmagic_mixable, me.dlna_profile, me.musicbrainz_id, me.lossless, me.lyrics, me.replay_gain, me.replay_peak, me.extid, me.virtual, me.coverid FROM tracks me WHERE ( url = ? ): 'file:///mnt/3f0284dc-d785-4eeb-b1f2-7b0843b4d930/Audio/Digital%20Downloads/CN%20Lester/I%27m%20Your%20Man.mp3'
[18-05-02 18:52:57.0007] Slim::Utils::Cache::cleanup (207) Cache purge: cache - skipping, purged recently
2018-05-02 18:52:58 Logitech Media Server died. Restarting.
[18-05-02 18:52:59.3198] main::init (387) Starting Logitech Media Server (v7.9.1, 1522157629, Fri Mar 30 12:28:01 CEST 2018) perl 5.022001 - x86_64-linux-gnu-thread-multi

What is positively bizarre is that I tried tweaking the settings to 'debug' for both server.* and database.* and... it now won't crash and restart. Having set them back to normal logging levels it is currently behaving itself... which is really throwing me.