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: /home/misc2010/bin/runsolver -s SIGUSR1 -M 1124 -C 290 -d 10 -w /home/misc2010/tmp/201108291842/gj-user-solver-1.0/rand152.cudf.user-upgrades.log.runsolver ./gj-user-solver-1.0 /home/misc2010/data/2011/user-upgrades/rand152.cudf /home/misc2010/tmp/201108291842/gj-user-solver-1.0/rand152.cudf.user-upgrades.result -notuptodate,-removed,-changed 

Enforcing CPUTime limit (soft limit, will send signal-name then SIGKILL): 290 seconds
Enforcing CPUTime limit (hard limit, will send SIGXCPU): 320 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: 1.02 0.95 0.84 5/37 18331
/proc/meminfo: memFree=803888/1048576 swapFree=0/0
[pid=18330] ppid=18329 vsize=2568 CPUtime=0
/proc/18330/stat : 18330 (gj-user-solver-) S 18329 18330 17511 34816 17511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 46007596 2629632 269 1283457024 134512640 135304128 4291915520 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18330/statm: 642 269 229 194 0 29 0
[pid=18331] ppid=18330 vsize=11044 CPUtime=0
/proc/18331/stat : 18331 (java) R 18330 18330 17511 34816 17511 4202496 727 0 0 0 0 0 0 0 25 0 1 0 46007596 11309056 464 1283457024 134512640 134550932 4288019120 18446744073709551615 4159882978 0 0 0 0 0 0 0 17 0 0 0 0
/proc/18331/statm: 2761 464 184 10 0 1103 0

[startup+0.205681 s]
/proc/loadavg: 1.02 0.95 0.84 5/37 18331
/proc/meminfo: memFree=803888/1048576 swapFree=0/0
[pid=18330] ppid=18329 vsize=2568 CPUtime=0
/proc/18330/stat : 18330 (gj-user-solver-) S 18329 18330 17511 34816 17511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 46007596 2629632 269 1283457024 134512640 135304128 4291915520 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18330/statm: 642 269 229 194 0 29 0
[pid=18331] ppid=18330 vsize=409920 CPUtime=0.2
/proc/18331/stat : 18331 (java) S 18330 18330 17511 34816 17511 4202496 4071 0 1 0 18 2 0 0 25 0 9 0 46007596 419758080 3499 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18331/statm: 102480 3499 1917 10 0 96628 0
Current children cumulated CPU time (s) 0.2
Current children cumulated vsize (KiB) 412488

[startup+0.305702 s]
/proc/loadavg: 1.02 0.95 0.84 5/37 18331
/proc/meminfo: memFree=803888/1048576 swapFree=0/0
[pid=18330] ppid=18329 vsize=2568 CPUtime=0
/proc/18330/stat : 18330 (gj-user-solver-) S 18329 18330 17511 34816 17511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 46007596 2629632 269 1283457024 134512640 135304128 4291915520 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18330/statm: 642 269 229 194 0 29 0
[pid=18331] ppid=18330 vsize=410476 CPUtime=0.3
/proc/18331/stat : 18331 (java) S 18330 18330 17511 34816 17511 4202496 4445 0 1 0 28 2 0 0 25 0 9 0 46007596 420327424 3873 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18331/statm: 102619 3873 1944 10 0 96767 0
Current children cumulated CPU time (s) 0.3
Current children cumulated vsize (KiB) 413044

[startup+0.405728 s]
/proc/loadavg: 1.02 0.95 0.84 5/37 18331
/proc/meminfo: memFree=803888/1048576 swapFree=0/0
[pid=18330] ppid=18329 vsize=2568 CPUtime=0
/proc/18330/stat : 18330 (gj-user-solver-) S 18329 18330 17511 34816 17511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 46007596 2629632 269 1283457024 134512640 135304128 4291915520 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18330/statm: 642 269 229 194 0 29 0
[pid=18331] ppid=18330 vsize=410476 CPUtime=0.4
/proc/18331/stat : 18331 (java) S 18330 18330 17511 34816 17511 4202496 6165 0 1 0 37 3 0 0 25 0 9 0 46007596 420327424 5592 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18331/statm: 102619 5592 1956 10 0 96767 0
Current children cumulated CPU time (s) 0.4
Current children cumulated vsize (KiB) 413044

[startup+0.705802 s]
/proc/loadavg: 1.02 0.95 0.84 5/37 18331
/proc/meminfo: memFree=803888/1048576 swapFree=0/0
[pid=18330] ppid=18329 vsize=2568 CPUtime=0
/proc/18330/stat : 18330 (gj-user-solver-) S 18329 18330 17511 34816 17511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 46007596 2629632 269 1283457024 134512640 135304128 4291915520 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18330/statm: 642 269 229 194 0 29 0
[pid=18331] ppid=18330 vsize=410616 CPUtime=0.7
/proc/18331/stat : 18331 (java) S 18330 18330 17511 34816 17511 4202496 12005 0 1 0 66 4 0 0 25 0 9 0 46007596 420470784 11246 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18331/statm: 102654 11246 2901 10 0 96802 0
Current children cumulated CPU time (s) 0.7
Current children cumulated vsize (KiB) 413184

[startup+1.50608 s]
/proc/loadavg: 1.02 0.95 0.84 2/46 18340
/proc/meminfo: memFree=745740/1048576 swapFree=0/0
[pid=18330] ppid=18329 vsize=2568 CPUtime=0
/proc/18330/stat : 18330 (gj-user-solver-) S 18329 18330 17511 34816 17511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 46007596 2629632 269 1283457024 134512640 135304128 4291915520 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18330/statm: 642 269 229 194 0 29 0
[pid=18331] ppid=18330 vsize=410748 CPUtime=1.5
/proc/18331/stat : 18331 (java) S 18330 18330 17511 34816 17511 4202496 26784 0 1 0 142 8 0 0 25 0 9 0 46007596 420605952 26025 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18331/statm: 102687 26025 2901 10 0 96835 0
[pid=18331/tid=18333] ppid=18330 vsize=410748 CPUtime=0.84
/proc/18331/task/18333/stat : 18333 (java) R 18330 18330 17511 34816 17511 4202560 6709 0 1 0 80 4 0 0 25 0 9 0 46007597 420605952 26025 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18331/tid=18334] ppid=18330 vsize=410748 CPUtime=0.6
/proc/18331/task/18334/stat : 18334 (java) R 18330 18330 17511 34816 17511 4202560 18688 0 0 0 58 2 0 0 18 0 9 0 46007597 420605952 26025 1283457024 134512640 134550932 4288019120 18446744073709551615 4151059369 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=18331/tid=18335] ppid=18330 vsize=410748 CPUtime=0
/proc/18331/task/18335/stat : 18335 (java) S 18330 18330 17511 34816 17511 4202560 15 0 0 0 0 0 0 0 20 0 9 0 46007598 420605952 26025 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18336] ppid=18330 vsize=410748 CPUtime=0
/proc/18331/task/18336/stat : 18336 (java) S 18330 18330 17511 34816 17511 4202560 5 0 0 0 0 0 0 0 20 0 9 0 46007598 420605952 26025 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18337] ppid=18330 vsize=410748 CPUtime=0
/proc/18331/task/18337/stat : 18337 (java) S 18330 18330 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 9 0 46007599 420605952 26025 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18338] ppid=18330 vsize=410748 CPUtime=0.03
/proc/18331/task/18338/stat : 18338 (java) S 18330 18330 17511 34816 17511 4202560 447 0 0 0 3 0 0 0 16 0 9 0 46007599 420605952 26025 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18339] ppid=18330 vsize=410748 CPUtime=0
/proc/18331/task/18339/stat : 18339 (java) S 18330 18330 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 9 0 46007599 420605952 26025 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18340] ppid=18330 vsize=410748 CPUtime=0
/proc/18331/task/18340/stat : 18340 (java) S 18330 18330 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 15 0 9 0 46007599 420605952 26025 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 413316

[startup+3.1066 s]
/proc/loadavg: 1.02 0.95 0.84 3/46 18340
/proc/meminfo: memFree=663900/1048576 swapFree=0/0
[pid=18330] ppid=18329 vsize=2568 CPUtime=0
/proc/18330/stat : 18330 (gj-user-solver-) S 18329 18330 17511 34816 17511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 46007596 2629632 269 1283457024 134512640 135304128 4291915520 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18330/statm: 642 269 229 194 0 29 0
[pid=18331] ppid=18330 vsize=410880 CPUtime=3.1
/proc/18331/stat : 18331 (java) S 18330 18330 17511 34816 17511 4202496 49565 0 1 0 294 16 0 0 25 0 9 0 46007596 420741120 48806 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18331/statm: 102720 48806 2901 10 0 96868 0
[pid=18331/tid=18333] ppid=18330 vsize=410880 CPUtime=1.46
/proc/18331/task/18333/stat : 18333 (java) R 18330 18330 17511 34816 17511 4202560 13862 0 1 0 140 6 0 0 25 0 9 0 46007597 420741120 48806 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18331/tid=18334] ppid=18330 vsize=410880 CPUtime=1.58
/proc/18331/task/18334/stat : 18334 (java) R 18330 18330 17511 34816 17511 4202560 34313 0 0 0 149 9 0 0 16 0 9 0 46007597 420741120 48806 1283457024 134512640 134550932 4288019120 18446744073709551615 4150758429 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=18331/tid=18335] ppid=18330 vsize=410880 CPUtime=0
/proc/18331/task/18335/stat : 18335 (java) S 18330 18330 17511 34816 17511 4202560 15 0 0 0 0 0 0 0 20 0 9 0 46007598 420741120 48806 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18336] ppid=18330 vsize=410880 CPUtime=0
/proc/18331/task/18336/stat : 18336 (java) S 18330 18330 17511 34816 17511 4202560 5 0 0 0 0 0 0 0 20 0 9 0 46007598 420741120 48806 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18337] ppid=18330 vsize=410880 CPUtime=0
/proc/18331/task/18337/stat : 18337 (java) S 18330 18330 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 9 0 46007599 420741120 48806 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18338] ppid=18330 vsize=410880 CPUtime=0.04
/proc/18331/task/18338/stat : 18338 (java) S 18330 18330 17511 34816 17511 4202560 450 0 0 0 4 0 0 0 15 0 9 0 46007599 420741120 48806 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18339] ppid=18330 vsize=410880 CPUtime=0
/proc/18331/task/18339/stat : 18339 (java) S 18330 18330 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 9 0 46007599 420741120 48806 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18340] ppid=18330 vsize=410880 CPUtime=0
/proc/18331/task/18340/stat : 18340 (java) S 18330 18330 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 15 0 9 0 46007599 420741120 48806 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.1
Current children cumulated vsize (KiB) 413448

[startup+6.3075 s]
/proc/loadavg: 1.02 0.95 0.84 2/46 18340
/proc/meminfo: memFree=537420/1048576 swapFree=0/0
[pid=18330] ppid=18329 vsize=2568 CPUtime=0
/proc/18330/stat : 18330 (gj-user-solver-) S 18329 18330 17511 34816 17511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 46007596 2629632 269 1283457024 134512640 135304128 4291915520 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18330/statm: 642 269 229 194 0 29 0
[pid=18331] ppid=18330 vsize=439920 CPUtime=6.3
/proc/18331/stat : 18331 (java) S 18330 18330 17511 34816 17511 4202496 78234 0 1 0 606 24 0 0 25 0 9 0 46007596 450478080 77469 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18331/statm: 109980 77469 2902 10 0 104128 0
[pid=18331/tid=18333] ppid=18330 vsize=439920 CPUtime=2.33
/proc/18331/task/18333/stat : 18333 (java) R 18330 18330 17511 34816 17511 4202560 13878 0 1 0 227 6 0 0 25 0 9 0 46007597 450478080 77469 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18331/tid=18334] ppid=18330 vsize=439920 CPUtime=3.9
/proc/18331/task/18334/stat : 18334 (java) R 18330 18330 17511 34816 17511 4202560 62948 0 0 0 373 17 0 0 16 0 9 0 46007597 450478080 77469 1283457024 134512640 134550932 4288019120 18446744073709551615 4152871522 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=18331/tid=18335] ppid=18330 vsize=439920 CPUtime=0
/proc/18331/task/18335/stat : 18335 (java) S 18330 18330 17511 34816 17511 4202560 15 0 0 0 0 0 0 0 20 0 9 0 46007598 450478080 77469 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18336] ppid=18330 vsize=439920 CPUtime=0
/proc/18331/task/18336/stat : 18336 (java) S 18330 18330 17511 34816 17511 4202560 5 0 0 0 0 0 0 0 20 0 9 0 46007598 450478080 77469 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18337] ppid=18330 vsize=439920 CPUtime=0
/proc/18331/task/18337/stat : 18337 (java) S 18330 18330 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 9 0 46007599 450478080 77469 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18338] ppid=18330 vsize=439920 CPUtime=0.05
/proc/18331/task/18338/stat : 18338 (java) S 18330 18330 17511 34816 17511 4202560 468 0 0 0 5 0 0 0 15 0 9 0 46007599 450478080 77469 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18339] ppid=18330 vsize=439920 CPUtime=0
/proc/18331/task/18339/stat : 18339 (java) S 18330 18330 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 9 0 46007599 450478080 77469 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18340] ppid=18330 vsize=439920 CPUtime=0
/proc/18331/task/18340/stat : 18340 (java) S 18330 18330 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 15 0 9 0 46007599 450478080 77469 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.3
Current children cumulated vsize (KiB) 442488

[startup+12.7096 s]
/proc/loadavg: 1.09 0.96 0.85 3/47 18343
/proc/meminfo: memFree=532700/1048576 swapFree=0/0
[pid=18330] ppid=18329 vsize=2568 CPUtime=0
/proc/18330/stat : 18330 (gj-user-solver-) S 18329 18330 17511 34816 17511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 46007596 2629632 269 1283457024 134512640 135304128 4291915520 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18330/statm: 642 269 229 194 0 29 0
[pid=18331] ppid=18330 vsize=411888 CPUtime=12.67
/proc/18331/stat : 18331 (java) S 18330 18330 17511 34816 17511 4202496 100041 0 1 0 1232 35 0 0 25 0 10 0 46007596 421773312 70652 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18331/statm: 102972 70652 2918 10 0 97117 0
[pid=18331/tid=18333] ppid=18330 vsize=411888 CPUtime=4.45
/proc/18331/task/18333/stat : 18333 (java) R 18330 18330 17511 34816 17511 4202560 14133 0 1 0 437 8 0 0 25 0 10 0 46007597 421773312 70652 1283457024 134512640 134550932 4288019120 18446744073709551615 4115349556 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18331/tid=18334] ppid=18330 vsize=411888 CPUtime=8.08
/proc/18331/task/18334/stat : 18334 (java) S 18330 18330 17511 34816 17511 4202560 84420 0 0 0 784 24 0 0 16 0 10 0 46007597 421773312 70652 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 0 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18335] ppid=18330 vsize=411888 CPUtime=0
/proc/18331/task/18335/stat : 18335 (java) S 18330 18330 17511 34816 17511 4202560 15 0 0 0 0 0 0 0 15 0 10 0 46007598 421773312 70652 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18336] ppid=18330 vsize=411888 CPUtime=0
/proc/18331/task/18336/stat : 18336 (java) S 18330 18330 17511 34816 17511 4202560 5 0 0 0 0 0 0 0 18 0 10 0 46007598 421773312 70652 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18337] ppid=18330 vsize=411888 CPUtime=0
/proc/18331/task/18337/stat : 18337 (java) S 18330 18330 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46007599 421773312 70652 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18338] ppid=18330 vsize=411888 CPUtime=0.11
/proc/18331/task/18338/stat : 18338 (java) S 18330 18330 17511 34816 17511 4202560 543 0 0 0 10 1 0 0 15 0 10 0 46007599 421773312 70652 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18339] ppid=18330 vsize=411888 CPUtime=0
/proc/18331/task/18339/stat : 18339 (java) S 18330 18330 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46007599 421773312 70652 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18340] ppid=18330 vsize=411888 CPUtime=0
/proc/18331/task/18340/stat : 18340 (java) S 18330 18330 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 15 0 10 0 46007599 421773312 70652 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18343] ppid=18330 vsize=411888 CPUtime=0
/proc/18331/task/18343/stat : 18343 (java) S 18330 18330 17511 34816 17511 4202560 5 0 0 0 0 0 0 0 22 0 10 0 46008687 421773312 70652 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 12.67
Current children cumulated vsize (KiB) 414456

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

[startup+12.9097 s]
/proc/loadavg: 1.09 0.96 0.85 3/47 18343
/proc/meminfo: memFree=532700/1048576 swapFree=0/0
[pid=18330] ppid=18329 vsize=2568 CPUtime=0
/proc/18330/stat : 18330 (gj-user-solver-) S 18329 18330 17511 34816 17511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 46007596 2629632 269 1283457024 134512640 135304128 4291915520 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18330/statm: 642 269 229 194 0 29 0
[pid=18331] ppid=18330 vsize=411888 CPUtime=12.87
/proc/18331/stat : 18331 (java) S 18330 18330 17511 34816 17511 4202496 100041 0 1 0 1252 35 0 0 25 0 10 0 46007596 421773312 70652 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18331/statm: 102972 70652 2918 10 0 97117 0
[pid=18331/tid=18333] ppid=18330 vsize=411888 CPUtime=4.65
/proc/18331/task/18333/stat : 18333 (java) R 18330 18330 17511 34816 17511 4202560 14133 0 1 0 457 8 0 0 25 0 10 0 46007597 421773312 70652 1283457024 134512640 134550932 4288019120 18446744073709551615 4115267165 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18331/tid=18334] ppid=18330 vsize=411888 CPUtime=8.08
/proc/18331/task/18334/stat : 18334 (java) S 18330 18330 17511 34816 17511 4202560 84420 0 0 0 784 24 0 0 16 0 10 0 46007597 421773312 70652 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 0 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18335] ppid=18330 vsize=411888 CPUtime=0
/proc/18331/task/18335/stat : 18335 (java) S 18330 18330 17511 34816 17511 4202560 15 0 0 0 0 0 0 0 15 0 10 0 46007598 421773312 70652 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18336] ppid=18330 vsize=411888 CPUtime=0
/proc/18331/task/18336/stat : 18336 (java) S 18330 18330 17511 34816 17511 4202560 5 0 0 0 0 0 0 0 18 0 10 0 46007598 421773312 70652 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18337] ppid=18330 vsize=411888 CPUtime=0
/proc/18331/task/18337/stat : 18337 (java) S 18330 18330 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46007599 421773312 70652 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18338] ppid=18330 vsize=411888 CPUtime=0.11
/proc/18331/task/18338/stat : 18338 (java) S 18330 18330 17511 34816 17511 4202560 543 0 0 0 10 1 0 0 15 0 10 0 46007599 421773312 70652 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18339] ppid=18330 vsize=411888 CPUtime=0
/proc/18331/task/18339/stat : 18339 (java) S 18330 18330 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46007599 421773312 70652 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18340] ppid=18330 vsize=411888 CPUtime=0
/proc/18331/task/18340/stat : 18340 (java) S 18330 18330 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 15 0 10 0 46007599 421773312 70652 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18343] ppid=18330 vsize=411888 CPUtime=0
/proc/18331/task/18343/stat : 18343 (java) S 18330 18330 17511 34816 17511 4202560 5 0 0 0 0 0 0 0 22 0 10 0 46008687 421773312 70652 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 12.87
Current children cumulated vsize (KiB) 414456

[startup+13.7098 s]
/proc/loadavg: 1.09 0.96 0.85 2/47 18343
/proc/meminfo: memFree=532700/1048576 swapFree=0/0
[pid=18330] ppid=18329 vsize=2568 CPUtime=0
/proc/18330/stat : 18330 (gj-user-solver-) S 18329 18330 17511 34816 17511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 46007596 2629632 269 1283457024 134512640 135304128 4291915520 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18330/statm: 642 269 229 194 0 29 0
[pid=18331] ppid=18330 vsize=411888 CPUtime=13.67
/proc/18331/stat : 18331 (java) S 18330 18330 17511 34816 17511 4202496 100046 0 1 0 1332 35 0 0 25 0 10 0 46007596 421773312 70657 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18331/statm: 102972 70657 2918 10 0 97117 0
[pid=18331/tid=18333] ppid=18330 vsize=411888 CPUtime=5.45
/proc/18331/task/18333/stat : 18333 (java) R 18330 18330 17511 34816 17511 4202560 14133 0 1 0 537 8 0 0 25 0 10 0 46007597 421773312 70657 1283457024 134512640 134550932 4288019120 18446744073709551615 4114890645 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18331/tid=18334] ppid=18330 vsize=411888 CPUtime=8.08
/proc/18331/task/18334/stat : 18334 (java) S 18330 18330 17511 34816 17511 4202560 84420 0 0 0 784 24 0 0 16 0 10 0 46007597 421773312 70657 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 0 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18335] ppid=18330 vsize=411888 CPUtime=0
/proc/18331/task/18335/stat : 18335 (java) S 18330 18330 17511 34816 17511 4202560 15 0 0 0 0 0 0 0 15 0 10 0 46007598 421773312 70657 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18336] ppid=18330 vsize=411888 CPUtime=0
/proc/18331/task/18336/stat : 18336 (java) S 18330 18330 17511 34816 17511 4202560 5 0 0 0 0 0 0 0 18 0 10 0 46007598 421773312 70657 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18337] ppid=18330 vsize=411888 CPUtime=0
/proc/18331/task/18337/stat : 18337 (java) S 18330 18330 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46007599 421773312 70657 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18338] ppid=18330 vsize=411888 CPUtime=0.11
/proc/18331/task/18338/stat : 18338 (java) S 18330 18330 17511 34816 17511 4202560 548 0 0 0 10 1 0 0 15 0 10 0 46007599 421773312 70657 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18339] ppid=18330 vsize=411888 CPUtime=0
/proc/18331/task/18339/stat : 18339 (java) S 18330 18330 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46007599 421773312 70657 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18340] ppid=18330 vsize=411888 CPUtime=0
/proc/18331/task/18340/stat : 18340 (java) R 18330 18330 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 15 0 10 0 46007599 421773312 70657 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18331/tid=18343] ppid=18330 vsize=411888 CPUtime=0
/proc/18331/task/18343/stat : 18343 (java) S 18330 18330 17511 34816 17511 4202560 5 0 0 0 0 0 0 0 22 0 10 0 46008687 421773312 70657 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 13.67
Current children cumulated vsize (KiB) 414456

[startup+14.51 s]
/proc/loadavg: 1.09 0.96 0.85 3/47 18345
/proc/meminfo: memFree=532948/1048576 swapFree=0/0
[pid=18330] ppid=18329 vsize=2568 CPUtime=0
/proc/18330/stat : 18330 (gj-user-solver-) S 18329 18330 17511 34816 17511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 46007596 2629632 269 1283457024 134512640 135304128 4291915520 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18330/statm: 642 269 229 194 0 29 0
[pid=18331] ppid=18330 vsize=411888 CPUtime=14.45
/proc/18331/stat : 18331 (java) S 18330 18330 17511 34816 17511 4202496 100047 0 1 0 1410 35 0 0 25 0 10 0 46007596 421773312 70658 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18331/statm: 102972 70658 2918 10 0 97117 0
[pid=18331/tid=18333] ppid=18330 vsize=411888 CPUtime=6.23
/proc/18331/task/18333/stat : 18333 (java) R 18330 18330 17511 34816 17511 4202560 14133 0 1 0 615 8 0 0 25 0 10 0 46007597 421773312 70658 1283457024 134512640 134550932 4288019120 18446744073709551615 4152971346 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=18331/tid=18334] ppid=18330 vsize=411888 CPUtime=8.08
/proc/18331/task/18334/stat : 18334 (java) S 18330 18330 17511 34816 17511 4202560 84420 0 0 0 784 24 0 0 15 0 10 0 46007597 421773312 70658 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 0 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18335] ppid=18330 vsize=411888 CPUtime=0
/proc/18331/task/18335/stat : 18335 (java) S 18330 18330 17511 34816 17511 4202560 15 0 0 0 0 0 0 0 15 0 10 0 46007598 421773312 70658 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18336] ppid=18330 vsize=411888 CPUtime=0
/proc/18331/task/18336/stat : 18336 (java) S 18330 18330 17511 34816 17511 4202560 5 0 0 0 0 0 0 0 18 0 10 0 46007598 421773312 70658 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18337] ppid=18330 vsize=411888 CPUtime=0
/proc/18331/task/18337/stat : 18337 (java) S 18330 18330 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46007599 421773312 70658 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18338] ppid=18330 vsize=411888 CPUtime=0.11
/proc/18331/task/18338/stat : 18338 (java) S 18330 18330 17511 34816 17511 4202560 549 0 0 0 10 1 0 0 15 0 10 0 46007599 421773312 70658 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18339] ppid=18330 vsize=411888 CPUtime=0
/proc/18331/task/18339/stat : 18339 (java) S 18330 18330 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46007599 421773312 70658 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18340] ppid=18330 vsize=411888 CPUtime=0
/proc/18331/task/18340/stat : 18340 (java) S 18330 18330 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 15 0 10 0 46007599 421773312 70658 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18343] ppid=18330 vsize=411888 CPUtime=0
/proc/18331/task/18343/stat : 18343 (java) S 18330 18330 17511 34816 17511 4202560 5 0 0 0 0 0 0 0 22 0 10 0 46008687 421773312 70658 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 14.45
Current children cumulated vsize (KiB) 414456

[startup+14.7026 s]
/proc/loadavg: 1.09 0.96 0.85 3/47 18345
/proc/meminfo: memFree=532948/1048576 swapFree=0/0
[pid=18330] ppid=18329 vsize=2568 CPUtime=0
/proc/18330/stat : 18330 (gj-user-solver-) S 18329 18330 17511 34816 17511 4202496 372 0 0 0 0 0 0 0 18 0 1 0 46007596 2629632 269 1283457024 134512640 135304128 4291915520 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/18330/statm: 642 269 229 194 0 29 0
[pid=18331] ppid=18330 vsize=411888 CPUtime=14.64
/proc/18331/stat : 18331 (java) S 18330 18330 17511 34816 17511 4202496 100051 0 1 0 1429 35 0 0 25 0 9 0 46007596 421773312 70662 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/18331/statm: 102972 70662 2921 10 0 97117 0
[pid=18331/tid=18333] ppid=18330 vsize=411888 CPUtime=6.39
/proc/18331/task/18333/stat : 18333 (java) S 18330 18330 17511 34816 17511 4202560 14133 0 1 0 631 8 0 0 25 0 9 0 46007597 421773312 70662 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18334] ppid=18330 vsize=411888 CPUtime=8.12
/proc/18331/task/18334/stat : 18334 (java) S 18330 18330 17511 34816 17511 4202560 84422 0 0 0 788 24 0 0 16 0 9 0 46007597 421773312 70662 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 0 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18335] ppid=18330 vsize=411888 CPUtime=0
/proc/18331/task/18335/stat : 18335 (java) S 18330 18330 17511 34816 17511 4202560 15 0 0 0 0 0 0 0 15 0 9 0 46007598 421773312 70662 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18336] ppid=18330 vsize=411888 CPUtime=0
/proc/18331/task/18336/stat : 18336 (java) S 18330 18330 17511 34816 17511 4202560 5 0 0 0 0 0 0 0 18 0 9 0 46007598 421773312 70662 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18337] ppid=18330 vsize=411888 CPUtime=0
/proc/18331/task/18337/stat : 18337 (java) S 18330 18330 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 9 0 46007599 421773312 70662 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18338] ppid=18330 vsize=411888 CPUtime=0.11
/proc/18331/task/18338/stat : 18338 (java) S 18330 18330 17511 34816 17511 4202560 550 0 0 0 10 1 0 0 15 0 9 0 46007599 421773312 70662 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18339] ppid=18330 vsize=411888 CPUtime=0
/proc/18331/task/18339/stat : 18339 (java) S 18330 18330 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 9 0 46007599 421773312 70662 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
[pid=18331/tid=18340] ppid=18330 vsize=411888 CPUtime=0
/proc/18331/task/18340/stat : 18340 (java) S 18330 18330 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 15 0 9 0 46007599 421773312 70662 1283457024 134512640 134550932 4288019120 18446744073709551615 4294960130 0 4 0 16800975 18446612132787398464 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 14.64
Current children cumulated vsize (KiB) 414456

Child status: 0
Real time (s): 14.7625
CPU time (s): 14.6649
CPU user time (s): 14.2929
CPU system time (s): 0.372023
CPU usage (%): 99.339
Max. virtual memory (cumulated for all children) (KiB): 442488

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 14.2929
system time used= 0.372023
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 100438
page faults= 1
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 1057
involuntary context switches= 1263

runsolver used 0 second user time and 0 second system time

The end