Bug 12691 - SqueezeSvr.exe keeps hanging and consuming 50% of CPU and 150MB of memory
: SqueezeSvr.exe keeps hanging and consuming 50% of CPU and 150MB of memory
Status: RESOLVED WORKSFORME
Product: Logitech Media Server
Classification: Unclassified
Component: Scanner
: 7.4.0
: PC Windows 7
: -- major (vote)
: 8.0.0
Assigned To: Andy Grundman
: SQLite
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2009-07-06 11:15 UTC by Chris Tashjian
Modified: 2011-01-12 12:06 UTC (History)
1 user (show)

See Also:
Category: ---


Attachments
One of the m4a files which triggers the "buffer_append_space: len 2778387 not supported" error (6.77 MB, application/x-zip-compressed)
2009-07-09 04:54 UTC, Chris Tashjian
Details
Scanner.log & cue sheet with bad "Œ" character (1.17 KB, application/x-zip-compressed)
2009-07-12 05:42 UTC, Chris Tashjian
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Chris Tashjian 2009-07-06 11:15:41 UTC
In the last half dozen builds of 7.4 I've noticed the server keeps hanging.  The time on my Boom locks up (i.e. displays 8:05am all day, where 8:05am is when the server stopped responding).  Looking at the windows task manager I can see that Squeez~3.exe (SqueezeSvr.exe) is consuming 50% of the CPU and aobut 150MB of memory.  Stopping the process and restarting the server seems to work, but it eventually locks up again.  I'm not even streaming music when it happens.  I believe it's still trying to scan my library.

Sorry for the lack of definitive info, the log files aren't helpful as there's no error in them... just some warnings (which I do not believe are the cause of the locking up):

[09-07-05 11:46:11.6613] Slim::Utils::Misc::msg (1160) Warning: [11:46:11.6611] Use of uninitialized value in hash element at /<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Tie/Cache/LRU/Array.pm line 135.
[09-07-05 11:46:11.7288] Slim::Utils::Misc::msg (1160) Warning: [11:46:11.7285] Use of uninitialized value $fullpath in hash element at /<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Slim/Music/Info.pm line 1463.
[09-07-05 11:46:11.7291] Slim::Utils::Misc::msg (1160) Warning: [11:46:11.7289] Use of uninitialized value $key in exists at /<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Tie/Cache/LRU/Array.pm line 160.
[09-07-05 11:46:11.7294] Slim::Utils::Misc::msg (1160) Warning: [11:46:11.7292] Use of uninitialized value $key in hash element at /<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Tie/Cache/LRU/Array.pm line 82.
[09-07-05 11:46:11.7298] Slim::Utils::Misc::msg (1160) Warning: [11:46:11.7296] Use of uninitialized value $key in hash element at /<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Tie/Cache/LRU/Array.pm line 89.
[09-07-05 11:46:11.7301] Slim::Utils::Misc::msg (1160) Warning: [11:46:11.7299] Use of uninitialized value $fullpath in concatenation (.) or string at /<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Slim/Music/Info.pm line 1466.
[09-07-05 11:46:11.7306] Slim::Utils::Misc::msg (1160) Warning: [11:46:11.7304] Use of uninitialized value $j in pattern match (m//) at /<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Slim/Music/Info.pm line 877.
[09-07-05 11:46:11.7309] Slim::Utils::Misc::msg (1160) Warning: [11:46:11.7307] Use of uninitialized value $directories in pattern match (m//) at /<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>File/Spec/Win32.pm line 228.
[09-07-05 11:46:11.7312] Slim::Utils::Misc::msg (1160) Warning: [11:46:11.7310] Use of uninitialized value $directories in split at /<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>File/Spec/Win32.pm line 229.
[09-07-05 11:46:11.7315] Slim::Utils::Misc::msg (1160) Warning: [11:46:11.7313] Use of uninitialized value $title in concatenation (.) or string at /<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Slim/Music/Info.pm line 644.
[09-07-05 11:46:11.7318] Slim::Utils::Misc::msg (1160) Warning: [11:46:11.7316] Use of uninitialized value $filepath in -e at /<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Slim/Formats.pm line 235.
[09-07-05 11:46:11.8719] Slim::Utils::Misc::msg (1160) Warning: [11:46:11.8716] Use of uninitialized value in division (/) at /<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Slim/Formats/Playlists/CUE.pm line 418.
[09-07-05 11:46:11.8724] Slim::Utils::Misc::msg (1160) Warning: [11:46:11.8722] Use of uninitialized value $path in open at /<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Slim/Formats/Playlists/CUE.pm line 434.
Comment 1 Chris Tashjian 2009-07-06 12:14:51 UTC
It's definitely during scanning... I restarted the server and about 30 mins after the server I see this:

[09-07-06 14:17:08.5473] Slim::Utils::Update::checkVersionCB (103) No new Squeezebox Server version available
[09-07-06 14:47:21.0213] Slim::Utils::Scanner::Local::__ANON__ (139) Removing deleted files (18)
[09-07-06 14:47:21.3892] Slim::Utils::Scanner::Local::__ANON__ (190) Scanning new files (510)
[09-07-06 14:47:21.7701] Slim::Utils::Scanner::Local::__ANON__ (241) Rescanning changed files (0)
[09-07-06 14:47:21.9185] Slim::Formats::readTags (178) Error: While trying to ->getTag(S:\_Music\SomeArtists - Album Title Name (2009 Version)\01 A Song Title.m4a) : buffer_append_space: len 2778387 not supported at /<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Slim/Formats/Movie.pm line 48.
[09-07-06 14:47:21.9191] Slim::Formats::readTags (178) Backtrace:

   frame 0: Slim::Utils::Log::logBacktrace (/<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Slim/Formats.pm line 178)
   frame 1: Slim::Formats::readTags (/<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Slim/Schema.pm line 1051)
   frame 2: Slim::Schema::newTrack (/<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Slim/Schema.pm line 1348)
   frame 3: Slim::Schema::updateOrCreate (/<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Slim/Utils/Scanner/Local.pm line 379)
   frame 4: Slim::Utils::Scanner::Local::__ANON__ (/<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>DBIx/Class/Storage/DBI.pm line 468)
   frame 5: (eval) (/<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>DBIx/Class/Storage/DBI.pm line 456)
   frame 6: DBIx::Class::Storage::DBI::txn_do (/<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>DBIx/Class/Schema.pm line 633)
   frame 7: DBIx::Class::Schema::txn_do (/<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Slim/Utils/Scanner/Local.pm line 441)
   frame 8: Slim::Utils::Scanner::Local::new (/<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Slim/Utils/Scanner/Local.pm line 218)
   frame 9: Slim::Utils::Scanner::Local::__ANON__ (/<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Slim/Utils/Scheduler.pm line 140)
   frame 10: (eval) (/<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Slim/Utils/Scheduler.pm line 140)
   frame 11: Slim::Utils::Scheduler::run_tasks (slimserver.pl line 593)
   frame 12: main::idle (slimserver.pl line 569)
   frame 13: main::main (slimserver.pl line 99)
   frame 14: PerlSvc::Interactive (/<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>PerlSvc.pm line 99)
   frame 15: PerlSvc::_interactive (slimserver.pl line 0)
   frame 16: (eval) (slimserver.pl line 0)


...and then a few more of these errors follow and then some other scanning errors which I have already reported.  The last log entry is:

[09-07-06 14:48:35.0098] Slim::Utils::Misc::msg (1160) Warning: [14:48:35.0095] Use of uninitialized value in division (/) at /<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Slim/Formats/Playlists/CUE.pm line 418.
[09-07-06 14:48:35.0104] Slim::Utils::Misc::msg (1160) Warning: [14:48:35.0101] Use of uninitialized value $path in open at /<C:\PROGRA~2\SQUEEZ~1\server\SQUEEZ~3.EXE>Slim/Formats/Playlists/CUE.pm line 434.


...and the time is now 15:17, so nothing new in 30 mins, but the CPU usage is holding steady at 50%, memory usage is 120,832K
Comment 2 Andy Grundman 2009-07-07 12:38:55 UTC
S:\_Music\SomeArtists - Album Title Name (2009 Version)\01 A Song
Title.m4a) : buffer_append_space: len 2778387

There may be a bug in Audio::Scan triggered by this file.  Can you please attach it to this bug?
Comment 3 Chris Tashjian 2009-07-09 04:54:36 UTC
Created attachment 5436 [details]
One of the m4a files which triggers the "buffer_append_space: len 2778387 not supported" error
Comment 4 Andy Grundman 2009-07-09 05:53:36 UTC
Hmm this file has a 2.7MB cover image.  Currently Audio::Scan doesn't like any individual item over 1M.  That'll be fixed in the next version of Audio::Scan to allow up to 5M.  I don't think this is the source of your issues though.  You should still consider reducing the size of your embedded artwork, you are likely wasting a lot of space.
Comment 5 Andy Grundman 2009-07-09 19:55:08 UTC
Audio::Scan 0.24 has ths fix for this problem.
Comment 6 Chris Tashjian 2009-07-12 05:41:57 UTC
Andy and I had an email thread going about this.  There's another issue which caused scanner.exe to peg CPU usage at 50% and stop.  In my library there was a .cue file with the first line:
    FILE "C:\GARYJULES2004-03-111.wav Œ" WAVE

The "Œ" was killing the scanner.  I removed that character from the .cue file and rescanned my library with no issues.

Prior to removing that character my scan would stop (hang for 12+ hrs) here:
    Scan new files   (21657  of  22112)

Now I was able to get thru it all:
===========
Scan new files   (22112  of  22112)   Complete  00:21:32
Remove deleted files   (1  of  1)   Complete  00:00:00
Remove deleted playlists   (1  of  1)   Complete  00:00:00
Scan new playlists   (2  of  2)   Complete  00:00:01
Merge Various Artists   (1321  of  1321)   Complete  00:00:21
Database Cleanup #1   (22473  of  22473)   Complete  00:00:30
Database Cleanup #2   (1  of  1)   Complete  00:00:18
The server has finished scanning your music collection.
Total Time: 00:22:42 (Saturday, July 11, 2009 / 9:38 AM)
===========


Attached in "bad_char.zip" is the scanner.log and the cue file.
Comment 7 Chris Tashjian 2009-07-12 05:42:50 UTC
Created attachment 5448 [details]
Scanner.log & cue sheet with bad "Œ" character
Comment 8 Andy Grundman 2009-07-29 14:40:48 UTC
Moving all SQLite-related bugs to 8.0.
Comment 9 Andy Grundman 2011-01-12 12:06:13 UTC
Old bug, closing.