בחלק הקודם של הפוסט הצגתי דיזיין אפשרי לתשתית לוגים– שכולל את RabbitMQ כמערכת ההודעות שלנו, logstash בתפקיד רכיב פירסור הלוגים, ElasticSearch בתפקיד מנוע האינדוקס (ולמעשה מסד הנתונים של כל התשתית) ו- Kibana בתור רכיב הויזואליזציה שיאפשר לנו לדעת מה קורה במערכת. להזכירכם – כך זה נראה:

בפוסט הקודם הראיתי איך מבצעים את שלבי הקמת התשתית:  התקנת ElasticSearch גם על windows וגם על linux וקינפוג של cluster, התקנת RabbitMQ והתקנת וקינפוג logstash. בפוסט הזה נמשיך עם התהליך ונשלים את שתי הקוביות החסרות: service שיאפשר כתיבה ל-log והתקנת וקינפוג Kibana, שיאפשר לנו לצפות בהודעות הלוג שלנו.

Service קליטת ההודעות

בתשתית שאנחנו מקימים – ברורה לנו מה המטרה הסופית. אנחנו רוצים יכולת לראות ולנהל את הלוגים שלנו בצורה נוחה. בפוסט הקודם גם הקמנו את התשתית הדרושה לנו לאכסון ולאחזור המידע, ובהמשך נדבר על הויזואליזציה של זה עבורנו – איך נתחקר את הלוגים.
אבל, שאלה בסיסית היא איך מתבצעת קליטת ההודעות מהאפליקציות השונות שכותבות ללוג – מדובר למעשה על החלק שאני סימנתי בתרשים למעלה בתור ה- “Logging Service”. מטרתו של ה- logging service פשוטה: להיות endpoint שמולו האפליקציות שכותבות ללוג מדברות, לקבל מהם את ההודעה ולכתוב ל- RabbitMQ בפורמט JSON מוסכם.

אפשר לשאול, ובצדק, מה התועלת בסרביס הזה אם דברים יכולים לכתוב את ההודעות ישירות ל- RabbitMQ? יותר מזה – אפשר לקנפג את logstash עצמו כדי שיקרא את הלוג הטקסטואלי של כל אחת מהאפליקציות שלנו ויכתוב אותו פשוט ישירות ל- ElasticSearch.

יש לכך כמה סיבות:

• סכימה: כל אחת ואחת מהתחנות בדרך, היא schema-less. אף אחת מהן לא אוכפת עבורנו באף רמה את הסכימה של המידע שהיא מעבדת. זה יתרון מצד אחד, וחסרון מצד שני. החסרון בא לידי ביטוי כשנרצה לתשאל – אם יהיו לנו מיליון שדות שאומרים אותו דבר, ועבור כל אפליקציה חדשה שמגיעה לכתוב הודעות היא תכתוב אותם בפורמט קצת שונה, ככה שיתקבלו שדות קצת שונים – אם נרצה לשאול שאלות פשוטות כמו “איזה הודעות קריטיות היו” או “איזה exceptions חוזרים הכי הרבה פעמים” או כל שאלה הכי פשוטה שתהיה – זאת תהיה משימה מורכבת שתדרוש תחזוקה, כי דברים לא יהיו באותו מבנה.
  אם כולם ידברו מול service מרכזי, שיקבל את המידע וייצר JSON שאותו הוא יכתוב לראביט שהוא כבר בפורמט המוסכם – אזי נפתור את הבעייה הזאת.
• להימנע מ- Polling: העבודה מול RabbitMQ כשה- logstash מקבל ממנו input טובה משמעותית מלקנפג את ה- logstash לעשות tail ללוגים של אפליקציות שונות מבחינת ביצועים – כי ל- polling יש עלות.
• להקל את התחזוקה: אם יש service מרכזי שאוכף פורמט מוסכם, לא נידרש לערוך קונפיגורציות כשנרצה להכניס אפליקציות נוספות.

פורמט ההודעה

כאמור בפוסט הקודם, הפורמט שבחרנו להודעות הוא JSON, כאשר לטובת הנוחות הגדרתי את ה- JSON במבנה שטוח לחלוטין (לקנפג את logstash עם מבנים יותר מורכבים, שכוללים למשל מערכים, או אובייקטים nested זה כמובן אפשרי – אבל סתם מסבך דברים, ולא צריך את זה במקרה שלנו). למשל, כך ייראה JSON של הודעה:

{

  "EventDateTime": "2016-12-14-21:02:07.149",

  "SourceApplication": "MyApp",

  "SourceModule": "MyModule",

  "SourceFile": null,

  "TextMessage": "error occured while doing math operation",

  "Level": "Error",

  "MessageVersion": 1,

  "ExceptionMessage": "Attempted to divide by zero.",

  "ExceptionType": "DivideByZeroException",

  "ExceptionStackTrace": "   at LogGenerator.Program.Main(String[] args) in c:\\users\\shaha\\Google Drive\\Documents\\Visual Studio 2015\\Projects\\LogGenerator\\LogGenerator\\Program.cs:line 18",

  "ExceptionString": "System.DivideByZeroException: Attempted to divide by zero.\r\n   at LogGenerator.Program.Main(String[] args) in c:\\users\\shaha\\Google Drive\\Documents\\Visual Studio 2015\\Projects\\LogGenerator\\LogGenerator\\Program.cs:line 18",

  "AdditionalField_FirstNum": 5,

  "AdditionalField_SecondNum": 0

}

האובייקט שהגדרתי אצלי לטובת הבדיקות נראה כך:

public enum VerboseLevel

  {

      Unspecified = 0,

      Debug,

      Verbose,

      Error,

      Critical

  }

  public class LogMessage

  {

      private readonly Dictionary<string, object> _additionalFields = new Dictionary<string, object>();

      public LogMessage(string sourceApp, string sourceModule)

      {

          SourceApplication = sourceApp;

          SourceModule = sourceModule;

      }

      public LogMessage(string sourceApp, string sourceModule, string msg, Exception exception = null) : this(sourceApp, sourceModule)

      {

          TextMessage = msg;

          if (exception != null)

          {

              Exception = exception;

              VerboseLevel = VerboseLevel.Error;

          }

      }

      public readonly int MessageVersion = 1;

      public string SourceApplication { get; set; }

      public string SourceModule { get; set; }

      public string SourceFile { get; set; }

      public Exception Exception { get; set; }

      public string TextMessage { get; set; }

      public DateTime EventDateTime { get; set; } = DateTime.Now;

      public VerboseLevel VerboseLevel { get; set; }

      public object this[string fieldName]

      {

          get { return _additionalFields[fieldName]; }

          set { _additionalFields[fieldName] = value; }

      }

      public string ToJson()

      {

          JObject obj = new JObject

          {

              {"EventDateTime", EventDateTime.ToString("yyyy-MM-dd-HH:mm:ss.fff")},

              {"SourceApplication", SourceApplication },

              {"SourceModule", SourceModule },

              {"SourceFile", SourceFile },

              {"TextMessage",TextMessage },

              {"Level",VerboseLevel.ToString() },

              {"MessageVersion", MessageVersion },

          };

          if (Exception != null)

          {

              obj.Add("ExceptionMessage", Exception.Message);

              obj.Add("ExceptionType", Exception.GetType().Name);

              obj.Add("ExceptionStackTrace", Exception.StackTrace);

              obj.Add("ExceptionString", Exception.ToString());

          }

          foreach (var additionalField in _additionalFields)

          {

              obj.Add($"AdditionalField_{additionalField.Key}", JToken.FromObject(additionalField.Value));

          }

          return obj.ToString(Formatting.Indented);

      }

  }

זמנים

אחד הדברים החשובים במעקב אחרי הודעות הוא נושא הזמן. למעשה, הזמן הוא השדה היחיד ש-logstash בקונפיגורציה שעשינו בפוסט הקודם מתייחס אליו באופן מיוחד. הוא מזהה את שדה ה- EventDateTime לפי הפורמט שקבענו בקונפיגורציית logstash בפוסט הקודם (שהוא בכוונה שונה מהפורמט ה-JSON-י הרגיל כדי להראות איך מקנפגים את זה), ומתייחס אליו בתור שדה ה- timestamp שמולו נעשה את כל ה- time based filtering כשנגיע לתחקור המידע. ולכן, חשוב לוודא שתמיד קיים השדה הזה ושהוא מפורסר כהלכה.

נקודה נוספת שחשוב לשים לב אליה בהקשרי זמנים היא רמת הדיוק. שדה התאריך והשעה ב-ElasticSearch נשמר עד לרמת המילי-שניות. זה אולי נשמע מדוייק, אבל זה ממש לא מדוייק מספיק. למשל, באפליקציה שפועלת וכותבת לוגים בקצב גבוהה יחסית, אנחנו עלולים בהחלט להיות במצב שכמה רשומות לוג נכתבו כשהשוני בינהן הוא מעבר לרוזולציית המילי-שניות. במקרה כזה, כאשר ננסה לחקור איזושהי בעייה שדורשת מאיתנו להסתכל על הודעות הלוג האלה, ונרצה באופן טבעי למיין אותם לפי הזמן שבו הם נכתבו – כדי שנעקוב אחרי הדברים בסדר ההתרחשות שלהם, אנחנו עלולים לראות דברים בסדר לא נכון. אירועים שקרו קודם יופיעו כאילו הם קרו אח”כ ולהיפך. צריך להיות מודעים לכך, כי זה עלול לבלבל. ניתן גם לעשות workaround מסויים שיתאים בחלק מהמקרים (בעיקר אם יש לנו פיקים במהלך השנייה, אבל באופן כללי יש לנו פחות מ-1000 הודעות בשנייה) והוא ברמת ה- service לדרוס את שדה המילי-שניות בהודעה ככה שהוא יהיה עולה באופן מלאכותי לפי סדר קליטת ההודעה ב- service כך שההודעה הראשונה בשנייה מסויימת תקבל את הערך 1 ל-ms שלה, השנייה את הערך 2 וכו’. כמובן שזה לא מתאים בכל המצבים, ופוגע את היכולת לעשות התאמות-זמנים מול מקורות מידע אחרים (אם ישנם כאלה), אבל זה יכול להיות שימושי.

ה- service עצמו

כאמור, הפונקציונאליות שה- service הזה אמור לספק היא מאד פשוטה: לקבל את המידע הנדרש (בד”כ שדות מסגרת מסויימים, כפי שניתן לראות באובייקט שהגדרתי קודם ובנוסף תמיכה בשדות חופשיים שממומשים באובייקט ששמתי קודם באמצעות Dictionary שאנחנו מסרלזים להודעה את הערכים שלו) ולכתוב אותו בתור JSON כמו שהראיתי קודם ל-RabbitMQ.

מכיוון שהפוסט הזה והקודם לא מוגבלים לפלטפורמות מסויימות, או לשפות פיתוח מסויימות – אני לא רואה טעם להעמיק ולהראות איך לממש service פשוט כזה, וכל אחד יכול לממש אותו בהתאם לצרכים שלו ולהעדפות שלו (ASP.NET Core, WCF, Node.JS, Python, PHP…). עם זאת, אני כן אפנה לתיעוד המעולה של RabbitMQ שמסביר טוב מאד איך כותבים אליו הודעות מכל שפה שיש SDK רשמי של RabbitMQ עבורה. מרגע שקיבלתם את המידע, וכתבתם את ההודעה ל- RabbitMQ (הודעה בדומה לפורמט שהראיתי קודם) – logstash שקינפגנו קודם יעשה את השאר, יקבל את ההודעה, יעשה עליה פירסור מינימלי בשביל לחלץ את שדה הזמן, ויכניס אותה ל-ElasticSearch.

Kibana

הרכיב הבא שנתייחס אליו הוא Kibana. למעשה, Kibana זה מנוע שמאפשר לנו להציג מידע שמאוכסן ב- ElasticSearch ולייצר dashboard-ים שונים מעליו. מדובר בממשק WEB-י בעל לא מעט אפשרויות (שהרבה מהם לוקחות השראה מ- Splunk).  יחסית קל ללמוד אותו, כך שאני אתמקד בעיקר באיך מתקינים אותו ובמונחים הבסיסיים לעבודה מולו.

התקנה

תחילה יש להיכנס לעמוד ההורדה ולהוריד את הגרסא המתאימה. בהסבר פה אני מדבר על גרסא 5.1.1 ל- Windows. את ה- ZIP שהורדנו נפתח לתוך c:\Kibana. לאחר מכן ניכנס ל c:\Kibana\Config ונערוך את kibana.yml כדי להגדיר את הכתובת לשרת ה- ElasticSearch שלנו (השדה שנקרא elasticsearch.url).  בנוסף, נרצה לשנות את זה שנוכל לגשת ל- Kibana מרחוק (ולא רק מהשרת שעליו היא מותקנת). כך זה ייראה אחרי שערכנו את ההגדרות (שימו לב שפה ה-Kibana מותקנת על אותו node שעליו מותקן ElasticSearch):

לאחר מכן, נריץ את ה- bat שנמצא ב c:\kibana\bin\kibana.bat. אחרי כמה שניות נראה את ההודעות הבאות:

וזה אומר ש- Kibana מוכנה לשימוש – רק צריך לגלוש על המכונה שבה התקנו ל http://localhost:5601. כשנגלוש, יופיע לנו המסך הבא:

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

[הערת אגב: כמובן שבסביבת production נרצה להתקין את Kibana בתור windows service, ואת זה אפשר לעשות עם nssm כמו שהראיתי בפוסט הקודם בסדרה עבור logstash, פשוט עם הכוונה ל- batch file של kibana.bat במקום לזה של logstash].

שימוש

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

מצד שמאל, יש לנו למעשה את הבחירה בין שלושת סוגי התצוגה העיקריים של Kibana: תצוגת ה- Discover (שעליה אנחנו נמצאים עכשיו), ה- Visualise (שמאפשרת לנו להכין ויזואליזציות של נתונים שונים) וה- Dashboard שמאפשר לנו לשלב את כל אותם הויזואליזציות ל- dashboards נוחים.

מלמעלה, אנחנו יכולים לראות את תיבת החיפוש. כזכור, הכל מתבסס פה על ElasticSearch שהוא מעל הכל שרת אינדוקס טקסטואלי. אנחנו יכולים לחפש מילה מסויימת, לחפש ביטויים לוגיים שונים (exception AND (sql OR hadoop)) וכו’.

אם נלחץ על החץ שליד אחד השורות שמופיעות, נוכל לראות בצורה טבלאית את השדות ששמורים עבור ה- document המסויים:

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

נוכל כמובן גם לשמור את החיפוש הזה (שזה אומר גם את החיפוש, הפילטורים שעשינו, והתצוגה שבחרנו) ע”י לחיצה על כפתור ה- save. למשל, אם נלחץ על סימן הכוכב שיש כשפותחים את אחת הרשומות ליד שדה ה- Exception Message, נוכל לייצר לנו תצוגה שכוללת רק את השגיאות שקרו – כלומר, תוכלו לראות שאין כבר שורות שאין להן Exception Message, ומתחת לשורת החיפוש מופיע ה-filter שלנו שמיישם את זה:

יצירת Dashboard

אחרי שקיבלנו טעימה קטנה של איך מתחילים עם Kibana, המטרה שלנו תהיה לייצר dashboard-ים שימושיים עבורנו. למשל, dashboard שיציג לנו את השגיאות הקריטיות האחרונות מכל האפליקציות + פילטור של אפליקציות בעייתיות, או שגיאות שחוזרות על עצמן כדי שנדע לזהות מגמות. או dashboard שמציג לנו את ה- latency של משתמשים בביצוע מגוון פעולות – שנוכל לאתר גם פה בעיות שונות ומשונות.

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

חלופות

ה- stack הטכנולוגי שראינו בפוסט הקודם ובפוסט הזה, מתבסס כולו על כלי open-source חינמיים, כאלה שאתם יכולים כבר היום להוריד ולהתקין. עם זאת, כמובן שלא מדובר בפיתרון היחיד בתחום ניהול הלוגים. אי אפשר לכתוב פוסט על לוגים בלי לכל הפחות להזכיר את Splunk,  המתחרה המסחרי החזק ביותר בתחום כנראה. בנוסף, יש לא מעט חברות שמציעות גם את פלטטפורמת ה- ELK בתור service ענני – במקום להקים את התשתיות אצלכם. ניתן למנות ברשימה את logit.io, או את הסטארטאפ הישראלי logz.io.

סיכום

בפוסט הקודם ובפוסט הזה סקרתי את כל מה שצריך כדי להתחיל ולהרים תשתית לוגים מבוססת על ELK stack: משתמשת ב- ElasticSearch כמנוע אינדוקס, logstash כמנוע קליטת הלוגים (למרות שהשימוש שעשינו בו היה מינימליסטי מאד בהשוואה ליכולות הרחבות שלו) ו- Kibana שנגענו בה קצת לטובת ויזואליזציה של הלוגים.

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

בהצלחה.