internal authentication error

add to -logentrytypes   'SEC.AUTH:7'

thanks mike. I don't seem to get any errors in the log, but still get the internal error

so, my callback is authenticate.p

using Progress.Lang.*.

using Progress.Security.PAMStatus.

procedure AuthenticateUser:

def input parameter p_CP as handle no-undo.

def input parameter p_SystemOptions as char extent no-undo.

def output parameter op_PAMStatus as integer init ? no-undo.

def output parameter op_ErrorMsg as character no-undo.

assign op_PAMStatus = PAMStatus:Success.

return.

end.

procedure AfterSetIdentity:

def input parameter p_CP as handle no-undo.

def input parameter p_SystemOptions as character extent no-undo.

end.

and my code to start the auth process is

def var ClientPrincipal as handle no-undo.

   message "#1 start log entry" view-as alert-box.

LOG-MANAGER:LOG-ENTRY-TYPES = "SEC.AUTH:7".

message "#2 create cp" view-as alert-box.

create client-principal ClientPrincipal.

message "#3 initialize cp" view-as alert-box.

   ClientPrincipal:initialize (p_user,?,?,p_password).

message "#4 set-client" view-as alert-box.

security-policy:set-client(ClientPrincipal).

message "#5 complete" view-as alert-box.

and the result log is

[13/12/14@10:32:26.410+0000] P-004588 T-010104 1 WS -- (Procedure: 'Authenticate dotr.ember.lib.base.Authentication' Line:48) #1 start log entry

5,879

[13/12/14@10:32:26.410+0000] P-004588 T-010104 1 WS -- Log entry types activated: SEC.AUTH:7

5,880

[13/12/14@10:32:26.410+0000] P-004588 T-010104 1 WS -- (Procedure: 'Authenticate dotr.ember.lib.base.Authentication' Line:50) #2 create cp

5,881

[13/12/14@10:32:26.410+0000] P-004588 T-010104 1 WS -- (Procedure: 'Authenticate dotr.ember.lib.base.Authentication' Line:52) #3 initialize cp

5,882

[13/12/14@10:32:26.410+0000] P-004588 T-010104 1 WS -- (Procedure: 'Authenticate dotr.ember.lib.base.Authentication' Line:54) #4 set-client

5,883

[13/12/14@10:32:26.410+0000] P-004588 T-010104 3 WS SEC.AUTH       database: hash42: domain 'dotr': userid: 'hash42SuperUser': prosetcp/SET-DB-CLIENT/SET-CLIENT user authentication (16399)

5,884

[13/12/14@10:32:26.410+0000] P-004588 T-010104 3 WS SEC.AUTH       database: hash42: domain 'dotr': userid: 'hash42SuperUser': proAuth - authenticate user (16399)

5,885

[13/12/14@10:32:26.410+0000] P-004588 T-010104 3 WS SEC.AUTH       database: hash42: domain 'dotr': userid: 'hash42SuperUser': proAuth - check user account status (16399)

5,886

[13/12/14@10:32:26.410+0000] P-004588 T-010104 2 WS SEC.AUTH       Execute callback AuthenticateUser in dotr\hash42\helper\authenticate.p for domain dotr

5,887

[13/12/14@10:32:26.410+0000] P-004588 T-010104 2 WS SEC.AUTH       Callback AuthenticateUser for domain dotr returned 1

5,888

[13/12/14@10:32:26.410+0000] P-004588 T-010104 3 WS SEC.AUTH       database: hash42: domain 'dotr': userid: 'hash42SuperUser': prosetcp/SET-DB-CLIENT/SET-CLIENT user authentication (16399)

5,889

[13/12/14@10:32:26.410+0000] P-004588 T-010104 3 WS SEC.AUTH       database: hash42: domain 'dotr': userid: 'hash42SuperUser': proAuth - authenticate user (16399)

5,890

[13/12/14@10:32:26.410+0000] P-004588 T-010104 4 WS SEC.AUTH       database hash42: domain 'dotr': userid: 'hash42SuperUser': proAuth/pam_authenticate [3] (16400)

5,891

[13/12/14@10:32:26.410+0000] P-004588 T-010104 4 WS SEC.AUTH       database hash42: domain 'dotr': userid: 'hash42SuperUser': prosetcp/proPamAuth [3] (16400)

Drat, I can see that it is getting an internal error [3] from a lower level subsystem, but that subsystem's logging is not turned on by default.

Can you now define the environment variable 'PSC_AUTH_DEBUG=D' before you run the ABL client.   That will add even more information to the client log.   If there is a way to attach or send me the log file rather than posting it as text that would be better.

log file attached.

The internal service error (#3) appears to be related to:

database: hash42: PAM module: 3 : Error decryptAndSealHandle failed with domain key decrypt error (16572)

database: hash42: PAM module: 3 :  Error pam_authenticate failed to seal pam handle (16572)

database hash42: domain 'dotr': userid: 'hash42SuperUser': proAuth/pam_authenticate [3] (16400)

Interpretation:  The domain's _Domain-access-code field was corrupt/invalid

Did you set the domain's access code with anything other than the DataAdmin utility?

No, didn't use the DataAdmin, as the application needs to create tenants as and when needed, not through the data asdmin. So, I used the tenant interface programming guide .

[snip]

oService:CreateTenant(oTenant).

oDomain = oService:NewDomain(this-object:Name).

assign oDomain:AuthenticationSystem = oService:GetAuthenticationSystem("hash42":u)

       oDomain:AccessCode           = hex-encode(message-digest("SHA-512",<data>,<hash>)

         oDomain:tenant               = oTenant.

oService:CreateDomain(oDomain).

[snip]

Can't say that I've ever looked closely at the class's interface, but I know that technically the following line cannot work when assigning a value to a Domain access code:

     oDomain:AccessCode           = hex-encode(message-digest("SHA-512",<data>,<hash>)

That is what is causing your error.

this is from "programming interfaces" manual

Why is the code broken ?

Ok, I overstated.   The normal method of manually storing a domain access code is through recording an encrypted value generated through the use of Security-Policy:Encrypt-Audit-Mac-Key(), and that was not in your code.   The doc just says use a variable, which doesn't help much in this case.  Unraveling the Domain class source showed that this encryption operation is being done for you.  So yes, I spoke to soon and in theory your code could work, but it obviously fails for some reason.

Back to the error you are seeing:  the debug log showed the error is occurring during the process of sealing the Client-Principal after your callback returns a success.   The first thing the seal operation does is to decrypt the encrypted value stored in the _sec_authentication-domain' s  _Domain-access-code field.   When decrypting the domain access code OE detected that the field's stored value was corrupted.   So the source of the corruption needs to be isolated to the application code, the Domain class, or OE internal.

This is as much information as I have without going through a debug session - which in any event should be done outside of this forum.   How would you like to proceed?

I've found and fixed the problem - at a guess your internal domain class uses a temp-table or a database table and indexes the access code field.

The problem is the length of the access code. if you change the length to 110 or less, it works fine. ;)

perhaps this needs to be documented. ;) Or, better still, remove the silly 127-byte limit on index fields !! It's 2014, give or take a day or several ...

Most happy you found the problem.   Yes, I do seem to remember seeing the Domain class using a temp-table.   Yes, the documentation should be enhanced to include a length restriction and a clear definition that the input property AccessCode's value will encrypt the value for you.  

Mike, just wanted to say thanks for all the support on this one. Appreciate that you were out there on a weekend !

thanks ;)

the maximum key size has been larger than that for a long time. as recall, it is over 3000 bytes. you must be hitting some other limit.

interesting. I did occasionally see the error

bfx: Field too large for a data item. Try to increase -s. (42)

as well -  although not all the time.