很多相机问题说到底是“日志不全”的问题。拿到客诉或者实验室里复现了一个概率性卡顿、花屏、预览黑屏第一件事就是抓UMD/KMD Log必要时还得Dump图像。高通Camx架构下这两类日志的输出机制截然不同用户态驱动UMD的日志走logcat或者camx私有文件内核态驱动KMD的日志走dmesg时间基准都不一样。只抓一份往往拼不出完整现场抓全了又不清楚该开哪个开关。这篇文章把我日常定位相机问题时用到的Camx日志开关、图像Dump方法和离线Log合成脚本整理出来适合做手机相机调试、驱动开发、影像效果验证的工程师参考也是写给刚接手Camx平台的人的一份起步笔记。1. Camx调试前必须搞懂的三层架构与日志链路1.1 用户态、内核态和固件各负责哪一段高通的相机软件栈从Android Camera HAL下来核心就是CamxCamera eXtension架构。整个链路可以粗分成三层用户态的Camx HAL层内核态的Camera Kernel Driver层还有跑在ISP/DSP硬件里的固件层。用户态驱动通常叫UMD对应Camx HAL和CHI override节点。它负责pipeline调度、feature协商、node连接、request分发也负责跟上层Camera Service打交道。你看到的预览、拍照流程、metadata大部分都是在这一层完成的。内核态驱动通常叫KMD对应内核里的cam_req_mgr、cam_sync、cam_isp、cam_sensor、cam_cci这些模块它负责真正操作硬件比如给sensor下I2C配置、把buffer地址写进ISP寄存器、处理中断、维护request状态机。固件层则是真正干重活的IFE、BPS、JPEG、IPE这些硬件上的固件通过KMD上抛的中断和共享内存与上层交互。理解这三层分工你才知道一条错误日志到底应该去哪里找。比如预览不出图如果UMD日志显示request已经提交了但KMD没有完成回调问题大概率在KMD和固件之间如果UMD自己就没有把preview request发到CSL那就要往上层pipeline配置方向查。1.2 一条日志从产生到落盘的完整路径不同层的日志产生和输出通道是完全分开的。UMD代码里用CamxLog宏打印的日志默认会走logcat如果有配置还可以同时写到文件KMD主要靠printk通过dmesg读取也有一部分会进pstore固件日志不是直接printk出来的通常是固件把调试信息写进共享内存或者通过debug寄存器上抛由KMD代打。这就是为什么你只看logcat永远看不到完整的kernel侧消息只看dmesg又不知道上层当时在干什么。这里要特别提醒Camx的上层日志很多时候不在logcat主缓冲区而是被HAL层的进程直接写到了 /data/vendor/camera/log 下面。抓log前先搞清楚你自己这份log是从哪个通道来的否则后面时间线对不上等于白折腾。1.3 不要一上来就全量开日志很多人Debug时习惯先把所有日志级别开到最大、所有分组都打开结果往往适得其反。Camx的日志分组很细全量打开后logcat会瞬间被打爆旧日志被冲掉而且打印本身会改变时序导致概率性bug不再复现。更实际的影响是性能相机链路每一帧都经过很多node全量verbose日志会让帧率肉眼可见地掉下来甚至触发降级策略。所以我建议按问题类型选择日志分组跑sensor相关就看CamXLogGroupSensor怀疑3A和IQ问题就开CamXLogGroupIQ和Stats怀疑硬件带宽/电源就开CPAS怀疑request调度就开Core加CSL。先小范围开确认信息不够再逐步扩大这样才能保证抓到的现场是真实的。2. UMD日志开关分组、级别与logcat提取命令2.1 camxoverridesettings.txt 与属性开关的关系Camx UMD日志的开关主要有两个入口一个是camxoverridesettings.txt文件另一个是persist属性。camxoverridesettings.txt常见路径是 /vendor/etc/camera/camxoverridesettings.txt不同平台也可能叫 camxoverridesettings.debug.txt优先级以后者为高。文件里可以配置日志mask、dump行为、pipeline行为等。在工程机或者userdebug机上最常用的几个设置大概是这样的# /vendor/etc/camera/camxoverridesettings.txt logFileMask0x7FFFFFFF logCtxMask0x7FFFFFFF logOutputMask2 enableDump1需要注意logFileMask的bit位定义在camx版本之间不完全一样动手前先去源码的camxoverridesettings.h里确认一下。比如有的版本里低4位是Core/IQ/Sensor/ICP有的版本已经扩了很多组。所以“抄配置”要带着版本意识否则你开了一堆mask实际想看的组没开。属性开关方面常见的有persist.vendor.camera.logs、persist.vendor.camera.logger这类设置后通常要重启camera provider进程才会生效。可以执行adb shell setprop persist.vendor.camera.logs 0x1F adb shell killall camera-provider-2-5 # 进程名按实际版本调整 adb shell setprop persist.vendor.camera.logger 1不过要注意不同平台、不同Android版本里进程名不一样有的叫cameraserver有的叫camera-provider-2-5还有的是vendor.qti.hardware.camera.provider2.6-service。进程名不确定就adb shell ps | grep camera看一眼。重启进程这个步骤经常被漏掉我见过太多人改了属性然后抱怨没效果实际上是没重启。2.2 日志分组与级别的选择逻辑Camx的日志级别从低到高大概是Verbose、Info、Warning、Error、Fatal。默认情况下很多组只打印Error和Warning这时候你想看一条request的完整生命周期肯定不够至少要把级别抬到Info。定位帧率问题或者request排队问题往往需要Verbose但要接受日志量爆炸的代价。分组的选择逻辑也很简单先看问题现象发生在哪个模块。预览卡顿多半在pipeline调度开Core拍照raw花屏可能在ICP/IFE开IQ和ICP对焦不对开Sensor和Stats热/功耗问题开CPAS。比较稳妥的方式是先把Core组打开跑一遍根据日志里的node名再决定要不要扩组。UMD日志里的关键字非常有辨识度比如Pipeline::Create、Node::ProcessRequest、CSLSubmit这些看到之后再按图索骥。2.3 用logcat提取和过滤Camx UMD日志清空旧日志、限定tag抓取是一个固定套路adb logcat -c adb logcat -v threadtime /tmp/camx_logcat.txt # 复现问题... # 复现完杀掉logcat adb shell killall logcat如果只想保留Camx相关内容可以用tag过滤adb logcat -v threadtime -s CamX CHI *:S /tmp/camx_only.txt这里的CamX是UMD的主tagCHI是ChiNode相关tag。实际跑起来还会出现很多子模块tag比如hwnode、imxxxx、flash等具体看平台。我个人的习惯是先全量抓logcat然后配合grep处理因为有时候问题日志所在的tag并不是一眼能猜到的。全量抓的话注意logcat缓冲区大小建议先把logcat buffer调大adb logcat -G 64M另外Camx支持把日志直接输出到文件配合logFileMask使用。输出文件的路径通常在 /data/vendor/camera/log 下名字类似 camx_0.log。这种文件的优势是不受logcat缓冲区和selinux策略影响但要记得定时清理否则debug一次能写几百MB。3. KMD与固件日志从dmesg到pstore的完整姿势3.1 KMD日志的重要模块与dmesg抓取命令内核侧的相机驱动模块需要重点关注这几个cam_req_mgr负责request管理cam_sync负责同步cam_isp负责ISP硬件配置cam_sensor和cam_cci负责sensor控制和I2C读写cam_cpas负责时钟/电源/带宽cam_flash负责闪光灯。任何一个模块出问题dmesg里都会留下线索。抓取内核日志常用两种方式实时的dmesg -w和落盘的kmsg:adb shell dmesg -w /tmp/cmn_kernel.log # 或 adb shell cat /proc/kmsg /tmp/cmn_kernel.log 实时调试推荐dmesg -w。如果要抓重启前的最后现场就需要看pstore里的last kmsg路径一般是 /sys/fs/pstore/console-ramoops 或 /proc/last_kmsg。这个在现场复现“重启后什么问题都没了”的场景下特别有用建议养成不稳定问题必抓pstore的习惯。内核日志的默认打印级别不一定把相机驱动全部打出来必要时先把printk级别调高adb shell echo 8 4 1 7 /proc/sys/kernel/printk3.2 固件日志的特殊性不是dmesg直接给全的Turbo、ICP这些硬件固件的日志处理起来比KMD麻烦。firmware内部有自己的日志buffer普通release版本里很多是关闭的。要抓固件日志一般得满足两个条件一是固件烧录的是带debug信息的版本二是通过KMD或专属节点把fw log导出。实际操作中Camx的KMD日志里如果出现CAM_FW相关的打印通常就是固件上抛的信息。如果怀疑某个case跟固件死机/超时有关先看kernel里有没有firmware crash的dump再看有没有fw version打印。固件日志过于底层普通调试不建议一上来就抓先确认问题是不是出现在固件侧再说。判断方法很朴素如果UMD和KMD的日志都显示request已经交付出去了但中断一直没有按预期上报或者上报时间明显异常这时才值得去挖固件。3.3 一整套KMD现场抓取组合拳我通常会在复现前一次性起三路采集adb shell echo 8 4 1 7 /proc/sys/kernel/printk adb shell dmesg -w /tmp/kernel.log adb logcat -v threadtime /tmp/logcat.log adb shell cat /proc/kmsg /tmp/kmsg_fallback.log 复现完成后把dmesg的tail部分、logcat里CamX/CHI的tag、以及meminfo里CMA信息一起拉下来adb shell cat /proc/meminfo | grep -i cma adb shell cat /d/ion/heaps/system不过在这些组合里最关键的还是“复现动作和日志时刻要能对上”。光有开始和结束的日志中间关键帧丢了很难定位。我一般会在复现动作前先在logcat里打一个醒目的标记比如adb log -t MY_MARK start reproduce touch camera后续对时间线的时候直接搜MY_MARK就能把问题窗口准确裁出来。4. Dump图像的开关、路径与RAW/YUV查看方法4.1 Dump buffer的前提条件与常用配置Dump图像本质上是把pipeline经过的buffer直接写到文件方便离线看每一帧到底长什么样。Camx里Dump的开关通常也在camxoverridesettings.txt里常见配置如下enableDump1 dump.mask0xFFFFFFFF dump.path/data/vendor/camera/ dump.raw1 dump.yuv1 dump.jpeg1有的版本里还会细分到按node类型dump比如只dumpIFE、BPS、JPEG节点。开Dump对性能影响比开日志还大写文件的速度跟不上帧率会导致明显的卡顿甚至超时所以只适合在固定场景下短时间开。抓完立刻关掉。如果不方便改vendor分区文件有些平台也支持属性开dump例如adb shell setprop persist.vendor.camera.dump 1但属性方式不一定在所有版本都生效。判断dump有没有生效最直接的办法就是看 /data/vendor/camera 下是否开始生成新的dump文件。4.2 Dump文件类型、路径和命名规律Dump出来的文件类型取决于你在pipeline里抓的是哪种buffer。常见的有RAWsensor直接输出的bayer数据文件名或后缀里能看到是raw10/raw16。YUV预览或录制的YUV帧NV12/NV21居多。JPEG拍照编码后的输出。Metadata每一帧对应的metadata dump通常是json或者可读文本。路径一般默认在 /data/vendor/camera/文件名会携带pipeline、port、node、类型和时间戳信息。不同平台命名规则不完全一样但大体都能看出类似端口号、frame number的字样。调试时要把整个目录拉出来分析而不是只盯其中一个文件adb shell ls -lt /data/vendor/camera/ | head -20 adb pull /data/vendor/camera/ /tmp/camera_dump/4.3 怎么查看RAW/YUV文件拿到dump文件后用图像浏览器直接打开通常是打不开的因为全是裸数据。RAW文件需要知道分辨率、bayer patternRGGB/BGGR等、bit depth、stride才能正确显示。这里分享一个最快的Python查看方法用numpy加opencv几行代码import numpy as np import cv2 # 以1920x1080 raw16为例分辨率按你的dump信息改 w, h 1920, 1080 raw16 np.fromfile(dump_raw_0.raw, dtypenp.uint16).reshape(h, w) cv2.imwrite(preview.png, (raw16 2).astype(np.uint8))YUV文件更简单用ffmpeg就能转ffmpeg -s 1920x1080 -pix_fmt nv12 -i dump.yuv dump.png这里面最坑的是stride。相机硬件为了对齐每一行数据长度往往比分辨率宽度大如果直接按分辨率解析图像会呈现斜切的效果俗称“斜纹”。遇到这种情况必须先查log或者metadata里记录的stride值用stride作为每行字节数去reshape。这个细节能过滤掉一大半“图像不对”的误判。5. 离线Log合成脚本合并logcat与dmesg的实战工具5.1 为什么一定要做离线合成UMD日志使用系统墙上时间格式是 08-21 10:15:30.123KMD日志使用内核启动后的时间格式是 [ 1234.567891]。两个时间基准完全不同如果只看一个再脑补另一个很容易把因果顺序搞反。比如一个典型场景预览卡顿logcat显示应用在T1时刻收到了预览帧dmesg显示ISP中断在T2才完成这个T1和T2之间到底差了多少没法直接算。所以需要一个脚本把logcat和dmesg按同一时间轴重排。脚本的核心思路是确定内核启动对应的墙上时间然后把logcat的墙上时间、dmesg的内核时间都换算成同一个绝对时间再按时间排序输出。这样就能在一条时间线上同时看到“上层提交request”和“内核完成硬件操作”的对应关系。5.2 抓log时必须顺手记录的两个关键值脚本能合出来的前提是你在抓log的时候额外记录了系统时间与uptime。具体操作是adb shell date %m-%d %H:%M:%S.%3N adb shell cat /proc/uptime假设date输出是 08-21 10:15:30.123uptime是 1234.56那么内核启动的墙上时间就是 08-21 10:15:30.123 减去1234.56秒。这个“启动时间”就是连接两个时间基准的桥梁。这个动作很容易被忽略但非常关键。如果抓log的时候没记录后面想合成只能靠运气猜记录了脚本随便跑。我自己的习惯是把这两条命令写进抓log的脚本第一行保证每次debug必有这两个值。5.3 合成脚本camx_log_merge.py脚本我用Python标准库写不需要安装额外依赖。用法很简单python3 camx_log_merge.py \ --date-out 08-21 10:15:30.123 --uptime 1234.56 \ -o merged.log \ logcat.log dmesg.log camx.log也可以直接给--boot-time省得自己算。脚本源码如下可以直接存成camx_log_merge.py使用#!/usr/bin/env python3 # -*- coding: utf-8 -*- camx_log_merge.py: 合并 logcat / dmesg / camx log 到统一时间轴。 import argparse import re import sys from datetime import datetime, timedelta LOG_RE re.compile( r^(?Pmon\d{2})-(?Pday\d{2})\s r(?Phour\d{2}):(?Pmin\d{2}):(?Psec\d{2})\.(?Pms\d{3})\s r(?Ppid\d)\s(?Ptid\d)\s r(?Plevel[VDIWEF])\s(?Ptag\S):\s*(?Pmsg.*)$ ) KMSG_RE re.compile( r^\s*\[\s*(?Psec\d)\.(?Pusec\d{6})\]\s*(?Pmsg.*)$ ) def parse_boot_time(date_out, uptime_sec): try: dt datetime.strptime(date_out, %m-%d %H:%M:%S.%f) except ValueError: dt datetime.strptime(date_out, %m-%d %H:%M:%S) return dt - timedelta(secondsuptime_sec) def parse_file(path, boot_dt, source): entries, unparsed [], [] with open(path, r, errorsreplace) as f: for line in f: line line.rstrip(\n) m LOG_RE.match(line) if m: year boot_dt.year dt datetime( year, int(m.group(mon)), int(m.group(day)), int(m.group(hour)), int(m.group(min)), int(m.group(sec)), int(m.group(ms)) * 1000, ) delta (dt - boot_dt).total_seconds() if delta -12 * 3600: dt dt.replace(yearyear 1) delta (dt - boot_dt).total_seconds() entries.append(( delta * 1000, flogcat/{m.group(level)}/{m.group(tag)}, m.group(msg).strip(), )) continue m KMSG_RE.match(line) if m: t int(m.group(sec)) int(m.group(usec)) / 1e6 entries.append((t * 1000, kmsg, m.group(msg).strip())) continue unparsed.append(line) return entries, unparsed def main(): ap argparse.ArgumentParser(description合并camx相关log到统一时间线) ap.add_argument(inputs, nargs, help要合并的log文件) ap.add_argument(-o, --output, defaultmerged.log) ap.add_argument(--boot-time, help内核启动的墙上时间, 如 08-21 08:35:22.456) ap.add_argument(--date-out, help抓log时date命令输出, 如 08-21 10:15:30.123) ap.add_argument(--uptime, typefloat, help抓log时/proc/uptime输出, 单位秒) ap.add_argument(--filter, actionappend, default[], help关键字过滤, 可多次指定) args ap.parse_args() if args.boot_time: boot_dt datetime.strptime(args.boot_time, %m-%d %H:%M:%S.%f) elif args.date_out and args.uptime is not None: boot_dt parse_boot_time(args.date_out, args.uptime) else: print(必须提供 --boot-time 或 --date-out --uptime 之一, filesys.stderr) sys.exit(1) all_entries, unparsed_lines [], [] for path in args.inputs: entries, unparsed parse_file(path, boot_dt, path) all_entries.extend(entries) unparsed_lines.extend(unparsed) all_entries.sort(keylambda x: x[0]) with open(args.output, w) as out: for time_ms, src, msg in all_entries: if time_ms 0: continue if args.filter and not any(k in msg for k in args.filter): continue dt boot_dt timedelta(millisecondstime_ms) ts dt.strftime(%H:%M:%S.) f{int(time_ms % 1000):03d} out.write(f[{ts}] [{src}] {msg}\n) if unparsed_lines: out.write(\n# ----- 未能解析的行, 原样保留 -----\n) out.write(\n.join(unparsed_lines) \n) print(f合并完成: {args.output}, 共 {len(all_entries)} 条) if __name__ __main__: main()这个版本我只保留了最常用的功能解析logcat和dmesg两种时间格式统一输出支持关键字过滤。没用到的行会原样保留到文件末尾防止信息丢失。5.4 脚本使用示例与效果假设有一个预览卡顿的casedmesg里cam_sync报了很多timeoutlogcat里CamX一直在等buffer。把两份log喂给脚本后输出大概是这样的[10:15:28.001] [logcat/D/CamX] request 1024 submitted to pipe [10:15:28.012] [kmsg] cam_sync: wait on sync obj 2048 timeout [10:15:28.015] [logcat/I/CamX] request 1024 result delivered [10:15:29.002] [logcat/D/CamX] request 1025 submitted to pipe一眼就能看出从submit到timeout再到delivered的时间间隔而且能看到卡顿是不是周期性发生。配合--filter cam_sync还可以只看sync相关的行排除logcat的噪音。脚本的局限也很明显它不处理logcat里非标准格式的行也不解析camx私有log文件里的自定义时间戳。但这些文件通常自带统一时间拆开看也没问题。如果你需要更复杂的窗口切分、帧率统计可以在这个基础上扩展比如按时间窗生成统计段或者把metadata里的帧号时间单独抽出来做曲线。6. 高频踩坑记录与定位思路6.1 日志开关开了却不生效的三个原因开关开了没输出是提问率最高的问题。排第一的原因是没重启进程。camxoverridesettings和persist属性大多在camera provider进程初始化时读一次不重启进程旧配置一直在改什么都不生效。第二个原因是文件路径或者名字不对特别是user build下vendor分区是只读的直接push不进去需要先remount或者用debug版overlay。第三个原因是selinux权限即使文件在进程没有读权限或者没有写日志目录的权限日志一样出不来。排查的时候可以先看camera进程起来时有没有读到override文件这个信息通常会在UMD日志最早的部分打印。另外可以临时用setenforce 0来排除selinux因素但注意这是调试行为量产环境必须还回去。6.2 Dump图像“看起来不对”的判定顺序拿到dump图发现花屏或者全黑先别急着往驱动bug上想按照这个顺序排查一是stride二是格式三是分辨率四是dump时机。stride不对的表现是图像整体斜切格式不对通常是颜色错乱、亮度异常分辨率不对是整体拉伸或者只有局部内容dump时机不对则是画面里内容不完整比如只dump到了半帧。这些参数从哪里拿Camx的metadata dump和log里通常记录着当前pipeline的port配置包括width/height/stride/format。先花几分钟把这些参数对齐再判断是不是真的异常。我见过太多人拿错误参数解析出来的花屏去报bug最后发现是自己的解析姿势不对。6.3 性能开销与量产取舍开日志和开Dump都有明显的性能代价。开了Dump之后一帧raw数据要写文件DDR带宽和IO开销都上去了帧率下降是必然的。开了全量verbose日志pipeline里每个node的进出都要打印耗时会翻倍。所以debug版本开这些没有问题但量产版本一定要把这些开关全部关闭特别是dump相关配置一旦泄漏到用户版本不仅是性能问题还可能把用户的图像数据写到本地隐私风险很大。Release版本建议保留最小可用日志比如只开Error级别、不开Dump。真有客诉问题优先让客诉用户抓一份带时间的logcat再配合pstore里的last kmsg大多数崩溃和系统侧问题都能覆盖到。我个人实际调试中还有个习惯把多路抓log和date/uptime记录做成一个固定脚本每次复现前直接执行复现完自动打包。这样不仅保证时间基准不缺还避免每次手动敲命令漏掉某些通道。离线合成脚本我一开始只是为了对齐一次棘手的request超时问题写的后来发现凡是涉及UMD与KMD交互的case几乎都能靠它快速判断瓶颈在谁那边。如果你也经常在相机链路上排查问题建议把这套流程固化下来比每次临时拼命令省下太多时间。