Revision history [back]

I have a problem/question regarding the init procedure

Hello all,

I'm trying to deploy the Orion ContextBroker on a Openshift/OKD(Kubernetes) cluster and I'm having a problem with its deployment regarding the initialization time.

I'm using the 2.2.0 release tag for the ContextBroker with mongoDB 3.2.0. The startup args for Orion are:
"-ipv4 -reqPoolSize 100 -notificationMode threadpool:10000:50 -statNotifQueue -statCounters -statSemWait -statTiming -relogAlarms -httpTimeout 100000"

The initialization appears to be somewhat inconsistent regarding the time required for the app to become available.
Sometimes the deployment runs "smoothly" and sometimes the app fails to start (in a reasonable time interval).

The initialization seems to freeze at a certain point which appears in the logs as [1]. The actual service isn't started (lsof -i -n -P doesn't return any processes using port 1026).
I use standard health-checks which, basically, do a "curl localhost:1026/version". I've tried modifying the timeouts and also the delay time from which the probe fires. Not even with 360sec (6 minutes) delay do I reach consistent deployments!

I've tested with different resource allocation and this doesn't seem to be the problem.

Also by checking the logs I see some "odd" intervals in the initialization procedure. I have some excerpts at the end of the message, [2], where I can see the last steps of the init procedure being executed(or, at least, logged) at precisely 1 minute intervals.

The problem is that once the readiness health check fails, the deployment fails as well. Orion seems to use a lot of RAM which does not get released even if the notification load disappears, from what I saw. The recommendation would be to restart the process, which, in my case, can be automatically handled if I set an upper memory limit for the container. So the initialization process comes again in question...also for the auto-scaling mechanism, etc.

Any hints towards how to solve this problem would be much appreciated!

Thanks, Dan

==========================

[1] - last 10-12 lines from ContextBroker's log; DEBUG -t 0-255

======================

[2] excerpt from final log entries of the initialization process; highlighted the timestamps for subsequent operations which happen to be at precisely 1 min interval; final entries are from the liveness probes when the app starts being available

======================
time=Wednesday 19 Jun 19:06:01 2019.060Z | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[94]:collectionQuery | msg=Database Operation Successful (query: {})
time=Wednesday 19 Jun 19:06:01 2019.107Z | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=contextBroker.cpp[1040]:main | msg=Startup completed
time=Wednesday 19 Jun 19:07:01 2019.062Z | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[94]:collectionQuery | msg=Database Operation Successful (query: {})
time=Wednesday 19 Jun 19:07:01 2019.064Z | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[449]:collectionUpdate | msg=Database Operation Successful (update: <{ _id: ObjectId('5d0215c1294122a2ec462ff3'), $or: [ { lastFailure: { $lt: 1560855211 } }, { lastFailure: { $exists: false } } ] }, { $set: { lastFailure: 1560855211, lastFailureReason: "Timeout was reached" } }>)
time=Wednesday 19 Jun 19:07:01 2019.064Z | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[449]:collectionUpdate | msg=Database Operation Successful (update: <{ _id: ObjectId('5d0215c1294122a2ec462ff3'), $or: [ { lastSuccess: { $lt: 1560855687 } }, { lastSuccess: { $exists: false } } ] }, { $set: { lastSuccess: 1560855687, lastSuccessCode: 200 } }>)
time=Wednesday 19 Jun 19:08:01 2019.066Z | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[94]:collectionQuery | msg=Database Operation Successful (query: {})
time=Wednesday 19 Jun 19:08:01 2019.067Z | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[449]:collectionUpdate | msg=Database Operation Successful (update: <{ _id: ObjectId('5d0215c1294122a2ec462ff3'), $or: [ { lastFailure: { $lt: 1560855211 } }, { lastFailure: { $exists: false } } ] }, { $set: { lastFailure: 1560855211, lastFailureReason: "Timeout was reached" } }>)
time=Wednesday 19 Jun 19:08:01 2019.067Z | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[449]:collectionUpdate | msg=Database Operation Successful (update: <{ _id: ObjectId('5d0215c1294122a2ec462ff3'), $or: [ { lastSuccess: { $lt: 1560855687 } }, { lastSuccess: { $exists: false } } ] }, { $set: { lastSuccess: 1560855687, lastSuccessCode: 200 } }>)
time=Wednesday 19 Jun 19:09:01 2019.069Z | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[94]:collectionQuery | msg=Database Operation Successful (query: {})
time=Wednesday 19 Jun 19:09:01 2019.071Z | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[449]:collectionUpdate | msg=Database Operation Successful (update: <{ _id: ObjectId('5d0215c1294122a2ec462ff3'), $or: [ { lastFailure: { $lt: 1560855211 } }, { lastFailure: { $exists: false } } ] }, { $set: { lastFailure: 1560855211, lastFailureReason: "Timeout was reached" } }>)
time=Wednesday 19 Jun 19:09:01 2019.071Z | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[449]:collectionUpdate | msg=Database Operation Successful (update: <{ _id: ObjectId('5d0215c1294122a2ec462ff3'), $or: [ { lastSuccess: { $lt: 1560855687 } }, { lastSuccess: { $exists: false } } ] }, { $set: { lastSuccess: 1560855687, lastSuccessCode: 200 } }>)
time=Wednesday 19 Jun 19:10:01 2019.073Z | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[94]:collectionQuery | msg=Database Operation Successful (query: {})
time=Wednesday 19 Jun 19:10:01 2019.075Z | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[449]:collectionUpdate | msg=Database Operation Successful (update: <{ _id: ObjectId('5d0215c1294122a2ec462ff3'), $or: [ { lastFailure: { $lt: 1560855211 } }, { lastFailure: { $exists: false } } ] }, { $set: { lastFailure: 1560855211, lastFailureReason: "Timeout was reached" } }>)
time=Wednesday 19 Jun 19:10:01 2019.076Z | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[449]:collectionUpdate | msg=Database Operation Successful (update: <{ _id: ObjectId('5d0215c1294122a2ec462ff3'), $or: [ { lastSuccess: { $lt: 1560855687 } }, { lastSuccess: { $exists: false } } ] }, { $set: { lastSuccess: 1560855687, lastSuccessCode: 200 } }>)
time=Wednesday 19 Jun 19:11:01 2019.078Z | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[94]:collectionQuery | msg=Database Operation Successful (query: {})
time=Wednesday 19 Jun 19:11:01 2019.079Z | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[449]:collectionUpdate | msg=Database Operation Successful (update: <{ _id: ObjectId('5d0215c1294122a2ec462ff3'), $or: [ { lastFailure: { $lt: 1560855211 } }, { lastFailure: { $exists: false } } ] }, { $set: { lastFailure: 1560855211, lastFailureReason: "Timeout was reached" } }>)
time=Wednesday 19 Jun 19:11:01 2019.080Z | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[449]:collectionUpdate | msg=Database Operation Successful (update: <{ _id: ObjectId('5d0215c1294122a2ec462ff3'), $or: [ { lastSuccess: { $lt: 1560855687 } }, { lastSuccess: { $exists: false } } ] }, { $set: { lastSuccess: 1560855687, lastSuccessCode: 200 } }>)
time=Wednesday 19 Jun 19:11:10 2019.809Z | lvl=INFO | corr=ffb9d5e6-92c5-11e9-885f-0a580a8301d0 | trans=1560971160-541-00000000001 | from=10.131.0.1 | srv=<none> | subsrv=<none> | comp=Orion | op=logMsg.h[1844]:lmTransactionStart | msg=Starting transaction from 10.131.0.1:58238/version
time=Wednesday 19 Jun 19:11:10 2019.820Z | lvl=INFO | corr=ffb9d5e6-92c5-11e9-885f-0a580a8301d0 | trans=1560971160-541-00000000001 | from=10.131.0.1 | srv=<none> | subsrv=<none> | comp=Orion | op=logMsg.h[1874]:lmTransactionEnd | msg=Transaction ended
time=Wednesday 19 Jun 19:11:25 2019.800Z | lvl=INFO | corr=08a93c1e-92c6-11e9-b713-0a580a8301d0 | trans=1560971160-541-00000000002 | from=10.131.0.1 | srv=<none> | subsrv=<none> | comp=Orion | op=logMsg.h[1844]:lmTransactionStart | msg=Starting transaction from 10.131.0.1:57998/version
time=Wednesday 19 Jun 19:11:25 2019.801Z | lvl=INFO | corr=08a93c1e-92c6-11e9-b713-0a580a8301d0 | trans=1560971160-541-00000000002 | from=10.131.0.1 | srv=<none> | subsrv=<none> | comp=Orion | op=logMsg.h[1874]:lmTransactionEnd | msg=Transaction ended

I have a problem/question regarding the init procedure

Hello all,

I'm trying to deploy the Orion ContextBroker on a Openshift/OKD(Kubernetes) cluster and I'm having a problem with its deployment regarding the initialization time.

I'm using the 2.2.0 release tag for the ContextBroker with mongoDB 3.2.0. The startup args for Orion are:
"

-ipv4 -reqPoolSize 100 -notificationMode threadpool:10000:50 -statNotifQueue -statCounters -statSemWait -statTiming -relogAlarms -httpTimeout ~~100000~~"

100000

The initialization seems to freeze at a certain point which appears in the logs as [1]. The actual service isn't started ~~(lsof~~ (lsof -i -n -P -P doesn't return any processes using port 1026).
I use standard health-checks which, basically, do a "curl localhost:1026/version". . I've tried modifying the timeouts and also the delay time from which the probe fires. Not even with 360sec (6 minutes) delay do I reach consistent deployments!

I've tested with different resource allocation and this doesn't seem to be the problem.

Any hints towards how to solve this problem would be much appreciated!

Thanks, Dan

~~==========================~~

[1] - last 10-12 lines from ContextBroker's log; DEBUG -t 0-255

=============================

time=Wednesday 19 Jun 16:50:35 2019.407Z | lvl=DEBUG | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[802]:getWriteConcern | msg=getWriteConcern()
time=Wednesday 19 Jun 16:50:35 2019.407Z | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[807]:getWriteConcern | msg=Database Operation Successful (getWriteConcern)
time=Wednesday 19 Jun 16:50:35 2019.407Z | lvl=DEBUG | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=mongoConnectionPool.cpp[240]:mongoConnect | msg=Active DB Write Concern mode: 1
time=Wednesday 19 Jun 16:50:35 2019.431Z | lvl=DEBUG | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[691]:runCollectionCommand | msg=runCommand() in 'admin' collection: '{ buildinfo: 1 }'
time=Wednesday 19 Jun 16:50:35 2019.431Z | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[701]:runCollectionCommand | msg=Database Operation Successful (command: { buildinfo: 1 })
time=Wednesday 19 Jun 16:50:35 2019.431Z | lvl=DEBUG | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=mongoConnectionPool.cpp[282]:mongoConnect | msg=mongo version server: 3.2.10 (mayor: 3, minor: 2, extra: 10)
time=Wednesday 19 Jun 16:50:35 2019.432Z | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=MongoGlobal.cpp[227]:mongoInit | msg=Connected to mongo at mongodb.civ-fiware.svc.cluster.local:admin as user 'admin'
time=Wednesday 19 Jun 16:50:35 2019.432Z | lvl=DEBUG | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=MongoGlobal.cpp[448]:setDbPrefix | msg=Set dbPrefix to 'admin'
time=Wednesday 19 Jun 16:50:35 2019.432Z | lvl=DEBUG | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=MongoGlobal.cpp[607]:composeDatabaseName | msg=database name composed: 'admin'
time=Wednesday 19 Jun 16:50:35 2019.435Z | lvl=DEBUG | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[577]:collectionCreateIndex | msg=createIndex() in 'admin.entities' collection: '{ location.coords: "2dsphere" }'

======================
}'

[2] excerpt from final log entries of the initialization process; highlighted the timestamps for subsequent operations which happen to be at precisely 1 min interval; final entries are from the liveness probes when the app starts being available
======================

time=Wednesday 19 Jun 19:06:01 2019.060Z | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[94]:collectionQuery | msg=Database Operation Successful (query: {})
time=Wednesday 19 Jun ~~19:06:01 2019.107Z~~ **19:06:01 2019.107Z** | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=contextBroker.cpp[1040]:main | msg=Startup completed
time=Wednesday 19 Jun ~~19:07:01 2019.062Z~~ **19:07:01 2019.062Z** | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[94]:collectionQuery | msg=Database Operation Successful (query: {})
time=Wednesday 19 Jun 19:07:01 2019.064Z | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[449]:collectionUpdate | msg=Database Operation Successful (update: <{ _id: ObjectId('5d0215c1294122a2ec462ff3'), $or: [ { lastFailure: { $lt: 1560855211 } }, { lastFailure: { $exists: false } } ] }, { $set: { lastFailure: 1560855211, lastFailureReason: "Timeout was reached" } }>)
time=Wednesday 19 Jun ~~19:07:01 2019.064Z~~ **19:07:01 2019.064Z** | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[449]:collectionUpdate | msg=Database Operation Successful (update: <{ _id: ObjectId('5d0215c1294122a2ec462ff3'), $or: [ { lastSuccess: { $lt: 1560855687 } }, { lastSuccess: { $exists: false } } ] }, { $set: { lastSuccess: 1560855687, lastSuccessCode: 200 } }>)
time=Wednesday 19 Jun ~~19:08:01 2019.066Z~~ **19:08:01 2019.066Z** | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[94]:collectionQuery | msg=Database Operation Successful (query: {})
time=Wednesday 19 Jun 19:08:01 2019.067Z | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[449]:collectionUpdate | msg=Database Operation Successful (update: <{ _id: ObjectId('5d0215c1294122a2ec462ff3'), $or: [ { lastFailure: { $lt: 1560855211 } }, { lastFailure: { $exists: false } } ] }, { $set: { lastFailure: 1560855211, lastFailureReason: "Timeout was reached" } }>)
time=Wednesday 19 Jun ~~19:08:01 2019.067Z~~ **19:08:01 2019.067Z** | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[449]:collectionUpdate | msg=Database Operation Successful (update: <{ _id: ObjectId('5d0215c1294122a2ec462ff3'), $or: [ { lastSuccess: { $lt: 1560855687 } }, { lastSuccess: { $exists: false } } ] }, { $set: { lastSuccess: 1560855687, lastSuccessCode: 200 } }>)
time=Wednesday 19 Jun ~~19:09:01 2019.069Z~~ **19:09:01 2019.069Z** | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[94]:collectionQuery | msg=Database Operation Successful (query: {})
time=Wednesday 19 Jun 19:09:01 2019.071Z | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[449]:collectionUpdate | msg=Database Operation Successful (update: <{ _id: ObjectId('5d0215c1294122a2ec462ff3'), $or: [ { lastFailure: { $lt: 1560855211 } }, { lastFailure: { $exists: false } } ] }, { $set: { lastFailure: 1560855211, lastFailureReason: "Timeout was reached" } }>)
time=Wednesday 19 Jun ~~19:09:01 2019.071Z~~ **19:09:01 2019.071Z** | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[449]:collectionUpdate | msg=Database Operation Successful (update: <{ _id: ObjectId('5d0215c1294122a2ec462ff3'), $or: [ { lastSuccess: { $lt: 1560855687 } }, { lastSuccess: { $exists: false } } ] }, { $set: { lastSuccess: 1560855687, lastSuccessCode: 200 } }>)
time=Wednesday 19 Jun ~~19:10:01 2019.073Z~~ **19:10:01 2019.073Z** | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[94]:collectionQuery | msg=Database Operation Successful (query: {})
time=Wednesday 19 Jun 19:10:01 2019.075Z | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[449]:collectionUpdate | msg=Database Operation Successful (update: <{ _id: ObjectId('5d0215c1294122a2ec462ff3'), $or: [ { lastFailure: { $lt: 1560855211 } }, { lastFailure: { $exists: false } } ] }, { $set: { lastFailure: 1560855211, lastFailureReason: "Timeout was reached" } }>)
time=Wednesday 19 Jun ~~19:10:01 2019.076Z~~ **19:10:01 2019.076Z** | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[449]:collectionUpdate | msg=Database Operation Successful (update: <{ _id: ObjectId('5d0215c1294122a2ec462ff3'), $or: [ { lastSuccess: { $lt: 1560855687 } }, { lastSuccess: { $exists: false } } ] }, { $set: { lastSuccess: 1560855687, lastSuccessCode: 200 } }>)
time=Wednesday 19 Jun ~~19:11:01 2019.078Z~~ **19:11:01 2019.078Z** | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[94]:collectionQuery | msg=Database Operation Successful (query: {})
time=Wednesday 19 Jun 19:11:01 2019.079Z | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[449]:collectionUpdate | msg=Database Operation Successful (update: <{ _id: ObjectId('5d0215c1294122a2ec462ff3'), $or: [ { lastFailure: { $lt: 1560855211 } }, { lastFailure: { $exists: false } } ] }, { $set: { lastFailure: 1560855211, lastFailureReason: "Timeout was reached" } }>)
time=Wednesday 19 Jun 19:11:01 2019.080Z | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[449]:collectionUpdate | msg=Database Operation Successful (update: <{ _id: ObjectId('5d0215c1294122a2ec462ff3'), $or: [ { lastSuccess: { $lt: 1560855687 } }, { lastSuccess: { $exists: false } } ] }, { $set: { lastSuccess: 1560855687, lastSuccessCode: 200 } }>)
time=Wednesday 19 Jun 19:11:10 2019.809Z | lvl=INFO | corr=ffb9d5e6-92c5-11e9-885f-0a580a8301d0 | trans=1560971160-541-00000000001 | from=10.131.0.1 | srv=<none> | subsrv=<none> | comp=Orion | op=logMsg.h[1844]:lmTransactionStart | msg=Starting transaction from 10.131.0.1:58238/version
time=Wednesday 19 Jun 19:11:10 2019.820Z | lvl=INFO | corr=ffb9d5e6-92c5-11e9-885f-0a580a8301d0 | trans=1560971160-541-00000000001 | from=10.131.0.1 | srv=<none> | subsrv=<none> | comp=Orion | op=logMsg.h[1874]:lmTransactionEnd | msg=Transaction ended
time=Wednesday 19 Jun 19:11:25 2019.800Z | lvl=INFO | corr=08a93c1e-92c6-11e9-b713-0a580a8301d0 | trans=1560971160-541-00000000002 | from=10.131.0.1 | srv=<none> | subsrv=<none> | comp=Orion | op=logMsg.h[1844]:lmTransactionStart | msg=Starting transaction from 10.131.0.1:57998/version
time=Wednesday 19 Jun 19:11:25 2019.801Z | lvl=INFO | corr=08a93c1e-92c6-11e9-b713-0a580a8301d0 | trans=1560971160-541-00000000002 | from=10.131.0.1 | srv=<none> | subsrv=<none> | comp=Orion | op=logMsg.h[1874]:lmTransactionEnd | msg=Transaction ~~ended~~
ended