Having issues posting an ad with many photos in Docker environment

[ghost]

Was using this project for several months without issue. Unfortunately I do not recall the original version I had. After upgrading the project on a Raspberry Pi I experienced many dependency issues so decided to move to the docker installation on another system.

Since install, I have been able to successfully post 1 of the 2 ads I have. The one that has issue has 7 photos. This was working on the previous version for a while without issues.

I've checked Kijiji's image limitations and my 7 photos appear to meet the requirements mentioned.

Some noteworthy items:

• If I post all 7 photos, my browser just receives a timeout. When doing a packet capture my browser doesn't seem to send a packet (HTTP POST) at all. I've tried a couple different browsers and received the same issue. On one of them (Internet Explorer) I received a HTTP error code 413 it seems in the packet capture file
• The next issue is when I removed 2 of the 7 photos (5 posted), I received an Internal Server Error and the following output below is presented in the docker logs:

  [2022-05-27 17:22:37 +0000] [1] [CRITICAL] WORKER TIMEOUT (pid:15)
  [2022-05-27 17:22:37 +0000] [15] [ERROR] Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/flask/app.py", line 2091, in __call__
  return self.wsgi_app(environ, start_response)
  File "/usr/local/lib/python3.6/site-packages/flask/app.py", line 2073, in wsgi_app
  response = self.full_dispatch_request()
  File "/usr/local/lib/python3.6/site-packages/flask/app.py", line 1516, in full_dispatch_request
  rv = self.dispatch_request()
  File "/usr/local/lib/python3.6/site-packages/flask/app.py", line 1502, in dispatch_request
  return self.ensure_sync(self.view_functions[rule.endpoint])(**req.view_args)
  File "/usr/local/lib/python3.6/site-packages/flask_login/utils.py", line 272, in decorated_view
  return func(*args, **kwargs)
  File "/app/kijiji_manager/views/ad.py", line 273, in post
  'pic:pictures': create_picture_payload(form.data),
  File "/app/kijiji_manager/views/ad.py", line 431, in create_picture_payload
  link = kijiji_api.upload_image(value)
  File "/app/kijiji_manager/kijijiapi.py", line 267, in upload_image
  r = self.session.post(api_endpoint, headers=headers, files=files)
  File "/usr/local/lib/python3.6/site-packages/httpx/_client.py", line 1129, in post
  extensions=extensions,
  File "/usr/local/lib/python3.6/site-packages/httpx/_client.py", line 802, in request
  return self.send(request, auth=auth, follow_redirects=follow_redirects)
  File "/usr/local/lib/python3.6/site-packages/httpx/_client.py", line 893, in send
  history=[],
  File "/usr/local/lib/python3.6/site-packages/httpx/_client.py", line 920, in _send_handling_auth
  history=history,
  File "/usr/local/lib/python3.6/site-packages/httpx/_client.py", line 954, in _send_handling_redirects
  response = self._send_single_request(request)
  File "/usr/local/lib/python3.6/site-packages/httpx/_client.py", line 990, in _send_single_request
  response = transport.handle_request(request)
  File "/usr/local/lib/python3.6/site-packages/httpx/_transports/default.py", line 187, in handle_request
  resp = self._pool.handle_request(req)
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/connection_pool.py", line 232, in handle_request
  response = connection.handle_request(request)
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/connection.py", line 94, in handle_request
  return self._connection.handle_request(request)
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/http11.py", line 102, in handle_request
  raise exc
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/http11.py", line 81, in handle_request
  ) = self._receive_response_headers(**kwargs)
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/http11.py", line 143, in _receive_response_headers
  event = self._receive_event(timeout=timeout)
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/http11.py", line 173, in _receive_event
  self.READ_NUM_BYTES, timeout=timeout
  File "/usr/local/lib/python3.6/site-packages/httpcore/backends/sync.py", line 26, in read
  return self._sock.recv(max_bytes)
  File "/usr/local/lib/python3.6/ssl.py", line 997, in recv
  return self.read(buflen)
  File "/usr/local/lib/python3.6/ssl.py", line 874, in read
  return self._sslobj.read(len, buffer)
  File "/usr/local/lib/python3.6/ssl.py", line 633, in read
  v = self._sslobj.read(len)
  File "/usr/local/lib/python3.6/site-packages/gunicorn/workers/base.py", line 203, in handle_abort
  sys.exit(1)
  SystemExit: 1

[jackm]

Yes this looks to me like a timeout issue. By default, Gunicorn has a 30 second timeout for workers and it is likely that the worker timed out waiting for the remote server (i.e. on Kijiji's side) to respond to the photo file upload HTTP POST request.

Are the photos particularly large in file size (i.e. >1MB)?

I have pushed a new branch which sets the Gunicorn timeout to 120 seconds; would you be able to checkout that branch and give it a try?

I may also have to increase the read timeout for kijiji-manager's httpx client as well since that is also currently set to 30 seconds.

[ghost]

Thanks for the quick responses @jackm,

Looks like your Dockerfiles are different between the branches. I tried digging through the code but wasn't able to find where you define the IP address the resource is available on (i.e. 0.0.0.0/0 vs localhost).

On your branch after I rebuild, I am presented with:

sudo docker logs kijiji-manager
Checking for script in /app/prestart.sh
There is no script /app/prestart.sh
[2022-05-27 19:38:20 +0000] [1] [INFO] Starting gunicorn 20.1.0
[2022-05-27 19:38:20 +0000] [1] [INFO] Listening at: http://127.0.0.1:8000 (1)
[2022-05-27 19:38:20 +0000] [1] [INFO] Using worker: egg:meinheld#gunicorn_worker
[2022-05-27 19:38:20 +0000] [9] [INFO] Booting worker with pid: 9

Launches as local host on port 8000. The container starts, but I can't access the webUI

When using the main branch, this is what I see and it works:

sudo docker logs kijiji-manager
Checking for script in /app/prestart.sh
There is no script /app/prestart.sh
[2022-05-27 20:07:55 +0000] [1] [INFO] Starting gunicorn 20.1.0
[2022-05-27 20:07:55 +0000] [1] [INFO] Listening at: http://0.0.0.0:80 (1)
[2022-05-27 20:07:55 +0000] [1] [INFO] Using worker: egg:meinheld#gunicorn_worker
[2022-05-27 20:07:55 +0000] [9] [INFO] Booting worker with pid: 9
[2022-05-27 20:07:55 +0000] [10] [INFO] Booting worker with pid: 10

[jackm]

Ah my mistake, by using a custom Gunicorn config file it overwrites the default one provided by the tiangolo/meinheld-gunicorn Docker image. I just pushed another commit to the branch which should fix this and make Gunicorn bind to 0.0.0.0:80 again.

[ghost]

No luck unfortunately. On the http://192.168.10.50:5000/post URL I immediately receive a "this site can't be reached" when hitting the post ad button

[ghost]

Worked when I posted 5/7 images. Previous post I tried posting all images.

[jackm]

Do the Docker logs still show a Gunicorn worker timeout?

[ghost]

No, looks good. I suppose it is possible it could be the browser. But I have seen the same behaviour on a few different browsers.

Checking for script in /app/prestart.sh
There is no script /app/prestart.sh
[2022-05-27 20:50:24 +0000] [1] [INFO] Starting gunicorn 20.1.0
[2022-05-27 20:50:24 +0000] [1] [INFO] Listening at: http://0.0.0.0:80 (1)
[2022-05-27 20:50:24 +0000] [1] [INFO] Using worker: egg:meinheld#gunicorn_worker
[2022-05-27 20:50:24 +0000] [9] [INFO] Booting worker with pid: 9
[2022-05-27 20:50:24 +0000] [10] [INFO] Booting worker with pid: 10
[2022-05-27 20:50:24 +0000] [11] [INFO] Booting worker with pid: 11
[2022-05-27 20:50:24 +0000] [12] [INFO] Booting worker with pid: 12
[2022-05-27 20:50:24 +0000] [13] [INFO] Booting worker with pid: 13
[2022-05-27 20:50:24 +0000] [17] [INFO] Booting worker with pid: 17
[2022-05-27 20:50:24 +0000] [19] [INFO] Booting worker with pid: 19
[2022-05-27 20:50:24 +0000] [21] [INFO] Booting worker with pid: 21
[2022-05-27 20:50:24 +0000] [22] [INFO] Booting worker with pid: 22
[2022-05-27 20:50:24 +0000] [24] [INFO] Booting worker with pid: 24
[2022-05-27 20:50:24 +0000] [25] [INFO] Booting worker with pid: 25
[2022-05-27 20:50:24 +0000] [27] [INFO] Booting worker with pid: 27
[2022-05-27 20:50:24 +0000] [29] [INFO] Booting worker with pid: 29
[2022-05-27 20:50:24 +0000] [37] [INFO] Booting worker with pid: 37
[2022-05-27 20:50:24 +0000] [38] [INFO] Booting worker with pid: 38
[2022-05-27 20:50:24 +0000] [47] [INFO] Booting worker with pid: 47

[jackm]

Are the photos particularly large in file size (i.e. >1MB)?

[ghost]

Are the photos particularly large in file size (i.e. >1MB)?

Most are approx 3 MB. The largest is 3.50 MB

Total amongst the photos I am trying to post is 20.5 MB (total 6 photos)

[jackm]

Those are rather large files - I'm wondering if reducing the file size will help lower the chance of a timeout waiting for the response from the remote server.

20MB of data doesn't seem like a lot to upload, but it's possible that the remote server is processing them in some way which means it takes longer for it to respond back.

I tend to resize most of my ad photos down to about 1000 to 1500 px on one of the dimensions (keeping same aspect ratio) before posting a new ad which usually reduces the file size down to roughly 500KB per photo file. I've posted ads with up to ten photos before without issue, but at 500KB per file that still only comes to 5MB of total data to upload.

[ghost]

So I pulled the newest updates (then deployed in docker again after building the new image) hoping the new changes to how media files are uploaded would resolve the issue. I received the same timeout issue in my browser again (using chrome)

I then re-sized the photos as per your suggestion and file sizes (total) went from approximately 20MB to 4.14MB total:

-rwxrwxrwx 1 topsecretuser topsecretuser 627K Jul  6 17:43 0.jpg
-rwxrwxrwx 1 topsecretuser topsecretuser 715K Jul  6 17:43 1.jpg
-rwxrwxrwx 1 topsecretuser topsecretuser 548K Jul  6 17:43 2.jpg
-rwxrwxrwx 1 topsecretuser topsecretuser 759K Jul  6 17:43 3.jpg
-rwxrwxrwx 1 topsecretuser topsecretuser 630K Jul  6 17:43 4.jpg
-rwxrwxrwx 1 topsecretuser topsecretuser 363K Jul  6 17:43 5.jpg
-rwxrwxrwx 1 topsecretuser topsecretuser 603K Jul  6 17:44 6.jpg

I then tried to post an AD (with the smaller filers) and in my browser (chrome) I received the following error:

Internal Server Error
The server encountered an internal error and was unable to complete your request. Either the server is overloaded or there is an error in the application.

Docker logs of error:

[2022-07-06 21:45:14 +0000] [1] [CRITICAL] WORKER TIMEOUT (pid:21)
[2022-07-06 21:45:14 +0000] [21] [ERROR] Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/flask/app.py", line 2091, in __call__
    return self.wsgi_app(environ, start_response)
  File "/usr/local/lib/python3.6/site-packages/flask/app.py", line 2073, in wsgi_app
    response = self.full_dispatch_request()
  File "/usr/local/lib/python3.6/site-packages/flask/app.py", line 1516, in full_dispatch_request
    rv = self.dispatch_request()
  File "/usr/local/lib/python3.6/site-packages/flask/app.py", line 1502, in dispatch_request
    return self.ensure_sync(self.view_functions[rule.endpoint])(**req.view_args)
  File "/usr/local/lib/python3.6/site-packages/flask_login/utils.py", line 272, in decorated_view
    return func(*args, **kwargs)
  File "/app/kijiji_manager/views/ad.py", line 275, in post
    'pic:pictures': create_picture_payload(form.data),
  File "/usr/local/lib/python3.6/site-packages/flask_login/utils.py", line 272, in decorated_view
    return func(*args, **kwargs)
  File "/app/kijiji_manager/views/ad.py", line 443, in create_picture_payload
    link = kijiji_api.upload_image(current_user.id, current_user.token, value)
  File "/app/kijiji_manager/kijijiapi.py", line 258, in upload_image
    r = self.session.post(api_endpoint, headers=headers, files=files)
  File "/usr/local/lib/python3.6/site-packages/httpx/_client.py", line 1129, in post
    extensions=extensions,
  File "/usr/local/lib/python3.6/site-packages/httpx/_client.py", line 802, in request
    return self.send(request, auth=auth, follow_redirects=follow_redirects)
  File "/usr/local/lib/python3.6/site-packages/httpx/_client.py", line 893, in send
    history=[],
  File "/usr/local/lib/python3.6/site-packages/httpx/_client.py", line 920, in _send_handling_auth
    history=history,
  File "/usr/local/lib/python3.6/site-packages/httpx/_client.py", line 954, in _send_handling_redirects
    response = self._send_single_request(request)
  File "/usr/local/lib/python3.6/site-packages/httpx/_client.py", line 990, in _send_single_request
    response = transport.handle_request(request)
  File "/usr/local/lib/python3.6/site-packages/httpx/_transports/default.py", line 218, in handle_request
    resp = self._pool.handle_request(req)
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/connection_pool.py", line 253, in handle_request
    raise exc
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/connection_pool.py", line 237, in handle_request
    response = connection.handle_request(request)
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/connection.py", line 90, in handle_request
    return self._connection.handle_request(request)
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/http11.py", line 102, in handle_request
    raise exc
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/http11.py", line 81, in handle_request
    ) = self._receive_response_headers(**kwargs)
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/http11.py", line 143, in _receive_response_headers
    event = self._receive_event(timeout=timeout)
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/http11.py", line 173, in _receive_event
    self.READ_NUM_BYTES, timeout=timeout
  File "/usr/local/lib/python3.6/site-packages/httpcore/backends/sync.py", line 26, in read
    return self._sock.recv(max_bytes)
  File "/usr/local/lib/python3.6/ssl.py", line 997, in recv
    return self.read(buflen)
  File "/usr/local/lib/python3.6/ssl.py", line 874, in read
    return self._sslobj.read(len, buffer)
  File "/usr/local/lib/python3.6/ssl.py", line 633, in read
    v = self._sslobj.read(len)
  File "/usr/local/lib/python3.6/site-packages/gunicorn/workers/base.py", line 203, in handle_abort
    sys.exit(1)
SystemExit: 1

[2022-07-06 21:45:15 +0000] [1] [WARNING] Worker with pid 21 was terminated due to signal 9
[2022-07-06 21:45:15 +0000] [153] [INFO] Booting worker with pid: 153

[ghost]

Just attempted again and it successfully posted.

[ghost]

Just tried another AD (with less photos) and received the same issue

-rwxrwxrwx 1 topsecretuser topsecretuser 371K Jul  6 18:29 1.jpeg
-rwxrwxrwx 1 topsecretuser topsecretuser 362K Jul  6 18:29 2.jpeg
-rwxrwxrwx 1 topsecretuser topsecretuser 281K Jul  6 18:28 3.jpeg
-rwxrwxrwx 1 topsecretuser topsecretuser 385K Jul  6 18:29 4.jpeg

Chrome browser:

Internal Server Error
The server encountered an internal error and was unable to complete your request. Either the server is overloaded or there is an error in the application.

Docker logs:

[2022-07-06 22:31:05 +0000] [1] [CRITICAL] WORKER TIMEOUT (pid:10)
[2022-07-06 22:31:05 +0000] [10] [ERROR] Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/flask/app.py", line 2091, in __call__
    return self.wsgi_app(environ, start_response)
  File "/usr/local/lib/python3.6/site-packages/flask/app.py", line 2073, in wsgi_app
    response = self.full_dispatch_request()
  File "/usr/local/lib/python3.6/site-packages/flask/app.py", line 1516, in full_dispatch_request
    rv = self.dispatch_request()
  File "/usr/local/lib/python3.6/site-packages/flask/app.py", line 1502, in dispatch_request
    return self.ensure_sync(self.view_functions[rule.endpoint])(**req.view_args)
  File "/usr/local/lib/python3.6/site-packages/flask_login/utils.py", line 272, in decorated_view
    return func(*args, **kwargs)
  File "/app/kijiji_manager/views/ad.py", line 275, in post
    'pic:pictures': create_picture_payload(form.data),
  File "/usr/local/lib/python3.6/site-packages/flask_login/utils.py", line 272, in decorated_view
    return func(*args, **kwargs)
  File "/app/kijiji_manager/views/ad.py", line 443, in create_picture_payload
    link = kijiji_api.upload_image(current_user.id, current_user.token, value)
  File "/app/kijiji_manager/kijijiapi.py", line 258, in upload_image
    r = self.session.post(api_endpoint, headers=headers, files=files)
  File "/usr/local/lib/python3.6/site-packages/httpx/_client.py", line 1129, in post
    extensions=extensions,
  File "/usr/local/lib/python3.6/site-packages/httpx/_client.py", line 802, in request
    return self.send(request, auth=auth, follow_redirects=follow_redirects)
  File "/usr/local/lib/python3.6/site-packages/httpx/_client.py", line 893, in send
    history=[],
  File "/usr/local/lib/python3.6/site-packages/httpx/_client.py", line 920, in _send_handling_auth
    history=history,
  File "/usr/local/lib/python3.6/site-packages/httpx/_client.py", line 954, in _send_handling_redirects
    response = self._send_single_request(request)
  File "/usr/local/lib/python3.6/site-packages/httpx/_client.py", line 990, in _send_single_request
    response = transport.handle_request(request)
  File "/usr/local/lib/python3.6/site-packages/httpx/_transports/default.py", line 218, in handle_request
    resp = self._pool.handle_request(req)
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/connection_pool.py", line 253, in handle_request
    raise exc
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/connection_pool.py", line 237, in handle_request
    response = connection.handle_request(request)
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/connection.py", line 90, in handle_request
    return self._connection.handle_request(request)
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/http11.py", line 102, in handle_request
    raise exc
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/http11.py", line 81, in handle_request
    ) = self._receive_response_headers(**kwargs)
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/http11.py", line 143, in _receive_response_headers
    event = self._receive_event(timeout=timeout)
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/http11.py", line 173, in _receive_event
    self.READ_NUM_BYTES, timeout=timeout
  File "/usr/local/lib/python3.6/site-packages/httpcore/backends/sync.py", line 26, in read
    return self._sock.recv(max_bytes)
  File "/usr/local/lib/python3.6/ssl.py", line 997, in recv
    return self.read(buflen)
  File "/usr/local/lib/python3.6/ssl.py", line 874, in read
    return self._sslobj.read(len, buffer)
  File "/usr/local/lib/python3.6/ssl.py", line 633, in read
    v = self._sslobj.read(len)
  File "/usr/local/lib/python3.6/site-packages/gunicorn/workers/base.py", line 203, in handle_abort
    sys.exit(1)
SystemExit: 1

[2022-07-06 22:31:06 +0000] [1] [WARNING] Worker with pid 10 was terminated due to signal 9
[2022-07-06 22:31:06 +0000] [162] [INFO] Booting worker with pid: 162

[jackm]

Odd that it sometimes works and other times it times out. Total file size being uploaded doesn't seem to make a difference.

Could you try the gunicorn-timeout branch again? I've updated it to contain the latest changes from the master branch now, in addition to increasing the worker timeout to 2 minutes.

[ghost]

I will change branch and deploy the docker container. However, below error is from today (on main branch) when a script I use to repost the ads was run. It appears one of my ads was never reposted. I manually had to go in afterwards and do so by posting the XML file. Hopefully this branch has the fix.

Docker Logs:

[2022-07-12 22:00:35 +0000] [1] [CRITICAL] WORKER TIMEOUT (pid:12)
[2022-07-12 22:00:35 +0000] [12] [ERROR] Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/flask/app.py", line 2091, in __call__
    return self.wsgi_app(environ, start_response)
  File "/usr/local/lib/python3.6/site-packages/flask/app.py", line 2073, in wsgi_app
    response = self.full_dispatch_request()
  File "/usr/local/lib/python3.6/site-packages/flask/app.py", line 1516, in full_dispatch_request
    rv = self.dispatch_request()
  File "/usr/local/lib/python3.6/site-packages/flask/app.py", line 1502, in dispatch_request
    return self.ensure_sync(self.view_functions[rule.endpoint])(**req.view_args)
  File "/usr/local/lib/python3.6/site-packages/flask_login/utils.py", line 272, in decorated_view
    return func(*args, **kwargs)
  File "/app/kijiji_manager/views/ad.py", line 544, in repost_all
    repost(ad_id)
  File "/usr/local/lib/python3.6/site-packages/flask_login/utils.py", line 272, in decorated_view
    return func(*args, **kwargs)
  File "/app/kijiji_manager/views/ad.py", line 478, in repost
    kijiji_api.delete_ad(current_user.id, current_user.token, ad_id)
  File "/app/kijiji_manager/kijijiapi.py", line 193, in delete_ad
    r = self.session.delete(f'{self.base_url}/users/{user_id}/ads/{ad_id}', headers=headers)
  File "/usr/local/lib/python3.6/site-packages/httpx/_client.py", line 1232, in delete
    extensions=extensions,
  File "/usr/local/lib/python3.6/site-packages/httpx/_client.py", line 802, in request
    return self.send(request, auth=auth, follow_redirects=follow_redirects)
  File "/usr/local/lib/python3.6/site-packages/httpx/_client.py", line 893, in send
    history=[],
  File "/usr/local/lib/python3.6/site-packages/httpx/_client.py", line 920, in _send_handling_auth
    history=history,
  File "/usr/local/lib/python3.6/site-packages/httpx/_client.py", line 954, in _send_handling_redirects
    response = self._send_single_request(request)
  File "/usr/local/lib/python3.6/site-packages/httpx/_client.py", line 990, in _send_single_request
    response = transport.handle_request(request)
  File "/usr/local/lib/python3.6/site-packages/httpx/_transports/default.py", line 218, in handle_request
    resp = self._pool.handle_request(req)
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/connection_pool.py", line 253, in handle_request
    raise exc
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/connection_pool.py", line 237, in handle_request
    response = connection.handle_request(request)
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/connection.py", line 90, in handle_request
    return self._connection.handle_request(request)
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/http11.py", line 102, in handle_request
    raise exc
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/http11.py", line 81, in handle_request
    ) = self._receive_response_headers(**kwargs)
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/http11.py", line 143, in _receive_response_headers
    event = self._receive_event(timeout=timeout)
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/http11.py", line 173, in _receive_event
    self.READ_NUM_BYTES, timeout=timeout
  File "/usr/local/lib/python3.6/site-packages/httpcore/backends/sync.py", line 26, in read
    return self._sock.recv(max_bytes)
  File "/usr/local/lib/python3.6/ssl.py", line 997, in recv
    return self.read(buflen)
  File "/usr/local/lib/python3.6/ssl.py", line 874, in read
    return self._sslobj.read(len, buffer)
  File "/usr/local/lib/python3.6/ssl.py", line 633, in read
    v = self._sslobj.read(len)
  File "/usr/local/lib/python3.6/site-packages/gunicorn/workers/base.py", line 203, in handle_abort
    sys.exit(1)
SystemExit: 1

[ghost]

Okay, I checked out the gunicorn-timeout branch, rebuilt the image and ran the container.

First AD I tried to post failed (chrome showed internal server error) and had only these two photos:

-rwxrwxrwx 1 topsecretuser topsecretuser 318K Jul 12 18:55 1.jpeg
-rwxrwxrwx 1 topsecretuser topsecretuser 256K Jul 12 18:55 2.jpeg

Docker logs:

[2022-07-12 22:56:42,717] ERROR in app: Exception on /post [POST]
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/httpcore/_exceptions.py", line 8, in map_exceptions
    yield
  File "/usr/local/lib/python3.6/site-packages/httpcore/backends/sync.py", line 26, in read
    return self._sock.recv(max_bytes)
  File "/usr/local/lib/python3.6/ssl.py", line 997, in recv
    return self.read(buflen)
  File "/usr/local/lib/python3.6/ssl.py", line 874, in read
    return self._sslobj.read(len, buffer)
  File "/usr/local/lib/python3.6/ssl.py", line 633, in read
    v = self._sslobj.read(len)
socket.timeout: The read operation timed out

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/httpx/_transports/default.py", line 60, in map_httpcore_exceptions
    yield
  File "/usr/local/lib/python3.6/site-packages/httpx/_transports/default.py", line 187, in handle_request
    resp = self._pool.handle_request(req)
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/connection_pool.py", line 248, in handle_request
    raise exc
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/connection_pool.py", line 232, in handle_request
    response = connection.handle_request(request)
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/connection.py", line 94, in handle_request
    return self._connection.handle_request(request)
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/http11.py", line 102, in handle_request
    raise exc
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/http11.py", line 81, in handle_request
    ) = self._receive_response_headers(**kwargs)
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/http11.py", line 143, in _receive_response_headers
    event = self._receive_event(timeout=timeout)
  File "/usr/local/lib/python3.6/site-packages/httpcore/_sync/http11.py", line 173, in _receive_event
    self.READ_NUM_BYTES, timeout=timeout
  File "/usr/local/lib/python3.6/site-packages/httpcore/backends/sync.py", line 26, in read
    return self._sock.recv(max_bytes)
  File "/usr/local/lib/python3.6/contextlib.py", line 99, in __exit__
    self.gen.throw(type, value, traceback)
  File "/usr/local/lib/python3.6/site-packages/httpcore/_exceptions.py", line 12, in map_exceptions
    raise to_exc(exc)
httpcore.ReadTimeout: The read operation timed out

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

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/flask/app.py", line 2073, in wsgi_app
    response = self.full_dispatch_request()
  File "/usr/local/lib/python3.6/site-packages/flask/app.py", line 1518, in full_dispatch_request
    rv = self.handle_user_exception(e)
  File "/usr/local/lib/python3.6/site-packages/flask/app.py", line 1516, in full_dispatch_request
    rv = self.dispatch_request()
  File "/usr/local/lib/python3.6/site-packages/flask/app.py", line 1502, in dispatch_request
    return self.ensure_sync(self.view_functions[rule.endpoint])(**req.view_args)
  File "/usr/local/lib/python3.6/site-packages/flask_login/utils.py", line 272, in decorated_view
    return func(*args, **kwargs)
  File "/app/kijiji_manager/views/ad.py", line 72, in post
    category_form.cat1.choices = [(cat['@id'], cat['cat:id-name']) for cat in kijiji_api.get_categories(current_user.id, current_user.token)['cat:categories']['cat:category']['cat:category']]
  File "/app/kijiji_manager/kijijiapi.py", line 132, in get_categories
    r = self.session.get(f'{self.base_url}/categories', headers=headers)
  File "/usr/local/lib/python3.6/site-packages/httpx/_client.py", line 1034, in get
    extensions=extensions,
  File "/usr/local/lib/python3.6/site-packages/httpx/_client.py", line 802, in request
    return self.send(request, auth=auth, follow_redirects=follow_redirects)
  File "/usr/local/lib/python3.6/site-packages/httpx/_client.py", line 893, in send
    history=[],
  File "/usr/local/lib/python3.6/site-packages/httpx/_client.py", line 920, in _send_handling_auth
    history=history,
  File "/usr/local/lib/python3.6/site-packages/httpx/_client.py", line 954, in _send_handling_redirects
    response = self._send_single_request(request)
  File "/usr/local/lib/python3.6/site-packages/httpx/_client.py", line 990, in _send_single_request
    response = transport.handle_request(request)
  File "/usr/local/lib/python3.6/site-packages/httpx/_transports/default.py", line 187, in handle_request
    resp = self._pool.handle_request(req)
  File "/usr/local/lib/python3.6/contextlib.py", line 99, in __exit__
    self.gen.throw(type, value, traceback)
  File "/usr/local/lib/python3.6/site-packages/httpx/_transports/default.py", line 77, in map_httpcore_exceptions
    raise mapped_exc(message) from exc
httpx.ReadTimeout: The read operation timed out

[ghost]

Trying to repost again and receiving in the browser (same ad and same photos as above post):

One of your images is not on an accepted service. Please upload your images again.

[jackm]

I will change branch and deploy the docker container. However, below error is from today (on main branch) when a script I use to repost the ads was run. It appears one of my ads was never reposted. I manually had to go in afterwards and do so by posting the XML file. Hopefully this branch has the fix.

This would be because when reposting an ad, it first deletes the old ad, then posts the same ad again. Because of the timeout it failed to post the ad after first deleting the original, which is why it doesn't appear on Kijiji after.

Okay, I checked out the gunicorn-timeout branch, rebuilt the image and ran the container.

The logs for this attempt show that it timed out waiting for a response after an HTTP GET request for the Kijiji categories (API endpoint https://mingle.kijiji.ca/api/categories). This happens to be the first HTTP request made when posting an ad. This GET request should be pretty quick - the response data is only about 150KB total size. I'm not sure why this would be happening, but it seems as though the connection between you and the Kijiji servers is either dropping out or Kijiji just took way to long to respond back.

Trying to repost again and receiving in the browser (same ad and same photos as above post):

One of your images is not on an accepted service. Please upload your images again.

I would check the image URLs found in the ad payload xml file. kijiji-manager should have automatically translated the URLs to be ones under the media.kijiji.ca domain, so check and verify that is true. If the image URLs are under a different domain then Kijiji will likely reject the ad post.

[dudududodododedede]

I also just started receiving timeout errors today I'm not running in Docker, just in a Mac virtualenv I'm also seeing the timeouts not just when attempting submit a post, also when just attempting to load the "post' page The timeouts are intermittent. If I try again it usually works. Seems to fail about 20% of the time

From logs:

127.0.0.1 - - [13/Jul/2022 14:08:31] "GET /post HTTP/1.1" 500 -
Traceback (most recent call last):
  File "/Users/user/Downloads/kijiji-manager/venv/lib/python3.9/site-packages/httpcore/_exceptions.py", line 8, in map_exceptions
    yield
  File "/Users/user/Downloads/kijiji-manager/venv/lib/python3.9/site-packages/httpcore/backends/sync.py", line 26, in read
    return self._sock.recv(max_bytes)
  File "/usr/local/Cellar/python@3.9/3.9.6/Frameworks/Python.framework/Versions/3.9/lib/python3.9/ssl.py", line 1226, in recv
    return self.read(buflen)
  File "/usr/local/Cellar/python@3.9/3.9.6/Frameworks/Python.framework/Versions/3.9/lib/python3.9/ssl.py", line 1101, in read
    return self._sslobj.read(len)
socket.timeout: The read operation timed out

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/Users/user/Downloads/kijiji-manager/venv/lib/python3.9/site-packages/httpx/_transports/default.py", line 60, in map_httpcore_exceptions
    yield
  File "/Users/user/Downloads/kijiji-manager/venv/lib/python3.9/site-packages/httpx/_transports/default.py", line 218, in handle_request
    resp = self._pool.handle_request(req)
  File "/Users/user/Downloads/kijiji-manager/venv/lib/python3.9/site-packages/httpcore/_sync/connection_pool.py", line 244, in handle_request
    raise exc
  File "/Users/user/Downloads/kijiji-manager/venv/lib/python3.9/site-packages/httpcore/_sync/connection_pool.py", line 228, in handle_request
    response = connection.handle_request(request)
  File "/Users/user/Downloads/kijiji-manager/venv/lib/python3.9/site-packages/httpcore/_sync/connection.py", line 90, in handle_request
    return self._connection.handle_request(request)
  File "/Users/user/Downloads/kijiji-manager/venv/lib/python3.9/site-packages/httpcore/_sync/http11.py", line 102, in handle_request
    raise exc
  File "/Users/user/Downloads/kijiji-manager/venv/lib/python3.9/site-packages/httpcore/_sync/http11.py", line 81, in handle_request
    ) = self._receive_response_headers(**kwargs)
  File "/Users/user/Downloads/kijiji-manager/venv/lib/python3.9/site-packages/httpcore/_sync/http11.py", line 143, in _receive_response_headers
    event = self._receive_event(timeout=timeout)
  File "/Users/user/Downloads/kijiji-manager/venv/lib/python3.9/site-packages/httpcore/_sync/http11.py", line 172, in _receive_event
    data = self._network_stream.read(
  File "/Users/user/Downloads/kijiji-manager/venv/lib/python3.9/site-packages/httpcore/backends/sync.py", line 26, in read
    return self._sock.recv(max_bytes)
  File "/usr/local/Cellar/python@3.9/3.9.6/Frameworks/Python.framework/Versions/3.9/lib/python3.9/contextlib.py", line 135, in __exit__
    self.gen.throw(type, value, traceback)
  File "/Users/user/Downloads/kijiji-manager/venv/lib/python3.9/site-packages/httpcore/_exceptions.py", line 12, in map_exceptions
    raise to_exc(exc)
httpcore.ReadTimeout: The read operation timed out

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

Traceback (most recent call last):
  File "/Users/user/Downloads/kijiji-manager/venv/lib/python3.9/site-packages/flask/app.py", line 2088, in __call__
    return self.wsgi_app(environ, start_response)
  File "/Users/user/Downloads/kijiji-manager/venv/lib/python3.9/site-packages/flask/app.py", line 2073, in wsgi_app
    response = self.handle_exception(e)
  File "/Users/user/Downloads/kijiji-manager/venv/lib/python3.9/site-packages/flask/app.py", line 2070, in wsgi_app
    response = self.full_dispatch_request()
  File "/Users/user/Downloads/kijiji-manager/venv/lib/python3.9/site-packages/flask/app.py", line 1515, in full_dispatch_request
    rv = self.handle_user_exception(e)
  File "/Users/user/Downloads/kijiji-manager/venv/lib/python3.9/site-packages/flask/app.py", line 1513, in full_dispatch_request
    rv = self.dispatch_request()
  File "/Users/user/Downloads/kijiji-manager/venv/lib/python3.9/site-packages/flask/app.py", line 1499, in dispatch_request
    return self.ensure_sync(self.view_functions[rule.endpoint])(**req.view_args)
  File "/Users/user/Downloads/kijiji-manager/venv/lib/python3.9/site-packages/flask_login/utils.py", line 272, in decorated_view
    return func(*args, **kwargs)
  File "/Users/user/Downloads/kijiji-manager/venv/lib/python3.9/site-packages/kijiji_manager/views/ad.py", line 74, in post
    category_form.cat1.choices = [(cat['@id'], cat['cat:id-name']) for cat in kijiji_api.get_categories(current_user.id, current_user.token)['cat:categories']['cat:category']['cat:category']]
  File "/Users/user/Downloads/kijiji-manager/venv/lib/python3.9/site-packages/kijiji_manager/kijijiapi.py", line 137, in get_categories
    r = self.session.get(f'{self.base_url}/categories', headers=headers)
  File "/Users/user/Downloads/kijiji-manager/venv/lib/python3.9/site-packages/httpx/_client.py", line 1025, in get
    return self.request(
  File "/Users/user/Downloads/kijiji-manager/venv/lib/python3.9/site-packages/httpx/_client.py", line 802, in request
    return self.send(request, auth=auth, follow_redirects=follow_redirects)
  File "/Users/user/Downloads/kijiji-manager/venv/lib/python3.9/site-packages/httpx/_client.py", line 889, in send
    response = self._send_handling_auth(
  File "/Users/user/Downloads/kijiji-manager/venv/lib/python3.9/site-packages/httpx/_client.py", line 917, in _send_handling_auth
    response = self._send_handling_redirects(
  File "/Users/user/Downloads/kijiji-manager/venv/lib/python3.9/site-packages/httpx/_client.py", line 954, in _send_handling_redirects
    response = self._send_single_request(request)
  File "/Users/user/Downloads/kijiji-manager/venv/lib/python3.9/site-packages/httpx/_client.py", line 990, in _send_single_request
    response = transport.handle_request(request)
  File "/Users/user/Downloads/kijiji-manager/venv/lib/python3.9/site-packages/httpx/_transports/default.py", line 218, in handle_request
    resp = self._pool.handle_request(req)
  File "/usr/local/Cellar/python@3.9/3.9.6/Frameworks/Python.framework/Versions/3.9/lib/python3.9/contextlib.py", line 135, in __exit__
    self.gen.throw(type, value, traceback)
  File "/Users/user/Downloads/kijiji-manager/venv/lib/python3.9/site-packages/httpx/_transports/default.py", line 77, in map_httpcore_exceptions
    raise mapped_exc(message) from exc
httpx.ReadTimeout: The read operation timed out

If I'm reading the logs correctly, my failures are also happening during get_categories

I'm on the master branch

[jackm]

This is puzzling as I cannot seem to recreate the issue on my end.

For example, every time I make a GET request for the get_categories API, it takes on average 0.5 seconds to complete the request. Uploading two images (650KB combined) takes around 3 seconds, and posting an ad payload takes about 1 second to respond. If it is taking longer than even 30 seconds that seems abnormal - longer than 2 minutes (e.g. when using the gunicorn-timeout branch) is ridiculously long.

[jackm]

The only cause I can come up with to explain this issue is something to do with the users network connection between them and the Kijiji servers, causing abnormally long response times and/or dropped or missing packets. Closing this.