Broken Connection on successive calls using add_bytes

[machawk1]

I am attempting to debug an issue wherein I am pushing the binary image data represented in Python byte string into IPFS using ipfshttpclient.

I have been able to distill this down to an example with two successive calls of add_bytes with large byte strings:

import ipfshttpclient
import os

bytes = bytearray(os.urandom(100000))

IPFS_API = ipfshttpclient.Client(f"/dns/localhost/tcp/5001/http")
res1 = IPFS_API.add_bytes(bytes)
res2 = IPFS_API.add_bytes(bytes)

...produces:

Traceback (most recent call last):
  File "/private/tmp/ipwb/ipwbve/lib/python3.7/site-packages/requests/adapters.py", line 472, in send
    low_conn.send(i)
  File "/usr/local/Cellar/python/3.7.2_2/Frameworks/Python.framework/Versions/3.7/lib/python3.7/http/client.py", line 977, in send
    self.sock.sendall(data)
BrokenPipeError: [Errno 32] Broken pipe

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/private/tmp/ipwb/ipwbve/lib/python3.7/site-packages/ipfshttpclient/http.py", line 251, in _do_request
    return requests.request(*args, **kwargs)
  File "/private/tmp/ipwb/ipwbve/lib/python3.7/site-packages/ipfshttpclient/requests_wrapper.py", line 244, in request
    return session.request(method=method, url=url, **kwargs)
  File "/private/tmp/ipwb/ipwbve/lib/python3.7/site-packages/ipfshttpclient/requests_wrapper.py", line 223, in request
    return super(Session, self).request(method, url, *args, **kwargs)
  File "/private/tmp/ipwb/ipwbve/lib/python3.7/site-packages/requests/sessions.py", line 533, in request
    resp = self.send(prep, **send_kwargs)
  File "/private/tmp/ipwb/ipwbve/lib/python3.7/site-packages/requests/sessions.py", line 646, in send
    r = adapter.send(request, **kwargs)
  File "/private/tmp/ipwb/ipwbve/lib/python3.7/site-packages/requests/adapters.py", line 498, in send
    raise ConnectionError(err, request=request)
requests.exceptions.ConnectionError: [Errno 32] Broken pipe

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "pngpushtest.py", line 8, in <module>
    res2 = IPFS_API.add_bytes(bytes)
  File "/private/tmp/ipwb/ipwbve/lib/python3.7/site-packages/ipfshttpclient/utils.py", line 142, in wrapper
    res = cmd(*args, **kwargs)
  File "/private/tmp/ipwb/ipwbve/lib/python3.7/site-packages/ipfshttpclient/client/base.py", line 15, in wrapper
    result = func(*args, **kwargs)
  File "/private/tmp/ipwb/ipwbve/lib/python3.7/site-packages/ipfshttpclient/client/__init__.py", line 223, in add_bytes
    data=body, headers=headers, **kwargs)
  File "/private/tmp/ipwb/ipwbve/lib/python3.7/site-packages/ipfshttpclient/http.py", line 50, in wrapper
    return func(self, *args, **merged)
  File "/private/tmp/ipwb/ipwbve/lib/python3.7/site-packages/ipfshttpclient/http.py", line 370, in request
    files, headers, data, timeout=timeout)
  File "/private/tmp/ipwb/ipwbve/lib/python3.7/site-packages/ipfshttpclient/http.py", line 288, in _request
    timeout=timeout)
  File "/private/tmp/ipwb/ipwbve/lib/python3.7/site-packages/ipfshttpclient/http.py", line 255, in _do_request
    six.raise_from(exceptions.ConnectionError(error), error)
  File "<string>", line 3, in raise_from
ipfshttpclient.exceptions.ConnectionError: ConnectionError: [Errno 32] Broken pipe

Changing the above line to bytes = bytearray(os.urandom(10)), using 10 instead of 100000 does not produce this exception.

• Python 3.7.2
• ipfshttpclient 0.4.12

[machawk1]

For completeness, before executing the above Python, I started the IPFS daemon locally:

$ ipfs daemon &
Initializing daemon...
go-ipfs version: 0.4.19-
Repo version: 7
System version: amd64/darwin
Golang version: go1.11.5
Swarm listening on /ip4/127.0.0.1/tcp/4001
Swarm listening on /ip4/192.168.1.7/tcp/4001
Swarm listening on /ip6/::1/tcp/4001
Swarm listening on /p2p-circuit
Swarm announcing /ip4/127.0.0.1/tcp/4001
Swarm announcing /ip4/192.168.1.7/tcp/4001
Swarm announcing /ip6/::1/tcp/4001
API server listening on /ip4/127.0.0.1/tcp/5001
WebUI: http://127.0.0.1:5001/webui
Gateway (readonly) server listening on /ip4/127.0.0.1/tcp/8080
Daemon is ready
$

I also updated to Python 3.7.3 using homebrew and experience the same issue.

[machawk1]

This looks to have been introduced between ipfsapi 0.4.3 and 0.4.4.

With code (ipfsapitest.py):

import ipfsapi
import os

bytes1 = bytearray(os.urandom(100000))

IPFS_API = ipfsapi.Client('localhost', 5001)

res1 = IPFS_API.add_bytes(bytes1)
res2 = IPFS_API.add_bytes(bytes1)
print(res1)
print(res2)

❯ pip3 freeze
certifi==2019.3.9
chardet==3.0.4
idna==2.8
ipfsapi==0.4.3
requests==2.22.0
six==1.12.0
urllib3==1.25.3

❯ python3 ipfsapitest.py
QmQSC8UbweG16KBvvxVab526UP5wDuJsaZsTRPuFoHMdUF
QmQSC8UbweG16KBvvxVab526UP5wDuJsaZsTRPuFoHMdUF

...then updating to ipfsapi 0.4.4 with a fresh virtualenv (which seems to also install ipfshttpclient):

❯ pip3 freeze
base58==1.0.3
certifi==2019.3.9
chardet==3.0.4
idna==2.8
ipfsapi==0.4.4
ipfshttpclient==0.4.12
multiaddr==0.0.8
netaddr==0.7.19
requests==2.22.0
six==1.12.0
urllib3==1.25.3
varint==1.0.2

❯ python3 ipfsapitest.py
ipfsapitest.py:1: FutureWarning: The `ipfsapi` library is deprecated and will stop receiving updates on the 31.12.2019! If you are on Python 3.5+ please enable and fix all Python deprecation warnings (CPython flag `-Wd`) and switch to the new `ipfshttpclient` library name. Python 2.7 and 3.4 will not be supported by the new library, so please upgrade.
  import ipfsapi 
Traceback (most recent call last):
  File "/private/tmp/ttt/lib/python3.7/site-packages/requests/adapters.py", line 471, in send
    low_conn.send(b'\r\n')
  File "/usr/local/Cellar/python/3.7.3/Frameworks/Python.framework/Versions/3.7/lib/python3.7/http/client.py", line 977, in send
    self.sock.sendall(data)
BrokenPipeError: [Errno 32] Broken pipe

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/private/tmp/ttt/lib/python3.7/site-packages/ipfshttpclient/http.py", line 251, in _do_request
    return requests.request(*args, **kwargs)
  File "/private/tmp/ttt/lib/python3.7/site-packages/ipfshttpclient/requests_wrapper.py", line 244, in request
    return session.request(method=method, url=url, **kwargs)
  File "/private/tmp/ttt/lib/python3.7/site-packages/ipfshttpclient/requests_wrapper.py", line 223, in request
    return super(Session, self).request(method, url, *args, **kwargs)
  File "/private/tmp/ttt/lib/python3.7/site-packages/requests/sessions.py", line 533, in request
    resp = self.send(prep, **send_kwargs)
  File "/private/tmp/ttt/lib/python3.7/site-packages/requests/sessions.py", line 646, in send
    r = adapter.send(request, **kwargs)
  File "/private/tmp/ttt/lib/python3.7/site-packages/requests/adapters.py", line 498, in send
    raise ConnectionError(err, request=request)
requests.exceptions.ConnectionError: [Errno 32] Broken pipe

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "ipfsapitest.py", line 9, in <module>
    res2 = IPFS_API.add_bytes(bytes1)
  File "/private/tmp/ttt/lib/python3.7/site-packages/ipfsapi/client/__init__.py", line 205, in wrapper
    return value(*args, **kwargs)
  File "/private/tmp/ttt/lib/python3.7/site-packages/ipfshttpclient/utils.py", line 142, in wrapper
    res = cmd(*args, **kwargs)
  File "/private/tmp/ttt/lib/python3.7/site-packages/ipfshttpclient/client/base.py", line 15, in wrapper
    result = func(*args, **kwargs)
  File "/private/tmp/ttt/lib/python3.7/site-packages/ipfshttpclient/client/__init__.py", line 223, in add_bytes
    data=body, headers=headers, **kwargs)
  File "/private/tmp/ttt/lib/python3.7/site-packages/ipfshttpclient/http.py", line 50, in wrapper
    return func(self, *args, **merged)
  File "/private/tmp/ttt/lib/python3.7/site-packages/ipfshttpclient/http.py", line 370, in request
    files, headers, data, timeout=timeout)
  File "/private/tmp/ttt/lib/python3.7/site-packages/ipfshttpclient/http.py", line 288, in _request
    timeout=timeout)
  File "/private/tmp/ttt/lib/python3.7/site-packages/ipfshttpclient/http.py", line 255, in _do_request
    six.raise_from(exceptions.ConnectionError(error), error)
  File "<string>", line 3, in raise_from
ipfshttpclient.exceptions.ConnectionError: ConnectionError: [Errno 32] Broken pipe

[ntninja]

Thanks you for this detailed analysis of the problem, unfortunately ipfsapi v0.4.3 and ipfsapi v0.4.4 (which is now a wrapper around ipfshttpclient) are really two different libraries. The versioning is somewhat deceiving here unfortunately, ipfshttpclient actually started with version 0.4.11 which is a lot closer to the truth.

If you have the time and knowledge, could you do a git bisect between master and 1b5b1c0911d32f963689ac04c2557a5dde7a17d8 on this repository and check which is the first commit that introduced this is issue? It would likely go a long way towards fixing this, but I don't really have the time right now unfortunately.

[ntninja]

Sorry, I just noticed again that your originally did use ipfshttpclient, which is of course the way to go here – one less potential error source. 👍
Unfortunately all that I said above of course applied to ipfshttpclient anyways, so nothing I suggested will change in practice I fear.

[machawk1]

@Alexander255 Thanks for the acknowledgement. I encountered this issue in attempting to update https://github.com/oduwsdl/ipwb to the latest, refactored, renamed ipfsapi (ipfshttpclient). I iteratively tested every prior version of ipfshttpclient then onto ipfsapi until I encountered the release that contained the above behavior.

I am not familiar with git bisect usage but this might be a good opportunity to become so. Given we heavily use ipfsapi in ipwb, it will be critical for ipwb to use the newer ipfshttpclient before ipfsapi stops receiving updates at the end of the year.

[machawk1]

Using git bisect, 9edc945 appears to be the commit where the issue is first exhibited.

[machawk1]

stream_bytes() in multipart.py, which add_bytes() calls, differs between 9edc945, where add_bytes() first exhibited the above issue, and its parent commit 1b5b1c0.

1b5b1c0
https://github.com/ipfs/py-ipfs-api/blob/1b5b1c0911d32f963689ac04c2557a5dde7a17d8/ipfshttpclient/multipart.py#L653-L655

9edc945
https://github.com/ipfs/py-ipfs-api/blob/9edc945088faf5df66cab1845bd2c87c5bc77ede/ipfshttpclient/multipart.py#L676-L677

[machawk1]

Another finding, the headers in 9edc945 contain "Connection: close" when in 1b5b1c0 they do not:

9edc945
{'Content-Disposition': 'form-data; filename="bytes"', 'Content-Type': 'multipart/form-data; boundary="5f4d03ef9cd94920b38fd0401375e214"', 'Connection': 'close'}
{'Content-Disposition': 'form-data; filename="bytes"', 'Content-Type': 'multipart/form-data; boundary="38984c57f12f49cbb79c405e5b5128e6"', 'Connection': 'close'}

1b5b1c0
{'Content-Disposition': 'form-data; filename="bytes"', 'Content-Type': 'multipart/form-data; boundary="1ae72c313dec4aceb349e85414acdaf2"'}

[machawk1]

https://github.com/ipfs/py-ipfs-api/blob/4891d7239d99d98a778873146f8cd27d10a7925b/ipfshttpclient/multipart.py#L141-L143

...seems to be the source of the header mentioned above. ipfs/kubo#5168 has since been closed. Removing this explicit Connection header specification fixes the problem on my initial testing.

EDIT: the issue remains. The pipe still breaks even when the headers do not contain Connection: close:

{'Content-Disposition': 'form-data; filename="bytes"', 'Content-Type': 'multipart/form-data; boundary="5ab37ea44c87464d8d7828727978aa51"'}
{'Content-Disposition': 'form-data; filename="bytes"', 'Content-Type': 'multipart/form-data; boundary="249814e886b848128a85d48bda7cc6d9"'}

[machawk1]

An optimistic update: I updated my go-ipfs to 0.4.21 and the original BrokenPipeError: [Errno 32] Broken pipe issue has disappeared. This whole issue may be moot if go-ipfs 0.4.21 is supported by ipfshttpclient.

The README states that 0.4.20 is blacklisted but was the issue that caused it to be so resolved in 0.4.21, @Alexander255? If so, we can proceed with migrating to ipfshttpclient with the insistence of a go-ipfs installation from ipwb users.

/cc @ibnesayeed

[ibnesayeed]

Thanks @machawk1, if the new version of this library works well with the new version of the go-ipfs then we can move on.

[ntninja]

@machawk1: Thanks for your tremendously valuable research here! While, as @ibnesayeed found out, adding the header should not be a problem anymore, it's still an unnecessary performance penalty and I'm glad to here that this can be removed with go-IPFS v0.4.19+.

I will create a patch that removes the Connection: close flag for v0.4.19+ and would welcome your feedback on this.

The problem with 0.4.20 was that several API methods had returned broken or incomplete responses making it basically useless if you relied on any of these. Hence I decided to blacklist it altogether, rather than dealing with support queries that I can do nothing about anyways. (As such I don't think it was related to this, but maybe played a part as well.)

[machawk1]

@Alexander255 What sort of testing would be required to ensure this module's full functionality with go-ipfs v0.4.21+? Do the issues that prevent the recommendation of v0.4.20 also exist in v0.4.21?

Given add_bytes() does not work reliably against v0.4.19, it might be good to move to a more current version of go-ipfs that has some bugs fixed, inclusive of the connection closing issue discussed above.

[ntninja]

Damn! Looks like I forgot the upload the changes I'm planning to land, somehow I thought them to already being released.

@machawk1: Please see and comment on #189. Thank you!

The issues in v0.4.20 were of a different nature, iirc the daemon sent incomplete responses to several calls. I can look it up if you want to know more.

[ntninja]

Support for 0.4.19 and below was dropped, so this isn't an issue anymore.