How do I avoid seeing an InternalError message when I would Apache Pinot #troubleshooting

Join Slack

How do I avoid seeing an InternalError message whe...

# troubleshooting

Tim Chan

09/29/2020, 5:11 PM

How do I avoid seeing an InternalError message when I would like to result a very very large result set?

Tim Chan

09/29/2020, 5:11 PM

image.png

Tim Chan

09/29/2020, 5:11 PM

When I do limit 10000 I do not see any error, but when I increase the limit to 100000 I see the above.

Yash Agarwal

09/29/2020, 5:13 PM

can you check the broker logs ?

Tim Chan

09/29/2020, 5:15 PM

i only see warn messages

Neha Pawar

09/29/2020, 7:03 PM

look for exceptions in the controller log too

Neha Pawar

09/29/2020, 7:04 PM

also what are the warn you see?

Tim Chan

09/29/2020, 7:07 PM

Copy code

2020/09/29 19:06:16.333 ERROR [PinotQueryResource] [grizzly-http-server-1] Caught exception while sending query request
java.io.IOException: Failed : HTTP error code : 500
        at org.apache.pinot.controller.api.resources.PinotQueryResource.sendPostRaw(PinotQueryResource.java:284) ~[pinot-all-0.5.0-SNAPSHOT-jar-with-dependencies.jar:0.5.0-SNAPSHOT-8511410b9b93616642c94ae11fc072444555962b]
        at org.apache.pinot.controller.api.resources.PinotQueryResource.sendRequestRaw(PinotQueryResource.java:322) ~[pinot-all-0.5.0-SNAPSHOT-jar-with-dependencies.jar:0.5.0-SNAPSHOT-8511410b9b93616642c94ae11fc072444555962b]
        at org.apache.pinot.controller.api.resources.PinotQueryResource.getQueryResponse(PinotQueryResource.java:204) ~[pinot-all-0.5.0-SNAPSHOT-jar-with-dependencies.jar:0.5.0-SNAPSHOT-8511410b9b93616642c94ae11fc072444555962b]
        at org.apache.pinot.controller.api.resources.PinotQueryResource.handlePostSql(PinotQueryResource.java:131) ~[pinot-all-0.5.0-SNAPSHOT-jar-with-dependencies.jar:0.5.0-SNAPSHOT-8511410b9b93616642c94ae11fc072444555962b]
        at sun.reflect.GeneratedMethodAccessor50.invoke(Unknown Source) ~[?:?]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_265]
        at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_265]
        at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory.lambda$static$0(ResourceMethodInvocationHandlerFactory.java:52) ~[pinot-all-0.5.0-SNAPSHOT-jar-with-dependencies.jar:0.5.0-SNAPSHOT-8511410b9b93616642c94ae11fc072444555962b]
        at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:124) [pinot-all-0.5.0-SNAPSHOT-jar-with-dependencies.jar:0.5.0-SNAPSHOT-8511410b9b93616642c94ae11fc072444555962b]
        at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:167) [pinot-all-0.5.0-SNAPSHOT-jar-with-dependencies.jar:0.5.0-SNAPSHOT-8511410b9b93616642c94ae11fc072444555962b]
        at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$TypeOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:219) [pinot-all-0.5.0-SNAPSHOT-jar-with-dependencies.jar:0.5.0-SNAPSHOT-8511410b9b93616642c94ae11fc072444555962b]
        at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:79) [pinot-all-0.5.0-SNAPSHOT-jar-with-dependencies.jar:0.5.0-SNAPSHOT-8511410b9b93616642c94ae11fc072444555962b]
        at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:469) [pinot-all-0.5.0-SNAPSHOT-jar-with-dependencies.jar:0.5.0-SNAPSHOT-8511410b9b93616642c94ae11fc072444555962b]
        at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:391) [pinot-all-0.5.0-SNAPSHOT-jar-with-dependencies.jar:0.5.0-SNAPSHOT-8511410b9b93616642c94ae11fc072444555962b]
        at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:80) [pinot-all-0.5.0-SNAPSHOT-jar-with-dependencies.jar:0.5.0-SNAPSHOT-8511410b9b93616642c94ae11fc072444555962b]
        at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:253) [pinot-all-0.5.0-SNAPSHOT-jar-with-dependencies.jar:0.5.0-SNAPSHOT-8511410b9b93616642c94ae11fc072444555962b]
        at org.glassfish.jersey.internal.Errors$1.call(Errors.java:248) [pinot-all-0.5.0-SNAPSHOT-jar-with-dependencies.jar:0.5.0-SNAPSHOT-8511410b9b93616642c94ae11fc072444555962b]
        at org.glassfish.jersey.internal.Errors$1.call(Errors.java:244) [pinot-all-0.5.0-SNAPSHOT-jar-with-dependencies.jar:0.5.0-SNAPSHOT-8511410b9b93616642c94ae11fc072444555962b]
        at org.glassfish.jersey.internal.Errors.process(Errors.java:292) [pinot-all-0.5.0-SNAPSHOT-jar-with-dependencies.jar:0.5.0-SNAPSHOT-8511410b9b93616642c94ae11fc072444555962b]
        at org.glassfish.jersey.internal.Errors.process(Errors.java:274) [pinot-all-0.5.0-SNAPSHOT-jar-with-dependencies.jar:0.5.0-SNAPSHOT-8511410b9b93616642c94ae11fc072444555962b]
        at org.glassfish.jersey.internal.Errors.process(Errors.java:244) [pinot-all-0.5.0-SNAPSHOT-jar-with-dependencies.jar:0.5.0-SNAPSHOT-8511410b9b93616642c94ae11fc072444555962b]
        at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:265) [pinot-all-0.5.0-SNAPSHOT-jar-with-dependencies.jar:0.5.0-SNAPSHOT-8511410b9b93616642c94ae11fc072444555962b]
        at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:232) [pinot-all-0.5.0-SNAPSHOT-jar-with-dependencies.jar:0.5.0-SNAPSHOT-8511410b9b93616642c94ae11fc072444555962b]
        at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:679) [pinot-all-0.5.0-SNAPSHOT-jar-with-dependencies.jar:0.5.0-SNAPSHOT-8511410b9b93616642c94ae11fc072444555962b]
        at org.glassfish.jersey.grizzly2.httpserver.GrizzlyHttpContainer.service(GrizzlyHttpContainer.java:353) [pinot-all-0.5.0-SNAPSHOT-jar-with-dependencies.jar:0.5.0-SNAPSHOT-8511410b9b93616642c94ae11fc072444555962b]
        at org.glassfish.grizzly.http.server.HttpHandler$1.run(HttpHandler.java:200) [pinot-all-0.5.0-SNAPSHOT-jar-with-dependencies.jar:0.5.0-SNAPSHOT-8511410b9b93616642c94ae11fc072444555962b]
        at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:569) [pinot-all-0.5.0-SNAPSHOT-jar-with-dependencies.jar:0.5.0-SNAPSHOT-8511410b9b93616642c94ae11fc072444555962b]
        at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:549) [pinot-all-0.5.0-SNAPSHOT-jar-with-dependencies.jar:0.5.0-SNAPSHOT-8511410b9b93616642c94ae11fc072444555962b]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_265]

Tim Chan

09/29/2020, 7:08 PM

the warn is for a missing segment

Tim Chan

09/29/2020, 7:08 PM

Copy code

2020/09/29 18:59:54.006 WARN [BaseInstanceSelector] [ClusterChangeHandlingThread] Failed to find servers hosting segment: sesame_person_features__3__202__20200918T0626Z for table: sesame_person_features_REALTIME (all ONLINE/CONSUMING instances: [] and OFFLINE instances: [] are disabled, counting segment as unavailable)

Neha Pawar

09/29/2020, 7:43 PM

how about exceptions on the server?

Tim Chan

09/30/2020, 5:53 AM

i don’t see any exceptions on the servers

Tim Chan

09/30/2020, 4:01 PM

i tried adjusting timeout settings in the broker and servers and it did not help

Yash Agarwal

09/30/2020, 4:01 PM

I think it is Memory issue.

Tim Chan

09/30/2020, 4:43 PM

give the server nodes more memory?

Neha Pawar

09/30/2020, 4:45 PM

you should’ve seen OutOfMemory errors on the servers though. Simply not working with absolutely no message is quite strange, unless the servers are already dead from OOM

Neha Pawar

09/30/2020, 4:46 PM

what is the jvm settings for servers currently? are the servers SSD nodes?

Tim Chan

09/30/2020, 4:47 PM

Copy code

JAVA_OPTS:  -Xms512M -Xmx1G -Dlog4j2.configurationFile=/opt/pinot/conf/pinot-server-log4j2.xml -Dplugins.dir=/opt/pinot/plugins

Tim Chan

09/30/2020, 4:48 PM

Copy code

Provisioner:           <http://kubernetes.io/gce-pd|kubernetes.io/gce-pd>
Parameters:            type=pd-standard

Tim Chan

09/30/2020, 4:49 PM

i believe that means they’re not ssd?

Neha Pawar

09/30/2020, 4:51 PM

1G does seem low for a high workload. No definitive way to tell yet, as to how much it should be. But please try increasing (4G if available) maybe it’ll help

Tim Chan

09/30/2020, 4:54 PM

ok. i will try that. thank you.

Tim Chan

09/30/2020, 5:00 PM

darn. still same issue.

Tim Chan

09/30/2020, 5:01 PM

Copy code

2020/09/30 06:33:05.663 ERROR [PinotQueryResource] [grizzly-http-server-1] Caught exception in sendQueryRaw
java.io.IOException: Failed : HTTP error code : 500

Tim Chan

09/30/2020, 5:01 PM

i don’t see errors in the server logs

Neha Pawar

09/30/2020, 5:01 PM

do you see any logs which tell the server acknowledged the query?

Tim Chan

09/30/2020, 5:09 PM

i don’t actually see such a thing in the server logs

Tim Chan

09/30/2020, 5:13 PM

i just ran a query with no errors and don’t see anything in the server logs nor controller logs to acknowledge that

Yash Agarwal

09/30/2020, 5:20 PM

I think I have faced the same issue. instead of querying using the ui, can you directly query the pinot broker using the sql endpoint ?

Tim Chan

09/30/2020, 5:22 PM

Copy code

File "/Users/tchan/Workspace/gbo-pinot/.venv/lib/python3.7/site-packages/pinotdb/db.py", line 279, in execute
    ) from e
pinotdb.exceptions.DatabaseError: Error when querying 
select sensor_id,
       time_stamp,
       annotations_json_str
  from sesame_person_features
 where time_stamp between 1601055847025 and 1601056747025

 order by time_stamp, sensor_id asc
 limit 56754 from <http://34.69.77.31:8099/query/sql>, raw response is:
<html><head><title>Grizzly 2.4.4</title><style><!--div.header {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#003300;font-size:22px;-moz-border-radius-topleft: 10px;border-top-left-radius: 10px;-moz-border-radius-topright: 10px;border-top-right-radius: 10px;padding-left: 5px}div.body {font-family:Tahoma,Arial,sans-serif;color:black;background-color:#FFFFCC;font-size:16px;padding-top:10px;padding-bottom:10px;padding-left:10px}div.footer {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#666633;font-size:14px;-moz-border-radius-bottomleft: 10px;border-bottom-left-radius: 10px;-moz-border-radius-bottomright: 10px;border-bottom-right-radius: 10px;padding-left: 5px}BODY {font-family:Tahoma,Arial,sans-serif;color:black;background-color:white;}B {font-family:Tahoma,Arial,sans-serif;color:black;}A {color : black;}HR {color : #999966;}--></style> </head><body><div class="header">Request failed.</div><div class="body">Request failed.</div><div class="footer">Grizzly 2.4.4</div></body></html>

Tim Chan

09/30/2020, 5:22 PM

i am using the pinotdb python library to run the same query

Jackie

09/30/2020, 5:23 PM

I cannot reproduce the issue on my local box with query:

select * from mytable order by AirTime limit 1000000

Jackie

09/30/2020, 5:24 PM

What is the content in

annotations_json_str

? Could that be large?

Tim Chan

09/30/2020, 5:24 PM

yes. very very large

Tim Chan

09/30/2020, 5:25 PM

we are storing highly nested json blob in that column

Tim Chan

09/30/2020, 5:29 PM

i just looked at one blob and it was 3.6k

Jackie

09/30/2020, 5:33 PM

I feel the problem is triggered by sending back huge response, trying to figure out where it throws exception

Tim Chan

09/30/2020, 5:34 PM

yes. doing a count(*) with the same query never has an error.

Jackie

09/30/2020, 5:36 PM

Can you try this query (removing

annotations_json_str

)

Copy code

select sensor_id,
       time_stamp
  from sesame_person_features
 where time_stamp between 1601055847025 and 1601056747025
order by time_stamp, sensor_id asc
limit 10000

Jackie

09/30/2020, 5:36 PM

I think it should also work

Jackie

09/30/2020, 5:45 PM

Can you check all the logs from the broker when you send the query? If you have multiple brokers, it might appear on any of them

Tim Chan

09/30/2020, 6:56 PM

Copy code

select sensor_id,
       time_stamp
  from sesame_person_features
 where time_stamp between 1601055847025 and 1601056747025
order by time_stamp, sensor_id asc
limit 56754

Tim Chan

09/30/2020, 6:56 PM

this runs fast and without errors

Jackie

09/30/2020, 8:08 PM

Yeah, then the problem is from the huge json string column. Can you please try to find the query log from the broker? The exception should also be logged there

Tim Chan

09/30/2020, 8:42 PM

i’m looking in the broker logs and do not see the error

Open in Slack

Previous Next