dblog.test 21 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593
  1. <?php
  2. /**
  3. * @file
  4. * Tests for dblog.module.
  5. */
  6. class DBLogTestCase extends DrupalWebTestCase {
  7. protected $big_user;
  8. protected $any_user;
  9. public static function getInfo() {
  10. return array(
  11. 'name' => 'DBLog functionality',
  12. 'description' => 'Generate events and verify dblog entries; verify user access to log reports based on persmissions.',
  13. 'group' => 'DBLog',
  14. );
  15. }
  16. /**
  17. * Enable modules and create users with specific permissions.
  18. */
  19. function setUp() {
  20. parent::setUp('dblog', 'blog', 'poll');
  21. // Create users.
  22. $this->big_user = $this->drupalCreateUser(array('administer site configuration', 'access administration pages', 'access site reports', 'administer users'));
  23. $this->any_user = $this->drupalCreateUser(array());
  24. }
  25. /**
  26. * Login users, create dblog events, and test dblog functionality through the admin and user interfaces.
  27. */
  28. function testDBLog() {
  29. // Login the admin user.
  30. $this->drupalLogin($this->big_user);
  31. $row_limit = 100;
  32. $this->verifyRowLimit($row_limit);
  33. $this->verifyCron($row_limit);
  34. $this->verifyEvents();
  35. $this->verifyReports();
  36. // Login the regular user.
  37. $this->drupalLogin($this->any_user);
  38. $this->verifyReports(403);
  39. }
  40. /**
  41. * Verify setting of the dblog row limit.
  42. *
  43. * @param integer $count Log row limit.
  44. */
  45. private function verifyRowLimit($row_limit) {
  46. // Change the dblog row limit.
  47. $edit = array();
  48. $edit['dblog_row_limit'] = $row_limit;
  49. $this->drupalPost('admin/config/development/logging', $edit, t('Save configuration'));
  50. $this->assertResponse(200);
  51. // Check row limit variable.
  52. $current_limit = variable_get('dblog_row_limit', 1000);
  53. $this->assertTrue($current_limit == $row_limit, t('[Cache] Row limit variable of @count equals row limit of @limit', array('@count' => $current_limit, '@limit' => $row_limit)));
  54. // Verify dblog row limit equals specified row limit.
  55. $current_limit = unserialize(db_query("SELECT value FROM {variable} WHERE name = :dblog_limit", array(':dblog_limit' => 'dblog_row_limit'))->fetchField());
  56. $this->assertTrue($current_limit == $row_limit, t('[Variable table] Row limit variable of @count equals row limit of @limit', array('@count' => $current_limit, '@limit' => $row_limit)));
  57. }
  58. /**
  59. * Verify cron applies the dblog row limit.
  60. *
  61. * @param integer $count Log row limit.
  62. */
  63. private function verifyCron($row_limit) {
  64. // Generate additional log entries.
  65. $this->generateLogEntries($row_limit + 10);
  66. // Verify dblog row count exceeds row limit.
  67. $count = db_query('SELECT COUNT(wid) FROM {watchdog}')->fetchField();
  68. $this->assertTrue($count > $row_limit, t('Dblog row count of @count exceeds row limit of @limit', array('@count' => $count, '@limit' => $row_limit)));
  69. // Run cron job.
  70. $this->cronRun();
  71. // Verify dblog row count equals row limit plus one because cron adds a record after it runs.
  72. $count = db_query('SELECT COUNT(wid) FROM {watchdog}')->fetchField();
  73. $this->assertTrue($count == $row_limit + 1, t('Dblog row count of @count equals row limit of @limit plus one', array('@count' => $count, '@limit' => $row_limit)));
  74. }
  75. /**
  76. * Generate dblog entries.
  77. *
  78. * @param integer $count
  79. * Number of log entries to generate.
  80. * @param $type
  81. * The type of watchdog entry.
  82. * @param $severity
  83. * The severity of the watchdog entry.
  84. */
  85. private function generateLogEntries($count, $type = 'custom', $severity = WATCHDOG_NOTICE) {
  86. global $base_root;
  87. // Prepare the fields to be logged
  88. $log = array(
  89. 'type' => $type,
  90. 'message' => 'Log entry added to test the dblog row limit.',
  91. 'variables' => array(),
  92. 'severity' => $severity,
  93. 'link' => NULL,
  94. 'user' => $this->big_user,
  95. 'uid' => isset($this->big_user->uid) ? $this->big_user->uid : 0,
  96. 'request_uri' => $base_root . request_uri(),
  97. 'referer' => $_SERVER['HTTP_REFERER'],
  98. 'ip' => ip_address(),
  99. 'timestamp' => REQUEST_TIME,
  100. );
  101. $message = 'Log entry added to test the dblog row limit. Entry #';
  102. for ($i = 0; $i < $count; $i++) {
  103. $log['message'] = $message . $i;
  104. dblog_watchdog($log);
  105. }
  106. }
  107. /**
  108. * Verify the logged in user has the desired access to the various dblog nodes.
  109. *
  110. * @param integer $response HTTP response code.
  111. */
  112. private function verifyReports($response = 200) {
  113. $quote = '&#039;';
  114. // View dblog help node.
  115. $this->drupalGet('admin/help/dblog');
  116. $this->assertResponse($response);
  117. if ($response == 200) {
  118. $this->assertText(t('Database logging'), t('DBLog help was displayed'));
  119. }
  120. // View dblog report node.
  121. $this->drupalGet('admin/reports/dblog');
  122. $this->assertResponse($response);
  123. if ($response == 200) {
  124. $this->assertText(t('Recent log messages'), t('DBLog report was displayed'));
  125. }
  126. // View dblog page-not-found report node.
  127. $this->drupalGet('admin/reports/page-not-found');
  128. $this->assertResponse($response);
  129. if ($response == 200) {
  130. $this->assertText(t('Top ' . $quote . 'page not found' . $quote . ' errors'), t('DBLog page-not-found report was displayed'));
  131. }
  132. // View dblog access-denied report node.
  133. $this->drupalGet('admin/reports/access-denied');
  134. $this->assertResponse($response);
  135. if ($response == 200) {
  136. $this->assertText(t('Top ' . $quote . 'access denied' . $quote . ' errors'), t('DBLog access-denied report was displayed'));
  137. }
  138. // View dblog event node.
  139. $this->drupalGet('admin/reports/event/1');
  140. $this->assertResponse($response);
  141. if ($response == 200) {
  142. $this->assertText(t('Details'), t('DBLog event node was displayed'));
  143. }
  144. }
  145. /**
  146. * Verify events.
  147. */
  148. private function verifyEvents() {
  149. // Invoke events.
  150. $this->doUser();
  151. $this->doNode('article');
  152. $this->doNode('blog');
  153. $this->doNode('page');
  154. $this->doNode('poll');
  155. // When a user account is canceled, any content they created remains but the
  156. // uid = 0. Their blog entry shows as "'s blog" on the home page. Records
  157. // in the watchdog table related to that user have the uid set to zero.
  158. }
  159. /**
  160. * Generate and verify user events.
  161. *
  162. */
  163. private function doUser() {
  164. // Set user variables.
  165. $name = $this->randomName();
  166. $pass = user_password();
  167. // Add user using form to generate add user event (which is not triggered by drupalCreateUser).
  168. $edit = array();
  169. $edit['name'] = $name;
  170. $edit['mail'] = $name . '@example.com';
  171. $edit['pass[pass1]'] = $pass;
  172. $edit['pass[pass2]'] = $pass;
  173. $edit['status'] = 1;
  174. $this->drupalPost('admin/people/create', $edit, t('Create new account'));
  175. $this->assertResponse(200);
  176. // Retrieve user object.
  177. $user = user_load_by_name($name);
  178. $this->assertTrue($user != NULL, t('User @name was loaded', array('@name' => $name)));
  179. $user->pass_raw = $pass; // Needed by drupalLogin.
  180. // Login user.
  181. $this->drupalLogin($user);
  182. // Logout user.
  183. $this->drupalLogout();
  184. // Fetch row ids in watchdog that relate to the user.
  185. $result = db_query('SELECT wid FROM {watchdog} WHERE uid = :uid', array(':uid' => $user->uid));
  186. foreach ($result as $row) {
  187. $ids[] = $row->wid;
  188. }
  189. $count_before = (isset($ids)) ? count($ids) : 0;
  190. $this->assertTrue($count_before > 0, t('DBLog contains @count records for @name', array('@count' => $count_before, '@name' => $user->name)));
  191. // Login the admin user.
  192. $this->drupalLogin($this->big_user);
  193. // Delete user.
  194. // We need to POST here to invoke batch_process() in the internal browser.
  195. $this->drupalPost('user/' . $user->uid . '/cancel', array('user_cancel_method' => 'user_cancel_reassign'), t('Cancel account'));
  196. // View the dblog report.
  197. $this->drupalGet('admin/reports/dblog');
  198. $this->assertResponse(200);
  199. // Verify events were recorded.
  200. // Add user.
  201. // Default display includes name and email address; if too long then email is replaced by three periods.
  202. $this->assertLogMessage(t('New user: %name (%email).', array('%name' => $name, '%email' => $user->mail)), t('DBLog event was recorded: [add user]'));
  203. // Login user.
  204. $this->assertLogMessage(t('Session opened for %name.', array('%name' => $name)), t('DBLog event was recorded: [login user]'));
  205. // Logout user.
  206. $this->assertLogMessage(t('Session closed for %name.', array('%name' => $name)), t('DBLog event was recorded: [logout user]'));
  207. // Delete user.
  208. $message = t('Deleted user: %name %email.', array('%name' => $name, '%email' => '<' . $user->mail . '>'));
  209. $message_text = truncate_utf8(filter_xss($message, array()), 56, TRUE, TRUE);
  210. // Verify full message on details page.
  211. $link = FALSE;
  212. if ($links = $this->xpath('//a[text()="' . html_entity_decode($message_text) . '"]')) {
  213. // Found link with the message text.
  214. $links = array_shift($links);
  215. foreach ($links->attributes() as $attr => $value) {
  216. if ($attr == 'href') {
  217. // Extract link to details page.
  218. $link = drupal_substr($value, strpos($value, 'admin/reports/event/'));
  219. $this->drupalGet($link);
  220. // Check for full message text on the details page.
  221. $this->assertRaw($message, t('DBLog event details was found: [delete user]'));
  222. break;
  223. }
  224. }
  225. }
  226. $this->assertTrue($link, t('DBLog event was recorded: [delete user]'));
  227. // Visit random URL (to generate page not found event).
  228. $not_found_url = $this->randomName(60);
  229. $this->drupalGet($not_found_url);
  230. $this->assertResponse(404);
  231. // View dblog page-not-found report page.
  232. $this->drupalGet('admin/reports/page-not-found');
  233. $this->assertResponse(200);
  234. // Check that full-length URL displayed.
  235. $this->assertText($not_found_url, t('DBLog event was recorded: [page not found]'));
  236. }
  237. /**
  238. * Generate and verify node events.
  239. *
  240. * @param string $type Content type.
  241. */
  242. private function doNode($type) {
  243. // Create user.
  244. $perm = array('create ' . $type . ' content', 'edit own ' . $type . ' content', 'delete own ' . $type . ' content');
  245. $user = $this->drupalCreateUser($perm);
  246. // Login user.
  247. $this->drupalLogin($user);
  248. // Create node using form to generate add content event (which is not triggered by drupalCreateNode).
  249. $edit = $this->getContent($type);
  250. $langcode = LANGUAGE_NONE;
  251. $title = $edit["title"];
  252. $this->drupalPost('node/add/' . $type, $edit, t('Save'));
  253. $this->assertResponse(200);
  254. // Retrieve node object.
  255. $node = $this->drupalGetNodeByTitle($title);
  256. $this->assertTrue($node != NULL, t('Node @title was loaded', array('@title' => $title)));
  257. // Edit node.
  258. $edit = $this->getContentUpdate($type);
  259. $this->drupalPost('node/' . $node->nid . '/edit', $edit, t('Save'));
  260. $this->assertResponse(200);
  261. // Delete node.
  262. $this->drupalPost('node/' . $node->nid . '/delete', array(), t('Delete'));
  263. $this->assertResponse(200);
  264. // View node (to generate page not found event).
  265. $this->drupalGet('node/' . $node->nid);
  266. $this->assertResponse(404);
  267. // View the dblog report (to generate access denied event).
  268. $this->drupalGet('admin/reports/dblog');
  269. $this->assertResponse(403);
  270. // Login the admin user.
  271. $this->drupalLogin($this->big_user);
  272. // View the dblog report.
  273. $this->drupalGet('admin/reports/dblog');
  274. $this->assertResponse(200);
  275. // Verify events were recorded.
  276. // Content added.
  277. $this->assertLogMessage(t('@type: added %title.', array('@type' => $type, '%title' => $title)), t('DBLog event was recorded: [content added]'));
  278. // Content updated.
  279. $this->assertLogMessage(t('@type: updated %title.', array('@type' => $type, '%title' => $title)), t('DBLog event was recorded: [content updated]'));
  280. // Content deleted.
  281. $this->assertLogMessage(t('@type: deleted %title.', array('@type' => $type, '%title' => $title)), t('DBLog event was recorded: [content deleted]'));
  282. // View dblog access-denied report node.
  283. $this->drupalGet('admin/reports/access-denied');
  284. $this->assertResponse(200);
  285. // Access denied.
  286. $this->assertText(t('admin/reports/dblog'), t('DBLog event was recorded: [access denied]'));
  287. // View dblog page-not-found report node.
  288. $this->drupalGet('admin/reports/page-not-found');
  289. $this->assertResponse(200);
  290. // Page not found.
  291. $this->assertText(t('node/@nid', array('@nid' => $node->nid)), t('DBLog event was recorded: [page not found]'));
  292. }
  293. /**
  294. * Create content based on content type.
  295. *
  296. * @param string $type Content type.
  297. * @return array Content.
  298. */
  299. private function getContent($type) {
  300. $langcode = LANGUAGE_NONE;
  301. switch ($type) {
  302. case 'poll':
  303. $content = array(
  304. "title" => $this->randomName(8),
  305. 'choice[new:0][chtext]' => $this->randomName(32),
  306. 'choice[new:1][chtext]' => $this->randomName(32),
  307. );
  308. break;
  309. default:
  310. $content = array(
  311. "title" => $this->randomName(8),
  312. "body[$langcode][0][value]" => $this->randomName(32),
  313. );
  314. break;
  315. }
  316. return $content;
  317. }
  318. /**
  319. * Create content update based on content type.
  320. *
  321. * @param string $type Content type.
  322. * @return array Content.
  323. */
  324. private function getContentUpdate($type) {
  325. switch ($type) {
  326. case 'poll':
  327. $content = array(
  328. 'choice[chid:1][chtext]' => $this->randomName(32),
  329. 'choice[chid:2][chtext]' => $this->randomName(32),
  330. );
  331. break;
  332. default:
  333. $langcode = LANGUAGE_NONE;
  334. $content = array(
  335. "body[$langcode][0][value]" => $this->randomName(32),
  336. );
  337. break;
  338. }
  339. return $content;
  340. }
  341. /**
  342. * Login an admin user, create dblog event, and test clearing dblog functionality through the admin interface.
  343. */
  344. protected function testDBLogAddAndClear() {
  345. global $base_root;
  346. // Get a count of how many watchdog entries there are.
  347. $count = db_query('SELECT COUNT(*) FROM {watchdog}')->fetchField();
  348. $log = array(
  349. 'type' => 'custom',
  350. 'message' => 'Log entry added to test the doClearTest clear down.',
  351. 'variables' => array(),
  352. 'severity' => WATCHDOG_NOTICE,
  353. 'link' => NULL,
  354. 'user' => $this->big_user,
  355. 'uid' => isset($this->big_user->uid) ? $this->big_user->uid : 0,
  356. 'request_uri' => $base_root . request_uri(),
  357. 'referer' => $_SERVER['HTTP_REFERER'],
  358. 'ip' => ip_address(),
  359. 'timestamp' => REQUEST_TIME,
  360. );
  361. // Add a watchdog entry.
  362. dblog_watchdog($log);
  363. // Make sure the table count has actually incremented.
  364. $this->assertEqual($count + 1, db_query('SELECT COUNT(*) FROM {watchdog}')->fetchField(), t('dblog_watchdog() added an entry to the dblog :count', array(':count' => $count)));
  365. // Login the admin user.
  366. $this->drupalLogin($this->big_user);
  367. // Now post to clear the db table.
  368. $this->drupalPost('admin/reports/dblog', array(), t('Clear log messages'));
  369. // Count rows in watchdog that previously related to the deleted user.
  370. $count = db_query('SELECT COUNT(*) FROM {watchdog}')->fetchField();
  371. $this->assertEqual($count, 0, t('DBLog contains :count records after a clear.', array(':count' => $count)));
  372. }
  373. /**
  374. * Test the dblog filter on admin/reports/dblog.
  375. */
  376. protected function testFilter() {
  377. $this->drupalLogin($this->big_user);
  378. // Clear log to ensure that only generated entries are found.
  379. db_delete('watchdog')->execute();
  380. // Generate watchdog entries.
  381. $type_names = array();
  382. $types = array();
  383. for ($i = 0; $i < 3; $i++) {
  384. $type_names[] = $type_name = $this->randomName();
  385. $severity = WATCHDOG_EMERGENCY;
  386. for ($j = 0; $j < 3; $j++) {
  387. $types[] = $type = array(
  388. 'count' => $j + 1,
  389. 'type' => $type_name,
  390. 'severity' => $severity++,
  391. );
  392. $this->generateLogEntries($type['count'], $type['type'], $type['severity']);
  393. }
  394. }
  395. // View the dblog.
  396. $this->drupalGet('admin/reports/dblog');
  397. // Confirm all the entries are displayed.
  398. $count = $this->getTypeCount($types);
  399. foreach ($types as $key => $type) {
  400. $this->assertEqual($count[$key], $type['count'], 'Count matched');
  401. }
  402. // Filter by each type and confirm that entries with various severities are
  403. // displayed.
  404. foreach ($type_names as $type_name) {
  405. $edit = array(
  406. 'type[]' => array($type_name),
  407. );
  408. $this->drupalPost(NULL, $edit, t('Filter'));
  409. // Count the number of entries of this type.
  410. $type_count = 0;
  411. foreach ($types as $type) {
  412. if ($type['type'] == $type_name) {
  413. $type_count += $type['count'];
  414. }
  415. }
  416. $count = $this->getTypeCount($types);
  417. $this->assertEqual(array_sum($count), $type_count, 'Count matched');
  418. }
  419. // Set filter to match each of the three type attributes and confirm the
  420. // number of entries displayed.
  421. foreach ($types as $key => $type) {
  422. $edit = array(
  423. 'type[]' => array($type['type']),
  424. 'severity[]' => array($type['severity']),
  425. );
  426. $this->drupalPost(NULL, $edit, t('Filter'));
  427. $count = $this->getTypeCount($types);
  428. $this->assertEqual(array_sum($count), $type['count'], 'Count matched');
  429. }
  430. // Clear all logs and make sure the confirmation message is found.
  431. $this->drupalPost('admin/reports/dblog', array(), t('Clear log messages'));
  432. $this->assertText(t('Database log cleared.'), t('Confirmation message found'));
  433. }
  434. /**
  435. * Get the log entry information form the page.
  436. *
  437. * @return
  438. * List of entries and their information.
  439. */
  440. protected function getLogEntries() {
  441. $entries = array();
  442. if ($table = $this->xpath('.//table[@id="admin-dblog"]')) {
  443. $table = array_shift($table);
  444. foreach ($table->tbody->tr as $row) {
  445. $entries[] = array(
  446. 'severity' => $this->getSeverityConstant($row['class']),
  447. 'type' => $this->asText($row->td[1]),
  448. 'message' => $this->asText($row->td[3]),
  449. 'user' => $this->asText($row->td[4]),
  450. );
  451. }
  452. }
  453. return $entries;
  454. }
  455. /**
  456. * Get the count of entries per type.
  457. *
  458. * @param $types
  459. * The type information to compare against.
  460. * @return
  461. * The count of each type keyed by the key of the $types array.
  462. */
  463. protected function getTypeCount(array $types) {
  464. $entries = $this->getLogEntries();
  465. $count = array_fill(0, count($types), 0);
  466. foreach ($entries as $entry) {
  467. foreach ($types as $key => $type) {
  468. if ($entry['type'] == $type['type'] && $entry['severity'] == $type['severity']) {
  469. $count[$key]++;
  470. break;
  471. }
  472. }
  473. }
  474. return $count;
  475. }
  476. /**
  477. * Get the watchdog severity constant corresponding to the CSS class.
  478. *
  479. * @param $class
  480. * CSS class attribute.
  481. * @return
  482. * The watchdog severity constant or NULL if not found.
  483. *
  484. * @ingroup logging_severity_levels
  485. */
  486. protected function getSeverityConstant($class) {
  487. // Reversed array from dblog_overview().
  488. $map = array(
  489. 'dblog-debug' => WATCHDOG_DEBUG,
  490. 'dblog-info' => WATCHDOG_INFO,
  491. 'dblog-notice' => WATCHDOG_NOTICE,
  492. 'dblog-warning' => WATCHDOG_WARNING,
  493. 'dblog-error' => WATCHDOG_ERROR,
  494. 'dblog-critical' => WATCHDOG_CRITICAL,
  495. 'dblog-alert' => WATCHDOG_ALERT,
  496. 'dblog-emerg' => WATCHDOG_EMERGENCY,
  497. );
  498. // Find the class that contains the severity.
  499. $classes = explode(' ', $class);
  500. foreach ($classes as $class) {
  501. if (isset($map[$class])) {
  502. return $map[$class];
  503. }
  504. }
  505. return NULL;
  506. }
  507. /**
  508. * Extract the text contained by the element.
  509. *
  510. * @param $element
  511. * Element to extract text from.
  512. * @return
  513. * Extracted text.
  514. */
  515. protected function asText(SimpleXMLElement $element) {
  516. if (!is_object($element)) {
  517. return $this->fail('The element is not an element.');
  518. }
  519. return trim(html_entity_decode(strip_tags($element->asXML())));
  520. }
  521. /**
  522. * Assert messages appear on the log overview screen.
  523. *
  524. * This function should be used only for admin/reports/dblog page, because it
  525. * check for the message link text truncated to 56 characters. Other dblog
  526. * pages have no detail links so contains a full message text.
  527. *
  528. * @param $log_message
  529. * The message to check.
  530. * @param $message
  531. * The message to pass to simpletest.
  532. */
  533. protected function assertLogMessage($log_message, $message) {
  534. $message_text = truncate_utf8(filter_xss($log_message, array()), 56, TRUE, TRUE);
  535. // After filter_xss() HTML entities should be converted to their characters
  536. // because assertLink() uses this string in xpath() to query DOM.
  537. $this->assertLink(html_entity_decode($message_text), 0, $message);
  538. }
  539. }