Reply To: Firefly keeps crashing on startup

#12716
Metzeler
Participant

@rpedde wrote:

@Metzeler wrote:

@fizze wrote:

Are you sure you aren’t invoking another copy of firefly in another skript?

In unslung, after installing the ipkg a startup skript is in /opt/etc/init.d/ anyway. So if you invoke another copy, there may be conflicts, locks on the DB and whatnot… causing firefly to shutdown, eventually?

But as far as I know the script under /opt/etc/init.d (S60mt-daapd) isn´t started during the NSLU boot process, that´s why I´ve put “./optetc/init.s/S60mt-daapd” in the rc.local.

Don’t know if it helps, but there are only three ways to send it a shutdown signal.

1. Send a TERM signal to the pid
2. Run another copy with a “-k” option
3. Hit the shutdown button from the web interface.

That’s it.

You can maybe turn the debuglevel up to 9 and comb through the logs to see which of the three it is.

— Ron

Hi Ron,

I´ve checked this, but amazingly I get different results with every start.
For the first start with debug level 9 the logfile looked like this:

2007-09-27 11:42:51 (00000400): Firefly Version svn-1668: Starting with debuglevel 9
2007-09-27 11:42:51 (00000400): Attempting to load plugin /opt/share/mt-daapd/plugins/rsp.so
2007-09-27 11:42:51 (00000400): Loaded plugin /opt/share/mt-daapd/plugins/rsp.so (rsp/svn-1668)
2007-09-27 11:42:51 (00000400): New transcode codec list:
2007-09-27 11:42:51 (00000400): Attempting to load plugin /opt/share/mt-daapd/plugins/out-daap.so
2007-09-27 11:42:51 (00000400): Loaded plugin /opt/share/mt-daapd/plugins/out-daap.so (daap/svn-1668)
2007-09-27 11:42:51 (00000400): New transcode codec list:
2007-09-27 11:42:51 (00000400): Attempting to load plugin /opt/share/mt-daapd/plugins/ssc-script.so
2007-09-27 11:42:51 (00000400): Loaded plugin /opt/share/mt-daapd/plugins/ssc-script.so (ssc-script/svn-1668)
2007-09-27 11:42:51 (00000400): New transcode codec list: ogg,flac,alac
2007-09-27 11:42:51 (00000400): Plugin loaded: ssc-script/svn-1668
2007-09-27 11:42:51 (00000400): Plugin loaded: daap/svn-1668
2007-09-27 11:42:51 (00000400): Plugin loaded: rsp/svn-1668
2007-09-27 11:42:51 (00000400): Starting rendezvous daemon
2007-09-27 11:42:51 (00000400): Starting signal handler
2007-09-27 11:42:51 (00000400): Pid: 499
2007-09-27 11:42:51 (00000400): Opening database
2007-09-27 11:42:51 (00000400): Executing: select value from config where term=’version’
2007-09-27 11:43:28 (00000400): Error: enum_begin failed (error 1): Misc SQL Error: database is locked
2007-09-27 11:43:28 (00000400): Can’t get db version. New database?
2007-09-27 11:43:28 (00000400): Results: 0
2007-09-27 11:43:28 (00000400): Initializing database
2007-09-27 11:43:28 (00000400): Execu2007-09-27 11:43:56 (00000400): R2007-09-27 11:43:59 (00000400): Executing: select value from config where term=’rescan’
2007-09-27 11:43:59 (00000400): Executing: vacuum
2007-09-27 11:45:05 (00000400): Rows: 0
2007-09-27 11:45:05 (00000400): Executing: create index idx_path on songs(path,idx)
2007-09-27 11:45:05 (00000400): Query: create index idx_path on songs(path,idx)
2007-09-27 11:45:05 (00000400): Error: index idx_path already exists
2007-09-27 11:45:05 (00000400): Executing: create index idx_songid on playlistitems(songid)
2007-09-27 11:45:05 (00000400): Query: create index idx_songid on playlistitems(songid)
2007-09-27 11:45:05 (00000400): Error: index idx_songid already exists
2007-09-27 11:45:05 (00000400): Executing: create index idx_playlistid on playlistitems(playlistid,songid)
2007-09-27 11:45:05 (00000400): Query: create index idx_playlistid on playlistitems(playlistid,songid)
2007-09-27 11:45:05 (00000400): Error: index idx_playlistid already exists
2007-09-27 11:45:05 (00000400): Executing: select count(*) FROM songs
2007-09-27 11:45:08 (00000400): Starting web server from /opt/share/mt-daapd/admin-root on port 3689
2007-09-27 11:45:08 (00000400): Listening on port 3689
2007-09-27 11:45:08 (00000400): Opening listen://3689
2007-09-27 11:45:08 (00000400): Checking handler for listen
2007-09-27 11:45:08 (00000400): opening 3689
2007-09-27 11:45:08 (00000400): Doing io_listen_open
2007-09-27 11:45:08 (00000400): Socket opened
2007-09-27 11:45:08 (00000400): Preparing to listen with 5 backlog on 3689
2007-09-27 11:45:08 (00000400): Starting server thread
2007-09-27 11:45:08 (00000400): Registering rendezvous names
2007-09-27 11:45:08 (00000400): Processing rendezvous message
2007-09-27 11:45:08 (00000400): Registering Mucke Spender._http._tcp (3689)
2007-09-27 11:45:08 (00000400): Registered service 0, name ‘Mucke Spender’, type ‘_http._tcp’, port 3689
2007-09-27 11:45:08 (00000400): Checking ssc-script/svn-1668
2007-09-27 11:45:08 (00000400): Checking daap/svn-1668
2007-09-27 11:45:08 (00000400): Registering _daap._tcp
2007-09-27 11:45:08 (00000400): Processing rendezvous message
2007-09-27 11:45:08 (00000400): Registering Mucke Spender._daap._tcp (3689)
2007-09-27 11:45:08 (00000400): Registered service 1, name ‘Mucke Spender’, type ‘_daap._tcp’, port 3689
2007-09-27 11:45:08 (00000400): Checking rsp/svn-1668
2007-09-27 11:45:08 (00000400): Registering _rsp._tcp
2007-09-27 11:45:08 (00000400): Processing rendezvous message
2007-09-27 11:45:08 (00000400): Registering Mucke Spender._rsp._tcp (3689)
2007-09-27 11:45:08 (00000400): Registered service 2, name ‘Mucke Spender’, type ‘_rsp._tcp’, port 3689
2007-09-27 11:45:08 (00000400): Executing: select count(*) FROM songs
2007-09-27 11:45:09 (00000400): Callback:
Mucke Spender_http_tcplocal Name Registered
2007-09-27 11:45:09 (00000400): Callback:
Mucke Spender_daap_tcplocal Name Registered
2007-09-27 11:45:09 (00000400): Callback:
Mucke Spender_rsp_tcplocal Name Registered
2007-09-27 11:45:09 (00000400): Serving 220 songs. Startup complete in 137 seconds

The second time it contained this:

2007-09-27 11:49:21 (00000400): Firefly Version svn-1668: Starting with debuglevel 9
2007-09-27 11:49:21 (00000400): Attempting to load plugin /opt/share/mt-daapd/plugins/rsp.so
2007-09-27 11:49:21 (00000400): Loaded plugin /opt/share/mt-daapd/plugins/rsp.so (rsp/svn-1668)
2007-09-27 11:49:21 (00000400): New transcode codec list:
2007-09-27 11:49:21 (00000400): Attempting to load plugin /opt/share/mt-daapd/plugins/out-daap.so
2007-09-27 11:49:21 (00000400): Loaded plugin /opt/share/mt-daapd/plugins/out-daap.so (daap/svn-1668)
2007-09-27 11:49:21 (00000400): New transcode codec list:
2007-09-27 11:49:21 (00000400): Attempting to load plugin /opt/share/mt-daapd/plugins/ssc-script.so
2007-09-27 11:49:21 (00000400): Loaded plugin /opt/share/mt-daapd/plugins/ssc-script.so (ssc-script/svn-1668)
2007-09-27 11:49:21 (00000400): New transcode codec list: ogg,flac,alac
2007-09-27 11:49:21 (00000400): Plugin loaded: ssc-script/svn-1668
2007-09-27 11:49:21 (00000400): Plugin loaded: daap/svn-1668
2007-09-27 11:49:21 (00000400): Plugin loaded: rsp/svn-1668
2007-09-27 11:49:21 (00000400): Starting rendezvous daemon
2007-09-27 11:49:21 (00000400): Starting signal handler
2007-09-27 11:49:21 (00000400): Pid: 499
2007-09-27 11:49:21 (00000400): Opening database
2007-09-27 11:49:21 (00000400): Executing: select value from config where term=’version’
2007-09-27 11:49:21 (00000400): Results: 0
2007-09-27 11:49:21 (00000400): Initializing database
2007-09-27 11:49:21 (00000400): Executing: select count(*) FROM songs
2007-09-27 11:49:23 (00000400): Executing: select value from config where term=’rescan’
2007-09-27 11:49:23 (00000400): Executing: vacuum
2007-09-27 11:50:33 (00000400): Rows: 0
2007-09-27 11:50:33 (00000400): Executing: create index idx_path on songs(path,idx)
2007-09-27 11:50:33 (00000400): Query: create index idx_path on songs(path,idx)
2007-09-27 11:50:33 (00000400): Error: index idx_path already exists
2007-09-27 11:50:33 (00000400): Executing: create index idx_songid on playlistitems(songid)
2007-09-27 11:50:33 (00000400): Query: create index idx_songid on playlistitems(songid)
2007-09-27 11:50:33 (00000400): Error: index idx_songid already exists
2007-09-27 11:50:33 (00000400): Executing: create index idx_playlistid on playlistitems(playlistid,songid)
2007-09-27 11:50:33 (00000400): Query: create index idx_playlistid on playlistitems(playlistid,songid)
2007-09-27 11:50:33 (00000400): Error: index idx_playlistid already exists
2007-09-27 11:50:33 (00000400): Executing: select count(*) FROM songs
2007-09-27 11:50:37 (00000400): Starting web server from /opt/share/mt-daapd/admin-root on port 3689
2007-09-27 11:50:37 (00000400): Listening on port 3689
2007-09-27 11:50:37 (00000400): Opening listen://3689
2007-09-27 11:50:37 (00000400): Checking handler for listen
2007-09-27 11:50:37 (00000400): opening 3689
2007-09-27 11:50:37 (00000400): Doing io_listen_open
2007-09-27 11:50:37 (00000400): Socket opened
2007-09-27 11:50:37 (00000400): Error binding socket
2007-09-27 11:50:37 (00000400): Listen port: socket/port in use
2007-09-27 112007-09-27 11:50:37 (00000400): Registering rendezvous names
2007-09-27 11:50:37 (00000400): Processing rendezvous message
2007-09-27 11:50:37 (00000400): Registering Mucke Spender._http._tcp (3689)
2007-09-27 11:50:37 (00000400): Registered service 0, name ‘Mucke Spender’, type ‘_http._tcp’, port 3689
2007-09-27 11:50:37 (00000400): Checking ssc-script/svn-1668
2007-09-27 11:50:37 (00000400): Checking daap/svn-1668
2007-09-27 11:50:37 (00000400): Registering _daap._tcp
2007-09-27 11:50:37 (00000400): Processing rendezvous message
2007-09-27 11:50:37 (00000400): Registering Mucke Spender._daap._tcp (3689)
2007-09-27 11:50:37 (00000400): Registered service 1, name ‘Mucke Spender’, type ‘_daap._tcp’, port 3689
2007-09-27 11:50:37 (00000400): Checking rsp/svn-1668
2007-09-27 11:50:37 (00000400): Registering _rsp._tcp
2007-09-27 11:50:37 (00000400): Processing rendezvous message
2007-09-27 11:50:37 (00000400): Registering Mucke Spender._rsp._tcp (3689)
2007-09-27 11:50:37 (00000400): Registered service 2, name ‘Mucke Spender’, type ‘_rsp._tcp’, port 3689
2007-09-27 11:50:37 (00000400): Executing: select count(*) FROM songs
2007-09-27 11:50:38 (00000400): Serving 220 songs. Startup complete in 77 seconds
2007-09-27 11:50:38 (00000400): Callback:
Mucke Spender_http_tcplocal Name Registered
2007-09-27 11:50:38 (00000400): Callback:
Mucke Spender_daap_tcplocal Name Registered
2007-09-27 11:50:38 (00000400): Callback:
Mucke Spender_rsp_tcplocal Name Registered

Thanks for your help!
Sven