Merge pull request #4482 from rundeck/feature/scheduled-execution-sta…

…ts-rebase

New scheduled execution stats table

rundeckapp/grails-app/controllers/rundeck/controllers/ExecutionController.groovy

@@ -359,9 +359,8 @@ class ExecutionController extends ControllerBase{
         def execState = e.executionState
         def execDuration = (e.dateCompleted ? e.dateCompleted.getTime() : System.currentTimeMillis()) - e.dateStarted.getTime()
         def jobAverage=-1L
-        if (e.scheduledExecution && e.scheduledExecution.totalTime >= 0 && e.scheduledExecution.execCount > 0) {
-            def long avg = Math.floor(e.scheduledExecution.totalTime / e.scheduledExecution.execCount)
-            jobAverage = avg
+        if (e.scheduledExecution && e.scheduledExecution.getAverageDuration() > 0) {
+            jobAverage = e.scheduledExecution.getAverageDuration()
         }
         def isClusterExec = frameworkService.isClusterModeEnabled() && e.serverNodeUUID !=
                 frameworkService.getServerUUID()

rundeckapp/grails-app/controllers/rundeck/controllers/MenuController.groovy

@@ -222,8 +222,11 @@ class MenuController extends ControllerBase implements ApplicationContextAware{
                         id: it.scheduledExecution.extid,
                         params:[project:it.scheduledExecution.project]
                 )
-                if (it.scheduledExecution && it.scheduledExecution.totalTime >= 0 && it.scheduledExecution.execCount > 0) {
-                    data['jobAverageDuration']= Math.floor(it.scheduledExecution.totalTime / it.scheduledExecution.execCount)
+                if (it.scheduledExecution){
+                    def seStats = it.scheduledExecution.getStats()
+                    if(scheduledExecution.getAverageDuration() > 0) {
+                        data['jobAverageDuration'] = scheduledExecution.getAverageDuration()
+                    }
                 }
                 if (it.argString) {
                     data.jobArguments = FrameworkService.parseOptsFromString(it.argString)
@@ -412,9 +415,8 @@ class MenuController extends ControllerBase implements ApplicationContextAware{
                             }
                         }
                     }
-                    if (se.totalTime >= 0 && se.execCount > 0) {
-                        def long avg = Math.floor(se.totalTime / se.execCount)
-                        data.averageDuration = avg
+                    if (se.getAverageDuration() > 0) {
+                        data.averageDuration = se.getAverageDuration()
                     }
                     JobInfo.from(
                             se,
@@ -2690,9 +2692,8 @@ class MenuController extends ControllerBase implements ApplicationContextAware{
             extra.serverNodeUUID = scheduledExecution.serverNodeUUID
             extra.serverOwner = scheduledExecution.serverNodeUUID == serverNodeUUID
         }
-        if (scheduledExecution.totalTime >= 0 && scheduledExecution.execCount > 0) {
-            def long avg = Math.floor(scheduledExecution.totalTime / scheduledExecution.execCount)
-            extra.averageDuration = avg
+        if (scheduledExecution.getAverageDuration()>0) {
+            extra.averageDuration = scheduledExecution.getAverageDuration()
         }
         if(scheduledExecution.shouldScheduleExecution()){
             extra.nextScheduledExecution=scheduledExecutionService.nextExecutionTime(scheduledExecution)

rundeckapp/grails-app/controllers/rundeck/controllers/ScheduledExecutionController.groovy

@@ -448,8 +448,8 @@ class ScheduledExecutionController  extends ControllerBase{
             Execution.countByScheduledExecution(scheduledExecution)
         }
         def reftotal = 0
-        if(scheduledExecution.refExecCount) {
-            reftotal = scheduledExecution.refExecCount
+        if(scheduledExecution.getRefExecCountStats()) {
+            reftotal = scheduledExecution.getRefExecCountStats()
         }
 
         def remoteClusterNodeUUID=null

rundeckapp/grails-app/domain/rundeck/ScheduledExecution.groovy

@@ -1065,8 +1065,10 @@ class ScheduledExecution extends ExecutionContext {
     }
 
     long getAverageDuration() {
-        if (totalTime && execCount) {
-            return Math.floor(totalTime / execCount)
+        def stats = getStats()
+        def statsContent= stats?.getContentMap()
+        if (statsContent && statsContent.totalTime && statsContent.execCount) {
+            return Math.floor(statsContent.totalTime / statsContent.execCount)
         }
         return 0;
     }
@@ -1117,5 +1119,46 @@ class ScheduledExecution extends ExecutionContext {
         }
     }
 
+    ScheduledExecutionStats getStats() {
+        def stats
+        if(this.id) {
+            stats = ScheduledExecutionStats.findBySe(this)
+            if (!stats) {
+                def content = [execCount   : this.execCount,
+                               totalTime   : this.totalTime,
+                               refExecCount: this.refExecCount]
+
+                stats = new ScheduledExecutionStats(se: this, contentMap: content).save()
+            }
+        }
+        stats
+    }
+
+    Long getRefExecCountStats(){
+        def stats = this.getStats()
+        def statsContent= stats?.getContentMap()
+        if (statsContent?.refExecCount) {
+            return statsContent.refExecCount
+        }
+        return 0;
+    }
+
+    Long getTotalTimeStats(){
+        def stats = this.getStats()
+        def statsContent= stats?.getContentMap()
+        if (statsContent?.totalTime) {
+            return statsContent.totalTime
+        }
+        return 0;
+    }
+
+    Long getExecCountStats(){
+        def stats = this.getStats()
+        def statsContent= stats?.getContentMap()
+        if (statsContent?.execCount) {
+            return statsContent.execCount
+        }
+        return 0;
+    }
 }
 

rundeckapp/grails-app/domain/rundeck/ScheduledExecutionStats.groovy

@@ -0,0 +1,41 @@
+package rundeck
+
+import com.fasterxml.jackson.core.JsonParseException
+import com.fasterxml.jackson.databind.ObjectMapper
+
+class ScheduledExecutionStats {
+
+    String content
+
+    static belongsTo=[se:ScheduledExecution]
+    static transients = ['contentMap']
+
+    static mapping = {
+        content type: 'text'
+    }
+
+    public Map getContentMap() {
+        if (null != content) {
+            final ObjectMapper objMapper = new ObjectMapper()
+            try{
+                return objMapper.readValue(content, Map.class)
+            }catch (JsonParseException e){
+                return null
+            }
+        } else {
+            return null
+        }
+
+    }
+
+
+    public void setContentMap(Map obj) {
+        if (null != obj) {
+            final ObjectMapper objMapper = new ObjectMapper()
+            content = objMapper.writeValueAsString(obj)
+        } else {
+            content = null
+        }
+    }
+
+}

rundeckapp/grails-app/services/rundeck/services/ApiService.groovy

@@ -963,8 +963,9 @@ class ApiService {
                     }
                     if (e.scheduledExecution) {
                         def jobparams = [id: e.scheduledExecution.extid]
-                        if (e.scheduledExecution.totalTime >= 0 && e.scheduledExecution.execCount > 0) {
-                            def long avg = Math.floor(e.scheduledExecution.totalTime / e.scheduledExecution.execCount)
+                        def seStats = e.scheduledExecution.getStats()
+                        if(e.scheduledExecution.getAverageDuration() > 0) {
+                            def long avg = e.scheduledExecution.getAverageDuration()
                             jobparams.averageDuration = avg
                         }
                         jobparams.'href'=(apiHrefForJob(e.scheduledExecution))
@@ -1053,8 +1054,9 @@ class ApiService {
                 }
                 if (e.scheduledExecution) {
                     def jobparams = [id: e.scheduledExecution.extid]
-                    if (e.scheduledExecution.totalTime >= 0 && e.scheduledExecution.execCount > 0) {
-                        def long avg = Math.floor(e.scheduledExecution.totalTime / e.scheduledExecution.execCount)
+                    def seStats = e.scheduledExecution.getStats()
+                    if (e.scheduledExecution.getAverageDuration() > 0) {
+                        def long avg = e.scheduledExecution.getAverageDuration()
                         jobparams.averageDuration = avg
                     }
                     execMap.job=jobparams

rundeckapp/grails-app/services/rundeck/services/ExecutionService.groovy

@@ -63,6 +63,7 @@ import org.springframework.context.ApplicationContext
 import org.springframework.context.ApplicationContextAware
 import org.springframework.context.MessageSource
 import org.springframework.transaction.TransactionDefinition
+import org.springframework.dao.DuplicateKeyException
 import org.springframework.validation.ObjectError
 import org.springframework.web.context.request.RequestContextHolder
 import org.springframework.web.servlet.support.RequestContextUtils as RCU
@@ -2802,47 +2803,108 @@ class ExecutionService implements ApplicationContextAware, StepExecutor, NodeSte
      * @param execution
      * @return
      */
-    def updateScheduledExecStatistics(Long schedId, eId, long time, boolean jobRef = false){
+    def updateScheduledExecStatistics(Long schedId, eId, long time) {
         def success = false
         try {
-            ScheduledExecution.withTransaction {
+            ScheduledExecutionStats.withTransaction {
                 def scheduledExecution = ScheduledExecution.get(schedId)
+                def seStats = scheduledExecution.getStats()
+
 
                 if (scheduledExecution.scheduled) {
                     scheduledExecution.nextExecution = scheduledExecutionService.nextExecutionTime(scheduledExecution)
+                    if (scheduledExecution.save(flush: true)) {
+                        log.info("updated scheduled Execution nextExecution")
+                    } else {
+                        scheduledExecution.errors.allErrors.each { log.warn(it.defaultMessage) }
+                        log.warn("failed saving scheduled Execution nextExecution")
+                    }
                 }
-                //TODO: record job stats in separate domain class
-                if (null == scheduledExecution.execCount || 0 == scheduledExecution.execCount || null == scheduledExecution.totalTime || 0 == scheduledExecution.totalTime) {
-                    scheduledExecution.execCount = 1
-                    scheduledExecution.totalTime = time
-                } else if (scheduledExecution.execCount > 0 && scheduledExecution.execCount < 10) {
-                    scheduledExecution.execCount++
-                    scheduledExecution.totalTime += time
-                } else if (scheduledExecution.execCount >= 10) {
-                    def popTime = scheduledExecution.totalTime.intdiv(scheduledExecution.execCount)
-                    scheduledExecution.totalTime -= popTime
-                    scheduledExecution.totalTime += time
+                def statsMap = seStats.getContentMap()
+                if (null == statsMap.execCount || 0 == statsMap.execCount || null == statsMap.totalTime || 0 == statsMap.totalTime) {
+                    statsMap.execCount = 1
+                    statsMap.totalTime = time
+                } else if (statsMap.execCount > 0 && statsMap.execCount < 10) {
+                    statsMap.execCount++
+                    statsMap.totalTime += time
+                } else if (statsMap.execCount >= 10) {
+                    def popTime = statsMap.totalTime.intdiv(statsMap.execCount)
+                    statsMap.totalTime -= popTime
+                    statsMap.totalTime += time
                 }
-                if(jobRef){
-                    if(!scheduledExecution.refExecCount){
-                        scheduledExecution.refExecCount=1
-                    }else{
-                        scheduledExecution.refExecCount++
-                    }
+                seStats.setContentMap(statsMap)
 
+                if (seStats.validate()) {
+                    if (seStats.save(flush: true)) {
+                        log.info("updated scheduled Execution Stats")
+                    } else {
+                        seStats.errors.allErrors.each { log.warn(it.defaultMessage) }
+                        log.warn("failed saving execution to history")
+                    }
+                    success = true
                 }
-                if (scheduledExecution.save(flush:true)) {
-                    log.info("updated scheduled Execution")
+
+
+            }
+        } catch (org.springframework.dao.ConcurrencyFailureException e) {
+            log.warn("Caught ConcurrencyFailureException, will retry updateScheduledExecStatistics for ${eId}")
+        } catch (StaleObjectStateException e) {
+            log.warn("Caught StaleObjectState, will retry updateScheduledExecStatistics for ${eId}")
+        } catch (DuplicateKeyException ve) {
+            log.warn("Caught DuplicateKeyException for migrated stats, will retry updateScheduledExecStatistics for ${eId}")
+        }
+        return success
+    }
+
+    /**
+     * Update jobref stats
+     * @param schedId
+     * @param time
+     * @return
+     */
+    def updateJobRefScheduledExecStatistics(Long schedId, long time) {
+        def success = false
+        try {
+            def scheduledExecution = ScheduledExecution.get(schedId)
+            def seStats = scheduledExecution.getStats()
+            def statsMap = seStats.getContentMap()
+
+            if (null == statsMap.execCount || 0 == statsMap.execCount || null == statsMap.totalTime || 0 == statsMap.totalTime) {
+                statsMap.execCount = 1
+                statsMap.totalTime = time
+            } else if (statsMap.execCount > 0 && statsMap.execCount < 10) {
+                statsMap.execCount++
+                statsMap.totalTime += time
+            } else if (statsMap.execCount >= 10) {
+                def popTime = statsMap.totalTime.intdiv(statsMap.execCount)
+                statsMap.totalTime -= popTime
+                statsMap.totalTime += time
+            }
+
+
+            if (!statsMap.refExecCount) {
+                statsMap.refExecCount = 1
+            } else {
+                statsMap.refExecCount++
+            }
+            seStats.setContentMap(statsMap)
+
+            if (seStats.validate()) {
+                if (seStats.save(flush: true)) {
+                    log.info("updated referenced Job Stats")
                 } else {
-                    scheduledExecution.errors.allErrors.each {log.warn(it.defaultMessage)}
-                    log.warn("failed saving execution to history")
+                    seStats.errors.allErrors.each { log.warn(it.defaultMessage) }
+                    log.warn("failed saving referenced Job Stats")
                 }
                 success = true
             }
         } catch (org.springframework.dao.ConcurrencyFailureException e) {
-            log.warn("Caught ConcurrencyFailureException, will retry updateScheduledExecStatistics for ${eId}")
+            log.warn("Caught ConcurrencyFailureException, dismissed statistic for referenced Job")
         } catch (StaleObjectStateException e) {
-            log.warn("Caught StaleObjectState, will retry updateScheduledExecStatistics for ${eId}")
+            log.warn("Caught StaleObjectState, dismissed statistic for for referenced Job")
+        } catch (DuplicateKeyException ve) {
+            // Do something ...
+            log.warn("Caught DuplicateKeyException for migrated stats, dismissed statistic for referenced Job")
         }
         return success
     }
@@ -3510,10 +3572,7 @@ class ExecutionService implements ApplicationContextAware, StepExecutor, NodeSte
         if(wresult.result) {
             def savedJobState = false
             if(!disableRefStats) {
-                savedJobState = updateScheduledExecStatistics(id, 'jobref', duration, true)
-                if (!savedJobState) {
-                    log.info("ExecutionJob: Failed to update job statistics for jobref")
-                }
+                updateJobRefScheduledExecStatistics(id, duration)
             }
             ReferencedExecution.withTransaction { status ->
                 refExec.status=wresult.result.success?EXECUTION_SUCCEEDED:EXECUTION_FAILED

rundeckapp/grails-app/services/rundeck/services/NotificationService.groovy

@@ -609,9 +609,8 @@ public class NotificationService implements ApplicationContextAware{
                 project: scheduledExecution.project,
                 description: scheduledExecution.description
         ]
-        if (scheduledExecution.totalTime >= 0 && scheduledExecution.execCount > 0) {
-            def long avg = Math.floor(scheduledExecution.totalTime / scheduledExecution.execCount)
-            job.averageDuration = avg
+        if (scheduledExecution.getAverageDuration() > 0) {
+            job.averageDuration = scheduledExecution.getAverageDuration()
         }
         job
     }

rundeckapp/grails-app/services/rundeck/services/ScheduledExecutionService.groovy

@@ -926,6 +926,12 @@ class ScheduledExecutionService implements ApplicationContextAware, Initializing
                         '" it is currently being executed: {{Execution ' + found.id + '}}'
                 return [success:false,error:errmsg]
             }
+            def stats= ScheduledExecutionStats.findAllBySe(scheduledExecution)
+            if(stats){
+                stats.each { st ->
+                    st.delete()
+                }
+            }
             def refExec = ReferencedExecution.findAllByScheduledExecution(scheduledExecution)
             if(refExec){
                 refExec.each { re ->
@@ -3190,6 +3196,11 @@ class ScheduledExecutionService implements ApplicationContextAware, Initializing
             scheduledExecution.uuid = UUID.randomUUID().toString()
         }
         if (!failed && scheduledExecution.save(flush:true)) {
+            def stats = ScheduledExecutionStats.findAllBySe(scheduledExecution)
+            if (!stats) {
+                stats = new ScheduledExecutionStats(se: scheduledExecution)
+                        .save(flush:true)
+            }
             rescheduleJob(scheduledExecution)
             def event = createJobChangeEvent(JobChangeEvent.JobChangeEventType.CREATE, scheduledExecution)
             return [success: true, scheduledExecution: scheduledExecution,jobChangeEvent: event]

rundeckapp/grails-app/views/execution/show.gsp

@@ -888,8 +888,8 @@
       <g:if test="${!authChecks[AuthConstants.ACTION_KILL]}">
           killjobhtml: "",
       </g:if>
-        totalDuration : '${enc(js:scheduledExecution?.totalTime ?: -1)}',
-        totalCount: '${enc(js:scheduledExecution?.execCount ?: -1)}'
+        totalDuration : '${enc(js:scheduledExecution?.getTotalTimeStats()?: -1)}',
+        totalCount: '${enc(js:scheduledExecution?.getExecCountStats()?: -1)}'
       });
       nodeflowvm=new NodeFlowViewModel(
         workflow,

rundeckapp/grails-app/views/menu/_runningExecutions.gsp

@@ -104,8 +104,8 @@
                         </span>
                     </g:if>
                     <g:else>
-                        <g:if test="${scheduledExecution && scheduledExecution.execCount>0 && scheduledExecution.totalTime > 0 && execution.dateStarted && timeNow >= execution.dateStarted.getTime()}">
-                            <g:set var="avgTime" value="${(Long)(scheduledExecution.totalTime/scheduledExecution.execCount)}"/>
+                        <g:if test="${scheduledExecution && scheduledExecution.getAverageDuration() > 0 && execution.dateStarted && timeNow >= execution.dateStarted.getTime()}">
+                            <g:set var="avgTime" value="${(Long)(scheduledExecution.getAverageDuration())}"/>
                             <g:set var="completePercent" value="${(int)Math.floor((double)(100 * (timeNow - execution.dateStarted.getTime())/(avgTime)))}"/>
                             <g:set var="estEndTime" value="${(long)(execution.dateStarted.getTime() + (long)avgTime)}"/>
                             <g:set var="completeEstimate" value="${new Date(estEndTime)}"/>