radsqlrelay: incorrect datetime error reading sql-relay file

[Alan DeKok]

On Nov 27, 2016, at 12:55 PM, I Want Wireless <iwantwireless at gmail.com> wrote:
> 
> FreeRadius 2.2.8 running on Ubuntu 14.04 LTS

  Upgrade to 3.0.12.

> sql_log is enabled in the accounting section of /sites-enabled/default
> 
> When I execute radsqlrelay it repeatedly dumps the following error to the
> screen and no records are created on the target server
> 
> /usr/bin/radsqlrelay -x  -1 -b radius -d mysql -h xxx.xxx.xxx.xxx -u
> radrelay_user -p somepassword /var/log/freeradius/radacct/sql-relay
> 
> 
> Incorrect datetime value: '0' for column 'acctstarttime' at row 1
> Incorrect datetime value: '0' for column 'acctstarttime' at row 1
> Incorrect datetime value: '0' for column 'acctstarttime' at row 1
> 
> 
> And indeed the file shows this:
> 
> head /var/log/freeradius/radacct/sql-relay
> 
> INSERT INTO radacct (AcctSessionId, UserName,    NASIPAddress,
> FramedIPAddress, AcctStartTime, AcctStopTime,     AcctSessionTime,
> AcctTerminateCause) VALUES   ('810001a7', 'acct203', 'xxx.xxx.37.1',
>   'xxx.xxx.3.50', '0', '0', '4801','');

  Well, '0' isn't a good start time.

  This value comes from the NAS.  So, blame the NAS for sending garbage data.

> But I am also logging to a local sql database and I see account start times
> there

  Then read the debug output to see what's going on.

> acctsessionid  acctuniqueid  username  nasipaddress nasportid nasporttype
> acctstarttime acctstoptime acctsessiontime
> 
> 810001a7 b051e93c387cc6be acct2203 xxx.xxx.37.1 15729080 Ethernet 2016-11-27
> 11:09:51 *NULL* 4801
> 810001a6 830d03bc3cbe59de acct2150 xxx.xxx.37.1 15729079 Ethernet 2016-11-27
> 11:03:00 *NULL* 5400
> 
> 
> I  must be missing something but I can find very little info on radsqlrelay
> other than the man

  radsqlrelay isn't the problem.  The problem is that the NAS is sending garbage, and you've configured FreeRADIUS to write that to the radsqlrelay file.

  Alan DeKok.