Thank you for the detailed answer Nice to read
I made some additionnal NPE checks to prevent the log gets filled.
I run the start sequence again and again and got a log with about 900 lines for each try.
2017-11-16 11:38:11.329 [DEBUG] [c.x.o.XmlDocumentBundleTracker:342 ] - Reading the XML document '/ESH-INF/thing/thing-types.xml' in module 'org.eclipse.smarthome.binding.tradfri'...
2017-11-16 11:38:11.331 [DEBUG] [c.x.o.XmlDocumentBundleTracker:342 ] - Reading the XML document '/ESH-INF/config/config.xml' in module 'org.eclipse.smarthome.binding.tradfri'...
2017-11-16 11:38:11.333 [DEBUG] [s.c.i.service.ReadyServiceImpl:49 ] - Added ready marker esh.xmlConfig=org.eclipse.smarthome.binding.tradfri
2017-11-16 11:38:11.334 [DEBUG] [c.x.o.XmlDocumentBundleTracker:342 ] - Reading the XML document '/ESH-INF/binding/binding.xml' in module 'org.eclipse.smarthome.binding.tradfri'...
2017-11-16 11:38:11.334 [DEBUG] [s.c.i.service.ReadyServiceImpl:49 ] - Added ready marker esh.xmlBindingInfo=org.eclipse.smarthome.binding.tradfri
2017-11-16 11:38:11.338 [INFO ] [.s.u.c.i.servlet.WebAppServlet:87 ] - Started Classic UI at /classicui/app
2017-11-16 11:38:11.341 [DEBUG] [.c.thing.internal.ThingManager:502 ] - Calling 'TradfriHandlerFactory.registerHandler()' for thing 'tradfri:gateway:a7cabab9'.
2017-11-16 11:38:11.348 [INFO ] [.s.u.b.i.servlet.WebAppServlet:84 ] - Started Basic UI at /basicui/app
2017-11-16 11:38:11.408 [DEBUG] [.c.thing.internal.ThingManager:603 ] - Configuration of thing tradfri:gateway:a7cabab9 needs [host], has [host, preSharedKey, code, port, identity].
2017-11-16 11:38:11.409 [DEBUG] [.c.thing.internal.ThingManager:630 ] - Calling initialize handler for thing 'tradfri:gateway:a7cabab9' at 'org.eclipse.smarthome.binding.tradfri.handler.TradfriGatewayHandler@4b3a6757'.
2017-11-16 11:38:11.587 [WARN ] [.d.TradfriDiscoveryParticipant:91 ] - Discovered Tradfri gateway doesn't have an IP address: [ServiceInfoImpl@524612020 name: 'gw-dcefcaba5307._coap._udp.local.' address: '(null):0' status: 'DNS: JmDNS-IP-2 [/xxx.xxxx.xxx.126] state: probing 1 task: null', has NO data
gw-dcefcaba5307._coap._udp.local.: ]
2017-11-16 11:38:11.589 [DEBUG] [.d.TradfriDiscoveryParticipant:79 ] - Discovered Tradfri gateway: [ServiceInfoImpl@293805100 name: 'gw-dcefcaba5307._coap._udp.local.' address: '/xxx.xxx.xxx.142:5684 /fe80:0:0:0:deef:caff:feba:5307:5684 ' status: 'DNS: JmDNS-IP-2 [/xxx.xxx.xxx.126] state: probing 1 task: null' is persistent, has data
version: 1.2.42]
The gateway takes a long time to setup
2017-11-16 11:38:16.412 [DEBUG] [s.core.common.SafeMethodCaller:205 ] - Timeout of 5000ms exceeded, thread safeCall-2 (131) in state RUNNABLE is at org.eclipse.smarthome.binding.tradfri.handler.TradfriGatewayHandler.initialize(TradfriGatewayHandler.java:87).
2017-11-16 11:38:16.413 [WARN ] [.c.thing.internal.ThingManager:641 ] - Initializing handler for thing 'tradfri:gateway:a7cabab9' takes more than 5000ms.
You will see that the refresh of the data is done, but the thing is not added to the inbox, as it is already present in the registry
I do not understand why the gateway gets remains not being online until the udp discovery has finished. The IP and secret is read .
2017-11-16 11:38:16.416 [DEBUG] [s.c.i.service.ReadyServiceImpl:49 ] - Added ready marker esh.xmlThingTypes=org.eclipse.smarthome.binding.tradfri
2017-11-16 11:38:23.293 [DEBUG] [.e.s.config.core.Configuration:99 ] - Setting value (String) xxx.xxx.xxx.142 to field 'host' in configuration class org.eclipse.smarthome.binding.tradfri.internal.config.TradfriGatewayConfig
2017-11-16 11:38:23.294 [DEBUG] [.e.s.config.core.Configuration:99 ] - Setting value (int) 5684 to field 'port' in configuration class org.eclipse.smarthome.binding.tradfri.internal.config.TradfriGatewayConfig
2017-11-16 11:38:23.294 [DEBUG] [.e.s.config.core.Configuration:99 ] - Setting value (String) xxxxxxxxx to field 'code' in configuration class org.eclipse.smarthome.binding.tradfri.internal.config.TradfriGatewayConfig
2017-11-16 11:38:23.295 [DEBUG] [.e.s.config.core.Configuration:99 ] - Setting value (String) to field 'identity' in configuration class org.eclipse.smarthome.binding.tradfri.internal.config.TradfriGatewayConfig
2017-11-16 11:38:23.296 [DEBUG] [.e.s.config.core.Configuration:99 ] - Setting value (String) xxxxxxxxxx to field 'preSharedKey' in configuration class org.eclipse.smarthome.binding.tradfri.internal.config.TradfriGatewayConfig
2017-11-16 11:38:23.296 [WARN ] [.s.b.t.h.TradfriGatewayHandler:108 ] - Gateway with old firmware - please consider upgrading to the latest version.
2017-11-16 11:38:23.301 [DEBUG] [.c.c.r.AbstractManagedProvider:128 ] - Updated element tradfri:gateway:a7caxxxx in ManagedThingProvider.
2017-11-16 11:38:25.269 [DEBUG] [s.c.d.internal.PersistentInbox:190 ] - Updated discovery result for 'homematic:HM-TC-IT-WM-W-EU:32b21339:LEQ0997044'.
2017-11-16 11:38:25.294 [DEBUG] [s.c.d.internal.PersistentInbox:190 ] - Updated discovery result for 'homematic:HM-WDS40-TH-I-2:32b21339:LEQ0228393'.
2017-11-16 11:38:25.601 [DEBUG] [s.c.d.internal.PersistentInbox:190 ] - Updated discovery result for 'homematic:HM-LC-Sw1PBU-FM:32b21339:LEQ0493990'.
2017-11-16 11:38:26.151 [DEBUG] [s.c.d.internal.PersistentInbox:190 ] - Updated discovery result for 'homematic:HM-CC-RT-DN:32b21339:LEQ0846743'.
2017-11-16 11:38:26.164 [DEBUG] [o.e.s.b.t.i.TradfriCoapHandler:56 ] - CoAP response
options: {"Content-Format":"application/json", "Max-Age":604800}
payload: {"9023":"0.tradfri.pool.ntp.org","9074":0,"9059":1510828705,"9080":0,"9072":0,"9060":"2017-11-16T10:38:25.059032Z","9062":0,"9061":0,"9083":"795-75-672","9029":"1.2.42","9081":"7e18215204400185","9082":true,"9092":0,"9054":0,"9073":0,"9055":0,"9066":5,"9069":1509650840,"9079":0,"9071":1,"9075":0,"9076":0,"9093":0,"9077":0,"9078":0,"9106":0}
2017-11-16 11:38:26.511 [DEBUG] [o.e.s.b.t.i.TradfriCoapHandler:56 ] - CoAP response
options: {"Content-Format":"application/json", "Max-Age":604800}
payload: [65537,65536,65539,65540,65538]
2017-11-16 11:38:26.511 [DEBUG] [.s.b.t.h.TradfriGatewayHandler:263 ] - onUpdate response: [65537,65536,65539,65540,65538]
2017-11-16 11:38:26.519 [DEBUG] [o.e.s.b.t.i.TradfriCoapHandler:56 ] - CoAP response
options: {"Content-Format":"application/json", "Max-Age":604800}
payload: {"9019":1,"9001":"RGB_Lampe_01","9002":1509652759,"3":{"0":"IKEA of Sweden","6":1,"1":"TRADFRI bulb E27 CWS opal 600lm","2":"","3":"1.3.002"},"9020":1510744144,"9003":65537,"9054":0,"5750":2,"3311":[{"5850":1,"5851":254,"5707":47324,"5708":51774,"5709":13107,"5710":6554,"5706":"6c83ba","9003":0}]}
2017-11-16 11:38:26.520 [DEBUG] [.s.b.t.h.TradfriGatewayHandler:294 ] - requestDeviceDetails response: {"9019":1,"9001":"RGB_Lampe_01","9002":1509652759,"3":{"0":"IKEA of Sweden","6":1,"1":"TRADFRI bulb E27 CWS opal 600lm","2":"","3":"1.3.002"},"9020":1510744144,"9003":65537,"9054":0,"5750":2,"3311":[{"5850":1,"5851":254,"5707":47324,"5708":51774,"5709":13107,"5710":6554,"5706":"6c83ba","9003":0}]}
2017-11-16 11:38:26.526 [DEBUG] [.t.i.d.TradfriDiscoveryService:144 ] - Adding device tradfri:0210:a7caxxx:65537 to inbox
2017-11-16 11:38:26.526 [DEBUG] [s.c.d.internal.PersistentInbox:198 ] - Discovery result with thing 'tradfri:0210:a7caxxxx:65537' not added as inbox entry. It is already present as thing in the ThingRegistry.
.....
so a later call to this item sees the coapClient empty.
The update every minute as sheduled ends with : "It is already present as thing in the ThingRegistry"
So it seems that his a tradfri problem, my homematic things work without this issue.
The log is too long to be presented in the community.
Do you want to get the complete file?
P.S I did my first debuging in fortran 1966, so now I have enough time to test and check
