NXP

NXP Nfc模块Framework层移植遇到的坑【一】

2019-07-12 11:16发布

Porting目标平台:

MT8735_L,MT8173_M,MT8783_N这里总结一下移植过程中遇到的一些坑

1. 由于 IOCTL 时传递参数类型错误导致的初始化失败

原因:由于 Hal 层中定义的 IOCTL 参数使用了long类型,但是kernel中定义的是unsigned int,hal 的指令在 kernel 中进行强转时会发生 errno = 0x16 的报错。(6.0和7.0移植的过程中都有发现这个错误)NXP在github上面的源码地址:点击这里跳转kernel和配置文件请务必让采购找供应商提供!!github上面的kernel源码并没有对特定平台做适配,部分功能可能需要微调,这个就看驱动工程师的实力了,跟Framework关系不大所以没有太多接触到。conf配置文件(下图中两个)一般直接让供应商提供项目中实际使用的芯片对应的配置文件即可,不需要做改动(如果需要调整log打印level等可以对照里面的注释来修改),这两个文件放在 system/etc/ 下

Log分析过程如下(以8783_N平台的log来分析):

如何从 log 打印信息中过滤查找自己需要的信息:

为了能够方便查找log信息,对问题进行定位,请务必记住一点,系统 log 日志请不要使用AS或者Eclipse来抓取!(IDE实时抓取的log缓冲区不足够支撑系统级log分析)
这是使用MTKLogger抓取出来的mtklog(截图中展示的是其中的mobilelog),我们需要关注的是图中圈注的两份log,加起来大约2M左右,不算太多。我这里遇到的现象是:开机之后进入设置,UI上的显示是enabling(switch开关切换到开,但是选项属于disable状态),判断应该是开机初始化的时候出现的问题,所以我们从main_log.boot开始查。Log文件大概有一万行左右,但是并不是所有信息都是我们需要的,我们先通过字符串过滤的方式过滤一遍(NXP的log信息还算比较规范的,直接按照nxp作为关键字过滤即可),文本工具使用notepad++或者UltraEdit均可:Search "Nxp" (109 hits in 1 file) e:UserslinqihanDesktop fc gmobilelogAPLog_2010_0101_000256main_log.boot (109 hits) Line 8640: 01-01 00:02:54.029246 1736 1736 D NfcAdaptation: bool CNfcConfig::readConfig(const char *, bool) Opened optional config /etc/libnfc-nxp.conf Line 8642: 01-01 00:02:54.034890 1736 1736 D NfcAdaptation: bool CNfcConfig::readConfig(const char *, bool) Cannot open config file /data/nfc/libnfc-nxpTransit.conf Line 8650: 01-01 00:02:54.037072 1736 1736 D : bool CNxpNfcConfig::readConfig(const char *, bool) Opened base config /etc/libnfc-nxp.conf Line 8650: 01-01 00:02:54.037072 1736 1736 D : bool CNxpNfcConfig::readConfig(const char *, bool) Opened base config /etc/libnfc-nxp.conf Line 8653: 01-01 00:02:54.040821 1736 1736 E : bool CNxpNfcConfig::readConfig(const char *, bool) Cannot open config file /data/nfc/libnfc-nxpTransit.conf Line 8653: 01-01 00:02:54.040821 1736 1736 E : bool CNxpNfcConfig::readConfig(const char *, bool) Cannot open config file /data/nfc/libnfc-nxpTransit.conf Line 8774: 01-01 00:02:54.207734 1736 1736 D RegisteredNxpServicesCache: Dynamic APDU Service file does not exist. Line 9147: 01-01 00:02:54.501366 1736 1869 D NxpNfcNciHal: nfc_open: enter; name=nci Line 9148: 01-01 00:02:54.501545 1736 1869 D NxpNfcNciHal: nfc_open: exit 0 Line 9177: 01-01 00:02:54.506406 1736 1873 D : bool nxp::CNfcConfig::readConfig(const char *, bool) Opened base config /etc/libnfc-nxp.conf Line 9177: 01-01 00:02:54.506406 1736 1873 D : bool nxp::CNfcConfig::readConfig(const char *, bool) Opened base config /etc/libnfc-nxp.conf Line 9178: 01-01 00:02:54.510691 1736 1873 D : bool nxp::CNfcConfig::readConfig(const char *, bool) Opened optional config /etc/libnfc-brcm.conf Line 9180: 01-01 00:02:54.518630 1736 1873 E : bool nxp::CNfcConfig::readConfig(const char *, bool) Cannot open config file /data/nfc/libnfc-nxpTransit.conf Line 9180: 01-01 00:02:54.518630 1736 1873 E : bool nxp::CNfcConfig::readConfig(const char *, bool) Cannot open config file /data/nfc/libnfc-nxpTransit.conf Line 9181: 01-01 00:02:54.518933 1736 1873 D : bool nxp::CNfcConfig::readConfig(const char *, bool) Opened base config /etc/libnfc-nxp.conf Line 9181: 01-01 00:02:54.518933 1736 1873 D : bool nxp::CNfcConfig::readConfig(const char *, bool) Opened base config /etc/libnfc-nxp.conf Line 9182: 01-01 00:02:54.523187 1736 1873 D : bool nxp::CNfcConfig::readConfig(const char *, bool) Opened optional config /etc/libnfc-brcm.conf Line 9185: 01-01 00:02:54.530700 1736 1873 E : bool nxp::CNfcConfig::readConfig(const char *, bool) Cannot open config file /data/nfc/libnfc-nxpTransit.conf Line 9185: 01-01 00:02:54.530700 1736 1873 E : bool nxp::CNfcConfig::readConfig(const char *, bool) Cannot open config file /data/nfc/libnfc-nxpTransit.conf Line 9186: 01-01 00:02:54.530998 1736 1873 D NxpExtns: const nxp::CNfcParam *nxp::CNfcConfig::find(const char *) const found NXPLOG_TML_LOGLEVEL=(0x3) Line 9186: 01-01 00:02:54.530998 1736 1873 D NxpExtns: const nxp::CNfcParam *nxp::CNfcConfig::find(const char *) const found NXPLOG_TML_LOGLEVEL=(0x3) Line 9186: 01-01 00:02:54.530998 1736 1873 D NxpExtns: const nxp::CNfcParam *nxp::CNfcConfig::find(const char *) const found NXPLOG_TML_LOGLEVEL=(0x3) Line 9186: 01-01 00:02:54.530998 1736 1873 D NxpExtns: const nxp::CNfcParam *nxp::CNfcConfig::find(const char *) const found NXPLOG_TML_LOGLEVEL=(0x3) Line 9187: 01-01 00:02:54.531047 1736 1873 D NxpExtns: const nxp::CNfcParam *nxp::CNfcConfig::find(const char *) const found NXPLOG_FWDNLD_LOGLEVEL=(0x3) Line 9187: 01-01 00:02:54.531047 1736 1873 D NxpExtns: const nxp::CNfcParam *nxp::CNfcConfig::find(const char *) const found NXPLOG_FWDNLD_LOGLEVEL=(0x3) Line 9187: 01-01 00:02:54.531047 1736 1873 D NxpExtns: const nxp::CNfcParam *nxp::CNfcConfig::find(const char *) const found NXPLOG_FWDNLD_LOGLEVEL=(0x3) Line 9187: 01-01 00:02:54.531047 1736 1873 D NxpExtns: const nxp::CNfcParam *nxp::CNfcConfig::find(const char *) const found NXPLOG_FWDNLD_LOGLEVEL=(0x3) Line 9188: 01-01 00:02:54.531086 1736 1873 D NxpExtns: const nxp::CNfcParam *nxp::CNfcConfig::find(const char *) const found NXPLOG_NCIX_LOGLEVEL=(0x3) Line 9188: 01-01 00:02:54.531086 1736 1873 D NxpExtns: const nxp::CNfcParam *nxp::CNfcConfig::find(const char *) const found NXPLOG_NCIX_LOGLEVEL=(0x3) Line 9188: 01-01 00:02:54.531086 1736 1873 D NxpExtns: const nxp::CNfcParam *nxp::CNfcConfig::find(const char *) const found NXPLOG_NCIX_LOGLEVEL=(0x3) Line 9188: 01-01 00:02:54.531086 1736 1873 D NxpExtns: const nxp::CNfcParam *nxp::CNfcConfig::find(const char *) const found NXPLOG_NCIX_LOGLEVEL=(0x3) Line 9189: 01-01 00:02:54.531122 1736 1873 D NxpExtns: const nxp::CNfcParam *nxp::CNfcConfig::find(const char *) const found NXPLOG_NCIR_LOGLEVEL=(0x3) Line 9189: 01-01 00:02:54.531122 1736 1873 D NxpExtns: const nxp::CNfcParam *nxp::CNfcConfig::find(const char *) const found NXPLOG_NCIR_LOGLEVEL=(0x3) Line 9189: 01-01 00:02:54.531122 1736 1873 D NxpExtns: const nxp::CNfcParam *nxp::CNfcConfig::find(const char *) const found NXPLOG_NCIR_LOGLEVEL=(0x3) Line 9189: 01-01 00:02:54.531122 1736 1873 D NxpExtns: const nxp::CNfcParam *nxp::CNfcConfig::find(const char *) const found NXPLOG_NCIR_LOGLEVEL=(0x3) Line 9190: 01-01 00:02:54.531172 1736 1873 D : phNxpLog_InitializeLogLevel: global =1, Fwdnld =3, extns =3, hal =3, tml =3, ncir =3, ncix =3 Line 9191: 01-01 00:02:54.531931 1736 1873 D NxpHal : Entering phNxpNciHal_init_monitor Line 9191: 01-01 00:02:54.531931 1736 1873 D NxpHal : Entering phNxpNciHal_init_monitor Line 9192: 01-01 00:02:54.532015 1736 1873 D NxpHal : Returning with SUCCESS Line 9193: 01-01 00:02:54.532094 1736 1873 D NxpExtns: const nxp::CNfcParam *nxp::CNfcConfig::find(const char *) const found NXP_NFC_DEV_NODE=/dev/pn544 Line 9193: 01-01 00:02:54.532094 1736 1873 D NxpExtns: const nxp::CNfcParam *nxp::CNfcConfig::find(const char *) const found NXP_NFC_DEV_NODE=/dev/pn544 Line 9193: 01-01 00:02:54.532094 1736 1873 D NxpExtns: const nxp::CNfcParam *nxp::CNfcConfig::find(const char *) const found NXP_NFC_DEV_NODE=/dev/pn544 Line 9193: 01-01 00:02:54.532094 1736 1873 D NxpExtns: const nxp::CNfcParam *nxp::CNfcConfig::find(const char *) const found NXP_NFC_DEV_NODE=/dev/pn544 Line 9194: 01-01 00:02:54.532147 1736 1873 D NxpTml : Opening port=/dev/pn544 Line 9195: 01-01 00:02:54.532307 1736 1873 D NxpTml : phTmlNfc_i2c_reset(), VEN level 0 Line 9196: 01-01 00:02:54.532377 1736 1873 E NxpTml : phTmlNfc_i2c_reset :failed errno = 0x16 Line 9198: 01-01 00:02:54.542660 1736 1873 D NxpTml : phTmlNfc_i2c_reset(), VEN level 1 Line 9200: 01-01 00:02:54.543030 1736 1873 E NxpTml : phTmlNfc_i2c_reset :failed errno = 0x16 Line 9201: 01-01 00:02:54.544699 1736 1888 D NxpTml : PN54X - Tml Reader Thread Started................ Line 9202: 01-01 00:02:54.544967 1736 1888 D NxpTml : PN54X - Read requested..... Line 9203: 01-01 00:02:54.545013 1736 1888 D NxpTml : PN54X - Invoking I2C Read..... Line 9209: 01-01 00:02:54.550076 1736 1889 D NxpTml : PN54X - Tml Writer Thread Started................ Line 9210: 01-01 00:02:54.550196 1736 1889 D NxpTml : PN54X - Tml Writer Thread Running................ Line 9211: 01-01 00:02:54.550880 1736 1891 D NxpHal : thread started Line 9219: 01-01 00:02:54.554407 1736 1873 D NxpExtns: const nxp::CNfcParam *nxp::CNfcConfig::find(const char *) const found MIFARE_READER_ENABLE=(0x1) Line 9219: 01-01 00:02:54.554407 1736 1873 D NxpExtns: const nxp::CNfcParam *nxp::CNfcConfig::find(const char *) const found MIFARE_READER_ENABLE=(0x1) Line 9219: 01-01 00:02:54.554407 1736 1873 D NxpExtns: const nxp::CNfcParam *nxp::CNfcConfig::find(const char *) const found MIFARE_READER_ENABLE=(0x1) Line 9220: 01-01 00:02:54.554623 1736 1889 D NxpTml : PN54X - Write requested..... Line 9221: 01-01 00:02:54.554689 1736 1889 D NxpTml : PN54X - Invoking I2C Write..... Line 9227: 01-01 00:02:54.582980 1736 1889 E NxpTml : _i2c_write() errno : 5 Line 9228: 01-01 00:02:54.583098 1736 1889 E NxpTml : PN54X - Error in I2C Write..... Line 9229: 01-01 00:02:54.583132 1736 1889 D NxpTml : PN54X - Posting Fresh Write message..... Line 9230: 01-01 00:02:54.583259 1736 1889 D NxpTml : PN54X - Tml Writer Thread Running................ Line 9232: 01-01 00:02:54.583758 1736 1891 E NxpHal : write error status = 0x1ff Line 9233: 01-01 00:02:54.583990 1736 1873 E NxpHal : write_unlocked failed - PN54X Maybe in Standby Mode - Retry Line 9236: 01-01 00:02:54.589262 1736 1889 D NxpTml : PN54X - Write requested..... Line 9237: 01-01 00:02:54.589323 1736 1889 D NxpTml : PN54X - Invoking I2C Write..... Line 9240: 01-01 00:02:54.611933 1736 1889 E NxpTml : _i2c_write() errno : 5 Line 9241: 01-01 00:02:54.612045 1736 1889 D NxpTml : PN54X - Posting Fresh Write message..... Line 9242: 01-01 00:02:54.612103 1736 1889 D NxpTml : PN54X - Tml Writer Thread Running................ Line 9243: 01-01 00:02:54.612285 1736 1891 E NxpHal : write error status = 0x1ff Line 9244: 01-01 00:02:54.612501 1736 1873 E NxpHal : write_unlocked failed - PN54X Maybe in Standby Mode - Retry Line 9251: 01-01 00:02:54.618355 1736 1889 D NxpTml : PN54X - Write requested..... Line 9252: 01-01 00:02:54.618508 1736 1889 D NxpTml : PN54X - Invoking I2C Write..... Line 9255: 01-01 00:02:54.641686 1736 1889 E NxpTml : _i2c_write() errno : 5 Line 9256: 01-01 00:02:54.641750 1736 1889 E NxpTml : PN54X - Error in I2C Write..... Line 9257: 01-01 00:02:54.641782 1736 1889 D NxpTml : PN54X - Posting Fresh Write message..... Line 9258: 01-01 00:02:54.641843 1736 1889 D NxpTml : PN54X - Tml Writer Thread Running................ Line 9259: 01-01 00:02:54.641947 1736 1891 E NxpHal : write error status = 0x1ff Line 9260: 01-01 00:02:54.642087 1736 1873 E NxpHal : write_unlocked failed - PN54X Maybe in Standby Mode - Retry Line 9261: 01-01 00:02:54.647441 1736 1889 D NxpTml : PN54X - Write requested..... Line 9262: 01-01 00:02:54.647552 1736 1889 D NxpTml : PN54X - Invoking I2C Write..... Line 9273: 01-01 00:02:54.672112 1736 1889 E NxpTml : _i2c_write() errno : 5 Line 9274: 01-01 00:02:54.672232 1736 1889 E NxpTml : PN54X - Error in I2C Write..... Line 9275: 01-01 00:02:54.672287 1736 1889 D NxpTml : PN54X - Posting Fresh Write message..... Line 9276: 01-01 00:02:54.672368 1736 1889 D NxpTml : PN54X - Tml Writer Thread Running................ Line 9277: 01-01 00:02:54.672432 1736 1891 E NxpHal : write error status = 0x1ff Line 9278: 01-01 00:02:54.672664 1736 1873 E NxpHal : write_unlocked failed - PN54X Maybe in Standby Mode - Retry Line 9282: 01-01 00:02:54.678179 1736 1889 D NxpTml : PN54X - Write requested..... Line 9283: 01-01 00:02:54.678306 1736 1889 D NxpTml : PN54X - Invoking I2C Write..... Line 9286: 01-01 00:02:54.701862 1736 1889 E NxpTml : _i2c_write() errno : 5 Line 9287: 01-01 00:02:54.701954 1736 1889 E NxpTml : PN54X - Error in I2C Write..... Line 9288: 01-01 00:02:54.701998 1736 1889 D NxpTml : PN54X - Posting Fresh Write message..... Line 9289: 01-01 00:02:54.702081 1736 1889 D NxpTml : PN54X - Tml Writer Thread Running................ Line 9290: 01-01 00:02:54.702262 1736 1891 E NxpHal : write error status = 0x1ff Line 9292: 01-01 00:02:54.702693 1736 1873 E NxpHal : write_unlocked failed - PN54X Maybe in Standby Mode - Retry Line 9293: 01-01 00:02:54.707987 1736 1889 D NxpTml : PN54X - Write requested..... Line 9294: 01-01 00:02:54.708059 1736 1889 D NxpTml : PN54X - Invoking I2C Write..... Line 9304: 01-01 00:02:54.731630 1736 1889 E NxpTml : _i2c_write() errno : 5 Line 9305: 01-01 00:02:54.731699 1736 1889 E NxpTml : PN54X - Error in I2C Write..... Line 9306: 01-01 00:02:54.731728 1736 1889 D NxpTml : PN54X - Posting Fresh Write message..... Line 9307: 01-01 00:02:54.731780 1736 1889 D NxpTml : PN54X - Tml Writer Thread Running................ Line 9308: 01-01 00:02:54.731869 1736 1891 E NxpHal : write error status = 0x1ff Line 9309: 01-01 00:02:54.731998 1736 1873 E NxpHal : write_unlocked failed - PN54X Maybe in Standby Mode (max count = 0x6) Line 9310: 01-01 00:02:54.732094 1736 1873 D NxpTml : phTmlNfc_i2c_reset(), VEN level 0 Line 9311: 01-01 00:02:54.732193 1736 1873 E NxpTml : phTmlNfc_i2c_reset :failed errno = 0x16 Line 9317: 01-01 00:02:54.742358 1736 1873 D NxpTml : phTmlNfc_i2c_reset(), VEN level 1 Line 9319: 01-01 00:02:54.742471 1736 1873 E NxpTml : phTmlNfc_i2c_reset :failed errno = 0x16 Line 9367: 01-01 00:02:54.842910 1736 1873 D NxpHal : PN54X Reset - SUCCESS 这样过滤完之后就只剩100多条了,从log上面看的流程是先通过读取配置文件得到对应的控制节点(/dev/pn544)和log打印等级,然后通过 ioctl 指令向芯片发送了下电上电的初始化指令(log里这一块返回了error 0x16),后续往节点写入的 ioctl 指令也没有正常执行(返回了error 5)。
sourcecode里通过 git grep 可以看到这个函数的定义是在 external/libnfc-nci/halimpl/pn54x/tml/phTmlNfc_i2c.h,而实现则是在 external/libnfc-nci/halimpl/pn54x/tml/phTmlNfc_i2c.c中。/******************************************************************************* ** ** Function phTmlNfc_i2c_reset ** ** Description Reset PN54X device, using VEN pin ** ** Parameters pDevHandle - valid device handle ** level - reset level ** ** Returns 0 - reset operation success ** -1 - reset operation failure ** *******************************************************************************/ int phTmlNfc_i2c_reset(void *pDevHandle, long level) { int ret = -1; NXPLOG_TML_D("phTmlNfc_i2c_reset(), VEN level %ld", level); if (NULL == pDevHandle) { return -1; } ret = ioctl((intptr_t)pDevHandle, PN544_SET_PWR, level); if(ret < 0) { NXPLOG_TML_E("%s :failed errno = 0x%x", __FUNCTION__, errno); if(level == 2 && errno == EBUSY) { notifyFwrequest = TRUE; }else{ notifyFwrequest = FALSE; } } if(level == 2 && ret == 0) { bFwDnldFlag = TRUE; }else{ bFwDnldFlag = FALSE; } return ret; }函数的功能也比较简单,就是发送一个 ioctl 的命令去与 kernel 进行通信,如果返回了通信报错就进行错误处理。P61_SET_SPI_PWR 这个指令的定义在 phTmlNfc_i2c.h 中,具体定义如下:
/*  * PN544 power control via ioctl  * PN544_SET_PWR(0): power off  * PN544_SET_PWR(1): power on  * PN544_SET_PWR(2): reset and power on with firmware download enabled  */ #define PN544_SET_PWR    _IOW(PN544_MAGIC, 0x01, long)这个指令的用途是用于给模块上/下电的,hal 层中的定义是 long 类型。再看一下 kernel 中定义的数据类型:/* * PN544 power control via ioctl * PN544_SET_PWR(0): power off * PN544_SET_PWR(1): power on * PN544_SET_PWR(2): reset and power on with firmware download enabled */ #define PN544_SET_PWR _IOW(PN544_MAGIC, 0x01, unsigned int) //#define PN544_SET_PWR 0x4004E901到这里就找到问题原因了,hal 层的指令在发送到 kernel 时由于发生了强转的报错所以报出了 errno = 16的报错。解决方案:1. 从 hal 中将 long 修改为 unsigned int2. 或者 kernel 中将 unsigned int 修改为 long