Image (Resize, Crop, ...) doesn't use previous generated files

Kirby 2 Issues 🐛
41

@lukasbestle It’s curious. When Xdebug is enabled, the logged timings says that the site runs faster with Xdebug enabled in comparison to when Xdebug is disabled. That can’t be right. And the fact is, that the site doesn’t runs faster, only Xdebug tells it runs fast. ???

E.g. Xdebug says that in worst case the site needs 670 ms to load (best case 120 ms - both would be fine). But in real the site needs approx. 4500 ms (timings measured by FireFox). The GET page itself needs this time (page-size: 2,4 KiB). All other elements like images and scripts are taken from FireFox’s cache (0 ms).

42

Where did you get the Xdebug timings from?

43

PHP-Version: 5.6.30
htaccess: php_value xdebug.profiler_enable 1
Xdebug-Version: 2.5.0

  • xdebug.profiler_output_name: cachegrind.out.%p
  • xdebug.max_nesting_level: 256

Log-Analyzers (same file, {main}):

  • WinCacheGrind 1.1.0.16 (675 ms)
  • QCachegrind 0.7.4 (101 ms)
44

Can you see in the profiler log where most of the execution time is spent?

45

I switched back to PHP 7.1 and deactivated Fast-CGI. Here are the results:

WinCacheGrind:

QCachegrind:

cachegrind.out.286549 (2).jpg842×586 101 KB

46

The results tell us that site/snippets/gallery.php is the file that generates the largest part of the delay in this request. But they don’t tell us which function that is called by the snippet is the issue (the thumb stuff itself is very fast with 34ms). Could you please post the gallery snippet?

47 
<!-- Snippet:Gallery -->
<?php if(!defined('KIRBY')) exit;

	if ($items->count()>0) {
		echo '<div class="row">';
		
		$index = -1;
		foreach($items as $item) {
			$index++;
			
			if (($index % 5) < 2) $class = 'col-xs-12 col-sm-6 col-md-6';
			else $class = 'col-xs-12 col-sm-6 col-md-4';
			
			$width = 750;
			$height = round($width * 9/16, -1);
			
			$time_start = microtime(true);
			
			if ($item->image())
				$newimage = $item->image()->crop($width, $height, 15);
			else $newimage = null;

			$time_end = microtime(true);
			$time = $time_end - $time_start;

			if ($newimage) {
				echo "<div class=\"$class\">";
				
				echo '<a href="' . $item->url() . '">';
				echo '<figure>';
				echo '<div class="gallery">';
				echo '<img src="' . $newimage->url() . '" width="100%" />';
	
				$title =$item->title()->html();
				$class = 'gallery';
				
				if (UserIsAdmin() || UserIsSupport())
					$title .= '<small class="hidden-print"> (' . intval($time * 1000) . '&nbsp;ms)</small>';
				if (UserIsAdmin())
					$class .= ' icon-' . VisibleTo($item);
				
				echo "<figcaption class=\"$class\">$title</figcaption>";
				echo '</div><!-- /.gallery -->';
				echo '</figure>';
				echo '</a>';
				
				echo '</div><!-- /.col -->';
			}
		}
		
		echo '</div><!-- /.row -->';
	}	
	
	// Show Pagination
	if ($items->pagination()->hasPages()) {
		echo '<nav class="hidden-print">';
		
		echo '<div class="row">';
		
		echo '<div class="col-xs-6">';
		if ($items->pagination()->hasNextPage())
			echo '<a class="btn btn-default" href="' . $items->pagination()->nextPageURL() . '">&lsaquo;&nbsp;Älteres</a>';
		echo '</div><!-- /.col -->';
		
		echo '<div class="col-xs-6 text-right">';
		if ($items->pagination()->hasPrevPage())
			echo '<a class="btn btn-default" href="' . $items->pagination()->prevPageURL() . '">Neueres&nbsp;&rsaquo;</a>';
		echo '</div><!-- /.col -->';
		
		echo '</div><!-- /.row -->';
			
		echo '</nav>';
	}	
?>
<!-- /Snippet:Gallery -->

To identify the part of code, where the most time is spent, I inserted profiling code in Lines 17 and 23. The long running part is the statement $newimage = $item->image()->crop($width, $height, 15);.

And here are three examples of timings:

48

@robert:
What are the times, if you delete temporarily for a test:

->crop($width, $height, 15)

If this is quicker, it may be the crop function. Otherwise these files may be very big and therefore the loading of the files takes some time respectively the hard drive needs some time…

49

@anon77445132: The tests I did before showed, that kirby does not create the thumbs when they exists. As it should be, kirby delivers the previous generated thumbs. I think the most of the time is required by determining the file-properties by PHP. But as I told before (in previous posts) I’m not familiar with PHP, so I cannot investigate deeper. So I hope you and others can help me.

And as you can see in the graphs attached below, the images for the gallery have a size of a few KiB. The original images are much bigger in size. This is required due to show them in a detailed-view.

@anon77445132, @lukasbestle: For your information the timings at FireFox. FireFox uses the cached files! The page-generation lasts 8007 ms!

FireFox(1).png754×411 28.4 KB