Development #71396
Les tests ECP sont devenus lents
Début:
17 novembre 2022
Echéance:
% réalisé:
0%
Temps estimé:
Patch proposed:
Oui
Planning:
Non
Description
Je n'en connais pas encore la cause mais sur une debian unstable les tests ECP sont beaucoup plus lent qu'avant, sur jenkins ça continue à aller vite.
Fichiers
Révisions associées
Historique
Mis à jour par Benjamin Dauvergne il y a plus d'un an
- Sujet changé de Les tests ECP sont devenus lent... à Les tests ECP sont devenus lents
Mis à jour par Benjamin Dauvergne il y a plus d'un an
Vraiment zarbi, ici classé par la magnitude du changement, les tests, avec le temps sur jenkins en buster, puis le temps sur sid.
test09_test_deserialization 0.00095 0.00073 0.77 test10_test_alldumps 0.00379 0.00312 0.82 test08_test_new_from_xmlNode 0.00030 0.00026 0.85 test07_registry_functional_mapping 0.00007 0.00006 0.92 test01_server_load_dump_empty_string 0.00006 0.00005 0.95 test02_server_load_dump_random_string 0.00015 0.00015 0.95 test03_server_load_dump_random_xml 0.00017 0.00016 0.97 test06_registry_direct_mapping 0.00006 0.00007 1.03 test15_ds_key_info 0.00049 0.00052 1.08 remove_warning_when_parssing_unknown_SNIPPET_LIST_NODES_20111007 0.00024 0.00032 1.32 test04_identity_load_dump_null 0.00002 0.00003 1.33 indexed_endpoints_20101008 0.00031 0.00045 1.43 test05_identity_load_dump_empty 0.00003 0.00005 1.56 test05_xsi_type 0.00032 0.00052 1.61 test06_lib_statuscode 0.00022 0.00046 2.06 test04_node_new_from_dump 0.00027 0.00059 2.17 test08_lasso_key 0.00117 0.00510 4.37 test04_multiple_dump_cycle 0.00356 0.01562 4.39 test01_server_new 0.00073 0.00323 4.41 test01_generateServersContextDumps 0.00097 0.00517 5.33 test02_provider_new_from_dump 0.00073 0.00391 5.37 test01_provider_new 0.00045 0.00262 5.77 test02_server_add_provider 0.00056 0.00336 5.95 test03_server_new_from_dump 0.00100 0.00673 6.77 test14_lasso_key 0.00037 0.00306 8.24 test03_serviceProviderLogin 0.01000 0.09536 9.53 test07_saml2_query_verify_signature 0.00045 0.00473 10.57 test02_serviceProviderLogin 0.01079 0.13168 12.21 test01_googleapps_27092010 0.00241 0.06882 28.57 test08_test_authnrequest_flags 0.01608 0.49773 30.95 test06_sso_sp_with_key_rollover 0.02864 0.90925 31.75 test16_test_get_issuer 0.00681 0.24818 36.42 test13_sso_sp_with_rsa_sha256_signatures 0.00581 0.24637 42.38 test02_saml2_serviceProviderLogin 0.02190 0.96095 43.89 test04_sso_then_slo_soap 0.02179 1.00039 45.91 test05_sso_idp_with_key_rollover 0.00892 0.47112 52.81 test11_ecp 0.01412 0.89178 63.14 test09_ecp 0.01414 0.89346 63.20 test01_metadata_load_der_certificate_from_x509_cert 0.00048 0.03048 63.24 test10_ecp 0.01413 0.90154 63.79 test02_metadata_load_pem_certificate_from_x509_cert 0.00047 0.03354 70.76 test12_ecp 0.08967 6.40321 71.41 test11_get_default_name_id_format 0.00082 0.05976 72.61 test07_sso_sp_with_hmac_sha256_signatures 0.00329 0.24474 74.43 test03_saml2_serviceProviderLogin 0.01351 1.05156 77.83 test06_metadata_load_public_key_from_rsa_keyvalue 0.00039 0.03186 81.06 test03_metadata_load_der_public_key_from_keyvalue 0.00049 0.04056 82.28 test05_metadata_load_public_key_from_x509_cert 0.00046 0.03971 86.70 test04_metadata_load_pem_public_key_from_keyvalue 0.00036 0.03271 90.35 test13_test_lasso_server_load_metadata 0.04429 4.03512 91.11 wrong_endpoint_index_in_artifacts 0.00107 0.09894 92.64 test07_metadata_role_descriptors 0.00067 0.06432 95.71 malformed_logout_request 0.00102 0.12716 124.42 test01_saml2_generateServersContextDumps 0.00176 0.25519 144.99
Strace avant, classé par nombre et type d'appel système:
1 access
1 arch_prctl
1 execve
1 +++ exited with 0 +++
1 exit_group
1 getrandom
1 prlimit64
1 rt_sigprocmask
1 set_robust_list
1 set_tid_address
3 munmap
5 getcwd
8 rt_sigaction
24 futex
28 mprotect
60 fcntl
60 lseek
60 unlink
66 brk
103 mmap
108 timer_create
108 timer_delete
514 close
514 fstat
587 read
592 getpid
1311 openat
1505 write
6484 stat
et après (sid, lent) :
1 access
1 arch_prctl
1 execve
1 +++ exited with 0 +++
1 exit_group
1 prlimit64
1 rseq
1 set_robust_list
1 set_tid_address
1 sysinfo
3 getrandom
3 munmap
4 pread64
5 getcwd
6 rt_sigaction
20 futex
23 mprotect
60 fcntl
60 lseek
60 unlink
83 brk
96 mmap
108 timer_create
108 timer_delete
279 getpid
1120 close
1308 openat
1505 write
9845 newfstatat
30379 read
Ça lit beaucoup plus, et donc la réponse c'est que j'ai un cert.pem et pas la machine jenkins...
openat(AT_FDCWD, "/usr/lib/ssl/cert.pem", O_RDONLY) = -1 ENOENT (Aucun fichier ou dossier de ce type) openat(AT_FDCWD, "/usr/lib/ssl/cert.pem", O_RDONLY) = -1 ENOENT (Aucun fichier ou dossier de ce type)
openat(AT_FDCWD, "/usr/lib/ssl/cert.pem", O_RDONLY) = 4
newfstatat(4, "", {st_mode=S_IFREG|0644, st_size=195453, ...}, AT_EMPTY_PATH) = 0
read(4, "-----BEGIN CERTIFICATE-----\nMIIH"..., 4096) = 4096
read(4, "QAL\ne3KHwGCmSUyIWOYdiPcUZEim2FgK"..., 4096) = 4096
Alors possible que ça ait toujours été lent :
Breakpoint 2, __libc_open64 (file=file@entry=0x7ffff798912f "/usr/lib/ssl/cert.pem", oflag=0) at ../sysdeps/unix/sysv/linux/open64.c:30
30 in ../sysdeps/unix/sysv/linux/open64.c
(gdb) bt
#0 __libc_open64 (file=file@entry=0x7ffff798912f "/usr/lib/ssl/cert.pem", oflag=0) at ../sysdeps/unix/sysv/linux/open64.c:30
#1 0x00007ffff727fe22 in __GI__IO_file_open
(fp=fp@entry=0x555555690000, filename=filename@entry=0x7ffff798912f "/usr/lib/ssl/cert.pem", posix_mode=<optimized out>, prot=prot@entry=438, read_write=8, is32not64=<optimized out>)
at ./libio/fileops.c:188
#2 0x00007ffff727fffb in _IO_new_file_fopen (fp=fp@entry=0x555555690000, filename=filename@entry=0x7ffff798912f "/usr/lib/ssl/cert.pem", mode=<optimized out>,
mode@entry=0x7ffff794a540 "r", is32not64=is32not64@entry=1) at ./libio/fileops.c:280
#3 0x00007ffff7274679 in __fopen_internal (filename=0x7ffff798912f "/usr/lib/ssl/cert.pem", mode=0x7ffff794a540 "r", is32=1) at ./libio/iofopen.c:75
#4 0x00007ffff77108d3 in BIO_new_file () at /lib/x86_64-linux-gnu/libcrypto.so.3
#5 0x00007ffff78baf9c in X509_load_cert_crl_file_ex () at /lib/x86_64-linux-gnu/libcrypto.so.3
#6 0x00007ffff78bb1b4 in () at /lib/x86_64-linux-gnu/libcrypto.so.3
#7 0x00007ffff78d5736 in X509_STORE_set_default_paths_ex () at /lib/x86_64-linux-gnu/libcrypto.so.3
#8 0x00007ffff7dcc28b in () at /lib/x86_64-linux-gnu/libxmlsec1-openssl.so.1
#9 0x00007ffff7d4ce99 in xmlSecKeyDataStoreCreate () at /lib/x86_64-linux-gnu/libxmlsec1.so.1
#10 0x00007ffff7dae95d in xmlSecOpenSSLKeysMngrInit () at /lib/x86_64-linux-gnu/libxmlsec1-openssl.so.1
#11 0x00007ffff7daafc4 in xmlSecOpenSSLAppDefaultKeysMngrInit () at /lib/x86_64-linux-gnu/libxmlsec1-openssl.so.1
#12 0x000055555559aa6d in lasso_xmlsec_load_key_info (key_descriptor=0x55555568a740) at tools.c:2689
On va voir pour ne pas tenter d'ouvrir cert.pem, on ne vérifie de toute façon aucune chaîne de certification dans lasso.
Mis à jour par Benjamin Dauvergne il y a plus d'un an
- Fichier 0001-Prevent-loading-of-default-cert-file-during-tests-71.patch 0001-Prevent-loading-of-default-cert-file-during-tests-71.patch ajouté
- Statut changé de Nouveau à Solution proposée
- Patch proposed changé de Non à Oui
Ce n'est pas vraiment la correction mais au moins les tests vont plus vite.
Mis à jour par Benjamin Dauvergne il y a plus d'un an
On peut rien faire de mieux, le chargement du keystore local est en dur dans le code de libxmlsec pour le backend openssl et le seul moyen de contrôle c'est la variable d'environnement SSL_CERT_FILE que je ne peux pas me permettre de modifier dans lasso (j'ai peur d'un effet de bord quand lasso est utilisé avec des threads).
Mis à jour par Pierre Ducroquet il y a plus d'un an
- Statut changé de Solution proposée à Solution validée
J'aime bien les hacks
Mis à jour par Benjamin Dauvergne il y a plus d'un an
- Statut changé de Solution validée à Résolu (à déployer)
commit 0705940804c8f5652167e5bc61099e75949d93bd
Author: Benjamin Dauvergne <bdauvergne@entrouvert.com>
Date: Thu Nov 17 16:48:20 2022 +0100
Prevent loading of default cert file during tests (#71396)
Prevent loading of default cert file during tests (#71396)