Examples with LoggableException com.apple.foundationdb.util.LoggableException used on opensource projects

Example 1 with LoggableException

use of com.apple.foundationdb.util.LoggableException in project fdb-record-layer by FoundationDB.

the class FDBRecordStore method logExceptionAsWarn.

private void logExceptionAsWarn(KeyValueLogMessage message, Throwable exception) {
    if (exception instanceof LoggableException) {
        LoggableException loggable = (LoggableException) exception;
        LOGGER.warn(message.addKeysAndValues(loggable.getLogInfo()).toString(), loggable);
    } else {
        LOGGER.warn(message.toString(), exception);
    }
}

Example 2 with LoggableException

use of com.apple.foundationdb.util.LoggableException in project fdb-record-layer by FoundationDB.

the class FDBRecordStore method deserializeRecord.

private <M extends Message> CompletableFuture<FDBStoredRecord<M>> deserializeRecord(@Nonnull RecordSerializer<M> typedSerializer, @Nonnull final FDBRawRecord rawRecord, @Nonnull final RecordMetaData metaData, @Nonnull final Optional<CompletableFuture<FDBRecordVersion>> versionFutureOptional) {
    final Tuple primaryKey = rawRecord.getPrimaryKey();
    final byte[] serialized = rawRecord.getRawRecord();
    try {
        final M protoRecord = typedSerializer.deserialize(metaData, primaryKey, rawRecord.getRawRecord(), getTimer());
        final RecordType recordType = metaData.getRecordTypeForDescriptor(protoRecord.getDescriptorForType());
        countKeysAndValues(FDBStoreTimer.Counts.LOAD_RECORD_KEY, FDBStoreTimer.Counts.LOAD_RECORD_KEY_BYTES, FDBStoreTimer.Counts.LOAD_RECORD_VALUE_BYTES, rawRecord);
        final FDBStoredRecordBuilder<M> recordBuilder = FDBStoredRecord.newBuilder(protoRecord).setPrimaryKey(primaryKey).setRecordType(recordType).setSize(rawRecord);
        if (rawRecord.hasVersion()) {
            // In the current format version, the version should be read along with the version,
            // so this should be hit the majority of the time.
            recordBuilder.setVersion(rawRecord.getVersion());
            return CompletableFuture.completedFuture(recordBuilder.build());
        } else if (versionFutureOptional.isPresent()) {
            // another read (which has hopefully happened in parallel with the main record read in the background).
            return versionFutureOptional.get().thenApply(version -> {
                recordBuilder.setVersion(version);
                return recordBuilder.build();
            });
        } else {
            // this will return an FDBStoredRecord where the version is unset.
            return CompletableFuture.completedFuture(recordBuilder.build());
        }
    } catch (Exception ex) {
        final LoggableException ex2 = new RecordCoreException("Failed to deserialize record", ex);
        ex2.addLogInfo(subspaceProvider.logKey(), subspaceProvider.toString(context), LogMessageKeys.PRIMARY_KEY, primaryKey, LogMessageKeys.META_DATA_VERSION, metaData.getVersion());
        if (LOGGER.isDebugEnabled()) {
            ex2.addLogInfo("serialized", ByteArrayUtil2.loggable(serialized));
        }
        if (LOGGER.isTraceEnabled()) {
            ex2.addLogInfo("descriptor", metaData.getUnionDescriptor().getFile().toProto());
        }
        throw ex2;
    }
}

Example 3 with LoggableException

use of com.apple.foundationdb.util.LoggableException in project fdb-record-layer by FoundationDB.

the class TextIndexTest method backwardsRangeScanRaceCondition.

// An older implementation did reverse range scan to find the keys before and after in order
// to find where insertions should go. This was able to reproduce an error where two keys could
// be returned after the scan that were both greater than the map key due to a race condition.
// This was able to reproduce the error when run alone.
@Test
public void backwardsRangeScanRaceCondition() throws Exception {
    final Random r = new Random(0x5ca1ab1e);
    final List<String> lexicon = Arrays.asList(TextSamples.ROMEO_AND_JULIET_PROLOGUE.split(" "));
    final SimpleDocument bigDocument = getRandomRecords(r, 1, lexicon, 100, 0).get(0);
    try (FDBRecordContext context = openContext()) {
        openRecordStore(context, metaDataBuilder -> metaDataBuilder.setSplitLongRecords(true));
        LOGGER.info(KeyValueLogMessage.of("saving document", LogMessageKeys.DOCUMENT, bigDocument));
        recordStore.saveRecord(bigDocument);
        commit(context);
    }
    try (FDBRecordContext context = openContext()) {
        openRecordStore(context, metaDataBuilder -> metaDataBuilder.setSplitLongRecords(true));
        recordStore.deleteRecord(Tuple.from(bigDocument.getDocId()));
        recordStore.saveRecord(bigDocument);
    // do not commit
    } catch (RuntimeException e) {
        Throwable err = e;
        while (!(err instanceof LoggableException) && err != null) {
            err = err.getCause();
        }
        if (err != null) {
            LoggableException logE = (LoggableException) err;
            LOGGER.error(KeyValueLogMessage.build("unable to save record").addKeysAndValues(logE.getLogInfo()).toString(), err);
            throw logE;
        } else {
            throw e;
        }
    }
}

Example 4 with LoggableException

use of com.apple.foundationdb.util.LoggableException in project fdb-record-layer by FoundationDB.

the class BunchedMapTest method stressTest.

private void stressTest(final Random r, final int trTotal, final int opTotal, final int keyCount, final int workerCount, boolean addBytesToValue, AtomicLong globalTrCount, int mapCount) throws InterruptedException, ExecutionException {
    final long initialTrCount = globalTrCount.get();
    final Subspace logSubspace = DirectoryLayer.getDefault().createOrOpen(db, PathUtil.from(getClass().getName(), "log")).get();
    db.run(tr -> {
        tr.clear(bmSubspace.range());
        tr.clear(logSubspace.range());
        // If the database is empty, putting these here stop scans from hitting the log subspace within a transaction
        tr.set(logSubspace.getKey(), new byte[0]);
        tr.set(ByteArrayUtil.join(logSubspace.getKey(), new byte[] { (byte) 0xff }), new byte[0]);
        return null;
    });
    final List<CompletableFuture<Void>> workers = Stream.generate(() -> {
        int bunchSize = r.nextInt(15) + 1;
        BunchedMap<Tuple, Tuple> workerMap = new BunchedMap<>(serializer, Comparator.naturalOrder(), bunchSize);
        AtomicInteger trCount = new AtomicInteger(0);
        return AsyncUtil.whileTrue(() -> {
            final Transaction tr = db.createTransaction();
            tr.options().setDebugTransactionIdentifier("stress-tr-" + globalTrCount.getAndIncrement());
            tr.options().setLogTransaction();
            final AtomicInteger opCount = new AtomicInteger(0);
            final AtomicInteger localOrder = new AtomicInteger(0);
            return AsyncUtil.whileTrue(() -> {
                int opCode = r.nextInt(4);
                CompletableFuture<?> op;
                if (opCode == 0) {
                    // Random put
                    CompletableFuture<?>[] futures = new CompletableFuture<?>[mapCount];
                    for (int i = 0; i < mapCount; i++) {
                        if (r.nextBoolean()) {
                            Tuple key = Tuple.from(r.nextInt(keyCount));
                            Tuple value;
                            if (addBytesToValue) {
                                int byteLength = r.nextInt(5000);
                                byte[] bytes = new byte[byteLength];
                                r.nextBytes(bytes);
                                value = Tuple.from(r.nextLong(), bytes);
                            } else {
                                value = Tuple.from(r.nextLong());
                            }
                            tr.mutate(MutationType.SET_VERSIONSTAMPED_KEY, getLogKey(logSubspace, i, localOrder), Tuple.from("PUT", key, value).pack());
                            futures[i] = workerMap.put(tr, bmSubspace.subspace(Tuple.from(i)), key, value);
                        } else {
                            futures[i] = AsyncUtil.DONE;
                        }
                    }
                    op = CompletableFuture.allOf(futures);
                } else if (opCode == 1) {
                    // Read a random key.
                    int mapIndex = r.nextInt(mapCount);
                    Tuple key = Tuple.from(r.nextInt(keyCount));
                    op = workerMap.get(tr, bmSubspace.get(mapIndex), key).thenAccept(optionalValue -> tr.mutate(MutationType.SET_VERSIONSTAMPED_KEY, getLogKey(logSubspace, mapIndex, localOrder), Tuple.from("GET", key, optionalValue.orElse(null)).pack()));
                } else if (opCode == 2) {
                    // Check contains key
                    int mapIndex = r.nextInt(mapCount);
                    Tuple key = Tuple.from(r.nextInt(keyCount));
                    op = workerMap.containsKey(tr, bmSubspace.subspace(Tuple.from(mapIndex)), key).thenAccept(wasPresent -> tr.mutate(MutationType.SET_VERSIONSTAMPED_KEY, getLogKey(logSubspace, mapIndex, localOrder), Tuple.from("CONTAINS_KEY", key, wasPresent).pack()));
                } else {
                    // Remove a random key
                    int mapIndex = r.nextInt(mapCount);
                    Tuple key = Tuple.from(r.nextInt(keyCount));
                    op = workerMap.remove(tr, bmSubspace.subspace(Tuple.from(mapIndex)), key).thenAccept(oldValue -> tr.mutate(MutationType.SET_VERSIONSTAMPED_KEY, getLogKey(logSubspace, mapIndex, localOrder), Tuple.from("REMOVE", key, oldValue.orElse(null)).pack()));
                }
                return op.thenApply(ignore -> opCount.incrementAndGet() < opTotal);
            }).thenCompose(vignore -> tr.commit()).handle((vignore, err) -> {
                tr.close();
                if (err != null) {
                    FDBException fdbE = unwrapException(err);
                    if (fdbE != null) {
                        if (fdbE.getCode() != FDBError.NOT_COMMITTED.code() && fdbE.getCode() != FDBError.TRANSACTION_TOO_OLD.code()) {
                            throw fdbE;
                        }
                    } else {
                        if (err instanceof RuntimeException) {
                            throw (RuntimeException) err;
                        } else {
                            throw new RuntimeException("verification error", err);
                        }
                    }
                }
                return trCount.incrementAndGet() < trTotal;
            });
        });
    }).limit(workerCount).collect(Collectors.toList());
    final AtomicBoolean stillWorking = new AtomicBoolean(true);
    final CompletableFuture<Void> verifierWorker = AsyncUtil.whileTrue(() -> {
        Transaction tr = db.createTransaction();
        AtomicLong versionRef = new AtomicLong(-1L);
        return tr.getReadVersion().thenCompose(version -> {
            versionRef.set(version);
            // Grab the mutation list.
            AtomicInteger mapIndex = new AtomicInteger(0);
            return AsyncUtil.whileTrue(() -> {
                Subspace mapSubspace = bmSubspace.subspace(Tuple.from(mapIndex.get()));
                Subspace mapLogSubspace = logSubspace.subspace(Tuple.from(mapIndex.get()));
                CompletableFuture<List<Tuple>> logFuture = AsyncUtil.mapIterable(tr.getRange(mapLogSubspace.range()), kv -> Tuple.fromBytes(kv.getValue())).asList();
                // Verify integrity and then grab all of the keys and values.
                CompletableFuture<List<Map.Entry<Tuple, Tuple>>> contentFuture = AsyncUtil.collectRemaining(map.scan(tr, mapSubspace));
                CompletableFuture<Void> integrityFuture = map.verifyIntegrity(tr, mapSubspace);
                return integrityFuture.thenCompose(vignore -> contentFuture.thenCombine(logFuture, (mapContents, logEntries) -> {
                    Map<Tuple, Tuple> mapCopy = new TreeMap<>();
                    for (Tuple logEntry : logEntries) {
                        String op = logEntry.getString(0);
                        if (op.equals("PUT")) {
                            mapCopy.put(logEntry.getNestedTuple(1), logEntry.getNestedTuple(2));
                        } else if (op.equals("GET")) {
                            assertEquals(logEntry.getNestedTuple(2), mapCopy.get(logEntry.getNestedTuple(1)));
                        } else if (op.equals("CONTAINS_KEY")) {
                            assertEquals(logEntry.getBoolean(2), mapCopy.containsKey(logEntry.getNestedTuple(1)));
                        } else if (op.equals("REMOVE")) {
                            Tuple oldValue = mapCopy.remove(logEntry.getNestedTuple(1));
                            assertEquals(logEntry.getNestedTuple(2), oldValue);
                        } else {
                            fail("Unexpected operation " + op);
                        }
                    }
                    assertEquals(new ArrayList<>(mapCopy.entrySet()), mapContents);
                    return mapIndex.incrementAndGet() < mapCount;
                })).handle((res, err) -> {
                    // Report error information unless it was just a transaction timeout (in which case we'll retry).
                    FDBException fdbE = unwrapException(err);
                    if (err != null && (fdbE == null || fdbE.getCode() != FDBError.TRANSACTION_TOO_OLD.code())) {
                        System.err.println("Error verifying consistency: " + err);
                        err.printStackTrace();
                        List<Map.Entry<Tuple, Tuple>> contents = contentFuture.join();
                        System.err.println("Map contents:");
                        contents.forEach(entry -> System.err.println("  " + entry.getKey() + " -> " + entry.getValue()));
                        System.err.println("DB contents:");
                        List<KeyValue> rangeKVs = tr.getRange(bmSubspace.range()).asList().join();
                        rangeKVs.forEach(kv -> {
                            Tuple boundaryKey = bmSubspace.unpack(kv.getKey());
                            System.err.println("  " + boundaryKey + " -> " + serializer.deserializeEntries(boundaryKey, kv.getValue()));
                        });
                        List<Tuple> logEntries = logFuture.join();
                        System.err.println("Log contents:");
                        logEntries.forEach(logEntry -> System.err.println(" " + logEntry));
                        if (err instanceof RuntimeException) {
                            throw (RuntimeException) err;
                        } else {
                            throw new LoggableException("unable to complete consistency check", err);
                        }
                    }
                    return res;
                });
            });
        }).whenComplete((v, t) -> tr.close()).thenApply(vignore -> stillWorking.get());
    });
    AtomicInteger mapIndex = new AtomicInteger(0);
    CompletableFuture<Void> compactingWorker = AsyncUtil.whileTrue(() -> {
        AtomicReference<byte[]> continuation = new AtomicReference<>(null);
        return AsyncUtil.whileTrue(() -> map.compact(db, bmSubspace.subspace(Tuple.from(mapIndex.get())), 5, continuation.get()).thenApply(nextContinuation -> {
            continuation.set(nextContinuation);
            return nextContinuation != null;
        })).thenApply(vignore -> {
            mapIndex.getAndUpdate(oldIndex -> (oldIndex + 1) % mapCount);
            return stillWorking.get();
        });
    });
    // Wait for all workers to stop working.
    AsyncUtil.whenAll(workers).whenComplete((vignore, err) -> stillWorking.set(false)).thenAcceptBoth(verifierWorker, (vignore1, vignore2) -> {
    }).thenAcceptBoth(compactingWorker, (vignore1, vignore2) -> {
    }).whenComplete((vignore, err) -> {
        System.out.printf("Completed stress test with %d workers, %d keys, and %d transactions %s (large values=%s).%n", workerCount, keyCount, globalTrCount.get() - initialTrCount, (err == null ? "successfully" : "with an error"), addBytesToValue);
        if (err != null) {
            err.printStackTrace();
        }
        for (int i = 0; i < mapCount; i++) {
            System.out.println(" Map " + i + ":");
            Subspace mapSubspace = bmSubspace.subspace(Tuple.from(i));
            List<KeyValue> rangeKVs = inconsistentScan(db, mapSubspace);
            System.out.println("  Boundary keys: " + rangeKVs.stream().map(kv -> mapSubspace.unpack(kv.getKey())).collect(Collectors.toList()));
            System.out.println("  Boundary info:");
            rangeKVs.forEach(kv -> {
                Tuple boundaryKey = mapSubspace.unpack(kv.getKey());
                System.out.printf("    %s: %d - %s%n", boundaryKey, serializer.deserializeEntries(boundaryKey, kv.getValue()).size(), serializer.deserializeKeys(boundaryKey, kv.getValue()));
            });
        }
        int opsCount = inconsistentScan(db, logSubspace).size();
        System.out.println("  Committed ops: " + opsCount);
    }).get();
}