Setter sometimes doesn't update the changes, and therefore, doesn't save later on.

[GeoffreyOnRails]

Steps to reproduce

Here is an issue that appears some times in one of our job, but that we don't manage to reproduce consistently. The assign_attributes, sometimes, does change my object values, but doesn't mark them as changed, and therefore won't be saved when I do a save! (no UPDATE SQL query sent).

class ExamReservation < ApplicationRecord
  belongs_to :selected_exam_center, class_name: "Location"
  # I removed all the stuff not related. There are a few callbacks, but nothing that should be related
  
  def my_flacky_method(some_params)
       # Initialize needed variables from some_params
      logger.warn("[DEBUG][my_method] Exam_reservation #{to_param}, before assign_attributes : object -> #{inspect}, object valid? -> #{valid?}, errors -> #{errors.full_messages}, changes -> #{changes}")
    assign_attributes(
      driving_exam_starts_at: starts_at, # Date
      status: Status::DRIVING_EXAM_BOOKED, #string
      comment: comment, #nil or string
      selected_exam_center: exam_center, #Location object
      automatic_booking: true
    )
    logger.warn("[DEBUG][my_method] Exam_reservation #{to_param}, before save - after assign_attributes : object -> #{inspect}, object valid? -> #{valid?}, errors -> #{errors.full_messages}, changes -> #{changes}")
    save!(validate: false)
    logger.warn("[DEBUG][my_method] Exam_reservation #{to_param}, after save : object -> #{inspect}, object valid? -> #{valid?}, errors -> #{errors.full_messages}, changes -> #{changes}")
  end
  reload
  logger.warn("[DEBUG][my_method] Error on #{to_param} after save : #{inspect}")
  end

Expected behavior

We would expect in our logs the object to have value modified, and the changes method to contain the values modified by the assign_attributes

Actual behavior

We DO have the fields modified in our object according to the logs (status, selected_exam_center_id...), however we have an empty value returned by the changes method, and therefore the save!(validate: false) does nothing. This behavior happens only sometimes though, even for the same object (doing it again with the same parameters sometimes passes.

Feb 20 12:49:47   W, [2024-02-20T11:49:47+00:002]  WARN -- ** BOOKING **: [DEBUG][my_method] Exam_reservation 6546388859, before assign_attributes : object -> #<ExamReservation id: 31493, student_id: 2216054, teacher_id: 1879574, training_end_date: "2024-01-11", inscription_date: "2024-01-11", priority_score: 80, status: "examen à planifier", driving_exam_starts_at: nil, urgent_driving_exam: false, teacher_comment: nil, created_at: "2024-01-11 19:26:06.618382000 +0100", updated_at: "2024-02-20 02:30:31.286590000 +0100", deadline: nil, bonus: [], comment: "Aucun créneau disponible pour l’instant, pour cett...", penalty_end_date: nil, selected_exam_center_id: nil, comment_updated_at: "2024-02-20 12:48:00.983422000 +0100", credits: nil, credits_consumed_at: "2024-02-19 09:54:49.217572000 +0100", reminder_mandate_sent_at: nil, automatic: false, reminder_credits_sent_at: nil, convocation_reminder_sent_at: nil>, object valid? -> true, errors -> [], changes -> {}

Feb 20 12:49:47   W, [2024-02-20T11:49:47+00:002]  WARN -- ** BOOKING **: [DEBUG][my_method] Exam_reservation 6546388859, before save - after assign_attributes : object -> #<ExamReservation id: 31493, student_id: 2216054, teacher_id: 1879574, training_end_date: "2024-01-11", inscription_date: "2024-01-11", priority_score: 80, status: "examen réservé", driving_exam_starts_at: "2024-03-06 09:00:00.000000000 +0100", urgent_driving_exam: false, teacher_comment: nil, created_at: "2024-01-11 19:26:06.618382000 +0100", updated_at: "2024-02-20 02:30:31.286590000 +0100", deadline: nil, bonus: [], comment: nil, penalty_end_date: nil, selected_exam_center_id: 277, comment_updated_at: "2024-02-20 12:48:00.983422000 +0100", credits: nil, credits_consumed_at: "2024-02-19 09:54:49.217572000 +0100", reminder_mandate_sent_at: nil, automatic: false, reminder_credits_sent_at: nil, convocation_reminder_sent_at: nil>, object valid? -> true, errors -> [], changes -> {}

Feb 20 12:49:47   W, [2024-02-20T11:49:47+00:002]  WARN -- ** BOOKING **: [DEBUG][my_method] Exam_reservation  6546388859, after save : object -> #<ExamReservation id: 31493, student_id: 2216054, teacher_id: 1879574, training_end_date: "2024-01-11", inscription_date: "2024-01-11", priority_score: 80, status: "examen réservé", driving_exam_starts_at: "2024-03-06 09:00:00.000000000 +0100", urgent_driving_exam: false, teacher_comment: nil, created_at: "2024-01-11 19:26:06.618382000 +0100", updated_at: "2024-02-20 02:30:31.286590000 +0100", deadline: nil, bonus: [], comment: nil, penalty_end_date: nil, selected_exam_center_id: 277, comment_updated_at: "2024-02-20 12:48:00.983422000 +0100", credits: nil, credits_consumed_at: "2024-02-19 09:54:49.217572000 +0100", reminder_mandate_sent_at: nil, automatic: false, reminder_credits_sent_at: nil, convocation_reminder_sent_at: nil>, object valid? -> true, errors -> [], changes -> {}

Feb 20 12:49:47   D, [2024-02-20T11:49:47+00:002] DEBUG -- ** BOOKING **:   ExamReservation Load (1.3ms)  SELECT "exam_reservations".* FROM "exam_reservations" WHERE "exam_reservations"."id" = 31493 LIMIT 1

Feb 20 12:49:48   W, [2024-02-20T11:49:48+00:002]  WARN -- ** BOOKING **: [DEBUG][apply_booking] Error on 6546388859 after save : -> #<ExamReservation id: 31493, student_id: 2216054, teacher_id: 1879574, training_end_date: "2024-01-11", inscription_date: "2024-01-11", priority_score: 80, status: "examen à planifier", driving_exam_starts_at: nil, urgent_driving_exam: false, teacher_comment: nil, created_at: "2024-01-11 19:26:06.618382000 +0100", updated_at: "2024-02-20 02:30:31.286590000 +0100", deadline: nil, bonus: [], comment: "Aucun créneau disponible pour l’instant, pour cett...", penalty_end_date: nil, selected_exam_center_id: nil, comment_updated_at: "2024-02-20 12:48:00.983422000 +0100", credits: nil, credits_consumed_at: "2024-02-19 09:54:49.217572000 +0100", reminder_mandate_sent_at: nil, automatic: false, reminder_credits_sent_at: nil, convocation_reminder_sent_at: nil>

System configuration

Rails version: 6.1.7.4

Ruby version: 3.1.0

Note : we didn't override the setter / getter method anywhere else.

> er = ExamReservation.find ...
> method = er.method(:status=)
=> #<Method: ExamReservation(id: integer, student_id: integer, teacher_id: integer, training_end_date: date, inscription_date: date, priority_score: integer, status: string, driving_exam_starts_at: datetime, urgent_driving_exam: boolean, teacher_comment: text, created_at: datetime, updated_at: datetime, deadline: date, bonus: jsonb, comment: string, penalty_end_date: date, selected_exam_center_id: integer, comment_updated_at: datetime, credits: integer, credits_consumed_at: datetime, reminder_mandate_sent_at: datetime, automatic: boolean, reminder_credits_sent_at: datetime, convocation_reminder_sent_at: datetime)(ExamReservation::GeneratedAttributeMethods)#status=(value) /app/vendor/bundle/ruby/3.1.0/gems/activemodel-6.1.7.4/lib/active_model/attribute_methods.rb:254>       
> method.super_method
=> nil
> er.method(:selected_exam_center)
=> #<Method: ExamReservation(id: integer, student_id: integer, teacher_id: integer, training_end_date: date, inscription_date: date, priority_score: integer, status: string, driving_exam_starts_at: datetime, urgent_driving_exam: boolean, teacher_comment: text, created_at: datetime, updated_at: datetime, deadline: date, bonus: jsonb, comment: string, penalty_end_date: date, selected_exam_center_id: integer, comment_updated_at: datetime, credits: integer, credits_consumed_at: datetime, reminder_mandate_sent_at: datetime, automatic: boolean, reminder_credits_sent_at: datetime, convocation_reminder_sent_at: datetime)(ExamReservation::GeneratedAssociationMethods)#selected_exam_center() /app/vendor/bundle/ruby/3.1.0/gems/activerecord-6.1.7.4/lib/active_record/associations/builder/association.rb:102>
> er.method(:selected_exam_center=)
=> #<Method: ExamReservation(id: integer, student_id: integer, teacher_id: integer, training_end_date: date, inscription_date: date, priority_score: integer, status: string, driving_exam_starts_at: datetime, urgent_driving_exam: boolean, teacher_comment: text, created_at: datetime, updated_at: datetime, deadline: date, bonus: jsonb, comment: string, penalty_end_date: date, selected_exam_center_id: integer, comment_updated_at: datetime, credits: integer, credits_consumed_at: datetime, reminder_mandate_sent_at: datetime, automatic: boolean, reminder_credits_sent_at: datetime, convocation_reminder_sent_at: datetime)(ExamReservation::GeneratedAssociationMethods)#selected_exam_center=(value) /app/vendor/bundle/ruby/3.1.0/gems/activerecord-6.1.7.4/lib/active_record/associations/builder/association.rb:110>                                  
 > er.method(:selected_exam_center=).super_method
nil

I know that I don't have something to reproduce, but the bug happens from time to time, feel free to ask any more data that could help clarify the bug.