Server's CertificateUserManager does'n work

[che2116]

Describe the bug
The server returns error: BadUserAccessDenied, when client tries to connect to the server with valid certificate and private key.

To Reproduce

1. Run server-with-encryption.py from examples directory.
2. Run UaExpert (v.1.5.1) as an OPC UA client.
3. In the UaExpert add new connection in the authentication settings select the certificate (examples/certificates/peer-certificate-example-1.der) and the private key (examples/certificates/peer-private-key-example-1.pem).
4. Try to connect to the server.
5. Server returns error BadUserAccessDenied

Expected behavior
The server must establish a connection with client.

Version
Python-Version: 3.8.5
opcua-asyncio Version: master branch

[ZuZuD]

I gave a try to server-with-encryption.py and it works like a charm from the asyncua client:

import sys
import asyncio
from asyncua.crypto import security_policies
from asyncua import ua, Client


c = Client(url="opc.tcp://127.0.0.1:4840");
cert = "../examples/certificates/peer-certificate-example-1.der"
key = "../examples/certificates/peer-private-key-example-1.pem"
await c.set_security(
        security_policies.SecurityPolicyBasic256Sha256,
        cert,
        key,
        mode=ua.MessageSecurityMode.SignAndEncrypt
)
await c.connect()
print(await c.get_node("ns=0;i=20001").read_browse_name())
print(await c.get_node("ns=0;i=20002").read_browse_name())
print(await c.get_node("ns=0;i=20002").read_value())

It prints

QualifiedName(0:MyObject)
QualifiedName(0:MyVariable)
0.2

And from the server side:

[...]
INFO:asyncua.server.internal_session:Created internal session ('127.0.0.1', 39150)
INFO:asyncua.server.internal_session:Create session request
INFO:asyncua.server.internal_server:get endpoint
INFO:asyncua.server.uaprocessor:Activate session request (None)
INFO:asyncua.server.internal_session:activate session
INFO:asyncua.server.internal_session:Activated internal session ('127.0.0.1', 39150) for user User(role=<UserRole.User: 3>, name='test_user')
INFO:asyncua.server.uaprocessor:Read request (User(role=<UserRole.User: 3>, name='test_user'))
INFO:asyncua.server.uaprocessor:Read request (User(role=<UserRole.User: 3>, name='test_user'))
INFO:asyncua.server.uaprocessor:Read request (User(role=<UserRole.User: 3>, name='test_user'))

What are the client settings you are trying to connect with? Can you provide the server logs? I hope the above example will help.

[AndreasHeine]

with uaexpert it asks for a pw (to decrypt) and its actually not provided by us ^^ (only @JoeyFaulkner knows the pw i guess) maybe making your own certs an keys solve it!

[JoeyFaulkner]

Oh damn! I didn't think I did put a password on them.. we should replace these with passwordless ones if so!

[che2116]

Private keys from examples/certficates are not encrypted. Open it in an editor and you will see -----BEGIN PRIVATE KEY-----. Encrypted private keys have -----BEGIN ENCRYPTED PRIVATE KEY-----.

[che2116]

Can you provide the server logs?

Here it is. Log level = DEBUG.

DEBUG:asyncio:Using selector: EpollSelector
INFO:asyncua.server.internal_session:Created internal session Internal
INFO:asyncua.server.address_space:add_node: while adding node i=15957, requested parent node i=11715 does not exists
INFO:asyncua.server.address_space:add_node: while adding node i=15958, requested parent node i=15957 does not exists
INFO:asyncua.server.address_space:add_node: while adding node i=15959, requested parent node i=15957 does not exists
INFO:asyncua.server.address_space:add_node: while adding node i=15960, requested parent node i=15957 does not exists
INFO:asyncua.server.address_space:add_node: while adding node i=15961, requested parent node i=15957 does not exists
INFO:asyncua.server.address_space:add_node: while adding node i=15962, requested parent node i=15957 does not exists
INFO:asyncua.server.address_space:add_node: while adding node i=15963, requested parent node i=15957 does not exists
INFO:asyncua.server.address_space:add_node: while adding node i=15964, requested parent node i=15957 does not exists
INFO:asyncua.server.address_space:add_node: while adding node i=16134, requested parent node i=15957 does not exists
INFO:asyncua.server.address_space:add_node: while adding node i=16135, requested parent node i=15957 does not exists
INFO:asyncua.server.address_space:add_node: while adding node i=16136, requested parent node i=15957 does not exists
INFO:asyncua.server.internal_server:starting internal server
INFO:asyncua.server.binary_server_asyncio:Listening on 0.0.0.0:4840
DEBUG:asyncua.server.server:OPC UA Server(opc.tcp://0.0.0.0:4840/freeopcua/server/) server started
INFO:asyncua.server.binary_server_asyncio:New connection from ('127.0.0.1', 46150)
DEBUG:asyncua.server.binary_server_asyncio:_process_received_message 66 66
DEBUG:asyncua.server.binary_server_asyncio:_process_received_message 121 121
DEBUG:asyncua.server.binary_server_asyncio:_process_received_message 99 99
DEBUG:asyncua.server.uaprocessor:process_message FourByteNodeId(i=428) RequestHeader(AuthenticationToken:i=0, Timestamp:2021-02-02 12:46:58.424948, RequestHandle:1, ReturnDiagnostics:0, AuditEntryId:None, TimeoutHint:10000, AdditionalHeader:None)
INFO:asyncua.server.uaprocessor:get endpoints request (None)
INFO:asyncua.server.internal_server:get endpoint
DEBUG:asyncua.server.binary_server_asyncio:_process_received_message 45 45
INFO:asyncua.server.binary_server_asyncio:processor returned False, we close connection from ('127.0.0.1', 46150)
INFO:asyncua.server.binary_server_asyncio:Lost connection from ('127.0.0.1', 46150), None
INFO:asyncua.server.uaprocessor:Cleanup client connection: ('127.0.0.1', 46150)
INFO:asyncua.server.binary_server_asyncio:New connection from ('127.0.0.1', 46152)
DEBUG:asyncua.server.binary_server_asyncio:_process_received_message 66 66
DEBUG:asyncua.server.binary_server_asyncio:_process_received_message 1766 1766
DEBUG:asyncua.server.binary_server_asyncio:_process_received_message 1524 1524
DEBUG:asyncua.server.uaprocessor:process_message FourByteNodeId(i=461) RequestHeader(AuthenticationToken:i=1001, Timestamp:2021-02-02 12:46:58.593125, RequestHandle:1000007, ReturnDiagnostics:0, AuditEntryId:None, TimeoutHint:10000, AdditionalHeader:None)
INFO:asyncua.server.uaprocessor:Create session request (None)
INFO:asyncua.server.internal_session:Created internal session ('127.0.0.1', 46152)
INFO:asyncua.server.internal_session:Create session request
INFO:asyncua.server.internal_server:get endpoint
DEBUG:asyncua.server.binary_server_asyncio:_process_received_message 1652 1652
DEBUG:asyncua.server.uaprocessor:process_message FourByteNodeId(i=467) RequestHeader(AuthenticationToken:i=1001, Timestamp:2021-02-02 12:46:58.606655, RequestHandle:1000008, ReturnDiagnostics:0, AuditEntryId:None, TimeoutHint:10000, AdditionalHeader:None)
INFO:asyncua.server.uaprocessor:Activate session request (None)
INFO:asyncua.server.internal_session:activate session
ERROR:asyncua.server.uaprocessor:sending service fault response: "User does not have permission to perform the requested operation." (BadUserAccessDenied)
DEBUG:asyncua.server.binary_server_asyncio:_process_received_message 84 84
DEBUG:asyncua.server.uaprocessor:process_message FourByteNodeId(i=473) RequestHeader(AuthenticationToken:i=1001, Timestamp:2021-02-02 12:46:58.628276, RequestHandle:1000009, ReturnDiagnostics:0, AuditEntryId:None, TimeoutHint:10000, AdditionalHeader:None)
WARNING:asyncua.server.uaprocessor:User(role=<UserRole.Anonymous: 1>, name=None) attempted to do something they are not permitted to do
INFO:asyncua.server.binary_server_asyncio:processor returned False, we close connection from ('127.0.0.1', 46152)
INFO:asyncua.server.binary_server_asyncio:Lost connection from ('127.0.0.1', 46152), None
INFO:asyncua.server.uaprocessor:Cleanup client connection: ('127.0.0.1', 46152)
INFO:asyncua.server.internal_session:close session ('127.0.0.1', 46152)
INFO:asyncua.server.subscription_service:delete subscriptions: []

[che2116]

UaExpert log

15:56:55.641 | Server Node        | FreeOpcUa Python Server        | Endpoint: 'opc.tcp://127.0.0.1:4840/freeopcua/server/'
15:56:55.641 | Server Node        | FreeOpcUa Python Server        | Security policy: 'http://opcfoundation.org/UA/SecurityPolicy#Basic256Sha256'
15:56:55.641 | Server Node        | FreeOpcUa Python Server        | ApplicationUri: 'urn:freeopcua:python:server'
15:56:55.641 | Server Node        | FreeOpcUa Python Server        | Used UserTokenType: Certificate
15:56:55.787 | Server Node        | FreeOpcUa Python Server        | Error 'BadUserAccessDenied' was returned during ActivateSession
15:56:55.791 | Server Node        | FreeOpcUa Python Server        | Connection status of server 'FreeOpcUa Python Server' changed to 'Disconnected'.

[AndreasHeine]

if you add uaexperts cert to the usermanager it should work (maybe something is wrong with the example certs... expiring in two months) await cert_user_manager.add_user("uaexpert.der", name='test_user')

@JoeyFaulkner do we verify the subjectAltname extension (host, ip, applicationuri)?

[JoeyFaulkner]

I'm not sure! Good question. My code used higher level certificate API so I'm not sure whether that's something they do

[araisch]

Same here with a self-signed User Certificate: Does not work, but UAExpert User Certificate does. User(role=<UserRole.Anonymous: 1>, name=None) attempted to do something they are not permitted to do Some property is checked in the cert, leading to that failure. If no one knows that I will investigate ("trial and error"), but would be great if anyone knows where to search :)

[janmuc]

@araisch did you maybe find the solution to the problem? I am having the same issue. Or even someone else?

[ratara]

My UA Expert client exactly states the failure. So server identification and identification in the certificate do not equal which leads to denied access. I try to set the server identification to check this out. - Keep you posted.

[AndreasHeine]

@ratara for sure they have to match! the certs have to have a subAltname extension with matching uri and ip of the python server.

[ratara]

Ok, the uri constraint is accepted, if I change the application uri to the one in the certificate. -> Real fix: Change the used certificate to use the right uri.

@AndreasHeine You are right. The IP address or DNS name is also missing in the cert, which possibly denies the access. Besides the certificate also does not provide KeyUsage and ExtendedKeyUsage fields although they are mandatory according to the opc ua spec.

I suggest to create new default certificates with all required fields and their right content for this example.

[ratara]

I generated public and private key like in your tutorial: https://github.com/FreeOpcUa/opcua-asyncio/blob/master/examples/generate_certificate.sh

I had to change the uri to the one used in the server and it worked.

I feel not like to change certificates in your project, so I this task has to be done by somebody.

Update I did not check the certificate for the user authentication.

[AndreasHeine]

the bad thing about certs they expire... the good thing about certs they expire... safer! 😅

[ratara]

Update: The user certificate is indeed password protected. We should replace it as proposed by @JoeyFaulkner

[TobiasNils]

Works for Sign as well as SignAndEncrypt policies.