Skip to content

Commit 1d4ac68

Browse files
committed
Merge pull request silverstripe#184 from chillu/ss-log-tweaks
SS_Log: String args, extra data logging, "in line of..." formatting
2 parents d912da4 + 24e2003 commit 1d4ac68

File tree

6 files changed

+130
-28
lines changed

6 files changed

+130
-28
lines changed

dev/Backtrace.php

+2-2
Original file line numberDiff line numberDiff line change
@@ -163,7 +163,7 @@ static function get_rendered_backtrace($bt, $plainText = false, $ignoredFunction
163163
foreach($bt as $item) {
164164
if($plainText) {
165165
$result .= self::full_func_name($item,true) . "\n";
166-
if(isset($item['line']) && isset($item['file'])) $result .= "line $item[line] of " . basename($item['file']) . "\n";
166+
if(isset($item['line']) && isset($item['file'])) $result .= basename($item['file']) . ":$item[line]\n";
167167
$result .= "\n";
168168
} else {
169169
if ($item['function'] == 'user_error') {
@@ -172,8 +172,8 @@ static function get_rendered_backtrace($bt, $plainText = false, $ignoredFunction
172172
$name = self::full_func_name($item,true);
173173
}
174174
$result .= "<li><b>" . htmlentities($name, ENT_COMPAT, 'UTF-8') . "</b>\n<br />\n";
175-
$result .= isset($item['line']) ? "Line $item[line] of " : '';
176175
$result .= isset($item['file']) ? htmlentities(basename($item['file']), ENT_COMPAT, 'UTF-8') : '';
176+
$result .= isset($item['line']) ? ":$item[line]" : '';
177177
$result .= "</li>\n";
178178
}
179179
}

dev/Debug.php

+4-4
Original file line numberDiff line numberDiff line change
@@ -67,9 +67,9 @@ static function show($val, $showHeader = true) {
6767
if($showHeader) {
6868
$caller = Debug::caller();
6969
if(Director::is_ajax() || Director::is_cli())
70-
echo "Debug ($caller[class]$caller[type]$caller[function]() in line $caller[line] of " . basename($caller['file']) . ")\n";
70+
echo "Debug ($caller[class]$caller[type]$caller[function]() in " . basename($caller['file']) . ":$caller[line])\n";
7171
else
72-
echo "<div style=\"background-color: white; text-align: left;\">\n<hr>\n<h3>Debug <span style=\"font-size: 65%\">($caller[class]$caller[type]$caller[function]() \n<span style=\"font-weight:normal\">in line</span> $caller[line] \n<span style=\"font-weight:normal\">of</span> " . basename($caller['file']) . ")</span>\n</h3>\n";
72+
echo "<div style=\"background-color: white; text-align: left;\">\n<hr>\n<h3>Debug <span style=\"font-size: 65%\">($caller[class]$caller[type]$caller[function]() \nin " . basename($caller['file']) . ":$caller[line])</span>\n</h3>\n";
7373
}
7474

7575
echo Debug::text($val);
@@ -88,7 +88,7 @@ static function show($val, $showHeader = true) {
8888
static function endshow($val) {
8989
if(!Director::isLive()) {
9090
$caller = Debug::caller();
91-
echo "<hr>\n<h3>Debug \n<span style=\"font-size: 65%\">($caller[class]$caller[type]$caller[function]() \n<span style=\"font-weight:normal\">in line</span> $caller[line] \n<span style=\"font-weight:normal\">of</span> " . basename($caller['file']) . ")</span>\n</h3>\n";
91+
echo "<hr>\n<h3>Debug \n<span style=\"font-size: 65%\">($caller[class]$caller[type]$caller[function]() \nin " . basename($caller['file']) . ":$caller[line])</span>\n</h3>\n";
9292
echo Debug::text($val);
9393
die();
9494
}
@@ -102,7 +102,7 @@ static function endshow($val) {
102102
static function dump($val) {
103103
echo '<pre style="background-color:#ccc;padding:5px;font-size:14px;line-height:18px;">';
104104
$caller = Debug::caller();
105-
echo "<span style=\"font-size: 12px;color:#666;\">Line $caller[line] of " . basename($caller['file']) . ":</span>\n";
105+
echo "<span style=\"font-size: 12px;color:#666;\">" . basename($caller['file']) . ":$caller[line] - </span>\n";
106106
if (is_string($val)) print_r(wordwrap($val, 100));
107107
else print_r($val);
108108
echo '</pre>';

dev/Log.php

+42-4
Original file line numberDiff line numberDiff line change
@@ -64,14 +64,41 @@ class SS_Log {
6464
protected static $logger;
6565

6666
/**
67-
* Get the logger currently in use, or create a new
68-
* one if it doesn't exist.
67+
* @var array Logs additional context from PHP's superglobals.
68+
* Caution: Depends on logger implementation (mainly targeted at {@link SS_LogEmailWriter}).
69+
* @see http://framework.zend.com/manual/en/zend.log.overview.html#zend.log.overview.understanding-fields
70+
*/
71+
static $log_globals = array(
72+
'_SERVER' => array(
73+
'HTTP_ACCEPT',
74+
'HTTP_ACCEPT_CHARSET',
75+
'HTTP_ACCEPT_ENCODING',
76+
'HTTP_ACCEPT_LANGUAGE',
77+
'HTTP_REFERRER',
78+
'HTTP_USER_AGENT',
79+
'HTTPS',
80+
'REMOTE_ADDR',
81+
),
82+
);
83+
84+
/**
85+
* Get the logger currently in use, or create a new one if it doesn't exist.
6986
*
7087
* @return object
7188
*/
7289
public static function get_logger() {
7390
if(!self::$logger) {
91+
// Create default logger
7492
self::$logger = new self::$logger_class;
93+
94+
// Add default context (shouldn't change until the actual log event happens)
95+
foreach(self::$log_globals as $globalName => $keys) {
96+
foreach($keys as $key) {
97+
$val = @$GLOBALS[$globalName][$key];
98+
self::$logger->setEventItem(sprintf('$%s[\'%s\']', $globalName, $key), $val);
99+
}
100+
}
101+
75102
}
76103
return self::$logger;
77104
}
@@ -123,8 +150,9 @@ public static function add_writer($writer, $priority = null, $comparison = '=')
123150
*
124151
* @param mixed $message Exception object or array of error context variables
125152
* @param const $priority Priority. Possible values: SS_Log::ERR, SS_Log::WARN or SS_Log::NOTICE
153+
* @param mixed $extras Extra information to log in event
126154
*/
127-
public static function log($message, $priority) {
155+
public static function log($message, $priority, $extras = null) {
128156
if($message instanceof Exception) {
129157
$message = array(
130158
'errno' => '',
@@ -133,9 +161,19 @@ public static function log($message, $priority) {
133161
'errline' => $message->getLine(),
134162
'errcontext' => $message->getTrace()
135163
);
164+
} elseif(is_string($message)) {
165+
$trace = SS_Backtrace::filtered_backtrace();
166+
$lastTrace = $trace[0];
167+
$message = array(
168+
'errno' => '',
169+
'errstr' => $message,
170+
'errfile' => @$lastTrace['file'],
171+
'errline' => @$lastTrace['line'],
172+
'errcontext' => $trace
173+
);
136174
}
137175
try {
138-
self::get_logger()->log($message, $priority);
176+
self::get_logger()->log($message, $priority, $extras);
139177
} catch(Exception $e) {
140178
// @todo How do we handle exceptions thrown from Zend_Log?
141179
// For example, an exception is thrown if no writers are added

dev/LogEmailWriter.php

+21-7
Original file line numberDiff line numberDiff line change
@@ -52,16 +52,30 @@ public function _write($event) {
5252
$subject = $formattedData['subject'];
5353
$data = $formattedData['data'];
5454

55-
$originalSMTP = ini_get('SMTP');
5655
// override the SMTP server with a custom one if required
56+
$originalSMTP = ini_get('SMTP');
5757
if($this->customSmtpServer) ini_set('SMTP', $this->customSmtpServer);
5858

59-
mail(
60-
$this->emailAddress,
61-
$subject,
62-
$data,
63-
"Content-type: text/html\nFrom: " . self::$send_from
64-
);
59+
// Use plain mail() implementation to avoid complexity of Mailer implementation.
60+
// Only use built-in mailer when we're in test mode (to allow introspection)
61+
$mailer = Email::mailer();
62+
if($mailer instanceof TestMailer) {
63+
$mailer->sendHTML(
64+
$this->emailAddress,
65+
null,
66+
$subject,
67+
$data,
68+
null,
69+
"Content-type: text/html\nFrom: " . self::$send_from
70+
);
71+
} else {
72+
mail(
73+
$this->emailAddress,
74+
$subject,
75+
$data,
76+
"Content-type: text/html\nFrom: " . self::$send_from
77+
);
78+
}
6579

6680
// reset the SMTP server to the original
6781
if($this->customSmtpServer) ini_set('SMTP', $originalSMTP);

dev/LogErrorEmailFormatter.php

+20-4
Original file line numberDiff line numberDiff line change
@@ -35,24 +35,40 @@ public function format($event) {
3535
$errline = $event['message']['errline'];
3636
$errcontext = $event['message']['errcontext'];
3737

38-
$data = "<div style=\"border: 5px $colour solid\">\n";
39-
$data .= "<p style=\"color: white; background-color: $colour; margin: 0\">$errorType: $errstr<br /> At line $errline in $errfile\n<br />\n<br />\n</p>\n";
38+
$data = '';
39+
$data .= '<style type="text/css">html, body, table {font-family: sans-serif; font-size: 12px;}</style>';
40+
$data .= "<div style=\"border: 5px $colour solid;\">\n";
41+
$data .= "<p style=\"color: white; background-color: $colour; margin: 0\">[$errorType] $errstr<br />$errfile:$errline\n<br />\n<br />\n</p>\n";
4042

4143
// Get a backtrace, filtering out debug method calls
4244
$data .= SS_Backtrace::backtrace(true, false, array(
4345
'SS_LogErrorEmailFormatter->format',
4446
'SS_LogEmailWriter->_write'
4547
));
4648

49+
// Compile extra data
50+
$blacklist = array('message', 'timestamp', 'priority', 'priorityName');
51+
$extras = array_diff_key($event, array_combine($blacklist, $blacklist));
52+
if($extras) {
53+
$data .= "<h3>Details</h3>\n";
54+
$data .= "<table class=\"extras\">\n";
55+
foreach($extras as $k => $v) {
56+
if(is_array($v)) $v = var_export($v, true);
57+
$data .= sprintf(
58+
"<tr><td><strong>%s</strong></td><td><pre>%s</pre></td></tr>\n", $k, $v);
59+
}
60+
$data .= "</table>\n";
61+
}
62+
4763
$data .= "</div>\n";
4864

4965
$relfile = Director::makeRelative($errfile);
50-
if($relfile[0] == '/') $relfile = substr($relfile, 1);
66+
if($relfile && $relfile[0] == '/') $relfile = substr($relfile, 1);
5167

5268
$host = @$_SERVER['HTTP_HOST'];
5369
$uri = @$_SERVER['REQUEST_URI'];
5470

55-
$subject = "$errorType at $relfile line {$errline} (http://{$host}{$uri})";
71+
$subject = "[$errorType] in $relfile:{$errline} (http://{$host}{$uri})";
5672

5773
return array(
5874
'subject' => $subject,

tests/dev/LogTest.php

+41-7
Original file line numberDiff line numberDiff line change
@@ -9,28 +9,62 @@ class SS_LogTest extends SapphireTest {
99

1010
function setUp() {
1111
parent::setUp();
12-
SS_Log::clear_writers(); // this test will break if existing writers are available!
13-
$this->testEmailWriter = new SS_LogEmailWriter('[email protected]');
14-
$this->testFileWriter = new SS_LogFileWriter('../test.log');
15-
SS_Log::add_writer($this->testEmailWriter, SS_Log::ERR);
16-
SS_Log::add_writer($this->testFileWriter, SS_Log::WARN);
12+
13+
SS_Log::clear_writers();
14+
}
15+
16+
function tearDown() {
17+
parent::tearDown();
18+
19+
SS_Log::clear_writers();
1720
}
1821

1922
function testExistingWriter() {
23+
$testEmailWriter = new SS_LogEmailWriter('[email protected]');
24+
$testFileWriter = new SS_LogFileWriter('../test.log');
25+
SS_Log::add_writer($testEmailWriter, SS_Log::ERR);
26+
SS_Log::add_writer($testFileWriter, SS_Log::WARN);
27+
2028
$writers = SS_Log::get_writers();
2129
$this->assertType('array', $writers);
2230
$this->assertEquals(2, count($writers));
2331
}
2432

2533
function testRemoveWriter() {
26-
SS_Log::remove_writer($this->testEmailWriter);
34+
$testEmailWriter = new SS_LogEmailWriter('[email protected]');
35+
$testFileWriter = new SS_LogFileWriter('../test.log');
36+
SS_Log::add_writer($testEmailWriter, SS_Log::ERR);
37+
SS_Log::add_writer($testFileWriter, SS_Log::WARN);
38+
39+
SS_Log::remove_writer($testEmailWriter);
2740
$writers = SS_Log::get_writers();
2841
$this->assertType('array', $writers);
2942
$this->assertEquals(1, count($writers));
30-
SS_Log::remove_writer($this->testFileWriter);
43+
44+
SS_Log::remove_writer($testFileWriter);
3145
$writers = SS_Log::get_writers();
3246
$this->assertType('array', $writers);
3347
$this->assertEquals(0, count($writers));
3448
}
3549

50+
function testEmailWriter() {
51+
$testEmailWriter = new SS_LogEmailWriter('[email protected]');
52+
SS_Log::add_writer($testEmailWriter, SS_Log::ERR);
53+
54+
SS_Log::log('Email test', SS_LOG::ERR, array('my-string' => 'test', 'my-array' => array('one' => 1)));
55+
$this->assertEmailSent('[email protected]');
56+
$email = $this->findEmail('[email protected]');
57+
$parser = new CSSContentParser($email['htmlContent']);
58+
$extras = $parser->getBySelector('table.extras');
59+
$extraRows = $extras[0]->tr;
60+
$this->assertContains('my-string', $extraRows[count($extraRows)-2]->td[0]->asXML(), 'Contains extra data key');
61+
$this->assertContains('test', $extraRows[count($extraRows)-2]->td[1]->asXML(), 'Contains extra data value');
62+
$this->assertContains('my-array', $extraRows[count($extraRows)-1]->td[0]->asXML(), 'Contains extra data key');
63+
$this->assertContains(
64+
"array('one'=&gt;1,)",
65+
str_replace(array("\r", "\n", " "), '', $extraRows[count($extraRows)-1]->td[1]->asXML()),
66+
'Serializes arrays correctly'
67+
);
68+
}
69+
3670
}

0 commit comments

Comments
 (0)