Return
-
Title
GetCommands already in progress since… -
Description
GetCommands already in progress since… -
Resolution
Issue
From time to time a modules which are performing export/import operations may log the following:2014-06-13 11:21:57Z|1008| 29| INFO| Get|GetCommands already in progress since [120] seconds. Waiting to finish.
Solution
This indicates a delay or slow-down in getting a response from the Archive Shuttle Core and it’s SQL Server. It is likely that the root cause is an overloaded or underpowered SQL Server.
Another example is shown below:2014-06-13 12:36:46Z|3036| 4| INFO| Get|Querying Core for 10 Commands (Backlog: 0) 2014-06-13 12:37:42Z|3036| 10| INFO| OnPerformanceTimerElapsedImpl|Last minute statistics: Count: [0] | Items/s: [0.00] | kb/s: [0] | ACPU: [92] | MaxCPU: [100] | MinCPU: [54] | TSize: [0 kb] | ASize: [0 kb] | MaxSize: [0 kb] | | MinSize (kb): [0] | ATime: [0 ms] | MaxTime: [0 ms] | MinTime: [0 ms] 2014-06-13 12:37:42Z|3036| 10| INFO| OnPerformanceTimerElapsedImpl|Last minute statistics: Free memory: [1577 MB] | Avg Free Memory: [1633 MB] | Process Memory: [54 MB] | Avg Process Memory: [56 MB] | APCPU: [1 %] | PCPU: [0 %] 2014-06-13 12:37:47Z|3036| 10| INFO| Get|GetCommands already in progress since [62] seconds. Waiting to finish. 2014-06-13 12:38:42Z|3036| 19| INFO| OnPerformanceTimerElapsedImpl|Last minute statistics: Count: [0] | Items/s: [0.00] | kb/s: [0] | ACPU: [95] | MaxCPU: [100] | MinCPU: [67] | TSize: [0 kb] | ASize: [0 kb] | MaxSize: [0 kb] | | MinSize (kb): [0] | ATime: [0 ms] | MaxTime: [0 ms] | MinTime: [0 ms] 2014-06-13 12:38:42Z|3036| 19| INFO| OnPerformanceTimerElapsedImpl|Last minute statistics: Free memory: [1543 MB] | Avg Free Memory: [1562 MB] | Process Memory: [54 MB] | Avg Process Memory: [56 MB] | APCPU: [1 %] | PCPU: [0 %] 2014-06-13 12:38:47Z|3036| 10| INFO| Get|GetCommands already in progress since [122] seconds. Waiting to finish. 2014-06-13 12:39:42Z|3036| 10| INFO| OnPerformanceTimerElapsedImpl|Last minute statistics: Count: [0] | Items/s: [0.00] | kb/s: [0] | ACPU: [95] | MaxCPU: [100] | MinCPU: [71] | TSize: [0 kb] | ASize: [0 kb] | MaxSize: [0 kb] | | MinSize (kb): [0] | ATime: [0 ms] | MaxTime: [0 ms] | MinTime: [0 ms] 2014-06-13 12:39:42Z|3036| 10| INFO| OnPerformanceTimerElapsedImpl|Last minute statistics: Free memory: [1520 MB] | Avg Free Memory: [1531 MB] | Process Memory: [54 MB] | Avg Process Memory: [56 MB] | APCPU: [1 %] | PCPU: [0 %] 2014-06-13 12:39:47Z|3036| 19| INFO| Get|GetCommands already in progress since [182] seconds. Waiting to finish. 2014-06-13 12:40:42Z|3036| 10| INFO| OnPerformanceTimerElapsedImpl|Last minute statistics: Count: [0] | Items/s: [0.00] | kb/s: [0] | ACPU: [55] | MaxCPU: [100] | MinCPU: [41] | TSize: [0 kb] | ASize: [0 kb] | MaxSize: [0 kb] | | MinSize (kb): [0] | ATime: [0 ms] | MaxTime: [0 ms] | MinTime: [0 ms] 2014-06-13 12:40:42Z|3036| 10| INFO| OnPerformanceTimerElapsedImpl|Last minute statistics: Free memory: [1442 MB] | Avg Free Memory: [1518 MB] | Process Memory: [55 MB] | Avg Process Memory: [56 MB] | APCPU: [1 %] | PCPU: [0 %] 2014-06-13 12:40:42Z|3036| 4| INFO| Get| -> Got 2 commands