ros_comm icon indicating copy to clipboard operation
ros_comm copied to clipboard
verified publisher icon ros

AttributeError: 'NoneType' object has no attribute 'buff_size'

Open khssnv opened this issue 6 years ago • 4 comments

Summary

Exception occurs after rospy.wait_for_message() call returns value (invoked in HTTP request handler).

Setup information

ROS version: melodic OS version: Ubuntu 18.04 Python version: python3.6

More details

I make HTTP endpoint returns latest message from topic. There is a Publisher created with latch parameter set and subscriber use rospy.wait_for_message() to get message into HTTP endpoint handler. Please find an example below. As you may find in logs, wait_for_message returns message and HTTP endpoint handler returns it to client. But there are exceptions from tcpros_base occurs after wait_for_message call.

Minimal example

Web server "Alice"

Provides /bob/pub HTTP GET endpoint. Contains wait_for_message call. Provides exceptions mentioned.

alice.py 
#!/usr/bin/env python3
# -*- coding: utf-8 -*-

import uvicorn
from fastapi import FastAPI
from starlette.responses import Response

import rospy
from std_msgs.msg import String


app = FastAPI()


@app.get("/bob/pub")
def handler():
    msg = rospy.wait_for_message("/bob/pub", String, timeout=1)
    return msg.data


if __name__ == "__main__":
    rospy.init_node("alice", log_level=rospy.DEBUG)
    uvicorn.run("alice:app", host="localhost", port=8081, log_level="info")

Publisher "Bob"

bob.py 
#!/usr/bin/env python3
# -*- coding: utf-8 -*-

import rospy
from std_msgs.msg import String


rospy.init_node("bob", log_level=rospy.DEBUG)
pub = rospy.Publisher("~pub", String, queue_size=10, latch=True)
def make_pub(event):
    pub.publish(String(data="bob text"))
rospy.Timer(rospy.Duration(secs=1), make_pub)
rospy.spin()

Execution logs

You could find exceptions mentioned in alice.py logs. There are 10 calls executed. Some of them gives no exception. Others gave AttributeError for connect and buff_size attributes.

$ curl localhost:8081/bob/pub 
$ curl localhost:8081/bob/pub
"bob text"%
$ curl localhost:8081/bob/pub
"bob text"%
$ curl localhost:8081/bob/pub
"bob text"%
$ curl localhost:8081/bob/pub
"bob text"%
$ curl localhost:8081/bob/pub
"bob text"%
$ curl localhost:8081/bob/pub
"bob text"%
$ curl localhost:8081/bob/pub
"bob text"%
$ curl localhost:8081/bob/pub
"bob text"%
$ curl localhost:8081/bob/pub
"bob text"%
$ curl localhost:8081/bob/pub
"bob text"%
$ rosrun alice alice.py 
$ rosrun alice alice.py
[DEBUG] [1582726909.166670]: init_node, name[/alice], pid[32326]
[DEBUG] [1582726909.168813]: binding to 0.0.0.0 0
[DEBUG] [1582726909.170569]: bound to 0.0.0.0 42299
[DEBUG] [1582726909.173463]: ... service URL is rosrpc://32vd:42299
[DEBUG] [1582726909.175300]: [/alice/get_loggers]: new Service instance
[DEBUG] [1582726909.178389]: ... service URL is rosrpc://32vd:42299
[DEBUG] [1582726909.179877]: [/alice/set_logger_level]: new Service instance
INFO:     Started server process [32326]
INFO:     Uvicorn running on http://localhost:8081 (Press CTRL+C to quit)
INFO:     Waiting for application startup.
INFO:     Application startup complete.
INFO:     topic[/rosout] adding connection to [/rosout], count 0
INFO:     topic[/bob/pub] adding connection to [http://32vd:33177/], count 0
[DEBUG] [1582726915.901713]: connecting to 32vd 36993
DEBUG:    connecting to 32vd 36993
INFO:     topic impl's ref count is zero, deleting topic /bob/pub...
[DEBUG] [1582726915.908231]: connecting to 32vd 36993
INFO:     topic[/bob/pub] removing connection to http://32vd:33177/
DEBUG:    connecting to 32vd 36993
WARNING:  Unknown error initiating TCP/IP socket to 32vd:36993 (http://32vd:33177/): 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))
AttributeError: 'NoneType' object has no attribute 'connect'

INFO:     127.0.0.1:54030 - "GET /bob/pub HTTP/1.1" 200 OK
INFO:     topic[/bob/pub] adding connection to [http://32vd:33177/], count 0
[DEBUG] [1582726917.048918]: connecting to 32vd 36993
DEBUG:    connecting to 32vd 36993
INFO:     topic impl's ref count is zero, deleting topic /bob/pub...
INFO:     topic[/bob/pub] removing connection to http://32vd:33177/
[DEBUG] [1582726917.057222]: connecting to 32vd 36993
DEBUG:    connecting to 32vd 36993
INFO:     127.0.0.1:54042 - "GET /bob/pub HTTP/1.1" 200 OK
WARNING:  Unknown error initiating TCP/IP socket to 32vd:36993 (http://32vd:33177/): Traceback (most recent call last):
  File "/opt/ros/melodic/lib/python2.7/dist-packages/rospy/impl/tcpros_base.py", line 558, in connect
    self.read_header()
  File "/opt/ros/melodic/lib/python2.7/dist-packages/rospy/impl/tcpros_base.py", line 653, in read_header
    self._validate_header(read_ros_handshake_header(sock, self.read_buff, self.protocol.buff_size))
AttributeError: 'NoneType' object has no attribute 'buff_size'

INFO:     topic[/bob/pub] adding connection to [http://32vd:33177/], count 0
[DEBUG] [1582726918.122460]: connecting to 32vd 36993
DEBUG:    connecting to 32vd 36993
INFO:     topic impl's ref count is zero, deleting topic /bob/pub...
INFO:     topic[/bob/pub] removing connection to http://32vd:33177/
INFO:     127.0.0.1:54054 - "GET /bob/pub HTTP/1.1" 200 OK
INFO:     topic[/bob/pub] adding connection to [http://32vd:33177/], count 0
[DEBUG] [1582726919.147857]: connecting to 32vd 36993
DEBUG:    connecting to 32vd 36993
INFO:     topic impl's ref count is zero, deleting topic /bob/pub...
[DEBUG] [1582726919.155630]: connecting to 32vd 36993
INFO:     topic[/bob/pub] removing connection to http://32vd:33177/
DEBUG:    connecting to 32vd 36993
WARNING:  Unknown error initiating TCP/IP socket to 32vd:36993 (http://32vd:33177/): 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))
AttributeError: 'NoneType' object has no attribute 'connect'

INFO:     127.0.0.1:54064 - "GET /bob/pub HTTP/1.1" 200 OK
INFO:     topic[/bob/pub] adding connection to [http://32vd:33177/], count 0
[DEBUG] [1582726920.072314]: connecting to 32vd 36993
DEBUG:    connecting to 32vd 36993
INFO:     topic impl's ref count is zero, deleting topic /bob/pub...
INFO:     topic[/bob/pub] removing connection to http://32vd:33177/
[DEBUG] [1582726920.077787]: connecting to 32vd 36993
DEBUG:    connecting to 32vd 36993
WARNING:  Unknown error initiating TCP/IP socket to 32vd:36993 (http://32vd:33177/): Traceback (most recent call last):
  File "/opt/ros/melodic/lib/python2.7/dist-packages/rospy/impl/tcpros_base.py", line 558, in connect
    self.read_header()
  File "/opt/ros/melodic/lib/python2.7/dist-packages/rospy/impl/tcpros_base.py", line 653, in read_header
    self._validate_header(read_ros_handshake_header(sock, self.read_buff, self.protocol.buff_size))
AttributeError: 'NoneType' object has no attribute 'buff_size'

INFO:     127.0.0.1:54074 - "GET /bob/pub HTTP/1.1" 200 OK
INFO:     topic[/bob/pub] adding connection to [http://32vd:33177/], count 0
[DEBUG] [1582726920.945377]: connecting to 32vd 36993
DEBUG:    connecting to 32vd 36993
INFO:     topic impl's ref count is zero, deleting topic /bob/pub...
INFO:     topic[/bob/pub] removing connection to http://32vd:33177/
[DEBUG] [1582726920.954013]: connecting to 32vd 36993
DEBUG:    connecting to 32vd 36993
WARNING:  Unknown error initiating TCP/IP socket to 32vd:36993 (http://32vd:33177/): Traceback (most recent call last):
  File "/opt/ros/melodic/lib/python2.7/dist-packages/rospy/impl/tcpros_base.py", line 558, in connect
    self.read_header()
  File "/opt/ros/melodic/lib/python2.7/dist-packages/rospy/impl/tcpros_base.py", line 653, in read_header
    self._validate_header(read_ros_handshake_header(sock, self.read_buff, self.protocol.buff_size))
AttributeError: 'NoneType' object has no attribute 'buff_size'

INFO:     127.0.0.1:54088 - "GET /bob/pub HTTP/1.1" 200 OK
INFO:     topic[/bob/pub] adding connection to [http://32vd:33177/], count 0
[DEBUG] [1582726921.889926]: connecting to 32vd 36993
DEBUG:    connecting to 32vd 36993
INFO:     topic impl's ref count is zero, deleting topic /bob/pub...
INFO:     topic[/bob/pub] removing connection to http://32vd:33177/
[DEBUG] [1582726921.898739]: connecting to 32vd 36993
DEBUG:    connecting to 32vd 36993
WARNING:  Unknown error initiating TCP/IP socket to 32vd:36993 (http://32vd:33177/): Traceback (most recent call last):
  File "/opt/ros/melodic/lib/python2.7/dist-packages/rospy/impl/tcpros_base.py", line 558, in connect
    self.read_header()
  File "/opt/ros/melodic/lib/python2.7/dist-packages/rospy/impl/tcpros_base.py", line 653, in read_header
    self._validate_header(read_ros_handshake_header(sock, self.read_buff, self.protocol.buff_size))
AttributeError: 'NoneType' object has no attribute 'buff_size'

INFO:     127.0.0.1:54102 - "GET /bob/pub HTTP/1.1" 200 OK
INFO:     topic[/bob/pub] adding connection to [http://32vd:33177/], count 0
[DEBUG] [1582726922.821767]: connecting to 32vd 36993
DEBUG:    connecting to 32vd 36993
INFO:     topic impl's ref count is zero, deleting topic /bob/pub...
INFO:     topic[/bob/pub] removing connection to http://32vd:33177/
[DEBUG] [1582726922.830297]: connecting to 32vd 36993
DEBUG:    connecting to 32vd 36993
WARNING:  Unknown error initiating TCP/IP socket to 32vd:36993 (http://32vd:33177/): Traceback (most recent call last):
  File "/opt/ros/melodic/lib/python2.7/dist-packages/rospy/impl/tcpros_base.py", line 558, in connect
    self.read_header()
  File "/opt/ros/melodic/lib/python2.7/dist-packages/rospy/impl/tcpros_base.py", line 653, in read_header
    self._validate_header(read_ros_handshake_header(sock, self.read_buff, self.protocol.buff_size))
AttributeError: 'NoneType' object has no attribute 'buff_size'

INFO:     127.0.0.1:54114 - "GET /bob/pub HTTP/1.1" 200 OK
INFO:     topic[/bob/pub] adding connection to [http://32vd:33177/], count 0
[DEBUG] [1582726923.671097]: connecting to 32vd 36993
DEBUG:    connecting to 32vd 36993
INFO:     topic impl's ref count is zero, deleting topic /bob/pub...
INFO:     topic[/bob/pub] removing connection to http://32vd:33177/
INFO:     127.0.0.1:54126 - "GET /bob/pub HTTP/1.1" 200 OK
INFO:     topic[/bob/pub] adding connection to [http://32vd:33177/], count 0
[DEBUG] [1582726924.435957]: connecting to 32vd 36993
DEBUG:    connecting to 32vd 36993
INFO:     topic impl's ref count is zero, deleting topic /bob/pub...
INFO:     topic[/bob/pub] removing connection to http://32vd:33177/
[DEBUG] [1582726924.443817]: connecting to 32vd 36993
INFO:     127.0.0.1:54136 - "GET /bob/pub HTTP/1.1" 200 OK
DEBUG:    connecting to 32vd 36993
WARNING:  Unknown error initiating TCP/IP socket to 32vd:36993 (http://32vd:33177/): Traceback (most recent call last):
  File "/opt/ros/melodic/lib/python2.7/dist-packages/rospy/impl/tcpros_base.py", line 558, in connect
    self.read_header()
  File "/opt/ros/melodic/lib/python2.7/dist-packages/rospy/impl/tcpros_base.py", line 653, in read_header
    self._validate_header(read_ros_handshake_header(sock, self.read_buff, self.protocol.buff_size))
AttributeError: 'NoneType' object has no attribute 'buff_size'
$ rosrun bob bob.py 
$ rosrun bob bob
[DEBUG] [1582726911.809096]: init_node, name[/bob], pid[32357]
[DEBUG] [1582726911.811201]: binding to 0.0.0.0 0
[DEBUG] [1582726911.812757]: bound to 0.0.0.0 36993
[DEBUG] [1582726911.814646]: ... service URL is rosrpc://32vd:36993
[DEBUG] [1582726911.816123]: [/bob/get_loggers]: new Service instance
[DEBUG] [1582726911.819473]: ... service URL is rosrpc://32vd:36993
[DEBUG] [1582726911.821454]: [/bob/set_logger_level]: new Service instance
[DEBUG] [1582726911.826141]: node[/bob, http://32vd:33177/] entering spin(), pid[32357]
[WARN] [1582726917.061248]: Inbound TCP/IP connection failed: connection from sender terminated before handshake header received. 0 bytes were received. Please check sender for additional details.
[WARN] [1582726920.083261]: Inbound TCP/IP connection failed: connection from sender terminated before handshake header received. 0 bytes were received. Please check sender for additional details.
[WARN] [1582726920.956348]: Inbound TCP/IP connection failed: connection from sender terminated before handshake header received. 0 bytes were received. Please check sender for additional details.
[WARN] [1582726921.901228]: Inbound TCP/IP connection failed: connection from sender terminated before handshake header received. 0 bytes were received. Please check sender for additional details.
[WARN] [1582726922.832478]: Inbound TCP/IP connection failed: connection from sender terminated before handshake header received. 0 bytes were received. Please check sender for additional details.
[WARN] [1582726924.450617]: Inbound TCP/IP connection failed: connection from sender terminated before handshake header received. 0 bytes were received. Please check sender for additional details.

khssnv avatar Feb 26 '20 14:02 khssnv

It looks like a race condition in which the socket has been closed and therefore various variables have been reset to None. Please consider to contribute a pull request targeting the default branch (currently noetic-devel).

dirk-thomas avatar Feb 28 '20 18:02 dirk-thomas

I also meet with this problem. My case is that I speeded up the Gazebo and then after around 10mins, this bug raised.

yizhengzhang1 avatar May 08 '20 08:05 yizhengzhang1

Hello, we have a customer encountering this issue, did you ever find a solution or workaround? Thank you!

jikawa-az avatar Feb 24 '21 17:02 jikawa-az

I encounter the same bug with my robot, unfortunately still running on ROS kinetic though. Would anyone have an idea if this could be fixed in ROS noetic by now?

anmakon avatar Jan 31 '23 16:01 anmakon

ROS 1 is end-of-life (EOL) as of today, May 31st 2025. I am archiving this repository because:

  • it only supports ROS 1
  • it isn't needed anymore in ROS 2

If you still rely on ROS 1, read this page to learn about your options.

sloretz avatar May 31 '25 19:05 sloretz