Bug 3777 - scanner.pl throwing errors in log
: scanner.pl throwing errors in log
Status: RESOLVED INVALID
Product: Logitech Media Server
Classification: Unclassified
Component: Scanner
: 6.5b1
: PC Windows Server 2003
: P2 normal (vote)
: ---
Assigned To: Dan Sully
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2006-07-19 02:36 UTC by Greg Hamilton
Modified: 2009-03-30 22:09 UTC (History)
3 users (show)

See Also:
Category: ---


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Greg Hamilton 2006-07-19 02:36:33 UTC
Various Art's and artwork are not working correctly.  
It seems that there are some errors during the scanning import process

I've attached the log


C:\Program Files\slimperl\trunk\server>perl scanner.pl --wipe --d_import --progr
ess
2006-07-18 21:49:25.5144 Import: Adding Slim::Music::PlaylistFolderScan Scan
2006-07-18 21:49:25.5154 Import: Adding Slim::Music::MusicFolderScan Scan
2006-07-18 21:49:25.5173 Import: Wiped all in-memory caches.
2006-07-18 21:49:25.5176 Import: Start schema_clear
2006-07-18 21:49:32.5746 Import: End schema_clear
2006-07-18 21:49:32.5749 Import: Wiped info database
2006-07-18 21:49:32.6208 Import: Starting Slim::Music::MusicFolderScan scan
2006-07-18 21:49:32.6271 About to look for files in D:\My Music
2006-07-18 21:49:32.6282 For files with extensions in: [(?i-xsm:\.(?:ape|wma|shn
|wav|wave|mp3|mp2|flc|flac|m4a|mov|m4b|mp4|mp+|mpc|ogg|aif|aiff|lnk|cue)$)]
2006-07-18 21:49:51.2915 Found 25628 files in D:\My Music
 52% [=====================                    ]  10.02 tracks/sec 23m13s LEFTUs
e of uninitialized value in multiplication (*) at C:\Program Files\slimperl\trun
k\server\lib/MP3/Info.pm line 1807, <$fh> line 1.
Use of uninitialized value in multiplication (*) at C:\Program Files\slimperl\tr
unk\server\lib/MP3/Info.pm line 1807, <$fh> line 1.
Use of uninitialized value in multiplication (*) at C:\Program Files\slimperl\tr
unk\server\lib/MP3/Info.pm line 1807, <$fh> line 1.
Use of uninitialized value in multiplication (*) at C:\Program Files\slimperl\tr
unk\server\lib/MP3/Info.pm line 1807, <$fh> line 1.
 53% [=====================                    ]   9.52 tracks/sec 22m47s LEFTSi
ze mismatch on APIC
 at C:\Program Files\slimperl\trunk\server/Slim/Formats/MP3.pm line 102
 58% [========================                 ]   8.76 tracks/sec 20m11s LEFTUs
e of uninitialized value in multiplication (*) at C:\Program Files\slimperl\trun
k\server\lib/MP3/Info.pm line 1807, <$fh> line 1.
Use of uninitialized value in multiplication (*) at C:\Program Files\slimperl\tr
unk\server\lib/MP3/Info.pm line 1807, <$fh> line 1.
Use of uninitialized value in multiplication (*) at C:\Program Files\slimperl\tr
unk\server\lib/MP3/Info.pm line 1807, <$fh> line 1.
Use of uninitialized value in multiplication (*) at C:\Program Files\slimperl\tr
unk\server\lib/MP3/Info.pm line 1807, <$fh> line 1.
100% [=========================================]   8.53 tracks/sec 50m04s DONE
2006-07-18 22:39:55.7880 Import: Completed Slim::Music::MusicFolderScan Scan in
3023 seconds.
2006-07-18 22:39:55.7885 Import: Starting Slim::Music::PlaylistFolderScan scan
2006-07-18 22:39:55.8733 About to look for files in D:\My Playlists
2006-07-18 22:39:55.8748 For files with extensions in: [(?i-xsm:\.(?:asf|wax|asx
|lnk|wpl|m3u|pls|xspf|cue|lnk)$)]
2006-07-18 22:39:55.8911 Import: Starting mergeVariousArtistsAlbums().
 13% [=====                                    ]  13.84 tracks/sec 01m27s LEFTDB
D::mysql::st execute failed: Can't create/write to file 'C:\DOCUME~1\ADMINI~1\LO
CALS~1\Temp\#sql_938_0.MYI' (Errcode: 13) at C:\Program Files\slimperl\trunk\ser
ver\CPAN/DBIx/Class/Storage/DBI.pm line 525.
2006-07-18 22:40:10.2359 ERROR: Error executing 'SELECT me.id, me.url, me.conten
t_type, me.title, me.titlesort, me.titlesearch, me.album, me.tracknum, me.timest
amp, me.filesize, me.tag, me.disc, me.thumb, me.remote, me.audio, me.audio_size,
 me.audio_offset, me.year, me.secs, me.cover, me.vbr_scale, me.bitrate, me.sampl
erate, me.samplesize, me.channels, me.block_alignment, me.endian, me.bpm, me.tag
version, me.drm, me.moodlogic_id, me.moodlogic_mixable, me.musicmagic_mixable, m
e.musicbrainz_id, me.playcount, me.lastplayed, me.lossless, me.lyrics, me.rating
, me.replay_gain, me.replay_peak, contributorTracks.role, contributorTracks.cont
ributor, contributorTracks.track FROM tracks me LEFT JOIN contributor_track cont
ributorTracks ON ( contributorTracks.track = me.id ) WHERE ( ( ( contributorTrac
ks.role = ? ) AND ( me.album = ? ) ) ) ORDER BY disc, tracknum, titlesort, contr
ibutorTracks.track' (`1', `309'): DBD::mysql::st execute failed: Can't create/wr
ite to file 'C:\DOCUME~1\ADMINI~1\LOCALS~1\Temp\#sql_938_0.MYI' (Errcode: 13) at
 C:\Program Files\slimperl\trunk\server\CPAN/DBIx/Class/Storage/DBI.pm line 525.


2006-07-18 22:40:10.2363 ERROR: Backtrace follows:

2006-07-18 22:40:10.2367 Backtrace:

   frame 0: Slim::Schema::Storage::throw_exception (C:\Program Files\slimperl\tr
unk\server\CPAN/DBIx/Class/Storage/DBI.pm line 530)
   frame 1: DBIx::Class::Storage::DBI::_execute (C:\Program Files\slimperl\trunk
\server\CPAN/DBIx/Class/Storage/DBI.pm line 577)
   frame 2: DBIx::Class::Storage::DBI::_select (C:\Program Files\slimperl\trunk\
server\CPAN/DBIx/Class/Storage/DBI/Cursor.pm line 79)
   frame 3: DBIx::Class::Storage::DBI::Cursor::next (C:\Program Files\slimperl\t
runk\server\CPAN/DBIx/Class/ResultSet.pm line 516)
   frame 4: DBIx::Class::ResultSet::next (C:\Program Files\slimperl\trunk\server
/Slim/Schema.pm line 777)
   frame 5: Slim::Schema::mergeVariousArtistsAlbums (C:/Program Files/slimperl/t
runk/server/Slim/Music/Import.pm line 141)
   frame 6: Slim::Music::Import::startScan (scanner.pl line 150)
   frame 7: main::__ANON__ (C:\Program Files\slimperl\trunk\server\CPAN/DBIx/Cla
ss/Schema.pm line 588)
   frame 8: (eval) (C:\Program Files\slimperl\trunk\server\CPAN/DBIx/Class/Schem
a.pm line 576)
   frame 9: DBIx::Class::Schema::txn_do (scanner.pl line 161)
   frame 10: main::main (scanner.pl line 278)

DBD::mysql::st fetchrow_array failed: fetch() without execute() at C:\Program Fi
les\slimperl\trunk\server\CPAN/DBIx/Class/Storage/DBI/Cursor.pm line 86.
2006-07-18 22:40:10.6431 ERROR: DBD::mysql::st fetchrow_array failed: fetch() wi
thout execute() at C:\Program Files\slimperl\trunk\server\CPAN/DBIx/Class/Storag
e/DBI/Cursor.pm line 86.

2006-07-18 22:40:10.6436 ERROR: Backtrace follows:

2006-07-18 22:40:10.6439 Backtrace:

   frame 0: Slim::Schema::throw_exception (C:\Program Files\slimperl\trunk\serve
r\CPAN/DBIx/Class/Schema.pm line 610)
   frame 1: DBIx::Class::Schema::txn_do (scanner.pl line 161)
   frame 2: main::main (scanner.pl line 278)
Comment 1 KDF 2006-07-19 07:25:10 UTC
see bug 3689
Comment 2 Dan Sully 2006-07-19 09:14:46 UTC
Greg - a reboot should fix this.
Comment 3 Chris Owens 2006-07-19 10:02:30 UTC
Let us know if you're still having a problem.
Comment 4 Greg Hamilton 2006-07-19 17:10:22 UTC
Dan, Chris

What about the:

Use of uninitialized value in multiplication (*) at C:\Program
Files\slimperl\trunk\server\lib/MP3/Info.pm line 1807, <$fh> line 1.

Is there anyway to determine what is causing this?  I'm assuming it's something tagged incorrectly.

Comment 5 Greg Hamilton 2006-07-19 17:53:27 UTC
A reboot cleared the major error, however i did have an additional question on how to determin what is causing the error/warning in info.pm.  Any way to get more details on what is causing it?
Comment 6 Dan Sully 2006-07-23 19:02:58 UTC
Yes - run with --d_scan to see what file. It will be an mp3.
Comment 7 Dan Sully 2006-07-25 23:02:10 UTC
ping
Comment 8 Greg Hamilton 2006-07-26 08:45:58 UTC
Resolved.  I had some files labeled as MP3's which were not.  
Comment 9 Greg Hamilton 2006-07-28 21:15:52 UTC
Dan

I update to revision 8731
and clean up my library to remove some corrputed MP3's

However I'm still having a problem during the mergeVariousArtistsAlbums phase
Any idea as to what is going on?  Windows Server 2003, running as the administrator.


Attached is the latest output from scanner.pl

C:\Program Files\slimperl\trunk\server>perl scanner.pl --wipe --d_import --progr
ess
2006-07-28 23:07:22.4604 Import: Adding Slim::Music::PlaylistFolderScan Scan
2006-07-28 23:07:22.4615 Import: Adding Slim::Music::MusicFolderScan Scan
2006-07-28 23:07:22.5497 Import: Wiped all in-memory caches.
2006-07-28 23:07:22.5500 Import: Start schema_clear
2006-07-28 23:07:29.0799 Import: End schema_clear
2006-07-28 23:07:29.0803 Import: Wiped info database
2006-07-28 23:07:29.0805 Import: Starting Slim::Music::MusicFolderScan scan
2006-07-28 23:07:58.1618 Found 25622 files in D:\My Music
100% [=========================================]   8.62 tracks/sec 49m32s DONE
2006-07-28 23:57:30.4626 Import: Completed Slim::Music::MusicFolderScan Scan in 3001 seconds.
2006-07-28 23:57:30.4631 Import: Starting Slim::Music::PlaylistFolderScan scan
2006-07-28 23:57:30.5062 Import: Starting mergeVariousArtistsAlbums().
 10% [=========                                                                                ]  32.74 tracks/sec 01m27s LEFTDBD::m
ysql::st execute failed: Can't create/write to file 'C:\DOCUME~1\ADMINI~1\LOCALS~1\Temp\#sql_8c4_0.MYI' (Errcode: 13) at C:\Program
Files\slimperl\trunk\server\CPAN/DBIx/Class/Storage/DBI.pm line 743.
2006-07-28 23:57:41.4343 ERROR: Error executing 'SELECT me.id, me.url, me.content_type, me.title, me.titlesort, me.titlesearch, me.a
lbum, me.tracknum, me.timestamp, me.filesize, me.tag, me.disc, me.thumb, me.remote, me.audio, me.audio_size, me.audio_offset, me.yea
r, me.secs, me.cover, me.vbr_scale, me.bitrate, me.samplerate, me.samplesize, me.channels, me.block_alignment, me.endian, me.bpm, me
.tagversion, me.drm, me.moodlogic_id, me.moodlogic_mixable, me.musicmagic_mixable, me.musicbrainz_id, me.playcount, me.lastplayed, m
e.lossless, me.lyrics, me.rating, me.replay_gain, me.replay_peak, contributorTracks.role, contributorTracks.contributor, contributor
Tracks.track FROM tracks me LEFT JOIN contributor_track contributorTracks ON ( contributorTracks.track = me.id ) WHERE ( ( ( contrib
utorTracks.role = ? ) AND ( me.album = ? ) ) ) ORDER BY disc, tracknum, titlesort, contributorTracks.track': DBD::mysql::st execute
failed: Can't create/write to file 'C:\DOCUME~1\ADMINI~1\LOCALS~1\Temp\#sql_8c4_0.MYI' (Errcode: 13) at C:\Program Files\slimperl\tr
unk\server\CPAN/DBIx/Class/Storage/DBI.pm line 743.

2006-07-28 23:57:41.4352 ERROR: Backtrace follows:

2006-07-28 23:57:41.4358 Backtrace:

   frame 0: Slim::Schema::Storage::throw_exception (C:\Program Files\slimperl\trunk\server\CPAN/DBIx/Class/Storage/DBI.pm line 745)
   frame 1: DBIx::Class::Storage::DBI::_execute (C:\Program Files\slimperl\trunk\server\CPAN/DBIx/Class/Storage/DBI.pm line 798)
   frame 2: DBIx::Class::Storage::DBI::_select (C:\Program Files\slimperl\trunk\server\CPAN/DBIx/Class/Storage/DBI/Cursor.pm line 79
)
   frame 3: DBIx::Class::Storage::DBI::Cursor::next (C:\Program Files\slimperl\trunk\server\CPAN/DBIx/Class/ResultSet.pm line 677)
   frame 4: DBIx::Class::ResultSet::next (C:\Program Files\slimperl\trunk\server/Slim/Schema.pm line 824)
   frame 5: Slim::Schema::mergeVariousArtistsAlbums (C:/Program Files/slimperl/trunk/server/Slim/Music/Import.pm line 154)
   frame 6: Slim::Music::Import::startScan (scanner.pl line 149)
   frame 7: main::__ANON__ (C:\Program Files\slimperl\trunk\server\CPAN/DBIx/Class/Schema.pm line 584)
   frame 8: (eval) (C:\Program Files\slimperl\trunk\server\CPAN/DBIx/Class/Schema.pm line 572)
   frame 9: DBIx::Class::Schema::txn_do (scanner.pl line 160)
   frame 10: main::main (scanner.pl line 277)

DBD::mysql::st fetchrow_array failed: fetch() without execute() at C:\Program Files\slimperl\trunk\server\CPAN/DBIx/Class/Storage/DB
I/Cursor.pm line 86.
2006-07-28 23:57:41.8537 ERROR: DBD::mysql::st fetchrow_array failed: fetch() without execute() at C:\Program Files\slimperl\trunk\s
erver\CPAN/DBIx/Class/Storage/DBI/Cursor.pm line 86.

2006-07-28 23:57:41.8672 ERROR: Backtrace follows:

2006-07-28 23:57:41.8764 Backtrace:

   frame 0: Slim::Schema::throw_exception (C:\Program Files\slimperl\trunk\server\CPAN/DBIx/Class/Schema.pm line 606)
   frame 1: DBIx::Class::Schema::txn_do (scanner.pl line 160)
   frame 2: main::main (scanner.pl line 277)


Comment 10 Dan Sully 2006-07-28 21:45:40 UTC
Subject: Re: 

Error code: 13 seems to be 'Permission Denied'.. but you're running as
Administrator, which doesn't make any sense. I've not seen this error before.
The only other variable here is Windows 2003 Server itself.. does it have any
different permission issues than say XP?

Comment 11 Dan Sully 2006-08-09 15:51:24 UTC
Greg - any luck/update here?

Thanks
Comment 12 Greg Hamilton 2006-08-09 18:07:20 UTC
Dan,

Sorry I missed your request for follow-up.  I can report as of yesterday afternoon the problem no longer occurs.
I figured out that the scanner was only failing during the mergeVarious portions and determined it was related to the CA E-trush antivirus software I was running.  Once I removed it and installed something else it has been working fine.    It's possible the virus scanner was just not releasing the file lock quick enough.
Comment 13 Dan Sully 2006-08-09 18:09:47 UTC
Thanks. Good to know. Wouldn't be the first time a virus scanner has caused issues.

Kevin - this is something your team should be aware of.
Comment 14 Chris Owens 2006-08-18 14:21:43 UTC
So is the problem that the virus scanner is tied in to the filesystem and is returning a failure trying to write that file  until it wakes up enough to be able to scan what's going on with our reading and writing?

Do other applications auto retry in this case?  Should we?
Comment 15 Dan Sully 2006-08-18 15:37:51 UTC
The virus scanner is being too slow checking the temporary file that MySQL is using.

It's a MySQL issue, I'm not sure if there's a work around
Comment 16 Greg Hamilton 2006-08-18 16:01:53 UTC
Dan

Do you know if MySql is always creating the temp files with the same extension?
If so it may be possible to put in a scanner exception.

Personally I switched antivirus scanners and I have not had the problem since.
Comment 17 Dan Sully 2006-08-18 16:03:52 UTC
I don't know.
Comment 18 Dwayne Hull 2009-03-30 22:09:54 UTC
*** Bug 11559 has been marked as a duplicate of this bug. ***