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/deb285a6-db9e-11df-8f4f-00163e3d3b7c.cudf.dudf-real.log.runsolver ./packup2mp4pa-0.6 /home/misc2010/data/2011/dudf-real//deb285a6-db9e-11df-8f4f-00163e3d3b7c.cudf /home/misc2010/tmp/201108251442/packup2mp4pa-0.6/deb285a6-db9e-11df-8f4f-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.22 1.43 1.35 5/35 29513 /proc/meminfo: memFree=273872/1048576 swapFree=0/0 [pid=29512] ppid=29511 vsize=2572 CPUtime=0 /proc/29512/stat : 29512 (packup2mp4pa-0.) R 29511 29512 4778 34817 4778 4202496 360 0 0 0 0 0 0 0 25 0 1 0 11252736 2633728 274 1283457024 134512640 135304128 4287570672 18446744073709551615 4294960130 0 65538 4 84480 0 0 0 17 0 0 0 0 /proc/29512/statm: 643 274 233 194 0 30 0 [pid=29513] ppid=29512 vsize=2572 CPUtime=0 /proc/29513/stat : 29513 (packup2mp4pa-0.) R 29512 29512 4778 34817 4778 4202560 0 0 0 0 0 0 0 0 25 0 1 0 11252736 2633728 41 1283457024 134512640 135304128 4287570672 18446744073709551615 4294960130 0 65538 4 84480 0 0 0 17 0 0 0 0 /proc/29513/statm: 643 41 0 194 0 30 0 [startup+0.143815 s] /proc/loadavg: 1.22 1.43 1.35 5/35 29513 /proc/meminfo: memFree=273872/1048576 swapFree=0/0 [pid=29512] ppid=29511 vsize=2572 CPUtime=0 /proc/29512/stat : 29512 (packup2mp4pa-0.) S 29511 29512 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 25 0 1 0 11252736 2633728 274 1283457024 134512640 135304128 4287570672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/29512/statm: 643 274 233 194 0 30 0 [pid=29513] ppid=29512 vsize=8748 CPUtime=0.14 /proc/29513/stat : 29513 (packup) R 29512 29512 4778 34817 4778 4202496 1687 0 0 0 13 1 0 0 25 0 1 0 11252736 8957952 1615 1283457024 134512640 134752139 4287466144 18446744073709551615 134682079 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/29513/statm: 2187 1615 286 59 0 1351 0 Current children cumulated CPU time (s) 0.14 Current children cumulated vsize (KiB) 11320 [startup+0.213825 s] /proc/loadavg: 1.22 1.43 1.35 5/35 29513 /proc/meminfo: memFree=273872/1048576 swapFree=0/0 [pid=29512] ppid=29511 vsize=2572 CPUtime=0 /proc/29512/stat : 29512 (packup2mp4pa-0.) S 29511 29512 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 25 0 1 0 11252736 2633728 274 1283457024 134512640 135304128 4287570672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/29512/statm: 643 274 233 194 0 30 0 [pid=29513] ppid=29512 vsize=10992 CPUtime=0.21 /proc/29513/stat : 29513 (packup) R 29512 29512 4778 34817 4778 4202496 2230 0 0 0 20 1 0 0 25 0 1 0 11252736 11255808 2158 1283457024 134512640 134752139 4287466144 18446744073709551615 4157097399 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/29513/statm: 2748 2158 286 59 0 1912 0 Current children cumulated CPU time (s) 0.21 Current children cumulated vsize (KiB) 13564 [startup+0.303839 s] /proc/loadavg: 1.22 1.43 1.35 5/35 29513 /proc/meminfo: memFree=273872/1048576 swapFree=0/0 [pid=29512] ppid=29511 vsize=2572 CPUtime=0 /proc/29512/stat : 29512 (packup2mp4pa-0.) S 29511 29512 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 25 0 1 0 11252736 2633728 274 1283457024 134512640 135304128 4287570672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/29512/statm: 643 274 233 194 0 30 0 [pid=29513] ppid=29512 vsize=13696 CPUtime=0.3 /proc/29513/stat : 29513 (packup) R 29512 29512 4778 34817 4778 4202496 2910 0 0 0 28 2 0 0 25 0 1 0 11252736 14024704 2838 1283457024 134512640 134752139 4287466144 18446744073709551615 4157072099 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/29513/statm: 3424 2838 286 59 0 2588 0 Current children cumulated CPU time (s) 0.3 Current children cumulated vsize (KiB) 16268 [startup+0.703909 s] /proc/loadavg: 1.22 1.43 1.35 5/35 29513 /proc/meminfo: memFree=273872/1048576 swapFree=0/0 [pid=29512] ppid=29511 vsize=2572 CPUtime=0 /proc/29512/stat : 29512 (packup2mp4pa-0.) S 29511 29512 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 25 0 1 0 11252736 2633728 274 1283457024 134512640 135304128 4287570672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/29512/statm: 643 274 233 194 0 30 0 [pid=29513] ppid=29512 vsize=26092 CPUtime=0.7 /proc/29513/stat : 29513 (packup) R 29512 29512 4778 34817 4778 4202496 6042 0 0 0 67 3 0 0 25 0 1 0 11252736 26718208 5970 1283457024 134512640 134752139 4287466144 18446744073709551615 4157097391 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/29513/statm: 6523 5970 307 59 0 5687 0 Current children cumulated CPU time (s) 0.7 Current children cumulated vsize (KiB) 28664 [startup+1.50384 s] /proc/loadavg: 1.22 1.43 1.35 2/38 29516 /proc/meminfo: memFree=242580/1048576 swapFree=0/0 [pid=29512] ppid=29511 vsize=2572 CPUtime=0 /proc/29512/stat : 29512 (packup2mp4pa-0.) S 29511 29512 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 25 0 1 0 11252736 2633728 274 1283457024 134512640 135304128 4287570672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/29512/statm: 643 274 233 194 0 30 0 [pid=29513] ppid=29512 vsize=30804 CPUtime=1.48 /proc/29513/stat : 29513 (packup) D 29512 29512 4778 34817 4778 4202496 6997 3346 0 0 80 13 49 6 20 0 1 0 11252736 31543296 6914 1283457024 134512640 134752139 4287466144 18446744073709551615 4294960130 0 0 18944 8192 18446744071696440003 0 0 17 0 0 0 0 /proc/29513/statm: 7701 6914 331 59 0 6865 0 Current children cumulated CPU time (s) 1.48 Current children cumulated vsize (KiB) 33376 [startup+3.10485 s] /proc/loadavg: 1.22 1.43 1.35 2/38 29518 /proc/meminfo: memFree=235760/1048576 swapFree=0/0 [pid=29512] ppid=29511 vsize=2572 CPUtime=0 /proc/29512/stat : 29512 (packup2mp4pa-0.) S 29511 29512 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 25 0 1 0 11252736 2633728 274 1283457024 134512640 135304128 4287570672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/29512/statm: 643 274 233 194 0 30 0 [pid=29513] ppid=29512 vsize=29776 CPUtime=1.61 /proc/29513/stat : 29513 (packup) S 29512 29512 4778 34817 4778 4202496 7012 3346 0 0 85 21 49 6 19 0 1 0 11252736 30490624 6923 1283457024 134512640 134752139 4287466144 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/29513/statm: 7444 6923 332 59 0 6608 0 [pid=29517] ppid=29513 vsize=1672 CPUtime=0.01 /proc/29517/stat : 29517 (sh) S 29513 29512 4778 34817 4778 4202496 145 0 0 0 0 1 0 0 19 0 1 0 11252911 1712128 123 1283457024 134512640 134593992 4288588944 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0 /proc/29517/statm: 418 123 108 20 0 45 0 [pid=29518] ppid=29517 vsize=55600 CPUtime=1.34 /proc/29518/stat : 29518 (minisatp_32) R 29517 29512 4778 34817 4778 4202496 17816 0 0 0 119 15 0 0 25 0 1 0 11252912 56934400 12396 1283457024 134512640 135413687 4288640192 18446744073709551615 134686484 0 0 18944 0 0 0 0 17 0 0 0 0 /proc/29518/statm: 13900 12396 108 220 0 13678 0 Current children cumulated CPU time (s) 2.96 Current children cumulated vsize (KiB) 89620 Solver just ended. Dumping a history of the last processes samples [startup+3.30492 s] /proc/loadavg: 1.22 1.43 1.35 2/38 29518 /proc/meminfo: memFree=235760/1048576 swapFree=0/0 [pid=29512] ppid=29511 vsize=2572 CPUtime=0 /proc/29512/stat : 29512 (packup2mp4pa-0.) S 29511 29512 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 25 0 1 0 11252736 2633728 274 1283457024 134512640 135304128 4287570672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/29512/statm: 643 274 233 194 0 30 0 [pid=29513] ppid=29512 vsize=29776 CPUtime=1.61 /proc/29513/stat : 29513 (packup) S 29512 29512 4778 34817 4778 4202496 7012 3346 0 0 85 21 49 6 19 0 1 0 11252736 30490624 6923 1283457024 134512640 134752139 4287466144 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/29513/statm: 7444 6923 332 59 0 6608 0 [pid=29517] ppid=29513 vsize=1672 CPUtime=0.01 /proc/29517/stat : 29517 (sh) S 29513 29512 4778 34817 4778 4202496 145 0 0 0 0 1 0 0 19 0 1 0 11252911 1712128 123 1283457024 134512640 134593992 4288588944 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0 /proc/29517/statm: 418 123 108 20 0 45 0 [pid=29518] ppid=29517 vsize=58716 CPUtime=1.54 /proc/29518/stat : 29518 (minisatp_32) R 29517 29512 4778 34817 4778 4202496 18063 0 0 0 139 15 0 0 25 0 1 0 11252912 60125184 12633 1283457024 134512640 135413687 4288640192 18446744073709551615 134697019 0 0 18944 0 0 0 0 17 0 0 0 0 /proc/29518/statm: 14679 12633 108 220 0 14457 0 Current children cumulated CPU time (s) 3.16 Current children cumulated vsize (KiB) 92736 [startup+3.50498 s] /proc/loadavg: 1.22 1.43 1.35 2/38 29518 /proc/meminfo: memFree=196824/1048576 swapFree=0/0 [pid=29512] ppid=29511 vsize=2572 CPUtime=0 /proc/29512/stat : 29512 (packup2mp4pa-0.) S 29511 29512 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 25 0 1 0 11252736 2633728 274 1283457024 134512640 135304128 4287570672 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/29512/statm: 643 274 233 194 0 30 0 [pid=29513] ppid=29512 vsize=30600 CPUtime=3.36 /proc/29513/stat : 29513 (packup) R 29512 29512 4778 34817 4778 4202496 13015 22489 0 0 88 24 201 23 18 0 1 0 11252736 31334400 7021 1283457024 134512640 134752139 4287466144 18446744073709551615 4157065454 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/29513/statm: 7650 7021 345 59 0 6814 0 Current children cumulated CPU time (s) 3.36 Current children cumulated vsize (KiB) 33172 Child status: 0 Real time (s): 3.55522 CPU time (s): 3.42821 CPU user time (s): 2.94418 CPU system time (s): 0.48403 CPU usage (%): 96.4275 Max. virtual memory (cumulated for all children) (KiB): 94964 getrusage(RUSAGE_CHILDREN,...) data: user time used= 2.94418 system time used= 0.48403 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 36634 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= 12 involuntary context switches= 85 runsolver used 0 second user time and 0 second system time The end