[Bug] zos_jobs_submit failed without any explanation when having a JCL Error #624

vlodeibm · 2023-01-30T16:52:49Z

Bug description

When using zos_jobs_submit to submit a JCL on which one we have an JCL Error, with have this message :
module_stderr: Shared connection to 9.30.222.103 closed.
module_stdout: |-
Traceback (most recent call last):
File "/u/vlode/.ansible/tmp/ansible-tmp-1675089822.939972-3762-210145075551644/AnsiballZ_zos_job_submit.py", line 100, in
_ansiballz_main()
File "/u/vlode/.ansible/tmp/ansible-tmp-1675089822.939972-3762-210145075551644/AnsiballZ_zos_job_submit.py", line 92, in _ansiballz_main
invoke_module(zipped_mod, temp_path, ANSIBALLZ_PARAMS)
File "/u/vlode/.ansible/tmp/ansible-tmp-1675089822.939972-3762-210145075551644/AnsiballZ_zos_job_submit.py", line 40, in invoke_module
runpy.run_module(mod_name='ansible_collections.ibm.ibm_zos_core.plugins.modules.zos_job_submit', init_globals=dict(_module_fqn='ansible_collections.ibm.ibm_zos_core.plugins.modules.zos_job_submit', _modlib_path=modlib_path),
File "/var/usr/lpp/IBM/cyp/v3r10/pyz/lib/python3.10/runpy.py", line 224, in run_module
return _run_module_code(code, init_globals, run_name, mod_spec)
File "/var/usr/lpp/IBM/cyp/v3r10/pyz/lib/python3.10/runpy.py", line 96, in _run_module_code
_run_code(code, mod_globals, init_globals,
File "/var/usr/lpp/IBM/cyp/v3r10/pyz/lib/python3.10/runpy.py", line 86, in _run_code
exec(code, run_globals)
File "/tmp/ansible_ibm.ibm_zos_core.zos_job_submit_payload_czn4l_ba/ansible_ibm.ibm_zos_core.zos_job_submit_payload.zip/ansible_collections/ibm/ibm_zos_core/plugins/modules/zos_job_submit.py", line 907, in
File "/tmp/ansible_ibm.ibm_zos_core.zos_job_submit_payload_czn4l_ba/ansible_ibm.ibm_zos_core.zos_job_submit_payload.zip/ansible_collections/ibm/ibm_zos_core/plugins/modules/zos_job_submit.py", line 903, in main
File "/tmp/ansible_ibm.ibm_zos_core.zos_job_submit_payload_czn4l_ba/ansible_ibm.ibm_zos_core.zos_job_submit_payload.zip/ansible_collections/ibm/ibm_zos_core/plugins/modules/zos_job_submit.py", line 854, in run_module
File "/tmp/ansible_ibm.ibm_zos_core.zos_job_submit_payload_czn4l_ba/ansible_ibm.ibm_zos_core.zos_job_submit_payload.zip/ansible_collections/ibm/ibm_zos_core/plugins/modules/zos_job_submit.py", line 656, in assert_valid_return_code
main.SubmitJCLError
msg: |-
MODULE FAILURE
See stdout/stderr for the exact error

In 1.3.6, we had all the output of the job (= zos_jobs_output) with the JCL Error :
jobs:
- class: A
content_type: JOB
ddnames:
- byte_count: '1079'
content:
- '1 J E S 2 J O B L O G -- S Y S T E M I
P O 1 -- N O D E T I V L P 0 2 '
- '0 '
- ' 10.29.26 JOB09018 ---- MONDAY, 30 JAN 2023 ----'
- ' 10.29.26 JOB09018 IRR010I USERID VLODE IS ASSIGNED TO THIS
JOB.'
- ' 10.29.26 JOB09018 ICH70001I VLODE LAST ACCESS AT 10:29:07
ON MONDAY, JANUARY 30, 2023'
- ' 10.29.26 JOB09018 $HASP373 FREE STARTED - INIT F - CLASS
A - SYS IPO1'
- ' 10.29.26 JOB09018 - --TIMINGS
(MINS.)-- ----PAGING COUNTS---'
- ' 10.29.26 JOB09018 -JOBNAME STEPNAME PROCSTEP RC EXCP CONN TCB SRB CLOCK SERV PG PAGE SWAP VIO
SWAPS'
- ' 10.29.26 JOB09018 -FREE STEP1 FLUSH 0 0 .00 .00 .0 0 0 0 0 0 0'
- ' 10.29.26 JOB09018 IEF453I FREE - JOB FAILED - JCL ERROR'
- ' 10.29.26 JOB09018 -FREE ENDED. NAME- TOTAL
TCB CPU TIME= .00 TOTAL ELAPSED TIME= .0'
- ' 10.29.26 JOB09018 $HASP395 FREE ENDED'
- 0------ JES2 JOB STATISTICS ------
- '- 30 JAN 2023 JOB EXECUTION DATE'
- '- 11 CARDS READ'
- '- 47 SYSOUT PRINT RECORDS'
- '- 0 SYSOUT PUNCH RECORDS'
- '- 6 SYSOUT SPOOL KBYTES'
- '- 0.00 MINUTES EXECUTION TIME'
- ' 1 //FREE JOB ''FREE'',MSGLEVEL=(1,1),MSGCLASS=R,NOTIFY=&SYSUID JOB09018'
- ' IEFC653I SUBSTITUTION JCL - ''FREE'',MSGLEVEL=(1,1),MSGCLASS=R,NOTIFY=VLODE'
- ' 2 //JOBLIB DD DISP=SHR,DSN=NAZARE.WDEPLOY.BNPP.LOADBA '
- ' 3 // DD DISP=SHR,DSN=NAZARE.WDEPLOY.BNPP.LOADSP '
- ' //* '
- ' 4 //STEP1 EXEC PGM=IDCAMS '
- ' 5 //SYSPRINT DD SYSOUT=* '
- ' 6 //SYSOUT DD SYSOUT=* '
- ' /* '
- ' 7 //SYSIN DD * '
- ' ICH70001I VLODE LAST ACCESS AT 10:29:07 ON MONDAY, JANUARY
30, 2023'
- ' IEFA111I FREE IS USING THE FOLLOWING JOB RELATED SETTINGS:'
- ' SWA=BELOW,TIOT SIZE=32K,DSENQSHR=DISALLOW,GDGBIAS=JOB'
- ' IEFA107I FREE STEP1 JOBLIB - DATA SET NAZARE.WDEPLOY.BNPP.LOADBA
NOT FOUND'
- ' IEF272I FREE STEP1 - STEP WAS NOT EXECUTED.'
- ' IEF373I STEP/STEP1 /START 2023030.1029'
- ' IEF032I STEP/STEP1 /STOP 2023030.1029 '
- ' CPU: 0 HR 00 MIN 00.00 SEC SRB: 0 HR 00
MIN 00.00 SEC '
- ' VIRT: 0K SYS: 0K EXT: 0K SYS: 0K'
- ' ATB- REAL: 1044K SLOTS: 0K'
- ' VIRT- ALLOC: 11M SHRD: 0M'
- ' IEF375I JOB/FREE /START 2023030.1029'
- ' IEF033I JOB/FREE /STOP 2023030.1029 '
- ' CPU: 0 HR 00 MIN 00.00 SEC SRB: 0 HR 00
MIN 00.00 SEC '
ddname: JESMSGLG
id: '2'
procstep: ''
record_count: '19'
stepname: JES2
- byte_count: '502'
content:
- '1 J E S 2 J O B L O G -- S Y S T E M I
P O 1 -- N O D E T I V L P 0 2 '
- '0 '
- ' 10.29.26 JOB09018 ---- MONDAY, 30 JAN 2023 ----'
- ' 10.29.26 JOB09018 IRR010I USERID VLODE IS ASSIGNED TO THIS
JOB.'
- ' 10.29.26 JOB09018 ICH70001I VLODE LAST ACCESS AT 10:29:07
ON MONDAY, JANUARY 30, 2023'
- ' 10.29.26 JOB09018 $HASP373 FREE STARTED - INIT F - CLASS
A - SYS IPO1'
- ' 10.29.26 JOB09018 - --TIMINGS
(MINS.)-- ----PAGING COUNTS---'
- ' 10.29.26 JOB09018 -JOBNAME STEPNAME PROCSTEP RC EXCP CONN TCB SRB CLOCK SERV PG PAGE SWAP VIO
SWAPS'
- ' 10.29.26 JOB09018 -FREE STEP1 FLUSH 0 0 .00 .00 .0 0 0 0 0 0 0'
- ' 10.29.26 JOB09018 IEF453I FREE - JOB FAILED - JCL ERROR'
- ' 10.29.26 JOB09018 -FREE ENDED. NAME- TOTAL
TCB CPU TIME= .00 TOTAL ELAPSED TIME= .0'
- ' 10.29.26 JOB09018 $HASP395 FREE ENDED'
- 0------ JES2 JOB STATISTICS ------
- '- 30 JAN 2023 JOB EXECUTION DATE'
- '- 11 CARDS READ'
- '- 47 SYSOUT PRINT RECORDS'
- '- 0 SYSOUT PUNCH RECORDS'
- '- 6 SYSOUT SPOOL KBYTES'
- '- 0.00 MINUTES EXECUTION TIME'
- ' 1 //FREE JOB ''FREE'',MSGLEVEL=(1,1),MSGCLASS=R,NOTIFY=&SYSUID JOB09018'
- ' IEFC653I SUBSTITUTION JCL - ''FREE'',MSGLEVEL=(1,1),MSGCLASS=R,NOTIFY=VLODE'
- ' 2 //JOBLIB DD DISP=SHR,DSN=NAZARE.WDEPLOY.BNPP.LOADBA '
- ' 3 // DD DISP=SHR,DSN=NAZARE.WDEPLOY.BNPP.LOADSP '
- ' //* '
- ' 4 //STEP1 EXEC PGM=IDCAMS '
- ' 5 //SYSPRINT DD SYSOUT=* '
- ' 6 //SYSOUT DD SYSOUT=* '
- ' /* '
- ' 7 //SYSIN DD * '
- ' ICH70001I VLODE LAST ACCESS AT 10:29:07 ON MONDAY, JANUARY
30, 2023'
- ' IEFA111I FREE IS USING THE FOLLOWING JOB RELATED SETTINGS:'
- ' SWA=BELOW,TIOT SIZE=32K,DSENQSHR=DISALLOW,GDGBIAS=JOB'
- ' IEFA107I FREE STEP1 JOBLIB - DATA SET NAZARE.WDEPLOY.BNPP.LOADBA
NOT FOUND'
- ' IEF272I FREE STEP1 - STEP WAS NOT EXECUTED.'
- ' IEF373I STEP/STEP1 /START 2023030.1029'
- ' IEF032I STEP/STEP1 /STOP 2023030.1029 '
- ' CPU: 0 HR 00 MIN 00.00 SEC SRB: 0 HR 00
MIN 00.00 SEC '
- ' VIRT: 0K SYS: 0K EXT: 0K SYS: 0K'
- ' ATB- REAL: 1044K SLOTS: 0K'
- ' VIRT- ALLOC: 11M SHRD: 0M'
- ' IEF375I JOB/FREE /START 2023030.1029'
- ' IEF033I JOB/FREE /STOP 2023030.1029 '
- ' CPU: 0 HR 00 MIN 00.00 SEC SRB: 0 HR 00
MIN 00.00 SEC '
ddname: JESJCL
id: '3'
procstep: ''
record_count: '10'
stepname: JES2
- byte_count: '878'
content:
- '1 J E S 2 J O B L O G -- S Y S T E M I
P O 1 -- N O D E T I V L P 0 2 '
- '0 '
- ' 10.29.26 JOB09018 ---- MONDAY, 30 JAN 2023 ----'
- ' 10.29.26 JOB09018 IRR010I USERID VLODE IS ASSIGNED TO THIS
JOB.'
- ' 10.29.26 JOB09018 ICH70001I VLODE LAST ACCESS AT 10:29:07
ON MONDAY, JANUARY 30, 2023'
- ' 10.29.26 JOB09018 $HASP373 FREE STARTED - INIT F - CLASS
A - SYS IPO1'
- ' 10.29.26 JOB09018 - --TIMINGS
(MINS.)-- ----PAGING COUNTS---'
- ' 10.29.26 JOB09018 -JOBNAME STEPNAME PROCSTEP RC EXCP CONN TCB SRB CLOCK SERV PG PAGE SWAP VIO
SWAPS'
- ' 10.29.26 JOB09018 -FREE STEP1 FLUSH 0 0 .00 .00 .0 0 0 0 0 0 0'
- ' 10.29.26 JOB09018 IEF453I FREE - JOB FAILED - JCL ERROR'
- ' 10.29.26 JOB09018 -FREE ENDED. NAME- TOTAL
TCB CPU TIME= .00 TOTAL ELAPSED TIME= .0'
- ' 10.29.26 JOB09018 $HASP395 FREE ENDED'
- 0------ JES2 JOB STATISTICS ------
- '- 30 JAN 2023 JOB EXECUTION DATE'
- '- 11 CARDS READ'
- '- 47 SYSOUT PRINT RECORDS'
- '- 0 SYSOUT PUNCH RECORDS'
- '- 6 SYSOUT SPOOL KBYTES'
- '- 0.00 MINUTES EXECUTION TIME'
- ' 1 //FREE JOB ''FREE'',MSGLEVEL=(1,1),MSGCLASS=R,NOTIFY=&SYSUID JOB09018'
- ' IEFC653I SUBSTITUTION JCL - ''FREE'',MSGLEVEL=(1,1),MSGCLASS=R,NOTIFY=VLODE'
- ' 2 //JOBLIB DD DISP=SHR,DSN=NAZARE.WDEPLOY.BNPP.LOADBA '
- ' 3 // DD DISP=SHR,DSN=NAZARE.WDEPLOY.BNPP.LOADSP '
- ' //* '
- ' 4 //STEP1 EXEC PGM=IDCAMS '
- ' 5 //SYSPRINT DD SYSOUT=* '
- ' 6 //SYSOUT DD SYSOUT=* '
- ' /* '
- ' 7 //SYSIN DD * '
- ' ICH70001I VLODE LAST ACCESS AT 10:29:07 ON MONDAY, JANUARY
30, 2023'
- ' IEFA111I FREE IS USING THE FOLLOWING JOB RELATED SETTINGS:'
- ' SWA=BELOW,TIOT SIZE=32K,DSENQSHR=DISALLOW,GDGBIAS=JOB'
- ' IEFA107I FREE STEP1 JOBLIB - DATA SET NAZARE.WDEPLOY.BNPP.LOADBA
NOT FOUND'
- ' IEF272I FREE STEP1 - STEP WAS NOT EXECUTED.'
- ' IEF373I STEP/STEP1 /START 2023030.1029'
- ' IEF032I STEP/STEP1 /STOP 2023030.1029 '
- ' CPU: 0 HR 00 MIN 00.00 SEC SRB: 0 HR 00
MIN 00.00 SEC '
- ' VIRT: 0K SYS: 0K EXT: 0K SYS: 0K'
- ' ATB- REAL: 1044K SLOTS: 0K'
- ' VIRT- ALLOC: 11M SHRD: 0M'
- ' IEF375I JOB/FREE /START 2023030.1029'
- ' IEF033I JOB/FREE /STOP 2023030.1029 '
- ' CPU: 0 HR 00 MIN 00.00 SEC SRB: 0 HR 00
MIN 00.00 SEC '
ddname: JESYSMSG
id: '4'
procstep: ''
record_count: '14'
stepname: JES2
job_id: JOB09018
job_name: FREE
owner: VLODE
ret_code:
msg: JCL ERROR
msg_txt: ''
subsystem: IPO1
system: ''
md5sum: 6d827110c269da5d3219c9e044d310bf
mode: '0600'
msg: SubmitJCLError('')
owner: VLODE
size: 1075
src: /u/vlode/.ansible/tmp/ansible-tmp-1675092551.1458178-3994-235740038396439/source
state: file
uid: 10148

Playbook verbosity output

No response

Contents of `ansible.cfg`

#*******************************************************************************
# Licensed Materials - Property of IBM
# (c) Copyright IBM Corp. 2022. All Rights Reserved.
#
# Note to U.S. Government Users Restricted Rights:
# Use, duplication or disclosure restricted by GSA ADP Schedule
# Contract with IBM Corp.
#*******************************************************************************
[defaults]
forks = 25
host_key_checking = False
#callbacks_enabled = timer, profile_tasks, profile_roles
stdout_callback = ibm.ibm_zos_plum_deploy.cb_evidences

[ssh_connection]
pipelining = True
#ssh_args = -o ControlMaster=auto -o ControlPersist=3600s -o PreferredAuthentications=publickey

[callback_evidences]
evidences_folder = ../evidences

Contents of the inventory

all:
  hosts:
    cvb1:
      ansible_host: X.X.X.X
      ansible_user: MYUSER
      ansible_ssh_port: 222

Contents of `group_vars` or `host_vars`

environment_vars:
  _BPXK_AUTOCVT: "ON"
  ZOAU_HOME: "{{ ZOAU }}"
  #PYTHONPATH: "{{ ZOAU }}/lib"
  LIBPATH: "{{ ZOAU }}/lib:{{ PYZ }}/lib:/lib:/usr/lib:."
  PATH: "{{ ZOAU }}/bin:{{ PYZ }}/bin:/bin:/var/bin"
  _CEE_RUNOPTS: "FILETAG(AUTOCVT,AUTOTAG) POSIX(ON)"
  _TAG_REDIR_ERR: "txt"
  _TAG_REDIR_IN: "txt"
  _TAG_REDIR_OUT: "txt"
  LANG: "C"

Ansible version

ansible [core 2.11.12]
  config file = None
  configured module search path = ['/home/vlode/.ansible/plugins/modules', '/usr/share/ansible/plugins/modules']
  ansible python module location = /usr/local/lib/python3.8/dist-packages/ansible
  ansible collection location = /home/vlode/.ansible/collections:/usr/share/ansible/collections
  executable location = /usr/local/bin/ansible
  python version = 3.8.10 (default, Jun 22 2022, 20:18:18) [GCC 9.4.0]
  jinja version = 2.10.1
  libyaml = True

IBM z/OS Ansible core Version

v1.4.0

IBM ZOAU version

v1.1.1

z/OS version

2.4

Ansible module

zos_job_submit

The text was updated successfully, but these errors were encountered:

ddimatos · 2023-02-12T05:42:12Z

Hello @vlodeibm - starting to triage this so we can evaluate it, looks like your JCL error was a data set not found, can you confirm so that we know how to recreate if needed.

ddimatos · 2023-02-12T06:10:32Z

@IBMAnsibleHelper - looks like it was introduced in PR #251 when other features were added. It so happens 1.5.0-beta.1 coming out very soon includes a large rewrite of the zos_job_submit and I can see this case is handled but slightly different.

In 1.4.0-beta.1 this was introduced in the noted PR and happens because the check throws a submitError that has no content and nothing catches it further to throw a module.fail_json(...).
Diff:

In 1.5.0-beta.1 the code is capturing the JCL error yet the full job output does not appear it will be not be propagated by design and instead what is propagated are more specific messages as to why the job failed and also includes the job ID so that one can use zos_job_output to obtain the result in the event of a failure. I will need to validate 1.5 to be certain but I don't believe that returning the job output is the direction if the code can infer a reasonable reason for failure and provide the added information to allow further diagnoses.

Additionally, a more complete test case is needed, there are some but we should be more specific in what is captured for comparison.

We will be looking into this to decide how to handle a 1.4.x change.

ddimatos · 2023-02-12T06:24:27Z

If 1.5.0-beta.1 is confirmed to not return job ouput and by design provides more targeted messaging this should be an announcement in our discussions.

vlodeibm · 2023-02-13T07:49:48Z

hello @ddimatos I confirm that in this case, the JCL error is due to Data set indicated in joblib car doe not exist

ddimatos · 2023-02-13T21:25:12Z

Ok, thank you @vlodeibm - we will try to recreate this with JCL such that the DSN does not exist, for that matter it could probably be any JCL error that would exercise the issue no job_output came back.

ddimatos · 2023-03-23T05:38:45Z

@vlodeibm - I am trying this on 1.4 and not able to recreate it, i have similar NOT FOUND for JOBLIB entry in my output:
The correct DSN in my JCL is without the x thus ANSIBLE.COBOL.LOADLIBX should really be ANSIBLE.COBOL.LOADLIB but with the non-existent ANSIBLE.COBOL.LOADLIBX, not able to reproduce. I tried also with more a change to the DSN DSN=FOO.COBOL.LOADLIB and still no luck.

JCL:

//**********************************************************************
//* JOB LIBRARY
//**********************************************************************
//JBLIBPM  JOB MSGCLASS=H,MSGLEVEL=(1,1),NOTIFY=&SYSUID,REGION=0M
//JOBLIB DD DSN=ANSIBLE.COBOL.LOADLIBX,DISP=SHR
//**********************************************************************
//* THIS STEP EXECUTES THE PROGRAM HELLOPGM
//**********************************************************************
//STEP1    EXEC PGM=HELLOPGM
//SYSPRINT DD SYSOUT=*
//SYSOUT   DD SYSOUT=*
//

Output:

{
   "changed":false,
   "checksum":"cf4e0bf472498121d197e0ceb83003edabb01292",
   "dest":"/tmp/ansible.4hlqqbjd",
   "duration":8,
   "gid":1,
   "group":"OMVSGRP",
   "job_id":"JOB00340",
   "jobs":[
      {
         "class":"A",
         "content_type":"JOB",
         "ddnames":[
            {
               "byte_count":"669",
               "content":[
                  "1                       J E S 2  J O B  L O G  --  S Y S T E M  S T L 1  --  N O D E  S T L 1            ",
                  "0 ",
                  " 22.33.47 JOB00340 ---- WEDNESDAY, 22 MAR 2023 ----",
                  " 22.33.47 JOB00340  IRR010I  USERID OMVSADM  IS ASSIGNED TO THIS JOB.",
                  " 22.33.47 JOB00340  ICH70001I OMVSADM  LAST ACCESS AT 22:33:41 ON WEDNESDAY, MARCH 22, 2023",
                  " 22.33.47 JOB00340  $HASP373 JBLIBPM  STARTED - INIT 8    - CLASS A        - SYS STL1",
                  " 22.33.47 JOB00340  SMF000I  JBLIBPM     STEP1       HELLOPGM    NOT EXECUTED",
                  " 22.33.47 JOB00340  IEF453I JBLIBPM - JOB FAILED - JCL ERROR",
                  " 22.33.47 JOB00340  $HASP395 JBLIBPM  ENDED",
                  "0------ JES2 JOB STATISTICS ------",
                  "-  22 MAR 2023 JOB EXECUTION DATE",
                  "-            9 CARDS READ",
                  "-           42 SYSOUT PRINT RECORDS",
                  "-            0 SYSOUT PUNCH RECORDS",
                  "-            5 SYSOUT SPOOL KBYTES",
                  "-         0.00 MINUTES EXECUTION TIME",
                  "         1 //JBLIBPM  JOB MSGCLASS=H,MSGLEVEL=(1,1),NOTIFY=&SYSUID,REGION=0M       JOB00340",
                  "           IEFC653I SUBSTITUTION JCL - MSGCLASS=H,MSGLEVEL=(1,1),NOTIFY=OMVSADM,REGION=0M",
                  "         2 //JOBLIB DD DSN=ANSIBLE.COBOL.LOADLIBX,DISP=SHR                                 ",
                  "           //**********************************************************************        ",
                  "           //* THIS STEP EXECUTES THE PROGRAM HELLOPGM                                     ",
                  "           //**********************************************************************        ",
                  "         3 //STEP1    EXEC PGM=HELLOPGM                                                    ",
                  "         4 //SYSPRINT DD SYSOUT=*                                                          ",
                  "         5 //SYSOUT   DD SYSOUT=*                                                          ",
                  "         6 //                                                                              ",
                  " ICH70001I OMVSADM  LAST ACCESS AT 22:33:41 ON WEDNESDAY, MARCH 22, 2023",
                  " IEFA107I JBLIBPM STEP1 JOBLIB - DATA SET ANSIBLE.COBOL.LOADLIBX NOT FOUND",
                  " IEF272I JBLIBPM STEP1 - STEP WAS NOT EXECUTED.",
                  " IEF373I STEP/STEP1   /START 2023081.2233",
                  " IEF032I STEP/STEP1   /STOP  2023081.2233 ",
                  "         CPU:     0 HR  00 MIN  00.00 SEC    SRB:     0 HR  00 MIN  00.00 SEC    ",
                  "         VIRT:     0K  SYS:     0K  EXT:        0K  SYS:        0K",
                  "         ATB- REAL:                  1036K  SLOTS:                     0K",
                  "              VIRT- ALLOC:      11M SHRD:       0M",
                  " IEF375I  JOB/JBLIBPM /START 2023081.2233",
                  " IEF033I  JOB/JBLIBPM /STOP  2023081.2233 ",
                  "         CPU:     0 HR  00 MIN  00.00 SEC    SRB:     0 HR  00 MIN  00.00 SEC    "
               ],
               "ddname":"JESMSGLG",
               "id":"2",
               "procstep":"",
               "record_count":"16",
               "stepname":"JES2"
            },
            {
               "byte_count":"613",
               "content":[
                  "1                       J E S 2  J O B  L O G  --  S Y S T E M  S T L 1  --  N O D E  S T L 1            ",
                  "0 ",
                  " 22.33.47 JOB00340 ---- WEDNESDAY, 22 MAR 2023 ----",
                  " 22.33.47 JOB00340  IRR010I  USERID OMVSADM  IS ASSIGNED TO THIS JOB.",
                  " 22.33.47 JOB00340  ICH70001I OMVSADM  LAST ACCESS AT 22:33:41 ON WEDNESDAY, MARCH 22, 2023",
                  " 22.33.47 JOB00340  $HASP373 JBLIBPM  STARTED - INIT 8    - CLASS A        - SYS STL1",
                  " 22.33.47 JOB00340  SMF000I  JBLIBPM     STEP1       HELLOPGM    NOT EXECUTED",
                  " 22.33.47 JOB00340  IEF453I JBLIBPM - JOB FAILED - JCL ERROR",
                  " 22.33.47 JOB00340  $HASP395 JBLIBPM  ENDED",
                  "0------ JES2 JOB STATISTICS ------",
                  "-  22 MAR 2023 JOB EXECUTION DATE",
                  "-            9 CARDS READ",
                  "-           42 SYSOUT PRINT RECORDS",
                  "-            0 SYSOUT PUNCH RECORDS",
                  "-            5 SYSOUT SPOOL KBYTES",
                  "-         0.00 MINUTES EXECUTION TIME",
                  "         1 //JBLIBPM  JOB MSGCLASS=H,MSGLEVEL=(1,1),NOTIFY=&SYSUID,REGION=0M       JOB00340",
                  "           IEFC653I SUBSTITUTION JCL - MSGCLASS=H,MSGLEVEL=(1,1),NOTIFY=OMVSADM,REGION=0M",
                  "         2 //JOBLIB DD DSN=ANSIBLE.COBOL.LOADLIBX,DISP=SHR                                 ",
                  "           //**********************************************************************        ",
                  "           //* THIS STEP EXECUTES THE PROGRAM HELLOPGM                                     ",
                  "           //**********************************************************************        ",
                  "         3 //STEP1    EXEC PGM=HELLOPGM                                                    ",
                  "         4 //SYSPRINT DD SYSOUT=*                                                          ",
                  "         5 //SYSOUT   DD SYSOUT=*                                                          ",
                  "         6 //                                                                              ",
                  " ICH70001I OMVSADM  LAST ACCESS AT 22:33:41 ON WEDNESDAY, MARCH 22, 2023",
                  " IEFA107I JBLIBPM STEP1 JOBLIB - DATA SET ANSIBLE.COBOL.LOADLIBX NOT FOUND",
                  " IEF272I JBLIBPM STEP1 - STEP WAS NOT EXECUTED.",
                  " IEF373I STEP/STEP1   /START 2023081.2233",
                  " IEF032I STEP/STEP1   /STOP  2023081.2233 ",
                  "         CPU:     0 HR  00 MIN  00.00 SEC    SRB:     0 HR  00 MIN  00.00 SEC    ",
                  "         VIRT:     0K  SYS:     0K  EXT:        0K  SYS:        0K",
                  "         ATB- REAL:                  1036K  SLOTS:                     0K",
                  "              VIRT- ALLOC:      11M SHRD:       0M",
                  " IEF375I  JOB/JBLIBPM /START 2023081.2233",
                  " IEF033I  JOB/JBLIBPM /STOP  2023081.2233 ",
                  "         CPU:     0 HR  00 MIN  00.00 SEC    SRB:     0 HR  00 MIN  00.00 SEC    "
               ],
               "ddname":"JESJCL",
               "id":"3",
               "procstep":"",
               "record_count":"10",
               "stepname":"JES2"
            },
            {
               "byte_count":"753",
               "content":[
                  "1                       J E S 2  J O B  L O G  --  S Y S T E M  S T L 1  --  N O D E  S T L 1            ",
                  "0 ",
                  " 22.33.47 JOB00340 ---- WEDNESDAY, 22 MAR 2023 ----",
                  " 22.33.47 JOB00340  IRR010I  USERID OMVSADM  IS ASSIGNED TO THIS JOB.",
                  " 22.33.47 JOB00340  ICH70001I OMVSADM  LAST ACCESS AT 22:33:41 ON WEDNESDAY, MARCH 22, 2023",
                  " 22.33.47 JOB00340  $HASP373 JBLIBPM  STARTED - INIT 8    - CLASS A        - SYS STL1",
                  " 22.33.47 JOB00340  SMF000I  JBLIBPM     STEP1       HELLOPGM    NOT EXECUTED",
                  " 22.33.47 JOB00340  IEF453I JBLIBPM - JOB FAILED - JCL ERROR",
                  " 22.33.47 JOB00340  $HASP395 JBLIBPM  ENDED",
                  "0------ JES2 JOB STATISTICS ------",
                  "-  22 MAR 2023 JOB EXECUTION DATE",
                  "-            9 CARDS READ",
                  "-           42 SYSOUT PRINT RECORDS",
                  "-            0 SYSOUT PUNCH RECORDS",
                  "-            5 SYSOUT SPOOL KBYTES",
                  "-         0.00 MINUTES EXECUTION TIME",
                  "         1 //JBLIBPM  JOB MSGCLASS=H,MSGLEVEL=(1,1),NOTIFY=&SYSUID,REGION=0M       JOB00340",
                  "           IEFC653I SUBSTITUTION JCL - MSGCLASS=H,MSGLEVEL=(1,1),NOTIFY=OMVSADM,REGION=0M",
                  "         2 //JOBLIB DD DSN=ANSIBLE.COBOL.LOADLIBX,DISP=SHR                                 ",
                  "           //**********************************************************************        ",
                  "           //* THIS STEP EXECUTES THE PROGRAM HELLOPGM                                     ",
                  "           //**********************************************************************        ",
                  "         3 //STEP1    EXEC PGM=HELLOPGM                                                    ",
                  "         4 //SYSPRINT DD SYSOUT=*                                                          ",
                  "         5 //SYSOUT   DD SYSOUT=*                                                          ",
                  "         6 //                                                                              ",
                  " ICH70001I OMVSADM  LAST ACCESS AT 22:33:41 ON WEDNESDAY, MARCH 22, 2023",
                  " IEFA107I JBLIBPM STEP1 JOBLIB - DATA SET ANSIBLE.COBOL.LOADLIBX NOT FOUND",
                  " IEF272I JBLIBPM STEP1 - STEP WAS NOT EXECUTED.",
                  " IEF373I STEP/STEP1   /START 2023081.2233",
                  " IEF032I STEP/STEP1   /STOP  2023081.2233 ",
                  "         CPU:     0 HR  00 MIN  00.00 SEC    SRB:     0 HR  00 MIN  00.00 SEC    ",
                  "         VIRT:     0K  SYS:     0K  EXT:        0K  SYS:        0K",
                  "         ATB- REAL:                  1036K  SLOTS:                     0K",
                  "              VIRT- ALLOC:      11M SHRD:       0M",
                  " IEF375I  JOB/JBLIBPM /START 2023081.2233",
                  " IEF033I  JOB/JBLIBPM /STOP  2023081.2233 ",
                  "         CPU:     0 HR  00 MIN  00.00 SEC    SRB:     0 HR  00 MIN  00.00 SEC    "
               ],
               "ddname":"JESYSMSG",
               "id":"4",
               "procstep":"",
               "record_count":"12",
               "stepname":"JES2"
            }
         ],
         "job_id":"JOB00340",
         "job_name":"JBLIBPM",
         "owner":"OMVSADM",
         "ret_code":{
            "code":null,
            "msg":"JCL ERROR",
            "msg_code":null,
            "msg_txt":"JCL Error detected.  Check the data dumps for more information.",
            "steps":[
               
            ]
         },
         "subsystem":"STL1",
         "system":""
      }
   ],
   "md5sum":"0b96c8e922b6cfa0d515cce8cada28f3",
   "message":{
      "stderr":"Submit succeeded, but job failed: JCL ERROR"
   },
   "mode":"0600",
   "msg":{
      "stderr":"Submit succeeded, but job failed: JCL ERROR"
   },
   "owner":"OBAGAOI",
   "size":858,
   "src":"/.ansible/tmp/ansible-tmp-1679549609.7433379-62207-214998751114165/source",
   "state":"file",
   "uid":0
}

ddimatos · 2023-03-23T05:44:17Z

In 1.5.0-beta.1 same test I get:

{
   "changed":false,
   "checksum":"e2df30bfcaa121abb90c4bb91de262b6eda92da0",
   "dest":"/tmp/ansible.x1poa5cj",
   "duration":0,
   "gid":1,
   "group":"OMVSGRP",
   "md5sum":"4dec5abc5d759253382d83c36483077f",
   "mode":"0600",
   "msg":"The JCL submitted with job id JOB00342 but there was an error, please review the error for further details: The job completion code (CC) was not in the job log. Please review the error JCLERR ? and the job log..",
   "owner":"OBAGAOI",
   "size":853,
   "src":"/.ansible/tmp/ansible-tmp-1679550158.055122-63098-260508131862296/source",
   "state":"file",
   "stderr":"The job completion code (CC) was not in the job log. Please review the error JCLERR ? and the job log.",
   "stderr_lines":[
      "The job completion code (CC) was not in the job log. Please review the error JCLERR ? and the job log."
   ],
   "uid":0
}

ddimatos · 2023-03-23T05:53:09Z

In what will be 1.5.0 GA in a few weeks (not available in galaxy/hub yet) the same test returns the job log a bit more information.

Msg in response:

   "msg":"The JCL submitted with job id JOB00344 but there was an error, please review 
   the error for further details: The job completion code (CC) was not in the job log. Please 
   review the error JCLERR ? and the job log.",

Response:

{
   "changed":false,
   "checksum":"e2df30bfcaa121abb90c4bb91de262b6eda92da0",
   "dest":"/tmp/ansible.5n612hv1",
   "duration":0,
   "gid":1,
   "group":"OMVSGRP",
   "jobs":[
      {
         "class":"A",
         "content_type":"",
         "ddnames":[
            {
               "byte_count":"133",
               "content":[
                  "1                       J E S 2  J O B  L O G  --  S Y S T E M  S T L 1  --  N O D E  S T L 1",
                  "0     ",
                  " 22.50.09 JOB00344 ---- WEDNESDAY, 22 MAR 2023 ----",
                  " 22.50.09 JOB00344  IRR010I  USERID OMVSADM  IS ASSIGNED TO THIS JOB.",
                  " 22.50.09 JOB00344  ICH70001I OMVSADM  LAST ACCESS AT 22:50:07 ON WEDNESDAY, MARCH 22, 2023",
                  " 22.50.09 JOB00344  $HASP373 JBLIBPM  STARTED - INIT 8    - CLASS A        - SYS STL1",
                  " 22.50.09 JOB00344  SMF000I  JBLIBPM     STEP1       HELLOPGM    NOT EXECUTED",
                  " 22.50.09 JOB00344  IEF453I JBLIBPM - JOB FAILED - JCL ERROR",
                  " 22.50.09 JOB00344  $HASP395 JBLIBPM  ENDED",
                  "0------ JES2 JOB STATISTICS ------",
                  "-  22 MAR 2023 JOB EXECUTION DATE",
                  "-            9 CARDS READ",
                  "-           42 SYSOUT PRINT RECORDS",
                  "-            0 SYSOUT PUNCH RECORDS",
                  "-            5 SYSOUT SPOOL KBYTES",
                  "-         0.00 MINUTES EXECUTION TIME"
               ],
               "ddname":"JESMSGLG",
               "id":"2",
               "proctep":null,
               "record_count":"16",
               "stepname":"JES2"
            },
            {
               "byte_count":"136",
               "content":[
                  "        1 //JBLIBPM  JOB MSGCLASS=H,MSGLEVEL=(1,1),NOTIFY=&SYSUID,REGION=0M       JOB00344",
                  "          IEFC653I SUBSTITUTION JCL - MSGCLASS=H,MSGLEVEL=(1,1),NOTIFY=OMVSADM,REGION=0M",
                  "        2 //JOBLIB DD DSN=FOO.COBOL.LOADLIB,DISP=SHR",
                  "          //**********************************************************************",
                  "          //* THIS STEP EXECUTES THE PROGRAM HELLOPGM",
                  "          //**********************************************************************",
                  "        3 //STEP1    EXEC PGM=HELLOPGM",
                  "        4 //SYSPRINT DD SYSOUT=*",
                  "        5 //SYSOUT   DD SYSOUT=*",
                  "        6 //"
               ],
               "ddname":"JESJCL",
               "id":"3",
               "proctep":null,
               "record_count":"10",
               "stepname":"JES2"
            },
            {
               "byte_count":"137",
               "content":[
                  " ICH70001I OMVSADM  LAST ACCESS AT 22:50:07 ON WEDNESDAY, MARCH 22, 2023",
                  " IEFA107I JBLIBPM STEP1 JOBLIB - DATA SET FOO.COBOL.LOADLIB NOT FOUND",
                  " IEF272I JBLIBPM STEP1 - STEP WAS NOT EXECUTED.",
                  " IEF373I STEP/STEP1   /START 2023081.2250",
                  " IEF032I STEP/STEP1   /STOP  2023081.2250",
                  "         CPU:     0 HR  00 MIN  00.00 SEC    SRB:     0 HR  00 MIN  00.00 SEC",
                  "         VIRT:     0K  SYS:     0K  EXT:        0K  SYS:        0K",
                  "         ATB- REAL:                  1036K  SLOTS:                     0K",
                  "              VIRT- ALLOC:      11M SHRD:       0M",
                  " IEF375I  JOB/JBLIBPM /START 2023081.2250",
                  " IEF033I  JOB/JBLIBPM /STOP  2023081.2250",
                  "         CPU:     0 HR  00 MIN  00.00 SEC    SRB:     0 HR  00 MIN  00.00 SEC"
               ],
               "ddname":"JESYSMSG",
               "id":"4",
               "proctep":null,
               "record_count":"12",
               "stepname":"JES2"
            }
         ],
         "duration":0,
         "job_id":"JOB00344",
         "job_name":"JBLIBPM",
         "owner":"OMVSADM",
         "ret_code":{
            "code":"",
            "msg":"JCLERR ?",
            "msg_code":"?",
            "msg_text":"JCLERR",
            "steps":[
               
            ]
         },
         "subsystem":"STL1",
         "system":"STL1"
      }
   ],
   "md5sum":"4dec5abc5d759253382d83c36483077f",
   "mode":"0600",
   "msg":"The JCL submitted with job id JOB00344 but there was an error, please review the error for further details: The job completion code (CC) was not in the job log. Please review the error JCLERR ? and the job log.",
   "owner":"OBAGAOI",
   "size":853,
   "src":"/.ansible/tmp/ansible-tmp-1679550602.285323-63606-124985460118594/source",
   "state":"file",
   "stderr":"The job completion code (CC) was not in the job log. Please review the error JCLERR ? and the job log.",
   "stderr_lines":[
      "The job completion code (CC) was not in the job log. Please review the error JCLERR ? and the job log."
   ],
   "uid":0
}
PLAY RECAP **********************************
zvm                        : ok=0    changed=0    unreachable=0    failed=1    skipped=0    rescued=0    ignored=0

ddimatos · 2023-03-23T05:59:13Z

Was not able to reproduce in 1.4.0 or 1.5.0-beta.1.
Given changes made for 1.5.0 GA issues #655 #670 #681 the overlap of changes to the zos_job_submit module improved the response as well.

There is no more work being done for 1.4.0 past the next 1.4.1 which is already code frozen, thus thus this can be considered fixed in 1.5.0.

vlodeibm added the Bug Something isn't working as designed. label Jan 30, 2023

vlodeibm assigned IBMAnsibleHelper Jan 30, 2023

vlodeibm changed the title ~~[Bug] zos_jobs_submit failed without any explanation when having a JCL Errir~~ [Bug] zos_jobs_submit failed without any explanation when having a JCL Error Jan 30, 2023

ddimatos added the Needs Triage Issue need assessment by a team member(s) label Jan 31, 2023

ddimatos added Stretch and removed Needs Triage Issue need assessment by a team member(s) labels Feb 12, 2023

ddimatos added this to IBM Ansible z/OS Core Collection Feb 12, 2023

ddimatos moved this to ⚙ Backlog in IBM Ansible z/OS Core Collection Feb 12, 2023

ddimatos removed the Stretch label Mar 22, 2023

ddimatos moved this from ⚙ Backlog to 🔍 Validation in IBM Ansible z/OS Core Collection Mar 23, 2023

ddimatos assigned ddimatos and unassigned IBMAnsibleHelper Mar 23, 2023

ddimatos added the In Progress This issue is under review by a team member. label Mar 23, 2023

This was referenced Mar 23, 2023

Bug fix to correct job log returining and other edge cases #683

Merged

Bug fix to correct job log returining and other edge cases #687

Closed

Bug fix to correct job log returining and other edge cases #688

Merged

ddimatos added this to the [Q1] [2023] Bugs milestone Mar 25, 2023

ddimatos moved this from 🔍 Validation to ✅ Done in IBM Ansible z/OS Core Collection Mar 26, 2023

ddimatos closed this as completed Mar 26, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[Bug] zos_jobs_submit failed without any explanation when having a JCL Error #624

[Bug] zos_jobs_submit failed without any explanation when having a JCL Error #624

vlodeibm commented Jan 30, 2023

ddimatos commented Feb 12, 2023

ddimatos commented Feb 12, 2023 •

edited

Loading

ddimatos commented Feb 12, 2023

vlodeibm commented Feb 13, 2023

ddimatos commented Feb 13, 2023

ddimatos commented Mar 23, 2023 •

edited

Loading

ddimatos commented Mar 23, 2023

ddimatos commented Mar 23, 2023

ddimatos commented Mar 23, 2023 •

edited

Loading

[Bug] zos_jobs_submit failed without any explanation when having a JCL Error #624

[Bug] zos_jobs_submit failed without any explanation when having a JCL Error #624

Comments

vlodeibm commented Jan 30, 2023

Bug description

Playbook verbosity output

Contents of ansible.cfg

Contents of the inventory

Contents of group_vars or host_vars

Ansible version

IBM z/OS Ansible core Version

IBM ZOAU version

z/OS version

Ansible module

ddimatos commented Feb 12, 2023

ddimatos commented Feb 12, 2023 • edited Loading

ddimatos commented Feb 12, 2023

vlodeibm commented Feb 13, 2023

ddimatos commented Feb 13, 2023

ddimatos commented Mar 23, 2023 • edited Loading

ddimatos commented Mar 23, 2023

ddimatos commented Mar 23, 2023

ddimatos commented Mar 23, 2023 • edited Loading

Contents of `ansible.cfg`

Contents of `group_vars` or `host_vars`

ddimatos commented Feb 12, 2023 •

edited

Loading

ddimatos commented Mar 23, 2023 •

edited

Loading

ddimatos commented Mar 23, 2023 •

edited

Loading