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/real/ca8f656c-db9e-11df-b9cf-00163e3d3b7c.cudf.log.runsolver /home/competition/p2cudf-full-1.15/p2cudf-full-1.15 /home/competition/data/real/ca8f656c-db9e-11df-b9cf-00163e3d3b7c.cudf /tmp/misc2012/2012-09-02-22:42/full/p2cudf-full-1.15/trendy-size/real/ca8f656c-db9e-11df-b9cf-00163e3d3b7c.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
Current StackSize limit: 8192 KiB


[startup+0 s]
/proc/loadavg: 2.11 1.64 1.26 2/59 18920
/proc/meminfo: memFree=476296/1022884 swapFree=0/0
[pid=18920] ppid=18919 vsize=3152 CPUtime=0
/proc/18920/stat : 18920 (runsolver) R 18919 1750 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 1 0 119836563 3227648 32 18446744073709551615 134512640 134586868 4290450912 4290448960 4151358512 0 0 16781316 24578 0 0 0 17 0 0 0 0 0 0
/proc/18920/statm: 788 32 0 19 0 73 0

[startup+0.107426 s]
/proc/loadavg: 2.11 1.64 1.26 2/59 18920
/proc/meminfo: memFree=476296/1022884 swapFree=0/0
[pid=18920] ppid=18919 vsize=9172 CPUtime=0
/proc/18920/stat : 18920 (p2cudf-full-1.1) S 18919 18920 1750 0 -1 4202496 457 291 2 1 0 0 0 0 20 0 1 0 119836563 9392128 332 18446744073709551615 4194304 5129932 140737352715152 140737352713296 140225275094110 0 65536 16781316 65538 0 0 0 17 0 0 0 2 0 0
/proc/18920/statm: 2293 332 280 229 0 53 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9172

[startup+0.200332 s]
/proc/loadavg: 2.11 1.64 1.26 2/59 18920
/proc/meminfo: memFree=476296/1022884 swapFree=0/0
[pid=18920] ppid=18919 vsize=9172 CPUtime=0
/proc/18920/stat : 18920 (p2cudf-full-1.1) S 18919 18920 1750 0 -1 4202496 457 291 2 1 0 0 0 0 20 0 1 0 119836563 9392128 332 18446744073709551615 4194304 5129932 140737352715152 140737352713296 140225275094110 0 65536 16781316 65538 0 0 0 17 0 0 0 2 0 0
/proc/18920/statm: 2293 332 280 229 0 53 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9172

[startup+0.300334 s]
/proc/loadavg: 2.11 1.64 1.26 2/59 18920
/proc/meminfo: memFree=476296/1022884 swapFree=0/0
[pid=18920] ppid=18919 vsize=9172 CPUtime=0
/proc/18920/stat : 18920 (p2cudf-full-1.1) S 18919 18920 1750 0 -1 4202496 457 291 2 1 0 0 0 0 20 0 1 0 119836563 9392128 332 18446744073709551615 4194304 5129932 140737352715152 140737352713296 140225275094110 0 65536 16781316 65538 0 0 0 17 0 0 0 2 0 0
/proc/18920/statm: 2293 332 280 229 0 53 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9172

[startup+0.700236 s]
/proc/loadavg: 2.11 1.64 1.26 2/59 18920
/proc/meminfo: memFree=476296/1022884 swapFree=0/0
[pid=18920] ppid=18919 vsize=9172 CPUtime=0
/proc/18920/stat : 18920 (p2cudf-full-1.1) S 18919 18920 1750 0 -1 4202496 457 291 2 1 0 0 0 0 20 0 1 0 119836563 9392128 332 18446744073709551615 4194304 5129932 140737352715152 140737352713296 140225275094110 0 65536 16781316 65538 0 0 0 17 0 0 0 2 0 0
/proc/18920/statm: 2293 332 280 229 0 53 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9172

[startup+1.50069 s]
/proc/loadavg: 2.11 1.64 1.26 5/70 18932
/proc/meminfo: memFree=432924/1022884 swapFree=0/0
[pid=18920] ppid=18919 vsize=9172 CPUtime=0
/proc/18920/stat : 18920 (p2cudf-full-1.1) S 18919 18920 1750 0 -1 4202496 457 291 2 1 0 0 0 0 20 0 1 0 119836563 9392128 332 18446744073709551615 4194304 5129932 140737352715152 140737352713296 140225275094110 0 65536 16781316 65538 0 0 0 17 0 0 0 2 0 0
/proc/18920/statm: 2293 332 280 229 0 53 0
[pid=18923] ppid=18920 vsize=1050900 CPUtime=1.41
/proc/18923/stat : 18923 (java) S 18920 18920 1750 0 -1 4202496 32408 0 5 0 129 12 0 0 20 0 10 0 119836567 1076121600 29059 18446744073709551615 4194304 4228012 140734912396864 140734912387888 139874137476725 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/18923/statm: 262725 29059 2348 9 0 250075 0
[pid=18923/tid=18924] ppid=18920 vsize=1050900 CPUtime=0.66
/proc/18923/task/18924/stat : 18924 (java) R 18920 18920 1750 0 -1 4202560 13475 0 5 0 58 8 0 0 20 0 10 0 119836568 1076121600 29059 18446744073709551615 4194304 4228012 140734912396864 139874144002720 139874041906642 0 4 0 16800975 0 0 0 -1 0 0 0 3 0 0
[pid=18923/tid=18925] ppid=18920 vsize=1050900 CPUtime=0
/proc/18923/task/18925/stat : 18925 (java) S 18920 18920 1750 0 -1 4202560 3 0 0 0 0 0 0 0 20 0 10 0 119836572 1076121600 29059 18446744073709551615 4194304 4228012 140734912396864 139874036649088 139874137491019 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18926] ppid=18920 vsize=1050900 CPUtime=0
/proc/18923/task/18926/stat : 18926 (java) S 18920 18920 1750 0 -1 4202560 15 0 0 0 0 0 0 0 20 0 10 0 119836573 1076121600 29059 18446744073709551615 4194304 4228012 140734912396864 139874035595280 139874137490132 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18927] ppid=18920 vsize=1050900 CPUtime=0
/proc/18923/task/18927/stat : 18927 (java) S 18920 18920 1750 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 10 0 119836573 1076121600 29059 18446744073709551615 4194304 4228012 140734912396864 139874034542496 139874137490132 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18928] ppid=18920 vsize=1050900 CPUtime=0
/proc/18923/task/18928/stat : 18928 (java) S 18920 18920 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119836577 1076121600 29059 18446744073709551615 4194304 4228012 140734912396864 139874033490928 139874137498656 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18929] ppid=18920 vsize=1050900 CPUtime=0.39
/proc/18923/task/18929/stat : 18929 (java) R 18920 18920 1750 0 -1 4202560 7838 0 0 0 37 2 0 0 20 0 10 0 119836577 1076121600 29059 18446744073709551615 4194304 4228012 140734912396864 139874032423496 139874123168238 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18930] ppid=18920 vsize=1050900 CPUtime=0.34
/proc/18923/task/18930/stat : 18930 (java) R 18920 18920 1750 0 -1 4202560 9805 0 0 0 32 2 0 0 20 0 10 0 119836577 1076121600 29059 18446744073709551615 4194304 4228012 140734912396864 139874031370776 139874123145505 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18931] ppid=18920 vsize=1050900 CPUtime=0
/proc/18923/task/18931/stat : 18931 (java) S 18920 18920 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119836577 1076121600 29059 18446744073709551615 4194304 4228012 140734912396864 139874030333136 139874137490132 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18932] ppid=18920 vsize=1050900 CPUtime=0
/proc/18923/task/18932/stat : 18932 (java) S 18920 18920 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119836577 1076121600 29059 18446744073709551615 4194304 4228012 140734912396864 139874029280640 139874137491019 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 1.41
Current children cumulated vsize (KiB) 1060072

[startup+3.1007 s]
/proc/loadavg: 2.11 1.64 1.26 4/70 18932
/proc/meminfo: memFree=330748/1022884 swapFree=0/0
[pid=18920] ppid=18919 vsize=9172 CPUtime=0
/proc/18920/stat : 18920 (p2cudf-full-1.1) S 18919 18920 1750 0 -1 4202496 457 291 2 1 0 0 0 0 20 0 1 0 119836563 9392128 332 18446744073709551615 4194304 5129932 140737352715152 140737352713296 140225275094110 0 65536 16781316 65538 0 0 0 17 0 0 0 2 0 0
/proc/18920/statm: 2293 332 280 229 0 53 0
[pid=18923] ppid=18920 vsize=1053148 CPUtime=2.99
/proc/18923/stat : 18923 (java) S 18920 18920 1750 0 -1 4202496 76392 0 5 0 269 30 0 0 20 0 10 0 119836567 1078423552 72105 18446744073709551615 4194304 4228012 140734912396864 140734912387888 139874137476725 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/18923/statm: 263287 72105 2368 9 0 250637 0
[pid=18923/tid=18924] ppid=18920 vsize=1053148 CPUtime=1.48
/proc/18923/task/18924/stat : 18924 (java) R 18920 18920 1750 0 -1 4202560 47399 0 5 0 126 22 0 0 20 0 10 0 119836568 1078423552 72105 18446744073709551615 4194304 4228012 140734912396864 139874144002752 139874041877609 0 4 0 16800975 0 0 0 -1 0 0 0 3 0 0
[pid=18923/tid=18925] ppid=18920 vsize=1053148 CPUtime=0.17
/proc/18923/task/18925/stat : 18925 (java) S 18920 18920 1750 0 -1 4202560 8322 0 0 0 14 3 0 0 20 0 10 0 119836572 1078423552 72105 18446744073709551615 4194304 4228012 140734912396864 139874036649088 139874137491019 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18926] ppid=18920 vsize=1053148 CPUtime=0
/proc/18923/task/18926/stat : 18926 (java) S 18920 18920 1750 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 119836573 1078423552 72105 18446744073709551615 4194304 4228012 140734912396864 139874035595280 139874137490132 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18927] ppid=18920 vsize=1053148 CPUtime=0
/proc/18923/task/18927/stat : 18927 (java) S 18920 18920 1750 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 119836573 1078423552 72105 18446744073709551615 4194304 4228012 140734912396864 139874034542496 139874137490132 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18928] ppid=18920 vsize=1053148 CPUtime=0
/proc/18923/task/18928/stat : 18928 (java) S 18920 18920 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119836577 1078423552 72105 18446744073709551615 4194304 4228012 140734912396864 139874033490928 139874137498656 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18929] ppid=18920 vsize=1053148 CPUtime=0.7
/proc/18923/task/18929/stat : 18929 (java) S 18920 18920 1750 0 -1 4202560 8249 0 0 0 68 2 0 0 20 0 10 0 119836577 1078423552 72105 18446744073709551615 4194304 4228012 140734912396864 139874032438288 139874137490132 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18930] ppid=18920 vsize=1053148 CPUtime=0.61
/proc/18923/task/18930/stat : 18930 (java) S 18920 18920 1750 0 -1 4202560 11131 0 0 0 59 2 0 0 20 0 10 0 119836577 1078423552 72105 18446744073709551615 4194304 4228012 140734912396864 139874031385616 139874137490132 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18931] ppid=18920 vsize=1053148 CPUtime=0
/proc/18923/task/18931/stat : 18931 (java) S 18920 18920 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119836577 1078423552 72105 18446744073709551615 4194304 4228012 140734912396864 139874030333136 139874137490132 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18932] ppid=18920 vsize=1053148 CPUtime=0
/proc/18923/task/18932/stat : 18932 (java) S 18920 18920 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119836577 1078423552 72105 18446744073709551615 4194304 4228012 140734912396864 139874029280640 139874137491019 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 2.99
Current children cumulated vsize (KiB) 1062320

[startup+6.30079 s]
/proc/loadavg: 2.18 1.66 1.27 4/70 18932
/proc/meminfo: memFree=93660/1022884 swapFree=0/0
[pid=18920] ppid=18919 vsize=9172 CPUtime=0
/proc/18920/stat : 18920 (p2cudf-full-1.1) S 18919 18920 1750 0 -1 4202496 457 291 2 1 0 0 0 0 20 0 1 0 119836563 9392128 332 18446744073709551615 4194304 5129932 140737352715152 140737352713296 140225275094110 0 65536 16781316 65538 0 0 0 17 0 0 0 2 0 0
/proc/18920/statm: 2293 332 280 229 0 53 0
[pid=18923] ppid=18920 vsize=1050296 CPUtime=6.15
/proc/18923/stat : 18923 (java) S 18920 18920 1750 0 -1 4202496 99581 0 5 0 577 38 0 0 20 0 10 0 119836567 1075503104 94866 18446744073709551615 4194304 4228012 140734912396864 140734912387888 139874137476725 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/18923/statm: 262574 94866 2374 9 0 249924 0
[pid=18923/tid=18924] ppid=18920 vsize=1050296 CPUtime=2.87
/proc/18923/task/18924/stat : 18924 (java) R 18920 18920 1750 0 -1 4202560 47702 0 5 0 263 24 0 0 20 0 10 0 119836568 1075503104 94866 18446744073709551615 4194304 4228012 140734912396864 139874144011256 139874041526244 0 4 0 16800975 0 0 0 -1 0 0 0 3 0 0
[pid=18923/tid=18925] ppid=18920 vsize=1050296 CPUtime=0.63
/proc/18923/task/18925/stat : 18925 (java) S 18920 18920 1750 0 -1 4202560 30286 0 0 0 55 8 0 0 20 0 10 0 119836572 1075503104 94866 18446744073709551615 4194304 4228012 140734912396864 139874036649088 139874137491019 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18926] ppid=18920 vsize=1050296 CPUtime=0
/proc/18923/task/18926/stat : 18926 (java) S 18920 18920 1750 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 119836573 1075503104 94866 18446744073709551615 4194304 4228012 140734912396864 139874035595280 139874137490132 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18927] ppid=18920 vsize=1050296 CPUtime=0
/proc/18923/task/18927/stat : 18927 (java) S 18920 18920 1750 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 119836573 1075503104 94866 18446744073709551615 4194304 4228012 140734912396864 139874034542496 139874137490132 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18928] ppid=18920 vsize=1050296 CPUtime=0
/proc/18923/task/18928/stat : 18928 (java) S 18920 18920 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119836577 1075503104 94866 18446744073709551615 4194304 4228012 140734912396864 139874033490928 139874137498656 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18929] ppid=18920 vsize=1050296 CPUtime=1.36
/proc/18923/task/18929/stat : 18929 (java) R 18920 18920 1750 0 -1 4202560 8489 0 0 0 134 2 0 0 20 0 10 0 119836577 1075503104 94866 18446744073709551615 4194304 4228012 140734912396864 139874032438032 139874121752252 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18930] ppid=18920 vsize=1050296 CPUtime=1.26
/proc/18923/task/18930/stat : 18930 (java) R 18920 18920 1750 0 -1 4202560 11813 0 0 0 124 2 0 0 20 0 10 0 119836577 1075503104 94866 18446744073709551615 4194304 4228012 140734912396864 139874031385360 139874124930472 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18931] ppid=18920 vsize=1050296 CPUtime=0
/proc/18923/task/18931/stat : 18931 (java) S 18920 18920 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119836577 1075503104 94866 18446744073709551615 4194304 4228012 140734912396864 139874030333136 139874137490132 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18932] ppid=18920 vsize=1050296 CPUtime=0
/proc/18923/task/18932/stat : 18932 (java) S 18920 18920 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119836577 1075503104 94866 18446744073709551615 4194304 4228012 140734912396864 139874029280640 139874137491019 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 6.15
Current children cumulated vsize (KiB) 1059468

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

[startup+6.40099 s]
/proc/loadavg: 2.18 1.66 1.27 4/70 18932
/proc/meminfo: memFree=93660/1022884 swapFree=0/0
[pid=18920] ppid=18919 vsize=9172 CPUtime=0
/proc/18920/stat : 18920 (p2cudf-full-1.1) S 18919 18920 1750 0 -1 4202496 457 291 2 1 0 0 0 0 20 0 1 0 119836563 9392128 332 18446744073709551615 4194304 5129932 140737352715152 140737352713296 140225275094110 0 65536 16781316 65538 0 0 0 17 0 0 0 2 0 0
/proc/18920/statm: 2293 332 280 229 0 53 0
[pid=18923] ppid=18920 vsize=1051912 CPUtime=6.25
/proc/18923/stat : 18923 (java) S 18920 18920 1750 0 -1 4202496 99989 0 5 0 587 38 0 0 20 0 10 0 119836567 1077157888 94964 18446744073709551615 4194304 4228012 140734912396864 140734912387888 139874137476725 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/18923/statm: 262978 94964 2374 9 0 250328 0
[pid=18923/tid=18924] ppid=18920 vsize=1051912 CPUtime=2.9
/proc/18923/task/18924/stat : 18924 (java) R 18920 18920 1750 0 -1 4202560 47702 0 5 0 266 24 0 0 20 0 10 0 119836568 1077157888 94964 18446744073709551615 4194304 4228012 140734912396864 139874144011256 139874041498442 0 4 0 16800975 0 0 0 -1 0 0 0 3 0 0
[pid=18923/tid=18925] ppid=18920 vsize=1051912 CPUtime=0.63
/proc/18923/task/18925/stat : 18925 (java) S 18920 18920 1750 0 -1 4202560 30286 0 0 0 55 8 0 0 20 0 10 0 119836572 1077157888 94964 18446744073709551615 4194304 4228012 140734912396864 139874036649088 139874137491019 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18926] ppid=18920 vsize=1051912 CPUtime=0
/proc/18923/task/18926/stat : 18926 (java) S 18920 18920 1750 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 119836573 1077157888 94964 18446744073709551615 4194304 4228012 140734912396864 139874035595280 139874137490132 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18927] ppid=18920 vsize=1051912 CPUtime=0
/proc/18923/task/18927/stat : 18927 (java) S 18920 18920 1750 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 119836573 1077157888 94964 18446744073709551615 4194304 4228012 140734912396864 139874034542496 139874137490132 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18928] ppid=18920 vsize=1051912 CPUtime=0
/proc/18923/task/18928/stat : 18928 (java) S 18920 18920 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119836577 1077157888 94964 18446744073709551615 4194304 4228012 140734912396864 139874033490928 139874137498656 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18929] ppid=18920 vsize=1051912 CPUtime=1.39
/proc/18923/task/18929/stat : 18929 (java) S 18920 18920 1750 0 -1 4202560 8493 0 0 0 137 2 0 0 20 0 10 0 119836577 1077157888 94964 18446744073709551615 4194304 4228012 140734912396864 139874032438288 139874137490132 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18930] ppid=18920 vsize=1051912 CPUtime=1.28
/proc/18923/task/18930/stat : 18930 (java) R 18920 18920 1750 0 -1 4202560 12217 0 0 0 126 2 0 0 20 0 10 0 119836577 1077157888 94964 18446744073709551615 4194304 4228012 140734912396864 139874031373192 139874121753194 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18931] ppid=18920 vsize=1051912 CPUtime=0
/proc/18923/task/18931/stat : 18931 (java) S 18920 18920 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119836577 1077157888 94964 18446744073709551615 4194304 4228012 140734912396864 139874030333136 139874137490132 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18932] ppid=18920 vsize=1051912 CPUtime=0
/proc/18923/task/18932/stat : 18932 (java) S 18920 18920 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119836577 1077157888 94964 18446744073709551615 4194304 4228012 140734912396864 139874029280640 139874137491019 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 6.25
Current children cumulated vsize (KiB) 1061084

[startup+8.00081 s]
/proc/loadavg: 2.24 1.68 1.28 2/70 18932
/proc/meminfo: memFree=91552/1022884 swapFree=0/0
[pid=18920] ppid=18919 vsize=9172 CPUtime=0
/proc/18920/stat : 18920 (p2cudf-full-1.1) S 18919 18920 1750 0 -1 4202496 457 291 2 1 0 0 0 0 20 0 1 0 119836563 9392128 332 18446744073709551615 4194304 5129932 140737352715152 140737352713296 140225275094110 0 65536 16781316 65538 0 0 0 17 0 0 0 2 0 0
/proc/18920/statm: 2293 332 280 229 0 53 0
[pid=18923] ppid=18920 vsize=1050296 CPUtime=7.82
/proc/18923/stat : 18923 (java) S 18920 18920 1750 0 -1 4202496 100923 0 5 0 743 39 0 0 20 0 10 0 119836567 1075503104 94685 18446744073709551615 4194304 4228012 140734912396864 140734912387888 139874137476725 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/18923/statm: 262574 94685 2377 9 0 249924 0
[pid=18923/tid=18924] ppid=18920 vsize=1050296 CPUtime=3.51
/proc/18923/task/18924/stat : 18924 (java) R 18920 18920 1750 0 -1 4202560 47747 0 5 0 327 24 0 0 20 0 10 0 119836568 1075503104 94685 18446744073709551615 4194304 4228012 140734912396864 139874144010960 139874120971672 0 4 0 16800975 0 0 0 -1 0 0 0 3 0 0
[pid=18923/tid=18925] ppid=18920 vsize=1050296 CPUtime=0.63
/proc/18923/task/18925/stat : 18925 (java) S 18920 18920 1750 0 -1 4202560 30286 0 0 0 55 8 0 0 20 0 10 0 119836572 1075503104 94685 18446744073709551615 4194304 4228012 140734912396864 139874036649088 139874137491019 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18926] ppid=18920 vsize=1050296 CPUtime=0
/proc/18923/task/18926/stat : 18926 (java) S 18920 18920 1750 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 119836573 1075503104 94685 18446744073709551615 4194304 4228012 140734912396864 139874035595280 139874137490132 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18927] ppid=18920 vsize=1050296 CPUtime=0
/proc/18923/task/18927/stat : 18927 (java) S 18920 18920 1750 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 119836573 1075503104 94685 18446744073709551615 4194304 4228012 140734912396864 139874034542496 139874137490132 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18928] ppid=18920 vsize=1050296 CPUtime=0
/proc/18923/task/18928/stat : 18928 (java) S 18920 18920 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119836577 1075503104 94685 18446744073709551615 4194304 4228012 140734912396864 139874033490928 139874137498656 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18929] ppid=18920 vsize=1050296 CPUtime=1.86
/proc/18923/task/18929/stat : 18929 (java) R 18920 18920 1750 0 -1 4202560 8528 0 0 0 184 2 0 0 20 0 10 0 119836577 1075503104 94685 18446744073709551615 4194304 4228012 140734912396864 139874032438032 139874120438504 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18930] ppid=18920 vsize=1050296 CPUtime=1.77
/proc/18923/task/18930/stat : 18930 (java) R 18920 18920 1750 0 -1 4202560 13071 0 0 0 175 2 0 0 20 0 10 0 119836577 1075503104 94685 18446744073709551615 4194304 4228012 140734912396864 139874031385360 139874120266723 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18931] ppid=18920 vsize=1050296 CPUtime=0
/proc/18923/task/18931/stat : 18931 (java) S 18920 18920 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119836577 1075503104 94685 18446744073709551615 4194304 4228012 140734912396864 139874030333136 139874137490132 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18932] ppid=18920 vsize=1050296 CPUtime=0
/proc/18923/task/18932/stat : 18932 (java) S 18920 18920 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119836577 1075503104 94685 18446744073709551615 4194304 4228012 140734912396864 139874029280640 139874137491019 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 7.82
Current children cumulated vsize (KiB) 1059468

[startup+8.80078 s]
/proc/loadavg: 2.24 1.68 1.28 3/71 18934
/proc/meminfo: memFree=91420/1022884 swapFree=0/0
[pid=18920] ppid=18919 vsize=9172 CPUtime=0
/proc/18920/stat : 18920 (p2cudf-full-1.1) S 18919 18920 1750 0 -1 4202496 457 291 2 1 0 0 0 0 20 0 1 0 119836563 9392128 332 18446744073709551615 4194304 5129932 140737352715152 140737352713296 140225275094110 0 65536 16781316 65538 0 0 0 17 0 0 0 2 0 0
/proc/18920/statm: 2293 332 280 229 0 53 0
[pid=18923] ppid=18920 vsize=1052352 CPUtime=8.62
/proc/18923/stat : 18923 (java) S 18920 18920 1750 0 -1 4202496 100992 0 5 0 822 40 0 0 20 0 11 0 119836567 1077608448 94752 18446744073709551615 4194304 4228012 140734912396864 140734912387888 139874137476725 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/18923/statm: 263088 94752 2379 9 0 250438 0
[pid=18923/tid=18924] ppid=18920 vsize=1052352 CPUtime=3.8
/proc/18923/task/18924/stat : 18924 (java) S 18920 18920 1750 0 -1 4202560 47796 0 5 0 355 25 0 0 20 0 11 0 119836568 1077608448 94752 18446744073709551615 4194304 4228012 140734912396864 139874144011184 139874137490132 0 4 0 16800975 0 0 0 -1 0 0 0 3 0 0
[pid=18923/tid=18925] ppid=18920 vsize=1052352 CPUtime=0.63
/proc/18923/task/18925/stat : 18925 (java) S 18920 18920 1750 0 -1 4202560 30287 0 0 0 55 8 0 0 20 0 11 0 119836572 1077608448 94752 18446744073709551615 4194304 4228012 140734912396864 139874036649088 139874137491019 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18926] ppid=18920 vsize=1052352 CPUtime=0
/proc/18923/task/18926/stat : 18926 (java) S 18920 18920 1750 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 119836573 1077608448 94752 18446744073709551615 4194304 4228012 140734912396864 139874035595280 139874137490132 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18927] ppid=18920 vsize=1052352 CPUtime=0
/proc/18923/task/18927/stat : 18927 (java) S 18920 18920 1750 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 119836573 1077608448 94752 18446744073709551615 4194304 4228012 140734912396864 139874034542496 139874137490132 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18928] ppid=18920 vsize=1052352 CPUtime=0
/proc/18923/task/18928/stat : 18928 (java) S 18920 18920 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 119836577 1077608448 94752 18446744073709551615 4194304 4228012 140734912396864 139874033490928 139874137498656 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18929] ppid=18920 vsize=1052352 CPUtime=2.13
/proc/18923/task/18929/stat : 18929 (java) R 18920 18920 1750 0 -1 4202560 8528 0 0 0 211 2 0 0 20 0 11 0 119836577 1077608448 94752 18446744073709551615 4194304 4228012 140734912396864 139874032438032 139874123204000 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18930] ppid=18920 vsize=1052352 CPUtime=2.02
/proc/18923/task/18930/stat : 18930 (java) R 18920 18920 1750 0 -1 4202560 13078 0 0 0 200 2 0 0 20 0 11 0 119836577 1077608448 94752 18446744073709551615 4194304 4228012 140734912396864 139874031385360 139874124931823 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18931] ppid=18920 vsize=1052352 CPUtime=0
/proc/18923/task/18931/stat : 18931 (java) S 18920 18920 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 119836577 1077608448 94752 18446744073709551615 4194304 4228012 140734912396864 139874030333136 139874137490132 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18932] ppid=18920 vsize=1052352 CPUtime=0
/proc/18923/task/18932/stat : 18932 (java) S 18920 18920 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 119836577 1077608448 94752 18446744073709551615 4194304 4228012 140734912396864 139874029280640 139874137491019 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18934] ppid=18920 vsize=1052352 CPUtime=0
/proc/18923/task/18934/stat : 18934 (java) S 18920 18920 1750 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 11 0 119837441 1077608448 94752 18446744073709551615 4194304 4228012 140734912396864 139874027030704 139874137491019 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 8.62
Current children cumulated vsize (KiB) 1061524

[startup+9.20091 s]
/proc/loadavg: 2.24 1.68 1.28 3/71 18934
/proc/meminfo: memFree=91420/1022884 swapFree=0/0
[pid=18920] ppid=18919 vsize=9172 CPUtime=0
/proc/18920/stat : 18920 (p2cudf-full-1.1) S 18919 18920 1750 0 -1 4202496 457 291 2 1 0 0 0 0 20 0 1 0 119836563 9392128 332 18446744073709551615 4194304 5129932 140737352715152 140737352713296 140225275094110 0 65536 16781316 65538 0 0 0 17 0 0 0 2 0 0
/proc/18920/statm: 2293 332 280 229 0 53 0
[pid=18923] ppid=18920 vsize=1052352 CPUtime=8.64
/proc/18923/stat : 18923 (java) S 18920 18920 1750 0 -1 4202496 100992 0 5 0 824 40 0 0 20 0 11 0 119836567 1077608448 94752 18446744073709551615 4194304 4228012 140734912396864 140734912387888 139874137476725 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/18923/statm: 263088 94752 2379 9 0 250438 0
[pid=18923/tid=18924] ppid=18920 vsize=1052352 CPUtime=3.8
/proc/18923/task/18924/stat : 18924 (java) S 18920 18920 1750 0 -1 4202560 47796 0 5 0 355 25 0 0 20 0 11 0 119836568 1077608448 94752 18446744073709551615 4194304 4228012 140734912396864 139874144011184 139874137490132 0 4 0 16800975 0 0 0 -1 0 0 0 3 0 0
[pid=18923/tid=18925] ppid=18920 vsize=1052352 CPUtime=0.63
/proc/18923/task/18925/stat : 18925 (java) S 18920 18920 1750 0 -1 4202560 30287 0 0 0 55 8 0 0 20 0 11 0 119836572 1077608448 94752 18446744073709551615 4194304 4228012 140734912396864 139874036649088 139874137491019 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18926] ppid=18920 vsize=1052352 CPUtime=0
/proc/18923/task/18926/stat : 18926 (java) S 18920 18920 1750 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 119836573 1077608448 94752 18446744073709551615 4194304 4228012 140734912396864 139874035595280 139874137490132 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18927] ppid=18920 vsize=1052352 CPUtime=0
/proc/18923/task/18927/stat : 18927 (java) S 18920 18920 1750 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 119836573 1077608448 94752 18446744073709551615 4194304 4228012 140734912396864 139874034542496 139874137490132 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18928] ppid=18920 vsize=1052352 CPUtime=0
/proc/18923/task/18928/stat : 18928 (java) S 18920 18920 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 119836577 1077608448 94752 18446744073709551615 4194304 4228012 140734912396864 139874033490928 139874137498656 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18929] ppid=18920 vsize=1052352 CPUtime=2.14
/proc/18923/task/18929/stat : 18929 (java) S 18920 18920 1750 0 -1 4202560 8528 0 0 0 212 2 0 0 20 0 11 0 119836577 1077608448 94752 18446744073709551615 4194304 4228012 140734912396864 139874032438288 139874137490132 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18930] ppid=18920 vsize=1052352 CPUtime=2.03
/proc/18923/task/18930/stat : 18930 (java) S 18920 18920 1750 0 -1 4202560 13078 0 0 0 201 2 0 0 20 0 11 0 119836577 1077608448 94752 18446744073709551615 4194304 4228012 140734912396864 139874031385616 139874137490132 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18931] ppid=18920 vsize=1052352 CPUtime=0
/proc/18923/task/18931/stat : 18931 (java) S 18920 18920 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 119836577 1077608448 94752 18446744073709551615 4194304 4228012 140734912396864 139874030333136 139874137490132 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18932] ppid=18920 vsize=1052352 CPUtime=0
/proc/18923/task/18932/stat : 18932 (java) S 18920 18920 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 119836577 1077608448 94752 18446744073709551615 4194304 4228012 140734912396864 139874029280640 139874137491019 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=18923/tid=18934] ppid=18920 vsize=1052352 CPUtime=0
/proc/18923/task/18934/stat : 18934 (java) S 18920 18920 1750 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 11 0 119837441 1077608448 94752 18446744073709551615 4194304 4228012 140734912396864 139874027030704 139874137491019 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 8.64
Current children cumulated vsize (KiB) 1061524

[startup+9.60713 s]
/proc/loadavg: 2.24 1.68 1.28 3/71 18934
/proc/meminfo: memFree=91420/1022884 swapFree=0/0
[pid=18920] ppid=18919 vsize=9172 CPUtime=0
/proc/18920/stat : 18920 (p2cudf-full-1.1) S 18919 18920 1750 0 -1 4202496 457 291 2 1 0 0 0 0 20 0 1 0 119836563 9392128 332 18446744073709551615 4194304 5129932 140737352715152 140737352713296 140225275094110 0 65536 16781316 65538 0 0 0 17 0 0 0 2 0 0
/proc/18920/statm: 2293 332 280 229 0 53 0
[pid=18923] ppid=18920 vsize=0 CPUtime=8.95
/proc/18923/stat : 18923 (java) Z 18920 18920 1750 0 -1 4203532 101018 0 5 0 849 46 0 0 20 0 2 0 119836567 0 0 18446744073709551615 0 0 0 0 0 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/18923/statm: 0 0 0 0 0 0 0
[pid=18923/tid=18929] ppid=18920 vsize=0 CPUtime=2.2
/proc/18923/task/18929/stat : 18929 (java) R 18920 18920 1750 0 -1 4203588 8533 0 0 0 218 2 0 0 20 0 2 0 119836577 0 0 18446744073709551615 0 0 0 0 0 0 4 0 16800975 18446744073709551615 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 8.95
Current children cumulated vsize (KiB) 9172

Child status: 0
Real time (s): 9.63914
CPU time (s): 8.99656
CPU user time (s): 8.50853
CPU system time (s): 0.48803
CPU usage (%): 93.3337
Max. virtual memory (cumulated for all children) (KiB): 1062792

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 8.50853
system time used= 0.48803
maximum resident set size= 379944
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 101779
page faults= 8
swaps= 0
block input operations= 27736
block output operations= 288
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 876
involuntary context switches= 2814

runsolver used 0.008 second user time and 0.100006 second system time

The end