fork() 50 times slower on some Linux kernels?

Discussion in 'C Programming' started by Elmar, Jan 9, 2012.

  1. Elmar

    Elmar Guest

    Dear all,

    a previous discussion in this group mentioned the problem that fork()
    is a resource bottleneck because it needs to (virtually) duplicate a
    process' memory space:

    http://groups.google.com/group/comp.lang.c/browse_thread/thread/911978685974e041/bdd37113d7b43e0c

    Here comes a surprising example:

    The program below first allocates 500 MB, and then calls the function
    system("ls Hello"), which just uses the shell 'ls' command to list a
    file named 'Hello', and finally prints the time required:

    #include <sys/time.h>
    #include <stdio.h>
    #include <malloc.h>
    #include <string.h>

    #define ALLOCSIZE (500*1024*1024)

    int main(int argc,char **argv)
    { void *mem;
    struct timeval before,after;

    mem=malloc(ALLOCSIZE);
    /* IF THE memset IS COMMENTED OUT, THE system CALL IS FAST */
    memset(mem,0,ALLOCSIZE);
    gettimeofday(&before,NULL);
    system("ls Hello");
    gettimeofday(&after,NULL);
    printf("Time before: %d.%06d\n",before.tv_sec,before.tv_usec);
    printf("Time after: %d.%06d\n",after.tv_sec,after.tv_usec); }


    On my Intel Core i7 with 8GB RAM/20 GB swap (64bit, CentOS uname
    2.6.18-238.5.1.el5 #1 SMP Fri Apr 1 18:41:58 EDT 2011 x86_64), the
    output is as follows:

    ls: Hello: No such file or directory
    Time before: 1326139795.216646
    Time after: 1326139796.137364

    So it takes almost *one second* to execute the shell command. If the
    'memset' is commented out, so that the allocated memory is not
    touched, the system call completes instantly:

    ls: Hello: No such file or directory
    Time before: 1326139934.344964
    Time after: 1326139934.359046

    Interestingly, the slowness seems to be kernel dependent. On my other
    old, slow computer, a Core2Duo with 1GB RAM/2 GB swap (32bit, Fedora
    Core uname 2.6.19-1.2895.fc6 #1 SMP Wed Jan 10 19:28:18 EST 2007 i686
    i686 i386 GNU/Linux), it completes instantly, also with memset
    present:

    ls: Hello: No such file or directory
    Time before: 1326140333.832788
    Time after: 1326140333.853900

    The enormous slowness on kernel 2.6.18-238.5.1 kills me, because my
    application needs to make about ~20 system calls during startup and
    thus needs 20 seconds to start!

    Google didn't help much, so my hope was that one of you has heard of/
    encountered this problem, knows which kernels are affected, and when/
    how it was solved, maybe there is a configuration trick etc.?

    Many thanks for your help,
    Elmar

    P.S.: It seems that also others are affected:
    http://stackoverflow.com/questions/5399030/clone-fork-process-creation-is-slow-on-some-machines
     
    Elmar, Jan 9, 2012
    #1
    1. Advertising

  2. Elmar

    Ian Collins Guest

    On 01/10/12 09:25 AM, Elmar wrote:
    > Dear all,
    >
    > a previous discussion in this group mentioned the problem that fork()
    > is a resource bottleneck because it needs to (virtually) duplicate a
    > process' memory space:


    This post belongs on a Linux development group, not here.

    --
    Ian Collins
     
    Ian Collins, Jan 9, 2012
    #2
    1. Advertising

  3. Elmar

    Kaz Kylheku Guest

    On 2012-01-09, Elmar <> wrote:
    > Interestingly, the slowness seems to be kernel dependent.


    How can you conclude that, when at the same time you are changing
    these variables:

    - architecture (x86_64 vs ia32)
    - hardware (different box)
    - different distro (CentOS vs Fedora)
     
    Kaz Kylheku, Jan 9, 2012
    #3
  4. On 09-Jan-12 14:25, Elmar wrote:
    > a previous discussion in this group mentioned the problem that fork()
    > is a resource bottleneck because it needs to (virtually) duplicate a
    > process' memory space:
    >
    > http://groups.google.com/group/comp.lang.c/browse_thread/thread/911978685974e041/bdd37113d7b43e0c
    > ...
    > Google didn't help much, so my hope was that one of you has heard of/
    > encountered this problem, knows which kernels are affected, and when/
    > how it was solved, maybe there is a configuration trick etc.?


    Did you read that thread? The answer is in there, and it has nothing to
    do with the kernel versions; it's about whether vm overcommitment is
    enabled (fast but unsafe) or disabled (safe but unfast).

    S

    --
    Stephen Sprunk "God does not play dice." --Albert Einstein
    CCIE #3723 "God is an inveterate gambler, and He throws the
    K5SSS dice at every possible opportunity." --Stephen Hawking
     
    Stephen Sprunk, Jan 9, 2012
    #4
  5. [OT] Re: fork() 50 times slower on some Linux kernels?

    Sorry, would have redirected this to a Linux or Unix group
    but too much of the original information has been snipped
    to be of any use over there, thus only the [OT] markers...

    To the OP: please repost on comp.os.linux.development.apps
    or comp.unix.programmer or similar where it would be on-
    topic.

    Kaz Kylheku <> wrote:
    > On 2012-01-09, Elmar <> wrote:
    > > Interestingly, the slowness seems to be kernel dependent.


    > How can you conclude that, when at the same time you are changing
    > these variables:


    > - architecture (x86_64 vs ia32)
    > - hardware (different box)
    > - different distro (CentOS vs Fedora)


    I guess the worrying thing is the difference it seems make
    if the memory is set or not. On my system (but with a 3.0
    kernel) I also see a difference, but at a much smaller scale
    - when the 500MB are set to 0 the system() call takes about
    15 ms (what the OP called "instantly";-) while without it's
    only 2.5 ms (both rather consistently). Not easily explained
    when assuming a simple COW-behaviour on fork. If this would
    be a Linux group I might even be tempted into booting an ol-
    der kernel to see what a difference that makes on the exact
    same hardware;-)
    Regards, Jens
    --
    \ Jens Thoms Toerring ___
    \__________________________ http://toerring.de
     
    Jens Thoms Toerring, Jan 9, 2012
    #5
  6. Elmar

    Kaz Kylheku Guest

    On 2012-01-09, Stephen Sprunk <> wrote:
    > On 09-Jan-12 14:25, Elmar wrote:
    >> a previous discussion in this group mentioned the problem that fork()
    >> is a resource bottleneck because it needs to (virtually) duplicate a
    >> process' memory space:
    >>
    >> http://groups.google.com/group/comp.lang.c/browse_thread/thread/911978685974e041/bdd37113d7b43e0c
    >> ...
    >> Google didn't help much, so my hope was that one of you has heard of/
    >> encountered this problem, knows which kernels are affected, and when/
    >> how it was solved, maybe there is a configuration trick etc.?

    >
    > Did you read that thread? The answer is in there, and it has nothing to
    > do with the kernel versions; it's about whether vm overcommitment is
    > enabled (fast but unsafe) or disabled (safe but unfast).


    That's going to be moot in this issue that he's having. Strict overcommit
    accounting only makes a difference to whether a call to mmap succeeds or
    fails. Allocation of the mmaps is still lazy. The OS merely ensures (sort of)
    that it has the "cash" to back the "check" it has written (i.e. that's exactly
    why this is called accounting!) ``If we hand out this virtual space, will there
    later be enough pages available to populate it?'' If the answer is no, then the
    mmap is denied (ENOMEM).

    (This accounting method isn't accurate, because the kernel OS can allocate pages
    for itself which are not accounted. That's why there is the percentage fudge
    factor ``make the total virtual memory outlay no more than XXX% relative
    to total core and swap''. If you make this 100, it is not strict enough because
    it allows as much total virtual memory as there is physical storage, with no
    space for kernel pages. But there is no guarantee that, say, 80% is enough,
    either, in every conceivable situation. Why not just add the kernel pages
    to the accounting? Then VM will be counted twice, because mmap regions are
    populated by the same kernel allocations! You would have to categorize kernel
    get_free_page calls into those which go into populating anonymous mmaps, and
    those which go elsewhere.)

    Overcommit accounting is also moot if you memset the memory, because then
    you're committing it immediately (taking the check written by mmap straight to
    the bank to get it in cash).

    In any case, did you notice in the original posting that this 1 second
    pause occurs on a system with 8GB of RAM?
     
    Kaz Kylheku, Jan 9, 2012
    #6
  7. Elmar

    Kaz Kylheku Guest

    Re: [OT] Re: fork() 50 times slower on some Linux kernels?

    On 2012-01-09, Jens Thoms Toerring <> wrote:
    > Sorry, would have redirected this to a Linux or Unix group
    > but too much of the original information has been snipped
    > to be of any use over there, thus only the [OT] markers...


    Sure, because Usenet discussion traffic has grown to such staggering volumes,
    that we can't possibly deal with any off-topic drift.
     
    Kaz Kylheku, Jan 9, 2012
    #7
  8. Elmar

    Ian Collins Guest

    Re: [OT] Re: fork() 50 times slower on some Linux kernels?

    On 01/10/12 11:32 AM, Kaz Kylheku wrote:
    > On 2012-01-09, Jens Thoms Toerring<> wrote:
    >> Sorry, would have redirected this to a Linux or Unix group
    >> but too much of the original information has been snipped
    >> to be of any use over there, thus only the [OT] markers...

    >
    > Sure, because Usenet discussion traffic has grown to such staggering volumes,
    > that we can't possibly deal with any off-topic drift.


    That's not really the point, is it? If someone wants to start a
    discussion on topic X, a group dedicated to topic X is the place to ask.
    Sending them there is the best response elsewhere.

    --
    Ian Collins
     
    Ian Collins, Jan 9, 2012
    #8
  9. On 09-Jan-12 16:30, Kaz Kylheku wrote:
    > On 2012-01-09, Stephen Sprunk <> wrote:
    >> On 09-Jan-12 14:25, Elmar wrote:
    >>> a previous discussion in this group mentioned the problem that fork()
    >>> is a resource bottleneck because it needs to (virtually) duplicate a
    >>> process' memory space:
    >>>
    >>> http://groups.google.com/group/comp.lang.c/browse_thread/thread/911978685974e041/bdd37113d7b43e0c
    >>> ...
    >>> Google didn't help much, so my hope was that one of you has heard of/
    >>> encountered this problem, knows which kernels are affected, and when/
    >>> how it was solved, maybe there is a configuration trick etc.?

    >>
    >> Did you read that thread? The answer is in there, and it has nothing to
    >> do with the kernel versions; it's about whether vm overcommitment is
    >> enabled (fast but unsafe) or disabled (safe but unfast).

    >
    > That's going to be moot in this issue that he's having. Strict overcommit
    > accounting only makes a difference to whether a call to mmap succeeds or
    > fails. Allocation of the mmaps is still lazy. The OS merely ensures (sort of)
    > that it has the "cash" to back the "check" it has written (i.e. that's exactly
    > why this is called accounting!) ``If we hand out this virtual space, will there
    > later be enough pages available to populate it?'' If the answer is no, then the
    > mmap is denied (ENOMEM).


    We're not talking about mmap() here; we're talking about fork().

    When you fork(), all the pages in the parent process are shared with the
    child, with copy-on-write behavior. When overcommitment is enabled,
    there is no backing guaranteed for those potential future copies, and
    modifying them (in either process) forces the kernel to find backing at
    some unspecified point in the future--which may fail. Disabling
    overcommitment moves that problem to the present by forcing the kernel
    to find backing for all those pages during the fork(), and that takes time.

    > In any case, did you notice in the original posting that this 1 second
    > pause occurs on a system with 8GB of RAM?


    That is apparently how long it takes for the kernel on his system to
    find backing for all those pages. I suspect that delay is why
    overcommitment is on by default.

    S

    --
    Stephen Sprunk "God does not play dice." --Albert Einstein
    CCIE #3723 "God is an inveterate gambler, and He throws the
    K5SSS dice at every possible opportunity." --Stephen Hawking
     
    Stephen Sprunk, Jan 9, 2012
    #9
  10. Re: [OT] fork() 50 times slower on some Linux kernels?

    Kaz, sorry for the "[OT]" but I prefer it that way;-)

    Stephen Sprunk <> wrote:
    > > In any case, did you notice in the original posting that this 1 second
    > > pause occurs on a system with 8GB of RAM?


    > That is apparently how long it takes for the kernel on his system to
    > find backing for all those pages. I suspect that delay is why
    > overcommitment is on by default.


    I now see what you meant in you're earlier post, but - as a
    completely unscientific experiment - switching off overcom-
    mitment doesn't seem to make any difference on my system.
    The (admittedly short and thus a bit dubious) times seem to
    stay more or less exactly what they were before (i.e. about
    15 ms when initializing the memory and 2.5 ms without). I'm
    also still a bit puzzled why it could take the kernel nearly
    1 second to find backing store on the system the OP seems to
    have - I don't know the clock speed, but it seems to have
    amounts of memory similar to mine (both 8 GB) and even a
    newer CPU (Intel i7 versus "only" an i5 here). Of course,
    this all could also be due to differences in the kernel ver-
    sions used...
    Best regards, Jens
    --
    \ Jens Thoms Toerring ___
    \__________________________ http://toerring.de
     
    Jens Thoms Toerring, Jan 9, 2012
    #10
  11. Elmar

    Kaz Kylheku Guest

    Re: [OT] fork() 50 times slower on some Linux kernels?

    On 2012-01-09, Jens Thoms Toerring <> wrote:
    > Kaz, sorry for the "[OT]" but I prefer it that way;-)
    >
    > Stephen Sprunk <> wrote:
    >> > In any case, did you notice in the original posting that this 1 second
    >> > pause occurs on a system with 8GB of RAM?

    >
    >> That is apparently how long it takes for the kernel on his system to
    >> find backing for all those pages. I suspect that delay is why
    >> overcommitment is on by default.

    >
    > I now see what you meant in you're earlier post, but - as a
    > completely unscientific experiment - switching off overcom-
    > mitment doesn't seem to make any difference on my system.


    Finding backing for pages happens during the memset operation, whereas what is
    being timed is the call to system().

    Even with strict accounting, fork should not be duplicating the pages and
    committing memory for them, but be implementing a copy-on-write optimization.
    Strict accounting would mean that fork should fail if creating the (empty!)
    maps for the process would bring the total VM footprint of the system over the
    limit.

    That's the theory.

    Where that 1 second is being spent is anyone's guess. Maybe
    that kernel has a patch that causes fork not to do copy-on-write.

    I would start by running the test case using
    "strace -f -r <command>" (with -f to follow forks
    and -r to print relative timestamps).

    This will reveal which syste call(s) are spending that time.

    system() is not a system call, but pretty complicated function
    which does a fork, exec and wait and probably mucking around
    with file descriptors and probably signal handling and such.
     
    Kaz Kylheku, Jan 10, 2012
    #11
  12. Re: [OT] fork() 50 times slower on some Linux kernels?

    On 09-Jan-12 18:22, Kaz Kylheku wrote:
    > On 2012-01-09, Jens Thoms Toerring <> wrote:
    >> Kaz, sorry for the "[OT]" but I prefer it that way;-)
    >> Stephen Sprunk <> wrote:
    >>>> In any case, did you notice in the original posting that this 1 second
    >>>> pause occurs on a system with 8GB of RAM?
    >>>
    >>> That is apparently how long it takes for the kernel on his system to
    >>> find backing for all those pages. I suspect that delay is why
    >>> overcommitment is on by default.

    >>
    >> I now see what you meant in you're earlier post, but - as a
    >> completely unscientific experiment - switching off overcom-
    >> mitment doesn't seem to make any difference on my system.

    >
    > Finding backing for pages happens during the memset operation, whereas
    > what is being timed is the call to system().
    >
    > Even with strict accounting, fork should not be duplicating the pages and
    > committing memory for them, but be implementing a copy-on-write optimization.
    > Strict accounting would mean that fork should fail if creating the (empty!)
    > maps for the process would bring the total VM footprint of the system over the
    > limit.
    >
    > That's the theory.


    If you don't back those pages during the fork() operation, then you're
    back to the original problem.

    For instance, imagine a process that allocates a thousand pages. If
    overcommitment is disabled, then the kernel will actually back them (or
    allocation will fail). The process forks, and then both parent and
    child write to each of the thousand pages, triggering a thousand
    copy-on-writes and the need to find a thousand backing pages. If even
    one of those pages can't be backed, then one of the processes will
    fail--something that should have been impossible. (Or worse, the OOM
    Killer turns its attention elsewhere to obtain backing pages...)

    A simpler implementation would be to reject copy-on-write entirely,
    duplicating the pages. However, that would unnecessarily double the
    number of active pages and pollute the cache even if no writes occur,
    which is the normal case.

    S

    --
    Stephen Sprunk "God does not play dice." --Albert Einstein
    CCIE #3723 "God is an inveterate gambler, and He throws the
    K5SSS dice at every possible opportunity." --Stephen Hawking
     
    Stephen Sprunk, Jan 10, 2012
    #12
  13. Re: [OT] fork() 50 times slower on some Linux kernels?

    On 09-Jan-12 21:43, William Ahern wrote:
    > Stephen Sprunk <> wrote:
    >> On 09-Jan-12 18:22, Kaz Kylheku wrote:

    > <snip>
    >>> Even with strict accounting, fork should not be duplicating the pages
    >>> and committing memory for them, but be implementing a copy-on-write
    >>> optimization. Strict accounting would mean that fork should fail if
    >>> creating the (empty!) maps for the process would bring the total VM
    >>> footprint of the system over the limit.
    >>>
    >>> That's the theory.

    >
    >> If you don't back those pages during the fork() operation, then you're
    >> back to the original problem.

    >
    >> For instance, imagine a process that allocates a thousand pages. If
    >> overcommitment is disabled, then the kernel will actually back them (or
    >> allocation will fail). The process forks, and then both parent and
    >> child write to each of the thousand pages, triggering a thousand
    >> copy-on-writes and the need to find a thousand backing pages. If even
    >> one of those pages can't be backed, then one of the processes will
    >> fail--something that should have been impossible. (Or worse, the OOM
    >> Killer turns its attention elsewhere to obtain backing pages...)
    >>
    >> A simpler implementation would be to reject copy-on-write entirely,
    >> duplicating the pages. However, that would unnecessarily double the
    >> number of active pages and pollute the cache even if no writes occur,
    >> which is the normal case.

    >
    > Maybe I misunderstand what you mean by "duplicate", but it seems to me you
    > don't need to reject copy-on-write. You just need to reserve the number of
    > pages needed to do any future copying. You could do this with simple
    > counters: # of pages in use, # of pages reserved.


    Right, that's the smart implementation: reserve the backing pages at the
    time the process fork()s, but leave both of them pointing at the same
    actual page until one of them changes it--at which point the page is
    copied to one of the reserved pages.

    The dumb implementation would be to copy every page at the time of
    fork(), which removes the need to track reserved pages and to worry
    about copy-on-write.

    Both take more time and effort than deferring backing them until a
    copy-on-write actually happens.

    > Like Ken, I also think that the bogeyman here--of processes which allocate a
    > ton of memory upfront--is a poor excuse and overhyped. Those applications
    > are few and far between. Sometimes important, maybe, but theoretically
    > easily fixed.


    My Firefox is eating 807MB right now, and it spawns new processes now
    and then. Overcommitment means the OS doesn't need to back those 202k
    pages during the fork() call--copies which would be trashed a few cycles
    after fork() returns when the child process calls exec().

    It's not just about malloc() or mmap(); those problems are simpler to
    explain, though tougher to justify.

    S

    --
    Stephen Sprunk "God does not play dice." --Albert Einstein
    CCIE #3723 "God is an inveterate gambler, and He throws the
    K5SSS dice at every possible opportunity." --Stephen Hawking
     
    Stephen Sprunk, Jan 10, 2012
    #13
  14. Elmar

    Nobody Guest

    On Mon, 09 Jan 2012 17:20:40 -0600, Stephen Sprunk wrote:

    > Disabling overcommitment moves that problem to the present by forcing
    > the kernel to find backing for all those pages during the fork(), and
    > that takes time.


    Why would it take time? Obviously it takes _some_ time, but there's no
    need for it to take significant time. It only has to check that the number
    of shared (copy-on-write) pages is less than the number of uncommitted
    pages, then subtract the former from the latter. It doesn't have to
    actually do anything with those pages.
     
    Nobody, Jan 10, 2012
    #14
  15. Elmar

    Elmar Guest

    On Jan 10, 12:57 am, (Jens Thoms Toerring) wrote:
    > Kaz, sorry for the "[OT]" but I prefer it that way;-)
    >
    > Stephen Sprunk <> wrote:
    > > > In any case, did you notice in the original posting that this 1 second
    > > > pause occurs on a system with 8GB of RAM?

    > > That is apparently how long it takes for the kernel on his system to
    > > find backing for all those pages. I suspect that delay is why
    > > overcommitment is on by default.

    >
    > I now see what you meant in you're earlier post, but - as a
    > completely unscientific experiment - switching off overcom-
    > mitment doesn't seem to make any difference on my system.
    > The (admittedly short and thus a bit dubious) times seem to
    > stay more or less exactly what they were before (i.e. about
    > 15 ms when initializing the memory and 2.5 ms without). I'm
    > also still a bit puzzled why it could take the kernel nearly
    > 1 second to find backing store on the system the OP seems to
    > have - I don't know the clock speed, but it seems to have
    > amounts of memory similar to mine (both 8 GB) and even a
    > newer CPU (Intel i7 versus "only" an i5 here). Of course,
    > this all could also be due to differences in the kernel ver-
    > sions used...


    First of all, sorry to everyone who complained about my sub-optimal
    choice of usenet group. I only ended up here because Google found the
    previous thread on fork() and overcommit in this group.

    BTW, the overcommit setting at my mysteriously slow fork() Core i7
    machine is the default 0:

    more /proc/sys/vm/overcommit_memory
    0

    Also, Kaz Kylheku was right: I was premature to blame the kernel. I
    now upgraded to the latest CentOS Kernel 2.6.18-274.12.1.el5 (problem
    persists), and installed the same Linux distro on another machine, but
    everything was fine there.

    So we now got same Linux Distro, same kernel 2.6.18-274.12.1.el5 #1
    SMP Tue Nov 29 13:37:46 EST 2011 x86_64, and..

    Core i7, 2.8GHz, 8GB RAM/20GB Swap: slow fork()
    Opteron 1.8GHz, 2GB RAM/4GB Swap: fast fork()

    I also shut down the X-server, since the Core i7 uses nVIDIA's
    proprietary driver, and the Opteron AMD's proprietary driver. But the
    Core i7 forks equally slow at runlevel 3.

    Kaz Kylheku also suggested to use 'strace -f -r', which I did
    (attached at the end for the slow forker).
    Comparison between the slow and the fast forker shows that 'mmap' is
    to be blamed (even without the timing info, one sees the output hang
    at mmap for a second).

    slow with memset:

    0.000571 mmap(NULL, 524292096, PROT_READ|PROT_WRITE, MAP_PRIVATE|
    MAP_ANONYMOUS, -1, 0) = 0x2b86fb5cc000
    1.631431 rt_sigaction(SIGINT, {0x1, [], SA_RESTORER,
    0x348a2302d0}, {SIG_DFL, [], 0}, 8) = 0

    fast without memset:

    0.000595 mmap(NULL, 524292096, PROT_READ|PROT_WRITE, MAP_PRIVATE|
    MAP_ANONYMOUS, -1, 0) = 0x2b0bb57a4000
    0.000194 rt_sigaction(SIGINT, {0x1, [], SA_RESTORER,
    0x348a2302d0}, {SIG_DFL, [], 0}, 8) = 0

    Complete output:

    $ strace -f -r a.out
    0.000000 execve("./a.out", ["a.out"], [/* 49 vars */]) = 0
    0.001729 brk(0) = 0xf699000
    0.000222 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|
    MAP_ANONYMOUS, -1, 0) = 0x2b86fb59b000
    0.000323 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|
    MAP_ANONYMOUS, -1, 0) = 0x2b86fb59c000
    0.000190 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such
    file or directory)
    0.000333 open("/etc/ld.so.cache", O_RDONLY) = 3
    0.000157 fstat(3, {st_mode=S_IFREG|0644, st_size=187712, ...}) =
    0
    0.000280 mmap(NULL, 187712, PROT_READ, MAP_PRIVATE, 3, 0) =
    0x2b86fb59d000
    0.000165 close(3) = 0
    0.000251 open("/lib64/libc.so.6", O_RDONLY) = 3
    0.000136 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>
    \0\1\0\0\0\220\332!\2124\0\0\0"..., 832) = 832
    0.000211 fstat(3, {st_mode=S_IFREG|0755, st_size=1722304, ...}) =
    0
    0.000372 mmap(0x348a200000, 3502424, PROT_READ|PROT_EXEC,
    MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x348a200000
    0.000120 mprotect(0x348a34e000, 2097152, PROT_NONE) = 0
    0.000134 mmap(0x348a54e000, 20480, PROT_READ|PROT_WRITE,
    MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x14e000) = 0x348a54e000
    0.000255 mmap(0x348a553000, 16728, PROT_READ|PROT_WRITE,
    MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x348a553000
    0.000169 close(3) = 0
    0.000184 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|
    MAP_ANONYMOUS, -1, 0) = 0x2b86fb5cb000
    0.000182 arch_prctl(ARCH_SET_FS, 0x2b86fb5cb6e0) = 0
    0.000459 mprotect(0x348a54e000, 16384, PROT_READ) = 0
    0.000141 mprotect(0x348a01c000, 4096, PROT_READ) = 0
    0.000146 munmap(0x2b86fb59d000, 187712) = 0
    0.000571 mmap(NULL, 524292096, PROT_READ|PROT_WRITE, MAP_PRIVATE|
    MAP_ANONYMOUS, -1, 0) = 0x2b86fb5cc000
    1.631431 rt_sigaction(SIGINT, {0x1, [], SA_RESTORER,
    0x348a2302d0}, {SIG_DFL, [], 0}, 8) = 0
    0.000381 rt_sigaction(SIGQUIT, {0x1, [], SA_RESTORER,
    0x348a2302d0}, {SIG_DFL, [], 0}, 8) = 0
    0.000212 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
    0.000122 clone(Process 25300 attached (waiting for parent)
    Process 25300 resumed (parent 25263 ready)
    child_stack=0, flags=CLONE_PARENT_SETTID|SIGCHLD,
    parent_tidptr=0x7fff8ab7c538) = 25300
    [pid 25300] 0.436593 rt_sigaction(SIGINT, {SIG_DFL, [],
    SA_RESTORER, 0x348a2302d0}, <unfinished ...>
    [pid 25263] 0.000055 wait4(25300, Process 25263 suspended
    <unfinished ...>
    [pid 25300] 0.000009 <... rt_sigaction resumed> NULL, 8) = 0
    [pid 25300] 0.000020 rt_sigaction(SIGQUIT, {SIG_DFL, [],
    SA_RESTORER, 0x348a2302d0}, NULL, 8) = 0
    [pid 25300] 0.000063 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
    [pid 25300] 0.000072 execve("/bin/sh", ["sh", "-c", "ls Hello"],
    [/* 49 vars */]) = 0
    [pid 25300] 0.451537 brk(0) = 0xfde2000
    [pid 25300] 0.000114 mmap(NULL, 4096, PROT_READ|PROT_WRITE,
    MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2b228a067000
    [pid 25300] 0.000140 mmap(NULL, 4096, PROT_READ|PROT_WRITE,
    MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2b228a068000
    [pid 25300] 0.000061 access("/etc/ld.so.preload", R_OK) = -1
    ENOENT (No such file or directory)
    [pid 25300] 0.000129 open("/etc/ld.so.cache", O_RDONLY) = 3
    [pid 25300] 0.000050 fstat(3, {st_mode=S_IFREG|0644,
    st_size=187712, ...}) = 0
    [pid 25300] 0.000177 mmap(NULL, 187712, PROT_READ, MAP_PRIVATE,
    3, 0) = 0x2b228a069000
    [pid 25300] 0.000055 close(3) = 0
    [pid 25300] 0.000162 open("/lib64/libtermcap.so.2", O_RDONLY) = 3
    [pid 25300] 0.000073 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>
    \0\1\0\0\0@\17\240\2154\0\0\0"..., 832) = 832
    [pid 25300] 0.000090 fstat(3, {st_mode=S_IFREG|0755,
    st_size=15584, ...}) = 0
    [pid 25300] 0.000186 mmap(0x348da00000, 2108688, PROT_READ|
    PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x348da00000
    [pid 25300] 0.000052 mprotect(0x348da03000, 2093056, PROT_NONE) =
    0
    [pid 25300] 0.000056 mmap(0x348dc02000, 4096, PROT_READ|
    PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) =
    0x348dc02000
    [pid 25300] 0.000089 close(3) = 0
    [pid 25300] 0.000125 open("/lib64/libdl.so.2", O_RDONLY) = 3
    [pid 25300] 0.000063 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>
    \0\1\0\0\0\20\16\240\2124\0\0\0"..., 832) = 832
    [pid 25300] 0.000079 fstat(3, {st_mode=S_IFREG|0755,
    st_size=23360, ...}) = 0
    [pid 25300] 0.000172 mmap(0x348aa00000, 2109696, PROT_READ|
    PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x348aa00000
    [pid 25300] 0.000042 mprotect(0x348aa02000, 2097152, PROT_NONE) =
    0
    [pid 25300] 0.000032 mmap(0x348ac02000, 8192, PROT_READ|
    PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) =
    0x348ac02000
    [pid 25300] 0.000071 close(3) = 0
    [pid 25300] 0.000098 open("/lib64/libc.so.6", O_RDONLY) = 3
    [pid 25300] 0.000058 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>
    \0\1\0\0\0\220\332!\2124\0\0\0"..., 832) = 832
    [pid 25300] 0.000094 fstat(3, {st_mode=S_IFREG|0755,
    st_size=1722304, ...}) = 0
    [pid 25300] 0.000180 mmap(0x348a200000, 3502424, PROT_READ|
    PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x348a200000
    [pid 25300] 0.000034 mprotect(0x348a34e000, 2097152, PROT_NONE) =
    0
    [pid 25300] 0.000051 mmap(0x348a54e000, 20480, PROT_READ|
    PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x14e000) =
    0x348a54e000
    [pid 25300] 0.000065 mmap(0x348a553000, 16728, PROT_READ|
    PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x348a553000
    [pid 25300] 0.000065 close(3) = 0
    [pid 25300] 0.000084 mmap(NULL, 4096, PROT_READ|PROT_WRITE,
    MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2b228a097000
    [pid 25300] 0.000104 mmap(NULL, 4096, PROT_READ|PROT_WRITE,
    MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2b228a098000
    [pid 25300] 0.000035 arch_prctl(ARCH_SET_FS, 0x2b228a097f50) = 0
    [pid 25300] 0.000078 mprotect(0x348ac02000, 4096, PROT_READ) = 0
    [pid 25300] 0.000030 mprotect(0x348a54e000, 16384, PROT_READ) = 0
    [pid 25300] 0.000044 mprotect(0x348a01c000, 4096, PROT_READ) = 0
    [pid 25300] 0.000076 munmap(0x2b228a069000, 187712) = 0
    [pid 25300] 0.000409 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0
    [pid 25300] 0.000063 open("/dev/tty", O_RDWR|O_NONBLOCK) = 3
    [pid 25300] 0.000067 close(3) = 0
    [pid 25300] 0.000557 brk(0) = 0xfde2000
    [pid 25300] 0.000045 brk(0xfe03000) = 0xfe03000
    [pid 25300] 0.000091 open("/usr/lib/locale/locale-archive",
    O_RDONLY) = 3
    [pid 25300] 0.000105 fstat(3, {st_mode=S_IFREG|0644,
    st_size=56426032, ...}) = 0
    [pid 25300] 0.000171 mmap(NULL, 56426032, PROT_READ, MAP_PRIVATE,
    3, 0) = 0x2b228a099000
    [pid 25300] 0.000054 close(3) = 0
    [pid 25300] 0.000220 getuid() = 500
    [pid 25300] 0.000031 getgid() = 500
    [pid 25300] 0.000034 geteuid() = 500
    [pid 25300] 0.000038 getegid() = 500
    [pid 25300] 0.000088 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0
    [pid 25300] 0.000316 open("/proc/meminfo", O_RDONLY) = 3
    [pid 25300] 0.000168 fstat(3, {st_mode=S_IFREG|0444,
    st_size=0, ...}) = 0
    [pid 25300] 0.000165 mmap(NULL, 4096, PROT_READ|PROT_WRITE,
    MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2b228d669000
    [pid 25300] 0.000062 read(3, "MemTotal: 8168624 kB
    \nMemFre"..., 1024) = 777
    [pid 25300] 0.000235 close(3) = 0
    [pid 25300] 0.000043 munmap(0x2b228d669000, 4096) = 0
    [pid 25300] 0.000217 rt_sigaction(SIGCHLD, {SIG_DFL, [],
    SA_RESTORER, 0x348a2302d0}, {SIG_DFL, [], 0}, 8) = 0
    [pid 25300] 0.000099 rt_sigaction(SIGCHLD, {SIG_DFL, [],
    SA_RESTORER, 0x348a2302d0}, {SIG_DFL, [], SA_RESTORER, 0x348a2302d0},
    8) = 0
    [pid 25300] 0.000121 rt_sigaction(SIGINT, {SIG_DFL, [],
    SA_RESTORER, 0x348a2302d0}, {SIG_DFL, [], 0}, 8) = 0
    [pid 25300] 0.000100 rt_sigaction(SIGINT, {SIG_DFL, [],
    SA_RESTORER, 0x348a2302d0}, {SIG_DFL, [], SA_RESTORER, 0x348a2302d0},
    8) = 0
    [pid 25300] 0.000111 rt_sigaction(SIGQUIT, {SIG_DFL, [],
    SA_RESTORER, 0x348a2302d0}, {SIG_DFL, [], 0}, 8) = 0
    [pid 25300] 0.000096 rt_sigaction(SIGQUIT, {SIG_DFL, [],
    SA_RESTORER, 0x348a2302d0}, {SIG_DFL, [], SA_RESTORER, 0x348a2302d0},
    8) = 0
    [pid 25300] 0.000098 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0
    [pid 25300] 0.000044 rt_sigaction(SIGQUIT, {0x1, [], SA_RESTORER,
    0x348a2302d0}, {SIG_DFL, [], SA_RESTORER, 0x348a2302d0}, 8) = 0
    [pid 25300] 0.000122 uname({sys="Linux", node="yasara3", ...}) =
    0
    [pid 25300] 0.000551 stat("/home/elmar/python", {st_mode=S_IFDIR|
    0777, st_size=36864, ...}) = 0
    [pid 25300] 0.000183 stat(".", {st_mode=S_IFDIR|0777,
    st_size=36864, ...}) = 0
    [pid 25300] 0.000178 getpid() = 25300
    [pid 25300] 0.000115 open("/usr/lib64/gconv/gconv-modules.cache",
    O_RDONLY) = 3
    [pid 25300] 0.000103 fstat(3, {st_mode=S_IFREG|0644,
    st_size=25464, ...}) = 0
    [pid 25300] 0.000157 mmap(NULL, 25464, PROT_READ, MAP_SHARED, 3,
    0) = 0x2b228d669000
    [pid 25300] 0.000049 close(3) = 0
    [pid 25300] 0.000136 getppid() = 25263
    [pid 25300] 0.000071 stat(".", {st_mode=S_IFDIR|0777,
    st_size=36864, ...}) = 0
    [pid 25300] 0.000198 stat("/usr/kerberos/sbin/sh",
    0x7fff8049aef0) = -1 ENOENT (No such file or directory)
    [pid 25300] 0.000078 stat("/usr/kerberos/bin/sh", 0x7fff8049aef0)
    = -1 ENOENT (No such file or directory)
    [pid 25300] 0.000062 stat("/usr/local/bin/sh", 0x7fff8049aef0) =
    -1 ENOENT (No such file or directory)
    [pid 25300] 0.000069 stat("/usr/bin/sh", 0x7fff8049aef0) = -1
    ENOENT (No such file or directory)
    [pid 25300] 0.000073 stat("/bin/sh", {st_mode=S_IFREG|0755,
    st_size=801528, ...}) = 0
    [pid 25300] 0.000161 access("/bin/sh", X_OK) = 0
    [pid 25300] 0.000053 access("/bin/sh", R_OK) = 0
    [pid 25300] 0.000042 stat("/bin/sh", {st_mode=S_IFREG|0755,
    st_size=801528, ...}) = 0
    [pid 25300] 0.000165 access("/bin/sh", X_OK) = 0
    [pid 25300] 0.000053 access("/bin/sh", R_OK) = 0
    [pid 25300] 0.000177 getpgrp() = 25262
    [pid 25300] 0.000042 rt_sigaction(SIGCHLD, {0x436360, [],
    SA_RESTORER, 0x348a2302d0}, {SIG_DFL, [], SA_RESTORER, 0x348a2302d0},
    8) = 0
    [pid 25300] 0.000407 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0
    [pid 25300] 0.000050 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0
    [pid 25300] 0.000104 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0
    [pid 25300] 0.000289 stat(".", {st_mode=S_IFDIR|0777,
    st_size=36864, ...}) = 0
    [pid 25300] 0.000179 stat("/usr/kerberos/sbin/ls",
    0x7fff8049adb0) = -1 ENOENT (No such file or directory)
    [pid 25300] 0.000064 stat("/usr/kerberos/bin/ls", 0x7fff8049adb0)
    = -1 ENOENT (No such file or directory)
    [pid 25300] 0.000072 stat("/usr/local/bin/ls", 0x7fff8049adb0) =
    -1 ENOENT (No such file or directory)
    [pid 25300] 0.000062 stat("/usr/bin/ls", 0x7fff8049adb0) = -1
    ENOENT (No such file or directory)
    [pid 25300] 0.000051 stat("/bin/ls", {st_mode=S_IFREG|0755,
    st_size=91272, ...}) = 0
    [pid 25300] 0.000190 access("/bin/ls", X_OK) = 0
    [pid 25300] 0.000032 access("/bin/ls", R_OK) = 0
    [pid 25300] 0.000036 stat("/bin/ls", {st_mode=S_IFREG|0755,
    st_size=91272, ...}) = 0
    [pid 25300] 0.000179 access("/bin/ls", X_OK) = 0
    [pid 25300] 0.000042 access("/bin/ls", R_OK) = 0
    [pid 25300] 0.000049 rt_sigaction(SIGINT, {SIG_DFL, [],
    SA_RESTORER, 0x348a2302d0}, {SIG_DFL, [], SA_RESTORER, 0x348a2302d0},
    8) = 0
    [pid 25300] 0.000108 rt_sigaction(SIGQUIT, {SIG_DFL, [],
    SA_RESTORER, 0x348a2302d0}, {0x1, [], SA_RESTORER, 0x348a2302d0}, 8) =
    0
    [pid 25300] 0.000105 rt_sigaction(SIGCHLD, {SIG_DFL, [],
    SA_RESTORER, 0x348a2302d0}, {0x436360, [], SA_RESTORER, 0x348a2302d0},
    8) = 0
    [pid 25300] 0.000110 execve("/bin/ls", ["ls", "Hello"], [/* 48
    vars */]) = 0
    [pid 25300] 0.002655 brk(0) = 0x3052000
    [pid 25300] 0.000086 mmap(NULL, 4096, PROT_READ|PROT_WRITE,
    MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2af0fbafe000
    [pid 25300] 0.000153 mmap(NULL, 4096, PROT_READ|PROT_WRITE,
    MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2af0fbaff000
    [pid 25300] 0.000068 access("/etc/ld.so.preload", R_OK) = -1
    ENOENT (No such file or directory)
    [pid 25300] 0.000108 open("/etc/ld.so.cache", O_RDONLY) = 3
    [pid 25300] 0.000059 fstat(3, {st_mode=S_IFREG|0644,
    st_size=187712, ...}) = 0
    [pid 25300] 0.000238 mmap(NULL, 187712, PROT_READ, MAP_PRIVATE,
    3, 0) = 0x2af0fbb00000
    [pid 25300] 0.000037 close(3) = 0
    [pid 25300] 0.000169 open("/lib64/librt.so.1", O_RDONLY) = 3
    [pid 25300] 0.000061 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>
    \0\1\0\0\0 \"\240\2164\0\0\0"..., 832) = 832
    [pid 25300] 0.000077 fstat(3, {st_mode=S_IFREG|0755,
    st_size=53448, ...}) = 0
    [pid 25300] 0.000158 mmap(0x348ea00000, 2132936, PROT_READ|
    PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x348ea00000
    [pid 25300] 0.000044 mprotect(0x348ea07000, 2097152, PROT_NONE) =
    0
    [pid 25300] 0.000042 mmap(0x348ec07000, 8192, PROT_READ|
    PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x7000) =
    0x348ec07000
    [pid 25300] 0.000131 close(3) = 0
    [pid 25300] 0.000139 open("/lib64/libacl.so.1", O_RDONLY) = 3
    [pid 25300] 0.000059 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>
    \0\1\0\0\0\240\30@\2234\0\0\0"..., 832) = 832
    [pid 25300] 0.000080 fstat(3, {st_mode=S_IFREG|0755,
    st_size=27920, ...}) = 0
    [pid 25300] 0.000156 mmap(0x3493400000, 2120904, PROT_READ|
    PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x3493400000
    [pid 25300] 0.000041 mprotect(0x3493406000, 2093056, PROT_NONE) =
    0
    [pid 25300] 0.000036 mmap(0x3493605000, 4096, PROT_READ|
    PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x5000) =
    0x3493605000
    [pid 25300] 0.000062 close(3) = 0
    [pid 25300] 0.000052 open("/lib64/libselinux.so.1", O_RDONLY) = 3
    [pid 25300] 0.000061 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>
    \0\1\0\0\0\340E`\2214\0\0\0"..., 832) = 832
    [pid 25300] 0.000066 fstat(3, {st_mode=S_IFREG|0755,
    st_size=95464, ...}) = 0
    [pid 25300] 0.000185 mmap(0x3491600000, 2192800, PROT_READ|
    PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x3491600000
    [pid 25300] 0.000041 mprotect(0x3491615000, 2097152, PROT_NONE) =
    0
    [pid 25300] 0.000030 mmap(0x3491815000, 8192, PROT_READ|
    PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x15000) =
    0x3491815000
    [pid 25300] 0.000076 mmap(0x3491817000, 1440, PROT_READ|
    PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x3491817000
    [pid 25300] 0.000063 close(3) = 0
    [pid 25300] 0.000081 open("/lib64/libc.so.6", O_RDONLY) = 3
    [pid 25300] 0.000066 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>
    \0\1\0\0\0\220\332!\2124\0\0\0"..., 832) = 832
    [pid 25300] 0.000078 fstat(3, {st_mode=S_IFREG|0755,
    st_size=1722304, ...}) = 0
    [pid 25300] 0.000160 mmap(NULL, 4096, PROT_READ|PROT_WRITE,
    MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2af0fbb2e000
    [pid 25300] 0.000047 mmap(0x348a200000, 3502424, PROT_READ|
    PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x348a200000
    [pid 25300] 0.000041 mprotect(0x348a34e000, 2097152, PROT_NONE) =
    0
    [pid 25300] 0.000030 mmap(0x348a54e000, 20480, PROT_READ|
    PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x14e000) =
    0x348a54e000
    [pid 25300] 0.000081 mmap(0x348a553000, 16728, PROT_READ|
    PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x348a553000
    [pid 25300] 0.000061 close(3) = 0
    [pid 25300] 0.000080 open("/lib64/libpthread.so.0", O_RDONLY) = 3
    [pid 25300] 0.000073 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>
    \0\1\0\0\0\240W\340\2124\0\0\0"..., 832) = 832
    [pid 25300] 0.000084 fstat(3, {st_mode=S_IFREG|0755,
    st_size=145824, ...}) = 0
    [pid 25300] 0.000155 mmap(0x348ae00000, 2204528, PROT_READ|
    PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x348ae00000
    [pid 25300] 0.000041 mprotect(0x348ae16000, 2093056, PROT_NONE) =
    0
    [pid 25300] 0.000032 mmap(0x348b015000, 8192, PROT_READ|
    PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x15000) =
    0x348b015000
    [pid 25300] 0.000058 mmap(0x348b017000, 13168, PROT_READ|
    PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x348b017000
    [pid 25300] 0.000063 close(3) = 0
    [pid 25300] 0.000073 open("/lib64/libattr.so.1", O_RDONLY) = 3
    [pid 25300] 0.000088 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>
    \0\1\0\0\0\320\17\300\2254\0\0\0"..., 832) = 832
    [pid 25300] 0.000085 fstat(3, {st_mode=S_IFREG|0755,
    st_size=17888, ...}) = 0
    [pid 25300] 0.000155 mmap(0x3495c00000, 2110728, PROT_READ|
    PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x3495c00000
    [pid 25300] 0.000030 mprotect(0x3495c04000, 2093056, PROT_NONE) =
    0
    [pid 25300] 0.000042 mmap(0x3495e03000, 4096, PROT_READ|
    PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x3000) =
    0x3495e03000
    [pid 25300] 0.000066 close(3) = 0
    [pid 25300] 0.000109 open("/lib64/libdl.so.2", O_RDONLY) = 3
    [pid 25300] 0.000075 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>
    \0\1\0\0\0\20\16\240\2124\0\0\0"..., 832) = 832
    [pid 25300] 0.000070 fstat(3, {st_mode=S_IFREG|0755,
    st_size=23360, ...}) = 0
    [pid 25300] 0.000156 mmap(NULL, 4096, PROT_READ|PROT_WRITE,
    MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2af0fbb2f000
    [pid 25300] 0.000045 mmap(0x348aa00000, 2109696, PROT_READ|
    PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x348aa00000
    [pid 25300] 0.000042 mprotect(0x348aa02000, 2097152, PROT_NONE) =
    0
    [pid 25300] 0.000030 mmap(0x348ac02000, 8192, PROT_READ|
    PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) =
    0x348ac02000
    [pid 25300] 0.000094 close(3) = 0
    [pid 25300] 0.000050 open("/lib64/libsepol.so.1", O_RDONLY) = 3
    [pid 25300] 0.000054 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>
    \0\1\0\0\0@= \2214\0\0\0"..., 832) = 832
    [pid 25300] 0.000074 fstat(3, {st_mode=S_IFREG|0755,
    st_size=247496, ...}) = 0
    [pid 25300] 0.000168 mmap(0x3491200000, 2383168, PROT_READ|
    PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x3491200000
    [pid 25300] 0.000043 mprotect(0x349123b000, 2097152, PROT_NONE) =
    0
    [pid 25300] 0.000036 mmap(0x349143b000, 4096, PROT_READ|
    PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x3b000) =
    0x349143b000
    [pid 25300] 0.000099 mmap(0x349143c000, 40256, PROT_READ|
    PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x349143c000
    [pid 25300] 0.000048 close(3) = 0
    [pid 25300] 0.000134 mmap(NULL, 4096, PROT_READ|PROT_WRITE,
    MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2af0fbb30000
    [pid 25300] 0.000070 mmap(NULL, 4096, PROT_READ|PROT_WRITE,
    MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2af0fbb31000
    [pid 25300] 0.000045 arch_prctl(ARCH_SET_FS, 0x2af0fbb30e20) = 0
    [pid 25300] 0.000130 mprotect(0x348ec07000, 4096, PROT_READ) = 0
    [pid 25300] 0.000036 mprotect(0x348a54e000, 16384, PROT_READ) = 0
    [pid 25300] 0.000028 mprotect(0x348b015000, 4096, PROT_READ) = 0
    [pid 25300] 0.000037 mprotect(0x348a01c000, 4096, PROT_READ) = 0
    [pid 25300] 0.000037 mprotect(0x348ac02000, 4096, PROT_READ) = 0
    [pid 25300] 0.000056 munmap(0x2af0fbb00000, 187712) = 0
    [pid 25300] 0.000281 set_tid_address(0x2af0fbb30eb0) = 25300
    [pid 25300] 0.000020 set_robust_list(0x2af0fbb30ec0, 0x18) = 0
    [pid 25300] 0.000026 futex(0x7fff2b1bab2c, FUTEX_WAKE_PRIVATE, 1)
    = 0
    [pid 25300] 0.000107 rt_sigaction(SIGRTMIN, {0x348ae05380, [],
    SA_RESTORER|SA_SIGINFO, 0x348ae0eb70}, NULL, 8) = 0
    [pid 25300] 0.000075 rt_sigaction(SIGRT_1, {0x348ae052b0, [],
    SA_RESTORER|SA_RESTART|SA_SIGINFO, 0x348ae0eb70}, NULL, 8) = 0
    [pid 25300] 0.000074 rt_sigprocmask(SIG_UNBLOCK, [RTMIN RT_1],
    NULL, 8) = 0
    [pid 25300] 0.000061 getrlimit(RLIMIT_STACK,
    {rlim_cur=10240*1024, rlim_max=RLIM_INFINITY}) = 0
    [pid 25300] 0.000312 access("/etc/selinux/", F_OK) = 0
    [pid 25300] 0.000431 brk(0) = 0x3052000
    [pid 25300] 0.000045 brk(0x3073000) = 0x3073000
    [pid 25300] 0.000086 open("/etc/selinux/config", O_RDONLY) = 3
    [pid 25300] 0.000151 fstat(3, {st_mode=S_IFREG|0644,
    st_size=511, ...}) = 0
    [pid 25300] 0.000167 mmap(NULL, 4096, PROT_READ|PROT_WRITE,
    MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2af0fbb00000
    [pid 25300] 0.000033 read(3, "# This file controls the state
    o"..., 4096) = 511
    [pid 25300] 0.000151 read(3, "", 4096) = 0
    [pid 25300] 0.000055 close(3) = 0
    [pid 25300] 0.000033 munmap(0x2af0fbb00000, 4096) = 0
    [pid 25300] 0.000226 open("/proc/mounts", O_RDONLY) = 3
    [pid 25300] 0.000163 fstat(3, {st_mode=S_IFREG|0444,
    st_size=0, ...}) = 0
    [pid 25300] 0.000159 mmap(NULL, 4096, PROT_READ|PROT_WRITE,
    MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2af0fbb00000
    [pid 25300] 0.000033 read(3, "rootfs / rootfs rw 0 0\n/dev/
    root"..., 1024) = 546
    [pid 25300] 0.000114 read(3, "", 1024) = 0
    [pid 25300] 0.000026 close(3) = 0
    [pid 25300] 0.000041 munmap(0x2af0fbb00000, 4096) = 0
    [pid 25300] 0.000296 open("/usr/lib/locale/locale-archive",
    O_RDONLY) = 3
    [pid 25300] 0.000084 fstat(3, {st_mode=S_IFREG|0644,
    st_size=56426032, ...}) = 0
    [pid 25300] 0.000156 mmap(NULL, 56426032, PROT_READ, MAP_PRIVATE,
    3, 0) = 0x2af0fbb32000
    [pid 25300] 0.000060 close(3) = 0
    [pid 25300] 0.000206 ioctl(1, SNDCTL_TMR_TIMEBASE or TCGETS,
    {B38400 opost isig icanon echo ...}) = 0
    [pid 25300] 0.000160 ioctl(1, TIOCGWINSZ, {ws_row=25, ws_col=80,
    ws_xpixel=0, ws_ypixel=0}) = 0
    [pid 25300] 0.000127 stat("Hello", 0x30535e8) = -1 ENOENT (No
    such file or directory)
    [pid 25300] 0.000044 lstat("Hello", 0x30535e8) = -1 ENOENT (No
    such file or directory)
    [pid 25300] 0.000112 write(2, "ls: ", 4ls: ) = 4
    [pid 25300] 0.000051 write(2, "Hello", 5Hello) = 5
    [pid 25300] 0.000097 open("/usr/share/locale/locale.alias",
    O_RDONLY) = 3
    [pid 25300] 0.000080 fstat(3, {st_mode=S_IFREG|0644,
    st_size=2528, ...}) = 0
    [pid 25300] 0.000196 mmap(NULL, 4096, PROT_READ|PROT_WRITE,
    MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2af0ff102000
    [pid 25300] 0.000029 read(3, "# Locale name alias data base.
    \n#"..., 4096) = 2528
    [pid 25300] 0.000160 read(3, "", 4096) = 0
    [pid 25300] 0.000051 close(3) = 0
    [pid 25300] 0.000034 munmap(0x2af0ff102000, 4096) = 0
    [pid 25300] 0.000080 open("/usr/share/locale/en_US.UTF-8/
    LC_MESSAGES/libc.mo", O_RDONLY) = -1 ENOENT (No such file or
    directory)
    [pid 25300] 0.000095 open("/usr/share/locale/en_US.utf8/
    LC_MESSAGES/libc.mo", O_RDONLY) = -1 ENOENT (No such file or
    directory)
    [pid 25300] 0.000086 open("/usr/share/locale/en_US/LC_MESSAGES/
    libc.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
    [pid 25300] 0.000086 open("/usr/share/locale/en.UTF-8/LC_MESSAGES/
    libc.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
    [pid 25300] 0.000095 open("/usr/share/locale/en.utf8/LC_MESSAGES/
    libc.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
    [pid 25300] 0.000092 open("/usr/share/locale/en/LC_MESSAGES/
    libc.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
    [pid 25300] 0.000099 write(2, ": No such file or directory", 27:
    No such file or directory) = 27
    [pid 25300] 0.000054 write(2, "\n", 1
    ) = 1
    [pid 25300] 0.000040 close(1) = 0
    [pid 25300] 0.000057 exit_group(2) = ?
    Process 25263 resumed
    Process 25300 detached
    0.001769 <... wait4 resumed> [{WIFEXITED(s) && WEXITSTATUS(s) ==
    2}], 0, NULL) = 25300
    0.000055 rt_sigaction(SIGINT, {SIG_DFL, [], SA_RESTORER,
    0x348a2302d0}, NULL, 8) = 0
    0.000086 rt_sigaction(SIGQUIT, {SIG_DFL, [], SA_RESTORER,
    0x348a2302d0}, NULL, 8) = 0
    0.000064 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
    0.000033 --- SIGCHLD (Child exited) @ 0 (0) ---
    0.000131 fstat(1, {st_mode=S_IFCHR|0600, st_rdev=makedev(136,
    24), ...}) = 0
    0.000162 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|
    MAP_ANONYMOUS, -1, 0) = 0x2b871a9cd000
    0.000141 write(1, "Time before: 1326320210.213833\n", 31Time
    before: 1326320210.213833
    ) = 31
    0.000081 write(1, "Time after: 1326320211.131237\n", 31Time
    after: 1326320211.131237
    ) = 31
    0.000088 exit_group(31) = ?


    Nasty, nasty ;-)

    CU,
    Elmar
     
    Elmar, Jan 11, 2012
    #15
    1. Advertising

Want to reply to this thread or ask your own question?

It takes just 2 minutes to sign up (and it's free!). Just click the sign up button to choose a username and then you can ask your own questions on the forum.
Similar Threads
  1. =?Utf-8?B?bWF2cmlja18xMDE=?=

    SetAuthCookie works some times and fails some times?

    =?Utf-8?B?bWF2cmlja18xMDE=?=, Mar 23, 2006, in forum: ASP .Net
    Replies:
    0
    Views:
    521
    =?Utf-8?B?bWF2cmlja18xMDE=?=
    Mar 23, 2006
  2. =?Utf-8?B?bWF2cmlja18xMDE=?=

    Forms Authentication Fails some times and not some times???

    =?Utf-8?B?bWF2cmlja18xMDE=?=, Mar 28, 2006, in forum: ASP .Net
    Replies:
    0
    Views:
    497
    =?Utf-8?B?bWF2cmlja18xMDE=?=
    Mar 28, 2006
  3. Andre Charbonneau

    XPath queries getting slower and slower...

    Andre Charbonneau, Feb 15, 2005, in forum: Java
    Replies:
    0
    Views:
    551
    Andre Charbonneau
    Feb 15, 2005
  4. Jack Steven
    Replies:
    2
    Views:
    450
    Chris Rebert
    Mar 9, 2009
  5. Jon

    TZ cache on some Linux kernels

    Jon, Oct 1, 2003, in forum: Perl Misc
    Replies:
    2
    Views:
    127
    Ilya Zakharevich
    Oct 2, 2003
Loading...

Share This Page