pulsar-admin should print better error message when schema is invalid
- Dominant language
- Java
- Stars
- 15.3k
- Forks
- 3.8k
- Avg merge
- 1d 22h
- Merged PRs (30d)
- 142
Description
**Is your enhancement request related to a problem? Please describe.**
Currently, pulsar-admin will sometimes output useful error messages and sometimes not. When it outputs a 500 Internal Server Error with no server-side error logged, Pulsar users often cannot figure out the reason and come to Slack for help.
There were 3 users who asked for help recently on Slack:
* https://apache-pulsar.slack.com/archives/C5Z4T36F7/p1617029453234900?thread_ts=1617029453.234900
* https://apache-pulsar.slack.com/archives/C5Z4T36F7/p1621333536003100?thread_ts=1621333536.003100
* https://apache-pulsar.slack.com/archives/C5Z4T36F7/p1621338997004100?thread_ts=1617029453.234900&cid=C5Z4T36F7
I encountered this problem as well, and it took me a while to figure out the problem. Exacerbating the problem is the fact that a documented example from https://pulsar.apache.org/docs/en/schema-manage/#upload-a-schema produces a 500 Internal Server Error.
The example that causes a 500 Internal Server error is:
```
{
"type": "JSON",
"schema": "{\"type\":\"record\",\"name\":\"User\",\"namespace\":\"com.foo\",\"fields\":[{\"name\":\"file1\",\"type\":[\"null\",\"string\"],\"default\":null},{\"name\":\"file2\",\"type\":\"string\",\"default\":null},{\"name\":\"file3\",\"type\":[\"null\",\"string\"],\"default\":\"dfdf\"}]}",
"properties": {}
}
```
**Describe the solution you'd like**
Here is an example of a helpful error from the `bin/pulsar-admin schemas upload --filename` command:
```
com.fasterxml.jackson.databind.JsonMappingException: Unrecognized character escape '}' (code 125)
at [Source: (File); line: 3, column: 274] (through reference chain: org.apache.pulsar.common.protocol.schema.PostSchemaPayload["schema"])
at com.fasterxml.jackson.databind.JsonMappingException.wrapWithPath(JsonMappingException.java:397)
at com.fasterxml.jackson.databind.JsonMappingException.wrapWithPath(JsonMappingException.java:356)
at com.fasterxml.jackson.databind.deser.BeanDeserializerBase.wrapAndThrow(BeanDeserializerBase.java:1726)
at com.fasterxml.jackson.databind.deser.BeanDeserializer.vanillaDeserialize(BeanDeserializer.java:295)
at com.fasterxml.jackson.databind.deser.BeanDeserializer.deserialize(BeanDeserializer.java:156)
at com.fasterxml.jackson.databind.ObjectMapper._readMapAndClose(ObjectMapper.java:4482)
at com.fasterxml.jackson.databind.ObjectMapper.readValue(ObjectMapper.java:3299)
at org.apache.pulsar.admin.cli.CmdSchemas$UploadSchema.run(CmdSchemas.java:86)
at org.apache.pulsar.admin.cli.CmdBase.run(CmdBase.java:76)
at org.apache.pulsar.admin.cli.PulsarAdminTool.run(PulsarAdminTool.java:246)
at org.apache.pulsar.admin.cli.PulsarAdminTool.main(PulsarAdminTool.java:288)
Caused by: com.fasterxml.jackson.core.JsonParseException: Unrecognized character escape '}' (code 125)
at [Source: (File); line: 3, column: 274]
at com.fasterxml.jackson.core.JsonParser._constructError(JsonParser.java:1851)
at com.fasterxml.jackson.core.base.ParserMinimalBase._reportError(ParserMinimalBase.java:707)
at com.fasterxml.jackson.core.base.ParserBase._handleUnrecognizedCharacterEscape(ParserBase.java:1031)
at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._decodeEscaped(UTF8StreamJsonParser.java:3305)
at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._finishString2(UTF8StreamJsonParser.java:2511)
at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._finishAndReturnString(UTF8StreamJsonParser.java:2466)
at com.fasterxml.jackson.core.json.UTF8StreamJsonParser.getText(UTF8StreamJsonParser.java:297)
at com.fasterxml.jackson.databind.deser.std.StringDeserializer.deserialize(StringDeserializer.java:35)
at com.fasterxml.jackson.databind.deser.std.StringDeserializer.deserialize(StringDeserializer.java:10)
at com.fasterxml.jackson.databind.deser.impl.MethodProperty.deserializeAndSet(MethodProperty.java:129)
at com.fasterxml.jackson.databind.deser.BeanDeserializer.vanillaDeserialize(BeanDeserializer.java:293)
```
Here is the unhelpful error message that multiple Pulsar users have been seeing:
```
19:08:18.342 [AsyncHttpClient-7-1] WARN org.apache.pulsar.client.admin.internal.BaseResource - [http://localhost:8999/admin/v2/schemas/climate/sandbox/chandana-user/schema] Failed to perform http post request: javax.ws.rs.InternalServerErrorException: HTTP 500 Internal Server Error
HTTP 500 Internal Server Error
Reason: HTTP 500 Internal Server Errorjava.io.ByteArrayInputStream@b97028c1
```
Commonly asked questions:
* What does Errorjava.io.ByteArrayInputStream@b97028c1 mean?
* Why isn't there server-side error logging for an Internal Server Error?
Desired outcome:
* Instead of `Errorjava.io.ByteArrayInputStream@b97028c1`, log something like "the schema uploaded is invalid".
* It would be better to describe why the schema is invalid, or where in the schema string (line number, character number) the invalidity was detected. It is a nice-to-have, as it would be consistent with existing parse errors that are helpful.
* If the 500 is returned by a broker, then that broker should log an error message. This way, at least the Pulsar user can see that the request reached the broker.
**Describe alternatives you've considered**
This is more of a bug than an enhancement request. I've described three options under `Desired outcome` in the previous section. The minimum that should be done is to replace `Errorjava.io.ByteArrayInputStream@b97028c1` with `the schema uploaded is invalid`.
**Additional context**
The schema registry is a major selling point of Pulsar vs Kafka. If schema registry is as hard to learn as it is today, it could turn away potential Pulsar users who are comparing messaging technologies.
Contributor guide
Research direction
Start by tracing CmdSchemas$UploadSchema.run and the request handling in BaseResource for invalid schema uploads, then inspect the related broker-side error path. Compare the useful Jackson parse output with the HTTP 500 response. Done means invalid schemas produce an actionable CLI error and the broker logs an error when it handles the request.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- java
- Domain
- backend, cli
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Stale
- Clarity
- Mostly clear
- Newbie friendliness
- 35/100