# Deep module calls are very slow

**URL:** <https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220>\
**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:** 14\
**Page:** 2

<div class="post-metadata">

**Author:** ![David\_Stone](https://sea1.discourse-cdn.com/inductiveautomation/user_avatar/forum.inductiveautomation.com/david_stone/32/79749_2.png) [@David\_Stone](https://forum.inductiveautomation.com/u/David_Stone)\
**Post date:** [May 15, 2025, 9:38am UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/21 "2025-05-15T09:38:20Z")

</div>

Instead of being irate on a forum filled with volunteers who are helping you as best they can, you should raise a ticket on the IA customer support portal and take advantage of the advanced level of support they offer for these sort of things.

---

<div class="post-metadata">

**Author:** ![JordanCClark](https://sea1.discourse-cdn.com/inductiveautomation/user_avatar/forum.inductiveautomation.com/jordancclark/32/83362_2.png) [@JordanCClark](https://forum.inductiveautomation.com/u/JordanCClark)\
**Post date:** [May 15, 2025, 11:40am UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/22 "2025-05-15T11:40:35Z")

</div>

EDIT: Apologies for the tone of my post. I'm feeling a bit salty today. But I'm not apologetic enough to change it.

_ **Why** _ are you putting these into site-packages? Your own tests show that it's more performant as a project script.

If it needs to be a global function, then put it in the gateway script project and use inheritance. That is the supported and documented method.

If it needs to be for multiple, but not all projects, then put it in its own project and make it inheritable

> **[Project Library | Ignition User Manual](https://www.docs.inductiveautomation.com/docs/8.1/platform/scripting/scripting-in-ignition/project-library#gateway-scripting-project)**
>
> Scripts under the Project Library are a project-based resource that allows user created Python scripts to be configured. Objects and functions created in a Project Library script can be called from anywhere in the project. Project Library scripts are...

> **[Project Inheritance | Ignition User Manual](https://www.docs.inductiveautomation.com/docs/8.1/platform/projects/project-inheritance#configuring-project-inheritance)**
>
> Project Inheritance allows one project to inherit resources from another project. If you have project resources that you want other projects to use such as views, windows, scripts, templates, or pipelines, you can create an inheritable project...

---

<div class="post-metadata">

**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 15, 2025, 1:02pm UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/23 "2025-05-15T13:02:14Z")

</div>

Whatever this is doesn't seem to have anything to do with Ignition, it's reproducible in standalone Jython.

edit: and although not an explanation, moving this line:

```python
import re

```

outside the function body makes both functions faster.

---

<div class="post-metadata">

**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 15, 2025, 1:08pm UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/24 "2025-05-15T13:08:51Z")

</div>

and now I wonder if the whole test methodology is flawed and just victim of JVM warmup / hotspot compilation, because switching the order of the functions tested also seems to have affected my results:

```python
import time
from folder1.f1 import checksomething as checksomething1
from test_file import checksomething as checksomething2
value = "ABCABC.4931"
now1 = time.time()
for _ in range(1000):
	x = checksomething2(value)
now2 = time.time()
for _ in range(1000):
	x = checksomething1(value)
now3 = time.time()

print("Time taken by checksomething2: ", now2 - now1)
print("Time taken by checksomething1: ", now3 - now2)

```

```python
kevin@DV-55J5DY3-LT:~$ java -jar jython-standalone-2.7.4.jar measure.py
('Time taken by checksomething2: ', 0.06099987030029297)
('Time taken by checksomething1: ', 0.009000062942504883)

```

(after moving `import re` outside the function body)

---

<div class="post-metadata">

**Author:** ![pturmel](https://sea1.discourse-cdn.com/inductiveautomation/user_avatar/forum.inductiveautomation.com/pturmel/32/3295_2.png) [@pturmel](https://forum.inductiveautomation.com/u/pturmel)\
**Post date:** [May 15, 2025, 1:35pm UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/25 "2025-05-15T13:35:22Z")

</div>

The `import` statement **always** takes the JVM-wide import lock. I suspect lock contention.

(Any use of import **inside** a function definition is a mistake, IMNSHO. Except where required by legacy scope, which can simply be avoided.)

---

<div class="post-metadata">

**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 15, 2025, 1:41pm UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/26 "2025-05-15T13:41:01Z")

</div>

Even after adding warmup rounds and removing the import statement, the first function measured is always just a little slower than the second, doesn't matter which one is first. I can't explain that 🤷‍♂️

---

<div class="post-metadata">

**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 15, 2025, 1:43pm UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/27 "2025-05-15T13:43:43Z")

</div>

With enough warmup rounds it really starts to converge though:

```python
import time
from folder1.f1 import checksomething as checksomething1
from test_file import checksomething as checksomething2

from java.lang import System

value = "ABCABC.4931"

# warmup
for _ in range(100000):
    x = checksomething1(value)
    x = checksomething2(value)

# measure
now1 = System.nanoTime()
for _ in range(10000):
	x = checksomething1(value)
now2 = System.nanoTime()
for _ in range(10000):
	x = checksomething2(value)
now3 = System.nanoTime()

print("Time taken by checksomething1: ", (now2 - now1) / 1000000.0, "ms")
print("Time taken by checksomething2: ", (now3 - now2) / 1000000.0, "ms")

```

```python
kevin@DV-55J5DY3-LT:~$ java -jar jython-standalone-2.7.4.jar measure.py
('Time taken by checksomething1: ', 15.275997, 'ms')
('Time taken by checksomething2: ', 13.782017, 'ms')

```

---

<div class="post-metadata">

**Author:** ![pturmel](https://sea1.discourse-cdn.com/inductiveautomation/user_avatar/forum.inductiveautomation.com/pturmel/32/3295_2.png) [@pturmel](https://forum.inductiveautomation.com/u/pturmel)\
**Post date:** [May 15, 2025, 1:44pm UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/28 "2025-05-15T13:44:10Z")

</div>

Instead of passing `value`, pass `"%s %d" % (value, _)` to force some work in each loop.

---

<div class="post-metadata">

**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 15, 2025, 1:47pm UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/29 "2025-05-15T13:47:33Z")

</div>

Slows it down a little, but still first is faster by a little. Run to run the timing is pretty inconsistent too.

```python
kevin@DV-55J5DY3-LT:~$ java -jar jython-standalone-2.7.4.jar measure.py
('Time taken by checksomething1: ', 78.806076, 'ms')
('Time taken by checksomething2: ', 64.63638, 'ms')

```

making sure the warmup isn't optimized away (hopefully) doesn't change anything either.

```python
# warmup
def blackhole(x):
    x = None
    pass

for _ in range(100000):
    x = checksomething1(value)
    blackhole(x)
    x = checksomething2(value)
    blackhole(x)

```

---

<div class="post-metadata">

**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 15, 2025, 1:48pm UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/30 "2025-05-15T13:48:41Z")

</div>

> [@Kevin.Herron](#):
>
> Run to run the timing is pretty inconsistent too.

Java running Python running in an Ubuntu VM... 🙃

---

<div class="post-metadata">

**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 15, 2025, 1:52pm UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/31 "2025-05-15T13:52:52Z")

</div>

Not GC either. I've gotta go for my morning run, got nerd sniped here.

```python
kevin@DV-55J5DY3-LT:~$ java -XX:+UnlockExperimentalVMOptions -XX:+UseEpsilonGC -Xms4G -Xmx4G -XX:+AlwaysPreTouch -jar jython-standalone-2.7.4.jar measure.py
('Time taken by checksomething1: ', 54.383027, 'ms')
('Time taken by checksomething2: ', 29.919179, 'ms')

```

---

<div class="post-metadata">

**Author:** ![pascal.fragnoud](https://sea1.discourse-cdn.com/inductiveautomation/user_avatar/forum.inductiveautomation.com/pascal.fragnoud/32/24728_2.png) [@pascal.fragnoud](https://forum.inductiveautomation.com/u/pascal.fragnoud)\
**Post date:** [May 15, 2025, 2:11pm UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/32 "2025-05-15T14:11:52Z")

</div>

> [@Kevin.Herron](#):
>
> I've gotta go for my morning run

Make sure you go first, apparently you'll run faster

---

<div class="post-metadata">

**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 15, 2025, 2:17pm UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/33 "2025-05-15T14:17:59Z")

</div>

this feels like hotspot or something funky with import resolution, probably hotspot if i had to guess (who knows how JVM compilation caches things)

---

<div class="post-metadata">

**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, 4:05pm UTC](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220/34 "2025-05-15T16:05:50Z")

</div>

Okay so it seems like the "import re" is impacting the duration differently for a non-module Have been testing this directly on Jython

```python
import re
import time
import checksomething2
from checksomething3 import checksomething as checksomething3

def checksomething1(value):
    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))

def checksomething1wimport(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))

value = "ABCABC.4931"

x = checksomething1(value)
now = time.time()
for _ in range(10000):
    x = checksomething1(value)
measured = time.time() - now
print("{0: 5f} s, Avg: {1: 5f} s 10000x checksomething1 (inline)".format(measured, measured / 10000.0))

x = checksomething1wimport(value)
now = time.time()
for _ in range(10000):
    x = checksomething1wimport(value)
measured = time.time() - now
print("{0: 5f} s, Avg: {1: 5f} s 10000x checksomething1 wimport (inline)".format(measured, measured / 10000.0))

x = checksomething2.checksomething(value)
now = time.time()
for _ in range(10000):
    x = checksomething2.checksomething(value)
measured = time.time() - now
print("{0: 5f} s, Avg: {1: 5f} s 10000x checksomething2 (/site-packages/checksomething2.py)".format(measured, measured / 10000.0))

x = checksomething2.checksomethingwimport(value)
now = time.time()
for _ in range(10000):
    x = checksomething2.checksomethingwimport(value)
measured = time.time() - now
print("{0: 5f} s, Avg: {1: 5f} s 10000x checksomething2 wimport (/site-packages/checksomething2.py)".format(measured, measured / 10000.0))

x = checksomething3.checksomething(value)
now = time.time()
for _ in range(10000):
    x = checksomething3.checksomething(value)
measured = time.time() - now
print("{0: 5f} s, Avg: {1: 5f} s 10000x checksomething3 (/site-packages/checksomething3/checksomething.py)".format(measured, measured / 10000.0))

x = checksomething3.checksomethingwimport(value)
now = time.time()
for _ in range(10000):
    x = checksomething3.checksomethingwimport(value)
measured = time.time() - now
print("{0: 5f} s, Avg: {1: 5f} s 10000x checksomething3 wimport (/site-packages/checksomething3/checksomething.py)".format(measured, measured / 10000.0))

```

checksomething.py

```python
import re
def checksomething(value):
    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))
        
def checksomethingwimport(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))

```

Results:

```python
 0.668000 s, Avg: 0.000067 s 10000x checksomething1 (inline)
 0.157000 s, Avg: 0.000016 s 10000x checksomething1 wimport (inline)
 0.115000 s, Avg: 0.000012 s 10000x checksomething2 (/site-packages/checksomething2.py)
 0.120000 s, Avg: 0.000012 s 10000x checksomething2 wimport (/site-packages/checksomething2.py)
 0.089000 s, Avg: 0.000009 s 10000x checksomething3 (/site-packages/checksomething3/checksomething.py)
 23.761000 s, Avg: 0.002376 s 10000x checksomething3 wimport (/site-packages/checksomething3/checksomething.py)

```

EDIT:  
Same results in Ignition, so it seems like the 'import re' did it ...

[Previous page](https://forum.inductiveautomation.com/t/deep-module-calls-are-very-slow/106220.md?page=1)