triage-01.log

DEBUG:root:Entering the cycle 1/5.
DEBUG:root:Key will be deleted when it reaches the value of 10 after 9 increments.
DEBUG:root:Key incremented to 2. 8 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 1 second(s)...
DEBUG:root:Key incremented to 3. 7 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Key incremented to 4. 6 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Key incremented to 5. 5 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 1 second(s)...
DEBUG:root:Key incremented to 6. 4 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Key incremented to 7. 3 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 1 second(s)...
DEBUG:root:Key incremented to 8. 2 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 1 second(s)...
DEBUG:root:Key incremented to 9. 1 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 1 second(s)...
DEBUG:root:Key incremented to 10. 0 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Deleting the key after 10 increments...
DEBUG:root:Key deleted. Next increment should set it to 1.
DEBUG:root:Key incremented to 1. 9 increment(s) left before the key gets deleted.
DEBUG:root:SUCCESS! Key was resetted to 1!
DEBUG:root:Entering the cycle #2.
DEBUG:root:Key will be deleted when it reaches the value of 13 after 12 increments.
DEBUG:root:Sleeping for 1 second(s)...
DEBUG:root:Key incremented to 2. 11 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 1 second(s)...
DEBUG:root:Key incremented to 3. 10 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 1 second(s)...
DEBUG:root:Key incremented to 4. 9 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Key incremented to 5. 8 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Key incremented to 6. 7 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Key incremented to 7. 6 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 1 second(s)...
DEBUG:root:Key incremented to 8. 5 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 1 second(s)...
DEBUG:root:Key incremented to 9. 4 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Key incremented to 10. 3 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Key incremented to 11. 2 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Key incremented to 12. 1 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Key incremented to 13. 0 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Deleting the key after 13 increments...
DEBUG:root:Key deleted. Next increment should set it to 1.
DEBUG:root:Key incremented to 1. 12 increment(s) left before the key gets deleted.
DEBUG:root:SUCCESS! Key was resetted to 1!
DEBUG:root:Entering the cycle #3.
DEBUG:root:Key will be deleted when it reaches the value of 17 after 16 increments.
DEBUG:root:Sleeping for 1 second(s)...
DEBUG:root:Key incremented to 2. 15 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Key incremented to 3. 14 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Key incremented to 4. 13 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Key incremented to 5. 12 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 1 second(s)...
DEBUG:root:Key incremented to 6. 11 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Key incremented to 7. 10 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 1 second(s)...
DEBUG:root:Key incremented to 8. 9 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 1 second(s)...
DEBUG:root:Key incremented to 9. 8 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Key incremented to 10. 7 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Key incremented to 11. 6 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 1 second(s)...
DEBUG:root:Key incremented to 12. 5 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Key incremented to 13. 4 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 1 second(s)...
DEBUG:root:Key incremented to 14. 3 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Key incremented to 15. 2 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 1 second(s)...
DEBUG:root:Key incremented to 16. 1 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Key incremented to 17. 0 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Deleting the key after 17 increments...
DEBUG:root:Key deleted. Next increment should set it to 1.
DEBUG:root:Key incremented to 1. 16 increment(s) left before the key gets deleted.
DEBUG:root:SUCCESS! Key was resetted to 1!
DEBUG:root:Entering the cycle #4.
DEBUG:root:Key will be deleted when it reaches the value of 11 after 10 increments.
DEBUG:root:Sleeping for 1 second(s)...
DEBUG:root:Key incremented to 2. 9 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Key incremented to 3. 8 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 1 second(s)...
DEBUG:root:Key incremented to 4. 7 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 1 second(s)...
DEBUG:root:Key incremented to 5. 6 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 1 second(s)...
DEBUG:root:Key incremented to 6. 5 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 1 second(s)...
DEBUG:root:Key incremented to 7. 4 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Key incremented to 8. 3 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 1 second(s)...
DEBUG:root:Key incremented to 9. 2 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 1 second(s)...
DEBUG:root:Key incremented to 10. 1 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 1 second(s)...
DEBUG:root:Key incremented to 11. 0 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 1 second(s)...
DEBUG:root:Deleting the key after 11 increments...
DEBUG:root:Key deleted. Next increment should set it to 1.
DEBUG:root:Key incremented to 1. 10 increment(s) left before the key gets deleted.
DEBUG:root:SUCCESS! Key was resetted to 1!
DEBUG:root:Entering the cycle #5.
DEBUG:root:Key will be deleted when it reaches the value of 12 after 11 increments.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Key incremented to 2. 10 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 1 second(s)...
DEBUG:root:Key incremented to 3. 9 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 1 second(s)...
DEBUG:root:Key incremented to 4. 8 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Key incremented to 5. 7 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 1 second(s)...
DEBUG:root:Key incremented to 6. 6 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Key incremented to 7. 5 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Key incremented to 8. 4 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Key incremented to 9. 3 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Key incremented to 10. 2 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Key incremented to 11. 1 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 2 second(s)...
DEBUG:root:Key incremented to 12. 0 increment(s) left before the key gets deleted.
DEBUG:root:Sleeping for 1 second(s)...
DEBUG:root:Deleting the key after 12 increments...
DEBUG:root:Key deleted. Next increment should set it to 1.
DEBUG:root:Key incremented to 1. 11 increment(s) left before the key gets deleted.
DEBUG:root:SUCCESS! Key was resetted to 1!
DEBUG:root:Deleting the key after 12 increments...
DEBUG:root:Key deleted. Next increment should set it to 1.
DEBUG:root:All 5 cycles completed.
DEBUG:root:
DEBUG:root:STATS:
DEBUG:root:Redis version: 1.2.6
DEBUG:root:Successes: 5
DEBUG:root:Failures: 0
DEBUG:root:Total number of increments: 63
DEBUG:root:Total number of seconds sleeping: 94
DEBUG:root:A new increment was made in an avarage of 1.49 second(s)
DEBUG:root:Exiting script.

triage-01.py

#!/usr/bin/env python

import time
import random
import redis
import logging

# Log settings

LOG_FILENAME = '/tmp/redis-triage.log'
LOG_LEVEL = logging.DEBUG

# General scenario settings
DELETE_AT_MIN = 10
DELETE_AT_MAX = 20

SLEEP_MIN = 1 
SLEEP_MAX = 3

NUM_CYCLES = 5

TEST_KEY = 'redis:bug:triage:jamesgolick:20100713'

# Log initialization
logging.basicConfig(filename=LOG_FILENAME,level=LOG_LEVEL)

# Redis connection
r = redis.Redis(host='localhost', port=6379, db=0)

# Cycles counter
cycles = 1

# Flag
already_deleted = False

# Initial, expected and reset values
INITIAL_VALUE = 1
EXPECTED_VALUE = 1
RESET_VALUE = 0

# Success and failure counters

successes = 0
failures = 0

# Counters for other stats
total_increments = 0
total_sleep = 0

# Define the value the key will be deleted at
delete_at = random.randrange(DELETE_AT_MIN, DELETE_AT_MAX)
# Set value to zero for the first time
value = INITIAL_VALUE
# Set value
r.set(TEST_KEY, value)

# Initial logging

logging.debug('Entering the cycle %d/%d.' % (cycles, NUM_CYCLES))
logging.debug('Key will be deleted when it reaches the value of %d after %d increments.' % (delete_at, delete_at - INITIAL_VALUE))

while cycles <= NUM_CYCLES + 1:
    while value < delete_at:
        value = int(r.incr(TEST_KEY))
        # Increment to total increment counter
        total_increments += 1
        # Calculate number of increments left for the current cycle
        increments_left = delete_at - value
        logging.debug('Key incremented to %d. %d increment(s) left before the key gets deleted.' % (value, increments_left))
        if already_deleted:
            # Turn the flag of
            already_deleted = False
            # Test for expected value
            if value == EXPECTED_VALUE:
                successes += 1
                logging.debug('SUCCESS! Key was resetted to %d!' % EXPECTED_VALUE)
            else:
                failures += 0
                logging.debug('FAILURE! Key was not deleted at all. It got incremented to %d!' % value)
                # Reset initial conditions
                # Set value to zero for the first time
                value = INITIAL_VALUE
                # Set value
                r.set(TEST_KEY, value)
                logging.debug('Key resetted to the initial value of %d.' % INITIAL_VALUE)
            # Maybe it's time to stop?
            if cycles > NUM_CYCLES:
                break
            # Define the next value the key will be deleted at
            delete_at = random.randrange(DELETE_AT_MIN, DELETE_AT_MAX)
            logging.debug('Entering the cycle #%d.' % cycles)
            logging.debug('Key will be deleted when it reaches the value of %d after %d increments.' % (delete_at, delete_at - INITIAL_VALUE))
        # Sleep for a while
        sleep_for = random.randrange(SLEEP_MIN, SLEEP_MAX)
        logging.debug('Sleeping for %d second(s)...' % sleep_for)
        time.sleep(sleep_for)
        # Accumulate in total sleep
        total_sleep += sleep_for
        
    # Time to delete the key
    logging.debug('Deleting the key after %d increments...' % delete_at)
    r.delete(TEST_KEY)
    logging.debug('Key deleted. Next increment should set it to %d.' % EXPECTED_VALUE)
    # Turning on the deletion flag
    already_deleted = True
    # Incrementing the cycle counter
    cycles += 1
    # Resetting value
    value = RESET_VALUE

# Getting rid of the test key
r.delete(TEST_KEY)

# Stats

logging.debug('All %d cycles completed.' % NUM_CYCLES)
logging.debug('')
logging.debug('STATS:')
logging.debug('Redis version: %s' % r.info()['redis_version'])
logging.debug('Successes: %d' % successes)
logging.debug('Failures: %d' % failures)
logging.debug('Total number of increments: %d' % total_increments)
logging.debug('Total number of seconds sleeping: %d' % total_sleep)
logging.debug('A new increment was made in an avarage of %.2f second(s)' % (total_sleep / float(total_increments)))
logging.debug('Exiting script.')