Subject: Re: memory leak in _libssh2_channel_open

Re: memory leak in _libssh2_channel_open

From: Steven Dake <sdake_at_redhat.com>
Date: Mon, 27 Feb 2012 21:17:29 -0700

On 02/26/2012 12:25 PM, Steven Dake wrote:
> On 02/26/2012 12:16 PM, Steven Dake wrote:
>> On 02/25/2012 02:25 PM, Daniel Stenberg wrote:
>>> On Sat, 25 Feb 2012, Steven Dake wrote:
>>>
>>>> So it appears the packets are still present on the session list but
>>>> somehow dropped by the open call and not removed.
>>>>
>>>> If you have other suggestions for getting to the root cause please let
>>>> me know. I am happy to help.
>>>
>>> My suspicion is that the call to _libssh2_list_add() within the
>>> src/packet.c:_libssh2_packet_add() function is what adds the packet to
>>> the incoming queue of packets, and some packets that arrive are never
>>> yanked off that list.
>>>
>>> If you would add some debug code that would count the length of that
>>> linked list and logged it occasionally we could see if that is true. The
>>> list should really only grow temporarily and then go back to almost
>>> nothing. If that turns out to be true, we then of course need to figure
>>> out what packets that are lingering there and how to stop them from
>>> doing it!
>>>
>>> (BTW, I'll be away on a week's vacation starting tomorrow so I might not
>>> respond very quickly until I get back.)
>>>
>>
>> I have found two packets that seem to leak into the session packet list
>> which are not removed
>>
>> The packet id 3 (#define SSH_MSG_UNIMPLEMENTED) seems to leak 1 or 2 times.
>>
>> Stack trace:
>> #0 0x000000366b436285 in raise () from /lib64/libc.so.6
>> #1 0x000000366b437b9b in abort () from /lib64/libc.so.6
>> #2 0x000000366b42ee9e in __assert_fail_base () from /lib64/libc.so.6
>> #3 0x000000366b42ef42 in __assert_fail () from /lib64/libc.so.6
>> #4 0x00007ffff7b5684b in _libssh2_packet_add (session=0x62eea0,
>> data=0x623500 "\024\250x\006\275 \336!\220\070\371#\375uÄŠ%",
>> datalen=769, macstate=0) at packet.c:429
>> #5 0x00007ffff7b6a96f in fullpacket (session=0x62eea0, encrypted=0) at
>> transport.c:236
>> #6 0x00007ffff7b6b1f3 in _libssh2_transport_read (session=0x62eea0) at
>> transport.c:556
>> #7 0x00007ffff7b57f4a in _libssh2_packet_require (session=0x62eea0,
>> packet_type=20 '\024', data=0x63bcb8, data_len=0x63bcc0, match_ofs=0,
>> match_buf=0x0, match_len=0, state=
>> 0x63bb60) at packet.c:1097
>> #8 0x00007ffff7b54167 in _libssh2_kex_exchange (session=0x62eea0,
>> reexchange=0, key_state=0x63bb58) at kex.c:1717
>> #9 0x00007ffff7b5ddf0 in session_startup (session=0x62eea0, sock=12) at
>> session.c:718
>> #10 0x00007ffff7b5e0ba in libssh2_session_handshake (session=0x62eea0,
>> sock=12) at session.c:796
>> #11 0x00007ffff7b5e112 in libssh2_session_startup (session=0x62eea0,
>> sock=12) at session.c:815
>> #12 0x000000000040600c in ssh_assembly_connect (data=0x629c60) at
>> trans_ssh.c:374
>> #13 0x00007ffff7d8b1eb in job_dispatch (item=0x6261b0, p=<optimized
>> out>) at loop_job.c:39
>> #14 0x00007ffff7d89d37 in qb_loop_run_level (level=0x60ff30) at loop.c:45
>> #15 qb_loop_run (lp=<optimized out>) at loop.c:206
>> #16 0x0000000000403745 in main (argc=<optimized out>,
>> argv=0x7fffffffde48) at caped.c:171
>>
>>
>> The packet id of 82 (#define SSH_MSG_REQUEST_FAILURE 82) leaks continuously.
>>
>> Two stack traces:
>> consistent leaks:
>> #0 0x000000366b436285 in raise () from /lib64/libc.so.6
>> #1 0x000000366b437b9b in abort () from /lib64/libc.so.6
>> #2 0x000000366b42ee9e in __assert_fail_base () from /lib64/libc.so.6
>> #3 0x000000366b42ef42 in __assert_fail () from /lib64/libc.so.6
>> #4 0x00007ffff7b56864 in _libssh2_packet_add (session=0x655220,
>> data=0x66e9b0 "`", datalen=5, macstate=0) at packet.c:430
>> #5 0x00007ffff7b6a987 in fullpacket (session=0x655220, encrypted=1) at
>> transport.c:236
>> #6 0x00007ffff7b6b20b in _libssh2_transport_read (session=0x655220) at
>> transport.c:556
>> #7 0x00007ffff7b4d8c2 in channel_wait_eof (channel=0x670c80) at
>> channel.c:2213
>> #8 0x00007ffff7b4d948 in libssh2_channel_wait_eof (channel=0x670c80) at
>> channel.c:2242
>> #9 0x00000000004058ea in assembly_ssh_exec (data=0x670800) at
>> trans_ssh.c:200
>> #10 0x00007ffff7d8b1eb in job_dispatch (item=0x66ffc0, p=<optimized
>> out>) at loop_job.c:39
>> #11 0x00007ffff7d89d37 in qb_loop_run_level (level=0x60ff30) at loop.c:45
>> #12 qb_loop_run (lp=<optimized out>) at loop.c:206
>> #13 0x0000000000403745 in main (argc=<optimized out>,
>> argv=0x7fffffffde48) at caped.c:171
>>
>>
>> a leak during startup on packet 82:
>> (gdb) where
>> #0 0x000000366b436285 in raise () from /lib64/libc.so.6
>> #1 0x000000366b437b9b in abort () from /lib64/libc.so.6
>> #2 0x000000366b42ee9e in __assert_fail_base () from /lib64/libc.so.6
>> #3 0x000000366b42ef42 in __assert_fail () from /lib64/libc.so.6
>> #4 0x00007ffff7b5684b in _libssh2_packet_add (session=0x62eea0,
>> data=0x6173a0 "\024\341l\241\236\003\\\277\340\256\357ь\364r\320\060",
>> datalen=769, macstate=0) at packet.c:429
>> #5 0x00007ffff7b6a96f in fullpacket (session=0x62eea0, encrypted=0) at
>> transport.c:236
>> #6 0x00007ffff7b6b1f3 in _libssh2_transport_read (session=0x62eea0) at
>> transport.c:556
>> #7 0x00007ffff7b57f4a in _libssh2_packet_require (session=0x62eea0,
>> packet_type=20 '\024', data=0x63bcb8, data_len=0x63bcc0, match_ofs=0,
>> match_buf=0x0, match_len=0, state=
>> 0x63bb60) at packet.c:1097
>> #8 0x00007ffff7b54167 in _libssh2_kex_exchange (session=0x62eea0,
>> reexchange=0, key_state=0x63bb58) at kex.c:1717
>> #9 0x00007ffff7b5ddf0 in session_startup (session=0x62eea0, sock=12) at
>> session.c:718
>> #10 0x00007ffff7b5e0ba in libssh2_session_handshake (session=0x62eea0,
>> sock=12) at session.c:796
>> #11 0x00007ffff7b5e112 in libssh2_session_startup (session=0x62eea0,
>> sock=12) at session.c:815
>> #12 0x000000000040600c in ssh_assembly_connect (data=0x629c60) at
>> trans_ssh.c:374
>> #13 0x00007ffff7d8b1eb in job_dispatch (item=0x6294c0, p=<optimized
>> out>) at loop_job.c:39
>> #14 0x00007ffff7d89d37 in qb_loop_run_level (level=0x60ff30) at loop.c:45
>> #15 qb_loop_run (lp=<optimized out>) at loop.c:206
>> #16 0x0000000000403745 in main (argc=<optimized out>,
>> argv=0x7fffffffde48) at caped.c:171
>>
>>
>
> here is the open leak
>
> (gdb) where
> #0 0x000000366b436285 in raise () from /lib64/libc.so.6
> #1 0x000000366b437b9b in abort () from /lib64/libc.so.6
> #2 0x000000366b42ee9e in __assert_fail_base () from /lib64/libc.so.6
> #3 0x000000366b42ef42 in __assert_fail () from /lib64/libc.so.6
> #4 0x00007ffff7b56866 in _libssh2_packet_add (session=0x62eea0,
> data=0x66f6e0 "[", datalen=17, macstate=0) at packet.c:430
> #5 0x00007ffff7b6a98b in fullpacket (session=0x62eea0, encrypted=1) at
> transport.c:236
> #6 0x00007ffff7b6b20f in _libssh2_transport_read (session=0x62eea0) at
> transport.c:556
> #7 0x00007ffff7b58288 in _libssh2_packet_requirev (session=0x62eea0,
> packet_types=0x7ffff7b70e15 "[\\", data=0x63bf80, data_len=0x63bf88,
> match_ofs=1, match_buf=0x62512c "",
> match_len=4, state=0x63bf60) at packet.c:1218
> #8 0x00007ffff7b49aa9 in _libssh2_channel_open (session=0x62eea0,
> channel_type=0x408603 "session", channel_type_len=7, window_size=262144,
> packet_size=32768, message=0x0,
> message_len=0) at channel.c:230
> #9 0x00007ffff7b49eec in libssh2_channel_open_ex (session=0x62eea0,
> type=0x408603 "session", type_len=7, window_size=262144,
> packet_size=32768, msg=0x0, msg_len=0)
> at channel.c:331
> #10 0x0000000000405aa8 in assembly_ssh_exec (data=0x62a490) at
> trans_ssh.c:145
> #11 0x00007ffff7d8b1eb in job_dispatch (item=0x654ad0, p=<optimized
> out>) at loop_job.c:39
> #12 0x00007ffff7d89d37 in qb_loop_run_level (level=0x60ff30) at loop.c:45
> #13 qb_loop_run (lp=<optimized out>) at loop.c:206
> #14 0x0000000000403745 in main (argc=<optimized out>,
> argv=0x7fffffffde48) at caped.c:171
>
>
>> It appears something related to how I'm using EOF seems to be causing
>> the problem. You mentioned in a different thread that call model I am
>> using may not work. What would you suggest?
>>
>> I'm not sure why there isn't a leak in the open path. Maybe valgrind ha
>> the stack trace recorded incorrectly? Or perhaps I am asserting on the
>> wrong iteration. I'll play with it more and see if I can find more
>> information.
>>
>> Regards
>> -steve

Hi,

I have found with my tracing patch I previously posted that the cause of
the problem of the heavy leak was related to using the following api:

libssh2_keepalive_config

If the code passes 1 in the want_reply parameter, the ssh server (fedora
16 opensshd) responds with a REQUEST_FAILURE (82) for every
keepalive_send the code calls. I am not sure where the error is there,
but I'd expect a REQUEST_FAILURE would result in no packet allocation in
packet add. I haven't provided a patch as I'm not sure exactly what the
solution should be.

Regards
-steve

\>> _______________________________________________
>> libssh2-devel http://cool.haxx.se/cgi-bin/mailman/listinfo/libssh2-devel
>
> _______________________________________________
> libssh2-devel http://cool.haxx.se/cgi-bin/mailman/listinfo/libssh2-devel

_______________________________________________
libssh2-devel http://cool.haxx.se/cgi-bin/mailman/listinfo/libssh2-devel
Received on 2012-02-28