Bug 12149 - Scanner fails if SC password-protection is enabled
: Scanner fails if SC password-protection is enabled
Status: CLOSED FIXED
Product: Logitech Media Server
Classification: Unclassified
Component: Scanner
: 7.4.0
: PC Debian Linux
: -- major (vote)
: 7.6.0
Assigned To: Andy Grundman
: SQLite
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2009-05-24 09:10 UTC by Aaron Solochek
Modified: 2011-04-29 15:19 UTC (History)
4 users (show)

See Also:
Category: ---


Attachments
Scanner log (7.27 KB, text/plain)
2009-05-24 09:10 UTC, Aaron Solochek
Details
Server log (71.56 KB, text/plain)
2009-05-24 09:10 UTC, Aaron Solochek
Details
scanner.log (7.17 KB, text/plain)
2009-06-03 09:21 UTC, Christian Kapeller
Details
server.log (11.17 MB, text/plain)
2009-06-03 09:24 UTC, Christian Kapeller
Details
scanner.log (3.01 MB, text/plain)
2009-06-09 09:53 UTC, Mikael Nyberg
Details
Server.log (38.27 KB, text/plain)
2009-06-09 09:55 UTC, Mikael Nyberg
Details
database files (5.62 MB, application/zip)
2009-06-09 10:13 UTC, Mikael Nyberg
Details
New logs with database.info debug switch. (122.30 KB, application/octet-stream)
2009-06-10 08:06 UTC, Mikael Nyberg
Details
New logs with database.info debug switch. (65.46 KB, application/octet-stream)
2009-06-10 08:07 UTC, Mikael Nyberg
Details
Server log after restart (no scanner log was created by SC ? ) (115.84 KB, application/octet-stream)
2009-06-10 08:23 UTC, Mikael Nyberg
Details
scanner.log after restart & 2'nd rescan try (122.30 KB, text/plain)
2009-06-10 08:33 UTC, Mikael Nyberg
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Aaron Solochek 2009-05-24 09:10:19 UTC
Created attachment 5262 [details]
Scanner log

I upgraded squeezecenter via the nightly debs from squeezecenter 7.4~26071 to  7.4~26719.  After squeezecenter was restarted, it complained a lot about the state of the database, and eventually launched the scanner, but despite running for hours, using plenty of cpu and definitely accessing the files (my music is on a NAS, and I can see the network activity/bandwidth of the scanner) the log doesn't show any files being processed.  I think it's probably 1 bug that the scanner process continues in the face of being unable to add anything to the database, but the main issue here is obviously the database stuff.  I've attached the logs.
Comment 1 Aaron Solochek 2009-05-24 09:10:51 UTC
Created attachment 5263 [details]
Server log
Comment 2 Aaron Solochek 2009-05-24 09:26:32 UTC
Update:  After killing the scanner process and restarting squeezecenter, things seems to be slightly better.  The scanner db was found, determined to be old, and then removed.  A new scan was initiated, and thus far there have been no bad errors in the scanner log (only errors reading some tags).  However, squeezecenter doesn't seem to know about any of the tracks already scanned.  I'm not sure if that is normal or not.  I'll send another update once the scanner finishes.
Comment 3 Aaron Solochek 2009-05-24 14:57:32 UTC
After 3.5 hours the scan finished, and despite listing every one of my music files in the log, nothing has been added to the database except for the couple of albums I listened to while it was scanning (I browsed to them via the music folder).  

In addition to taking way longer than I remember the old scanner taking, it also used up a lot more cpu.  I'm assuming this is because it's spinning like crazy trying to do some db operation that fails, but I really am not sure.  

Is there some way to manually check the database to verify it's accessible?  I know how to do that in mysql, but I have never dealt with sqlite before.
Comment 4 Christian Kapeller 2009-06-03 09:20:03 UTC
I can confirm this problem for r26820 from the unstable apt repository, running on ubuntu 8.04.
Comment 5 Christian Kapeller 2009-06-03 09:21:22 UTC
Created attachment 5303 [details]
scanner.log
Comment 6 Christian Kapeller 2009-06-03 09:24:50 UTC
Created attachment 5304 [details]
server.log
Comment 7 Mikael Nyberg 2009-06-09 09:49:00 UTC
I also have this bug ?


Version: 7.4 - 26954 @ Tue Jun 9 01:09:23 PDT 2009
Hostname: hal.home.lan
Server IP Address: 192.168.1.5
Server HTTP Port Number: 9000
Operating system: Red Hat - EN - utf8
Platform Architecture: i686-linux
Perl Version: 5.8.8 - i686-linux-thread-multi
Total Players Recognized: 4
 
Library Statistics
Total Tracks: 0
Total Albums: 0
Total Artists: 0
Total Genres: 0
Total Playing Time: 0:00:00

Same symptoms according to scanner log all my files is scanned ? but no database is created ?
Comment 8 Mikael Nyberg 2009-06-09 09:53:25 UTC
Created attachment 5314 [details]
scanner.log
Comment 9 Mikael Nyberg 2009-06-09 09:55:07 UTC
Created attachment 5315 [details]
Server.log

atached scanner and server logs
Comment 10 Mikael Nyberg 2009-06-09 10:13:10 UTC
Created attachment 5316 [details]
database files

The resulting database files from my cache in a zip file
Comment 11 Mikael Nyberg 2009-06-09 10:16:01 UTC
If I use BMF i get files added to my dB ?
Comment 12 Mikael Nyberg 2009-06-09 10:28:28 UTC
Whenever scanning no progress is reported by the web-UI ?
Comment 13 Mikael Nyberg 2009-06-09 10:46:47 UTC
After some starts and stops of SC and killing of a perl process some kind of scanning is slowly taking place before it was perl using 97% cpu and SC next to nothing now SC is using most of the cpu ?
Comment 14 Mikael Nyberg 2009-06-09 11:04:02 UTC
However no real progress report in the web-UI i have to manually refresh the pages to see the library increase but its painfully slow.
wiped my cache and rebooted lets see what it is doing now....
Comment 15 Mikael Nyberg 2009-06-09 11:31:47 UTC
No this did not work

when scanning is not working it looks like this when running the top command

 PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                      
 3920 squeezec  25   0 48484  33m 2980 R 98.7  3.5   2:21.73 perl                                         
 3912 squeezec  15   0 86292  70m 3412 S  0.7  7.4   0:35.19 squeezecenter-s                              
 2198 mysql     20   0  121m  18m 3520 S  0.3  1.9   0:00.79 mysqld                                       
    1 root      15   0  1716  596  512 S  0.0  0.1   0:00.93 init                                         
    2 root      RT   0     0    0    0 S  0.0  0.0   0:00.00 migration/0                                  
    3 root      34  19     0    0    0 S  0.0  0.0   0:00.00 ksoftirqd/0                                  
    4 root      RT   0     0    0    0 S  0.0  0.0   0:00.00 watchdog/0        

And so on

If i stop all scanning do some BMF and then restart SC i Managed to get some scanning going in background for unknown reasons ?

then it's only SC using all memory not that perl process

I'll wait out this scan to see if it's actually is creating a usable database for me
Comment 16 Andy Grundman 2009-06-09 15:41:02 UTC
OK, so the fact that you still have a squeezecenter-scanner.db file means the scanner didn't finish properly.  That file should have been moved back to squeezecenter.db when scanning was finished.  I wonder if you could reproduce with the database.info debug switch.  You will also want to scan a much smaller subset of your library for this test.  See if you can just scan a single directory.
Comment 17 Mikael Nyberg 2009-06-09 19:14:55 UTC
Oh did not see your reply sorry. (i did not get to my mailbox ? )
Comment 18 Mikael Nyberg 2009-06-09 19:23:28 UTC
However after waiting out that scan it did reate a databse for me that works ? I think I can see all my files.

But that scan did not output anyting to the scanner.log like the failed scan ?

Will do this next time:
database.info debug switch.

I'm expecting a couple of new CD's in a day or two

Btw during that failed scan the library never grows it stays at "0" artists etc all the time.
The "kind of" working scan that I had increased the count when you refreshed the SC web page during the scan.

I'll try again tomorrow it's late..
Comment 19 luny 2009-06-09 22:45:19 UTC
same problem here

- no progress in web UI during scan,
- after stopping and starting SC in SSODS, the squeezecenter-scanner.db is gone and music library is updated

when running scanner from the prompt, it gives the following message (even though I have set locale in SSODS to UTF8): "Your locale was detected as C, you may have problems with non-Latin filenames.  Consider changing your LANG variable to the correct locale, i.e. en_US.utf8"


Version: 7.4 - 26954 @ Tue Jun 9 01:08:52 PDT 2009
Hostname: DiskStation
Server IP Address: 192.168.1.67
Server HTTP Port Number: 9000
Operating system: Synology DiskStation (SSODS) - EN - utf8 
Platform Architecture: armv5tejl-linux
Perl Version: 5.8.8 - armv5tejl-linux-thread-multi
Total Players Recognized: 1
Comment 20 Mikael Nyberg 2009-06-10 08:05:40 UTC
Did this experiment

set "database.info debug switch."

choosed one subfolder with one album folder in it 12 songs or something.

And then i choosed "clear and rescan" and pressed the "rescan" button..

Nothing happenend ? the old dB is still there fully functional.

will attach log's they have some interesting unauthorized errors and is showing that something actually tried to scan the selected directory.
Comment 21 Mikael Nyberg 2009-06-10 08:06:47 UTC
Created attachment 5323 [details]
New logs with database.info debug switch.
Comment 22 Mikael Nyberg 2009-06-10 08:07:28 UTC
Created attachment 5324 [details]
New logs with database.info debug switch.
Comment 23 Mikael Nyberg 2009-06-10 08:18:31 UTC
Next experiment restart of Squeezebox server:

Resulting in this database after restart:
 
Library Statistics
Total Tracks: 31
Total Albums: 5
Total Artists: 5
Total Genres: 5
Total Playing Time: 2:20:57
 
Music Scan Details
Directory Scan   (13  of  13)   Complete  00:00:04

Playlist Scan   (5  of  5)   Complete  00:00:01

Merge Various Artists   (4  of  4)   Complete  00:00:01

Artwork Scan   (4  of  4)   Complete  00:00:02

The server has finished scanning your music collection.
Total Time: 00:00:08 (Wednesday, June 10, 2009 / 4:50 PM)
 
Interesting facts the selected "Music folder" contains only one of these albums !!
1 of these was in the playlist of my boom the 3 other albums are random afiak.

Attach a new set of logs
Comment 24 Mikael Nyberg 2009-06-10 08:23:00 UTC
Created attachment 5325 [details]
Server log after restart (no scanner log was created by SC  ? )
Comment 25 Mikael Nyberg 2009-06-10 08:32:16 UTC
Another try at rescan gets me a new scanner log this contain hints about files not in the selected folder but it's one of the "mystery albums" that was added after the restart ?

I spamm you with yet another log....
Comment 26 Mikael Nyberg 2009-06-10 08:33:12 UTC
Created attachment 5326 [details]
scanner.log after restart & 2'nd rescan try
Comment 27 Mikael Nyberg 2009-06-10 08:44:42 UTC
my last comment was a little wrong the scanner.log contains "dub colossus"
wich is what i'm scanning but it adds "Miles remembered" "Ingenue"
and a "A Beard of Bees" these albums are not in music folder path
Comment 28 Andy Grundman 2009-06-10 10:11:56 UTC
Do you have password protection enabled for SC?  That may be the issue, I see a lot of 401 errors in the log.
Comment 29 Mikael Nyberg 2009-06-10 10:17:08 UTC
Yes I'm using password protection in SC Déjà vu :)

I will try to remove must kill SC now it's scanning...
Comment 30 Andy Grundman 2009-06-10 10:20:21 UTC
OK I will fix that.  In the meantime if you disable that, it should fix the problem.
Comment 31 Mikael Nyberg 2009-06-10 10:30:11 UTC
It actually starts to scan ! yes, but updating of the web-UI's progress is not as swift as the MySQL was, You have to force reload the settings page before you see something both under basic where the scanning options bar is supposed to go grey and the link under should show "Scanning - View Progress   " this does not happen when you press "rescan" even if the scan starts you have to reload.
After a reload the music scan details appears.

CPU is pegged to 99% I supose it scans faster if i'm not using the web-UI for a while
Comment 32 Mikael Nyberg 2009-06-10 11:26:53 UTC
Hmm I migth have hijacked this bug ? the original poster had "noweb - sqlite"
in the description ? noweb indicating that maybe he didn't use the web-UI and therefore no password problem ?
Comment 33 Andy Grundman 2009-06-10 11:28:50 UTC
No that's just the name of the branch.
Comment 34 Aaron Solochek 2009-06-10 11:32:38 UTC
No, I was using the web.  the noweb-sqlite was just the svn branch the nightly builds that are giving me problems came from.  

And yes, I have the password protection enabled.
Comment 35 Mikael Nyberg 2009-06-10 13:23:28 UTC
Yes it did scan very well, but we have another problem

CPU usage is high all the time after the scan i had to restart SS after the scan.
to get it down to normal levels.


Library Statistics
Total Tracks: 18,430
Total Albums: 1,458
Total Artists: 1,152
Total Genres: 148
Total Playing Time: 1461:08:46
 
Music Scan Details
Directory Scan   (18430  of  18430)   Complete  02:07:23

Playlist Scan   (5  of  5)   Complete  00:00:01

Merge Various Artists   (1436  of  1436)   Complete  00:05:51

Artwork Scan   (1458  of  1458)   Complete  00:19:52
  
The server has finished scanning your music collection.
Total Time: 02:33:07 (Wednesday, June 10, 2009 / 9:55 PM)
Comment 36 Aaron Solochek 2009-06-16 08:27:58 UTC
I'm trying 27063 and my cpu is at 100% while trying to scan.  I'm going to leave it for a while and see if it actually works.  I disabled the password and restarted squeezecenter before this scan.
Comment 37 Aaron Solochek 2009-06-16 16:50:57 UTC
So I thought the scan finished, but cpu was still 100%.  I let it run for hours at 100% cpu, but I am sick of hearing the fan running, so I'm reverting back to the old working version.

I am getting a lot of errors in my server.log about being unable to read the tags of a file (I've checked a number of them, and the tags seem fine and perfectly readable to me), as well as this warning that drives me nuts:

[09-06-16 19:24:15.7925] Slim::Utils::Misc::msg (1175) Warning: [19:24:15.7918] Use of uninitialized value in numeric eq (==) at /usr/share/perl5/Slim/Utils/Scanner/Local.pm line 226.
Comment 38 Andy Grundman 2009-07-29 14:40:42 UTC
Moving all SQLite-related bugs to 8.0.
Comment 39 Andy Grundman 2011-01-12 12:05:20 UTC
Fixed.
Comment 40 Paul Chandler 2011-04-29 15:19:22 UTC
Was able to complete a scan while the password-protection was enabled. 
Build 7.6.0 r32376