on 2021 Apr 28 4:16 AM
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.
You must be a registered user to add a comment. If you've already registered, sign in. Otherwise, register and sign in.
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..?
You must be a registered user to add a comment. If you've already registered, sign in. Otherwise, register and sign in.
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
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?
But I guess that's limited by the license?
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.
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
SET OPTION PUBLIC.max_query_tasks = '0';
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
maybe it needed to wait for a checkpoint or file grow to finish?
You must be a registered user to add a comment. If you've already registered, sign in. Otherwise, register and sign in.
User | Count |
---|---|
75 | |
10 | |
10 | |
10 | |
10 | |
9 | |
8 | |
7 | |
5 | |
5 |
You must be a registered user to add a comment. If you've already registered, sign in. Otherwise, register and sign in.