udacity / sdc-issue-reports

29 stars 6 forks source link

Error: Process dies after a minute [styx_server-2] process has died ; signal_shutdown [atexit]; socket.timeout: timed out #1452

Closed testo301 closed 5 years ago

testo301 commented 5 years ago

Hi, I'm facing the following communication problem between Ubuntu (Win10 embedded WSL) and the Simulator for Capstone Project. The communication stops between the simulator and ubuntu after c.a. 1 minute of car driving itself.

Workspace and VM/VirtualBox are unusable for me (extremely low performance resulting in car being volatile, tested on two machines). WSL Ubuntu ROS + Win10 Simulator is the only viable option.

There was one thread on it present, however the response pertains to the VM instance ports (https://knowledge.udacity.com/questions/12389)

Error message and the Full log:

127.0.0.1 - - [03/Apr/2019 12:48:13] "GET /socket.io/?EIO=4&transport=websocket HTTP/1.1" 200 0 60.279210

(5309) wsgi exited, is_accepting=True

Traceback (most recent call last):

File "/home/ubuntu/Project2/CarND-Capstone/ros/src/styx/server.py", line 68, in

eventlet.wsgi.server(eventlet.listen(('', 4567)), app)

File "/home/ubuntu/.local/lib/python2.7/site-packages/eventlet/wsgi.py", line 954, in server

client_socket, client_addr = sock.accept()

File "/home/ubuntu/.local/lib/python2.7/site-packages/eventlet/greenio/base.py", line 228, in accept

self._trampoline(fd, read=True, timeout=self.gettimeout(), timeout_exc=_timeout_exc)

File "/home/ubuntu/.local/lib/python2.7/site-packages/eventlet/greenio/base.py", line 208, in _trampoline

mark_as_closed=self._mark_as_closed)

File "/home/ubuntu/.local/lib/python2.7/site-packages/eventlet/hubs/init.py", line 164, in trampoline

return hub.switch()

File "/home/ubuntu/.local/lib/python2.7/site-packages/eventlet/hubs/hub.py", line 297, in switch

return self.greenlet.switch()

socket.timeout: timed out

Exception in thread Thread-3:

Traceback (most recent call last):

File "/usr/lib/python2.7/threading.py", line 801, in __bootstrap_inner

self.run()

File "/usr/lib/python2.7/threading.py", line 754, in run

self.target(*self.args, **self.__kwargs)

File "/opt/ros/melodic/lib/python2.7/dist-packages/rospy/impl/tcpros_base.py", line 154, in run

(client_sock, client_addr) = self.server_sock.accept()

File "/home/ubuntu/.local/lib/python2.7/site-packages/eventlet/greenio/base.py", line 222, in accept

res = socket_accept(fd)

File "/home/ubuntu/.local/lib/python2.7/site-packages/eventlet/greenio/base.py", line 61, in socket_accept

return descriptor.accept()

File "/usr/lib/python2.7/socket.py", line 206, in accept

sock, addr = self._sock.accept()

File "/usr/lib/python2.7/socket.py", line 174, in _dummy

raise error(EBADF, 'Bad file descriptor')

error: [Errno 9] Bad file descriptor

[styx_server-2] process has died [pid 5309, exit code 1, cmd /home/ubuntu/Project2/CarND-Capstone/ros/src/styx/server.py __name:=styx_server __log:=/home/ubuntu/.ros/log/cf567134-55fd-11e9-99eb-e4e7491b8d72/styx_server-2.log].

log file: /home/ubuntu/.ros/log/cf567134-55fd-11e9-99eb-e4e7491b8d72/styx_server-2*.log

FULL LOG:

[rospy.client][INFO] 2019-04-02 10:35:25,413: init_node, name[/styx_server], pid[3861]

[xmlrpc][INFO] 2019-04-02 10:35:25,417: XML-RPC server binding to 0.0.0.0:0

[xmlrpc][INFO] 2019-04-02 10:35:25,420: Started XML-RPC server [http://ANONYMIZED:53717/]

[rospy.init][INFO] 2019-04-02 10:35:25,421: ROS Slave URI: [http://ANONYMIZED:53717/]

[rospy.impl.masterslave][INFO] 2019-04-02 10:35:25,421: _ready: http://ANONYMIZED:53717/

[xmlrpc][INFO] 2019-04-02 10:35:25,423: xml rpc node: starting XML-RPC server

[rospy.registration][INFO] 2019-04-02 10:35:25,424: Registering with master node http://localhost:11311

[rospy.init][INFO] 2019-04-02 10:35:25,522: registered with master

[rospy.rosout][INFO] 2019-04-02 10:35:25,523: initializing /rosout core topic

[rospy.rosout][INFO] 2019-04-02 10:35:25,529: connected to core topic /rosout

[rospy.simtime][INFO] 2019-04-02 10:35:25,533: /use_sim_time is not set, will not subscribe to simulated time [/clock] topic

[rospy.internal][INFO] 2019-04-02 10:35:25,612: topic[/vehicle/brake_cmd] adding connection to [http://ANONYMIZED:53665/], count 0

[rospy.internal][INFO] 2019-04-02 10:35:25,621: topic[/final_waypoints] adding connection to [http://ANONYMIZED:53684/], count 0

[rospy.internal][INFO] 2019-04-02 10:35:25,631: topic[/vehicle/throttle_cmd] adding connection to [http://ANONYMIZED:53665/], count 0

[rospy.internal][INFO] 2019-04-02 10:35:25,647: topic[/vehicle/steering_cmd] adding connection to [http://ANONYMIZED:53665/], count 0

[rospy.internal][INFO] 2019-04-02 10:35:25,682: topic[/current_pose] adding connection to [/waypoint_updater], count 0

[rospy.internal][INFO] 2019-04-02 10:35:25,727: topic[/vehicle/dbw_enabled] adding connection to [/dbw_node], count 0

[rospy.internal][INFO] 2019-04-02 10:35:25,731: topic[/current_velocity] adding connection to [/dbw_node], count 0

[rospy.internal][INFO] 2019-04-02 10:35:25,747: topic[/rosout] adding connection to [/rosout], count 0

[rospy.internal][INFO] 2019-04-02 10:35:25,865: topic[/current_pose] adding connection to [/pure_pursuit], count 1

[rospy.internal][INFO] 2019-04-02 10:35:25,868: topic[/current_velocity] adding connection to [/pure_pursuit], count 1

[rospy.internal][INFO] 2019-04-02 10:35:27,511: topic[/image_color] adding connection to [/tl_detector], count 0

[rospy.internal][INFO] 2019-04-02 10:35:27,512: topic[/vehicle/traffic_lights] adding connection to [/tl_detector], count 0

[rospy.internal][INFO] 2019-04-02 10:35:27,514: topic[/current_pose] adding connection to [/tl_detector], count 2

[rospy.internal][INFO] 2019-04-02 10:35:29,591: topic[/tf] adding connection to [/tl_detector], count 0

[rospy.core][INFO] 2019-04-02 10:36:25,773: signal_shutdown [atexit]

[rospy.internal][INFO] 2019-04-02 10:36:25,788: topic[/vehicle/dbw_enabled] removing connection to /dbw_node

[rospy.internal][INFO] 2019-04-02 10:36:25,789: topic[/rosout] removing connection to /rosout

[rospy.internal][INFO] 2019-04-02 10:36:25,789: topic[/current_velocity] removing connection to /dbw_node

[rospy.internal][INFO] 2019-04-02 10:36:25,790: topic[/current_velocity] removing connection to /pure_pursuit

[rospy.internal][INFO] 2019-04-02 10:36:25,790: topic[/tf] removing connection to /tl_detector

[rospy.internal][INFO] 2019-04-02 10:36:25,791: topic[/vehicle/traffic_lights] removing connection to /tl_detector

[rospy.internal][INFO] 2019-04-02 10:36:25,792: topic[/current_pose] removing connection to /waypoint_updater

[rospy.internal][INFO] 2019-04-02 10:36:25,793: topic[/current_pose] removing connection to /pure_pursuit

[rospy.internal][INFO] 2019-04-02 10:36:25,793: topic[/current_pose] removing connection to /tl_detector

[rospy.internal][INFO] 2019-04-02 10:36:25,794: topic[/image_color] removing connection to /tl_detector

[rospy.internal][INFO] 2019-04-02 10:36:25,795: topic[/vehicle/throttle_cmd] removing connection to http://ANONYMIZED:53665/

[rospy.internal][INFO] 2019-04-02 10:36:25,797: topic[/final_waypoints] removing connection to http://ANONYMIZED:53684/

[rospy.internal][INFO] 2019-04-02 10:36:25,798: topic[/vehicle/steering_cmd] removing connection to http://ANONYMIZED:53665/

[rospy.internal][INFO] 2019-04-02 10:36:25,799: topic[/vehicle/brake_cmd] removing connection to http://ANONYMIZED:53665/

[rospy.impl.masterslave][INFO] 2019-04-02 10:36:25,800: atexit

[rospy.internal][WARNING] 2019-04-02 10:36:25,802: Unknown error initiating TCP/IP socket to ANONYMIZED:53668 (http://ANONYMIZED:53665/): Traceback (most recent call last):

File "/opt/ros/melodic/lib/python2.7/dist-packages/rospy/impl/tcpros_base.py", line 556, in connect

self.socket.connect((dest_addr, dest_port))

File "/home/ubuntu/.local/lib/python2.7/site-packages/eventlet/greenio/base.py", line 261, in connect

self._trampoline(fd, write=True, timeout=timeout, timeout_exc=_timeout_exc)

File "/home/ubuntu/.local/lib/python2.7/site-packages/eventlet/greenio/base.py", line 208, in _trampoline

mark_as_closed=self._mark_as_closed)

File "/home/ubuntu/.local/lib/python2.7/site-packages/eventlet/hubs/init.py", line 150, in trampoline

fileno = fd.fileno()

File "/usr/lib/python2.7/socket.py", line 228, in meth

return getattr(self._sock,name)(*args)

File "/usr/lib/python2.7/socket.py", line 174, in _dummy

raise error(EBADF, 'Bad file descriptor')

error: [Errno 9] Bad file descriptor

mvirgo commented 5 years ago

Hi there! We are in the process of closing this Waffle board out, fyi. You should utilize Knowledge for debugging-type questions.

There's a couple first steps that might help with this issue.

1) Check whether there is a firewall or similar on your Ubuntu set-up; it may need port forwarding set up on it as well (somewhat similar to the Knowledge post).

2) If you haven't done so already, make sure to run pip install -r requirements.txt with the project files.

testo301 commented 5 years ago

Thank you, yes I checked the firewall and reinstalled all packages but the issue is still there. I also posted the same problem on the Knowledge: https://knowledge.udacity.com/questions/37234

mvirgo commented 5 years ago

Hi there! With Waffle closing its doors next month, and the ability to leave more detailed feedback on each classroom page (see “Send Feedback” in the upper right if you are enrolled in the program), we are migrating away from our Waffle board. All issues and conversations here will be migrated onto our internal platforms.

Over the next week, I am leaving these notes in case anyone has further follow-ups they want to get in before the board closes, as well as migrating over the tickets. As of 4/19, I will close all the remaining open tickets, and archive the related Github repository.