[Caml-list] Memory leaks generated by Scanf.fscanf?

[Caml-list] Memory leaks generated by Scanf.fscanf?

[jean-vincent.loddo]

Hi,

working on Marionnet (https://launchpad.net/marionnet), I noticed a 
serious memory leak making the system unusable after a few tens of 
minutes. After investigation, the problem seems to be related to 
Scanf.fscanf. This hypothesis is confirmed by the fact that by replacing 
it with the composition of Pervasives.input_line and Scanf.sscanf, the 
problem disappears. I tried to write a simple code (I put it at the end 
of this message) that illustrates the problem with a thread scanning the 
content of a file repetitively (with fscanf or sscanf). The result is 
the same with OCaml 3.12.1 or 4.01.0: with sscanf (~with_sscanf:true) 
the function `start_thread' shows that data are successfully collected:

Iteration #01: stat called 256 times: live blocks: 109590
Iteration #02: stat called 256 times: live blocks: 103063
Iteration #03: stat called 256 times: live blocks: 104091
Iteration #04: stat called 256 times: live blocks: 105119
Iteration #05: stat called 256 times: live blocks: 106147
Iteration #06: stat called 256 times: live blocks: 107175
Iteration #07: stat called 256 times: live blocks: 108203
Iteration #08: stat called 256 times: live blocks: 99637
Iteration #09: stat called 256 times: live blocks: 100665
Iteration #10: stat called 256 times: live blocks: 101693
Iteration #11: stat called 256 times: live blocks: 102721
Iteration #12: stat called 256 times: live blocks: 103749
Iteration #13: stat called 256 times: live blocks: 99637
Iteration #14: stat called 256 times: live blocks: 100665
Iteration #15: stat called 256 times: live blocks: 101693

With fscanf however the used memory continues to grow (things are 
apparently not collected, even if they should):

Iteration #01: stat called 256 times: live blocks: 114469
Iteration #02: stat called 256 times: live blocks: 107613
Iteration #03: stat called 256 times: live blocks: 111456
Iteration #04: stat called 256 times: live blocks: 115299
Iteration #05: stat called 256 times: live blocks: 118890
Iteration #06: stat called 256 times: live blocks: 116601
Iteration #07: stat called 256 times: live blocks: 120235
Iteration #08: stat called 256 times: live blocks: 123925
Iteration #09: stat called 256 times: live blocks: 127615
Iteration #10: stat called 256 times: live blocks: 131179
Iteration #11: stat called 256 times: live blocks: 135023
Iteration #12: stat called 256 times: live blocks: 135583
Iteration #13: stat called 256 times: live blocks: 140450
Iteration #14: stat called 256 times: live blocks: 144197
Iteration #15: stat called 256 times: live blocks: 147790

Sorry if the problem is well known or if something is wrong in my 
analysis, but I can not find anything about it on this list neither on 
the net.
Best regards,
Jean-Vincent Loddo

---
let stat_with_fscanf pid =
   let filename = Printf.sprintf "/proc/%d/stat" pid in
   try
     let ch = open_in filename in
     let result =
       try
         let obj =
           Scanf.fscanf ch "%d %s %c %d %d %s@\n"
             (fun pid comm state ppid pgrp _ -> (pid, comm, state, ppid, 
pgrp))
         in
         Some obj
       with Scanf.Scan_failure(msg) ->
         (Printf.kfprintf flush stderr "failed scanning file %s: %s\n" 
filename msg; None)
     in
     let () = close_in ch in
     result
   with _ -> None

let stat_with_sscanf pid =
   let input_line_from_file filename =
     try
       let ch = open_in filename in
       let result = try Some (input_line ch) with _ -> None in
       let () = close_in ch in
       result
     with _ -> None
   in
   let filename = Printf.sprintf "/proc/%d/stat" pid in
   match (input_line_from_file filename) with
   | None -> None
   | Some line ->
       try
         let obj =
           Scanf.sscanf line "%d %s %c %d %d %s@\n"
             (fun pid comm state ppid pgrp _ -> (pid, comm, state, ppid, 
pgrp))
         in
         Some obj
       with Scanf.Scan_failure(msg) ->
         (Printf.kfprintf flush stderr "failed scanning file %s: %s\n" 
filename msg; None)

(* Just for testing: stat 256 times the `init' process (pid 1) *)
let get_some_stats ?(with_sscanf=false) () =
   let stat = if with_sscanf then stat_with_sscanf else stat_with_fscanf 
in
   let init_pid = 1 in
   let zs = Array.create 256 init_pid in
   Array.map (stat) zs

let start_thread ?with_sscanf () =
   let rec loop i =
     let xs = get_some_stats ?with_sscanf () in
     let () =
       Printf.kfprintf flush stderr
         "Iteration #%02d: stat called %d times: live blocks: %d\n"
         i (Array.length xs) (Gc.stat ()).Gc.live_blocks
     in
     let () = Thread.delay 2. in
     loop (i+1)
   in
   let _ = Thread.create (loop) 1 in
   ()

(* Usage:
    start_thread ~with_sscanf:true ();;
    start_thread ();;
*)

Re: [Caml-list] Memory leaks generated by Scanf.fscanf?

[Jeremy Yallop]

On 20 June 2014 13:29,  <jean-vincent.loddo@lipn.univ-paris13.fr> wrote:
> working on Marionnet (https://launchpad.net/marionnet), I noticed a serious
> memory leak making the system unusable after a few tens of minutes. After
> investigation, the problem seems to be related to Scanf.fscanf.

It looks like your leak is caused by the 'memo' table in the Scanf
module that associates a lookahead buffer with each input channel:

   https://github.com/ocaml/ocaml/blob/trunk/stdlib/scanf.ml#L393

as explained by a comment in the Scanf code:

   https://github.com/ocaml/ocaml/blob/trunk/stdlib/scanf.ml#L268-L320

Entries are added to the table for each input channel used for
scanning, but there's no mechanism for removing entries.  This would
be worth raising on Mantis.

Re: [Caml-list] Memory leaks generated by Scanf.fscanf?

[Gabriel Scherer]

It looks like ephemerons would be a perfect fit to fix this issue, but
unfortunately they're not yet available.

It should be possible instead, at each call of the memo function, to
iterate on the table and remove any item for file-descriptor which has
been closed (I don't think checking whether a file-descriptor is
closed is provided by an OCaml-land function right now, but it'd be
easy to add to the runtime). That would make Scanning.from_channel
slower (linear in the number of opened channels, though we could
easily amortize by checking for all N new channels), but remove the
leak, I think.


On Fri, Jun 20, 2014 at 3:01 PM, Jeremy Yallop <yallop@gmail.com> wrote:
> On 20 June 2014 13:29,  <jean-vincent.loddo@lipn.univ-paris13.fr> wrote:
>> working on Marionnet (https://launchpad.net/marionnet), I noticed a serious
>> memory leak making the system unusable after a few tens of minutes. After
>> investigation, the problem seems to be related to Scanf.fscanf.
>
> It looks like your leak is caused by the 'memo' table in the Scanf
> module that associates a lookahead buffer with each input channel:
>
>    https://github.com/ocaml/ocaml/blob/trunk/stdlib/scanf.ml#L393
>
> as explained by a comment in the Scanf code:
>
>    https://github.com/ocaml/ocaml/blob/trunk/stdlib/scanf.ml#L268-L320
>
> Entries are added to the table for each input channel used for
> scanning, but there's no mechanism for removing entries.  This would
> be worth raising on Mantis.
>
> --
> Caml-list mailing list.  Subscription management and archives:
> https://sympa.inria.fr/sympa/arc/caml-list
> Beginner's list: http://groups.yahoo.com/group/ocaml_beginners
> Bug reports: http://caml.inria.fr/bin/caml-bugs

Re: [Caml-list] Memory leaks generated by Scanf.fscanf?

[Benoît Vaugon]

[-- Attachment #1: Type: text/plain, Size: 3371 bytes --]

I attach a samll patch based on weak-pointers that seems to solve
the problem.The Jean-Vincent example now prints something like:

Iteration #01: stat called 256 times: live blocks: 788
Iteration #02: stat called 256 times: live blocks: 4866
Iteration #03: stat called 256 times: live blocks: 9712
Iteration #04: stat called 256 times: live blocks: 9467
Iteration #05: stat called 256 times: live blocks: 13099
Iteration #06: stat called 256 times: live blocks: 16865
Iteration #07: stat called 256 times: live blocks: 9463
Iteration #08: stat called 256 times: live blocks: 6833
Iteration #09: stat called 256 times: live blocks: 1290
Iteration #10: stat called 256 times: live blocks: 3831
Iteration #11: stat called 256 times: live blocks: 3831
Iteration #12: stat called 256 times: live blocks: 3831
Iteration #13: stat called 256 times: live blocks: 3833
Iteration #14: stat called 256 times: live blocks: 3829
Iteration #15: stat called 256 times: live blocks: 3829
Iteration #16: stat called 256 times: live blocks: 3829
Iteration #17: stat called 256 times: live blocks: 3829
Iteration #18: stat called 256 times: live blocks: 3829
Iteration #19: stat called 256 times: live blocks: 3829
Iteration #20: stat called 256 times: live blocks: 3829

This patch also preserves the scanf semantics about factorisation
of scanning buffers. This property may be verified by running the
following code:

Scanf.fscanf stdin "%[0-9]" (fun s -> print_endline s);;
Gc.compact ();;
Scanf.fscanf stdin "\n%d" (fun n -> print_endline (string_of_int n));;

Regards,
Benoît.


Le 20/06/2014 17:35, Gabriel Scherer a écrit :
> It looks like ephemerons would be a perfect fit to fix this issue, but
> unfortunately they're not yet available.
>
> It should be possible instead, at each call of the memo function, to
> iterate on the table and remove any item for file-descriptor which has
> been closed (I don't think checking whether a file-descriptor is
> closed is provided by an OCaml-land function right now, but it'd be
> easy to add to the runtime). That would make Scanning.from_channel
> slower (linear in the number of opened channels, though we could
> easily amortize by checking for all N new channels), but remove the
> leak, I think.
>
>
> On Fri, Jun 20, 2014 at 3:01 PM, Jeremy Yallop <yallop@gmail.com> wrote:
>> On 20 June 2014 13:29,  <jean-vincent.loddo@lipn.univ-paris13.fr> wrote:
>>> working on Marionnet (https://launchpad.net/marionnet), I noticed a serious
>>> memory leak making the system unusable after a few tens of minutes. After
>>> investigation, the problem seems to be related to Scanf.fscanf.
>> It looks like your leak is caused by the 'memo' table in the Scanf
>> module that associates a lookahead buffer with each input channel:
>>
>>     https://github.com/ocaml/ocaml/blob/trunk/stdlib/scanf.ml#L393
>>
>> as explained by a comment in the Scanf code:
>>
>>     https://github.com/ocaml/ocaml/blob/trunk/stdlib/scanf.ml#L268-L320
>>
>> Entries are added to the table for each input channel used for
>> scanning, but there's no mechanism for removing entries.  This would
>> be worth raising on Mantis.
>>
>> --
>> Caml-list mailing list.  Subscription management and archives:
>> https://sympa.inria.fr/sympa/arc/caml-list
>> Beginner's list: http://groups.yahoo.com/group/ocaml_beginners
>> Bug reports: http://caml.inria.fr/bin/caml-bugs


[-- Attachment #2: fix-scanf-memory-leak.diff --]
[-- Type: text/x-patch, Size: 2698 bytes --]

diff -Naur old/stdlib/.depend new/stdlib/.depend
--- old/stdlib/.depend	2014-06-22 18:34:31.298480318 +0200
+++ new/stdlib/.depend	2014-06-22 18:34:17.522479966 +0200
@@ -147,10 +147,10 @@
     digest.cmx char.cmx array.cmx random.cmi
 scanf.cmo : string.cmi printf.cmi pervasives.cmi list.cmi \
     camlinternalFormatBasics.cmi camlinternalFormat.cmi bytes.cmi buffer.cmi \
-    scanf.cmi
+    weak.cmi scanf.cmi
 scanf.cmx : string.cmx printf.cmx pervasives.cmx list.cmx \
     camlinternalFormatBasics.cmx camlinternalFormat.cmx bytes.cmx buffer.cmx \
-    scanf.cmi
+    weak.cmx scanf.cmi
 set.cmo : list.cmi set.cmi
 set.cmx : list.cmx set.cmi
 sort.cmo : array.cmi sort.cmi
diff -Naur old/stdlib/Makefile.shared new/stdlib/Makefile.shared
--- old/stdlib/Makefile.shared	2014-06-22 18:33:54.426479374 +0200
+++ new/stdlib/Makefile.shared	2014-06-22 18:33:42.866479078 +0200
@@ -30,9 +30,9 @@
   camlinternalLazy.cmo lazy.cmo stream.cmo \
   buffer.cmo camlinternalFormat.cmo printf.cmo \
   arg.cmo printexc.cmo gc.cmo \
-  digest.cmo random.cmo hashtbl.cmo format.cmo scanf.cmo callback.cmo \
+  digest.cmo random.cmo hashtbl.cmo format.cmo weak.cmo scanf.cmo callback.cmo \
   camlinternalOO.cmo oo.cmo camlinternalMod.cmo \
-  genlex.cmo weak.cmo \
+  genlex.cmo \
   filename.cmo complex.cmo \
   arrayLabels.cmo listLabels.cmo bytesLabels.cmo \
   stringLabels.cmo moreLabels.cmo stdLabels.cmo
diff -Naur old/stdlib/scanf.ml new/stdlib/scanf.ml
--- old/stdlib/scanf.ml	2014-06-22 18:31:52.162476244 +0200
+++ new/stdlib/scanf.ml	2014-06-22 18:31:35.010475805 +0200
@@ -390,12 +390,31 @@
   let from_file_bin = open_in_bin;;
 
   let memo_from_ic =
-    let memo = ref [] in
+    let module IcMemo = Weak.Make (struct
+      type t = Pervasives.in_channel
+      let equal ic1 ic2 = ic1 = ic2
+      let hash ic = Hashtbl.hash ic
+    end) in
+    let module PairMemo = Weak.Make (struct
+      type t = Pervasives.in_channel * in_channel
+      let equal (ic1, _) (ic2, _) = ic1 = ic2
+      let hash (ic, _) = Hashtbl.hash ic
+    end) in
+    let ic_memo = IcMemo.create 16 in
+    let pair_memo = PairMemo.create 16 in
+    let rec finaliser ((ic, _) as pair) =
+      if IcMemo.mem ic_memo ic then (
+        Gc.finalise finaliser pair;
+        PairMemo.add pair_memo pair;
+      ) in
     (fun scan_close_ic ic ->
-     try List.assq ic !memo with
+     try snd (PairMemo.find pair_memo (ic, stdin)) with
      | Not_found ->
        let ib = from_ic scan_close_ic (From_channel ic) ic in
-       memo := (ic, ib) :: !memo;
+       let pair = (ic, ib) in
+       IcMemo.add ic_memo ic;
+       Gc.finalise finaliser pair;
+       PairMemo.add pair_memo pair;
        ib)
   ;;
 

Re: [Caml-list] Memory leaks generated by Scanf.fscanf?

[François Bobot]

On 22/06/2014 19:11, Benoît Vaugon wrote:
> I attach a samll patch based on weak-pointers that seems to solve
> the problem.The Jean-Vincent example now prints something like:

Wow! That's a funny solution, but I'm just afraid that it rely on a bad behavior of the GC that the
first three commits of !22 (https://github.com/ocaml/ocaml/pull/22) correct.

In english terms, what Benoît does:
  - put the key in a weak-set to be able to test if it disappeared
  - create a pair that store the key and the associated value
  - put this pair in a weak set, where it will be reclaimed at the next GC because it is reachable
only through a weak pointer.
  - add a finalizer on the pair that add again the pair in the weak set at each GC
  - stop to add it when the key is not present anymore.


The correction of this algorithm rely on the following (good, IMHO) behavior:
  - A value which have an attached finalizer is marked alive, so an ocaml function can run with this
function and one can make it reachable again.

and the following bad behavior:
  - The weak pointers are cleaned before the marking of finalized pointer.

If the cleaning is done later, the pair is marked, then the key is marked, the key is not removed
from the weak-set, thus the key never disappear.

The fact that "The weak pointers are cleaned before the marking of finalized pointer" is bad mainly
because you don't have anymore the property that if a value disappear from a weak set then it have
been reclaimed and can't be used anymore. Use of (==) and tag in hashconsed values are based on this
property.  Moreover the fact that the cleaning of weak pointer is done during the marking phase can
also lead to a value disappearing from a weak set but not from another.

In conclusion the ephemerons are the real solution for the 4.03 release. For the 4.02 I'm not sure
the added complexity and memory/cpu cost is worse it.

Moreover I don't understand why Scanf.from_channel must be memoized by the library. Can't we say
that the user of the library shouldn't call it twice with the same value? The example of
jean-vincent loddo will work with such API, no? We can also add a new not memoized function.

-- 
François

Re: [Caml-list] Memory leaks generated by Scanf.fscanf?

[Jeremy Yallop]

On 20 June 2014 14:01, Jeremy Yallop <yallop@gmail.com> wrote:
> Entries are added to the table for each input channel used for
> scanning, but there's no mechanism for removing entries.  This would
> be worth raising on Mantis.

   http://caml.inria.fr/mantis/view.php?id=6473