juniper_junos_software module failure: No handlers could be found for logger "ncclient.transport.session"

[jindu-okoli]

Issue Type

• Bug Report

Module Name

Juniper.Junos role and Python libraries version

~/Desktop/junos_upgrade$ pip freeze
ansible==2.7.5
apache-libcloud==2.2.1
asn1crypto==0.24.0
bcrypt==3.1.5
beautifulsoup4==4.6.0
certifi==2018.11.29
cffi==1.11.5
chardet==3.0.4
cryptography==2.4.2
enum34==1.1.6
html5lib==0.999999999
httplib2==0.9.2
idna==2.8
ipaddress==1.0.22
Jinja2==2.10
jmespath==0.9.3
junos-eznc==2.2.0
jxmlease==1.0.1
keyring==10.6.0
keyrings.alt==3.0
lockfile==0.12.2
lxml==4.2.5
MarkupSafe==1.1.0
ncclient==0.6.3
netaddr==0.7.19
paramiko==2.4.2
pyasn1==0.4.4
pycparser==2.19
pycrypto==2.6.1
pygobject==3.26.1
pykerberos==1.1.14
PyNaCl==1.3.0
pyOpenSSL==17.5.0
pyserial==3.4
pyxdg==0.25
PyYAML==3.13
requests==2.21.0
scp==0.13.0
SecretStorage==2.3.1
selectors2==2.0.1
simplejson==3.13.2
six==1.12.0
urllib3==1.24.1
webencodings==0.5
xmltodict==0.11.0

Juniper.junos-2.1.0

OS / Environment

Junos version: 14X53-D47, 17.2R1, 17.3R3 Model: EX4300

Summary

I get this error when upgrading a Junos device. The device reboots and the software is installed on the device but the script fails with this error : No handlers could be found for logger "ncclient.transport.session" Also, nothing is written to the log file. I have tried specifying the full path, creating the file with right permissions but it is still empty.

Steps to reproduce

---
- name: Software update
  hosts: devices
  roles:
  - Juniper.junos
  connection: local
  gather_facts: no

  vars:
    wait_time: 900
    log_dir: "log"
    netconf_port: 830
  vars_files:
  - vault-vars.yml

  tasks:
  - name: Install Junos Software
    juniper_junos_software:
      provider: "{{lab_credentials}}"
      local_package: /var/tmp/jinstall-ex-4300-17.2R1.13-signed.tgz
      reboot_pause: 65
      logfile: "{{ log_dir }}/{{ inventory_hostname }}.log"

Expected results

The script  upgrades/downgrades the device without failing

Actual results

fatal: [poc-ex4300-13]: FAILED! => { "changed": false, "rc": 1 }

MSG:

MODULE FAILURE See stdout/stderr for the exact error

MODULE_STDERR:

No handlers could be found for logger "ncclient.transport.session" Traceback (most recent call last): File "/home/lab/.ansible/tmp/ansible-tmp-1546944251.76-50816382439807/AnsiballZ_juniper_junos_software.py", line 113, in _ansiballz_main() File "/home/lab/.ansible/tmp/ansible-tmp-1546944251.76-50816382439807/AnsiballZ_juniper_junos_software.py", line 105, in _ansiballz_main invoke_module(zipped_mod, temp_path, ANSIBALLZ_PARAMS) File "/home/lab/.ansible/tmp/ansible-tmp-1546944251.76-50816382439807/AnsiballZ_juniper_junos_software.py", line 48, in invoke_module imp.load_module('main', mod, module, MOD_DESC) File "/tmp/ansible_juniper_junos_software_payload_zOMHhH/main.py", line 747, in File "/tmp/ansible_juniper_junos_software_payload_zOMHhH/main.py", line 743, in main File "/tmp/ansible_juniper_junos_software_payload_zOMHhH/ansible_juniper_junos_software_payload.zip/ansible/module_utils/juniper_junos_common.py", line 792, in exit_json File "/tmp/ansible_juniper_junos_software_payload_zOMHhH/ansible_juniper_junos_software_payload.zip/ansible/module_utils/juniper_junos_common.py", line 1327, in close File "/home/lab/.local/lib/python2.7/site-packages/jnpr/junos/device.py", line 1328, in close self._conn.close_session() File "/home/lab/.local/lib/python2.7/site-packages/ncclient/manager.py", line 216, in execute raise_mode=self._raise_mode).request(*args, **kwds) File "/home/lab/.local/lib/python2.7/site-packages/ncclient/operations/session.py", line 28, in request return self._request(new_ele("close-session")) File "/home/lab/.local/lib/python2.7/site-packages/ncclient/operations/rpc.py", line 347, in _request raise TimeoutExpiredError('ncclient timed out while waiting for an rpc reply.') ncclient.operations.errors.TimeoutExpiredError: ncclient timed out while waiting for an rpc reply.

[tuhoanganh]

i'm facing the same problem when using juniper_junos_jsnapy. Python 2.7.5 jsnapy 1.3.2 ansible 2.7.9

std_err: fatal: [AGG01]: FAILED! => { "changed": false, "module_stderr": "No handlers could be found for logger "ncclient.transport.session"\n", "module_stdout": "Taking snapshot of COMMAND: show interface xe-* \nTaking snapshot of COMMAND: show interface ge-* \n**************************** Device: 10.96.10.13 **\nTests Included: check_MTU_xe \n Command: show interface xe- \nPASS | All "mtu" is equal to "1514" [ 4 matched ]\nTests Included: check_MTU_ge \n Command: show interface ge- **********************\n[ERROR] Cong ge-0/2/0 MTU khac 1514, MTU hien tai la 9014 \nFAIL | All "mtu" is not equal to "1514" [ 0 matched / 1 failed ]\n------------------------------- Final Result!! -------------------------------\ncheck_MTU_ge : Failed\ncheck_MTU_xe : Passed\nTotal No of tests passed: 1\nTotal No of tests failed: 1 \nOverall Tests failed!!! \n\n{"final_result": "Failed", "total_failed": 1, "changed": false, "total_passed": 1, "test_results": {"show interface xe-": [{"xpath": "//physical-interface[normalize-space(oper-status)= \"up\"]", "count": {"fail": 0, "pass": 4}, "testoperation": "is-equal", "passed": [{"pre": {"mtu": "1514"}, "post": {"name": "xe-4/0/0", "mtu": "1514"}, "message": "[PASS] Cong xe-4/0/0 MTU la 1514 ", "actual_node_value": "1514", "id": {"name": "xe-4/0/0"}}, {"pre": {"mtu": "1514"}, "post": {"name": "xe-4/0/1", "mtu": "1514"}, "message": "[PASS] Cong xe-4/0/1 MTU la 1514 ", "actual_node_value": "1514", "id": {"name": "xe-4/0/1"}}, {"pre": {"mtu": "1514"}, "post": {"name": "xe-4/0/2", "mtu": "1514"}, "message": "[PASS] Cong xe-4/0/2 MTU la 1514 ", "actual_node_value": "1514", "id": {"name": "xe-4/0/2"}}, {"pre": {"mtu": "1514"}, "post": {"name": "xe-4/0/3", "mtu": "1514"}, "message": "[PASS] Cong xe-4/0/3 MTU la 1514 ", "actual_node_value": "1514", "id": {"name": "xe-4/0/3"}}], "node_name": "mtu", "failed": [], "result": true, "expected_node_value": "1514", "test_name": "check_MTU_xe"}], "show interface ge-": [{"xpath": "//physical-interface[normalize-space(oper-status)= \"up\"]", "count": {"fail": 1, "pass": 0}, "testoperation": "is-equal", "passed": [], "node_name": "mtu", "failed": [{"pre": {"mtu": "9014"}, "post": {"name": "ge-0/2/0", "mtu": "9014"}, "message": "[ERROR] Cong ge-0/2/0 MTU khac 1514, MTU hien tai la 9014 ", "actual_node_value": "9014", "id": {"name": "ge-0/2/0"}}], "result": false, "expected_node_value": "1514", "test_name": "check_MTU_ge"}]}, "failed": false, "total_tests": 2, "device": "10.96.10.13", "action": "snapcheck", "router": "10.96.10.13", "invocation": {"module_args": {"baud": null, "attempts": null, "ssh_private_key_file": null, "config_file": null, "level": null, "passwd": "VALUE_SPECIFIED_IN_NO_LOG_PARAMETER", "logdir": null, "ssh_config": null, "host": "10.96.10.13", "dir": "/etc/jsnapy/testfiles", "user": "juniper", "timeout": 30, "action": "snapcheck", "console": null, "logfile": null, "port": 830, "test_files": ["/home/juniper/METRO_HNI_JSNAPY/MBF_jsnapy.yml"], "mode": null}}, "pass_percentage": 50, "passPercentage": 50, "msg": "Test Failed: Passed 1, Failed 1"}\n", "msg": "MODULE FAILURE\nSee stdout/stderr for the exact error", "rc": 0 }