ibm_zos_core
ibm_zos_core copied to clipboard
[Bug] [zos_mvs_raw] Verbose output is omitted if rc=0
Bug description
I have a playbook where I:
- create a data set.
- invoke
zos_mvs_raw
toLISTCAT
the data set - delete the data set.
With or without verbose enabled, the output is the same. There is no way for me to see the underlying ZOAU logs.
For example, if I were to call mvscmd on shell with verbose enabled, I see the ZOAU logs printed out at the bottom after the regular LISTCAT output:
1IDCAMS SYSTEM SERVICES TIME: 19:54:37 03/28/24 PAGE 1
0
LISTCAT ENTRIES('KETAN.PRIVATE.ONE')
0NONVSAM ------- KETAN.PRIVATE.ONE
IN-CAT --- CATALOG.SVPLEX9.MASTER
1IDCAMS SYSTEM SERVICES TIME: 19:54:37 03/28/24 PAGE 2
0 THE NUMBER OF ENTRIES PROCESSED WAS:
AIX -------------------0
ALIAS -----------------0
CLUSTER ---------------0
DATA ------------------0
GDG -------------------0
INDEX -----------------0
NONVSAM ---------------1
PAGESPACE -------------0
PATH ------------------0
SPACE -----------------0
USERCATALOG -----------0
TAPELIBRARY -----------0
TAPEVOLUME ------------0
TOTAL -----------------1
0 THE NUMBER OF PROTECTED ENTRIES SUPPRESSED WAS 0
0IDC0001I FUNCTION COMPLETED, HIGHEST CONDITION CODE WAS 0
0
0IDC0002I IDCAMS PROCESSING COMPLETE. MAXIMUM CONDITION CODE WAS 0
BGYSC0307I Program: <idcams> Arguments: <>
BGYSC0308I DDNames:
BGYSC0333I SYSIN=stdin
BGYSC0310I SYSPRINT=*
BGYSC0332I Dynamic allocation succeeded for SYSIN (temporary dataset for stdin)
BGYSC0304I Dynamic allocation succeeded for SYSPRINT (temporary dataset for console)
BGYSC0328I OS Load program IDCAMS
BGYSC0319I Program is APF authorized
BGYSC0320I Addressing mode: AMODE31
BGYSC0327I Attach Exit code: 0 from IDCAMS
BGYSC0355I Stdin free succeeded for SYSIN
BGYSC0356I Console free succeeded for SYSPRINT
Homework:
program_response = run_zos_program(
program=program,
parm=program_parm,
dd_statements=dd_statements,
authorized=authorized,
verbose=verbose,
)
if program_response.rc != 0 and program_response.stderr:
raise ZOSRawError(
program,
"{0} {1}".format(program_response.stdout, program_response.stderr),
)
response = build_response(program_response.rc, dd_statements)
result["changed"] = True
except Exception as e:
result["backups"] = backups
module.fail_json(msg=repr(e), **result)
In the above snippet from plugins/modules/zos_mvs_raw.py
, the run_zos_program
function calls either MVSCmd.execute_authorized
or MVSCmd.execute
, which in turn constructs a command string and passes it to run_command
. The run_command
function runs the mvscmd
and returns a tuple (rc, out, err)
(which is packaged into an MVSCmdReponse
object as rc
, stdout
, and stderr
).
Notice in the above snippet, where if the rc is not non-zero (ie rc=0), the rc
and the dd_statements is passed to a function build_response
. The out
and err
portion of the returned tuple are not captured. The verbose ZOAU logs would be in one of those.
Conversely, upon receiving a non-zero rc
, the out
and err
as well as the rc
are raised in an Error (and returned to the user).
The playbook:
vars:
RC_0_DATA_SET_NAME: "KETAN.ANSIBLE.ONE"
DATA_SET_TO_LISTCAT: "KETAN.ANSIBLE.SOMEDS"
IDCAMS_STDIN: " LISTCAT ENTRIES('{{ DATA_SET_TO_LISTCAT | upper }}')"
tasks:
- name: create some data set
block:
- name: create data set to LISTCAT
zos_data_set:
name: "{{ DATA_SET_TO_LISTCAT }}"
type: SEQ
state: present
replace: yes
- name: mvs raw with verbose with rc=0
zos_mvs_raw:
verbose: True
program_name: idcams
auth: True
dds:
- dd_data_set:
dd_name: SYSPRINT
data_set_name: "{{ RC_0_DATA_SET_NAME }}"
disposition: new
type: seq
return_content:
type: text
- dd_input:
dd_name: SYSIN
content: "{{ IDCAMS_STDIN }}"
register: output_rc_0
- name: print output
debug:
msg:
- "{{ output_rc_0 }}"
always:
- name: delete data sets
zos_data_set:
name: "{{ item }}"
state: absent
loop:
- "{{ DATA_SET_TO_LISTCAT }}"
- "{{ RC_0_DATA_SET_NAME }}"
Non-verbose output:
TASK [create data set to LISTCAT] *****************************************************************************************************************************************************************************************************************************
Thursday 28 March 2024 17:36:33 -0700 (0:00:00.007) 0:00:00.007 ********
changed: [zvm]
TASK [mvs raw with verbose with rc=0] *************************************************************************************************************************************************************************************************************************
Thursday 28 March 2024 17:36:36 -0700 (0:00:03.767) 0:00:03.775 ********
changed: [zvm]
TASK [print output] *******************************************************************************************************************************************************************************************************************************************
Thursday 28 March 2024 17:36:40 -0700 (0:00:03.107) 0:00:06.882 ********
ok: [zvm] => {
"msg": [
{
"backups": [],
"changed": true,
"dd_names": [
{
"byte_count": 1213,
"content": [
"\fIDCAMS SYSTEM SERVICES TIME: 20:36:39 03/28/24 PAGE 1",
"",
" ",
" LISTCAT ENTRIES('KETAN.ANSIBLE.SOMEDS')",
"",
"NONVSAM ------- KETAN.ANSIBLE.SOMEDS",
" IN-CAT --- CATALOG.SVPLEX9.MASTER\fIDCAMS SYSTEM SERVICES TIME: 20:36:39 03/28/24 PAGE 2",
"",
" THE NUMBER OF ENTRIES PROCESSED WAS:",
" AIX -------------------0",
" ALIAS -----------------0",
" CLUSTER ---------------0",
" DATA ------------------0",
" GDG -------------------0",
" INDEX -----------------0",
" NONVSAM ---------------1",
" PAGESPACE -------------0",
" PATH ------------------0",
" SPACE -----------------0",
" USERCATALOG -----------0",
" TAPELIBRARY -----------0",
" TAPEVOLUME ------------0",
" TOTAL -----------------1",
"",
" THE NUMBER OF PROTECTED ENTRIES SUPPRESSED WAS 0",
"",
"IDC0001I FUNCTION COMPLETED, HIGHEST CONDITION CODE WAS 0",
"",
" ",
"",
"IDC0002I IDCAMS PROCESSING COMPLETE. MAXIMUM CONDITION CODE WAS 0",
""
],
"dd_name": "SYSPRINT",
"name": "KETAN.ANSIBLE.ONE",
"record_count": 32
}
],
"failed": false,
"ret_code": {
"code": 0
}
}
]
}
See the verbose output below:
IBM z/OS Ansible core Version
v1.10.0-beta.1
IBM Z Open Automation Utilities
v1.3.0
IBM Enterprise Python
v3.11.x (default)
ansible-version
v2.15.x
z/OS version
v2.5 (default)
Ansible module
zos_mvs_raw
Playbook verbosity output.
ansible-playbook [core 2.15.5]
config file = /etc/ansible/ansible.cfg
configured module search path = ['/Users/ketan/.ansible/plugins/modules', '/usr/share/ansible/plugins/modules']
ansible python module location = /Users/ketan/venvs/3.11/ansible-2.15/lib/python3.11/site-packages/ansible
ansible collection location = /Users/ketan/.ansible/collections:/usr/share/ansible/collections
executable location = /Users/ketan/venvs/3.11/ansible-2.15/bin/ansible-playbook
python version = 3.11.3 (main, May 1 2023, 16:38:43) [Clang 14.0.3 (clang-1403.0.22.14.1)] (/Users/ketan/venvs/3.11/ansible-2.15/bin/python3.11)
jinja version = 3.1.2
libyaml = True
Using /etc/ansible/ansible.cfg as config file
host_list declined parsing /Users/ketan/inventory as it did not pass its verify_file() method
script declined parsing /Users/ketan/inventory as it did not pass its verify_file() method
auto declined parsing /Users/ketan/inventory as it did not pass its verify_file() method
Parsed /Users/ketan/inventory inventory source with ini plugin
redirecting (type: callback) ansible.builtin.profile_tasks to ansible.posix.profile_tasks
Skipping callback 'default', as we already have a stdout callback.
Skipping callback 'minimal', as we already have a stdout callback.
Skipping callback 'oneline', as we already have a stdout callback.
PLAYBOOK: npXzoau13X.yml **************************************************************************************************************************************************************************************************************************************
1 plays in npXzoau13X.yml
PLAY [npX,zoau1.3.X] ******************************************************************************************************************************************************************************************************************************************
TASK [create data set to LISTCAT] *****************************************************************************************************************************************************************************************************************************
task path: /Users/ketan/dev/playbooks/npXzoau13X.yml:47
Thursday 28 March 2024 17:07:21 -0700 (0:00:00.007) 0:00:00.007 ********
Using module file /Users/ketan/.ansible/collections/ansible_collections/ibm/ibm_zos_core/plugins/modules/zos_data_set.py
Pipelining is enabled.
<pkstnp9.pok.stglabs.ibm.com> ESTABLISH SSH CONNECTION FOR USER: KETAN
<pkstnp9.pok.stglabs.ibm.com> SSH: EXEC ssh -C -o ControlMaster=auto -o ControlPersist=60s -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o 'User="KETAN"' -o ConnectTimeout=10 -o 'ControlPath="/Users/ketan/.ansible/cp/64a13ee7bc"' pkstnp9.pok.stglabs.ibm.com '/bin/sh -c '"'"'_BPXK_AUTOCVT=ALL _CEE_RUNOPTS='"'"'"'"'"'"'"'"'FILETAG(AUTOCVT,AUTOTAG) POSIX(ON)'"'"'"'"'"'"'"'"' _TAG_REDIR_ERR=txt _TAG_REDIR_IN=txt _TAG_REDIR_OUT=txt LANG=C ZOAU=/global/zoautil/1.3.0.0/bin LIBPATH=/global/zoautil/1.3.0.0/lib/:/global/cyp/3.11/usr/lpp/IBM/cyp/v3r11/pyz/lib:/lib:/usr/lib:. PYTHONPATH=/global/zoautil/1.3.0.0/lib/3.11 PATH=/global/zoautil/1.3.0.0/bin:/global/cyp/3.11/usr/lpp/IBM/cyp/v3r11/pyz/bin:/bin:/usr/sbin:/var/bin:. PYTHONSTDINENCODING=cp1047 /global/cyp/3.11/usr/lpp/IBM/cyp/v3r11/pyz/bin/python3 && sleep 0'"'"''
<pkstnp9.pok.stglabs.ibm.com> (0, b'\n{"changed": true, "message": "", "names": ["KETAN.ANSIBLE.SOMEDS"], "invocation": {"module_args": {"name": "KETAN.ANSIBLE.SOMEDS", "type": "SEQ", "state": "present", "replace": true, "space_type": "M", "space_primary": 5, "space_secondary": 3, "record_format": "FB", "force": false, "batch": null, "sms_management_class": null, "sms_storage_class": null, "sms_data_class": null, "block_size": null, "directory_blocks": null, "record_length": null, "key_offset": null, "key_length": null, "volumes": null, "tmp_hlq": null}}}\n', b'')
changed: [zvm] => {
"changed": true,
"invocation": {
"module_args": {
"batch": null,
"block_size": null,
"directory_blocks": null,
"force": false,
"key_length": null,
"key_offset": null,
"name": "KETAN.ANSIBLE.SOMEDS",
"record_format": "FB",
"record_length": null,
"replace": true,
"sms_data_class": null,
"sms_management_class": null,
"sms_storage_class": null,
"space_primary": 5,
"space_secondary": 3,
"space_type": "M",
"state": "present",
"tmp_hlq": null,
"type": "SEQ",
"volumes": null
}
},
"message": "",
"names": [
"KETAN.ANSIBLE.SOMEDS"
]
}
TASK [mvs raw with verbose with rc=0] *************************************************************************************************************************************************************************************************************************
task path: /Users/ketan/dev/playbooks/npXzoau13X.yml:54
Thursday 28 March 2024 17:07:25 -0700 (0:00:03.808) 0:00:03.815 ********
Using module file /Users/ketan/.ansible/collections/ansible_collections/ibm/ibm_zos_core/plugins/modules/zos_mvs_raw.py
Pipelining is enabled.
<pkstnp9.pok.stglabs.ibm.com> ESTABLISH SSH CONNECTION FOR USER: KETAN
<pkstnp9.pok.stglabs.ibm.com> SSH: EXEC ssh -C -o ControlMaster=auto -o ControlPersist=60s -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o 'User="KETAN"' -o ConnectTimeout=10 -o 'ControlPath="/Users/ketan/.ansible/cp/64a13ee7bc"' pkstnp9.pok.stglabs.ibm.com '/bin/sh -c '"'"'_BPXK_AUTOCVT=ALL _CEE_RUNOPTS='"'"'"'"'"'"'"'"'FILETAG(AUTOCVT,AUTOTAG) POSIX(ON)'"'"'"'"'"'"'"'"' _TAG_REDIR_ERR=txt _TAG_REDIR_IN=txt _TAG_REDIR_OUT=txt LANG=C ZOAU=/global/zoautil/1.3.0.0/bin LIBPATH=/global/zoautil/1.3.0.0/lib/:/global/cyp/3.11/usr/lpp/IBM/cyp/v3r11/pyz/lib:/lib:/usr/lib:. PYTHONPATH=/global/zoautil/1.3.0.0/lib/3.11 PATH=/global/zoautil/1.3.0.0/bin:/global/cyp/3.11/usr/lpp/IBM/cyp/v3r11/pyz/bin:/bin:/usr/sbin:/var/bin:. PYTHONSTDINENCODING=cp1047 /global/cyp/3.11/usr/lpp/IBM/cyp/v3r11/pyz/bin/python3 && sleep 0'"'"''
<pkstnp9.pok.stglabs.ibm.com> (0, b'\n{"changed": true, "dd_names": [{"dd_name": "SYSPRINT", "name": "KETAN.ANSIBLE.ONE", "content": ["\\fIDCAMS SYSTEM SERVICES TIME: 20:07:28 03/28/24 PAGE 1", "", " ", " LISTCAT ENTRIES(\'KETAN.ANSIBLE.SOMEDS\')", "", "NONVSAM ------- KETAN.ANSIBLE.SOMEDS", " IN-CAT --- CATALOG.SVPLEX9.MASTER\\fIDCAMS SYSTEM SERVICES TIME: 20:07:28 03/28/24 PAGE 2", "", " THE NUMBER OF ENTRIES PROCESSED WAS:", " AIX -------------------0", " ALIAS -----------------0", " CLUSTER ---------------0", " DATA ------------------0", " GDG -------------------0", " INDEX -----------------0", " NONVSAM ---------------1", " PAGESPACE -------------0", " PATH ------------------0", " SPACE -----------------0", " USERCATALOG -----------0", " TAPELIBRARY -----------0", " TAPEVOLUME ------------0", " TOTAL -----------------1", "", " THE NUMBER OF PROTECTED ENTRIES SUPPRESSED WAS 0", "", "IDC0001I FUNCTION COMPLETED, HIGHEST CONDITION CODE WAS 0", "", " ", "", "IDC0002I IDCAMS PROCESSING COMPLETE. MAXIMUM CONDITION CODE WAS 0", ""], "record_count": 32, "byte_count": 1213}], "ret_code": {"code": 0}, "backups": [], "invocation": {"module_args": {"verbose": true, "program_name": "idcams", "auth": true, "dds": [{"dd_data_set": {"dd_name": "SYSPRINT", "data_set_name": "KETAN.ANSIBLE.ONE", "disposition": "new", "type": "seq", "return_content": {"type": "text", "src_encoding": "ibm-1047", "response_encoding": "iso8859-1"}, "reuse": false, "replace": false, "backup": false, "disposition_normal": null, "disposition_abnormal": null, "space_type": null, "space_primary": null, "space_secondary": null, "volumes": null, "sms_management_class": null, "sms_storage_class": null, "sms_data_class": null, "block_size": null, "directory_blocks": null, "key_label": null, "encryption_key_1": null, "encryption_key_2": null, "key_length": null, "key_offset": null, "record_length": null, "record_format": null}, "dd_unix": null, "dd_input": null, "dd_output": null, "dd_vio": null, "dd_concat": null, "dd_dummy": null}, {"dd_input": {"dd_name": "SYSIN", "content": " LISTCAT ENTRIES(\'KETAN.ANSIBLE.SOMEDS\')", "return_content": null}, "dd_data_set": null, "dd_unix": null, "dd_output": null, "dd_vio": null, "dd_concat": null, "dd_dummy": null}], "parm": null, "tmp_hlq": null}}}\n', b'')
changed: [zvm] => {
"backups": [],
"changed": true,
"dd_names": [
{
"byte_count": 1213,
"content": [
"\fIDCAMS SYSTEM SERVICES TIME: 20:07:28 03/28/24 PAGE 1",
"",
" ",
" LISTCAT ENTRIES('KETAN.ANSIBLE.SOMEDS')",
"",
"NONVSAM ------- KETAN.ANSIBLE.SOMEDS",
" IN-CAT --- CATALOG.SVPLEX9.MASTER\fIDCAMS SYSTEM SERVICES TIME: 20:07:28 03/28/24 PAGE 2",
"",
" THE NUMBER OF ENTRIES PROCESSED WAS:",
" AIX -------------------0",
" ALIAS -----------------0",
" CLUSTER ---------------0",
" DATA ------------------0",
" GDG -------------------0",
" INDEX -----------------0",
" NONVSAM ---------------1",
" PAGESPACE -------------0",
" PATH ------------------0",
" SPACE -----------------0",
" USERCATALOG -----------0",
" TAPELIBRARY -----------0",
" TAPEVOLUME ------------0",
" TOTAL -----------------1",
"",
" THE NUMBER OF PROTECTED ENTRIES SUPPRESSED WAS 0",
"",
"IDC0001I FUNCTION COMPLETED, HIGHEST CONDITION CODE WAS 0",
"",
" ",
"",
"IDC0002I IDCAMS PROCESSING COMPLETE. MAXIMUM CONDITION CODE WAS 0",
""
],
"dd_name": "SYSPRINT",
"name": "KETAN.ANSIBLE.ONE",
"record_count": 32
}
],
"invocation": {
"module_args": {
"auth": true,
"dds": [
{
"dd_concat": null,
"dd_data_set": {
"backup": false,
"block_size": null,
"data_set_name": "KETAN.ANSIBLE.ONE",
"dd_name": "SYSPRINT",
"directory_blocks": null,
"disposition": "new",
"disposition_abnormal": null,
"disposition_normal": null,
"encryption_key_1": null,
"encryption_key_2": null,
"key_label": null,
"key_length": null,
"key_offset": null,
"record_format": null,
"record_length": null,
"replace": false,
"return_content": {
"response_encoding": "iso8859-1",
"src_encoding": "ibm-1047",
"type": "text"
},
"reuse": false,
"sms_data_class": null,
"sms_management_class": null,
"sms_storage_class": null,
"space_primary": null,
"space_secondary": null,
"space_type": null,
"type": "seq",
"volumes": null
},
"dd_dummy": null,
"dd_input": null,
"dd_output": null,
"dd_unix": null,
"dd_vio": null
},
{
"dd_concat": null,
"dd_data_set": null,
"dd_dummy": null,
"dd_input": {
"content": " LISTCAT ENTRIES('KETAN.ANSIBLE.SOMEDS')",
"dd_name": "SYSIN",
"return_content": null
},
"dd_output": null,
"dd_unix": null,
"dd_vio": null
}
],
"parm": null,
"program_name": "idcams",
"tmp_hlq": null,
"verbose": true
}
},
"ret_code": {
"code": 0
}
}
TASK [print output] *******************************************************************************************************************************************************************************************************************************************
task path: /Users/ketan/dev/playbooks/npXzoau13X.yml:91
Thursday 28 March 2024 17:07:29 -0700 (0:00:03.946) 0:00:07.762 ********
ok: [zvm] => {
"msg": [
{
"backups": [],
"changed": true,
"dd_names": [
{
"byte_count": 1213,
"content": [
"\fIDCAMS SYSTEM SERVICES TIME: 20:07:28 03/28/24 PAGE 1",
"",
" ",
" LISTCAT ENTRIES('KETAN.ANSIBLE.SOMEDS')",
"",
"NONVSAM ------- KETAN.ANSIBLE.SOMEDS",
" IN-CAT --- CATALOG.SVPLEX9.MASTER\fIDCAMS SYSTEM SERVICES TIME: 20:07:28 03/28/24 PAGE 2",
"",
" THE NUMBER OF ENTRIES PROCESSED WAS:",
" AIX -------------------0",
" ALIAS -----------------0",
" CLUSTER ---------------0",
" DATA ------------------0",
" GDG -------------------0",
" INDEX -----------------0",
" NONVSAM ---------------1",
" PAGESPACE -------------0",
" PATH ------------------0",
" SPACE -----------------0",
" USERCATALOG -----------0",
" TAPELIBRARY -----------0",
" TAPEVOLUME ------------0",
" TOTAL -----------------1",
"",
" THE NUMBER OF PROTECTED ENTRIES SUPPRESSED WAS 0",
"",
"IDC0001I FUNCTION COMPLETED, HIGHEST CONDITION CODE WAS 0",
"",
" ",
"",
"IDC0002I IDCAMS PROCESSING COMPLETE. MAXIMUM CONDITION CODE WAS 0",
""
],
"dd_name": "SYSPRINT",
"name": "KETAN.ANSIBLE.ONE",
"record_count": 32
}
],
"failed": false,
"ret_code": {
"code": 0
}
}
]
}