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/201103031013/p2cudf-trendy-1.12/1596.cudf.caixa.log.runsolver ./p2cudf-trendy-1.12 /home/misc2010/data/misc4/caixa//1596.cudf /home/misc2010/tmp/201103031013/p2cudf-trendy-1.12/1596.cudf.caixa.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.87 1.73 1.42 5/37 23302
/proc/meminfo: memFree=287844/1048576 swapFree=0/0
[pid=23298] ppid=23297 vsize=2564 CPUtime=0
/proc/23298/stat : 23298 (p2cudf-trendy-1) S 23297 23298 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 25 0 1 0 75840671 2625536 269 1283457024 134512640 135304128 4293025888 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23298/statm: 641 269 230 194 0 28 0
[pid=23299] ppid=23298 vsize=2568 CPUtime=0
/proc/23299/stat : 23299 (p2cudf) S 23298 23298 29493 34817 29493 4202496 352 0 0 0 0 0 0 0 25 0 1 0 75840671 2629632 271 1283457024 134512640 135304128 4288613408 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0
/proc/23299/statm: 642 271 231 194 0 29 0
[pid=23300] ppid=23299 vsize=2568 CPUtime=0
/proc/23300/stat : 23300 (p2cudf) R 23299 23298 29493 34817 29493 4202560 117 0 0 0 0 0 0 0 25 0 1 0 75840671 2629632 125 1283457024 134512640 135304128 4288613408 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/23300/statm: 642 125 84 194 0 29 0
[pid=23301] ppid=23300 vsize=1788 CPUtime=0
/proc/23301/stat : 23301 (java) R 23300 23298 29493 34817 29493 4194304 400 0 0 0 0 0 0 0 25 0 1 0 75840671 1830912 128 1283457024 134512640 134550932 4290586080 18446744073709551615 4160110958 0 0 0 0 0 0 0 17 0 0 0 0
/proc/23301/statm: 447 128 102 10 0 48 0
[pid=23302] ppid=23300 vsize=2568 CPUtime=0
/proc/23302/stat : 23302 (p2cudf) R 23300 23298 29493 34817 29493 4202560 0 0 0 0 0 0 0 0 25 0 1 0 75840671 2629632 41 1283457024 134512640 135304128 4288613408 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/23302/statm: 642 41 0 194 0 29 0

[startup+0.19574 s]
/proc/loadavg: 1.87 1.73 1.42 5/37 23302
/proc/meminfo: memFree=287844/1048576 swapFree=0/0
[pid=23298] ppid=23297 vsize=2564 CPUtime=0
/proc/23298/stat : 23298 (p2cudf-trendy-1) S 23297 23298 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 25 0 1 0 75840671 2625536 269 1283457024 134512640 135304128 4293025888 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23298/statm: 641 269 230 194 0 28 0
[pid=23299] ppid=23298 vsize=2572 CPUtime=0.03
/proc/23299/stat : 23299 (p2cudf) S 23298 23298 29493 34817 29493 4202496 391 3016 0 1 0 0 2 1 25 0 1 0 75840671 2633728 280 1283457024 134512640 135304128 4288613408 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23299/statm: 643 280 239 194 0 30 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5136

[startup+0.205732 s]
/proc/loadavg: 1.87 1.73 1.42 5/37 23302
/proc/meminfo: memFree=287844/1048576 swapFree=0/0
[pid=23298] ppid=23297 vsize=2564 CPUtime=0
/proc/23298/stat : 23298 (p2cudf-trendy-1) S 23297 23298 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 25 0 1 0 75840671 2625536 269 1283457024 134512640 135304128 4293025888 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23298/statm: 641 269 230 194 0 28 0
[pid=23299] ppid=23298 vsize=2572 CPUtime=0.03
/proc/23299/stat : 23299 (p2cudf) S 23298 23298 29493 34817 29493 4202496 391 3016 0 1 0 0 2 1 25 0 1 0 75840671 2633728 280 1283457024 134512640 135304128 4288613408 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23299/statm: 643 280 239 194 0 30 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5136

[startup+0.305748 s]
/proc/loadavg: 1.87 1.73 1.42 5/37 23302
/proc/meminfo: memFree=287844/1048576 swapFree=0/0
[pid=23298] ppid=23297 vsize=2564 CPUtime=0
/proc/23298/stat : 23298 (p2cudf-trendy-1) S 23297 23298 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 25 0 1 0 75840671 2625536 269 1283457024 134512640 135304128 4293025888 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23298/statm: 641 269 230 194 0 28 0
[pid=23299] ppid=23298 vsize=2572 CPUtime=0.03
/proc/23299/stat : 23299 (p2cudf) S 23298 23298 29493 34817 29493 4202496 391 3016 0 1 0 0 2 1 25 0 1 0 75840671 2633728 280 1283457024 134512640 135304128 4288613408 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23299/statm: 643 280 239 194 0 30 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5136

[startup+0.705815 s]
/proc/loadavg: 1.87 1.73 1.42 5/37 23302
/proc/meminfo: memFree=287844/1048576 swapFree=0/0
[pid=23298] ppid=23297 vsize=2564 CPUtime=0
/proc/23298/stat : 23298 (p2cudf-trendy-1) S 23297 23298 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 25 0 1 0 75840671 2625536 269 1283457024 134512640 135304128 4293025888 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23298/statm: 641 269 230 194 0 28 0
[pid=23299] ppid=23298 vsize=2572 CPUtime=0.03
/proc/23299/stat : 23299 (p2cudf) S 23298 23298 29493 34817 29493 4202496 391 3016 0 1 0 0 2 1 25 0 1 0 75840671 2633728 280 1283457024 134512640 135304128 4288613408 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23299/statm: 643 280 239 194 0 30 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5136

[startup+1.50601 s]
/proc/loadavg: 1.96 1.75 1.43 5/45 23321
/proc/meminfo: memFree=246432/1048576 swapFree=0/0
[pid=23298] ppid=23297 vsize=2564 CPUtime=0
/proc/23298/stat : 23298 (p2cudf-trendy-1) S 23297 23298 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 25 0 1 0 75840671 2625536 269 1283457024 134512640 135304128 4293025888 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23298/statm: 641 269 230 194 0 28 0
[pid=23299] ppid=23298 vsize=2572 CPUtime=0.03
/proc/23299/stat : 23299 (p2cudf) S 23298 23298 29493 34817 29493 4202496 391 3016 0 1 0 0 2 1 25 0 1 0 75840671 2633728 280 1283457024 134512640 135304128 4288613408 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23299/statm: 643 280 239 194 0 30 0
[pid=23312] ppid=23299 vsize=882140 CPUtime=1.46
/proc/23312/stat : 23312 (java) S 23299 23298 29493 34817 29493 4202496 18336 0 1 0 139 7 0 0 25 0 10 0 75840674 903311360 13787 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/23312/statm: 220535 13787 1725 10 0 217626 0
[pid=23312/tid=23313] ppid=23299 vsize=882140 CPUtime=0.62
/proc/23312/task/23313/stat : 23313 (java) R 23299 23298 29493 34817 29493 4202560 5903 0 1 0 60 2 0 0 25 0 10 0 75840675 903311360 13787 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=23312/tid=23314] ppid=23299 vsize=882140 CPUtime=0
/proc/23312/task/23314/stat : 23314 (java) S 23299 23298 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 15 0 10 0 75840676 903311360 13787 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 0 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23315] ppid=23299 vsize=882140 CPUtime=0
/proc/23312/task/23315/stat : 23315 (java) S 23299 23298 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 25 0 10 0 75840677 903311360 13787 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23316] ppid=23299 vsize=882140 CPUtime=0
/proc/23312/task/23316/stat : 23316 (java) S 23299 23298 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 10 0 75840677 903311360 13787 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23317] ppid=23299 vsize=882140 CPUtime=0
/proc/23312/task/23317/stat : 23317 (java) S 23299 23298 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 75840679 903311360 13787 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23318] ppid=23299 vsize=882140 CPUtime=0.55
/proc/23312/task/23318/stat : 23318 (java) R 23299 23298 29493 34817 29493 4202560 8846 0 0 0 51 4 0 0 22 0 10 0 75840679 903311360 13787 1283457024 134512640 134550932 4288483984 18446744073709551615 4153619723 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=23312/tid=23319] ppid=23299 vsize=882140 CPUtime=0.27
/proc/23312/task/23319/stat : 23319 (java) R 23299 23298 29493 34817 29493 4202560 2506 0 0 0 27 0 0 0 24 0 10 0 75840680 903311360 13787 1283457024 134512640 134550932 4288483984 18446744073709551615 4152119987 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=23312/tid=23320] ppid=23299 vsize=882140 CPUtime=0
/proc/23312/task/23320/stat : 23320 (java) S 23299 23298 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 75840680 903311360 13787 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23321] ppid=23299 vsize=882140 CPUtime=0
/proc/23312/task/23321/stat : 23321 (java) S 23299 23298 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 10 0 75840680 903311360 13787 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 887276

[startup+3.10632 s]
/proc/loadavg: 1.96 1.75 1.43 4/45 23321
/proc/meminfo: memFree=200428/1048576 swapFree=0/0
[pid=23298] ppid=23297 vsize=2564 CPUtime=0
/proc/23298/stat : 23298 (p2cudf-trendy-1) S 23297 23298 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 25 0 1 0 75840671 2625536 269 1283457024 134512640 135304128 4293025888 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23298/statm: 641 269 230 194 0 28 0
[pid=23299] ppid=23298 vsize=2572 CPUtime=0.03
/proc/23299/stat : 23299 (p2cudf) S 23298 23298 29493 34817 29493 4202496 391 3016 0 1 0 0 2 1 25 0 1 0 75840671 2633728 280 1283457024 134512640 135304128 4288613408 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23299/statm: 643 280 239 194 0 30 0
[pid=23312] ppid=23299 vsize=882832 CPUtime=3.05
/proc/23312/stat : 23312 (java) S 23299 23298 29493 34817 29493 4202496 57652 0 1 0 289 16 0 0 25 0 10 0 75840674 904019968 50292 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/23312/statm: 220708 50292 1742 10 0 217799 0
[pid=23312/tid=23313] ppid=23299 vsize=882832 CPUtime=1.52
/proc/23312/task/23313/stat : 23313 (java) R 23299 23298 29493 34817 29493 4202560 42117 0 1 0 142 10 0 0 25 0 10 0 75840675 904019968 50292 1283457024 134512640 134550932 4288483984 18446744073709551615 4095436254 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=23312/tid=23314] ppid=23299 vsize=882832 CPUtime=0
/proc/23312/task/23314/stat : 23314 (java) S 23299 23298 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 15 0 10 0 75840676 904019968 50292 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 0 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23315] ppid=23299 vsize=882832 CPUtime=0
/proc/23312/task/23315/stat : 23315 (java) S 23299 23298 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 25 0 10 0 75840677 904019968 50292 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23316] ppid=23299 vsize=882832 CPUtime=0
/proc/23312/task/23316/stat : 23316 (java) S 23299 23298 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 10 0 75840677 904019968 50292 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23317] ppid=23299 vsize=882832 CPUtime=0
/proc/23312/task/23317/stat : 23317 (java) S 23299 23298 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 75840679 904019968 50292 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23318] ppid=23299 vsize=882832 CPUtime=0.86
/proc/23312/task/23318/stat : 23318 (java) S 23299 23298 29493 34817 29493 4202560 8992 0 0 0 82 4 0 0 20 0 10 0 75840679 904019968 50292 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23319] ppid=23299 vsize=882832 CPUtime=0.67
/proc/23312/task/23319/stat : 23319 (java) R 23299 23298 29493 34817 29493 4202560 5462 0 0 0 65 2 0 0 25 0 10 0 75840680 904019968 50292 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=23312/tid=23320] ppid=23299 vsize=882832 CPUtime=0
/proc/23312/task/23320/stat : 23320 (java) S 23299 23298 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 75840680 904019968 50292 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23321] ppid=23299 vsize=882832 CPUtime=0
/proc/23312/task/23321/stat : 23321 (java) S 23299 23298 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 10 0 75840680 904019968 50292 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.08
Current children cumulated vsize (KiB) 887968

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

[startup+3.20637 s]
/proc/loadavg: 1.96 1.75 1.43 4/45 23321
/proc/meminfo: memFree=200428/1048576 swapFree=0/0
[pid=23298] ppid=23297 vsize=2564 CPUtime=0
/proc/23298/stat : 23298 (p2cudf-trendy-1) S 23297 23298 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 25 0 1 0 75840671 2625536 269 1283457024 134512640 135304128 4293025888 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23298/statm: 641 269 230 194 0 28 0
[pid=23299] ppid=23298 vsize=2572 CPUtime=0.03
/proc/23299/stat : 23299 (p2cudf) S 23298 23298 29493 34817 29493 4202496 391 3016 0 1 0 0 2 1 25 0 1 0 75840671 2633728 280 1283457024 134512640 135304128 4288613408 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23299/statm: 643 280 239 194 0 30 0
[pid=23312] ppid=23299 vsize=882832 CPUtime=3.15
/proc/23312/stat : 23312 (java) S 23299 23298 29493 34817 29493 4202496 57859 0 1 0 299 16 0 0 25 0 10 0 75840674 904019968 50499 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/23312/statm: 220708 50499 1743 10 0 217799 0
[pid=23312/tid=23313] ppid=23299 vsize=882832 CPUtime=1.53
/proc/23312/task/23313/stat : 23313 (java) R 23299 23298 29493 34817 29493 4202560 42315 0 1 0 143 10 0 0 25 0 10 0 75840675 904019968 50499 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=23312/tid=23314] ppid=23299 vsize=882832 CPUtime=0
/proc/23312/task/23314/stat : 23314 (java) S 23299 23298 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 15 0 10 0 75840676 904019968 50499 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 0 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23315] ppid=23299 vsize=882832 CPUtime=0
/proc/23312/task/23315/stat : 23315 (java) S 23299 23298 29493 34817 29493 4202560 8 0 0 0 0 0 0 0 25 0 10 0 75840677 904019968 50499 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23316] ppid=23299 vsize=882832 CPUtime=0
/proc/23312/task/23316/stat : 23316 (java) S 23299 23298 29493 34817 29493 4202560 4 0 0 0 0 0 0 0 25 0 10 0 75840677 904019968 50499 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23317] ppid=23299 vsize=882832 CPUtime=0
/proc/23312/task/23317/stat : 23317 (java) S 23299 23298 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 75840679 904019968 50499 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23318] ppid=23299 vsize=882832 CPUtime=0.9
/proc/23312/task/23318/stat : 23318 (java) S 23299 23298 29493 34817 29493 4202560 8997 0 0 0 86 4 0 0 17 0 10 0 75840679 904019968 50499 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23319] ppid=23299 vsize=882832 CPUtime=0.72
/proc/23312/task/23319/stat : 23319 (java) R 23299 23298 29493 34817 29493 4202560 5466 0 0 0 70 2 0 0 24 0 10 0 75840680 904019968 50499 1283457024 134512640 134550932 4288483984 18446744073709551615 4152370096 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=23312/tid=23320] ppid=23299 vsize=882832 CPUtime=0
/proc/23312/task/23320/stat : 23320 (java) S 23299 23298 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 75840680 904019968 50499 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23321] ppid=23299 vsize=882832 CPUtime=0
/proc/23312/task/23321/stat : 23321 (java) S 23299 23298 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 10 0 75840680 904019968 50499 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.18
Current children cumulated vsize (KiB) 887968

[startup+4.82684 s]
/proc/loadavg: 1.96 1.75 1.43 3/45 23321
/proc/meminfo: memFree=7296/1048576 swapFree=0/0
[pid=23298] ppid=23297 vsize=2564 CPUtime=0
/proc/23298/stat : 23298 (p2cudf-trendy-1) S 23297 23298 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 25 0 1 0 75840671 2625536 269 1283457024 134512640 135304128 4293025888 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23298/statm: 641 269 230 194 0 28 0
[pid=23299] ppid=23298 vsize=2572 CPUtime=0.03
/proc/23299/stat : 23299 (p2cudf) S 23298 23298 29493 34817 29493 4202496 391 3016 0 1 0 0 2 1 25 0 1 0 75840671 2633728 280 1283457024 134512640 135304128 4288613408 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23299/statm: 643 280 239 194 0 30 0
[pid=23312] ppid=23299 vsize=882140 CPUtime=4.77
/proc/23312/stat : 23312 (java) S 23299 23298 29493 34817 29493 4202496 81823 0 1 0 452 25 0 0 25 0 10 0 75840674 903311360 73480 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/23312/statm: 220535 73480 1748 10 0 217626 0
[pid=23312/tid=23313] ppid=23299 vsize=882140 CPUtime=2.03
/proc/23312/task/23313/stat : 23313 (java) R 23299 23298 29493 34817 29493 4202560 50156 0 1 0 190 13 0 0 25 0 10 0 75840675 903311360 73480 1283457024 134512640 134550932 4288483984 18446744073709551615 4149328649 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=23312/tid=23314] ppid=23299 vsize=882140 CPUtime=0.34
/proc/23312/task/23314/stat : 23314 (java) S 23299 23298 29493 34817 29493 4202560 15255 0 0 0 28 6 0 0 16 0 10 0 75840676 903311360 73480 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 0 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23315] ppid=23299 vsize=882140 CPUtime=0
/proc/23312/task/23315/stat : 23315 (java) S 23299 23298 29493 34817 29493 4202560 9 0 0 0 0 0 0 0 18 0 10 0 75840677 903311360 73480 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23316] ppid=23299 vsize=882140 CPUtime=0
/proc/23312/task/23316/stat : 23316 (java) S 23299 23298 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 10 0 75840677 903311360 73480 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23317] ppid=23299 vsize=882140 CPUtime=0
/proc/23312/task/23317/stat : 23317 (java) S 23299 23298 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 75840679 903311360 73480 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23318] ppid=23299 vsize=882140 CPUtime=1.53
/proc/23312/task/23318/stat : 23318 (java) R 23299 23298 29493 34817 29493 4202560 9855 0 0 0 149 4 0 0 15 0 10 0 75840679 903311360 73480 1283457024 134512640 134550932 4288483984 18446744073709551615 4150307712 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=23312/tid=23319] ppid=23299 vsize=882140 CPUtime=0.87
/proc/23312/task/23319/stat : 23319 (java) R 23299 23298 29493 34817 29493 4202560 5479 0 0 0 85 2 0 0 24 0 10 0 75840680 903311360 73480 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=23312/tid=23320] ppid=23299 vsize=882140 CPUtime=0
/proc/23312/task/23320/stat : 23320 (java) S 23299 23298 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 75840680 903311360 73480 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23321] ppid=23299 vsize=882140 CPUtime=0
/proc/23312/task/23321/stat : 23321 (java) R 23299 23298 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 10 0 75840680 903311360 73480 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.8
Current children cumulated vsize (KiB) 887276

[startup+5.206 s]
/proc/loadavg: 1.96 1.75 1.43 3/45 23321
/proc/meminfo: memFree=7296/1048576 swapFree=0/0
[pid=23298] ppid=23297 vsize=2564 CPUtime=0
/proc/23298/stat : 23298 (p2cudf-trendy-1) S 23297 23298 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 25 0 1 0 75840671 2625536 269 1283457024 134512640 135304128 4293025888 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23298/statm: 641 269 230 194 0 28 0
[pid=23299] ppid=23298 vsize=2572 CPUtime=0.03
/proc/23299/stat : 23299 (p2cudf) S 23298 23298 29493 34817 29493 4202496 391 3016 0 1 0 0 2 1 25 0 1 0 75840671 2633728 280 1283457024 134512640 135304128 4288613408 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23299/statm: 643 280 239 194 0 30 0
[pid=23312] ppid=23299 vsize=882464 CPUtime=4.94
/proc/23312/stat : 23312 (java) S 23299 23298 29493 34817 29493 4202496 81899 0 1 0 468 26 0 0 25 0 11 0 75840674 903643136 73556 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/23312/statm: 220616 73556 1763 10 0 217707 0
[pid=23312/tid=23313] ppid=23299 vsize=882464 CPUtime=2.11
/proc/23312/task/23313/stat : 23313 (java) S 23299 23298 29493 34817 29493 4202560 50202 0 1 0 197 14 0 0 25 0 11 0 75840675 903643136 73556 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23314] ppid=23299 vsize=882464 CPUtime=0.34
/proc/23312/task/23314/stat : 23314 (java) S 23299 23298 29493 34817 29493 4202560 15255 0 0 0 28 6 0 0 15 0 11 0 75840676 903643136 73556 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 0 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23315] ppid=23299 vsize=882464 CPUtime=0
/proc/23312/task/23315/stat : 23315 (java) S 23299 23298 29493 34817 29493 4202560 9 0 0 0 0 0 0 0 18 0 11 0 75840677 903643136 73556 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23316] ppid=23299 vsize=882464 CPUtime=0
/proc/23312/task/23316/stat : 23316 (java) S 23299 23298 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 11 0 75840677 903643136 73556 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23317] ppid=23299 vsize=882464 CPUtime=0
/proc/23312/task/23317/stat : 23317 (java) S 23299 23298 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 75840679 903643136 73556 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23318] ppid=23299 vsize=882464 CPUtime=1.59
/proc/23312/task/23318/stat : 23318 (java) S 23299 23298 29493 34817 29493 4202560 9864 0 0 0 155 4 0 0 16 0 11 0 75840679 903643136 73556 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23319] ppid=23299 vsize=882464 CPUtime=0.89
/proc/23312/task/23319/stat : 23319 (java) S 23299 23298 29493 34817 29493 4202560 5496 0 0 0 87 2 0 0 24 0 11 0 75840680 903643136 73556 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23320] ppid=23299 vsize=882464 CPUtime=0
/proc/23312/task/23320/stat : 23320 (java) S 23299 23298 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 75840680 903643136 73556 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23321] ppid=23299 vsize=882464 CPUtime=0
/proc/23312/task/23321/stat : 23321 (java) S 23299 23298 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 11 0 75840680 903643136 73556 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.97
Current children cumulated vsize (KiB) 887600

[startup+5.40599 s]
/proc/loadavg: 1.96 1.75 1.43 3/45 23321
/proc/meminfo: memFree=7296/1048576 swapFree=0/0
[pid=23298] ppid=23297 vsize=2564 CPUtime=0
/proc/23298/stat : 23298 (p2cudf-trendy-1) S 23297 23298 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 25 0 1 0 75840671 2625536 269 1283457024 134512640 135304128 4293025888 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23298/statm: 641 269 230 194 0 28 0
[pid=23299] ppid=23298 vsize=2572 CPUtime=0.03
/proc/23299/stat : 23299 (p2cudf) S 23298 23298 29493 34817 29493 4202496 391 3016 0 1 0 0 2 1 25 0 1 0 75840671 2633728 280 1283457024 134512640 135304128 4288613408 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23299/statm: 643 280 239 194 0 30 0
[pid=23312] ppid=23299 vsize=882464 CPUtime=4.94
/proc/23312/stat : 23312 (java) S 23299 23298 29493 34817 29493 4202496 81899 0 1 0 468 26 0 0 25 0 11 0 75840674 903643136 73556 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/23312/statm: 220616 73556 1763 10 0 217707 0
[pid=23312/tid=23313] ppid=23299 vsize=882464 CPUtime=2.11
/proc/23312/task/23313/stat : 23313 (java) S 23299 23298 29493 34817 29493 4202560 50202 0 1 0 197 14 0 0 25 0 11 0 75840675 903643136 73556 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23314] ppid=23299 vsize=882464 CPUtime=0.34
/proc/23312/task/23314/stat : 23314 (java) S 23299 23298 29493 34817 29493 4202560 15255 0 0 0 28 6 0 0 15 0 11 0 75840676 903643136 73556 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 0 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23315] ppid=23299 vsize=882464 CPUtime=0
/proc/23312/task/23315/stat : 23315 (java) S 23299 23298 29493 34817 29493 4202560 9 0 0 0 0 0 0 0 18 0 11 0 75840677 903643136 73556 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23316] ppid=23299 vsize=882464 CPUtime=0
/proc/23312/task/23316/stat : 23316 (java) S 23299 23298 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 11 0 75840677 903643136 73556 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23317] ppid=23299 vsize=882464 CPUtime=0
/proc/23312/task/23317/stat : 23317 (java) S 23299 23298 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 75840679 903643136 73556 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23318] ppid=23299 vsize=882464 CPUtime=1.59
/proc/23312/task/23318/stat : 23318 (java) S 23299 23298 29493 34817 29493 4202560 9864 0 0 0 155 4 0 0 16 0 11 0 75840679 903643136 73556 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23319] ppid=23299 vsize=882464 CPUtime=0.89
/proc/23312/task/23319/stat : 23319 (java) S 23299 23298 29493 34817 29493 4202560 5496 0 0 0 87 2 0 0 24 0 11 0 75840680 903643136 73556 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23320] ppid=23299 vsize=882464 CPUtime=0
/proc/23312/task/23320/stat : 23320 (java) S 23299 23298 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 11 0 75840680 903643136 73556 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23321] ppid=23299 vsize=882464 CPUtime=0
/proc/23312/task/23321/stat : 23321 (java) S 23299 23298 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 11 0 75840680 903643136 73556 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.97
Current children cumulated vsize (KiB) 887600

[startup+5.50605 s]
/proc/loadavg: 1.96 1.75 1.43 1/45 23322
/proc/meminfo: memFree=7296/1048576 swapFree=0/0
[pid=23298] ppid=23297 vsize=2564 CPUtime=0
/proc/23298/stat : 23298 (p2cudf-trendy-1) S 23297 23298 29493 34817 29493 4202496 373 0 0 0 0 0 0 0 25 0 1 0 75840671 2625536 269 1283457024 134512640 135304128 4293025888 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23298/statm: 641 269 230 194 0 28 0
[pid=23299] ppid=23298 vsize=2572 CPUtime=0.03
/proc/23299/stat : 23299 (p2cudf) S 23298 23298 29493 34817 29493 4202496 391 3016 0 1 0 0 2 1 25 0 1 0 75840671 2633728 280 1283457024 134512640 135304128 4288613408 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23299/statm: 643 280 239 194 0 30 0
[pid=23312] ppid=23299 vsize=882464 CPUtime=4.94
/proc/23312/stat : 23312 (java) S 23299 23298 29493 34817 29493 4202496 81901 0 1 0 468 26 0 0 25 0 10 0 75840674 903643136 73558 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/23312/statm: 220616 73558 1765 10 0 217707 0
[pid=23312/tid=23313] ppid=23299 vsize=882464 CPUtime=2.11
/proc/23312/task/23313/stat : 23313 (java) S 23299 23298 29493 34817 29493 4202560 50202 0 1 0 197 14 0 0 20 0 10 0 75840675 903643136 73558 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23314] ppid=23299 vsize=882464 CPUtime=0.34
/proc/23312/task/23314/stat : 23314 (java) S 23299 23298 29493 34817 29493 4202560 15256 0 0 0 28 6 0 0 16 0 10 0 75840676 903643136 73558 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 0 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23315] ppid=23299 vsize=882464 CPUtime=0
/proc/23312/task/23315/stat : 23315 (java) S 23299 23298 29493 34817 29493 4202560 9 0 0 0 0 0 0 0 18 0 10 0 75840677 903643136 73558 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23316] ppid=23299 vsize=882464 CPUtime=0
/proc/23312/task/23316/stat : 23316 (java) S 23299 23298 29493 34817 29493 4202560 6 0 0 0 0 0 0 0 18 0 10 0 75840677 903643136 73558 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23317] ppid=23299 vsize=882464 CPUtime=0
/proc/23312/task/23317/stat : 23317 (java) S 23299 23298 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 75840679 903643136 73558 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23318] ppid=23299 vsize=882464 CPUtime=1.59
/proc/23312/task/23318/stat : 23318 (java) S 23299 23298 29493 34817 29493 4202560 9864 0 0 0 155 4 0 0 16 0 10 0 75840679 903643136 73558 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23319] ppid=23299 vsize=882464 CPUtime=0.89
/proc/23312/task/23319/stat : 23319 (java) S 23299 23298 29493 34817 29493 4202560 5496 0 0 0 87 2 0 0 24 0 10 0 75840680 903643136 73558 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23320] ppid=23299 vsize=882464 CPUtime=0
/proc/23312/task/23320/stat : 23320 (java) S 23299 23298 29493 34817 29493 4202560 1 0 0 0 0 0 0 0 25 0 10 0 75840680 903643136 73558 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
[pid=23312/tid=23321] ppid=23299 vsize=882464 CPUtime=0
/proc/23312/task/23321/stat : 23321 (java) S 23299 23298 29493 34817 29493 4202560 2 0 0 0 0 0 0 0 15 0 10 0 75840680 903643136 73558 1283457024 134512640 134550932 4288483984 18446744073709551615 4294960130 0 4 0 16800975 18446612132467745728 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.97
Current children cumulated vsize (KiB) 887600

Child status: 0
Real time (s): 5.56284
CPU time (s): 5.00431
CPU user time (s): 4.70829
CPU system time (s): 0.296018
CPU usage (%): 89.9596
Max. virtual memory (cumulated for all children) (KiB): 892220

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 4.70829
system time used= 0.296018
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 85706
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= 315
involuntary context switches= 309

runsolver used 0 second user time and 0 second system time

The end