Unicorn

Unicorn

[Paul Sponagl]

Hi Eric,

the Featurelist sounds great !

I was using qrp for a long time and now i am eagerly awaiting a  
production ready release of unicorn :)

Btw. I tried it on OS-X with -l /tmp/thin.0.sock and it took a while  
for nginx to spit out the page...

... (60: Operation timed out) while reading upstream, client:  
127.0.0.1, server: w..., request: "GET / HTTP/1.1", upstream: "http://unix 
:/tmp/thin.0.sock:/" ...

but finally it appeared  (for now it is not development ready for  
me ;) But this evening i'll give it a try with tcp sockets.

thank you for your efforts in this great project and all the best

Paul




!DSPAM:4a51b6975171980815732!

Re: Unicorn

[Eric Wong]

Paul Sponagl <paul@sponagl.de> wrote:
> Hi Eric,
>
> the Featurelist sounds great !
>
> I was using qrp for a long time and now i am eagerly awaiting a  
> production ready release of unicorn :)
>
> Btw. I tried it on OS-X with -l /tmp/thin.0.sock and it took a while for 
> nginx to spit out the page...
>
> ... (60: Operation timed out) while reading upstream, client: 127.0.0.1, 
> server: w..., request: "GET / HTTP/1.1", upstream: "http://unix 
> :/tmp/thin.0.sock:/" ...
>
> but finally it appeared  (for now it is not development ready for me ;) 
> But this evening i'll give it a try with tcp sockets.

Weird.  I'm doubtful TCP sockets would solve your problems but let me
know if it fixes it.  UNIX and TCP sockets follow exactly the same code
paths once the server is running so I'm not sure what could be the issue
(especially since you're sending a body-less GET request).  Maybe OSX
has some weird rules/bugs with UNIX sockets (I've heard of issues with
FIFOs on OSX), but I don't have access to an OSX machine.

Is your "GET / HTTP/1.1" request supposed to be taking over 60s?  60
seconds is the default (and IMHO very conservative) timeout for when
Unicorn decides to terminate a request.

0.8.1 should actually be considered production-ready.  It doesn't
support chunked transfer-encoding; but otherwise it's been running
fine for some internal APIs for quite a while now.

> thank you for your efforts in this great project and all the best

Thanks for giving it a shot!

-- 
Eric Wong

Re: Unicorn

[Paul Sponagl]

Hi Eric,

unicorn does not close the connection on osx after sending the content.
(It acts as the client would send a Connection: Keep-Alive)
The connection will be aborted by nginx after about 60
secs and the content will be send out.

Macintosh:~> telnet 127.0.0.1 3001
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
GET / HTTP/1.1

HTTP/1.1 200 OK
Date: Tue, 07 Jul 2009 08:11:17 GMT
Status: 200 OK
Connection: close
X-Runtime: 293
ETag: "2659d611050f70fc65c6c052687e5a13"
Content-Type: text/html; charset=utf-8
Cache-Control: private, max-age=0, must-revalidate
Content-Length: 24328
...
the rest of the content



Hope that helps to track it down further.

Best
Paul


Am 07.07.2009 um 01:16 schrieb Eric Wong:

> Paul Sponagl <paul@sponagl.de> wrote:
>> Hi Eric,
>>
>> the Featurelist sounds great !
>>
>> I was using qrp for a long time and now i am eagerly awaiting a
>> production ready release of unicorn :)
>>
>> Btw. I tried it on OS-X with -l /tmp/thin.0.sock and it took a  
>> while for
>> nginx to spit out the page...
>>
>> ... (60: Operation timed out) while reading upstream, client:  
>> 127.0.0.1,
>> server: w..., request: "GET / HTTP/1.1", upstream: "http://unix
>> :/tmp/thin.0.sock:/" ...
>>
>> but finally it appeared  (for now it is not development ready for  
>> me ;)
>> But this evening i'll give it a try with tcp sockets.
>
> Weird.  I'm doubtful TCP sockets would solve your problems but let me
> know if it fixes it.  UNIX and TCP sockets follow exactly the same  
> code
> paths once the server is running so I'm not sure what could be the  
> issue
> (especially since you're sending a body-less GET request).  Maybe OSX
> has some weird rules/bugs with UNIX sockets (I've heard of issues with
> FIFOs on OSX), but I don't have access to an OSX machine.
>
> Is your "GET / HTTP/1.1" request supposed to be taking over 60s?  60
> seconds is the default (and IMHO very conservative) timeout for when
> Unicorn decides to terminate a request.
>
> 0.8.1 should actually be considered production-ready.  It doesn't
> support chunked transfer-encoding; but otherwise it's been running
> fine for some internal APIs for quite a while now.
>
>> thank you for your efforts in this great project and all the best
>
> Thanks for giving it a shot!
>
> -- 
> Eric Wong
>
> 
>
>


!DSPAM:4a53088a5179781588283!

Re: Unicorn

[Eric Wong]

Paul Sponagl <paul@sponagl.de> wrote:
> Hi Eric,
>
> unicorn does not close the connection on osx after sending the content.
> (It acts as the client would send a Connection: Keep-Alive)
> The connection will be aborted by nginx after about 60
> secs and the content will be send out.
>
> Macintosh:~> telnet 127.0.0.1 3001
> Trying 127.0.0.1...
> Connected to localhost.
> Escape character is '^]'.
> GET / HTTP/1.1
>
> HTTP/1.1 200 OK
> Date: Tue, 07 Jul 2009 08:11:17 GMT
> Status: 200 OK
> Connection: close
> X-Runtime: 293
> ETag: "2659d611050f70fc65c6c052687e5a13"
> Content-Type: text/html; charset=utf-8
> Cache-Control: private, max-age=0, must-revalidate
> Content-Length: 24328
> ...
> the rest of the content

Hi Paul,

This is strange.  Can you tell that you're getting all 24328 bytes of
the content?  And no exception is thrown to stderr, either?  Unicorn
should've closed the socket even on an exception.  Which version of OSX
and Ruby are you running?  Is there anything special/weird about the
Rack response body you're sending?   Does Rack::Lint complain about
anything?  Unicorn is fairly strict about Rack::Lint compatibility.

Does the following patch help?

diff --git a/lib/unicorn/http_response.rb b/lib/unicorn/http_response.rb
index bfaa33d..acf4d04 100644
--- a/lib/unicorn/http_response.rb
+++ b/lib/unicorn/http_response.rb
@@ -60,6 +60,7 @@ module Unicorn
                    "Connection: close\r\n" \
                    "#{OUT.join(Z)}\r\n")
       body.each { |chunk| socket.write(chunk) }
+      socket.flush
       socket.close # flushes and uncorks the socket immediately
       ensure
         body.respond_to?(:close) and body.close rescue nil
------------------------------------------------------------------------

Or you can replace the "socket.close" with "exit!(0)" and really
force it to close :)

Thanks again for trying this!

-- 
Eric Wong

Re: Unicorn

[Paul Sponagl]

Eric - you're a genius ! This patch solved it!
Indeed i am forking a sleeping cache refresh process at requests to  
'/' via a system call.
Now i am ready to give it a try. Thank you very much for your help!

All the best for you and unicorn
Paul

PS: Last time i forgot to cc to the list - i added my previous mail  
below to keep searchers- and engines happy.

Am 09.07.2009 um 00:04 schrieb Eric Wong:

> Paul Sponagl <paul@sponagl.de> wrote:
>
> <snip>
>
>> hmmm - everything works as it should...
>
> Very odd, nothing out of the ordinary there.  Is there any chance your
> application forks/execs long-running processes in the background?  I'm
> relying on the FD_CLOEXEC flag to be inherited by accepted sockets  
> from
> the original listen socket.  Maybe that's not the case with OSX...
>
> Perhaps this patch can fix things under OSX?
>
> diff --git a/lib/unicorn.rb b/lib/unicorn.rb
> index 281aa7d..f3073f4 100644
> --- a/lib/unicorn.rb
> +++ b/lib/unicorn.rb
> @@ -444,6 +444,7 @@ module Unicorn
>     # once a client is accepted, it is processed in its entirety here
>     # in 3 easy steps: read request, call app, write app response
>     def process_client(app, client)
> +      client.fcntl(Fcntl::F_SETFD, Fcntl::FD_CLOEXEC)
>       response = app.call(env = REQUEST.read(client))
>
>       if 100 == response.first.to_i
>
>> i also tried this config.ru
>> ---8<---
>> # config.ru
>> require "config/environment"
>> use Rack::Lint
>> run ActionController::Dispatcher.new
>> ---8<---
>>
>> does this activate Rack::Lint ?
>
> Yes it should.
>
> Thanks for looking into this issue and doing detailed analysis
> on it!
>
> -- 
> Eric Wong
>
> 
>
>

Hi Eric,

ok, let me write down a few tests:


unicorn_rails with static content:
-------------------------------------------

Macintosh-2:> echo -n "7 bytes" > public/test.html
Macintosh-2:> unicorn_rails
I, [2009-07-08T09:46:53.445542 #25037]  INFO -- : listening on  
addr=0.0.0.0:8080 fd=3
I, [2009-07-08T09:46:53.647616 #25037]  INFO -- : worker=0 spawning...
I, [2009-07-08T09:46:53.648553 #25037]  INFO -- : master process ready
I, [2009-07-08T09:46:53.651324 #25039]  INFO -- : worker=0 spawned  
pid=25039
I, [2009-07-08T09:46:53.651812 #25039]  INFO -- : Refreshing Gem list
worker=0 ready

Macintosh-2:~> telnet 127.0.0.1 8080
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
GET /test.html HTTP/1.1
Host: test.local

HTTP/1.1 200 OK
Date: Wed, 08 Jul 2009 07:47:33 GMT
Status: 200 OK
Connection: close
Last-Modified: Wed, 08 Jul 2009 07:46:42 GMT
Content-Type: text/html
Content-Length: 7

7 bytesConnection closed by foreign host.

Worked ...

unicorn_rails with simple rails content:
--------------------------------------------------

class HomeController < ApplicationController
  layout 'home'
  def test
    render :text => '7 bytes'
  end

Macintosh-2:~> telnet 127.0.0.1 8080
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
GET /home/test HTTP/1.1
Host: test.local

HTTP/1.1 200 OK
Date: Wed, 08 Jul 2009 07:50:23 GMT
Status: 200 OK
Connection: close
X-Runtime: 2059
ETag: "4028bd3c2c4b2eec87994d1a46c86878"
Content-Type: text/html; charset=utf-8
Cache-Control: private, max-age=0, must-revalidate
Content-Length: 7
Set-Cookie: flash=%7B%7D; path=/
Set-Cookie: _bilderbuch_session=...; path=/; HttpOnly

7 bytesConnection closed by foreign host.

worked...

thin with more complex rails content:
--------------------------------------------------

Macintosh-2:~> wget --server-response http://127.0.0.1:8080/
--10:01:52--  http://127.0.0.1:8080/
           => `index.html.3'
Verbindungsaufbau zu 127.0.0.1:8080... verbunden.
HTTP Anforderung gesendet, warte auf Antwort...
1 HTTP/1.1 200 OK
2 X-Runtime: 446
3 ETag: "0eda35d2574d23011a57cff8043800c8"
4 Content-Type: text/html; charset=utf-8
5 Cache-Control: private, max-age=0, must-revalidate
6 Set-Cookie: flash=%7B%7D; path=/
7 Set-Cookie: _bilderbuch_session=...; path=/; HttpOnly
8 Content-Length: 24340
9 Connection: keep-alive
10 Server: thin 1.0.0 codename That's What She Said

100%[======>] 24,340        23.21M/s    ETA 00:00

10:01:53 (23.21 MB/s) - »index.html.3« gespeichert [24340/24340]

Macintosh-2:~> ls -la index.html.3
-rw-r--r--    1 paulspon paulspon    24340  8. Jul 10:01 index.html.3

worked (content-length and filesize matches)...

unicorn_rails with more complex rails content:
-------------------------------------------------------------

Macintosh-2:~> wget --server-response http://127.0.0.1:8080/
--10:02:50--  http://127.0.0.1:8080/
           => `index.html.4'
Verbindungsaufbau zu 127.0.0.1:8080... verbunden.
HTTP Anforderung gesendet, warte auf Antwort...
1 HTTP/1.1 200 OK
2 Date: Wed, 08 Jul 2009 08:02:51 GMT
3 Status: 200 OK
4 Connection: close
5 X-Runtime: 1541
6 ETag: "e750924df3f2890ab7d8a560d0088c1a"
7 Content-Type: text/html; charset=utf-8
8 Cache-Control: private, max-age=0, must-revalidate
9 Content-Length: 24376
10 Set-Cookie: flash=%7B%7D; path=/
11 Set-Cookie: _bilderbuch_session=...; path=/; HttpOnly

0% [ ] 0             --.--K/s    ETA --:--

does not work (waiting forever...) but - after killing unicorn_rails

Macintosh-2:~> ls -la index.html.4
-rw-r--r--    1 paulspon paulspon    24376  8. Jul 10:02 index.html.4

its there...

unicorn_rails with more complex rails content:
( after adding your suggested socket.flush: )
-------------------------------------------------------------

no changes - still timeouts...


a few more tests:
----------------------------
      socket.write("HTTP/1.1 #{status}\r\n" \
                   "Date: #{Time.now.httpdate}\r\n" \
                   "Status: #{status}\r\n" \
                   "Connection: close\r\n" \
                   "#{OUT.join(Z)}\r\n")
      size = 0
      puts "after socket.write HEADER"
      body.each { |chunk|
        size += chunk.length
        socket.write(chunk)
      }
      puts "after socket.write BODY #{size}"
      socket.flush
      exit!(0)

Content lengt matches output
wget :...
9 Content-Length: 25257
...

after socket.write HEADER
after socket.write BODY 25257
I, [2009-07-08T10:18:16.137773 #25334]  INFO -- : reaped  
#<Process::Status: pid=25336,exited(0)> worker=0
I, [2009-07-08T10:18:16.161050 #25334]  INFO -- : worker=0 spawning...
...

hmmm - everything works as it should...

i also tried this config.ru
---8<---
# config.ru
require "config/environment"
use Rack::Lint
run ActionController::Dispatcher.new
---8<---

does this activate Rack::Lint ?



this is all really strange - do i miss something simple in here ???

Best
Paul


!DSPAM:4a55a7665173716248820!

Re: Unicorn

[Eric Wong]

Paul Sponagl <paul@sponagl.de> wrote:
> Eric - you're a genius ! This patch solved it!

Cool, but a genius would've avoided this problem entirely :)

> Indeed i am forking a sleeping cache refresh process at requests to '/' 
> via a system call.
> Now i am ready to give it a try. Thank you very much for your help!
>
> All the best for you and unicorn
> Paul

No problem, thanks for reporting the issues.  I've just released 0.8.2
(stable) and 0.9.1 (experimental) with the fix.  Hopefully that's the
last 0.8.x release since I've bigger plans for 0.9.x (or 0.10.x).

> PS: Last time i forgot to cc to the list - i added my previous mail  
> below to keep searchers- and engines happy.

Thanks again, btw can you avoid top-posting here?  I'm really old
school like that :)

-- 
Eric Wong