How to debug

Switch debug log on

Configuration file for frontend, brain and probe is located by default in the config folder and is named respectively frontend.ini, brain.ini and probe.ini.

To turn on debug log just add the following line:

     [log]
     syslog = 0
     debug = 1

and restart all related applications.

To turn on SQL debug log (warning: its verbose) just add the following line:

     [log]
     syslog = 0
     debug = 1
     sql_debug = 1

and restart all related applications.

Debug a probe

Open a session on the probe machine and change directory to the irma-probe location. Try the run_module tool on a file to see what analyzer is detected and what is its output on a file.

     $ sudo su deploy
     $ cd /opt/irma/irma-probe/current
     $ ./venv/bin/python -m tools.run_module

     [...]
     usage: run_module.py [-h] [-v]
                  {Unarchive,StaticAnalyzer,ClamAV,VirusTotal} filename
                  [filename ...]
     run_module.py: error: too few arguments

Here 4 probes are automatically detected. Now try one on a file:

$ ./venv/bin/python -m tools.run_module ClamAV requirements.txt
{'database': {'/var/lib/clamav/bytecode.cvd': {'ctime': 1458640823.285298,
                                       'mtime': 1458640823.069295,
                                       'sha256': '82972e6cc5f1204829dba913cb1a0b5f8152eb73d3407f6b86cf388626cff1a1'},
      '/var/lib/clamav/daily.cvd': {'ctime': 1458640822.8932924,
                                    'mtime': 1458640822.6692889,
                                    'sha256': '9804c9b9aaf983f85b4f13a7053f98eb7cca5a5a88d3897d49b22182b228885f'},
      '/var/lib/clamav/main.cvd': {'ctime': 1458640821.6972747,
                                   'mtime': 1458640813.9771628,
                                   'sha256': '4a8dfbc4c44704186ad29b5a3f8bdb6674b679cecdf83b156dd1c650129b56f2'}},
 'duration': 0.0045299530029296875,
 'error': None,
 'name': 'Clam AntiVirus Scanner',
 'platform': 'linux2',
 'results': None,
 'status': 0,
 'type': 'antivirus',
 'version': '0.99'}

And check the output.

Debug Ansible Provisioning

To debug errors while provisioning (same goes with deployment) with following typical command:

$ ansible-playbook  --private-key=~/.vagrant.d/insecure_private_key --inventory-file=.vagrant/provisioners/ansible/inventory/vagrant_ansible_inventory -u vagrant playbooks/provisioning.yml

Example output:

TASK [Mayeu.RabbitMQ : add rabbitmq user and set privileges] *******************
[DEPRECATION WARNING]: Using bare variables is deprecated. Update your playbooks so that the environment value uses the
full variable syntax ('{{rabbitmq_users_definitions}}').
This feature will be removed in a future release. Deprecation
warnings can be disabled by setting deprecation_warnings=False in ansible.cfg.
failed: [brain.irma] (item={u'vhost': u'mqbrain', u'password': u'brain', u'user': u'brain'}) => {"failed": true, "item": {"password": "brain", "user": "brain", "vhost": "mqbrain"}, "module_stderr": "", "module_stdout": "Traceback (most recent call last):\r\n  File \"/tmp/ansible_wKXoO5/ansible_module_rabbitmq_user.py\", line 302, in <module>\r\n    main()\r\n  File \"/tmp/ansible_wKXoO5/ansible_module_rabbitmq_user.py\", line 274, in main\r\n    if rabbitmq_user.get():\r\n  File \"/tmp/ansible_wKXoO5/ansible_module_rabbitmq_user.py\", line 155, in get\r\n    users = self._exec(['list_users'], True)\r\n  File \"/tmp/ansible_wKXoO5/ansible_module_rabbitmq_user.py\", line 150, in _exec\r\n    rc, out, err = self.module.run_command(cmd + args, check_rc=True)\r\n  File \"/tmp/ansible_wKXoO5/ansible_modlib.zip/ansible/module_utils/basic.py\", line 1993, in run_command\r\n  File \"/usr/lib/python2.7/posixpath.py\", line 261, in expanduser\r\n    if not path.startswith('~'):\r\nAttributeError: 'list' object has no attribute 'startswith'\r\n", "msg": "MODULE FAILURE", "parsed": false}

You could first increase ansible verbosity by adding -vvv option (-vvvv on windows for winrm debug), it will help is the problem is linked to arguments.

     $ ansible-playbook -vvv --private-key=~/.vagrant.d/insecure_private_key --inventory-file=.vagrant/provisioners/ansible/inventory/vagrant_ansible_inventory -u vagrant playbooks/provisioning.yml
     TASK [Mayeu.RabbitMQ : add rabbitmq user and set privileges] *******************
     task path: /home/alex/repo/irma-ansible/roles/Mayeu.RabbitMQ/tasks/vhost.yml:13
     [DEPRECATION WARNING]: Using bare variables is deprecated. Update your playbooks so that the environment value uses the full
     variable syntax ('{{rabbitmq_users_definitions}}').
     This feature will be removed in a future release. Deprecation warnings can be
     disabled by setting deprecation_warnings=False in ansible.cfg.
     <127.0.0.1> ESTABLISH SSH CONNECTION FOR USER: vagrant
     <127.0.0.1> SSH: EXEC ssh -C -q -o ForwardAgent=yes -o Port=2222 -o 'IdentityFile="/home/alex/.vagrant.d/insecure_private_key"' -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o User=vagrant -o ConnectTimeout=10 127.0.0.1 '/bin/sh -c '"'"'( umask 77 && mkdir -p "` echo $HOME/.ansible/tmp/ansible-tmp-1468570550.09-211613386938202 `" && echo ansible-tmp-1468570550.09-211613386938202="` echo $HOME/.ansible/tmp/ansible-tmp-1468570550.09-211613386938202 `" ) && sleep 0'"'"''
     <127.0.0.1> PUT /tmp/tmpiysJ6l TO /home/vagrant/.ansible/tmp/ansible-tmp-1468570550.09-211613386938202/rabbitmq_user
     <127.0.0.1> SSH: EXEC sftp -b - -C -o ForwardAgent=yes -o Port=2222 -o 'IdentityFile="/home/alex/.vagrant.d/insecure_private_key"' -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o User=vagrant -o ConnectTimeout=10 '[127.0.0.1]'
     <127.0.0.1> ESTABLISH SSH CONNECTION FOR USER: vagrant
     <127.0.0.1> SSH: EXEC ssh -C -q -o ForwardAgent=yes -o Port=2222 -o 'IdentityFile="/home/alex/.vagrant.d/insecure_private_key"' -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o User=vagrant -o ConnectTimeout=10 -tt 127.0.0.1 '/bin/sh -c '"'"'sudo -H -S -n -u root /bin/sh -c '"'"'"'"'"'"'"'"'echo BECOME-SUCCESS-rbeeckncuxenewcwkayivqiwvarchlrd; LANG=fr_FR.UTF-8 LC_ALL=fr_FR.UTF-8 LC_MESSAGES=fr_FR.UTF-8 /usr/bin/python /home/vagrant/.ansible/tmp/ansible-tmp-1468570550.09-211613386938202/rabbitmq_user; rm -rf "/home/vagrant/.ansible/tmp/ansible-tmp-1468570550.09-211613386938202/" > /dev/null 2>&1'"'"'"'"'"'"'"'"' && sleep 0'"'"''
     failed: [brain.irma] (item={u'vhost': u'mqbrain', u'password': u'brain', u'user': u'brain'}) => {"failed": true, "invocation": {"module_name": "rabbitmq_user"}, "item": {"password": "brain", "user": "brain", "vhost": "mqbrain"}, "module_stderr": "", "module_stdout": "Traceback (most recent call last):\r\n  File \"/tmp/ansible_Qo3lZl/ansible_module_rabbitmq_user.py\", line 302, in <module>\r\n    main()\r\n  File \"/tmp/ansible_Qo3lZl/ansible_module_rabbitmq_user.py\", line 274, in main\r\n    if rabbitmq_user.get():\r\n  File \"/tmp/ansible_Qo3lZl/ansible_module_rabbitmq_user.py\", line 155, in get\r\n    users = self._exec(['list_users'], True)\r\n  File \"/tmp/ansible_Qo3lZl/ansible_module_rabbitmq_user.py\", line 150, in _exec\r\n    rc, out, err = self.module.run_command(cmd + args, check_rc=True)\r\n  File \"/tmp/ansible_Qo3lZl/ansible_modlib.zip/ansible/module_utils/basic.py\", line 1993, in run_command\r\n  File \"/usr/lib/python2.7/posixpath.py\", line 261, in expanduser\r\n    if not path.startswith('~'):\r\nAttributeError: 'list' object has no attribute 'startswith'\r\n", "msg": "MODULE FAILURE", "parsed": false}

In this particular case, verbose doesnt add much information as the problem is linked to ansible scripts. Lets go one level deeper so. Ansible output the temporary script executed on guest (highlighted in previous code block), but delete it just after execution. To further debug it we will set ansible to keep remote files and the debug session will now takes place inside the guest.

$ ANSIBLE_KEEP_REMOTE_FILES=1 ansible-playbook -vvv --private-key=~/.vagrant.d/insecure_private_key --inventory-file=.vagrant/provisioners/ansible/inventory/vagrant_ansible_inventory -u vagrant playbooks/provisioning.yml

in debug log get the temporary ansible path to remote script:

/usr/bin/python /home/vagrant/.ansible/tmp/ansible-tmp-1468571039.87-134696488633275/rabbitmq_user

Log in to remote machine and go to the temporary ansible dir. Explode the compressed script and run it locallly:

$ vagrant@brain:~/.ansible/tmp/ansible-tmp-1468571039.87-134696488633275$ ls
rabbitmq_user

$ vagrant@brain:~/.ansible/tmp/ansible-tmp-1468571039.87-134696488633275$ python rabbitmq_user explode
Module expanded into:
/home/vagrant/.ansible/tmp/ansible-tmp-1468571039.87-134696488633275/debug_dir

$ vagrant@brain:~/.ansible/tmp/ansible-tmp-1468571039.87-134696488633275$ ls debug_dir/
ansible
ansible_module_rabbitmq_user.py
args

$ vagrant@brain:~/.ansible/tmp/ansible-tmp-1468571039.87-134696488633275$ python rabbitmq_user execute
Traceback (most recent call last):
  File "/home/vagrant/.ansible/tmp/ansible-tmp-1468571039.87-134696488633275/debug_dir/ansible_module_rabbitmq_user.py", line 302, in <module>
    main()
  File "/home/vagrant/.ansible/tmp/ansible-tmp-1468571039.87-134696488633275/debug_dir/ansible_module_rabbitmq_user.py", line 274, in main
    if rabbitmq_user.get():
  File "/home/vagrant/.ansible/tmp/ansible-tmp-1468571039.87-134696488633275/debug_dir/ansible_module_rabbitmq_user.py", line 155, in get
    users = self._exec(['list_users'], True)
  File "/home/vagrant/.ansible/tmp/ansible-tmp-1468571039.87-134696488633275/debug_dir/ansible_module_rabbitmq_user.py", line 150, in _exec
    rc, out, err = self.module.run_command(cmd + args, check_rc=True)
  File "/home/vagrant/.ansible/tmp/ansible-tmp-1468571039.87-134696488633275/debug_dir/ansible/module_utils/basic.py", line 1993, in run_command
    args = [ os.path.expandvars(os.path.expanduser(x)) for x in args if x is not None ]
  File "/usr/lib/python2.7/posixpath.py", line 261, in expanduser
    if not path.startswith('~'):
AttributeError: 'list' object has no attribute 'startswith'

You could now add debug to source files and properly understand where the problem is. In our example case, it is an ansible problem related to module_rabbitmq_user present in 2.1.0.0 see github PR