I have a database where a couple of clients perform querys with a fairly rapid response, however sometimes the querys take EXTREMLY long time to execute, and I wonder why.
Do you have any pointers for me on where to look, what to do?
In this excercept from the log you'll see that the first query in the log was executed with a normal response time, however, when the same query is made later (at about 00.28.03 by Mediacollection) it times out. At around 00.28.03 there is also another query made by another machine(VentuzTV4A), and its response time ends up just below 10s.
To me it seems the queryprocessor is not queuing up the querys in a good fashion, or do any of you have another view of the problem?
Best regards,
Sam
Log below: -----------------------------------------------------------------------
00:18:01.388 0:0:0:0:0:0:0:1:58557 MediaCollection REQUEST OPEN tv4 0.27 ms 00:18:01.388 0:0:0:0:0:0:0:1:58557 MediaCollection OK Database 'tv4' was opened in 0.05 ms. 0.4 ms 00:18:01.388 0:0:0:0:0:0:0:1:58557 MediaCollection REQUEST XQUERY (//EVENT[@IDdeko="106139482"]) [last()] 0.19 ms 00:18:01.575 0:0:0:0:0:0:0:1:58557 MediaCollection OK Query executed in 191.63 ms. 192.0 ms 00:18:01.575 0:0:0:0:0:0:0:1:58557 MediaCollection REQUEST EXIT 0.15 ms 00:18:01.575 0:0:0:0:0:0:0:1:58557 MediaCollection OK 0.36 ms
00:27:41.538 0:0:0:0:0:0:0:1:58625 MediaCollection OK Database 'tv4' was opened in 0.05 ms. 0.41 ms 00:27:41.538 0:0:0:0:0:0:0:1:58625 MediaCollection REQUEST XQUERY (//EVENT[@IDdeko="106139699"]) [last()] 0.19 ms 00:27:41.725 0:0:0:0:0:0:0:1:58625 MediaCollection OK Query executed in 193.58 ms. 193.94 ms 00:27:41.725 0:0:0:0:0:0:0:1:58625 MediaCollection REQUEST EXIT 0.15 ms 00:27:41.725 0:0:0:0:0:0:0:1:58625 MediaCollection OK 0.33 ms 00:27:49.026 0:0:0:0:0:0:0:1:58626 MediaCollection REQUEST OPEN tv4 0.29 ms 00:27:49.026 0:0:0:0:0:0:0:1:58626 MediaCollection OK Database 'tv4' was opened in 0.06 ms. 0.45 ms 00:27:49.026 0:0:0:0:0:0:0:1:58626 MediaCollection REQUEST XQUERY (//EVENT[@IDdeko="106139480"]) [last()] 0.22 ms 00:27:49.213 0:0:0:0:0:0:0:1:58626 MediaCollection OK Query executed in 188.08 ms. 188.45 ms 00:27:49.213 0:0:0:0:0:0:0:1:58626 MediaCollection REQUEST EXIT 0.38 ms 00:27:49.213 0:0:0:0:0:0:0:1:58626 MediaCollection OK 4.13 ms 00:28:03.721 10.0.29.134:55434 VentuzTV4A REQUEST OPEN tv4 203.11 ms 00:28:03.721 10.0.29.134:55434 VentuzTV4A OK Database 'tv4' was opened in 0.06 ms. 0.4 ms 00:28:03.861 0:0:0:0:0:0:0:1:58627 MediaCollection REQUEST OPEN tv4 0.23 ms 00:28:03.861 0:0:0:0:0:0:0:1:58627 MediaCollection OK Database 'tv4' was opened in 0.04 ms. 0.36 ms 00:28:03.861 0:0:0:0:0:0:0:1:58627 MediaCollection REQUEST XQUERY (//EVENT[@IDdeko="106139482"]) [last()] 0.19 ms 00:28:03.924 10.0.29.134:55434 VentuzTV4A REQUEST XQUERY (/DEKOEVENTS/EVENT[@IDdeko="106139846"]) [last()] 202.22 ms 00:28:13.876 0:0:0:0:0:0:0:1:58627 MediaCollection ERROR Timeout exceeded. 10008.52 ms 00:28:13.892 10.0.29.134:55434 VentuzTV4A OK Query executed in 9975.78 ms. 9976.17 ms 00:28:13.892 10.0.29.134:55434 VentuzTV4A REQUEST EXIT 0.14 ms 00:28:13.892 10.0.29.134:55434 VentuzTV4A OK 0.26 ms 00:28:14.922 0:0:0:0:0:0:0:1:58628 MediaCollection REQUEST OPEN tv4 0.23 ms 00:28:14.922 0:0:0:0:0:0:0:1:58628 MediaCollection OK Database 'tv4' was opened in 0.05 ms. 0.39 ms 00:28:14.922 0:0:0:0:0:0:0:1:58628 MediaCollection REQUEST XQUERY (//EVENT[@IDdeko="106139840"]) [last()] 0.19 ms 00:28:15.093 0:0:0:0:0:0:0:1:58628 MediaCollection OK Query executed in 171.06 ms. 171.41 ms 00:28:15.093 0:0:0:0:0:0:0:1:58628 MediaCollection REQUEST EXIT 0.14 ms 00:28:15.093 0:0:0:0:0:0:0:1:58628 MediaCollection OK 0.4 ms 00:28:22.332 0:0:0:0:0:0:0:1:58629 MediaCollection REQUEST OPEN tv4 0.27 ms 00:28:22.332 0:0:0:0:0:0:0:1:58629 MediaCollection OK Database 'tv4' was opened in 0.05 ms. 0.4 ms 00:28:22.332 0:0:0:0:0:0:0:1:58629 MediaCollection REQUEST XQUERY (//EVENT[@IDdeko="106139698"]) [last()] 0.19 ms