Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Running the EOS setup with docker compose fails occassionally #586

Closed
dpakach opened this issue Sep 16, 2020 · 5 comments
Closed

Running the EOS setup with docker compose fails occassionally #586

dpakach opened this issue Sep 16, 2020 · 5 comments
Labels
Category:Defect Existing functionality is not working as expected Type:Bug

Comments

@dpakach
Copy link
Contributor

dpakach commented Sep 16, 2020

Steps

  1. run the EOS setup using docker-compose file included in ocis
  2. Login as user Einstein and try to upload file

Expected behavior

  1. The file upload should always be successful

Actual behavior

  1. The upload is successful sometimes but fails occasionally.

This issue is intermittent. This probably occurs when the services don't start in correct order or due to some race condition

Server logs

ocis          | 2020-09-16T05:32:26.150786420Z 2020-09-16T05:32:26Z INF eos: get md for ref:path:"/hello2.txt"  pkg=rgrpc service=reva traceid=297a61475ebe7e77af84b458d54f71ed
ocis          | 2020-09-16T05:32:26.151749161Z 2020-09-16T05:32:26Z DBG eos: wrap external=/hello2.txt internal=/eos/dockertest/reva/users/4/4c510ada-c86b-4815-8820-42cdf82c3d51/hello2.txt pkg=rgrpc service=reva traceid=297a61475ebe7e77af84b458d54f71ed
ocis          | 2020-09-16T05:32:26.188641860Z 2020-09-16T05:32:26Z INF eos cmd args="[/usr/bin/eos -r 20000 30000 file info /eos/dockertest/reva/users/4/4c510ada-c86b-4815-8820-42cdf82c3d51/hello2.txt -m --comment 297a61475ebe7e77af84b458d54f71ed]" env=[EOS_MGM_URL=root://mgm-master.testnet:1094] err="error: cannot stat '/eos/dockertest/reva/users/4/4c510ada-c86b-4815-8820-42cdf82c3d51/hello2.txt'\n (errc=2) (No such file or directory)\n" exit=2 pkg=rgrpc service=reva traceid=297a61475ebe7e77af84b458d54f71ed
ocis          | 2020-09-16T05:32:26.188681107Z 2020-09-16T05:32:26Z WRN root/go/pkg/mod/github.com/cs3org/[email protected]/internal/grpc/services/storageprovider/storageprovider.go:468 > file not found pkg=rgrpc service=reva traceid=297a61475ebe7e77af84b458d54f71ed
ocis          | 2020-09-16T05:32:26.188686569Z 2020-09-16T05:32:26Z INF unary code=OK end="16/Sep/2020:05:32:26 +0000" from=tcp://127.0.0.1:38306 pkg=rgrpc service=reva start="16/Sep/2020:05:32:26 +0000" time_ns=38313922 traceid=297a61475ebe7e77af84b458d54f71ed uri=/cs3.storage.provider.v1beta1.ProviderAPI/Stat user-agent=grpc-go/1.26.0
ocis          | 2020-09-16T05:32:26.188972479Z 2020-09-16T05:32:26Z INF unary code=OK end="16/Sep/2020:05:32:26 +0000" from=tcp://127.0.0.1:59350 pkg=rgrpc service=reva start="16/Sep/2020:05:32:26 +0000" time_ns=39508793 traceid=297a61475ebe7e77af84b458d54f71ed uri=/cs3.gateway.v1beta1.GatewayAPI/Stat user-agent=grpc-go/1.26.0
ocis          | 2020-09-16T05:32:26.189279665Z 2020-09-16T05:32:26Z DBG skipping auth method=/cs3.gateway.v1beta1.GatewayAPI/InitiateFileUpload pkg=rgrpc service=reva traceid=297a61475ebe7e77af84b458d54f71ed
ocis          | 2020-09-16T05:32:26.189597377Z 2020-09-16T05:32:26Z INF unary code=OK end="16/Sep/2020:05:32:26 +0000" from=tcp://127.0.0.1:59240 pkg=rgrpc service=reva start="16/Sep/2020:05:32:26 +0000" time_ns=117042 traceid=297a61475ebe7e77af84b458d54f71ed uri=/cs3.storage.registry.v1beta1.RegistryAPI/GetStorageProvider user-agent=grpc-go/1.26.0
ocis          | 2020-09-16T05:32:26.190433511Z 2020-09-16T05:32:26Z DBG eos: wrap external=/hello2.txt internal=/eos/dockertest/reva/users/4/4c510ada-c86b-4815-8820-42cdf82c3d51/hello2.txt pkg=rgrpc service=reva traceid=297a61475ebe7e77af84b458d54f71ed
ocis          | 2020-09-16T05:32:26.190611656Z 2020-09-16T05:32:26Z DBG eos: NewUpload info={"ID":"","IsFinal":false,"IsPartial":false,"MetaData":{"dir":"/eos/dockertest/reva/users/4/4c510ada-c86b-4815-8820-42cdf82c3d51","filename":"hello2.txt","mtime":"1599538531.799"},"Offset":0,"PartialUploads":null,"Size":7,"SizeIsDeferred":false,"Storage":null} pkg=rgrpc service=reva traceid=297a61475ebe7e77af84b458d54f71ed
ocis          | 2020-09-16T05:32:26.190630847Z 2020-09-16T05:32:26Z DBG eos: resolved filename info={"ID":"","IsFinal":false,"IsPartial":false,"MetaData":{"dir":"/eos/dockertest/reva/users/4/4c510ada-c86b-4815-8820-42cdf82c3d51","filename":"hello2.txt","mtime":"1599538531.799"},"Offset":0,"PartialUploads":null,"Size":7,"SizeIsDeferred":false,"Storage":null} pkg=rgrpc service=reva traceid=297a61475ebe7e77af84b458d54f71ed
ocis          | 2020-09-16T05:32:26.190800207Z 2020-09-16T05:32:26Z INF file upload data-server=http://localhost:9156/data/ea42403f-dbfe-49fd-b125-e2fbbbca2ebc fn=/home/hello2.txt pkg=rgrpc service=reva traceid=297a61475ebe7e77af84b458d54f71ed xs="map[md5:100 unset:1000]"
ocis          | 2020-09-16T05:32:26.190808676Z 2020-09-16T05:32:26Z INF unary code=OK end="16/Sep/2020:05:32:26 +0000" from=tcp://127.0.0.1:38306 pkg=rgrpc service=reva start="16/Sep/2020:05:32:26 +0000" time_ns=716861 traceid=297a61475ebe7e77af84b458d54f71ed uri=/cs3.storage.provider.v1beta1.ProviderAPI/InitiateFileUpload user-agent=grpc-go/1.26.0
ocis          | 2020-09-16T05:32:26.191151213Z 2020-09-16T05:32:26Z INF unary code=OK end="16/Sep/2020:05:32:26 +0000" from=tcp://127.0.0.1:59350 pkg=rgrpc service=reva start="16/Sep/2020:05:32:26 +0000" time_ns=1791363 traceid=297a61475ebe7e77af84b458d54f71ed uri=/cs3.gateway.v1beta1.GatewayAPI/InitiateFileUpload user-agent=grpc-go/1.26.0
ocis          | 2020-09-16T05:32:26.191556509Z 2020-09-16T05:32:26Z INF http end="16/Sep/2020:05:32:26 +0000" host=127.0.0.1 method=POST pkg=rhttp proto=HTTP/1.1 service=reva size=0 start="16/Sep/2020:05:32:26 +0000" status=201 time_ns=42501360 traceid=297a61475ebe7e77af84b458d54f71ed uri=/remote.php/dav/files/4c510ada-c86b-4815-8820-42cdf82c3d51/ url=/remote.php/dav/files/4c510ada-c86b-4815-8820-42cdf82c3d51/
ocis          | 2020-09-16T05:32:26.205359543Z 2020-09-16T05:32:26Z DBG director found path=/konnect/v1/userinfo policy=reva prefix=/konnect/ routeType=prefix service=proxy
ocis          | 2020-09-16T05:32:26.206036466Z 2020-09-16T05:32:26Z DBG Bind request basedn=dc=example,dc=org binddn=cn=konnectd,ou=sysusers,dc=example,dc=org service=glauth src={"IP":"127.0.0.1","Port":53332,"Zone":""}
ocis          | 2020-09-16T05:32:26.206554908Z 2020-09-16T05:32:26Z DBG using query query={"conjuncts":[{"field":"bleve_type","term":"account"},{"field":"on_premises_sam_account_name","fuzziness":0,"match":"konnectd","prefix_length":0}]} service=accounts
ocis          | 2020-09-16T05:32:26.271380199Z 2020-09-16T05:32:26Z INF access token is already provided pkg=rhttp service=reva traceid=a96e376cf5768913c95efeef1020ed3d
ocis          | 2020-09-16T05:32:26.271504127Z 2020-09-16T05:32:26Z DBG http routing: head=data tail=/ea42403f-dbfe-49fd-b125-e2fbbbca2ebc svc=data pkg=rhttp service=reva
ocis          | 2020-09-16T05:32:26.271512518Z [tusd] 2020/09/16 05:32:26 event="RequestIncoming" method="PATCH" path="/ea42403f-dbfe-49fd-b125-e2fbbbca2ebc" requestId="" 
ocis          | 2020-09-16T05:32:26.271516510Z 2020-09-16T05:32:26Z INF tusd routing: path=/ea42403f-dbfe-49fd-b125-e2fbbbca2ebc pkg=rhttp service=reva traceid=a96e376cf5768913c95efeef1020ed3d
ocis          | 2020-09-16T05:32:26.271520133Z [tusd] 2020/09/16 05:32:26 event="ChunkWriteStart" id="ea42403f-dbfe-49fd-b125-e2fbbbca2ebc" maxSize="7" offset="0" 
ocis          | 2020-09-16T05:32:26.271628364Z [tusd] 2020/09/16 05:32:26 event="ChunkWriteComplete" id="ea42403f-dbfe-49fd-b125-e2fbbbca2ebc" bytesWritten="7" 
ocis          | 2020-09-16T05:32:26.287575316Z [tusd] 2020/09/16 05:32:26 event="ResponseOutgoing" status="500" method="PATCH" path="/ea42403f-dbfe-49fd-b125-e2fbbbca2ebc" error="eosclient: error while executing command: exit status 54" requestId="" 
ocis          | 2020-09-16T05:32:26.288235816Z 2020-09-16T05:32:26Z ERR http end="16/Sep/2020:05:32:26 +0000" host=127.0.0.1 method=PATCH pkg=rhttp proto=HTTP/1.1 service=reva size=57 start="16/Sep/2020:05:32:26 +0000" status=500 time_ns=16189509 traceid=a96e376cf5768913c95efeef1020ed3d uri=/data/ea42403f-dbfe-49fd-b125-e2fbbbca2ebc url=/data/ea42403f-dbfe-49fd-b125-e2fbbbca2ebc
ocis          | 2020-09-16T05:32:26.288961945Z 2020-09-16T05:32:26Z ERR http end="16/Sep/2020:05:32:26 +0000" host=127.0.0.1 method=PATCH pkg=rhttp proto=HTTP/1.1 service=reva size=0 start="16/Sep/2020:05:32:26 +0000" status=500 time_ns=18570261 traceid=a96e376cf5768913c95efeef1020ed3d uri=/data/eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJyZXZhIiwiZXhwIjoxNjAwMzIwNzQ2LCJpYXQiOjE2MDAyMzQzNDYsInRhcmdldCI6Imh0dHA6Ly9sb2NhbGhvc3Q6OTE1Ni9kYXRhL2VhNDI0MDNmLWRiZmUtNDlmZC1iMTI1LWUyZmJiYmNhMmViYyJ9.EcRVATrAbXjc_PK4mwoTAU6VXSnWemsgW8o6r1GgHsg url=/data/eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJyZXZhIiwiZXhwIjoxNjAwMzIwNzQ2LCJpYXQiOjE2MDAyMzQzNDYsInRhcmdldCI6Imh0dHA6Ly9sb2NhbGhvc3Q6OTE1Ni9kYXRhL2VhNDI0MDNmLWRiZmUtNDlmZC1iMTI1LWUyZmJiYmNhMmViYyJ9.EcRVATrAbXjc_PK4mwoTAU6VXSnWemsgW8o6r1GgHsg
ocis          | 2020-09-16T05:32:26.289193520Z 2020-09-16 05:32:26.289076 I | httputil: ReverseProxy read error during body copy: unexpected EOF
ocis          | 2020-09-16T05:32:26.289201729Z 2020-09-16 05:32:26.289157 I | suppressing panic for copyResponse error in test; copy error: unexpected EOF
ocis          | 2020-09-16T05:32:26.315557329Z 2020-09-16T05:32:26Z DBG director found path=/konnect/v1/userinfo policy=reva prefix=/konnect/ routeType=prefix service=proxy
ocis          | 2020-09-16T05:32:26.316536104Z 2020-09-16T05:32:26Z DBG Bind request basedn=dc=example,dc=org binddn=cn=konnectd,ou=sysusers,dc=example,dc=org service=glauth src={"IP":"127.0.0.1","Port":53344,"Zone":""}
ocis          | 2020-09-16T05:32:26.318874020Z 2020-09-16T05:32:26Z DBG using query query={"conjuncts":[{"field":"bleve_type","term":"account"},{"field":"on_premises_sam_account_name","fuzziness":0,"match":"konnectd","prefix_length":0}]} service=accounts
@jnweiger
Copy link
Contributor

jnweiger commented Nov 6, 2020

@dpakach We currently has two official compose files:

  • ocis/ocis/docker-compose.yml
  • ocis/ocis/docker-compose-eos-test.yml

The second one is new, maybe that can solve some of your issues?

@settings settings bot removed the bug label Jan 12, 2021
@refs refs added the Category:Defect Existing functionality is not working as expected label Jan 13, 2021
@refs
Copy link
Member

refs commented Jan 13, 2021

ping @dpakach

@dpakach
Copy link
Contributor Author

dpakach commented Jan 13, 2021

@refs I'll try running it again tomorrow and see if the setup is stable

@refs
Copy link
Member

refs commented Jan 13, 2021

@refs I'll try running it again tomorrow and see if the setup is stable

Thanks! didn't intend to distract you, just pinging to get another pair of eyes.

@refs refs changed the title [EOS] Running the EOS setup with docker compose fails occassionally Running the EOS setup with docker compose fails occassionally Jan 18, 2021
@settings settings bot removed the Storage:EOS label Jan 29, 2021
@settings settings bot removed the p3-medium label Apr 7, 2021
@butonic
Copy link
Member

butonic commented Jul 1, 2021

eos tests are no longer covered by ocis ci. it should run in reva or elsewhere.

@butonic butonic closed this as completed Jul 1, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Category:Defect Existing functionality is not working as expected Type:Bug
Projects
None yet
Development

No branches or pull requests

4 participants