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/201109011757/gj-user-solver-1.0/e0bd67a6-56d0-11df-b11f-00163e7a6f5e.cudf.dudf-real.log.runsolver ./gj-user-solver-1.0 /home/misc2010/data/2011/dudf-real//e0bd67a6-56d0-11df-b11f-00163e7a6f5e.cudf /home/misc2010/tmp/201109011757/gj-user-solver-1.0/e0bd67a6-56d0-11df-b11f-00163e7a6f5e.cudf.dudf-real.result -sum(pin-priority-1),-sum(pin-priority-500),-sum(pin-priority-700),-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.42 1.15 1.04 5/35 3606
/proc/meminfo: memFree=248320/1048576 swapFree=0/0
[pid=3605] ppid=3604 vsize=2564 CPUtime=0
/proc/3605/stat : 3605 (gj-user-solver-) R 3604 3605 22717 34817 22717 4202496 354 0 0 0 0 0 0 0 25 0 1 0 73600229 2625536 267 1283457024 134512640 135304128 4290997680 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/3605/statm: 641 267 228 194 0 28 0
[pid=3606] ppid=3605 vsize=2564 CPUtime=0
/proc/3606/stat : 3606 (gj-user-solver-) R 3605 3605 22717 34817 22717 4202560 0 0 0 0 0 0 0 0 25 0 1 0 73600229 2625536 39 1283457024 134512640 135304128 4290997680 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/3606/statm: 641 39 0 194 0 28 0

[startup+0.161653 s]
/proc/loadavg: 1.42 1.15 1.04 5/35 3606
/proc/meminfo: memFree=248320/1048576 swapFree=0/0
[pid=3605] ppid=3604 vsize=2564 CPUtime=0
/proc/3605/stat : 3605 (gj-user-solver-) S 3604 3605 22717 34817 22717 4202496 371 0 0 0 0 0 0 0 25 0 1 0 73600229 2625536 268 1283457024 134512640 135304128 4290997680 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3605/statm: 641 268 229 194 0 28 0
[pid=3606] ppid=3605 vsize=410204 CPUtime=0.16
/proc/3606/stat : 3606 (java) S 3605 3605 22717 34817 22717 4202496 4383 0 1 0 16 0 0 0 25 0 9 0 73600229 420048896 3811 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/3606/statm: 102551 3811 1946 10 0 96699 0
Current children cumulated CPU time (s) 0.16
Current children cumulated vsize (KiB) 412768

[startup+0.21166 s]
/proc/loadavg: 1.42 1.15 1.04 5/35 3606
/proc/meminfo: memFree=248320/1048576 swapFree=0/0
[pid=3605] ppid=3604 vsize=2564 CPUtime=0
/proc/3605/stat : 3605 (gj-user-solver-) S 3604 3605 22717 34817 22717 4202496 371 0 0 0 0 0 0 0 25 0 1 0 73600229 2625536 268 1283457024 134512640 135304128 4290997680 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3605/statm: 641 268 229 194 0 28 0
[pid=3606] ppid=3605 vsize=410204 CPUtime=0.21
/proc/3606/stat : 3606 (java) S 3605 3605 22717 34817 22717 4202496 4707 0 1 0 20 1 0 0 25 0 9 0 73600229 420048896 4135 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/3606/statm: 102551 4135 1946 10 0 96699 0
Current children cumulated CPU time (s) 0.21
Current children cumulated vsize (KiB) 412768

[startup+0.311683 s]
/proc/loadavg: 1.42 1.15 1.04 5/35 3606
/proc/meminfo: memFree=248320/1048576 swapFree=0/0
[pid=3605] ppid=3604 vsize=2564 CPUtime=0
/proc/3605/stat : 3605 (gj-user-solver-) S 3604 3605 22717 34817 22717 4202496 371 0 0 0 0 0 0 0 25 0 1 0 73600229 2625536 268 1283457024 134512640 135304128 4290997680 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3605/statm: 641 268 229 194 0 28 0
[pid=3606] ppid=3605 vsize=410204 CPUtime=0.31
/proc/3606/stat : 3606 (java) S 3605 3605 22717 34817 22717 4202496 5316 0 1 0 30 1 0 0 25 0 9 0 73600229 420048896 4743 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/3606/statm: 102551 4743 1952 10 0 96699 0
Current children cumulated CPU time (s) 0.31
Current children cumulated vsize (KiB) 412768

[startup+0.711805 s]
/proc/loadavg: 1.42 1.15 1.04 5/35 3606
/proc/meminfo: memFree=248320/1048576 swapFree=0/0
[pid=3605] ppid=3604 vsize=2564 CPUtime=0
/proc/3605/stat : 3605 (gj-user-solver-) S 3604 3605 22717 34817 22717 4202496 371 0 0 0 0 0 0 0 25 0 1 0 73600229 2625536 268 1283457024 134512640 135304128 4290997680 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3605/statm: 641 268 229 194 0 28 0
[pid=3606] ppid=3605 vsize=410756 CPUtime=0.71
/proc/3606/stat : 3606 (java) S 3605 3605 22717 34817 22717 4202496 12912 0 1 0 68 3 0 0 25 0 9 0 73600229 420614144 12153 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/3606/statm: 102689 12153 2901 10 0 96837 0
Current children cumulated CPU time (s) 0.71
Current children cumulated vsize (KiB) 413320

[startup+1.50202 s]
/proc/loadavg: 1.42 1.15 1.04 2/44 3615
/proc/meminfo: memFree=188656/1048576 swapFree=0/0
[pid=3605] ppid=3604 vsize=2564 CPUtime=0
/proc/3605/stat : 3605 (gj-user-solver-) S 3604 3605 22717 34817 22717 4202496 371 0 0 0 0 0 0 0 25 0 1 0 73600229 2625536 268 1283457024 134512640 135304128 4290997680 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3605/statm: 641 268 229 194 0 28 0
[pid=3606] ppid=3605 vsize=410756 CPUtime=1.49
/proc/3606/stat : 3606 (java) S 3605 3605 22717 34817 22717 4202496 27116 0 1 0 142 7 0 0 25 0 9 0 73600229 420614144 26357 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/3606/statm: 102689 26357 2901 10 0 96837 0
[pid=3606/tid=3608] ppid=3605 vsize=410756 CPUtime=0.79
/proc/3606/task/3608/stat : 3608 (java) S 3605 3605 22717 34817 22717 4202560 6843 0 1 0 77 2 0 0 24 0 9 0 73600230 420614144 26357 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3609] ppid=3605 vsize=410756 CPUtime=0.65
/proc/3606/task/3609/stat : 3609 (java) R 3605 3605 22717 34817 22717 4202560 18893 0 0 0 61 4 0 0 19 0 9 0 73600231 420614144 26357 1283457024 134512640 134550932 4288457392 18446744073709551615 4151384002 0 0 0 16800975 0 0 0 -1 0 0 0 0
[pid=3606/tid=3610] ppid=3605 vsize=410756 CPUtime=0
/proc/3606/task/3610/stat : 3610 (java) S 3605 3605 22717 34817 22717 4202560 15 0 0 0 0 0 0 0 20 0 9 0 73600231 420614144 26357 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3611] ppid=3605 vsize=410756 CPUtime=0
/proc/3606/task/3611/stat : 3611 (java) S 3605 3605 22717 34817 22717 4202560 5 0 0 0 0 0 0 0 20 0 9 0 73600231 420614144 26357 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3612] ppid=3605 vsize=410756 CPUtime=0
/proc/3606/task/3612/stat : 3612 (java) S 3605 3605 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 9 0 73600232 420614144 26357 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3613] ppid=3605 vsize=410756 CPUtime=0.04
/proc/3606/task/3613/stat : 3613 (java) S 3605 3605 22717 34817 22717 4202560 441 0 0 0 4 0 0 0 21 0 9 0 73600232 420614144 26357 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3614] ppid=3605 vsize=410756 CPUtime=0
/proc/3606/task/3614/stat : 3614 (java) S 3605 3605 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 9 0 73600232 420614144 26357 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3615] ppid=3605 vsize=410756 CPUtime=0
/proc/3606/task/3615/stat : 3615 (java) S 3605 3605 22717 34817 22717 4202560 0 0 0 0 0 0 0 0 15 0 9 0 73600232 420614144 26357 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 413320

[startup+3.10243 s]
/proc/loadavg: 1.42 1.15 1.04 2/44 3615
/proc/meminfo: memFree=115372/1048576 swapFree=0/0
[pid=3605] ppid=3604 vsize=2564 CPUtime=0
/proc/3605/stat : 3605 (gj-user-solver-) S 3604 3605 22717 34817 22717 4202496 371 0 0 0 0 0 0 0 25 0 1 0 73600229 2625536 268 1283457024 134512640 135304128 4290997680 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3605/statm: 641 268 229 194 0 28 0
[pid=3606] ppid=3605 vsize=411092 CPUtime=3.09
/proc/3606/stat : 3606 (java) S 3605 3605 22717 34817 22717 4202496 39949 0 1 0 298 11 0 0 25 0 10 0 73600229 420958208 39108 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/3606/statm: 102773 39108 2927 10 0 96918 0
[pid=3606/tid=3608] ppid=3605 vsize=411092 CPUtime=1.84
/proc/3606/task/3608/stat : 3608 (java) R 3605 3605 22717 34817 22717 4202560 9939 0 1 0 182 2 0 0 25 0 10 0 73600230 420958208 39108 1283457024 134512640 134550932 4288457392 18446744073709551615 4115588588 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=3606/tid=3609] ppid=3605 vsize=411092 CPUtime=1.14
/proc/3606/task/3609/stat : 3609 (java) S 3605 3605 22717 34817 22717 4202560 28546 0 0 0 106 8 0 0 16 0 10 0 73600231 420958208 39108 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 0 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3610] ppid=3605 vsize=411092 CPUtime=0
/proc/3606/task/3610/stat : 3610 (java) S 3605 3605 22717 34817 22717 4202560 15 0 0 0 0 0 0 0 18 0 10 0 73600231 420958208 39108 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3611] ppid=3605 vsize=411092 CPUtime=0
/proc/3606/task/3611/stat : 3611 (java) S 3605 3605 22717 34817 22717 4202560 5 0 0 0 0 0 0 0 18 0 10 0 73600231 420958208 39108 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3612] ppid=3605 vsize=411092 CPUtime=0
/proc/3606/task/3612/stat : 3612 (java) S 3605 3605 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 10 0 73600232 420958208 39108 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3613] ppid=3605 vsize=411092 CPUtime=0.1
/proc/3606/task/3613/stat : 3613 (java) S 3605 3605 22717 34817 22717 4202560 520 0 0 0 10 0 0 0 15 0 10 0 73600232 420958208 39108 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3614] ppid=3605 vsize=411092 CPUtime=0
/proc/3606/task/3614/stat : 3614 (java) S 3605 3605 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 10 0 73600232 420958208 39108 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3615] ppid=3605 vsize=411092 CPUtime=0
/proc/3606/task/3615/stat : 3615 (java) S 3605 3605 22717 34817 22717 4202560 0 0 0 0 0 0 0 0 15 0 10 0 73600232 420958208 39108 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.09
Current children cumulated vsize (KiB) 413656

[startup+6.31326 s]
/proc/loadavg: 1.39 1.14 1.04 2/44 3616
/proc/meminfo: memFree=87844/1048576 swapFree=0/0
[pid=3605] ppid=3604 vsize=2564 CPUtime=0
/proc/3605/stat : 3605 (gj-user-solver-) S 3604 3605 22717 34817 22717 4202496 371 0 0 0 0 0 0 0 25 0 1 0 73600229 2625536 268 1283457024 134512640 135304128 4290997680 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3605/statm: 641 268 229 194 0 28 0
[pid=3606] ppid=3605 vsize=411092 CPUtime=6.28
/proc/3606/stat : 3606 (java) S 3605 3605 22717 34817 22717 4202496 44129 0 1 0 616 12 0 0 25 0 10 0 73600229 420958208 43288 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/3606/statm: 102773 43288 2928 10 0 96918 0
[pid=3606/tid=3608] ppid=3605 vsize=411092 CPUtime=4.87
/proc/3606/task/3608/stat : 3608 (java) R 3605 3605 22717 34817 22717 4202560 9944 0 1 0 485 2 0 0 25 0 10 0 73600230 420958208 43288 1283457024 134512640 134550932 4288457392 18446744073709551615 4116046405 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=3606/tid=3609] ppid=3605 vsize=411092 CPUtime=1.27
/proc/3606/task/3609/stat : 3609 (java) S 3605 3605 22717 34817 22717 4202560 32698 0 0 0 118 9 0 0 16 0 10 0 73600231 420958208 43288 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 0 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3610] ppid=3605 vsize=411092 CPUtime=0
/proc/3606/task/3610/stat : 3610 (java) S 3605 3605 22717 34817 22717 4202560 15 0 0 0 0 0 0 0 15 0 10 0 73600231 420958208 43288 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3611] ppid=3605 vsize=411092 CPUtime=0
/proc/3606/task/3611/stat : 3611 (java) S 3605 3605 22717 34817 22717 4202560 5 0 0 0 0 0 0 0 18 0 10 0 73600231 420958208 43288 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3612] ppid=3605 vsize=411092 CPUtime=0
/proc/3606/task/3612/stat : 3612 (java) S 3605 3605 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 10 0 73600232 420958208 43288 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3613] ppid=3605 vsize=411092 CPUtime=0.12
/proc/3606/task/3613/stat : 3613 (java) S 3605 3605 22717 34817 22717 4202560 543 0 0 0 12 0 0 0 15 0 10 0 73600232 420958208 43288 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3614] ppid=3605 vsize=411092 CPUtime=0
/proc/3606/task/3614/stat : 3614 (java) S 3605 3605 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 10 0 73600232 420958208 43288 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3615] ppid=3605 vsize=411092 CPUtime=0
/proc/3606/task/3615/stat : 3615 (java) S 3605 3605 22717 34817 22717 4202560 0 0 0 0 0 0 0 0 15 0 10 0 73600232 420958208 43288 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3616] ppid=3605 vsize=411092 CPUtime=0
/proc/3606/task/3616/stat : 3616 (java) S 3605 3605 22717 34817 22717 4202560 5 0 0 0 0 0 0 0 25 0 10 0 73600473 420958208 43288 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.28
Current children cumulated vsize (KiB) 413656

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

[startup+6.40328 s]
/proc/loadavg: 1.39 1.14 1.04 2/44 3616
/proc/meminfo: memFree=87844/1048576 swapFree=0/0
[pid=3605] ppid=3604 vsize=2564 CPUtime=0
/proc/3605/stat : 3605 (gj-user-solver-) S 3604 3605 22717 34817 22717 4202496 371 0 0 0 0 0 0 0 25 0 1 0 73600229 2625536 268 1283457024 134512640 135304128 4290997680 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3605/statm: 641 268 229 194 0 28 0
[pid=3606] ppid=3605 vsize=411092 CPUtime=6.37
/proc/3606/stat : 3606 (java) S 3605 3605 22717 34817 22717 4202496 44129 0 1 0 625 12 0 0 25 0 10 0 73600229 420958208 43288 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/3606/statm: 102773 43288 2928 10 0 96918 0
[pid=3606/tid=3608] ppid=3605 vsize=411092 CPUtime=4.96
/proc/3606/task/3608/stat : 3608 (java) R 3605 3605 22717 34817 22717 4202560 9944 0 1 0 494 2 0 0 25 0 10 0 73600230 420958208 43288 1283457024 134512640 134550932 4288457392 18446744073709551615 4116004081 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=3606/tid=3609] ppid=3605 vsize=411092 CPUtime=1.27
/proc/3606/task/3609/stat : 3609 (java) S 3605 3605 22717 34817 22717 4202560 32698 0 0 0 118 9 0 0 16 0 10 0 73600231 420958208 43288 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 0 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3610] ppid=3605 vsize=411092 CPUtime=0
/proc/3606/task/3610/stat : 3610 (java) S 3605 3605 22717 34817 22717 4202560 15 0 0 0 0 0 0 0 15 0 10 0 73600231 420958208 43288 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3611] ppid=3605 vsize=411092 CPUtime=0
/proc/3606/task/3611/stat : 3611 (java) S 3605 3605 22717 34817 22717 4202560 5 0 0 0 0 0 0 0 18 0 10 0 73600231 420958208 43288 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3612] ppid=3605 vsize=411092 CPUtime=0
/proc/3606/task/3612/stat : 3612 (java) S 3605 3605 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 10 0 73600232 420958208 43288 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3613] ppid=3605 vsize=411092 CPUtime=0.12
/proc/3606/task/3613/stat : 3613 (java) S 3605 3605 22717 34817 22717 4202560 543 0 0 0 12 0 0 0 15 0 10 0 73600232 420958208 43288 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3614] ppid=3605 vsize=411092 CPUtime=0
/proc/3606/task/3614/stat : 3614 (java) S 3605 3605 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 10 0 73600232 420958208 43288 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3615] ppid=3605 vsize=411092 CPUtime=0
/proc/3606/task/3615/stat : 3615 (java) S 3605 3605 22717 34817 22717 4202560 0 0 0 0 0 0 0 0 15 0 10 0 73600232 420958208 43288 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3616] ppid=3605 vsize=411092 CPUtime=0
/proc/3606/task/3616/stat : 3616 (java) S 3605 3605 22717 34817 22717 4202560 5 0 0 0 0 0 0 0 25 0 10 0 73600473 420958208 43288 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.37
Current children cumulated vsize (KiB) 413656

[startup+6.802 s]
/proc/loadavg: 1.39 1.14 1.04 2/44 3616
/proc/meminfo: memFree=86240/1048576 swapFree=0/0
[pid=3605] ppid=3604 vsize=2564 CPUtime=0
/proc/3605/stat : 3605 (gj-user-solver-) S 3604 3605 22717 34817 22717 4202496 371 0 0 0 0 0 0 0 25 0 1 0 73600229 2625536 268 1283457024 134512640 135304128 4290997680 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3605/statm: 641 268 229 194 0 28 0
[pid=3606] ppid=3605 vsize=411092 CPUtime=6.72
/proc/3606/stat : 3606 (java) S 3605 3605 22717 34817 22717 4202496 44144 0 1 0 660 12 0 0 25 0 9 0 73600229 420958208 43303 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/3606/statm: 102773 43303 2929 10 0 96918 0
[pid=3606/tid=3608] ppid=3605 vsize=411092 CPUtime=5.31
/proc/3606/task/3608/stat : 3608 (java) S 3605 3605 22717 34817 22717 4202560 9944 0 1 0 529 2 0 0 25 0 9 0 73600230 420958208 43303 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3609] ppid=3605 vsize=411092 CPUtime=1.27
/proc/3606/task/3609/stat : 3609 (java) S 3605 3605 22717 34817 22717 4202560 32698 0 0 0 118 9 0 0 16 0 9 0 73600231 420958208 43303 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 0 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3610] ppid=3605 vsize=411092 CPUtime=0
/proc/3606/task/3610/stat : 3610 (java) S 3605 3605 22717 34817 22717 4202560 15 0 0 0 0 0 0 0 15 0 9 0 73600231 420958208 43303 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3611] ppid=3605 vsize=411092 CPUtime=0
/proc/3606/task/3611/stat : 3611 (java) S 3605 3605 22717 34817 22717 4202560 5 0 0 0 0 0 0 0 18 0 9 0 73600231 420958208 43303 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3612] ppid=3605 vsize=411092 CPUtime=0
/proc/3606/task/3612/stat : 3612 (java) S 3605 3605 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 9 0 73600232 420958208 43303 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3613] ppid=3605 vsize=411092 CPUtime=0.12
/proc/3606/task/3613/stat : 3613 (java) S 3605 3605 22717 34817 22717 4202560 557 0 0 0 12 0 0 0 16 0 9 0 73600232 420958208 43303 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3614] ppid=3605 vsize=411092 CPUtime=0
/proc/3606/task/3614/stat : 3614 (java) S 3605 3605 22717 34817 22717 4202560 1 0 0 0 0 0 0 0 25 0 9 0 73600232 420958208 43303 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
[pid=3606/tid=3615] ppid=3605 vsize=411092 CPUtime=0
/proc/3606/task/3615/stat : 3615 (java) S 3605 3605 22717 34817 22717 4202560 0 0 0 0 0 0 0 0 15 0 9 0 73600232 420958208 43303 1283457024 134512640 134550932 4288457392 18446744073709551615 4294960130 0 4 0 16800975 18446612133395905408 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 6.72
Current children cumulated vsize (KiB) 413656

Child status: 0
Real time (s): 6.81898
CPU time (s): 6.74042
CPU user time (s): 6.60841
CPU system time (s): 0.132008
CPU usage (%): 98.848
Max. virtual memory (cumulated for all children) (KiB): 413656

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 6.60841
system time used= 0.132008
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 44530
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= 896
involuntary context switches= 1149

runsolver used 0 second user time and 0.012 second system time

The end