superset icon indicating copy to clipboard operation
superset copied to clipboard

unknown error from gunicorn thrown (in logfile) if authlib is used: "ValueError: count must be a positive integer (got 0)"

Open nigzak opened this issue 3 years ago • 4 comments

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", []),
		}
        

nigzak avatar Jul 19 '22 12:07 nigzak

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 ?

sfirke avatar Jul 21 '22 15:07 sfirke

I'm getting the same, any workarounds?

korjavin avatar Aug 26 '22 10:08 korjavin

Gunicorn fix: https://github.com/benoitc/gunicorn/issues/2692.

dharmic6 avatar Sep 09 '22 22:09 dharmic6

i got this error too, how to fix it in docker?

skyonedot avatar Sep 18 '22 11:09 skyonedot

@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

mlmaverick avatar Oct 06 '22 07:10 mlmaverick

@kgopal492 do we need to pull https://github.com/pinterest/superset/pull/11 against master to resolve this issue?

rusackas avatar Jan 12 '23 15:01 rusackas

@kgopal492 do we need to pull pinterest#11 against master to resolve this issue? @rusackas while https://github.com/pinterest/superset/pull/11 fixes it, its not ideal as it pulls gunicorn at master instead 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

philicious avatar Apr 28 '23 15:04 philicious

@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

goen74 avatar May 22 '23 06:05 goen74

I have updates to superset version 3.0.2 but the bug is still present

cooervo avatar Jan 03 '24 19:01 cooervo

@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 avatar Jan 03 '24 20:01 philicious

@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 )
image

In k9s I'm confirming image is 3.0.2:

image

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 avatar Jan 03 '24 20:01 cooervo

@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 avatar Jan 03 '24 21:01 philicious

@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 avatar Jan 03 '24 21:01 cooervo

@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

philicious avatar Jan 04 '24 02:01 philicious

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.

rusackas avatar Feb 01 '24 20:02 rusackas