Bug 14466 - segmentation fault on startup (sql helper related)
: segmentation fault on startup (sql helper related)
Status: NEW
Product: Logitech Media Server
Classification: Unclassified
Component: Misc
: 7.4.1
: PC Ubuntu Linux
: -- normal with 3 votes (vote)
: ---
Assigned To: Unassigned bug - please assign me!
http://forums.slimdevices.com/showthr...
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2009-10-01 01:18 UTC by Jussi Kukkonen
Modified: 2011-05-30 07:24 UTC (History)
4 users (show)

See Also:
Category: Bug


Attachments
sbs output with "--d_startup --debug server=debug,database.mysql" (9.60 KB, text/plain)
2009-10-05 03:12 UTC, Jussi Kukkonen
Details
Output from SBS debug run enclosed (10.95 KB, text/plain)
2009-10-05 06:08 UTC, Per Arne Enstad
Details
Log using the debug parameters provided, Ubuntu 6.06 (10.82 KB, text/plain)
2009-10-05 06:42 UTC, Brian Morley
Details
generated my.cnf (1.17 KB, text/plain)
2009-10-05 08:42 UTC, Jussi Kukkonen
Details
Debug on fresh VM of Ubuntu 6.06 (10.89 KB, text/plain)
2009-10-05 15:08 UTC, Brian Morley
Details
Debug printout from testing SB 7.4.1 startup on an Ubuntu 6.06 LTS (14.52 KB, text/plain)
2009-10-22 12:53 UTC, Per Arne Enstad
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Jussi Kukkonen 2009-10-01 01:18:49 UTC
I'm seeing a segfault on startup after upgrading to SBS (using your stable Debian packages). Output with "--debug server=DEBUG database=DEBUG" follows:

[09-10-01 11:07:59.7614] main::init (320) Starting Squeezebox Server (v7.4.0, r28672, Mon Sep 28 17:48:40 PDT 2009) perl 5.008007
[09-10-01 11:07:59.7663] main::init (337) Squeezebox Server OS Specific init...
[09-10-01 11:07:59.7669] main::init (381) Squeezebox Server settings effective user and group if requested...
[09-10-01 11:07:59.7674] main::init (398) Squeezebox Server binary search path init...
[09-10-01 11:07:59.7682] main::init (402) Squeezebox Server PluginManager init...
[09-10-01 11:07:59.8188] main::init (405) Squeezebox Server strings init...
[09-10-01 11:07:59.8219] Slim::Utils::Strings::loadStrings (131) Retrieving string data from string cache: /var/lib/squeezeboxserver/cache/stringcache.i686-linux.bin
[09-10-01 11:07:59.8471] main::init (409) Squeezebox Server SQL init...
Segmentation fault


This is on an an ancient Ubuntu install (6.06.2) so I do understand if you're not interested in supporting something like perl 5.8.7. It would be nice if these requirements were expressed in the debian packaging though.

However, if you'd like to help me debug this, I'm prepared to do the legwork.  I'm quite accustomed to debugging, but perl scares me so a bit of help would be welcome... 

The OS identification seems to work all right (Debian is found), but I don't understand where the call "$sqlHelperClass->init()" actually goes: I thought MySQLHelper::init but that does not seem to get called?
Comment 1 Jussi Kukkonen 2009-10-01 01:29:37 UTC
Same thing with 7.4.1 r28710 (from unstable repo).
Comment 2 James Richardson 2009-10-01 17:35:47 UTC
Michael: Related to the ReadyNAS issue?
Comment 3 Jussi Kukkonen 2009-10-02 03:24:39 UTC
Something I forgot to mention: Just like another user* in the forums, I also did see the web interface initially. I selected the music and playlist dirs and then the server stopped responding (and started crashing at startup).

*) http://forums.slimdevices.com/showthread.php?t=68875
Comment 4 Jussi Kukkonen 2009-10-02 06:14:51 UTC
I'll document my attempts at figuring this out. Like I said, I don't really know my way around perl so feel free to advice...

Any attempts at adding debug printing in Slim::Utils::MySQLHelper::init() or deeper fail.

Running in debugger I can actually step into  MySQLHelper::init(). Things go fine until the last line of DBD::mysql::dr::connect(), which is line 146 in CPAN/DBD/mysql.pm:
       $this;
That call will never return and will keep hogging a fair amount of CPU.

The call stack looks like this:

main::init(/usr/sbin/squeezeboxserver:410):
410:			$sqlHelperClass->init();

Slim::Utils::MySQLHelper::dbh(/usr/share/perl5/Slim/Utils/MySQLHelper.pm:546):
546:		return eval { DBI->connect($dsn, undef, undef, { 'PrintError' => 0, 'RaiseError' => 0 }) };

DBI::connect(/usr/share/squeezeboxserver/CPAN/DBI.pm:708):
708:	    my $dbh = &$connect_closure(undef, undef);

DBI::CODE(0xb31e544)(/usr/share/squeezeboxserver/CPAN/DBI.pm:640):
640:		unless ($dbh = $drh->$connect_meth($dsn, $user, $pass, $attr)) {

DBD::mysql::dr::connect(/usr/share/squeezeboxserver/CPAN/DBD/mysql.pm:146):
146:	    $this;
Comment 5 Michael Herger 2009-10-05 00:19:42 UTC
Please wipe all your cache folder and try again.

All those who voted for this bug: could you please give some information about your systems?
Comment 6 Jussi Kukkonen 2009-10-05 01:12:46 UTC
(In reply to comment #5)
> Please wipe all your cache folder and try again.

I assume this means /var/lib/squeezeboxserver/cache/. Removing this directory makes no difference. 

Just in case it is useful, here are the contents of 
/var/lib/squeezeboxserver/cache/mysql-error-log.txt after cleaning the cache dir and starting SBS once.

  jku@luna:~$ cat /var/lib/squeezeboxserver/cache/mysql-error-log.txt 
  InnoDB: The first specified data file ./ibdata1 did not exist:
  InnoDB: a new database to be created!
  091005 11:01:57  InnoDB: Setting file ./ibdata1 size to 10 MB
  InnoDB: Database physically writes the file full: wait...
  091005 11:01:57  InnoDB: Log file ./ib_logfile0 did not exist: new to be created
  InnoDB: Setting log file ./ib_logfile0 size to 5 MB
  InnoDB: Database physically writes the file full: wait...
  091005 11:01:57  InnoDB: Log file ./ib_logfile1 did not exist: new to be created
  InnoDB: Setting log file ./ib_logfile1 size to 5 MB
  InnoDB: Database physically writes the file full: wait...
  InnoDB: Doublewrite buffer not found: creating new
  InnoDB: Doublewrite buffer created
  InnoDB: Creating foreign key constraint system tables
  InnoDB: Foreign key constraint system tables created
  091005 11:01:58  InnoDB: Started; log sequence number 0 0
  091005 11:01:58 [Warning] Can't open and lock time zone table: Table 'mysql.time_zone_leap_second' doesn't exist trying to live without them
/usr/sbin/mysqld: ready for connections.
  Version: '4.1.15-Debian_1ubuntu5'  socket: '/var/lib/squeezeboxserver/cache/squeezebox-mysql.sock'  port: 9092  Source distribution


> All those who voted for this bug: could you please give some information about
> your systems?

If you need anything specific, please let me know. I don't really know what else to tell you.
Comment 7 Michael Herger 2009-10-05 02:25:38 UTC
Jussi - thanks for the additional information. What I'm looking for is OS versions etc. which you have given, but not the others who voted for this bug.

> I'm seeing a segfault on startup after upgrading to SBS (using your stable
> Debian packages). Output with "--debug server=DEBUG database=DEBUG" follows:

Could you please try again with "--d_startup --debug server=debug,database.mysql"
Comment 8 Jussi Kukkonen 2009-10-05 03:12:10 UTC
Created attachment 6013 [details]
sbs output with "--d_startup --debug server=debug,database.mysql"

(In reply to comment #7)
> Jussi - thanks for the additional information. What I'm looking for is OS
> versions etc. which you have given, but not the others who voted for this bug.

At least one other forum poster was also on Ubuntu 6.06.

> > I'm seeing a segfault on startup after upgrading to SBS (using your stable
> > Debian packages). Output with "--debug server=DEBUG database=DEBUG" follows:
> 
> Could you please try again with "--d_startup --debug
> server=debug,database.mysql"

attaching output. I thought you might have missed a "=debug" after database.mysql, but adding that made no difference to the output.
Comment 9 Per Arne Enstad 2009-10-05 06:04:39 UTC
(In reply to comment #7)
> Jussi - thanks for the additional information. What I'm looking for is OS
> versions etc. which you have given, but not the others who voted for this bug.
> 
> > I'm seeing a segfault on startup after upgrading to SBS (using your stable
> > Debian packages). Output with "--debug server=DEBUG database=DEBUG" follows:
> 
> Could you please try again with "--d_startup --debug
> server=debug,database.mysql"

I'm seeing the same problem as Jussi. My distro is:

pae@vaktmester:/etc$ more lsb-release
DISTRIB_ID=Ubuntu
DISTRIB_RELEASE=6.06
DISTRIB_CODENAME=dapper
DISTRIB_DESCRIPTION="Ubuntu 6.06.2 LTS"

Will attach the output from sbs startup with parameters above in case it provides additional information to what has already been submitted.

Regards,

- Per Arne Enstad
Comment 10 Per Arne Enstad 2009-10-05 06:08:25 UTC
Created attachment 6014 [details]
Output from SBS debug run enclosed


pae@vaktmester:~$ sudo squeezeboxserver --d_startup --debug server=debug,database.mysql
Comment 11 Brian Morley 2009-10-05 06:42:59 UTC
Created attachment 6015 [details]
Log using the debug parameters provided, Ubuntu 6.06
Comment 12 Brian Morley 2009-10-05 07:56:59 UTC
(In reply to comment #9)
> (In reply to comment #7)
> > Jussi - thanks for the additional information. What I'm looking for is OS
> > versions etc. which you have given, but not the others who voted for this bug.
> > 
> > > I'm seeing a segfault on startup after upgrading to SBS (using your stable
> > > Debian packages). Output with "--debug server=DEBUG database=DEBUG" follows:
> > 
> > Could you please try again with "--d_startup --debug
> > server=debug,database.mysql"
> 
> I'm seeing the same problem as Jussi. My distro is:
> 
> pae@vaktmester:/etc$ more lsb-release
> DISTRIB_ID=Ubuntu
> DISTRIB_RELEASE=6.06
> DISTRIB_CODENAME=dapper
> DISTRIB_DESCRIPTION="Ubuntu 6.06.2 LTS"
> 
> Will attach the output from sbs startup with parameters above in case it
> provides additional information to what has already been submitted.
> 
> Regards,
> 
> - Per Arne Enstad

My distribution information is identical
Comment 13 Michael Herger 2009-10-05 08:17:11 UTC
Is /var/lib/squeezeboxserver/cache/my.cnf being created?

QA - do you have a Ubuntu 6.06 VM you could test this with?
Comment 14 Jussi Kukkonen 2009-10-05 08:42:45 UTC
Created attachment 6016 [details]
generated my.cnf

(In reply to comment #13)
> Is /var/lib/squeezeboxserver/cache/my.cnf being created?

Yes. Attaching the created my.cnf (looks fine to me).

I noticed that I get some additional output if I remove the cache dir and then run with "--d_startup --debug server=debug,database.mysql":

 [... clip lots of identical output ...]
[09-10-05 18:40:18.8141] main::init (409) Squeezebox Server SQL init...
[09-10-05 18:40:18.8151] Slim::Utils::MySQLHelper::createConfig (167) createConfig() Creating config from file: [/usr/share/squeezeboxserver/MySQL/my.tt] -> [/var/lib/squeezeboxserver/cache/my.cnf].
[09-10-05 18:40:18.8380] Slim::Utils::MySQLHelper::init (99) Creating system tables..
[09-10-05 18:40:18.8389] Slim::Utils::MySQLHelper::startServer (238) About to start MySQL as a process with command: [/usr/sbin/mysqld --defaults-file=/var/lib/squeezeboxserver/cache/my.cnf]
[09-10-05 18:40:19.9990] Slim::Utils::MySQLHelper::stopServer (411) Running shutdown.
Segmentation fault
Comment 15 Brian Morley 2009-10-05 15:08:13 UTC
Created attachment 6018 [details]
Debug on fresh VM of Ubuntu 6.06
Comment 16 Brian Morley 2009-10-05 15:12:06 UTC
I downloaded a VMware appliance of Ubuntu 6.06 for Fusion on a Mac

After getting all updates, I installed SBS.  Initially when I checked the /var/lib/Squeezeboxserver/cache there was nothing present.  After stopping and starting, the cache directory was populated.  The my.cnf file was present at that point.

I included debug information using the parameters provided in the attachments section.
Comment 17 Jussi Kukkonen 2009-10-17 11:16:52 UTC
I thought I'd mention that I am ready to work on this myself, but I need a bit of help -- I just don't know what is failing and how I should proceed.

Alternatively (if your QA does not have Ubuntu 6.06.2 available), I could arrange shell access for a slimdevices developer on my media machine.
Comment 18 James Richardson 2009-10-22 11:28:35 UTC
Jusssi: please re-test with the latest 7.4.1 stable build, are you able to replicate the issue?
Comment 19 Per Arne Enstad 2009-10-22 12:15:31 UTC
(In reply to comment #18)
> Jusssi: please re-test with the latest 7.4.1 stable build, are you able to
> replicate the issue?

Hmmm...
The 7.4.1 stable distro seems to include a test for PERL => 5.8.8. 
Standard Ubuntu 6.06 LTS is only @ 5.8.7:

Unpacking replacement squeezeboxserver ...
dpkg: dependency problems prevent configuration of squeezeboxserver:
 squeezeboxserver depends on perl (>= 5.8.8); however:
  Version of perl on system is 5.8.7-10ubuntu1.2.
dpkg: error processing squeezeboxserver (--install):
 dependency problems - leaving unconfigured
Errors were encountered while processing:
 squeezeboxserver

Do you have a convenient way to circumvent this test in order to test the original problem?
Comment 20 Per Arne Enstad 2009-10-22 12:47:21 UTC
(In reply to comment #18)
> Jusssi: please re-test with the latest 7.4.1 stable build, are you able to
> replicate the issue?

Forget the previous post. I must learn to think before I write.. :)
The following fixed the dependencies problem and allowed the package to be installed:

sudo dpkg -i --force depends squeezeboxserver_7.4.1_all.deb

But from here some wierd behaveour occurs. Starting the squeezeboxserver the normal way results in (appearently) same behaveour as before - crash and restart every 5 seconds.

However manual start with debug yields another result, see attachment.

sudo squeezeboxserver --d_startup --debug server=debug,database.mysql

Regards,

Per Arne
Comment 21 Per Arne Enstad 2009-10-22 12:53:19 UTC
Created attachment 6189 [details]
Debug printout from testing SB 7.4.1 startup on an Ubuntu 6.06 LTS

After performing this debug run, the following process is still active:

113      26505  0.0  7.4  95360 14136 ?        Sl   21:27   0:00 /usr/sbin/mysqld --defaults-file=/var/lib/squeezeboxserver/cache/my.cnf
Comment 22 Jussi Kukkonen 2009-10-23 05:06:25 UTC
I'll test when I have my next service break  -- I'm trying to keep up the so far excellent "Significant Other Acceptance Factor" -- this will be in the next few days.

(In reply to comment #20)
> But from here some wierd behaveour occurs. Starting the squeezeboxserver the
> normal way results in (appearently) same behaveour as before - crash and
> restart every 5 seconds.
> 
> However manual start with debug yields another result, see attachment.

Based on the log it looks like this specific bug is fixed: "Squeezebox Server SQL init" seems to complete fine.

Googling reveals that ownership issues with the log directory may be a reason for the errors you see. You are running the binary as root and it may have created the log directory somewhere as root. Later it changes into user squeezeboxserver and doesn't have rights to write to the log dir anymore... I'm not sure what the default location is though.
Comment 23 Jussi Kukkonen 2009-10-24 03:31:26 UTC
(In reply to comment #18)
> Jusssi: please re-test with the latest 7.4.1 stable build, are you able to
> replicate the issue?

Yes. No changes in behaviour. Except that the Perl requirements seem to have changed as Per noted.

I did see the server start once (similar to comment 3) but then it segfaulted after I've set the music and playlist dir in the web ui. I could not reproduce this again, normally I just get the same output as in the first attachment.


James, I notice you downgraded the severity from critical. I don't quite understand that: A segfault at startup seems to easily fill the requirements for Critical.
Comment 24 Jussi Kukkonen 2009-10-28 03:54:17 UTC
I'm sorry to report that I have not been able to continue testing with a "supported" system: upgrading perl to 5.8.8 is beyond my skills and time at the moment. Details for those interested in trying:
 * Ubuntu Hardy perl binaries require a libc upgrade
 * Building hardys perl source packages requires upgrading libdb4.6-dev and gcc
I just can't justify doing either of these at the moment.

I can continue testing if the developers think there's a point of doing that with perl 5.8.7, otherwise I'll have to give up and continue with squeezecenter 7.3.4 -- it's just fine for me so I'm not really complaining ;)
Comment 25 Marc Reichman 2010-03-06 07:49:11 UTC
I had the same issue on my FC3 install that I was running 5.8.7 on. Upgrading to 5.8.8 via SRPM made this go away.
Comment 26 Chris Owens 2010-03-15 18:06:31 UTC
7.4.x milestone is in the past
Comment 27 Michael Herger 2011-05-30 07:24:30 UTC
Is this still an issue?