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/978532fa-c730-11df-b070-00163e3d3b7c.cudf.dudf-real.log.runsolver ./packup2mp4pa-0.6 /home/misc2010/data/2011/dudf-real//978532fa-c730-11df-b070-00163e3d3b7c.cudf /home/misc2010/tmp/201108251442/packup2mp4pa-0.6/978532fa-c730-11df-b070-00163e3d3b7c.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.40 1.42 1.31 5/34 26508 /proc/meminfo: memFree=312304/1048576 swapFree=0/0 [pid=26507] ppid=26506 vsize=2572 CPUtime=0 /proc/26507/stat : 26507 (packup2mp4pa-0.) S 26506 26507 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 11215405 2633728 275 1283457024 134512640 135304128 4288369584 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/26507/statm: 643 275 233 194 0 30 0 [pid=26508] ppid=26507 vsize=4112 CPUtime=0.02 /proc/26508/stat : 26508 (packup) R 26507 26507 4778 34817 4778 4202496 518 0 0 0 2 0 0 0 25 0 1 0 11215405 4210688 446 1283457024 134512640 134752139 4293093376 18446744073709551615 134681493 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/26508/statm: 1028 446 286 59 0 192 0 [startup+0.2242 s] /proc/loadavg: 1.40 1.42 1.31 5/34 26508 /proc/meminfo: memFree=312304/1048576 swapFree=0/0 [pid=26507] ppid=26506 vsize=2572 CPUtime=0 /proc/26507/stat : 26507 (packup2mp4pa-0.) S 26506 26507 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 11215405 2633728 275 1283457024 134512640 135304128 4288369584 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/26507/statm: 643 275 233 194 0 30 0 [pid=26508] ppid=26507 vsize=10992 CPUtime=0.23 /proc/26508/stat : 26508 (packup) R 26507 26507 4778 34817 4778 4202496 2239 0 0 0 23 0 0 0 25 0 1 0 11215405 11255808 2167 1283457024 134512640 134752139 4293093376 18446744073709551615 134681770 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/26508/statm: 2748 2167 286 59 0 1912 0 Current children cumulated CPU time (s) 0.23 Current children cumulated vsize (KiB) 13564 [startup+0.304216 s] /proc/loadavg: 1.40 1.42 1.31 5/34 26508 /proc/meminfo: memFree=312304/1048576 swapFree=0/0 [pid=26507] ppid=26506 vsize=2572 CPUtime=0 /proc/26507/stat : 26507 (packup2mp4pa-0.) S 26506 26507 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 11215405 2633728 275 1283457024 134512640 135304128 4288369584 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/26507/statm: 643 275 233 194 0 30 0 [pid=26508] ppid=26507 vsize=13088 CPUtime=0.31 /proc/26508/stat : 26508 (packup) R 26507 26507 4778 34817 4778 4202496 2777 0 0 0 31 0 0 0 25 0 1 0 11215405 13402112 2705 1283457024 134512640 134752139 4293093376 18446744073709551615 134682016 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/26508/statm: 3272 2705 286 59 0 2436 0 Current children cumulated CPU time (s) 0.31 Current children cumulated vsize (KiB) 15660 [startup+0.404243 s] /proc/loadavg: 1.40 1.42 1.31 5/34 26508 /proc/meminfo: memFree=312304/1048576 swapFree=0/0 [pid=26507] ppid=26506 vsize=2572 CPUtime=0 /proc/26507/stat : 26507 (packup2mp4pa-0.) S 26506 26507 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 11215405 2633728 275 1283457024 134512640 135304128 4288369584 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/26507/statm: 643 275 233 194 0 30 0 [pid=26508] ppid=26507 vsize=15596 CPUtime=0.4 /proc/26508/stat : 26508 (packup) R 26507 26507 4778 34817 4778 4202496 3402 0 0 0 40 0 0 0 25 0 1 0 11215405 15970304 3330 1283457024 134512640 134752139 4293093376 18446744073709551615 4157285643 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/26508/statm: 3899 3330 286 59 0 3063 0 Current children cumulated CPU time (s) 0.4 Current children cumulated vsize (KiB) 18168 [startup+0.704309 s] /proc/loadavg: 1.40 1.42 1.31 5/34 26508 /proc/meminfo: memFree=312304/1048576 swapFree=0/0 [pid=26507] ppid=26506 vsize=2572 CPUtime=0 /proc/26507/stat : 26507 (packup2mp4pa-0.) S 26506 26507 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 11215405 2633728 275 1283457024 134512640 135304128 4288369584 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/26507/statm: 643 275 233 194 0 30 0 [pid=26508] ppid=26507 vsize=22804 CPUtime=0.7 /proc/26508/stat : 26508 (packup) R 26507 26507 4778 34817 4778 4202496 5182 0 0 0 70 0 0 0 25 0 1 0 11215405 23351296 5110 1283457024 134512640 134752139 4293093376 18446744073709551615 134706154 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/26508/statm: 5701 5110 286 59 0 4865 0 Current children cumulated CPU time (s) 0.7 Current children cumulated vsize (KiB) 25376 [startup+1.5045 s] /proc/loadavg: 1.40 1.42 1.31 2/35 26509 /proc/meminfo: memFree=279360/1048576 swapFree=0/0 [pid=26507] ppid=26506 vsize=2572 CPUtime=0 /proc/26507/stat : 26507 (packup2mp4pa-0.) S 26506 26507 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 11215405 2633728 275 1283457024 134512640 135304128 4288369584 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/26507/statm: 643 275 233 194 0 30 0 [pid=26508] ppid=26507 vsize=47728 CPUtime=1.49 /proc/26508/stat : 26508 (packup) R 26507 26507 4778 34817 4778 4202496 11568 0 0 0 139 10 0 0 25 0 1 0 11215405 48873472 11181 1283457024 134512640 134752139 4293093376 18446744073709551615 4294960130 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/26508/statm: 11932 11181 321 59 0 11096 0 Current children cumulated CPU time (s) 1.49 Current children cumulated vsize (KiB) 50300 [startup+3.10482 s] /proc/loadavg: 1.40 1.42 1.31 2/37 26511 /proc/meminfo: memFree=254156/1048576 swapFree=0/0 [pid=26507] ppid=26506 vsize=2572 CPUtime=0 /proc/26507/stat : 26507 (packup2mp4pa-0.) S 26506 26507 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 11215405 2633728 275 1283457024 134512640 135304128 4288369584 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/26507/statm: 643 275 233 194 0 30 0 [pid=26508] ppid=26507 vsize=47728 CPUtime=1.7 /proc/26508/stat : 26508 (packup) S 26507 26507 4778 34817 4778 4202496 11572 0 0 0 147 23 0 0 25 0 1 0 11215405 48873472 11184 1283457024 134512640 134752139 4293093376 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/26508/statm: 11932 11184 324 59 0 11096 0 [pid=26510] ppid=26508 vsize=1672 CPUtime=0 /proc/26510/stat : 26510 (sh) S 26508 26507 4778 34817 4778 4202496 146 0 0 0 0 0 0 0 25 0 1 0 11215575 1712128 124 1283457024 134512640 134593992 4291954624 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0 /proc/26510/statm: 418 124 108 20 0 45 0 [pid=26511] ppid=26510 vsize=32108 CPUtime=1.37 /proc/26511/stat : 26511 (minisatp_32) R 26510 26507 4778 34817 4778 4202496 7794 0 0 0 125 12 0 0 25 0 1 0 11215577 32878592 6918 1283457024 134512640 135413687 4294912688 18446744073709551615 134960945 0 0 18944 0 0 0 0 17 0 0 0 0 /proc/26511/statm: 8027 6918 85 220 0 7805 0 Current children cumulated CPU time (s) 3.07 Current children cumulated vsize (KiB) 84080 [startup+6.30561 s] /proc/loadavg: 1.37 1.41 1.31 2/37 26513 /proc/meminfo: memFree=259116/1048576 swapFree=0/0 [pid=26507] ppid=26506 vsize=2572 CPUtime=0 /proc/26507/stat : 26507 (packup2mp4pa-0.) S 26506 26507 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 11215405 2633728 275 1283457024 134512640 135304128 4288369584 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/26507/statm: 643 275 233 194 0 30 0 [pid=26508] ppid=26507 vsize=47732 CPUtime=5.26 /proc/26508/stat : 26508 (packup) S 26507 26507 4778 34817 4778 4202496 11650 27242 0 0 160 41 298 27 18 0 1 0 11215405 48877568 11193 1283457024 134512640 134752139 4293093376 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/26508/statm: 11933 11193 332 59 0 11097 0 [pid=26512] ppid=26508 vsize=1672 CPUtime=0.01 /proc/26512/stat : 26512 (sh) S 26508 26507 4778 34817 4778 4202496 146 0 0 0 0 1 0 0 18 0 1 0 11215936 1712128 124 1283457024 134512640 134593992 4290741920 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0 /proc/26512/statm: 418 124 108 20 0 45 0 [pid=26513] ppid=26512 vsize=25644 CPUtime=0.98 /proc/26513/stat : 26513 (minisatp_32) R 26512 26507 4778 34817 4778 4202496 5580 0 0 0 98 0 0 0 23 0 1 0 11215937 26259456 5053 1283457024 134512640 135413687 4294355504 18446744073709551615 134962797 0 0 18944 0 0 0 0 17 0 0 0 0 /proc/26513/statm: 6411 5053 77 220 0 6189 0 Current children cumulated CPU time (s) 6.25 Current children cumulated vsize (KiB) 77620 Solver just ended. Dumping a history of the last processes samples [startup+6.50565 s] /proc/loadavg: 1.37 1.41 1.31 2/37 26513 /proc/meminfo: memFree=259116/1048576 swapFree=0/0 [pid=26507] ppid=26506 vsize=2572 CPUtime=0 /proc/26507/stat : 26507 (packup2mp4pa-0.) S 26506 26507 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 11215405 2633728 275 1283457024 134512640 135304128 4288369584 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/26507/statm: 643 275 233 194 0 30 0 [pid=26508] ppid=26507 vsize=47732 CPUtime=5.26 /proc/26508/stat : 26508 (packup) S 26507 26507 4778 34817 4778 4202496 11650 27242 0 0 160 41 298 27 18 0 1 0 11215405 48877568 11193 1283457024 134512640 134752139 4293093376 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/26508/statm: 11933 11193 332 59 0 11097 0 [pid=26512] ppid=26508 vsize=1672 CPUtime=0.01 /proc/26512/stat : 26512 (sh) S 26508 26507 4778 34817 4778 4202496 146 0 0 0 0 1 0 0 18 0 1 0 11215936 1712128 124 1283457024 134512640 134593992 4290741920 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0 /proc/26512/statm: 418 124 108 20 0 45 0 [pid=26513] ppid=26512 vsize=30468 CPUtime=1.18 /proc/26513/stat : 26513 (minisatp_32) R 26512 26507 4778 34817 4778 4202496 6931 0 0 0 118 0 0 0 24 0 1 0 11215937 31199232 6273 1283457024 134512640 135413687 4294355504 18446744073709551615 134520273 0 0 18944 0 0 0 0 17 0 0 0 0 /proc/26513/statm: 7617 6273 83 220 0 7395 0 Current children cumulated CPU time (s) 6.45 Current children cumulated vsize (KiB) 82444 [startup+8.10608 s] /proc/loadavg: 1.37 1.41 1.31 2/37 26513 /proc/meminfo: memFree=170208/1048576 swapFree=0/0 [pid=26507] ppid=26506 vsize=2572 CPUtime=0 /proc/26507/stat : 26507 (packup2mp4pa-0.) S 26506 26507 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 11215405 2633728 275 1283457024 134512640 135304128 4288369584 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/26507/statm: 643 275 233 194 0 30 0 [pid=26508] ppid=26507 vsize=47732 CPUtime=5.26 /proc/26508/stat : 26508 (packup) S 26507 26507 4778 34817 4778 4202496 11650 27242 0 0 160 41 298 27 18 0 1 0 11215405 48877568 11193 1283457024 134512640 134752139 4293093376 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/26508/statm: 11933 11193 332 59 0 11097 0 [pid=26512] ppid=26508 vsize=1672 CPUtime=0.01 /proc/26512/stat : 26512 (sh) S 26508 26507 4778 34817 4778 4202496 146 0 0 0 0 1 0 0 18 0 1 0 11215936 1712128 124 1283457024 134512640 134593992 4290741920 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0 /proc/26512/statm: 418 124 108 20 0 45 0 [pid=26513] ppid=26512 vsize=121848 CPUtime=2.78 /proc/26513/stat : 26513 (minisatp_32) R 26512 26507 4778 34817 4778 4202496 32119 0 0 0 254 24 0 0 25 0 1 0 11215937 124772352 26575 1283457024 134512640 135413687 4294355504 18446744073709551615 134683810 0 0 18944 0 0 0 0 17 0 0 0 0 /proc/26513/statm: 30462 26575 107 220 0 30240 0 Current children cumulated CPU time (s) 8.05 Current children cumulated vsize (KiB) 173824 [startup+8.90631 s] /proc/loadavg: 1.34 1.41 1.30 2/37 26513 /proc/meminfo: memFree=163024/1048576 swapFree=0/0 [pid=26507] ppid=26506 vsize=2572 CPUtime=0 /proc/26507/stat : 26507 (packup2mp4pa-0.) S 26506 26507 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 11215405 2633728 275 1283457024 134512640 135304128 4288369584 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/26507/statm: 643 275 233 194 0 30 0 [pid=26508] ppid=26507 vsize=47732 CPUtime=5.26 /proc/26508/stat : 26508 (packup) S 26507 26507 4778 34817 4778 4202496 11650 27242 0 0 160 41 298 27 18 0 1 0 11215405 48877568 11193 1283457024 134512640 134752139 4293093376 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/26508/statm: 11933 11193 332 59 0 11097 0 [pid=26512] ppid=26508 vsize=1672 CPUtime=0.01 /proc/26512/stat : 26512 (sh) S 26508 26507 4778 34817 4778 4202496 146 0 0 0 0 1 0 0 18 0 1 0 11215936 1712128 124 1283457024 134512640 134593992 4290741920 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0 /proc/26512/statm: 418 124 108 20 0 45 0 [pid=26513] ppid=26512 vsize=112188 CPUtime=3.57 /proc/26513/stat : 26513 (minisatp_32) R 26512 26507 4778 34817 4778 4202496 34575 0 0 0 332 25 0 0 25 0 1 0 11215937 114880512 25833 1283457024 134512640 135413687 4294355504 18446744073709551615 134698544 0 0 18944 0 0 0 0 17 0 0 0 0 /proc/26513/statm: 28047 25833 107 220 0 27825 0 Current children cumulated CPU time (s) 8.84 Current children cumulated vsize (KiB) 164164 [startup+9.30642 s] /proc/loadavg: 1.34 1.41 1.30 2/37 26513 /proc/meminfo: memFree=163024/1048576 swapFree=0/0 [pid=26507] ppid=26506 vsize=2572 CPUtime=0 /proc/26507/stat : 26507 (packup2mp4pa-0.) S 26506 26507 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 11215405 2633728 275 1283457024 134512640 135304128 4288369584 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/26507/statm: 643 275 233 194 0 30 0 [pid=26508] ppid=26507 vsize=47732 CPUtime=5.26 /proc/26508/stat : 26508 (packup) S 26507 26507 4778 34817 4778 4202496 11650 27242 0 0 160 41 298 27 18 0 1 0 11215405 48877568 11193 1283457024 134512640 134752139 4293093376 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/26508/statm: 11933 11193 332 59 0 11097 0 [pid=26512] ppid=26508 vsize=1672 CPUtime=0.01 /proc/26512/stat : 26512 (sh) S 26508 26507 4778 34817 4778 4202496 146 0 0 0 0 1 0 0 18 0 1 0 11215936 1712128 124 1283457024 134512640 134593992 4290741920 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0 /proc/26512/statm: 418 124 108 20 0 45 0 [pid=26513] ppid=26512 vsize=108336 CPUtime=3.98 /proc/26513/stat : 26513 (minisatp_32) R 26512 26507 4778 34817 4778 4202496 36431 0 0 0 370 28 0 0 25 0 1 0 11215937 110936064 25272 1283457024 134512640 135413687 4294355504 18446744073709551615 134948381 0 0 18944 0 0 0 0 17 0 0 0 0 /proc/26513/statm: 27084 25272 107 220 0 26862 0 Current children cumulated CPU time (s) 9.25 Current children cumulated vsize (KiB) 160312 [startup+9.40657 s] /proc/loadavg: 1.34 1.41 1.30 2/37 26513 /proc/meminfo: memFree=163024/1048576 swapFree=0/0 [pid=26507] ppid=26506 vsize=2572 CPUtime=0 /proc/26507/stat : 26507 (packup2mp4pa-0.) S 26506 26507 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 11215405 2633728 275 1283457024 134512640 135304128 4288369584 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/26507/statm: 643 275 233 194 0 30 0 [pid=26508] ppid=26507 vsize=47736 CPUtime=9.36 /proc/26508/stat : 26508 (packup) R 26507 26507 4778 34817 4778 4202496 14273 63833 0 0 163 44 672 57 18 0 1 0 11215405 48881664 11207 1283457024 134512640 134752139 4293093376 18446744073709551615 4159223524 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/26508/statm: 11934 11207 345 59 0 11098 0 Current children cumulated CPU time (s) 9.36 Current children cumulated vsize (KiB) 50308 Child status: 0 Real time (s): 9.50216 CPU time (s): 9.47259 CPU user time (s): 8.44053 CPU system time (s): 1.03206 CPU usage (%): 99.6888 Max. virtual memory (cumulated for all children) (KiB): 173824 getrusage(RUSAGE_CHILDREN,...) data: user time used= 8.44053 system time used= 1.03206 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 86041 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= 161 runsolver used 0 second user time and 0 second system time The end