The PyMiers

10x engineer - cắt giảm chi phí 10 lần


10x engineer là một thần thoại (myth) lâu đời trong giới IT, mơ tưởng về 1 developer có khả năng code "hơn" người bình thường 10 lần. Vì là "myth", nên có người tin, có người không.

The Myth

Thần thoại 3x 4x 5x ... 10x (xxxxxxxxxx)

Việc lên internet tìm kiếm 10x engineer trên thế giới không quá khó khăn, nhưng gặp khi đi làm ngoài thực tế là chuyện không nhiều. 10x thế giới tạm kể:

những ví dụ trên chỉ phục vụ mục đích dễ hình dung, bởi họ thuộc cỡ 100 hay 1000x chứ không phải 10x. Bí quyết là gì không rõ, nhưng điểm chung: họ đều đã ngoài 40 và dành hơn nửa cuộc đời làm software. Không có ai 30 đã về nghỉ hay lên làm manager cả.

Tiêu chí 10x không rõ ràng, vì đây là "myth", nên mỗi người nghĩ theo 1 kiểu. Theo một tiêu chí ví dụ, mrX gõ nhanh hơn mrY 10 lần, nên cũng có khi được gọi là 10x engineer.

Bài viết này không liên quan tới chuyện các 10x nói trên, mà đơn giản chỉ là tiết kiệm 10x chi phí chạy code Python, nhờ được học Python "tử tế".

Ví dụ

Sinh ra 1 file .log.gz chứa 1_500_000 dòng (từ 3 dòng lặp đi lặp lại)

import gzip

lines = [
    'http 2015-05-13T23:39:43.945958Z my-loadbalancer 192.168.131.39:2817 10.0.0.1:80 0.000073 0.001048 0.000057 200 200 0 29 "GET http://www.example.com:80/index HTTP/1.1" "curl/7.38.0" - - arn:aws:elasticloadbalancing:us-west-2:123456789012:targetgroup/my-targets/73e2d6bc24d8a067 "Root=1-58337262-36d228ad5d99923122bbe354"',
    'https 2015-05-13T23:39:43.945958Z my-loadbalancer 192.168.131.39:2817 10.0.0.1:80 0.000086 0.001048 0.001337 200 200 0 57 "GET https://mytest-111.ap-northeast-1.elb.amazonaws.com:443/p/a/t/h?foo=bar&hoge=fuga HTTP/1.1" "curl/7.38.0" DHE-RSA-AES128-SHA TLSv1.2 arn:aws:elasticloadbalancing:us-west-2:123456789012:targetgroup/my-targets/73e2d6bc24d8a067 "Root=1-58337262-36d228ad5d99923122bbe354"',
    'https 2015-05-13T23:39:43.945958Z my-loadbalancer 192.168.131.39:2817 10.0.0.1:80 0.000086 0.001048 0.001337 200 200 0 57 "GET https://mytest-111.ap-northeast-1.elb.amazonaws.com:443/p/a/t/h?foo=bar&hoge=fuga:904abc HTTP/1.1" "curl/7.38.0" DHE-RSA-AES128-SHA TLSv1.2 arn:aws:elasticloadbalancing:us-west-2:123456789012:targetgroup/my-targets/73e2d6bc24d8a067 "Root=1-58337262-36d228ad5d99923122bbe354"',
]
with gzip.open("bigfile.log.gz", "wb") as fout:
    i = 0
    while i < 1_500_000:
        line = lines[i % len(lines)] + "\n"
        fout.write(line.encode('utf-8'))
        i = i + 1

File này có kích thước khá nhỏ (<10MB)

$ python makelog.py; ls -la bigfile.log.gz
-rw-rw-r-- 1 hvn hvn 2960897 Jun 30 22:42 bigfile.log.gz
$ gunzip bigfile.log.gz; wc -l bigfile.log; ls -l bigfile.log
1500000 bigfile.log
-rw-rw-r-- 1 hvn hvn 559000000 Jun 30 22:42 bigfile.log
$ ls -lh bigfile.log
-rw-rw-r-- 1 hvn hvn 534M Jun 30 22:42 bigfile.log

nhưng khi giải nén, kích thước lớn hơn rất nhiều lần (do dữ liệu trùng lặp nhiều nên nén lại từ to thành rất nhỏ).

Đây là đoạn code ban đầu, nó đọc các dòng text từ 1 file có đuôi .log.gz ra. Hãy xem kỹ xem bạn có thể "tối ưu" được bao nhiêu bước và trở thành mấy x từ đây?

Code albv1.py

import gzip

i = 0
with gzip.open("bigfile.log.gz", "rt") as f:
    for line in f.readlines():
        i = i + 1
        if i == 10:
            break

print("Proceeded {} lines".format(i))

File nén có đuôi .gz được tạo bởi các chương trình gzip, bên dưới dùng thư viện zlib. Thư viện gzip của Python cho phép mở file .gz như file text bình thường, nó thực hiện giải nén phía sau bức màn bí mật. Mode mở file rt giúp lib gzip hiểu ta muốn thu được str sau khi giải nén, còn khi mặc định nó mở ở mode rb, trả về kiểu bytes. Chạy đoạn code trên, sử dụng /usr/bin/time -v để đo thời gian chạy và các thông số chi tiết về bộ nhớ max. (trên MacOS dùng -l)

$ /usr/bin/time -v python3 albv1.py
Proceeded 10 lines
    ...
    Maximum resident set size (kbytes): 693652
    ...

Code này dùng ~ 600 MB RAM.

Sau khi thay đổi, code chỉ còn dùng ~ 9MB RAM

$ /usr/bin/time -v python3 albv2.py
Proceeded 10 lines
    ...
    Maximum resident set size (kbytes): 9752
    ...

Chỉ thay đổi duy nhất 1 dòng:

$ diff albv1.py albv2.py
12c12
<     for line in f.readlines():
---
>     for line in f:

Điều này bất kỳ học viên Pymi.vn nào cũng phát hiện ra ngay, bởi trong hệ thống bài tập đã có 1 bài xử lý file 30 triệu dòng nặng hơn 500 MB tương tự. Cách xử lý từng dòng một:

for line in f:

mà không dùng f.readlines() hay f.read(), vì chúng đọc toàn bộ nội dung file từ ổ cứng vào RAM. Chú ý cả sự chênh lệch, Python đọc file text 534MB vào thành 670MB RAM.

"Bí kíp" đọc file theo dòng này dù chẳng có gì đặc biệt, ghi rõ trong tài liệu trang chủ nhưng lại trở thành chuyện lạ với hàng ngàn bài hướng dẫn trên mạng, thậm chí cả sách cũng dạy dùng readlines. Hãy thử search github có tới hơn 2 triệu kết quả, dù cho github không search chính xác được, thì chuyện này vẫn không phải là hiếm.

Search StackOverFlow python read file into list, trả về hàng loạt kết quả cũng không ổn tí nào.

readlines hay read hoàn toàn ok khi lập trình viên làm chủ được kích thước file đầu vào (file cố định, file được cam kết là nhỏ), nhưng khi file có size tới hàng MB, nó sẽ chiếm không ít RAM để chạy chương trình.

Phiên bản v2 có thể xử lý file có kích thước lớn tùy ý, 10GB, 100GB, đều vẫn chỉ dùng < 10MB (với giả thiết kích thước mỗi dòng không quá khác biệt).

Vậy chỉ cần được học Python tử tế, đã trở thành 10x rồi.

Độ đo

Để tính mấy x cho rõ ràng, bài này sẽ sử dụng đơn vị đo mà loài người ưa chuộng nhất: tiền.

Tính tiền 1 chương trình trong 1 cái máy thì khá khó, nhưng ngày nay, khi "cloud computing" là thời thượng, chạy code trên AWS lambda giúp chuyện tính tiền dễ như học toán cấp 1. Xem AWS Lambda pricing

Tiền cũng là thước đo lý tưởng khi các công ty ngày nay đua theo "performance review", "360 review", "data driven"... Một dòng review ghi: "cắt giảm chi phí 70.000 đô la Biden/năm nhờ tối ưu code" sẽ giúp manager dễ hiểu, dễ đánh giá hơn hẳn viết "tăng tốc chương trình 100 lần nhờ tối ưu regex sử dụng non greedy-matching" hay "cải thiện tính đọc được và tính ổn định của code".

Theo thử nghiệm trên máy, hai phiên bản v1 và v2 chạy về tốc độ là như nhau (hoặc chênh 1 2 3 giây trên tổng 60s không đáng kể), thì phần còn lại của biểu thức phụ thuộc vào lượng RAM sử dụng. Tăng cấu hình RAM cho Lambda function bao nhiêu lần, thì giá gấp bấy nhiêu. Code đăng ký dùng 256 MB RAM sẽ có giá đắt gấp đôi code đăng ký 128MB. Với ví dụ trong bài, mỗi file log kích thước cỡ 300-600 MB, lập trình viên sẽ thường để mức an toàn là 1024MB (1GB) tránh tình trạng có file 800MB xuất hiện mà thiếu RAM.

Code v2 luôn dùng 10MB RAM (=> 100x), nhưng mức tối thiểu AWS Lambda cho phép là 128MB, vậy ở đây tiết kiệm 8 lần => 8x.

Cú twist giật mình: câu chuyện thực ra không đơn giản vậy, với nhiều RAM hơn, AWS Lambda sẽ cấp thêm "năng lượng" cho CPU tỷ lệ với RAM, trong ví dụ này, nếu hầu hết thời gian chương trình đều để dùng CPU, giảm 8x RAM đăng ký đồng nghĩa với giảm tốc độ CPU 8 lần. Hay kết quả là v2 chạy mất 8s x 128MB thì v1 chạy mất 1s x 1024 MB, và giá tiền là như nhau.

Lambda allocates CPU power in proportion to the amount of memory configured. Memory is the amount of memory available to your Lambda function at runtime. You can increase or decrease the memory and CPU power allocated to your function using the Memory (MB) setting. To configure the memory for your function, set a value between 128 MB and 10,240 MB in 1-MB increments. At 1,769 MB, a function has the equivalent of one vCPU (one vCPU-second of credits per second).

Lambda configuration memory

Theo tài liệu này, nếu function chỉ sử dụng 1 core (code không sử dụng thư viện multiprocess), tốc độ CPU của nó đạt tối đa khi cấu hình 1769MB, dù có tăng RAM lên 2048MB thì chỉ tăng thêm 1 core nữa chứ không làm core ban đầu mạnh lên, hay nói cách khác: không làm code chạy nhanh hơn.

PS: trong môi trường lượng CPU là cố định (máy ảo, máy vật lý...), v2 vẫn là 100x.

Cú twist số 2: việc tính tiền trên các hệ thống cloud không hề đơn giản, có hàng ngàn dịch vụ cung cấp giải pháp phân tích, đọc hiểu, tối ưu code cloud. Hay mọc cả ra nghề FinOps chuyên về tối ưu hóa cloud cost, ngành kinh tế trên mây (cloud economics) với các chuyên gia có nghệ danh "cloud economist".

Kết luận 1: 100x là có thật, nhưng còn phụ thuộc vào hoàn cảnh, không nằm ngoài "thuyết tương đối". Việc giảm 8x RAM ở đây không làm giảm chi phí, công việc tiếp theo là cắt giảm chi phí bằng cách tăng tốc code.

Tuy không cải thiện về đơn vị đo của bài này là tiền, nhưng một đoạn code không chỉ có mỗi tiền, ngoài hiệu năng, nó còn nhiều tiêu chí khác khó đánh giá hơn như "tính đọc được" (code dễ đọc), "tính ổn định",... Dùng for line in f cải thiện được tính ổn định của chương trình, cho phép nó chạy ngon lành khi kích thước file đầu vào tăng lên - trong khi chương trình ban đầu sẽ lỗi do không đủ RAM.

Tăng tốc regex

Phiên bản sau thêm công đoạn xử lý từng dòng để lọc ra các giá trị mong muốn, sử dụng công cụ: "regular expression" - hay gọi ngắn là regex. Bạn đọc không nên quá tập trung hay sợ hãi khi nhìn vào phần "pattern" viết đống giun dế gì, vì không nhiều người có khả năng đọc, hiểu, phân tích đoạn này, kể cả có 10 năm đi code hay làm sysadmin. Code regex thường khó đọc khó hiểu, khi cần dùng chủ yếu các lập trình viên đi copy, đoạn bên dưới cũng là copy từ link trong comment.

import gzip
import regex

# copied and edited from https://gist.github.com/szinck/d456fbf691483ab77d2453c316db3371
pattern = '(.*?) (.*?) (.*?) ([0-9.]+):([0-9]*) ([0-9.]+):([0-9]*) ([.0-9]*) ([.0-9]*) ([.0-9]*) (-|[0-9]*) (-|[0-9]*) ([-0-9]*) ([-0-9]*) "(.*?) .*:([0-9]+)([^? ]*)(\\x3f?.*?) (.*?)" "(.*?)" (.*?) (.*?) (.*?) "(.*?)" *$'
# example in AWS docs does not work directly with python https://docs.aws.amazon.com/athena/latest/ug/application-load-balancer-logs.html

p = re.compile(pattern)

i = 0
with gzip.open("bigfile.log.gz", "rt") as f:
    for line in f.readlines():
        i = i + 1
        m = p.match(line)
        if m:
            result = " ".join(m.group(17, 11))
            # print("sending", result)
        if i == 10:
            break

print("Proceeded {} lines".format(i))

Không hiểu gì thì làm sao mà tăng tốc?

Học regex trong 7 phút

7 phút đủ để quán bia làm xong món "giò nóng 7 phút". Trong 7 phút đủ để bạn có kiến thức regex bằng với 90% lập trình viên trên thế giới.

regex là gì

regex là một ngôn ngữ dùng để mô tả pattern (tiếng Việt hay dịch là dạng, mẫu) của 1 giá trị. Ví dụ: một số điện thoại di động ở Việt Nam là một số có 10 hay 11 chữ số. Các pattern sau sẽ "match" (khớp mẫu) số điện thoại:

  • \d+
  • [0-9]+

Hai pattern này tương đương, nó sẽ match với 1 hoặc nhiều chữ số viết liền nhau. Dấu + theo sau là biểu diễn cho "1 hoặc nhiều". Phổ biến không kém dấu +, là dấu *. Dấu * có nghĩa là match 0 hoặc nhiều:

  • \d*
  • [0-9]*

cũng sẽ match số điện thoại di động ở Việt Nam.

Dùng + khẳng định phải có ít nhất 1 số từ 0 đến 9 (ký hiệu [0-9]), thì dùng * dễ dãi hơn, không có số nào cũng được. Pattern .* là pattern phổ biến nhất với người học regex với thời lượng dưới 5 ngày.

. đại diện cho 1 ký tự nào đó, nào cũng được, a b c hay 0 1 2 hay % = # gì cũng ok. .* là pattern match được mọi thứ.

Tránh nhầm lẫn dấu * hay thấy khi gõ câu lệnh Linux, kiểu như ls ~/*.py, * này không phải regex, đây là khái niệm globbing, mặc dù tác dụng hơi giống, nó sẽ trả về tất cả các tên file có đuôi .py

Dấu ? match 0 hoặc 1 lần, pattern https? sẽ match cả http lẫn https.

Dùng trang regex101.com để thử các pattern và xem kết quả cho tiện.

Hay bật python3 lên rồi gõ

>>> import re
>>> re.findall('.*', '0987654321')
['0987654321', '']

Có thể chỉ định số lần match với cú pháp {ít nhất, nhiều nhất}, pattern 0[0-9]{9, 10} match số điện thoại di động ở Việt Nam.

Đơn giản, đúng không? Hãy viết 1 đoạn regex để kiểm tra 1 email có hợp lệ không.

Mọi người đều biết "chung chung" là email có dạng gìđó@gìđấy.đuôi, vậy regex có thể là .+@.+\..+. Chú ý dấu . trong tên miền phải gõ \., vì dấu . là 1 ký hiệu regex đặc biệt đã nói ở trên. Đây là regex đầy đủ để kiểm tra 1 địa chỉ email, và không có một ai trên trái đất này cho rằng nó đơn giản cả.

Đến đây, đã có 1 manh mối để tối ưu tốc độ rồi... re là standard library của Python, có sẵn, không cài gì cả. Nhưng đoạn code trên lại import 1 thư viện tên regex. Đây là thư viện phải cài thêm,

This regex implementation is backwards-compatible with the standard ‘re’ module, but offers additional functionality.

Thử thay regex bằng re giúp cắt giảm 10s trong đoạn code chạy 60s trên máy tác giả. Có thể "đoán" rằng re có trong stdlib và được tối ưu đủ trò nên chạy nhanh hơn. Những việc đoán này phải dựa trên cơ sở đo. Để đo tốc độ trong Python, python có sãn thư viện cProfile.

Profiling Python với cProfile

Thay regex bằng re, chạy lại đoạn code với câu lệnh sau để xem các function nào dùng nhiều thời gian nhất/gọi nhiều lần nhất.

  • tottime total time: tổng thời gian function chạy sau N lần, không tính chuyện gọi function khác.
  • cumtime cummulative time: tổng thời gian function chạy sau N lần, bao gồm cả việc gọi các function khác.
$ /usr/bin/time -v python3 -m cProfile -s tottime albv1.py
Proceeded 50000 lines
         252074 function calls (251832 primitive calls) in 45.948 seconds

   Ordered by: internal time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    50000   45.834    0.001   45.834    0.001 {method 'match' of 're.Pattern' objects}
        1    0.033    0.033   45.948   45.948 albv1.py:1(<module>)
        1    0.016    0.016    0.061    0.061 {method 'readlines' of '_io._IOBase' objects}
     2277    0.014    0.000    0.014    0.000 {built-in method zlib.crc32}
    50000    0.012    0.000    0.012    0.000 {method 'group' of 're.Match' objects}
     2275    0.008    0.000    0.008    0.000 {method 'decompress' of 'zlib.Decompress' objects}
    50054    0.005    0.000    0.005    0.000 {method 'join' of 'str' objects}
    52282    0.004    0.000    0.004    0.000 gzip.py:314(closed)
     2276    0.004    0.000    0.034    0.000 _compression.py:66(readinto)

Kết quả cho thấy hầu hết thời gian đều dùng vào việc chạy regex method match. re viết bằng C, lẽ ra phải chạy rất nhanh, thì khi copy thử pattern và 1 ví dụ lên regex101, sẽ thấy lý do vì sao nó chậm. Để kiểm tra pattern có match string ví dụ sau không, re phải dùng tới 112690 bước!!!

http 2015-05-13T23:39:43.945958Z my-loadbalancer 192.168.131.39:2817 10.0.0.1:80 0.000073 0.001048 0.000057 200 200 0 29 "GET http://www. example.com:80/index HTTP/1.1" "curl/7.38.0" - - arn:aws:elasticloadbalancing:us-west-2:123456789012:targetgroup/my-targets/73e2d6bc24d8a067 " Root=1-58337262-36d228ad5d99923122bbe354"

con số này quá lớn, dù có viết đoạn code lằng nhằng với 20 câu if, cũng không thể tới 112690 bước. Tăng tốc regex không phải chuyện dễ, nhưng có 1 tip rất phổ biến: chỗ nào dùng .* chỗ đó có vẻ chậm/sai/cần tối ưu (khác với .*?).

Đoạn regex mới

pattern = '(.*?) (.*?) (.*?) ([0-9.]+):([0-9]*) ([0-9.]+):([0-9]*) ([.0-9]*) ([.0-9]*) ([.0-9]*) (-|[0-9]*) (-|[0-9]*) ([-0-9]*) ([-0-9]*) "(.*?) https?://[^:]+:([0-9]+)([^? ]*)(\\x3f?.*?) (.*?)" "(.*?)" (.*?) (.*?) (.*?) "(.*?)" *$'

có 1 điểm khác so với đoạn cũ

pattern = '(.*?) (.*?) (.*?) ([0-9.]+):([0-9]*) ([0-9.]+):([0-9]*) ([.0-9]*) ([.0-9]*) ([.0-9]*) (-|[0-9]*) (-|[0-9]*) ([-0-9]*) ([-0-9]*) "(.*?) .*:([0-9]+)([^? ]*)(\\x3f?.*?) (.*?)" "(.*?)" (.*?) (.*?) (.*?) "(.*?)" *$'

chỗ .*:([0-9]+) dùng để match domain và port như https://pymi.vn:443, thay .* trong đoạn này với https?://[^:]+ cho tác dụng tương đương. https?://[^:]+ match 1 đoạn text bắt đầu bằng http hay https, rồi :// rồi bất cứ thứ gì cho tới khi gặp dấu : thì dừng lại. Đoạn này match sau 524 bước

Chú ý đoạn code mới cho rằng mọi url đều bắt đầu với http hay https, điều này có thể sai (ví dụ wss:// cho websocket), tùy theo yêu cầu bài toán.

Một cách khác, là dùng pattern [^:]+:[^:]+: match mọi thứ có dạng something:something dừng lại khi gặp dấu : thứ 2. Pattern sẽ match wss://abcde trong string wss://abcde:443, pattern này match sau 518 bước.

Một cách khác nữa, là dùng .+?:.+?:. +* bình thường sẽ match nhiều nhất có thể, thì khi thêm ? sau nó, +? hay *? sẽ match ít nhất có thể. Đây gọi là tính năng non-greedy Cho string abcdabcd, a.+d sẽ match abcdabcd nhưng a.+?d chỉ match abcd. Pattern này match sau 543 bước.

Dấu đóng mở ngoặc () dùng để capture kết quả, kết quả match thành công sẽ được lưu lại thành 1 group, đánh theo thứ tự xuất hiện. Đoạn code trong bài lấy ra group 17 và 11 từ kết quả match.

$ /usr/bin/time -v python3 -m cProfile -s tottime albv1_regex.py

Proceeded 50000 lines
         252201 function calls (251956 primitive calls) in 0.310 seconds

   Ordered by: internal time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    50000    0.208    0.000    0.208    0.000 {method 'match' of 're.Pattern' objects}
        1    0.026    0.026    0.310    0.310 albv1_regex.py:1(<module>)
        1    0.016    0.016    0.061    0.061 {method 'readlines' of '_io._IOBase' objects}
     2277    0.014    0.000    0.014    0.000 {built-in method zlib.crc32}
    50000    0.008    0.000    0.008    0.000 {method 'group' of 're.Match' objects}
     2275    0.008    0.000    0.008    0.000 {method 'decompress' of 'zlib.Decompress' objects}
    52282    0.004    0.000    0.004    0.000 gzip.py:314(closed)
    50054    0.004    0.000    0.004    0.000 {method 'join' of 'str' objects}
     2276    0.004    0.000    0.030    0.000 gzip.py:454(read)

45 giây -> xuống còn 0.3 giây cho ta cảm giác code mới chắc là sai nên mới 150x như vậy.

Sửa regex xong làm sao biết đúng sai?

Một cách đơn giản là thử, cho 2 pattern match và lấy kết quả ra rồi so sánh lần lượt với mỗi dòng log, qua cả file đều giống nhau là có vẻ ổn rồi.

p1 = re.compile(pattern1)
p2 = re.compile(pattern2)

for line in f:
    m1 = p1.match(line)
    m2 = p2.match(line)
    if m1:
        assert m1.groups() == m2.group(), (m1, m2, line)

PS: khi tối ưu đoạn code này, vô tình phát hiện ra đoạn code ban đầu xử lý không đúng khi URL path có chứa dấu :, 3 phiên bản mới không gặp phải vấn đề này.

Kết luận 2: 150x là có thật và không cần phải học "regex" nâng cao.

Học và dùng regex

Python có viết 1 tài liệu cơ bản về regex trong mục howto, nếu một ngày buồn chán quá không có gì làm, hay muốn tìm ý nghĩa của cuộc sống, bạn có thể ngồi học regex.

xkcd

Hoặc đi tìm một "khóa học regex"? cái này chưa có, cơ hội khởi nghiệp làm giàu còn rất rộng mở cho các chuyên gia công nghệ bán "khoá học làm chủ regex để học sâu với trí tuệ nhân tạo 4.0".

Regex là một công cụ mạnh, nhưng khó dùng đúng, nó giải quyết được 1 số bài toán, 1 số thì không và nên dùng cách khác đơn giản hơn như parse HTML.

regex nổi tiếng phức tạp, và từng tạo ra không ít sự cố trong các hệ thống lớn toàn cầu.

Some people, when confronted with a problem, think "I know, I'll use regular expressions." Now they have two problems.

Khi một bài toán có thể giải quyết theo 1 cách khác đơn giản hơn, thì nên tránh dùng regex.

Chú ý: trong ví dụ này, nhằm mục tiêu giữ lại code gần giống với code ban đầu nhất, không thay đổi quá nhiều, nên đã không viết lại đoạn code lọc ra urlpath và statuscode mà vẫn dùng regex.

Tăng tốc gửi message đến kafka

Kafka là gì

Apache Kafka is an open-source distributed event streaming platform used by thousands of companies for high-performance data pipelines, streaming analytics, data integration, and mission-critical applications.

https://kafka.apache.org/

Nói đơn giản, Kafka như hệ thống ống nước, mạng lưới điện, mạng lưới viễn thông, nó đủ tính năng để đáp ứng mọi nhu cầu truyền tải dữ liệu từ nhiều nguồn đến nhiều đích. Kafka được dùng phổ biến trong các doanh nghiệp, các hệ thống xử lý data, logging...

Kafka có nhiều tính năng, bài này sử dụng nó như 1 hệ thống pub-sub, tức có 1 bên gửi message đi, và 1/nhiều bên nhận message.

Cài đặt kafka

Cài Java

sudo apt-get update && sudo apt-get install -y openjdk-11-jre-headless

Cài đặt kafka đơn giản với 5 bước không cần sudo

curl -LO https://mirror.downloadvn.com/apache/kafka/2.8.0/kafka_2.13-2.8.0.tgz
tar xvf kafka_2.13-2.8.0.tgz
cd kafka_2.13-2.8.0
bin/zookeeper-server-start.sh config/zookeeper.properties
## mở 1 terminal khác
cd kafka_2.13-2.8.0
bin/kafka-server-start.sh config/server.properties

Python Kafka producer

Phiên bản đầy đủ của chương trình trước khi mang đi tối ưu: nó đọc file log AWS ALB đã nén .gz, lấy ra urlpath và status code bằng regex, rồi gửi kết quả đến kafka.

pip install kafka-python
import gzip
import re
from kafka import KafkaProducer

producer = KafkaProducer(linger_ms=5, batch_size=65536, acks=0, compression_type="lz4")

pattern = '(.*?) (.*?) (.*?) ([0-9.]+):([0-9]*) ([0-9.]+):([0-9]*) ([.0-9]*) ([.0-9]*) ([.0-9]*) (-|[0-9]*) (-|[0-9]*) ([-0-9]*) ([-0-9]*) "(.*?) [^:]+:[^:]+:([0-9]+)([^? ]*)(\\x3f?.*?) (.*?)" "(.*?)" (.*?) (.*?) (.*?) "(.*?)" *$'
p = re.compile(pattern)

i = 0
with gzip.open("bigfile.log.gz", "rt") as f:
    for line in f:
        i = i + 1
        if i % 10000 == 0:
            print(i)
        m = p.match(line)
        if m:
            result = " ".join(m.group(17, 11))
            producer.send("alblog", result.encode("utf-8"))

print("Processed {} lines".format(i))

Khi chưa gửi message tới kafka, code chạy mất 8s, khi gửi đến kafka trên cùng máy, code chạy mất 60s (khi profile chậm hơn nữa do quá trình profile can thiệp ảnh hưởng tới tốc độ):

Processed 1500000 lines
         133875187 function calls (133873425 primitive calls) in 91.895 seconds

   Ordered by: internal time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
  1500001    8.978    0.000    8.978    0.000 {method 'match' of 're.Pattern' objects}
  1500000    8.602    0.000   73.735    0.000 kafka.py:538(send)
  1500282    7.845    0.000   14.095    0.000 default_records.py:406(append)
  1500000    6.948    0.000   39.138    0.000 record_accumulator.py:200(append)
  1500282    4.675    0.000   28.579    0.000 record_accumulator.py:57(try_append)
        1    4.299    4.299   92.439   92.439 albv1_regex2.py:1(<module>)
  1500000    4.147    0.000    6.439    0.000 future.py:32(__init__)
  7501128    3.138    0.000    4.001    0.000 util.py:10(encode_varint)
  1500000    2.754    0.000   12.242    0.000 kafka.py:716(_partition)
  3000001    2.270    0.000    2.688    0.000 cluster.py:106(partitions_for_topic)
  1500000    1.946    0.000    4.090    0.000 cluster.py:119(available_partitions_for_topic)
  1500000    1.840    0.000    4.318    0.000 kafka.py:664(_wait_on_metadata)
    65554    1.721    0.000    1.721    0.000 {built-in method zlib.crc32}
  1500000    1.682    0.000    2.811    0.000 default_records.py:563(size_of)
15397286/15397055    1.615    0.000    1.615    0.000 {built-in method builtins.len}
...

Việc gửi 1.5 triệu message tới kafka chạy cùng máy mất tới 73s (cumtime) trong output profiling. Trong đó có dòng thứ 3, 4 và 5 đều là "append". Mở code của thư viện kafka-python ra xem, phần này append các message vào 1 list "accumulator", để bao giờ đủ 65536 phần tử mới gửi đi (batch_size=65536 lúc tạo producer). Batching là tính năng phổ biến trong các thư viện liên quan tới network, do việc gửi nhận qua network thường chậm, nên gom lại một đống rồi gửi đi để giảm số lần gửi/nhận. Nhưng trong ví dụ này, việc batching tốn tới 20s thì có vẻ không ổn. Sau một hồi chỉnh sửa các tham số (batch_size, linger_ms ...), giải pháp lại là "think outside of the box", tìm xem Python còn có thư viện kafka nào khác không.

Thư viện confluent-kafka-python sử dụng librdkafka viết bằng C hứa hẹn cho một performance tốt hơn nhiều

import gzip
import re
from confluent_kafka import Producer


producer = Producer(
    {'bootstrap.servers': "localhost:9092",
    'queue.buffering.max.messages': 65536,
    'acks': 0,
     'compression.type': 'lz4'}
)


pattern = '(.*?) (.*?) (.*?) ([0-9.]+):([0-9]*) ([0-9.]+):([0-9]*) ([.0-9]*) ([.0-9]*) ([.0-9]*) (-|[0-9]*) (-|[0-9]*) ([-0-9]*) ([-0-9]*) "(.*?) [^:]+:[^:]+:([0-9]+)([^? ]*)(\\x3f?.*?) (.*?)" "(.*?)" (.*?) (.*?) (.*?) "(.*?)" *$'

p = re.compile(pattern)

i = 0
with gzip.open("bigfile.log.gz", "rt") as f:
    for line in f:
        i = i + 1
        if i % 10000 == 0:
            print(i)
        m = p.match(line)
        if m:
            result = " ".join(m.group(17, 11))
            try:
                producer.produce("alblog", result.encode("utf-8"))
                producer.poll(0)
            except BufferError:
                print("Buffer full, waiting for free space on the queue")
                producer.poll(1)
    producer.flush()

print("Processed {} lines".format(i))

và thực nghiệm thấy đúng là như thế:

Processed 1500000 lines
         11882360 function calls (11882085 primitive calls) in 21.700 seconds

   Ordered by: internal time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
  1500000    9.328    0.000    9.328    0.000 {method 'match' of 're.Pattern' objects}
  1500000    4.197    0.000    4.197    0.000 {method 'produce' of 'cimpl.Producer' objects}
        1    3.457    3.457   21.700   21.700 albv1_regex2.py:1(<module>)
  1500000    1.511    0.000    1.511    0.000 {method 'poll' of 'cimpl.Producer' objects}
    65554    0.519    0.000    0.519    0.000 {built-in method zlib.crc32}
  1500000    0.410    0.000    0.410    0.000 {method 'group' of 're.Match' objects}
    65552    0.386    0.000    0.386    0.000 {method 'decompress' of 'zlib.Decompress' objects}
  1565559    0.255    0.000    0.255    0.000 gzip.py:314(closed)
  1500117    0.232    0.000    0.232    0.000 {method 'join' of 'str' objects}
    65553    0.218    0.000    1.687    0.000 _compression.py:66(readinto)
    65553    0.207    0.000    1.417    0.000 gzip.py:454(read)

Từ 91s -> 21.7s, ta rút gọn thêm được 4x.

Kết luận 3: thư viện có this có that, hãy tự đo và kiểm tra các options.

Kết quả

Sau 3 lần tối ưu, code mới dùng 100x ít RAM hơn, nhanh gấp 150 * 4 == 600 lần code ban đầu, chi phí giảm: 600 lần so với ban đầu. Giả sử đoạn code này hiện đang tốn $6000/tháng (6 * 12 = $72k/năm), thì sau khi tối ưu còn $10/tháng -> $120/năm.

$70.000 mỗi năm được tiết kiệm này nên dùng để thưởng nóng cho 10x dev hay chỉ thưởng $7k?

Thực tế (kinh tế) thì không phải thế, thưởng nóng $1-2-3k đã là nhiều lắm rồi. Không bàn tới chuyện quản lý doanh nghiệp/nhân sự/kinh tế ở đây, nhưng có thể thấy 1 điều, 1 lập trình viên có mức lương cao ngất ngưởng không phải là chuyện vô lý, khi họ có thể tự trả lương cho mình 1 vài năm trong vòng 1 2 ngày tối ưu code.

Kết luận

10x engineering là có thật. 10x phụ thuộc vào hoàn cảnh, tiêu chí đánh giá, nhưng học Python tại PyMi.vn rõ ràng là khoản đầu tư 10x. Việc tối ưu code, sử dụng cProfile của Python là một công việc thú vị, nhưng cần đặt vào đúng chỗ. Tối ưu đoạn code tiêu tốn $72k/năm để còn $120/năm mang lại lợi ích kinh tế khác biệt (trong môi trường doanh nghiệp) so với tối ưu đoạn code $72/năm còn $0.12/năm.

Bạn đọc đam mê có thể tiếp tục tối ưu và gửi kết quả tới tác giả bằng cách tạo 1 pull request trên GitHub. Ngoài ra, có thể viết hẳn 1 chương trình hẳn hoi giúp lấy log AWS load balancer về rồi gửi tới 1 đích đến tùy ý. Đây là một vấn đề phổ biến khi dùng AWS Load Balancer mà chưa có giải pháp triệt để.

Không phải kết luận

Giống như mọi bài viết về optimize/benchmark, kết quả rất phụ thuộc và bài toán cụ thể, môi trường (phiên bản, hệ điều hành ...) cụ thể. Bài viết này KHÔNG kết luận:

  • for line in f nhanh hay chậm hơn for line in f.readlines()
  • Lib re nhanh hơn lib regex
  • confluent-kafka-python nhanh hơn kafka-python

Kết quả có thể hoàn toàn bị đảo ngược khi test trên 1 hệ điều hành khác (như MacOS, Windows) hay một phiên bản Python/thư viện khác, hay từng đoạn code chạy riêng sẽ khác với khi 2,3 đoạn code kết hợp lại. Kết luận chỉ nên đưa ra khi đem đi chạy thật với tình huống cụ thể, đến lúc tính tiền.

References

Hết

Bài viết thực hiện trên

$ grep VERSION= /etc/os-release; python3 --version
VERSION="20.04.2 LTS (Focal Fossa)"
Python 3.8.5

HVN at http://pymi.vn and https://www.familug.org.

Comments