<div dir="ltr"><div class="gmail_quote"><div dir="ltr">Hello everyone, I was observing my debug mode on server and I notice, when I am logging out a user the radius server make the same 3 times! It is normal behavior ??? I have configure my FreeRadius to work with MySQL.<div><br></div><div>Here is my log:<div><div>Ready to process requests</div><div>Received Accounting-Request Id 198 from <a href="http://192.168.40.101:58545" target="_blank">192.168.40.101:58545</a> to <a href="http://192.168.40.12:1813" target="_blank">192.168.40.12:1813</a> length 194</div><div><span style="white-space:pre-wrap">       </span>Acct-Status-Type = Stop</div><div><span style="white-space:pre-wrap">  </span>Acct-Terminate-Cause = User-Request</div><div><span style="white-space:pre-wrap">      </span>NAS-Port-Type = Wireless-802.11</div><div><span style="white-space:pre-wrap">  </span>Calling-Station-Id = '30:39:26:86:CC:EA'</div><div><span style="white-space:pre-wrap"> </span>Called-Station-Id = 'hotspot1'</div><div><span style="white-space:pre-wrap">   </span>NAS-Port-Id = 'citystore_test'</div><div><span style="white-space:pre-wrap">   </span>User-Name = 'user1'</div><div><span style="white-space:pre-wrap">      </span>NAS-Port = 2151678022</div><div><span style="white-space:pre-wrap">    </span>Acct-Session-Id = '80400046'</div><div><span style="white-space:pre-wrap">     </span>Framed-IP-Address = 10.5.50.254</div><div><span style="white-space:pre-wrap">  </span>Mikrotik-Host-IP = 10.5.50.254</div><div><span style="white-space:pre-wrap">   </span>Event-Timestamp = 'Sep 24 2014 14:28:16 EEST'</div><div><span style="white-space:pre-wrap">    </span>Acct-Input-Octets = 2197666</div><div><span style="white-space:pre-wrap">      </span>Acct-Output-Octets = 18331654</div><div><span style="white-space:pre-wrap">    </span>Acct-Input-Gigawords = 0</div><div><span style="white-space:pre-wrap"> </span>Acct-Output-Gigawords = 0</div><div><span style="white-space:pre-wrap">        </span>Acct-Input-Packets = 16603</div><div><span style="white-space:pre-wrap">       </span>Acct-Output-Packets = 16236</div><div><span style="white-space:pre-wrap">      </span>Acct-Session-Time = 1448</div><div><span style="white-space:pre-wrap"> </span>NAS-Identifier = 'MikroTik'</div><div><span style="white-space:pre-wrap">      </span>Acct-Delay-Time = 0</div><div><span style="white-space:pre-wrap">      </span>NAS-IP-Address = 192.168.40.101</div><div>(5) Received Accounting-Request packet from host 192.168.40.101 port 58545, id=198, length=194</div><div>(5) <span style="white-space:pre-wrap"> </span>Acct-Status-Type = Stop</div><div>(5) <span style="white-space:pre-wrap">      </span>Acct-Terminate-Cause = User-Request</div><div>(5) <span style="white-space:pre-wrap">  </span>NAS-Port-Type = Wireless-802.11</div><div>(5) <span style="white-space:pre-wrap">      </span>Calling-Station-Id = '30:39:26:86:CC:EA'</div><div>(5) <span style="white-space:pre-wrap">     </span>Called-Station-Id = 'hotspot1'</div><div>(5) <span style="white-space:pre-wrap">       </span>NAS-Port-Id = 'citystore_test'</div><div>(5) <span style="white-space:pre-wrap">       </span>User-Name = 'user1'</div><div>(5) <span style="white-space:pre-wrap">  </span>NAS-Port = 2151678022</div><div>(5) <span style="white-space:pre-wrap">        </span>Acct-Session-Id = '80400046'</div><div>(5) <span style="white-space:pre-wrap"> </span>Framed-IP-Address = 10.5.50.254</div><div>(5) <span style="white-space:pre-wrap">      </span>Mikrotik-Host-IP = 10.5.50.254</div><div>(5) <span style="white-space:pre-wrap">       </span>Event-Timestamp = 'Sep 24 2014 14:28:16 EEST'</div><div>(5) <span style="white-space:pre-wrap">        </span>Acct-Input-Octets = 2197666</div><div>(5) <span style="white-space:pre-wrap">  </span>Acct-Output-Octets = 18331654</div><div>(5) <span style="white-space:pre-wrap">        </span>Acct-Input-Gigawords = 0</div><div>(5) <span style="white-space:pre-wrap">     </span>Acct-Output-Gigawords = 0</div><div>(5) <span style="white-space:pre-wrap">    </span>Acct-Input-Packets = 16603</div><div>(5) <span style="white-space:pre-wrap">   </span>Acct-Output-Packets = 16236</div><div>(5) <span style="white-space:pre-wrap">  </span>Acct-Session-Time = 1448</div><div>(5) <span style="white-space:pre-wrap">     </span>NAS-Identifier = 'MikroTik'</div><div>(5) <span style="white-space:pre-wrap">  </span>Acct-Delay-Time = 0</div><div>(5) <span style="white-space:pre-wrap">  </span>NAS-IP-Address = 192.168.40.101</div><div>(5) # Executing section preacct from file /etc/freeradius/sites-enabled/default</div><div>(5)   preacct {</div><div>(5)   [preprocess] = ok</div><div>(5)   acct_unique acct_unique {</div><div>(5)     if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) </div><div>(5) EXPAND %{string:Class}</div><div>(5)    --> </div><div>(5)     if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i)  -> FALSE</div><div>(5)    else else {</div><div>(5)     update request {</div><div>(5) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}</div><div>(5)    --> cd7c5cd7ff1adea4aeffeb8b6c859901</div><div>(5) <span style="white-space:pre-wrap">      </span>Acct-Unique-Session-Id := "cd7c5cd7ff1adea4aeffeb8b6c859901"</div><div>(5)     } # update request = noop</div><div>(5)    } # else else = noop</div><div>(5)   } # acct_unique acct_unique = noop</div><div>(5)  suffix : Checking for suffix after "@"</div><div>(5)  suffix : No '@' in User-Name = "user1", looking up realm NULL</div><div>(5)  suffix : No such realm "NULL"</div><div>(5)   [suffix] = noop</div><div>(5)   [files] = noop</div><div>(5)  } #  preacct = ok</div><div>(5) # Executing section accounting from file /etc/freeradius/sites-enabled/default</div><div>(5)   accounting {</div><div>(5)  detail : EXPAND /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d</div><div>(5)  detail :    --> /var/log/freeradius/radacct/<a href="http://192.168.40.101/detail-20140925" target="_blank">192.168.40.101/detail-20140925</a></div><div>(5)  detail : /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/freeradius/radacct/<a href="http://192.168.40.101/detail-20140925" target="_blank">192.168.40.101/detail-20140925</a></div><div>(5)  detail : EXPAND %t</div><div>(5)  detail :    --> Thu Sep 25 14:24:47 2014</div><div>(5)   [detail] = ok</div><div>(5)   [unix] = ok</div><div>(5)  radutmp : EXPAND /var/log/freeradius/radutmp</div><div>(5)  radutmp :    --> /var/log/freeradius/radutmp</div><div>(5)  radutmp : EXPAND %{User-Name}</div><div>(5)  radutmp :    --> user1</div><div>(5)   [radutmp] = ok</div><div>(5)  sql : EXPAND %{tolower:type.%{Acct-Status-Type}.query}</div><div>(5)  sql :    --> type.stop.query</div><div>(5)  sql : Using query template 'query'</div><div>rlm_sql (sql): Reserved connection (6)</div><div>(5)  sql : EXPAND %{User-Name}</div><div>(5)  sql :    --> user1</div><div>(5)  sql : SQL-User-Name set to 'user1'</div><div>(5)  sql : EXPAND UPDATE radacct SET acctstoptime<span style="white-space:pre-wrap">    </span>= FROM_UNIXTIME(%{integer:Event-Timestamp}), acctsessiontime<span style="white-space:pre-wrap">    </span>= '%{Acct-Session-Time}', acctinputoctets<span style="white-space:pre-wrap">       </span>= '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', acctterminatecause = '%{Acct-Terminate-Cause}', connectinfo_stop = '%{Connect-Info}' WHERE acctsessionid <span style="white-space:pre-wrap">        </span>= '%{Acct-Session-Id}' AND username<span style="white-space:pre-wrap">             </span>= '%{SQL-User-Name}' AND nasipaddress<span style="white-space:pre-wrap">   </span>= '%{NAS-IP-Address}'</div><div>(5)  sql :    --> UPDATE radacct SET acctstoptime<span style="white-space:pre-wrap">     </span>= FROM_UNIXTIME(1411558096), acctsessiontime<span style="white-space:pre-wrap">    </span>= '1448', acctinputoctets<span style="white-space:pre-wrap">       </span>= '0' << 32 | '2197666', acctoutputoctets = '0' << 32 | '18331654', acctterminatecause = 'User-Request', connectinfo_stop = '' WHERE acctsessionid <span style="white-space:pre-wrap"> </span>= '80400046' AND username<span style="white-space:pre-wrap">               </span>= 'user1' AND nasipaddress<span style="white-space:pre-wrap">      </span>= '192.168.40.101'</div><div>rlm_sql (sql): Executing query: 'UPDATE radacct SET acctstoptime<span style="white-space:pre-wrap">   </span>= FROM_UNIXTIME(1411558096), acctsessiontime<span style="white-space:pre-wrap">    </span>= '1448', acctinputoctets<span style="white-space:pre-wrap">       </span>= '0' << 32 | '2197666', acctoutputoctets = '0' << 32 | '18331654', acctterminatecause = 'User-Request', connectinfo_stop = '' WHERE acctsessionid <span style="white-space:pre-wrap"> </span>= '80400046' AND username<span style="white-space:pre-wrap">               </span>= 'user1' AND nasipaddress<span style="white-space:pre-wrap">      </span>= '192.168.40.101''</div><div>rlm_sql_mysql: Rows matched: 1  Changed: 1  Warnings: 0</div><div>rlm_sql (sql): Released connection (6)</div><div>rlm_sql (sql): 0 of 3 connections in use.  Need more spares</div><div>rlm_sql (sql): Opening additional connection (7)</div><div>rlm_sql_mysql: Starting connect to MySQL server</div><div>rlm_sql (sql): Closing connection (5): Hit idle_timeout, was idle for 1449 seconds</div><div>rlm_sql (sql): You probably need to lower "min"</div><div>rlm_sql_mysql: Socket destructor called, closing socket</div><div>rlm_sql (sql): Closing connection (4): Hit idle_timeout, was idle for 1467 seconds</div><div>rlm_sql (sql): You probably need to lower "min"</div><div>rlm_sql_mysql: Socket destructor called, closing socket</div><div>(5)   [sql] = ok</div><div>(5)   [exec] = noop</div><div>(5)  attr_filter.accounting_response : EXPAND %{User-Name}</div><div>(5)  attr_filter.accounting_response :    --> user1</div><div>(5)  attr_filter.accounting_response : Matched entry DEFAULT at line 12</div><div>(5)   [attr_filter.accounting_response] = updated</div><div>(5)  } #  accounting = updated</div><div>(5) Sending Accounting-Response packet to host 192.168.40.101 port 58545, id=198, length=0</div><div>Sending Accounting-Response Id 198 from <a href="http://192.168.40.12:1813" target="_blank">192.168.40.12:1813</a> to <a href="http://192.168.40.101:58545" target="_blank">192.168.40.101:58545</a></div><div>(5) Finished request</div><div>(5) Cleaning up request packet ID 198 with timestamp +1572</div><div>Received Accounting-Request Id 198 from <a href="http://192.168.40.101:58545" target="_blank">192.168.40.101:58545</a> to <a href="http://192.168.40.12:1813" target="_blank">192.168.40.12:1813</a> length 194</div><div><span style="white-space:pre-wrap">     </span>Acct-Status-Type = Stop</div><div><span style="white-space:pre-wrap">  </span>Acct-Terminate-Cause = User-Request</div><div><span style="white-space:pre-wrap">      </span>NAS-Port-Type = Wireless-802.11</div><div><span style="white-space:pre-wrap">  </span>Calling-Station-Id = '30:39:26:86:CC:EA'</div><div><span style="white-space:pre-wrap"> </span>Called-Station-Id = 'hotspot1'</div><div><span style="white-space:pre-wrap">   </span>NAS-Port-Id = 'citystore_test'</div><div><span style="white-space:pre-wrap">   </span>User-Name = 'user1'</div><div><span style="white-space:pre-wrap">      </span>NAS-Port = 2151678022</div><div><span style="white-space:pre-wrap">    </span>Acct-Session-Id = '80400046'</div><div><span style="white-space:pre-wrap">     </span>Framed-IP-Address = 10.5.50.254</div><div><span style="white-space:pre-wrap">  </span>Mikrotik-Host-IP = 10.5.50.254</div><div><span style="white-space:pre-wrap">   </span>Event-Timestamp = 'Sep 24 2014 14:28:16 EEST'</div><div><span style="white-space:pre-wrap">    </span>Acct-Input-Octets = 2197666</div><div><span style="white-space:pre-wrap">      </span>Acct-Output-Octets = 18331654</div><div><span style="white-space:pre-wrap">    </span>Acct-Input-Gigawords = 0</div><div><span style="white-space:pre-wrap"> </span>Acct-Output-Gigawords = 0</div><div><span style="white-space:pre-wrap">        </span>Acct-Input-Packets = 16603</div><div><span style="white-space:pre-wrap">       </span>Acct-Output-Packets = 16236</div><div><span style="white-space:pre-wrap">      </span>Acct-Session-Time = 1448</div><div><span style="white-space:pre-wrap"> </span>NAS-Identifier = 'MikroTik'</div><div><span style="white-space:pre-wrap">      </span>Acct-Delay-Time = 0</div><div><span style="white-space:pre-wrap">      </span>NAS-IP-Address = 192.168.40.101</div><div>(6) Received Accounting-Request packet from host 192.168.40.101 port 58545, id=198, length=194</div><div>(6) <span style="white-space:pre-wrap"> </span>Acct-Status-Type = Stop</div><div>(6) <span style="white-space:pre-wrap">      </span>Acct-Terminate-Cause = User-Request</div><div>(6) <span style="white-space:pre-wrap">  </span>NAS-Port-Type = Wireless-802.11</div><div>(6) <span style="white-space:pre-wrap">      </span>Calling-Station-Id = '30:39:26:86:CC:EA'</div><div>(6) <span style="white-space:pre-wrap">     </span>Called-Station-Id = 'hotspot1'</div><div>(6) <span style="white-space:pre-wrap">       </span>NAS-Port-Id = 'citystore_test'</div><div>(6) <span style="white-space:pre-wrap">       </span>User-Name = 'user1'</div><div>(6) <span style="white-space:pre-wrap">  </span>NAS-Port = 2151678022</div><div>(6) <span style="white-space:pre-wrap">        </span>Acct-Session-Id = '80400046'</div><div>(6) <span style="white-space:pre-wrap"> </span>Framed-IP-Address = 10.5.50.254</div><div>(6) <span style="white-space:pre-wrap">      </span>Mikrotik-Host-IP = 10.5.50.254</div><div>(6) <span style="white-space:pre-wrap">       </span>Event-Timestamp = 'Sep 24 2014 14:28:16 EEST'</div><div>(6) <span style="white-space:pre-wrap">        </span>Acct-Input-Octets = 2197666</div><div>(6) <span style="white-space:pre-wrap">  </span>Acct-Output-Octets = 18331654</div><div>(6) <span style="white-space:pre-wrap">        </span>Acct-Input-Gigawords = 0</div><div>(6) <span style="white-space:pre-wrap">     </span>Acct-Output-Gigawords = 0</div><div>(6) <span style="white-space:pre-wrap">    </span>Acct-Input-Packets = 16603</div><div>(6) <span style="white-space:pre-wrap">   </span>Acct-Output-Packets = 16236</div><div>(6) <span style="white-space:pre-wrap">  </span>Acct-Session-Time = 1448</div><div>(6) <span style="white-space:pre-wrap">     </span>NAS-Identifier = 'MikroTik'</div><div>(6) <span style="white-space:pre-wrap">  </span>Acct-Delay-Time = 0</div><div>(6) <span style="white-space:pre-wrap">  </span>NAS-IP-Address = 192.168.40.101</div><div>(6) # Executing section preacct from file /etc/freeradius/sites-enabled/default</div><div>(6)   preacct {</div><div>(6)   [preprocess] = ok</div><div>(6)   acct_unique acct_unique {</div><div>(6)     if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) </div><div>(6) EXPAND %{string:Class}</div><div>(6)    --> </div><div>(6)     if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i)  -> FALSE</div><div>(6)    else else {</div><div>(6)     update request {</div><div>(6) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}</div><div>(6)    --> cd7c5cd7ff1adea4aeffeb8b6c859901</div><div>(6) <span style="white-space:pre-wrap">      </span>Acct-Unique-Session-Id := "cd7c5cd7ff1adea4aeffeb8b6c859901"</div><div>(6)     } # update request = noop</div><div>(6)    } # else else = noop</div><div>(6)   } # acct_unique acct_unique = noop</div><div>(6)  suffix : Checking for suffix after "@"</div><div>(6)  suffix : No '@' in User-Name = "user1", looking up realm NULL</div><div>(6)  suffix : No such realm "NULL"</div><div>(6)   [suffix] = noop</div><div>(6)   [files] = noop</div><div>(6)  } #  preacct = ok</div><div>(6) # Executing section accounting from file /etc/freeradius/sites-enabled/default</div><div>(6)   accounting {</div><div>(6)  detail : EXPAND /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d</div><div>(6)  detail :    --> /var/log/freeradius/radacct/<a href="http://192.168.40.101/detail-20140925" target="_blank">192.168.40.101/detail-20140925</a></div><div>(6)  detail : /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/freeradius/radacct/<a href="http://192.168.40.101/detail-20140925" target="_blank">192.168.40.101/detail-20140925</a></div><div>(6)  detail : EXPAND %t</div><div>(6)  detail :    --> Thu Sep 25 14:24:47 2014</div><div>(6)   [detail] = ok</div><div>(6)   [unix] = ok</div><div>(6)  radutmp : EXPAND /var/log/freeradius/radutmp</div><div>(6)  radutmp :    --> /var/log/freeradius/radutmp</div><div>(6)  radutmp : EXPAND %{User-Name}</div><div>(6)  radutmp :    --> user1</div><div>(6)  WARNING: radutmp : Logout for NAS mikrotik port 2151678022, but no Login record</div><div>(6)   [radutmp] = ok</div><div>(6)  sql : EXPAND %{tolower:type.%{Acct-Status-Type}.query}</div><div>(6)  sql :    --> type.stop.query</div><div>(6)  sql : Using query template 'query'</div><div>rlm_sql (sql): Reserved connection (7)</div><div>(6)  sql : EXPAND %{User-Name}</div><div>(6)  sql :    --> user1</div><div>(6)  sql : SQL-User-Name set to 'user1'</div><div>(6)  sql : EXPAND UPDATE radacct SET acctstoptime<span style="white-space:pre-wrap">        </span>= FROM_UNIXTIME(%{integer:Event-Timestamp}), acctsessiontime<span style="white-space:pre-wrap">    </span>= '%{Acct-Session-Time}', acctinputoctets<span style="white-space:pre-wrap">       </span>= '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', acctterminatecause = '%{Acct-Terminate-Cause}', connectinfo_stop = '%{Connect-Info}' WHERE acctsessionid <span style="white-space:pre-wrap">        </span>= '%{Acct-Session-Id}' AND username<span style="white-space:pre-wrap">             </span>= '%{SQL-User-Name}' AND nasipaddress<span style="white-space:pre-wrap">   </span>= '%{NAS-IP-Address}'</div><div>(6)  sql :    --> UPDATE radacct SET acctstoptime<span style="white-space:pre-wrap">     </span>= FROM_UNIXTIME(1411558096), acctsessiontime<span style="white-space:pre-wrap">    </span>= '1448', acctinputoctets<span style="white-space:pre-wrap">       </span>= '0' << 32 | '2197666', acctoutputoctets = '0' << 32 | '18331654', acctterminatecause = 'User-Request', connectinfo_stop = '' WHERE acctsessionid <span style="white-space:pre-wrap"> </span>= '80400046' AND username<span style="white-space:pre-wrap">               </span>= 'user1' AND nasipaddress<span style="white-space:pre-wrap">      </span>= '192.168.40.101'</div><div>rlm_sql (sql): Executing query: 'UPDATE radacct SET acctstoptime<span style="white-space:pre-wrap">   </span>= FROM_UNIXTIME(1411558096), acctsessiontime<span style="white-space:pre-wrap">    </span>= '1448', acctinputoctets<span style="white-space:pre-wrap">       </span>= '0' << 32 | '2197666', acctoutputoctets = '0' << 32 | '18331654', acctterminatecause = 'User-Request', connectinfo_stop = '' WHERE acctsessionid <span style="white-space:pre-wrap"> </span>= '80400046' AND username<span style="white-space:pre-wrap">               </span>= 'user1' AND nasipaddress<span style="white-space:pre-wrap">      </span>= '192.168.40.101''</div><div>rlm_sql_mysql: Rows matched: 1  Changed: 0  Warnings: 0</div><div>rlm_sql (sql): Released connection (7)</div><div>(6)   [sql] = ok</div><div>(6)   [exec] = noop</div><div>(6)  attr_filter.accounting_response : EXPAND %{User-Name}</div><div>(6)  attr_filter.accounting_response :    --> user1</div><div>(6)  attr_filter.accounting_response : Matched entry DEFAULT at line 12</div><div>(6)   [attr_filter.accounting_response] = updated</div><div>(6)  } #  accounting = updated</div><div>(6) Sending Accounting-Response packet to host 192.168.40.101 port 58545, id=198, length=0</div><div>Sending Accounting-Response Id 198 from <a href="http://192.168.40.12:1813" target="_blank">192.168.40.12:1813</a> to <a href="http://192.168.40.101:58545" target="_blank">192.168.40.101:58545</a></div><div>(6) Finished request</div><div>Waking up in 0.3 seconds.</div><div>Received Accounting-Request Id 198 from <a href="http://192.168.40.101:58545" target="_blank">192.168.40.101:58545</a> to <a href="http://192.168.40.12:1813" target="_blank">192.168.40.12:1813</a> length 194</div><div>(6) Cleaning up request packet ID 198 with timestamp +1572</div><div><span style="white-space:pre-wrap">   </span>Acct-Status-Type = Stop</div><div><span style="white-space:pre-wrap">  </span>Acct-Terminate-Cause = User-Request</div><div><span style="white-space:pre-wrap">      </span>NAS-Port-Type = Wireless-802.11</div><div><span style="white-space:pre-wrap">  </span>Calling-Station-Id = '30:39:26:86:CC:EA'</div><div><span style="white-space:pre-wrap"> </span>Called-Station-Id = 'hotspot1'</div><div><span style="white-space:pre-wrap">   </span>NAS-Port-Id = 'citystore_test'</div><div><span style="white-space:pre-wrap">   </span>User-Name = 'user1'</div><div><span style="white-space:pre-wrap">      </span>NAS-Port = 2151678022</div><div><span style="white-space:pre-wrap">    </span>Acct-Session-Id = '80400046'</div><div><span style="white-space:pre-wrap">     </span>Framed-IP-Address = 10.5.50.254</div><div><span style="white-space:pre-wrap">  </span>Mikrotik-Host-IP = 10.5.50.254</div><div><span style="white-space:pre-wrap">   </span>Event-Timestamp = 'Sep 24 2014 14:28:16 EEST'</div><div><span style="white-space:pre-wrap">    </span>Acct-Input-Octets = 2197666</div><div><span style="white-space:pre-wrap">      </span>Acct-Output-Octets = 18331654</div><div><span style="white-space:pre-wrap">    </span>Acct-Input-Gigawords = 0</div><div><span style="white-space:pre-wrap"> </span>Acct-Output-Gigawords = 0</div><div><span style="white-space:pre-wrap">        </span>Acct-Input-Packets = 16603</div><div><span style="white-space:pre-wrap">       </span>Acct-Output-Packets = 16236</div><div><span style="white-space:pre-wrap">      </span>Acct-Session-Time = 1448</div><div><span style="white-space:pre-wrap"> </span>NAS-Identifier = 'MikroTik'</div><div><span style="white-space:pre-wrap">      </span>Acct-Delay-Time = 1</div><div><span style="white-space:pre-wrap">      </span>NAS-IP-Address = 192.168.40.101</div><div>(7) Received Accounting-Request packet from host 192.168.40.101 port 58545, id=198, length=194</div><div>(7) <span style="white-space:pre-wrap"> </span>Acct-Status-Type = Stop</div><div>(7) <span style="white-space:pre-wrap">      </span>Acct-Terminate-Cause = User-Request</div><div>(7) <span style="white-space:pre-wrap">  </span>NAS-Port-Type = Wireless-802.11</div><div>(7) <span style="white-space:pre-wrap">      </span>Calling-Station-Id = '30:39:26:86:CC:EA'</div><div>(7) <span style="white-space:pre-wrap">     </span>Called-Station-Id = 'hotspot1'</div><div>(7) <span style="white-space:pre-wrap">       </span>NAS-Port-Id = 'citystore_test'</div><div>(7) <span style="white-space:pre-wrap">       </span>User-Name = 'user1'</div><div>(7) <span style="white-space:pre-wrap">  </span>NAS-Port = 2151678022</div><div>(7) <span style="white-space:pre-wrap">        </span>Acct-Session-Id = '80400046'</div><div>(7) <span style="white-space:pre-wrap"> </span>Framed-IP-Address = 10.5.50.254</div><div>(7) <span style="white-space:pre-wrap">      </span>Mikrotik-Host-IP = 10.5.50.254</div><div>(7) <span style="white-space:pre-wrap">       </span>Event-Timestamp = 'Sep 24 2014 14:28:16 EEST'</div><div>(7) <span style="white-space:pre-wrap">        </span>Acct-Input-Octets = 2197666</div><div>(7) <span style="white-space:pre-wrap">  </span>Acct-Output-Octets = 18331654</div><div>(7) <span style="white-space:pre-wrap">        </span>Acct-Input-Gigawords = 0</div><div>(7) <span style="white-space:pre-wrap">     </span>Acct-Output-Gigawords = 0</div><div>(7) <span style="white-space:pre-wrap">    </span>Acct-Input-Packets = 16603</div><div>(7) <span style="white-space:pre-wrap">   </span>Acct-Output-Packets = 16236</div><div>(7) <span style="white-space:pre-wrap">  </span>Acct-Session-Time = 1448</div><div>(7) <span style="white-space:pre-wrap">     </span>NAS-Identifier = 'MikroTik'</div><div>(7) <span style="white-space:pre-wrap">  </span>Acct-Delay-Time = 1</div><div>(7) <span style="white-space:pre-wrap">  </span>NAS-IP-Address = 192.168.40.101</div><div>(7) # Executing section preacct from file /etc/freeradius/sites-enabled/default</div><div>(7)   preacct {</div><div>(7)   [preprocess] = ok</div><div>(7)   acct_unique acct_unique {</div><div>(7)     if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) </div><div>(7) EXPAND %{string:Class}</div><div>(7)    --> </div><div>(7)     if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i)  -> FALSE</div><div>(7)    else else {</div><div>(7)     update request {</div><div>(7) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}</div><div>(7)    --> cd7c5cd7ff1adea4aeffeb8b6c859901</div><div>(7) <span style="white-space:pre-wrap">      </span>Acct-Unique-Session-Id := "cd7c5cd7ff1adea4aeffeb8b6c859901"</div><div>(7)     } # update request = noop</div><div>(7)    } # else else = noop</div><div>(7)   } # acct_unique acct_unique = noop</div><div>(7)  suffix : Checking for suffix after "@"</div><div>(7)  suffix : No '@' in User-Name = "user1", looking up realm NULL</div><div>(7)  suffix : No such realm "NULL"</div><div>(7)   [suffix] = noop</div><div>(7)   [files] = noop</div><div>(7)  } #  preacct = ok</div><div>(7) # Executing section accounting from file /etc/freeradius/sites-enabled/default</div><div>(7)   accounting {</div><div>(7)  detail : EXPAND /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d</div><div>(7)  detail :    --> /var/log/freeradius/radacct/<a href="http://192.168.40.101/detail-20140925" target="_blank">192.168.40.101/detail-20140925</a></div><div>(7)  detail : /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/freeradius/radacct/<a href="http://192.168.40.101/detail-20140925" target="_blank">192.168.40.101/detail-20140925</a></div><div>(7)  detail : EXPAND %t</div><div>(7)  detail :    --> Thu Sep 25 14:24:47 2014</div><div>(7)   [detail] = ok</div><div>(7)   [unix] = ok</div><div>(7)  radutmp : EXPAND /var/log/freeradius/radutmp</div><div>(7)  radutmp :    --> /var/log/freeradius/radutmp</div><div>(7)  radutmp : EXPAND %{User-Name}</div><div>(7)  radutmp :    --> user1</div><div>(7)  WARNING: radutmp : Logout for NAS mikrotik port 2151678022, but no Login record</div><div>(7)   [radutmp] = ok</div><div>(7)  sql : EXPAND %{tolower:type.%{Acct-Status-Type}.query}</div><div>(7)  sql :    --> type.stop.query</div><div>(7)  sql : Using query template 'query'</div><div>rlm_sql (sql): Reserved connection (7)</div><div>(7)  sql : EXPAND %{User-Name}</div><div>(7)  sql :    --> user1</div><div>(7)  sql : SQL-User-Name set to 'user1'</div><div>(7)  sql : EXPAND UPDATE radacct SET acctstoptime<span style="white-space:pre-wrap">        </span>= FROM_UNIXTIME(%{integer:Event-Timestamp}), acctsessiontime<span style="white-space:pre-wrap">    </span>= '%{Acct-Session-Time}', acctinputoctets<span style="white-space:pre-wrap">       </span>= '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', acctterminatecause = '%{Acct-Terminate-Cause}', connectinfo_stop = '%{Connect-Info}' WHERE acctsessionid <span style="white-space:pre-wrap">        </span>= '%{Acct-Session-Id}' AND username<span style="white-space:pre-wrap">             </span>= '%{SQL-User-Name}' AND nasipaddress<span style="white-space:pre-wrap">   </span>= '%{NAS-IP-Address}'</div><div>(7)  sql :    --> UPDATE radacct SET acctstoptime<span style="white-space:pre-wrap">     </span>= FROM_UNIXTIME(1411558096), acctsessiontime<span style="white-space:pre-wrap">    </span>= '1448', acctinputoctets<span style="white-space:pre-wrap">       </span>= '0' << 32 | '2197666', acctoutputoctets = '0' << 32 | '18331654', acctterminatecause = 'User-Request', connectinfo_stop = '' WHERE acctsessionid <span style="white-space:pre-wrap"> </span>= '80400046' AND username<span style="white-space:pre-wrap">               </span>= 'user1' AND nasipaddress<span style="white-space:pre-wrap">      </span>= '192.168.40.101'</div><div>rlm_sql (sql): Executing query: 'UPDATE radacct SET acctstoptime<span style="white-space:pre-wrap">   </span>= FROM_UNIXTIME(1411558096), acctsessiontime<span style="white-space:pre-wrap">    </span>= '1448', acctinputoctets<span style="white-space:pre-wrap">       </span>= '0' << 32 | '2197666', acctoutputoctets = '0' << 32 | '18331654', acctterminatecause = 'User-Request', connectinfo_stop = '' WHERE acctsessionid <span style="white-space:pre-wrap"> </span>= '80400046' AND username<span style="white-space:pre-wrap">               </span>= 'user1' AND nasipaddress<span style="white-space:pre-wrap">      </span>= '192.168.40.101''</div><div>rlm_sql_mysql: Rows matched: 1  Changed: 0  Warnings: 0</div><div>rlm_sql (sql): Released connection (7)</div><div>(7)   [sql] = ok</div><div>(7)   [exec] = noop</div><div>(7)  attr_filter.accounting_response : EXPAND %{User-Name}</div><div>(7)  attr_filter.accounting_response :    --> user1</div><div>(7)  attr_filter.accounting_response : Matched entry DEFAULT at line 12</div><div>(7)   [attr_filter.accounting_response] = updated</div><div>(7)  } #  accounting = updated</div><div>(7) Sending Accounting-Response packet to host 192.168.40.101 port 58545, id=198, length=0</div><div>Sending Accounting-Response Id 198 from <a href="http://192.168.40.12:1813" target="_blank">192.168.40.12:1813</a> to <a href="http://192.168.40.101:58545" target="_blank">192.168.40.101:58545</a></div><div>(7) Finished request</div><div>Waking up in 0.2 seconds.</div><div>(7) Cleaning up request packet ID 198 with timestamp +1572</div></div><div><br></div></div><div>Thanks for your attention and time!</div></div>
</div><br></div>