Hammer Test causing warnings due to waiting time (no errors) - normal behavior?

[Paula86]

Greetings!

I am trying to verify that my new g.skill ddr4 memory is working fine at the specified timings and clock. The system underwent 4 passes of memtest without errors, but I noticed that the hammer test took much longer than I anticipated. (I have some experience using memtest on other computers). This has caused the 4 complete 13-test passes of memtest to require almost 10 hours of testing.

The specs are:
i7-6800k on stock settings
Msi X99 Board
Gskill 3000mhz 64GB Ram running at xmp 2.0 settings.

Attached is a small excerpt from the memtest86.log. My question is whether the huge number of warnings and 'waiting time' is expected for 12 threads/64gb ram or if this is cause for concern?

Thanks in advance for your input!

Best Regards,
Paula

2016-12-22 02:06:27 - Locking all memory ranges first...
2016-12-22 02:06:27 - Memory range locked: 0x0 - 0x3F000 (66925900KB of available memory left)
2016-12-22 02:06:27 - Memory range locked: 0x40000 - 0xA0000 (66925516KB of available memory left)
2016-12-22 02:06:28 - Memory range locked: 0x100000 - 0x10000000 (66664396KB of available memory left)
2016-12-22 02:06:28 - Memory range locked: 0x1000B000 - 0x264C9000 (66299092KB of available memory left)
2016-12-22 02:06:28 - Memory range locked: 0x26549000 - 0x341A8000 (66073432KB of available memory left)
2016-12-22 02:06:28 - Memory range locked: 0x344DA000 - 0x349C3000 (66068404KB of available memory left)
2016-12-22 02:06:28 - Memory range locked: 0x38688000 - 0x388BE000 (66066140KB of available memory left)
2016-12-22 02:06:28 - Memory range locked: 0x39EF6000 - 0x3A4AD000 (66060288KB of available memory left)
2016-12-22 02:06:28 - Reducing memory range: 0x100000000 - 0x10C0000000 ==> 0x100000000 - 0x10BFF00000
2016-12-22 02:06:28 - Memory range locked: 0x100000000 - 0x10BFF00000 (1024KB of available memory left)
2016-12-22 02:06:28 - All memory ranges successfully locked
2016-12-22 02:07:13 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0x100000000 - 0x120000000]
2016-12-22 02:07:48 - WARNING - waited for 10s for CPU #8 to finish (BSP test time = 24844ms)
2016-12-22 02:07:48 - WARNING - waited for 10s for CPU #9 to finish (BSP test time = 24844ms)
2016-12-22 02:09:30 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0x140000000 - 0x160000000]
2016-12-22 02:10:08 - WARNING - waited for 10s for CPU #9 to finish (BSP test time = 28363ms)
2016-12-22 02:11:46 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0x180000000 - 0x1A0000000]
2016-12-22 02:12:22 - WARNING - waited for 10s for CPU #8 to finish (BSP test time = 26148ms)
2016-12-22 02:12:22 - WARNING - waited for 10s for CPU #9 to finish (BSP test time = 26148ms)
2016-12-22 02:14:02 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0x1C0000000 - 0x1E0000000]
2016-12-22 02:14:38 - WARNING - waited for 10s for CPU #9 to finish (BSP test time = 25814ms)
2016-12-22 02:14:38 - WARNING - waited for 10s for CPU #10 to finish (BSP test time = 25814ms)
2016-12-22 02:14:38 - WARNING - waited for 10s for CPU #11 to finish (BSP test time = 25814ms)
2016-12-22 02:16:14 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0x200000000 - 0x220000000]
2016-12-22 02:16:52 - WARNING - waited for 10s for CPU #8 to finish (BSP test time = 27595ms)
2016-12-22 02:16:52 - WARNING - waited for 10s for CPU #9 to finish (BSP test time = 27595ms)
2016-12-22 02:18:31 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0x240000000 - 0x260000000]
2016-12-22 02:19:05 - WARNING - waited for 10s for CPU #9 to finish (BSP test time = 23934ms)
2016-12-22 02:19:05 - WARNING - waited for 10s for CPU #10 to finish (BSP test time = 23934ms)
2016-12-22 02:19:05 - WARNING - waited for 10s for CPU #11 to finish (BSP test time = 23934ms)
2016-12-22 02:20:41 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0x280000000 - 0x2A0000000]
2016-12-22 02:21:17 - WARNING - waited for 10s for CPU #8 to finish (BSP test time = 26087ms)
2016-12-22 02:21:17 - WARNING - waited for 10s for CPU #9 to finish (BSP test time = 26087ms)
2016-12-22 02:22:59 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0x2C0000000 - 0x2E0000000]
2016-12-22 02:23:35 - WARNING - waited for 10s for CPU #10 to finish (BSP test time = 26008ms)
2016-12-22 02:23:35 - WARNING - waited for 10s for CPU #11 to finish (BSP test time = 26008ms)
2016-12-22 02:25:17 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0x300000000 - 0x320000000]
2016-12-22 02:25:53 - WARNING - waited for 10s for CPU #9 to finish (BSP test time = 25879ms)
2016-12-22 02:25:53 - WARNING - waited for 10s for CPU #10 to finish (BSP test time = 25879ms)
2016-12-22 02:25:53 - WARNING - waited for 10s for CPU #11 to finish (BSP test time = 25879ms)
2016-12-22 02:27:28 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0x340000000 - 0x360000000]
2016-12-22 02:29:44 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0x380000000 - 0x3A0000000]
2016-12-22 02:32:01 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0x3C0000000 - 0x3E0000000]
2016-12-22 02:32:37 - WARNING - waited for 10s for CPU #8 to finish (BSP test time = 25847ms)
2016-12-22 02:32:37 - WARNING - waited for 10s for CPU #9 to finish (BSP test time = 25847ms)
2016-12-22 02:34:11 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0x400000000 - 0x420000000]
2016-12-22 02:34:46 - WARNING - waited for 10s for CPU #8 to finish (BSP test time = 25424ms)
2016-12-22 02:34:46 - WARNING - waited for 10s for CPU #9 to finish (BSP test time = 25424ms)
2016-12-22 02:34:46 - WARNING - waited for 10s for CPU #10 to finish (BSP test time = 25424ms)
2016-12-22 02:34:46 - WARNING - waited for 10s for CPU #11 to finish (BSP test time = 25424ms)
2016-12-22 02:36:27 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0x440000000 - 0x460000000]
2016-12-22 02:37:04 - WARNING - waited for 10s for CPU #9 to finish (BSP test time = 27232ms)
2016-12-22 02:38:44 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0x480000000 - 0x4A0000000]
2016-12-22 02:39:20 - WARNING - waited for 10s for CPU #9 to finish (BSP test time = 25674ms)
2016-12-22 02:39:20 - WARNING - waited for 10s for CPU #10 to finish (BSP test time = 25674ms)
2016-12-22 02:39:20 - WARNING - waited for 10s for CPU #11 to finish (BSP test time = 25674ms)
2016-12-22 02:40:52 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0x4C0000000 - 0x4E0000000]
2016-12-22 02:43:00 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0x500000000 - 0x520000000]
2016-12-22 02:43:36 - WARNING - waited for 10s for CPU #4 to finish (BSP test time = 25963ms)
2016-12-22 02:43:36 - WARNING - waited for 10s for CPU #5 to finish (BSP test time = 25963ms)
2016-12-22 02:45:09 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0x540000000 - 0x560000000]
2016-12-22 02:45:48 - WARNING - waited for 10s for CPU #8 to finish (BSP test time = 27985ms)
2016-12-22 02:45:48 - WARNING - waited for 10s for CPU #9 to finish (BSP test time = 27985ms)
2016-12-22 02:47:27 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0x580000000 - 0x5A0000000]
2016-12-22 02:48:06 - WARNING - waited for 10s for CPU #6 to finish (BSP test time = 28486ms)
2016-12-22 02:48:06 - WARNING - waited for 10s for CPU #7 to finish (BSP test time = 28486ms)
2016-12-22 02:48:06 - WARNING - waited for 10s for CPU #10 to finish (BSP test time = 28486ms)
2016-12-22 02:48:06 - WARNING - waited for 10s for CPU #11 to finish (BSP test time = 28486ms)
2016-12-22 02:49:46 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0x5C0000000 - 0x5E0000000]
2016-12-22 02:50:27 - WARNING - waited for 10s for CPU #8 to finish (BSP test time = 30534ms)
2016-12-22 02:50:27 - WARNING - waited for 10s for CPU #9 to finish (BSP test time = 30534ms)
2016-12-22 02:52:04 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0x600000000 - 0x620000000]
2016-12-22 02:54:20 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0x640000000 - 0x660000000]
2016-12-22 02:54:57 - WARNING - waited for 10s for CPU #8 to finish (BSP test time = 26564ms)
2016-12-22 02:54:57 - WARNING - waited for 10s for CPU #9 to finish (BSP test time = 26564ms)
2016-12-22 02:56:37 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0x680000000 - 0x6A0000000]
[.... more and more of the same ....]
2016-12-22 04:01:43 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0xDC0000000 - 0xDE0000000]
2016-12-22 04:02:20 - WARNING - waited for 10s for CPU #8 to finish (BSP test time = 26350ms)
2016-12-22 04:02:20 - WARNING - waited for 10s for CPU #9 to finish (BSP test time = 26350ms)
2016-12-22 04:02:20 - WARNING - waited for 10s for CPU #10 to finish (BSP test time = 26350ms)
2016-12-22 04:02:20 - WARNING - waited for 10s for CPU #11 to finish (BSP test time = 26350ms)
2016-12-22 04:04:00 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0xE00000000 - 0xE20000000]
2016-12-22 04:04:34 - WARNING - waited for 10s for CPU #11 to finish (BSP test time = 24224ms)
2016-12-22 04:04:44 - WARNING - waited for 20s for CPU #11 to finish (BSP test time = 24224ms)
2016-12-22 04:06:17 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0xE40000000 - 0xE60000000]
2016-12-22 04:08:29 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0xE80000000 - 0xEA0000000]
2016-12-22 04:09:08 - WARNING - waited for 10s for CPU #9 to finish (BSP test time = 28723ms)
2016-12-22 04:10:40 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0xEC0000000 - 0xEE0000000]
2016-12-22 04:12:57 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0xF00000000 - 0xF20000000]
2016-12-22 04:15:09 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0xF40000000 - 0xF60000000]
2016-12-22 04:17:19 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0xF80000000 - 0xFA0000000]
2016-12-22 04:17:57 - WARNING - waited for 10s for CPU #8 to finish (BSP test time = 27556ms)
2016-12-22 04:17:57 - WARNING - waited for 10s for CPU #9 to finish (BSP test time = 27556ms)
2016-12-22 04:19:37 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0xFC0000000 - 0xFE0000000]
2016-12-22 04:20:12 - WARNING - waited for 10s for CPU #9 to finish (BSP test time = 25057ms)
2016-12-22 04:20:22 - WARNING - waited for 20s for CPU #9 to finish (BSP test time = 25057ms)
2016-12-22 04:21:54 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0x1000000000 - 0x1020000000]
2016-12-22 04:22:28 - WARNING - waited for 10s for CPU #8 to finish (BSP test time = 24436ms)
2016-12-22 04:22:28 - WARNING - waited for 10s for CPU #9 to finish (BSP test time = 24436ms)
2016-12-22 04:22:38 - WARNING - waited for 20s for CPU #8 to finish (BSP test time = 24436ms)
2016-12-22 04:22:38 - WARNING - waited for 20s for CPU #9 to finish (BSP test time = 24436ms)
2016-12-22 04:24:11 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0x1040000000 - 0x1060000000]
2016-12-22 04:24:49 - WARNING - waited for 10s for CPU #10 to finish (BSP test time = 28385ms)
2016-12-22 04:24:49 - WARNING - waited for 10s for CPU #11 to finish (BSP test time = 28385ms)
2016-12-22 04:26:28 - RunHammerTest - Running hammer test on 12 CPUs (512MB each) [0x1080000000 - 0x10A0000000]
2016-12-22 04:27:58 - Cleanup - Unlocking all memory ranges...
2016-12-22 04:27:58 - MtSupportRunAllTests - Test execution time: 8490.889 (Test 13 cumulative error count: 0)
2016-12-22 04:27:58 - Finished pass #2 (of 10) (Cumulative error count: 0)

[keith]

The system underwent 4 passes of memtest without errors, but I noticed that the hammer test took much longer than I anticipated. (I have some experience using memtest on other computers). This has caused the 4 complete 13-test passes of memtest to require almost 10 hours of testing.

The test duration doesn't look too unusual. Test 13, due to the nature of the test, takes longer than the other tests. You can see a brief description of the test here:
http://memtest86.com/technical.htm#algorithm

The warnings don't seem to indicate any cause for concern. When you have 12 threads hammering memory at the same time, the bus contention is bound to cause discrepancies in the thread execution time.