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/rand600.cudf.s.log.runsolver ./packup2hy4tr-0.6 /home/misc2010/data/2011/incremental/s/rand600.cudf /home/misc2010/tmp/201108281254/packup2hy4tr-0.6/rand600.cudf.s.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.07 1.02 0.98 4/37 20152
/proc/meminfo: memFree=291264/1048576 swapFree=0/0
[pid=20151] ppid=20150 vsize=2568 CPUtime=0
/proc/20151/stat : 20151 (packup2hy4tr-0.) S 20150 20151 17551 34817 17551 4202496 378 0 0 0 0 0 0 0 18 0 1 0 35697266 2629632 274 1283457024 134512640 135304128 4287947648 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/20151/statm: 642 274 233 194 0 29 0
[pid=20152] ppid=20151 vsize=3420 CPUtime=0.01
/proc/20152/stat : 20152 (packup) R 20151 20151 17551 34817 17551 4202496 246 0 0 0 1 0 0 0 25 0 1 0 35697267 3502080 175 1283457024 134512640 134752139 4291135088 18446744073709551615 4159115520 0 0 0 0 0 0 0 17 0 0 0 0
/proc/20152/statm: 855 175 147 59 0 19 0

[startup+0.200197 s]
/proc/loadavg: 1.07 1.02 0.98 4/37 20152
/proc/meminfo: memFree=291264/1048576 swapFree=0/0
[pid=20151] ppid=20150 vsize=2568 CPUtime=0
/proc/20151/stat : 20151 (packup2hy4tr-0.) S 20150 20151 17551 34817 17551 4202496 378 0 0 0 0 0 0 0 18 0 1 0 35697266 2629632 274 1283457024 134512640 135304128 4287947648 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/20151/statm: 642 274 233 194 0 29 0
[pid=20152] ppid=20151 vsize=8648 CPUtime=0.14
/proc/20152/stat : 20152 (packup) D 20151 20151 17551 34817 17551 4202496 1657 0 0 0 14 0 0 0 25 0 1 0 35697267 8855552 1585 1283457024 134512640 134752139 4291135088 18446744073709551615 4294960130 0 0 18944 8192 18446744071564332000 0 0 17 0 0 0 0
/proc/20152/statm: 2162 1585 286 59 0 1326 0
Current children cumulated CPU time (s) 0.14
Current children cumulated vsize (KiB) 11216

[startup+0.304183 s]
/proc/loadavg: 1.07 1.02 0.98 4/37 20152
/proc/meminfo: memFree=291264/1048576 swapFree=0/0
[pid=20151] ppid=20150 vsize=2568 CPUtime=0
/proc/20151/stat : 20151 (packup2hy4tr-0.) S 20150 20151 17551 34817 17551 4202496 378 0 0 0 0 0 0 0 18 0 1 0 35697266 2629632 274 1283457024 134512640 135304128 4287947648 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/20151/statm: 642 274 233 194 0 29 0
[pid=20152] ppid=20151 vsize=10316 CPUtime=0.18
/proc/20152/stat : 20152 (packup) R 20151 20151 17551 34817 17551 4202496 2081 0 0 0 18 0 0 0 25 0 1 0 35697267 10563584 2009 1283457024 134512640 134752139 4291135088 18446744073709551615 4157309702 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/20152/statm: 2579 2009 286 59 0 1743 0
Current children cumulated CPU time (s) 0.18
Current children cumulated vsize (KiB) 12884

[startup+0.404188 s]
/proc/loadavg: 1.07 1.02 0.98 4/37 20152
/proc/meminfo: memFree=291264/1048576 swapFree=0/0
[pid=20151] ppid=20150 vsize=2568 CPUtime=0
/proc/20151/stat : 20151 (packup2hy4tr-0.) S 20150 20151 17551 34817 17551 4202496 378 0 0 0 0 0 0 0 18 0 1 0 35697266 2629632 274 1283457024 134512640 135304128 4287947648 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/20151/statm: 642 274 233 194 0 29 0
[pid=20152] ppid=20151 vsize=14792 CPUtime=0.26
/proc/20152/stat : 20152 (packup) D 20151 20151 17551 34817 17551 4202496 3233 0 0 0 25 1 0 0 25 0 1 0 35697267 15147008 3161 1283457024 134512640 134752139 4291135088 18446744073709551615 4294960130 0 0 18944 8192 18446744071696440003 0 0 17 0 0 0 0
/proc/20152/statm: 3698 3161 321 59 0 2862 0
Current children cumulated CPU time (s) 0.26
Current children cumulated vsize (KiB) 17360

[startup+0.714009 s]
/proc/loadavg: 1.07 1.02 0.98 4/37 20152
/proc/meminfo: memFree=291264/1048576 swapFree=0/0
[pid=20151] ppid=20150 vsize=2568 CPUtime=0
/proc/20151/stat : 20151 (packup2hy4tr-0.) S 20150 20151 17551 34817 17551 4202496 378 0 0 0 0 0 0 0 18 0 1 0 35697266 2629632 274 1283457024 134512640 135304128 4287947648 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/20151/statm: 642 274 233 194 0 29 0
[pid=20152] ppid=20151 vsize=15372 CPUtime=0.54
/proc/20152/stat : 20152 (packup) R 20151 20151 17551 34817 17551 4202496 3477 2543 0 0 26 7 19 2 23 0 1 0 35697267 15740928 3250 1283457024 134512640 134752139 4291135088 18446744073709551615 4294960130 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/20152/statm: 3843 3250 332 59 0 3007 0
Current children cumulated CPU time (s) 0.54
Current children cumulated vsize (KiB) 17940

[startup+1.5142 s]
/proc/loadavg: 1.07 1.02 0.98 2/41 20171
/proc/meminfo: memFree=271068/1048576 swapFree=0/0
[pid=20151] ppid=20150 vsize=2568 CPUtime=0
/proc/20151/stat : 20151 (packup2hy4tr-0.) S 20150 20151 17551 34817 17551 4202496 378 0 0 0 0 0 0 0 18 0 1 0 35697266 2629632 274 1283457024 134512640 135304128 4287947648 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/20151/statm: 642 274 233 194 0 29 0
[pid=20152] ppid=20151 vsize=15376 CPUtime=0.87
/proc/20152/stat : 20152 (packup) S 20151 20151 17551 34817 17551 4202496 3518 5099 0 0 31 13 40 3 22 0 1 0 35697267 15745024 3251 1283457024 134512640 134752139 4291135088 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/20152/statm: 3844 3251 332 59 0 3008 0
[pid=20166] ppid=20152 vsize=1672 CPUtime=0
/proc/20166/stat : 20166 (sh) S 20152 20151 17551 34817 17551 4202496 145 0 0 0 0 0 0 0 22 0 1 0 35697371 1712128 123 1283457024 134512640 134593992 4294105568 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/20166/statm: 418 123 108 20 0 45 0
[pid=20167] ppid=20166 vsize=2568 CPUtime=0
/proc/20167/stat : 20167 (run_h) S 20166 20151 17551 34817 17551 4202496 365 612 0 0 0 0 0 0 25 0 1 0 35697371 2629632 272 1283457024 134512640 135304128 4289969664 18446744073709551615 4294960130 0 65536 18948 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/20167/statm: 642 272 232 194 0 29 0
[pid=20171] ppid=20167 vsize=18748 CPUtime=0.46
/proc/20171/stat : 20171 (minisatp_32) R 20167 20151 17551 34817 17551 4202496 6341 0 0 0 44 2 0 0 25 0 1 0 35697372 19197952 4202 1283457024 134512640 135413687 4289484160 18446744073709551615 134699053 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/20171/statm: 4687 4202 107 220 0 4465 0
Current children cumulated CPU time (s) 1.33
Current children cumulated vsize (KiB) 40932

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

[startup+1.71425 s]
/proc/loadavg: 1.07 1.02 0.98 2/41 20171
/proc/meminfo: memFree=271068/1048576 swapFree=0/0
[pid=20151] ppid=20150 vsize=2568 CPUtime=0
/proc/20151/stat : 20151 (packup2hy4tr-0.) S 20150 20151 17551 34817 17551 4202496 378 0 0 0 0 0 0 0 18 0 1 0 35697266 2629632 274 1283457024 134512640 135304128 4287947648 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/20151/statm: 642 274 233 194 0 29 0
[pid=20152] ppid=20151 vsize=15376 CPUtime=0.87
/proc/20152/stat : 20152 (packup) S 20151 20151 17551 34817 17551 4202496 3518 5099 0 0 31 13 40 3 22 0 1 0 35697267 15745024 3251 1283457024 134512640 134752139 4291135088 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/20152/statm: 3844 3251 332 59 0 3008 0
[pid=20166] ppid=20152 vsize=1672 CPUtime=0
/proc/20166/stat : 20166 (sh) S 20152 20151 17551 34817 17551 4202496 145 0 0 0 0 0 0 0 22 0 1 0 35697371 1712128 123 1283457024 134512640 134593992 4294105568 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/20166/statm: 418 123 108 20 0 45 0
[pid=20167] ppid=20166 vsize=2568 CPUtime=0
/proc/20167/stat : 20167 (run_h) S 20166 20151 17551 34817 17551 4202496 365 612 0 0 0 0 0 0 25 0 1 0 35697371 2629632 272 1283457024 134512640 135304128 4289969664 18446744073709551615 4294960130 0 65536 18948 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/20167/statm: 642 272 232 194 0 29 0
[pid=20171] ppid=20167 vsize=27748 CPUtime=0.66
/proc/20171/stat : 20171 (minisatp_32) R 20167 20151 17551 34817 17551 4202496 9194 0 0 0 61 5 0 0 25 0 1 0 35697372 28413952 6172 1283457024 134512640 135413687 4289484160 18446744073709551615 134648894 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/20171/statm: 6937 6172 109 220 0 6715 0
Current children cumulated CPU time (s) 1.53
Current children cumulated vsize (KiB) 49932

[startup+1.90431 s]
/proc/loadavg: 1.07 1.02 0.98 2/41 20171
/proc/meminfo: memFree=271068/1048576 swapFree=0/0
[pid=20151] ppid=20150 vsize=2568 CPUtime=0
/proc/20151/stat : 20151 (packup2hy4tr-0.) S 20150 20151 17551 34817 17551 4202496 378 0 0 0 0 0 0 0 18 0 1 0 35697266 2629632 274 1283457024 134512640 135304128 4287947648 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/20151/statm: 642 274 233 194 0 29 0
[pid=20152] ppid=20151 vsize=15376 CPUtime=0.87
/proc/20152/stat : 20152 (packup) S 20151 20151 17551 34817 17551 4202496 3518 5099 0 0 31 13 40 3 22 0 1 0 35697267 15745024 3251 1283457024 134512640 134752139 4291135088 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/20152/statm: 3844 3251 332 59 0 3008 0
[pid=20166] ppid=20152 vsize=1672 CPUtime=0
/proc/20166/stat : 20166 (sh) S 20152 20151 17551 34817 17551 4202496 145 0 0 0 0 0 0 0 22 0 1 0 35697371 1712128 123 1283457024 134512640 134593992 4294105568 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/20166/statm: 418 123 108 20 0 45 0
[pid=20167] ppid=20166 vsize=2568 CPUtime=0
/proc/20167/stat : 20167 (run_h) S 20166 20151 17551 34817 17551 4202496 365 612 0 0 0 0 0 0 25 0 1 0 35697371 2629632 272 1283457024 134512640 135304128 4289969664 18446744073709551615 4294960130 0 65536 18948 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/20167/statm: 642 272 232 194 0 29 0
[pid=20171] ppid=20167 vsize=29764 CPUtime=0.85
/proc/20171/stat : 20171 (minisatp_32) R 20167 20151 17551 34817 17551 4202496 10377 0 0 0 78 7 0 0 25 0 1 0 35697372 30478336 6563 1283457024 134512640 135413687 4289484160 18446744073709551615 134649574 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/20171/statm: 7441 6563 109 220 0 7219 0
Current children cumulated CPU time (s) 1.72
Current children cumulated vsize (KiB) 51948

[startup+2.00436 s]
/proc/loadavg: 1.07 1.02 0.98 2/41 20171
/proc/meminfo: memFree=271068/1048576 swapFree=0/0
[pid=20151] ppid=20150 vsize=2568 CPUtime=0
/proc/20151/stat : 20151 (packup2hy4tr-0.) S 20150 20151 17551 34817 17551 4202496 378 0 0 0 0 0 0 0 18 0 1 0 35697266 2629632 274 1283457024 134512640 135304128 4287947648 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/20151/statm: 642 274 233 194 0 29 0
[pid=20152] ppid=20151 vsize=15380 CPUtime=1.83
/proc/20152/stat : 20152 (packup) R 20151 20151 17551 34817 17551 4202496 5482 16668 0 0 31 15 125 12 18 0 1 0 35697267 15749120 3265 1283457024 134512640 134752139 4291135088 18446744073709551615 4159258820 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/20152/statm: 3845 3265 345 59 0 3009 0
Current children cumulated CPU time (s) 1.83
Current children cumulated vsize (KiB) 17948

Child status: 0
Real time (s): 2.02091
CPU time (s): 1.85612
CPU user time (s): 1.5841
CPU system time (s): 0.272017
CPU usage (%): 91.8456
Max. virtual memory (cumulated for all children) (KiB): 53624

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 1.5841
system time used= 0.272017
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 23363
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= 50
involuntary context switches= 95

runsolver used 0 second user time and 0 second system time

The end