f-spot crashes during import and some seconds after restarting f-spot

[coCoKNIght]

Binary package hint: f-spot

Jaunty
f-spot 0.5.0.3
I wanted to import my photos folder (3GB) from my backup but during the process f-spot crashed.
After that when I reopen f-spot it crashes again after a few seconds.
Then I've renamed my photos.db to photos.db.bak -> f-spot starts without any fotos. I then tryed to import all the fotos that were already copied to the Pictures folder but the same crash occurred.

I also noticed that some photos were imported multiple times in different folders. Typically a photo that was taken on say 2008/11/23 would appear in the folder 2008/11/23/ and 2008/11/24/.

F-spot also created some files with the name of a photo but with very strange extensions. Unfortunatly I've not kept a record of that...

I now have all my photos imported and all is fine but I copied them into the Pictures folder manually and imported folder by folder without the "copy to Pictures folder" option. When I was reaching 1000 photos in f-spot, it got really slow and I even had to restart the computer once because nothing was responding anymore. I tryed to login from tty1 but it would take too long for the password input dialogue to appear.
After reboot f-spot was not slow anymore, which was kind of unexpected.

[coCoKNIght (cocoknight)]

This is the output of f-spot with the --debug option after reopening f-spot after the import crash:

-------------------
f-spot --debug
** Running f-spot in Debug Mode **
** Running Mono with --debug **
[Info 12:47:33.901] Initializing DBus
[Debug 12:47:34.630] DBusInitialization took 0.675659s
[Info 12:47:34.631] Initializing Mono.Addins
[Debug 12:47:36.819] Mono.Addins Initialization took 2.187834s
[Info 12:47:36.862] Starting new FSpot server
[Debug 12:47:42.172] Db Initialization took 1.131251s
[Debug 12:47:46.159] QueryToTemp took 0.234586s : SELECT id, time, uri, description, roll_id, default_version_id, rating, md5_sum FROM photos WHERE id NOT IN (SELECT photo_id FROM photo_tags WHERE tag_id = 2) ORDER BY time DESC
[Debug 12:47:46.585] PhotosPerMonth took 0.128551s
[Debug 12:47:46.629] TimeAdaptor REAL Reload took 0.377137s
[Debug 12:47:47.144] Query took 0.104016s : SELECT * FROM photoquery_temp_0 LIMIT 100 OFFSET 0
get fences failed: -1
param: 6, val: 0
[Info 12:47:49.017] Starting BeagleService
[Debug 12:47:49.038] BeagleService startup took 7.6E-05s
[Info 12:47:49.038] Hack for gnome-settings-daemon engaged
Syncing metadata to file...
[Debug 12:47:49.581] open uri = file:///home/cocoknight/Pictures/2006/01/26/19-09-05_0323.jpg
[Debug 12:47:49.761] IndexOf took 0.016586s : SELECT ROWID FROM photoquery_temp_0 WHERE time <= 1262320199 ORDER BY time DESC LIMIT 1
[Debug 12:47:49.769] IndexOf took 0.005641s : SELECT ROWID FROM photoquery_temp_0 WHERE id = 104
old = "" new = "" heading = "ASCII"
value = 2006:01:26 14:24:38 len = 19
value = f-spot version 0.5.0.3 len = 22
value = 2009:05:14 12:47:50 len = 19
value = f-spot version 0.5.0.3 len = 22
value = 2009:05:14 12:47:50 len = 19
Saved 1669 bytes
Syncing metadata to file...
[Debug 12:47:51.135] open uri = file:///home/cocoknight/Pictures/2000/09/02/b2mech003.jpg
old = "" new = "" heading = "ASCII"
value = 2000:09:02 18:35:34 len = 19
_:bnode-1745358336 <http://ns.adobe.com/photoshop/1.0/Urgency> "10" .
<http://fakebase.f-spot.org/internal/> <http://ns.adobe.com/xap/1.0/Rating> "4" .
value = f-spot version 0.5.0.3 len = 22
value = 2009:05:14 12:47:51 len = 19
value = f-spot version 0.5.0.3 len = 22
value = 2009:05:14 12:47:51 len = 19

(f-spot:12077): GdkPixbuf-WARNING **: GdkPixbufLoader finalized without calling gdk_pixbuf_loader_close() - this is not allowed. You must explicitly end the data stream to the loader before dropping the last reference.
Stacktrace:

  at (wrapper managed-to-native) Exif.ExifData.exif_data_save_data (System.Runtime.InteropServices.HandleRef,intptr&,uint&) <0x00004>
  at (wrapper managed-to-native) Exif.ExifData.exif_data_save_data (System.Runtime.InteropServices.HandleRef,intptr&,uint&) <0xffffffff>
  at Exif.ExifData.Save () <0x0006c>
  at JpegHeader.SetExif (Exif.ExifData) <0x00014>
  at FSpot.JpegFile.SaveMetaData (System.IO.Stream,System.IO.Stream) <0x0004e>
  at FSpot.JpegFile.SaveMetaData (string) <0x00095>
  at FSpot.Jobs.SyncMetadataJob.WriteMetadataToImage (FSpot.Photo) <0x001d5>
  at FSpot.Jobs.SyncMetadataJob.Execute () <0x0008b>
  at Job.Run () <0x0001a>
  at Banshee.Kernel.Scheduler.ProcessJobThread () <0x0015d>
  at (wrapper runtime-invoke) Sy...

[coCoKNIght (cocoknight)]

And when I rename the photos.db file to photos.db.bak and start f-spot with the --debug option and start to import the files in Pictures, this is the end of the output:

------------------
[Debug 13:09:56.146] open uri = file:///home/cocoknight/Pictures/2001/11/15/Esmebigeyesspotligtside.JPG
Stacktrace:

  at (wrapper managed-to-native) Exif.ExifData.exif_data_save_data (System.Runtime.InteropServices.HandleRef,intptr&,uint&) <0x00004>
  at (wrapper managed-to-native) Exif.ExifData.exif_data_save_data (System.Runtime.InteropServices.HandleRef,intptr&,uint&) <0xffffffff>
  at Exif.ExifData.Save () <0x0006c>
  at JpegHeader.SetExif (Exif.ExifData) <0x00014>
  at FSpot.JpegFile.SaveMetaData (System.IO.Stream,System.IO.Stream) <0x0004e>
  at FSpot.JpegFile.SaveMetaData (string) <0x00095>
  at FSpot.Jobs.SyncMetadataJob.WriteMetadataToImage (FSpot.Photo) <0x001d5>
  at FSpot.Jobs.SyncMetadataJob.Execute () <0x0008b>
  at Job.Run () <0x0001a>
  at Banshee.Kernel.Scheduler.ProcessJobThread () <0x0015d>
  at (wrapper runtime-invoke) System.Object.runtime_invoke_void__this__ (object,intptr,intptr,intptr) <0xffffffff>

Native stacktrace:

 f-spot [0x806d944]
 f-spot [0x808616b]
 [0xb7fa3410]
 /usr/lib/libexif.so.12(exif_set_short+0x2c) [0xb4c3331c]
 /usr/lib/libexif.so.12 [0xb4c2a4a3]
 /usr/lib/libexif.so.12 [0xb4c2a66e]
 /usr/lib/libexif.so.12(exif_data_save_data+0x108) [0xb4c2ad28]
 [0xb19054fa]
 [0xb190545d]
 [0xb1905395]
 [0xb19052d7]
 [0xb1904a56]
 [0xb3b189f6]
 [0xb3c4b264]
 [0xb3c4b183]
 [0xb3c4ad66]
 [0xb5d1ed61]
 f-spot(mono_runtime_delegate_invoke+0x34) [0x80b8974]
 f-spot [0x80f76bf]
 f-spot [0x81653b6]
 f-spot [0x81833b5]
 /lib/tls/i686/cmov/libpthread.so.0 [0xb7eaf4ff]
 /lib/tls/i686/cmov/libc.so.6(clone+0x5e) [0xb7e0449e]

Debug info from gdb:

=================================================================
Got a SIGSEGV while executing native code. This usually indicates
a fatal error in the mono runtime or one of the native libraries
used by your application.
=================================================================

Aborted

[Pedro Villavicencio (pedro)]

loks like an exif related one, could you attach the file located at: file:///home/cocoknight/Pictures/2001/11/15/Esmebigeyesspotligtside.JPG ? Thanks.

[coCoKNIght (cocoknight)]

Since I managed to import Esmebigeyesspotligtside.JPG alright I looked for a more representating debug output and photo-file:
Ok, this is a more representative debug output. The import folder has only 13 pictures and f-spot seems to have a problem with file:///home/cocoknight/Pictures/Fotos/textures/steinplatten.JPG which I have attached to this reply.

f-spot --debug
** Running f-spot in Debug Mode **
** Running Mono with --debug **
[Info 11:50:57.739] Initializing DBus
[Debug 11:50:58.327] DBusInitialization took 0.536944s
[Info 11:50:58.327] Initializing Mono.Addins
[Debug 11:51:00.352] Mono.Addins Initialization took 2.024338s
[Info 11:51:00.376] Starting new FSpot server
[Debug 11:51:02.287] Db Initialization took 1.195157s
[Debug 11:51:04.731] QueryToTemp took 0.01964s : SELECT id, time, uri, description, roll_id, default_version_id, rating, md5_sum FROM photos WHERE id NOT IN (SELECT photo_id FROM photo_tags WHERE tag_id = 2) ORDER BY time DESC
[Debug 11:51:05.043] PhotosPerMonth took 0.001626s
[Debug 11:51:05.055] TimeAdaptor REAL Reload took 0.221701s
get fences failed: -1
param: 6, val: 0
item ImportCommand+SourceItem
[Debug 11:51:35.969] Scanning /home/cocoknight/Pictures/Fotos/textures for new photos
[Debug 11:51:35.998] Query Uri file:///home/cocoknight/Pictures/Fotos/textures
[Debug 11:51:36.016] Query took 0.004747s : SELECT id, time, uri, description, roll_id, default_version_id, rating, md5_sum FROM photos WHERE uri LIKE :uri AND uri NOT LIKE :uri_
[Debug 11:51:36.367] GetByUri query took 0.001034s
[Debug 11:51:36.376] open uri = file:///home/cocoknight/Pictures/Fotos/textures/06.tif
[Debug 11:51:36.485] open uri = file:///home/cocoknight/Pictures/Fotos/textures/06.tif
[Debug 11:51:36.922] open uri = file:///home/cocoknight/Pictures/Fotos/textures/06.tif
cleanup context
cleanup context
[Debug 11:51:37.168] open uri = file:///home/cocoknight/Pictures/Fotos/textures/06.tif
[Debug 11:51:37.169] open uri = file:///home/cocoknight/Pictures/Fotos/textures/06.tif
[Debug 11:51:37.261] open uri = file:///home/cocoknight/Pictures/Fotos/textures/06.tif
[Debug 11:51:37.785] IndicesOf took 0.159537s : SELECT ROWID FROM photoquery_temp_0 WHERE id IN (1)
[Debug 11:51:37.788] IndicesOf took 0.165609s
[Debug 11:51:37.980] Commit took 0.378326s
[Debug 11:51:37.990] open uri = file:///home/cocoknight/Pictures/Fotos/textures/06.tif
[Debug 11:51:38.010] open uri = file:///home/cocoknight/Pictures/Fotos/textures/06.tif

(f-spot:13630): GdkPixbuf-WARNING **: GdkPixbufLoader finalized without calling gdk_pixbuf_loader_close() - this is not allowed. You must explicitly end the data stream to the loader before dropping the last reference.
[Debug 11:51:38.124] GetByUri query took 0.000957s
[Debug 11:51:38.126] open uri = file:///home/cocoknight/Pictures/Fotos/textures/KaLt.JPG
[Debug 11:51:38.129] open uri = file:///home/cocoknight/Pictures/Fotos/textures/KaLt.JPG
[Debug 11:51:38.402] open uri = file:///home/cocoknight/Pictures/Fotos/textures/KaLt.JPG
Syncing metadata to file...
[Debug 11:51:38.500] open uri = file:///home/cocoknight/Pictures/Fotos/textures/06.tif
[Debug 11:51:38.681] open uri = file:///home/cocoknight/Pictures/Fotos/textures/Ka...

[Pedro Villavicencio (pedro)]

thanks trace matches bug 279440