Please Note This forum exists for community support for the Mango product family and the Radix IoT Platform. Although Radix IoT employees participate in this forum from time to time, there is no guarantee of a response to anything posted here, nor can Radix IoT, LLC guarantee the accuracy of any information expressed or conveyed. Specific project questions from customers with active support contracts are asked to send requests to support@radixiot.com.

Radix IoT Website Mango 3 Documentation Website Mango 4 Documentation Website

  • Hi, we have an instalation with a medium bacnet network (a server connected via an ethernet backbone to 6 mstp routers connected to ~100 devices total), and we are having a couple of stability issues, watching the log we found errors being thrown ALL the time, the errors are:

    feb 23 17:25:12 bms-server ma.sh[16335]: ERROR 2017-02-23 17:25:12,189 (com.serotonin.bacnet4j.transport.DefaultTransport.run:416) - Error during expire messages:
    feb 23 17:25:12 bms-server ma.sh[16335]: java.lang.RuntimeException: Invalid arguments: router address not provided for remote recipient Address [networkNumber=501, macAddress=[53]]
    feb 23 17:25:12 bms-server ma.sh[16335]:         at com.serotonin.bacnet4j.npdu.Network.sendAPDU(Network.java:104)
    feb 23 17:25:12 bms-server ma.sh[16335]:         at com.serotonin.bacnet4j.transport.DefaultTransport.sendForResponse(DefaultTransport.java:851)
    feb 23 17:25:12 bms-server ma.sh[16335]:         at com.serotonin.bacnet4j.transport.DefaultTransport.expire(DefaultTransport.java:804)
    feb 23 17:25:12 bms-server ma.sh[16335]:         at com.serotonin.bacnet4j.transport.DefaultTransport.run(DefaultTransport.java:414)
    feb 23 17:25:12 bms-server ma.sh[16335]:         at java.lang.Thread.run(Thread.java:745)
    
    
    feb 23 17:59:38 bms-server ma.sh[16335]: ERROR 2017-02-23 17:59:38,892 (com.serotonin.bacnet4j.transport.DefaultTransport.run:395) - Error during send: com.serotonin.bacnet4j.transport.DefaultTransport$OutgoingConfirmed@17efad5
    feb 23 17:59:38 bms-server ma.sh[16335]: com.serotonin.bacnet4j.exception.BACnetRuntimeException: Cannot enter a client into the un-acked messages list. key=Key(address=Address [networkNumber=201, macAddress=[5c]], linkService=[a,a2,5,c3,ba,c0], invokeId=-4, fromServer=true)
    feb 23 17:59:38 bms-server ma.sh[16335]:         at com.serotonin.bacnet4j.transport.UnackedMessages.addClient(UnackedMessages.java:69)
    feb 23 17:59:38 bms-server ma.sh[16335]:         at com.serotonin.bacnet4j.transport.DefaultTransport$OutgoingConfirmed.sendImpl(DefaultTransport.java:314)
    feb 23 17:59:38 bms-server ma.sh[16335]:         at com.serotonin.bacnet4j.transport.DefaultTransport$Outgoing.send(DefaultTransport.java:281)
    feb 23 17:59:38 bms-server ma.sh[16335]:         at com.serotonin.bacnet4j.transport.DefaultTransport.run(DefaultTransport.java:392)
    feb 23 17:59:38 bms-server ma.sh[16335]:         at java.lang.Thread.run(Thread.java:745)
    
    

    this one is not that common:

    feb 23 18:32:38 bms-server ma.sh[16335]: ERROR 2017-02-23 18:32:38,607 (com.serotonin.bacnet4j.event.DefaultExceptionListener.receivedException:48) -
    feb 23 18:32:38 bms-server ma.sh[16335]: com.serotonin.bacnet4j.exception.ReflectionException: java.lang.reflect.InvocationTargetException
    feb 23 18:32:38 bms-server ma.sh[16335]:         at com.serotonin.bacnet4j.type.Encodable.read(Encodable.java:214)
    feb 23 18:32:38 bms-server ma.sh[16335]:         at com.serotonin.bacnet4j.type.Encodable.readWrapped(Encodable.java:400)
    feb 23 18:32:38 bms-server ma.sh[16335]:         at com.serotonin.bacnet4j.type.Encodable.readEncodable(Encodable.java:364)
    feb 23 18:32:38 bms-server ma.sh[16335]:         at com.serotonin.bacnet4j.type.constructed.PropertyValue.<init>(PropertyValue.java:88)
    feb 23 18:32:38 bms-server ma.sh[16335]:         at sun.reflect.GeneratedConstructorAccessor64.newInstance(Unknown Source)
    feb 23 18:32:38 bms-server ma.sh[16335]:         at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    feb 23 18:32:38 bms-server ma.sh[16335]:         at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
    feb 23 18:32:38 bms-server ma.sh[16335]:         at com.serotonin.bacnet4j.type.Encodable.read(Encodable.java:202)
    feb 23 18:32:38 bms-server ma.sh[16335]:         at com.serotonin.bacnet4j.type.constructed.SequenceOf.<init>(SequenceOf.java:80)
    feb 23 18:32:38 bms-server ma.sh[16335]:         at com.serotonin.bacnet4j.type.Encodable.readSequenceOf(Encodable.java:273)
    feb 23 18:32:38 bms-server ma.sh[16335]:         at com.serotonin.bacnet4j.service.unconfirmed.UnconfirmedCovNotificationRequest.<init>(UnconfirmedCovNotificationRequest.java:90)
    feb 23 18:32:38 bms-server ma.sh[16335]:         at com.serotonin.bacnet4j.service.unconfirmed.UnconfirmedRequestService.createUnconfirmedRequestService(UnconfirmedRequestService.java:78)
    feb 23 18:32:38 bms-server ma.sh[16335]:         at com.serotonin.bacnet4j.apdu.UnconfirmedRequest.parseServiceData(UnconfirmedRequest.java:91)
    feb 23 18:32:38 bms-server ma.sh[16335]:         at com.serotonin.bacnet4j.transport.DefaultTransport.receiveAPDU(DefaultTransport.java:538)
    feb 23 18:32:38 bms-server ma.sh[16335]:         at com.serotonin.bacnet4j.transport.DefaultTransport.receiveImpl(DefaultTransport.java:463)
    feb 23 18:32:38 bms-server ma.sh[16335]:         at com.serotonin.bacnet4j.transport.DefaultTransport.run(DefaultTransport.java:404)
    feb 23 18:32:38 bms-server ma.sh[16335]:         at java.lang.Thread.run(Thread.java:745)
    feb 23 18:32:38 bms-server ma.sh[16335]: Caused by: java.lang.reflect.InvocationTargetException
    feb 23 18:32:38 bms-server ma.sh[16335]:         at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    feb 23 18:32:38 bms-server ma.sh[16335]:         at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
    feb 23 18:32:38 bms-server ma.sh[16335]:         at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    feb 23 18:32:38 bms-server ma.sh[16335]:         at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
    feb 23 18:32:38 bms-server ma.sh[16335]:         at com.serotonin.bacnet4j.type.Encodable.read(Encodable.java:202)
    feb 23 18:32:38 bms-server ma.sh[16335]:         ... 16 more
    feb 23 18:32:38 bms-server ma.sh[16335]: Caused by: java.lang.IndexOutOfBoundsException: Index: 11, Size: 3
    feb 23 18:32:38 bms-server ma.sh[16335]:         at java.util.ArrayList.rangeCheck(ArrayList.java:653)
    feb 23 18:32:38 bms-server ma.sh[16335]:         at java.util.ArrayList.get(ArrayList.java:429)
    feb 23 18:32:38 bms-server ma.sh[16335]:         at com.serotonin.bacnet4j.type.constructed.Choice.read(Choice.java:73)
    feb 23 18:32:38 bms-server ma.sh[16335]:         at com.serotonin.bacnet4j.type.constructed.Choice.<init>(Choice.java:62)
    feb 23 18:32:38 bms-server ma.sh[16335]:         at com.serotonin.bacnet4j.type.constructed.TimeStamp.<init>(TimeStamp.java:75)
    feb 23 18:32:38 bms-server ma.sh[16335]:         ... 21 more
    

    an example point config:

    0_1487884179654_Screenshot_2017-02-23_17-55-03.png

    the routing table of one of our bacnet routers:
    0_1487884535594_Screenshot_2017-02-23_18-14-39.png

    BACNet local device config:
    0_1487886040805_Screenshot_2017-02-23_18-39-18.png

    Some help would be appreciated! :)


  • Hi jmpy,

    Thanks for collecting so much information on this issue!

    With regards to the "Runtime Exception: Invalid arguments: router address not provided for remote recipient" exception, this is what is causing the second exception, not being able to enter a client into the un-acked messages list. This is a known issue, and I'll email you a JAR for fixing that particular issue with instructions to update. It's an interim solution.

    The ReflectionException is new to me, I'll check that out, but I can't profess expertise in BACnet4J. It is undergoing active development right now, but we're not prepared to offer a timeline on the next version. I will ensure the developer is aware of the information you've collected here, though!

    I do know those "router address not provided" exceptions can have to do with Mango not having gotten the full description of the network topology. But I can offer little more advice than saying 'Run the discovery tool a few times" as I've not had the opportunity to play with a network that is experiencing this issue, yet.


  • Hi jmpy,

    Did the JAR I provide you help alleviate this at all?

    The assessment of the ReflectionException points to some corruption of the incoming datagram. From the developer,

    "If you look at Timestamp in the code or the spec, you'll see that it is a choice of three types: either a Time, a sequence number, or a DateTime. This is why it says "length 3". There shouldn't be any reason why it is asking for index 11 except data corruption, which i know is a dramatic conclusion to reach. It would be great if wire traces could be captured that show what is going on, but i know this is a lot to ask."

    There was also interest in knowing the specification compliance of the affected device, but it's probably nontrivial to assess what device is producing that error, or perhaps unknown what version of the specification it's complying with.


  • Hi phil,

    I now tested the jar you sent, and it doesn't seem to help. Those errors pop up by the hundreds on start, but then appear much less after the system has settled a little.
    The thing that did became much more common is the "java.lang.reflect.InvocationTargetException" exception.

    ERROR 2017-02-28 18:48:42,379 (com.serotonin.bacnet4j.event.DefaultExceptionListener.receivedException:48) -  
    com.serotonin.bacnet4j.exception.ReflectionException: java.lang.reflect.InvocationTargetException
    	at com.serotonin.bacnet4j.type.Encodable.read(Encodable.java:214)
    	at com.serotonin.bacnet4j.type.Encodable.readWrapped(Encodable.java:400)
    	at com.serotonin.bacnet4j.type.Encodable.readEncodable(Encodable.java:364)
    	at com.serotonin.bacnet4j.type.constructed.PropertyValue.<init>(PropertyValue.java:88)
    	at sun.reflect.GeneratedConstructorAccessor54.newInstance(Unknown Source)
    	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    	at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
    	at com.serotonin.bacnet4j.type.Encodable.read(Encodable.java:202)
    	at com.serotonin.bacnet4j.type.constructed.SequenceOf.<init>(SequenceOf.java:80)
    	at com.serotonin.bacnet4j.type.Encodable.readSequenceOf(Encodable.java:273)
    	at com.serotonin.bacnet4j.service.unconfirmed.UnconfirmedCovNotificationRequest.<init>(UnconfirmedCovNotificationRequest.java:90)
    	at com.serotonin.bacnet4j.service.unconfirmed.UnconfirmedRequestService.createUnconfirmedRequestService(UnconfirmedRequestService.java:78)
    	at com.serotonin.bacnet4j.apdu.UnconfirmedRequest.parseServiceData(UnconfirmedRequest.java:91)
    	at com.serotonin.bacnet4j.transport.DefaultTransport.receiveAPDU(DefaultTransport.java:540)
    	at com.serotonin.bacnet4j.transport.DefaultTransport.receiveImpl(DefaultTransport.java:465)
    	at com.serotonin.bacnet4j.transport.DefaultTransport.run(DefaultTransport.java:406)
    	at java.lang.Thread.run(Thread.java:745)
    Caused by: java.lang.reflect.InvocationTargetException
    	at sun.reflect.GeneratedConstructorAccessor91.newInstance(Unknown Source)
    	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    	at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
    	at com.serotonin.bacnet4j.type.Encodable.read(Encodable.java:202)
    	... 16 more
    Caused by: java.lang.IndexOutOfBoundsException: Index: 11, Size: 3
    	at java.util.ArrayList.rangeCheck(ArrayList.java:653)
    	at java.util.ArrayList.get(ArrayList.java:429)
    	at com.serotonin.bacnet4j.type.constructed.Choice.read(Choice.java:73)
    	at com.serotonin.bacnet4j.type.constructed.Choice.<init>(Choice.java:62)
    	at com.serotonin.bacnet4j.type.constructed.TimeStamp.<init>(TimeStamp.java:75)
    	... 20 more
    

    also, something is just found: (that the scanner also throws exceptions)
    0_1488318985039_Screenshot_2017-02-28_18-48-11.png

    The routers we are using are these: KMC BAC-5051E (BTL listed)

    We are capable of collecting more information, just let's us know what do you need...


  • Another error we see sometimes: (in this case trying to force a point read)

    ERROR 2017-02-28 21:22:56,224 (com.serotonin.m2m2.web.dwr.util.ExceptionDetectionFilter.doFilter:38) - DWR invocation exception 
    java.lang.ClassCastException: com.serotonin.bacnet4j.transport.ServiceFutureImpl cannot be cast to com.serotonin.bacnet4j.service.acknowledgement.ReadPropertyAck
    	at com.serotonin.ma.bacnet.BACnetDataSourceRT.forcePointRead(BACnetDataSourceRT.java:373)
    	at com.serotonin.m2m2.rt.RuntimeManager.forcePointRead(RuntimeManager.java:650)
    	at com.serotonin.m2m2.web.dwr.BaseDwr.forcePointRead(BaseDwr.java:278)
    	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    	at java.lang.reflect.Method.invoke(Method.java:498)
    	at org.directwebremoting.impl.ExecuteAjaxFilter.doFilter(ExecuteAjaxFilter.java:34)
    	at org.directwebremoting.impl.DefaultRemoter$1.doFilter(DefaultRemoter.java:428)
    	at com.serotonin.m2m2.web.dwr.util.TranslationsFilter.doFilter(TranslationsFilter.java:37)
    	at org.directwebremoting.impl.DefaultRemoter$1.doFilter(DefaultRemoter.java:428)
    	at com.serotonin.m2m2.web.dwr.util.ExceptionDetectionFilter.doFilter(ExceptionDetectionFilter.java:26)
    	at org.directwebremoting.impl.DefaultRemoter$1.doFilter(DefaultRemoter.java:428)
    	at com.serotonin.m2m2.web.dwr.util.DwrPermissionFilter.doFilter(DwrPermissionFilter.java:45)
    	at org.directwebremoting.impl.DefaultRemoter$1.doFilter(DefaultRemoter.java:428)
    	at org.directwebremoting.impl.DefaultRemoter.execute(DefaultRemoter.java:431)
    	at org.directwebremoting.impl.DefaultRemoter.execute(DefaultRemoter.java:283)
    	at org.directwebremoting.servlet.PlainCallHandler.handle(PlainCallHandler.java:52)
    	at org.directwebremoting.servlet.UrlProcessor.handle(UrlProcessor.java:101)
    	at org.directwebremoting.servlet.DwrServlet.doPost(DwrServlet.java:146)
    	at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
    	at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
    	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:808)
    	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1669)
    	at org.eclipse.jetty.servlets.UserAgentFilter.doFilter(UserAgentFilter.java:83)
    	at org.eclipse.jetty.servlets.GzipFilter.doFilter(GzipFilter.java:300)
    	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
    	at org.springframework.web.filter.ShallowEtagHeaderFilter.doFilterInternal(ShallowEtagHeaderFilter.java:87)
    	at com.serotonin.m2m2.web.filter.MangoShallowEtagHeaderFilter.doFilterInternal(MangoShallowEtagHeaderFilter.java:47)
    	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
    	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:585)
    	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
    	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:577)
    	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:223)
    	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127)
    	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515)
    	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
    	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061)
    	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
    	at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:215)
    	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)
    	at org.eclipse.jetty.server.Server.handle(Server.java:499)
    	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:310)
    	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:257)
    	at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:540)
    	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635)
    	at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555)
    	at java.lang.Thread.run(Thread.java:745)