[Modules] mod_gnutls: does gnutls_allocate_* the counterpart gnutls_free_*

Sun Nov 21 11:24:41 EST 2010

On 19.11.2010 00:14, Nikos Mavrogiannopoulos wrote:
> On 11/18/2010 10:20 PM, Hardy Griech wrote:
>> On 18.11.2010 10:45, Nikos Mavrogiannopoulos wrote:
>> :
>>> Can you use valgrind to trace the leak?
>> valgrind shows as the main leak:
>>
>> ==23601== 19,733,881 (2,399,856 direct, 17,334,025 indirect) bytes in
>> 692 blocks are definitely lost in loss record 1,743 of 1,743
>> ==23601==    at 0x482328F: calloc (vg_replace_malloc.c:467)
>> ==23601==    by 0x4F1D13D: gnutls_init (in /usr/lib/libgnutls.so.26.16.10)
>> ==23601==    by 0x4ED44A0: mgs_hook_pre_connection (gnutls_hooks.c:711)
>> ==23601==    by 0x148E3F: ap_run_pre_connection (in
>> /usr/lib/apache2/mpm-prefork/apache2)
>> ==23601==    by 0x148E93: ap_process_connection (in
>> /usr/lib/apache2/mpm-prefork/apache2)
>> ==23601==    by 0x159189: ??? (in /usr/lib/apache2/mpm-prefork/apache2)
>> ==23601==    by 0x1594C0: ??? (in /usr/lib/apache2/mpm-prefork/apache2)
>> ==23601==    by 0x159C4E: ap_mpm_run (in
>> /usr/lib/apache2/mpm-prefork/apache2)
>> ==23601==    by 0x12AFA1: main (in /usr/lib/apache2/mpm-prefork/apache2)
>> Does that help?
>
> Pretty strage... It does mean that gnutls_deinit isn't called. Are you
> sure it is the reason for the leak... I mean here do you really see it
> being leaked as many times as the connections you have?

Hi Nikos,

I've added code to mod_gnutls where gnutls_init() and gnutls_deinit() 
are called.  Result is, that gnutls_deinit() is called only in some rare 
cases.

Typical connection is like that

mgs_hook_pre_connection: 735
create_gnutls_handle: 696
create_gnutls_handle: 711 gnutls_init
<4> REC[0xb9543c50]: Expected Packet[0] Handshake(22) with length: 1

<4> REC[0xb9543c50]: Received Packet[0] Handshake(22) with length: 45

<4> REC[0xb9543c50]: Decrypted Packet[0] Handshake(22) with length: 45

<3> HSK[0xb9543c50]: CLIENT HELLO was received [45 bytes]

<3> HSK[0xb9543c50]: Client's version: 3.1

<2> ASSERT: gnutls_db.c:326

<2> ASSERT: gnutls_db.c:246

<2> ASSERT: gnutls_extensions.c:140

mgs_select_virtual_server_cb: 130
mgs_find_sni_server: 618
<2> ASSERT: gnutls_extensions.c:140

<2> ASSERT: gnutls_extensions.c:140

cert_retrieve_fn: 195
<3> HSK[0xb9543c50]: Removing ciphersuite: PSK_SHA_ARCFOUR_SHA1

<3> HSK[0xb9543c50]: Removing ciphersuite: PSK_SHA_3DES_EDE_CBC_SHA1

<3> HSK[0xb9543c50]: Removing ciphersuite: PSK_SHA_AES_128_CBC_SHA1

<3> HSK[0xb9543c50]: Removing ciphersuite: PSK_SHA_AES_256_CBC_SHA1

<3> HSK[0xb9543c50]: Removing ciphersuite: DHE_PSK_SHA_ARCFOUR_SHA1

<3> HSK[0xb9543c50]: Removing ciphersuite: DHE_PSK_SHA_3DES_EDE_CBC_SHA1

<3> HSK[0xb9543c50]: Removing ciphersuite: DHE_PSK_SHA_AES_128_CBC_SHA1

<3> HSK[0xb9543c50]: Removing ciphersuite: DHE_PSK_SHA_AES_256_CBC_SHA1

<3> HSK[0xb9543c50]: Removing ciphersuite: SRP_SHA_3DES_EDE_CBC_SHA1

<3> HSK[0xb9543c50]: Removing ciphersuite: SRP_SHA_AES_128_CBC_SHA1

<3> HSK[0xb9543c50]: Removing ciphersuite: SRP_SHA_AES_256_CBC_SHA1

<3> HSK[0xb9543c50]: Removing ciphersuite: SRP_SHA_DSS_3DES_EDE_CBC_SHA1

<3> HSK[0xb9543c50]: Removing ciphersuite: SRP_SHA_RSA_3DES_EDE_CBC_SHA1

<3> HSK[0xb9543c50]: Removing ciphersuite: SRP_SHA_DSS_AES_128_CBC_SHA1

<3> HSK[0xb9543c50]: Removing ciphersuite: SRP_SHA_RSA_AES_128_CBC_SHA1

<3> HSK[0xb9543c50]: Removing ciphersuite: SRP_SHA_DSS_AES_256_CBC_SHA1

<3> HSK[0xb9543c50]: Removing ciphersuite: SRP_SHA_RSA_AES_256_CBC_SHA1

<3> HSK[0xb9543c50]: Removing ciphersuite: DHE_DSS_ARCFOUR_SHA1

<3> HSK[0xb9543c50]: Removing ciphersuite: DHE_DSS_3DES_EDE_CBC_SHA1

<3> HSK[0xb9543c50]: Removing ciphersuite: DHE_DSS_AES_128_CBC_SHA1

<3> HSK[0xb9543c50]: Removing ciphersuite: DHE_DSS_AES_256_CBC_SHA1

<3> HSK[0xb9543c50]: Removing ciphersuite: DHE_DSS_CAMELLIA_128_CBC_SHA1

<3> HSK[0xb9543c50]: Removing ciphersuite: DHE_DSS_CAMELLIA_256_CBC_SHA1

<3> HSK[0xb9543c50]: Keeping ciphersuite: DHE_RSA_3DES_EDE_CBC_SHA1

<3> HSK[0xb9543c50]: Keeping ciphersuite: DHE_RSA_AES_128_CBC_SHA1

<3> HSK[0xb9543c50]: Keeping ciphersuite: DHE_RSA_AES_256_CBC_SHA1

<3> HSK[0xb9543c50]: Keeping ciphersuite: DHE_RSA_CAMELLIA_128_CBC_SHA1

<3> HSK[0xb9543c50]: Keeping ciphersuite: DHE_RSA_CAMELLIA_256_CBC_SHA1

<3> HSK[0xb9543c50]: Keeping ciphersuite: RSA_ARCFOUR_SHA1

<3> HSK[0xb9543c50]: Keeping ciphersuite: RSA_ARCFOUR_MD5

<3> HSK[0xb9543c50]: Keeping ciphersuite: RSA_3DES_EDE_CBC_SHA1

<3> HSK[0xb9543c50]: Keeping ciphersuite: RSA_AES_128_CBC_SHA1

<3> HSK[0xb9543c50]: Keeping ciphersuite: RSA_AES_256_CBC_SHA1

<3> HSK[0xb9543c50]: Keeping ciphersuite: RSA_CAMELLIA_128_CBC_SHA1

<3> HSK[0xb9543c50]: Keeping ciphersuite: RSA_CAMELLIA_256_CBC_SHA1

<3> HSK[0xb9543c50]: Selected cipher suite: RSA_AES_128_CBC_SHA1

<3> HSK[0xb9543c50]: Selected Compression Method: NULL

<3> HSK[0xb9543c50]: Allowing unsafe initial negotiation

<3> HSK[0xb9543c50]: SessionID: 
edbf9370e842c02ea974ee47767a1ec726b51cf4601a6a277e3c5570691f2dda

<3> HSK[0xb9543c50]: SERVER HELLO was sent [74 bytes]

<4> REC[0xb9543c50]: Sending Packet[0] Handshake(22) with length: 74

<4> REC[0xb9543c50]: Sent Packet[1] Handshake(22) with length: 79

<3> HSK[0xb9543c50]: CERTIFICATE was sent [823 bytes]

<4> REC[0xb9543c50]: Sending Packet[1] Handshake(22) with length: 823

<4> REC[0xb9543c50]: Sent Packet[2] Handshake(22) with length: 828

<3> HSK[0xb9543c50]: SERVER HELLO DONE was sent [4 bytes]

<4> REC[0xb9543c50]: Sending Packet[2] Handshake(22) with length: 4

<4> REC[0xb9543c50]: Sent Packet[3] Handshake(22) with length: 9

<4> REC[0xb9543c50]: Expected Packet[1] Handshake(22) with length: 1

<4> REC[0xb9543c50]: Received Packet[1] Handshake(22) with length: 134

<4> REC[0xb9543c50]: Decrypted Packet[1] Handshake(22) with length: 134

<3> HSK[0xb9543c50]: CLIENT KEY EXCHANGE was received [134 bytes]

<4> REC[0xb9543c50]: Expected Packet[2] Change Cipher Spec(20) with 
length: 1

<4> REC[0xb9543c50]: Received Packet[2] Change Cipher Spec(20) with 
length: 1

<4> REC[0xb9543c50]: ChangeCipherSpec Packet was received

<9> INT: PREMASTER SECRET[48]: 
03019f458556a38e9658488c03d838cf6083b7489a75b74131f70406e7b8df74ef219564b56c43eed32d6e37e3d7695b

<9> INT: CLIENT RANDOM[32]: 
4ce94703d6619ccc7baba53840a13a3078e432fbd00a34fd604454c4dd18206b

<9> INT: SERVER RANDOM[32]: 
4ce94701ab7c19c86c74323ce7d3adca1964ad486d925f982a06f841e245be9c

<9> INT: MASTER SECRET: 
8725965c7937c4356156e0d45c4fcbe91ccdefef94b81056f20b987a3a1a85df388939554229eba589b3ca740d530b97

<9> INT: KEY BLOCK[104]: 
fbabeb64f55ba57ad45888222a7675985cb8046adfe71c5a1ac2235301f474ff

<9> INT: CLIENT WRITE KEY [16]: b532a0873856fcb08c92f814e4372123

<9> INT: SERVER WRITE KEY [16]: 0e85bea20b386b64021c7ad699d5e825

<3> HSK[0xb9543c50]: Cipher Suite: RSA_AES_128_CBC_SHA1

<3> HSK[0xb9543c50]: Initializing internal [read] cipher sessions

<4> REC[0xb9543c50]: Expected Packet[0] Handshake(22) with length: 1

<4> REC[0xb9543c50]: Received Packet[0] Handshake(22) with length: 48

<4> REC[0xb9543c50]: Decrypted Packet[0] Handshake(22) with length: 16

<3> HSK[0xb9543c50]: FINISHED was received [16 bytes]

<3> REC[0xb9543c50]: Sent ChangeCipherSpec

<4> REC[0xb9543c50]: Sending Packet[3] Change Cipher Spec(20) with length: 1

<4> REC[0xb9543c50]: Sent Packet[4] Change Cipher Spec(20) with length: 6

<3> HSK[0xb9543c50]: Cipher Suite: RSA_AES_128_CBC_SHA1

<3> HSK[0xb9543c50]: Initializing internal [write] cipher sessions

<3> HSK[0xb9543c50]: FINISHED was sent [16 bytes]

<4> REC[0xb9543c50]: Sending Packet[0] Handshake(22) with length: 16

<4> REC[0xb9543c50]: Sent Packet[1] Handshake(22) with length: 133

<4> REC[0xb9543c50]: Expected Packet[1] Application Data(23) with 
length: 8192

<4> REC[0xb9543c50]: Received Packet[1] Application Data(23) with 
length: 112

<4> REC[0xb9543c50]: Decrypted Packet[1] Application Data(23) with 
length: 77

mgs_hook_authz: 866
mgs_hook_fixups: 781
<2> ASSERT: gnutls_srp.c:653

mgs_add_common_cert_vars: 939
<4> REC[0xb9543c50]: Sending Packet[1] Application Data(23) with length: 184

<4> REC[0xb9543c50]: Sent Packet[2] Application Data(23) with length: 293

<4> REC[0xb9543c50]: Sending Packet[2] Application Data(23) with length: 5

<4> REC[0xb9543c50]: Sent Packet[3] Application Data(23) with length: 197

<4> REC[0xb9543c50]: Sending Packet[3] Application Data(23) with length: 
1429

<4> REC[0xb9543c50]: Sent Packet[4] Application Data(23) with length: 1461

<4> REC[0xb9543c50]: Sending Packet[4] Application Data(23) with length: 2

<4> REC[0xb9543c50]: Sent Packet[5] Application Data(23) with length: 53

<4> REC[0xb9543c50]: Sending Packet[5] Application Data(23) with length: 5

<4> REC[0xb9543c50]: Sent Packet[6] Application Data(23) with length: 229

mgs_hook_pre_connection: 735

I'm wondering which hook is actually called on termination of a connection?

Hardy