Dead slow, CPUs running at 100%

[pgman]

I just started ASP 1.0.0.39 on Linux. I have a pretty fast computer: iCore7 (4 cores + hyperthreading) 8Gb RAM, boatload of disk space, no swapping on Ubuntu 10.04 Lucid.

The CPUs are all running at 98+% or 100%, pegged all the time. Why? Same system but with Bibble 5.2.3 the CPUs are running between 10% to 20% depending on the activity, and only the building of the previews does it goes higher.

Am I missing something or...

Any suggestion?

Thanks

[spoilerhead]

hm, i usually only know that from plugins going amok.
can you provide an AfterShotPro.log file? (from ~/.AfterShotPro/)

also, is ASP by chance rebuilding its Previews? (o doubt so, as you would see i in the left bottom corner)

[pgman]

Code: Select all

25020.146: System locale: en_CA
25020.150: Loaded  "/opt/AfterShotPro/supportfiles/locale/aftershot_en.qm" 
25020.185: AfterShot vers.: 1.0.0.39 
25020.185: Built on: "Tue Dec 27 2011" 
25020.185: Language: en 
25020.185: App Path: /opt/AfterShotPro/bin/AfterShotPro 
25020.185: System Home: ../supportfiles 
25020.185: User Home: /home/froggy/.AfterShotPro 
25020.185: Prefs Home: /home/froggy/.config/Corel/AfterShot Pro.conf 
25020.185: Platform:     Linux 
25020.185: Issue: "Ubuntu 10.04.4 LTS \n \l" 
25020.185: Kernel: "Linux version 2.6.32-38-generic (buildd@allspice) (gcc version 4.4.3 (Ubuntu 4.4.3-4ubuntu5) ) #83-Ubuntu SMP Wed Jan 4 11:12:07 UTC 2012" 
25020.185: Build Mode:   Release 
25020.185: Product Name: "AfterShot Pro" 
25020.185: Registered Version 
25020.186: Initializing 
25020.186: Cpu Manager init: 4
25020.186: "MemTotal:        8155208 kB" 
25020.187: Memory:  3 
25020.187: ====================================================
25020.187: Asset: 2147483647 purge
25020.187: ====================================================
25020.187: Heavy Asset: 2147483647 purge
25020.187: ====================================================
25020.187: NoiseEngine: 150 purge
25020.187: NoiseEngine: 75 cache (50 min)
25020.187: ====================================================
25020.187: Histogram: 24 purge
25020.187: Histogram: 12 cache (12 min)
25020.187: ====================================================
25020.187: PluginData: 9 purge
25020.187: PluginData: 9 cache (8 min)
25020.187: ====================================================
25020.187: ImageMaster: 600 purge
25020.187: ImageMaster: 300 cache (50 min)
25020.187: ====================================================
25020.187: NContainer: 2147483647 purge
25020.187: ====================================================
25020.187: Path: 2147483647 purge
25020.187: Path: 2147483647 cache (2147483647 min)
25020.187: ====================================================
25020.187: RawData: 25165821 purge
25020.187: ====================================================
25020.187: UncompressedRawData: 9 purge
25020.187: UncompressedRawData: 9 cache (8 min)
25020.188: ====================================================
25020.188: Version: 600 purge
25020.188: Version: 300 cache (50 min)
25020.188: ====================================================
25020.188: PerfectlyClear: 6 purge
25020.188: PerfectlyClear: 4 cache (4 min)
25020.188: ====================================================
25020.188: TileStack: 24 purge
25020.188: TileStack: 12 cache (12 min)
25020.188: ====================================================
25020.188: StackTile: 3000 purge
25020.194: ====================================================
25020.194: BImageTile: 1800 purge
25020.194: ====================================================
25020.194: BTiledImage: 2147483647 purge
25020.194: ====================================================
25020.194: RegionImageTile: 3000 purge
25020.194: ====================================================
25020.194: Allocate Asset manager
25020.195: Option group -  ""  - already contains an option with name -  "TIFFTAG_AFMODE" 
25020.195:   Option was not registered. 
25020.195: Option group -  ""  - already contains an option with name -  "TIFFTAG_FLASHMODE" 
25020.195:   Option was not registered. 
25020.195: Globals: systemhome ../supportfiles
25020.196: Globals: userhome /home/froggy/.AfterShotPro
25020.196: 
====================  Plugins  =====================
      Name: 
Identifier: 
   Version: 1.0.0
      Path: 


      Name: FatToni
Identifier: sph.FatToni
   Version: 0.32.0
      Path: <User Home>/Plugins/FatToni.afplugin


      Name: Silicon Bonk
Identifier: sph.SiliconBonk
   Version: 0.33.0
      Path: <User Home>/Plugins/Silicon Bonk.afplugin


      Name: zFrame
Identifier: tin.tin.zFrame
   Version: 3.1.2
      Path: <User Home>/Plugins/zFrame.afplugin


      Name: zPerspector
Identifier: tin.tin.zPerspector
   Version: 2.0.1
      Path: <User Home>/Plugins/zPerspector.afplugin


      Name: zText
Identifier: tin.tin.zText
   Version: 2.0.0
      Path: <User Home>/Plugins/zText.afplugin


      Name: Black and White
Identifier: com.corel.BlackAndWhite
   Version: 1.0.0
      Path: <System Home>/plugins/Black and White.afplugin


====================================================

25020.272: /home/froggy/.AfterShotPro/bibbledebug
25020.273: Creating main window 
25020.274: Starting Catalog Manager 
25020.274: New Io Asset Mananager
25020.275:   DB 0 at version 20 
25020.275: Locking catalog:  "/home/froggy/.AfterShotPro/cache" 
25020.275: Locking for station:  "{e83432a7-f95b-9b4b-b4ba-7bf522c72579}" 
25020.275: Opening DB "/home/froggy/.AfterShotPro/cache" 
25020.276:   DB 1 is already up to date 
25020.277: Scheduled Cache Cleaning 
25020.290: CacheReducer removed 0 versions due to age older than QDateTime("Mon Feb 6 06:57:00 2012") 
25020.290:   Starting cache cleanup 
25020.291:   purging history for 2 versions 
25020.352:   Finished cache cleanup 
25020.352: Locking catalog:  "/home/froggy/Pictures/AfterShot Pro Catalogs/AfterShot Pro Catalog 2012" 
25020.352: Locking for station:  "{e83432a7-f95b-9b4b-b4ba-7bf522c72579}" 
25020.352: Opening DB "/home/froggy/Pictures/AfterShot Pro Catalogs/AfterShot Pro Catalog 2012" 
25020.353:   DB 2 is already up to date 
25020.406: Starting Asset Manager 
25020.406: Starting Memory Manager 
25020.600: Trying to set queue hotkey  "T"  for queue  "16-bit TIFF" 
25020.600: Trying to set queue hotkey  "8"  for queue  "8-bit TIFF" 
25020.600: Trying to set queue hotkey  "D"  for queue  "Download" 
25020.600: Trying to set queue hotkey  "F"  for queue  "JPEG Full Size" 
25020.600: Trying to set queue hotkey  "J"  for queue  "JPEG Proof" 
25020.917: Trying to set copyset shortcut  "Ctrl+8"  for  "Color Correction" 
25020.917: Trying to set copyset shortcut  "Ctrl+9"  for  "Exposure" 
25020.917: Trying to set copyset shortcut  "Ctrl+3"  for  "GPS Settings" 
25020.917: Trying to set copyset shortcut  "Ctrl+4"  for  "IPTC Photographer's Details" 
25020.917: Trying to set copyset shortcut  "Ctrl+1"  for  "Metadata and IPTC" 
25020.918: Trying to set copyset shortcut  "Ctrl+2"  for  "Metadata, IPTC, and GPS" 
25020.918: Registering AfterShot plugin...  "BibbleBuiltin" 
25020.918: Registering AfterShot plugin...  "BlackAndWhite" 
25020.918: Registering AfterShot plugin...  "zPerspector" 
25020.918: zPerspectorFilter   loaded. group_id  5 
25020.918: zGridFilter         loaded. group_id  5 
25020.918: Registering AfterShot plugin...  "zFrame" 
25020.918: Registering AfterShot plugin...  "SiliconBonk" 
25020.919: Successfully registered  "SiliconBonkFilter"  filter after Curves 
25020.919: Registering AfterShot plugin...  "zText" 
25020.919: Registering AfterShot plugin...  "FatToni" 
25020.919: Successfully registered  "FatToniFilter"  filter after SiliconBonk 
25020.919: 0 :  "UncompressedRawData" 
25020.919: 1 :  "RawNoise" 
25020.919: 2 :  "Demosaic" 
25020.919: 3 :  "TiffSrc" 
25020.919: 4 :  "JpegSrc" 
25020.919: 5 :  "Mip" 
25020.919: 6 :  "PreScalingFilter" 
25020.919: 7 :  "CameraRgbToWorkingspace_Rendered" 
25020.919: 8 :  "CloneLayer" 
25020.919: 9 :  "HealRendererFilter" 
25020.919: 10 :  "NoiseNinja" 
25020.919: 11 :  "SpatialDistortion" 
25020.919: 12 :  "zPerspectorFilter" 
25020.919: 13 :  "Positive Vignette" 
25020.919: 14 :  "Mirror" 
25020.919: 15 :  "Crop" 
25020.919: 16 :  "WhiteBalance" 
25020.919: 17 :  "AutoLevel" 
25020.919: 18 :  "Exposure" 
25020.919: 19 :  "FillLight" 
25020.919: 20 :  "CameraRgbToWorkingspace_Raw" 
25020.919: 21 :  "Sharpen" 
25020.920: 22 :  "Invert" 
25020.920: 23 :  "PerfectlyClear" 
25020.920: 24 :  "Color" 
25020.920: 25 :  "SelectiveColor" 
25020.920: 26 :  "RgbToLab" 
25020.920: 27 :  "LabToRgb" 
25020.920: 28 :  "BlackAndWhiteFilter" 
25020.920: 29 :  "Curves" 
25020.920: 30 :  "SiliconBonkFilter" 
25020.920: 31 :  "FatToniFilter" 
25020.920: 32 :  "zGridFilter" 
25020.920: 33 :  "Negative Vignette" 
25020.920: 34 :  "zFrameFilter" 
25020.920: 35 :  "zTextFilter" 
25020.920: 0 :  "VersionStackSrc" 
25020.920: 1 :  "PostImage" 
25020.920: 0 :  "JpegSrc" 
25020.920: 1 :  "Mip" 
25021.543: FIXME: SettingsForm::SettingsForm 
25021.634: FIXME: SettingsForm::SettingsForm 
25021.707: FIXME: SettingsForm::SettingsForm 
25021.823: FIXME: SettingsForm::SettingsForm 
25021.882: FIXME: SettingsForm::SettingsForm 
25021.930: FIXME: SettingsForm::SettingsForm 
25022.647: Ready 
25022.791: Initializing file system view... 
25022.792: File: s: 29
25022.794: File system view initialized. 
25022.794: Container __CATALOG_ROOT__/assets
25022.838: File does not exist or could not be opened:  "/home/froggy/.AfterShotPro/slideshow.xmp" 
25022.838: No custom slideshow settings found 
25023.503: MultiImageView::doCursor() Invalid cursor mode 
25023.505: File: s: 3
25023.506: File: s: 53
25023.509: File: s: 11
25023.511: File: s: 7
25023.512: File: s: 4
25023.512: File: s: 5
25023.514: File: s: 62
25023.523: File: s: 86
25023.530: ContainerAsset could not get path by ID
25023.532: Container __CATALOG_ROOT__/assets
25023.534: Container __CATALOG_ROOT__/assets/home
25023.536: Container __CATALOG_ROOT__/assets/home/froggy
25023.539: Container __CATALOG_ROOT__/assets/home/froggy/library
25023.541: Container __CATALOG_ROOT__/assets/home/froggy/library/places
25023.544: Container __CATALOG_ROOT__/assets/home/froggy/library/places/canada
25023.547: Container __CATALOG_ROOT__/assets/home/froggy/library/places/canada/bc
25023.550: Container __CATALOG_ROOT__/assets/home/froggy/library/places/canada/bc/reifel
25023.551: set sort order ascending 
25023.552: Container __CATALOG_ROOT__/assets/home/froggy/library/places/canada/bc/reifel/reifel-20120204
25023.555: Opening DB "/home/froggy/.AfterShotPro/cache" 
25023.567: viewmode: 1
25023.729: Starting import with settings :  "<x:xmpmeta xmlns:x="adobe:ns:meta/" x:xmptk="XMP Core 4.4.0">
 <rdf:RDF xmlns:rdf="http://www.w3.org/1999/02/22-rdf-syntax-ns#">
  <rdf:Description rdf:about=""
    xmlns:bibp="http://www.bibblelabs.com/BibblePrivate/5.0/"
   bibp:MoveCopy="2"
   bibp:LibraryLoc=""
   bibp:LibraryID="1050"
   bibp:LibraryUuid="{1ebf7c6c-1696-1d4a-a427-bd608183b20c}"
   bibp:Organize="0"
   bibp:FolderTemplate=""
   bibp:Recurse="false"
   bibp:RenameOn="false"
   bibp:FileTemplate=""
   bibp:ImportPath="/home/froggy/library/places/canada/bc/reifel/reifel-20120204"
   bibp:KeywordList=""
   bibp:FolderFilter=""
   bibp:QueueName=""
   bibp:QueueType="0"
   bibp:QueueOnlyNewFiles="false"
   bibp:JobName=""
   bibp:PresetList=""/>
 </rdf:RDF>
</x:xmpmeta>
" 
25023.729: Adding master versions 
25023.745: Adding master versions 
25023.746: Scanning file  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2547.cr2" 
25023.756: Scanning file  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2548.cr2" 
25023.757: Scanning file  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2549.cr2" 
25023.758: Scanning file  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2550.cr2" 
25023.758: Scanning file  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2551.cr2" 
25023.759: Scanning file  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2552.cr2" 
25023.760: Scanning file  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2553.cr2" 
25023.761: Scanning file  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2555.cr2" 
25023.761: Scanning file  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2556.cr2" 
25023.762: Scanning file  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2557.cr2" 
25023.767: Adding master versions 
25023.767: Scanning file  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2558.cr2" 
25023.775: Scanning file  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2560.cr2" 
25023.776: Scanning file  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2561.cr2" 
25023.776: Scanning file  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2562.cr2" 
25023.777: Scanning file  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2563.cr2" 
25023.778: Scanning file  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2564.cr2" 
25023.778: Scanning file  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2565.cr2" 
25023.779: Scanning file  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2566.cr2" 
25023.780: Scanning file  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2567.cr2" 
25023.781: Scanning file  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2568.cr2" 
25023.840: Adding master versions 
25023.840: Scanning file  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2569.cr2" 
25023.848: Scanning file  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2570.cr2" 
25023.848: Scanning file  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2571.cr2" 
25023.849: Scanning file  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2572.cr2" 
25023.850: Scanning file  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2573.cr2" 
25023.851: Scanning file  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2591.cr2" 
25023.851: Scanning file  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2592.cr2" 
25023.852: Scanning file  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2593.cr2" 
25024.646: Extracting RAW data:  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2591.cr2" 
25024.742: Decoding RAW data:  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2591.cr2" 
25028.476: "/usr/local/sbin" 
25028.476: "/usr/local/bin" 
25028.476: "/usr/sbin" 
25028.476: "/usr/bin" 
25028.476: "/sbin" 
25028.476: "/bin" 
25028.476: "/usr/games" 
25028.477: "/usr/local/sbin" 
25028.477: "/usr/local/bin" 
25028.477: "/usr/sbin" 
25028.477: "/usr/bin" 
25028.477: "/sbin" 
25028.477: "/bin" 
25028.477: "/usr/games" 
25028.477: "/usr/local/sbin" 
25028.477: "/usr/local/bin" 
25028.477: "/usr/sbin" 
25028.477: "/usr/bin" 
25028.477: "/sbin" 
25028.477: "/bin" 
25028.477: "/usr/games" 
25050.750: Trying to set copyset shortcut  "Ctrl+8"  for  "Color Correction" 
25050.751: Trying to set copyset shortcut  "Ctrl+9"  for  "Exposure" 
25050.751: Trying to set copyset shortcut  "Ctrl+3"  for  "GPS Settings" 
25050.751: Trying to set copyset shortcut  "Ctrl+4"  for  "IPTC Photographer's Details" 
25050.751: Trying to set copyset shortcut  "Ctrl+1"  for  "Metadata and IPTC" 
25050.752: Trying to set copyset shortcut  "Ctrl+2"  for  "Metadata, IPTC, and GPS" 
25052.481: Trying to set copyset shortcut  "Ctrl+8"  for  "Color Correction" 
25052.482: Trying to set copyset shortcut  "Ctrl+9"  for  "Exposure" 
25052.482: Trying to set copyset shortcut  "Ctrl+3"  for  "GPS Settings" 
25052.482: Trying to set copyset shortcut  "Ctrl+4"  for  "IPTC Photographer's Details" 
25052.482: Trying to set copyset shortcut  "Ctrl+1"  for  "Metadata and IPTC" 
25052.483: Trying to set copyset shortcut  "Ctrl+2"  for  "Metadata, IPTC, and GPS" 
25067.215: Extracting RAW data:  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2592.cr2" 
25067.276: Decoding RAW data:  "/home/froggy/library/places/canada/bc/reifel/reifel-20120204/reifel-20120204-2592.cr2" 
25199.219: Unlocking catalog:  "/home/froggy/.AfterShotPro/cache" 
25199.219: Unlocking catalog:  "/home/froggy/Pictures/AfterShot Pro Catalogs/AfterShot Pro Catalog 2012" 
25199.469: Early Cleanup
25199.469: delete globals
25199.469: delete globals
25199.469: delete mid globals
25199.470: delete done globals

[madsec]

I have the same problem with the high cpu usage, but it's not happening always. I can reproduce the situation though. Running a Linux Fedora 16 64bit with the same version of ASP and nearly all available plugins installed.

In normal operation everything works fine. When I start going through my pictures very fast in combined view, ASP rebuilds the previews for the pictures, I can see that also by the messages in terminal (start ASP in terminal with just the command AfterShotPro). Everything fine till now. When I go very fast trough the images, and backwards also, the building preview operation starts a loop and some of the previews are rebuild permanently. This causes in my case the high cpu usage, after a restart everything is fine again. Also moving slowly through the images works fine.

I was about to report a bug after some playing around yesterday evening. Now I would like to hear some other experiences first.

[spoilerhead]

The usual debug steps would be to move away ~/.AfterShotPro/Plugins and see if it still happens (i.e. without the plugins). If its fixed by that, bring back the plugins one by one to isolate the faulty one, if its not fixed, then it's a problem in the core application. strace come in really helpful in that case.

[elslunko]

It's likely zframe :

http://support.bibblelabs.com/forums/vi ... 98&t=19799

[madsec]

Yes, you are right, it's zFrame! Removed the zFrame-plugin from the ~/.AfterShotPro/Plugins folder and now the error is gone. Thanks very much for the tip!

[tintin]

yeah, that bug of zFrame is known... and the update is already on the way... may take some really few days yet, before launching it...
sorry for the circumstances!

br,
tintin

[madsec]

Kein Ding! Danke für die tolle Arbeit!

Grüße,
madsec

[kaymann]

The bugs is alive in Win 7 as well...

[madsec]

tintin has updated his plugin zFrame: http://forum.corel.com/EN/viewtopic.php ... 31#p240631

Works fine now, no CPU issue anymore in my case!

[-cr]

zFrame_3.1.3_WML.afzplug installed, and still suffering from the problem described.
If catalogues weren't incompatible, and with all my 2012 shots in ASP, I'd go back to Bibble5 until this is fixed.
:-/

Btw: I'm running ASP 1.0.0.39 w/ all (afaik) current plugins installed, on Ubuntu 11.10.

[madsec]

Have you installed the new "Nuance" plugin? Have experienced the problem with this plugin installed, but didn't test it well enough to be sure yet.

You can try to start ASP without plugins by renameing the plugin directory in the ASP location on your hard-drive. If the problem remains, than you can be sure that the problem comes from ASP itself.

[Dutchmm]

zFrame_3.1.3_WML.afzplug installed, and still suffering from the problem described.
If catalogues weren't incompatible, and with all my 2012 shots in ASP, I'd go back to Bibble5 until this is fixed.
:-/

Btw: I'm running ASP 1.0.0.39 w/ all (afaik) current plugins installed, on Ubuntu 11.10.

I am running the same version of ASP, with (as you say: AFAIK) all the known plugins, on Linux Mint 12 - which is an offshoot of Ubuntu 11.10 - and am not seeing any of the slowdown you describe. This on the 32 bit version. Are you by any chance on 64 bit? There must be some difference...

[-cr]

[...] This on the 32 bit version. Are you by any chance on 64 bit? There must be some difference...

Nope, I'm using a 32 bit OS as well (as it says in my profile).