Firefly keeps crashing on startup

Viewing 7 posts - 1 through 7 (of 7 total)
  • Author
    Posts
  • #1764
    Metzeler
    Participant

    Hi,

    I´m using firefly svn-1668 on a NSLU2 in combination with the roku soundbrigde. The server is startet automatically on NSLU startup via the rc.local file.

    Nearly everytime (sometimes it works) I start the NSLU, the firefly server is starting and shutting down on startup. The logfile looks like the following:

    2007-09-26 11:25:59 (00000400): Firefly Version svn-1668: Starting with debuglevel 6
    2007-09-26 11:25:59 (00000400): Loaded plugin /opt/share/mt-daapd/plugins/rsp.so (rsp/svn-1668)
    2007-09-26 11:25:59 (00000400): Loaded plugin /opt/share/mt-daapd/plugins/out-daap.so (daap/svn-1668)
    2007-09-26 11:25:59 (00000400): Loaded plugin /opt/share/mt-daapd/plugins/ssc-script.so (ssc-script/svn-1668)
    2007-09-26 11:25:59 (00000400): Plugin loaded: ssc-script/svn-1668
    2007-09-26 11:25:59 (00000400): Plugin loaded: daap/svn-1668
    2007-09-26 11:25:59 (00000400): Plugin loaded: rsp/svn-1668
    2007-09-26 11:25:59 (00000400): Starting rendezvous daemon
    2007-09-26 11:25:59 (00000400): Starting signal handler
    2007-09-26 11:26:00 (00000400): Initializing database
    2007-09-26 11:27:13 (00000400): Starting web server from /opt/share/mt-daapd/admin-root on port 3689
    2007-09-26 11:27:13 (00000400): Listening on port 3689
    2007-09-26 11:27:13 (00000400): Listen port: socket/por2007-09-26 11:27:13 (00000400): Registering rendezvous names
    2007-09-26 11:27:14 (00000400): Serving 220 songs. Startup complete in 78 seconds
    2007-09-26 11:27:16 (00000400): Got shutdown signal.
    2007-09-26 11:27:16 (00000400): Stopping gracefully
    2007-09-26 11:27:16 (00000400): Stopping rendezvous daemon
    2007-09-26 11:27:16 (00000400): Closing database
    2007-09-26 11:27:16 (00000400): Done!

    Where does this “got shutdown signal” come from?

    Can you please give me a hint to get it working.

    Thanks!

    #12713
    fizze
    Participant

    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?

    #12714
    Metzeler
    Participant

    @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.

    #12715
    rpedde
    Participant

    @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

    #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

    #12717
    fizze
    Participant

    @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.

    Yes it is being executed at startup. They all are.
    That also goes well with your mixed experiences.

    The socket is locked by another instance of mt-daapd, and so is the database. Go figure. 🙂

    ps aux|grep daapd

    is your friend.

    You normally get 4 Threads of mt-daapd for each instance.
    Depending on you using busybox or the real procps-ps, your mileage may vary.

    #12718
    Metzeler
    Participant

    Oh, thanks for this information. I´ve read in another forum that is has to be included in the rc.local otherwise the server must be started manually.

    Anyways, I´ve changed the rc.local and deleted the entry for the S60mt-daapd script and…

    IT WORKS! 😉

    Thanks a lot! 😀

Viewing 7 posts - 1 through 7 (of 7 total)
  • The forum ‘Setup Issues’ is closed to new topics and replies.