Add Honeynode emulator for device221
[transportpce.git] / tests / honeynode221 / log / honeycomb / honeycomb.log
1 2019-05-20 16:18:33.915 CEST [main] INFO  io.fd.honeycomb.infra.distro.Main - Starting honeycomb
2 2019-05-20 16:18:34.220 CEST [main] INFO  i.f.h.i.d.a.ActiveModuleProvider - Reading active modules configuration for distribution
3 2019-05-20 16:18:34.248 CEST [main] INFO  i.f.h.t.device.DeviceModule - Initializing Device Module
4 2019-05-20 16:18:34.259 CEST [main] INFO  i.f.h.t.d.c.DeviceConfigurationModule - Initializing Device Readers Module
5 2019-05-20 16:18:34.262 CEST [main] INFO  i.f.h.t.d.c.PmConfigurationModule - Initializing Pm Readers Module
6 2019-05-20 16:18:34.264 CEST [main] INFO  i.f.h.t.device.DeviceModule - Device Module intitailized !
7 2019-05-20 16:18:34.264 CEST [main] INFO  i.f.h.t.d.c.NetconfConfigurationModule - Initializing Netconf Readers Module
8 2019-05-20 16:18:34.266 CEST [main] INFO  i.f.h.t.device.DeviceModule - Netconf Module intitailized !
9 2019-05-20 16:18:34.268 CEST [main] INFO  i.f.h.i.d.s.YangBindingProviderModule - Configuring YangBindingProviderModule
10 2019-05-20 16:18:34.269 CEST [main] INFO  i.f.h.t.device.DeviceRpcModule - Initializing Device Rpcs Module
11 2019-05-20 16:18:34.289 CEST [main] INFO  i.f.h.t.d.DeviceNotificationModule - Initializing Device Notification Module
12 2019-05-20 16:18:34.292 CEST [main] INFO  i.f.h.t.device.DeviceWriterModule - Initializing Device Writers Module
13 2019-05-20 16:18:34.302 CEST [main] INFO  i.f.h.n.n.NetconfReadersModule - Initializing NETCONF Northbound readers
14 2019-05-20 16:18:34.305 CEST [main] INFO  i.f.h.n.netconf.NetconfModule - Starting NETCONF Northbound
15 2019-05-20 16:18:34.434 CEST [main] INFO  i.f.h.t.device.DeviceReaderModule - Initializing Device, PM and Netconf Readers Module
16 2019-05-20 16:18:34.625 CEST [main] INFO  i.f.h.i.d.a.ActiveModuleProvider - Reading active modules configuration for distribution
17 2019-05-20 16:18:34.654 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: ModuleInfoBackedCtxProvider{writerFactories=io.fd.honeycomb.infra.distro.schema.YangModulesProvider$YangModules@447a020}
18 2019-05-20 16:18:35.190 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.schema.SchemaServiceProvider@4c36250e
19 2019-05-20 16:18:35.913 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataTreeProvider$ContextDataTreeProvider@6cc558c6
20 2019-05-20 16:18:35.934 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.PersistingDataTreeProvider$ContextPersistingDataTreeProvider@63f259c3
21 2019-05-20 16:18:35.934 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.context.ModifiableDTMgrProvider@3db972d2
22 2019-05-20 16:18:35.935 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.schema.SerializerProvider@158f4cfe
23 2019-05-20 16:18:36.211 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataTreeProvider$ConfigDataTreeProvider@1e7ab390
24 2019-05-20 16:18:36.211 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.PersistingDataTreeProvider$ConfigPersistingDataTreeProvider@77774571
25 2019-05-20 16:18:36.212 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataStoreProvider@62010f5c
26 2019-05-20 16:18:36.223 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataStoreProvider@132e0cc
27 2019-05-20 16:18:36.224 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.InmemoryDOMDataBrokerProvider@4745e9c
28 2019-05-20 16:18:36.233 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.transportpce.device.DeviceBindingDataBrokerProvider@715b886f
29 2019-05-20 16:18:36.236 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.config.WriterRegistryProvider@4228bf58
30 2019-05-20 16:18:36.278 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.context.HoneycombContextDOMDataBrokerProvider@26ceffa8
31 2019-05-20 16:18:36.279 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.BindingDataBrokerProvider@4bc33720
32 2019-05-20 16:18:36.279 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.ModifiableDTDelegProvider@67064bdc
33 2019-05-20 16:18:36.280 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataStoreProvider@7c8c9a05
34 2019-05-20 16:18:36.280 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataStoreProvider@5c2375a9
35 2019-05-20 16:18:36.280 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.InmemoryDOMDataBrokerProvider@1b7a52dd
36 2019-05-20 16:18:36.280 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.BindingDataBrokerProvider@5ad5be4a
37 2019-05-20 16:18:36.280 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfMonitoringReaderFactoryProvider@737d100a
38 2019-05-20 16:18:36.281 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfNotificationsReaderFactoryProvider@3af7d855
39 2019-05-20 16:18:42.454 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.oper.ReaderRegistryProvider@1768c0b3
40 2019-05-20 16:18:42.458 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - writting xml file data to oper datastore
41 2019-05-20 16:18:42.458 CEST [main] INFO  i.f.h.t.d.t.DefaultDeviceFactory - file 'oper-XPDRA.xml' exists at location : /home/gilles/git/01/transportpce/tests/honeynode221/honeynode-distribution/target/honeynode-distribution-1.18.01-hc/honeynode-distribution-1.18.01/config/device/oper-XPDRA.xml
42 2019-05-20 16:18:42.569 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - result info : NodeIdType [_value=XPDR-A1]
43 2019-05-20 16:18:42.569 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - Getting device info from xml file for device 'XPDR-A1'
44 2019-05-20 16:18:42.646 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - WriteTransaction is ok, copy device info to oper datastore
45 2019-05-20 16:18:43.468 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - device 'XPDR-A1' writed to oper datastore
46 2019-05-20 16:18:43.468 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - writting netconf state to oper datastore
47 2019-05-20 16:18:43.469 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - Loading models from directory.
48 2019-05-20 16:18:43.469 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - folder '/home/gilles/git/01/transportpce/tests/honeynode221/honeynode-distribution/target/honeynode-distribution-1.18.01-hc/honeynode-distribution-1.18.01/config/yang' exists !
49 2019-05-20 16:18:43.771 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - WriteTransaction is ok, copy device info to oper datastore
50 2019-05-20 16:18:43.827 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - netconf state writed to oper datastore
51 2019-05-20 16:18:43.827 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - writting netconf stream to oper datastore
52 2019-05-20 16:18:43.827 CEST [main] INFO  i.f.h.t.d.t.DefaultNetconfFactory - file 'oper-XPDRA.xml' exists at location : /home/gilles/git/01/transportpce/tests/honeynode221/honeynode-distribution/target/honeynode-distribution-1.18.01-hc/honeynode-distribution-1.18.01/config/device/oper-XPDRA.xml
53 2019-05-20 16:18:43.846 CEST [main] INFO  i.f.h.t.d.c.NetconfConfiguration - netconf streams result : Streams{getStream=[Stream{getName=StreamNameType [_value=OPENROADM], augmentations={}}], augmentations={}}
54 2019-05-20 16:18:43.847 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - Netconf Data gets from xml file is present
55 2019-05-20 16:18:43.848 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - WriteTransaction is ok
56 2019-05-20 16:18:43.857 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - netconf stream writed to oper datastore
57 2019-05-20 16:18:43.857 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - loading device configuration info from xml file...
58 2019-05-20 16:18:43.857 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - process to transform xml file 
59 2019-05-20 16:18:43.860 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - transforming xml data to config device ...
60 2019-05-20 16:18:43.972 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - removing namespace ...
61 2019-05-20 16:18:43.988 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - device info gets from xml file !
62 2019-05-20 16:18:43.988 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - process to transform xml file to config data
63 2019-05-20 16:18:43.989 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - transforming xml string to config device ...
64 2019-05-20 16:18:43.997 CEST [main] INFO  i.f.h.t.d.t.DefaultDeviceFactory - device data config string is ok 
65 2019-05-20 16:18:44.002 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - result info : NodeIdType [_value=XPDR-A1]
66 2019-05-20 16:18:44.003 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - OrgOpenroadmDevice info gets : NodeIdType [_value=XPDR-A1]
67 2019-05-20 16:18:44.003 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - WriteTransaction is ok, copy device info to config datastore
68 2019-05-20 16:18:44.013 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - device writed to config datastore
69 2019-05-20 16:18:44.014 CEST [main] INFO  i.f.h.t.device.read.PmReaderFactory - writting xml pm file data to oper datastore
70 2019-05-20 16:18:44.014 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - onDataTreeChanged
71 2019-05-20 16:18:44.014 CEST [main] INFO  i.f.h.t.d.t.DefaultPmListFactory - file with pm 'oper-XPDRA.xml' exists at location : /home/gilles/git/01/transportpce/tests/honeynode221/honeynode-distribution/target/honeynode-distribution-1.18.01-hc/honeynode-distribution-1.18.01/config/device/oper-XPDRA.xml
72 2019-05-20 16:18:44.015 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - Received Device change(WRITE):
73  before=null 
74  after=OrgOpenroadmDevice{getCircuitPacks=[CircuitPacks{getCircuitPackMode=NORMAL, getCircuitPackName=1/0/3-PLUG-CLIENT, getCircuitPackProductCode=Client_P, getCircuitPackType=client_pluggable, getParentCircuitPack=ParentCircuitPack{getCircuitPackName=1/0, getCpSlotName=4, augmentations={}}, getPorts=[Ports{getAdministrativeState=InService, getPortName=C1, getPortQual=XpdrClient, getPortType=QSFP28, augmentations={}}], getShelf=1, getSlot=1, getSubSlot=1, augmentations={}}, CircuitPacks{getAdministrativeState=InService, getCircuitPackMode=inServiceMode, getCircuitPackName=1/0, getCircuitPackProductCode=baseXPDR, getCircuitPackType=Base_transponder_circuit_pack, getShelf=1, getSlot=1, augmentations={}}, CircuitPacks{getCircuitPackMode=NORMAL, getCircuitPackName=1/0/1-PLUG-CLIENT, getCircuitPackProductCode=Client_P, getCircuitPackType=client_pluggable, getParentCircuitPack=ParentCircuitPack{getCircuitPackName=1/0, getCpSlotName=2, augmentations={}}, getPorts=[Ports{getAdministrativeState=InService, getPortName=C1, getPortQual=XpdrClient, getPortType=QSFP28, augmentations={}}], getShelf=1, getSlot=1, getSubSlot=1, augmentations={}}, CircuitPacks{getCircuitPackMode=NORMAL, getCircuitPackName=1/0/1-PLUG-NET, getCircuitPackProductCode=Line_NW_P, getCircuitPackType=line_pluggable, getParentCircuitPack=ParentCircuitPack{getCircuitPackName=1/0, getCpSlotName=1, augmentations={}}, getPorts=[Ports{getAdministrativeState=InService, getPortName=1, getPortQual=XpdrNetwork, getPortType=CFP2, augmentations={}}], getShelf=1, getSlot=1, getSubSlot=1, augmentations={}}, CircuitPacks{getCircuitPackMode=NORMAL, getCircuitPackName=1/0/2-PLUG-NET, getCircuitPackProductCode=Line_NW_P, getCircuitPackType=line_pluggable, getParentCircuitPack=ParentCircuitPack{getCircuitPackName=1/0, getCpSlotName=3, augmentations={}}, getPorts=[Ports{getAdministrativeState=InService, getPortName=1, getPortQual=XpdrNetwork, getPortType=CFP2, augmentations={}}], getShelf=1, getSlot=1, getSubSlot=1, augmentations={}}], getInfo=Info{getClli=NodeC, getDefaultGateway=IpAddress [_ipv4Address=Ipv4Address [_value=1.2.3.4]], getGeoLocation=GeoLocation{getLatitude=1.0000, getLongitude=2.0000, augmentations={}}, getIpAddress=IpAddress [_ipv4Address=Ipv4Address [_value=1.2.3.4]], getNodeId=NodeIdType [_value=XPDR-A1], getNodeNumber=1, getNodeType=Xpdr, getPrefixLength=24, getTemplate=template_TRANSPONDER, augmentations={}}, getShelves=[Shelves{getAdministrativeState=InService, getDueDate=DateAndTime [_value=2017-02-24T15:56:10+00:00], getRack=XYZ, getShelfName=1, getShelfPosition=1, getShelfType=pizza, augmentations={}}], getUsers=Users{getUser=[User{getGroup=Sudo, getName=UsernameType [_value=openroadm], getPassword=PasswordType [_value=openroadm], augmentations={}}], augmentations={}}, augmentations={}}
75 2019-05-20 16:18:44.025 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - processing change ...
76 2019-05-20 16:18:44.025 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - WriteTransactions are ok, merge device info to datastores
77 2019-05-20 16:18:44.031 CEST [main] INFO  i.f.h.t.d.c.PmConfiguration - result pm list size : 1
78 2019-05-20 16:18:44.031 CEST [main] INFO  i.f.h.t.device.read.PmReaderFactory - Getting pm info from xml file for device 
79 2019-05-20 16:18:44.032 CEST [main] INFO  i.f.h.t.device.read.PmReaderFactory - WriteTransaction is ok, copy currentPmList to oper datastore
80 2019-05-20 16:18:44.033 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - device 'XPDR-A1' merged to device oper datastore
81 2019-05-20 16:18:44.083 CEST [main] INFO  i.f.h.t.device.read.PmReaderFactory - currentPmList writed to oper datastore
82 2019-05-20 16:18:44.090 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.oper.ReadableDTDelegProvider@121bacf4
83 2019-05-20 16:18:44.093 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfBindingBrokerProvider@258cb16c
84 2019-05-20 16:18:44.094 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfNotificationMapperProvider@2966695e
85 2019-05-20 16:18:44.102 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.RpcRegistryBuilderProvider@1d8264c9
86 2019-05-20 16:18:44.103 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.RpcRegistryProvider@59e182
87 2019-05-20 16:18:44.104 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.HoneycombDOMRpcServiceProvider@138c53c7
88 2019-05-20 16:18:44.105 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfMdsalMapperProvider@1eee885c
89 2019-05-20 16:18:44.116 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfMonitoringServiceProvider@61ed43ae
90 2019-05-20 16:18:44.128 CEST [main] INFO  o.o.n.i.o.NetconfSessionMonitoringService - Scheduling thread pool is present = false, update interval 0: /netconf-state/sessions won't be updated.
91 2019-05-20 16:18:44.129 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfMonitoringMapperProvider@655936bd
92 2019-05-20 16:18:44.150 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DOMNotificationServiceProvider@647407b4
93 2019-05-20 16:18:44.162 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.HoneycombNotificationManagerProvider@b6b8632
94 2019-05-20 16:18:44.165 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.HoneycombNotification2NetconfProvider@52b31599
95 2019-05-20 16:18:44.172 CEST [main] INFO  i.f.h.n.n.HoneycombNotification2NetconfProvider - Exposing HONEYCOMB_NETCONF notification stream: honeycomb
96 2019-05-20 16:18:44.172 CEST [pool-18-thread-3] INFO  i.f.h.t.d.n.DeviceNotificationProducer - Starting notification stream for OrgOpenroadmDevice
97 2019-05-20 16:18:44.173 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NettyThreadGroupProvider@66df0533
98 2019-05-20 16:18:44.174 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - onDataTreeChanged
99 2019-05-20 16:18:44.174 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - transforming changes to notification...
100 2019-05-20 16:18:44.174 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - Received Device change :
101 WRITE
102 2019-05-20 16:18:44.175 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - device operational datastore is created !
103 2019-05-20 16:18:44.175 CEST [operational-DCL-0] WARN  i.f.h.t.d.n.DeviceNotificationProducer - edit List is empty !
104 2019-05-20 16:18:44.175 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - Emitting notification : null
105 2019-05-20 16:18:44.175 CEST [operational-DCL-0] WARN  i.f.h.t.d.n.DeviceNotificationProducer - Failed to emit notification
106 2019-05-20 16:18:44.208 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfServerDispatcherProvider@519910b2
107 2019-05-20 16:18:44.212 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfTcpServerProvider@273b3afc
108 2019-05-20 16:18:44.213 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfSshServerProvider@444dac3f
109 2019-05-20 16:18:44.213 CEST [main] INFO  i.f.h.n.n.NetconfSshServerProvider - Starting NETCONF SSH
110 2019-05-20 16:18:44.273 CEST [main] WARN  io.netty.bootstrap.ServerBootstrap - Unknown channel option 'SO_BACKLOG' for channel '[id: 0x17b553fd]'
111 2019-05-20 16:18:44.545 CEST [main] INFO  io.fd.honeycomb.infra.distro.Main - Initializing configuration
112 2019-05-20 16:18:44.545 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.context.PersistedContextInitializerProvider@226ddb69
113 2019-05-20 16:18:44.547 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.PersistedConfigInitializerProvider@5f666412
114 2019-05-20 16:18:44.547 CEST [main] INFO  i.f.h.i.d.d.PersistedConfigInitializerProvider - RestoringInitializer ...
115 2019-05-20 16:18:44.547 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.initializer.ModifiableDTDelegInitProvider@1ce6c617
116 2019-05-20 16:18:44.548 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.HoneycombDOMDataBrokerProvider@2d1e3187
117 2019-05-20 16:18:44.548 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.BindingDataBrokerProvider@26308d2a
118 2019-05-20 16:18:44.548 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.context.RealtimeMappingContextProvider@38f3ef54
119 2019-05-20 16:18:44.549 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.initializer.InitializerRegistryAdapterProvider@f32397
120 2019-05-20 16:18:44.549 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Config initialization started
121 2019-05-20 16:18:44.549 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Persisted context restored successfully
122 2019-05-20 16:18:44.550 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Configuration initialized successfully
123 2019-05-20 16:18:44.550 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Persisted configuration restored successfully
124 2019-05-20 16:18:44.550 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Honeycomb initialized
125 2019-05-20 16:18:44.550 CEST [main] INFO  io.fd.honeycomb.infra.distro.Main - Configuration initialized successfully
126 2019-05-20 16:18:44.550 CEST [main] INFO  io.fd.honeycomb.infra.distro.Main - Honeycomb started successfully!
127 2019-05-20 16:18:44.629 CEST [netconf-netty-0] INFO  i.f.h.n.n.NetconfSshServerProvider - Netconf SSH endpoint started successfully at /0.0.0.0:17840
128 2019-05-20 16:19:32.923 CEST [main] INFO  io.fd.honeycomb.infra.distro.Main - Starting honeycomb
129 2019-05-20 16:19:33.233 CEST [main] INFO  i.f.h.i.d.a.ActiveModuleProvider - Reading active modules configuration for distribution
130 2019-05-20 16:19:33.261 CEST [main] INFO  i.f.h.t.device.DeviceModule - Initializing Device Module
131 2019-05-20 16:19:33.272 CEST [main] INFO  i.f.h.t.d.c.DeviceConfigurationModule - Initializing Device Readers Module
132 2019-05-20 16:19:33.275 CEST [main] INFO  i.f.h.t.d.c.PmConfigurationModule - Initializing Pm Readers Module
133 2019-05-20 16:19:33.278 CEST [main] INFO  i.f.h.t.device.DeviceModule - Device Module intitailized !
134 2019-05-20 16:19:33.278 CEST [main] INFO  i.f.h.t.d.c.NetconfConfigurationModule - Initializing Netconf Readers Module
135 2019-05-20 16:19:33.280 CEST [main] INFO  i.f.h.t.device.DeviceModule - Netconf Module intitailized !
136 2019-05-20 16:19:33.281 CEST [main] INFO  i.f.h.i.d.s.YangBindingProviderModule - Configuring YangBindingProviderModule
137 2019-05-20 16:19:33.283 CEST [main] INFO  i.f.h.t.device.DeviceRpcModule - Initializing Device Rpcs Module
138 2019-05-20 16:19:33.304 CEST [main] INFO  i.f.h.t.d.DeviceNotificationModule - Initializing Device Notification Module
139 2019-05-20 16:19:33.306 CEST [main] INFO  i.f.h.t.device.DeviceWriterModule - Initializing Device Writers Module
140 2019-05-20 16:19:33.316 CEST [main] INFO  i.f.h.n.n.NetconfReadersModule - Initializing NETCONF Northbound readers
141 2019-05-20 16:19:33.319 CEST [main] INFO  i.f.h.n.netconf.NetconfModule - Starting NETCONF Northbound
142 2019-05-20 16:19:33.450 CEST [main] INFO  i.f.h.t.device.DeviceReaderModule - Initializing Device, PM and Netconf Readers Module
143 2019-05-20 16:19:33.647 CEST [main] INFO  i.f.h.i.d.a.ActiveModuleProvider - Reading active modules configuration for distribution
144 2019-05-20 16:19:33.677 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: ModuleInfoBackedCtxProvider{writerFactories=io.fd.honeycomb.infra.distro.schema.YangModulesProvider$YangModules@447a020}
145 2019-05-20 16:19:34.212 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.schema.SchemaServiceProvider@4c36250e
146 2019-05-20 16:19:34.946 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataTreeProvider$ContextDataTreeProvider@6cc558c6
147 2019-05-20 16:19:34.967 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.PersistingDataTreeProvider$ContextPersistingDataTreeProvider@63f259c3
148 2019-05-20 16:19:34.967 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.context.ModifiableDTMgrProvider@3db972d2
149 2019-05-20 16:19:34.968 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.schema.SerializerProvider@158f4cfe
150 2019-05-20 16:19:35.255 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataTreeProvider$ConfigDataTreeProvider@77774571
151 2019-05-20 16:19:35.255 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.PersistingDataTreeProvider$ConfigPersistingDataTreeProvider@6cd64ee8
152 2019-05-20 16:19:35.256 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataStoreProvider@62010f5c
153 2019-05-20 16:19:35.268 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataStoreProvider@132e0cc
154 2019-05-20 16:19:35.268 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.InmemoryDOMDataBrokerProvider@75de29c0
155 2019-05-20 16:19:35.277 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.transportpce.device.DeviceBindingDataBrokerProvider@1e253c9d
156 2019-05-20 16:19:35.281 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.config.WriterRegistryProvider@20b9d5d5
157 2019-05-20 16:19:35.322 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.context.HoneycombContextDOMDataBrokerProvider@26ceffa8
158 2019-05-20 16:19:35.322 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.BindingDataBrokerProvider@67064bdc
159 2019-05-20 16:19:35.322 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.ModifiableDTDelegProvider@18578491
160 2019-05-20 16:19:35.323 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataStoreProvider@7c8c9a05
161 2019-05-20 16:19:35.323 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataStoreProvider@5c2375a9
162 2019-05-20 16:19:35.324 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.InmemoryDOMDataBrokerProvider@5ad5be4a
163 2019-05-20 16:19:35.324 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.BindingDataBrokerProvider@737d100a
164 2019-05-20 16:19:35.324 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfMonitoringReaderFactoryProvider@6535117e
165 2019-05-20 16:19:35.324 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfNotificationsReaderFactoryProvider@f88bfbe
166 2019-05-20 16:19:40.467 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.oper.ReaderRegistryProvider@287213ac
167 2019-05-20 16:19:40.471 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - writting xml file data to oper datastore
168 2019-05-20 16:19:40.471 CEST [main] INFO  i.f.h.t.d.t.DefaultDeviceFactory - file 'oper-XPDRA.xml' exists at location : /home/gilles/git/01/transportpce/tests/honeynode221/honeynode-distribution/target/honeynode-distribution-1.18.01-hc/honeynode-distribution-1.18.01/config/device/oper-XPDRA.xml
169 2019-05-20 16:19:40.568 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - result info : NodeIdType [_value=XPDR-A1]
170 2019-05-20 16:19:40.568 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - Getting device info from xml file for device 'XPDR-A1'
171 2019-05-20 16:19:40.621 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - WriteTransaction is ok, copy device info to oper datastore
172 2019-05-20 16:19:40.967 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - device 'XPDR-A1' writed to oper datastore
173 2019-05-20 16:19:40.967 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - writting netconf state to oper datastore
174 2019-05-20 16:19:40.967 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - Loading models from directory.
175 2019-05-20 16:19:40.968 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - folder '/home/gilles/git/01/transportpce/tests/honeynode221/honeynode-distribution/target/honeynode-distribution-1.18.01-hc/honeynode-distribution-1.18.01/config/yang' exists !
176 2019-05-20 16:19:41.211 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - WriteTransaction is ok, copy device info to oper datastore
177 2019-05-20 16:19:41.271 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - netconf state writed to oper datastore
178 2019-05-20 16:19:41.271 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - writting netconf stream to oper datastore
179 2019-05-20 16:19:41.272 CEST [main] INFO  i.f.h.t.d.t.DefaultNetconfFactory - file 'oper-XPDRA.xml' exists at location : /home/gilles/git/01/transportpce/tests/honeynode221/honeynode-distribution/target/honeynode-distribution-1.18.01-hc/honeynode-distribution-1.18.01/config/device/oper-XPDRA.xml
180 2019-05-20 16:19:41.299 CEST [main] INFO  i.f.h.t.d.c.NetconfConfiguration - netconf streams result : Streams{getStream=[Stream{getName=StreamNameType [_value=OPENROADM], augmentations={}}], augmentations={}}
181 2019-05-20 16:19:41.302 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - Netconf Data gets from xml file is present
182 2019-05-20 16:19:41.303 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - WriteTransaction is ok
183 2019-05-20 16:19:41.313 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - netconf stream writed to oper datastore
184 2019-05-20 16:19:41.313 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - loading device configuration info from xml file...
185 2019-05-20 16:19:41.313 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - process to transform xml file 
186 2019-05-20 16:19:41.316 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - transforming xml data to config device ...
187 2019-05-20 16:19:41.435 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - removing namespace ...
188 2019-05-20 16:19:41.451 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - device info gets from xml file !
189 2019-05-20 16:19:41.452 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - process to transform xml file to config data
190 2019-05-20 16:19:41.452 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - transforming xml string to config device ...
191 2019-05-20 16:19:41.462 CEST [main] INFO  i.f.h.t.d.t.DefaultDeviceFactory - device data config string is ok 
192 2019-05-20 16:19:41.467 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - result info : NodeIdType [_value=XPDR-A1]
193 2019-05-20 16:19:41.467 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - OrgOpenroadmDevice info gets : NodeIdType [_value=XPDR-A1]
194 2019-05-20 16:19:41.467 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - WriteTransaction is ok, copy device info to config datastore
195 2019-05-20 16:19:41.477 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - device writed to config datastore
196 2019-05-20 16:19:41.477 CEST [main] INFO  i.f.h.t.device.read.PmReaderFactory - writting xml pm file data to oper datastore
197 2019-05-20 16:19:41.477 CEST [main] INFO  i.f.h.t.d.t.DefaultPmListFactory - file with pm 'oper-XPDRA.xml' exists at location : /home/gilles/git/01/transportpce/tests/honeynode221/honeynode-distribution/target/honeynode-distribution-1.18.01-hc/honeynode-distribution-1.18.01/config/device/oper-XPDRA.xml
198 2019-05-20 16:19:41.478 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - onDataTreeChanged
199 2019-05-20 16:19:41.480 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - Received Device change(WRITE):
200  before=null 
201  after=OrgOpenroadmDevice{getCircuitPacks=[CircuitPacks{getCircuitPackMode=NORMAL, getCircuitPackName=1/0/3-PLUG-CLIENT, getCircuitPackProductCode=Client_P, getCircuitPackType=client_pluggable, getParentCircuitPack=ParentCircuitPack{getCircuitPackName=1/0, getCpSlotName=4, augmentations={}}, getPorts=[Ports{getAdministrativeState=InService, getPortName=C1, getPortQual=XpdrClient, getPortType=QSFP28, augmentations={}}], getShelf=1, getSlot=1, getSubSlot=1, augmentations={}}, CircuitPacks{getAdministrativeState=InService, getCircuitPackMode=inServiceMode, getCircuitPackName=1/0, getCircuitPackProductCode=baseXPDR, getCircuitPackType=Base_transponder_circuit_pack, getShelf=1, getSlot=1, augmentations={}}, CircuitPacks{getCircuitPackMode=NORMAL, getCircuitPackName=1/0/1-PLUG-CLIENT, getCircuitPackProductCode=Client_P, getCircuitPackType=client_pluggable, getParentCircuitPack=ParentCircuitPack{getCircuitPackName=1/0, getCpSlotName=2, augmentations={}}, getPorts=[Ports{getAdministrativeState=InService, getPortName=C1, getPortQual=XpdrClient, getPortType=QSFP28, augmentations={}}], getShelf=1, getSlot=1, getSubSlot=1, augmentations={}}, CircuitPacks{getCircuitPackMode=NORMAL, getCircuitPackName=1/0/1-PLUG-NET, getCircuitPackProductCode=Line_NW_P, getCircuitPackType=line_pluggable, getParentCircuitPack=ParentCircuitPack{getCircuitPackName=1/0, getCpSlotName=1, augmentations={}}, getPorts=[Ports{getAdministrativeState=InService, getPortName=1, getPortQual=XpdrNetwork, getPortType=CFP2, augmentations={}}], getShelf=1, getSlot=1, getSubSlot=1, augmentations={}}, CircuitPacks{getCircuitPackMode=NORMAL, getCircuitPackName=1/0/2-PLUG-NET, getCircuitPackProductCode=Line_NW_P, getCircuitPackType=line_pluggable, getParentCircuitPack=ParentCircuitPack{getCircuitPackName=1/0, getCpSlotName=3, augmentations={}}, getPorts=[Ports{getAdministrativeState=InService, getPortName=1, getPortQual=XpdrNetwork, getPortType=CFP2, augmentations={}}], getShelf=1, getSlot=1, getSubSlot=1, augmentations={}}], getInfo=Info{getClli=NodeC, getDefaultGateway=IpAddress [_ipv4Address=Ipv4Address [_value=1.2.3.4]], getGeoLocation=GeoLocation{getLatitude=1.0000, getLongitude=2.0000, augmentations={}}, getIpAddress=IpAddress [_ipv4Address=Ipv4Address [_value=1.2.3.4]], getNodeId=NodeIdType [_value=XPDR-A1], getNodeNumber=1, getNodeType=Xpdr, getPrefixLength=24, getTemplate=template_TRANSPONDER, augmentations={}}, getShelves=[Shelves{getAdministrativeState=InService, getDueDate=DateAndTime [_value=2017-02-24T15:56:10+00:00], getRack=XYZ, getShelfName=1, getShelfPosition=1, getShelfType=pizza, augmentations={}}], getUsers=Users{getUser=[User{getGroup=Sudo, getName=UsernameType [_value=openroadm], getPassword=PasswordType [_value=openroadm], augmentations={}}], augmentations={}}, augmentations={}}
202 2019-05-20 16:19:41.491 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - processing change ...
203 2019-05-20 16:19:41.491 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - WriteTransactions are ok, merge device info to datastores
204 2019-05-20 16:19:41.495 CEST [main] INFO  i.f.h.t.d.c.PmConfiguration - result pm list size : 1
205 2019-05-20 16:19:41.495 CEST [main] INFO  i.f.h.t.device.read.PmReaderFactory - Getting pm info from xml file for device 
206 2019-05-20 16:19:41.495 CEST [main] INFO  i.f.h.t.device.read.PmReaderFactory - WriteTransaction is ok, copy currentPmList to oper datastore
207 2019-05-20 16:19:41.500 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - device 'XPDR-A1' merged to device oper datastore
208 2019-05-20 16:19:41.533 CEST [main] INFO  i.f.h.t.device.read.PmReaderFactory - currentPmList writed to oper datastore
209 2019-05-20 16:19:41.542 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.oper.ReadableDTDelegProvider@2954dc9e
210 2019-05-20 16:19:41.545 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfBindingBrokerProvider@52b44e58
211 2019-05-20 16:19:41.547 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfNotificationMapperProvider@21ae26b0
212 2019-05-20 16:19:41.555 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.RpcRegistryBuilderProvider@300f2857
213 2019-05-20 16:19:41.556 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.RpcRegistryProvider@5f1495c6
214 2019-05-20 16:19:41.557 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.HoneycombDOMRpcServiceProvider@4b0d7cb5
215 2019-05-20 16:19:41.558 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfMdsalMapperProvider@dda90c0
216 2019-05-20 16:19:41.570 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfMonitoringServiceProvider@71993eba
217 2019-05-20 16:19:41.583 CEST [main] INFO  o.o.n.i.o.NetconfSessionMonitoringService - Scheduling thread pool is present = false, update interval 0: /netconf-state/sessions won't be updated.
218 2019-05-20 16:19:41.584 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfMonitoringMapperProvider@2298e5d2
219 2019-05-20 16:19:41.607 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DOMNotificationServiceProvider@2596ae35
220 2019-05-20 16:19:41.620 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.HoneycombNotificationManagerProvider@6a7488a0
221 2019-05-20 16:19:41.627 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.HoneycombNotification2NetconfProvider@b6b8632
222 2019-05-20 16:19:41.634 CEST [main] INFO  i.f.h.n.n.HoneycombNotification2NetconfProvider - Exposing HONEYCOMB_NETCONF notification stream: honeycomb
223 2019-05-20 16:19:41.634 CEST [pool-18-thread-3] INFO  i.f.h.t.d.n.DeviceNotificationProducer - Starting notification stream for OrgOpenroadmDevice
224 2019-05-20 16:19:41.635 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NettyThreadGroupProvider@4bfe0b18
225 2019-05-20 16:19:41.637 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - onDataTreeChanged
226 2019-05-20 16:19:41.637 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - transforming changes to notification...
227 2019-05-20 16:19:41.637 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - Received Device change :
228 WRITE
229 2019-05-20 16:19:41.638 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - device operational datastore is created !
230 2019-05-20 16:19:41.638 CEST [operational-DCL-0] WARN  i.f.h.t.d.n.DeviceNotificationProducer - edit List is empty !
231 2019-05-20 16:19:41.638 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - Emitting notification : null
232 2019-05-20 16:19:41.638 CEST [operational-DCL-0] WARN  i.f.h.t.d.n.DeviceNotificationProducer - Failed to emit notification
233 2019-05-20 16:19:41.701 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfServerDispatcherProvider@4b74fb68
234 2019-05-20 16:19:41.707 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfTcpServerProvider@4f251b32
235 2019-05-20 16:19:41.709 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfSshServerProvider@52565dea
236 2019-05-20 16:19:41.709 CEST [main] INFO  i.f.h.n.n.NetconfSshServerProvider - Starting NETCONF SSH
237 2019-05-20 16:19:41.797 CEST [main] WARN  io.netty.bootstrap.ServerBootstrap - Unknown channel option 'SO_BACKLOG' for channel '[id: 0xf039ef03]'
238 2019-05-20 16:19:42.113 CEST [main] INFO  io.fd.honeycomb.infra.distro.Main - Initializing configuration
239 2019-05-20 16:19:42.113 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.context.PersistedContextInitializerProvider@150658c8
240 2019-05-20 16:19:42.115 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.PersistedConfigInitializerProvider@5dadf7d9
241 2019-05-20 16:19:42.115 CEST [main] INFO  i.f.h.i.d.d.PersistedConfigInitializerProvider - RestoringInitializer ...
242 2019-05-20 16:19:42.115 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.initializer.ModifiableDTDelegInitProvider@5a1f3003
243 2019-05-20 16:19:42.116 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.HoneycombDOMDataBrokerProvider@649b0336
244 2019-05-20 16:19:42.116 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.BindingDataBrokerProvider@3e666559
245 2019-05-20 16:19:42.116 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.context.RealtimeMappingContextProvider@461e3e5
246 2019-05-20 16:19:42.117 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.initializer.InitializerRegistryAdapterProvider@6179761f
247 2019-05-20 16:19:42.117 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Config initialization started
248 2019-05-20 16:19:42.117 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Persisted context restored successfully
249 2019-05-20 16:19:42.118 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Configuration initialized successfully
250 2019-05-20 16:19:42.118 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Persisted configuration restored successfully
251 2019-05-20 16:19:42.118 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Honeycomb initialized
252 2019-05-20 16:19:42.118 CEST [main] INFO  io.fd.honeycomb.infra.distro.Main - Configuration initialized successfully
253 2019-05-20 16:19:42.118 CEST [main] INFO  io.fd.honeycomb.infra.distro.Main - Honeycomb started successfully!
254 2019-05-20 16:19:42.208 CEST [netconf-netty-0] INFO  i.f.h.n.n.NetconfSshServerProvider - Netconf SSH endpoint started successfully at /0.0.0.0:17841
255 2019-05-20 16:22:00.815 CEST [Thread-5] INFO  i.f.h.impl.ShutdownHandlerImpl - Closing component notification-to-mdsal-writer
256 2019-05-20 16:22:00.816 CEST [Thread-5] INFO  i.f.h.impl.ShutdownHandlerImpl - Closing component netconf-notification-service-factory
257 2019-05-20 16:22:03.327 CEST [main] INFO  io.fd.honeycomb.infra.distro.Main - Starting honeycomb
258 2019-05-20 16:22:03.626 CEST [main] INFO  i.f.h.i.d.a.ActiveModuleProvider - Reading active modules configuration for distribution
259 2019-05-20 16:22:03.654 CEST [main] INFO  i.f.h.t.device.DeviceModule - Initializing Device Module
260 2019-05-20 16:22:03.664 CEST [main] INFO  i.f.h.t.d.c.DeviceConfigurationModule - Initializing Device Readers Module
261 2019-05-20 16:22:03.667 CEST [main] INFO  i.f.h.t.d.c.PmConfigurationModule - Initializing Pm Readers Module
262 2019-05-20 16:22:03.670 CEST [main] INFO  i.f.h.t.device.DeviceModule - Device Module intitailized !
263 2019-05-20 16:22:03.670 CEST [main] INFO  i.f.h.t.d.c.NetconfConfigurationModule - Initializing Netconf Readers Module
264 2019-05-20 16:22:03.672 CEST [main] INFO  i.f.h.t.device.DeviceModule - Netconf Module intitailized !
265 2019-05-20 16:22:03.673 CEST [main] INFO  i.f.h.i.d.s.YangBindingProviderModule - Configuring YangBindingProviderModule
266 2019-05-20 16:22:03.675 CEST [main] INFO  i.f.h.t.device.DeviceRpcModule - Initializing Device Rpcs Module
267 2019-05-20 16:22:03.695 CEST [main] INFO  i.f.h.t.d.DeviceNotificationModule - Initializing Device Notification Module
268 2019-05-20 16:22:03.697 CEST [main] INFO  i.f.h.t.device.DeviceWriterModule - Initializing Device Writers Module
269 2019-05-20 16:22:03.707 CEST [main] INFO  i.f.h.n.n.NetconfReadersModule - Initializing NETCONF Northbound readers
270 2019-05-20 16:22:03.710 CEST [main] INFO  i.f.h.n.netconf.NetconfModule - Starting NETCONF Northbound
271 2019-05-20 16:22:03.835 CEST [main] INFO  i.f.h.t.device.DeviceReaderModule - Initializing Device, PM and Netconf Readers Module
272 2019-05-20 16:22:04.025 CEST [main] INFO  i.f.h.i.d.a.ActiveModuleProvider - Reading active modules configuration for distribution
273 2019-05-20 16:22:04.055 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: ModuleInfoBackedCtxProvider{writerFactories=io.fd.honeycomb.infra.distro.schema.YangModulesProvider$YangModules@447a020}
274 2019-05-20 16:22:04.610 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.schema.SchemaServiceProvider@4c36250e
275 2019-05-20 16:22:05.378 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataTreeProvider$ContextDataTreeProvider@6cc558c6
276 2019-05-20 16:22:05.400 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.PersistingDataTreeProvider$ContextPersistingDataTreeProvider@63f259c3
277 2019-05-20 16:22:05.401 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.context.ModifiableDTMgrProvider@3db972d2
278 2019-05-20 16:22:05.401 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.schema.SerializerProvider@158f4cfe
279 2019-05-20 16:22:05.705 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataTreeProvider$ConfigDataTreeProvider@77774571
280 2019-05-20 16:22:05.705 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.PersistingDataTreeProvider$ConfigPersistingDataTreeProvider@6cd64ee8
281 2019-05-20 16:22:05.706 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataStoreProvider@62010f5c
282 2019-05-20 16:22:05.717 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataStoreProvider@132e0cc
283 2019-05-20 16:22:05.718 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.InmemoryDOMDataBrokerProvider@75de29c0
284 2019-05-20 16:22:05.727 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.transportpce.device.DeviceBindingDataBrokerProvider@1e253c9d
285 2019-05-20 16:22:05.730 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.config.WriterRegistryProvider@20b9d5d5
286 2019-05-20 16:22:05.771 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.context.HoneycombContextDOMDataBrokerProvider@26ceffa8
287 2019-05-20 16:22:05.771 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.BindingDataBrokerProvider@67064bdc
288 2019-05-20 16:22:05.771 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.ModifiableDTDelegProvider@18578491
289 2019-05-20 16:22:05.772 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataStoreProvider@7c8c9a05
290 2019-05-20 16:22:05.773 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataStoreProvider@5c2375a9
291 2019-05-20 16:22:05.773 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.InmemoryDOMDataBrokerProvider@5ad5be4a
292 2019-05-20 16:22:05.773 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.BindingDataBrokerProvider@737d100a
293 2019-05-20 16:22:05.773 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfMonitoringReaderFactoryProvider@6535117e
294 2019-05-20 16:22:05.773 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfNotificationsReaderFactoryProvider@f88bfbe
295 2019-05-20 16:22:10.983 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.oper.ReaderRegistryProvider@380d3099
296 2019-05-20 16:22:10.988 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - writting xml file data to oper datastore
297 2019-05-20 16:22:10.988 CEST [main] INFO  i.f.h.t.d.t.DefaultDeviceFactory - file 'oper-XPDRA.xml' exists at location : /home/gilles/git/01/transportpce/tests/honeynode221/honeynode-distribution/target/honeynode-distribution-1.18.01-hc/honeynode-distribution-1.18.01/config/device/oper-XPDRA.xml
298 2019-05-20 16:22:11.085 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - result info : NodeIdType [_value=XPDR-A1]
299 2019-05-20 16:22:11.085 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - Getting device info from xml file for device 'XPDR-A1'
300 2019-05-20 16:22:11.138 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - WriteTransaction is ok, copy device info to oper datastore
301 2019-05-20 16:22:11.524 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - device 'XPDR-A1' writed to oper datastore
302 2019-05-20 16:22:11.524 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - writting netconf state to oper datastore
303 2019-05-20 16:22:11.525 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - Loading models from directory.
304 2019-05-20 16:22:11.525 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - folder '/home/gilles/git/01/transportpce/tests/honeynode221/honeynode-distribution/target/honeynode-distribution-1.18.01-hc/honeynode-distribution-1.18.01/config/yang' exists !
305 2019-05-20 16:22:11.739 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - WriteTransaction is ok, copy device info to oper datastore
306 2019-05-20 16:22:11.794 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - netconf state writed to oper datastore
307 2019-05-20 16:22:11.794 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - writting netconf stream to oper datastore
308 2019-05-20 16:22:11.795 CEST [main] INFO  i.f.h.t.d.t.DefaultNetconfFactory - file 'oper-XPDRA.xml' exists at location : /home/gilles/git/01/transportpce/tests/honeynode221/honeynode-distribution/target/honeynode-distribution-1.18.01-hc/honeynode-distribution-1.18.01/config/device/oper-XPDRA.xml
309 2019-05-20 16:22:11.823 CEST [main] INFO  i.f.h.t.d.c.NetconfConfiguration - netconf streams result : Streams{getStream=[Stream{getName=StreamNameType [_value=OPENROADM], augmentations={}}], augmentations={}}
310 2019-05-20 16:22:11.825 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - Netconf Data gets from xml file is present
311 2019-05-20 16:22:11.826 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - WriteTransaction is ok
312 2019-05-20 16:22:11.835 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - netconf stream writed to oper datastore
313 2019-05-20 16:22:11.835 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - loading device configuration info from xml file...
314 2019-05-20 16:22:11.835 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - process to transform xml file 
315 2019-05-20 16:22:11.838 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - transforming xml data to config device ...
316 2019-05-20 16:22:11.957 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - removing namespace ...
317 2019-05-20 16:22:11.974 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - device info gets from xml file !
318 2019-05-20 16:22:11.974 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - process to transform xml file to config data
319 2019-05-20 16:22:11.975 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - transforming xml string to config device ...
320 2019-05-20 16:22:11.984 CEST [main] INFO  i.f.h.t.d.t.DefaultDeviceFactory - device data config string is ok 
321 2019-05-20 16:22:11.990 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - result info : NodeIdType [_value=XPDR-A1]
322 2019-05-20 16:22:11.990 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - OrgOpenroadmDevice info gets : NodeIdType [_value=XPDR-A1]
323 2019-05-20 16:22:11.990 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - WriteTransaction is ok, copy device info to config datastore
324 2019-05-20 16:22:12.000 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - device writed to config datastore
325 2019-05-20 16:22:12.001 CEST [main] INFO  i.f.h.t.device.read.PmReaderFactory - writting xml pm file data to oper datastore
326 2019-05-20 16:22:12.001 CEST [main] INFO  i.f.h.t.d.t.DefaultPmListFactory - file with pm 'oper-XPDRA.xml' exists at location : /home/gilles/git/01/transportpce/tests/honeynode221/honeynode-distribution/target/honeynode-distribution-1.18.01-hc/honeynode-distribution-1.18.01/config/device/oper-XPDRA.xml
327 2019-05-20 16:22:12.001 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - onDataTreeChanged
328 2019-05-20 16:22:12.002 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - Received Device change(WRITE):
329  before=null 
330  after=OrgOpenroadmDevice{getCircuitPacks=[CircuitPacks{getCircuitPackMode=NORMAL, getCircuitPackName=1/0/3-PLUG-CLIENT, getCircuitPackProductCode=Client_P, getCircuitPackType=client_pluggable, getParentCircuitPack=ParentCircuitPack{getCircuitPackName=1/0, getCpSlotName=4, augmentations={}}, getPorts=[Ports{getAdministrativeState=InService, getPortName=C1, getPortQual=XpdrClient, getPortType=QSFP28, augmentations={}}], getShelf=1, getSlot=1, getSubSlot=1, augmentations={}}, CircuitPacks{getAdministrativeState=InService, getCircuitPackMode=inServiceMode, getCircuitPackName=1/0, getCircuitPackProductCode=baseXPDR, getCircuitPackType=Base_transponder_circuit_pack, getShelf=1, getSlot=1, augmentations={}}, CircuitPacks{getCircuitPackMode=NORMAL, getCircuitPackName=1/0/1-PLUG-CLIENT, getCircuitPackProductCode=Client_P, getCircuitPackType=client_pluggable, getParentCircuitPack=ParentCircuitPack{getCircuitPackName=1/0, getCpSlotName=2, augmentations={}}, getPorts=[Ports{getAdministrativeState=InService, getPortName=C1, getPortQual=XpdrClient, getPortType=QSFP28, augmentations={}}], getShelf=1, getSlot=1, getSubSlot=1, augmentations={}}, CircuitPacks{getCircuitPackMode=NORMAL, getCircuitPackName=1/0/1-PLUG-NET, getCircuitPackProductCode=Line_NW_P, getCircuitPackType=line_pluggable, getParentCircuitPack=ParentCircuitPack{getCircuitPackName=1/0, getCpSlotName=1, augmentations={}}, getPorts=[Ports{getAdministrativeState=InService, getPortName=1, getPortQual=XpdrNetwork, getPortType=CFP2, augmentations={}}], getShelf=1, getSlot=1, getSubSlot=1, augmentations={}}, CircuitPacks{getCircuitPackMode=NORMAL, getCircuitPackName=1/0/2-PLUG-NET, getCircuitPackProductCode=Line_NW_P, getCircuitPackType=line_pluggable, getParentCircuitPack=ParentCircuitPack{getCircuitPackName=1/0, getCpSlotName=3, augmentations={}}, getPorts=[Ports{getAdministrativeState=InService, getPortName=1, getPortQual=XpdrNetwork, getPortType=CFP2, augmentations={}}], getShelf=1, getSlot=1, getSubSlot=1, augmentations={}}], getInfo=Info{getClli=NodeC, getDefaultGateway=IpAddress [_ipv4Address=Ipv4Address [_value=1.2.3.4]], getGeoLocation=GeoLocation{getLatitude=1.0000, getLongitude=2.0000, augmentations={}}, getIpAddress=IpAddress [_ipv4Address=Ipv4Address [_value=1.2.3.4]], getNodeId=NodeIdType [_value=XPDR-A1], getNodeNumber=1, getNodeType=Xpdr, getPrefixLength=24, getTemplate=template_TRANSPONDER, augmentations={}}, getShelves=[Shelves{getAdministrativeState=InService, getDueDate=DateAndTime [_value=2017-02-24T15:56:10+00:00], getRack=XYZ, getShelfName=1, getShelfPosition=1, getShelfType=pizza, augmentations={}}], getUsers=Users{getUser=[User{getGroup=Sudo, getName=UsernameType [_value=openroadm], getPassword=PasswordType [_value=openroadm], augmentations={}}], augmentations={}}, augmentations={}}
331 2019-05-20 16:22:12.013 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - processing change ...
332 2019-05-20 16:22:12.013 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - WriteTransactions are ok, merge device info to datastores
333 2019-05-20 16:22:12.021 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - device 'XPDR-A1' merged to device oper datastore
334 2019-05-20 16:22:12.023 CEST [main] INFO  i.f.h.t.d.c.PmConfiguration - result pm list size : 1
335 2019-05-20 16:22:12.023 CEST [main] INFO  i.f.h.t.device.read.PmReaderFactory - Getting pm info from xml file for device 
336 2019-05-20 16:22:12.024 CEST [main] INFO  i.f.h.t.device.read.PmReaderFactory - WriteTransaction is ok, copy currentPmList to oper datastore
337 2019-05-20 16:22:12.056 CEST [main] INFO  i.f.h.t.device.read.PmReaderFactory - currentPmList writed to oper datastore
338 2019-05-20 16:22:12.063 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.oper.ReadableDTDelegProvider@58e13c25
339 2019-05-20 16:22:12.066 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfBindingBrokerProvider@1538ca32
340 2019-05-20 16:22:12.067 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfNotificationMapperProvider@40fc9cce
341 2019-05-20 16:22:12.075 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.RpcRegistryBuilderProvider@4b0d7cb5
342 2019-05-20 16:22:12.076 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.RpcRegistryProvider@2066f0d3
343 2019-05-20 16:22:12.077 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.HoneycombDOMRpcServiceProvider@dda90c0
344 2019-05-20 16:22:12.078 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfMdsalMapperProvider@1db078d9
345 2019-05-20 16:22:12.089 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfMonitoringServiceProvider@4341ce99
346 2019-05-20 16:22:12.101 CEST [main] INFO  o.o.n.i.o.NetconfSessionMonitoringService - Scheduling thread pool is present = false, update interval 0: /netconf-state/sessions won't be updated.
347 2019-05-20 16:22:12.102 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfMonitoringMapperProvider@335755a0
348 2019-05-20 16:22:12.152 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DOMNotificationServiceProvider@6efd96c7
349 2019-05-20 16:22:12.165 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.HoneycombNotificationManagerProvider@56c9fb47
350 2019-05-20 16:22:12.170 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.HoneycombNotification2NetconfProvider@694396a
351 2019-05-20 16:22:12.176 CEST [main] INFO  i.f.h.n.n.HoneycombNotification2NetconfProvider - Exposing HONEYCOMB_NETCONF notification stream: honeycomb
352 2019-05-20 16:22:12.176 CEST [pool-18-thread-3] INFO  i.f.h.t.d.n.DeviceNotificationProducer - Starting notification stream for OrgOpenroadmDevice
353 2019-05-20 16:22:12.176 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NettyThreadGroupProvider@5a25183b
354 2019-05-20 16:22:12.186 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - onDataTreeChanged
355 2019-05-20 16:22:12.186 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - transforming changes to notification...
356 2019-05-20 16:22:12.186 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - Received Device change :
357 WRITE
358 2019-05-20 16:22:12.188 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - device operational datastore is created !
359 2019-05-20 16:22:12.188 CEST [operational-DCL-0] WARN  i.f.h.t.d.n.DeviceNotificationProducer - edit List is empty !
360 2019-05-20 16:22:12.188 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - Emitting notification : null
361 2019-05-20 16:22:12.188 CEST [operational-DCL-0] WARN  i.f.h.t.d.n.DeviceNotificationProducer - Failed to emit notification
362 2019-05-20 16:22:12.212 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfServerDispatcherProvider@25becefb
363 2019-05-20 16:22:12.216 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfTcpServerProvider@2720786f
364 2019-05-20 16:22:12.217 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfSshServerProvider@7c4d896a
365 2019-05-20 16:22:12.217 CEST [main] INFO  i.f.h.n.n.NetconfSshServerProvider - Starting NETCONF SSH
366 2019-05-20 16:22:12.293 CEST [main] WARN  io.netty.bootstrap.ServerBootstrap - Unknown channel option 'SO_BACKLOG' for channel '[id: 0xb727ebc7]'
367 2019-05-20 16:22:12.585 CEST [main] INFO  io.fd.honeycomb.infra.distro.Main - Initializing configuration
368 2019-05-20 16:22:12.586 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.context.PersistedContextInitializerProvider@2f8a57c2
369 2019-05-20 16:22:12.588 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.PersistedConfigInitializerProvider@4727acf9
370 2019-05-20 16:22:12.588 CEST [main] INFO  i.f.h.i.d.d.PersistedConfigInitializerProvider - RestoringInitializer ...
371 2019-05-20 16:22:12.588 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.initializer.ModifiableDTDelegInitProvider@9201335
372 2019-05-20 16:22:12.589 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.HoneycombDOMDataBrokerProvider@684968be
373 2019-05-20 16:22:12.589 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.BindingDataBrokerProvider@7c49fbd8
374 2019-05-20 16:22:12.589 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.context.RealtimeMappingContextProvider@7a4a91f8
375 2019-05-20 16:22:12.590 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.initializer.InitializerRegistryAdapterProvider@249199a7
376 2019-05-20 16:22:12.590 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Config initialization started
377 2019-05-20 16:22:12.590 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Persisted context restored successfully
378 2019-05-20 16:22:12.591 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Configuration initialized successfully
379 2019-05-20 16:22:12.591 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Persisted configuration restored successfully
380 2019-05-20 16:22:12.591 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Honeycomb initialized
381 2019-05-20 16:22:12.591 CEST [main] INFO  io.fd.honeycomb.infra.distro.Main - Configuration initialized successfully
382 2019-05-20 16:22:12.591 CEST [main] INFO  io.fd.honeycomb.infra.distro.Main - Honeycomb started successfully!
383 2019-05-20 16:22:12.693 CEST [netconf-netty-0] INFO  i.f.h.n.n.NetconfSshServerProvider - Netconf SSH endpoint started successfully at /0.0.0.0:17840
384 2019-05-20 16:25:09.142 CEST [Thread-5] INFO  i.f.h.impl.ShutdownHandlerImpl - Closing component notification-to-mdsal-writer
385 2019-05-20 16:25:09.144 CEST [Thread-5] INFO  i.f.h.impl.ShutdownHandlerImpl - Closing component netconf-notification-service-factory
386 2019-05-20 16:26:16.144 CEST [main] INFO  io.fd.honeycomb.infra.distro.Main - Starting honeycomb
387 2019-05-20 16:26:16.451 CEST [main] INFO  i.f.h.i.d.a.ActiveModuleProvider - Reading active modules configuration for distribution
388 2019-05-20 16:26:16.479 CEST [main] INFO  i.f.h.t.device.DeviceModule - Initializing Device Module
389 2019-05-20 16:26:16.489 CEST [main] INFO  i.f.h.t.d.c.DeviceConfigurationModule - Initializing Device Readers Module
390 2019-05-20 16:26:16.492 CEST [main] INFO  i.f.h.t.d.c.PmConfigurationModule - Initializing Pm Readers Module
391 2019-05-20 16:26:16.495 CEST [main] INFO  i.f.h.t.device.DeviceModule - Device Module intitailized !
392 2019-05-20 16:26:16.495 CEST [main] INFO  i.f.h.t.d.c.NetconfConfigurationModule - Initializing Netconf Readers Module
393 2019-05-20 16:26:16.497 CEST [main] INFO  i.f.h.t.device.DeviceModule - Netconf Module intitailized !
394 2019-05-20 16:26:16.498 CEST [main] INFO  i.f.h.i.d.s.YangBindingProviderModule - Configuring YangBindingProviderModule
395 2019-05-20 16:26:16.500 CEST [main] INFO  i.f.h.t.device.DeviceRpcModule - Initializing Device Rpcs Module
396 2019-05-20 16:26:16.520 CEST [main] INFO  i.f.h.t.d.DeviceNotificationModule - Initializing Device Notification Module
397 2019-05-20 16:26:16.522 CEST [main] INFO  i.f.h.t.device.DeviceWriterModule - Initializing Device Writers Module
398 2019-05-20 16:26:16.532 CEST [main] INFO  i.f.h.n.n.NetconfReadersModule - Initializing NETCONF Northbound readers
399 2019-05-20 16:26:16.536 CEST [main] INFO  i.f.h.n.netconf.NetconfModule - Starting NETCONF Northbound
400 2019-05-20 16:26:16.665 CEST [main] INFO  i.f.h.t.device.DeviceReaderModule - Initializing Device, PM and Netconf Readers Module
401 2019-05-20 16:26:16.862 CEST [main] INFO  i.f.h.i.d.a.ActiveModuleProvider - Reading active modules configuration for distribution
402 2019-05-20 16:26:16.891 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: ModuleInfoBackedCtxProvider{writerFactories=io.fd.honeycomb.infra.distro.schema.YangModulesProvider$YangModules@447a020}
403 2019-05-20 16:26:17.423 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.schema.SchemaServiceProvider@4c36250e
404 2019-05-20 16:26:18.169 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataTreeProvider$ContextDataTreeProvider@6cc558c6
405 2019-05-20 16:26:18.191 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.PersistingDataTreeProvider$ContextPersistingDataTreeProvider@63f259c3
406 2019-05-20 16:26:18.191 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.context.ModifiableDTMgrProvider@3db972d2
407 2019-05-20 16:26:18.192 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.schema.SerializerProvider@158f4cfe
408 2019-05-20 16:26:18.471 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataTreeProvider$ConfigDataTreeProvider@77774571
409 2019-05-20 16:26:18.472 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.PersistingDataTreeProvider$ConfigPersistingDataTreeProvider@6cd64ee8
410 2019-05-20 16:26:18.473 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataStoreProvider@62010f5c
411 2019-05-20 16:26:18.484 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataStoreProvider@132e0cc
412 2019-05-20 16:26:18.484 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.InmemoryDOMDataBrokerProvider@75de29c0
413 2019-05-20 16:26:18.493 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.transportpce.device.DeviceBindingDataBrokerProvider@1e253c9d
414 2019-05-20 16:26:18.497 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.config.WriterRegistryProvider@20b9d5d5
415 2019-05-20 16:26:18.538 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.context.HoneycombContextDOMDataBrokerProvider@26ceffa8
416 2019-05-20 16:26:18.539 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.BindingDataBrokerProvider@67064bdc
417 2019-05-20 16:26:18.539 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.ModifiableDTDelegProvider@18578491
418 2019-05-20 16:26:18.540 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataStoreProvider@7c8c9a05
419 2019-05-20 16:26:18.540 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataStoreProvider@5c2375a9
420 2019-05-20 16:26:18.540 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.InmemoryDOMDataBrokerProvider@5ad5be4a
421 2019-05-20 16:26:18.540 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.BindingDataBrokerProvider@737d100a
422 2019-05-20 16:26:18.540 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfMonitoringReaderFactoryProvider@6535117e
423 2019-05-20 16:26:18.541 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfNotificationsReaderFactoryProvider@f88bfbe
424 2019-05-20 16:26:24.204 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.oper.ReaderRegistryProvider@287213ac
425 2019-05-20 16:26:24.208 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - writting xml file data to oper datastore
426 2019-05-20 16:26:24.208 CEST [main] INFO  i.f.h.t.d.t.DefaultDeviceFactory - file 'oper-XPDRA.xml' exists at location : /home/gilles/git/01/transportpce/tests/honeynode221/honeynode-distribution/target/honeynode-distribution-1.18.01-hc/honeynode-distribution-1.18.01/config/device/oper-XPDRA.xml
427 2019-05-20 16:26:24.298 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - result info : NodeIdType [_value=XPDR-A1]
428 2019-05-20 16:26:24.299 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - Getting device info from xml file for device 'XPDR-A1'
429 2019-05-20 16:26:24.349 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - WriteTransaction is ok, copy device info to oper datastore
430 2019-05-20 16:26:24.892 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - device 'XPDR-A1' writed to oper datastore
431 2019-05-20 16:26:24.892 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - writting netconf state to oper datastore
432 2019-05-20 16:26:24.892 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - Loading models from directory.
433 2019-05-20 16:26:24.892 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - folder '/home/gilles/git/01/transportpce/tests/honeynode221/honeynode-distribution/target/honeynode-distribution-1.18.01-hc/honeynode-distribution-1.18.01/config/yang' exists !
434 2019-05-20 16:26:25.102 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - WriteTransaction is ok, copy device info to oper datastore
435 2019-05-20 16:26:25.148 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - netconf state writed to oper datastore
436 2019-05-20 16:26:25.148 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - writting netconf stream to oper datastore
437 2019-05-20 16:26:25.148 CEST [main] INFO  i.f.h.t.d.t.DefaultNetconfFactory - file 'oper-XPDRA.xml' exists at location : /home/gilles/git/01/transportpce/tests/honeynode221/honeynode-distribution/target/honeynode-distribution-1.18.01-hc/honeynode-distribution-1.18.01/config/device/oper-XPDRA.xml
438 2019-05-20 16:26:25.166 CEST [main] INFO  i.f.h.t.d.c.NetconfConfiguration - netconf streams result : Streams{getStream=[Stream{getName=StreamNameType [_value=OPENROADM], augmentations={}}], augmentations={}}
439 2019-05-20 16:26:25.167 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - Netconf Data gets from xml file is present
440 2019-05-20 16:26:25.168 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - WriteTransaction is ok
441 2019-05-20 16:26:25.177 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - netconf stream writed to oper datastore
442 2019-05-20 16:26:25.177 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - loading device configuration info from xml file...
443 2019-05-20 16:26:25.177 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - process to transform xml file 
444 2019-05-20 16:26:25.179 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - transforming xml data to config device ...
445 2019-05-20 16:26:25.292 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - removing namespace ...
446 2019-05-20 16:26:25.309 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - device info gets from xml file !
447 2019-05-20 16:26:25.309 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - process to transform xml file to config data
448 2019-05-20 16:26:25.310 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - transforming xml string to config device ...
449 2019-05-20 16:26:25.318 CEST [main] INFO  i.f.h.t.d.t.DefaultDeviceFactory - device data config string is ok 
450 2019-05-20 16:26:25.324 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - result info : NodeIdType [_value=XPDR-A1]
451 2019-05-20 16:26:25.324 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - OrgOpenroadmDevice info gets : NodeIdType [_value=XPDR-A1]
452 2019-05-20 16:26:25.324 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - WriteTransaction is ok, copy device info to config datastore
453 2019-05-20 16:26:25.333 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - device writed to config datastore
454 2019-05-20 16:26:25.334 CEST [main] INFO  i.f.h.t.device.read.PmReaderFactory - writting xml pm file data to oper datastore
455 2019-05-20 16:26:25.334 CEST [main] INFO  i.f.h.t.d.t.DefaultPmListFactory - file with pm 'oper-XPDRA.xml' exists at location : /home/gilles/git/01/transportpce/tests/honeynode221/honeynode-distribution/target/honeynode-distribution-1.18.01-hc/honeynode-distribution-1.18.01/config/device/oper-XPDRA.xml
456 2019-05-20 16:26:25.334 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - onDataTreeChanged
457 2019-05-20 16:26:25.335 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - Received Device change(WRITE):
458  before=null 
459  after=OrgOpenroadmDevice{getCircuitPacks=[CircuitPacks{getAdministrativeState=InService, getCircuitPackMode=inServiceMode, getCircuitPackName=1/0, getCircuitPackProductCode=baseXPDR, getCircuitPackType=Base_transponder_circuit_pack, getShelf=1, getSlot=1, augmentations={}}, CircuitPacks{getCircuitPackMode=NORMAL, getCircuitPackName=1/0/1-PLUG-CLIENT, getCircuitPackProductCode=Client_P, getCircuitPackType=client_pluggable, getParentCircuitPack=ParentCircuitPack{getCircuitPackName=1/0, getCpSlotName=2, augmentations={}}, getPorts=[Ports{getAdministrativeState=InService, getPortName=C1, getPortQual=XpdrClient, getPortType=QSFP28, augmentations={}}], getShelf=1, getSlot=1, getSubSlot=1, augmentations={}}, CircuitPacks{getCircuitPackMode=NORMAL, getCircuitPackName=1/0/2-PLUG-CLIENT, getCircuitPackProductCode=Client_P, getCircuitPackType=client_pluggable, getParentCircuitPack=ParentCircuitPack{getCircuitPackName=1/0, getCpSlotName=4, augmentations={}}, getPorts=[Ports{getAdministrativeState=InService, getPortName=C1, getPortQual=XpdrClient, getPortType=QSFP28, augmentations={}}], getShelf=1, getSlot=1, getSubSlot=1, augmentations={}}, CircuitPacks{getCircuitPackMode=NORMAL, getCircuitPackName=1/0/1-PLUG-NET, getCircuitPackProductCode=Line_NW_P, getCircuitPackType=line_pluggable, getParentCircuitPack=ParentCircuitPack{getCircuitPackName=1/0, getCpSlotName=1, augmentations={}}, getPorts=[Ports{getAdministrativeState=InService, getPortName=1, getPortQual=XpdrNetwork, getPortType=CFP2, augmentations={}}], getShelf=1, getSlot=1, getSubSlot=1, augmentations={}}, CircuitPacks{getCircuitPackMode=NORMAL, getCircuitPackName=1/0/2-PLUG-NET, getCircuitPackProductCode=Line_NW_P, getCircuitPackType=line_pluggable, getParentCircuitPack=ParentCircuitPack{getCircuitPackName=1/0, getCpSlotName=3, augmentations={}}, getPorts=[Ports{getAdministrativeState=InService, getPortName=1, getPortQual=XpdrNetwork, getPortType=CFP2, augmentations={}}], getShelf=1, getSlot=1, getSubSlot=1, augmentations={}}], getInfo=Info{getClli=NodeC, getDefaultGateway=IpAddress [_ipv4Address=Ipv4Address [_value=1.2.3.4]], getGeoLocation=GeoLocation{getLatitude=1.0000, getLongitude=2.0000, augmentations={}}, getIpAddress=IpAddress [_ipv4Address=Ipv4Address [_value=1.2.3.4]], getNodeId=NodeIdType [_value=XPDR-A1], getNodeNumber=1, getNodeType=Xpdr, getPrefixLength=24, getTemplate=template_TRANSPONDER, augmentations={}}, getShelves=[Shelves{getAdministrativeState=InService, getDueDate=DateAndTime [_value=2017-02-24T15:56:10+00:00], getRack=XYZ, getShelfName=1, getShelfPosition=1, getShelfType=pizza, augmentations={}}], getUsers=Users{getUser=[User{getGroup=Sudo, getName=UsernameType [_value=openroadm], getPassword=PasswordType [_value=openroadm], augmentations={}}], augmentations={}}, augmentations={}}
460 2019-05-20 16:26:25.343 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - processing change ...
461 2019-05-20 16:26:25.343 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - WriteTransactions are ok, merge device info to datastores
462 2019-05-20 16:26:25.350 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - device 'XPDR-A1' merged to device oper datastore
463 2019-05-20 16:26:25.355 CEST [main] INFO  i.f.h.t.d.c.PmConfiguration - result pm list size : 1
464 2019-05-20 16:26:25.355 CEST [main] INFO  i.f.h.t.device.read.PmReaderFactory - Getting pm info from xml file for device 
465 2019-05-20 16:26:25.356 CEST [main] INFO  i.f.h.t.device.read.PmReaderFactory - WriteTransaction is ok, copy currentPmList to oper datastore
466 2019-05-20 16:26:25.387 CEST [main] INFO  i.f.h.t.device.read.PmReaderFactory - currentPmList writed to oper datastore
467 2019-05-20 16:26:25.394 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.oper.ReadableDTDelegProvider@6354fb91
468 2019-05-20 16:26:25.396 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfBindingBrokerProvider@78493c50
469 2019-05-20 16:26:25.398 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfNotificationMapperProvider@121bacf4
470 2019-05-20 16:26:25.406 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.RpcRegistryBuilderProvider@583ae407
471 2019-05-20 16:26:25.407 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.RpcRegistryProvider@3782d1e6
472 2019-05-20 16:26:25.407 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.HoneycombDOMRpcServiceProvider@ebfe707
473 2019-05-20 16:26:25.408 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfMdsalMapperProvider@12bbf99e
474 2019-05-20 16:26:25.419 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfMonitoringServiceProvider@2b7af38e
475 2019-05-20 16:26:25.431 CEST [main] INFO  o.o.n.i.o.NetconfSessionMonitoringService - Scheduling thread pool is present = false, update interval 0: /netconf-state/sessions won't be updated.
476 2019-05-20 16:26:25.431 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfMonitoringMapperProvider@18456783
477 2019-05-20 16:26:25.452 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DOMNotificationServiceProvider@7506e95a
478 2019-05-20 16:26:25.464 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.HoneycombNotificationManagerProvider@41d72593
479 2019-05-20 16:26:25.482 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.HoneycombNotification2NetconfProvider@56c9fb47
480 2019-05-20 16:26:25.491 CEST [main] INFO  i.f.h.n.n.HoneycombNotification2NetconfProvider - Exposing HONEYCOMB_NETCONF notification stream: honeycomb
481 2019-05-20 16:26:25.491 CEST [pool-18-thread-3] INFO  i.f.h.t.d.n.DeviceNotificationProducer - Starting notification stream for OrgOpenroadmDevice
482 2019-05-20 16:26:25.492 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NettyThreadGroupProvider@4bddc770
483 2019-05-20 16:26:25.493 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - onDataTreeChanged
484 2019-05-20 16:26:25.493 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - transforming changes to notification...
485 2019-05-20 16:26:25.493 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - Received Device change :
486 WRITE
487 2019-05-20 16:26:25.494 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - device operational datastore is created !
488 2019-05-20 16:26:25.494 CEST [operational-DCL-0] WARN  i.f.h.t.d.n.DeviceNotificationProducer - edit List is empty !
489 2019-05-20 16:26:25.494 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - Emitting notification : null
490 2019-05-20 16:26:25.494 CEST [operational-DCL-0] WARN  i.f.h.t.d.n.DeviceNotificationProducer - Failed to emit notification
491 2019-05-20 16:26:25.517 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfServerDispatcherProvider@5b0c28d0
492 2019-05-20 16:26:25.522 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfTcpServerProvider@354ec60
493 2019-05-20 16:26:25.523 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfSshServerProvider@3c1d5349
494 2019-05-20 16:26:25.523 CEST [main] INFO  i.f.h.n.n.NetconfSshServerProvider - Starting NETCONF SSH
495 2019-05-20 16:26:25.582 CEST [main] WARN  io.netty.bootstrap.ServerBootstrap - Unknown channel option 'SO_BACKLOG' for channel '[id: 0x21015074]'
496 2019-05-20 16:26:25.875 CEST [main] INFO  io.fd.honeycomb.infra.distro.Main - Initializing configuration
497 2019-05-20 16:26:25.876 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.context.PersistedContextInitializerProvider@7499df3a
498 2019-05-20 16:26:25.877 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.PersistedConfigInitializerProvider@1eb9713
499 2019-05-20 16:26:25.877 CEST [main] INFO  i.f.h.i.d.d.PersistedConfigInitializerProvider - RestoringInitializer ...
500 2019-05-20 16:26:25.877 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.initializer.ModifiableDTDelegInitProvider@3a949bec
501 2019-05-20 16:26:25.878 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.HoneycombDOMDataBrokerProvider@3eeee97f
502 2019-05-20 16:26:25.878 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.BindingDataBrokerProvider@14415802
503 2019-05-20 16:26:25.878 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.context.RealtimeMappingContextProvider@1c1b9f36
504 2019-05-20 16:26:25.879 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.initializer.InitializerRegistryAdapterProvider@7a8a2cd8
505 2019-05-20 16:26:25.879 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Config initialization started
506 2019-05-20 16:26:25.879 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Persisted context restored successfully
507 2019-05-20 16:26:25.880 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Configuration initialized successfully
508 2019-05-20 16:26:25.880 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Persisted configuration restored successfully
509 2019-05-20 16:26:25.880 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Honeycomb initialized
510 2019-05-20 16:26:25.880 CEST [main] INFO  io.fd.honeycomb.infra.distro.Main - Configuration initialized successfully
511 2019-05-20 16:26:25.880 CEST [main] INFO  io.fd.honeycomb.infra.distro.Main - Honeycomb started successfully!
512 2019-05-20 16:26:25.962 CEST [netconf-netty-0] INFO  i.f.h.n.n.NetconfSshServerProvider - Netconf SSH endpoint started successfully at /0.0.0.0:17840
513 2019-05-20 16:27:18.230 CEST [Thread-5] INFO  i.f.h.impl.ShutdownHandlerImpl - Closing component notification-to-mdsal-writer
514 2019-05-20 16:27:18.232 CEST [Thread-5] INFO  i.f.h.impl.ShutdownHandlerImpl - Closing component netconf-notification-service-factory
515 2019-05-20 16:28:04.541 CEST [main] INFO  io.fd.honeycomb.infra.distro.Main - Starting honeycomb
516 2019-05-20 16:28:04.851 CEST [main] INFO  i.f.h.i.d.a.ActiveModuleProvider - Reading active modules configuration for distribution
517 2019-05-20 16:28:04.880 CEST [main] INFO  i.f.h.t.device.DeviceModule - Initializing Device Module
518 2019-05-20 16:28:04.892 CEST [main] INFO  i.f.h.t.d.c.DeviceConfigurationModule - Initializing Device Readers Module
519 2019-05-20 16:28:04.895 CEST [main] INFO  i.f.h.t.d.c.PmConfigurationModule - Initializing Pm Readers Module
520 2019-05-20 16:28:04.897 CEST [main] INFO  i.f.h.t.device.DeviceModule - Device Module intitailized !
521 2019-05-20 16:28:04.897 CEST [main] INFO  i.f.h.t.d.c.NetconfConfigurationModule - Initializing Netconf Readers Module
522 2019-05-20 16:28:04.899 CEST [main] INFO  i.f.h.t.device.DeviceModule - Netconf Module intitailized !
523 2019-05-20 16:28:04.901 CEST [main] INFO  i.f.h.i.d.s.YangBindingProviderModule - Configuring YangBindingProviderModule
524 2019-05-20 16:28:04.902 CEST [main] INFO  i.f.h.t.device.DeviceRpcModule - Initializing Device Rpcs Module
525 2019-05-20 16:28:04.923 CEST [main] INFO  i.f.h.t.d.DeviceNotificationModule - Initializing Device Notification Module
526 2019-05-20 16:28:04.926 CEST [main] INFO  i.f.h.t.device.DeviceWriterModule - Initializing Device Writers Module
527 2019-05-20 16:28:04.936 CEST [main] INFO  i.f.h.n.n.NetconfReadersModule - Initializing NETCONF Northbound readers
528 2019-05-20 16:28:04.939 CEST [main] INFO  i.f.h.n.netconf.NetconfModule - Starting NETCONF Northbound
529 2019-05-20 16:28:05.071 CEST [main] INFO  i.f.h.t.device.DeviceReaderModule - Initializing Device, PM and Netconf Readers Module
530 2019-05-20 16:28:05.266 CEST [main] INFO  i.f.h.i.d.a.ActiveModuleProvider - Reading active modules configuration for distribution
531 2019-05-20 16:28:05.296 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: ModuleInfoBackedCtxProvider{writerFactories=io.fd.honeycomb.infra.distro.schema.YangModulesProvider$YangModules@447a020}
532 2019-05-20 16:28:05.832 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.schema.SchemaServiceProvider@4c36250e
533 2019-05-20 16:28:06.617 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataTreeProvider$ContextDataTreeProvider@6cc558c6
534 2019-05-20 16:28:06.639 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.PersistingDataTreeProvider$ContextPersistingDataTreeProvider@63f259c3
535 2019-05-20 16:28:06.640 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.context.ModifiableDTMgrProvider@3db972d2
536 2019-05-20 16:28:06.640 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.schema.SerializerProvider@158f4cfe
537 2019-05-20 16:28:06.923 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataTreeProvider$ConfigDataTreeProvider@77774571
538 2019-05-20 16:28:06.924 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.PersistingDataTreeProvider$ConfigPersistingDataTreeProvider@6cd64ee8
539 2019-05-20 16:28:06.925 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataStoreProvider@62010f5c
540 2019-05-20 16:28:06.935 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataStoreProvider@132e0cc
541 2019-05-20 16:28:06.936 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.InmemoryDOMDataBrokerProvider@75de29c0
542 2019-05-20 16:28:06.945 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.transportpce.device.DeviceBindingDataBrokerProvider@1e253c9d
543 2019-05-20 16:28:06.949 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.config.WriterRegistryProvider@20b9d5d5
544 2019-05-20 16:28:06.991 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.context.HoneycombContextDOMDataBrokerProvider@26ceffa8
545 2019-05-20 16:28:06.992 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.BindingDataBrokerProvider@67064bdc
546 2019-05-20 16:28:06.992 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.ModifiableDTDelegProvider@18578491
547 2019-05-20 16:28:06.993 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataStoreProvider@7c8c9a05
548 2019-05-20 16:28:06.994 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataStoreProvider@5c2375a9
549 2019-05-20 16:28:06.994 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.InmemoryDOMDataBrokerProvider@5ad5be4a
550 2019-05-20 16:28:06.994 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.BindingDataBrokerProvider@737d100a
551 2019-05-20 16:28:06.994 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfMonitoringReaderFactoryProvider@6535117e
552 2019-05-20 16:28:06.994 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfNotificationsReaderFactoryProvider@f88bfbe
553 2019-05-20 16:28:12.118 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.oper.ReaderRegistryProvider@380d3099
554 2019-05-20 16:28:12.123 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - writting xml file data to oper datastore
555 2019-05-20 16:28:12.123 CEST [main] INFO  i.f.h.t.d.t.DefaultDeviceFactory - file 'oper-ROADMA.xml' exists at location : /home/gilles/git/01/transportpce/tests/honeynode221/honeynode-distribution/target/honeynode-distribution-1.18.01-hc/honeynode-distribution-1.18.01/config/device/oper-ROADMA.xml
556 2019-05-20 16:28:12.237 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - result info : NodeIdType [_value=ROADM-A1]
557 2019-05-20 16:28:12.238 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - Getting device info from xml file for device 'ROADM-A1'
558 2019-05-20 16:28:12.504 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - WriteTransaction is ok, copy device info to oper datastore
559 2019-05-20 16:28:12.911 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - device 'ROADM-A1' writed to oper datastore
560 2019-05-20 16:28:12.911 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - writting netconf state to oper datastore
561 2019-05-20 16:28:12.912 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - Loading models from directory.
562 2019-05-20 16:28:12.912 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - folder '/home/gilles/git/01/transportpce/tests/honeynode221/honeynode-distribution/target/honeynode-distribution-1.18.01-hc/honeynode-distribution-1.18.01/config/yang' exists !
563 2019-05-20 16:28:13.126 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - WriteTransaction is ok, copy device info to oper datastore
564 2019-05-20 16:28:13.175 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - netconf state writed to oper datastore
565 2019-05-20 16:28:13.175 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - writting netconf stream to oper datastore
566 2019-05-20 16:28:13.175 CEST [main] INFO  i.f.h.t.d.t.DefaultNetconfFactory - file 'oper-ROADMA.xml' exists at location : /home/gilles/git/01/transportpce/tests/honeynode221/honeynode-distribution/target/honeynode-distribution-1.18.01-hc/honeynode-distribution-1.18.01/config/device/oper-ROADMA.xml
567 2019-05-20 16:28:13.200 CEST [main] INFO  i.f.h.t.d.c.NetconfConfiguration - netconf streams result : Streams{getStream=[Stream{getName=StreamNameType [_value=OPENROADM], augmentations={}}], augmentations={}}
568 2019-05-20 16:28:13.201 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - Netconf Data gets from xml file is present
569 2019-05-20 16:28:13.203 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - WriteTransaction is ok
570 2019-05-20 16:28:13.212 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - netconf stream writed to oper datastore
571 2019-05-20 16:28:13.212 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - loading device configuration info from xml file...
572 2019-05-20 16:28:13.212 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - process to transform xml file 
573 2019-05-20 16:28:13.215 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - transforming xml data to config device ...
574 2019-05-20 16:28:13.360 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - removing namespace ...
575 2019-05-20 16:28:13.387 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - device info gets from xml file !
576 2019-05-20 16:28:13.387 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - process to transform xml file to config data
577 2019-05-20 16:28:13.388 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - transforming xml string to config device ...
578 2019-05-20 16:28:13.400 CEST [main] INFO  i.f.h.t.d.t.DefaultDeviceFactory - device data config string is ok 
579 2019-05-20 16:28:13.410 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - result info : NodeIdType [_value=ROADM-A1]
580 2019-05-20 16:28:13.410 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - OrgOpenroadmDevice info gets : NodeIdType [_value=ROADM-A1]
581 2019-05-20 16:28:13.410 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - WriteTransaction is ok, copy device info to config datastore
582 2019-05-20 16:28:13.425 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - device writed to config datastore
583 2019-05-20 16:28:13.426 CEST [main] INFO  i.f.h.t.device.read.PmReaderFactory - writting xml pm file data to oper datastore
584 2019-05-20 16:28:13.426 CEST [main] INFO  i.f.h.t.d.t.DefaultPmListFactory - file with pm 'oper-ROADMA.xml' exists at location : /home/gilles/git/01/transportpce/tests/honeynode221/honeynode-distribution/target/honeynode-distribution-1.18.01-hc/honeynode-distribution-1.18.01/config/device/oper-ROADMA.xml
585 2019-05-20 16:28:13.427 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - onDataTreeChanged
586 2019-05-20 16:28:13.428 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - Received Device change(WRITE):
587  before=null 
588  after=OrgOpenroadmDevice{getCircuitPacks=[CircuitPacks{getAdministrativeState=InService, getCircuitPackMode=inServiceMode, getCircuitPackName=5/0, getCircuitPackProductCode=SRGRx, getCircuitPackType=ADDDROP, getEquipmentState=ReservedForFacilityAvailable, getPorts=[Ports{getAdministrativeState=InService, getLogicalConnectionPoint=SRG3-CP-TXRX, getPortName=AD-DEG1, getPortQual=RoadmInternal, getPortType=Edge, augmentations={}}, Ports{getAdministrativeState=InService, getCircuitId=SRG1, getLogicalConnectionPoint=SRG3-PP1, getPortName=C1, getPortQual=RoadmExternal, getPortType=Client, augmentations={}}, Ports{getAdministrativeState=InService, getCircuitId=SRG1, getLogicalConnectionPoint=SRG3-PP2, getPortName=C2, getPortQual=RoadmExternal, getPortType=Client, augmentations={}}, Ports{getAdministrativeState=InService, getLogicalConnectionPoint=SRG3-CP-TXRX, getPortName=AD-DEG2, getPortQual=RoadmInternal, getPortType=Edge, augmentations={}}, Ports{getAdministrativeState=InService, getCircuitId=SRG1, getLogicalConnectionPoint=SRG3-PP3, getPortName=C3, getPortQual=RoadmExternal, getPortType=Client, augmentations={}}, Ports{getAdministrativeState=InService, getCircuitId=SRG1, getLogicalConnectionPoint=SRG3-PP4, getPortName=C4, getPortQual=RoadmExternal, getPortType=Client, augmentations={}}], getShelf=1, getSlot=2, augmentations={}}, CircuitPacks{getAdministrativeState=InService, getCircuitPackMode=inServiceMode, getCircuitPackName=2/0, getCircuitPackProductCode=DegE, getCircuitPackType=WSSDEG, getEquipmentState=NotReservedAvailable, getPorts=[Ports{getAdministrativeState=InService, getCircuitId=1, getLogicalConnectionPoint=DEG2-TTP-TXRX, getPortName=L1, getPortQual=RoadmExternal, getPortType=LINE, augmentations={}}, Ports{getAdministrativeState=InService, getCircuitId=1, getLogicalConnectionPoint=DEG2-CTP-TXRX, getPortName=C1, getPortQual=RoadmInternal, getPortType=Client, augmentations={}}, Ports{getAdministrativeState=InService, getCircuitId=1, getLogicalConnectionPoint=DEG2-CTP-TXRX, getPortName=C2, getPortQual=RoadmInternal, getPortType=Client, augmentations={}}, Ports{getAdministrativeState=InService, getCircuitId=1, getLogicalConnectionPoint=DEG2-CTP-TXRX, getPortName=C3, getPortQual=RoadmInternal, getPortType=Client, augmentations={}}, Ports{getAdministrativeState=InService, getCircuitId=1, getLogicalConnectionPoint=DEG2-CTP-TXRX, getPortName=C4, getPortQual=RoadmInternal, getPortType=Client, augmentations={}}], getShelf=1, getSlot=1, augmentations={}}, CircuitPacks{getAdministrativeState=InService, getCircuitPackMode=inServiceMode, getCircuitPackName=1/0, getCircuitPackProductCode=DegW, getCircuitPackType=WSSDEG, getEquipmentState=NotReservedAvailable, getPorts=[Ports{getAdministrativeState=InService, getCircuitId=1, getLogicalConnectionPoint=DEG1-TTP-TXRX, getPortName=L1, getPortQual=RoadmExternal, getPortType=LINE, augmentations={}}, Ports{getAdministrativeState=InService, getCircuitId=1, getLogicalConnectionPoint=DEG1-CTP-TXRX, getPortName=C1, getPortQual=RoadmInternal, getPortType=Client, augmentations={}}, Ports{getAdministrativeState=InService, getCircuitId=1, getLogicalConnectionPoint=DEG1-CTP-TXRX, getPortName=C2, getPortQual=RoadmInternal, getPortType=Client, augmentations={}}, Ports{getAdministrativeState=InService, getCircuitId=1, getLogicalConnectionPoint=DEG1-CTP-TXRX, getPortName=C3, getPortQual=RoadmInternal, getPortType=Client, augmentations={}}, Ports{getAdministrativeState=InService, getCircuitId=1, getLogicalConnectionPoint=DEG1-CTP-TXRX, getPortName=C4, getPortQual=RoadmInternal, getPortType=Client, augmentations={}}], getShelf=1, getSlot=1, augmentations={}}, CircuitPacks{getAdministrativeState=InService, getCircuitPackMode=NORMAL, getCircuitPackName=2/0/OSC-PLUG, getCircuitPackType=port, getEquipmentState=NotReservedAvailable, getParentCircuitPack=ParentCircuitPack{getCircuitPackName=2/0, getCpSlotName=OSC-SLOT, augmentations={}}, getPorts=[Ports{getAdministrativeState=InService, getPortName=OSC-PORT, getPortQual=RoadmInternal, getPortType=1GEX, augmentations={}}], getShelf=2, getSlot=0, getSubSlot=0, augmentations={}}, CircuitPacks{getAdministrativeState=InService, getCircuitPackMode=inServiceMode, getCircuitPackName=3/0, getCircuitPackProductCode=SRGRx, getCircuitPackType=ADDDROP, getEquipmentState=ReservedForFacilityAvailable, getPorts=[Ports{getAdministrativeState=InService, getLogicalConnectionPoint=SRG1-CP-TXRX, getPortName=AD-DEG1, getPortQual=RoadmInternal, getPortType=Edge, augmentations={}}, Ports{getAdministrativeState=InService, getCircuitId=SRG1, getLogicalConnectionPoint=SRG1-PP1, getPortName=C1, getPortQual=RoadmExternal, getPortType=Client, augmentations={}}, Ports{getAdministrativeState=InService, getCircuitId=SRG1, getLogicalConnectionPoint=SRG1-PP2, getPortName=C2, getPortQual=RoadmExternal, getPortType=Client, augmentations={}}, Ports{getAdministrativeState=InService, getLogicalConnectionPoint=SRG1-CP-TXRX, getPortName=AD-DEG2, getPortQual=RoadmInternal, getPortType=Edge, augmentations={}}, Ports{getAdministrativeState=InService, getCircuitId=SRG1, getLogicalConnectionPoint=SRG1-PP3, getPortName=C3, getPortQual=RoadmExternal, getPortType=Client, augmentations={}}, Ports{getAdministrativeState=InService, getCircuitId=SRG1, getLogicalConnectionPoint=SRG1-PP4, getPortName=C4, getPortQual=RoadmExternal, getPortType=Client, augmentations={}}], getShelf=1, getSlot=2, augmentations={}}, CircuitPacks{getAdministrativeState=InService, getCircuitPackMode=inServiceMode, getCircuitPackName=2/0/ETH-PLUG, getCircuitPackProductCode=Eth, getCircuitPackType=port, getEquipmentState=NotReservedAvailable, getParentCircuitPack=ParentCircuitPack{getCircuitPackName=2/0, getCpSlotName=ETH-PLUG, augmentations={}}, getPorts=[Ports{getAdministrativeState=InService, getPortName=ETH-PLUG, getPortQual=RoadmInternal, getPortType=1GEX, augmentations={}}], getShelf=1, getSlot=1, getSubSlot=0, augmentations={}}], getDegree=[Degree{getCircuitPacks=[CircuitPacks{getCircuitPackName=2/0/ETH-PLUG, getIndex=1, augmentations={}}], getConnectionPorts=[ConnectionPorts{getCircuitPackName=2/0, getIndex=1, getPortName=L1, augmentations={}}], getDegreeNumber=2, augmentations={}}, Degree{getCircuitPacks=[CircuitPacks{getCircuitPackName=1/0/ETH-PLUG, getIndex=1, augmentations={}}], getConnectionPorts=[ConnectionPorts{getCircuitPackName=1/0, getIndex=1, getPortName=L1, augmentations={}}], getDegreeNumber=1, augmentations={}}], getInfo=Info{getClli=NodeA, getDefaultGateway=IpAddress [_ipv4Address=Ipv4Address [_value=127.0.0.20]], getGeoLocation=GeoLocation{getLatitude=1.0000, getLongitude=2.0000, augmentations={}}, getIpAddress=IpAddress [_ipv4Address=Ipv4Address [_value=127.0.0.11]], getNodeId=NodeIdType [_value=ROADM-A1], getNodeNumber=2, getNodeType=Rdm, getPrefixLength=28, getTemplate=template_1, augmentations={}}, getInterface=[Interface{getAdministrativeState=InService, getName=1GE-interface-2, getSupportingCircuitPackName=2/0/ETH-PLUG, getSupportingPort=ETH-PLUG, getType=class org.opendaylight.yang.gen.v1.http.org.openroadm.interfaces.rev170626.EthernetCsmacd, augmentations={interface org.opendaylight.yang.gen.v1.http.org.openroadm.ethernet.interfaces.rev181019.Interface1=Interface1{getEthernet=Ethernet{getAutoNegotiation=Enabled, getDuplex=Full, getMtu=1800, getSpeed=1000, augmentations={}}}}}, Interface{getAdministrativeState=InService, getName=OTS-DEG2-TTP-TXRX, getSupportingCircuitPackName=2/0, getSupportingPort=L1, getType=class org.opendaylight.yang.gen.v1.http.org.openroadm.interfaces.rev170626.OpticalTransport, augmentations={interface org.opendaylight.yang.gen.v1.http.org.openroadm.optical.transport.interfaces.rev181019.Interface1=Interface1{getOts=Ots{getFiberType=Smf, getIngressSpanLossAgingMargin=RatioDB [_value=0, _UNITS=dB], getSpanLossReceive=RatioDB [_value=15, _UNITS=dB], getSpanLossTransmit=RatioDB [_value=6, _UNITS=dB], augmentations={}}}}}, Interface{getAdministrativeState=InService, getCircuitId=TBD, getDescription=TBD, getName=OMS-DEG2-TTP-TXRX, getSupportingCircuitPackName=2/0, getSupportingInterface=OTS-DEG2-TTP-TXRX, getSupportingPort=L1, getType=class org.opendaylight.yang.gen.v1.http.org.openroadm.interfaces.rev170626.OpenROADMOpticalMultiplex, augmentations={}}], getProtocols=Protocols{augmentations={interface org.opendaylight.yang.gen.v1.http.org.openroadm.lldp.rev181019.Protocols1=Protocols1{getLldp=Lldp{getGlobalConfig=GlobalConfig{getAdminStatus=Enable, getMsgTxHoldMultiplier=4, getMsgTxInterval=20, augmentations={}}, getPortConfig=[PortConfig{getAdminStatus=Txandrx, getIfName=1GE-interface-2, augmentations={}}], augmentations={}}}}}, getSharedRiskGroup=[SharedRiskGroup{getCircuitPacks=[CircuitPacks{getCircuitPackName=3/0, getIndex=1, augmentations={}}], getSrgNumber=1, augmentations={}}, SharedRiskGroup{getCircuitPacks=[CircuitPacks{getCircuitPackName=5/0, getIndex=1, augmentations={}}], getSrgNumber=3, augmentations={}}], getUsers=Users{getUser=[User{getGroup=Sudo, getName=UsernameType [_value=openroadm], getPassword=PasswordType [_value=openroadm], augmentations={}}], augmentations={}}, augmentations={}}
589 2019-05-20 16:28:13.441 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - processing change ...
590 2019-05-20 16:28:13.441 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - WriteTransactions are ok, merge device info to datastores
591 2019-05-20 16:28:13.451 CEST [main] INFO  i.f.h.t.d.c.PmConfiguration - result pm list size : 1
592 2019-05-20 16:28:13.452 CEST [main] INFO  i.f.h.t.device.read.PmReaderFactory - Getting pm info from xml file for device 
593 2019-05-20 16:28:13.452 CEST [main] INFO  i.f.h.t.device.read.PmReaderFactory - WriteTransaction is ok, copy currentPmList to oper datastore
594 2019-05-20 16:28:13.456 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - device 'ROADM-A1' merged to device oper datastore
595 2019-05-20 16:28:13.487 CEST [main] INFO  i.f.h.t.device.read.PmReaderFactory - currentPmList writed to oper datastore
596 2019-05-20 16:28:13.494 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.oper.ReadableDTDelegProvider@3fe900b0
597 2019-05-20 16:28:13.497 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfBindingBrokerProvider@44e0a1ce
598 2019-05-20 16:28:13.498 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfNotificationMapperProvider@5058da5a
599 2019-05-20 16:28:13.506 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.RpcRegistryBuilderProvider@172d9bb2
600 2019-05-20 16:28:13.507 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.RpcRegistryProvider@485ca712
601 2019-05-20 16:28:13.508 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.HoneycombDOMRpcServiceProvider@23277696
602 2019-05-20 16:28:13.509 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfMdsalMapperProvider@3f7fbfba
603 2019-05-20 16:28:13.520 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfMonitoringServiceProvider@2596ae35
604 2019-05-20 16:28:13.533 CEST [main] INFO  o.o.n.i.o.NetconfSessionMonitoringService - Scheduling thread pool is present = false, update interval 0: /netconf-state/sessions won't be updated.
605 2019-05-20 16:28:13.533 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfMonitoringMapperProvider@255a1fdb
606 2019-05-20 16:28:13.553 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DOMNotificationServiceProvider@19f7107e
607 2019-05-20 16:28:13.565 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.HoneycombNotificationManagerProvider@336e1bcf
608 2019-05-20 16:28:13.569 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.HoneycombNotification2NetconfProvider@4054397
609 2019-05-20 16:28:13.575 CEST [main] INFO  i.f.h.n.n.HoneycombNotification2NetconfProvider - Exposing HONEYCOMB_NETCONF notification stream: honeycomb
610 2019-05-20 16:28:13.575 CEST [pool-18-thread-3] INFO  i.f.h.t.d.n.DeviceNotificationProducer - Starting notification stream for OrgOpenroadmDevice
611 2019-05-20 16:28:13.575 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NettyThreadGroupProvider@26d6399e
612 2019-05-20 16:28:13.577 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - onDataTreeChanged
613 2019-05-20 16:28:13.577 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - transforming changes to notification...
614 2019-05-20 16:28:13.577 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - Received Device change :
615 WRITE
616 2019-05-20 16:28:13.578 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - device operational datastore is created !
617 2019-05-20 16:28:13.578 CEST [operational-DCL-0] WARN  i.f.h.t.d.n.DeviceNotificationProducer - edit List is empty !
618 2019-05-20 16:28:13.578 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - Emitting notification : null
619 2019-05-20 16:28:13.578 CEST [operational-DCL-0] WARN  i.f.h.t.d.n.DeviceNotificationProducer - Failed to emit notification
620 2019-05-20 16:28:13.605 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfServerDispatcherProvider@f2d9eb
621 2019-05-20 16:28:13.609 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfTcpServerProvider@70b95f05
622 2019-05-20 16:28:13.610 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfSshServerProvider@1ad13538
623 2019-05-20 16:28:13.610 CEST [main] INFO  i.f.h.n.n.NetconfSshServerProvider - Starting NETCONF SSH
624 2019-05-20 16:28:13.671 CEST [main] WARN  io.netty.bootstrap.ServerBootstrap - Unknown channel option 'SO_BACKLOG' for channel '[id: 0x6f6e448c]'
625 2019-05-20 16:28:13.949 CEST [main] INFO  io.fd.honeycomb.infra.distro.Main - Initializing configuration
626 2019-05-20 16:28:13.949 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.context.PersistedContextInitializerProvider@720574a4
627 2019-05-20 16:28:13.951 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.PersistedConfigInitializerProvider@2348e36
628 2019-05-20 16:28:13.951 CEST [main] INFO  i.f.h.i.d.d.PersistedConfigInitializerProvider - RestoringInitializer ...
629 2019-05-20 16:28:13.951 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.initializer.ModifiableDTDelegInitProvider@5c6d1a38
630 2019-05-20 16:28:13.951 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.HoneycombDOMDataBrokerProvider@27c5fba0
631 2019-05-20 16:28:13.952 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.BindingDataBrokerProvider@de3b06a
632 2019-05-20 16:28:13.952 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.context.RealtimeMappingContextProvider@205d8cfa
633 2019-05-20 16:28:13.952 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.initializer.InitializerRegistryAdapterProvider@698ba673
634 2019-05-20 16:28:13.953 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Config initialization started
635 2019-05-20 16:28:13.953 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Persisted context restored successfully
636 2019-05-20 16:28:13.954 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Configuration initialized successfully
637 2019-05-20 16:28:13.954 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Persisted configuration restored successfully
638 2019-05-20 16:28:13.954 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Honeycomb initialized
639 2019-05-20 16:28:13.954 CEST [main] INFO  io.fd.honeycomb.infra.distro.Main - Configuration initialized successfully
640 2019-05-20 16:28:13.954 CEST [main] INFO  io.fd.honeycomb.infra.distro.Main - Honeycomb started successfully!
641 2019-05-20 16:28:14.046 CEST [netconf-netty-0] INFO  i.f.h.n.n.NetconfSshServerProvider - Netconf SSH endpoint started successfully at /0.0.0.0:17841
642 2019-05-20 16:33:25.548 CEST [main] INFO  io.fd.honeycomb.infra.distro.Main - Starting honeycomb
643 2019-05-20 16:33:25.854 CEST [main] INFO  i.f.h.i.d.a.ActiveModuleProvider - Reading active modules configuration for distribution
644 2019-05-20 16:33:25.883 CEST [main] INFO  i.f.h.t.device.DeviceModule - Initializing Device Module
645 2019-05-20 16:33:25.893 CEST [main] INFO  i.f.h.t.d.c.DeviceConfigurationModule - Initializing Device Readers Module
646 2019-05-20 16:33:25.896 CEST [main] INFO  i.f.h.t.d.c.PmConfigurationModule - Initializing Pm Readers Module
647 2019-05-20 16:33:25.899 CEST [main] INFO  i.f.h.t.device.DeviceModule - Device Module intitailized !
648 2019-05-20 16:33:25.899 CEST [main] INFO  i.f.h.t.d.c.NetconfConfigurationModule - Initializing Netconf Readers Module
649 2019-05-20 16:33:25.901 CEST [main] INFO  i.f.h.t.device.DeviceModule - Netconf Module intitailized !
650 2019-05-20 16:33:25.902 CEST [main] INFO  i.f.h.i.d.s.YangBindingProviderModule - Configuring YangBindingProviderModule
651 2019-05-20 16:33:25.904 CEST [main] INFO  i.f.h.t.device.DeviceRpcModule - Initializing Device Rpcs Module
652 2019-05-20 16:33:25.924 CEST [main] INFO  i.f.h.t.d.DeviceNotificationModule - Initializing Device Notification Module
653 2019-05-20 16:33:25.927 CEST [main] INFO  i.f.h.t.device.DeviceWriterModule - Initializing Device Writers Module
654 2019-05-20 16:33:25.937 CEST [main] INFO  i.f.h.n.n.NetconfReadersModule - Initializing NETCONF Northbound readers
655 2019-05-20 16:33:25.940 CEST [main] INFO  i.f.h.n.netconf.NetconfModule - Starting NETCONF Northbound
656 2019-05-20 16:33:26.070 CEST [main] INFO  i.f.h.t.device.DeviceReaderModule - Initializing Device, PM and Netconf Readers Module
657 2019-05-20 16:33:26.263 CEST [main] INFO  i.f.h.i.d.a.ActiveModuleProvider - Reading active modules configuration for distribution
658 2019-05-20 16:33:26.292 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: ModuleInfoBackedCtxProvider{writerFactories=io.fd.honeycomb.infra.distro.schema.YangModulesProvider$YangModules@447a020}
659 2019-05-20 16:33:26.834 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.schema.SchemaServiceProvider@4c36250e
660 2019-05-20 16:33:27.595 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataTreeProvider$ContextDataTreeProvider@6cc558c6
661 2019-05-20 16:33:27.617 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.PersistingDataTreeProvider$ContextPersistingDataTreeProvider@63f259c3
662 2019-05-20 16:33:27.617 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.context.ModifiableDTMgrProvider@3db972d2
663 2019-05-20 16:33:27.618 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.schema.SerializerProvider@158f4cfe
664 2019-05-20 16:33:27.896 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataTreeProvider$ConfigDataTreeProvider@77774571
665 2019-05-20 16:33:27.897 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.PersistingDataTreeProvider$ConfigPersistingDataTreeProvider@6cd64ee8
666 2019-05-20 16:33:27.898 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataStoreProvider@62010f5c
667 2019-05-20 16:33:27.909 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataStoreProvider@132e0cc
668 2019-05-20 16:33:27.909 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.InmemoryDOMDataBrokerProvider@75de29c0
669 2019-05-20 16:33:27.918 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.transportpce.device.DeviceBindingDataBrokerProvider@1e253c9d
670 2019-05-20 16:33:27.922 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.config.WriterRegistryProvider@20b9d5d5
671 2019-05-20 16:33:27.962 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.context.HoneycombContextDOMDataBrokerProvider@26ceffa8
672 2019-05-20 16:33:27.963 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.BindingDataBrokerProvider@67064bdc
673 2019-05-20 16:33:27.963 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.ModifiableDTDelegProvider@18578491
674 2019-05-20 16:33:27.964 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataStoreProvider@7c8c9a05
675 2019-05-20 16:33:27.964 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataStoreProvider@5c2375a9
676 2019-05-20 16:33:27.965 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.InmemoryDOMDataBrokerProvider@5ad5be4a
677 2019-05-20 16:33:27.965 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.BindingDataBrokerProvider@737d100a
678 2019-05-20 16:33:27.965 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfMonitoringReaderFactoryProvider@6535117e
679 2019-05-20 16:33:27.965 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfNotificationsReaderFactoryProvider@f88bfbe
680 2019-05-20 16:33:33.544 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.oper.ReaderRegistryProvider@380d3099
681 2019-05-20 16:33:33.548 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - writting xml file data to oper datastore
682 2019-05-20 16:33:33.548 CEST [main] INFO  i.f.h.t.d.t.DefaultDeviceFactory - file 'oper-ROADMC.xml' exists at location : /home/gilles/git/01/transportpce/tests/honeynode221/honeynode-distribution/target/honeynode-distribution-1.18.01-hc/honeynode-distribution-1.18.01/config/device/oper-ROADMC.xml
683 2019-05-20 16:33:33.652 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - result info : NodeIdType [_value=ROADM-C1]
684 2019-05-20 16:33:33.652 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - Getting device info from xml file for device 'ROADM-C1'
685 2019-05-20 16:33:33.704 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - WriteTransaction is ok, copy device info to oper datastore
686 2019-05-20 16:33:34.301 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - device 'ROADM-C1' writed to oper datastore
687 2019-05-20 16:33:34.301 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - writting netconf state to oper datastore
688 2019-05-20 16:33:34.301 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - Loading models from directory.
689 2019-05-20 16:33:34.301 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - folder '/home/gilles/git/01/transportpce/tests/honeynode221/honeynode-distribution/target/honeynode-distribution-1.18.01-hc/honeynode-distribution-1.18.01/config/yang' exists !
690 2019-05-20 16:33:34.509 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - WriteTransaction is ok, copy device info to oper datastore
691 2019-05-20 16:33:34.555 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - netconf state writed to oper datastore
692 2019-05-20 16:33:34.556 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - writting netconf stream to oper datastore
693 2019-05-20 16:33:34.556 CEST [main] INFO  i.f.h.t.d.t.DefaultNetconfFactory - file 'oper-ROADMC.xml' exists at location : /home/gilles/git/01/transportpce/tests/honeynode221/honeynode-distribution/target/honeynode-distribution-1.18.01-hc/honeynode-distribution-1.18.01/config/device/oper-ROADMC.xml
694 2019-05-20 16:33:34.577 CEST [main] INFO  i.f.h.t.d.c.NetconfConfiguration - netconf streams result : Streams{getStream=[Stream{getName=StreamNameType [_value=OPENROADM], augmentations={}}], augmentations={}}
695 2019-05-20 16:33:34.579 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - Netconf Data gets from xml file is present
696 2019-05-20 16:33:34.580 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - WriteTransaction is ok
697 2019-05-20 16:33:34.588 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - netconf stream writed to oper datastore
698 2019-05-20 16:33:34.588 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - loading device configuration info from xml file...
699 2019-05-20 16:33:34.588 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - process to transform xml file 
700 2019-05-20 16:33:34.591 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - transforming xml data to config device ...
701 2019-05-20 16:33:34.707 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - removing namespace ...
702 2019-05-20 16:33:34.729 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - device info gets from xml file !
703 2019-05-20 16:33:34.729 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - process to transform xml file to config data
704 2019-05-20 16:33:34.730 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - transforming xml string to config device ...
705 2019-05-20 16:33:34.739 CEST [main] INFO  i.f.h.t.d.t.DefaultDeviceFactory - device data config string is ok 
706 2019-05-20 16:33:34.747 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - result info : NodeIdType [_value=ROADM-C1]
707 2019-05-20 16:33:34.747 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - OrgOpenroadmDevice info gets : NodeIdType [_value=ROADM-C1]
708 2019-05-20 16:33:34.747 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - WriteTransaction is ok, copy device info to config datastore
709 2019-05-20 16:33:34.759 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - device writed to config datastore
710 2019-05-20 16:33:34.760 CEST [main] INFO  i.f.h.t.device.read.PmReaderFactory - writting xml pm file data to oper datastore
711 2019-05-20 16:33:34.760 CEST [main] INFO  i.f.h.t.d.t.DefaultPmListFactory - file with pm 'oper-ROADMC.xml' exists at location : /home/gilles/git/01/transportpce/tests/honeynode221/honeynode-distribution/target/honeynode-distribution-1.18.01-hc/honeynode-distribution-1.18.01/config/device/oper-ROADMC.xml
712 2019-05-20 16:33:34.760 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - onDataTreeChanged
713 2019-05-20 16:33:34.762 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - Received Device change(WRITE):
714  before=null 
715  after=OrgOpenroadmDevice{getCircuitPacks=[CircuitPacks{getAdministrativeState=InService, getCircuitPackMode=NORMAL, getCircuitPackName=1/0/OSC-PLUG, getCircuitPackType=port, getEquipmentState=NotReservedAvailable, getParentCircuitPack=ParentCircuitPack{getCircuitPackName=1/0, getCpSlotName=OSC-SLOT, augmentations={}}, getPorts=[Ports{getAdministrativeState=InService, getPortName=OSC-PORT, getPortQual=RoadmInternal, getPortType=1GEX, augmentations={}}], getShelf=2, getSlot=0, getSubSlot=0, augmentations={}}, CircuitPacks{getAdministrativeState=InService, getCircuitPackMode=inServiceMode, getCircuitPackName=1/0/ETH-PLUG, getCircuitPackProductCode=Eth, getCircuitPackType=port, getEquipmentState=NotReservedAvailable, getParentCircuitPack=ParentCircuitPack{getCircuitPackName=1/0, getCpSlotName=ETH-PLUG, augmentations={}}, getPorts=[Ports{getAdministrativeState=InService, getPortName=ETH-PLUG, getPortQual=RoadmInternal, getPortType=1GEX, augmentations={}}], getShelf=1, getSlot=1, getSubSlot=0, augmentations={}}, CircuitPacks{getAdministrativeState=InService, getCircuitPackMode=inServiceMode, getCircuitPackName=1/0, getCircuitPackProductCode=DegW, getCircuitPackType=WSSDEG, getEquipmentState=NotReservedAvailable, getPorts=[Ports{getAdministrativeState=InService, getCircuitId=1, getLogicalConnectionPoint=DEG1-TTP-TXRX, getPortName=L1, getPortQual=RoadmExternal, getPortType=LINE, augmentations={}}, Ports{getAdministrativeState=InService, getCircuitId=1, getLogicalConnectionPoint=DEG1-CTP-TXRX, getPortName=C1, getPortQual=RoadmInternal, getPortType=Client, augmentations={}}, Ports{getAdministrativeState=InService, getCircuitId=1, getLogicalConnectionPoint=DEG1-CTP-TXRX, getPortName=C2, getPortQual=RoadmInternal, getPortType=Client, augmentations={}}, Ports{getAdministrativeState=InService, getCircuitId=1, getLogicalConnectionPoint=DEG1-CTP-TXRX, getPortName=C3, getPortQual=RoadmInternal, getPortType=Client, augmentations={}}, Ports{getAdministrativeState=InService, getCircuitId=1, getLogicalConnectionPoint=DEG1-CTP-TXRX, getPortName=C4, getPortQual=RoadmInternal, getPortType=Client, augmentations={}}], getShelf=1, getSlot=1, augmentations={}}, CircuitPacks{getAdministrativeState=InService, getCircuitPackMode=inServiceMode, getCircuitPackName=3/0, getCircuitPackProductCode=SRGRx, getCircuitPackType=ADDDROP, getEquipmentState=ReservedForFacilityAvailable, getPorts=[Ports{getAdministrativeState=InService, getLogicalConnectionPoint=SRG1-CP-TXRX, getPortName=AD-DEG1, getPortQual=RoadmInternal, getPortType=Edge, augmentations={}}, Ports{getAdministrativeState=InService, getCircuitId=SRG1, getLogicalConnectionPoint=SRG1-PP1, getPortName=C1, getPortQual=RoadmExternal, getPortType=Client, augmentations={}}, Ports{getAdministrativeState=InService, getCircuitId=SRG1, getLogicalConnectionPoint=SRG1-PP2, getPortName=C2, getPortQual=RoadmExternal, getPortType=Client, augmentations={}}, Ports{getAdministrativeState=InService, getLogicalConnectionPoint=SRG1-CP-TXRX, getPortName=AD-DEG2, getPortQual=RoadmInternal, getPortType=Edge, augmentations={}}, Ports{getAdministrativeState=InService, getCircuitId=SRG1, getLogicalConnectionPoint=SRG1-PP3, getPortName=C3, getPortQual=RoadmExternal, getPortType=Client, augmentations={}}, Ports{getAdministrativeState=InService, getCircuitId=SRG1, getLogicalConnectionPoint=SRG1-PP4, getPortName=C4, getPortQual=RoadmExternal, getPortType=Client, augmentations={}}], getShelf=1, getSlot=2, augmentations={}}], getDegree=[Degree{getCircuitPacks=[CircuitPacks{getCircuitPackName=1/0/ETH-PLUG, getIndex=1, augmentations={}}], getConnectionPorts=[ConnectionPorts{getCircuitPackName=1/0, getIndex=1, getPortName=L1, augmentations={}}], getDegreeNumber=1, augmentations={}}], getInfo=Info{getClli=NodeC, getDefaultGateway=IpAddress [_ipv4Address=Ipv4Address [_value=127.0.0.20]], getGeoLocation=GeoLocation{getLatitude=1.0000, getLongitude=2.0000, augmentations={}}, getIpAddress=IpAddress [_ipv4Address=Ipv4Address [_value=127.0.0.11]], getNodeId=NodeIdType [_value=ROADM-C1], getNodeNumber=4, getNodeType=Rdm, getPrefixLength=28, getTemplate=template_1, augmentations={}}, getInterface=[Interface{getAdministrativeState=InService, getCircuitId=TBD, getDescription=TBD, getName=OMS-DEG1-TTP-TXRX, getSupportingCircuitPackName=1/0, getSupportingInterface=OTS-DEG1-TTP-TXRX, getSupportingPort=L1, getType=class org.opendaylight.yang.gen.v1.http.org.openroadm.interfaces.rev170626.OpenROADMOpticalMultiplex, augmentations={}}, Interface{getAdministrativeState=InService, getName=1GE-interface-1, getSupportingCircuitPackName=1/0/ETH-PLUG, getSupportingPort=ETH-PLUG, getType=class org.opendaylight.yang.gen.v1.http.org.openroadm.interfaces.rev170626.EthernetCsmacd, augmentations={interface org.opendaylight.yang.gen.v1.http.org.openroadm.ethernet.interfaces.rev181019.Interface1=Interface1{getEthernet=Ethernet{getAutoNegotiation=Enabled, getDuplex=Full, getMtu=1800, getSpeed=1000, augmentations={}}}}}, Interface{getAdministrativeState=InService, getName=OTS-DEG1-TTP-TXRX, getSupportingCircuitPackName=1/0, getSupportingPort=L1, getType=class org.opendaylight.yang.gen.v1.http.org.openroadm.interfaces.rev170626.OpticalTransport, augmentations={interface org.opendaylight.yang.gen.v1.http.org.openroadm.optical.transport.interfaces.rev181019.Interface1=Interface1{getOts=Ots{getFiberType=Smf, getIngressSpanLossAgingMargin=RatioDB [_value=0, _UNITS=dB], getSpanLossReceive=RatioDB [_value=15, _UNITS=dB], getSpanLossTransmit=RatioDB [_value=6, _UNITS=dB], augmentations={}}}}}], getProtocols=Protocols{augmentations={interface org.opendaylight.yang.gen.v1.http.org.openroadm.lldp.rev181019.Protocols1=Protocols1{getLldp=Lldp{getGlobalConfig=GlobalConfig{getAdminStatus=Enable, getMsgTxHoldMultiplier=4, getMsgTxInterval=20, augmentations={}}, getPortConfig=[PortConfig{getAdminStatus=Txandrx, getIfName=1GE-interface-1, augmentations={}}], augmentations={}}}}}, getSharedRiskGroup=[SharedRiskGroup{getCircuitPacks=[CircuitPacks{getCircuitPackName=3/0, getIndex=1, augmentations={}}], getSrgNumber=1, augmentations={}}], getUsers=Users{getUser=[User{getGroup=Sudo, getName=UsernameType [_value=openroadm], getPassword=PasswordType [_value=openroadm], augmentations={}}], augmentations={}}, augmentations={}}
716 2019-05-20 16:33:34.773 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - processing change ...
717 2019-05-20 16:33:34.774 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - WriteTransactions are ok, merge device info to datastores
718 2019-05-20 16:33:34.784 CEST [main] INFO  i.f.h.t.d.c.PmConfiguration - result pm list size : 1
719 2019-05-20 16:33:34.784 CEST [main] INFO  i.f.h.t.device.read.PmReaderFactory - Getting pm info from xml file for device 
720 2019-05-20 16:33:34.785 CEST [main] INFO  i.f.h.t.device.read.PmReaderFactory - WriteTransaction is ok, copy currentPmList to oper datastore
721 2019-05-20 16:33:34.789 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - device 'ROADM-C1' merged to device oper datastore
722 2019-05-20 16:33:34.816 CEST [main] INFO  i.f.h.t.device.read.PmReaderFactory - currentPmList writed to oper datastore
723 2019-05-20 16:33:34.822 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.oper.ReadableDTDelegProvider@474e0ab4
724 2019-05-20 16:33:34.824 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfBindingBrokerProvider@600c5acf
725 2019-05-20 16:33:34.826 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfNotificationMapperProvider@56677422
726 2019-05-20 16:33:34.833 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.RpcRegistryBuilderProvider@501c3ef6
727 2019-05-20 16:33:34.834 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.RpcRegistryProvider@40ba320f
728 2019-05-20 16:33:34.835 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.HoneycombDOMRpcServiceProvider@6981107f
729 2019-05-20 16:33:34.836 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfMdsalMapperProvider@77f3e77a
730 2019-05-20 16:33:34.863 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfMonitoringServiceProvider@34b1bc0f
731 2019-05-20 16:33:34.876 CEST [main] INFO  o.o.n.i.o.NetconfSessionMonitoringService - Scheduling thread pool is present = false, update interval 0: /netconf-state/sessions won't be updated.
732 2019-05-20 16:33:34.876 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfMonitoringMapperProvider@49b257f9
733 2019-05-20 16:33:34.895 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DOMNotificationServiceProvider@21622e1
734 2019-05-20 16:33:34.907 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.HoneycombNotificationManagerProvider@58ef7429
735 2019-05-20 16:33:34.911 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.HoneycombNotification2NetconfProvider@541c9054
736 2019-05-20 16:33:34.918 CEST [main] INFO  i.f.h.n.n.HoneycombNotification2NetconfProvider - Exposing HONEYCOMB_NETCONF notification stream: honeycomb
737 2019-05-20 16:33:34.918 CEST [pool-18-thread-3] INFO  i.f.h.t.d.n.DeviceNotificationProducer - Starting notification stream for OrgOpenroadmDevice
738 2019-05-20 16:33:34.918 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NettyThreadGroupProvider@34f8cee0
739 2019-05-20 16:33:34.920 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - onDataTreeChanged
740 2019-05-20 16:33:34.920 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - transforming changes to notification...
741 2019-05-20 16:33:34.920 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - Received Device change :
742 WRITE
743 2019-05-20 16:33:34.921 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - device operational datastore is created !
744 2019-05-20 16:33:34.921 CEST [operational-DCL-0] WARN  i.f.h.t.d.n.DeviceNotificationProducer - edit List is empty !
745 2019-05-20 16:33:34.921 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - Emitting notification : null
746 2019-05-20 16:33:34.921 CEST [operational-DCL-0] WARN  i.f.h.t.d.n.DeviceNotificationProducer - Failed to emit notification
747 2019-05-20 16:33:34.948 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfServerDispatcherProvider@5555eb81
748 2019-05-20 16:33:34.954 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfTcpServerProvider@169d11c5
749 2019-05-20 16:33:34.955 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfSshServerProvider@1894b733
750 2019-05-20 16:33:34.955 CEST [main] INFO  i.f.h.n.n.NetconfSshServerProvider - Starting NETCONF SSH
751 2019-05-20 16:33:35.020 CEST [main] WARN  io.netty.bootstrap.ServerBootstrap - Unknown channel option 'SO_BACKLOG' for channel '[id: 0x42478495]'
752 2019-05-20 16:33:35.290 CEST [main] INFO  io.fd.honeycomb.infra.distro.Main - Initializing configuration
753 2019-05-20 16:33:35.291 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.context.PersistedContextInitializerProvider@59d768de
754 2019-05-20 16:33:35.292 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.PersistedConfigInitializerProvider@1bac51bd
755 2019-05-20 16:33:35.292 CEST [main] INFO  i.f.h.i.d.d.PersistedConfigInitializerProvider - RestoringInitializer ...
756 2019-05-20 16:33:35.293 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.initializer.ModifiableDTDelegInitProvider@6150e1c5
757 2019-05-20 16:33:35.293 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.HoneycombDOMDataBrokerProvider@7ab8af34
758 2019-05-20 16:33:35.293 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.BindingDataBrokerProvider@2fdd5baa
759 2019-05-20 16:33:35.294 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.context.RealtimeMappingContextProvider@698ba673
760 2019-05-20 16:33:35.294 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.initializer.InitializerRegistryAdapterProvider@7d5b1786
761 2019-05-20 16:33:35.294 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Config initialization started
762 2019-05-20 16:33:35.294 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Persisted context restored successfully
763 2019-05-20 16:33:35.295 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Configuration initialized successfully
764 2019-05-20 16:33:35.295 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Persisted configuration restored successfully
765 2019-05-20 16:33:35.295 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Honeycomb initialized
766 2019-05-20 16:33:35.295 CEST [main] INFO  io.fd.honeycomb.infra.distro.Main - Configuration initialized successfully
767 2019-05-20 16:33:35.295 CEST [main] INFO  io.fd.honeycomb.infra.distro.Main - Honeycomb started successfully!
768 2019-05-20 16:33:35.375 CEST [netconf-netty-0] INFO  i.f.h.n.n.NetconfSshServerProvider - Netconf SSH endpoint started successfully at /0.0.0.0:17843
769 2019-05-20 16:34:57.288 CEST [main] INFO  io.fd.honeycomb.infra.distro.Main - Starting honeycomb
770 2019-05-20 16:34:57.594 CEST [main] INFO  i.f.h.i.d.a.ActiveModuleProvider - Reading active modules configuration for distribution
771 2019-05-20 16:34:57.622 CEST [main] INFO  i.f.h.t.device.DeviceModule - Initializing Device Module
772 2019-05-20 16:34:57.633 CEST [main] INFO  i.f.h.t.d.c.DeviceConfigurationModule - Initializing Device Readers Module
773 2019-05-20 16:34:57.636 CEST [main] INFO  i.f.h.t.d.c.PmConfigurationModule - Initializing Pm Readers Module
774 2019-05-20 16:34:57.638 CEST [main] INFO  i.f.h.t.device.DeviceModule - Device Module intitailized !
775 2019-05-20 16:34:57.638 CEST [main] INFO  i.f.h.t.d.c.NetconfConfigurationModule - Initializing Netconf Readers Module
776 2019-05-20 16:34:57.640 CEST [main] INFO  i.f.h.t.device.DeviceModule - Netconf Module intitailized !
777 2019-05-20 16:34:57.642 CEST [main] INFO  i.f.h.i.d.s.YangBindingProviderModule - Configuring YangBindingProviderModule
778 2019-05-20 16:34:57.643 CEST [main] INFO  i.f.h.t.device.DeviceRpcModule - Initializing Device Rpcs Module
779 2019-05-20 16:34:57.664 CEST [main] INFO  i.f.h.t.d.DeviceNotificationModule - Initializing Device Notification Module
780 2019-05-20 16:34:57.667 CEST [main] INFO  i.f.h.t.device.DeviceWriterModule - Initializing Device Writers Module
781 2019-05-20 16:34:57.677 CEST [main] INFO  i.f.h.n.n.NetconfReadersModule - Initializing NETCONF Northbound readers
782 2019-05-20 16:34:57.680 CEST [main] INFO  i.f.h.n.netconf.NetconfModule - Starting NETCONF Northbound
783 2019-05-20 16:34:57.809 CEST [main] INFO  i.f.h.t.device.DeviceReaderModule - Initializing Device, PM and Netconf Readers Module
784 2019-05-20 16:34:58.002 CEST [main] INFO  i.f.h.i.d.a.ActiveModuleProvider - Reading active modules configuration for distribution
785 2019-05-20 16:34:58.031 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: ModuleInfoBackedCtxProvider{writerFactories=io.fd.honeycomb.infra.distro.schema.YangModulesProvider$YangModules@447a020}
786 2019-05-20 16:34:58.565 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.schema.SchemaServiceProvider@4c36250e
787 2019-05-20 16:34:59.273 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataTreeProvider$ContextDataTreeProvider@6cc558c6
788 2019-05-20 16:34:59.294 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.PersistingDataTreeProvider$ContextPersistingDataTreeProvider@63f259c3
789 2019-05-20 16:34:59.295 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.context.ModifiableDTMgrProvider@3db972d2
790 2019-05-20 16:34:59.295 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.schema.SerializerProvider@158f4cfe
791 2019-05-20 16:34:59.575 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataTreeProvider$ConfigDataTreeProvider@77774571
792 2019-05-20 16:34:59.575 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.PersistingDataTreeProvider$ConfigPersistingDataTreeProvider@6cd64ee8
793 2019-05-20 16:34:59.576 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataStoreProvider@62010f5c
794 2019-05-20 16:34:59.588 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataStoreProvider@132e0cc
795 2019-05-20 16:34:59.588 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.InmemoryDOMDataBrokerProvider@75de29c0
796 2019-05-20 16:34:59.597 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.transportpce.device.DeviceBindingDataBrokerProvider@1e253c9d
797 2019-05-20 16:34:59.600 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.config.WriterRegistryProvider@20b9d5d5
798 2019-05-20 16:34:59.641 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.context.HoneycombContextDOMDataBrokerProvider@26ceffa8
799 2019-05-20 16:34:59.642 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.BindingDataBrokerProvider@67064bdc
800 2019-05-20 16:34:59.642 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.ModifiableDTDelegProvider@18578491
801 2019-05-20 16:34:59.643 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataStoreProvider@7c8c9a05
802 2019-05-20 16:34:59.643 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DataStoreProvider@5c2375a9
803 2019-05-20 16:34:59.643 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.InmemoryDOMDataBrokerProvider@5ad5be4a
804 2019-05-20 16:34:59.643 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.BindingDataBrokerProvider@737d100a
805 2019-05-20 16:34:59.644 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfMonitoringReaderFactoryProvider@6535117e
806 2019-05-20 16:34:59.644 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfNotificationsReaderFactoryProvider@f88bfbe
807 2019-05-20 16:35:04.847 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.oper.ReaderRegistryProvider@380d3099
808 2019-05-20 16:35:04.851 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - writting xml file data to oper datastore
809 2019-05-20 16:35:04.851 CEST [main] INFO  i.f.h.t.d.t.DefaultDeviceFactory - file 'oper-XPDRC.xml' exists at location : /home/gilles/git/01/transportpce/tests/honeynode221/honeynode-distribution/target/honeynode-distribution-1.18.01-hc/honeynode-distribution-1.18.01/config/device/oper-XPDRC.xml
810 2019-05-20 16:35:04.951 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - result info : NodeIdType [_value=XPDR-C1]
811 2019-05-20 16:35:04.951 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - Getting device info from xml file for device 'XPDR-C1'
812 2019-05-20 16:35:05.009 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - WriteTransaction is ok, copy device info to oper datastore
813 2019-05-20 16:35:05.574 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - device 'XPDR-C1' writed to oper datastore
814 2019-05-20 16:35:05.574 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - writting netconf state to oper datastore
815 2019-05-20 16:35:05.574 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - Loading models from directory.
816 2019-05-20 16:35:05.575 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - folder '/home/gilles/git/01/transportpce/tests/honeynode221/honeynode-distribution/target/honeynode-distribution-1.18.01-hc/honeynode-distribution-1.18.01/config/yang' exists !
817 2019-05-20 16:35:05.788 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - WriteTransaction is ok, copy device info to oper datastore
818 2019-05-20 16:35:05.833 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - netconf state writed to oper datastore
819 2019-05-20 16:35:05.833 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - writting netconf stream to oper datastore
820 2019-05-20 16:35:05.833 CEST [main] INFO  i.f.h.t.d.t.DefaultNetconfFactory - file 'oper-XPDRC.xml' exists at location : /home/gilles/git/01/transportpce/tests/honeynode221/honeynode-distribution/target/honeynode-distribution-1.18.01-hc/honeynode-distribution-1.18.01/config/device/oper-XPDRC.xml
821 2019-05-20 16:35:05.851 CEST [main] INFO  i.f.h.t.d.c.NetconfConfiguration - netconf streams result : Streams{getStream=[Stream{getName=StreamNameType [_value=OPENROADM], augmentations={}}], augmentations={}}
822 2019-05-20 16:35:05.853 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - Netconf Data gets from xml file is present
823 2019-05-20 16:35:05.854 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - WriteTransaction is ok
824 2019-05-20 16:35:05.862 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - netconf stream writed to oper datastore
825 2019-05-20 16:35:05.862 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - loading device configuration info from xml file...
826 2019-05-20 16:35:05.862 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - process to transform xml file 
827 2019-05-20 16:35:05.865 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - transforming xml data to config device ...
828 2019-05-20 16:35:05.975 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - removing namespace ...
829 2019-05-20 16:35:05.992 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - device info gets from xml file !
830 2019-05-20 16:35:05.992 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - process to transform xml file to config data
831 2019-05-20 16:35:05.993 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - transforming xml string to config device ...
832 2019-05-20 16:35:06.001 CEST [main] INFO  i.f.h.t.d.t.DefaultDeviceFactory - device data config string is ok 
833 2019-05-20 16:35:06.007 CEST [main] INFO  i.f.h.t.d.c.DeviceConfiguration - result info : NodeIdType [_value=XPDR-C1]
834 2019-05-20 16:35:06.007 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - OrgOpenroadmDevice info gets : NodeIdType [_value=XPDR-C1]
835 2019-05-20 16:35:06.007 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - WriteTransaction is ok, copy device info to config datastore
836 2019-05-20 16:35:06.017 CEST [main] INFO  i.f.h.t.d.read.DeviceReaderFactory - device writed to config datastore
837 2019-05-20 16:35:06.017 CEST [main] INFO  i.f.h.t.device.read.PmReaderFactory - writting xml pm file data to oper datastore
838 2019-05-20 16:35:06.017 CEST [main] INFO  i.f.h.t.d.t.DefaultPmListFactory - file with pm 'oper-XPDRC.xml' exists at location : /home/gilles/git/01/transportpce/tests/honeynode221/honeynode-distribution/target/honeynode-distribution-1.18.01-hc/honeynode-distribution-1.18.01/config/device/oper-XPDRC.xml
839 2019-05-20 16:35:06.017 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - onDataTreeChanged
840 2019-05-20 16:35:06.018 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - Received Device change(WRITE):
841  before=null 
842  after=OrgOpenroadmDevice{getCircuitPacks=[CircuitPacks{getAdministrativeState=InService, getCircuitPackMode=inServiceMode, getCircuitPackName=1/0, getCircuitPackProductCode=baseXPDR, getCircuitPackType=Base_transponder_circuit_pack, getShelf=1, getSlot=1, augmentations={}}, CircuitPacks{getCircuitPackMode=NORMAL, getCircuitPackName=1/0/1-PLUG-CLIENT, getCircuitPackProductCode=Client_P, getCircuitPackType=client_pluggable, getParentCircuitPack=ParentCircuitPack{getCircuitPackName=1/0, getCpSlotName=2, augmentations={}}, getPorts=[Ports{getAdministrativeState=InService, getPortName=C1, getPortQual=XpdrClient, getPortType=QSFP28, augmentations={}}], getShelf=1, getSlot=1, getSubSlot=1, augmentations={}}, CircuitPacks{getCircuitPackMode=NORMAL, getCircuitPackName=1/0/2-PLUG-CLIENT, getCircuitPackProductCode=Client_P, getCircuitPackType=client_pluggable, getParentCircuitPack=ParentCircuitPack{getCircuitPackName=1/0, getCpSlotName=4, augmentations={}}, getPorts=[Ports{getAdministrativeState=InService, getPortName=C1, getPortQual=XpdrClient, getPortType=QSFP28, augmentations={}}], getShelf=1, getSlot=1, getSubSlot=1, augmentations={}}, CircuitPacks{getCircuitPackMode=NORMAL, getCircuitPackName=1/0/1-PLUG-NET, getCircuitPackProductCode=Line_NW_P, getCircuitPackType=line_pluggable, getParentCircuitPack=ParentCircuitPack{getCircuitPackName=1/0, getCpSlotName=1, augmentations={}}, getPorts=[Ports{getAdministrativeState=InService, getPortName=1, getPortQual=XpdrNetwork, getPortType=CFP2, augmentations={}}], getShelf=1, getSlot=1, getSubSlot=1, augmentations={}}, CircuitPacks{getCircuitPackMode=NORMAL, getCircuitPackName=1/0/2-PLUG-NET, getCircuitPackProductCode=Line_NW_P, getCircuitPackType=line_pluggable, getParentCircuitPack=ParentCircuitPack{getCircuitPackName=1/0, getCpSlotName=3, augmentations={}}, getPorts=[Ports{getAdministrativeState=InService, getPortName=1, getPortQual=XpdrNetwork, getPortType=CFP2, augmentations={}}], getShelf=1, getSlot=1, getSubSlot=1, augmentations={}}], getInfo=Info{getClli=NodeC, getDefaultGateway=IpAddress [_ipv4Address=Ipv4Address [_value=1.2.3.4]], getGeoLocation=GeoLocation{getLatitude=1.0000, getLongitude=2.0000, augmentations={}}, getIpAddress=IpAddress [_ipv4Address=Ipv4Address [_value=1.2.3.4]], getNodeId=NodeIdType [_value=XPDR-C1], getNodeNumber=1, getNodeType=Xpdr, getPrefixLength=24, getTemplate=template_TRANSPONDER, augmentations={}}, getShelves=[Shelves{getAdministrativeState=InService, getDueDate=DateAndTime [_value=2017-02-24T15:56:10+00:00], getRack=XYZ, getShelfName=1, getShelfPosition=1, getShelfType=pizza, augmentations={}}], getUsers=Users{getUser=[User{getGroup=Sudo, getName=UsernameType [_value=openroadm], getPassword=PasswordType [_value=openroadm], augmentations={}}], augmentations={}}, augmentations={}}
843 2019-05-20 16:35:06.026 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - processing change ...
844 2019-05-20 16:35:06.026 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - WriteTransactions are ok, merge device info to datastores
845 2019-05-20 16:35:06.033 CEST [config-DCL-0] INFO  i.f.h.t.d.w.DeviceChangeListener - device 'XPDR-C1' merged to device oper datastore
846 2019-05-20 16:35:06.034 CEST [main] INFO  i.f.h.t.d.c.PmConfiguration - result pm list size : 1
847 2019-05-20 16:35:06.034 CEST [main] INFO  i.f.h.t.device.read.PmReaderFactory - Getting pm info from xml file for device 
848 2019-05-20 16:35:06.035 CEST [main] INFO  i.f.h.t.device.read.PmReaderFactory - WriteTransaction is ok, copy currentPmList to oper datastore
849 2019-05-20 16:35:06.067 CEST [main] INFO  i.f.h.t.device.read.PmReaderFactory - currentPmList writed to oper datastore
850 2019-05-20 16:35:06.074 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.oper.ReadableDTDelegProvider@571ae6d5
851 2019-05-20 16:35:06.076 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfBindingBrokerProvider@59ef35de
852 2019-05-20 16:35:06.078 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfNotificationMapperProvider@2eaafa39
853 2019-05-20 16:35:06.087 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.RpcRegistryBuilderProvider@48e48923
854 2019-05-20 16:35:06.087 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.RpcRegistryProvider@6c1f6481
855 2019-05-20 16:35:06.088 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.HoneycombDOMRpcServiceProvider@2a428e3b
856 2019-05-20 16:35:06.089 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfMdsalMapperProvider@4473d830
857 2019-05-20 16:35:06.100 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfMonitoringServiceProvider@73e15280
858 2019-05-20 16:35:06.131 CEST [main] INFO  o.o.n.i.o.NetconfSessionMonitoringService - Scheduling thread pool is present = false, update interval 0: /netconf-state/sessions won't be updated.
859 2019-05-20 16:35:06.132 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfMonitoringMapperProvider@47a20fab
860 2019-05-20 16:35:06.152 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.DOMNotificationServiceProvider@719edb69
861 2019-05-20 16:35:06.166 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.HoneycombNotificationManagerProvider@71e21f48
862 2019-05-20 16:35:06.170 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.HoneycombNotification2NetconfProvider@18f557ce
863 2019-05-20 16:35:06.176 CEST [main] INFO  i.f.h.n.n.HoneycombNotification2NetconfProvider - Exposing HONEYCOMB_NETCONF notification stream: honeycomb
864 2019-05-20 16:35:06.176 CEST [pool-18-thread-3] INFO  i.f.h.t.d.n.DeviceNotificationProducer - Starting notification stream for OrgOpenroadmDevice
865 2019-05-20 16:35:06.176 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NettyThreadGroupProvider@53600a30
866 2019-05-20 16:35:06.178 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - onDataTreeChanged
867 2019-05-20 16:35:06.178 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - transforming changes to notification...
868 2019-05-20 16:35:06.178 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - Received Device change :
869 WRITE
870 2019-05-20 16:35:06.179 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - device operational datastore is created !
871 2019-05-20 16:35:06.179 CEST [operational-DCL-0] WARN  i.f.h.t.d.n.DeviceNotificationProducer - edit List is empty !
872 2019-05-20 16:35:06.179 CEST [operational-DCL-0] INFO  i.f.h.t.d.n.DeviceNotificationProducer - Emitting notification : null
873 2019-05-20 16:35:06.179 CEST [operational-DCL-0] WARN  i.f.h.t.d.n.DeviceNotificationProducer - Failed to emit notification
874 2019-05-20 16:35:06.203 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfServerDispatcherProvider@3fd762bb
875 2019-05-20 16:35:06.207 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfTcpServerProvider@2b6cd876
876 2019-05-20 16:35:06.208 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.northbound.netconf.NetconfSshServerProvider@70207dcb
877 2019-05-20 16:35:06.208 CEST [main] INFO  i.f.h.n.n.NetconfSshServerProvider - Starting NETCONF SSH
878 2019-05-20 16:35:06.269 CEST [main] WARN  io.netty.bootstrap.ServerBootstrap - Unknown channel option 'SO_BACKLOG' for channel '[id: 0x85cde949]'
879 2019-05-20 16:35:06.542 CEST [main] INFO  io.fd.honeycomb.infra.distro.Main - Initializing configuration
880 2019-05-20 16:35:06.543 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.context.PersistedContextInitializerProvider@1eb9713
881 2019-05-20 16:35:06.544 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.PersistedConfigInitializerProvider@514753f4
882 2019-05-20 16:35:06.544 CEST [main] INFO  i.f.h.i.d.d.PersistedConfigInitializerProvider - RestoringInitializer ...
883 2019-05-20 16:35:06.544 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.initializer.ModifiableDTDelegInitProvider@2f8a57c2
884 2019-05-20 16:35:06.545 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.HoneycombDOMDataBrokerProvider@61d2ff30
885 2019-05-20 16:35:06.545 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.BindingDataBrokerProvider@6c60a141
886 2019-05-20 16:35:06.545 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.data.context.RealtimeMappingContextProvider@78626f16
887 2019-05-20 16:35:06.546 CEST [main] INFO  i.f.h.binding.init.ProviderTrait - Providing: io.fd.honeycomb.infra.distro.initializer.InitializerRegistryAdapterProvider@3e666559
888 2019-05-20 16:35:06.546 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Config initialization started
889 2019-05-20 16:35:06.546 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Persisted context restored successfully
890 2019-05-20 16:35:06.547 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Configuration initialized successfully
891 2019-05-20 16:35:06.547 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Persisted configuration restored successfully
892 2019-05-20 16:35:06.547 CEST [main] INFO  i.f.h.i.d.i.InitializerRegistryAdapter - Honeycomb initialized
893 2019-05-20 16:35:06.547 CEST [main] INFO  io.fd.honeycomb.infra.distro.Main - Configuration initialized successfully
894 2019-05-20 16:35:06.547 CEST [main] INFO  io.fd.honeycomb.infra.distro.Main - Honeycomb started successfully!
895 2019-05-20 16:35:06.629 CEST [netconf-netty-0] INFO  i.f.h.n.n.NetconfSshServerProvider - Netconf SSH endpoint started successfully at /0.0.0.0:17844
896 2019-05-20 16:39:00.502 CEST [Thread-5] INFO  i.f.h.impl.ShutdownHandlerImpl - Closing component notification-to-mdsal-writer
897 2019-05-20 16:39:00.503 CEST [Thread-5] INFO  i.f.h.impl.ShutdownHandlerImpl - Closing component netconf-notification-service-factory
898 2019-05-20 16:39:03.270 CEST [Thread-5] INFO  i.f.h.impl.ShutdownHandlerImpl - Closing component notification-to-mdsal-writer
899 2019-05-20 16:39:03.271 CEST [Thread-5] INFO  i.f.h.impl.ShutdownHandlerImpl - Closing component netconf-notification-service-factory
900 2019-05-20 16:39:04.292 CEST [Thread-5] INFO  i.f.h.impl.ShutdownHandlerImpl - Closing component notification-to-mdsal-writer
901 2019-05-20 16:39:04.293 CEST [Thread-5] INFO  i.f.h.impl.ShutdownHandlerImpl - Closing component netconf-notification-service-factory
902 2019-05-20 16:39:05.317 CEST [Thread-5] INFO  i.f.h.impl.ShutdownHandlerImpl - Closing component notification-to-mdsal-writer
903 2019-05-20 16:39:05.319 CEST [Thread-5] INFO  i.f.h.impl.ShutdownHandlerImpl - Closing component netconf-notification-service-factory