search

OSGP / Documentation

This repository contains documentation for the Open Smart Grid Platform project. This repository is built as a GitBook, therefore all content has to be written using markdown syntax. See the latest GitBook:
https://documentation.gxf.lfenergy.org/
Apache License 2.0
24 stars 15 forks source link

Registering a simulated device times out #205

Closed sameersubudhi closed 5 years ago

sameersubudhi commented 5 years ago

Hi,

While I try to register a simulated device on the locally installed OSGP platform, I receive a timeout message. Meanwhile, I see the below error messages related to encryption:

Security exception creating public key for algorithm "EC" by provider "SunPKCS11-NSS"

Kindly help me resolve the issue. The screenshot and the generated logs are attached below.

screenshot from 2019-02-04 11-14-23 Logs:

2019-02-04 09:39:30.301] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-13] INFO o.o.w.service.RegisterDevice@sendRequest:309 - Trying to send request: registerDeviceRequest {
  deviceIdentification: "SSLD_000-00-01"
  ipAddress: "\000\000\001"
  deviceType: SSLD
  hasSchedule: false
  randomDevice: 42264
}

2019-02-04 09:39:30.310] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-13] INFO o.o.w.service.OslpChannelHandler@send:396 - Sending OSLP request: registerDeviceRequest {
  deviceIdentification: "SSLD_000-00-01"
  ipAddress: "\000\000\001"
  deviceType: SSLD
  hasSchedule: false
  randomDevice: 42264
}

2019-02-04 09:39:30.789] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-13] INFO o.o.w.a.config.ApplicationContext@lambda$clientBootstrap$0:269 - Created new client pipeline
2019-02-04 09:39:38.830] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-13] INFO o.o.w.service.OslpChannelHandler@channelOpen:356 - Channel -1836240726 opened
2019-02-04 09:39:39.865] [bsu-ThinkPad-T470] [New I/O server boss #18] INFO o.o.a.p.o.e.a.config.OslpConfig@getPipeline:114 - Created server new pipeline
2019-02-04 09:39:40.315] [bsu-ThinkPad-T470] [New I/O server boss #18] INFO o.j.n.handler.logging.LoggingHandler@info:48 - [id: 0x036dd0f2, /127.0.0.1:38332 => /127.0.0.1:12122] OPEN
2019-02-04 09:39:40.317] [bsu-ThinkPad-T470] [New I/O server boss #18] INFO o.o.a.p.o.e.i.n.OslpChannelHandlerServer@channelOpen:71 - 57528562 Channel opened
2019-02-04 09:39:40.320] [bsu-ThinkPad-T470] [New I/O worker #10] INFO o.j.n.handler.logging.LoggingHandler@info:48 - [id: 0x036dd0f2, /127.0.0.1:38332 => /127.0.0.1:12122] BOUND: /127.0.0.1:12122
2019-02-04 09:39:40.320] [bsu-ThinkPad-T470] [New I/O worker #10] INFO o.j.n.handler.logging.LoggingHandler@info:48 - [id: 0x036dd0f2, /127.0.0.1:38332 => /127.0.0.1:12122] CONNECTED: /127.0.0.1:38332
2019-02-04 09:39:45.509] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-13] INFO o.o.w.service.OslpChannelHandler@send:408 - Connection established to: localhost/127.0.0.1:12122
2019-02-04 09:39:45.787] [bsu-ThinkPad-T470] [New I/O worker #10] INFO o.j.n.handler.logging.LoggingHandler@info:48 - [id: 0x036dd0f2, /127.0.0.1:38332 => /127.0.0.1:12122] RECEIVED: BigEndianHeapChannelBuffer(ridx=0, widx=176, cap=176)
2019-02-04 09:39:45.832] [bsu-ThinkPad-T470] [New I/O worker #10] INFO o.o.a.p.o.e.a.s.o.OslpDeviceSettingsService@getDeviceByDeviceIdentification:68 - get device by device identification: SSLD_000-00-01
2019-02-04 09:39:46.060] [bsu-ThinkPad-T470] [New I/O worker #10] INFO o.j.n.handler.logging.LoggingHandler@info:52 - [id: 0x036dd0f2, /127.0.0.1:38332 => /127.0.0.1:12122] EXCEPTION: org.opensmartgridplatform.shared.exceptionhandling.EncrypterException: Security exception creating public key for algorithm "EC" by provider "SunPKCS11-NSS"
org.opensmartgridplatform.shared.exceptionhandling.EncrypterException: Security exception creating public key for algorithm "EC" by provider "SunPKCS11-NSS"
    at org.opensmartgridplatform.shared.security.CertificateHelper.createPublicKey(CertificateHelper.java:149) ~[shared-4.35.0-SNAPSHOT.jar:na]
    at org.opensmartgridplatform.shared.security.CertificateHelper.createPublicKeyFromBase64(CertificateHelper.java:139) ~[shared-4.35.0-SNAPSHOT.jar:na]
    at org.opensmartgridplatform.adapter.protocol.oslp.elster.infra.networking.OslpSecurityHandler.messageReceived(OslpSecurityHandler.java:65) ~[classes/:na]
    at org.jboss.netty.channel.SimpleChannelHandler.handleUpstream(SimpleChannelHandler.java:88) ~[netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:296) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.handler.codec.frame.FrameDecoder.unfoldAndFireMessageReceived(FrameDecoder.java:462) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.handler.codec.replay.ReplayingDecoder.callDecode(ReplayingDecoder.java:536) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.handler.codec.replay.ReplayingDecoder.messageReceived(ReplayingDecoder.java:435) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.handler.logging.LoggingHandler.handleUpstream(LoggingHandler.java:332) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:559) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:268) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:255) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.socket.nio.NioWorker.read(NioWorker.java:88) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.socket.nio.AbstractNioWorker.process(AbstractNioWorker.java:108) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:318) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42) [netty-3.9.4.Final.jar:na]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_201]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_201]
    at java.lang.Thread.run(Thread.java:748) [na:1.8.0_201]
Caused by: java.security.NoSuchProviderException: no such provider: SunPKCS11-NSS
    at sun.security.jca.GetInstance.getService(GetInstance.java:83) ~[na:1.8.0_201]
    at sun.security.jca.GetInstance.getInstance(GetInstance.java:206) ~[na:1.8.0_201]
    at java.security.KeyFactory.getInstance(KeyFactory.java:211) ~[na:1.8.0_201]
    at org.opensmartgridplatform.shared.security.CertificateHelper.createPublicKey(CertificateHelper.java:145) ~[shared-4.35.0-SNAPSHOT.jar:na]
    ... 27 common frames omitted
2019-02-04 09:39:46.062] [bsu-ThinkPad-T470] [New I/O worker #10] WARN o.o.a.p.o.e.i.n.OslpChannelHandlerServer@exceptionCaught:99 - 57528562 Unexpected exception from downstream. {}
org.opensmartgridplatform.shared.exceptionhandling.EncrypterException: Security exception creating public key for algorithm "EC" by provider "SunPKCS11-NSS"
    at org.opensmartgridplatform.shared.security.CertificateHelper.createPublicKey(CertificateHelper.java:149) ~[shared-4.35.0-SNAPSHOT.jar:na]
    at org.opensmartgridplatform.shared.security.CertificateHelper.createPublicKeyFromBase64(CertificateHelper.java:139) ~[shared-4.35.0-SNAPSHOT.jar:na]
    at org.opensmartgridplatform.adapter.protocol.oslp.elster.infra.networking.OslpSecurityHandler.messageReceived(OslpSecurityHandler.java:65) ~[classes/:na]
    at org.jboss.netty.channel.SimpleChannelHandler.handleUpstream(SimpleChannelHandler.java:88) ~[netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:296) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.handler.codec.frame.FrameDecoder.unfoldAndFireMessageReceived(FrameDecoder.java:462) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.handler.codec.replay.ReplayingDecoder.callDecode(ReplayingDecoder.java:536) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.handler.codec.replay.ReplayingDecoder.messageReceived(ReplayingDecoder.java:435) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.handler.logging.LoggingHandler.handleUpstream(LoggingHandler.java:332) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:559) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:268) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:255) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.socket.nio.NioWorker.read(NioWorker.java:88) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.socket.nio.AbstractNioWorker.process(AbstractNioWorker.java:108) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:318) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42) [netty-3.9.4.Final.jar:na]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_201]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_201]
    at java.lang.Thread.run(Thread.java:748) [na:1.8.0_201]
Caused by: java.security.NoSuchProviderException: no such provider: SunPKCS11-NSS
    at sun.security.jca.GetInstance.getService(GetInstance.java:83) ~[na:1.8.0_201]
    at sun.security.jca.GetInstance.getInstance(GetInstance.java:206) ~[na:1.8.0_201]
    at java.security.KeyFactory.getInstance(KeyFactory.java:211) ~[na:1.8.0_201]
    at org.opensmartgridplatform.shared.security.CertificateHelper.createPublicKey(CertificateHelper.java:145) ~[shared-4.35.0-SNAPSHOT.jar:na]
    ... 27 common frames omitted
2019-02-04 09:39:46.065] [bsu-ThinkPad-T470] [New I/O worker #10] WARN o.j.n.channel.DefaultChannelPipeline@warn:76 - An exception was thrown by a user handler while handling an exception event ([id: 0x036dd0f2, /127.0.0.1:38332 => /127.0.0.1:12122] EXCEPTION: org.opensmartgridplatform.shared.exceptionhandling.EncrypterException: Security exception creating public key for algorithm "EC" by provider "SunPKCS11-NSS")
java.lang.NullPointerException: null
    at org.opensmartgridplatform.adapter.protocol.oslp.elster.infra.networking.OslpChannelHandler.exceptionCaught(OslpChannelHandler.java:100) ~[classes/:na]
    at org.jboss.netty.channel.SimpleChannelHandler.handleUpstream(SimpleChannelHandler.java:130) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.SimpleChannelHandler.exceptionCaught(SimpleChannelHandler.java:156) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.SimpleChannelHandler.handleUpstream(SimpleChannelHandler.java:130) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.handler.codec.frame.FrameDecoder.exceptionCaught(FrameDecoder.java:377) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:112) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.handler.logging.LoggingHandler.handleUpstream(LoggingHandler.java:332) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:559) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.Channels.fireExceptionCaught(Channels.java:525) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.AbstractChannelSink.exceptionCaught(AbstractChannelSink.java:48) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.DefaultChannelPipeline.notifyHandlerException(DefaultChannelPipeline.java:658) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:566) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:296) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.handler.codec.frame.FrameDecoder.unfoldAndFireMessageReceived(FrameDecoder.java:462) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.handler.codec.replay.ReplayingDecoder.callDecode(ReplayingDecoder.java:536) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.handler.codec.replay.ReplayingDecoder.messageReceived(ReplayingDecoder.java:435) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.handler.logging.LoggingHandler.handleUpstream(LoggingHandler.java:332) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:559) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:268) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:255) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.socket.nio.NioWorker.read(NioWorker.java:88) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.socket.nio.AbstractNioWorker.process(AbstractNioWorker.java:108) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:318) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) [netty-3.9.4.Final.jar:na]
    at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42) [netty-3.9.4.Final.jar:na]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_201]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_201]
    at java.lang.Thread.run(Thread.java:748) [na:1.8.0_201]
2019-02-04 09:40:00.000] [bsu-ThinkPad-T470] [osgp-core-scheduling-1] INFO o.o.c.a.tasks.ScheduledTaskScheduler@run:50 - Processing scheduled tasks
2019-02-04 09:40:00.000] [bsu-ThinkPad-T470] [osgp-adapter-domain-publiclighting-event-retrieval-scheduled-task-3] INFO o.o.a.d.p.application.tasks.BaseTask@findManufacturer:66 - Trying to find manufacturer for name: ABB
2019-02-04 09:40:02.947] [bsu-ThinkPad-T470] [osgp-adapter-domain-publiclighting-event-retrieval-scheduled-task-3] WARN o.o.a.d.p.application.tasks.BaseTask@findManufacturer:69 - No manufacturer found for name: ABB
2019-02-04 09:40:08.432] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-13] WARN o.o.w.service.OslpChannelHandler@get:117 - Failed to receive response from device SSLD_000-00-01 within timelimit 20000 ms
2019-02-04 09:40:08.614] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-13] ERROR o.o.w.service.OslpChannelHandler@send:435 - send exception
java.io.IOException: Failed to receive response within timelimit 20000 ms
    at org.opensmartgridplatform.webdevicesimulator.service.OslpChannelHandler$Callback.get(OslpChannelHandler.java:119) ~[classes/:na]
    at org.opensmartgridplatform.webdevicesimulator.service.OslpChannelHandler.send(OslpChannelHandler.java:423) ~[classes/:na]
    at org.opensmartgridplatform.webdevicesimulator.service.RegisterDevice.sendRequest(RegisterDevice.java:310) [classes/:na]
    at org.opensmartgridplatform.webdevicesimulator.service.RegisterDevice.sendRegisterDeviceCommand(RegisterDevice.java:134) [classes/:na]
    at org.opensmartgridplatform.webdevicesimulator.web.controller.DeviceManagementController.sendRegisterDeviceCommand(DeviceManagementController.java:324) [classes/:na]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_201]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_201]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_201]
    at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_201]
    at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:205) [spring-web-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:133) [spring-web-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:97) [spring-webmvc-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:827) [spring-webmvc-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:738) [spring-webmvc-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85) [spring-webmvc-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:967) [spring-webmvc-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:901) [spring-webmvc-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:970) [spring-webmvc-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:872) [spring-webmvc-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:661) [servlet-api.jar:na]
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:846) [spring-webmvc-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:742) [servlet-api.jar:na]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) [catalina.jar:8.5.33]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [catalina.jar:8.5.33]
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52) [tomcat-websocket.jar:8.5.33]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [catalina.jar:8.5.33]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [catalina.jar:8.5.33]
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198) [catalina.jar:8.5.33]
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) [catalina.jar:8.5.33]
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:493) [catalina.jar:8.5.33]
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140) [catalina.jar:8.5.33]
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81) [catalina.jar:8.5.33]
    at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:650) [catalina.jar:8.5.33]
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87) [catalina.jar:8.5.33]
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342) [catalina.jar:8.5.33]
    at org.apache.coyote.ajp.AjpProcessor.service(AjpProcessor.java:479) [tomcat-coyote.jar:8.5.33]
    at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) [tomcat-coyote.jar:8.5.33]
    at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:806) [tomcat-coyote.jar:8.5.33]
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1498) [tomcat-coyote.jar:8.5.33]
    at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) [tomcat-coyote.jar:8.5.33]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_201]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_201]
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-util.jar:8.5.33]
    at java.lang.Thread.run(Thread.java:748) [na:1.8.0_201]
2019-02-04 09:40:08.663] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-13] ERROR o.o.w.service.RegisterDevice@sendRegisterDeviceCommand:164 - register device exception
java.io.IOException: Failed to receive response within timelimit 20000 ms
    at org.opensmartgridplatform.webdevicesimulator.service.OslpChannelHandler$Callback.get(OslpChannelHandler.java:119) ~[classes/:na]
    at org.opensmartgridplatform.webdevicesimulator.service.OslpChannelHandler.send(OslpChannelHandler.java:423) ~[classes/:na]
    at org.opensmartgridplatform.webdevicesimulator.service.RegisterDevice.sendRequest(RegisterDevice.java:310) ~[classes/:na]
    at org.opensmartgridplatform.webdevicesimulator.service.RegisterDevice.sendRegisterDeviceCommand(RegisterDevice.java:134) ~[classes/:na]
    at org.opensmartgridplatform.webdevicesimulator.web.controller.DeviceManagementController.sendRegisterDeviceCommand(DeviceManagementController.java:324) [classes/:na]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_201]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_201]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_201]
    at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_201]
    at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:205) [spring-web-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:133) [spring-web-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:97) [spring-webmvc-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:827) [spring-webmvc-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:738) [spring-webmvc-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85) [spring-webmvc-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:967) [spring-webmvc-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:901) [spring-webmvc-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:970) [spring-webmvc-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:872) [spring-webmvc-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:661) [servlet-api.jar:na]
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:846) [spring-webmvc-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:742) [servlet-api.jar:na]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) [catalina.jar:8.5.33]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [catalina.jar:8.5.33]
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52) [tomcat-websocket.jar:8.5.33]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [catalina.jar:8.5.33]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [catalina.jar:8.5.33]
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198) [catalina.jar:8.5.33]
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) [catalina.jar:8.5.33]
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:493) [catalina.jar:8.5.33]
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140) [catalina.jar:8.5.33]
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81) [catalina.jar:8.5.33]
    at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:650) [catalina.jar:8.5.33]
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87) [catalina.jar:8.5.33]
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342) [catalina.jar:8.5.33]
    at org.apache.coyote.ajp.AjpProcessor.service(AjpProcessor.java:479) [tomcat-coyote.jar:8.5.33]
    at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) [tomcat-coyote.jar:8.5.33]
    at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:806) [tomcat-coyote.jar:8.5.33]
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1498) [tomcat-coyote.jar:8.5.33]
    at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) [tomcat-coyote.jar:8.5.33]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_201]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_201]
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-util.jar:8.5.33]
    at java.lang.Thread.run(Thread.java:748) [na:1.8.0_201]
2019-02-04 09:45:00.000] [bsu-ThinkPad-T470] [osgp-core-scheduling-1] INFO o.o.c.a.tasks.ScheduledTaskScheduler@run:50 - Processing scheduled tasks
2019-02-04 09:50:00.000] [bsu-ThinkPad-T470] [osgp-adapter-domain-publiclighting-event-retrieval-scheduled-task-4] INFO o.o.a.d.p.application.tasks.BaseTask@findManufacturer:66 - Trying to find manufacturer for name: ABB
2019-02-04 09:50:00.000] [bsu-ThinkPad-T470] [osgp-core-scheduling-1] INFO o.o.c.a.tasks.ScheduledTaskScheduler@run:50 - Processing scheduled tasks
2019-02-04 09:50:02.288] [bsu-ThinkPad-T470] [osgp-adapter-domain-publiclighting-event-retrieval-scheduled-task-4] WARN o.o.a.d.p.application.tasks.BaseTask@findManufacturer:69 - No manufacturer found for name: ABB
2019-02-04 09:55:00.001] [bsu-ThinkPad-T470] [osgp-core-scheduling-1] INFO o.o.c.a.tasks.ScheduledTaskScheduler@run:50 - Processing scheduled tasks
2019-02-04 10:00:00.000] [bsu-ThinkPad-T470] [osgp-adapter-domain-publiclighting-event-retrieval-scheduled-task-1] INFO o.o.a.d.p.application.tasks.BaseTask@findManufacturer:66 - Trying to find manufacturer for name: KAIFA
2019-02-04 10:00:00.001] [bsu-ThinkPad-T470] [osgp-core-scheduling-1] INFO o.o.c.a.tasks.ScheduledTaskScheduler@run:50 - Processing scheduled tasks
2019-02-04 10:00:00.001] [bsu-ThinkPad-T470] [osgp-adapter-domain-publiclighting-event-retrieval-scheduled-task-2] INFO o.o.a.d.p.application.tasks.BaseTask@findManufacturer:66 - Trying to find manufacturer for name: ABB
2019-02-04 10:00:00.313] [bsu-ThinkPad-T470] [osgp-adapter-domain-publiclighting-event-retrieval-scheduled-task-2] WARN o.o.a.d.p.application.tasks.BaseTask@findManufacturer:69 - No manufacturer found for name: ABB
2019-02-04 10:00:00.320] [bsu-ThinkPad-T470] [osgp-adapter-domain-publiclighting-event-retrieval-scheduled-task-1] WARN o.o.a.d.p.application.tasks.BaseTask@findManufacturer:69 - No manufacturer found for name: KAIFA
2019-02-04 10:05:00.000] [bsu-ThinkPad-T470] [osgp-core-scheduling-1] INFO o.o.c.a.tasks.ScheduledTaskScheduler@run:50 - Processing scheduled tasks
2019-02-04 10:10:00.000] [bsu-ThinkPad-T470] [osgp-adapter-domain-publiclighting-event-retrieval-scheduled-task-5] INFO o.o.a.d.p.application.tasks.BaseTask@findManufacturer:66 - Trying to find manufacturer for name: ABB
2019-02-04 10:10:00.000] [bsu-ThinkPad-T470] [osgp-core-scheduling-1] INFO o.o.c.a.tasks.ScheduledTaskScheduler@run:50 - Processing scheduled tasks
2019-02-04 10:10:00.412] [bsu-ThinkPad-T470] [osgp-adapter-domain-publiclighting-event-retrieval-scheduled-task-5] WARN o.o.a.d.p.application.tasks.BaseTask@findManufacturer:69 - No manufacturer found for name: ABB
sameersubudhi commented 5 years ago

I also happen to notice in the console logs that the signing-server application fails to start during the application startup, because of the same error reported earlier.

SEVERE: Context [/signing-server] startup failed due to previous errors

Below are the startup logs related to signing-server. (The complete console log can be found in the attached file [OSGP_App_Startup_ConsoleLogs.log]):

Feb 04, 2019 10:54:22 AM org.apache.jasper.servlet.TldScanner scanJars
INFO: At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
Feb 04, 2019 10:54:22 AM org.apache.catalina.core.ApplicationContext log
INFO: 1 Spring WebApplicationInitializers detected on classpath
Feb 04, 2019 10:54:22 AM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Feb 04, 2019 10:54:22 AM org.springframework.web.context.ContextLoader initWebApplicationContext
INFO: Root WebApplicationContext: initialization started
Feb 04, 2019 10:54:22 AM org.springframework.web.context.support.AnnotationConfigWebApplicationContext prepareRefresh
INFO: Refreshing Root WebApplicationContext: startup date [Mon Feb 04 10:54:22 UTC 2019]; root of context hierarchy
Feb 04, 2019 10:54:23 AM org.springframework.web.context.support.AnnotationConfigWebApplicationContext loadBeanDefinitions
INFO: Registering annotated classes: [class org.opensmartgridplatform.signing.server.application.config.ApplicationContext]
Feb 04, 2019 10:54:23 AM org.springframework.context.annotation.ConfigurationClassParser processPropertySource
INFO: Properties location [file:${osgp/SigningServer/config}] not resolvable: /etc/osp/signing-server.properties (No such file or directory)
Feb 04, 2019 10:54:23 AM org.springframework.context.annotation.ConfigurationClassParser processPropertySource
INFO: Properties location [file:${osgp/SigningServer/config}] not resolvable: /etc/osp/signing-server.properties (No such file or directory)
2019-02-04 10:54:23.986] [bsu-ThinkPad-T470] [localhost-startStop-1] ERROR o.o.s.s.a.config.ApplicationContext@privateKey:54 - Error creating private key bean
org.opensmartgridplatform.shared.exceptionhandling.EncrypterException: Security exception creating private key for algorithm "EC" by provider "SunPKCS11-NSS"
    at org.opensmartgridplatform.shared.security.CertificateHelper.createPrivateKey(CertificateHelper.java:90) ~[shared-4.35.0-SNAPSHOT.jar:na]
    at org.opensmartgridplatform.shared.security.CertificateHelper.createPrivateKey(CertificateHelper.java:57) ~[shared-4.35.0-SNAPSHOT.jar:na]
    at org.opensmartgridplatform.signing.server.application.config.ApplicationContext.privateKey(ApplicationContext.java:48) ~[classes/:na]
    at org.opensmartgridplatform.signing.server.application.config.ApplicationContext$$EnhancerBySpringCGLIB$$6a8b8af3.CGLIB$privateKey$3(<generated>) [classes/:na]
    at org.opensmartgridplatform.signing.server.application.config.ApplicationContext$$EnhancerBySpringCGLIB$$6a8b8af3$$FastClassBySpringCGLIB$$9b924219.invoke(<generated>) [classes/:na]
    at org.springframework.cglib.proxy.MethodProxy.invokeSuper(MethodProxy.java:228) [spring-core-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.context.annotation.ConfigurationClassEnhancer$BeanMethodInterceptor.intercept(ConfigurationClassEnhancer.java:358) [spring-context-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.opensmartgridplatform.signing.server.application.config.ApplicationContext$$EnhancerBySpringCGLIB$$6a8b8af3.privateKey(<generated>) [classes/:na]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_201]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_201]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_201]
    at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_201]
    at org.springframework.beans.factory.support.SimpleInstantiationStrategy.instantiate(SimpleInstantiationStrategy.java:162) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.ConstructorResolver.instantiateUsingFactoryMethod(ConstructorResolver.java:588) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.instantiateUsingFactoryMethod(AbstractAutowireCapableBeanFactory.java:1181) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBeanInstance(AbstractAutowireCapableBeanFactory.java:1075) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:513) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:483) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:312) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:308) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.config.DependencyDescriptor.resolveCandidate(DependencyDescriptor.java:208) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.doResolveDependency(DefaultListableBeanFactory.java:1138) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveDependency(DefaultListableBeanFactory.java:1066) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor$AutowiredFieldElement.inject(AutowiredAnnotationBeanPostProcessor.java:585) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.annotation.InjectionMetadata.inject(InjectionMetadata.java:88) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor.postProcessPropertyValues(AutowiredAnnotationBeanPostProcessor.java:366) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1272) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:553) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:483) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:312) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:308) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.config.DependencyDescriptor.resolveCandidate(DependencyDescriptor.java:208) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.doResolveDependency(DefaultListableBeanFactory.java:1138) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveDependency(DefaultListableBeanFactory.java:1066) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor$AutowiredFieldElement.inject(AutowiredAnnotationBeanPostProcessor.java:585) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.annotation.InjectionMetadata.inject(InjectionMetadata.java:88) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor.postProcessPropertyValues(AutowiredAnnotationBeanPostProcessor.java:366) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1272) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:553) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:483) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:312) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:308) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.config.DependencyDescriptor.resolveCandidate(DependencyDescriptor.java:208) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.doResolveDependency(DefaultListableBeanFactory.java:1138) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveDependency(DefaultListableBeanFactory.java:1066) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor$AutowiredFieldElement.inject(AutowiredAnnotationBeanPostProcessor.java:585) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.annotation.InjectionMetadata.inject(InjectionMetadata.java:88) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor.postProcessPropertyValues(AutowiredAnnotationBeanPostProcessor.java:366) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1272) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:553) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:483) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:312) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:308) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:761) [spring-beans-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:867) [spring-context-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:543) [spring-context-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.web.context.ContextLoader.configureAndRefreshWebApplicationContext(ContextLoader.java:443) [spring-web-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:325) [spring-web-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:107) [spring-web-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4790) [catalina.jar:8.5.33]
    at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5256) [catalina.jar:8.5.33]
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150) [catalina.jar:8.5.33]
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1420) [catalina.jar:8.5.33]
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1410) [catalina.jar:8.5.33]
    at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_201]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_201]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_201]
    at java.lang.Thread.run(Thread.java:748) [na:1.8.0_201]
Caused by: java.security.NoSuchProviderException: no such provider: SunPKCS11-NSS
    at sun.security.jca.GetInstance.getService(GetInstance.java:83) ~[na:1.8.0_201]
    at sun.security.jca.GetInstance.getInstance(GetInstance.java:206) ~[na:1.8.0_201]
    at java.security.KeyFactory.getInstance(KeyFactory.java:211) ~[na:1.8.0_201]
    at org.opensmartgridplatform.shared.security.CertificateHelper.createPrivateKey(CertificateHelper.java:86) ~[shared-4.35.0-SNAPSHOT.jar:na]
    ... 75 common frames omitted
Feb 04, 2019 10:54:23 AM org.springframework.web.context.support.AnnotationConfigWebApplicationContext refresh
WARNING: Exception encountered during context initialization - cancelling refresh attempt: org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'messagingConfig': Unsatisfied dependency expressed through field 'requestsMessageListener'; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'signingServerRequestsMessageListener': Unsatisfied dependency expressed through field 'signingService'; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'signingService': Unsatisfied dependency expressed through field 'privateKey'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'privateKey' defined in org.opensmartgridplatform.signing.server.application.config.ApplicationContext: Bean instantiation via factory method failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [java.security.PrivateKey]: Factory method 'privateKey' threw exception; nested exception is org.opensmartgridplatform.signing.server.domain.exceptions.SigningServerException: Error creating private key bean
Feb 04, 2019 10:54:24 AM org.springframework.web.context.ContextLoader initWebApplicationContext
SEVERE: Context initialization failed
org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'messagingConfig': Unsatisfied dependency expressed through field 'requestsMessageListener'; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'signingServerRequestsMessageListener': Unsatisfied dependency expressed through field 'signingService'; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'signingService': Unsatisfied dependency expressed through field 'privateKey'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'privateKey' defined in org.opensmartgridplatform.signing.server.application.config.ApplicationContext: Bean instantiation via factory method failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [java.security.PrivateKey]: Factory method 'privateKey' threw exception; nested exception is org.opensmartgridplatform.signing.server.domain.exceptions.SigningServerException: Error creating private key bean
    at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor$AutowiredFieldElement.inject(AutowiredAnnotationBeanPostProcessor.java:588)
    at org.springframework.beans.factory.annotation.InjectionMetadata.inject(InjectionMetadata.java:88)
    at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor.postProcessPropertyValues(AutowiredAnnotationBeanPostProcessor.java:366)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1272)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:553)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:483)
    at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:312)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:308)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:761)
    at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:867)
    at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:543)
    at org.springframework.web.context.ContextLoader.configureAndRefreshWebApplicationContext(ContextLoader.java:443)
    at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:325)
    at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:107)
    at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4790)
    at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5256)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1420)
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1410)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)
Caused by: org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'signingServerRequestsMessageListener': Unsatisfied dependency expressed through field 'signingService'; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'signingService': Unsatisfied dependency expressed through field 'privateKey'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'privateKey' defined in org.opensmartgridplatform.signing.server.application.config.ApplicationContext: Bean instantiation via factory method failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [java.security.PrivateKey]: Factory method 'privateKey' threw exception; nested exception is org.opensmartgridplatform.signing.server.domain.exceptions.SigningServerException: Error creating private key bean
    at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor$AutowiredFieldElement.inject(AutowiredAnnotationBeanPostProcessor.java:588)
    at org.springframework.beans.factory.annotation.InjectionMetadata.inject(InjectionMetadata.java:88)
    at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor.postProcessPropertyValues(AutowiredAnnotationBeanPostProcessor.java:366)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1272)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:553)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:483)
    at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:312)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:308)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202)
    at org.springframework.beans.factory.config.DependencyDescriptor.resolveCandidate(DependencyDescriptor.java:208)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.doResolveDependency(DefaultListableBeanFactory.java:1138)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveDependency(DefaultListableBeanFactory.java:1066)
    at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor$AutowiredFieldElement.inject(AutowiredAnnotationBeanPostProcessor.java:585)
    ... 24 more
Caused by: org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'signingService': Unsatisfied dependency expressed through field 'privateKey'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'privateKey' defined in org.opensmartgridplatform.signing.server.application.config.ApplicationContext: Bean instantiation via factory method failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [java.security.PrivateKey]: Factory method 'privateKey' threw exception; nested exception is org.opensmartgridplatform.signing.server.domain.exceptions.SigningServerException: Error creating private key bean
    at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor$AutowiredFieldElement.inject(AutowiredAnnotationBeanPostProcessor.java:588)
    at org.springframework.beans.factory.annotation.InjectionMetadata.inject(InjectionMetadata.java:88)
    at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor.postProcessPropertyValues(AutowiredAnnotationBeanPostProcessor.java:366)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1272)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:553)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:483)
    at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:312)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:308)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202)
    at org.springframework.beans.factory.config.DependencyDescriptor.resolveCandidate(DependencyDescriptor.java:208)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.doResolveDependency(DefaultListableBeanFactory.java:1138)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveDependency(DefaultListableBeanFactory.java:1066)
    at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor$AutowiredFieldElement.inject(AutowiredAnnotationBeanPostProcessor.java:585)
    ... 37 more
Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'privateKey' defined in org.opensmartgridplatform.signing.server.application.config.ApplicationContext: Bean instantiation via factory method failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [java.security.PrivateKey]: Factory method 'privateKey' threw exception; nested exception is org.opensmartgridplatform.signing.server.domain.exceptions.SigningServerException: Error creating private key bean
    at org.springframework.beans.factory.support.ConstructorResolver.instantiateUsingFactoryMethod(ConstructorResolver.java:599)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.instantiateUsingFactoryMethod(AbstractAutowireCapableBeanFactory.java:1181)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBeanInstance(AbstractAutowireCapableBeanFactory.java:1075)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:513)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:483)
    at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:312)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:308)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202)
    at org.springframework.beans.factory.config.DependencyDescriptor.resolveCandidate(DependencyDescriptor.java:208)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.doResolveDependency(DefaultListableBeanFactory.java:1138)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveDependency(DefaultListableBeanFactory.java:1066)
    at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor$AutowiredFieldElement.inject(AutowiredAnnotationBeanPostProcessor.java:585)
    ... 50 more
Caused by: org.springframework.beans.BeanInstantiationException: Failed to instantiate [java.security.PrivateKey]: Factory method 'privateKey' threw exception; nested exception is org.opensmartgridplatform.signing.server.domain.exceptions.SigningServerException: Error creating private key bean
    at org.springframework.beans.factory.support.SimpleInstantiationStrategy.instantiate(SimpleInstantiationStrategy.java:189)
    at org.springframework.beans.factory.support.ConstructorResolver.instantiateUsingFactoryMethod(ConstructorResolver.java:588)
    ... 62 more
Caused by: org.opensmartgridplatform.signing.server.domain.exceptions.SigningServerException: Error creating private key bean
    at org.opensmartgridplatform.signing.server.application.config.ApplicationContext.privateKey(ApplicationContext.java:55)
    at org.opensmartgridplatform.signing.server.application.config.ApplicationContext$$EnhancerBySpringCGLIB$$6a8b8af3.CGLIB$privateKey$3(<generated>)
    at org.opensmartgridplatform.signing.server.application.config.ApplicationContext$$EnhancerBySpringCGLIB$$6a8b8af3$$FastClassBySpringCGLIB$$9b924219.invoke(<generated>)
    at org.springframework.cglib.proxy.MethodProxy.invokeSuper(MethodProxy.java:228)
    at org.springframework.context.annotation.ConfigurationClassEnhancer$BeanMethodInterceptor.intercept(ConfigurationClassEnhancer.java:358)
    at org.opensmartgridplatform.signing.server.application.config.ApplicationContext$$EnhancerBySpringCGLIB$$6a8b8af3.privateKey(<generated>)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.springframework.beans.factory.support.SimpleInstantiationStrategy.instantiate(SimpleInstantiationStrategy.java:162)
    ... 63 more
Caused by: org.opensmartgridplatform.shared.exceptionhandling.EncrypterException: Security exception creating private key for algorithm "EC" by provider "SunPKCS11-NSS"
    at org.opensmartgridplatform.shared.security.CertificateHelper.createPrivateKey(CertificateHelper.java:90)
    at org.opensmartgridplatform.shared.security.CertificateHelper.createPrivateKey(CertificateHelper.java:57)
    at org.opensmartgridplatform.signing.server.application.config.ApplicationContext.privateKey(ApplicationContext.java:48)
    ... 73 more
Caused by: java.security.NoSuchProviderException: no such provider: SunPKCS11-NSS
    at sun.security.jca.GetInstance.getService(GetInstance.java:83)
    at sun.security.jca.GetInstance.getInstance(GetInstance.java:206)
    at java.security.KeyFactory.getInstance(KeyFactory.java:211)
    at org.opensmartgridplatform.shared.security.CertificateHelper.createPrivateKey(CertificateHelper.java:86)
    ... 75 more

Feb 04, 2019 10:54:24 AM org.apache.catalina.core.StandardContext listenerStart
SEVERE: Exception sending context initialized event to listener instance of class [org.springframework.web.context.ContextLoaderListener]
org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'messagingConfig': Unsatisfied dependency expressed through field 'requestsMessageListener'; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'signingServerRequestsMessageListener': Unsatisfied dependency expressed through field 'signingService'; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'signingService': Unsatisfied dependency expressed through field 'privateKey'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'privateKey' defined in org.opensmartgridplatform.signing.server.application.config.ApplicationContext: Bean instantiation via factory method failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [java.security.PrivateKey]: Factory method 'privateKey' threw exception; nested exception is org.opensmartgridplatform.signing.server.domain.exceptions.SigningServerException: Error creating private key bean
    at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor$AutowiredFieldElement.inject(AutowiredAnnotationBeanPostProcessor.java:588)
    at org.springframework.beans.factory.annotation.InjectionMetadata.inject(InjectionMetadata.java:88)
    at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor.postProcessPropertyValues(AutowiredAnnotationBeanPostProcessor.java:366)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1272)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:553)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:483)
    at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:312)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:308)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:761)
    at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:867)
    at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:543)
    at org.springframework.web.context.ContextLoader.configureAndRefreshWebApplicationContext(ContextLoader.java:443)
    at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:325)
    at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:107)
    at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4790)
    at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5256)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1420)
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1410)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)
Caused by: org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'signingServerRequestsMessageListener': Unsatisfied dependency expressed through field 'signingService'; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'signingService': Unsatisfied dependency expressed through field 'privateKey'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'privateKey' defined in org.opensmartgridplatform.signing.server.application.config.ApplicationContext: Bean instantiation via factory method failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [java.security.PrivateKey]: Factory method 'privateKey' threw exception; nested exception is org.opensmartgridplatform.signing.server.domain.exceptions.SigningServerException: Error creating private key bean
    at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor$AutowiredFieldElement.inject(AutowiredAnnotationBeanPostProcessor.java:588)
    at org.springframework.beans.factory.annotation.InjectionMetadata.inject(InjectionMetadata.java:88)
    at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor.postProcessPropertyValues(AutowiredAnnotationBeanPostProcessor.java:366)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1272)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:553)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:483)
    at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:312)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:308)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202)
    at org.springframework.beans.factory.config.DependencyDescriptor.resolveCandidate(DependencyDescriptor.java:208)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.doResolveDependency(DefaultListableBeanFactory.java:1138)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveDependency(DefaultListableBeanFactory.java:1066)
    at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor$AutowiredFieldElement.inject(AutowiredAnnotationBeanPostProcessor.java:585)
    ... 24 more
Caused by: org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'signingService': Unsatisfied dependency expressed through field 'privateKey'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'privateKey' defined in org.opensmartgridplatform.signing.server.application.config.ApplicationContext: Bean instantiation via factory method failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [java.security.PrivateKey]: Factory method 'privateKey' threw exception; nested exception is org.opensmartgridplatform.signing.server.domain.exceptions.SigningServerException: Error creating private key bean
    at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor$AutowiredFieldElement.inject(AutowiredAnnotationBeanPostProcessor.java:588)
    at org.springframework.beans.factory.annotation.InjectionMetadata.inject(InjectionMetadata.java:88)
    at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor.postProcessPropertyValues(AutowiredAnnotationBeanPostProcessor.java:366)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1272)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:553)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:483)
    at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:312)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:308)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202)
    at org.springframework.beans.factory.config.DependencyDescriptor.resolveCandidate(DependencyDescriptor.java:208)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.doResolveDependency(DefaultListableBeanFactory.java:1138)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveDependency(DefaultListableBeanFactory.java:1066)
    at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor$AutowiredFieldElement.inject(AutowiredAnnotationBeanPostProcessor.java:585)
    ... 37 more
Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'privateKey' defined in org.opensmartgridplatform.signing.server.application.config.ApplicationContext: Bean instantiation via factory method failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [java.security.PrivateKey]: Factory method 'privateKey' threw exception; nested exception is org.opensmartgridplatform.signing.server.domain.exceptions.SigningServerException: Error creating private key bean
    at org.springframework.beans.factory.support.ConstructorResolver.instantiateUsingFactoryMethod(ConstructorResolver.java:599)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.instantiateUsingFactoryMethod(AbstractAutowireCapableBeanFactory.java:1181)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBeanInstance(AbstractAutowireCapableBeanFactory.java:1075)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:513)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:483)
    at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:312)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:308)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202)
    at org.springframework.beans.factory.config.DependencyDescriptor.resolveCandidate(DependencyDescriptor.java:208)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.doResolveDependency(DefaultListableBeanFactory.java:1138)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveDependency(DefaultListableBeanFactory.java:1066)
    at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor$AutowiredFieldElement.inject(AutowiredAnnotationBeanPostProcessor.java:585)
    ... 50 more
Caused by: org.springframework.beans.BeanInstantiationException: Failed to instantiate [java.security.PrivateKey]: Factory method 'privateKey' threw exception; nested exception is org.opensmartgridplatform.signing.server.domain.exceptions.SigningServerException: Error creating private key bean
    at org.springframework.beans.factory.support.SimpleInstantiationStrategy.instantiate(SimpleInstantiationStrategy.java:189)
    at org.springframework.beans.factory.support.ConstructorResolver.instantiateUsingFactoryMethod(ConstructorResolver.java:588)
    ... 62 more
Caused by: org.opensmartgridplatform.signing.server.domain.exceptions.SigningServerException: Error creating private key bean
    at org.opensmartgridplatform.signing.server.application.config.ApplicationContext.privateKey(ApplicationContext.java:55)
    at org.opensmartgridplatform.signing.server.application.config.ApplicationContext$$EnhancerBySpringCGLIB$$6a8b8af3.CGLIB$privateKey$3(<generated>)
    at org.opensmartgridplatform.signing.server.application.config.ApplicationContext$$EnhancerBySpringCGLIB$$6a8b8af3$$FastClassBySpringCGLIB$$9b924219.invoke(<generated>)
    at org.springframework.cglib.proxy.MethodProxy.invokeSuper(MethodProxy.java:228)
    at org.springframework.context.annotation.ConfigurationClassEnhancer$BeanMethodInterceptor.intercept(ConfigurationClassEnhancer.java:358)
    at org.opensmartgridplatform.signing.server.application.config.ApplicationContext$$EnhancerBySpringCGLIB$$6a8b8af3.privateKey(<generated>)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.springframework.beans.factory.support.SimpleInstantiationStrategy.instantiate(SimpleInstantiationStrategy.java:162)
    ... 63 more
Caused by: org.opensmartgridplatform.shared.exceptionhandling.EncrypterException: Security exception creating private key for algorithm "EC" by provider "SunPKCS11-NSS"
    at org.opensmartgridplatform.shared.security.CertificateHelper.createPrivateKey(CertificateHelper.java:90)
    at org.opensmartgridplatform.shared.security.CertificateHelper.createPrivateKey(CertificateHelper.java:57)
    at org.opensmartgridplatform.signing.server.application.config.ApplicationContext.privateKey(ApplicationContext.java:48)
    ... 73 more
Caused by: java.security.NoSuchProviderException: no such provider: SunPKCS11-NSS
    at sun.security.jca.GetInstance.getService(GetInstance.java:83)
    at sun.security.jca.GetInstance.getInstance(GetInstance.java:206)
    at java.security.KeyFactory.getInstance(KeyFactory.java:211)
    at org.opensmartgridplatform.shared.security.CertificateHelper.createPrivateKey(CertificateHelper.java:86)
    ... 75 more

Feb 04, 2019 10:54:24 AM org.apache.catalina.core.StandardContext startInternal
SEVERE: One or more listeners failed to start. Full details will be found in the appropriate container log file
Feb 04, 2019 10:54:24 AM org.apache.catalina.core.StandardContext startInternal
SEVERE: Context [/signing-server] startup failed due to previous errors
Feb 04, 2019 10:54:24 AM org.apache.catalina.core.ApplicationContext log
INFO: Closing Spring root WebApplicationContext
Feb 04, 2019 10:54:29 AM org.apache.jasper.servlet.TldScanner scanJars
INFO: At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
Feb 04, 2019 10:54:30 AM org.apache.catalina.core.ApplicationContext log
INFO: 1 Spring WebApplicationInitializers detected on classpath
Feb 04, 2019 10:54:30 AM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
smvdheijden commented 5 years ago

Seems that the SunPKCS11-NSS security provider could not be found. Have you recently updated Java on your system? If so, the java.security file might be overwritten. Could you try adding the following line to the java.security file below the other security providers? security.provider.10=sun.security.pkcs11.SunPKCS11 ${java.home}/lib/security/nss.cfg

sameersubudhi commented 5 years ago

@smvdheijden Thank you for the input. This has resolved the java.security.NoSuchProviderException: no such provider: SunPKCS11-NSS issue.

However, when I try to fire a SetLight request to switch ON the SSLD device, I receive an INACTIVE_DEVICE exception.

Below are the server console logs and the SOAP response respectively. Console logs when trying from the web-app

Feb 05, 2019 11:06:09 AM org.springframework.oxm.jaxb.Jaxb2Marshaller createJaxbContextFromContextPath
INFO: Creating JAXBContext with context path [org.opensmartgridplatform.adapter.ws.schema.publiclighting.adhocmanagement]
2019-02-05 11:06:12.414] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-16] INFO o.o.a.w.p.e.PublicLightingAdHocManagementEndpoint@findAllDevices:95 - Finding All Devices Request received from organisation: test-org.
2019-02-05 11:06:12.473] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-16] INFO o.o.a.w.e.WebServiceMonitorInterceptor@printSoapMessage:314 - soap message: <SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/"><SOAP-ENV:Header><OrganisationIdentification xmlns="http://www.opensmartgridplatform.org/schemas/common">test-org</OrganisationIdentification><ApplicationName xmlns="http://www.opensmartgridplatform.org/schemas/common">demo-app</ApplicationName><UserName xmlns="http://www.opensmartgridplatform.org/schemas/common">bsu</UserName></SOAP-ENV:Header><SOAP-ENV:Body><ns2:FindAllDevicesRequest xmlns:ns2="http://www.opensmartgridplatform.org/schemas/publiclighting/adhocmanagement/2014/10" xmlns:ns3="http://www.opensmartgridplatform.org/schemas/common/2014/10"><ns2:Page>0</ns2:Page></ns2:FindAllDevicesRequest></SOAP-ENV:Body></SOAP-ENV:Envelope>
2019-02-05 11:06:12.481] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-16] INFO o.o.a.w.e.WebServiceMonitorInterceptor@printSoapMessage:314 - soap message: <SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/"><SOAP-ENV:Header/><SOAP-ENV:Body><ns2:FindAllDevicesResponse xmlns:ns2="http://www.opensmartgridplatform.org/schemas/publiclighting/adhocmanagement/2014/10" xmlns:ns3="http://www.opensmartgridplatform.org/schemas/common/2014/10"><ns2:DevicePage><ns2:TotalPages>1</ns2:TotalPages><ns2:Devices><ns2:DeviceIdentification>SSLD_000-00-02</ns2:DeviceIdentification><ns2:Activated>false</ns2:Activated><ns2:HasSchedule>false</ns2:HasSchedule><ns2:PublicKeyPresent>false</ns2:PublicKeyPresent></ns2:Devices><ns2:Devices><ns2:DeviceIdentification>SSLD_000-00-01</ns2:DeviceIdentification><ns2:Activated>false</ns2:Activated><ns2:HasSchedule>false</ns2:HasSchedule><ns2:PublicKeyPresent>true</ns2:PublicKeyPresent></ns2:Devices></ns2:DevicePage></ns2:FindAllDevicesResponse></SOAP-ENV:Body></SOAP-ENV:Envelope>
2019-02-05 11:06:12.485] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-16] INFO o.o.a.w.i.jms.LoggingMessageSender@sendMessage:53 - Sending logger message to queue
2019-02-05 11:06:12.487] [bsu-ThinkPad-T470] [ActiveMQ Task-1] INFO o.a.a.t.failover.FailoverTransport@doReconnect:1052 - Successfully connected to tcp://localhost:61616
Feb 05, 2019 11:06:14 AM org.springframework.oxm.jaxb.Jaxb2Marshaller createJaxbContextFromContextPath
INFO: Creating JAXBContext with context path [org.opensmartgridplatform.adapter.ws.schema.publiclighting.adhocmanagement]
2019-02-05 11:06:14.797] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-19] INFO o.o.a.w.p.e.PublicLightingAdHocManagementEndpoint@getStatus:188 - Get Status received from organisation: test-org for device: SSLD_000-00-01 with message priority: .
2019-02-05 11:06:14.813] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-19] ERROR o.o.a.w.p.e.PublicLightingAdHocManagementEndpoint@handleException:397 - Exception occurred: 
org.opensmartgridplatform.shared.exceptionhandling.FunctionalException: INACTIVE_DEVICE
    at org.opensmartgridplatform.domain.core.services.DeviceDomainService.searchActiveDevice(DeviceDomainService.java:76) ~[osgp-domain-core-4.35.0-SNAPSHOT.jar:na]
    at org.opensmartgridplatform.domain.core.services.DeviceDomainService$$FastClassBySpringCGLIB$$ad28b2b0.invoke(<generated>) ~[osgp-domain-core-4.35.0-SNAPSHOT.jar:na]
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) ~[spring-core-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:736) ~[spring-aop-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) ~[spring-aop-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.validation.beanvalidation.MethodValidationInterceptor$HibernateValidatorDelegate.invokeWithinValidation(MethodValidationInterceptor.java:202) ~[spring-context-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.validation.beanvalidation.MethodValidationInterceptor.invoke(MethodValidationInterceptor.java:161) ~[spring-context-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99) ~[spring-tx-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:282) ~[spring-tx-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96) ~[spring-tx-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:671) ~[spring-aop-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.opensmartgridplatform.domain.core.services.DeviceDomainService$$EnhancerBySpringCGLIB$$6f81b33a.searchActiveDevice(<generated>) ~[osgp-domain-core-4.35.0-SNAPSHOT.jar:na]
    at org.opensmartgridplatform.adapter.ws.publiclighting.application.services.DomainHelperService.findActiveDevice(DomainHelperService.java:45) ~[classes/:na]
    at org.opensmartgridplatform.adapter.ws.publiclighting.application.services.AdHocManagementService.enqueueGetStatusRequest(AdHocManagementService.java:124) ~[classes/:na]
    at org.opensmartgridplatform.adapter.ws.publiclighting.application.services.AdHocManagementService$$FastClassBySpringCGLIB$$b1e61b65.invoke(<generated>) ~[classes/:na]
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) ~[spring-core-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:736) ~[spring-aop-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) ~[spring-aop-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.validation.beanvalidation.MethodValidationInterceptor$HibernateValidatorDelegate.invokeWithinValidation(MethodValidationInterceptor.java:202) ~[spring-context-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.validation.beanvalidation.MethodValidationInterceptor.invoke(MethodValidationInterceptor.java:161) ~[spring-context-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99) ~[spring-tx-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:282) ~[spring-tx-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96) ~[spring-tx-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:671) ~[spring-aop-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.opensmartgridplatform.adapter.ws.publiclighting.application.services.AdHocManagementService$$EnhancerBySpringCGLIB$$e8528679.enqueueGetStatusRequest(<generated>) ~[classes/:na]
    at org.opensmartgridplatform.adapter.ws.publiclighting.endpoints.PublicLightingAdHocManagementEndpoint.getStatus(PublicLightingAdHocManagementEndpoint.java:194) ~[classes/:na]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_191]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_191]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_191]
    at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_191]
    at org.springframework.ws.server.endpoint.MethodEndpoint.invoke(MethodEndpoint.java:134) [spring-ws-core-2.4.0.RELEASE.jar:2.4.0.RELEASE]
    at org.springframework.ws.server.endpoint.adapter.DefaultMethodEndpointAdapter.invokeInternal(DefaultMethodEndpointAdapter.java:291) [spring-ws-core-2.4.0.RELEASE.jar:2.4.0.RELEASE]
    at org.springframework.ws.server.endpoint.adapter.AbstractMethodEndpointAdapter.invoke(AbstractMethodEndpointAdapter.java:55) [spring-ws-core-2.4.0.RELEASE.jar:2.4.0.RELEASE]
    at org.springframework.ws.server.MessageDispatcher.dispatch(MessageDispatcher.java:236) [spring-ws-core-2.4.0.RELEASE.jar:2.4.0.RELEASE]
    at org.springframework.ws.server.MessageDispatcher.receive(MessageDispatcher.java:176) [spring-ws-core-2.4.0.RELEASE.jar:2.4.0.RELEASE]
    at org.springframework.ws.transport.support.WebServiceMessageReceiverObjectSupport.handleConnection(WebServiceMessageReceiverObjectSupport.java:89) [spring-ws-core-2.4.0.RELEASE.jar:2.4.0.RELEASE]
    at org.springframework.ws.transport.http.WebServiceMessageReceiverHandlerAdapter.handle(WebServiceMessageReceiverHandlerAdapter.java:61) [spring-ws-core-2.4.0.RELEASE.jar:2.4.0.RELEASE]
    at org.springframework.ws.transport.http.MessageDispatcherServlet.doService(MessageDispatcherServlet.java:293) [spring-ws-core-2.4.0.RELEASE.jar:2.4.0.RELEASE]
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:970) [spring-webmvc-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:872) [spring-webmvc-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:661) [servlet-api.jar:na]
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:846) [spring-webmvc-4.3.18.RELEASE.jar:4.3.18.RELEASE]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:742) [servlet-api.jar:na]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) [catalina.jar:8.5.33]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [catalina.jar:8.5.33]
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52) [tomcat-websocket.jar:8.5.33]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [catalina.jar:8.5.33]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [catalina.jar:8.5.33]
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198) [catalina.jar:8.5.33]
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) [catalina.jar:8.5.33]
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:493) [catalina.jar:8.5.33]
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140) [catalina.jar:8.5.33]
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81) [catalina.jar:8.5.33]
    at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:650) [catalina.jar:8.5.33]
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87) [catalina.jar:8.5.33]
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342) [catalina.jar:8.5.33]
    at org.apache.coyote.ajp.AjpProcessor.service(AjpProcessor.java:479) [tomcat-coyote.jar:8.5.33]
    at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) [tomcat-coyote.jar:8.5.33]
    at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:806) [tomcat-coyote.jar:8.5.33]
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1498) [tomcat-coyote.jar:8.5.33]
    at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) [tomcat-coyote.jar:8.5.33]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_191]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_191]
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-util.jar:8.5.33]
    at java.lang.Thread.run(Thread.java:748) [na:1.8.0_191]
Caused by: org.opensmartgridplatform.domain.core.exceptions.InactiveDeviceException: Device SSLD_000-00-01 is not active in the platform
    ... 69 common frames omitted
2019-02-05 11:06:14.823] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-19] INFO o.o.a.w.e.WebServiceMonitorInterceptor@printSoapMessage:314 - soap message: <SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/"><SOAP-ENV:Header><OrganisationIdentification xmlns="http://www.opensmartgridplatform.org/schemas/common">test-org</OrganisationIdentification><ApplicationName xmlns="http://www.opensmartgridplatform.org/schemas/common">demo-app</ApplicationName><UserName xmlns="http://www.opensmartgridplatform.org/schemas/common">bsu</UserName></SOAP-ENV:Header><SOAP-ENV:Body><ns2:GetStatusRequest xmlns:ns2="http://www.opensmartgridplatform.org/schemas/publiclighting/adhocmanagement/2014/10" xmlns:ns3="http://www.opensmartgridplatform.org/schemas/common/2014/10"><ns2:DeviceIdentification>SSLD_000-00-01</ns2:DeviceIdentification></ns2:GetStatusRequest></SOAP-ENV:Body></SOAP-ENV:Envelope>
2019-02-05 11:06:14.826] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-19] INFO o.o.a.w.e.WebServiceMonitorInterceptor@printSoapMessage:314 - soap message: <SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/"><SOAP-ENV:Header/><SOAP-ENV:Body><SOAP-ENV:Fault><faultcode>SOAP-ENV:Server</faultcode><faultstring xml:lang="en">INACTIVE_DEVICE</faultstring><detail><ns2:FunctionalFault xmlns:ns2="http://www.opensmartgridplatform.org/schemas/common/2014/10"><ns2:Code>207</ns2:Code><ns2:Message>INACTIVE_DEVICE</ns2:Message><ns2:Component>WS_PUBLIC_LIGHTING</ns2:Component><ns2:InnerException>org.opensmartgridplatform.domain.core.exceptions.InactiveDeviceException</ns2:InnerException><ns2:InnerMessage>Device SSLD_000-00-01 is not active in the platform</ns2:InnerMessage></ns2:FunctionalFault></detail></SOAP-ENV:Fault></SOAP-ENV:Body></SOAP-ENV:Envelope>
2019-02-05 11:06:14.829] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-19] INFO o.o.a.w.i.jms.LoggingMessageSender@sendMessage:53 - Sending logger message to queue
2019-02-05 11:06:14.833] [bsu-ThinkPad-T470] [ActiveMQ Task-1] INFO o.a.a.t.failover.FailoverTransport@doReconnect:1052 - Successfully connected to tcp://localhost:61616

SOAP Request

<soapenv:Envelope xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/" xmlns:ns="http://www.opensmartgridplatform.org/schemas/common/2014/10" xmlns:ns1="http://www.opensmartgridplatform.org/schemas/publiclighting/adhocmanagement/2014/10">
   <soapenv:Header>
      <ns:ApplicationName>APPLICATION_NAME</ns:ApplicationName>
      <ns:UserName>USER_NAME</ns:UserName>
      <ns:OrganisationIdentification>test-org</ns:OrganisationIdentification>
   </soapenv:Header>
   <soapenv:Body>
      <ns1:SetLightRequest>
         <!--type: Identification-->
         <ns1:DeviceIdentification>SSLD_000-00-01</ns1:DeviceIdentification>
         <!--1 to 6 repetitions:-->
         <ns1:LightValue>
            <!--Optional:-->
            <!--anonymous type-->
            <ns1:Index>0</ns1:Index>
            <!--type: boolean-->
            <ns1:On>true</ns1:On>
            <!--Optional:-->
            <!--anonymous type-->
            <ns1:DimValue>100</ns1:DimValue>
         </ns1:LightValue>
      </ns1:SetLightRequest>
   </soapenv:Body>
</soapenv:Envelope>

SOAP Response

<SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/">
   <SOAP-ENV:Header/>
   <SOAP-ENV:Body>
      <SOAP-ENV:Fault>
         <faultcode>SOAP-ENV:Server</faultcode>
         <faultstring xml:lang="en">INACTIVE_DEVICE</faultstring>
         <detail>
            <ns2:FunctionalFault xmlns:ns2="http://www.opensmartgridplatform.org/schemas/common/2014/10">
               <ns2:Code>207</ns2:Code>
               <ns2:Message>INACTIVE_DEVICE</ns2:Message>
               <ns2:Component>WS_PUBLIC_LIGHTING</ns2:Component>
               <ns2:InnerException>org.opensmartgridplatform.domain.core.exceptions.InactiveDeviceException</ns2:InnerException>
               <ns2:InnerMessage>Device SSLD_000-00-01 is not active in the platform</ns2:InnerMessage>
            </ns2:FunctionalFault>
         </detail>
      </SOAP-ENV:Fault>
   </SOAP-ENV:Body>
</SOAP-ENV:Envelope>
smvdheijden commented 5 years ago

This is probably caused by the device not being registered yet. Could you try registering the device using the device simulator? (First click the "Register device" button, wait for the notification and then press the "Confirm device registration" button)

sameersubudhi commented 5 years ago

@smvdheijden I had already registered the device and confirmed it as well. (Should I retry doing it again?)

screenshot from 2019-02-05 12-28-04 screenshot from 2019-02-05 12-30-12

smvdheijden commented 5 years ago

Could you retry the registration, and then check the device table in the osgp_core database? After a successful registration the device record in the table should have the following values: is_activated: true device_lifecycle_status; IN_USE

sameersubudhi commented 5 years ago

@smvdheijden Retried the registration. But the values in the osgp_core.device table didn't update as desired. The values for the fields against the device (SSLD_000-00-01) record are still

is_activated: FALSE
device_lifecycle_status: NEW_IN_INVENTORY

screenshot from 2019-02-05 14-15-10 screenshot from 2019-02-05 14-15-24 screenshot from 2019-02-05 14-19-47

Console logs

2019-02-05 13:14:54.331] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-14] INFO o.o.w.service.RegisterDevice@sendRequest:309 - Trying to send request: registerDeviceRequest {
  deviceIdentification: "SSLD_000-00-01"
  ipAddress: "\000\000\001"
  deviceType: SSLD
  hasSchedule: false
  randomDevice: 49956
}

2019-02-05 13:14:54.332] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-14] INFO o.o.w.service.OslpChannelHandler@send:396 - Sending OSLP request: registerDeviceRequest {
  deviceIdentification: "SSLD_000-00-01"
  ipAddress: "\000\000\001"
  deviceType: SSLD
  hasSchedule: false
  randomDevice: 49956
}

2019-02-05 13:14:54.335] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-14] INFO o.o.w.a.config.ApplicationContext@lambda$clientBootstrap$0:269 - Created new client pipeline
2019-02-05 13:14:54.336] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-14] INFO o.o.w.service.OslpChannelHandler@channelOpen:356 - Channel -629098145 opened
2019-02-05 13:14:54.340] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-14] INFO o.o.w.service.OslpChannelHandler@send:408 - Connection established to: localhost/127.0.0.1:12122
2019-02-05 13:14:54.341] [bsu-ThinkPad-T470] [New I/O server boss #18] INFO o.o.a.p.o.e.a.config.OslpConfig@getPipeline:114 - Created server new pipeline
2019-02-05 13:14:54.342] [bsu-ThinkPad-T470] [New I/O server boss #18] INFO o.j.n.handler.logging.LoggingHandler@info:48 - [id: 0x58efc763, /127.0.0.1:44646 => /127.0.0.1:12122] OPEN
2019-02-05 13:14:54.342] [bsu-ThinkPad-T470] [New I/O server boss #18] INFO o.o.a.p.o.e.i.n.OslpChannelHandlerServer@channelOpen:71 - 1492109155 Channel opened
2019-02-05 13:14:54.345] [bsu-ThinkPad-T470] [New I/O worker #12] INFO o.j.n.handler.logging.LoggingHandler@info:48 - [id: 0x58efc763, /127.0.0.1:44646 => /127.0.0.1:12122] BOUND: /127.0.0.1:12122
2019-02-05 13:14:54.345] [bsu-ThinkPad-T470] [New I/O worker #12] INFO o.j.n.handler.logging.LoggingHandler@info:48 - [id: 0x58efc763, /127.0.0.1:44646 => /127.0.0.1:12122] CONNECTED: /127.0.0.1:44646
2019-02-05 13:14:54.346] [bsu-ThinkPad-T470] [New I/O worker #12] INFO o.j.n.handler.logging.LoggingHandler@info:48 - [id: 0x58efc763, /127.0.0.1:44646 => /127.0.0.1:12122] RECEIVED: BigEndianHeapChannelBuffer(ridx=0, widx=176, cap=176)
2019-02-05 13:14:54.356] [bsu-ThinkPad-T470] [New I/O worker #12] INFO o.o.a.p.o.e.a.s.o.OslpDeviceSettingsService@getDeviceByDeviceIdentification:68 - get device by device identification: SSLD_000-00-01
2019-02-05 13:14:54.390] [bsu-ThinkPad-T470] [ActiveMQ Task-1] INFO o.a.a.t.failover.FailoverTransport@doReconnect:1052 - Successfully connected to tcp://localhost:61616
2019-02-05 13:14:54.486] [bsu-ThinkPad-T470] [New I/O worker #12] INFO o.o.a.p.o.e.i.n.OslpChannelHandlerServer@messageReceived:127 - 1492109155 Received OSLP Request: registerDeviceRequest {
  deviceIdentification: "SSLD_000-00-01"
  ipAddress: "\000\000\001"
  deviceType: SSLD
  hasSchedule: false
  randomDevice: 49956
}

2019-02-05 13:14:54.488] [bsu-ThinkPad-T470] [New I/O worker #12] INFO o.o.a.p.o.e.i.m.OsgpRequestMessageSender@send:34 - Sending request message to OSGP.
2019-02-05 13:14:54.492] [bsu-ThinkPad-T470] [ActiveMQ Task-1] INFO o.a.a.t.failover.FailoverTransport@doReconnect:1052 - Successfully connected to tcp://localhost:61616
2019-02-05 13:14:54.545] [bsu-ThinkPad-T470] [New I/O worker #12] INFO o.o.a.p.o.e.a.s.o.OslpDeviceSettingsService@getDeviceByDeviceIdentification:68 - get device by device identification: SSLD_000-00-01
2019-02-05 13:14:54.547] [bsu-ThinkPad-T470] [New I/O worker #12] INFO o.o.a.p.o.e.a.s.o.OslpDeviceSettingsService@updateDevice:50 - update device: SSLD_000-00-01
2019-02-05 13:14:54.578] [bsu-ThinkPad-T470] [New I/O worker #12] INFO o.o.a.p.o.e.i.m.SigningServerRequestMessageSender@send:43 - Sending request message to signing server, with reply-to-queue: queue://signing-server.1_0.responses-bsu-ThinkPad-T470.
2019-02-05 13:14:54.619] [bsu-ThinkPad-T470] [signingServerRequestsMessageListenerContainer-1] INFO o.o.s.s.i.m.SigningServerRequestMessageListener@onMessage:48 - Received message of type: SIGNING_REQUEST, for device: deviceIdentification with correlationId: 1492109155 and replyToQueue: queue://signing-server.1_0.responses-bsu-ThinkPad-T470
2019-02-05 13:14:54.621] [bsu-ThinkPad-T470] [signingServerRequestsMessageListenerContainer-1] INFO o.o.s.s.a.services.SigningService@sign:65 - Received message to sign for device: deviceIdentification with correlationId: 1492109155
2019-02-05 13:14:54.624] [bsu-ThinkPad-T470] [signingServerRequestsMessageListenerContainer-1] INFO o.o.s.s.a.services.SigningService@doSignMessage:99 - Message for device: deviceIdentification with correlationId: 1492109155 signed, sending response to protocol-adapter
2019-02-05 13:14:54.663] [bsu-ThinkPad-T470] [signingResponsesMessageListenerContainer-1] INFO o.o.a.p.o.e.i.m.SigningServerResponsesMessageListener@onMessage:37 - Received message of type: SIGNING_RESPONSE
2019-02-05 13:14:55.241] [bsu-ThinkPad-T470] [signingResponsesMessageListenerContainer-1] INFO o.o.a.p.o.e.i.m.SigningServerResponsesMessageListener@onMessage:55 - Read signed message, messageType: SIGNING_RESPONSE, messagePriority: 0, deviceIdentification: deviceIdentification, result: OK, correlationId: 1492109155
2019-02-05 13:14:55.241] [bsu-ThinkPad-T470] [signingResponsesMessageListenerContainer-1] INFO o.o.a.p.o.e.a.s.o.OslpSigningService@handleSignedOslpResponse:159 - oslpEnvelope.size: 185 for message type: null
2019-02-05 13:14:55.247] [bsu-ThinkPad-T470] [signingResponsesMessageListenerContainer-1] INFO o.j.n.handler.logging.LoggingHandler@info:48 - [id: 0x58efc763, /127.0.0.1:44646 => /127.0.0.1:12122] WRITE: BigEndianHeapChannelBuffer(ridx=0, widx=185, cap=185)
2019-02-05 13:14:55.247] [bsu-ThinkPad-T470] [New I/O worker #12] INFO o.j.n.handler.logging.LoggingHandler@info:48 - [id: 0x58efc763, /127.0.0.1:44646 => /127.0.0.1:12122] WRITTEN_AMOUNT: 185
2019-02-05 13:14:55.247] [bsu-ThinkPad-T470] [signingResponsesMessageListenerContainer-1] INFO o.o.a.p.o.e.i.n.OslpChannelHandlerServer@processSignedOslpEnvelope:185 - 1492109155 Send OSLP Response: registerDeviceResponse {
  status: OK
  currentTime: "20190205131454"
  randomDevice: 49956
  randomPlatform: 3229
  locationInfo {
    timeOffset: 60
    latitude: 52132632
    longitude: 5291266
  }
}

2019-02-05 13:14:55.261] [bsu-ThinkPad-T470] [New I/O worker #3] INFO o.o.w.service.OslpChannelHandler@messageReceived:286 - Received OSLP Response (before callback): registerDeviceResponse {
  status: OK
  currentTime: "20190205131454"
  randomDevice: 49956
  randomPlatform: 3229
  locationInfo {
    timeOffset: 60
    latitude: 52132632
    longitude: 5291266
  }
}

2019-02-05 13:14:55.261] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-14] INFO o.o.w.service.OslpChannelHandler@get:123 - Response received within 20000 ms
2019-02-05 13:14:55.261] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-14] INFO o.o.w.service.OslpChannelHandler@send:424 - Received OSLP response (after callback): registerDeviceResponse {
  status: OK
  currentTime: "20190205131454"
  randomDevice: 49956
  randomPlatform: 3229
  locationInfo {
    timeOffset: 60
    latitude: 52132632
    longitude: 5291266
  }
}

2019-02-05 13:14:55.262] [bsu-ThinkPad-T470] [New I/O worker #12] INFO o.j.n.handler.logging.LoggingHandler@info:48 - [id: 0x58efc763, /127.0.0.1:44646 :> /127.0.0.1:12122] DISCONNECTED
2019-02-05 13:14:55.264] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-14] INFO o.o.w.service.RegisterDevice@sendRequest:312 - Received response: registerDeviceResponse {
  status: OK
  currentTime: "20190205131454"
  randomDevice: 49956
  randomPlatform: 3229
  locationInfo {
    timeOffset: 60
    latitude: 52132632
    longitude: 5291266
  }
}

2019-02-05 13:14:55.306] [bsu-ThinkPad-T470] [New I/O worker #3] INFO o.o.w.service.OslpChannelHandler@channelDisconnected:362 - Channel -629098145 disconnected
2019-02-05 13:14:55.307] [bsu-ThinkPad-T470] [New I/O worker #3] INFO o.o.w.service.OslpChannelHandler@channelUnbound:374 - Channel -629098145 unbound
2019-02-05 13:14:55.307] [bsu-ThinkPad-T470] [New I/O worker #3] INFO o.o.w.service.OslpChannelHandler@channelClosed:368 - Channel -629098145 closed
2019-02-05 13:14:55.311] [bsu-ThinkPad-T470] [New I/O worker #12] INFO o.o.a.p.o.e.i.n.OslpChannelHandlerServer@channelDisconnected:77 - 1492109155 Channel disconnected
2019-02-05 13:14:55.311] [bsu-ThinkPad-T470] [New I/O worker #12] INFO o.j.n.handler.logging.LoggingHandler@info:48 - [id: 0x58efc763, /127.0.0.1:44646 :> /127.0.0.1:12122] UNBOUND
2019-02-05 13:14:55.312] [bsu-ThinkPad-T470] [New I/O worker #12] INFO o.o.a.p.o.e.i.n.OslpChannelHandlerServer@channelUnbound:89 - 1492109155 Channel unbound
2019-02-05 13:14:55.312] [bsu-ThinkPad-T470] [New I/O worker #12] INFO o.j.n.handler.logging.LoggingHandler@info:48 - [id: 0x58efc763, /127.0.0.1:44646 :> /127.0.0.1:12122] CLOSED
2019-02-05 13:14:55.312] [bsu-ThinkPad-T470] [New I/O worker #12] INFO o.o.a.p.o.e.i.n.OslpChannelHandlerServer@channelClosed:83 - 1492109155 Channel closed
2019-02-05 13:15:18.966] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-15] INFO o.o.w.service.RegisterDevice@sendRequest:309 - Trying to send request: confirmRegisterDeviceRequest {
  randomDevice: 49956
  randomPlatform: 3229
}

2019-02-05 13:15:18.967] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-15] INFO o.o.w.service.OslpChannelHandler@send:396 - Sending OSLP request: confirmRegisterDeviceRequest {
  randomDevice: 49956
  randomPlatform: 3229
}

2019-02-05 13:15:18.968] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-15] INFO o.o.w.a.config.ApplicationContext@lambda$clientBootstrap$0:269 - Created new client pipeline
2019-02-05 13:15:18.968] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-15] INFO o.o.w.service.OslpChannelHandler@channelOpen:356 - Channel 957762998 opened
2019-02-05 13:15:18.969] [bsu-ThinkPad-T470] [New I/O server boss #18] INFO o.o.a.p.o.e.a.config.OslpConfig@getPipeline:114 - Created server new pipeline
2019-02-05 13:15:18.969] [bsu-ThinkPad-T470] [New I/O server boss #18] INFO o.j.n.handler.logging.LoggingHandler@info:48 - [id: 0x1da87682, /127.0.0.1:44660 => /127.0.0.1:12122] OPEN
2019-02-05 13:15:18.969] [bsu-ThinkPad-T470] [New I/O server boss #18] INFO o.o.a.p.o.e.i.n.OslpChannelHandlerServer@channelOpen:71 - 497579650 Channel opened
2019-02-05 13:15:18.970] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-15] INFO o.o.w.service.OslpChannelHandler@send:408 - Connection established to: localhost/127.0.0.1:12122
2019-02-05 13:15:18.971] [bsu-ThinkPad-T470] [New I/O worker #13] INFO o.j.n.handler.logging.LoggingHandler@info:48 - [id: 0x1da87682, /127.0.0.1:44660 => /127.0.0.1:12122] BOUND: /127.0.0.1:12122
2019-02-05 13:15:18.971] [bsu-ThinkPad-T470] [New I/O worker #13] INFO o.j.n.handler.logging.LoggingHandler@info:48 - [id: 0x1da87682, /127.0.0.1:44660 => /127.0.0.1:12122] CONNECTED: /127.0.0.1:44660
2019-02-05 13:15:18.971] [bsu-ThinkPad-T470] [New I/O worker #13] INFO o.j.n.handler.logging.LoggingHandler@info:48 - [id: 0x1da87682, /127.0.0.1:44660 => /127.0.0.1:12122] RECEIVED: BigEndianHeapChannelBuffer(ridx=0, widx=154, cap=154)
2019-02-05 13:15:18.973] [bsu-ThinkPad-T470] [New I/O worker #13] INFO o.o.a.p.o.e.a.s.o.OslpDeviceSettingsService@getDeviceByUid:62 - get device by UID: AAHn1h93rsbQsx6t
2019-02-05 13:15:18.996] [bsu-ThinkPad-T470] [New I/O worker #13] INFO o.o.a.p.o.e.i.n.OslpChannelHandlerServer@messageReceived:127 - 497579650 Received OSLP Request: confirmRegisterDeviceRequest {
  randomDevice: 49956
  randomPlatform: 3229
}

2019-02-05 13:15:18.996] [bsu-ThinkPad-T470] [New I/O worker #13] INFO o.o.a.p.o.e.a.s.o.OslpDeviceSettingsService@getDeviceByUid:62 - get device by UID: AAHn1h93rsbQsx6t
2019-02-05 13:15:18.998] [bsu-ThinkPad-T470] [New I/O worker #13] INFO o.o.a.p.o.e.a.s.o.OslpDeviceSettingsService@getDeviceByUid:62 - get device by UID: AAHn1h93rsbQsx6t
2019-02-05 13:15:19.000] [bsu-ThinkPad-T470] [New I/O worker #13] INFO o.o.a.p.o.e.a.s.o.OslpDeviceSettingsService@updateDevice:50 - update device: SSLD_000-00-01
2019-02-05 13:15:19.004] [bsu-ThinkPad-T470] [New I/O worker #13] INFO o.o.a.p.o.e.i.m.SigningServerRequestMessageSender@send:43 - Sending request message to signing server, with reply-to-queue: queue://signing-server.1_0.responses-bsu-ThinkPad-T470.
2019-02-05 13:15:19.016] [bsu-ThinkPad-T470] [signingServerRequestsMessageListenerContainer-2] INFO o.o.s.s.i.m.SigningServerRequestMessageListener@onMessage:48 - Received message of type: SIGNING_REQUEST, for device: deviceIdentification with correlationId: 497579650 and replyToQueue: queue://signing-server.1_0.responses-bsu-ThinkPad-T470
2019-02-05 13:15:19.017] [bsu-ThinkPad-T470] [signingServerRequestsMessageListenerContainer-2] INFO o.o.s.s.a.services.SigningService@sign:65 - Received message to sign for device: deviceIdentification with correlationId: 497579650
2019-02-05 13:15:19.018] [bsu-ThinkPad-T470] [signingServerRequestsMessageListenerContainer-2] INFO o.o.s.s.a.services.SigningService@doSignMessage:99 - Message for device: deviceIdentification with correlationId: 497579650 signed, sending response to protocol-adapter
2019-02-05 13:15:19.028] [bsu-ThinkPad-T470] [signingResponsesMessageListenerContainer-3] INFO o.o.a.p.o.e.i.m.SigningServerResponsesMessageListener@onMessage:37 - Received message of type: SIGNING_RESPONSE
2019-02-05 13:15:19.029] [bsu-ThinkPad-T470] [signingResponsesMessageListenerContainer-3] INFO o.o.a.p.o.e.i.m.SigningServerResponsesMessageListener@onMessage:55 - Read signed message, messageType: SIGNING_RESPONSE, messagePriority: 0, deviceIdentification: deviceIdentification, result: OK, correlationId: 497579650
2019-02-05 13:15:19.030] [bsu-ThinkPad-T470] [signingResponsesMessageListenerContainer-3] INFO o.o.a.p.o.e.a.s.o.OslpSigningService@handleSignedOslpResponse:159 - oslpEnvelope.size: 158 for message type: null
2019-02-05 13:15:19.033] [bsu-ThinkPad-T470] [signingResponsesMessageListenerContainer-3] INFO o.j.n.handler.logging.LoggingHandler@info:48 - [id: 0x1da87682, /127.0.0.1:44660 => /127.0.0.1:12122] WRITE: BigEndianHeapChannelBuffer(ridx=0, widx=158, cap=158)
2019-02-05 13:15:19.034] [bsu-ThinkPad-T470] [New I/O worker #13] INFO o.j.n.handler.logging.LoggingHandler@info:48 - [id: 0x1da87682, /127.0.0.1:44660 => /127.0.0.1:12122] WRITTEN_AMOUNT: 158
2019-02-05 13:15:19.034] [bsu-ThinkPad-T470] [signingResponsesMessageListenerContainer-3] INFO o.o.a.p.o.e.i.n.OslpChannelHandlerServer@processSignedOslpEnvelope:185 - 497579650 Send OSLP Response: confirmRegisterDeviceResponse {
  status: OK
  randomDevice: 49956
  randomPlatform: 3229
  sequenceWindow: 6
}

2019-02-05 13:15:19.041] [bsu-ThinkPad-T470] [New I/O worker #4] INFO o.o.w.service.OslpChannelHandler@messageReceived:286 - Received OSLP Response (before callback): confirmRegisterDeviceResponse {
  status: OK
  randomDevice: 49956
  randomPlatform: 3229
  sequenceWindow: 6
}

2019-02-05 13:15:19.041] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-15] INFO o.o.w.service.OslpChannelHandler@get:123 - Response received within 20000 ms
2019-02-05 13:15:19.041] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-15] INFO o.o.w.service.OslpChannelHandler@send:424 - Received OSLP response (after callback): confirmRegisterDeviceResponse {
  status: OK
  randomDevice: 49956
  randomPlatform: 3229
  sequenceWindow: 6
}

2019-02-05 13:15:19.042] [bsu-ThinkPad-T470] [New I/O worker #13] INFO o.j.n.handler.logging.LoggingHandler@info:48 - [id: 0x1da87682, /127.0.0.1:44660 :> /127.0.0.1:12122] DISCONNECTED
2019-02-05 13:15:19.042] [bsu-ThinkPad-T470] [ajp-nio-8009-exec-15] INFO o.o.w.service.RegisterDevice@sendRequest:312 - Received response: confirmRegisterDeviceResponse {
  status: OK
  randomDevice: 49956
  randomPlatform: 3229
  sequenceWindow: 6
}

2019-02-05 13:15:19.044] [bsu-ThinkPad-T470] [New I/O worker #13] INFO o.o.a.p.o.e.i.n.OslpChannelHandlerServer@channelDisconnected:77 - 497579650 Channel disconnected
2019-02-05 13:15:19.045] [bsu-ThinkPad-T470] [New I/O worker #13] INFO o.j.n.handler.logging.LoggingHandler@info:48 - [id: 0x1da87682, /127.0.0.1:44660 :> /127.0.0.1:12122] UNBOUND
2019-02-05 13:15:19.045] [bsu-ThinkPad-T470] [New I/O worker #13] INFO o.o.a.p.o.e.i.n.OslpChannelHandlerServer@channelUnbound:89 - 497579650 Channel unbound
2019-02-05 13:15:19.045] [bsu-ThinkPad-T470] [New I/O worker #13] INFO o.j.n.handler.logging.LoggingHandler@info:48 - [id: 0x1da87682, /127.0.0.1:44660 :> /127.0.0.1:12122] CLOSED
2019-02-05 13:15:19.045] [bsu-ThinkPad-T470] [New I/O worker #13] INFO o.o.a.p.o.e.i.n.OslpChannelHandlerServer@channelClosed:83 - 497579650 Channel closed
2019-02-05 13:15:19.045] [bsu-ThinkPad-T470] [New I/O worker #4] INFO o.o.w.service.OslpChannelHandler@channelDisconnected:362 - Channel 957762998 disconnected
2019-02-05 13:15:19.046] [bsu-ThinkPad-T470] [New I/O worker #4] INFO o.o.w.service.OslpChannelHandler@channelUnbound:374 - Channel 957762998 unbound
2019-02-05 13:15:19.046] [bsu-ThinkPad-T470] [New I/O worker #4] INFO o.o.w.service.OslpChannelHandler@channelClosed:368 - Channel 957762998 closed
smvdheijden commented 5 years ago

Could you verify that all OSGP components, and especially osgp-core, are running? Perhaps using Tomcat Manager or Psi Probe? Could you also have a look at the ActiveMQ queues? Does every queue have consumers? Are there any messages stuck in queues? Do you see any stack traces while starting up Tomcat?

sameersubudhi commented 5 years ago

@smvdheijden

  1. Using psi-probe, I could see that osgp-adapter-ws-tariffswitching was down (everything else was up and running) and after I refreshed the application on the psi-probe web interface things seemed to work as expected. screenshot from 2019-02-05 17-29-48

  2. Some ActiveMQ queues have consumers, some don't. By "stuck", are you referring to "Number of Pending messages" or "Messages Enqueued"? screenshot from 2019-02-05 17-42-08 screenshot from 2019-02-05 17-42-26 screenshot from 2019-02-05 17-42-36 screenshot from 2019-02-05 17-42-42

  3. Console logs show no stack traces while starting up Tomcat.

smvdheijden commented 5 years ago

Could you check the osgp-core.log file for the occurrence of REGISTER_DEVICE? Normally after a device registration from the device simulator, the osgp-protocol-adapter-oslp-elster component should send a REGISTER_DEVICE message to the osgp-core component using the "osgp-core.1_0.protocol-oslp-elster.1_0.requests" queue in ActiveMQ. The osgp-core component should then update the device data. The logging in the osgp-core.log file should contain something like:

INFO o.o.c.i.j.p.i.ProtocolRequestMessageListener@onMessage:45 - Received message of type: REGISTER_DEVICE
INFO o.o.c.i.j.p.i.m.RegisterDeviceMessageProcessor@processMessage:52 - Received message of messageType: REGISTER_DEVICE organisationIdentification: no-organisation deviceIdentification: SSLD_000-00-01
INFO o.o.c.i.j.p.i.m.RegisterDeviceMessageProcessor@updateRegistrationData:91 - updateRegistrationData called for device: SSLD_000-00-01 ipAddress: 127.0.0.1, deviceType: SSLD hasSchedule: false.

Maybe you could try again, using the following steps:

  1. Start Tomcat
  2. Make sure all components are running using psi-probe
  3. Check in ActiveMQ if there are consumers on the osgp-core.1_0.protocol-oslp-elster.1_0.requests queue and check the number of messages enqueued/dequeued on that queue
  4. Register device and confirm device registration in the device simulator
  5. Check if the number of messages enqueued/dequeued of the osgp-core.1_0.protocol-oslp-elster.1_0.requests queue has increased
  6. Check if the REGISTER_DEVICE message is received by osgp core by checking the osgp-core.log file
  7. Check if the is_activated and device_lifecycle_status fields are updated in the Device table in the osgp_core database
sameersubudhi commented 5 years ago

@smvdheijden I followed the steps mentioned above and everything seems to currently work as expected.

  1. ActiveMQ initial status: For osgp-core.1_0.protocol-oslp-elster.1_0.requests queue: 
    # of consumers: 2
# messages enqueued: 0
# messages dequeued: 0
  2. ActiveMQ status after device registration and confirmation on simulator: For osgp-core.1_0.protocol-oslp-elster.1_0.requests queue: 
    # of consumers: 2
# messages enqueued: 1
# messages dequeued: 1
  3. osgp-core.log entry: 
    2019-02-06 11:11:07.839] [bsu-ThinkPad-T470] [DefaultMessageListenerContainer-1] INFO o.o.c.i.j.p.i.ProtocolRequestMessageListener@onMessage:45 - Received message of type: REGISTER_DEVICE
2019-02-06 11:11:07.840] [bsu-ThinkPad-T470] [DefaultMessageListenerContainer-1] INFO o.o.c.i.j.p.i.m.RegisterDeviceMessageProcessor@processMessage:52 - Received message of messageType: REGISTER_DEVICE organisationIdentification: no-organisation deviceIdentification: SSLD_000-00-01
2019-02-06 11:11:07.922] [bsu-ThinkPad-T470] [DefaultMessageListenerContainer-1] INFO o.o.c.i.j.p.i.m.RegisterDeviceMessageProcessor@updateRegistrationData:91 - updateRegistrationData called for device: SSLD_000-00-01 ipAddress: 127.0.0.1, deviceType: SSLD hasSchedule: false.
  4. Field status in osgp_core.devices: 
    is_activated: TRUE
device_lifecycle_status: IN_USE
smvdheijden commented 5 years ago

Ok, good to hear it is working. Is the SetLight request also working properly now?

sameersubudhi commented 5 years ago

@smvdheijden Yes. SetLight now works! Thank you for your help and support. Much appreciated :+1:

smvdheijden commented 5 years ago

Glad I could help. As it is working now, I will close this issue.

Sander3003 commented 5 years ago

@sameersubudhi feel free to help us improve the documentation so we can give others a better experience in using the Open Smart Grid Platform.

sameersubudhi commented 5 years ago

@Sander3003 I'll be happy to contribute my learnings and will be helping in updating the documentation. Kindly expect my inputs by the end of February 2019.