yiisoft/yii2-twig

Twig extension very slow when using alias

yii-bot opened this issue · 6 comments

yii-bot commented

This issue has originally been reported by @jonny7 at yiisoft/yii2#13683.
Moved here by @samdark.

What steps will reproduce the problem?

I'm using the following to generate a single PDF.

//Find a layout within all layout sub-directories (only two)
        $layoutName = \Yii::getAlias('@twig') . '/' . $action . '.twig';
        $layoutFilePath = \Yii::$app->getViewPath() . $layoutName;
        if( false == is_file($layoutFilePath))
        {
          $layoutName = \Yii::getAlias('@cotwig') . '/' . $action . '.twig';
          $layoutFilePath = \Yii::$app->getViewPath() . $layoutName;
        }

        // confirm data returned
        if(!empty($data) && is_file($layoutFilePath) ){

          $content = $this->renderPartial($layoutName, [ 'model' => $data ] );
          //return $content;
          // load the pdf
          $doc = new Pdf([
            // set to use core fonts only
            'mode' => Pdf::MODE_UTF8,
            // A4 paper format
            'format' => Pdf::FORMAT_A4,
            // portrait orientation
            'orientation' => Pdf::ORIENT_PORTRAIT,
            // stream to browser inline
            'destination' => Pdf::DEST_BROWSER,
            // your html content input
            'content' => $content,
            //Any CSS file which needs to be loaded to sytle render the html
            //'cssFile' => $cssLayoutFilePath, (can't do it here as NULL or "" will remove default style)
            'marginTop' => 5,
            'marginBottom' => 0,
          ]);

          //Determine if there is an css file needed for rendering template
          $cssLayoutFilePath = $layoutFilePath . ".css";
          if( true == is_file($cssLayoutFilePath) )
          {
            //$doc->cssFile = $cssLayoutFilePath; //Note that this will override the loading of css file  @vendor/kartik-v/yii2-mpdf/assets/bootstrap.min.css
            $doc->cssInline = file_get_contents($cssLayoutFilePath);
          }

          // render Pdf
          return $doc->render();

What is the expected result?

I'm unsure of why is_dir is called so often for a simple alias call. In our profiler work, we accounts that of the 10 second generation time, around 7 seconds was due to calling is_dir()

What do you get instead?

Here is a picture of the profiler output: http://tinypic.com/r/t5svpt/9

Additional info

I'm not on an expert on the inner workings of Yii, but wondering if this is something that can be tamed or a legitimate situation that needs to be reviewed

Q A
Yii version 2.11.2?
PHP version 5.6.28
Operating system Windows 7
antgubarev commented

What is PDF class?

jonny7 commented

@amarox It is Kartik's mPDF wrapper. https://github.com/kartik-v/yii2-mpdf

antgubarev commented

I try

$content = $this->renderPartial('@twig/site/index.twig', [
    'dataProvider' => $dataProvider,
    'someFunction' => $someFunction,
    'model' => $data
]);

echo $content;

and it's working fast. What i'm doing wrong?

In your example renderPartial has called with absolute view path. This should entail an error "View file not found". Are you sure that code in example is right?

yii-bot commented

Thanks for posting in our issue tracker.
In order to properly assist you, we need additional information:

  • When does the issue occur?
  • What do you see?
  • What was the expected result?
  • Can you supply us with a stacktrace? (optional)
  • Do you have exact code to reproduce it? Maybe a PHPUnit tests that fails? (optional)

Thanks!

This is an automated comment, triggered by adding the label status:need more info.

mikkelcp1 commented

More Info:

This issue occurs whenever the renderPartial is called (forget about the mPDF stuff) :
$this->renderPartial($layoutName, [ 'model' => $data ] );

We expect the execution time of the http request to be consistent (i.e. milleseconds, not 7 seconds which is what we see).

XDebug was enabled to try to see where the performance is lagging with the following results:

  • 70% of total Elapsed time was spent in calls to is_dir within yii\twig\ViewRenderer::addAliases

The follow patch was created to remove this performance hit:

+++ C:/xampp2/htdocs/ccns-reporting/vendor/yiisoft/yii2-twig/ViewRenderer.php	Tue Feb 28 12:53:05 2017
@@ -169,7 +169,11 @@
         if ($view instanceof View) {
             $this->addFallbackPaths($loader, $view->theme);
         }
-        $this->addAliases($loader, Yii::$aliases);
+        //Performance Issue:
+        // Issue is this is taking 7 to 10 seconds to is_dir for all Yii::aliases
+        // Removed as we do not use alias within templates anyway
+        //$this->addAliases($loader, Yii::$aliases);
         $this->twig->setLoader($loader);
         return $this->twig->render(pathinfo($file, PATHINFO_BASENAME), $params);

Testing Results of Performance with and without patch applied:

Without the patch:

  1. Wait >= ~8 seconds, execute the http request (Repeat step a few times) ( estimated Elapsed Time 3 to 7 seconds).
  2. Wait <= ~3 seconds, execute the http request (Repeat step a few times) ( estimated Elapsed Time 0.3 -0.4 seconds).

With the patch:

  1. Wait any amount of seconds, execute the http request (Repeat step a few times) ( estimated Elapsed Time 0.3 -0.4 seconds).

Conclusion

  • This might be some odd problem only within the environment Windows7, NTFS.
  • is_dir was called 79 times (for execution) on all aliases each time you render a twig file. Is it better to cache the result of is_dir to limit possible I/O issues within environment / file system.
  • For now we will need to apply the patch to ensure we do not hit this odd performance issue which seems to only occur with a 8+ wait time between repeated http requests. (Update: php's clearstatcache() seems to explain the magic 8+ seconds duration).
antgubarev commented

I still don`t repeat this bug. Including windows 8, windows 10 with NTFS.
I think that it is a local unique problem.