The string for the message can cause "sprintf too few args"
brennanMKE opened this issue · 10 comments
With the message below I found that I get the sprintf too few args error. I was returning the path for a REST call which includes % signs which I expect was causing sprintf to experience this error.
Requested resource was not found: /v2/resource/1?api_key=API_KEY&append_to_response=abc%2Cxyz%2Cghz%2Cuix%2C&lang=en
If the message itself can contain the "%" character, you have to use "%s". Instead of:
new VError(str)you would use:
new VError('%s', str)You should do this any time you don't know where "str" came from or if you know it may contain "%". In your case, this may make sense:
new VError('Requested resource was not found: %s', path)@brennanMKE In my opinion is right and this behaviour should be supported and not throw error.
@davepacheco in node.js when you use console.log or util.format and pass placeholders which are not provided, it does not throw any error, it just prints the message as is.
VError/WError is different because it is using sprintf of extsprintf which will throw an error.
This is not a good choice of behaviour because it is totally different than node.js standard and thus i think it is wrong to throw an error.
I suggest that instead of using extsprintf you should just use node.js's util.format.
for now the solution that i am doing is to override extsprintf.sprintf with util.format in our lib because it is not acceptable to crash in this cases and this is not the required behaviour i expect.
var mod_extsprintf = require('extsprintf'); var util = require('util'); mod_extsprintf.sprintf = util.format;
I'm sorry this behavior breaks your programs, but the interface is working as documented and there's a correct way to use it that doesn't have this problem. Changing this interface would break other people depending on extsprintf features.
One thing we could do is try to look for the number of "%" expansions and identify whether the arguments are obviously wrong, similar to what we do already do for dealing with potentially null or defined arguments. At that point, it's looking more appealing to add a less strict mode to node-extsprintf and use that here.
That said, in the case you've got here, it really seems dangerous. What if you've mix a URL like the one you have above and also provide an argument? Wouldn't that corrupt the message?
I've also encountered such problem, and I was just about to submit a feature request, that we could use an option to disable sprintf completely.
But then then I just tried escaping a percent sign in a message and it seemed to do the exact thing so my problem was solved.
VError('Requested resource was not found: /v2/resource/1?api_key=API_KEY&append_to_response=abc%2Cxyz%2Cghz%2Cuix%2C&lang=en)'
.replace(/%/g, '%%'))In this case, I think you'd be better off using something like:
VError('Requested resource was not found: %s',
'/v2/resource/1?api_key=API_KEY&append_to_response=abc%2Cxyz%2Cghz%2Cuix%2C&lang=en')My team just got bitten by this in production. This may be documented behavior but this design decision does not follow the principle of least astonishment and has caught us completely by surprise. Having error handling code throw an error because of a % symbol is very undesirable and has made it very difficult for us to work out what is going wrong. I strongly recommend revisiting this design decision or at a minimum create a simple way to disable this behavior in a global way.
@BenSayers, I'm sorry to hear about the production issue. I've had that happen as well -- I know it's frustrating.
That said, for many of us that use VError, the current behavior is the least surprising. Personally, I would find it far more surprising (and frustrating) if the implementation allowed '%' to be ambiguous and attempted to infer what was meant. That approach can be wrong, too -- but it would result in an implicit, non-fatal failure rather than an explicit, fatal failure. Because many of us use --abort-on-uncaught-exception and debug from the core files, fatal failures tend to be far easier to debug. In this case, we'd be virtually guaranteed to root-cause the bug in VError caller right away from the core file. If another bug caused the underlying error in the first place (as I've often found when this case comes up), there's a good chance that we'd be able to debug that, too, since we'd have a core file from precisely the moment of the failure.
On the other hand, if the implementation tried to guess what you meant and got it wrong, it might produce a subtly (but critically) incorrect error message, like reporting the wrong URL that was accessed. It would be hard to know you'd even hit that bug, and it could be extremely time-consuming to track it down (since people typically exhaust other options before guessing that an error message itself was just wrong).
So there's a tradeoff here. We made this choice intentionally, and it works well for us. Of course, I understand that it might not be right for everybody.
It sounds like you spent a lot of time debugging the underlying issue. If you're not using core files, I can see that you might not have enough information in the exception to know what the problem was.
How much would it have helped if sprintf itself had reported more information about the problem, like too few arguments for format string "$format_string": could not find match for '%' formatter at character $position?
We are not using core files or the templating feature provided by VError. I can see how ambiguous % symbols might cause an incorrect error message for those who are using the templating feature however for those who are not this behaviour of throwing an exception provides no value or benefit, which is why I recommended providing a way to globally opt out.
The reason debugging the underlying issue took us so long is VError is masking the underlying exception that led to the situation. If you surfaced this underlying error details as part of the error that is thrown that would have significantly improved the situation.