Bug 15829 – Wipe and rescan fails with "Local music service has been stopped due to a problem"

Bug 15829 - Wipe and rescan fails with "Local music service has been stopped due to a problem"

Summary:

Wipe and rescan fails with "Local music service has been stopped due to a pro...

Status:	RESOLVED INVALID

Product:	SB Touch
Classification:	Unclassified
Component:	TinySC
Version:	7.5.0
Platform:	PC Windows XP

Importance:	-- normal (vote)
Target Milestone:	7.5.0
Assigned To:	Mickey Gee

URL:
Keywords:

Depends on:
Blocks:
	Show dependency tree / graph

Reported:	2010-03-03 11:28 UTC by Mickey Gee
Modified:	2010-03-04 17:57 UTC (History)
CC List:	4 users (show)

See Also:
Category:	---

Attachments
Add an attachment (proposed patch, testcase, etc.)

Note You need to log in before you can comment on or make changes to this bug.

Description Mickey Gee 2010-03-03 11:28:51 UTC

Upgraded firmware from r8610, which was playing flac track from TinySC and connected USB hard drive immediately before firmware upgrade.

Now, I have problems getting TinySC to start. See message in summary every time I try to do a wipe and scan.

From messages file, I get the following:

Mar  3 19:10:20 kernel: usb 1-1.4: new full speed USB device using fsl-ehci and address 3
Mar  3 19:10:20 kernel: usb 1-1.4: not running at top speed; connect to a high speed hub
Mar  3 19:10:20 kernel: usb 1-1.4: configuration #1 chosen from 1 choice
Mar  3 19:10:20 kernel: scsi0 : SCSI emulation for USB Mass Storage devices
Mar  3 19:10:20 kernel: usb-storage: device found at 3
Mar  3 19:10:20 kernel: usb-storage: waiting for device to settle before scanning
Mar  3 19:10:25 kernel: scsi 0:0:0:0: Direct-Access     Toshiba  USB2.0 Drive R00 1.43 PQ: 0 ANSI: 0
Mar  3 19:10:25 kernel: sd 0:0:0:0: [sda] 195371568 512-byte hardware sectors (100030 MB)
Mar  3 19:10:25 kernel: sd 0:0:0:0: [sda] Write Protect is off
Mar  3 19:10:25 kernel: sd 0:0:0:0: [sda] Mode Sense: 00 00 00 00
Mar  3 19:10:25 kernel: sd 0:0:0:0: [sda] Assuming drive cache: write through
Mar  3 19:10:25 kernel: sd 0:0:0:0: [sda] 195371568 512-byte hardware sectors (100030 MB)
Mar  3 19:10:25 kernel: sd 0:0:0:0: [sda] Write Protect is off
Mar  3 19:10:25 kernel: sd 0:0:0:0: [sda] Mode Sense: 00 00 00 00
Mar  3 19:10:25 kernel: sd 0:0:0:0: [sda] Assuming drive cache: write through
Mar  3 19:10:25 kernel:  sda:
Mar  3 19:10:25 kernel:  sda1
Mar  3 19:10:25 kernel: sd 0:0:0:0: [sda] Attached SCSI disk
Mar  3 19:10:25 kernel: usb-storage: device scan complete
Mar  3 11:10:29 root: mount.sh/automount Auto-mount of [/media/sda1] successful
Mar  3 11:10:29 squeezeplay: WARN   applet.SqueezeCenter - SqueezeCenterApplet.lua:171 addMountedDevice: sda1
Mar  3 11:10:29 squeezeplay: INFO   squeezeplay.applets - AppletManager.lua:708 store settings: SqueezeCenter
Mar  3 11:10:29 squeezeplay: WARN   applet.SqueezeCenter - SqueezeCenterApplet.lua:1205 !! Writing prefs.json file and starting scan
Mar  3 11:10:29 squeezeplay: WARN   applet.SqueezeCenter - SqueezeCenterApplet.lua:1017 Restarting squeezebox server
Mar  3 11:10:43 squeezeplay: WARN   net.thread - NetworkThread.lua:146 network thread timeout for Task(SocketHttp {mysqueezebox.com_Request}(R))
Mar  3 11:11:25 squeezeplay: WARN   applet.SqueezeboxFab4 - SqueezeboxFab4Applet.lua:773 SC guard timer - SC got killed!!!
Mar  3 11:11:38 squeezeplay: WARN   applet.SqueezeCenter - SqueezeCenterApplet.lua:1059 /media/sda1/.Squeezebox present: nil
Mar  3 11:12:09 squeezeplay: WARN   applet.SqueezeboxFab4 - SqueezeboxFab4Applet.lua:773 SC guard timer - SC got killed!!!
Mar  3 11:12:55 squeezeplay: INFO   squeezeplay.applets - AppletMeta.lua:146 entering SetupSSH

Running with firmware r8617 and a USB drive connected to Fab4 through USB hub.

Comment 1 Mickey Gee 2010-03-03 11:37:24 UTC

Same problem with another USB drive. This one had a database to wipe. Previous USB drive did not. Both drives have around 7K tracks with ~80GB music library. Same result:

Mar  3 19:28:14 kernel: usb-storage: waiting for device to settle before scanning
Mar  3 19:28:19 kernel: scsi 1:0:0:0: Direct-Access     FUJITSU  MHV2120AH             PQ: 0 ANSI: 0
Mar  3 19:28:19 kernel: sd 1:0:0:0: [sda] 234441648 512-byte hardware sectors (120034 MB)
Mar  3 19:28:19 kernel: sd 1:0:0:0: [sda] Write Protect is off
Mar  3 19:28:19 kernel: sd 1:0:0:0: [sda] Mode Sense: 03 00 00 00
Mar  3 19:28:19 kernel: sd 1:0:0:0: [sda] Assuming drive cache: write through
Mar  3 19:28:19 kernel: sd 1:0:0:0: [sda] 234441648 512-byte hardware sectors (120034 MB)
Mar  3 19:28:19 kernel: sd 1:0:0:0: [sda] Write Protect is off
Mar  3 19:28:19 kernel: sd 1:0:0:0: [sda] Mode Sense: 03 00 00 00
Mar  3 19:28:19 kernel: sd 1:0:0:0: [sda] Assuming drive cache: write through
Mar  3 19:28:19 kernel:  sda:
Mar  3 19:28:19 kernel:  sda1
Mar  3 19:28:19 kernel: sd 1:0:0:0: [sda] Attached SCSI disk
Mar  3 19:28:19 kernel: usb-storage: device scan complete
Mar  3 11:28:28 root: mount.sh/automount Auto-mount of [/media/sda1] successful
Mar  3 11:28:28 ntfs-3g[1735]: Version 2009.4.4 integrated FUSE 27
Mar  3 11:28:28 ntfs-3g[1735]: Mounted /dev/sda1 (Read-Write, label "", NTFS 3.1)
Mar  3 11:28:28 ntfs-3g[1735]: Cmdline options: 
Mar  3 11:28:28 ntfs-3g[1735]: Mount options: silent,allow_other,nonempty,relatime,fsname=/dev/sda1,blkdev,blksize=4096
Mar  3 11:28:29 squeezeplay: WARN   applet.SqueezeCenter - SqueezeCenterApplet.lua:171 addMountedDevice: sda1
Mar  3 11:28:29 squeezeplay: INFO   squeezeplay.applets - AppletManager.lua:708 store settings: SqueezeCenter
Mar  3 11:28:29 squeezeplay: WARN   applet.SqueezeCenter - SqueezeCenterApplet.lua:1205 !! Writing prefs.json file and starting scan
Mar  3 11:28:29 squeezeplay: WARN   applet.SqueezeCenter - SqueezeCenterApplet.lua:1017 Restarting squeezebox server
Mar  3 11:29:19 squeezeplay: WARN   applet.SqueezeboxFab4 - SqueezeboxFab4Applet.lua:773 SC guard timer - SC got killed!!!
Mar  3 11:29:30 ntfs-3g[1735]: Incomplete multi-sector transfer: magic: 0x454c4946  size: 1024  usa_ofs: 48  usa_count: 0  data: 65016  usn: 65015: Input/output error
Mar  3 11:29:30 ntfs-3g[1735]: Record 23349 has no FILE magic (0x44414142)
Mar  3 11:29:31 squeezeplay: WARN   applet.SqueezeCenter - SqueezeCenterApplet.lua:1054 squeezeboxDirPresent(), found it: .Squeezebox
Mar  3 11:29:31 squeezeplay: WARN   applet.SqueezeCenter - SqueezeCenterApplet.lua:1059 /media/sda1/.Squeezebox present: .Squeezebox
Mar  3 11:29:32 squeezeplay: WARN   applet.SqueezeCenter - SqueezeCenterApplet.lua:1054 squeezeboxDirPresent(), found it: .Squeezebox
Mar  3 11:29:32 squeezeplay: WARN   applet.SqueezeCenter - SqueezeCenterApplet.lua:1059 /media/sda1/.Squeezebox present: .Squeezebox
Mar  3 11:29:33 squeezeplay: WARN   applet.SqueezeCenter - SqueezeCenterApplet.lua:1054 squeezeboxDirPresent(), found it: .Squeezebox
Mar  3 11:29:33 squeezeplay: WARN   applet.SqueezeCenter - SqueezeCenterApplet.lua:1059 /media/sda1/.Squeezebox present: .Squeezebox
Mar  3 11:29:34 squeezeplay: WARN   applet.SqueezeCenter - SqueezeCenterApplet.lua:1054 squeezeboxDirPresent(), found it: .Squeezebox
Mar  3 11:29:34 squeezeplay: WARN   applet.SqueezeCenter - SqueezeCenterApplet.lua:1059 /media/sda1/.Squeezebox present: .Squeezebox
...
Mar  3 11:30:29 squeezeplay: WARN   applet.SqueezeCenter - SqueezeCenterApplet.lua:1059 /media/sda1/.Squeezebox present: .Squeezebox
Mar  3 11:30:30 squeezeplay: WARN   applet.SqueezeCenter - SqueezeCenterApplet.lua:1054 squeezeboxDirPresent(), found it: .Squeezebox
Mar  3 11:30:30 squeezeplay: WARN   applet.SqueezeCenter - SqueezeCenterApplet.lua:1059 /media/sda1/.Squeezebox present: .Squeezebox
Mar  3 11:30:31 squeezeplay: WARN   applet.SqueezeCenter - SqueezeCenterApplet.lua:1054 squeezeboxDirPresent(), found it: .Squeezebox
Mar  3 11:30:31 squeezeplay: WARN   applet.SqueezeCenter - SqueezeCenterApplet.lua:1059 /media/sda1/.Squeezebox present: .Squeezebox
Mar  3 11:30:31 squeezeplay: WARN   applet.SqueezeCenter - SqueezeCenterApplet.lua:858 *** .Squeezebox dir failed to be successfully removed from /media/sda1
Mar  3 11:31:02 squeezeplay: WARN   applet.SqueezeboxFab4 - SqueezeboxFab4Applet.lua:773 SC guard timer - SC got killed!!!

Comment 2 Felix Mueller 2010-03-03 12:11:18 UTC

Mickey - there was a problem with TinySC, see: http://forums.slimdevices.com/showthread.php?t=75870

Comment 3 Mickey Gee 2010-03-03 13:15:50 UTC

Now running firmware r8622 with same results. Here's the info from messages log:

Mar  3 13:05:34 ntfs-3g[991]: Incomplete multi-sector transfer: magic: 0x454c4946  size: 1024  usa_ofs: 48  usa_count: 0  data: 65016  usn: 65015: Input/output error
Mar  3 13:05:34 ntfs-3g[991]: Record 23349 has no FILE magic (0x44414142)
Mar  3 13:05:35 squeezeplay: WARN   applet.SqueezeCenter - SqueezeCenterApplet.lua:1054 squeezeboxDirPresent(), found it: .Squeezebox
...
Mar  3 13:06:35 squeezeplay: WARN   applet.SqueezeCenter - SqueezeCenterApplet.lua:1059 /media/sda1/.Squeezebox present: .Squeezebox
Mar  3 13:06:35 squeezeplay: WARN   applet.SqueezeCenter - SqueezeCenterApplet.lua:858 *** .Squeezebox dir failed to be successfully removed from /media/sda1
Mar  3 13:07:22 slimserver.pl: [10-03-03 13:07:22.0914] main::init (342) Starting Squeezebox Server (v7.5.0, r30318, Wed Mar  3 13:31:06 MST 2010) perl 5.010000
Mar  3 13:07:32 ntfs-3g[991]: Incomplete multi-sector transfer: magic: 0x454c4946  size: 1024  usa_ofs: 48  usa_count: 0  data: 65016  usn: 65015: Input/output error
Mar  3 13:07:32 ntfs-3g[991]: Record 23349 has no FILE magic (0x44414142)
Mar  3 13:07:32 ntfs-3g[991]: Incomplete multi-sector transfer: magic: 0x454c4946  size: 1024  usa_ofs: 48  usa_count: 0  data: 65016  usn: 65015: Input/output error
Mar  3 13:07:32 ntfs-3g[991]: Record 23349 has no FILE magic (0x44414142)
Mar  3 13:07:32 ntfs-3g[991]: Incomplete multi-sector transfer: magic: 0x454c4946  size: 1024  usa_ofs: 48  usa_count: 0  data: 65016  usn: 65015: Input/output error
Mar  3 13:07:32 ntfs-3g[991]: Record 23349 has no FILE magic (0x44414142)
Mar  3 13:07:32 slimserver.pl: [10-03-03 13:07:32.9080] Slim::Schema::Storage::throw_exception (65) Warning: Unable to connect to the database - trying to bring it up!
Mar  3 13:07:32 slimserver.pl: [10-03-03 13:07:32.9304] Slim::Schema::Storage::throw_exception (119) Error: Can't call method "do" on unblessed reference at /usr/squeezecenter/CPAN/DBIx/Class/Storage/DBI.pm line 974.
Mar  3 13:07:32 slimserver.pl: [10-03-03 13:07:32.9478] Slim::Schema::Storage::throw_exception (119) Backtrace:     frame 0: Slim::Utils::Log::logBacktrace (/usr/squeezecenter/Slim/Schema/Storage.pm line 119)    frame 1: Slim::Schema::Storage::throw_exception (/usr/squeezecenter/Slim/Schema/Storage.pm line 47)    frame 2: Slim::Schema::Storage::dbh (/usr/squeezecenter/Slim/Schema.pm line 301)    frame 3: Slim::Schema::_connect (/usr/squeezecenter/Slim/Schema.pm line 132)    frame 4: Slim::Schema::init (/usr/squeezecenter/Slim/Music/Import.pm line 645)    frame 5: Slim::Music::Import::_checkLibraryStatus (/usr/squeezecenter/Slim/Music/Import.pm line 584)    frame 6: Slim::Music::Import::useImporter (/usr/squeezecenter/Slim/Music/MusicFolderScan.pm line 48)    frame 7: Slim::Music::MusicFolderScan::init (/usr/squeezecenter/slimserver.pl line 509)    frame 8: main::init (/usr/squeezecenter/slimserver.pl line 632)    frame 9: main::main (/usr/squeezecenter/slimserver.pl line 1127)
Mar  3 13:07:32 slimserver.pl: [10-03-03 13:07:32.9844] Carp::Clan::__ANON__ (214) Warning: Carp::Clan::__ANON__(): Can't call method "do" on unblessed reference at /usr/squeezecenter/CPAN/DBIx/Class/Storage/DBI.pm line 974.
Mar  3 13:07:33 slimserver.pl: [10-03-03 13:07:32.9990] Slim::Schema::forceCommit (2076) Warning: Trying to commit transactions before DB is initialized!
Mar  3 13:07:36 squeezeplay: WARN   applet.SqueezeboxFab4 - SqueezeboxFab4Applet.lua:773 SC guard timer - SC got killed!!!

Comment 4 Andy Grundman 2010-03-03 13:27:16 UTC

Looks like you killed your NTFS filesystem?

Comment 5 Mickey Gee 2010-03-04 17:57:37 UTC

Performed disk check under Windows. Plugged drive into Fab4 r8622. Running without problems.