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/p2cudf-user-1.13/3e4f8550-0b33-11df-942d-00163e1d94dc.cudf.dudf-real.log.runsolver ./p2cudf-user-1.13 /home/misc2010/data/2011/dudf-real//3e4f8550-0b33-11df-942d-00163e1d94dc.cudf /home/misc2010/tmp/201108291842/p2cudf-user-1.13/3e4f8550-0b33-11df-942d-00163e1d94dc.cudf.dudf-real.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.47 1.28 1.15 5/35 22303
/proc/meminfo: memFree=282260/1048576 swapFree=0/0
[pid=22302] ppid=22301 vsize=2568 CPUtime=0
/proc/22302/stat : 22302 (p2cudf-user-1.1) R 22301 22302 17511 34816 17511 4202496 357 0 0 0 0 0 0 0 25 0 1 0 46235899 2629632 271 1283457024 134512640 135304128 4290954736 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/22302/statm: 642 271 230 194 0 29 0
[pid=22303] ppid=22302 vsize=2568 CPUtime=0
/proc/22303/stat : 22303 (p2cudf-user-1.1) R 22302 22302 17511 34816 17511 4202560 0 0 0 0 0 0 0 0 25 0 1 0 46235899 2629632 41 1283457024 134512640 135304128 4290954736 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/22303/statm: 642 41 0 194 0 29 0

[startup+0.164439 s]
/proc/loadavg: 1.47 1.28 1.15 5/35 22303
/proc/meminfo: memFree=282260/1048576 swapFree=0/0
[pid=22302] ppid=22301 vsize=2568 CPUtime=0
/proc/22302/stat : 22302 (p2cudf-user-1.1) S 22301 22302 17511 34816 17511 4202496 376 0 0 0 0 0 0 0 25 0 1 0 46235899 2629632 271 1283457024 134512640 135304128 4290954736 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22302/statm: 642 271 230 194 0 29 0
[pid=22303] ppid=22302 vsize=2572 CPUtime=0.03
/proc/22303/stat : 22303 (p2cudf) S 22302 22302 17511 34816 17511 4202496 393 3013 0 1 0 0 2 1 25 0 1 0 46235899 2633728 281 1283457024 134512640 135304128 4289623264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22303/statm: 643 281 239 194 0 30 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5140

[startup+0.204445 s]
/proc/loadavg: 1.47 1.28 1.15 5/35 22303
/proc/meminfo: memFree=282260/1048576 swapFree=0/0
[pid=22302] ppid=22301 vsize=2568 CPUtime=0
/proc/22302/stat : 22302 (p2cudf-user-1.1) S 22301 22302 17511 34816 17511 4202496 376 0 0 0 0 0 0 0 25 0 1 0 46235899 2629632 271 1283457024 134512640 135304128 4290954736 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22302/statm: 642 271 230 194 0 29 0
[pid=22303] ppid=22302 vsize=2572 CPUtime=0.03
/proc/22303/stat : 22303 (p2cudf) S 22302 22302 17511 34816 17511 4202496 393 3013 0 1 0 0 2 1 25 0 1 0 46235899 2633728 281 1283457024 134512640 135304128 4289623264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22303/statm: 643 281 239 194 0 30 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5140

[startup+0.304457 s]
/proc/loadavg: 1.47 1.28 1.15 5/35 22303
/proc/meminfo: memFree=282260/1048576 swapFree=0/0
[pid=22302] ppid=22301 vsize=2568 CPUtime=0
/proc/22302/stat : 22302 (p2cudf-user-1.1) S 22301 22302 17511 34816 17511 4202496 376 0 0 0 0 0 0 0 25 0 1 0 46235899 2629632 271 1283457024 134512640 135304128 4290954736 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22302/statm: 642 271 230 194 0 29 0
[pid=22303] ppid=22302 vsize=2572 CPUtime=0.03
/proc/22303/stat : 22303 (p2cudf) S 22302 22302 17511 34816 17511 4202496 393 3013 0 1 0 0 2 1 25 0 1 0 46235899 2633728 281 1283457024 134512640 135304128 4289623264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22303/statm: 643 281 239 194 0 30 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5140

[startup+0.707677 s]
/proc/loadavg: 1.47 1.28 1.15 5/35 22303
/proc/meminfo: memFree=282260/1048576 swapFree=0/0
[pid=22302] ppid=22301 vsize=2568 CPUtime=0
/proc/22302/stat : 22302 (p2cudf-user-1.1) S 22301 22302 17511 34816 17511 4202496 376 0 0 0 0 0 0 0 25 0 1 0 46235899 2629632 271 1283457024 134512640 135304128 4290954736 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22302/statm: 642 271 230 194 0 29 0
[pid=22303] ppid=22302 vsize=2572 CPUtime=0.03
/proc/22303/stat : 22303 (p2cudf) S 22302 22302 17511 34816 17511 4202496 393 3013 0 1 0 0 2 1 25 0 1 0 46235899 2633728 281 1283457024 134512640 135304128 4289623264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22303/statm: 643 281 239 194 0 30 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5140

[startup+1.50793 s]
/proc/loadavg: 1.47 1.28 1.15 3/46 22325
/proc/meminfo: memFree=233484/1048576 swapFree=0/0
[pid=22302] ppid=22301 vsize=2568 CPUtime=0
/proc/22302/stat : 22302 (p2cudf-user-1.1) S 22301 22302 17511 34816 17511 4202496 376 0 0 0 0 0 0 0 25 0 1 0 46235899 2629632 271 1283457024 134512640 135304128 4290954736 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22302/statm: 642 271 230 194 0 29 0
[pid=22303] ppid=22302 vsize=2572 CPUtime=0.03
/proc/22303/stat : 22303 (p2cudf) S 22302 22302 17511 34816 17511 4202496 393 3013 0 1 0 0 2 1 25 0 1 0 46235899 2633728 281 1283457024 134512640 135304128 4289623264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22303/statm: 643 281 239 194 0 30 0
[pid=22316] ppid=22303 vsize=884520 CPUtime=1.46
/proc/22316/stat : 22316 (java) S 22303 22302 17511 34816 17511 4202496 19726 0 1 0 138 8 0 0 25 0 10 0 46235902 905748480 16305 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/22316/statm: 221130 16305 1727 10 0 218221 0
[pid=22316/tid=22317] ppid=22303 vsize=884520 CPUtime=0.79
/proc/22316/task/22317/stat : 22317 (java) R 22303 22302 17511 34816 17511 4202560 8328 0 1 0 75 4 0 0 25 0 10 0 46235903 905748480 16305 1283457024 134512640 134550932 4290262032 18446744073709551615 4094940674 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=22316/tid=22318] ppid=22303 vsize=884520 CPUtime=0
/proc/22316/task/22318/stat : 22318 (java) S 22303 22302 17511 34816 17511 4202560 6 0 0 0 0 0 0 0 18 0 10 0 46235905 905748480 16305 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 0 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22319] ppid=22303 vsize=884520 CPUtime=0
/proc/22316/task/22319/stat : 22319 (java) S 22303 22302 17511 34816 17511 4202560 8 0 0 0 0 0 0 0 25 0 10 0 46235905 905748480 16305 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22320] ppid=22303 vsize=884520 CPUtime=0
/proc/22316/task/22320/stat : 22320 (java) S 22303 22302 17511 34816 17511 4202560 4 0 0 0 0 0 0 0 25 0 10 0 46235905 905748480 16305 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22321] ppid=22303 vsize=884520 CPUtime=0
/proc/22316/task/22321/stat : 22321 (java) S 22303 22302 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46235908 905748480 16305 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22322] ppid=22303 vsize=884520 CPUtime=0.43
/proc/22316/task/22322/stat : 22322 (java) R 22303 22302 17511 34816 17511 4202560 8493 0 0 0 41 2 0 0 25 0 10 0 46235908 905748480 16305 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=22316/tid=22323] ppid=22303 vsize=884520 CPUtime=0.22
/proc/22316/task/22323/stat : 22323 (java) R 22303 22302 17511 34816 17511 4202560 1825 0 0 0 21 1 0 0 18 0 10 0 46235908 905748480 16305 1283457024 134512640 134550932 4290262032 18446744073709551615 4151596264 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=22316/tid=22324] ppid=22303 vsize=884520 CPUtime=0
/proc/22316/task/22324/stat : 22324 (java) S 22303 22302 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46235908 905748480 16305 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22325] ppid=22303 vsize=884520 CPUtime=0
/proc/22316/task/22325/stat : 22325 (java) S 22303 22302 17511 34816 17511 4202560 2 0 0 0 0 0 0 0 15 0 10 0 46235908 905748480 16305 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 889660

[startup+3.10837 s]
/proc/loadavg: 1.47 1.28 1.15 3/46 22325
/proc/meminfo: memFree=142964/1048576 swapFree=0/0
[pid=22302] ppid=22301 vsize=2568 CPUtime=0
/proc/22302/stat : 22302 (p2cudf-user-1.1) S 22301 22302 17511 34816 17511 4202496 376 0 0 0 0 0 0 0 25 0 1 0 46235899 2629632 271 1283457024 134512640 135304128 4290954736 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22302/statm: 642 271 230 194 0 29 0
[pid=22303] ppid=22302 vsize=2572 CPUtime=0.03
/proc/22303/stat : 22303 (p2cudf) S 22302 22302 17511 34816 17511 4202496 393 3013 0 1 0 0 2 1 25 0 1 0 46235899 2633728 281 1283457024 134512640 135304128 4289623264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22303/statm: 643 281 239 194 0 30 0
[pid=22316] ppid=22303 vsize=882136 CPUtime=3.05
/proc/22316/stat : 22316 (java) S 22303 22302 17511 34816 17511 4202496 74717 0 1 0 276 29 0 0 25 0 10 0 46235902 903307264 70692 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/22316/statm: 220534 70692 1743 10 0 217625 0
[pid=22316/tid=22317] ppid=22303 vsize=882136 CPUtime=1.79
/proc/22316/task/22317/stat : 22317 (java) R 22303 22302 17511 34816 17511 4202560 50088 0 1 0 160 19 0 0 25 0 10 0 46235903 903307264 70692 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=22316/tid=22318] ppid=22303 vsize=882136 CPUtime=0.26
/proc/22316/task/22318/stat : 22318 (java) S 22303 22302 17511 34816 17511 4202560 12746 0 0 0 20 6 0 0 16 0 10 0 46235905 903307264 70692 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 0 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22319] ppid=22303 vsize=882136 CPUtime=0
/proc/22316/task/22319/stat : 22319 (java) S 22303 22302 17511 34816 17511 4202560 8 0 0 0 0 0 0 0 18 0 10 0 46235905 903307264 70692 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22320] ppid=22303 vsize=882136 CPUtime=0
/proc/22316/task/22320/stat : 22320 (java) S 22303 22302 17511 34816 17511 4202560 6 0 0 0 0 0 0 0 18 0 10 0 46235905 903307264 70692 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22321] ppid=22303 vsize=882136 CPUtime=0
/proc/22316/task/22321/stat : 22321 (java) S 22303 22302 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46235908 903307264 70692 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22322] ppid=22303 vsize=882136 CPUtime=0.56
/proc/22316/task/22322/stat : 22322 (java) R 22303 22302 17511 34816 17511 4202560 8557 0 0 0 54 2 0 0 16 0 10 0 46235908 903307264 70692 1283457024 134512640 134550932 4290262032 18446744073709551615 4151591972 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=22316/tid=22323] ppid=22303 vsize=882136 CPUtime=0.43
/proc/22316/task/22323/stat : 22323 (java) S 22303 22302 17511 34816 17511 4202560 2250 0 0 0 42 1 0 0 16 0 10 0 46235908 903307264 70692 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22324] ppid=22303 vsize=882136 CPUtime=0
/proc/22316/task/22324/stat : 22324 (java) S 22303 22302 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46235908 903307264 70692 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22325] ppid=22303 vsize=882136 CPUtime=0
/proc/22316/task/22325/stat : 22325 (java) S 22303 22302 17511 34816 17511 4202560 2 0 0 0 0 0 0 0 15 0 10 0 46235908 903307264 70692 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.08
Current children cumulated vsize (KiB) 887276

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

[startup+3.2084 s]
/proc/loadavg: 1.47 1.28 1.15 3/46 22325
/proc/meminfo: memFree=142964/1048576 swapFree=0/0
[pid=22302] ppid=22301 vsize=2568 CPUtime=0
/proc/22302/stat : 22302 (p2cudf-user-1.1) S 22301 22302 17511 34816 17511 4202496 376 0 0 0 0 0 0 0 25 0 1 0 46235899 2629632 271 1283457024 134512640 135304128 4290954736 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22302/statm: 642 271 230 194 0 29 0
[pid=22303] ppid=22302 vsize=2572 CPUtime=0.03
/proc/22303/stat : 22303 (p2cudf) S 22302 22302 17511 34816 17511 4202496 393 3013 0 1 0 0 2 1 25 0 1 0 46235899 2633728 281 1283457024 134512640 135304128 4289623264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22303/statm: 643 281 239 194 0 30 0
[pid=22316] ppid=22303 vsize=882136 CPUtime=3.15
/proc/22316/stat : 22316 (java) S 22303 22302 17511 34816 17511 4202496 74720 0 1 0 286 29 0 0 25 0 10 0 46235902 903307264 70695 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/22316/statm: 220534 70695 1743 10 0 217625 0
[pid=22316/tid=22317] ppid=22303 vsize=882136 CPUtime=1.82
/proc/22316/task/22317/stat : 22317 (java) R 22303 22302 17511 34816 17511 4202560 50088 0 1 0 163 19 0 0 25 0 10 0 46235903 903307264 70695 1283457024 134512640 134550932 4290262032 18446744073709551615 4094661342 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=22316/tid=22318] ppid=22303 vsize=882136 CPUtime=0.26
/proc/22316/task/22318/stat : 22318 (java) S 22303 22302 17511 34816 17511 4202560 12746 0 0 0 20 6 0 0 16 0 10 0 46235905 903307264 70695 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 0 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22319] ppid=22303 vsize=882136 CPUtime=0
/proc/22316/task/22319/stat : 22319 (java) S 22303 22302 17511 34816 17511 4202560 8 0 0 0 0 0 0 0 18 0 10 0 46235905 903307264 70695 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22320] ppid=22303 vsize=882136 CPUtime=0
/proc/22316/task/22320/stat : 22320 (java) S 22303 22302 17511 34816 17511 4202560 6 0 0 0 0 0 0 0 18 0 10 0 46235905 903307264 70695 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22321] ppid=22303 vsize=882136 CPUtime=0
/proc/22316/task/22321/stat : 22321 (java) S 22303 22302 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46235908 903307264 70695 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22322] ppid=22303 vsize=882136 CPUtime=0.62
/proc/22316/task/22322/stat : 22322 (java) S 22303 22302 17511 34816 17511 4202560 8560 0 0 0 60 2 0 0 16 0 10 0 46235908 903307264 70695 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22323] ppid=22303 vsize=882136 CPUtime=0.43
/proc/22316/task/22323/stat : 22323 (java) S 22303 22302 17511 34816 17511 4202560 2250 0 0 0 42 1 0 0 16 0 10 0 46235908 903307264 70695 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22324] ppid=22303 vsize=882136 CPUtime=0
/proc/22316/task/22324/stat : 22324 (java) S 22303 22302 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 10 0 46235908 903307264 70695 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22325] ppid=22303 vsize=882136 CPUtime=0
/proc/22316/task/22325/stat : 22325 (java) R 22303 22302 17511 34816 17511 4202560 2 0 0 0 0 0 0 0 15 0 10 0 46235908 903307264 70695 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.18
Current children cumulated vsize (KiB) 887276

[startup+3.90915 s]
/proc/loadavg: 1.47 1.28 1.15 3/46 22325
/proc/meminfo: memFree=5332/1048576 swapFree=0/0
[pid=22302] ppid=22301 vsize=2568 CPUtime=0
/proc/22302/stat : 22302 (p2cudf-user-1.1) S 22301 22302 17511 34816 17511 4202496 376 0 0 0 0 0 0 0 25 0 1 0 46235899 2629632 271 1283457024 134512640 135304128 4290954736 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22302/statm: 642 271 230 194 0 29 0
[pid=22303] ppid=22302 vsize=2572 CPUtime=0.03
/proc/22303/stat : 22303 (p2cudf) S 22302 22302 17511 34816 17511 4202496 393 3013 0 1 0 0 2 1 25 0 1 0 46235899 2633728 281 1283457024 134512640 135304128 4289623264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22303/statm: 643 281 239 194 0 30 0
[pid=22316] ppid=22303 vsize=882460 CPUtime=3.85
/proc/22316/stat : 22316 (java) S 22303 22302 17511 34816 17511 4202496 74963 0 1 0 356 29 0 0 25 0 11 0 46235902 903639040 70938 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/22316/statm: 220615 70938 1760 10 0 217706 0
[pid=22316/tid=22317] ppid=22303 vsize=882460 CPUtime=2.13
/proc/22316/task/22317/stat : 22317 (java) R 22303 22302 17511 34816 17511 4202560 50271 0 1 0 194 19 0 0 25 0 11 0 46235903 903639040 70938 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=22316/tid=22318] ppid=22303 vsize=882460 CPUtime=0.26
/proc/22316/task/22318/stat : 22318 (java) S 22303 22302 17511 34816 17511 4202560 12746 0 0 0 20 6 0 0 16 0 11 0 46235905 903639040 70938 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 0 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22319] ppid=22303 vsize=882460 CPUtime=0
/proc/22316/task/22319/stat : 22319 (java) S 22303 22302 17511 34816 17511 4202560 8 0 0 0 0 0 0 0 18 0 11 0 46235905 903639040 70938 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22320] ppid=22303 vsize=882460 CPUtime=0
/proc/22316/task/22320/stat : 22320 (java) S 22303 22302 17511 34816 17511 4202560 6 0 0 0 0 0 0 0 18 0 11 0 46235905 903639040 70938 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22321] ppid=22303 vsize=882460 CPUtime=0
/proc/22316/task/22321/stat : 22321 (java) S 22303 22302 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 11 0 46235908 903639040 70938 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22322] ppid=22303 vsize=882460 CPUtime=1.01
/proc/22316/task/22322/stat : 22322 (java) S 22303 22302 17511 34816 17511 4202560 8618 0 0 0 99 2 0 0 15 0 11 0 46235908 903639040 70938 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22323] ppid=22303 vsize=882460 CPUtime=0.43
/proc/22316/task/22323/stat : 22323 (java) S 22303 22302 17511 34816 17511 4202560 2250 0 0 0 42 1 0 0 16 0 11 0 46235908 903639040 70938 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22324] ppid=22303 vsize=882460 CPUtime=0
/proc/22316/task/22324/stat : 22324 (java) S 22303 22302 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 11 0 46235908 903639040 70938 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22325] ppid=22303 vsize=882460 CPUtime=0
/proc/22316/task/22325/stat : 22325 (java) S 22303 22302 17511 34816 17511 4202560 2 0 0 0 0 0 0 0 15 0 11 0 46235908 903639040 70938 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.88
Current children cumulated vsize (KiB) 887600

[startup+4.30438 s]
/proc/loadavg: 1.47 1.28 1.15 1/47 22327
/proc/meminfo: memFree=5472/1048576 swapFree=0/0
[pid=22302] ppid=22301 vsize=2568 CPUtime=0
/proc/22302/stat : 22302 (p2cudf-user-1.1) S 22301 22302 17511 34816 17511 4202496 376 0 0 0 0 0 0 0 25 0 1 0 46235899 2629632 271 1283457024 134512640 135304128 4290954736 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22302/statm: 642 271 230 194 0 29 0
[pid=22303] ppid=22302 vsize=2572 CPUtime=0.03
/proc/22303/stat : 22303 (p2cudf) S 22302 22302 17511 34816 17511 4202496 393 3013 0 1 0 0 2 1 25 0 1 0 46235899 2633728 281 1283457024 134512640 135304128 4289623264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22303/statm: 643 281 239 194 0 30 0
[pid=22316] ppid=22303 vsize=882784 CPUtime=3.9
/proc/22316/stat : 22316 (java) S 22303 22302 17511 34816 17511 4202496 74989 0 1 0 361 29 0 0 25 0 11 0 46235902 903970816 70964 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/22316/statm: 220696 70964 1767 10 0 217787 0
[pid=22316/tid=22317] ppid=22303 vsize=882784 CPUtime=2.16
/proc/22316/task/22317/stat : 22317 (java) S 22303 22302 17511 34816 17511 4202560 50280 0 1 0 197 19 0 0 25 0 11 0 46235903 903970816 70964 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22318] ppid=22303 vsize=882784 CPUtime=0.26
/proc/22316/task/22318/stat : 22318 (java) S 22303 22302 17511 34816 17511 4202560 12746 0 0 0 20 6 0 0 15 0 11 0 46235905 903970816 70964 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 0 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22319] ppid=22303 vsize=882784 CPUtime=0
/proc/22316/task/22319/stat : 22319 (java) S 22303 22302 17511 34816 17511 4202560 8 0 0 0 0 0 0 0 18 0 11 0 46235905 903970816 70964 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22320] ppid=22303 vsize=882784 CPUtime=0
/proc/22316/task/22320/stat : 22320 (java) S 22303 22302 17511 34816 17511 4202560 6 0 0 0 0 0 0 0 18 0 11 0 46235905 903970816 70964 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22321] ppid=22303 vsize=882784 CPUtime=0
/proc/22316/task/22321/stat : 22321 (java) S 22303 22302 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 11 0 46235908 903970816 70964 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22322] ppid=22303 vsize=882784 CPUtime=1.03
/proc/22316/task/22322/stat : 22322 (java) S 22303 22302 17511 34816 17511 4202560 8627 0 0 0 101 2 0 0 15 0 11 0 46235908 903970816 70964 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22323] ppid=22303 vsize=882784 CPUtime=0.43
/proc/22316/task/22323/stat : 22323 (java) S 22303 22302 17511 34816 17511 4202560 2250 0 0 0 42 1 0 0 16 0 11 0 46235908 903970816 70964 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22324] ppid=22303 vsize=882784 CPUtime=0
/proc/22316/task/22324/stat : 22324 (java) S 22303 22302 17511 34816 17511 4202560 1 0 0 0 0 0 0 0 25 0 11 0 46235908 903970816 70964 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22325] ppid=22303 vsize=882784 CPUtime=0
/proc/22316/task/22325/stat : 22325 (java) S 22303 22302 17511 34816 17511 4202560 2 0 0 0 0 0 0 0 15 0 11 0 46235908 903970816 70964 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
[pid=22316/tid=22327] ppid=22303 vsize=882784 CPUtime=0
/proc/22316/task/22327/stat : 22327 (java) S 22303 22302 17511 34816 17511 4202560 4 0 0 0 0 0 0 0 25 0 11 0 46236295 903970816 70964 1283457024 134512640 134550932 4290262032 18446744073709551615 4294960130 0 4 0 16800975 18446612132787399360 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.93
Current children cumulated vsize (KiB) 887924

[startup+4.50594 s]
/proc/loadavg: 1.47 1.28 1.15 1/47 22327
/proc/meminfo: memFree=5472/1048576 swapFree=0/0
[pid=22302] ppid=22301 vsize=2568 CPUtime=0
/proc/22302/stat : 22302 (p2cudf-user-1.1) S 22301 22302 17511 34816 17511 4202496 376 0 0 0 0 0 0 0 25 0 1 0 46235899 2629632 271 1283457024 134512640 135304128 4290954736 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22302/statm: 642 271 230 194 0 29 0
[pid=22303] ppid=22302 vsize=2572 CPUtime=0.03
/proc/22303/stat : 22303 (p2cudf) S 22302 22302 17511 34816 17511 4202496 393 3013 0 1 0 0 2 1 25 0 1 0 46235899 2633728 281 1283457024 134512640 135304128 4289623264 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22303/statm: 643 281 239 194 0 30 0
[pid=22316] ppid=22303 vsize=0 CPUtime=3.93
/proc/22316/stat : 22316 (java) Z 22303 22302 17511 34816 17511 4203532 74998 0 1 0 363 30 0 0 18 0 2 0 46235902 0 0 1283457024 0 0 0 0 0 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/22316/statm: 0 0 0 0 0 0 0
[pid=22316/tid=22317] ppid=22303 vsize=0 CPUtime=2.17
/proc/22316/task/22317/stat : 22317 (java) R 22303 22302 17511 34816 17511 4203588 50280 0 1 0 197 20 0 0 20 0 2 0 46235903 0 0 1283457024 0 0 0 0 0 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.96
Current children cumulated vsize (KiB) 5140

Child status: 0
Real time (s): 4.51943
CPU time (s): 3.98825
CPU user time (s): 3.66423
CPU system time (s): 0.32402
CPU usage (%): 88.2468
Max. virtual memory (cumulated for all children) (KiB): 891268

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 3.66423
system time used= 0.32402
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 78799
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= 510
involuntary context switches= 489

runsolver used 0 second user time and 0 second system time

The end