jet-admin / jet-django

Jet Bridge (Django) for Jet Admin – Admin panel framework for your application
https://app.jetadmin.io/demo
Other
192 stars 32 forks source link

Zappa AWS Lambda - {"message": "Endpoint request timed out"} - Task timed out - Forbidden: /jet_api/model_descriptions/ #4

Closed Vadorequest closed 5 years ago

Vadorequest commented 5 years ago

I have deployed my API but I get the following

{"detail":"You do not have permission to perform this action."}

https://0fkluarvo2.execute-api.eu-west-1.amazonaws.com/staging/jet_api/model_descriptions/

I really don't understand what is wrong, I have a minimal setup with a db.sqlite3 database and not much besides that. It was working fine then broke at some point.

f1nality commented 5 years ago

Looks like there is a problem with packets going from AWS to jet server. We are investigating this issue now.

Vadorequest commented 5 years ago

😢

I wasted hours trying to figure out what's wrong, could you please improve the error messages so at least we know it's not related to our app? It'd help avoid wasting so much time and report the issue directly to you.

Something like "Oops, something went wrong on Jet Admin http://jetadmin.io, we're investigating the issue. This error is most likely not related to your app, report additional info on Github" either in the log or server response, etc.

Vadorequest commented 5 years ago

Also, this is a major issue because it totally broke my entire app. I couldn't run migrations anymore because of this.

Jet Admin should make sure that if something broke on your side, or isn't working correctly at least it wouldn't kill the whole app. I'm planning on building a CMS with Jet Django, running in parallel with an API powered by Django itself. Those are two distinct things and I can't have the CMS kill the API because something went wrong somewhere, especially if it's something on your side I have no control over.

If the CMS breaks, then so be it, it's bad enough as it is. But if it kills the API in the process then it's much much worse.

f1nality commented 5 years ago

@Vadorequest JET can't kill your app. It just adds some new API endpoints and 1 new table. It does not do anything else to your application

Vadorequest commented 5 years ago

That's what I thought too, but the thing is, it does.

If I enable the following lines in my Django app:

# INSTALLED_APPS
  'jet_django',  # XXX See https://docs.jetadmin.io

# urls.py
from jet_django.urls import jet_urls
  url(r'^jet_api/', include(jet_urls)),  # XXX See https://docs.jetadmin.io

Then my endpoint https://0fkluarvo2.execute-api.eu-west-1.amazonaws.com/staging/admin returns a 504 with {"message": "Endpoint request timed out"}

If I disable those same lines, my app run correctly. (without jet_api endpoint, of course)

So, it does break my app because the connection times-out and the request gets stopped.


Here are some logs:

[1551292050162] Instancing..
[1551292054798] [DEBUG] 2019-02-27T18:27:34.798Z a78e9fad-dbf9-4a54-a933-9e3c1da3c01b Starting new HTTPS connection (1): api.jetadmin.io:443
[1551292073207] 2019-02-27T18:27:53.207Z 6dfb3557-ab08-4bf1-846e-cd19977b0e08 Task timed out after 30.03 seconds
[1551292080192] 2019-02-27T18:28:00.192Z a78e9fad-dbf9-4a54-a933-9e3c1da3c01b Task timed out after 30.03 seconds
[1551292081470] Instancing..
[1551292086261] [DEBUG] 2019-02-27T18:28:06.261Z 0a69b51d-5061-4f15-94a0-6c47b0b8ed05 Starting new HTTPS connection (1): api.jetadmin.io:443

To my understanding, Django fails to start and keep restarting because it timeouts when trying to reach api.jetadmin.io. Because of this, it never starts, it keeps hanging. That's why the app is broken, because it cannot start at all.

f1nality commented 5 years ago

@Vadorequest hm, i'm trying to investigate it. Here is the line which makes connection to Jet backend and times out:

jet_django/apps.py

...
        try:
            register_token()
        except:  # if no migrations yet
            pass
...

There is try-except block which should bypass any errors, thought there is a 30s delay in startup since it trying to connect. So after 30s your app should launch any way, I don't see errors in your log output which may lead to crash.

f1nality commented 5 years ago

By the way, problem with AWS servers requires us to move our servers, this issue will be resolving this Sunday.

Vadorequest commented 5 years ago

Ahah, that's why it fails on my setup!

I use Zappa to power my Django app, and Zappa is basically a layer around AWS Lambda. The point is, I run on AWS Lambda and a Lambda has a ... 30 sec hard timeout.

So, since your own default timeout is 30sec, it waits too long and the Lambda timeout is reached, which kills the process, and try again.

There are two ways to resolve this issue:

In any case, this behaviour should be documented in the README because it will impact all kind of Serverless-based environment apps. And if people are not aware of this, then it'll work fine until everything breaks at once, if it's not lambda-friendly by design.

f1nality commented 5 years ago

@Vadorequest i'm trying to reproduce this issue, but without success. I've setup an eu-west-1 (EU Ireland) EC2 AWS server and tried to get api.jetadmin.io page:

wget https://api.jetadmin.io/api/

It downloaded successfully. I've tried to execute https request to https://api.jetadmin.io/api/ with AWS Lambda service - also worked.

Could you please run this command on your server too? Maybe its something with permission/policies on your configuration?

Vadorequest commented 5 years ago

It's not related to permission/policies since it had worked the day before and nothing has changed on my setup about that. (also, I'm running my tests with full AWS administrator access)

I'll try again.

f1nality commented 5 years ago

@Vadorequest can we continue in some messenger to resolve this issue quicker? Skype, whatsapp, telegram? If so, please write me your contacts (on my email if you don't want to write it here)

Vadorequest commented 5 years ago

I sent you an email at denis at kildishev.ru

Vadorequest commented 5 years ago

I just tried again and I have a new error message when the Lambda starts using zappa tail

[1551604285683] Instancing..
[1551604291218] Application starting with ENV: staging
[1551604291718] bad magic number in 'jet_django': b'\x03\xf3\r\n': ImportError
Traceback (most recent call last):
  File "/var/task/handler.py", line 580, in lambda_handler
  return LambdaHandler.lambda_handler(event, context)
  File "/var/task/handler.py", line 245, in lambda_handler
  handler = cls()
  File "/var/task/handler.py", line 151, in __init__
  wsgi_app_function = get_django_wsgi(self.settings.DJANGO_SETTINGS)
  File "/var/task/zappa/ext/django_zappa.py", line 20, in get_django_wsgi
  return get_wsgi_application()
  File "/var/task/django/core/wsgi.py", line 12, in get_wsgi_application
  django.setup(set_prefix=False)
  File "/var/task/django/__init__.py", line 24, in setup
  apps.populate(settings.INSTALLED_APPS)
  File "/var/task/django/apps/registry.py", line 89, in populate
  app_config = AppConfig.create(entry)
  File "/var/task/django/apps/config.py", line 90, in create
  module = import_module(entry)
  File "/var/lang/lib/python3.6/importlib/__init__.py", line 126, in import_module
  return _bootstrap._gcd_import(name[level:], package, level)
  File "<frozen importlib._bootstrap>", line 994, in _gcd_import
  File "<frozen importlib._bootstrap>", line 971, in _find_and_load
  File "<frozen importlib._bootstrap>", line 955, in _find_and_load_unlocked
  File "<frozen importlib._bootstrap>", line 665, in _load_unlocked
  File "<frozen importlib._bootstrap_external>", line 674, in exec_module
  File "<frozen importlib._bootstrap_external>", line 888, in get_code
  File "<frozen importlib._bootstrap_external>", line 455, in _validate_bytecode_header
ImportError: bad magic number in 'jet_django': b'\x03\xf3\r\n'

Seems to be related with file zappa/ext/django_zappa.py

Error message printed on the lambda at https://jugzryz6zi.execute-api.eu-west-1.amazonaws.com/staging/

{
    'message': 'An uncaught exception happened while servicing this request. You can investigate this with the `zappa tail` command.',
    'traceback': ['Traceback (most recent call last):\\n', '  File \"/var/task/handler.py\", line 518, in handler\\n    response = Response.from_app(self.wsgi_app, environ)\\n', '  File \"/var/task/werkzeug/wrappers.py\", line 939, in from_app\\n    return cls(*_run_wsgi_app(app, environ, buffered))\\n', '  File \"/var/task/werkzeug/test.py\", line 923, in run_wsgi_app\\n    app_rv = app(environ, start_response)\\n', \"TypeError: 'NoneType' object is not callable\\n\"]}
Vadorequest commented 5 years ago

The issue with ImportError: bad magic number in 'jet_django': b'\x03\xf3\r\n' was related to https://github.com/Miserlou/Zappa/issues/854 and was fixed by doing a find . -name \*.pyc -delete from the project root.

Vadorequest commented 5 years ago

Alright, time for a summary on this (those issues):

  1. I tried to access https://0fkluarvo2.execute-api.eu-west-1.amazonaws.com/staging/jet_api/model_descriptions/ directly from the browser and got {"detail":"You do not have permission to perform this action."}: This is normal because the endpoint requires an authentication, provided by Headers, and therefore not possible to just go to that url through the browser. That was not a real issue but the expected behaviour.

  2. I tried to access https://0fkluarvo2.execute-api.eu-west-1.amazonaws.com/staging/admin and got a 504 {"message": "Endpoint request timed out"}:
    This was because my Lambda runs inside a VPC and was not allowed to connect to internet. This was very difficult to troubleshot and this error should be more obvious. Thanks to @f1nality who helped me pinpoint the issue, I wasn't aware of this limitation since it's the first time I use Lambda inside a VPC (which is required to connect to AWS RDS Aurora) Figuring out the Lambda couldn't talk to the Jet API took us a good ~90mn, not so obvious indeed.

Here is the script I used to "ping" external services from inside AWS Lambda: https://gist.github.com/Vadorequest/aff8e9ce2dcc4c67637a34f567190825

Proof it works now (ping from lambda) ```bash zappa manage staging ping [START] RequestId: b0f50286-72a3-4cca-95df-98c34814e75a Version: $LATEST [DEBUG] 2019-03-03T23:12:31.647Z b0f50286-72a3-4cca-95df-98c34814e75a Zappa Event: {'manage': 'ping'} HTTP Error 404: Not Found: HTTPError Traceback (most recent call last): File "/var/task/handler.py", line 580, in lambda_handler return LambdaHandler.lambda_handler(event, context) File "/var/task/handler.py", line 248, in lambda_handler return handler.handler(event, context) File "/var/task/handler.py", line 413, in handler management.call_command(*event['manage'].split(' ')) File "/var/task/django/core/management/__init__.py", line 148, in call_command return command.execute(*args, **defaults) File "/var/task/django/core/management/base.py", line 353, in execute output = self.handle(*args, **options) File "/var/task/scripts/management/commands/ping.py", line 25, in handle print(urllib.request.urlopen(address).read()) File "/var/lang/lib/python3.6/urllib/request.py", line 223, in urlopen return opener.open(url, data, timeout) File "/var/lang/lib/python3.6/urllib/request.py", line 532, in open response = meth(req, response) File "/var/lang/lib/python3.6/urllib/request.py", line 642, in http_response 'http', request, response, code, msg, hdrs) File "/var/lang/lib/python3.6/urllib/request.py", line 570, in error return self._call_chain(*args) File "/var/lang/lib/python3.6/urllib/request.py", line 504, in _call_chain result = func(*args) File "/var/lang/lib/python3.6/urllib/request.py", line 650, in http_error_default raise HTTPError(req.full_url, code, msg, hdrs, fp) urllib.error.HTTPError: HTTP Error 404: Not Found [END] RequestId: b0f50286-72a3-4cca-95df-98c34814e75a [REPORT] RequestId: b0f50286-72a3-4cca-95df-98c34814e75a Duration: 592.32 ms Billed Duration: 600 ms Memory Size: 128 MB Max Memory Used: 57 MB Error: Unhandled error occurred while invoking command. ``` Getting a 404 proves the endpoint was reached.

Resolving the issue, by allowing the Lambda to reach the internet took me several hours (like, almost 6h...), it's very hard, error-prone and technically complex to understand:

I don't know how that could be done, but giving even the slightest indication that internet isn't accessible would tremendously help developers going through this and are unaware of the Lambda/VPC closed network thing.

Due to the fact that the Lambda couldn't reach the api.jetadmin.io, and there was no custom timeout on my side, this issue led to crash the whole application, because the Lambda would automatically timeout after 30 seconds. This unknown behaviour was also very difficult to figure out.

  1. There were no permission/credentials issues, I'm using a FullAdministrator user
  2. I also ran into ImportError: bad magic number in 'jet_django': b'\x03\xf3\r\n' which was totally unrelated. Most likely because I had moved folders in my app and the .pyc files were outdated. See https://github.com/jet-admin/jet-django/issues/4#issuecomment-469009309
  3. Now that the Lambda/VPC issue is resolved, I encountered more 😄 django.db.utils.ProgrammingError: (1146, "Table 'tfp_backoffice_test.jet_django_token' doesn't exist") I had forgotten to run the migrations because the app wasn't activated. Was fixed by running migrations.
  4. At this point, the app seemed to work (I refreshed my https://app.jetadmin.io/app/tfp_backoffice/project/models and it displayed my models) but it only worked a few minutes. I don't know if it really worked or loaded a cached version of the models. But I experienced the Forbidden: /staging/jet_api/model_descriptions/ again.
Server logs ``` [1551650905195] django.db.utils.ProgrammingError: (1146, "Table 'tfp_backoffice_test.jet_django_token' doesn't exist") [1551650905195] Internal Server Error: /staging/jet_api/model_descriptions/ [1551650905195] [ERROR] 2019-03-03T22:08:25.195Z 2e45e790-be99-48b1-96ee-152f25aa0b3a Internal Server Error: /staging/jet_api/model_descriptions/ [1551650905214] [INFO] 2019-03-03T22:08:25.196Z 2e45e790-be99-48b1-96ee-152f25aa0b3a 82.255.108.108 - - [03/Mar/2019:22:08:25 +0000] "GET /jet_api/model_descriptions/ HTTP/1.1" 500 25 "https://app.jetadmin.io/app/tfp_backoffice" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_2) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.119 Safari/537.36" 0/43.839999999999996 [1551650905354] Operations to perform: [1551650905354] Apply all migrations: admin, auth, campus, contenttypes, dashboard, institution, jet, jet_django, org, sessions, student_solution [1551650905634] Running migrations: [1551650906103] Applying jet_django.0001_initial... OK [1551650906356] [DEBUG] 2019-03-03T22:08:26.356Z f88fee0f-2d29-461d-8e80-39c500788ff4 Zappa Event: {'resource': '/{proxy+}', 'path': '/jet_api/model_descriptions/', 'httpMethod': 'GET', 'headers': {'Accept': 'application/json, text/plain, */*', 'accept-encoding': 'gzip, deflate, br', 'Accept-Language': 'fr,en;q=0.9,en-GB;q=0.8,en-US;q=0.7,de;q=0.6', 'Authorization': 'Token 5060dc19ef9a9f364fbf282cf12d5006c2a08e97', 'CloudFront-Forwarded-Proto': 'https', 'CloudFront-Is-Desktop-Viewer': 'true', 'CloudFront-Is-Mobile-Viewer': 'false', 'CloudFront-Is-SmartTV-Viewer': 'false', 'CloudFront-Is-Tablet-Viewer': 'false', 'CloudFront-Viewer-Country': 'FR', 'Host': 'jugzryz6zi.execute-api.eu-west-1.amazonaws.com', 'origin': 'https://app.jetadmin.io', 'Referer': 'https://app.jetadmin.io/app/tfp_backoffice', 'User-Agent': 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_2) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.119 Safari/537.36', 'Via': '2.0 3b14001c94de06c6d9e0fbf3d55a7626.cloudfront.net (CloudFront)', 'X-Amz-Cf-Id': 'jNFESCHnrA6Z_qXOmI7fvKNFAz0OUaRI_WCH54S37Z1ZsDrH-5aPjA==', 'X-Amzn-Trace-Id': 'Root=1-5c7c505a-7b67735006fa49a2fb6c2b47', 'X-Forwarded-For': '82.255.108.108, 216.137.58.55', 'X-Forwarded-Port': '443', 'X-Forwarded-Proto': 'https'}, 'multiValueHeaders': {'Accept': ['application/json, text/plain, */*'], 'accept-encoding': ['gzip, deflate, br'], 'Accept-Language': ['fr,en;q=0.9,en-GB;q=0.8,en-US;q=0.7,de;q=0.6'], 'Authorization': ['Token 5060dc19ef9a9f364fbf282cf12d5006c2a08e97'], 'CloudFront-Forwarded-Proto': ['https'], 'CloudFront-Is-Desktop-Viewer': ['true'], 'CloudFront-Is-Mobile-Viewer': ['false'], 'CloudFront-Is-SmartTV-Viewer': ['false'], 'CloudFront-Is-Tablet-Viewer': ['false'], 'CloudFront-Viewer-Country': ['FR'], 'Host': ['jugzryz6zi.execute-api.eu-west-1.amazonaws.com'], 'origin': ['https://app.jetadmin.io'], 'Referer': ['https://app.jetadmin.io/app/tfp_backoffice'], 'User-Agent': ['Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_2) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.119 Safari/537.36'], 'Via': ['2.0 3b14001c94de06c6d9e0fbf3d55a7626.cloudfront.net (CloudFront)'], 'X-Amz-Cf-Id': ['jNFESCHnrA6Z_qXOmI7fvKNFAz0OUaRI_WCH54S37Z1ZsDrH-5aPjA=='], 'X-Amzn-Trace-Id': ['Root=1-5c7c505a-7b67735006fa49a2fb6c2b47'], 'X-Forwarded-For': ['82.255.108.108, 216.137.58.55'], 'X-Forwarded-Port': ['443'], 'X-Forwarded-Proto': ['https']}, 'queryStringParameters': None, 'multiValueQueryStringParameters': None, 'pathParameters': {'proxy': 'jet_api/model_descriptions'}, 'stageVariables': None, 'requestContext': {'resourceId': '55ym3m', 'resourcePath': '/{proxy+}', 'httpMethod': 'GET', 'extendedRequestId': 'V_F-HEn0DoEFlZg=', 'requestTime': '03/Mar/2019:22:08:26 +0000', 'path': '/staging/jet_api/model_descriptions/', 'accountId': '878228269602', 'protocol': 'HTTP/1.1', 'stage': 'staging', 'domainPrefix': 'jugzryz6zi', 'requestTimeEpoch': 1551650906342, 'requestId': 'de6258da-3e00-11e9-959a-e1d8a7b66ea3', 'identity': {'cognitoIdentityPoolId': None, 'accountId': None, 'cognitoIdentityId': None, 'caller': None, 'sourceIp': '82.255.108.108', 'accessKey': None, 'cognitoAuthenticationType': None, 'cognitoAuthenticationProvider': None, 'userArn': None, 'userAgent': 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_2) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.119 Safari/537.36', 'user': None}, 'domainName': 'jugzryz6zi.execute-api.eu-west-1.amazonaws.com', 'apiId': 'jugzryz6zi'}, 'body': None, 'isBase64Encoded': False} [1551650906359] Applying jet_django.0002_auto_20181014_2002... OK [1551650906395] Forbidden: /staging/jet_api/model_descriptions/ [1551650906395] [WARNING] 2019-03-03T22:08:26.387Z f88fee0f-2d29-461d-8e80-39c500788ff4 Forbidden: /staging/jet_api/model_descriptions/ [1551650906396] [INFO] 2019-03-03T22:08:26.396Z f88fee0f-2d29-461d-8e80-39c500788ff4 82.255.108.108 - - [03/Mar/2019:22:08:26 +0000] "GET /jet_api/model_descriptions/ HTTP/1.1" 403 63 "https://app.jetadmin.io/app/tfp_backoffice" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_2) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.119 Safari/537.36" 0/39.599000000000004 [1551650906590] [DEBUG] 2019-03-03T22:08:26.590Z 2f3c38a5-ea09-43cb-9b65-8f094ad06aab Zappa Event: {'resource': '/{proxy+}', 'path': '/jet_api/model_descriptions/', 'httpMethod': 'GET', 'headers': {'Accept': 'application/json, text/plain, */*', 'accept-encoding': 'gzip, deflate, br', 'Accept-Language': 'fr,en;q=0.9,en-GB;q=0.8,en-US;q=0.7,de;q=0.6', 'Authorization': 'Token 5060dc19ef9a9f364fbf282cf12d5006c2a08e97', 'CloudFront-Forwarded-Proto': 'https', 'CloudFront-Is-Desktop-Viewer': 'true', 'CloudFront-Is-Mobile-Viewer': 'false', 'CloudFront-Is-SmartTV-Viewer': 'false', 'CloudFront-Is-Tablet-Viewer': 'false', 'CloudFront-Viewer-Country': 'FR', 'Host': 'jugzryz6zi.execute-api.eu-west-1.amazonaws.com', 'origin': 'https://app.jetadmin.io', 'Referer': 'https://app.jetadmin.io/app/tfp_backoffice', 'User-Agent': 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_2) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.119 Safari/537.36', 'Via': '2.0 3b14001c94de06c6d9e0fbf3d55a7626.cloudfront.net (CloudFront)', 'X-Amz-Cf-Id': 'JdskBLzLvwBhbVk60am9wr-tUxIAziCCh49jS4a5gGc3hT93uizCig==', 'X-Amzn-Trace-Id': 'Root=1-5c7c505a-b3923d35851e0719e980b963', 'X-Forwarded-For': '82.255.108.108, 216.137.58.55', 'X-Forwarded-Port': '443', 'X-Forwarded-Proto': 'https'}, 'multiValueHeaders': {'Accept': ['application/json, text/plain, */*'], 'accept-encoding': ['gzip, deflate, br'], 'Accept-Language': ['fr,en;q=0.9,en-GB;q=0.8,en-US;q=0.7,de;q=0.6'], 'Authorization': ['Token 5060dc19ef9a9f364fbf282cf12d5006c2a08e97'], 'CloudFront-Forwarded-Proto': ['https'], 'CloudFront-Is-Desktop-Viewer': ['true'], 'CloudFront-Is-Mobile-Viewer': ['false'], 'CloudFront-Is-SmartTV-Viewer': ['false'], 'CloudFront-Is-Tablet-Viewer': ['false'], 'CloudFront-Viewer-Country': ['FR'], 'Host': ['jugzryz6zi.execute-api.eu-west-1.amazonaws.com'], 'origin': ['https://app.jetadmin.io'], 'Referer': ['https://app.jetadmin.io/app/tfp_backoffice'], 'User-Agent': ['Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_2) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.119 Safari/537.36'], 'Via': ['2.0 3b14001c94de06c6d9e0fbf3d55a7626.cloudfront.net (CloudFront)'], 'X-Amz-Cf-Id': ['JdskBLzLvwBhbVk60am9wr-tUxIAziCCh49jS4a5gGc3hT93uizCig=='], 'X-Amzn-Trace-Id': ['Root=1-5c7c505a-b3923d35851e0719e980b963'], 'X-Forwarded-For': ['82.255.108.108, 216.137.58.55'], 'X-Forwarded-Port': ['443'], 'X-Forwarded-Proto': ['https']}, 'queryStringParameters': None, 'multiValueQueryStringParameters': None, 'pathParameters': {'proxy': 'jet_api/model_descriptions'}, 'stageVariables': None, 'requestContext': {'resourceId': '55ym3m', 'resourcePath': '/{proxy+}', 'httpMethod': 'GET', 'extendedRequestId': 'V_F-JGySjoEFujA=', 'requestTime': '03/Mar/2019:22:08:26 +0000', 'path': '/staging/jet_api/model_descriptions/', 'accountId': '878228269602', 'protocol': 'HTTP/1.1', 'stage': 'staging', 'domainPrefix': 'jugzryz6zi', 'requestTimeEpoch': 1551650906577, 'requestId': 'de86347c-3e00-11e9-964f-1dbba8afb281', 'identity': {'cognitoIdentityPoolId': None, 'accountId': None, 'cognitoIdentityId': None, 'caller': None, 'sourceIp': '82.255.108.108', 'accessKey': None, 'cognitoAuthenticationType': None, 'cognitoAuthenticationProvider': None, 'userArn': None, 'userAgent': 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_2) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.119 Safari/537.36', 'user': None}, 'domainName': 'jugzryz6zi.execute-api.eu-west-1.amazonaws.com', 'apiId': 'jugzryz6zi'}, 'body': None, 'isBase64Encoded': False} [1551650906615] Forbidden: /staging/jet_api/model_descriptions/ [1551650906615] [WARNING] 2019-03-03T22:08:26.607Z 2f3c38a5-ea09-43cb-9b65-8f094ad06aab Forbidden: /staging/jet_api/model_descriptions/ [1551650906616] [INFO] 2019-03-03T22:08:26.616Z 2f3c38a5-ea09-43cb-9b65-8f094ad06aab 82.255.108.108 - - [03/Mar/2019:22:08:26 +0000] "GET /jet_api/model_descriptions/ HTTP/1.1" 403 63 "https://app.jetadmin.io/app/tfp_backoffice" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_2) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.119 Safari/537.36" 0/25.182 ```

For a few minutes, the https://app.jetadmin.io/app/tfp_backoffice DDoS my /jet_api/ endpoint. There is something wrong with UI which basically sent HTTP request to my /staging/jet_api/model_descriptions/ endpoint in a loop. This broke the Jet Admin app, because the browser became unresponsive, and also slowed down my computer due to the huge amount of logs displaying in the console in real-time. (please fix this!)

image

I see lots of OPTIONS requests being sent, about 2-3 per second. That's what DDoS my API (I disabled jet_django that's why it shows 404, but still, shouldn't DDoS like that) This happens when I'm at https://app.jetadmin.io/app/tfp_backoffice

And now... It's back to the behaviour I was experimenting a few days ago. The lambda basically timeouts after 30sec [1551656138200] 2019-03-03T23:35:38.179Z f9c2d096-8901-4cd0-99be-ae7ae0ae5766 Task timed out after 30.02 seconds and the server can't start, which kills the whole app. But I don't have any further detail, there is no error message as for why it times out. The only thing I know is that it only does when the jet_django app is activated in INSTALLED_APPS.

I also have tried using a tunnel from my localhost app and used it in https://app.jetadmin.io/app/tfp_backoffice settings api endpoint and it does work correctly. So the issue I'm facing only happens when jet_django is enabled, and only in AWS Lambda environment.

Vadorequest commented 5 years ago

Is there a way to go into verbose mode with jet to enable better logging? Could help troubleshoot the issue.

I feel like there is something wrong that happens when the jet_api is initialized, maybe a middleware, something that tries to authenticate, set token, or similar. Somehow the process fails but doesn't crash and doesn't get killed until the lambda itself times out and restart the process.

Vadorequest commented 5 years ago

The issue regarding the timeout was related to the allocated memory on the Lambda.

I had allocated 128Mo, which is the minimal (and often enough), but it was not enough for JET internal call to JetAdminModelDescription in admin/model_description.py from jet.register(model) in JetDjangoConfig

See those logs which prove the issue, look at the time the logs were generated and you'll see the Lambda is killed because the operation takes too long (30s): https://gist.github.com/Vadorequest/4d5ae7379202c72daeb9e5089297d886

Increasing to 512Mo fixed the issue.

Performance benchmark: (manual)


@f1nality I strongly suggest you add some logging on this part. Basically, knowing how much time the process takes would tremendously help. If it's close to 20-25 sec, or if the process fails then displaying a message about a lack of physical resources would be a good hint.

Anyway, this must be handled better, because it could fail any time if the time it takes is too close to 30s, adding a few new models (or another app!) could potentially crash the app and would be difficult to troubleshoot. It took me days

Vadorequest commented 5 years ago

Now, my app can start properly whether jet_admin is enabled or not, it doesn't break the django admin anymore because there is no timeout.

But still, it doesn't work yet.


When I go to https://app.jetadmin.io/app/tfp_backoffice/project/models, I get the following in the browser console: image

{"detail":"You do not have permission to perform this action."}

And the following in the server logs:

[1551723882670] [DEBUG] 2019-03-04T18:24:42.670Z 3c403b8a-5e5d-45b3-baa9-0e78d7a0a1e6 Starting new HTTPS connection (1): api.jetadmin.io:443
[1551723882976] [DEBUG] 2019-03-04T18:24:42.976Z 3c403b8a-5e5d-45b3-baa9-0e78d7a0a1e6 https://api.jetadmin.io:443 "POST /api/project_auth/ HTTP/1.1" 400 39
[1551723882978] [JET] Project Auth request error: 400 Bad Request {"non_field_errors":["Not authorized"]}
[1551723882978] [ERROR] 2019-03-04T18:24:42.978Z 3c403b8a-5e5d-45b3-baa9-0e78d7a0a1e6 [JET] Project Auth request error: 400 Bad Request {"non_field_errors":["Not authorized"]}
[1551723882979] Forbidden: /staging/jet_api/model_descriptions/
[1551723882979] [WARNING] 2019-03-04T18:24:42.979Z 3c403b8a-5e5d-45b3-baa9-0e78d7a0a1e6 Forbidden: /staging/jet_api/model_descriptions/
Vadorequest commented 5 years ago

The issue was happening because I had dropped my online DB and the token had been regenerated and wasn't matching the token from my project on https://app.jetadmin.io

I wrote a script to change the value whenever I do that again in the future. (I do drop the DB frequently due to bad DB schema, easier to erase and rebuild since it's a work in progress)

With this being resolved, my Jet Admin app finally works and it's the end (or beginning? 😆 ) of my troubles with Jet Admin & Zappa on AWS Lambda configuration. :)

Those 2 script may come in handy if you're using Zappa with no access to your RDS instance. ```py from django.core.management.base import BaseCommand from scripts.management.utils.execute_raw_sql import execute_raw_sql class Command(BaseCommand): """ Force update the token value used by jet_django_token """ help = "Runs a raw SQL query" def add_arguments(self, parser): parser.add_argument( '--token', dest='token', help='New token value to use', default='aaa3d3daaaa1459b9a176bc6d6a6aaaa' ) def handle(self, *args, **options): self.stdout.write(self.style.SUCCESS('Updating token')) token = options.get('token') sql = "UPDATE jet_django_token SET token = '{token}' WHERE id = 1".format(token=token) execute_raw_sql(sql) ``` ```py from django.core.management.base import BaseCommand from scripts.management.utils.execute_raw_sql import execute_raw_sql class Command(BaseCommand): """ Force update the token value used by jet_django_token """ help = "Runs a raw SQL query" def handle(self, *args, **options): self.stdout.write(self.style.SUCCESS('Reading tokens')) sql = "SELECT * FROM jet_django_token" execute_raw_sql(sql) ``` ```py from django.db import connection def execute_raw_sql(raw_sql): """ Can be used locally but also on a remote database if executed through Zappa :param raw_sql: :return: """ print('Running raw SQL query') queries = raw_sql.split(';') with connection.cursor() as cursor: for query in queries: print( "Running SQL query:\n" '> "{sql}"\n'.format(sql=query) ) cursor.execute(query, []) row = cursor.fetchall() print( "SQL query output:\n" "{output}".format(output=row) ) ```