# Logger usage clarification

**URL:** <https://forum.inductiveautomation.com/t/logger-usage-clarification/102717>\
**Category:** Ignition\
**Created:** [February 21, 2025, 7:29pm UTC](https://forum.inductiveautomation.com/t/logger-usage-clarification/102717 "2025-02-21T19:29:22Z")\
**Posts on this page:** 14\
**Page:** 1

<div class="post-metadata">

**Author:** ![Eugene49](https://avatars.discourse-cdn.com/v4/letter/e/c6cbf5/32.png) [@Eugene49](https://forum.inductiveautomation.com/u/Eugene49)\
**Post date:** [February 21, 2025, 7:29pm UTC](https://forum.inductiveautomation.com/t/logger-usage-clarification/102717/1 "2025-02-21T19:29:22Z")

</div>

Hi Forum,

I did my testing below:

 ![image](https://us1.discourse-cdn.com/inductiveautomation/original/3X/b/4/b45b8e4546c5f616352ca5217389c85df2e482d5.png)

Clarification:  
The purpose of logging is, I want to log message every time, such that, when glitch happened in the past, I can go thru the log message to see what was going on that time.

But this is not the case, for example, If on the script, i purposely log as "Debug", but for some reason a colleague, changed the log level to "Info". My debug message will not be log.

This beats the purpose of logging the message.  
What is the reason behind this feature; a way to filter which message being logged?

Is there another strategy I can use to make sure, my log message is being log?

---

<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:** [February 21, 2025, 7:37pm UTC](https://forum.inductiveautomation.com/t/logger-usage-clarification/102717/2 "2025-02-21T19:37:33Z")

</div>

> [@Eugene49](#):
>
> What is the reason behind this feature

Performance and storage.

Logging is designed to quickly discard messages at too low a level, without even evaluating their formatting arguments, to minimize the performance penalty of logging. ( **Severe** performance hit.)

This has the side-benefit of requiring no disk space, and therefore extending the log rotation time period of whatever logs are actually enabled.

All of Ignition's log levels are INFO at gateway startup. If you absolutely have to log something reliably, use INFO level. But think really hard about whether you really need that. Consider logging at INFO level the first time something happens (in some time period), and logging at DEBUG level after that. So users can see that something is happening, but don't get bombarded with it without need.

{ When including dynamic content in your logs, you should always use the `.infof()` or `.debugf()` logger methods. Avoid doing any complex calculations to hand to format arguments. Instead, arrange for your objects to intelligently stringify on demand from a `%s` placeholder. Those won't execute when the log level is disabled. }

---

<div class="post-metadata">

**Author:** ![Eugene49](https://avatars.discourse-cdn.com/v4/letter/e/c6cbf5/32.png) [@Eugene49](https://forum.inductiveautomation.com/u/Eugene49)\
**Post date:** [February 21, 2025, 8:01pm UTC](https://forum.inductiveautomation.com/t/logger-usage-clarification/102717/3 "2025-02-21T20:01:47Z")

</div>

Thanks.  
I understood.  
One note for each developer, `Level setting` in `Status-Diagnostic->Log` is universal and fixed.

And I recall that,  
it is on developer discretion, to decide, which `debug level` to use for each debug message.

Thus its a normal scenario where, a developer expect something will go wrong, then only go to gateway log and set logging level to debug, and reset to info when developer is confident that everything looks good. -- i wish there was a timer.

But in a scenario where multiple developers are debugging, we don't want them to set `level=Info`, when you want it to be `level=debug`. hmm

p.s.  
what is wrong with `logger.info("my name is: %s" % myName")`

Edit:  
Another place when I want debug message to always show:  
I use `system.perspective.print()` this will show on browser console and can display object (as oppose to only string).

---

<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:** [February 21, 2025, 8:07pm UTC](https://forum.inductiveautomation.com/t/logger-usage-clarification/102717/4 "2025-02-21T20:07:17Z")

</div>

> [@Eugene49](#):
>
> p.s.

That has to perform the string operation even when the INFO level is turned off. If you use this instead:

```python
logger.infof("my name is: %s", myName)

```

then the string manipulation will not be executed at all if INFO is turned off.

If `myName` is some complex object that requires substantial stringification code, then skipping it is a big performance win.

---

<div class="post-metadata">

**Author:** ![Eugene49](https://avatars.discourse-cdn.com/v4/letter/e/c6cbf5/32.png) [@Eugene49](https://forum.inductiveautomation.com/u/Eugene49)\
**Post date:** [February 21, 2025, 8:16pm UTC](https://forum.inductiveautomation.com/t/logger-usage-clarification/102717/5 "2025-02-21T20:16:02Z")

</div>

You are saying:

when `level=warn`, both will not be log:  
`logger.info("my name is: %s" % myName)`  
`logger.infof("my name is: %s", myName)`

but the latter is better, because the operation (string replacement) is skip.  
while the former still do the operation but not logged anyway.

---

<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:** [February 21, 2025, 8:17pm UTC](https://forum.inductiveautomation.com/t/logger-usage-clarification/102717/6 "2025-02-21T20:17:51Z")

</div>

Yes, because in the first case the formatting happens before the string is sent to the logger.

---

<div class="post-metadata">

**Author:** ![Eugene49](https://avatars.discourse-cdn.com/v4/letter/e/c6cbf5/32.png) [@Eugene49](https://forum.inductiveautomation.com/u/Eugene49)\
**Post date:** [February 21, 2025, 8:32pm UTC](https://forum.inductiveautomation.com/t/logger-usage-clarification/102717/7 "2025-02-21T20:32:36Z")

</div>

Let's put a nail to this habit:  
During development, I use to add `system.perspective.print()` then delete it, when every thing works.

Two scenarios:

1. doing a named query
2. sending an email

Both I want to log.

For the NQ, I want to log if query was successful, what is the query, what are the parameters.

For the email, I want to log if email was successfully sent, subject, and recipients.

Which goes to `perspective.print`, which goes to `logger.info`

For NQ result, how do I evaluate result to success or fail, even if result can be different type?

```python
result = system.db.runNamedQuery(query, params)

```

For email:

```python
system.net.sendEmail() #...does not return anything. TSK!

```

---

<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:** [February 21, 2025, 8:36pm UTC](https://forum.inductiveautomation.com/t/logger-usage-clarification/102717/8 "2025-02-21T20:36:20Z")

</div>

For the query, well... it depends on the query. It's up to you to check the returned value and see if it corresponds to what you expects.

Don't forget that most functions can raise errors, so wrap your calls in `try/except` if you want to personally handle errors. And keep in mind that database related functions will raise a java error, not a python one. `sendEmail` might raise a java error too.

---

<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:** [February 21, 2025, 8:51pm UTC](https://forum.inductiveautomation.com/t/logger-usage-clarification/102717/9 "2025-02-21T20:51:50Z")

</div>

Nothing should be left going to `system.perspective.print()` when you are done. That is a burden on the browser connection, not just burning a bit of gateway CPU.

> [@Eugene49](#):
>
> For NQ result

Do something like this (with some help from my Integration Toolkit):

```python
# In some library
from java.lang import Throwable
logger = system.util.getLogger(system.util.getProjectName() + "." + system.reflect.getModulePath())

def someOperation(params):
	try:
		return system.db.runNamedQuery("path/to/query", params)
	except Throwable, t:
		logger.warnf("Java error in path/to/query: %s", [params], t)
	except Exception, e:
		logger.warnf("Jython error in path/to/query: %s", [params], system.reflect.asThrowable(e, None))

```

That will log errors in JDBC. You would then check the return value for expected results.

I use WARN level where the code should never fail that way without big problems. I use lesser log levels for unexpected/invalid result data.

Do similar with your email call.

---

<div class="post-metadata">

**Author:** ![Eugene49](https://avatars.discourse-cdn.com/v4/letter/e/c6cbf5/32.png) [@Eugene49](https://forum.inductiveautomation.com/u/Eugene49)\
**Post date:** [February 21, 2025, 8:56pm UTC](https://forum.inductiveautomation.com/t/logger-usage-clarification/102717/10 "2025-02-21T20:56:35Z")

</div>

> [@pturmel](#):
>
> Nothing should be left going to `system.perspective.print()` when you are done. That is a burden on the browser connection, not just burning a bit of gateway CPU.

Sounds good.

I will note this.  
And Yeah, i got it..

"I would only log when NQ returns error, and include queryPath and params to the log message, by converting params to string first"

For emails.  
Log every time, log both recipients and email subject.

---

<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:** [February 21, 2025, 9:01pm UTC](https://forum.inductiveautomation.com/t/logger-usage-clarification/102717/11 "2025-02-21T21:01:15Z")

</div>

> [@Eugene49](#):
>
> converting params to string first

Nah. See edit above. (Note quirk in `.warnf()` when also passing a `Throwable`.)

---

<div class="post-metadata">

**Author:** ![Eugene49](https://avatars.discourse-cdn.com/v4/letter/e/c6cbf5/32.png) [@Eugene49](https://forum.inductiveautomation.com/u/Eugene49)\
**Post date:** [February 21, 2025, 9:19pm UTC](https://forum.inductiveautomation.com/t/logger-usage-clarification/102717/12 "2025-02-21T21:19:34Z")

</div>

Cool the above does it.

Another Instance where I have a lot of debug messages is in sendMesage:  
sending side:

```python
	messageType = "btnSave"
	system.perspective.print("send message: %s" % messageType)
	system.perspective.sendMessage(messageType, payload={})

```

receiving side:

```python
	system.perspective.print("inside btnSave")

```

I guess I only want to show this during debuging..

---

<div class="post-metadata">

**Author:** ![Gustavo\_Cardoso](https://sea1.discourse-cdn.com/inductiveautomation/user_avatar/forum.inductiveautomation.com/gustavo_cardoso/32/85783_2.png) [@Gustavo\_Cardoso](https://forum.inductiveautomation.com/u/Gustavo_Cardoso)\
**Post date:** [June 8, 2026, 2:58pm UTC](https://forum.inductiveautomation.com/t/logger-usage-clarification/102717/13 "2026-06-08T14:58:22Z")

</div>

> [@pturmel](#):
>
> to minimize the performance penalty of logging. ( **Severe** performance hit.)

Hello everyone,

Reading this quote raised some questions for me regarding best logging practices in our systems. I'd love to get some clarity on how Ignition handles logging under the hood:

1. **Log Level Execution:** If I log something at the debug level (`logger.debug(...)`) but the logger's level is set to INFO, does this "log action" still execute, or is it bypassed entirely?

2. **Performance Impact:** What is the real danger here — the log method call itself, or the logger instantiation?

3. **Project Best Practices:** Is the best approach to instantiate a single logger for an entire project so all functions use the same object, or is it better to separate the loggers with better context names?

4. **Module Development:** This question extends to module development. I am creating loggers for specific classes within my devices (it's a driver module), using a hierarchical structure like `"ExampleDevice"`, `"ExampleDevice.MessageHandler"`, and `"ExampleDevice.MessageHandler.AlarmMessage"`. How many instances of loggers are "acceptable" for a module to create without hurting performance?

5. **Logger Lifecycle:** What is the lifecycle of a Logger object? When is an instance actually terminated/garbage collected?

**Note:** The link to the [LoggerEx](https://files.inductiveautomation.com/sdk/javadoc/ignition80/8.0.12/com/inductiveautomation/ignition/common/util/LoggerEx.html) documentation in the Ignition User Manual is currently not working (see the attached screenshot). Maybe it would have answered some of my questions!

 ![image](https://us1.discourse-cdn.com/inductiveautomation/original/3X/7/4/74a2d7e0e924dd3a6067b0490b133fec167f7ef7.png)

Thanks in advance for the help!

---

<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:** [June 8, 2026, 3:14pm UTC](https://forum.inductiveautomation.com/t/logger-usage-clarification/102717/14 "2026-06-08T15:14:04Z")

</div>

1. The `.debug()` method is called, but then does nothing more. It does mean the **arguments** to `.debug()` will be computed and passed, then discarded. That is why you should use `.debugf()`, which skips the message formatting when it can.

2. The hazard is constructing complex log messages just to throw them away.

3. Instantiate loggers as long-lived variables in the top level of project library scripts. (Outside any function definitions.) I typically use one per library script, named for the project and script path.

4. You should use canonical class names for your module logger names. Use a static final fields for per-class loggers. For long-lived class instances, a final field is also reasonable if you want to embed an instance name in the logger name.

5. Logger objects persist in the logging system for the life of the JVM, once created, IIUC.