# Strange callback behavior

**URL:** <https://www.ruby-forum.com/t/strange-callback-behavior/97137>\
**Category:** Rails\
**Created:** [December 11, 2005, 4:25am UTC](https://www.ruby-forum.com/t/strange-callback-behavior/97137 "2005-12-11T04:25:36Z")\
**Posts on this page:** 3\
**Page:** 1

<div class="post-metadata">

**Author:** ![ryan.wood](https://www.ruby-forum.com/letter_avatar_proxy/v4/letter/r/df788c/32.png) [@ryan.wood](https://www.ruby-forum.com/u/ryan.wood)\
**Post date:** [December 11, 2005, 4:25am UTC](https://www.ruby-forum.com/t/strange-callback-behavior/97137/1 "2005-12-11T04:25:36Z")

</div>

I’m not sure if you guys can help on this one, but I’ll give it a  
shot. On my hosted site (running linux and RC5 (0.14.4)) I’m seeing  
that the before\_update callback is called multiple times on a single  
update. This is a prblem because I’m using it to hash a password and  
it’s getting double hashed.

What’s strange is that it works correctly on my WinXP dev box (on  
RC5), but when I publish the same code to the shared box, I have  
problems. I’ve added some additional logging to try to diagnose the  
problem. I noticed that the active record callback “before\_update”  
gets fired twice in a row on one update. On my dev box it only fires  
once. Any ideas on this one?

–Ryan

---

<div class="post-metadata">

**Author:** ![ryan.wood](https://www.ruby-forum.com/letter_avatar_proxy/v4/letter/r/df788c/32.png) [@ryan.wood](https://www.ruby-forum.com/u/ryan.wood)\
**Post date:** [December 11, 2005, 4:54am UTC](https://www.ruby-forum.com/t/strange-callback-behavior/97137/2 "2005-12-11T04:54:03Z")

</div>

I wanted to add a little code to see if that gave any additional  
insight.

> From my user class (based on login\_generator):

```
# Apply SHA1 encryption to the supplied password.
# We will additionally surround the password with a salt
# for additional security.
def self.sha1(pass)
  Digest::SHA1.hexdigest("#{salt}--#{pass}--")
end

before_create :l1, :crypt_password

# Before saving the record to database we will crypt the password
# using SHA1.
# We never store the actual password in the DB.
def crypt_password
  logger.debug " **Hashing password: #{password}.**"
  write_attribute "password", self.class.sha1(password)
  logger.debug " **Hashed password is #{password}.**"
end

before_update :l2, :crypt_unless_empty

#used only for temporary debug logging
def l1
  logger.debug "** before_create event called."
end

def l2
  logger.debug "** before_update event called."
end

# If the record is updated we will check if the password is empty.
# If its empty we assume that the user didn't want to change his
# password and just reset it to the old value.
def crypt_unless_empty
  # get original password for comparison
  user = self.class.find(self.id)

  if password.empty?
    # on update, blank password means that no change is desired
    self.password = user.password
  else
    # if the password is different from the original, assume
    # that it has been changed and needs hashing
    logger.debug "** Calling 'crypt_password' from 

```

‘crypt\_unless\_empty’."  
crypt\_password if password != user.password  
end  
end

In the UserController class:

def update  
begin  
@user = User.find(params[:id])  
logger.debug “\*\* Before updating user **"  
if @user.update\_attributes(params[:user])  
logger.debug "** User successully updated. \*\*”  
flash[:notice] = “#{@user.name} was successfully updated.”  
redirect\_to :action =\> ‘list’  
else  
load\_options  
render :action =\> ‘edit’  
end  
rescue Exception =\> ex  
flash[:notice] = ex  
edit  
render :action =\> ‘edit’  
end  
end

Snippet from the log:

Processing UserController#update (for 71.12.25.100 at 2005-12-10  
22:11:25) [POST]  
Parameters: {“user”=\>{“password\_confirmation”=\>“123123”,  
“role\_id”=\>“2”, “advertiser\_id”=\>“6”, “first\_name”=\>“Test”,  
“login”=\>“user”, “password”=\>“123123”, “last\_name”=\>“User”},  
“commit”=\>“Edit”, “action”=\>“update”, “id”=\>“11”,  
“controller”=\>“admin/user”}  
User Columns (0.000854) SHOW FIELDS FROM users  
Role Load (0.000322) SELECT \* FROM roles WHERE (roles.id = 1) LIMIT 1  
Role Columns (0.000570) SHOW FIELDS FROM roles  
User Load (0.000744) SELECT \* FROM users WHERE (users.id = ‘11’) LIMIT  
1  
\*\* Before updating user \*\*  
SQL (0.000108) BEGIN  
Role Load (0.000334) SELECT \* FROM roles WHERE (roles.id = 2) LIMIT 1  
User Load (0.000960) SELECT \* FROM users WHERE (login = ‘user’ AND id  
\<\> 11) LIMIT 1  
User Load (0.000692) SELECT \* FROM users WHERE (login = ‘user’ AND id  
\<\> 11) LIMIT 1  
\*\* before\_update event called.  
User Load (0.000858) SELECT \* FROM users WHERE (users.id = 11) LIMIT 1  
\*\* Calling ‘crypt\_password’ from ‘crypt\_unless\_empty’.  
\*\* Hashing password: 123123. \*\*  
\*\* Hashed password is e54d12732c6a871bbcbe8e42f8d4e8ebf420b780. \*\*  
\*\* before\_update event called.  
User Load (0.000737) SELECT \* FROM users WHERE (users.id = 11) LIMIT 1  
\*\* Calling ‘crypt\_password’ from ‘crypt\_unless\_empty’.  
\*\* Hashing password: e54d12732c6a871bbcbe8e42f8d4e8ebf420b780. \*\*  
\*\* Hashed password is f581de6ded936f92101b37805e84c81529eabb28. \*\*  
User Update (0.000262) UPDATE users SET `created_at` = ‘2005-12-09  
14:37:24’, `login` = ‘user’, `last_name` = ‘User’, `last_session_at` =  
NULL, `first_name` = ‘Test’, `role_id` = 2, `advertiser_id` = 6,  
`last_accessed_at` = NULL, `password` =  
‘f581de6ded936f92101b37805e84c81529eabb28’, `updated_at` = ‘2005-12-10  
22:11:25’ WHERE id = 11  
SQL (0.028787) COMMIT  
\*\* User successully updated. \*\*

You can see where it hashes the password twice because before\_update  
was fired twice. Any help is GREATLY appreciated. Thanks.

-Ryan

---

<div class="post-metadata">

**Author:** ![ryan.wood](https://www.ruby-forum.com/letter_avatar_proxy/v4/letter/r/df788c/32.png) [@ryan.wood](https://www.ruby-forum.com/u/ryan.wood)\
**Post date:** [December 11, 2005, 8:02pm UTC](https://www.ruby-forum.com/t/strange-callback-behavior/97137/3 "2005-12-11T20:02:57Z")

</div>

Anyone have any ideas on this? It’s driving me crazy.

I’ve also noticed that all of my validation errors are duplicating as  
well. It’s like called object.update\_attributes(@params[object]) is  
somehow running twice. Unfortunately, I can’t debug very well as it is  
only happening on a shared server. It started right after the upgrade  
to RC5, but is only happening on my User object that is using the  
login generator. Any help would really be appreciated.

–Ryan