[BUG] Log cluttered with message: "'delimiter' and 'merge' options of 'config.get' are skipped when the salt command type is 'unknown'"

[danny-smit]

Your setup

Formula commit hash / release tag

Using openssh-formula: 3.0.1 Using the python client API to trigger the salt run: https://docs.saltproject.io/en/latest/ref/clients/index.html

Versions reports (master & minion)

v3004

Pillar / config used

Default pillar.example. Any configuration will do.

---

Bug details

Describe the bug

When salt states are executed using the salt client API, the openssh formula is cluttering the logs with the following message:

map.jinja: the 'delimiter' and 'merge' options of 'config.get' are skipped when the salt command type is 'unknown'

Source of the error is: https://github.com/saltstack-formulas/openssh-formula/blob/v3.0.1/openssh/libmatchers.jinja#L179 which depends on: https://github.com/saltstack-formulas/openssh-formula/blob/v3.0.1/openssh/libsaltcli.jinja

With the python api, the __cli parameter in libsaltcli.jinja, is filled with the name of the python script that is executed. Which can be anything.

Steps to reproduce the bug

$> python3                                                    
>>> import logging
>>> logging.basicConfig()                                                        
>>>                                                                              
>>> import salt.client
>>> caller = salt.client.Caller()                                                
>>>                                                                              
>>> caller.cmd('state.apply', 'openssh')          
ERROR:salt.loaded.int.module.logmod:map.jinja configuration: the 'delimiter' and 'merge' options of 'config.get' are skipped when the salt command type is 'unknown'          
ERROR:salt.loaded.int.module.logmod:map.jinja: the 'delimiter' and 'merge' options of 'config.get' are skipped when the salt command type is 'unknown'                        
ERROR:salt.loaded.int.module.logmod:map.jinja: the 'delimiter' and 'merge' options of 'config.get' are skipped when the salt command type is 'unknown'                        
...                             

Expected behaviour

No error, as the formula functions normally.

Attempts to fix the bug

Best fix: Change log.error to log.debug in: https://github.com/saltstack-formulas/openssh-formula/blob/v3.0.1/openssh/libmatchers.jinja#L179

Alternative hack: Work around the error by forcing the python code to identify as the salt minion:

opts = salt.config.minion_config('/etc/salt/minion')
opts['__cli'] = 'salt-minion'
caller = salt.client.Caller(mopts=opts)

Additional context

[myii]

Thanks for the report, @danny-smit. We haven't catered for the Salt Client API yet. This issue is actually more general than this formula; any changes will be needed to be pushed across numerous formulas.

@baby-gnu Any idea on how we should go about handling this? Ideally, fixing libsaltcli.jinja would be best but:

With the python api, the __cli parameter in libsaltcli.jinja, is filled with the name of the python script that is executed. Which can be anything.

[baby-gnu]

Hello.

I think we could set cli in libsaltcli.jinja to api before doing the final else if the option is set and keep unknown only when the value is not defined:

diff --git a/TEMPLATE/libsaltcli.jinja b/TEMPLATE/libsaltcli.jinja
index 5c3593e..c6a5b25 100644
--- a/TEMPLATE/libsaltcli.jinja
+++ b/TEMPLATE/libsaltcli.jinja
@@ -10,6 +10,8 @@
 {%-   set cli = 'minion' %}
 {%- elif opts_cli == 'salt-call' %}
 {%-   set cli = 'ssh' if opts_masteropts_cli in ('salt-ssh', 'salt-master') else 'local' %}
+{%- elif opts_cli %}
+{%-   set cli = 'api' %}
 {%- else %}
 {%-   set cli = 'unknown' %}
 {%- endif %}

Then, we rework a little the libmatchers.jinja to apply the merge strategy of config.get except for ssh and unknown

diff --git a/TEMPLATE/libmatchers.jinja b/TEMPLATE/libmatchers.jinja
index 1b1c705..3424923 100644
--- a/TEMPLATE/libmatchers.jinja
+++ b/TEMPLATE/libmatchers.jinja
@@ -162,7 +162,7 @@
 {%-     endif %}

 {#-     Add `merge:` option to `salt["config.get"]` if configured #}
-{%-     if cli in ["minion", "local"] and parsed.query_method == "config.get" and config_get_strategy %}
+{%-     if cli not in ["ssh", "unknown"] and parsed.query_method == "config.get" and config_get_strategy %}
 {%-       set query_opts = {
             "merge": config_get_strategy,
             "delimiter": parsed.query_delimiter,
@@ -175,7 +175,7 @@
             ~ "'"
           ) %}
 {%-     else %}
-{%-       if cli not in ["minion", "local"] %}
+{%-       if cli in ["ssh", "unknown"] %}
 {%-         do salt["log.error"](
               log_prefix
               ~ "the 'delimiter' and 'merge' options of 'config.get' are skipped when the salt command type is '"

Because the merge is a problem only for salt-ssh, the unknown case should not happen (maybe could not?).

[baby-gnu]

I think we could change the logging to warning instead of error:

diff --git a/TEMPLATE/libmatchers.jinja b/TEMPLATE/libmatchers.jinja
index 1b1c705..6a7196f 100644
--- a/TEMPLATE/libmatchers.jinja
+++ b/TEMPLATE/libmatchers.jinja
@@ -162,7 +162,7 @@
 {%-     endif %}

 {#-     Add `merge:` option to `salt["config.get"]` if configured #}
-{%-     if cli in ["minion", "local"] and parsed.query_method == "config.get" and config_get_strategy %}
+{%-     if cli not in ["ssh", "unknown"] and parsed.query_method == "config.get" and config_get_strategy %}
 {%-       set query_opts = {
             "merge": config_get_strategy,
             "delimiter": parsed.query_delimiter,
@@ -175,8 +175,8 @@
             ~ "'"
           ) %}
 {%-     else %}
-{%-       if cli not in ["minion", "local"] %}
-{%-         do salt["log.error"](
+{%-       if cli in ["ssh", "unknown"] %}
+{%-         do salt["log.warning"](
               log_prefix
               ~ "the 'delimiter' and 'merge' options of 'config.get' are skipped when the salt command type is '"
               ~ cli

[myii]

@baby-gnu Thanks for breaking that down. Shall we try it out in a PR for this formula? If all works well, we can then push the changes out to the other formulas.

[baby-gnu]

@danny-smit note that running directly from the python3 command line always trigger the bug since sys.argv is not set:

# python3
Python 3.9.2 (default, Feb 28 2021, 17:03:44) 
[GCC 10.2.1 20210110] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import logging
>>> logging.basicConfig()
>>> import salt.client
>>> caller = salt.client.Caller()
>>> caller.cmd('state.apply', 'foo.test')
WARNING:salt.loaded.int.module.logmod:map.jinja configuration: the 'delimiter' and 'merge' options of 'config.get' are skipped when the salt command type is 'unknown'
WARNING:salt.loaded.int.module.logmod:map.jinja: the 'delimiter' and 'merge' options of 'config.get' are skipped when the salt command type is 'unknown'
WARNING:salt.loaded.int.module.logmod:map.jinja: the 'delimiter' and 'merge' options of 'config.get' are skipped when the salt command type is 'unknown'
WARNING:salt.loaded.int.module.logmod:map.jinja: the 'delimiter' and 'merge' options of 'config.get' are skipped when the salt command type is 'unknown'
WARNING:salt.loaded.int.module.logmod:map.jinja: the 'delimiter' and 'merge' options of 'config.get' are skipped when the salt command type is 'unknown'
WARNING:salt.loaded.int.module.logmod:map.jinja: the 'delimiter' and 'merge' options of 'config.get' are skipped when the salt command type is 'unknown'
WARNING:salt.loaded.int.module.logmod:map.jinja: the 'delimiter' and 'merge' options of 'config.get' are skipped when the salt command type is 'unknown'
WARNING:salt.loaded.int.module.logmod:map.jinja: the 'delimiter' and 'merge' options of 'config.get' are skipped when the salt command type is 'unknown'
WARNING:salt.loaded.int.module.logmod:map.jinja: the 'delimiter' and 'merge' options of 'config.get' are skipped when the salt command type is 'unknown'
{'test_|-do-nothing_|-do-nothing_|-nop': {'name': 'do-nothing', 'changes': {}, 'result': True, 'comment': 'Success!', '__sls__': 'foo.test', '__run_num__': 0, 'start_time': '14:42:19.113104', 'duration': 0.64, '__id__': 'do-nothing'}}

When overriding sys.argv, it's working as expected:

# python3
Python 3.9.2 (default, Feb 28 2021, 17:03:44) 
[GCC 10.2.1 20210110] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import sys
>>> sys.argv=['bidule']
>>> import logging
>>> logging.basicConfig()
>>> import salt.client
>>> caller = salt.client.Caller()
>>> caller.cmd('state.apply', 'foo.test')
{'test_|-do-nothing_|-do-nothing_|-nop': {'name': 'do-nothing', 'changes': {}, 'result': True, 'comment': 'Success!', '__sls__': 'foo.test', '__run_num__': 0, 'start_time': '14:41:13.997712', 'duration': 0.736, '__id__': 'do-nothing'}}

[myii]

@danny-smit This has been fixed by #204. I'd appreciate it if you could confirm that this is now working properly, so that we can propagate this through all the formulas using the same libraries.

[saltstack-formulas-travis]

:tada: This issue has been resolved in version 3.0.2 :tada:

The release is available on GitHub release

Your semantic-release bot :package::rocket:

[danny-smit]

note that running directly from the python3 command line always trigger the bug since sys.argv is not set:

@baby-gnu Thanks. The python3 command line was just to provide an easily reproducible scenario, my actual use case is running it from a python script. So this change helps!

I'd appreciate it if you could confirm that this is now working properly, so that we can propagate this through all the formulas using the same libraries.

@myii Yes, I can confirm that this resolves the issue.

Thanks to both of you!