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

small race in the HTTP watch init code #198

Closed
samoht opened this issue Apr 28, 2015 · 5 comments
Closed

small race in the HTTP watch init code #198

samoht opened this issue Apr 28, 2015 · 5 comments
Labels
type/bug Related to a bug

Comments

@samoht
Copy link
Member

samoht commented Apr 28, 2015

This is sometimes triggered if you run ./test.native test HTTP.MEM 4 --verbose &> l in a loop.

@samoht samoht added the type/bug Related to a bug label Apr 28, 2015
samoht referenced this issue in samoht/irmin Apr 28, 2015
@talex5
Copy link
Contributor

talex5 commented May 18, 2015

Is this bug this error?

### stderr ###
# Failure("Fail workers:  watch-tag add 0:true x=1/0/0:1/1 s=0/0/0:0/0 0/0 (322, 300.810s): expecting 0/0, got 0/1")
# W: Test 'test_irmin' fails: Command '/home/travis/.opam/system/build/irmin.0.9.4/_build/lib_test/test.native -q' terminated with error code 2
# E: Failure("Tests had a 100.00% failure rate")
# make: *** [test] Error 1

Because if so, it can also mess up Travis builds for programs that depend on Irmin ;-) (maybe we should only run tests for the package being tested?)

@samoht
Copy link
Member Author

samoht commented May 18, 2015

yes this is indeed the error ... I need to find time to fix this, sorry :-(

talex5 added a commit to talex5/cuekeeper that referenced this issue May 18, 2015
Using "TESTS=true" also runs e.g. Irmin's unit tests, which is slow and
sometimes fails (see mirage/irmin#198).
talex5 added a commit to talex5/cuekeeper that referenced this issue May 18, 2015
Using "TESTS=true" also runs e.g. Irmin's unit tests, which is slow and
sometimes fails (see mirage/irmin#198).
@talex5
Copy link
Contributor

talex5 commented May 18, 2015

No problem; just checking it was known!

talex5 added a commit to talex5/irmin that referenced this issue May 18, 2015
For some reason, mirage#198 is happening more frequently now.
@samoht
Copy link
Member Author

samoht commented Jun 10, 2015

maybe we should only run tests for the package being tested

the opam file has been fixed to do this in 0.9.5

@samoht
Copy link
Member Author

samoht commented Jun 19, 2015

Can definitely reproduce with the test loop described in the first post:

2015-06-19 15:35:06.413 HTTP         DEBUG: post /tag/watch {"task":{"date":"1434724506","uid":"661","owner":"Irmin piana.mac.cl.cam.ac.uk.[..
2015-06-19 15:35:06.413 WATCH        DEBUG: watch [6: 0k/0g]: id=50
--------------------------------------------------------------------------------
2015-06-19 15:35:06.413              INFO : ASSERT workers: [pre-condition] watch-tag add 0:true x=0/0/0:1/0 s=0/0/0:0/0 0/0 (0, 0.000s)
--------------------------------------------------------------------------------
--------------------------------------------------------------------------------
2015-06-19 15:35:06.413              INFO : ASSERT state: [pre-condition] watch-tag add 0:true x=0/0/0:1/0 s=0/0/0:0/0 (0, 0.000s)
--------------------------------------------------------------------------------
2015-06-19 15:35:06.413              DEBUG: [waiting for]  watch-tag add 0:true x=1/0/0:1/1 s=0/0/0:0/0
2015-06-19 15:35:06.413 HTTP         DEBUG: post /tag/update/t0 {"params":"ffde71f2990949351222f5fe8968cde1d819703c"}
2015-06-19 15:35:06.416 HTTP.server  INFO : Connection 15: POST /tag/update/t0
2015-06-19 15:35:06.416 HTTP.server  DEBUG: process: length=53 body="{\"params\":\"ffde71f2990949351222f5fe8968cde1d819703c\"}"
2015-06-19 15:35:06.416 MEM          DEBUG: update
2015-06-19 15:35:06.416 WATCH        DEBUG: notify-all[3.0]: firing!
2015-06-19 15:35:06.416 WATCH        DEBUG: notify-all[3.1]: firing!
2015-06-19 15:35:06.416 HTTP.server  INFO : Connection 14: POST /tag/watch
2015-06-19 15:35:06.416 HTTP.server  DEBUG: process: length=115 body="{\"task\":{\"date\":\"1434724506\",\"uid\":\"661\",\"owner\":\"Irmin piana.mac.cl.cam.ac.uk.[.."
2015-06-19 15:35:06.416 HTTP         DEBUG: got response: {"result":null}
2015-06-19 15:35:06.416 WATCH        DEBUG: watch [3: 0k/2g]: id=2
2015-06-19 15:35:06.416              DEBUG: check-worker: expected 0/1, got 0/0
2015-06-19 15:35:06.416 HTTP.server  DEBUG: Connection 15: closed!
2015-06-19 15:35:06.418              DEBUG: Test.retry 0, 0.001s
2015-06-19 15:35:06.418              DEBUG: check-worker: expected 0/1, got 0/0
2015-06-19 15:35:06.420              DEBUG: Test.retry 1, 0.004s
...
2015-06-19 15:40:06.957              DEBUG: Test.retry 320, 300.541s
2015-06-19 15:40:06.958              DEBUG: check-worker: expected 0/1, got 0/0
2015-06-19 15:40:06.965 MEM          DEBUG: iter
                  [ERROR]
Failure("Fail workers:  watch-tag add 0:true x=1/0/0:1/1 s=0/0/0:0/0 0/0 (321, 300.541s): expecting 0/0, got 0/1")

@samoht samoht closed this as completed in a74fd49 Jun 23, 2015
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
type/bug Related to a bug
Projects
None yet
Development

No branches or pull requests

2 participants