unknown error from gunicorn thrown (in logfile) if authlib is used: "ValueError: count must be a positive integer (got 0)"
the issue is only visible to me in the logfile - unclear if there are more impacts => there is no logging available where I can see more - I even activated DEBUG level and nothing is being added
How to reproduce the bug
pull latest images from dockerhub docker pull apache/superset:1.5.1 start container add authlib (pip install authlib - for me its 1.0.1) add configuration for oauth initialize container start container login
Expected results
no error visible
Actual results
...
::1 - - [19/Jul/2022:12:44:29 +0000] "GET /static/appbuilder/datepicker/bootstrap-datepicker.css HTTP/1.1" 200 863 "https://superset.localhost/users/list/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/103.0.0.0 Safari/537.36"
::1 - - [19/Jul/2022:12:44:29 +0000] "GET /static/appbuilder/css/font-awesome.min.css HTTP/1.1" 200 6977 "https://superset.localhost/users/list/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/103.0.0.0 Safari/537.36"
::1 - - [19/Jul/2022:12:44:29 +0000] "GET /static/appbuilder/css/ab.css HTTP/1.1" 200 282 "https://superset.localhost/users/list/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/103.0.0.0 Safari/537.36"
::1 - - [19/Jul/2022:12:44:29 +0000] "GET /static/appbuilder/css/bootstrap.min.css HTTP/1.1" 200 20335 "https://superset.localhost/users/list/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/103.0.0.0 Safari/537.36"
::1 - - [19/Jul/2022:12:44:29 +0000] "GET /static/appbuilder/css/flags/flags16.css HTTP/1.1" 200 1460 "https://superset.localhost/users/list/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/103.0.0.0 Safari/537.36"
::1 - - [19/Jul/2022:12:44:29 +0000] "GET /static/assets/theme.040143a715177735b3e5.entry.css HTTP/1.1" 200 87037 "https://superset.localhost/users/list/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/103.0.0.0 Safari/537.36"
[2022-07-19 12:44:29 +0000] [10] [ERROR] Error handling request
Traceback (most recent call last):
File "/usr/local/lib/python3.8/site-packages/gunicorn/workers/gthread.py", line 326, in handle_request
resp.write_file(respiter)
File "/usr/local/lib/python3.8/site-packages/gunicorn/http/wsgi.py", line 385, in write_file
if not self.sendfile(respiter):
File "/usr/local/lib/python3.8/site-packages/gunicorn/http/wsgi.py", line 375, in sendfile
self.sock.sendfile(respiter.filelike, count=nbytes)
File "/usr/local/lib/python3.8/socket.py", line 482, in sendfile
return self._sendfile_use_sendfile(file, offset, count)
File "/usr/local/lib/python3.8/socket.py", line 346, in _sendfile_use_sendfile
self._check_sendfile_params(file, offset, count)
File "/usr/local/lib/python3.8/socket.py", line 460, in _check_sendfile_params
raise ValueError(
ValueError: count must be a positive integer (got 0)
::1 - - [19/Jul/2022:12:44:29 +0000] "GET /static/assets/7550.0cfaa3644756c68a9121.entry.js HTTP/1.1" 200 4655 "https://superset.localhost/users/list/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/103.0.0.0 Safari/537.36"
::1 - - [19/Jul/2022:12:44:29 +0000] "GET /static/assets/2102.845d152f4a59b751bb85.entry.js HTTP/1.1" 200 11485 "https://superset.localhost/users/list/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/103.0.0.0 Safari/537.36"
::1 - - [19/Jul/2022:12:44:29 +0000] "GET /static/assets/4998.93793b600cc2e5a5e93b.entry.js HTTP/1.1" 200 13740 "https://superset.localhost/users/list/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/103.0.0.0 Safari/537.36"
::1 - - [19/Jul/2022:12:44:29 +0000] "GET /static/assets/preamble.1bf7b5219f08ba7b95c9.entry.js HTTP/1.1" 200 864 "https://superset.localhost/users/list/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/103.0.0.0 Safari/537.36"
::1 - - [19/Jul/2022:12:44:29 +0000] "GET /static/assets/9525.3bcd1d5086bb0c969860.entry.js HTTP/1.1" 200 16302 "https://superset.localhost/users/list/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/103.0.0.0 Safari/537.36"
::1 - - [19/Jul/2022:12:44:29 +0000] "GET /static/assets/1334.68738edb2dbfd30fd357.entry.js HTTP/1.1" 200 57462 "https://superset.localhost/users/list/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/103.0.0.0 Safari/537.36"
...
Screenshots
NOT AVAILABLE - no error visible in UI
Environment
(please complete the following information):
- browser type and version: actual CHROME
- superset version: 1.5.1 + authlib 1.0.1
- any feature flags active: NO
Checklist
Make sure to follow these steps before submitting your issue - thank you!
- [x] I have checked the superset logs for python stacktraces and included it here as text if there are any.
- [x] I have reproduced the issue with at least the latest released version of superset.
- [x] I have checked the issue tracker for the same issue and I haven't found one similar.
Additional context
superset_config.py
from flask_appbuilder.security.manager import AUTH_OID,AUTH_REMOTE_USER,AUTH_DB, AUTH_LDAP, AUTH_OAUTH
from celery.schedules import crontab
import os
from custom_sso_security_manager import CustomSsoSecurityManager
CUSTOM_SECURITY_MANAGER = CustomSsoSecurityManager
basedir = os.path.abspath(os.path.dirname(__file__))
SUPERSET_WORKERS = 1
# AUTHENTIFICATION STUFF ---------------------------------------------------------------------------
OIDCCID="XXXX"
OIDCCS="YYYY"
CSRF_ENABLED = True
AUTH_TYPE = AUTH_OAUTH
AUTH_USER_REGISTRATION = True
AUTH_ROLES_MAPPING = {
"XXX": ["XXX"],
"YYYY": ["YYYY"],
"ZZZZ": ["Admin"]
}
AUTH_ROLES_SYNC_AT_LOGIN = True
PERMANENT_SESSION_LIFETIME = 600
OAUTH_PROVIDERS = [
{
'name': 'REMOVED',
'icon': 'REMOVED',
'token_key': 'access_token',
'remote_app': {
'client_id': OIDCCID,
'client_secret': OIDCCS,
'api_base_url': 'REMOVED',
'client_kwargs':{
'scope': 'openid email profile authorization_group entitlement_group scoped_entitlement offline_access'
},
'access_token_url': 'REMOVED',
'refresh_token_url' : 'REMOVED',
'api_base_url':'https://localhost',
'code_challenge_method':'S256',
'authorize_url' : 'REMOVED',
'jwks_uri': 'REMOVED'
}
}
]
ENABLE_PROXY_FIX = True
PREFERRED_URL_SCHEME = 'https'
# Console Log Settings
DATA_DIR = os.path.join(os.path.expanduser('~'), '.superset')
if not os.path.exists(DATA_DIR):
os.makedirs(DATA_DIR)
LOG_FORMAT = '%(asctime)s:%(levelname)s:%(name)s:%(message)s'
LOG_LEVEL = 'DEBUG'
# ---------------------------------------------------
# Enable Time Rotate Log Handler
# ---------------------------------------------------
# LOG_LEVEL = DEBUG, INFO, WARNING, ERROR, CRITICAL
ENABLE_TIME_ROTATE = False
TIME_ROTATE_LOG_LEVEL = 'DEBUG'
FILENAME = os.path.join(DATA_DIR, 'superset.log')
ROLLOVER = 'midnight'
INTERVAL = 1
BACKUP_COUNT = 30
cusotm_sso_security_manager.py
from superset.security import SupersetSecurityManager
import logging
class CustomSsoSecurityManager(SupersetSecurityManager):
def oauth_user_info(self, provider, response=None):
access_token = response["access_token"]
headers = {'Authorization': 'Bearer %s' % (access_token)}
me = self.appbuilder.sm.oauth_remotes[provider].get("REMOVED", headers=headers)
data = me.json()
logging.debug("User info from REMOVED: %s", data)
logging.debug("Entitlements: %s", data.get("entitlement_group", []))
return {
"username": data.get("sub", ""),
"first_name": data.get("given_name", ""),
"last_name": data.get("family_name", ""),
"email": data.get("email", ""),
"role_keys": data.get("entitlement_group", []),
}
I'm seeing this in my logs too, though I'm not using authlib. Maybe related to https://stackoverflow.com/questions/68219233/run-flask-with-gunicorn-got-error-handling-request-count-must-be-a-positive-in ?
I'm getting the same, any workarounds?
Gunicorn fix: https://github.com/benoitc/gunicorn/issues/2692.
i got this error too, how to fix it in docker?
@skyonedot for now add this to your dockerfile after you have installed superset.
RUN pip install --force-reinstall git+https://github.com/benoitc/gunicorn.git@master
@kgopal492 do we need to pull https://github.com/pinterest/superset/pull/11 against master to resolve this issue?
@kgopal492 do we need to pull pinterest#11 against
masterto resolve this issue? @rusackas while https://github.com/pinterest/superset/pull/11 fixes it, its not ideal as it pulls gunicorn atmasterinstead of a fixed version. using the git SHA of master^HEAD would be better. best would be for gunicorn to release a new version which could then be used as minimum requirement in python
@skyonedot for now add this to your dockerfile after you have installed superset.
RUN pip install --force-reinstall git+https://github.com/benoitc/gunicorn.git@master
I solved my problem with the above command. I no longer get errors
I have updates to superset version 3.0.2 but the bug is still present
@cooervo thats odd. the bug is supposed to be fixed in gunicorn 21.x and that dependency got updated in https://github.com/apache/superset/pull/25313 , ~so 3.0.2 should contain it~ Update: 3.1.0 will contain it
@philicious
Just double checked indeed it's there this is the error I get in GKE:
ValueError: count must be a positive integer (got 0)
at ._check_sendfile_params ( /usr/local/lib/python3.8/socket.py:460 )
at ._sendfile_use_sendfile ( /usr/local/lib/python3.8/socket.py:346 )
at .sendfile ( /usr/local/lib/python3.8/socket.py:482 )
at .sendfile ( /usr/local/lib/python3.8/site-packages/gunicorn/http/wsgi.py:375 )
at .write_file ( /usr/local/lib/python3.8/site-packages/gunicorn/http/wsgi.py:385 )
at .handle_request ( /usr/local/lib/python3.8/site-packages/gunicorn/workers/gthread.py:326 )
In k9s I'm confirming image is 3.0.2:
If I check the pod I see old gunicorn is installed in base.txt:
/app/requirements# cat base.txt | grep "guni"
gunicorn==20.1.0
@cooervo uhm ye, seems its not yet in 3.0.2 https://github.com/apache/superset/blob/3.0.2/requirements/base.txt but will be on 3.1.0
I for myself am still on 3.0.0 and have a pip install gunicorn==21.2.0 in my helm config:
bootstrapScript: |
#!/bin/bash
pip install psycopg2==2.9.1 \
Authlib==1.0.1 \
sqlalchemy-bigquery==1.5.0 \
elasticsearch-dbapi==0.2.9 \
gunicorn==21.2.0
@philicious thanks for further help.
So am a bit confused I see it present on branch = 3.1 https://github.com/apache/superset/blob/3.1/requirements/base.txt
But can't find it in any tag. trying to target a valid docker image tag with gunicorn >= 21
@cooervo you can use e.g. docker tag 3.1.0rc3 (or any other git Tag as docker tag)
https://hub.docker.com/layers/apache/superset/3.1.0rc3/images/sha256-3789d5a14b95c2cec653e5e030a64939a84dbebdc0029c0ee25874498d16663c?context=explore
Closing this out since it's out in 3.1.0, which is official at this point. If there's more to be done, I'd suggest regrouping on a fresh Issue.