lithops
lithops copied to clipboard
Published
20 hours ago •
lithops-cloud
lithops-cloud
Lithops from main branch not working anymore.
I have encountered an issue with the repo where the code stops working as expected starting from commit e636cde6adf695f7990096c43e8694c41d36eac9. I haven't been able to locate what is causing the problem.
Steps to reproduce:
- Clone the repository in a new pythonv3.12 environment
- Checkout to the faulty commit
- Install current package via pip once inside root dir (pip install .)
- Run lithops test
Expected output (extracted from reproducing those steps but using earlier commit 2f2fa7d0e5b95d42380c6b8306ea38af6c7c03f0):
2024-03-06 12:48:42,509 [INFO] config.py:139 -- Lithops v3.1.3.dev0 - Python3.12
2024-03-06 12:48:42,510 [DEBUG] config.py:106 -- Config file not found. Setting Lithops to Localhost mode
2024-03-06 12:48:42,510 [DEBUG] config.py:174 -- Loading compute backend module: localhost
2024-03-06 12:48:42,510 [DEBUG] config.py:233 -- Loading Storage backend module: localhost
2024-03-06 12:48:42,513 [DEBUG] localhost.py:36 -- Creating Localhost storage client
2024-03-06 12:48:42,514 [INFO] localhost.py:39 -- Localhost storage client created
2024-03-06 12:48:42,514 [DEBUG] localhost.py:60 -- Creating Localhost compute client
2024-03-06 12:48:42,514 [INFO] localhost.py:70 -- Localhost compute v1 client created
2024-03-06 12:48:42,515 [DEBUG] invokers.py:93 -- ExecutorID 47a3b2-0 - Invoker initialized. Max workers: 1
2024-03-06 12:48:42,516 [DEBUG] localhost.py:261 -- Starting python environment for python
2024-03-06 12:48:42,516 [DEBUG] localhost.py:264 -- Setting up python environment
2024-03-06 12:48:42,694 [DEBUG] executors.py:148 -- Function executor for localhost created with ID: 47a3b2-0
2024-03-06 12:48:42,694 [INFO] invokers.py:107 -- ExecutorID 47a3b2-0 | JobID A000 - Selected Runtime: python
2024-03-06 12:48:42,695 [DEBUG] storage.py:474 -- Runtime metadata found in local disk cache
2024-03-06 12:48:42,696 [DEBUG] job.py:242 -- ExecutorID 47a3b2-0 | JobID A000 - Serializing function and data
2024-03-06 12:48:42,698 [DEBUG] serialize.py:73 -- Referenced Modules: lithops
2024-03-06 12:48:42,698 [DEBUG] module_dependency.py:109 -- Module 'lithops' is already installed in the runtime, skipping
2024-03-06 12:48:42,698 [DEBUG] serialize.py:118 -- Modules to transmit: None
2024-03-06 12:48:42,699 [DEBUG] job.py:276 -- ExecutorID 47a3b2-0 | JobID A000 - Uploading function and modules to the storage backend
2024-03-06 12:48:42,699 [DEBUG] job.py:302 -- ExecutorID 47a3b2-0 | JobID A000 - Uploading data to the storage backend
2024-03-06 12:48:42,700 [INFO] invokers.py:172 -- ExecutorID 47a3b2-0 | JobID A000 - Starting function invocation: hello() - Total: 1 activations
2024-03-06 12:48:42,700 [DEBUG] invokers.py:177 -- ExecutorID 47a3b2-0 | JobID A000 - Worker processes: 8 - Chunksize: 8
2024-03-06 12:48:42,700 [DEBUG] localhost.py:131 -- ExecutorID 47a3b2-0 | JobID A000 - Putting job into localhost queue
2024-03-06 12:48:42,701 [DEBUG] localhost.py:91 -- Staring localhost job manager
2024-03-06 12:48:42,702 [DEBUG] invokers.py:253 -- ExecutorID 47a3b2-0 | JobID A000 - Job invoked (0.002s) - Activation ID: 47a3b2-0-A000
2024-03-06 12:48:42,702 [INFO] invokers.py:208 -- ExecutorID 47a3b2-0 | JobID A000 - View execution logs at /tmp/lithops-acando/logs/47a3b2-0-A000.log
2024-03-06 12:48:42,703 [DEBUG] localhost.py:102 -- ExecutorID 47a3b2-0 | JobID A000 - Running 1 activations in the localhost worker
2024-03-06 12:48:42,703 [DEBUG] monitor.py:427 -- ExecutorID 47a3b2-0 - Starting Storage job monitor
2024-03-06 12:48:42,704 [INFO] executors.py:491 -- ExecutorID 47a3b2-0 - Getting results from 1 function activations
2024-03-06 12:48:42,704 [INFO] wait.py:101 -- ExecutorID 47a3b2-0 - Waiting for 1 function activations to complete
2024-03-06 12:48:44,045 [DEBUG] localhost.py:106 -- ExecutorID 47a3b2-0 | JobID A000 - Execution finished
2024-03-06 12:48:44,046 [DEBUG] localhost.py:111 -- Localhost job manager finished
2024-03-06 12:48:44,707 [DEBUG] monitor.py:142 -- ExecutorID 47a3b2-0 - Pending: 0 - Running: 0 - Done: 1
2024-03-06 12:48:44,707 [DEBUG] monitor.py:455 -- ExecutorID 47a3b2-0 - Storage job monitor finished
2024-03-06 12:48:45,709 [DEBUG] future.py:230 -- ExecutorID 47a3b2-0 | JobID A000 - Got status from call 00000 - Activation ID: db0c69df64a8 - Time: 0.03 seconds
2024-03-06 12:48:45,709 [DEBUG] future.py:287 -- ExecutorID 47a3b2-0 | JobID A000 - Got output from call 00000 - Activation ID: db0c69df64a8
2024-03-06 12:48:45,710 [INFO] executors.py:607 -- ExecutorID 47a3b2-0 - Cleaning temporary data
2024-03-06 12:48:45,712 [DEBUG] executors.py:516 -- ExecutorID 47a3b2-0 - Finished getting results
Actual output (extracted from faulty commit as indicated in the steps):
2024-03-06 12:51:48,531 [INFO] config.py:139 -- Lithops v3.1.3.dev0 - Python3.12
2024-03-06 12:51:48,531 [DEBUG] config.py:106 -- Config file not found. Setting Lithops to Localhost mode
2024-03-06 12:51:48,532 [DEBUG] config.py:174 -- Loading compute backend module: localhost
2024-03-06 12:51:48,532 [DEBUG] config.py:233 -- Loading Storage backend module: localhost
2024-03-06 12:51:48,535 [DEBUG] localhost.py:36 -- Creating Localhost storage client
2024-03-06 12:51:48,535 [INFO] localhost.py:39 -- Localhost storage client created
2024-03-06 12:51:48,535 [DEBUG] localhost.py:60 -- Creating Localhost compute client
2024-03-06 12:51:48,536 [INFO] localhost.py:70 -- Localhost compute v1 client created
2024-03-06 12:51:48,537 [DEBUG] invokers.py:93 -- ExecutorID d2fd46-0 - Invoker initialized. Max workers: 1
2024-03-06 12:51:48,537 [DEBUG] localhost.py:302 -- Starting docker environment for python
2024-03-06 12:51:48,537 [DEBUG] localhost.py:307 -- Setting up Docker environment
2024-03-06 12:51:48,720 [DEBUG] executors.py:148 -- Function executor for localhost created with ID: d2fd46-0
2024-03-06 12:51:48,720 [INFO] invokers.py:107 -- ExecutorID d2fd46-0 | JobID A000 - Selected Runtime: python
2024-03-06 12:51:48,720 [DEBUG] storage.py:474 -- Runtime metadata found in local disk cache
2024-03-06 12:51:48,721 [DEBUG] job.py:242 -- ExecutorID d2fd46-0 | JobID A000 - Serializing function and data
2024-03-06 12:51:48,723 [DEBUG] serialize.py:73 -- Referenced Modules: lithops
2024-03-06 12:51:48,723 [DEBUG] module_dependency.py:109 -- Module 'lithops' is already installed in the runtime, skipping
2024-03-06 12:51:48,724 [DEBUG] serialize.py:118 -- Modules to transmit: None
2024-03-06 12:51:48,724 [DEBUG] job.py:276 -- ExecutorID d2fd46-0 | JobID A000 - Uploading function and modules to the storage backend
2024-03-06 12:51:48,725 [DEBUG] job.py:302 -- ExecutorID d2fd46-0 | JobID A000 - Uploading data to the storage backend
2024-03-06 12:51:48,726 [INFO] invokers.py:172 -- ExecutorID d2fd46-0 | JobID A000 - Starting function invocation: hello() - Total: 1 activations
2024-03-06 12:51:48,726 [DEBUG] invokers.py:177 -- ExecutorID d2fd46-0 | JobID A000 - Worker processes: 8 - Chunksize: 8
2024-03-06 12:51:48,726 [DEBUG] localhost.py:132 -- ExecutorID d2fd46-0 | JobID A000 - Putting job into localhost queue
2024-03-06 12:51:48,727 [DEBUG] localhost.py:92 -- Staring localhost job manager
2024-03-06 12:51:48,728 [DEBUG] invokers.py:253 -- ExecutorID d2fd46-0 | JobID A000 - Job invoked (0.002s) - Activation ID: d2fd46-0-A000
2024-03-06 12:51:48,728 [INFO] invokers.py:208 -- ExecutorID d2fd46-0 | JobID A000 - View execution logs at /tmp/lithops-acando/logs/d2fd46-0-A000.log
2024-03-06 12:51:48,729 [DEBUG] localhost.py:103 -- ExecutorID d2fd46-0 | JobID A000 - Running 1 activations in the localhost worker
2024-03-06 12:51:48,729 [DEBUG] monitor.py:427 -- ExecutorID d2fd46-0 - Starting Storage job monitor
2024-03-06 12:51:48,729 [INFO] executors.py:491 -- ExecutorID d2fd46-0 - Getting results from 1 function activations
2024-03-06 12:51:48,730 [INFO] wait.py:101 -- ExecutorID d2fd46-0 - Waiting for 1 function activations to complete
2024-03-06 12:51:50,732 [DEBUG] monitor.py:142 -- ExecutorID d2fd46-0 - Pending: 1 - Running: 0 - Done: 0
2024-03-06 12:51:51,063 [DEBUG] localhost.py:107 -- ExecutorID d2fd46-0 | JobID A000 - Execution finished
2024-03-06 12:51:51,063 [DEBUG] localhost.py:112 -- Localhost job manager finished
2024-03-06 12:52:22,771 [DEBUG] monitor.py:142 -- ExecutorID d2fd46-0 - Pending: 1 - Running: 0 - Done: 0
2024-03-06 12:52:54,809 [DEBUG] monitor.py:142 -- ExecutorID d2fd46-0 - Pending: 1 - Running: 0 - Done: 0
2024-03-06 12:53:26,847 [DEBUG] monitor.py:142 -- ExecutorID d2fd46-0 - Pending: 1 - Running: 0 - Done: 0
In principle this is already fixed on master branch, can you make sure you have the latest changes?
I have tried on the most recent commit 66e3051f9bdde328985160978576cc94eeaeb668 and I get the same result. Tested on multiple machines.
I updated the lithops version on master branch. Can you check it again with the latest changes and post here the debug logs?
Here are the logs. It behaves the same
2024-03-06 18:18:31,679 [INFO] config.py:139 -- Lithops v3.1.3.dev1 - Python3.12
2024-03-06 18:18:31,679 [DEBUG] config.py:106 -- Config file not found. Setting Lithops to Localhost mode
2024-03-06 18:18:31,679 [DEBUG] config.py:174 -- Loading compute backend module: localhost
2024-03-06 18:18:31,679 [DEBUG] config.py:233 -- Loading Storage backend module: localhost
2024-03-06 18:18:31,679 [DEBUG] localhost.py:36 -- Creating Localhost storage client
2024-03-06 18:18:31,679 [INFO] localhost.py:39 -- Localhost storage client created
2024-03-06 18:18:31,679 [DEBUG] localhost.py:60 -- Creating Localhost compute client
2024-03-06 18:18:31,679 [INFO] localhost.py:70 -- Localhost compute v1 client created
2024-03-06 18:18:31,680 [DEBUG] invokers.py:93 -- ExecutorID addabf-0 - Invoker initialized. Max workers: 1
2024-03-06 18:18:31,680 [DEBUG] localhost.py:262 -- Starting python environment for python
2024-03-06 18:18:31,680 [DEBUG] localhost.py:265 -- Setting up python environment
2024-03-06 18:18:31,712 [DEBUG] executors.py:148 -- Function executor for localhost created with ID: addabf-0
2024-03-06 18:18:31,712 [INFO] invokers.py:107 -- ExecutorID addabf-0 | JobID A000 - Selected Runtime: python
2024-03-06 18:18:31,712 [DEBUG] storage.py:474 -- Runtime metadata found in local disk cache
2024-03-06 18:18:31,712 [DEBUG] job.py:242 -- ExecutorID addabf-0 | JobID A000 - Serializing function and data
2024-03-06 18:18:31,713 [DEBUG] serialize.py:73 -- Referenced Modules: lithops
2024-03-06 18:18:31,713 [DEBUG] module_dependency.py:109 -- Module 'lithops' is already installed in the runtime, skipping
2024-03-06 18:18:31,713 [DEBUG] serialize.py:118 -- Modules to transmit: None
2024-03-06 18:18:31,713 [DEBUG] job.py:276 -- ExecutorID addabf-0 | JobID A000 - Uploading function and modules to the storage backend
2024-03-06 18:18:31,713 [DEBUG] job.py:302 -- ExecutorID addabf-0 | JobID A000 - Uploading data to the storage backend
2024-03-06 18:18:31,713 [INFO] invokers.py:174 -- ExecutorID addabf-0 | JobID A000 - Starting function invocation: hello() - Total: 1 activations
2024-03-06 18:18:31,713 [DEBUG] invokers.py:179 -- ExecutorID addabf-0 | JobID A000 - Worker processes: 8 - Chunksize: 8
2024-03-06 18:18:31,713 [DEBUG] localhost.py:132 -- ExecutorID addabf-0 | JobID A000 - Putting job into localhost queue
2024-03-06 18:18:31,713 [DEBUG] localhost.py:92 -- Staring localhost job manager
2024-03-06 18:18:31,714 [DEBUG] invokers.py:255 -- ExecutorID addabf-0 | JobID A000 - Job invoked (0.001s) - Activation ID: addabf-0-A000
2024-03-06 18:18:31,714 [DEBUG] localhost.py:103 -- ExecutorID addabf-0 | JobID A000 - Running 1 activations in the localhost worker
2024-03-06 18:18:31,714 [INFO] invokers.py:210 -- ExecutorID addabf-0 | JobID A000 - View execution logs at /tmp/lithops-acando/logs/addabf-0-A000.log
2024-03-06 18:18:31,714 [DEBUG] monitor.py:427 -- ExecutorID addabf-0 - Starting Storage job monitor
2024-03-06 18:18:31,714 [INFO] executors.py:491 -- ExecutorID addabf-0 - Getting results from 1 function activations
2024-03-06 18:18:31,714 [INFO] wait.py:101 -- ExecutorID addabf-0 - Waiting for 1 function activations to complete
2024-03-06 18:18:31,986 [DEBUG] localhost.py:107 -- ExecutorID addabf-0 | JobID A000 - Execution finished
2024-03-06 18:18:31,986 [DEBUG] localhost.py:112 -- Localhost job manager finished
2024-03-06 18:18:33,719 [DEBUG] monitor.py:142 -- ExecutorID addabf-0 - Pending: 1 - Running: 0 - Done: 0
2024-03-06 18:19:05,751 [DEBUG] monitor.py:142 -- ExecutorID addabf-0 - Pending: 1 - Running: 0 - Done: 0
2024-03-06 18:19:37,786 [DEBUG] monitor.py:142 -- ExecutorID addabf-0 - Pending: 1 - Running: 0 - Done: 0
in this folder /tmp/lithops-acando/ you should have a file called localhost-runner.log. can you post the content here?
2024-03-06 18:18:31,936 [INFO] localhost-runner.py:88 -- Starting Localhost job runner
2024-03-06 18:18:31,936 [INFO] localhost-runner.py:90 -- Received command: run_job
2024-03-06 18:18:31,936 [INFO] localhost-runner.py:53 -- Got /tmp/lithops-acando/storage/lithops.jobs/addabf-0-A000-job.json job file
2024-03-06 18:18:31,936 [INFO] localhost-runner.py:62 -- ExecutorID addabf-0 | JobID A000 - Starting execution
2024-03-06 18:18:31,937 [INFO] localhost.py:39 -- Localhost storage client created
2024-03-06 18:18:31,937 [INFO] utils.py:50 -- Getting function and modules
2024-03-06 18:18:31,937 [INFO] utils.py:64 -- Loading function/mods /opt/lithops/lithops.jobs/addabf-0/e48d9cfd278f3a91264f51bd12bce69e.func.pickle from storage
Traceback (most recent call last):
File "/tmp/lithops-acando/localhost-runner.py", line 97, in <module>
switcher.get(command, lambda: "Invalid command")()
File "/tmp/lithops-acando/localhost-runner.py", line 69, in run_job
function_handler(job_payload)
File "/tmp/lithops-acando/lithops/worker/handler.py", line 71, in function_handler
job = create_job(payload)
^^^^^^^^^^^^^^^^^^^
File "/tmp/lithops-acando/lithops/worker/handler.py", line 61, in create_job
job.func = get_function_and_modules(job, internal_storage)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/tmp/lithops-acando/lithops/worker/utils.py", line 66, in get_function_and_modules
os.makedirs(os.path.dirname(func_path), exist_ok=True)
File "<frozen os>", line 215, in makedirs
File "<frozen os>", line 215, in makedirs
File "<frozen os>", line 225, in makedirs
PermissionError: [Errno 13] Permission denied: '/opt/lithops'
I see. it seems your user does not have permissions to create this folder /opt/lithops. I will check if we can use a different folder