martijnvanbrummelen / nwipe

nwipe secure disk eraser
GNU General Public License v2.0
801 stars 86 forks source link

Implement High-Quality Random Number Generation Using AES-CTR Mode with OpenSSL and AES-NI Support #559

Closed Knogle closed 1 month ago

Knogle commented 8 months ago

In this pull request, I present my implementation of a pseudo-random number generator (PRNG) utilizing the AES-CTR (Advanced Encryption Standard - Counter mode) in 128-bit mode. This implementation is designed to produce high-quality random numbers, which are essential for a wide range of cryptographic applications. By integrating with the OpenSSL library and exploiting AES-NI (Advanced Encryption Standard New Instructions) hardware acceleration when available, I ensure both the security and efficiency of the random number generation process. It provides the highest-quality of PRNGs yet for NWIPE, and is a CSPRNG.

Key Features:

AES-CTR Mode: I chose AES in Counter mode due to its renowned capability to generate secure and unpredictable pseudo-random sequences. This mode operates by encrypting incrementing counter values, with the encryption output serving as the stream of random bytes.

128-bit AES: Utilizing a 128-bit key size for AES encryption provides a strong security measure while maintaining efficient performance, adhering to current cryptographic standards for pseudo-random number generation.

Integration with OpenSSL: OpenSSL, being a well-established and rigorously tested cryptographic library, is used to manage AES operations. This integration ensures a high level of security and performance for the AES-CTR operations within our PRNG.

Leveraging AES-NI Support: My implementation automatically detects and utilizes AES-NI, a set of instructions that enhance AES operations on most modern processors. This feature significantly improves the speed of random number generation, reducing CPU usage and enhancing scalability.

Implementation Details:

Initialization: At the outset, the PRNG's state is initialized with a distinct 128-bit key and an initial counter value, using OpenSSL's AES_set_encrypt_key to prepare the AES key structure for subsequent operations.

Generating Random Numbers: For generating random numbers, the current counter value is encrypted under the configured AES key in CTR mode. The output of this encryption serves as the source of pseudo-random bytes, with the counter incremented after each operation to maintain the uniqueness of subsequent inputs.

State Management: The PRNG's internal state, including the AES key, counter (IV), and encryption buffer (ecount), is securely managed within an aes_ctr_state_t structure. This careful management is crucial for preserving the integrity and unpredictability of the random number stream.

Optimizing for Hardware: By optimizing for AES-NI, my implementation ensures enhanced performance through hardware acceleration, providing an efficient solution for generating random numbers across various applications.

This PRNG implementation stands as a robust and efficient tool for generating high-quality pseudo-random numbers, crucial for cryptographic operations, secure communications, and randomized algorithms. The combination of AES-CTR mode, OpenSSL's reliability, and the performance benefits of AES-NI hardware acceleration results in a superior random number generator.

I have ensured that the implementation is well-documented with clear comments, making it accessible for review, understanding, and maintenance, following best practices in both software development and cryptographic standards.

I look forward to receiving feedback on this pull request to further improve and ensure the effectiveness of the PRNG implementation.

Test of randomness: 54e9585c-0218-4a40-be46-7911db900e0b

c860977f-8f4a-4015-ae21-1ae074824db6

NIST Test Suite:

A total of 188 tests (some of the 15 tests actually consist of multiple sub-tests)
were conducted to evaluate the randomness of 32 bitstreams of 1048576 bits from:

    /dev/loop0

- - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -

The numerous empirical results of these tests were then interpreted with
an examination of the proportion of sequences that pass a statistical test
(proportion analysis) and the distribution of p-values to check for uniformity
(uniformity analysis). The results were the following:

    188/188 tests passed successfully both the analyses.
    0/188 tests did not pass successfully both the analyses.

- - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -

Here are the results of the single tests:

 - The "Frequency" test passed both the analyses.

 - The "Block Frequency" test passed both the analyses.

 - The "Cumulative Sums" (forward) test passed both the analyses.
   The "Cumulative Sums" (backward) test passed both the analyses.

 - The "Runs" test passed both the analyses.

 - The "Longest Run of Ones" test passed both the analyses.

 - The "Binary Matrix Rank" test passed both the analyses.

 - The "Discrete Fourier Transform" test passed both the analyses.

 - 148/148 of the "Non-overlapping Template Matching" tests passed both the analyses.

 - The "Overlapping Template Matching" test passed both the analyses.

 - The "Maurer's Universal Statistical" test passed both the analyses.

 - The "Approximate Entropy" test passed both the analyses.

 - 8/8 of the "Random Excursions" tests passed both the analyses.

 - 18/18 of the "Random Excursions Variant" tests passed both the analyses.

 - The "Serial" (first) test passed both the analyses.
   The "Serial" (second) test passed both the analyses.

 - The "Linear Complexity" test passed both the analyses.

- - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -

The missing tests (if any) were whether disabled manually by the user or disabled
at run time due to input size requirements not satisfied by this run.

SmallCrush Test:

========= Summary results of SmallCrush =========

 Version:          TestU01 1.2.3
 Generator:        ufile_CreateReadBin
 Number of statistics:  15
 Total CPU time:   00:00:06.46

 All tests were passed

Screenshot from 2024-03-24 03-35-36

Knogle commented 8 months ago

Maybe some interesting insight. We've had an issue with a buffer overflow of bufpos. I think there was too much data, so it wasn't synced properly and fast enough, and caused the other parameters to corrupt, causing access on not-initialized memory. This one was important to me to fix, because i think a crypto-secure PRNG with good speed is an important thing! CPUs starting from Westmere-EP with AES-Ni can benefit from it. Better than the SHA solution.

==40641== Conditional jump or move depends on uninitialised value(s)
==40641==    at 0x4B9F565: CRYPTO_ctr128_encrypt_ctr32 (ctr128.c:183)
==40641==    by 0x4C655A1: ossl_cipher_hw_generic_ctr (ciphercommon_hw.c:117)
==40641==    by 0x4C60FCC: ossl_cipher_generic_stream_update (ciphercommon.c:469)
==40641==    by 0x4B61076: EVP_EncryptUpdate (evp_enc.c:643)
==40641==    by 0x414314: aes_ctr_prng_genrand_uint128_to_buf (aes_ctr_prng.c:133)
==40641==    by 0x417F5F: nwipe_aes_ctr_prng_read (prng.c:293)

So i've used a temporary buffer now, and i'm writing 4x 32-Bit values now. It's decreasing the performance slightly, but ensures memory safety now. Speed is still fast enough, considering the excellt quality of the random numbers, passing all tests without fail.

Before:

void aes_ctr_prng_genrand_uint128_to_buf(aes_ctr_state_t* state, unsigned char* bufpos) {
    int outlen;

    EVP_EncryptUpdate(state->ctx, bufpos, &outlen, bufpos, 16);
    // OpenSSL internally calls CRYPTO_ctr128_encrypt_ctr32
}

After:

/* Generates pseudorandom numbers and writes them to a buffer.
   - state: Pointer to the initialized AES CTR PRNG state.
   - bufpos: Target buffer where the pseudorandom numbers will be written. */
void aes_ctr_prng_genrand_uint128_to_buf( aes_ctr_state_t* state, unsigned char* bufpos )
{
    unsigned char temp_buffer[16]; /* Intermediate buffer for 128 bits */
    int outlen;

    /* Generate pseudorandom numbers in the intermediate buffer */
    EVP_EncryptUpdate( state->ctx, temp_buffer, &outlen, temp_buffer, sizeof( temp_buffer ) );

    /* Write the data from the intermediate buffer to bufpos in four 32-bit steps.
       This process is crucial to prevent a buffer overflow of bufpos, as it ensures
       that exactly 16 bytes (128 bits) of pseudorandom data are safely transferred
       into bufpos. Copying the data in controlled 32-bit segments allows for precise
       management of the memory space allocated to bufpos, mitigating the risk of
       writing beyond its allocated size. */
    int i = 0;
    while( i < 4 )
    {
        /* Copy each 32-bit segment from the intermediate buffer to the target buffer.
           This step-by-step approach is essential for maintaining the integrity of
           the buffer and ensuring that only the intended amount of data is written.
           The ternary operator is used here for illustrative purposes and does not
           alter the functionality. */
        memcpy( bufpos + ( i * 4 ), temp_buffer + ( i * 4 ), 4 );
        i = ( i < 4 ) ? i + 1 : 4;  // Ternary operator to increment i or keep it at 4
    }
}

And it delivers incredible performance.

Screenshot from 2024-03-24 03-35-36

Knogle commented 8 months ago

Did a 24 /dev/loop device wipe, performed great! More than 2000MB/s of throughput on an 8-Core CPU.

I've created another 'optional' commit. Setting AES-128 CTR as the default PRNG for 64-Bit CPUs, as most of the 64-Bit CPUs back to 2009 should massively benefit from it. Also it provides by far better PRNG quality than ISAAC and the others. For 32-Bit i've set XORoshiro256 as the default PRNG due to it's simplicity. It should perform best on legacy systems.

Screenshot from 2024-03-24 17-37-29

Screenshot from 2024-03-24 17-35-06 nwipe.log

PartialVolume commented 8 months ago

Looks good. I'm currently running a 18 drive test which should complete tomorrow afternoon.

PartialVolume commented 8 months ago

Bad news, speed is ok but I'm still seeing verification error on some drives but not all.

  1. The drives that fail verification, fail on every block suggesting a bad seed on the verification pass? However this doesn't happen on every verification suggesting a intermittent issue.

Screenshot_20240325_112258

PartialVolume commented 8 months ago

The logs, I don't see anything unusual, other than the verification errors. The count of "Initialising AES CTR PRNG" (36x) and "PRNG stream is active" (18x) are as would be expected for a 18 drive wipe.

[2024/03/25 02:58:03]    info: nwipe 0.36
[2024/03/25 02:58:03]    info: Linux version 6.5.13-1-pve (build@proxmox) (gcc 
                               (Debian 12.2.0-14) 12.2.0, GNU ld (GNU Binutils
                                for Debian) 2.40) #1 SMP PREEMPT_DYNAMIC PMX 6
                               .5.13-1 (2024-02-05T13:50Z)
[2024/03/25 02:58:03] warning: Device /dev/nvme0 not found
[2024/03/25 02:58:03] warning: Device /dev/nvme1 not found
[2024/03/25 02:58:03]  notice: Found /dev/sdaa,  USB    , Seagate FreeAgent Go,   80 GB, S/N=XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:03]    info: /dev/sdaa, sector(logical)/block(physical) sizes 512/512
[2024/03/25 02:58:03]    info: HPA:  max sectors   = 156301488/156301488, hpa is disabled
 on /dev/sdaa
[2024/03/25 02:58:03]    info: HPA values 156301488 / 156301488 on /dev/sdaa
[2024/03/25 02:58:03]    info: hdparm:DCO Real max sectors reported as 156301488 on /dev/sdaa
[2024/03/25 02:58:03]    info: NWipe: DCO Real max sectors reported as 156301488 on /dev/sdaa
[2024/03/25 02:58:03]    info: libata: apparent max sectors reported as 156301488 with sector size as 512/512 (logical/physical) on /dev/sdaa
[2024/03/25 02:58:03]    info: No hidden sectors on /dev/sdaa
[2024/03/25 02:58:03]    info: func:nwipe_read_dco_real_max_sectors(), DCO real max sectors = 156301488
[2024/03/25 02:58:03]    info:  
[2024/03/25 02:58:03]  notice: Found /dev/sdab,  USB-SSD, Samsung SSD 860 EVO 500G,  500 GB, S/N=XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:03]    info: /dev/sdab, sector(logical)/block(physical) sizes 512/4096
[2024/03/25 02:58:03]   error: SG_IO bad/missing sense data hdparm --verbose -N /dev/sdab 2>&1

[2024/03/25 02:58:03] warning: [UNKNOWN] We can't find the HPA line, has hdparm ouput unknown/changed? /dev/sdab
[2024/03/25 02:58:03]    info: hdparm:DCO Real max sectors reported as 976773168 on /dev/sdab
[2024/03/25 02:58:03]    info: NWipe: DCO Real max sectors reported as 976773168 on /dev/sdab
[2024/03/25 02:58:03]    info: libata: apparent max sectors reported as 976773168 with sector size as 512/4096 (logical/physical) on /dev/sdab
[2024/03/25 02:58:03]    info: No hidden sectors on /dev/sdab
[2024/03/25 02:58:03]    info: func:nwipe_read_dco_real_max_sectors(), DCO real max sectors = 976773168
[2024/03/25 02:58:03]    info:  
[2024/03/25 02:58:03] warning: Device /dev/sdc not found
[2024/03/25 02:58:03]  notice: Found /dev/sdd,  ATA    , ST1000NX0423, 1000 GB, S/N=XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:03]    info: /dev/sdd, sector(logical)/block(physical) sizes 512/512
[2024/03/25 02:58:03]    info: HPA:  max sectors   = 1953525168/1953525168, accessible max address disabled
 on /dev/sdd
[2024/03/25 02:58:03]    info: HPA values 1953525168 / 1953525168 on /dev/sdd
[2024/03/25 02:58:03]    info: DCO Real max sectors not found
[2024/03/25 02:58:03]    info: libata: apparent max sectors reported as 1953525168 with sector size as 512/512 (logical/physical) on /dev/sdd
[2024/03/25 02:58:03]    info: No hidden sectors on /dev/sdd
[2024/03/25 02:58:03]    info: func:nwipe_read_dco_real_max_sectors(), DCO real max sectors = 0
[2024/03/25 02:58:03]    info:  
[2024/03/25 02:58:03]  notice: Found /dev/sde,  ATA    , ST1000NX0423, 1000 GB, S/N=XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:03]    info: /dev/sde, sector(logical)/block(physical) sizes 512/512
[2024/03/25 02:58:03]    info: HPA:  max sectors   = 1953525168/1953525168, accessible max address disabled
 on /dev/sde
[2024/03/25 02:58:03]    info: HPA values 1953525168 / 1953525168 on /dev/sde
[2024/03/25 02:58:03]    info: DCO Real max sectors not found
[2024/03/25 02:58:03]    info: libata: apparent max sectors reported as 1953525168 with sector size as 512/512 (logical/physical) on /dev/sde
[2024/03/25 02:58:03]    info: No hidden sectors on /dev/sde
[2024/03/25 02:58:03]    info: func:nwipe_read_dco_real_max_sectors(), DCO real max sectors = 0
[2024/03/25 02:58:03]    info:  
[2024/03/25 02:58:03]  notice: Found /dev/sdf,  ATA    , ST1000NX0423, 1000 GB, S/N=XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:03]    info: /dev/sdf, sector(logical)/block(physical) sizes 512/512
[2024/03/25 02:58:03]    info: HPA:  max sectors   = 1953525168/1953525168, accessible max address disabled
 on /dev/sdf
[2024/03/25 02:58:03]    info: HPA values 1953525168 / 1953525168 on /dev/sdf
[2024/03/25 02:58:03]    info: DCO Real max sectors not found
[2024/03/25 02:58:03]    info: libata: apparent max sectors reported as 1953525168 with sector size as 512/512 (logical/physical) on /dev/sdf
[2024/03/25 02:58:03]    info: No hidden sectors on /dev/sdf
[2024/03/25 02:58:03]    info: func:nwipe_read_dco_real_max_sectors(), DCO real max sectors = 0
[2024/03/25 02:58:03]    info:  
[2024/03/25 02:58:03]  notice: Found /dev/sdg,  SAS    , NETAPP X421_HCOBD450A10,  450 GB, S/N=XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:03]    info: /dev/sdg, sector(logical)/block(physical) sizes 512/512
[2024/03/25 02:58:03]   error: SG_IO bad/missing sense data hdparm --verbose -N /dev/sdg 2>&1

[2024/03/25 02:58:03] warning: [UNKNOWN] We can't find the HPA line, has hdparm ouput unknown/changed? /dev/sdg
[2024/03/25 02:58:03]    info: DCO Real max sectors not found
[2024/03/25 02:58:03]    info: libata: apparent max sectors reported as 879097968 with sector size as 512/512 (logical/physical) on /dev/sdg
[2024/03/25 02:58:03]    info: func:nwipe_read_dco_real_max_sectors(), DCO real max sectors = 0
[2024/03/25 02:58:03]    info:  
[2024/03/25 02:58:03]  notice: Found /dev/sdh,  ATA-SSD, SanDisk SSD PLUS,  240 GB, S/N=XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:03]    info: /dev/sdh, sector(logical)/block(physical) sizes 512/512
[2024/03/25 02:58:03]    info: HPA:  max sectors   = 468862128/468862129, accessible max address enabled
 on /dev/sdh
[2024/03/25 02:58:03]    info: HPA values 468862128 / 468862129 on /dev/sdh
[2024/03/25 02:58:03]    info: hdparm:DCO Real max sectors reported as 468862128 on /dev/sdh
[2024/03/25 02:58:03]    info: NWipe: DCO Real max sectors reported as 468862128 on /dev/sdh
[2024/03/25 02:58:03]    info: libata: apparent max sectors reported as 468862128 with sector size as 512/512 (logical/physical) on /dev/sdh
[2024/03/25 02:58:03] warning:  *********************************
[2024/03/25 02:58:03] warning:  *** HIDDEN SECTORS DETECTED ! *** on /dev/sdh
[2024/03/25 02:58:03] warning:  *********************************
[2024/03/25 02:58:03]    info: func:nwipe_read_dco_real_max_sectors(), DCO real max sectors = 468862128
[2024/03/25 02:58:03]    info:  
[2024/03/25 02:58:03]  notice: Found /dev/sdi,  ATA-SSD, CT500MX500SSD1,  500 GB, S/N=XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:03]    info: /dev/sdi, sector(logical)/block(physical) sizes 512/4096
[2024/03/25 02:58:03]    info: HPA:  max sectors   = 976773168/976773168, accessible max address disabled
 on /dev/sdi
[2024/03/25 02:58:03]    info: HPA values 976773168 / 976773168 on /dev/sdi
[2024/03/25 02:58:03]    info: DCO Real max sectors not found
[2024/03/25 02:58:03]    info: libata: apparent max sectors reported as 976773168 with sector size as 512/4096 (logical/physical) on /dev/sdi
[2024/03/25 02:58:03]    info: No hidden sectors on /dev/sdi
[2024/03/25 02:58:03]    info: func:nwipe_read_dco_real_max_sectors(), DCO real max sectors = 0
[2024/03/25 02:58:03]    info:  
[2024/03/25 02:58:03]  notice: Found /dev/sdj,  ATA-SSD, OCZ-TRION100,  240 GB, S/N=XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:03]    info: /dev/sdj, sector(logical)/block(physical) sizes 512/512
[2024/03/25 02:58:04]    info: HPA:  max sectors   = 468862128/468862128, hpa is disabled
 on /dev/sdj
[2024/03/25 02:58:04]    info: HPA values 468862128 / 468862128 on /dev/sdj
[2024/03/25 02:58:04]    info: DCO Real max sectors not found
[2024/03/25 02:58:04]    info: libata: apparent max sectors reported as 468862128 with sector size as 512/512 (logical/physical) on /dev/sdj
[2024/03/25 02:58:04]    info: No hidden sectors on /dev/sdj
[2024/03/25 02:58:04]    info: func:nwipe_read_dco_real_max_sectors(), DCO real max sectors = 0
[2024/03/25 02:58:04]    info:  
[2024/03/25 02:58:04]  notice: Found /dev/sdk,  SAS    , SEAGATE ST1200MM0088, 1200 GB, S/N=XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:04]    info: /dev/sdk, sector(logical)/block(physical) sizes 512/512
[2024/03/25 02:58:04]   error: SG_IO bad/missing sense data hdparm --verbose -N /dev/sdk 2>&1

[2024/03/25 02:58:04] warning: [UNKNOWN] We can't find the HPA line, has hdparm ouput unknown/changed? /dev/sdk
[2024/03/25 02:58:04]    info: hdparm:DCO Real max sectors reported as 1 on /dev/sdk
[2024/03/25 02:58:04]    info: NWipe: DCO Real max sectors reported as 1 on /dev/sdk
[2024/03/25 02:58:04]    info: libata: apparent max sectors reported as 2344225968 with sector size as 512/512 (logical/physical) on /dev/sdk
[2024/03/25 02:58:04]    info: func:nwipe_read_dco_real_max_sectors(), DCO real max sectors = 0
[2024/03/25 02:58:04]    info:  
[2024/03/25 02:58:04]  notice: Found /dev/sdl,  ATA    , ST1000NX0423, 1000 GB, S/N=XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:04]    info: /dev/sdl, sector(logical)/block(physical) sizes 512/512
[2024/03/25 02:58:04]    info: HPA:  max sectors   = 1953525168/1953525168, accessible max address disabled
 on /dev/sdl
[2024/03/25 02:58:04]    info: HPA values 1953525168 / 1953525168 on /dev/sdl
[2024/03/25 02:58:04]    info: DCO Real max sectors not found
[2024/03/25 02:58:04]    info: libata: apparent max sectors reported as 1953525168 with sector size as 512/512 (logical/physical) on /dev/sdl
[2024/03/25 02:58:04]    info: No hidden sectors on /dev/sdl
[2024/03/25 02:58:04]    info: func:nwipe_read_dco_real_max_sectors(), DCO real max sectors = 0
[2024/03/25 02:58:04]    info:  
[2024/03/25 02:58:04]  notice: Found /dev/sdm,  SAS    , TOSHIBA AL14SEB120N, 1200 GB, S/N=XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:04]    info: /dev/sdm, sector(logical)/block(physical) sizes 512/512
[2024/03/25 02:58:04]   error: SG_IO bad/missing sense data hdparm --verbose -N /dev/sdm 2>&1

[2024/03/25 02:58:04] warning: [UNKNOWN] We can't find the HPA line, has hdparm ouput unknown/changed? /dev/sdm
[2024/03/25 02:58:04]    info: hdparm:DCO Real max sectors reported as 1 on /dev/sdm
[2024/03/25 02:58:04]    info: NWipe: DCO Real max sectors reported as 1 on /dev/sdm
[2024/03/25 02:58:04]    info: libata: apparent max sectors reported as 2344225968 with sector size as 512/512 (logical/physical) on /dev/sdm
[2024/03/25 02:58:04]    info: func:nwipe_read_dco_real_max_sectors(), DCO real max sectors = 0
[2024/03/25 02:58:04]    info:  
[2024/03/25 02:58:04]  notice: Found /dev/sdn,  SAS    , SEAGATE ST1200MM0088, 1200 GB, S/N=XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:04]    info: /dev/sdn, sector(logical)/block(physical) sizes 512/512
[2024/03/25 02:58:04]   error: SG_IO bad/missing sense data hdparm --verbose -N /dev/sdn 2>&1

[2024/03/25 02:58:04] warning: [UNKNOWN] We can't find the HPA line, has hdparm ouput unknown/changed? /dev/sdn
[2024/03/25 02:58:04]    info: hdparm:DCO Real max sectors reported as 1 on /dev/sdn
[2024/03/25 02:58:04]    info: NWipe: DCO Real max sectors reported as 1 on /dev/sdn
[2024/03/25 02:58:04]    info: libata: apparent max sectors reported as 2344225968 with sector size as 512/512 (logical/physical) on /dev/sdn
[2024/03/25 02:58:04]    info: func:nwipe_read_dco_real_max_sectors(), DCO real max sectors = 0
[2024/03/25 02:58:04]    info:  
[2024/03/25 02:58:04]  notice: Found /dev/sdo,  ATA-SSD, Corsair Force LS,   60 GB, S/N=XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:04]    info: /dev/sdo, sector(logical)/block(physical) sizes 512/512
[2024/03/25 02:58:04]    info: HPA:  max sectors   = 117231408/117231408, hpa is disabled
 on /dev/sdo
[2024/03/25 02:58:04]    info: HPA values 117231408 / 117231408 on /dev/sdo
[2024/03/25 02:58:04]    info: hdparm:DCO Real max sectors reported as 117231408 on /dev/sdo
[2024/03/25 02:58:04]    info: NWipe: DCO Real max sectors reported as 117231408 on /dev/sdo
[2024/03/25 02:58:04]    info: libata: apparent max sectors reported as 117231408 with sector size as 512/512 (logical/physical) on /dev/sdo
[2024/03/25 02:58:04]    info: No hidden sectors on /dev/sdo
[2024/03/25 02:58:04]    info: func:nwipe_read_dco_real_max_sectors(), DCO real max sectors = 117231408
[2024/03/25 02:58:04]    info:  
[2024/03/25 02:58:04]  notice: Found /dev/sdp,  ATA-SSD, SanDisk SSD PLUS,  240 GB, S/N=XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:04]    info: /dev/sdp, sector(logical)/block(physical) sizes 512/512
[2024/03/25 02:58:04]    info: HPA:  max sectors   = 468862128/468862129, accessible max address enabled
 on /dev/sdp
[2024/03/25 02:58:04]    info: HPA values 468862128 / 468862129 on /dev/sdp
[2024/03/25 02:58:04]    info: hdparm:DCO Real max sectors reported as 468862128 on /dev/sdp
[2024/03/25 02:58:04]    info: NWipe: DCO Real max sectors reported as 468862128 on /dev/sdp
[2024/03/25 02:58:04]    info: libata: apparent max sectors reported as 468862128 with sector size as 512/512 (logical/physical) on /dev/sdp
[2024/03/25 02:58:04] warning:  *********************************
[2024/03/25 02:58:04] warning:  *** HIDDEN SECTORS DETECTED ! *** on /dev/sdp
[2024/03/25 02:58:04] warning:  *********************************
[2024/03/25 02:58:04]    info: func:nwipe_read_dco_real_max_sectors(), DCO real max sectors = 468862128
[2024/03/25 02:58:04]    info:  
[2024/03/25 02:58:04]  notice: Found /dev/sdq,  SAS-SSD, STEC Z16IZF2D-200UCT,  200 GB, S/N=XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:04]    info: /dev/sdq, sector(logical)/block(physical) sizes 512/512
[2024/03/25 02:58:04]   error: SG_IO bad/missing sense data hdparm --verbose -N /dev/sdq 2>&1

[2024/03/25 02:58:04] warning: [UNKNOWN] We can't find the HPA line, has hdparm ouput unknown/changed? /dev/sdq
[2024/03/25 02:58:04]    info: hdparm:DCO Real max sectors reported as 1 on /dev/sdq
[2024/03/25 02:58:04]    info: NWipe: DCO Real max sectors reported as 1 on /dev/sdq
[2024/03/25 02:58:04]    info: libata: apparent max sectors reported as 390721968 with sector size as 512/512 (logical/physical) on /dev/sdq
[2024/03/25 02:58:04]    info: func:nwipe_read_dco_real_max_sectors(), DCO real max sectors = 0
[2024/03/25 02:58:04]    info:  
[2024/03/25 02:58:04]  notice: Found /dev/sdr,  SAS-SSD, STEC SDT5C-S200SS,  200 GB, S/N=XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:04]    info: /dev/sdr, sector(logical)/block(physical) sizes 512/512
[2024/03/25 02:58:04]   error: SG_IO bad/missing sense data hdparm --verbose -N /dev/sdr 2>&1

[2024/03/25 02:58:04] warning: [UNKNOWN] We can't find the HPA line, has hdparm ouput unknown/changed? /dev/sdr
[2024/03/25 02:58:04]    info: hdparm:DCO Real max sectors reported as 1 on /dev/sdr
[2024/03/25 02:58:04]    info: NWipe: DCO Real max sectors reported as 1 on /dev/sdr
[2024/03/25 02:58:04]    info: libata: apparent max sectors reported as 390721968 with sector size as 512/512 (logical/physical) on /dev/sdr
[2024/03/25 02:58:04]    info: func:nwipe_read_dco_real_max_sectors(), DCO real max sectors = 0
[2024/03/25 02:58:04]    info:  
[2024/03/25 02:58:04] warning: Device /dev/sds not found
[2024/03/25 02:58:04]  notice: Found /dev/sdt,  SAS    , SEAGATE ST1200MM0088, 1200 GB, S/N=XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:04]    info: /dev/sdt, sector(logical)/block(physical) sizes 512/512
[2024/03/25 02:58:04]   error: SG_IO bad/missing sense data hdparm --verbose -N /dev/sdt 2>&1

[2024/03/25 02:58:04] warning: [UNKNOWN] We can't find the HPA line, has hdparm ouput unknown/changed? /dev/sdt
[2024/03/25 02:58:04]    info: hdparm:DCO Real max sectors reported as 1 on /dev/sdt
[2024/03/25 02:58:04]    info: NWipe: DCO Real max sectors reported as 1 on /dev/sdt
[2024/03/25 02:58:04]    info: libata: apparent max sectors reported as 2344225968 with sector size as 512/512 (logical/physical) on /dev/sdt
[2024/03/25 02:58:04]    info: func:nwipe_read_dco_real_max_sectors(), DCO real max sectors = 0
[2024/03/25 02:58:04]    info:  
[2024/03/25 02:58:04]  notice: Found /dev/sdu,  SAS    , HP MM1000FBFVR, 1000 GB, S/N=XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:04]    info: /dev/sdu, sector(logical)/block(physical) sizes 512/512
[2024/03/25 02:58:04]   error: SG_IO bad/missing sense data hdparm --verbose -N /dev/sdu 2>&1

[2024/03/25 02:58:04] warning: [UNKNOWN] We can't find the HPA line, has hdparm ouput unknown/changed? /dev/sdu
[2024/03/25 02:58:04]    info: hdparm:DCO Real max sectors reported as 1 on /dev/sdu
[2024/03/25 02:58:04]    info: NWipe: DCO Real max sectors reported as 1 on /dev/sdu
[2024/03/25 02:58:04]    info: libata: apparent max sectors reported as 1953525168 with sector size as 512/512 (logical/physical) on /dev/sdu
[2024/03/25 02:58:04]    info: func:nwipe_read_dco_real_max_sectors(), DCO real max sectors = 0
[2024/03/25 02:58:04]    info:  
[2024/03/25 02:58:04]  notice: Found /dev/sdv,  SAS    , HP MM1000FBFVR, 1000 GB, S/N=XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:04]    info: /dev/sdv, sector(logical)/block(physical) sizes 512/512
[2024/03/25 02:58:04]   error: SG_IO bad/missing sense data hdparm --verbose -N /dev/sdv 2>&1

[2024/03/25 02:58:04] warning: [UNKNOWN] We can't find the HPA line, has hdparm ouput unknown/changed? /dev/sdv
[2024/03/25 02:58:04]    info: hdparm:DCO Real max sectors reported as 1 on /dev/sdv
[2024/03/25 02:58:04]    info: NWipe: DCO Real max sectors reported as 1 on /dev/sdv
[2024/03/25 02:58:04]    info: libata: apparent max sectors reported as 1953525168 with sector size as 512/512 (logical/physical) on /dev/sdv
[2024/03/25 02:58:04]    info: func:nwipe_read_dco_real_max_sectors(), DCO real max sectors = 0
[2024/03/25 02:58:04]    info:  
[2024/03/25 02:58:04]  notice: Found /dev/sdw,  SAS    , HP MM1000FBFVR, 1000 GB, S/N=XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:04]    info: /dev/sdw, sector(logical)/block(physical) sizes 512/512
[2024/03/25 02:58:04]   error: SG_IO bad/missing sense data hdparm --verbose -N /dev/sdw 2>&1

[2024/03/25 02:58:04] warning: [UNKNOWN] We can't find the HPA line, has hdparm ouput unknown/changed? /dev/sdw
[2024/03/25 02:58:04]    info: hdparm:DCO Real max sectors reported as 1 on /dev/sdw
[2024/03/25 02:58:04]    info: NWipe: DCO Real max sectors reported as 1 on /dev/sdw
[2024/03/25 02:58:04]    info: libata: apparent max sectors reported as 1953525168 with sector size as 512/512 (logical/physical) on /dev/sdw
[2024/03/25 02:58:04]    info: func:nwipe_read_dco_real_max_sectors(), DCO real max sectors = 0
[2024/03/25 02:58:04]    info:  
[2024/03/25 02:58:04] warning: Device /dev/sdx not found
[2024/03/25 02:58:04] warning: Device /dev/sdy not found
[2024/03/25 02:58:04]  notice: Found /dev/sdz,  SAS    , HP MM1000FBFVR, 1000 GB, S/N=XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:04]    info: /dev/sdz, sector(logical)/block(physical) sizes 512/512
[2024/03/25 02:58:04]   error: SG_IO bad/missing sense data hdparm --verbose -N /dev/sdz 2>&1

[2024/03/25 02:58:04] warning: [UNKNOWN] We can't find the HPA line, has hdparm ouput unknown/changed? /dev/sdz
[2024/03/25 02:58:04]    info: hdparm:DCO Real max sectors reported as 1 on /dev/sdz
[2024/03/25 02:58:04]    info: NWipe: DCO Real max sectors reported as 1 on /dev/sdz
[2024/03/25 02:58:04]    info: libata: apparent max sectors reported as 1953525168 with sector size as 512/512 (logical/physical) on /dev/sdz
[2024/03/25 02:58:04]    info: func:nwipe_read_dco_real_max_sectors(), DCO real max sectors = 0
[2024/03/25 02:58:04]    info:  
[2024/03/25 02:58:04]    info: bios-version = 2.9.0
[2024/03/25 02:58:05]    info: bios-release-date = 12/06/2019
[2024/03/25 02:58:05]    info: system-manufacturer = Dell Inc.
[2024/03/25 02:58:05]    info: system-product-name = PowerEdge R720xd
[2024/03/25 02:58:05]    info: system-version = Not Specified
[2024/03/25 02:58:05]    info: system-serial-number = XXXXXXXXXXXXXXX
[2024/03/25 02:58:05]    info: system-uuid = XXXXXXXXXXXXXXX
[2024/03/25 02:58:05]    info: baseboard-manufacturer = Dell Inc.
[2024/03/25 02:58:05]    info: baseboard-product-name = 0020HJ
[2024/03/25 02:58:05]    info: baseboard-version = A01
[2024/03/25 02:58:05]    info: baseboard-serial-number = XXXXXXXXXXXXXXX
[2024/03/25 02:58:05]    info: baseboard-asset-tag = XXXXXXXXXXXXXXX
[2024/03/25 02:58:05]    info: chassis-manufacturer = Dell Inc.
[2024/03/25 02:58:05]    info: chassis-type = Rack Mount Chassis
[2024/03/25 02:58:05]    info: chassis-version = Not Specified
[2024/03/25 02:58:05]    info: chassis-serial-number = XXXXXXXXXXXXXXX
[2024/03/25 02:58:05]    info: chassis-asset-tag = XXXXXXXXXXXXXXX
[2024/03/25 02:58:05]    info: processor-family = Xeon
[2024/03/25 02:58:05]    info: processor-family = Xeon
[2024/03/25 02:58:05]    info: processor-manufacturer = Intel
[2024/03/25 02:58:05]    info: processor-manufacturer = Intel
[2024/03/25 02:58:05]    info: processor-version =       Intel(R) Xeon(R) CPU E5-2680 v2 @ 2.80GHz
[2024/03/25 02:58:05]    info: processor-version =       Intel(R) Xeon(R) CPU E5-2680 v2 @ 2.80GHz
[2024/03/25 02:58:05]    info: processor-frequency = 2800 MHz
[2024/03/25 02:58:05]    info: processor-frequency = 2800 MHz
[2024/03/25 02:58:05]  notice: Opened entropy source '/dev/urandom'.
[2024/03/25 02:58:05]  notice: hwmon: Module drivetemp loaded, drive temperatures available
[2024/03/25 02:58:05]  notice: hwmon: sdd has temperature monitoring
[2024/03/25 02:58:05]    info: Temperature limits for /dev/sdd, critical=N/A, max=N/A, highest=N/A, lowest=N/A, min=N/A, low critical=N/A. 
[2024/03/25 02:58:05]  notice: hwmon: sde has temperature monitoring
[2024/03/25 02:58:05]    info: Temperature limits for /dev/sde, critical=N/A, max=N/A, highest=N/A, lowest=N/A, min=N/A, low critical=N/A. 
[2024/03/25 02:58:05]  notice: hwmon: sdf has temperature monitoring
[2024/03/25 02:58:05]    info: Temperature limits for /dev/sdf, critical=N/A, max=N/A, highest=N/A, lowest=N/A, min=N/A, low critical=N/A. 
[2024/03/25 02:58:05]  notice: no hwmon data for /dev/sdg, try to get SCSI data
[2024/03/25 02:58:05]    info: got SCSI temperature data for /dev/sdg
[2024/03/25 02:58:05]    info: Temperature limits for /dev/sdg, critical=85c, max=80c, highest=30c, lowest=30c, min=N/A, low critical=-40c.
[2024/03/25 02:58:05]  notice: hwmon: sdh has temperature monitoring
[2024/03/25 02:58:05]    info: Temperature limits for /dev/sdh, critical=N/A, max=N/A, highest=N/A, lowest=N/A, min=N/A, low critical=N/A. 
[2024/03/25 02:58:05]  notice: hwmon: sdi has temperature monitoring
[2024/03/25 02:58:05]    info: Temperature limits for /dev/sdi, critical=N/A, max=N/A, highest=N/A, lowest=N/A, min=N/A, low critical=N/A. 
[2024/03/25 02:58:05]  notice: hwmon: sdj has temperature monitoring
[2024/03/25 02:58:05]    info: Temperature limits for /dev/sdj, critical=N/A, max=N/A, highest=N/A, lowest=N/A, min=N/A, low critical=N/A. 
[2024/03/25 02:58:05]  notice: no hwmon data for /dev/sdk, try to get SCSI data
[2024/03/25 02:58:05]    info: got SCSI temperature data for /dev/sdk
[2024/03/25 02:58:05]    info: Temperature limits for /dev/sdk, critical=60c, max=55c, highest=34c, lowest=34c, min=N/A, low critical=-40c.
[2024/03/25 02:58:05]  notice: hwmon: sdl has temperature monitoring
[2024/03/25 02:58:05]    info: Temperature limits for /dev/sdl, critical=N/A, max=N/A, highest=N/A, lowest=N/A, min=N/A, low critical=N/A. 
[2024/03/25 02:58:05]  notice: no hwmon data for /dev/sdm, try to get SCSI data
[2024/03/25 02:58:05]    info: got SCSI temperature data for /dev/sdm
[2024/03/25 02:58:05]    info: Temperature limits for /dev/sdm, critical=65c, max=60c, highest=32c, lowest=32c, min=N/A, low critical=-40c.
[2024/03/25 02:58:05]  notice: no hwmon data for /dev/sdn, try to get SCSI data
[2024/03/25 02:58:05]    info: got SCSI temperature data for /dev/sdn
[2024/03/25 02:58:05]    info: Temperature limits for /dev/sdn, critical=60c, max=55c, highest=32c, lowest=32c, min=N/A, low critical=-40c.
[2024/03/25 02:58:05]  notice: hwmon: sdo has temperature monitoring
[2024/03/25 02:58:05]    info: Temperature limits for /dev/sdo, critical=N/A, max=N/A, highest=N/A, lowest=N/A, min=N/A, low critical=N/A. 
[2024/03/25 02:58:05]  notice: hwmon: sdp has temperature monitoring
[2024/03/25 02:58:05]    info: Temperature limits for /dev/sdp, critical=N/A, max=N/A, highest=N/A, lowest=N/A, min=N/A, low critical=N/A. 
[2024/03/25 02:58:05]  notice: no hwmon data for /dev/sdq, try to get SCSI data
[2024/03/25 02:58:05]    info: got SCSI temperature data for /dev/sdq
[2024/03/25 02:58:05]    info: Temperature limits for /dev/sdq, critical=75c, max=70c, highest=50c, lowest=50c, min=N/A, low critical=-40c.
[2024/03/25 02:58:05]  notice: no hwmon data for /dev/sdr, try to get SCSI data
[2024/03/25 02:58:05]    info: got SCSI temperature data for /dev/sdr
[2024/03/25 02:58:05]    info: Temperature limits for /dev/sdr, critical=80c, max=75c, highest=56c, lowest=56c, min=N/A, low critical=-40c.
[2024/03/25 02:58:05]  notice: no hwmon data for /dev/sdt, try to get SCSI data
[2024/03/25 02:58:05]    info: got SCSI temperature data for /dev/sdt
[2024/03/25 02:58:05]    info: Temperature limits for /dev/sdt, critical=60c, max=55c, highest=34c, lowest=34c, min=N/A, low critical=-40c.
[2024/03/25 02:58:05]  notice: no hwmon data for /dev/sdu, try to get SCSI data
[2024/03/25 02:58:05]    info: got SCSI temperature data for /dev/sdu
[2024/03/25 02:58:05]    info: Temperature limits for /dev/sdu, critical=65c, max=60c, highest=31c, lowest=31c, min=N/A, low critical=-40c.
[2024/03/25 02:58:05]  notice: no hwmon data for /dev/sdv, try to get SCSI data
[2024/03/25 02:58:05]    info: got SCSI temperature data for /dev/sdv
[2024/03/25 02:58:05]    info: Temperature limits for /dev/sdv, critical=65c, max=60c, highest=31c, lowest=31c, min=N/A, low critical=-40c.
[2024/03/25 02:58:05]  notice: no hwmon data for /dev/sdw, try to get SCSI data
[2024/03/25 02:58:05]    info: got SCSI temperature data for /dev/sdw
[2024/03/25 02:58:05]    info: Temperature limits for /dev/sdw, critical=65c, max=60c, highest=32c, lowest=32c, min=N/A, low critical=-40c.
[2024/03/25 02:58:05]  notice: no hwmon data for /dev/sdz, try to get SCSI data
[2024/03/25 02:58:06]    info: got SCSI temperature data for /dev/sdz
[2024/03/25 02:58:06]    info: Temperature limits for /dev/sdz, critical=65c, max=60c, highest=32c, lowest=32c, min=N/A, low critical=-40c.
[2024/03/25 02:58:06]    info: Temperature limits for /dev/sdaa, critical=N/A, max=N/A, highest=N/A, lowest=N/A, min=N/A, low critical=N/A. 
[2024/03/25 02:58:06]    info: Temperature limits for /dev/sdab, critical=N/A, max=N/A, highest=N/A, lowest=N/A, min=N/A, low critical=N/A. 
[2024/03/25 02:58:32]  notice: Program options are set as follows...
[2024/03/25 02:58:32]  notice:   autonuke = 0 (off)
[2024/03/25 02:58:32]  notice:   autopoweroff = 0 (off)
[2024/03/25 02:58:32]  notice:   do not perform a final blank pass
[2024/03/25 02:58:32]  notice:   banner   = nwipe 0.36
[2024/03/25 02:58:32]  notice:   prng     = AES-CTR New Instructions (EXPERIMENTAL!)
[2024/03/25 02:58:32]  notice:   method   = PRNG Stream
[2024/03/25 02:58:32]  notice:   quiet    = 1
[2024/03/25 02:58:32]  notice:   rounds   = 1
[2024/03/25 02:58:32]  notice:   sync     = 100000
[2024/03/25 02:58:32]  notice:   verify   = 2 (all passes)
[2024/03/25 02:58:32]  notice: /dev/sdd has serial number XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:32]  notice: /dev/sdd, sect/blk/dev 512/4096/1000204886016
[2024/03/25 02:58:32]  notice: /dev/sde has serial number XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:32]  notice: /dev/sde, sect/blk/dev 512/4096/1000204886016
[2024/03/25 02:58:32]  notice: Invoking method 'PRNG Stream' on /dev/sdd
[2024/03/25 02:58:32]  notice: Starting round 1 of 1 on /dev/sdd
[2024/03/25 02:58:32]  notice: Starting pass 1/1, round 1/1, on /dev/sdd
[2024/03/25 02:58:32]  notice: Invoking method 'PRNG Stream' on /dev/sde
[2024/03/25 02:58:32]  notice: Starting round 1 of 1 on /dev/sde
[2024/03/25 02:58:32]  notice: Starting pass 1/1, round 1/1, on /dev/sde
[2024/03/25 02:58:32]  notice: /dev/sdf has serial number XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:32]  notice: /dev/sdf, sect/blk/dev 512/4096/1000204886016
[2024/03/25 02:58:32]  notice: Initialising AES CTR PRNG
[2024/03/25 02:58:32]  notice: /dev/sdh has serial number XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:32]  notice: Initialising AES CTR PRNG
[2024/03/25 02:58:32]  notice: /dev/sdh, sect/blk/dev 512/4096/240057409536
[2024/03/25 02:58:32]  notice: Invoking method 'PRNG Stream' on /dev/sdf
[2024/03/25 02:58:32]  notice: Starting round 1 of 1 on /dev/sdf
[2024/03/25 02:58:32]  notice: Starting pass 1/1, round 1/1, on /dev/sdf
[2024/03/25 02:58:32]  notice: Initialising AES CTR PRNG
[2024/03/25 02:58:32]  notice: /dev/sdi has serial number XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:32]  notice: /dev/sdi, sect/blk/dev 512/4096/500107862016
[2024/03/25 02:58:32]  notice: Invoking method 'PRNG Stream' on /dev/sdh
[2024/03/25 02:58:32]  notice: Starting round 1 of 1 on /dev/sdh
[2024/03/25 02:58:32]  notice: Starting pass 1/1, round 1/1, on /dev/sdh
[2024/03/25 02:58:32]  notice: Initialising AES CTR PRNG
[2024/03/25 02:58:32]  notice: /dev/sdj has serial number XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:32]  notice: /dev/sdj, sect/blk/dev 512/4096/240057409536
[2024/03/25 02:58:32]  notice: Invoking method 'PRNG Stream' on /dev/sdi
[2024/03/25 02:58:32]  notice: Starting round 1 of 1 on /dev/sdi
[2024/03/25 02:58:32]  notice: Starting pass 1/1, round 1/1, on /dev/sdi
[2024/03/25 02:58:32]  notice: Initialising AES CTR PRNG
[2024/03/25 02:58:32]  notice: /dev/sdk has serial number XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:32]  notice: /dev/sdk, sect/blk/dev 512/4096/1200243695616
[2024/03/25 02:58:32]  notice: Invoking method 'PRNG Stream' on /dev/sdj
[2024/03/25 02:58:32]  notice: Starting round 1 of 1 on /dev/sdj
[2024/03/25 02:58:32]  notice: Starting pass 1/1, round 1/1, on /dev/sdj
[2024/03/25 02:58:32]  notice: Initialising AES CTR PRNG
[2024/03/25 02:58:32]  notice: /dev/sdl has serial number XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:32]  notice: /dev/sdl, sect/blk/dev 512/4096/1000204886016
[2024/03/25 02:58:32]  notice: Invoking method 'PRNG Stream' on /dev/sdk
[2024/03/25 02:58:32]  notice: Starting round 1 of 1 on /dev/sdk
[2024/03/25 02:58:32]  notice: Starting pass 1/1, round 1/1, on /dev/sdk
[2024/03/25 02:58:32]  notice: Initialising AES CTR PRNG
[2024/03/25 02:58:32]  notice: /dev/sdo has serial number XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:32]  notice: /dev/sdo, sect/blk/dev 512/4096/60022480896
[2024/03/25 02:58:32]  notice: Invoking method 'PRNG Stream' on /dev/sdl
[2024/03/25 02:58:32]  notice: Starting round 1 of 1 on /dev/sdl
[2024/03/25 02:58:32]  notice: Starting pass 1/1, round 1/1, on /dev/sdl
[2024/03/25 02:58:32]  notice: Invoking method 'PRNG Stream' on /dev/sdo
[2024/03/25 02:58:32]  notice: Starting round 1 of 1 on /dev/sdo
[2024/03/25 02:58:32]  notice: Starting pass 1/1, round 1/1, on /dev/sdo
[2024/03/25 02:58:32]  notice: /dev/sdp has serial number XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:32]  notice: /dev/sdp, sect/blk/dev 512/4096/240057409536
[2024/03/25 02:58:32]  notice: Initialising AES CTR PRNG
[2024/03/25 02:58:32]  notice: Initialising AES CTR PRNG
[2024/03/25 02:58:32]  notice: /dev/sdr has serial number XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:32]  notice: /dev/sdr, sect/blk/dev 512/4096/200049647616
[2024/03/25 02:58:32]  notice: Invoking method 'PRNG Stream' on /dev/sdp
[2024/03/25 02:58:32]  notice: Starting round 1 of 1 on /dev/sdp
[2024/03/25 02:58:32]  notice: Starting pass 1/1, round 1/1, on /dev/sdp
[2024/03/25 02:58:32]  notice: Invoking method 'PRNG Stream' on /dev/sdr
[2024/03/25 02:58:32]  notice: Starting round 1 of 1 on /dev/sdr
[2024/03/25 02:58:32]  notice: Starting pass 1/1, round 1/1, on /dev/sdr
[2024/03/25 02:58:32]  notice: /dev/sdt has serial number XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:32]  notice: Initialising AES CTR PRNG
[2024/03/25 02:58:32]  notice: Initialising AES CTR PRNG
[2024/03/25 02:58:32]  notice: /dev/sdt, sect/blk/dev 512/4096/1200243695616
[2024/03/25 02:58:32]  notice: /dev/sdu has serial number XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:32]  notice: /dev/sdu, sect/blk/dev 512/4096/1000204886016
[2024/03/25 02:58:32]  notice: Invoking method 'PRNG Stream' on /dev/sdt
[2024/03/25 02:58:32]  notice: Starting round 1 of 1 on /dev/sdt
[2024/03/25 02:58:32]  notice: Starting pass 1/1, round 1/1, on /dev/sdt
[2024/03/25 02:58:32]  notice: /dev/sdv has serial number XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:32]  notice: /dev/sdv, sect/blk/dev 512/4096/1000204886016
[2024/03/25 02:58:32]  notice: Initialising AES CTR PRNG
[2024/03/25 02:58:32]  notice: Invoking method 'PRNG Stream' on /dev/sdu
[2024/03/25 02:58:32]  notice: Starting round 1 of 1 on /dev/sdu
[2024/03/25 02:58:32]  notice: Starting pass 1/1, round 1/1, on /dev/sdu
[2024/03/25 02:58:32]  notice: /dev/sdw has serial number XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:32]  notice: Invoking method 'PRNG Stream' on /dev/sdv
[2024/03/25 02:58:32]  notice: Starting round 1 of 1 on /dev/sdv
[2024/03/25 02:58:32]  notice: Starting pass 1/1, round 1/1, on /dev/sdv
[2024/03/25 02:58:32]  notice: Initialising AES CTR PRNG
[2024/03/25 02:58:32]  notice: /dev/sdw, sect/blk/dev 512/4096/1000204886016
[2024/03/25 02:58:32]  notice: Initialising AES CTR PRNG
[2024/03/25 02:58:32]  notice: /dev/sdz has serial number XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:32]  notice: /dev/sdz, sect/blk/dev 512/4096/1000204886016
[2024/03/25 02:58:32]  notice: Invoking method 'PRNG Stream' on /dev/sdw
[2024/03/25 02:58:32]  notice: Starting round 1 of 1 on /dev/sdw
[2024/03/25 02:58:32]  notice: Starting pass 1/1, round 1/1, on /dev/sdw
[2024/03/25 02:58:32]  notice: Invoking method 'PRNG Stream' on /dev/sdz
[2024/03/25 02:58:32]  notice: Starting round 1 of 1 on /dev/sdz
[2024/03/25 02:58:32]  notice: Starting pass 1/1, round 1/1, on /dev/sdz
[2024/03/25 02:58:32]  notice: Initialising AES CTR PRNG
[2024/03/25 02:58:32]  notice: Initialising AES CTR PRNG
[2024/03/25 02:58:32]  notice: /dev/sdaa has serial number XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:32]  notice: /dev/sdaa, sect/blk/dev 512/4096/80026361856
[2024/03/25 02:58:32]  notice: /dev/sdab has serial number XXXXXXXXXXXXXXXXXXXX
[2024/03/25 02:58:32]  notice: /dev/sdab, sect/blk/dev 512/4096/500107862016
[2024/03/25 02:58:32]  notice: Invoking method 'PRNG Stream' on /dev/sdaa
[2024/03/25 02:58:32]  notice: Starting round 1 of 1 on /dev/sdaa
[2024/03/25 02:58:32]  notice: Starting pass 1/1, round 1/1, on /dev/sdaa
[2024/03/25 02:58:32]  notice: Invoking method 'PRNG Stream' on /dev/sdab
[2024/03/25 02:58:32]  notice: Starting round 1 of 1 on /dev/sdab
[2024/03/25 02:58:32]  notice: Starting pass 1/1, round 1/1, on /dev/sdab
[2024/03/25 02:58:32]  notice: Initialising AES CTR PRNG
[2024/03/25 02:58:32]  notice: Initialising AES CTR PRNG
[2024/03/25 02:58:32]  notice: prng stream is active
[2024/03/25 02:58:32]  notice: prng stream is active
[2024/03/25 02:58:32]  notice: prng stream is active
[2024/03/25 02:58:32]  notice: prng stream is active
[2024/03/25 02:58:32]  notice: prng stream is active
[2024/03/25 02:58:32]  notice: prng stream is active
[2024/03/25 02:58:32]  notice: prng stream is active
[2024/03/25 02:58:32]  notice: prng stream is active
[2024/03/25 02:58:32]  notice: prng stream is active
[2024/03/25 02:58:32]  notice: prng stream is active
[2024/03/25 02:58:32]  notice: prng stream is active
[2024/03/25 02:58:32]  notice: prng stream is active
[2024/03/25 02:58:32]  notice: prng stream is active
[2024/03/25 02:58:32]  notice: prng stream is active
[2024/03/25 02:58:32]  notice: prng stream is active
[2024/03/25 02:58:32]  notice: prng stream is active
[2024/03/25 02:58:32]  notice: prng stream is active
[2024/03/25 02:58:32]  notice: prng stream is active
[2024/03/25 03:07:24]  notice: 60022480896 bytes written to /dev/sdo
[2024/03/25 03:07:24]  notice: Verifying pass 1 of 1, round 1 of 1, on /dev/sdo
[2024/03/25 03:07:24]  notice: Initialising AES CTR PRNG
[2024/03/25 03:11:26]  notice: 60022480896 bytes read from /dev/sdo
[2024/03/25 03:11:26]  notice: Verified pass 1 of 1, round 1 of 1, on '/dev/sdo'.
[2024/03/25 03:11:26]  notice: Finished pass 1/1, round 1/1, on /dev/sdo
[2024/03/25 03:11:26]  notice: Finished final round 1 of 1 on /dev/sdo
[2024/03/25 03:11:26]   error: 14653925 verification errors on '/dev/sdo'.
[2024/03/25 03:27:01]  notice: 200049647616 bytes written to /dev/sdr
[2024/03/25 03:27:01]  notice: Verifying pass 1 of 1, round 1 of 1, on /dev/sdr
[2024/03/25 03:27:01]  notice: Initialising AES CTR PRNG
[2024/03/25 03:35:21]  notice: 240057409536 bytes written to /dev/sdh
[2024/03/25 03:35:21]  notice: Verifying pass 1 of 1, round 1 of 1, on /dev/sdh
[2024/03/25 03:35:21]  notice: Initialising AES CTR PRNG
[2024/03/25 03:35:54]  notice: 240057409536 bytes written to /dev/sdp
[2024/03/25 03:35:54]  notice: Verifying pass 1 of 1, round 1 of 1, on /dev/sdp
[2024/03/25 03:35:54]  notice: Initialising AES CTR PRNG
[2024/03/25 03:44:36]  notice: 200049647616 bytes read from /dev/sdr
[2024/03/25 03:44:36]  notice: Verified pass 1 of 1, round 1 of 1, on '/dev/sdr'.
[2024/03/25 03:44:36]  notice: Finished pass 1/1, round 1/1, on /dev/sdr
[2024/03/25 03:44:36]  notice: Finished final round 1 of 1 on /dev/sdr
[2024/03/25 03:50:59]  notice: 500107862016 bytes written to /dev/sdi
[2024/03/25 03:50:59]  notice: Verifying pass 1 of 1, round 1 of 1, on /dev/sdi
[2024/03/25 03:50:59]  notice: Initialising AES CTR PRNG
[2024/03/25 03:51:49]  notice: 240057409536 bytes read from /dev/sdh
[2024/03/25 03:51:49]  notice: Verified pass 1 of 1, round 1 of 1, on '/dev/sdh'.
[2024/03/25 03:51:49]  notice: Finished pass 1/1, round 1/1, on /dev/sdh
[2024/03/25 03:51:49]  notice: Finished final round 1 of 1 on /dev/sdh
[2024/03/25 03:52:28]  notice: 240057409536 bytes read from /dev/sdp
[2024/03/25 03:52:28]  notice: Verified pass 1 of 1, round 1 of 1, on '/dev/sdp'.
[2024/03/25 03:52:28]  notice: Finished pass 1/1, round 1/1, on /dev/sdp
[2024/03/25 03:52:28]  notice: Finished final round 1 of 1 on /dev/sdp
[2024/03/25 03:54:43]  notice: 240057409536 bytes written to /dev/sdj
[2024/03/25 03:54:43]  notice: Verifying pass 1 of 1, round 1 of 1, on /dev/sdj
[2024/03/25 03:54:43]  notice: Initialising AES CTR PRNG
[2024/03/25 04:11:16]  notice: 240057409536 bytes read from /dev/sdj
[2024/03/25 04:11:16]  notice: Verified pass 1 of 1, round 1 of 1, on '/dev/sdj'.
[2024/03/25 04:11:16]  notice: Finished pass 1/1, round 1/1, on /dev/sdj
[2024/03/25 04:11:16]  notice: Finished final round 1 of 1 on /dev/sdj
[2024/03/25 04:11:16]   error: 58607765 verification errors on '/dev/sdj'.
[2024/03/25 04:14:57]  notice: 80026361856 bytes written to /dev/sdaa
[2024/03/25 04:14:57]  notice: Verifying pass 1 of 1, round 1 of 1, on /dev/sdaa
[2024/03/25 04:14:57]  notice: Initialising AES CTR PRNG
[2024/03/25 04:26:53]  notice: 500107862016 bytes read from /dev/sdi
[2024/03/25 04:26:53]  notice: Verified pass 1 of 1, round 1 of 1, on '/dev/sdi'.
[2024/03/25 04:26:53]  notice: Finished pass 1/1, round 1/1, on /dev/sdi
[2024/03/25 04:26:53]  notice: Finished final round 1 of 1 on /dev/sdi
[2024/03/25 05:27:12]  notice: 80026361856 bytes read from /dev/sdaa
[2024/03/25 05:27:12]  notice: Verified pass 1 of 1, round 1 of 1, on '/dev/sdaa'.
[2024/03/25 05:27:12]  notice: Finished pass 1/1, round 1/1, on /dev/sdaa
[2024/03/25 05:27:12]  notice: Finished final round 1 of 1 on /dev/sdaa
[2024/03/25 06:27:29]  notice: 1200243695616 bytes written to /dev/sdk
[2024/03/25 06:27:29]  notice: Verifying pass 1 of 1, round 1 of 1, on /dev/sdk
[2024/03/25 06:27:29]  notice: Initialising AES CTR PRNG
[2024/03/25 06:27:30]  notice: 1200243695616 bytes written to /dev/sdt
[2024/03/25 06:27:30]  notice: Verifying pass 1 of 1, round 1 of 1, on /dev/sdt
[2024/03/25 06:27:30]  notice: Initialising AES CTR PRNG
[2024/03/25 06:45:59]  notice: 1000204886016 bytes written to /dev/sdf
[2024/03/25 06:45:59]  notice: Verifying pass 1 of 1, round 1 of 1, on /dev/sdf
[2024/03/25 06:45:59]  notice: Initialising AES CTR PRNG
[2024/03/25 06:47:07]  notice: 1000204886016 bytes written to /dev/sdl
[2024/03/25 06:47:07]  notice: Verifying pass 1 of 1, round 1 of 1, on /dev/sdl
[2024/03/25 06:47:07]  notice: Initialising AES CTR PRNG
[2024/03/25 06:47:31]  notice: 1000204886016 bytes written to /dev/sdd
[2024/03/25 06:47:31]  notice: Verifying pass 1 of 1, round 1 of 1, on /dev/sdd
[2024/03/25 06:47:31]  notice: Initialising AES CTR PRNG
[2024/03/25 06:49:17]  notice: 1000204886016 bytes written to /dev/sde
[2024/03/25 06:49:17]  notice: Verifying pass 1 of 1, round 1 of 1, on /dev/sde
[2024/03/25 06:49:17]  notice: Initialising AES CTR PRNG
[2024/03/25 07:09:00]  notice: 1000204886016 bytes written to /dev/sdz
[2024/03/25 07:09:00]  notice: Verifying pass 1 of 1, round 1 of 1, on /dev/sdz
[2024/03/25 07:09:00]  notice: Initialising AES CTR PRNG
[2024/03/25 07:09:41]  notice: 1000204886016 bytes written to /dev/sdw
[2024/03/25 07:09:41]  notice: Verifying pass 1 of 1, round 1 of 1, on /dev/sdw
[2024/03/25 07:09:41]  notice: Initialising AES CTR PRNG
[2024/03/25 07:10:09]  notice: 1000204886016 bytes written to /dev/sdu
[2024/03/25 07:10:09]  notice: Verifying pass 1 of 1, round 1 of 1, on /dev/sdu
[2024/03/25 07:10:09]  notice: Initialising AES CTR PRNG
[2024/03/25 07:10:50]  notice: 1000204886016 bytes written to /dev/sdv
[2024/03/25 07:10:50]  notice: Verifying pass 1 of 1, round 1 of 1, on /dev/sdv
[2024/03/25 07:10:50]  notice: Initialising AES CTR PRNG
[2024/03/25 08:07:22]  notice: 500107862016 bytes written to /dev/sdab
[2024/03/25 08:07:22]  notice: Verifying pass 1 of 1, round 1 of 1, on /dev/sdab
[2024/03/25 08:07:22]  notice: Initialising AES CTR PRNG
[2024/03/25 08:36:24]  notice: 1200243695616 bytes read from /dev/sdt
[2024/03/25 08:36:24]  notice: Verified pass 1 of 1, round 1 of 1, on '/dev/sdt'.
[2024/03/25 08:36:24]  notice: Finished pass 1/1, round 1/1, on /dev/sdt
[2024/03/25 08:36:24]  notice: Finished final round 1 of 1 on /dev/sdt
[2024/03/25 08:36:24]  notice: 1200243695616 bytes read from /dev/sdk
[2024/03/25 08:36:24]  notice: Verified pass 1 of 1, round 1 of 1, on '/dev/sdk'.
[2024/03/25 08:36:24]  notice: Finished pass 1/1, round 1/1, on /dev/sdk
[2024/03/25 08:36:24]  notice: Finished final round 1 of 1 on /dev/sdk
[2024/03/25 09:27:02]  notice: 1000204886016 bytes read from /dev/sdf
[2024/03/25 09:27:02]  notice: Verified pass 1 of 1, round 1 of 1, on '/dev/sdf'.
[2024/03/25 09:27:02]  notice: Finished pass 1/1, round 1/1, on /dev/sdf
[2024/03/25 09:27:02]  notice: Finished final round 1 of 1 on /dev/sdf
[2024/03/25 09:28:33]  notice: 1000204886016 bytes read from /dev/sdl
[2024/03/25 09:28:33]  notice: Verified pass 1 of 1, round 1 of 1, on '/dev/sdl'.
[2024/03/25 09:28:33]  notice: Finished pass 1/1, round 1/1, on /dev/sdl
[2024/03/25 09:28:33]  notice: Finished final round 1 of 1 on /dev/sdl
[2024/03/25 09:29:30]  notice: 1000204886016 bytes read from /dev/sdd
[2024/03/25 09:29:30]  notice: Verified pass 1 of 1, round 1 of 1, on '/dev/sdd'.
[2024/03/25 09:29:30]  notice: Finished pass 1/1, round 1/1, on /dev/sdd
[2024/03/25 09:29:30]  notice: Finished final round 1 of 1 on /dev/sdd
[2024/03/25 09:34:51]  notice: 1000204886016 bytes read from /dev/sde
[2024/03/25 09:34:51]  notice: Verified pass 1 of 1, round 1 of 1, on '/dev/sde'.
[2024/03/25 09:34:51]  notice: Finished pass 1/1, round 1/1, on /dev/sde
[2024/03/25 09:34:51]  notice: Finished final round 1 of 1 on /dev/sde
[2024/03/25 09:34:51]   error: 244090646 verification errors on '/dev/sde'.
[2024/03/25 10:09:03]  notice: 1000204886016 bytes read from /dev/sdz
[2024/03/25 10:09:03]  notice: Verified pass 1 of 1, round 1 of 1, on '/dev/sdz'.
[2024/03/25 10:09:03]  notice: Finished pass 1/1, round 1/1, on /dev/sdz
[2024/03/25 10:09:03]  notice: Finished final round 1 of 1 on /dev/sdz
[2024/03/25 10:10:01]  notice: 1000204886016 bytes read from /dev/sdw
[2024/03/25 10:10:01]  notice: Verified pass 1 of 1, round 1 of 1, on '/dev/sdw'.
[2024/03/25 10:10:01]  notice: Finished pass 1/1, round 1/1, on /dev/sdw
[2024/03/25 10:10:01]  notice: Finished final round 1 of 1 on /dev/sdw
[2024/03/25 10:10:45]  notice: 1000204886016 bytes read from /dev/sdu
[2024/03/25 10:10:45]  notice: Verified pass 1 of 1, round 1 of 1, on '/dev/sdu'.
[2024/03/25 10:10:45]  notice: Finished pass 1/1, round 1/1, on /dev/sdu
[2024/03/25 10:10:45]  notice: Finished final round 1 of 1 on /dev/sdu
[2024/03/25 10:12:30]  notice: 1000204886016 bytes read from /dev/sdv
[2024/03/25 10:12:30]  notice: Verified pass 1 of 1, round 1 of 1, on '/dev/sdv'.
[2024/03/25 10:12:30]  notice: Finished pass 1/1, round 1/1, on /dev/sdv
[2024/03/25 10:12:30]  notice: Finished final round 1 of 1 on /dev/sdv
[2024/03/25 11:42:39]  notice: 500107862016 bytes read from /dev/sdab
[2024/03/25 11:42:39]  notice: Verified pass 1 of 1, round 1 of 1, on '/dev/sdab'.
[2024/03/25 11:42:39]  notice: Finished pass 1/1, round 1/1, on /dev/sdab
[2024/03/25 11:42:39]  notice: Finished final round 1 of 1 on /dev/sdab
[2024/03/25 12:33:09]   fatal: Nwipe exited with errors on device = /dev/sde, see log for specific error

[2024/03/25 12:33:09]   fatal: Nwipe exited with errors on device = /dev/sdj, see log for specific error

[2024/03/25 12:33:09]   fatal: Nwipe exited with errors on device = /dev/sdo, see log for specific error

******************************** Error Summary *********************************
!   Device | Pass Errors | Verifications Errors | Fdatasync I\O Errors
--------------------------------------------------------------------------------
       sdd |           0 |                    0 |                    0
!      sde |           1 |            244090646 |                    0
       sdf |           0 |                    0 |                    0
       sdh |           0 |                    0 |                    0
       sdi |           0 |                    0 |                    0
!      sdj |           1 |             58607765 |                    0
       sdk |           0 |                    0 |                    0
       sdl |           0 |                    0 |                    0
!      sdo |           1 |             14653925 |                    0
       sdp |           0 |                    0 |                    0
       sdr |           0 |                    0 |                    0
       sdt |           0 |                    0 |                    0
       sdu |           0 |                    0 |                    0
       sdv |           0 |                    0 |                    0
       sdw |           0 |                    0 |                    0
       sdz |           0 |                    0 |                    0
      sdaa |           0 |                    0 |                    0
      sdab |           0 |                    0 |                    0
********************************************************************************

********************************* Drive Status *********************************
!   Device | Status | Thru-put | HH:MM:SS | Model/Serial Number
--------------------------------------------------------------------------------
       sdd | Erased |   85 MB/s | 06:30:58 | ST1000NX0423/XXXXXXXXXXXXXXXXXXXX
!      sde |-FAILED-|   84 MB/s | 06:36:19 | ST1000NX0423/XXXXXXXXXXXXXXXXXXXX
       sdf | Erased |   85 MB/s | 06:28:30 | ST1000NX0423/XXXXXXXXXXXXXXXXXXXX
       sdh | Erased |  150 MB/s | 06:53:17 | SanDisk SSD PLUS/XXXXXXXXXXXXXXXXXXXX
       sdi | Erased |  188 MB/s | 01:28:21 | CT500MX500SSD1/XXXXXXXXXXXXXXXXXXXX
!      sdj |-FAILED-|  110 MB/s | 01:12:44 | OCZ-TRION100/XXXXXXXXXXXXXXXXXXXX
       sdk | Erased |  118 MB/s | 05:37:52 | SEAGATE ST1200MM0/XXXXXXXXXXXXXXXXXXXX
       sdl | Erased |   85 MB/s | 06:30:01 | ST1000NX0423/XXXXXXXXXXXXXXXXXXXX
!      sdo |-FAILED-|  155 MB/s | 06:12:54 | Corsair Force LS/XXXXXXXXXXXXXXXXXXXX
       sdp | Erased |  148 MB/s | 06:53:56 | SanDisk SSD PLUS/XXXXXXXXXXXXXXXXXXXX
       sdr | Erased |  144 MB/s | 06:46:04 | STEC SDT5C-S200SS/XXXXXXXXXXXXXXXXXXXX
       sdt | Erased |  118 MB/s | 05:37:52 | SEAGATE ST1200MM0/XXXXXXXXXXXXXXXXXXXX
       sdu | Erased |   77 MB/s | 07:12:13 | HP MM1000FBFVR/XXXXXXXXXXXXXXXXXXXX
       sdv | Erased |   76 MB/s | 07:13:58 | HP MM1000FBFVR/XXXXXXXXXXXXXXXXXXXX
       sdw | Erased |   77 MB/s | 07:11:29 | HP MM1000FBFVR/XXXXXXXXXXXXXXXXXXXX
       sdz | Erased |   77 MB/s | 07:10:31 | HP MM1000FBFVR/XXXXXXXXXXXXXXXXXXXX
      sdaa | Erased |   17 MB/s | 02:28:40 | Seagate FreeAgent/XXXXXXXXXXXXXXXXXXXX
      sdab | Erased |   31 MB/s | 08:44:07 | Samsung SSD 860 E/XXXXXXXXXXXXXXXXXXXX
--------------------------------------------------------------------------------
[2024/03/25 12:34:14] Total Throughput 1833 MB/s, PRNG Stream, 1R+NB+VA
********************************************************************************

Creating PDF report in .

[2024/03/25 12:34:14]    info: Nwipe was aborted by the user. Check the summary table for the drive status.
PartialVolume commented 8 months ago

Based on drive I/O throughput, it looks like AES-CTR is about 10% slower than XORshiro.

PartialVolume commented 8 months ago

Below is the hex data of the first block of a drive that failed verification on every block, looking like random data.

00000000   16 88 DC 48  DD 6E E1 6E  F4 4D CE 51  D4 4D 54 8E  DE 4C 73 4F  ...H.n.n.M.Q.MT..LsO
00000014   4E 67 8F 3B  75 6D 99 42  86 75 DD 92  9D 6D F4 01  DC D6 F3 0A  Ng.;um.B.u...m......
00000028   E7 C7 FB F8  57 FA E0 E3  82 B4 B9 B4  8C 4A 72 3B  F2 1A 0E B4  ....W........Jr;....
0000003C   50 B3 B5 E5  3D DB FE A7  4B 6F A7 6C  01 F4 FD 89  F1 57 24 27  P...=...Ko.l.....W$'
00000050   81 9F F1 5F  E5 CD 49 CD  CC D7 02 BB  80 0F 8A B2  16 69 7F 7D  ..._..I..........i.}
00000064   DE 56 38 18  5B 34 98 03  AF CA E5 EA  BC CD C0 24  62 89 C2 83  .V8.[4.........$b...
00000078   BA 4D 2B C6  31 14 AF 7F  A9 42 BC DE  1D BE FD 5D  61 1E ED 0F  .M+.1....B.....]a...
0000008C   66 EB FB 03  0E FC 39 9E  B9 C4 0E FF  55 C7 55 9D  62 21 52 45  f.....9.....U.U.b!RE
000000A0   D5 C9 69 AF  70 A7 C4 17  0B 05 31 32  56 DF 75 25  FC 41 69 37  ..i.p.....12V.u%.Ai7
000000B4   35 12 EA DF  2C F7 E2 4C  CA 82 E3 8C  98 F0 EB 5B  82 4A E8 FC  5...,..L.......[.J..
000000C8   CA 05 B3 A2  07 EF 79 FA  EF AF D9 76  17 59 F7 00  B7 7F BA 05  ......y....v.Y......
000000DC   5D 45 20 4B  28 9D 09 5E  F1 8A 4D FC  D2 14 03 FC  23 96 66 BD  ]E K(..^..M.....#.f.
000000F0   5F 46 CC 11  73 27 4B 49  D9 0C 8D A8  E5 B1 EE CC  0A 50 6A 74  _F..s'KI.........Pjt
00000104   EF CD 37 17  40 19 11 C8  57 88 68 ED  EE ED F1 3B  3F D1 2D CA  ..7.@...W.h....;?.-.
00000118   CE 4C A8 26  83 70 D4 D2  F6 C6 BC 9A  9F C0 2B 6B  3D 89 3C BA  .L.&.p........+k=.<.
0000012C   7D C7 6D 3E  34 2E 2B C4  86 1A E7 F2  A3 BC B5 21  37 A2 8F 8A  }.m>4.+........!7...
00000140   63 F3 04 71  30 44 E9 08  7A 9E D9 A0  A0 C9 89 1C  30 23 B5 54  c..q0D..z.......0#.T
00000154   EC 79 75 E5  7A FB 4E A8  61 DD 91 A4  0A 36 F0 C5  96 EB 70 B8  .yu.z.N.a....6....p.
00000168   ED 56 27 1D  B9 6D 67 8D  62 80 21 8E  E3 FD EC 34  E5 C7 CB 6E  .V'..mg.b.!....4...n
0000017C   4C 08 31 CF  50 51 E1 23  9C D3 0E F2  DC 7C 5D 44  FD 53 DC 1C  L.1.PQ.#.....|]D.S..
00000190   8E C3 85 B8  4A 28 22 37  58 E4 12 51  D0 C6 DB 64  DD 8C 60 12  ....J("7X..Q...d..`.
000001A4   37 99 3E 07  66 7A 9C 62  54 E3 BB 20  24 67 96 7F  7B 03 F3 1D  7.>.fz.bT.. $g..{...
000001B8   92 8F 8F 90  43 8C 07 C7  BF A6 8D 46  E1 1B 4A EA  60 DC 3E E4  ....C......F..J.`.>.
000001CC   E6 D0 D2 69  66 56 00 9B  36 3A 8E 17  79 61 72 B0  6E 05 74 0B  ...ifV..6:..yar.n.t.
000001E0   3F 5A 9D E3  17 C7 EA 51  21 65 83 43  AA A9 A7 54  DF 88 4C 8F  ?Z.....Q!e.C...T..L.
000001F4   50 82 E6 10  58 0D 45 DF  BE B0 14 24  85 A0 0E EF  89 4C 80 51  P...X.E....$.....L.Q
00000208   CF C0 71 1A  C8 39 85 B3  62 E2 68 66  A1 AC AC C1  54 EC AA 8D  ..q..9..b.hf....T...
0000021C   37 8C D8 78  9F 6F 8D 9D  12 A2 05 A7  CC B7 E1 8B  1E 69 8B 1E  7..x.o...........i..
00000230   D8 9B 4A 5E  5E 33 BB 27  8B 14 EE CD  E9 63 19 E3  9D 22 04 EA  ..J^^3.'.....c..."..
00000244   C2 2F B5 D4  FA 1D 96 2C  B4 5D 73 35  D3 67 D9 BD  C3 77 B6 2E  ./.....,.]s5.g...w..
00000258   B3 1B B7 76  A5 E6 C8 29  D1 AB A2 9D  2E 18 82 D7  D3 AC 04 24  ...v...)...........$
0000026C   FF FB 3F 56  C1 7C EF 57  B7 C2 74 51  0B 6B 3D AF  6F DF 37 5B  ..?V.|.W..tQ.k=.o.7[
00000280   FB A1 B2 E7  A8 81 C7 BF  29 64 8E A9  23 A9 27 64  8A A8 1B 67  ........)d..#.'d...g
00000294   22 81 1B 54  6C 1C 4D F9  E0 4C 0D B9  31 DF 39 39  07 71 8A B3  "..Tl.M..L..1.99.q..
000002A8   C0 D4 2C 27  E5 7D 23 A6  77 18 C3 C0  65 45 14 57  8D 90 14 CA  ..,'.}#.w...eE.W....
000002BC   C8 33 99 25  57 35 15 E7  E2 98 0C 30  75 22 D9 2E  43 57 96 77  .3.%W5.....0u"..CW.w
000002D0   89 58 0B 95  E7 69 B2 63  9C E9 E5 B6  49 93 31 DF  54 55 E6 B6  .X...i.c....I.1.TU..
000002E4   D0 94 27 AB  77 CC DE F8  B9 D9 29 9A  50 AA B6 CA  FA E7 D8 FC  ..'.w.....).P.......
000002F8   99 A6 E2 A3  0E 33 75 7B  46 6A F4 A9  CF 57 19 4A  B9 32 32 FB  .....3u{Fj...W.J.22.
0000030C   28 BA 40 06  48 AB 3E B9  CF 82 46 FF  87 CC 05 53  26 E1 BC 0E  (.@.H.>...F....S&...
00000320   31 F2 D1 F8  83 D9 C6 3E  BA F8 44 40  41 2D 4A 13  B2 C7 0D 35  1......>..D@A-J....5
00000334   F7 1C 01 47  CB C5 02 41  BF D4 5A 97  92 2F 20 27  3F 0E E7 45  ...G...A..Z../ '?..E
00000348   AA 91 A5 5E  A9 4B 2E 52  B5 80 78 CD  4E AF 13 2B  41 19 2E 2A  ...^.K.R..x.N..+A..*
0000035C   30 96 5C 6A  21 5C E3 DC  5A DE 3E 8A  AF 9D 2B 20  6E 8D A9 92  0.\j!\..Z.>...+ n...
00000370   38 B0 72 C7  04 E9 B6 07  8B C9 E9 6E  82 E1 F6 BD  28 D3 9D 04  8.r........n....(...
00000384   2C 50 1B 9C  D3 64 DD F5  33 84 D5 01  19 B4 40 C2  6B A6 B9 67  ,P...d..3.....@.k..g
00000398   13 AF 43 96  DC 03 FB B8  BF 97 3C 73  13 C4 59 C8  DF 7A 9B CF  ..C.......<s..Y..z..
000003AC   C6 E3 03 33  CA DF 94 0D  63 63 55 E1  A9 F0 98 87  89 63 5F DC  ...3....ccU......c_.
000003C0   D8 C1 CE C7  C3 6D 5D B6  92 A2 3A B3  6C 25 EA AA  39 61 B4 E4  .....m]...:.l%..9a..
000003D4   A2 ED 85 6E  F5 8F 5F 37  B2 D0 D6 50  4B 0B DB BE  36 19 ED 6E  ...n.._7...PK...6..n
000003E8   17 B6 2C 9A  E4 00 A2 54  02 BA 64 6B  30 A1 1A 67  6B 8B FB 75  ..,....T..dk0..gk..u
000003FC   AE E7 C8 60  1F B3 28 48  EA 63 1E 23  19 06 E4 A0  1C 88 5B 25  ...`..(H.c.#......[%
00000410   E8 BC FE 45  9B 34 EA B7  B5 43 DE 47  07 5F E6 47  CD B7 2C 47  ...E.4...C.G._.G..,G
00000424   CC EA 8A C3  07 5D 25 2A  44 A1 CF 3D  56 C7 0F 6B  FC 79 EE 74  .....]%*D..=V..k.y.t
PartialVolume commented 8 months ago

@Knogle If you want me to rerun the test with some debug code added, let me know.

Knogle commented 8 months ago

@Knogle If you want me to rerun the test with some debug code added, let me know.

Thanks a lot for your testing already. As i see, real hard drives still behave differently than loop devices heh. But i think we are already a bit closer.

Can you clone my aes-ctr-debug branch and build it? I will add further debug code there to not mess up this PR. Currently i have set a static seed for all runs, so it will always generate the same random data. So we can check if there is something wrong with the seed itself, or something else.

I personally i am suspecting still some kind of buffer overflow of bufpos, but let's test :)

unsigned long static_seed[] = {0x12345678, 0x9abcdef0}; // Example of a static seed
unsigned long seed_length = sizeof(static_seed) / sizeof(unsigned long); // Calculate the length of the seed
PartialVolume commented 8 months ago

debug branch is running. I'll update you in a few hours.

Knogle commented 8 months ago

Thanks! I really hope we can sort this out :) It passes the mother of all tests, the BigCrush test also without issues.

========= Summary results of BigCrush =========

 Version:          TestU01 1.2.3
 Generator:        ufile_CreateReadBin
 Number of statistics:  160
 Total CPU time:   01:56:28.39

 All tests were passed
PartialVolume commented 8 months ago

Fails as before, different drives though. Bug in openssl?

https://github.com/martijnvanbrummelen/nwipe/assets/22084881/a2eabe46-002c-45e7-b0ed-c59fd5ce31ed

Knogle commented 8 months ago

Hey. To be honest i dont suspect an issue in OpenSSL here. I've opened an issue on https://github.com/openssl/openssl already and we've gone through everything. I think in order to fix that, we have to further understand how bufpos works. Because changing the method of writing into buffer, using a temp_buffer, has already massively decreased the amount of failing drives. Usually the issue we have is: Something happens, i don't know exactly what, somehow we are having a buffer overrun, causing memory that contains state->ctx to be not initialized, written full of random content, causing to have a different seed in runtime. The other PRNGs i implemented are not subsceptible to this issue, even when having a buffer overflow, because they don't rely on further parameters apart from the seed.

Could you run your run with valgrind, means, valgrind nwipe or something similar , just put valgrind in front. It will take massively longer, but the result would be very interesting in order to track the issue down.

EDIT: I am also suspecting something behind the writing process into the buffer. Because i can't reproduce this issue, even using massive amount of loop devices.

Knogle commented 8 months ago

I can try to utilize the u32_to_buf functions provided by nwipe itself, maybe it will work differently.

EDIT:

I've updated the debug branch again, maybe another try? Screenshot from 2024-03-25 20-46-07

PartialVolume commented 8 months ago

I can try to utilize the u32_to_buf functions provided by nwipe itself, maybe it will work differently.

EDIT:

I've updated the debug branch again, maybe another try?

The test is running.

PartialVolume commented 8 months ago

Failed.

Screenshot_20240325_232805

Knogle commented 8 months ago

Oh okay, now i am really out of ideas unfortunately. Using own AES implementation would be around 1000 lines of code, so that's no feasible option. Maybe try the binary i've built, maybe it's some issue with the OpenSSL version. If it dosn't work, please try to run nwipe using valgrind, so we can check it out after a few days what's actually wrong. nwipe.zip

PartialVolume commented 8 months ago

Oh okay, now i am really out of ideas unfortunately. Using own AES implementation would be around 1000 lines of code, so that's no feasible option. Maybe try the binary i've built, maybe it's some issue with the OpenSSL version. If it dosn't work, please try to run nwipe using valgrind, so we can check it out after a few days what's actually wrong. nwipe.zip

I'm just thinking about logging the key, state IV and first 4096 block to a file on every initialisation along with data identifying the device. Then a comparison can be made between these values on the wipe & verification passes. These values should then hopefully identify whether the problem is in the nwipe code or the openssl code.

You said valgrind was reporting un-initialised variables somewhere? Was that in the openssl functions?

Also the function calls in the initialisation function should really have there return status checked and a output to nwipe_log on failure.

I had a look at the EVP code and it does look like it should be thread safe (in theory). Unfortunately wrapping the openssl functions in a lock drastically reduces throughput < 1MB/sec and would take 200+ hours to complete the test. So for the time being I've put that to one side.

Knogle commented 8 months ago

Please give it a try :) I'm curious about your results.

Using valgrind i was able to find out, EVP_EncryptUpdate inside of aes_ctr_prng_genrand_uint128_to_buf wasn't initialized correctly.

==40641== Conditional jump or move depends on uninitialised value(s)
==40641==    at 0x4B9F565: CRYPTO_ctr128_encrypt_ctr32 (ctr128.c:183)
==40641==    by 0x4C655A1: ossl_cipher_hw_generic_ctr (ciphercommon_hw.c:117)
==40641==    by 0x4C60FCC: ossl_cipher_generic_stream_update (ciphercommon.c:469)
==40641==    by 0x4B61076: EVP_EncryptUpdate (evp_enc.c:643)
==40641==    by 0x414314: aes_ctr_prng_genrand_uint128_to_buf (aes_ctr_prng.c:133)
==40641==    by 0x417F5F: nwipe_aes_ctr_prng_read (prng.c:293)

But we are correctly allocating memory and initializing it through calloc.

*state = calloc( 1, sizeof( aes_ctr_state_t ) );

The RAM layout is more or less like this

nwipe --> aes_ctr_state --> bufpos --> aes-ivec --> aes-ecount --> aes-key

if bufpos is overrun, it wil lwrite into aes-ivec, causing it to be not-initialized anymore, containing random data, leading into a different stream of PRNG data.

Here one of my snippets in order to logging.

#include "aes_ctr_prng.h"
#include <openssl/evp.h>
#include <openssl/sha.h>
#include <string.h>
#include <stdio.h>
#include <openssl/err.h>

// Helper function to log data as a hex string to a file
void log_data_to_file(const char* filename, const unsigned char* data, size_t data_len) {
    FILE* file = fopen(filename, "a");  // 'a' to append at the end of the file
    if (!file) {
        perror("Error opening log file");
        return;
    }
    for (size_t i = 0; i < data_len; ++i) {
        fprintf(file, "%02X", data[i]);
    }
    fprintf(file, "\n");
    fclose(file);
}

void aes_ctr_prng_init(aes_ctr_state_t* state, unsigned long init_key[], unsigned long key_length) {
    unsigned char key[32];  // Space for a 256-bit key
    int ret;

    memset(state->ivec, 0, AES_BLOCK_SIZE);
    state->num = 0;
    memset(state->ecount, 0, AES_BLOCK_SIZE);

    EVP_MD_CTX* mdctx = EVP_MD_CTX_new();
    if (!mdctx) {
        fprintf(stderr, "Failed to create EVP_MD_CTX\n");
        ERR_print_errors_fp(stderr);
        return;
    }

    ret = EVP_DigestInit_ex(mdctx, EVP_sha256(), NULL);
    if (!ret) {
        fprintf(stderr, "EVP_DigestInit_ex failed\n");
        ERR_print_errors_fp(stderr);
        EVP_MD_CTX_free(mdctx);
        return;
    }

    ret = EVP_DigestUpdate(mdctx, (unsigned char*)init_key, key_length * sizeof(unsigned long));
    if (!ret) {
        fprintf(stderr, "EVP_DigestUpdate failed\n");
        ERR_print_errors_fp(stderr);
        EVP_MD_CTX_free(mdctx);
        return;
    }

    ret = EVP_DigestFinal_ex(mdctx, key, NULL);
    if (!ret) {
        fprintf(stderr, "EVP_DigestFinal_ex failed\n");
        ERR_print_errors_fp(stderr);
        EVP_MD_CTX_free(mdctx);
        return;
    }
    EVP_MD_CTX_free(mdctx);

    state->ctx = EVP_CIPHER_CTX_new();
    if (!state->ctx) {
        fprintf(stderr, "Failed to create EVP_CIPHER_CTX\n");
        ERR_print_errors_fp(stderr);
        return;
    }

    ret = EVP_EncryptInit_ex(state->ctx, EVP_aes_256_ctr(), NULL, key, state->ivec);
    if (!ret) {
        fprintf(stderr, "EVP_EncryptInit_ex failed\n");
        ERR_print_errors_fp(stderr);
        EVP_CIPHER_CTX_free(state->ctx);
        return;
    }

    // Log the initial values of ivec and key
    log_data_to_file("ivec_log.txt", state->ivec, AES_BLOCK_SIZE);
    log_data_to_file("key_log.txt", key, sizeof(key));
}

void aes_ctr_prng_genrand_uint128_to_buf(aes_ctr_state_t* state, unsigned char* bufpos) {
    unsigned char temp_buffer[16]; // Intermediate buffer for 128 bits
    int outlen;

    // Generate pseudorandom numbers in the intermediate buffer
    EVP_EncryptUpdate(state->ctx, temp_buffer, &outlen, temp_buffer, sizeof(temp_buffer));

    // Directly copy the generated random data to the destination buffer
    memcpy(bufpos, temp_buffer, 16);

    // The following logging is commented out for potential future use
    // To activate logging, remove the comments from the next lines

    // Log the current values of ecount
    // log_data_to_file("ecount_log.txt", state->ecount, AES_BLOCK_SIZE);

    // Log the generated pseudorandom data
    // log_data_to_file("prng_output_log.txt", temp_buffer, sizeof(temp_buffer));
}

What i would be interested in.

In this function, you could change the for loop, which writes 4x 32-Bit values to 1, in order to write 1x32-Bit only. It will slower down the speed, but we can check wheter the buffer causes issues or not.

int nwipe_aes_ctr_prng_read(NWIPE_PRNG_READ_SIGNATURE) {
    u8* restrict bufpos = buffer;
    size_t words = count / SIZE_OF_AES_CTR_PRNG;

    /* Loop to fill the buffer with 128-bit blocks */
    for (size_t ii = 0; ii < words; ++ii) {
        unsigned char temp_buffer[16]; // Temporary buffer for 128-bit random data
        aes_ctr_prng_genrand_uint128_to_buf((aes_ctr_state_t*)*state, temp_buffer);

        // Now, instead of incrementing bufpos by SIZE_OF_AES_CTR_PRNG, we use u32_to_buffer to write each 32-bit block
        for (int i = 0; i < 4; ++i) {
            // Extract a 32-bit value from temp_buffer
            u32 val;
            memcpy(&val, temp_buffer + (i * 4), 4);

            // Use u32_to_buffer to write this 32-bit value into the main buffer
            u32_to_buffer(bufpos, val, 4);
            bufpos += 4; // Move to the next position in buffer for the next 32-bit block
        }
    }

FYI: https://github.com/openssl/openssl/issues/23957

Knogle commented 8 months ago

Best practice would be, adding this here in the aes_ctr_prng.c and call it at the end in nwipe_aes_ctr_read, after the random numbers have bene generated.

But unfortunately causes a segfault. But it's best practice to release the encryption context after the streaming is done. Currently we are not doing it like that.

void aes_ctr_prng_cleanup(aes_ctr_state_t* state) {
    if (state != NULL) {
        // Release the encryption context
        if (state->ctx != NULL) {
            EVP_CIPHER_CTX_free(state->ctx);
            state->ctx = NULL; // It's good practice to set the pointer to NULL after freeing
        }

        // Further cleanup could go here if `aes_ctr_state_t`
        // contains other resources that need to be released.

        // Since state here is a pointer to a structure that may have been allocated
        // outside of this function, we do not set state itself to NULL.
        // It is the caller's responsibility to manage the lifetime of the state object.
    }
}

And in prng.c

int nwipe_aes_ctr_prng_read(NWIPE_PRNG_READ_SIGNATURE) {
[...]
    aes_ctr_prng_cleanup((aes_ctr_state_t*)*state);
    return 0;  // Success
}

Would be best practice, but leads to a Segmentation fault, don't know why. EDIT: According to valgrind, the free function is trying to access not-mapped memory. I think we are having some issue in our memory allocation.


==59621== Invalid read of size 4
==59621==    at 0x4B5C34B: EVP_EncryptUpdate (in /usr/lib64/libcrypto.so.3.1.1)
==59621==    by 0x4147F2: aes_ctr_prng_genrand_uint128_to_buf (aes_ctr_prng.c:68)
==59621==    by 0x418662: nwipe_aes_ctr_prng_read (prng.c:385)
==59621==    by 0x411734: nwipe_random_pass (pass.c:322)
==59621==    by 0x415EAC: nwipe_runmethod (method.c:934)
==59621==    by 0x416FD9: nwipe_random (method.c:742)
==59621==    by 0x4F47896: start_thread (in /usr/lib64/libc.so.6)
==59621==    by 0x4FCE673: clone (in /usr/lib64/libc.so.6)
==59621==  Address 0x10 is not stack'd, malloc'd or (recently) free'd
==59621== 
==59621== 
==59621== Process terminating with default action of signal 11 (SIGSEGV)
==59621==  Access not within mapped region at address 0x10
==59621==    at 0x4B5C34B: EVP_EncryptUpdate (in /usr/lib64/libcrypto.so.3.1.1)
==59621==    by 0x4147F2: aes_ctr_prng_genrand_uint128_to_buf (aes_ctr_prng.c:68)
==59621==    by 0x418662: nwipe_aes_ctr_prng_read (prng.c:385)
==59621==    by 0x411734: nwipe_random_pass (pass.c:322)
==59621==    by 0x415EAC: nwipe_runmethod (method.c:934)
==59621==    by 0x416FD9: nwipe_random (method.c:742)
==59621==    by 0x4F47896: start_thread (in /usr/lib64/libc.so.6)
==59621==    by 0x4FCE673: clone (in /usr/lib64/libc.so.6)
==59621==  If you believe this happened as a result of a stack
==59621==  overflow in your program's main thread (unlikely but
==59621==  possible), you can try to increase the size of the
==59621==  main thread stack using the --main-stacksize= flag.
==59621==  The main thread stack size used in this run was 8388608.

What's HIGHLY interesting here. The memory it tries to access, is immediatly behind the allocated memory. Don't know, how we can improve the allocation. I'm sure, when we fix this memory allocation issue, it will fix the other issues as well.

==59621== Address 0x545dc40 is 0 bytes after a block of size 4,096 alloc'd

Knogle commented 8 months ago

Please give it a try again the latest commit in the aes-ctr-debug branch, i've done a major rewrite, aes_ctr_prng_cleanup works now without segfault, also there is a massive performance increase.

If this one also doesn't work, maybe you have some idea. My next idea would be to use dynamic memory allocation during runtime for all parameters used in the encryption function.

Screenshot from 2024-03-26 03-08-35

PartialVolume commented 8 months ago

The 16 drive test has started using the code with your new cleanup function, will update you shortly.

PartialVolume commented 8 months ago

Unfortunately failed again. I'm also not seeing the performance gain. I've double checked the code I'm compiling is the new code with the cleanup function, so I'm pretty sure 2 or 3 drives will fail verification once the wipe completes.

Screenshot_20240326_132343

and three drives fail and once again not always the same drives.

Screenshot_20240326_182807

Knogle commented 8 months ago

Oh okay. Running with valgrind would be really interesting. But you should write into a logfile because i expect a lot of output. valgrind --log-file='/tmp/valgrind.log' nwipe

Next steps i can try after this:

PartialVolume commented 8 months ago

Running valgrind to completion is not practical as it would take over 500hrs, however i did start a 16 drive wipe with valgrind and aborted after a few minutes. The log may have something useful.

Bearing in mind I'm wiping 16 drives which means there are 16 wipe threads in operation, one GUI thread and a temperature thread, valgrind reported a single thread with a issue. Thread 4 ..

==1906966== Thread 4:
==1906966== Invalid read of size 1
==1906966==    at 0x11BBF3: nwipe_random_pass (pass.c:328)
==1906966==    by 0x12054F: nwipe_runmethod (method.c:934)
==1906966==    by 0x12174C: nwipe_random (method.c:742)
==1906966==    by 0x5095133: start_thread (pthread_create.c:442)
==1906966==    by 0x5114A3F: clone (clone.S:100)
==1906966==  Address 0x71ce4c0 is 0 bytes after a block of size 4,096 alloc'd
==1906966==    at 0x48455EF: calloc (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux
.so)
==1906966==    by 0x11BA2E: nwipe_random_pass (pass.c:268)
==1906966==    by 0x12054F: nwipe_runmethod (method.c:934)
==1906966==    by 0x12174C: nwipe_random (method.c:742)
==1906966==    by 0x5095133: start_thread (pthread_create.c:442)
==1906966==    by 0x5114A3F: clone (clone.S:100)

The calloc mentioned is the allocation of 4096 bytes where we read the prngs data into. The error indicates a overrun of 1 byte passed the end of the 4096 block of memory. My first thought is that the prngs length is incorrect but for only that one byte. Does this make sense? So maybe recording the prng length field during initialisation, i.e that would be 16 entries in the nwipe log the value should of course all be the same.

PartialVolume commented 8 months ago

Implicit declaration: aes_ctr_prng_init is not declared in aes_ctr_prng.h

Screenshot_20240326_195422

PartialVolume commented 8 months ago

Ignore that last comment, I was looking at your master not the aes-ctr-debug branch. However aes_ctr_prng_cleanup has an implicit declaration.

PartialVolume commented 8 months ago

Slightly of topic and as a reminder for me, I need to update the PDF code to report the xoro & Fibonacci prngs correctly rather than saying the prng is unknown.

Screenshot_20240326_201937

Knogle commented 8 months ago

Sounds great ! :) Regarding the memory issue, it's an issue with the existing nwipe code. I think we have memory leaks there, corrupting the AES function. I've ran Mersenne, causing the same issue you observed.

What do you think, i could start troubleshooting the existing memory leak issue in pass.c and later on we can keep going with AES.

==6062== 
==6062== Thread 4:
==6062== Invalid read of size 1
==6062==    at 0x4117BC: nwipe_random_pass (pass.c:328)
==6062==    by 0x415EFC: nwipe_runmethod (method.c:934)
==6062==    by 0x417029: nwipe_random (method.c:742)
==6062==    by 0x4E98946: start_thread (pthread_create.c:444)
==6062==    by 0x4F1E873: clone (clone.S:100)
==6062==  Address 0x539da20 is 0 bytes after a block of size 4,096 alloc'd
==6062==    at 0x4849E60: calloc (vg_replace_malloc.c:1595)
==6062==    by 0x4115FE: nwipe_random_pass (pass.c:268)
==6062==    by 0x415EFC: nwipe_runmethod (method.c:934)
==6062==    by 0x417029: nwipe_random (method.c:742)
==6062==    by 0x4E98946: start_thread (pthread_create.c:444)
==6062==    by 0x4F1E873: clone (clone.S:100)
Knogle commented 8 months ago

I've found the issue in pass.c

/* For the first block only, check the prng actually wrote something to the buffer */
if( z == c->device_size )
{
    idx = c->device_stat.st_blksize;
    while( idx > 0 )
    {
        if( b[idx] != 0 )
        {
            nwipe_log( NWIPE_LOG_NOTICE, "prng stream is active" );
            break;

idx = c->device_stat.st_blksize - 1;
while( idx > 0 )
{
    if( b[idx] != 0 )
    {
        nwipe_log( NWIPE_LOG_NOTICE, "prng stream is active" );
        break;
    }

I will set up a PR for that.

PartialVolume commented 8 months ago

Slightly of topic and as a reminder for me, I need to update the PDF code to report the xoro & Fibonacci prngs correctly rather than saying the prng is unknown.

Screenshot_20240326_201937

Merged https://github.com/martijnvanbrummelen/nwipe/commit/a4ce92be6fc7b10e22b14c9823b6f23c557ccffb

PartialVolume commented 8 months ago

I've found the issue in pass.c

Well spotted, that would certainly be reading one byte passed the end of the buffer. I don't see it fixing our verification issue though.

Knogle commented 8 months ago

I've found the issue in pass.c

Well spotted, that would certainly be reading one byte passed the end of the buffer. I don't see it fixing our verification issue though.

Can you give it a try again using the latest aes-ctr-debug branch? It includes the latest PR, 'maybe' it works. Let's see.

Maybe we have another issue here. I will further analyze the code.

==7915== Thread 4:
==7915== Conditional jump or move depends on uninitialised value(s)
==7915==    at 0x4117C1: nwipe_random_pass (pass.c:330)
==7915==    by 0x415EEC: nwipe_runmethod (method.c:934)
==7915==    by 0x417019: nwipe_random (method.c:742)
==7915==    by 0x4E98946: start_thread (pthread_create.c:444)
==7915==    by 0x4F1E873: clone (clone.S:100)

as well as

==7915== LEAK SUMMARY:
==7915==    definitely lost: 31 bytes in 3 blocks
==7915==    indirectly lost: 6,960 bytes in 2 blocks
==7915==      possibly lost: 913 bytes in 12 blocks
==7915==    still reachable: 155,034 bytes in 466 blocks
==7915==         suppressed: 0 bytes in 0 blocks
==7915== Rerun with --leak-check=full to see details of leaked memory
PartialVolume commented 8 months ago

I just tried it wiping a single loop drive and still get the same valgrind error.

==45180== Thread 4:
==45180== Invalid read of size 1
==45180==    at 0x11A6AB: nwipe_random_pass (pass.c:328)
==45180==    by 0x11F0F8: nwipe_runmethod (method.c:934)
==45180==    by 0x120550: nwipe_random (method.c:742)
==45180==    by 0x49E5AC2: start_thread (pthread_create.c:442)
==45180==    by 0x4A76A03: clone (clone.S:100)
==45180==  Address 0x4f6bf80 is 0 bytes after a block of size 4,096 alloc'd
==45180==    at 0x484DA83: calloc (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
==45180==    by 0x11A4F2: nwipe_random_pass (pass.c:268)
==45180==    by 0x11F0F8: nwipe_runmethod (method.c:934)
==45180==    by 0x120550: nwipe_random (method.c:742)
==45180==    by 0x49E5AC2: start_thread (pthread_create.c:442)
==45180==    by 0x4A76A03: clone (clone.S:100)
PartialVolume commented 8 months ago

@Knogle I'm going to have to call it a night, early start tomorrow. Good luck :-)

Knogle commented 8 months ago

@Knogle I'm going to have to call it a night, early start tomorrow. Good luck :-)

Thanks! Can you maybe try our current master branch without AES includig the new PR and check with Valgrind what's going on?

PartialVolume commented 8 months ago

That valgrind error has gone. I've run it a couple of times now and it's not reporting that error is 0 bytes after a block of size 4,096 alloc'd. Seems to be ok now.

Knogle commented 8 months ago

There are also issues that can be connected with the verification pass.

==10289== Syscall param write(buf) points to uninitialised byte(s)
==10289==    at 0x4F0D1AD: __libc_write (write.c:26)
==10289==    by 0x4F0D1AD: write (write.c:24)
==10289==    by 0x4116A0: nwipe_random_pass (pass.c:349)
==10289==    by 0x415EEC: nwipe_runmethod (method.c:934)
==10289==    by 0x417019: nwipe_random (method.c:742)
==10289==    by 0x4E98946: start_thread (pthread_create.c:444)
==10289==    by 0x4F1E873: clone (clone.S:100)
==10289==  Address 0x539db90 is 0 bytes inside a block of size 4,096 alloc'd
==10289==    at 0x4849E60: calloc (vg_replace_malloc.c:1595)
==10289==    by 0x4115FE: nwipe_random_pass (pass.c:268)
==10289==    by 0x415EEC: nwipe_runmethod (method.c:934)
==10289==    by 0x417019: nwipe_random (method.c:742)
==10289==    by 0x4E98946: start_thread (pthread_create.c:444)
==10289==    by 0x4F1E873: clone (clone.S:100)
==10289== Conditional jump or move depends on uninitialised value(s)
==10289==    at 0x484E90E: bcmp (vg_replace_strmem.c:1229)
==10289==    by 0x41138B: nwipe_random_verify (pass.c:198)
==10289==    by 0x4160A6: nwipe_runmethod (method.c:961)
==10289==    by 0x417019: nwipe_random (method.c:742)
==10289==    by 0x4E98946: start_thread (pthread_create.c:444)
==10289==    by 0x4F1E873: clone (clone.S:100)
Knogle commented 8 months ago

Maybe this one helps you.

https://gist.github.com/Knogle/a99e4bc7237d2bced8bfe457abdc36fe

./loopmount automount will create 24 loop devices with a size between 10M and 10G. Can you maybe run a test on those loop devices using the latest aes-ctr-debug branch?

EDIT:

I have now added logging through the nwipe_log function to the AES PRNG.

Knogle commented 8 months ago

@PartialVolume

Regarding the init state, the aes_ctr_prng_cleanup((aes_ctr_state_t*)*state); function is our issue because it is causing the state to be reset. I think we have to find another place for this function. If you remove it in prng.c, you won't have any aes_ctr_prng_genrand_uint128_to_buf: State not initialized or NULL errors anymore. A proper place for this function would be after a pass is complete. But i don't know where we can call it in order to achieve this.

PartialVolume commented 8 months ago

@PartialVolume

Regarding the init state, the aes_ctr_prng_cleanup((aes_ctr_state_t*)*state); function is our issue because it is causing the state to be reset. I think we have to find another place for this function. If you remove it in prng.c, you won't have any aes_ctr_prng_genrand_uint128_to_buf: State not initialized or NULL errors anymore. A proper place for this function would be after a pass is complete. But i don't know where we can call it in order to achieve this.

Ok, I'll give that a try. Is aes_ctr_prng_cleanup((aes_ctr_state_t*)*state); supposed to be called after every block of data is generated or just at the end when we've finished and move onto initialisation for the verification pass?

Knogle commented 8 months ago

@PartialVolume Regarding the init state, the aes_ctr_prng_cleanup((aes_ctr_state_t*)*state); function is our issue because it is causing the state to be reset. I think we have to find another place for this function. If you remove it in prng.c, you won't have any aes_ctr_prng_genrand_uint128_to_buf: State not initialized or NULL errors anymore. A proper place for this function would be after a pass is complete. But i don't know where we can call it in order to achieve this.

Ok, I'll give that a try. Is aes_ctr_prng_cleanup((aes_ctr_state_t*)*state); supposed to be called after every block of data is generated or just at the end when we've finished and move onto initialisation for the verification pass?

Exactly! It's meant to be used after the pass is complete, prior to the verification pass. If we ran out of ideas i will consult Devin AI and ask him what we can do :)

EDIT: I'm using a workaround for this issue and i'm on a good way to solve this! But maybe you still have some idea, i am curious.

@PartialVolume

Does the verification pass, call the PRNG in a different way?

I've added some nwipe_log strings, and they are only being called once. So it's no surprise, the verification pass being different.

Where does the verify pass handle the PRNG?

[2024/03/29 07:24:27]  notice: /dev/loop1, sect/blk/dev 512/4096/16777216
[2024/03/29 07:24:27]  notice: Invoking method 'PRNG Stream' on /dev/loop1
[2024/03/29 07:24:27]  notice: Starting round 1 of 1 on /dev/loop1
[2024/03/29 07:24:27]  notice: Starting pass 1/1, round 1/1, on /dev/loop1
[2024/03/29 07:24:27]  notice: Initialising AES CTR PRNG
[2024/03/29 07:24:27]  notice: Processing seed for AES CTR PRNG initialization.
[2024/03/29 07:24:27]  notice: Seed successfully logged to seed_post_log.txt
[2024/03/29 07:24:27]  notice: AES CTR PRNG successfully initialized.
[2024/03/29 07:24:27]  notice: prng stream is active
[2024/03/29 07:24:27]  notice: 16777216 bytes written to /dev/loop1
[2024/03/29 07:24:27]  notice: Verifying pass 1 of 1, round 1 of 1, on /dev/loop1
[2024/03/29 07:24:27]  notice: Initialising AES CTR PRNG
[2024/03/29 07:24:27]  notice: 16777216 bytes read from /dev/loop1
[2024/03/29 07:24:27]  notice: Verified pass 1 of 1, round 1 of 1, on '/dev/loop1'.
[2024/03/29 07:24:27]  notice: Finished pass 1/1, round 1/1, on /dev/loop1
[2024/03/29 07:24:27]  notice: Finished final round 1 of 1 on /dev/loop1
[2024/03/29 07:24:27]   error: 4096 verification errors on '/dev/loop1'.
[2024/03/29 07:24:30]   fatal: Nwipe exited with errors on device = /dev/loop1, see log for specific error

EDIT2:

@PartialVolume

That's what i am currently working on. It has a great footprint regarding valgrind, because the memory management is very easy and clean using smart pointers, so i don't have to worry about this stuff.

https://github.com/Knogle/nwipe/tree/aes-ctr-cpp

There are still issues during verification, because i have to understand how the verifiy pass accesses the PRNG. Still no idea about it.

PartialVolume commented 8 months ago

If we ran out of ideas i will consult Devin AI and ask him what we can do :)

God help us, lol. If it's anything like chatGPT it will be like talking to a person with impeccable spelling, grammar and sentence construction (unlike me) that knows all the right buzz words but has a lack of understanding at a deeper level or is able to see the bigger picture. At least that's what I've found. It looks incredibly impressive when you don't understand the subject, but when you do know the subject you quickly realise it's talking nonsense, but incredibly articulate nonsense.

I sort of imagine Devin to be the same, syntactically it never makes a mistake, but fails to grasp the overall purpose or meaning behind the code so suggests things that are not appropriate for the codes true purpose.

I don't trust all the smart gizmo's on my car either and for very good reason. One of the 'features' nearly caused a accident because the car was unable to interpret a mud spattered 40mph sigh as a mud splattered 40mph sign and instead incorrectly decided it was a 20mph sign and rapidly slowed down, not great when the person behind you is driving too close and makes it look like you are brake checking them, when it's the damn car trying to get you into trouble :-) If Devin is as good as the website suggests I'm out of a job. ;-)

PartialVolume commented 8 months ago

@Knogle I'm taking a break over this bank holiday weekend in the UK so will get back to the code next week.

However, the most appropriate place for a clean up function would be at the end of the function in pass.c that writes the random pass. It would be enclosed in a if statement that checks for the AES prng being used. I can provide more detail on a suitable location next week.

Knogle commented 8 months ago

@Knogle I'm taking a break over this bank holiday weekend in the UK so will get back to the code next week.

However, the most appropriate place for a clean up function would be at the end of the function in pass.c that writes the random pass. It would be enclosed in a if statement that checks for the AES prng being used. I can provide more detail on a suitable location next week.

Alright, no issue :) Take your time! I think there is no pressure here.

Knogle commented 8 months ago

I've conducted tests on 25 loop devices and also on an X58 platform equipped with an Intel Xeon X5650, the first CPU to offer AES-NI support with the Westmere-EP architecture. In my view, the results were impressive! I used the latest aes-ctr branch. Perhaps you might consider giving it a try as well! Up to now, I haven't encountered any issues with Valgrind regarding uninitialized memory for the AES algorithm. Only my nvme0n1 temperature went critical during these tests using loop devices heh.

Is it possible to reboot your testing machine, or can you try with loop devices as well?

Also my latest script in order to setup loop devices. Maybe it's useful for you as well!

https://gist.github.com/Knogle/fc1ee304ed6f1d76876157acbd659ed6

Screenshot from 2024-03-31 11-31-31

./mount-loop.sh polymount rand 24 1G 10G

Screenshot from 2024-03-31 11-18-58 Screenshot from 2024-03-31 10-56-08

And on real hardware.

snapshot

nwipe.log

Still maintaining excellent PRNG quality.

chairman@fedora:~/Projects/PRNG/sts$ cat result.txt 
A total of 188 tests (some of the 15 tests actually consist of multiple sub-tests)
were conducted to evaluate the randomness of 32 bitstreams of 1048576 bits from:

    /dev/loop2

- - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -

The numerous empirical results of these tests were then interpreted with
an examination of the proportion of sequences that pass a statistical test
(proportion analysis) and the distribution of p-values to check for uniformity
(uniformity analysis). The results were the following:

    188/188 tests passed successfully both the analyses.
    0/188 tests did not pass successfully both the analyses.

- - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -

Here are the results of the single tests:

 - The "Frequency" test passed both the analyses.

 - The "Block Frequency" test passed both the analyses.

 - The "Cumulative Sums" (forward) test passed both the analyses.
   The "Cumulative Sums" (backward) test passed both the analyses.

 - The "Runs" test passed both the analyses.

 - The "Longest Run of Ones" test passed both the analyses.

 - The "Binary Matrix Rank" test passed both the analyses.

 - The "Discrete Fourier Transform" test passed both the analyses.

 - 148/148 of the "Non-overlapping Template Matching" tests passed both the analyses.

 - The "Overlapping Template Matching" test passed both the analyses.

 - The "Maurer's Universal Statistical" test passed both the analyses.

 - The "Approximate Entropy" test passed both the analyses.

 - 8/8 of the "Random Excursions" tests passed both the analyses.

 - 18/18 of the "Random Excursions Variant" tests passed both the analyses.

 - The "Serial" (first) test passed both the analyses.
   The "Serial" (second) test passed both the analyses.

 - The "Linear Complexity" test passed both the analyses.

- - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -

The missing tests (if any) were whether disabled manually by the user or disabled
at run time due to input size requirements not satisfied by this run.
PartialVolume commented 8 months ago

You've removed all the error checking on the functions?

Knogle commented 8 months ago

Hey @PartialVolume , enjoy your holiday, no pressure to test now :)

I've got 3 implementations to test now.

  1. The default C only implementation as discussed previously. At least in my case performed well, on loopback devices as well as on real hardware, on Intel X5650. Maybe you can retest if possible, maybe with reboot or something.
  2. A C++ implementation, maintaining almost the same principles. aes-ctr-cpp branch.
  3. A major rewrite in C++, using smart pointers in order to ensure maximum memory safety. aes-ctr-cpp-smartptr branch.
Knogle commented 8 months ago

You've removed all the error checking on the functions?

Oh sorry, you are right! Added error checking again.

EDIT:

That's my current test build. I will test all 3 variants using 24 loop devices, and later on using real hardware, 5x HDDs, 1x SATA SSD, 1x USB --> SATA SSD, 1x USB SSD, and 1x IDE ATA 4,3 Quantum Bigfoot.

I'm curious about your results :)

20240331_144633 20240331_144637

Knogle commented 7 months ago

@PartialVolume

Hey how are you doing :) Can you maybe perform tests for the aes-ctr-cpp-smartptr branch on your server machine?

I have at least locally done extensive tests, but i am curious for the big real world scenario.

https://github.com/Knogle/nwipe/tree/aes-ctr-cpp-smartptr

I will create a seperate PR.