Le 9 juil. 2014 à 01:18, Arran Cudbard-Bell a écrit :
On 8 Jul 2014, at 14:57, Axel Luttgens wrote:
[...] 3. The post-auth query is defined as:
query = "\ INSERT INTO ${..postauth_table} \ (username, pass, reply, authdate) \ VALUES ( \ '%{SQL-User-Name}', \ '%{%{User-Password}:-%{Chap-Password}}', \ '%{reply:Packet-Type}', \ %{%{integer:Event-Timestamp}:-date('now')})"
and the log shows it expands as:
INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'bob', 'hello', 'Access-Accept', )
As a result, no row is inserted into table "radpostauth", since its column "authdate" is defined to be NOT NULL.
Could you provide the debug output please.
Hello Arran, Thank you for your reply. Here's the output (with -Xx): Wed Jul 9 17:32:02 2014 : Auth: (0) Login OK: [bob] (from client localhost port 0) Wed Jul 9 17:32:02 2014 : Debug: (0) # Executing section post-auth from file /_ROOT/etc/raddb/sites-enabled/default Wed Jul 9 17:32:02 2014 : Debug: (0) post-auth { Wed Jul 9 17:32:02 2014 : Debug: (0) modsingle[post-auth]: calling sql (rlm_sql) for request 0 Wed Jul 9 17:32:02 2014 : Debug: .query Wed Jul 9 17:32:02 2014 : Debug: Parsed xlat tree: Wed Jul 9 17:32:02 2014 : Debug: literal --> .query Wed Jul 9 17:32:02 2014 : Debug: (0) sql : EXPAND .query Wed Jul 9 17:32:02 2014 : Debug: (0) sql : --> .query Wed Jul 9 17:32:02 2014 : Debug: (0) sql : Using query template 'query' Wed Jul 9 17:32:02 2014 : Debug: rlm_sql (sql): Reserved connection (4) Wed Jul 9 17:32:02 2014 : Debug: %{User-Name} Wed Jul 9 17:32:02 2014 : Debug: Parsed xlat tree: Wed Jul 9 17:32:02 2014 : Debug: attribute --> User-Name Wed Jul 9 17:32:02 2014 : Debug: (0) sql : EXPAND %{User-Name} Wed Jul 9 17:32:02 2014 : Debug: (0) sql : --> bob Wed Jul 9 17:32:02 2014 : Debug: (0) sql : SQL-User-Name set to 'bob' Wed Jul 9 17:32:02 2014 : Debug: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', %{%{integer:Event-Timestamp}:-date('now')}) Wed Jul 9 17:32:02 2014 : Debug: Parsed xlat tree: Wed Jul 9 17:32:02 2014 : Debug: literal --> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( ' Wed Jul 9 17:32:02 2014 : Debug: attribute --> SQL-User-Name Wed Jul 9 17:32:02 2014 : Debug: literal --> ', ' Wed Jul 9 17:32:02 2014 : Debug: if { Wed Jul 9 17:32:02 2014 : Debug: attribute --> User-Password Wed Jul 9 17:32:02 2014 : Debug: } Wed Jul 9 17:32:02 2014 : Debug: else { Wed Jul 9 17:32:02 2014 : Debug: attribute --> CHAP-Password Wed Jul 9 17:32:02 2014 : Debug: } Wed Jul 9 17:32:02 2014 : Debug: literal --> ', ' Wed Jul 9 17:32:02 2014 : Debug: attribute --> Packet-Type Wed Jul 9 17:32:02 2014 : Debug: literal --> ', Wed Jul 9 17:32:02 2014 : Debug: if { Wed Jul 9 17:32:02 2014 : Debug: xlat --> integer Wed Jul 9 17:32:02 2014 : Debug: { Wed Jul 9 17:32:02 2014 : Debug: literal --> Event-Timestamp Wed Jul 9 17:32:02 2014 : Debug: } Wed Jul 9 17:32:02 2014 : Debug: } Wed Jul 9 17:32:02 2014 : Debug: else { Wed Jul 9 17:32:02 2014 : Debug: literal --> date('now') Wed Jul 9 17:32:02 2014 : Debug: } Wed Jul 9 17:32:02 2014 : Debug: literal --> ) Wed Jul 9 17:32:02 2014 : Debug: (0) sql : EXPAND INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', %{%{integer:Event-Timestamp}:-date('now')}) Wed Jul 9 17:32:02 2014 : Debug: (0) sql : --> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'bob', 'hello', 'Access-Accept', ) Wed Jul 9 17:32:02 2014 : Debug: rlm_sql (sql): Executing query: 'INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'bob', 'hello', 'Access-Accept', )' Wed Jul 9 17:32:02 2014 : Debug: (0) sql : No additional queries configured
How is the expression %{%{integer:Event-Timestamp}:-date('now')} supposed to be interpreted? More specifically, why the enclosing %{...}?
It's interpreted by the xlat parser. As integer:Event-Timestamp expands to a zero length string, data('now') should be inserted into the query string instead...
Yes, that's what I thought to have (more or less) understood from the docs. ;-) But...
I guess that's a bug.
... but indeed, perhaps something strange is at work here. For example, when I remove the "integer:" piece before "Event-Timestamp", this is what I get in the debug output: Wed Jul 9 18:13:50 2014 : Auth: (0) Login OK: [bob] (from client localhost port 0) Wed Jul 9 18:13:50 2014 : Debug: (0) # Executing section post-auth from file /_ROOT/etc/raddb/sites-enabled/default Wed Jul 9 18:13:50 2014 : Debug: (0) post-auth { Wed Jul 9 18:13:50 2014 : Debug: (0) modsingle[post-auth]: calling sql (rlm_sql) for request 0 Wed Jul 9 18:13:50 2014 : Debug: .query Wed Jul 9 18:13:50 2014 : Debug: Parsed xlat tree: Wed Jul 9 18:13:50 2014 : Debug: literal --> .query Wed Jul 9 18:13:50 2014 : Debug: (0) sql : EXPAND .query Wed Jul 9 18:13:50 2014 : Debug: (0) sql : --> .query Wed Jul 9 18:13:50 2014 : Debug: (0) sql : Using query template 'query' Wed Jul 9 18:13:50 2014 : Debug: rlm_sql (sql): Reserved connection (4) Wed Jul 9 18:13:50 2014 : Debug: %{User-Name} Wed Jul 9 18:13:50 2014 : Debug: Parsed xlat tree: Wed Jul 9 18:13:50 2014 : Debug: attribute --> User-Name Wed Jul 9 18:13:50 2014 : Debug: (0) sql : EXPAND %{User-Name} Wed Jul 9 18:13:50 2014 : Debug: (0) sql : --> bob Wed Jul 9 18:13:50 2014 : Debug: (0) sql : SQL-User-Name set to 'bob' Wed Jul 9 18:13:50 2014 : Debug: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', %{%{Event-Timestamp}:-date('now')}) Wed Jul 9 18:13:50 2014 : Debug: Parsed xlat tree: Wed Jul 9 18:13:50 2014 : Debug: literal --> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( ' Wed Jul 9 18:13:50 2014 : Debug: attribute --> SQL-User-Name Wed Jul 9 18:13:50 2014 : Debug: literal --> ', ' Wed Jul 9 18:13:50 2014 : Debug: if { Wed Jul 9 18:13:50 2014 : Debug: attribute --> User-Password Wed Jul 9 18:13:50 2014 : Debug: } Wed Jul 9 18:13:50 2014 : Debug: else { Wed Jul 9 18:13:50 2014 : Debug: attribute --> CHAP-Password Wed Jul 9 18:13:50 2014 : Debug: } Wed Jul 9 18:13:50 2014 : Debug: literal --> ', ' Wed Jul 9 18:13:50 2014 : Debug: attribute --> Packet-Type Wed Jul 9 18:13:50 2014 : Debug: literal --> ', Wed Jul 9 18:13:50 2014 : Debug: if { Wed Jul 9 18:13:50 2014 : Debug: attribute --> Event-Timestamp Wed Jul 9 18:13:50 2014 : Debug: } Wed Jul 9 18:13:50 2014 : Debug: else { Wed Jul 9 18:13:50 2014 : Debug: literal --> date('now') Wed Jul 9 18:13:50 2014 : Debug: } Wed Jul 9 18:13:50 2014 : Debug: literal --> ) Wed Jul 9 18:13:50 2014 : Debug: (0) sql : EXPAND INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', %{%{Event-Timestamp}:-date('now')}) Wed Jul 9 18:13:50 2014 : Debug: (0) sql : --> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'bob', 'hello', 'Access-Accept', date=28=27now=27=29) Wed Jul 9 18:13:50 2014 : Debug: rlm_sql (sql): Executing query: 'INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'bob', 'hello', 'Access-Accept', date=28=27now=27=29)' Wed Jul 9 18:13:50 2014 : Debug: (0) sql : No additional queries configured Of course, that "date=28=27now=27=29" sequence of characters doesn't make any sense for sqlite, and no row gets inserted into the table. Still investigating...
4. Replacing above expression by '%S' works beautifully. I mean, the expansion for the query yields a timestamp such as "'2014-07-08 18:09:54'", and a row is now happily inserted into table "radpostauth". :-) What is the rationale for having devised a query based on Event-Timestamp at first hand?
It's adjusted for delay, whereas %S isn't.
If you're using the detail/reader writer combo using %S will produce invalid results.
If you're doing accounting Acct-Delay-Time will be taken into account when producing the value for Event-Timestamp also.
I don't understand everything yet (I'm just a plain newbie wrt FR...), but am I supposed to have a value for "Event-Timestamp" in the post-auth section (as defined by, basically, the standard configuration coming with FR)? Axel