1 2 3 4 Previous Next 59 Replies Latest reply on Feb 9, 2016 6:47 AM by gdurniak

    Weird script performance

    siplus

      Hi all,

       

      I've stumbled upon a problem to which I can't give an explanation, despite my efforts (as you will see).

      Hopefully some bright ideas from the community will shed some light on this.

       

      A) SITUATION

       

      - A medical solution made of 70 databases and 158 tables.

       

      - The solution is split upon 2 servers, one holding strict medical data, the other one billing data.


      - The 2 servers are 2 macMinis, similar (CPU/RAM/HD), on my local network, running only FM Server 13.


      - I am the only user, using FMPA 13 and FMPA 14 on a MacBookPro 17", 16 GB RAM, OS X 10.10.5.

        No traffic on network (no mail checking, no browsers, no mounted volumes, nada)

        No WiFi, no VPN, Ethernet at 1st place in Network Services list.

        Constantly having about 9 GB of unused RAM

       

       

      - Databases playing a role in the situation:

       

       

        SERVER 1    SERVER 2

      ------------------------------------------------

        Doctors     Payments

        Patients    Performances

        ......      Validator

                    .....

       

      - A payment is related to many Performances (which are in fact its line items).

      - The Validator database has some internal tables and a PerformanceLine table, plus a script "Validate".

      - The Validate script is called with a PaymentID from Payments.

      - A global var is set, which allows it to relate to performances.

      - It GTRRs to the related performances, imports them into its PerformanceLine table, processes every

        record, builds an errorResult var, deletes the PerformanceLines it worked upon and exits with

        ScriptResult = errorResult.


        The Validator does fetch a bit of data from "Doctors" on Server1, because every performance line

        has a DoctorID and every Doctor has a list of Specializations which allow/don't allow him to

        execute a specific performance.


        The Validator does fetch a bit of data from "Patients"on Server1, (age and sex) because

        specific Performances (Pediatrics, Gynecology etc) are only valid under specific rules.

       

       

       

      B) THE SETUP

       

       

      - In payments I have a selection of 50 test payments (out of 81500). Every payment contains the same identical performances (15 of them), all belonging to the same doctor. (The Performance database contains a total of 700'000 records).

       

      - The only thing that distinguishes a payment from another is the PatientID.

       

      - I am on a simple list layout in the Payments database (Accounting list), showing these 50 payments, and I am calling a script in Payments, which goes to the first record, then loops on the 50 payments calling the Validator:

       

      01 Replace Field Contents [No dialog; Payment::ValidationResult; ""]

      02 Commit Records/Requests [Skip data entry validation; No dialog]

      03 Set Error Capture [On]

      04 Go to Layout [“Accounting List” (Payment)]

      05 Set Variable [$Found; Value:Get(FoundCount)]  <--- always 50 for this test

      06 Set Variable [$$StartTime; Value:Get ( CurrentTimeUTCMilliseconds )]

      07 # Loop on found payments

      08 Go to Record/Request/Page [First]

      09 Loop

      10 # Validate Tarmed, only if validation not ok

      11 If [RightWords(Payment::ValidationResult;1)   ≠  "OK"]

      12 Set Field [Payment::ValidationTimeStamp; Get ( CurrentTimeStamp )]

      13 Perform Script [“Validate” from file: “Validator”; Parameter: Payment::IDPayment & "¶0¶1"]

      14 Set Field [Payment::ValidationResult; Get ( ScriptResult )]

      15 Close File [“Validator”]    <--- this line is not always present, see results below

      16 End If

      17 Go to Record/Request/Page [Next; Exit after last]

      18 End Loop

      19 Set Variable [$$EndTime; Value:"Total time for " & $Found &" validations: " &

         (Get (CurrentTimeUTCMilliseconds ) - $$StartTime)/1000 & " seconds."]

      20 Show Custom Dialog ["Time taken"; $$EndTime]

       

      - I run this script from the Scripts menu, Manage Scripts window and Data Viewer window are closed.

       

      - I run the script several times and take note of the time taken, shown by line 20

       

      - I quit Filemaker, do ONLY ONE change in the overall setup (see RUN DETAILS below), then reopen the solution and do another run.

       

       

       

      C) THE RESULTS

       

       

      TEST 1, RUN DETAILS: Client = FMPA 13, 512 Cache, Server 1 2048 cache, Server 2 4096 cache, line 15 in script disabled

       

      Run#   TimeTaken (seconds)

      1      86

      2      93

      3      101

      4      109

      5      125

      6      154

      7      167

       

       

      TEST 2, RUN DETAILS: Client = FMPA 13, 512 Cache, Server 1 2048 cache, Server 2 64 cache, line 15 in script disabled

       

      Run#   TimeTaken (seconds)

      1      79

      2      86

      3      94

      4      100

      5      108

      6      113

      7      120

       

       

       

      TEST 3, RUN DETAILS: Client = FMPA 13, 128 Cache, Server 1 2048 cache, Server 2 64 cache, line 15 in script disabled

       

      Run#   TimeTaken (seconds)

      1      79

      2      86

      3      92

      4      100

      5      108

      6      113

       

      FROM NOW ON, TEST RUNS HAVE SCRIPT LINE 15 ENABLED.

       

      TEST 4, RUN DETAILS: Client = FMPA 13, 128 Cache, Server 1 2048 cache, Server 2 64 cache, line 15 in script enabled

       

      Run#   TimeTaken (seconds)

      1      85

      2      93

      3      102

      4      113

      5      159


      TEST 5, RUN DETAILS: Client = FMPA 13, 128 Cache, Server 1 64 cache, Server 2 64 cache, line 15 in script enabled

       

      Run#   TimeTaken (seconds)

      1      85

      2      93

      3      104

      4      141

      5      149

       

       

      TEST 6, RUN DETAILS: Client = FMPA 14 running in 32 bit mode, 128 Cache, Server 1 64 cache, Server 2 64 cache, line 15 in script enabled

       

       

      Run#   TimeTaken (seconds)

      1      116

      2      188

      3      154  (?)

      4      252

       

       

      TEST 7, RUN DETAILS: Client = FMPA 14 running in 64 bit mode, 128 Cache, Server 1 64 cache, Server 2 64 cache, line 15 in script enabled

       

       

      Run# TimeTaken (seconds)

      1      116

      2      180

      3      152     (?)

      4      254

       

       

      D) THE PROBLEM

       

       

      I think the problem is obvious: same script, run several times in a row on the same data, executing slower and slower each time.

       

      Why does it happen ?

       

      How is quitting Filemaker involved in resetting the speed to a best value, despite data having to be cached again ?

       

      And the bonus question: why is FMPA 14 so much lousier than FMPA 13 ?

        • 1. Re: Weird script performance
          Markus Schneider

          does a 'flush cache to disk' step change anything?

           

          where does the time go? Could You add some steps to the 'stop-watch' to get 'split-times' at specific actions in the script?

          (I got a CF that deals with start/stop/split - times, but I only got the iPad at te moment)

          • 2. Re: Weird script performance
            RubenVanDenBoogaard

            It looks like the issue is in the validator script since the other script does not do much.

            What you could try is to run the validator script server sided that might improve the performance.

            - Try a flush cache step in the validator script

            - track the time it takes to run the validator script for each step to see where the time is building up

            - can you pull info out of the doctors and patient database using ExecuteSQL rather then a relation

            - can you just loop over the related PerformanceLine records in the validator script instead of importing them

            - can you do a find on the PerformanceLine records instead of a GTRR

             

            Hope that helps.

             

            Ruben

            • 3. Re: Weird script performance
              siplus

              no, flush cache to disk does nothing - it's the first step of the Validator script.

               

              I can try calling the script 50 times with the same PaymentID and see if there's a change.

              • 4. Re: Weird script performance
                Mike_Mitchell

                siplus wrote:

                 

                 

                And the bonus question: why is FMPA 14 so much lousier than FMPA 13 ?

                 

                 

                Don't know that I can speak to most of this, but it's possible the mismatch between Server and the client has something to do with this.

                • 5. Re: Weird script performance
                  siplus

                  Thanks for your considerations.

                   

                  The problem here is not optimizing the Validator script (which can be slightly, but not much, be done). It's understanding why the same black box, run on the same data, gets slower and slower on subsequent calls, all the rest remaining the same.

                  • 6. Re: Weird script performance
                    Steve Wright

                    That's certainly an odd set of timings..

                     

                    I can't think of anything really to help other than what has been suggested... but perhaps also trying a freeze window step, prior to the loop, it may not help consecutive runs, but should help through the looping / overall.

                    • 7. Re: Weird script performance
                      RubenVanDenBoogaard

                      normally is a matter of caches or variables getting larger. Try flushing the cache after each run, or even after each call to Validator.

                       

                      Hope that helps

                      • 8. Re: Weird script performance
                        siplus

                        Tried that, too, brings no difference (the validator itself starts with Freeze window and allow user abort(off))

                        • 9. Re: Weird script performance
                          Markus Schneider

                          bonus question:

                          I did a lot testing with FM14 under windows - and the performance can be poor. There are scriptsteps that have FM to redraw a layout, counting a few seconds (hide textruler, ie)

                           

                          we also noticed quite big differencies when ie a script-workspace-window was open, etc. (Windows, virtualized clients, only 4GB RAM, poor graphic-card)

                          • 10. Re: Weird script performance
                            siplus

                            Yeah, the bonus question is quite academic - we are waiting for FMP15, 'nuff said,

                            • 11. Re: Weird script performance
                              Steve Wright

                              Back in previous versions when 'screen flicker' was a thing (on Windows OS).. the freeze window step would cause a screen redraw before freezing, causing the same 'flicker' as a refresh window step.  So my thinking is that you may be refreshing the window in order to freeze it 50 times without realising it.


                              Also, since the validator script is being run in another file, the freeze window within the validator script will be relevant only to the hidden window, unless you have that window in view, then it shouldn't need it, unless it's also performing loops.

                              I'm pretty sure it works that way... In which case it's not going to stop the parent window from redrawing / refreshing data as it loops, even though it may not be noticeableIt would make more sense (to me) if it were added outside of the loop and not called within it.  


                              Still, I wouldn't expect to see the results you are getting no matter how freeze window is setup.

                               

                              • 12. Re: Weird script performance
                                siplus


                                Still, I wouldn't expect to see the results you are getting no matter how freeze window is setup.

                                 

                                 

                                 

                                Exactly.

                                 

                                Also interesting is to know why going from Run1 to Run2, in which I lowered the cache on the Filemaker Server hosting most of the data in play from 4096 to the minimum of 64, brings better timing.

                                 

                                However, the problem seems to be on the client side, (unreleased memory ?) as quitting Filemaker and restarting it resets the speed.

                                • 13. Re: Weird script performance
                                  cloudbase.software

                                  I suspect this:

                                  builds an errorResult var

                                  Is this a global var that sets new data to itself? Such as errorResult & $someNewError...

                                   

                                  Each new setting of the variable gets bigger each time and things get slower as the data gets bigger. It explains why a restart clears up the speed as well.

                                  • 14. Re: Weird script performance
                                    siplus

                                    no, it's called $BillErrorMessage, local to the script and should be freed on script exit.

                                     

                                    no $$Vars.

                                     

                                    On line 439 of the script (last line) there's a Exit Script [Result: $BillErrorMessage] and that's it.

                                     

                                    And IMHO adding some text to a global would not double the time it takes for the 50 loop to run - after 7 runs - as it actually happens.

                                    1 2 3 4 Previous Next