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/201108251442/packup2mp4pa-0.6/rand438.cudf.user-upgrades.log.runsolver ./packup2mp4pa-0.6 /home/misc2010/data/2011/user-upgrades/rand438.cudf /home/misc2010/tmp/201108251442/packup2mp4pa-0.6/rand438.cudf.user-upgrades.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.36 1.29 1.12 4/34 19180 /proc/meminfo: memFree=286220/1048576 swapFree=0/0 [pid=19179] ppid=19178 vsize=2568 CPUtime=0 /proc/19179/stat : 19179 (packup2mp4pa-0.) S 19178 19179 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11110924 2629632 274 1283457024 134512640 135304128 4292847648 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/19179/statm: 642 274 233 194 0 29 0 [pid=19180] ppid=19179 vsize=3716 CPUtime=0 /proc/19180/stat : 19180 (packup) R 19179 19179 4778 34817 4778 4202496 433 0 0 0 0 0 0 0 25 0 1 0 11110924 3805184 362 1283457024 134512640 134752139 4291171936 18446744073709551615 134681652 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/19180/statm: 929 362 286 59 0 93 0 [startup+0.135831 s] /proc/loadavg: 1.36 1.29 1.12 4/34 19180 /proc/meminfo: memFree=286220/1048576 swapFree=0/0 [pid=19179] ppid=19178 vsize=2568 CPUtime=0 /proc/19179/stat : 19179 (packup2mp4pa-0.) S 19178 19179 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11110924 2629632 274 1283457024 134512640 135304128 4292847648 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/19179/statm: 642 274 233 194 0 29 0 [pid=19180] ppid=19179 vsize=7956 CPUtime=0.14 /proc/19180/stat : 19180 (packup) R 19179 19179 4778 34817 4778 4202496 1473 0 0 0 14 0 0 0 25 0 1 0 11110924 8146944 1402 1283457024 134512640 134752139 4291171936 18446744073709551615 134681863 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/19180/statm: 1989 1402 286 59 0 1153 0 Current children cumulated CPU time (s) 0.14 Current children cumulated vsize (KiB) 10524 [startup+0.21586 s] /proc/loadavg: 1.36 1.29 1.12 4/34 19180 /proc/meminfo: memFree=286220/1048576 swapFree=0/0 [pid=19179] ppid=19178 vsize=2568 CPUtime=0 /proc/19179/stat : 19179 (packup2mp4pa-0.) S 19178 19179 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11110924 2629632 274 1283457024 134512640 135304128 4292847648 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/19179/statm: 642 274 233 194 0 29 0 [pid=19180] ppid=19179 vsize=10200 CPUtime=0.21 /proc/19180/stat : 19180 (packup) R 19179 19179 4778 34817 4778 4202496 2024 0 0 0 21 0 0 0 25 0 1 0 11110924 10444800 1953 1283457024 134512640 134752139 4291171936 18446744073709551615 134681826 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/19180/statm: 2550 1953 286 59 0 1714 0 Current children cumulated CPU time (s) 0.21 Current children cumulated vsize (KiB) 12768 [startup+0.315886 s] /proc/loadavg: 1.36 1.29 1.12 4/34 19180 /proc/meminfo: memFree=286220/1048576 swapFree=0/0 [pid=19179] ppid=19178 vsize=2568 CPUtime=0 /proc/19179/stat : 19179 (packup2mp4pa-0.) S 19178 19179 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11110924 2629632 274 1283457024 134512640 135304128 4292847648 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/19179/statm: 642 274 233 194 0 29 0 [pid=19180] ppid=19179 vsize=12600 CPUtime=0.31 /proc/19180/stat : 19180 (packup) R 19179 19179 4778 34817 4778 4202496 2639 0 0 0 31 0 0 0 25 0 1 0 11110924 12902400 2568 1283457024 134512640 134752139 4291171936 18446744073709551615 134682079 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/19180/statm: 3150 2568 286 59 0 2314 0 Current children cumulated CPU time (s) 0.31 Current children cumulated vsize (KiB) 15168 [startup+0.706031 s] /proc/loadavg: 1.36 1.29 1.12 4/34 19180 /proc/meminfo: memFree=286220/1048576 swapFree=0/0 [pid=19179] ppid=19178 vsize=2568 CPUtime=0 /proc/19179/stat : 19179 (packup2mp4pa-0.) S 19178 19179 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11110924 2629632 274 1283457024 134512640 135304128 4292847648 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/19179/statm: 642 274 233 194 0 29 0 [pid=19180] ppid=19179 vsize=21392 CPUtime=0.7 /proc/19180/stat : 19180 (packup) R 19179 19179 4778 34817 4778 4202496 4837 0 0 0 69 1 0 0 25 0 1 0 11110924 21905408 4766 1283457024 134512640 134752139 4291171936 18446744073709551615 134681798 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/19180/statm: 5348 4766 286 59 0 4512 0 Current children cumulated CPU time (s) 0.7 Current children cumulated vsize (KiB) 23960 [startup+1.50624 s] /proc/loadavg: 1.36 1.29 1.12 2/35 19181 /proc/meminfo: memFree=260276/1048576 swapFree=0/0 [pid=19179] ppid=19178 vsize=2568 CPUtime=0 /proc/19179/stat : 19179 (packup2mp4pa-0.) S 19178 19179 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11110924 2629632 274 1283457024 134512640 135304128 4292847648 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/19179/statm: 642 274 233 194 0 29 0 [pid=19180] ppid=19179 vsize=37376 CPUtime=1.44 /proc/19180/stat : 19180 (packup) S 19179 19179 4778 34817 4778 4202496 8878 0 0 0 138 6 0 0 25 0 1 0 11110924 38273024 8757 1283457024 134512640 134752139 4291171936 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/19180/statm: 9344 8757 324 59 0 8508 0 Current children cumulated CPU time (s) 1.44 Current children cumulated vsize (KiB) 39944 Solver just ended. Dumping a history of the last processes samples [startup+1.60626 s] /proc/loadavg: 1.36 1.29 1.12 2/35 19181 /proc/meminfo: memFree=260276/1048576 swapFree=0/0 [pid=19179] ppid=19178 vsize=2568 CPUtime=0 /proc/19179/stat : 19179 (packup2mp4pa-0.) S 19178 19179 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11110924 2629632 274 1283457024 134512640 135304128 4292847648 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/19179/statm: 642 274 233 194 0 29 0 [pid=19180] ppid=19179 vsize=37376 CPUtime=1.44 /proc/19180/stat : 19180 (packup) S 19179 19179 4778 34817 4778 4202496 8878 0 0 0 138 6 0 0 25 0 1 0 11110924 38273024 8757 1283457024 134512640 134752139 4291171936 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/19180/statm: 9344 8757 324 59 0 8508 0 Current children cumulated CPU time (s) 1.44 Current children cumulated vsize (KiB) 39944 [startup+2.40652 s] /proc/loadavg: 1.36 1.29 1.12 2/37 19185 /proc/meminfo: memFree=246976/1048576 swapFree=0/0 [pid=19179] ppid=19178 vsize=2568 CPUtime=0 /proc/19179/stat : 19179 (packup2mp4pa-0.) S 19178 19179 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11110924 2629632 274 1283457024 134512640 135304128 4292847648 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/19179/statm: 642 274 233 194 0 29 0 [pid=19180] ppid=19179 vsize=37380 CPUtime=1.94 /proc/19180/stat : 19180 (packup) S 19179 19179 4778 34817 4778 4202496 8924 4485 0 0 140 10 38 6 21 0 1 0 11110924 38277120 8766 1283457024 134512640 134752139 4291171936 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/19180/statm: 9345 8766 332 59 0 8509 0 [pid=19184] ppid=19180 vsize=1672 CPUtime=0 /proc/19184/stat : 19184 (sh) S 19180 19179 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 21 0 1 0 11111121 1712128 123 1283457024 134512640 134593992 4287011600 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0 /proc/19184/statm: 418 123 108 20 0 45 0 [pid=19185] ppid=19184 vsize=20036 CPUtime=0.43 /proc/19185/stat : 19185 (minisatp_32) R 19184 19179 4778 34817 4778 4202496 6540 0 0 0 39 4 0 0 25 0 1 0 11111121 20516864 4624 1283457024 134512640 135413687 4294822560 18446744073709551615 134686562 0 0 18944 0 0 0 0 17 0 0 0 0 /proc/19185/statm: 5009 4624 108 220 0 4787 0 Current children cumulated CPU time (s) 2.37 Current children cumulated vsize (KiB) 61656 [startup+2.60659 s] /proc/loadavg: 1.36 1.29 1.12 2/37 19185 /proc/meminfo: memFree=246976/1048576 swapFree=0/0 [pid=19179] ppid=19178 vsize=2568 CPUtime=0 /proc/19179/stat : 19179 (packup2mp4pa-0.) S 19178 19179 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11110924 2629632 274 1283457024 134512640 135304128 4292847648 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/19179/statm: 642 274 233 194 0 29 0 [pid=19180] ppid=19179 vsize=37380 CPUtime=1.94 /proc/19180/stat : 19180 (packup) S 19179 19179 4778 34817 4778 4202496 8924 4485 0 0 140 10 38 6 21 0 1 0 11110924 38277120 8766 1283457024 134512640 134752139 4291171936 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/19180/statm: 9345 8766 332 59 0 8509 0 [pid=19184] ppid=19180 vsize=1672 CPUtime=0 /proc/19184/stat : 19184 (sh) S 19180 19179 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 21 0 1 0 11111121 1712128 123 1283457024 134512640 134593992 4287011600 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0 /proc/19184/statm: 418 123 108 20 0 45 0 [pid=19185] ppid=19184 vsize=23760 CPUtime=0.63 /proc/19185/stat : 19185 (minisatp_32) R 19184 19179 4778 34817 4778 4202496 8115 0 0 0 59 4 0 0 25 0 1 0 11111121 24330240 5322 1283457024 134512640 135413687 4294822560 18446744073709551615 134696701 0 0 18944 0 0 0 0 17 0 0 0 0 /proc/19185/statm: 5940 5322 108 220 0 5718 0 Current children cumulated CPU time (s) 2.57 Current children cumulated vsize (KiB) 65380 [startup+2.71663 s] /proc/loadavg: 1.36 1.29 1.12 2/37 19185 /proc/meminfo: memFree=246976/1048576 swapFree=0/0 [pid=19179] ppid=19178 vsize=2568 CPUtime=0 /proc/19179/stat : 19179 (packup2mp4pa-0.) S 19178 19179 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11110924 2629632 274 1283457024 134512640 135304128 4292847648 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/19179/statm: 642 274 233 194 0 29 0 [pid=19180] ppid=19179 vsize=36424 CPUtime=2.71 /proc/19180/stat : 19180 (packup) R 19179 19179 4778 34817 4778 4202496 17093 13115 0 0 146 12 102 11 15 0 1 0 11110924 37298176 8586 1283457024 134512640 134752139 4291171936 18446744073709551615 134555056 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/19180/statm: 9106 8586 345 59 0 8270 0 Current children cumulated CPU time (s) 2.71 Current children cumulated vsize (KiB) 38992 Child status: 0 Real time (s): 2.72451 CPU time (s): 2.72017 CPU user time (s): 2.48816 CPU system time (s): 0.232014 CPU usage (%): 99.8406 Max. virtual memory (cumulated for all children) (KiB): 65380 getrusage(RUSAGE_CHILDREN,...) data: user time used= 2.48815 system time used= 0.232014 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 30679 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= 11 involuntary context switches= 56 runsolver used 0 second user time and 0 second system time The end