runsolver Copyright (C) 2010 Olivier ROUSSEL

This is runsolver version 3.2.9a (svn: 651)

This program is distributed in the hope that it will be useful,
but WITHOUT ANY WARRANTY; without even the implied warranty of
MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
GNU General Public License for more details.

command line: runsolver -s SIGUSR1 -M 1124 -C 150 -d 10 -w /tmp/misc2012/2012-09-02-17:21/basic/p2cudf-basic-1.15/embedded/real/301cbe92-a79c-11e0-9181-00163e1e087d.cudf.log.runsolver /home/competition/p2cudf-basic-1.15/p2cudf-basic-1.15 /home/competition/data/real/301cbe92-a79c-11e0-9181-00163e1e087d.cudf /tmp/misc2012/2012-09-02-17:21/basic/p2cudf-basic-1.15/embedded/real/301cbe92-a79c-11e0-9181-00163e1e087d.cudf.result -sum(solution,installedsize),-count(removed) 

Enforcing CPUTime limit (soft limit, will send signal-name then SIGKILL): 150 seconds
Enforcing CPUTime limit (hard limit, will send SIGXCPU): 180 seconds
Enforcing VSIZE limit (soft limit, will send signal-name then SIGKILL): 1150976 KiB
Enforcing VSIZE limit (hard limit, stack expansion will fail with SIGSEGV, brk() and mmap() will return ENOMEM): 1202176 KiB

[startup+0 s]
/proc/loadavg: 1.30 1.20 1.02 2/59 24344
/proc/meminfo: memFree=475608/1022884 swapFree=0/0
[pid=24344] ppid=24343 vsize=3152 CPUtime=0
/proc/24344/stat : 24344 (runsolver) R 24343 1733 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 1 0 115995967 3227648 33 18446744073709551615 134512640 134586868 4291084720 4291082768 4152013872 0 0 16781316 24578 0 0 0 17 0 0 0 0 0 0
/proc/24344/statm: 788 33 0 19 0 73 0
Current StackSize limit: 8192 KiB


[startup+0.106839 s]
/proc/loadavg: 1.30 1.20 1.02 2/59 24344
/proc/meminfo: memFree=475608/1022884 swapFree=0/0
[pid=24344] ppid=24343 vsize=9172 CPUtime=0
/proc/24344/stat : 24344 (p2cudf-basic-1.) S 24343 24344 1733 0 -1 4202496 460 290 0 0 0 0 0 0 20 0 1 0 115995967 9392128 332 18446744073709551615 4194304 5129932 140736591569488 140736591567632 140300370203742 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24344/statm: 2293 332 280 229 0 53 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9172

[startup+0.200264 s]
/proc/loadavg: 1.30 1.20 1.02 2/59 24344
/proc/meminfo: memFree=475608/1022884 swapFree=0/0
[pid=24344] ppid=24343 vsize=9172 CPUtime=0
/proc/24344/stat : 24344 (p2cudf-basic-1.) S 24343 24344 1733 0 -1 4202496 460 290 0 0 0 0 0 0 20 0 1 0 115995967 9392128 332 18446744073709551615 4194304 5129932 140736591569488 140736591567632 140300370203742 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24344/statm: 2293 332 280 229 0 53 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9172

[startup+0.300301 s]
/proc/loadavg: 1.30 1.20 1.02 2/59 24344
/proc/meminfo: memFree=475608/1022884 swapFree=0/0
[pid=24344] ppid=24343 vsize=9172 CPUtime=0
/proc/24344/stat : 24344 (p2cudf-basic-1.) S 24343 24344 1733 0 -1 4202496 460 290 0 0 0 0 0 0 20 0 1 0 115995967 9392128 332 18446744073709551615 4194304 5129932 140736591569488 140736591567632 140300370203742 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24344/statm: 2293 332 280 229 0 53 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9172

[startup+0.700226 s]
/proc/loadavg: 1.30 1.20 1.02 2/59 24344
/proc/meminfo: memFree=475608/1022884 swapFree=0/0
[pid=24344] ppid=24343 vsize=9172 CPUtime=0
/proc/24344/stat : 24344 (p2cudf-basic-1.) S 24343 24344 1733 0 -1 4202496 460 290 0 0 0 0 0 0 20 0 1 0 115995967 9392128 332 18446744073709551615 4194304 5129932 140736591569488 140736591567632 140300370203742 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24344/statm: 2293 332 280 229 0 53 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9172

[startup+1.50075 s]
/proc/loadavg: 1.30 1.20 1.02 4/70 24356
/proc/meminfo: memFree=430748/1022884 swapFree=0/0
[pid=24344] ppid=24343 vsize=9172 CPUtime=0
/proc/24344/stat : 24344 (p2cudf-basic-1.) S 24343 24344 1733 0 -1 4202496 460 290 0 0 0 0 0 0 20 0 1 0 115995967 9392128 332 18446744073709551615 4194304 5129932 140736591569488 140736591567632 140300370203742 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24344/statm: 2293 332 280 229 0 53 0
[pid=24347] ppid=24344 vsize=1059316 CPUtime=1.46
/proc/24347/stat : 24347 (java) S 24344 24344 1733 0 -1 4202496 32280 0 0 0 135 11 0 0 20 0 10 0 115995968 1084739584 29448 18446744073709551615 4194304 4228012 140736373087376 140736373078400 140382259744373 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24347/statm: 264829 29448 2348 9 0 252179 0
[pid=24347/tid=24348] ppid=24344 vsize=1059316 CPUtime=0.65
/proc/24347/task/24348/stat : 24348 (java) R 24344 24344 1733 0 -1 4202560 13125 0 0 0 59 6 0 0 20 0 10 0 115995968 1084739584 29448 18446744073709551615 4194304 4228012 140736373087376 140382266270368 140382163752417 0 4 0 16800975 0 0 0 -1 0 0 0 2 0 0
[pid=24347/tid=24349] ppid=24344 vsize=1059316 CPUtime=0
/proc/24347/task/24349/stat : 24349 (java) S 24344 24344 1733 0 -1 4202560 4 0 0 0 0 0 0 0 20 0 10 0 115995970 1084739584 29448 18446744073709551615 4194304 4228012 140736373087376 140382158916736 140382259758667 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24350] ppid=24344 vsize=1059316 CPUtime=0
/proc/24347/task/24350/stat : 24350 (java) S 24344 24344 1733 0 -1 4202560 15 0 0 0 0 0 0 0 20 0 10 0 115995970 1084739584 29448 18446744073709551615 4194304 4228012 140736373087376 140382157862928 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24351] ppid=24344 vsize=1059316 CPUtime=0
/proc/24347/task/24351/stat : 24351 (java) S 24344 24344 1733 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 10 0 115995971 1084739584 29448 18446744073709551615 4194304 4228012 140736373087376 140382156810144 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24352] ppid=24344 vsize=1059316 CPUtime=0
/proc/24347/task/24352/stat : 24352 (java) S 24344 24344 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 115995973 1084739584 29448 18446744073709551615 4194304 4228012 140736373087376 140382155758576 140382259766304 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24353] ppid=24344 vsize=1059316 CPUtime=0.42
/proc/24347/task/24353/stat : 24353 (java) R 24344 24344 1733 0 -1 4202560 9012 0 0 0 40 2 0 0 20 0 10 0 115995973 1084739584 29448 18446744073709551615 4194304 4228012 140736373087376 140382154693784 140382243342607 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24354] ppid=24344 vsize=1059316 CPUtime=0.37
/proc/24347/task/24354/stat : 24354 (java) R 24344 24344 1733 0 -1 4202560 8850 0 0 0 36 1 0 0 20 0 10 0 115995973 1084739584 29448 18446744073709551615 4194304 4228012 140736373087376 140382153638472 140382245417370 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24355] ppid=24344 vsize=1059316 CPUtime=0
/proc/24347/task/24355/stat : 24355 (java) S 24344 24344 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115995973 1084739584 29448 18446744073709551615 4194304 4228012 140736373087376 140382152600784 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24356] ppid=24344 vsize=1059316 CPUtime=0
/proc/24347/task/24356/stat : 24356 (java) S 24344 24344 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115995973 1084739584 29448 18446744073709551615 4194304 4228012 140736373087376 140382151548288 140382259758667 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 1.46
Current children cumulated vsize (KiB) 1068488

[startup+3.10057 s]
/proc/loadavg: 1.30 1.20 1.02 4/70 24356
/proc/meminfo: memFree=330184/1022884 swapFree=0/0
[pid=24344] ppid=24343 vsize=9172 CPUtime=0
/proc/24344/stat : 24344 (p2cudf-basic-1.) S 24343 24344 1733 0 -1 4202496 460 290 0 0 0 0 0 0 20 0 1 0 115995967 9392128 332 18446744073709551615 4194304 5129932 140736591569488 140736591567632 140300370203742 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24344/statm: 2293 332 280 229 0 53 0
[pid=24347] ppid=24344 vsize=1057652 CPUtime=3.04
/proc/24347/stat : 24347 (java) S 24344 24344 1733 0 -1 4202496 90402 0 0 0 274 30 0 0 20 0 10 0 115995968 1083035648 86262 18446744073709551615 4194304 4228012 140736373087376 140736373078400 140382259744373 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24347/statm: 264413 86262 2369 9 0 251763 0
[pid=24347/tid=24348] ppid=24344 vsize=1057652 CPUtime=1.38
/proc/24347/task/24348/stat : 24348 (java) S 24344 24344 1733 0 -1 4202560 47423 0 0 0 120 18 0 0 20 0 10 0 115995968 1083035648 86262 18446744073709551615 4194304 4228012 140736373087376 140382266278320 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 2 0 0
[pid=24347/tid=24349] ppid=24344 vsize=1057652 CPUtime=0.31
/proc/24347/task/24349/stat : 24349 (java) R 24344 24344 1733 0 -1 4202560 22052 0 0 0 23 8 0 0 20 0 10 0 115995970 1083035648 86262 18446744073709551615 4194304 4228012 140736373087376 140382158916112 140382244055080 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24350] ppid=24344 vsize=1057652 CPUtime=0
/proc/24347/task/24350/stat : 24350 (java) S 24344 24344 1733 0 -1 4202560 15 0 0 0 0 0 0 0 20 0 10 0 115995970 1083035648 86262 18446744073709551615 4194304 4228012 140736373087376 140382157862928 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24351] ppid=24344 vsize=1057652 CPUtime=0
/proc/24347/task/24351/stat : 24351 (java) S 24344 24344 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 115995971 1083035648 86262 18446744073709551615 4194304 4228012 140736373087376 140382156810144 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24352] ppid=24344 vsize=1057652 CPUtime=0
/proc/24347/task/24352/stat : 24352 (java) S 24344 24344 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 115995973 1083035648 86262 18446744073709551615 4194304 4228012 140736373087376 140382155758576 140382259766304 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24353] ppid=24344 vsize=1057652 CPUtime=0.66
/proc/24347/task/24353/stat : 24353 (java) S 24344 24344 1733 0 -1 4202560 10270 0 0 0 64 2 0 0 20 0 10 0 115995973 1083035648 86262 18446744073709551615 4194304 4228012 140736373087376 140382154705936 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24354] ppid=24344 vsize=1057652 CPUtime=0.66
/proc/24347/task/24354/stat : 24354 (java) S 24344 24344 1733 0 -1 4202560 9365 0 0 0 65 1 0 0 20 0 10 0 115995973 1083035648 86262 18446744073709551615 4194304 4228012 140736373087376 140382153653264 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24355] ppid=24344 vsize=1057652 CPUtime=0
/proc/24347/task/24355/stat : 24355 (java) S 24344 24344 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115995973 1083035648 86262 18446744073709551615 4194304 4228012 140736373087376 140382152600784 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24356] ppid=24344 vsize=1057652 CPUtime=0
/proc/24347/task/24356/stat : 24356 (java) S 24344 24344 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115995973 1083035648 86262 18446744073709551615 4194304 4228012 140736373087376 140382151548288 140382259758667 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 3.04
Current children cumulated vsize (KiB) 1066824

[startup+6.30057 s]
/proc/loadavg: 1.28 1.20 1.02 4/70 24356
/proc/meminfo: memFree=19564/1022884 swapFree=0/0
[pid=24344] ppid=24343 vsize=9172 CPUtime=0
/proc/24344/stat : 24344 (p2cudf-basic-1.) S 24343 24344 1733 0 -1 4202496 460 290 0 0 0 0 0 0 20 0 1 0 115995967 9392128 332 18446744073709551615 4194304 5129932 140736591569488 140736591567632 140300370203742 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24344/statm: 2293 332 280 229 0 53 0
[pid=24347] ppid=24344 vsize=1057652 CPUtime=6.12
/proc/24347/stat : 24347 (java) S 24344 24344 1733 0 -1 4202496 115877 0 0 0 575 37 0 0 20 0 10 0 115995968 1083035648 111079 18446744073709551615 4194304 4228012 140736373087376 140736373078400 140382259744373 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24347/statm: 264413 111079 2373 9 0 251763 0
[pid=24347/tid=24348] ppid=24344 vsize=1057652 CPUtime=2.98
/proc/24347/task/24348/stat : 24348 (java) R 24344 24344 1733 0 -1 4202560 47721 0 0 0 278 20 0 0 20 0 10 0 115995968 1083035648 111079 18446744073709551615 4194304 4228012 140736373087376 140382266278144 140382163701320 0 4 0 16800975 0 0 0 -1 0 0 0 11 0 0
[pid=24347/tid=24349] ppid=24344 vsize=1057652 CPUtime=1.03
/proc/24347/task/24349/stat : 24349 (java) S 24344 24344 1733 0 -1 4202560 47075 0 0 0 91 12 0 0 20 0 10 0 115995970 1083035648 111079 18446744073709551615 4194304 4228012 140736373087376 140382158916736 140382259758667 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24350] ppid=24344 vsize=1057652 CPUtime=0
/proc/24347/task/24350/stat : 24350 (java) S 24344 24344 1733 0 -1 4202560 15 0 0 0 0 0 0 0 20 0 10 0 115995970 1083035648 111079 18446744073709551615 4194304 4228012 140736373087376 140382157862928 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24351] ppid=24344 vsize=1057652 CPUtime=0
/proc/24347/task/24351/stat : 24351 (java) S 24344 24344 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 115995971 1083035648 111079 18446744073709551615 4194304 4228012 140736373087376 140382156810144 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24352] ppid=24344 vsize=1057652 CPUtime=0
/proc/24347/task/24352/stat : 24352 (java) S 24344 24344 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 115995973 1083035648 111079 18446744073709551615 4194304 4228012 140736373087376 140382155758576 140382259766304 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24353] ppid=24344 vsize=1057652 CPUtime=1.04
/proc/24347/task/24353/stat : 24353 (java) R 24344 24344 1733 0 -1 4202560 10388 0 0 0 102 2 0 0 20 0 10 0 115995973 1083035648 111079 18446744073709551615 4194304 4228012 140736373087376 140382154705680 140382246431320 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24354] ppid=24344 vsize=1057652 CPUtime=1.03
/proc/24347/task/24354/stat : 24354 (java) R 24344 24344 1733 0 -1 4202560 9401 0 0 0 102 1 0 0 20 0 10 0 115995973 1083035648 111079 18446744073709551615 4194304 4228012 140736373087376 140382153653008 140382246445539 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24355] ppid=24344 vsize=1057652 CPUtime=0
/proc/24347/task/24355/stat : 24355 (java) S 24344 24344 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115995973 1083035648 111079 18446744073709551615 4194304 4228012 140736373087376 140382152600784 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24356] ppid=24344 vsize=1057652 CPUtime=0
/proc/24347/task/24356/stat : 24356 (java) S 24344 24344 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115995973 1083035648 111079 18446744073709551615 4194304 4228012 140736373087376 140382151548288 140382259758667 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 6.12
Current children cumulated vsize (KiB) 1066824

Solver just ended. Dumping a history of the last processes samples

[startup+6.40074 s]
/proc/loadavg: 1.28 1.20 1.02 4/70 24356
/proc/meminfo: memFree=19564/1022884 swapFree=0/0
[pid=24344] ppid=24343 vsize=9172 CPUtime=0
/proc/24344/stat : 24344 (p2cudf-basic-1.) S 24343 24344 1733 0 -1 4202496 460 290 0 0 0 0 0 0 20 0 1 0 115995967 9392128 332 18446744073709551615 4194304 5129932 140736591569488 140736591567632 140300370203742 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24344/statm: 2293 332 280 229 0 53 0
[pid=24347] ppid=24344 vsize=1057652 CPUtime=6.22
/proc/24347/stat : 24347 (java) S 24344 24344 1733 0 -1 4202496 115888 0 0 0 585 37 0 0 20 0 10 0 115995968 1083035648 111090 18446744073709551615 4194304 4228012 140736373087376 140736373078400 140382259744373 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24347/statm: 264413 111090 2373 9 0 251763 0
[pid=24347/tid=24348] ppid=24344 vsize=1057652 CPUtime=3.02
/proc/24347/task/24348/stat : 24348 (java) R 24344 24344 1733 0 -1 4202560 47723 0 0 0 282 20 0 0 20 0 10 0 115995968 1083035648 111090 18446744073709551615 4194304 4228012 140736373087376 140382266278472 140382163792880 0 4 0 16800975 0 0 0 -1 0 0 0 11 0 0
[pid=24347/tid=24349] ppid=24344 vsize=1057652 CPUtime=1.03
/proc/24347/task/24349/stat : 24349 (java) S 24344 24344 1733 0 -1 4202560 47075 0 0 0 91 12 0 0 20 0 10 0 115995970 1083035648 111090 18446744073709551615 4194304 4228012 140736373087376 140382158916736 140382259758667 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24350] ppid=24344 vsize=1057652 CPUtime=0
/proc/24347/task/24350/stat : 24350 (java) S 24344 24344 1733 0 -1 4202560 15 0 0 0 0 0 0 0 20 0 10 0 115995970 1083035648 111090 18446744073709551615 4194304 4228012 140736373087376 140382157862928 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24351] ppid=24344 vsize=1057652 CPUtime=0
/proc/24347/task/24351/stat : 24351 (java) S 24344 24344 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 115995971 1083035648 111090 18446744073709551615 4194304 4228012 140736373087376 140382156810144 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24352] ppid=24344 vsize=1057652 CPUtime=0
/proc/24347/task/24352/stat : 24352 (java) S 24344 24344 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 115995973 1083035648 111090 18446744073709551615 4194304 4228012 140736373087376 140382155758576 140382259766304 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24353] ppid=24344 vsize=1057652 CPUtime=1.08
/proc/24347/task/24353/stat : 24353 (java) R 24344 24344 1733 0 -1 4202560 10388 0 0 0 106 2 0 0 20 0 10 0 115995973 1083035648 111090 18446744073709551615 4194304 4228012 140736373087376 140382154705680 140382246444077 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24354] ppid=24344 vsize=1057652 CPUtime=1.06
/proc/24347/task/24354/stat : 24354 (java) R 24344 24344 1733 0 -1 4202560 9410 0 0 0 105 1 0 0 20 0 10 0 115995973 1083035648 111090 18446744073709551615 4194304 4228012 140736373087376 140382153653008 140382243575360 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24355] ppid=24344 vsize=1057652 CPUtime=0
/proc/24347/task/24355/stat : 24355 (java) S 24344 24344 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115995973 1083035648 111090 18446744073709551615 4194304 4228012 140736373087376 140382152600784 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24356] ppid=24344 vsize=1057652 CPUtime=0
/proc/24347/task/24356/stat : 24356 (java) S 24344 24344 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115995973 1083035648 111090 18446744073709551615 4194304 4228012 140736373087376 140382151548288 140382259758667 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 6.22
Current children cumulated vsize (KiB) 1066824

[startup+7.20058 s]
/proc/loadavg: 1.28 1.20 1.02 4/70 24356
/proc/meminfo: memFree=17952/1022884 swapFree=0/0
[pid=24344] ppid=24343 vsize=9172 CPUtime=0
/proc/24344/stat : 24344 (p2cudf-basic-1.) S 24343 24344 1733 0 -1 4202496 460 290 0 0 0 0 0 0 20 0 1 0 115995967 9392128 332 18446744073709551615 4194304 5129932 140736591569488 140736591567632 140300370203742 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24344/statm: 2293 332 280 229 0 53 0
[pid=24347] ppid=24344 vsize=1057652 CPUtime=7
/proc/24347/stat : 24347 (java) S 24344 24344 1733 0 -1 4202496 116735 0 0 0 663 37 0 0 20 0 10 0 115995968 1083035648 111283 18446744073709551615 4194304 4228012 140736373087376 140736373078400 140382259744373 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24347/statm: 264413 111283 2374 9 0 251763 0
[pid=24347/tid=24348] ppid=24344 vsize=1057652 CPUtime=3.28
/proc/24347/task/24348/stat : 24348 (java) R 24344 24344 1733 0 -1 4202560 47724 0 0 0 308 20 0 0 20 0 10 0 115995968 1083035648 111283 18446744073709551615 4194304 4228012 140736373087376 140382266278616 140382246829315 0 4 0 16800975 0 0 0 -1 0 0 0 11 0 0
[pid=24347/tid=24349] ppid=24344 vsize=1057652 CPUtime=1.03
/proc/24347/task/24349/stat : 24349 (java) S 24344 24344 1733 0 -1 4202560 47075 0 0 0 91 12 0 0 20 0 10 0 115995970 1083035648 111283 18446744073709551615 4194304 4228012 140736373087376 140382158916736 140382259758667 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24350] ppid=24344 vsize=1057652 CPUtime=0
/proc/24347/task/24350/stat : 24350 (java) S 24344 24344 1733 0 -1 4202560 15 0 0 0 0 0 0 0 20 0 10 0 115995970 1083035648 111283 18446744073709551615 4194304 4228012 140736373087376 140382157862928 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24351] ppid=24344 vsize=1057652 CPUtime=0
/proc/24347/task/24351/stat : 24351 (java) S 24344 24344 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 115995971 1083035648 111283 18446744073709551615 4194304 4228012 140736373087376 140382156810144 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24352] ppid=24344 vsize=1057652 CPUtime=0
/proc/24347/task/24352/stat : 24352 (java) S 24344 24344 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 115995973 1083035648 111283 18446744073709551615 4194304 4228012 140736373087376 140382155758576 140382259766304 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24353] ppid=24344 vsize=1057652 CPUtime=1.34
/proc/24347/task/24353/stat : 24353 (java) R 24344 24344 1733 0 -1 4202560 11202 0 0 0 132 2 0 0 20 0 10 0 115995973 1083035648 111283 18446744073709551615 4194304 4228012 140736373087376 140382154705680 140382244020248 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24354] ppid=24344 vsize=1057652 CPUtime=1.33
/proc/24347/task/24354/stat : 24354 (java) R 24344 24344 1733 0 -1 4202560 9442 0 0 0 132 1 0 0 20 0 10 0 115995973 1083035648 111283 18446744073709551615 4194304 4228012 140736373087376 140382153653008 140382244020914 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24355] ppid=24344 vsize=1057652 CPUtime=0
/proc/24347/task/24355/stat : 24355 (java) S 24344 24344 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115995973 1083035648 111283 18446744073709551615 4194304 4228012 140736373087376 140382152600784 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24356] ppid=24344 vsize=1057652 CPUtime=0
/proc/24347/task/24356/stat : 24356 (java) S 24344 24344 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 115995973 1083035648 111283 18446744073709551615 4194304 4228012 140736373087376 140382151548288 140382259758667 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 7
Current children cumulated vsize (KiB) 1066824

[startup+8.00085 s]
/proc/loadavg: 1.26 1.19 1.02 2/70 24356
/proc/meminfo: memFree=17332/1022884 swapFree=0/0
[pid=24344] ppid=24343 vsize=9172 CPUtime=0
/proc/24344/stat : 24344 (p2cudf-basic-1.) S 24343 24344 1733 0 -1 4202496 460 290 0 0 0 0 0 0 20 0 1 0 115995967 9392128 332 18446744073709551615 4194304 5129932 140736591569488 140736591567632 140300370203742 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24344/statm: 2293 332 280 229 0 53 0
[pid=24347] ppid=24344 vsize=1058680 CPUtime=7.65
/proc/24347/stat : 24347 (java) S 24344 24344 1733 0 -1 4202496 116843 0 0 0 728 37 0 0 20 0 11 0 115995968 1084088320 111391 18446744073709551615 4194304 4228012 140736373087376 140736373078400 140382259744373 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24347/statm: 264670 111391 2376 9 0 252020 0
[pid=24347/tid=24348] ppid=24344 vsize=1058680 CPUtime=3.59
/proc/24347/task/24348/stat : 24348 (java) S 24344 24344 1733 0 -1 4202560 47774 0 0 0 339 20 0 0 20 0 11 0 115995968 1084088320 111391 18446744073709551615 4194304 4228012 140736373087376 140382266278832 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 11 0 0
[pid=24347/tid=24349] ppid=24344 vsize=1058680 CPUtime=1.03
/proc/24347/task/24349/stat : 24349 (java) S 24344 24344 1733 0 -1 4202560 47075 0 0 0 91 12 0 0 20 0 11 0 115995970 1084088320 111391 18446744073709551615 4194304 4228012 140736373087376 140382158916736 140382259758667 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24350] ppid=24344 vsize=1058680 CPUtime=0
/proc/24347/task/24350/stat : 24350 (java) S 24344 24344 1733 0 -1 4202560 15 0 0 0 0 0 0 0 20 0 11 0 115995970 1084088320 111391 18446744073709551615 4194304 4228012 140736373087376 140382157862928 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24351] ppid=24344 vsize=1058680 CPUtime=0
/proc/24347/task/24351/stat : 24351 (java) S 24344 24344 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 115995971 1084088320 111391 18446744073709551615 4194304 4228012 140736373087376 140382156810144 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24352] ppid=24344 vsize=1058680 CPUtime=0
/proc/24347/task/24352/stat : 24352 (java) S 24344 24344 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 115995973 1084088320 111391 18446744073709551615 4194304 4228012 140736373087376 140382155758576 140382259766304 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24353] ppid=24344 vsize=1058680 CPUtime=1.48
/proc/24347/task/24353/stat : 24353 (java) S 24344 24344 1733 0 -1 4202560 11225 0 0 0 146 2 0 0 20 0 11 0 115995973 1084088320 111391 18446744073709551615 4194304 4228012 140736373087376 140382154705936 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24354] ppid=24344 vsize=1058680 CPUtime=1.51
/proc/24347/task/24354/stat : 24354 (java) S 24344 24344 1733 0 -1 4202560 9471 0 0 0 150 1 0 0 20 0 11 0 115995973 1084088320 111391 18446744073709551615 4194304 4228012 140736373087376 140382153653264 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24355] ppid=24344 vsize=1058680 CPUtime=0
/proc/24347/task/24355/stat : 24355 (java) S 24344 24344 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 115995973 1084088320 111391 18446744073709551615 4194304 4228012 140736373087376 140382152600784 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24356] ppid=24344 vsize=1058680 CPUtime=0
/proc/24347/task/24356/stat : 24356 (java) S 24344 24344 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 115995973 1084088320 111391 18446744073709551615 4194304 4228012 140736373087376 140382151548288 140382259758667 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 7.65
Current children cumulated vsize (KiB) 1067852

[startup+8.20083 s]
/proc/loadavg: 1.26 1.19 1.02 2/70 24356
/proc/meminfo: memFree=17332/1022884 swapFree=0/0
[pid=24344] ppid=24343 vsize=9172 CPUtime=0
/proc/24344/stat : 24344 (p2cudf-basic-1.) S 24343 24344 1733 0 -1 4202496 460 290 0 0 0 0 0 0 20 0 1 0 115995967 9392128 332 18446744073709551615 4194304 5129932 140736591569488 140736591567632 140300370203742 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24344/statm: 2293 332 280 229 0 53 0
[pid=24347] ppid=24344 vsize=1058680 CPUtime=7.65
/proc/24347/stat : 24347 (java) S 24344 24344 1733 0 -1 4202496 116843 0 0 0 728 37 0 0 20 0 11 0 115995968 1084088320 111391 18446744073709551615 4194304 4228012 140736373087376 140736373078400 140382259744373 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24347/statm: 264670 111391 2376 9 0 252020 0
[pid=24347/tid=24348] ppid=24344 vsize=1058680 CPUtime=3.59
/proc/24347/task/24348/stat : 24348 (java) S 24344 24344 1733 0 -1 4202560 47774 0 0 0 339 20 0 0 20 0 11 0 115995968 1084088320 111391 18446744073709551615 4194304 4228012 140736373087376 140382266278832 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 11 0 0
[pid=24347/tid=24349] ppid=24344 vsize=1058680 CPUtime=1.03
/proc/24347/task/24349/stat : 24349 (java) S 24344 24344 1733 0 -1 4202560 47075 0 0 0 91 12 0 0 20 0 11 0 115995970 1084088320 111391 18446744073709551615 4194304 4228012 140736373087376 140382158916736 140382259758667 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24350] ppid=24344 vsize=1058680 CPUtime=0
/proc/24347/task/24350/stat : 24350 (java) S 24344 24344 1733 0 -1 4202560 15 0 0 0 0 0 0 0 20 0 11 0 115995970 1084088320 111391 18446744073709551615 4194304 4228012 140736373087376 140382157862928 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24351] ppid=24344 vsize=1058680 CPUtime=0
/proc/24347/task/24351/stat : 24351 (java) S 24344 24344 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 115995971 1084088320 111391 18446744073709551615 4194304 4228012 140736373087376 140382156810144 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24352] ppid=24344 vsize=1058680 CPUtime=0
/proc/24347/task/24352/stat : 24352 (java) S 24344 24344 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 115995973 1084088320 111391 18446744073709551615 4194304 4228012 140736373087376 140382155758576 140382259766304 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24353] ppid=24344 vsize=1058680 CPUtime=1.48
/proc/24347/task/24353/stat : 24353 (java) S 24344 24344 1733 0 -1 4202560 11225 0 0 0 146 2 0 0 20 0 11 0 115995973 1084088320 111391 18446744073709551615 4194304 4228012 140736373087376 140382154705936 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24354] ppid=24344 vsize=1058680 CPUtime=1.51
/proc/24347/task/24354/stat : 24354 (java) S 24344 24344 1733 0 -1 4202560 9471 0 0 0 150 1 0 0 20 0 11 0 115995973 1084088320 111391 18446744073709551615 4194304 4228012 140736373087376 140382153653264 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24355] ppid=24344 vsize=1058680 CPUtime=0
/proc/24347/task/24355/stat : 24355 (java) S 24344 24344 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 115995973 1084088320 111391 18446744073709551615 4194304 4228012 140736373087376 140382152600784 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24356] ppid=24344 vsize=1058680 CPUtime=0
/proc/24347/task/24356/stat : 24356 (java) S 24344 24344 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 115995973 1084088320 111391 18446744073709551615 4194304 4228012 140736373087376 140382151548288 140382259758667 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 7.65
Current children cumulated vsize (KiB) 1067852

[startup+8.30081 s]
/proc/loadavg: 1.26 1.19 1.02 2/70 24356
/proc/meminfo: memFree=17332/1022884 swapFree=0/0
[pid=24344] ppid=24343 vsize=9172 CPUtime=0
/proc/24344/stat : 24344 (p2cudf-basic-1.) S 24343 24344 1733 0 -1 4202496 460 290 0 0 0 0 0 0 20 0 1 0 115995967 9392128 332 18446744073709551615 4194304 5129932 140736591569488 140736591567632 140300370203742 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24344/statm: 2293 332 280 229 0 53 0
[pid=24347] ppid=24344 vsize=1058680 CPUtime=7.65
/proc/24347/stat : 24347 (java) S 24344 24344 1733 0 -1 4202496 116843 0 0 0 728 37 0 0 20 0 11 0 115995968 1084088320 111391 18446744073709551615 4194304 4228012 140736373087376 140736373078400 140382259744373 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24347/statm: 264670 111391 2376 9 0 252020 0
[pid=24347/tid=24348] ppid=24344 vsize=1058680 CPUtime=3.59
/proc/24347/task/24348/stat : 24348 (java) S 24344 24344 1733 0 -1 4202560 47774 0 0 0 339 20 0 0 20 0 11 0 115995968 1084088320 111391 18446744073709551615 4194304 4228012 140736373087376 140382266278832 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 11 0 0
[pid=24347/tid=24349] ppid=24344 vsize=1058680 CPUtime=1.03
/proc/24347/task/24349/stat : 24349 (java) S 24344 24344 1733 0 -1 4202560 47075 0 0 0 91 12 0 0 20 0 11 0 115995970 1084088320 111391 18446744073709551615 4194304 4228012 140736373087376 140382158916736 140382259758667 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24350] ppid=24344 vsize=1058680 CPUtime=0
/proc/24347/task/24350/stat : 24350 (java) S 24344 24344 1733 0 -1 4202560 15 0 0 0 0 0 0 0 20 0 11 0 115995970 1084088320 111391 18446744073709551615 4194304 4228012 140736373087376 140382157862928 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24351] ppid=24344 vsize=1058680 CPUtime=0
/proc/24347/task/24351/stat : 24351 (java) S 24344 24344 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 115995971 1084088320 111391 18446744073709551615 4194304 4228012 140736373087376 140382156810144 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24352] ppid=24344 vsize=1058680 CPUtime=0
/proc/24347/task/24352/stat : 24352 (java) S 24344 24344 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 115995973 1084088320 111391 18446744073709551615 4194304 4228012 140736373087376 140382155758576 140382259766304 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24353] ppid=24344 vsize=1058680 CPUtime=1.48
/proc/24347/task/24353/stat : 24353 (java) S 24344 24344 1733 0 -1 4202560 11225 0 0 0 146 2 0 0 20 0 11 0 115995973 1084088320 111391 18446744073709551615 4194304 4228012 140736373087376 140382154705936 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24354] ppid=24344 vsize=1058680 CPUtime=1.51
/proc/24347/task/24354/stat : 24354 (java) S 24344 24344 1733 0 -1 4202560 9471 0 0 0 150 1 0 0 20 0 11 0 115995973 1084088320 111391 18446744073709551615 4194304 4228012 140736373087376 140382153653264 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24355] ppid=24344 vsize=1058680 CPUtime=0
/proc/24347/task/24355/stat : 24355 (java) S 24344 24344 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 115995973 1084088320 111391 18446744073709551615 4194304 4228012 140736373087376 140382152600784 140382259757780 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24347/tid=24356] ppid=24344 vsize=1058680 CPUtime=0
/proc/24347/task/24356/stat : 24356 (java) S 24344 24344 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 115995973 1084088320 111391 18446744073709551615 4194304 4228012 140736373087376 140382151548288 140382259758667 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 7.65
Current children cumulated vsize (KiB) 1067852

Child status: 0
Real time (s): 8.38503
CPU time (s): 7.72048
CPU user time (s): 7.30446
CPU system time (s): 0.416026
CPU usage (%): 92.0746
Max. virtual memory (cumulated for all children) (KiB): 1070160

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 7.30446
system time used= 0.416026
maximum resident set size= 446772
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 117618
page faults= 0
swaps= 0
block input operations= 41408
block output operations= 80
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 679
involuntary context switches= 2153

runsolver used 0.028001 second user time and 0.056003 second system time

The end