FireFly Media Server (formerly mt-daapd) › Firefly Media Server Forums › Firefly Media Server › Nightlies Feedback › svn 1586 crashed when scan
- This topic has 16 replies, 3 voices, and was last updated 13 years, 5 months ago by
yllu.
-
AuthorPosts
-
24th August 2007 at 8:26 am #1649
yllu
ParticipantThere are 11 media files in my folder, including 5 wav files, 2 M4V files and 4 mp4 files.
After starting mt-daapd about 3 hours with 1 second rescan-interval, mt-daapd crashed.
The following is the end of the log file with debug level 9.
2007-08-23 14:19:15 (40018260): Rows: 1
2007-08-23 14:19:15 (40018260): Skipping file, not modified
2007-08-23 14:19:15 (40018260): Ending song scan
2007-08-23 14:19:15 (40018260): Executing: pragma synchronous = off
2007-08-23 14:19:15 (40018260): Rows: 1
2007-08-23 14:19:15 (40018260): Executing: begin transaction
2007-08-23 14:19:15 (40018260): Rows: 1
2007-08-23 14:19:15 (40018260): Processing playlists
2007-08-23 14:19:15 (40018260): Starting playlist scan
2007-08-23 14:19:15 (40018260): Finished playlist loop
2007-08-23 14:19:15 (40018260): Executing: end transaction
2007-08-23 14:19:15 (40018260): Rows: 1
2007-08-23 14:19:15 (40018260): Executing: pragma synchronous=normal
2007-08-23 14:19:15 (40018260): Rows: 1
2007-08-23 14:19:15 (40018260): Executing: delete from songs where id not in (select id from updated)
2007-08-23 14:19:15 (40018260): Rows: 0
2007-08-23 14:19:15 (40018260): Executing: update songs set force_update=0
2007-08-23 14:19:15 (40018260): Rows: 11
2007-08-23 14:19:15 (40018260): Executing: drop table updated
2007-08-23 14:19:15 (40018260): Rows: 11
2007-08-23 14:19:15 (40018260): Executing: delete from playlists where ((type=2) OR (type=3)) and id not in (select id from plupdated)
2007-08-23 14:19:15 (40018260): Rows: 0
2007-08-23 14:19:15 (40018260): Executing: delete from playlistitems where playlistid not in (select distinct id from playlists)
2007-08-23 14:19:15 (40018260): Rows: 0
2007-08-23 14:19:15 (40018260): Executing: drop table plupdated
2007-08-23 14:19:15 (40018260): Rows: 0
2007-08-23 14:19:15 (40018260): Updating playlists
2007-08-23 14:19:15 (40018260): Executing: select count(*) from playlists
2007-08-23 14:19:15 (40018260): Executing: select * from playlists
2007-08-23 14:19:15 (40018260): Executing: update playlists set items=(select count(*) from songs where 1) where id=1
2007-08-23 14:19:15 (40018260): Rows: 1
2007-08-23 14:19:15 (40018260): Executing: select count(*) FROM songs
2007-08-23 14:19:15 (40018260): Scanned 11 songs (was 11) in 0 seconds
2007-08-23 14:19:17 (40018260): Rescanning database
2007-08-23 14:19:17 (40018260): Starting scan_init
2007-08-23 14:19:17 (40018260): Starting db scan
2007-08-23 14:19:17 (40018260): Executing: drop table updated
2007-08-23 14:19:17 (40018260): Query: drop table updated
2007-08-23 14:19:17 (40018260): Error: no such table: updated
2007-08-23 14:19:17 (40018260): Executing: create temp table updated (id int)
2007-08-23 14:19:17 (40018260): Rows: 1
2007-08-23 14:19:17 (40018260): Executing: drop table plupdated
2007-08-23 14:19:17 (40018260): Query: drop table plupdated
2007-08-23 14:19:17 (40018260): Error: no such table: plupdated
2007-08-23 14:19:17 (40018260): Executing: create temp table plupdated(id int)
2007-08-23 14:19:17 (40018260): Rows: 1
2007-08-23 14:19:17 (40018260): Scanning for MP3s in /dev/null
2007-08-23 14:19:17 (40018260): opendir: Not a directory
2007-08-23 14:19:17 (40018260): Scanning for MP3s in /i-data/md0/admin/Test0823
2007-08-23 14:19:17 (40018260): Found /i-data/0add4eca/admin/Test0823/Music
2007-08-23 14:19:17 (40018260): Found Music.. recursing
2007-08-23 14:19:17 (40018260): Found /i-data/0add4eca/admin/Test0823/Music/wav
2007-08-23 14:19:17 (40018260): Found wav.. recursing
2007-08-23 14:19:17 (40018260): Found /i-data/0add4eca/admin/Test0823/Music/wav/imonBeep.wav
2007-08-23 14:19:17 (40018260): Executing: select * from songs where path='/i-data/0add4eca/admin/Test0823/Music/wav/imonBeep.wav' and idx=0
2007-08-23 14:19:17 (40018260): Executing: INSERT INTO updated VALUES (1)
2007-08-23 14:19:17 (40018260): Rows: 1
2007-08-23 14:19:17 (40018260): Skipping file, not modified
2007-08-23 14:19:17 (40018260): Found /i-data/0add4eca/admin/Test0823/Music/wav/sonata a major - alla turca - allegretto.wav
2007-08-23 14:19:17 (40018260): Executing: select * from songs where path='/i-data/0add4eca/admin/Test0823/Music/wav/sonata a major - alla turca - allegretto.wav' and idx=0
2007-08-23 14:19:17 (40018260): Executing: INSERT INTO updated VALUES (2)
2007-08-23 14:19:17 (40018260): Rows: 1
2007-08-23 14:19:17 (40018260): Skipping file, not modified
2007-08-23 14:19:17 (40018260): Found /i-data/0add4eca/admin/Test0823/Music/wav/48kHz mo 16bit PCM.wav
2007-08-23 14:19:17 (40018260): Executing: select * from songs where path='/i-data/0add4eca/admin/Test0823/Music/wav/48kHz mo 16bit PCM.wav' and idx=0
2007-08-23 14:19:17 (40018260): Executing: INSERT INTO updated VALUES (3)
2007-08-23 14:19:17 (40018260): Rows: 1
2007-08-23 14:19:17 (40018260): Skipping file, not modified
2007-08-23 14:19:17 (40018260): Found /i-data/0add4eca/admin/Test0823/Music/wav/16kHz st 16bit PCM.wav
2007-08-23 14:19:17 (40018260): Executing: select * from songs where path='/i-data/0add4eca/admin/Test0823/Music/wav/16kHz st 16bit PCM.wav' and idx=0
2007-08-23 14:19:17 (40018260): Executing: INSERT INTO updated VALUES (4)
2007-08-23 14:19:17 (40018260): Rows: 1
2007-08-23 14:19:17 (40018260): Skipping file, not modified
2007-08-23 14:19:17 (40018260): Found /i-data/0add4eca/admin/Test0823/Music/wav/44.1kHz mo 16bit PCM.wav
2007-08-23 14:19:17 (40018260): Executing: select * from songs where path='/i-data/0add4eca/admin/Test0823/Music/wav/44.1kHz mo 16bit PCM.wav' and idx=0
2007-08-23 14:19:17 (40018260): Executing: INSERT INTO updated VALUES (5)
2007-08-23 14:19:17 (40018260): Rows: 1
2007-08-23 14:19:17 (40018260): Skipping file, not modified
2007-08-23 14:19:17 (40018260): Found /i-data/0add4eca/admin/Test0823/Video
2007-08-23 14:19:17 (40018260): Found Video.. recursing
2007-08-23 14:19:17 (40018260): Found /i-data/0add4eca/admin/Test0823/Video/M4V
2007-08-23 14:19:17 (40018260): Found M4V.. recursing
2007-08-23 14:19:17 (40018260): Found /i-data/0add4eca/admin/Test0823/Video/M4V/720p_VideoOnly.m4v
2007-08-23 14:19:17 (40018260): Executing: select * from songs where path='/i-data/0add4eca/admin/Test0823/Video/M4V/720p_VideoOnly.m4v' and idx=0
2007-08-23 14:19:17 (40018260): Executing: INSERT INTO updated VALUES (6)
2007-08-23 14:19:17 (40018260): Rows: 1
2007-08-23 14:19:17 (40018260): Skipping file, not modified
2007-08-23 14:19:17 (40018260): Found /i-data/0add4eca/admin/Test0823/Video/M4V/news_sif_1m.m4v
2007-08-23 14:19:17 (40018260): Executing: select * from songs where path='/i-data/0add4eca/admin/Test0823/Video/M4V/news_sif_1m.m4v' and idx=0
2007-08-23 14:19:17 (40018260): Executing: INSERT INTO updated VALUES (7)
2007-08-23 14:19:17 (40018260): Rows: 1
2007-08-23 14:19:17 (40018260): Skipping file, not modified
2007-08-23 14:19:17 (40018260): Found /i-data/0add4eca/admin/Test0823/Video/MP4
2007-08-23 14:19:17 (40018260): Found MP4.. recursing
2007-08-23 14:19:17 (40018260): Found /i-data/0add4eca/admin/Test0823/Video/MP4/Trek2_C_1Mb.mp4
2007-08-23 14:19:17 (40018260): Executing: select * from songs where path='/i-data/0add4eca/admin/Test0823/Video/MP4/Trek2_C_1Mb.mp4' and idx=0
2007-08-23 14:19:17 (40018260): Executing: INSERT INTO updated VALUES (8)
2007-08-23 14:19:17 (40018260): Rows: 1
2007-08-23 14:19:17 (40018260): Skipping file, not modified
2007-08-23 14:19:17 (40018260): Found /i-data/0add4eca/admin/Test0823/Video/MP4/Stig_V_1500_Shanghai.mp4
2007-08-23 14:19:17 (40018260): Executing: select * from songs where path='/i-data/0add4eca/admin/Test0823/Video/MP4/Stig_V_1500_Shanghai.mp4' and idx=0
2007-08-23 14:19:17 (40018260): Executing: INSERT INTO updated VALUES (9)
2007-08-23 14:19:17 (40018260): Rows: 1
2007-08-23 14:19:17 (40018260): Skipping file, not modified
2007-08-23 14:19:17 (40018260): Found /i-data/0add4eca/admin/Test0823/Video/MP4/SONY P800 Motorola A835 - Budweiser (Nude Ferret).mp4
2007-08-23 14:19:17 (40018260): Executing: select * from songs where path='/i-data/0add4eca/admin/Test0823/Video/MP4/SONY P800 Motorola A835 - Budweiser (Nude Ferret).mp4' and idx=0
2007-08-23 14:19:17 (40018260): Executing: INSERT INTO updated VALUES (10)
2007-08-23 14:19:17 (40018260): Rows: 1
2007-08-23 14:19:17 (40018260): Skipping file, not modified
2007-08-23 14:19:17 (40018260): Found /i-data/0add4eca/admin/Test0823/Video/MP4/SONY P800 - MP4 VIDEO - Nike - Football - The Mission.mp4
2007-08-23 14:19:17 (40018260): Executing: select * from songs where path='/i-data/0add4eca/admin/Test0823/Video/MP4/SONY P800 - MP4 VIDEO - Nike - Football - The Mission.mp4' and idx=0
2007-08-23 14:19:17 (40018260): Executing: INSERT INTO updated VALUES (11)
2007-08-23 14:19:17 (40018260): Rows: 1
2007-08-23 14:19:17 (40018260): Skipping file, not modified
2007-08-23 14:19:17 (40018260): Processing rendezvous message
2007-08-23 14:19:17 (40018260): Rendezvous socket closed (daap server crashed?) Aborting.
2007-08-23 14:19:17: Aborting
Are there any non-supported files between these 11 files? Or it’s mt-daapd’s bug?
Thanks for solutions.24th August 2007 at 11:55 am #12156fizze
ParticipantFirst of all a rescan interval of 1sec does not seem sane to me 😉
Secondly, those look like mp4 video files, which Im not sure firefly even serves.
If you’re on windows on a decent PC, you can safely set the rescan interval to, say, 600 seconds (10 minutes). You might as well just enable “always_scan” in the ini file rather than force it to do a rescan every other second.
I guess the filescanner hickups when it iterates that fast.
25th August 2007 at 7:40 am #12157rpedde
Participant@fizze wrote:
First of all a rescan interval of 1sec does not seem sane to me 😉
Secondly, those look like mp4 video files, which Im not sure firefly even serves.
If you’re on windows on a decent PC, you can safely set the rescan interval to, say, 600 seconds (10 minutes). You might as well just enable “always_scan” in the ini file rather than force it to do a rescan every other second.
I guess the filescanner hickups when it iterates that fast.
It will serve mp4 after a fashion. But there is something with that specific file that’s making it crap out.
How big is the file? Is it emailable, or is there a link to it on the interwub somewhere?
27th August 2007 at 3:42 am #12158yllu
ParticipantI use some other files including media and non-media file to run mt-daapd, and changed rescan-interval to 20 seconds.
Here is the end of mt-daapd.log file in one of my test.2007-08-24 03:43:07 (40018260): Found /_store/#u#aBD#j/X5#d#fN/#oIYO#d/#aT#gB0/J#fPG#l
2007-08-24 03:43:07 (40018260): Found J#fPG#l.. recursing
2007-08-24 03:43:07 (40018260): Found /_store/#u#aBD#j/X5#d#fN/#oIYO#d/#aT#gB0/J#fPG#l/#v#c
2007-08-24 03:43:07 (40018260): Found /_store/#u#aBD#j/X5#d#fN/#oIYO#d/#aT#gB0/J#fPG#l/#v#c.refcount.1
2007-08-24 03:43:07 (40018260): Processing rendezvous message
2007-08-24 03:43:07 (40018260): Rendezvous socket closed (daap server crashed?) Aborting.
2007-08-24 03:43:07: AbortingI also use strace to get some log at the same time.
03:43:07 lstat64("/_store", {st_mode=S_IFDIR|0777, st_size=562949953421312, ...}) = 0
03:43:07 lstat64("/_store/#u#aBD#j", {st_mode=S_IFDIR|0777, st_size=562949953421312, ...}) = 0
03:43:07 lstat64("/_store/#u#aBD#j/X5#d#fN", {st_mode=S_IFDIR|0777, st_size=562949953421312, ...}) = 0
03:43:07 lstat64("/_store/#u#aBD#j/X5#d#fN/#oIYO#d", {st_mode=S_IFDIR|0777, st_size=562949953421312, ...}) = 0
03:43:07 lstat64("/_store/#u#aBD#j/X5#d#fN/#oIYO#d/#aT#gB0", {st_mode=S_IFDIR|0777, st_size=562949953421312, ...}) = 0
03:43:07 lstat64("/_store/#u#aBD#j/X5#d#fN/#oIYO#d/#aT#gB0/J#fPG#l", {st_mode=S_IFDIR|0777, st_size=562949953421312, ...}) = 0
03:43:07 lstat64("/_store/#u#aBD#j/X5#d#fN/#oIYO#d/#aT#gB0/J#fPG#l/#v#c.refcount.1", {st_mode=S_IFREG|0777, st_size=562949953421312, ...}) = 0
03:43:07 time(NULL) = 1187898187
03:43:07 write(3, "2007-08-24 03:43:07 (40018260): "..., 150) = 150
03:43:07 write(2, "Found /_store/#u#aBD#j/X5#d#fN/#"..., 118) = 118
03:43:07 stat64("/_store/#u#aBD#j/X5#d#fN/#oIYO#d/#aT#gB0/J#fPG#l/#v#c.refcount.1", {st_mode=S_IFREG|0777, st_size=562949953421312, ...}) = 0
03:43:07 lstat64("/_store", {st_mode=S_IFDIR|0777, st_size=562949953421312, ...}) = 0
03:43:07 lstat64("/_store/#u#aBD#j", {st_mode=S_IFDIR|0777, st_size=562949953421312, ...}) = 0
03:43:07 lstat64("/_store/#u#aBD#j/X5#d#fN", {st_mode=S_IFDIR|0777, st_size=562949953421312, ...}) = 0
03:43:07 lstat64("/_store/#u#aBD#j/X5#d#fN/#oIYO#d", {st_mode=S_IFDIR|0777, st_size=562949953421312, ...}) = 0
03:43:07 lstat64("/_store/#u#aBD#j/X5#d#fN/#oIYO#d/#aT#gB0", {st_mode=S_IFDIR|0777, st_size=562949953421312, ...}) = 0
03:43:07 lstat64("/_store/#u#aBD#j/X5#d#fN/#oIYO#d/#aT#gB0/J#fPG#l", {st_mode=S_IFDIR|0777, st_size=562949953421312, ...}) = 0
03:43:07 lstat64("/_store/#u#aBD#j/X5#d#fN/#oIYO#d/#aT#gB0/J#fPG#l/#v#c.refcount.1", {st_mode=S_IFREG|0777, st_size=562949953421312, ...}) = 0
03:43:07 stat64("/_store/#u#aBD#j/X5#d#fN/#oIYO#d/#aT#gB0/J#fPG#l/#v#c.refcount.1", {st_mode=S_IFREG|0777, st_size=562949953421312, ...}) = 0
03:43:07 getdents64(0x15, 0x40b3e028, 0x20000, 0xffffffff) = 0
03:43:07 munmap(0x40b3e000, 135168) = 0
03:43:07 close(21) = 0
03:43:07 getdents64(0x14, 0x40b1d028, 0x20000, 0xffffffff) = 0
03:43:07 munmap(0x40b1d000, 135168) = 0
03:43:07 close(20) = 0
03:43:07 getdents64(0x13, 0x40afc028, 0x20000, 0xffffffff) = 0
03:43:07 --- SIGSEGV (Segmentation fault) @ 0 (0) ---mt-daapd end up with segmentation fault.
Besides, I found that mt-daapd not always stopped after scanning a specific file.
However, the end of the log is always the same – “Processing rendezvous message. Rendezvous socket closed (daap server crashed?) Aborting.”
And the end of strace log is always the same too.
It seems like program’s bug, not due to non-supported file.27th August 2007 at 6:02 am #12159yllu
ParticipantThe 4 MP4 files mentioned in the first test are
http://totoro.cs.nthu.edu.tw/~phlee/mp4.rar28th August 2007 at 4:00 am #12160rpedde
Participant@yllu wrote:
Besides, I found that mt-daapd not always stopped after scanning a specific file.
However, the end of the log is always the same – “Processing rendezvous message. Rendezvous socket closed (daap server crashed?) Aborting.”
And the end of strace log is always the same too.
It seems like program’s bug, not due to non-supported file.Ya, sure does.
That’s not a real directory, is it? Or is that some kind of multibyte codepage?
And what kind system and os is it? Looks 64-bit right? Is it Solaris, by any chance?
28th August 2007 at 6:25 am #12161yllu
ParticipantOS is Linux arm. Kernel version is 2.6.18.6.
The testing files are created by Memeo auto backup.
I’m not sure what format Memeo is using for its directory structure.30th August 2007 at 3:32 am #12162yllu
ParticipantI ran another test with only 2 m4v files that I mentioned above.
It successfaully lasted a weekend (about 3 days).
I tried to make the 2 m4v file name longer.- 720p_VideoOnlyabcdefghijklmnopqrstuvwxyzabcdefghijklmnopqrstuvwxyzabcdefghijklmnopqrstuvwxyzabcdefghijklmnopqrstuvwxyzabcdefghijklmnopqrstuvwxyzabcdefghijklmnopqrstuvwxyz.m4v
- news_sif_1mabcdefghijklmnopqrstuvwxyzabcdefghijklmnopqrstuvwxyzabcdefghijklmnopqrstuvwxyzabcdefghijklmnopqrstuvwxyzabcdefghijklmnopqrstuvwxyzabcdefghijklmnopqrstuvwxyz.m4v
The test fails after a few hours.
These are some log that I collected from gdb:
0x40152f94 in nanosleep () from /lib/libc.so.6
(gdb) br rend-posix.c:460
Breakpoint 1 at 0x22f4c: file rend-posix.c, line 460.
(gdb) c
Continuing.
Program received signal SIGSEGV, Segmentation fault.
0x4014eb30 in readdir_r () from /lib/libc.so.6
(gdb) bt
#0 0x4014eb30 in readdir_r () from /lib/libc.so.6
#1 0x00012220 in scan_path (path=0xbeff1bb0 "/i-data/bbb56a93/public/LongFile")
at mp3-scanner.c:365
#2 0x0001258c in scan_init (patharray=0x9b288) at mp3-scanner.c:284
#3 0x0000bb00 in main (argc=2, argv=0x0) at main.c:615
(gdb) fr 1
#1 0x00012220 in scan_path (path=0xbeff1bb0 "/i-data/bbb56a93/public/LongFile")
at mp3-scanner.c:365
365 err=readdir_r(current_dir,(struct dirent *)de,&pde);
(gdb) l
360 return 0;
361 }
362
363 pde=(struct dirent *)&de;
364
365 err=readdir_r(current_dir,(struct dirent *)de,&pde);
366 if(err == -1) {
367 DPRINTF(E_DBG,L_SCAN,"Error on readdir_r: %sn",strerror(errno));
368 err=errno;
369 closedir(current_dir);
(gdb) p pde
$1 = (struct dirent *) 0x0
(gdb) p de
$2 = "30b000001225S)À0000720p_VideoOnlyabcdefghijklmnopqrstuvwxyzabcdefghijklmnopqrstuvwxyzabcdefghijklmnopqrstuvwxyzabcdefghijklmnopqrstuvwxyzabcdefghijklmnopqrstuvwxyzabcdefghijklmnopqrstuvwxyz.m4v", '' , "200^a", '' ...
(gdb) p current_dir
$4 = (DIR *) 0x40a36008
(gdb) print *current_dir
$5 =
(gdb) print readdir_r
$6 = {} 0x4014ea1c
Maybe the buffer size of file name or something is not enough and make pde become 0x0.
30th August 2007 at 5:42 am #12163rpedde
Participant@yllu wrote:
365 err=readdir_r(current_dir,(struct dirent *)de,&pde);
Ooof. That’s it.
Should be fixed in next nightly.
— Ron
30th August 2007 at 6:29 am #12164yllu
ParticipantI tried to set PATH_MAX to 2048.
I also tried to modify line 334 in mp3-scanner.c to set
char de[sizeof(struct dirent) + MAXNAMLEN + 1]; to char de[sizeof(struct dirent) + MAXNAMLEN + 1024];.
However, the tests both failed.
And I can not figure out what’s wrong with line 365 in mp3-scanner.c.31st August 2007 at 3:07 am #12165rpedde
Participant@yllu wrote:
I tried to set PATH_MAX to 2048.
I also tried to modify line 334 in mp3-scanner.c to set
char de[sizeof(struct dirent) + MAXNAMLEN + 1]; to char de[sizeof(struct dirent) + MAXNAMLEN + 1024];.
However, the tests both failed.
And I can not figure out what’s wrong with line 365 in mp3-scanner.c.Looks to me like it should be:
err=readdir_r(current_dir,(struct dirent *)&de,&pde);
rather than
err=readdir_r(current_dir,(struct dirent *)de,&pde);
— Ron
31st August 2007 at 8:13 am #12166yllu
ParticipantUnfortunately, the test still failed after modifying line 365 in mp3-scanner.c.
3rd September 2007 at 12:53 pm #12167yllu
ParticipantDo you have any new ideas about the bug? 🙄
3rd September 2007 at 5:28 pm #12168rpedde
Participant@yllu wrote:
Do you have any new ideas about the bug? 🙄
The only thing I can think is stack limits… does this machine has small stack requirements? I’ve got some patches to reduce stack consumption, but I haven’t applied them yet.
4th September 2007 at 2:35 am #12169yllu
ParticipantLinux arm OS with 2.6.18 kernel.
And no other memory consumption process is running while mt-daapd is running.
It seems like not the stack issue. 😥 -
AuthorPosts
- The forum ‘Nightlies Feedback’ is closed to new topics and replies.