[Bug] [zos_copy] File wrongly modified after second zos_copy

[vcorfmatibm]

Is there an existing issue for this?

• There are no existing issues.

Are the dependencies a supported version?

• The dependencies are supported.

IBM Z Open Automation Utilities

v1.2.1

IBM Enterprise Python

v3.8.x

IBM z/OS Ansible core Version

v1.5.0

ansible-version

v2.11.x

z/OS version

v2.4

Ansible module

zos_copy

Bug description

Problem with zos_copy module when I copy a file from a uss directory to another uss directory when the file already exists in dest (Test also with version 1.4.0 and 1.5.0-beta.1 of Ansible z/OS core collection)
Here's my task:

• name: "Test zos_copy"
  zos_copy:
  src: "/tmp/input/test2.txt"
  dest: "/tmp/wd_uss/txt/test2.txt"
  remote_src: true
  mode: '0755'
  backup: false
  force: true
  The content of the file to copy is :
  Ceci n est que du text
  After first copy, test2.txt content in tmp/wd_uss/txt is ok :
  Ceci n est que du text
  After second copy (/tmp/wd_uss/txt/test2.txt already exists), file is modified (content unreadable).
  !! I don't touch the source, it's the same on the 1st and 2nd launch (/tmp/input/test2.txt)

For information :
ls -T /tmp/input/test2.txt ==>
t IBM-1047 T=on /tmp/input/test2.txt
ls -T /tmp/wd_uss/txt/test2.txt ==>
t IBM-1047 T=on /tmp/wd_uss/txt/test2.txt
When I run the task for the second time, the module returns "changed": true

Playbook verbosity output.

TASK [ibm.ibm_zos_wazi_deploy.zos_deploy : Test uss_copy] **************************************************************
task path: /mnt/c/Users/058275706/git/wazi-deploy-samples/translator/ansible/ansible_collections/ibm/ibm_zos_wazi_deploy/roles/zos_deploy/tasks/ibm_zos_collections/test.yml:16
<9.30.222.103> ESTABLISH SSH CONNECTION FOR USER: vcorfma
<9.30.222.103> SSH: EXEC ssh -C -o ControlMaster=auto -o ControlPersist=60s -o StrictHostKeyChecking=no -o Port=222 -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o 'User="vcorfma"' -o ConnectTimeout=10 -o 'ControlPath="/home/vcorfmat/.ansible/cp/70a06198bc"' 9.30.222.103 '/bin/sh -c '"'"'echo ~vcorfma && sleep 0'"'"''
<9.30.222.103> (0, b'/u/vcorfma\n', b'')
<9.30.222.103> ESTABLISH SSH CONNECTION FOR USER: vcorfma
<9.30.222.103> SSH: EXEC ssh -C -o ControlMaster=auto -o ControlPersist=60s -o StrictHostKeyChecking=no -o Port=222 -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o 'User="vcorfma"' -o ConnectTimeout=10 -o 'ControlPath="/home/vcorfmat/.ansible/cp/70a06198bc"' 9.30.222.103 '/bin/sh -c '"'"'( umask 77 && mkdir -p "echo /u/vcorfma/.ansible/tmp"&& mkdir "echo /u/vcorfma/.ansible/tmp/ansible-tmp-1681474911.0594854-304-278803071325442" && echo ansible-tmp-1681474911.0594854-304-278803071325442="echo /u/vcorfma/.ansible/tmp/ansible-tmp-1681474911.0594854-304-278803071325442" ) && sleep 0'"'"''
<9.30.222.103> (0, b'ansible-tmp-1681474911.0594854-304-278803071325442=/u/vcorfma/.ansible/tmp/ansible-tmp-1681474911.0594854-304-278803071325442\n', b'')
Using module file /home/vcorfmat/.ansible/collections/ansible_collections/ibm/ibm_zos_core/plugins/modules/zos_copy.py
<9.30.222.103> PUT /home/vcorfmat/.ansible/tmp/ansible-local-182tsmuxyly/tmpncu3q_94 TO /u/vcorfma/.ansible/tmp/ansible-tmp-1681474911.0594854-304-278803071325442/AnsiballZ_zos_copy.py
<9.30.222.103> SSH: EXEC sftp -b - -C -o ControlMaster=auto -o ControlPersist=60s -o StrictHostKeyChecking=no -o Port=222 -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o 'User="vcorfma"' -o ConnectTimeout=10 -o 'ControlPath="/home/vcorfmat/.ansible/cp/70a06198bc"' '[9.30.222.103]'
<9.30.222.103> (0, b'sftp> put /home/vcorfmat/.ansible/tmp/ansible-local-182tsmuxyly/tmpncu3q_94 /u/vcorfma/.ansible/tmp/ansible-tmp-1681474911.0594854-304-278803071325442/AnsiballZ_zos_copy.py\n', b'')
<9.30.222.103> ESTABLISH SSH CONNECTION FOR USER: vcorfma
<9.30.222.103> SSH: EXEC ssh -C -o ControlMaster=auto -o ControlPersist=60s -o StrictHostKeyChecking=no -o Port=222 -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o 'User="vcorfma"' -o ConnectTimeout=10 -o 'ControlPath="/home/vcorfmat/.ansible/cp/70a06198bc"' 9.30.222.103 '/bin/sh -c '"'"'chmod u+x /u/vcorfma/.ansible/tmp/ansible-tmp-1681474911.0594854-304-278803071325442/ /u/vcorfma/.ansible/tmp/ansible-tmp-1681474911.0594854-304-278803071325442/AnsiballZ_zos_copy.py && sleep 0'"'"''
<9.30.222.103> (0, b'', b'')
<9.30.222.103> ESTABLISH SSH CONNECTION FOR USER: vcorfma
<9.30.222.103> SSH: EXEC ssh -C -o ControlMaster=auto -o ControlPersist=60s -o StrictHostKeyChecking=no -o Port=222 -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o 'User="vcorfma"' -o ConnectTimeout=10 -o 'ControlPath="/home/vcorfmat/.ansible/cp/70a06198bc"' -tt 9.30.222.103 '/bin/sh -c '"'"'_BPXK_AUTOCVT=ON ZOAU_HOME=/var/usr/lpp/IBM/zoautil LIBPATH=/var/usr/lpp/IBM/zoautil/lib:/var/usr/lpp/IBM/cyp/v3r10/pyz/lib:/lib:/usr/lib:. PATH=/var/usr/lpp/IBM/zoautil/bin:/var/usr/lpp/IBM/cyp/v3r10/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 /var/usr/lpp/IBM/cyp/v3r10/pyz/bin/python3 /u/vcorfma/.ansible/tmp/ansible-tmp-1681474911.0594854-304-278803071325442/AnsiballZ_zos_copy.py && sleep 0'"'"''
<9.30.222.103> (0, b'\r\n{"size": 23, "changed": false, "src": "/SYSTEM/tmp/input/test2.txt", "dest": "/tmp/wd_uss/txt/test2.txt", "ds_type": "USS", "dest_exists": true, "backup_name": null, "uid": 10149, "gid": 100, "owner": "VCORFMA", "group": "OMVS", "mode": "0755", "state": "file", "invocation": {"module_args": {"src": "/tmp/input/test2.txt", "dest": "/tmp/wd_uss/txt/test2.txt", "remote_src": true, "mode": "0755", "backup": false, "force": true, "is_uss": true, "is_pds": false, "is_src_dir": false, "copy_member": false, "src_member": false, "temp_path": null, "is_mvs_dest": false, "local_charset": "UTF-8", "is_binary": false, "local_follow": true, "ignore_sftp_stderr": false, "validate": false, "unsafe_writes": false, "encoding": null, "content": null, "backup_name": null, "volume": null, "dest_data_set": null, "size": null, "tmp_hlq": null, "owner": null, "group": null, "seuser": null, "serole": null, "selevel": null, "setype": null, "attributes": null}}}\r\n', b'Shared connection to 9.30.222.103 closed.\r\n')
<9.30.222.103> ESTABLISH SSH CONNECTION FOR USER: vcorfma
<9.30.222.103> SSH: EXEC ssh -C -o ControlMaster=auto -o ControlPersist=60s -o StrictHostKeyChecking=no -o Port=222 -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o 'User="vcorfma"' -o ConnectTimeout=10 -o 'ControlPath="/home/vcorfmat/.ansible/cp/70a06198bc"' 9.30.222.103 '/bin/sh -c '"'"'rm -f -r /u/vcorfma/.ansible/tmp/ansible-tmp-1681474911.0594854-304-278803071325442/ > /dev/null 2>&1 && sleep 0'"'"''
<9.30.222.103> (0, b'', b'')
ok: [zos_host_01] => {
"changed": false,
"dest": "/tmp/wd_uss/txt/test2.txt",
"gid": 100,
"group": "OMVS",
"invocation": {
"module_args": {
"backup": false,
"dest": "/tmp/wd_uss/txt/test2.txt",
"force": true,
"mode": "0755",
"remote_src": true,
"src": "/tmp/input/test2.txt"
}
},
"is_binary": false,
"mode": "0755",
"owner": "VCORFMA",
"size": 23,
"src": "/SYSTEM/tmp/input/test2.txt",
"state": "file",
"uid": 10149
}

Ansible configuration.

#*******************************************************************************
# 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_wazi_deploy.cb_evidences

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

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"

[ddimatos]

We need Ansible dev to triage this, simply run the scenario and see if it is still an issue with our latest dev branch. From there we can figure out how to plan.

[ketankelkar]

I was unable to recreate the issue, see attached playbook to view how i attempted it. I ran it twice in a row (as-is) and also ran it with the commented out tasks in play, where i call zos_copy twice in a row. Both approaches yielded the same correct results, the destination file was still read-able.

TASK [Test zos_copy] ***************************************************************************************************************************************************************************
changed: [zos_host]

TASK [cat file] ********************************************************************************************************************************************************************************
changed: [zos_host]

TASK [print output] ****************************************************************************************************************************************************************************
ok: [zos_host] => {
    "output.stdout": "Ceci n est que du text"
}

TASK [Test zos_copy x2] ************************************************************************************************************************************************************************
ok: [zos_host]

TASK [cat file x2] *****************************************************************************************************************************************************************************
changed: [zos_host]

TASK [print output x2] *************************************************************************************************************************************************************************
ok: [zos_host] => {
    "output.stdout": "Ceci n est que du text"
}

It may be helpful if you could try running my playbook and see if you get the same results. One thing to note, I had to remove the stdout_callback = ibm.ibm_zos_wazi_deploy.cb_evidences line from the ansible.cfg file

Note- had to attach my playbook as a text file.
recreate.yml.txt

[ddimatos]

@vcorfmatibm - Since the issue has not had any updates since July 24th (past our 60 day retention) , we will close the issue. You can reopen and we will triage.

[vcorfmatibm]

@ddimatos I tried to execute the playbook [recreate.yml.txt] given by @ketankelkar. If I test with python 3.9 it's ok, the file is readable after the second copy. But with python 3.10 or 3.11, the file is not readable after the second copy

[ddimatos]

@vcorfmatibm thank you for the update.
There are known issues with IBM Open Enterprise SDK for Python versuions 3.10/3.11 we are working on in issue #676 , the impact has been only in community modules, in other words, our zos_modules are not impacted. Since @ketankelkar has been leading the python issue #676 and this one, I will let him comment if your issue is part of issue #676 so that we can decide if this should remain open or not.

[ketankelkar]

While I verify on my end, @vcorfmatibm, would you mind running the recreate with the PYTHONSTDINENCODING: "cp1047" included as part of your environment_vars? From above I see it's not in your current set of 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"

[jbyibm]

With PYTHONSTDINENCODING: "cp1047" it fail.

PLAY [all] *************************************************************************************************************

TASK [setup] ***********************************************************************************************************
changed: [zos_host_01]

TASK [Test zos_copy] ***************************************************************************************************
changed: [zos_host_01]

TASK [cat file] ********************************************************************************************************
changed: [zos_host_01]

TASK [print output] ****************************************************************************************************
ok: [zos_host_01] => {
    "output.stdout": "Ceci n est que du text"
}

TASK [Test zos_copy x2] ************************************************************************************************
changed: [zos_host_01]

TASK [cat file x2] *****************************************************************************************************
[DEPRECATION WARNING]: Module "ansible.builtin.command" returned non UTF-8 data in the JSON response. This will become
an error in the future. This feature will be removed in version 2.18. Deprecation warnings can be disabled by setting
deprecation_warnings=False in ansible.cfg.
changed: [zos_host_01]

TASK [print output x2] *************************************************************************************************
[DEPRECATION WARNING]: Non UTF-8 encoded data replaced with "?" while displaying text to stdout/stderr, this is
temporary and will become an error. This feature will be removed in version 2.18. Deprecation warnings can be disabled
by setting deprecation_warnings=False in ansible.cfg.
ok: [zos_host_01] => {
    "output.stdout": "Å?@?@?@?@?@?\u0015"
}

TASK [cleanup] *********************************************************************************************************
[WARNING]: raw module does not support the environment keyword
changed: [zos_host_01]

PLAY RECAP *************************************************************************************************************
zos_host_01                : ok=8    changed=6    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0

ansible [core 2.15.4]
  config file = None
  configured module search path = ['/home/jby/.ansible/plugins/modules', '/usr/share/ansible/plugins/modules']
  ansible python module location = /home/jby/.local/lib/python3.10/site-packages/ansible
  ansible collection location = /home/jby/.ansible/collections:/usr/share/ansible/collections
  executable location = /home/jby/.local/bin/ansible
  python version = 3.10.12 (main, Jun 11 2023, 05:26:28) [GCC 11.4.0] (/usr/bin/python3)
  jinja version = 3.1.2
  libyaml = True

Python 3.11.3 on the z/OS

[vcorfmatibm]

@ddimatos Hello ! What do we do with this problem ? Do you reopen this issue ? Do you open an other one ? Thanks by advance for your response

[ddimatos]

Hi @vcorfmatibm - I am waiting to hear from @ketankelkar if what you are experiencing with python 3.10/3.11 is the same issue as #676 else we might need to create a new issue.

[ketankelkar]

Sorry for the delays folks, I was able to recreate the unreadable file on a 2nd zos_copy. Will be investigating further into the issue in the morning.

[DEPRECATION WARNING]: Non UTF-8 encoded data replaced with "?" while displaying text to stdout/stderr, this is temporary and will become an error. This feature will be removed in version 2.18. Deprecation warnings can be 
disabled by setting deprecation_warnings=False in ansible.cfg.
ok: [zvm] => {
    "output.stdout": "Å?@?@?@?@?@?\u0015"
}

Took a look at the hex dump after each copy to see if anything stood out:
1st zos_copy

bash-4.3# ls -T .
t IBM-1047    T=on  test2.txt
bash-4.3# od -x test2.txt 
0000000000      C385    8389    4095    4085    A2A3    4098    A485    4084
0000000020      A440    A385    A7A3    1500
0000000027

2nd zos_copy

bash-4.3# ls -T .
t IBM-1047    T=on  test2.txt
bash-4.3# cat test2.txt   
bash-4.3# od -x test2.txt 4.3# cat test2.txt 
0000000000      6625    2329    7C35    7C25    4AB1    7C38    9F25    7C24
0000000020      9F7C    B125    B5B1    3D00
0000000027

File tagging seems to be intact for both copies.

I used the same playbook I pasted above with:

  vars:
    ZOAU: /zoau/v1.2.4
    PYZ: /allpython/3.11/usr/lpp/IBM/cyp/v3r11/pyz/

  environment:
    _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"
    PYTHONSTDINENCODING: 'cp1047'

[jbyibm]

Thanks for this update. We have high interest for a fix.

[ddimatos]

While @ketankelkar is on PTO, I took their recreate and noticed a few things. I started by looking for a repeating hex value in the corrupt result, I noticed 25 which corresponds to the e position for EBCDIC value 85 which is a good sign, at least there is a pattern.

Corrupt hex values 25 repeating:

6625 2329 7C35 7C25 4AB1 7C38 9F25 7C24

Under a hunch, my guess is something told the code to use ISO8859-1 for the from encoding and IBM-1047 as the to encoding on a IBM-1047 encoding file, which is the reverse of what it should be and this manual recreate demonstrates this:

test2.txt is IBM-1047, I can cat the file and see that as well, the tag is present:

# ls -laT test2.txt
t IBM-1047    T=on  -rw-r--r--   1 BPXROOT  OMVSGRP       23 Oct 24 14:14 test2.txt

# cat test2.txt
Ceci n est que du text

# od -x test2.txt
0000000000      C385    8389    4095    4085    A2A3    4098    A485    4084
0000000020      A440    A385    A7A3    1500
0000000027

Perform an inverted encoding conversion (error) in this step:

# iconv -f ISO8859-1 -t IBM-1047 test2.txt >invalid.txt

Now the file is corrupt, unreadable, hex values show a repeating pattern but unreadable and not any values I could correspond to which makes sense because the conversion was inverted.

# ls -laT invalid.txt
- untagged    T=off -rw-r--r--   1 BPXROOT  OMVSGRP       23 Oct 24 14:55 invalid.txt

# cat invalid.txt
��@�@���@���@��@����

# od -x invalid.txt
0000000000      6625    2329    7C35    7C25    4AB1    7C38    9F25    7C24
0000000020      9F7C    B125    B5B1    3D00
0000000027

I also divided this test into 2 playbooks to rule out anything that was happening by sharing a same runtime and still ended up with corrupt content.

Next step is to investigate why this is happening.

[ddimatos]

I have found the source of the issue, while we are investigating a dependency as the source of the issue, I do believe we have a work around for this, the work around will need to go through a full testing cycle and regression.

I will update the issue once the dependency evaluates our findings.

In the mean time, we will see who on the team has availability to put this fix in the next beta release 1.9.0-beta.1 and possibly consider a GA fix for 1.8.0.

[ddimatos]

The source of the issue is that a file is copied with shutil.copy into a new file is fine, while if copied to existing file the data gets encoded incorrectly. The recreate in python is:

1. A source file in USS:

# cat /tmp/recreate737/src/test2.txt
Ceci n est que du text

2. Perform a shutil.copy to a new non-existent file /tmp/test_1.txt (point is the file does not exist), this yields expected results.

>>> shutil.copy(src_file_path,"/tmp/test_1.txt")
'/tmp/test_1.txt'
Expected results are good so far.
# ls -laT |grep test_1.txt
t IBM-1047    T=on  -rw-r--r--   1 BPXROOT  OMVSGRP23 Oct 24 18:28 test_1.txt
# cat test_1.txt
Ceci n est que du text
# od -x test_1.txt
0000000000      C385    8389    4095    4085    A2A3    4098    A485    4084
0000000020      A440    A385    A7A3    1500
0000000027

3. Repeat the above exact same step in bullet 2, no change, just replace the file "/tmp/test_1.txt"

>>> shutil.copy(src_file_path,"/tmp/test_1.txt")
'/tmp/test_1.txt'
Unexpected result. What I get back is not IBM-1047, ASCII or UTF8
# ls -laT |grep test_1.txt
t IBM-1047    T=on  -rw-r--r--   1 BPXROOT  OMVSGRP23 Oct 24 18:29 test_1.txt
# cat test_1.txt
��@�@���@���@��@����
# od -x test_1.txt
0000000000      6625    2329    7C35    7C25    4AB1    7C38    9F25    7C24
0000000020      9F7C    B125    B5B1    3D00
0000000027

4. Evaluate
   For example take the first char C , the unexpected result does not correspond to any of these encodings, the first hex value is 66 in the unexpected hex dump, where as in expected its a C3 , nothing maps to 66.

char    hex   encoding
C       xC3   ebcdic
C       x43   UTF-8
C       x43   ASCII

Dependency is working on this, but we will review implementing a work around.

[ddimatos]

While I did not prepare a branch or a patch and only focused on one such shutil.copy invocation that causes this reported issue, there are other invocations we should evaluate. Below is the simple snippet I used that should resolve this, and here is the line I replaced.

                opts = dict()
                opts["options"] = ""
                response = datasets._copy(new_src, dest, None, **opts)
                #shutil.copy(new_src, dest)

[fernandofloresg]

I put on a fix in #1064 after finding this also happens when copying a directory into an existing directory tree. The fix is aimed to be back ported into v1.8.0 too.