tests/phpunit/api/v3/LoggingTest.php

   1 <?php
   2 /*
   3  +--------------------------------------------------------------------+
   4  | Copyright CiviCRM LLC. All rights reserved.                        |
   5  |                                                                    |
   6  | This work is published under the GNU AGPLv3 license with some      |
   7  | permitted exceptions and without any warranty. For full license    |
   8  | and copyright information, see https://civicrm.org/licensing       |
   9  +--------------------------------------------------------------------+
  10  */
  11
  12 /**
  13  * Test class for Logging API.
  14  *
  15  * @package CiviCRM
  16  * @group headless
  17  */
  18 class api_v3_LoggingTest extends CiviUnitTestCase {
  19
  20   /**
  21    * Sets up the fixture, for example, opens a network connection.
  22    *
  23    * This method is called before a test is executed.
  24    */
  25   protected function setUp() {
  26     $this->ensureTempColIsCleanedUp();
  27     parent::setUp();
  28   }
  29
  30   /**
  31    * Clean up log tables.
  32    */
  33   protected function tearDown() {
  34     $this->quickCleanup(['civicrm_email', 'civicrm_address']);
  35     parent::tearDown();
  36     $this->callAPISuccess('Setting', 'create', ['logging' => FALSE]);
  37     $schema = new CRM_Logging_Schema();
  38     $schema->dropAllLogTables();
  39     CRM_Core_DAO::executeQuery("DELETE FROM civicrm_setting WHERE name LIKE 'logg%'");
  40   }
  41
  42   /**
  43    * Test that logging is successfully enabled and disabled.
  44    */
  45   public function testEnableDisableLogging() {
  46     $this->assertEquals(0, $this->callAPISuccessGetValue('Setting', ['name' => 'logging']));
  47     $this->assertLoggingEnabled(FALSE);
  48
  49     $this->callAPISuccess('Setting', 'create', ['logging' => TRUE]);
  50     $this->assertLoggingEnabled(TRUE);
  51     $this->checkLogTableCreated();
  52     $this->checkTriggersCreated(TRUE);
  53     // Create a contact to make sure they aren't borked.
  54     $this->individualCreate();
  55     $this->assertTrue($this->callAPISuccessGetValue('Setting', ['name' => 'logging']));
  56     $this->assertEquals(1, $this->callAPISuccessGetValue('Setting', ['name' => 'logging_all_tables_uniquid']));
  57     $this->assertEquals(
  58       date('Y-m-d'),
  59       date('Y-m-d', strtotime($this->callAPISuccessGetValue('Setting', ['name' => 'logging_uniqueid_date'])))
  60     );
  61
  62     $this->callAPISuccess('Setting', 'create', ['logging' => FALSE]);
  63     $this->assertEquals(0, $this->callAPISuccessGetValue('Setting', ['name' => 'logging']));
  64     $this->assertLoggingEnabled(FALSE);
  65   }
  66
  67   /**
  68    * Test that logging is successfully enabled and disabled.
  69    */
  70   public function testEnableDisableLoggingWithTriggerHook() {
  71     $this->hookClass->setHook('civicrm_alterLogTables', [$this, 'innodbLogTableSpec']);
  72     $this->callAPISuccess('Setting', 'create', ['logging' => TRUE]);
  73     $this->checkINNODBLogTableCreated();
  74     $this->checkTriggersCreated(TRUE);
  75     // Create a contact to make sure they aren't borked.
  76     $this->individualCreate();
  77     $this->callAPISuccess('Setting', 'create', ['logging' => FALSE]);
  78   }
  79
  80   /**
  81    * Check responsible creation when old structure log table exists.
  82    *
  83    * When an existing table exists NEW tables will have the varchar type for log_conn_id.
  84    *
  85    * Existing tables will be unchanged, and the trigger will use log_conn_id
  86    * rather than uniqueId to be consistent across the tables.
  87    *
  88    * The settings for unique id will not be set.
  89    */
  90   public function testEnableLoggingLegacyLogTableExists() {
  91     $this->createLegacyStyleContactLogTable();
  92     $this->callAPISuccess('Setting', 'create', ['logging' => TRUE]);
  93     $this->checkTriggersCreated(FALSE);
  94     $this->assertEquals(0, $this->callAPISuccessGetValue('Setting', ['name' => 'logging_all_tables_uniquid']));
  95     $this->assertEmpty($this->callAPISuccessGetValue('Setting', ['name' => 'logging_uniqueid_date']));
  96   }
  97
  98   /**
  99    * Check we can update legacy log tables using the api function.
 100    */
 101   public function testUpdateLegacyLogTable() {
 102     $this->createLegacyStyleContactLogTable();
 103     $this->callAPISuccess('Setting', 'create', ['logging' => TRUE]);
 104     $this->callAPISuccess('System', 'updatelogtables', []);
 105     $this->checkLogTableCreated();
 106     $this->checkTriggersCreated(TRUE);
 107     $this->assertEquals(0, $this->callAPISuccessGetValue('Setting', ['name' => 'logging_all_tables_uniquid']));
 108     $this->assertEquals(
 109       date('Y-m-d'),
 110       date('Y-m-d', strtotime($this->callAPISuccessGetValue('Setting', ['name' => 'logging_uniqueid_date'])))
 111     );
 112   }
 113
 114   /**
 115    * Check if we can create missing log tables using api.
 116    */
 117   public function testCreateMissingLogTables() {
 118     $this->callAPISuccess('Setting', 'create', ['logging' => TRUE]);
 119     CRM_Core_DAO::executeQuery("DROP TABLE log_civicrm_contact");
 120     $this->callAPISuccess('System', 'createmissinglogtables', []);
 121
 122     //Assert if log_civicrm_contact is created.
 123     $this->checkLogTableCreated();
 124   }
 125
 126   /**
 127    * Check we can update legacy log tables using the api function.
 128    */
 129   public function testUpdateLogTableHookINNODB() {
 130     $this->createLegacyStyleContactLogTable();
 131     $this->callAPISuccess('Setting', 'create', ['logging' => TRUE]);
 132     $this->hookClass->setHook('civicrm_alterLogTables', [$this, 'innodbLogTableSpec']);
 133     $this->callAPISuccess('System', 'updatelogtables', []);
 134     $this->checkINNODBLogTableCreated();
 135     $this->checkTriggersCreated(TRUE);
 136     // Make sure that the absence of a hook specifying INNODB does not cause revert to archive.
 137     // Only a positive action, like specifying ARCHIVE in a hook should trigger a change back to archive.
 138     $this->hookClass->setHook('civicrm_alterLogTables', []);
 139     $schema = new CRM_Logging_Schema();
 140     $spec = $schema->getLogTableSpec();
 141     $this->assertEquals([], $spec['civicrm_contact']);
 142     $this->callAPISuccess('System', 'updatelogtables', []);
 143     $this->checkINNODBLogTableCreated();
 144     // Check if API creates new indexes when they're added by hook
 145     $this->hookClass->setHook('civicrm_alterLogTables', [$this, 'innodbLogTableSpecNewIndex']);
 146     $this->callAPISuccess('System', 'updatelogtables', []);
 147     $this->checkINNODBLogTableCreated();
 148     $this->assertContains('KEY `index_log_user_id` (`log_user_id`)', $this->checkLogTableCreated());
 149   }
 150
 151   /**
 152    * Check that if a field is added then the trigger is updated on refresh.
 153    */
 154   public function testRebuildTriggerAfterSchemaChange() {
 155     $this->callAPISuccess('Setting', 'create', ['logging' => TRUE]);
 156     $tables = ['civicrm_acl', 'civicrm_website'];
 157     foreach ($tables as $table) {
 158       CRM_Core_DAO::executeQuery("ALTER TABLE $table ADD column temp_col INT(10)");
 159     }
 160
 161     $schema = new CRM_Logging_Schema();
 162     $schema->fixSchemaDifferencesForAll(TRUE);
 163
 164     foreach ($tables as $table) {
 165       $this->assertTrue($this->checkColumnExistsInTable('log_' . $table, 'temp_col'), 'log_' . $table . ' has temp_col');
 166       $dao = CRM_Core_DAO::executeQuery("SHOW TRIGGERS LIKE '{$table}'");
 167       while ($dao->fetch()) {
 168         $this->assertContains('temp_col', $dao->Statement);
 169       }
 170     }
 171     CRM_Core_DAO::executeQuery("ALTER TABLE civicrm_acl DROP column temp_col");
 172     CRM_Core_DAO::executeQuery("ALTER TABLE civicrm_website DROP column temp_col");
 173   }
 174
 175   /**
 176    * Use a hook to declare an INNODB engine for the contact log table.
 177    *
 178    * @param array $logTableSpec
 179    */
 180   public function innodbLogTableSpec(&$logTableSpec) {
 181     $logTableSpec['civicrm_contact'] = [
 182       'engine' => 'InnoDB',
 183       'engine_config' => 'ROW_FORMAT=COMPRESSED KEY_BLOCK_SIZE=4',
 184       'indexes' => [
 185         'index_id' => 'id',
 186         'index_log_conn_id' => 'log_conn_id',
 187         'index_log_date' => 'log_date',
 188       ],
 189     ];
 190   }
 191
 192   /**
 193    * Set log engine to InnoDB and add one index
 194    *
 195    * @param array $logTableSpec
 196    */
 197   public function innodbLogTableSpecNewIndex(&$logTableSpec) {
 198     $logTableSpec['civicrm_contact'] = [
 199       'engine' => 'InnoDB',
 200       'engine_config' => 'ROW_FORMAT=COMPRESSED KEY_BLOCK_SIZE=4',
 201       'indexes' => [
 202         'index_id' => 'id',
 203         'index_log_conn_id' => 'log_conn_id',
 204         'index_log_date' => 'log_date',
 205         // new index
 206         'index_log_user_id' => 'log_user_id',
 207       ],
 208     ];
 209   }
 210
 211   /**
 212    * Check the log tables were created and look OK.
 213    */
 214   protected function checkLogTableCreated() {
 215     $dao = CRM_Core_DAO::executeQuery("SHOW CREATE TABLE log_civicrm_contact");
 216     $dao->fetch();
 217     $this->assertEquals('log_civicrm_contact', $dao->Table);
 218     $tableField = 'Create_Table';
 219     $this->assertContains('`log_date` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP,', $dao->$tableField);
 220     $this->assertContains('`log_conn_id` varchar(17)', $dao->$tableField);
 221     return $dao->$tableField;
 222   }
 223
 224   /**
 225    * Check the log tables were created and reflect the INNODB hook.
 226    */
 227   protected function checkINNODBLogTableCreated() {
 228     $createTableString = $this->checkLogTableCreated();
 229     $this->assertContains('ENGINE=InnoDB', $createTableString);
 230     $this->assertContains('ROW_FORMAT=COMPRESSED KEY_BLOCK_SIZE=4', $createTableString);
 231     $this->assertContains('KEY `index_id` (`id`),', $createTableString);
 232   }
 233
 234   /**
 235    * Check the triggers were created and look OK.
 236    *
 237    * @param bool $unique
 238    *   Is the site configured for unique logging connection IDs per CRM-18193?
 239    */
 240   protected function checkTriggersCreated($unique) {
 241     $dao = CRM_Core_DAO::executeQuery("SHOW TRIGGERS LIKE 'civicrm_contact'");
 242     while ($dao->fetch()) {
 243       if ($dao->Timing == 'After') {
 244         if ($unique) {
 245           $this->assertContains('@uniqueID', $dao->Statement);
 246         }
 247         else {
 248           $this->assertContains('CONNECTION_ID()', $dao->Statement);
 249         }
 250       }
 251     }
 252   }
 253
 254   /**
 255    * Assert logging is enabled or disabled as per input parameter.
 256    *
 257    * @param bool $expected
 258    *   Do we expect it to be enabled.
 259    */
 260   protected function assertLoggingEnabled($expected) {
 261     $schema = new CRM_Logging_Schema();
 262     $this->assertTrue($schema->isEnabled() === $expected);
 263   }
 264
 265   /**
 266    * Create the contact log table with log_conn_id as an integer.
 267    */
 268   protected function createLegacyStyleContactLogTable() {
 269     CRM_Core_DAO::executeQuery("
 270       CREATE TABLE log_civicrm_contact
 271       (log_conn_id INT NULL, log_user_id INT NULL, log_date timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP)
 272       ENGINE=ARCHIVE
 273       (SELECT c.*, CURRENT_TIMESTAMP as log_date, 'Initialize' as 'log_action'
 274       FROM civicrm_contact c)
 275     ");
 276   }
 277
 278   /**
 279    * Test changes can be reverted.
 280    */
 281   public function testRevert() {
 282     $contactId = $this->individualCreate();
 283     $this->callAPISuccess('Setting', 'create', ['logging' => TRUE]);
 284     // Pause for one second here to ensure the timestamps between the first create action
 285     // and the second differ.
 286     sleep(1);
 287     CRM_Core_DAO::executeQuery("SET @uniqueID = 'woot'");
 288     $timeStamp = date('Y-m-d H:i:s');
 289     $this->callAPISuccess('Contact', 'create', [
 290       'id' => $contactId,
 291       'first_name' => 'Dopey',
 292       'api.email.create' => ['email' => 'dopey@mail.com'],
 293     ]
 294     );
 295     $email = $this->callAPISuccessGetSingle('email', ['email' => 'dopey@mail.com']);
 296     $this->callAPIAndDocument('Logging', 'revert', ['log_conn_id' => 'woot', 'log_date' => $timeStamp], __FILE__, 'Revert');
 297     $this->assertEquals('Anthony', $this->callAPISuccessGetValue('contact', ['id' => $contactId, 'return' => 'first_name']));
 298     $this->callAPISuccessGetCount('Email', ['id' => $email['id']], 0);
 299   }
 300
 301   /**
 302    * Test changes can be reverted.
 303    */
 304   public function testRevertNoDate() {
 305     $contactId = $this->individualCreate();
 306     $this->callAPISuccess('Setting', 'create', ['logging' => TRUE]);
 307     // Pause for one second here to ensure the timestamps between the first create action
 308     // and the second differ.
 309     sleep(1);
 310     CRM_Core_DAO::executeQuery("SET @uniqueID = 'Wot woot'");
 311     $this->callAPISuccess('Contact', 'create', [
 312       'id' => $contactId,
 313       'first_name' => 'Dopey',
 314       'api.email.create' => ['email' => 'dopey@mail.com'],
 315     ]);
 316     $email = $this->callAPISuccessGetSingle('email', ['email' => 'dopey@mail.com']);
 317     $this->callAPISuccess('Logging', 'revert', ['log_conn_id' => 'Wot woot']);
 318     $this->assertEquals('Anthony', $this->callAPISuccessGetValue('contact', ['id' => $contactId, 'return' => 'first_name']));
 319     $this->callAPISuccessGetCount('Email', ['id' => $email['id']], 0);
 320   }
 321
 322   /**
 323    * Ensure that a limited list of tables can be reverted.
 324    *
 325    * In this case ONLY civicrm_address is reverted and we check that email, contact and contribution
 326    * entities have not been.
 327    *
 328    * @throws \Exception
 329    */
 330   public function testRevertRestrictedTables() {
 331
 332     CRM_Core_DAO::executeQuery("SET @uniqueID = 'temp name'");
 333     $this->callAPISuccess('Setting', 'create', ['logging' => TRUE]);
 334
 335     $contactId = $this->individualCreate(['address' => [['street_address' => '27 Cool way', 'location_type_id' => 1]]]);
 336     $contact = $this->callAPISuccessGetSingle('contact', ['id' => $contactId]);
 337     $this->assertEquals('Anthony', $contact['first_name']);
 338     $this->assertEquals('anthony_anderson@civicrm.org', $contact['email']);
 339     $this->assertEquals('27 Cool way', $contact['street_address']);
 340
 341     sleep(1);
 342     CRM_Core_DAO::executeQuery("SET @uniqueID = 'bitty bot bot'");
 343     $this->callAPISuccess('Contact', 'create', [
 344       'id' => $contactId,
 345       'first_name' => 'Dopey',
 346       'address' => [['street_address' => '25 Dorky way', 'location_type_id' => 1]],
 347       'email' => ['email' => ['email' => 'dopey@mail.com', 'location_type_id' => 1]],
 348       'api.contribution.create' => ['financial_type_id' => 'Donation', 'receive_date' => 'now', 'total_amount' => 10],
 349     ]);
 350     $contact = $this->callAPISuccessGetSingle('contact', ['id' => $contactId, 'return' => ['first_name', 'email', 'modified_date', 'street_address']]);
 351     $this->assertEquals('Dopey', $contact['first_name']);
 352     $this->assertEquals('dopey@mail.com', $contact['email']);
 353     $this->assertEquals('25 Dorky way', $contact['street_address']);
 354     $modifiedDate = $contact['modified_date'];
 355     // To protect against the modified date not changing due to the updates being too close together.
 356     sleep(1);
 357     $loggings = $this->callAPISuccess('Logging', 'get', ['log_conn_id' => 'bitty bot bot', 'tables' => ['civicrm_address']]);
 358     $this->assertEquals('civicrm_address', $loggings['values'][0]['table'], CRM_Core_DAO::executeQuery('SELECT * FROM log_civicrm_address')->toArray());
 359     $this->assertEquals(1, $loggings['count'], CRM_Core_DAO::executeQuery('SELECT * FROM log_civicrm_address')->toArray());
 360     $this->assertEquals('27 Cool way', $loggings['values'][0]['from']);
 361     $this->assertEquals('25 Dorky way', $loggings['values'][0]['to']);
 362     $this->callAPISuccess('Logging', 'revert', ['log_conn_id' => 'bitty bot bot', 'tables' => ['civicrm_address']]);
 363
 364     $contact = $this->callAPISuccessGetSingle('contact', ['id' => $contactId, 'return' => ['first_name', 'email', 'modified_date', 'street_address']]);
 365     $this->assertEquals('Dopey', $contact['first_name']);
 366     $this->assertEquals('dopey@mail.com', $contact['email']);
 367     $this->assertEquals('27 Cool way', $contact['street_address']);
 368     $this->callAPISuccessGetCount('Contribution', ['contact_id' => $contactId], 1);
 369     $this->assertTrue(strtotime($modifiedDate) < strtotime($contact['modified_date']));
 370   }
 371
 372   /**
 373    * Test changes can be reverted.
 374    */
 375   public function testRevertNoDateNotUnique() {
 376     $contactId = $this->individualCreate();
 377     $this->callAPISuccess('Setting', 'create', ['logging' => TRUE]);
 378     CRM_Core_DAO::executeQuery("SET @uniqueID = 'Wopity woot'");
 379     $this->callAPISuccess('Contact', 'create', [
 380       'id' => $contactId,
 381       'first_name' => 'Dopey',
 382       'api.email.create' => ['email' => 'dopey@mail.com'],
 383     ]);
 384     $this->callAPISuccess('Setting', 'create', ['logging_all_tables_uniquid' => FALSE]);
 385     $this->callAPISuccess('Setting', 'create', ['logging_uniqueid_date' => date('Y-m-d H:i:s', strtotime('+ 1 hour'))]);
 386     $this->callAPIFailure(
 387       'Logging',
 388       'revert',
 389       ['log_conn_id' => 'Wopity woot'],
 390       'The connection date must be passed in to disambiguate this logging entry per CRM-18193'
 391     );
 392   }
 393
 394   /**
 395    * Test changes can be retrieved.
 396    */
 397   public function testGet() {
 398     $contactId = $this->individualCreate();
 399     $this->callAPISuccess('Setting', 'create', ['logging' => TRUE]);
 400     CRM_Core_DAO::executeQuery("SET @uniqueID = 'wooty woot'");
 401     // Add delay so the update is actually enough after the create that the timestamps differ
 402     sleep(1);
 403     $timeStamp = date('Y-m-d H:i:s');
 404     $this->callAPISuccess('Contact', 'create', [
 405       'id' => $contactId,
 406       'first_name' => 'Dopey',
 407       'last_name' => 'Dwarf',
 408       'api.email.create' => ['email' => 'dopey@mail.com'],
 409     ]);
 410     $this->callAPISuccessGetSingle('email', ['email' => 'dopey@mail.com']);
 411     $diffs = $this->callAPISuccess('Logging', 'get', ['log_conn_id' => 'wooty woot', 'log_date' => $timeStamp], __FUNCTION__, __FILE__);
 412     $this->assertLoggingIncludes($diffs['values'], ['to' => 'Dwarf, Dopey']);
 413     $this->assertLoggingIncludes($diffs['values'], ['to' => 'Mr. Dopey Dwarf II', 'table' => 'civicrm_contact', 'action' => 'Update', 'field' => 'display_name']);
 414     $this->assertLoggingIncludes($diffs['values'], ['to' => 'dopey@mail.com', 'table' => 'civicrm_email', 'action' => 'Insert', 'field' => 'email']);
 415   }
 416
 417   /**
 418    * Test changes can be retrieved without log_date being required.
 419    */
 420   public function testGetNoDate() {
 421     $contactId = $this->individualCreate();
 422     $this->callAPISuccess('Setting', 'create', ['logging' => TRUE]);
 423     CRM_Core_DAO::executeQuery("SET @uniqueID = 'wooty wop wop'");
 424     // Perhaps if initialize & create are exactly the same time it can't cope.
 425     // 1 second delay
 426     sleep(1);
 427     $this->callAPISuccess('Contact', 'create', [
 428       'id' => $contactId,
 429       'first_name' => 'Dopey',
 430       'last_name' => 'Dwarf',
 431       'api.email.create' => ['email' => 'dopey@mail.com'],
 432     ]);
 433     $this->callAPISuccessGetSingle('email', ['email' => 'dopey@mail.com']);
 434     $diffs = $this->callAPIAndDocument('Logging', 'get', ['log_conn_id' => 'wooty wop wop'], __FUNCTION__, __FILE__);
 435     $this->assertLoggingIncludes($diffs['values'], ['to' => 'Dwarf, Dopey']);
 436     $this->assertLoggingIncludes($diffs['values'], ['to' => 'Mr. Dopey Dwarf II', 'table' => 'civicrm_contact', 'action' => 'Update', 'field' => 'display_name']);
 437     $this->assertLoggingIncludes($diffs['values'], ['to' => 'dopey@mail.com', 'table' => 'civicrm_email', 'action' => 'Insert', 'field' => 'email']);
 438   }
 439
 440   /**
 441    * Assert the values in the $expect array in included in the logging diff.
 442    *
 443    * @param array $diffs
 444    * @param array $expect
 445    *
 446    * @return bool
 447    * @throws \CRM_Core_Exception
 448    */
 449   public function assertLoggingIncludes($diffs, $expect) {
 450     foreach ($diffs as $diff) {
 451       foreach ($expect as $expectKey => $expectValue) {
 452         if ($diff[$expectKey] != $expectValue) {
 453           continue;
 454         }
 455         return TRUE;
 456       }
 457     }
 458     throw new CRM_Core_Exception("No match found for key : $expectKey with value : $expectValue" . print_r($diffs, 1));
 459   }
 460
 461   /**
 462    * Check if the column exists in the table.
 463    *
 464    * @param string $table
 465    * @param string $column
 466    *
 467    * @return bool
 468    */
 469   protected function checkColumnExistsInTable($table, $column) {
 470     $dao = CRM_Core_DAO::executeQuery("SHOW columns FROM {$table} WHERE Field = '{$column}'");
 471     $dao->fetch(TRUE);
 472     return ($dao->N == 1);
 473   }
 474
 475   /**
 476    * Helper for when it crashes and clean up needs to be done.
 477    */
 478   protected function ensureTempColIsCleanedUp() {
 479     if ($this->checkColumnExistsInTable('civicrm_acl', 'temp_col')) {
 480       CRM_Core_DAO::executeQuery("ALTER TABLE civicrm_acl DROP Column temp_col");
 481       CRM_Core_DAO::executeQuery("ALTER TABLE civicrm_website DROP Column temp_col");
 482     }
 483   }
 484
 485 }