Revision history [back]

Hi and thanks for the answer and tests!

I'm using the "answer" section simply because the reply doesn't fit a comment.

As I saw this question/problem wasn't getting moderated and made public I went ahead and posted it on the github repo for the project as well: https://github.com/telefonicaid/fiware-orion/issues/3515

My configuration is quite similar. I use a custom build where I simply add a wrapper script to start the main process. This serves as a more convenient way to configure different startup arguments for the main process. The script:

\!/bin/bash

/usr/bin/contextBroker -fg -logLevel $ORION_LOG_LEVEL -dbhost $ORION_MONGO_HOST -db $ORION_MONGO_DB \
    -dbuser $ORION_MONGO_USER -dbpwd $ORION_MONGO_PASS $ORION_EXTRA_ARGS

So my yaml definition for the Pod/DeploymentConfiguration is:

              command:
                - /opt/bin/runContextBroker.sh
              image: ""
              imagePullPolicy: IfNotPresent
              env:
                - name: TZ
                  value: ${ENV_TZ}
                - name: ORION_LOG_LEVEL
                  valueFrom:
                    configMapKeyRef:
                      name: ${ORION_CONF}
                      key: ORION_LOG_LEVEL
                - name: ORION_MONGO_HOST
                  valueFrom:
                    configMapKeyRef:
                      name: ${ORION_CONF}
                      key: ORION_MONGO_HOST
                - name: ORION_MONGO_DB
                  valueFrom:
                    secretKeyRef:
                      key: database-name
                      name: ${MONGODB_ENV}
                - name: ORION_MONGO_USER
                  valueFrom:
                    configMapKeyRef:
                      name: ${ORION_CONF}
                      key: ORION_MONGO_USER
                - name: ORION_MONGO_PASS
                  valueFrom:
                    secretKeyRef:
                      key: database-admin-password
                      name: ${MONGODB_ENV}
                - name: ORION_EXTRA_ARGS
                  valueFrom:
                    configMapKeyRef:
                      name: ${ORION_CONF}
                      key: ORION_EXTRA_ARGS
              ports:
                - containerPort: 1026
                  protocol: TCP

The excerpt above uses some parameters that reference a ConfigMap - ORIONCONF and a Secret - MONGODBENV(OKD objects; given your reply I imagine you are familiar with them), but the deployed Pod ends up starting with pretty much the same arguments. The ORIONEXTRAARGS env var holds all the startup arguments that I've mentioned in the initial mail and that, I see, you use in your test. I don't use an exec in my startup script so that PID 1 of the container would actually go to the contextBroker process. Will have to try this (ss noted in the last github comment by Fermin Marquez).
Again, as mentioned in the github discussion I have switched to 3.6 version of Mongo, but this hasn't led to an improvement in my case.

The problem I have is that sometimes, just like in your test example, the serrvice starts without any problems/right away and sometimes the initialization process gets stuck, the process doesn't begin listening on the 1026 port so it practically doesn't begin to run. What I found is that there's precisely the same step where the init process arrives during failed inits:

time=Monday 24 Jun 09:32:17 2019.632Z | 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'

If using the INFO log level, this would be the same 42nd line inside the Pod/container log.

When the Pod starts without issues, the log gets past this point and shows:

time=Monday 24 Jun 09:32:17 2019.632Z | 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=Monday 24 Jun 09:32:18 2019.023Z | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[597]:collectionCreateIndex | msg=Database Operation Successful (createIndex: { location.coords: "2dsphere" })
time=Monday 24 Jun 09:32:18 2019.095Z | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[597]:collectionCreateIndex | msg=Database Operation Successful (createIndex: { expDate: 1 })
time=Monday 24 Jun 09:32:18 2019.116Z | 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=Monday 24 Jun 09:32:18 2019.135Z | 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

You'd notice the same timestap; that is because I've just used the same line from the log for conveninece. What I want to point out is the initialization phases as they appear in the logs.

So, judging from the logs, it seems that the point at which the initialization gets stuck is at Database Operation Successful (createIndex: { location.coords: "2dsphere" }). Somehow this operations isn't run successfully at time.

PS: Just after seeing your post did I realize that I can use text formatting inside the message here. The initial one is really rough on the eyes...will try to edit it.

Hi and thanks for the answer and tests!

I'm using the "answer" section simply because the reply doesn't fit a comment.

As I saw this question/problem wasn't getting moderated and made public I went ahead and posted it on the github repo for the project as well: https://github.com/telefonicaid/fiware-orion/issues/3515

My configuration is quite similar. I use a custom build where I simply add a wrapper script to start the main process. This serves as a more convenient way to configure different startup arguments for the main process. The script:

\!/bin/bash

/usr/bin/contextBroker -fg -logLevel $ORION_LOG_LEVEL -dbhost $ORION_MONGO_HOST -db $ORION_MONGO_DB \
    -dbuser $ORION_MONGO_USER -dbpwd $ORION_MONGO_PASS $ORION_EXTRA_ARGS

So my yaml definition for the Pod/DeploymentConfiguration is:

              command:
                - /opt/bin/runContextBroker.sh
              image: ""
              imagePullPolicy: IfNotPresent
              env:
                - name: TZ
                  value: ${ENV_TZ}
                - name: ORION_LOG_LEVEL
                  valueFrom:
                    configMapKeyRef:
                      name: ${ORION_CONF}
                      key: ORION_LOG_LEVEL
                - name: ORION_MONGO_HOST
                  valueFrom:
                    configMapKeyRef:
                      name: ${ORION_CONF}
                      key: ORION_MONGO_HOST
                - name: ORION_MONGO_DB
                  valueFrom:
                    secretKeyRef:
                      key: database-name
                      name: ${MONGODB_ENV}
                - name: ORION_MONGO_USER
                  valueFrom:
                    configMapKeyRef:
                      name: ${ORION_CONF}
                      key: ORION_MONGO_USER
                - name: ORION_MONGO_PASS
                  valueFrom:
                    secretKeyRef:
                      key: database-admin-password
                      name: ${MONGODB_ENV}
                - name: ORION_EXTRA_ARGS
                  valueFrom:
                    configMapKeyRef:
                      name: ${ORION_CONF}
                      key: ORION_EXTRA_ARGS
              ports:
                - containerPort: 1026
                  protocol: TCP

The excerpt above uses some parameters that reference a ConfigMap - ORIONCONFORION_CONF and a Secret - MONGODBENVMONGODB_ENV(OKD objects; given your reply I imagine you are familiar with them), but the deployed Pod ends up starting with pretty much the same arguments. The ORIONEXTRAARGSORION_EXTRA_ARGS env var holds all the startup arguments that I've mentioned in the initial mail and that, I see, you use in your test. I don't use an exec in my startup script so that PID 1 of the container would actually go to the contextBroker process. Will have to try this (ss noted in the last github comment by Fermin Marquez).
Again, as mentioned in the github discussion I have switched to 3.6 version of Mongo, but this hasn't led to an improvement in my case.

The problem I have is that sometimes, just like in your test example, the serrvice starts without any problems/right away and sometimes the initialization process gets stuck, the process doesn't begin listening on the 1026 port so it practically doesn't begin to run. What I found is that there's precisely the same step where the init process arrives during failed inits:

time=Monday 24 Jun 09:32:17 2019.632Z | 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'

If using the INFO log level, this would be the same 42nd line inside the Pod/container log.

When the Pod starts without issues, the log gets past this point and shows:

time=Monday 24 Jun 09:32:17 2019.632Z | 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=Monday 24 Jun 09:32:18 2019.023Z | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[597]:collectionCreateIndex | msg=Database Operation Successful (createIndex: { location.coords: "2dsphere" })
time=Monday 24 Jun 09:32:18 2019.095Z | lvl=INFO | corr=N/A | trans=N/A | from=N/A | srv=N/A | subsrv=N/A | comp=Orion | op=connectionOperations.cpp[597]:collectionCreateIndex | msg=Database Operation Successful (createIndex: { expDate: 1 })
time=Monday 24 Jun 09:32:18 2019.116Z | 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=Monday 24 Jun 09:32:18 2019.135Z | 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

You'd notice the same timestap; that is because I've just used the same line from the log for conveninece. What I want to point out is the initialization phases as they appear in the logs.

So, judging from the logs, it seems that the point at which the initialization gets stuck is at Database Operation Successful (createIndex: { location.coords: "2dsphere" }). Somehow this operations isn't run successfully at time.

PS: Just after seeing your post did I realize that I can use text formatting inside the message here. The initial one is really rough on the eyes...will try to edit it.