Concurrent record locks are withheld from client/servers ses

Posted by dbeavon on 14-Dec-2018 16:22

We have started using client/server connections from PASOE to our database.

I was troubleshooting a performance issue with database locks.  I've noticed that if *multiple* client/server connections are accessing the same record, it takes quite a long time for the record to be made available to each of them in turn.  Even if the work that needs to be done with the record takes 100 ms, the record won't become available to another client connection for two seconds.

Here is some sample code that will be run concurrently from multiple ABL sessions.

DEFINE VARIABLE iFindTime1 AS INTEGER NO-UNDO.
DEFINE VARIABLE iFindTime2 AS INTEGER NO-UNDO.


   L_LockUser:
   DO TRANSACTION:
      
            
      ETIME(TRUE).
      
      FIND FIRST gen_user WHERE gen_user.entity = "entity" AND gen_user.user-name = "me" EXCLUSIVE-LOCK.
      
      PAUSE 0.100.
      
      iFindTime1 = ETIME.
            
      UNDO L_LockUser, LEAVE L_LockUser.
            
   END. 
      
   iFindTime2 = ETIME.

   LOG-MANAGER:WRITE-MESSAGE("Lock Wait Times" + STRING(iFindTime1) + " " + STRING(iFindTime2) ).

Assuming five ABL sessions start running this same code at the same time, the output will appear like so:

[18/12/14@11:06:26.521-0500] P-004840 T-015380 1 AS-81 APPL           ... Running GetData...  
[18/12/14@11:06:26.521-0500] P-004840 T-027016 1 AS-79 APPL           ... Running GetData...  
[18/12/14@11:06:26.522-0500] P-004840 T-023104 1 AS-77 APPL           ... Running GetData...  
[18/12/14@11:06:26.526-0500] P-004840 T-028252 1 AS-80 APPL           ... Running GetData...  
[18/12/14@11:06:26.526-0500] P-004840 T-016688 1 AS-78 APPL           ... Running GetData...  

 
[18/12/14@11:06:26.675-0500] P-004840 T-027016 1 AS-79 APPL          Lock Wait Times  103 103 
[18/12/14@11:06:28.674-0500] P-004840 T-015380 1 AS-81 APPL          Lock Wait Times  2102 2103 
[18/12/14@11:06:30.678-0500] P-004840 T-023104 1 AS-77 APPL          Lock Wait Times  4103 4104 
[18/12/14@11:06:32.681-0500] P-004840 T-028252 1 AS-80 APPL          Lock Wait Times  6104 6105 
[18/12/14@11:06:34.682-0500] P-004840 T-016688 1 AS-78 APPL          Lock Wait Times  8104 8105 

Notice that the time waiting for the record to become available is about 2000 ms if it wasn't already available. And the work takes only 100 ms.

Is there a way to configure that?  I would think that releasing the lock after 50 or 100 ms would be high for most applications, but forcing users to wait 2000 ms seems excessive.

Thanks in advance.

Posted by gus bjorklund on 17-Dec-2018 20:28

there arer nwetowrk tuning paramtyers that richb implemented in 10.2B06 and later. One of these (-Nmsgwait) is how often the server checks for stuff to do. the default for this was 2 seconds for the past 25 years (sinve v4) (way way too long).

unfortunately, unless i am mistaken, now the configuration parameter -Nmsgwait can be set only as low as 1 second. 1 msec would be much better.

-gus

Posted by ChUIMonster on 14-Dec-2018 17:43

1)  Is FIRST actually relevant to your work-around?

2)  What is the impact of adding "-Nmsgwait 1" to your startup parameters (for your original code)?

All Replies

Posted by dbeavon on 14-Dec-2018 17:01

I was able to make this work a bit faster by using FIND FIRST with NO-WAIT.  It isn't pretty, but I replace the FIND FIRST with the entire loop shown below.  It keeps trying to lock the record in a loop until it finally gets it.

      RELEASE gen_user.
      
      DO WHILE TRUE:
         
         FIND FIRST gen_user WHERE gen_user.entity = "entity" AND gen_user.user-name = "me" EXCLUSIVE-LOCK NO-WAIT NO-ERROR.
         
         IF AVAILABLE gen_user THEN LEAVE.
         
         PAUSE 0.010.
         
      END.
      

If someone understands why my original example had caused the client session to block each other for increments of 2000 ms, then I would be eager to hear the reason.  My intention was that they wouldn't block each other longer than ~100 ms that is used to process the transaction.

Thanks, David

Posted by ChUIMonster on 14-Dec-2018 17:43

1)  Is FIRST actually relevant to your work-around?

2)  What is the impact of adding "-Nmsgwait 1" to your startup parameters (for your original code)?

Posted by dbeavon on 14-Dec-2018 18:14

The "FIRST" wasn't relevant and I removed it for now.

2) The Nmsgwait was already 1.  Out of curiousity I bumped that up to 4 and things get a lot worse than before (especially in PASOE since the max lock wait time is 10 seconds, and all five sessions aren't able to get a record lock anymore in that limited amount of time.)  Here is the new output from my original code, as five sessions simultaneously start executing at the same time.

[18/12/14@13:02:25.041-0500] P-004464 T-029728 1 AS-7 APPL           Lock Wait Times  103 103 
[18/12/14@13:02:31.064-0500] P-004464 T-014696 1 AS-6 APPL           Lock Wait Times  6105 6124
[18/12/14@13:02:34.946-0500] P-004464 T-029636 1 AS-8 -- (Procedure: 'GetData app/Production/Maintenance/Kiln/AppServer/KilnTesting.p' Line:64) Lock wait timeout of 10 seconds expired (8812)
[18/12/14@13:02:34.966-0500] P-004464 T-022712 1 AS-4 -- (Procedure: 'GetData app/Production/Maintenance/Kiln/AppServer/KilnTesting.p' Line:64) Lock wait timeout of 10 seconds expired (8812)
[18/12/14@13:02:34.987-0500] P-004464 T-028988 1 AS-9 -- (Procedure: 'GetData app/Production/Maintenance/Kiln/AppServer/KilnTesting.p' Line:64) Lock wait timeout of 10 seconds expired (8812)

It seems that this Nmsgwait is the parameter that controls how long it takes for sessions to detect that a lock was released.  It is very unfortunate that this is measured seconds rather than milliseconds...  I suppose that means I have to just use my NO-WAIT looping strategy.

Posted by gus bjorklund on 17-Dec-2018 20:28

there arer nwetowrk tuning paramtyers that richb implemented in 10.2B06 and later. One of these (-Nmsgwait) is how often the server checks for stuff to do. the default for this was 2 seconds for the past 25 years (sinve v4) (way way too long).

unfortunately, unless i am mistaken, now the configuration parameter -Nmsgwait can be set only as low as 1 second. 1 msec would be much better.

-gus

This thread is closed