3

I'm interested in understanding the performance impact of encryption on a piece of hardware, so I have written a test program to that effect (sorry for the massive code dump). It uses PolarSSl to perform encryption and decryption on a number of files it creates. I (for the moment) only record the time it takes to perform the encryption and decryption and the results are shown in the graph bellow. However this is not what I was expecting to see. I was just wondering if anyone could either spot a issue in the program or offer me an explanation to the graph. EDIT apologies some labels on the graph would of been a massive help, seconds on the y,file size (Mebibyte) on the x. Cheers Results

    #include <stdio.h>
#include <string.h>
#include <stdlib.h>
#include <stdio.h>
#include <time.h>
#include <sys/types.h>
#include <unistd.h>
#include <sys/time.h> //high percission

#include <polarssl/aes.h>
#include <polarssl/sha256.h> // This in the real version should be a higher 512

struct timespec diff(struct timespec start, struct timespec end);

/**
 * @brief createFiles Creates a series of files of various sizes (512KB, 1mb,2mb,3mb,4mb) for encryption, and then to be decrypted
 */
void createFiles(u_int64_t* sizes, u_int8_t noOfFiles)
{


    u_int8_t i = 0;

    for(i = 0; i < noOfFiles; i++)
    {
        char str[noOfFiles];
        sprintf(str, "%d", i);
        FILE *fp = fopen(str, "wb");

        char *buffer= malloc(sizes[i]);
        memset(buffer,'a',sizes[i]);
        fprintf(fp,buffer);

        fclose(fp);
        memset(buffer,0,sizes[i]);
    }
}

int encryptFile(int fileNo, struct timespec* timeTaken)
{


    int returnvalue = -1;
    unsigned char key[32] = {'0','1','2','3','4','5','6','7','8','9','0','1','2','3','4','5','6','7','8','9','0','1','2','3','4','5','6','7','8','9','0','1'}; // Holds the key
    unsigned char IV[16];
    FILE * fin = NULL; //The temp file we created
    FILE* fout  = NULL; //The temp file to open
    u_int64_t fileSize = 0;

    struct timespec start,end, timeDiff;

    //Create the contex objects
    aes_context aes_ctx;
    int i;
    char str[1];
    sprintf(str, "%d", fileNo);

    //file name is i value prepended by c
    char* out;
    const char* extension = "c";
    out = malloc(strlen(str)+2);
    strcpy(out, str);
    strcat(out, extension);

    //Open the relevent file
    if((fin = fopen(str, "rb" ) ) != NULL)
    {
        //Open the output file
        if((fout = fopen( out, "wb" )) != NULL)
        {

            //get the size of the file, and check it is not empty
            if(!( ( fileSize = lseek( fileno(fin ), 0, SEEK_END ) ) < 0 ))
            {
                //reset the seek position
                if(fseek( fin, 0, SEEK_SET ) < 0 )
                {
                    fprintf( stderr, "fseek(0,SEEK_SET) failed\n" );
                }
                else
                {
                    returnvalue = 0;

                    //generate IV
                    srand(time(NULL));
                    for( i = 0; i < 16; i++)
                    {
                        IV[i] = rand();
                    }

                    //create a buffer large enough to hold the file -- on a real system i susspect we would do this incormentaly 16bytes at time for example
                    int addition = ((fileSize +15)/16) *16;
                    char* buffer = malloc(addition);
                    char* encryptBuffer= malloc(addition);
                    fread(buffer,sizeof(char),addition,fin); // read the file
                    clock_gettime(CLOCK_MONOTONIC,  &start);

                    int error =  aes_setkey_enc(&aes_ctx, key, 256 );//Set up the ctx object -- setting the key

                    if(error != POLARSSL_ERR_AES_INVALID_KEY_LENGTH)
                    {


                        error == aes_crypt_cbc( &aes_ctx, AES_ENCRYPT, addition, IV, buffer, encryptBuffer ); //--encrypt the data
                        clock_gettime(CLOCK_MONOTONIC,  &end);
                        if(error != POLARSSL_ERR_AES_INVALID_INPUT_LENGTH)
                        {
                            fwrite(IV, sizeof(char), 16, fout);
                            fwrite(encryptBuffer, sizeof(char), sizeof(char)*fileSize, fout);

                        }
                        else
                        {
                            printf("error");
                        }

                        memset(buffer,0,addition);
                        memset(encryptBuffer,0,addition);
                        memset( &aes_ctx, 0, sizeof(  aes_context ) );
                    }
                    else
                    {
                        printf("Invalid key length");
                    }

                    // Calculate the difference
                    timeDiff = diff(start,end);


     //            printf("For file %i, with a size of %i bytes, the time taken to encrypt was ", fileNo,fileSize);
       //            printf("%d.%d seconds\n", timeDiff.tv_sec, timeDiff.tv_nsec);
                    fflush(stdout);
                    timeTaken->tv_sec = timeDiff.tv_sec;
                    timeTaken->tv_nsec = timeDiff.tv_nsec;
                }
            }

            fclose(fout);
        }
        fclose(fin);
    }


    return returnvalue;
}


int decryptfile(int fileNumber, struct timespec* timeTaken)
{
    u_int64_t fileSize = 0;
    int returnvalue = -1;
    char str[1];
    unsigned char key[32] = {'0','1','2','3','4','5','6','7','8','9','0','1','2','3','4','5','6','7','8','9','0','1','2','3','4','5','6','7','8','9','0','1'}; // Holds the key

    unsigned char IV[16];
    struct timespec start,end, timeDiff;


    //Create the contex objects
    aes_context aes_ctx;
    sprintf(str, "%d", fileNumber);

    //file name is i vavlue prepended by c
    char* in;
    const char* extension = "c";
    in = malloc(strlen(str)+2);
    strcpy(in, str);
    strcat(in, extension);

    char* out;
    //decrypt to fine number +d
    const char* extension2 = "d";
    out = malloc(strlen(str)+2);
    strcpy(out, str);
    strcat(out, extension2);


    FILE * fin = NULL; //The temp file we created
    FILE* fout  = NULL; //The temp file to open

    if((fin = fopen(in, "rb" ) ) != NULL)
    {
        //Open the output file
        if((fout = fopen( out, "wb" )) != NULL)
        {


            //get the size of the file, and check it is not empty
            if(!( ( fileSize = lseek( fileno(fin ), 0, SEEK_END ) ) < 0 ))
            {

                if(fseek( fin, 0, SEEK_SET ) < 0 )
                {
                    fprintf( stderr, "fseek(0,SEEK_SET) failed\n" );
                }
                else
                {

                    int addition = ((fileSize +15)/16) *16;
                    char* buffer = malloc(addition);
                    char* decryptBuffer = malloc((addition - 16));
                    char* resultBuffer = malloc((addition - 16));


                    fflush(stdout);
                    fread(buffer,sizeof(char),fileSize,fin); // read the file

                    memcpy(IV,buffer,16);
                    memcpy(decryptBuffer,(buffer + 16),addition);
                    memset(buffer,0,addition);  // Clear this to save on memory
                    clock_gettime(CLOCK_MONOTONIC,  &start);
                    int error =  aes_setkey_dec(&aes_ctx, key, 256 );//Set up the ctx object -- setting the key

                    if(error != POLARSSL_ERR_AES_INVALID_KEY_LENGTH)
                    {
                        error == aes_crypt_cbc( &aes_ctx, AES_DECRYPT, addition-16, IV, decryptBuffer, resultBuffer); //--encrypt the data
                        clock_gettime(CLOCK_MONOTONIC,  &end);
                        if(error != POLARSSL_ERR_AES_INVALID_INPUT_LENGTH)
                        {
                            fwrite(resultBuffer, sizeof(char), sizeof(char)*(addition - 16), fout);

                        }
                    }
                    returnvalue = 0;

                    memset(buffer,0,sizeof(buffer));
                    memset(decryptBuffer,0,sizeof(decryptBuffer));
                    memset(resultBuffer,0,sizeof(resultBuffer));
                }

            }
        }
    }

    // Calculate the difference
    timeDiff = diff(start,end);


 //   printf("For file %i, with a size of %i bytes, the time taken to decrypt was ", fileNumber,fileSize);
  //  printf("%d.%d seconds\n", timeDiff.tv_sec, timeDiff.tv_nsec);
    timeTaken->tv_sec = timeDiff.tv_sec;
    timeTaken->tv_nsec = timeDiff.tv_nsec;

    fflush(stdout);

    return returnvalue;
}


struct timespec diff(struct timespec start, struct timespec end)
{
    struct timespec temp;
    if ((end.tv_nsec-start.tv_nsec)<0) {
        temp.tv_sec = end.tv_sec-start.tv_sec-1;
        temp.tv_nsec = (1000000000+end.tv_nsec)-start.tv_nsec;
    } else {
        temp.tv_sec = end.tv_sec-start.tv_sec;
        temp.tv_nsec = end.tv_nsec-start.tv_nsec;
    }
    return temp;
}


/**
 *This is just to demo encryption times, the actuall methods used in tis should not be addopted as a final solution
 */
int main()
{

    //1048576 = 1mb
    u_int32_t kb = 1024; //bits;
    u_int64_t mb = 1024 * kb;
    const u_int8_t noOfFiles = 5;
    const u_int8_t noOfTests = 5;

    struct timespec encryptTimes[noOfTests][noOfFiles];
    struct timespec decryptTimes[noOfTests][noOfFiles];

    u_int64_t sizes[5] = {(500*kb),mb,(mb*5),(mb*15),(mb*30)}; // Create the sizes of the files to be written

    createFiles(sizes,noOfFiles);

    u_int8_t i =0;
    u_int8_t k = 0;

    for(k = 0; k < noOfTests; k++)
    {
        for( i = 0; i < noOfFiles; i++)
        {

            struct timespec encryptTime;
            if(encryptFile(i,&encryptTime) ==-1)
            {

                printf("Failed to open encrypted files ensure that the file encryption has been run first!");
            }
            else
            {
                encryptTimes[k][i]= encryptTime;

                struct timespec decryptTime;

                if(decryptfile(i,&decryptTime) == -1)
                {
                    printf("failed to open encrypted file to perform decryption!");
                }
                else
                {
                    decryptTimes[k][i] = decryptTime;
                }

            }
        }
    }

    for(i = 0; i < noOfFiles; i++)
    {
        printf("\nTime taken to encrypt file size of %i bytes:\n",sizes[i]);
     struct timespec encryptTime;

        for(k = 0; k < noOfTests; k++)
        {
            encryptTime = encryptTimes [k][i];

                printf("%d.%d\n", encryptTime.tv_sec, encryptTime.tv_nsec);
        }
    }

    for(i = 0; i < noOfFiles; i++)
    {
        printf("\nTime taken to decrypt file size of %i bytes:\n",sizes[i]);
     struct timespec decryptTime;

        for(k = 0; k < noOfTests; k++)
        {
            decryptTime = decryptTimes [k][i];

                printf("%i.%i \n", decryptTime.tv_sec, decryptTime.tv_nsec);
        }
    }
    return 0;
}
Nark
  • 310
  • 1
  • 2
  • 10
  • 3
    What about [axis labels?](http://xkcd.com/833/) – ugoren Jan 20 '14 at 09:55
  • Are we to assume the layering just blows on that graph and there are really two plots there? I would expect them to be similar only because it is after all a symmetric algorithm, but confirmation (and a legend) would be nice. – WhozCraig Jan 20 '14 at 10:01
  • 2
    Your main issue is that your 'test' includes all the memory allocation and file IO in the process. My guess: the 0.5 and 5 'high points' are caused by either IO or memory cache misses. Both memory allocation (your `malloc()`) and your IO accesses (`fopen()`, `lseek()`, etc) are very unpredictable, depend on caching, other OS activity.. For performance testing I would advise to loop just the encryption / decryption part, not the memory / file parts.. And run up tests to 1000 or so.. 5 is way to little with all the different factors that impact your system.. – Paul Jan 20 '14 at 10:26
  • Shoot the axis labels didn't export correctly sorry about that have added them to the post now. – Nark Jan 20 '14 at 11:07
  • Ok thanks Paul, ill try that test over night. – Nark Jan 20 '14 at 11:08
  • @Paul Actually Paul just had another look and I don't believe I am taking into account the memory allocation or IO accesses, as the start timer call is made just before decryption/encryption and then stopped just after. – Nark Jan 20 '14 at 11:16
  • @Nark Yeah, from a technical code perspective you are right.. But right when you start timing for round 2, the kernel has to decide when to flush those IO buffers for the file for round 1.. So I think you will get MUCH better accuracy if you look just the encrypt/decrypt part (key setup / decrypt) X times (More than 5). So loop around the part where you now start / stop timing.. – Paul Jan 20 '14 at 14:26

1 Answers1

0

This may be related to Linux kernel caching. I suggest cleaning them just before running test:

echo 3 | sudo tee /proc/sys/vm/drop_caches

P.S. You could save some coding using time command to measure execution time.

PauliusZ
  • 363
  • 4
  • 7