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/201108251442/p2cudf-paranoid-1.13/rand600.cudf.s.log.runsolver ./p2cudf-paranoid-1.13 /home/misc2010/data/2011/incremental/s/rand600.cudf /home/misc2010/tmp/201108251442/p2cudf-paranoid-1.13/rand600.cudf.s.result 

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.12 1.04 1.04 5/37 14585
/proc/meminfo: memFree=357552/1048576 swapFree=0/0
[pid=14581] ppid=14580 vsize=2568 CPUtime=0
/proc/14581/stat : 14581 (p2cudf-paranoid) S 14580 14581 4778 34817 4778 4202496 375 0 0 0 0 0 0 0 24 0 1 0 10743256 2629632 270 1283457024 134512640 135304128 4287634224 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14581/statm: 642 270 230 194 0 29 0
[pid=14582] ppid=14581 vsize=2568 CPUtime=0
/proc/14582/stat : 14582 (p2cudf) S 14581 14581 4778 34817 4778 4202496 351 0 0 0 0 0 0 0 24 0 1 0 10743256 2629632 270 1283457024 134512640 135304128 4291313344 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0
/proc/14582/statm: 642 270 231 194 0 29 0
[pid=14583] ppid=14582 vsize=2568 CPUtime=0
/proc/14583/stat : 14583 (p2cudf) R 14582 14581 4778 34817 4778 4202560 117 0 0 0 0 0 0 0 25 0 1 0 10743256 2629632 125 1283457024 134512640 135304128 4291313344 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/14583/statm: 642 125 84 194 0 29 0
[pid=14584] ppid=14583 vsize=11048 CPUtime=0.01
/proc/14584/stat : 14584 (java) R 14583 14581 4778 34817 4778 4202496 502 0 0 0 1 0 0 0 25 0 1 0 10743256 11313152 226 1283457024 134512640 134550932 4288345024 18446744073709551615 4159710932 0 0 0 0 0 0 0 17 0 0 0 0
/proc/14584/statm: 2762 226 157 10 0 1104 0
[pid=14585] ppid=14583 vsize=2568 CPUtime=0
/proc/14585/stat : 14585 (p2cudf) R 14583 14581 4778 34817 4778 4202560 0 0 0 0 0 0 0 0 25 0 1 0 10743256 2629632 41 1283457024 134512640 135304128 4291313344 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/14585/statm: 642 41 0 194 0 29 0

[startup+0.16612 s]
/proc/loadavg: 1.12 1.04 1.04 5/37 14585
/proc/meminfo: memFree=357552/1048576 swapFree=0/0
[pid=14581] ppid=14580 vsize=2568 CPUtime=0
/proc/14581/stat : 14581 (p2cudf-paranoid) S 14580 14581 4778 34817 4778 4202496 375 0 0 0 0 0 0 0 24 0 1 0 10743256 2629632 270 1283457024 134512640 135304128 4287634224 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14581/statm: 642 270 230 194 0 29 0
[pid=14582] ppid=14581 vsize=2572 CPUtime=0.03
/proc/14582/stat : 14582 (p2cudf) S 14581 14581 4778 34817 4778 4202496 388 3015 0 1 0 0 3 0 25 0 1 0 10743256 2633728 279 1283457024 134512640 135304128 4291313344 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14582/statm: 643 279 239 194 0 30 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5140

[startup+0.206118 s]
/proc/loadavg: 1.12 1.04 1.04 5/37 14585
/proc/meminfo: memFree=357552/1048576 swapFree=0/0
[pid=14581] ppid=14580 vsize=2568 CPUtime=0
/proc/14581/stat : 14581 (p2cudf-paranoid) S 14580 14581 4778 34817 4778 4202496 375 0 0 0 0 0 0 0 24 0 1 0 10743256 2629632 270 1283457024 134512640 135304128 4287634224 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14581/statm: 642 270 230 194 0 29 0
[pid=14582] ppid=14581 vsize=2572 CPUtime=0.03
/proc/14582/stat : 14582 (p2cudf) S 14581 14581 4778 34817 4778 4202496 388 3015 0 1 0 0 3 0 25 0 1 0 10743256 2633728 279 1283457024 134512640 135304128 4291313344 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14582/statm: 643 279 239 194 0 30 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5140

[startup+0.306138 s]
/proc/loadavg: 1.12 1.04 1.04 5/37 14585
/proc/meminfo: memFree=357552/1048576 swapFree=0/0
[pid=14581] ppid=14580 vsize=2568 CPUtime=0
/proc/14581/stat : 14581 (p2cudf-paranoid) S 14580 14581 4778 34817 4778 4202496 375 0 0 0 0 0 0 0 24 0 1 0 10743256 2629632 270 1283457024 134512640 135304128 4287634224 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14581/statm: 642 270 230 194 0 29 0
[pid=14582] ppid=14581 vsize=2572 CPUtime=0.03
/proc/14582/stat : 14582 (p2cudf) S 14581 14581 4778 34817 4778 4202496 388 3015 0 1 0 0 3 0 25 0 1 0 10743256 2633728 279 1283457024 134512640 135304128 4291313344 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14582/statm: 643 279 239 194 0 30 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5140

[startup+0.706249 s]
/proc/loadavg: 1.12 1.04 1.04 5/37 14585
/proc/meminfo: memFree=357552/1048576 swapFree=0/0
[pid=14581] ppid=14580 vsize=2568 CPUtime=0
/proc/14581/stat : 14581 (p2cudf-paranoid) S 14580 14581 4778 34817 4778 4202496 375 0 0 0 0 0 0 0 24 0 1 0 10743256 2629632 270 1283457024 134512640 135304128 4287634224 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14581/statm: 642 270 230 194 0 29 0
[pid=14582] ppid=14581 vsize=2572 CPUtime=0.03
/proc/14582/stat : 14582 (p2cudf) S 14581 14581 4778 34817 4778 4202496 388 3015 0 1 0 0 3 0 25 0 1 0 10743256 2633728 279 1283457024 134512640 135304128 4291313344 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14582/statm: 643 279 239 194 0 30 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5140

[startup+1.50644 s]
/proc/loadavg: 1.12 1.04 1.04 4/45 14604
/proc/meminfo: memFree=313164/1048576 swapFree=0/0
[pid=14581] ppid=14580 vsize=2568 CPUtime=0
/proc/14581/stat : 14581 (p2cudf-paranoid) S 14580 14581 4778 34817 4778 4202496 375 0 0 0 0 0 0 0 24 0 1 0 10743256 2629632 270 1283457024 134512640 135304128 4287634224 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14581/statm: 642 270 230 194 0 29 0
[pid=14582] ppid=14581 vsize=2572 CPUtime=0.03
/proc/14582/stat : 14582 (p2cudf) S 14581 14581 4778 34817 4778 4202496 388 3015 0 1 0 0 3 0 25 0 1 0 10743256 2633728 279 1283457024 134512640 135304128 4291313344 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14582/statm: 643 279 239 194 0 30 0
[pid=14595] ppid=14582 vsize=886432 CPUtime=1.48
/proc/14595/stat : 14595 (java) S 14582 14581 4778 34817 4778 4202496 21619 0 1 0 140 8 0 0 25 0 10 0 10743259 907706368 18261 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/14595/statm: 221608 18261 1724 10 0 218699 0
[pid=14595/tid=14596] ppid=14582 vsize=886432 CPUtime=0.79
/proc/14595/task/14596/stat : 14596 (java) R 14582 14581 4778 34817 4778 4202560 9857 0 1 0 76 3 0 0 25 0 10 0 10743260 907706368 18261 1283457024 134512640 134550932 4292794048 18446744073709551615 4153055528 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=14595/tid=14597] ppid=14582 vsize=886432 CPUtime=0
/proc/14595/task/14597/stat : 14597 (java) S 14582 14581 4778 34817 4778 4202560 7 0 0 0 0 0 0 0 17 0 10 0 10743261 907706368 18261 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 0 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14598] ppid=14582 vsize=886432 CPUtime=0
/proc/14595/task/14598/stat : 14598 (java) S 14582 14581 4778 34817 4778 4202560 8 0 0 0 0 0 0 0 25 0 10 0 10743262 907706368 18261 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14599] ppid=14582 vsize=886432 CPUtime=0
/proc/14595/task/14599/stat : 14599 (java) S 14582 14581 4778 34817 4778 4202560 4 0 0 0 0 0 0 0 25 0 10 0 10743262 907706368 18261 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14600] ppid=14582 vsize=886432 CPUtime=0
/proc/14595/task/14600/stat : 14600 (java) S 14582 14581 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 10 0 10743264 907706368 18261 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14601] ppid=14582 vsize=886432 CPUtime=0.44
/proc/14595/task/14601/stat : 14601 (java) R 14582 14581 4778 34817 4778 4202560 8676 0 0 0 42 2 0 0 25 0 10 0 10743264 907706368 18261 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=14595/tid=14602] ppid=14582 vsize=886432 CPUtime=0.23
/proc/14595/task/14602/stat : 14602 (java) S 14582 14581 4778 34817 4778 4202560 2006 0 0 0 21 2 0 0 22 0 10 0 10743264 907706368 18261 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14603] ppid=14582 vsize=886432 CPUtime=0
/proc/14595/task/14603/stat : 14603 (java) S 14582 14581 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 10 0 10743264 907706368 18261 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14604] ppid=14582 vsize=886432 CPUtime=0
/proc/14595/task/14604/stat : 14604 (java) S 14582 14581 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 10 0 10743264 907706368 18261 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.51
Current children cumulated vsize (KiB) 891572

[startup+3.10686 s]
/proc/loadavg: 1.12 1.04 1.04 3/45 14604
/proc/meminfo: memFree=254760/1048576 swapFree=0/0
[pid=14581] ppid=14580 vsize=2568 CPUtime=0
/proc/14581/stat : 14581 (p2cudf-paranoid) S 14580 14581 4778 34817 4778 4202496 375 0 0 0 0 0 0 0 24 0 1 0 10743256 2629632 270 1283457024 134512640 135304128 4287634224 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14581/statm: 642 270 230 194 0 29 0
[pid=14582] ppid=14581 vsize=2572 CPUtime=0.03
/proc/14582/stat : 14582 (p2cudf) S 14581 14581 4778 34817 4778 4202496 388 3015 0 1 0 0 3 0 25 0 1 0 10743256 2633728 279 1283457024 134512640 135304128 4291313344 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14582/statm: 643 279 239 194 0 30 0
[pid=14595] ppid=14582 vsize=884620 CPUtime=3.07
/proc/14595/stat : 14595 (java) S 14582 14581 4778 34817 4778 4202496 38536 0 1 0 294 13 0 0 25 0 11 0 10743259 905850880 33000 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/14595/statm: 221155 33000 1755 10 0 218246 0
[pid=14595/tid=14596] ppid=14582 vsize=884620 CPUtime=1.37
/proc/14595/task/14596/stat : 14596 (java) R 14582 14581 4778 34817 4778 4202560 24510 0 1 0 129 8 0 0 25 0 11 0 10743260 905850880 33000 1283457024 134512640 134550932 4292794048 18446744073709551615 4096027892 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=14595/tid=14597] ppid=14582 vsize=884620 CPUtime=0
/proc/14595/task/14597/stat : 14597 (java) S 14582 14581 4778 34817 4778 4202560 7 0 0 0 0 0 0 0 15 0 11 0 10743261 905850880 33000 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 0 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14598] ppid=14582 vsize=884620 CPUtime=0
/proc/14595/task/14598/stat : 14598 (java) S 14582 14581 4778 34817 4778 4202560 8 0 0 0 0 0 0 0 25 0 11 0 10743262 905850880 33000 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14599] ppid=14582 vsize=884620 CPUtime=0
/proc/14595/task/14599/stat : 14599 (java) S 14582 14581 4778 34817 4778 4202560 4 0 0 0 0 0 0 0 25 0 11 0 10743262 905850880 33000 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14600] ppid=14582 vsize=884620 CPUtime=0
/proc/14595/task/14600/stat : 14600 (java) S 14582 14581 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 11 0 10743264 905850880 33000 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14601] ppid=14582 vsize=884620 CPUtime=0.5
/proc/14595/task/14601/stat : 14601 (java) S 14582 14581 4778 34817 4778 4202560 8737 0 0 0 48 2 0 0 25 0 11 0 10743264 905850880 33000 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14602] ppid=14582 vsize=884620 CPUtime=1.19
/proc/14595/task/14602/stat : 14602 (java) S 14582 14581 4778 34817 4778 4202560 4208 0 0 0 117 2 0 0 15 0 11 0 10743264 905850880 33000 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14603] ppid=14582 vsize=884620 CPUtime=0
/proc/14595/task/14603/stat : 14603 (java) S 14582 14581 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 11 0 10743264 905850880 33000 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14604] ppid=14582 vsize=884620 CPUtime=0
/proc/14595/task/14604/stat : 14604 (java) S 14582 14581 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 11 0 10743264 905850880 33000 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.1
Current children cumulated vsize (KiB) 889760

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

[startup+3.20688 s]
/proc/loadavg: 1.12 1.04 1.04 3/45 14604
/proc/meminfo: memFree=254760/1048576 swapFree=0/0
[pid=14581] ppid=14580 vsize=2568 CPUtime=0
/proc/14581/stat : 14581 (p2cudf-paranoid) S 14580 14581 4778 34817 4778 4202496 375 0 0 0 0 0 0 0 24 0 1 0 10743256 2629632 270 1283457024 134512640 135304128 4287634224 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14581/statm: 642 270 230 194 0 29 0
[pid=14582] ppid=14581 vsize=2572 CPUtime=0.03
/proc/14582/stat : 14582 (p2cudf) S 14581 14581 4778 34817 4778 4202496 388 3015 0 1 0 0 3 0 25 0 1 0 10743256 2633728 279 1283457024 134512640 135304128 4291313344 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14582/statm: 643 279 239 194 0 30 0
[pid=14595] ppid=14582 vsize=884620 CPUtime=3.17
/proc/14595/stat : 14595 (java) S 14582 14581 4778 34817 4778 4202496 38647 0 1 0 304 13 0 0 25 0 11 0 10743259 905850880 33111 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/14595/statm: 221155 33111 1759 10 0 218246 0
[pid=14595/tid=14596] ppid=14582 vsize=884620 CPUtime=1.4
/proc/14595/task/14596/stat : 14596 (java) R 14582 14581 4778 34817 4778 4202560 24608 0 1 0 132 8 0 0 25 0 11 0 10743260 905850880 33111 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=14595/tid=14597] ppid=14582 vsize=884620 CPUtime=0
/proc/14595/task/14597/stat : 14597 (java) S 14582 14581 4778 34817 4778 4202560 7 0 0 0 0 0 0 0 15 0 11 0 10743261 905850880 33111 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 0 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14598] ppid=14582 vsize=884620 CPUtime=0
/proc/14595/task/14598/stat : 14598 (java) S 14582 14581 4778 34817 4778 4202560 8 0 0 0 0 0 0 0 25 0 11 0 10743262 905850880 33111 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14599] ppid=14582 vsize=884620 CPUtime=0
/proc/14595/task/14599/stat : 14599 (java) S 14582 14581 4778 34817 4778 4202560 4 0 0 0 0 0 0 0 25 0 11 0 10743262 905850880 33111 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14600] ppid=14582 vsize=884620 CPUtime=0
/proc/14595/task/14600/stat : 14600 (java) S 14582 14581 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 11 0 10743264 905850880 33111 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14601] ppid=14582 vsize=884620 CPUtime=0.5
/proc/14595/task/14601/stat : 14601 (java) S 14582 14581 4778 34817 4778 4202560 8737 0 0 0 48 2 0 0 25 0 11 0 10743264 905850880 33111 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14602] ppid=14582 vsize=884620 CPUtime=1.26
/proc/14595/task/14602/stat : 14602 (java) R 14582 14581 4778 34817 4778 4202560 4221 0 0 0 124 2 0 0 16 0 11 0 10743264 905850880 33111 1283457024 134512640 134550932 4292794048 18446744073709551615 4149020592 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=14595/tid=14603] ppid=14582 vsize=884620 CPUtime=0
/proc/14595/task/14603/stat : 14603 (java) S 14582 14581 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 11 0 10743264 905850880 33111 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14604] ppid=14582 vsize=884620 CPUtime=0
/proc/14595/task/14604/stat : 14604 (java) S 14582 14581 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 11 0 10743264 905850880 33111 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.2
Current children cumulated vsize (KiB) 889760

[startup+3.6062 s]
/proc/loadavg: 1.12 1.04 1.04 4/46 14605
/proc/meminfo: memFree=231572/1048576 swapFree=0/0
[pid=14581] ppid=14580 vsize=2568 CPUtime=0
/proc/14581/stat : 14581 (p2cudf-paranoid) S 14580 14581 4778 34817 4778 4202496 375 0 0 0 0 0 0 0 24 0 1 0 10743256 2629632 270 1283457024 134512640 135304128 4287634224 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14581/statm: 642 270 230 194 0 29 0
[pid=14582] ppid=14581 vsize=2572 CPUtime=0.03
/proc/14582/stat : 14582 (p2cudf) S 14581 14581 4778 34817 4778 4202496 388 3015 0 1 0 0 3 0 25 0 1 0 10743256 2633728 279 1283457024 134512640 135304128 4291313344 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14582/statm: 643 279 239 194 0 30 0
[pid=14595] ppid=14582 vsize=884944 CPUtime=3.28
/proc/14595/stat : 14595 (java) S 14582 14581 4778 34817 4778 4202496 38744 0 1 0 315 13 0 0 25 0 11 0 10743259 906182656 33208 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/14595/statm: 221236 33208 1763 10 0 218327 0
[pid=14595/tid=14596] ppid=14582 vsize=884944 CPUtime=1.42
/proc/14595/task/14596/stat : 14596 (java) S 14582 14581 4778 34817 4778 4202560 24683 0 1 0 134 8 0 0 25 0 11 0 10743260 906182656 33208 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14597] ppid=14582 vsize=884944 CPUtime=0
/proc/14595/task/14597/stat : 14597 (java) S 14582 14581 4778 34817 4778 4202560 7 0 0 0 0 0 0 0 15 0 11 0 10743261 906182656 33208 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 0 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14598] ppid=14582 vsize=884944 CPUtime=0
/proc/14595/task/14598/stat : 14598 (java) S 14582 14581 4778 34817 4778 4202560 8 0 0 0 0 0 0 0 25 0 11 0 10743262 906182656 33208 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14599] ppid=14582 vsize=884944 CPUtime=0
/proc/14595/task/14599/stat : 14599 (java) S 14582 14581 4778 34817 4778 4202560 4 0 0 0 0 0 0 0 25 0 11 0 10743262 906182656 33208 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14600] ppid=14582 vsize=884944 CPUtime=0
/proc/14595/task/14600/stat : 14600 (java) S 14582 14581 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 11 0 10743264 906182656 33208 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14601] ppid=14582 vsize=884944 CPUtime=0.5
/proc/14595/task/14601/stat : 14601 (java) S 14582 14581 4778 34817 4778 4202560 8737 0 0 0 48 2 0 0 25 0 11 0 10743264 906182656 33208 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14602] ppid=14582 vsize=884944 CPUtime=1.34
/proc/14595/task/14602/stat : 14602 (java) S 14582 14581 4778 34817 4778 4202560 4235 0 0 0 132 2 0 0 15 0 11 0 10743264 906182656 33208 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14603] ppid=14582 vsize=884944 CPUtime=0
/proc/14595/task/14603/stat : 14603 (java) S 14582 14581 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 11 0 10743264 906182656 33208 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14604] ppid=14582 vsize=884944 CPUtime=0
/proc/14595/task/14604/stat : 14604 (java) S 14582 14581 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 11 0 10743264 906182656 33208 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.31
Current children cumulated vsize (KiB) 890084

[startup+3.80628 s]
/proc/loadavg: 1.12 1.04 1.04 4/46 14605
/proc/meminfo: memFree=231572/1048576 swapFree=0/0
[pid=14581] ppid=14580 vsize=2568 CPUtime=0
/proc/14581/stat : 14581 (p2cudf-paranoid) S 14580 14581 4778 34817 4778 4202496 375 0 0 0 0 0 0 0 24 0 1 0 10743256 2629632 270 1283457024 134512640 135304128 4287634224 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14581/statm: 642 270 230 194 0 29 0
[pid=14582] ppid=14581 vsize=2572 CPUtime=0.03
/proc/14582/stat : 14582 (p2cudf) S 14581 14581 4778 34817 4778 4202496 388 3015 0 1 0 0 3 0 25 0 1 0 10743256 2633728 279 1283457024 134512640 135304128 4291313344 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14582/statm: 643 279 239 194 0 30 0
[pid=14595] ppid=14582 vsize=884944 CPUtime=3.28
/proc/14595/stat : 14595 (java) S 14582 14581 4778 34817 4778 4202496 38744 0 1 0 315 13 0 0 25 0 11 0 10743259 906182656 33208 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/14595/statm: 221236 33208 1763 10 0 218327 0
[pid=14595/tid=14596] ppid=14582 vsize=884944 CPUtime=1.42
/proc/14595/task/14596/stat : 14596 (java) S 14582 14581 4778 34817 4778 4202560 24683 0 1 0 134 8 0 0 25 0 11 0 10743260 906182656 33208 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14597] ppid=14582 vsize=884944 CPUtime=0
/proc/14595/task/14597/stat : 14597 (java) S 14582 14581 4778 34817 4778 4202560 7 0 0 0 0 0 0 0 15 0 11 0 10743261 906182656 33208 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 0 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14598] ppid=14582 vsize=884944 CPUtime=0
/proc/14595/task/14598/stat : 14598 (java) S 14582 14581 4778 34817 4778 4202560 8 0 0 0 0 0 0 0 25 0 11 0 10743262 906182656 33208 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14599] ppid=14582 vsize=884944 CPUtime=0
/proc/14595/task/14599/stat : 14599 (java) S 14582 14581 4778 34817 4778 4202560 4 0 0 0 0 0 0 0 25 0 11 0 10743262 906182656 33208 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14600] ppid=14582 vsize=884944 CPUtime=0
/proc/14595/task/14600/stat : 14600 (java) S 14582 14581 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 11 0 10743264 906182656 33208 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14601] ppid=14582 vsize=884944 CPUtime=0.5
/proc/14595/task/14601/stat : 14601 (java) S 14582 14581 4778 34817 4778 4202560 8737 0 0 0 48 2 0 0 25 0 11 0 10743264 906182656 33208 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14602] ppid=14582 vsize=884944 CPUtime=1.34
/proc/14595/task/14602/stat : 14602 (java) S 14582 14581 4778 34817 4778 4202560 4235 0 0 0 132 2 0 0 15 0 11 0 10743264 906182656 33208 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14603] ppid=14582 vsize=884944 CPUtime=0
/proc/14595/task/14603/stat : 14603 (java) S 14582 14581 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 11 0 10743264 906182656 33208 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14604] ppid=14582 vsize=884944 CPUtime=0
/proc/14595/task/14604/stat : 14604 (java) S 14582 14581 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 11 0 10743264 906182656 33208 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.31
Current children cumulated vsize (KiB) 890084

[startup+3.90627 s]
/proc/loadavg: 1.12 1.04 1.04 4/46 14605
/proc/meminfo: memFree=231572/1048576 swapFree=0/0
[pid=14581] ppid=14580 vsize=2568 CPUtime=0
/proc/14581/stat : 14581 (p2cudf-paranoid) S 14580 14581 4778 34817 4778 4202496 375 0 0 0 0 0 0 0 24 0 1 0 10743256 2629632 270 1283457024 134512640 135304128 4287634224 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14581/statm: 642 270 230 194 0 29 0
[pid=14582] ppid=14581 vsize=2572 CPUtime=0.03
/proc/14582/stat : 14582 (p2cudf) S 14581 14581 4778 34817 4778 4202496 388 3015 0 1 0 0 3 0 25 0 1 0 10743256 2633728 279 1283457024 134512640 135304128 4291313344 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14582/statm: 643 279 239 194 0 30 0
[pid=14595] ppid=14582 vsize=884944 CPUtime=3.34
/proc/14595/stat : 14595 (java) S 14582 14581 4778 34817 4778 4202496 38879 0 1 0 321 13 0 0 25 0 10 0 10743259 906182656 33343 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/14595/statm: 221236 33343 1763 10 0 218327 0
[pid=14595/tid=14596] ppid=14582 vsize=884944 CPUtime=1.42
/proc/14595/task/14596/stat : 14596 (java) S 14582 14581 4778 34817 4778 4202560 24683 0 1 0 134 8 0 0 20 0 10 0 10743260 906182656 33343 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14597] ppid=14582 vsize=884944 CPUtime=0
/proc/14595/task/14597/stat : 14597 (java) S 14582 14581 4778 34817 4778 4202560 7 0 0 0 0 0 0 0 16 0 10 0 10743261 906182656 33343 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 0 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14598] ppid=14582 vsize=884944 CPUtime=0
/proc/14595/task/14598/stat : 14598 (java) S 14582 14581 4778 34817 4778 4202560 8 0 0 0 0 0 0 0 25 0 10 0 10743262 906182656 33343 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14599] ppid=14582 vsize=884944 CPUtime=0
/proc/14595/task/14599/stat : 14599 (java) S 14582 14581 4778 34817 4778 4202560 4 0 0 0 0 0 0 0 25 0 10 0 10743262 906182656 33343 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14600] ppid=14582 vsize=884944 CPUtime=0
/proc/14595/task/14600/stat : 14600 (java) S 14582 14581 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 10 0 10743264 906182656 33343 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14601] ppid=14582 vsize=884944 CPUtime=0.5
/proc/14595/task/14601/stat : 14601 (java) S 14582 14581 4778 34817 4778 4202560 8737 0 0 0 48 2 0 0 25 0 10 0 10743264 906182656 33343 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14602] ppid=14582 vsize=884944 CPUtime=1.35
/proc/14595/task/14602/stat : 14602 (java) S 14582 14581 4778 34817 4778 4202560 4236 0 0 0 133 2 0 0 16 0 10 0 10743264 906182656 33343 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14603] ppid=14582 vsize=884944 CPUtime=0
/proc/14595/task/14603/stat : 14603 (java) S 14582 14581 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 10 0 10743264 906182656 33343 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
[pid=14595/tid=14604] ppid=14582 vsize=884944 CPUtime=0
/proc/14595/task/14604/stat : 14604 (java) S 14582 14581 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 10 0 10743264 906182656 33343 1283457024 134512640 134550932 4292794048 18446744073709551615 4294960130 0 4 0 16800975 18446612133155121344 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.37
Current children cumulated vsize (KiB) 890084

Child status: 0
Real time (s): 3.9309
CPU time (s): 3.39221
CPU user time (s): 3.2442
CPU system time (s): 0.148009
CPU usage (%): 86.2961
Max. virtual memory (cumulated for all children) (KiB): 891572

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 3.2442
system time used= 0.148009
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 42682
page faults= 2
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 525
involuntary context switches= 499

runsolver used 0 second user time and 0 second system time

The end