ValidationError string representation shows no relevant details

[bitmage]

I'm getting a ValidationError which looks like this:

ValidationError: Validation failed
  at model.Document.invalidate (.../project/node_modules/mongoose/lib/document.js:990:32)
  at .../project/node_modules/mongoose/lib/document.js:959:16
  at validate (.../project/node_modules/mongoose/lib/schematype.js:561:7)
  at .../project/node_modules/mongoose/lib/schematype.js:577:9
  at Array.forEach (native)
  at ObjectId.SchemaType.doValidate (.../project/node_modules/mongoose/lib/schematype.js:565:19)
  at .../project/node_modules/mongoose/lib/document.js:957:9
  at process._tickCallback (node.js:415:13)

The problem is there's no useful information contained in the error.

1. No lines of code in my application are mentioned.
2. It doesn't say what model failed.
3. It doesn't say what field or value failed.

I hunted down the error, and I see it has an 'errors' subobject:

ValidatorError: Path `account` is required.
  at validate (.../project/node_modules/mongoose/lib/schematype.js:610:16)
  at .../project/node_modules/mongoose/lib/schematype.js:627:9
  at Array.forEach (native)
  at ObjectId.SchemaType.doValidate (.../project/node_modules/mongoose/lib/schematype.js:614:19)
  at .../project/node_modules/mongoose/lib/document.js:956:9
  at process._tickCallback (node.js:415:13)

1. Still no mention of what model failed (account is required on a number of my models).
2. Still no mention of my application code in the stack trace.

There are a couple of things I think would be helpful:

1. Add the model name and a listing of fields that errored to the main error message. This way it will print out useful information by default, without requiring the consumer to create custom logic to pull out the details.
2. Is it possible to create a dummy error object when the initial create or save request is made, and then use the stack trace if any errors occur? Just throwing out ideas here, but anything that could show me the entry point into your library in the trace would be very helpful, as that's the line of code I actually need to change.

[bitmage]

This is really causing problems for me as I'm doing some wide spread refactorings of the models in an existing system. Pinpointing the location of failures would save me a lot of time... If anyone can suggest a way to get real stack traces out of this I'm all ears.

[vkarpov15]

@bitmage are you using .save()? Try using .validate() (docs) before .save()

[bitmage]

Using validate produces the same result. Also, I noticed that if I'm using chai, and I:

expect(err).to.not.exist

... with one of the validation errors from Mongoose, I get:

Uncaught AssertionError: expected { Object (message, name, ...) } to not exist

Most other errors from Node libraries toString() as their message and stack trace by default, which would be my desired result.

[bitmage]

I'm going to take a stab at correcting some of these issues. Would you like the changes on the 3.8.x branch or some other?

[vkarpov15]

@bitmage would be much appreciated. Changes against master branch please.

[bitmage]

@vkarpov15 Well, I got something to work, but it's a hack that involves generating an error at the entry point in order to harvest the stack trace. You can see the code here:

https://github.com/TorchlightSoftware/mongoose/compare/master

A few notes:

I first tried capturing the entry point by saving the validate function's caller:

https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Global_Objects/Function/caller

I passed that through to the ValidationError constructor and used it as the second argument for Error.captureStackTrace(). The stack came out blank. I think this is because after process.nextTick, the stack doesn't include that entry point at all, so the filtering can't work as expected. That seems consistent with the documentation for captureStackTrace:

https://code.google.com/p/v8/wiki/JavaScriptStackTraceApi

So, then I tried the method you see in the current code. I created a new error as soon as we enter the validate function. There I get a stack trace that includes my application code, but has a bunch of noise from the hooks api. Next, I used Error.captureStackTrace on the error. Strangely enough, the hook entries disappeared and it put the top line of the stack trace right on the line of code in my app that called validate().

Success! Though through a strange route...

So a few questions:

1. Is there a better way to get stack traces from before a process.nextTick? It seems very difficult with the V8/JS API.
2. Domains might solve the problem, but I don't understand them very well.
3. If there's no better way to do it, maybe we can generalize the approach so it's reusable and doesn't clutter the library.

Let me know what you think. I didn't submit a pull request because I think it still needs some work.

[vkarpov15]

Async stack traces are pretty difficult, not sure if its at all possible.

Also, I'd recommend having a sensible fallback in case captureStackTrace doesn't exist. Since mongoose validation is going to the browser, we need to be cognizant of details like captureStackTrace doesn't exist in IE.

[bitmage]

I've added some further changes to include the sub-errors in the stack trace message. Super helpful in saving time now that I have full details on what failed and where.

I'll work on incorporating a fallback as you mention, and trying for a more encapsulated solution. Will probably be a few days.

[benbuckman]

See PR -- #2364 -- I believe this fixes the reported issue.

[bitmage]

Can you show an example stack trace that you're obtaining? I'm curious as to how you got any info before the process.nextTick without explicitly capturing a stack trace at the entry point. That nextTick prevented me from seeing any application lines in the stack trace in my testing... And I think it's important to have them.

[jondavidjohn]

I think the greater issue here is that there can be multiple validation errors triggered in a single pass.

Have you attempted to inspect the err.errors object?

[jondavidjohn]

Generally the ValidationError object is just a collection of ValidatorError objects that give you a clear picture of which fields are failing.

[bitmage]

@jondavidjohn There are no relevant stack trace details in any of the err.errors objects.

[jondavidjohn]

ahh, you're looking for a stack trace to a validation error?

Seems like stack traces are most useful in situations where uncaught or unexpected errors happen, it seems like ValidationError's happen in a very specific few places and should be expected / handled.

1. Calling .validate() directly
2. Calling .save()

I don' t particularly see the benefit of the ValidationError having a stack trace, with multiple validation errors, where would you expect the stack trace to lead you?

[jondavidjohn]

I do however think, adding the model name to the original error message might be useful.

[ksikka]

Concrete example of where more information would be helpful: I wrote a job that gets data from an API and creates mongoose models out of the data. After running it, I got:

ValidationError: Client validation failed

I didn't know why it failed. I looked at the stack trace to see exactly at which line it failed - line 139 - and navigated to that line of code.

client.lastName = remoteClient.LastName;

Why would this fail? I looked at the model, lastName expects a string. It must be the case that the value assigned to the field was not a string. But then what was it? I had to run my script again with extra logging to determine it was a number.

This could have all been avoided if the error message read:

ValidationError: Client validation failed: Expected string for lastName, but got number instead.

As for multiple errors, just append (N more errors...) to the message.

Thoughts?

[wclr]

@vkarpov15

While trying saving the document get this on 4.11.6 I get nothing meaning validation error

 MongooseError:
reader_1                |     at ValidationError (/app/node_modules/mongoose/lib/error/validation.js:27:11)
reader_1                |     at model.Document.invalidate (/app/node_modules/mongoose/lib/document.js:1592:32)
reader_1                |     at _init (/app/node_modules/mongoose/lib/document.js:400:18)
reader_1                |     at init (/app/node_modules/mongoose/lib/document.js:367:7)
reader_1                |     at model.Document.init (/app/node_modules/mongoose/lib/document.js:331:3)
reader_1                |     at completeOne (/app/node_modules/mongoose/lib/query.js:1710:10)
reader_1                |     at Immediate.<anonymous> (/app/node_modules/mongoose/lib/query.js:1311:13)
reader_1                |     at Immediate.<anonymous> (/app/node_modules/mquery/lib/utils.js:137:16)
reader_1                |     at runCallback (timers.js:800:20)
reader_1                |     at tryOnImmediate (timers.js:762:5)
reader_1                |     at processImmediate [as _immediateCallback] (timers.js:733:5)

When I use .validate I get the correct error like:

 { ValidationError: User validation failed: welcomeSent: Cast to date f
ailed for value "true" at path "welcomeSent"
reader_1                |     at ValidationError.inspect (/app/node_modules/mongoose/lib/error/validation.js:57:23)
reader_1                |     at formatValue (util.js:328:36)
reader_1                |     at inspect (util.js:188:10)
reader_1                |     at exports.format (util.js:128:20)
reader_1                |     at Console.log (console.js:106:24)

Is it expected behavior? If so, I wonder why.

[vkarpov15]

@whitecolor not expected behavior. Can you open up a new issue with some code samples please?