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/aspcud-paranoid-1.5/c2164c84-b015-11df-8b50-00163e46d37a.cudf.dudf-real.log.runsolver ./aspcud-paranoid-1.5 /home/misc2010/data/2011/dudf-real//c2164c84-b015-11df-8b50-00163e46d37a.cudf /home/misc2010/tmp/201108251442/aspcud-paranoid-1.5/c2164c84-b015-11df-8b50-00163e46d37a.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.47 1.46 1.33 6/37 27496 /proc/meminfo: memFree=287320/1048576 swapFree=0/0 [pid=27480] ppid=27479 vsize=2596 CPUtime=0 /proc/27480/stat : 27480 (aspcud-paranoid) R 27479 27480 4778 34817 4778 4202496 624 2937 0 0 0 0 0 0 25 0 1 0 11229550 2658304 298 1283457024 134512640 135304128 4292198208 18446744073709551615 4294960130 0 65538 4 1132560123 0 0 0 17 0 0 0 0 /proc/27480/statm: 649 298 250 194 0 36 0 [pid=27494] ppid=27480 vsize=2596 CPUtime=0 /proc/27494/stat : 27494 (aspcud-paranoid) R 27480 27480 4778 34817 4778 4202560 110 0 0 0 0 0 0 0 25 0 1 0 11229551 2658304 132 1283457024 134512640 135304128 4292198208 18446744073709551615 4294960130 0 0 6 1132494585 0 0 0 17 0 0 0 0 /proc/27494/statm: 649 132 83 194 0 36 0 [pid=27495] ppid=27480 vsize=2596 CPUtime=0.01 /proc/27495/stat : 27495 (aspcud-paranoid) S 27480 27480 4778 34817 4778 4202560 110 0 0 0 1 0 0 0 25 0 1 0 11229551 2658304 132 1283457024 134512640 135304128 4292198208 18446744073709551615 4294960130 0 0 6 1132494585 18446744071564457842 0 0 17 0 0 0 0 /proc/27495/statm: 649 132 83 194 0 36 0 [pid=27496] ppid=27480 vsize=2596 CPUtime=0 /proc/27496/stat : 27496 (aspcud-paranoid) R 27480 27480 4778 34817 4778 4202560 0 0 0 0 0 0 0 0 25 0 1 0 11229552 2658304 48 1283457024 134512640 135304128 4292198208 18446744073709551615 4294960130 0 65538 4 1132560123 0 0 0 17 0 0 0 0 /proc/27496/statm: 649 48 0 194 0 36 0 [startup+0.133159 s] /proc/loadavg: 1.47 1.46 1.33 6/37 27496 /proc/meminfo: memFree=287320/1048576 swapFree=0/0 [pid=27480] ppid=27479 vsize=2596 CPUtime=0 /proc/27480/stat : 27480 (aspcud-paranoid) S 27479 27480 4778 34817 4778 4202496 649 2937 0 0 0 0 0 0 25 0 1 0 11229550 2658304 299 1283457024 134512640 135304128 4292198208 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/27480/statm: 649 299 251 194 0 36 0 [pid=27494] ppid=27480 vsize=1928 CPUtime=0 /proc/27494/stat : 27494 (clasp) S 27480 27480 4778 34817 4778 4202496 292 0 0 0 0 0 0 0 25 0 1 0 11229551 1974272 160 1283457024 134512640 136285277 4289070144 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0 /proc/27494/statm: 482 160 144 433 0 47 0 [pid=27495] ppid=27480 vsize=2584 CPUtime=0.01 /proc/27495/stat : 27495 (gringo) S 27480 27480 4778 34817 4778 4202496 404 0 0 0 1 0 0 0 25 0 1 0 11229551 2646016 272 1283457024 134512640 136933539 4294599168 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/27495/statm: 646 272 242 592 0 51 0 [pid=27496] ppid=27480 vsize=4480 CPUtime=0.09 /proc/27496/stat : 27496 (cudf2lp) R 27480 27480 4778 34817 4778 4202496 1055 0 0 0 9 0 0 0 25 0 1 0 11229552 4587520 878 1283457024 134512640 135786343 4294037904 18446744073709551615 134566531 0 0 6 0 0 0 0 17 0 0 0 0 /proc/27496/statm: 1120 878 126 311 0 807 0 Current children cumulated CPU time (s) 0.1 Current children cumulated vsize (KiB) 11588 [startup+0.205157 s] /proc/loadavg: 1.47 1.46 1.33 6/37 27496 /proc/meminfo: memFree=287320/1048576 swapFree=0/0 [pid=27480] ppid=27479 vsize=2596 CPUtime=0 /proc/27480/stat : 27480 (aspcud-paranoid) S 27479 27480 4778 34817 4778 4202496 649 2937 0 0 0 0 0 0 25 0 1 0 11229550 2658304 299 1283457024 134512640 135304128 4292198208 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/27480/statm: 649 299 251 194 0 36 0 [pid=27494] ppid=27480 vsize=1928 CPUtime=0 /proc/27494/stat : 27494 (clasp) S 27480 27480 4778 34817 4778 4202496 292 0 0 0 0 0 0 0 25 0 1 0 11229551 1974272 160 1283457024 134512640 136285277 4289070144 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0 /proc/27494/statm: 482 160 144 433 0 47 0 [pid=27495] ppid=27480 vsize=2584 CPUtime=0.01 /proc/27495/stat : 27495 (gringo) S 27480 27480 4778 34817 4778 4202496 404 0 0 0 1 0 0 0 25 0 1 0 11229551 2646016 272 1283457024 134512640 136933539 4294599168 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/27495/statm: 646 272 242 592 0 51 0 [pid=27496] ppid=27480 vsize=5800 CPUtime=0.16 /proc/27496/stat : 27496 (cudf2lp) R 27480 27480 4778 34817 4778 4202496 1469 0 0 0 15 1 0 0 25 0 1 0 11229552 5939200 1203 1283457024 134512640 135786343 4294037904 18446744073709551615 134596144 0 0 6 0 0 0 0 17 0 0 0 0 /proc/27496/statm: 1450 1203 126 311 0 1137 0 Current children cumulated CPU time (s) 0.17 Current children cumulated vsize (KiB) 12908 [startup+0.305176 s] /proc/loadavg: 1.47 1.46 1.33 6/37 27496 /proc/meminfo: memFree=287320/1048576 swapFree=0/0 [pid=27480] ppid=27479 vsize=2596 CPUtime=0 /proc/27480/stat : 27480 (aspcud-paranoid) S 27479 27480 4778 34817 4778 4202496 649 2937 0 0 0 0 0 0 25 0 1 0 11229550 2658304 299 1283457024 134512640 135304128 4292198208 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/27480/statm: 649 299 251 194 0 36 0 [pid=27494] ppid=27480 vsize=1928 CPUtime=0 /proc/27494/stat : 27494 (clasp) S 27480 27480 4778 34817 4778 4202496 292 0 0 0 0 0 0 0 25 0 1 0 11229551 1974272 160 1283457024 134512640 136285277 4289070144 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0 /proc/27494/statm: 482 160 144 433 0 47 0 [pid=27495] ppid=27480 vsize=2584 CPUtime=0.01 /proc/27495/stat : 27495 (gringo) S 27480 27480 4778 34817 4778 4202496 404 0 0 0 1 0 0 0 25 0 1 0 11229551 2646016 272 1283457024 134512640 136933539 4294599168 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/27495/statm: 646 272 242 592 0 51 0 [pid=27496] ppid=27480 vsize=8716 CPUtime=0.25 /proc/27496/stat : 27496 (cudf2lp) R 27480 27480 4778 34817 4778 4202496 2254 0 0 0 24 1 0 0 25 0 1 0 11229552 8925184 1811 1283457024 134512640 135786343 4294037904 18446744073709551615 134614683 0 0 6 0 0 0 0 17 0 0 0 0 /proc/27496/statm: 2179 1811 126 311 0 1866 0 Current children cumulated CPU time (s) 0.26 Current children cumulated vsize (KiB) 15824 [startup+0.705196 s] /proc/loadavg: 1.47 1.46 1.33 6/37 27496 /proc/meminfo: memFree=287320/1048576 swapFree=0/0 [pid=27480] ppid=27479 vsize=2596 CPUtime=0 /proc/27480/stat : 27480 (aspcud-paranoid) S 27479 27480 4778 34817 4778 4202496 649 2937 0 0 0 0 0 0 25 0 1 0 11229550 2658304 299 1283457024 134512640 135304128 4292198208 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/27480/statm: 649 299 251 194 0 36 0 [pid=27494] ppid=27480 vsize=1928 CPUtime=0 /proc/27494/stat : 27494 (clasp) S 27480 27480 4778 34817 4778 4202496 292 0 0 0 0 0 0 0 25 0 1 0 11229551 1974272 160 1283457024 134512640 136285277 4289070144 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0 /proc/27494/statm: 482 160 144 433 0 47 0 [pid=27495] ppid=27480 vsize=2584 CPUtime=0.01 /proc/27495/stat : 27495 (gringo) S 27480 27480 4778 34817 4778 4202496 404 0 0 0 1 0 0 0 25 0 1 0 11229551 2646016 272 1283457024 134512640 136933539 4294599168 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/27495/statm: 646 272 242 592 0 51 0 [pid=27496] ppid=27480 vsize=14732 CPUtime=0.6 /proc/27496/stat : 27496 (cudf2lp) R 27480 27480 4778 34817 4778 4202496 4186 0 0 0 58 2 0 0 25 0 1 0 11229552 15085568 3341 1283457024 134512640 135786343 4294037904 18446744073709551615 135208222 0 0 6 0 0 0 0 17 0 0 0 0 /proc/27496/statm: 3683 3341 126 311 0 3370 0 Current children cumulated CPU time (s) 0.61 Current children cumulated vsize (KiB) 21840 [startup+1.50616 s] /proc/loadavg: 1.47 1.46 1.33 3/38 27497 /proc/meminfo: memFree=248104/1048576 swapFree=0/0 [pid=27480] ppid=27479 vsize=2596 CPUtime=1.31 /proc/27480/stat : 27480 (aspcud-paranoid) S 27479 27480 4778 34817 4778 4202496 649 15000 0 0 0 0 127 4 17 0 1 0 11229550 2658304 299 1283457024 134512640 135304128 4292198208 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/27480/statm: 649 299 251 194 0 36 0 [pid=27494] ppid=27480 vsize=10544 CPUtime=0.07 /proc/27494/stat : 27494 (clasp) R 27480 27480 4778 34817 4778 4202496 2632 0 0 0 6 1 0 0 18 0 1 0 11229551 10797056 2357 1283457024 134512640 136285277 4289070144 18446744073709551615 135047248 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/27494/statm: 2636 2357 188 433 0 2201 0 Current children cumulated CPU time (s) 1.38 Current children cumulated vsize (KiB) 13140 Solver just ended. Dumping a history of the last processes samples [startup+1.50616 s] /proc/loadavg: 1.47 1.46 1.33 3/38 27497 /proc/meminfo: memFree=248104/1048576 swapFree=0/0 [pid=27480] ppid=27479 vsize=2596 CPUtime=1.31 /proc/27480/stat : 27480 (aspcud-paranoid) S 27479 27480 4778 34817 4778 4202496 649 15000 0 0 0 0 127 4 17 0 1 0 11229550 2658304 299 1283457024 134512640 135304128 4292198208 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/27480/statm: 649 299 251 194 0 36 0 [pid=27494] ppid=27480 vsize=10544 CPUtime=0.07 /proc/27494/stat : 27494 (clasp) R 27480 27480 4778 34817 4778 4202496 2632 0 0 0 6 1 0 0 18 0 1 0 11229551 10797056 2357 1283457024 134512640 136285277 4289070144 18446744073709551615 135047248 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/27494/statm: 2636 2357 188 433 0 2201 0 Current children cumulated CPU time (s) 1.38 Current children cumulated vsize (KiB) 13140 Child status: 0 Real time (s): 1.58284 CPU time (s): 1.47609 CPU user time (s): 1.39609 CPU system time (s): 0.080005 CPU usage (%): 93.2559 Max. virtual memory (cumulated for all children) (KiB): 36828 getrusage(RUSAGE_CHILDREN,...) data: user time used= 1.39609 system time used= 0.080005 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 22324 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= 388 involuntary context switches= 309 runsolver used 0 second user time and 0 second system time The end