Uploaded image for project: 'mod-permissions'
  1. mod-permissions
  2. MODPERMS-91

/perms/users web API possibly relies on incorrect count_estimate_default() value and doesn't return records

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: In bugfix review (View Workflow)
    • Priority: TBD
    • Resolution: Done
    • Affects Version/s: 5.11.2
    • Fix Version/s: 5.11.3
    • Labels:
      None
    • Template:
      Standard Bug Write-Up Format
    • Development Team:
      Core: Platform

      Description

      I have 116,507 rows in my permissions_users table.

      I tried getting rows starting at 110,000 for a length of 10,000.

      Note, most other APIs have offset and limit query parameters. This one is inconsistent and uses start and length instead. Also, start, is one-one based, not zero-based like it is for the other APIs.

      FolioLibrary Verbose: 0 : Querying permissions users
          ThreadId=1
          DateTime=2020-07-17T23:07:28.4969807Z
      FolioLibrary Verbose: 0 : http://myhost:9130/perms/users?query=cql.allrecords=1 sortby id&start=110001&length=10000
          ThreadId=1
          DateTime=2020-07-17T23:07:28.4979810Z
      FolioLibrary Verbose: 0 : Accept: application/json, text/plain
      x-okapi-tenant: diku
      x-okapi-token: 
          ThreadId=1
          DateTime=2020-07-17T23:07:28.4979810Z
      FolioLibrary Verbose: 0 : X-Okapi-Trace: GET mod-authtoken-2.4.0 http://gooseberry:9144/perms/users.. : 202 5160us, GET mod-permissions-5.9.0 http://gooseberry:9136/perms/users.. : 200 11680us
      transfer-encoding: chunked
      {
        "permissionUsers" : [ ],
        "totalRecords" : 109964
      }
          ThreadId=1
          DateTime=2020-07-17T23:07:28.5491991Z
      FolioLibrary Verbose: 0 : 00:00:00.0919898
          ThreadId=1
          DateTime=2020-07-17T23:07:28.5891941Z
      

      As you can see above totalRecords is being incorrectly reported at 109,964.

      The following is what appears in the mod-permissions log.

      Jul 17, 2020 11:07:28 PM org.folio.cql2pgjson.CQL2PgJSON loadDbSchema
      INFO: loadDbSchema: Loaded templates/db_scripts/schema.json OK
      17 Jul 2020 23:07:28:715 INFO  CQLWrapper [1166843eqId] CQL >>> SQL: cql.allrecords=1 sortby id >>>WHERE true ORDER BY id LIMIT 10000 OFFSET 110000
      17 Jul 2020 23:07:28:723 INFO  LogUtil [1166851eqId] org.folio.rest.RestVerticle start  invoking getPermsUsers
      17 Jul 2020 23:07:28:724 INFO  LogUtil [1166852eqId] 128.135.55.213:40090 GET /perms/users query=cql.allrecords=1%20sortby%20id&start=110001&length=10000 HTTP_1_1 200 56 11 tid=diku OK
      

      The following is what is in the PostgreSQL log.

      2020-07-17 18:07:28.714 CDT [17947] diku_mod_permissions@folio LOG:  statement: SELECT 1 AS alive
      2020-07-17 18:07:28.715 CDT [17947] diku_mod_permissions@folio LOG:  statement: SELECT count_estimate_default('SELECT * FROM diku_mod_permissions.permissions_users WHERE true ORDER BY id')
      

      As you can see above, it's calling count_estimate_default(). As the name of the function indicates, the count is an estimate. However, I'm thinking the code may check the value and see that the offset value is greater than that and hence doesn't execute the actual query to get the data.

      However, I don't know if that's true, because if I execute the query above without a LIMIT or OFFSET. I see the following in the SQL logs. Note, there is one call to get the count, and another to get the data.

      2020-07-17 18:47:42.991 CDT [18256] diku_mod_permissions@folio LOG:  statement: SELECT count_estimate_default('SELECT * FROM diku_mod_permissions.permissions_users WHERE true ORDER BY id')
      2020-07-17 18:47:43.009 CDT [18256] diku_mod_permissions@folio LOG:  statement: SELECT * FROM diku_mod_permissions.permissions_users WHERE true ORDER BY id LIMIT 2147483647 OFFSET 0
      

      And for that query, it returns the correct number of results. Though if you look at the returned JSON, you can see that in that case, the totalRecords value is incorrect as well.

        }, {
          "id" : "fffff9eb-9df1-4d2f-ac42-b6f49e7090e6",
          "userId" : "fffff9eb-9df1-4d2f-ac42-b6f49e7090e6",
          "permissions" : [ ],
          "metadata" : {
            "createdDate" : "2020-07-08T18:48:07.896+0000",
            "createdByUserId" : "023cfa2a-bf04-4156-86e6-4520e4dc35ca",
            "updatedDate" : "2020-07-08T18:48:07.896+0000",
            "updatedByUserId" : "023cfa2a-bf04-4156-86e6-4520e4dc35ca"
          }
        } ],
        "totalRecords" : 109964
      }
      

      Also, can you please change this API so that it uses offset and limit query parameters instead of start and length?

        TestRail: Results

          Attachments

            Issue Links

              Activity

                People

                Assignee:
                Unassigned Unassigned
                Reporter:
                jemiller Jon Miller
                Votes:
                0 Vote for this issue
                Watchers:
                3 Start watching this issue

                  Dates

                  Created:
                  Updated:
                  Resolved:

                    TestRail: Runs

                      TestRail: Cases