2.x.x regression: custom SQL queries
Stefan Winter
stefan.winter at restena.lu
Fri Jul 5 09:00:18 CEST 2013
Hi again,
uh, more things seem not to be in order in 2.x.x at the moment. With
yesterday's checkout, I notice that %md5 doesn't exist?
> grep md5 konsoleXxx.txt
Fri Jul 5 08:41:31 2013 : Info: WARNING: Unknown module "md5" in string expansion "%"
Fri Jul 5 08:41:32 2013 : Info: WARNING: Unknown module "md5" in string expansion "%%{md5:%rand:1000000%Y%m%d%h%M%S}%{md5:%rand:1000000%Y%m%d%h%M%S}"
Fri Jul 5 08:41:35 2013 : Info: WARNING: Unknown module "md5" in string expansion "%"
Fri Jul 5 08:41:40 2013 : Info: WARNING: Unknown module "md5" in string expansion "%%{md5:%rand:1000000%Y%m%d%h%M%S}%{md5:%rand:1000000%Y%m%d%h%M%S}"
Fri Jul 5 08:41:41 2013 : Info: WARNING: Unknown module "md5" in string expansion "%"
Fri Jul 5 08:41:43 2013 : Info: WARNING: Unknown module "md5" in string expansion "%"
Fri Jul 5 08:41:43 2013 : Info: WARNING: Unknown module "md5" in string expansion "%"
Note that I neither use a double %% nor an expression which only
consists of a single % with nothing else in my config.
It looks to me like the xlat parser is seriously confused.
Starting 2.2.0 instead, with the identical config shows proper expansions:
> grep md5 konsoleXxx.txt
Fri Jul 5 08:42:33 2013 : Info: expand: %{md5:%rand:1000000%Y%m%d%h%M%S}%{md5:%rand:1000000%Y%m%d%h%M%S}%{md5:%rand:1000000%Y%m%d%h%M%S} -> c8fa166695715ca21e5de23b718f13a5c8fa166695715ca21e5de23b718f13a5c8fa166695715ca21e5de23b718f13a5
Fri Jul 5 08:42:33 2013 : Info: expand: %{md5:%rand:1000000%Y%m%d%h%M%S}%{md5:%rand:1000000%Y%m%d%h%M%S}%{md5:%rand:1000000%Y%m%d%h%M%S} -> c8fa166695715ca21e5de23b718f13a5c8fa166695715ca21e5de23b718f13a5c8fa166695715ca21e5de23b718f13a5
Fri Jul 5 08:42:34 2013 : Info: expand: %{md5:%{config:cui_hash_key}%{request:User-Name}%{outer.request:Operator-Name}} -> 3ebe422cd006d883f0d1677e0b1a8fda
Fri Jul 5 08:42:34 2013 : Info: expand: %{md5:%{config:cui_hash_key}%{request:User-Name}%{Operator-Name}} -> 3ebe422cd006d883f0d1677e0b1a8fda
Fri Jul 5 08:42:35 2013 : Info: expand: %{md5:%{config:cui_hash_key}%{request:User-Name}%{outer.request:Operator-Name}} -> 2d0b24b6a2f1c3407671f60d87281a6d
Fri Jul 5 08:42:35 2013 : Info: expand: %{md5:%{config:cui_hash_key}%{request:User-Name}%{Operator-Name}} -> 2d0b24b6a2f1c3407671f60d87281a6d
Fri Jul 5 08:42:35 2013 : Info: expand: %{md5:%rand:1000000%Y%m%d%h%M%S}%{md5:%rand:1000000%Y%m%d%h%M%S}%{md5:%rand:1000000%Y%m%d%h%M%S} -> 406b166c2c2b1ce9b5ee781ef919b58d406b166c2c2b1ce9b5ee781ef919b58d406b166c2c2b1ce9b5ee781ef919b58d
Fri Jul 5 08:42:36 2013 : Info: expand: %{md5:%rand:1000000%Y%m%d%h%M%S}%{md5:%rand:1000000%Y%m%d%h%M%S}%{md5:%rand:1000000%Y%m%d%h%M%S} -> 3480a4b72a897793df2e166e10d6dc163480a4b72a897793df2e166e10d6dc163480a4b72a897793df2e166e10d6dc16
Fri Jul 5 08:42:37 2013 : Info: expand: %{md5:%rand:1000000%Y%m%d%h%M%S}%{md5:%rand:1000000%Y%m%d%h%M%S}%{md5:%rand:1000000%Y%m%d%h%M%S} -> 76afb853382432f4bbb77330433b866876afb853382432f4bbb77330433b866876afb853382432f4bbb77330433b8668
Fri Jul 5 08:42:38 2013 : Info: expand: %{md5:%rand:1000000%Y%m%d%h%M%S}%{md5:%rand:1000000%Y%m%d%h%M%S}%{md5:%rand:1000000%Y%m%d%h%M%S} -> fa3c4b0643df91b8a499bafee0e535d0fa3c4b0643df91b8a499bafee0e535d0fa3c4b0643df91b8a499bafee0e535d0
Fri Jul 5 08:42:38 2013 : Info: expand: %{md5:%{config:cui_hash_key}%{request:User-Name}%{outer.request:Operator-Name}} -> f73e0c6824ee2803594b8fc776d58791
Fri Jul 5 08:42:39 2013 : Info: expand: %{md5:%{config:cui_hash_key}%{request:User-Name}%{Operator-Name}} -> f73e0c6824ee2803594b8fc776d58791
Fri Jul 5 08:42:39 2013 : Info: expand: %{md5:%{config:cui_hash_key}%{request:User-Name}%{outer.request:Operator-Name}} -> d809d816a751c6e65d5447453e3b861e
Fri Jul 5 08:42:39 2013 : Info: expand: %{md5:%{config:cui_hash_key}%{request:User-Name}%{Operator-Name}} -> b984fa271511afdf66149ff0de23f338
Fri Jul 5 08:42:40 2013 : Info: expand: %{md5:%{config:cui_hash_key}%{request:User-Name}%{outer.request:Operator-Name}} -> d809d816a751c6e65d5447453e3b861e
Fri Jul 5 08:42:40 2013 : Info: expand: %{md5:%{config:cui_hash_key}%{request:User-Name}%{Operator-Name}} -> b984fa271511afdf66149ff0de23f338
I'm abandoning 2.x.x GIT for now, cherry-picking only the SSHA1 hash patch into 2.2.0.
Greetings,
Stefan
On 04.07.2013 09:02, Stefan Winter wrote:
> Hi,
>
> I think I found a regression in the 2.x.x branch. I used to use 2.2.0 until I needed the SSHA1 patch from branch; but with branch code, something totally unrelated now stopped working.
>
> I have a custom SQL query in post-auth, it calls an SQL module instance "sql-webmailsso-users" and does an INSERT. Here is what works with 2.2.0 code:
>
> 2.2.0:
>
> expand: INSERT INTO check_webmailsso_users (user,token,timeout) VALUES('%{User-Name}','%{control:RESTENA-Rand-Source}',TIMESTAMPADD(hour, 12, NOW())) ON DUPLICATE KEY UPDATE token='%{control:RESTENA-Rand-Source}', tim
> eout=TIMESTAMPADD(hour, 12, NOW()) -> INSERT INTO check_webmailsso_users (user,token,timeout) VALUES('swinter','620413e46406a7c05e84253cd75fcb06620413e46406a7c05e84253cd75fcb06620413e46406a7c05e84253cd75fcb06',TIMESTAMPADD(hour, 12, NOW())) ON DUPLICATE KEY UPDATE token='620413e46406a7c05e84253cd75fcb06620413e46406a7c05e84253cd75fcb06620413e46406a7c05e84253cd75fcb06', timeout=TIMESTAMPADD(hour, 12, NOW())
> rlm_sql (sql-webmailsso-users): Reserving sql socket id: 1
> rlm_sql (sql-webmailsso-users): Released sql socket id: 1
> expand: %{sql-webmailsso-users:INSERT INTO check_webmailsso_users (user,token,timeout) VALUES('%{User-Name}','%{control:RESTENA-Rand-Source}',TIMESTAMPADD(hour, 12, NOW())) ON DUPLICATE KEY UPDATE token='%{control:RESTENA-Rand-Source}', timeout=TIMESTAMPADD(hour, 12, NOW())} -> 1
> +++[expand] returns noop
> expand: urn:restena:magicmushroom=%{control:RESTENA-Rand-Source} -> urn:restena:magicmushroom=620413e46406a7c05e84253cd75fcb06620413e46406a7c05e84253cd75fcb06620413e46406a7c05e84253cd75fcb06
>
> I.e. expansion gets done, and the SQL query gets executed. Note that there is a line "+++[expand] returns noop" in the middle.
>
> With 2.x.x branch code, the identical config does not actually perfom the SQL query; even though things still get expanded as they should. Ominously, that "noop" line is NOT showing up in the two 2.x.x branch snapshots I tested with. Here are two examples:
>
> 20130610:
>
> expand: INSERT INTO check_webmailsso_users (user,token,timeout) VALUES('%{User-Name}','%{control:RESTENA-Rand-Source}',TIMESTAMPADD(hour, 12, NOW())) ON DUPLICATE KEY UPDATE token='%{control:RESTENA-Rand-Source}', tim
> eout=TIMESTAMPADD(hour, 12, NOW()) -> INSERT INTO check_webmailsso_users (user,token,timeout) VALUES('swinter','8570ceee00c6d8ed3f1c56e2d47c51318570ceee00c6d8ed3f1c56e2d47c51318570ceee00c6d8ed3f1c56e2d47c5131',TIMESTAMPADD(hour, 12, NOW())) ON DUPLICATE KEY UPDATE token='8570ceee00c6d8ed3f1c56e2d47c51318570ceee00c6d8ed3f1c56e2d47c51318570ceee00c6d8ed3f1c56e2d47c5131', timeout=TIMESTAMPADD(hour, 12, NOW())
> rlm_sql (sql-webmailsso-users): Reserving sql socket id: 6
> rlm_sql (sql-webmailsso-users): Released sql socket id: 6
> expand: %{sql-webmailsso-users:INSERT INTO check_webmailsso_users (user,token,timeout) VALUES('%{User-Name}','%{control:RESTENA-Rand-Source}',TIMESTAMPADD(hour, 12, NOW())) ON DUPLICATE KEY UPDATE token='%{control:RESTENA-Rand-Source}', timeout=TIMESTAMPADD(hour, 12, NOW())} -> 1
> expand: urn:restena:magicmushroom=%{control:RESTENA-Rand-Source} -> urn:restena:magicmushroom=8570ceee00c6d8ed3f1c56e2d47c51318570ceee00c6d8ed3f1c56e2d47c51318570ceee00c6d8ed3f1c56e2d47c5131
>
> 20310704:
>
> expand: INSERT INTO check_webmailsso_users (user,token,timeout) VALUES('%{User-Name}','%{control:RESTENA-Rand-Source}',TIMESTAMPADD(hour, 12, NOW())) ON DUPLICATE KEY UPDATE token='%{control:RESTENA-Rand-Source}', tim
> eout=TIMESTAMPADD(hour, 12, NOW()) -> INSERT INTO check_webmailsso_users (user,token,timeout) VALUES('swinter','af571d6c1794a2e491091ac6990d5d6daf571d6c1794a2e491091ac6990d5d6daf571d6c1794a2e491091ac6990d5d6d',TIMESTAMPADD(hour, 12, NOW())) ON DUPLICATE KEY UPDATE token='af571d6c1794a2e491091ac6990d5d6daf571d6c1794a2e491091ac6990d5d6daf571d6c1794a2e491091ac6990d5d6d', timeout=TIMESTAMPADD(hour, 12, NOW())
> rlm_sql (sql-webmailsso-users): Reserving sql socket id: 8
> rlm_sql (sql-webmailsso-users): Released sql socket id: 8
> expand: %{sql-webmailsso-users:INSERT INTO check_webmailsso_users (user,token,timeout) VALUES('%{User-Name}','%{control:RESTENA-Rand-Source}',TIMESTAMPADD(hour, 12, NOW())) ON DUPLICATE KEY UPDATE token='%{control:RESTENA-Rand-Source}', timeout=TIMESTAMPADD(hour, 12, NOW())} -> 1
> expand: urn:restena:magicmushroom=%{control:RESTENA-Rand-Source} -> urn:restena:magicmushroom=af571d6c1794a2e491091ac6990d5d6daf571d6c1794a2e491091ac6990d5d6daf571d6c1794a2e491091ac6990d5d6d
>
> Everything looks "pretty much" okay - but my database never gets the INSERT. The only difference I really see in the log is that the "noop" line doesn't show up.
>
> Hope that explains the problem, and helps in finding the problem.
>
> Stefan
>
>
>
> -
> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/devel.html
>
--
Stefan WINTER
Ingenieur de Recherche
Fondation RESTENA - Réseau Téléinformatique de l'Education Nationale et de la Recherche
6, rue Richard Coudenhove-Kalergi
L-1359 Luxembourg
Tel: +352 424409 1
Fax: +352 422473
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 263 bytes
Desc: OpenPGP digital signature
URL: <http://lists.freeradius.org/pipermail/freeradius-devel/attachments/20130705/c5e0e0f3/attachment.pgp>
More information about the Freeradius-Devel
mailing list