Overview
This article will explain basics to understand how search can be observed in IDOL side logs. That will help troubleshooting unexpected search behavior.
Basics
When considering search in IDOL, its log can be found from DAH (orchestrating searches from the cluster) and each engine (Daily and all backend engines). Usually, we only need to look at DAH's action.log. In individual engines there are query.log that gives the same information, but for the corresponding engine. That said, let's concentrate on DAH's action.log.
There are two different actions that are meaningful:
ACTION=QUERY
and
ACTION=GETQUERYTAGVALUES
The first one is for the actual result listing and the second one is for the numeric data e.g. how many results we have.
Another piece of information in the log that is important is so called thread, a number between square brackets e.g. [2]. That means a specific action. That is because the log lines of different actions overlap with each other.
Basic structure and example
Then, let's move to the actual, simplest example. We will do a quick search proposal. There are no facets or any other advanced terms in our search. The action.log will look like this:
19/03/2025 15:01:08 [3] 00-Always: ACTION=QUERY&DatabaseMatch=v%2Dc47c1d25%2D4b7b%2D40c4%2D94d9%2D06a59141124a%2D20241017%2Dyp05&LanguageType=germanUTF8&AnyLanguage=true&MaxResults=30&TimeoutMS=15000&AbsWeight=false&Combine=DREREFERENCE&Print=Fields&PrintFields=MFSCORE%2BMFOBJDATAJSON%2BMFREPOSITORYPATHJSON&Text=%28%28%28%28%28PROPOSAL%29%29%29%29%3ADRETITLE%2A%3AMFMETA%5F%2A%3AMFFILE%5F%2A%29%20AND%20%28%28%200MFOT0%20%29%3AMFMETA%5FOT%20AND%20%28%200MFOTN%20%29%3AMFMETA%5FOT%5FFLAGS%20AND%20%28%200MFOTO%20%29%3AMFMETA%5FOT%5FFLAGS%20AND%20%28%20%28%20%220MFCON%22%20%29%3AMFMETA%5FCHECKEDOUT%20OR%20%28%20%220MFCO41%40LPT%2DCHHWNLL02XT%22%20%29%3AMFMETA%5FCHECKEDOUT%20%29%20AND%20%28%20%28%20%220MFCIN%22%20%29%3AMFMETA%5FCHECKEDIN%20OR%20%28%20NOT%20%28%20%220MFCI41%40LPT%2DCHHWNLL02XT%22%20%29%3AMFMETA%5FCHECKEDIN%20%29%20%29%29&SecurityInfo=ODg6MXwbDqJo5M2PvGE0RmJBSCE3T7Ba1xFkqf%2F47H5740MYZVdLb7UipXdEO9S7ZJNb29jPs%2Fw2rSp4DzQNH%2ByWokNhF9UC9ZufJwu9G%2FdGUJ0pcXnDj7BQysr9 (127.0.0.1)
19/03/2025 15:01:08 [3] 00-Always: Generated ActionId 6d859b1f236932843e4507005c70adc04d715232
19/03/2025 15:01:08 [3] 30-Normal: Engine 0 returned 0 results in 0.001748 seconds.
19/03/2025 15:01:08 [3] 30-Normal: Engine 1 returned 21 results in 0.007122 seconds.
19/03/2025 15:01:08 [3] 30-Normal: Engine 2 returned 25 results in 0.007542 seconds.
19/03/2025 15:01:08 [3] 30-Normal: Completed Action, returning 30 hits
19/03/2025 15:01:08 [3] 30-Normal: Request completed in 10 ms.
19/03/2025 15:01:08 [1] 00-Always: Request from 127.0.0.1
19/03/2025 15:01:08 [1] 00-Always: ACTION=GETQUERYTAGVALUES&DatabaseMatch=v%2Dc47c1d25%2D4b7b%2D40c4%2D94d9%2D06a59141124a%2D20241017%2Dyp05&LanguageType=germanUTF8&AnyLanguage=true&DocumentCount=true&TimeoutMS=15000&Text=%28%28%28%28%28PROPOSAL%29%29%29%29%3ADRETITLE%2A%3AMFMETA%5F%2A%3AMFFILE%5F%2A%29%20AND%20%28%28%200MFOTN%20%29%3AMFMETA%5FOT%5FFLAGS%20AND%20%28%200MFOTO%20%29%3AMFMETA%5FOT%5FFLAGS%20AND%20%28%20%28%20%220MFCON%22%20%29%3AMFMETA%5FCHECKEDOUT%20OR%20%28%20%220MFCO41%40LPT%2DCHHWNLL02XT%22%20%29%3AMFMETA%5FCHECKEDOUT%20%29%20AND%20%28%20%28%20%220MFCIN%22%20%29%3AMFMETA%5FCHECKEDIN%20OR%20%28%20NOT%20%28%20%220MFCI41%40LPT%2DCHHWNLL02XT%22%20%29%3AMFMETA%5FCHECKEDIN%20%29%20%29%29&FieldName=MFMETA%5FOT&SecurityInfo=ODg6MXwbDqJo5M2PvGE0RmJBSCE3T7Ba1xFkqf%2F47H5740MYZVdLb7UipXdEO9S7ZJNb29jPs%2Fw2rSp4DzQNH%2ByWokNhF9UC9ZufJwu9G%2FdGUJ0pcXnDj7BQysr9 (127.0.0.1)
19/03/2025 15:01:08 [1] 00-Always: Generated ActionId 18dc7b2b717daf1402062e9846808b4c09a809f4
19/03/2025 15:01:08 [1] 30-Normal: Engine 0 returned 1 results in 0.001748 seconds.
19/03/2025 15:01:08 [1] 30-Normal: Engine 1 returned 1 results in 0.003357 seconds.
19/03/2025 15:01:08 [1] 30-Normal: Engine 2 returned 1 results in 0.003502 seconds.
19/03/2025 15:01:08 [1] 30-Normal: Completed Action, returning 1 hits
19/03/2025 15:01:08 [1] 30-Normal: Request completed in 5 ms.
There are two actions and their threads (red). If we remove the parameters after the action, the log seems almost self-explanatory:
19/03/2025 15:01:08 [3] 00-Always: ACTION=QUERY
19/03/2025 15:01:08 [3] 00-Always: Generated ActionId 6d859b1f236932843e4507005c70adc04d715232
19/03/2025 15:01:08 [3] 30-Normal: Engine 0 returned 0 results in 0.001748 seconds.
19/03/2025 15:01:08 [3] 30-Normal: Engine 1 returned 21 results in 0.007122 seconds.
19/03/2025 15:01:08 [3] 30-Normal: Engine 2 returned 25 results in 0.007542 seconds.
19/03/2025 15:01:08 [3] 30-Normal: Completed Action, returning 30 hits
19/03/2025 15:01:08 [3] 30-Normal: Request completed in 10 ms.
19/03/2025 15:01:08 [1] 00-Always: Request from 127.0.0.1
19/03/2025 15:01:08 [1] 00-Always: ACTION=GETQUERYTAGVALUES
19/03/2025 15:01:08 [1] 00-Always: Generated ActionId 18dc7b2b717daf1402062e9846808b4c09a809f4
19/03/2025 15:01:08 [1] 30-Normal: Engine 0 returned 1 results in 0.001748 seconds.
19/03/2025 15:01:08 [1] 30-Normal: Engine 1 returned 1 results in 0.003357 seconds.
19/03/2025 15:01:08 [1] 30-Normal: Engine 2 returned 1 results in 0.003502 seconds.
19/03/2025 15:01:08 [1] 30-Normal: Completed Action, returning 1 hits
19/03/2025 15:01:08 [1] 30-Normal: Request completed in 5 ms.
In the client, we have 30 rows of results from ACTION=QUERY and numeric information, 30 hits from ACTION=GETQUERYTAGVALUES in one field (that's why returning 1 hit).
ACTION and its parameters
The most interesting part though and the one that is usually meaningful for the troubleshooting is the contents of the ACTION row and especially ACTION=QUERY, because that corresponds to the result lines we see. Before we can read it properly, we have to URL decode it e.g. in some web service. Let's look at what the previous ACTION=QUERY looks like after decoding it:
ACTION=QUERY&DatabaseMatch=v-c47c1d25-4b7b-40c4-94d9-06a59141124a-20241017-yp05&LanguageType=germanUTF8&AnyLanguage=true&MaxResults=30&TimeoutMS=15000&AbsWeight=false&Combine=DREREFERENCE&Print=Fields&PrintFields=MFSCORE+MFOBJDATAJSON+MFREPOSITORYPATHJSON&Text=(((((PROPOSAL)))):DRETITLE*:MFMETA_*:MFFILE_*) AND (( 0MFOT0 ):MFMETA_OT AND ( 0MFOTN ):MFMETA_OT_FLAGS AND ( 0MFOTO ):MFMETA_OT_FLAGS AND ( ( "0MFCON" ):MFMETA_CHECKEDOUT OR ( "0MFCO41@LPT-CHHWNLL02XT" ):MFMETA_CHECKEDOUT ) AND ( ( "0MFCIN" ):MFMETA_CHECKEDIN OR ( NOT ( "0MFCI41@LPT-CHHWNLL02XT" ):MFMETA_CHECKEDIN ) ))&SecurityInfo=ODg6MXwbDqJo5M2PvGE0RmJBSCE3T7Ba1xFkqf/47H5740MYZVdLb7UipXdEO9S7ZJNb29jPs/w2rSp4DzQNH+yWokNhF9UC9ZufJwu9G/dGUJ0pcXnDj7BQysr9 (127.0.0.1)
Much clearer, but if we still divide each parameter to its own row:
ACTION=QUERY&
DatabaseMatch=v-c47c1d25-4b7b-40c4-94d9-06a59141124a-20241017-yp05&
LanguageType=germanUTF8&
AnyLanguage=true&
MaxResults=30&
TimeoutMS=15000&
AbsWeight=false&
Combine=DREREFERENCE&
Print=Fields&
PrintFields=MFSCORE+MFOBJDATAJSON+MFREPOSITORYPATHJSON&
Text=(((((PROPOSAL)))):DRETITLE*:MFMETA_*:MFFILE_*) AND (( 0MFOT0 ):MFMETA_OT AND ( 0MFOTN ):MFMETA_OT_FLAGS AND ( 0MFOTO ):MFMETA_OT_FLAGS AND ( ( "0MFCON" ):MFMETA_CHECKEDOUT OR ( "0MFCO41@LPT-CHHWNLL02XT" ):MFMETA_CHECKEDOUT ) AND ( ( "0MFCIN" ):MFMETA_CHECKEDIN OR ( NOT ( "0MFCI41@LPT-CHHWNLL02XT" ):MFMETA_CHECKEDIN ) ))&
SecurityInfo=ODg6MXwbDqJo5M2PvGE0RmJBSCE3T7Ba1xFkqf/47H5740MYZVdLb7UipXdEO9S7ZJNb29jPs/w2rSp4DzQNH+yWokNhF9UC9ZufJwu9G/dGUJ0pcXnDj7BQysr9 (127.0.0.1)
Now this is very readable. The most relevant fields are Text and LanguageType. The latter is quite sef-evident, but let's see what the Text has?
As we can see, this is a kind of Boolean search with AND's, OR's, asterisks and a lot of parentheses. Also, the order of the field and the data is reversed to which we have used to i.e. first the data/text and then the fields we are looking for it from.
Below I have divided the Text parameter and added some explanations.
(((((PROPOSAL)))):DRETITLE*:MFMETA_*:MFFILE_*)
- We are looking word PROPOSAL from any field that start DRETITLE, MFMETA_ and MFFILE_
- This is the most important part for troubleshooting. The latter are quite default.
AND (( 0MFOT0 ):MFMETA_OT
- We are looking for Object Type ID 0 (Document) from field MFMETA_OT
The data after that goes with the same logic. All fields can be found from the index data and index data can be retrieved via MFIDOLConsole command getcontent.
