ניטור ביצועים של שאילתות

8 במרץ 2015

תגיות: , , ,
אין תגובות

אחת המשימות הנפוצות של כל DBA היא ניטור (Monitoring). זאת לא סתם משימה, זאת אסטרטגיה שלמה. DBA טוב צריך לתכנן את אסטרטגיית הניטור שלו ולהוציא אותה לפועל. אבל אני לא כאן בשביל לדבר על ניטור באופן כללי. אני רוצה לדבר על אחד מתחומי הניטור הכי נפוצים – ביצועים של שאילתות.

הסיבה שניטור ביצועים של שאילתות הוא פעולה כל-כך נפוצה היא שבדרך כלל המשתמשים מתלוננים על כך. זה יכול להיות דו"ח מסוים שלוקח לו יותר מדי זמן לסיים או מסך מסוים באפליקציה שלוקח לו הרבה זמן לעלות. בסופו של דבר יש שאילתה כלשהי שלא עובדת טוב. צריך למצוא אותה, להבין מה לא בסדר, ולפתור את הבעיה.

אז אני כאן כדי לדבר על החלק של מציאת השאילתות הבעייתיות. יש הרבה דרכים לעשות זאת, והן נבדלות זו מזו ברמת היעילות וברמת המורכבות שלהן. אחת מהסיטואציות שאני נתקל בה הרבה אצל לקוחות היא כשהלקוח מתלונן על בעיית ביצועים כלשהי שקרתה בעבר. ללקוח אין אסטרטגיית ניטור, ואין שום תהליך שאוסף נתונים על ביצועים של שאילתות. במצב כזה, אם הבעיה לא משתחזרת, אז אין לנו באמת דרך לדעת מה קרה. ואם הבעיה כן משתחזרת, אז צריך להקים תהליך שיתחיל לאסוף נתונים, ולחכות מספיק זמן כדי לאסוף את הנתונים הרלוונטיים על מנת לנתח את הבעיה בצורה יעילה.

למזלנו, SQL Server אוסף בעצמו סטטיסטיקות של ביצועי שאילתות, ואנחנו יכולים לגשת למידע באמצעות DMV – sys.dm_exec_query_stats. ה-View הזה מציג מידע סטטיסטי על תוכניות ביצוע (Execution Plans) שנמצאות כרגע ב-Plan Cache. הוא אוסף נתונים מהאתחול האחרון של ה-Instance, אבל רק כל עוד תוכנית הביצוע נמצאת ב-Cache. באמצעות ה-DMV הזה אפשר להתחיל מיד לנתח את הביצועים של שאילתה מסוימת, גם אם היתה בעיה בעבר, ולא צריך לחכות עד שנאסוף מספיק נתונים. ואפשר לעשות את זה באמצעות כתיבת שאילתות פשוטות. לא צריך לעבוד עם תוכנות חיצוניות או לבצע משימות מורכבות.

להלן פירוט של כמה מהעמודות ב-DMV הזה:

שם העמודה

Description

sql_handle

זהו מצביע לטקסט של ה-Batch

statement_start_offset

המרחק ב-Bytes מתחילת ה-Batch לתחילת השאילתה

statement_end_offset

המרחק ב-Bytes מתחילת ה-Batch לסוף השאילתה

plan_generation_num

מספר הפעמים שתוכנית הביצוע עברה קומפילציה מאז שנכנסה לראשונה ל-Cache

plan_handle

זהו מצביע לתוכנית הביצוע ב-Cache

creation_time

הזמן שבו תוכנית הביצוע עברה קומפילציה בפעם האחרונה

last_execution_time

הזמן שבו השאילתה התחילה לרוץ בפעם האחרונה

execution_count

מספר הפעמים שתוכנית הביצוע רצה מאז הקומפילציה האחרונה (creation_time)

כל שאר העמודות מייצגות מידע כמותי סטטיסטי לגבי הביצוע של השאילתות. יש 7 תחומים שאפשר לנטר באמצעות ה-View הזה:

1. Worker Time – זמן CPU (מדווח במיקרו-שניות)

2. Physical Reads – מספר הדפים שנקראו מהדיסק

3. Logical Writes – מספר הדפים שנכתבו ב-Buffer Pool

4. Logical Reads – מספר הדפים שנקראו מה-Buffer Pool

5. CLR Time – זמן CPU שנצרך ע"י CLR (מדווח במיקרו-שניות)

6. Elapsed Time – זמן כולל (מדווח במיקרו-שניות)

7. Rows – מספר השורות שהשאילתה החזירה

עבור כל תחום אפשר לתשאל 4 ערכים שונים: סה"כ, אחרון, מינימום ומקסימום. לדוגמא, אפשר לקבל את זמן ה-CPU הכולל שנצרך או את מספר ה-Logical Reads המקסימלי עבור שאילתה מסוימת. אפשר גם בקלות לחשב ערך ממוצע (למשל, ממוצע של זמן הריצה הכולל) ע"י חלוקה של הסה"כ במספר ההרצות (execution_count).

image

יש כמה דברים חשובים שצריך לדעת לגבי ה-View הזה…

Batch לעומת Statement

כל שורה ב-View מייצגת שאילתה או פקודה (Statement) ספציפית בתוך Batch. אם Batch מסוים מכיל מספר שאילתות, אז ה-View יכלול מספר שורות – אחת לכל שאילתה. כל העמודות המתוארות בטבלה לעיל מתארות את כל ה-Batch, חוץ מ-"statement_start_offset", "statement_end_offset" ו-"last_execution_time", ולכן הערכים בעמודות האלה יחזרו על עצמם בכל השורות שמתייחסות לאותו Batch. כל שאר העמודות (הנתונים הסטטיסטיים) מתייחסות רק לשאילתה הספציפית שמיוצגת ע"י אותה שורה.

אפשר להשתמש בפונקציה sys.dm_exec_sql_text על מנת לקבל את הטקסט של Batch מסוים על סמך ה-"sql_handle" שלו. אפשר גם להשתמש בפונקציה sys.dm_exec_query_plan על מנת לקבל את תוכנית הביצוע בפורמט XML על סמך ה-"plan_handle" שלה. השאילתה הבאה מחזירה את כל תוכניות הביצוע שנמצאות כרגע ב-Cache, כולל הטקסט של כל Batch ותוכנית הביצוע עצמה:

SELECT

    BatchText                = BatchTexts.text ,

    BatchPlan                = BatchPlans.query_plan ,

    CreationDateTime        = QueryStats.creation_time ,

    LastExecutionDateTime    = QueryStats.last_execution_time

FROM

    sys.dm_exec_query_stats AS QueryStats

CROSS APPLY

    sys.dm_exec_sql_text (QueryStats.sql_handle) AS BatchTexts

CROSS APPLY

    sys.dm_exec_query_plan (QueryStats.plan_handle) AS BatchPlans;

אבל זה לא מספיק טוב, כי המידע הסטטיסטי ב-View הזה מתייחס לשאילתה ספציפית, ואנחנו צריכים דרך לקבל את הטקסט ואת תוכנית הביצוע של השאילתה הספציפית, כדי שנדע לאיזה שאילתה מתייחס המידע הסטטיסטי.

את הטקסט של השאילתה אפשר לחשב באמצעות "statement_start_offset" ו-"statement_end_offset". כתבתי פונקציה סקלרית פשוטה, שמקבלת את הערכים של "sql_handle", "statement_start_offset" ו-"statement_end_offset", ומחזירה את הטקסט של השאילתה הרלוונטית:

CREATE FUNCTION

    Execution.udf_s_StatementLevelText

(

    @inSQLHandle            AS VARBINARY(64) ,

    @inStatementStartOffset    AS INT ,

    @inStatementEndOffset    AS INT

)

RETURNS

    NVARCHAR(MAX)

AS

BEGIN

 

    DECLARE @nvcResult AS NVARCHAR(MAX);

 

    SELECT

        @nvcResult = SUBSTRING

                        (

                             ,

                            @inStatementStartOffset / 2 ,

                            (

                                CASE @inStatementEndOffset

                                    WHEN -1 THEN LEN ()

                                    ELSE @inStatementEndOffset / 2

                                END

                                - @inStatementStartOffset / 2

                            )

                            + 1

                        )

    FROM

        sys.dm_exec_sql_text (@inSQLHandle);

 

    RETURN @nvcResult;

 

END;

GO

על מנת לקבל את תוכנית הביצוע של שאילתה ספציפית, אפשר להשתמש בפונקציה sys.dm_exec_text_query_plan, שמקבלת את הערכים של "plan_handle", "statement_start_offset" ו-"statement_end_offset". הפונקציה מחזירה את תוכנית הביצוע של השאילתה הרלוונטית בפורמט טקסטואלי. על מנת לקבל את תוכנית הביצוע בפורמט XML, צריך פשוט להמיר את הערך המוחזר ל-XML.

השאילתה הבאה מחזירה שורה לכל שאילתה, כולל הטקסט ותוכנית הביצוע של השאילתה הספציפית, כמו גם זמן הריצה (Elapsed Time) הממוצע של השאילתה:

SELECT

    StatementText        = Execution.udf_s_StatementLevelText (QueryStats.sql_handle , QueryStats.statement_start_offset , QueryStats.statement_end_offset) ,

    StatementPlan        = CAST (StatementPlans.query_plan AS XML) ,

    AverageElapsedTime    = CAST ((CAST (QueryStats.total_elapsed_time AS DECIMAL(19,2)) / CAST (QueryStats.execution_count AS DECIMAL(19,2))) AS DECIMAL(19,2))

FROM

    sys.dm_exec_query_stats AS QueryStats

CROSS APPLY

    sys.dm_exec_text_query_plan (QueryStats.plan_handle , QueryStats.statement_start_offset , QueryStats.statement_end_offset) AS StatementPlans;

image

זמן הריצה האחרון (Last Execution Time)

העמודה "last_execution_time" מתעדכנת ברגע ששאילתה מתחילה לרוץ. כל שאר העמודות, כמו "execution_count" וכל המידע הסטטיסטי, מתעדכנות ברגע שהשאילתה מסיימת לרוץ בהצלחה. אז אם שאילתה מסוימת נכשלת הרבה פעמים, הערך בעמודה "last_execution_time" יראה שהשאילתה רצה ממש לאחרונה, אבל הערך בעמודה "execution_count" יראה שהשאילתה רצה מעט מאוד פעמים, וכל המידע הסטטיסטי יהיה לא אמין, מכיוון שהוא מתייחס רק לריצות מוצלחות של השאילתה.

מקרה אחד נפוץ (ובעייתי) הוא שאילתה עם זמן ריצה כל-כך גבוה, כך שברוב המקרים היא מקבלת Time Out מהאפליקציה. זאת בדיוק השאילתה שעבורה אנחנו רוצים לנטר מידע סטטיסטי לגבי הריצות שלה. נניח שהשאילתה רצה 5 פעמים בשניה בממוצע. אם נתשאל את ה-View הזה, נראה שזמן הריצה האחרון של השאילתה הוא ממש עכשיו, אבל מספר הריצות (execution_count) לא יהיה אפילו קרוב ל-5 פעמים בשניה. בנוסף, המידע הסטטיסטי יתן לנו תמונה לגבי הביצועים של השאילתה כשהיא מסתיימת בהצלחה, שזה בדיוק ההיפך ממה שאנחנו מחפשים.

במקרה כזה, ה-DMV הזה לא יהיה מאוד שימושי, ועדיף להשתמש בטכניקות ניטור אחרות, כגון: SQL Trace או Extended Events.

image

כמה זמן?

חשוב מאוד לזכור שה-DMV הזה שומר מידע סטטיסטי עבור שאילתה מסוימת כל עוד השאילתה נמצאת ב-Cache. אם השאילתה יוצאת מה-Cache או שהיא עוברת קומפילציה מחדש, אז המידע הסטטיסטי כבר לא זמין. לכן תמיד חשוב לבדוק את הערך של "creation_time", שזה הזמן שבו השאילתה עברה קומפילציה בפעם האחרונה, וזהו גם הזמן שבו המידע הסטטיסטי התחיל להיאסף. בנוסף, כדאי לבדוק את הערך של "execution_count", שמייצג את מספר הריצות של השאילתה מאז הקומפילציה האחרונה.

יש שלוש בעיות עם ה-DMV הזה:

1. אם השאילתה עברה קומפילציה ממש לאחרונה, ומספר הריצות מאז הוא יחסית נמוך, אז המידע הסטטיסטי עלול להיות מטעה ולא אמין. כדי שמידע סטטיסטי יהיה אמין, צריך לצבור מספיק נתונים לאורך זמן…

2. אם היה לנו מידע סטטיסטי אמין ומדויק על שאילתה מסוימת, שנצבר על סמך הרבה ריצות של השאילתה בחודש האחרון, אבל בדיוק עכשיו השאילתה עברה קומפילציה מחדש, כל המידע הזה נעלם בבת אחת, והוא כבר לא זמין יותר.

3. מצד שני, אם תוכנית ביצוע מסוימת נמצאת ב-Cache כבר הרבה מאוד זמן, המידע הסטטיסטי מייצג את הביצועים של השאילתה על פני כל התקופה. אין לנו דרך לקבל מידע סטטיסטי רק על השבוע האחרון, למשל, או רק על טווח תאריכים מסוים בעבר.

על מנת לפתור את הבעיות האלה, אנחנו צריכים לקחת דגימות של ה-DMV הזה כל כמה זמן, ולשמור אותן בטבלה משלנו. כך תהיה לנו היסטוריה של כל המידע הסטטיסטי על שאילתות בשרת, ולא נצטרך לדאוג שנאבד מידע.

ברגע שיש לנו את הדגימות בטבלה משלנו, אשפר לתשאל את הטבלה הזאת על מנת לקבל מידע סטטיסטי בטווח זמן כלשהו. לדוגמא, אם אנחנו לוקחים דגימה כל 5 דקות, ואנחנו שומרים היסטוריה של 10 הימים האחרונים בטבלה, אז אנחנו יכולים לנטר ביצועים של שאילתות בכל טווח זמנים (ברזולוציה של 5 דקות) ב-10 הימים האחרונים. למשל: אתמול בין 09:00 ל-12:00. לשם כך צריך למצוא את הדגימה שנלקחה אתמול ב-09:00, ואת זאת שנלקחה אתמול ב-12:00, ולחשב את ההפרשים בין שתי הדגימות. אם תוכנית ביצוע מסוימת מופיעה בשתי הדגימות, אז צריך לחשב את ההפרש בין שתי הדגימות. אם תוכנית ביצוע מסוימת מופיעה רק בדגימה השניה (12:00), אז צריך לחשב את המידע הסטטיסטי מאז ה-"creation_time", שחייב להיות בין 09:00 ל-12:00. אם תוכנית ביצוע מסוימת מופיעה רק בדגימה הראשונה (09:00), אז זה אומר שהיא יצאה מה-Cache או עברה קומפילציה מחדש בזמן כלשהו בין 09:00 ל-12:00, ואז צריך לנסות טווח זמן קצר יותר על מנת לקבל מידע סטטיסטי על השאילתה הזאת.

אז הכנתי סקריפט שעושה את כל זה. אתם מוזמנים להוריד מכאן.

הסקריפט כולל את הדברים הבאים:

1. הוא יוצר בסיס נתונים חדש בשם "QueryStatistics", שבו נשמור את כל המידע ההיסטורי.

2. הוא יוצר את הסכימה "Execution", שבה ניצור את כל האוביקטים.

3. הוא יוצר את הפונקציה "Execution.udf_s_StatementLevelText", שהוזכרה לעיל. הפונקציה הזאת מחזירה את הטקסט של שאילתה ספציפית מתוך Batch על סמך הערכים של "statement_start_offset" ו-"statement_end_offset".

4. הוא יוצר אוביקט Sequence ושתי טבלאות: "Execution.QueryStatsSnapshots" ו-"Execution.QueryStatsSnapshotsData".

5. הוא יוצר את הפרוצדורה "Execution.usp_TakeQueryStatsSnapshot", שעושה בדיוק מה שהשם שלה אומר.

6. הוא יוצר Job, שמריץ את הפרוצדורה "Execution.usp_TakeQueryStatsSnapshot" פעם ב-10 דקות.

7. הוא יוצר את הפונקציה "Execution.udf_il_GetQueryStatistics", שמחזירה מידע סטטיסטי על ביצועים של שאילתות בטווח זמן מסוים בין שתי דגימות.

8. הוא מדגים שאילתה שמחזירה מידע סטטיסטי מ-24 השעות האחרונות ע"י קריאה לפונקציה "Execution.udf_il_GetQueryStatistics".

את התזמון של ה-Job כדאי לשנות על מנת להתאים אותו לצרכים שלכם. מצד אחד, כדאי לקחת כמה שיותר דגימות על מנת לשפר את הדיוק ואת היכולת לנטר בטווחי זמנים יותר קצרים. מצד שני, כל דגימה כוללת המון מידע ותופסת הרבה מאוד מקום. אחרי קצת ניסיונות והתאמות, כל אחד ימצא את התזמון שמתאים לו.

משהו אחד שלא כלול בסקריפט הוא מחיקה של מידע ישן. צריך ליצור Job נוסף, שתפקידו למחוק מידע ישן מהטבלאות. אחרת, המידע ילך ויגדל כל הזמן, עד שזה כבר יהיה יותר מדי. גם במקרה הזה, צריך לקבל החלטה כמה מידע לשמור, כי מצד אחד אנחנו רוצים לשמור כמה שיותר, אבל מצד שני אנחנו לא רוצים שזה יהיה יותר מדי.

image

זהו! כל מה שנותר לכם לעשות זה להריץ את הסקריפט בשרת שלכם ולהתחיל לנטר ביצועים של שאילתות בדרך הנכונה. בהצלחה!

פוסט זה נכתב על ידי גיא גלנצר, מנכ"ל חברת מדירה, אשר מתמחה במתן פתרונות בתחום פלטפורמת המידע של מיקרוסופט.

גיא הוא גם SQL MVP של מיקרוסופט ומנהל את הפורום האינטרנטי ואת קבוצת המשתמשים בנושא SQL במיקרוסופט.

יש לכם שאלות בנושאי SQL שאתם רוצים לשאול את גיא? כנסו לפורום SQL שלנו בעברית!

הוסף תגובה
facebook linkedin twitter email

כתיבת תגובה

האימייל לא יוצג באתר. שדות החובה מסומנים *