ansible-collections / ibm_zos_core

Red Hat Ansible Certified Content for IBM Z
77 stars 44 forks source link

[Documentation] Unable to use zos_job_submit and NOT wait for job completion #1192

Closed Michael-Baylis closed 7 months ago

Michael-Baylis commented 9 months ago

Is there an existing issue for this?

Are the dependencies a supported version?

IBM Z Open Automation Utilities

v1.2.5

IBM Enterprise Python

v3.9.x

IBM z/OS Ansible core Version

v1.8.0-beta.1

ansible-version

v2.12.x

z/OS version

v2.5

Ansible module

zos_job_submit

Bug description

The zos_job_submit documentaion states "Submit a job and optionally monitor for completion", but there is no option to specify this now "wait:" is ignored. With "wait_time_s" defaulting to 10 seconds, the task will always wait.

  - name: Submit SYSRES job
    ibm.ibm_zos_core.zos_job_submit:
      src: IBMUSER.TEMP.PTF(SYSRES)
      location: DATA_SET

providing depreciated wait: does not affect it. and obv can't use wait_time_s: 0

  - name: Submit SYSRES job
    ibm.ibm_zos_core.zos_job_submit:
      src: IBMUSER.TEMP.PTF(SYSRES)
      location: DATA_SET
     wait:false

Playbook verbosity output.

fatal: [hsnmike]: FAILED! => {"changed": false, "duration": 10, "jobs": [{"asid": "46", "class": "A", "content_type": "", "creation_date": "2024-01-29", "creation_time": "5:42:19", "ddnames": [{"byte_count": "133", "content": xxxx], "duration": 10, "job_class": "A", "job_id": "JOB03906", "job_name": "SYSRES", "owner": "IBMUSER", "priority": "9", "program_name": "?", "queue_position": "0", "ret_code": {"code": null, "msg": "AC ?", "msg_code": "?", "msg_text": "AC", "steps": []}, "subsystem": "TVT5002", "svc_class": "BATNORML", "system": "IPO1"}], "msg": "The JCL submitted with job id JOB03906 but appears to be a long running job that exceeded its maximum wait time of 10 second(s). Consider using module zos_job_query to poll for a long running job or increase option 'wait_times_s` to a value greater than 10."}

Ansible configuration.

No response

Contents of the inventory

No response

Contents of group_vars or host_vars

No response

Michael-Baylis commented 9 months ago

Currently have to surround the actual job with a gener copying to SYSOUT=(A,INTRDR)

ddimatos commented 9 months ago

Hello @Michael-Baylis , Thank you for opening an bug issue, allow me to backtrack a bit and lead in with my questions.

The original wait doc is below for reference, as we plan to remove the deprecated option in the near future:

  wait:
    required: false
    default: false
    type: bool
    description:
      - Wait for the Job to finish and capture the output. Default is false.
      - When I(wait) is false or absent, the module will wait up to 10 seconds for the job to start,
        but will not wait for the job to complete.
      - If I(wait) is true, User can specify the wait time, see option ``wait_time_s``.

The original implementation of wait was unnecessary because it was used to tell the source that the module will be waiting and to expect that wait_time_s will be provided; I found it unnecessary to have a boolean instruct the source to prepare for wait_time_s, thus we defaulted wait_time_s to 10 seconds, with a range of >=0 but less than 86400 seconds (24 hours). The upper bound of 24 we felt would suffice and replicate what a wait would have done.

Regarding "Submit a job and optionally monitor for completion" , this probably should updated, I think what that meant is you can submit a job and specify how long you want to monitor it for completion, lets say you have a long running job at 60 seconds and you only wait 10 seconds, after 10 seconds the module will fail with appropriate with a message, job ID and stating that the jobs elapsed time has exceeded wait_time_s and either to add more time or monitor the jobs status using zos_job_query.

As for value 0 for wait_time_s, I was reserving that for a future change where when the time is 0, we won't wait, we will submit the JCL and return , a Fire and Forget model, described here.

It sounds like "Unable to use zos_job_submit and NOT wait for job completion" corresponds to issue #715 where you would be able to submit a job and NOT wait; is this the enhancement you are desiring?

As for the "Submit a job and optionally monitor for completion", this is a documentation bug, I would not consider this missing capability.

Michael-Baylis commented 9 months ago

Except, wait: false is not being honoured. It still waits for the job for 10 seconds.

Michael-Baylis commented 9 months ago
  tasks:
  - name: Submit Receive job 
    ibm.ibm_zos_core.zos_job_submit:
      src: IBMUSER.TEMP.PTF(RECEIVE)
      location: DATA_SET
      wait: false
Michael-Baylis commented 9 months ago
TASK [Submit Receive job] *********************************************************************************************************************************************************************
task path: /git/k8s4z-build/test.yml:19
<hursvl01.hursley.ibm.com> ESTABLISH SSH CONNECTION FOR USER: ibmuser
<hursvl01.hursley.ibm.com> SSH: EXEC sshpass -d10 ssh -vvv -C -o ControlMaster=auto -o ControlPersist=60s -o Port=20122 -o 'User="ibmuser"' -o ConnectTimeout=10 -o 'ControlPath="/root/.ansible/cp/36e3ec8490"' hursvl01.hursley.ibm.com '/bin/sh -c '"'"'echo ~ibmuser && sleep 0'"'"''
<hursvl01.hursley.ibm.com> (0, b'/u/ibmuser\n', b'OpenSSH_8.2p1 Ubuntu-4ubuntu0.11, OpenSSL 1.1.1f  31 Mar 2020\r\ndebug1: Reading configuration data /root/.ssh/config\r\ndebug1: /root/.ssh/config line 4: Applying options for *\r\ndebug3: kex names ok: [diffie-hellman-group1-sha1]\r\ndebug1: /root/.ssh/config line 18: Applying options for hursvl01.hursley.ibm.com\r\ndebug1: Reading configuration data /etc/ssh/ssh_config\r\ndebug1: /etc/ssh/ssh_config line 19: include /etc/ssh/ssh_config.d/*.conf matched no files\r\ndebug1: /etc/ssh/ssh_config line 21: Applying options for *\r\ndebug1: auto-mux: Trying existing master\r\ndebug1: Control socket "/root/.ansible/cp/36e3ec8490" does not exist\r\ndebug2: resolving "hursvl01.hursley.ibm.com" port 20122\r\ndebug2: ssh_connect_direct\r\ndebug1: Connecting to hursvl01.hursley.ibm.com [9.20.6.250] port 20122.\r\ndebug2: fd 3 setting O_NONBLOCK\r\ndebug1: fd 3 clearing O_NONBLOCK\r\ndebug1: Connection established.\r\ndebug3: timeout: 9964 ms remain after connect\r\ndebug1: identity file /root/.ssh/id_rsa type -1\r\ndebug1: identity file /root/.ssh/id_rsa-cert type -1\r\ndebug1: identity file /root/.ssh/id_dsa type -1\r\ndebug1: identity file /root/.ssh/id_dsa-cert type -1\r\ndebug1: identity file /root/.ssh/id_ecdsa type -1\r\ndebug1: identity file /root/.ssh/id_ecdsa-cert type -1\r\ndebug1: identity file /root/.ssh/id_ecdsa_sk type -1\r\ndebug1: identity file /root/.ssh/id_ecdsa_sk-cert type -1\r\ndebug1: identity file /root/.ssh/id_ed25519 type -1\r\ndebug1: identity file /root/.ssh/id_ed25519-cert type -1\r\ndebug1: identity file /root/.ssh/id_ed25519_sk type -1\r\ndebug1: identity file /root/.ssh/id_ed25519_sk-cert type -1\r\ndebug1: identity file /root/.ssh/id_xmss type -1\r\ndebug1: identity file /root/.ssh/id_xmss-cert type -1\r\ndebug1: Local version string SSH-2.0-OpenSSH_8.2p1 Ubuntu-4ubuntu0.11\r\ndebug1: Remote protocol version 2.0, remote software version OpenSSH_7.6\r\ndebug1: match: OpenSSH_7.6 pat OpenSSH_7.0*,OpenSSH_7.1*,OpenSSH_7.2*,OpenSSH_7.3*,OpenSSH_7.4*,OpenSSH_7.5*,OpenSSH_7.6*,OpenSSH_7.7* compat 0x04000002\r\ndebug2: fd 3 setting O_NONBLOCK\r\ndebug1: Authenticating to hursvl01.hursley.ibm.com:20122 as \'ibmuser\'\r\ndebug3: put_host_port: [hursvl01.hursley.ibm.com]:20122\r\ndebug3: hostkeys_foreach: reading file "/root/.ssh/known_hosts"\r\ndebug3: record_hostkey: found key type RSA in file /root/.ssh/known_hosts:225\r\ndebug3: load_hostkeys: loaded 1 keys from [hursvl01.hursley.ibm.com]:20122\r\ndebug3: order_hostkeyalgs: prefer hostkeyalgs: rsa-sha2-512-cert-v01@openssh.com,rsa-sha2-256-cert-v01@openssh.com,ssh-rsa-cert-v01@openssh.com,rsa-sha2-512,rsa-sha2-256,ssh-rsa\r\ndebug3: send packet: type 20\r\ndebug1: SSH2_MSG_KEXINIT sent\r\ndebug3: receive packet: type 20\r\ndebug1: SSH2_MSG_KEXINIT received\r\ndebug2: local client KEXINIT proposal\r\ndebug2: KEX algorithms: curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,diffie-hellman-group14-sha256,ext-info-c,kex-strict-c-v00@openssh.com\r\ndebug2: host key algorithms: rsa-sha2-512-cert-v01@openssh.com,rsa-sha2-256-cert-v01@openssh.com,ssh-rsa-cert-v01@openssh.com,rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256-cert-v01@openssh.com,ecdsa-sha2-nistp384-cert-v01@openssh.com,ecdsa-sha2-nistp521-cert-v01@openssh.com,sk-ecdsa-sha2-nistp256-cert-v01@openssh.com,ssh-ed25519-cert-v01@openssh.com,sk-ssh-ed25519-cert-v01@openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,sk-ecdsa-sha2-nistp256@openssh.com,ssh-ed25519,sk-ssh-ed25519@openssh.com\r\ndebug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com\r\ndebug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com\r\ndebug2: MACs ctos: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1\r\ndebug2: MACs stoc: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1\r\ndebug2: compression ctos: zlib@openssh.com,zlib,none\r\ndebug2: compression stoc: zlib@openssh.com,zlib,none\r\ndebug2: languages ctos: \r\ndebug2: languages stoc: \r\ndebug2: first_kex_follows 0 \r\ndebug2: reserved 0 \r\ndebug2: peer server KEXINIT proposal\r\ndebug2: KEX algorithms: curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,diffie-hellman-group14-sha256,diffie-hellman-group14-sha1\r\ndebug2: host key algorithms: ssh-rsa,rsa-sha2-512,rsa-sha2-256\r\ndebug2: ciphers ctos: aes128-ctr,aes192-ctr,aes256-ctr\r\ndebug2: ciphers stoc: aes128-ctr,aes192-ctr,aes256-ctr\r\ndebug2: MACs ctos: hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1\r\ndebug2: MACs stoc: hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1\r\ndebug2: compression ctos: none,zlib@openssh.com\r\ndebug2: compression stoc: none,zlib@openssh.com\r\ndebug2: languages ctos: \r\ndebug2: languages stoc: \r\ndebug2: first_kex_follows 0 \r\ndebug2: reserved 0 \r\ndebug1: kex: algorithm: curve25519-sha256\r\ndebug1: kex: host key algorithm: rsa-sha2-512\r\ndebug1: kex: server->client cipher: aes128-ctr MAC: hmac-sha2-256-etm@openssh.com compression: zlib@openssh.com\r\ndebug1: kex: client->server cipher: aes128-ctr MAC: hmac-sha2-256-etm@openssh.com compression: zlib@openssh.com\r\ndebug3: send packet: type 30\r\ndebug1: expecting SSH2_MSG_KEX_ECDH_REPLY\r\ndebug3: receive packet: type 31\r\ndebug1: Server host key: ssh-rsa SHA256:4Ov6KHwRR4URnKKZauyaOZuaQvKLt/we8NvYJphMTFw\r\ndebug3: put_host_port: [9.20.6.250]:20122\r\ndebug3: put_host_port: [hursvl01.hursley.ibm.com]:20122\r\ndebug3: hostkeys_foreach: reading file "/root/.ssh/known_hosts"\r\ndebug3: record_hostkey: found key type RSA in file /root/.ssh/known_hosts:225\r\ndebug3: load_hostkeys: loaded 1 keys from [hursvl01.hursley.ibm.com]:20122\r\ndebug3: hostkeys_foreach: reading file "/root/.ssh/known_hosts"\r\ndebug3: record_hostkey: found key type RSA in file /root/.ssh/known_hosts:225\r\ndebug3: load_hostkeys: loaded 1 keys from [9.20.6.250]:20122\r\ndebug1: Host \'[hursvl01.hursley.ibm.com]:20122\' is known and matches the RSA host key.\r\ndebug1: Found key in /root/.ssh/known_hosts:225\r\ndebug3: send packet: type 21\r\ndebug2: set_newkeys: mode 1\r\ndebug1: rekey out after 4294967296 blocks\r\ndebug1: SSH2_MSG_NEWKEYS sent\r\ndebug1: expecting SSH2_MSG_NEWKEYS\r\ndebug3: receive packet: type 21\r\ndebug1: SSH2_MSG_NEWKEYS received\r\ndebug2: set_newkeys: mode 0\r\ndebug1: rekey in after 4294967296 blocks\r\ndebug1: Will attempt key: Ishanagi - GitHub - SSH Key RSA SHA256:rKmPMuBNwfWCPziQR4g6aj8K1gHOf1Kb4oYPDTpP2A0 agent\r\ndebug1: Will attempt key: Main SSH Key RSA SHA256:XKQlBN2e5G9+lsgwkQRxQrULFr1bU3KNB8Vlh2fC/g4 agent\r\ndebug1: Will attempt key: /root/.ssh/id_rsa \r\ndebug1: Will attempt key: /root/.ssh/id_dsa \r\ndebug1: Will attempt key: /root/.ssh/id_ecdsa \r\ndebug1: Will attempt key: /root/.ssh/id_ecdsa_sk \r\ndebug1: Will attempt key: /root/.ssh/id_ed25519 \r\ndebug1: Will attempt key: /root/.ssh/id_ed25519_sk \r\ndebug1: Will attempt key: /root/.ssh/id_xmss \r\ndebug2: pubkey_prepare: done\r\ndebug3: send packet: type 5\r\ndebug3: receive packet: type 7\r\ndebug1: SSH2_MSG_EXT_INFO received\r\ndebug1: kex_input_ext_info: server-sig-algs=<ssh-ed25519,ssh-rsa,rsa-sha2-256,rsa-sha2-512,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521>\r\ndebug3: receive packet: type 6\r\ndebug2: service_accept: ssh-userauth\r\ndebug1: SSH2_MSG_SERVICE_ACCEPT received\r\ndebug3: send packet: type 50\r\ndebug3: receive packet: type 51\r\ndebug1: Authentications that can continue: publickey,password\r\ndebug3: start over, passed a different list publickey,password\r\ndebug3: preferred gssapi-with-mic,publickey,keyboard-interactive,password\r\ndebug3: authmethod_lookup publickey\r\ndebug3: remaining preferred: keyboard-interactive,password\r\ndebug3: authmethod_is_enabled publickey\r\ndebug1: Next authentication method: publickey\r\ndebug1: Offering public key: Ishanagi - GitHub - SSH Key RSA SHA256:rKmPMuBNwfWCPziQR4g6aj8K1gHOf1Kb4oYPDTpP2A0 agent\r\ndebug3: send packet: type 50\r\ndebug2: we sent a publickey packet, wait for reply\r\ndebug3: receive packet: type 51\r\ndebug1: Authentications that can continue: publickey,password\r\ndebug1: Offering public key: Main SSH Key RSA SHA256:XKQlBN2e5G9+lsgwkQRxQrULFr1bU3KNB8Vlh2fC/g4 agent\r\ndebug3: send packet: type 50\r\ndebug2: we sent a publickey packet, wait for reply\r\ndebug3: receive packet: type 51\r\ndebug1: Authentications that can continue: publickey,password\r\ndebug1: Trying private key: /root/.ssh/id_rsa\r\ndebug3: no such identity: /root/.ssh/id_rsa: No such file or directory\r\ndebug1: Trying private key: /root/.ssh/id_dsa\r\ndebug3: no such identity: /root/.ssh/id_dsa: No such file or directory\r\ndebug1: Trying private key: /root/.ssh/id_ecdsa\r\ndebug3: no such identity: /root/.ssh/id_ecdsa: No such file or directory\r\ndebug1: Trying private key: /root/.ssh/id_ecdsa_sk\r\ndebug3: no such identity: /root/.ssh/id_ecdsa_sk: No such file or directory\r\ndebug1: Trying private key: /root/.ssh/id_ed25519\r\ndebug3: no such identity: /root/.ssh/id_ed25519: No such file or directory\r\ndebug1: Trying private key: /root/.ssh/id_ed25519_sk\r\ndebug3: no such identity: /root/.ssh/id_ed25519_sk: No such file or directory\r\ndebug1: Trying private key: /root/.ssh/id_xmss\r\ndebug3: no such identity: /root/.ssh/id_xmss: No such file or directory\r\ndebug2: we did not send a packet, disable method\r\ndebug3: authmethod_lookup password\r\ndebug3: remaining preferred: ,password\r\ndebug3: authmethod_is_enabled password\r\ndebug1: Next authentication method: password\r\ndebug3: send packet: type 50\r\ndebug2: we sent a password packet, wait for reply\r\ndebug3: receive packet: type 52\r\ndebug1: Enabling compression at level 6.\r\ndebug1: Authentication succeeded (password).\r\nAuthenticated to hursvl01.hursley.ibm.com ([9.20.6.250]:20122).\r\ndebug1: setting up multiplex master socket\r\ndebug3: muxserver_listen: temporary control path /root/.ansible/cp/36e3ec8490.2unXOzAbOBHNNvNr\r\ndebug2: fd 4 setting O_NONBLOCK\r\ndebug3: fd 4 is O_NONBLOCK\r\ndebug3: fd 4 is O_NONBLOCK\r\ndebug1: channel 0: new [/root/.ansible/cp/36e3ec8490]\r\ndebug3: muxserver_listen: mux listener channel 0 fd 4\r\ndebug2: fd 3 setting TCP_NODELAY\r\ndebug3: ssh_packet_set_tos: set IP_TOS 0x08\r\ndebug1: control_persist_detach: backgrounding master process\r\ndebug2: control_persist_detach: background process is 7024\r\ndebug2: fd 4 setting O_NONBLOCK\r\ndebug1: forking to background\r\ndebug1: Entering interactive session.\r\ndebug1: pledge: id\r\ndebug2: set_control_persist_exit_time: schedule exit in 60 seconds\r\ndebug1: multiplexing control connection\r\ndebug2: fd 5 setting O_NONBLOCK\r\ndebug3: fd 5 is O_NONBLOCK\r\ndebug1: channel 1: new [mux-control]\r\ndebug3: channel_post_mux_listener: new mux channel 1 fd 5\r\ndebug3: mux_master_read_cb: channel 1: hello sent\r\ndebug2: set_control_persist_exit_time: cancel scheduled exit\r\ndebug3: mux_master_read_cb: channel 1 packet type 0x00000001 len 4\r\ndebug2: mux_master_process_hello: channel 1 slave version 4\r\ndebug2: mux_client_hello_exchange: master version 4\r\ndebug3: mux_client_forwards: request forwardings: 0 local, 0 remote\r\ndebug3: mux_client_request_session: entering\r\ndebug3: mux_client_request_alive: entering\r\ndebug3: mux_master_read_cb: channel 1 packet type 0x10000004 len 4\r\ndebug2: mux_master_process_alive_check: channel 1: alive check\r\ndebug3: mux_client_request_alive: done pid = 7026\r\ndebug3: mux_client_request_session: session request sent\r\ndebug3: mux_master_read_cb: channel 1 packet type 0x10000002 len 103\r\ndebug2: mux_master_process_new_session: channel 1: request tty 0, X 0, agent 1, subsys 0, term "xterm-256color", cmd "/bin/sh -c \'echo ~ibmuser && sleep 0\'", env 1\r\ndebug3: mux_master_process_new_session: got fds stdin 6, stdout 7, stderr 8\r\ndebug2: fd 7 setting O_NONBLOCK\r\ndebug2: fd 8 setting O_NONBLOCK\r\ndebug1: channel 2: new [client-session]\r\ndebug2: mux_master_process_new_session: channel_new: 2 linked to control channel 1\r\ndebug2: channel 2: send open\r\ndebug3: send packet: type 90\r\ndebug3: receive packet: type 80\r\ndebug1: client_input_global_request: rtype hostkeys-00@openssh.com want_reply 0\r\ndebug3: receive packet: type 91\r\ndebug2: channel_input_open_confirmation: channel 2: callback start\r\ndebug1: Requesting authentication agent forwarding.\r\ndebug2: channel 2: request auth-agent-req@openssh.com confirm 0\r\ndebug3: send packet: type 98\r\ndebug2: client_session2_setup: id 2\r\ndebug1: Sending environment.\r\ndebug1: Sending env LANG = C.UTF-8\r\ndebug2: channel 2: request env confirm 0\r\ndebug3: send packet: type 98\r\ndebug1: Sending command: /bin/sh -c \'echo ~ibmuser && sleep 0\'\r\ndebug2: channel 2: request exec confirm 1\r\ndebug3: send packet: type 98\r\ndebug3: mux_session_confirm: sending success reply\r\ndebug2: channel_input_open_confirmation: channel 2: callback done\r\ndebug2: channel 2: open confirm rwindow 0 rmax 32768\r\ndebug2: channel 2: rcvd adjust 2097152\r\ndebug3: receive packet: type 99\r\ndebug2: channel_input_status_confirm: type 99 id 2\r\ndebug2: exec request accepted on channel 2\r\ndebug3: receive packet: type 98\r\ndebug1: client_input_channel_req: channel 2 rtype exit-status reply 0\r\ndebug3: mux_exit_message: channel 2: exit message, exitval 0\r\ndebug3: receive packet: type 98\r\ndebug1: client_input_channel_req: channel 2 rtype eow@openssh.com reply 0\r\ndebug2: channel 2: rcvd eow\r\ndebug2: channel 2: chan_shutdown_read (i0 o0 sock -1 wfd 6 efd 8 [write])\r\ndebug2: channel 2: input open -> closed\r\ndebug3: receive packet: type 96\r\ndebug2: channel 2: rcvd eof\r\ndebug2: channel 2: output open -> drain\r\ndebug2: channel 2: obuf empty\r\ndebug2: channel 2: chan_shutdown_write (i3 o1 sock -1 wfd 7 efd 8 [write])\r\ndebug2: channel 2: output drain -> closed\r\ndebug3: receive packet: type 97\r\ndebug2: channel 2: rcvd close\r\ndebug3: channel 2: will not send data after close\r\ndebug2: channel 2: send close\r\ndebug3: send packet: type 97\r\ndebug2: channel 2: is dead\r\ndebug2: channel 2: gc: notify user\r\ndebug3: mux_master_session_cleanup_cb: entering for channel 2\r\ndebug2: channel 1: rcvd close\r\ndebug2: channel 1: output open -> drain\r\ndebug2: channel 1: chan_shutdown_read (i0 o1 sock 5 wfd 5 efd -1 [closed])\r\ndebug2: channel 1: input open -> closed\r\ndebug2: channel 2: gc: user detached\r\ndebug2: channel 2: is dead\r\ndebug2: channel 2: garbage collecting\r\ndebug1: channel 2: free: client-session, nchannels 3\r\ndebug3: channel 2: status: The following connections are open:\r\n  #1 mux-control (t16 nr0 i3/0 o1/16 e[closed]/0 fd 5/5/-1 sock 5 cc -1)\r\n  #2 client-session (t4 r0 i3/0 o3/0 e[write]/0 fd -1/-1/8 sock -1 cc -1)\r\n\r\ndebug2: channel 1: obuf empty\r\ndebug2: channel 1: chan_shutdown_write (i3 o1 sock 5 wfd 5 efd -1 [closed])\r\ndebug2: channel 1: output drain -> closed\r\ndebug2: channel 1: is dead (local)\r\ndebug2: channel 1: gc: notify user\r\ndebug3: mux_master_control_cleanup_cb: entering for channel 1\r\ndebug2: channel 1: gc: user detached\r\ndebug2: channel 1: is dead (local)\r\ndebug2: channel 1: garbage collecting\r\ndebug1: channel 1: free: mux-control, nchannels 2\r\ndebug3: channel 1: status: The following connections are open:\r\n  #1 mux-control (t16 nr0 i3/0 o3/0 e[closed]/0 fd 5/5/-1 sock 5 cc -1)\r\n\r\ndebug3: mux_client_read_packet: read header failed: Broken pipe\r\ndebug2: set_control_persist_exit_time: schedule exit in 60 seconds\r\ndebug2: Received exit status from master 0\r\n')
<hursvl01.hursley.ibm.com> ESTABLISH SSH CONNECTION FOR USER: ibmuser
<hursvl01.hursley.ibm.com> SSH: EXEC sshpass -d10 ssh -vvv -C -o ControlMaster=auto -o ControlPersist=60s -o Port=20122 -o 'User="ibmuser"' -o ConnectTimeout=10 -o 'ControlPath="/root/.ansible/cp/36e3ec8490"' hursvl01.hursley.ibm.com '/bin/sh -c '"'"'( umask 77 && mkdir -p "` echo /u/ibmuser/.ansible/tmp `"&& mkdir "` echo /u/ibmuser/.ansible/tmp/ansible-tmp-1707385392.830748-7002-45259896926787 `" && echo ansible-tmp-1707385392.830748-7002-45259896926787="` echo /u/ibmuser/.ansible/tmp/ansible-tmp-1707385392.830748-7002-45259896926787 `" ) && sleep 0'"'"''
<hursvl01.hursley.ibm.com> (0, b'ansible-tmp-1707385392.830748-7002-45259896926787=/u/ibmuser/.ansible/tmp/ansible-tmp-1707385392.830748-7002-45259896926787\n', b'OpenSSH_8.2p1 Ubuntu-4ubuntu0.11, OpenSSL 1.1.1f  31 Mar 2020\r\ndebug1: Reading configuration data /root/.ssh/config\r\ndebug1: /root/.ssh/config line 4: Applying options for *\r\ndebug3: kex names ok: [diffie-hellman-group1-sha1]\r\ndebug1: /root/.ssh/config line 18: Applying options for hursvl01.hursley.ibm.com\r\ndebug1: Reading configuration data /etc/ssh/ssh_config\r\ndebug1: /etc/ssh/ssh_config line 19: include /etc/ssh/ssh_config.d/*.conf matched no files\r\ndebug1: /etc/ssh/ssh_config line 21: Applying options for *\r\ndebug1: auto-mux: Trying existing master\r\ndebug2: fd 3 setting O_NONBLOCK\r\ndebug2: mux_client_hello_exchange: master version 4\r\ndebug3: mux_client_forwards: request forwardings: 0 local, 0 remote\r\ndebug3: mux_client_request_session: entering\r\ndebug3: mux_client_request_alive: entering\r\ndebug3: mux_client_request_alive: done pid = 7026\r\ndebug3: mux_client_request_session: session request sent\r\ndebug3: mux_client_read_packet: read header failed: Broken pipe\r\ndebug2: Received exit status from master 0\r\n')
Using module file /root/.ansible/collections/ansible_collections/ibm/ibm_zos_core/plugins/modules/zos_job_submit.py
<hursvl01.hursley.ibm.com> PUT /root/.ansible/tmp/ansible-local-6994z0fx2vyv/tmpe9t2iowt TO /u/ibmuser/.ansible/tmp/ansible-tmp-1707385392.830748-7002-45259896926787/AnsiballZ_zos_job_submit.py
<hursvl01.hursley.ibm.com> SSH: EXEC sshpass -d10 sftp -o BatchMode=no -b - -vvv -C -o ControlMaster=auto -o ControlPersist=60s -o Port=20122 -o 'User="ibmuser"' -o ConnectTimeout=10 -o 'ControlPath="/root/.ansible/cp/36e3ec8490"' '[hursvl01.hursley.ibm.com]'
<hursvl01.hursley.ibm.com> (0, b'sftp> put /root/.ansible/tmp/ansible-local-6994z0fx2vyv/tmpe9t2iowt /u/ibmuser/.ansible/tmp/ansible-tmp-1707385392.830748-7002-45259896926787/AnsiballZ_zos_job_submit.py\n', b'OpenSSH_8.2p1 Ubuntu-4ubuntu0.11, OpenSSL 1.1.1f  31 Mar 2020\r\ndebug1: Reading configuration data /root/.ssh/config\r\ndebug1: /root/.ssh/config line 4: Applying options for *\r\ndebug3: kex names ok: [diffie-hellman-group1-sha1]\r\ndebug1: /root/.ssh/config line 18: Applying options for hursvl01.hursley.ibm.com\r\ndebug1: Reading configuration data /etc/ssh/ssh_config\r\ndebug1: /etc/ssh/ssh_config line 19: include /etc/ssh/ssh_config.d/*.conf matched no files\r\ndebug1: /etc/ssh/ssh_config line 21: Applying options for *\r\ndebug1: auto-mux: Trying existing master\r\ndebug2: fd 3 setting O_NONBLOCK\r\ndebug2: mux_client_hello_exchange: master version 4\r\ndebug3: mux_client_forwards: request forwardings: 0 local, 0 remote\r\ndebug3: mux_client_request_session: entering\r\ndebug3: mux_client_request_alive: entering\r\ndebug3: mux_client_request_alive: done pid = 7026\r\ndebug3: mux_client_request_session: session request sent\r\ndebug2: Remote version: 3\r\ndebug2: Server supports extension "posix-rename@openssh.com" revision 1\r\ndebug2: Server supports extension "statvfs@openssh.com" revision 2\r\ndebug2: Server supports extension "fstatvfs@openssh.com" revision 2\r\ndebug2: Server supports extension "hardlink@openssh.com" revision 1\r\ndebug2: Server supports extension "fsync@openssh.com" revision 1\r\ndebug3: Sent message fd 3 T:16 I:1\r\ndebug3: SSH_FXP_REALPATH . -> /u/ibmuser size 0\r\ndebug3: Looking up /root/.ansible/tmp/ansible-local-6994z0fx2vyv/tmpe9t2iowt\r\ndebug3: Sent message fd 3 T:17 I:2\r\ndebug3: Received stat reply T:101 I:2\r\ndebug1: Couldn\'t stat remote file: No such file or directory\r\ndebug3: Sent message SSH2_FXP_OPEN I:3 P:/u/ibmuser/.ansible/tmp/ansible-tmp-1707385392.830748-7002-45259896926787/AnsiballZ_zos_job_submit.py\r\ndebug3: Sent message SSH2_FXP_WRITE I:4 O:0 S:32768\r\ndebug3: SSH2_FXP_STATUS 0\r\ndebug3: In write loop, ack for 4 32768 bytes at 0\r\ndebug3: Sent message SSH2_FXP_WRITE I:5 O:32768 S:32768\r\ndebug3: Sent message SSH2_FXP_WRITE I:6 O:65536 S:32768\r\ndebug3: Sent message SSH2_FXP_WRITE I:7 O:98304 S:32768\r\ndebug3: Sent message SSH2_FXP_WRITE I:8 O:131072 S:32768\r\ndebug3: Sent message SSH2_FXP_WRITE I:9 O:163840 S:32768\r\ndebug3: Sent message SSH2_FXP_WRITE I:10 O:196608 S:7343\r\ndebug3: SSH2_FXP_STATUS 0\r\ndebug3: In write loop, ack for 5 32768 bytes at 32768\r\ndebug3: SSH2_FXP_STATUS 0\r\ndebug3: In write loop, ack for 6 32768 bytes at 65536\r\ndebug3: SSH2_FXP_STATUS 0\r\ndebug3: In write loop, ack for 7 32768 bytes at 98304\r\ndebug3: SSH2_FXP_STATUS 0\r\ndebug3: In write loop, ack for 8 32768 bytes at 131072\r\ndebug3: SSH2_FXP_STATUS 0\r\ndebug3: In write loop, ack for 9 32768 bytes at 163840\r\ndebug3: SSH2_FXP_STATUS 0\r\ndebug3: In write loop, ack for 10 7343 bytes at 196608\r\ndebug3: Sent message SSH2_FXP_CLOSE I:4\r\ndebug3: SSH2_FXP_STATUS 0\r\ndebug3: mux_client_read_packet: read header failed: Broken pipe\r\ndebug2: Received exit status from master 0\r\n')
<hursvl01.hursley.ibm.com> ESTABLISH SSH CONNECTION FOR USER: ibmuser
<hursvl01.hursley.ibm.com> SSH: EXEC sshpass -d10 ssh -vvv -C -o ControlMaster=auto -o ControlPersist=60s -o Port=20122 -o 'User="ibmuser"' -o ConnectTimeout=10 -o 'ControlPath="/root/.ansible/cp/36e3ec8490"' hursvl01.hursley.ibm.com '/bin/sh -c '"'"'chmod u+x /u/ibmuser/.ansible/tmp/ansible-tmp-1707385392.830748-7002-45259896926787/ /u/ibmuser/.ansible/tmp/ansible-tmp-1707385392.830748-7002-45259896926787/AnsiballZ_zos_job_submit.py && sleep 0'"'"''
<hursvl01.hursley.ibm.com> (0, b'', b'OpenSSH_8.2p1 Ubuntu-4ubuntu0.11, OpenSSL 1.1.1f  31 Mar 2020\r\ndebug1: Reading configuration data /root/.ssh/config\r\ndebug1: /root/.ssh/config line 4: Applying options for *\r\ndebug3: kex names ok: [diffie-hellman-group1-sha1]\r\ndebug1: /root/.ssh/config line 18: Applying options for hursvl01.hursley.ibm.com\r\ndebug1: Reading configuration data /etc/ssh/ssh_config\r\ndebug1: /etc/ssh/ssh_config line 19: include /etc/ssh/ssh_config.d/*.conf matched no files\r\ndebug1: /etc/ssh/ssh_config line 21: Applying options for *\r\ndebug1: auto-mux: Trying existing master\r\ndebug2: fd 3 setting O_NONBLOCK\r\ndebug2: mux_client_hello_exchange: master version 4\r\ndebug3: mux_client_forwards: request forwardings: 0 local, 0 remote\r\ndebug3: mux_client_request_session: entering\r\ndebug3: mux_client_request_alive: entering\r\ndebug3: mux_client_request_alive: done pid = 7026\r\ndebug3: mux_client_request_session: session request sent\r\ndebug3: mux_client_read_packet: read header failed: Broken pipe\r\ndebug2: Received exit status from master 0\r\n')
<hursvl01.hursley.ibm.com> ESTABLISH SSH CONNECTION FOR USER: ibmuser
<hursvl01.hursley.ibm.com> SSH: EXEC sshpass -d10 ssh -vvv -C -o ControlMaster=auto -o ControlPersist=60s -o Port=20122 -o 'User="ibmuser"' -o ConnectTimeout=10 -o 'ControlPath="/root/.ansible/cp/36e3ec8490"' -tt hursvl01.hursley.ibm.com '/bin/sh -c '"'"'_BPXK_AUTOCVT=ON PATH=/bin:/usr/lpp/IBM/cyp/v3r9/pyz/bin:/usr/lpp/IBM/zoautil/bin LIBPATH=/usr/lpp/IBM/cyp/v3r9/pyz/lib:/lib:/usr/lib:/usr/lpp/IBM/zoautil/lib ZOAU_HOME=/usr/lpp/IBM/zoautil ZOAU_ROOT=/usr/lpp/IBM/zoautil PYTHONPATH=/usr/lpp/IBM/zoautil/lib /usr/lpp/IBM/cyp/v3r9/pyz/bin/python3 /u/ibmuser/.ansible/tmp/ansible-tmp-1707385392.830748-7002-45259896926787/AnsiballZ_zos_job_submit.py && sleep 0'"'"''
<hursvl01.hursley.ibm.com> (0, b'\r\n{"changed": false, "duration": 11, "failed": true, "jobs": [{"job_id": "JOB03777", "job_name": "RECEIVE", "subsystem": "TVT5002", "system": "IPO1", "owner": "IBMUSER", "ret_code": {"msg": "AC ?", "msg_code": "?", "code": null, "msg_text": "AC", "steps": []}, "job_class": "A", "svc_class": "BATNORML", "priority": "9", "asid": "46", "creation_date": "2024-02-08", "creation_time": "4:43:14", "queue_position": "0", "program_name": "?", "class": "A", "content_type": "", "ddnames": [{"ddname": "JESMSGLG", "record_count": "4", "id": "2", "stepname": "JES2", "proctep": null, "byte_count": "133", "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 V T 5 0 0 2", "0     ", " 04.43.14 JOB03777 ---- THURSDAY,  08 FEB 2024 ----", " 04.43.14 JOB03777  IRR010I  USERID IBMUSER  IS ASSIGNED TO THIS JOB.", " 04.43.14 JOB03777  ICH70001I IBMUSER  LAST ACCESS AT 04:43:11 ON THURSDAY, FEBRUARY 8, 2024", " 04.43.14 JOB03777  $HASP373 RECEIVE  STARTED - INIT A    - CLASS A        - SYS IPO1"]}, {"ddname": "JESJCL", "record_count": "18", "id": "3", "stepname": "JES2", "proctep": null, "byte_count": "136", "content": ["        1 //RECEIVE JOB \'RECEIVE\',                                                JOB03777", "          //         CLASS=A,", "          //*        TYPRUN=SCAN,", "          //         MSGCLASS=H,", "          //         NOTIFY=&SYSUID", "          //*********************************************************************", "          IEFC653I SUBSTITUTION JCL - \'RECEIVE\',CLASS=A,MSGCLASS=H,NOTIFY=IBMUSER", "        2 //STEP1    EXEC PGM=GIMSMP,REGION=0M,", "          //             PARM=\'PROCESS=WAIT\'", "        3 //SMPCSI   DD DSN=OS250F.CSI,DISP=SHR                                                  4 //SMPPTFIN DD DSN=IBMUSER.TEMP.PTF(SMPPTFIN),DISP=SHR", "        5 //SMPHOLD  DD DSN=IBMUSER.TEMP.PTF(SMPHOLD),DISP=SHR", "        6 //SMPOUT   DD SYSOUT=*", "        7 //SMPRPT   DD SYSOUT=*", "        8 //SMPLIST  DD SYSOUT=*", "        9 //SYSPRINT DD SYSOUT=*", "       10 //SMPCNTL  DD *", "       11 //"]}, {"ddname": "JESYSMSG", "record_count": "0", "id": "4", "stepname": "JES2", "proctep": null, "byte_count": "137", "content": [" ICH70001I IBMUSER  LAST ACCESS AT 04:43:11 ON THURSDAY, FEBRUARY 8, 2024", " IEFA111I RECEIVE IS USING THE FOLLOWING JOB RELATED SETTINGS:", "          SWA=BELOW,TIOT SIZE=32K,DSENQSHR=DISALLOW,GDGBIAS=JOB", " IEF236I ALLOC. FOR RECEIVE STEP1", " IEF237I 0403 ALLOCATED TO SMPCSI", " IGD103I SMS ALLOCATED TO DDNAME SMPPTFIN", " IGD103I SMS ALLOCATED TO DDNAME SMPHOLD", " IEF237I JES2 ALLOCATED TO SMPOUT", " IEF237I JES2 ALLOCATED TO SMPRPT", " IEF237I JES2 ALLOCATED TO SMPLIST", " IEF237I JES2 ALLOCATED TO SYSPRINT", " IEF237I JES2 ALLOCATED TO SMPCNTL", " IEF237I 0403 ALLOCATED TO SMPLOG", " IEF237I 0403 ALLOCATED TO SMPLOGA", " IGD101I SMS ALLOCATED TO DDNAME (SYSUT1  )", "         DSN (SYS24039.T044314.RA000.RECEIVE.R0100008     )", "         STORCLAS (CLASS2) MGMTCLAS (        ) DATACLAS (        )", "         VOL SER NOS= T50024", " IGD101I SMS ALLOCATED TO DDNAME (SYSUT2  )", "         DSN (SYS24039.T044314.RA000.RECEIVE.R0100009     )", "         STORCLAS (CLASS2) MGMTCLAS (        ) DATACLAS (        )", "         VOL SER NOS= T50022", " IGD101I SMS ALLOCATED TO DDNAME (SYSUT3  )", "         DSN (SYS24039.T044314.RA000.RECEIVE.R0100010     )", "         STORCLAS (CLASS2) MGMTCLAS (        ) DATACLAS (        )", "         VOL SER NOS= T50023", " IGD101I SMS ALLOCATED TO DDNAME (SYSUT4  )", "         DSN (SYS24039.T044314.RA000.RECEIVE.R0100011     )", "         STORCLAS (CLASS2) MGMTCLAS (        ) DATACLAS (        )", "         VOL SER NOS= T50024", " IEF237I 0403 ALLOCATED TO SMPPTS"]}, {"ddname": "SMPOUT", "record_count": "0", "id": "102", "stepname": "STEP1", "proctep": null, "byte_count": "121", "content": ["1PAGE 0001  - NOW SET TO GLOBAL ZONE          DATE 02/08/24  TIME 04:43:14  SMP/E 37.16   SMPOUT   OUTPUT", "      ", " GIM42401I    THE FOLLOWING PARAMETERS WERE SPECIFIED ON THE EXEC STATEMENT FOR GIMSMP: \'PROCESS=WAIT\'.", "   SET      BOUNDARY (GLOBAL) .", " GIM20501I    SET PROCESSING IS COMPLETE. THE HIGHEST RETURN CODE WAS 00.", "      ", "      ", "   RECEIVE.", "      ", " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UI92253.", " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UI92719.", " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UI94621.", " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UJ92940.", " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UJ93246.", " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UJ93367.", " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UJ93788.", " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UI92612.", " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UI93113.", " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UI94715.", " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UJ93296.", " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UJ93325.", " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UJ93387.", " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UJ93780.", " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UJ93816.", " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UJ94237.", " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UJ94259.", " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UJ94301.", " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UJ94317.", " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UJ94336.", " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UJ94420."]}, {"ddname": "SMPRPT", "record_count": "0", "id": "103", "stepname": "STEP1", "proctep": null, "byte_count": "121", "content": ["1PAGE 0001  - NOW SET TO GLOBAL ZONE          DATE 02/08/24  TIME 04:43:14  SMP/E 37.16   SMPRPT   OUTPUT", "      ", "   RECEIVE."]}], "duration": 11}], "msg": "The JCL submitted with job id JOB03777 but appears to be a long running job that exceeded its maximum wait time of 10 second(s). Consider using module zos_job_query to poll for a long running job or increase option \'wait_times_s` to a value greater than 11.", "invocation": {"module_args": {"src": "IBMUSER.TEMP.PTF(RECEIVE)", "location": "DATA_SET", "wait": false, "return_output": true, "wait_time_s": 10, "use_template": false, "encoding": null, "volume": null, "max_rc": null, "temp_file": null, "template_parameters": null, "from_encoding": "UTF-8", "to_encoding": "IBM-1047"}}}\r\n', b'OpenSSH_8.2p1 Ubuntu-4ubuntu0.11, OpenSSL 1.1.1f  31 Mar 2020\r\ndebug1: Reading configuration data /root/.ssh/config\r\ndebug1: /root/.ssh/config line 4: Applying options for *\r\ndebug3: kex names ok: [diffie-hellman-group1-sha1]\r\ndebug1: /root/.ssh/config line 18: Applying options for hursvl01.hursley.ibm.com\r\ndebug1: Reading configuration data /etc/ssh/ssh_config\r\ndebug1: /etc/ssh/ssh_config line 19: include /etc/ssh/ssh_config.d/*.conf matched no files\r\ndebug1: /etc/ssh/ssh_config line 21: Applying options for *\r\ndebug1: auto-mux: Trying existing master\r\ndebug2: fd 3 setting O_NONBLOCK\r\ndebug2: mux_client_hello_exchange: master version 4\r\ndebug3: mux_client_forwards: request forwardings: 0 local, 0 remote\r\ndebug3: mux_client_request_session: entering\r\ndebug3: mux_client_request_alive: entering\r\ndebug3: mux_client_request_alive: done pid = 7026\r\ndebug3: mux_client_request_session: session request sent\r\ndebug3: mux_client_read_packet: read header failed: Broken pipe\r\ndebug2: Received exit status from master 0\r\nShared connection to hursvl01.hursley.ibm.com closed.\r\n')
<hursvl01.hursley.ibm.com> ESTABLISH SSH CONNECTION FOR USER: ibmuser
<hursvl01.hursley.ibm.com> SSH: EXEC sshpass -d10 ssh -vvv -C -o ControlMaster=auto -o ControlPersist=60s -o Port=20122 -o 'User="ibmuser"' -o ConnectTimeout=10 -o 'ControlPath="/root/.ansible/cp/36e3ec8490"' hursvl01.hursley.ibm.com '/bin/sh -c '"'"'rm -f -r /u/ibmuser/.ansible/tmp/ansible-tmp-1707385392.830748-7002-45259896926787/ > /dev/null 2>&1 && sleep 0'"'"''
<hursvl01.hursley.ibm.com> (0, b'', b'OpenSSH_8.2p1 Ubuntu-4ubuntu0.11, OpenSSL 1.1.1f  31 Mar 2020\r\ndebug1: Reading configuration data /root/.ssh/config\r\ndebug1: /root/.ssh/config line 4: Applying options for *\r\ndebug3: kex names ok: [diffie-hellman-group1-sha1]\r\ndebug1: /root/.ssh/config line 18: Applying options for hursvl01.hursley.ibm.com\r\ndebug1: Reading configuration data /etc/ssh/ssh_config\r\ndebug1: /etc/ssh/ssh_config line 19: include /etc/ssh/ssh_config.d/*.conf matched no files\r\ndebug1: /etc/ssh/ssh_config line 21: Applying options for *\r\ndebug1: auto-mux: Trying existing master\r\ndebug2: fd 3 setting O_NONBLOCK\r\ndebug2: mux_client_hello_exchange: master version 4\r\ndebug3: mux_client_forwards: request forwardings: 0 local, 0 remote\r\ndebug3: mux_client_request_session: entering\r\ndebug3: mux_client_request_alive: entering\r\ndebug3: mux_client_request_alive: done pid = 7026\r\ndebug3: mux_client_request_session: session request sent\r\ndebug3: mux_client_read_packet: read header failed: Broken pipe\r\ndebug2: Received exit status from master 0\r\n')
fatal: [h3nmike]: FAILED! => {
    "changed": false,
    "duration": 11,
    "invocation": {
        "module_args": {
            "encoding": null,
            "from_encoding": "UTF-8",
            "location": "DATA_SET",
            "max_rc": null,
            "return_output": true,
            "src": "IBMUSER.TEMP.PTF(RECEIVE)",
            "temp_file": null,
            "template_parameters": null,
            "to_encoding": "IBM-1047",
            "use_template": false,
            "volume": null,
            "wait": false,
            "wait_time_s": 10
        }
    },
    "jobs": [
        {
            "asid": "46",
            "class": "A",
            "content_type": "",
            "creation_date": "2024-02-08",
            "creation_time": "4:43:14",
            "ddnames": [
                {
                    "byte_count": "133",
                    "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 V T 5 0 0 2",
                        "0     ",
                        " 04.43.14 JOB03777 ---- THURSDAY,  08 FEB 2024 ----",
                        " 04.43.14 JOB03777  IRR010I  USERID IBMUSER  IS ASSIGNED TO THIS JOB.",
                        " 04.43.14 JOB03777  ICH70001I IBMUSER  LAST ACCESS AT 04:43:11 ON THURSDAY, FEBRUARY 8, 2024",
                        " 04.43.14 JOB03777  $HASP373 RECEIVE  STARTED - INIT A    - CLASS A        - SYS IPO1"
                    ],
                    "ddname": "JESMSGLG",
                    "id": "2",
                    "proctep": null,
                    "record_count": "4",
                    "stepname": "JES2"
                },
                {
                    "byte_count": "136",
                    "content": [
                        "        1 //RECEIVE JOB 'RECEIVE',                                                JOB03777",
                        "          //         CLASS=A,",
                        "          //*        TYPRUN=SCAN,",
                        "          //         MSGCLASS=H,",
                        "          //         NOTIFY=&SYSUID",
                        "          //*********************************************************************",
                        "          IEFC653I SUBSTITUTION JCL - 'RECEIVE',CLASS=A,MSGCLASS=H,NOTIFY=IBMUSER",
                        "        2 //STEP1    EXEC PGM=GIMSMP,REGION=0M,",
                        "          //             PARM='PROCESS=WAIT'",
                        "        3 //SMPCSI   DD DSN=OS250F.CSI,DISP=SHR                                                  4 //SMPPTFIN DD DSN=IBMUSER.TEMP.PTF(SMPPTFIN),DISP=SHR",
                        "        5 //SMPHOLD  DD DSN=IBMUSER.TEMP.PTF(SMPHOLD),DISP=SHR",
                        "        6 //SMPOUT   DD SYSOUT=*",
                        "        7 //SMPRPT   DD SYSOUT=*",
                        "        8 //SMPLIST  DD SYSOUT=*",
                        "        9 //SYSPRINT DD SYSOUT=*",
                        "       10 //SMPCNTL  DD *",
                        "       11 //"
                    ],
                    "ddname": "JESJCL",
                    "id": "3",
                    "proctep": null,
                    "record_count": "18",
                    "stepname": "JES2"
                },
                {
                    "byte_count": "137",
                    "content": [
                        " ICH70001I IBMUSER  LAST ACCESS AT 04:43:11 ON THURSDAY, FEBRUARY 8, 2024",
                        " IEFA111I RECEIVE IS USING THE FOLLOWING JOB RELATED SETTINGS:",
                        "          SWA=BELOW,TIOT SIZE=32K,DSENQSHR=DISALLOW,GDGBIAS=JOB",
                        " IEF236I ALLOC. FOR RECEIVE STEP1",
                        " IEF237I 0403 ALLOCATED TO SMPCSI",
                        " IGD103I SMS ALLOCATED TO DDNAME SMPPTFIN",
                        " IGD103I SMS ALLOCATED TO DDNAME SMPHOLD",
                        " IEF237I JES2 ALLOCATED TO SMPOUT",
                        " IEF237I JES2 ALLOCATED TO SMPRPT",
                        " IEF237I JES2 ALLOCATED TO SMPLIST",
                        " IEF237I JES2 ALLOCATED TO SYSPRINT",
                        " IEF237I JES2 ALLOCATED TO SMPCNTL",
                        " IEF237I 0403 ALLOCATED TO SMPLOG",
                        " IEF237I 0403 ALLOCATED TO SMPLOGA",
                        " IGD101I SMS ALLOCATED TO DDNAME (SYSUT1  )",
                        "         DSN (SYS24039.T044314.RA000.RECEIVE.R0100008     )",
                        "         STORCLAS (CLASS2) MGMTCLAS (        ) DATACLAS (        )",
                        "         VOL SER NOS= T50024",
                        " IGD101I SMS ALLOCATED TO DDNAME (SYSUT2  )",
                        "         DSN (SYS24039.T044314.RA000.RECEIVE.R0100009     )",
                        "         STORCLAS (CLASS2) MGMTCLAS (        ) DATACLAS (        )",
                        "         VOL SER NOS= T50022",
                        " IGD101I SMS ALLOCATED TO DDNAME (SYSUT3  )",
                        "         DSN (SYS24039.T044314.RA000.RECEIVE.R0100010     )",
                        "         STORCLAS (CLASS2) MGMTCLAS (        ) DATACLAS (        )",
                        "         VOL SER NOS= T50023",
                        " IGD101I SMS ALLOCATED TO DDNAME (SYSUT4  )",
                        "         DSN (SYS24039.T044314.RA000.RECEIVE.R0100011     )",
                        "         STORCLAS (CLASS2) MGMTCLAS (        ) DATACLAS (        )",
                        "         VOL SER NOS= T50024",
                        " IEF237I 0403 ALLOCATED TO SMPPTS"
                    ],
                    "ddname": "JESYSMSG",
                    "id": "4",
                    "proctep": null,
                    "record_count": "0",
                    "stepname": "JES2"
                },
                {
                    "byte_count": "121",
                    "content": [
                        "1PAGE 0001  - NOW SET TO GLOBAL ZONE          DATE 02/08/24  TIME 04:43:14  SMP/E 37.16   SMPOUT   OUTPUT",
                        "      ",
                        " GIM42401I    THE FOLLOWING PARAMETERS WERE SPECIFIED ON THE EXEC STATEMENT FOR GIMSMP: 'PROCESS=WAIT'.",
                        "   SET      BOUNDARY (GLOBAL) .",
                        " GIM20501I    SET PROCESSING IS COMPLETE. THE HIGHEST RETURN CODE WAS 00.",
                        "      ",
                        "      ",
                        "   RECEIVE.",
                        "      ",
                        " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UI92253.",
                        " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UI92719.",
                        " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UI94621.",
                        " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UJ92940.",
                        " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UJ93246.",
                        " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UJ93367.",
                        " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UJ93788.",
                        " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UI92612.",
                        " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UI93113.",
                        " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UI94715.",
                        " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UJ93296.",
                        " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UJ93325.",
                        " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UJ93387.",
                        " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UJ93780.",
                        " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UJ93816.",
                        " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UJ94237.",
                        " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UJ94259.",
                        " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UJ94301.",
                        " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UJ94317.",
                        " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UJ94336.",
                        " GIM22701I    RECEIVE PROCESSING WAS SUCCESSFUL FOR SYSMOD UJ94420."
                    ],
                    "ddname": "SMPOUT",
                    "id": "102",
                    "proctep": null,
                    "record_count": "0",
                    "stepname": "STEP1"
                },
                {
                    "byte_count": "121",
                    "content": [
                        "1PAGE 0001  - NOW SET TO GLOBAL ZONE          DATE 02/08/24  TIME 04:43:14  SMP/E 37.16   SMPRPT   OUTPUT",
                        "      ",
                        "   RECEIVE."
                    ],
                    "ddname": "SMPRPT",
                    "id": "103",
                    "proctep": null,
                    "record_count": "0",
                    "stepname": "STEP1"
                }
            ],
            "duration": 11,
            "job_class": "A",
            "job_id": "JOB03777",
            "job_name": "RECEIVE",
            "owner": "IBMUSER",
            "priority": "9",
            "program_name": "?",
            "queue_position": "0",
            "ret_code": {
                "code": null,
                "msg": "AC ?",
                "msg_code": "?",
                "msg_text": "AC",
                "steps": []
            },
            "subsystem": "TVT5002",
            "svc_class": "BATNORML",
            "system": "IPO1"
        }
    ],
    "msg": "The JCL submitted with job id JOB03777 but appears to be a long running job that exceeded its maximum wait time of 10 second(s). Consider using module zos_job_query to poll for a long running job or increase option 'wait_times_s` to a value greater than 11."
}

PLAY RECAP ************************************************************************************************************************************************************************************
h3nmike                    : ok=0    changed=0    unreachable=0    failed=1    skipped=0    rescued=0    ignored=0 
Michael-Baylis commented 9 months ago

and yes #715 is what we need when wait: false disappears. But as it stands, wait: false should be working, but it doesn't

ddimatos commented 9 months ago

and yes #715 is what we need when wait: false disappears. But as it stands, wait: false should be working, but it doesn't

@Michael-Baylis - wait has been deprecated since version 1.5.0 , April of 2023, we generally allow for a deprecation to remain in place for 1 year, we are approaching that, during this time the interface remains unchanged to avoid impact to playbooks, you should have been seen some indication of this with this code:

 wait=dict(type="bool", required=False, default=False,
                  removed_at_date='2022-11-30',
                  removed_from_collection='ibm.ibm_zos_core'),

Also it was in our announcements

The doc since 1.5.0 has stated the below, "Setting this option will yield no change, it is deprecated.".

  wait:
    required: false
    default: false
    type: bool
    description:
      - Setting this option will yield no change, it is deprecated. There is no
        no need to set I(wait); setting I(wait_times_s) is the correct way to
        configure the amount of tme to wait for a job to execute.
      - Configuring wait used by the L(zos_job_submit,./zos_job_submit.html) module has been
        deprecated and will be removed in ibm.ibm_zos_core collection.
      - See option I(wait_time_s).

We will prioritize work item #715 as others have asked for it assuming there is capacity in Q2 2024.

As a work around, what I suggest is using either USS sub or zoau jsub as a submit and forget model for now, you can do that by invoking the shell, command or raw modules that are in ansible.builtin.

    - name: Get attributes for data sets
       ansible.builtin.command: jsub "IBMUSER.TEMP.PTF(RECEIVE)"

If this explains the various points, then I can convert this to a doc change to aid in clarity around such points you noted.

Michael-Baylis commented 9 months ago

I think the problem here is my understanding of "depreciated". Depreciated to me means, it still works but is not the way forward and should be replaced asap. The doc should have said that the parameter has been "disabled" and no longer functions.

wait_times_s: 0 should have been implemented when wait: was disabled.

I will use my workaround in the meantime.

ddimatos commented 8 months ago

Thank you for the suggestion @Michael-Baylis , regarding having implemented wait_time_s: 0, that is being reserved for a submit and forget model, the reason wait was removed was because it does not behave the same as wait_time_s:0, it was not a sumbit and forget or even a submit and wait for ever, what wait did was just let the code know that the user was going to adjust the wait_time_s, refer to the original snippet of the doc below:

If I(wait) is true, User can specify the wait time, see option ``wait_time_s``.

You are correct in the deprecations meaning, having it enabled really brought no value.

We did explain that setting the value would yield no change, the doc did state "Setting this option will yield no change", going forward we can be more explicit.

Going back to your first point that the doc says "Submit a job and optionally monitor for completion", we can edit the doc , but if you don't want to wait, set the wait_time_s to 1 second and use Ansible ignore_errors: true.

ddimatos commented 8 months ago

Reopen to improve documentation.