[isf-wifidog] Successful auth - but re-locks - continued.

listserv.traffic at sloop.net listserv.traffic at sloop.net
Mar 31 Oct 15:10:19 EST 2006


Sorry, Benoit to keep sucking up your time and energy... :(

Ok, I did a full reinstall using version 1120 of the auth engine.

I actually pull it down to a Windows client, and then copy the
.svn, doc, sql and wifidog directories into the root of the web-server
- in this case /var/www/html (Again, just wanting to make sure I'm not
doing something wrong.)

I also dropped and re-created the wifidog DB.

I then run the install.php as normal.

---
As long as I'm at it, let me describe the full config - perhaps that
has bearing.

OpenWRT White Russian RC5, with the backport WiFiDog Gateway
wifidog_1.1.3_beta2-1_mipsel.ipk  - all on a WRT-54GL.

The Auth-server is NOT the the gateway to the internet. The WRT-54GL
IS.

ASCII Map of network, in case it matters...
---
Internet  -- (Some world routable IP) WRT-54GL (192.168.1.254)
                                         |
                                      (Ethernet Switch)
                                         |
                                      WifiDog Auth Server (192.168.1.253)

---
If one turns bridging on (on the WRT-54GL) the Internet is accessible. DNS works
etc.

---
OS for Auth Server: FC5 - using standard packaged PHP/HTTPD/etc yum installs.

---
Here's a level 6 log of the same behavior as before.

---
[6][Sat Jan  1 00:16:47 2000][1850](conf.c:575) Reading configuration file '/etc/wifidog.conf'
[6][Sat Jan  1 00:16:47 2000][1850](gateway.c:370) Setting started_time
[5][Sat Jan  1 00:16:47 2000][1850](gateway.c:399) Creating web server on 192.168.1.254:2060
[6][Sat Jan  1 00:16:47 2000][1850](firewall.c:208) Removing Firewall rules
[6][Sat Jan  1 00:16:49 2000][1850](firewall.c:151) Creating ICMP socket
[6][Sat Jan  1 00:16:49 2000][1850](firewall.c:161) Initializing Firewall
iptables: Chain already exists
[5][Sat Jan  1 00:16:51 2000][1850](gateway.c:443) Waiting for connections
[6][Sat Jan  1 00:16:51 2000][2010](util.c:228) ONLINE status became ON
[6][Sat Jan  1 00:16:51 2000][2010](firewall.c:183) Clearing the authservers list
[6][Sat Jan  1 00:16:51 2000][2010](firewall.c:192) Setting the authservers list
[6][Sat Jan  1 00:16:51 2000][2010](util.c:270) AUTH_ONLINE status became ON
[6][Sat Jan  1 00:17:09 2000][1850](gateway.c:468) Received connection from 192.168.1.211, spawning worker thread
[6][Sat Jan  1 00:17:09 2000][2019](http.c:123) Captured 192.168.1.211 requesting [http%3A//www.sloop.net/] and re-directed them to login page
[6][Sat Jan  1 00:17:18 2000][1850](gateway.c:468) Received connection from 192.168.1.211, spawning worker thread
[6][Sat Jan  1 00:17:18 2000][2020](client_list.c:108) Added a new client to linked list: IP: 192.168.1.211 Token: 25b25b6a3b66774a19c8b483b78aea05
[6][Sat Jan  1 00:17:18 2000][2020](centralserver.c:149) Auth server returned authentication code 1
[6][Sat Jan  1 00:17:18 2000][2020](auth.c:209) Got ALLOWED from central server authenticating token 25b25b6a3b66774a19c8b483b78aea05 from 192.168.1.211 at 00:0D:60:89:39:E0 - adding to firewall and redirecting them to portal
[6][Sat Jan  1 00:17:51 2000][2008](centralserver.c:149) Auth server returned authentication code 0
[5][Sat Jan  1 00:17:51 2000][2008](firewall.c:280) 192.168.1.211 - Denied. Removing client and firewall rules
[6][Sat Jan  1 00:17:54 2000][1850](gateway.c:468) Received connection from 192.168.1.211, spawning worker thread
[6][Sat Jan  1 00:17:54 2000][2033](http.c:123) Captured 192.168.1.211 requesting [http%3A//www.sloop.net/] and re-directed them to login page

---
Level & debug - not including start-up and shut-down.

---
[6][Sat Jan  1 00:18:36 2000][2124](gateway.c:468) Received connection from 192.168.1.211, spawning worker thread
[7][Sat Jan  1 00:18:36 2000][2293](httpd_thread.c:65) Processing request from 192.168.1.211
[7][Sat Jan  1 00:18:36 2000][2293](httpd_thread.c:66) Calling httpdProcessRequest() for 192.168.1.211
[6][Sat Jan  1 00:18:36 2000][2293](http.c:123) Captured 192.168.1.211 requesting [http%3A//www.sloop.net/] and re-directed them to login page
[7][Sat Jan  1 00:18:36 2000][2293](httpd_thread.c:68) Returned from httpdProcessRequest() for 192.168.1.211
[7][Sat Jan  1 00:18:36 2000][2293](httpd_thread.c:73) Closing connection with 192.168.1.211
[6][Sat Jan  1 00:18:46 2000][2124](gateway.c:468) Received connection from 192.168.1.211, spawning worker thread
[7][Sat Jan  1 00:18:46 2000][2294](httpd_thread.c:65) Processing request from 192.168.1.211
[7][Sat Jan  1 00:18:46 2000][2294](httpd_thread.c:66) Calling httpdProcessRequest() for 192.168.1.211
[7][Sat Jan  1 00:18:46 2000][2294](http.c:177) Locking client list
[7][Sat Jan  1 00:18:46 2000][2294](http.c:177) Client list locked
[7][Sat Jan  1 00:18:46 2000][2294](http.c:180) New client for 192.168.1.211
[6][Sat Jan  1 00:18:46 2000][2294](client_list.c:108) Added a new client to linked list: IP: 192.168.1.211 Token: 251f120127acace533427c8cdc5e8067
[7][Sat Jan  1 00:18:46 2000][2294](http.c:186) Unlocking client list
[7][Sat Jan  1 00:18:46 2000][2294](http.c:186) Client list unlocked
[7][Sat Jan  1 00:18:46 2000][2294](auth.c:106) Locking client list
[7][Sat Jan  1 00:18:46 2000][2294](auth.c:106) Client list locked
[7][Sat Jan  1 00:18:46 2000][2294](auth.c:119) Unlocking client list
[7][Sat Jan  1 00:18:46 2000][2294](auth.c:119) Client list unlocked
[7][Sat Jan  1 00:18:46 2000][2294](centralserver.c:168) Locking config
[7][Sat Jan  1 00:18:46 2000][2294](centralserver.c:168) Config locked
[7][Sat Jan  1 00:18:46 2000][2294](centralserver.c:210) Level 1: Calculated 1 auth servers in list
[7][Sat Jan  1 00:18:46 2000][2294](centralserver.c:225) Level 1: Resolving auth server [192.168.1.253]
[7][Sat Jan  1 00:18:46 2000][2294](util.c:126) Locking wd_gethostbyname()
[7][Sat Jan  1 00:18:46 2000][2294](util.c:126) wd_gethostbyname() locked
[7][Sat Jan  1 00:18:46 2000][2294](util.c:141) Unlocking wd_gethostbyname()
[7][Sat Jan  1 00:18:46 2000][2294](util.c:141) wd_gethostbyname() unlocked
[7][Sat Jan  1 00:18:46 2000][2294](centralserver.c:279) Level 1: Resolving auth server [192.168.1.253] succeeded = [192.168.1.253]
[7][Sat Jan  1 00:18:46 2000][2294](centralserver.c:304) Level 1: Connecting to auth server 192.168.1.253:80
[7][Sat Jan  1 00:18:46 2000][2294](centralserver.c:330) Level 1: Successfully connected to auth server 192.168.1.253:80
[7][Sat Jan  1 00:18:46 2000][2294](centralserver.c:170) Unlocking config
[7][Sat Jan  1 00:18:46 2000][2294](centralserver.c:170) Config unlocked
[7][Sat Jan  1 00:18:46 2000][2294](centralserver.c:177) Connected to auth server
[7][Sat Jan  1 00:18:46 2000][2294](centralserver.c:95) Sending HTTP request to auth server: [GET /wifidog/auth/?stage=login&ip=192.168.1.211&mac=00:0D:60:89:39:E0&token=251f120127acace533427c8cdc5e8067&incoming=0&outgoing=0 HTTP/1.0
User-Agent: WiFiDog 1.1.3_beta2
Host: 192.168.1.253

]

[7][Sat Jan  1 00:18:46 2000][2294](centralserver.c:98) Reading response
[7][Sat Jan  1 00:18:46 2000][2294](centralserver.c:125) Read 210 bytes, total now 210
[7][Sat Jan  1 00:18:46 2000][2294](centralserver.c:145) HTTP Response from Server: [HTTP/1.1 200 OK
Date: Tue, 31 Oct 2006 21:45:51 GMT
Server: Apache/2.2.2 (Fedora)
X-Powered-By: PHP/5.1.4
Content-Length: 19
Connection: close
Content-Type: text/html; charset=UTF-8

Auth: 1
Messages:
]
[6][Sat Jan  1 00:18:46 2000][2294](centralserver.c:149) Auth server returned authentication code 1
[7][Sat Jan  1 00:18:46 2000][2294](auth.c:123) Locking client list
[7][Sat Jan  1 00:18:46 2000][2294](auth.c:123) Client list locked
[6][Sat Jan  1 00:18:46 2000][2294](auth.c:209) Got ALLOWED from central server authenticating token 251f120127acace533427c8cdc5e8067 from 192.168.1.211 at 00:0D:60:89:39:E0 - adding to firewall and redirecting them to portal
[7][Sat Jan  1 00:18:46 2000][2294](firewall.c:87) Allowing 192.168.1.211 00:0D:60:89:39:E0 with fw_connection_state 2
[7][Sat Jan  1 00:18:46 2000][2294](fw_iptables.c:79) Executing command: iptables -t mangle -A WiFiDog_Outgoing -s 192.168.1.211 -m mac --mac-source 00:0D:60:89:39:E0 -j MARK --set-mark 2
[7][Sat Jan  1 00:18:46 2000][2294](util.c:108) Waiting for PID 2295 to exit
[7][Sat Jan  1 00:18:46 2000][2294](gateway.c:256) Handler for SIGCHLD called. Trying to reap a child
[7][Sat Jan  1 00:18:46 2000][2294](gateway.c:260) Handler for SIGCHLD reaped child PID -1
[7][Sat Jan  1 00:18:46 2000][2294](util.c:110) Process PID 2295 exited
[7][Sat Jan  1 00:18:46 2000][2294](fw_iptables.c:79) Executing command: iptables -t mangle -A WiFiDog_Incoming -d 192.168.1.211 -j ACCEPT
[7][Sat Jan  1 00:18:46 2000][2294](util.c:108) Waiting for PID 2297 to exit
[7][Sat Jan  1 00:18:46 2000][2294](gateway.c:256) Handler for SIGCHLD called. Trying to reap a child
[7][Sat Jan  1 00:18:46 2000][2294](gateway.c:260) Handler for SIGCHLD reaped child PID -1
[7][Sat Jan  1 00:18:46 2000][2294](util.c:110) Process PID 2297 exited
[7][Sat Jan  1 00:18:46 2000][2294](auth.c:265) Unlocking client list
[7][Sat Jan  1 00:18:46 2000][2294](auth.c:265) Client list unlocked
[7][Sat Jan  1 00:18:46 2000][2294](httpd_thread.c:68) Returned from httpdProcessRequest() for 192.168.1.211
[7][Sat Jan  1 00:18:46 2000][2294](httpd_thread.c:73) Closing connection with 192.168.1.211
[7][Sat Jan  1 00:19:23 2000][2282](auth.c:83) Running fw_counter()
[7][Sat Jan  1 00:19:23 2000][2282](fw_iptables.c:480) Outgoing 192.168.1.211 Bytes=684
[7][Sat Jan  1 00:19:23 2000][2282](fw_iptables.c:481) Locking client list
[7][Sat Jan  1 00:19:23 2000][2282](fw_iptables.c:481) Client list locked
[7][Sat Jan  1 00:19:23 2000][2282](fw_iptables.c:486) 192.168.1.211 - Updated counter.outgoing to 684 bytes
[7][Sat Jan  1 00:19:23 2000][2282](fw_iptables.c:491) Unlocking client list
[7][Sat Jan  1 00:19:23 2000][2282](fw_iptables.c:491) Client list unlocked
[7][Sat Jan  1 00:19:23 2000][2282](gateway.c:256) Handler for SIGCHLD called. Trying to reap a child
[7][Sat Jan  1 00:19:23 2000][2282](gateway.c:260) Handler for SIGCHLD reaped child PID 2299
[7][Sat Jan  1 00:19:23 2000][2282](fw_iptables.c:518) Incoming 192.168.1.211 Bytes=4621
[7][Sat Jan  1 00:19:23 2000][2282](fw_iptables.c:519) Locking client list
[7][Sat Jan  1 00:19:23 2000][2282](fw_iptables.c:519) Client list locked
[7][Sat Jan  1 00:19:23 2000][2282](fw_iptables.c:523) 192.168.1.211 - Updated counter.incoming to 4621 bytes
[7][Sat Jan  1 00:19:23 2000][2282](fw_iptables.c:528) Unlocking client list
[7][Sat Jan  1 00:19:23 2000][2282](fw_iptables.c:528) Client list unlocked
[7][Sat Jan  1 00:19:23 2000][2282](gateway.c:256) Handler for SIGCHLD called. Trying to reap a child
[7][Sat Jan  1 00:19:23 2000][2282](gateway.c:260) Handler for SIGCHLD reaped child PID 2301
[7][Sat Jan  1 00:19:23 2000][2282](firewall.c:229) Locking client list
[7][Sat Jan  1 00:19:23 2000][2282](firewall.c:229) Client list locked
[7][Sat Jan  1 00:19:23 2000][2282](firewall.c:240) Unlocking client list
[7][Sat Jan  1 00:19:23 2000][2282](firewall.c:240) Client list unlocked
[7][Sat Jan  1 00:19:23 2000][2282](centralserver.c:168) Locking config
[7][Sat Jan  1 00:19:23 2000][2282](centralserver.c:168) Config locked
[7][Sat Jan  1 00:19:23 2000][2282](centralserver.c:210) Level 1: Calculated 1 auth servers in list
[7][Sat Jan  1 00:19:23 2000][2282](centralserver.c:225) Level 1: Resolving auth server [192.168.1.253]
[7][Sat Jan  1 00:19:23 2000][2282](util.c:126) Locking wd_gethostbyname()
[7][Sat Jan  1 00:19:23 2000][2282](util.c:126) wd_gethostbyname() locked
[7][Sat Jan  1 00:19:23 2000][2282](util.c:141) Unlocking wd_gethostbyname()
[7][Sat Jan  1 00:19:23 2000][2282](util.c:141) wd_gethostbyname() unlocked
[7][Sat Jan  1 00:19:23 2000][2282](centralserver.c:279) Level 1: Resolving auth server [192.168.1.253] succeeded = [192.168.1.253]
[7][Sat Jan  1 00:19:23 2000][2282](centralserver.c:304) Level 1: Connecting to auth server 192.168.1.253:80
[7][Sat Jan  1 00:19:23 2000][2282](centralserver.c:330) Level 1: Successfully connected to auth server 192.168.1.253:80
[7][Sat Jan  1 00:19:23 2000][2282](centralserver.c:170) Unlocking config
[7][Sat Jan  1 00:19:23 2000][2282](centralserver.c:170) Config unlocked
[7][Sat Jan  1 00:19:23 2000][2282](centralserver.c:177) Connected to auth server
[7][Sat Jan  1 00:19:23 2000][2282](centralserver.c:95) Sending HTTP request to auth server: [GET /wifidog/auth/?stage=counters&ip=192.168.1.211&mac=00:0D:60:89:39:E0&token=251f120127acace533427c8cdc5e8067&incoming=4621&outgoing=684 HTTP/1.0
User-Agent: WiFiDog 1.1.3_beta2
Host: 192.168.1.253

]

[7][Sat Jan  1 00:19:23 2000][2282](centralserver.c:98) Reading response
[7][Sat Jan  1 00:19:23 2000][2282](centralserver.c:125) Read 230 bytes, total now 230
[7][Sat Jan  1 00:19:23 2000][2282](centralserver.c:145) HTTP Response from Server: [HTTP/1.1 200 OK
Date: Tue, 31 Oct 2006 21:46:27 GMT
Server: Apache/2.2.2 (Fedora)
X-Powered-By: PHP/5.1.4
Content-Length: 39
Connection: close
Content-Type: text/html; charset=UTF-8

Auth: 0
Messages: | Updated counters.
]
[6][Sat Jan  1 00:19:23 2000][2282](centralserver.c:149) Auth server returned authentication code 0
[7][Sat Jan  1 00:19:23 2000][2282](firewall.c:247) Locking client list
[7][Sat Jan  1 00:19:23 2000][2282](firewall.c:247) Client list locked
[5][Sat Jan  1 00:19:23 2000][2282](firewall.c:280) 192.168.1.211 - Denied. Removing client and firewall rules
[7][Sat Jan  1 00:19:23 2000][2282](firewall.c:102) Denying 192.168.1.211 00:0D:60:89:39:E0 with fw_connection_state 2
[7][Sat Jan  1 00:19:23 2000][2282](fw_iptables.c:79) Executing command: iptables -t mangle -D WiFiDog_Outgoing -s 192.168.1.211 -m mac --mac-source 00:0D:60:89:39:E0 -j MARK --set-mark 2
[7][Sat Jan  1 00:19:23 2000][2282](util.c:108) Waiting for PID 2303 to exit
[7][Sat Jan  1 00:19:23 2000][2282](gateway.c:256) Handler for SIGCHLD called. Trying to reap a child
[7][Sat Jan  1 00:19:23 2000][2282](gateway.c:260) Handler for SIGCHLD reaped child PID -1
[7][Sat Jan  1 00:19:23 2000][2282](util.c:110) Process PID 2303 exited
[7][Sat Jan  1 00:19:23 2000][2282](fw_iptables.c:79) Executing command: iptables -t mangle -D WiFiDog_Incoming -d 192.168.1.211 -j ACCEPT
[7][Sat Jan  1 00:19:23 2000][2282](util.c:108) Waiting for PID 2305 to exit
[7][Sat Jan  1 00:19:23 2000][2282](gateway.c:256) Handler for SIGCHLD called. Trying to reap a child
[7][Sat Jan  1 00:19:23 2000][2282](gateway.c:260) Handler for SIGCHLD reaped child PID -1
[7][Sat Jan  1 00:19:23 2000][2282](util.c:110) Process PID 2305 exited
[7][Sat Jan  1 00:19:23 2000][2282](firewall.c:326) Unlocking client list
[7][Sat Jan  1 00:19:23 2000][2282](firewall.c:326) Client list unlocked
[7][Sat Jan  1 00:19:24 2000][2284](ping_thread.c:69) Running ping()
[7][Sat Jan  1 00:19:24 2000][2284](ping_thread.c:105) Entering ping()
[7][Sat Jan  1 00:19:24 2000][2284](centralserver.c:168) Locking config
[7][Sat Jan  1 00:19:24 2000][2284](centralserver.c:168) Config locked
[7][Sat Jan  1 00:19:24 2000][2284](centralserver.c:210) Level 1: Calculated 1 auth servers in list
[7][Sat Jan  1 00:19:24 2000][2284](centralserver.c:225) Level 1: Resolving auth server [192.168.1.253]
[7][Sat Jan  1 00:19:24 2000][2284](util.c:126) Locking wd_gethostbyname()
[7][Sat Jan  1 00:19:24 2000][2284](util.c:126) wd_gethostbyname() locked
[7][Sat Jan  1 00:19:24 2000][2284](util.c:141) Unlocking wd_gethostbyname()
[7][Sat Jan  1 00:19:24 2000][2284](util.c:141) wd_gethostbyname() unlocked
[7][Sat Jan  1 00:19:24 2000][2284](centralserver.c:279) Level 1: Resolving auth server [192.168.1.253] succeeded = [192.168.1.253]
[7][Sat Jan  1 00:19:24 2000][2284](centralserver.c:304) Level 1: Connecting to auth server 192.168.1.253:80
[7][Sat Jan  1 00:19:24 2000][2284](centralserver.c:330) Level 1: Successfully connected to auth server 192.168.1.253:80
[7][Sat Jan  1 00:19:24 2000][2284](centralserver.c:170) Unlocking config
[7][Sat Jan  1 00:19:24 2000][2284](centralserver.c:170) Config unlocked
[7][Sat Jan  1 00:19:24 2000][2284](centralserver.c:177) Connected to auth server
[7][Sat Jan  1 00:19:24 2000][2284](ping_thread.c:156) HTTP Request to Server: [GET /wifidog/ping/?gw_id=default&sys_uptime=1164&sys_memfree=5256&sys_load=0.09&wifidog_uptime=65 HTTP/1.0
User-Agent: WiFiDog 1.1.3_beta2
Host: 192.168.1.253

]
[7][Sat Jan  1 00:19:24 2000][2284](ping_thread.c:160) Reading response
[7][Sat Jan  1 00:19:24 2000][2284](ping_thread.c:188) Read 194 bytes, total now 194
[7][Sat Jan  1 00:19:24 2000][2284](ping_thread.c:206) Done reading reply, total 194 bytes
[7][Sat Jan  1 00:19:24 2000][2284](ping_thread.c:210) HTTP Response from Server: [HTTP/1.1 200 OK
Date: Tue, 31 Oct 2006 21:46:28 GMT
Server: Apache/2.2.2 (Fedora)
X-Powered-By: PHP/5.1.4
Content-Length: 4
Connection: close
Content-Type: text/html; charset=UTF-8

Pong]
[7][Sat Jan  1 00:19:24 2000][2284](ping_thread.c:217) Auth Server Says: Pong
[6][Sat Jan  1 00:19:31 2000][2124](gateway.c:468) Received connection from 192.168.1.211, spawning worker thread
[7][Sat Jan  1 00:19:31 2000][2307](httpd_thread.c:65) Processing request from 192.168.1.211
[7][Sat Jan  1 00:19:31 2000][2307](httpd_thread.c:66) Calling httpdProcessRequest() for 192.168.1.211
[6][Sat Jan  1 00:19:31 2000][2307](http.c:123) Captured 192.168.1.211 requesting [http%3A//www.sloop.net/] and re-directed them to login page
[7][Sat Jan  1 00:19:31 2000][2307](httpd_thread.c:68) Returned from httpdProcessRequest() for 192.168.1.211
[7][Sat Jan  1 00:19:31 2000][2307](httpd_thread.c:73) Closing connection with 192.168.1.211

---
TIA

-Greg



Plus d'informations sur la liste de diffusion WiFiDog