diff --git a/changelog/unreleased/SOLR-16155-no-field-values-in-update-errors.yml b/changelog/unreleased/SOLR-16155-no-field-values-in-update-errors.yml new file mode 100644 index 000000000000..df880fdc6879 --- /dev/null +++ b/changelog/unreleased/SOLR-16155-no-field-values-in-update-errors.yml @@ -0,0 +1,7 @@ +title: Document construction and javabin add error messages omit field values and document contents, retaining the document id and field name where available. Value-bearing causes are omitted from these exceptions so ordinary error logs and response traces do not expose them; conversion and javabin failure details are available at TRACE level instead. +type: changed +authors: + - name: Nick Shanin +links: + - name: SOLR-16155 + url: https://issues.apache.org/jira/browse/SOLR-16155 diff --git a/solr/core/src/java/org/apache/solr/handler/loader/JavabinLoader.java b/solr/core/src/java/org/apache/solr/handler/loader/JavabinLoader.java index 23ad278d4918..4ae81aadd3b1 100644 --- a/solr/core/src/java/org/apache/solr/handler/loader/JavabinLoader.java +++ b/solr/core/src/java/org/apache/solr/handler/loader/JavabinLoader.java @@ -19,6 +19,7 @@ import java.io.EOFException; import java.io.IOException; import java.io.InputStream; +import java.lang.invoke.MethodHandles; import java.util.List; import java.util.Map; import java.util.Map.Entry; @@ -38,9 +39,12 @@ import org.apache.solr.common.util.NamedList; import org.apache.solr.request.SolrQueryRequest; import org.apache.solr.response.SolrQueryResponse; +import org.apache.solr.schema.SchemaField; import org.apache.solr.update.AddUpdateCommand; import org.apache.solr.update.DeleteUpdateCommand; import org.apache.solr.update.processor.UpdateRequestProcessor; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; /** * Update handler which uses the JavaBin format @@ -49,6 +53,8 @@ * @see org.apache.solr.common.util.JavaBinCodec */ public class JavabinLoader extends ContentStreamLoader { + private static final Logger log = LoggerFactory.getLogger(MethodHandles.lookup().lookupClass()); + final ContentStreamLoader contentStreamLoader; public JavabinLoader() { @@ -122,8 +128,12 @@ public void update( processor.processAdd(addCmd); addCmd.clear(); } catch (IOException e) { + if (log.isTraceEnabled()) { + log.trace("Error adding document {}", document, e); + } throw new SolrException( - SolrException.ErrorCode.SERVER_ERROR, "ERROR adding document " + document, e); + SolrException.ErrorCode.SERVER_ERROR, + "ERROR adding document" + describeDocument(req, document)); } } }; @@ -141,6 +151,15 @@ public void update( } } + /** The document's unique key for an error message, without any other field values. */ + private static String describeDocument(SolrQueryRequest req, SolrInputDocument document) { + SchemaField uniqueKeyField = req.getSchema().getUniqueKeyField(); + if (uniqueKeyField == null) { + return ""; + } + return " [doc=" + document.getFieldValue(uniqueKeyField.getName()) + "]"; + } + @SuppressWarnings( "ReferenceEquality") // END_OBJ is a unique sentinel; identity check is intentional private void handleMultiStream( diff --git a/solr/core/src/java/org/apache/solr/schema/DenseVectorField.java b/solr/core/src/java/org/apache/solr/schema/DenseVectorField.java index e06dfa6127b1..4c570e0ce01f 100644 --- a/solr/core/src/java/org/apache/solr/schema/DenseVectorField.java +++ b/solr/core/src/java/org/apache/solr/schema/DenseVectorField.java @@ -368,10 +368,11 @@ public List createFields(SchemaField field, Object value) { } return fields; } catch (RuntimeException e) { + if (log.isTraceEnabled()) { + log.trace("Error while creating field '{}' from value '{}'", field, value, e); + } throw new SolrException( - SolrException.ErrorCode.SERVER_ERROR, - "Error while creating field '" + field + "' from value '" + value + "'", - e); + SolrException.ErrorCode.SERVER_ERROR, "Error while creating field '" + field + "'"); } } diff --git a/solr/core/src/java/org/apache/solr/schema/FieldType.java b/solr/core/src/java/org/apache/solr/schema/FieldType.java index ce4dc99d92a3..6862feb72434 100644 --- a/solr/core/src/java/org/apache/solr/schema/FieldType.java +++ b/solr/core/src/java/org/apache/solr/schema/FieldType.java @@ -306,10 +306,11 @@ public IndexableField createField(SchemaField field, Object value) { } catch (SolrException se) { throw se; // BAD_REQUEST to fall through } catch (RuntimeException e) { + if (log.isTraceEnabled()) { + log.trace("Error while creating field '{}' from value '{}'", field, value, e); + } throw new SolrException( - SolrException.ErrorCode.SERVER_ERROR, - "Error while creating field '" + field + "' from value '" + value + "'", - e); + SolrException.ErrorCode.SERVER_ERROR, "Error while creating field '" + field + "'"); } if (val == null) return null; diff --git a/solr/core/src/java/org/apache/solr/schema/RankField.java b/solr/core/src/java/org/apache/solr/schema/RankField.java index 0bb1b09db193..a794abab09ff 100644 --- a/solr/core/src/java/org/apache/solr/schema/RankField.java +++ b/solr/core/src/java/org/apache/solr/schema/RankField.java @@ -17,6 +17,7 @@ package org.apache.solr.schema; import java.io.IOException; +import java.lang.invoke.MethodHandles; import java.util.Map; import org.apache.lucene.document.FeatureField; import org.apache.lucene.index.IndexableField; @@ -30,6 +31,8 @@ import org.apache.solr.search.QParser; import org.apache.solr.search.RankQParserPlugin; import org.apache.solr.uninverting.UninvertingReader.Type; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; /** * {@code RankField}s can be used to store scoring factors to improve document ranking. They should @@ -59,6 +62,8 @@ */ public class RankField extends FieldType { + private static final Logger log = LoggerFactory.getLogger(MethodHandles.lookup().lookupClass()); + /* * While the user can create multiple RankFields, internally we use a single Lucene field, * and we map the Solr field name to the "feature" in Lucene's FeatureField. This is mainly @@ -109,10 +114,12 @@ protected IndexableField createField(String name, String val, IndexableFieldType try { featureValue = Float.parseFloat(val); } catch (NumberFormatException nfe) { + if (log.isTraceEnabled()) { + log.trace("Error while creating field '{}' from value '{}'", name, val, nfe); + } throw new SolrException( SolrException.ErrorCode.BAD_REQUEST, - "Error while creating field '" + name + "' from value '" + val + "'. Expecting float.", - nfe); + "Error while creating field '" + name + "'. Expecting float."); } // Internally, we always use the same field return new FeatureField(INTERNAL_RANK_FIELD_NAME, name, featureValue); diff --git a/solr/core/src/java/org/apache/solr/schema/StrFloatLateInteractionVectorField.java b/solr/core/src/java/org/apache/solr/schema/StrFloatLateInteractionVectorField.java index f80b6cbea54b..f4f0c07fd6df 100644 --- a/solr/core/src/java/org/apache/solr/schema/StrFloatLateInteractionVectorField.java +++ b/solr/core/src/java/org/apache/solr/schema/StrFloatLateInteractionVectorField.java @@ -209,10 +209,11 @@ public List createFields(SchemaField field, Object value) { return fields; } catch (SyntaxError | RuntimeException e) { + if (log.isTraceEnabled()) { + log.trace("Error while creating field '{}' from value '{}'", field, value, e); + } throw new SolrException( - SolrException.ErrorCode.SERVER_ERROR, - "Error while creating field '" + field + "' from value '" + value + "'", - e); + SolrException.ErrorCode.SERVER_ERROR, "Error while creating field '" + field + "'"); } } diff --git a/solr/core/src/java/org/apache/solr/update/DocumentBuilder.java b/solr/core/src/java/org/apache/solr/update/DocumentBuilder.java index 390d86161812..202ca2c44809 100644 --- a/solr/core/src/java/org/apache/solr/update/DocumentBuilder.java +++ b/solr/core/src/java/org/apache/solr/update/DocumentBuilder.java @@ -16,6 +16,7 @@ */ package org.apache.solr.update; +import java.lang.invoke.MethodHandles; import java.util.ArrayList; import java.util.HashSet; import java.util.Iterator; @@ -34,14 +35,17 @@ import org.apache.solr.schema.FieldType; import org.apache.solr.schema.IndexSchema; import org.apache.solr.schema.SchemaField; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; /** Builds a Lucene {@link Document} from a {@link SolrInputDocument}. */ public class DocumentBuilder { + private static final Logger log = LoggerFactory.getLogger(MethodHandles.lookup().lookupClass()); + // accessible only for tests static int MIN_LENGTH_TO_MOVE_LAST = Integer.getInteger("solr.docBuilder.minLengthToMoveLast", 4 * 1024); // internal setting - static int MAX_VALUES_AS_STRING_LENGTH = 256; /** * Add a field value to a given document. @@ -93,6 +97,18 @@ private static String getID(SolrInputDocument doc, IndexSchema schema) { return id; } + private static String getFieldErrorMessage( + SolrInputDocument doc, IndexSchema schema, String fieldName) { + return "ERROR: " + getID(doc, schema) + "Error adding field '" + fieldName + "'"; + } + + /** The error message omits field values, so keep them available for debugging at TRACE. */ + private static void traceFieldError(String message, SolrInputField field, Exception ex) { + if (log.isTraceEnabled()) { + log.trace("{}: value={}", message, field.getValue(), ex); + } + } + /** * @see DocumentBuilder#toDocument(SolrInputDocument, IndexSchema, boolean, boolean) */ @@ -163,21 +179,12 @@ public static Document toDocument( && field.getValueCount() > 1 && !(sfield.getType() instanceof DenseVectorField)) { - // Ensure we do not flood the logs with extremely long values - String fieldValue = field.getValue().toString(); - if (fieldValue.length() > MAX_VALUES_AS_STRING_LENGTH) { - assert fieldValue.endsWith("]"); - fieldValue = fieldValue.substring(0, MAX_VALUES_AS_STRING_LENGTH - 4) + "...]"; - } - throw new SolrException( SolrException.ErrorCode.BAD_REQUEST, "ERROR: " + getID(doc, schema) + "multiple values encountered for non multiValued field " - + sfield.getName() - + ": " - + fieldValue); + + sfield.getName()); } List copyFields = schema.getCopyFieldsList(name); @@ -272,29 +279,14 @@ public static Document toDocument( } } } catch (SolrException ex) { - throw new SolrException( - SolrException.ErrorCode.getErrorCode(ex.code()), - "ERROR: " - + getID(doc, schema) - + "Error adding field '" - + field.getName() - + "'='" - + field.getValue() - + "' msg=" - + ex.getMessage(), - ex); + String message = getFieldErrorMessage(doc, schema, name); + traceFieldError(message, field, ex); + // Causes can contain field values and are logged and serialized by request handlers. + throw new SolrException(SolrException.ErrorCode.getErrorCode(ex.code()), message); } catch (Exception ex) { - throw new SolrException( - SolrException.ErrorCode.BAD_REQUEST, - "ERROR: " - + getID(doc, schema) - + "Error adding field '" - + field.getName() - + "'='" - + field.getValue() - + "' msg=" - + ex.getMessage(), - ex); + String message = getFieldErrorMessage(doc, schema, name); + traceFieldError(message, field, ex); + throw new SolrException(SolrException.ErrorCode.BAD_REQUEST, message); } // make sure the field was used somehow... @@ -376,9 +368,7 @@ private static boolean addCopyFields( throw new SolrException( SolrException.ErrorCode.BAD_REQUEST, "Multiple values encountered for non multiValued copy field " - + destinationField.getName() - + ": " - + originalFieldValue); + + destinationField.getName()); } Object fieldValue = originalFieldValue; // Perhaps trim the length of a copy field diff --git a/solr/core/src/test/org/apache/solr/handler/loader/JavabinLoaderTest.java b/solr/core/src/test/org/apache/solr/handler/loader/JavabinLoaderTest.java index 66ac7c724db4..078b05c456f7 100644 --- a/solr/core/src/test/org/apache/solr/handler/loader/JavabinLoaderTest.java +++ b/solr/core/src/test/org/apache/solr/handler/loader/JavabinLoaderTest.java @@ -17,6 +17,8 @@ package org.apache.solr.handler.loader; import java.io.ByteArrayOutputStream; +import java.io.IOException; +import java.lang.invoke.MethodHandles; import java.util.ArrayList; import java.util.Arrays; import java.util.List; @@ -24,16 +26,27 @@ import org.apache.solr.client.solrj.embedded.EmbeddedSolrServer; import org.apache.solr.client.solrj.request.JavaBinUpdateRequestCodec; import org.apache.solr.client.solrj.request.UpdateRequest; +import org.apache.solr.common.SolrException; import org.apache.solr.common.SolrInputDocument; import org.apache.solr.common.util.ContentStreamBase; +import org.apache.solr.common.util.NamedList; +import org.apache.solr.common.util.Utils; import org.apache.solr.request.SolrQueryRequest; import org.apache.solr.response.SolrQueryResponse; +import org.apache.solr.servlet.ResponseUtils; import org.apache.solr.update.AddUpdateCommand; import org.apache.solr.update.processor.BufferingRequestProcessor; +import org.apache.solr.update.processor.UpdateRequestProcessor; +import org.apache.solr.util.LogLevel; +import org.apache.solr.util.LogListener; import org.junit.BeforeClass; import org.junit.Test; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; public class JavabinLoaderTest extends SolrTestCaseJ4 { + private static final Logger log = LoggerFactory.getLogger(MethodHandles.lookup().lookupClass()); + @BeforeClass public static void beforeTests() throws Exception { initCore("solrconfig.xml", "schema.xml"); @@ -115,4 +128,69 @@ public void javabinLoader_denseVector_shouldIndexCorrectly() throws Exception { "//result/doc[1]/arr[@name=\"vector\"]/float[3][.='" + 3.4 + "']", "//result/doc[1]/arr[@name=\"vector\"]/float[4][.='" + 4.4 + "']"); } + + @Test + @LogLevel("org.apache.solr.handler.loader.JavabinLoader=INFO") + public void testIOExceptionDoesNotLeakDocumentContents() throws Exception { + SolrInputDocument doc = new SolrInputDocument(); + doc.addField("id", "7"); + doc.addField("name", "secret customer value"); + + UpdateRequest updateRequest = new UpdateRequest(); + updateRequest.add(doc); + + ByteArrayOutputStream os = new ByteArrayOutputStream(); + new JavaBinUpdateRequestCodec().marshal(updateRequest, os); + + UpdateRequestProcessor failingProcessor = + new BufferingRequestProcessor(null) { + @Override + public void processAdd(AddUpdateCommand cmd) throws IOException { + throw new IOException("simulated failure for secret customer value"); + } + }; + + SolrQueryRequest req = req(); + try { + SolrException ex = + expectThrows( + SolrException.class, + () -> + new JavabinLoader() + .load( + req, + new SolrQueryResponse(), + new ContentStreamBase.ByteArrayStream(os.toByteArray(), "test"), + failingProcessor)); + assertEquals("ERROR adding document [doc=7]", ex.getMessage()); + assertFalse(ex.getMessage().contains("secret customer value")); + assertEquals(500, ex.code()); + + try (LogListener errors = + LogListener.error(JavabinLoader.class).substring("ERROR adding document [doc=7]"); + LogListener leakedValues = + LogListener.error(JavabinLoader.class).substring("secret customer value")) { + var logger = LoggerFactory.getLogger(JavabinLoader.class); + NamedList errorInfo = new NamedList<>(); + assertEquals(500, ResponseUtils.getErrorInfo(ex, errorInfo, logger, false)); + assertNotNull( + "Exercise response traces, not just the outer message", errorInfo.get("trace")); + assertFalse(Utils.toJSONString(errorInfo).contains("secret customer value")); + var typedErrorInfo = ResponseUtils.getTypedErrorInfo(ex, logger, false); + assertNotNull(typedErrorInfo.trace); + assertFalse(Utils.toJSONString(typedErrorInfo).contains("secret customer value")); + assertEquals(2, errors.getCount()); + int leakedValueCount = leakedValues.getCount(); + assertEquals("500 Exception", errors.pollMessage()); + assertEquals("500 Exception", errors.pollMessage()); + while (leakedValues.pollMessage() != null) { + // Drain matches before asserting to avoid close-time secondary failures. + } + assertEquals("Sensitive value present in ERROR log", 0, leakedValueCount); + } + assertNull(ex.getCause()); + } finally { + req.close(); + } + } } diff --git a/solr/core/src/test/org/apache/solr/schema/DenseVectorFieldTest.java b/solr/core/src/test/org/apache/solr/schema/DenseVectorFieldTest.java index 3160b4561150..30769fca8a44 100644 --- a/solr/core/src/test/org/apache/solr/schema/DenseVectorFieldTest.java +++ b/solr/core/src/test/org/apache/solr/schema/DenseVectorFieldTest.java @@ -21,6 +21,7 @@ import java.io.ByteArrayOutputStream; import java.util.ArrayList; import java.util.Arrays; +import java.util.HashMap; import java.util.List; import java.util.Map; import org.apache.lucene.index.VectorEncoding; @@ -726,14 +727,8 @@ public void denseVectorByteEncoding_shouldRaiseExceptionWithValuesOutsideBoundar }); assertThat( - thrown.getCause().getMessage(), - is( - "Error while creating field 'vector_byte_encoding{type=knn_vector_byte_encoding,properties=indexed,stored,omitNorms,omitTermFreqAndPositions,useDocValuesAsStored}' from value '[128, 6, 7, 8]'")); - - assertThat( - thrown.getCause().getCause().getMessage(), - is( - "incorrect vector element: '128'. The expected format is:'[b1,b2..b3]' where each element b is a byte (-128 to 127)")); + thrown.getMessage(), is("ERROR: [doc=0] Error adding field 'vector_byte_encoding'")); + assertNull(thrown.getCause()); SolrInputDocument doc1 = new SolrInputDocument(); doc1.addField("id", "1"); @@ -748,13 +743,62 @@ public void denseVectorByteEncoding_shouldRaiseExceptionWithValuesOutsideBoundar }); assertThat( - thrown.getCause().getMessage(), - is( - "Error while creating field 'vector_byte_encoding{type=knn_vector_byte_encoding,properties=indexed,stored,omitNorms,omitTermFreqAndPositions,useDocValuesAsStored}' from value '[1, -129, 7, 8]'")); + thrown.getMessage(), is("ERROR: [doc=1] Error adding field 'vector_byte_encoding'")); + assertNull(thrown.getCause()); + } finally { + deleteCore(); + } + } + + @Test + public void fieldTypeCreateFieldErrorDoesNotLeakFieldValue() throws Exception { + try { + initCore("solrconfig.xml", "schema-densevector.xml"); + IndexSchema schema = h.getCore().getLatestSchema(); + // A field type whose conversion fails with a RuntimeException, so the failure surfaces + // through FieldType.createField's error wrapping. + FieldType failingType = + new StrField() { + @Override + public String toInternal(String val) { + throw new IllegalArgumentException("cannot convert: " + val); + } + }; + failingType.init(schema, new HashMap<>()); + SchemaField field = + new SchemaField( + "failing_field", failingType, FieldProperties.INDEXED | FieldProperties.STORED, null); + SolrException thrown = + assertThrows( + "A failing conversion should throw an exception", + SolrException.class, + () -> failingType.createField(field, "secret-value")); + assertTrue(thrown.getMessage().contains("Error while creating field")); + assertFalse(thrown.getMessage().contains("secret-value")); + assertEquals(500, thrown.code()); + assertNull(thrown.getCause()); + } finally { + deleteCore(); + } + } + + @Test + public void denseVectorCreateFieldsErrorDoesNotLeakFieldValue() throws Exception { + try { + initCore("solrconfig.xml", "schema-densevector.xml"); + SolrInputDocument doc = new SolrInputDocument(); + doc.addField("id", "0"); + doc.addField("vector_byte_encoding", Arrays.asList(128, 6, 7, 8)); + RuntimeException thrown = + assertThrows( + "Incorrect elements should throw an exception", + SolrException.class, + () -> { + assertU(adoc(doc)); + }); assertThat( - thrown.getCause().getCause().getMessage(), - is( - "incorrect vector element: '-129'. The expected format is:'[b1,b2..b3]' where each element b is a byte (-128 to 127)")); + thrown.getMessage(), is("ERROR: [doc=0] Error adding field 'vector_byte_encoding'")); + assertNull(thrown.getCause()); } finally { deleteCore(); } @@ -777,14 +821,8 @@ public void denseVectorByteEncoding_shouldRaiseExceptionWithFloatValues() throws }); assertThat( - thrown.getCause().getMessage(), - is( - "Error while creating field 'vector_byte_encoding{type=knn_vector_byte_encoding,properties=indexed,stored,omitNorms,omitTermFreqAndPositions,useDocValuesAsStored}' from value '[14.3, 6.2, 7.2, 8.1]'")); - - assertThat( - thrown.getCause().getCause().getMessage(), - is( - "incorrect vector element: '14.3'. The expected format is:'[b1,b2..b3]' where each element b is a byte (-128 to 127)")); + thrown.getMessage(), is("ERROR: [doc=0] Error adding field 'vector_byte_encoding'")); + assertNull(thrown.getCause()); } finally { deleteCore(); } diff --git a/solr/core/src/test/org/apache/solr/schema/RankFieldTest.java b/solr/core/src/test/org/apache/solr/schema/RankFieldTest.java index 2a127c5441b0..5155f6954dd4 100644 --- a/solr/core/src/test/org/apache/solr/schema/RankFieldTest.java +++ b/solr/core/src/test/org/apache/solr/schema/RankFieldTest.java @@ -22,6 +22,7 @@ import org.apache.lucene.index.LeafReader; import org.apache.lucene.util.BytesRef; import org.apache.solr.SolrTestCaseJ4; +import org.apache.solr.common.SolrException; import org.apache.solr.common.params.ModifiableSolrParams; import org.apache.solr.handler.RequestHandlerBase; import org.apache.solr.util.LogListener; @@ -59,9 +60,22 @@ public void testBasic() { RankField.class, h.getCore().getLatestSchema().getField(RANK_1).getType().getClass()); } + public void testCreateFieldErrorDoesNotLeakFieldValue() { + RankField type = (RankField) h.getCore().getLatestSchema().getField(RANK_1).getType(); + SolrException ex = + expectThrows( + SolrException.class, () -> type.createField(RANK_1, "not-a-float-secret", null)); + assertTrue(ex.getMessage().contains("Error while creating field '" + RANK_1 + "'")); + assertTrue(ex.getMessage().contains("Expecting float.")); + assertFalse(ex.getMessage().contains("not-a-float-secret")); + assertEquals(400, ex.code()); + assertNull(ex.getCause()); + } + public void testBadFormat() { try (LogListener errors = - LogListener.error(RequestHandlerBase.class).substring("Expecting float")) { + LogListener.error(RequestHandlerBase.class) + .substring("Error adding field '" + RANK_1 + "'")) { assertFailedU(adoc("id", "1", RANK_1, "foo")); assertFailedU(adoc("id", "1", RANK_1, "1.2.3")); @@ -70,7 +84,8 @@ public void testBadFormat() { } try (LogListener errors = - LogListener.error(RequestHandlerBase.class).substring("must be finite")) { + LogListener.error(RequestHandlerBase.class) + .substring("Error adding field '" + RANK_1 + "'")) { assertFailedU(adoc("id", "1", RANK_1, Float.toString(Float.POSITIVE_INFINITY))); assertFailedU(adoc("id", "1", RANK_1, Float.toString(Float.NEGATIVE_INFINITY))); @@ -81,7 +96,8 @@ public void testBadFormat() { } try (LogListener errors = - LogListener.error(RequestHandlerBase.class).substring("must be a positive")) { + LogListener.error(RequestHandlerBase.class) + .substring("Error adding field '" + RANK_1 + "'")) { assertFailedU(adoc("id", "1", RANK_1, Float.toString(-0.0f))); assertFailedU(adoc("id", "1", RANK_1, Float.toString(-1f))); diff --git a/solr/core/src/test/org/apache/solr/update/DocumentBuilderTest.java b/solr/core/src/test/org/apache/solr/update/DocumentBuilderTest.java index 80ecd512e1c9..9a270937c38b 100644 --- a/solr/core/src/test/org/apache/solr/update/DocumentBuilderTest.java +++ b/solr/core/src/test/org/apache/solr/update/DocumentBuilderTest.java @@ -36,7 +36,10 @@ import org.apache.solr.common.SolrInputField; import org.apache.solr.common.util.ByteArrayUtf8CharSequence; import org.apache.solr.core.SolrCore; +import org.apache.solr.handler.RequestHandlerBase; import org.apache.solr.schema.FieldType; +import org.apache.solr.util.LogLevel; +import org.apache.solr.util.LogListener; import org.junit.After; import org.junit.AfterClass; import org.junit.BeforeClass; @@ -104,13 +107,93 @@ public void testExceptions() { expectThrows( Exception.class, () -> DocumentBuilder.toDocument(doc, core.getLatestSchema())); assertTrue("should have document ID", ex.getMessage().indexOf("doc=123") > 0); - assertTrue("cause is number format", ex.getCause() instanceof NumberFormatException); + assertNull("value-bearing parse errors must not escape through causes", ex.getCause()); // now make sure it is OK doc.setField("weight", "1.34"); DocumentBuilder.toDocument(doc, core.getLatestSchema()); } + @Test + public void testExceptionMessagesDoNotLeakFieldValues() { + SolrCore core = h.getCore(); + + SolrInputDocument doc = new SolrInputDocument(); + doc.addField("id", "123"); + doc.addField("weight", "not-a-number-secret"); + SolrException ex = + expectThrows( + SolrException.class, () -> DocumentBuilder.toDocument(doc, core.getLatestSchema())); + assertTrue(ex.getMessage().contains("Error adding field 'weight'")); + assertFalse(ex.getMessage().contains("not-a-number-secret")); + assertEquals(400, ex.code()); + assertNull(ex.getCause()); + + SolrInputDocument multiValueDoc = new SolrInputDocument(); + multiValueDoc.addField("id", "456"); + multiValueDoc.addField("weight", "secret-one"); + multiValueDoc.addField("weight", "secret-two"); + SolrException multiValueEx = + expectThrows( + SolrException.class, + () -> DocumentBuilder.toDocument(multiValueDoc, core.getLatestSchema())); + assertTrue( + multiValueEx + .getMessage() + .contains("multiple values encountered for non multiValued field weight")); + assertFalse(multiValueEx.getMessage().contains("secret-one")); + assertFalse(multiValueEx.getMessage().contains("secret-two")); + } + + @Test + @LogLevel("org.apache.solr.update.DocumentBuilder=INFO") + public void testFailedUpdateDoesNotLogFieldValue() { + try (LogListener errors = + LogListener.error(RequestHandlerBase.class).substring("Error adding field 'weight'"); + LogListener leakedValues = + LogListener.error(RequestHandlerBase.class).substring("not-a-number-secret"); + LogListener documentIds = + LogListener.error(RequestHandlerBase.class).substring("[doc=123]")) { + assertFailedU(adoc("id", "123", "weight", "not-a-number-secret")); + assertEquals(1, errors.getCount()); + assertEquals(1, documentIds.getCount()); + String message = errors.pollMessage(); + assertNotNull(message); + assertFalse(message.contains("not-a-number-secret")); + assertNotNull(documentIds.pollMessage()); + int leakedValueCount = leakedValues.getCount(); + while (leakedValues.pollMessage() != null) { + // Drain matches before asserting to avoid close-time secondary failures. + } + assertEquals("Sensitive value present in ERROR log", 0, leakedValueCount); + } + } + + @Test + @LogLevel("org.apache.solr.update.DocumentBuilder=TRACE") + public void testFieldErrorDetailsAreAvailableAtTrace() { + try (LogListener valueTraces = + LogListener.trace(DocumentBuilder.class).substring("not-a-number-secret"); + LogListener exceptionTraces = + LogListener.trace(DocumentBuilder.class) + .substring(NumberFormatException.class.getName())) { + SolrInputDocument doc = new SolrInputDocument(); + doc.addField("id", "123"); + doc.addField("weight", "not-a-number-secret"); + SolrException ex = + expectThrows( + SolrException.class, + () -> DocumentBuilder.toDocument(doc, h.getCore().getLatestSchema())); + assertNull(ex.getCause()); + assertEquals(1, valueTraces.getCount()); + assertEquals(1, exceptionTraces.getCount()); + String traceMessage = valueTraces.pollMessage(); + assertNotNull(traceMessage); + assertTrue(traceMessage.contains("not-a-number-secret")); + assertNotNull(exceptionTraces.pollMessage()); + } + } + @Test public void testMultiField() { SolrCore core = h.getCore(); @@ -417,10 +500,7 @@ public void denseVector_incorrectCopyFieldDestinationType_shouldThrowException() () -> { DocumentBuilder.toDocument(doc, core.getLatestSchema()); }); - assertThat( - thrown.getMessage(), - is( - "ERROR: [doc=0] Error adding field 'vector3'='[1.1, 2.1, 3.1, 4.1]' msg=The copy field destination must be a DenseVectorField: vector_f_p")); + assertThat(thrown.getMessage(), is("ERROR: [doc=0] Error adding field 'vector3'")); } @Test @@ -438,13 +518,7 @@ public void denseVector_incorrectCopyFieldDestinationDimension_shouldThrowExcept () -> { DocumentBuilder.toDocument(doc, core.getLatestSchema()); }); - assertThat( - thrown.getMessage(), - is( - "ERROR: [doc=0] Error adding field 'vector4'='[1.1, 2.1, 3.1, 4.1]' msg=Error while creating field 'vector5{type=knn_vector5,properties=indexed,stored}' from value '[1.1, 2.1, 3.1, 4.1]'")); - assertThat( - thrown.getCause().getCause().getMessage(), - is( - "incorrect vector dimension. The vector value has size 4 while it is expected a vector with size 5")); + assertThat(thrown.getMessage(), is("ERROR: [doc=0] Error adding field 'vector4'")); + assertNull(thrown.getCause()); } } diff --git a/solr/core/src/test/org/apache/solr/update/processor/TolerantUpdateProcessorTest.java b/solr/core/src/test/org/apache/solr/update/processor/TolerantUpdateProcessorTest.java index f87d1b2d260a..b2f4bc93799a 100644 --- a/solr/core/src/test/org/apache/solr/update/processor/TolerantUpdateProcessorTest.java +++ b/solr/core/src/test/org/apache/solr/update/processor/TolerantUpdateProcessorTest.java @@ -237,10 +237,8 @@ public void testMaxErrorsThrowsException() { assertAddsSucceedWithErrors( "tolerant-chain-max-errors-not-set", docs, requestParams, badIds)); assertTrue( - e.getMessage(), - e.getMessage() - .contains( - "ERROR: [doc=1] Error adding field 'weight'='b' msg=For input string: \"b\"")); + e.getMessage(), e.getMessage().contains("ERROR: [doc=1] Error adding field 'weight'")); + assertFalse(e.getMessage(), e.getMessage().contains("'b'")); // the first good documents made it to the index assertU(commit()); assertQ(req("q", "*:*"), "//result[@numFound='6']"); @@ -269,10 +267,8 @@ public void testMaxErrors0() { () -> assertAddsSucceedWithErrors( "tolerant-chain-max-errors-10", smallBatch, requestParams, "1")); - assertTrue( - e.getMessage() - .contains( - "ERROR: [doc=1] Error adding field 'weight'='b' msg=For input string: \"b\"")); + assertTrue(e.getMessage().contains("ERROR: [doc=1] Error adding field 'weight'")); + assertFalse(e.getMessage(), e.getMessage().contains("'b'")); // the first good documents made it to the index assertU(commit()); diff --git a/solr/test-framework/src/java/org/apache/solr/util/LogListener.java b/solr/test-framework/src/java/org/apache/solr/util/LogListener.java index 5de956d6b434..4299d6efb871 100644 --- a/solr/test-framework/src/java/org/apache/solr/util/LogListener.java +++ b/solr/test-framework/src/java/org/apache/solr/util/LogListener.java @@ -161,6 +161,11 @@ public static LogListener debug(final String logger) { return create(Level.DEBUG, logger); } + /** Listens for TRACE log messages for the specified logger */ + public static LogListener trace(final Class logger) { + return create(Level.TRACE, logger.getName()); + } + // TODO: more factories for other levels? private static LogListener create(final Level level, final String logger) {