Ghi Chú Về Một Số Lỗi Gặp Phải Gần Đây

Ghi lại một vài lỗi kỹ thuật gần đây gặp phải

Khi code của bản thân gặp sự cố, phần lớn trường hợp tôi sẽ chọn cách viết lại. Miễn là phân chia module rõ ràng, thiết kế hợp lý, phần cần viết lại thường không quá nhiều. Tuy nhiên khi code của đồng nghiệp gặp vấn đề, đa phần chúng ta chỉ còn cách kiên nhẫn mò mẫm tìm nguyên nhân. Đây chính là tình cảnh tôi đã trải qua trong vài ngày qua.

Vài hôm trước, hệ thống của chúng tôi tiến hành nâng cấp, nhưng tình trạng hoạt động trên mạng công cộng luôn không ổn định. Lần ra mắt sản phẩm này có phần gấp gáp dù đã qua kiểm thử nội bộ. Trong giai đoạn test, mọi thứ đều diễn ra suôn sẻ, nhưng khi triển khai thực tế trên môi trường phức tạp hơn nhiều, áp lực debug tăng cao đáng kể. Đặc biệt với hệ thống phục vụ game thủ, một khi đã phát hành thì không thể tùy tiện dừng dịch vụ. Điều này khiến chúng tôi phải dựa vào cơ chế hotfix - sửa lỗi trực tiếp trên hệ thống đang chạy.

Hôm qua, một lỗi nghiêm trọng đã khiến tôi thức trắng đêm, tôi xin ghi lại chi tiết để làm bài học cảnh giác cho các vấn đề tương tự sau này.

Hệ thống vốn đã vận hành ổn định suốt 18 tiếng đồng hồ, cả ngày hôm đó đều không có biến động gì. Về mặt lý thuyết, dự án này không thuộc phạm vi trách nhiệm của tôi, tuy nhiên tôi đã implement một module liên quan đến module cốt lõi trong dự án chính, nên tôi vẫn theo dõi log vận hành thường xuyên.

Đến tận khuya, khi đang đun nước chuẩn bị tắm rồi về nhà nghỉ ngơi, trong lúc chờ đợi tôi vừa lật xem cuốn sách phổ biến kiến thức vũ trụ học, vừa liếc nhìn log của module mình viết. Bỗng nhiên phát hiện vài điểm bất thường.

Dù các gói dữ liệu vẫn còn hợp lệ, nhưng luồng dữ liệu đầu vào có vẻ không bình thường. Tôi lập tức tập trung cao độ để tìm hiểu nguyên nhân. Sau khi kiểm tra sơ bộ hệ thống, phát hiện ra toàn bộ hệ thống đã không còn hoạt động bình thường. Lúc này đã qua 12 giờ đêm, văn phòng chỉ còn mình tôi, chắc hẳn đồng nghiệp đều đã ngủ say. Tôi quyết định tự mình xử lý vấn đề này.

Tôi dành thời gian xem xét kỹ lưỡng log của tất cả các subsystem, truy vết luồng dữ liệu bất thường. Vì phần lớn code trước đó tôi chưa từng đọc qua, việc đối chiếu phân tích gặp không ít khó khăn.

Hiện tượng bất thường là: Trong một số trường hợp đặc biệt, sẽ có luồng dữ liệu lạ đi qua hệ thống của tôi. Tuy nhiên trên log, không có hệ thống nào ghi nhận việc phát sinh các gói dữ liệu này. Sau khi hiểu rõ luồng dữ liệu, tôi đã đọc qua code của tất cả các subsystem nghi ngờ có lỗi (trong đó phát hiện hai chỗ xử lý chưa đúng các trường hợp biên, tôi đã sửa luôn trên đường đi), nhưng vẫn không tìm ra nguyên nhân gốc rễ.

Thực ra lỗi này đã từng xảy ra vào đêm hôm kia, nhưng khi tôi nêu vấn đề vào hôm sau, không ai nghĩ code của mình gây ra sự cố. Trong khi đó hệ thống lại vận hành ổn định suốt cả ngày, khiến tôi vô cùng bực bội. Là lập trình viên, chúng tôi đều tin rằng: Nếu lỗi đã từng xuất hiện, sẽ không thể tự động biến mất. Tình trạng này khiến tâm lý vô cùng khó chịu, bực tức.

Có đồng nghiệp còn nghi ngờ có thể do hệ thống phần cứng gặp vấn đề, vì trong giai đoạn test nội bộ chưa từng xảy ra sự cố tương tự. Ban đầu tôi kiên định cho rằng chắc chắn là do lỗi implement của chúng tôi, nhưng sau một ngày vật lộn với code, đến tận đêm khuya tinh thần suy nhược gần như muốn từ bỏ niềm tin.

Quá trình debug gian nan giữa chừng tôi xin không mô tả chi tiết. Chỉ có thể nói là trải qua trăm thử nghìn tra, đầu óc quay cuồng, cuối cùng sáng nay cùng đồng nghiệp vừa đến công ty đã xác định được nguyên nhân cốt lõi:

Hệ thống của chúng tôi là kiến trúc đa tiến trình, trong đó một subsystem có chứa manager, manager này sẽ fork tiến trình con để khởi động các subsystem cấp dưới. Sau khi fork xong, nó đóng luôn file descriptor stdout của chính mình. Tiến trình con vốn không dùng printf để ghi log nên không có vấn đề gì. Nhưng vấn đề nằm ở thư viện do một đồng nghiệp tiền nhiệm viết, khi tiến trình bất thường thoát ra, có thể dùng printf để in ra một số thông tin. Cần lưu ý rằng: printf thuộc CRT library, có cơ chế buffer ở user space. Khi tiến trình thoát, buffer này sẽ được flush ra stdout.

Vấn đề nằm ở chỗ: stdout đã bị đóng, nhưng socket dùng để giao tiếp với bên ngoài của manager lại quên đóng sau khi fork tiến trình con. Mà socket quan trọng này lại trùng số hiệu file descriptor với stdout. Hậu quả là: dữ liệu giao tiếp giữa các subsystem lớn bị chèn ngẫu nhiên bởi tiến trình đáng lẽ phải bị cô lập, mà không ai biết nguồn gốc từ đâu. Trong file log hàng trăm MB, lỗi này xảy ra ngẫu nhiên, phần lớn bị lọc bỏ nên không gây ảnh hưởng nghiêm trọng. Nhưng hạt giống bug này đã tồn tại lâu dài mà không ai để ý.

Cho đến khi một hệ thống khác kích hoạt điều kiện biên xử lý ngoại lệ, nhánh code chưa từng được test này mới bộc lộ bug, kết hợp với lỗi trên khiến toàn bộ hệ thống tê liệt.

P/s: Vụ việc lần này không chỉ mang lại bài học về quản lý dự án và code, mà còn để lại kinh nghiệm kỹ thuật quan trọng: Đừng vội vàng đóng stdout, thay vào đó hãy redirect nó đến thiết bị null.

Ban đầu định tiếp tục chia sẻ thêm vài lỗi khác nữa, nhưng viết đến đây đã mất hết hứng thú. Vấn đề đã được giải quyết, có thể yên tâm đón Tết Thanh Minh. Chúc mọi người nghỉ lễ vui vẻ!