[Glass] Fastcgi Socket issues
Locked
[Glass] Fastcgi Socket issues
 
|
Hi, We are using Nginx, FastCGi and Gemstone 3.2 (Seaside 3.1.x) Under load we see a lot of socket errors (see below) in the fastcgi logs. The first issue is gone after i have removed the addToLog calls after the retry. In most if not all cases the first issue happens only after the commit retry loop. But I can't explain why this solves the issue. The second issue "ENOTCONN, Socket is not connected" is still in our logs and I can't find the reason for this issue. I can even reproduce the error on the test system (4 running fastcgi's) if I generate some load. Any suggestions? Regards Gerhard Socket issue #1: ----------- Commit failure - retrying LOG ENTRY: aSymbolDictionary-----------30.03.2015 14:13:55 failure Read-Write Conflicts... Write-Write Conflicts... 73241035521 73241047809 73242811393 73242820609 73254391809 73278833921 Write-Dependency Conflicts... Write-ReadLock Conflicts... Write-WriteLock Conflicts... Rc-Write-Write Conflicts... Synchronized-Commit Conflicts... ----------- Commit failure - retrying LOG ENTRY: aSymbolDictionary-----------30.03.2015 14:13:55 ----------- Unreportable ERROR Encountered: 2015-03-30T14:13:55.9887080192565+02:00a ImproperOperation occurred (error 2364), The object aGsSocket that has some associated session state has lost that transient state. Examples of classes that use session state are GsSocket and GsFile. 1 FSGsSocketServer >> notifyUnreportableError: @2 line 4 [GsNMethod 128111352065] 2 [] in ExecBlock0 (FSConnection) >> notifyUnreportableError: @3 line 6 [GsNMethod 814696705] 3 ExecBlock0 (ExecBlock) >> on:do: @3 line 42 [GsNMethod 364136449] 4 FSConnection >> notifyUnreportableError: @2 line 7 [GsNMethod 815339265] 5 [] in ExecBlock1 (FSConnection) >> handleError: @3 line 23 [GsNMethod 814686465] 6 ImproperOperation (AbstractException) >> _executeHandler: @3 line 8 [GsNMethod 370108417] 7 ImproperOperation (AbstractException) >> _signalFromPrimitive: @1 line 1 [GsNMethod 370093569] 8 GsSocket >> _write:startingAt:ofSize: @1 line 1 [GsNMethod 392681985] 9 GsSocket >> write:from:startingAt: @4 line 18 [GsNMethod 392695041] 10 GsSocket >> write: @3 line 10 [GsNMethod 392694785] 11 FSGsSocket >> nextPutAll: @5 line 5 [GsNMethod 815303937] 12 FSRecordStruct >> writeToStream: @12 line 13 [GsNMethod 815188481] 13 [] in ExecBlock1 (FSRecordSeries) >> writeToStream: @2 line 3 [GsNMethod 814744065] 14 OrderedCollection (Collection) >> do: @5 line 10 [GsNMethod 365533953] 15 FSRecordSeries >> writeToStream: @3 line 3 [GsNMethod 815171841] 16 FSConnection >> writeRecord: @3 line 3 [GsNMethod 815346433] 17 [] in ExecBlock0 (FSConnection) >> handleError: @22 line 21 [GsNMethod 814686721] 18 ExecBlock0 (ExecBlock) >> on:do: @3 line 42 [GsNMethod 364136449] 19 FSConnection >> handleError: @2 line 22 [GsNMethod 815345409] 20 [] in ExecBlock1 (FSConnection) >> safeServe @2 line 13 [GsNMethod 815636481] 21 ImproperOperation (AbstractException) >> _executeHandler: @3 line 8 [GsNMethod 370108417] 22 ImproperOperation (AbstractException) >> _signalFromPrimitive: @1 line 1 [GsNMethod 370093569] 23 GsSocket >> _write:startingAt:ofSize: @1 line 1 [GsNMethod 392681985] 24 GsSocket >> write:from:startingAt: @4 line 18 [GsNMethod 392695041] 25 GsSocket >> write: @3 line 10 [GsNMethod 392694785] 26 FSGsSocket >> nextPutAll: @5 line 5 [GsNMethod 815303937] 27 FSRecordStruct >> writeToStream: @12 line 13 [GsNMethod 815188481] 28 [] in ExecBlock1 (FSRecordSeries) >> streamToStream: @2 line 6 [GsNMethod 814749697] 29 OrderedCollection (SequenceableCollection) >> from:to:do: @11 line 10 [GsNMethod 361582849] 30 FSRecordSeries >> streamToStream: @5 line 6 [GsNMethod 815174913] 31 FSConnection >> streamRecord: @3 line 6 [GsNMethod 815338753] Socket issue #2: ----------- Unreportable ERROR Encountered: 2015-04-01T18:51:48.0392289161682+02:00UserDefinedError: send(13,0x7fa44d8b0708,8,0) failed with errno=107,ENOTCONN, Socket is not connected 1 FSGsSocketServer >> notifyUnreportableError: @2 line 4 [GsNMethod 128111352065] 2 [] in ExecBlock0 (FSConnection) >> notifyUnreportableError: @3 line 6 [GsNMethod 814696705] 3 ExecBlock0 (ExecBlock) >> on:do: @3 line 42 [GsNMethod 364136449] 4 FSConnection >> notifyUnreportableError: @2 line 7 [GsNMethod 815339265] 5 [] in ExecBlock1 (FSConnection) >> handleError: @3 line 23 [GsNMethod 814686465] 6 UserDefinedError (AbstractException) >> _executeHandler: @3 line 8 [GsNMethod 370108417] 7 UserDefinedError (AbstractException) >> _signalWith: @1 line 1 [GsNMethod 370105857] 8 UserDefinedError (AbstractException) >> signal @2 line 47 [GsNMethod 370109697] 9 FSGsSocket (Object) >> error: @6 line 7 [GsNMethod 363207169] 10 FSGsSocket >> nextPutAll: @11 line 6 [GsNMethod 815303937] 11 FSRecordStruct >> writeToStream: @12 line 13 [GsNMethod 815188481] 12 [] in ExecBlock1 (FSRecordSeries) >> writeToStream: @2 line 3 [GsNMethod 814744065] 13 OrderedCollection (Collection) >> do: @5 line 10 [GsNMethod 365533953] 14 FSRecordSeries >> writeToStream: @3 line 3 [GsNMethod 815171841] 15 FSConnection >> writeRecord: @3 line 3 [GsNMethod 815346433] 16 [] in ExecBlock0 (FSConnection) >> handleError: @22 line 21 [GsNMethod 814686721] 17 ExecBlock0 (ExecBlock) >> on:do: @3 line 42 [GsNMethod 364136449] 18 FSConnection >> handleError: @2 line 22 [GsNMethod 815345409] 19 [] in ExecBlock1 (FSConnection) >> safeServe @2 line 13 [GsNMethod 815636481] 20 UserDefinedError (AbstractException) >> _executeHandler: @3 line 8 [GsNMethod 370108417] 21 UserDefinedError (AbstractException) >> _signalWith: @1 line 1 [GsNMethod 370105857] 22 UserDefinedError (AbstractException) >> signal @2 line 47 [GsNMethod 370109697] 23 FSGsSocket (Object) >> error: @6 line 7 [GsNMethod 363207169] 24 FSGsSocket >> nextPutAll: @11 line 6 [GsNMethod 815303937] 25 FSRecordStruct >> writeToStream: @14 line 14 [GsNMethod 815188481] 26 FSConnection >> writeRecord: @3 line 3 [GsNMethod 815346433] 27 FSResponderRole (FSRole) >> sendEndRequestSuccess @5 line 4 [GsNMethod 815217409] 28 FSResponderRole >> send @4 line 8 [GsNMethod 815241217] 29 FSResponderRole (FSRole) >> handleConnection @4 line 6 [GsNMethod 815218433] 30 FSConnection >> unsafeServe @5 line 8 [GsNMethod 815343617] 31 [] in ExecBlock0 (FSConnection) >> safeServe @2 line 8 [GsNMethod 815042305] 32 ExecBlock0 (ExecBlock) >> on:do: @3 line 42 [GsNMethod 364136449] 33 [] in ExecBlock0 (FSConnection) >> safeServe @2 line 9 [GsNMethod 815636737] 34 ExecBlock0 (ExecBlock) >> on:do: @3 line 42 [GsNMethod 364136449] 35 [] in ExecBlock0 (FSConnection) >> safeServe @2 line 12 [GsNMethod 814690561] 36 ExecBlock0 (ExecBlock) >> ensure: @2 line 12 [GsNMethod 364180993] 37 FSConnection >> safeServe @2 line 15 [GsNMethod 815343361] 38 FSConnection >> serve @2 line 4 [GsNMethod 815339777] 39 [] in ExecBlock (FSSocketServer) >> listen: @3 line 15 [GsNMethod 814801153] 40 GsProcess >> _start @7 line 16 [GsNMethod 370139649] 41 <Reenter marker> ==> FastCGI_server-9003.log.1 <== 2015-04-02T07:31:55.9581229686737+02:00: https://xxxxxxx/test?_s=to2JAP-JIInBRGhf&_k=kpFT55JXXVNncoXl /test?_s=to2JAP-JIInBRGhf&_k=fT9IEZXwjGg2QS-Y --------------------------------------------- ----------- Unreportable ERROR Encountered: 2015-04-02T07:31:56.0916519165039+02:00UserDefinedError: send(13,0x7f30cafde008,65535,0) failed with errno=107,ENOTCONN, Socket is not connected 1 FSGsSocketServer >> notifyUnreportableError: @2 line 4 [GsNMethod 128111352065] 2 [] in ExecBlock0 (FSConnection) >> notifyUnreportableError: @3 line 6 [GsNMethod 814696705] 3 ExecBlock0 (ExecBlock) >> on:do: @3 line 42 [GsNMethod 364136449] 4 FSConnection >> notifyUnreportableError: @2 line 7 [GsNMethod 815339265] 5 [] in ExecBlock1 (FSConnection) >> handleError: @3 line 23 [GsNMethod 814686465] 6 UserDefinedError (AbstractException) >> _executeHandler: @3 line 8 [GsNMethod 370108417] 7 UserDefinedError (AbstractException) >> _signalWith: @1 line 1 [GsNMethod 370105857] 8 UserDefinedError (AbstractException) >> signal @2 line 47 [GsNMethod 370109697] 9 FSGsSocket (Object) >> error: @6 line 7 [GsNMethod 363207169] 10 FSGsSocket >> nextPutAll: @11 line 6 [GsNMethod 815303937] 11 FSRecordStruct >> writeToStream: @30 line 23 [GsNMethod 21533370113] 12 [] in ExecBlock1 (FSRecordSeries) >> writeToStream: @2 line 3 [GsNMethod 814744065] 13 OrderedCollection (Collection) >> do: @5 line 10 [GsNMethod 365533953] 14 FSRecordSeries >> writeToStream: @3 line 3 [GsNMethod 815171841] 15 FSConnection >> writeRecord: @3 line 3 [GsNMethod 815346433] 16 [] in ExecBlock0 (FSConnection) >> handleError: @22 line 21 [GsNMethod 814686721] 17 ExecBlock0 (ExecBlock) >> on:do: @3 line 42 [GsNMethod 364136449] 18 FSConnection >> handleError: @2 line 22 [GsNMethod 815345409] 19 [] in ExecBlock1 (FSConnection) >> safeServe @2 line 13 [GsNMethod 815636481] 20 UserDefinedError (AbstractException) >> _executeHandler: @3 line 8 [GsNMethod 370108417] 21 UserDefinedError (AbstractException) >> _signalWith: @1 line 1 [GsNMethod 370105857] 22 UserDefinedError (AbstractException) >> signal @2 line 47 [GsNMethod 370109697] 23 FSGsSocket (Object) >> error: @6 line 7 [GsNMethod 363207169] 24 FSGsSocket >> nextPutAll: @11 line 6 [GsNMethod 815303937] 25 FSRecordStruct >> writeToStream: @32 line 24 [GsNMethod 21533370113] 26 [] in ExecBlock1 (FSRecordSeries) >> streamToStream: @2 line 6 [GsNMethod 814749697] 27 OrderedCollection (SequenceableCollection) >> from:to:do: @11 line 10 [GsNMethod 361582849] 28 FSRecordSeries >> streamToStream: @5 line 6 [GsNMethod 815174913] 29 FSConnection >> streamRecord: @3 line 6 [GsNMethod 815338753] 30 FSConnection >> nextPutAll: @4 line 4 [GsNMethod 815344897] 31 FSResponderRole (FSRole) >> nextPutAll: @3 line 7 [GsNMethod 815212545] 32 WAFastCGIAdaptor >> answerResponderRole: @3 line 10 [GsNMethod 815363841] 33 FSResponderRole >> answer @3 line 4 [GsNMethod 815240961] 34 FSResponderRole (FSRole) >> handleConnection @3 line 5 [GsNMethod 815218433] 35 FSConnection >> unsafeServe @5 line 8 [GsNMethod 815343617] 36 [] in ExecBlock0 (FSConnection) >> safeServe @2 line 8 [GsNMethod 815042305] 37 ExecBlock0 (ExecBlock) >> on:do: @3 line 42 [GsNMethod 364136449] 38 [] in ExecBlock0 (FSConnection) >> safeServe @2 line 9 [GsNMethod 815636737] 39 ExecBlock0 (ExecBlock) >> on:do: @3 line 42 [GsNMethod 364136449] 40 [] in ExecBlock0 (FSConnection) >> safeServe @2 line 12 [GsNMethod 814690561] 41 ExecBlock0 (ExecBlock) >> ensure: @2 line 12 [GsNMethod 364180993] 42 FSConnection >> safeServe @2 line 15 [GsNMethod 815343361] 43 FSConnection >> serve @2 line 4 [GsNMethod 815339777] 44 [] in ExecBlock (FSSocketServer) >> listen: @3 line 15 [GsNMethod 814801153] 45 GsProcess >> _start @7 line 16 [GsNMethod 370139649] 46 <Reenter marker> Nginx debug log: 2015/04/02 09:45:47 [debug] 30417#0: *27 fastcgi param: "QUERY_STRING: _s=to2JAP-JIInBRGhf&_k=-_M7PBbUrqJsbOfI" 2015/04/02 09:45:47 [debug] 30417#0: *27 fastcgi param: "REQUEST_METHOD: GET" 2015/04/02 09:45:47 [debug] 30417#0: *27 fastcgi param: "CONTENT_TYPE: " 2015/04/02 09:45:47 [debug] 30417#0: *27 fastcgi param: "CONTENT_LENGTH: " 2015/04/02 09:45:47 [debug] 30417#0: *27 fastcgi param: "SCRIPT_NAME: /test" 2015/04/02 09:45:47 [debug] 30417#0: *27 fastcgi param: "REQUEST_URI: /test?_s=to2JAP-JIInBRGhf&_k=-_M7PBbUrqJsbOfI" 2015/04/02 09:45:47 [debug] 30417#0: *27 fastcgi param: "DOCUMENT_URI: /test" 2015/04/02 09:45:47 [debug] 30417#0: *27 fastcgi param: "DOCUMENT_ROOT: /var/www" 2015/04/02 09:45:47 [debug] 30417#0: *27 fastcgi param: "SERVER_PROTOCOL: HTTP/1.1" 2015/04/02 09:45:47 [debug] 30417#0: *27 fastcgi param: "HTTPS: on" 2015/04/02 09:45:47 [debug] 30417#0: *27 fastcgi param: "GATEWAY_INTERFACE: CGI/1.1" 2015/04/02 09:45:47 [debug] 30417#0: *27 fastcgi param: "SERVER_SOFTWARE: nginx/1.6.2" 2015/04/02 09:45:47 [debug] 30417#0: *27 fastcgi param: "REMOTE_ADDR: ::ffff:185.44.52.19" 2015/04/02 09:45:47 [debug] 30417#0: *27 fastcgi param: "REMOTE_PORT: 59031" 2015/04/02 09:45:47 [debug] 30417#0: *27 fastcgi param: "SERVER_ADDR: ::ffff:194.242.17.46" 2015/04/02 09:45:47 [debug] 30417#0: *27 fastcgi param: "SERVER_PORT: 443" 2015/04/02 09:45:47 [debug] 30417#0: *27 fastcgi param: "SERVER_NAME: xxxxxxxx.com" 2015/04/02 09:45:47 [debug] 30417#0: *27 fastcgi param: "REDIRECT_STATUS: 200" 2015/04/02 09:45:47 [debug] 30417#0: *27 fastcgi param: "HTTP_HOST: test-dev.test-saas.com" 2015/04/02 09:45:47 [debug] 30417#0: *27 fastcgi param: "HTTP_CONNECTION: keep-alive" 2015/04/02 09:45:47 [debug] 30417#0: *27 fastcgi param: "HTTP_CACHE_CONTROL: max-age=0" 2015/04/02 09:45:47 [debug] 30417#0: *27 fastcgi param: "HTTP_ACCEPT: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8" 2015/04/02 09:45:47 [debug] 30417#0: *27 fastcgi param: "HTTP_USER_AGENT: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/41.0.2272.89 Safari/537.36" 2015/04/02 09:45:47 [debug] 30417#0: *27 fastcgi param: "HTTP_REFERER: https://xxxxxxxxxxxxx/test?_s=to2JAP-JIInBRGhf&_k=QsA7EW6dlH-Ks2fm" 2015/04/02 09:45:47 [debug] 30417#0: *27 fastcgi param: "HTTP_ACCEPT_ENCODING: gzip, deflate, sdch" 2015/04/02 09:45:47 [debug] 30417#0: *27 fastcgi param: "HTTP_ACCEPT_LANGUAGE: de-DE,de;q=0.8,en-US;q=0.6,en;q=0.4,fil;q=0.2,pt;q=0.2" 2015/04/02 09:45:47 [info] 30417#0: *27 epoll_wait() reported that client prematurely closed connection, so upstream connection is closed too while sending request to upstream, client: ::ffff:185.44.52.19, server: test-dev.test-saas.com, request: "GET /test?_s=to2JAP-JIInBRGhf&_k=-_M7PBbUrqJsbOfI HTTP/1.1", upstream: "fastcgi://127.0.0.1:9002", host: "test-dev.test-saas.com", referrer: "https://xxxxxxxxxxxxxxxx/test?_s=to2JAP-JIInBRGhf&_k=QsA7EW6dlH-Ks2fm" 2015/04/02 09:45:47 [debug] 30417#0: *27 finalize http fastcgi request 2015/04/02 09:45:47 [debug] 30417#0: *28 fastcgi param: "QUERY_STRING: _s=to2JAP-JIInBRGhf&_k=-_M7PBbUrqJsbOfI" 2015/04/02 09:45:47 [debug] 30417#0: *28 fastcgi param: "REQUEST_METHOD: GET" 2015/04/02 09:45:47 [debug] 30417#0: *28 fastcgi param: "CONTENT_TYPE: " 2015/04/02 09:45:47 [debug] 30417#0: *28 fastcgi param: "CONTENT_LENGTH: " 2015/04/02 09:45:47 [debug] 30417#0: *28 fastcgi param: "SCRIPT_NAME: /test" 2015/04/02 09:45:47 [debug] 30417#0: *28 fastcgi param: "REQUEST_URI: /test?_s=to2JAP-JIInBRGhf&_k=-_M7PBbUrqJsbOfI" 2015/04/02 09:45:47 [debug] 30417#0: *28 fastcgi param: "DOCUMENT_URI: /test" 2015/04/02 09:45:47 [debug] 30417#0: *28 fastcgi param: "DOCUMENT_ROOT: /var/www" 2015/04/02 09:45:47 [debug] 30417#0: *28 fastcgi param: "SERVER_PROTOCOL: HTTP/1.1" 2015/04/02 09:45:47 [debug] 30417#0: *28 fastcgi param: "HTTPS: on" 2015/04/02 09:45:47 [debug] 30417#0: *28 fastcgi param: "GATEWAY_INTERFACE: CGI/1.1" 2015/04/02 09:45:47 [debug] 30417#0: *28 fastcgi param: "SERVER_SOFTWARE: nginx/1.6.2" 2015/04/02 09:45:47 [debug] 30417#0: *28 fastcgi param: "REMOTE_ADDR: ::ffff:185.44.52.19" 2015/04/02 09:45:47 [debug] 30417#0: *28 fastcgi param: "REMOTE_PORT: 30750" 2015/04/02 09:45:47 [debug] 30417#0: *28 fastcgi param: "SERVER_ADDR: ::ffff:194.242.17.46" 2015/04/02 09:45:47 [debug] 30417#0: *28 fastcgi param: "SERVER_PORT: 443" 2015/04/02 09:45:47 [debug] 30417#0: *28 fastcgi param: "SERVER_NAME: xxxxxxxxx.com" 2015/04/02 09:45:47 [debug] 30417#0: *28 fastcgi param: "REDIRECT_STATUS: 200" 2015/04/02 09:45:47 [debug] 30417#0: *28 fastcgi param: "HTTP_HOST: xxxxxxxxx.com" 2015/04/02 09:45:47 [debug] 30417#0: *28 fastcgi param: "HTTP_CONNECTION: keep-alive" 2015/04/02 09:45:47 [debug] 30417#0: *28 fastcgi param: "HTTP_CACHE_CONTROL: max-age=0" 2015/04/02 09:45:47 [debug] 30417#0: *28 fastcgi param: "HTTP_ACCEPT: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8" 2015/04/02 09:45:47 [debug] 30417#0: *28 fastcgi param: "HTTP_USER_AGENT: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/41.0.2272.89 Safari/537.36" 2015/04/02 09:45:47 [debug] 30417#0: *28 fastcgi param: "HTTP_REFERER: https://xxxxxxxxx/test?_s=to2JAP-JIInBRGhf&_k=QsA7EW6dlH-Ks2fm" 2015/04/02 09:45:47 [debug] 30417#0: *28 fastcgi param: "HTTP_ACCEPT_ENCODING: gzip, deflate, sdch" 2015/04/02 09:45:47 [debug] 30417#0: *28 fastcgi param: "HTTP_ACCEPT_LANGUAGE: de-DE,de;q=0.8,en-US;q=0.6,en;q=0.4,fil;q=0.2,pt;q=0.2" 2015/04/02 09:45:47 [info] 30417#0: *28 epoll_wait() reported that client prematurely closed connection, so upstream connection is closed too while sending request to upstream, client: ::ffff:185.44.52.19, server: test-dev.test-saas.com, request: "GET /test?_s=to2JAP-JIInBRGhf&_k=-_M7PBbUrqJsbOfI HTTP/1.1", upstream: "fastcgi://127.0.0.1:9003", host: "test-dev.test-saas.com", referrer: "https://xxxxxxxx/test?_s=to2JAP-JIInBRGhf&_k=QsA7EW6dlH-Ks2fm" 2015/04/02 09:45:47 [debug] 30417#0: *28 finalize http fastcgi request 2015/04/02 09:45:47 [debug] 30417#0: *20 fastcgi param: "QUERY_STRING: _s=to2JAP-JIInBRGhf&_k=-_M7PBbUrqJsbOfI" 2015/04/02 09:45:47 [debug] 30417#0: *20 fastcgi param: "REQUEST_METHOD: GET" 2015/04/02 09:45:47 [debug] 30417#0: *20 fastcgi param: "CONTENT_TYPE: " 2015/04/02 09:45:47 [debug] 30417#0: *20 fastcgi param: "CONTENT_LENGTH: " 2015/04/02 09:45:47 [debug] 30417#0: *20 fastcgi param: "SCRIPT_NAME: /test" 2015/04/02 09:45:47 [debug] 30417#0: *20 fastcgi param: "REQUEST_URI: /test?_s=to2JAP-JIInBRGhf&_k=-_M7PBbUrqJsbOfI" 2015/04/02 09:45:47 [debug] 30417#0: *20 fastcgi param: "DOCUMENT_URI: /test" 2015/04/02 09:45:47 [debug] 30417#0: *20 fastcgi param: "DOCUMENT_ROOT: /var/www" 2015/04/02 09:45:47 [debug] 30417#0: *20 fastcgi param: "SERVER_PROTOCOL: HTTP/1.1" 2015/04/02 09:45:47 [debug] 30417#0: *20 fastcgi param: "HTTPS: on" 2015/04/02 09:45:47 [debug] 30417#0: *20 fastcgi param: "GATEWAY_INTERFACE: CGI/1.1" 2015/04/02 09:45:47 [debug] 30417#0: *20 fastcgi param: "SERVER_SOFTWARE: nginx/1.6.2" 2015/04/02 09:45:47 [debug] 30417#0: *20 fastcgi param: "REMOTE_ADDR: ::ffff:185.44.52.19" 2015/04/02 09:45:47 [debug] 30417#0: *20 fastcgi param: "REMOTE_PORT: 58259" 2015/04/02 09:45:47 [debug] 30417#0: *20 fastcgi param: "SERVER_ADDR: ::ffff:194.242.17.46" 2015/04/02 09:45:47 [debug] 30417#0: *20 fastcgi param: "SERVER_PORT: 443" 2015/04/02 09:45:47 [debug] 30417#0: *20 fastcgi param: "SERVER_NAME: xxxxxxxxxxxxxxxx.com" 2015/04/02 09:45:47 [debug] 30417#0: *20 fastcgi param: "REDIRECT_STATUS: 200" 2015/04/02 09:45:47 [debug] 30417#0: *20 fastcgi param: "HTTP_HOST: xxxxxxxxxxxxxxxx.com" 2015/04/02 09:45:47 [debug] 30417#0: *20 fastcgi param: "HTTP_CONNECTION: keep-alive" 2015/04/02 09:45:47 [debug] 30417#0: *20 fastcgi param: "HTTP_CACHE_CONTROL: max-age=0" 2015/04/02 09:45:47 [debug] 30417#0: *20 fastcgi param: "HTTP_ACCEPT: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8" 2015/04/02 09:45:47 [debug] 30417#0: *20 fastcgi param: "HTTP_USER_AGENT: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/41.0.2272.89 Safari/537.36" 2015/04/02 09:45:47 [debug] 30417#0: *20 fastcgi param: "HTTP_REFERER: https://xxxxxxxxx/test?_s=to2JAP-JIInBRGhf&_k=QsA7EW6dlH-Ks2fm" 2015/04/02 09:45:47 [debug] 30417#0: *20 fastcgi param: "HTTP_ACCEPT_ENCODING: gzip, deflate, sdch" 2015/04/02 09:45:47 [debug] 30417#0: *20 fastcgi param: "HTTP_ACCEPT_LANGUAGE: de-DE,de;q=0.8,en-US;q=0.6,en;q=0.4,fil;q=0.2,pt;q=0.2" 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 01 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 06 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 00 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 01 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: FF 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: FF 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 00 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 00 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record length: 65535 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi parser: -2 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi parser: 0 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi header: "Status: 200" 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi parser: 0 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi header: "Content-length: 92451" 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi parser: 0 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi header: "Content-type: text/html;charset=utf-8" 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi parser: 1 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi header done 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 01 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 06 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 00 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 01 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 69 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 71 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 00 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 00 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record length: 26993 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 01 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 06 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 00 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 01 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 00 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 00 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 00 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 00 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record length: 0 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi closed stdout 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 01 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 06 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 00 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 01 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 00 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 00 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 00 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 00 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record length: 0 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi closed stdout 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 01 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 03 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 00 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 01 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 00 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 08 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 00 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record byte: 00 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi record length: 8 2015/04/02 09:45:47 [debug] 30417#0: *20 http fastcgi sent end request 2015/04/02 09:45:47 [debug] 30417#0: *20 finalize http fastcgi request
_______________________________________________ Glass mailing list [hidden email] http://lists.gemtalksystems.com/mailman/listinfo/glass |
Re: [Glass] Fastcgi Socket issues
|
|
Gerhard,
For Socket issue #1, the error is indicating that a reference to a GsSocket was committed and then some of the state managed by that socket was lost ... In the normal run of things I would not expect socket instances to get committed ... I don't think that WAFastCGIAdaptor instances (the ultimate parent) should be persisted... For Socket issue #2, ENOTCONN means that the socket is not connected and could have been caused by the client deciding to close the connection ... From the stack: 27 FSResponderRole (FSRole) >> sendEndRequestSuccess @5 line 4 [GsNMethod 815217409] It appears that the stderr and stdout have already been succesfully written to the connection and the error is occurring when the server is writing the last little bit to say that fastCGI is done with the request ... so it is indeed likely that the nginx server itself is deciding to close the connection... If I'm not mistaken the nginx log entry confirms this diagnosis as well: 2015/04/02 09:45:47 [info] 30417#0: *27 epoll_wait() reported that client prematurely closed connection, so upstream connection is closed too while sending request to upstream, client: ::ffff:185.44.52.19, server: test-dev.test-saas.com, request: "GET /test?_s=to2JAP-JIInBRGhf&_k=-_M7PBbUrqJsbOfI HTTP/1.1", upstream: "fastcgi://127.0.0.1:9002", host: "test-dev.test-saas.com", referrer: "https://xxxxxxxxxxxxxxxx/test?_s=to2JAP-JIInBRGhf&_k=QsA7EW6dlH-Ks2fm" Dale On 04/02/2015 09:26 AM, Gerhard
Obermann via Glass wrote:
_______________________________________________ Glass mailing list [hidden email] http://lists.gemtalksystems.com/mailman/listinfo/glass |
Re: [Glass] Fastcgi Socket issues
|
|
Hi Dale,
I have the same issue, but not with fast_cgi. What happens with the socket and persitance if one has activated the logToObjectLog flag? Would this persist sockets during error cases? Especiall if one endup in an "halt"? Sebastian Am 02.04.2015 um 10:00 schrieb Dale Henrichs via Glass: Gerhard, _______________________________________________ Glass mailing list [hidden email] http://lists.gemtalksystems.com/mailman/listinfo/glass |
Re: [Glass] Fastcgi Socket issues
|
|
Sebastian,
Care was taken with the FastCGI code to try to avoid (perhaps not completely successfully) to avoid referencing socket instances from a persistent root ... In your case, with the gemServer (I assume) and using ZnNewGemServer (or one of the newer Zinc server implementations) I had to rewrite portions of the Zinc stack to make it "safe" to persist continuations (which happen when you use the logToObjectLog flag) ... this code isn't quite as old and the Zinc architecture when used with non-Seaside stacks (again presuming that you are not using Seaside) the server implementation (where the GsSocket resides) is not insulated from the continuation stack quite as cleanly ... With all of that said, if you could provide me with some stacks from your log file, I might be able to identify the specific problem ... Dale On 04/02/2015 10:07 AM, Sebastian
Heidbrink via Glass wrote:
_______________________________________________ Glass mailing list [hidden email] http://lists.gemtalksystems.com/mailman/listinfo/glass |
Re: [Glass] Fastcgi Socket issues
|
|
In reply to this post by GLASS mailing list
On Thu, Apr 2, 2015 at 1:26 PM, Gerhard Obermann via Glass <[hidden email]> wrote:
Hi Gerhard, I had a similar problem once I was (accidentally) storing GsFile or GsSocket instances in persistent collections. Then likely some of these objects went to disk, and when they come back, you get this error. So... I would check FSRecordSeries and callers... to be sure you are not making the GsSocket instance persistent. Maybe the heavy load makes it reproduce it because it's only when the SPC gets full enough to flush the GsSocket instance to disk... Cheers,
_______________________________________________ Glass mailing list [hidden email] http://lists.gemtalksystems.com/mailman/listinfo/glass |
Re: [Glass] Fastcgi Socket issues
|
|
Ups...Sorry, I don't know why I didn't see all answers but only Gerhard email. Sorry. On Thu, Apr 2, 2015 at 4:55 PM, Mariano Martinez Peck <[hidden email]> wrote:
_______________________________________________ Glass mailing list [hidden email] http://lists.gemtalksystems.com/mailman/listinfo/glass |
Re: [Glass] Fastcgi Socket issues
|
|
In reply to this post by GLASS mailing list
Well the first issue is gone since i have removed the default addToLog calls (including a commit) after the retry of commit conflicts. The second issue is mostly (as Dale pointed out) a cancel of the socket from the client, although it happens every few minutes, so I am not sure if this is always the reason. Gerhard On Thu, Apr 2, 2015 at 9:55 PM, Mariano Martinez Peck <[hidden email]> wrote:
_______________________________________________ Glass mailing list [hidden email] http://lists.gemtalksystems.com/mailman/listinfo/glass |
Re: [Glass] Fastcgi Socket issues
|
|
Gerhard,
Could you give me a pointer to the "default addToLog calls with commits" that you are referring to. When I looked at the code this morning I don't recall seeing any persistent objects being modified in the error logging code nor do I remember seeing commits... I could be wrong, but if you tell me the method that you fixed and and what you did to fix it, I would know exactly what you did rather than find something that I think you did.... Re ENOTCONN, I would think that the most common occurrence would be a user closing the tab on their browser, so it would be interesting to see the stack in the cases when FSResponderRole (FSRole) >> sendEndRequestSuccess is not on the stack ... because it's pretty obvious that you cannot get to sendEndRequestSuccess without having just successfully written to the socket ... different stacks may help us identify different mechanisms ... Dale On 4/2/15 1:03 PM, Gerhard Obermann via
Glass wrote:
_______________________________________________ Glass mailing list [hidden email] http://lists.gemtalksystems.com/mailman/listinfo/glass |
Re: [Glass] Fastcgi Socket issues
|
|
Thanks Gerhard,
I think I now understand this problem and I've submitted a bug report[1] on this with a bit more analysis if you are interested .. Thanks man! Dale [1] https://github.com/GsDevKit/Seaside31/issues/64 On 04/02/2015 10:09 PM, Gerhard
Obermann wrote:
_______________________________________________ Glass mailing list [hidden email] http://lists.gemtalksystems.com/mailman/listinfo/glass |
| Free forum by Nabble | Edit this page |