You are here: Home » Topic » Server crashing on Terrastation Live

Server crashing on Terrastation Live

This topic contains 4 replies, has 2 voices, and was last updated by  mbaker 9 years, 11 months ago.

Viewing 5 posts - 1 through 5 (of 5 total)
  • Author
    Posts
  • #2109

    mbaker
    Participant

    Hiya. I’ve done a search around and haven’t found a solution to this problem so…

    I’ve been using Firefly for a couple of years on Windoze but just got a TSLive (Arm9) and figured it would be worth trying to get it going so I can permanently brick my old server. I used the guidance and downloads I found here (which were extremely helpful):
    http://buffalo.nas-central.org/index.php/Firefly_on_StockFirmware

    Managed to get pretty far:
    – downloaded and installed all the pieces (svn-1586)
    – tweaked the config
    – started firefly and indexed 15,000 songs in 15min (using only 10% of my TSLive CPU)

    But once the beast finished indexing it died:

    2008-01-06 17:49:57 (4001d4a0): Can't get db version. New database?
    2008-01-06 17:49:57 (4001d4a0): Initializing database
    2008-01-06 17:49:57 (4001d4a0): Error: enum_begin failed (error 1): ?
    2008-01-06 17:49:57 (4001d4a0): Error: enum_begin failed (error 1): ?
    2008-01-06 17:49:57 (4001d4a0): Full reload...
    2008-01-06 17:49:57 (4001d4a0): Starting web server from /usr/local/share/mt-daapd/admin-root on port 3689
    2008-01-06 17:49:57 (4001d4a0): Registering rendezvous names
    2008-01-06 17:49:57 (4001d4a0): Serving 0 songs. Startup complete in 1 seconds
    2008-01-06 17:49:57 (4001d4a0): Rescanning database
    2008-01-06 18:04:32 (4001d4a0): Starting playlist scan
    2008-01-06 18:05:58 (4001d4a0): Rendezvous socket closed (daap server crashed?) Aborting.
    2008-01-06 18:05:58: Aborting

    If I restart (using debug 9) I get the following pretty quickly:

    2008-01-06 18:51:27 (4001d4a0): Executing: select value from config where term='rescan'
    2008-01-06 18:51:27 (4001d4a0): Executing: vacuum
    2008-01-06 18:51:27 (4001d4a0): select(8, 0.099609)
    2008-01-06 18:51:27 (4001d4a0): select(8, 0.099609)
    2008-01-06 18:51:27 (4001d4a0): select(8, 1.899414)
    2008-01-06 18:51:29 (4001d4a0): select(8, 0.099609)
    2008-01-06 18:51:29 (4001d4a0): select(8, 0.099609)
    2008-01-06 18:51:29 (4001d4a0): select(8, 3.899414)
    2008-01-06 18:51:33 (4001d4a0): select(8, 0.100585)
    2008-01-06 18:51:33 (4001d4a0): select(8, 0.099609)
    2008-01-06 18:51:33 (4001d4a0): select(8, 5.000000)
    2008-01-06 18:51:38 (4001d4a0): select(8, 2.899414)
    2008-01-06 18:51:41 (4001d4a0): select(8, 0.080078)
    2008-01-06 18:51:41 (4001d4a0): select(8, 0.079101)
    2008-01-06 18:51:41 (4001d4a0): select(8, 5.000000)
    2008-01-06 18:51:46 (4001d4a0): select(8, 5.000000)
    2008-01-06 18:51:50 (4001d4a0): Query: vacuum
    2008-01-06 18:51:50 (4001d4a0): Error: disk I/O error
    2008-01-06 18:51:50: Aborting
    2008-01-06 18:51:50 (4001d4a0): Processing rendezvous message
    2008-01-06 18:51:50 (4001d4a0): Rendezvous socket closed (daap server crashed?) Aborting.
    2008-01-06 18:51:50: Aborting

    I found a reference to Query: vacuum in the forum and it recommended deleting songs.db and then rebuilding. I’ve tried that twice now but get the same result.

    I can connect directly to the DB using sqlite and it looks fine but is missing the playlists from my iTunes xml file (which it’s used successfully to build the file list).

    Any thoughts?

    M

    #15758

    rpedde
    Participant

    @mbaker wrote:


    2008-01-06 18:51:50 (4001d4a0): Query: vacuum
    2008-01-06 18:51:50 (4001d4a0): Error: disk I/O error

    That’s really what it is. It got a read or write error trying do something iwth the database.

    Is it possible the /tmp directory isn’t writable by the “runas” user? also, look for a .journal file in the same directory as the db file and delete both. You might also have better luck with sqlite3 versus sqlite2.

    These are the things that come to mind first. Also, make sure to do the initial index at -d9. It may (will?) take quite some time, but you’ll get a better idea of why it’s crashing int he first place.

    — Ron

    #15759

    mbaker
    Participant

    Thanks Ron.

    I’ve checked /tmp (which points to /mnt/ram, a small ram drive it seems) and it’s writable. We’re not trying to write anything large there, are we? It’s got a max size of 15M.

    I’ll try the from scratch -9 first before having a go at a new DB version.

    How goes that DB rebuild?

    M

    #15760

    mbaker
    Participant

    OK. Tried the rebuild with -9. Happily found that this didn’t slow down the build at all. Still managing about 1000 songs per minute.

    However, it didn’t reach the end of the scan, seemingly crashing due to one of the other processes. See below…

    M


    2008-01-12 09:02:09 (4001d4a0): Found music file: 06 Chainsaw.m4a
    2008-01-12 09:02:09 (4001d4a0): Codec type: mp4a
    2008-01-12 09:02:09 (41b77520): Thread 168: Read: Accept: text/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5
    2008-01-12 09:02:09 (41b77520): Thread 168: Adding header *Accept=text/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;
    q=0.5*
    2008-01-12 09:02:09 (41b77520): Added *Accept=text/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5*
    2008-01-12 09:02:09 (41b77520): Thread 168: Read: Accept-Language: en-us,en;q=0.5
    2008-01-12 09:02:09 (41b77520): Thread 168: Adding header *Accept-Language=en-us,en;q=0.5*
    2008-01-12 09:02:09 (41b77520): Added *Accept-Language=en-us,en;q=0.5*
    2008-01-12 09:02:09 (41b77520): Thread 168: Read: Accept-Encoding: gzip,deflate
    2008-01-12 09:02:09 (41b77520): Thread 168: Adding header *Accept-Encoding=gzip,deflate*
    2008-01-12 09:02:09 (41b77520): Added *Accept-Encoding=gzip,deflate*
    2008-01-12 09:02:09 (41b77520): Thread 168: Read: Accept-Charset: ISO-8859-1,utf
    -8;q=0.7,*;q=0.7
    2008-01-12 09:02:09 (41b77520): Thread 168: Adding header *Accept-Charset=ISO-88
    59-1,utf-8;q=0.7,*;q=0.7*
    2008-01-12 09:02:09 (41b77520): Added *Accept-Charset=ISO-8859-1,utf-8;q=0.7,*;q
    =0.7*
    2008-01-12 09:02:09 (41b77520): Thread 168: Read: Keep-Alive: 300
    2008-01-12 09:02:09 (41b77520): Thread 168: Adding header *Keep-Alive=300*
    2008-01-12 09:02:09 (41b77520): Added *Keep-Alive=300*
    2008-01-12 09:02:09 (41b77520): Thread 168: Read: Connection: keep-alive
    2008-01-12 09:02:09 (41b77520): Thread 168: Adding header *Connection=keep-alive
    *
    2008-01-12 09:02:09 (41b77520): Added *Connection=keep-alive*
    2008-01-12 09:02:09 (41b77520): Thread 168: Read: X-Requested-With: XMLHttpReque
    st
    2008-01-12 09:02:09 (41b77520): Thread 168: Adding header *X-Requested-With=XMLH
    ttpRequest*
    2008-01-12 09:02:09 (41b77520): Added *X-Requested-With=XMLHttpRequest*
    2008-01-12 09:02:09 (41b77520): Thread 168: Read: X-Prototype-Version: 1.4.0
    2008-01-12 09:02:09 (41b77520): Thread 168: Adding header *X-Prototype-Version=1
    .4.0*
    2008-01-12 09:02:09 (41b77520): Added *X-Prototype-Version=1.4.0*
    2008-01-12 09:02:09 (41b77520): Thread 168: Read: Referer: http://gaia:3689/inde
    x.html
    2008-01-12 09:02:09 (41b77520): Thread 168: Adding header *Referer=http://gaia:3
    689/index.html*
    2008-01-12 09:02:09 (41b77520): Added *Referer=http://gaia:3689/index.html*
    2008-01-12 09:02:09 (41b77520): Thread 168: Read: Authorization: Basic OmZpcmVmb
    Hk=
    2008-01-12 09:02:09 (41b77520): Thread 168: Adding header *Authorization=Basic O
    mZpcmVmbHk=*
    2008-01-12 09:02:09 (41b77520): Added *Authorization=Basic OmZpcmVmbHk=*
    2008-01-12 09:02:09 (41b77520): Thread 168: Read:
    2008-01-12 09:02:09 (41b77520): Thread 168: Headers parsed!
    2008-01-12 09:02:09 (41b77520): Checking to see if connection matches close
    2008-01-12 09:02:09 (41b77520): And it does NOT
    2008-01-12 09:02:09 (41b77520): Thread 168: Connection type HTTP/1.1
    : Connection: persist
    2008-01-12 09:02:09 (41b77520): Thread 168: parsing GET args
    2008-01-12 09:02:09 (41b77520): Thread 168: Entering ws_getgetvars (method=stats
    )
    2008-01-12 09:02:09 (41b77520): Thread 168: Adding arg method = stats
    2008-01-12 09:02:09 (41b77520): Added *method=stats*
    2008-01-12 09:02:09 (41b77520): Thread 168: Done parsing GET/POST args!
    2008-01-12 09:02:09 (41b77520): Thread 168: Original URI: /xml-rpc
    2008-01-12 09:02:09 (41b77520): Thread 168: Translated URI: /xml-rpc
    2008-01-12 09:02:09 (41b77520): Thread 168: Preparing to find handler
    2008-01-12 09:02:09 (41b77520): Checking /xml-rpc against handler for /
    2008-01-12 09:02:09 (41b77520): Thread 168: URI Match!
    2008-01-12 09:02:09 (41b77520): Thread 168: Time is 1200128529 seconds after epo
    ch
    2008-01-12 09:02:09 (41b77520): Thread 168: Setting time header
    2008-01-12 09:02:09 (41b77520): Added *Date=Sat, 12 Jan 2008 09:02:09 GMT*
    2008-01-12 09:02:09 (41b77520): Added *Connection=keep-alive*
    2008-01-12 09:02:09 (41b77520): Added *Server=mt-daapd/svn-1586*
    2008-01-12 09:02:09 (41b77520): Added *Content-Type=text/html*
    2008-01-12 09:02:09 (41b77520): Added *Content-Language=en_us*
    2008-01-12 09:02:09 (41b77520): Thread 168: Using non-default handler
    2008-01-12 09:02:09 (41b77520): in main_auth
    2008-01-12 09:02:09 (41b77520): Checking url /xml-rpc
    2008-01-12 09:02:09 (41b77520): Checking url /xml-rpc
    2008-01-12 09:02:09 (41b77520): Dispatching auth for /xml-rpc to config auth
    2008-01-12 09:02:09 (41b77520): Checking if pw required for /xml-rpc as admin
    2008-01-12 09:02:09 (41b77520): Yep
    2008-01-12 09:02:09 (41b77520): Preparing to decode OmZpcmVmbHk=
    2008-01-12 09:02:09 (41b77520): Decoded :firefly
    2008-01-12 09:02:09 (41b77520): Decoded user=, pw=firefly
    2008-01-12 09:02:09 (41b77520): in main_auth
    2008-01-12 09:02:09 (41b77520): Checking url /xml-rpc
    2008-01-12 09:02:09 (41b77520): Checking url /xml-rpc
    2008-01-12 09:02:09 (41b77520): Dispatching auth for /xml-rpc to config auth
    2008-01-12 09:02:09 (41b77520): Added *HTTP_USER=*
    2008-01-12 09:02:09 (41b77520): Added *HTTP_PASSWD=firefly*
    2008-01-12 09:02:09 (41b77520): in main_handler
    2008-01-12 09:02:09 (41b77520): Checking url /xml-rpc
    2008-01-12 09:02:09 (41b77520): Checking url /xml-rpc
    2008-01-12 09:02:09 (41b77520): Dispatching /xml-rpc to config handler
    2008-01-12 09:02:09 (41b77520): Entering config_handler
    2008-01-12 09:02:09 (41b77520): Entering config_set_status
    2008-01-12 09:02:09 (41b77520): Exiting config_set_status
    2008-01-12 09:02:09 (41b77520): Updating Connection from keep-alive to close
    2008-01-12 09:02:09 (41b77520): Entering config_set_status
    2008-01-12 09:02:09 (41b77520): Exiting config_set_status
    2008-01-12 09:02:09 (41b77520): Added *Cache-Control=no-cache*
    2008-01-12 09:02:09 (41b77520): Added *Expires=-1*
    2008-01-12 09:02:09 (41b77520): Updating Content-Type from text/html to text/xml
    ; charset=utf-8
    2008-01-12 09:02:09 (41b77520): Emitting reponse header Expires: -1
    2008-01-12 09:02:09 (41b77520): Emitting reponse header Cache-Control: no-cache
    2008-01-12 09:02:09 (41b77520): Emitting reponse header Content-Language: en_us
    2008-01-12 09:02:09 (41b77520): Emitting reponse header Content-Type: text/xml;
    charset=utf-8
    2008-01-12 09:02:09 (41b77520): Emitting reponse header Server: mt-daapd/svn-158
    6
    2008-01-12 09:02:09 (41b77520): Emitting reponse header Connection: close
    2008-01-12 09:02:09 (41b77520): Emitting reponse header Date: Sat, 12 Jan 2008 0
    9:02:09 GMT
    2008-01-12 09:02:09 (41b77520): Status inquiry
    2008-01-12 09:02:09 (4001d4a0): Processing rendezvous message
    2008-01-12 09:02:09 (4001d4a0): select(8, 5.000000)
    2008-01-12 09:02:09 (41b77520): Returning status 0
    2008-01-12 09:02:09 (41b77520): Executing: select count(*) FROM songs
    2008-01-12 09:02:09 (4001d4a0): Song length: 355 seconds
    2008-01-12 09:02:09 (4001d4a0): esds bitrate: 128
    2008-01-12 09:02:09 (4001d4a0): Date Added: 1155231063
    2008-01-12 09:02:09 (4001d4a0): Codec: mp4a
    2008-01-12 09:02:13 (4001d4a0): Processing rendezvous message
    2008-01-12 09:02:13 (4001d4a0): Rendezvous socket closed (daap server crashed?)
    Aborting.
    2008-01-12 09:02:13: Aborting
    #15761

    mbaker
    Participant

    Me again. Continued testing and think I found a more useful error message that helped me to solve the problem.


    2008-01-13 08:27:32 (4001d4a0): Found /mnt/array1/Music/Album Artwork/Download/8DC1DD60EC7C97F3/09/00/10
    2008-01-13 08:27:32 (4001d4a0): Found 10.. recursing
    2008-01-13 08:27:32 (4001d4a0): Found /mnt/array1/Music/Album Artwork/Download/8DC1DD60EC7C97F3/09/00/10/8DC1DD60EC7C97F3-2F960DF25E02008-01-13 08:59:07 (4001d4a0): select(8, 5.000000)
    2008-01-13 08:59:08 (4001d4a0): Query: commit transaction
    2008-01-13 08:59:08 (4001d4a0): Error: database is full
    2008-01-13 08:59:08: Aborting
    2008-01-13 08:59:08 (4001d4a0): Processing rendezvous message
    2008-01-13 08:59:08 (4001d4a0): Rendezvous socket closed (daap server crashed?) Aborting.
    2008-01-13 08:59:08: Aborting

    The database is full message made me do a quick df. It turns out that both the cache and log folders are on the TSL’s small / partition. With a large database like mine (plus running at debug 9) I was maxing out the partition, causing the write error and the crash.

    The TSL comes with a nasty mt-daapd pre-installed and it keeps its files in a pre-created directory on the main disk array. I’ve changed the conf to put the log and db there and now it’s running perfectly.

    I’ll go back to the original instruction writers and provide them with the update.

    Cheers and good luck with the db rebuild!

    M

Viewing 5 posts - 1 through 5 (of 5 total)

You must be logged in to reply to this topic.