Problem with large size .flac-files

[uncleremus]

Hello,

I have noticed a problem recently when streaming larger files from firefly. I have tested with a Roku Soundbridge and iTunes and the problem is on both. In this scenario, at 07:56:20, I choose to play a song called “Billy The Mountain” and at 07:56:24, the Roku starts the next song on the album called “Call Any Vegetable”. The file “Billy The Mountain” is listed as

ll /mnt/disk1/music/01 Billy The Mountain.flac

149M -rw-r--r-- 1 user1 users 149M 17 dec 17.08 /mnt/disk1/music/01 Billy The Mountain.flac

and will not play. The other file is listed as

ll /mnt/disk1/music/frank_zappa/just_another_band_from_la/call_any_vegetable.flac

48M -rwxrwxrwx 1 user1 root 48M 10 aug 18.06 /mnt/disk1/music/frank_zappa/just_another_band_from_la/call_any_vegetable.flac

and will play. Here’s the debug output:

2007-12-18 07:51:07 (b78af6c0): Firefly Version svn-1586: Starting with debuglevel 9

2007-12-18 07:51:07 (b78af6c0): Attempting to load plugin /usr/share/mt-daapd/plugins/rsp.so

2007-12-18 07:51:07 (b78af6c0): Loaded plugin /usr/share/mt-daapd/plugins/rsp.so (rsp/svn-1586)

2007-12-18 07:51:07 (b78af6c0): New transcode codec list:

2007-12-18 07:51:07 (b78af6c0): Attempting to load plugin /usr/share/mt-daapd/plugins/ssc-script.so

2007-12-18 07:51:07 (b78af6c0): Loaded plugin /usr/share/mt-daapd/plugins/ssc-script.so (ssc-script/svn-1586)

2007-12-18 07:51:07 (b78af6c0): New transcode codec list: ogg,flac,alac

2007-12-18 07:51:07 (b78af6c0): Attempting to load plugin /usr/share/mt-daapd/plugins/out-daap.so

2007-12-18 07:51:07 (b78af6c0): Loaded plugin /usr/share/mt-daapd/plugins/out-daap.so (daap/svn-1586)

2007-12-18 07:51:07 (b78af6c0): New transcode codec list: ogg,flac,alac

2007-12-18 07:51:07 (b78af6c0): Attempting to load plugin /usr/share/mt-daapd/plugins/ssc-ffmpeg.so

2007-12-18 07:51:07 (b78af6c0): Loaded plugin /usr/share/mt-daapd/plugins/ssc-ffmpeg.so (ssc-ffmpeg/svn-1586)

2007-12-18 07:51:07 (b78af6c0): New transcode codec list: flac,alac,ogg,wma,ogg,flac,alac

2007-12-18 07:51:07 (b78af6c0): Plugin loaded: ssc-ffmpeg/svn-1586

2007-12-18 07:51:07 (b78af6c0): Plugin loaded: daap/svn-1586

2007-12-18 07:51:07 (b78af6c0): Plugin loaded: ssc-script/svn-1586

2007-12-18 07:51:07 (b78af6c0): Plugin loaded: rsp/svn-1586

2007-12-18 07:51:07 (b78af6c0): Starting rendezvous daemon

2007-12-18 07:51:07 (b78af6c0): Starting signal handler

2007-12-18 07:51:07 (b78af6c0): Pid: 9156

2007-12-18 07:51:07 (b78af6c0): Opening database

2007-12-18 07:51:07 (b78af6c0): Executing: select value from config where term='version'

2007-12-18 07:51:07 (b78af6c0): select(8, 0.000976)

2007-12-18 07:51:07 (b78af6c0): select(8, 0.245117)

2007-12-18 07:51:07 (b78af6c0): Results: 0

2007-12-18 07:51:07 (b78af6c0): Initializing database

2007-12-18 07:51:07 (b78af6c0): Executing: select count(*) FROM songs

2007-12-18 07:51:07 (b78af6c0): Executing: select value from config where term='rescan'

2007-12-18 07:51:07 (b78af6c0): Executing: vacuum



....



2007-12-18 07:56:20 (b680cb90): Thread 15: Entering ws_dispatcher (Connection from 192.168.0.104)

2007-12-18 07:56:20 (b680cb90): Thread 15: got request

2007-12-18 07:56:20 (b680cb90): Request: GET /rsp/db/0?query=id%3D17632&type=full HTTP/1.0^M

2007-12-18 07:56:20 (b680cb90): Thread 15: Read: User-Agent: Roku SoundBridge/3.0^M

2007-12-18 07:56:20 (b680cb90): Thread 15: Adding header *User-Agent=Roku SoundBridge/3.0*

2007-12-18 07:56:20 (b680cb90): Added *User-Agent=Roku SoundBridge/3.0*

2007-12-18 07:56:20 (b680cb90): Thread 15: Read: Host: 192.168.0.106:3689^M

2007-12-18 07:56:20 (b680cb90): Thread 15: Adding header *Host=192.168.0.106:3689*

2007-12-18 07:56:20 (b680cb90): Added *Host=192.168.0.106:3689*

2007-12-18 07:56:20 (b680cb90): Thread 15: Read: Accept: */*^M

2007-12-18 07:56:20 (b680cb90): Thread 15: Adding header *Accept=*/**

2007-12-18 07:56:20 (b680cb90): Added *Accept=*/**

2007-12-18 07:56:20 (b680cb90): Thread 15: Read: Pragma: no-cache^M

2007-12-18 07:56:20 (b680cb90): Thread 15: Adding header *Pragma=no-cache*

2007-12-18 07:56:20 (b680cb90): Added *Pragma=no-cache*

2007-12-18 07:56:20 (b680cb90): Thread 15: Read: accept-encoding: gzip^M

2007-12-18 07:56:20 (b680cb90): Thread 15: Adding header *accept-encoding=gzip*

2007-12-18 07:56:20 (b680cb90): Added *accept-encoding=gzip*

2007-12-18 07:56:20 (b680cb90): Thread 15: Read: accept-codecs: wma,mpeg,wav,mp4a,alac^M

2007-12-18 07:56:20 (b680cb90): Thread 15: Adding header *accept-codecs=wma,mpeg,wav,mp4a,alac*

2007-12-18 07:56:20 (b680cb90): Added *accept-codecs=wma,mpeg,wav,mp4a,alac*

2007-12-18 07:56:20 (b680cb90): Thread 15: Read: rsp-version: 0.1^M

2007-12-18 07:56:20 (b680cb90): Thread 15: Adding header *rsp-version=0.1*

2007-12-18 07:56:20 (b680cb90): Added *rsp-version=0.1*

2007-12-18 07:56:20 (b680cb90): Thread 15: Read: transcode-codecs: wav,mp3^M

2007-12-18 07:56:20 (b680cb90): Thread 15: Adding header *transcode-codecs=wav,mp3*

2007-12-18 07:56:20 (b680cb90): Added *transcode-codecs=wav,mp3*

2007-12-18 07:56:20 (b680cb90): Thread 15: Read: ^M

2007-12-18 07:56:20 (b680cb90): Thread 15: Headers parsed!

2007-12-18 07:56:20 (b680cb90): Checking to see if connection matches keep-alive

2007-12-18 07:56:20 (b680cb90): Nope!

2007-12-18 07:56:20 (b680cb90): Thread 15: Connection type HTTP/1.0^M

: Connection: non-persist

2007-12-18 07:56:20 (b680cb90): Thread 15: parsing GET args

2007-12-18 07:56:20 (b680cb90): Thread 15: Entering ws_getgetvars (query=id%3D17632&type=full)

2007-12-18 07:56:20 (b680cb90): Thread 15: Adding arg query = id=17632

2007-12-18 07:56:20 (b680cb90): Added *query=id=17632*

2007-12-18 07:56:20 (b680cb90): Thread 15: Adding arg type = full

2007-12-18 07:56:20 (b680cb90): Added *type=full*

2007-12-18 07:56:20 (b680cb90): Thread 15: Done parsing GET/POST args!

2007-12-18 07:56:20 (b680cb90): Thread 15: Original URI: /rsp/db/0

2007-12-18 07:56:20 (b680cb90): Thread 15: Translated URI: /rsp/db/0

2007-12-18 07:56:20 (b680cb90): Thread 15: Preparing to find handler

2007-12-18 07:56:20 (b680cb90): Checking /rsp/db/0 against handler for /

2007-12-18 07:56:20 (b680cb90): Thread 15: URI Match!

2007-12-18 07:56:20 (b680cb90): Thread 15: Time is 1197960980 seconds after epoch

2007-12-18 07:56:20 (b680cb90): Thread 15: Setting time header

2007-12-18 07:56:20 (b680cb90): Added *Date=Tue, 18 Dec 2007 06:56:20 GMT*

2007-12-18 07:56:20 (b680cb90): Added *Connection=close*

2007-12-18 07:56:20 (b680cb90): Added *Server=mt-daapd/svn-1586*

2007-12-18 07:56:20 (b680cb90): Added *Content-Type=text/html*

2007-12-18 07:56:20 (b680cb90): Added *Content-Language=en_us*

2007-12-18 07:56:20 (b680cb90): Thread 15: Using non-default handler

2007-12-18 07:56:20 (b680cb90): in main_auth

2007-12-18 07:56:20 (b680cb90): Checking url /rsp/db/0

2007-12-18 07:56:20 (b680cb90): Checking url /rsp/db/0

2007-12-18 07:56:20 (b680cb90): Dispatching auth for /rsp/db/0 to plugin

2007-12-18 07:56:20 (b680cb90): Checking url /rsp/db/0

2007-12-18 07:56:20 (b680cb90): Checking url /rsp/db/0

2007-12-18 07:56:20 (b680cb90): Dispatching /rsp/db/0 to rsp/svn-1586

2007-12-18 07:56:20 (b680cb90): Checking if pw required for /rsp/db/0 as user

2007-12-18 07:56:20 (b680cb90): Nope

2007-12-18 07:56:20 (b680cb90): in main_handler

2007-12-18 07:56:20 (b680cb90): Checking url /rsp/db/0

2007-12-18 07:56:20 (b680cb90): Checking url /rsp/db/0

2007-12-18 07:56:20 (b680cb90): Dispatching /rsp/db/0 to plugin

2007-12-18 07:56:20 (b680cb90): Checking url /rsp/db/0

2007-12-18 07:56:20 (b680cb90): Checking url /rsp/db/0

2007-12-18 07:56:20 (b680cb90): Dispatching /rsp/db/0 to rsp/svn-1586

2007-12-18 07:56:20 (b680cb90): Getting uri...

2007-12-18 07:56:20 (b680cb90): Mallocing privinfo...

2007-12-18 07:56:20 (b680cb90): Tokenizing url

2007-12-18 07:56:20 (b680cb90): Found 5 elements

2007-12-18 07:56:20 (b680cb90): Checking reponse 0

2007-12-18 07:56:20 (b680cb90): Checking reponse 1

2007-12-18 07:56:20 (b680cb90): Checking reponse 2

2007-12-18 07:56:20 (b680cb90): Found it! Index: 2

2007-12-18 07:56:20 (b680cb90):   Returning token 2002

2007-12-18 07:56:20 (b680cb90):   Entering sp_parse_phrase

2007-12-18 07:56:20 (b680cb90):     Entering sp_parse_oexpr

2007-12-18 07:56:20 (b680cb90):      Entering sp_parse_aexpr

2007-12-18 07:56:20 (b680cb90):       Entering sp_parse_expr

2007-12-18 07:56:20 (b680cb90):        Entering sp_parse_criterion

2007-12-18 07:56:20 (b680cb90):         Entering sp_parse_int_criterion

2007-12-18 07:56:20 (b680cb90):         Returning token 000f

2007-12-18 07:56:20 (b680cb90):         Returning token 00fd

2007-12-18 07:56:20 (b680cb90):         Exiting sp_parse_int_criterion (success)

2007-12-18 07:56:20 (b680cb90):        Exiting sp_parse_criterion (success)

2007-12-18 07:56:20 (b680cb90):       Exiting sp_parse_expr (success)

2007-12-18 07:56:20 (b680cb90):      Exiting sp_parse_aexpr (success)

2007-12-18 07:56:20 (b680cb90):     Exiting sp_parse_oexpr (success)

2007-12-18 07:56:20 (b680cb90):    Exiting sp_parse_phrase (success)

2007-12-18 07:56:20 (b680cb90): Got query/filter

2007-12-18 07:56:20 (b680cb90): Fetching sql statement size

2007-12-18 07:56:20 (b680cb90): Size: 47

2007-12-18 07:56:20 (b680cb90): Serialized to : (id = 17632)

2007-12-18 07:56:20 (b680cb90): Executing: select count(songs.id) from songs  where ((id = 17632))

2007-12-18 07:56:20 (b680cb90): Number of results: 1

2007-12-18 07:56:20 (b680cb90): Executing: select * from songs  where ((id = 17632))

2007-12-18 07:56:20 (b680cb90): Gzipping output

2007-12-18 07:56:20 (b680cb90): Added *Content-Encoding=gzip*

2007-12-18 07:56:20 (b680cb90): Added *Vary=Accept-Encoding*

2007-12-18 07:56:20 (b680cb90): Updating Connection from close to Close

2007-12-18 07:56:20 (b680cb90): Added *Cache-Control=no-cache*

2007-12-18 07:56:20 (b680cb90): Added *Expires=-1*

2007-12-18 07:56:20 (b680cb90): Updating Content-Type from text/html to text/xml; charset=utf-8

2007-12-18 07:56:20 (b680cb90): Emitting reponse header Expires: -1

2007-12-18 07:56:20 (b680cb90): Emitting reponse header Cache-Control: no-cache

2007-12-18 07:56:20 (b680cb90): Emitting reponse header Vary: Accept-Encoding

2007-12-18 07:56:20 (b680cb90): Emitting reponse header Content-Encoding: gzip

2007-12-18 07:56:20 (b680cb90): Emitting reponse header Content-Language: en_us

2007-12-18 07:56:20 (b680cb90): Emitting reponse header Content-Type: text/xml; charset=utf-8

2007-12-18 07:56:20 (b680cb90): Emitting reponse header Server: mt-daapd/svn-1586

2007-12-18 07:56:20 (b680cb90): Emitting reponse header Connection: Close

2007-12-18 07:56:20 (b680cb90): Emitting reponse header Date: Tue, 18 Dec 2007 06:56:20 GMT

2007-12-18 07:56:20 (b680cb90): Transcode: 1, flac: 01 Billy The Mountain.flac

2007-12-18 07:56:20 (b680cb90): Done sending xml stream

2007-12-18 07:56:20 (b680cb90): Thread 15: Terminating

2007-12-18 07:56:20 (b680cb90): Thread 15: Freeing request headers

2007-12-18 07:56:20 (b680cb90): Thread 15: Freeing response headers

2007-12-18 07:56:20 (b680cb90): Thread 15: Freeing request vars

2007-12-18 07:56:20 (b680cb90): Thread 15: Closing fd

2007-12-18 07:56:20 (b680cb90): With thread 15 exiting, 0 are still running

2007-12-18 07:56:20 (b680cb90): Thread 16: Entering ws_dispatcher (Connection from 192.168.0.104)

2007-12-18 07:56:20 (b680cb90): Thread 16: got request

2007-12-18 07:56:20 (b680cb90): Request: GET /rsp/stream/17632 HTTP/1.0^M

2007-12-18 07:56:20 (b680cb90): Thread 16: Read: User-Agent: Roku SoundBridge/3.0^M

2007-12-18 07:56:20 (b680cb90): Thread 16: Adding header *User-Agent=Roku SoundBridge/3.0*

2007-12-18 07:56:20 (b680cb90): Added *User-Agent=Roku SoundBridge/3.0*

2007-12-18 07:56:20 (b680cb90): Thread 16: Read: Host: 192.168.0.106:3689^M

2007-12-18 07:56:20 (b680cb90): Thread 16: Adding header *Host=192.168.0.106:3689*

2007-12-18 07:56:20 (b680cb90): Added *Host=192.168.0.106:3689*

2007-12-18 07:56:20 (b680cb90): Thread 16: Read: Accept: */*^M

2007-12-18 07:56:20 (b680cb90): Thread 16: Adding header *Accept=*/**

2007-12-18 07:56:20 (b680cb90): Added *Accept=*/**

2007-12-18 07:56:20 (b680cb90): Thread 16: Read: Pragma: no-cache^M

2007-12-18 07:56:20 (b680cb90): Thread 16: Adding header *Pragma=no-cache*

2007-12-18 07:56:20 (b680cb90): Added *Pragma=no-cache*

2007-12-18 07:56:20 (b680cb90): Thread 16: Read: accept-codecs: wma,mpeg,wav,mp4a,alac^M

2007-12-18 07:56:20 (b680cb90): Thread 16: Adding header *accept-codecs=wma,mpeg,wav,mp4a,alac*

2007-12-18 07:56:20 (b680cb90): Added *accept-codecs=wma,mpeg,wav,mp4a,alac*

2007-12-18 07:56:20 (b680cb90): Thread 16: Read: rsp-version: 0.1^M

2007-12-18 07:56:20 (b680cb90): Thread 16: Adding header *rsp-version=0.1*

2007-12-18 07:56:20 (b680cb90): Added *rsp-version=0.1*

2007-12-18 07:56:20 (b680cb90): Thread 16: Read: transcode-codecs: wav,mp3^M

2007-12-18 07:56:20 (b680cb90): Thread 16: Adding header *transcode-codecs=wav,mp3*

2007-12-18 07:56:20 (b680cb90): Added *transcode-codecs=wav,mp3*

2007-12-18 07:56:20 (b680cb90): Thread 16: Read: ^M

2007-12-18 07:56:20 (b680cb90): Thread 16: Headers parsed!

2007-12-18 07:56:20 (b680cb90): Checking to see if connection matches keep-alive

2007-12-18 07:56:20 (b680cb90): Nope!

2007-12-18 07:56:20 (b680cb90): Thread 16: Connection type HTTP/1.0^M

: Connection: non-persist

2007-12-18 07:56:20 (b680cb90): Thread 16: Original URI: /rsp/stream/17632

2007-12-18 07:56:20 (b680cb90): Thread 16: Translated URI: /rsp/stream/17632

2007-12-18 07:56:20 (b680cb90): Thread 16: Preparing to find handler

2007-12-18 07:56:20 (b680cb90): Checking /rsp/stream/17632 against handler for /

2007-12-18 07:56:20 (b680cb90): Thread 16: URI Match!

2007-12-18 07:56:20 (b680cb90): Thread 16: Time is 1197960980 seconds after epoch

2007-12-18 07:56:20 (b680cb90): Thread 16: Setting time header

2007-12-18 07:56:20 (b680cb90): Added *Date=Tue, 18 Dec 2007 06:56:20 GMT*

2007-12-18 07:56:20 (b680cb90): Added *Connection=close*

2007-12-18 07:56:20 (b680cb90): Added *Server=mt-daapd/svn-1586*

2007-12-18 07:56:20 (b680cb90): Added *Content-Type=text/html*

2007-12-18 07:56:20 (b680cb90): Added *Content-Language=en_us*

2007-12-18 07:56:20 (b680cb90): Thread 16: Using non-default handler

2007-12-18 07:56:20 (b680cb90): in main_auth

2007-12-18 07:56:20 (b680cb90): Checking url /rsp/stream/17632

2007-12-18 07:56:20 (b680cb90): Checking url /rsp/stream/17632

2007-12-18 07:56:20 (b680cb90): Dispatching auth for /rsp/stream/17632 to plugin

2007-12-18 07:56:20 (b680cb90): Checking url /rsp/stream/17632

2007-12-18 07:56:20 (b680cb90): Checking url /rsp/stream/17632

2007-12-18 07:56:20 (b680cb90): Dispatching /rsp/stream/17632 to rsp/svn-1586

2007-12-18 07:56:20 (b680cb90): Checking if pw required for /rsp/stream/17632 as user

2007-12-18 07:56:20 (b680cb90): Nope

2007-12-18 07:56:20 (b680cb90): in main_handler

2007-12-18 07:56:20 (b680cb90): Checking url /rsp/stream/17632

2007-12-18 07:56:20 (b680cb90): Checking url /rsp/stream/17632

2007-12-18 07:56:20 (b680cb90): Dispatching /rsp/stream/17632 to plugin

2007-12-18 07:56:20 (b680cb90): Checking url /rsp/stream/17632

2007-12-18 07:56:20 (b680cb90): Checking url /rsp/stream/17632

2007-12-18 07:56:20 (b680cb90): Dispatching /rsp/stream/17632 to rsp/svn-1586

2007-12-18 07:56:20 (b680cb90): Getting uri...

2007-12-18 07:56:20 (b680cb90): Mallocing privinfo...

2007-12-18 07:56:20 (b680cb90): Tokenizing url

2007-12-18 07:56:20 (b680cb90): Found 5 elements

2007-12-18 07:56:20 (b680cb90): Checking reponse 0

2007-12-18 07:56:20 (b680cb90): Checking reponse 1

2007-12-18 07:56:20 (b680cb90): Checking reponse 2

2007-12-18 07:56:20 (b680cb90): Checking reponse 3

2007-12-18 07:56:20 (b680cb90): Checking reponse 4

2007-12-18 07:56:20 (b680cb90): Found it! Index: 4

2007-12-18 07:56:20 (b680cb90): Executing: select * from songs where id=17632

2007-12-18 07:56:20 (b680cb90): Entering config_set_status

2007-12-18 07:56:20 (b680cb90): Exiting config_set_status

2007-12-18 07:56:20 (b680cb90): Session 0: Streaming file '01 Billy The Mountain.flac' to 192.168.0.104 (offset 0)

2007-12-18 07:56:20 (b680cb90): Transcoding /mnt/disk1/music/01 Billy The Mountain.flac with ssc-ffmpeg/svn-1586

2007-12-18 07:56:20 (b680cb90): opening /mnt/disk1/music/01 Billy The Mountain.flac

2007-12-18 07:56:20 (b680cb90): opening file raw

2007-12-18 07:56:20 (b680cb90): Updating Content-Type from text/html to audio/wav

2007-12-18 07:56:20 (b680cb90): Updating Connection from close to Close

2007-12-18 07:56:20 (b680cb90): Emitting reponse header Content-Language: en_us

2007-12-18 07:56:20 (b680cb90): Emitting reponse header Content-Type: audio/wav

2007-12-18 07:56:20 (b680cb90): Emitting reponse header Server: mt-daapd/svn-1586

2007-12-18 07:56:20 (b680cb90): Emitting reponse header Connection: Close

2007-12-18 07:56:20 (b680cb90): Emitting reponse header Date: Tue, 18 Dec 2007 06:56:20 GMT

2007-12-18 07:56:20 (b680cb90): Channels.......: 2

2007-12-18 07:56:20 (b680cb90): Sample rate....: 44100

2007-12-18 07:56:20 (b680cb90): Bits/Sample....: 16

2007-12-18 07:56:20 (b680cb90): Swab...........: 0

2007-12-18 07:56:20 (b680cb90): Entering config_set_status

2007-12-18 07:56:20 (b680cb90): Exiting config_set_status

2007-12-18 07:56:20 (b680cb90): Thread 16: Terminating

2007-12-18 07:56:20 (b680cb90): Thread 16: Freeing request headers

2007-12-18 07:56:20 (b680cb90): Thread 16: Freeing response headers

2007-12-18 07:56:20 (b680cb90): Thread 16: Freeing request vars

2007-12-18 07:56:20 (b680cb90): Thread 16: Closing fd

2007-12-18 07:56:20 (b680cb90): With thread 16 exiting, 0 are still running

2007-12-18 07:56:23 (b78af6c0): select(8, 5.000000)

2007-12-18 07:56:24 (b680cb90): Thread 17: Entering ws_dispatcher (Connection from 192.168.0.104)

2007-12-18 07:56:24 (b680cb90): Thread 17: got request

2007-12-18 07:56:24 (b680cb90): Request: GET /rsp/db/0?query=id%3D4176&type=full HTTP/1.0^M

2007-12-18 07:56:24 (b680cb90): Thread 17: Read: User-Agent: Roku SoundBridge/3.0^M

2007-12-18 07:56:24 (b680cb90): Thread 17: Adding header *User-Agent=Roku SoundBridge/3.0*

2007-12-18 07:56:24 (b680cb90): Added *User-Agent=Roku SoundBridge/3.0*

2007-12-18 07:56:24 (b680cb90): Thread 17: Read: Host: 192.168.0.106:3689^M

2007-12-18 07:56:24 (b680cb90): Thread 17: Adding header *Host=192.168.0.106:3689*

2007-12-18 07:56:24 (b680cb90): Added *Host=192.168.0.106:3689*

2007-12-18 07:56:24 (b680cb90): Thread 17: Read: Accept: */*^M

2007-12-18 07:56:24 (b680cb90): Thread 17: Adding header *Accept=*/**

2007-12-18 07:56:24 (b680cb90): Added *Accept=*/**

2007-12-18 07:56:24 (b680cb90): Thread 17: Read: Pragma: no-cache^M

2007-12-18 07:56:24 (b680cb90): Thread 17: Adding header *Pragma=no-cache*

2007-12-18 07:56:24 (b680cb90): Added *Pragma=no-cache*

2007-12-18 07:56:24 (b680cb90): Thread 17: Read: accept-encoding: gzip^M

2007-12-18 07:56:24 (b680cb90): Thread 17: Adding header *accept-encoding=gzip*

2007-12-18 07:56:24 (b680cb90): Added *accept-encoding=gzip*

2007-12-18 07:56:24 (b680cb90): Thread 17: Read: accept-codecs: wma,mpeg,wav,mp4a,alac^M

2007-12-18 07:56:24 (b680cb90): Thread 17: Adding header *accept-codecs=wma,mpeg,wav,mp4a,alac*

2007-12-18 07:56:24 (b680cb90): Added *accept-codecs=wma,mpeg,wav,mp4a,alac*

2007-12-18 07:56:24 (b680cb90): Thread 17: Read: rsp-version: 0.1^M

2007-12-18 07:56:24 (b680cb90): Thread 17: Adding header *rsp-version=0.1*

2007-12-18 07:56:24 (b680cb90): Added *rsp-version=0.1*

2007-12-18 07:56:24 (b680cb90): Thread 17: Read: transcode-codecs: wav,mp3^M

2007-12-18 07:56:24 (b680cb90): Thread 17: Adding header *transcode-codecs=wav,mp3*

2007-12-18 07:56:24 (b680cb90): Added *transcode-codecs=wav,mp3*

2007-12-18 07:56:24 (b680cb90): Thread 17: Read: ^M

2007-12-18 07:56:24 (b680cb90): Thread 17: Headers parsed!

2007-12-18 07:56:24 (b680cb90): Checking to see if connection matches keep-alive

2007-12-18 07:56:24 (b680cb90): Nope!

2007-12-18 07:56:24 (b680cb90): Thread 17: Connection type HTTP/1.0^M

: Connection: non-persist

2007-12-18 07:56:24 (b680cb90): Thread 17: parsing GET args

2007-12-18 07:56:24 (b680cb90): Thread 17: Entering ws_getgetvars (query=id%3D4176&type=full)

2007-12-18 07:56:24 (b680cb90): Thread 17: Adding arg query = id=4176

2007-12-18 07:56:24 (b680cb90): Added *query=id=4176*

2007-12-18 07:56:24 (b680cb90): Thread 17: Adding arg type = full

2007-12-18 07:56:24 (b680cb90): Added *type=full*

2007-12-18 07:56:24 (b680cb90): Thread 17: Done parsing GET/POST args!

2007-12-18 07:56:24 (b680cb90): Thread 17: Original URI: /rsp/db/0

2007-12-18 07:56:24 (b680cb90): Thread 17: Translated URI: /rsp/db/0

2007-12-18 07:56:24 (b680cb90): Thread 17: Preparing to find handler

2007-12-18 07:56:24 (b680cb90): Checking /rsp/db/0 against handler for /

2007-12-18 07:56:24 (b680cb90): Thread 17: URI Match!

2007-12-18 07:56:24 (b680cb90): Thread 17: Time is 1197960984 seconds after epoch

2007-12-18 07:56:24 (b680cb90): Thread 17: Setting time header

2007-12-18 07:56:24 (b680cb90): Added *Date=Tue, 18 Dec 2007 06:56:24 GMT*

2007-12-18 07:56:24 (b680cb90): Added *Connection=close*

2007-12-18 07:56:24 (b680cb90): Added *Server=mt-daapd/svn-1586*

2007-12-18 07:56:24 (b680cb90): Added *Content-Type=text/html*

2007-12-18 07:56:24 (b680cb90): Added *Content-Language=en_us*

2007-12-18 07:56:24 (b680cb90): Thread 17: Using non-default handler

2007-12-18 07:56:24 (b680cb90): in main_auth

2007-12-18 07:56:24 (b680cb90): Checking url /rsp/db/0

2007-12-18 07:56:24 (b680cb90): Checking url /rsp/db/0

2007-12-18 07:56:24 (b680cb90): Dispatching auth for /rsp/db/0 to plugin

2007-12-18 07:56:24 (b680cb90): Checking url /rsp/db/0

2007-12-18 07:56:24 (b680cb90): Checking url /rsp/db/0

2007-12-18 07:56:24 (b680cb90): Dispatching /rsp/db/0 to rsp/svn-1586

2007-12-18 07:56:24 (b680cb90): Checking if pw required for /rsp/db/0 as user

2007-12-18 07:56:24 (b680cb90): Nope

2007-12-18 07:56:24 (b680cb90): in main_handler

2007-12-18 07:56:24 (b680cb90): Checking url /rsp/db/0

2007-12-18 07:56:24 (b680cb90): Checking url /rsp/db/0

2007-12-18 07:56:24 (b680cb90): Dispatching /rsp/db/0 to plugin

2007-12-18 07:56:24 (b680cb90): Checking url /rsp/db/0

2007-12-18 07:56:24 (b680cb90): Checking url /rsp/db/0

2007-12-18 07:56:24 (b680cb90): Dispatching /rsp/db/0 to rsp/svn-1586

2007-12-18 07:56:24 (b680cb90): Getting uri...

2007-12-18 07:56:24 (b680cb90): Mallocing privinfo...

2007-12-18 07:56:24 (b680cb90): Tokenizing url

2007-12-18 07:56:24 (b680cb90): Found 5 elements

2007-12-18 07:56:24 (b680cb90): Checking reponse 0

2007-12-18 07:56:24 (b680cb90): Checking reponse 1

2007-12-18 07:56:24 (b680cb90): Checking reponse 2

2007-12-18 07:56:24 (b680cb90): Found it! Index: 2

2007-12-18 07:56:24 (b680cb90):   Returning token 2002

2007-12-18 07:56:24 (b680cb90):   Entering sp_parse_phrase

2007-12-18 07:56:24 (b680cb90):     Entering sp_parse_oexpr

2007-12-18 07:56:24 (b680cb90):      Entering sp_parse_aexpr

2007-12-18 07:56:24 (b680cb90):       Entering sp_parse_expr

2007-12-18 07:56:24 (b680cb90):        Entering sp_parse_criterion

2007-12-18 07:56:24 (b680cb90):         Entering sp_parse_int_criterion

2007-12-18 07:56:24 (b680cb90):         Returning token 000f

2007-12-18 07:56:24 (b680cb90):         Returning token 00fd

2007-12-18 07:56:24 (b680cb90):         Exiting sp_parse_int_criterion (success)

2007-12-18 07:56:24 (b680cb90):        Exiting sp_parse_criterion (success)

2007-12-18 07:56:24 (b680cb90):       Exiting sp_parse_expr (success)

2007-12-18 07:56:24 (b680cb90):      Exiting sp_parse_aexpr (success)

2007-12-18 07:56:24 (b680cb90):     Exiting sp_parse_oexpr (success)

2007-12-18 07:56:24 (b680cb90):    Exiting sp_parse_phrase (success)

2007-12-18 07:56:24 (b680cb90): Got query/filter

2007-12-18 07:56:24 (b680cb90): Fetching sql statement size

2007-12-18 07:56:24 (b680cb90): Size: 47

2007-12-18 07:56:24 (b680cb90): Serialized to : (id = 4176)

2007-12-18 07:56:24 (b680cb90): Executing: select count(songs.id) from songs  where ((id = 4176))

2007-12-18 07:56:24 (b680cb90): Number of results: 1

2007-12-18 07:56:24 (b680cb90): Executing: select * from songs  where ((id = 4176))

2007-12-18 07:56:24 (b680cb90): Gzipping output

2007-12-18 07:56:24 (b680cb90): Added *Content-Encoding=gzip*

2007-12-18 07:56:24 (b680cb90): Added *Vary=Accept-Encoding*

2007-12-18 07:56:24 (b680cb90): Updating Connection from close to Close

2007-12-18 07:56:24 (b680cb90): Added *Cache-Control=no-cache*

2007-12-18 07:56:24 (b680cb90): Added *Expires=-1*

2007-12-18 07:56:24 (b680cb90): Updating Content-Type from text/html to text/xml; charset=utf-8

2007-12-18 07:56:24 (b680cb90): Emitting reponse header Expires: -1

2007-12-18 07:56:24 (b680cb90): Emitting reponse header Cache-Control: no-cache

2007-12-18 07:56:24 (b680cb90): Emitting reponse header Vary: Accept-Encoding

2007-12-18 07:56:24 (b680cb90): Emitting reponse header Content-Encoding: gzip

2007-12-18 07:56:24 (b680cb90): Emitting reponse header Content-Language: en_us

2007-12-18 07:56:24 (b680cb90): Emitting reponse header Content-Type: text/xml; charset=utf-8

2007-12-18 07:56:24 (b680cb90): Emitting reponse header Server: mt-daapd/svn-1586

2007-12-18 07:56:24 (b680cb90): Emitting reponse header Connection: Close

2007-12-18 07:56:24 (b680cb90): Emitting reponse header Date: Tue, 18 Dec 2007 06:56:24 GMT

2007-12-18 07:56:24 (b680cb90): Transcode: 1, flac: call_any_vegetable.flac

2007-12-18 07:56:24 (b680cb90): Done sending xml stream

2007-12-18 07:56:24 (b680cb90): Thread 17: Terminating

2007-12-18 07:56:24 (b680cb90): Thread 17: Freeing request headers

2007-12-18 07:56:24 (b680cb90): Thread 17: Freeing response headers

2007-12-18 07:56:24 (b680cb90): Thread 17: Freeing request vars

2007-12-18 07:56:24 (b680cb90): Thread 17: Closing fd

2007-12-18 07:56:24 (b680cb90): With thread 17 exiting, 0 are still running

2007-12-18 07:56:24 (b680cb90): Thread 18: Entering ws_dispatcher (Connection from 192.168.0.104)

2007-12-18 07:56:24 (b680cb90): Thread 18: got request

2007-12-18 07:56:24 (b680cb90): Request: GET /rsp/stream/4176 HTTP/1.0^M

2007-12-18 07:56:24 (b680cb90): Thread 18: Read: User-Agent: Roku SoundBridge/3.0^M

2007-12-18 07:56:24 (b680cb90): Thread 18: Adding header *User-Agent=Roku SoundBridge/3.0*

2007-12-18 07:56:24 (b680cb90): Added *User-Agent=Roku SoundBridge/3.0*

2007-12-18 07:56:24 (b680cb90): Thread 18: Read: Host: 192.168.0.106:3689^M

2007-12-18 07:56:24 (b680cb90): Thread 18: Adding header *Host=192.168.0.106:3689*

2007-12-18 07:56:24 (b680cb90): Added *Host=192.168.0.106:3689*

2007-12-18 07:56:24 (b680cb90): Thread 18: Read: Accept: */*^M

2007-12-18 07:56:24 (b680cb90): Thread 18: Adding header *Accept=*/**

2007-12-18 07:56:24 (b680cb90): Added *Accept=*/**

2007-12-18 07:56:24 (b680cb90): Thread 18: Read: Pragma: no-cache^M

2007-12-18 07:56:24 (b680cb90): Thread 18: Adding header *Pragma=no-cache*

2007-12-18 07:56:24 (b680cb90): Added *Pragma=no-cache*

2007-12-18 07:56:24 (b680cb90): Thread 18: Read: accept-codecs: wma,mpeg,wav,mp4a,alac^M

2007-12-18 07:56:24 (b680cb90): Thread 18: Adding header *accept-codecs=wma,mpeg,wav,mp4a,alac*

2007-12-18 07:56:24 (b680cb90): Added *accept-codecs=wma,mpeg,wav,mp4a,alac*

2007-12-18 07:56:24 (b680cb90): Thread 18: Read: rsp-version: 0.1^M

2007-12-18 07:56:24 (b680cb90): Thread 18: Adding header *rsp-version=0.1*

2007-12-18 07:56:24 (b680cb90): Added *rsp-version=0.1*

2007-12-18 07:56:24 (b680cb90): Thread 18: Read: transcode-codecs: wav,mp3^M

2007-12-18 07:56:24 (b680cb90): Thread 18: Adding header *transcode-codecs=wav,mp3*

2007-12-18 07:56:24 (b680cb90): Added *transcode-codecs=wav,mp3*

2007-12-18 07:56:24 (b680cb90): Thread 18: Read: ^M

2007-12-18 07:56:24 (b680cb90): Thread 18: Headers parsed!

2007-12-18 07:56:24 (b680cb90): Checking to see if connection matches keep-alive

2007-12-18 07:56:24 (b680cb90): Nope!

2007-12-18 07:56:24 (b680cb90): Thread 18: Connection type HTTP/1.0^M

: Connection: non-persist

2007-12-18 07:56:24 (b680cb90): Thread 18: Original URI: /rsp/stream/4176

2007-12-18 07:56:24 (b680cb90): Thread 18: Translated URI: /rsp/stream/4176

2007-12-18 07:56:24 (b680cb90): Thread 18: Preparing to find handler

2007-12-18 07:56:24 (b680cb90): Checking /rsp/stream/4176 against handler for /

2007-12-18 07:56:24 (b680cb90): Thread 18: URI Match!

2007-12-18 07:56:24 (b680cb90): Thread 18: Time is 1197960984 seconds after epoch

2007-12-18 07:56:24 (b680cb90): Thread 18: Setting time header

2007-12-18 07:56:24 (b680cb90): Added *Date=Tue, 18 Dec 2007 06:56:24 GMT*

2007-12-18 07:56:24 (b680cb90): Added *Connection=close*

2007-12-18 07:56:24 (b680cb90): Added *Server=mt-daapd/svn-1586*

2007-12-18 07:56:24 (b680cb90): Added *Content-Type=text/html*

2007-12-18 07:56:24 (b680cb90): Added *Content-Language=en_us*

2007-12-18 07:56:24 (b680cb90): Thread 18: Using non-default handler

2007-12-18 07:56:24 (b680cb90): in main_auth

2007-12-18 07:56:24 (b680cb90): Checking url /rsp/stream/4176

2007-12-18 07:56:24 (b680cb90): Checking url /rsp/stream/4176

2007-12-18 07:56:24 (b680cb90): Dispatching auth for /rsp/stream/4176 to plugin

2007-12-18 07:56:24 (b680cb90): Checking url /rsp/stream/4176

2007-12-18 07:56:24 (b680cb90): Checking url /rsp/stream/4176

2007-12-18 07:56:24 (b680cb90): Dispatching /rsp/stream/4176 to rsp/svn-1586

2007-12-18 07:56:24 (b680cb90): Checking if pw required for /rsp/stream/4176 as user

2007-12-18 07:56:24 (b680cb90): Nope

2007-12-18 07:56:24 (b680cb90): in main_handler

2007-12-18 07:56:24 (b680cb90): Checking url /rsp/stream/4176

2007-12-18 07:56:24 (b680cb90): Checking url /rsp/stream/4176

2007-12-18 07:56:24 (b680cb90): Dispatching /rsp/stream/4176 to plugin

2007-12-18 07:56:24 (b680cb90): Checking url /rsp/stream/4176

2007-12-18 07:56:24 (b680cb90): Checking url /rsp/stream/4176

2007-12-18 07:56:24 (b680cb90): Dispatching /rsp/stream/4176 to rsp/svn-1586

2007-12-18 07:56:24 (b680cb90): Getting uri...

2007-12-18 07:56:24 (b680cb90): Mallocing privinfo...

2007-12-18 07:56:24 (b680cb90): Tokenizing url

2007-12-18 07:56:24 (b680cb90): Found 5 elements

2007-12-18 07:56:24 (b680cb90): Checking reponse 0

2007-12-18 07:56:24 (b680cb90): Checking reponse 1

2007-12-18 07:56:24 (b680cb90): Checking reponse 2

2007-12-18 07:56:24 (b680cb90): Checking reponse 3

2007-12-18 07:56:24 (b680cb90): Checking reponse 4

2007-12-18 07:56:24 (b680cb90): Found it! Index: 4

2007-12-18 07:56:24 (b680cb90): Executing: select * from songs where id=4176

2007-12-18 07:56:24 (b680cb90): Entering config_set_status

2007-12-18 07:56:24 (b680cb90): Exiting config_set_status

2007-12-18 07:56:24 (b680cb90): Session 0: Streaming file 'call_any_vegetable.flac' to 192.168.0.104 (offset 0)

2007-12-18 07:56:24 (b680cb90): Transcoding /mnt/disk1/music/frank_zappa/just_another_band_from_la/call_any_vegetable.flac with ssc-ffmpeg/svn-1586

2007-12-18 07:56:24 (b680cb90): opening /mnt/disk1/music/frank_zappa/just_another_band_from_la/call_any_vegetable.flac

2007-12-18 07:56:24 (b680cb90): opening file raw

2007-12-18 07:56:24 (b680cb90): Updating Content-Type from text/html to audio/wav

2007-12-18 07:56:24 (b680cb90): Updating Connection from close to Close

2007-12-18 07:56:24 (b680cb90): Emitting reponse header Content-Language: en_us

2007-12-18 07:56:24 (b680cb90): Emitting reponse header Content-Type: audio/wav

2007-12-18 07:56:24 (b680cb90): Emitting reponse header Server: mt-daapd/svn-1586

2007-12-18 07:56:24 (b680cb90): Emitting reponse header Connection: Close

2007-12-18 07:56:24 (b680cb90): Emitting reponse header Date: Tue, 18 Dec 2007 06:56:24 GMT

2007-12-18 07:56:24 (b680cb90): Channels.......: 2

2007-12-18 07:56:24 (b680cb90): Sample rate....: 44100

2007-12-18 07:56:24 (b680cb90): Bits/Sample....: 16

2007-12-18 07:56:24 (b680cb90): Swab...........: 0

2007-12-18 07:56:28 (b78af6c0): select(8, 5.000000)

2007-12-18 07:56:31 (b680cb90): Entering config_set_status

2007-12-18 07:56:31 (b680cb90): Exiting config_set_status

2007-12-18 07:56:31 (b680cb90): Thread 18: Terminating

2007-12-18 07:56:31 (b680cb90): Thread 18: Freeing request headers

2007-12-18 07:56:31 (b680cb90): Thread 18: Freeing response headers

[uncleremus]

But, it seems like this is not exclusively due to file size, since I have another version of the song “Billy The Mountain” lying around which will play nicely on the Roku Soundbridge. The difference I know is that it is encoded with an older flac-version

 vendor string: reference libFLAC 1.1.2 20050205

and the newer

 vendor string: reference libFLAC 1.2.1 20070917

EDIT: I might also add that the .flac files causing trouble are perfectly playable in e.g. amarok

[rpedde]

@uncleremus wrote:

But, it seems like this is not exclusively due to file size, since I have another version of the song “Billy The Mountain” lying around which will play nicely on the Roku Soundbridge. The difference I know is that it is encoded with an older flac-version

 vendor string: reference libFLAC 1.1.2 20050205

and the newer

 vendor string: reference libFLAC 1.2.1 20070917

EDIT: I might also add that the .flac files causing trouble are perfectly playable in e.g. amarok

I actually think iirc it’s to do with cover art.

Well, that’s only partly true.. that and flac command-line executable for flac, I think.

[S80_UK]

Hi,

This is what I’ve been looking into. It is true that the cover art changes in FLAC seem to have helped to create this problem but the files do not need to have cover art in to fall foul of it. I read that the real problem is the size of buffer allocated in the FLAC library for handling tags and other data. I suspect (but cannot prove) that other information such as seek tables may be included in this, which is while larger files are more likely to show the problem. Some applications / FLAC libraries use a larger buffer or a different scheme for handling this data.

There is a FLAC library using version 1.2.1 in testing for Debian Etch, and I have been meaning to get around to testing it myself, but I have not yet had the spare time to play…

[uncleremus]

@rpedde wrote:

I actually think iirc it’s to do with cover art.

Well, that’s only partly true.. that and flac command-line executable for flac, I think.

But, I hope I have been clear about the other songs from the same album plays just fine? It is only one song, in this case a song lasting more that 20 minutes, that doesn’t play. The other songs are ripped with exactly the same command line switches and executable.

[S80_UK]

@uncleremus wrote:

But, I hope I have been clear about the other songs from the same album plays just fine? It is only one song, in this case a song lasting more that 20 minutes, that doesn’t play. The other songs are ripped with exactly the same command line switches and executable.

Very clear – that’s exactly the problem that I have also. Example – Autobahn by Kraftwerk encoded with 1.2.1 – I can’t play the title track with the SoundBridge using Firefly under Windows but I can play all of the others. It is a known issue of how FLAC is sometimes used. Some devices with old FLAC decoders work – some don’t.

[uncleremus]

@S80_UK wrote:

Very clear – that’s exactly the problem that I have also. Example – Autobahn by Kraftwerk encoded with 1.2.1 – I can’t play the title track with the SoundBridge using Firefly under Windows but I can play all of the others. It is a known issue of how FLAC is sometimes used. Some devices with old FLAC decoders work – some don’t.

Thanks for your reply. Very interesting. I downgraded my flac (Gentoo Linux) to 1.1.4 today and was very hopeful, but still the file wouldn’t plat after encoding with that.

Could this maybe be fixed by a software change? Would be in at least both iTunes and Roku then if I am correct.

[S80_UK]

The software change needs to be in the FLAC liibrary that is used by Firefly. I have no issues running Firefly on my NSLU2, only under Windows on PC. The difference is the audio library that is used. I think NSLU2 uses libflac, whereas the PC version of Firefly uses ffmpeg (I think) and I understand that it is ffmpeg that needs updating for the Windows version to work.

This is not a Roku or iTunes issue since neither knows anything about FLAC – Firelfy transcodes FLAC to WAV. The reason that you see the error is simply that Firefly is able to report that there is an error from the transcoding function.

[uncleremus]

Thanks again, I have tried on the server side to downgrade ffmpeg and flac, but to no avail. (The reason I did was that I haven’t observed this problem earlier, so I thought maybe something had been updated that contained the “bug”).

But one thing still bothers me. How can it be that two encodings with different flac-versions of the same song causes two different behaviours when played back? I mean, if the library that decodes is the “culprit”, how can it work with one version of flac encoding? Is it that I got lucky in terms of e.g. buffer size, or seek tables, when the encoding was done?

[S80_UK]

The reason that you see the problem is related to differences in the encoded files. If you have problem files, you can encode them with a older version of FLAC and they will play fine with both older and newer decoders.

I know it can be confusing, but it’s just the way it is. As I mentioned, I have old decoders that can play the files from the new encoder and some that can’t. The NSLU2 with Firefly has no trouble, and in my car I have a Phatbox – that runs FLAC 1.1.2 as the decoder and it also has no issues with files from 1.2.1. So it is not the decoder itself which is broken but the way in which is it used in the application (on the PC), or more specifically in the decoder library.

You are right in one sense – the tables in most files take little enough room. It is just some bigger files that seem to have the issue.

[Author]

Posts