G2 -> G3 Import hangs at start
|
alecmyers
Joined: 2006-08-01
Posts: 4342 |
Posted: Wed, 2009-05-06 10:58
|
|
Just checking out G3, and the import-from-G2 module. G2 installation is recognised but the importer hangs with the progress bar on zero. I can use the pause button to return to the Tasks page; if I resume the task I get the stalled progress bar again. This is for both of two different G2 installations, here's the system info from the smaller of the two: Gallery version = 2.3 core 1.3.0 The g3 log entries refer to the task as "stalled", and that's the status given in the Maintenance page (after using the pause button) - I don't know if it should rightly show as anything else, as I've not seen the task working correctly yet. I'm not sure in G3 where to start looking, so any clues appreciated. |
|
Posts: 1153
yep, i got the same problem.
in /var/log/
2009-05-06 19:59:38 -04:00 --- error: Uncaught Exception: @todo G2_FUNCTION_FAILED in file modules/g2_import/helpers/g2_import.php on line 24
not sure if that was the output before or after I pressed "cancel" while attempting to import.
my G2.3 multisite info.
Gallery version = 2.3 core 1.3.0
API = Core 7.54, Module 3.9, Theme 2.6, Embed 1.5
PHP version = 5.2.9 apache2handler
Webserver = Apache/2.2.11 (FreeBSD)
Database = mysqlt 5.0.77, lock.system=flock
Toolkits = Ffmpeg, ImageMagick, LinkItemToolkit, Thumbnail, SquareThumb, ArchiveUpload, Exif
Acceleration = none/1814400, none/1814400
Operating system = FreeBSD 7.0-STABLE
Default theme = siriux
gettext = enabled
Locale = en_US
Browser = Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10.4; en-US; rv:1.9.0.10) Gecko/2009042315 Firefox/3.0.10
Rows in GalleryAccessMap table = 9
Rows in GalleryAccessSubscriberMap table = 998
Rows in GalleryUser table = 2
Rows in GalleryItem table = 996
Rows in GalleryAlbumItem table = 44
Rows in GalleryCacheMap table = 0
___________________________________________________
http://pixi.me/
Posts: 7994
Thanks for the feedback. This type of issue is to be expected at first while we iron out the kinks in the import system. The first thing we need to do is to figure out what the actual G2 operation was that failed and start from there.
I've just checked a change into svn to add some log messages on G2 function call failures. Can you svn up to 20688 and try again and when it fails report back with the error info? Thanks!
Posts: 4342
Hi Bharat,
I'm now at 20688. This is the content of the 2009-05-07.log.php file relevant to an attempt to import:
At that time the comments module was not installed. I installed that module and presto-hey, the import is now working. I'll try the other gallery (10's of thousands of images tomorrow probably.)
Hope that's useful...
EDIT: cool, the import worked, no other issues. It was a bit slow though - about three photos per second, for a total of 5 or 6 minutes on a 1000-image G2 installation, and that's on dedicated hardware. Importing 50-100k images is going to take a while.
Posts: 4342
I've just seen the comments in this post (http://gallery.menalto.com/node/87609#comment-307289) about the speed of importing. On the same hardware G2 copies imports and builds 1000 images with resizes in about 35-40 seconds (or less - I confess I've never timed it precisely, but it's pretty zippy) so hopefully even allowing the G2 import process to rebuild thumbnails and resizes from scratch there's still some room for optimisation. (Clearly understood that this is still alpha software, so not making any judgements!)
Posts: 7994
Theoretically the speed here between G2 and G3 should be comparable. Most of the time should be spent in the graphics conversion tool and that's the same between G2 and G3. It's possible however that it's the G3 task framework that's slowing things down. The task framework allows us to run very long operations in a way that does not overly stress the apache server, won't run up against time limits and can be suspended and resumed. The downside is that it requires frequent requests from the client to keep the operation going and those may be overly expensive. One thing you could try is to let each task request run longer. Right now each one runs for 1 second so that we have granular user feedback. Set that to 10 seconds and see what you get (g2_import_task.php line 62)
<time passes>
Ok, I ran a profiling run on this and found out that 65% of the time on a 10 second run is spent in the exif module. Wow! When I disable the EXIF module then 53% of the time is spent running the graphics toolkits and 20% of the time is in Kohana ORM overhead. Can you guys try disabling exif temporarily and see how your import goes? You can always re-enable exif and sync it back up again.
Posts: 4342
I just checked, and exif wasn't enabled on G3 at the time. With exif enabled, I don't actually see a difference in the import speed - which is odd. EDIT: actually that could be because none of the images have any EXIF data.
Changing the tickle time on the task to 10 seconds didn't make any difference either - 30, 61, 90 images at 10, 20, 30 seconds. How does G3 select an image toolkit?
EDIT (again) - G3 was on the default GD toolkit (yes, I found the settings now...) - but switching to imageMagick didn't improve things either (30,62,91 at 10,20,30 seconds). Which is distinctly odd!
Posts: 7994
@alecmyers hm. I wonder where the time is going in your case. Can you try installing xdebug and running webgrind? (http://code.google.com/p/webgrind/) To test just one task run I put this code in core/controllers/scaffold.php
function test() { $task = task::run(2); printf("<pre>%s</pre>",print_r($task->status,1));flush(); $this->auto_render = false; }Start up a task, let it run to the photos section then pause it and replace "2" in the example above with the real task id, which you can find by viewing the source or hovering over the resume or cancel links. Then browse to gallery3/index.php/scaffold/test to kick it off.
Posts: 4342
I'm having difficulty in getting xdebug to load at the moment - if I can't get it to work tonight, I'll try again tomorrow.
OK - xdebug installed and loaded, webgrind installed. I get your instructions about the function test(), and I've updated it with the task id, and resumed the task. I've visited the gallery3/index.php/scaffold/test to "kick things off" - what then am I looking for in webgrind - I just get a bare-ish page, with 'Select a cachegrind file above' - and no obvious files listed. Could you be a bit more explicit in the instructions at that point?
Posts: 4342
More progress... a bit of experimentation and I've got xdebug producing cachegrind files now. Do I have to go back to the maintenance page to finish the import? The scaffold/test halts after (now) 10 seconds with "Importing photos 37 / 1095" - is that all I need?
Posts: 7994
So for me after 10 seconds of importing photos I have an about 150MB file containing performance info which I can view in webgrind. You don't need to finish the import to start analyzing that data. Show 100% of calls and sort by self cost, then you can track back any expensive operation to its callers. For example in my 10 second riun, the 2nd most time spent is in 305 calls to php::mysqli->multi_query which, when I track it back through the Kohana code leads to ORM::save which makes
* 55 calls to Databsae::insert
* 26 calls to Database::update
* 22 calls to ORM_MPTT::add_to_parent
* 179 calls to Database::get
* 11 each calls to ORM_MPTT::lock and unlock
Backtracking to code that calls ORM::save I see:
* 11 calls from access::add_item
* 35 calls from item::save
* 11 calls from g2_import::set_map
* 11 calls from access::add_item
* 1 call to task::save
* 11 calls to search_event::item_created
This is all fairly reasonable considering that we're expecting to be adding a lot of database rows during an import process.
Another way to look at it is that we spend 53.19% of our time in php::exec calling ImageMagick, 18.39% of our time in php::mysqli->multi_query calling out to mysql, 5.87% of our time calling php::copy. We're not doing anything particularly excessive there so that's 77.45% of our time doing stuff that we are expecting to have to do. Throw in another 3.18% for calling getimagesize() and we're spending 80% of our time doing regular stuff.
Are you seeing the same results?
I'm going to try an approach where if the g2 image has the same dimensions as the expected g3 image (resize, thumbnail, etc) I'm going to try coping it over instead of regenerating it. That might let us eat into the 50% of time that we spend running ImageMagick.
Posts: 7994
Ok, in r20707 I committed a change to copy over G2 derivatives when they match the G3 thumb/resize dimension. This cuts the graphics toolkit out in many cases and makes things go 2-3x faster for me. Let me know what you think.
Posts: 4342
OK - in the old version I get 68% in exec calls to ImageMagick, and 10% in calls to php::mysqli->multi_query.
aside: "Sigh.. fix it the *right* way." - ROFL
updating (again)...
Importing 35/70/105 pictures at 10/20/30 seconds, so not much change. I guess I should reprofile, see what's happening.
Posts: 4342
@bharat: btw, looks like you still have an (undocumented) dependency on the g2 comments module - latest svn code bombs out with this on an upgrade attempt, unless comments installed in g2:
modules/g2_import/helpers/g2_import.php [100]: g2( Array ( [0] => GalleryStatus Object ( [_stack] => [_errorCode] => 17 [_errorMessage] => Unknown permission id: comment.view [_stackTrace] => Array ( [0] => Array . . .Do you want me to file a ticket?
Posts: 7994
Doh, of course. I hadn't tested it on a G2 with the comments module uninstalled. I've filed a ticket for that here:
http://apps.sourceforge.net/trac/gallery/ticket/276
Posts: 7994
Ok, this should be fixed now. Can you try again?
Posts: 4342
This is a really lovely touch - but a bit glitchy -
Import works (without comments) but still seems to run at the same speed. I'm not sure the crossloading the files is working right, in respect of my size settings though - perhaps a glitch at my end. I'll try to have a look tomorrow and reprofile.
Posts: 7994
Can you take a look at g2_import::common_sizes() to see if you can figure out what's going wrong with the G2 thumb/resize size estimation?
Posts: 4342
First thought is that this G2 installation doesn't have any resizes (most originals are 600px x 400px) so the query for type DERIVATIVE_TYPE_IMAGE_RESIZE will return an empty result for both landscape and portrait. It's not clear in my mind how I would expect the {0,1,2...} resizes of G2 to carry over to the (is this right?) obligatory 1 resize of G3. What if I don't want any resizes different to the original in G3? Should I be able to set the resize to the same as the original size?
The query for thumbnail sizes returns the expected result.
Aside: both landscape and portrait searches use the ">=" operator - is there a problem with counting images where height=width twice?
EDIT: yes that appears to be the problem. Having created but a single resize (500px) I now get this (which is correct):
Posts: 7994
Ah, yeah ok I hadn't considered that scenario. I'll just drop the note in that case.
Right now G3 doesn't have the facility for you to *not* have a resize. I'll have to think about how we'd do that. I guess we'd need a setting in the UI to allow you to turn off resizes, then figure out how to deal with that properly in the theme.
You're right about the double counting; I'll change the second one to > to avoid that problem.
Posts: 4342
In the G3 (general) importer, would it be possible to detect if the resize is the same size as the original and simply duplicate the file at that stage? That would appear to be the easiest way, and it avoids an expensive unnecessary call to an image manipulation library regardless of how the image is added to G3.
Posts: 7994
Yes, that's possible. Want to take a shot at writing the code for that by modifying g2_import::copy_matching_thumbnails_and_resizes() ?
Posts: 4342
Happy to try - but it's going to take me a while to dig through how G3 works before I'm comfortable with writing code for it. Still, I guess there's no urgency.