runtime-logging.md 16.4 KB
Newer Older
1 2 3
Logging
=======

Qiang Xue committed
4 5 6
Yii provides a powerful logging framework that is highly customizable and extensible. Using this framework, you
can easily log various types of messages, filter them, and gather them at different targets, such as files, databases,
emails. 
Qiang Xue committed
7

8
Using the Yii logging framework involves the following steps:
Qiang Xue committed
9 10
 
* Record [log messages](#log-messages) at various places in your code;
11 12
* Configure [log targets](#log-targets) in the application configuration to filter and export log messages;
* Examine the filtered logged messages exported by different targets (e.g. the [Yii debugger](tool-debugger.md)).
13

Qiang Xue committed
14
In this section, we will mainly describe the first two steps.
15

Qiang Xue committed
16 17 18 19 20 21 22 23 24 25 26 27 28 29

## Log Messages <a name="log-messages"></a>

Recording log messages is as simple as calling one of the following logging methods:

* [[Yii::trace()]]: record a message to trace how a piece of code runs. This is mainly for development use.
* [[Yii::info()]]: record a message that conveys some useful information.
* [[Yii::warning()]]: record a warning message that indicates something unexpected has happened.
* [[Yii::error()]]: record a fatal error that should be investigated as soon as possible.

These logging methods record log messages at various *severity levels* and *categories*. They share
the same function signature `function ($message, $category = 'application')`, where `$message` stands for
the log message to be recorded, while `$category` is the category of the log message. The code in the following
example records a trace message under the default category `application`:
30 31

```php
Qiang Xue committed
32
Yii::trace('start calculating average revenue');
33 34
```

Qiang Xue committed
35 36 37
> Info: Log messages can be strings as well as complex data, such as arrays or objects. It is the responsibility
of [log targets](#log-targets) to properly deal with log messages. By default, if a log message is not a string,
it will be exported as a string by calling [[yii\helpers\VarDumper::export()]].
38

Qiang Xue committed
39 40 41
To better organize and filter log messages, it is recommended that you specify an appropriate category for each
log message. You may choose a hierarchical naming scheme for categories, which will make it easier for 
[log targets](#log-targets) to filter messages based on their categories. A simple yet effective naming scheme
42
is to use the PHP magic constant `__METHOD__` for the category names. This is also the approach used in the core 
Qiang Xue committed
43
Yii framework code. For example,
44

Qiang Xue committed
45 46 47
```php
Yii::trace('start calculating average revenue', __METHOD__);
```
48

Qiang Xue committed
49
The `__METHOD__` constant evaluates as the name of the method (prefixed with the fully qualified class name) where 
50
the constant appears. For example, it is equal to the string `'app\controllers\RevenueController::calculate'` if 
Qiang Xue committed
51
the above line of code is called within this method.
52

Qiang Xue committed
53 54 55 56
> Info: The logging methods described above are actually shortcuts to the [[yii\log\Logger::log()|log()]] method 
of the [[yii\log\Logger|logger object]] which is a singleton accessible through the expression `Yii::getLogger()`. When
enough messages are logged or when the application ends, the logger object will call a  
[[yii\log\Dispatcher|message dispatcher]] to send recorded log messages to the registered [log targets](#log-targets).
57 58


Qiang Xue committed
59
## Log Targets <a name="log-targets"></a>
60

61
A log target is an instance of the [[yii\log\Target]] class or its child class. It filters the log messages by their
62
severity levels and categories and then exports them to some medium. For example, a  [[yii\log\DbTarget|database target]]
63
exports the filtered log messages to a database table, while an [[yii\log\EmailTarget|email target]] exports
64
the log messages to specified email addresses.
65

66
You can register multiple log targets in an application by configuring them through the `log` [application component](structure-application-components.md)
Qiang Xue committed
67
in the application configuration, like the following:
68 69

```php
Qiang Xue committed
70 71 72 73
return [
    // the "log" component must be loaded during bootstrapping time
    'bootstrap' => ['log'],
    
74 75 76
    'components' => [
        'log' => [
            'targets' => [
Qiang Xue committed
77 78 79
                [
                    'class' => 'yii\log\DbTarget',
                    'levels' => ['error', 'warning'],
80
                ],
Qiang Xue committed
81
                [
82
                    'class' => 'yii\log\EmailTarget',
Qiang Xue committed
83 84
                    'levels' => ['error'],
                    'categories' => ['yii\db\*'],
85
                    'message' => [
Qiang Xue committed
86 87 88
                       'from' => ['log@example.com'],
                       'to' => ['admin@example.com', 'developer@example.com'],
                       'subject' => 'Database errors at example.com',
89 90 91 92 93
                    ],
                ],
            ],
        ],
    ],
Qiang Xue committed
94 95 96
];
```

97 98
> Note: The `log` component must be loaded during [bootstrapping](runtime-bootstrapping.md) time so that
it can dispatch log messages to targets promptly. That is why it is listed in the `bootstrap` array as shown above.
Qiang Xue committed
99 100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119

In the above code, two log targets are registered in the [[yii\log\Dispatcher::targets]] property: 

* the first target selects error and warning messages and saves them in a database table;
* the second target selects error messages under the categories whose names start with `yii\db\`, and sends
  them in an email to both `admin@example.com` and `developer@example.com`.

Yii comes with the following built-in log targets. Please refer to the API documentation about these classes to 
learn how to configure and use them. 

* [[yii\log\DbTarget]]: stores log messages in a database table.
* [[yii\log\EmailTarget]]: sends log messages to pre-specified email addresses.
* [[yii\log\FileTarget]]: saves log messages in files.
* [[yii\log\SyslogTarget]]: saves log messages to syslog by calling the PHP function `syslog()`.

In the following, we will describe the features common to all log targets.

  
### Message Filtering <a name="message-filtering"></a>

For each log target, you can configure its [[yii\log\Target::levels|levels]] and 
120
[[yii\log\Target::categories|categories]] properties to specify which severity levels and categories of the messages the target should process.
Qiang Xue committed
121 122 123 124 125 126 127

The [[yii\log\Target::levels|levels]] property takes an array consisting of one or several of the following values:

* `error`: corresponding to messages logged by [[Yii::error()]].
* `warning`: corresponding to messages logged by [[Yii::warning()]].
* `info`: corresponding to messages logged by [[Yii::info()]].
* `trace`: corresponding to messages logged by [[Yii::trace()]].
Qiang Xue committed
128 129
* `profile`: corresponding to messages logged by [[Yii::beginProfile()]] and [[Yii::endProfile()]], which will
be explained in more details in the [Profiling](#performance-profiling) subsection.
Qiang Xue committed
130 131 132 133 134 135 136 137 138 139 140 141 142 143 144

If you do not specify the [[yii\log\Target::levels|levels]] property, it means the target will process messages
of *any* severity level.

The [[yii\log\Target::categories|categories]] property takes an array consisting of message category names or patterns.
A target will only process messages whose category can be found or match one of the patterns in this array.
A category pattern is a category name prefix with an asterisk `*` at its end. A category name matches a category pattern
if it starts with the same prefix of the pattern. For example, `yii\db\Command::execute` and `yii\db\Command::query`
are used as category names for the log messages recorded in the [[yii\db\Command]] class. They both match
the pattern `yii\db\*`.

If you do not specify the [[yii\log\Target::categories|categories]] property, it means the target will process
messages of *any* category.

Besides whitelisting the categories by the [[yii\log\Target::categories|categories]] property, you may also
145
blacklist certain categories by the [[yii\log\Target::except|except]] property. If the category of a message
Qiang Xue committed
146 147 148 149 150 151 152 153 154 155 156 157 158 159 160 161
is found or matches one of the patterns in this property, it will NOT be processed by the target.
 
The following target configuration specifies that the target should only process error and warning messages
under the categories whose names match either `yii\db\*` or `yii\web\HttpException:*`, but not `yii\web\HttpException:404`.

```php
[
    'class' => 'yii\log\FileTarget',
    'levels' => ['error', 'warning'],
    'categories' => [
        'yii\db\*',
        'yii\web\HttpException:*',
    ],
    'except' => [
        'yii\web\HttpException:404',
    ],
162 163 164
]
```

165 166 167 168
> Info: When an HTTP exception is caught by the [error handler](runtime-handling-errors.md), an error message
  will be logged with the category name in the format of `yii\web\HttpException:ErrorCode`. For example,
  the [[yii\web\NotFoundHttpException]] will cause an error message of category `yii\web\HttpException:404`.

Qiang Xue committed
169 170 171

### Message Formatting <a name="message-formatting"></a>

172
Log targets export the filtered log messages in a certain format. For example, if you install
173 174 175 176 177 178 179 180 181 182 183 184 185 186 187
a log target of the class [[yii\log\FileTarget]], you may find a log message similar to the following in the
`runtime/log/app.log` file:

```
2014-10-04 18:10:15 [::1][][-][trace][yii\base\Module::getModule] Loading module: debug
```

By default, log messages will be formatted as follows by the [[yii\log\Target::formatMessage()]]:

```
Timestamp [IP address][User ID][Session ID][Severity Level][Category] Message Text
```

You may customize this format by configuring the [[yii\log\Target::prefix]] property which takes a PHP callable
returning a customized message prefix. For example, the following code configures a log target to prefix each
188
log message with the current user ID (IP address and Session ID are removed for privacy reasons).
189 190 191 192 193 194 195 196 197 198 199 200 201 202 203 204 205 206 207 208 209 210 211 212 213

```php
[
    'class' => 'yii\log\FileTarget',
    'prefix' => function ($message) {
        $user = Yii::$app->has('user', true) ? Yii::$app->get('user') : null;
        $userID = $user ? $user->getId(false) : '-';
        return "[$userID]";
    }
]
```

Besides message prefixes, log targets also append some context information to each batch of log messages.
By default, the values of these global PHP variables are included: `$_GET`, `$_POST`, `$_FILES`, `$_COOKIE`,
`$_SESSION` and `$_SERVER`. You may adjust this behavior by configuring the [[yii\log\Target::logVars]] property
with the names of the global variables that you want to include by the log target. For example, the following
log target configuration specifies that only the value of the `$_SERVER` variable will be appended to the log messages.

```php
[
    'class' => 'yii\log\FileTarget',
    'logVars' => ['_SERVER'],
]
```

Qiang Xue committed
214 215 216 217
You may configure `logVars` to be an empty array to totally disable the inclusion of context information.
Or if you want to implement your own way of providing context information, you may override the
[[yii\log\Target::getContextMessage()]] method.

218 219 220 221 222 223 224 225 226 227 228 229 230 231 232 233 234 235 236 237 238 239 240 241 242 243

### Message Trace Level <a name="trace-level"></a>

During development, it is often desirable to see where each log message is coming from. This can be achieved by
configuring the [[yii\log\Dispatcher::traceLevel|traceLevel]] property of the `log` component like the following:

```php
return [
    'bootstrap' => ['log'],
    'components' => [
        'log' => [
            'traceLevel' => YII_DEBUG ? 3 : 0,
            'targets' => [...],
        ],
    ],
];
```

The above application configuration sets [[yii\log\Dispatcher::traceLevel|traceLevel]] to be 3 if `YII_DEBUG` is on
and 0 if `YII_DEBUG` is off. This means, if `YII_DEBUG` is on, each log message will be appended with at most 3
levels of the call stack at which the log message is recorded; and if `YII_DEBUG` is off, no call stack information
will be included.

> Info: Getting call stack information is not trivial. Therefore, you should only use this feature during development
or when debugging an application.

Qiang Xue committed
244 245 246

### Message Flushing and Exporting <a name="flushing-exporting"></a>

247 248
As aforementioned, log messages are maintained in an array by the [[yii\log\Logger|logger object]]. To limit the
memory consumption by this array, the logger will flush the recorded messages to the [log targets](#log-targets)
249
each time the array accumulates a certain number of log messages. You can customize this number by configuring
250 251 252 253 254 255 256 257 258 259 260 261 262 263 264 265 266 267 268 269 270 271 272 273 274 275 276 277 278 279 280
the [[yii\log\Dispatcher::flushInterval|flushInterval]] property of the `log` component:


```php
return [
    'bootstrap' => ['log'],
    'components' => [
        'log' => [
            'flushInterval' => 100,   // default is 1000
            'targets' => [...],
        ],
    ],
];
```

> Info: Message flushing also occurs when the application ends, which ensures log targets can receive complete log messages.

When the [[yii\log\Logger|logger object]] flushes log messages to [log targets](#log-targets), they do not get exported
immediately. Instead, the message exporting only occurs when a log target accumulates certain number of the filtered
messages. You can customize this number by configuring the [[yii\log\Target::exportInterval|exportInterval]]
property of individual [log targets](#log-targets), like the following,

```php
[
    'class' => 'yii\log\FileTarget',
    'exportInterval' => 100,  // default is 1000
]
```

Because of the flushing and exporting level setting, by default when you call `Yii::trace()` or any other logging
method, you will NOT see the log message immediately in the log targets. This could be a problem for some long-running
281
console applications. To make each log message appear immediately in the log targets, you should set both
282
[[yii\log\Dispatcher::flushInterval|flushInterval]] and [[yii\log\Target::exportInterval|exportInterval]] to be 1,
283
as shown below:
284 285 286 287 288 289 290 291 292 293 294 295 296 297 298 299 300 301 302 303

```php
return [
    'bootstrap' => ['log'],
    'components' => [
        'log' => [
            'flushInterval' => 1,
            'targets' => [
                [
                    'class' => 'yii\log\FileTarget',
                    'exportInterval' => 1,
                ],
            ],
        ],
    ],
];
```

> Note: Frequent message flushing and exporting will degrade the performance of your application.

304

305 306 307 308
### Toggling Log Targets <a name="toggling-log-targets"></a>

You can enable or disable a log target by configuring its [[yii\log\Target::enabled|enabled]] property.
You may do so via the log target configuration or by the following PHP statement in your code:
309 310 311 312 313

```php
Yii::$app->log->targets['file']->enabled = false;
```

314
The above code requires you to name a target as `file`, as shown below by using string keys in the
315 316 317 318 319 320 321 322 323 324 325 326 327 328 329 330 331 332 333
`targets` array:

```php
return [
    'bootstrap' => ['log'],
    'components' => [
        'log' => [
            'targets' => [
                'file' => [
                    'class' => 'yii\log\FileTarget',
                ],
                'db' => [
                    'class' => 'yii\log\DbTarget',
                ],
            ],
        ],
    ],
];
```
334

Qiang Xue committed
335 336

### Creating New Targets <a name="new-targets"></a>
337

338 339 340 341
Creating a new log target class is very simple. You mainly need to implement the [[yii\log\Target::export()]] method
sending the content of the [[yii\log\Target::messages]] array to a designated medium. You may call the
[[yii\log\Target::formatMessage()]] method to format each message. For more details, you may refer to any of the
log target classes included in the Yii release.
342

Qiang Xue committed
343

344
## Performance Profiling <a name="performance-profiling"></a>
345

346 347 348
Performance profiling is a special type of message logging that is used to measure the time taken by certain
code blocks and find out what are the performance bottlenecks. For example, the [[yii\db\Command]] class uses
performance profiling to find out the time taken by each DB query.
349

350
To use performance profiling, first identify the code blocks that need to be profiled. Then enclose each
351
code block like the following:
352

353 354
```php
\Yii::beginProfile('myBenchmark');
355

356
...code block being profiled...
357

358 359 360
\Yii::endProfile('myBenchmark');
```

361 362
where `myBenchmark` stands for a unique token identifying a code block. Later when you examine the profiling
result, you will use this token to locate the time spent by the corresponding code block.
363

364 365
It is important to make sure that the pairs of `beginProfile` and `endProfile` are properly nested.
For example,
366 367 368

```php
\Yii::beginProfile('block1');
369

370
    // some code to be profiled
371

372 373 374
    \Yii::beginProfile('block2');
        // some other code to be profiled
    \Yii::endProfile('block2');
375

376 377
\Yii::endProfile('block1');
```
378

379 380
If you miss `\Yii::endProfile('block1')` or switch the order of `\Yii::endProfile('block1')` and
`\Yii::endProfile('block2')`, the performance profiling will not work.
Qiang Xue committed
381

382
For each code block being profiled, a log message with the severity level `profile` is recorded. You can configure
383 384
a [log target](#log-targets) to collect such messages and export them. The [Yii debugger](tool-debugger.md) has
a built-in performance profiling panel showing the profiling results.