|
We have some performance troubles with a database of our biggest customer. Foxhound did not report any problems. Usage of CPU(1-15%), Disk and Active requests (mostly around 5, very rare a unschelded task, very very rare a blocked connection). When I open Performance Monitor I see some things that I do not understand: 1. In the tabpage "Statements" I see a slow query that should be very fast, there are 120 rows in the tabel. Strange is that there is a large Idle time. (see below a copy of the screen *1) What does that Idle time mean and how can I prevent that large idle times?
*1)
Execute Statement Properties
============================
General
-------
Operation type: Execute Statement
Date: Today 8:38:39
Execution time: 4,19 sec
Connection: 729443 (WRO)
Statement timing:
Prepare statement < 1 ms
Execute statement < 1 ms
Fetch results < 1 ms
**Idle 4,19 sec**
Blocked 0 ms
Statement handle: 668839
Cursor handle: 79016
SQL
---
select "event_jobs"."nummer","event_jobs"."user","event_jobs"."sql","event_jobs"."status","event_jobs"."omschrijving","event_jobs"."usertxt","event_jobs"."result","event_jobs"."start","event_jobs"."stop","event_jobs"."scheduled_for","event_jobs"."window","event_jobs"."id",cast(cast("datediff"("second","start","stop") as integer)/60 as integer) as "minuten",cast("datediff"("second","start","stop") as integer)-(cast(cast("datediff"("second","start","stop") as integer)/60 as integer))*60 as "seconden" from "event_jobs" where("event_jobs"."status" <= 3) and("event_jobs"."user" = 160)
Plan
----
event_jobs<seq>{4}
Stored SQL
----------
This operation did not run any stored SQL.
Blocking
--------
This operation did not block.
Connection
----------
Connected: Before profiling started
Disconnected: Still connected
max_temp_space: 0
max_priority: normal
timestamp_format: yyyy-mm-dd hh:nn:ss.ssssss
preserve_source_format: On
optimization_workload: Mixed
time_zone:
optimization_goal: First-row
post_login_procedure: dbo.sa_post_login_procedure
debug_messages: Off
st_geometry_on_invalid: Error
AppInfo: IP=192.168.87.34;HOST=TSNW02;OSUSER=wessel;OS='Windows 2012R2 Build 9200 ';EXE='C:\Program Files (x86)\TSD\WinTreeClient\bin\wintree.exe';PID=0x1001c;THREAD=0xae6c;VERSION=17.0.10.6057;API=ODBC;TIMEZONEADJUSTMENT=120
max_plans_cached: 20
string_rtruncation: Off
update_statistics: On
subsume_row_locks: On
global_database_id: 2147483647
extended_join_syntax: On
first_day_of_week: 7
login_procedure: DBA.login_check
checkpoint_time: 60
ansi_permissions: On
timestamp_with_time_zone_format: yyyy-mm-dd hh:nn:ss.ssssss +hh:nn
http_session_timeout: 30
conn_auditing: On
request_timeout: 0
cooperative_commit_timeout: 250
synchronize_mirror_on_commit: Off
st_geometry_asbinary_format: WKB
TimeZoneAdjustment: 120
date_order: YMD
min_role_admins: 1
prevent_article_pkey_update: On
max_query_tasks: 1
remote_idle_timeout: 15
audit_log:
blocking: On
max_recursive_iterations: 100
st_geometry_astext_format: WKT
oem_string:
user_estimates: Override-magic
SessionTimeout: 0
ansi_close_cursors_on_rollback: Off
db_publisher: -1
http_connection_pool_timeout: 60
integrated_server_name:
sql_flagger_error_level: Off
continue_after_raiserror: Off
webservice_sessionid_name: SessionID
return_date_time_as_string: Off
java_location:
st_geometry_interpolation: relative-tolerance-percent=.3
pinned_cursor_percent_of_cache: 10
UserID: WRO
fire_triggers: On
precision: 30
st_geometry_describe_type: char
cooperative_commits: On
materialized_view_optimization: Stale
conversion_error: On
disk_sandbox: Off
tsql_variables: Off
for_xml_null_treatment: Omit
progress_messages: Off
updatable_statement_isolation: 0
verify_password_function:
ansi_blanks: Off
isolation_level: 0
sort_collation: Internal
date_format: yyyy-mm-dd
divide_by_zero_error: On
on_charset_conversion_failure: Ignore
ansi_update_constraints: Off
auditing: Off
optimization_level: 9
max_statement_count: 50
row_counts: Off
max_client_statements_cached: 10
Database: bootenco
priority: normal
close_on_endtrans: On
st_geometry_asxml_format: GML
chained: On
odbc_distinguish_char_and_varchar: Off
allow_write_client_file: Off
blocking_timeout: 0
allow_read_client_file: Off
suppress_tds_debugging: Off
cis_option: 0
query_mem_timeout: -1
delayed_commits: Off
time_zone_adjustment: 120
truncate_timestamp_values: Off
default_dbspace:
delayed_commit_timeout: 500
nearest_century: 0
uuid_has_hyphens: On
tsql_outer_joins: Off
collect_statistics_on_dml_updates: On
non_keywords:
recovery_time: 2
rollback_on_deadlock: On
tds_empty_string_is_null: Off
auto_commit_on_create_local_temp_index: Off
java_class_path:
http_connection_pool_basesize: 10
read_past_deleted: On
time_format: hh:nn:ss
Name: WINTREE-11#1
wait_for_commit: Off
reserved_keywords:
allow_snapshot_isolation: Off
scale: 6
dedicated_task: Off
extern_login_credentials: Effective_user
prefetch: Conditional
quoted_identifier: On
log_deadlocks: On
odbc_describe_binary_as_varbinary: Off
max_cursor_count: 50
min_password_length: 0
blocking_others_timeout: 0
default_timestamp_increment: 1
IdleTimeout: 0
ansinull: On
ansi_substring: On
allow_nulls_by_default: On
max_connections: 32766
trusted_certificates_file:
webservice_namespace_host:
HasSecuredFeature: No
java_vm_options:
temp_space_limit_check: On
background_priority: Off
on_tsql_error: Conditional
cis_rowset_size: 50
sql_flagger_warning_level: Off
|
|
Volker is correct to mention optimization_goal First-row; changing that might make all your troubles go away. It is not clear how "execution time" and "idle" are defined for the SQL Anywhere 17 Profiler (dbprof)... Execution time: 4,19 sec **Idle 4,19 sec** ...or why they are strangely the same :) Foxhound 5's definitions are found here: Database-level: Executing, Idle, Waiting Conns https://www.risingroad.com/foxhound-5-0/foxhound5_help/foxhound_history.html#multi_Executing Connection-level: Waiting Time, Busy, Wait, Idle https://www.risingroad.com/foxhound-5-0/foxhound5_help/foxhound_history.html#conn_waiting In particular, connection "idle time" is not the same as "waiting", it's the part left over after "busy" and "waiting"... total_time = time since LoginTime busy_time = ReqTimeActive - ReqTimeBlockIO - ReqTimeBlockContention - ReqTimeBlockLock wait_time = ReqTimeUnscheduled + ReqTimeBlockIO + ReqTimeBlockContention + ReqTimeBlockLock idle_time = total_time - busy_time - wait_time ...I'd love to look at your foxhound5.db file :) About those funky ReqCountActive and ReqCountUnscheduled numbers: From time to time, over the years, various SQL Anywhere properties have returned wildly invalid values. These problems come and go, and they don't cause much grief (to me) any more because Foxhound now checks everything for reasonableness and ignores the outliers; i.e., treats them as zero. |
|
maybe it needed to wait for a checkpoint or file grow to finish? |
|
The optimization setting I wille check. Thx. It looks there is some settings wrong. I have installed Foxhoud a couple of weeks ago. That showed no really problems. The customer does have a new very fast server with 113G memory, the chache is 35G (initial set) and is never increased. (the server was replaced by a new one recently to solve the perfomance problem, helping a little) The CPU is most of the time around 2% to 5%. In taskmanager nothing wrong to see. Low CPU, harddisk and network. But when the users are very busy the server is sometimes unreachable or very slow. Even a 'select * from dummy' can take seconds (seen a few times) When I look with sa_performance_diagonistics() I see that for all connections the ReqCountActive and ReqCountUnschedulded are the same. The highest values are 492.552 for ReqCountUnscheduld and 492.553 for RegCountActive. That looks not OK to me..? The appliaction is old and calls a lot of heavy queries with a lot of nested selects. We will a look at that of course. But it seems that only a small part of the server capacity is used. How is that possible? What setting can cause this strange behavior? (max_query_task is set to 1) Any clues..? Two questions: 1 This is a physical server, isn't it? (ie not a VM) 2 Do you have any back-up software running that uses MS Shadow Copy? If so do you have the SQL Anywhere Volume Shadow Copy Service installed and running?
(06 May '21, 05:13)
Justin Willey
We experience exactly the same. The overall performance after unload/reload from SA16 to SA17 has decreased by a lot. Some queries that is super fast in SA16 takes "for over" in SA17, with high Idle time and the feeling that the applications hangs much more than before. Can something be done to tweak the optimizer? Server is started without any switches or restrictions in cache size. Currently the database uses 15 GB of RAM on a VMWare server (Windows 2019 Server) with a total of 32 GB. CPU at 30%, only using one logical core out of a total of 4 (which is very annoying). But I guess that's limited by the license? Bjarne
(18 May '21, 14:41)
Bjarne Anker
Replies hidden
There do seem to be a lot of complaints about V17 performance lately, not just in this forum. My theory is this: changes to the query engine had the unintended consequence of releasing "Queries From Hell" from the bondage of "Lucky Happenstance Plans" chosen by previous versions. Where do you see "high Idle time" and why do you care about how much time the server doesn't have any work to do? (see my reply to HansTSD on the subject of "busy versus wait versus idle") What other changes did you make at the same time as upgrading?
That might be one of the "other changes"... it could very well be the reason for bad performance... don't settle for being annoyed, investigate the facts :) Seriously, run Foxhound for a couple of days, send me the foxhound5.db file and get the free hour of performance and tuning consultation described here https://www.risingroad.com/foxhound-5-0/foxhound5_help/foxhound_introduction.html#support Questions specific to how Foxhound works are always free, forever.
(18 May '21, 15:52)
Breck Carter
The first thing to do with Foxhound is click on "Display Schema" (not Monitor Database), and then click on "Options" in the menu, and see if there are any "Options with non-default values" and post them here. There is one default you might WANT to change
if you are running a multi-user transactional update workload, rather than a heavyweight BI query load... intra-query parallelism has been know to kill clerical response time. See http://sqlanywhere.blogspot.com/2011/08/new-maxbps768-set-maxquerytasks-1.html
(18 May '21, 16:05)
Breck Carter
Further to my unproven theory, bad choices may matter a lot more with V17 than earlier versions; e.g., optimization_goal = First-row and max_query_tasks = unlimited.
(18 May '21, 16:10)
Breck Carter
|
I have no clue, and Martins' suggestions seem reasonable, and with isolation level 0 it can't be blocked by other connections unless exclusive access was given to another transaction.
Is that query part of a longer transaction or does it run on its own (i.e. does the connection a commit right before and after that query)?
Is there a particular reason you are using "optimization_goal: First-row" instead of teh default "All-rows"?