Changeset 3349

Timestamp:

18 Mar 2008, 17:54:22 (17 years ago)

Author:

joachim

Message:

include timing functions,
to enable set with_timing to True

Location:

WAeUP_SRP/base

Files:

• WAeUPTool.py (modified) (11 diffs)
• skins/waeup_student/admitStudents.py (modified) (1 diff)

WAeUP_SRP/base/WAeUPTool.py

@@ -885 +885 @@
 ###)
 
+    def init_timing(self): ###(
+        if self.with_timing:
+            if not hasattr(self,'_v_step_times'):
+                self._v_timer_count = 0
+                self._v_total = 0
+                self._v_step_times = {}
+                current = DateTime.DateTime().strftime("%d-%m-%y_%H_%M_%S")
+                self._v_timer_file = "%s/export/timing_%s.csv" % (i_home,current,)
+            self.timer_step = 0
+            self.total_time = 0
+            self.elapse = time.time()
+            self.i_elapse = time.time()
+            self.c_elapse = time.clock()
+
+###)
+
+    def do_timing(self): ###(
+        if self.with_timing:
+            try:
+                raise 'dummy'
+            except:
+                frame = sys.exc_traceback.tb_frame.f_back
+                locals = frame.f_locals
+                globals = frame.f_globals
+                functionname = frame.f_code.co_name
+                filename = os.path.basename(frame.f_code.co_filename)
+                lineno = frame.f_lineno
+                mod_line = "%(functionname)s:%(lineno)s" % vars()
+            i_time = time.time() - self.i_elapse
+            td = {}
+            if self._v_step_times.has_key(mod_line):
+                a_time = self._v_step_times[mod_line]['a_time'] + i_time
+                td['a_time'] = a_time
+            else:
+                td['a_time'] = i_time
+            td['i_time'] = i_time
+            self._v_step_times[mod_line] = td
+            self.i_time = i_time
+            self.total_time += i_time
+            self.timer_step +=1
+            self.i_elapse = time.time()
+
+###)
+
+    security.declareProtected(ModifyPortalContent,'print_timing') ###( ###(
+    def print_timing(self):
+        if self.with_timing:
+            l = []
+            timer_count = self._v_timer_count + 1
+            mod_lines = self._v_step_times.keys()
+            mod_lines.sort(cmp,reverse=0)
+            for mod_line in mod_lines:
+                td = self._v_step_times[mod_line]
+                i_time = td['i_time']
+                a_time = td['a_time']/(self._v_timer_count + 1)
+                l += ("%(mod_line)s,%(i_time)6.2f,%(a_time)6.2f,%(timer_count)d" % vars()),
+            total_time = self.total_time
+            total_avarage = self._v_total / timer_count
+            l += ("total,%(total_time)6.4f,%(total_avarage)6.4f,%(timer_count)d" % vars()),
+            print "\r\n".join(l)
+            out = open(self._v_timer_file,'a')
+            out.write("\r\n".join(l))
+            out.close()
+
+###)
+
+    security.declareProtected(ModifyPortalContent,'get_timing_data') ###( ###(
+    def get_timing_data(self):
+        if self.with_timing:
+            timer_count = self._v_timer_count + 1
+            results = {}
+            for k,d in self._v_step_times.items():
+                dd = {}
+                dd['a_time'] = d['a_time']/timer_count
+                dd['i_time'] = d['i_time']
+                dd['count'] = timer_count
+                results[k] = dd
+            dd = {}
+            dd['a_time'] = self._v_total / timer_count
+            dd['i_time'] = self.total_time
+            dd['count'] = timer_count
+            results["total"] = dd
+            return results
+    ###)
+
     security.declareProtected(ModifyPortalContent,'admitOneStudent') ###(
-    def admitOneStudent(self,brain,entry_session,pin_password):
+    def admitOneStudent(self,brain,entry_session,pin_password,with_timing=False):
         "create Datastructure for an admitted Student"
         #import pdb;pdb.set_trace()
+        logger = logging.getLogger('WAeUPTool.admitOneStudent')
+        self.with_timing = with_timing
         if not hasattr(self,"_v_certificates"):
             self._v_certificates = self.getCertificatesDict()
         students_folder = self.portal_url.getPortalObject().campus.students
-        logger = logging.getLogger('WAeUPTool.admitOneStudent')
         if brain.screening_type in ('cest','sandwich',):
             reg_no = "%s%s/07" % (brain.course1,brain.serial)
@@ -914 +1000 @@
             logger.info('sex of %s not available' % (reg_no))
             return
+        self.init_timing()
         student_id = self.generateStudentId('?')
         students_folder.invokeFactory('Student', student_id)
         student_object = getattr(students_folder,student_id)
+        self.do_timing()
         if pin_password:
             password = pin_parts[2]
             self.makeStudentMember(student_id,password = password)
         student_object.manage_setLocalRoles(student_id, ['Owner',])
+        self.do_timing()
         #logger.info("creating %s reg_no %s" % (student_id,reg_no))
         #
@@ -928 +1017 @@
         application = student_object.application
         #self.portal_workflow.doActionFor(application,'open',dest_container=application)
+        self.do_timing()
         da = {'Title': 'Application Data'}
         da['jamb_reg_no'] = reg_no
@@ -944 +1034 @@
 
         da['entry_mode'] = self._v_certificates[brain.course_admitted]['study_mode']
-
-        #if brain.entry_mode:
-        #    da['entry_mode'] = brain.entry_mode
-        #elif brain.screening_type == 'pume':
-        #    da['entry_mode'] = 'ume_ft'
-        #elif brain.screening_type == 'pde':
-        #    da['entry_mode'] = 'de_ft'
-        #elif brain.screening_type == 'pce':
-        #    da['entry_mode'] = 'pce'
-        #elif brain.screening_type == 'prence':
-        #    da['entry_mode'] = 'prence'
-        #else:
-        #    da['entry_mode'] = ''
-
 
         da['entry_session'] = entry_session
@@ -976 +1052 @@
 
         application.getContent().edit(mapping=da)
+        self.do_timing()
         #self.portal_workflow.doActionFor(application,'close',dest_container=application)
         #
@@ -983 +1060 @@
         personal = student_object.personal
         #self.portal_workflow.doActionFor(personal,'open',dest_container=personal)
+        self.do_timing()
         dp = {'Title': 'Personal Data'}
         dp['sex'] = brain.sex
@@ -991 +1069 @@
         dp['firstname'] = brain.firstname
         personal.getContent().edit(mapping=dp)
+        self.do_timing()
         #
         # clearance
@@ -1001 +1080 @@
         dc['birthday'] = brain.date_of_birth
         clearance.getContent().edit(mapping=dc)
+        self.do_timing()
         #self.portal_workflow.doActionFor(clearance,'close',dest_container=clearance)
         #
@@ -1008 +1088 @@
         studycourse = student_object.study_course
         #self.portal_workflow.doActionFor(studycourse,'open',dest_container=studycourse)
+        self.do_timing()
         dsc = {}
         dsc['study_course'] = brain.course_admitted
@@ -1020 +1101 @@
         dsc['current_session'] = entry_session
         studycourse.getContent().edit(mapping=dsc)
+        self.do_timing()
         #
         # payments folder
         student_object.invokeFactory('PaymentsFolder','payments')
         payments = getattr(student_object,'payments')
+        self.do_timing()
         dpay = {}
         dpay['Title'] = 'Payments'
         payments.getContent().edit(mapping=dpay)
         self.portal_workflow.doActionFor(payments,'open')
+        self.do_timing()
         #
         # passport foto
@@ -1048 +1132 @@
                                                              app_picture))
 
+        self.do_timing()
+        self.print_timing()
+        if with_timing:
+            self.timer_step = 0
+            self._v_timer_count += 1
+            self._v_total += self.total_time
         return student_id
     ###)

WAeUP_SRP/base/skins/waeup_student/admitStudents.py

@@ -44 +44 @@
 admitted = 0
 cocount = 0
-commit_after = 20
+old_commit_count = -1
+commit_after = 40
 d = {'status': 'created'}
 reg_nos = [brain.reg_no for brain in brains]
+with_timing = True
 for reg_no in reg_nos:
     count += 1
-    if admitted and not admitted % commit_after:
+    must_commit = (admitted != old_commit_count) and (not admitted % commit_after)
+    if must_commit:
+        old_commit_count = admitted
         context.waeup_tool.doCommit()
         logger.info("Committing %s transactions, total %s" % (commit_after,count))
         cocount += 1
-        #if cocount > 1:
-        #    break
+        if cocount > 2:
+            break
     brain = aq_applicants(Eq('reg_no',reg_no))[0]
     #logger.info("start creating  objects of student %s" % (brain.reg_no))
-    sid = d['student_id'] = context.waeup_tool.admitOneStudent(brain,entry_session,pin_password)
+    sid = d['student_id'] = context.waeup_tool.admitOneStudent(brain,
+                                                               entry_session,
+                                                               pin_password,
+                                                               with_timing = with_timing)
+        
     if sid is not None:
         d['reg_no'] = reg_no
         context.applicants_catalog.modifyRecord(**d)
         logger.info("created objects of student %s with id %s" % (reg_no,sid))
+        if with_timing:
+            data = context.waeup_tool.get_timing_data()
+            logger.info("timing %(i_time)6.2f/%(a_time)6.2f" % data['total'])
         admitted += 1
     else: