search

aliasrobotics / aztarna

aztarna, a footprinting tool for robots.
https://aliasrobotics.com
GNU General Public License v3.0
89 stars 27 forks source link

Logging error with SROS #21

Closed vmayoral closed 5 years ago

vmayoral commented 5 years ago

Getting the following:

Connecting to 127.0.0.1:11311
[+] SROS host found!!!
--- Logging error ---
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/dist-packages/aztarna-1.0-py3.6.egg/aztarna/ros/sros/scanner.py", line 43, in scan_host
    master_address, port, master_cert = await get_sros_certificate(address, master_port, timeout)
  File "/usr/local/lib/python3.6/dist-packages/aztarna-1.0-py3.6.egg/aztarna/ros/sros/helpers.py", line 176, in get_sros_certificate
    await writer.wait_closed()
AttributeError: 'StreamWriter' object has no attribute 'wait_closed'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.6/logging/__init__.py", line 994, in emit
    msg = self.format(record)
  File "/usr/lib/python3.6/logging/__init__.py", line 840, in format
    return fmt.format(record)
  File "/usr/lib/python3.6/logging/__init__.py", line 577, in format
    record.message = record.getMessage()
  File "/usr/lib/python3.6/logging/__init__.py", line 338, in getMessage
    msg = msg % self.args
TypeError: not all arguments converted during string formatting
Call stack:
  File "/usr/local/bin/aztarna", line 9, in <module>
    load_entry_point('aztarna==1.0', 'console_scripts', 'aztarna')()
  File "/usr/local/lib/python3.6/dist-packages/aztarna-1.0-py3.6.egg/aztarna/cmd.py", line 65, in main
    scanner.scan()
  File "/usr/local/lib/python3.6/dist-packages/aztarna-1.0-py3.6.egg/aztarna/ros/sros/scanner.py", line 101, in scan
    asyncio.get_event_loop().run_until_complete(self.scan_network())
  File "/usr/local/lib/python3.6/dist-packages/aztarna-1.0-py3.6.egg/aztarna/ros/sros/scanner.py", line 71, in scan_host
    logger.exception('Exception at host scan', e)
Message: 'Exception at host scan'
Arguments: (AttributeError("'StreamWriter' object has no attribute 'wait_closed'",),)

Refer to https://github.com/vmayoral/basic_robot_cybersecurity/tree/master/robot_footprinting/tutorial2 to reproduce it. In a nutshell:

| victor:~/basic_robot_cybersecurity/robot_footprinting/tutorial2 (master)$ 
| => docker run --privileged -it basic_cybersecurity_footprinting2:latest
root@dbb103d7b6e0:~/sros_catkin_ws# 
root@dbb103d7b6e0:~/sros_catkin_ws# 
root@dbb103d7b6e0:~/sros_catkin_ws# ls
build  devel  install  logs  rospkg  src
root@dbb103d7b6e0:~/sros_catkin_ws# 
root@dbb103d7b6e0:~/sros_catkin_ws# sroskeyserver &
[1] 64
root@dbb103d7b6e0:~/sros_catkin_ws# Starting an XML-RPC server to bootstrap SSL key distribution...
Certificate generated: root
Certificate generated: master
sleeping until keyserver has generated the initial keyring...
Horray, the keyserver is now open for business.
sroscore &
[2] 70
root@dbb103d7b6e0:~/sros_catkin_ws# initializing node's keystore: /root/.ros/sros/keystore/nodes/roslaunch
Certificate generated: roslaunch
all startup certificates are present
... logging to /root/.ros/log/aa53e8e0-05d4-11e9-b4e2-0242ac110003/roslaunch-dbb103d7b6e0-70.log
Checking log directory for disk usage. This may take awhile.
Press Ctrl-C to interrupt
Done checking log file disk usage. Usage is <1GB.

started roslaunch server http://dbb103d7b6e0:39101/
ros_comm version 1.12.0

SUMMARY
========

PARAMETERS
 * /rosdistro: kinetic
 * /rosversion: 1.12.0

NODES

auto-starting new master
process[master]: started with pid [81]
initializing node's keystore: /root/.ros/sros/keystore/nodes/master
Certificate generated: master
all startup certificates are present
ROS_MASTER_URI=https://dbb103d7b6e0:11311/

setting /run_id to aa53e8e0-05d4-11e9-b4e2-0242ac110003
process[rosoutpy-1]: started with pid [95]
started core service [/rosoutpy]
initializing node's keystore: /root/.ros/sros/keystore/nodes/rosoutpy
Certificate generated: rosoutpy
all startup certificates are present
##################################################
policy:
 {
    "OID": "1.2.3.4.5.6.7.8.9.1", 
    "allow": {
        "OID": "1.2.3.4.5.6.7.8.9.1.1", 
        "policy_qualifiers": [
            "/rosout"
        ]
    }, 
    "deny": {
        "OID": "1.2.3.4.5.6.7.8.9.1.2"
    }, 
    "mask": "s"
}
Callback: accept_topic
 action: /rosout
 allowed: True
##################################################
##################################################
policy:
 {
    "OID": "1.2.3.4.5.6.7.8.9.2", 
    "allow": {
        "OID": "1.2.3.4.5.6.7.8.9.2.1", 
        "policy_qualifiers": [
            "/rosout", 
            "/rosout_agg"
        ]
    }, 
    "deny": {
        "OID": "1.2.3.4.5.6.7.8.9.2.2"
    }, 
    "mask": "p"
}
Callback: connect_topic
 action: /rosout
 allowed: True
##################################################

root@dbb103d7b6e0:~/sros_catkin_ws# 
root@dbb103d7b6e0:~/sros_catkin_ws# 
root@dbb103d7b6e0:~/sros_catkin_ws# 
root@dbb103d7b6e0:~/sros_catkin_ws# 
root@dbb103d7b6e0:~/sros_catkin_ws# 
root@dbb103d7b6e0:~/sros_catkin_ws# ./aztarna -t SROS -a 127.0.0.1
bash: ./aztarna: No such file or directory
root@dbb103d7b6e0:~/sros_catkin_ws# aztarna -t SROS -a 127.0.0.1
Connecting to 127.0.0.1:11311
[+] SROS host found!!!
--- Logging error ---
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/dist-packages/aztarna-1.0-py3.6.egg/aztarna/ros/sros/scanner.py", line 43, in scan_host
    master_address, port, master_cert = await get_sros_certificate(address, master_port, timeout)
  File "/usr/local/lib/python3.6/dist-packages/aztarna-1.0-py3.6.egg/aztarna/ros/sros/helpers.py", line 176, in get_sros_certificate
    await writer.wait_closed()
AttributeError: 'StreamWriter' object has no attribute 'wait_closed'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.6/logging/__init__.py", line 994, in emit
    msg = self.format(record)
  File "/usr/lib/python3.6/logging/__init__.py", line 840, in format
    return fmt.format(record)
  File "/usr/lib/python3.6/logging/__init__.py", line 577, in format
    record.message = record.getMessage()
  File "/usr/lib/python3.6/logging/__init__.py", line 338, in getMessage
    msg = msg % self.args
TypeError: not all arguments converted during string formatting
Call stack:
  File "/usr/local/bin/aztarna", line 9, in <module>
    load_entry_point('aztarna==1.0', 'console_scripts', 'aztarna')()
  File "/usr/local/lib/python3.6/dist-packages/aztarna-1.0-py3.6.egg/aztarna/cmd.py", line 65, in main
    scanner.scan()
  File "/usr/local/lib/python3.6/dist-packages/aztarna-1.0-py3.6.egg/aztarna/ros/sros/scanner.py", line 101, in scan
    asyncio.get_event_loop().run_until_complete(self.scan_network())
  File "/usr/local/lib/python3.6/dist-packages/aztarna-1.0-py3.6.egg/aztarna/ros/sros/scanner.py", line 71, in scan_host
    logger.exception('Exception at host scan', e)
Message: 'Exception at host scan'
Arguments: (AttributeError("'StreamWriter' object has no attribute 'wait_closed'",),)
vmayoral commented 5 years ago

@olaldiko did we fix this?

olaldiko commented 5 years ago

Yes, two different bugs were involved. One is that the failing function was introduced in Python3.7(added the requirement on the setup) and the other was regarding to passing the exception object to the logger, which is implicitly taken.