403/403 Test #258: ep_testsuite.full_eviction.magma ..............................................................................................***Timeout 600.04 sec
|
09:47:39 Running [0000/0157]: expiry pager settings...(2220 ms) OK
|
09:47:39 Running [0001/0157]: expiry...(88 ms) OK
|
09:47:39 Running [0002/0157]: expiry with xattr...WARNING: Logging before InitGoogleLogging() is written to STDERR
|
09:47:39 E0820 00:37:41.606091 108132 NotificationQueue.h:555] [NotificationQueue] Unexpected state while draining signals: signal_=1 bytes_read=0
|
09:47:39 (83 ms) OK
|
09:47:39 Running [0003/0157]: expiry_loader...(143 ms) OK
|
09:47:39 Running [0004/0157]: expiration on compaction...(138 ms) OK
|
09:47:39 Running [0005/0157]: expiration on warmup...(1221 ms) OK
|
09:47:39 Running [0006/0157]: expiry_duplicate_warmup...(146 ms) OK
|
09:47:39 Running [0007/0157]: expiry_no_items_warmup...(3221 ms) OK
|
09:47:39 Running [0008/0157]: replica read...(105 ms) OK
|
09:47:39 Running [0009/0157]: replica read: invalid state - active...(91 ms) OK
|
09:47:39 Running [0010/0157]: replica read: invalid state - pending...(98 ms) OK
|
09:47:39 Running [0011/0157]: replica read: invalid state - dead...(102 ms) OK
|
09:47:39 Running [0012/0157]: replica read: invalid key...(100 ms) OK
|
09:47:39 Running [0013/0157]: test getr with evicted key...(98 ms) OK
|
09:47:39 Running [0014/0157]: test observe no data...(88 ms) OK
|
09:47:39 Running [0015/0157]: test observe single key...(73 ms) OK
|
09:47:39 Running [0016/0157]: test observe on temp item...(88 ms) OK
|
09:47:39 Running [0017/0157]: test observe multi key...(93 ms) OK
|
09:47:39 Running [0018/0157]: test multiple observes...(74 ms) OK
|
09:47:39 Running [0019/0157]: test observe with not found...(91 ms) OK
|
09:47:39 Running [0020/0157]: test observe not my vbucket...(68 ms) OK
|
09:47:39 Running [0021/0157]: test observe seqno basic tests...(103 ms) OK
|
09:47:39 Running [0022/0157]: test observe seqno failover...(126 ms) OK
|
09:47:39 Running [0023/0157]: test observe seqno error...(75 ms) OK
|
09:47:39 Running [0024/0157]: test memory condition...(77 ms) OK
|
09:47:39 Running [0025/0157]: warmup conf...(135 ms) OK
|
09:47:39 Running [0026/0157]: itempager conf...(87 ms) OK
|
09:47:39 Running [0027/0157]: PiTR conf...(95 ms) OK
|
09:47:39 Running [0028/0157]: bloomfilter conf...(7 ms) SKIPPED_UNDER_MAGMA
|
09:47:39 Running [0029/0157]: test bloomfilters...(7 ms) SKIPPED_UNDER_MAGMA
|
09:47:39 Running [0030/0157]: test bloomfilters with store apis...(7 ms) SKIPPED_UNDER_MAGMA
|
09:47:39 Running [0031/0157]: test bloomfilters's in a delete+set scenario...(7 ms) SKIPPED_UNDER_MAGMA
|
09:47:39 Running [0032/0157]: test datatype...(77 ms) OK
|
09:47:39 Running [0033/0157]: test datatype with unknown command...(93 ms) OK
|
09:47:39 Running [0034/0157]: test access scanner settings...(157 ms) OK
|
09:47:39 Running [0035/0157]: test access scanner...(259 ms) OK
|
09:47:39 Running [0036/0157]: test set_param message...(95 ms) OK
|
09:47:39 Running [0037/0157]: test warmup oom...WARNING: Found duplicate entry for "max_size"
|
09:47:39 WARNING: Found duplicate entry for "item_eviction_policy"
|
09:47:39 (634 ms) OK
|
09:47:39 Running [0038/0157]: item stats...(173 ms) OK
|
09:47:39 Running [0039/0157]: stats...(103 ms) OK
|
09:47:39 Running [0040/0157]: io stats...(93 ms) SKIPPED
|
09:47:39 Running [0041/0157]: file stats...(142 ms) OK
|
09:47:39 Running [0042/0157]: file stats post warmup...E0820 00:37:50.478209 48660 NotificationQueue.h:555] [NotificationQueue] Unexpected state while draining signals: signal_=1 bytes_read=0
|
09:47:39 (262 ms) OK
|
09:47:39 Running [0043/0157]: bg stats...(203 ms) OK
|
09:47:39 Running [0044/0157]: bg meta stats...(132 ms) OK
|
09:47:39 Running [0045/0157]: mem stats...(1215 ms) OK
|
09:47:39 Running [0046/0157]: stats key...(138 ms) OK
|
09:47:39 Running [0047/0157]: stats key EACCESS...(235 ms) OK
|
09:47:39 Running [0048/0157]: stats vkey...(489 ms) OK
|
09:47:39 Running [0049/0157]: stats vkey callback tests...(393 ms) OK
|
09:47:39 Running [0050/0157]: warmup stats...(496 ms) OK
|
09:47:39 Running [0051/0157]: warmup with threshold...(592 ms) OK
|
09:47:39 Running [0052/0157]: seqno stats...(134 ms) OK
|
09:47:39 Running [0053/0157]: diskinfo stats...(161 ms) OK
|
09:47:39 Running [0054/0157]: stats curr_items ADD SET...(118 ms) OK
|
09:47:39 Running [0055/0157]: stats curr_items DELETE...(104 ms) OK
|
09:47:39 Running [0056/0157]: stats curr_items vbucket_state_dead...(106 ms) OK
|
09:47:39 Running [0057/0157]: startup token stat...(185 ms) OK
|
09:47:39 Running [0058/0157]: ep workload stats...(90 ms) OK
|
09:47:39 Running [0059/0157]: ep max workload stats...(99 ms) OK
|
09:47:39 Running [0060/0157]: test ALL_KEYS api...(125 ms) OK
|
09:47:39 Running [0061/0157]: test ALL_KEYS api during bucket creation...(141 ms) OK
|
09:47:39 Running [0062/0157]: ep worker stats...(116 ms) SKIPPED
|
09:47:39 Running [0063/0157]: value eviction...(230 ms) OK
|
09:47:39 Running [0064/0157]: duplicate items on disk...(1556 ms) OK
|
09:47:39 Running [0065/0157]: test special char keys...(136 ms) OK
|
09:47:39 Running [0066/0157]: test binary keys...(136 ms) OK
|
09:47:39 Running [0067/0157]: test restart...(136 ms) OK
|
09:47:39 Running [0068/0157]: set+get+restart+hit (bin)...(134 ms) OK
|
09:47:39 Running [0069/0157]: test kill -9 bucket...(232 ms) OK
|
09:47:39 Running [0070/0157]: test shutdown with force...(300 ms) OK
|
09:47:39 Running [0071/0157]: test shutdown without force...(323 ms) OK
|
09:47:39 Running [0072/0157]: test shutdown snapshot range...E0820 00:37:59.140311 56748 NotificationQueue.h:555] [NotificationQueue] Unexpected state while draining signals: signal_=1 bytes_read=0
|
09:47:39 (189 ms) OK
|
09:47:39 Running [0073/0157]: disk>RAM golden path...(2239 ms) OK
|
09:47:39 Running [0074/0157]: disk>RAM paged-out rm...(1163 ms) OK
|
09:47:39 Running [0075/0157]: disk>RAM update paged-out...(84 ms) OK
|
09:47:39 Running [0076/0157]: disk>RAM delete paged-out...(85 ms) OK
|
09:47:39 Running [0077/0157]: disk>RAM set bgfetch race (skipped)...(61 ms) SKIPPED
|
09:47:39 Running [0078/0157]: disk>RAM delete bgfetch race (skipped)...(64 ms) SKIPPED
|
09:47:39 Running [0079/0157]: vbucket get (dead)...(75 ms) OK
|
09:47:39 Running [0080/0157]: vbucket get (pending)...(94 ms) OK
|
09:47:39 Running [0081/0157]: vbucket get (replica)...E0820 00:38:03.098390 106332 NotificationQueue.h:555] [NotificationQueue] Unexpected state while draining signals: signal_=1 bytes_read=0
|
09:47:39 (86 ms) OK
|
09:47:39 Running [0082/0157]: vbucket set (dead)...(76 ms) OK
|
09:47:39 Running [0083/0157]: vbucket set (pending)...(79 ms) OK
|
09:47:39 Running [0084/0157]: vbucket set (replica)...(75 ms) OK
|
09:47:39 Running [0085/0157]: vbucket replace (dead)...(65 ms) OK
|
09:47:39 Running [0086/0157]: vbucket replace (pending)...(74 ms) OK
|
09:47:39 Running [0087/0157]: vbucket replace (replica)...(81 ms) OK
|
09:47:39 Running [0088/0157]: vbucket add (dead)...(69 ms) OK
|
09:47:39 Running [0089/0157]: vbucket add (pending)...(82 ms) OK
|
09:47:39 Running [0090/0157]: vbucket add (replica)...(88 ms) OK
|
09:47:39 Running [0091/0157]: vbucket cas (dead)...(78 ms) OK
|
09:47:39 Running [0092/0157]: vbucket cas (pending)...(86 ms) OK
|
09:47:39 Running [0093/0157]: vbucket cas (replica)...(86 ms) OK
|
09:47:39 Running [0094/0157]: vbucket del (dead)...(70 ms) OK
|
09:47:39 Running [0095/0157]: vbucket del (pending)...(82 ms) OK
|
09:47:39 Running [0096/0157]: vbucket del (replica)...(91 ms) OK
|
09:47:39 Running [0097/0157]: test vbucket get...(93 ms) OK
|
09:47:39 Running [0098/0157]: test vbucket get missing...(80 ms) OK
|
09:47:39 Running [0099/0157]: test vbucket create...(100 ms) OK
|
09:47:39 Running [0100/0157]: test vbucket compact...(148 ms) OK
|
09:47:39 Running [0101/0157]: test compaction config...(72 ms) OK
|
09:47:39 Running [0102/0157]: test multiple vb compactions...(241 ms) OK
|
09:47:39 Running [0103/0157]: test multiple vb compactions with workload...(260 ms) OK
|
09:47:39 Running [0104/0157]: test async vbucket destroy...2021-08-20T00:38:05.335969-07:00 CRITICAL (default) MagmaKVStore::prepareToDeleteImpl vb:1 GetKVStoreRevision failed. Status:NotExists: KVStore ID:1 does not exist
|
09:47:39 (78 ms) OK
|
09:47:39 Running [0105/0157]: test sync vbucket destroy...2021-08-20T00:38:05.414077-07:00 CRITICAL (default) MagmaKVStore::prepareToDeleteImpl vb:1 GetKVStoreRevision failed. Status:NotExists: KVStore ID:1 does not exist
|
09:47:39 (75 ms) OK
|
09:47:39 Running [0106/0157]: test async vbucket destroy (multitable)...2021-08-20T00:38:05.483536-07:00 CRITICAL (default) MagmaKVStore::prepareToDeleteImpl vb:1 GetKVStoreRevision failed. Status:NotExists: KVStore ID:1 does not exist
|
09:47:39 (69 ms) OK
|
09:47:39 Running [0107/0157]: test sync vbucket destroy (multitable)...2021-08-20T00:38:05.554366-07:00 CRITICAL (default) MagmaKVStore::prepareToDeleteImpl vb:1 GetKVStoreRevision failed. Status:NotExists: KVStore ID:1 does not exist
|
09:47:39 (70 ms) OK
|
09:47:39 Running [0108/0157]: test vbucket destroy stats...(1184 ms) OK
|
09:47:39 Running [0109/0157]: test async vbucket destroy restart...(189 ms) OK
|
09:47:39 Running [0110/0157]: test sync vbucket destroy restart...(187 ms) OK
|
09:47:39 Running [0111/0157]: test takeover stats race with vbucket create (DCP)...(82 ms) OK
|
09:47:39 Running [0112/0157]: test num persisted deletes (takeover stats)...(7 ms) SKIPPED_UNDER_MAGMA
|
09:47:39 Running [0113/0157]: test stats uuid...(68 ms) OK
|
09:47:39 Running [0114/0157]: revision sequence numbers...(72 ms) OK
|
09:47:39 Running [0115/0157]: mb-4314...(71 ms) OK
|
09:47:39 Running [0116/0157]: mb-3466...(69 ms) OK
|
09:47:39 Running [0117/0157]: control data traffic...(72 ms) OK
|
09:47:39 Running [0118/0157]: multiple transactions...(115 ms) OK
|
09:47:39 Running [0119/0157]: test set ret meta...(74 ms) OK
|
09:47:39 Running [0120/0157]: test set ret meta error...2021-08-20T00:38:07.822337-07:00 CRITICAL (default) MagmaKVStore::prepareToDeleteImpl vb:1 GetKVStoreRevision failed. Status:NotExists: KVStore ID:1 does not exist
|
09:47:39 2021-08-20T00:38:07.822763-07:00 CRITICAL (default) MagmaKVStore::prepareToDeleteImpl vb:1 GetKVStoreRevision failed. Status:NotExists: KVStore ID:1 does not exist
|
09:47:39 (69 ms) OK
|
09:47:39 Running [0121/0157]: test add ret meta...(74 ms) OK
|
09:47:39 Running [0122/0157]: test add ret meta error...2021-08-20T00:38:07.964701-07:00 CRITICAL (default) MagmaKVStore::prepareToDeleteImpl vb:1 GetKVStoreRevision failed. Status:NotExists: KVStore ID:1 does not exist
|
09:47:39 2021-08-20T00:38:07.964998-07:00 CRITICAL (default) MagmaKVStore::prepareToDeleteImpl vb:1 GetKVStoreRevision failed. Status:NotExists: KVStore ID:1 does not exist
|
09:47:39 (69 ms) OK
|
09:47:39 Running [0123/0157]: test del ret meta...(75 ms) OK
|
09:47:39 Running [0124/0157]: test del ret meta error...2021-08-20T00:38:08.109346-07:00 CRITICAL (default) MagmaKVStore::prepareToDeleteImpl vb:1 GetKVStoreRevision failed. Status:NotExists: KVStore ID:1 does not exist
|
09:47:39 2021-08-20T00:38:08.109568-07:00 CRITICAL (default) MagmaKVStore::prepareToDeleteImpl vb:1 GetKVStoreRevision failed. Status:NotExists: KVStore ID:1 does not exist
|
09:47:39 (65 ms) OK
|
09:47:39 Running [0125/0157]: test set with item_eviction...(83 ms) OK
|
09:47:39 Running [0126/0157]: test set_with_meta with item_eviction...(85 ms) OK
|
09:47:39 Running [0127/0157]: test multiple set and del with meta with item_eviction...(283 ms) OK
|
09:47:39 Running [0128/0157]: test add with item_eviction...(78 ms) OK
|
09:47:39 Running [0129/0157]: test replace with eviction...(82 ms) OK
|
09:47:39 Running [0130/0157]: test replace with eviction (full)...(82 ms) OK
|
09:47:39 Running [0131/0157]: test get_and_touch with item_eviction...(76 ms) OK
|
09:47:39 Running [0132/0157]: test key_stats with item_eviction...(78 ms) OK
|
09:47:39 Running [0133/0157]: test del with item_eviction...(76 ms) OK
|
09:47:39 Running [0134/0157]: test del_with_meta with item_eviction...(77 ms) OK
|
09:47:39 Running [0135/0157]: test observe with item_eviction...(186 ms) OK
|
09:47:39 Running [0136/0157]: test expired item with item_eviction...(137 ms) OK
|
09:47:39 Running [0137/0157]: test get & delete on non existent items...(75 ms) OK
|
09:47:39 Running [0138/0157]: test MB-16421...(86 ms) OK
|
09:47:39 Running [0139/0157]: test eviction with xattr...(82 ms) OK
|
09:47:39 Running [0140/0157]: test get random key...(78 ms) OK
|
09:47:39 Running [0141/0157]: test failover log behavior...(182 ms) OK
|
09:47:39 Running [0142/0157]: test hlc cas...(75 ms) OK
|
09:47:39
|
Running [0143/0157]: multi_bucket set/get ...W0820 00:38:22.832646 44600 HazptrDomain.h:670] Using the default inline executor for asynchronous reclamation may be susceptible to deadlock if the current thread happens to hold a resource needed by the deleter of a reclaimable object
|
Major