Maximum I2C Clock Frequency
-
@Morten-Nissov 1MHz is a supported clock rate for i2c on the DSP based on what I can see in the code. But we have never tried running a device at 1MHz on i2c so it's tough to say why it wouldn't be working for you.
-
@Eric-Katzfey We based the driver off of the IST8310 magnetometer driver, so setting
static constexpr uint32_t I2C_SPEED = 1000 * 1000; // 400 kHz I2C serial interface
which is used in the driver_main.cppextern "C" int tmag5273_main(int argc, char *argv[]) { int ch; using ThisDriver = TMAG5273; BusCLIArguments cli{true, false}; cli.i2c_address = I2C_ADDRESS_DEFAULT; cli.default_i2c_frequency = I2C_SPEED; ... BusInstanceIterator iterator(MODULE_NAME, cli, DRV_MAG_DEVTYPE_TMAG5273); if (!strcmp(verb, "start")) { return ThisDriver::module_start(cli, iterator); }
At lower I2C clock speeds it seems to work, so I would assume at least parts of the driver are correct. PX4 seems to crash right after calling the
qshell
line to start the driver.Edit: Setting
I2C_SPEED = 400 * 1000;
does not crash -
@Eric-Katzfey Also, we haven't added pullup-resistors ourselves. I'm not sure what kind of hardware already exists on the voxl 2 mini for this purpose. Cables are generally short though (<5cm) so I'm not sure how big of a deal this is.
-
@Morten-Nissov It's quite possible that even though the code appears to support that rate it may not. Unfortunately, there really is no way for us to figure this out without being able to replicate your hardware setup. So when it crashes can you look at dmesg afterwards and see if you see a message indicating that Slpi has crashed? I'm assuming that you are using the i2c pins 4 and 5 on connector J19?
-
I did a quick test using existing i2c barometer driver (ICP101XX which is on board on VOXL2). The driver has default speed of 100khz : https://github.com/modalai/px4-firmware/blob/voxl-dev/src/drivers/barometer/invensense/icp101xx/Inven_Sense_ICP101XX_registers.hpp#L47 . I changed the speed to 400k and 1M and it works. Values above that (i tried 3M) causes the driver to fail to open port, specifically i can see the dsp output (using
mini-dm
) in case of failure :[08500/01] 23:57.342 0047:01: SDSP: qshell gotten: icp101xx start -I -b 5 0088 qshell.cpp [08500/01] 23:57.342 0047:01: SDSP: arg0 = 'icp101xx' 0163 qshell.cpp [08500/01] 23:57.342 0047:01: SDSP: arg1 = 'start' 0163 qshell.cpp [08500/01] 23:57.342 0047:01: SDSP: arg2 = '-I' 0163 qshell.cpp [08500/01] 23:57.342 0047:01: SDSP: arg3 = '-b' 0163 qshell.cpp [08500/01] 23:57.342 0047:01: SDSP: arg4 = '5' 0163 qshell.cpp [08500/01] 23:57.345 0045:01: SDSP: *** I2C Device ID 0xb76329 12018473 0072 I2C.cpp [08500/02] 23:57.345 0045:01: SDSP: I2C Error: sns_scp_open failed 0885 sns_flight_controller_sensor_ [08500/03] 23:57.345 0045:01: SDSP: i2c init failed 0100 I2C.cpp
However, there is no crash even in case the port fails to open. At 1M speed, i am able to check module status using
qshell icp101xx status
and it does not report any bad transfersI can stop and start the driver at run time without an issue.
You can test this out using the barometer driver yourself as well. I suspect there maybe some other issue that causes a crash. Also, you can unplug your mag and see if the issue remains at 1M speed setting (the expected behavior is that the i2c port should open but device won't be found, so driver won't start)
Alex
-
Sorry both for the delay, I've been out of office over easter.
@Eric-Katzfey We've tried the magnetometer + magnetometer library with 1MHz I2C on a teensy, so at least the non-voxl2 mini components should support it. Yes you're correct, about the pins. I'll take a look at the dmesg outputs tomorrow and get back to you.
@Alex-Kushleyev I'll try this as well: 1) starting driver at 1M w/out sensor to see driver starts and reports device not found, 2) starting driver manually during runtime and see status output.
Thanks for the support!
-
I set the I2C frequency to
static constexpr uint32_t I2C_SPEED = 1000 * 1000; // 400 kHz I2C serial interface
and flash the voxl2-mini. I then manually start px4 byvoxl-px4 -d
and wait until all is started. I then started the magnetometer driver byqshell tmag5273 start -X -b 1
which causes the px4 session to start printing a lot of messages and stop responding to things like ctrl+c:pxh> qshell tmag5273 start -X -b 1 INFO [qshell] Send cmd: 'tmag5273 start -X -b 1' INFO [muorb] SLPI: Marking DeviceNode(qshell_req) as advertised in process_remote_topic INFO [muorb] SLPI: qshell gotten: tmag5273 start -X -b 1 INFO [muorb] SLPI: arg0 = 'tmag5273' INFO [muorb] SLPI: arg1 = 'start' INFO [muorb] SLPI: arg2 = '-X' INFO [muorb] SLPI: arg3 = '-b' INFO [muorb] SLPI: arg4 = '1' INFO [muorb] SLPI: *** I2C Device ID 0xd3509 865545 INFO [muorb] SLPI: Too many arming check events (1, 14 > 14). Not reporting all INFO [muorb] SLPI: Preflight Fail: Accel Sensor 0 missing INFO [muorb] SLPI: Preflight Fail: barometer 0 missing INFO [muorb] SLPI: Preflight Fail: ekf2 missing data INFO [muorb] SLPI: Preflight Fail: Gyro Sensor 0 missing INFO [muorb] SLPI: Preflight Fail: Compass Sensor 0 missing INFO [muorb] SLPI: Preflight Fail: Battery unhealthy >>> Got an exception from send_request <<< >>> Got an exception from send_request <<< >>> Send failed after retries <<< Sending topic message --- msg_id: 1033 --- topic name: offboard_control_mode Sending topic message --- msg_id: 1033 --- topic name: offboard_control_mode Sending topic message --- msg_id: 1033 --- topic name: offboard_control_mode Sending topic message --- msg_id: 1033 --- topic name: offboard_control_mode Sending topic message --- msg_id: 1033 --- topic name: telemetry_status Sending topic message --- msg_id: 1033 --- topic name: offboard_control_mode Sending topic message --- msg_id: 1033 --- topic name: telemetry_status Sending topic message --- msg_id: 1033 --- topic name: offboard_control_mode Connection error: connection reset Sending topic message --- msg_id: 1033 --- topic name: offboard_control_mode Got response cb 0 Got flight controller event Received standard error event SNS_STD_ERROR_NOT_SUPPORTED Sending topic message --- msg_id: 1033 --- topic name: cpuload Got response cb 0 Got flight controller event Received standard error event SNS_STD_ERROR_NOT_SUPPORTED Sending topic message --- msg_id: 1033 --- topic name: offboard_control_mode Got response cb 0 Got flight controller event Received standard error event SNS_STD_ERROR_NOT_SUPPORTED Sending topic message --- msg_id: 1033 --- topic name: offboard_control_mode Got response cb 0 Got flight controller event Received standard error event SNS_STD_ERROR_NOT_SUPPORTED
The dmesg output seems too long, I'm not entirely sure what exactly I'm looking for but this piece at the end seemed interesting:
[ 5.610560] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.615800] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.617899] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.618780] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.621479] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.622003] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.622899] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.622989] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.623637] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.624191] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.624915] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.626410] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.629129] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.631157] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.633089] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.633682] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.633727] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.641154] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.642545] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.645431] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.649037] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.649964] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.653350] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.660602] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.661748] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.670667] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.670926] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.671126] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.677110] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.679867] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.679921] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.680361] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.681618] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.681731] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.682135] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.682902] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.683738] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.683871] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.683900] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.684928] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.686749] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.687598] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.688077] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.689980] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.691480] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.692511] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.692563] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.692698] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.694912] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.695387] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.695556] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.697739] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.698446] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.698871] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.699012] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.701161] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.702005] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.704599] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.705506] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 5.706275] ufshcd-qcom 1d84000.ufshc: ufshcd_ioctl: User buffer is NULL! [ 6.202818] spi_geni 98c000.spi: tx_fifo 16 rx_fifo 16 tx_width 32 [ 6.300368] Started adbd. [ 7.122898] devfreq-qcom-fw 18590000.qcom,devfreq-l3:qcom,cdsp-cdsp-l3-lat: Successfully started CDSP L3 governor [ 7.615569] CAM_ERR: CAM-MEM: cam_mem_mgr_create_debug_fs: 126 failed to create dentry [ 7.645673] CAM_INFO: CAM-HFI: cam_hfi_init: 878 Init IO1 : [0x10c00000 0xcf300000] IO2 [0xe0200000 0x1ed00000] [ 7.655955] CAM_INFO: CAM-ICP: cam_icp_mgr_hw_open: 3879 FW download done successfully [ 7.655962] CAM_INFO: CAM-ICP: cam_icp_mgr_process_dbg_buf: 2572 FW_DBG:CICP_FW_E : HFI :QC_IMAGE_VERSION_STRING=CICP.FW.1.0-00079,OEM_IMAGE_VERSION_STRING=CRM,BUILD_TIME: Oct 17 2019 05:49:19,CACHE_ENABLED at icphostinterface.c:636 QC_IMAGE_VERSION_STRING=CICP.FW.1.0-00079 OEM_IMAGE_VERSION_STRING=CRM [ 7.655968] CAM_INFO: CAM-ICP: cam_icp_mgr_process_dbg_buf: 2572 FW_DBG:CICP_FW_E : HFI :ELF variant: CACHE-ENABLED:T480:API_V2:USE_CDM_1_1: , API version: 0x2000049 at icphostinterface.c:637 QC_IMAGE_VERSION_STRING=CICP.FW.1.0-00079 OEM_IMAGE_VERSION_STRING=CRM [ 7.826104] qcom,camera ac4f000.qcom,cci:qcom,cam-sensor0: Linked as a consumer to regulator.60 [ 7.826159] qcom,camera ac4f000.qcom,cci:qcom,cam-sensor0: Linked as a consumer to regulator.79 [ 7.849942] CAM_ERR: CAM-CCI: cam_cci_irq: 238 Base: pK-error, M0_Q1 NACK ERROR: 0x10000000 [ 7.850128] CAM_ERR: CAM-CCI: cam_cci_read: 1329 ERROR with Slave 0x7a: [ 7.850139] CAM_ERR: CAM-CCI: cam_cci_read_bytes: 1613 failed to read rc:-22 [ 7.850147] CAM_ERR: CAM-SENSOR: cam_cci_i2c_read: 35 rc = -22 [ 7.850158] CAM_WARN: CAM-SENSOR: cam_sensor_match_id: 707 read id: 0x0 expected id 0x3d: [ 7.850328] qcom,camera ac4f000.qcom,cci:qcom,cam-sensor0: Dropping the link to regulator.79 [ 7.854323] qcom,camera ac4f000.qcom,cci:qcom,cam-sensor0: Dropping the link to regulator.60 [ 7.883924] qcom,camera ac50000.qcom,cci:qcom,cam-sensor2: Linked as a consumer to regulator.60 [ 7.884305] qcom,camera ac50000.qcom,cci:qcom,cam-sensor2: Linked as a consumer to regulator.79 [ 7.901272] CAM_ERR: CAM-CCI: cam_cci_irq: 238 Base: pK-error, M0_Q1 NACK ERROR: 0x10000000 [ 7.901342] CAM_ERR: CAM-CCI: cam_cci_read: 1329 ERROR with Slave 0x20: [ 7.901351] CAM_ERR: CAM-CCI: cam_cci_read_bytes: 1613 failed to read rc:-22 [ 7.901358] CAM_ERR: CAM-SENSOR: cam_cci_i2c_read: 35 rc = -22 [ 7.901367] CAM_WARN: CAM-SENSOR: cam_sensor_match_id: 707 read id: 0x0 expected id 0x214: [ 7.901521] qcom,camera ac50000.qcom,cci:qcom,cam-sensor2: Dropping the link to regulator.79 [ 7.905194] qcom,camera ac50000.qcom,cci:qcom,cam-sensor2: Dropping the link to regulator.60 [ 7.933390] qcom,camera ac50000.qcom,cci:qcom,cam-sensor3: Linked as a consumer to regulator.55 [ 7.935713] qcom,camera ac50000.qcom,cci:qcom,cam-sensor3: Linked as a consumer to regulator.60 [ 7.935848] qcom,camera ac50000.qcom,cci:qcom,cam-sensor3: Linked as a consumer to regulator.79 [ 7.959966] CAM_INFO: CAM-SENSOR: cam_sensor_set_alt_id: 731 [Applying Alternative Address] : Sensor Index : 1464402100 [ 7.959977] CAM_INFO: CAM-SENSOR: cam_sensor_set_alt_id: 732 [Applying Alternative Address] : Slave Address : 0xE2 [ 7.959985] CAM_INFO: CAM-SENSOR: cam_sensor_set_alt_id: 733 [Applying Alternative Address] : Slave sensor id: 0x7750 [ 7.959993] CAM_INFO: CAM-SENSOR: cam_sensor_set_alt_id: 734 [Applying Alternative Address] : cci_client sid : 0x71 [ 7.960434] CAM_ERR: CAM-CCI: cam_cci_irq: 258 Base: pK-error, M1_Q0 NACK ERROR: 0x20000000 [ 7.960506] CAM_ERR: CAM-CCI: cam_cci_wait: 270 failed rc -22 [ 7.960515] CAM_ERR: CAM-CCI: cam_cci_transfer_end: 345 failed rc -22 [ 7.960526] CAM_ERR: CAM-CCI: cam_cci_data_queue: 870 Slave: 0xe0 failed rc -22 [ 7.960533] CAM_ERR: CAM-CCI: cam_cci_i2c_write: 1450 failed rc: -22 [ 7.960542] CAM_ERR: CAM-SENSOR: cam_cci_i2c_write_table_cmd: 123 Failed rc = -22 [ 7.960550] CAM_ERR: CAM-SENSOR: cam_sensor_set_alt_id: 768 [Applying Alternative Address] : Probe : camera_io_dev_write failed: rc=-22 [ 7.960701] CAM_ERR: CAM-CCI: cam_cci_irq: 264 Base: pK-error, M1_Q1 NACK ERROR: 0x40000000 [ 7.960766] CAM_ERR: CAM-CCI: cam_cci_read: 1329 ERROR with Slave 0xe0: [ 7.960774] CAM_ERR: CAM-CCI: cam_cci_read_bytes: 1613 failed to read rc:-22 [ 7.960781] CAM_ERR: CAM-SENSOR: cam_cci_i2c_read: 35 rc = -22 [ 7.960789] CAM_WARN: CAM-SENSOR: cam_sensor_match_id: 707 read id: 0x0 expected id 0x7750: [ 7.960912] qcom,camera ac50000.qcom,cci:qcom,cam-sensor3: Dropping the link to regulator.79 [ 7.964320] qcom,camera ac50000.qcom,cci:qcom,cam-sensor3: Dropping the link to regulator.60 [ 7.964463] qcom,camera ac50000.qcom,cci:qcom,cam-sensor3: Dropping the link to regulator.55 [ 8.017749] CAM_WARN: CAM-CRM: cam_req_mgr_close: 160 release invoked associated userspace process has died [ 10.386107] CAM_ERR: CAM-MEM: cam_mem_mgr_create_debug_fs: 126 failed to create dentry [ 10.401487] CAM_INFO: CAM-HFI: cam_hfi_init: 878 Init IO1 : [0x10c00000 0xcf300000] IO2 [0xe0200000 0x1ed00000] [ 10.412099] CAM_INFO: CAM-ICP: cam_icp_mgr_hw_open: 3879 FW download done successfully [ 10.412119] CAM_INFO: CAM-ICP: cam_icp_mgr_process_dbg_buf: 2572 FW_DBG:CICP_FW_E : HFI :QC_IMAGE_VERSION_STRING=CICP.FW.1.0-00079,OEM_IMAGE_VERSION_STRING=CRM,BUILD_TIME: Oct 17 2019 05:49:19,CACHE_ENABLED at icphostinterface.c:636 QC_IMAGE_VERSION_STRING=CICP.FW.1.0-00079 OEM_IMAGE_VERSION_STRING=CRM [ 10.412130] CAM_INFO: CAM-ICP: cam_icp_mgr_process_dbg_buf: 2572 FW_DBG:CICP_FW_E : HFI :ELF variant: CACHE-ENABLED:T480:API_V2:USE_CDM_1_1: , API version: 0x2000049 at icphostinterface.c:637 QC_IMAGE_VERSION_STRING=CICP.FW.1.0-00079 OEM_IMAGE_VERSION_STRING=CRM [ 10.481289] qcom,camera ac4f000.qcom,cci:qcom,cam-sensor0: Linked as a consumer to regulator.60 [ 10.481326] qcom,camera ac4f000.qcom,cci:qcom,cam-sensor0: Linked as a consumer to regulator.79 [ 10.504189] CAM_ERR: CAM-CCI: cam_cci_irq: 238 Base: pK-error, M0_Q1 NACK ERROR: 0x10000000 [ 10.504359] CAM_ERR: CAM-CCI: cam_cci_read: 1329 ERROR with Slave 0x7a: [ 10.504366] CAM_ERR: CAM-CCI: cam_cci_read_bytes: 1613 failed to read rc:-22 [ 10.504370] CAM_ERR: CAM-SENSOR: cam_cci_i2c_read: 35 rc = -22 [ 10.504374] CAM_WARN: CAM-SENSOR: cam_sensor_match_id: 707 read id: 0x0 expected id 0x3d: [ 10.504462] qcom,camera ac4f000.qcom,cci:qcom,cam-sensor0: Dropping the link to regulator.79 [ 10.508103] qcom,camera ac4f000.qcom,cci:qcom,cam-sensor0: Dropping the link to regulator.60 [ 10.534478] qcom,camera ac50000.qcom,cci:qcom,cam-sensor2: Linked as a consumer to regulator.60 [ 10.534525] qcom,camera ac50000.qcom,cci:qcom,cam-sensor2: Linked as a consumer to regulator.79 [ 10.550529] CAM_ERR: CAM-CCI: cam_cci_irq: 238 Base: pK-error, M0_Q1 NACK ERROR: 0x10000000 [ 10.550681] CAM_ERR: CAM-CCI: cam_cci_read: 1329 ERROR with Slave 0x20: [ 10.550686] CAM_ERR: CAM-CCI: cam_cci_read_bytes: 1613 failed to read rc:-22 [ 10.550688] CAM_ERR: CAM-SENSOR: cam_cci_i2c_read: 35 rc = -22 [ 10.550691] CAM_WARN: CAM-SENSOR: cam_sensor_match_id: 707 read id: 0x0 expected id 0x214: [ 10.550759] qcom,camera ac50000.qcom,cci:qcom,cam-sensor2: Dropping the link to regulator.79 [ 10.554106] qcom,camera ac50000.qcom,cci:qcom,cam-sensor2: Dropping the link to regulator.60 [ 10.581531] qcom,camera ac50000.qcom,cci:qcom,cam-sensor3: Linked as a consumer to regulator.55 [ 10.584273] qcom,camera ac50000.qcom,cci:qcom,cam-sensor3: Linked as a consumer to regulator.60 [ 10.584486] qcom,camera ac50000.qcom,cci:qcom,cam-sensor3: Linked as a consumer to regulator.79 [ 10.609377] CAM_INFO: CAM-SENSOR: cam_sensor_set_alt_id: 731 [Applying Alternative Address] : Sensor Index : 1464402100 [ 10.609388] CAM_INFO: CAM-SENSOR: cam_sensor_set_alt_id: 732 [Applying Alternative Address] : Slave Address : 0xE2 [ 10.609396] CAM_INFO: CAM-SENSOR: cam_sensor_set_alt_id: 733 [Applying Alternative Address] : Slave sensor id: 0x7750 [ 10.609404] CAM_INFO: CAM-SENSOR: cam_sensor_set_alt_id: 734 [Applying Alternative Address] : cci_client sid : 0x71 [ 10.609591] CAM_ERR: CAM-CCI: cam_cci_irq: 258 Base: pK-error, M1_Q0 NACK ERROR: 0x20000000 [ 10.609649] CAM_ERR: CAM-CCI: cam_cci_wait: 270 failed rc -22 [ 10.609658] CAM_ERR: CAM-CCI: cam_cci_transfer_end: 345 failed rc -22 [ 10.609668] CAM_ERR: CAM-CCI: cam_cci_data_queue: 870 Slave: 0xe0 failed rc -22 [ 10.609677] CAM_ERR: CAM-CCI: cam_cci_i2c_write: 1450 failed rc: -22 [ 10.609686] CAM_ERR: CAM-SENSOR: cam_cci_i2c_write_table_cmd: 123 Failed rc = -22 [ 10.609695] CAM_ERR: CAM-SENSOR: cam_sensor_set_alt_id: 768 [Applying Alternative Address] : Probe : camera_io_dev_write failed: rc=-22 [ 10.609780] CAM_ERR: CAM-CCI: cam_cci_read: 1340 read_words = 0, exp words = 1 [ 10.609789] CAM_ERR: CAM-CCI: cam_cci_read_bytes: 1613 failed to read rc:-22 [ 10.609807] CAM_ERR: CAM-SENSOR: cam_cci_i2c_read: 35 rc = -22 [ 10.609828] CAM_WARN: CAM-SENSOR: cam_sensor_match_id: 707 read id: 0x0 expected id 0x7750: [ 10.609850] CAM_ERR: CAM-CCI: cam_cci_irq: 264 Base: pK-error, M1_Q1 NACK ERROR: 0x40000000 [ 10.610038] qcom,camera ac50000.qcom,cci:qcom,cam-sensor3: Dropping the link to regulator.79 [ 10.614302] qcom,camera ac50000.qcom,cci:qcom,cam-sensor3: Dropping the link to regulator.60 [ 10.614426] qcom,camera ac50000.qcom,cci:qcom,cam-sensor3: Dropping the link to regulator.55 [ 10.667487] CAM_WARN: CAM-CRM: cam_req_mgr_close: 160 release invoked associated userspace process has died [ 16.001681] msm-usb-ssphy-qmp 88e8000.ssphy: USB DP QMP PHY: Update TYPEC CTRL(3) [ 16.056809] msm-dwc3 a600000.ssusb: DWC3 exited from low power mode [ 16.588523] android_work: sent uevent USB_STATE=CONNECTED [ 16.595024] android_work: sent uevent USB_STATE=DISCONNECTED [ 16.708577] android_work: sent uevent USB_STATE=CONNECTED [ 16.719299] configfs-gadget gadget: high-speed config #1: c [ 16.720248] android_work: sent uevent USB_STATE=CONFIGURED [ 33.761075] vdd_tof: disabling [ 33.761082] vdd_hap_boost: disabling [ 101.427770] boot log copy done [ 386.820967] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x41b08 [ 493.337423] Fatal error on slpi! [ 493.337495] slpi subsystem failure reason: err_qdi.c:1063:PC=b21d30bc,SP=317b8a48,FP=317b8a78,LR=b21d300c,BADVA=96,CAUSE=7003,TASK=Anonymous. [ 493.337517] subsys-restart: subsystem_restart_dev(): Restart sequence requested for slpi, restart_level = RELATED. [ 493.338559] adsprpc: fastrpc_restart_notifier_cb: slpi subsystem is restarting [ 493.338564] subsys-restart: subsystem_shutdown(): [kworker/u19:0:1832]: Shutting down slpi [ 493.350877] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30030 [ 493.350922] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30040 [ 493.354910] coresight-remote-etm soc:ssc_etm0: Connection disconnected between QMI handle and 8 service [ 493.354939] sysmon-qmi: ssctl_del_server: Connection lost between QMI handle and slpi's SSCTL service [ 493.355792] adsprpc: fastrpc_rpmsg_remove: closed rpmsg channel of slpi [ 493.357015] adsprpc: fastrpc_restart_notifier_cb: received RAMDUMP notification for slpi [ 493.358631] subsys-restart: subsystem_powerup(): [kworker/u19:0:1832]: Powering up slpi [ 493.359427] subsys-pil-tz 5c00000.qcom,ssc: slpi: loading from 0x0000000088c00000 to 0x000000008a600000 [ 493.424824] subsys-pil-tz 5c00000.qcom,ssc: slpi: Brought out of reset [ 493.481943] subsys-pil-tz 5c00000.qcom,ssc: Subsystem error monitoring/handling services are up [ 493.481967] subsys-pil-tz 5c00000.qcom,ssc: slpi: Power/Clock ready interrupt received [ 493.485644] adsprpc: fastrpc_restart_notifier_cb: slpi subsystem is up [ 493.485650] subsys-restart: subsystem_restart_wq_func(): [kworker/u19:0:1832]: Restart sequence for slpi completed. [ 493.486551] 724585192:Entered [ 493.487029] 724585192:SMD QRTR driver probed [ 493.491727] adsprpc: fastrpc_rpmsg_probe: opened rpmsg channel for slpi [ 493.496270] sysmon-qmi: ssctl_new_server: Connection established between QMI handle and slpi's SSCTL service [ 493.496274] coresight-remote-etm soc:ssc_etm0: Connection established between QMI handle and 8 service [ 493.500386] diag: In diag_send_peripheral_buffering_mode, buffering flag not set for 3 [ 511.812370] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x41b08 [ 511.812390] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x41b08 [ 543.813331] Fatal error on slpi! [ 543.813445] slpi subsystem failure reason: err_qdi.c:1063:EF:sensor_process:0x1:Anonymous:0x3f:sns_com_port_i2c.c:239:status != I2C_ERROR_TRANSFER_TIMEOUT. [ 543.813505] subsys-restart: subsystem_restart_dev(): Restart sequence requested for slpi, restart_level = RELATED. [ 543.816229] adsprpc: fastrpc_restart_notifier_cb: slpi subsystem is restarting [ 543.816239] subsys-restart: subsystem_shutdown(): [kworker/u19:0:1832]: Shutting down slpi [ 543.830145] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30030 [ 543.830185] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30040 [ 543.830198] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30040 [ 543.832708] adsprpc: fastrpc_rpmsg_remove: closed rpmsg channel of slpi [ 543.833188] adsprpc: fastrpc_restart_notifier_cb: received RAMDUMP notification for slpi [ 543.834471] coresight-remote-etm soc:ssc_etm0: Connection disconnected between QMI handle and 8 service [ 543.834596] sysmon-qmi: ssctl_del_server: Connection lost between QMI handle and slpi's SSCTL service [ 543.834722] subsys-restart: subsystem_powerup(): [kworker/u19:0:1832]: Powering up slpi [ 543.835597] subsys-pil-tz 5c00000.qcom,ssc: slpi: loading from 0x0000000088c00000 to 0x000000008a600000 [ 543.900964] subsys-pil-tz 5c00000.qcom,ssc: slpi: Brought out of reset [ 543.962375] subsys-pil-tz 5c00000.qcom,ssc: Subsystem error monitoring/handling services are up [ 543.962598] subsys-pil-tz 5c00000.qcom,ssc: slpi: Power/Clock ready interrupt received [ 543.966771] adsprpc: fastrpc_restart_notifier_cb: slpi subsystem is up [ 543.966785] subsys-restart: subsystem_restart_wq_func(): [kworker/u19:0:1832]: Restart sequence for slpi completed. [ 543.967361] 724585192:Entered [ 543.967859] 724585192:SMD QRTR driver probed [ 543.972003] adsprpc: fastrpc_rpmsg_probe: opened rpmsg channel for slpi [ 543.986270] sysmon-qmi: ssctl_new_server: Connection established between QMI handle and slpi's SSCTL service [ 543.986299] coresight-remote-etm soc:ssc_etm0: Connection established between QMI handle and 8 service [ 543.987828] diag: In diag_send_peripheral_buffering_mode, buffering flag not set for 3 [ 545.281536] Fatal error on slpi! [ 545.281639] slpi subsystem failure reason: err_qdi.c:1063:EF:sensor_process:0x1:SNS_SEE_I_1:0x68:sns_stream_service.c:436:req_found. [ 545.281693] subsys-restart: subsystem_restart_dev(): Restart sequence requested for slpi, restart_level = RELATED. [ 545.282937] adsprpc: fastrpc_restart_notifier_cb: slpi subsystem is restarting [ 545.282951] subsys-restart: subsystem_shutdown(): [kworker/u19:0:1832]: Shutting down slpi [ 545.296247] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30030 [ 545.296267] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30030 [ 545.296342] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30040 [ 545.299310] coresight-remote-etm soc:ssc_etm0: Connection disconnected between QMI handle and 8 service [ 545.299396] adsprpc: fastrpc_rpmsg_remove: closed rpmsg channel of slpi [ 545.299877] sysmon-qmi: ssctl_del_server: Connection lost between QMI handle and slpi's SSCTL service [ 545.300918] adsprpc: fastrpc_restart_notifier_cb: received RAMDUMP notification for slpi [ 545.302334] subsys-restart: subsystem_powerup(): [kworker/u19:0:1832]: Powering up slpi [ 545.302732] subsys-pil-tz 5c00000.qcom,ssc: slpi: loading from 0x0000000088c00000 to 0x000000008a600000 [ 545.376922] subsys-pil-tz 5c00000.qcom,ssc: slpi: Brought out of reset [ 545.438467] subsys-pil-tz 5c00000.qcom,ssc: Subsystem error monitoring/handling services are up [ 545.438529] subsys-pil-tz 5c00000.qcom,ssc: slpi: Power/Clock ready interrupt received [ 545.442768] adsprpc: fastrpc_restart_notifier_cb: slpi subsystem is up [ 545.442783] subsys-restart: subsystem_restart_wq_func(): [kworker/u19:0:1832]: Restart sequence for slpi completed. [ 545.443409] 724585192:Entered [ 545.443972] 724585192:SMD QRTR driver probed [ 545.449760] adsprpc: fastrpc_rpmsg_probe: opened rpmsg channel for slpi [ 545.451027] sysmon-qmi: ssctl_new_server: Connection established between QMI handle and slpi's SSCTL service [ 545.451059] coresight-remote-etm soc:ssc_etm0: Connection established between QMI handle and 8 service [ 545.459198] diag: In diag_send_peripheral_buffering_mode, buffering flag not set for 3 [ 546.775564] Fatal error on slpi! [ 546.775671] slpi subsystem failure reason: err_qdi.c:1063:EF:sensor_process:0x1:SNS_SEE_I_0:0x69:sns_stream_service.c:436:req_found. [ 546.775730] subsys-restart: subsystem_restart_dev(): Restart sequence requested for slpi, restart_level = RELATED. [ 546.777007] adsprpc: fastrpc_restart_notifier_cb: slpi subsystem is restarting [ 546.777020] subsys-restart: subsystem_shutdown(): [kworker/u19:0:1832]: Shutting down slpi [ 546.790351] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30030 [ 546.793366] adsprpc: fastrpc_rpmsg_remove: closed rpmsg channel of slpi [ 546.793908] coresight-remote-etm soc:ssc_etm0: Connection disconnected between QMI handle and 8 service [ 546.794365] sysmon-qmi: ssctl_del_server: Connection lost between QMI handle and slpi's SSCTL service [ 546.794985] adsprpc: fastrpc_restart_notifier_cb: received RAMDUMP notification for slpi [ 546.798133] subsys-restart: subsystem_powerup(): [kworker/u19:0:1832]: Powering up slpi [ 546.798436] subsys-pil-tz 5c00000.qcom,ssc: slpi: loading from 0x0000000088c00000 to 0x000000008a600000 [ 546.878630] subsys-pil-tz 5c00000.qcom,ssc: slpi: Brought out of reset [ 546.941273] subsys-pil-tz 5c00000.qcom,ssc: Subsystem error monitoring/handling services are up [ 546.941338] subsys-pil-tz 5c00000.qcom,ssc: slpi: Power/Clock ready interrupt received [ 546.941470] qcom_rpmh DRV:apps_rsc TCS Busy, retrying RPMH message send: addr=0x30040 [ 546.943459] adsprpc: fastrpc_restart_notifier_cb: slpi subsystem is up [ 546.943465] subsys-restart: subsystem_restart_wq_func(): [kworker/u19:0:1832]: Restart sequence for slpi completed. [ 546.943741] 724585192:Entered [ 546.944172] 724585192:SMD QRTR driver probed [ 546.945397] sysmon-qmi: ssctl_new_server: Connection established between QMI handle and slpi's SSCTL service [ 546.945412] coresight-remote-etm soc:ssc_etm0: Connection established between QMI handle and 8 service [ 546.949929] adsprpc: fastrpc_rpmsg_probe: opened rpmsg channel for slpi [ 546.955524] diag: In diag_send_peripheral_buffering_mode, buffering flag not set for 3
in particular the line
[ 493.337495] slpi subsystem failure reason: err_qdi.c:1063:PC=b21d30bc,SP=317b8a48,FP=317b8a78,LR=b21d300c,BADVA=96,CAUSE=7003,TASK=Anonymous.
-
Hi again,
If it's of any help, the repo we're developing this on is: https://github.com/ntnu-arl/modalai-px4-firmware/tree/dev/tmag5273
There isn't really much going on aside from blending a sparkfun library into the ist8310 impl used as a px4 driver template.
-
@Morten-Nissov Yes, that means the DSP running PX4 crashed
-
@Morten-Nissov This line doesn't look good:
ScheduleDelayed(1_us);
That's too fast -
@Eric-Katzfey I saw the shedule delayed call in the driver we used as template (with a different number), do you have a recommendation for what a lower bound should be?
We intentionally set it very low to gauge whether the I2C communication was limiting our update rate in the 400kHz case, which it was.
-
@Eric-Katzfey Hi again,
The same happens setting ScheduleDelayed to 20ms (even as high as 100ms). So I guess we're never getting to this point in the code before crashing.
Edit: The driver manages to run
if (!strcmp(verb, "start")) { return ThisDriver::module_start(cli, iterator); }
however it never manages to enter
void TMAG5273::RunImpl()
. It seems like the crash happens atint ret = I2C::init();
inTMAG5273::init()
. Using print statements I can see it never manages to execute any line which requires using I2C (e.g. reading a register for probing), which would seem to make sense is I2C never manages to startup.Edit2: As per @Alex-Kushleyev message, I can also manage to change the barometer rate to 1MHz and it starts successfully:
INFO [muorb] SLPI: qshell gotten: icp101xx start -I -b 5 INFO [muorb] SLPI: arg0 = 'icp101xx' INFO [muorb] SLPI: arg1 = 'start' INFO [muorb] SLPI: arg2 = '-I' INFO [muorb] SLPI: arg3 = '-b' INFO [muorb] SLPI: arg4 = '5' INFO [muorb] SLPI: *** I2C Device ID 0xb76329 12018473 INFO [muorb] SLPI: icp101xx #0 on I2C bus 5 INFO [muorb] SLPI: address 0x63 INFO [muorb] SLPI: INFO [muorb] SLPI: Ok executing command: icp101xx start -I -b 5
As far as I can see there is virtually no difference in how our mag driver and the barometer driver initialize the I2C object. Note, unplugging the magnetometer results in the same crash as before
INFO [muorb] SLPI: qshell gotten: tmag5273 start -X -b 1 INFO [muorb] SLPI: arg0 = 'tmag5273' INFO [muorb] SLPI: arg1 = 'start' INFO [muorb] SLPI: arg2 = '-X' INFO [muorb] SLPI: arg3 = '-b' INFO [muorb] SLPI: arg4 = '1' INFO [muorb] SLPI: -----------------------here------------------- INFO [muorb] SLPI: -----------------------hi------------------- INFO [muorb] SLPI: -----------------------start------------------- INFO [muorb] SLPI: *** I2C Device ID 0xd3509 865545 INFO [muorb] SLPI: -------------------- const INFO [muorb] SLPI: -------------------- init INFO [muorb] SLPI: -------------------- probe INFO [muorb] SLPI: -------------------- isConnected INFO [muorb] SLPI: Too many arming check events (1, 14 > 14). Not reporting all INFO [muorb] SLPI: Preflight Fail: Accel Sensor 0 missing INFO [muorb] SLPI: Preflight Fail: barometer 0 missing INFO [muorb] SLPI: Preflight Fail: ekf2 missing data INFO [muorb] SLPI: Preflight Fail: Gyro Sensor 0 missing INFO [muorb] SLPI: Preflight Fail: Compass Sensor 0 missing INFO [muorb] SLPI: Preflight Fail: Battery unhealthy >>> Got an exception from send_request <<< >>> Send succeeded after retries <<< Sending topic message --- msg_id: 1033 --- topic name: offboard_control_mode
Note, this time there are some print statement I added to check where the crash was happening. As before it doesn't manage to get past
int ret = I2C::init();
. -
I am not sure exactly what the issue is with 1Mbit i2c rate, but i see another way how you can speed up your reads. Currently the code reads each of the 3 axes separately (X, Y and Z) and each axis is using two separate i2c calls to read the value (LSB and MSB). For each single byte read, it actually takes about 3 bytes (time-wise) because the first byte is the slave address, second byte is the address of register to read and 3rd byte is actual value sent by the sensor.
All the result registers are stored one after another, specifically designed to be read in a single batch : https://github.com/ntnu-arl/modalai-px4-firmware/blob/dev/tmag5273/src/drivers/magnetometer/tmag5273/TI_TMAG5273_registers.hpp#L187 . So you should change your code to make a single read to read all of the result registers, and if you use the current 400khz, you will get at least 3x speedup, at least in the reading part. Then you have to make sure the sensor has completed the conversion, or whatever is steps are needed for the sensor update cycle.
Alex
-
@Alex-Kushleyev Sorry if this is a stupid question, for reading more than one byte with the px4 I2C implementation we do this by calling
transfer(&cmd, 1, &buffer, num_read);
with the appropriate number fornum_read
, or is there more to do? -
Yes you can read more than 1 byte at a time by setting num_read accordingly and making sure the buffer for holding the incoming data is large enough. You would need to set the read address to the start address where you want to start reading the data array.
Then you will need to parse the data out of the returned array into x, y, z axes (and temperature if you are reading that).
-
@Alex-Kushleyev Sorry didn't see the message, but ended up getting the same place. Implemented a read multiple registers which seems to work:
void TMAG5273::RegisterReadMultiple(Register reg, uint8_t* buffer, uint8_t bytes) { const uint8_t cmd = static_cast<uint8_t>(reg); transfer(&cmd, 1, buffer, bytes); }
This turned out to be significantly faster (~4x I think), so even without 1MHz I think it could be sufficient for us. Thanks for the help!
-
@Morten-Nissov , great! You are welcome. Make sure to change that 1us scheduling interval to a more reasonable value
-