How to debug the slowness in docker container

[felixgao]

Inside an Linux container

Using command .venv/bin/uvicorn with args app.service.server:app
[2024-02-27T00:14:15+0000] INFO [] module=init: config: log_level='INFO' expose_metrics=False mesh_port=8090
[2024-02-27T00:14:17+0000] INFO [] module=ocr: config_file='/app/config.yaml'
[2024-02-27T00:14:19+0000] INFO [] module=init: Registered app routers
[2024-02-27T00:14:19+0000] INFO [] module=init: Created app [PaddleOCRService]!
INFO: Started server process [1]
INFO: Waiting for application startup.
INFO: Application startup complete.
INFO: Uvicorn running on http://0.0.0.0:8090 (Press CTRL+C to quit)
[2024-02-27T00:14:28+0000] INFO [tid=71ea9130-0ce4-4461-891d-82c5e806903e] module=ocr: Converting Image file to text
[2024-02-27T00:14:28+0000] INFO [tid=71ea9130-0ce4-4461-891d-82c5e806903e] module=ocr: Loaded image to memory
[2024-02-27T00:14:29+0000] INFO [tid=71ea9130-0ce4-4461-891d-82c5e806903e] module=ocr: Converted Image color space to BGR
2024/02/27 00:15:28 [error] 24#24: *1 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 172.17.0.1, server: , request: "POST /ocr/file HTTP/1.1", upstream: "http://127.0.0.1:8090/ocr/file", host: "localhost:8443"
[2024-02-27T00:24:27+0000] INFO [intuit_tid=71ea9130-0ce4-4461-891d-82c5e806903e] module=ocr: OCRed Image

It seems to take 10 minutes before I can OCR an image that is 1.7MB.

However, when I directly use the package on the command line it only takes a few seconds

On my M1 Mac

❯ time poetry run rapidocr_onnxruntime --print_verbose -img ~/Downloads/Costco.jpg
config={'Global': {'text_score': 0.5, 'use_det': True, 'use_cls': True, 'use_rec': True, 'print_verbose': True, 'min_height': 30, 'width_height_ratio': 8, 'img_path': '/Users/gg/Downloads/Costco.jpg', 'print_cost': False, 'no_det': False, 'no_cls': False, 'no_rec': False, 'vis_res': False, 'vis_font_path': None, 'vis_save_path': '.'}, 'Det': {'use_cuda': False, 'model_path': '/Users/gg/intuit/github/cortex/paddleocrservice/.venv/lib/python3.11/site-packages/rapidocr_onnxruntime/models/ch_PP-OCRv4_det_infer.onnx', 'limit_side_len': 736, 'limit_type': 'min', 'thresh': 0.3, 'box_thresh': 0.5, 'max_candidates': 1000, 'unclip_ratio': 1.6, 'use_dilation': True, 'score_mode': 'fast'}, 'Cls': {'use_cuda': False, 'model_path': '/Users/gg/intuit/github/cortex/paddleocrservice/.venv/lib/python3.11/site-packages/rapidocr_onnxruntime/models/ch_ppocr_mobile_v2.0_cls_infer.onnx', 'cls_image_shape': [3, 48, 192], 'cls_batch_num': 6, 'cls_thresh': 0.9, 'label_list': ['0', '180']}, 'Rec': {'use_cuda': False, 'model_path': '/Users/gg/intuit/github/cortex/paddleocrservice/.venv/lib/python3.11/site-packages/rapidocr_onnxruntime/models/ch_PP-OCRv4_rec_infer.onnx', 'rec_img_shape': [3, 48, 320], 'rec_batch_num': 6, 'rec_keys_path': None}}
[[[[420.0, 131.0], [967.0, 131.0], [967.0, 239.0], [420.0, 239.0]], 'STCO', 0.6921928286552429], [[[423.0, 247.0], [965.0, 246.0], [965.0, 303.0], [423.0, 304.0]], 'WHOLESALE', 0.8858321487903595], [[[197.0, 363.0], [713.0, 379.0], [711.0, 422.0], [195.0, 406.0]], 'NE San Jose', 0.8130927334229151], [[[711.0, 381.0], [955.0, 371.0], [957.0, 411.0], [713.0, 421.0]], ' #1 004', 0.7951146960258484], [[[282.0, 418.0], [878.0, 428.0], [878.0, 477.0], [281.0, 467.0]], '1709 Automation Parkway', 0.957424725095431], [[[330.0, 473.0], [796.0, 480.0], [795.0, 530.0], [329.0, 523.0]], 'San Jose, CA 95131', 0.9394202702923825], [[[383.0, 533.0], [745.0, 538.0], [744.0, 581.0], [382.0, 576.0]], '(408) 678-2150', 0.9319113612174987], [[[81.0, 687.0], [659.0, 707.0], [657.0, 760.0], [79.0, 740.0]], '1Ul Member 111803047855', 0.8939815933505694], [[[236.0, 756.0], [733.0, 765.0], [732.0, 808.0], [236.0, 799.0]], '654260 MELAT0NIN5MG', 0.9123572826385498], [[[862.0, 758.0], [1048.0, 748.0], [1051.0, 796.0], [865.0, 806.0]], '11.99 A', 0.8563249334692955], [[[130.0, 805.0], [629.0, 818.0], [628.0, 864.0], [128.0, 851.0]], '0000297987 / 654260', 0.9465338379144669], [[[884.0, 813.0], [1048.0, 803.0], [1051.0, 851.0], [887.0, 861.0]], '3.00-A', 0.8529943483216422], [[[260.0, 866.0], [681.0, 875.0], [680.0, 921.0], [259.0, 912.0]], '47537 R0TISSERIE', 0.9378023533260121], [[[885.0, 868.0], [1049.0, 860.0], [1052.0, 909.0], [887.0, 917.0]], '4.75 A', 0.8108115877423968], [[[66.0, 911.0], [103.0, 911.0], [103.0, 1097.0], [66.0, 1097.0]], 'FEEL', 0.776979672908783], [[[231.0, 920.0], [733.0, 930.0], [732.0, 977.0], [230.0, 967.0]], '536099 KS ALLGY 600', 0.9446307182312011], [[[883.0, 925.0], [1049.0, 917.0], [1051.0, 965.0], [885.0, 973.0]], '4.49 A', 0.8541683810097831], [[[255.0, 977.0], [729.0, 986.0], [728.0, 1033.0], [254.0, 1024.0]], '91655 BEEF 0X TAIL', 0.9176113668240999], [[[860.0, 979.0], [998.0, 976.0], [1000.0, 1026.0], [861.0, 1029.0]], '35.16', 0.8331109086672465], [[[228.0, 1031.0], [736.0, 1042.0], [735.0, 1092.0], [226.0, 1081.0]], '563891 ANGUS CHSBRG', 0.9476129055023194], [[[861.0, 1038.0], [997.0, 1031.0], [999.0, 1080.0], [863.0, 1087.0]], '14.99', 0.8332075973351797], [[[121.0, 1087.0], [395.0, 1096.0], [394.0, 1139.0], [119.0, 1130.0]], '0000297321', 0.9089403911070391], [[[378.0, 1096.0], [622.0, 1098.0], [621.0, 1144.0], [378.0, 1142.0]], '/ 563891', 0.8855035305023193], [[[881.0, 1092.0], [1019.0, 1085.0], [1022.0, 1137.0], [883.0, 1144.0]], '5.00-', 0.8327144682407379], [[[204.0, 1147.0], [392.0, 1152.0], [391.0, 1197.0], [202.0, 1192.0]], '1599905', 0.8748569786548615], [[[413.0, 1155.0], [705.0, 1157.0], [705.0, 1201.0], [413.0, 1199.0]], 'TERRA CHIPS', 0.9157347331444422], [[[881.0, 1150.0], [998.0, 1145.0], [1000.0, 1199.0], [883.0, 1204.0]], '7.49', 0.7998852729797363], [[[64.0, 1196.0], [395.0, 1211.0], [393.0, 1258.0], [62.0, 1243.0]], 'E 0000297190', 0.9060862752107474], [[[381.0, 1213.0], [626.0, 1213.0], [626.0, 1257.0], [381.0, 1257.0]], '/1599905', 0.8824285732375251], [[[880.0, 1208.0], [1019.0, 1200.0], [1022.0, 1252.0], [883.0, 1260.0]], '3.00-', 0.8327874739964803], [[[204.0, 1263.0], [625.0, 1270.0], [624.0, 1316.0], [204.0, 1309.0]], '1326036 D0WNLGHT', 0.9218472417663125], [[[883.0, 1264.0], [1047.0, 1261.0], [1048.0, 1310.0], [884.0, 1313.0]], '7.97 A', 0.8085448401314872], [[[202.0, 1320.0], [627.0, 1326.0], [626.0, 1373.0], [202.0, 1367.0]], '1659561 S0Y GIFT', 0.9375481570468229], [[[857.0, 1322.0], [995.0, 1320.0], [996.0, 1369.0], [858.0, 1371.0]], '26.99', 0.8333064317703247], [[[199.0, 1377.0], [730.0, 1383.0], [729.0, 1430.0], [199.0, 1424.0]], '1691148 ABALONE SAUC', 0.9247595838138035], [[[879.0, 1378.0], [996.0, 1376.0], [997.0, 1429.0], [880.0, 1431.0]], '8.99', 0.7999334096908569], [[[91.0, 1427.0], [309.0, 1438.0], [307.0, 1485.0], [89.0, 1474.0]], '3 @ 7.97', 0.8272785478168063], [[[199.0, 1492.0], [621.0, 1498.0], [620.0, 1544.0], [199.0, 1538.0]], '1326036 D0WNLGHT', 0.9385190956732806], [[[857.0, 1494.0], [1046.0, 1491.0], [1047.0, 1542.0], [858.0, 1545.0]], '23.91 A', 0.8739022389054298], [[[61.0, 1540.0], [282.0, 1549.0], [278.0, 1641.0], [57.0, 1632.0]], 'VOID', 0.7922422289848328], [[[196.0, 1649.0], [727.0, 1654.0], [727.0, 1701.0], [196.0, 1696.0]], '1691148 ABAL0NE SAUC', 0.9217858257747832], [[[878.0, 1650.0], [1018.0, 1647.0], [1020.0, 1699.0], [879.0, 1702.0]], '8.99-', 0.8330206175645193], [[[57.0, 1700.0], [278.0, 1707.0], [275.0, 1796.0], [54.0, 1789.0]], 'VOID', 0.7925425410270691], [[[198.0, 1807.0], [620.0, 1809.0], [619.0, 1852.0], [198.0, 1850.0]], '1659561 S0Y GIFT', 0.9221077631501591], [[[856.0, 1805.0], [1013.0, 1805.0], [1013.0, 1854.0], [856.0, 1854.0]], '26.99-', 0.8570490734917777], [[[276.0, 1864.0], [487.0, 1866.0], [486.0, 1911.0], [276.0, 1909.0]], 'SUBTOTAL', 0.8881123661994934], [[[855.0, 1862.0], [992.0, 1862.0], [992.0, 1911.0], [855.0, 1911.0]], '99.75', 0.8332757552464803], [[[272.0, 1920.0], [359.0, 1920.0], [359.0, 1969.0], [272.0, 1969.0]], 'TAX', 0.7497549206018448], [[[880.0, 1918.0], [992.0, 1918.0], [992.0, 1969.0], [880.0, 1969.0]], '4.70', 0.7999366879463196], [[[272.0, 1976.0], [407.0, 1978.0], [406.0, 2027.0], [271.0, 2025.0]], 'TOTAL', 0.8324441810448965], [[[836.0, 1978.0], [1009.0, 1980.0], [1009.0, 2024.0], [835.0, 2022.0]], '104.45 ', 0.825279526412487], [[[57.0, 2098.0], [485.0, 2098.0], [485.0, 2138.0], [57.0, 2138.0]], 'XXXXXXXXXXXX5403', 0.9190684276468614], [[[748.0, 2090.0], [992.0, 2092.0], [992.0, 2143.0], [747.0, 2141.0]], 'CHIP Read', 0.8994688570499421], [[[51.0, 2153.0], [198.0, 2153.0], [198.0, 2201.0], [51.0, 2201.0]], 'AID:', 0.7707867860794068], [[[213.0, 2155.0], [591.0, 2153.0], [592.0, 2196.0], [213.0, 2198.0]], 'A0000000031010', 0.9283870061238607], [[[49.0, 2212.0], [167.0, 2212.0], [167.0, 2262.0], [49.0, 2262.0]], 'Seq#', 0.7575817346572876], [[[215.0, 2211.0], [356.0, 2211.0], [356.0, 2259.0], [215.0, 2259.0]], '12837', 0.8330714106559753], [[[509.0, 2210.0], [830.0, 2206.0], [830.0, 2255.0], [510.0, 2259.0]], 'App# : 05290C', 0.873178848198482], [[[46.0, 2270.0], [168.0, 2270.0], [168.0, 2323.0], [46.0, 2323.0]], 'Visa', 0.7486562848091125], [[[295.0, 2271.0], [670.0, 2267.0], [671.0, 2314.0], [295.0, 2318.0]], 'ResP: APPROVED', 0.900809895992279], [[[50.0, 2333.0], [685.0, 2326.0], [686.0, 2372.0], [50.0, 2379.0]], 'Tran ID#: 307600012837.:', 0.9308841753005982], [[[47.0, 2515.0], [562.0, 2509.0], [563.0, 2561.0], [47.0, 2567.0]], 'APPROVED - Purchase', 0.948972350358963], [[[47.0, 2579.0], [454.0, 2571.0], [455.0, 2618.0], [48.0, 2626.0]], 'AMOUNT: $104.45', 0.9227995648980141], [[[44.0, 2636.0], [807.0, 2626.0], [808.0, 2679.0], [44.0, 2689.0]], '03/17/2023 10:33 1004 12 9 5', 0.9516078336485501], [[[260.0, 2752.0], [376.0, 2755.0], [374.0, 2806.0], [258.0, 2803.0]], 'Visa', 0.7436046361923218], [[[832.0, 2748.0], [996.0, 2750.0], [996.0, 2803.0], [831.0, 2801.0]], '104.45', 0.8570642811911446], [[[259.0, 2813.0], [425.0, 2811.0], [426.0, 2863.0], [259.0, 2865.0]], 'CHANGE', 0.856063859803336], [[[881.0, 2810.0], [996.0, 2810.0], [996.0, 2864.0], [881.0, 2864.0]], '0.00', 0.799259603023529], [[[881.0, 2933.0], [999.0, 2933.0], [999.0, 2991.0], [881.0, 2991.0]], '4.70', 0.7997966766357422], [[[64.0, 2947.0], [396.0, 2936.0], [397.0, 2985.0], [66.0, 2996.0]], 'A 9.375% TAX', 0.9049274279521062], [[[881.0, 2992.0], [998.0, 2994.0], [997.0, 3053.0], [880.0, 3051.0]], '4.70', 0.7998796939849854], [[[65.0, 3007.0], [314.0, 2997.0], [316.0, 3048.0], [67.0, 3058.0]], 'TOTAL TAX', 0.8614233434200287], [[[34.0, 3063.0], [809.0, 3049.0], [811.0, 3109.0], [35.0, 3123.0]], 'TOTAL NUMBER OF ITEMS SOLD -', 0.9501045181833464], [[[877.0, 3054.0], [976.0, 3054.0], [976.0, 3115.0], [877.0, 3115.0]], '10', 0.6636072993278503], [[[36.0, 3131.0], [450.0, 3114.0], [452.0, 3167.0], [38.0, 3184.0]], 'INSTANT SAVINGS', 0.9170595966279507], [[[770.0, 3122.0], [966.0, 3122.0], [966.0, 3170.0], [770.0, 3170.0]], '$ 11.00', 0.8492126986384392], [[[31.0, 3184.0], [811.0, 3169.0], [813.0, 3235.0], [32.0, 3250.0]], 'x7117202k: 10:33 1004 12 9 5', 0.8348767428562559], [[[224.0, 3307.0], [859.0, 3304.0], [859.0, 3357.0], [224.0, 3360.0]], 'FSA N/TAX AMT(F) = 4.49', 0.9187779178222021], [[[221.0, 3368.0], [424.0, 3365.0], [425.0, 3419.0], [221.0, 3422.0]], 'FSA TAX', 0.813681036233902], [[[689.0, 3367.0], [860.0, 3367.0], [860.0, 3418.0], [689.0, 3418.0]], '- 0.42', 0.7666766898972648], [[[220.0, 3429.0], [473.0, 3425.0], [474.0, 3479.0], [221.0, 3483.0]], 'FSA TOTAL', 0.8786071717739106], [[[688.0, 3428.0], [856.0, 3428.0], [856.0, 3479.0], [688.0, 3479.0]], '- 4.91', 0.7816318103245327], [[[277.0, 3644.0], [826.0, 3641.0], [826.0, 3684.0], [277.0, 3687.0]], '21100401200092303171033', 0.9560053075353304], [[[23.0, 3714.0], [558.0, 3684.0], [562.0, 3751.0], [27.0, 3781.0]], 'OP#: 5 Name: Gaby T', 0.9428421169519424], [[[298.0, 3767.0], [753.0, 3764.0], [753.0, 3808.0], [298.0, 3811.0]], 'Thank  You!', 0.8765674630800883], [[[521.0, 3819.0], [1007.0, 3837.0], [1005.0, 3890.0], [519.0, 3872.0]], 'Come Again', 0.8660521344705061], [[[195.0, 3839.0], [479.0, 3834.0], [480.0, 3874.0], [195.0, 3879.0]], 'Please', 0.822684781891959]]
poetry run rapidocr_onnxruntime --print_verbose -img ~/Downloads/Costco.jpg  11.28s user 3.94s system 331% cpu 4.585 total

Is there any flags to print what went inside the docker container?

The code is really simple in ocr.py

"""
Example API endpoint
"""

from __future__ import annotations

import json
import logging

import cv2
from dotenv import find_dotenv
import numpy as np
from fastapi import APIRouter, Depends, File, UploadFile
from pydantic import BaseModel, Field
from typing_extensions import Annotated

from app.service.datamodel import PaddleOCRResult
from PIL import Image

try:
    from rapidocr_onnxruntime import RapidOCR
except ImportError:
    msg = "`rapidocr-onnxruntime` package not found, please install it with "
    raise ImportError(msg)

from ..config import SvcSettings, get_settings

logger = logging.getLogger(__name__)


class OCREngine:
    def __init__(self) -> None:
        self.ocr = RapidOCR()

    def __call__(self, img) -> dict[str, PaddleOCRResult]:
        img = np.array(img)
        img = cv2.cvtColor(img, cv2.COLOR_RGB2BGR)
        logger.info("Converted Image color space to BGR")

        ocr_res, _ = self.ocr(img)
        logger.info("OCRed Image")
        if not ocr_res:
            return json.dumps({})

        return self._post_process_result(ocr_res)

    def _post_process_result(
        self, ocr_result: list[dict]
    ) -> dict[str, PaddleOCRResult]:
        out_dict = {
            str(i): PaddleOCRResult(text=rec, box=dt_box, score=score)
            for i, (dt_box, rec, score) in enumerate(ocr_result)
        }
        return out_dict


ocr = OCREngine()

router = APIRouter(prefix="/ocr")


@router.post("/file")
def get_log_level(
    file: Annotated[
        UploadFile, File(description="An Image file to be OCRed into text")
    ],
) -> PaddleOCRResult:
    """
    An example endpoint that uses the settings.
    """
    logger.info("Converting Image file to text")
    img = Image.open(file.file)
    logger.info("Loaded image to memory")
    result, _ = ocr(img)
    logger.info(f"{result=}")
    return result

[felixgao]

I was able to switch from an AMD64 architecture image to ARM64 base images. now the result seems to be returning within few seconds (3 seconds according to the logs). I still think there is room for optimization, but sure how to do it yet. Any suggestions?

[SWHL]

You can try the rapidocr_openvino package on the CPU machine.
If you have GPU, you also try rapidocr_paddle package.