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/201108281254/packup2hy4tr-0.6/fe523ea6-9b1b-11df-bc37-00163e46d37a.cudf.dudf-real.log.runsolver ./packup2hy4tr-0.6 /home/misc2010/data/2011/dudf-real//fe523ea6-9b1b-11df-bc37-00163e46d37a.cudf /home/misc2010/tmp/201108281254/packup2hy4tr-0.6/fe523ea6-9b1b-11df-bc37-00163e46d37a.cudf.dudf-real.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.06 1.04 1.00 3/37 24492
/proc/meminfo: memFree=544644/1048576 swapFree=0/0
[pid=24491] ppid=24490 vsize=2576 CPUtime=0
/proc/24491/stat : 24491 (packup2hy4tr-0.) S 24490 24491 17551 34817 17551 4202496 379 0 0 0 0 0 0 0 18 0 1 0 36067167 2637824 275 1283457024 134512640 135304128 4289840400 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/24491/statm: 644 275 233 194 0 31 0
[pid=24492] ppid=24491 vsize=3712 CPUtime=0
/proc/24492/stat : 24492 (packup) D 24491 24491 17551 34817 17551 4202496 389 0 0 0 0 0 0 0 18 0 1 0 36067167 3801088 317 1283457024 134512640 134752139 4292577168 18446744073709551615 4294960130 0 0 18944 8192 18446744071564332000 0 0 17 0 0 0 0
/proc/24492/statm: 928 317 273 59 0 92 0

[startup+0.172575 s]
/proc/loadavg: 1.06 1.04 1.00 3/37 24492
/proc/meminfo: memFree=544644/1048576 swapFree=0/0
[pid=24491] ppid=24490 vsize=2576 CPUtime=0
/proc/24491/stat : 24491 (packup2hy4tr-0.) S 24490 24491 17551 34817 17551 4202496 379 0 0 0 0 0 0 0 18 0 1 0 36067167 2637824 275 1283457024 134512640 135304128 4289840400 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/24491/statm: 644 275 233 194 0 31 0
[pid=24492] ppid=24491 vsize=8908 CPUtime=0.14
/proc/24492/stat : 24492 (packup) R 24491 24491 17551 34817 17551 4202496 1708 0 0 0 14 0 0 0 25 0 1 0 36067167 9121792 1636 1283457024 134512640 134752139 4292577168 18446744073709551615 134681826 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/24492/statm: 2227 1636 286 59 0 1391 0
Current children cumulated CPU time (s) 0.14
Current children cumulated vsize (KiB) 11484

[startup+0.204582 s]
/proc/loadavg: 1.06 1.04 1.00 3/37 24492
/proc/meminfo: memFree=544644/1048576 swapFree=0/0
[pid=24491] ppid=24490 vsize=2576 CPUtime=0
/proc/24491/stat : 24491 (packup2hy4tr-0.) S 24490 24491 17551 34817 17551 4202496 379 0 0 0 0 0 0 0 18 0 1 0 36067167 2637824 275 1283457024 134512640 135304128 4289840400 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/24491/statm: 644 275 233 194 0 31 0
[pid=24492] ppid=24491 vsize=9832 CPUtime=0.16
/proc/24492/stat : 24492 (packup) R 24491 24491 17551 34817 17551 4202496 1943 0 0 0 16 0 0 0 25 0 1 0 36067167 10067968 1871 1283457024 134512640 134752139 4292577168 18446744073709551615 134681152 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/24492/statm: 2458 1871 286 59 0 1622 0
Current children cumulated CPU time (s) 0.16
Current children cumulated vsize (KiB) 12408

[startup+0.304591 s]
/proc/loadavg: 1.06 1.04 1.00 3/37 24492
/proc/meminfo: memFree=544644/1048576 swapFree=0/0
[pid=24491] ppid=24490 vsize=2576 CPUtime=0
/proc/24491/stat : 24491 (packup2hy4tr-0.) S 24490 24491 17551 34817 17551 4202496 379 0 0 0 0 0 0 0 18 0 1 0 36067167 2637824 275 1283457024 134512640 135304128 4289840400 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/24491/statm: 644 275 233 194 0 31 0
[pid=24492] ppid=24491 vsize=12600 CPUtime=0.23
/proc/24492/stat : 24492 (packup) D 24491 24491 17551 34817 17551 4202496 2633 0 0 0 22 1 0 0 25 0 1 0 36067167 12902400 2561 1283457024 134512640 134752139 4292577168 18446744073709551615 4294960130 0 0 18944 8192 18446744071564332000 0 0 17 0 0 0 0
/proc/24492/statm: 3150 2561 286 59 0 2314 0
Current children cumulated CPU time (s) 0.23
Current children cumulated vsize (KiB) 15176

[startup+0.704608 s]
/proc/loadavg: 1.06 1.04 1.00 3/37 24492
/proc/meminfo: memFree=544644/1048576 swapFree=0/0
[pid=24491] ppid=24490 vsize=2576 CPUtime=0
/proc/24491/stat : 24491 (packup2hy4tr-0.) S 24490 24491 17551 34817 17551 4202496 379 0 0 0 0 0 0 0 18 0 1 0 36067167 2637824 275 1283457024 134512640 135304128 4289840400 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/24491/statm: 644 275 233 194 0 31 0
[pid=24492] ppid=24491 vsize=22300 CPUtime=0.57
/proc/24492/stat : 24492 (packup) R 24491 24491 17551 34817 17551 4202496 5082 0 0 0 53 4 0 0 25 0 1 0 36067167 22835200 5010 1283457024 134512640 134752139 4292577168 18446744073709551615 134682176 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/24492/statm: 5575 5010 286 59 0 4739 0
Current children cumulated CPU time (s) 0.57
Current children cumulated vsize (KiB) 24876

[startup+1.50824 s]
/proc/loadavg: 1.05 1.04 1.00 2/38 24493
/proc/meminfo: memFree=498080/1048576 swapFree=0/0
[pid=24491] ppid=24490 vsize=2576 CPUtime=0
/proc/24491/stat : 24491 (packup2hy4tr-0.) S 24490 24491 17551 34817 17551 4202496 379 0 0 0 0 0 0 0 18 0 1 0 36067167 2637824 275 1283457024 134512640 135304128 4289840400 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/24491/statm: 644 275 233 194 0 31 0
[pid=24492] ppid=24491 vsize=35788 CPUtime=1.07
/proc/24492/stat : 24492 (packup) S 24491 24491 17551 34817 17551 4202496 8467 0 0 0 90 17 0 0 25 0 1 0 36067167 36646912 8394 1283457024 134512640 134752139 4292577168 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/24492/statm: 8947 8394 324 59 0 8111 0
Current children cumulated CPU time (s) 1.07
Current children cumulated vsize (KiB) 38364

[startup+3.10891 s]
/proc/loadavg: 1.05 1.04 1.00 2/38 24499
/proc/meminfo: memFree=491880/1048576 swapFree=0/0
[pid=24491] ppid=24490 vsize=2576 CPUtime=0
/proc/24491/stat : 24491 (packup2hy4tr-0.) S 24490 24491 17551 34817 17551 4202496 379 0 0 0 0 0 0 0 18 0 1 0 36067167 2637824 275 1283457024 134512640 135304128 4289840400 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/24491/statm: 644 275 233 194 0 31 0
[pid=24492] ppid=24491 vsize=37212 CPUtime=2
/proc/24492/stat : 24492 (packup) S 24491 24491 17551 34817 17551 4202496 9093 5574 0 0 98 28 64 10 18 0 1 0 36067167 38105088 8630 1283457024 134512640 134752139 4292577168 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/24492/statm: 9303 8630 332 59 0 8467 0
Current children cumulated CPU time (s) 2
Current children cumulated vsize (KiB) 39788
heavy processes:

[startup+6.30935 s]
/proc/loadavg: 1.05 1.04 1.00 2/43 24522
/proc/meminfo: memFree=432280/1048576 swapFree=0/0
[pid=24491] ppid=24490 vsize=2576 CPUtime=0
/proc/24491/stat : 24491 (packup2hy4tr-0.) S 24490 24491 17551 34817 17551 4202496 379 0 0 0 0 0 0 0 18 0 1 0 36067167 2637824 275 1283457024 134512640 135304128 4289840400 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/24491/statm: 644 275 233 194 0 31 0
[pid=24492] ppid=24491 vsize=37220 CPUtime=4.53
/proc/24492/stat : 24492 (packup) S 24491 24491 17551 34817 17551 4202496 9213 25461 0 0 116 46 255 36 16 0 1 0 36067167 38113280 8637 1283457024 134512640 134752139 4292577168 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/24492/statm: 9305 8637 332 59 0 8469 0
[pid=24512] ppid=24492 vsize=1672 CPUtime=0.01
/proc/24512/stat : 24512 (sh) S 24492 24491 17551 34817 17551 4202496 146 0 0 0 0 1 0 0 16 0 1 0 36067652 1712128 124 1283457024 134512640 134593992 4291426128 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/24512/statm: 418 124 108 20 0 45 0
[pid=24513] ppid=24512 vsize=2572 CPUtime=0
/proc/24513/stat : 24513 (run_h) S 24512 24491 17551 34817 17551 4202496 368 611 0 0 0 0 0 0 18 0 1 0 36067653 2633728 274 1283457024 134512640 135304128 4289934848 18446744073709551615 4294960130 0 65536 18948 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24513/statm: 643 274 232 194 0 30 0
[pid=24517] ppid=24513 vsize=2572 CPUtime=0
/proc/24517/stat : 24517 (run_scip) S 24513 24491 17551 34817 17551 4202496 395 754 0 0 0 0 0 0 21 0 1 0 36067653 2633728 269 1283457024 134512640 135304128 4287771616 18446744073709551615 4294960130 0 65536 18948 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24517/statm: 643 269 228 194 0 30 0
[pid=24521] ppid=24517 vsize=74684 CPUtime=1.36
/proc/24521/stat : 24521 (scip-2.0.1.linu) R 24517 24491 17551 34817 17551 4202496 19737 0 0 0 112 24 0 0 25 0 1 0 36067654 76476416 16634 1283457024 134512640 143279753 4287759264 18446744073709551615 4294960130 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/24521/statm: 18671 16634 768 2141 0 16527 0
[pid=24522] ppid=24517 vsize=7376 CPUtime=0.05
/proc/24522/stat : 24522 (scip2v) R 24517 24491 17551 34817 17551 4202496 1041 0 0 0 3 2 0 0 18 0 1 0 36067655 7553024 880 1283457024 134512640 136477024 4292102176 18446744073709551615 4157430305 0 0 16800256 2 0 0 0 17 0 0 0 0
/proc/24522/statm: 1844 880 479 480 0 429 0
Current children cumulated CPU time (s) 5.95
Current children cumulated vsize (KiB) 128672

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

[startup+6.4294 s]
/proc/loadavg: 1.05 1.04 1.00 2/43 24522
/proc/meminfo: memFree=432280/1048576 swapFree=0/0
[pid=24491] ppid=24490 vsize=2576 CPUtime=0
/proc/24491/stat : 24491 (packup2hy4tr-0.) S 24490 24491 17551 34817 17551 4202496 379 0 0 0 0 0 0 0 18 0 1 0 36067167 2637824 275 1283457024 134512640 135304128 4289840400 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/24491/statm: 644 275 233 194 0 31 0
[pid=24492] ppid=24491 vsize=37224 CPUtime=6.1
/proc/24492/stat : 24492 (packup) R 24491 24491 17551 34817 17551 4202496 10785 48598 0 0 117 48 376 69 15 0 1 0 36067167 38117376 8651 1283457024 134512640 134752139 4292577168 18446744073709551615 4157297942 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/24492/statm: 9306 8651 345 59 0 8470 0
Current children cumulated CPU time (s) 6.1
Current children cumulated vsize (KiB) 39800

Child status: 0
Real time (s): 6.50572
CPU time (s): 6.18439
CPU user time (s): 5.00031
CPU system time (s): 1.18407
CPU usage (%): 95.0607
Max. virtual memory (cumulated for all children) (KiB): 128672

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 5.00031
system time used= 1.18407
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 66153
page faults= 0
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 13438
involuntary context switches= 13488

runsolver used 0 second user time and 0.012 second system time

The end