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/rand583.cudf.log.runsolver /home/competition/p2cudf-full-1.15/p2cudf-full-1.15 /home/competition/data/upgrade/easy/rand583.cudf /tmp/misc2012/2012-09-02-22:42/full/p2cudf-full-1.15/trendy-size/upgrade/easy/rand583.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.79 1.73 1.39 2/59 19300
/proc/meminfo: memFree=488400/1022884 swapFree=0/0
[pid=19300] ppid=19299 vsize=3152 CPUtime=0
/proc/19300/stat : 19300 (runsolver) R 19299 1750 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 1 0 119865149 3227648 32 18446744073709551615 134512640 134586868 4290656256 4290654304 4151583792 0 0 16781316 24578 0 0 0 17 0 0 0 0 0 0
/proc/19300/statm: 788 32 0 19 0 73 0
Current StackSize limit: 8192 KiB


[startup+0.138961 s]
/proc/loadavg: 1.79 1.73 1.39 2/59 19300
/proc/meminfo: memFree=488400/1022884 swapFree=0/0
[pid=19300] ppid=19299 vsize=9168 CPUtime=0
/proc/19300/stat : 19300 (p2cudf-full-1.1) S 19299 19300 1750 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 119865149 9388032 330 18446744073709551615 4194304 5129932 140734129502336 140734129500480 140658447897694 0 65536 16781316 65538 0 0 0 17 0 0 0 3 0 0
/proc/19300/statm: 2292 330 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+0.200267 s]
/proc/loadavg: 1.79 1.73 1.39 2/59 19300
/proc/meminfo: memFree=488400/1022884 swapFree=0/0
[pid=19300] ppid=19299 vsize=9168 CPUtime=0
/proc/19300/stat : 19300 (p2cudf-full-1.1) S 19299 19300 1750 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 119865149 9388032 330 18446744073709551615 4194304 5129932 140734129502336 140734129500480 140658447897694 0 65536 16781316 65538 0 0 0 17 0 0 0 3 0 0
/proc/19300/statm: 2292 330 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+0.300238 s]
/proc/loadavg: 1.79 1.73 1.39 2/59 19300
/proc/meminfo: memFree=488400/1022884 swapFree=0/0
[pid=19300] ppid=19299 vsize=9168 CPUtime=0
/proc/19300/stat : 19300 (p2cudf-full-1.1) S 19299 19300 1750 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 119865149 9388032 330 18446744073709551615 4194304 5129932 140734129502336 140734129500480 140658447897694 0 65536 16781316 65538 0 0 0 17 0 0 0 3 0 0
/proc/19300/statm: 2292 330 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+0.700196 s]
/proc/loadavg: 1.79 1.73 1.39 2/59 19300
/proc/meminfo: memFree=488400/1022884 swapFree=0/0
[pid=19300] ppid=19299 vsize=9168 CPUtime=0
/proc/19300/stat : 19300 (p2cudf-full-1.1) S 19299 19300 1750 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 119865149 9388032 330 18446744073709551615 4194304 5129932 140734129502336 140734129500480 140658447897694 0 65536 16781316 65538 0 0 0 17 0 0 0 3 0 0
/proc/19300/statm: 2292 330 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+1.5006 s]
/proc/loadavg: 1.79 1.73 1.39 4/70 19312
/proc/meminfo: memFree=397172/1022884 swapFree=0/0
[pid=19300] ppid=19299 vsize=9168 CPUtime=0
/proc/19300/stat : 19300 (p2cudf-full-1.1) S 19299 19300 1750 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 119865149 9388032 330 18446744073709551615 4194304 5129932 140734129502336 140734129500480 140658447897694 0 65536 16781316 65538 0 0 0 17 0 0 0 3 0 0
/proc/19300/statm: 2292 330 280 229 0 52 0
[pid=19303] ppid=19300 vsize=1051860 CPUtime=1.29
/proc/19303/stat : 19303 (java) S 19300 19300 1750 0 -1 4202496 39909 0 20 0 112 17 0 0 20 0 10 0 119865153 1077104640 35878 18446744073709551615 4194304 4228012 140734113218752 140734113209776 139636019830389 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 8 0 0
/proc/19303/statm: 262965 35878 2346 9 0 250315 0
[pid=19303/tid=19304] ppid=19300 vsize=1051860 CPUtime=0.56
/proc/19303/task/19304/stat : 19304 (java) R 19300 19300 1750 0 -1 4202560 19308 0 8 0 48 8 0 0 20 0 10 0 119865163 1077104640 35878 18446744073709551615 4194304 4228012 140734113218752 139636026356384 139635924166775 0 4 0 16800975 0 0 0 -1 0 0 0 7 0 0
[pid=19303/tid=19305] ppid=19300 vsize=1051860 CPUtime=0
/proc/19303/task/19305/stat : 19305 (java) S 19300 19300 1750 0 -1 4202560 3 0 0 0 0 0 0 0 20 0 10 0 119865170 1077104640 35878 18446744073709551615 4194304 4228012 140734113218752 139635919002752 139636019844683 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19306] ppid=19300 vsize=1051860 CPUtime=0
/proc/19303/task/19306/stat : 19306 (java) S 19300 19300 1750 0 -1 4202560 15 0 0 0 0 0 0 0 20 0 10 0 119865171 1077104640 35878 18446744073709551615 4194304 4228012 140734113218752 139635917948944 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19307] ppid=19300 vsize=1051860 CPUtime=0
/proc/19303/task/19307/stat : 19307 (java) S 19300 19300 1750 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 10 0 119865171 1077104640 35878 18446744073709551615 4194304 4228012 140734113218752 139635916896160 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19308] ppid=19300 vsize=1051860 CPUtime=0
/proc/19303/task/19308/stat : 19308 (java) S 19300 19300 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 119865173 1077104640 35878 18446744073709551615 4194304 4228012 140734113218752 139635915844592 139636019852320 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19309] ppid=19300 vsize=1051860 CPUtime=0.35
/proc/19303/task/19309/stat : 19309 (java) R 19300 19300 1750 0 -1 4202560 9939 0 0 0 32 3 0 0 20 0 10 0 119865173 1077104640 35878 18446744073709551615 4194304 4228012 140734113218752 139635914779480 139636002055872 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19310] ppid=19300 vsize=1051860 CPUtime=0.35
/proc/19303/task/19310/stat : 19310 (java) R 19300 19300 1750 0 -1 4202560 9383 0 0 0 30 5 0 0 20 0 10 0 119865173 1077104640 35878 18446744073709551615 4194304 4228012 140734113218752 139635913726856 139636004109928 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19311] ppid=19300 vsize=1051860 CPUtime=0
/proc/19303/task/19311/stat : 19311 (java) S 19300 19300 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119865173 1077104640 35878 18446744073709551615 4194304 4228012 140734113218752 139635912686800 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19312] ppid=19300 vsize=1051860 CPUtime=0
/proc/19303/task/19312/stat : 19312 (java) S 19300 19300 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119865173 1077104640 35878 18446744073709551615 4194304 4228012 140734113218752 139635911634304 139636019844683 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 1.29
Current children cumulated vsize (KiB) 1061028

[startup+3.1006 s]
/proc/loadavg: 1.88 1.75 1.40 2/70 19312
/proc/meminfo: memFree=205964/1022884 swapFree=0/0
[pid=19300] ppid=19299 vsize=9168 CPUtime=0
/proc/19300/stat : 19300 (p2cudf-full-1.1) S 19299 19300 1750 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 119865149 9388032 330 18446744073709551615 4194304 5129932 140734129502336 140734129500480 140658447897694 0 65536 16781316 65538 0 0 0 17 0 0 0 3 0 0
/proc/19300/statm: 2292 330 280 229 0 52 0
[pid=19303] ppid=19300 vsize=1051388 CPUtime=2.86
/proc/19303/stat : 19303 (java) S 19300 19300 1750 0 -1 4202496 97753 0 20 0 251 35 0 0 20 0 10 0 119865153 1076621312 92350 18446744073709551615 4194304 4228012 140734113218752 140734113209776 139636019830389 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 8 0 0
/proc/19303/statm: 262847 92350 2367 9 0 250197 0
[pid=19303/tid=19304] ppid=19300 vsize=1051388 CPUtime=1.42
/proc/19303/task/19304/stat : 19304 (java) R 19300 19300 1750 0 -1 4202560 47415 0 8 0 124 18 0 0 20 0 10 0 119865163 1076621312 92350 18446744073709551615 4194304 4228012 140734113218752 139636026356416 139635924168097 0 4 0 16800975 0 0 0 -1 0 0 0 8 0 0
[pid=19303/tid=19305] ppid=19300 vsize=1051388 CPUtime=0.46
/proc/19303/task/19305/stat : 19305 (java) S 19300 19300 1750 0 -1 4202560 29273 0 0 0 38 8 0 0 20 0 10 0 119865170 1076621312 92350 18446744073709551615 4194304 4228012 140734113218752 139635919002752 139636019844683 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19306] ppid=19300 vsize=1051388 CPUtime=0
/proc/19303/task/19306/stat : 19306 (java) S 19300 19300 1750 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 119865171 1076621312 92350 18446744073709551615 4194304 4228012 140734113218752 139635917948944 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19307] ppid=19300 vsize=1051388 CPUtime=0
/proc/19303/task/19307/stat : 19307 (java) S 19300 19300 1750 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 119865171 1076621312 92350 18446744073709551615 4194304 4228012 140734113218752 139635916896160 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19308] ppid=19300 vsize=1051388 CPUtime=0
/proc/19303/task/19308/stat : 19308 (java) S 19300 19300 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 119865173 1076621312 92350 18446744073709551615 4194304 4228012 140734113218752 139635915844592 139636019852320 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19309] ppid=19300 vsize=1051388 CPUtime=0.48
/proc/19303/task/19309/stat : 19309 (java) S 19300 19300 1750 0 -1 4202560 10046 0 0 0 45 3 0 0 20 0 10 0 119865173 1076621312 92350 18446744073709551615 4194304 4228012 140734113218752 139635914791952 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19310] ppid=19300 vsize=1051388 CPUtime=0.47
/proc/19303/task/19310/stat : 19310 (java) S 19300 19300 1750 0 -1 4202560 9739 0 0 0 42 5 0 0 20 0 10 0 119865173 1076621312 92350 18446744073709551615 4194304 4228012 140734113218752 139635913739280 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19311] ppid=19300 vsize=1051388 CPUtime=0
/proc/19303/task/19311/stat : 19311 (java) S 19300 19300 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119865173 1076621312 92350 18446744073709551615 4194304 4228012 140734113218752 139635912686800 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19312] ppid=19300 vsize=1051388 CPUtime=0
/proc/19303/task/19312/stat : 19312 (java) S 19300 19300 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119865173 1076621312 92350 18446744073709551615 4194304 4228012 140734113218752 139635911634304 139636019844683 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 2.86
Current children cumulated vsize (KiB) 1060556

[startup+6.30075 s]
/proc/loadavg: 1.88 1.75 1.40 4/70 19312
/proc/meminfo: memFree=10748/1022884 swapFree=0/0
[pid=19300] ppid=19299 vsize=9168 CPUtime=0
/proc/19300/stat : 19300 (p2cudf-full-1.1) S 19299 19300 1750 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 119865149 9388032 330 18446744073709551615 4194304 5129932 140734129502336 140734129500480 140658447897694 0 65536 16781316 65538 0 0 0 17 0 0 0 3 0 0
/proc/19300/statm: 2292 330 280 229 0 52 0
[pid=19303] ppid=19300 vsize=1048540 CPUtime=6
/proc/19303/stat : 19303 (java) S 19300 19300 1750 0 -1 4202496 124680 0 20 0 556 44 0 0 20 0 10 0 119865153 1073704960 116924 18446744073709551615 4194304 4228012 140734113218752 140734113209776 139636019830389 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 8 0 0
/proc/19303/statm: 262135 116924 2375 9 0 249485 0
[pid=19303/tid=19304] ppid=19300 vsize=1048540 CPUtime=2.77
/proc/19303/task/19304/stat : 19304 (java) R 19300 19300 1750 0 -1 4202560 47716 0 8 0 257 20 0 0 20 0 10 0 119865163 1073704960 116924 18446744073709551615 4194304 4228012 140734113218752 139636026363272 139636005765280 0 4 0 16800975 0 0 0 -1 0 0 0 11 0 0
[pid=19303/tid=19305] ppid=19300 vsize=1048540 CPUtime=0.98
/proc/19303/task/19305/stat : 19305 (java) S 19300 19300 1750 0 -1 4202560 53201 0 0 0 84 14 0 0 20 0 10 0 119865170 1073704960 116924 18446744073709551615 4194304 4228012 140734113218752 139635919002752 139636019844683 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19306] ppid=19300 vsize=1048540 CPUtime=0
/proc/19303/task/19306/stat : 19306 (java) S 19300 19300 1750 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 119865171 1073704960 116924 18446744073709551615 4194304 4228012 140734113218752 139635917948944 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19307] ppid=19300 vsize=1048540 CPUtime=0
/proc/19303/task/19307/stat : 19307 (java) S 19300 19300 1750 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 119865171 1073704960 116924 18446744073709551615 4194304 4228012 140734113218752 139635916896160 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19308] ppid=19300 vsize=1048540 CPUtime=0
/proc/19303/task/19308/stat : 19308 (java) S 19300 19300 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 119865173 1073704960 116924 18446744073709551615 4194304 4228012 140734113218752 139635915844592 139636019852320 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19309] ppid=19300 vsize=1048540 CPUtime=1.08
/proc/19303/task/19309/stat : 19309 (java) R 19300 19300 1750 0 -1 4202560 10139 0 0 0 104 4 0 0 20 0 10 0 119865173 1073704960 116924 18446744073709551615 4194304 4228012 140734113218752 139635914791696 139636003661116 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19310] ppid=19300 vsize=1048540 CPUtime=1.14
/proc/19303/task/19310/stat : 19310 (java) R 19300 19300 1750 0 -1 4202560 12343 0 0 0 108 6 0 0 20 0 10 0 119865173 1073704960 116924 18446744073709551615 4194304 4228012 140734113218752 139635913727096 139636006529912 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19311] ppid=19300 vsize=1048540 CPUtime=0
/proc/19303/task/19311/stat : 19311 (java) S 19300 19300 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119865173 1073704960 116924 18446744073709551615 4194304 4228012 140734113218752 139635912686800 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19312] ppid=19300 vsize=1048540 CPUtime=0
/proc/19303/task/19312/stat : 19312 (java) S 19300 19300 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 119865173 1073704960 116924 18446744073709551615 4194304 4228012 140734113218752 139635911634304 139636019844683 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 6
Current children cumulated vsize (KiB) 1057708

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

[startup+6.40097 s]
/proc/loadavg: 1.88 1.75 1.40 4/70 19312
/proc/meminfo: memFree=10748/1022884 swapFree=0/0
[pid=19300] ppid=19299 vsize=9168 CPUtime=0
/proc/19300/stat : 19300 (p2cudf-full-1.1) S 19299 19300 1750 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 119865149 9388032 330 18446744073709551615 4194304 5129932 140734129502336 140734129500480 140658447897694 0 65536 16781316 65538 0 0 0 17 0 0 0 3 0 0
/proc/19300/statm: 2292 330 280 229 0 52 0
[pid=19303] ppid=19300 vsize=1048540 CPUtime=6.1
/proc/19303/stat : 19303 (java) S 19300 19300 1750 0 -1 4202496 124680 0 20 0 566 44 0 0 20 0 10 0 119865153 1073704960 116536 18446744073709551615 4194304 4228012 140734113218752 140734113209776 139636019830389 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 8 0 0
/proc/19303/statm: 262135 116536 2375 9 0 249485 0
[pid=19303/tid=19304] ppid=19300 vsize=1048540 CPUtime=2.8
/proc/19303/task/19304/stat : 19304 (java) R 19300 19300 1750 0 -1 4202560 47716 0 8 0 260 20 0 0 20 0 10 0 119865163 1073704960 116536 18446744073709551615 4194304 4228012 140734113218752 139636026363272 139635924261107 0 4 0 16800975 0 0 0 -1 0 0 0 11 0 0
[pid=19303/tid=19305] ppid=19300 vsize=1048540 CPUtime=0.98
/proc/19303/task/19305/stat : 19305 (java) S 19300 19300 1750 0 -1 4202560 53201 0 0 0 84 14 0 0 20 0 10 0 119865170 1073704960 116536 18446744073709551615 4194304 4228012 140734113218752 139635919002752 139636019844683 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19306] ppid=19300 vsize=1048540 CPUtime=0
/proc/19303/task/19306/stat : 19306 (java) S 19300 19300 1750 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 119865171 1073704960 116536 18446744073709551615 4194304 4228012 140734113218752 139635917948944 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19307] ppid=19300 vsize=1048540 CPUtime=0
/proc/19303/task/19307/stat : 19307 (java) S 19300 19300 1750 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 119865171 1073704960 116536 18446744073709551615 4194304 4228012 140734113218752 139635916896160 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19308] ppid=19300 vsize=1048540 CPUtime=0
/proc/19303/task/19308/stat : 19308 (java) S 19300 19300 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 119865173 1073704960 116536 18446744073709551615 4194304 4228012 140734113218752 139635915844592 139636019852320 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19309] ppid=19300 vsize=1048540 CPUtime=1.11
/proc/19303/task/19309/stat : 19309 (java) R 19300 19300 1750 0 -1 4202560 10139 0 0 0 107 4 0 0 20 0 10 0 119865173 1073704960 116536 18446744073709551615 4194304 4228012 140734113218752 139635914791696 139636003628510 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19310] ppid=19300 vsize=1048540 CPUtime=1.18
/proc/19303/task/19310/stat : 19310 (java) R 19300 19300 1750 0 -1 4202560 12343 0 0 0 112 6 0 0 20 0 10 0 119865173 1073704960 116536 18446744073709551615 4194304 4228012 140734113218752 139635913727000 139636001202654 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19311] ppid=19300 vsize=1048540 CPUtime=0
/proc/19303/task/19311/stat : 19311 (java) S 19300 19300 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119865173 1073704960 116536 18446744073709551615 4194304 4228012 140734113218752 139635912686800 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19312] ppid=19300 vsize=1048540 CPUtime=0
/proc/19303/task/19312/stat : 19312 (java) S 19300 19300 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 119865173 1073704960 116536 18446744073709551615 4194304 4228012 140734113218752 139635911634304 139636019844683 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 6.1
Current children cumulated vsize (KiB) 1057708

[startup+8.00074 s]
/proc/loadavg: 1.97 1.77 1.41 4/70 19312
/proc/meminfo: memFree=10500/1022884 swapFree=0/0
[pid=19300] ppid=19299 vsize=9168 CPUtime=0
/proc/19300/stat : 19300 (p2cudf-full-1.1) S 19299 19300 1750 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 119865149 9388032 330 18446744073709551615 4194304 5129932 140734129502336 140734129500480 140658447897694 0 65536 16781316 65538 0 0 0 17 0 0 0 3 0 0
/proc/19300/statm: 2292 330 280 229 0 52 0
[pid=19303] ppid=19300 vsize=1048540 CPUtime=7.67
/proc/19303/stat : 19303 (java) S 19300 19300 1750 0 -1 4202496 124830 0 20 0 723 44 0 0 20 0 10 0 119865153 1073704960 116642 18446744073709551615 4194304 4228012 140734113218752 140734113209776 139636019830389 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 8 0 0
/proc/19303/statm: 262135 116642 2376 9 0 249485 0
[pid=19303/tid=19304] ppid=19300 vsize=1048540 CPUtime=3.42
/proc/19303/task/19304/stat : 19304 (java) R 19300 19300 1750 0 -1 4202560 47732 0 8 0 322 20 0 0 20 0 10 0 119865163 1073704960 116642 18446744073709551615 4194304 4228012 140734113218752 139636026365168 139635923876887 0 4 0 16800975 0 0 0 -1 0 0 0 11 0 0
[pid=19303/tid=19305] ppid=19300 vsize=1048540 CPUtime=0.98
/proc/19303/task/19305/stat : 19305 (java) S 19300 19300 1750 0 -1 4202560 53201 0 0 0 84 14 0 0 20 0 10 0 119865170 1073704960 116642 18446744073709551615 4194304 4228012 140734113218752 139635919002752 139636019844683 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19306] ppid=19300 vsize=1048540 CPUtime=0
/proc/19303/task/19306/stat : 19306 (java) S 19300 19300 1750 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 119865171 1073704960 116642 18446744073709551615 4194304 4228012 140734113218752 139635917948944 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19307] ppid=19300 vsize=1048540 CPUtime=0
/proc/19303/task/19307/stat : 19307 (java) S 19300 19300 1750 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 119865171 1073704960 116642 18446744073709551615 4194304 4228012 140734113218752 139635916896160 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19308] ppid=19300 vsize=1048540 CPUtime=0
/proc/19303/task/19308/stat : 19308 (java) S 19300 19300 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 119865173 1073704960 116642 18446744073709551615 4194304 4228012 140734113218752 139635915844592 139636019852320 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19309] ppid=19300 vsize=1048540 CPUtime=1.56
/proc/19303/task/19309/stat : 19309 (java) R 19300 19300 1750 0 -1 4202560 10198 0 0 0 152 4 0 0 20 0 10 0 119865173 1073704960 116642 18446744073709551615 4194304 4228012 140734113218752 139635914791696 139636005979636 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19310] ppid=19300 vsize=1048540 CPUtime=1.68
/proc/19303/task/19310/stat : 19310 (java) R 19300 19300 1750 0 -1 4202560 12418 0 0 0 162 6 0 0 20 0 10 0 119865173 1073704960 116642 18446744073709551615 4194304 4228012 140734113218752 139635913739024 139636002684189 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19311] ppid=19300 vsize=1048540 CPUtime=0
/proc/19303/task/19311/stat : 19311 (java) S 19300 19300 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119865173 1073704960 116642 18446744073709551615 4194304 4228012 140734113218752 139635912686800 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19312] ppid=19300 vsize=1048540 CPUtime=0
/proc/19303/task/19312/stat : 19312 (java) S 19300 19300 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 119865173 1073704960 116642 18446744073709551615 4194304 4228012 140734113218752 139635911634304 139636019844683 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 7.67
Current children cumulated vsize (KiB) 1057708

[startup+9.60081 s]
/proc/loadavg: 1.97 1.77 1.41 3/71 19313
/proc/meminfo: memFree=10376/1022884 swapFree=0/0
[pid=19300] ppid=19299 vsize=9168 CPUtime=0
/proc/19300/stat : 19300 (p2cudf-full-1.1) S 19299 19300 1750 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 119865149 9388032 330 18446744073709551615 4194304 5129932 140734129502336 140734129500480 140658447897694 0 65536 16781316 65538 0 0 0 17 0 0 0 3 0 0
/proc/19300/statm: 2292 330 280 229 0 52 0
[pid=19303] ppid=19300 vsize=1049568 CPUtime=9.24
/proc/19303/stat : 19303 (java) S 19300 19300 1750 0 -1 4202496 124954 0 20 0 880 44 0 0 20 0 11 0 119865153 1074757632 116766 18446744073709551615 4194304 4228012 140734113218752 140734113209776 139636019830389 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 8 0 0
/proc/19303/statm: 262392 116766 2380 9 0 249742 0
[pid=19303/tid=19304] ppid=19300 vsize=1049568 CPUtime=4.21
/proc/19303/task/19304/stat : 19304 (java) R 19300 19300 1750 0 -1 4202560 47796 0 8 0 401 20 0 0 20 0 11 0 119865163 1074757632 116766 18446744073709551615 4194304 4228012 140734113218752 139636026363896 139635925264024 0 4 0 16800975 0 0 0 -1 0 0 0 11 0 0
[pid=19303/tid=19305] ppid=19300 vsize=1049568 CPUtime=0.99
/proc/19303/task/19305/stat : 19305 (java) S 19300 19300 1750 0 -1 4202560 53202 0 0 0 85 14 0 0 20 0 11 0 119865170 1074757632 116766 18446744073709551615 4194304 4228012 140734113218752 139635919002752 139636019844683 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19306] ppid=19300 vsize=1049568 CPUtime=0
/proc/19303/task/19306/stat : 19306 (java) S 19300 19300 1750 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 119865171 1074757632 116766 18446744073709551615 4194304 4228012 140734113218752 139635917948944 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19307] ppid=19300 vsize=1049568 CPUtime=0
/proc/19303/task/19307/stat : 19307 (java) S 19300 19300 1750 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 119865171 1074757632 116766 18446744073709551615 4194304 4228012 140734113218752 139635916896160 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19308] ppid=19300 vsize=1049568 CPUtime=0
/proc/19303/task/19308/stat : 19308 (java) S 19300 19300 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 119865173 1074757632 116766 18446744073709551615 4194304 4228012 140734113218752 139635915844592 139636019852320 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19309] ppid=19300 vsize=1049568 CPUtime=1.98
/proc/19303/task/19309/stat : 19309 (java) S 19300 19300 1750 0 -1 4202560 10228 0 0 0 194 4 0 0 20 0 11 0 119865173 1074757632 116766 18446744073709551615 4194304 4228012 140734113218752 139635914791952 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19310] ppid=19300 vsize=1049568 CPUtime=2.03
/proc/19303/task/19310/stat : 19310 (java) S 19300 19300 1750 0 -1 4202560 12441 0 0 0 197 6 0 0 20 0 11 0 119865173 1074757632 116766 18446744073709551615 4194304 4228012 140734113218752 139635913739280 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19311] ppid=19300 vsize=1049568 CPUtime=0
/proc/19303/task/19311/stat : 19311 (java) S 19300 19300 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 119865173 1074757632 116766 18446744073709551615 4194304 4228012 140734113218752 139635912686800 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19312] ppid=19300 vsize=1049568 CPUtime=0
/proc/19303/task/19312/stat : 19312 (java) S 19300 19300 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 119865173 1074757632 116766 18446744073709551615 4194304 4228012 140734113218752 139635911634304 139636019844683 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19313] ppid=19300 vsize=1049568 CPUtime=0
/proc/19303/task/19313/stat : 19313 (java) S 19300 19300 1750 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 11 0 119865983 1074757632 116766 18446744073709551615 4194304 4228012 140734113218752 139635910436704 139636019844683 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 9.24
Current children cumulated vsize (KiB) 1058736

[startup+10.0055 s]
/proc/loadavg: 1.97 1.77 1.41 1/71 19314
/proc/meminfo: memFree=9988/1022884 swapFree=0/0
[pid=19300] ppid=19299 vsize=9168 CPUtime=0
/proc/19300/stat : 19300 (p2cudf-full-1.1) S 19299 19300 1750 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 119865149 9388032 330 18446744073709551615 4194304 5129932 140734129502336 140734129500480 140658447897694 0 65536 16781316 65538 0 0 0 17 0 0 0 3 0 0
/proc/19300/statm: 2292 330 280 229 0 52 0
[pid=19303] ppid=19300 vsize=1050596 CPUtime=9.47
/proc/19303/stat : 19303 (java) S 19300 19300 1750 0 -1 4202496 124970 0 20 0 903 44 0 0 20 0 11 0 119865153 1075810304 116780 18446744073709551615 4194304 4228012 140734113218752 140734113209776 139636019830389 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 8 0 0
/proc/19303/statm: 262649 116780 2381 9 0 249999 0
[pid=19303/tid=19304] ppid=19300 vsize=1050596 CPUtime=4.34
/proc/19303/task/19304/stat : 19304 (java) S 19300 19300 1750 0 -1 4202560 47805 0 8 0 414 20 0 0 20 0 11 0 119865163 1075810304 116780 18446744073709551615 4194304 4228012 140734113218752 139636026364848 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 11 0 0
[pid=19303/tid=19305] ppid=19300 vsize=1050596 CPUtime=0.99
/proc/19303/task/19305/stat : 19305 (java) S 19300 19300 1750 0 -1 4202560 53202 0 0 0 85 14 0 0 20 0 11 0 119865170 1075810304 116780 18446744073709551615 4194304 4228012 140734113218752 139635919002752 139636019844683 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19306] ppid=19300 vsize=1050596 CPUtime=0
/proc/19303/task/19306/stat : 19306 (java) S 19300 19300 1750 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 119865171 1075810304 116780 18446744073709551615 4194304 4228012 140734113218752 139635917948944 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19307] ppid=19300 vsize=1050596 CPUtime=0
/proc/19303/task/19307/stat : 19307 (java) S 19300 19300 1750 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 119865171 1075810304 116780 18446744073709551615 4194304 4228012 140734113218752 139635916896160 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19308] ppid=19300 vsize=1050596 CPUtime=0
/proc/19303/task/19308/stat : 19308 (java) S 19300 19300 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 119865173 1075810304 116780 18446744073709551615 4194304 4228012 140734113218752 139635915844592 139636019852320 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19309] ppid=19300 vsize=1050596 CPUtime=2.03
/proc/19303/task/19309/stat : 19309 (java) S 19300 19300 1750 0 -1 4202560 10229 0 0 0 199 4 0 0 20 0 11 0 119865173 1075810304 116780 18446744073709551615 4194304 4228012 140734113218752 139635914791952 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19310] ppid=19300 vsize=1050596 CPUtime=2.09
/proc/19303/task/19310/stat : 19310 (java) S 19300 19300 1750 0 -1 4202560 12441 0 0 0 203 6 0 0 20 0 11 0 119865173 1075810304 116780 18446744073709551615 4194304 4228012 140734113218752 139635913739280 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19311] ppid=19300 vsize=1050596 CPUtime=0
/proc/19303/task/19311/stat : 19311 (java) S 19300 19300 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 119865173 1075810304 116780 18446744073709551615 4194304 4228012 140734113218752 139635912686800 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19312] ppid=19300 vsize=1050596 CPUtime=0
/proc/19303/task/19312/stat : 19312 (java) S 19300 19300 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 119865173 1075810304 116780 18446744073709551615 4194304 4228012 140734113218752 139635911634304 139636019844683 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19314] ppid=19300 vsize=1050596 CPUtime=0
/proc/19303/task/19314/stat : 19314 (java) S 19300 19300 1750 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 11 0 119866129 1075810304 116780 18446744073709551615 4194304 4228012 140734113218752 139635909384368 139636019844683 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 9.47
Current children cumulated vsize (KiB) 1059764

[startup+10.4008 s]
/proc/loadavg: 1.97 1.77 1.41 1/71 19314
/proc/meminfo: memFree=9988/1022884 swapFree=0/0
[pid=19300] ppid=19299 vsize=9168 CPUtime=0
/proc/19300/stat : 19300 (p2cudf-full-1.1) S 19299 19300 1750 0 -1 4202496 455 290 2 1 0 0 0 0 20 0 1 0 119865149 9388032 330 18446744073709551615 4194304 5129932 140734129502336 140734129500480 140658447897694 0 65536 16781316 65538 0 0 0 17 0 0 0 3 0 0
/proc/19300/statm: 2292 330 280 229 0 52 0
[pid=19303] ppid=19300 vsize=1050596 CPUtime=9.56
/proc/19303/stat : 19303 (java) S 19300 19300 1750 0 -1 4202496 124972 0 20 0 908 48 0 0 20 0 11 0 119865153 1075810304 116470 18446744073709551615 4194304 4228012 140734113218752 140734113209776 139636019830389 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 8 0 0
/proc/19303/statm: 262649 116470 2381 9 0 249999 0
[pid=19303/tid=19304] ppid=19300 vsize=1050596 CPUtime=4.34
/proc/19303/task/19304/stat : 19304 (java) S 19300 19300 1750 0 -1 4202560 47805 0 8 0 414 20 0 0 20 0 11 0 119865163 1075810304 116470 18446744073709551615 4194304 4228012 140734113218752 139636026364848 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 11 0 0
[pid=19303/tid=19305] ppid=19300 vsize=1050596 CPUtime=0.99
/proc/19303/task/19305/stat : 19305 (java) S 19300 19300 1750 0 -1 4202560 53202 0 0 0 85 14 0 0 20 0 11 0 119865170 1075810304 116470 18446744073709551615 4194304 4228012 140734113218752 139635919002752 139636019844683 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19306] ppid=19300 vsize=1050596 CPUtime=0
/proc/19303/task/19306/stat : 19306 (java) S 19300 19300 1750 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 119865171 1075810304 116470 18446744073709551615 4194304 4228012 140734113218752 139635917948944 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19307] ppid=19300 vsize=1050596 CPUtime=0
/proc/19303/task/19307/stat : 19307 (java) S 19300 19300 1750 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 119865171 1075810304 116470 18446744073709551615 4194304 4228012 140734113218752 139635916896160 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19308] ppid=19300 vsize=1050596 CPUtime=0
/proc/19303/task/19308/stat : 19308 (java) S 19300 19300 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 119865173 1075810304 116470 18446744073709551615 4194304 4228012 140734113218752 139635915844592 139636019852320 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19309] ppid=19300 vsize=1050596 CPUtime=2.04
/proc/19303/task/19309/stat : 19309 (java) S 19300 19300 1750 0 -1 4202560 10229 0 0 0 200 4 0 0 20 0 11 0 119865173 1075810304 116470 18446744073709551615 4194304 4228012 140734113218752 139635914791952 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19310] ppid=19300 vsize=1050596 CPUtime=2.1
/proc/19303/task/19310/stat : 19310 (java) S 19300 19300 1750 0 -1 4202560 12441 0 0 0 204 6 0 0 20 0 11 0 119865173 1075810304 116470 18446744073709551615 4194304 4228012 140734113218752 139635913739280 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19311] ppid=19300 vsize=1050596 CPUtime=0
/proc/19303/task/19311/stat : 19311 (java) S 19300 19300 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 119865173 1075810304 116470 18446744073709551615 4194304 4228012 140734113218752 139635912686800 139636019843796 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19312] ppid=19300 vsize=1050596 CPUtime=0
/proc/19303/task/19312/stat : 19312 (java) S 19300 19300 1750 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 119865173 1075810304 116470 18446744073709551615 4194304 4228012 140734113218752 139635911634304 139636019844683 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=19303/tid=19314] ppid=19300 vsize=1050596 CPUtime=0.07
/proc/19303/task/19314/stat : 19314 (java) R 19300 19300 1750 0 -1 4202560 8 0 0 0 3 4 0 0 20 0 11 0 119866129 1075810304 116470 18446744073709551615 4194304 4228012 140734113218752 139635909375280 139636019855661 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 9.56
Current children cumulated vsize (KiB) 1059764

Child status: 0
Real time (s): 10.4636
CPU time (s): 9.6406
CPU user time (s): 9.11257
CPU system time (s): 0.528033
CPU usage (%): 92.1345
Max. virtual memory (cumulated for all children) (KiB): 1061756

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 9.11257
system time used= 0.528033
maximum resident set size= 467800
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 125740
page faults= 23
swaps= 0
block input operations= 44768
block output operations= 176
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 1032
involuntary context switches= 2885

runsolver used 0.016001 second user time and 0.088005 second system time

The end