azure-search-openai-demo
azure-search-openai-demo copied to clipboard
app runs locally but not on azure
Please provide us with the following information:
This issue is for a: (mark with an x
)
- [x] bug report -> please search issues before submitting
- [ ] feature request
- [ ] documentation issue or request
- [ ] regression (a behavior that used to work and stopped in a new release)
Minimal steps to reproduce
I made small adjustments in the backend and imported some modules. The app runs locally without problems but not on azure. I'm getting the error ModuleNotFoundError: No module named 'main'
Any log messages given by the failure
2023-11-13T15:00:51.048245136Z Documentation: http://aka.ms/webapp-linux 2023-11-13T15:00:51.048248537Z Python 3.11.4 2023-11-13T15:00:51.048252037Z Note: Any data outside '/home' is not persisted 2023-11-13T15:00:53.841410117Z Starting OpenBSD Secure Shell server: sshd. 2023-11-13T15:00:54.079495903Z Site's appCommandLine: python3 -m gunicorn main:app 2023-11-13T15:00:54.080804907Z Launching oryx with: create-script -appPath /home/site/wwwroot -output /opt/startup/startup.sh -virtualEnvName antenv -defaultApp /opt/defaultsite -userStartupCommand 'python3 -m gunicorn main:app' 2023-11-13T15:00:54.249114991Z Could not find build manifest file at '/home/site/wwwroot/oryx-manifest.toml' 2023-11-13T15:00:54.249849694Z Could not find operation ID in manifest. Generating an operation id... 2023-11-13T15:00:54.258543119Z Build Operation ID: 23ac646d-8475-407f-9678-e9a68c100d0c 2023-11-13T15:00:54.932481259Z Oryx Version: 0.2.20230707.1, Commit: 0bd28e69919b5e8beba451e8677e3345f0be8361, ReleaseTagName: 20230707.1 2023-11-13T15:00:55.020314512Z Writing output script to '/opt/startup/startup.sh' 2023-11-13T15:00:55.144179167Z WARNING: Could not find virtual environment directory /home/site/wwwroot/antenv. 2023-11-13T15:00:55.151022287Z WARNING: Could not find package directory /home/site/wwwroot/oryx_packages. 2023-11-13T15:01:02.485772081Z [2023-11-13 15:01:02 +0000] [59] [INFO] Starting gunicorn 20.1.0 2023-11-13T15:01:02.507425354Z [2023-11-13 15:01:02 +0000] [59] [INFO] Listening at: http://0.0.0.0:8000 (59) 2023-11-13T15:01:02.507455954Z [2023-11-13 15:01:02 +0000] [59] [INFO] Using worker: sync 2023-11-13T15:01:02.720012673Z [2023-11-13 15:01:02 +0000] [65] [INFO] Booting worker with pid: 65 2023-11-13T15:01:02.807577969Z [2023-11-13 15:01:02 +0000] [65] [ERROR] Exception in worker process 2023-11-13T15:01:02.807624769Z Traceback (most recent call last): 2023-11-13T15:01:02.807630869Z File "/opt/python/3/lib/python3.11/site-packages/gunicorn/arbiter.py", line 589, in spawn_worker 2023-11-13T15:01:02.807634869Z worker.init_process() 2023-11-13T15:01:02.807638569Z File "/opt/python/3/lib/python3.11/site-packages/gunicorn/workers/base.py", line 134, in init_process 2023-11-13T15:01:02.807648869Z self.load_wsgi() 2023-11-13T15:01:02.807653669Z File "/opt/python/3/lib/python3.11/site-packages/gunicorn/workers/base.py", line 146, in load_wsgi 2023-11-13T15:01:02.807669369Z self.wsgi = self.app.wsgi() 2023-11-13T15:01:02.807673869Z ^^^^^^^^^^^^^^^ 2023-11-13T15:01:02.807677269Z File "/opt/python/3/lib/python3.11/site-packages/gunicorn/app/base.py", line 67, in wsgi 2023-11-13T15:01:02.807680969Z self.callable = self.load() 2023-11-13T15:01:02.807684369Z ^^^^^^^^^^^ 2023-11-13T15:01:02.807687769Z File "/opt/python/3/lib/python3.11/site-packages/gunicorn/app/wsgiapp.py", line 58, in load 2023-11-13T15:01:02.807691269Z return self.load_wsgiapp() 2023-11-13T15:01:02.807694769Z ^^^^^^^^^^^^^^^^^^^ 2023-11-13T15:01:02.807698169Z File "/opt/python/3/lib/python3.11/site-packages/gunicorn/app/wsgiapp.py", line 48, in load_wsgiapp 2023-11-13T15:01:02.807701769Z return util.import_app(self.app_uri) 2023-11-13T15:01:02.807705169Z ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 2023-11-13T15:01:02.807708669Z File "/opt/python/3/lib/python3.11/site-packages/gunicorn/util.py", line 359, in import_app 2023-11-13T15:01:02.807712269Z mod = importlib.import_module(module) 2023-11-13T15:01:02.807715669Z ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 2023-11-13T15:01:02.807719069Z File "/opt/python/3/lib/python3.11/importlib/init.py", line 126, in import_module 2023-11-13T15:01:02.807777469Z return _bootstrap._gcd_import(name[level:], package, level) 2023-11-13T15:01:02.807786769Z ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 2023-11-13T15:01:02.807790869Z File "
", line 1204, in _gcd_import 2023-11-13T15:01:02.807794869Z File " ", line 1176, in _find_and_load 2023-11-13T15:01:02.807798569Z File " ", line 1140, in _find_and_load_unlocked 2023-11-13T15:01:02.807802169Z ModuleNotFoundError: No module named 'main' 2023-11-13T15:01:02.818257005Z [2023-11-13 15:01:02 +0000] [65] [INFO] Worker exiting (pid: 65) 2023-11-13T15:01:04.082955771Z [2023-11-13 15:01:04 +0000] [59] [INFO] Shutting down: Master 2023-11-13T15:01:04.112193770Z [2023-11-13 15:01:04 +0000] [59] [INFO] Reason: Worker failed to boot.
OS and Version?
Windows 11 Pro
azd version?
azd version 1.4.3 (commit d165bd2de96dae75de57604c0d8a5553ae214618)
logs deployment center
Sometimes that means the app is still starting up (the code isn't fully loaded), have you tried waiting 10 minutes and checking again?
yes, I waited much longer than 10 minutes and it didn't help.
Okay, well the error indicates that it can't find main.py, which means something went awry with the code upload, since app/backend/ should have a main.py. You could try re-running "azd deploy", and/or you could check the Deployment logs in the Azure Portal to see if it reported any issues with deployment. See first part of my blog post here: https://blog.pamelafox.org/2023/06/tips-for-debugging-flask-deployments-to.html
Thank you for your help Pamela. Re-running with azd deploy didn't help and the logs also look normal from my point of view? Could it be that it has to do with the changes in the backend and the imported modules, even though it works locally? Any problems with Linux on azure and Windows locally?
Hm, the Oryx build logs look fine.
Your logs look like what I see when the app starts to restart the server before it has the code fully ready. It errors, but then once the code is ready, the next server restart works. I wonder if you can try Restart Server or running just azd deploy.
I'll share the logs from my most recent server start, it looks like yours at first and then fixes itself.
2023-11-14T22:46:50.590985786Z _____
2023-11-14T22:46:50.591034989Z / _ \ __________ _________ ____
2023-11-14T22:46:50.591046990Z / /_\ \\___ / | \_ __ \_/ __ \
2023-11-14T22:46:50.591051890Z / | \/ /| | /| | \/\ ___/
2023-11-14T22:46:50.591056091Z \____|__ /_____ \____/ |__| \___ >
2023-11-14T22:46:50.591061391Z \/ \/ \/
2023-11-14T22:46:50.591065491Z A P P S E R V I C E O N L I N U X
2023-11-14T22:46:50.591069391Z
2023-11-14T22:46:50.591073192Z Documentation: http://aka.ms/webapp-linux
2023-11-14T22:46:50.591077092Z Python 3.11.4
2023-11-14T22:46:50.591080992Z Note: Any data outside '/home' is not persisted
2023-11-14T22:47:00.677725263Z Starting OpenBSD Secure Shell server: sshd.
2023-11-14T22:47:01.212757873Z Site's appCommandLine: python3 -m gunicorn main:app
2023-11-14T22:47:02.321658713Z Starting periodic command scheduler: cron.
2023-11-14T22:47:02.321691315Z Launching oryx with: create-script -appPath /home/site/wwwroot -output /opt/startup/startup.sh -virtualEnvName antenv -defaultApp /opt/defaultsite -userStartupCommand 'python3 -m gunicorn main:app'
2023-11-14T22:47:02.812998063Z Could not find build manifest file at '/home/site/wwwroot/oryx-manifest.toml'
2023-11-14T22:47:02.814704385Z Could not find operation ID in manifest. Generating an operation id...
2023-11-14T22:47:02.821619280Z Build Operation ID: c5688804-09b6-47b3-ad6f-355838c172f3
2023-11-14T22:47:03.795591343Z Oryx Version: 0.2.20230707.1, Commit: 0bd28e69919b5e8beba451e8677e3345f0be8361, ReleaseTagName: 20230707.1
2023-11-14T22:47:03.902461487Z Writing output script to '/opt/startup/startup.sh'
2023-11-14T22:47:04.066207297Z WARNING: Could not find virtual environment directory /home/site/wwwroot/antenv.
2023-11-14T22:47:04.066252400Z WARNING: Could not find package directory /home/site/wwwroot/__oryx_packages__.
2023-11-14T22:47:08.329477991Z [2023-11-14 22:47:08 +0000] [72] [INFO] Starting gunicorn 20.1.0
2023-11-14T22:47:08.338782656Z [2023-11-14 22:47:08 +0000] [72] [INFO] Listening at: http://0.0.0.0:8000 (72)
2023-11-14T22:47:08.338826059Z [2023-11-14 22:47:08 +0000] [72] [INFO] Using worker: sync
2023-11-14T22:47:08.416792928Z [2023-11-14 22:47:08 +0000] [73] [INFO] Booting worker with pid: 73
2023-11-14T22:47:08.682769626Z [2023-11-14 22:47:08 +0000] [73] [ERROR] Exception in worker process
2023-11-14T22:47:08.682839031Z Traceback (most recent call last):
2023-11-14T22:47:08.682846231Z File "/opt/python/3/lib/python3.11/site-packages/gunicorn/arbiter.py", line 589, in spawn_worker
2023-11-14T22:47:08.682852531Z worker.init_process()
2023-11-14T22:47:08.682857532Z File "/opt/python/3/lib/python3.11/site-packages/gunicorn/workers/base.py", line 134, in init_process
2023-11-14T22:47:08.682862732Z self.load_wsgi()
2023-11-14T22:47:08.682885634Z File "/opt/python/3/lib/python3.11/site-packages/gunicorn/workers/base.py", line 146, in load_wsgi
2023-11-14T22:47:08.682891134Z self.wsgi = self.app.wsgi()
2023-11-14T22:47:08.682895735Z ^^^^^^^^^^^^^^^
2023-11-14T22:47:08.682900435Z File "/opt/python/3/lib/python3.11/site-packages/gunicorn/app/base.py", line 67, in wsgi
2023-11-14T22:47:08.682905235Z self.callable = self.load()
2023-11-14T22:47:08.682909836Z ^^^^^^^^^^^
2023-11-14T22:47:08.682914536Z File "/opt/python/3/lib/python3.11/site-packages/gunicorn/app/wsgiapp.py", line 58, in load
2023-11-14T22:47:08.682919636Z return self.load_wsgiapp()
2023-11-14T22:47:08.682924337Z ^^^^^^^^^^^^^^^^^^^
2023-11-14T22:47:08.682928937Z File "/opt/python/3/lib/python3.11/site-packages/gunicorn/app/wsgiapp.py", line 48, in load_wsgiapp
2023-11-14T22:47:08.682933637Z return util.import_app(self.app_uri)
2023-11-14T22:47:08.682938238Z ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2023-11-14T22:47:08.682942838Z File "/opt/python/3/lib/python3.11/site-packages/gunicorn/util.py", line 359, in import_app
2023-11-14T22:47:08.682947738Z mod = importlib.import_module(module)
2023-11-14T22:47:08.682952239Z ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2023-11-14T22:47:08.682956839Z File "/opt/python/3/lib/python3.11/importlib/__init__.py", line 126, in import_module
2023-11-14T22:47:08.682961539Z return _bootstrap._gcd_import(name[level:], package, level)
2023-11-14T22:47:08.682966240Z ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2023-11-14T22:47:08.682971240Z File "<frozen importlib._bootstrap>", line 1204, in _gcd_import
2023-11-14T22:47:08.682976540Z File "<frozen importlib._bootstrap>", line 1176, in _find_and_load
2023-11-14T22:47:08.682981541Z File "<frozen importlib._bootstrap>", line 1140, in _find_and_load_unlocked
2023-11-14T22:47:08.682986341Z ModuleNotFoundError: No module named 'main'
2023-11-14T22:47:08.691051117Z [2023-11-14 22:47:08 +0000] [73] [INFO] Worker exiting (pid: 73)
2023-11-14T22:47:09.443242935Z [2023-11-14 22:47:09 +0000] [72] [INFO] Shutting down: Master
2023-11-14T22:47:09.444523826Z [2023-11-14 22:47:09 +0000] [72] [INFO] Reason: Worker failed to boot.
2023-11-14T22:52:03.964739739Z _____
2023-11-14T22:52:03.964788142Z / _ \ __________ _________ ____
2023-11-14T22:52:03.964793742Z / /_\ \\___ / | \_ __ \_/ __ \
2023-11-14T22:52:03.964798242Z / | \/ /| | /| | \/\ ___/
2023-11-14T22:52:03.964802542Z \____|__ /_____ \____/ |__| \___ >
2023-11-14T22:52:03.964806943Z \/ \/ \/
2023-11-14T22:52:03.964811243Z A P P S E R V I C E O N L I N U X
2023-11-14T22:52:03.964815343Z
2023-11-14T22:52:03.964819243Z Documentation: http://aka.ms/webapp-linux
2023-11-14T22:52:03.964823343Z Python 3.11.4
2023-11-14T22:52:03.964827344Z Note: Any data outside '/home' is not persisted
2023-11-14T22:52:06.786887176Z Starting OpenBSD Secure Shell server: sshd.
2023-11-14T22:52:07.416817170Z Site's appCommandLine: python3 -m gunicorn main:app
2023-11-14T22:52:08.266259617Z Starting periodic command scheduler: cron.
2023-11-14T22:52:08.267829604Z Launching oryx with: create-script -appPath /home/site/wwwroot -output /opt/startup/startup.sh -virtualEnvName antenv -defaultApp /opt/defaultsite -userStartupCommand 'python3 -m gunicorn main:app'
2023-11-14T22:52:08.383778325Z Found build manifest file at '/home/site/wwwroot/oryx-manifest.toml'. Deserializing it...
2023-11-14T22:52:08.386990003Z Build Operation ID: 1cfa1d0420698611
2023-11-14T22:52:08.388924710Z Oryx Version: 0.2.20230707.1, Commit: 0bd28e69919b5e8beba451e8677e3345f0be8361, ReleaseTagName: 20230707.1
2023-11-14T22:52:08.394796935Z Output is compressed. Extracting it...
2023-11-14T22:52:08.495341403Z Extracting '/home/site/wwwroot/output.tar.gz' to directory '/tmp/8dbe562e63641aa'...
2023-11-14T22:52:38.954832207Z App path is set to '/tmp/8dbe562e63641aa'
2023-11-14T22:52:39.082043924Z Writing output script to '/opt/startup/startup.sh'
2023-11-14T22:52:39.212233861Z Using packages from virtual environment antenv located at /tmp/8dbe562e63641aa/antenv.
2023-11-14T22:52:39.212274963Z Updated PYTHONPATH to '/opt/startup/app_logs:/tmp/8dbe562e63641aa/antenv/lib/python3.11/site-packages'
2023-11-14T22:52:41.003229677Z [2023-11-14 22:52:41 +0000] [74] [INFO] Starting gunicorn 20.1.0
2023-11-14T22:52:41.005456895Z [2023-11-14 22:52:41 +0000] [74] [INFO] Listening at: http://0.0.0.0:8000 (74)
2023-11-14T22:52:41.011535719Z [2023-11-14 22:52:41 +0000] [74] [INFO] Using worker: uvicorn.workers.UvicornWorker
2023-11-14T22:52:41.033938612Z [2023-11-14 22:52:41 +0000] [75] [INFO] Booting worker with pid: 75
2023-11-14T22:52:41.102637171Z [2023-11-14 22:52:41 +0000] [76] [INFO] Booting worker with pid: 76
2023-11-14T22:52:41.163480212Z [2023-11-14 22:52:41 +0000] [77] [INFO] Booting worker with pid: 77
2023-11-14T22:53:13.740452991Z [2023-11-14 22:53:13 +0000] [76] [INFO] Started server process [76]
2023-11-14T22:53:13.741783053Z [2023-11-14 22:53:13 +0000] [76] [INFO] Waiting for application startup.
2023-11-14T22:53:13.751407099Z [2023-11-14 22:53:13 +0000] [75] [INFO] Started server process [75]
2023-11-14T22:53:13.752934270Z [2023-11-14 22:53:13 +0000] [75] [INFO] Waiting for application startup.
2023-11-14T22:53:13.761449965Z WARNING:azure.identity.aio._credentials.environment:Incomplete environment configuration. These variables are set: AZURE_TENANT_ID
2023-11-14T22:53:13.770482684Z WARNING:azure.identity.aio._credentials.environment:Incomplete environment configuration. These variables are set: AZURE_TENANT_ID
2023-11-14T22:53:13.780911967Z [2023-11-14 22:53:13 +0000] [77] [INFO] Started server process [77]
2023-11-14T22:53:13.790122794Z [2023-11-14 22:53:13 +0000] [77] [INFO] Waiting for application startup.
2023-11-14T22:53:13.793155135Z WARNING:azure.identity.aio._credentials.environment:Incomplete environment configuration. These variables are set: AZURE_TENANT_ID
2023-11-14T22:53:17.705159396Z [2023-11-14 22:53:17 +0000] [76] [INFO] Application startup complete.
2023-11-14T22:53:17.714583598Z [2023-11-14 22:53:17 +0000] [75] [INFO] Application startup complete.
2023-11-14T22:53:17.736555867Z [2023-11-14 22:53:17 +0000] [77] [INFO] Application startup complete.
Rerunning server or deploy again results always in the same error. Do you have any other ideas about what could be the reason?
@MarPeg53 Are you able to SSH into the server from the Portal? If you can, then you can poke around and see what files are actually there. If you can't SSH due to the issue with starting the server, you could temporarily override the startup command to something that should always work (an empty string might work), and then SSH.
This issue is stale because it has been open 60 days with no activity. Remove stale label or comment or this issue will be closed.
The app was just running fine, then suddenly I got an application error. I am getting the same error log:
2023-11-14T22:47:08.682971240Z File "
Did anyone find a solution to this?
The error "No module named 'main'" generally means that the App Service does not have your application code (it cannot find main.py, which should be in the backend folder that gets uploaded). It's very common for that to be the case a few minutes after deploy while the server is still warming up. However, if you still see it, then I recommend checking the Deployment logs to make sure your last deployment was successful. You may need to do another deployment if the last one failed.
More details in my post at https://blog.pamelafox.org/2023/06/tips-for-debugging-flask-deployments-to.html
@pamelafox checking the deployment logs was a great hint! Thank you! I reversed the last changes and now it works again. Need to check what went wrong there...