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 300 -d 10 -w /tmp/misc2012/2012-09-02-22:42/full/p2cudf-full-1.15/trendy-size/upgrade/easy/rand381.cudf.log.runsolver /home/competition/p2cudf-full-1.15/p2cudf-full-1.15 /home/competition/data/upgrade/easy/rand381.cudf /tmp/misc2012/2012-09-02-22:42/full/p2cudf-full-1.15/trendy-size/upgrade/easy/rand381.cudf.result -count(removed),-sum(solution,installedsize),-notuptodate(solution),-unsat_recommends(solution),-count(new) 

Enforcing CPUTime limit (soft limit, will send signal-name then SIGKILL): 300 seconds
Enforcing CPUTime limit (hard limit, will send SIGXCPU): 330 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.00 1.02 1.00 2/60 24858
/proc/meminfo: memFree=642852/1022884 swapFree=0/0
[pid=24858] ppid=24857 vsize=3152 CPUtime=0
/proc/24858/stat : 24858 (runsolver) R 24857 32685 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 1 0 41635671 3227648 32 18446744073709551615 134512640 134586868 4294447872 4294445920 4151469104 0 0 16781316 24578 0 0 0 17 0 0 0 0 0 0
/proc/24858/statm: 788 32 0 19 0 73 0
Current StackSize limit: 8192 KiB


[startup+0.160927 s]
/proc/loadavg: 1.00 1.02 1.00 2/60 24858
/proc/meminfo: memFree=642852/1022884 swapFree=0/0
[pid=24858] ppid=24857 vsize=9168 CPUtime=0
/proc/24858/stat : 24858 (p2cudf-full-1.1) S 24857 24858 32685 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 41635671 9388032 330 18446744073709551615 4194304 5129932 140734658429792 140734658427936 140415821341790 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24858/statm: 2292 330 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+0.20034 s]
/proc/loadavg: 1.00 1.02 1.00 2/60 24858
/proc/meminfo: memFree=642852/1022884 swapFree=0/0
[pid=24858] ppid=24857 vsize=9168 CPUtime=0
/proc/24858/stat : 24858 (p2cudf-full-1.1) S 24857 24858 32685 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 41635671 9388032 330 18446744073709551615 4194304 5129932 140734658429792 140734658427936 140415821341790 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24858/statm: 2292 330 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+0.300318 s]
/proc/loadavg: 1.00 1.02 1.00 2/60 24858
/proc/meminfo: memFree=642852/1022884 swapFree=0/0
[pid=24858] ppid=24857 vsize=9168 CPUtime=0
/proc/24858/stat : 24858 (p2cudf-full-1.1) S 24857 24858 32685 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 41635671 9388032 330 18446744073709551615 4194304 5129932 140734658429792 140734658427936 140415821341790 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24858/statm: 2292 330 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+0.700249 s]
/proc/loadavg: 1.00 1.02 1.00 2/60 24858
/proc/meminfo: memFree=642852/1022884 swapFree=0/0
[pid=24858] ppid=24857 vsize=9168 CPUtime=0
/proc/24858/stat : 24858 (p2cudf-full-1.1) S 24857 24858 32685 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 41635671 9388032 330 18446744073709551615 4194304 5129932 140734658429792 140734658427936 140415821341790 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24858/statm: 2292 330 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+1.50059 s]
/proc/loadavg: 1.00 1.02 1.00 4/71 24870
/proc/meminfo: memFree=571456/1022884 swapFree=0/0
[pid=24858] ppid=24857 vsize=9168 CPUtime=0
/proc/24858/stat : 24858 (p2cudf-full-1.1) S 24857 24858 32685 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 41635671 9388032 330 18446744073709551615 4194304 5129932 140734658429792 140734658427936 140415821341790 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24858/statm: 2292 330 280 229 0 52 0
[pid=24861] ppid=24858 vsize=1052812 CPUtime=1.47
/proc/24861/stat : 24861 (java) S 24858 24858 32685 0 -1 4202496 38698 0 0 0 134 13 0 0 20 0 10 0 41635672 1078079488 34412 18446744073709551615 4194304 4228012 140737060245440 140737060236464 139643286548085 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24861/statm: 263203 34412 2348 9 0 250553 0
[pid=24861/tid=24862] ppid=24858 vsize=1052812 CPUtime=0.67
/proc/24861/task/24862/stat : 24862 (java) R 24858 24858 32685 0 -1 4202560 18054 0 0 0 60 7 0 0 20 0 10 0 41635673 1078079488 34412 18446744073709551615 4194304 4228012 140737060245440 139643293074080 139643190504070 0 4 0 16800975 0 0 0 -1 0 0 0 1 0 0
[pid=24861/tid=24863] ppid=24858 vsize=1052812 CPUtime=0
/proc/24861/task/24863/stat : 24863 (java) S 24858 24858 32685 0 -1 4202560 4 0 0 0 0 0 0 0 20 0 10 0 41635675 1078079488 34412 18446744073709551615 4194304 4228012 140737060245440 139643185720448 139643286562379 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24864] ppid=24858 vsize=1052812 CPUtime=0
/proc/24861/task/24864/stat : 24864 (java) S 24858 24858 32685 0 -1 4202560 15 0 0 0 0 0 0 0 20 0 10 0 41635676 1078079488 34412 18446744073709551615 4194304 4228012 140737060245440 139643184666640 139643286561492 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24865] ppid=24858 vsize=1052812 CPUtime=0
/proc/24861/task/24865/stat : 24865 (java) S 24858 24858 32685 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 10 0 41635676 1078079488 34412 18446744073709551615 4194304 4228012 140737060245440 139643183613856 139643286561492 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24866] ppid=24858 vsize=1052812 CPUtime=0
/proc/24861/task/24866/stat : 24866 (java) S 24858 24858 32685 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 41635680 1078079488 34412 18446744073709551615 4194304 4228012 140737060245440 139643182562288 139643286570016 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24867] ppid=24858 vsize=1052812 CPUtime=0.38
/proc/24861/task/24867/stat : 24867 (java) R 24858 24858 32685 0 -1 4202560 10188 0 0 0 36 2 0 0 20 0 10 0 41635680 1078079488 34412 18446744073709551615 4194304 4228012 140737060245440 139643181497224 139643272706741 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24868] ppid=24858 vsize=1052812 CPUtime=0.39
/proc/24861/task/24868/stat : 24868 (java) R 24858 24858 32685 0 -1 4202560 9165 0 0 0 37 2 0 0 20 0 10 0 41635680 1078079488 34412 18446744073709551615 4194304 4228012 140737060245440 139643180444504 139643270822135 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24869] ppid=24858 vsize=1052812 CPUtime=0
/proc/24861/task/24869/stat : 24869 (java) S 24858 24858 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 41635680 1078079488 34412 18446744073709551615 4194304 4228012 140737060245440 139643179404496 139643286561492 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24870] ppid=24858 vsize=1052812 CPUtime=0
/proc/24861/task/24870/stat : 24870 (java) S 24858 24858 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 41635680 1078079488 34412 18446744073709551615 4194304 4228012 140737060245440 139643178352000 139643286562379 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 1.47
Current children cumulated vsize (KiB) 1061980

[startup+3.10059 s]
/proc/loadavg: 1.16 1.05 1.01 2/71 24870
/proc/meminfo: memFree=362640/1022884 swapFree=0/0
[pid=24858] ppid=24857 vsize=9168 CPUtime=0
/proc/24858/stat : 24858 (p2cudf-full-1.1) S 24857 24858 32685 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 41635671 9388032 330 18446744073709551615 4194304 5129932 140734658429792 140734658427936 140415821341790 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24858/statm: 2292 330 280 229 0 52 0
[pid=24861] ppid=24858 vsize=1052340 CPUtime=3.05
/proc/24861/stat : 24861 (java) S 24858 24858 32685 0 -1 4202496 98001 0 0 0 273 32 0 0 20 0 10 0 41635672 1077596160 92335 18446744073709551615 4194304 4228012 140737060245440 140737060236464 139643286548085 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24861/statm: 263085 92335 2369 9 0 250435 0
[pid=24861/tid=24862] ppid=24858 vsize=1052340 CPUtime=1.53
/proc/24861/task/24862/stat : 24862 (java) R 24858 24858 32685 0 -1 4202560 47424 0 0 0 138 15 0 0 20 0 10 0 41635673 1077596160 92335 18446744073709551615 4194304 4228012 140737060245440 139643293074112 139643190889219 0 4 0 16800975 0 0 0 -1 0 0 0 1 0 0
[pid=24861/tid=24863] ppid=24858 vsize=1052340 CPUtime=0.46
/proc/24861/task/24863/stat : 24863 (java) S 24858 24858 32685 0 -1 4202560 29274 0 0 0 34 12 0 0 20 0 10 0 41635675 1077596160 92335 18446744073709551615 4194304 4228012 140737060245440 139643185720448 139643286562379 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24864] ppid=24858 vsize=1052340 CPUtime=0
/proc/24861/task/24864/stat : 24864 (java) S 24858 24858 32685 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 41635676 1077596160 92335 18446744073709551615 4194304 4228012 140737060245440 139643184666640 139643286561492 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24865] ppid=24858 vsize=1052340 CPUtime=0
/proc/24861/task/24865/stat : 24865 (java) S 24858 24858 32685 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 41635676 1077596160 92335 18446744073709551615 4194304 4228012 140737060245440 139643183613856 139643286561492 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24866] ppid=24858 vsize=1052340 CPUtime=0
/proc/24861/task/24866/stat : 24866 (java) S 24858 24858 32685 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 41635680 1077596160 92335 18446744073709551615 4194304 4228012 140737060245440 139643182562288 139643286570016 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24867] ppid=24858 vsize=1052340 CPUtime=0.49
/proc/24861/task/24867/stat : 24867 (java) R 24858 24858 32685 0 -1 4202560 10739 0 0 0 47 2 0 0 20 0 10 0 41635680 1077596160 92335 18446744073709551615 4194304 4228012 140737060245440 139643181509392 139643272221082 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24868] ppid=24858 vsize=1052340 CPUtime=0.53
/proc/24861/task/24868/stat : 24868 (java) R 24858 24858 32685 0 -1 4202560 9273 0 0 0 51 2 0 0 20 0 10 0 41635680 1077596160 92335 18446744073709551615 4194304 4228012 140737060245440 139643180456720 139643270852637 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24869] ppid=24858 vsize=1052340 CPUtime=0
/proc/24861/task/24869/stat : 24869 (java) S 24858 24858 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 41635680 1077596160 92335 18446744073709551615 4194304 4228012 140737060245440 139643179404496 139643286561492 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24870] ppid=24858 vsize=1052340 CPUtime=0
/proc/24861/task/24870/stat : 24870 (java) S 24858 24858 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 41635680 1077596160 92335 18446744073709551615 4194304 4228012 140737060245440 139643178352000 139643286562379 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 3.05
Current children cumulated vsize (KiB) 1061508

[startup+6.30061 s]
/proc/loadavg: 1.16 1.05 1.01 4/71 24870
/proc/meminfo: memFree=162504/1022884 swapFree=0/0
[pid=24858] ppid=24857 vsize=9168 CPUtime=0
/proc/24858/stat : 24858 (p2cudf-full-1.1) S 24857 24858 32685 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 41635671 9388032 330 18446744073709551615 4194304 5129932 140734658429792 140734658427936 140415821341790 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24858/statm: 2292 330 280 229 0 52 0
[pid=24861] ppid=24858 vsize=1052340 CPUtime=6.17
/proc/24861/stat : 24861 (java) S 24858 24858 32685 0 -1 4202496 124819 0 0 0 573 44 0 0 20 0 10 0 41635672 1077596160 116612 18446744073709551615 4194304 4228012 140737060245440 140737060236464 139643286548085 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24861/statm: 263085 116612 2375 9 0 250435 0
[pid=24861/tid=24862] ppid=24858 vsize=1052340 CPUtime=2.88
/proc/24861/task/24862/stat : 24862 (java) R 24858 24858 32685 0 -1 4202560 47728 0 0 0 272 16 0 0 20 0 10 0 41635673 1077596160 116612 18446744073709551615 4194304 4228012 140737060245440 139643293081856 139643190711795 0 4 0 16800975 0 0 0 -1 0 0 0 6 0 0
[pid=24861/tid=24863] ppid=24858 vsize=1052340 CPUtime=0.96
/proc/24861/task/24863/stat : 24863 (java) S 24858 24858 32685 0 -1 4202560 53196 0 0 0 76 20 0 0 20 0 10 0 41635675 1077596160 116612 18446744073709551615 4194304 4228012 140737060245440 139643185720448 139643286562379 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24864] ppid=24858 vsize=1052340 CPUtime=0
/proc/24861/task/24864/stat : 24864 (java) S 24858 24858 32685 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 41635676 1077596160 116612 18446744073709551615 4194304 4228012 140737060245440 139643184666640 139643286561492 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24865] ppid=24858 vsize=1052340 CPUtime=0
/proc/24861/task/24865/stat : 24865 (java) S 24858 24858 32685 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 41635676 1077596160 116612 18446744073709551615 4194304 4228012 140737060245440 139643183613856 139643286561492 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24866] ppid=24858 vsize=1052340 CPUtime=0
/proc/24861/task/24866/stat : 24866 (java) S 24858 24858 32685 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 41635680 1077596160 116612 18446744073709551615 4194304 4228012 140737060245440 139643182562288 139643286570016 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24867] ppid=24858 vsize=1052340 CPUtime=1.2
/proc/24861/task/24867/stat : 24867 (java) R 24858 24858 32685 0 -1 4202560 13149 0 0 0 116 4 0 0 20 0 10 0 41635680 1077596160 116612 18446744073709551615 4194304 4228012 140737060245440 139643181509392 139643269663392 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24868] ppid=24858 vsize=1052340 CPUtime=1.11
/proc/24861/task/24868/stat : 24868 (java) R 24858 24858 32685 0 -1 4202560 9455 0 0 0 108 3 0 0 20 0 10 0 41635680 1077596160 116612 18446744073709551615 4194304 4228012 140737060245440 139643180456720 139643272883444 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24869] ppid=24858 vsize=1052340 CPUtime=0
/proc/24861/task/24869/stat : 24869 (java) S 24858 24858 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 41635680 1077596160 116612 18446744073709551615 4194304 4228012 140737060245440 139643179404496 139643286561492 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24870] ppid=24858 vsize=1052340 CPUtime=0
/proc/24861/task/24870/stat : 24870 (java) S 24858 24858 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 41635680 1077596160 116612 18446744073709551615 4194304 4228012 140737060245440 139643178352000 139643286562379 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 6.17
Current children cumulated vsize (KiB) 1061508

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

[startup+6.40086 s]
/proc/loadavg: 1.16 1.05 1.01 4/71 24870
/proc/meminfo: memFree=162504/1022884 swapFree=0/0
[pid=24858] ppid=24857 vsize=9168 CPUtime=0
/proc/24858/stat : 24858 (p2cudf-full-1.1) S 24857 24858 32685 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 41635671 9388032 330 18446744073709551615 4194304 5129932 140734658429792 140734658427936 140415821341790 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24858/statm: 2292 330 280 229 0 52 0
[pid=24861] ppid=24858 vsize=1052340 CPUtime=6.27
/proc/24861/stat : 24861 (java) S 24858 24858 32685 0 -1 4202496 124827 0 0 0 583 44 0 0 20 0 10 0 41635672 1077596160 116620 18446744073709551615 4194304 4228012 140737060245440 140737060236464 139643286548085 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24861/statm: 263085 116620 2376 9 0 250435 0
[pid=24861/tid=24862] ppid=24858 vsize=1052340 CPUtime=2.94
/proc/24861/task/24862/stat : 24862 (java) R 24858 24858 32685 0 -1 4202560 47729 0 0 0 278 16 0 0 20 0 10 0 41635673 1077596160 116620 18446744073709551615 4194304 4228012 140737060245440 139643293082296 139643190597942 0 4 0 16800975 0 0 0 -1 0 0 0 6 0 0
[pid=24861/tid=24863] ppid=24858 vsize=1052340 CPUtime=0.96
/proc/24861/task/24863/stat : 24863 (java) S 24858 24858 32685 0 -1 4202560 53196 0 0 0 76 20 0 0 20 0 10 0 41635675 1077596160 116620 18446744073709551615 4194304 4228012 140737060245440 139643185720448 139643286562379 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24864] ppid=24858 vsize=1052340 CPUtime=0
/proc/24861/task/24864/stat : 24864 (java) S 24858 24858 32685 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 41635676 1077596160 116620 18446744073709551615 4194304 4228012 140737060245440 139643184666640 139643286561492 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24865] ppid=24858 vsize=1052340 CPUtime=0
/proc/24861/task/24865/stat : 24865 (java) S 24858 24858 32685 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 41635676 1077596160 116620 18446744073709551615 4194304 4228012 140737060245440 139643183613856 139643286561492 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24866] ppid=24858 vsize=1052340 CPUtime=0
/proc/24861/task/24866/stat : 24866 (java) S 24858 24858 32685 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 41635680 1077596160 116620 18446744073709551615 4194304 4228012 140737060245440 139643182562288 139643286570016 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24867] ppid=24858 vsize=1052340 CPUtime=1.22
/proc/24861/task/24867/stat : 24867 (java) S 24858 24858 32685 0 -1 4202560 13151 0 0 0 118 4 0 0 20 0 10 0 41635680 1077596160 116620 18446744073709551615 4194304 4228012 140737060245440 139643181509648 139643286561492 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24868] ppid=24858 vsize=1052340 CPUtime=1.13
/proc/24861/task/24868/stat : 24868 (java) S 24858 24858 32685 0 -1 4202560 9460 0 0 0 110 3 0 0 20 0 10 0 41635680 1077596160 116620 18446744073709551615 4194304 4228012 140737060245440 139643180456976 139643286561492 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24869] ppid=24858 vsize=1052340 CPUtime=0
/proc/24861/task/24869/stat : 24869 (java) S 24858 24858 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 41635680 1077596160 116620 18446744073709551615 4194304 4228012 140737060245440 139643179404496 139643286561492 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24870] ppid=24858 vsize=1052340 CPUtime=0
/proc/24861/task/24870/stat : 24870 (java) S 24858 24858 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 41635680 1077596160 116620 18446744073709551615 4194304 4228012 140737060245440 139643178352000 139643286562379 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 6.27
Current children cumulated vsize (KiB) 1061508

[startup+7.20063 s]
/proc/loadavg: 1.31 1.09 1.02 2/71 24870
/proc/meminfo: memFree=162752/1022884 swapFree=0/0
[pid=24858] ppid=24857 vsize=9168 CPUtime=0
/proc/24858/stat : 24858 (p2cudf-full-1.1) S 24857 24858 32685 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 41635671 9388032 330 18446744073709551615 4194304 5129932 140734658429792 140734658427936 140415821341790 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24858/statm: 2292 330 280 229 0 52 0
[pid=24861] ppid=24858 vsize=1053368 CPUtime=7.07
/proc/24861/stat : 24861 (java) S 24858 24858 32685 0 -1 4202496 124938 0 0 0 662 45 0 0 20 0 11 0 41635672 1078648832 116731 18446744073709551615 4194304 4228012 140737060245440 140737060236464 139643286548085 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24861/statm: 263342 116731 2378 9 0 250692 0
[pid=24861/tid=24862] ppid=24858 vsize=1053368 CPUtime=3.31
/proc/24861/task/24862/stat : 24862 (java) R 24858 24858 32685 0 -1 4202560 47799 0 0 0 315 16 0 0 20 0 11 0 41635673 1078648832 116731 18446744073709551615 4194304 4228012 140737060245440 139643293081568 139643190594216 0 4 0 16800975 0 0 0 -1 0 0 0 6 0 0
[pid=24861/tid=24863] ppid=24858 vsize=1053368 CPUtime=0.97
/proc/24861/task/24863/stat : 24863 (java) S 24858 24858 32685 0 -1 4202560 53197 0 0 0 76 21 0 0 20 0 11 0 41635675 1078648832 116731 18446744073709551615 4194304 4228012 140737060245440 139643185720448 139643286562379 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24864] ppid=24858 vsize=1053368 CPUtime=0
/proc/24861/task/24864/stat : 24864 (java) S 24858 24858 32685 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 41635676 1078648832 116731 18446744073709551615 4194304 4228012 140737060245440 139643184666640 139643286561492 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24865] ppid=24858 vsize=1053368 CPUtime=0
/proc/24861/task/24865/stat : 24865 (java) S 24858 24858 32685 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 41635676 1078648832 116731 18446744073709551615 4194304 4228012 140737060245440 139643183613856 139643286561492 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24866] ppid=24858 vsize=1053368 CPUtime=0
/proc/24861/task/24866/stat : 24866 (java) S 24858 24858 32685 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 41635680 1078648832 116731 18446744073709551615 4194304 4228012 140737060245440 139643182562288 139643286570016 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24867] ppid=24858 vsize=1053368 CPUtime=1.42
/proc/24861/task/24867/stat : 24867 (java) R 24858 24858 32685 0 -1 4202560 13174 0 0 0 138 4 0 0 20 0 11 0 41635680 1078648832 116731 18446744073709551615 4194304 4228012 140737060245440 139643181509392 139643270852772 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24868] ppid=24858 vsize=1053368 CPUtime=1.34
/proc/24861/task/24868/stat : 24868 (java) R 24858 24858 32685 0 -1 4202560 9471 0 0 0 131 3 0 0 20 0 11 0 41635680 1078648832 116731 18446744073709551615 4194304 4228012 140737060245440 139643180456720 139643272120528 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24869] ppid=24858 vsize=1053368 CPUtime=0
/proc/24861/task/24869/stat : 24869 (java) S 24858 24858 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 41635680 1078648832 116731 18446744073709551615 4194304 4228012 140737060245440 139643179404496 139643286561492 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24870] ppid=24858 vsize=1053368 CPUtime=0
/proc/24861/task/24870/stat : 24870 (java) S 24858 24858 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 41635680 1078648832 116731 18446744073709551615 4194304 4228012 140737060245440 139643178352000 139643286562379 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 7.07
Current children cumulated vsize (KiB) 1062536

[startup+8.00092 s]
/proc/loadavg: 1.31 1.09 1.02 1/72 24872
/proc/meminfo: memFree=162496/1022884 swapFree=0/0
[pid=24858] ppid=24857 vsize=9168 CPUtime=0
/proc/24858/stat : 24858 (p2cudf-full-1.1) S 24857 24858 32685 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 41635671 9388032 330 18446744073709551615 4194304 5129932 140734658429792 140734658427936 140415821341790 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24858/statm: 2292 330 280 229 0 52 0
[pid=24861] ppid=24858 vsize=1054396 CPUtime=7.51
/proc/24861/stat : 24861 (java) S 24858 24858 32685 0 -1 4202496 125000 0 0 0 706 45 0 0 20 0 11 0 41635672 1079701504 116791 18446744073709551615 4194304 4228012 140737060245440 140737060236464 139643286548085 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24861/statm: 263599 116791 2380 9 0 250949 0
[pid=24861/tid=24862] ppid=24858 vsize=1054396 CPUtime=3.46
/proc/24861/task/24862/stat : 24862 (java) S 24858 24858 32685 0 -1 4202560 47818 0 0 0 330 16 0 0 20 0 11 0 41635673 1079701504 116791 18446744073709551615 4194304 4228012 140737060245440 139643293082544 139643286561492 0 4 0 16800975 0 0 0 -1 0 0 0 6 0 0
[pid=24861/tid=24863] ppid=24858 vsize=1054396 CPUtime=0.97
/proc/24861/task/24863/stat : 24863 (java) S 24858 24858 32685 0 -1 4202560 53197 0 0 0 76 21 0 0 20 0 11 0 41635675 1079701504 116791 18446744073709551615 4194304 4228012 140737060245440 139643185720448 139643286562379 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24864] ppid=24858 vsize=1054396 CPUtime=0
/proc/24861/task/24864/stat : 24864 (java) S 24858 24858 32685 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 41635676 1079701504 116791 18446744073709551615 4194304 4228012 140737060245440 139643184666640 139643286561492 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24865] ppid=24858 vsize=1054396 CPUtime=0
/proc/24861/task/24865/stat : 24865 (java) S 24858 24858 32685 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 41635676 1079701504 116791 18446744073709551615 4194304 4228012 140737060245440 139643183613856 139643286561492 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24866] ppid=24858 vsize=1054396 CPUtime=0
/proc/24861/task/24866/stat : 24866 (java) S 24858 24858 32685 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 41635680 1079701504 116791 18446744073709551615 4194304 4228012 140737060245440 139643182562288 139643286570016 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24867] ppid=24858 vsize=1054396 CPUtime=1.57
/proc/24861/task/24867/stat : 24867 (java) S 24858 24858 32685 0 -1 4202560 13194 0 0 0 153 4 0 0 20 0 11 0 41635680 1079701504 116791 18446744073709551615 4194304 4228012 140737060245440 139643181509648 139643286561492 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24868] ppid=24858 vsize=1054396 CPUtime=1.48
/proc/24861/task/24868/stat : 24868 (java) S 24858 24858 32685 0 -1 4202560 9488 0 0 0 145 3 0 0 20 0 11 0 41635680 1079701504 116791 18446744073709551615 4194304 4228012 140737060245440 139643180456976 139643286561492 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24869] ppid=24858 vsize=1054396 CPUtime=0
/proc/24861/task/24869/stat : 24869 (java) S 24858 24858 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 41635680 1079701504 116791 18446744073709551615 4194304 4228012 140737060245440 139643179404496 139643286561492 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24870] ppid=24858 vsize=1054396 CPUtime=0
/proc/24861/task/24870/stat : 24870 (java) S 24858 24858 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 41635680 1079701504 116791 18446744073709551615 4194304 4228012 140737060245440 139643178352000 139643286562379 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24872] ppid=24858 vsize=1054396 CPUtime=0
/proc/24861/task/24872/stat : 24872 (java) S 24858 24858 32685 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 11 0 41636434 1079701504 116791 18446744073709551615 4194304 4228012 140737060245440 139643176097968 139643286562379 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 7.51
Current children cumulated vsize (KiB) 1063564

[startup+8.20083 s]
/proc/loadavg: 1.31 1.09 1.02 1/72 24872
/proc/meminfo: memFree=162496/1022884 swapFree=0/0
[pid=24858] ppid=24857 vsize=9168 CPUtime=0
/proc/24858/stat : 24858 (p2cudf-full-1.1) S 24857 24858 32685 0 -1 4202496 455 292 0 0 0 0 0 0 20 0 1 0 41635671 9388032 330 18446744073709551615 4194304 5129932 140734658429792 140734658427936 140415821341790 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/24858/statm: 2292 330 280 229 0 52 0
[pid=24861] ppid=24858 vsize=1054396 CPUtime=7.58
/proc/24861/stat : 24861 (java) S 24858 24858 32685 0 -1 4202496 125003 0 0 0 711 47 0 0 20 0 11 0 41635672 1079701504 116794 18446744073709551615 4194304 4228012 140737060245440 140737060236464 139643286548085 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/24861/statm: 263599 116794 2380 9 0 250949 0
[pid=24861/tid=24862] ppid=24858 vsize=1054396 CPUtime=3.46
/proc/24861/task/24862/stat : 24862 (java) S 24858 24858 32685 0 -1 4202560 47818 0 0 0 330 16 0 0 20 0 11 0 41635673 1079701504 116794 18446744073709551615 4194304 4228012 140737060245440 139643293082544 139643286561492 0 4 0 16800975 0 0 0 -1 0 0 0 6 0 0
[pid=24861/tid=24863] ppid=24858 vsize=1054396 CPUtime=0.97
/proc/24861/task/24863/stat : 24863 (java) S 24858 24858 32685 0 -1 4202560 53197 0 0 0 76 21 0 0 20 0 11 0 41635675 1079701504 116794 18446744073709551615 4194304 4228012 140737060245440 139643185720448 139643286562379 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24864] ppid=24858 vsize=1054396 CPUtime=0
/proc/24861/task/24864/stat : 24864 (java) S 24858 24858 32685 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 41635676 1079701504 116794 18446744073709551615 4194304 4228012 140737060245440 139643184666640 139643286561492 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24865] ppid=24858 vsize=1054396 CPUtime=0
/proc/24861/task/24865/stat : 24865 (java) S 24858 24858 32685 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 41635676 1079701504 116794 18446744073709551615 4194304 4228012 140737060245440 139643183613856 139643286561492 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24866] ppid=24858 vsize=1054396 CPUtime=0
/proc/24861/task/24866/stat : 24866 (java) S 24858 24858 32685 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 41635680 1079701504 116794 18446744073709551615 4194304 4228012 140737060245440 139643182562288 139643286570016 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24867] ppid=24858 vsize=1054396 CPUtime=1.57
/proc/24861/task/24867/stat : 24867 (java) S 24858 24858 32685 0 -1 4202560 13194 0 0 0 153 4 0 0 20 0 11 0 41635680 1079701504 116794 18446744073709551615 4194304 4228012 140737060245440 139643181509648 139643286561492 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24868] ppid=24858 vsize=1054396 CPUtime=1.48
/proc/24861/task/24868/stat : 24868 (java) S 24858 24858 32685 0 -1 4202560 9488 0 0 0 145 3 0 0 20 0 11 0 41635680 1079701504 116794 18446744073709551615 4194304 4228012 140737060245440 139643180456976 139643286561492 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24869] ppid=24858 vsize=1054396 CPUtime=0
/proc/24861/task/24869/stat : 24869 (java) S 24858 24858 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 41635680 1079701504 116794 18446744073709551615 4194304 4228012 140737060245440 139643179404496 139643286561492 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24870] ppid=24858 vsize=1054396 CPUtime=0
/proc/24861/task/24870/stat : 24870 (java) S 24858 24858 32685 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 41635680 1079701504 116794 18446744073709551615 4194304 4228012 140737060245440 139643178352000 139643286562379 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=24861/tid=24872] ppid=24858 vsize=1054396 CPUtime=0.06
/proc/24861/task/24872/stat : 24872 (java) R 24858 24858 32685 0 -1 4202560 9 0 0 0 4 2 0 0 20 0 11 0 41636434 1079701504 116794 18446744073709551615 4194304 4228012 140737060245440 139643176088768 139643190605304 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 7.58
Current children cumulated vsize (KiB) 1063564

Child status: 0
Real time (s): 8.29435
CPU time (s): 7.68848
CPU user time (s): 7.14445
CPU system time (s): 0.544034
CPU usage (%): 92.6954
Max. virtual memory (cumulated for all children) (KiB): 1063564

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 7.14445
system time used= 0.544034
maximum resident set size= 468728
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 125773
page faults= 0
swaps= 0
block input operations= 42384
block output operations= 176
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 823
involuntary context switches= 1749

runsolver used 0.020001 second user time and 0.056003 second system time

The end