[BUG] Task fails with 'SSL alert number 40' error

[andylamb-rlg]

Describe the bug The AzureLoadTest@1 task fails with an SSL handshake error:

EPROTO 139788598056768:error:14094410:SSL routines:ssl3_read_bytes:sslv3 alert handshake failure:../deps/openssl/openssl/ssl/record/rec_layer_s3.c:1544:SSL alert number 40

Do I need to configure the SSL version/cipher suite somewhere?

Expected behavior Load Test should start successfully.

Logs Debug output from AzureLoadTest@1 task:

2023-01-13T15:48:31.9207510Z ##[section]Starting: AzureLoadTest
2023-01-13T15:48:31.9217033Z ==============================================================================
2023-01-13T15:48:31.9217258Z Task         : Azure Load Testing
2023-01-13T15:48:31.9217398Z Description  : Automate performance regression testing with Azure Load Testing
2023-01-13T15:48:31.9217590Z Version      : 1.2.18
2023-01-13T15:48:31.9217726Z Author       : Microsoft Corporation
2023-01-13T15:48:31.9217900Z Help         : https://docs.microsoft.com/azure/load-testing/tutorial-cicd-azure-pipelines#azure-load-testing-task
2023-01-13T15:48:31.9218153Z ==============================================================================
2023-01-13T15:48:31.9927105Z ##[debug]Using node path: /agent/externals/node10/bin/node
2023-01-13T15:48:32.1051395Z ##[debug]agent.TempDirectory=/agent/_work/_temp
2023-01-13T15:48:32.1074149Z ##[debug]loading inputs and endpoints
2023-01-13T15:48:32.1084252Z ##[debug]loading INPUT_CONNECTEDSERVICENAMEARM
2023-01-13T15:48:32.1098883Z ##[debug]loading INPUT_LOADTESTCONFIGFILE
2023-01-13T15:48:32.1100842Z ##[debug]loading INPUT_RESOURCEGROUP
2023-01-13T15:48:32.1102490Z ##[debug]loading INPUT_LOADTESTRESOURCE
2023-01-13T15:48:32.1106756Z ##[debug]loading ENDPOINT_AUTH_<redacted-sp-id>
2023-01-13T15:48:32.1109008Z ##[debug]loading ENDPOINT_AUTH_SCHEME_<redacted-sp-id>
2023-01-13T15:48:32.1111039Z ##[debug]loading ENDPOINT_AUTH_PARAMETER_<redacted-sp-id>_SERVICEPRINCIPALID
2023-01-13T15:48:32.1113524Z ##[debug]loading ENDPOINT_AUTH_PARAMETER_<redacted-sp-id>_AUTHENTICATIONTYPE
2023-01-13T15:48:32.1115572Z ##[debug]loading ENDPOINT_AUTH_PARAMETER_<redacted-sp-id>_TENANTID
2023-01-13T15:48:32.1117617Z ##[debug]loading ENDPOINT_AUTH_PARAMETER_<redacted-sp-id>_SERVICEPRINCIPALKEY
2023-01-13T15:48:32.1119071Z ##[debug]loading ENDPOINT_AUTH_SYSTEMVSSCONNECTION
2023-01-13T15:48:32.1120363Z ##[debug]loading ENDPOINT_AUTH_SCHEME_SYSTEMVSSCONNECTION
2023-01-13T15:48:32.1121797Z ##[debug]loading ENDPOINT_AUTH_PARAMETER_SYSTEMVSSCONNECTION_ACCESSTOKEN
2023-01-13T15:48:32.1123278Z ##[debug]loading SECRET_SYSTEM_ACCESSTOKEN
2023-01-13T15:48:32.1124593Z ##[debug]loaded 14
2023-01-13T15:48:32.1129191Z ##[debug]Agent.ProxyUrl=undefined
2023-01-13T15:48:32.1130741Z ##[debug]Agent.CAInfo=undefined
2023-01-13T15:48:32.1131766Z ##[debug]Agent.ClientCert=undefined
2023-01-13T15:48:32.1136399Z ##[debug]Agent.SkipCertValidation=undefined
2023-01-13T15:48:32.2248897Z ##[debug]connectedServiceNameARM=<redacted-sp-id>
2023-01-13T15:48:32.2250837Z ##[debug]<redacted-sp-id> auth param serviceprincipalid = ***
2023-01-13T15:48:32.2252850Z ##[debug]<redacted-sp-id> auth param serviceprincipalkey = ***
2023-01-13T15:48:32.2254624Z ##[debug]<redacted-sp-id> data SubscriptionID = <redacted-sub-id>
2023-01-13T15:48:32.2257366Z ##[debug]<redacted-sp-id> auth param tenantid = <redacted-tenant-id>
2023-01-13T15:48:32.2258947Z ##[debug]loadTestConfigFile=/agent/_work/4/s/.ci/perf/config-dev.yml
2023-01-13T15:48:32.2309744Z ##[debug]secrets=undefined
2023-01-13T15:48:32.2310892Z ##[debug]env=undefined
2023-01-13T15:48:32.2312750Z ##[debug]resourceGroup=<redacted-resource-group-name>
2023-01-13T15:48:32.2314036Z ##[debug]loadTestResource=<redacted-loadtest-resource-name>
2023-01-13T15:48:32.9143491Z ##[debug]task result: Failed
2023-01-13T15:48:32.9180539Z ##[error]write EPROTO 139788598056768:error:14094410:SSL routines:ssl3_read_bytes:sslv3 alert handshake failure:../deps/openssl/openssl/ssl/record/rec_layer_s3.c:1544:SSL alert number 40

2023-01-13T15:48:32.9195612Z ##[debug]Processed: ##vso[task.issue type=error;]write EPROTO 139788598056768:error:14094410:SSL routines:ssl3_read_bytes:sslv3 alert handshake failure:../deps/openssl/openssl/ssl/record/rec_layer_s3.c:1544:SSL alert number 40%0A
2023-01-13T15:48:32.9208483Z ##[debug]Processed: ##vso[task.complete result=Failed;]write EPROTO 139788598056768:error:14094410:SSL routines:ssl3_read_bytes:sslv3 alert handshake failure:../deps/openssl/openssl/ssl/record/rec_layer_s3.c:1544:SSL alert number 40%0A
2023-01-13T15:48:32.9245794Z ##[section]Finishing: AzureLoadTest

Cross-posting from https://github.com/Azure/load-testing/issues/26 which seems to be an unmonitored project?

AB#1719886

[Nagarjuna-Vipparthi]

@andylamb-rlg Thank you for reaching out. We are looking into the issue and will get back to you. Meanwhile, can you please check and confirm if the service principal is not expired and has the required permissions?

[andylamb-rlg]

Thanks @Nagarjuna-Vipparthi, the Service Principal has not expired and as far as I'm aware it has all the permissions required, according to the documentation.

[andylamb-rlg]

Hi, @Nagarjuna-Vipparthi, did you find anything useful, regarding this issue? Thanks.

[andylamb-rlg]

Some additional detail... I've run some tests using cURL against the loadtesting.azure.com URL where I'm seeing the error.

curl -v 'https://uksouth.cnt-prod.loadtesting.azure.com/health' is successful and returns:

2023-01-27T10:38:19.0291572Z   % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
2023-01-27T10:38:19.0292883Z                                  Dload  Upload   Total   Spent    Left  Speed
2023-01-27T10:38:19.0293950Z 
2023-01-27T10:38:19.0569409Z   0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0*   Trying 20.90.234.208...
2023-01-27T10:38:19.0570841Z * TCP_NODELAY set
2023-01-27T10:38:19.0583373Z * Connected to uksouth.cnt-prod.loadtesting.azure.com (20.90.234.208) port 443 (#0)
2023-01-27T10:38:19.0592324Z * ALPN, offering h2
2023-01-27T10:38:19.0593212Z * ALPN, offering http/1.1
2023-01-27T10:38:19.0650356Z * successfully set certificate verify locations:
2023-01-27T10:38:19.0651827Z *   CAfile: /etc/ssl/certs/ca-certificates.crt
2023-01-27T10:38:19.0652299Z   CApath: /etc/ssl/certs
2023-01-27T10:38:19.0658374Z } [5 bytes data]
2023-01-27T10:38:19.0659056Z * TLSv1.3 (OUT), TLS handshake, Client hello (1):
2023-01-27T10:38:19.0659552Z } [512 bytes data]
2023-01-27T10:38:19.0703694Z * TLSv1.3 (IN), TLS handshake, Server hello (2):
2023-01-27T10:38:19.0705541Z { [97 bytes data]
2023-01-27T10:38:19.0796222Z * TLSv1.2 (IN), TLS handshake, Certificate (11):
2023-01-27T10:38:19.0804449Z { [4861 bytes data]
2023-01-27T10:38:19.0806814Z * TLSv1.2 (IN), TLS handshake, Server key exchange (12):
2023-01-27T10:38:19.0808868Z { [556 bytes data]
2023-01-27T10:38:19.0812530Z * TLSv1.2 (IN), TLS handshake, Server finished (14):
2023-01-27T10:38:19.0813366Z { [4 bytes data]
2023-01-27T10:38:19.0814131Z * TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
2023-01-27T10:38:19.0814660Z } [37 bytes data]
2023-01-27T10:38:19.0819966Z * TLSv1.2 (OUT), TLS change cipher, Client hello (1):
2023-01-27T10:38:19.0820653Z } [1 bytes data]
2023-01-27T10:38:19.0821506Z * TLSv1.2 (OUT), TLS handshake, Finished (20):
2023-01-27T10:38:19.0822158Z } [16 bytes data]
2023-01-27T10:38:19.0825932Z * TLSv1.2 (IN), TLS handshake, Finished (20):
2023-01-27T10:38:19.0826497Z { [16 bytes data]
2023-01-27T10:38:19.0827832Z * SSL connection using TLSv1.2 / ECDHE-RSA-AES256-GCM-SHA384
2023-01-27T10:38:19.0966410Z * ALPN, server did not agree to a protocol
2023-01-27T10:38:19.0967368Z * Server certificate:
2023-01-27T10:38:19.0973400Z *  subject: CN=Azure Firewall Manager CA; CN=uksouth.cnt-prod.loadtesting.azure.com
2023-01-27T10:38:19.0974073Z *  start date: Jan 26 10:38:18 2023 GMT
2023-01-27T10:38:19.0974589Z *  expire date: Jan 27 10:38:18 2024 GMT
2023-01-27T10:38:19.0975710Z *  subjectAltName: host "uksouth.cnt-prod.loadtesting.azure.com" matched cert's "uksouth.cnt-prod.loadtesting.azure.com"
2023-01-27T10:38:19.0976404Z *  issuer: CN=Azure Firewall Manager CA
2023-01-27T10:38:19.0976890Z *  SSL certificate verify ok.
2023-01-27T10:38:19.0977425Z } [5 bytes data]
2023-01-27T10:38:19.0978130Z > GET /health HTTP/1.1
2023-01-27T10:38:19.0979195Z > Host: uksouth.cnt-prod.loadtesting.azure.com
2023-01-27T10:38:19.0980051Z > User-Agent: curl/7.58.0
2023-01-27T10:38:19.0980519Z > Accept: */*
2023-01-27T10:38:19.0980888Z > 
2023-01-27T10:38:19.1269703Z { [5 bytes data]
2023-01-27T10:38:19.1270235Z < HTTP/1.1 500 Internal Server Error
2023-01-27T10:38:19.1271607Z < content-type: text/plain; charset=utf-8
2023-01-27T10:38:19.1272555Z < x-content-type-options: nosniff
2023-01-27T10:38:19.1273091Z < date: Fri, 27 Jan 2023 10:38:19 GMT
2023-01-27T10:38:19.1273815Z < content-length: 89
2023-01-27T10:38:19.1274186Z < 
2023-01-27T10:38:19.1274552Z { [89 bytes data]
2023-01-27T10:38:19.1274708Z 
2023-01-27T10:38:19.1280460Z 100    89  100    89    0     0    908      0 --:--:-- --:--:-- --:--:--   908
2023-01-27T10:38:19.1281488Z * Connection #0 to host uksouth.cnt-prod.loadtesting.azure.com left intact
2023-01-27T10:38:19.1286921Z x509: certificate is valid for ingress.local, not uksouth.cnt-prod.loadtesting.azure.com

curl -v 'https://d25c908e-6bfd-4fd5-b44d-e6237608b43e.uksouth.cnt-prod.loadtesting.azure.com/health' is unsuccessful and returns:

2023-01-27T10:38:20.4090029Z   % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
2023-01-27T10:38:20.4091641Z                                  Dload  Upload   Total   Spent    Left  Speed
2023-01-27T10:38:20.4092325Z 
2023-01-27T10:38:20.4207595Z   0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0*   Trying 20.90.234.208...
2023-01-27T10:38:20.4208821Z * TCP_NODELAY set
2023-01-27T10:38:20.4221762Z * Connected to d25c908e-6bfd-4fd5-b44d-e6237608b43e.uksouth.cnt-prod.loadtesting.azure.com (20.90.234.208) port 443 (#0)
2023-01-27T10:38:20.4230179Z * ALPN, offering h2
2023-01-27T10:38:20.4230997Z * ALPN, offering http/1.1
2023-01-27T10:38:20.4287395Z * successfully set certificate verify locations:
2023-01-27T10:38:20.4288872Z *   CAfile: /etc/ssl/certs/ca-certificates.crt
2023-01-27T10:38:20.4289471Z   CApath: /etc/ssl/certs
2023-01-27T10:38:20.4294660Z } [5 bytes data]
2023-01-27T10:38:20.4295450Z * TLSv1.3 (OUT), TLS handshake, Client hello (1):
2023-01-27T10:38:20.4296193Z } [512 bytes data]
2023-01-27T10:38:20.4336735Z * TLSv1.3 (IN), TLS alert, Server hello (2):
2023-01-27T10:38:20.4338375Z { [2 bytes data]
2023-01-27T10:38:20.4339072Z * error:14094410:SSL routines:ssl3_read_bytes:sslv3 alert handshake failure
2023-01-27T10:38:20.4339773Z * stopped the pause stream!
2023-01-27T10:38:20.4342821Z 
2023-01-27T10:38:20.4347464Z   0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
2023-01-27T10:38:20.4348417Z * Closing connection 0
2023-01-27T10:38:20.4359899Z curl: (35) error:14094410:SSL routines:ssl3_read_bytes:sslv3 alert handshake failure

So the issue seems specific to the sub-domain.

[Nagarjuna-Vipparthi]

@andylamb-rlg Apologies for the delay. Thank you for sharing additional information. Will get back to you soon on this.

[Nagarjuna-Vipparthi]

@andylamb-rlg We were not able to reproduce the error on our end. Sharing links (to some relevant issues) that can help you fix any issues at your end.

https://serverfault.com/questions/889631/curl-fails-to-retrieve-https-content-error14094410ssl-routinesssl3-read-byte https://stefanos.cloud/kb/error-cannot-resolve-the-ssl-host-name-ssl-error-40-in-citrix-virtual-apps-and-desktops/#:~:text=This%20issue%27s%20root%20cause%20is,Clear%20your%20browser%20cache.

Please let us know if you are still facing the issue.

Tagging @mohitpavan as FYI

[andylamb-rlg]

Thanks @Nagarjuna-Vipparthi, but the links haven't helped... I can force the curl request to use the same TLS version and cipher on the subdomain as on the root domain, but it doesn't make a difference. I'm getting the same behaviour from multiple machines, so I don't think it's a local cache issue.

[Nagarjuna-Vipparthi]

@andylamb-rlg Can you please send an email to 'azloadfeedback@microsoft.com' so that we can set up a meeting to discuss and resolve this issue? Thanks

[andylamb-rlg]

Thanks for the offer, @Nagarjuna-Vipparthi, but we've moved to an alternative solution for load testing now as we couldn't get passed this issue.