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/rand512.cudf.dudf-random.log.runsolver ./p2cudf-paranoid-1.13 /home/misc2010/data/2011/dudf-random//rand512.cudf /home/misc2010/tmp/201108251442/p2cudf-paranoid-1.13/rand512.cudf.dudf-random.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.39 1.31 1.13 5/35 19317
/proc/meminfo: memFree=290392/1048576 swapFree=0/0
[pid=19315] ppid=19314 vsize=2572 CPUtime=0
/proc/19315/stat : 19315 (p2cudf-paranoid) S 19314 19315 4778 34817 4778 4202496 376 0 0 0 0 0 0 0 18 0 1 0 11112881 2633728 271 1283457024 134512640 135304128 4291282592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/19315/statm: 643 271 230 194 0 30 0
[pid=19316] ppid=19315 vsize=2564 CPUtime=0
/proc/19316/stat : 19316 (p2cudf) R 19315 19315 4778 34817 4778 4202496 345 0 0 0 0 0 0 0 25 0 1 0 11112882 2625536 270 1283457024 134512640 135304128 4289842512 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/19316/statm: 641 270 231 194 0 28 0
[pid=19317] ppid=19316 vsize=2564 CPUtime=0
/proc/19317/stat : 19317 (p2cudf) R 19316 19315 4778 34817 4778 4202560 0 0 0 0 0 0 0 0 25 0 1 0 11112882 2625536 39 1283457024 134512640 135304128 4289842512 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/19317/statm: 641 39 0 194 0 28 0

[startup+0.125792 s]
/proc/loadavg: 1.39 1.31 1.13 5/35 19317
/proc/meminfo: memFree=290392/1048576 swapFree=0/0
[pid=19315] ppid=19314 vsize=2572 CPUtime=0
/proc/19315/stat : 19315 (p2cudf-paranoid) S 19314 19315 4778 34817 4778 4202496 376 0 0 0 0 0 0 0 18 0 1 0 11112881 2633728 271 1283457024 134512640 135304128 4291282592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/19315/statm: 643 271 230 194 0 30 0
[pid=19316] ppid=19315 vsize=2568 CPUtime=0.02
/proc/19316/stat : 19316 (p2cudf) S 19315 19315 4778 34817 4778 4202496 389 3013 0 1 0 0 1 1 25 0 1 0 11112882 2629632 279 1283457024 134512640 135304128 4289842512 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/19316/statm: 642 279 239 194 0 29 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5140

[startup+0.205794 s]
/proc/loadavg: 1.39 1.31 1.13 5/35 19317
/proc/meminfo: memFree=290392/1048576 swapFree=0/0
[pid=19315] ppid=19314 vsize=2572 CPUtime=0
/proc/19315/stat : 19315 (p2cudf-paranoid) S 19314 19315 4778 34817 4778 4202496 376 0 0 0 0 0 0 0 18 0 1 0 11112881 2633728 271 1283457024 134512640 135304128 4291282592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/19315/statm: 643 271 230 194 0 30 0
[pid=19316] ppid=19315 vsize=2568 CPUtime=0.02
/proc/19316/stat : 19316 (p2cudf) S 19315 19315 4778 34817 4778 4202496 389 3013 0 1 0 0 1 1 25 0 1 0 11112882 2629632 279 1283457024 134512640 135304128 4289842512 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/19316/statm: 642 279 239 194 0 29 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5140

[startup+0.315806 s]
/proc/loadavg: 1.39 1.31 1.13 5/35 19317
/proc/meminfo: memFree=290392/1048576 swapFree=0/0
[pid=19315] ppid=19314 vsize=2572 CPUtime=0
/proc/19315/stat : 19315 (p2cudf-paranoid) S 19314 19315 4778 34817 4778 4202496 376 0 0 0 0 0 0 0 18 0 1 0 11112881 2633728 271 1283457024 134512640 135304128 4291282592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/19315/statm: 643 271 230 194 0 30 0
[pid=19316] ppid=19315 vsize=2568 CPUtime=0.02
/proc/19316/stat : 19316 (p2cudf) S 19315 19315 4778 34817 4778 4202496 389 3013 0 1 0 0 1 1 25 0 1 0 11112882 2629632 279 1283457024 134512640 135304128 4289842512 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/19316/statm: 642 279 239 194 0 29 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5140

[startup+0.705893 s]
/proc/loadavg: 1.39 1.31 1.13 5/35 19317
/proc/meminfo: memFree=290392/1048576 swapFree=0/0
[pid=19315] ppid=19314 vsize=2572 CPUtime=0
/proc/19315/stat : 19315 (p2cudf-paranoid) S 19314 19315 4778 34817 4778 4202496 376 0 0 0 0 0 0 0 18 0 1 0 11112881 2633728 271 1283457024 134512640 135304128 4291282592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/19315/statm: 643 271 230 194 0 30 0
[pid=19316] ppid=19315 vsize=2568 CPUtime=0.02
/proc/19316/stat : 19316 (p2cudf) S 19315 19315 4778 34817 4778 4202496 389 3013 0 1 0 0 1 1 25 0 1 0 11112882 2629632 279 1283457024 134512640 135304128 4289842512 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/19316/statm: 642 279 239 194 0 29 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 5140

[startup+1.50602 s]
/proc/loadavg: 1.39 1.31 1.13 5/45 19338
/proc/meminfo: memFree=249320/1048576 swapFree=0/0
[pid=19315] ppid=19314 vsize=2572 CPUtime=0
/proc/19315/stat : 19315 (p2cudf-paranoid) S 19314 19315 4778 34817 4778 4202496 376 0 0 0 0 0 0 0 18 0 1 0 11112881 2633728 271 1283457024 134512640 135304128 4291282592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/19315/statm: 643 271 230 194 0 30 0
[pid=19316] ppid=19315 vsize=2568 CPUtime=0.02
/proc/19316/stat : 19316 (p2cudf) S 19315 19315 4778 34817 4778 4202496 389 3013 0 1 0 0 1 1 25 0 1 0 11112882 2629632 279 1283457024 134512640 135304128 4289842512 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/19316/statm: 642 279 239 194 0 29 0
[pid=19329] ppid=19316 vsize=884824 CPUtime=1.48
/proc/19329/stat : 19329 (java) S 19316 19315 4778 34817 4778 4202496 21193 0 1 0 142 6 0 0 25 0 10 0 11112885 906059776 17801 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/19329/statm: 221206 17801 1721 10 0 218297 0
[pid=19329/tid=19330] ppid=19316 vsize=884824 CPUtime=0.79
/proc/19329/task/19330/stat : 19330 (java) R 19316 19315 4778 34817 4778 4202560 9763 0 1 0 77 2 0 0 25 0 10 0 11112886 906059776 17801 1283457024 134512640 134550932 4288811760 18446744073709551615 4094909374 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=19329/tid=19331] ppid=19316 vsize=884824 CPUtime=0
/proc/19329/task/19331/stat : 19331 (java) S 19316 19315 4778 34817 4778 4202560 6 0 0 0 0 0 0 0 16 0 10 0 11112887 906059776 17801 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 0 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19332] ppid=19316 vsize=884824 CPUtime=0
/proc/19329/task/19332/stat : 19332 (java) S 19316 19315 4778 34817 4778 4202560 8 0 0 0 0 0 0 0 25 0 10 0 11112888 906059776 17801 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19333] ppid=19316 vsize=884824 CPUtime=0
/proc/19329/task/19333/stat : 19333 (java) S 19316 19315 4778 34817 4778 4202560 4 0 0 0 0 0 0 0 25 0 10 0 11112888 906059776 17801 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19334] ppid=19316 vsize=884824 CPUtime=0
/proc/19329/task/19334/stat : 19334 (java) S 19316 19315 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 10 0 11112890 906059776 17801 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19335] ppid=19316 vsize=884824 CPUtime=0.32
/proc/19329/task/19335/stat : 19335 (java) R 19316 19315 4778 34817 4778 4202560 5371 0 0 0 30 2 0 0 18 0 10 0 11112890 906059776 17801 1283457024 134512640 134550932 4288811760 18446744073709551615 4148542720 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=19329/tid=19336] ppid=19316 vsize=884824 CPUtime=0.34
/proc/19329/task/19336/stat : 19336 (java) R 19316 19315 4778 34817 4778 4202560 4978 0 0 0 34 0 0 0 25 0 10 0 11112890 906059776 17801 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=19329/tid=19337] ppid=19316 vsize=884824 CPUtime=0
/proc/19329/task/19337/stat : 19337 (java) S 19316 19315 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 10 0 11112890 906059776 17801 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19338] ppid=19316 vsize=884824 CPUtime=0
/proc/19329/task/19338/stat : 19338 (java) S 19316 19315 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 10 0 11112890 906059776 17801 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 889964

[startup+3.10623 s]
/proc/loadavg: 1.39 1.31 1.13 2/45 19338
/proc/meminfo: memFree=136108/1048576 swapFree=0/0
[pid=19315] ppid=19314 vsize=2572 CPUtime=0
/proc/19315/stat : 19315 (p2cudf-paranoid) S 19314 19315 4778 34817 4778 4202496 376 0 0 0 0 0 0 0 18 0 1 0 11112881 2633728 271 1283457024 134512640 135304128 4291282592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/19315/statm: 643 271 230 194 0 30 0
[pid=19316] ppid=19315 vsize=2568 CPUtime=0.02
/proc/19316/stat : 19316 (p2cudf) S 19315 19315 4778 34817 4778 4202496 389 3013 0 1 0 0 1 1 25 0 1 0 11112882 2629632 279 1283457024 134512640 135304128 4289842512 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/19316/statm: 642 279 239 194 0 29 0
[pid=19329] ppid=19316 vsize=884616 CPUtime=3.08
/proc/19329/stat : 19329 (java) S 19316 19315 4778 34817 4778 4202496 54777 0 1 0 290 18 0 0 25 0 10 0 11112885 905846784 50526 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/19329/statm: 221154 50526 1744 10 0 218245 0
[pid=19329/tid=19330] ppid=19316 vsize=884616 CPUtime=1.6
/proc/19329/task/19330/stat : 19330 (java) R 19316 19315 4778 34817 4778 4202560 42037 0 1 0 146 14 0 0 25 0 10 0 11112886 905846784 50526 1283457024 134512640 134550932 4288811760 18446744073709551615 4151708352 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=19329/tid=19331] ppid=19316 vsize=884616 CPUtime=0
/proc/19329/task/19331/stat : 19331 (java) S 19316 19315 4778 34817 4778 4202560 6 0 0 0 0 0 0 0 16 0 10 0 11112887 905846784 50526 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 0 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19332] ppid=19316 vsize=884616 CPUtime=0
/proc/19329/task/19332/stat : 19332 (java) S 19316 19315 4778 34817 4778 4202560 8 0 0 0 0 0 0 0 25 0 10 0 11112888 905846784 50526 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19333] ppid=19316 vsize=884616 CPUtime=0
/proc/19329/task/19333/stat : 19333 (java) S 19316 19315 4778 34817 4778 4202560 4 0 0 0 0 0 0 0 25 0 10 0 11112888 905846784 50526 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19334] ppid=19316 vsize=884616 CPUtime=0
/proc/19329/task/19334/stat : 19334 (java) S 19316 19315 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 10 0 11112890 905846784 50526 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19335] ppid=19316 vsize=884616 CPUtime=0.92
/proc/19329/task/19335/stat : 19335 (java) S 19316 19315 4778 34817 4778 4202560 6636 0 0 0 90 2 0 0 16 0 10 0 11112890 905846784 50526 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19336] ppid=19316 vsize=884616 CPUtime=0.53
/proc/19329/task/19336/stat : 19336 (java) S 19316 19315 4778 34817 4778 4202560 5023 0 0 0 53 0 0 0 21 0 10 0 11112890 905846784 50526 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19337] ppid=19316 vsize=884616 CPUtime=0
/proc/19329/task/19337/stat : 19337 (java) S 19316 19315 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 10 0 11112890 905846784 50526 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19338] ppid=19316 vsize=884616 CPUtime=0
/proc/19329/task/19338/stat : 19338 (java) S 19316 19315 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 10 0 11112890 905846784 50526 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.1
Current children cumulated vsize (KiB) 889756

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

[startup+3.20624 s]
/proc/loadavg: 1.39 1.31 1.13 2/45 19338
/proc/meminfo: memFree=136108/1048576 swapFree=0/0
[pid=19315] ppid=19314 vsize=2572 CPUtime=0
/proc/19315/stat : 19315 (p2cudf-paranoid) S 19314 19315 4778 34817 4778 4202496 376 0 0 0 0 0 0 0 18 0 1 0 11112881 2633728 271 1283457024 134512640 135304128 4291282592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/19315/statm: 643 271 230 194 0 30 0
[pid=19316] ppid=19315 vsize=2568 CPUtime=0.02
/proc/19316/stat : 19316 (p2cudf) S 19315 19315 4778 34817 4778 4202496 389 3013 0 1 0 0 1 1 25 0 1 0 11112882 2629632 279 1283457024 134512640 135304128 4289842512 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/19316/statm: 642 279 239 194 0 29 0
[pid=19329] ppid=19316 vsize=884616 CPUtime=3.18
/proc/19329/stat : 19329 (java) S 19316 19315 4778 34817 4778 4202496 55688 0 1 0 300 18 0 0 25 0 10 0 11112885 905846784 51437 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/19329/statm: 221154 51437 1744 10 0 218245 0
[pid=19329/tid=19330] ppid=19316 vsize=884616 CPUtime=1.64
/proc/19329/task/19330/stat : 19330 (java) R 19316 19315 4778 34817 4778 4202560 42945 0 1 0 150 14 0 0 25 0 10 0 11112886 905846784 51437 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=19329/tid=19331] ppid=19316 vsize=884616 CPUtime=0
/proc/19329/task/19331/stat : 19331 (java) S 19316 19315 4778 34817 4778 4202560 6 0 0 0 0 0 0 0 16 0 10 0 11112887 905846784 51437 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 0 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19332] ppid=19316 vsize=884616 CPUtime=0
/proc/19329/task/19332/stat : 19332 (java) S 19316 19315 4778 34817 4778 4202560 8 0 0 0 0 0 0 0 25 0 10 0 11112888 905846784 51437 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19333] ppid=19316 vsize=884616 CPUtime=0
/proc/19329/task/19333/stat : 19333 (java) S 19316 19315 4778 34817 4778 4202560 4 0 0 0 0 0 0 0 25 0 10 0 11112888 905846784 51437 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19334] ppid=19316 vsize=884616 CPUtime=0
/proc/19329/task/19334/stat : 19334 (java) S 19316 19315 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 10 0 11112890 905846784 51437 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19335] ppid=19316 vsize=884616 CPUtime=0.92
/proc/19329/task/19335/stat : 19335 (java) S 19316 19315 4778 34817 4778 4202560 6636 0 0 0 90 2 0 0 16 0 10 0 11112890 905846784 51437 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19336] ppid=19316 vsize=884616 CPUtime=0.6
/proc/19329/task/19336/stat : 19336 (java) R 19316 19315 4778 34817 4778 4202560 5026 0 0 0 60 0 0 0 20 0 10 0 11112890 905846784 51437 1283457024 134512640 134550932 4288811760 18446744073709551615 4148849649 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=19329/tid=19337] ppid=19316 vsize=884616 CPUtime=0
/proc/19329/task/19337/stat : 19337 (java) S 19316 19315 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 10 0 11112890 905846784 51437 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19338] ppid=19316 vsize=884616 CPUtime=0
/proc/19329/task/19338/stat : 19338 (java) S 19316 19315 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 10 0 11112890 905846784 51437 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.2
Current children cumulated vsize (KiB) 889756

[startup+4.00601 s]
/proc/loadavg: 1.44 1.32 1.13 3/45 19338
/proc/meminfo: memFree=85764/1048576 swapFree=0/0
[pid=19315] ppid=19314 vsize=2572 CPUtime=0
/proc/19315/stat : 19315 (p2cudf-paranoid) S 19314 19315 4778 34817 4778 4202496 376 0 0 0 0 0 0 0 18 0 1 0 11112881 2633728 271 1283457024 134512640 135304128 4291282592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/19315/statm: 643 271 230 194 0 30 0
[pid=19316] ppid=19315 vsize=2568 CPUtime=0.02
/proc/19316/stat : 19316 (p2cudf) S 19315 19315 4778 34817 4778 4202496 389 3013 0 1 0 0 1 1 25 0 1 0 11112882 2629632 279 1283457024 134512640 135304128 4289842512 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/19316/statm: 642 279 239 194 0 29 0
[pid=19329] ppid=19316 vsize=885264 CPUtime=3.9
/proc/19329/stat : 19329 (java) S 19316 19315 4778 34817 4778 4202496 60318 0 1 0 372 18 0 0 25 0 11 0 11112885 906510336 56067 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/19329/statm: 221316 56067 1763 10 0 218407 0
[pid=19329/tid=19330] ppid=19316 vsize=885264 CPUtime=1.96
/proc/19329/task/19330/stat : 19330 (java) S 19316 19315 4778 34817 4778 4202560 47504 0 1 0 182 14 0 0 25 0 11 0 11112886 906510336 56067 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19331] ppid=19316 vsize=885264 CPUtime=0
/proc/19329/task/19331/stat : 19331 (java) S 19316 19315 4778 34817 4778 4202560 6 0 0 0 0 0 0 0 16 0 11 0 11112887 906510336 56067 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 0 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19332] ppid=19316 vsize=885264 CPUtime=0
/proc/19329/task/19332/stat : 19332 (java) S 19316 19315 4778 34817 4778 4202560 8 0 0 0 0 0 0 0 25 0 11 0 11112888 906510336 56067 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19333] ppid=19316 vsize=885264 CPUtime=0
/proc/19329/task/19333/stat : 19333 (java) S 19316 19315 4778 34817 4778 4202560 4 0 0 0 0 0 0 0 25 0 11 0 11112888 906510336 56067 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19334] ppid=19316 vsize=885264 CPUtime=0
/proc/19329/task/19334/stat : 19334 (java) S 19316 19315 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 11 0 11112890 906510336 56067 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19335] ppid=19316 vsize=885264 CPUtime=1.16
/proc/19329/task/19335/stat : 19335 (java) S 19316 19315 4778 34817 4778 4202560 6666 0 0 0 114 2 0 0 15 0 11 0 11112890 906510336 56067 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19336] ppid=19316 vsize=885264 CPUtime=0.75
/proc/19329/task/19336/stat : 19336 (java) S 19316 19315 4778 34817 4778 4202560 5057 0 0 0 75 0 0 0 19 0 11 0 11112890 906510336 56067 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19337] ppid=19316 vsize=885264 CPUtime=0
/proc/19329/task/19337/stat : 19337 (java) S 19316 19315 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 11 0 11112890 906510336 56067 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19338] ppid=19316 vsize=885264 CPUtime=0
/proc/19329/task/19338/stat : 19338 (java) S 19316 19315 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 11 0 11112890 906510336 56067 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.92
Current children cumulated vsize (KiB) 890404

[startup+4.40607 s]
/proc/loadavg: 1.44 1.32 1.13 1/46 19340
/proc/meminfo: memFree=72240/1048576 swapFree=0/0
[pid=19315] ppid=19314 vsize=2572 CPUtime=0
/proc/19315/stat : 19315 (p2cudf-paranoid) S 19314 19315 4778 34817 4778 4202496 376 0 0 0 0 0 0 0 18 0 1 0 11112881 2633728 271 1283457024 134512640 135304128 4291282592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/19315/statm: 643 271 230 194 0 30 0
[pid=19316] ppid=19315 vsize=2568 CPUtime=0.02
/proc/19316/stat : 19316 (p2cudf) S 19315 19315 4778 34817 4778 4202496 389 3013 0 1 0 0 1 1 25 0 1 0 11112882 2629632 279 1283457024 134512640 135304128 4289842512 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/19316/statm: 642 279 239 194 0 29 0
[pid=19329] ppid=19316 vsize=885264 CPUtime=3.9
/proc/19329/stat : 19329 (java) S 19316 19315 4778 34817 4778 4202496 60318 0 1 0 372 18 0 0 25 0 11 0 11112885 906510336 56067 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/19329/statm: 221316 56067 1763 10 0 218407 0
[pid=19329/tid=19330] ppid=19316 vsize=885264 CPUtime=1.96
/proc/19329/task/19330/stat : 19330 (java) S 19316 19315 4778 34817 4778 4202560 47504 0 1 0 182 14 0 0 25 0 11 0 11112886 906510336 56067 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19331] ppid=19316 vsize=885264 CPUtime=0
/proc/19329/task/19331/stat : 19331 (java) S 19316 19315 4778 34817 4778 4202560 6 0 0 0 0 0 0 0 16 0 11 0 11112887 906510336 56067 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 0 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19332] ppid=19316 vsize=885264 CPUtime=0
/proc/19329/task/19332/stat : 19332 (java) S 19316 19315 4778 34817 4778 4202560 8 0 0 0 0 0 0 0 25 0 11 0 11112888 906510336 56067 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19333] ppid=19316 vsize=885264 CPUtime=0
/proc/19329/task/19333/stat : 19333 (java) S 19316 19315 4778 34817 4778 4202560 4 0 0 0 0 0 0 0 25 0 11 0 11112888 906510336 56067 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19334] ppid=19316 vsize=885264 CPUtime=0
/proc/19329/task/19334/stat : 19334 (java) S 19316 19315 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 11 0 11112890 906510336 56067 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19335] ppid=19316 vsize=885264 CPUtime=1.16
/proc/19329/task/19335/stat : 19335 (java) S 19316 19315 4778 34817 4778 4202560 6666 0 0 0 114 2 0 0 15 0 11 0 11112890 906510336 56067 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19336] ppid=19316 vsize=885264 CPUtime=0.75
/proc/19329/task/19336/stat : 19336 (java) S 19316 19315 4778 34817 4778 4202560 5057 0 0 0 75 0 0 0 19 0 11 0 11112890 906510336 56067 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19337] ppid=19316 vsize=885264 CPUtime=0
/proc/19329/task/19337/stat : 19337 (java) S 19316 19315 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 11 0 11112890 906510336 56067 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19338] ppid=19316 vsize=885264 CPUtime=0
/proc/19329/task/19338/stat : 19338 (java) S 19316 19315 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 11 0 11112890 906510336 56067 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19340] ppid=19316 vsize=885264 CPUtime=0
/proc/19329/task/19340/stat : 19340 (java) S 19316 19315 4778 34817 4778 4202560 5 0 0 0 0 0 0 0 25 0 11 0 11113275 906510336 56067 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.92
Current children cumulated vsize (KiB) 890404

[startup+4.60612 s]
/proc/loadavg: 1.44 1.32 1.13 1/46 19340
/proc/meminfo: memFree=72240/1048576 swapFree=0/0
[pid=19315] ppid=19314 vsize=2572 CPUtime=0
/proc/19315/stat : 19315 (p2cudf-paranoid) S 19314 19315 4778 34817 4778 4202496 376 0 0 0 0 0 0 0 18 0 1 0 11112881 2633728 271 1283457024 134512640 135304128 4291282592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/19315/statm: 643 271 230 194 0 30 0
[pid=19316] ppid=19315 vsize=2568 CPUtime=0.02
/proc/19316/stat : 19316 (p2cudf) S 19315 19315 4778 34817 4778 4202496 389 3013 0 1 0 0 1 1 25 0 1 0 11112882 2629632 279 1283457024 134512640 135304128 4289842512 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/19316/statm: 642 279 239 194 0 29 0
[pid=19329] ppid=19316 vsize=885264 CPUtime=4.06
/proc/19329/stat : 19329 (java) S 19316 19315 4778 34817 4778 4202496 60579 0 1 0 383 23 0 0 25 0 11 0 11112885 906510336 56328 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/19329/statm: 221316 56328 1765 10 0 218407 0
[pid=19329/tid=19330] ppid=19316 vsize=885264 CPUtime=1.96
/proc/19329/task/19330/stat : 19330 (java) S 19316 19315 4778 34817 4778 4202560 47504 0 1 0 182 14 0 0 25 0 11 0 11112886 906510336 56328 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19331] ppid=19316 vsize=885264 CPUtime=0
/proc/19329/task/19331/stat : 19331 (java) S 19316 19315 4778 34817 4778 4202560 6 0 0 0 0 0 0 0 16 0 11 0 11112887 906510336 56328 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 0 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19332] ppid=19316 vsize=885264 CPUtime=0
/proc/19329/task/19332/stat : 19332 (java) S 19316 19315 4778 34817 4778 4202560 8 0 0 0 0 0 0 0 25 0 11 0 11112888 906510336 56328 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19333] ppid=19316 vsize=885264 CPUtime=0
/proc/19329/task/19333/stat : 19333 (java) S 19316 19315 4778 34817 4778 4202560 4 0 0 0 0 0 0 0 25 0 11 0 11112888 906510336 56328 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19334] ppid=19316 vsize=885264 CPUtime=0
/proc/19329/task/19334/stat : 19334 (java) S 19316 19315 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 11 0 11112890 906510336 56328 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19335] ppid=19316 vsize=885264 CPUtime=1.16
/proc/19329/task/19335/stat : 19335 (java) S 19316 19315 4778 34817 4778 4202560 6666 0 0 0 114 2 0 0 15 0 11 0 11112890 906510336 56328 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19336] ppid=19316 vsize=885264 CPUtime=0.8
/proc/19329/task/19336/stat : 19336 (java) S 19316 19315 4778 34817 4778 4202560 5068 0 0 0 80 0 0 0 16 0 11 0 11112890 906510336 56328 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19337] ppid=19316 vsize=885264 CPUtime=0
/proc/19329/task/19337/stat : 19337 (java) S 19316 19315 4778 34817 4778 4202560 1 0 0 0 0 0 0 0 25 0 11 0 11112890 906510336 56328 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19338] ppid=19316 vsize=885264 CPUtime=0
/proc/19329/task/19338/stat : 19338 (java) S 19316 19315 4778 34817 4778 4202560 2 0 0 0 0 0 0 0 15 0 11 0 11112890 906510336 56328 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 18446612133155122240 0 0 -1 0 0 0 0
[pid=19329/tid=19340] ppid=19316 vsize=885264 CPUtime=0.1
/proc/19329/task/19340/stat : 19340 (java) R 19316 19315 4778 34817 4778 4202560 255 0 0 0 6 4 0 0 20 0 11 0 11113275 906510336 56328 1283457024 134512640 134550932 4288811760 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.08
Current children cumulated vsize (KiB) 890404

Child status: 0
Real time (s): 4.62838
CPU time (s): 4.11226
CPU user time (s): 3.85224
CPU system time (s): 0.260016
CPU usage (%): 88.8486
Max. virtual memory (cumulated for all children) (KiB): 891108

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 3.85224
system time used= 0.260016
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 64395
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= 583
involuntary context switches= 568

runsolver used 0 second user time and 0 second system time

The end