Skip to content

Performance on logbook search

There are sometimes that the search of the logbook takes many seconds.

This issue investigates why and ideally will propose a solution. Example:

Find started at 2022-03-26T05:51:21.296Z and finished at 2022-03-26T05:51:53.250Z

2022-03-26T05:51:21.296Z [debug]: getEvents 
  				 investigationId : undefined
				 instrumentName : id32
				 search : undulators
				 sortBy : _id
				 sortOrder : -1
				 skip : 0
				 limit : 100
				 types : annotation,notification-comment,notification-error,notification-info,notification-debug,notification-commandline
				 format : json
				 username : demariaa/255362
				 fullName : Alejandro DE MARIA
				 isAdministrator : true
				 isInstrumentScientist : true
				 filterInvestigation : false
				 formattedDate : undefined

2022-03-26T05:51:21.296Z [debug]: Starting the search by: undulators 
  				 sort : {"_id":"-1"}
				 find : {"$and":[{"$or":[{"instrumentName":"id32"},{"instrumentName":"ID32"}]},{"$or":[{"type":"annotation"},{"type":"notification","category":"comment"},{"type":"notification","category":"error"},{"type":"notification","category":"info"},{"type":"notification","category":"debug"},{"type":"notification","category":"commandline"}]}]}

2022-03-26T05:51:21.326Z [debug]: Search query 
  				 find : {"$and":[{"$or":[{"instrumentName":"id32"},{"instrumentName":"ID32"}]},{"$or":[{"type":"annotation"},{"type":"notification","category":"comment"},{"type":"notification","category":"error"},{"type":"notification","category":"info"},{"type":"notification","category":"debug"},{"type":"notification","category":"commandline"}]},{"$or":[{"content.text":{}}]}]}

2022-03-26T05:51:21.327Z [debug]: Find clause is: 
  				 find : {"$and":[{"$or":[{"instrumentName":"id32"},{"instrumentName":"ID32"}]},{"$or":[{"type":"annotation"},{"type":"notification","category":"comment"},{"type":"notification","category":"error"},{"type":"notification","category":"info"},{"type":"notification","category":"debug"},{"type":"notification","category":"commandline"}]},{"$or":[{"content.text":{}}]}]}

2022-03-26T05:51:21.327Z [debug]: Find clause is: 
  				 find : {"$and":[{"$or":[{"instrumentName":"id32"},{"instrumentName":"ID32"}]},{"$or":[{"type":"annotation"},{"type":"notification","category":"comment"},{"type":"notification","category":"error"},{"type":"notification","category":"info"},{"type":"notification","category":"debug"},{"type":"notification","category":"commandline"}]}]}

2022-03-26T05:51:22.046Z [debug]: Count 
  				 find : {"$and":[{"$or":[{"instrumentName":"id32"},{"instrumentName":"ID32"}]},{"$or":[{"type":"annotation"},{"type":"notification","category":"comment"},{"type":"notification","category":"error"},{"type":"notification","category":"info"},{"type":"notification","category":"debug"},{"type":"notification","category":"commandline"}]}]}
				 count : 194697

2022-03-26T05:51:22.182Z [debug]: Count 
  				 find : {"$and":[{"$or":[{"instrumentName":"id32"},{"instrumentName":"ID32"}]},{"$or":[{"type":"annotation"},{"type":"notification","category":"comment"},{"type":"notification","category":"error"},{"type":"notification","category":"info"},{"type":"notification","category":"debug"},{"type":"notification","category":"commandline"}]},{"$or":[{"content.text":{}}]}]}
				 count : 25

2022-03-26T05:51:22.221Z [debug]: Count 
  				 find : {"$and":[{"$or":[{"instrumentName":"id32"},{"instrumentName":"ID32"}]},{"$or":[{"type":"annotation"},{"type":"notification","category":"comment"},{"type":"notification","category":"error"},{"type":"notification","category":"info"},{"type":"notification","category":"debug"},{"type":"notification","category":"commandline"}]},{"$or":[{"content.text":{}}]}]}
				 count : 25

2022-03-26T05:51:22.298Z [debug]: Database ops finished time to find:  
  				 time : 970.783902
				 events : 25
				 total : 25
				 find : {"$and":[{"$or":[{"instrumentName":"id32"},{"instrumentName":"ID32"}]},{"$or":[{"type":"annotation"},{"type":"notification","category":"comment"},{"type":"notification","category":"error"},{"type":"notification","category":"info"},{"type":"notification","category":"debug"},{"type":"notification","category":"commandline"}]},{"$or":[{"content.text":{}}]}]}

2022-03-26T05:51:22.298Z [debug]: Final time to find:  
  				 time : 971.111243

2022-03-26T05:51:53.200Z [debug]: Database ops finished time to find:  
  				 time : 871.928034
				 events : 194697
				 total : 194697
				 find : {"$and":[{"$or":[{"instrumentName":"id32"},{"instrumentName":"ID32"}]},{"$or":[{"type":"annotation"},{"type":"notification","category":"comment"},{"type":"notification","category":"error"},{"type":"notification","category":"info"},{"type":"notification","category":"debug"},{"type":"notification","category":"commandline"}]}]}

2022-03-26T05:51:53.250Z [debug]: Final time to find:  
  				 time : 922.157621