Crash during fxbench

[stevenjswanson]

From @stevenjswanson on June 13, 2017 23:2

I'm getting a consistent crash while running fxbench on the test machine.

commit f5ccaacfda12289ace1f53109ad3104bbc43e3ca

dmesg:

[ 938.940146] nova: Current epoch id: 0 [ 938.940205] nova: nova_save_inode_list_to_log: 18 inode nodes, pi head 0x333835000, tail 0x333835120 [ 938.940269] nova: nova_save_blocknode_mappings_to_log: 279 blocknodes, 2 log pages, pi head 0x333836000, tail 0x333837190 [ 938.949153] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 938.949155] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 938.949259] nova: Start NOVA snapshot cleaner thread. [ 938.949267] nova: Running snapshot cleaner thread [ 938.949294] nova: nova_init_inode_list_from_inode: 18 inode nodes [ 938.949296] nova: Recovered 0 snapshots, latest epoch ID 0 [ 938.949296] nova: NOVA: Normal shutdown [ 938.951513] nova: Current epoch id: 0 [ 938.968640] run fstests generic/311 at 2017-06-13 21:24:57 [ 939.127874] run fstests generic/312 at 2017-06-13 21:24:57 [ 939.286753] run fstests generic/313 at 2017-06-13 21:24:58 [ 943.482926] nova: Current epoch id: 0 [ 943.482978] nova: nova_save_inode_list_to_log: 18 inode nodes, pi head 0x333835000, tail 0x333835120 [ 943.483038] nova: nova_save_blocknode_mappings_to_log: 279 blocknodes, 2 log pages, pi head 0x333836000, tail 0x333837190 [ 943.491356] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 943.491359] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 943.491449] nova: Start NOVA snapshot cleaner thread. [ 943.491455] nova: Running snapshot cleaner thread [ 943.491483] nova: nova_init_inode_list_from_inode: 18 inode nodes [ 943.491486] nova: Recovered 0 snapshots, latest epoch ID 0 [ 943.491486] nova: NOVA: Normal shutdown [ 943.493635] nova: Current epoch id: 0 [ 943.510833] run fstests generic/314 at 2017-06-13 21:25:02 [ 943.706188] run fstests generic/315 at 2017-06-13 21:25:02 [ 943.887646] run fstests generic/316 at 2017-06-13 21:25:02 [ 944.069018] run fstests generic/317 at 2017-06-13 21:25:02 [ 944.246876] nova: Current epoch id: 0 [ 944.246960] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x2de65f000, tail 0x2de65f080 [ 944.246987] nova: nova_save_blocknode_mappings_to_log: 57 blocknodes, 1 log pages, pi head 0x2de660000, tail 0x2de660390 [ 944.312210] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 944.312212] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 944.312326] nova: Start NOVA snapshot cleaner thread. [ 944.312333] nova: Running snapshot cleaner thread [ 944.312348] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 944.312350] nova: Recovered 0 snapshots, latest epoch ID 0 [ 944.312350] nova: NOVA: Normal shutdown [ 944.315444] nova: Current epoch id: 0 [ 944.338880] nova: Current epoch id: 0 [ 944.338930] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0xe65e000, tail 0xe65e080 [ 944.338945] nova: nova_save_blocknode_mappings_to_log: 57 blocknodes, 1 log pages, pi head 0xe65f000, tail 0xe65f390 [ 944.344853] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 944.344855] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 944.344945] nova: Start NOVA snapshot cleaner thread. [ 944.344959] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 944.344960] nova: Recovered 0 snapshots, latest epoch ID 0 [ 944.344961] nova: NOVA: Normal shutdown [ 944.344980] nova: Running snapshot cleaner thread [ 944.348049] nova: Current epoch id: 0 [ 944.386798] nova: Current epoch id: 0 [ 944.386843] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x176656000, tail 0x176656080 [ 944.386858] nova: nova_save_blocknode_mappings_to_log: 57 blocknodes, 1 log pages, pi head 0x176657000, tail 0x176657380 [ 944.392985] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 944.392987] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 944.393121] nova: Start NOVA snapshot cleaner thread. [ 944.393128] nova: Running snapshot cleaner thread [ 944.393135] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 944.393137] nova: Recovered 0 snapshots, latest epoch ID 0 [ 944.393137] nova: NOVA: Normal shutdown [ 944.396217] nova: Current epoch id: 0 [ 944.418799] nova: Current epoch id: 0 [ 944.418857] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x1ee657000, tail 0x1ee657080 [ 944.418872] nova: nova_save_blocknode_mappings_to_log: 57 blocknodes, 1 log pages, pi head 0x1ee658000, tail 0x1ee658390 [ 944.459280] run fstests generic/318 at 2017-06-13 21:25:03 [ 944.680721] run fstests generic/319 at 2017-06-13 21:25:03 [ 944.877109] run fstests generic/320 at 2017-06-13 21:25:03 [ 945.077249] run fstests generic/321 at 2017-06-13 21:25:03 [ 945.245400] run fstests generic/322 at 2017-06-13 21:25:04 [ 945.406189] run fstests generic/323 at 2017-06-13 21:25:04 [ 1065.919146] nova: Current epoch id: 0 [ 1065.919204] nova: nova_save_inode_list_to_log: 17 inode nodes, pi head 0xb37c1000, tail 0xb37c1110 [ 1065.919262] nova: nova_save_blocknode_mappings_to_log: 266 blocknodes, 2 log pages, pi head 0xb37c3000, tail 0xb37c40c0 [ 1065.928506] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 1065.928508] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1065.928591] nova: Start NOVA snapshot cleaner thread. [ 1065.928599] nova: Running snapshot cleaner thread [ 1065.928625] nova: nova_init_inode_list_from_inode: 17 inode nodes [ 1065.928628] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1065.928628] nova: NOVA: Normal shutdown [ 1065.930833] nova: Current epoch id: 0 [ 1065.948750] run fstests generic/324 at 2017-06-13 21:27:04 [ 1066.136179] run fstests generic/325 at 2017-06-13 21:27:04 [ 1066.321253] run fstests generic/326 at 2017-06-13 21:27:05 [ 1066.511037] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1066.511039] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1066.511108] nova: Start NOVA snapshot cleaner thread. [ 1066.511114] nova: Running snapshot cleaner thread [ 1066.511122] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1066.511125] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1066.511125] nova: NOVA: Normal shutdown [ 1066.514297] nova: Current epoch id: 0 [ 1066.546957] nova: Current epoch id: 0 [ 1066.547003] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x176656000, tail 0x176656080 [ 1066.547019] nova: nova_save_blocknode_mappings_to_log: 57 blocknodes, 1 log pages, pi head 0x176657000, tail 0x176657380 [ 1066.552817] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1066.552818] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1066.552951] nova: Start NOVA snapshot cleaner thread. [ 1066.552960] nova: Running snapshot cleaner thread [ 1066.552964] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1066.552966] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1066.552967] nova: NOVA: Normal shutdown [ 1066.556085] nova: Current epoch id: 0 [ 1066.582945] nova: Current epoch id: 0 [ 1066.583019] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x356669000, tail 0x356669080 [ 1066.583040] nova: nova_save_blocknode_mappings_to_log: 55 blocknodes, 1 log pages, pi head 0x35666a000, tail 0x35666a370 [ 1066.605550] run fstests generic/327 at 2017-06-13 21:27:05 [ 1066.785492] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1066.785495] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1066.785617] nova: Start NOVA snapshot cleaner thread. [ 1066.785628] nova: Running snapshot cleaner thread [ 1066.785639] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1066.785642] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1066.785643] nova: NOVA: Normal shutdown [ 1066.789768] nova: Current epoch id: 0 [ 1066.814976] nova: Current epoch id: 0 [ 1066.815046] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x356656000, tail 0x356656080 [ 1066.815068] nova: nova_save_blocknode_mappings_to_log: 57 blocknodes, 1 log pages, pi head 0x356657000, tail 0x356657390 [ 1066.821008] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1066.821010] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1066.821110] nova: Start NOVA snapshot cleaner thread. [ 1066.821118] nova: Running snapshot cleaner thread [ 1066.821129] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1066.821132] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1066.821133] nova: NOVA: Normal shutdown [ 1066.824722] nova: Current epoch id: 0 [ 1066.850850] nova: Current epoch id: 0 [ 1066.850892] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0xe65e000, tail 0xe65e080 [ 1066.850907] nova: nova_save_blocknode_mappings_to_log: 55 blocknodes, 1 log pages, pi head 0xe65f000, tail 0xe65f370 [ 1066.873287] run fstests generic/328 at 2017-06-13 21:27:05 [ 1067.056916] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1067.056920] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1067.057021] nova: Start NOVA snapshot cleaner thread. [ 1067.057030] nova: Running snapshot cleaner thread [ 1067.057050] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1067.057053] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1067.057054] nova: NOVA: Normal shutdown [ 1067.060511] nova: Current epoch id: 0 [ 1067.087064] nova: Current epoch id: 0 [ 1067.087124] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x356656000, tail 0x356656080 [ 1067.087150] nova: nova_save_blocknode_mappings_to_log: 57 blocknodes, 1 log pages, pi head 0x356657000, tail 0x356657390 [ 1067.092794] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1067.092797] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1067.092945] nova: Start NOVA snapshot cleaner thread. [ 1067.092960] nova: Running snapshot cleaner thread [ 1067.092961] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1067.092963] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1067.092964] nova: NOVA: Normal shutdown [ 1067.096110] nova: Current epoch id: 0 [ 1067.126872] nova: Current epoch id: 0 [ 1067.126938] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x1ee657000, tail 0x1ee657080 [ 1067.126952] nova: nova_save_blocknode_mappings_to_log: 51 blocknodes, 1 log pages, pi head 0x1ee658000, tail 0x1ee658330 [ 1067.148881] run fstests generic/329 at 2017-06-13 21:27:05 [ 1067.397610] run fstests generic/330 at 2017-06-13 21:27:06 [ 1067.576008] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1067.576010] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1067.576136] nova: Start NOVA snapshot cleaner thread. [ 1067.576144] nova: Running snapshot cleaner thread [ 1067.576155] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1067.576157] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1067.576157] nova: NOVA: Normal shutdown [ 1067.579252] nova: Current epoch id: 0 [ 1067.614897] nova: Current epoch id: 0 [ 1067.614951] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x2de65f000, tail 0x2de65f080 [ 1067.614966] nova: nova_save_blocknode_mappings_to_log: 57 blocknodes, 1 log pages, pi head 0x2de660000, tail 0x2de660390 [ 1067.620483] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1067.620485] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1067.620646] nova: Start NOVA snapshot cleaner thread. [ 1067.620651] nova: Running snapshot cleaner thread [ 1067.620661] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1067.620663] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1067.620664] nova: NOVA: Normal shutdown [ 1067.624021] nova: Current epoch id: 0 [ 1067.642863] nova: Current epoch id: 0 [ 1067.642910] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0xfe656000, tail 0xfe656080 [ 1067.642925] nova: nova_save_blocknode_mappings_to_log: 54 blocknodes, 1 log pages, pi head 0xfe658000, tail 0xfe658360 [ 1067.665110] run fstests generic/331 at 2017-06-13 21:27:06 [ 1067.843563] run fstests generic/332 at 2017-06-13 21:27:06 [ 1068.039758] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1068.039761] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1068.039859] nova: Start NOVA snapshot cleaner thread. [ 1068.039867] nova: Running snapshot cleaner thread [ 1068.039872] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1068.039874] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1068.039874] nova: NOVA: Normal shutdown [ 1068.042975] nova: Current epoch id: 0 [ 1068.071052] nova: Current epoch id: 0 [ 1068.071125] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0xfe656000, tail 0xfe656080 [ 1068.071147] nova: nova_save_blocknode_mappings_to_log: 56 blocknodes, 1 log pages, pi head 0xfe658000, tail 0xfe658380 [ 1068.077578] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1068.077582] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1068.077667] nova: Start NOVA snapshot cleaner thread. [ 1068.077675] nova: Running snapshot cleaner thread [ 1068.077688] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1068.077692] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1068.077692] nova: NOVA: Normal shutdown [ 1068.081128] nova: Current epoch id: 0 [ 1068.102863] nova: Current epoch id: 0 [ 1068.102910] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x1ee657000, tail 0x1ee657080 [ 1068.102930] nova: nova_save_blocknode_mappings_to_log: 52 blocknodes, 1 log pages, pi head 0x1ee658000, tail 0x1ee658340 [ 1068.125787] run fstests generic/333 at 2017-06-13 21:27:06 [ 1068.319498] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1068.319500] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1068.319616] nova: Start NOVA snapshot cleaner thread. [ 1068.319624] nova: Running snapshot cleaner thread [ 1068.319629] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1068.319632] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1068.319632] nova: NOVA: Normal shutdown [ 1068.322663] nova: Current epoch id: 0 [ 1068.346894] nova: Current epoch id: 0 [ 1068.346952] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0xe65e000, tail 0xe65e080 [ 1068.346966] nova: nova_save_blocknode_mappings_to_log: 57 blocknodes, 1 log pages, pi head 0xe65f000, tail 0xe65f390 [ 1068.352817] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1068.352819] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1068.352903] nova: Start NOVA snapshot cleaner thread. [ 1068.352912] nova: Running snapshot cleaner thread [ 1068.352916] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1068.352918] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1068.352919] nova: NOVA: Normal shutdown [ 1068.356263] nova: Current epoch id: 0 [ 1068.378913] nova: Current epoch id: 0 [ 1068.378954] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x86656000, tail 0x86656080 [ 1068.378969] nova: nova_save_blocknode_mappings_to_log: 55 blocknodes, 1 log pages, pi head 0x86658000, tail 0x86658370 [ 1068.400231] run fstests generic/334 at 2017-06-13 21:27:07 [ 1068.592265] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1068.592267] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1068.592361] nova: Start NOVA snapshot cleaner thread. [ 1068.592369] nova: Running snapshot cleaner thread [ 1068.592378] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1068.592380] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1068.592380] nova: NOVA: Normal shutdown [ 1068.595511] nova: Current epoch id: 0 [ 1068.614923] nova: Current epoch id: 0 [ 1068.614948] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x2de65f000, tail 0x2de65f080 [ 1068.614964] nova: nova_save_blocknode_mappings_to_log: 57 blocknodes, 1 log pages, pi head 0x2de660000, tail 0x2de660390 [ 1068.620148] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1068.620172] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1068.620248] nova: Start NOVA snapshot cleaner thread. [ 1068.620256] nova: Running snapshot cleaner thread [ 1068.620261] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1068.620263] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1068.620263] nova: NOVA: Normal shutdown [ 1068.623323] nova: Current epoch id: 0 [ 1068.650869] nova: Current epoch id: 0 [ 1068.650921] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0xe65e000, tail 0xe65e080 [ 1068.650936] nova: nova_save_blocknode_mappings_to_log: 55 blocknodes, 1 log pages, pi head 0xe65f000, tail 0xe65f370 [ 1068.671959] run fstests generic/335 at 2017-06-13 21:27:07 [ 1068.869682] run fstests generic/336 at 2017-06-13 21:27:07 [ 1069.045560] run fstests generic/337 at 2017-06-13 21:27:07 [ 1069.240938] run fstests generic/338 at 2017-06-13 21:27:08 [ 1069.416588] run fstests generic/339 at 2017-06-13 21:27:08 [ 1069.599025] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1069.599027] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1069.599103] nova: Start NOVA snapshot cleaner thread. [ 1069.599111] nova: Running snapshot cleaner thread [ 1069.599117] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1069.599119] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1069.599119] nova: NOVA: Normal shutdown [ 1069.602230] nova: Current epoch id: 0 [ 1069.622894] nova: Current epoch id: 0 [ 1069.622945] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x176656000, tail 0x176656080 [ 1069.622961] nova: nova_save_blocknode_mappings_to_log: 57 blocknodes, 1 log pages, pi head 0x176657000, tail 0x176657380 [ 1069.629093] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1069.629095] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1069.629175] nova: Start NOVA snapshot cleaner thread. [ 1069.629184] nova: Running snapshot cleaner thread [ 1069.629199] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1069.629202] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1069.629202] nova: NOVA: Normal shutdown [ 1069.632320] nova: Current epoch id: 0 [ 1070.151657] nova: Current epoch id: 0 [ 1070.151782] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x86656000, tail 0x86656080 [ 1070.151809] nova: nova_save_blocknode_mappings_to_log: 50 blocknodes, 1 log pages, pi head 0x86658000, tail 0x86658320 [ 1070.222316] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1070.222319] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1070.222456] nova: Start NOVA snapshot cleaner thread. [ 1070.222465] nova: Running snapshot cleaner thread [ 1070.222474] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1070.222477] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1070.222478] nova: NOVA: Normal shutdown [ 1070.225938] nova: Current epoch id: 0 [ 1070.538885] nova: Current epoch id: 0 [ 1070.538935] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x176656000, tail 0x176656080 [ 1070.538950] nova: nova_save_blocknode_mappings_to_log: 57 blocknodes, 1 log pages, pi head 0x176657000, tail 0x176657380 [ 1070.547711] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1070.547713] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1070.547783] nova: Start NOVA snapshot cleaner thread. [ 1070.547789] nova: Running snapshot cleaner thread [ 1070.547803] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1070.547805] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1070.547806] nova: NOVA: Normal shutdown [ 1070.551066] nova: Current epoch id: 0 [ 1070.572797] run fstests generic/340 at 2017-06-13 21:27:09 [ 1070.774863] nova: Current epoch id: 0 [ 1070.774917] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x176656000, tail 0x176656080 [ 1070.774932] nova: nova_save_blocknode_mappings_to_log: 57 blocknodes, 1 log pages, pi head 0x176657000, tail 0x176657380 [ 1070.784350] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1070.784352] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1070.784477] nova: Start NOVA snapshot cleaner thread. [ 1070.784486] nova: Running snapshot cleaner thread [ 1070.784492] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1070.784494] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1070.784495] nova: NOVA: Normal shutdown [ 1070.787629] nova: Current epoch id: 0 [ 1070.818912] nova: Current epoch id: 0 [ 1070.818955] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x1ee657000, tail 0x1ee657080 [ 1070.818971] nova: nova_save_blocknode_mappings_to_log: 57 blocknodes, 1 log pages, pi head 0x1ee658000, tail 0x1ee658390 [ 1070.824718] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1070.824720] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1070.824846] nova: Start NOVA snapshot cleaner thread. [ 1070.824849] nova: Running snapshot cleaner thread [ 1070.824866] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1070.824869] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1070.824869] nova: NOVA: Normal shutdown [ 1070.828069] nova: Current epoch id: 0 [ 1072.966874] nova: Current epoch id: 0 [ 1072.966974] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0xfe656000, tail 0xfe656080 [ 1072.966990] nova: nova_save_blocknode_mappings_to_log: 56 blocknodes, 1 log pages, pi head 0xfe658000, tail 0xfe658380 [ 1072.978028] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1072.978030] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1072.978187] nova: Start NOVA snapshot cleaner thread. [ 1072.978196] nova: Running snapshot cleaner thread [ 1072.978219] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1072.978223] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1072.978223] nova: NOVA: Normal shutdown [ 1072.982117] nova: Current epoch id: 0 [ 1073.004191] run fstests generic/341 at 2017-06-13 21:27:11 [ 1073.193290] run fstests generic/342 at 2017-06-13 21:27:12 [ 1073.366135] run fstests generic/343 at 2017-06-13 21:27:12 [ 1073.548467] run fstests generic/344 at 2017-06-13 21:27:12 [ 1073.734861] nova: Current epoch id: 0 [ 1073.734911] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0xe65e000, tail 0xe65e080 [ 1073.734927] nova: nova_save_blocknode_mappings_to_log: 57 blocknodes, 1 log pages, pi head 0xe65f000, tail 0xe65f390 [ 1073.769472] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1073.769475] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1073.769600] nova: Start NOVA snapshot cleaner thread. [ 1073.769607] nova: Running snapshot cleaner thread [ 1073.769614] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1073.769616] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1073.769617] nova: NOVA: Normal shutdown [ 1073.772768] nova: Current epoch id: 0 [ 1073.806892] nova: Current epoch id: 0 [ 1073.806942] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x86656000, tail 0x86656080 [ 1073.806957] nova: nova_save_blocknode_mappings_to_log: 56 blocknodes, 1 log pages, pi head 0x86658000, tail 0x86658380 [ 1073.813063] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1073.813065] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1073.813164] nova: Start NOVA snapshot cleaner thread. [ 1073.813170] nova: Running snapshot cleaner thread [ 1073.813177] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1073.813179] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1073.813180] nova: NOVA: Normal shutdown [ 1073.816341] nova: Current epoch id: 0 [ 1079.166886] nova: Current epoch id: 0 [ 1079.166948] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x1ee657000, tail 0x1ee657080 [ 1079.166972] nova: nova_save_blocknode_mappings_to_log: 57 blocknodes, 1 log pages, pi head 0x1ee658000, tail 0x1ee658390 [ 1079.178443] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1079.178447] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1079.178532] nova: Start NOVA snapshot cleaner thread. [ 1079.178541] nova: Running snapshot cleaner thread [ 1079.178557] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1079.178560] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1079.178560] nova: NOVA: Normal shutdown [ 1079.182573] nova: Current epoch id: 0 [ 1079.205618] run fstests generic/345 at 2017-06-13 21:27:18 [ 1079.394860] nova: Current epoch id: 0 [ 1079.394918] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0xe65e000, tail 0xe65e080 [ 1079.394934] nova: nova_save_blocknode_mappings_to_log: 57 blocknodes, 1 log pages, pi head 0xe65f000, tail 0xe65f390 [ 1079.497841] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1079.497843] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1079.497946] nova: Start NOVA snapshot cleaner thread. [ 1079.497953] nova: Running snapshot cleaner thread [ 1079.497970] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1079.497972] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1079.497973] nova: NOVA: Normal shutdown [ 1079.501139] nova: Current epoch id: 0 [ 1079.546880] nova: Current epoch id: 0 [ 1079.546924] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x356656000, tail 0x356656080 [ 1079.546939] nova: nova_save_blocknode_mappings_to_log: 57 blocknodes, 1 log pages, pi head 0x356657000, tail 0x356657390 [ 1079.552858] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1079.552860] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1079.552967] nova: Start NOVA snapshot cleaner thread. [ 1079.552976] nova: Running snapshot cleaner thread [ 1079.552982] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1079.552984] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1079.552984] nova: NOVA: Normal shutdown [ 1079.556118] nova: Current epoch id: 0 [ 1085.162846] nova: Current epoch id: 0 [ 1085.162895] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x1ee657000, tail 0x1ee657080 [ 1085.162912] nova: nova_save_blocknode_mappings_to_log: 57 blocknodes, 1 log pages, pi head 0x1ee658000, tail 0x1ee658390 [ 1085.171620] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1085.171622] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1085.171716] nova: Start NOVA snapshot cleaner thread. [ 1085.171726] nova: Running snapshot cleaner thread [ 1085.171729] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1085.171732] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1085.171732] nova: NOVA: Normal shutdown [ 1085.174782] nova: Current epoch id: 0 [ 1085.194676] run fstests generic/346 at 2017-06-13 21:27:24 [ 1085.366871] nova: Current epoch id: 0 [ 1085.366927] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x1ee657000, tail 0x1ee657080 [ 1085.366943] nova: nova_save_blocknode_mappings_to_log: 57 blocknodes, 1 log pages, pi head 0x1ee658000, tail 0x1ee658390 [ 1085.374375] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1085.374377] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1085.374452] nova: Start NOVA snapshot cleaner thread. [ 1085.374459] nova: Running snapshot cleaner thread [ 1085.374466] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1085.374468] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1085.374469] nova: NOVA: Normal shutdown [ 1085.377579] nova: Current epoch id: 0 [ 1085.410901] nova: Current epoch id: 0 [ 1085.410952] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x176656000, tail 0x176656080 [ 1085.410981] nova: nova_save_blocknode_mappings_to_log: 57 blocknodes, 1 log pages, pi head 0x176657000, tail 0x176657380 [ 1085.416437] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1085.416439] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1085.416522] nova: Start NOVA snapshot cleaner thread. [ 1085.416530] nova: Running snapshot cleaner thread [ 1085.416536] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1085.416539] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1085.416539] nova: NOVA: Normal shutdown [ 1085.419722] nova: Current epoch id: 0 [ 1087.614854] nova: Current epoch id: 0 [ 1087.614890] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x1ee657000, tail 0x1ee657080 [ 1087.614905] nova: nova_save_blocknode_mappings_to_log: 57 blocknodes, 1 log pages, pi head 0x1ee658000, tail 0x1ee658390 [ 1087.623534] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1087.623536] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1087.623607] nova: Start NOVA snapshot cleaner thread. [ 1087.623614] nova: Running snapshot cleaner thread [ 1087.623620] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1087.623622] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1087.623623] nova: NOVA: Normal shutdown [ 1087.626739] nova: Current epoch id: 0 [ 1087.697705] run fstests generic/347 at 2017-06-13 21:27:26 [ 1087.902833] nova: Current epoch id: 0 [ 1087.902885] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0xfe656000, tail 0xfe656080 [ 1087.902901] nova: nova_save_blocknode_mappings_to_log: 56 blocknodes, 1 log pages, pi head 0xfe658000, tail 0xfe658380 [ 1087.925655] run fstests generic/348 at 2017-06-13 21:27:26 [ 1088.082516] run fstests generic/349 at 2017-06-13 21:27:26 [ 1088.236982] run fstests generic/350 at 2017-06-13 21:27:27 [ 1088.390177] run fstests generic/351 at 2017-06-13 21:27:27 [ 1088.545075] run fstests generic/352 at 2017-06-13 21:27:27 [ 1088.708163] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1088.708165] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1088.708263] nova: Start NOVA snapshot cleaner thread. [ 1088.708271] nova: Running snapshot cleaner thread [ 1088.708277] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1088.708280] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1088.708280] nova: NOVA: Normal shutdown [ 1088.711496] nova: Current epoch id: 0 [ 1088.738906] nova: Current epoch id: 0 [ 1088.738959] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x86656000, tail 0x86656080 [ 1088.738974] nova: nova_save_blocknode_mappings_to_log: 56 blocknodes, 1 log pages, pi head 0x86658000, tail 0x86658380 [ 1088.744574] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1088.744576] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1088.744651] nova: Start NOVA snapshot cleaner thread. [ 1088.744659] nova: Running snapshot cleaner thread [ 1088.744664] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1088.744667] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1088.744667] nova: NOVA: Normal shutdown [ 1088.747792] nova: Current epoch id: 0 [ 1088.770909] nova: Current epoch id: 0 [ 1088.770953] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x1ee657000, tail 0x1ee657080 [ 1088.770967] nova: nova_save_blocknode_mappings_to_log: 53 blocknodes, 1 log pages, pi head 0x1ee658000, tail 0x1ee658350 [ 1088.790859] run fstests generic/353 at 2017-06-13 21:27:27 [ 1088.957662] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1088.957664] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1088.957774] nova: Start NOVA snapshot cleaner thread. [ 1088.957782] nova: Running snapshot cleaner thread [ 1088.957787] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1088.957789] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1088.957789] nova: NOVA: Normal shutdown [ 1088.960987] nova: Current epoch id: 0 [ 1088.998904] nova: Current epoch id: 0 [ 1088.998959] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x176656000, tail 0x176656080 [ 1088.998979] nova: nova_save_blocknode_mappings_to_log: 57 blocknodes, 1 log pages, pi head 0x176657000, tail 0x176657380 [ 1089.004556] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1089.004558] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1089.004644] nova: Start NOVA snapshot cleaner thread. [ 1089.004658] nova: Running snapshot cleaner thread [ 1089.004663] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1089.004666] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1089.004666] nova: NOVA: Normal shutdown [ 1089.007765] nova: Current epoch id: 0 [ 1089.034844] nova: Current epoch id: 0 [ 1089.034882] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x1ee657000, tail 0x1ee657080 [ 1089.034897] nova: nova_save_blocknode_mappings_to_log: 55 blocknodes, 1 log pages, pi head 0x1ee658000, tail 0x1ee658370 [ 1089.055372] run fstests generic/354 at 2017-06-13 21:27:27 [ 1089.207157] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1089.207159] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1089.207268] nova: Start NOVA snapshot cleaner thread. [ 1089.207275] nova: Running snapshot cleaner thread [ 1089.207282] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1089.207284] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1089.207284] nova: NOVA: Normal shutdown [ 1089.210490] nova: Current epoch id: 0 [ 1089.234889] nova: Current epoch id: 0 [ 1089.234992] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x266657000, tail 0x266657080 [ 1089.235007] nova: nova_save_blocknode_mappings_to_log: 57 blocknodes, 1 log pages, pi head 0x266658000, tail 0x266658390 [ 1089.240227] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1089.240229] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1089.240326] nova: Start NOVA snapshot cleaner thread. [ 1089.240332] nova: Running snapshot cleaner thread [ 1089.240340] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1089.240342] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1089.240342] nova: NOVA: Normal shutdown [ 1089.243491] nova: Current epoch id: 0 [ 1092.574846] nova: Current epoch id: 0 [ 1092.574902] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x86656000, tail 0x86656080 [ 1092.574918] nova: nova_save_blocknode_mappings_to_log: 56 blocknodes, 1 log pages, pi head 0x86658000, tail 0x86658380 [ 1092.583834] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1092.583836] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1092.583933] nova: Start NOVA snapshot cleaner thread. [ 1092.583941] nova: Running snapshot cleaner thread [ 1092.583947] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1092.583950] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1092.583950] nova: NOVA: Normal shutdown [ 1092.587081] nova: Current epoch id: 0 [ 1092.607768] run fstests generic/355 at 2017-06-13 21:27:31 [ 1092.887050] nova: Current epoch id: 0 [ 1092.887110] nova: nova_save_inode_list_to_log: 17 inode nodes, pi head 0x1379c000, tail 0x1379c110 [ 1092.887182] nova: nova_save_blocknode_mappings_to_log: 269 blocknodes, 2 log pages, pi head 0x1379e000, tail 0x1379f0f0 [ 1092.897892] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 1092.897895] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1092.898029] nova: Start NOVA snapshot cleaner thread. [ 1092.898037] nova: Running snapshot cleaner thread [ 1092.898094] nova: nova_init_inode_list_from_inode: 17 inode nodes [ 1092.898097] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1092.898098] nova: NOVA: Normal shutdown [ 1092.901557] nova: Current epoch id: 0 [ 1092.924629] run fstests generic/356 at 2017-06-13 21:27:31 [ 1093.122838] nova: Current epoch id: 0 [ 1093.122909] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x176656000, tail 0x176656080 [ 1093.122925] nova: nova_save_blocknode_mappings_to_log: 57 blocknodes, 1 log pages, pi head 0x176657000, tail 0x176657380 [ 1093.135354] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1093.135356] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1093.135554] nova: Start NOVA snapshot cleaner thread. [ 1093.135560] nova: Running snapshot cleaner thread [ 1093.135575] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1093.135577] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1093.135577] nova: NOVA: Normal shutdown [ 1093.138839] nova: Current epoch id: 0 [ 1093.158985] nova: Current epoch id: 0 [ 1093.159036] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x266657000, tail 0x266657080 [ 1093.159052] nova: nova_save_blocknode_mappings_to_log: 57 blocknodes, 1 log pages, pi head 0x266658000, tail 0x266658390 [ 1093.164656] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1093.164658] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1093.164773] nova: Start NOVA snapshot cleaner thread. [ 1093.164782] nova: Running snapshot cleaner thread [ 1093.164787] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1093.164789] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1093.164789] nova: NOVA: Normal shutdown [ 1093.167915] nova: Current epoch id: 0 [ 1093.198861] nova: Current epoch id: 0 [ 1093.198900] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x266657000, tail 0x266657080 [ 1093.198918] nova: nova_save_blocknode_mappings_to_log: 52 blocknodes, 1 log pages, pi head 0x266658000, tail 0x266658340 [ 1093.223050] run fstests generic/357 at 2017-06-13 21:27:32 [ 1093.401695] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1093.401697] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1093.401788] nova: Start NOVA snapshot cleaner thread. [ 1093.401804] nova: Running snapshot cleaner thread [ 1093.401805] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1093.401807] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1093.401807] nova: NOVA: Normal shutdown [ 1093.404932] nova: Current epoch id: 0 [ 1093.430893] nova: Current epoch id: 0 [ 1093.430954] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x176656000, tail 0x176656080 [ 1093.430970] nova: nova_save_blocknode_mappings_to_log: 57 blocknodes, 1 log pages, pi head 0x176657000, tail 0x176657380 [ 1093.436267] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1093.436269] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1093.436345] nova: Start NOVA snapshot cleaner thread. [ 1093.436354] nova: Running snapshot cleaner thread [ 1093.436359] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1093.436361] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1093.436362] nova: NOVA: Normal shutdown [ 1093.439512] nova: Current epoch id: 0 [ 1093.458845] nova: Current epoch id: 0 [ 1093.458888] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x86656000, tail 0x86656080 [ 1093.458902] nova: nova_save_blocknode_mappings_to_log: 50 blocknodes, 1 log pages, pi head 0x86658000, tail 0x86658320 [ 1093.480025] run fstests generic/358 at 2017-06-13 21:27:32 [ 1093.643898] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1093.643900] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1093.643988] nova: Start NOVA snapshot cleaner thread. [ 1093.643997] nova: Running snapshot cleaner thread [ 1093.644002] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1093.644004] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1093.644004] nova: NOVA: Normal shutdown [ 1093.647140] nova: Current epoch id: 0 [ 1093.674890] nova: Current epoch id: 0 [ 1093.674944] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x2de65f000, tail 0x2de65f080 [ 1093.674960] nova: nova_save_blocknode_mappings_to_log: 57 blocknodes, 1 log pages, pi head 0x2de660000, tail 0x2de660390 [ 1093.680164] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1093.680166] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1093.680243] nova: Start NOVA snapshot cleaner thread. [ 1093.680249] nova: Running snapshot cleaner thread [ 1093.680262] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1093.680264] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1093.680264] nova: NOVA: Normal shutdown [ 1093.683428] nova: Current epoch id: 0 [ 1093.702870] nova: Current epoch id: 0 [ 1093.702917] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x266657000, tail 0x266657080 [ 1093.702931] nova: nova_save_blocknode_mappings_to_log: 52 blocknodes, 1 log pages, pi head 0x266658000, tail 0x266658340 [ 1093.722662] run fstests generic/359 at 2017-06-13 21:27:32 [ 1093.886219] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1093.886221] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1093.886334] nova: Start NOVA snapshot cleaner thread. [ 1093.886343] nova: Running snapshot cleaner thread [ 1093.886348] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1093.886350] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1093.886350] nova: NOVA: Normal shutdown [ 1093.889553] nova: Current epoch id: 0 [ 1093.914913] nova: Current epoch id: 0 [ 1093.914961] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x176656000, tail 0x176656080 [ 1093.914975] nova: nova_save_blocknode_mappings_to_log: 57 blocknodes, 1 log pages, pi head 0x176657000, tail 0x176657380 [ 1093.920158] nova: nova_get_nvmm_info: dev pmem1, phys_addr 0x780000000, virt_addr ffff960100000000, size 16106127360 [ 1093.920160] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1093.920227] nova: Start NOVA snapshot cleaner thread. [ 1093.920235] nova: Running snapshot cleaner thread [ 1093.920239] nova: nova_init_inode_list_from_inode: 8 inode nodes [ 1093.920242] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1093.920242] nova: NOVA: Normal shutdown [ 1093.923354] nova: Current epoch id: 0 [ 1093.950847] nova: Current epoch id: 0 [ 1093.950894] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x266657000, tail 0x266657080 [ 1093.950910] nova: nova_save_blocknode_mappings_to_log: 56 blocknodes, 1 log pages, pi head 0x266658000, tail 0x266658380 [ 1093.970844] run fstests generic/360 at 2017-06-13 21:27:32 [ 1094.186987] nova: Current epoch id: 0 [ 1094.187038] nova: nova_save_inode_list_to_log: 17 inode nodes, pi head 0x1379c000, tail 0x1379c110 [ 1094.187097] nova: nova_save_blocknode_mappings_to_log: 269 blocknodes, 2 log pages, pi head 0x1379e000, tail 0x1379f0f0 [ 1094.195687] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 1094.195689] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 1094.195793] nova: Start NOVA snapshot cleaner thread. [ 1094.195799] nova: Running snapshot cleaner thread [ 1094.195845] nova: nova_init_inode_list_from_inode: 17 inode nodes [ 1094.195847] nova: Recovered 0 snapshots, latest epoch ID 0 [ 1094.195848] nova: NOVA: Normal shutdown [ 1094.198051] nova: Current epoch id: 0 [ 1094.217723] run fstests generic/361 at 2017-06-13 21:27:33 [ 1094.390332] run fstests generic/362 at 2017-06-13 21:27:33 [ 1094.555244] run fstests generic/363 at 2017-06-13 21:27:33 [ 1094.732231] run fstests generic/364 at 2017-06-13 21:27:33 [ 1094.918696] run fstests generic/365 at 2017-06-13 21:27:33 [ 1095.112954] run fstests generic/366 at 2017-06-13 21:27:33 [ 1095.313351] run fstests generic/367 at 2017-06-13 21:27:34 [ 1095.525719] run fstests generic/368 at 2017-06-13 21:27:34 [ 1095.765772] run fstests generic/369 at 2017-06-13 21:27:34 [ 1095.979956] run fstests generic/370 at 2017-06-13 21:27:34 [ 1096.203190] run fstests shared/001 at 2017-06-13 21:27:35 [ 1096.411449] run fstests shared/002 at 2017-06-13 21:27:35 [ 1096.599096] run fstests shared/003 at 2017-06-13 21:27:35 [ 1096.785760] run fstests shared/004 at 2017-06-13 21:27:35 [ 1096.968559] run fstests shared/006 at 2017-06-13 21:27:35 [ 1097.149328] run fstests shared/032 at 2017-06-13 21:27:35 [ 1097.349243] run fstests shared/051 at 2017-06-13 21:27:36 [ 1097.535033] run fstests shared/272 at 2017-06-13 21:27:36 [ 1097.705330] run fstests shared/289 at 2017-06-13 21:27:36 [ 1097.885625] run fstests shared/298 at 2017-06-13 21:27:36 [ 1098.114981] nova: Current epoch id: 0 [ 1098.115039] nova: nova_save_inode_list_to_log: 17 inode nodes, pi head 0x333837000, tail 0x333837110 [ 1098.115097] nova: nova_save_blocknode_mappings_to_log: 270 blocknodes, 2 log pages, pi head 0x333838000, tail 0x333839100 [ 2233.291562] EXT4-fs (loop1): mounting ext3 file system using the ext4 subsystem [ 2233.294797] EXT4-fs (loop1): mounted filesystem with ordered data mode. Opts: usrquota,grpquota [ 2233.329583] EXT4-fs (loop1): re-mounted. Opts: (null) [ 2233.333116] EXT4-fs (loop1): re-mounted. Opts: (null) [ 2240.923460] drop-caches (25336): drop_caches: 3 [ 2242.464826] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2242.464829] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2242.464981] nova: Start NOVA snapshot cleaner thread. [ 2242.464983] nova: creating an empty nova of size 21474836480 [ 2242.464989] nova: Running snapshot cleaner thread [ 2242.467095] nova: NOVA initialization finish [ 2242.467106] nova: Current epoch id: 0 [ 2242.509084] drop-caches (25456): drop_caches: 3 [ 2251.797477] nova: nova_cow_file_write alloc blocks failed -28 [ 2251.797479] nova: nova_cow_file_write alloc blocks failed -28 [ 2251.797481] nova: nova_cow_file_write alloc blocks failed -28 [ 2251.797482] nova: nova_cow_file_write alloc blocks failed -28 [ 2252.206307] drop-caches (25489): drop_caches: 3 [ 2253.331276] nova: Current epoch id: 0 [ 2253.331314] nova error: [ 2253.331315] ERROR: no inode log page available: 1 -28 [ 2253.331316] nova: Error saving inode list: -28 [ 2253.331316] nova error: [ 2253.331317] ERROR: no inode log page available: 0 -22 [ 2253.331317] nova: Error saving blocknode mappings: -22 [ 2253.411165] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2253.411167] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2253.411278] nova: Start NOVA snapshot cleaner thread. [ 2253.411281] nova: creating an empty nova of size 21474836480 [ 2253.411286] nova: Running snapshot cleaner thread [ 2253.413416] nova: NOVA initialization finish [ 2253.413429] nova: Current epoch id: 0 [ 2253.465026] drop-caches (25511): drop_caches: 3 [ 2262.734509] nova: nova_cow_file_write alloc blocks failed -28 [ 2262.734513] nova: nova_cow_file_write alloc blocks failed -28 [ 2263.136655] drop-caches (25540): drop_caches: 3 [ 2264.539293] nova: Current epoch id: 0 [ 2264.539374] nova error: [ 2264.539375] ERROR: no inode log page available: 1 -28 [ 2264.539376] nova: Error saving inode list: -28 [ 2264.539376] nova error: [ 2264.539377] ERROR: no inode log page available: 0 -22 [ 2264.539377] nova: Error saving blocknode mappings: -22 [ 2264.600054] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2264.600057] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2264.600179] nova: Start NOVA snapshot cleaner thread. [ 2264.600181] nova: creating an empty nova of size 21474836480 [ 2264.600187] nova: Running snapshot cleaner thread [ 2264.602296] nova: NOVA initialization finish [ 2264.602304] nova: Current epoch id: 0 [ 2264.679735] drop-caches (25562): drop_caches: 3 [ 2281.201397] drop-caches (25587): drop_caches: 3 [ 2282.451272] nova: Current epoch id: 0 [ 2282.451353] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x1cdd56000, tail 0x1cdd56080 [ 2282.451360] nova: nova_save_blocknode_mappings_to_log: 7 blocknodes, 1 log pages, pi head 0x26dd56000, tail 0x26dd56070 [ 2282.505200] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2282.505203] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2282.505315] nova: Start NOVA snapshot cleaner thread. [ 2282.505317] nova: creating an empty nova of size 21474836480 [ 2282.505323] nova: Running snapshot cleaner thread [ 2282.507450] nova: NOVA initialization finish [ 2282.507459] nova: Current epoch id: 0 [ 2282.551944] drop-caches (25609): drop_caches: 3 [ 2298.598691] drop-caches (25642): drop_caches: 3 [ 2299.791289] nova: Current epoch id: 0 [ 2299.791343] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x1327c000, tail 0x1327c080 [ 2299.791358] nova: nova_save_blocknode_mappings_to_log: 48 blocknodes, 1 log pages, pi head 0x1327f000, tail 0x1327f300 [ 2299.877244] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2299.877247] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2299.877327] nova: Start NOVA snapshot cleaner thread. [ 2299.877329] nova: creating an empty nova of size 21474836480 [ 2299.877334] nova: Running snapshot cleaner thread [ 2299.879495] nova: NOVA initialization finish [ 2299.879503] nova: Current epoch id: 0 [ 2299.942202] drop-caches (25664): drop_caches: 3 [ 2316.245515] drop-caches (25691): drop_caches: 3 [ 2317.627292] nova: Current epoch id: 0 [ 2317.627366] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x1327c000, tail 0x1327c080 [ 2317.627377] nova: nova_save_blocknode_mappings_to_log: 28 blocknodes, 1 log pages, pi head 0x1327d000, tail 0x1327d1c0 [ 2317.698630] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2317.698632] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2317.698780] nova: Start NOVA snapshot cleaner thread. [ 2317.698782] nova: creating an empty nova of size 21474836480 [ 2317.698790] nova: Running snapshot cleaner thread [ 2317.701162] nova: NOVA initialization finish [ 2317.701173] nova: Current epoch id: 0 [ 2317.747317] drop-caches (25713): drop_caches: 3 [ 2333.756977] drop-caches (25737): drop_caches: 3 [ 2335.039283] nova: Current epoch id: 0 [ 2335.039346] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x13284000, tail 0x13284080 [ 2335.039354] nova: nova_save_blocknode_mappings_to_log: 17 blocknodes, 1 log pages, pi head 0x13288000, tail 0x13288110 [ 2335.095789] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2335.095791] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2335.095910] nova: Start NOVA snapshot cleaner thread. [ 2335.095913] nova: creating an empty nova of size 21474836480 [ 2335.095918] nova: Running snapshot cleaner thread [ 2335.098018] nova: NOVA initialization finish [ 2335.098026] nova: Current epoch id: 0 [ 2335.161150] drop-caches (25759): drop_caches: 3 [ 2351.378847] drop-caches (25786): drop_caches: 3 [ 2352.651816] nova: Current epoch id: 0 [ 2352.651893] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x13283000, tail 0x13283080 [ 2352.651901] nova: nova_save_blocknode_mappings_to_log: 16 blocknodes, 1 log pages, pi head 0x142d4000, tail 0x142d40f0 [ 2352.717980] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2352.717984] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2352.718111] nova: Start NOVA snapshot cleaner thread. [ 2352.718114] nova: creating an empty nova of size 21474836480 [ 2352.718122] nova: Running snapshot cleaner thread [ 2352.720716] nova: NOVA initialization finish [ 2352.720733] nova: Current epoch id: 0 [ 2352.768312] drop-caches (25808): drop_caches: 3 [ 2368.852799] drop-caches (25833): drop_caches: 3 [ 2370.035534] nova: Current epoch id: 0 [ 2370.035594] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x1327a000, tail 0x1327a080 [ 2370.035601] nova: nova_save_blocknode_mappings_to_log: 13 blocknodes, 1 log pages, pi head 0x13963000, tail 0x139630d0 [ 2370.106559] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2370.106561] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2370.106714] nova: Start NOVA snapshot cleaner thread. [ 2370.106717] nova: creating an empty nova of size 21474836480 [ 2370.106720] nova: Running snapshot cleaner thread [ 2370.109079] nova: NOVA initialization finish [ 2370.109089] nova: Current epoch id: 0 [ 2370.158135] drop-caches (25855): drop_caches: 3 [ 2386.414767] drop-caches (25879): drop_caches: 3 [ 2387.739418] nova: Current epoch id: 0 [ 2387.739511] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x1394a000, tail 0x1394a080 [ 2387.739518] nova: nova_save_blocknode_mappings_to_log: 14 blocknodes, 1 log pages, pi head 0x1394b000, tail 0x1394b0e0 [ 2387.803004] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2387.803006] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2387.803197] nova: Start NOVA snapshot cleaner thread. [ 2387.803199] nova: creating an empty nova of size 21474836480 [ 2387.803211] nova: Running snapshot cleaner thread [ 2387.805574] nova: NOVA initialization finish [ 2387.805585] nova: Current epoch id: 0 [ 2387.846192] drop-caches (25901): drop_caches: 3 [ 2403.932562] drop-caches (25934): drop_caches: 3 [ 2404.971327] nova: Current epoch id: 0 [ 2404.971383] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x13284000, tail 0x13284080 [ 2404.971399] nova: nova_save_blocknode_mappings_to_log: 51 blocknodes, 1 log pages, pi head 0x13286000, tail 0x13286330 [ 2405.024727] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2405.024729] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2405.024807] nova: Start NOVA snapshot cleaner thread. [ 2405.024810] nova: creating an empty nova of size 21474836480 [ 2405.024815] nova: Running snapshot cleaner thread [ 2405.026934] nova: NOVA initialization finish [ 2405.026943] nova: Current epoch id: 0 [ 2405.075656] drop-caches (25956): drop_caches: 3 [ 2421.259372] drop-caches (25983): drop_caches: 3 [ 2422.399302] nova: Current epoch id: 0 [ 2422.399351] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x1327c000, tail 0x1327c080 [ 2422.399362] nova: nova_save_blocknode_mappings_to_log: 29 blocknodes, 1 log pages, pi head 0x1327d000, tail 0x1327d1d0 [ 2422.471888] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2422.471890] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2422.472104] nova: Start NOVA snapshot cleaner thread. [ 2422.472106] nova: creating an empty nova of size 21474836480 [ 2422.472114] nova: Running snapshot cleaner thread [ 2422.474232] nova: NOVA initialization finish [ 2422.474242] nova: Current epoch id: 0 [ 2422.537519] drop-caches (26005): drop_caches: 3 [ 2438.662492] drop-caches (26029): drop_caches: 3 [ 2439.847322] nova: Current epoch id: 0 [ 2439.847385] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x13284000, tail 0x13284080 [ 2439.847393] nova: nova_save_blocknode_mappings_to_log: 18 blocknodes, 1 log pages, pi head 0x13286000, tail 0x13286120 [ 2439.926939] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2439.926941] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2439.927064] nova: Start NOVA snapshot cleaner thread. [ 2439.927066] nova: creating an empty nova of size 21474836480 [ 2439.927075] nova: Running snapshot cleaner thread [ 2439.929428] nova: NOVA initialization finish [ 2439.929439] nova: Current epoch id: 0 [ 2439.982758] drop-caches (26051): drop_caches: 3 [ 2456.360535] drop-caches (26084): drop_caches: 3 [ 2457.707338] nova: Current epoch id: 0 [ 2457.707413] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x13285000, tail 0x13285080 [ 2457.707426] nova: nova_save_blocknode_mappings_to_log: 43 blocknodes, 1 log pages, pi head 0x1328c000, tail 0x1328c2b0 [ 2457.815631] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2457.815632] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2457.815723] nova: Start NOVA snapshot cleaner thread. [ 2457.815725] nova: creating an empty nova of size 21474836480 [ 2457.815727] nova: Running snapshot cleaner thread [ 2457.817848] nova: NOVA initialization finish [ 2457.817856] nova: Current epoch id: 0 [ 2457.862048] drop-caches (26106): drop_caches: 3 [ 2474.025741] drop-caches (26133): drop_caches: 3 [ 2475.219331] nova: Current epoch id: 0 [ 2475.219382] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x13286000, tail 0x13286080 [ 2475.219391] nova: nova_save_blocknode_mappings_to_log: 25 blocknodes, 1 log pages, pi head 0x13287000, tail 0x13287190 [ 2475.279049] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2475.279052] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2475.279143] nova: Start NOVA snapshot cleaner thread. [ 2475.279146] nova: creating an empty nova of size 21474836480 [ 2475.279153] nova: Running snapshot cleaner thread [ 2475.281287] nova: NOVA initialization finish [ 2475.281296] nova: Current epoch id: 0 [ 2475.336790] drop-caches (26155): drop_caches: 3 [ 2491.716136] drop-caches (26179): drop_caches: 3 [ 2493.143340] nova: Current epoch id: 0 [ 2493.143392] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x1327c000, tail 0x1327c080 [ 2493.143399] nova: nova_save_blocknode_mappings_to_log: 16 blocknodes, 1 log pages, pi head 0x13283000, tail 0x13283100 [ 2493.200688] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2493.200690] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2493.200849] nova: Start NOVA snapshot cleaner thread. [ 2493.200851] nova: creating an empty nova of size 21474836480 [ 2493.200860] nova: Running snapshot cleaner thread [ 2493.202965] nova: NOVA initialization finish [ 2493.202974] nova: Current epoch id: 0 [ 2493.266869] drop-caches (26201): drop_caches: 3 [ 2537.582502] drop-caches (26250): drop_caches: 3 [ 2540.965803] nova: Current epoch id: 0 [ 2540.966260] nova: nova_save_inode_list_to_log: 1921 inode nodes, pi head 0x297073000, tail 0x29707a8f0 [ 2540.966266] nova: nova_save_blocknode_mappings_to_log: 8 blocknodes, 1 log pages, pi head 0x29707b000, tail 0x29707b080 [ 2542.061231] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2542.061232] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2542.061319] nova: Start NOVA snapshot cleaner thread. [ 2542.061321] nova: creating an empty nova of size 21474836480 [ 2542.061327] nova: Running snapshot cleaner thread [ 2542.063506] nova: NOVA initialization finish [ 2542.063515] nova: Current epoch id: 0 [ 2542.114263] drop-caches (26272): drop_caches: 3 [ 2583.718982] drop-caches (26300): drop_caches: 3 [ 2587.712608] nova: Current epoch id: 0 [ 2587.712729] nova: nova_save_inode_list_to_log: 259 inode nodes, pi head 0x296473000, tail 0x296474050 [ 2587.712735] nova: nova_save_blocknode_mappings_to_log: 8 blocknodes, 1 log pages, pi head 0x296475000, tail 0x296475080 [ 2588.784277] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2588.784280] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2588.784401] nova: Start NOVA snapshot cleaner thread. [ 2588.784404] nova: creating an empty nova of size 21474836480 [ 2588.784408] nova: Running snapshot cleaner thread [ 2588.786572] nova: NOVA initialization finish [ 2588.786585] nova: Current epoch id: 0 [ 2588.840582] drop-caches (26322): drop_caches: 3 [ 2625.442381] drop-caches (26346): drop_caches: 3 [ 2628.275028] nova: Current epoch id: 0 [ 2628.275100] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x2b3327000, tail 0x2b3327080 [ 2628.275105] nova: nova_save_blocknode_mappings_to_log: 8 blocknodes, 1 log pages, pi head 0x2b3328000, tail 0x2b3328080 [ 2629.334814] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2629.334816] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2629.334929] nova: Start NOVA snapshot cleaner thread. [ 2629.334931] nova: creating an empty nova of size 21474836480 [ 2629.334938] nova: Running snapshot cleaner thread [ 2629.337166] nova: NOVA initialization finish [ 2629.337175] nova: Current epoch id: 0 [ 2629.375510] drop-caches (26368): drop_caches: 3 [ 2642.112246] fxmark invoked oom-killer: gfp_mask=0x16040c0(GFP_KERNEL|__GFP_COMP|__GFP_NOTRACK), nodemask=0, order=0, oom_score_adj=0 [ 2642.112247] fxmark cpuset=/ mems_allowed=0 [ 2642.112251] CPU: 3 PID: 26373 Comm: fxmark Tainted: G OE 4.10.0-rc8-nova #4 [ 2642.112252] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 [ 2642.112253] Call Trace: [ 2642.112259] dump_stack+0x63/0x81 [ 2642.112262] dump_header+0x7b/0x1fd [ 2642.112266] ? apparmor_capable+0x2f/0x40 [ 2642.112268] oom_kill_process+0x208/0x3e0 [ 2642.112269] out_of_memory+0x120/0x4c0 [ 2642.112272] __alloc_pages_slowpath+0xb37/0xba0 [ 2642.112274] __alloc_pages_nodemask+0x209/0x260 [ 2642.112276] alloc_pages_current+0x95/0x140 [ 2642.112279] new_slab+0x425/0x6f0 [ 2642.112280] ___slab_alloc+0x3a0/0x4b0 [ 2642.112283] ? get_empty_filp+0x5c/0x1c0 [ 2642.112284] ? get_empty_filp+0x5c/0x1c0 [ 2642.112286] __slab_alloc+0x20/0x40 [ 2642.112287] kmem_cache_alloc+0x15e/0x1a0 [ 2642.112289] get_empty_filp+0x5c/0x1c0 [ 2642.112290] path_openat+0x40/0x14f0 [ 2642.112292] do_filp_open+0x91/0x100 [ 2642.112293] ? list_lru_add+0x5a/0x120 [ 2642.112295] ? __alloc_fd+0x46/0x170 [ 2642.112296] do_sys_open+0x130/0x220 [ 2642.112297] SyS_open+0x1e/0x20 [ 2642.112299] entry_SYSCALL_64_fastpath+0x1e/0xad [ 2642.112300] RIP: 0033:0x7f8907ab7a70 [ 2642.112301] RSP: 002b:00007ffc1d18b0e8 EFLAGS: 00000246 ORIG_RAX: 0000000000000002 [ 2642.112302] RAX: ffffffffffffffda RBX: 0000000000116ca5 RCX: 00007f8907ab7a70 [ 2642.112302] RDX: 00000000000001c0 RSI: 0000000000000042 RDI: 00007ffc1d18c100 [ 2642.112303] RBP: 00007ffc1d18c100 R08: 0000000000000001 R09: 0000000000000028 [ 2642.112303] R10: 0000000000000075 R11: 0000000000000246 R12: 00007f8907f9f000 [ 2642.112304] R13: 00007ffc1d18b100 R14: 00007f8907fa81c0 R15: 000056316fe65532 [ 2642.112305] Mem-Info: [ 2642.112309] active_anon:467465 inactive_anon:2221 isolated_anon:0 active_file:4546 inactive_file:4386 isolated_file:0 unevictable:912 dirty:2 writeback:0 unstable:0 slab_reclaimable:3659301 slab_unreclaimable:16059 mapped:9567 shmem:2227 pagetables:2059 bounce:0 free:34891 free_pcp:0 free_cma:0 [ 2642.112312] Node 0 active_anon:1869860kB inactive_anon:8884kB active_file:18184kB inactive_file:17544kB unevictable:3648kB isolated(anon):0kB isolated(file):0kB mapped:38268kB dirty:8kB writeback:0kB shmem:0kB shmem_thp: 0kB shmem_pmdmapped: 1705984kB anon_thp: 8908kB writeback_tmp:0kB unstable:0kB pages_scanned:0 all_unreclaimable? no [ 2642.112312] Node 0 DMA free:15908kB min:60kB low:72kB high:84kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15992kB managed:15908kB mlocked:0kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB [ 2642.112315] lowmem_reserve[]: 0 2984 17026 17026 17026 [ 2642.112317] Node 0 DMA32 free:67996kB min:11836kB low:14892kB high:17948kB active_anon:2048kB inactive_anon:0kB active_file:4kB inactive_file:4kB unevictable:0kB writepending:0kB present:3129332kB managed:3063764kB mlocked:0kB slab_reclaimable:2993092kB slab_unreclaimable:164kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB [ 2642.112319] lowmem_reserve[]: 0 0 14041 14041 14041 [ 2642.112321] Node 0 Normal free:55660kB min:55684kB low:70060kB high:84436kB active_anon:1867812kB inactive_anon:8884kB active_file:18180kB inactive_file:17540kB unevictable:3648kB writepending:8kB present:14680064kB managed:14382792kB mlocked:3648kB slab_reclaimable:11644112kB slab_unreclaimable:64072kB kernel_stack:3936kB pagetables:8236kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB [ 2642.112323] lowmem_reserve[]: 0 0 0 0 0 [ 2642.112325] Node 0 DMA: 14kB (U) 08kB 016kB 132kB (U) 264kB (U) 1128kB (U) 1256kB (U) 0512kB 11024kB (U) 12048kB (M) 34096kB (M) = 15908kB [ 2642.112331] Node 0 DMA32: 144kB (UEH) 238kB (UEH) 2616kB (UMEH) 2132kB (UE) 2364kB (UMEH) 18128kB (UMEH) 12256kB (UMH) 9512kB (UMEH) 41024kB (UMH) 32048kB (EH) 114096kB (M) = 68080kB [ 2642.112338] Node 0 Normal: 28564kB (UMEH) 32238kB (UMEH) 30516kB (UME) 16032kB (UME) 14164kB (ME) 0128kB 0256kB 0512kB 01024kB 02048kB 0*4096kB = 56232kB [ 2642.112345] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=1048576kB [ 2642.112345] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB [ 2642.112346] 11728 total pagecache pages [ 2642.112347] 0 pages in swap cache [ 2642.112347] Swap cache stats: add 0, delete 0, find 0/0 [ 2642.112348] Free swap = 0kB [ 2642.112348] Total swap = 0kB [ 2642.112349] 4456347 pages RAM [ 2642.112349] 0 pages HighMem/MovableOnly [ 2642.112350] 90731 pages reserved [ 2642.112350] 0 pages cma reserved [ 2642.112350] 0 pages hwpoisoned [ 2642.112351] [ pid ] uid tgid total_vm rss nr_ptes nr_pmds swapents oom_score_adj name [ 2642.112355] [ 699] 0 699 11554 1748 25 3 0 0 systemd-journal [ 2642.112357] [ 748] 0 748 25746 353 18 3 0 0 lvmetad [ 2642.112359] [ 788] 0 788 11048 990 22 3 0 -1000 systemd-udevd [ 2642.112360] [ 1404] 0 1404 4029 227 11 3 0 0 dhclient [ 2642.112361] [ 1564] 0 1564 7036 552 19 3 0 0 atd [ 2642.112362] [ 1574] 106 1574 11327 875 26 3 0 -900 dbus-daemon [ 2642.112363] [ 1594] 102 1594 12476 967 29 3 0 0 systemd-resolve [ 2642.112364] [ 1612] 0 1612 1097 333 8 3 0 0 acpid [ 2642.112366] [ 1618] 0 1618 7460 686 19 3 0 0 cron [ 2642.112367] [ 1631] 104 1631 66414 899 32 4 0 0 rsyslogd [ 2642.112368] [ 1660] 0 1660 11638 841 26 3 0 0 systemd-logind [ 2642.112369] [ 1667] 0 1667 70987 1377 42 4 0 0 accounts-daemon [ 2642.112370] [ 1687] 0 1687 87738 2944 30 6 0 0 snapd [ 2642.112371] [ 1716] 0 1716 40223 318 16 3 0 0 lxcfs [ 2642.112373] [ 1726] 0 1726 1124 199 8 3 0 0 sshguard-journa [ 2642.112374] [ 1728] 0 1728 11950 1335 25 3 0 0 journalctl [ 2642.112375] [ 1729] 0 1729 4046 626 11 3 0 0 sshguard [ 2642.112376] [ 1754] 0 1754 1124 185 8 4 0 0 sshg-fw [ 2642.112377] [ 1829] 0 1829 71578 1306 43 3 0 0 polkitd [ 2642.112378] [ 1963] 0 1963 1304 30 7 3 0 0 iscsid [ 2642.112379] [ 1965] 0 1965 1429 875 8 3 0 -17 iscsid [ 2642.112380] [ 2033] 0 2033 3623 489 12 3 0 0 agetty [ 2642.112382] [ 2076] 0 2076 3679 425 12 3 0 0 agetty [ 2642.112383] [ 2105] 112 2105 24490 1157 21 3 0 0 ntpd [ 2642.112384] [ 2108] 0 2108 17103 5361 37 3 0 0 google_ip_forwa [ 2642.112385] [ 2115] 0 2115 17086 5391 37 3 0 0 google_accounts [ 2642.112386] [ 2122] 0 2122 17502 1270 38 3 0 -1000 sshd [ 2642.112388] [ 2124] 0 2124 17099 5329 39 3 0 0 google_clock_sk [ 2642.112389] [ 2143] 113 2143 16280 1031 35 3 0 0 systemd [ 2642.112390] [ 2151] 113 2151 21784 487 44 3 0 0 (sd-pam) [ 2642.112391] [ 2170] 113 2170 4713 45 13 3 0 0 daemon [ 2642.112392] [ 2184] 113 2184 2556257 449971 1031 12 0 0 java [ 2642.112394] [ 2197] 0 2197 25359 1369 54 3 0 0 sshd [ 2642.112395] [ 2215] 1001 2215 16280 1045 35 3 0 0 systemd [ 2642.112396] [ 2216] 1001 2216 21784 487 44 3 0 0 (sd-pam) [ 2642.112397] [ 2367] 1001 2367 25359 754 50 3 0 0 sshd [ 2642.112398] [ 2377] 1001 2377 5401 1012 15 3 0 0 bash [ 2642.112400] [25320] 113 25320 1124 199 8 3 0 0 sh [ 2642.112401] [25323] 113 25323 1124 188 7 3 0 0 script.sh [ 2642.112402] [25324] 113 25324 12034 3341 26 3 0 0 python3 [ 2642.112403] [26369] 113 26369 1124 190 8 3 0 0 sh [ 2642.112404] [26370] 113 26370 1075 180 7 3 0 0 fxmark [ 2642.112405] [26371] 113 26371 1075 20 7 3 0 0 fxmark [ 2642.112406] [26372] 113 26372 1075 20 7 3 0 0 fxmark [ 2642.112407] [26373] 113 26373 1075 20 7 3 0 0 fxmark [ 2642.112408] Out of memory: Kill process 2184 (java) score 103 or sacrifice child [ 2642.129387] Killed process 25320 (sh) total-vm:4496kB, anon-rss:72kB, file-rss:724kB, shmem-rss:0kB [ 2655.645777] drop-caches (26406): drop_caches: 3 [ 2658.723383] nova: Current epoch id: 0 [ 2658.723428] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x1dc6d000, tail 0x1dc6d080 [ 2658.723434] nova: nova_save_blocknode_mappings_to_log: 8 blocknodes, 1 log pages, pi head 0x1dc6e000, tail 0x1dc6e080 [ 2658.796291] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2658.796293] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2658.796377] nova: Start NOVA snapshot cleaner thread. [ 2658.796380] nova: creating an empty nova of size 21474836480 [ 2658.796385] nova: Running snapshot cleaner thread [ 2658.798510] nova: NOVA initialization finish [ 2658.798520] nova: Current epoch id: 0 [ 2658.844683] drop-caches (26428): drop_caches: 3 [ 2685.079639] drop-caches (26455): drop_caches: 3 [ 2688.339457] nova: Current epoch id: 0 [ 2688.339527] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x1db76000, tail 0x1db76080 [ 2688.339533] nova: nova_save_blocknode_mappings_to_log: 8 blocknodes, 1 log pages, pi head 0x1db77000, tail 0x1db77080 [ 2688.416087] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2688.416090] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2688.416218] nova: Start NOVA snapshot cleaner thread. [ 2688.416220] nova: creating an empty nova of size 21474836480 [ 2688.416239] nova: Running snapshot cleaner thread [ 2688.418357] nova: NOVA initialization finish [ 2688.418365] nova: Current epoch id: 0 [ 2688.457291] drop-caches (26477): drop_caches: 3 [ 2710.324384] drop-caches (26501): drop_caches: 3 [ 2711.963443] nova: Current epoch id: 0 [ 2711.963494] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x1db76000, tail 0x1db76080 [ 2711.963500] nova: nova_save_blocknode_mappings_to_log: 8 blocknodes, 1 log pages, pi head 0x1db77000, tail 0x1db77080 [ 2712.036692] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2712.036694] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2712.036774] nova: Start NOVA snapshot cleaner thread. [ 2712.036776] nova: creating an empty nova of size 21474836480 [ 2712.036782] nova: Running snapshot cleaner thread [ 2712.038913] nova: NOVA initialization finish [ 2712.038922] nova: Current epoch id: 0 [ 2712.093655] drop-caches (26523): drop_caches: 3 [ 2725.322054] nova error: [ 2725.322057] ERROR: no inode log page available: 1 -28 [ 2725.322057] nova error: [ 2725.322058] nova_initialize_inode_log ERROR: no inode log page available [ 2725.322059] nova error: [ 2725.322060] nova error: [ 2725.322061] nova_append_file_write_entry failed [ 2725.322062] nova: nova_cow_file_write: append inode entry failed [ 2725.322063] ERROR: no inode log page available: 1 -28 [ 2725.322064] nova error: [ 2725.322065] nova_initialize_inode_log ERROR: no inode log page available [ 2725.322065] nova error: [ 2725.322066] nova_append_file_write_entry failed [ 2725.322066] nova: nova_cow_file_write: append inode entry failed [ 2725.322068] nova error: [ 2725.322069] ERROR: no inode log page available: 1 -28 [ 2725.322070] nova error: [ 2725.322071] nova_initialize_inode_log ERROR: no inode log page available [ 2725.322071] nova error: [ 2725.322071] nova_append_file_write_entry failed [ 2725.322072] nova: nova_cow_file_write: append inode entry failed [ 2725.322074] nova error: [ 2725.322075] ERROR: no inode log page available: 1 -28 [ 2725.322076] nova error: [ 2725.322077] nova_initialize_inode_log ERROR: no inode log page available [ 2725.322077] nova error: [ 2725.322078] nova_append_file_write_entry failed [ 2725.322079] nova: nova_cow_file_write: append inode entry failed [ 2728.385978] drop-caches (26556): drop_caches: 3 [ 2731.949009] nova: Current epoch id: 0 [ 2731.949066] nova error: [ 2731.949069] ERROR: no inode log page available: 1 -28 [ 2731.949070] nova: Error saving inode list: -28 [ 2731.949070] nova error: [ 2731.949071] ERROR: no inode log page available: 1 -28 [ 2731.949071] nova: Error saving blocknode mappings: -28 [ 2733.333761] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2733.333763] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2733.333863] nova: Start NOVA snapshot cleaner thread. [ 2733.333865] nova: creating an empty nova of size 21474836480 [ 2733.333875] nova: Running snapshot cleaner thread [ 2733.336135] nova: NOVA initialization finish [ 2733.336145] nova: Current epoch id: 0 [ 2733.391500] drop-caches (26578): drop_caches: 3 [ 2749.268320] nova error: [ 2749.268322] ERROR: no inode log page available: 1 -28 [ 2749.268323] nova error: [ 2749.268324] nova_initialize_inode_log ERROR: no inode log page available [ 2749.268324] nova error: [ 2749.268325] nova_append_file_write_entry failed [ 2749.268326] nova: nova_cow_file_write: append inode entry failed [ 2749.268331] nova error: [ 2749.268333] ERROR: no inode log page available: 1 -28 [ 2749.268334] nova error: [ 2749.268335] nova_initialize_inode_log ERROR: no inode log page available [ 2749.268335] nova error: [ 2749.268336] nova_append_file_write_entry failed [ 2749.268336] nova: nova_cow_file_write: append inode entry failed [ 2751.805447] drop-caches (26605): drop_caches: 3 [ 2755.311343] nova: Current epoch id: 0 [ 2755.311453] nova error: [ 2755.311455] ERROR: no inode log page available: 1 -28 [ 2755.311456] nova: Error saving inode list: -28 [ 2755.311456] nova error: [ 2755.311457] ERROR: no inode log page available: 1 -28 [ 2755.311457] nova: Error saving blocknode mappings: -28 [ 2756.925687] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2756.925689] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2756.925850] nova: Start NOVA snapshot cleaner thread. [ 2756.925852] nova: creating an empty nova of size 21474836480 [ 2756.925876] nova: Running snapshot cleaner thread [ 2756.928148] nova: NOVA initialization finish [ 2756.928158] nova: Current epoch id: 0 [ 2756.975251] drop-caches (26627): drop_caches: 3 [ 2775.394442] drop-caches (26651): drop_caches: 3 [ 2778.264496] nova: Current epoch id: 0 [ 2778.264606] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x2d2ede000, tail 0x2d2ede080 [ 2778.264613] nova: nova_save_blocknode_mappings_to_log: 7 blocknodes, 1 log pages, pi head 0x2d2edf000, tail 0x2d2edf070 [ 2779.230753] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2779.230755] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2779.230830] nova: Start NOVA snapshot cleaner thread. [ 2779.230832] nova: creating an empty nova of size 21474836480 [ 2779.230835] nova: Running snapshot cleaner thread [ 2779.233162] nova: NOVA initialization finish [ 2779.233173] nova: Current epoch id: 0 [ 2779.284815] drop-caches (26673): drop_caches: 3 [ 2783.522614] nova: nova_cow_file_write alloc blocks failed -28 [ 2783.522616] nova: nova_cow_file_write alloc blocks failed -28 [ 2783.522617] nova: nova_cow_file_write alloc blocks failed -28 [ 2783.522619] nova: nova_cow_file_write alloc blocks failed -28 [ 2785.002630] nova error: [ 2785.002633] ERROR: no inode log page available: 256 -28 [ 2785.002634] nova error: [ 2785.002634] nova_extend_inode_log ERROR: no inode log page available [ 2785.002635] nova: curr_p 0x3b8823fc0, 36326 pages [ 2785.002635] nova error: [ 2785.002636] nova_append_setattr_entry failed [ 2785.002636] nova: nova_handle_setattr_operation: append setattr entry failure [ 2785.330585] drop-caches (26698): drop_caches: 3 [ 2785.684623] nova: Current epoch id: 0 [ 2785.684699] nova error: [ 2785.684700] ERROR: no inode log page available: 1 -28 [ 2785.684701] nova: Error saving inode list: -28 [ 2785.684702] nova error: [ 2785.684702] ERROR: no inode log page available: 1 -28 [ 2785.684703] nova: Error saving blocknode mappings: -28 [ 2785.746347] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2785.746349] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2785.746472] nova: Start NOVA snapshot cleaner thread. [ 2785.746475] nova: creating an empty nova of size 21474836480 [ 2785.746482] nova: Running snapshot cleaner thread [ 2785.748739] nova: NOVA initialization finish [ 2785.748750] nova: Current epoch id: 0 [ 2785.774429] drop-caches (26720): drop_caches: 3 [ 2793.894362] nova: nova_cow_file_write alloc blocks failed -28 [ 2793.894363] nova: nova_cow_file_write alloc blocks failed -28 [ 2804.367848] drop-caches (26752): drop_caches: 3 [ 2805.407422] nova: Current epoch id: 0 [ 2805.407475] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x13285000, tail 0x13285080 [ 2805.409530] nova: nova_save_blocknode_mappings_to_log: 9569 blocknodes, 38 log pages, pi head 0x13286000, tail 0x132abab0 [ 2805.460200] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2805.460202] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2805.460297] nova: Start NOVA snapshot cleaner thread. [ 2805.460300] nova: creating an empty nova of size 21474836480 [ 2805.460308] nova: Running snapshot cleaner thread [ 2805.462428] nova: NOVA initialization finish [ 2805.462436] nova: Current epoch id: 0 [ 2805.519638] drop-caches (26774): drop_caches: 3 [ 2822.206448] nova: nova_cow_file_write alloc blocks failed -28 [ 2838.835059] drop-caches (26796): drop_caches: 3 [ 2840.055465] nova: Current epoch id: 0 [ 2840.055518] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x1327c000, tail 0x1327c080 [ 2840.055589] nova: nova_save_blocknode_mappings_to_log: 323 blocknodes, 2 log pages, pi head 0x1327d000, tail 0x1327e450 [ 2840.099738] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2840.099740] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2840.099821] nova: Start NOVA snapshot cleaner thread. [ 2840.099823] nova: creating an empty nova of size 21474836480 [ 2840.099831] nova: Running snapshot cleaner thread [ 2840.101927] nova: NOVA initialization finish [ 2840.101936] nova: Current epoch id: 0 [ 2840.155346] drop-caches (26818): drop_caches: 3 [ 2859.892227] drop-caches (26847): drop_caches: 3 [ 2861.219713] nova: Current epoch id: 0 [ 2861.219772] nova: nova_save_inode_list_to_log: 39 inode nodes, pi head 0x13283000, tail 0x13283270 [ 2861.219854] nova: nova_save_blocknode_mappings_to_log: 383 blocknodes, 2 log pages, pi head 0x13284000, tail 0x13285810 [ 2861.287898] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2861.287900] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2861.288038] nova: Start NOVA snapshot cleaner thread. [ 2861.288040] nova: creating an empty nova of size 21474836480 [ 2861.288047] nova: Running snapshot cleaner thread [ 2861.290149] nova: NOVA initialization finish [ 2861.290158] nova: Current epoch id: 0 [ 2861.335476] drop-caches (26869): drop_caches: 3 [ 2881.517843] drop-caches (26896): drop_caches: 3 [ 2882.939684] nova: Current epoch id: 0 [ 2882.939750] nova: nova_save_inode_list_to_log: 19 inode nodes, pi head 0x1327c000, tail 0x1327c130 [ 2882.939825] nova: nova_save_blocknode_mappings_to_log: 213 blocknodes, 1 log pages, pi head 0x1327d000, tail 0x1327dd50 [ 2883.021245] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2883.021248] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2883.021382] nova: Start NOVA snapshot cleaner thread. [ 2883.021386] nova: creating an empty nova of size 21474836480 [ 2883.021391] nova: Running snapshot cleaner thread [ 2883.023992] nova: NOVA initialization finish [ 2883.024009] nova: Current epoch id: 0 [ 2883.075468] drop-caches (26918): drop_caches: 3 [ 2902.748827] drop-caches (26944): drop_caches: 3 [ 2904.219493] nova: Current epoch id: 0 [ 2904.219579] nova: nova_save_inode_list_to_log: 15 inode nodes, pi head 0x13286000, tail 0x132860f0 [ 2904.219606] nova: nova_save_blocknode_mappings_to_log: 118 blocknodes, 1 log pages, pi head 0x13287000, tail 0x13287760 [ 2904.288181] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2904.288184] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2904.288283] nova: Start NOVA snapshot cleaner thread. [ 2904.288285] nova: creating an empty nova of size 21474836480 [ 2904.288293] nova: Running snapshot cleaner thread [ 2904.290437] nova: NOVA initialization finish [ 2904.290446] nova: Current epoch id: 0 [ 2904.345080] drop-caches (26966): drop_caches: 3 [ 2921.042869] drop-caches (26999): drop_caches: 3 [ 2922.271483] nova: Current epoch id: 0 [ 2922.271529] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x1327e000, tail 0x1327e080 [ 2922.271535] nova: nova_save_blocknode_mappings_to_log: 8 blocknodes, 1 log pages, pi head 0x1327f000, tail 0x1327f080 [ 2922.344002] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2922.344004] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2922.344153] nova: Start NOVA snapshot cleaner thread. [ 2922.344156] nova: creating an empty nova of size 21474836480 [ 2922.344163] nova: Running snapshot cleaner thread [ 2922.346326] nova: NOVA initialization finish [ 2922.346335] nova: Current epoch id: 0 [ 2922.391796] drop-caches (27021): drop_caches: 3 [ 2938.642862] drop-caches (27048): drop_caches: 3 [ 2940.031474] nova: Current epoch id: 0 [ 2940.031532] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x1327e000, tail 0x1327e080 [ 2940.031538] nova: nova_save_blocknode_mappings_to_log: 8 blocknodes, 1 log pages, pi head 0x1327f000, tail 0x1327f080 [ 2940.092196] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2940.092198] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2940.092325] nova: Start NOVA snapshot cleaner thread. [ 2940.092328] nova: creating an empty nova of size 21474836480 [ 2940.092334] nova: Running snapshot cleaner thread [ 2940.094879] nova: NOVA initialization finish [ 2940.094895] nova: Current epoch id: 0 [ 2940.157403] drop-caches (27070): drop_caches: 3 [ 2956.617647] drop-caches (27094): drop_caches: 3 [ 2957.951518] nova: Current epoch id: 0 [ 2957.951560] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x13287000, tail 0x13287080 [ 2957.951565] nova: nova_save_blocknode_mappings_to_log: 8 blocknodes, 1 log pages, pi head 0x13288000, tail 0x13288080 [ 2958.030480] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2958.030482] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2958.030592] nova: Start NOVA snapshot cleaner thread. [ 2958.030595] nova: creating an empty nova of size 21474836480 [ 2958.030602] nova: Running snapshot cleaner thread [ 2958.032885] nova: NOVA initialization finish [ 2958.032895] nova: Current epoch id: 0 [ 2958.144081] drop-caches (27116): drop_caches: 3 [ 2978.882500] drop-caches (2995): drop_caches: 3 [ 2980.183500] nova: Current epoch id: 0 [ 2980.183551] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x144cb000, tail 0x144cb080 [ 2980.183556] nova: nova_save_blocknode_mappings_to_log: 8 blocknodes, 1 log pages, pi head 0x144cc000, tail 0x144cc080 [ 2980.235850] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 2980.235851] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 2980.235950] nova: Start NOVA snapshot cleaner thread. [ 2980.235953] nova: creating an empty nova of size 21474836480 [ 2980.235958] nova: Running snapshot cleaner thread [ 2980.238145] nova: NOVA initialization finish [ 2980.238155] nova: Current epoch id: 0 [ 2980.281838] drop-caches (3017): drop_caches: 3 [ 3001.177680] drop-caches (11233): drop_caches: 3 [ 3002.551488] nova: Current epoch id: 0 [ 3002.551556] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x144cb000, tail 0x144cb080 [ 3002.551562] nova: nova_save_blocknode_mappings_to_log: 8 blocknodes, 1 log pages, pi head 0x144cc000, tail 0x144cc080 [ 3002.615808] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 3002.615810] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 3002.615912] nova: Start NOVA snapshot cleaner thread. [ 3002.615915] nova: creating an empty nova of size 21474836480 [ 3002.615918] nova: Running snapshot cleaner thread [ 3002.618045] nova: NOVA initialization finish [ 3002.618055] nova: Current epoch id: 0 [ 3002.669871] drop-caches (11255): drop_caches: 3 [ 3023.368878] drop-caches (19469): drop_caches: 3 [ 3024.563492] nova: Current epoch id: 0 [ 3024.563545] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x144cb000, tail 0x144cb080 [ 3024.563551] nova: nova_save_blocknode_mappings_to_log: 8 blocknodes, 1 log pages, pi head 0x144cc000, tail 0x144cc080 [ 3024.629555] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 3024.629557] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 3024.629675] nova: Start NOVA snapshot cleaner thread. [ 3024.629677] nova: creating an empty nova of size 21474836480 [ 3024.629683] nova: Running snapshot cleaner thread [ 3024.631854] nova: NOVA initialization finish [ 3024.631865] nova: Current epoch id: 0 [ 3024.694309] drop-caches (19491): drop_caches: 3 [ 3045.510916] drop-caches (27716): drop_caches: 3 [ 3046.895522] nova: Current epoch id: 0 [ 3046.895578] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x293272000, tail 0x293272080 [ 3046.895585] nova: nova_save_blocknode_mappings_to_log: 8 blocknodes, 1 log pages, pi head 0x293273000, tail 0x293273080 [ 3046.968075] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 3046.968077] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 3046.968166] nova: Start NOVA snapshot cleaner thread. [ 3046.968169] nova: creating an empty nova of size 21474836480 [ 3046.968172] nova: Running snapshot cleaner thread [ 3046.970296] nova: NOVA initialization finish [ 3046.970307] nova: Current epoch id: 0 [ 3047.011819] drop-caches (27738): drop_caches: 3 [ 3067.572487] drop-caches (3615): drop_caches: 3 [ 3068.911516] nova: Current epoch id: 0 [ 3068.911562] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0xb3272000, tail 0xb3272080 [ 3068.911567] nova: nova_save_blocknode_mappings_to_log: 8 blocknodes, 1 log pages, pi head 0xb3273000, tail 0xb3273080 [ 3068.989754] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 3068.989756] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 3068.989839] nova: Start NOVA snapshot cleaner thread. [ 3068.989841] nova: creating an empty nova of size 21474836480 [ 3068.989844] nova: Running snapshot cleaner thread [ 3068.992106] nova: NOVA initialization finish [ 3068.992116] nova: Current epoch id: 0 [ 3069.059535] drop-caches (3637): drop_caches: 3 [ 3090.137839] drop-caches (11852): drop_caches: 3 [ 3091.323532] nova: Current epoch id: 0 [ 3091.323603] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x144cb000, tail 0x144cb080 [ 3091.323608] nova: nova_save_blocknode_mappings_to_log: 8 blocknodes, 1 log pages, pi head 0x144cc000, tail 0x144cc080 [ 3091.378641] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 3091.378643] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 3091.378768] nova: Start NOVA snapshot cleaner thread. [ 3091.378771] nova: creating an empty nova of size 21474836480 [ 3091.378775] nova: Running snapshot cleaner thread [ 3091.380990] nova: NOVA initialization finish [ 3091.381000] nova: Current epoch id: 0 [ 3091.430271] drop-caches (11874): drop_caches: 3 [ 3126.072719] drop-caches (11917): drop_caches: 3 [ 3130.002784] nova: Current epoch id: 0 [ 3130.002858] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x294c72000, tail 0x294c72080 [ 3130.002864] nova: nova_save_blocknode_mappings_to_log: 8 blocknodes, 1 log pages, pi head 0x294c73000, tail 0x294c73080 [ 3131.706109] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 3131.706111] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 3131.706241] nova: Start NOVA snapshot cleaner thread. [ 3131.706243] nova: creating an empty nova of size 21474836480 [ 3131.706249] nova: Running snapshot cleaner thread [ 3131.708522] nova: NOVA initialization finish [ 3131.708531] nova: Current epoch id: 0 [ 3131.747794] drop-caches (11939): drop_caches: 3 [ 3167.382034] drop-caches (11966): drop_caches: 3 [ 3171.704286] nova: Current epoch id: 0 [ 3171.704340] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x295072000, tail 0x295072080 [ 3171.704345] nova: nova_save_blocknode_mappings_to_log: 8 blocknodes, 1 log pages, pi head 0x295073000, tail 0x295073080 [ 3173.573120] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 3173.573122] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 3173.573221] nova: Start NOVA snapshot cleaner thread. [ 3173.573223] nova: creating an empty nova of size 21474836480 [ 3173.573231] nova: Running snapshot cleaner thread [ 3173.575354] nova: NOVA initialization finish [ 3173.575363] nova: Current epoch id: 0 [ 3173.616347] drop-caches (11988): drop_caches: 3 [ 3208.947122] drop-caches (12012): drop_caches: 3 [ 3212.968613] nova: Current epoch id: 0 [ 3212.968668] nova: nova_save_inode_list_to_log: 8 inode nodes, pi head 0x294c72000, tail 0x294c72080 [ 3212.968674] nova: nova_save_blocknode_mappings_to_log: 8 blocknodes, 1 log pages, pi head 0x294c73000, tail 0x294c73080 [ 3214.659614] nova: nova_get_nvmm_info: dev pmem0, phys_addr 0x280000000, virt_addr ffff95fc00000000, size 21474836480 [ 3214.659616] nova: measure timing 0, replica metadata 1, metadata checksum 1, inplace metadata update 1, inplace update 0, wprotect 0, mmap Cow 1, data checksum 1, data parity 1, DRAM checksum 1 [ 3214.659723] nova: Start NOVA snapshot cleaner thread. [ 3214.659725] nova: creating an empty nova of size 21474836480 [ 3214.659727] nova: Running snapshot cleaner thread [ 3214.661861] nova: NOVA initialization finish [ 3214.661872] nova: Current epoch id: 0 [ 3214.714345] drop-caches (12034): drop_caches: 3 [ 3231.542154] nova: nova_insert_dir_radix_tree ERROR -12: n_dir_rd-0-514432.dat [ 3231.542156] nova error: [ 3231.542157] nova_rebuild_handle_dentry ERROR -12 [ 3231.542262] nova: nova_insert_dir_radix_tree ERROR -12: n_dir_rd-0-1084475.dat [ 3231.542262] nova error: [ 3231.542263] nova_create return -12

Copied from original issue: NVSL/nova-dev#16

[stevenjswanson]

From @Andiry on June 14, 2017 0:59

1. Do you encounter this issue when running fxmark?

2. Can you specify which exact test cause this issue?

3. FxMark has a known issue on system with small DRAM. It creates as many file as possible that fills the whole NVMM space. Since NOVA uses radix tree for directory and the key is the hash value of the file name, creating too many files consume all the DRAM for the radix tree and causes OOM.

[stevenjswanson]

Yes, on fxmark.

It's a new issue: the rest works with what's in Nova-linux. Fails for current nova-dev.

-steve

-- Composed on (and maybe dictated to) my phone.

On Jun 13, 2017, at 18:00, Andiry Xu [email protected] wrote:

Do you encounter this issue when running fxmark? 2.

Can you specify which exact test cause this issue? 3.

FxMark has a known issue on system with small DRAM. It creates as many file as possible that fills the whole NVMM space. Since NOVA uses radix tree for directory and the key is the hash value of the file name, creating too many files consume all the DRAM for the radix tree and causes OOM.

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/NVSL/nova-dev/issues/16#issuecomment-308289686, or mute the thread https://github.com/notifications/unsubscribe-auth/AIpg3bNXiTsFJZdtuX3vSTEWECCkG6sqks5sDzCMgaJpZM4N5MKo .

[stevenjswanson]

Here’s the output from fxmark:

NVMM:NOVA:DRBL:1:directio

INFO: DirectIO Enabled

ncpu secs works works/sec real.sec user.sec nice.sec sys.sec idle.sec iowait.sec irq.sec softirq.sec steal.sec guest.sec user.util nice.util sys.util idle.util iowait.util irq.util softirq.util steal.util guest.util

1 15.000033 10827945.000000 721861.411905 15.3331 0.24 0 14.84 107.56 0.01 0 0 0 0 0.195655 0 12.098 87.6861 0.0081523 0 0 0 0

NUM_TEST_CONF = 54

trying to unmount... /mnt/ramdisk trying to unmount... /mnt/ramdisk [Pipeline] } [Pipeline] // dir [Pipeline] } [Pipeline] // stage [Pipeline] } [Pipeline] // node [Pipeline] End of Pipeline ERROR: script returned exit code -1 Finished: FAILURE

The “trying to unmount” suggests it finished

NVMM:NOVA:DRBL:1:directio

INFO: DirectIO Enabled

maybe it crashed during dismount or while starting up for the next test.

-steve

On Jun 13, 2017, at 5:59 PM, Andiry Xu [email protected] wrote:

Do you encounter this issue when running fxmark?

Can you specify which exact test cause this issue?

FxMark has a known issue on system with small DRAM. It creates as many file as possible that fills the whole NVMM space. Since NOVA uses radix tree for directory and the key is the hash value of the file name, creating too many files consume all the DRAM for the radix tree and causes OOM.

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/NVSL/nova-dev/issues/16#issuecomment-308289686, or mute the thread https://github.com/notifications/unsubscribe-auth/AIpg3bNXiTsFJZdtuX3vSTEWECCkG6sqks5sDzCMgaJpZM4N5MKo.

[stevenjswanson]

How big is “small DRAM”?

-steve

On Jun 13, 2017, at 5:59 PM, Andiry Xu [email protected] wrote:

Do you encounter this issue when running fxmark?

Can you specify which exact test cause this issue?

FxMark has a known issue on system with small DRAM. It creates as many file as possible that fills the whole NVMM space. Since NOVA uses radix tree for directory and the key is the hash value of the file name, creating too many files consume all the DRAM for the radix tree and causes OOM.

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/NVSL/nova-dev/issues/16#issuecomment-308289686, or mute the thread https://github.com/notifications/unsubscribe-auth/AIpg3bNXiTsFJZdtuX3vSTEWECCkG6sqks5sDzCMgaJpZM4N5MKo.

[stevenjswanson]

From @Andiry on June 14, 2017 8:0

To efficiently locate a file in a dir, we use hash(filename) as the key, and the corresponding dentry address as the value in a radix tree. Hash(filename) is supposed to evenly distribute in 64 bit integer range. Radix tree is a trie tree.

So that means if all the hash values do not share a common prefix, then the space efficiency will be pretty bad. A single key can take ( 4KB * depth_of_tree) in the worst case. And DRAM are consumed quickly in this case. Assume 5000000 files and the radix tree has 3 layers. In the worst case it takes 5 * 10^6 * 4KB * 3 = 60GB.