logging sql queries while testing

nsbucky · June 17, 2010, 6:07pm

Im currently trying to view my sql queries in some kind of log, and it doesn’t seem to be working with the CLogRoute. I have profiling enabled, but I want to see the actual queries that are being run, as one of my models is acting strange. Here is my test.php config file:




return CMap::mergeArray(

	require(dirname(__FILE__).'/main.php'),

	array(

		'components'=>array(

            #/*

				'fixture'=>array(

					'class'=>'system.test.CDbFixtureManager',                

				),

	            #*/

				'db'=>array(

					'connectionString' => 'mysql:host=localhost;dbname=intakes_manager_test',

					'emulatePrepare' => true,

					'username' => 'root',

					'password' => 'root',

					'charset' => 'utf8',

					'enableProfiling'=>true

				),

				'log'=>array(

					'class'=>'CLogRouter',

					'routes'=>array(

						array(

							'class'=>'CFileLogRoute',

							'levels'=>'error,trace,info,warning',

							//'filter'=>'CLogFilter',

                            'categories'=>'system.*'

						)

					)

				),

		 ),

	)

);

im trying to test with phpunit from command line and that works fine, but it doesnt put any output in runtime/application.log

narkomanC · June 18, 2010, 7:38am

i dont knwo whats abouyt profiling, but maybe you should add "profile" level to log route also.

"error, warning, trace, info, profile"

anyway, for sql logs i got working this configuration


		'log'=>array(

			'class'=>'CLogRouter',

			'routes'=>array(

				array(

					'class'=>'CFileLogRoute',

					'levels'=>'trace',

					'categories'=>'system.db.*',

					'logFile'=>'sql.log',

				),

mikl · June 18, 2010, 7:46am

Some things to check for logging of SQL statements:

You won’t see logs if you use yiilite.php. It has all Yii::trace() calls removed.
Since Yii::trace() is used, logging only happens if YII_DEBUG===true
You should set enableParamLogging=>true in your db configuration to see the bound parameters
enableProfiling is for measuring execution times. You need a CProfileLogRoute to see the results.

nsbucky · June 18, 2010, 11:46pm

wow thanks everyone, Ill check this out and let you know

nsbucky · June 19, 2010, 12:08am

ok I added the first suggestions, but dont see anything in my logs, here is my test.php


define('YII_DEBUG', true);

return CMap::mergeArray(

	require(dirname(__FILE__).'/main.php'),

	array(

		'components'=>array(

            #/*

				'fixture'=>array(

					'class'=>'system.test.CDbFixtureManager',                

				),

	            #*/

				'db'=>array(

					'connectionString' => 'mysql:host=localhost;dbname=intakes_manager_test',

					'emulatePrepare' => true,

					'username' => 'root',

					'password' => 'root',

					'charset' => 'utf8',

					'enableProfiling'=>true,

                    'enableParamLogging'=>true,

				),

				'log'=>array(

					'class'=>'CLogRouter',

					'routes'=>array(

						array(

							'class'=>'CFileLogRoute',

							'levels'=>'error,trace,info,warning',

							//'filter'=>'CLogFilter',

                            'categories'=>'system.db.*',

                            'logFile'=>'sql.log'

						)

					)

				),

		 ),

	)

);

I dont see where I can tell that I am using yiilite, I tried reading the docs which talks about it, but Im not clear on how that is specifically invoked or not used.

narkomanC · June 19, 2010, 6:49am

try now like Mike said about YII_DEBUG. go to the your app index.php file and on top of the file add:


// localhost = in production mode

if($_SERVER['REMOTE_ADDR'] == '127.0.0.1') defined('YII_DEBUG') or define('YII_DEBUG',true);

now your local machine will be always in debug mode (if you are testing on local machine).

Or just set YII_DEBUG


defined('YII_DEBUG') or define('YII_DEBUG',true);

nsbucky · June 19, 2010, 3:46pm

well I have the YII_DEBUG set in that test.php config file, and since Im just running unit tests, it will never load the index.php file. I changed my testing bootstrap file to have the YII_DEBUG constant, but I’m still not getting any output anywhere.

mikl · June 20, 2010, 9:58am

Could you try with CWebLogRoute first (with default parameters, no level, categories, etc.)? It’s the quickest way to see logs. They get added right at the end of your page. Just to make sure, you don’t have a permission problem…

This is my standard debug log config:


    // preloading 'log' component

    'preload'=>array('log'),


    // application components

    'components'=>array(

        'log'=>array(

            'class'=>'CLogRouter',

            'routes'=>array(

                array(

                    'class'=>'CWebLogRoute',

                ),

            ),

        ),


        ...

nsbucky · June 20, 2010, 2:58pm

yeah the weblogroute doesn’t show any output when using phpunit to test models, which is what I am trying to get, it will show output when going through HTTP, which is not what I need. Surely I can’t be the first person to have needed this haha

nsbucky · June 24, 2010, 9:27pm

Ok so I kind of got this working, I think it has something to do with triggering the clean up endRequest event from yii.

if in my phpunit CDbTestCase function I want to see all the sql that was used during that particular run then I had to call this:

Yii::app()->log->processLogs(null);

for me, at least according my config (above) it will create a file called sql.log in runtime/. It prints out a bunch of stuff, but it has helped me figure out a few things when debugging active record queries.

mikl · July 15, 2010, 11:48am

I had the same problem now. I missed in your first post, that you talked about test cases . Your hint with processLogs() brought me on the right track: The OnEndRequest is not fired after each test. So i added this to all my testcases:


public static $isIsolated=false;


// We need to do that, to access isolation status from static tearDownAfterClass:

public function setUp()

{

    self::$isIsolated=$this->inIsolation;

}


public function tearDown()

{

    if (self::$isIsolated)   // Each test requires a onEndRequest

        Yii::app()->onEndRequest(new CEvent($this));

}


public static function tearDownAfterClass()

{

    if (!self::$isIsolated)  // OnEndRequest is triggered after last test

        Yii::app()->onEndRequest(new CEvent(null));

}

Now you your logfiles will be populated again.

EDIT: And since IPB board is crap, you have to manually make an uppercase "E" from onEndRequest…

nsbucky · July 15, 2010, 2:29pm

oh awesome mike thanks! I’ll add that later today as I’m working on stuff.

balrok · September 4, 2010, 2:10pm

I’m new to testing but this sounds like it should be added to the core cause it’s unexpected behaviour if log-routes won’t work anymore…

But since I don’t know much I won’t file an issue for that

kokomo · August 14, 2011, 9:40pm

I know it is an old topic but I have the same problem and want to solve it the best and easiest way.

So how is the status of this problem/bug? Could not find any issue on code.google so should we fill a bug report for it if it is still an actual issue?

What is the prefered way/workaround to enable logging during unit tests? Tried mike’s solution but it didn’t work.

Thanks for any help/answers…

gazbond · October 1, 2011, 11:03pm

Same problem here. Any other solutions?

gazbond · October 2, 2011, 10:00am

Adding the following to my unit test classes works for me:




public static function tearDownAfterClass()

{

    Yii::app()->onEndRequest(new CEvent(null));

}

nsbucky · May 16, 2012, 10:57pm

I can confirm that this code does work when you add it to your CDbTestCase extended class:




public static function tearDownAfterClass()

{

    Yii::app()->onEndRequest(new CEvent(null));

}

Herode · July 17, 2013, 11:34am

A bit of necrothreading maybe but… I’m using unit tests with Yii and I’m unable to log anything, even using the above code. Any updates about this problem ?

fragoulas · March 11, 2014, 9:42am

same here

Herode · March 12, 2014, 12:23pm

BTW, I eventually managed to run the above code but I also found another solution. Try to add the following code at the end of your bootstrap.php file :


	Yii::getLogger()->autoFlush = 1;

	Yii::getLogger()->autoDump = true;

For a more detailed explanation :

http://www.hypothese.net/how-can-i-get-logs-in-test-mode-with-yii/news/show/18

(the paper is also availabel in french)