[Backlogmanager] [FIWARE-JIRA] (HELP-21647) [fiware-stackoverflow] Differences in query logs when read by STH-Comet caused by Cygnus version upgrade

[Fernando Lopez (JIRA)]

     [ https://jira.fiware.org/browse/HELP-21647?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Fernando Lopez reassigned HELP-21647:
-------------------------------------

    Assignee: Miguel Ángel Pedraza

> [fiware-stackoverflow] Differences in query logs when read by STH-Comet caused by Cygnus version upgrade
> --------------------------------------------------------------------------------------------------------
>
>                 Key: HELP-21647
>                 URL: https://jira.fiware.org/browse/HELP-21647
>             Project: Help-Desk
>          Issue Type: Monitor
>          Components: FIWARE-TECH-HELP
>            Reporter: Backlog Manager
>            Assignee: Miguel Ángel Pedraza
>              Labels: fiware, fiware-cygnus, fiware-sth-comet, mongodb
>
> Created question in FIWARE Q/A platform on 28-06-2023 at 05:06
> {color: red}Please, ANSWER this question AT{color} https://stackoverflow.com/questions/76570277/differences-in-query-logs-when-read-by-sth-comet-caused-by-cygnus-version-upgrad
> +Question:+
> Differences in query logs when read by STH-Comet caused by Cygnus version upgrade
> +Description:+
> I am investigating Cygnus and STH-Comet and would like to know the impact of the Cygnus version upgrade.
> I have created an environment with the following docker-compose.yml.
> And, I have switched the Cygnus version in the commented out section to investigate.
> docker-compose.yml:
> version: "3"
> services:
>   orion:
>     container_name: orion
>     image: fiware/orion:3.7.0
>     links:
>       - mongo
>     ports:
>       - "1026:1026"
>     command: -dbhost mongo -logLevel DEBUG
>   cygnus:
>     container_name: cygnus
>     image: fiware/cygnus-ngsi:2.20.0
>     # image: fiware/cygnus-ngsi:3.2.0
>     links:
>       - mongo
>     ports:
>       - "5051:5051"
>       - "5080:5080"
>     environment:
>       - CYGNUS_MONGO_HOSTS=mongo:27017
>       - CYGNUS_API_PORT=5080
>       - CYGNUS_MONGO_DATA_MODEL=dm-by-service-path
>       - CYGNUS_STH_DATA_MODEL=dm-by-service-path
>   sth:
>     container_name: sth
>     image: fiware/sth-comet:2.10.0
>     depends_on:
>       - "mongo"
>     links:
>       - mongo
>     ports:
>       - "8666:8666"
>     environment:
>       - STH_HOST=0.0.0.0
>       - DB_URI=mongo:27017
>       - DATA_MODEL=collection-per-service-path
>   mongo:
>     container_name: mongo
>     image: mongo:4.4
>     ports:
>       - "27017:27017"
>     command: --logpath=/var/log/mongodb/mongo.log --profile=1 --slowms=-1
> I have created the following entities and also the following subscription.
> entity:
> {
>     "id": "Car1",
>     "type": "Car",
>     "speed": {
>         "type": "Float",
>         "value": 80,
>         "metadata": {}
>     }
> }
> subscription:
> {
>   "description": "Test",
>   "subject": {
>     "entities": [
>       {
>         "idPattern": "Car1$",
>         "type": "Car"
>       }
>     ]
>   },
>   "notification": {
>     "http": {
>       "url": "http://cygnus:5051/notify"
>     },
>     "attrsFormat": "legacy"
>   },
>   "expires": "2040-01-01T14:00:00.000Z"
> }
> After creating the above subscription, I will update the entity several times to create historical data.
> I ran the following command to get the historical data.
> curl "localhost:8666/STH/v2/entities/Car1/attrs/speed?type=Car&lastN=5" -H 'fiware-service:example' -H 'fiware-servicepath:/'
> The following query logs are mongodb logs when I read the historical data by STH-Comet.
> // Log of STH-Comet query to get data written by Cygnus 2.20.0
> {"t":{"$date":"2023-06-28T03:54:01.910+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn11","msg":"Slow query","attr":{"type":"command","ns":"sth_example.$cmd","command":{"listCollections":1,"filter":{"name":"sth_/"},"cursor":{},"nameOnly":true,"lsid":{"id":{"$uuid":"a7f6f881-1db3-42f0-86b6-c14fc3425419"}},"$db":"sth_example"},"numYields":0,"reslen":166,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"r":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"r":1}},"Database":{"acquireCount":{"r":1}},"Collection":{"acquireCount":{"r":2}},"Mutex":{"acquireCount":{"r":1}}},"protocol":"op_msg","durationMillis":0}}
> {"t":{"$date":"2023-06-28T03:54:01.916+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn11","msg":"Slow query","attr":{"type":"command","ns":"sth_example.sth_/","command":{"count":"sth_/","query":{"entityId":"Car1","entityType":"Car","attrName":"speed"},"skip":0,"limit":0,"$db":"sth_example"},"planSummary":"COUNT_SCAN { entityId: 1, entityType: 1, attrName: 1, recvTime: 1 }","keysExamined":3,"docsExamined":0,"numYields":0,"queryHash":"41C2776D","planCacheKey":"2D54FA2D","reslen":45,"locks":{"FeatureCompatibilityVersion":{"acquireCount":{"r":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"r":1}},"Database":{"acquireCount":{"r":1}},"Collection":{"acquireCount":{"r":1}},"Mutex":{"acquireCount":{"r":1}}},"storage":{},"protocol":"op_msg","durationMillis":0}}
> {"t":{"$date":"2023-06-28T03:54:01.920+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn11","msg":"Slow query","attr":{"type":"command","ns":"sth_example.sth_/","command":{"find":"sth_/","filter":{"entityId":"Car1","entityType":"Car","attrName":"speed"},"sort":{"recvTime":-1},"limit":5,"returnKey":false,"showRecordId":false,"lsid":{"id":{"$uuid":"a7f6f881-1db3-42f0-86b6-c14fc3425419"}},"$db":"sth_example"},"planSummary":"IXSCAN { entityId: 1, entityType: 1, attrName: 1, recvTime: 1 }","keysExamined":2,"docsExamined":2,"cursorExhausted":true,"numYields":0,"nreturned":2,"queryHash":"C0A2C615","planCacheKey":"26B66C8B","reslen":380,"locks":{"FeatureCompatibilityVersion":{"acquireCount":{"r":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"r":1}},"Database":{"acquireCount":{"r":1}},"Collection":{"acquireCount":{"r":1}},"Mutex":{"acquireCount":{"r":1}}},"storage":{},"protocol":"op_msg","durationMillis":0}}
> // Log of STH-Comet query to get data written by Cygnus 3.2.0
> {"t":{"$date":"2023-06-28T03:43:44.631+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn11","msg":"Slow query","attr":{"type":"command","ns":"sth_example.$cmd","command":{"listCollections":1,"filter":{"name":"sth_/"},"cursor":{},"nameOnly":true,"lsid":{"id":{"$uuid":"8dde283d-302e-4374-aa83-a3c78a19080c"}},"$db":"sth_example"},"numYields":0,"reslen":166,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"r":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"r":1}},"Database":{"acquireCount":{"r":1}},"Collection":{"acquireCount":{"r":2}},"Mutex":{"acquireCount":{"r":1}}},"protocol":"op_msg","durationMillis":0}}
> {"t":{"$date":"2023-06-28T03:43:44.634+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn11","msg":"Slow query","attr":{"type":"command","ns":"sth_example.sth_/","command":{"count":"sth_/","query":{"entityId":"Car1","entityType":"Car","attrName":"speed"},"skip":0,"limit":0,"$db":"sth_example"},"planSummary":"COLLSCAN","keysExamined":0,"docsExamined":2,"numYields":0,"queryHash":"41C2776D","planCacheKey":"2D54FA2D","reslen":45,"locks":{"FeatureCompatibilityVersion":{"acquireCount":{"r":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"r":1}},"Database":{"acquireCount":{"r":1}},"Collection":{"acquireCount":{"r":1}},"Mutex":{"acquireCount":{"r":1}}},"storage":{},"protocol":"op_msg","durationMillis":0}}
> {"t":{"$date":"2023-06-28T03:43:44.636+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn11","msg":"Slow query","attr":{"type":"command","ns":"sth_example.sth_/","command":{"find":"sth_/","filter":{"entityId":"Car1","entityType":"Car","attrName":"speed"},"sort":{"recvTime":-1},"limit":5,"returnKey":false,"showRecordId":false,"lsid":{"id":{"$uuid":"8dde283d-302e-4374-aa83-a3c78a19080c"}},"$db":"sth_example"},"planSummary":"IXSCAN { recvTime: 1, entityId: 1, entityType: 1, attrName: 1, attrType: 1, attrValue: 1 }","keysExamined":2,"docsExamined":2,"cursorExhausted":true,"numYields":0,"nreturned":2,"queryHash":"C0A2C615","planCacheKey":"26B66C8B","reslen":380,"locks":{"FeatureCompatibilityVersion":{"acquireCount":{"r":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"r":1}},"Database":{"acquireCount":{"r":1}},"Collection":{"acquireCount":{"r":1}},"Mutex":{"acquireCount":{"r":1}}},"storage":{},"protocol":"op_msg","durationMillis":0}}
> When I run the following code in STH-Comet, the "planSummary" goes from "COUNT_SCAN" to "COLLSCAN".
> https://github.com/telefonicaid/fiware-sth-comet/blob/2.10.0/lib/database/sthDatabase.js#L510-L523
> The more historical data, the slower that query becomes, is this a bug or am I misconfigured?
> Thank you in advance.



--
This message was sent by Atlassian JIRA
(v6.4.1#64016)