Problem. Benchmarck, AR and CWebLogRoute

Entry

I have action



public function actionPost() {


	if(isset($_GET['id'])) {


		$post = Pages_mdl_post::model()->findByPk($_GET['id'], 'post_right_view=1');


		if(isset($post)) {


			$category=Pages_mdl_category::model()->findByPk($post->post_category);


			$this->render('post', array('c'=>$category, 'p'=>$post) ));


 		} else {


			throw new CHttpException(404);


		}


	}


}


It works. But …

Problem

I can not understand one thing.

FIRST TEST (CWebLogRoute ON -> 35 requests per second)

In my conf:



	'log'=>array(


		'class'=>'CLogRouter',


		'routes'=>array(


			array(


				'class'=>'CFileLogRoute',


				'levels'=>'error, warning',


			),


			array(


				'class'=>'CWebLogRoute',


				'levels'=>'trace',


			),


		),


	),





I run "Apache Benchmark" 5 times:



> ab -t 7 -c 5 */post/id/1


Results: 34.92, 34.86, 35.29, 34.35, 35.00 requests per second

Full result:



Benchmarking 10.8.15.159 (be patient)


Finished 245 requests








Server Software:        Apache/2.2.10


Server Hostname:        10.8.15.159


Server Port:            80





Document Path:          /_yii/pages.guest/post/id/1


Document Length:        8144 bytes





Concurrency Level:      5


Time taken for tests:   7.000 seconds


Complete requests:      245


Failed requests:        48


   (Connect: 0, Receive: 0, Length: 48, Exceptions: 0)


Write errors:           0


Total transferred:      2083304 bytes


HTML transferred:       1994859 bytes


Requests per second:    35.00 [#/sec] (mean)


Time per request:       142.857 [ms] (mean)


Time per request:       28.571 [ms] (mean, across all concurrent requests)


Transfer rate:          290.64 [Kbytes/sec] received





Connection Times (ms)


              min  mean[+/-sd] median   max


Connect:        0    6   7.6      0      16


Processing:    94  135  22.8    125     203


Waiting:       94  131  23.1    125     203


Total:         94  141  22.5    141     203





Percentage of the requests served within a certain time (ms)


  50%    141


  66%    141


  75%    156


  80%    156


  90%    172


  95%    188


  98%    203


  99%    203


 100%    203 (longest request)


SECOND TEST (CWebLogRoute OFF -> 2 requests per second)

In my conf:



	'log'=>array(


		'class'=>'CLogRouter',


		'routes'=>array(


			array(


				'class'=>'CFileLogRoute',


				'levels'=>'error, warning',


			),


//			array(


//				'class'=>'CWebLogRoute',


//				'levels'=>'trace',


//			),


		),


	),





I run "Apache Benchmark" 5 times:



> ab -t 7 -c 5 */post/id/1


Results: 2.08, 2.08, 2.07, 2.08, 2.06 requests per second

Full result:



Benchmarking 10.8.15.159 (be patient)


Finished 16 requests








Server Software:        Apache/2.2.10


Server Hostname:        10.8.15.159


Server Port:            80





Document Path:          /_yii/pages.guest/post/id/1


Document Length:        4710 bytes





Concurrency Level:      5


Time taken for tests:   7.750 seconds


Complete requests:      16


Failed requests:        0


Write errors:           0


Total transferred:      101860 bytes


HTML transferred:       94200 bytes


Requests per second:    2.06 [#/sec] (mean)


Time per request:       2421.875 [ms] (mean)


Time per request:       484.375 [ms] (mean, across all concurrent requests)


Transfer rate:          12.84 [Kbytes/sec] received





Connection Times (ms)


              min  mean[+/-sd] median   max


Connect:        0    4   7.0      0      16


Processing:  1906 1965  47.9   2000    2016


Waiting:       47  107  22.0    109     141


Total:       1906 1969  47.4   2000    2016





Percentage of the requests served within a certain time (ms)


  50%   2000


  66%   2000


  75%   2016


  80%   2016


  90%   2016


  95%   2016


  98%   2016


  99%   2016


 100%   2016 (longest request)


Help me ;—]

Is that the only change between the two tests? I can't think of a reason to interpret this. You can call microtime at the begin and end of the entry script and see what is the difference.

Yes, it is the only change between the two tests.

All the more strange that microtime() return:

first test (ON):

0.64062600 1232118736 — 0.68226100 1232118736 = 0.04

second test (OFF):

0.62500100 1232118472 — 0.66499800 1232118472 = 0.04


Very, very posible, it is not Yii problem.

First test (ON): httpd used 80% of CPU, mysqld — 10%, free — 0%;

Seccond test (OFF): httpd used 0-22% of CPU, mysql — 0-2%, free — 73-90%.