3 answers
- 10-1
/opt/opendaylight/current/data/karaf.log
- Frédéric Larocque
Thanks Brian Freeman,
Here is the karaf.log karaf.log
What is the meaning of this "could not map" ?
Could not map [ {"Status":{"Value":"FAILURE","Code":"500"},"CommonHeader":{"OriginatorID":null,"SubRequestID":"1","RequestID":"fb00b9e5-6ade-4dc0-af03-a8b897624c5f","APIver":"1.01","TimeStamp":"1566155263044"},"Payload":{"streams":"{\\\"streams\\\": {\\\"active-streams\\\": 5}}","generic-vnf.vnf-id":"e59ae2b6-83b2-48f4-bb0f-6551fbb65495"}} ] to org.onap.appc.listener.demo.model.IncomingMessage
com.fasterxml.jackson.databind.JsonMappingException: Can not construct instance of org.onap.appc.listener.demo.model.CommonMessage$Streams: no String-argument constructor/factory method to deserialize from String value ('{\"streams\": {\"active-streams\": 5}}')
at [Source: {"Status":{"Value":"FAILURE","Code":"500"},"CommonHeader":{"OriginatorID":null,"SubRequestID":"1","RequestID":"fb00b9e5-6ade-4dc0-af03-a8b897624c5f","APIver":"1.01","TimeStamp":"1566155263044"},"Payload":{"streams":"{\\\"streams\\\": {\\\"active-streams\\\": 5}}","generic-vnf.vnf-id":"e59ae2b6-83b2-48f4-bb0f-6551fbb65495"}}; line: 1, column: 216] (through reference chain: org.onap.appc.listener.demo.model.IncomingMessage["Payload"]->org.onap.appc.listener.demo.model.CommonMessage$Payload["streams"])
at com.fasterxml.jackson.databind.JsonMappingException.from(JsonMappingException.java:270) ~[27:com.fasterxml.jackson.core.jackson-databind:2.8.11.2]
at com.fasterxml.jackson.databind.DeserializationContext.instantiationException(DeserializationContext.java:1469) [27:com.fasterxml.jackson.core.jackson-databind:2.8.11.2]
at com.fasterxml.jackson.databind.DeserializationContext.handleMissingInstantiator(DeserializationContext.java:1012) [27:com.fasterxml.jackson.core.jackson-databind:2.8.11.2]
at com.fasterxml.jackson.databind.deser.ValueInstantiator._createFromStringFallbacks(ValueInstantiator.java:371) [27:com.fasterxml.jackson.core.jackson-databind:2.8.11.2]
at com.fasterxml.jackson.databind.deser.std.StdValueInstantiator.createFromString(StdValueInstantiator.java:324) [27:com.fasterxml.jackson.core.jackson-databind:2.8.11.2]
at com.fasterxml.jackson.databind.deser.BeanDeserializerBase.deserializeFromString(BeanDeserializerBase.java:1282) [27:com.fasterxml.jackson.core.jackson-databind:2.8.11.2]
at com.fasterxml.jackson.databind.deser.BeanDeserializer._deserializeOther(BeanDeserializer.java:159) [27:com.fasterxml.jackson.core.jackson-databind:2.8.11.2]
at com.fasterxml.jackson.databind.deser.BeanDeserializer.deserialize(BeanDeserializer.java:150) [27:com.fasterxml.jackson.core.jackson-databind:2.8.11.2]
at com.fasterxml.jackson.databind.deser.SettableBeanProperty.deserialize(SettableBeanProperty.java:504) [27:com.fasterxml.jackson.core.jackson-databind:2.8.11.2]
at com.fasterxml.jackson.databind.deser.impl.MethodProperty.deserializeAndSet(MethodProperty.java:104) [27:com.fasterxml.jackson.core.jackson-databind:2.8.11.2]
at com.fasterxml.jackson.databind.deser.BeanDeserializer.vanillaDeserialize(BeanDeserializer.java:276) [27:com.fasterxml.jackson.core.jackson-databind:2.8.11.2]
at com.fasterxml.jackson.databind.deser.BeanDeserializer.deserialize(BeanDeserializer.java:140) [27:com.fasterxml.jackson.core.jackson-databind:2.8.11.2]
at com.fasterxml.jackson.databind.deser.SettableBeanProperty.deserialize(SettableBeanProperty.java:504) [27:com.fasterxml.jackson.core.jackson-databind:2.8.11.2]
at com.fasterxml.jackson.databind.deser.impl.MethodProperty.deserializeAndSet(MethodProperty.java:104) [27:com.fasterxml.jackson.core.jackson-databind:2.8.11.2]
at com.fasterxml.jackson.databind.deser.BeanDeserializer.vanillaDeserialize(BeanDeserializer.java:276) [27:com.fasterxml.jackson.core.jackson-databind:2.8.11.2]
at com.fasterxml.jackson.databind.deser.BeanDeserializer.deserialize(BeanDeserializer.java:140) [27:com.fasterxml.jackson.core.jackson-databind:2.8.11.2]
at com.fasterxml.jackson.databind.ObjectMapper._readMapAndClose(ObjectMapper.java:3814) [27:com.fasterxml.jackson.core.jackson-databind:2.8.11.2]
at com.fasterxml.jackson.databind.ObjectMapper.readValue(ObjectMapper.java:2858) [27:com.fasterxml.jackson.core.jackson-databind:2.8.11.2]
at org.onap.appc.listener.util.Mapper.mapOne(Mapper.java:59) [494:org.onap.appc.listener:1.5.2]
at org.onap.appc.listener.util.Mapper.mapList(Mapper.java:69) [494:org.onap.appc.listener:1.5.2]
at org.onap.appc.listener.impl.EventHandlerImpl.getIncomingEvents(EventHandlerImpl.java:204) [494:org.onap.appc.listener:1.5.2]
at org.onap.appc.listener.demo.impl.ListenerImpl.run(ListenerImpl.java:72) [494:org.onap.appc.listener:1.5.2]
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) [?:?]
Add your comment... - 10-1
I don't think this is an error, but rather this configuration issue that was fixed:
POLICY-1830 - Policy throws error parsing its Publish on APPC-CL topic Closed
BTW - Brian you need to verify and close it if the configuration that Jorge did fixed it.
Pam
Add your comment... - 10-1
No
This is hourly longevity test which has been running for weeks on dublin. We do have times that the windriver infrastructure gets funky.
Take a look at the APPC logs to see why its replying with a HTTP 500.
It could be the vPNG needs to be rebooted. the demo vnf's aren't as robust as a real vnf.
Brian
- Frédéric Larocque
Hi Brian Freeman,
Running this command : kubectl -n onap log -f dev-appc-appc-0 appc
I can't see anything in the log about why APPC is returning 500.
I've tried to look in the pod to find an another log file specific to OpenDayLight but I did not find it.
Apache Karaf starting up. Press Enter to open the shell now...
91% [=================================================================> ]Starting the bundle
94% [===================================================================> ]2019-08-08T19:44:41.852+0000 INIT [cadi] Loading CADI Properties from /opt/onap/appc/data/properties/cadi.properties
2019-08-08T19:44:41.856+0000 INIT [cadi] cadi_keyfile points to /opt/onap/appc/data/stores/org.onap.appc.keyfile
2019-08-08T19:44:41.913+0000 INIT [cadi] cadi_protocols is set to TLSv1.1,TLSv1.2
2019-08-08T19:44:42.101+0000 INFO [cadi] AAFLocator enabled using https://aaf-locate.onap:8095
2019-08-08T19:44:42.104+0000 INIT [cadi] Cleaning Thread initialized with interval of 60000 ms and max objects of 1000
2019-08-08T19:44:42.110+0000 INIT [cadi] ID Conversion from admin to appc@appc.onap.org enabled
2019-08-08T19:44:42.110+0000 INIT [cadi] MapBathConversion enabled with file /opt/onap/appc/data/properties/bath_config.csv2019-08-08T19:44:42.197+0000 INIT [cadi] Loading CADI Properties from /opt/onap/appc/data/properties/cadi.properties
2019-08-08T19:44:42.197+0000 INIT [cadi] cadi_keyfile points to /opt/onap/appc/data/stores/org.onap.appc.keyfile
2019-08-08T19:44:42.234+0000 INFO [cadi] AAFLocator enabled using https://aaf-locate.onap:8095
2019-08-08T19:44:42.236+0000 INIT [cadi] Cleaning Thread initialized with interval of 60000 ms and max objects of 1000
2019-08-08T19:44:42.237+0000 INIT [cadi] ID Conversion from admin to appc@appc.onap.org enabled
2019-08-08T19:44:42.237+0000 INIT [cadi] MapBathConversion enabled with file /opt/onap/appc/data/properties/bath_config.csv95% [====================================================================> ]2019-08-08T19:44:47.913+0000 INIT [cadi] Loading CADI Properties from /opt/onap/appc/data/properties/cadi.properties
2019-08-08T19:44:47.914+0000 INIT [cadi] cadi_keyfile points to /opt/onap/appc/data/stores/org.onap.appc.keyfile
2019-08-08T19:44:47.994+0000 INFO [cadi] AAFLocator enabled using https://aaf-locate.onap:8095
2019-08-08T19:44:47.996+0000 INIT [cadi] Cleaning Thread initialized with interval of 60000 ms and max objects of 1000
2019-08-08T19:44:47.997+0000 INIT [cadi] ID Conversion from admin to appc@appc.onap.org enabled
2019-08-08T19:44:47.998+0000 INIT [cadi] MapBathConversion enabled with file /opt/onap/appc/data/properties/bath_config.csv2019-08-08T19:44:48.013+0000 INIT [cadi] Loading CADI Properties from /opt/onap/appc/data/properties/cadi.properties
2019-08-08T19:44:48.014+0000 INIT [cadi] cadi_keyfile points to /opt/onap/appc/data/stores/org.onap.appc.keyfile
2019-08-08T19:44:48.086+0000 INFO [cadi] AAFLocator enabled using https://aaf-locate.onap:8095
2019-08-08T19:44:48.087+0000 INIT [cadi] Cleaning Thread initialized with interval of 60000 ms and max objects of 1000
2019-08-08T19:44:48.088+0000 INIT [cadi] ID Conversion from admin to appc@appc.onap.org enabled
2019-08-08T19:44:48.088+0000 INIT [cadi] MapBathConversion enabled with file /opt/onap/appc/data/properties/bath_config.csv100% [========================================================================]
Karaf started in 47s. Bundle stats: 494 active, 495 total
2019-08-15T19:58:55.624+0000 AUDIT [cadi] ID admin converted to appc@appc.onap.org
2019-08-15T19:58:55.624+0000 AUDIT [cadi] ID admin converted to appc@appc.onap.org
2019-08-15T19:58:55.625+0000 AUDIT [cadi] ID admin converted to appc@appc.onap.org
2019-08-15T19:58:56.478+0000 INFO [cadi] AAFLurPerm: Loaded appc@appc.onap.org perms from AAF in 25.862700 ms, remote=22.296560
2019-08-15T19:58:56.478+0000 INFO [cadi] AAFLurPerm: Loaded appc@appc.onap.org perms from AAF in 25.759905 ms, remote=22.312092
2019-08-15T19:58:56.484+0000 INFO [cadi] AAFLurPerm: Loaded appc@appc.onap.org perms from AAF in 32.840965 ms, remote=31.767132
2019-08-15T20:00:42.882+0000 INFO [cadi] AAFLurPerm removed 1 and renewed 0 expired Permissions out of 2 and removed 0 password misses out of 0
2019-08-15T20:01:42.882+0000 INFO [cadi] AAFLurPerm removed 1 and renewed 0 expired Permissions out of 2 and removed 0 password misses out of 0
2019-08-15T20:02:42.882+0000 INFO [cadi] AAFLurPerm removed 1 and renewed 0 expired Permissions out of 2 and removed 0 password misses out of 0
2019-08-15T20:03:42.882+0000 INFO [cadi] AAFLurPerm removed 1 and renewed 0 expired Permissions out of 2 and removed 0 password misses out of 0
2019-08-15T20:04:42.882+0000 INFO [cadi] AAFLurPerm removed 1 and renewed 0 expired Permissions out of 2 and removed 0 password misses out of 0 - Frédéric Larocque
I forgot to tell you, that I tried to reboot the vPNG but it didn't solve the problem
Add your comment...
Hi,
I deployed the vFWCL using robot. Everything was working fine , pg-stream was replaced by APPC at their average value.
After some days, I noticed that the vFWCL was not working anymore. I get a "Policy was unable to parse APP-C response status code field." during the policy execution.
Here is the result of the network.log :
[2019-08-15T18:19:22.156+00:00|Session org.onap.policy.drools-applications.controlloop.common:controller-usecases:1.4.2:usecases][OUT|DMAAP|POLICY-CL-MGT]
{
"AAI": {
"vserver.prov-status": "ACTIVE",
"vserver.resource-version": "1565305905528",
"vserver.is-closed-loop-disabled": "false",
"vserver.vserver-name2": "Ete_vFWCLvFWSNK_8cb889ad_0",
"vserver.vserver-id": "7a6e494c-f501-4428-b69b-ebaf020ee293",
"vserver.vserver-selflink": "http://172.24.52.27:8774/v2.1/servers/7a6e494c-f501-4428-b69b-ebaf020ee293",
"vserver.in-maint": "false",
"vserver.vserver-name": "Ete_vFWCLvFWSNK_8cb889ad_0"
},
"closedLoopAlarmStart": 1565893064579348,
"closedLoopControlName": "ControlLoop-vFirewall-ff06f951-08ea-40f5-85f9-df87daad0919",
"version": "1.0.2",
"requestId": "e7144737-8b29-4a6c-8bb8-6314e32a5c26",
"closedLoopEventClient": "DCAE_INSTANCE_ID.dcae-tca",
"targetType": "VM",
"target": "vserver.vserver-name",
"from": "policy:usecases",
"policyScope": "onap.policies.controlloop.Operational:1.0.0",
"policyName": "operational.modifyconfig.APPC.RESPONSE",
"policyVersion": "1.0.0",
"notification": "OPERATION: FAILURE",
"message": "actor=APPC,operation=ModifyConfig,target=Target [type=VNF, resourceId=ff06f951-08ea-40f5-85f9-df87daad0919],start=2019-08-15T18:19:21.473Z,end=2019-08-15T18:19:22.133Z,subRequestId=1,outcome=Failure_Exception,message=Policy was unable to parse APP-C response status code field.",
"notificationTime": "2019-08-15 18:19:22.156000+00:00",
"history": [
{
"actor": "APPC",
"operation": "ModifyConfig",
"target": "Target [type=VNF, resourceId=ff06f951-08ea-40f5-85f9-df87daad0919]",
"start": 1565893161473,
"end": 1565893162133,
"subRequestId": "1",
"outcome": "Failure_Exception",
"message": "Policy was unable to parse APP-C response status code field."
}
]
}
[2019-08-15T18:19:22.157+00:00|Session org.onap.policy.drools-applications.controlloop.common:controller-usecases:1.4.2:usecases][OUT|DMAAP|POLICY-CL-MGT]
{
"AAI": {
"vserver.prov-status": "ACTIVE",
"vserver.resource-version": "1565305905528",
"vserver.is-closed-loop-disabled": "false",
"vserver.vserver-name2": "Ete_vFWCLvFWSNK_8cb889ad_0",
"vserver.vserver-id": "7a6e494c-f501-4428-b69b-ebaf020ee293",
"vserver.vserver-selflink": "http://172.24.52.27:8774/v2.1/servers/7a6e494c-f501-4428-b69b-ebaf020ee293",
"vserver.in-maint": "false",
"vserver.vserver-name": "Ete_vFWCLvFWSNK_8cb889ad_0"
},
"closedLoopAlarmStart": 1565893064579348,
"closedLoopControlName": "ControlLoop-vFirewall-ff06f951-08ea-40f5-85f9-df87daad0919",
"version": "1.0.2",
"requestId": "e7144737-8b29-4a6c-8bb8-6314e32a5c26",
"closedLoopEventClient": "DCAE_INSTANCE_ID.dcae-tca",
"targetType": "VM",
"target": "vserver.vserver-name",
"from": "policy:usecases",
"policyScope": "onap.policies.controlloop.Operational:1.0.0",
"policyName": "operational.modifyconfig.EVENT.MANAGER",
"policyVersion": "1.0.0",
"notification": "FINAL: FAILURE",
"message": "Exception in processing closed loop",
"notificationTime": "2019-08-15 18:19:22.157000+00:00",
"history": [
{
"actor": "APPC",
"operation": "ModifyConfig",
"target": "Target [type=VNF, resourceId=ff06f951-08ea-40f5-85f9-df87daad0919]",
"start": 1565893161473,
"end": 1565893162133,
"subRequestId": "1",
"outcome": "Failure_Exception",
"message": "Policy was unable to parse APP-C response status code field."
}
]
}
[2019-08-15T18:19:22.259+00:00|DMAAP-source-APPC-CL][IN|DMAAP|APPC-CL]
{"Status":{"Value":"ACCEPTED","Code":"100"},"CommonHeader":{"OriginatorID":null,"SubRequestID":"1","RequestID":"e7144737-8b29-4a6c-8bb8-6314e32a5c26","APIver":"1.01","TimeStamp":"1565893161473"},"Payload":{"streams":"{\\\"streams\\\": {\\\"active-streams\\\": 5}}","generic-vnf.vnf-id":"f0b67eab-2151-4521-8ce7-4929c4797934"}}
[2019-08-15T18:19:22.804+00:00|DMAAP-source-APPC-CL][IN|DMAAP|APPC-CL]
{"Status":{"Value":"FAILURE","Code":"500"},"CommonHeader":{"OriginatorID":null,"SubRequestID":"1","RequestID":"e7144737-8b29-4a6c-8bb8-6314e32a5c26","APIver":"1.01","TimeStamp":"1565893161473"},"Payload":{"streams":"{\\\"streams\\\": {\\\"active-streams\\\": 5}}","generic-vnf.vnf-id":"f0b67eab-2151-4521-8ce7-4929c4797934"}}
[2019-08-15T18:19:31.174+00:00|qtp1534754611-35]10.42.7.64 - - [15/Aug/2019:18:19:31 +0000] "GET /healthcheck HTTP/1.1" 200 102
[2019-08-15T18:19:37.507+00:00|DMAAP-source-POLICY-PDP-PAP][IN|DMAAP|POLICY-PDP-PAP]
{"pdpType":"xacml","state":"ACTIVE","healthy":"HEALTHY","supportedPolicyTypes":[{"name":"onap.policies.optimization.AffinityPolicy","version":"1.0.0"},{"name":"onap.policies.optimization.DistancePolicy","version":"1.0.0"},{"name":"onap.policies.optimization.HpaPolicy","version":"1.0.0"},{"name":"onap.policies.optimization.OptimizationPolicy","version":"1.0.0"},{"name":"onap.policies.optimization.PciPolicy","version":"1.0.0"},{"name":"onap.policies.optimization.QueryPolicy","version":"1.0.0"},{"name":"onap.policies.optimization.SubscriberPolicy","version":"1.0.0"},{"name":"onap.policies.optimization.Vim_fit","version":"1.0.0"},{"name":"onap.policies.optimization.VnfPolicy","version":"1.0.0"},{"name":"onap.policies.controlloop.guard.FrequencyLimiter","version":"1.0.0"},{"name":"onap.policies.controlloop.guard.MinMax","version":"1.0.0"},{"name":"onap.policies.controlloop.guard.Blacklist","version":"1.0.0"},{"name":"onap.policies.controlloop.guard.coordination.FirstBlocksSecond","version":"1.0.0"},{"name":"onap.Monitoring","version":"1.0.0"},{"name":"onap.policies.monitoring.cdap.tca.hi.lo.app","version":"1.0.0"},{"name":"onap.policies.monitoring.dcaegen2.collectors.datafile.datafile-app-server","version":"1.0.0"},{"name":"onap.policies.monitoring.docker.sonhandler.app","version":"1.0.0"}],"policies":[{"name":"guard.frequency.scaleout","version":"1.0.0"},{"name":"onap.vfirewall.tca","version":"1.0.0"},{"name":"tca_k8s_demoVLB_v3_0_vLBMS955b7e4b-a3260_k8s-tca-clamp-policy-05082019","version":"1.0.0"}],"messageName":"PDP_STATUS","requestId":"42978617-aae3-47fb-85f0-d2f2c81f6b57","timestampMs":1565893176837,"name":"dev-policy-policy-xacml-pdp-7b5f66d66f-v5fzj","pdpGroup":"defaultGroup","pdpSubgroup":"xacml"}
Is this a known issue ? That the vFWCL will stop working after a couple of days ?
Thanks