# Deep module calls are very slow **URL:** \ **Category:** Ignition\ **Created:** [May 13, 2025, 7:26pm UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220 "2025-05-13T19:26:45Z")\ **Posts on this page:** 20\ **Page:** 1
**Author:** ![Henkert](https://avatars.discourse-cdn.com/v4/letter/h/8e7dd6/32.png) [@Henkert](https://forum.inductiveautomation.com/u/Henkert)\ **Post date:** [May 13, 2025, 7:26pm UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/1 "2025-05-13T19:26:45Z")
I am using a python module for ERP communication, however I am troubleshooting some performance issues. After some testing I discovered that the same function with identical code in the script console or a single python-file directly in site-packages folder runs very fast, while calling the same function from a module e.g. module.components.erp.jobs.checksomething(value) is incredibly slow. In order to test this I put the code in a while loop (1000x) and measured the time. For comparison the same code in the console or single python-file takes 0.0 s and the same code called from the module takes 4.9 s. Please help me solve this. I tried shallowing or wrapping the import like this: `from module.components.erp.jobs import checksomething` or `_checksomething = module.components.erp.jobs.checksomething` Both do not change anything The code in script console: ```python > import time > from module.components.erp.jobs import checksomething as checksomething1 > from test_file import checksomething as checksomething2 > value = "ABCABC.4931" > now1 = time.time() > for _ in range(1000): > x = checksomething1(value) > now2 = time.time() > for _ in range(1000): > x = checksomething2(value) > now3 = time.time() > > now2 - now1 # outputs: 4.85899996758 > now3 - now2 # outputs: 0.0090000629425 ``` site-packages\module\components\erp\jobs.py ```python > """ > Bunch of code > """ > def checksomething(value): > import re > matches = re.findall(r"(\w+)\.?(\d+)?", value) > if len(matches) >= 1 and len(matches[0]) >= 2 and len(matches[0][0]) > 0: > return str(matches[0][0]) > else: > raise Exception("Invalid value '{0}'".format(value)) ``` Same code in: site-packages\test\_file.py ```python > def checksomething(value): > import re > matches = re.findall(r"(\w+)\.?(\d+)?", value) > if len(matches) >= 1 and len(matches[0]) >= 2 and len(matches[0][0]) > 0: > return str(matches[0][0]) > else: > raise Exception("Invalid value '{0}'".format(value)) ``` ---
**Author:** ![ryan.white](https://sea1.discourse-cdn.com/inductiveautomation/user_avatar/forum.inductiveautomation.com/ryan.white/32/73193_2.png) [@ryan.white](https://forum.inductiveautomation.com/u/ryan.white)\ **Post date:** [May 13, 2025, 7:46pm UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/2 "2025-05-13T19:46:16Z")
Not sure if its impacting the speed but do not import libraries inside of a function definition, especially in a project library script. Move it to sit outside of the function definition (ideally at the top of the file). Also consider compiling and caching the re matcher (outside of the function definition) in a top level variable, and using the Java RE classes (`java.util.regex.Matcher` and `java.util.regex.Pattern`) instead of python. ---
**Author:** ![dkhayes117](https://sea1.discourse-cdn.com/inductiveautomation/user_avatar/forum.inductiveautomation.com/dkhayes117/32/68344_2.png) [@dkhayes117](https://forum.inductiveautomation.com/u/dkhayes117)\ **Post date:** [May 13, 2025, 7:48pm UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/3 "2025-05-13T19:48:32Z")
When doing benchmarking, it is best practice to use Java's nano time. I would run your tests again using this method. ```python from java.lang import System t1 = System.nanoTime() # script goes brrrr print System.nanoTime() - t1 ``` ---
**Author:** ![Henkert](https://avatars.discourse-cdn.com/v4/letter/h/8e7dd6/32.png) [@Henkert](https://forum.inductiveautomation.com/u/Henkert)\ **Post date:** [May 13, 2025, 7:50pm UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/4 "2025-05-13T19:50:51Z")
Yea, tried that aswell... doesn't make any difference ---
**Author:** ![Kevin.Herron](https://sea1.discourse-cdn.com/inductiveautomation/user_avatar/forum.inductiveautomation.com/kevin.herron/32/7259_2.png) [@Kevin.Herron](https://forum.inductiveautomation.com/u/Kevin.Herron)\ **Post date:** [May 13, 2025, 7:52pm UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/5 "2025-05-13T19:52:28Z")
Is it slow every time you run it or just the first time? If you call it once as a throwaway and then time it what happens? ---
**Author:** ![ryan.white](https://sea1.discourse-cdn.com/inductiveautomation/user_avatar/forum.inductiveautomation.com/ryan.white/32/73193_2.png) [@ryan.white](https://forum.inductiveautomation.com/u/ryan.white)\ **Post date:** [May 13, 2025, 7:53pm UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/6 "2025-05-13T19:53:19Z")
Also, have you separated this script out into its own file at the same depth and then tried calling it? ---
**Author:** ![Henkert](https://avatars.discourse-cdn.com/v4/letter/h/8e7dd6/32.png) [@Henkert](https://forum.inductiveautomation.com/u/Henkert)\ **Post date:** [May 13, 2025, 7:53pm UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/7 "2025-05-13T19:53:39Z")
Okay, the results with the nanoTime() function are: ```python 6349360300 # module.components.erp.jobs.checksomething 17205901 # test_file.checksomething 7057100 # Directly in console ``` So similar results ---
**Author:** ![Henkert](https://avatars.discourse-cdn.com/v4/letter/h/8e7dd6/32.png) [@Henkert](https://forum.inductiveautomation.com/u/Henkert)\ **Post date:** [May 13, 2025, 7:54pm UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/8 "2025-05-13T19:54:36Z")
Yes I did, thats basically the testing I did as described above. When doing this it is much faster. ---
**Author:** ![Henkert](https://avatars.discourse-cdn.com/v4/letter/h/8e7dd6/32.png) [@Henkert](https://forum.inductiveautomation.com/u/Henkert)\ **Post date:** [May 13, 2025, 7:58pm UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/9 "2025-05-13T19:58:54Z")
I did some testing, seems to run slow each time, see below ```python 6598600 # First call of module.components.erp.jobs.checksomething 5462810600 # 1000 sequential calls (avg. 5462810) ``` EDIT: Actually, does seems to have some kind of impact. Below some results for running testing first and second time in script console: ```python Jython 2.7.3, executing locally in the Designer. Press (Ctrl + Space) to activate autocompletion. >>> START 1000 calls at depth module.components.erp.test_file.checksomething: 8.0734377 s, avg 0.0080735527 s 1000 calls at depth module.components.test_file.checksomething: 5.5843203 s, avg 0.005584376199 s 1000 calls at depth module.test_file.checksomething: 3.1591856 s, avg 0.0031594073 s 1000 calls at depth test_module.test_file.checksomething: 3.219457 s, avg 0.003219652 s 1000 calls at depth test_file.checksomething: 0.011500399 s, avg 1.1554099e-05 s >>> START 1000 calls at depth module.components.erp.test_file.checksomething: 3.5183277 s, avg 0.0035184247 s 1000 calls at depth module.components.test_file.checksomething: 3.053373499 s, avg 0.0030534299 s 1000 calls at depth module.test_file.checksomething: 3.018941601 s, avg 0.003019001701 s 1000 calls at depth test_module.test_file.checksomething: 3.2018797 s, avg 0.0032019709 s 1000 calls at depth test_file.checksomething: 0.0047055 s, avg 4.7444e-06 s >>> ``` ---
**Author:** ![ryan.white](https://sea1.discourse-cdn.com/inductiveautomation/user_avatar/forum.inductiveautomation.com/ryan.white/32/73193_2.png) [@ryan.white](https://forum.inductiveautomation.com/u/ryan.white)\ **Post date:** [May 13, 2025, 8:00pm UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/10 "2025-05-13T20:00:00Z")
> [@Henkert](#): > > When doing this it is much faster. To make sure I'm understanding correctly, you made a file at `site-packages/module/components/erp/test_file.py`, put only `checksomething` in there and then called it, and it ran faster? Or are you talking about the file at base depth that you made(`site-packages/test_file.py`)? ---
**Author:** ![dkhayes117](https://sea1.discourse-cdn.com/inductiveautomation/user_avatar/forum.inductiveautomation.com/dkhayes117/32/68344_2.png) [@dkhayes117](https://forum.inductiveautomation.com/u/dkhayes117)\ **Post date:** [May 13, 2025, 8:05pm UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/11 "2025-05-13T20:05:10Z")
Make sure that in project scripts you put the imports outside of the function (top level). This should save some execution time by not importing every time the function is called. ---
**Author:** ![Henkert](https://avatars.discourse-cdn.com/v4/letter/h/8e7dd6/32.png) [@Henkert](https://forum.inductiveautomation.com/u/Henkert)\ **Post date:** [May 13, 2025, 8:07pm UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/12 "2025-05-13T20:07:37Z")
Great suggestion! No, made the file at base depth. Copied the test\_file.py to the /site-packages/module/components/erp/test\_file.py (without any other content besides the checksomething function). ```python single call at /site-packages/module/components/erp/test_file.py: 5126799 1000 calls at /site-packages/module/components/erp/test_file.py: 4170137000 1000 calls at /site-packages/test_file.py: 5000199 1000 calls in console: 7918000 ``` EDIT: Did some more testing ```python 1000 calls at depth module.components.erp.test_file.checksomething: 4.7632177 s, avg 0.0047633 1000 calls at depth module.components.test_file.checksomething: 4.9434838 s, avg 0.0049435599 1000 calls at depth module.test_file.checksomething: 4.2983209 s, avg 0.004298386599 1000 calls at depth test_file.checksomething: 0.005669799 s, avg 5.716099e-06 ``` EDIT2: Created a test\_module to put test\_file.py in. Seems like that once there is a module involved it gets very slow ... ```python 1000 calls at depth module.components.erp.test_file.checksomething: 3.152241601 s, avg 0.003152348301 s 1000 calls at depth module.components.test_file.checksomething: 3.019533999 s, avg 0.0030195856 s 1000 calls at depth module.test_file.checksomething: 2.9465203 s, avg 0.0029467295 s 1000 calls at depth test_module.test_file.checksomething: 2.9453126 s, avg 0.002945374199 s 1000 calls at depth test_file.checksomething: 0.0055201 s, avg 5.5673e-06 s ``` ---
**Author:** ![ryan.white](https://sea1.discourse-cdn.com/inductiveautomation/user_avatar/forum.inductiveautomation.com/ryan.white/32/73193_2.png) [@ryan.white](https://forum.inductiveautomation.com/u/ryan.white)\ **Post date:** [May 13, 2025, 8:39pm UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/13 "2025-05-13T20:39:29Z")
What Ignition version are you on? I'm 8.1.44. I'm attempting to replicate at least in project library scripts, and the most I'm getting with the import in the function definition is 20ms total, with typical total time per 1000 calls in the 3-4ms range. Moving the import outside of the function def, along with compiling the RE pulls it down closer to 2-3ms, with the call in the console almost always matching time the call in the project library. There is a slight difference, with the module call being slightly higher. I do occasionally get a high time call. ---
**Author:** ![Henkert](https://avatars.discourse-cdn.com/v4/letter/h/8e7dd6/32.png) [@Henkert](https://forum.inductiveautomation.com/u/Henkert)\ **Post date:** [May 13, 2025, 8:41pm UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/14 "2025-05-13T20:41:12Z")
Updating as we speak, from 8.1.44 to 8.1.48. Will let the results know. ---
**Author:** ![Henkert](https://avatars.discourse-cdn.com/v4/letter/h/8e7dd6/32.png) [@Henkert](https://forum.inductiveautomation.com/u/Henkert)\ **Post date:** [May 13, 2025, 8:45pm UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/15 "2025-05-13T20:45:27Z")
Think the major difference here is that I am developing the module in sites-packages and not project library scripts ---
**Author:** ![Henkert](https://avatars.discourse-cdn.com/v4/letter/h/8e7dd6/32.png) [@Henkert](https://forum.inductiveautomation.com/u/Henkert)\ **Post date:** [May 13, 2025, 9:10pm UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/16 "2025-05-13T21:10:14Z")
Same results for 8.1.48... ---
**Author:** ![Henkert](https://avatars.discourse-cdn.com/v4/letter/h/8e7dd6/32.png) [@Henkert](https://forum.inductiveautomation.com/u/Henkert)\ **Post date:** [May 13, 2025, 9:46pm UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/17 "2025-05-13T21:46:41Z")
Okay so, this behavious only seems to occur when using a module in the /site-packages/ folder. Using the same path for a project library script this seems to work normally, also when there is a single folder in the /site-packages/ folder. ```python 4.0817866 s, avg 0.0040818749 s -> 1000 calls at /site-packages/module.components.erp.test_file.checksomething 4.7811206 s, avg 0.0047811821 s -> 1000 calls at /site-packages/module.components.test_file.checksomething 3.3498809 s, avg 0.0033499429 s -> 1000 calls at /site-packages/module.test_file.checksomething 4.029137501 s, avg 0.004029197701 s -> 1000 calls at /site-packages/test_module.test_file.checksomething 0.005512301 s, avg 5.652401e-06 s -> 1000 calls at /site-packages/test_file.checksomething 0.006463801 s, avg 6.545701e-06 s -> 1000 calls at prooject library package test_module1.test_file.checksomething ``` ---
**Author:** ![Leor\_Fishman](https://avatars.discourse-cdn.com/v4/letter/l/e19adc/32.png) [@Leor\_Fishman](https://forum.inductiveautomation.com/u/Leor_Fishman)\ **Post date:** [May 14, 2025, 12:09am UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/18 "2025-05-14T00:09:27Z")
That sounds to me like it's something with path resolution, maybe? Not sure how ignition handles that ---
**Author:** ![Henkert](https://avatars.discourse-cdn.com/v4/letter/h/8e7dd6/32.png) [@Henkert](https://forum.inductiveautomation.com/u/Henkert)\ **Post date:** [May 14, 2025, 7:28am UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/19 "2025-05-14T07:28:54Z")
Same results when calling the module from pylib-folder instead of site-packages... ---
**Author:** ![Henkert](https://avatars.discourse-cdn.com/v4/letter/h/8e7dd6/32.png) [@Henkert](https://forum.inductiveautomation.com/u/Henkert)\ **Post date:** [May 15, 2025, 8:05am UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/20 "2025-05-15T08:05:33Z")
Could someone from Inductive Automation please explain whether this is normal behaviour or a bug? Is there a workaround? Could I be expecting a fix soon? Because this really is killing the performance [Next page](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220.md?page=2)