171.67.108.200 - Internal Server Error

[billford]

Good point, I hadn't thought of that!

[VijayPande]

It should be up. I’ve asked Joe to write up a summary of what happened and the fixes he’s done to handle it in the future.

[bruce]

It only happened once and the alternate AS worked as it should, but the problem may not be completely cured:

Code: Select all

******************************* Date: 2015-05-11 *******************************
09:30:00:WARNING:WU00:FS00:Failed to get assignment from '171.67.108.200:8080': 10001: Server responded: HTTP_INTERNAL_SERVER_ERROR
09:30:00:ERROR:WU00:FS00:Exception: Server did not assign work unit
09:30:00:WU00:FS00:Connecting to 171.67.108.204:80
09:30:00:WU00:FS00:Assigned to work server 171.64.65.124
******************************* Date: 2015-05-11 *******************************

[billford]

Similar here, only one occurrence but on both AS's- second attempt was successful:

Code: Select all

22:02:37:WU01:FS00:Connecting to 171.67.108.200:8080
22:02:38:WARNING:WU01:FS00:Failed to get assignment from '171.67.108.200:8080': 10001: Server responded: HTTP_INTERNAL_SERVER_ERROR
22:02:38:WU01:FS00:Connecting to 171.67.108.204:80
22:02:39:WARNING:WU01:FS00:Failed to get assignment from '171.67.108.204:80': 10001: Server responded: HTTP_INTERNAL_SERVER_ERROR
22:02:39:ERROR:WU01:FS00:Exception: Could not get an assignment
22:02:39:WU01:FS00:Connecting to 171.67.108.200:8080
22:02:40:WU01:FS00:Assigned to work server 171.64.65.99

[markfw]

I have multiple machines, but all have a variant of this error. Here is one :

Code: Select all

02:27:38:  <team v='198'/>
02:27:38:  <user v='Mark_F_Williams'/>
02:27:38:
02:27:38:  <!-- Folding Slots -->
02:27:38:  <slot id='0' type='GPU'>
02:27:38:    <client-type v='beta'/>
02:27:38:  </slot>
02:27:38:</config>
02:27:38:Trying to access database...
02:27:39:Successfully acquired database lock
02:27:39:Enabled folding slot 00: READY gpu:0:\"GK110 [GeForce GTX 780 Ti]\"
02:27:39:WU00:FS00:Connecting to assign-GPU.stanford.edu:80
02:27:39:WARNING:WU00:FS00:Failed to get assignment from 'assign-GPU.stanford.edu:80': 10001: Server responded: HTTP_INTERNAL_SERVER_ERROR
02:27:39:WU00:FS00:Connecting to assign-GPU.stanford.edu:8080
02:27:40:WARNING:WU00:FS00:Failed to get assignment from 'assign-GPU.stanford.edu:8080': 10001: Server responded: HTTP_INTERNAL_SERVER_ERROR
02:27:40:ERROR:WU00:FS00:Exception: Could not get an assignment
02:27:40:WU00:FS00:Connecting to assign-GPU.stanford.edu:80
02:27:40:WARNING:WU00:FS00:Failed to get assignment from 'assign-GPU.stanford.edu:80': 10001: Server responded: HTTP_INTERNAL_SERVER_ERROR
02:27:40:WU00:FS00:Connecting to assign-GPU.stanford.edu:8080
02:27:40:Server connection id=1 on 0.0.0.0:36330 from 127.0.0.1
02:27:40:WARNING:WU00:FS00:Failed to get assignment from 'assign-GPU.stanford.edu:8080': 10001: Server responded: HTTP_INTERNAL_SERVER_ERROR
02:27:40:ERROR:WU00:FS00:Exception: Could not get an assignment
02:28:40:WU00:FS00:Connecting to assign-GPU.stanford.edu:80
02:28:40:WARNING:WU00:FS00:Failed to get assignment from 'assign-GPU.stanford.edu:80': 10001: Server responded: HTTP_INTERNAL_SERVER_ERROR
02:28:40:WU00:FS00:Connecting to assign-GPU.stanford.edu:8080
02:28:40:WARNING:WU00:FS00:Failed to get assignment from 'assign-GPU.stanford.edu:8080': 10001: Server responded: HTTP_INTERNAL_SERVER_ERROR
02:28:40:ERROR:WU00:FS00:Exception: Could not get an assignment
02:30:17:WU00:FS00:Connecting to assign-GPU.stanford.edu:80
02:30:17:WARNING:WU00:FS00:Failed to get assignment from 'assign-GPU.stanford.edu:80': 10001: Server responded: HTTP_INTERNAL_SERVER_ERROR
02:30:17:WU00:FS00:Connecting to assign-GPU.stanford.edu:8080
02:30:17:WARNING:WU00:FS00:Failed to get assignment from 'assign-GPU.stanford.edu:8080': 10001: Server responded: HTTP_INTERNAL_SERVER_ERROR
02:30:17:ERROR:WU00:FS00:Exception: Could not get an assignment
02:32:54:WU00:FS00:Connecting to assign-GPU.stanford.edu:80
02:32:55:WARNING:WU00:FS00:Failed to get assignment from 'assign-GPU.stanford.edu:80': 10001: Server responded: HTTP_INTERNAL_SERVER_ERROR
02:32:55:WU00:FS00:Connecting to assign-GPU.stanford.edu:8080
02:32:55:WARNING:WU00:FS00:Failed to get assignment from 'assign-GPU.stanford.edu:8080': 10001: Server responded: HTTP_INTERNAL_SERVER_ERROR
02:32:55:ERROR:WU00:FS00:Exception: Could not get an assignment
02:36:35:Server connection id=2 on 0.0.0.0:36330 from 192.168.1.2
02:37:09:WU00:FS00:Connecting to assign-GPU.stanford.edu:80
02:37:09:WARNING:WU00:FS00:Failed to get assignment from 'assign-GPU.stanford.edu:80': 10001: Server responded: HTTP_INTERNAL_SERVER_ERROR
02:37:09:WU00:FS00:Connecting to assign-GPU.stanford.edu:8080
02:37:09:WARNING:WU00:FS00:Failed to get assignment from 'assign-GPU.stanford.edu:8080': 10001: Server responded: HTTP_INTERNAL_SERVER_ERROR
02:37:09:ERROR:WU00:FS00:Exception: Could not get an assignment
02:44:00:WU00:FS00:Connecting to assign-GPU.stanford.edu:80
02:44:00:WARNING:WU00:FS00:Failed to get assignment from 'assign-GPU.stanford.edu:80': 10001: Server responded: HTTP_INTERNAL_SERVER_ERROR
02:44:00:WU00:FS00:Connecting to assign-GPU.stanford.edu:8080
02:44:01:WARNING:WU00:FS00:Failed to get assignment from 'assign-GPU.stanford.edu:8080': 10001: Server responded: HTTP_INTERNAL_SERVER_ERROR
02:44:01:ERROR:WU00:FS00:Exception: Could not get an assignment
02:55:05:WU00:FS00:Connecting to assign-GPU.stanford.edu:80
02:55:06:WARNING:WU00:FS00:Failed to get assignment from 'assign-GPU.stanford.edu:80': 10001: Server responded: HTTP_INTERNAL_SERVER_ERROR
02:55:06:WU00:FS00:Connecting to assign-GPU.stanford.edu:8080
02:55:06:WARNING:WU00:FS00:Failed to get assignment from 'assign-GPU.stanford.edu:8080': 10001: Server responded: HTTP_INTERNAL_SERVER_ERROR
02:55:06:ERROR:WU00:FS00:Exception: Could not get an assignment
03:13:02:WU00:FS00:Connecting to assign-GPU.stanford.edu:80
03:13:02:WARNING:WU00:FS00:Failed to get assignment from 'assign-GPU.stanford.edu:80': 10001: Server responded: HTTP_INTERNAL_SERVER_ERROR
03:13:02:WU00:FS00:Connecting to assign-GPU.stanford.edu:8080
03:13:03:WARNING:WU00:FS00:Failed to get assignment from 'assign-GPU.stanford.edu:8080': 10001: Server responded: HTTP_INTERNAL_SERVER_ERROR

Here is another:

Code: Select all

02:51:37:WU02:FS01:0xa5:Completed 247500 out of 250000 steps  (99%)
02:52:20:WU00:FS00:0x18:Completed 11680000 out of 16000000 steps (73%)
02:57:06:WU00:FS00:0x18:Completed 11840000 out of 16000000 steps (74%)
03:01:52:WU00:FS00:0x18:Completed 12000000 out of 16000000 steps (75%)
03:06:42:WU00:FS00:0x18:Completed 12160000 out of 16000000 steps (76%)
03:11:28:WU00:FS00:0x18:Completed 12320000 out of 16000000 steps (77%)
03:16:14:WU00:FS00:0x18:Completed 12480000 out of 16000000 steps (78%)
03:19:09:WU02:FS01:0xa5:Completed 250000 out of 250000 steps  (100%)
03:19:10:WU01:FS01:Connecting to 171.67.108.200:8080
\x1b[93m03:19:10:WARNING:WU01:FS01:Failed to get assignment from '171.67.108.200:8080': 10001: Server responded: HTTP_INTERNAL_SERVER_ERROR\x1b[0m
03:19:10:WU01:FS01:Connecting to 171.67.108.204:80
03:19:11:WU01:FS01:Assigned to work server 128.143.231.201
03:19:11:WU01:FS01:Requesting new work unit for slot 01: RUNNING cpu:24 from 128.143.231.201
03:19:11:WU01:FS01:Connecting to 128.143.231.201:8080
03:19:12:WU01:FS01:Downloading 512B
03:19:12:WU01:FS01:Download complete
03:19:12:WU01:FS01:Received Unit: id:01 state:DOWNLOAD error:NO_ERROR project:8106 run:0 clone:68 gen:1 core:0xa5 unit:0x00000003088988e154cd32b6fab8f902
03:19:21:WU02:FS01:0xa5:DynamicWrapper: Finished Work Unit: sleep=10000
03:19:31:WU02:FS01:0xa5:
03:19:31:WU02:FS01:0xa5:Finished Work Unit:
03:19:31:WU02:FS01:0xa5:- Reading up to 64046640 from \"02/wudata_01.trr\": Read 64046640
03:19:32:WU02:FS01:0xa5:trr file hash check passed.
03:19:32:WU02:FS01:0xa5:- Reading up to 31768468 from \"02/wudata_01.xtc\": Read 31768468
03:19:32:WU02:FS01:0xa5:xtc file hash check passed.
03:19:32:WU02:FS01:0xa5:edr file hash check passed.
03:19:32:WU02:FS01:0xa5:logfile size: 198010
03:19:32:WU02:FS01:0xa5:Leaving Run
03:19:34:WU02:FS01:0xa5:- Writing 96173994 bytes of core data to disk...
03:19:48:WU02:FS01:0xa5:Done: 96173482 -> 91458485 (compressed to 5.7 percent)
03:19:48:WU02:FS01:0xa5:  ... Done.
03:20:01:WU02:FS01:0xa5:- Shutting down core
03:20:01:WU02:FS01:0xa5:
03:20:01:WU02:FS01:0xa5:Folding@home Core Shutdown: FINISHED_UNIT
03:20:04:WU02:FS01:FahCore returned: FINISHED_UNIT (100 = 0x64)
03:20:04:WU02:FS01:Sending unit results: id:02 state:SEND error:NO_ERROR project:8108 run:0 clone:86 gen:23 core:0xa5 unit:0x0000001d088988e154ce736ee84a44d7
03:20:04:WU02:FS01:Uploading 87.22MiB to 128.143.231.201
03:20:04:WU02:FS01:Connecting to 128.143.231.201:8080
03:20:04:WU01:FS01:Starting
03:20:04:WU01:FS01:Running FahCore: /usr/bin/FAHCoreWrapper /var/lib/fahclient/cores/web.stanford.edu/~pande/Linux/AMD64/Core_a5.fah/FahCore_a5 -dir 01 -suffix 01 -version 704 -lifeline 1362 -checkpoint 15 -np 24
03:20:04:WU01:FS01:Started FahCore on PID 22354
03:20:04:WU01:FS01:Core PID:22358
03:20:04:WU01:FS01:FahCore 0xa5 started
\x1b[93m03:20:04:WARNING:WU01:FS01:FahCore returned: FILE_IO_ERROR (117 = 0x75)\x1b[0m
\x1b[93m03:20:04:WARNING:WU01:FS01:Fatal error, dumping\x1b[0m
03:20:04:WU01:FS01:Sending unit results: id:01 state:SEND error:DUMPED project:8106 run:0 clone:68 gen:1 core:0xa5 unit:0x00000003088988e154cd32b6fab8f902
03:20:04:WU01:FS01:Connecting to 128.143.231.201:8080
03:20:05:WU03:FS01:Connecting to 171.67.108.200:8080
\x1b[93m03:20:05:WARNING:WU03:FS01:Failed to get assignment from '171.67.108.200:8080': 10001: Server responded: HTTP_INTERNAL_SERVER_ERROR\x1b[0m
03:20:05:WU03:FS01:Connecting to 171.67.108.204:80
03:20:05:WU03:FS01:Assigned to work server 128.143.231.201
03:20:05:WU03:FS01:Requesting new work unit for slot 01: READY cpu:24 from 128.143.231.201
03:20:05:WU03:FS01:Connecting to 128.143.231.201:8080
03:20:10:WU02:FS01:Upload 20.42%
03:20:16:WU02:FS01:Upload 41.27%
03:20:22:WU02:FS01:Upload 61.34%
03:20:28:WU02:FS01:Upload 82.76%
03:20:56:WU00:FS00:0x18:Completed 12640000 out of 16000000 steps (79%)
\x1b[93m03:21:06:WARNING:WU01:FS01:Exception: Failed to send results to work server: 10002: Received short response, expected 512 bytes, got 0\x1b[0m
03:21:06:WU01:FS01:Trying to send results to collection server
03:21:06:WU01:FS01:Connecting to 128.143.199.97:8080
03:21:07:WU01:FS01:Server responded WORK_ACK (400)
03:21:07:WU01:FS01:Cleaning up
\x1b[91m03:21:10:ERROR:WU03:FS01:Exception: 10002: Received short response, expected 512 bytes, got 0\x1b[0m
03:21:10:WU03:FS01:Connecting to 171.67.108.200:8080
\x1b[93m03:21:11:WARNING:WU03:FS01:Failed to get assignment from '171.67.108.200:8080': 10001: Server responded: HTTP_INTERNAL_SERVER_ERROR\x1b[0m
03:21:11:WU03:FS01:Connecting to 171.67.108.204:80
03:21:11:WU03:FS01:Assigned to work server 128.143.231.201
03:21:11:WU03:FS01:Requesting new work unit for slot 01: READY cpu:24 from 128.143.231.201
03:21:11:WU03:FS01:Connecting to 128.143.231.201:8080
\x1b[93m03:21:48:WARNING:WU02:FS01:Exception: Failed to send results to work server: 10002: Received short response, expected 512 bytes, got 0\x1b[0m
03:21:48:WU02:FS01:Trying to send results to collection server
03:21:48:WU02:FS01:Uploading 87.22MiB to 128.143.199.97
03:21:48:WU02:FS01:Connecting to 128.143.199.97:8080
03:21:54:WU02:FS01:Upload 15.48%
03:22:00:WU02:FS01:Upload 37.12%
03:22:06:WU02:FS01:Upload 57.25%
03:22:12:WU02:FS01:Upload 77.89%
03:22:18:WU02:FS01:Upload 99.24%
03:22:33:WU02:FS01:Upload complete
03:22:33:WU02:FS01:Server responded WORK_ACK (400)
03:22:33:WU02:FS01:Final credit estimate, 77072.00 points
03:22:33:WU02:FS01:Cleaning up
\x1b[91m03:22:45:ERROR:WU03:FS01:Exception: 10002: Received short response, expected 512 bytes, got 0\x1b[0m
03:22:46:WU03:FS01:Connecting to 171.67.108.200:8080
\x1b[93m03:22:47:WARNING:WU03:FS01:Failed to get assignment from '171.67.108.200:8080': 10001: Server responded: HTTP_INTERNAL_SERVER_ERROR\x1b[0m
03:22:47:WU03:FS01:Connecting to 171.67.108.204:80
03:22:47:WU03:FS01:Assigned to work server 128.143.231.201
03:22:47:WU03:FS01:Requesting new work unit for slot 01: READY cpu:24 from 128.143.231.201
03:22:47:WU03:FS01:Connecting to 128.143.231.201:8080
\x1b[91m03:25:29:ERROR:WU03:FS01:Exception: 10002: Received short response, expected 512 bytes, got 0\x1b[0m
03:25:29:WU03:FS01:Connecting to 171.67.108.200:8080
\x1b[93m03:25:30:WARNING:WU03:FS01:Failed to get assignment from '171.67.108.200:8080': 10001: Server responded: HTTP_INTERNAL_SERVER_ERROR\x1b[0m
03:25:30:WU03:FS01:Connecting to 171.67.108.204:80
03:25:30:WU00:FS00:0x18:Completed 12800000 out of 16000000 steps (80%)
03:25:30:WU03:FS01:Assigned to work server 128.143.231.201
03:25:30:WU03:FS01:Requesting new work unit for slot 01: READY cpu:24 from 128.143.231.201
03:25:30:WU03:FS01:Connecting to 128.143.231.201:8080

Mod edit: Please enclose your log file postings in Code tags

[billford]

Agreed- same error across all 6 clients, both port 80 and 8080, smp and GPU. Typically:

Code: Select all

04:10:14:WARNING:WU00:FS00:Failed to get assignment from '171.67.108.200:8080': 10001: Server responded: HTTP_INTERNAL_SERVER_ERROR

Failback to 171.67.108.204 seems OK.

[bollix47]

Also, the Internal Server Error occurs when trying to look up a project description:

Code: Select all

Internal Server Error

The server encountered an internal error or misconfiguration and was unable to complete your request.

Please contact the server administrator, root@localhost and inform them of the time the error occurred, and anything you might have done that may have caused the error.

More information about this error may be available in the server error log.

Apache/2.0.52 (CentOS) Server at fah-web.stanford.edu Port 80

It doesn't appear to matter whether trying from Project Summary or FAHControl.

[billford]

Yup, same here (as you'd expect!)

Wonder if it's connected with the stats misbehaviour I reported here?

Can't see why it should be, and the timings in my client logs neither support or refute the idea, but it seems quite a coincidence.

[bollix47]

Rather than speculate I've notified PG about this and the stats problems

[billford]

Can't ask for more than that, thanks

[billford]

FWIW, I'm beginning to see the same error on both AS's

Code: Select all

11:36:32:WARNING:WU02:FS00:Failed to get assignment from '171.67.108.200:8080': 10001: Server responded: HTTP_INTERNAL_SERVER_ERROR
11:36:32:WU02:FS00:Connecting to 171.67.108.204:80
11:36:32:WARNING:WU02:FS00:Failed to get assignment from '171.67.108.204:80': 10001: Server responded: HTTP_INTERNAL_SERVER_ERROR
11:36:32:ERROR:WU02:FS00:Exception: Could not get an assignment

[toTOW]

According to Server Status page, the main AS is completely down (Standby - Not Accept) ... secondary one seems OK, but it might be occasionnally overloaded if it has to handle the load of all FAH clients ...

[billford]

I noticed that, but thought "(Standby - Not Accept)" only applied to WS's and it was just how the program interpreted the response it got when an AS was queried?

[toTOW]

The weird thing is that the monitoring is not the same on both AS ... that's why I think this "not accept" might be real ...

[billford]

Ah right, I see.