Hello Gilles,


Do you have any input on why does the write behave so terribly slow for Digikam, when writing data metadata into images ?


rrs@learner:~$ dstat
Terminal width too small, trimming output.
----total-cpu-usage---- -dsk/total- ------memory-usage----- -net/total- ----swap--->
usr sys idl wai hiq siq| read  writ| used  buff  cach  free| recv  send| used  free>
 17   2  62  18   0   0|3810k 2667k|2256M  172M 5412M 69.3M|   0     0 |1296M 7284M>
  4   2  15  79   0   0|7300k  372k|2258M  172M 5409M 70.3M| 293B 1456B|1295M 7285M>
  6   2   7  85   0   0|  13M  148k|2261M  172M 5420M 55.5M|  17k 3457B|1294M 7286M>
  6   2   7  84   0   0|  12M  348k|2260M  172M 5418M 59.0M|  22k   11k|1294M 7286M>
  4   2  27  68   0   0|  13M 2140k|2262M  172M 5423M 51.8M|5245B  810B|1294M 7286M>
 16   3   4  77   0   0|  14M 4896k|2263M  172M 5419M 55.0M|1919B 2041B|1294M 7286M>
 16   2  13  69   0   0|2916k 2040k|2263M  172M 5416M 57.5M|1266B 1396B|1293M 7287M>
  7   3  13  77   0   0|  18M  324k|2264M  172M 5415M 58.9M| 132B  172B|1293M 7287M>
  8   3  11  78   0   0|  15M  324k|2265M  172M 5417M 55.2M| 126B  172B|1293M 7287M>
 41   6   5  47   0   0|  17M 3096k|2310M  172M 5372M 54.6M|3236B 9116B|1293M 7287M>
 13   2   1  83   0   0|3268k   39M|2298M  172M 5363M 75.9M|5837B 4834B|1293M 7287M>
  6   3  11  80   0   0|  18M  592k|2304M  172M 5375M 58.3M|  66B  264B|1293M 7287M>
  6   2  18  74   0   0|  14M  212k|2305M  172M 5373M 58.3M|3428B 1204B|1293M 7287M>
  6   2  29  64   0   0|  12M  404k|2306M  172M 5378M 52.9M|2862B    0 |1293M 7287M>
  4   4  22  70   0   0|  22M  184k|2336M  172M 5347M 53.6M|   0     0 |1293M 7287M>
  2   1  44  53   0   0|  68k   50M|2307M  172M 5328M  102M| 264B  457B|1293M 7287M>
  6   2  16  77   0   0|  11M  540k|2305M  172M 5356M 76.4M|   0     0 |1293M 7287M>
  4   3  23  69   0   0|  25M  260k|2303M  172M 5377M 56.6M|   0     0 |1293M 7287M>
  6   2  20  72   0   0|  11M  400k|2308M  172M 5377M 52.3M|  66B  172B|1293M 7287M>
  2   2  27  69   0   0|  14M  296k|2308M  172M 5371M 58.1M| 132B   86B|1293M 7287M>
  4   5  13  78   0   0|2868k   57M|2344M  172M 5292M  100M|   0     0 |1293M 7287M>
  2   1  26  71   0   0|3108k   36M|2307M  172M 5292M  138M|1252B 1978B|1293M 7287M>
  8   2  31  59   0   0|  18M  460k|2302M  172M 5309M  126M|   0     0 |1293M 7287M>
  6   2  34  57   0   0|  25M  164k|2306M  172M 5337M 93.9M|   0     0 |1293M 7287M>
  6   2  29  64   0   0|  18M 1924k|2305M  172M 5358M 73.6M|   0   218B|1293M 7287M>
  4   5  30  61   0   0|3428k   56M|2327M  172M 5311M 98.5M| 738B  867B|1293M 7287M>
  5   2  23  71   0   0|7632k   20M|2279M  172M 5330M  128M|   0     0 |1292M 7288M>
  5   3  10  82   0   0|  12M  576k|2280M  172M 5339M  118M|2475B 3592B|1292M 7288M>
  8   4   4  85   0   0|  14M   60k|2279M  172M 5350M  108M|  19k   18k|1290M 7290M>
  6   3  11  81   0   0|  11M  452k|2283M  172M 5356M 97.9M|  12k   12k|1290M 7290M>
  3   3   1  93   0   0|2756k   56M|2284M  172M 5347M  105M|4690B 2536B|1289M 7291M>
  5   2  15  78   0   0|  17M  588k|2282M  172M 5367M 87.0M|   0     0 |1289M 7291M>
  8   2  15  76   0   0|  21M  512k|2282M  172M 5390M 64.9M|   0     0 |1289M 7291M>
  5   3   9  84   0   0|  21M  220k|2282M  172M 5394M 61.3M|1750B  284B|1289M 7291M>
  8   3  24  65   0   0|  20M  672k|2285M  172M 5393M 58.4M|2862B    0 |1289M 7291M>
  4   3  15  78   0   0|6312k   42M|2285M  172M 5363M 88.5M| 408B  218B|1289M 7291M>
  7   2  20  71   0   0|  20M  456k|2282M  172M 5392M 62.6M| 537B  817B|1289M 7291M>
  8   3  15  74   0   0|  24M  216k|2287M  172M 5395M 55.1M|  66B    0 |1289M 7291M>
  6   3  22  69   0   0|  19M  600k|2287M  172M 5395M 55.3M|   0   198B|1289M 7291M>
  8   3  21  69   0   0|  22M  600k|2284M  172M 5399M 53.7M|   0     0 |1289M 7291M>^C
2015-10-13 / 22:01:28 ♒♒♒  ☺    



From the looks of it, my guess is that you are doing too frequent fsync() calls. But that is just a gut feel. I have neither profiled, nor have I looked into the code yet.

But whatever the case, the pattern of your writes are terrible. Look at the CPU wait column. What is ending up here is that digikam writes are causing the entire CPU cycles blocked, thus leaving not much "free" cpu resources for other processes. Thus leading to an overall sluggish system when digikam is run and writing data.


PS: I have strong feeling that you are doing very frequent fsync() calls. But in my brief lookup, I couldn't gather that data. Neither ltrace or strace work on the digikam pid.

Reproducible: Always

Steps to Reproduce:
1. Run digikam
2. Tell digikam to write metada from db to individual files
3. watch the cpu block

Actual Results:  
CPU blocks. System CPU cycle starvation

Expected Results:  
Digikam is not that big a mammoth software that it should make a quad core Core i7 box with  8 GiB RAM to crawl.