Bug 1044666

Summary: Can curl HTTPS requests make fewer access system calls?
Product: Red Hat Enterprise Linux 6 Reporter: Peter Edwards <thatsafunnyname>
Component: nss-softoknAssignee: Elio Maldonado Batiz <emaldona>
Status: CLOSED ERRATA QA Contact: Alicja Kario <hkario>
Severity: medium Docs Contact:
Priority: medium    
Version: 6.4CC: hkario, kdudka, kustodian, matti, pchavan, rrelyea
Target Milestone: rc   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: nss-softokn-3.14.3-12.el6 Doc Type: Bug Fix
Doc Text:
Cause: The NSS did not check whether the NSS_SDB_USE_CACHE environment variable was set to trye before calling the sdb_measureAccess internal function. Consequence: When using curl or libcurl, which depennds on nss, to make a HTTPS requests there were many "access" system calls to paths/directories/files that do not exist, and this bloated the dentry_cache. Fix: NSS now avoids calls to sdb_measureAccess in lib/softoken/sdb.c s_open if NSS_SDB_USE_CACHE is "yes" Result: The system calls to non-existent paths have gone down and curl HTTPS requests not longer cause bloats in in the directory entry cache.
Story Points: ---
Clone Of:
: 1117959 (view as bug list) Environment:
Last Closed: 2014-10-14 05:03:26 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 994246, 1056252, 1117959    

Description Peter Edwards 2013-12-18 19:20:12 UTC
Description of problem:

When using curl 7.19.7-37.el6_4, or libcurl on RHEL 6.4 to make a HTTPS request there are many "access" system calls to paths/directories/files that do not exist, this bloats the dentry_cache.

Version-Release number of selected component (if applicable):

curl 7.19.7-37.el6_4.x86_64 on RHEL 6.4
nss 3.14.3-4.el6_4.x86_64

I also tested 3.15.1-15.el6, and 7.29.0-12.el7 on RHEL 7.0 Beta.

How reproducible:

Very, strace curl making a HTTPS request.
Watch dentry_cache size in "slabtop".

Steps to Reproduce:

strace -fc -e trace=access curl 'https://www.google.com' > /dev/null

Actual results:

  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
131   262  131   262    0     0   1564      0 --:--:-- --:--:-- --:--:-- 13789
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
100.00    0.000598           0      1576      1574 access
------ ----------- ----------- --------- --------- ----------------
100.00    0.000598                  1576      1574 total

Expected results:

Less calls to directories that do not exist, dentry_cache not bloated in size.
I did not find an option to change this behaviour, I was able to use the environment variable SSL_DIR to change the path being used but this did not change the behaviour.

Additional info:
 
strace -f -e trace=access curl 'https://www.google.com'
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb", W_OK)          = -1 EACCES (Permission denied)
access("/hhoudini/.pki/nssdb/.2777916463_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916464_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916465_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916466_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916467_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916468_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916469_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916470_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916471_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916472_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916473_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916474_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916475_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916476_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916477_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916478_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916479_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916480_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916481_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916482_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916483_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916484_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916485_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916486_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916487_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916488_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916489_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916490_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916491_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916492_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916493_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916494_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916495_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916496_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916497_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916498_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916499_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916500_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916501_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916502_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916503_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916504_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916505_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916506_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916507_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916508_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916509_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916510_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916511_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916512_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916513_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916514_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916515_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916516_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916517_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916518_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916519_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916520_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916521_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916522_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916523_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916524_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916525_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916526_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916527_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916528_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916529_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916530_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916531_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916532_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916533_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916534_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916535_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916536_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916537_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916538_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916539_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916540_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916541_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916542_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916543_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916544_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916545_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916546_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916547_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916548_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916549_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916550_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916551_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916552_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916553_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916554_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916555_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916556_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916557_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916558_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916559_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916560_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916561_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916562_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916563_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916564_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916565_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916566_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916567_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916568_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916569_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/.2777916570_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/cert9.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/cert8.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/cert7.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/cert6.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/cert5.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/cert4.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/cert3.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/cert2.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/key3.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/key2.db", F_OK) = -1 ENOENT (No such file or directory)
access("/hhoudini/.pki/nssdb/secmod.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916496_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916497_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916498_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916499_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916500_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916501_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916502_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916503_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916504_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916505_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916506_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916507_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916508_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916509_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916510_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916511_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916512_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916513_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916514_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916515_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916516_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916517_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916518_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916519_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916520_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916521_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916522_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916523_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916524_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916525_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916526_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916527_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916528_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916529_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916530_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916531_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916532_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916533_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916534_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916535_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916536_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916537_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916538_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916539_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916540_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916541_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916542_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916543_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916544_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916545_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916546_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916547_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916548_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916549_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916550_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916551_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916552_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916553_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916554_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916555_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916556_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916557_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916558_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916559_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916560_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916561_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916562_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916563_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916564_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916565_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916566_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916567_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916568_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916569_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916570_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916571_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916572_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916573_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916574_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916575_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916576_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916577_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916578_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916579_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916580_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916581_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916582_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916583_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916584_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916585_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916586_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916587_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916588_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916589_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916590_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916591_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916592_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916593_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916594_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916595_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916596_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916597_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916598_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916599_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916600_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916601_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916602_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916603_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916604_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916605_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916606_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/.2777916607_dOeSnotExist_.db", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/cert9.db", F_OK) = 0
access("/etc/pki/nssdb/cert9.db-journal", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/key4.db", F_OK)  = 0
access("/etc/pki/nssdb/key4.db-journal", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/key4.db-journal", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/key4.db-journal", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/key4.db-journal", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/cert9.db-journal", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/cert9.db-journal", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/cert9.db-journal", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/cert9.db-journal", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/cert9.db-journal", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/cert9.db-journal", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/cert9.db-journal", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/cert9.db-journal", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/cert9.db-journal", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/cert9.db-journal", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/cert9.db-journal", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/cert9.db-journal", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/cert9.db-journal", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/cert9.db-journal", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/pki/nssdb/cert9.db-journal", F_OK) = -1 ENOENT (No such file or directory)
 
Just to show how big the dentry_cache was:
 
  OBJS ACTIVE  USE OBJ SIZE  SLABS OBJ/SLAB CACHE SIZE NAME
182485800 182485794   5%    0.19K 9124290       20  36497160K dentry
2816736 1883738  66%    0.10K  76128       37    304512K buffer_head
393547 359443  91%    0.20K  20713       19     82852K vm_area_struct
231910 190008  81%    0.55K  33130        7    132520K radix_tree_node
194887 157962  81%    0.05K   2531       77     10124K anon_vma_chain
174380 118313  67%    0.19K   8719       20     34876K filp
169924 137070  80%    0.04K   1847       92      7388K anon_vma
159975 159922  99%    1.02K  53325        3    213300K nfs_inode_cache
 
Also reported here:
  http://curl.haxx.se/mail/tracker-2013-06/0114.html

Comment 2 Peter Edwards 2013-12-19 15:56:22 UTC
I noticed:
 
valgrind --trace-children=yes curl 'https://google.com'
 
reports "possibly lost: 176 bytes in 4 blocks"
 
40 bytes in 1 blocks are possibly lost in loss record 44 of 101
   at 0x4A072CB: malloc (vg_replace_malloc.c:263)
   by 0x314B20D78B: ??? (in /lib64/libnspr4.so)
   by 0x314B225014: ??? (in /lib64/libnspr4.so)
   by 0x314B226210: PR_Socket (in /lib64/libnspr4.so)
   by 0x38AD840637: Curl_nss_connect (in /usr/lib64/libcurl.so.4.1.1)
   by 0x38AD838481: Curl_ssl_connect (in /usr/lib64/libcurl.so.4.1.1)
   by 0x38AD816ECA: Curl_http_connect (in /usr/lib64/libcurl.so.4.1.1)
   by 0x38AD81D681: Curl_protocol_connect (in /usr/lib64/libcurl.so.4.1.1)
   by 0x38AD823B3B: Curl_connect (in /usr/lib64/libcurl.so.4.1.1)
   by 0x38AD82BBAF: Curl_perform (in /usr/lib64/libcurl.so.4.1.1)
   by 0x40875F: ??? (in /usr/bin/curl)
   by 0x3146E1ECDC: (below main) (in /lib64/libc-2.12.so)
 
40 bytes in 1 blocks are possibly lost in loss record 45 of 101
   at 0x4A072CB: malloc (vg_replace_malloc.c:263)
   by 0x314B20D78B: ??? (in /lib64/libnspr4.so)
   by 0x314B225014: ??? (in /lib64/libnspr4.so)
   by 0x314B2253D8: PR_OpenFile (in /lib64/libnspr4.so)
   by 0x5742CB4: ???
   by 0x574052A: ???
   by 0x57458C8: ???
   by 0x574C521: ???
   by 0x314B6470C9: ??? (in /usr/lib64/libnss3.so)
   by 0x314B647362: PK11_CreateGenericObject (in /usr/lib64/libnss3.so)
   by 0x38AD83F49F: ??? (in /usr/lib64/libcurl.so.4.1.1)
   by 0x38AD83F626: ??? (in /usr/lib64/libcurl.so.4.1.1)
 
48 bytes in 1 blocks are possibly lost in loss record 49 of 101
   at 0x4A072CB: malloc (vg_replace_malloc.c:263)
   by 0x314B20D779: ??? (in /lib64/libnspr4.so)
   by 0x314B225014: ??? (in /lib64/libnspr4.so)
   by 0x314B226210: PR_Socket (in /lib64/libnspr4.so)
   by 0x38AD840637: Curl_nss_connect (in /usr/lib64/libcurl.so.4.1.1)
   by 0x38AD838481: Curl_ssl_connect (in /usr/lib64/libcurl.so.4.1.1)
   by 0x38AD816ECA: Curl_http_connect (in /usr/lib64/libcurl.so.4.1.1)
   by 0x38AD81D681: Curl_protocol_connect (in /usr/lib64/libcurl.so.4.1.1)
   by 0x38AD823B3B: Curl_connect (in /usr/lib64/libcurl.so.4.1.1)
   by 0x38AD82BBAF: Curl_perform (in /usr/lib64/libcurl.so.4.1.1)
   by 0x40875F: ??? (in /usr/bin/curl)
   by 0x3146E1ECDC: (below main) (in /lib64/libc-2.12.so)
 
48 bytes in 1 blocks are possibly lost in loss record 50 of 101
   at 0x4A072CB: malloc (vg_replace_malloc.c:263)
   by 0x314B20D779: ??? (in /lib64/libnspr4.so)
   by 0x314B225014: ??? (in /lib64/libnspr4.so)
   by 0x314B2253D8: PR_OpenFile (in /lib64/libnspr4.so)
   by 0x5742CB4: ???
   by 0x574052A: ???
   by 0x57458C8: ???
   by 0x574C521: ???
   by 0x314B6470C9: ??? (in /usr/lib64/libnss3.so)
   by 0x314B647362: PK11_CreateGenericObject (in /usr/lib64/libnss3.so)
   by 0x38AD83F49F: ??? (in /usr/lib64/libcurl.so.4.1.1)
   by 0x38AD83F626: ??? (in /usr/lib64/libcurl.so.4.1.1)
 
I don't know if these are false.  I found:
 
  https://bugzilla.redhat.com/show_bug.cgi?id=1007603#c13
 
nss is also using sqlite.
 
Thanks.

Comment 3 Kamil Dudka 2013-12-19 16:47:32 UTC
The certificate database is manipulated by NSS.  I am switching the component...

Comment 4 Peter Edwards 2013-12-19 17:01:42 UTC
I created a support request:
  https://access.redhat.com/support/cases/01002015/

Comment 5 Peter Edwards 2013-12-20 11:47:29 UTC
Here is a reproducer showing how a single process making sequential HTTPS requests using curl can cause significant increases in the dentry cache (and slab), after running:
 
echo 2 > /proc/sys/vm/drop_caches
 
as root, then run this command as non root, replace the url with a HTTPS server you are responsible for:
 
/bin/egrep 'Slab|claim' /proc/meminfo ; /usr/bin/slabtop -o | /bin/egrep 'Slab|SLAB|dent' ; /usr/bin/perl -e 'foreach(1..1000){print q{.}.`/usr/bin/curl --silent https://replace-with-a-server-you-admin.com/does_not_exist.html > /dev/null`};print qq{\n}' ; /usr/bin/slabtop -o | /bin/egrep 'Slab|SLAB|dent' ;  /bin/egrep 'Slab|claim' /proc/meminfo
 
First run:
 
Slab:             291652 kB
SReclaimable:     212536 kB
SUnreclaim:        79116 kB
 Active / Total Slabs (% used)      : 68277 / 68291 (100.0%)
  OBJS ACTIVE  USE OBJ SIZE  SLABS OBJ/SLAB CACHE SIZE NAME
 51320  18890  36%    0.19K   2566       20     10264K dentry
...<removed>...
 Active / Total Slabs (% used)      : 74055 / 74079 (100.0%)
  OBJS ACTIVE  USE OBJ SIZE  SLABS OBJ/SLAB CACHE SIZE NAME
145380 145380 100%    0.19K   7269       20     29076K dentry
Slab:             314800 kB
SReclaimable:     235300 kB
SUnreclaim:        79500 kB
 
after 15 more runs the 16th run looks like this:
 
Slab:             646524 kB
SReclaimable:     567352 kB
SUnreclaim:        79172 kB
 Active / Total Slabs (% used)      : 157004 / 157014 (100.0%)
  OBJS ACTIVE  USE OBJ SIZE  SLABS OBJ/SLAB CACHE SIZE NAME
1792780 1792780 100%    0.19K  89639       20    358556K dentry
...<removed>...
 Active / Total Slabs (% used)      : 162842 / 162861 (100.0%)
  OBJS ACTIVE  USE OBJ SIZE  SLABS OBJ/SLAB CACHE SIZE NAME
1907720 1907720 100%    0.19K  95386       20    381544K dentry
Slab:             669860 kB
SReclaimable:     590196 kB
SUnreclaim:        79664 kB
 
Slab more than doubled in size and the dentry cache size and number of objects increased to 37 times the initial sizes.
 
It would be great if curl (libcurl) could be used to make HTTPS connections/requests and not have the nss library nss-3.14.3/mozilla/security/nss/lib/softoken/sdb.c:sdb_measureAccess() "find out how expensive the access system call is for non-existant files in the given directory.  Return the number of operations done in 33 ms".  When sdb_measureAccess() is called from sdb_init it uses the environment variable NSS_SDB_USE_CACHE to control if the cache is used or not ("yes" or "no"), however in s_open it is called without examining the environment variable NSS_SDB_USE_CACHE.
 
    /* how long does it take to test for a non-existant file in our working
     * directory? Allows us to test if we may be on a network file system */
    accessOps = sdb_measureAccess(directory);
 
Changed from 200 iterations in:
 https://hg.mozilla.org/projects/nss/diff/4d876e0ee318/security/nss/lib/softoken/sdb.c 
added in:
 https://hg.mozilla.org/projects/nss/annotate/198b92c76b08/security/nss/lib/softoken/sdb.c
for:
 https://bugzilla.mozilla.org/show_bug.cgi?id=391294 
 
On a RHEL5.9 the same command does not cause a significant increase in dentry_cache/slab, curl being built with OpenSSL and not NSS.
 
Thanks.

Comment 7 Peter Edwards 2013-12-29 09:08:52 UTC
Here is a reproducer without curl, using nss-3.15.1-15.el6 and the code from curl-7.19.7/lib/nss.c (curl-7.19.7-37.el6_4)
 
cat test.cxx
#include <stdio.h>
#include <nss.h>
 
int main(int argc, char* argv[]) {
 
  NSSInitParameters initparams;
  memset((void *) &initparams, '\0', sizeof(initparams));
  initparams.length = sizeof(initparams);
 
#define SSL_PATH "sql:/etc/pki/nssdb"
  char *certpath;
  certpath = (char *)SSL_PATH;
  printf("NSS_InitContext(%s\n",certpath);
  NSSInitContext * nss_context = NULL;
  nss_context = NSS_InitContext(certpath, "", "", "", &initparams, NSS_INIT_READONLY | NSS_INIT_PK11RELOAD);
 
  if(nss_context != NULL){
    printf("nss_context != NULL\n");
  } else {
    printf("nss_context == NULL\n");
  }
 
  return 0;
}
 
g++ -g -I/usr/include/nspr4 -I/usr/include/nss3 -lnss3 -lssl3 test.cxx -o test
 
strace -cfe trace=access ./test
NSS_InitContext(sql:/etc/pki/nssdb
nss_context != NULL
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
100.00    0.001080           1      1189      1185 access
------ ----------- ----------- --------- --------- ----------------
100.00    0.001080                  1189      1185 total

gdb backtraces with a breakpoint on sdb_measureAccess
 
#0  sdb_measureAccess (directory=0x60aab4 "/cchaplin/.pki/nssdb") at sdb.c:360
#1  0x00007ffff761c90c in s_open (directory=0x60aab4 "/cchaplin/.pki/nssdb", certPrefix=<value optimized out>, keyPrefix=0x608440 "",
    cert_version=<value optimized out>, key_version=<value optimized out>, flags=1, certdb=0x7fffffffe2a8, keydb=0x7fffffffe2b0, newInit=0x7fffffffe2c8) at sdb.c:2016
#2  0x00007ffff7621bd6 in sftk_DBInit (configdir=0x60aab0 "sql:/cchaplin/.pki/nssdb", certPrefix=0x606550 "", keyPrefix=0x608440 "", updatedir=<value optimized out>,
    updCertPrefix=0x0, updKeyPrefix=0x0, updateID=0x60d8b0 "", readOnly=1, noCertDB=0, noKeyDB=0, forceOpen=0, isFIPS=0, certDB=0x7fffffffe368, keyDB=0x7fffffffe360)
    at sftkdb.c:2611
#3  0x00007ffff7608ebb in SFTK_SlotReInit (slot=0x629c20, configdir=<value optimized out>, updatedir=<value optimized out>, updateID=<value optimized out>, params=0x60e2e8,
    moduleIndex=0) at pkcs11.c:2362
#4  0x00007ffff76091ce in SFTK_SlotInit (configdir=0x60aab0 "sql:/cchaplin/.pki/nssdb", updatedir=0x608700 "", updateID=0x60d8b0 "", params=0x60e2e8, moduleIndex=0)
    at pkcs11.c:2474
#5  0x00007ffff76095f6 in nsc_CommonInitialize (pReserved=<value optimized out>, isFIPS=<value optimized out>) at pkcs11.c:2905
#6  0x00007ffff76096b7 in NSC_Initialize (pReserved=0x7fffffffe520) at pkcs11.c:2967
#7  0x00007ffff7cf6467 in secmod_ModuleInit (mod=0x607790, reload=0x7fffffffe668, alreadyLoaded=0x7fffffffe5bc) at pk11load.c:221
#8  0x00007ffff7cf6de7 in secmod_LoadPKCS11Module (mod=0x607790, oldModule=0x7fffffffe668) at pk11load.c:457
#9  0x00007ffff7d0a6ea in SECMOD_LoadModule (
    modulespec=0x607100 "library= module=\"NSS User database\" parameters=\"configdir='sql:/cchaplin/.pki/nssdb'  certPrefix='' keyPrefix='' secmod='' flags=readOnly updatedir='' updateCertPrefix='' updateKeyPrefix='' "..., parent=0x6067d0, recurse=1) at pk11pars.c:1010
#10 0x00007ffff7d0a7e0 in SECMOD_LoadModule (
    modulespec=0x6065d0 "library=\"libnsssysinit.so\" name=\"NSS Internal PKCS #11 Module\" NSS=\"Flags=internal,moduleDBOnly,critical trustOrder=75 cipherOrder=100 slotParams=(1={slotFlags=[RSA,DSA,DH,RC2,RC4,DES,RANDOM,SHA1,MD5,"..., parent=<value optimized out>, recurse=<value optimized out>) at pk11pars.c:1045
#11 0x00007ffff7d0a7e0 in SECMOD_LoadModule (
    modulespec=0x603d70 "name=\"NSS Internal Module\" parameters=\"configdir='sql:/etc/pki/nssdb' certPrefix='' keyPrefix='' secmod='' flags=readOnly updatedir='' updateCertPrefix='' updateKeyPrefix='' updateid='' updateTokenDes"..., parent=<value optimized out>, recurse=<value optimized out>) at pk11pars.c:1045
#12 0x00007ffff7cd9a94 in nss_InitModules (configdir=0x400928 "sql:/etc/pki/nssdb", certPrefix=<value optimized out>, keyPrefix=<value optimized out>, secmodName=0x40094f "",
    updateDir=<value optimized out>, updCertPrefix=0x603d10 "Linux2.6_x86_64_glibc_PTH_64_OPT.OBJ/lib/libsoftokn3.so", updKeyPrefix=0x7ffff7dbefc3 "",
    updateID=0x7ffff7dbefc3 "", updateName=0x7ffff7dbefc3 "", initContextPtr=0x7fffffffe908, initParams=0x7fffffffe930, readOnly=1, noCertDB=0, noModDB=0, forceOpen=0,
    noRootInit=1, optimizeSpace=0, noSingleThreadedModules=0, allowAlreadyInitializedModules=1, dontFinalizeModules=0) at nssinit.c:435
#13 nss_Init (configdir=0x400928 "sql:/etc/pki/nssdb", certPrefix=<value optimized out>, keyPrefix=<value optimized out>, secmodName=0x40094f "",
    updateDir=<value optimized out>, updCertPrefix=0x603d10 "Linux2.6_x86_64_glibc_PTH_64_OPT.OBJ/lib/libsoftokn3.so", updKeyPrefix=0x7ffff7dbefc3 "",
    updateID=0x7ffff7dbefc3 "", updateName=0x7ffff7dbefc3 "", initContextPtr=0x7fffffffe908, initParams=0x7fffffffe930, readOnly=1, noCertDB=0, noModDB=0, forceOpen=0,
    noRootInit=1, optimizeSpace=0, noSingleThreadedModules=0, allowAlreadyInitializedModules=1, dontFinalizeModules=0) at nssinit.c:639
#14 0x00007ffff7cda261 in NSS_InitContext (configdir=<value optimized out>, certPrefix=<value optimized out>, keyPrefix=<value optimized out>, secmodName=<value optimized out>,
    initParams=<value optimized out>, flags=<value optimized out>) at nssinit.c:834
#15 0x00000000004007fe in main (argc=1, argv=0x7fffffffea78) at test.cxx:15
 
#0  sdb_measureAccess (directory=0x60e254 "/etc/pki/nssdb") at sdb.c:360
#1  0x00007ffff761c90c in s_open (directory=0x60e254 "/etc/pki/nssdb", certPrefix=<value optimized out>, keyPrefix=0x0, cert_version=<value optimized out>,
    key_version=<value optimized out>, flags=1, certdb=0x7fffffffe1b8, keydb=0x7fffffffe1c0, newInit=0x7fffffffe1d8) at sdb.c:2016
#2  0x00007ffff7621bd6 in sftk_DBInit (configdir=0x60e250 "sql:/etc/pki/nssdb", certPrefix=0x0, keyPrefix=0x0, updatedir=<value optimized out>, updCertPrefix=0x0,
    updKeyPrefix=0x0, updateID=0x0, readOnly=1, noCertDB=0, noKeyDB=0, forceOpen=0, isFIPS=0, certDB=0x7fffffffe278, keyDB=0x7fffffffe270) at sftkdb.c:2611
#3  0x00007ffff7608ebb in SFTK_SlotReInit (slot=0x652dd0, configdir=<value optimized out>, updatedir=<value optimized out>, updateID=<value optimized out>, params=0x652d50,
    moduleIndex=0) at pkcs11.c:2362
#4  0x00007ffff76091ce in SFTK_SlotInit (configdir=0x0, updatedir=0x0, updateID=0x0, params=0x652d50, moduleIndex=0) at pkcs11.c:2474
#5  0x00007ffff760bc6b in sftk_CreateNewSlot (hSession=1, pTemplate=<value optimized out>, ulCount=<value optimized out>, phObject=0x7fffffffe488) at pkcs11.c:4027
#6  NSC_CreateObject (hSession=1, pTemplate=<value optimized out>, ulCount=<value optimized out>, phObject=0x7fffffffe488) at pkcs11.c:4094
#7  0x00007ffff7d0689a in PK11_CreateNewObject (slot=0x64fd00, session=1, theTemplate=<value optimized out>, count=2, token=0, objectID=<value optimized out>) at pk11obj.c:378
#8  0x00007ffff7d16dc1 in secmod_UserDBOp (slot=0x64fd00, objClass=3461563221, sendSpec=<value optimized out>) at pk11util.c:1281
#9  0x00007ffff7d175b5 in SECMOD_OpenNewSlot (mod=0x607790, moduleSpec=<value optimized out>) at pk11util.c:1388
#10 0x00007ffff7cf65a2 in secmod_handleReload (mod=0x647d40, reload=0x7fffffffe668, alreadyLoaded=0x7fffffffe5bc) at pk11load.c:142
#11 secmod_ModuleInit (mod=0x647d40, reload=0x7fffffffe668, alreadyLoaded=0x7fffffffe5bc) at pk11load.c:234
#12 0x00007ffff7cf6de7 in secmod_LoadPKCS11Module (mod=0x647d40, oldModule=0x7fffffffe668) at pk11load.c:457
#13 0x00007ffff7d0a6ea in SECMOD_LoadModule (
    modulespec=0x607420 "library= module=\"NSS system database\" parameters=\"configdir='sql:/etc/pki/nssdb' tokenDescription='NSS system database' flags=readonly\" NSS=\"trustOrder=80 cipherOrder=100 slotParams={0x00000001=[slotF"..., parent=0x6067d0, recurse=1) at pk11pars.c:1010
#14 0x00007ffff7d0a7e0 in SECMOD_LoadModule (
    modulespec=0x6065d0 "library=\"libnsssysinit.so\" name=\"NSS Internal PKCS #11 Module\" NSS=\"Flags=internal,moduleDBOnly,critical trustOrder=75 cipherOrder=100 slotParams=(1={slotFlags=[RSA,DSA,DH,RC2,RC4,DES,RANDOM,SHA1,MD5,"..., parent=<value optimized out>, recurse=<value optimized out>) at pk11pars.c:1045
#15 0x00007ffff7d0a7e0 in SECMOD_LoadModule (
    modulespec=0x603d70 "name=\"NSS Internal Module\" parameters=\"configdir='sql:/etc/pki/nssdb' certPrefix='' keyPrefix='' secmod='' flags=readOnly updatedir='' updateCertPrefix='' updateKeyPrefix='' updateid='' updateTokenDes"..., parent=<value optimized out>, recurse=<value optimized out>) at pk11pars.c:1045
#16 0x00007ffff7cd9a94 in nss_InitModules (configdir=0x400928 "sql:/etc/pki/nssdb", certPrefix=<value optimized out>, keyPrefix=<value optimized out>, secmodName=0x40094f "",
    updateDir=<value optimized out>, updCertPrefix=0x603d10 "Linux2.6_x86_64_glibc_PTH_64_OPT.OBJ/lib/libsoftokn3.so", updKeyPrefix=0x7ffff7dbefc3 "",
    updateID=0x7ffff7dbefc3 "", updateName=0x7ffff7dbefc3 "", initContextPtr=0x7fffffffe908, initParams=0x7fffffffe930, readOnly=1, noCertDB=0, noModDB=0, forceOpen=0,
    noRootInit=1, optimizeSpace=0, noSingleThreadedModules=0, allowAlreadyInitializedModules=1, dontFinalizeModules=0) at nssinit.c:435
#17 nss_Init (configdir=0x400928 "sql:/etc/pki/nssdb", certPrefix=<value optimized out>, keyPrefix=<value optimized out>, secmodName=0x40094f "",
    updateDir=<value optimized out>, updCertPrefix=0x603d10 "Linux2.6_x86_64_glibc_PTH_64_OPT.OBJ/lib/libsoftokn3.so", updKeyPrefix=0x7ffff7dbefc3 "",
    updateID=0x7ffff7dbefc3 "", updateName=0x7ffff7dbefc3 "", initContextPtr=0x7fffffffe908, initParams=0x7fffffffe930, readOnly=1, noCertDB=0, noModDB=0, forceOpen=0,
    noRootInit=1, optimizeSpace=0, noSingleThreadedModules=0, allowAlreadyInitializedModules=1, dontFinalizeModules=0) at nssinit.c:639
#18 0x00007ffff7cda261 in NSS_InitContext (configdir=<value optimized out>, certPrefix=<value optimized out>, keyPrefix=<value optimized out>, secmodName=<value optimized out>,
    initParams=<value optimized out>, flags=<value optimized out>) at nssinit.c:834
#19 0x00000000004007fe in main (argc=1, argv=0x7fffffffea78) at test.cxx:15

Comment 8 Peter Edwards 2013-12-30 17:49:20 UTC
Using the patch below against nss-3.15.1, if the environment variable NSS_SDB_USE_CACHE is set to "yes" or "no" then the call(s) to sdb_measureAccess is(are) avoided, and subsequent "access" system calls for non-existant files that bloat the dentry cache are also avoided.

diff -up nss/lib/softoken/sdb.c.rhbz1044666 nss/lib/softoken/sdb.c
--- nss/lib/softoken/sdb.c.rhbz1044666    2013-06-27 13:58:08.000000000 -0400
+++ nss/lib/softoken/sdb.c     2013-12-30 12:16:18.960019375 -0500
@@ -2012,7 +2012,14 @@ s_open(const char *directory, const char

     /* how long does it take to test for a non-existant file in our working
      * directory? Allows us to test if we may be on a network file system */
-    accessOps = sdb_measureAccess(directory);
+    accessOps = 1;
+    {
+       char *env;
+       env = PR_GetEnv("NSS_SDB_USE_CACHE");
+       if ( !(env) || ( (PORT_Strcasecmp(env,"no") != 0) && (PORT_Strcasecmp(env,"yes") != 0) ) ){
+         accessOps = sdb_measureAccess(directory);
+       }
+    }

     /*
      * open the cert data base

Comment 9 Peter Edwards 2014-01-24 11:26:40 UTC
Upstream change:
  https://hg.mozilla.org/projects/nss/rev/5a67f6beee9a
 
diff --git a/lib/softoken/sdb.c b/lib/softoken/sdb.c
--- a/lib/softoken/sdb.c
+++ b/lib/softoken/sdb.c
@@ -2012,17 +2012,17 @@ s_open(const char *directory, const char
 
     /* how long does it take to test for a non-existant file in our working
      * directory? Allows us to test if we may be on a network file system */
     accessOps = 1;
     {
         char *env;
         env = PR_GetEnv("NSS_SDB_USE_CACHE");
         /* If the environment variable is set to yes or no, sdb_init() will
-         * ignore the value of accessOps, and we can skip the measuring. */
+         * ignore the value of accessOps, and we can skip the measuring.*/
         if (!env || ((PORT_Strcasecmp(env, "no") != 0) &&
                      (PORT_Strcasecmp(env, "yes") != 0))){
            accessOps = sdb_measureAccess(directory);
         }
     }
 
     /*
      * open the cert data base

Comment 10 Kamil Dudka 2014-01-24 11:49:50 UTC
The only change above is a white-space change in a comment.  That could hardly resolve this issue...

Comment 11 Kamil Dudka 2014-01-24 11:52:59 UTC
This looks like the actual fix of the issue:

https://hg.mozilla.org/projects/nss/rev/9934c8faef29

Comment 12 Peter Edwards 2014-01-24 12:29:27 UTC
Thanks Kamil, you are correct, the change was applied in 2 changesets.  I linked in the upstream bug report.

Comment 23 Peter Edwards 2014-07-22 21:38:50 UTC
https://rhn.redhat.com/errata/RHSA-2014-0917.html upgrades NSS to 3.16.1-4 so it should have the fix.

Comment 24 Peter Edwards 2014-07-23 09:47:38 UTC
https://rhn.redhat.com/errata/RHSA-2014-0917.html did not include an upgrade to nss-softokn so no fix yet.

Comment 26 Strahinja Kustudic 2014-10-04 21:36:18 UTC
Do you know when is the upgrade for nss-softokn planned to be released?

Comment 27 errata-xmlrpc 2014-10-14 05:03:26 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

http://rhn.redhat.com/errata/RHBA-2014-1378.html