xen-api-client.lwt leaks file descriptors in xapi

[gaborigloi]

When the xen-api-client client library is used, instead of xapi's built-in xapi-client library, as a client keeps logging in and then logging out, the file descriptors of xapi will keep increasing until about 1000, when it will drop back to 80, and the client will get the following error:

Server_error(SESSION_AUTHENTICATION_FAILED, [ root; Module is unknown ])

When using xapi-client, the number of file descriptors used by xapi stays at about 81.

Might be related to #31

[gaborigloi]

The following program using xen-api-client can be used to reproduce this issue:

open Lwt;;

let host = "..."
let uname = "..."
let pwd = "..."

let rpc =
  let host_uri = "http://" ^ host in
  Xen_api_lwt_unix.make host_uri;;

let rec loop n =
  if (n > 0) then begin
    Lwt_io.printlf "logging in %d" n >>= fun () ->
    Xen_api_lwt_unix.Session.login_with_password ~rpc ~uname ~pwd ~version:"1.0" ~originator:"leak_test" >>= fun session_id ->
    Xen_api_lwt_unix.Session.logout ~rpc ~session_id >>= fun () ->
    loop (n - 1)
  end else Lwt.return_unit
in
Lwt_main.run (loop 1030);;
(* Compile with:
ocamlfind ocamlc -o test_xen_xapi_client -linkpkg -package lwt -package xen-api-client.lwt  test_xen_api_client.ml
*)

On the XenServer host, the file descriptor usage of xapi can be monitored using the following command:

watch "lsof -p $(pgrep -f /opt/xensource/bin/xapi) | wc -l"

The following program using xapi-client doesn't cause the file descriptor number to increase, it remains constant as the client keeps logging in and then logging out:

let () =

  let host = "..." in
  let uname = "..." in
  let pwd = "..." in

  let rpc xml =
    let open Xmlrpc_client in
    let http = xmlrpc ~version:"1.0" "/" in
    XMLRPC_protocol.rpc ~srcstr:"test" ~dststr:"xapi"
      ~transport:(TCP (host, 80)) ~http xml
  in

  for i = 1 to 1030 do
    Printf.printf "logging in %d\n%!" i;
    let session_id = Client.Client.Session.login_with_password ~rpc ~uname ~pwd ~version:"1.0" ~originator:"leak_test" in
    Client.Client.Session.logout ~rpc ~session_id
  done
(* Compile with:
ocamlfind ocamlc -o test_xapi_client -linkpkg -package lwt -package xapi-client -thread test_xapi_client.ml
*)

[mseri]

Isn't that a problem of the library user instead of the library? I guess we could provide a with_session helper that takes care of logging out, but it should really be whomever uses the library that takes care of reusing a session or opening/closing them

[mseri]

I think we have an issue if the following leaks file descriptors

open Lwt;;

let host = "..."
let uname = "..."
let pwd = "..."

let rpc =
  let host_uri = "http://" ^ host in
  Xen_api_lwt_unix.make host_uri;;

let rec loop n =
  if (n > 0) then begin
    Lwt_io.printlf "logging in %d" n >>= fun () ->
    Xen_api_lwt_unix.Session.login_with_password ~rpc ~uname ~pwd ~version:"1.0" ~originator:"leak_test" >>= fun _session_id ->
    Lwt_io.printlf "logged in %d" n >>= fun () ->
    Lwt_io.printlf "loggin out %d" n >>= fun () ->
    Xen_api_lwt_unix.Session.logout ~rpc ~session_id >>= fun () ->
    Lwt_io.printlf "logged out %d" n >>= fun () ->
    loop (n - 1)
  end else Lwt.return_unit
in
Lwt_main.run (loop 1000);;

[gaborigloi]

@mseri the above does leak, I posted the wrong snippet, sorry, that code shouldn't have been commented out. I've updated my comment.

[mseri]

Then we have a problem :P

[gaborigloi]

This has caused an issue in xapi-nbd as well, where after about 190 connect/disconnect loops it broke xapi, which could not process subsequent commands due to too many open files:

[root@jupiter ~]# xe vdi-list The server failed to handle your request, due to an internal error.  The given message may give details useful for debugging the problem. message: Unix_error: Too many open files

The error in xensource.log was Unix_error 'Too many open files' 'open' '/dev/urandom' (EMFILE), which makes sense, because it's opened for each session:

Jul 25 16:35:57 dt14 xapi: [debug|jupiter|20113 UNIX /var/lib/xcp/xapi||cli] xe vdi-list username=root password=(omitted)
Jul 25 16:35:57 dt14 xapi: [ warn|jupiter|20113 UNIX /var/lib/xcp/xapi||cli] Uncaught exception: Unix_error 'Too many open files' 'open' '/dev/urandom'
Jul 25 16:35:57 dt14 xapi: [error|jupiter|20113 UNIX /var/lib/xcp/xapi||cli] Converting exception INTERNAL_ERROR: [ Unix.Unix_error(Unix.EMFILE, "open", "/dev/urandom") ] into a CLI response
Jul 25 16:35:57 dt14 xapi: [error|jupiter|20113 UNIX /var/lib/xcp/xapi||backtrace] Raised Unix.Unix_error(Unix.EMFILE, "open", "/dev/urandom")
Jul 25 16:35:57 dt14 xapi: [error|jupiter|20113 UNIX /var/lib/xcp/xapi||backtrace] 1/1 xapi @ dt14 Raised at file (Thread 20113 has no backtrace table. Was with_backtraces called?, line 0

[gaborigloi]

Interestingly, I saw the same behaviour when I commented out the Xen_api_lwt_unix.Session.logout command - it did not fail earlier than with the logout.

[gaborigloi]

Tried with xapi-nbd and Lwt 2.7.1, still failed. xapi-nbd reported:

SM.VDI.activate ~dbg ~dp ~sr ~vdi
Caught Storage_interface.Backend_error(_)

xapi essentially stopped working:

[root@xrtuk-07-12hb ~]# xe vdi-list The server failed to handle your request, due to an internal error.  The given message may give details useful for debugging the problem. message: Http_client.Http_error("500", "{ frame = false; method = POST; uri = /; query = [  ]; content_length = [  ]; transfer encoding = ; version = 1.1; cookie = [  ]; task = ; subtask_of = DummyRef:|cce6d1ed-969f-0925-9ded-a4fcf733b857|session.login_with_password; content-type = ; host = ; user_agent = xen-api-libs/1.0 }")

It had 1051 open file descriptors:

1051

The interesting thing is, that in case of the above repro, xapi can clean up the leaked file descriptors somehow, and any further connection from the client, while with xapi-nbd, it doesn't do that, it just stops working.

[gaborigloi]

The source of the problem is the difference in the behaviour of the rpc function from xapi-client, and the one from xen-api-client. The XMLRPC_protocol.rpc function uses with_transport from the same module, so it opens and closes a connection for each XenAPI call (we use the Client in message_forwarding the same way, with the same rpc function). On the other hand, the rpc function created by xen-api-client connects, but doesn't disconnect: https://github.com/xapi-project/xen-api-client/blob/master/lib/xen_api.ml#L155
(Actuall xen-api-client has support for using the same connection for multiple XenAPI calls: https://github.com/xapi-project/xen-api-client/blob/master/lib/xen_api.ml#L76 . However, in this case, the user would have to remember to close the connection manually. I'm not sure whether this is exposed to the library user or not. It would be the best to use this with a wrapper function like with_connection that automatically closes the connection.)