Missing user_stat record causes login to crash


(Michael - DiscourseHosting.com) #1

After updating all our forums to v0.9.7 last Friday we’ve received some complaints about users unable to login.

We’ve done some investigation and we found that the common trigger of this bug was that those users didn’t have a user_stat database record.

Upon login, the following happens:

[RAILS_ROOT]/lib/auth/default_current_user_provider.rb:35:in `current_user'

    if current_user
      current_user.update_last_seen!
      current_user.update_ip_address!(request.ip)
    end

Then update_last_seen is called:

[RAILS_ROOT]/app/models/user.rb:286:in `update_last_seen!'

 def update_last_seen!(now=nil)
    now ||= Time.zone.now
    now_date = now.to_date

    # Only update last seen once every minute
    redis_key = "user:#{self.id}:#{now_date}"
    if $redis.setnx(redis_key, "1")
      $redis.expire(redis_key, SiteSetting.active_user_rate_limit_secs)

      update_visit_record!(now_date)

      # using update_column to avoid the AR transaction
      # Keep track of our last visit
      if seen_before? && (self.last_seen_at < (now - SiteSetting.previous_visit_timeout_hours.hours))
        previous_visit_at = last_seen_at
        update_column(:previous_visit_at, previous_visit_at)
      end
      update_column(:last_seen_at, now)
    end
  end

In the middle of this function is update_visit_record, which tries to update the user_stat for this user

[RAILS_ROOT]/app/models/user.rb:266:in `update_visit_record!’

  def update_visit_record!(date)
    unless has_visit_record?(date)
      user_stat.update_column(:days_visited, user_stat.days_visited + 1)
      user_visits.create!(visited_at: date)
    end
  end

This code does not check for the actual availability of a user_stat record for this user. If the user doesn’t have one (for instance because they didn’t login since Sept 11 when the user_stat table was introduced, it crashes. This code has been introduced 9 days ago in a large refactor.

Manually creating a user_stat record for the affected users solved the problem.


While I’m talking about the user_stats table: IMHO this kind of vertical partitioning is not a very good practice.
The reason for introducing this table is stated as

This is information that is not usually needed when representing a user and is in a separate table with a has one relationship to avoid querying it all the time.

The users table has 46 columns and contains between about 100 and 2050 bytes of data per record. Does it really make a difference that those seven integers and one boolean are moved to a separate table? I could imagine the other way around would make some sense - not having to retrieve the entire user when you only want the statistics - but I see no place where only user_stats is queried*. So this might be even bad for performance, since an extra query is needed.

*) if I overlooked such a place then of course this might be a good idea after all, but for now I’m missing the point.

Also, a field like has_custom_avatar does not sound like a ‘statistic’ and it’s very odd that it is placed in this table and not in users.


production_error.log may contain plaintext passwords
(Sam Saffron) #2

The check is omitted cause the existence of the record in user_stats is guaranteed here:

Of course this is not a db level guarantee, I may add a trigger so we are 100% sure.

Regardless, I am curious, are you directly modifying the database to create these users? How did they get into the DB without the user_stats record? There is a migration that backfills.

We are not done moving, but yes it does make sense.

  1. Active Record is not that fast at yanking tons of columns out of a table, there is a lot of string -> date or string -> boolean conversions going on.
  2. @eviltrout is not a fan of partial selecting, even though I am Enemy of the State - Evil Trout's Blog … regardless Active Record makes it really hard to do lazy loading properly
  3. This move out reduces contention. Stats columns are updated aggressively, something that can cause locking, I wanted the locking localized to a tiny table.
  4. This move out simplifies and trims down our huge User model

Not sure how / why has_custom_avatar got there, its probably my fault for miscommunicating stuff to @zogstrip we probably want to keep all avatar related information together, I am fine to move this back to the user table for the time being.


(Robin Ward) #3

Actually that was my doing, and the first column in the table.

has_custom_avatar is an expensive call. It often requires a check on gravatar if the user has not uploaded an avatar directly to your Discourse instance. When I created user_stats, I imagined it as a place for the results of expensive queries alongside denormalized counter caches.

I’d be happy to discuss moving it out, but it is an infrequently used value that is expensive to compute.

Agreed on all other points. Well, I am not against partial selecting if we make a new class to hold it in :slight_smile: I’m against it when a User class ends up with partial columns. If the result was a different object or even a hash that’s OK by me!


(Sam Saffron) #4

I understand this objection, Active Record is really weak here, in general ORMs allow you to do this cleanly, EG:

http://datamapper.org/articles/spotlight_on_laziness.html

http://sequel.rubyforge.org/rdoc-plugins/classes/Sequel/Plugins/LazyAttributes.html

Some rightfully consider lazy loading an anti pattern, as when its implemented transparently it can lead to nasty N+1 issues.

Personally, I feel it would be cleaner if we had a few views and just used them when we needed partial rows.

Perhaps we could have this (backed by a basic_users view)

class BasicUser < ActiveRecord::Base
end

class User < BasicUser
end

I am not sure how it would all hang, but probably worth experimenting with (it would also allow decomposing User class some)


(Michael - DiscourseHosting.com) #5

“No”, and “beats me”, respectively.

Those users have been created the regular way. Apparently the migration didn’t work or something else was wrong - dunno what happened but there was no user_stats record. There was no trickery or doubtful actions on our side that can explain that :smile:

BTW this happened on multiple independent forums.


(Michael - DiscourseHosting.com) #6

Thank you for your explanation about the vertical partitioning,

This makes sense. Note that the reason given in the change was the other way around, so that put me on the wrong idea.

This is information that is not usually needed when representing a
user and is in a separate table with a has one relationship to avoid
querying it all the time.

Talks about not having to load user_stats when you load users, you say “I don’t want to update users when I update user_stats” :smile:


(Jeff Atwood) #7

Is this still an issue with latest code?


(Michael - DiscourseHosting.com) #8

Nope, it was only that specific migration. Never happened again after that single time.


(Jeff Atwood) #9