ใช้ประโยชน์สูงสุดจากไฟล์บันทึก PHP ของคุณ: คู่มือปฏิบัติ

เผยแพร่แล้ว: 2022-03-11

อาจกล่าวได้ถูกต้องว่าบันทึกเป็นหนึ่งในเครื่องมือที่ประเมินค่าต่ำและใช้งานน้อยเกินไปสำหรับนักพัฒนา php อิสระ แม้จะมีข้อมูลมากมายที่พวกเขาสามารถนำเสนอได้ แต่ก็ไม่ใช่เรื่องแปลกที่บันทึกจะเป็นสถานที่ สุดท้าย ที่นักพัฒนาซอฟต์แวร์ค้นหาเมื่อพยายามแก้ไขปัญหา

ในความเป็นจริง ไฟล์บันทึก PHP ในหลาย ๆ กรณีควรเป็นที่ แรก ในการค้นหาเบาะแสเมื่อเกิดปัญหาขึ้น บ่อยครั้ง ข้อมูลที่มีอยู่สามารถลดระยะเวลาที่ใช้ในการดึงผมของคุณออกเพื่อพยายามติดตามแมลงตัวร้ายได้อย่างมาก

แต่บางทีอาจสำคัญกว่านั้น ด้วยความคิดสร้างสรรค์และไตร่ตรอง ไฟล์บันทึกของคุณสามารถใช้เป็นแหล่งข้อมูลที่มีคุณค่าของข้อมูลการใช้งานและการวิเคราะห์ การใช้ไฟล์บันทึกอย่างสร้างสรรค์สามารถช่วยตอบคำถามต่างๆ เช่น เบราว์เซอร์ใดที่ใช้บ่อยที่สุดในการเยี่ยมชมไซต์ของฉัน เวลาตอบสนองโดยเฉลี่ยจากเซิร์ฟเวอร์ของฉันคือเท่าใด เปอร์เซ็นต์ของคำขอไปยังรูทของไซต์คือเท่าใด การใช้งานเปลี่ยนไปอย่างไรตั้งแต่เราปรับใช้การอัปเดตล่าสุด และอีกมากมาย

ไฟล์บันทึก PHP

บทความนี้มีเคล็ดลับจำนวนหนึ่งเกี่ยวกับวิธีกำหนดค่าไฟล์บันทึกของคุณ ตลอดจนวิธีประมวลผลข้อมูลที่มีอยู่ในไฟล์ เพื่อเพิ่มประโยชน์ที่ได้รับสูงสุด

แม้ว่าบทความนี้จะเน้นทางเทคนิคที่การบันทึกสำหรับนักพัฒนา PHP แต่ข้อมูลส่วนใหญ่ที่นำเสนอในที่นี้ค่อนข้างจะไม่เชื่อเรื่องเทคโนโลยีและเกี่ยวข้องกับภาษาและเทคโนโลยีอื่นๆ ด้วย

หมายเหตุ: บทความนี้สันนิษฐานว่ามีความคุ้นเคยพื้นฐานกับเชลล์ Unix สำหรับผู้ที่ไม่มีความรู้นี้มีภาคผนวกซึ่งแนะนำคำสั่งบางอย่างที่จำเป็นสำหรับการเข้าถึงและการอ่านล็อกไฟล์บนระบบ Unix

โครงการตัวอย่างไฟล์บันทึก PHP ของเรา

เป็นตัวอย่างโครงการเพื่อการอภิปรายในบทความนี้ เราจะใช้ Symfony Standard เป็นโครงการที่ทำงาน และเราจะตั้งค่าบน Debian 7 Wheezy ด้วย rsyslogd , nginx และ PHP-FPM

 composer create-project symfony/framework-standard-edition my "2.6.*"

สิ่งนี้ทำให้เรามีโครงการทดสอบการทำงานที่มี UI ที่ดีได้อย่างรวดเร็ว

เคล็ดลับสำหรับการกำหนดค่าไฟล์บันทึกของคุณ

ต่อไปนี้คือคำแนะนำบางประการเกี่ยวกับวิธีกำหนดค่าไฟล์บันทึกของคุณเพื่อช่วยเพิ่มมูลค่าสูงสุด

การกำหนดค่าบันทึกข้อผิดพลาด

บันทึกข้อผิดพลาดแสดงถึงรูปแบบพื้นฐานของการบันทึก คือ การเก็บข้อมูลเพิ่มเติมและรายละเอียดเมื่อเกิดปัญหา ดังนั้น ในโลกอุดมคติ คุณต้องการให้ไม่มีข้อผิดพลาดและบันทึกข้อผิดพลาดของคุณจะว่างเปล่า แต่เมื่อเกิดปัญหาขึ้น (ซึ่งมักจะเกิดขึ้นอย่างสม่ำเสมอ) บันทึกข้อผิดพลาดของคุณควรเป็นหนึ่งในจุดหยุดแรกที่คุณทำบนเส้นทางการดีบักของคุณ

บันทึกข้อผิดพลาดมักจะกำหนดค่าได้ง่ายมาก

ประการหนึ่ง ข้อความแสดงข้อผิดพลาดและข้อขัดข้องทั้งหมดสามารถบันทึกไว้ในบันทึกข้อผิดพลาดในรูปแบบเดียวกับที่จะแสดงต่อผู้ใช้ ด้วยการกำหนดค่าที่เรียบง่าย ผู้ใช้จะไม่จำเป็นต้องเห็นการติดตามข้อผิดพลาดที่น่าเกลียดบนไซต์ของคุณ ในขณะที่ devops จะยังสามารถติดตามระบบและตรวจทานข้อความแสดงข้อผิดพลาดเหล่านี้ในรายละเอียดที่เต็มไปด้วยเลือด ต่อไปนี้เป็นวิธีตั้งค่าการบันทึกประเภทนี้ใน PHP:

 log_errors = On error_reporting = E_ALL error_log = /path/to/my/error/log

อีกสองบรรทัดที่สำคัญที่จะรวมไว้ในล็อกไฟล์สำหรับไซต์ที่ใช้งานจริง เพื่อป้องกันไม่ให้รายละเอียดข้อผิดพลาดระดับเลือดนองถูกนำเสนอต่อผู้ใช้ ได้แก่:

 display_errors = Off display_startup_errors = Off

บันทึกระบบ ( syslog ) Confguration

มีการใช้งานร่วมกันได้หลายอย่างของ syslog daemon ในโลกโอเพ่นซอร์ส ได้แก่:

  • syslogd และ sysklogd – มักพบเห็นได้ในระบบครอบครัว BSD, CentOS, Mac OS X และอื่นๆ
  • syslog-ng – ค่าเริ่มต้นสำหรับ Gentoo และ SuSE builds ที่ทันสมัย
  • rsyslogd – ใช้กันอย่างแพร่หลายในระบบปฏิบัติการตระกูล Debian และ Fedora

(หมายเหตุ: ในบทความนี้ เราจะใช้ rsyslogd สำหรับตัวอย่าง)

การกำหนดค่า syslog พื้นฐานโดยทั่วไปเพียงพอสำหรับการจับภาพข้อความบันทึกของคุณในไฟล์บันทึกทั้งระบบ (โดยปกติ /var/log/syslog ; อาจเป็น /var/log/messages หรือ /var/log/system.log ขึ้นอยู่กับ distro ที่คุณใช้อยู่)

บันทึกของระบบจัดเตรียมสิ่งอำนวยความสะดวกบันทึกต่างๆ โดยแปดรายการ ( LOG_LOCAL0 ถึง LOG_LOCAL7 ) สงวนไว้สำหรับโปรเจ็กต์ที่ผู้ใช้ปรับใช้ ตัวอย่างเช่น นี่คือวิธีที่คุณอาจตั้งค่า LOG_LOCAL0 ให้เขียนไฟล์บันทึกแยกกัน 4 ไฟล์ ตามระดับการบันทึก (เช่น ข้อผิดพลาด คำเตือน ข้อมูล การดีบัก):

 # /etc/rsyslog.d/my.conf local0.err /var/log/my/err.log local0.warning /var/log/my/warning.log local0.info -/var/log/my/info.log local0.debug -/var/log/my/debug.log

ตอนนี้ เมื่อใดก็ตามที่คุณเขียนข้อความบันทึกไปยังสิ่งอำนวยความสะดวก LOG_LOCAL0 ข้อความแสดงข้อผิดพลาดจะไปที่ /var/log/my/err.log ข้อความเตือนจะไปที่ /var/log/my/warning.log เป็นต้น อย่างไรก็ตาม โปรดทราบว่า syslog daemon จะกรองข้อความสำหรับแต่ละไฟล์ตามกฎของ "ระดับนี้ขึ้นไป" ดังนั้น ในตัวอย่างข้างต้น ข้อความแสดงข้อผิดพลาดทั้งหมดจะปรากฏในไฟล์ที่กำหนดค่าทั้งสี่ไฟล์ ข้อความเตือนจะปรากฏในทุกไฟล์ยกเว้นบันทึกข้อผิดพลาด ข้อความข้อมูลจะปรากฏในข้อมูลและบันทึกการดีบัก และข้อความแก้ไขข้อบกพร่องจะไปที่ debug.log .

หมายเหตุสำคัญเพิ่มเติมประการหนึ่ง; เครื่องหมาย - ก่อนไฟล์ข้อมูลและระดับการดีบักในตัวอย่างไฟล์การกำหนดค่าด้านบนระบุว่าการเขียนไปยังไฟล์เหล่านั้นควรทำแบบอะซิงโครนัส (เนื่องจากการดำเนินการเหล่านี้ไม่มีการบล็อก) โดยทั่วไปแล้วสิ่งนี้จะใช้ได้ (และแม้จะแนะนำในสถานการณ์ส่วนใหญ่) สำหรับข้อมูลและบันทึกการแก้ไขข้อบกพร่อง แต่วิธีที่ดีที่สุดคือเขียนบันทึกข้อผิดพลาด (และอาจเป็นบันทึกการเตือนด้วยเช่นกัน) แบบซิงโครนัส

ในการปิดระดับการบันทึกที่มีความสำคัญน้อยกว่า (เช่น บนเซิร์ฟเวอร์ที่ใช้งานจริง) คุณเพียงแค่เปลี่ยนเส้นทางข้อความที่เกี่ยวข้องไปที่ /dev/null (เช่น ไม่มีที่ไหนเลย):

 local0.debug /dev/null # -/var/log/my/debug.log

การปรับแต่งเฉพาะที่มีประโยชน์อย่างหนึ่งโดยเฉพาะเพื่อสนับสนุนการแยกวิเคราะห์ไฟล์บันทึก PHP บางส่วนที่เราจะกล่าวถึงในบทความนี้ต่อไปคือการใช้แท็บเป็นตัวคั่นในข้อความบันทึก สามารถทำได้โดยการเพิ่มไฟล์ต่อไปนี้ใน /etc/rsyslog.d :

 # /etc/rsyslog.d/fixtab.conf $EscapeControlCharactersOnReceive off

และสุดท้าย อย่าลืมรีสตาร์ท syslog daemon หลังจากที่คุณทำการเปลี่ยนแปลงการกำหนดค่าใดๆ เพื่อให้การเปลี่ยนแปลงมีผล:

 service rsyslog restart

การกำหนดค่าบันทึกเซิร์ฟเวอร์

ต่างจากบันทึกของแอปพลิเคชันและบันทึกข้อผิดพลาดที่คุณสามารถเขียนได้ บันทึกของเซิร์ฟเวอร์ถูกเขียนโดยดีมอนเซิร์ฟเวอร์ที่เกี่ยวข้องเท่านั้น (เช่น เว็บเซิร์ฟเวอร์ เซิร์ฟเวอร์ฐานข้อมูล ฯลฯ) ในแต่ละคำขอ "การควบคุม" เพียงอย่างเดียวที่คุณมีต่อบันทึกเหล่านี้คือในขอบเขตที่เซิร์ฟเวอร์อนุญาตให้คุณกำหนดค่าฟังก์ชันการบันทึก แม้ว่าไฟล์เหล่านี้อาจมีข้อมูลมากมายที่ต้องกลั่นกรอง แต่ก็มักจะเป็นวิธีเดียวที่จะทำความเข้าใจให้ชัดเจนว่าเกิดอะไรขึ้นกับเซิร์ฟเวอร์ของคุณ

มาปรับใช้แอปพลิเคชันตัวอย่าง Symfony Standard ของเราในสภาพแวดล้อม nginx พร้อมแบ็กเอนด์ที่เก็บข้อมูล MySQL นี่คือการกำหนดค่าโฮสต์ nginx ที่เราจะใช้:

 server { server_name my.log-sandbox; root /var/www/my/web; location / { # try to serve file directly, fallback to app.php try_files $uri /app.php$is_args$args; } # DEV # This rule should only be placed on your development environment # In production, don't include this and don't deploy app_dev.php or config.php location ~ ^/(app_dev|config)\.php(/|$) { fastcgi_pass unix:/var/run/php5-fpm.sock; fastcgi_split_path_info ^(.+\.php)(/.*)$; include fastcgi_params; fastcgi_param SCRIPT_FILENAME $document_root$fastcgi_script_name; fastcgi_param HTTPS off; } # PROD location ~ ^/app\.php(/|$) { fastcgi_pass unix:/var/run/php5-fpm.sock; fastcgi_split_path_info ^(.+\.php)(/.*)$; include fastcgi_params; fastcgi_param SCRIPT_FILENAME $document_root$fastcgi_script_name; fastcgi_param HTTPS off; # Prevents URIs that include the front controller. This will 404: # http://domain.tld/app.php/some-path # Remove the internal directive to allow URIs like this internal; } error_log /var/log/nginx/my_error.log; access_log /var/log/nginx/my_access.log; }

สำหรับคำสั่งสองคำสั่งสุดท้ายข้างต้น: access_log แสดงถึงบันทึกคำขอทั่วไป ในขณะที่ error_log ใช้สำหรับข้อผิดพลาด และเช่นเดียวกับบันทึกข้อผิดพลาดของแอปพลิเคชัน คุณควรตั้งค่าการตรวจสอบเพิ่มเติมเพื่อรับการแจ้งเตือนถึงปัญหาเพื่อให้คุณตอบสนองได้อย่างรวดเร็ว

หมายเหตุ: นี่เป็นไฟล์กำหนดค่า nginx ที่ตั้งใจทำให้เข้าใจง่ายเกินไป ซึ่งจัดทำขึ้นเพื่อเป็นตัวอย่างเท่านั้น แทบไม่ให้ความสำคัญกับความปลอดภัยและประสิทธิภาพเลย และไม่ควรใช้เหมือนในสภาพแวดล้อม "จริง" ใดๆ

นี่คือสิ่งที่เราได้รับใน /var/log/nginx/my_access.log หลังจากพิมพ์ http://my.log-sandbox/app_dev.php/ ในเบราว์เซอร์แล้วกด Enter

 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /app_dev.php/ HTTP/1.1" 200 6715 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /bundles/framework/css/body.css HTTP/1.1" 200 6657 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /bundles/framework/css/structure.css HTTP/1.1" 200 1191 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /bundles/acmedemo/css/demo.css HTTP/1.1" 200 2204 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /bundles/acmedemo/images/welcome-quick-tour.gif HTTP/1.1" 200 4770 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /bundles/acmedemo/images/welcome-demo.gif HTTP/1.1" 200 4053 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /bundles/acmedemo/images/welcome-configure.gif HTTP/1.1" 200 3530 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /favicon.ico HTTP/1.1" 200 6518 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:30 +0300] "GET /app_dev.php/_wdt/e50d73 HTTP/1.1" 200 13265 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36"

นี่แสดงว่าสำหรับการให้บริการหน้าเดียว เบราว์เซอร์ทำการเรียก HTTP 9 ครั้ง อย่างไรก็ตาม 7 รายการดังกล่าวเป็นคำขอสำหรับเนื้อหาแบบคงที่ ซึ่งเรียบง่ายและมีน้ำหนักเบา อย่างไรก็ตาม พวกเขายังคงใช้ทรัพยากรเครือข่าย และนี่คือสิ่งที่สามารถเพิ่มประสิทธิภาพได้โดยใช้สไปรท์และเทคนิคการย่อขนาดต่างๆ

แม้ว่าจะมีการกล่าวถึงการเพิ่มประสิทธิภาพเหล่านั้นในบทความอื่น แต่สิ่งที่สำคัญที่นี่คือ เราสามารถบันทึกคำขอไปยังเนื้อหาแบบคงที่แยกกันโดยใช้คำสั่ง location อื่นสำหรับพวกเขา:

 location ~ \.(jpg|jpeg|gif|png|ico|css|zip|tgz|gz|rar|bz2|pdf|txt|tar|wav|bmp|rtf|js)$ { access_log /var/log/nginx/my_access-static.log; }

โปรดจำไว้ว่า location nginx ทำการจับคู่นิพจน์ทั่วไปอย่างง่าย ดังนั้นคุณจึงสามารถรวมส่วนขยายเนื้อหาแบบคงที่ได้มากเท่าที่คุณต้องการส่งในไซต์ของคุณ

การแยกวิเคราะห์บันทึกดังกล่าวไม่แตกต่างจากการแยกวิเคราะห์บันทึกของแอปพลิเคชัน

บันทึกอื่น ๆ ที่ควรค่าแก่การกล่าวถึง

บันทึก PHP อื่น ๆ อีกสองรายการที่น่ากล่าวถึงคือบันทึกการดีบักและบันทึกการจัดเก็บข้อมูล

บันทึกการดีบัก

อีกสิ่งหนึ่งที่สะดวกเกี่ยวกับบันทึก nginx คือบันทึกการดีบัก เราสามารถเปิดใช้งานได้โดยแทนที่บรรทัด error_log ของการกำหนดค่าด้วยสิ่งต่อไปนี้ (จำเป็นต้องติดตั้งโมดูลดีบัก nginx):

 error_log /var/log/nginx/my_error.log debug;

การตั้งค่าเดียวกันนี้ใช้กับ Apache หรือเว็บเซิร์ฟเวอร์อื่นๆ ที่คุณใช้

และโดยบังเอิญ บันทึกการดีบักจะ ไม่ เกี่ยวข้องกับบันทึกข้อผิดพลาด แม้ว่าจะมีการกำหนดค่าไว้ในคำสั่ง error_log

แม้ว่าบันทึกการดีบักจะเป็นแบบละเอียดจริงๆ (คำขอ nginx เดียว เช่น สร้างข้อมูลบันทึก 127KB!) แต่ก็ยังมีประโยชน์มาก การเข้าดูไฟล์บันทึกอาจเป็นเรื่องยุ่งยากและน่าเบื่อ แต่บ่อยครั้งสามารถให้เบาะแสและข้อมูลได้อย่างรวดเร็ว ซึ่งช่วยเร่งกระบวนการดีบักได้อย่างมาก

โดยเฉพาะอย่างยิ่ง บันทึกการดีบักสามารถช่วยในการดีบักการกำหนดค่า nginx โดยเฉพาะอย่างยิ่งส่วนที่ซับซ้อนที่สุด เช่น การจับคู่ location และการ rewrite เชนใหม่

แน่นอน ไม่ควรเปิดใช้งานบันทึกการดีบักในสภาพแวดล้อมที่ใช้งานจริง จำนวนพื้นที่ที่พวกเขาใช้และจำนวนข้อมูลที่จัดเก็บหมายถึงการโหลด I/O จำนวนมากบนเซิร์ฟเวอร์ของคุณ ซึ่งอาจทำให้ประสิทธิภาพของทั้งระบบลดลงอย่างมาก

บันทึกการจัดเก็บข้อมูล

บันทึกเซิร์ฟเวอร์อีกประเภทหนึ่ง (มีประโยชน์สำหรับการดีบัก) คือ บันทึกการจัดเก็บข้อมูล ใน MySQL คุณสามารถเปิดใช้งานได้โดยเพิ่มบรรทัดเหล่านี้:

 [mysqld] general_log = 1 general_log_file = /var/log/mysql/query.log

บันทึกเหล่านี้ประกอบด้วยรายการการสืบค้นที่เรียกใช้โดยระบบในขณะที่ให้บริการคำขอฐานข้อมูลตามลำดับเวลา ซึ่งอาจเป็นประโยชน์สำหรับความต้องการในการดีบักและการติดตามต่างๆ อย่างไรก็ตาม ไม่ควรเปิดใช้งานอยู่บนระบบที่ใช้งานจริง เนื่องจากจะสร้างโหลด I/O ที่ไม่จำเป็นเพิ่มเติม ซึ่งส่งผลต่อประสิทธิภาพการทำงาน

กำลังเขียนไปยังไฟล์บันทึกของคุณ

PHP เองมีฟังก์ชันสำหรับการเปิด เขียนและปิดล็อกไฟล์ ( openlog() , syslog() และ closelog() ตามลำดับ)

นอกจากนี้ยังมีไลบรารีการบันทึกจำนวนมากสำหรับนักพัฒนา PHP เช่น Monolog (เป็นที่นิยมในหมู่ผู้ใช้ Symfony และ Laravel) ตลอดจนการใช้งานเฉพาะเฟรมเวิร์กต่างๆ เช่น ความสามารถในการบันทึกที่รวมอยู่ใน CakePHP โดยทั่วไป ไลบรารีอย่าง Monolog ไม่เพียงแต่ตัดการเรียก syslog() เท่านั้น แต่ยังอนุญาตให้ใช้ฟังก์ชันและเครื่องมือแบ็กเอนด์อื่นๆ

ต่อไปนี้คือตัวอย่างง่ายๆ ของการเขียนบันทึกลงในบันทึก:

 <?php openlog(uniqid(), LOG_ODELAY, LOG_LOCAL0); syslog(LOG_INFO, 'It works!');

การโทรของเราที่นี่เพื่อ openlog :

  • กำหนดค่า PHP เพื่อเติมตัวระบุที่ไม่ซ้ำกับข้อความบันทึกของระบบแต่ละข้อความภายในอายุการใช้งานของสคริปต์
  • ตั้งค่าให้ชะลอการเปิดการเชื่อมต่อ syslog จนกว่าจะมีการเรียก syslog() ครั้งแรก
  • ตั้งค่า LOG_LOCAL0 เป็นสิ่งอำนวยความสะดวกการบันทึกเริ่มต้น

เนื้อหาของไฟล์บันทึกจะมีลักษณะดังนี้หลังจากรันโค้ดด้านบน:

 # cat /var/log/my/info.log Mar 2 00:23:29 log-sandbox 54f39161a2e55: It works!

การเพิ่มมูลค่าไฟล์บันทึก PHP ของคุณให้สูงสุด

ตอนนี้เราเก่งทฤษฎีและพื้นฐานแล้ว มาดูกันว่าเราจะได้รับอะไรจากบันทึกการเปลี่ยนแปลงน้อยที่สุดเท่าที่จะเป็นไปได้สำหรับโครงการ Symfony Standard ตัวอย่างของเรา

ขั้นแรก ให้สร้างสคริปต์ src/log-begin.php (เพื่อเปิดและกำหนดค่าบันทึกของเราอย่างเหมาะสม) และ src/log-end.php (เพื่อบันทึกข้อมูลเกี่ยวกับการสำเร็จ) โปรดทราบว่า เพื่อความง่าย เราจะเขียนข้อความทั้งหมดลงในบันทึกข้อมูล

 # src/log-begin.php <?php define('START_TIME', microtime(true)); openlog(uniqid(), LOG_ODELAY, LOG_LOCAL0); syslog(LOG_INFO, 'BEGIN'); syslog(LOG_INFO, "URI\t{$_SERVER['REQUEST_URI']}"); $browserHash = substr(md5($_SERVER['HTTP_USER_AGENT']), 0, 7); syslog(LOG_INFO, "CLIENT\t{$_SERVER['REMOTE_ADDR']}\t{$browserHash}"); <br /> # src/log-end.php <?php syslog(LOG_INFO, "DISPATCH TIME\t" . round(microtime(true) - START_TIME, 2)); syslog(LOG_INFO, 'END');

และขอสคริปต์เหล่านี้ใน app.php :

 <?php require_once(dirname(__DIR__) . '/src/log-begin.php'); syslog(LOG_INFO, "MODE\tPROD"); # original app.php contents require_once(dirname(__DIR__) . '/src/log-end.php');

สำหรับสภาพแวดล้อมการพัฒนา เราต้องการสคริปต์เหล่านี้ใน app_dev.php ด้วย รหัสที่จะทำเช่นนั้นจะเหมือนกับด้านบน ยกเว้นเราจะตั้งค่า MODE เป็น DEV แทนที่จะเป็น PROD

เรายังต้องการติดตามว่าคอนโทรลเลอร์ใดที่ถูกเรียกใช้ ดังนั้นเรามาเพิ่มอีกหนึ่งบรรทัดใน Acme\DemoBundle\EventListener\ControllerListener ที่จุดเริ่มต้นของ ControllerListener::onKernelController() :

 syslog(LOG_INFO, "CONTROLLER\t" . get_class($event->getController()[0]));

โปรดทราบว่าการเปลี่ยนแปลงเหล่านี้มีโค้ดเพิ่มเติมเพียง 15 บรรทัด แต่สามารถให้ข้อมูลจำนวนมากได้

การวิเคราะห์ข้อมูลในไฟล์บันทึกของคุณ

สำหรับผู้เริ่มต้น มาดูจำนวนคำขอ HTTP ที่จำเป็นสำหรับการโหลดหน้าเว็บแต่ละครั้ง

นี่คือข้อมูลในบันทึกสำหรับคำขอหนึ่งรายการ โดยอิงตามวิธีที่เรากำหนดค่าการบันทึกของเรา:

 Mar 3 12:04:20 log-sandbox 54f58724b1ccc: BEGIN Mar 3 12:04:20 log-sandbox 54f58724b1ccc: URI /app_dev.php/ Mar 3 12:04:20 log-sandbox 54f58724b1ccc: CLIENT 192.168.56.1 1b101cd Mar 3 12:04:20 log-sandbox 54f58724b1ccc: MODE DEV Mar 3 12:04:23 log-sandbox 54f58724b1ccc: CONTROLLER Acme\DemoBundle\Controller\WelcomeController Mar 3 12:04:25 log-sandbox 54f58724b1ccc: DISPATCH TIME 4.51 Mar 3 12:04:25 log-sandbox 54f58724b1ccc: END Mar 3 12:04:25 log-sandbox 54f5872967dea: BEGIN Mar 3 12:04:25 log-sandbox 54f5872967dea: URI /app_dev.php/_wdt/59b8b6 Mar 3 12:04:25 log-sandbox 54f5872967dea: CLIENT 192.168.56.1 1b101cd Mar 3 12:04:25 log-sandbox 54f5872967dea: MODE DEV Mar 3 12:04:28 log-sandbox 54f5872967dea: CONTROLLER Symfony\Bundle\WebProfilerBundle\Controller\ProfilerController Mar 3 12:04:29 log-sandbox 54f5872967dea: DISPATCH TIME 4.17 Mar 3 12:04:29 log-sandbox 54f5872967dea: END

ตอนนี้เราทราบแล้วว่าการโหลดหน้าเว็บแต่ละครั้งมีคำขอ HTTP สองคำขอ

จริงๆแล้วมีสองประเด็นที่น่ากล่าวถึงที่นี่ อย่างแรก คำขอสองคำขอต่อการโหลดหน้ามีไว้สำหรับการใช้ Symfony ในโหมด dev (ซึ่งฉันได้ทำไปตลอดบทความนี้) คุณสามารถระบุการเรียกโหมด dev ได้โดยการค้นหา /app-dev.php/ ส่วน URL ประการที่สอง สมมติว่าการโหลดหน้าเว็บแต่ละครั้งมีคำขอสองรายการต่อจากนี้ไปยังแอป Symfony ดังที่เราเห็นในบันทึกการเข้าถึง nginx ก่อนหน้านี้ มีการเรียก HTTP มากขึ้น ซึ่งบางส่วนมีไว้สำหรับเนื้อหาแบบคงที่

ตกลง ตอนนี้ มาท่องไซต์สาธิตกัน (เพื่อสร้างข้อมูลในไฟล์บันทึก) และมาดูกันว่าเราจะเรียนรู้อะไรได้อีกจากบันทึกเหล่านี้

มีการส่งคำขอทั้งหมดกี่รายการตั้งแต่เริ่มต้นไฟล์บันทึก

 # grep -c BEGIN info.log 10

มีสิ่งใดที่ล้มเหลว (สคริปต์ปิดตัวลงโดยไม่ถึงจุดสิ้นสุด) หรือไม่?

 # grep -c END info.log 10

เราเห็นว่าจำนวนระเบียน BEGIN และ END ตรงกัน ดังนั้นข้อมูลนี้จึงบอกเราว่าการโทรทั้งหมดสำเร็จ (หากสคริปต์ PHP ไม่เสร็จสมบูรณ์ สคริปต์นั้นจะไม่สามารถดำเนินการตามสคริปต์ src/log-end.php ได้)

เปอร์เซ็นต์ของคำขอไปยังรูทของไซต์คือเท่าใด

 # `grep -cE "\s/app_dev.php/$" info.log` 2

สิ่งนี้บอกเราว่ามีการโหลดรูทไซต์ 2 หน้า เนื่องจากก่อนหน้านี้เราได้เรียนรู้ว่า (a) มีคำขอ 2 รายการไปยังแอปต่อการโหลดหน้าเว็บ และ (b) มีคำขอ HTTP ทั้งหมด 10 รายการ เปอร์เซ็นต์ของคำขอไปยังรากของไซต์คือ 40% (เช่น 2x2/10)

คลาสคอนโทรลเลอร์ใดที่รับผิดชอบในการให้บริการคำขอไปยังรูทไซต์

 # grep -E "\s/$|\s/app_dev.php/$" info.log | head -n1 Mar 3 12:04:20 log-sandbox 54f58724b1ccc: URI /app_dev.php/ # grep 54f58724b1ccc info.log | grep CONTROLLER Mar 3 12:04:23 log-sandbox 54f58724b1ccc: CONTROLLER Acme\DemoBundle\Controller\WelcomeController

ที่นี่เราใช้ ID เฉพาะของคำขอเพื่อตรวจสอบข้อความบันทึกทั้งหมดที่เกี่ยวข้องกับคำขอเดียวนั้น ด้วยเหตุนี้ เราจึงสามารถระบุได้ว่าคลาสคอนโทรลเลอร์ที่รับผิดชอบในการให้บริการคำขอไปยังรูทไซต์คือ Acme\DemoBundle\Controller\WelcomeController

ลูกค้ารายใดที่มี IP ของซับเน็ต 192.168.0.0/16 ที่เข้าถึงไซต์นี้

 # grep CLIENT info.log | cut -d":" -f4 | cut -f2 | sort | uniq 192.168.56.1

ตามที่คาดไว้ในกรณีทดสอบง่ายๆ นี้ มีเพียงคอมพิวเตอร์โฮสต์ของฉันเท่านั้นที่เข้าถึงไซต์ได้ แน่นอนว่านี่เป็นตัวอย่างที่ง่ายมาก แต่ความสามารถที่แสดงออกมา (ของความสามารถในการวิเคราะห์แหล่งที่มาของการเข้าชมไซต์ของคุณ) นั้นค่อนข้างทรงพลังและมีความสำคัญ

การเข้าชมไซต์ของฉันมาจาก FireFox มากเพียงใด

มี 1b101cd เป็นแฮชของ Firefox User-Agent ของฉัน ฉันสามารถตอบคำถามนี้ได้ดังนี้:

 # grep -c 1b101cd info.log 8 # grep -c CLIENT info.log 10

คำตอบ: 80% (เช่น 8/10)

เปอร์เซ็นต์ของคำขอที่ให้การตอบสนองช้าคือเท่าใด

สำหรับจุดประสงค์ของตัวอย่างนี้ เราจะนิยามคำว่า "ช้า" ว่าใช้เวลามากกว่า 5 วินาทีในการตอบกลับ ดังนั้น:

 # grep "DISPATCH TIME" info.log | grep -cE "\s[0-9]{2,}\.|\s[5-9]\." 2

คำตอบ: 20% (เช่น 2/10)

มีใครเคยใส่พารามิเตอร์ GET บ้างไหม?

 # grep URI info.log | grep \?

ไม่ Symfony standard ใช้เฉพาะ URL ทาก ดังนั้นสิ่งนี้ยังบอกเราที่นี่ว่าไม่มีใครพยายามแฮ็คไซต์

นี่เป็นเพียงตัวอย่างเล็กๆ น้อยๆ ที่ค่อนข้างเป็นพื้นฐานเกี่ยวกับวิธีที่ไฟล์บันทึกสามารถใช้ประโยชน์อย่างสร้างสรรค์เพื่อให้ได้ข้อมูลการใช้งานอันมีค่าและแม้แต่การวิเคราะห์ขั้นพื้นฐาน

สิ่งอื่น ๆ ที่ควรทราบ

การรักษาความปลอดภัยของสิ่งต่าง ๆ

ข้อควรระวังอีกอย่างหนึ่งคือเพื่อความปลอดภัย คุณอาจคิดว่าคำขอบันทึกเป็นความคิดที่ดี โดยส่วนใหญ่แล้วเป็นเช่นนั้น อย่างไรก็ตาม สิ่งสำคัญคือต้องระมัดระวังอย่างยิ่งในการลบข้อมูลผู้ใช้ที่อาจมีความละเอียดอ่อนก่อนที่จะจัดเก็บไว้ในบันทึก

ไฟล์บันทึกการต่อสู้บวม

เนื่องจากไฟล์บันทึกเป็นไฟล์ข้อความที่คุณใส่ข้อมูล ต่อท้าย เสมอ จึงมีการเติบโตอย่างต่อเนื่อง เนื่องจากเป็นปัญหาที่ทราบกันดีอยู่แล้ว จึงมีแนวทางมาตรฐานบางประการในการควบคุมการเติบโตของไฟล์บันทึก

วิธีที่ง่ายที่สุดคือการ หมุนบันทึก บันทึกการหมุนหมายถึง:

  • แทนที่บันทึกเป็นระยะด้วยไฟล์ว่างใหม่เพื่อการเขียนเพิ่มเติม
  • การจัดเก็บไฟล์เก่าสำหรับประวัติ
  • การลบไฟล์ที่ “เก่า” เพียงพอเพื่อเพิ่มพื้นที่ว่างในดิสก์
  • ตรวจสอบให้แน่ใจว่าแอปพลิเคชันสามารถเขียนไปยังบันทึกโดยไม่หยุดชะงักเมื่อไฟล์เหล่านี้เปลี่ยนแปลง

วิธีแก้ปัญหาที่พบบ่อยที่สุดคือ logrotate ซึ่งมาพร้อมกับการติดตั้งล่วงหน้าด้วย *nix distributions ส่วนใหญ่ มาดูไฟล์การกำหนดค่าอย่างง่ายสำหรับการหมุนบันทึกของเรา:

 /var/log/my/debug.log /var/log/my/info.log /var/log/my/warning.log /var/log/my/error.log { rotate 7 daily missingok notifempty delaycompress compress sharedscripts postrotate invoke-rc.d rsyslog rotate > /dev/null endscript }

แนวทางขั้นสูงอีกวิธีหนึ่งคือการทำให้ rsyslogd เขียนข้อความลงในไฟล์ ซึ่งสร้างขึ้นแบบไดนามิกตามวันที่และเวลาปัจจุบัน สิ่งนี้ยังคงต้องการโซลูชันแบบกำหนดเองสำหรับการลบไฟล์ที่เก่ากว่า แต่ให้ devops จัดการกรอบเวลาสำหรับไฟล์บันทึกแต่ละไฟล์ได้อย่างแม่นยำ สำหรับตัวอย่างของเรา:

 $template DynaLocal0Err, "/var/log/my/error-%$NOW%-%$HOUR%.log" $template DynaLocal0Info, "/var/log/my/info-%$NOW%-%$HOUR%.log" $template DynaLocal0Warning, "/var/log/my/warning-%$NOW%-%$HOUR%.log" $template DynaLocal0Debug, "/var/log/my/debug-%$NOW%-%$HOUR%.log" local1.err -?DynaLocal0Err local1.info -?DynaLocal0Info local1.warning -?DynaLocal0Warning local1.debug -?DynaLocal0Debug

ด้วยวิธีนี้ rsyslog จะสร้างไฟล์บันทึกแต่ละรายการในแต่ละชั่วโมง และไม่จำเป็นต้องหมุนและรีสตาร์ท daemon ต่อไปนี้คือวิธีลบไฟล์บันทึกที่เก่ากว่า 5 วันเพื่อให้วิธีแก้ปัญหานี้สำเร็จ:

 find /var/log/my/ -mtime +5 -print0 | xargs -0 rm

บันทึกระยะไกล

เมื่อโปรเจ็กต์เติบโตขึ้น การแยกวิเคราะห์ข้อมูลจากบันทึกจะทำให้ทรัพยากรหิวโหยมากขึ้นเรื่อยๆ ซึ่งไม่เพียงแต่หมายถึงการสร้างภาระเซิร์ฟเวอร์เพิ่มเติมเท่านั้น นอกจากนี้ยังหมายถึงการสร้างภาระสูงสุดบน CPU และดิสก์ไดรฟ์ในเวลาที่คุณแยกวิเคราะห์บันทึก ซึ่งอาจทำให้เวลาตอบสนองของเซิร์ฟเวอร์ลดลงสำหรับผู้ใช้ (หรือในกรณีที่เลวร้ายที่สุดอาจทำให้ไซต์ล่มได้)

ในการแก้ปัญหานี้ ให้ลองตั้งค่า เซิร์ฟเวอร์การบันทึกแบบรวมศูนย์ สิ่งที่คุณต้องการสำหรับสิ่งนี้คืออีกกล่องหนึ่งที่เปิด UDP พอร์ต 514 (ค่าเริ่มต้น) ในการทำให้ rsyslogd ฟังการเชื่อมต่อ ให้เพิ่มบรรทัดต่อไปนี้ในไฟล์ปรับแต่ง:

 $UDPServerRun 514

เมื่อมีสิ่งนี้ การตั้งค่าไคลเอนต์นั้นง่ายเหมือน:

 *.* @HOSTNAME:514

(โดยที่ HOSTNAME เป็นชื่อโฮสต์ของเซิร์ฟเวอร์การบันทึกระยะไกลของคุณ)

บทสรุป

แม้ว่าบทความนี้จะแสดงให้เห็นวิธีที่สร้างสรรค์ซึ่งไฟล์บันทึกสามารถให้ข้อมูลที่มีค่ามากกว่าที่คุณคิดไว้ก่อนหน้านี้ สิ่งสำคัญคือต้องเน้นว่าเราได้ขีดข่วนพื้นผิวของสิ่งที่เป็นไปได้เท่านั้น ขอบเขต ขอบเขต และรูปแบบของสิ่งที่คุณบันทึกได้นั้นแทบจะไร้ขีดจำกัด ซึ่งหมายความว่า - หากมีข้อมูลการใช้งานหรือการวิเคราะห์ที่คุณต้องการดึงออกจากบันทึกของคุณ - คุณเพียงแค่ต้องบันทึกในลักษณะที่จะทำให้แยกวิเคราะห์และวิเคราะห์ได้ง่ายในภายหลัง นอกจากนี้ การวิเคราะห์นั้นมักจะสามารถทำได้ด้วยเครื่องมือบรรทัดคำสั่งมาตรฐานของ Linux เช่น grep , sed หรือ awk

อันที่จริง ไฟล์บันทึก PHP เป็นเครื่องมือที่ทรงพลังที่สุดที่สามารถให้ประโยชน์มหาศาล

ทรัพยากร

รหัสบน GitHub: https://github.com/isanosyan/toptal-blog-logs-post-example

ภาคผนวก: การอ่านและการจัดการไฟล์บันทึกใน Unix Shell

ต่อไปนี้คือคำแนะนำสั้นๆ เกี่ยวกับเครื่องมือบรรทัดคำสั่ง *nix ทั่วไปบางส่วน ซึ่งคุณจะต้องการทำความคุ้นเคยกับการอ่านและจัดการไฟล์บันทึกของคุณ

  • cat อาจเป็นแมวที่ง่ายที่สุด มันพิมพ์ไฟล์ทั้งหมดไปยังกระแสข้อมูลขาออก ตัวอย่างเช่น คำสั่งต่อไปนี้จะพิมพ์ logfile1 ไปยังคอนโซล:

     cat logfile1

  • > อักขระอนุญาตให้ผู้ใช้เปลี่ยนเส้นทางเอาต์พุต เช่น ไปยังไฟล์อื่น เปิดสตรีมเป้าหมายในโหมดเขียน (ซึ่งหมายถึงการล้างเนื้อหาเป้าหมาย) นี่คือวิธีที่เราแทนที่เนื้อหาของ tmpfile ด้วยเนื้อหาของ logfile1 :

     cat logfile1 > tmpfile

  • >> เปลี่ยนเส้นทางเอาต์พุตและเปิดสตรีมเป้าหมายในโหมดผนวก เนื้อหาปัจจุบันของไฟล์เป้าหมายจะยังคงอยู่ บรรทัดใหม่จะถูกเพิ่มที่ด้านล่าง สิ่งนี้จะผนวกเนื้อหา logfile1 ต่อท้าย tmpfile :

     cat logfile1 >> tmpfile

  • grep กรองไฟล์ตามรูปแบบและพิมพ์เฉพาะบรรทัดที่ตรงกัน คำสั่งด้านล่างจะพิมพ์เฉพาะบรรทัดของ logfile1 ที่มีข้อความ Bingo :

     grep Bingo logfile1

  • cut พิมพ์เนื้อหาของคอลัมน์เดียว (ตามหมายเลขเริ่มต้นจาก 1) โดยค่าเริ่มต้นจะค้นหาอักขระแท็บเป็นตัวคั่นระหว่างคอลัมน์ ตัวอย่างเช่น หากคุณมีไฟล์ที่มีการประทับเวลาเต็มรูปแบบในรูปแบบ YYYY-MM-DD HH:MM:SS การดำเนินการนี้จะช่วยให้คุณพิมพ์ได้เฉพาะปี:

     cut -d"-" -f1 logfile1

  • head แสดงเฉพาะบรรทัดแรกของไฟล์

  • tail แสดงเฉพาะบรรทัดสุดท้ายของไฟล์

  • sort ลำดับบรรทัดในผลลัพธ์

  • uniq กรองบรรทัดที่ซ้ำกัน

  • wc นับคำ (หรือบรรทัดเมื่อใช้กับแฟล็ก -l )

  • | (กล่าวคือ สัญลักษณ์ "ท่อ") ให้เอาต์พุตจากคำสั่งหนึ่งเป็นอินพุตไปยังคำสั่งถัดไป ไพพ์สะดวกมากสำหรับการรวมคำสั่ง ตัวอย่างเช่น ต่อไปนี้คือวิธีที่เราสามารถค้นหาเดือนของปี 2014 ที่เกิดขึ้นภายในชุดของการประทับเวลา:

     grep -E "^2014" logfile1 | cut -d"-" -f2 | sort | uniq

ในที่นี้เราจับคู่บรรทัดกับนิพจน์ทั่วไป "เริ่มต้นด้วยปี 2014" จากนั้นให้ตัดเดือน สุดท้าย เราใช้ชุดค่าผสม sort และ uniq เพื่อพิมพ์รายการเพียงครั้งเดียว