search

proycon / gecco

Generic Environment for Context-Aware Correction of Orthography
GNU General Public License v3.0
22 stars 7 forks source link

Processes don't exit when threads execute in wrong order (finalising before threads ready) #8

Open proycon opened 8 years ago

proycon commented 8 years ago

Gecco processes don't exit properly in certain cases. Output shows "finalising" before "threads ready" in all these cases. Race condition somewhere?

Example log output:

14:29:52.544599 Loading local modules
14:29:52.544660 Modules loaded (0.031049013137817383s)
14:29:52.553045 Starting Tokeniser
14:29:52.732148 Tokeniser finished
14:29:52.732229 Reading FoLiA document
14:29:53.450088 Initialising modules on document
14:29:53.450973         Initialising module errorlist
14:29:53.451012         Initialising module hunspell
14:29:53.451036         Initialising module runon
14:29:53.451056         Initialising module splits
14:29:53.451075         Initialising module confusible_zei_zij
14:29:53.451095         Initialising module confusible_nog_noch
14:29:53.451113         Initialising module confusible_hard_hart
14:29:53.451130         Initialising module confusible_licht_ligt
14:29:53.451147         Initialising module confusible_grootte_grote
14:29:53.451164         Initialising module confusible_deze_dit
14:29:53.451181         Initialising module confusible_de_het
14:29:53.451198         Initialising module confusible_u_uw
14:29:53.451215         Initialising module confusible_kan_ken
14:29:53.451232         Initialising module confusible_me_mijn
14:29:53.451249         Initialising module confusible_word_wordt
14:29:53.451267         Initialising module confusible_hun_zij
14:29:53.451284         Initialising module confusiblesuffix_d_dt
14:29:53.451306         Preparing input of Word
14:29:54.305952 Input ready (0.8558549880981445s)
14:29:54.319317 Processing modules
14:29:54.320611 Processing output...
14:29:54.631710 [hunspell] Adding correction for untitled.p.3.s.1.w.1
14:29:54.836819 [hunspell] Adding correction for untitled.p.6.s.2.w.16
14:29:57.991656 [hunspell] Adding correction for untitled.p.6.s.16.w.15
14:29:58.867755 [hunspell] Adding correction for untitled.p.9.s.2.w.31
14:29:58.869521 [hunspell] Adding correction for untitled.p.9.s.5.w.4
14:29:58.870426 [hunspell] Adding correction for untitled.p.9.s.2.w.15
14:29:59.709621 [hunspell] Adding correction for untitled.p.9.s.10.w.18
14:29:59.740576 [hunspell] Adding correction for untitled.p.10.s.1.w.22
14:30:00.726238 [hunspell] Adding correction for untitled.p.10.s.1.w.36
14:30:01.106829 [hunspell] Adding correction for untitled.p.10.s.1.w.7
14:30:01.110097 [hunspell] Adding correction for untitled.p.10.s.1.w.10
14:30:01.111579 [hunspell] Adding correction for untitled.p.10.s.1.w.34
14:30:01.112581 [hunspell] Adding correction for untitled.p.10.s.1.w.24
14:30:02.708256 [hunspell] Adding correction for untitled.p.13.s.12.w.20
14:30:02.710925 [hunspell] Adding correction for untitled.p.13.s.12.w.17
14:30:02.883386 [hunspell] Adding correction for untitled.p.13.s.21.w.36
14:30:05.040993 [hunspell] Adding correction for untitled.p.13.s.21.w.30
14:30:05.278094 [hunspell] Adding correction for untitled.p.13.s.28.w.11
14:30:05.337748 [confusible_de_het] Adding correction for untitled.p.13.s.35.w.20
14:30:05.666915 [hunspell] Adding correction for untitled.p.15.s.5.w.20
14:30:05.734413 [confusible_de_het] Adding correction for untitled.p.15.s.15.w.3
14:30:07.277669 [confusible_hun_zij] Adding correction for untitled.p.18.s.8.w.2
14:30:08.570857 [hunspell] Adding correction for untitled.p.18.s.19.w.2
14:30:09.060058 [hunspell] Adding correction for untitled.p.20.s.23.w.19
14:30:09.799702 [hunspell] Adding correction for untitled.p.20.s.32.w.27
14:30:09.898175 [confusible_deze_dit] Adding correction for untitled.p.22.s.4.w.13
14:30:10.724452 [hunspell] Adding correction for untitled.p.23.s.3.w.19
14:30:10.769361 [hunspell] Adding correction for untitled.p.23.s.12.w.16
14:30:10.870364 [hunspell] Adding correction for untitled.p.23.s.12.w.18
14:30:10.927537 [confusible_hun_zij] Adding correction for untitled.p.23.s.19.w.3
14:30:10.965381 [hunspell] Adding correction for untitled.p.23.s.27.w.3
14:30:11.128947 [hunspell] Adding correction for untitled.p.24.s.4.w.8
14:30:11.130733 Finalising modules on document
14:30:11.131760 Saving document /scratch2/www/webservices-lst/live/writable/valkuil/projects/internal/Dd7dfd93a0da756482b98c7ceecfd1bad/output//Dd7dfd93a0da756482b98c7ceecfd1bad.xml....
14:29:54.336508 12 threads ready.
14:30:11.129039 Input queue processed (16.809709310531616s)
        hunspell        42.5152s        261 calls       27 corrections
        runon   0.1869s 537 calls       0 corrections
        splits  0.1708s 572 calls       2 corrections
        errorlist       0.1447s 538 calls       0 corrections
        confusible_de_het       0.038s  47 calls        2 corrections
        confusiblesuffix_d_dt   0.0118s 9 calls 0 corrections
        confusible_nog_noch     0.004s  2 calls 0 corrections
        confusible_licht_ligt   0.002s  1 calls 0 corrections
        confusible_kan_ken      0.0017s 1 calls 0 corrections
        confusible_deze_dit     0.0013s 1 calls 1 corrections
14:30:12.137501 Processing done (real total 17.75s , virtual output 43.07635712623596s, real input 16.809709310531616s)
proycon commented 8 years ago

Seems solved...

proycon commented 8 years ago

Reopening, it's still not solved..

proycon commented 8 years ago

Even that didn't work :(

[CLAM Dispatcher] Adding to PYTHONPATH: /scratch2/www/valkuil-gecco/valkuilwebservice
[CLAM Dispatcher] Started CLAM Dispatcher v2.1 with valkuilwebservice (2016-04-01 12:03:43)
[CLAM Dispatcher] Running /scratch2/www/valkuil-gecco/valkuilwebservice/valkuilwebservice_wrapper.py "/scratch2/www/valkuil-gecco/" "/scratch2/www/webservices-lst/live/writable/valkuil/projects/proycon/associatieverdrag/clam.xml" "/scratch2/www/webservices-lst/live/writable/valkuil/projects/proycon/associatieverdrag/.status" "/scratch2/www/webservices-lst/live/writable/valkuil/projects/proycon/associatieverdrag/output/"
[CLAM Dispatcher] Running with pid 27704 (2016-04-01 12:03:43)
Initiating tokeniser...
12:03:44.556610 GECCO v0.2 using valkuil
12:03:44.556699 Loading remote modules
12:03:44.559710 Connection to hunspell@applejack.science.ru.nl:61986 refused
12:03:44.562603 Connection to confusible_grootte_grote@applejack.science.ru.nl:12655 refused
12:03:44.562779 Connection to confusible_me_mijn@applejack.science.ru.nl:42951 refused
12:03:44.562928 Connection to confusiblesuffix_d_dt@applejack.science.ru.nl:42316 refused
12:03:44.563072 Connection to splits@applejack.science.ru.nl:28042 refused
12:03:44.565758 Connection to confusible_word_wordt@applejack.science.ru.nl:32457 refused
12:03:44.565951 Connection to confusible_kan_ken@applejack.science.ru.nl:38879 refused
12:03:44.567817 Connection to confusible_u_uw@applejack.science.ru.nl:34219 refused
12:03:44.567979 Connection to confusible_hard_hart@applejack.science.ru.nl:27366 refused
12:03:44.570054 Connection to errorlist@applejack.science.ru.nl:17777 refused
12:03:44.571067 Connection to confusible_hun_zij@applejack.science.ru.nl:14822 refused
12:03:44.572929 Connection to confusible_de_het@applejack.science.ru.nl:20696 refused
12:03:44.575767 Connection to confusible_licht_ligt@applejack.science.ru.nl:14723 refused
12:03:44.575927 Connection to confusible_deze_dit@applejack.science.ru.nl:49224 refused
12:03:44.577755 Connection to confusible_nog_noch@applejack.science.ru.nl:55560 refused
12:03:44.577935 Connection to runon@applejack.science.ru.nl:19897 refused
12:03:44.579107 Connection to confusible_zei_zij@applejack.science.ru.nl:20629 refused
12:03:44.579906   found confusible_u_uw@applejack.science.ru.nl:42974, load 0.0890625
12:03:44.579949   found confusiblesuffix_d_dt@applejack.science.ru.nl:10310, load 0.0890625
12:03:44.579972 [confusiblesuffix_d_dt] Loading models (for client)...
12:03:44.580200   found confusible_hun_zij@applejack.science.ru.nl:35181, load 0.0890625
12:03:44.580225   found confusible_word_wordt@applejack.science.ru.nl:48016, load 0.0890625
12:03:44.580245   found splits@applejack.science.ru.nl:31055, load 0.0890625
12:03:44.580263   found confusible_deze_dit@applejack.science.ru.nl:62711, load 0.0890625
12:03:44.580280   found confusible_zei_zij@applejack.science.ru.nl:36871, load 0.0890625
12:03:44.580297   found confusible_grootte_grote@applejack.science.ru.nl:29716, load 0.0890625
12:03:44.580314   found errorlist@applejack.science.ru.nl:60348, load 0.0890625
12:03:44.580331   found confusible_hard_hart@applejack.science.ru.nl:51753, load 0.0890625
12:03:44.580348   found hunspell@applejack.science.ru.nl:35750, load 0.0890625
12:03:44.580382   found confusible_me_mijn@applejack.science.ru.nl:49124, load 0.0890625
12:03:44.580401   found runon@applejack.science.ru.nl:39545, load 0.0890625
12:03:44.580418   found confusible_licht_ligt@applejack.science.ru.nl:62224, load 0.0890625
12:03:44.580435   found confusible_kan_ken@applejack.science.ru.nl:35115, load 0.0890625
12:03:44.580452   found confusible_nog_noch@applejack.science.ru.nl:25095, load 0.0890625
12:03:44.580469   found confusible_de_het@applejack.science.ru.nl:38021, load 0.0890625
12:03:44.580484 Loading local modules
12:03:44.580560 Modules loaded (0.023856639862060547s)
12:03:44.590972 Starting Tokeniser
12:03:48.533438 Tokeniser finished
12:03:48.533831 Reading FoLiA document
12:04:00.262395 Initialising modules on document
12:04:00.324986     Initialising module errorlist
12:04:00.325068     Initialising module hunspell
12:04:00.325094     Initialising module runon
12:04:00.325114     Initialising module splits
12:04:00.325135     Initialising module confusible_zei_zij
12:04:00.325156     Initialising module confusible_nog_noch
12:04:00.325175     Initialising module confusible_hard_hart
12:04:00.325196     Initialising module confusible_licht_ligt
12:04:00.325214     Initialising module confusible_grootte_grote
12:04:00.325231     Initialising module confusible_deze_dit
12:04:00.325251     Initialising module confusible_de_het
12:04:00.325269     Initialising module confusible_u_uw
12:04:00.325288     Initialising module confusible_kan_ken
12:04:00.325308     Initialising module confusible_me_mijn
12:04:00.325329     Initialising module confusible_word_wordt
12:04:00.325346     Initialising module confusible_hun_zij
12:04:00.325364     Initialising module confusiblesuffix_d_dt
12:04:00.325406     Preparing input of Word
12:04:21.251591 Input ready (20.989173889160156s)
12:04:21.260525 Processing modules
12:04:21.263803 12 threads ready.
12:04:21.262134 Waiting for processors to be ready...
12:04:21.334403 Processing output...
12:04:21.410914 [hunspell] Adding correction for untitled.p.3.s.1.w.11
12:04:21.804288 [confusible_de_het] Adding correction for untitled.p.42.s.1.w.62
12:04:22.579244 [hunspell] Adding correction for untitled.p.42.s.1.w.42
....
12:07:33.055228 [hunspell] Adding correction for untitled.p.3050.s.1.w.36
12:07:33.801895 Finalising modules on document
12:07:33.802488 Saving document /scratch2/www/webservices-lst/live/writable/valkuil/projects/proycon/associatieverdrag/output//verdrag.xml....
12:04:21.334197 12 threads started.
12:07:33.800457 Input queue processed (192.5399284362793s)
    hunspell    14.0761s    272 calls   288 corrections
    runon   0.1436s 518 calls   2 corrections
    splits  0.1329s 569 calls   45 corrections
    errorlist   0.0968s 519 calls   0 corrections
    confusible_de_het   0.0509s 81 calls    130 corrections
    confusiblesuffix_d_dt   0.0052s 4 calls 1 corrections
    confusible_deze_dit 0.0035s 3 calls 7 corrections
    confusible_hun_zij  0.0028s 1 calls 6 corrections
    confusible_kan_ken  0.0025s 2 calls 0 corrections
    confusible_nog_noch 0.0016s 1 calls 7 corrections
12:08:14.382210 Cleanup...
12:08:14.382320 Processing done (real total 233.05s , virtual output 14.515918016433716s, real input 192.5399284362793s)
proycon commented 8 years ago

Committed some more fixes, might be fixed now... wait to see what happens on server...

proycon commented 8 years ago

There are still lingering processes, but their project directories are already gone and the master process seems to have exited (so it changed into a related but different issue now):

access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:06 +0200] "PUT /valkuil/Db4c8cc29844362a338e729b45f26387b/ HTTP/1.1" 401 328 "-" "CLAMClientAPI-0.9.13"
access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:06 +0200] "PUT /valkuil/Db4c8cc29844362a338e729b45f26387b/ HTTP/1.1" 201 455 "-" "CLAMClientAPI-0.9.13"
access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:06 +0200] "GET /valkuil/Db4c8cc29844362a338e729b45f26387b/ HTTP/1.1" 401 328 "-" "CLAMClientAPI-0.9.13"
access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:06 +0200] "GET /valkuil/Db4c8cc29844362a338e729b45f26387b/ HTTP/1.1" 200 2939 "-" "CLAMClientAPI-0.9.13"
access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:06 +0200] "POST /valkuil/Db4c8cc29844362a338e729b45f26387b/input/Db4c8cc29844362a338e729b45f26387b.txt HTTP/1.1" 401 328 "-" "CLAMClientAPI-0.9.13"
access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:06 +0200] "POST /valkuil/Db4c8cc29844362a338e729b45f26387b/input/Db4c8cc29844362a338e729b45f26387b.txt HTTP/1.1" 200 545 "-" "CLAMClientAPI-0.9.13"
access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:06 +0200] "POST /valkuil/Db4c8cc29844362a338e729b45f26387b/ HTTP/1.1" 401 328 "-" "CLAMClientAPI-0.9.13"
access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:07 +0200] "POST /valkuil/Db4c8cc29844362a338e729b45f26387b/ HTTP/1.1" 202 1477 "-" "CLAMClientAPI-0.9.13"
access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:07 +0200] "GET /valkuil/Db4c8cc29844362a338e729b45f26387b/ HTTP/1.1" 401 328 "-" "CLAMClientAPI-0.9.13"
access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:07 +0200] "GET /valkuil/Db4c8cc29844362a338e729b45f26387b/ HTTP/1.1" 200 876 "-" "CLAMClientAPI-0.9.13"
access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:08 +0200] "GET /valkuil/Db4c8cc29844362a338e729b45f26387b/ HTTP/1.1" 401 328 "-" "CLAMClientAPI-0.9.13"
access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:08 +0200] "GET /valkuil/Db4c8cc29844362a338e729b45f26387b/ HTTP/1.1" 200 1094 "-" "CLAMClientAPI-0.9.13"
access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:09 +0200] "GET /valkuil/Db4c8cc29844362a338e729b45f26387b/ HTTP/1.1" 401 328 "-" "CLAMClientAPI-0.9.13"
access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:09 +0200] "GET /valkuil/Db4c8cc29844362a338e729b45f26387b/ HTTP/1.1" 200 1094 "-" "CLAMClientAPI-0.9.13"
access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:10 +0200] "GET /valkuil/Db4c8cc29844362a338e729b45f26387b/ HTTP/1.1" 401 328 "-" "CLAMClientAPI-0.9.13"
access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:11 +0200] "GET /valkuil/Db4c8cc29844362a338e729b45f26387b/ HTTP/1.1" 200 1118 "-" "CLAMClientAPI-0.9.13"
access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:12 +0200] "GET /valkuil/Db4c8cc29844362a338e729b45f26387b/ HTTP/1.1" 401 328 "-" "CLAMClientAPI-0.9.13"
access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:12 +0200] "GET /valkuil/Db4c8cc29844362a338e729b45f26387b/ HTTP/1.1" 200 4820 "-" "CLAMClientAPI-0.9.13"
access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:12 +0200] "GET /valkuil/Db4c8cc29844362a338e729b45f26387b/output/error.log/metadata HTTP/1.1" 401 328 "-" "CLAMClientAPI-0.9.13"
access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:12 +0200] "GET /valkuil/Db4c8cc29844362a338e729b45f26387b/output/error.log/metadata HTTP/1.1" 404 191 "-" "CLAMClientAPI-0.9.13"
access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:12 +0200] "GET /valkuil/Db4c8cc29844362a338e729b45f26387b/output/Db4c8cc29844362a338e729b45f26387b.xml/metadata HTTP/1.1" 401 328 "-" "CLAMClientAPI-0.9.13"
access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:12 +0200] "GET /valkuil/Db4c8cc29844362a338e729b45f26387b/output/Db4c8cc29844362a338e729b45f26387b.xml/metadata HTTP/1.1" 200 1125 "-" "CLAMClientAPI-0.9.13"
access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:12 +0200] "GET /valkuil/Db4c8cc29844362a338e729b45f26387b/input/Db4c8cc29844362a338e729b45f26387b.folia.xml/metadata HTTP/1.1" 401 328 "-" "CLAMClientAPI-0.9.13"
access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:13 +0200] "GET /valkuil/Db4c8cc29844362a338e729b45f26387b/input/Db4c8cc29844362a338e729b45f26387b.folia.xml/metadata HTTP/1.1" 404 191 "-" "CLAMClientAPI-0.9.13"
access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:13 +0200] "GET /valkuil/Db4c8cc29844362a338e729b45f26387b/input/Db4c8cc29844362a338e729b45f26387b.txt/metadata HTTP/1.1" 401 328 "-" "CLAMClientAPI-0.9.13"
access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:13 +0200] "GET /valkuil/Db4c8cc29844362a338e729b45f26387b/input/Db4c8cc29844362a338e729b45f26387b.txt/metadata HTTP/1.1" 200 343 "-" "CLAMClientAPI-0.9.13"
access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:14 +0200] "GET /valkuil/Db4c8cc29844362a338e729b45f26387b/output/Db4c8cc29844362a338e729b45f26387b.xml/metadata HTTP/1.1" 401 328 "-" "CLAMClientAPI-0.9.13"
access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:14 +0200] "GET /valkuil/Db4c8cc29844362a338e729b45f26387b/output/Db4c8cc29844362a338e729b45f26387b.xml/metadata HTTP/1.1" 200 1125 "-" "CLAMClientAPI-0.9.13"
access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:14 +0200] "GET /valkuil/Db4c8cc29844362a338e729b45f26387b/output/Db4c8cc29844362a338e729b45f26387b.xml HTTP/1.1" 401 309 "-" "CLAMCLientAPI-0.9.13"
access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:14 +0200] "GET /valkuil/Db4c8cc29844362a338e729b45f26387b/output/Db4c8cc29844362a338e729b45f26387b.xml HTTP/1.1" 200 167041 "-" "CLAMCLientAPI-0.9.13"
access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:14 +0200] "DELETE /valkuil/Db4c8cc29844362a338e729b45f26387b/ HTTP/1.1" 401 328 "-" "CLAMClientAPI-0.9.13"
access.log-20160406:131.174.30.3 webservices-lst.science.ru.nl - - [05/Apr/2016:14:12:15 +0200] "DELETE /valkuil/Db4c8cc29844362a338e729b45f26387b/ HTTP/1.1" 200 158 "-" "CLAMClientAPI-0.9.13"