[Glass] Nginx , FastCGI and GLASS problem
Paul DeBruicker
pdebruic at gmail.com
Wed Dec 4 14:29:55 PST 2013
Sounds to me like you have an error in your Seaside app or your own code that
kills your FastCGI gems.
In your Seaside app are you using the WAGemStoneProductionErrorHandler? If
not, switch to it. If so, are any errors getting put on the ObjectLog?
Do you have monit or daemontools monitoring your FastCGI gems to restart
them automatically when they become unresponsive?
Mariano Martinez Peck wrote
> ObjectLog, from yesterday: FastCGI: topaz exit Object: port: 9003
> pid:
> 2743
>
>
> And now, FastCGI of 9001 (gem 1)
>
> Unreportable ERROR Encountered:
> 2013-12-04T07:22:54.77649903297424-08:00UserDefinedError:
> send(15,0x7f352f636400,49,0) failed with errno=107,ENOTCONN, Socket is not
> connected-----------
>
> So I got this error in each of the gems....
>
> Any idea?
>
>
>
> On Wed, Dec 4, 2013 at 9:56 AM, Mariano Martinez Peck <
> marianopeck@
> > wrote:
>
>>
>>
>>
>> On Tue, Nov 26, 2013 at 3:22 AM, Johan Brichau <
> johan@
> > wrote:
>>
>>> Mariano,
>>>
>>> I would guess not all fastcgi gems are running correctly on all ports.
>>> There is a default timeout of 60s in nginx before it will pass a fastcgi
>>> request to another port in the upstream configuration.
>>>
>>> The reason you see the delay with the post and not with the following
>>> get
>>> might be because nginx is doing a round-trip load balance over the
>>> fastcgi
>>> backends and one request goes to a working port but the next is not (or
>>> vice-versa).
>>>
>>> You might want to experiment by limiting the nginx conf to a single
>>> fastcgi backend and/or change the default timeout and put some logging
>>> code
>>> in your app when the request gets to seaside. That would at least allow
>>> to
>>> find on what to focus.
>>>
>>>
>>
>> Thanks Johan, that was indeed the problem. This is the second time that
>> happened to me. If I restart everything, it will probably be "fixed". But
>> I
>> don't want to do that to really fix the problem. So 9001 is answering
>> correct, yet, 9002 yields timeone and 9003 yields could not connect after
>> 1
>> minute.... I tried by doing:
>>
>> curl -v http://localhost:9003/myApp
>>
>> So...the thing is how to know what the hell is happening that some of my
>> gems (or FastCGI adaptors) go down for some reason.
>> I have checked all my gemstone logs. 2 things look suspicious.
>> FastCGI_server-9003.log shows that I have a button that updates my app
>> code
>> in GemStone which is causing this:
>>
>> a RepositoryViewLost occurred (notification 3031), When running outside
>> of a transaction the session failed to respond quickly enough to a
>> request from Stone to abort. All object caches have been cleared.
>> nil
>>
>> Then,there are some: ----------- Commit failure - retrying LOG ENTRY:
>> aSymbolDictionary-----------
>>
>> Here is the pieces of logs I could rescue. Maybe someone could help me
>> figure out what is happening!
>>
>> Thanks in advance!!
>>
>>
>> seaside_2485pcmon.log
>>
>> [12/04/13 02:17:21.210 EST]: Client died: Slot 12, PID 2743,
>> LostOtFlags 0, Name FastCGI-11-DataCurator
>> [12/04/13 02:17:21.210 EST]: Starting crashed client recovery: Slot 12,
>> PID 2743, Name FastCGI-11-DataCurator
>> Cleaned up locked/pinned frame 550 for crashed process 2743
>> Cleaned up locked/pinned frame 11545 for crashed process 2743
>> Cleaned up locked/pinned frame 3929 for crashed process 2743
>> Cleaned up locked/pinned frame 11407 for crashed process 2743
>> Disposing free frame cache from slot 12: 4 of 4 frames recovered.
>> [12/04/13 02:17:23.451 EST]: Finished crashed client recovery: Slot 12,
>> PID 2743, Name FastCGI-11-DataCurator
>>
>>
>> FastCGI_server-9001.log (which is the only gem/adaptor that seems to be
>> working)
>>
>> paz 1> topaz 1> topaz 1> topaz 1> FastCGI Server started on port 9001
>> ----------- Unreportable ERROR Encountered:
>> 2013-12-03T22:52:06.46091294288635-08:00UserDefinedError:
>> send(16,0x7f352f6ebba8,7416,0) failed with errno=107,ENOTCONN, Socket is
>> not connected-----------
>> ----------- Unreportable ERROR Encountered:
>> 2013-12-03T22:53:06.45396900177002-08:00UserDefinedError:
>> send(17,0x7f352f786110,7416,0) failed with errno=107,ENOTCONN, Socket is
>> not connected-----------
>> ----------- Unreportable ERROR Encountered:
>> 2013-12-03T23:05:07.57434701919556-08:00UserDefinedError:
>> send(14,0x7f352f65e6c0,2673,0) failed with errno=107,ENOTCONN, Socket is
>> not connected-----------
>> ----------- Unreportable ERROR Encountered:
>> 2013-12-03T23:05:31.43626189231873-08:00UserDefinedError:
>> send(15,0x7f352f6bed60,2673,0) failed with errno=107,ENOTCONN, Socket is
>> not connected-----------
>> ----------- Unreportable ERROR Encountered:
>> 2013-12-03T23:14:13.39595103263855-08:00UserDefinedError:
>> send(16,0x7f352f71f7e0,2673,0) failed with errno=107,ENOTCONN, Socket is
>> not connected-----------
>> ----------- Unreportable ERROR Encountered:
>> 2013-12-03T23:15:13.47269105911255-08:00UserDefinedError:
>> send(17,0x7f352f77ff90,2673,0) failed with errno=107,ENOTCONN, Socket is
>> not connected-----------
>>
>>
>> FastCGI_server-9002.log
>>
>> failure
>> Read-Write Conflicts...
>> Write-Write Conflicts...
>> 383168257
>> Write-Dependency Conflicts...
>> Write-ReadLock Conflicts...
>> Write-WriteLock Conflicts...
>> Rc-Write-Write Conflicts...
>> Synchronized-Commit Conflicts...
>> ----------- Commit failure - retrying LOG ENTRY:
>> aSymbolDictionary-----------
>> failure
>> Read-Write Conflicts...
>> Write-Write Conflicts...
>> 383168257
>> Write-Dependency Conflicts...
>> Write-ReadLock Conflicts...
>> Write-WriteLock Conflicts...
>> Rc-Write-Write Conflicts...
>> Synchronized-Commit Conflicts...
>> ----------- Commit failure - retrying LOG ENTRY:
>> aSymbolDictionary-----------
>> ----------- Unreportable ERROR Encountered:
>> 2013-12-04T04:36:49.04186797142029-08:00UserDefinedError:
>> send(16,0x7f21f9462268,2673,0) failed with errno=107,ENOTCONN, Socket is
>> not connected-----------
>> ----------- Unreportable ERROR Encountered:
>> 2013-12-04T04:36:49.0669538974762-08:00UserDefinedError:
>> send(17,0x7f21f94ed6c8,2673,0) failed with errno=107,ENOTCONN, Socket is
>> not connected-----------
>> ----------- Unreportable ERROR Encountered:
>> 2013-12-04T04:36:49.10030889511108-08:00UserDefinedError:
>> send(18,0x7f21f9551ae8,2673,0) failed with errno=107,ENOTCONN, Socket is
>> not connected-----------
>> ----------- Unreportable ERROR Encountered:
>> 2013-12-04T04:36:49.11388611793518-08:00UserDefinedError:
>> send(14,0x7f21f95b2918,2673,0) failed with errno=107,ENOTCONN, Socket is
>> not connected-----------
>> ----------- Unreportable ERROR Encountered:
>> 2013-12-04T04:36:49.12687110900879-08:00UserDefinedError:
>> send(19,0x7f21f96184e8,2673,0) failed with errno=107,ENOTCONN, Socket is
>> not connected-----------
>> ----------- Unreportable ERROR Encountered:
>> 2013-12-04T04:36:49.12758493423462-08:00UserDefinedError: Incorrect FCGI
>> version. Expected: 1 Received: 71-----------
>> ----------- Unreportable ERROR Encountered:
>> 2013-12-04T04:36:49.15798401832581-08:00UserDefinedError:
>> send(15,0x7f21f968f7d8,2673,0) failed with errno=107,ENOTCONN, Socket is
>> not connected-----------
>>
>>
>>
>> FastCGI_server-9003.log
>>
>>
>> --transcript--'...finished 1.4-baseline'
>> failure
>> Read-Write Conflicts...
>> Write-Write Conflicts...
>> 288128769
>> 294245633
>> Write-Dependency Conflicts...
>> Write-ReadLock Conflicts...
>> Write-WriteLock Conflicts...
>> Rc-Write-Write Conflicts...
>> Synchronized-Commit Conflicts...
>> ----------- Commit failure - retrying LOG ENTRY:
>> aSymbolDictionary-----------
>> -----------------------------------------------------
>> GemStone: Error Nonfatal
>> a RepositoryViewLost occurred (notification 3031), When running outside
>> of a transaction the session failed to respond quickly enough to a
>> request from Stone to abort. All object caches have been cleared.
>> nil
>> Error Category: 231169 [GemStone] Number: 3031 Arg Count: 1 Context :
>> 318063361 exception : 318063105
>> Arg 1: [20 sz:0 cls: 76289 UndefinedObject] nil
>> topaz > exec iferr 1 : where
>> ==> 1 AbstractException >> _signalWith: (envId 0) @6 line 25
>> [methId 4496129]
>> 2 [] in AbstractException >> _signalAsync (envId 0) @2 line 19
>> [methId 4605185]
>> 3 ExecBlock >> ensure: (envId 0) @2 line 12
>> [methId 3709185]
>> 4 AbstractException >> _signalAsync (envId 0) @6 line 21
>> [methId 4600321]
>> 5 ProcessorScheduler >> _reapEvents: (envId 0) @96 line 86
>> [methId 4810241]
>> 6 ProcessorScheduler >> _findReadyProcess: (envId 0) @2 line 8
>> [methId 4815105]
>> 7 ProcessorScheduler >> _reschedule (envId 0) @3 line 8
>> [methId 4805121]
>> 8 GsProcess >> _wait (envId 0) @3 line 3
>> [methId 4486145]
>> 9 Delay >> _wait: (envId 0) @26 line 26
>> [methId 13285377]
>> 10 Delay >> wait (envId 0) @3 line 5
>> [methId 13307905]
>> 11 [] in Executed Code (envId 0) @3 line 32
>> [methId 318074625]
>> 12 GsProcess >> _start (envId 0) @7 line 16
>> [methId 4467969]
>> 13 GsNMethod class >> _gsReturnToC (envId 0) @1 line 1
>> [methId 4461825]
>> [GsProcess 318063361]
>> topaz 1> topaz 1> [268 sz:0 cls: 68097 Boolean] true
>>
>>
>>
>>
>>
>>
>>
>>
>>> Johan
>>>
>>> On 26 Nov 2013, at 00:33, Mariano Martinez Peck <
> marianopeck@
> >
>>> wrote:
>>>
>>> Also, when I see that 1-minute request in the browser development tools,
>>> it appears like 2ms receiving, 1 minute waiting...weird!
>>>
>>>
>>> On Mon, Nov 25, 2013 at 8:26 PM, Mariano Martinez Peck <
>>>
> marianopeck@
>> wrote:
>>>
>>>> HI guys. This is the first time I am trying to use FastCGI. For some
>>>> reason, i have a timeout with fastCGI.
>>>> I started the Gems either with:
>>>>
>>>>
>>>> WAGemStoneRunSeasideGems default
>>>> name: 'FastCGI';
>>>> adaptorClass: WAFastCGIAdaptor;
>>>> ports: #(9001 9002 9003).
>>>> WAGemStoneRunSeasideGems restartGems.
>>>>
>>>> (from GemTools) or from command line:
>>>>
>>>> ./startSeaside_FastCGI 9001
>>>>
>>>> In either case, what happens is that I can browse my app
>>>> http:localhost:9001/dp (and 9002 and 9003). But when I do a request to
>>>> the
>>>> server trough my FastCGI, it takes ONE MINUTE to load the page. I am
>>>> using
>>>> Nginx in the backend with this configuration:
>>>>
>>>> upstream seaside
>>>> {
>>>> server localhost:9001;
>>>> server localhost:9002;
>>>> server localhost:9003;
>>>> }
>>>>
>>>> server
>>>> {
>>>>
>>>> listen 33300;
>>>> server_name localhost;
>>>> root /var/www/glass/;
>>>>
>>>>
>>>> access_log /var/log/nginx/fastCGI.log;
>>>> error_log /var/log/nginx/error.log info;
>>>>
>>>> location /
>>>> {
>>>> try_files $uri @seaside;
>>>> # error_page 403 404 = @seaside;
>>>> }
>>>>
>>>> location @seaside
>>>> {
>>>> include fastcgi_params;
>>>> fastcgi_pass seaside;
>>>> }
>>>> }
>>>>
>>>>
>>>> Using the webtools of the browser, I see that each time I go to a page,
>>>> there is either a GET or a POST that takes exactly 1 minute. I
>>>> mean...nothing happens, until one minute passes and then the page is
>>>> rendered. The requests are small. And in fact, browsing directly to
>>>> 9001/2/3 works perfectly. So I guess this is a one minute timeout of
>>>> something.
>>>>
>>>> For what I can see, it could be related to the
>>>>
>>>> keepalive_timeout 65;
>>>>
>>>> And in nginx error.log I see something like:
>>>>
>>>> 2013/11/25 17:38:18 [error] 22835#0: *73 upstream timed out (60:
>>>> Operation timed out) while reading response header from upstream,
>>>> client:
>>>> 127.0.0.1, server: localhost, request: "GET /dp HTTP/1.1", upstream:
>>>> "fastcgi://127.0.0.1:9001", host: "localhost:33300"
>>>> 2013/11/25 17:38:18 [info] 22835#0: *73 kevent() reported that client
>>>> 127.0.0.1 closed keepalive connection
>>>>
>>>> Any ideas what could be wrong?
>>>>
>>>>
>>>> Thanks!
>>>>
>>>> --
>>>> Mariano
>>>> http://marianopeck.wordpress.com
>>>>
>>>
>>>
>>>
>>> --
>>> Mariano
>>> http://marianopeck.wordpress.com
>>>
>>> _______________________________________________
>>>
>>> Glass mailing list
>>>
> Glass at .gemtalksystems
>>> http://lists.gemtalksystems.com/mailman/listinfo/glass
>>>
>>>
>>
>>
>> --
>> Mariano
>> http://marianopeck.wordpress.com
>>
>
>
>
> --
> Mariano
> http://marianopeck.wordpress.com
>
> _______________________________________________
> Glass mailing list
> Glass at .gemtalksystems
> http://lists.gemtalksystems.com/mailman/listinfo/glass
--
View this message in context: http://forum.world.st/Glass-Nginx-FastCGI-and-GLASS-problem-tp4725218p4727568.html
Sent from the GLASS mailing list archive at Nabble.com.
More information about the Glass
mailing list