upstream could not be resolved...

[Alexandre Snarskii]

Hi!

Странная проблема вылезла: похоже, при какой-то фазе луны nginx
не может найти upstream, заданный в конфиге и лезет за ним в DNS. 

Задача - хитрый request routing в зависимости от переменных запроса,
поэтому запросы сначала передаются на fastcgi-скрипт, который 
делает необходимый анализ и отдает обратно x-accel-redirect 
на внутренний хост. 

Конфиг примерно такой: 

 http { 
  upstream sws-pod2 {  # с точным заданием номера порта тоже пробовал
   server a.b.c.d;
  }
  server { 
   listen ...;
   location / { 
     fastcgi_pass 127.0.0.1:1030;
   }
   location ~* http://(.*):([0-9]+) { # да, знаю, криво. 
     internal;
     proxy_pass http://$1:$2/$request_uri$is_args$args;
   }
 }
  

часть debug log'а: 

2010/12/08 16:17:09 [debug] 24395#0: *8 http fastcgi parser: 0
2010/12/08 16:17:09 [debug] 24395#0: *8 http fastcgi header: "X-Accel-Redirect: http://sws-pod2:80"
2010/12/08 16:17:09 [debug] 24395#0: *8 http fastcgi parser: 1
2010/12/08 16:17:09 [debug] 24395#0: *8 http fastcgi header done
2010/12/08 16:17:09 [debug] 24395#0: *8 finalize http upstream request: -5
2010/12/08 16:17:09 [debug] 24395#0: *8 finalize http fastcgi request
2010/12/08 16:17:09 [debug] 24395#0: *8 free rr peer 1 0
2010/12/08 16:17:09 [debug] 24395#0: *8 close http upstream connection: 74
2010/12/08 16:17:09 [debug] 24395#0: *8 event timer del: 74: 3324098876
2010/12/08 16:17:09 [debug] 24395#0: *8 internal redirect: "http://sws-pod2:80?"
2010/12/08 16:17:09 [debug] 24395#0: *8 rewrite phase: 0
[...]

2010/12/08 16:17:09 [debug] 24395#0: *8 using configuration "http://(.*):([0-9]+)"

[.... - все заголовки копируются вполне корректно ]

2010/12/08 16:17:09 [debug] 24395#0: resolve: "sws-pod2"
2010/12/08 16:17:09 [debug] 24395#0: malloc: 090160E0:60
2010/12/08 16:17:09 [debug] 24395#0: malloc: 0904FD88:8
2010/12/08 16:17:09 [debug] 24395#0: malloc: 090CBB90:26
2010/12/08 16:17:09 [debug] 24395#0: resolve: "sws-pod2" 62087
2010/12/08 16:17:09 [debug] 24395#0: send: fd:70 26 of 26
2010/12/08 16:17:09 [debug] 24395#0: malloc: 090F88B8:52
2010/12/08 16:17:09 [debug] 24395#0: event timer add: -1: 30000:3324070903
2010/12/08 16:17:09 [debug] 24395#0: event timer add: -1: 5000:3324045903
2010/12/08 16:17:09 [debug] 24395#0: *8 http finalize request: -4, "http://sws-pod2:80?" a:1, c:3
2010/12/08 16:17:09 [debug] 24395#0: *8 http request count:3 blk:0
2010/12/08 16:17:09 [debug] 24395#0: *8 http finalize request: -4, "http://sws-pod2:80?" a:1, c:2
2010/12/08 16:17:09 [debug] 24395#0: *8 http request count:2 blk:0
2010/12/08 16:17:09 [debug] 24395#0: posted event 00000000
2010/12/08 16:17:09 [debug] 24395#0: worker cycle
2010/12/08 16:17:09 [debug] 24395#0: accept mutex locked
2010/12/08 16:17:09 [debug] 24395#0: epoll timer: 5000
2010/12/08 16:17:09 [debug] 24395#0: epoll: fd:70 ev:0001 d:B7EDC764
2010/12/08 16:17:09 [debug] 24395#0: post event B7E58D3C
2010/12/08 16:17:09 [debug] 24395#0: timer delta: 2
2010/12/08 16:17:09 [debug] 24395#0: posted events B7E58D3C
2010/12/08 16:17:09 [debug] 24395#0: posted event B7E58D3C
2010/12/08 16:17:09 [debug] 24395#0: delete posted event B7E58D3C
2010/12/08 16:17:09 [debug] 24395#0: recv: fd:70 26 of 4096
2010/12/08 16:17:09 [debug] 24395#0: resolver DNS response 62087 fl:8182 1/0/0/0
2010/12/08 16:17:09 [debug] 24395#0: resolver DNS response qt:1 cl:1
2010/12/08 16:17:09 [debug] 24395#0: malloc: 09050200:8
2010/12/08 16:17:09 [debug] 24395#0: resolver qs:sws-pod2
2010/12/08 16:17:09 [error] 24395#0: *8 sws-pod2 could not be resolved (2: Server failure), client: 192.168.13.218, server: service, request: "POST /login/main.asp HTTP/1.1", host: "192.168.15.132", referrer: "http://192.168.15.132/login/rdr.asp"
2010/12/08 16:17:09 [debug] 24395#0: *8 finalize http upstream request: 502
2010/12/08 16:17:09 [debug] 24395#0: resolve name done: 2


-- 
In theory, there is no difference between theory and practice. 
But, in practice, there is.