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/201108241238/packup2mp4tr-0.6/rand485.cudf.s-e.log.runsolver ./packup2mp4tr-0.6 /home/misc2010/data/2011/incremental/s-e/rand485.cudf /home/misc2010/tmp/201108241238/packup2mp4tr-0.6/rand485.cudf.s-e.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.21 1.07 1.01 4/34 14074
/proc/meminfo: memFree=493108/1048576 swapFree=0/0
[pid=14073] ppid=14072 vsize=2572 CPUtime=0
/proc/14073/stat : 14073 (packup2mp4tr-0.) S 14072 14073 1511 34817 1511 4202496 377 0 0 0 0 0 0 0 18 0 1 0 3318915 2633728 274 1283457024 134512640 135304128 4292282272 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/14073/statm: 643 274 233 194 0 30 0
[pid=14074] ppid=14073 vsize=3552 CPUtime=0.01
/proc/14074/stat : 14074 (packup) R 14073 14073 1511 34817 1511 4202496 350 0 0 0 0 1 0 0 25 0 1 0 3318915 3637248 279 1283457024 134512640 134752139 4287539952 18446744073709551615 4294960130 0 0 0 0 0 0 0 17 0 0 0 0
/proc/14074/statm: 888 279 245 59 0 52 0

[startup+0.203251 s]
/proc/loadavg: 1.21 1.07 1.01 4/34 14074
/proc/meminfo: memFree=493108/1048576 swapFree=0/0
[pid=14073] ppid=14072 vsize=2572 CPUtime=0
/proc/14073/stat : 14073 (packup2mp4tr-0.) S 14072 14073 1511 34817 1511 4202496 377 0 0 0 0 0 0 0 18 0 1 0 3318915 2633728 274 1283457024 134512640 135304128 4292282272 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/14073/statm: 643 274 233 194 0 30 0
[pid=14074] ppid=14073 vsize=10868 CPUtime=0.2
/proc/14074/stat : 14074 (packup) R 14073 14073 1511 34817 1511 4202496 2219 0 0 0 18 2 0 0 25 0 1 0 3318915 11128832 2148 1283457024 134512640 134752139 4287539952 18446744073709551615 4157252967 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/14074/statm: 2717 2148 286 59 0 1881 0
Current children cumulated CPU time (s) 0.2
Current children cumulated vsize (KiB) 13440

[startup+0.31329 s]
/proc/loadavg: 1.21 1.07 1.01 4/34 14074
/proc/meminfo: memFree=493108/1048576 swapFree=0/0
[pid=14073] ppid=14072 vsize=2572 CPUtime=0
/proc/14073/stat : 14073 (packup2mp4tr-0.) S 14072 14073 1511 34817 1511 4202496 377 0 0 0 0 0 0 0 18 0 1 0 3318915 2633728 274 1283457024 134512640 135304128 4292282272 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/14073/statm: 643 274 233 194 0 30 0
[pid=14074] ppid=14073 vsize=14204 CPUtime=0.31
/proc/14074/stat : 14074 (packup) R 14073 14073 1511 34817 1511 4202496 3054 0 0 0 29 2 0 0 25 0 1 0 3318915 14544896 2983 1283457024 134512640 134752139 4287539952 18446744073709551615 134681895 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/14074/statm: 3551 2983 286 59 0 2715 0
Current children cumulated CPU time (s) 0.31
Current children cumulated vsize (KiB) 16776

[startup+0.403312 s]
/proc/loadavg: 1.21 1.07 1.01 4/34 14074
/proc/meminfo: memFree=493108/1048576 swapFree=0/0
[pid=14073] ppid=14072 vsize=2572 CPUtime=0
/proc/14073/stat : 14073 (packup2mp4tr-0.) S 14072 14073 1511 34817 1511 4202496 377 0 0 0 0 0 0 0 18 0 1 0 3318915 2633728 274 1283457024 134512640 135304128 4292282272 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/14073/statm: 643 274 233 194 0 30 0
[pid=14074] ppid=14073 vsize=16776 CPUtime=0.4
/proc/14074/stat : 14074 (packup) R 14073 14073 1511 34817 1511 4202496 3691 0 0 0 38 2 0 0 25 0 1 0 3318915 17178624 3620 1283457024 134512640 134752139 4287539952 18446744073709551615 4294960130 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/14074/statm: 4194 3620 286 59 0 3358 0
Current children cumulated CPU time (s) 0.4
Current children cumulated vsize (KiB) 19348

[startup+0.713389 s]
/proc/loadavg: 1.21 1.07 1.01 4/34 14074
/proc/meminfo: memFree=493108/1048576 swapFree=0/0
[pid=14073] ppid=14072 vsize=2572 CPUtime=0
/proc/14073/stat : 14073 (packup2mp4tr-0.) S 14072 14073 1511 34817 1511 4202496 377 0 0 0 0 0 0 0 18 0 1 0 3318915 2633728 274 1283457024 134512640 135304128 4292282272 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/14073/statm: 643 274 233 194 0 30 0
[pid=14074] ppid=14073 vsize=28324 CPUtime=0.71
/proc/14074/stat : 14074 (packup) R 14073 14073 1511 34817 1511 4202496 6599 0 0 0 62 9 0 0 25 0 1 0 3318915 29003776 6414 1283457024 134512640 134752139 4287539952 18446744073709551615 4294960130 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/14074/statm: 7081 6414 321 59 0 6245 0
Current children cumulated CPU time (s) 0.71
Current children cumulated vsize (KiB) 30896

[startup+1.51362 s]
/proc/loadavg: 1.21 1.07 1.01 2/37 14077
/proc/meminfo: memFree=458964/1048576 swapFree=0/0
[pid=14073] ppid=14072 vsize=2572 CPUtime=0
/proc/14073/stat : 14073 (packup2mp4tr-0.) S 14072 14073 1511 34817 1511 4202496 377 0 0 0 0 0 0 0 18 0 1 0 3318915 2633728 274 1283457024 134512640 135304128 4292282272 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/14073/statm: 643 274 233 194 0 30 0
[pid=14074] ppid=14073 vsize=28324 CPUtime=0.79
/proc/14074/stat : 14074 (packup) S 14073 14073 1511 34817 1511 4202496 6603 0 0 0 64 15 0 0 25 0 1 0 3318915 29003776 6417 1283457024 134512640 134752139 4287539952 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/14074/statm: 7081 6417 324 59 0 6245 0
[pid=14076] ppid=14074 vsize=1668 CPUtime=0.01
/proc/14076/stat : 14076 (sh) S 14074 14073 1511 34817 1511 4202496 145 0 0 0 1 0 0 0 25 0 1 0 3318995 1708032 123 1283457024 134512640 134593992 4288375904 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/14076/statm: 417 123 108 20 0 44 0
[pid=14077] ppid=14076 vsize=17440 CPUtime=0.7
/proc/14077/stat : 14077 (minisatp_32) R 14076 14073 1511 34817 1511 4202496 5074 0 0 0 62 8 0 0 25 0 1 0 3318995 17858560 4024 1283457024 134512640 135413687 4289381744 18446744073709551615 134696769 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/14077/statm: 4360 4024 108 220 0 4138 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 50004

[startup+3.10417 s]
/proc/loadavg: 1.21 1.07 1.01 2/37 14079
/proc/meminfo: memFree=456112/1048576 swapFree=0/0
[pid=14073] ppid=14072 vsize=2572 CPUtime=0
/proc/14073/stat : 14073 (packup2mp4tr-0.) S 14072 14073 1511 34817 1511 4202496 377 0 0 0 0 0 0 0 18 0 1 0 3318915 2633728 274 1283457024 134512640 135304128 4292282272 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/14073/statm: 643 274 233 194 0 30 0
[pid=14074] ppid=14073 vsize=28328 CPUtime=1.76
/proc/14074/stat : 14074 (packup) S 14073 14073 1511 34817 1511 4202496 6663 5799 0 0 70 26 72 8 19 0 1 0 3318915 29007872 6430 1283457024 134512640 134752139 4287539952 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/14074/statm: 7082 6430 332 59 0 6246 0
[pid=14078] ppid=14074 vsize=1668 CPUtime=0
/proc/14078/stat : 14078 (sh) S 14074 14073 1511 34817 1511 4202496 145 0 0 0 0 0 0 0 19 0 1 0 3319093 1708032 123 1283457024 134512640 134593992 4294863504 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/14078/statm: 417 123 108 20 0 44 0
[pid=14079] ppid=14078 vsize=41196 CPUtime=1.32
/proc/14079/stat : 14079 (minisatp_32) R 14078 14073 1511 34817 1511 4202496 13940 0 0 0 122 10 0 0 25 0 1 0 3319093 42184704 9220 1283457024 134512640 135413687 4290614944 18446744073709551615 134960810 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/14079/statm: 10299 9220 107 220 0 10077 0
Current children cumulated CPU time (s) 3.08
Current children cumulated vsize (KiB) 73764

[startup+6.30486 s]
/proc/loadavg: 1.19 1.06 1.01 2/37 14081
/proc/meminfo: memFree=421392/1048576 swapFree=0/0
[pid=14073] ppid=14072 vsize=2572 CPUtime=0
/proc/14073/stat : 14073 (packup2mp4tr-0.) S 14072 14073 1511 34817 1511 4202496 377 0 0 0 0 0 0 0 18 0 1 0 3318915 2633728 274 1283457024 134512640 135304128 4292282272 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/14073/statm: 643 274 233 194 0 30 0
[pid=14074] ppid=14073 vsize=28336 CPUtime=6.12
/proc/14074/stat : 14074 (packup) S 14073 14073 1511 34817 1511 4202496 6781 42106 0 0 83 48 449 32 18 0 1 0 3318915 29016064 6436 1283457024 134512640 134752139 4287539952 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/14074/statm: 7084 6436 332 59 0 6248 0
Current children cumulated CPU time (s) 6.12
Current children cumulated vsize (KiB) 30908

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

[startup+6.50492 s]
/proc/loadavg: 1.19 1.06 1.01 2/37 14081
/proc/meminfo: memFree=421392/1048576 swapFree=0/0
[pid=14073] ppid=14072 vsize=2572 CPUtime=0
/proc/14073/stat : 14073 (packup2mp4tr-0.) S 14072 14073 1511 34817 1511 4202496 377 0 0 0 0 0 0 0 18 0 1 0 3318915 2633728 274 1283457024 134512640 135304128 4292282272 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/14073/statm: 643 274 233 194 0 30 0
[pid=14074] ppid=14073 vsize=28336 CPUtime=6.12
/proc/14074/stat : 14074 (packup) S 14073 14073 1511 34817 1511 4202496 6781 42106 0 0 83 48 449 32 18 0 1 0 3318915 29016064 6436 1283457024 134512640 134752139 4287539952 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/14074/statm: 7084 6436 332 59 0 6248 0
Current children cumulated CPU time (s) 6.12
Current children cumulated vsize (KiB) 30908

[startup+8.10528 s]
/proc/loadavg: 1.19 1.06 1.01 2/37 14083
/proc/meminfo: memFree=416440/1048576 swapFree=0/0
[pid=14073] ppid=14072 vsize=2572 CPUtime=0
/proc/14073/stat : 14073 (packup2mp4tr-0.) S 14072 14073 1511 34817 1511 4202496 377 0 0 0 0 0 0 0 18 0 1 0 3318915 2633728 274 1283457024 134512640 135304128 4292282272 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/14073/statm: 643 274 233 194 0 30 0
[pid=14074] ppid=14073 vsize=28336 CPUtime=6.12
/proc/14074/stat : 14074 (packup) S 14073 14073 1511 34817 1511 4202496 6781 42106 0 0 83 48 449 32 18 0 1 0 3318915 29016064 6436 1283457024 134512640 134752139 4287539952 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/14074/statm: 7084 6436 332 59 0 6248 0
[pid=14082] ppid=14074 vsize=1676 CPUtime=0
/proc/14082/stat : 14082 (sh) S 14074 14073 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 19 0 1 0 3319530 1716224 124 1283457024 134512640 134593992 4290295344 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/14082/statm: 419 124 108 20 0 46 0
[pid=14083] ppid=14082 vsize=57476 CPUtime=1.96
/proc/14083/stat : 14083 (minisatp_32) R 14082 14073 1511 34817 1511 4202496 20082 0 0 0 180 16 0 0 25 0 1 0 3319530 58855424 12625 1283457024 134512640 135413687 4291485552 18446744073709551615 134689964 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/14083/statm: 14369 12625 94 220 0 14147 0
Current children cumulated CPU time (s) 8.08
Current children cumulated vsize (KiB) 90060

[startup+8.90556 s]
/proc/loadavg: 1.18 1.06 1.01 2/37 14083
/proc/meminfo: memFree=401064/1048576 swapFree=0/0
[pid=14073] ppid=14072 vsize=2572 CPUtime=0
/proc/14073/stat : 14073 (packup2mp4tr-0.) S 14072 14073 1511 34817 1511 4202496 377 0 0 0 0 0 0 0 18 0 1 0 3318915 2633728 274 1283457024 134512640 135304128 4292282272 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/14073/statm: 643 274 233 194 0 30 0
[pid=14074] ppid=14073 vsize=28336 CPUtime=6.12
/proc/14074/stat : 14074 (packup) S 14073 14073 1511 34817 1511 4202496 6781 42106 0 0 83 48 449 32 18 0 1 0 3318915 29016064 6436 1283457024 134512640 134752139 4287539952 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/14074/statm: 7084 6436 332 59 0 6248 0
[pid=14082] ppid=14074 vsize=1676 CPUtime=0
/proc/14082/stat : 14082 (sh) S 14074 14073 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 19 0 1 0 3319530 1716224 124 1283457024 134512640 134593992 4290295344 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/14082/statm: 419 124 108 20 0 46 0
[pid=14083] ppid=14082 vsize=73340 CPUtime=2.75
/proc/14083/stat : 14083 (minisatp_32) R 14082 14073 1511 34817 1511 4202496 26265 0 0 0 257 18 0 0 25 0 1 0 3319530 75100160 16509 1283457024 134512640 135413687 4291485552 18446744073709551615 134698551 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/14083/statm: 18335 16509 107 220 0 18113 0
Current children cumulated CPU time (s) 8.87
Current children cumulated vsize (KiB) 105924

[startup+9.30646 s]
/proc/loadavg: 1.18 1.06 1.01 2/37 14083
/proc/meminfo: memFree=401064/1048576 swapFree=0/0
[pid=14073] ppid=14072 vsize=2572 CPUtime=0
/proc/14073/stat : 14073 (packup2mp4tr-0.) S 14072 14073 1511 34817 1511 4202496 377 0 0 0 0 0 0 0 18 0 1 0 3318915 2633728 274 1283457024 134512640 135304128 4292282272 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/14073/statm: 643 274 233 194 0 30 0
[pid=14074] ppid=14073 vsize=28340 CPUtime=9.29
/proc/14074/stat : 14074 (packup) R 14073 14073 1511 34817 1511 4202496 8161 69030 0 0 84 49 742 54 18 0 1 0 3318915 29020160 6450 1283457024 134512640 134752139 4287539952 18446744073709551615 134525484 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/14074/statm: 7085 6450 345 59 0 6249 0
Current children cumulated CPU time (s) 9.29
Current children cumulated vsize (KiB) 30912

Child status: 0
Real time (s): 9.36325
CPU time (s): 9.35658
CPU user time (s): 8.30852
CPU system time (s): 1.04806
CPU usage (%): 99.9289
Max. virtual memory (cumulated for all children) (KiB): 105924

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 8.30852
system time used= 1.04807
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 81988
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= 19
involuntary context switches= 174

runsolver used 0 second user time and 0 second system time

The end