0044414: UserLock feature (delay login on wrong login) has bad performance by default

Openbravo Issue Tracking System - Openbravo ERP

View Issue Details

Project

Category

View Status

Date Submitted

Last Update

0044414

Openbravo ERP

C. Security

public

2020-06-18 16:58

2022-02-01 07:24

Reporter

shuehner

Assigned To

Triage Platform Base

Priority

normal

Severity

minor

Reproducibility

have not tried

Status

new

Resolution

open

Platform

OS Version

Product Version

Target Version

Fixed in Version

Merge Request Status

Review Assigned To

OBNetwork customer

Web browser

Modules

Core

Support ticket

Regression level

Regression date

Regression introduced in release

Regression introduced by commit

Triggers an Emergency Pack

Summary

0044414: UserLock feature (delay login on wrong login) has bad performance by default

Description

UserLock code (login.trial.*) which is active by default has noticable performance hit during every Login. In customer install where that was noticed average of 50ms per call.

Checking pg_stat_statement in example customer install (19Q3.x but same code in pi) shows this query:
https://code.openbravo.com/erp/devel/pi/file/tip/src/org/openbravo/base/secureApp/UserLock.java#l105 [^]

Showing us at top3 of all queries (with respect to total query runtime) of the instance.

8.2 Millsion calls with total time taken: 129hours
More relevant per call:
- mean_time 56ms
- max_time 2.85seconds
- Data touched (cache + disk read) per call 685MB

Cause:
- Query filter by username and login_stats <> T
  - then Max-created

That is currently not effective indexed and uses "Index Scna Backwards" of ad_session_created_idx and doing all filtering manually.
Effective performance depends on if user did recently login (good performance or not).

Example explain plan for username only having logged in once in last 116k total ad_session entries:

openbravo=# explain (analyze,buffers) select max(adsession0_.Created) as col_0_0_ from AD_Session adsession0_ where adsession0_.Username='<THE-USERNAME>' and adsession0_.Login_Status<>'F';
                                                                                 QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Result (cost=872.23..872.24 rows=1 width=8) (actual time=78.369..78.369 rows=1 loops=1)
   Buffers: shared hit=112808
   InitPlan 1 (returns $0)
     -> Limit (cost=0.42..872.23 rows=1 width=8) (actual time=78.366..78.366 rows=0 loops=1)
           Buffers: shared hit=112808
           -> Index Scan Backward using ad_session_created_idx on ad_session adsession0_ (cost=0.42..15693.08 rows=18 width=8) (actual time=78.365..78.365 rows=0 loops=1)
                 Index Cond: (created IS NOT NULL)
                 Filter: (((login_status)::text <> 'F'::text) AND ((username)::text = '<THE-USERNAME>'::text))
                 Rows Removed by Filter: 117047
                 Buffers: shared hit=112808
Planning time: 0.126 ms
Execution time: 78.389 ms

Data statistics on case shown here:
openbravo=# select login_status, count(*) from ad_session group by 1 order by 2;
login_status | count
--------------+-------
RESTR | 2
CUR | 288
S | 2474
F | 19548
OBPOS_POS | 94737
(5 rows)

                             ^
openbravo=# select count(*) from ad_session;
count
--------
117049
(1 row)

Steps To Reproduce

In database filled with ca. 100k ad_session entries for many different users
Run 1 Openbravo login (backoffice or WebPOS) and check performance for above query (+ 2nd follow up query in UserLock.java).

Probably best to take copy of ad_session from existing bigger production install to have a representative dataset (of really used system with relevant set of users)

Proposed Solution

Additional Information