Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Bizarre log and restarting behaviour #32

Open
pmirallesr opened this issue May 15, 2020 · 6 comments
Open

Bizarre log and restarting behaviour #32

pmirallesr opened this issue May 15, 2020 · 6 comments

Comments

@pmirallesr
Copy link

pmirallesr commented May 15, 2020

So as noted in another issue, my LEDs flicker ocassionally. On top of that I cannot initiate remote control of the duckie due to the script being unable to connect to the ROS Master at 11311, an error that is repeated in the docker logs of some of the containers running in my duckie (car-interface).

Upon checking the logs of duckiebot-interface, I've come to believe that it's it responsibility to start said ros Master node. On top of that, the container restarts periodically, albeit with error code 0 so presumedly without faulty behaviour. However the logs reveal at least 2 problems ocurring:

This seems to be the cause of the container restarting:

================================================================================REQUIRED process [mobyduck/camera_node-2] has died!
process has died [pid 98, exit code 1, cmd /code/catkin_ws/src/dt-duckiebot-interface/packages/camera_driver/src/camera_node.py __name:=camera_node __log:=/root/.ros/log/40cd37d0-96c6-11ea-97e7-b827ebc67da2/mobyduck-camera_node-2.log].
log file: /root/.ros/log/40cd37d0-96c6-11ea-97e7-b827ebc67da2/mobyduck-camera_node-2*.log
Initiating shutdown!
================================================================================

This is another red message that occurs repeatedly

[ERROR] [1589558887.278684679]: Couldn't open joystick /dev/input/js0. Will retry every second.

Here is the full message that keeps on being repeated inside the docker log on every restart:

[INFO] [1589558877.617834]: [/mobyduck/led_emitter_node] Initializing...
[INFO] [1589558877.689427]: [/mobyduck/led_emitter_node] Setting parameter ~LED_scale = 0.8 
[INFO] [1589558877.697534]: [/mobyduck/led_emitter_node] Setting parameter ~channel_order = {'duckiebot': 'RGB', 'traffic_light': 'GRB'} 
[INFO] [1589558877.719048]: [/mobyduck/led_emitter_node] Setting parameter ~LED_protocol = {'signals': {'BLUE': {'color_list': 'blue', 'frequency_mask': [], 'frequency': 0, 'color_mask': []}, 'LIGHT_OFF': {'color_list': 'switchedoff', 'frequency_mask': [], 'frequency': 0, 'color_mask': []}, 'CAR_DRIVING': {'color_list': ['white', 'red', 'white', 'red', 'white'], 'frequency_mask': [], 'frequency': 0, 'color_mask': []}, 'CAR_SIGNAL_PRIORITY': {'color_list': ['purple', 'red', 'purple', 'red', 'purple'], 'frequency': 5.7, 'color_mask': [], 'frequency_mask': [1, 0, 1, 0, 1]}, 'CAR_SIGNAL_A': {'color_mask': [], 'frequency': 4, 'color_list': ['white', 'red', 'white', 'red', 'white'], 'frequency_mask': [1, 0, 1, 0, 1]}, 'CAR_SIGNAL_SACRIFICE_FOR_PRIORITY': {'color_mask': [], 'frequency': 1.9, 'color_list': ['white', 'red', 'white', 'red', 'white'], 'frequency_mask': [1, 0, 1, 0, 1]}, 'GREEN': {'color_mask': [], 'frequency_mask': [], 'frequency': 0, 'color_list': 'green'}, 'CAR_SIGNAL_GREEN': {'color_mask': [], 'frequency_mask': [1, 1, 1, 1, 1], 'frequency': 5.7, 'color_list': 'green'}, 'WHITE': {'color_mask': [], 'frequency_mask': [], 'frequency': 0, 'color_list': 'white'}, 'light_off': {'color_list': 'switchedoff', 'frequency': 0, 'color_mask': [], 'frequency_mask': []}, 'RED': {'color_mask': [], 'frequency_mask': [], 'frequency': 0, 'color_list': 'red'}}, 'frequencies': {'f1': 1.9, 'f2': 4, 'f3': 5.7, 'f4': 7.8, 'f5': 10.6}, 'colors': {'pink': [1, 0, 0.5], 'blue': [0, 0, 1], 'purple': [1, 0, 1], 'switchedoff': [0, 0, 0], 'yellow': [1, 1, 0], 'green': [0, 1, 0], 'cyan': [0, 1, 1], 'white': [1, 1, 1], 'red': [1, 0, 0]}} 
[INFO] [1589558877.812493]: [/mobyduck/led_emitter_node] Colors remapped to RGB
[INFO] [1589558877.838329]: [/mobyduck/led_emitter_node] Pattern changed to ('WHITE'), cycle: 0 
[INFO] [1589558877.839479]: [/mobyduck/led_emitter_node] Initialized.
[INFO] [1589558877.991905]: [/mobyduck/led_emitter_node] Pattern changed to ('LIGHT_OFF'), cycle: 0 
[INFO] [1589558877.993787]: [/mobyduck/led_emitter_node] Shutdown.
[]
 * /mobyduck/led_emitter_node/LED_protocol/signals/LIGHT_OFF/color_list: switchedoff
 * /mobyduck/led_emitter_node/LED_protocol/signals/LIGHT_OFF/color_mask: []
 * /mobyduck/led_emitter_node/LED_protocol/signals/LIGHT_OFF/frequency: 0
 * /mobyduck/led_emitter_node/LED_protocol/signals/LIGHT_OFF/frequency_mask: []
 * /mobyduck/led_emitter_node/LED_protocol/signals/RED/color_list: red
 * /mobyduck/led_emitter_node/LED_protocol/signals/RED/color_mask: []
 * /mobyduck/led_emitter_node/LED_protocol/signals/RED/frequency: 0
 * /mobyduck/led_emitter_node/LED_protocol/signals/RED/frequency_mask: []
 * /mobyduck/led_emitter_node/LED_protocol/signals/WHITE/color_list: white
 * /mobyduck/led_emitter_node/LED_protocol/signals/WHITE/color_mask: []
 * /mobyduck/led_emitter_node/LED_protocol/signals/WHITE/frequency: 0
 * /mobyduck/led_emitter_node/LED_protocol/signals/WHITE/frequency_mask: []
 * /mobyduck/led_emitter_node/LED_protocol/signals/light_off/color_list: switchedoff
 * /mobyduck/led_emitter_node/LED_protocol/signals/light_off/color_mask: []
 * /mobyduck/led_emitter_node/LED_protocol/signals/light_off/frequency: 0
 * /mobyduck/led_emitter_node/LED_protocol/signals/light_off/frequency_mask: []
 * /mobyduck/led_emitter_node/LED_scale: 0.8
 * /mobyduck/led_emitter_node/channel_order/duckiebot: RGB
 * /mobyduck/led_emitter_node/channel_order/traffic_light: GRB
 * /mobyduck/led_emitter_node/robot_type: duckiebot
 * /rosdistro: kinetic
 * /rosversion: 1.12.14

NODES
  /mobyduck/
    camera_node (camera_driver/camera_node.py)
    joy_node (joy/joy_node)
    led_emitter_node (led_emitter/led_emitter_node.py)
    wheels_driver_node (wheels_driver/wheels_driver_node.py)

auto-starting new master
process[master]: started with pid [68]
ROS_MASTER_URI=http://mobyduck.local:11311/

setting /run_id to 3ab6a764-96c6-11ea-b997-b827ebc67da2
process[rosout-1]: started with pid [81]
started core service [/rosout]
process[mobyduck/camera_node-2]: started with pid [98]
process[mobyduck/led_emitter_node-3]: started with pid [99]
process[mobyduck/joy_node-4]: started with pid [100]
process[mobyduck/wheels_driver_node-5]: started with pid [103]
[mobyduck/wheels_driver_node-5] killing on exit
[mobyduck/led_emitter_node-3] killing on exit
[mobyduck/joy_node-4] killing on exit
[mobyduck/camera_node-2] killing on exit
[rosout-1] killing on exit
[master] killing on exit
shutting down processing monitor...
... shutting down processing monitor complete
done
The environment variable VEHICLE_NAME is not set. Using 'mobyduck'.
... logging to /root/.ros/log/40cd37d0-96c6-11ea-97e7-b827ebc67da2/roslaunch-mobyduck-58.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://192.168.1.41:42347/

SUMMARY
========

PARAMETERS
 * /mobyduck/camera_node/exposure_mode: sports
 * /mobyduck/camera_node/framerate: 30
 * /mobyduck/camera_node/res_h: 480
 * /mobyduck/camera_node/res_w: 640
 * /mobyduck/joy_node/autorepeat_rate: 2.0
 * /mobyduck/joy_node/coalesce_interval: 0.02
 * /mobyduck/joy_node/deadzone: 0.01
 * /mobyduck/joy_node/dev: /dev/input/js0
 * /mobyduck/led_emitter_node/LED_protocol/colors/blue: [0, 0, 1]
 * /mobyduck/led_emitter_node/LED_protocol/colors/cyan: [0, 1, 1]
 * /mobyduck/led_emitter_node/LED_protocol/colors/green: [0, 1, 0]
 * /mobyduck/led_emitter_node/LED_protocol/colors/pink: [1, 0, 0.5]
 * /mobyduck/led_emitter_node/LED_protocol/colors/purple: [1, 0, 1]
 * /mobyduck/led_emitter_node/LED_protocol/colors/red: [1, 0, 0]
 * /mobyduck/led_emitter_node/LED_protocol/colors/switchedoff: [0, 0, 0]
 * /mobyduck/led_emitter_node/LED_protocol/colors/white: [1, 1, 1]
 * /mobyduck/led_emitter_node/LED_protocol/colors/yellow: [1, 1, 0]
 * /mobyduck/led_emitter_node/LED_protocol/frequencies/f1: 1.9
 * /mobyduck/led_emitter_node/LED_protocol/frequencies/f2: 4
 * /mobyduck/led_emitter_node/LED_protocol/frequencies/f3: 5.7
 * /mobyduck/led_emitter_node/LED_protocol/frequencies/f4: 7.8
 * /mobyduck/led_emitter_node/LED_protocol/frequencies/f5: 10.6
 * /mobyduck/led_emitter_node/LED_protocol/signals/BLUE/color_list: blue
 * /mobyduck/led_emitter_node/LED_protocol/signals/BLUE/color_mask: []
 * /mobyduck/led_emitter_node/LED_protocol/signals/BLUE/frequency: 0
 * /mobyduck/led_emitter_node/LED_protocol/signals/BLUE/frequency_mask: []
 * /mobyduck/led_emitter_node/LED_protocol/signals/CAR_DRIVING/color_list: ['white', 'red', ...
 * /mobyduck/led_emitter_node/LED_protocol/signals/CAR_DRIVING/color_mask: []
 * /mobyduck/led_emitter_node/LED_protocol/signals/CAR_DRIVING/frequency: 0
 * /mobyduck/led_emitter_node/LED_protocol/signals/CAR_DRIVING/frequency_mask: []
 * /mobyduck/led_emitter_node/LED_protocol/signals/CAR_SIGNAL_A/color_list: ['white', 'red', ...
 * /mobyduck/led_emitter_node/LED_protocol/signals/CAR_SIGNAL_A/color_mask: []
 * /mobyduck/led_emitter_node/LED_protocol/signals/CAR_SIGNAL_A/frequency: 4
 * /mobyduck/led_emitter_node/LED_protocol/signals/CAR_SIGNAL_A/frequency_mask: [1, 0, 1, 0, 1]
 * /mobyduck/led_emitter_node/LED_protocol/signals/CAR_SIGNAL_GREEN/color_list: green
 * /mobyduck/led_emitter_node/LED_protocol/signals/CAR_SIGNAL_GREEN/color_mask: []
 * /mobyduck/led_emitter_node/LED_protocol/signals/CAR_SIGNAL_GREEN/frequency: 5.7
 * /mobyduck/led_emitter_node/LED_protocol/signals/CAR_SIGNAL_GREEN/frequency_mask: [1, 1, 1, 1, 1]
 * /mobyduck/led_emitter_node/LED_protocol/signals/CAR_SIGNAL_PRIORITY/color_list: ['purple', 'red',...
 * /mobyduck/led_emitter_node/LED_protocol/signals/CAR_SIGNAL_PRIORITY/color_mask: []
 * /mobyduck/led_emitter_node/LED_protocol/signals/CAR_SIGNAL_PRIORITY/frequency: 5.7
 * /mobyduck/led_emitter_node/LED_protocol/signals/CAR_SIGNAL_PRIORITY/frequency_mask: [1, 0, 1, 0, 1]
 * /mobyduck/led_emitter_node/LED_protocol/signals/CAR_SIGNAL_SACRIFICE_FOR_PRIORITY/color_list: ['white', 'red', ...
 * /mobyduck/led_emitter_node/LED_protocol/signals/CAR_SIGNAL_SACRIFICE_FOR_PRIORITY/color_mask: []
 * /mobyduck/led_emitter_node/LED_protocol/signals/CAR_SIGNAL_SACRIFICE_FOR_PRIORITY/frequency: 1.9
 * /mobyduck/led_emitter_node/LED_protocol/signals/CAR_SIGNAL_SACRIFICE_FOR_PRIORITY/frequency_mask: [1, 0, 1, 0, 1]
 * /mobyduck/led_emitter_node/LED_protocol/signals/GREEN/color_list: green
 * /mobyduck/led_emitter_node/LED_protocol/signals/GREEN/color_mask: []
 * /mobyduck/led_emitter_node/LED_protocol/signals/GREEN/frequency: 0
[ERROR] [1589558887.278684679]: Couldn't open joystick /dev/input/js0. Will retry every second.
mmal: mmal_vc_component_create: failed to create component 'vc.ril.camera' (1:ENOMEM)
mmal: mmal_component_create_core: could not create component 'vc.ril.camera' (1)
 * /mobyduck/led_emitter_node/LED_protocol/signals/GREEN/frequency_mask: [INFO] [1589558887.617997]: [/mobyduck/camera_node] Initializing...
[INFO] [1589558887.637193]: [/mobyduck/camera_node] Setting parameter ~res_w = 640 
[INFO] [1589558887.644440]: [/mobyduck/camera_node] Setting parameter ~framerate = 30 
[INFO] [1589558887.650954]: [/mobyduck/camera_node] Setting parameter ~exposure_mode = sports 
[INFO] [1589558887.657261]: [/mobyduck/camera_node] Setting parameter ~res_h = 480 
Traceback (most recent call last):
  File "/code/catkin_ws/src/dt-duckiebot-interface/packages/camera_driver/src/camera_node.py", line 291, in <module>
    camera_node = CameraNode(node_name='camera')
  File "/code/catkin_ws/src/dt-duckiebot-interface/packages/camera_driver/src/camera_node.py", line 66, in __init__
    self.camera = PiCamera()
  File "/usr/local/lib/python2.7/dist-packages/picamera/camera.py", line 431, in __init__
    self._init_camera(camera_num, stereo_mode, stereo_decimate)
  File "/usr/local/lib/python2.7/dist-packages/picamera/camera.py", line 460, in _init_camera
    "Camera is not enabled. Try running 'sudo raspi-config' "
picamera.exc.PiCameraError: Camera is not enabled. Try running 'sudo raspi-config' and ensure that the camera has been enabled.
[INFO] [1589558887.718014]: [/mobyduck/camera_node] Shutdown.
================================================================================REQUIRED process [mobyduck/camera_node-2] has died!
process has died [pid 98, exit code 1, cmd /code/catkin_ws/src/dt-duckiebot-interface/packages/camera_driver/src/camera_node.py __name:=camera_node __log:=/root/.ros/log/40cd37d0-96c6-11ea-97e7-b827ebc67da2/mobyduck-camera_node-2.log].
log file: /root/.ros/log/40cd37d0-96c6-11ea-97e7-b827ebc67da2/mobyduck-camera_node-2*.log
Initiating shutdown!
================================================================================
Traceback (most recent call last):
  File "/code/catkin_ws/src/dt-duckiebot-interface/packages/wheels_driver/src/wheels_driver_node.py", line 4, in <module>
    from duckietown_msgs.msg import WheelsCmdStamped, BoolStamped
  File "/code/catkin_ws/devel/lib/python2.7/dist-packages/duckietown_msgs/msg/__init__.py", line 4, in <module>
    from ._AprilTagDetection import *
  File "/code/catkin_ws/devel/lib/python2.7/dist-packages/duckietown_msgs/msg/_AprilTagDetection.py", line 8, in <module>
    import geometry_msgs.msg
  File "/opt/ros/kinetic/lib/python2.7/dist-packages/geometry_msgs/msg/__init__.py", line 13, in <module>
    from ._Pose2D import *
  File "/opt/ros/kinetic/lib/python2.7/dist-packages/geometry_msgs/msg/_Pose2D.py", line 2, in <module>
    """autogenerated by genpy from geometry_msgs/Pose2D.msg. Do not edit."""
KeyboardInterrupt

NOTE: Since the error is ended by a "Keyboard Interrupt" (that is not me on my keyboard), the traceback error will vary depending on where on the code the program was when said interrupt was activated. The rest of the message will be identical between failures

@liampaull
Copy link
Member

this looks like it could be a hardware problem. To verify that the hardware works, 1) stop the duckiebot-interface 2) ssh into the robot 3) run sudo raspistill -o out.jpg
if you see a file out.jpg get created then the camera is functional

@pmirallesr
Copy link
Author

pmirallesr commented May 18, 2020

Thanks for your response. Like you suggested, the camera is not functional. Here's the output from the command you suggested I try

duckie@mobyduck:~$ sudo raspistill -o out.jpg
mmal: Cannot read camera info, keeping the defaults for OV5647
mmal: mmal_vc_component_create: failed to create component 'vc.ril.camera' (1:ENOMEM)
mmal: mmal_component_create_core: could not create component 'vc.ril.camera' (1)
mmal: Failed to create camera component
mmal: main: Failed to create camera component
mmal: Camera is not detected. Please check carefully the camera module is installed correctly

Should I disassemble my duckie and verify that everything is well connected together like the message says? Also, do you believe the camera not being detected is the source of the ROS master not being up then?

@pmirallesr
Copy link
Author

pmirallesr commented May 25, 2020

I have disassembled and reassembled the duckiebot. I found no problem in how the camera was connected. Reassembled the duckie with the propperly connected camera and repeated the procedure above, but sudo raspistill -o out.jpg still does not work. There is however a small red LED light on on the camera panel, so the connection is correct to some extent.

@liampaull
Copy link
Member

make sure that you are not already reading from the camera with one of the docker containers that is running. If something else is already reading from the camera you will also get this output. Safest is to stop all the running containers and then do the ssh/raspistill thing.

@pmirallesr
Copy link
Author

pmirallesr commented May 25, 2020

Ok I did and indeed raspistill works, gives a good photograph with no issues. But does that mean that some of the containers are trying to simultaneously use the camera?

Anytime that the container "duckiebot-interface" is up (no other container influences the camera), the camera will be inaccessible through raspistill since it's "in use" by duckiebot-interface. However the container will fail then restart, and examining its logs shows the cyclic error message I posted earlier.

Additionally near the end of the logs the cyclical message will change for a set amount of times: One of the two red error messages -this one- disappears. The rest of the cyclical log message remains the same:

mmal: mmal_vc_component_create: failed to create component 'vc.ril.camera' (1:ENOMEM)
mmal: mmal_component_create_core: could not create component 'vc.ril.camera' (1)
 * /mobyduck/led_emitter_node/LED_protocol/signals/GREEN/frequency_mask: [INFO] [1590396586.780740]: [/mobyduck/camera_node] Initializing...
[INFO] [1590396586.796725]: [/mobyduck/camera_node] Setting parameter ~res_w = 640 
[INFO] [1590396586.802423]: [/mobyduck/camera_node] Setting parameter ~framerate = 30 
[INFO] [1590396586.807599]: [/mobyduck/camera_node] Setting parameter ~exposure_mode = sports 
[INFO] [1590396586.813275]: [/mobyduck/camera_node] Setting parameter ~res_h = 480 
Traceback (most recent call last):
  File "/code/catkin_ws/src/dt-duckiebot-interface/packages/camera_driver/src/camera_node.py", line 291, in <module>
    camera_node = CameraNode(node_name='camera')
  File "/code/catkin_ws/src/dt-duckiebot-interface/packages/camera_driver/src/camera_node.py", line 66, in __init__
    self.camera = PiCamera()
  File "/usr/local/lib/python2.7/dist-packages/picamera/camera.py", line 431, in __init__
    self._init_camera(camera_num, stereo_mode, stereo_decimate)
  File "/usr/local/lib/python2.7/dist-packages/picamera/camera.py", line 460, in _init_camera
    "Camera is not enabled. Try running 'sudo raspi-config' "
picamera.exc.PiCameraError: Camera is not enabled. Try running 'sudo raspi-config' and ensure that the camera has been enabled.
[INFO] [1590396586.886210]: [/mobyduck/camera_node] Shutdown.
================================================================================REQUIRED process [mobyduck/camera_node-2] has died!
process has died [pid 98, exit code 1, cmd /code/catkin_ws/src/dt-duckiebot-interface/packages/camera_driver/src/camera_node.py __name:=camera_node __log:=/root/.ros/log/ac81b956-9e64-11ea-bb76-b827ebc67da2/mobyduck-camera_node-2.log].
log file: /root/.ros/log/ac81b956-9e64-11ea-bb76-b827ebc67da2/mobyduck-camera_node-2*.log
Initiating shutdown!
================================================================================
Traceback (most recent call last):
  File "/code/catkin_ws/src/dt-duckiebot-interface/packages/wheels_driver/src/wheels_driver_node.py", line 2, in <module>
    import rospy
  File "/opt/ros/kinetic/lib/python2.7/dist-packages/rospy/__init__.py", line 49, in <module>
    from .client import spin, myargv, init_node, \
  File "/opt/ros/kinetic/lib/python2.7/dist-packages/rospy/client.py", line 49, in <module>
    import rosgraph
  File "/opt/ros/kinetic/lib/python2.7/dist-packages/rosgraph/__init__.py", line 36, in <module>
    from . masterapi import Master, MasterFailure, MasterError, MasterException
  File "/opt/ros/kinetic/lib/python2.7/dist-packages/rosgraph/masterapi.py", line 41, in <module>
    from xmlrpc.client import ServerProxy  # Python 3.x
  File "/opt/ros/kinetic/lib/python2.7/dist-packages/rosgraph/xmlrpc.py", line 67, in <module>
    import rosgraph.network
  File "/opt/ros/kinetic/lib/python2.7/dist-packages/rosgraph/network.py", line 58, in <module>
    import urllib.parse as urlparse
  File "/usr/lib/python2.7/urllib.py", line 23, in <module>
    """
KeyboardInterrupt

@Pidongg
Copy link

Pidongg commented Jan 11, 2024

Hi, just wondering if you found a solution to your problem in the end? I am having a similar issue :)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants