Graphing problem with new items

jonathanb · August 4, 2021, 11:21am

Hi,

I was wondering on where to go on this one. I have MySQL persistence running for graphing etc and it has worked fine until I added a new item to display a graph on. I am using openhab 3.0.0 release build with the basicui to the android app. I am running on a pi talking to a MySQL server to limit writes.

In the site map I am using:

Text item=ExternalEnergy label="Total used [%.3f Kw]" {
                       Switch item=tgraph_Period label="Chart Period" icon="time" mappings=[0="8h", 1="Day", 2="3 Day", 3="Week", 4="Month"]
                        Chart item=ExternalEnergy service="jdbc" period=8h refresh=60000 visibility=[tgraph_Period==0]
                        Chart item=ExternalEnergy service="jdbc" period=D refresh=60000 visibility=[tgraph_Period==1]
                        Chart item=ExternalEnergy service="jdbc" period=3D refresh=60000 visibility=[tgraph_Period==2]
                        Chart item=ExternalEnergy service="jdbc" period=W refresh=60000 visibility=[tgraph_Period==3]
                        Chart item=ExternalEnergy service="jdbc" period=M refresh=60000 visibility=[tgraph_Period==4]
               }

But when I view the graph which it never displays I get:

[WARN ] [e.io.http.servlet.BaseOpenHABServlet] - Illegal argument in chart: Series name cannot be null or zero-length!!!

Not sure where to start. Any help or pointers would be appreciated.

jonathanb · August 4, 2021, 6:42pm

I have done an update and increased logging to the full error:

2021-08-04 20:40:12.098 [WARN ] [e.io.http.servlet.BaseOpenHABServlet] - Illegal argument in chart: Series name cannot be null or zero-length!!!

2021-08-04 20:40:12.101 [WARN ] [org.eclipse.jetty.server.HttpChannel] - /chart

java.lang.IllegalStateException: COMMITTED

	at org.eclipse.jetty.server.HttpChannelState.sendError(HttpChannelState.java:896) ~[?:?]

	at org.eclipse.jetty.server.Response.sendError(Response.java:471) ~[?:?]

	at org.openhab.core.ui.internal.chart.ChartServlet.doGet(ChartServlet.java:327) ~[?:?]

	at javax.servlet.http.HttpServlet.service(HttpServlet.java:687) ~[bundleFile:3.1.0]

	at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) ~[bundleFile:3.1.0]

	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:791) ~[?:?]

	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:550) ~[?:?]

	at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:71) ~[?:?]

	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) ~[bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:602) ~[?:?]

	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) ~[bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235) ~[bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1624) ~[bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) ~[bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1435) ~[bundleFile:9.4.40.v20210413]

	at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:294) ~[?:?]

	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188) ~[bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501) ~[?:?]

	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1594) ~[bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186) ~[bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1350) ~[bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) ~[bundleFile:9.4.40.v20210413]

	at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:82) ~[?:?]

	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) ~[bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.server.Server.handle(Server.java:516) ~[bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:388) ~[bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:633) ~[bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:380) [bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277) [bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) [bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) [bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.onFillable(SslConnection.java:540) [bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:395) [bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.io.ssl.SslConnection$2.succeeded(SslConnection.java:161) [bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) [bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104) [bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336) [bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313) [bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171) [bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129) [bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:383) [bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:882) [bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1036) [bundleFile:9.4.40.v20210413]

	at java.lang.Thread.run(Thread.java:829) [?:?]

rossko57 · August 4, 2021, 7:45pm

Are you actually persisting your new Item?

jonathanb · August 4, 2021, 8:30pm

Yes I have double checked the database and it is there and writing data into it.

jonathanb · August 7, 2021, 12:42pm

Does anyone know what the java error means or how to get further info to find out what is wrong?

opus · August 7, 2021, 3:13pm

Did you check with the API-Explorer wether openHAB can access the persisted values?

jonathanb · August 7, 2021, 3:25pm

Didn’t think to try that but:

/rest/persistence/items/ExternalFactor

{
  "name": "ExternalFactor",
  "datapoints": "3158",
  "data": [
    {
      "time": 1628263491771,
      "state": "74.0"
    },
    {
      "time": 1628263532188,
      "state": "73.0"
    },
    {
      "time": 1628263542283,
      "state": "74.0"
    },
    {
      "time": 1628263552398,
      "state": "76.0"
    },
    {
      "time": 1628263562502,
      "state": "74.0"
    },
    {
      "time": 1628263592820,
      "state": "73.0"
    },
    {
      "time": 1628263602915,
      "state": "74.0"
    },
............

rossko57 · August 7, 2021, 3:53pm

But you’re trying to chart

jonathanb · August 7, 2021, 4:03pm

Sorry for the confusion but it is failing on a few charts and that was another example.

I have checked the Openhab V3 interface and that is working fine for the graphs. Maybe I should sort out the new UI to suit.

Wolfgang_S · August 8, 2021, 8:05am

As far as I can see it is related to this part in the code

        // Set the content type to that provided by the chart provider
        res.setContentType("image/" + provider.getChartType());
        logger.debug("chart building with width {} height {} dpi {}", width, height, dpi);
        try (ImageOutputStream imageOutputStream = ImageIO.createImageOutputStream(res.getOutputStream())) {
            BufferedImage chart = provider.createChart(serviceName, req.getParameter("theme"), timeBegin, timeEnd,
                    height, width, req.getParameter("items"), req.getParameter("groups"), dpi, legend);
            ImageIO.write(chart, provider.getChartType().toString(), imageOutputStream);
            logger.debug("Chart successfully generated and written to the response.");
        } catch (ItemNotFoundException e) {
            logger.debug("{}", e.getMessage());
            res.sendError(HttpServletResponse.SC_BAD_REQUEST, e.getMessage());
        } catch (IllegalArgumentException e) {
            logger.warn("Illegal argument in chart: {}", e.getMessage());
            res.sendError(HttpServletResponse.SC_BAD_REQUEST, "Illegal argument in chart: " + e.getMessage());
        } catch (IIOException | EOFException e) {
            // this can happen if the request is terminated while the image is streamed, see
            // https://github.com/openhab/openhab-distro/issues/684
            logger.debug("Failed writing image to response stream", e);
        } catch (RuntimeException e) {
            if (logger.isDebugEnabled()) {
                // we also attach the stack trace
                logger.warn("Chart generation failed: {}", e.getMessage(), e);
            } else {
                logger.warn("Chart generation failed: {}", e.getMessage());
            }
            res.sendError(HttpServletResponse.SC_INTERNAL_SERVER_ERROR, e.getMessage());
        }

In case it wold be a problem of the item(name) I would expect to see it because this is before the illegal argument.

Would it help to enable debugging log for … as the code contains a very first line

        logger.debug("Received incoming chart request: {}", req);

in openhab-core/bundles/org.openhab.core.ui/src/main/java/org/openhab/core/ui/internal/chart/ChartServlet.java

jonathanb · August 8, 2021, 9:39am

I will get this and report back.

jonathanb · August 10, 2021, 9:48pm

2021-08-10 22:45:59.216 [DEBUG] [ab.core.ui.icon.internal.IconServlet] - Requested icon category  provided by no icon provider

2021-08-10 22:46:00.122 [DEBUG] [ui.internal.items.ItemUIRegistryImpl] - Checking visiblity for widget 'null'.

2021-08-10 22:46:00.127 [DEBUG] [ui.internal.items.ItemUIRegistryImpl] - Checking visiblity for widget 'null'.

2021-08-10 22:46:00.128 [DEBUG] [ui.internal.items.ItemUIRegistryImpl] - Widget null is not visible.

2021-08-10 22:46:00.131 [DEBUG] [ui.internal.items.ItemUIRegistryImpl] - Checking visiblity for widget 'null'.

2021-08-10 22:46:00.132 [DEBUG] [ui.internal.items.ItemUIRegistryImpl] - Widget null is not visible.

2021-08-10 22:46:00.135 [DEBUG] [ui.internal.items.ItemUIRegistryImpl] - Checking visiblity for widget 'null'.

2021-08-10 22:46:00.136 [DEBUG] [ui.internal.items.ItemUIRegistryImpl] - Widget null is not visible.

2021-08-10 22:46:00.139 [DEBUG] [ui.internal.items.ItemUIRegistryImpl] - Checking visiblity for widget 'null'.

2021-08-10 22:46:00.140 [DEBUG] [ui.internal.items.ItemUIRegistryImpl] - Widget null is not visible.

2021-08-10 22:46:00.256 [DEBUG] [ltchartprovider.DefaultChartProvider] - Rendering chart: service: 'jdbc', theme: 'white', startTime: 'Tue Aug 10 14:46:00 BST 2021', endTime: 'Tue Aug 10 22:46:00 BST 2021', width: '1440', height: '720', items: 'ExternalEnergy', groups: 'null', dpi: '280', legend: 'null'

2021-08-10 22:46:00.431 [WARN ] [e.io.http.servlet.BaseOpenHABServlet] - Illegal argument in chart: Series name cannot be null or zero-length!!!

2021-08-10 22:46:00.432 [WARN ] [org.eclipse.jetty.server.HttpChannel] - /chart

java.lang.IllegalStateException: COMMITTED

	at org.eclipse.jetty.server.HttpChannelState.sendError(HttpChannelState.java:896) ~[?:?]

	at org.eclipse.jetty.server.Response.sendError(Response.java:471) ~[?:?]

	at org.openhab.core.ui.internal.chart.ChartServlet.doGet(ChartServlet.java:327) ~[?:?]

	at javax.servlet.http.HttpServlet.service(HttpServlet.java:687) ~[bundleFile:3.1.0]

	at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) ~[bundleFile:3.1.0]

	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:791) ~[?:?]

	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:550) ~[?:?]

	at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:71) ~[?:?]

	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) ~[bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:602) ~[?:?]

	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) ~[bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235) ~[bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1624) ~[bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) ~[bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1435) ~[bundleFile:9.4.40.v20210413]

	at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:294) ~[?:?]

	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188) ~[bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501) ~[?:?]

	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1594) ~[bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186) ~[bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1350) ~[bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) ~[bundleFile:9.4.40.v20210413]

	at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:82) ~[?:?]

	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) ~[bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.server.Server.handle(Server.java:516) ~[bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:388) ~[bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:633) ~[bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:380) [bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277) [bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) [bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) [bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.onFillable(SslConnection.java:540) [bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:395) [bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.io.ssl.SslConnection$2.succeeded(SslConnection.java:161) [bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) [bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104) [bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336) [bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313) [bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171) [bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129) [bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:383) [bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:882) [bundleFile:9.4.40.v20210413]

	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1036) [bundleFile:9.4.40.v20210413]

	at java.lang.Thread.run(Thread.java:829) [?:?]

If I am reading this right it is because there is no legend coming through.

Wolfgang_S · August 11, 2021, 4:54am

Could be wrong but I don’t think that the legend is the problem. In case it is just one parameter to display a legend is not required.
The above code extract shows a line containing debug log statement that shows Received incoming chart request: {}. This is not shown in your log extract.
If that row is shown we are sure that we are in the subroutine that raises the exception “Illegal argument in chart” and as far as I understand it should show all parts of the req object.

Is there maybe more information available before the log extract that you posted ?

rossko57 · August 11, 2021, 10:59am

Silly thought, but does your Item have any label set? I can imagine charting tripping over an empty label.

jonathanb · August 13, 2021, 8:09pm

@rossko57 Certainly wasn’t a silly suggestion. You are right the basic UI trips over no label being set. I have set them and it all now works. Daft I didn’t set one in the first place but hay.