1.9 FastRouter issues

[prymitive]

moving from mailing list and jabber so history is in one place, 1.9 FastRouter produces this errors in log:

[uwsgi-fastrouter client_addr: 0.0.0.0 client_port: 0] fr_recv_uwsgi_header(): Bad address [plugins/fastrouter/fastrouter.c line 231]

it's random and it's rare.

With this debug patch:

diff --git a/plugins/fastrouter/fastrouter.c b/plugins/fastrouter/fastrouter.c
index 1f105f4..be4ff08 100644
--- a/plugins/fastrouter/fastrouter.c
+++ b/plugins/fastrouter/fastrouter.c
@@ -225,6 +225,9 @@ static ssize_t fr_recv_uwsgi_vars(struct corerouter_peer *main_peer) {

 // called soon after accept()
 static ssize_t fr_recv_uwsgi_header(struct corerouter_peer *main_peer) {
+       if (4 - (int) main_peer->in->pos < 0) {
+               uwsgi_log("BUG pos is %llu, len is %llu\n", (unsigned long long) main_peer->in->pos, (unsigned long long) main_peer->in->len);
+       }                                                                                                                                                                                                          
        ssize_t len = cr_read_exact(main_peer, 4, "fr_recv_uwsgi_header()");                                                                                                                                       
        if (!len) return 0;

I'm getting:

Mar 6 17:05:35 a115 uwsgi: BUG pos is 4193, len is 4193
Mar 6 17:05:45 a115 uwsgi: BUG pos is 4193, len is 4193
Mar 6 17:06:28 a115 uwsgi: BUG pos is 4566, len is 4566
Mar 6 17:06:44 a115 uwsgi: BUG pos is 4586, len is 4586
Mar 6 17:06:50 a115 uwsgi: BUG pos is 4585, len is 4585
Mar 6 17:07:32 a115 uwsgi: BUG pos is 4472, len is 4472
Mar 6 17:10:35 a115 uwsgi: BUG pos is 4193, len is 4193
Mar 6 17:10:45 a115 uwsgi: BUG pos is 4193, len is 4193
Mar 6 17:12:32 a115 uwsgi: BUG pos is 4472, len is 4472
Mar 6 17:56:51 a115 uwsgi: BUG pos is 5236, len is 5236
Mar 6 17:57:50 a115 uwsgi: BUG pos is 5717, len is 5717
Mar 6 17:58:15 a115 uwsgi: BUG pos is 5765, len is 5765
Mar 6 18:03:20 a115 uwsgi: BUG pos is 5981, len is 5981

[unbit]

still beating my head on that :( i was not able to reproduce it, but i have the feeling that it is a very stupid bug (but well hidden)

[prymitive]

It's defiantly rare, I only get 10-100 errors per day and FastRouter is handling few million requests.
If you want to get more debug info, than I'm happy to provide it, I just need to know what data to collect.

[unbit]

I think it should be fixed. Basically if you get EAGAIN after the first 4 bytes of the uwsgi header the corerouter was calling the header parser again as the hook was not reset. It was a very rare case as it is pretty uncommon to receive only a 4 byte segment from the network stack.

[prymitive]

great, I'll do some testing today to verify it's fixed