<div dir="ltr"><div>Hi,</div><div><br></div><div>thanks for the suggestion! However, seems like all server processes are ready at this point</div><div><br></div><div>## modified wsgi file:</div><div><br></div><div>import os</div>

<div>pid = os.getpid()</div><div>print "loading stage 1", pid</div><div>application = myapp.create_app(CONFIG_FILE, None, log, strict=True)</div><div>print "loading stage 2", pid</div><div><br></div><div>

application.logger.setLevel(logging.DEBUG)</div><div>for handler in log.logger().handlers:</div><div>    application.logger.addHandler(handler)</div><div>print "loading stage 3", pid</div><div><br></div><div>## updated logs</div>

<div><br></div><div><div>...The work of process 17248 is done. Seeya!</div><div>...The work of process 17249 is done. Seeya!</div><div>worker 1 killed successfully (pid: 17248)</div><div>Respawned uWSGI worker 1 (new pid: 17424)</div>

<div>worker 2 killed successfully (pid: 17249)</div><div>Respawned uWSGI worker 2 (new pid: 17425)</div><div>loading stage 1 17425</div><div>loading stage 1 17424</div><div>loading stage 2 17424</div><div>loading stage 2 17425</div>

<div>loading stage 3 17424</div><div>loading stage 3 17425</div><div>WSGI app 0 (mountpoint='') ready in 1 seconds on interpreter 0x2278480 pid: 17424 (default app)</div><div>WSGI app 0 (mountpoint='') ready in 1 seconds on interpreter 0x2278480 pid: 17425 (default app)</div>

<div>...The work of process 17425 is done. Seeya!</div><div>...The work of process 17424 is done. Seeya!</div><div>worker 1 killed successfully (pid: 17424)</div><div>Respawned uWSGI worker 1 (new pid: 17956)</div><div>worker 2 killed successfully (pid: 17425)</div>

<div>Respawned uWSGI worker 2 (new pid: 17957)</div><div>loading stage 1 17957</div><div>loading stage 1 17956</div><div>loading stage 2 17956</div><div>loading stage 2 17957</div><div>loading stage 3 17956</div><div>loading stage 3 17957</div>

<div>WSGI app 0 (mountpoint='') ready in 1 seconds on interpreter 0x2278480 pid: 17956 (default app)</div><div>WSGI app 0 (mountpoint='') ready in 1 seconds on interpreter 0x2278480 pid: 17957 (default app)</div>

<div>[pid: 17956|app: 0|req: 2/3571] 192.168.100.11 () {32 vars in 432 bytes} [Wed Apr  9 15:48:11 2014] GET /myapp/... => generated 238 bytes in 7 msecs (HTTP/1.1 404) 2 headers in 72 bytes (1 switches on core 1)</div>

<div>[pid: 17956|app: 0|req: 10/3573] 192.168.100.11 () {32 vars in 432 bytes} [Wed Apr  9 15:48:11 2014] GET /myapp/... => generated 238 bytes in 16 msecs (HTTP/1.1 404) 2 headers in 72 bytes (1 switches on core 0)</div>

<div>[pid: 17956|app: 0|req: 18/3575] 192.168.100.11 () {32 vars in 432 bytes} [Wed Apr  9 15:48:11 2014] GET /myapp/... => generated 238 bytes in 24 msecs (HTTP/1.1 404) 2 headers in 72 bytes (1 switches on core 6)</div>

</div><div><br></div><div>## FWIW, I decided to do another test to see if new threads are spawned before the function returns</div><div><br></div><div><div>import os, threading</div><div>pid = os.getpid()</div><div>print "loading stage 1", pid, threading.active_count()</div>

<div>application = myapp.create_app(CONFIG_FILE, None, log, strict=True)</div><div>print "loading stage 2", pid, threading.active_count()</div><div><br></div><div>application.logger.setLevel(logging.DEBUG)</div>

<div>for handler in log.logger().handlers:</div><div>    application.logger.addHandler(handler)</div><div>print "loading stage 3", pid, threading.active_count()</div></div><div><br></div><div><br></div><div>and get</div>

<div><br></div><div><br></div><div><div>Respawned uWSGI worker 1 (new pid: 23145)</div><div>worker 2 killed successfully (pid: 22771)</div><div>Respawned uWSGI worker 2 (new pid: 23146)</div><div>loading stage 1 23146 1</div>

<div>loading stage 1 23145 1</div><div>loading stage 2 23145 1</div><div>loading stage 3 23145 1</div><div>WSGI app 0 (mountpoint='') ready in 1 seconds on interpreter 0x2340480 pid: 23145 (default app)</div><div>

loading stage 2 23146 1</div><div>loading stage 3 23146 1</div><div>WSGI app 0 (mountpoint='') ready in 1 seconds on interpreter 0x2340480 pid: 23146 (default app)</div><div>[pid: 23146|app: 0|req: 31/2387] 192.168.100.11 () {32 vars in 432 bytes} [Wed Apr  9 15:52:38 2014] GET /myapp/... => generated 238 bytes in 26 msecs (HTTP/1.1 404) 2 headers in 72 bytes (1 switches on core 28)</div>

</div><div><br></div><div><br></div><div>so, could it be that it's not uwsgi's fault after all? As mentioned initially, the flask-guys sent me to this mailing list, because they said it's not flask's fault. But, from all my debug-logs, it seems like the first thread does the set-up and at the point where all the blueprints have been set up, there is still only one thread.... but of course I have no idea of the uwsgi internals (and neither the flask ones) ;)</div>

<div><br></div><div>-Clemens</div><div><br></div><div><br></div><div><br></div><div><br></div><div><br></div></div><div class="gmail_extra"><br><br><div class="gmail_quote">On Wed, Apr 9, 2014 at 2:40 AM, Roberto De Ioris <span dir="ltr"><<a href="mailto:roberto@unbit.it" target="_blank">roberto@unbit.it</a>></span> wrote:<br>

<blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div class="HOEnZb"><div class="h5"><br>
> I modified the code as follows:<br>
><br>
> [...]<br>
> print "loading stage 1"<br>
> application = myapp.create_app(CONFIG_FILE, None, log, strict=True)<br>
> print "loading stage 2"<br>
> application.logger.setLevel(logging.DEBUG)<br>
> for handler in log.logger().handlers:<br>
>     application.logger.addHandler(handler)<br>
> print "loading stage 3"<br>
><br>
> and get the following logs<br>
><br>
> /usr/bin/uwsgi --ini /etc/uwsgi/apps-enabled/myapp.ini 2>&1 | grep -v<br>
> HTTP.....200<br>
> [uWSGI] getting INI configuration from /etc/uwsgi/apps-enabled/myapp.ini<br>
> *** Starting uWSGI 2.0.3 (64bit) on [Tue Apr  8 18:16:20 2014] ***<br>
> compiled with version: 4.6.3 on 08 April 2014 02:43:31<br>
> os: Linux-3.2.0-60-generic #91-Ubuntu SMP Wed Feb 19 03:54:44 UTC 2014<br>
> nodename: mynode<br>
> machine: x86_64<br>
> clock source: unix<br>
> detected number of CPU cores: 8<br>
> current working directory: /var/log<br>
> detected binary path: /usr/local/bin/uwsgi<br>
> !!! no internal routing support, rebuild with pcre support !!!<br>
> setgid() to 1010<br>
> setuid() to 1002<br>
> your processes number limit is 128020<br>
> your memory page size is 4096 bytes<br>
> detected max file descriptor number: 1024<br>
> lock engine: pthread robust mutexes<br>
> thunder lock: disabled (you can enable it with --thunder-lock)<br>
> uwsgi socket 0 bound to TCP address <a href="http://127.0.0.1:4003" target="_blank">127.0.0.1:4003</a> fd 3<br>
> Python version: 2.7.3 (default, Feb 27 2014, 20:09:21)  [GCC 4.6.3]<br>
> Python main interpreter initialized at 0x1d5d480<br>
> python threads support enabled<br>
> your server socket listen backlog is limited to 100 connections<br>
> your mercy for graceful operations on workers is 60 seconds<br>
> mapped 2503992 bytes (2445 KB) for 150 cores<br>
> *** Operational MODE: preforking+threaded ***<br>
> *** uWSGI is running in multiple interpreter mode ***<br>
> spawned uWSGI master process (pid: 19627)<br>
> spawned uWSGI worker 1 (pid: 19629, cores: 75)<br>
> spawned uWSGI worker 2 (pid: 19630, cores: 75)<br>
> loading stage 1<br>
> loading stage 1<br>
> loading stage 2<br>
> loading stage 2<br>
> loading stage 3<br>
> loading stage 3<br>
><br>
> [...]<br>
><br>
> worker 2 killed successfully (pid: 22063)<br>
> Respawned uWSGI worker 2 (new pid: 22494)<br>
> worker 1 killed successfully (pid: 22064)<br>
> Respawned uWSGI worker 1 (new pid: 22495)<br>
> loading stage 1<br>
> loading stage 1<br>
> loading stage 2<br>
> loading stage 3<br>
> loading stage 2<br>
> WSGI app 0 (mountpoint='') ready in 0 seconds on interpreter 0x1d5d480<br>
> pid:<br>
> 22494 (default app)<br>
> loading stage 3<br>
> WSGI app 0 (mountpoint='') ready in 0 seconds on interpreter 0x1d5d480<br>
> pid:<br>
> 22495 (default app)<br>
><br>
> [...]<br>
><br>
> ...The work of process 22494 is done. Seeya!<br>
> ...The work of process 22495 is done. Seeya!<br>
> worker 2 killed successfully (pid: 22494)<br>
> Respawned uWSGI worker 2 (new pid: 22685)<br>
> worker 1 killed successfully (pid: 22495)<br>
> Respawned uWSGI worker 1 (new pid: 22686)<br>
> loading stage 1<br>
> loading stage 1<br>
> loading stage 2<br>
> loading stage 2<br>
> loading stage 3<br>
> WSGI app 0 (mountpoint='') ready in 0 seconds on interpreter 0x1d5d480<br>
> pid:<br>
> 22686 (default app)<br>
> loading stage 3<br>
> WSGI app 0 (mountpoint='') ready in 0 seconds on interpreter 0x1d5d480<br>
> pid:<br>
> 22685 (default app)<br>
> [pid: 22685|app: 0|req: 3/4660] 192.168.100.11 () {32 vars in 432 bytes}<br>
> [Tue Apr  8 18:18:07 2014] GET /myapp/... => generated 238 bytes in 6<br>
> msecs<br>
> (HTTP/1.1 404) 2 headers in 72 bytes (1 switches on core 0)<br>
> [pid: 22686|app: 0|req: 16/4665] 192.168.100.11 () {32 vars in 432 bytes}<br>
> [Tue Apr  8 18:18:07 2014] GET /myapp/... => generated 238 bytes in 26<br>
> msecs (HTTP/1.1 404) 2 headers in 72 bytes (1 switches on core 5)<br>
> [pid: 22686|app: 0|req: 54/4677] 192.168.100.11 () {32 vars in 432 bytes}<br>
> [Tue Apr  8 18:18:07 2014] GET /myapp/... => generated 238 bytes in 56<br>
> msecs (HTTP/1.1 404) 2 headers in 72 bytes (1 switches on core 7)<br>
> [pid: 22686|app: 0|req: 54/4678] 192.168.100.11 () {32 vars in 432 bytes}<br>
> [Tue Apr  8 18:18:07 2014] GET /myapp/... => generated 238 bytes in 58<br>
> msecs (HTTP/1.1 404) 2 headers in 72 bytes (1 switches on core 1)<br>
><br>
> after this, the logs are empty again - that is, no more 404s for a while<br>
> (note that I grep out the HTTP-200s before and after)<br>
><br>
> thanks!<br>
> -Clemens<br>
><br>
><br>
<br>
</div></div>can you repeat the test printing the process pid (os.getpid()) at each<br>
line ? in this way we can see if all the stages are executed before the<br>
"readyness" announce<br>
<br>
Thanks<br>
<div class="HOEnZb"><div class="h5"><br>
--<br>
Roberto De Ioris<br>
<a href="http://unbit.it" target="_blank">http://unbit.it</a><br>
_______________________________________________<br>
uWSGI mailing list<br>
<a href="mailto:uWSGI@lists.unbit.it">uWSGI@lists.unbit.it</a><br>
<a href="http://lists.unbit.it/cgi-bin/mailman/listinfo/uwsgi" target="_blank">http://lists.unbit.it/cgi-bin/mailman/listinfo/uwsgi</a><br>
</div></div></blockquote></div><br><br clear="all"><div><br></div>-- <br><div dir="ltr"><div>Clemens Kolbitsch</div><div>Security Researcher</div><div><a href="mailto:kolbitsch@lastline.com" target="_blank">kolbitsch@lastline.com</a></div>

<div>Mobile +1 (206) 356-7745</div><div>Land +1 (805) 456-7076<br></div><div><br></div><div>Lastline, Inc.</div><div>6950 Hollister Avenue, Suite 101</div><div>Goleta, CA 93117</div><div><br></div><div><a href="http://www.lastline.com" target="_blank">www.lastline.com</a></div>

</div>
</div>