juju models is O(N^2) wrt modelUsers collection

Bug #1732509 reported by John A Meinel
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Canonical Juju
Fix Released
High
John A Meinel

Bug Description

Model.Users does:
 coll, closer := m.st.db().GetCollection(modelUsersC)
 defer closer()

 var userDocs []userAccessDoc
 err := coll.Find(nil).All(&userDocs)
 if err != nil {
  return nil, errors.Trace(err)
 }
I did a quick peek, and it seems that our collectionWrapper only munges queries if they include _id, and so a 'nil' query will read *all* docs from the collection.

Which means that if you have 200 models, that means at least 200 modelUser entries (assuming each model has at least 1 owner).
Which then means that doing:
juju list-models

will go to each model, and load all 200 modelUser docs, to filter back down to only the users relevant for this model.
Now, it looks like we might auto-munge in a "model-uuid: X" query. However, there is no model-uuid index defined on the collection:
> db.modelusers.getIndices()
[
        {
                "v" : 1,
                "key" : {
                        "_id" : 1
                },
                "name" : "_id_",
                "ns" : "juju.modelusers"
        }
]

I'm looking to rewrite this to do more batching, and less potato-ing anyway, but this is definitely Quadratic in the number of models a controller has.

John A Meinel (jameinel)
tags: added: list-models performance
Revision history for this message
John A Meinel (jameinel) wrote :

The easy fix might be to just put an index on model-uuid on that collection.

Revision history for this message
John A Meinel (jameinel) wrote :

                          ns total read write 2017-11-15T19:25:35Z
             juju.modelusers 393ms 393ms 0ms
             juju.migrations 181ms 181ms 0ms
                 juju.models 160ms 160ms 0ms
               juju.machines 158ms 158ms 0ms
                  juju.users 80ms 80ms 0ms
juju.modelUserLastConnection 78ms 76ms 2ms
            juju.permissions 77ms 77ms 0ms
               juju.statuses 75ms 75ms 0ms
               juju.settings 70ms 70ms 0ms
               juju.txns.log 58ms 50ms 7ms

                          ns total read write 2017-11-15T19:25:45Z
             juju.modelusers 388ms 388ms 0ms
             juju.migrations 176ms 176ms 0ms
                 juju.models 158ms 158ms 0ms
               juju.machines 155ms 155ms 0ms
               juju.txns.log 86ms 73ms 13ms
                   juju.txns 77ms 4ms 73ms
                  juju.users 77ms 77ms 0ms
juju.modelUserLastConnection 76ms 74ms 2ms
            juju.permissions 75ms 75ms 0ms
               juju.statuses 73ms 73ms 0ms

                          ns total read write 2017-11-15T19:26:17Z
             juju.migrations 176ms 176ms 0ms
             juju.modelusers 159ms 159ms 0ms
                 juju.models 158ms 158ms 0ms
               juju.machines 142ms 142ms 0ms
               juju.txns.log 87ms 76ms 11ms
juju.modelUserLastConnection 79ms 77ms 2ms
                  juju.users 78ms 78ms 0ms
            juju.permissions 75ms 75ms 0ms
               juju.statuses 74ms 74ms 0ms
               juju.settings 70ms 70ms 0ms

                          ns total read write 2017-11-15T19:26:27Z
             juju.migrations 182ms 182ms 0ms
                 juju.models 167ms 167ms 0ms
             juju.modelusers 166ms 166ms 0ms
               juju.machines 148ms 148ms 0ms
juju.modelUserLastConnection 83ms 81ms 2ms
                  juju.users 82ms 82ms 0ms
            juju.permissions 79ms 79ms 0ms
               juju.statuses 78ms 78ms 0ms
               juju.txns.log 74ms 65ms 9ms
               juju.settings 73ms 73ms 0ms

Can you tell when the index was added?

Revision history for this message
John A Meinel (jameinel) wrote :

Note that my change that attempts to move everything over to batch queries instead of being potatoes. I haven't managed to get all the same data that it was getting, but can you spot the part that is still a potato:
                     ns total read write 2017-11-15T19:51:25Z
       juju.permissions 185ms 185ms 0ms
          juju.txns.log 84ms 71ms 12ms
              juju.txns 74ms 4ms 69ms
          juju.settings 56ms 56ms 0ms
            juju.models 55ms 55ms 0ms
          juju.statuses 41ms 41ms 0ms
            juju.leases 36ms 15ms 21ms
presence.presence.pings 26ms 24ms 1ms
        juju.modelusers 17ms 17ms 0ms
         local.oplog.rs 13ms 13ms 0ms

              ns total read write 2017-11-15T19:51:35Z
juju.permissions 178ms 178ms 0ms
   juju.txns.log 98ms 85ms 12ms
       juju.txns 71ms 4ms 67ms
   juju.settings 57ms 57ms 0ms
     juju.models 52ms 52ms 0ms
   juju.statuses 38ms 38ms 0ms
     juju.leases 36ms 14ms 21ms
 juju.modelusers 16ms 16ms 0ms
  local.oplog.rs 12ms 12ms 0ms
      juju.users 9ms 9ms 0ms

(permissions is still doing a lookup one user at a time, and its now the dominant time sink. modelusers is 1/10th the load even with the index.)

Changed in juju:
status: Triaged → In Progress
milestone: none → 2.3-rc2
Revision history for this message
Anastasia (anastasia-macmood) wrote :

Commit https://github.com/juju/juju/commit/d4b277f7c814253b40d54e114abebb8f9c81044f adds an index that improves the experience. It went into 2.3-rc1.

Changed in juju:
status: In Progress → Fix Committed
milestone: 2.3-rc2 → 2.3-rc1
Changed in juju:
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.