Repository: ansible/awx
File: awx/main/models/unified_jobs.py (Python)

Code before:
        if self.failed != failed:
            self.failed = failed
            if 'failed' not in update_fields:
                update_fields.append('failed')

        # Sanity check: Has the job just started? If so, mark down its start
        # time.
        if self.status == 'running' and not self.started:
            self.started = now()
            if 'started' not in update_fields:
                update_fields.append('started')

        # Sanity check: Has the job just completed? If so, mark down its
        # completion time, and record its output to the database.
        if self.status in ('successful', 'failed', 'error', 'canceled') and not self.finished:
            # Record the `finished` time.
            self.finished = now()
            if 'finished' not in update_fields:
                update_fields.append('finished')

        if self.elapsed is None:
            self.elapsed = 0.0
            if 'elapsed' not in update_fields:
                update_fields.append('elapsed')

        # If we have a start and finished time, and haven't already calculated
        # out the time that elapsed, do so.
        if self.started and self.finished and self.elapsed == 0.0:
            td = self.finished - self.started
            self.elapsed = (td.microseconds + (td.seconds + td.days * 24 * 3600) * 10 ** 6) / (10 ** 6 * 1.0)
            if 'elapsed' not in update_fields:
                update_fields.append('elapsed')

        # Ensure that the job template information is current.
        if self.unified_job_template != self._get_parent_instance():
            self.unified_job_template = self._get_parent_instance()
            if 'unified_job_template' not in update_fields:
                update_fields.append('unified_job_template')

        if self.cancel_flag and not self.canceled_on:
            # Record the 'canceled' time.
            self.canceled_on = now()
            if 'canceled_on' not in update_fields:
                update_fields.append('canceled_on')
        # Okay; we're done. Perform the actual save.
        result = super(UnifiedJob, self).save(*args, **kwargs)

        # If status changed, update the parent instance.
        if self.status != status_before:
            # Update parent outside of the transaction for Job w/ allow_simultaneous=True
            # This dodges lock contention at the expense of the foreign key not being

Review comment (bug):
this line is the culprit

the issue is that on a job run we call `.save()` multiple times

when `started` and `finished` is defined and elapsed is 0.0, we set it (e.g. 5 seconds) and correctly save this field to the database

now on the very next `.save()`, the `not self.elapsed` condition fails, and we set elapsed back to 0.0

the `if self.elapsed != elapsed` condition is now true, `self.elapsed` (which is 5 seconds) is not equal to 0.0, so we save 0.0 to the database

Code after:
        failed = bool(self.status in ('failed', 'error', 'canceled'))
        if self.failed != failed:
            self.failed = failed
            if 'failed' not in update_fields:
                update_fields.append('failed')

        # Sanity check: Has the job just started? If so, mark down its start
        # time.
        if self.status == 'running' and not self.started:
            self.started = now()
            if 'started' not in update_fields:
                update_fields.append('started')

        # Sanity check: Has the job just completed? If so, mark down its
        # completion time, and record its output to the database.
        if self.status in ('successful', 'failed', 'error', 'canceled') and not self.finished:
            # Record the `finished` time.
            self.finished = now()
            if 'finished' not in update_fields:
                update_fields.append('finished')

        dq = decimal.Decimal('1.000')
        if self.elapsed is None:
            self.elapsed = decimal.Decimal(0.0).quantize(dq)

        # If we have a start and finished time, and haven't already calculated
        # out the time that elapsed, do so.
        if self.started and self.finished and self.elapsed == 0.0:
            td = self.finished - self.started
            elapsed = decimal.Decimal(td.total_seconds())
            self.elapsed = elapsed.quantize(dq)
            if 'elapsed' not in update_fields:
                update_fields.append('elapsed')

        # Ensure that the job template information is current.
        if self.unified_job_template != self._get_parent_instance():
            self.unified_job_template = self._get_parent_instance()
            if 'unified_job_template' not in update_fields:
                update_fields.append('unified_job_template')

        if self.cancel_flag and not self.canceled_on:
            # Record the 'canceled' time.
            self.canceled_on = now()
            if 'canceled_on' not in update_fields:
                update_fields.append('canceled_on')
        # Okay; we're done. Perform the actual save.
        result = super(UnifiedJob, self).save(*args, **kwargs)

        # If status changed, update the parent instance.
        if self.status != status_before:
            # Update parent outside of the transaction for Job w/ allow_simultaneous=True