RADIUS SM QoS parameters - VSA attributes not apply

Hi,

   we have FreeRADIUS server which after authentication send reply with VSA attributes, but  AP don't accept them and set default/implicit data rate to authenticated SM - see picture.

"RADIUS Authentication reply" section on AP is blank (don't see reply!?)

Full RADIUS debug is in attachment, bellow is little cut:

(399)   sql : EXPAND %{User-Name}
(399)   sql :    --> 0a-00-3e-40-9c-32
(399)   sql : SQL-User-Name set to '0a-00-3e-40-9c-32'
rlm_sql (sql): Reserved connection (256)
(399)   sql : EXPAND SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id
(399)   sql :    --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = '0a-00-3e-40-9c-32' ORDER BY id
rlm_sql (sql): Executing query: 'SELECT id, username, attribute, value, op FROM radcheck WHERE username = '0a-00-3e-40-9c-32' ORDER BY id'
(399)   sql : User found in radcheck table
(399)   sql : Check items matched
(399)   sql : EXPAND SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id
(399)   sql :    --> SELECT id, username, attribute, value, op FROM radreply WHERE username = '0a-00-3e-40-9c-32' ORDER BY id
rlm_sql (sql): Executing query: 'SELECT id, username, attribute, value, op FROM radreply WHERE username = '0a-00-3e-40-9c-32' ORDER BY id'
(399)   sql : User found in radreply table
(399)   sql : EXPAND SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority
(399)   sql :    --> SELECT groupname FROM radusergroup WHERE username = '0a-00-3e-40-9c-32' ORDER BY priority
rlm_sql (sql): Executing query: 'SELECT groupname FROM radusergroup WHERE username = '0a-00-3e-40-9c-32' ORDER BY priority'
(399)   sql : User not found in any groups
rlm_sql (sql): Released connection (256)
(399)    [sql] = ok
(399)    [expiration] = noop
(399)    [logintime] = noop
(399)   WARNING: pap : Auth-Type already set.  Not setting to PAP
(399)    [pap] = noop
(399)   } #  authorize = ok
(399)  Found Auth-Type = MSCHAP
(399)  # Executing group from file /etc/raddb/sites-enabled/inner-tunnel
(399)   Auth-Type MS-CHAP {
(399)   mschap : Found Cleartext-Password, hashing to create LM-Password
(399)   mschap : Found Cleartext-Password, hashing to create NT-Password
(399)   mschap : Creating challenge hash with username: 0a-00-3e-40-9c-32
(399)   mschap : Client is using MS-CHAPv2
(399)   mschap : Adding MS-CHAPv2 MPPE keys
(399)    [mschap] = ok
(399)   } # Auth-Type MS-CHAP = ok
(399)  # Executing section post-auth from file /etc/raddb/sites-enabled/inner-tunnel
(399)    post-auth {
(399)   sql : EXPAND .query
(399)   sql :    --> .query
(399)   sql : Using query template 'query'
rlm_sql (sql): Reserved connection (256)
(399)   sql : EXPAND %{User-Name}
(399)   sql :    --> 0a-00-3e-40-9c-32
(399)   sql : SQL-User-Name set to '0a-00-3e-40-9c-32'
(399)   sql : EXPAND INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')
(399)   sql :    --> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '0a-00-3e-40-9c-32', '', 'Access-Accept', '2017-02-09 13:03:26')
rlm_sql (sql): Executing query: 'INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '0a-00-3e-40-9c-32', '', 'Access-Accept', '2017-02-09 13:03:26')'
rlm_sql (sql): Released connection (256)
(399)    [sql] = ok
(399)   } #  post-auth = ok
(399)    Reply:
    Cambium-Canopy-HPENABLE = Enable
    Cambium-Canopy-HPDLCIR = 500
    Cambium-Canopy-HPULCIR = 500
    Cambium-Canopy-LPDLCIR = 300
    Cambium-Canopy-LPULCIR = 300
    Cambium-Canopy-DLBR = 3000
    Cambium-Canopy-ULBR = 1000
    MS-CHAP2-Success = 0x38533d33324335454243323037463238333944333736334145444543313445353242413337333737323039
    MS-MPPE-Recv-Key = 0x6e34e7646052c658a35efc1bbae64876
    MS-MPPE-Send-Key = 0x2b7b0915e7fed650c0aa8f132dd942d2
    MS-MPPE-Encryption-Policy = Encryption-Allowed
    MS-MPPE-Encryption-Types = RC4-40or128-bit-Allowed
(399)  } # server inner-tunnel
(399)  eap_ttls : Got tunneled Access-Accept
(399)  eap_ttls : Got MS-CHAP2-Success, tunneling it to the client in a challenge
(399)  eap_ttls : sending tunneled reply attributes
    MS-CHAP2-Success = 0x38533d33324335454243323037463238333944333736334145444543313445353242413337333737323039
(399)  eap_ttls : end tunneled reply attributes
(399)  eap : New EAP session, adding 'State' attribute to reply 0x78dc0ab07ddb1fe3
(399)   [eap] = handled
(399)  } #  authenticate = handled
(399) Sending Access-Challenge packet to host 10.6.1.90 port 1236, id=0, length=0
(399)     EAP-Message = 0x0107005f158000000055170301005091ab6a0ca8da7a4c9de8e06b63d9df2c0af84b771a8c39ac6997dafaf4fd8ea059d1662d4b4cc0626ffbb495fff79a432ca8001e85caa5572f335f8b8d97b7fdd32d4c4cfa2d78bacedf1452958fd1df
(399)     Message-Authenticator = 0x00000000000000000000000000000000
(399)     State = 0x78dc0ab07ddb1fe36f01bf10d02412ef
Sending Access-Challenge Id 0 from 89.190.92.142:1812 to 10.6.1.90:1236
    EAP-Message = 0x0107005f158000000055170301005091ab6a0ca8da7a4c9de8e06b63d9df2c0af84b771a8c39ac6997dafaf4fd8ea059d1662d4b4cc0626ffbb495fff79a432ca8001e85caa5572f335f8b8d97b7fdd32d4c4cfa2d78bacedf1452958fd1df
    Message-Authenticator = 0x00000000000000000000000000000000
    State = 0x78dc0ab07ddb1fe36f01bf10d02412ef
(399) Finished request

This might seem like an obvious question, but your RADIUS debug log didn't clear it up: are you sure RADIUS is including the correct dictionary file for the attributes you are assigning? That would allow authentication, but would keep FreeRADIUS from sending the correct info for the attributes.

Hi,

>"RADIUS Authentication reply" section on AP is blank (don't see reply!?)

Because you have not configured(RADIUS debug logs that you have attached confirms that) reply message VSA for the user file, open the users file and where you have configured SM user name and password add Reply-Message ="whatever you want to display"

 Regarding configuration not applied , on AP check

Configuration → General Bandwidth Configuration Source

This should be set to Authentication server only then VSA applied to SM.

dshea:

I hope - CANOPY dictionary file was uploaded to "/usr/share/freeradius/dictionary.canopy" and "/usr/share/freeradius/dictionary" file was modifyed to "$INCLUDE dictionary.canopy"

Chitrang:

we use MariaDB (MySQL) for RADIUS AAA... so in table "radreply" we have this values:

MariaDB [radius]> select * from radreply where username='0a-00-3e-40-9c-32';
+-----+-------------------+-------------------------+----+-------+
| id | username | attribute | op | value |
+-----+-------------------+-------------------------+----+-------+
| 112 | 0a-00-3e-40-9c-32 | Cambium-Canopy-HPENABLE | := | 1 |
| 115 | 0a-00-3e-40-9c-32 | Cambium-Canopy-HPDLCIR | += | 500 |
| 116 | 0a-00-3e-40-9c-32 | Cambium-Canopy-HPULCIR | += | 500 |
| 117 | 0a-00-3e-40-9c-32 | Cambium-Canopy-LPDLCIR | += | 300 |
| 118 | 0a-00-3e-40-9c-32 | Cambium-Canopy-LPULCIR | += | 300 |
| 120 | 0a-00-3e-40-9c-32 | Cambium-Canopy-DLBR | += | 3000 |
| 121 | 0a-00-3e-40-9c-32 | Cambium-Canopy-ULBR | += | 1000 |
+-----+-------------------+-------------------------+----+-------+
7 rows in set (0.00 sec)

MariaDB [radius]>

In this table you have to add another VSA Reply-Message defined https://tools.ietf.org/html/rfc2865#page-41 for example you may use Reply-Message = “Hello from freeradius”

Hi,

   we try all but still without luck. Please look into debug:

Thu Mar  2 12:21:18 2017 : Debug: (5) Received Access-Request packet from host 192.168.2.250 port 1236, id=0, length=271
Thu Mar  2 12:21:18 2017 : Debug: (5)     Calling-Station-Id = '0A-00-3E-40-58-80'
Thu Mar  2 12:21:18 2017 : Debug: (5)     User-Name = 'anonymous'
Thu Mar  2 12:21:18 2017 : Debug: (5)     State = 0x74f1779370f762bb24343c1c695e59ff
Thu Mar  2 12:21:18 2017 : Debug: (5)     NAS-IP-Address = 192.168.2.250
Thu Mar  2 12:21:18 2017 : Debug: (5)     NAS-Port = 5
Thu Mar  2 12:21:18 2017 : Debug: (5)     NAS-Port-Type = Wireless-Other
Thu Mar  2 12:21:18 2017 : Debug: (5)     Framed-MTU = 1020
Thu Mar  2 12:21:18 2017 : Debug: (5)     EAP-Message = 0x0206009f15800000009517030100902b06e2f654852f7f84b91b9c5410a2158f01ce87929a97acfd4644a3a73d962adf967397f1da5614c274b6b8e5218821905b06b051ab78658c772701b7cde2fb7a9aede0703a4a851866c6d0fa951cc33b70bc1689da726dbb5df3772be7c6eacb58b29f4d4a6ee4933ee1b11fb2db4b7be8805f9e6445f794bd9b1a7cd09a0cc0074903260b02bfae47e57fa75203a4
Thu Mar  2 12:21:18 2017 : Debug: (5)     Message-Authenticator = 0x50be33961580758d1ed962a04664c642
Thu Mar  2 12:21:18 2017 : Debug: (5) # Executing section authorize from file /etc/raddb/sites-enabled/default
Thu Mar  2 12:21:18 2017 : Debug: (5)   authorize {
Thu Mar  2 12:21:18 2017 : Debug: (5)   filter_username filter_username {
Thu Mar  2 12:21:18 2017 : Debug: (5)     if (!&User-Name)
Thu Mar  2 12:21:18 2017 : Debug: (5)     if (!&User-Name)  -> FALSE
Thu Mar  2 12:21:18 2017 : Debug: (5)     if (&User-Name =~ / /)
Thu Mar  2 12:21:18 2017 : Debug: (5)     if (&User-Name =~ / /)  -> FALSE
Thu Mar  2 12:21:18 2017 : Debug: (5)     if (&User-Name =~ /@.*@/ )
Thu Mar  2 12:21:18 2017 : Debug: (5)     if (&User-Name =~ /@.*@/ )  -> FALSE
Thu Mar  2 12:21:18 2017 : Debug: (5)     if (&User-Name =~ /\\.\\./ )
Thu Mar  2 12:21:18 2017 : Debug: (5)     if (&User-Name =~ /\\.\\./ )  -> FALSE
Thu Mar  2 12:21:18 2017 : Debug: (5)     if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\\.(.+)$/))  
Thu Mar  2 12:21:18 2017 : Debug: (5)     if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\\.(.+)$/))   -> FALSE
Thu Mar  2 12:21:18 2017 : Debug: (5)     if (&User-Name =~ /\\.$/)  
Thu Mar  2 12:21:18 2017 : Debug: (5)     if (&User-Name =~ /\\.$/)   -> FALSE
Thu Mar  2 12:21:18 2017 : Debug: (5)     if (&User-Name =~ /@\\./)  
Thu Mar  2 12:21:18 2017 : Debug: (5)     if (&User-Name =~ /@\\./)   -> FALSE
Thu Mar  2 12:21:18 2017 : Debug: (5)   } # filter_username filter_username = notfound
Thu Mar  2 12:21:18 2017 : Debug: (5)  modsingle[authorize]: calling preprocess (rlm_preprocess) for request 5
Thu Mar  2 12:21:18 2017 : Debug: (5) modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 5
Thu Mar  2 12:21:18 2017 : Debug: (5)   [preprocess] = ok
Thu Mar  2 12:21:18 2017 : Debug: (5)  modsingle[authorize]: calling chap (rlm_chap) for request 5
Thu Mar  2 12:21:18 2017 : Debug: (5) modsingle[authorize]: returned from chap (rlm_chap) for request 5
Thu Mar  2 12:21:18 2017 : Debug: (5)   [chap] = noop
Thu Mar  2 12:21:18 2017 : Debug: (5)  modsingle[authorize]: calling mschap (rlm_mschap) for request 5
Thu Mar  2 12:21:18 2017 : Debug: (5) modsingle[authorize]: returned from mschap (rlm_mschap) for request 5
Thu Mar  2 12:21:18 2017 : Debug: (5)   [mschap] = noop
Thu Mar  2 12:21:18 2017 : Debug: (5)  modsingle[authorize]: calling digest (rlm_digest) for request 5
Thu Mar  2 12:21:18 2017 : Debug: (5) modsingle[authorize]: returned from digest (rlm_digest) for request 5
Thu Mar  2 12:21:18 2017 : Debug: (5)   [digest] = noop
Thu Mar  2 12:21:18 2017 : Debug: (5)  modsingle[authorize]: calling suffix (rlm_realm) for request 5
Thu Mar  2 12:21:18 2017 : Debug: (5)  suffix : Checking for suffix after "@"
Thu Mar  2 12:21:18 2017 : Debug: (5)  suffix : No '@' in User-Name = "anonymous", looking up realm NULL
Thu Mar  2 12:21:18 2017 : Debug: (5)  suffix : No such realm "NULL"
Thu Mar  2 12:21:18 2017 : Debug: (5) modsingle[authorize]: returned from suffix (rlm_realm) for request 5
Thu Mar  2 12:21:18 2017 : Debug: (5)   [suffix] = noop
Thu Mar  2 12:21:18 2017 : Debug: (5)  modsingle[authorize]: calling eap (rlm_eap) for request 5
Thu Mar  2 12:21:18 2017 : Debug: (5)  eap : Peer sent code Response (2) ID 6 length 159
Thu Mar  2 12:21:18 2017 : Debug: (5)  eap : Continuing tunnel setup
Thu Mar  2 12:21:18 2017 : Debug: (5) modsingle[authorize]: returned from eap (rlm_eap) for request 5
Thu Mar  2 12:21:18 2017 : Debug: (5)   [eap] = ok
Thu Mar  2 12:21:18 2017 : Debug: (5)  } #  authorize = ok
Thu Mar  2 12:21:18 2017 : Debug: (5) Found Auth-Type = EAP
Thu Mar  2 12:21:18 2017 : Debug: (5) # Executing group from file /etc/raddb/sites-enabled/default
Thu Mar  2 12:21:18 2017 : Debug: (5)   authenticate {
Thu Mar  2 12:21:18 2017 : Debug: (5)  modsingle[authenticate]: calling eap (rlm_eap) for request 5
Thu Mar  2 12:21:18 2017 : Debug: (5)  eap : Expiring EAP session with state 0x74f1779370f762bb
Thu Mar  2 12:21:18 2017 : Debug: (5)  eap : Finished EAP session with state 0x74f1779370f762bb
Thu Mar  2 12:21:18 2017 : Debug: (5)  eap : Previous EAP request found for state 0x74f1779370f762bb, released from the list
Thu Mar  2 12:21:18 2017 : Debug: (5)  eap : Peer sent method TTLS (21)
Thu Mar  2 12:21:18 2017 : Debug: (5)  eap : EAP TTLS (21)
Thu Mar  2 12:21:18 2017 : Debug: (5)  eap : Calling eap_ttls to process EAP data
Thu Mar  2 12:21:18 2017 : Debug: (5)  eap_ttls : Authenticate
Thu Mar  2 12:21:18 2017 : Debug: (5)  eap_ttls : processing EAP-TLS
Thu Mar  2 12:21:18 2017 : Debug:   TLS Length 149
Thu Mar  2 12:21:18 2017 : Debug: (5)  eap_ttls : Length Included
Thu Mar  2 12:21:18 2017 : Debug: (5)  eap_ttls : eaptls_verify returned 11
Thu Mar  2 12:21:18 2017 : Debug: (5)  eap_ttls : eaptls_process returned 7
Thu Mar  2 12:21:18 2017 : Debug: (5)  eap_ttls : Session established.  Proceeding to decode tunneled attributes
Thu Mar  2 12:21:18 2017 : Debug: (5)  eap_ttls : Got tunneled request
    User-Name = '0a-00-3e-40-58-80'
    MS-CHAP-Challenge = 0x60c157013a58a78195fb3d69c6fb2d32
    MS-CHAP2-Response = 0x55001a965021b5f46d56944df3c4ab73fe9c00000000000000004370044ee0b00235435d418e5279f8e0dd5673df40b1c5d1
Thu Mar  2 12:21:18 2017 : Debug: (5)  eap_ttls : Sending tunneled request
Thu Mar  2 12:21:18 2017 : Debug: (5)  server inner-tunnel {
Thu Mar  2 12:21:18 2017 : Debug: (5)    Request:
    User-Name = '0a-00-3e-40-58-80'
    MS-CHAP-Challenge = 0x60c157013a58a78195fb3d69c6fb2d32
    MS-CHAP2-Response = 0x55001a965021b5f46d56944df3c4ab73fe9c00000000000000004370044ee0b00235435d418e5279f8e0dd5673df40b1c5d1
Thu Mar  2 12:21:18 2017 : Debug: (5)  # Executing section authorize from file /etc/raddb/sites-enabled/inner-tunnel
Thu Mar  2 12:21:18 2017 : Debug: (5)    authorize {
Thu Mar  2 12:21:18 2017 : Debug: (5)   modsingle[authorize]: calling chap (rlm_chap) for request 5
Thu Mar  2 12:21:18 2017 : Debug: (5)  modsingle[authorize]: returned from chap (rlm_chap) for request 5
Thu Mar  2 12:21:18 2017 : Debug: (5)    [chap] = noop
Thu Mar  2 12:21:18 2017 : Debug: (5)   modsingle[authorize]: calling mschap (rlm_mschap) for request 5
Thu Mar  2 12:21:18 2017 : Debug: (5)   mschap : Found MS-CHAP attributes.  Setting 'Auth-Type  = mschap'
Thu Mar  2 12:21:18 2017 : Debug: (5)  modsingle[authorize]: returned from mschap (rlm_mschap) for request 5
Thu Mar  2 12:21:18 2017 : Debug: (5)    [mschap] = ok
Thu Mar  2 12:21:18 2017 : Debug: (5)   modsingle[authorize]: calling suffix (rlm_realm) for request 5
Thu Mar  2 12:21:18 2017 : Debug: (5)   suffix : Checking for suffix after "@"
Thu Mar  2 12:21:18 2017 : Debug: (5)   suffix : No '@' in User-Name = "0a-00-3e-40-58-80", looking up realm NULL
Thu Mar  2 12:21:18 2017 : Debug: (5)   suffix : No such realm "NULL"
Thu Mar  2 12:21:18 2017 : Debug: (5)  modsingle[authorize]: returned from suffix (rlm_realm) for request 5
Thu Mar  2 12:21:18 2017 : Debug: (5)    [suffix] = noop
Thu Mar  2 12:21:18 2017 : Debug: (5)    update control {
Thu Mar  2 12:21:18 2017 : Debug: (5)      Proxy-To-Realm := 'LOCAL'
Thu Mar  2 12:21:18 2017 : Debug: (5)    } # update control = noop
Thu Mar  2 12:21:18 2017 : Debug: (5)   modsingle[authorize]: calling eap (rlm_eap) for request 5
Thu Mar  2 12:21:18 2017 : Debug: (5)   eap : No EAP-Message, not doing EAP
Thu Mar  2 12:21:18 2017 : Debug: (5)  modsingle[authorize]: returned from eap (rlm_eap) for request 5
Thu Mar  2 12:21:18 2017 : Debug: (5)    [eap] = noop
Thu Mar  2 12:21:18 2017 : Debug: (5)   modsingle[authorize]: calling files (rlm_files) for request 5
Thu Mar  2 12:21:18 2017 : Debug: (5)   files : users: Matched entry 0a-00-3e-40-58-80 at line 69
Thu Mar  2 12:21:18 2017 : Debug: (5)   files : ::: FROM 7 TO 0 MAX 7
Thu Mar  2 12:21:18 2017 : Debug: (5)   files : ::: Examining Cambium-Canopy-LPDLCIR
Thu Mar  2 12:21:18 2017 : Debug: (5)   files : ::: APPENDING Cambium-Canopy-LPDLCIR FROM 0 TO 0
Thu Mar  2 12:21:18 2017 : Debug: (5)   files : ::: Examining Cambium-Canopy-LPULCIR
Thu Mar  2 12:21:18 2017 : Debug: (5)   files : ::: APPENDING Cambium-Canopy-LPULCIR FROM 1 TO 1
Thu Mar  2 12:21:18 2017 : Debug: (5)   files : ::: Examining Cambium-Canopy-DLBR
Thu Mar  2 12:21:18 2017 : Debug: (5)   files : ::: APPENDING Cambium-Canopy-DLBR FROM 2 TO 2
Thu Mar  2 12:21:18 2017 : Debug: (5)   files : ::: Examining Cambium-Canopy-DLBL
Thu Mar  2 12:21:18 2017 : Debug: (5)   files : ::: APPENDING Cambium-Canopy-DLBL FROM 3 TO 3
Thu Mar  2 12:21:18 2017 : Debug: (5)   files : ::: Examining Cambium-Canopy-ULBR
Thu Mar  2 12:21:18 2017 : Debug: (5)   files : ::: APPENDING Cambium-Canopy-ULBR FROM 4 TO 4
Thu Mar  2 12:21:18 2017 : Debug: (5)   files : ::: Examining Cambium-Canopy-ULBL
Thu Mar  2 12:21:18 2017 : Debug: (5)   files : ::: APPENDING Cambium-Canopy-ULBL FROM 5 TO 5
Thu Mar  2 12:21:18 2017 : Debug: (5)   files : ::: Examining Reply-Message
Thu Mar  2 12:21:18 2017 : Debug: (5)   files : ::: APPENDING Reply-Message FROM 6 TO 6
Thu Mar  2 12:21:18 2017 : Debug: (5)   files : ::: TO in 0 out 7
Thu Mar  2 12:21:18 2017 : Debug: (5)   files : ::: to[0] = Cambium-Canopy-LPDLCIR
Thu Mar  2 12:21:18 2017 : Debug: (5)   files : ::: to[1] = Cambium-Canopy-LPULCIR
Thu Mar  2 12:21:18 2017 : Debug: (5)   files : ::: to[2] = Cambium-Canopy-DLBR
Thu Mar  2 12:21:18 2017 : Debug: (5)   files : ::: to[3] = Cambium-Canopy-DLBL
Thu Mar  2 12:21:18 2017 : Debug: (5)   files : ::: to[4] = Cambium-Canopy-ULBR
Thu Mar  2 12:21:18 2017 : Debug: (5)   files : ::: to[5] = Cambium-Canopy-ULBL
Thu Mar  2 12:21:18 2017 : Debug: (5)   files : ::: to[6] = Reply-Message
Thu Mar  2 12:21:18 2017 : Debug: (5)  modsingle[authorize]: returned from files (rlm_files) for request 5
Thu Mar  2 12:21:18 2017 : Debug: (5)    [files] = ok
Thu Mar  2 12:21:18 2017 : Debug: (5)   modsingle[authorize]: calling expiration (rlm_expiration) for request 5
Thu Mar  2 12:21:18 2017 : Debug: (5)  modsingle[authorize]: returned from expiration (rlm_expiration) for request 5
Thu Mar  2 12:21:18 2017 : Debug: (5)    [expiration] = noop
Thu Mar  2 12:21:18 2017 : Debug: (5)   modsingle[authorize]: calling logintime (rlm_logintime) for request 5
Thu Mar  2 12:21:18 2017 : Debug: (5)  modsingle[authorize]: returned from logintime (rlm_logintime) for request 5
Thu Mar  2 12:21:18 2017 : Debug: (5)    [logintime] = noop
Thu Mar  2 12:21:18 2017 : Debug: (5)   modsingle[authorize]: calling pap (rlm_pap) for request 5
Thu Mar  2 12:21:18 2017 : WARNING: (5)   pap : Auth-Type already set.  Not setting to PAP
Thu Mar  2 12:21:18 2017 : Debug: (5)  modsingle[authorize]: returned from pap (rlm_pap) for request 5
Thu Mar  2 12:21:18 2017 : Debug: (5)    [pap] = noop
Thu Mar  2 12:21:18 2017 : Debug: (5)   } #  authorize = ok
Thu Mar  2 12:21:18 2017 : Debug: (5)  Found Auth-Type = MSCHAP
Thu Mar  2 12:21:18 2017 : Debug: (5)  # Executing group from file /etc/raddb/sites-enabled/inner-tunnel
Thu Mar  2 12:21:18 2017 : Debug: (5)   Auth-Type MS-CHAP {
Thu Mar  2 12:21:18 2017 : Debug: (5)   modsingle[authenticate]: calling mschap (rlm_mschap) for request 5
Thu Mar  2 12:21:18 2017 : Debug: (5)   mschap : Found Cleartext-Password, hashing to create LM-Password
Thu Mar  2 12:21:18 2017 : Debug: (5)   mschap : Found Cleartext-Password, hashing to create NT-Password
Thu Mar  2 12:21:18 2017 : Debug: (5)   mschap : Creating challenge hash with username: 0a-00-3e-40-58-80
Thu Mar  2 12:21:18 2017 : Debug: (5)   mschap : Client is using MS-CHAPv2
Thu Mar  2 12:21:18 2017 : Debug: (5)   mschap : Adding MS-CHAPv2 MPPE keys
Thu Mar  2 12:21:18 2017 : Debug: (5)  modsingle[authenticate]: returned from mschap (rlm_mschap) for request 5
Thu Mar  2 12:21:18 2017 : Debug: (5)    [mschap] = ok
Thu Mar  2 12:21:18 2017 : Debug: (5)   } # Auth-Type MS-CHAP = ok
Thu Mar  2 12:21:18 2017 : Debug: (5)  # Executing section post-auth from file /etc/raddb/sites-enabled/inner-tunnel
Thu Mar  2 12:21:18 2017 : Debug: (5)   post-auth { ... } # empty sub-section is ignored
Thu Mar  2 12:21:18 2017 : Debug: (5)    Reply:
    Cambium-Canopy-LPDLCIR = 200
    Cambium-Canopy-LPULCIR = 200
    Cambium-Canopy-DLBR = 200
    Cambium-Canopy-DLBL = 2000
    Cambium-Canopy-ULBR = 200
    Cambium-Canopy-ULBL = 2000
    Reply-Message = 'Hello from freeradius'
    MS-CHAP2-Success = 0x55533d30443744433731364644383541454542384242314446364541383530393241453945324633313242
    MS-MPPE-Recv-Key = 0x5a506c1522b7eb6b4dd5f04901a54cbd
    MS-MPPE-Send-Key = 0x9e0522d6a875426b8df6b466b3a5d168
    MS-MPPE-Encryption-Policy = Encryption-Allowed
    MS-MPPE-Encryption-Types = RC4-40or128-bit-Allowed
Thu Mar  2 12:21:18 2017 : Debug: (5)  } # server inner-tunnel
Thu Mar  2 12:21:18 2017 : Debug: (5)  eap_ttls : Got tunneled Access-Accept
Thu Mar  2 12:21:18 2017 : Debug: (5)  eap_ttls : Got MS-CHAP2-Success, tunneling it to the client in a challenge
Thu Mar  2 12:21:18 2017 : Debug: (5)  eap_ttls : sending tunneled reply attributes
    MS-CHAP2-Success = 0x55533d30443744433731364644383541454542384242314446364541383530393241453945324633313242
Thu Mar  2 12:21:18 2017 : Debug: (5)  eap_ttls : end tunneled reply attributes
Thu Mar  2 12:21:18 2017 : Debug: (5)  eap : New EAP session, adding 'State' attribute to reply 0x74f1779371f662bb
Thu Mar  2 12:21:18 2017 : Debug: (5) modsingle[authenticate]: returned from eap (rlm_eap) for request 5
Thu Mar  2 12:21:18 2017 : Debug: (5)   [eap] = handled
Thu Mar  2 12:21:18 2017 : Debug: (5)  } #  authenticate = handled
Thu Mar  2 12:21:18 2017 : Debug: (5) Sending Access-Challenge packet to host 192.168.2.250 port 1236, id=0, length=0
Thu Mar  2 12:21:18 2017 : Debug: (5)     EAP-Message = 0x0107005f1580000000551703010050e080602a5d8da450983f3eb248a59a72a0af31d5adf9ac9fa38cae0220299b422dd346782f9deba39bc642873f30a462fe8b983a9286795a8dfe977e15ca47c8d33cadcfceb944db9dc27435b9a762b3
Thu Mar  2 12:21:18 2017 : Debug: (5)     Message-Authenticator = 0x00000000000000000000000000000000
Thu Mar  2 12:21:18 2017 : Debug: (5)     State = 0x74f1779371f662bb24343c1c695e59ff
Sending Access-Challenge Id 0 from 192.168.2.235:1812 to 192.168.2.250:1236
    EAP-Message = 0x0107005f1580000000551703010050e080602a5d8da450983f3eb248a59a72a0af31d5adf9ac9fa38cae0220299b422dd346782f9deba39bc642873f30a462fe8b983a9286795a8dfe977e15ca47c8d33cadcfceb944db9dc27435b9a762b3
    Message-Authenticator = 0x00000000000000000000000000000000
    State = 0x74f1779371f662bb24343c1c695e59ff
Thu Mar  2 12:21:18 2017 : Debug: (5) Finished request

On AP check

Configuration → General Bandwidth Configuration Source

This should be set to Authentication server, only then VSA applied to SM.

Yes of course, it is.

Messsages from syslogserver:

Mar  2 21:22:37 192.168.2.250 CANOPY: state_table_event; table=RfSess; Event=Sync; NewState=Sync; Flag=0;
Mar  2 21:22:37 192.168.2.250 CANOPY: state_table_event; table=RfRegulatory; Event=Regulator Checks Passed. (RegPass); NewState=Active (REGPASSSTATE); Flag=0;
Mar  2 21:22:37 192.168.2.250 CANOPY: state_table_event; table=RfSess; Event=MsgForSync; NewState=Sync; Flag=0;
Mar  2 21:22:47 192.168.2.250 CANOPY: state_table_event; table=RfSync; Event=AP Sync; NewState=In Sync; Flag=0;
Mar  2 21:22:47 192.168.2.250 CANOPY: state_table_event; table=RfRegulatory; Event=Regulator Check Initiated. (RegCheck); NewState=Active (REGPASSSTATE); Flag=0;
Mar  2 21:22:47 192.168.2.250 CANOPY: state_table_event; table=RfSess; Event=Sync; NewState=Sync; Flag=0;
Mar  2 21:22:47 192.168.2.250 CANOPY: state_table_event; table=DfsInfo; Event=DFSEnable; NewState=Idle; Flag=0;
Mar  2 21:22:47 192.168.2.250 CANOPY: state_table_event; table=RfSess; Event=MsgForSync; NewState=Sync; Flag=0;
Mar  2 21:22:55 192.168.2.250 CANOPY: state_table_event; table=APAuthen[2]; Event=AUTHEN_REQ; NewState=AUTHENTICATING; Flag=0;
Mar  2 21:22:55 192.168.2.250 CANOPY: state_table_event; table=APSession[2]; Event=REGREQ; NewState=REGISTERING; Flag=0;
Mar  2 21:22:55 192.168.2.250 CANOPY: event; sm_auth_success; SM authentication success;
Mar  2 21:22:55 192.168.2.250 CANOPY: state_table_event; table=APAuthen[2]; Event=AUTHEN_SUC; NewState=AUTHENTICATED; Flag=0;
Mar  2 21:22:55 192.168.2.250 CANOPY: state_table_event; table=APAuthor[2]; Event=AUTHOR_REQ; NewState=AUTHORIZING; Flag=0;
Mar  2 21:22:55 192.168.2.250 CANOPY: state_table_event; table=APSession[2]; Event=AUTHEN_SUC; NewState=IN SESSION; Flag=0;
Mar  2 21:22:55 192.168.2.250 CANOPY: state_table_event; table=APAuthor[2]; Event=SET_PARAMS; NewState=AUTHORIZING; Flag=0;
Mar  2 21:22:55 192.168.2.250 CANOPY: state_table_event; table=APAuthor[2]; Event=SEND_PARAMS; NewState=AUTHORIZING; Flag=0;
Mar  2 21:22:56 192.168.2.250 CANOPY: state_table_event; table=APSession[2]; Event=SEND_AUTHOR_MSG; NewState=IN SESSION; Flag=0;
Mar  2 21:22:56 192.168.2.250 CANOPY: event; sm_register; Registered with 0a-00-3e-40-58-80;
Mar  2 21:22:56 192.168.2.250 CANOPY: state_table_event; table=APAuthor[2]; Event=AUTHOR_SUC; NewState=AUTHORIZED; Flag=0;
Mar  2 21:22:56 192.168.2.250 CANOPY: state_table_event; table=APSession[2]; Event=SES_MSG; MsgType=ESNQUERY; NewState=IN SESSION; Flag=0;
Mar  2 21:22:57 192.168.2.250 CANOPY: state_table_event; table=RfGps; Event=GPSTCXOCal; NewState=Idle; Flag=0;

These logs are OK, where are you seeing the SM QoS parameters from RADIUS.

Note that they will be displayed on AP -> Session Status List under configuration .

Please check.