Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-15602

server occasionally does not update timestamp for column (ON UPDATE CURRENT_TIMESTAMP)

    XMLWordPrintable

Details

    Description

      I have a table with a timestamp column with "ON UPDATE CURRENT_TIMESTAMP" that behaves correctly almost always. but occasionally that timestamp column is NOT modified when the row is updated.
      the table definition is similar to:

      CREATE TABLE `table_xyz` (
      		 
        `id` int(11) unsigned NOT NULL AUTO_INCREMENT,
      		 
        `object_id` int(11) unsigned NOT NULL,
      		 
        `last_modified` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP,
      		 
        `deleted` tinyint(1) NOT NULL DEFAULT '0',
      		 
        `created_on` timestamp NOT NULL DEFAULT '1970-01-01 00:00:01',
      		 
        PRIMARY KEY (`id`),
      		 
        UNIQUE KEY `uq_object_id` (`object_id`),
      		 
        KEY `last_modified` (`last_modified`)
      		 
      ) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_unicode_ci;

      this works correctly the majority of the time:

      insert into table_xyz (object_id) values (44);
      		 
      update table_xyz set deleted = 1 where id in (1) and deleted = 0;

      occasionally, mariadb just seems to ignore the ON UPDATE CURRENT_TIMESTAMP clause though. here is an excerpt from our binlog with annotated row events. the table was updated at 180319 1:13:12 (utc) which is later than the epoch shows below. column 13 corresponds to `last_modifed`. note that column 13 is not changed in the row update in the binlog (to be clear, it is not changed on the master server itself either). 1521337159 (the existing value of the row when the update occurred) is March 18, 2018 1:39:19 AM which is before the event shown here.

      # at 945450098
      		 
      #180319  1:13:12 server id 371  end_log_pos 945450138   GTID 0-371-5349209007 cid=6416620345 trans
      		 
      /*!100001 SET @@session.gtid_seq_no=5349209007*//*!*/;
      		 
      BEGIN
      		 
      /*!*/;
      		 
      # at 945450138
      		 
      ...
      		 
      #180319  1:13:12 server id 371  end_log_pos 945450884   Annotate_rows:
      		 
      #Q> /*trace_id:3a3cdc48756e1528,span_id:de5181b87d8857b7,application:abc:LineItemController,action:doDelete,timestamp:1521421992*/ UPDATE db.table_xyz SET deleted = 1 WHERE id  IN (432854801) AND object_type = 'xyz_abc' AND deleted = 0
      		 
      #180319  1:13:12 server id 371  end_log_pos 945450974   Table_map: `db`.`table_xyz` mapped to number 25 (has triggers)
      		 
      # at 945450974
      		 
      #180319  1:13:12 server id 371  end_log_pos 945451136   Update_rows: table id 25 flags: STMT_END_F
      		 
      ### UPDATE `db`.`table_xyz`
      		 
      ### WHERE
      		 
      ###   @1=432854801
      		 
      ###   @2=1
      		 
      ###   @3=8
      		 
      ###   @4=3
      		 
      ###   @5=5543740
      		 
      ###   @6=2759860
      		 
      ###   @7=NULL
      		 
      ###   @8=85000
      		 
      ###   @9=NULL
      		 
      ###   @10=6538
      		 
      ###   @11=1.00
      		 
      ###   @12=-4 (252)
      		 
      ###   @13=1521337159
      		 
      ###   @14=0
      		 
      ###   @15=1
      		 
      ###   @16=1
      		 
      ###   @17=NULL
      		 
      ###   @18='US/Eastern'
      		 
      ###   @19=1
      		 
      ###   @20=1521336850
      		 
      ###   @21=NULL
      		 
      ###   @22=NULL
      		 
      ### SET
      		 
      ###   @1=432854801
      		 
      ###   @2=1
      		 
      ###   @3=8
      		 
      ###   @4=3
      		 
      ###   @5=5543740
      		 
      ###   @6=2759860
      		 
      ###   @7=NULL
      		 
      ###   @8=85000
      		 
      ###   @9=NULL
      		 
      ###   @10=6538
      		 
      ###   @11=1.00
      		 
      ###   @12=-4 (252)
      		 
      ###   @13=1521337159
      		 
      ###   @14=1
      		 
      ###   @15=1
      		 
      ###   @16=1
      		 
      ###   @17=NULL
      		 
      ###   @18='US/Eastern'
      		 
      ###   @19=1
      		 
      ###   @20=1521336850
      		 
      ###   @21=NULL
      		 
      ###   @22=NULL
      		 
      # at 945451136
      		 
      # at 945451410
      		 
      ...
      		 
      #180319  1:13:12 server id 371  end_log_pos 945456124   Xid = 6416620548
      		 
      COMMIT/*!*/;

      at regular intervals we have application logic that builds complete snapshots of states of numerous objects. we detect faults when there are clear violations of object states between parent-child object relationships. so it is likely this logic is catching every occurrence of this issue on tables where we have those relationships whereas many users may not be noticing if this happens. of course, we also have many tables that don't have such relationships so in those cases we may not be aware this is even happening.

      I have found two somewhat slightly related tickets which I have linked. also note that we recently upgraded from version 10.0.20 to 10.1.28. we were not experiencing this issue while on version 10.0.20. our application logic has not changed since we upgraded to 10.1.28.

      Is there some sequence of events that could cause this? any known related issues that might explain it?? thanks!!

      Attachments

        Issue Links

          relates to

          Bug - A problem which impairs or prevents the functions of the product. MDEV-15710 server occasionally does not not use correct 'DEFAULT CURRENT_TIMESTAMP' on insert

          • Major - Major loss of function.
          • Closed

          Bug - A problem which impairs or prevents the functions of the product. MDEV-6849 ON UPDATE CURRENT_TIMESTAMP doesn't always work

          • Blocker - Blocks development and/or testing work, production could not run.
          • Closed

          Bug - A problem which impairs or prevents the functions of the product. MDEV-14605 ON UPDATE CURRENT_TIMESTAMP fields by multi-table UPDATE are not logged with binlog_row_image=MINIMAL

          • Critical - Crashes, loss of data, severe memory leak.
          • Closed

          Activity

            People

              Unassigned Unassigned
              chada chad ambrosius
              Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Git Integration

                  Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.