WU not being received by my computer
7 May 2005 13:01:00 UTC
Topic 189125
(moderation:
H E L P ! ! I have my prefrences set to 7 days and keep requesting more WU (Currently have 3) boinc shows WU have been assigned to this computer but I am not getting them.? messages say max of 8 quota reached!
WU not being received by my computer
)
H E L P ! ! I have my prefrences set to 7 days and keep requesting more WU (Currently have 3) boinc shows WU have been assigned to this computer but I am not getting them.? messages say max of 8 quota reached!
Mark, has this problem been happening consistently? We are still trying to track down what's going on when WU go missing. Do you have any sort of firewall or proxy server set up?
Bruce
Director, Einstein@Home
Got problem solved by
)
Got problem solved by switching from boinc 4.19 to boinc 4.37 Thanks - Mark Reiss
Got problem solved by
)
Got problem solved by switching from boinc 4.19 to boinc 4.37 Thanks - Mark Reiss
As of 05/08/05 @ 23:41 New york Time - WU not uploading and total credit and avg. credit not updating. No firewall or proxy in effect. Currently using BOINC v 4.37
Thanks -- Mark Reiss
Got problem solved by
)
Got problem solved by switching from boinc 4.19 to boinc 4.37 Thanks - Mark Reiss
As of 05/08/05 @ 23:41 New york Time - WU not uploading and total credit and avg. credit not updating. No firewall or proxy in effect. Currently using BOINC v 4.37
Thanks -- Mark Reiss
As of 05/08/05 @ 23:50 New York Time - Was able to send in WU & get totals updated by clicking on no new work within projects tab twice.
Thanks -- Mark Reiss
Mark, has this problem been
)
Mark, has this problem been happening consistently? We are still trying to track down what's going on when WU go missing. Do you have any sort of firewall or proxy server set up?
Bruce
Hi Bruce
Just had the same bad experience on a host that is usually very reliable. Messages are posted below for futher diagnosis, but a cursory examination indicates that the scheduler assigns the work to the host, even though it is not confirmed as received by the host. Ultimately, the host cannot request more because of the quota limit. In my case there is a proxy between the host and the net, and as can be seen from the messages, the uploads proceed fine, but the scheduler response is not received.
HostID in question is: 61874
BOINC V4.26 for windows.
I feel sure that tomorrow the host will be able to receive work again, but I'm rather annoyed with the host because of the 16 results that are wasted. If you have any further questions, please let me know. I'd be keen to know what your server logs can unearth. The times in the messages files are local, which is UTC+2.
begin messages:
09/05/2005 16:33:31||Resuming network activity
09/05/2005 16:33:32||Insufficient work; requesting more
09/05/2005 16:33:32|Einstein@Home|Requesting 518400.00 seconds of work
09/05/2005 16:33:32|Einstein@Home|Sending request to scheduler: http://einstein.phys.uwm.edu/EinsteinAtHome_cgi/cgi
09/05/2005 16:33:32|Einstein@Home|Started upload of H1_0723.4__0723.9_0.1_T15_Run2_1_0
09/05/2005 16:33:32|Einstein@Home|Started upload of H1_0723.4__0723.5_0.1_T16_Run2_1_0
09/05/2005 16:34:03|Einstein@Home|Scheduler RPC to http://einstein.phys.uwm.edu/EinsteinAtHome_cgi/cgi failed
09/05/2005 16:34:03|Einstein@Home|No schedulers responded
09/05/2005 16:34:03|Einstein@Home|Deferring communication with project for 1 minutes and 0 seconds
09/05/2005 16:34:12|Einstein@Home|Finished upload of H1_0723.4__0723.9_0.1_T15_Run2_1_0
09/05/2005 16:34:12|Einstein@Home|Throughput 508424 bytes/sec
09/05/2005 16:34:12|Einstein@Home|Started upload of H1_0723.4__0723.8_0.1_T16_Run2_3_0
09/05/2005 16:34:43|Einstein@Home|Finished upload of H1_0723.4__0723.8_0.1_T16_Run2_3_0
09/05/2005 16:34:43|Einstein@Home|Throughput 95129 bytes/sec
09/05/2005 16:34:43|Einstein@Home|Started upload of H1_0723.4__0723.8_0.1_T05_Run2_5_0
09/05/2005 16:34:46|Einstein@Home|Finished upload of H1_0723.4__0723.5_0.1_T16_Run2_1_0
09/05/2005 16:34:46|Einstein@Home|Throughput 3862 bytes/sec
09/05/2005 16:34:46|Einstein@Home|Started upload of H1_0723.4__0723.7_0.1_T15_Run2_4_0
09/05/2005 16:34:53|Einstein@Home|Finished upload of H1_0723.4__0723.8_0.1_T05_Run2_5_0
09/05/2005 16:34:53|Einstein@Home|Throughput 862400 bytes/sec
09/05/2005 16:34:53|Einstein@Home|Started upload of H1_0659.0__0659.4_0.1_T00_Fin1_2_0
09/05/2005 16:35:04||Insufficient work; requesting more
09/05/2005 16:35:04|Einstein@Home|Requesting 518400.00 seconds of work
09/05/2005 16:35:04|Einstein@Home|Sending request to scheduler: http://einstein.phys.uwm.edu/EinsteinAtHome_cgi/cgi
09/05/2005 16:35:11|Einstein@Home|Finished upload of H1_0723.4__0723.7_0.1_T15_Run2_4_0
09/05/2005 16:35:11|Einstein@Home|Throughput 345638 bytes/sec
09/05/2005 16:35:11|Einstein@Home|Started upload of H1_0659.0__0659.0_0.1_T01_Fin1_3_0
09/05/2005 16:35:32|Einstein@Home|Finished upload of H1_0659.0__0659.4_0.1_T00_Fin1_2_0
09/05/2005 16:35:32|Einstein@Home|Throughput 294852 bytes/sec
09/05/2005 16:35:32|Einstein@Home|Started upload of H1_0659.0__0659.1_0.1_T01_Fin1_2_0
09/05/2005 16:35:35|Einstein@Home|Finished upload of H1_0659.0__0659.0_0.1_T01_Fin1_3_0
09/05/2005 16:35:35|Einstein@Home|Throughput 669632 bytes/sec
09/05/2005 16:35:35|Einstein@Home|Started upload of H1_0659.0__0659.1_0.1_T00_Fin1_5_0
09/05/2005 16:35:40|Einstein@Home|Scheduler RPC to http://einstein.phys.uwm.edu/EinsteinAtHome_cgi/cgi failed
09/05/2005 16:35:40|Einstein@Home|No schedulers responded
09/05/2005 16:35:40|Einstein@Home|Deferring communication with project for 1 minutes and 0 seconds
09/05/2005 16:36:08|Einstein@Home|Finished upload of H1_0659.0__0659.1_0.1_T01_Fin1_2_0
09/05/2005 16:36:08|Einstein@Home|Throughput 720821 bytes/sec
09/05/2005 16:36:08|Einstein@Home|Started upload of H1_0659.0__0659.2_0.1_T01_Fin1_1_0
09/05/2005 16:36:41||Insufficient work; requesting more
09/05/2005 16:36:41|Einstein@Home|Requesting 518400.00 seconds of work
09/05/2005 16:36:41|Einstein@Home|Sending request to scheduler: http://einstein.phys.uwm.edu/EinsteinAtHome_cgi/cgi
09/05/2005 16:37:07|Einstein@Home|Scheduler RPC to http://einstein.phys.uwm.edu/EinsteinAtHome_cgi/cgi succeeded
09/05/2005 16:37:07|Einstein@Home|Message from server: No work sent
09/05/2005 16:37:07|Einstein@Home|Message from server: (reached daily quota of 16 results)
09/05/2005 16:37:07|Einstein@Home|No work from project
09/05/2005 16:37:07|Einstein@Home|Deferring communication with project for 1 hours, 0 minutes, and 0 seconds
09/05/2005 16:37:17|Einstein@Home|Finished upload of H1_0659.0__0659.1_0.1_T00_Fin1_5_0
09/05/2005 16:37:17|Einstein@Home|Throughput 5132 bytes/sec
09/05/2005 16:37:18|Einstein@Home|Finished upload of H1_0659.0__0659.2_0.1_T01_Fin1_1_0
09/05/2005 16:37:18|Einstein@Home|Throughput 39340 bytes/sec
09/05/2005 16:41:57||Suspending network activity - user request
Just to add my own troubles
)
Just to add my own troubles to the list. I just switched from 4.19 to 4.25 a few days ago.
I am now having the same problem. WU's are listed on the results page of my account but have not made it to my computers.
Einstein is the only project to have this behaviour, Seti, LCH, Protein all work flawlessly.
Einstein is the only project
)
Einstein is the only project to have this behaviour, Seti, LCH, Protein all work flawlessly.
Actually, I've seen this before on SETI about a month ago. Different host than this one though, and with BOINC v4.25. Only affected about 7 or 8 WU's, IIRC.
I suspect that the scheduler request->assign->send->acknowledge logic is a bit flawed and fails under certain conditions. If I get a chance, I'll try and figure it out and see if I can spot anything that looks like a problem.
I feel sure that tomorrow the
)
I feel sure that tomorrow the host will be able to receive work again,...
Well, another two scheduler requests, another 16 WU's assigned and another two "No schedulers responded" today. :(
To troubleshoot this, I'm going to put my proxy in full debug mode and capture everything that's being sent and received.
Unfortunately, it'll be another 24 hours before I'll be able to report back. If I try again now, I'll just get another "reached daily quota" reply...
Mark, has this problem been
)
Mark, has this problem been happening consistently? We are still trying to track down what's going on when WU go missing. Do you have any sort of firewall or proxy server set up?
Bruce
Hi Bruce
Just had the same bad experience on a host that is usually very reliable. Messages are posted below for futher diagnosis, but a cursory examination indicates that the scheduler assigns the work to the host, even though it is not confirmed as received by the host. Ultimately, the host cannot request more because of the quota limit. In my case there is a proxy between the host and the net, and as can be seen from the messages, the uploads proceed fine, but the scheduler response is not received.
HostID in question is: 61874
BOINC V4.26 for windows.
I feel sure that tomorrow the host will be able to receive work again, but I'm rather annoyed with the host because of the 16 results that are wasted. If you have any further questions, please let me know. I'd be keen to know what your server logs can unearth. The times in the messages files are local, which is UTC+2.
begin messages:
09/05/2005 16:33:31||Resuming network activity
09/05/2005 16:33:32||Insufficient work; requesting more
09/05/2005 16:33:32|Einstein@Home|Requesting 518400.00 seconds of work
09/05/2005 16:33:32|Einstein@Home|Sending request to scheduler: http://einstein.phys.uwm.edu/EinsteinAtHome_cgi/cgi
09/05/2005 16:33:32|Einstein@Home|Started upload of H1_0723.4__0723.9_0.1_T15_Run2_1_0
09/05/2005 16:33:32|Einstein@Home|Started upload of H1_0723.4__0723.5_0.1_T16_Run2_1_0
09/05/2005 16:34:03|Einstein@Home|Scheduler RPC to http://einstein.phys.uwm.edu/EinsteinAtHome_cgi/cgi failed
09/05/2005 16:34:03|Einstein@Home|No schedulers responded
09/05/2005 16:34:03|Einstein@Home|Deferring communication with project for 1 minutes and 0 seconds
09/05/2005 16:34:12|Einstein@Home|Finished upload of H1_0723.4__0723.9_0.1_T15_Run2_1_0
09/05/2005 16:34:12|Einstein@Home|Throughput 508424 bytes/sec
09/05/2005 16:34:12|Einstein@Home|Started upload of H1_0723.4__0723.8_0.1_T16_Run2_3_0
09/05/2005 16:34:43|Einstein@Home|Finished upload of H1_0723.4__0723.8_0.1_T16_Run2_3_0
09/05/2005 16:34:43|Einstein@Home|Throughput 95129 bytes/sec
09/05/2005 16:34:43|Einstein@Home|Started upload of H1_0723.4__0723.8_0.1_T05_Run2_5_0
09/05/2005 16:34:46|Einstein@Home|Finished upload of H1_0723.4__0723.5_0.1_T16_Run2_1_0
09/05/2005 16:34:46|Einstein@Home|Throughput 3862 bytes/sec
09/05/2005 16:34:46|Einstein@Home|Started upload of H1_0723.4__0723.7_0.1_T15_Run2_4_0
09/05/2005 16:34:53|Einstein@Home|Finished upload of H1_0723.4__0723.8_0.1_T05_Run2_5_0
09/05/2005 16:34:53|Einstein@Home|Throughput 862400 bytes/sec
09/05/2005 16:34:53|Einstein@Home|Started upload of H1_0659.0__0659.4_0.1_T00_Fin1_2_0
09/05/2005 16:35:04||Insufficient work; requesting more
09/05/2005 16:35:04|Einstein@Home|Requesting 518400.00 seconds of work
09/05/2005 16:35:04|Einstein@Home|Sending request to scheduler: http://einstein.phys.uwm.edu/EinsteinAtHome_cgi/cgi
09/05/2005 16:35:11|Einstein@Home|Finished upload of H1_0723.4__0723.7_0.1_T15_Run2_4_0
09/05/2005 16:35:11|Einstein@Home|Throughput 345638 bytes/sec
09/05/2005 16:35:11|Einstein@Home|Started upload of H1_0659.0__0659.0_0.1_T01_Fin1_3_0
09/05/2005 16:35:32|Einstein@Home|Finished upload of H1_0659.0__0659.4_0.1_T00_Fin1_2_0
09/05/2005 16:35:32|Einstein@Home|Throughput 294852 bytes/sec
09/05/2005 16:35:32|Einstein@Home|Started upload of H1_0659.0__0659.1_0.1_T01_Fin1_2_0
09/05/2005 16:35:35|Einstein@Home|Finished upload of H1_0659.0__0659.0_0.1_T01_Fin1_3_0
09/05/2005 16:35:35|Einstein@Home|Throughput 669632 bytes/sec
09/05/2005 16:35:35|Einstein@Home|Started upload of H1_0659.0__0659.1_0.1_T00_Fin1_5_0
09/05/2005 16:35:40|Einstein@Home|Scheduler RPC to http://einstein.phys.uwm.edu/EinsteinAtHome_cgi/cgi failed
09/05/2005 16:35:40|Einstein@Home|No schedulers responded
09/05/2005 16:35:40|Einstein@Home|Deferring communication with project for 1 minutes and 0 seconds
09/05/2005 16:36:08|Einstein@Home|Finished upload of H1_0659.0__0659.1_0.1_T01_Fin1_2_0
09/05/2005 16:36:08|Einstein@Home|Throughput 720821 bytes/sec
09/05/2005 16:36:08|Einstein@Home|Started upload of H1_0659.0__0659.2_0.1_T01_Fin1_1_0
09/05/2005 16:36:41||Insufficient work; requesting more
09/05/2005 16:36:41|Einstein@Home|Requesting 518400.00 seconds of work
09/05/2005 16:36:41|Einstein@Home|Sending request to scheduler: http://einstein.phys.uwm.edu/EinsteinAtHome_cgi/cgi
09/05/2005 16:37:07|Einstein@Home|Scheduler RPC to http://einstein.phys.uwm.edu/EinsteinAtHome_cgi/cgi succeeded
09/05/2005 16:37:07|Einstein@Home|Message from server: No work sent
09/05/2005 16:37:07|Einstein@Home|Message from server: (reached daily quota of 16 results)
09/05/2005 16:37:07|Einstein@Home|No work from project
09/05/2005 16:37:07|Einstein@Home|Deferring communication with project for 1 hours, 0 minutes, and 0 seconds
09/05/2005 16:37:17|Einstein@Home|Finished upload of H1_0659.0__0659.1_0.1_T00_Fin1_5_0
09/05/2005 16:37:17|Einstein@Home|Throughput 5132 bytes/sec
09/05/2005 16:37:18|Einstein@Home|Finished upload of H1_0659.0__0659.2_0.1_T01_Fin1_1_0
09/05/2005 16:37:18|Einstein@Home|Throughput 39340 bytes/sec
09/05/2005 16:41:57||Suspending network activity - user request
Here is the relevant part of the scheduler log. The basic problem seems to be that on your end the core client timed out after 36 seconds, whereas on the server, the scheduler continued to run for 61 seconds. I am making some inquiries with the BOINC developers to try and understand if the core client has a time-out which might have caused this broken connection and hence the lost WU.
PS: you might want to use ntp or some other method to set the correct time on your machine. It's off by a few minutes.
Cheers,
Bruce
2005-05-09 14:26:14 [PID=26946] [debug ] REQUEST_METHOD=POST CONTENT_TYPE=application/octet-stream HTTP_ACCEPT= HTTP_USER_AGENT=BOINC client (windows_intelx86 4.26)
2005-05-09 14:26:14 [PID=26946] [debug ] CONTENT_LENGTH=5893 from X.X.X.X
2005-05-09 14:26:15 [PID=26946] [normal ] Handling request: IP X.X.X.X, auth XXX, host 61874, platform windows_intelx86, version 4.26
2005-05-09 14:26:15 [PID=26946] [normal ] OS version Microsoft Windows XP Professional Edition, Service Pack 2, (05.01.2600.00)
2005-05-09 14:26:15 [PID=26946] [debug ] Request [HOST#61874] Database [HOST#61874] Request [RPC#91] Database [RPC#84]
2005-05-09 14:26:15 [PID=26946] [normal ] Processing request from [USER#167] [HOST#61874] [IP X.X.X.X] [RPC#91] core client version 4.26
2005-05-09 14:26:15 [PID=26946] [debug ] [HOST#61874] Resetting nresults_today
2005-05-09 14:26:15 [PID=26946] [normal ] [HOST#61874] [RESULT#3911567 H1_0723.4__0723.5_0.1_T15_Run2_1] got result
2005-05-09 14:26:15 [PID=26946] [debug ] cpu 42878.468750 cpcs 0.001458, cc 62.521891
2005-05-09 14:26:15 [PID=26946] [debug ] [RESULT#3911567 H1_0723.4__0723.5_0.1_T15_Run2_1]: setting outcome SUCCESS
2005-05-09 14:26:15 [PID=26946] [normal ] [HOST#61874] [RESULT#3915377 H1_0723.4__0723.8_0.1_T15_Run2_2] got result
2005-05-09 14:26:15 [PID=26946] [debug ] cpu 42308.968750 cpcs 0.001458, cc 61.691492
2005-05-09 14:26:15 [PID=26946] [debug ] [RESULT#3915377 H1_0723.4__0723.8_0.1_T15_Run2_2]: setting outcome SUCCESS
2005-05-09 14:26:15 [PID=26946] [normal ] [HOST#61874] got request for 518400.000000 seconds of work; available disk 14.636548 GB
2005-05-09 14:26:15 [PID=26946] [debug ] [HOST#61874]: has file H1_0659.0
2005-05-09 14:26:15 [PID=26946] [debug ] in_send_results_for_file(H1_0659.0, 0) prev_result.id=4103282
2005-05-09 14:26:15 [PID=26946] [debug ] Sorted list of URLs follows [host timezone: UTC+7200]
2005-05-09 14:26:15 [PID=26946] [debug ] zone=+03600 url=http://einstein.aei.mpg.de
2005-05-09 14:26:15 [PID=26946] [debug ] zone=+00000 url=http://einstein.astro.gla.ac.uk
2005-05-09 14:26:15 [PID=26946] [debug ] zone=-18000 url=http://einstein.aset.psu.edu
2005-05-09 14:26:15 [PID=26946] [debug ] zone=-18000 url=http://morel.mit.edu
2005-05-09 14:26:15 [PID=26946] [debug ] zone=-21600 url=http://einstein.phys.uwm.edu
2005-05-09 14:26:15 [PID=26946] [debug ] [HOST#61874] Sending app_version einstein windows_intelx86 479
2005-05-09 14:26:15 [PID=26946] [debug ] [HOST#61874] Already has file H1_0659.0
2005-05-09 14:26:15 [PID=26946] [debug ] [HOST#61874] reducing disk needed for WU by 14736000 bytes (length of H1_0659.0)
2005-05-09 14:26:15 [PID=26946] [debug ] est cpu dur 30069.284065; running_frac 0.930656; rsf 0.500000; est 64619.523091
2005-05-09 14:26:15 [PID=26946] [normal ] [HOST#61874] Sending [RESULT#4160517 H1_0659.0__0659.0_0.1_T02_Fin1_3] (fills 64619.52 seconds)
2005-05-09 14:26:15 [PID=26946] [debug ] in_send_results_for_file(H1_0659.0, 1) prev_result.id=4160517
2005-05-09 14:26:15 [PID=26946] [debug ] est cpu dur 30069.284065; running_frac 0.930656; rsf 0.500000; est 64619.523091
2005-05-09 14:26:15 [PID=26946] [debug ] [HOST#61874] Sending app_version einstein windows_intelx86 479
2005-05-09 14:26:15 [PID=26946] [debug ] [HOST#61874] Already has file H1_0659.0
2005-05-09 14:26:15 [PID=26946] [debug ] [HOST#61874] reducing disk needed for WU by 14736000 bytes (length of H1_0659.0)
2005-05-09 14:26:15 [PID=26946] [debug ] est cpu dur 30069.284065; running_frac 0.930656; rsf 0.500000; est 64619.523091
2005-05-09 14:26:15 [PID=26946] [normal ] [HOST#61874] Sending [RESULT#4172748 H1_0659.0__0659.1_0.1_T02_Fin1_1] (fills 64619.52 seconds)
2005-05-09 14:26:15 [PID=26946] [debug ] in_send_results_for_file(H1_0659.0, 2) prev_result.id=4172748
2005-05-09 14:26:15 [PID=26946] [debug ] touched ../locality_scheduling/need_work/H1_0659.0: need work for file H1_0659.0
2005-05-09 14:26:15 [PID=26946] [debug ] make_more_work_for_file(H1_0659.0, 2)=0
2005-05-09 14:26:25 [PID=26946] [debug ] in_send_results_for_file(H1_0659.0, 3) prev_result.id=4172748
2005-05-09 14:26:25 [PID=26946] [debug ] est cpu dur 30069.284065; running_frac 0.930656; rsf 0.500000; est 64619.523091
2005-05-09 14:26:25 [PID=26946] [debug ] [HOST#61874] Sending app_version einstein windows_intelx86 479
2005-05-09 14:26:25 [PID=26946] [debug ] [HOST#61874] Already has file H1_0659.0
2005-05-09 14:26:25 [PID=26946] [debug ] [HOST#61874] reducing disk needed for WU by 14736000 bytes (length of H1_0659.0)
2005-05-09 14:26:25 [PID=26946] [debug ] est cpu dur 30069.284065; running_frac 0.930656; rsf 0.500000; est 64619.523091
2005-05-09 14:26:25 [PID=26946] [normal ] [HOST#61874] Sending [RESULT#4192499 H1_0659.0__0659.2_0.1_T02_Fin1_0] (fills 64619.52 seconds)
2005-05-09 14:26:25 [PID=26946] [debug ] in_send_results_for_file(H1_0659.0, 4) prev_result.id=4192499
2005-05-09 14:26:25 [PID=26946] [debug ] touched ../locality_scheduling/need_work/H1_0659.0: need work for file H1_0659.0
2005-05-09 14:26:25 [PID=26946] [debug ] make_more_work_for_file(H1_0659.0, 4)=0
2005-05-09 14:26:35 [PID=26946] [debug ] in_send_results_for_file(H1_0659.0, 5) prev_result.id=4192499
2005-05-09 14:26:35 [PID=26946] [debug ] est cpu dur 30069.284065; running_frac 0.930656; rsf 0.500000; est 64619.523091
2005-05-09 14:26:35 [PID=26946] [debug ] [HOST#61874] Sending app_version einstein windows_intelx86 479
2005-05-09 14:26:35 [PID=26946] [debug ] [HOST#61874] Already has file H1_0659.0
2005-05-09 14:26:35 [PID=26946] [debug ] [HOST#61874] reducing disk needed for WU by 14736000 bytes (length of H1_0659.0)
2005-05-09 14:26:35 [PID=26946] [debug ] est cpu dur 30069.284065; running_frac 0.930656; rsf 0.500000; est 64619.523091
2005-05-09 14:26:35 [PID=26946] [normal ] [HOST#61874] Sending [RESULT#4192517 H1_0659.0__0659.3_0.1_T02_Fin1_0] (fills 64619.52 seconds)
2005-05-09 14:26:35 [PID=26946] [debug ] in_send_results_for_file(H1_0659.0, 6) prev_result.id=4192517
2005-05-09 14:26:35 [PID=26946] [debug ] touched ../locality_scheduling/need_work/H1_0659.0: need work for file H1_0659.0
2005-05-09 14:26:35 [PID=26946] [debug ] make_more_work_for_file(H1_0659.0, 6)=0
2005-05-09 14:26:45 [PID=26946] [debug ] in_send_results_for_file(H1_0659.0, 7) prev_result.id=4192517
2005-05-09 14:26:45 [PID=26946] [debug ] est cpu dur 30069.284065; running_frac 0.930656; rsf 0.500000; est 64619.523091
2005-05-09 14:26:45 [PID=26946] [debug ] [HOST#61874] Sending app_version einstein windows_intelx86 479
2005-05-09 14:26:45 [PID=26946] [debug ] [HOST#61874] Already has file H1_0659.0
2005-05-09 14:26:45 [PID=26946] [debug ] [HOST#61874] reducing disk needed for WU by 14736000 bytes (length of H1_0659.0)
2005-05-09 14:26:45 [PID=26946] [debug ] est cpu dur 30069.284065; running_frac 0.930656; rsf 0.500000; est 64619.523091
2005-05-09 14:26:45 [PID=26946] [normal ] [HOST#61874] Sending [RESULT#4192533 H1_0659.0__0659.4_0.1_T02_Fin1_0] (fills 64619.52 seconds)
2005-05-09 14:26:45 [PID=26946] [debug ] in_send_results_for_file(H1_0659.0, 8) prev_result.id=4192533
2005-05-09 14:26:45 [PID=26946] [debug ] touched ../locality_scheduling/need_work/H1_0659.0: need work for file H1_0659.0
2005-05-09 14:26:45 [PID=26946] [debug ] make_more_work_for_file(H1_0659.0, 8)=0
2005-05-09 14:26:55 [PID=26946] [debug ] in_send_results_for_file(H1_0659.0, 9) prev_result.id=4192533
2005-05-09 14:26:55 [PID=26946] [debug ] est cpu dur 30069.284065; running_frac 0.930656; rsf 0.500000; est 64619.523091
2005-05-09 14:26:55 [PID=26946] [debug ] [HOST#61874] Sending app_version einstein windows_intelx86 479
2005-05-09 14:26:55 [PID=26946] [debug ] [HOST#61874] Already has file H1_0659.0
2005-05-09 14:26:55 [PID=26946] [debug ] [HOST#61874] reducing disk needed for WU by 14736000 bytes (length of H1_0659.0)
2005-05-09 14:26:55 [PID=26946] [debug ] est cpu dur 30069.284065; running_frac 0.930656; rsf 0.500000; est 64619.523091
2005-05-09 14:26:55 [PID=26946] [normal ] [HOST#61874] Sending [RESULT#4192550 H1_0659.0__0659.0_0.1_T03_Fin1_0] (fills 64619.52 seconds)
2005-05-09 14:26:55 [PID=26946] [debug ] in_send_results_for_file(H1_0659.0, 10) prev_result.id=4192550
2005-05-09 14:26:55 [PID=26946] [debug ] touched ../locality_scheduling/need_work/H1_0659.0: need work for file H1_0659.0
2005-05-09 14:26:55 [PID=26946] [debug ] make_more_work_for_file(H1_0659.0, 10)=0
2005-05-09 14:27:05 [PID=26946] [debug ] in_send_results_for_file(H1_0659.0, 11) prev_result.id=4192550
2005-05-09 14:27:05 [PID=26946] [debug ] est cpu dur 30069.284065; running_frac 0.930656; rsf 0.500000; est 64619.523091
2005-05-09 14:27:05 [PID=26946] [debug ] [HOST#61874] Sending app_version einstein windows_intelx86 479
2005-05-09 14:27:05 [PID=26946] [debug ] [HOST#61874] Already has file H1_0659.0
2005-05-09 14:27:05 [PID=26946] [debug ] [HOST#61874] reducing disk needed for WU by 14736000 bytes (length of H1_0659.0)
2005-05-09 14:27:05 [PID=26946] [debug ] est cpu dur 30069.284065; running_frac 0.930656; rsf 0.500000; est 64619.523091
2005-05-09 14:27:05 [PID=26946] [normal ] [HOST#61874] Sending [RESULT#4192560 H1_0659.0__0659.1_0.1_T03_Fin1_0] (fills 64619.52 seconds)
2005-05-09 14:27:05 [PID=26946] [debug ] in_send_results_for_file(H1_0659.0, 12) prev_result.id=4192560
2005-05-09 14:27:05 [PID=26946] [debug ] touched ../locality_scheduling/need_work/H1_0659.0: need work for file H1_0659.0
2005-05-09 14:27:05 [PID=26946] [debug ] make_more_work_for_file(H1_0659.0, 12)=0
2005-05-09 14:27:15 [PID=26946] [debug ] in_send_results_for_file(H1_0659.0, 13) prev_result.id=4192560
2005-05-09 14:27:15 [PID=26946] [debug ] est cpu dur 30069.284065; running_frac 0.930656; rsf 0.500000; est 64619.523091
2005-05-09 14:27:15 [PID=26946] [debug ] [HOST#61874] Sending app_version einstein windows_intelx86 479
2005-05-09 14:27:15 [PID=26946] [debug ] [HOST#61874] Already has file H1_0659.0
2005-05-09 14:27:15 [PID=26946] [debug ] [HOST#61874] reducing disk needed for WU by 14736000 bytes (length of H1_0659.0)
2005-05-09 14:27:15 [PID=26946] [debug ] est cpu dur 30069.284065; running_frac 0.930656; rsf 0.500000; est 64619.523091
2005-05-09 14:27:15 [PID=26946] [normal ] [HOST#61874] Sending [RESULT#4192571 H1_0659.0__0659.2_0.1_T03_Fin1_0] (fills 64619.52 seconds)
2005-05-09 14:27:15 [PID=26946] [normal ] [HOST#61874] Sent 8 results [scheduler ran 61 seconds]
2005-05-09 14:27:51 [PID=27170] [debug ] REQUEST_METHOD=POST CONTENT_TYPE=application/octet-stream HTTP_ACCEPT= HTTP_USER_AGENT=BOINC client (windows_intelx86 4.26)
2005-05-09 14:27:51 [PID=27170] [debug ] CONTENT_LENGTH=8743 from X.X.X.X
2005-05-09 14:27:57 [PID=27170] [normal ] Handling request: IP X.X.X.X, auth XXX, host 61874, platform windows_intelx86, version 4.26
2005-05-09 14:27:57 [PID=27170] [normal ] OS version Microsoft Windows XP Professional Edition, Service Pack 2, (05.01.2600.00)
2005-05-09 14:27:57 [PID=27170] [debug ] Request [HOST#61874] Database [HOST#61874] Request [RPC#92] Database [RPC#84]
2005-05-09 14:27:57 [PID=27170] [normal ] Processing request from [USER#167] [HOST#61874] [IP X.X.X.X] [RPC#92] core client version 4.26
2005-05-09 14:27:57 [PID=27170] [normal ] [HOST#61874] [RESULT#3911567 H1_0723.4__0723.5_0.1_T15_Run2_1] got result
2005-05-09 14:27:57 [PID=27170] [CRITICAL] [HOST#61874] [RESULT#3911567 H1_0723.4__0723.5_0.1_T15_Run2_1] got result twice
2005-05-09 14:27:57 [PID=27170] [normal ] [HOST#61874] [RESULT#3915377 H1_0723.4__0723.8_0.1_T15_Run2_2] got result
2005-05-09 14:27:57 [PID=27170] [CRITICAL] [HOST#61874] [RESULT#3915377 H1_0723.4__0723.8_0.1_T15_Run2_2] got result twice
2005-05-09 14:27:57 [PID=27170] [normal ] [HOST#61874] [RESULT#3917535 H1_0723.4__0723.9_0.1_T15_Run2_1] got result
2005-05-09 14:27:57 [PID=27170] [debug ] cpu 42579.468750 cpcs 0.001458, cc 62.085913
2005-05-09 14:27:57 [PID=27170] [debug ] [RESULT#3917535 H1_0723.4__0723.9_0.1_T15_Run2_1]: setting outcome SUCCESS
2005-05-09 14:27:57 [PID=27170] [normal ] [HOST#61874] [RESULT#3918538 H1_0723.4__0723.5_0.1_T16_Run2_1] got result
2005-05-09 14:27:57 [PID=27170] [debug ] cpu 42031.906250 cpcs 0.001458, cc 61.287502
2005-05-09 14:27:57 [PID=27170] [debug ] [RESULT#3918538 H1_0723.4__0723.5_0.1_T16_Run2_1]: setting outcome SUCCESS
2005-05-09 14:27:57 [PID=27170] [normal ] [HOST#61874] [RESULT#3924126 H1_0723.4__0723.8_0.1_T16_Run2_3] got result
2005-05-09 14:27:57 [PID=27170] [debug ] cpu 42833.687500 cpcs 0.001458, cc 62.456595
2005-05-09 14:27:57 [PID=27170] [debug ] [RESULT#3924126 H1_0723.4__0723.8_0.1_T16_Run2_3]: setting outcome SUCCESS
2005-05-09 14:27:57 [PID=27170] [normal ] [HOST#61874] [RESULT#3983822 H1_0723.4__0723.8_0.1_T05_Run2_5] got result
2005-05-09 14:27:57 [PID=27170] [debug ] cpu 42275.000000 cpcs 0.001458, cc 61.641962
2005-05-09 14:27:57 [PID=27170] [debug ] [RESULT#3983822 H1_0723.4__0723.8_0.1_T05_Run2_5]: setting outcome SUCCESS
2005-05-09 14:27:57 [PID=27170] [normal ] [HOST#61874] got request for 518400.000000 seconds of work; available disk 14.636548 GB
2005-05-09 14:27:57 [PID=27170] [debug ] [HOST#61874]: has file H1_0659.0
2005-05-09 14:27:57 [PID=27170] [debug ] in_send_results_for_file(H1_0659.0, 0) prev_result.id=4192571
2005-05-09 14:27:57 [PID=27170] [debug ] touched ../locality_scheduling/need_work/H1_0659.0: need work for file H1_0659.0
2005-05-09 14:27:57 [PID=27170] [debug ] make_more_work_for_file(H1_0659.0, 0)=0
2005-05-09 14:28:07 [PID=27170] [debug ] in_send_results_for_file(H1_0659.0, 1) prev_result.id=4192571
2005-05-09 14:28:07 [PID=27170] [debug ] Sorted list of URLs follows [host timezone: UTC+7200]
2005-05-09 14:28:07 [PID=27170] [debug ] zone=+03600 url=http://einstein.aei.mpg.de
2005-05-09 14:28:07 [PID=27170] [debug ] zone=+00000 url=http://einstein.astro.gla.ac.uk
2005-05-09 14:28:07 [PID=27170] [debug ] zone=-18000 url=http://einstein.aset.psu.edu
2005-05-09 14:28:07 [PID=27170] [debug ] zone=-18000 url=http://morel.mit.edu
2005-05-09 14:28:07 [PID=27170] [debug ] zone=-21600 url=http://einstein.phys.uwm.edu
2005-05-09 14:28:07 [PID=27170] [debug ] [HOST#61874] Sending app_version einstein windows_intelx86 479
2005-05-09 14:28:07 [PID=27170] [debug ] [HOST#61874] Already has file H1_0659.0
2005-05-09 14:28:07 [PID=27170] [debug ] [HOST#61874] reducing disk needed for WU by 14736000 bytes (length of H1_0659.0)
2005-05-09 14:28:07 [PID=27170] [debug ] est cpu dur 30069.284065; running_frac 0.930659; rsf 0.500000; est 64619.320680
2005-05-09 14:28:07 [PID=27170] [normal ] [HOST#61874] Sending [RESULT#4192591 H1_0659.0__0659.3_0.1_T03_Fin1_0] (fills 64619.32 seconds)
2005-05-09 14:28:07 [PID=27170] [debug ] in_send_results_for_file(H1_0659.0, 2) prev_result.id=4192591
2005-05-09 14:28:07 [PID=27170] [debug ] touched ../locality_scheduling/need_work/H1_0659.0: need work for file H1_0659.0
2005-05-09 14:28:07 [PID=27170] [debug ] make_more_work_for_file(H1_0659.0, 2)=0
2005-05-09 14:28:17 [PID=27170] [debug ] in_send_results_for_file(H1_0659.0, 3) prev_result.id=4192591
2005-05-09 14:28:17 [PID=27170] [debug ] est cpu dur 30069.284065; running_frac 0.930659; rsf 0.500000; est 64619.320680
2005-05-09 14:28:17 [PID=27170] [debug ] [HOST#61874] Sending app_version einstein windows_intelx86 479
2005-05-09 14:28:17 [PID=27170] [debug ] [HOST#61874] Already has file H1_0659.0
2005-05-09 14:28:17 [PID=27170] [debug ] [HOST#61874] reducing disk needed for WU by 14736000 bytes (length of H1_0659.0)
2005-05-09 14:28:17 [PID=27170] [debug ] est cpu dur 30069.284065; running_frac 0.930659; rsf 0.500000; est 64619.320680
2005-05-09 14:28:17 [PID=27170] [normal ] [HOST#61874] Sending [RESULT#4192595 H1_0659.0__0659.4_0.1_T03_Fin1_0] (fills 64619.32 seconds)
2005-05-09 14:28:17 [PID=27170] [debug ] in_send_results_for_file(H1_0659.0, 4) prev_result.id=4192595
2005-05-09 14:28:17 [PID=27170] [debug ] touched ../locality_scheduling/need_work/H1_0659.0: need work for file H1_0659.0
2005-05-09 14:28:17 [PID=27170] [debug ] make_more_work_for_file(H1_0659.0, 4)=0
2005-05-09 14:28:27 [PID=27170] [debug ] in_send_results_for_file(H1_0659.0, 5) prev_result.id=4192595
2005-05-09 14:28:27 [PID=27170] [debug ] est cpu dur 30069.284065; running_frac 0.930659; rsf 0.500000; est 64619.320680
2005-05-09 14:28:27 [PID=27170] [debug ] [HOST#61874] Sending app_version einstein windows_intelx86 479
2005-05-09 14:28:27 [PID=27170] [debug ] [HOST#61874] Already has file H1_0659.0
2005-05-09 14:28:27 [PID=27170] [debug ] [HOST#61874] reducing disk needed for WU by 14736000 bytes (length of H1_0659.0)
2005-05-09 14:28:27 [PID=27170] [debug ] est cpu dur 30069.284065; running_frac 0.930659; rsf 0.500000; est 64619.320680
2005-05-09 14:28:27 [PID=27170] [normal ] [HOST#61874] Sending [RESULT#4192599 H1_0659.0__0659.0_0.1_T04_Fin1_0] (fills 64619.32 seconds)
2005-05-09 14:28:27 [PID=27170] [debug ] in_send_results_for_file(H1_0659.0, 6) prev_result.id=4192599
2005-05-09 14:28:27 [PID=27170] [debug ] touched ../locality_scheduling/need_work/H1_0659.0: need work for file H1_0659.0
2005-05-09 14:28:27 [PID=27170] [debug ] make_more_work_for_file(H1_0659.0, 6)=0
2005-05-09 14:28:37 [PID=27170] [debug ] in_send_results_for_file(H1_0659.0, 7) prev_result.id=4192599
2005-05-09 14:28:37 [PID=27170] [debug ] est cpu dur 30069.284065; running_frac 0.930659; rsf 0.500000; est 64619.320680
2005-05-09 14:28:37 [PID=27170] [debug ] [HOST#61874] Sending app_version einstein windows_intelx86 479
2005-05-09 14:28:37 [PID=27170] [debug ] [HOST#61874] Already has file H1_0659.0
2005-05-09 14:28:37 [PID=27170] [debug ] [HOST#61874] reducing disk needed for WU by 14736000 bytes (length of H1_0659.0)
2005-05-09 14:28:37 [PID=27170] [debug ] est cpu dur 30069.284065; running_frac 0.930659; rsf 0.500000; est 64619.320680
2005-05-09 14:28:37 [PID=27170] [normal ] [HOST#61874] Sending [RESULT#4192607 H1_0659.0__0659.1_0.1_T04_Fin1_0] (fills 64619.32 seconds)
2005-05-09 14:28:37 [PID=27170] [debug ] in_send_results_for_file(H1_0659.0, 8) prev_result.id=4192607
2005-05-09 14:28:37 [PID=27170] [debug ] touched ../locality_scheduling/need_work/H1_0659.0: need work for file H1_0659.0
2005-05-09 14:28:37 [PID=27170] [debug ] make_more_work_for_file(H1_0659.0, 8)=0
2005-05-09 14:28:47 [PID=27170] [debug ] in_send_results_for_file(H1_0659.0, 9) prev_result.id=4192607
2005-05-09 14:28:47 [PID=27170] [debug ] est cpu dur 30069.284065; running_frac 0.930659; rsf 0.500000; est 64619.320680
2005-05-09 14:28:47 [PID=27170] [debug ] [HOST#61874] Sending app_version einstein windows_intelx86 479
2005-05-09 14:28:47 [PID=27170] [debug ] [HOST#61874] Already has file H1_0659.0
2005-05-09 14:28:47 [PID=27170] [debug ] [HOST#61874] reducing disk needed for WU by 14736000 bytes (length of H1_0659.0)
2005-05-09 14:28:47 [PID=27170] [debug ] est cpu dur 30069.284065; running_frac 0.930659; rsf 0.500000; est 64619.320680
2005-05-09 14:28:47 [PID=27170] [normal ] [HOST#61874] Sending [RESULT#4192623 H1_0659.0__0659.2_0.1_T04_Fin1_0] (fills 64619.32 seconds)
2005-05-09 14:28:47 [PID=27170] [debug ] in_send_results_for_file(H1_0659.0, 10) prev_result.id=4192623
2005-05-09 14:28:47 [PID=27170] [debug ] touched ../locality_scheduling/need_work/H1_0659.0: need work for file H1_0659.0
2005-05-09 14:28:47 [PID=27170] [debug ] make_more_work_for_file(H1_0659.0, 10)=0
2005-05-09 14:28:57 [PID=27170] [debug ] in_send_results_for_file(H1_0659.0, 11) prev_result.id=4192623
2005-05-09 14:28:57 [PID=27170] [debug ] est cpu dur 30069.284065; running_frac 0.930659; rsf 0.500000; est 64619.320680
2005-05-09 14:28:57 [PID=27170] [debug ] [HOST#61874] Sending app_version einstein windows_intelx86 479
2005-05-09 14:28:57 [PID=27170] [debug ] [HOST#61874] Already has file H1_0659.0
2005-05-09 14:28:57 [PID=27170] [debug ] [HOST#61874] reducing disk needed for WU by 14736000 bytes (length of H1_0659.0)
2005-05-09 14:28:57 [PID=27170] [debug ] est cpu dur 30069.284065; running_frac 0.930659; rsf 0.500000; est 64619.320680
2005-05-09 14:28:57 [PID=27170] [normal ] [HOST#61874] Sending [RESULT#4192631 H1_0659.0__0659.3_0.1_T04_Fin1_0] (fills 64619.32 seconds)
2005-05-09 14:28:57 [PID=27170] [debug ] in_send_results_for_file(H1_0659.0, 12) prev_result.id=4192631
2005-05-09 14:28:57 [PID=27170] [debug ] touched ../locality_scheduling/need_work/H1_0659.0: need work for file H1_0659.0
2005-05-09 14:28:57 [PID=27170] [debug ] make_more_work_for_file(H1_0659.0, 12)=0
2005-05-09 14:29:07 [PID=27170] [debug ] in_send_results_for_file(H1_0659.0, 13) prev_result.id=4192631
2005-05-09 14:29:07 [PID=27170] [debug ] est cpu dur 30069.284065; running_frac 0.930659; rsf 0.500000; est 64619.320680
2005-05-09 14:29:07 [PID=27170] [debug ] [HOST#61874] Sending app_version einstein windows_intelx86 479
2005-05-09 14:29:07 [PID=27170] [debug ] [HOST#61874] Already has file H1_0659.0
2005-05-09 14:29:07 [PID=27170] [debug ] [HOST#61874] reducing disk needed for WU by 14736000 bytes (length of H1_0659.0)
2005-05-09 14:29:07 [PID=27170] [debug ] est cpu dur 30069.284065; running_frac 0.930659; rsf 0.500000; est 64619.320680
2005-05-09 14:29:07 [PID=27170] [normal ] [HOST#61874] Sending [RESULT#4192639 H1_0659.0__0659.4_0.1_T04_Fin1_0] (fills 64619.32 seconds)
2005-05-09 14:29:07 [PID=27170] [debug ] in_send_results_for_file(H1_0659.0, 14) prev_result.id=4192639
2005-05-09 14:29:07 [PID=27170] [debug ] touched ../locality_scheduling/need_work/H1_0659.0: need work for file H1_0659.0
2005-05-09 14:29:07 [PID=27170] [debug ] make_more_work_for_file(H1_0659.0, 14)=0
2005-05-09 14:29:17 [PID=27170] [debug ] in_send_results_for_file(H1_0659.0, 15) prev_result.id=4192639
2005-05-09 14:29:17 [PID=27170] [debug ] est cpu dur 30069.284065; running_frac 0.930659; rsf 0.500000; est 64619.320680
2005-05-09 14:29:17 [PID=27170] [debug ] [HOST#61874] Sending app_version einstein windows_intelx86 479
2005-05-09 14:29:17 [PID=27170] [debug ] [HOST#61874] Already has file H1_0659.0
2005-05-09 14:29:17 [PID=27170] [debug ] [HOST#61874] reducing disk needed for WU by 14736000 bytes (length of H1_0659.0)
2005-05-09 14:29:17 [PID=27170] [debug ] est cpu dur 30069.284065; running_frac 0.930659; rsf 0.500000; est 64619.320680
2005-05-09 14:29:17 [PID=27170] [normal ] [HOST#61874] Sending [RESULT#4192648 H1_0659.0__0659.0_0.1_T05_Fin1_0] (fills 64619.32 seconds)
2005-05-09 14:29:17 [PID=27170] [normal ] [HOST#61874] Sent 8 results [scheduler ran 86 seconds]
2005-05-09 14:29:34 [PID=27358] [debug ] REQUEST_METHOD=POST CONTENT_TYPE=application/octet-stream HTTP_ACCEPT= HTTP_USER_AGENT=BOINC client (windows_intelx86 4.26)
2005-05-09 14:29:34 [PID=27358] [debug ] CONTENT_LENGTH=11593 from X.X.X.X
2005-05-09 14:29:47 [PID=27358] [normal ] Handling request: IP X.X.X.X, auth XXX, host 61874, platform windows_intelx86, version 4.26
2005-05-09 14:29:47 [PID=27358] [normal ] OS version Microsoft Windows XP Professional Edition, Service Pack 2, (05.01.2600.00)
2005-05-09 14:29:47 [PID=27358] [debug ] Request [HOST#61874] Database [HOST#61874] Request [RPC#93] Database [RPC#84]
2005-05-09 14:29:47 [PID=27358] [normal ] Processing request from [USER#167] [HOST#61874] [IP X.X.X.X] [RPC#93] core client version 4.26
2005-05-09 14:29:47 [PID=27358] [normal ] [HOST#61874] [RESULT#3911567 H1_0723.4__0723.5_0.1_T15_Run2_1] got result
2005-05-09 14:29:47 [PID=27358] [CRITICAL] [HOST#61874] [RESULT#3911567 H1_0723.4__0723.5_0.1_T15_Run2_1] got result twice
2005-05-09 14:29:47 [PID=27358] [normal ] [HOST#61874] [RESULT#3915377 H1_0723.4__0723.8_0.1_T15_Run2_2] got result
2005-05-09 14:29:47 [PID=27358] [CRITICAL] [HOST#61874] [RESULT#3915377 H1_0723.4__0723.8_0.1_T15_Run2_2] got result twice
2005-05-09 14:29:47 [PID=27358] [normal ] [HOST#61874] [RESULT#3917535 H1_0723.4__0723.9_0.1_T15_Run2_1] got result
2005-05-09 14:29:47 [PID=27358] [CRITICAL] [HOST#61874] [RESULT#3917535 H1_0723.4__0723.9_0.1_T15_Run2_1] got result twice
2005-05-09 14:29:47 [PID=27358] [normal ] [HOST#61874] [RESULT#3918538 H1_0723.4__0723.5_0.1_T16_Run2_1] got result
2005-05-09 14:29:47 [PID=27358] [CRITICAL] [HOST#61874] [RESULT#3918538 H1_0723.4__0723.5_0.1_T16_Run2_1] got result twice
2005-05-09 14:29:47 [PID=27358] [normal ] [HOST#61874] [RESULT#3924126 H1_0723.4__0723.8_0.1_T16_Run2_3] got result
2005-05-09 14:29:47 [PID=27358] [CRITICAL] [HOST#61874] [RESULT#3924126 H1_0723.4__0723.8_0.1_T16_Run2_3] got result twice
2005-05-09 14:29:47 [PID=27358] [normal ] [HOST#61874] [RESULT#3983822 H1_0723.4__0723.8_0.1_T05_Run2_5] got result
2005-05-09 14:29:47 [PID=27358] [CRITICAL] [HOST#61874] [RESULT#3983822 H1_0723.4__0723.8_0.1_T05_Run2_5] got result twice
2005-05-09 14:29:47 [PID=27358] [normal ] [HOST#61874] [RESULT#4014138 H1_0723.4__0723.7_0.1_T15_Run2_4] got result
2005-05-09 14:29:47 [PID=27358] [debug ] cpu 41979.640625 cpcs 0.001458, cc 61.211293
2005-05-09 14:29:47 [PID=27358] [debug ] [RESULT#4014138 H1_0723.4__0723.7_0.1_T15_Run2_4]: setting outcome SUCCESS
2005-05-09 14:29:47 [PID=27358] [normal ] [HOST#61874] [RESULT#4001025 H1_0659.0__0659.4_0.1_T00_Fin1_2] got result
2005-05-09 14:29:47 [PID=27358] [debug ] cpu 42549.265625 cpcs 0.001458, cc 62.041874
2005-05-09 14:29:47 [PID=27358] [debug ] [RESULT#4001025 H1_0659.0__0659.4_0.1_T00_Fin1_2]: setting outcome SUCCESS
2005-05-09 14:29:47 [PID=27358] [normal ] [HOST#61874] [RESULT#4012049 H1_0659.0__0659.0_0.1_T01_Fin1_3] got result
2005-05-09 14:29:47 [PID=27358] [debug ] cpu 42615.671875 cpcs 0.001458, cc 62.138702
2005-05-09 14:29:47 [PID=27358] [debug ] [RESULT#4012049 H1_0659.0__0659.0_0.1_T01_Fin1_3]: setting outcome SUCCESS
2005-05-09 14:29:47 [PID=27358] [normal ] [HOST#61874] [RESULT#4012110 H1_0659.0__0659.1_0.1_T01_Fin1_2] got result
2005-05-09 14:29:47 [PID=27358] [debug ] cpu 42075.062500 cpcs 0.001458, cc 61.350429
2005-05-09 14:29:47 [PID=27358] [debug ] [RESULT#4012110 H1_0659.0__0659.1_0.1_T01_Fin1_2]: setting outcome SUCCESS
2005-05-09 14:29:47 [PID=27358] [normal ] [HOST#61874] got request for 518400.000000 seconds of work; available disk 14.636548 GB
2005-05-09 14:29:47 [PID=27358] [debug ] [HOST#61874]: has file H1_0659.0
2005-05-09 14:29:47 [PID=27358] [normal ] [HOST#61874] Sent 0 results [scheduler ran 13 seconds]
2005-05-09 14:29:47 [PID=27358] [normal ] Daily result quota exceeded for host 61874
2005-05-09 14:29:47 [PID=27358] [debug ] [HOST#61874] MSG(high) No work sent
2005-05-09 14:29:47 [PID=27358] [debug ] [HOST#61874] MSG(high) (reached daily quota of 16 results)
2005-05-09 14:29:47 [PID=27358] [normal ] sending delay request 3600.000000
[root@einstein tmp]#
Director, Einstein@Home
Here is the relevant part of
)
Here is the relevant part of the scheduler log. The basic problem seems to be that on your end the core client timed out after 36 seconds, whereas on the server, the scheduler continued to run for 61 seconds. I am making some inquiries with the BOINC developers to try and understand if the core client has a time-out which might have caused this broken connection and hence the lost WU.
Excellent. Thanks for the log snippet.
I suspect that there isn't a timeout in the client, or if there is, it's not as short as 36secs. There is a timeout in my proxy, which is around the 30sec mark. I'll need to up this setting, but the question is "how high?". I'll try 180secs for starters.
PS: you might want to use ntp or some other method to set the correct time on your machine. It's off by a few minutes.
You're 100% right, sorry about that... I'll have to look into it. :)
Well, it looks like my particular problem was easy enough to find, but the implications provide some food for thought.
It seems that a slow scheduler response, combined with a proxy time-out can cause quite a bit of grief for a project. How do we make BOINC more robust in this department? Perhaps the client needs to "acknowledge" a scheduler reply?
Thanks very much for the feedback. It's much appreciated.