[isf-wifidog] token that wasn't TOKEN_UNUSED
Steven Kurylo
steven.kurylo+wifidog at aviawest.com
Jeu 22 Avr 16:21:53 EDT 2010
Hi,
I've just upgraded to the lastest SVN and I can reproduce 100% "Tried to
login with a token that wasn't TOKEN_UNUSED" when a user logs in, which
then sends them to the denied message:
http://192.168.0.1:80/wifidog/gw_message.php?message=denied
After the user first sees the denied message, user is then in limbo.
All future requests are sent to the login page and all login attempts
are denied by the gateway. The login page does say I'm logged in on the
left hand side, but even if I log out, trying to log back in gets the
denied message.
On the weekends we peak at about 50 users, and we'll have 1 or 2
complaints with this issue. We're using radius, and do allow a user to
be logged in more than once.
To reproduce:
1. Boot Knoppix
2. Associate to wifi and receive DHCP lease
3. Open firefox with a saved session which has two tabs from google.com
4. Both tabs get redirected to login page
5. Log in with the first tab - everything works
6. Log in with the second tab - denied message and now you're in limbo.
Is anyone else seeing this?
Thank you.
--
[7][Wed Apr 21 11:00:43 2010][8153](centralserver.c:308) Level 1:
Resolving auth server [192.168.0.3] succeeded = [192.168.0.3]
[7][Wed Apr 21 11:00:43 2010][8153](centralserver.c:333) Level 1:
Connecting to auth server 192.168.0.3:80
[7][Wed Apr 21 11:00:43 2010][8153](centralserver.c:359) Level 1:
Successfully connected to auth server 192.168.0.3:80
[7][Wed Apr 21 11:00:43 2010][8153](centralserver.c:190) Unlocking config
[7][Wed Apr 21 11:00:43 2010][8153](centralserver.c:190) Config unlocked
[7][Wed Apr 21 11:00:43 2010][8153](centralserver.c:197) Connected to
auth server
[7][Wed Apr 21 11:00:43 2010][8153](centralserver.c:114) Sending HTTP
request to auth server: [GET
/wifidog/auth/?stage=login&ip=192.168.0.36&mac=00:0C:29:09:8D:B9&tok
User-Agent: WiFiDog 20090925
Host: 192.168.0.3
]
[7][Wed Apr 21 11:00:43 2010][8153](centralserver.c:117) Reading response
[7][Wed Apr 21 11:00:43 2010][8153](centralserver.c:144) Read 338 bytes,
total now 338
[7][Wed Apr 21 11:00:43 2010][8153](centralserver.c:164) HTTP Response
from Server: [HTTP/1.1 200 OK
Date: Wed, 21 Apr 2010 18:00:43 GMT
Server: Apache
X-Powered-By: PHP/5.2.4-2ubuntu5.6
Content-Length: 165
Connection: close
Content-Type: text/html
<br />
<b>Notice</b>: Undefined index: token in
<b>/var/www/wifidog/classes/Authenticators/AuthenticatorRadius.php</b>
on line <b>331</b><br />
Auth: 1
Messages:
]
[6][Wed Apr 21 11:00:43 2010][8153](centralserver.c:168) Auth server
returned authentication code 1
[7][Wed Apr 21 11:00:43 2010][8153](auth.c:126) Locking client list
[7][Wed Apr 21 11:00:43 2010][8153](auth.c:126) Client list locked
[6][Wed Apr 21 11:00:43 2010][8153](auth.c:184) Got ALLOWED from central
server authenticating token 5b2705f657cc0c3aafd7924884f037e2 from
192.168.0.36 at 00:0C:29:09:
[7][Wed Apr 21 11:00:43 2010][8153](firewall.c:94) Allowing 192.168.0.36
00:0C:29:09:8D:B9 with fw_connection_state 2
[7][Wed Apr 21 11:00:43 2010][8153](fw_iptables.c:111) Executing
command: iptables -t mangle -A WiFiDog_eth1_Outgoing -s 192.168.0.36 -m
mac --mac-source 00:0C:29:09:8
[7][Wed Apr 21 11:00:43 2010][8153](gateway.c:259) Handler for SIGCHLD
called. Trying to reap a child
[7][Wed Apr 21 11:00:43 2010][8153](gateway.c:263) Handler for SIGCHLD
reaped child PID 8394
[7][Wed Apr 21 11:00:43 2010][8153](util.c:122) Waiting for PID 8394 to exit
[7][Wed Apr 21 11:00:43 2010][8153](util.c:124) Process PID -1 exited
[7][Wed Apr 21 11:00:43 2010][8153](fw_iptables.c:111) Executing
command: iptables -t mangle -A WiFiDog_eth1_Incoming -d 192.168.0.36 -j
ACCEPT
[7][Wed Apr 21 11:00:43 2010][8153](util.c:122) Waiting for PID 8397 to exit
[7][Wed Apr 21 11:00:43 2010][8153](gateway.c:259) Handler for SIGCHLD
called. Trying to reap a child
[7][Wed Apr 21 11:00:43 2010][8153](gateway.c:263) Handler for SIGCHLD
reaped child PID -1
[7][Wed Apr 21 11:00:43 2010][8153](util.c:124) Process PID 8397 exited
[7][Wed Apr 21 11:00:43 2010][8153](http.c:208) Redirecting client
browser to http://192.168.0.3:80/wifidog/portal/?gw_id=PRK
[7][Wed Apr 21 11:00:43 2010][8153](auth.c:215) Unlocking client list
[7][Wed Apr 21 11:00:43 2010][8153](auth.c:215) Client list unlocked
[7][Wed Apr 21 11:00:43 2010][8153](httpd_thread.c:68) Returned from
httpdProcessRequest() for 192.168.0.36
[7][Wed Apr 21 11:00:43 2010][8153](httpd_thread.c:73) Closing
connection with 192.168.0.36
[6][Wed Apr 21 11:00:58 2010][8153](gateway.c:474) Received connection
from 192.168.0.36, spawning worker thread
[7][Wed Apr 21 11:00:58 2010][8153](httpd_thread.c:65) Processing
request from 192.168.0.36
[7][Wed Apr 21 11:00:58 2010][8153](httpd_thread.c:66) Calling
httpdProcessRequest() for 192.168.0.36
[7][Wed Apr 21 11:00:58 2010][8153](http.c:247) Locking client list
[7][Wed Apr 21 11:00:58 2010][8153](http.c:247) Client list locked
[7][Wed Apr 21 11:00:58 2010][8153](http.c:285) Client for 192.168.0.36
is already in the client list
[7][Wed Apr 21 11:00:58 2010][8153](http.c:287) Unlocking client list
[7][Wed Apr 21 11:00:58 2010][8153](http.c:287) Client list unlocked
[7][Wed Apr 21 11:00:58 2010][8153](auth.c:104) Locking client list
[7][Wed Apr 21 11:00:58 2010][8153](auth.c:104) Client list locked
[7][Wed Apr 21 11:00:58 2010][8153](auth.c:117) Unlocking client list
[7][Wed Apr 21 11:00:58 2010][8153](auth.c:117) Client list unlocked
[7][Wed Apr 21 11:00:58 2010][8153](centralserver.c:188) Locking config
[7][Wed Apr 21 11:00:58 2010][8153](centralserver.c:188) Config locked
[7][Wed Apr 21 11:00:58 2010][8153](centralserver.c:232) Level 1:
Calculated 1 auth servers in list
[7][Wed Apr 21 11:00:58 2010][8153](centralserver.c:248) Level 1:
Resolving auth server [192.168.0.3]
[7][Wed Apr 21 11:00:58 2010][8153](util.c:139) Locking wd_gethostbyname()
[7][Wed Apr 21 11:00:58 2010][8153](util.c:139) wd_gethostbyname() locked
[7][Wed Apr 21 11:00:58 2010][8153](util.c:154) Unlocking wd_gethostbyname()
[7][Wed Apr 21 11:00:58 2010][8153](util.c:154) wd_gethostbyname() unlocked
[7][Wed Apr 21 11:00:58 2010][8153](centralserver.c:308) Level 1:
Resolving auth server [192.168.0.3] succeeded = [192.168.0.3]
[7][Wed Apr 21 11:00:58 2010][8153](centralserver.c:333) Level 1:
Connecting to auth server 192.168.0.3:80
[7][Wed Apr 21 11:00:58 2010][8153](centralserver.c:359) Level 1:
Successfully connected to auth server 192.168.0.3:80
[7][Wed Apr 21 11:00:58 2010][8153](centralserver.c:190) Unlocking config
[7][Wed Apr 21 11:00:58 2010][8153](centralserver.c:190) Config unlocked
[7][Wed Apr 21 11:00:58 2010][8153](centralserver.c:197) Connected to
auth server
[7][Wed Apr 21 11:00:58 2010][8153](centralserver.c:114) Sending HTTP
request to auth server: [GET
/wifidog/auth/?stage=login&ip=192.168.0.36&mac=00:0C:29:09:8D:B9&tok
User-Agent: WiFiDog 20090925
Host: 192.168.0.3
]
[7][Wed Apr 21 11:00:58 2010][8153](centralserver.c:117) Reading response
[7][Wed Apr 21 11:00:58 2010][8153](centralserver.c:144) Read 362 bytes,
total now 362
[7][Wed Apr 21 11:00:58 2010][8153](centralserver.c:164) HTTP Response
from Server: [HTTP/1.1 200 OK
Date: Wed, 21 Apr 2010 18:00:58 GMT
Server: Apache
X-Powered-By: PHP/5.2.4-2ubuntu5.6
Content-Length: 189
Connection: close
Content-Type: text/html
<br />
<b>Notice</b>: Undefined index: gw_id in
<b>/var/www/wifidog/auth/index.php</b> on line <b>106</b><br />
Auth: 0
Messages: | Tried to login with a token that wasn't TOKEN_UNUSED.
]
[6][Wed Apr 21 11:00:58 2010][8153](centralserver.c:168) Auth server
returned authentication code 0
[7][Wed Apr 21 11:00:58 2010][8153](auth.c:126) Locking client list
[7][Wed Apr 21 11:00:58 2010][8153](auth.c:126) Client list locked
[6][Wed Apr 21 11:00:58 2010][8153](auth.c:156) Got DENIED from central
server authenticating token 5b2705f657cc0c3aafd7924884f037e2 from
192.168.0.36 at 00:0C:29:09:8
[7][Wed Apr 21 11:00:58 2010][8153](firewall.c:109) Denying 192.168.0.36
00:0C:29:09:8D:B9 with fw_connection_state 2
[7][Wed Apr 21 11:00:58 2010][8153](fw_iptables.c:111) Executing
command: iptables -t mangle -D WiFiDog_eth1_Outgoing -s 192.168.0.36 -m
mac --mac-source 00:0C:29:09:8
[7][Wed Apr 21 11:00:58 2010][8153](gateway.c:259) Handler for SIGCHLD
called. Trying to reap a child
[7][Wed Apr 21 11:00:58 2010][8153](gateway.c:263) Handler for SIGCHLD
reaped child PID 8401
[7][Wed Apr 21 11:00:58 2010][8153](util.c:122) Waiting for PID 8401 to exit
[7][Wed Apr 21 11:00:58 2010][8153](util.c:124) Process PID -1 exited
[7][Wed Apr 21 11:00:58 2010][8153](fw_iptables.c:111) Executing
command: iptables -t mangle -D WiFiDog_eth1_Incoming -d 192.168.0.36 -j
ACCEPT
[7][Wed Apr 21 11:00:58 2010][8153](util.c:122) Waiting for PID 8404 to exit
[7][Wed Apr 21 11:00:58 2010][8153](gateway.c:259) Handler for SIGCHLD
called. Trying to reap a child
[7][Wed Apr 21 11:00:58 2010][8153](gateway.c:263) Handler for SIGCHLD
reaped child PID -1
[7][Wed Apr 21 11:00:58 2010][8153](util.c:124) Process PID 8404 exited
[7][Wed Apr 21 11:00:58 2010][8153](http.c:208) Redirecting client
browser to http://192.168.0.3:80/wifidog/gw_message.php?message=denied
[7][Wed Apr 21 11:00:58 2010][8153](auth.c:215) Unlocking client list
[7][Wed Apr 21 11:00:58 2010][8153](auth.c:215) Client list unlocked
[7][Wed Apr 21 11:00:58 2010][8153](httpd_thread.c:68) Returned from
httpdProcessRequest() for 192.168.0.36
[7][Wed Apr 21 11:00:58 2010][8153](httpd_thread.c:73) Closing
connection with 192.168.0.36
Plus d'informations sur la liste de diffusion WiFiDog