Resource update succeed only sometimes

[bruno-marino]

Describe the bug Updating a resource is not always successful. It is not a problem of resource because the same call for the same resource can succeed if repeated.

It seems that the result of the following call can fail or succeed randomly.

curl -H "Authorization: ${APIKEY}" "${APIBASE}/action/resource_update" --form id=${RESOURCE_ID}  --form upload=@"${FILE_NAME}.csv" --form package_id=${ID_DATASET}  --form name="${RESOURCE_NAME}" --form format=csv  --form description="${DESCRIPTION}"

where ${..} is to be replaced with appropriate data.

Docker images affected

• CKAN 2.9.4
• Datapusher (from dockerfile: https://github.com/keitaroinc/docker-ckan/blob/master/images/datapusher/Dockerfile)

the only change made to the dockerfile of the given datapusher is to set python 3.8 instead of python 3.9 to prevent compatibility errors.

That is, this fix has been made:

RUN apk add --no-cache --repository=http://dl-cdn.alpinelinux.org/alpine/v3.13/main \.
               python3=3.8.10-r0 \
               python3-dev=3.8.10-r0 && \
        apk add --no-cache \
              ....

How to reproduce the error

1. Install CKAN and Datapusher in this repo, by keep care to use the following dockerfile in docker-compose: https://github.com/keitaroinc/docker-ckan/blob/master/images/datapusher/Dockerfile, instead of the image that appear in the docker-compose (image: ghcr.io/keitaroinc/datapusher:${DATAPUSHER_VERSION})
2. Call several times the following curl

curl -H "Authorization: ${APIKEY}" "${APIBASE}/action/resource_update" --form id=${RESOURCE_ID}  --form upload=@"${FILE_NAME}.csv" --form package_id=${ID_DATASET}  --form name="${RESOURCE_NAME}" --form format=csv  --form description="${DESCRIPTION}"

Sometimes the curl will fail seemingly at random.

Datapusher container log ({IP_ADDRESS_OF_CKAN_INSTALLATION} is the ip address of the ckan installation).

Fetching from: http://{IP_ADDRESS_OF_CKAN_INSTALLATION}:5000/dataset/78ebed9e-8e76-4c09-8201-7e4b4225a866/resource/d9110c47-f3fa-4b6f-999b-d53e2fd9a6a7/download/samplecsvfile_11kb.csv
Rewrote resource url to: http://ckan:5000/dataset/78ebed9e-8e76-4c09-8201-7e4b4225a866/resource/d9110c47-f3fa-4b6f-999b-d53e2fd9a6a7/download/samplecsvfile_11kb.csv
Deleting "d9110c47-f3fa-4b6f-999b-d53e2fd9a6a7" from datastore.
Job "push_to_datastore (trigger: RunTriggerNow, run = True, next run at: None)" raised an exception
Traceback (most recent call last):
  File "/usr/lib/python3.8/site-packages/urllib3/connectionpool.py", line 670, in urlopen
    httplib_response = self._make_request(
  File "/usr/lib/python3.8/site-packages/urllib3/connectionpool.py", line 426, in _make_request
    six.raise_from(e, None)
  File "<string>", line 3, in raise_from
  File "/usr/lib/python3.8/site-packages/urllib3/connectionpool.py", line 421, in _make_request
    httplib_response = conn.getresponse()
  File "/usr/lib/python3.8/http/client.py", line 1344, in getresponse
    response.begin()
  File "/usr/lib/python3.8/http/client.py", line 307, in begin
    version, status, reason = self._read_status()
  File "/usr/lib/python3.8/http/client.py", line 276, in _read_status
    raise RemoteDisconnected("Remote end closed connection without"
http.client.RemoteDisconnected: Remote end closed connection without response
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
  File "/usr/lib/python3.8/site-packages/requests/adapters.py", line 439, in send
    resp = conn.urlopen(
  File "/usr/lib/python3.8/site-packages/urllib3/connectionpool.py", line 726, in urlopen
    retries = retries.increment(
  File "/usr/lib/python3.8/site-packages/urllib3/util/retry.py", line 410, in increment
    raise six.reraise(type(error), error, _stacktrace)
  File "/usr/lib/python3.8/site-packages/urllib3/packages/six.py", line 734, in reraise
    raise value.with_traceback(tb)
  File "/usr/lib/python3.8/site-packages/urllib3/connectionpool.py", line 670, in urlopen
    httplib_response = self._make_request(
  File "/usr/lib/python3.8/site-packages/urllib3/connectionpool.py", line 426, in _make_request
    six.raise_from(e, None)
  File "<string>", line 3, in raise_from
  File "/usr/lib/python3.8/site-packages/urllib3/connectionpool.py", line 421, in _make_request
    httplib_response = conn.getresponse()
  File "/usr/lib/python3.8/http/client.py", line 1344, in getresponse
    response.begin()
  File "/usr/lib/python3.8/http/client.py", line 307, in begin
    version, status, reason = self._read_status()
  File "/usr/lib/python3.8/http/client.py", line 276, in _read_status
    raise RemoteDisconnected("Remote end closed connection without"
urllib3.exceptions.ProtocolError: ('Connection aborted.', RemoteDisconnected('Remote end closed connection without response'))
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
  File "/usr/lib/python3.8/site-packages/datapusher/jobs.py", line 209, in delete_datastore_resource
    response = requests.post(delete_url,
  File "/usr/lib/python3.8/site-packages/requests/api.py", line 119, in post
    return request('post', url, data=data, json=json, **kwargs)
  File "/usr/lib/python3.8/site-packages/requests/api.py", line 61, in request
    return session.request(method=method, url=url, **kwargs)
  File "/usr/lib/python3.8/site-packages/requests/sessions.py", line 530, in request
    resp = self.send(prep, **send_kwargs)
  File "/usr/lib/python3.8/site-packages/requests/sessions.py", line 643, in send
    r = adapter.send(request, **kwargs)
  File "/usr/lib/python3.8/site-packages/requests/adapters.py", line 498, in send
    raise ConnectionError(err, request=request)
requests.exceptions.ConnectionError: ('Connection aborted.', RemoteDisconnected('Remote end closed connection without response'))
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
  File "/usr/lib/python3.8/site-packages/apscheduler/scheduler.py", line 512, in _run_job
    retval = job.func(*job.args, **job.kwargs)
  File "/usr/lib/python3.8/site-packages/datapusher/jobs.py", line 502, in push_to_datastore
    delete_datastore_resource(resource_id, api_key, ckan_url)
  File "/usr/lib/python3.8/site-packages/datapusher/jobs.py", line 219, in delete_datastore_resource
    raise util.JobError('Deleting existing datastore failed.')
ckanserviceprovider.util.JobError: <unprintable JobError object>

CKAN container log

Thu Jan 13 15:17:13 2022 - *** HARAKIRI ON WORKER 2 (pid: 30135, try: 1) ***
Thu Jan 13 15:17:13 2022 - HARAKIRI !!! worker 2 status !!!
Thu Jan 13 15:17:13 2022 - HARAKIRI [core 1997] 172.29.0.5 - POST /api/3/action/datastore_delete since 1642086982
Thu Jan 13 15:17:13 2022 - HARAKIRI [core 1998] 10.122.17.173 - POST /api/3/action/resource_update since 1642086982
Thu Jan 13 15:17:13 2022 - HARAKIRI !!! end of worker 2 status !!!

[mbocevski]

This looks like a local issue with your docker setup... Have you verified the docker bridge or networking works fine? Chekc the docker daemon logs or network logs to see whether you find anything strange

[bruno-marino]

Everything seems to work correctly. I am working on a virtual centOs machine and I checked the network with the following command: sudo journalctl -fu docker.service. Maybe there is another way to check docker daemon or network logs? Anyway I found that when the problem occurs in the postgres db container I have these logs:

2022-02-02 09:46:57.167 UTC [1] LOG:  database system is ready to accept connections
2022-02-02 09:48:46.060 UTC [70] LOG:  unexpected EOF on client connection with an open transaction
2022-02-02 09:48:46.061 UTC [71] LOG:  unexpected EOF on client connection with an open transaction
2022-02-02 09:50:43.195 UTC [104] LOG:  unexpected EOF on client connection with an open transaction
2022-02-02 09:50:43.199 UTC [103] LOG:  could not receive data from client: Connection reset by peer
2022-02-02 09:50:43.199 UTC [103] LOG:  unexpected EOF on client connection with an open transaction
2022-02-02 09:52:01.290 UTC [68] LOG:  unexpected EOF on client connection with an open transaction
2022-02-02 09:52:01.293 UTC [113] LOG:  unexpected EOF on client connection with an open transaction

[blazhovsky]

Thanks for the debugging info @bruno-marino! We'll continue looking into this. Are you still getting the same issue with the latest version of the docker compose setup?

[bruno-marino]

Yes, I'm having the same problem with the latest version of docker-compose. The last time I had a version without this problem was when ckan's patch "01_patch_resource_replace_upload.patch" was still applicable.

[blazhovsky]

Closing this since we reverted the uwsgi and gevent versions that were causing this issue around February/March 2022. We have had no reports for this issue since.