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)

Tags

NOR, Performance

Attached Files

Relationships [ Relation Graph ] [ Dependency Graph ]

related to	defect	0025466	3.0PR14Q2	closed	alostale	Performace problem during the login
related to	defect	0046189		closed	alostale	WS calls UserLock for every request even within the same session
related to	defect	0055823		new	Triage Platform Base	User locking check should not be done in WS requests for WS-only users

Notes
There are no notes attached to this issue.

Issue History
Date Modified	Username	Field	Change
2020-06-18 16:58	shuehner	New Issue
2020-06-18 16:58	shuehner	Assigned To	=> platform
2020-06-18 16:58	shuehner	Modules	=> Core
2020-06-18 16:58	shuehner	Triggers an Emergency Pack	=> No
2020-06-18 16:58	shuehner	Tag Attached: Performance
2020-06-18 17:00	shuehner	Relationship added	related to 0025466
2021-03-31 08:52	alostale	Relationship added	related to 0046189
2021-03-31 12:34	rafaroda	Tag Attached: NOR
2022-02-01 07:24	alostale	Assigned To	platform => Triage Platform Base
2024-06-24 11:48	caristu	Relationship added	related to 0055823