This thread has been locked.

If you have a related question, please click the "Ask a related question" button in the top right corner. The newly created question will be automatically linked to this question.

Linux/TDA2PXEVM: "exportDmaBuf failed"

Part Number: TDA2PXEVM

Tool/software: Linux

Hi:

  The issue happened in our product board which have 512M, the use case as following:

5238.uc_cfg.txt
UC_srv_calibration=yes
UC_csi2Cal_multi_cam_view=yes
UC_csi2Cal_multi_cam_3d_srv=yes

ifeq ($(ISS_INCLUDE),yes)
UC_iss_capture_isp_simcop_display=yes
UC_iss_multi_cam_isp_sgx_3d_srv_display=yes
UC_iss_multi_cam_isp_sgx_2mp_3d_srv=yes
UC_iss_multi_cam_isp_sgx_2mp_3d_srv_adaptive=yes
endif

UC_vip_single_cam_connectorLinksA15_sgx_display=yes
UC_vip_single_cam_enc_dec_sgx_display=yes
UC_vip_single_cam_framecopy_sgx_display=yes
UC_vip_single_cam_framecopyEve_sgx_display=yes
UC_vip_single_cam_sgx_display=yes

UC_srv_calibration=yes
UC_lvds_vip_multi_cam_3d_srv=yes
UC_lvds_vip_multi_cam_view_sgx_display=yes

ifeq ($(AVB_INCLUDE),yes)
UC_avb_rx_multi_cam_decode_sgx_display=yes
endif
3247.cfg.txt
#
# This file defines the modules included in $(MAKECONFIG) config
#
# Modules are split into,
# - Use-cases specified in uc_cfg.mk
# - Other system config/feature, specified in this file
#
# Any specific overrides are also specified in this file
# Example, for TDA3x SoC EVE2/3/4 are not present and hence force marked as <blank>, i.e disabled
#

#
# Additional config options
#

#
# CPUs to included in build
#
# IPU1 (core 0 & 1 are) not supported when IPU_PRIMARY_CORE=ipu2
PROC_IPU1_0_INCLUDE=yes
PROC_IPU1_1_INCLUDE=no
PROC_IPU2_INCLUDE=yes
PROC_A15_0_INCLUDE=yes
PROC_DSP1_INCLUDE=yes
PROC_DSP2_INCLUDE=yes
PROC_EVE1_INCLUDE=no
PROC_EVE2_INCLUDE=no


VSDK_BOARD_TYPE=TDA2PX_EVM

# Supported values: DDR_MEM_1024M
DDR_MEM=DDR_MEM_1024M

# Supported values: ipu1_0 ipu1_1 ipu2 a15_0 none
NDK_PROC_TO_USE=none

#
# Used to control building of algorithm source.
# By default algorithm source not included in Vision SDK
#
BUILD_ALGORITHMS=no

#
# Applies profile to all cores
#
# Supported profiles: release debug
#PROFILE=debug
PROFILE ?= release

PROFILE_ipu1_0 ?= $(PROFILE)
PROFILE_ipu1_1 ?= $(PROFILE)
PROFILE_ipu2 ?= $(PROFILE)
PROFILE_c66xdsp_1 ?= $(PROFILE)
PROFILE_c66xdsp_2 ?= $(PROFILE)
PROFILE_arp32_1 ?= $(PROFILE)
PROFILE_arp32_2 ?= $(PROFILE)
PROFILE_a15_0 ?= $(PROFILE)


#
# For TDA2xx, TDA2Px & TDA2Ex - vision SDK can run on either IPU1 or IPU2 subsystem
# For TDA3xx - We have only IPU1 and hence IPU1 is the only option
# Select IPU primary core from the available IPU1 & IPU2 subsytems
#
# Supported values: ipu1_0 ipu2
IPU_PRIMARY_CORE=ipu2
IPU_SECONDARY_CORE=ipu1_0

#
# Set A15_TARGET_OS
# A15 can run Linux or Bios
#
#                 A15_TARGET_OS support
#   Platform        BIOS        Linux
#
#   TDA2XX_EVM      yes         yes
#   TDA3XX_EVM      yes         no
#   TDA2EX_EVM      yes         yes
#   TDA2PX_EVM      yes         yes
#
# Supported values: Bios Linux
A15_TARGET_OS=Linux

# Both IVAHD_INCLUDE & IPUMM_INCLUDE should not be set to "yes"
# Only one should be enabled to avoid IVA-HD resource conflict
IPUMM_INCLUDE=no
IVAHD_INCLUDE=yes
VPE_INCLUDE=yes
DSS_INCLUDE=yes
CAL_INCLUDE=yes
ISS_INCLUDE=yes

AVB_INCLUDE=no

#
# Enable below macro to enable DCAN integration into Vision SDK.
#
DCAN_INCLUDE=no

CPU_IDLE_ENABLED=yes

#
# Enable below macro to view the bandwidth used by different IPs in the device
# as a graphical plot on the display screen.
#
DATA_VIS_INCLUDE=no

#
# Enable below macro to enable OPENVX into Vision SDK
#
OPENVX_INCLUDE=no

#
# Enable this macro to enable Ultra sonic based initialization
# This is added as the power measurement and Ultra sonic use the same
# pad on the device. Kindly note the Ultrasonic and power measurement
# use the same GPIO6_14/15 pads with different functionalities. Ultrasonic configures
# UART10 on those pads and power measurement configures I2C3. Hence when this
# macro is yes the power measurement functionality is not supported.
#
ULTRASONIC_INCLUDE=yes
PGA450=no
PGA460=yes
ENABLE_ALL_DEPTH=yes

CIO_REDIRECT=yes

HS_DEVICE=no

DEFAULT_UBOOT_CONFIG  := dra7xx_evm_vision_config
DEFAULT_KERNEL_CONFIG := ti_sdk_dra7x_release_defconfig
ECARX_KERNEL_CONFIG := ti_sdk_dra7x_release_ecarx_defconfig
# For TDA2x
DEFAULT_DTB := dra76-evm-infoadas.dtb
CMEM_INCLUDE=yes

include $($(MAKEAPPNAME)_PATH)/configs/$(MAKECONFIG)/uc_cfg.mk

the link chain configuration is :

The trace is printed in links_fw/src/hlos/system/system_common.c, 

#ifndef QNX_BUILD
    gSystem_objCommon.devBufFD = open("/dev/vmemexp", O_RDWR | O_CLOEXEC);
#endif

###.........

Int32 System_exportDmaBuf(void * vAddr, UInt32 size, UInt32 *fdBuf)
{
    Int32 retVal = -1;
#ifndef QNX_BUILD
    struct dmabuf_vmem_export exp;
    exp.vaddr = (unsigned long)vAddr;
    exp.size = size;

    if(gSystem_objCommon.devBufFD > 0)
    {
        /* Export as DMAbuf handle */
        retVal = ioctl(gSystem_objCommon.devBufFD, DBUFIOC_EXPORT_VIRTMEM, &exp);
        if(retVal == SYSTEM_LINK_STATUS_SOK)
        {
            *fdBuf = exp.fd;
        }
        else
        {
            Vps_printf(" exportDmaBuf failed \n ");
        }
    }
#else
    retVal = SYSTEM_LINK_STATUS_SOK;
#endif
return retVal;
}

And it's about 5% that the issue show up when we run apps.out, please check the log in attachment.

devBufFD.log
12-17-20 54:49.771  [HOST] [IPU1-0]    101.364850 s: actX  0.000000
12-17-20 54:49.771  [HOST] [IPU1-0]    101.364942 s: actY  0.000000
12-17-20 54:49.771  [HOST] [IPU1-0]    101.365003 s: TargetPhi,0.000000
12-17-20 54:49.771  [HOST] [IPU1-0]    101.374916 s: actX  0.000000
12-17-20 54:49.771  [HOST] [IPU1-0]    101.375038 s: actY  0.000000
12-17-20 54:49.771  [HOST] [IPU1-0]    101.375099 s: TargetPhi,0.000000
12-17-20 54:49.772  [HOST] [IPU1-0]    101.378942 s: >>APA_Alg_KC2InfoForTest len:1
12-17-20 54:49.772  [HOST] [IPU2  ]    101.375953 s: ov1063x/src/bspdrv_ov1063xI2c.c @ Line 188: 
12-17-20 54:49.772  [HOST] [IPU2  ]    101.376044 s: init aP0101 ok
12-17-20 54:49.772  [HOST] [IPU2  ]    101.376105 s: pObj->createPrms.deviceI2cAddr[0] = 38
12-17-20 54:49.772  [HOST] [IPU2  ]    101.376197 s: ov1063x/src/bspdrv_ov1063xI2c.c @ Line 451: 
12-17-20 54:49.773  [HOST] [IPU2  ]    101.376258 s: ok status = 0
12-17-20 54:49.773  [HOST] [IPU1-0]    101.386841 s: actX  0.000000
12-17-20 54:49.773  [HOST] [IPU1-0]    101.386933 s: actY  0.000000
12-17-20 54:49.773  [HOST] [IPU1-0]    101.386994 s: TargetPhi,0.000000
12-17-20 54:49.773  [HOST] [IPU2  ]    101.391966 s: ov1063x/src/bspdrv_ov1063xI2c.c @ Line 188: 
12-17-20 54:49.773  [HOST] [IPU2  ]    101.392057 s: init aP0101 ok
12-17-20 54:49.774  [HOST] [IPU1-0]    101.396937 s: actX  0.000000
12-17-20 54:49.774  [HOST] [IPU1-0]    101.396998 s: actY  0.000000
12-17-20 54:49.774  [HOST] [IPU1-0]    101.397059 s: TargetPhi,0.000000
12-17-20 54:49.774  [HOST] [IPU1-0]    101.408833 s: actX  0.000000
12-17-20 54:49.774  [HOST] [IPU1-0]    101.408955 s: actY  0.000000
12-17-20 54:49.774  [HOST] [IPU1-0]    101.409016 s: TargetPhi,0.000000
12-17-20 54:49.774  [HOST] [IPU2  ]    101.408101 s: ov1063x/src/bspdrv_ov1063xI2c.c @ Line 188: 
12-17-20 54:49.775  [HOST] [IPU2  ]    101.408192 s: init aP0101 ok
12-17-20 54:49.775  [HOST] [IPU1-0]    101.418928 s: actX  0.000000
12-17-20 54:49.775  [HOST] [IPU1-0]    101.418989 s: actY  0.000000
12-17-20 54:49.775  [HOST] [IPU1-0]    101.419081 s: TargetPhi,0.000000
12-17-20 54:49.775  [HOST] [IPU2  ]    101.423961 s: ov1063x/src/bspdrv_ov1063xI2c.c @ Line 188: 
12-17-20 54:49.775  [HOST] [IPU2  ]    101.424052 s: init aP0101 ok
12-17-20 54:49.776  [HOST] [IPU2  ]    101.424083 s: pObj->createPrms.deviceI2cAddr[0] = 39
12-17-20 54:49.776  [HOST] [IPU2  ]    101.424174 s: ov1063x/src/bspdrv_ov1063xI2c.c @ Line 451: 
12-17-20 54:49.776  [HOST] [IPU2  ]    101.424266 s: ok status = 0
12-17-20 54:49.776  [HOST] [IPU1-0]    101.430885 s: actX  0.000000
12-17-20 54:49.776  [HOST] [IPU1-0]    101.430976 s: actY  0.000000
12-17-20 54:49.777  [HOST] [IPU1-0]    101.431037 s: TargetPhi,0.000000
12-17-20 54:49.777  [HOST] [IPU1-0]    101.440919 s: actX  0.000000
12-17-20 54:49.780  [HOST] [IPU1-0]    101.441011 s: actY  0.000000
12-17-20 54:49.780  [HOST] [IPU1-0]    101.441072 s: TargetPhi,0.000000
12-17-20 54:49.780  [HOST] [IPU2  ]    101.439974 s: ov1063x/src/bspdrv_ov1063xI2c.c @ Line 188: 
12-17-20 54:49.781  [HOST] [IPU2  ]    101.440035 s: init aP0101 ok
12-17-20 54:49.788  [HOST] [IPU1-0]    101.452845 s: actX  0.000000
12-17-20 54:49.788  [HOST] [IPU1-0]    101.452937 s: actY  0.000000
12-17-20 54:49.788  [HOST] [IPU1-0]    101.453028 s: TargetPhi,0.000000
12-17-20 54:49.789  [HOST] [IPU1-0]    101.462941 s: actX  0.000000
12-17-20 54:49.789  [HOST] [IPU1-0]    101.463002 s: actY  0.000000
12-17-20 54:49.789  [HOST] [IPU1-0]    101.463063 s: TargetPhi,0.000000
12-17-20 54:49.789  [HOST] [IPU2  ]    101.455956 s: ov1063x/src/bspdrv_ov1063xI2c.c @ Line 188: 
12-17-20 54:49.789  [HOST] [IPU2  ]    101.456048 s: init aP0101 ok
12-17-20 54:49.789  [HOST] [IPU1-0]    101.474897 s: actX  0.000000
12-17-20 54:49.790  [HOST] [IPU2  ]    101.471969 s: ov1063x/src/bspdrv_ov1063xI2c.c @ Line 188: 
12-17-20 54:49.790  [HOST] [IPU2  ]    101.472030 s: init aP0101 ok
12-17-20 54:49.790  [HOST] [IPU2  ]    101.472091 s: pObj->createPrms.deviceI2cAddr[0] = 3a
12-17-20 54:49.790  [HOST] [IPU2  ]    101.472183 s: ov1063x/src/bspdrv_ov1063xI2c.c @ Line 451: 
12-17-20 54:49.790  [HOST] [IPU2  ]    101.472274 s: ok status = 0
12-17-20 54:49.790  [HOST] [IPU1-0]    101.474989 s: actY  0.000000
12-17-20 54:49.790  [HOST] [IPU1-0]    101.475050 s: TargetPhi,0.000000
12-17-20 54:49.791  [HOST] [IPU1-0]    101.480936 s: >>APA_Alg_KC2InfoForTest len:1
12-17-20 54:49.791  [HOST] [IPU1-0]    101.484932 s: actX  0.000000
12-17-20 54:49.791  [HOST] [IPU1-0]    101.484993 s: actY  0.000000
12-17-20 54:49.791  [HOST] [IPU1-0]    101.485054 s: TargetPhi,0.000000
12-17-20 54:49.791  [HOST] [IPU2  ]    101.488104 s: ov1063x/src/bspdrv_ov1063xI2c.c @ Line 188: 
12-17-20 54:49.793  [HOST] [IPU2  ]    101.488196 s: init aP0101 ok
12-17-20 54:49.829  [HOST] [IPU1-0]    101.496827 s: actX  0.000000
12-17-20 54:49.829  [HOST] [IPU1-0]    101.496949 s: actY  0.000000
12-17-20 54:49.829  [HOST] [IPU1-0]    101.497010 s: TargetPhi,0.000000
12-17-20 54:49.830  [HOST] [IPU2  ]    101.503965 s: ov1063x/src/bspdrv_ov1063xI2c.c @ Line 188: 
12-17-20 54:49.830  [HOST] [IPU2  ]    101.504056 s: init aP0101 ok
12-17-20 54:49.830  [HOST] [IPU1-0]    101.506923 s: actX  0.000000
12-17-20 54:49.830  [HOST] [IPU1-0]    101.507015 s: actY  0.000000
12-17-20 54:49.830  [HOST] [IPU1-0]    101.507076 s: TargetPhi,0.000000
12-17-20 54:49.830  [HOST] [IPU1-0]    101.518849 s: actX  0.000000
12-17-20 54:49.830  [HOST] [IPU1-0]    101.518941 s: actY  0.000000
12-17-20 54:49.831  [HOST] [IPU1-0]    101.519002 s: TargetPhi,0.000000
12-17-20 54:49.831  [HOST] [IPU2  ]    101.519978 s: ov1063x/src/bspdrv_ov1063xI2c.c @ Line 188: 
12-17-20 54:49.831  [HOST] [IPU2  ]    101.520039 s: init aP0101 ok
12-17-20 54:49.831  [HOST] [IPU2  ]    101.520100 s: pObj->createPrms.deviceI2cAddr[0] = 3b
12-17-20 54:49.831  [HOST] [IPU2  ]    101.520191 s: ov1063x/src/bspdrv_ov1063xI2c.c @ Line 451: 
12-17-20 54:49.831  [HOST] [IPU2  ]    101.520283 s: ok status = 0
12-17-20 54:49.831  [HOST] [IPU1-0]    101.528945 s: actX  0.000000
12-17-20 54:49.832  [HOST] [IPU1-0]    101.529006 s: actY  0.000000
12-17-20 54:49.832  [HOST] [IPU1-0]    101.529067 s: TargetPhi,0.000000
12-17-20 54:49.832  [HOST] [HOST  ]    101.533886 s:  SGXFRMCPY: Start in progress !!!
12-17-20 54:49.832  [HOST] [HOST  ]    101.533886 s:  SGXFRMCPY: Start Done !!!
12-17-20 54:49.832  [HOST] [IPU2  ]    101.533215 s:  DISPLAY: Start in progress !!!
12-17-20 54:49.832  [HOST] [IPU2  ]    101.533306 s:  DISPLAY: Start Done !!!
12-17-20 54:49.834 Vehicle Service is now listening on port 10086 
12-17-20 54:49.875  [HOST] [IPU1-0]    101.540840 s: actX  0.000000
12-17-20 54:49.875  [HOST] [IPU1-0]    101.540962 s: actY  0.000000
12-17-20 54:49.876  [HOST] [IPU1-0]    101.541023 s: TargetPhi,0.000000
12-17-20 54:49.876  [HOST] [IPU2  ]    101.536173 s:  ISSCAPTURE: Start in progress !!!
12-17-20 54:49.876  [HOST] [IPU2  ]    101.536417 s:  ISSCAPTURE: Start Done !!!
12-17-20 54:49.876  [HOST] [IPU1-0]    101.550936 s: actX  0.000000
12-17-20 54:49.876  [HOST] [IPU1-0]    101.550997 s: actY  0.000000
12-17-20 54:49.877  [HOST] [IPU1-0]    101.551058 s: TargetPhi,0.000000
12-17-20 54:49.877  [HOST] [HOST  ]    101.553467 s: Warning : Could not Find /home/Recording.txt file, Recording not started!!!
12-17-20 54:49.877  [HOST] [HOST  ]    101.553498 s: Warning : If you wish to enable Recording create file /home/Recording.txt and restart the Program
12-17-20 54:49.877  [HOST] [IPU1-0]    101.562892 s: actX  0.000000
12-17-20 54:49.878  [HOST] [IPU1-0]    101.562984 s: actY  0.000000
12-17-20 54:49.878  [HOST] [IPU1-0]    101.563045 s: TargetPhi,0.000000
12-17-20 54:49.878  [HOST] [IPU1-0]    101.572927 s: actX  0.000000
12-17-20 54:49.878  [HOST] [IPU1-0]    101.573018 s: actY  0.000000
12-17-20 54:49.880  [HOST] [IPU1-0]    101.573079 s: TargetPhi,0.000000
12-17-20 54:49.919  [HOST] [IPU1-0]    101.578936 s: >>APA_Alg_KC2InfoForTest len:1
12-17-20 54:49.919  [HOST] [IPU1-0]    101.584853 s: actX  0.000000
12-17-20 54:49.919  [HOST] [IPU1-0]    101.584944 s: actY  0.000000
12-17-20 54:49.919  [HOST] [IPU1-0]    101.585005 s: TargetPhi,0.000000
12-17-20 54:49.919  [HOST] [IPU1-0]    101.594949 s: actX  0.000000
12-17-20 54:49.919  [HOST] [IPU1-0]    101.595010 s: actY  0.000000
12-17-20 54:49.920  [HOST] [IPU1-0]    101.595071 s: TargetPhi,0.000000
12-17-20 54:49.920  [HOST] [IPU1-0]    101.606874 s: actX  0.000000
12-17-20 54:49.920  [HOST] [IPU1-0]    101.607027 s: actY  0.000000
12-17-20 54:49.921  [HOST] [IPU1-0]    101.607118 s: TargetPhi,0.000000
12-17-20 54:49.960  [HOST] [IPU1-0]    101.616940 s: actX  0.000000
12-17-20 54:50.030  [HOST] [IPU1-0]    101.617031 s: actY  0.000000
12-17-20 54:50.032  [HOST] [IPU1-0]    101.617092 s: TargetPhi,0.000000
12-17-20 54:52.473  [HOST] [IPU1-0]    101.628865 s: actX  0.000000
12-17-20 54:52.474  [HOST] [IPU1-0]    101.629018 s: actY  0.000000
12-17-20 54:52.474  [HOST] [IPU1-0]    101.629140 s: TargetPhi,0.000000
12-17-20 54:52.474  [HOST] [IPU1-0]    101.638931 s: actX  0.000000
12-17-20 54:52.475  [HOST] [IPU1-0]    101.639053 s: actY  0.000000
12-17-20 54:52.475  [HOST] [IPU1-0]    101.639114 s: TargetPhi,0.000000
12-17-20 54:52.476  [HOST] [IPU1-0]    101.650857 s: actX  0.000000
12-17-20 54:52.476  [HOST] [IPU1-0]    101.650948 s: actY  0.000000
12-17-20 54:52.476  [HOST] [IPU1-0]    101.651009 s: TargetPhi,0.000000
12-17-20 54:52.477  [HOST] [IPU1-0]    101.660922 s: actX  0.000000
12-17-20 54:52.477  [HOST] [IPU1-0]    101.661013 s: actY  0.000000
12-17-20 54:52.477  [HOST] [IPU1-0]    101.661074 s: TargetPhi,0.000000
12-17-20 54:52.477  [HOST] [IPU1-0]    101.672848 s: actX  0.000000
12-17-20 54:52.477  [HOST] [IPU1-0]    101.672939 s: actY  0.000000
12-17-20 54:52.477  [HOST] [IPU1-0]    101.673
12-17-20 54:52.478  [HOST] [IPU1-0] 000 s: TargetPhi,0.000000
12-17-20 54:52.478  [HOST] [IPU1-0]    101.680930 s: >>APA_Alg_KC2InfoForTest len:1
12-17-20 54:52.478  [HOST] [IPU1-0]    101.682943 s: actX  0.000000
12-17-20 54:52.478  [HOST] [IPU1-0]    101.683004 s: actY  0.000000
12-17-20 54:52.479  [HOST] [IPU1-0]    101.683096 s: TargetPhi,0.000000
12-17-20 54:52.479  [HOST] [IPU1-0]    101.694869 s: actX  0.000000
12-17-20 54:52.479  [HOST] [IPU1-0]    101.694961 s: actY  0.000000
12-17-20 54:52.479  [HOST] [IPU1-0]    101.695022 s: TargetPhi,0.000000
12-17-20 54:52.479  [HOST] [IPU1-0]    101.704935 s: actX  0.000000
12-17-20 54:52.480  [HOST] [IPU1-0]    101.705026 s: actY  0.000000
12-17-20 54:52.480  [HOST] [IPU1-0]    101.705087 s: TargetPhi,0.000000
12-17-20 54:52.480  [HOST] [IPU1-0]    101.719056 s: actX  0.000000
12-17-20 54:52.481  [HOST] [IPU1-0]    101.719148 s: actY  0.000000
12-17-20 54:52.481  [HOST] [IPU1-0]    101.719209 s: TargetPhi,0.000000
12-17-20 54:52.481  [HOST] [IPU1-0]    101.728969 s: actX  0.000000
12-17-20 54:52.482  [HOST] [IPU1-0]    101.729061 s: actY  0.000000
12-17-20 54:52.482  [HOST] [IPU1-0]    101.729152 s: TargetPhi,0.000000
12-17-20 54:52.482  [HOST] [IPU1-0]    101.740865 s: actX  0.000000
12-17-20 54:52.482  [HOST] [IPU1-0]    101.740956 s: actY  0.000000
12-17-20 54:52.482  [HOST] [IPU1-0]    101.741017 s: TargetPhi,0.000000
12-17-20 54:52.483  [HOST] [IPU1-0]    101.750930 s: actX  0.000000
12-17-20 54:52.483  [HOST] [IPU1-0]    101.751021 s: actY  0.000000
12-17-20 54:52.483  [HOST] [IPU1-0]    101.751082 s: TargetPhi,0.000000
12-17-20 54:52.483  [HOST] [IPU1-0]    101.762856 s: actX  0.000000
12-17-20 54:52.484  [HOST] [IPU1-0]    101.762947 s: actY  0.000000
12-17-20 54:52.484  [HOST] [IPU1-0]    101.763008 s: TargetPhi,0.000000
12-17-20 54:52.489  [HOST] [IPU1-0]    101.772951 s: actX  0.000000
12-17-20 54:52.490  [HOST] [IPU1-0]    101.773073 s: actY  0.000000
12-17-20 54:52.490  [HOST] [IPU1-0]    101.773134 s: TargetPhi,0.000000
12-17-20 54:52.490  [HOST] [IPU1-0]    101.778930 s: >>APA_Alg_KC2InfoForTest len:1
12-17-20 54:52.490  [HOST] [IPU1-0]    101.784847 s: actX  0.000000
12-17-20 54:52.491  [HOST] [IPU1-0]    101.784969 s: actY  0.000000
12-17-20 54:52.491  [HOST] [IPU1-0]    101.785030 s: TargetPhi,0.000000
12-17-20 54:52.491  [HOST] [IPU1-0]    101.794942 s: actX  0.000000
12-17-20 54:52.491  [HOST] [IPU1-0]    101.795003 s: actY  0.000000
12-17-20 54:52.492  [HOST] [IPU1-0]    101.795064 s: TargetPhi,0.000000
12-17-20 54:52.492  [HOST] [IPU1-0]    101.806868 s: actX  0.000000
12-17-20 54:52.492  [HOST] [IPU1-0]    101.806960 s: actY  0.000000
12-17-20 54:52.492  [HOST] [IPU1-0]    101.807021 s: TargetPhi,0.000000
12-17-20 54:52.493  [HOST] [IPU1-0]    101.816934 s: actX  0.000000
12-17-20 54:52.493  [HOST] [IPU1-0]    101.817025 s: actY  0.000000
12-17-20 54:52.493  [HOST] [IPU1-0]    101.817086 s: TargetPhi,0.000000
12-17-20 54:52.493  [HOST] [IPU1-0]    101.828890 s: actX  0.000000
12-17-20 54:52.493  [HOST] [IPU1-0]    101.828981 s: actY  0.000000
12-17-20 54:52.494  [HOST] [IPU1-0]    101.829073 s: TargetPhi,0.000000
12-17-20 54:52.494  [HOST] [IPU1-0]    101.838955 s: actX  0.000000
12-17-20 54:52.494  [HOST] [IPU1-0]    101.839016 s: actY  0.000000
12-17-20 54:52.494  [HOST] [IPU1-0]    101.839077 s: TargetPhi,0.000000
12-17-20 54:52.495  [HOST] [IPU1-0]    101.850850 s: actX  0.000000
12-17-20 54:52.495  [HOST] [IPU1-0]    101.850972 s: actY  0.000000
12-17-20 54:52.495  [HOST] [IPU1-0]    101.851033 s: TargetPhi,0.000000
12-17-20 54:52.495  [HOST] [IPU1-0]    101.860946 s: actX  0.000000
12-17-20 54:52.495  [HOST] [IPU1-0]    101.861007 s: actY  0.000000
12-17-20 54:52.496  [HOST] [IPU1-0]    101.861068 s: TargetPhi,0.000000
12-17-20 54:52.496  [HOST] [IPU1-0]    101.872842 s: actX  0.000000
12-17-20 54:52.497  [HOST] [IPU1-0]    101.872994 s: actY  0.000000
12-17-20 54:52.497  [HOST] [IPU1-0]    101.873055 s: TargetPhi,0.000000
12-17-20 54:52.498  [HOST] [IPU1-0]    101.878942 s: >>APA_Alg_KC2InfoForTest len:1
12-17-20 54:52.498  [HOST] [IPU1-0]    101.882937 s: actX  0.000000
12-17-20 54:52.498  [HOST] [IPU1-0]    101.883029 s: actY  0.000000
12-17-20 54:52.499  [HOST] [IPU1-0]    101.883090 s: TargetPhi,0.000000
12-17-20 54:52.499  [HOST] [IPU1-0]    101.894863 s: actX  0.000000
12-17-20 54:52.499  [HOST] [IPU1-0]    101.894955 s: actY  0.000000
12-17-20 54:52.500  [HOST] [IPU1-0]    101.895046 s: TargetPhi,0.000000
12-17-20 54:52.500  [HOST] [IPU1-0]    101.904928 s: actX  0.000000
12-17-20 54:52.500  [HOST] [IPU1-0]    101.905020 s: actY  0.000000
12-17-20 54:52.501  [HOST] [IPU1-0]    101.905081 s: TargetPhi,0.000000
12-17-20 54:52.504  [HOST] [IPU1-0]    101.916854 s: actX  0.000000
12-17-20 54:52.505  [HOST] [IPU1-0]    101.916946 s: actY  0.000000
12-17-20 54:52.505  [HOST] [IPU1-0]    101.917037 s: TargetPhi,0.000000
12-17-20 54:52.506  [HOST] [HOST  ]    101.849173 s:  exportDmaBuf failed 
12-17-20 54:52.506  [HOST] [HOST  ]  
12-17-20 54:52.507  [HOST] [IPU1-0]    101.926950 s: actX  0.000000
12-17-20 54:52.507  [HOST] [IPU1-0]    101.927011 s: actY  0.000000
12-17-20 54:52.508  [HOST] [IPU1-0]    101.927072 s: TargetPhi,0.000000
12-17-20 54:52.508  [HOST] [IPU1-0]    101.938845 s: actX  0.000000
12-17-20 54:52.508  [HOST] [IPU1-0]    101.938937 s: actY  0.000000
12-17-20 54:52.509  [HOST] [IPU1-0]    101.939028 s: TargetPhi,0.000000
12-17-20 54:52.509  [HOST] [IPU1-0]    101.948941 s: actX  0.000000
12-17-20 54:52.509  [HOST] [IPU1-0]    101.949002 s: actY  0.000000
12-17-20 54:52.509  [HOST] [IPU1-0]    101.949094 s: TargetPhi,0.000000
12-17-20 54:52.510  [HOST] [IPU1-0]    101.960867 s: actX  0.000000
12-17-20 54:52.510  [HOST] [IPU1-0]    101.960958 s: actY  0.000000
12-17-20 54:52.510  [HOST] [IPU1-0]    101.961019 s: TargetPhi,0.000000
12-17-20 54:52.510  [HOST] [IPU1-0]    101.970932 s: actX  0.000000
12-17-20 54:52.510  [HOST] [IPU1-0]    101.971024 s: actY  0.000000
12-17-20 54:52.511  [HOST] [IPU1-0]    101.971085 s: TargetPhi,0.000000
12-17-20 54:52.511  [HOST] [IPU1-0]    101.978954 s: >>APA_Alg_KC2InfoForTest len:1
12-17-20 54:52.512  [HOST] [IPU1-0]    101.983651 s: actX  0.000000
12-17-20 54:52.512  [HOST] [IPU1-0]    101.983743 s: actY  0.000000
12-17-20 54:52.512  [HOST] [IPU1-0]    101.983804 s: TargetPhi,0.000000
12-17-20 54:52.512  [HOST] [IPU1-0]    101.993960 s: actX  0.000000
12-17-20 54:52.513  [HOST] [IPU1-0]    101.994021 s: actY  0.000000
12-17-20 54:52.513  [HOST] [IPU1-0]    101.994082 s: TargetPhi,0.000000
12-17-20 54:52.513  [HOST] [IPU1-0]    102.005886 s: actX  0.000000
12-17-20 54:52.514  [HOST] [IPU1-0]    102.006008 s: actY  0.000000
12-17-20 54:52.514  [HOST] [IPU1-0]    102.006069 s: TargetPhi,0.000000
12-17-20 54:52.514  [HOST] [IPU1-0]    102.015951 s: actX  0.000000
12-17-20 54:52.515  [HOST] [IPU1-0]    102.016012 s: actY  0.000000
12-17-20 54:52.515  [HOST] [IPU1-0]    102.016073 s: TargetPhi,0.000000
12-17-20 54:52.515  [HOST] [IPU1-0]    102.027847 s: actX  0.000000
12-17-20 54:52.515  [HOST] [IPU1-0]    102.027969 s: actY  0.000000
12-17-20 54:52.516  [HOST] [IPU1-0]    102.028030 s: TargetPhi,0.000000
12-17-20 54:52.516  [HOST] [IPU1-0]    102.037943 s: actX  0.000000
12-17-20 54:52.517  [HOST] [IPU1-0]    102.038034 s: actY  0.000000
12-17-20 54:52.517  [HOST] [IPU1-0]    102.038095 s: TargetPhi,0.000000
12-17-20 54:52.517  [HOST] [IPU1-0]    102.049899 s: actX  0.000000
12-17-20 54:52.518  [HOST] [IPU1-0]    102.050021 s: actY  0.000000
12-17-20 54:52.522  [HOST] [IPU1-0]    102.050082 s: TargetPhi,0.000000
12-17-20 54:52.523  [HOST] [IPU1-0]    102.059934 s: actX  0.000000
12-17-20 54:52.523  [HOST] [IPU1-0]    102.060025 s: actY  0.000000
12-17-20 54:52.523  [HOST] [IPU1-0]    102.060086 s: TargetPhi,0.000000
12-17-20 54:52.524  [HOST] [IPU1-0]    102.071859 s: actX  0.000000
12-17-20 54:52.524  [HOST] [IPU1-0]    102.071951 s: actY  0.000000
12-17-20 54:52.524  [HOST] [IPU1-0]    102.072012 s: TargetPhi,0.000000
12-17-20 54:52.524  [HOST] [IPU1-0]    102.079942 s: >>APA_Alg_KC2InfoForTest len:1
12-17-20 54:52.525  [HOST] [IPU1-0]    102.081955 s: actX  0.000000
12-17-20 54:52.525  [HOST] [IPU1-0]    102.082016 s: actY  0.000000
12-17-20 54:52.525  [HOST] [IPU1-0]    102.082108 s: TargetPhi,0.000000
12-17-20 54:52.525  [HOST] [IPU1-0]    102.093851 s: actX  0.000000
12-17-20 54:52.526  [HOST] [IPU1-0]    102.093973 s: actY  0.000000
12-17-20 54:52.526  [HOST] [IPU1-0]    102.094034 s: TargetPhi,0.000000
12-17-20 54:52.526  [HOST] [IPU1-0]    102.103946 s: actX  0.000000
12-17-20 54:52.527  [HOST] [IPU1-0]    102.104038 s: actY  0.000000
12-17-20 54:52.527  [HOST] [IPU1-0]    102.104099 s: TargetPhi,0.000000
12-17-20 54:52.527  [HOST] [IPU1-0]    102.115872 s: actX  0.000000
12-17-20 54:52.528  [HOST] [IPU1-0]    102.115964 s: actY  0.000000
12-17-20 54:52.529  [HOST] [IPU1-0]    102.116055 s: TargetPhi,0.000000
12-17-20 54:52.529  [HOST] [IPU1-0]    102.125937 s: actX  0.000000
12-17-20 54:52.530  [HOST] [IPU1-0]    102.126029 s: actY  0.000000
12-17-20 54:52.530  [HOST] [IPU1-0]    102.126090 s: TargetPhi,0.000000
12-17-20 54:52.530  [HOST] [IPU1-0]    102.137863 s: actX  0.000000
12-17-20 54:52.531  [HOST] [IPU1-0]    102.137955 s: actY  0.000000
12-17-20 54:52.531  [HOST] [IPU1-0]    102.138016 s: TargetPhi,0.000000
12-17-20 54:52.531  [HOST] [IPU1-0]    102.147959 s: actX  0.000000
12-17-20 54:52.532  [HOST] [IPU1-0]    102.148020 s: actY  0.000000
12-17-20 54:52.532  [HOST] [IPU1-0]    102.148081 s: TargetPhi,0.000000
12-17-20 54:52.532  [HOST] [IPU1-0]    102.159854 s: actX  0.000000
12-17-20 54:52.533  [HOST] [IPU1-0]    102.159976 s: actY  0.000000
12-17-20 54:52.533  [HOST] [IPU1-0]    102.160037 s: TargetPhi,0.000000
12-17-20 54:52.534  [HOST] [IPU1-0]    102.169950 s: actX  0.000000
12-17-20 54:52.534  [HOST] [IPU1-0]    102.170011 s: actY  0.000000
12-17-20 54:52.535  [HOST] [IPU1-0]    102.170103 s: TargetPhi,0.000000
12-17-20 54:52.535  [HOST] [IPU1-0]    102.177941 s: >>APA_Alg_KC2InfoForTest len:1
12-17-20 54:52.535  [HOST] [IPU1-0]    102.182303 s: actX  0.000000
12-17-20 54:52.535  [HOST] [IPU1-0]    102.182364 s: actY  0.000000
12-17-20 54:52.536  [HOST] [IPU1-0]    102.182425 s: TargetPhi,0.000000
12-17-20 54:52.536  [HOST] [IPU1-0]    102.191941 s: actX  0.000000
12-17-20 54:52.537  [HOST] [IPU1-0]    102.192033 s: actY  0.000000
12-17-20 54:52.540  [HOST] [IPU1-0]    102.192094 s: TargetPhi,0.000000
12-17-20 54:52.541  [HOST] [IPU1-0]    102.203867 s: actX  0.000000
12-17-20 54:52.541  [HOST] [IPU1-0]    102.203989 s: actY  0.000000
12-17-20 54:52.542  [HOST] [IPU1-0]    102.204050 s: TargetPhi,0.000000
12-17-20 54:52.542  [HOST] [IPU1-0]    102.213963 s: actX  0.000000
12-17-20 54:52.543  [HOST] [IPU1-0]    102.214024 s: actY  0.000000
12-17-20 54:52.543  [HOST] [IPU1-0]    102.214085 s: TargetPhi,0.000000
12-17-20 54:52.544  [HOST] [IPU1-0]    102.225858 s: actX  0.000000
12-17-20 54:52.544  [HOST] [IPU1-0]    102.225980 s: actY  0.000000
12-17-20 54:52.545  [HOST] [IPU1-0]    102.226041 s: TargetPhi,0.000000
12-17-20 54:52.545  [HOST] [IPU1-0]    102.235954 s: actX  0.000000
12-17-20 54:52.545  [HOST] [IPU1-0]    102.236015 s: actY  0.000000
12-17-20 54:52.546  [HOST] [IPU1-0]    102.236076 s: TargetPhi,0.000000
12-17-20 54:52.546  [HOST] [IPU1-0]    102.247849 s: actX  0.000000
12-17-20 54:52.546  [HOST] [IPU1-0]    102.247971 s: actY  0.000000
12-17-20 54:52.547  [HOST] [IPU1-0]    102.248032 s: TargetPhi,0.000000
12-17-20 54:52.547  [HOST] [IPU1-0]    102.257945 s: actX  0.000000
12-17-20 54:52.547  [HOST] [IPU1-0]    102.258036 s: actY  0.000000
12-17-20 54:52.547  [HOST] [IPU1-0]    102.258097 s: TargetPhi,0.000000
12-17-20 54:52.548  [HOST] [IPU1-0]    102.271274 s: actX  0.000000
12-17-20 54:52.548  [HOST] [IPU1-0]    102.271365 s: actY  0.000000
12-17-20 54:52.548  [HOST] [IPU1-0]    102.271426 s: TargetPhi,0.000000
12-17-20 54:52.549  [HOST] [IPU1-0]    102.278960 s: >>APA_Alg_KC2InfoForTest len:1
12-17-20 54:52.550  [HOST] [IPU1-0]    102.280943 s: actX  0.000000
12-17-20 54:52.550  [HOST] [IPU1-0]    102.281034 s: actY  0.000000
12-17-20 54:52.550  [HOST] [IPU1-0]    102.281095 s: TargetPhi,0.000000
12-17-20 54:52.550  [HOST] [IPU1-0]    102.293875 s: actX  0.000000
12-17-20 54:52.551  [HOST] [IPU1-0]    102.293966 s: actY  0.000000
12-17-20 54:52.551  [HOST] [IPU1-0]    102.294058 s: TargetPhi,0.000000
12-17-20 54:52.551  [HOST] [IPU1-0]    102.304001 s: actX  0.000000
12-17-20 54:52.551  [HOST] [IPU1-0]    102.304062 s: actY  0.000000
12-17-20 54:52.552  [HOST] [IPU1-0]    102.304154 s: TargetPhi,0.000000
12-17-20 54:52.552  [HOST] [IPU1-0]    102.315866 s: actX  0.000000
12-17-20 54:52.554  [HOST] [IPU1-0]    102.315958 s: actY  0.000000
12-17-20 54:52.565  [HOST] [IPU1-0]    102.316019 s: TargetPhi,0.000000
12-17-20 54:52.565  [HOST] [IPU1-0]    102.325962 s: actX  0.000000
12-17-20 54:52.566  [HOST] [IPU1-0]    102.326023 s: actY  0.000000
12-17-20 54:52.566  [HOST] [IPU1-0]    102.326084 s: TargetPhi,0.000000
12-17-20 54:52.566  [HOST] [IPU1-0]    102.337857 s: actX  0.000000
12-17-20 54:52.567  [HOST] [IPU1-0]    102.337979 s: actY  0.000000
12-17-20 54:52.567  [HOST] [IPU1-0]    102.338040 s: TargetPhi,0.000000
12-17-20 54:52.567  [HOST] [IPU1-0]    102.347953 s: actX  0.000000
12-17-20 54:52.568  [HOST] [IPU1-0]    102.348075 s: actY  0.000000
12-17-20 54:52.568  [HOST] [IPU1-0]    102.348136 s: TargetPhi,0.000000
12-17-20 54:52.569  [HOST] [IPU1-0]    102.359879 s: actX  0.000000
12-17-20 54:52.569  [HOST] [IPU1-0]    102.359970 s: actY  0.000000
12-17-20 54:52.570  [HOST] [IPU1-0]    102.360031 s: TargetPhi,0.000000
12-17-20 54:52.570  [HOST] [IPU1-0]    102.369944 s: actX  0.000000
12-17-20 54:52.571  [HOST] [IPU1-0]    102.370035 s: actY  0.000000
12-17-20 54:52.571  [HOST] [IPU1-0]    102.370096 s: TargetPhi,0.000000
12-17-20 54:52.572  [HOST] [IPU1-0]    102.377966 s: >>APA_Alg_KC2InfoForTest len:1
12-17-20 54:52.572  [HOST] [IPU1-0]    102.381870 s: actX  0.000000
12-17-20 54:52.573  [HOST] [IPU1-0]    102.381961 s: actY  0.000000
12-17-20 54:52.573  [HOST] [IPU1-0]    102.382022 s: TargetPhi,0.000000
12-17-20 54:52.573  [HOST] [IPU1-0]    102.391966 s: actX  0.000000
12-17-20 54:52.574  [HOST] [IPU1-0]    102.392027 s: actY  0.000000
12-17-20 54:52.574  [HOST] [IPU1-0]    102.392088 s: TargetPhi,0.000000
12-17-20 54:52.575  [HOST] [IPU1-0]    102.404684 s: actX  0.000000
12-17-20 54:52.575  [HOST] [IPU1-0]    102.404745 s: actY  0.000000
12-17-20 54:52.576  [HOST] [IPU1-0]    102.404837 s: TargetPhi,0.000000
12-17-20 54:52.576  [HOST] [IPU1-0]    102.414963 s: actX  0.000000
12-17-20 54:52.576  [HOST] [IPU1-0]    102.415024 s: actY  0.000000
12-17-20 54:52.576  [HOST] [IPU1-0]    102.415085 s: TargetPhi,0.000000
12-17-20 54:52.577  [HOST] [IPU1-0]    102.426859 s: actX  0.000000
12-17-20 54:52.577  [HOST] [IPU1-0]    102.426981 s: actY  0.000000
12-17-20 54:52.577  [HOST] [IPU1-0]    102.427042 s: TargetPhi,0.000000
12-17-20 54:52.578  [HOST] [IPU1-0]    102.436954 s: actX  0.000000
12-17-20 54:52.579  [HOST] [IPU1-0]    102.437015 s: actY  0.000000
12-17-20 54:52.579  [HOST] [IPU1-0]    102.437107 s: TargetPhi,0.000000
12-17-20 54:52.579  [HOST] [IPU1-0]    102.448850 s: actX  0.000000
12-17-20 54:52.579  [HOST] [IPU1-0]    102.448972 s: actY  0.000000
12-17-20 54:52.579  [HOST] [IPU1-0]    102.449033 s: TargetPhi,0.000000
12-17-20 54:52.581  [HOST] [IPU1-0]    102.458945 s: actX  0.000000
12-17-20 54:52.581  [HOST] [IPU1-0]    102.459037 s: actY  0.000000
12-17-20 54:52.581  [HOST] [IPU1-0]    102.459098 s: TargetPhi,0.000000
12-17-20 54:52.584  [HOST] [IPU1-0]    102.470871 s: actX  0.000000
12-17-20 54:52.584  [HOST] [IPU1-0]    102.470963 s: actY  0.000000
12-17-20 54:52.585  [HOST] [IPU1-0]    102.471024 s: TargetPhi,0.000000
12-17-20 54:52.585  [HOST] [IPU1-0]    102.478954 s: >>APA_Alg_KC2InfoForTest len:1
12-17-20 54:52.585  [HOST] [IPU1-0]    102.480967 s: actX  0.000000
12-17-20 54:52.586  [HOST] [IPU1-0]    102.481058 s: actY  0.000000
12-17-20 54:52.586  [HOST] [IPU1-0]    102.481119 s: TargetPhi,0.000000
12-17-20 54:52.587  [HOST] [IPU1-0]    102.492893 s: actX  0.000000
12-17-20 54:52.587  [HOST] [IPU1-0]    102.492984 s: actY  0.000000
12-17-20 54:52.587  [HOST] [IPU1-0]    102.493045 s: TargetPhi,0.000000
12-17-20 54:52.587  [HOST] [IPU1-0]    102.502958 s: actX  0.000000
12-17-20 54:52.588  [HOST] [IPU1-0]    102.503019 s: actY  0.000000
12-17-20 54:52.588  [HOST] [IPU1-0]    102.503080 s: TargetPhi,0.000000
12-17-20 54:52.588  [HOST] [IPU1-0]    102.514914 s: actX  0.000000
12-17-20 54:52.588  [HOST] [IPU1-0]    102.515006 s: actY  0.000000
12-17-20 54:52.589  [HOST] [IPU1-0]    102.515097 s: TargetPhi,0.000000
12-17-20 54:52.589  [HOST] [IPU1-0]    102.524949 s: actX  0.000000
12-17-20 54:52.589  [HOST] [IPU1-0]    102.525071 s: actY  0.000000
12-17-20 54:52.590  [HOST] [IPU1-0]    102.525132 s: TargetPhi,0.000000
12-17-20 54:52.590  [HOST] [IPU1-0]    102.536875 s: actX  0.000000
12-17-20 54:52.592  [HOST] [IPU1-0]    102.536966 s: actY  0.000000
12-17-20 54:52.592  [HOST] [IPU1-0]    102.537027 s: TargetPhi,0.000000
12-17-20 54:52.592  [HOST] [IPU1-0]    102.546971 s: actX  0.000000
12-17-20 54:52.592  [HOST] [IPU1-0]    102.547032 s: actY  0.000000
12-17-20 54:52.593  [HOST] [IPU1-0]    102.547093 s: TargetPhi,0.000000
12-17-20 54:52.593  [HOST] [IPU1-0]    102.558927 s: actX  0.000000
12-17-20 54:52.593  [HOST] [IPU1-0]    102.559019 s: actY  0.000000
12-17-20 54:52.593  [HOST] [IPU1-0]    102.559110 s: TargetPhi,0.000000
12-17-20 54:52.594  [HOST] [HOST  ]    102.202769 s:  exportDmaBuf failed 
12-17-20 54:52.594  [HOST] [HOST  ]  
12-17-20 54:52.594  [HOST] [HOST  ]    102.556396 s:  exportDmaBuf failed 
12-17-20 54:52.594  [HOST] [HOST  ]  
12-17-20 54:52.594  [HOST] [IPU1-0]    102.568962 s: actX  0.000000
12-17-20 54:52.595  [HOST] [IPU1-0]    102.569053 s: actY  0.000000
12-17-20 54:52.597  [HOST] [IPU1-0]    102.569145 s: TargetPhi,0.000000
12-17-20 54:52.782  [HOST] [IPU1-0]    102.580888 s: actX  0.000000
12-17-20 54:52.782  [HOST] [IPU1-0]    102.580979 s: actY  0.000000
12-17-20 54:52.782  [HOST] [IPU1-0]    102.581040 s: TargetPhi,0.000000
12-17-20 54:52.783  [HOST] [IPU1-0]    102.581254 s: >>APA_Alg_KC2InfoForTest len:1
12-17-20 54:52.783  [HOST] [IPU1-0]    102.590953 s: actX  0.000000
12-17-20 54:52.783  [HOST] [IPU1-0]    102.591044 s: actY  0.000000
12-17-20 54:52.783  [HOST] [IPU1-0]    102.591105 s: TargetPhi,0.000000
12-17-20 54:52.784  [HOST] [IPU1-0]    102.602879 s: actX  0.000000
12-17-20 54:52.784  [HOST] [IPU1-0]    102.602970 s: actY  0.000000
12-17-20 54:52.784  [HOST] [IPU1-0]    102.603031 s: TargetPhi,0.000000
12-17-20 54:52.784  [HOST] [IPU1-0]    102.612975 s: actX  0.000000
12-17-20 54:52.784  [HOST] [IPU1-0]    102.613036 s: actY  0.000000
12-17-20 54:52.785  [HOST] [IPU1-0]    102.613097 s: TargetPhi,0.000000
12-17-20 54:52.785  [HOST] [IPU1-0]    102.624870 s: actX  0.000000
12-17-20 54:52.785  [HOST] [IPU1-0]    102.625022 s: actY  0.000000
12-17-20 54:52.785  [HOST] [IPU1-0]    102.625083 s: TargetPhi,0.000000
12-17-20 54:52.786  [HOST] [IPU1-0]    102.634966 s: actX  0.000000
12-17-20 54:52.786  [HOST] [IPU1-0]    102.635027 s: actY  0.000000
12-17-20 54:52.786  [HOST] [IPU1-0]    102.635088 s: TargetPhi,0.000000
12-17-20 54:52.786  [HOST] [IPU1-0]    102.646891 s: actX  0.000000
12-17-20 54:52.786  [HOST] [IPU1-0]    102.646983 s: actY  0.000000
12-17-20 54:52.787  [HOST] [IPU1-0]    102.647044 s: TargetPhi,0.000000
12-17-20 54:52.787  [HOST] [IPU1-0]    102.656957 s: actX  0.000000
12-17-20 54:52.787  [HOST] [IPU1-0]    102.657048 s: actY  0.000000
12-17-20 54:52.787  [HOST] [IPU1-0]    102.657109 s: TargetPhi,0.000000
12-17-20 54:52.787  [HOST] [IPU1-0]    102.668883 s: actX  0.000000
12-17-20 54:52.788  [HOST] [IPU1-0]    102.669035 s: actY  0.000000
12-17-20 54:52.788  [HOST] [IPU1-0]    102.669096 s: TargetPhi,0.000000
12-17-20 54:52.788  [HOST] [IPU1-0]    102.678948 s: actX  0.000000
12-17-20 54:52.788  [HOST] [IPU1-0]    102.679039 s: actY  0.000000
12-17-20 54:52.789  [HOST] [IPU1-0]    102.679100 s: TargetPhi,0.000000
12-17-20 54:52.789  [HOST] [IPU1-0]    102.679253 s: >>APA_Alg_KC2InfoForTest len:1
12-17-20 54:52.789  [HOST] [IPU1-0]    102.690874 s: actX  0.000000
12-17-20 54:52.789  [HOST] [IPU1-0]    102.690996 s: actY  0.000000
12-17-20 54:52.789  [HOST] [IPU1-0]    102.691057 s: TargetPhi,0.000000
12-17-20 54:52.790  [HOST] [IPU1-0]    102.700969 s: actX  0.000000
12-17-20 54:52.790  [HOST] [IPU1-0]    102.701030 s: actY  0.000000
12-17-20 54:52.790  [HOST] [IPU1-0]    102.701091 s: TargetPhi,0.000000
12-17-20 54:52.793  [HOST] [IPU1-0]    102.712895 s: actX  0.000000
12-17-20 54:52.802  [HOST] [IPU1-0]    102.712987 s: actY  0.000000
12-17-20 54:52.802  [HOST] [IPU1-0]    102.713078 s: TargetPhi,0.000000
12-17-20 54:52.803  [HOST] [IPU1-0]    102.722961 s: actX  0.000000
12-17-20 54:52.803  [HOST] [IPU1-0]    102.723052 s: actY  0.000000
12-17-20 54:52.803  [HOST] [IPU1-0]    102.723113 s: TargetPhi,0.000000
12-17-20 54:52.803  [HOST] [IPU1-0]    102.734886 s: actX  0.000000
12-17-20 54:52.804  [HOST] [IPU1-0]    102.734978 s: actY  0.000000
12-17-20 54:52.804  [HOST] [IPU1-0]    102.735069 s: TargetPhi,0.000000
12-17-20 54:52.804  [HOST] [IPU1-0]    102.744952 s: actX  0.000000
12-17-20 54:52.804  [HOST] [IPU1-0]    102.745043 s: actY  0.000000
12-17-20 54:52.805  [HOST] [IPU1-0]    102.745104 s: Targ
12-17-20 54:52.805  [HOST] [IPU1-0] etPhi,0.000000
12-17-20 54:52.805  [HOST] [IPU1-0]    102.756877 s: actX  0.000000
12-17-20 54:52.805  [HOST] [IPU1-0]    102.756969 s: actY  0.000000
12-17-20 54:52.806  [HOST] [IPU1-0]    102.757030 s: TargetPhi,0.000000
12-17-20 54:52.806  [HOST] [IPU1-0]    102.766973 s: actX  0.000000
12-17-20 54:52.806  [HOST] [IPU1-0]    102.767034 s: actY  0.000000
12-17-20 54:52.807  [HOST] [IPU1-0]    102.767095 s: TargetPhi,0.000000
12-17-20 54:52.807  [HOST] [IPU1-0]    102.778869 s: actX  0.000000
12-17-20 54:52.807  [HOST] [IPU1-0]    102.778960 s: actY  0.000000
12-17-20 54:52.808  [HOST] [IPU1-0]    102.779052 s: TargetPhi,0.000000
12-17-20 54:52.808  [HOST] [IPU1-0]    102.779204 s: >>APA_Alg_KC2InfoForTest len:1
12-17-20 54:52.808  [HOST] [IPU1-0]    102.788964 s: actX  0.000000
12-17-20 54:52.809  [HOST] [IPU1-0]    102.789056 s: actY  0.000000
12-17-20 54:52.809  [HOST] [IPU1-0]    102.789117 s: TargetPhi,0.000000
12-17-20 54:52.809  [HOST] [IPU1-0]    102.800890 s: actX  0.000000
12-17-20 54:52.810  [HOST] [IPU1-0]    102.800982 s: actY  0.000000
12-17-20 54:52.810  [HOST] [IPU1-0]    102.801073 s: TargetPhi,0.000000
12-17-20 54:52.810  [HOST] [IPU1-0]    102.810955 s: actX  0.000000
12-17-20 54:52.811  [HOST] [IPU1-0]    102.811047 s: actY  0.000000
12-17-20 54:52.811  [HOST] [IPU1-0]    102.811108 s: TargetPhi,0.000000
12-17-20 54:52.811  [HOST] [IPU1-0]    102.825108 s: actX  0.000000
12-17-20 54:52.812  [HOST] [IPU1-0]    102.825169 s: actY  0.000000
12-17-20 54:52.812  [HOST] [IPU1-0]    102.825230 s: TargetPhi,0.000000
12-17-20 54:52.812  [HOST] [IPU1-0]    102.834960 s: actX  0.000000
12-17-20 54:52.812  [HOST] [IPU1-0]    102.835051 s: actY  0.000000
12-17-20 54:52.812  [HOST] [IPU1-0]    102.835112 s: TargetPhi,0.000000
12-17-20 54:52.813  [HOST] [IPU1-0]    102.846885 s: actX  0.000000
12-17-20 54:52.813  [HOST] [IPU1-0]    102.847007 s: actY  0.000000
12-17-20 54:52.813  [HOST] [IPU1-0]    102.847068 s: TargetPhi,0.000000
12-17-20 54:52.813  [HOST] [IPU1-0]    102.856981 s: actX  0.000000
12-17-20 54:52.817  [HOST] [IPU1-0]    102.857042 s: actY  0.000000
12-17-20 54:52.818  [HOST] [IPU1-0]    102.857103 s: TargetPhi,0.000000
12-17-20 54:52.818  [HOST] [IPU1-0]    102.868876 s: actX  0.000000
12-17-20 54:52.819  [HOST] [IPU1-0]    102.868998 s: actY  0.000000
12-17-20 54:52.819  [HOST] [IPU1-0]    102.869059 s: TargetPhi,0.000000
12-17-20 54:52.820  [HOST] [IPU1-0]    102.877722 s: >>APA_Alg_KC2InfoForTest len:1
12-17-20 54:52.820  [HOST] [IPU1-0]    102.878972 s: actX  0.000000
12-17-20 54:52.821  [HOST] [IPU1-0]    102.879033 s: actY  0.000000
12-17-20 54:52.821  [HOST] [IPU1-0]    102.879125 s: TargetPhi,0.000000
12-17-20 54:52.821  [HOST] [IPU1-0]    102.890868 s: actX  0.000000
12-17-20 54:52.822  [HOST] [IPU1-0]    102.890990 s: actY  0.000000
12-17-20 54:52.822  [HOST] [IPU1-0]    102.891051 s: TargetPhi,0.000000
12-17-20 54:52.823  [HOST] [IPU1-0]    102.900963 s: actX  0.000000
12-17-20 54:52.823  [HOST] [IPU1-0]    102.901055 s: actY  0.000000
12-17-20 54:52.823  [HOST] [IPU1-0]    102.901116 s: TargetPhi,0.000000
12-17-20 54:52.823  [HOST] [IPU1-0]    102.912920 s: actX  0.000000
12-17-20 54:52.824  [HOST] [IPU1-0]    102.913011 s: actY  0.000000
12-17-20 54:52.824  [HOST] [IPU1-0]    102.913072 s: TargetPhi,0.000000
12-17-20 54:52.825  [HOST] [IPU1-0]    102.922985 s: actX  0.000000
12-17-20 54:52.826  [HOST] [IPU1-0]    102.923076 s: actY  0.000000
12-17-20 54:52.826  [HOST] [IPU1-0]    102.923168 s: TargetPhi,0.000000
12-17-20 54:52.826  [HOST] [IPU1-0]    102.934880 s: actX  0.000000
12-17-20 54:52.827  [HOST] [IPU1-0]    102.935002 s: actY  0.000000
12-17-20 54:52.827  [HOST] [IPU1-0]    102.935063 s: TargetPhi,0.000000
12-17-20 54:52.827  [HOST] [IPU1-0]    102.944976 s: actX  0.000000
12-17-20 54:52.828  [HOST] [IPU1-0]    102.945037 s: actY  0.000000
12-17-20 54:52.828  [HOST] [IPU1-0]    102.945098 s: TargetPhi,0.000000
12-17-20 54:52.828  [HOST] [IPU1-0]    102.956902 s: actX  0.000000
12-17-20 54:52.828  [HOST] [IPU1-0]    102.957024 s: actY  0.000000
12-17-20 54:52.828  [HOST] [IPU1-0]    102.957085 s: TargetPhi,0.000000
12-17-20 54:52.829  [HOST] [IPU1-0]    102.966967 s: actX  0.000000
12-17-20 54:52.829  [HOST] [IPU1-0]    102.967059 s: actY  0.000000
12-17-20 54:52.829  [HOST] [IPU1-0]    102.967150 s: TargetPhi,0.000000
12-17-20 54:52.829  [HOST] [IPU1-0]    102.978893 s: actX  0.000000
12-17-20 54:52.830  [HOST] [IPU1-0]    102.978984 s: actY  0.000000
12-17-20 54:52.830  [HOST] [IPU1-0]    102.979045 s: TargetPhi,0.000000
12-17-20 54:52.830  [HOST] [IPU1-0]    102.979259 s: >>APA_Alg_KC2InfoForTest len:1
12-17-20 54:52.830  [HOST] [IPU1-0]    102.988958 s: actX  0.000000
12-17-20 54:52.830  [HOST] [IPU1-0]    102.989050 s: actY  0.000000
12-17-20 54:52.831  [HOST] [IPU1-0]    102.989111 s: TargetPhi,0.000000
12-17-20 54:52.831  [HOST] [IPU1-0]    103.000884 s: actX  0.000000
12-17-20 54:52.835  [HOST] [IPU1-0]    103.001006 s: actY  0.000000
12-17-20 54:52.835  [HOST] [IPU1-0]    103.001067 s: TargetPhi,0.000000
12-17-20 54:52.836  [HOST] [IPU1-0]    103.010980 s: actX  0.000000
12-17-20 54:52.836  [HOST] [IPU1-0]    103.011041 s: actY  0.000000
12-17-20 54:52.836  [HOST] [IPU1-0]    103.011132 s: TargetPhi,0.000000
12-17-20 54:52.837  [HOST] [IPU1-0]    103.022936 s: actX  0.000000
12-17-20 54:52.837  [HOST] [IPU1-0]    103.023028 s: actY  0.000000
12-17-20 54:52.837  [HOST] [IPU1-0]    103.023089 s: TargetPhi,0.000000
12-17-20 54:52.838  [HOST] [IPU1-0]    103.032971 s: actX  0.000000
12-17-20 54:52.838  [HOST] [IPU1-0]    103.033032 s: actY  0.000000
12-17-20 54:52.839  [HOST] [IPU1-0]    103.033123 s: TargetPhi,0.000000
12-17-20 54:52.839  [HOST] [IPU1-0]    103.044866 s: actX  0.000000
12-17-20 54:52.839  [HOST] [IPU1-0]    103.044988 s: actY  0.000000
12-17-20 54:52.840  [HOST] [IPU1-0]    103.045049 s: TargetPhi,0.000000
12-17-20 54:52.840  [HOST] [IPU1-0]    103.054962 s: actX  0.000000
12-17-20 54:52.841  [HOST] [IPU1-0]    103.055053 s: actY  0.000000
12-17-20 54:52.842  [HOST] [IPU1-0]    103.055114 s: TargetPhi,0.000000
12-17-20 54:52.842  [HOST] [IPU1-0]    103.066888 s: actX  0.000000
12-17-20 54:52.843  [HOST] [IPU1-0]    103.067040 s: actY  0.000000
12-17-20 54:52.843  [HOST] [IPU1-0]    103.067101 s: TargetPhi,0.000000
12-17-20 54:52.843  [HOST] [IPU1-0]    103.076984 s: actX  0.000000
12-17-20 54:52.844  [HOST] [IPU1-0]    103.077045 s: actY  0.000000
12-17-20 54:52.844  [HOST] [IPU1-0]    103.077106 s: TargetPhi,0.000000
12-17-20 54:52.844  [HOST] [IPU1-0]    103.077258 s: >>APA_Alg_KC2InfoForTest len:1
12-17-20 54:52.844  [HOST] [IPU1-0]    103.089702 s: actX  0.000000
12-17-20 54:52.845  [HOST] [IPU1-0]    103.089794 s: actY  0.000000
12-17-20 54:52.845  [HOST] [IPU1-0]    103.089885 s: TargetPhi,0.000000
12-17-20 54:52.845  [HOST] [IPU1-0]    103.099981 s: actX  0.000000
12-17-20 54:52.846  [HOST] [IPU1-0]    103.100042 s: actY  0.000000
12-17-20 54:52.846  [HOST] [IPU1-0]    103.100103 s: TargetPhi,0.000000
12-17-20 54:52.846  [HOST] [IPU1-0]    103.111877 s: actX  0.000000
12-17-20 54:52.847  [HOST] [IPU1-0]    103.111999 s: actY  0.000000
12-17-20 54:52.847  [HOST] [IPU1-0]    103.112060 s: TargetPhi,0.000000
12-17-20 54:52.848  [HOST] [IPU1-0]    103.121972 s: actX  0.000000
12-17-20 54:52.848  [HOST] [IPU1-0]    103.122064 s: actY  0.000000
12-17-20 54:52.848  [HOST] [IPU1-0]    103.122125 s: TargetPhi,0.000000
12-17-20 54:52.849  [HOST] [IPU1-0]    103.133929 s: actX  0.000000
12-17-20 54:52.849  [HOST] [IPU1-0]    103.134051 s: actY  0.000000
12-17-20 54:52.850  [HOST] [IPU1-0]    103.134112 s: TargetPhi,0.000000
12-17-20 54:52.850  [HOST] [IPU1-0]    103.143963 s: actX  0.000000
12-17-20 54:52.850  [HOST] [IPU1-0]    103.144085 s: actY  0.000000
12-17-20 54:52.855  [HOST] [IPU1-0]    103.144177 s: TargetPhi,0.000000
12-17-20 54:52.855  [HOST] [IPU1-0]    103.155889 s: actX  0.000000
12-17-20 54:52.856  [HOST] [IPU1-0]    103.156011 s: actY  0.000000
12-17-20 54:52.856  [HOST] [IPU1-0]    103.156072 s: TargetPhi,0.000000
12-17-20 54:52.856  [HOST] [IPU1-0]    103.165985 s: actX  0.000000
12-17-20 54:52.857  [HOST] [IPU1-0]    103.166046 s: actY  0.000000
12-17-20 54:52.857  [HOST] [IPU1-0]    103.166107 s: TargetPhi,0.000000
12-17-20 54:52.858  [HOST] [IPU1-0]    103.177880 s: actX  0.000000
12-17-20 54:52.858  [HOST] [IPU1-0]    103.178002 s: actY  0.000000
12-17-20 54:52.858  [HOST] [IPU1-0]    103.178063 s: TargetPhi,0.000000
12-17-20 54:52.859  [HOST] [IPU1-0]    103.179985 s: >>APA_Alg_KC2InfoForTest len:1
12-17-20 54:52.859  [HOST] [IPU1-0]    103.187976 s: actX  0.000000
12-17-20 54:52.859  [HOST] [IPU1-0]    103.188068 s: actY  0.000000
12-17-20 54:52.860  [HOST] [IPU1-0]    103.188159 s: TargetPhi,0.000000
12-17-20 54:52.860  [HOST] [IPU1-0]    103.199871 s: actX  0.000000
12-17-20 54:52.860  [HOST] [IPU1-0]    103.199993 s: actY  0.000000
12-17-20 54:52.861  [HOST] [IPU1-0]    103.200054 s: TargetPhi,0.000000
12-17-20 54:52.861  [HOST] [IPU1-0]    103.209967 s: actX  0.000000
12-17-20 54:52.862  [HOST] [IPU1-0]    103.210059 s: actY  0.000000
12-17-20 54:52.863  [HOST] [IPU1-0]    103.210120 s: TargetPhi,0.000000
12-17-20 54:52.863  [HOST] [IPU1-0]    103.221893 s: actX  0.000000
12-17-20 54:52.863  [HOST] [IPU1-0]    103.221984 s: actY  0.000000
12-17-20 54:52.864  [HOST] [IPU1-0]    103.222076 s: TargetPhi,0.000000
12-17-20 54:52.864  [HOST] [IPU1-0]    103.231989 s: actX  0.000000
12-17-20 54:52.865  [HOST] [IPU1-0]    103.232050 s: actY  0.000000
12-17-20 54:52.865  [HOST] [IPU1-0]    103.232111 s: TargetPhi,0.000000
12-17-20 54:52.865  [HOST] [IPU1-0]    103.243884 s: actX  0.000000
12-17-20 54:52.866  [HOST] [IPU1-0]    103.244037 s: actY  0.000000
12-17-20 54:52.866  [HOST] [IPU1-0]    103.244098 s: TargetPhi,0.000000
12-17-20 54:52.866  [HOST] [IPU1-0]    103.253980 s: actX  0.000000
12-17-20 54:52.867  [HOST] [IPU1-0]    103.254071 s: actY  0.000000
12-17-20 54:52.867  [HOST] [IPU1-0]    103.254132 s: TargetPhi,0.000000
12-17-20 54:52.867  [HOST] [IPU1-0]    103.265906 s: actX  0.000000
12-17-20 54:52.868  [HOST] [IPU1-0]    103.265997 s: actY  0.000000
12-17-20 54:52.868  [HOST] [IPU1-0]    103.266058 s: TargetPhi,0.000000
12-17-20 54:52.868  [HOST] [IPU1-0]    103.275971 s: actX  0.000000
12-17-20 54:52.869  [HOST] [IPU1-0]    103.276062 s: actY  0.000000
12-17-20 54:52.869  [HOST] [IPU1-0]    103.276123 s: TargetPhi,0.000000
12-17-20 54:52.869  [HOST] [IPU1-0]    103.277984 s: >>APA_Alg_KC2InfoForTest len:1
12-17-20 54:52.870  [HOST] [IPU1-0]    103.287897 s: actX  0.000000
12-17-20 54:52.871  [HOST] [IPU1-0]    103.288049 s: actY  0.000000
12-17-20 54:52.875  [HOST] [IPU1-0]    103.288110 s: TargetPhi,0.000000
12-17-20 54:52.876  [HOST] [IPU1-0]    103.297993 s: actX  0.000000
12-17-20 54:52.876  [HOST] [IPU1-0]    103.298054 s: actY  0.000000
12-17-20 54:52.877  [HOST] [IPU1-0]    103.298115 s: TargetPhi,0.000000
12-17-20 54:52.877  [HOST] [IPU1-0]    103.309888 s: actX  0.000000
12-17-20 54:52.877  [HOST] [IPU1-0]    103.309979 s: actY  0.000000
12-17-20 54:52.878  [HOST] [IPU1-0]    103.310040 s: TargetPhi,0.000000
12-17-20 54:52.878  [HOST] [IPU1-0]    103.319984 s: actX  0.000000
12-17-20 54:52.878  [HOST] [IPU1-0]    103.320045 s: actY  0.000000
12-17-20 54:52.879  [HOST] [IPU1-0]    103.320106 s: TargetPhi,0.000000
12-17-20 54:52.879  [HOST] [IPU1-0]    103.331909 s: actX  0.000000
12-17-20 54:52.880  [HOST] [IPU1-0]    103.332001 s: actY  0.000000
12-17-20 54:52.880  [HOST] [IPU1-0]    103.332123 s: TargetPhi,0.000000
12-17-20 54:52.880  [HOST] [IPU1-0]    103.341975 s: actX  0.000000
12-17-20 54:52.881  [HOST] [IPU1-0]    103.342066 s: actY  0.000000
12-17-20 54:52.881  [HOST] [IPU1-0]    103.342127 s: TargetPhi,0.000000
12-17-20 54:52.881  [HOST] [IPU1-0]    103.353901 s: actX  0.000000
12-17-20 54:52.882  [HOST] [IPU1-0]    103.353992 s: actY  0.000000
12-17-20 54:52.882  [HOST] [IPU1-0]    103.354053 s: TargetPhi,0.000000
12-17-20 54:52.883  [HOST] [IPU1-0]    103.363966 s: actX  0.000000
12-17-20 54:52.883  [HOST] [IPU1-0]    103.364057 s: actY  0.000000
12-17-20 54:52.884  [HOST] [IPU1-0]    103.364118 s: TargetPhi,0.000000
12-17-20 54:52.884  [HOST] [IPU1-0]    103.377325 s: actX  0.000000
12-17-20 54:52.884  [HOST] [IPU1-0]    103.377386 s: actY  0.000000
12-17-20 54:52.885  [HOST] [IPU1-0]    103.377447 s: TargetPhi,0.000000
12-17-20 54:52.885  [HOST] [IPU1-0]    103.378972 s: >>APA_Alg_KC2InfoForTest len:1
12-17-20 54:52.886  [HOST] [IPU1-0]    103.386994 s: actX  0.000000
12-17-20 54:52.886  [HOST] [IPU1-0]    103.387055 s: actY  0.000000
12-17-20 54:52.886  [HOST] [IPU1-0]    103.387116 s: TargetPhi,0.000000
12-17-20 54:52.887  [HOST] [IPU1-0]    103.399896 s: actX  0.000000
12-17-20 54:52.887  [HOST] [IPU1-0]    103.399987 s: actY  0.000000
12-17-20 54:52.888  [HOST] [IPU1-0]    103.400048 s: TargetPhi,0.000000
12-17-20 54:52.888  [HOST] [IPU1-0]    103.409992 s: actX  0.000000
12-17-20 54:52.888  [HOST] [IPU1-0]    103.410053 s: actY  0.000000
12-17-20 54:52.889  [HOST] [IPU1-0]    103.410144 s: TargetPhi,0.000000
12-17-20 54:52.889  [HOST] [IPU1-0]    103.421887 s: actX  0.000000
12-17-20 54:52.889  [HOST] [IPU1-0]    103.422009 s: actY  0.000000
12-17-20 54:52.890  [HOST] [IPU1-0]    103.422070 s: TargetPhi,0.000000
12-17-20 54:52.890  [HOST] [IPU1-0]    103.431983 s: actX  0.000000
12-17-20 54:52.890  [HOST] [IPU1-0]    103.432044 s: actY  0.000000
12-17-20 54:52.891  [HOST] [IPU1-0]    103.432135 s: TargetPhi,0.000000
12-17-20 54:52.895  [HOST] [IPU1-0]    103.443908 s: actX  0.000000
12-17-20 54:52.896  [HOST] [IPU1-0]    103.444000 s: actY  0.000000
12-17-20 54:52.896  [HOST] [IPU1-0]    103.444091 s: TargetPhi,0.000000
12-17-20 54:52.897  [HOST] [IPU1-0]    103.453974 s: actX  0.000000
12-17-20 54:52.897  [HOST] [IPU1-0]    103.454065 s: actY  0.000000
12-17-20 54:52.897  [HOST] [IPU1-0]    103.454126 s: TargetPhi,0.000000
12-17-20 54:52.898  [HOST] [IPU1-0]    103.465900 s: actX  0.000000
12-17-20 54:52.899  [HOST] [IPU1-0]    103.465991 s: actY  0.000000
12-17-20 54:52.899  [HOST] [IPU1-0]    103.466052 s: TargetPhi,0.000000
12-17-20 54:52.899  [HOST] [IPU1-0]    103.475995 s: actX  0.000000
12-17-20 54:52.900  [HOST] [IPU1-0]    103.476056 s: actY  0.000000
12-17-20 54:52.901  [HOST] [IPU1-0]    103.476117 s: TargetPhi,0.000000
12-17-20 54:52.901  [HOST] [IPU1-0]    103.476270 s: >>APA_Alg_KC2InfoForTest len:1
12-17-20 54:52.901  [HOST] [IPU1-0]    103.487891 s: actX  0.000000
12-17-20 54:52.901  [HOST] [IPU1-0]    103.488013 s: actY  0.000000
12-17-20 54:52.902  [HOST] [IPU1-0]    103.488074 s: TargetPhi,0.000000
12-17-20 54:52.902  [HOST] [IPU1-0]    103.497986 s: actX  0.000000
12-17-20 54:52.903  [HOST] [IPU1-0]    103.498047 s: actY  0.000000
12-17-20 54:52.904  [HOST] [IPU1-0]    103.498139 s: TargetPhi,0.000000
12-17-20 54:52.904  [HOST] [IPU1-0]    103.510705 s: actX  0.000000
12-17-20 54:52.904  [HOST] [IPU1-0]    103.510766 s: actY  0.000000
12-17-20 54:52.904  [HOST] [IPU1-0]    103.510858 s: TargetPhi,0.000000
12-17-20 54:52.905  [HOST] [IPU1-0]    103.520984 s: actX  0.000000
12-17-20 54:52.905  [HOST] [IPU1-0]    103.521045 s: actY  0.000000
12-17-20 54:52.905  [HOST] [IPU1-0]    103.521137 s: TargetPhi,0.000000
12-17-20 54:52.905  [HOST] [IPU1-0]    103.532910 s: actX  0.000000
12-17-20 54:52.905  [HOST] [IPU1-0]    103.533001 s: actY  0.000000
12-17-20 54:52.906  [HOST] [IPU1-0]    103.533062 s: TargetPhi,0.000000
12-17-20 54:52.906  [HOST] [IPU1-0]    103.542975 s: actX  0.000000
12-17-20 54:52.906  [HOST] [IPU1-0]    103.543067 s: actY  0.000000
12-17-20 54:52.906  [HOST] [IPU1-0]    103.543128 s: TargetPhi,0.000000
12-17-20 54:52.907  [HOST] [IPU1-0]    103.554901 s: actX  0.000000
12-17-20 54:52.907  [HOST] [IPU1-0]    103.554992 s: actY  0.000000
12-17-20 54:52.907  [HOST] [IPU1-0]    103.555084 s: TargetPhi,0.000000
12-17-20 54:52.907  [HOST] [IPU1-0]    103.564997 s: actX  0.000000
12-17-20 54:52.908  [HOST] [IPU1-0]    103.565058 s: actY  0.000000
12-17-20 54:52.908  [HOST] [IPU1-0]    103.565119 s: TargetPhi,0.000000
12-17-20 54:52.908  [HOST] [IPU1-0]    103.576953 s: actX  0.000000
12-17-20 54:52.909  [HOST] [IPU1-0]    103.577045 s: actY  0.000000
12-17-20 54:52.909  [HOST] [IPU1-0]    103.577106 s: TargetPhi,0.000000
12-17-20 54:52.909  [HOST] [IPU1-0]    103.578997 s: >>APA_Alg_KC2InfoForTest len:1
12-17-20 54:52.911  [HOST] [IPU1-0]    103.586988 s: actX  0.000000
12-17-20 54:52.912  [HOST] [IPU1-0]    103.587079 s: actY  0.000000
12-17-20 54:52.912  [HOST] [IPU1-0]    103.587140 s: TargetPhi,0.000000
12-17-20 54:52.912  [HOST] [IPU1-0]    103.598914 s: actX  0.000000
12-17-20 54:52.912  [HOST] [IPU1-0]    103.599005 s: actY  0.000000
12-17-20 54:52.912  [HOST] [IPU1-0]    103.599066 s: TargetPhi,0.000000
12-17-20 54:52.913  [HOST] [IPU1-0]    103.608979 s: actX  0.000000
12-17-20 54:52.913  [HOST] [IPU1-0]    103.609070 s: actY  0.000000
12-17-20 54:52.913  [HOST] [IPU1-0]    103.609131 s: TargetPhi,0.000000
12-17-20 54:52.913  [HOST] [IPU1-0]    103.620905 s: actX  0.000000
12-17-20 54:52.914  [HOST] [IPU1-0]    103.620996 s: actY  0.000000
12-17-20 54:52.914  [HOST] [IPU1-0]    103.621057 s: TargetPhi,0.000000
12-17-20 54:52.914  [HOST] [IPU1-0]    103.631001 s: actX  0.000000
12-17-20 54:52.914  [HOST] [IPU1-0]    103.631062 s: actY  0.000000
12-17-20 54:52.914  [HOST] [IPU1-0]    103.631123 s: TargetPhi,0.000000
12-17-20 54:52.915  [HOST] [IPU1-0]    103.642896 s: actX  0.000000
12-17-20 54:52.915  [HOST] [IPU1-0]    103.643018 s: actY  0.000000
12-17-20 54:52.915  [HOST] [IPU1-0]    103.643079 s: TargetPhi,0.000000
12-17-20 54:52.915  [HOST] [IPU1-0]    103.652992 s: actX  0.000000
12-17-20 54:52.915  [HOST] [IPU1-0]    104.261910 s: actX  0.000000
12-17-20 54:52.915  [HOST] [IPU1-0]    104.262032 s: actY  0.000000
12-17-20 54:52.916  [HOST] [IPU1-0]    104.262093 s: TargetPhi,0.000000
12-17-20 54:52.916  [HOST] [IPU1-0]    104.272006 s: actX  0.000000
12-17-20 54:52.916  [HOST] [IPU1-0]    104.272097 s: actY  0.000000
12-17-20 54:52.916  [HOST] [IPU1-0]    104.272158 s: TargetPhi,0.000000
12-17-20 54:52.917  [HOST] [IPU1-0]    104.276001 s: >>APA_Alg_KC2InfoForTest len:1
12-17-20 54:52.917  [HOST] [IPU1-0]    104.283932 s: actX  0.000000
12-17-20 54:52.917  [HOST] [IPU1-0]    104.284023 s: actY  0.000000
12-17-20 54:52.917  [HOST] [IPU1-0]    104.284084 s: TargetPhi,0.000000
12-17-20 54:52.918  [HOST] [IPU1-0]    104.293997 s: actX  0.000000
12-17-20 54:52.918  [HOST] [IPU1-0]    104.294088 s: actY  0.000000
12-17-20 54:52.919  [HOST] [IPU1-0]    104.294149 s: TargetPhi,0.000000
12-17-20 54:52.919  [HOST] [IPU1-0]    104.305923 s: actX  0.000000
12-17-20 54:52.919  [HOST] [IPU1-0]    104.306014 s: actY  0.000000
12-17-20 54:52.919  [HOST] [IPU1-0]    104.306075 s: TargetPhi,0.000000
12-17-20 54:52.919  [HOST] [IPU1-0]    104.316019 s: actX  0.000000
12-17-20 54:52.919  [HOST] [IPU1-0]    104.316080 s: actY  0.000000
12-17-20 54:52.920  [HOST] [IPU1-0]    104.316141 s: TargetPhi,0.000000
12-17-20 54:52.920  [HOST] [IPU1-0]    104.327914 s: actX  0.000000
12-17-20 54:52.920  [HOST] [IPU1-0]    104.328036 s: actY  0.000000
12-17-20 54:52.920  [HOST] [IPU1-0]    104.328097 s: TargetPhi,0.000000
12-17-20 54:52.923  [HOST] [IPU1-0]    104.338010 s: actX  0.000000
12-17-20 54:52.923  [HOST] [IPU1-0]    104.338071 s: actY  0.000000
12-17-20 54:52.923  [HOST] [IPU1-0]    104.338162 s: TargetPhi,0.000000
12-17-20 54:52.924  [HOST] [IPU1-0]    104.349935 s: actX  0.000000
12-17-20 54:52.924  [HOST] [IPU1-0]    104.350027 s: actY  0.000000
12-17-20 54:52.924  [HOST] [IPU1-0]    104.350088 s: TargetPhi,0.000000
12-17-20 54:52.924  [HOST] [IPU1-0]    104.360001 s: actX  0.000000
12-17-20 54:52.925  [HOST] [IPU1-0]    104.360092 s: actY  0.000000
12-17-20 54:52.925  [HOST] [IPU1-0]    104.360153 s: TargetPhi,0.000000
12-17-20 54:52.925  [HOST] [IPU1-0]    104.371988 s: actX  0.000000
12-17-20 54:52.925  [HOST] [IPU1-0]    104.372079 s: actY  0.000000
12-17-20 54:52.926  [HOST] [IPU1-0]    104.372140 s: TargetPhi,0.000000
12-17-20 54:52.926  [HOST] [IPU1-0]    104.376014 s: >>APA_Alg_KC2InfoForTest len:1
12-17-20 54:52.926  [HOST] [IPU1-0]    104.382022 s: actX  0.000000
12-17-20 54:52.926  [HOST] [IPU1-0]    104.382114 s: actY  0.000000
12-17-20 54:52.926  [HOST] [IPU1-0]    104.382175 s: TargetPhi,0.000000
12-17-20 54:52.926  [HOST] [IPU1-0]    104.393918 s: actX  0.000000
12-17-20 54:52.927  [HOST] [IPU1-0]    104.394009 s: actY  0.000000
12-17-20 54:52.927  [HOST] [IPU1-0]    104.394070 s: TargetPhi,0.000000
12-17-20 54:52.927  [HOST] [IPU1-0]    104.404013 s: actX  0.000000
12-17-20 54:52.927  [HOST] [IPU1-0]    104.404105 s: actY  0.000000
12-17-20 54:52.927  [HOST] [IPU1-0]    104.404166 s: TargetPhi,0.000000
12-17-20 54:52.928  [HOST] [IPU1-0]    104.415909 s: actX  0.000000
12-17-20 54:52.928  [HOST] [IPU1-0]    104.416031 s: actY  0.000000
12-17-20 54:52.928  [HOST] [IPU1-0]    104.416092 s: TargetPhi,0.000000
12-17-20 54:52.928  [HOST] [IPU1-0]    104.426005 s: actX  0.000000
12-17-20 54:52.928  [HOST] [IPU1-0]    104.426096 s: actY  0.000000
12-17-20 54:52.928  [HOST] [IPU1-0]    104.426157 s: TargetPhi,0.000000
12-17-20 54:52.929  [HOST] [IPU1-0]    104.437930 s: actX  0.000000
12-17-20 54:52.929  [HOST] [IPU1-0]    104.438022 s: actY  0.000000
12-17-20 54:52.929  [HOST] [IPU1-0]    104.438113 s: TargetPhi,0.000000
12-17-20 54:52.929  [HOST] [IPU1-0]    104.447996 s: actX  0.000000
12-17-20 54:52.929  [HOST] [IPU1-0]    104.448087 s: actY  0.000000
12-17-20 54:52.929  [HOST] [IPU1-0]    104.448148 s: TargetPhi,0.000000
12-17-20 54:52.929  [HOST] [IPU1-0]    104.459921 s: actX  0.000000
12-17-20 54:52.930  [HOST] [IPU1-0]    104.460013 s: actY  0.000000
12-17-20 54:52.930  [HOST] [IPU1-0]    104.460104 s: TargetPhi,0.000000
12-17-20 54:52.930  [HOST] [IPU1-0]    104.470017 s: actX  0.000000
12-17-20 54:52.930  [HOST] [IPU1-0]    104.470078 s: actY  0.000000
12-17-20 54:52.930  [HOST] [IPU1-0]    104.470139 s: TargetPhi,0.000000
12-17-20 54:52.931  [HOST] [IPU1-0]    104.474013 s: >>APA_Alg_KC2InfoForTest len:1
12-17-20 54:52.935  [HOST] [IPU1-0]    104.483346 s: actX  0.000000
12-17-20 54:52.935  [HOST] [IPU1-0]    104.483468 s: actY  0.000000
12-17-20 54:52.936  [HOST] [IPU1-0]    104.483529 s: TargetPhi,0.000000
12-17-20 54:52.936  [HOST] [IPU1-0]    104.493015 s: actX  0.000000
12-17-20 54:52.936  [HOST] [IPU1-0]    104.493076 s: actY  0.000000
12-17-20 54:52.936  [HOST] [IPU1-0]    104.493167 s: TargetPhi,0.000000
12-17-20 54:52.936  [HOST] [HOST  ]    102.909992 s:  exportDmaBuf failed 
12-17-20 54:52.936  [HOST] [HOST  ]  
12-17-20 54:52.936  [HOST] [HOST  ]    103.263527 s:  exportDmaBuf failed 
12-17-20 54:52.937  [HOST] [HOST  ]  
12-17-20 54:52.937  [HOST] [HOST  ]    103.617062 s:  exportDmaBuf failed 
12-17-20 54:52.937  [HOST] [HOST  ]  
12-17-20 54:52.937  [HOST] [HOST  ]    104.252302 s:  exportDmaBuf failed 
12-17-20 54:52.938  [HOST] [HOST  ]  
12-17-20 54:52.957  [HOST] [IPU1-0]    104.505917 s: actX  0.000000
12-17-20 54:52.957  [HOST] [IPU1-0]    104.506008 s: actY  0.000000
12-17-20 54:52.957  [HOST] [IPU1-0]    104.506130 s: TargetPhi,0.000000
12-17-20 54:52.957  [HOST] [IPU1-0]    104.516012 s: actX  0.000000
12-17-20 54:52.957  [HOST] [IPU1-0]    104.516104 s: actY  0.000000
12-17-20 54:52.958  [HOST] [IPU1-0]    104.516165 s: TargetPhi,0.000000
12-17-20 54:52.958  [HOST] [IPU1-0]    104.527938 s: actX  0.000000
12-17-20 54:52.959  [HOST] [IPU1-0]    104.528030 s: actY  0.000000
12-17-20 54:52.959  [HOST] [IPU1-0]    104.528091 s: TargetPhi,0.000000
12-17-20 54:52.959  [HOST] [IPU1-0]    104.538004 s: actX  0.000000
12-17-20 54:52.959  [HOST] [IPU1-0]    104.538095 s: actY  0.000000
12-17-20 54:52.960  [HOST] [IPU1-0]    104.538156 s: TargetPhi,0.000000

Any suggestion is appreciated!

  • Hi,

    Can you check if CONFIG_ARM_LAPE=y in your kernel config. If this is enabled, can you disable this config (CONFIG_ARM_LPAE=n), and see if you still notice this error?


    Regards

    Shravan

  • os_tools/linux/kernel/omap/arch/arm/configs/ti_sdk_dra7x_release_ecarx_defconfig:443:# CONFIG_ARM_LPAE is not set

    the  LAPE is disabled.

  • any updates?  right now reproduced 3 times even after reboot

  • add extra trace:

    [HOST] [HOST ] 127.784572 s: exportDmaBuf failed retVal=-1
    [HOST] [HOST ] errno Invalid argument
    [HOST] [HOST ] 128.139510 s: exportDmaBuf failed retVal=-1
    [HOST] [HOST ] errno Invalid argument
  • Hi :

       Attach the kernel information

    exportMem.txt
    root@dra7xx-evm:/opt/vision_sdk# [  126.797261] omap_l3_noc 44000000.ocp: L3 application error: target 3 mod:2 (unclearable)
    [  126.805427] omap_l3_noc 44000000.ocp: L3 debug error: target 3 mod:2 (unclearable)
    [  131.756121] apps2.out: page allocation failure: order:0, mode:0x0
    [  131.762306] CPU: 1 PID: 891 Comm: apps2.out Tainted: G           O    4.4.84 #29
    [  131.762447] apps2.out: page allocation failure: order:0, mode:0x0
    [  131.775853] Hardware name: Generic DRA74X (Flattened Device Tree)
    [  131.781971] Backtrace: 
    [  131.784452] [<c0013b1c>] (dump_backtrace) from [<c0013d18>] (show_stack+0x18/0x1c)
    [  131.792052]  r7:c0936664 r6:60070013 r5:00000000 r4:c0953590
    [  131.797774] [<c0013d00>] (show_stack) from [<c02b39a8>] (dump_stack+0x8c/0xa0)
    [  131.805031] [<c02b391c>] (dump_stack) from [<c00d77c8>] (warn_alloc_failed+0xe4/0x124)
    [  131.812979]  r7:c0936664 r6:00000000 r5:00000000 r4:00000000
    [  131.818699] [<c00d76e8>] (warn_alloc_failed) from [<c00da330>] (__alloc_pages_nodemask+0x1c4/0x958)
    [  131.827780]  r3:00000000 r2:00000000
    [  131.831383]  r6:d3d2c000 r5:00000000 r4:00000050
    [  131.836047] [<c00da16c>] (__alloc_pages_nodemask) from [<c00daadc>] (__get_free_pages+0x18/0x34)
    [  131.844868]  r10:00000000 r9:d2bff49c r8:00000100 r7:00000ff0 r6:00000053 r5:00000000
    [  131.852769]  r4:000000ff
    [  131.855324] [<c00daac4>] (__get_free_pages) from [<c02c1a8c>] (sg_kmalloc+0x2c/0x30)
    [  131.863104] [<c02c1a60>] (sg_kmalloc) from [<c02c19a4>] (__sg_alloc_table+0xf8/0x134)
    [  131.870971] [<c02c18ac>] (__sg_alloc_table) from [<c02c2134>] (sg_alloc_table+0x30/0xb4)
    [  131.879094]  r10:d2bff49c r9:00000152 r8:ffffe000 r7:00000000 r6:dbdb8600 r5:af68a000
    [  131.886997]  r4:d2bff49c
    [  131.889551] [<c02c2104>] (sg_alloc_table) from [<c0414290>] (vmem_export_single+0x1cc/0x648)
    [  131.898022]  r7:00000000 r6:dbdb8600 r5:af68a000 r4:d3d2deec
    [  131.903740] [<c04140c4>] (vmem_export_single) from [<c04147d8>] (vmemexp_ioctl+0xcc/0x134)
    [  131.912037]  r10:00000000 r9:d3d2c000 r8:a7ac8d34 r7:00000051 r6:dbdb8600 r5:ffffe000
    [  131.919938]  r4:a7ac8d34
    [  131.922490] [<c041470c>] (vmemexp_ioctl) from [<c013158c>] (do_vfs_ioctl+0x460/0x6dc)
    [  131.930351]  r7:00000005 r6:dbf50240 r5:dc1518a8 r4:a7ac8d34
    [  131.936071] [<c013112c>] (do_vfs_ioctl) from [<c0131844>] (SyS_ioctl+0x3c/0x64)
    [  131.943407]  r10:00000000 r9:d3d2c000 r8:a7ac8d34 r7:c00cdbd0 r6:dbf50240 r5:00000005
    [  131.951308]  r4:dbf50241
    [  131.953861] [<c0131808>] (SyS_ioctl) from [<c000fc60>] (ret_fast_syscall+0x0/0x3c)
    [  131.961459]  r9:d3d2c000 r8:c000fe24 r7:00000036 r6:000fcd54 r5:00151800 r4:af68a000
    [  131.969280] CPU: 0 PID: 890 Comm: apps2.out Tainted: G           O    4.4.84 #29
    [  131.969331] Mem-Info:
    [  131.969343] active_anon:8243 inactive_anon:4579 isolated_anon:0
    [  131.969343]  active_file:11776 inactive_file:11639 isolated_file:0
    [  131.969343]  unevictable:0 dirty:78 writeback:0 unstable:0
    [  131.969343]  slab_reclaimable:1739 slab_unreclaimable:2676
    [  131.969343]  mapped:19017 shmem:4927 pagetables:276 bounce:0
    [  131.969343]  free:8486 free_pcp:37 free_cma:8208
    [  131.969357] Normal free:33944kB min:1780kB low:2224kB high:2668kB active_anon:32972kB inactive_anon:18316kB active_file:47104kB inactive_file:46556kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:501760kB managed:305172kB mlocked:0kB dirty:312kB writeback:0kB mapped:76068kB shmem:19708kB slab_reclaimable:6956kB slab_unreclaimable:10704kB kernel_stack:1280kB pagetables:1104kB unstable:0kB bounce:0kB free_pcp:148kB local_pcp:36kB free_cma:32832kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
    [  131.969366] lowmem_reserve[]: 0 0 0
    [  131.969408] Normal: 1*4kB (U) 10*8kB (UEC) 10*16kB (UE) 8*32kB (UEC) 11*64kB (UE) 6*128kB (C) 1*256kB (C) 4*512kB (C) 3*1024kB (C) 3*2048kB (C) 5*4096kB (C) = 33972kB
    [  131.969411] 28330 total pagecache pages
    [  131.969415] 0 pages in swap cache
    [  131.969419] Swap cache stats: add 0, delete 0, find 0/0
    [  131.969421] Free swap  = 0kB
    [  131.969423] Total swap = 0kB
    [  131.969426] 125440 pages RAM
    [  131.969428] 0 pages HighMem/MovableOnly
    [  131.969430] 49147 pages reserved
    [  131.969432] 26624 pages cma reserved
    [  131.969435] Failed to allocated sgt for 338 pages
    [  131.969442] vmemexp vmemexp: sg_alloc_from_vaddr failed
    [  131.969448] vmemexp vmemexp: vmem af68a000 export failed
    [  132.123627] Hardware name: Generic DRA74X (Flattened Device Tree)
    [  132.129745] Backtrace: 
    [  132.132225] [<c0013b1c>] (dump_backtrace) from [<c0013d18>] (show_stack+0x18/0x1c)
    [  132.139826]  r7:c0936664 r6:80070013 r5:00000000 r4:c0953590
    [  132.145549] [<c0013d00>] (show_stack) from [<c02b39a8>] (dump_stack+0x8c/0xa0)
    [  132.152807] [<c02b391c>] (dump_stack) from [<c00d77c8>] (warn_alloc_failed+0xe4/0x124)
    [  132.160756]  r7:c0936664 r6:00000000 r5:00000000 r4:00000000
    [  132.166479] [<c00d76e8>] (warn_alloc_failed) from [<c00da330>] (__alloc_pages_nodemask+0x1c4/0x958)
    [  132.175560]  r3:00000000 r2:00000000
    [  132.179164]  r6:d4ad2000 r5:00000000 r4:00000050
    [  132.183829] [<c00da16c>] (__alloc_pages_nodemask) from [<c00daadc>] (__get_free_pages+0x18/0x34)
    [  132.192649]  r10:00000000 r9:d3ed179c r8:00000100 r7:00000ff0 r6:00000053 r5:00000000
    [  132.200551]  r4:000000ff
    [  132.203106] [<c00daac4>] (__get_free_pages) from [<c02c1a8c>] (sg_kmalloc+0x2c/0x30)
    [  132.210887] [<c02c1a60>] (sg_kmalloc) from [<c02c19a4>] (__sg_alloc_table+0xf8/0x134)
    [  132.218752] [<c02c18ac>] (__sg_alloc_table) from [<c02c2134>] (sg_alloc_table+0x30/0xb4)
    [  132.226874]  r10:d3ed179c r9:00000152 r8:ffffe000 r7:00000000 r6:dbdb8600 r5:b2444000
    [  132.234775]  r4:d3ed179c
    [  132.237330] [<c02c2104>] (sg_alloc_table) from [<c0414290>] (vmem_export_single+0x1cc/0x648)
    [  132.245801]  r7:00000000 r6:dbdb8600 r5:b2444000 r4:d4ad3eec
    [  132.251517] [<c04140c4>] (vmem_export_single) from [<c04147d8>] (vmemexp_ioctl+0xcc/0x134)
    [  132.259814]  r10:00000000 r9:d4ad2000 r8:a82c8d34 r7:00000051 r6:dbdb8600 r5:ffffe000
    [  132.267715]  r4:a82c8d34
    [  132.270269] [<c041470c>] (vmemexp_ioctl) from [<c013158c>] (do_vfs_ioctl+0x460/0x6dc)
    [  132.278130]  r7:00000005 r6:dbf50240 r5:dc1518a8 r4:a82c8d34
    [  132.283845] [<c013112c>] (do_vfs_ioctl) from [<c0131844>] (SyS_ioctl+0x3c/0x64)
    [  132.291182]  r10:00000000 r9:d4ad2000 r8:a82c8d34 r7:c00cdbd0 r6:dbf50240 r5:00000005
    [  132.299084]  r4:dbf50241
    [  132.301638] [<c0131808>] (SyS_ioctl) from [<c000fc60>] (ret_fast_syscall+0x0/0x3c)
    [  132.309236]  r9:d4ad2000 r8:c000fe24 r7:00000036 r6:000f9cdc r5:00151800 r4:b2444800
    [  132.317245] Mem-Info:
    [  132.319548] active_anon:8261 inactive_anon:4579 isolated_anon:0
    [  132.319548]  active_file:11689 inactive_file:11224 isolated_file:0
    [  132.319548]  unevictable:0 dirty:78 writeback:0 unstable:0
    [  132.319548]  slab_reclaimable:1739 slab_unreclaimable:2676
    [  132.319548]  mapped:19043 shmem:4927 pagetables:289 bounce:0
    [  132.319548]  free:8909 free_pcp:105 free_cma:8208
    [  132.353113] Normal free:35660kB min:1780kB low:2224kB high:2668kB active_anon:33016kB inactive_anon:18316kB active_file:46756kB inactive_file:44900kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:501760kB managed:305172kB mlocked:0kB dirty:328kB writeback:0kB mapped:76240kB shmem:19708kB slab_reclaimable:6952kB slab_unreclaimable:10704kB kernel_stack:1296kB pagetables:1132kB unstable:0kB bounce:0kB free_pcp:420kB local_pcp:112kB free_cma:32832kB writeback_tmp:0kB pages_scanned:4 all_unreclaimable? no
    [  132.399040] lowmem_reserve[]: 0 0 0
    [  132.402609] Normal: 89*4kB (M) 68*8kB (UMEC) 39*16kB (ME) 14*32kB (UMEC) 14*64kB (UME) 6*128kB (C) 1*256kB (C) 4*512kB (C) 3*1024kB (C) 3*2048kB (C) 5*4096kB (C) = 35636kB
    [  132.418217] 27833 total pagecache pages
    [  132.422067] 0 pages in swap cache
    [  132.425418] Swap cache stats: add 0, delete 0, find 0/0
    [  132.430664] Free swap  = 0kB
    [  132.433567] Total swap = 0kB
    [  132.436455] 125440 pages RAM
    [  132.439342] 0 pages HighMem/MovableOnly
    [  132.443211] 49147 pages reserved
    [  132.446449] 26624 pages cma reserved
    [  132.450035] Failed to allocated sgt for 338 pages
    [  132.454774] vmemexp vmemexp: sg_alloc_from_vaddr failed
    [  132.460023] vmemexp vmemexp: vmem b2444000 export failed

  • Hi:

      Finally, we found the System_exportDmaBuf() in ipcInLink_drv.c(line 418) rise this issue.

  • fully log of allocate page fail.log
    root@dra7xx-evm:~# dmesg 
    [    0.000000] Booting Linux on physical CPU 0x0
    [    0.000000] Initializing cgroup subsys cpuset
    [    0.000000] Initializing cgroup subsys cpu
    [    0.000000] Initializing cgroup subsys cpuacct
    [    0.000000] Linux version 4.4.84 (chengangyi@ecarx-5288-V3) (gcc version 5.3.1 20160113 (Linaro GCC 5.3-2016.02) ) #31 SMP PREEMPT Mon Jan 7 11:35:57 CST 2019
    [    0.000000] CPU: ARMv7 Processor [412fc0f2] revision 2 (ARMv7), cr=10c5387d
    [    0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache
    [    0.000000] Machine model: TI DRA762 EVM
    [    0.000000] Reserved memory: created DMA memory pool at 0x40300000, size 3 MiB
    [    0.000000] Reserved memory: initialized node cmem@40300000, compatible id shared-dma-pool
    [    0.000000] Reserved memory: regions without no-map are not yet supported
    [    0.000000] Reserved memory: regions without no-map are not yet supported
    [    0.000000] Reserved memory: created CMA memory pool at 0x96000000, size 32 MiB
    [    0.000000] Reserved memory: initialized node ipu2_cma@96000000, compatible id shared-dma-pool
    [    0.000000] Reserved memory: created CMA memory pool at 0x98000000, size 16 MiB
    [    0.000000] Reserved memory: initialized node dsp1_cma@98000000, compatible id shared-dma-pool
    [    0.000000] Reserved memory: created CMA memory pool at 0x99000000, size 16 MiB
    [    0.000000] Reserved memory: initialized node dsp2_cma@99000000, compatible id shared-dma-pool
    [    0.000000] Reserved memory: created CMA memory pool at 0x9a000000, size 16 MiB
    [    0.000000] Reserved memory: initialized node ipu1_cma@9a000000, compatible id shared-dma-pool
    [    0.000000] Reserved memory: created DMA memory pool at 0x9db00000, size 32 MiB
    [    0.000000] Reserved memory: initialized node cmem@9db00000, compatible id shared-dma-pool
    [    0.000000] Reserved memory: regions without no-map are not yet supported
    [    0.000000] cma: Reserved 12 MiB at 0x9cc00000
    [    0.000000] Memory policy: Data cache writealloc
    [    0.000000] OMAP4: Map 0x9fe00000 to fe600000 for dram barrier
    [    0.000000] On node 0 totalpages: 121344
    [    0.000000] free_area_init_node: node 0, pgdat c0981780, node_mem_map dc780000
    [    0.000000]   Normal zone: 1152 pages used for memmap
    [    0.000000]   Normal zone: 0 pages reserved
    [    0.000000]   Normal zone: 121344 pages, LIFO batch:31
    [    0.000000] DRA762 ES1.0
    [    0.000000] PERCPU: Embedded 11 pages/cpu @dda4f000 s14912 r8192 d21952 u45056
    [    0.000000] pcpu-alloc: s14912 r8192 d21952 u45056 alloc=11*4096
    [    0.000000] pcpu-alloc: [0] 0 [0] 1 
    [    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 120192
    [    0.000000] Kernel command line: console=ttyS9,115200n8 vram=16M root=PARTUUID=a80e22b0-02 rw rootwait ip=none mem=512M
    [    0.000000] PID hash table entries: 2048 (order: 1, 8192 bytes)
    [    0.000000] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
    [    0.000000] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
    [    0.000000] Memory: 194380K/485376K available (6663K kernel code, 319K rwdata, 2392K rodata, 332K init, 286K bss, 196788K reserved, 94208K cma-reserved, 0K highmem)
    [    0.000000] Virtual kernel memory layout:
    [    0.000000]     vector  : 0xffff0000 - 0xffff1000   (   4 kB)
    [    0.000000]     fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
    [    0.000000]     vmalloc : 0xe0800000 - 0xff800000   ( 496 MB)
    [    0.000000]     lowmem  : 0xc0000000 - 0xe0000000   ( 512 MB)
    [    0.000000]     pkmap   : 0xbfe00000 - 0xc0000000   (   2 MB)
    [    0.000000]     modules : 0xbf000000 - 0xbfe00000   (  14 MB)
    [    0.000000]       .text : 0xc0008000 - 0xc08e000c   (9057 kB)
    [    0.000000]       .init : 0xc08e1000 - 0xc0934000   ( 332 kB)
    [    0.000000]       .data : 0xc0934000 - 0xc0983e20   ( 320 kB)
    [    0.000000]        .bss : 0xc0985000 - 0xc09cc980   ( 287 kB)
    [    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1
    [    0.000000] Preemptible hierarchical RCU implementation.
    [    0.000000]  Build-time adjustment of leaf fanout to 32.
    [    0.000000] NR_IRQS:16 nr_irqs:16 16
    [    0.000000] ti_dt_clocks_register: failed to lookup clock node gmac_gmii_ref_clk_div
    [    0.000000] OMAP clockevent source: timer1 at 32786 Hz
    [    0.000000] Architected cp15 timer(s) running at 6.14MHz (phys).
    [    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x16af5adb9, max_idle_ns: 440795202250 ns
    [    0.000004] sched_clock: 56 bits at 6MHz, resolution 162ns, wraps every 4398046511023ns
    [    0.000015] Switching to timer-based delay loop, resolution 162ns
    [    0.000331] clocksource: 32k_counter: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 58327039986419 ns
    [    0.000339] OMAP clocksource: 32k_counter at 32768 Hz
    [    0.000801] Console: colour dummy device 80x30
    [    0.000820] Calibrating delay loop (skipped), value calculated using timer frequency.. 12.29 BogoMIPS (lpj=61475)
    [    0.000833] pid_max: default: 32768 minimum: 301
    [    0.000929] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
    [    0.000939] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
    [    0.001477] Initializing cgroup subsys io
    [    0.001494] Initializing cgroup subsys memory
    [    0.001518] Initializing cgroup subsys devices
    [    0.001532] Initializing cgroup subsys freezer
    [    0.001543] Initializing cgroup subsys perf_event
    [    0.001555] Initializing cgroup subsys pids
    [    0.001580] CPU: Testing write buffer coherency: ok
    [    0.001782] /cpus/cpu@0 missing clock-frequency property
    [    0.001798] /cpus/cpu@1 missing clock-frequency property
    [    0.001808] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
    [    0.001850] Setting up static identity map for 0x80008340 - 0x800083a0
    [    0.080088] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
    [    0.080155] Brought up 2 CPUs
    [    0.080168] SMP: Total of 2 processors activated (24.59 BogoMIPS).
    [    0.080174] CPU: All CPU(s) started in HYP mode.
    [    0.080180] CPU: Virtualization extensions available.
    [    0.081220] devtmpfs: initialized
    [    0.110836] VFP support v0.3: implementor 41 architecture 4 part 30 variant f rev 0
    [    0.111803] omap_hwmod: l3_main_2 using broken dt data from ocp
    [    0.229345] omap_hwmod: dcan1: _wait_target_disable failed
    [    0.326287] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
    [    0.326311] futex hash table entries: 512 (order: 3, 32768 bytes)
    [    0.328219] pinctrl core: initialized pinctrl subsystem
    [    0.329062] NET: Registered protocol family 16
    [    0.330030] DMA: preallocated 256 KiB pool for atomic coherent allocations
    [    0.360210] cpuidle: using governor ladder
    [    0.390236] cpuidle: using governor menu
    [    0.398822] OMAP GPIO hardware version 0.1
    [    0.402980] GPIO line 161 (radio_rst) hogged as output/low
    [    0.405384] irq: no irq domain found for /ocp/l4@4a000000/scm@2000/pinmux@1400 !
    [    0.430195] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
    [    0.430206] hw-breakpoint: maximum watchpoint size is 8 bytes.
    [    0.430717] omap4_sram_init:Unable to allocate sram needed to handle errata I688
    [    0.430727] omap4_sram_init:Unable to get sram pool needed to handle errata I688
    [    0.431202] OMAP DMA hardware revision 0.0
    [    0.471481] omap-dma-engine 4a056000.dma-controller: OMAP DMA engine driver (LinkedList1/2/3 supported)
    [    0.472646] edma 43300000.edma: memcpy is disabled
    [    0.477451] edma 43300000.edma: TI EDMA DMA engine driver
    [    0.482362] omap-iommu 40d01000.mmu: 40d01000.mmu registered
    [    0.482537] omap-iommu 40d02000.mmu: 40d02000.mmu registered
    [    0.482707] omap-iommu 58882000.mmu: 58882000.mmu registered
    [    0.482862] omap-iommu 55082000.mmu: 55082000.mmu registered
    [    0.483139] omap-iommu 41501000.mmu: 41501000.mmu registered
    [    0.483328] omap-iommu 41502000.mmu: 41502000.mmu registered
    [    0.486366] palmas 0-0058: IRQ missing: skipping irq request
    [    0.500673] palmas 0-0058: Muxing GPIO 51, PWM 0, LED 2
    [    0.551201] irq: no irq domain found for /ocp/i2c@48070000/tps65917@58 !
    [    0.551745] pcf857x: probe of 0-0020 failed with error -121
    [    0.551997] pcf857x: probe of 0-0021 failed with error -121
    [    0.552225] pcf857x: probe of 0-0026 failed with error -121
    [    0.552384] omap_i2c 48070000.i2c: bus 0 rev0.12 at 400 kHz
    [    0.552795] omap_i2c 48060000.i2c: bus 2 rev0.12 at 400 kHz
    [    0.570535] pcf857x: probe of 3-0021 failed with error -121
    [    0.570573] omap_i2c 4807a000.i2c: bus 3 rev0.12 at 400 kHz
    [    0.570773] media: Linux media interface: v0.10
    [    0.570822] Linux video capture interface: v2.00
    [    0.570859] pps_core: LinuxPPS API ver. 1 registered
    [    0.570866] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
    [    0.570889] PTP clock support registered
    [    0.570932] EDAC MC: Ver: 3.0.0
    [    0.571690] omap-mailbox 48840000.mailbox: omap mailbox rev 0x400
    [    0.571987] omap-mailbox 48842000.mailbox: omap mailbox rev 0x400
    [    0.572335] Advanced Linux Sound Architecture Driver Initialized.
    [    0.573177] clocksource: Switched to clocksource arch_sys_counter
    [    0.583489] NET: Registered protocol family 2
    [    0.583980] TCP established hash table entries: 4096 (order: 2, 16384 bytes)
    [    0.584020] TCP bind hash table entries: 4096 (order: 3, 32768 bytes)
    [    0.584087] TCP: Hash tables configured (established 4096 bind 4096)
    [    0.584127] UDP hash table entries: 256 (order: 1, 8192 bytes)
    [    0.584148] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes)
    [    0.584335] NET: Registered protocol family 1
    [    0.584596] RPC: Registered named UNIX socket transport module.
    [    0.584605] RPC: Registered udp transport module.
    [    0.584612] RPC: Registered tcp transport module.
    [    0.584618] RPC: Registered tcp NFSv4.1 backchannel transport module.
    [    0.584633] PCI: CLS 0 bytes, default 64
    [    0.585605] hw perfevents: enabled with armv7_cortex_a15 PMU driver, 7 counters available
    [    0.594483] squashfs: version 4.0 (2009/01/31) Phillip Lougher
    [    0.595120] NFS: Registering the id_resolver key type
    [    0.595148] Key type id_resolver registered
    [    0.595156] Key type id_legacy registered
    [    0.595224] ntfs: driver 2.1.32 [Flags: R/O].
    [    0.596628] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247)
    [    0.596642] io scheduler noop registered
    [    0.596653] io scheduler deadline registered
    [    0.596684] io scheduler cfq registered (default)
    [    0.599058] vsys_5v0: supplied by vsys_12v0
    [    0.599106] ldo3: supplied by vsys_5v0
    [    0.602781] pinctrl-single 4a003400.pinmux: 282 pins at pa fc003400 size 1128
    [    0.606106] PCI host bridge /ocp/axi@0/pcie_rc@51000000 ranges:
    [    0.606119]   No bus range found for /ocp/axi@0/pcie_rc@51000000, using [bus 00-ff]
    [    0.606152]    IO 0x20003000..0x20012fff -> 0x00000000
    [    0.606173]   MEM 0x20013000..0x2fffffff -> 0x20013000
    [    0.636151] dra7-pcie 51000000.pcie_rc: link is not up
    [    0.636316] dra7-pcie 51000000.pcie_rc: PCI host bridge to bus 0000:00
    [    0.636329] pci_bus 0000:00: root bus resource [bus 00-ff]
    [    0.636339] pci_bus 0000:00: root bus resource [io  0x0000-0xffff]
    [    0.636349] pci_bus 0000:00: root bus resource [mem 0x20013000-0x2fffffff]
    [    0.636382] pci 0000:00:00.0: [104c:8888] type 01 class 0x060400
    [    0.636425] pci 0000:00:00.0: reg 0x10: [mem 0x00000000-0x000fffff]
    [    0.636447] pci 0000:00:00.0: reg 0x14: [mem 0x00000000-0x0000ffff]
    [    0.636514] pci 0000:00:00.0: supports D1
    [    0.636524] pci 0000:00:00.0: PME# supported from D0 D1 D3hot
    [    0.636755] PCI: bus0: Fast back to back transfers disabled
    [    0.636873] PCI: bus1: Fast back to back transfers enabled
    [    0.636953] pci 0000:00:00.0: BAR 0: assigned [mem 0x20100000-0x201fffff]
    [    0.636967] pci 0000:00:00.0: BAR 1: assigned [mem 0x20020000-0x2002ffff]
    [    0.636980] pci 0000:00:00.0: PCI bridge to [bus 01]
    [    0.637206] pcieport 0000:00:00.0: Signaling PME through PCIe PME interrupt
    [    0.637219] pcie_pme 0000:00:00.0:pcie01: service driver pcie_pme loaded
    [    0.637344] aer 0000:00:00.0:pcie02: service driver aer loaded
    [    0.697791] Serial: 8250/16550 driver, 10 ports, IRQ sharing disabled
    [    0.701164] 4806a000.serial: ttyS0 at MMIO 0x4806a000 (irq = 301, base_baud = 3000000) is a 8250
    [    0.702035] 4806c000.serial: ttyS1 at MMIO 0x4806c000 (irq = 302, base_baud = 3000000) is a 8250
    [    0.702873] 48020000.serial: ttyS2 at MMIO 0x48020000 (irq = 303, base_baud = 3000000) is a 8250
    [    0.703708] console [ttyS9] disabled
    [    0.703757] 4ae2b000.serial: ttyS9 at MMIO 0x4ae2b000 (irq = 304, base_baud = 3000000) is a 8250
    [    1.745452] console [ttyS9] enabled
    [    1.750155] [drm] Initialized drm 1.1.0 20060810
    [    1.755681] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
    [    1.762325] [drm] No driver support for vblank timestamp query.
    [    1.768487] [drm] Initialized vdrm 1.0.0 20110917 on minor 0
    [    1.781469] loop: module loaded
    [    1.787394] vmemexp device MAJOR num = 245
    [    1.791522] vmemexp class registered
    [    1.795260] /dev/vmemexp device registered
    [    1.799374] ioctl DBUFIOC_EXPORT_VIRTMEM = -1072899120
    [    1.807661] m25p80 spi32766.0: unrecognized JEDEC id bytes: 00,  0,  0
    [    1.815371] libphy: Fixed MDIO Bus: probed
    [    1.863212] davinci_mdio 48485000.mdio: davinci mdio revision 1.6
    [    1.869336] libphy: 48485000.mdio: probed
    [    1.876414] davinci_mdio 48485000.mdio: phy[1]: device 48485000.mdio:01, driver RTL9000A Gigabit Ethernet
    [    1.886692] cpsw 48484000.ethernet: Detected MACID = f8:36:9b:86:3f:e0
    [    1.893382] cpsw 48484000.ethernet: cpts: overflow check period 800
    [    1.900326] cpsw 48484000.ethernet: cpsw: Detected MACID = f8:36:9b:86:3f:e1
    [    1.908994] mousedev: PS/2 mouse device common for all mice
    [    1.915235] i2c /dev entries driver
    [    1.924007] omap_hsmmc 4809c000.mmc: Got CD GPIO
    [    1.928839] omap_hsmmc 4809c000.mmc: no pinctrl state for sdr104 mode
    [    1.935360] omap_hsmmc 4809c000.mmc: no pinctrl state for ddr50 mode
    [    1.941744] omap_hsmmc 4809c000.mmc: no pinctrl state for sdr50 mode
    [    1.948142] omap_hsmmc 4809c000.mmc: no pinctrl state for sdr25 mode
    [    1.954537] omap_hsmmc 4809c000.mmc: no pinctrl state for sdr12 mode
    [    1.961171] vsys_3v3: supplied by vsys_12v0
    [    1.965438] vio_3v3: supplied by vsys_3v3
    [    1.969496] vio_3v3_sd: supplied by vio_3v3
    [    1.974331] ldo4: supplied by vsys_5v0
    [    2.023629] omap_hsmmc 480b4000.mmc: no pinctrl state for sdr25 mode
    [    2.030014] omap_hsmmc 480b4000.mmc: no pinctrl state for sdr12 mode
    [    2.046769] smps5: supplied by vsys_3v3
    [    2.050839] vio_1v8: supplied by smps5
    [    2.094054] ledtrig-cpu: registered to indicate activity on CPUs
    [    2.105189] hwspinlock_user gatemp: requested 20 hwspinlocks
    [    2.112099] aic_dvdd: supplied by vio_3v3
    [    2.117391] davinci-mcasp 48464000.mcasp: DAI is shared
    [    2.123491] davinci-mcasp 48474000.mcasp: DAI is shared
    [    2.129977] NET: Registered protocol family 10
    [    2.145303] sit: IPv6 over IPv4 tunneling driver
    [    2.150492] NET: Registered protocol family 17
    [    2.155220] Key type dns_resolver registered
    [    2.159621] omap_voltage_late_init: Voltage driver support not added
    [    2.166511] Adding alias for supply vdd,cpu0 -> vdd,4a003b20.oppdm
    [    2.172719] Adding alias for supply vbb,cpu0 -> vbb,4a003b20.oppdm
    [    2.179014] buck10: supplied by vsys_3v3
    [    2.183572] Adding alias for supply vdd,cpu0 -> vdd,4a003b20.oppdm
    [    2.189780] Adding alias for supply vbb,cpu0 -> vbb,4a003b20.oppdm
    [    2.197960] Power Management for TI OMAP4+ devices.
    [    2.202998] Registering SWP/SWPB emulation handler
    [    2.208603] dmm 4e000000.dmm: workaround for errata i878 in use
    [    2.215647] dmm 4e000000.dmm: initialized all PAT entries
    [    2.221652] [drm] Initialized omapdrm 1.0.0 20110917 on minor 1
    [    2.238851] asoc-simple-card sound0: tlv320aic3x-hifi <-> 48468000.mcasp mapping ok
    [    2.258287] hctosys: unable to open rtc device (rtc0)
    [    2.260520] mmc0: host does not support reading read-only switch, assuming write-enable
    [    2.262569] mmc0: new high speed SDHC card at address 59b4
    [    2.272918] mmcblk0: mmc0:59b4 USD00 7.33 GiB 
    [    2.277666]  mmcblk0: p1 p2
    [    2.291170] aic_dvdd: disabling
    [    2.294489] ALSA device list:
    [    2.297465]   #0: DRA7xx-EVM
    [    2.301710] EXT4-fs (mmcblk0p2): couldn't mount as ext3 due to feature incompatibilities
    [    2.310368] EXT4-fs (mmcblk0p2): couldn't mount as ext2 due to feature incompatibilities
    [    2.326925] mmc1: MAN_BKOPS_EN bit is not set
    [    2.340010] mmc1: new HS200 MMC card at address 0001
    [    2.345262] mmcblk1: mmc1:0001 DG4008 7.28 GiB 
    [    2.360026] mmcblk1boot0: mmc1:0001 DG4008 partition 1 4.00 MiB
    [    2.376220] mmcblk1boot1: mmc1:0001 DG4008 partition 2 4.00 MiB
    [    2.382844]  mmcblk1: p1 p2
    [    2.787864] EXT4-fs (mmcblk0p2): recovery complete
    [    2.795799] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
    [    2.803968] VFS: Mounted root (ext4 filesystem) on device 179:2.
    [    2.812069] devtmpfs: mounted
    [    2.815243] Freeing unused kernel memory: 332K
    [    2.819704] This architecture does not have kernel memory protection.
    [    3.010399] systemd[1]: System time before build time, advancing clock.
    [    3.055585] random: systemd: uninitialized urandom read (16 bytes read, 18 bits of entropy available)
    [    3.067574] random: systemd: uninitialized urandom read (16 bytes read, 18 bits of entropy available)
    [    3.083966] systemd[1]: systemd 229 running in system mode. (+PAM -AUDIT -SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP -LIBCRYPTSETUP -GCRYPT +GNUTLS +ACL +XZ -LZ4 -SECCOMP +BLKID -ELFUTILS +KMOD -IDN)
    [    3.102458] systemd[1]: Detected architecture arm.
    [    3.124114] systemd[1]: Set hostname to <dra7xx-evm>.
    [    3.209238] random: systemd-gpt-aut: uninitialized urandom read (16 bytes read, 19 bits of entropy available)
    [    3.219434] random: systemd-gpt-aut: uninitialized urandom read (16 bytes read, 19 bits of entropy available)
    [    3.235909] random: systemd-sysv-ge: uninitialized urandom read (16 bytes read, 19 bits of entropy available)
    [    3.254411] random: systemd-sysv-ge: uninitialized urandom read (16 bytes read, 21 bits of entropy available)
    [    3.267113] random: systemd-sysv-ge: uninitialized urandom read (16 bytes read, 21 bits of entropy available)
    [    3.351723] random: systemd: uninitialized urandom read (16 bytes read, 23 bits of entropy available)
    [    3.361302] random: systemd: uninitialized urandom read (16 bytes read, 23 bits of entropy available)
    [    3.371419] random: systemd: uninitialized urandom read (16 bytes read, 23 bits of entropy available)
    [    3.775433] systemd[1]: sysinit.target: Found ordering cycle on sysinit.target/start
    [    3.783241] systemd[1]: sysinit.target: Found dependency on alignment.service/start
    [    3.790938] systemd[1]: sysinit.target: Found dependency on basic.target/start
    [    3.798222] systemd[1]: sysinit.target: Found dependency on sysinit.target/start
    [    3.805670] systemd[1]: sysinit.target: Breaking ordering cycle by deleting job alignment.service/start
    [    3.815142] systemd[1]: alignment.service: Job alignment.service/start deleted to break ordering cycle starting with sysinit.target/start
    [    3.855159] systemd[1]: Reached target Remote File Systems.
    [    3.873430] systemd[1]: Listening on Journal Socket.
    [    3.893295] systemd[1]: Reached target Swap.
    [    3.913537] systemd[1]: Listening on Network Service Netlink Socket.
    [    3.943396] systemd[1]: Listening on /dev/initctl Compatibility Named Pipe.
    [    3.986479] systemd[1]: Created slice System Slice.
    [    4.033564] systemd[1]: Starting Create list of required static device nodes for the current kernel...
    [    4.064061] systemd[1]: Created slice system-getty.slice.
    [    4.083383] systemd[1]: Listening on Syslog Socket.
    [    4.103385] systemd[1]: Listening on Journal Socket (/dev/log).
    [    4.163334] systemd[1]: Mounting Debug File System...
    [    4.186086] systemd[1]: Mounting Temporary Directory...
    [    4.203404] systemd[1]: Listening on udev Kernel Socket.
    [    4.253367] systemd[1]: Mounting POSIX Message Queue File System...
    [    4.277469] systemd[1]: Starting Load Kernel Modules...
    [    4.303521] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
    [    4.363510] systemd[1]: Starting Remount Root and Kernel File Systems...
    [    4.379045] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
    [    4.386940] systemd[1]: Starting Journal Service...
    [    4.403463] systemd[1]: Listening on udev Control Socket.
    [    4.453537] systemd[1]: Starting Setup Virtual Console...
    [    4.474124] systemd[1]: Created slice system-serial\x2dgetty.slice.
    [    4.493550] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
    [    4.523343] systemd[1]: Reached target Paths.
    [    4.543906] systemd[1]: Created slice User and Session Slice.
    [    4.563305] systemd[1]: Reached target Slices.
    [    4.618096] systemd[1]: Mounted Debug File System.
    [    4.643398] systemd[1]: Mounted POSIX Message Queue File System.
    [    4.663321] systemd[1]: Mounted Temporary Directory.
    [    4.683499] systemd[1]: Started Journal Service.
    [    5.276385] systemd-journald[115]: Received request to flush runtime journal from PID 1
    [    5.660600] omap-rproc 58820000.ipu: assigned reserved memory node ipu1_cma@9a000000
    [    5.715767]  remoteproc0: 58820000.ipu is available
    [    5.720673]  remoteproc0: Note: remoteproc is still under development and considered experimental.
    [    5.734735]  remoteproc0: THE BINARY FORMAT IS NOT YET FINALIZED, and backward compatibility isn't yet guaranteed.
    [    5.753662] omap-rproc 55020000.ipu: assigned reserved memory node ipu2_cma@96000000
    [    5.764312]  remoteproc1: 55020000.ipu is available
    [    5.773043]  remoteproc1: Note: remoteproc is still under development and considered experimental.
    [    5.785879]  remoteproc1: THE BINARY FORMAT IS NOT YET FINALIZED, and backward compatibility isn't yet guaranteed.
    [    5.803651]  remoteproc0: registered virtio0 (type 7)
    [    5.812814] omap-rproc 40800000.dsp: assigned reserved memory node dsp1_cma@98000000
    [    5.828891]  remoteproc2: 40800000.dsp is available
    [    5.836630]  remoteproc2: Note: remoteproc is still under development and considered experimental.
    [    5.857187]  remoteproc2: THE BINARY FORMAT IS NOT YET FINALIZED, and backward compatibility isn't yet guaranteed.
    [    5.877406] omap-rproc 41000000.dsp: assigned reserved memory node dsp2_cma@99000000
    [    5.889989]  remoteproc3: 41000000.dsp is available
    [    5.897391]  remoteproc3: Note: remoteproc is still under development and considered experimental.
    [    5.910792]  remoteproc3: THE BINARY FORMAT IS NOT YET FINALIZED, and backward compatibility isn't yet guaranteed.
    [    6.136789] omap_rng 48090000.rng: OMAP Random Number Generator ver. 20
    [    6.355729] omap-sham 4b101000.sham: hw accel on OMAP rev 4.3
    [    6.410927] omap-des 480a5000.des: OMAP DES hw accel rev: 2.2
    [    6.555002]  remoteproc3: registered virtio1 (type 7)
    [    6.721087]  remoteproc2: registered virtio2 (type 7)
    [    6.771074] omap-aes 4b500000.aes: OMAP AES hw accel rev: 3.3
    [    6.777390] omap-aes 4b700000.aes: OMAP AES hw accel rev: 3.3
    [    6.991521] SCSI subsystem initialized
    [    7.432030] [drm] Initialized pvr 1.14.3699939 20110701 on minor 2
    [    7.514659]  remoteproc1: registered virtio3 (type 7)
    [    7.524705] libata version 3.00 loaded.
    [    7.588133] ahci 4a140000.sata: SSS flag set, parallel bus scan disabled
    [    7.619413] ahci 4a140000.sata: AHCI 0001.0300 32 slots 1 ports 3 Gbps 0x1 impl platform mode
    [    7.645047] ahci 4a140000.sata: flags: 64bit ncq sntf stag pm led clo only pmp pio slum part ccc apst 
    [    7.704672] scsi host0: ahci
    [    7.708258] ata1: SATA max UDMA/133 mmio [mem 0x4a140000-0x4a1410ff] port 0x100 irq 342
    [    7.816330] PVR_K: UM DDK-(3699939) and KM DDK-(3699939) match. [ OK ]
    [    8.074782] ata1: SATA link down (SStatus 0 SControl 300)
    [    8.107352] net eth1: initializing cpsw version 1.15 (0)
    [    8.125429] net eth0: initialized cpsw ale version 1.4
    [    8.136129] EXT4-fs (mmcblk1p2): mounting ext2 file system using the ext4 subsystem
    [    8.154276] net eth0: ALE Table size 1024
    [    8.171019] libphy: PHY 48485000.mdio:03 not found
    [    8.180918] EXT4-fs (mmcblk1p2): warning: mounting unchecked fs, running e2fsck is recommended
    [    8.186601] net eth1: phy "48485000.mdio:03" not found on slave 1, err -19
    [    8.211719] IPv6: ADDRCONF(NETDEV_UP): eth1: link is not ready
    [    8.221063] EXT4-fs (mmcblk1p2): mounted filesystem without journal. Opts: (null)
    [    8.238189] FAT-fs (mmcblk1p1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
    [    8.254823] net eth0: initializing cpsw version 1.15 (0)
    [    8.266478] FAT-fs (mmcblk0p1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
    [    8.436204] net eth0: phy found : id is : 0x1ccb00
    [    8.470968] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
    [    8.584858]  remoteproc0: powering up 58820000.ipu
    [    8.590629]  remoteproc0: Booting fw image dra7-ipu1-fw.xem4, size 610048
    [    8.590695] omap-iommu 58882000.mmu: 58882000.mmu: version 2.1
    [    8.622100]  remoteproc0: remote processor 58820000.ipu is now up
    [    8.629280] virtio_rpmsg_bus virtio0: rpmsg host is online
    [    8.637808]  remoteproc3: powering up 41000000.dsp
    [    8.649686]  remoteproc3: Booting fw image dra7-dsp2-fw.xe66, size 5583987
    [    8.663838] omap_hwmod: mmu0_dsp2: _wait_target_disable failed
    [    8.669721] omap-iommu 41501000.mmu: 41501000.mmu: version 3.0
    [    8.675655] omap-iommu 41502000.mmu: 41502000.mmu: version 3.0
    [    8.726875]  remoteproc3: remote processor 41000000.dsp is now up
    [    8.743822] virtio_rpmsg_bus virtio1: rpmsg host is online
    [    8.750030]  remoteproc2: powering up 40800000.dsp
    [    8.769236]  remoteproc2: Booting fw image dra7-dsp1-fw.xe66, size 5583987
    [    8.799777] omap_hwmod: mmu0_dsp1: _wait_target_disable failed
    [    8.805657] omap-iommu 40d01000.mmu: 40d01000.mmu: version 3.0
    [    8.811569] omap-iommu 40d02000.mmu: 40d02000.mmu: version 3.0
    [    8.859372]  remoteproc2: remote processor 40800000.dsp is now up
    [    8.866298] virtio_rpmsg_bus virtio2: rpmsg host is online
    [    8.872489]  remoteproc1: powering up 55020000.ipu
    [    8.887278]  remoteproc1: Booting fw image dra7-ipu2-fw.xem4, size 9392404
    [    8.894276] omap-iommu 55082000.mmu: 55082000.mmu: version 2.1
    [    8.925660]  remoteproc1: remote processor 55020000.ipu is now up
    [    8.932982] virtio_rpmsg_bus virtio3: rpmsg host is online
    [    8.984410] virtio_rpmsg_bus virtio3: creating channel rpmsg-proto addr 0x50
    [    8.991616] virtio_rpmsg_bus virtio1: creating channel rpmsg-proto addr 0x50
    [    9.012735] NET: Registered protocol family 41
    [    9.017926] virtio_rpmsg_bus virtio2: creating channel rpmsg-proto addr 0x50
    [    9.043339] virtio_rpmsg_bus virtio0: creating channel rpmsg-proto addr 0x50
    [    9.405644] usbcore: registered new interface driver usbfs
    [    9.413350] usbcore: registered new interface driver hub
    [    9.420303] usbcore: registered new device driver usb
    [    9.505853] xhci-hcd xhci-hcd.2.auto: xHCI Host Controller
    [    9.512203] xhci-hcd xhci-hcd.2.auto: new USB bus registered, assigned bus number 1
    [    9.524529] xhci-hcd xhci-hcd.2.auto: hcc params 0x0220f04c hci version 0x100 quirks 0x00210010
    [    9.535498] xhci-hcd xhci-hcd.2.auto: irq 462, io mem 0x488d0000
    [    9.551819] hub 1-0:1.0: USB hub found
    [    9.558930] hub 1-0:1.0: 1 port detected
    [    9.569846] xhci-hcd xhci-hcd.2.auto: xHCI Host Controller
    [    9.578949] xhci-hcd xhci-hcd.2.auto: new USB bus registered, assigned bus number 2
    [    9.588812] usb usb2: We don't know the algorithms for LPM for this host, disabling LPM.
    [    9.599152] hub 2-0:1.0: USB hub found
    [    9.605008] hub 2-0:1.0: 1 port detected
    [    9.727962] DMA: Module install successful, device major num = 242 
    [    9.736126] DRV: Module install successful
    [   10.323021] vmemexp vmemexp: Initialized new context d3a11540
    [   10.339951] omap_l3_noc 44000000.ocp: L3 application error: target 3 mod:2 (unclearable)
    [   10.348132] omap_l3_noc 44000000.ocp: L3 debug error: target 3 mod:2 (unclearable)
    [   10.435587] cpsw 48484000.ethernet eth0: Link is Up - 100Mbps/Full - flow control off
    [   10.443513] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
    [   11.833535] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   11.833552] vmemexp vmemexp: vmem_export_single: Export request 1843200 bytes vmem at 0xb0052000
    [   11.833729] vmemexp vmemexp: vmem b0052000 of size 1843200 exported as dmafd 16
    [   11.834010] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   11.834022] vmemexp vmemexp: vmem_export_single: Export request 1843200 bytes vmem at 0xb0214000
    [   11.834193] vmemexp vmemexp: vmem b0214000 of size 1843200 exported as dmafd 17
    [   11.834467] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   11.834478] vmemexp vmemexp: vmem_export_single: Export request 1843200 bytes vmem at 0xb03d6000
    [   11.834648] vmemexp vmemexp: vmem b03d6000 of size 1843200 exported as dmafd 18
    [   11.834949] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   11.834960] vmemexp vmemexp: vmem_export_single: Export request 1843200 bytes vmem at 0xb0598000
    [   11.835178] vmemexp vmemexp: vmem b0598000 of size 1843200 exported as dmafd 19
    [   11.835455] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   11.835466] vmemexp vmemexp: vmem_export_single: Export request 1843200 bytes vmem at 0xb075a000
    [   11.835635] vmemexp vmemexp: vmem b075a000 of size 1843200 exported as dmafd 20
    [   11.835936] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   11.835947] vmemexp vmemexp: vmem_export_single: Export request 1843200 bytes vmem at 0xb091c000
    [   11.836116] vmemexp vmemexp: vmem b091c000 of size 1843200 exported as dmafd 21
    [   11.836398] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   11.836409] vmemexp vmemexp: vmem_export_single: Export request 1843200 bytes vmem at 0xb0ade000
    [   11.836580] vmemexp vmemexp: vmem b0ade000 of size 1843200 exported as dmafd 22
    [   11.837082] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   11.837093] vmemexp vmemexp: vmem_export_single: Export request 1843200 bytes vmem at 0xb0ca0000
    [   11.837262] vmemexp vmemexp: vmem b0ca0000 of size 1843200 exported as dmafd 23
    [   11.837556] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   11.837566] vmemexp vmemexp: vmem_export_single: Export request 1843200 bytes vmem at 0xb0e62000
    [   11.837736] vmemexp vmemexp: vmem b0e62000 of size 1843200 exported as dmafd 24
    [   11.838010] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   11.838020] vmemexp vmemexp: vmem_export_single: Export request 1843200 bytes vmem at 0xb1024000
    [   11.838188] vmemexp vmemexp: vmem b1024000 of size 1843200 exported as dmafd 25
    [   11.838461] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   11.838471] vmemexp vmemexp: vmem_export_single: Export request 1843200 bytes vmem at 0xb11e6000
    [   11.838640] vmemexp vmemexp: vmem b11e6000 of size 1843200 exported as dmafd 26
    [   11.838941] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   11.838952] vmemexp vmemexp: vmem_export_single: Export request 1843200 bytes vmem at 0xb13a8000
    [   11.839121] vmemexp vmemexp: vmem b13a8000 of size 1843200 exported as dmafd 27
    [   11.882403] vmemexp vmemexp: Initialized new context d38f0700
    [   11.882750] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   11.882763] vmemexp vmemexp: vmem_export_single: Export request 3686400 bytes vmem at 0xb156a000
    [   11.883090] vmemexp vmemexp: vmem b156a000 of size 3686400 exported as dmafd 33
    [   11.883163] vmemexp vmemexp: vmemexp_release
    [   11.883204] vmemexp vmemexp: vmemexp_release: Unref dmafd 33
    [   11.883214] vmemexp vmemexp: Closing context d38f0700
    [   11.883243] vmemexp vmemexp: Initialized new context d38f0700
    [   11.883548] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   11.883560] vmemexp vmemexp: vmem_export_single: Export request 3686400 bytes vmem at 0xb18ee000
    [   11.883911] vmemexp vmemexp: vmem b18ee000 of size 3686400 exported as dmafd 33
    [   11.883941] vmemexp vmemexp: vmemexp_release
    [   11.883951] vmemexp vmemexp: vmemexp_release: Unref dmafd 33
    [   11.883961] vmemexp vmemexp: Closing context d38f0700
    [   11.883986] vmemexp vmemexp: Initialized new context d38f0700
    [   11.884271] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   11.884282] vmemexp vmemexp: vmem_export_single: Export request 3686400 bytes vmem at 0xb1c72000
    [   11.884609] vmemexp vmemexp: vmem b1c72000 of size 3686400 exported as dmafd 33
    [   11.884636] vmemexp vmemexp: vmemexp_release
    [   11.884645] vmemexp vmemexp: vmemexp_release: Unref dmafd 33
    [   11.884655] vmemexp vmemexp: Closing context d38f0700
    [   11.884678] vmemexp vmemexp: Initialized new context d38f0700
    [   11.884984] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   11.884995] vmemexp vmemexp: vmem_export_single: Export request 3686400 bytes vmem at 0xb1ff6000
    [   11.885319] vmemexp vmemexp: vmem b1ff6000 of size 3686400 exported as dmafd 33
    [   11.885345] vmemexp vmemexp: vmemexp_release
    [   11.885354] vmemexp vmemexp: vmemexp_release: Unref dmafd 33
    [   11.885362] vmemexp vmemexp: Closing context d38f0700
    [   15.145416] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.145434] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xae739000
    [   15.145581] vmemexp vmemexp: vmem ae739000 of size 1382400 exported as dmafd 44
    [   15.155350] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.155370] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xaec81000
    [   15.155571] vmemexp vmemexp: vmem aec81000 of size 1382400 exported as dmafd 45
    [   15.155600] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.155612] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xaf1c9000
    [   15.155770] vmemexp vmemexp: vmem af1c9000 of size 1382400 exported as dmafd 46
    [   15.156742] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.156768] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xb237a000
    [   15.157119] vmemexp vmemexp: vmem b237a000 of size 1382400 exported as dmafd 47
    [   15.169335] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.169364] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xaf711000
    [   15.169454] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.169469] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xb24cb000
    [   15.169574] vmemexp vmemexp: vmem af711000 of size 1382400 exported as dmafd 48
    [   15.169657] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.169668] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xae739000
    [   15.169678] vmemexp vmemexp: find_exported_buf: Match found
    [   15.169688] vmemexp vmemexp: vmem_export_single: Buffer already exported at dmafd 44
    [   15.169692] vmemexp vmemexp: vmem b24cb000 of size 1382400 exported as dmafd 49
    [   15.169707] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.169713] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.169719] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xb261d000
    [   15.169727] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xaec81000
    [   15.169732] vmemexp vmemexp: find_exported_buf: Match found
    [   15.169738] vmemexp vmemexp: vmem_export_single: Buffer already exported at dmafd 45
    [   15.169744] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.169756] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xaf1c9000
    [   15.169764] vmemexp vmemexp: find_exported_buf: Match found
    [   15.169773] vmemexp vmemexp: vmem_export_single: Buffer already exported at dmafd 46
    [   15.169784] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.169793] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xaf711000
    [   15.169802] vmemexp vmemexp: find_exported_buf: Match found
    [   15.169810] vmemexp vmemexp: vmem_export_single: Buffer already exported at dmafd 48
    [   15.169894] vmemexp vmemexp: vmem b261d000 of size 1382400 exported as dmafd 50
    [   15.176374] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.176398] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xb276e000
    [   15.176436] apps2.out: page allocation failure: order:0, mode:0x0
    [   15.182596] CPU: 1 PID: 733 Comm: apps2.out Tainted: G           O    4.4.84 #31
    [   15.190034] Hardware name: Generic DRA74X (Flattened Device Tree)
    [   15.196157] Backtrace: 
    [   15.198647] [<c0013b1c>] (dump_backtrace) from [<c0013d18>] (show_stack+0x18/0x1c)
    [   15.206250]  r7:c0936664 r6:60070013 r5:00000000 r4:c0953590
    [   15.211988] [<c0013d00>] (show_stack) from [<c02b39a8>] (dump_stack+0x8c/0xa0)
    [   15.219247] [<c02b391c>] (dump_stack) from [<c00d77c8>] (warn_alloc_failed+0xe4/0x124)
    [   15.227197]  r7:c0936664 r6:00000000 r5:00000000 r4:00000000
    [   15.232926] [<c00d76e8>] (warn_alloc_failed) from [<c00da330>] (__alloc_pages_nodemask+0x1c4/0x958)
    [   15.242010]  r3:00000000 r2:00000000
    [   15.245618]  r6:db5ec000 r5:00000000 r4:00000050
    [   15.250288] [<c00da16c>] (__alloc_pages_nodemask) from [<c00daadc>] (__get_free_pages+0x18/0x34)
    [   15.259109]  r10:00000000 r9:d436a75c r8:00000100 r7:00000ff0 r6:00000053 r5:00000000
    [   15.267023]  r4:000000ff
    [   15.269583] [<c00daac4>] (__get_free_pages) from [<c02c1a8c>] (sg_kmalloc+0x2c/0x30)
    [   15.277363] [<c02c1a60>] (sg_kmalloc) from [<c02c19a4>] (__sg_alloc_table+0xf8/0x134)
    [   15.285232] [<c02c18ac>] (__sg_alloc_table) from [<c02c2134>] (sg_alloc_table+0x30/0xb4)
    [   15.293357]  r10:d436a75c r9:00000152 r8:ffffe000 r7:00000000 r6:d3a11540 r5:b276e000
    [   15.301268]  r4:d436a75c
    [   15.303825] [<c02c2104>] (sg_alloc_table) from [<c0414290>] (vmem_export_single+0x1cc/0x648)
    [   15.312297]  r7:00000000 r6:d3a11540 r5:b276e000 r4:db5edeec
    [   15.318024] [<c04140c4>] (vmem_export_single) from [<c04147d8>] (vmemexp_ioctl+0xcc/0x134)
    [   15.326322]  r10:00000000 r9:db5ec000 r8:a834fd34 r7:00000051 r6:d3a11540 r5:ffffe000
    [   15.334234]  r4:a834fd34
    [   15.336789] [<c041470c>] (vmemexp_ioctl) from [<c013158c>] (do_vfs_ioctl+0x460/0x6dc)
    [   15.344651]  r7:00000005 r6:db77c9c0 r5:db9518a8 r4:a834fd34
    [   15.350378] [<c013112c>] (do_vfs_ioctl) from [<c0131844>] (SyS_ioctl+0x3c/0x64)
    [   15.357717]  r10:00000000 r9:db5ec000 r8:a834fd34 r7:c00cdbd0 r6:db77c9c0 r5:00000005
    [   15.365627]  r4:db77c9c1
    [   15.368183] [<c0131808>] (SyS_ioctl) from [<c000fc60>] (ret_fast_syscall+0x0/0x3c)
    [   15.375783]  r9:db5ec000 r8:c000fe24 r7:00000036 r6:00130964 r5:00151800 r4:b276e800
    [   15.383735] Mem-Info:
    [   15.386045] active_anon:6335 inactive_anon:5254 isolated_anon:0
    [   15.386045]  active_file:11675 inactive_file:11698 isolated_file:32
    [   15.386045]  unevictable:0 dirty:129 writeback:0 unstable:0
    [   15.386045]  slab_reclaimable:1676 slab_unreclaimable:2640
    [   15.386045]  mapped:19056 shmem:5318 pagetables:248 bounce:0
    [   15.386045]  free:5799 free_pcp:97 free_cma:5299
    [   15.419682] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.419687] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xae88b000
    [   15.419718] Normal free:23196kB min:1760kB low:2200kB high:2640kB active_anon:25340kB inactive_anon:21016kB active_file:46700kB inactive_file:46792kB unevictable:0kB isolated(anon):0kB isolated(file):128kB present:485376kB managed:288920kB mlocked:0kB dirty:516kB writeback:0kB mapped:76224kB shmem:21272kB slab_reclaimable:6704kB slab_unreclaimable:10560kB kernel_stack:1256kB pagetables:992kB unstable:0kB bounce:0kB free_pcp:392kB local_pcp:300kB free_cma:21196kB writeback_tmp:0kB pages_scanned:256 all_unreclaimable? no
    [   15.419828] vmemexp vmemexp: vmem ae88b000 of size 1382400 exported as dmafd 51
    [   15.419835] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.419839] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xaedd3000
    [   15.419977] vmemexp vmemexp: vmem aedd3000 of size 1382400 exported as dmafd 52
    [   15.419983] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.419986] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xaf31b000
    [   15.420120] vmemexp vmemexp: vmem af31b000 of size 1382400 exported as dmafd 53
    [   15.420126] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.420130] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xaf863000
    [   15.420265] vmemexp vmemexp: vmem af863000 of size 1382400 exported as dmafd 54
    [   15.420288] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.420292] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xae9dd000
    [   15.420423] vmemexp vmemexp: vmem ae9dd000 of size 1382400 exported as dmafd 55
    [   15.420429] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.420433] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xaef25000
    [   15.420569] vmemexp vmemexp: vmem aef25000 of size 1382400 exported as dmafd 56
    [   15.420574] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.420578] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xaf46d000
    [   15.420744] vmemexp vmemexp: vmem af46d000 of size 1382400 exported as dmafd 57
    [   15.420749] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.420753] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xaf9b5000
    [   15.420886] vmemexp vmemexp: vmem af9b5000 of size 1382400 exported as dmafd 58
    [   15.420908] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.420911] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xaeb2f000
    [   15.421044] vmemexp vmemexp: vmem aeb2f000 of size 1382400 exported as dmafd 59
    [   15.421049] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.421053] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xaf077000
    [   15.421187] vmemexp vmemexp: vmem af077000 of size 1382400 exported as dmafd 60
    [   15.421192] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.421195] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xaf5bf000
    [   15.421330] vmemexp vmemexp: vmem af5bf000 of size 1382400 exported as dmafd 61
    [   15.421335] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.421339] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xafb07000
    [   15.421473] vmemexp vmemexp: vmem afb07000 of size 1382400 exported as dmafd 62
    [   15.421494] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.421498] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xae739000
    [   15.421501] vmemexp vmemexp: find_exported_buf: Match found
    [   15.421505] vmemexp vmemexp: vmem_export_single: Buffer already exported at dmafd 44
    [   15.421510] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.421514] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xaec81000
    [   15.421518] vmemexp vmemexp: find_exported_buf: Match found
    [   15.421522] vmemexp vmemexp: vmem_export_single: Buffer already exported at dmafd 45
    [   15.421527] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.421531] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xaf1c9000
    [   15.421534] vmemexp vmemexp: find_exported_buf: Match found
    [   15.421538] vmemexp vmemexp: vmem_export_single: Buffer already exported at dmafd 46
    [   15.421543] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.421547] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xaf711000
    [   15.421550] vmemexp vmemexp: find_exported_buf: Match found
    [   15.421554] vmemexp vmemexp: vmem_export_single: Buffer already exported at dmafd 48
    [   15.465925] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.465934] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xae88b000
    [   15.465938] vmemexp vmemexp: find_exported_buf: Match found
    [   15.465942] vmemexp vmemexp: vmem_export_single: Buffer already exported at dmafd 51
    [   15.465964] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.465970] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xaedd3000
    [   15.465975] vmemexp vmemexp: find_exported_buf: Match found
    [   15.465983] vmemexp vmemexp: vmem_export_single: Buffer already exported at dmafd 52
    [   15.466002] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.466006] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xaf31b000
    [   15.466009] vmemexp vmemexp: find_exported_buf: Match found
    [   15.466014] vmemexp vmemexp: vmem_export_single: Buffer already exported at dmafd 53
    [   15.466027] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.466032] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xaf863000
    [   15.466036] vmemexp vmemexp: find_exported_buf: Match found
    [   15.466040] vmemexp vmemexp: vmem_export_single: Buffer already exported at dmafd 54
    [   15.466054] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.466058] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xae9dd000
    [   15.466062] vmemexp vmemexp: find_exported_buf: Match found
    [   15.466066] vmemexp vmemexp: vmem_export_single: Buffer already exported at dmafd 55
    [   15.466079] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.466083] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xaef25000
    [   15.466088] vmemexp vmemexp: find_exported_buf: Match found
    [   15.466092] vmemexp vmemexp: vmem_export_single: Buffer already exported at dmafd 56
    [   15.466106] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.466110] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xaf46d000
    [   15.466114] vmemexp vmemexp: find_exported_buf: Match found
    [   15.466118] vmemexp vmemexp: vmem_export_single: Buffer already exported at dmafd 57
    [   15.466132] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.466136] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xaf9b5000
    [   15.466140] vmemexp vmemexp: find_exported_buf: Match found
    [   15.466144] vmemexp vmemexp: vmem_export_single: Buffer already exported at dmafd 58
    [   15.466157] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.466162] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xaeb2f000
    [   15.466166] vmemexp vmemexp: find_exported_buf: Match found
    [   15.466169] vmemexp vmemexp: vmem_export_single: Buffer already exported at dmafd 59
    [   15.466173] lowmem_reserve[]: 0
    [   15.466193] vmemexp vmemexp: vmemexp_ioctl cmd=c00cdbd0
    [   15.466196] vmemexp vmemexp: vmem_export_single: Export request 1382400 bytes vmem at 0xaf077000
    [   15.466201] vmemexp vmemexp: find_exported_buf: Match found
    [   15.466205] vmemexp vmemexp: vmem_export_single: Buffer already exported at dmafd 60
    [   15.469210]  0 0
    [   15.471545] Normal: 26*4kB (UMEHC) 29*8kB (UMEH) 26*16kB (UMEH) 18*32kB (UMHC) 17*64kB (UMC) 9*128kB (UMC) 0*256kB 5*512kB (C) 3*1024kB (C) 3*2048kB (C) 2*4096kB (C) = 23536kB
    [   15.487509] 28688 total pagecache pages
    [   15.491362] 0 pages in swap cache
    [   15.494700] Swap cache stats: add 0, delete 0, find 0/0
    [   15.499958] Free swap  = 0kB
    [   15.502854] Total swap = 0kB
    [   15.505763] 121344 pages RAM
    [   15.508657] 0 pages HighMem/MovableOnly
    [   15.512509] 49114 pages reserved
    [   15.515759] 23552 pages cma reserved
    [   15.519350] Failed to allocated sgt for 338 pages
    [   15.524088] vmemexp vmemexp: sg_alloc_from_vaddr failed
    [   15.529366] vmemexp vmemexp: vmem b276e000 export failed
    root@dra7xx-evm:~# 
    root@dra7xx-evm:~# free
                 total       used       free     shared    buffers     cached
    Mem:        288920     260916      28004      21260       5004     103904
    -/+ buffers/cache:     152008     136912
    Swap:            0          0          0
    

  • Hi:

      finally, we found the __get_free_page() return NULL, but we actually have enough memory, please have look at the trace in attachment.exportfailed-1.log

  • Hi,

    The kmalloc is actually allocating memory from lowmem.

    What is your memory reservations in the kernel?

    From the log, I could infer that you are using 512MB lowmem and 496 for vmalloc.

    Note that all the reserved-mem entries will take up memory from the lowmem section and eventually kernel might run out of the lowmem.

    You can increase the lowmem by adding a commandline parameter as

    vmalloc=256M

    This will increase the lowmem and remove any failures due to scarcity of lowmem in kernel.

    Also, it would be useful if you can track down how much memory is getting requested to be allocated?

    That will help us understad the failure. Kmalloc tries to allocate contiguous memory, so bigger allocations are likely to fail.

    Regards,

    Nikhil D

  • Hello Nikhil D:

    Nikhil Devshatwar said:
    What is your memory reservations in the kernel?

      you mean the configuration in xxxx.xs file? it's 64 M.

    Nikhil Devshatwar said:
    You can increase the lowmem by adding a commandline parameter as

      For now, it's 16M

    Nikhil Devshatwar said:

    Also, it would be useful if you can track down how much memory is getting requested to be allocated?

     in ti_components/os_tools/linux/kernel/omap/lib/scatterlist.c

    static struct scatterlist *sg_kmalloc(unsigned int nents, gfp_t gfp_mask)
    {
            if (nents == SG_MAX_SINGLE_ALLOC) {
                    /*
                     * Kmemleak doesn't track page allocations as they are not
                     * commonly used (in a raw form) for kernel data structures.
                     * As we chain together a list of pages and then a normal
                     * kmalloc (tracked by kmemleak), in order to for that last
                     * allocation not to become decoupled (and thus a
                     * false-positive) we need to inform kmemleak of all the
                     * intermediate allocations.
                     */
                    void *ptr = (void *) __get_free_page(gfp_mask);
                    kmemleak_alloc(ptr, PAGE_SIZE, 1, gfp_mask);
                    return ptr;
            } else
                    return kmalloc(nents * sizeof(struct scatterlist), gfp_mask);
    }

    it failed as __get_free_page() return NULL, here just request one page, for trace, you can look into the attachment, and search the key word "freepage addr"8713.exportfailed-1.log

    and we modify the source in ti_components/os_tools/linux/kernel/omap/drivers/dma-buf/vmem-exp.c

    	if (pages == NULL)
    		return -ENOMEM;
    
    	if (sg_alloc_table(sgt, nr, GFP_KERNEL)) {
    		printk(KERN_ALERT "Failed to allocated sgt for %d pages\n", nr);
    		goto out;
    	}
    

    change 0 to GFP_KERNEL, then issue disappeared.

    and we're wondering which is the right to fix this issue by change the vmalloc or change the GFP flag?

     

  • Hi,

    You can increase the lowmem by adding a commandline parameter.

    Change your uenv.txt file for changing bootargs.

    vmalloc=256M

    You can confirm this by checking the bootlog showing lesser vmalloc value and thereby increased lowmem

    Regards,

    Nikhil D

  • Hello Nikhil D:

      Please have a look at the boot log.

      we don't see any difference when update the vmalloc in kernel command line.

    7142.boot.log
    [14:23:44:664]spl: error reading im[    0.000000] Booting Linux on physical CPU 0x0
    [14:23:44:665][    0.000000] Initializing cgroup subsys cpuset
    [14:23:44:676][    0.000000] Initializing cgroup subsys cpu
    [14:23:44:676][    0.000000] Initializing cgroup subsys cpuacct
    [14:23:44:687][    0.000000] Linux version 4.4.84 (root@ubuntu) (gcc version 5.3.1 20160113 (Linaro GCC 5.3-2016.02) ) #17 SMP PREEMPT Mon Jan 14 18:29:14 PST 2019
    [14:23:44:699][    0.000000] CPU: ARMv7 Processor [412fc0f2] revision 2 (ARMv7), cr=10c5387d
    [14:23:44:699][    0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache
    [14:23:44:710][    0.000000] Machine model: TI DRA762 EVM
    [14:23:44:710][    0.000000] Reserved memory: created DMA memory pool at 0x40300000, size 3 MiB
    [14:23:44:721][    0.000000] Reserved memory: initialized node cmem@40300000, compatible id shared-dma-pool
    [14:23:44:732][    0.000000] Reserved memory: regions without no-map are not yet supported
    [14:23:44:732][    0.000000] Reserved memory: regions without no-map are not yet supported
    [14:23:44:744][    0.000000] Reserved memory: created CMA memory pool at 0x96000000, size 32 MiB
    [14:23:44:754][    0.000000] Reserved memory: initialized node ipu2_cma@96000000, compatible id shared-dma-pool
    [14:23:44:765][    0.000000] Reserved memory: created CMA memory pool at 0x98000000, size 16 MiB
    [14:23:44:766][    0.000000] Reserved memory: initialized node dsp1_cma@98000000, compatible id shared-dma-pool
    [14:23:44:777][    0.000000] Reserved memory: created CMA memory pool at 0x99000000, size 16 MiB
    [14:23:44:788][    0.000000] Reserved memory: initialized node dsp2_cma@99000000, compatible id shared-dma-pool
    [14:23:44:788][    0.000000] Reserved memory: created CMA memory pool at 0x9a000000, size 16 MiB
    [14:23:44:799][    0.000000] Reserved memory: initialized node ipu1_cma@9a000000, compatible id shared-dma-pool
    [14:23:44:811][    0.000000] Reserved memory: created DMA memory pool at 0x9e000000, size 16 MiB
    [14:23:44:822][    0.000000] Reserved memory: initialized node cmem@9e000000, compatible id shared-dma-pool
    [14:23:44:822][    0.000000] Reserved memory: regions without no-map are not yet supported
    [14:23:44:832][    0.000000] cma: Reserved 24 MiB at 0x9c800000
    [14:23:44:833][    0.000000] Memory policy: Data cache writealloc
    [14:23:44:833][    0.000000] OMAP4: Map 0x9fe00000 to fe600000 for dram barrier
    [14:23:44:844][    0.000000] DRA762 ES1.0
    [14:23:44:844][    0.000000] PERCPU: Embedded 11 pages/cpu @df5c9000 s14912 r8192 d21952 u45056
    [14:23:44:855][    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 124288
    [14:23:44:866][    0.000000] Kernel command line: console=ttyS0,115200n8 vram=16M root=PARTUUID=cf7ef352-02 rw rootwait ip=none mem=512M 
    [14:23:44:878][    0.000000] PID hash table entries: 2048 (order: 1, 8192 bytes)
    [14:23:44:878][    0.000000] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
    [14:23:44:889][    0.000000] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
    [14:23:44:900][    0.000000] Memory: 198344K/501760K available (6663K kernel code, 319K rwdata, 2392K rodata, 332K init, 286K bss, 196920K reserved, 106496K cma-reserved, 0K highmem)
    [14:23:44:915][    0.000000] Virtual kernel memory layout:
    [14:23:44:916][    0.000000]     vector  : 0xffff0000 - 0xffff1000   (   4 kB)
    [14:23:44:926][    0.000000]     fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
    [14:23:44:928][    0.000000]     vmalloc : 0xe0800000 - 0xff800000   ( 496 MB)
    [14:23:44:937][    0.000000]     lowmem  : 0xc0000000 - 0xe0000000   ( 512 MB)
    [14:23:44:938][    0.000000]     pkmap   : 0xbfe00000 - 0xc0000000   (   2 MB)
    [14:23:44:948][    0.000000]     modules : 0xbf000000 - 0xbfe00000   (  14 MB)
    [14:23:44:949][    0.000000]       .text : 0xc0008000 - 0xc08e000c   (9057 kB)
    [14:23:44:959][    0.000000]       .init : 0xc08e1000 - 0xc0934000   ( 332 kB)
    [14:23:44:961][    0.000000]       .data : 0xc0934000 - 0xc0983e20   ( 320 kB)
    [14:23:44:971][    0.000000]        .bss : 0xc0985000 - 0xc09cc980   ( 287 kB)
    [14:23:44:972][    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1
    [14:23:44:984][    0.000000] Preemptible hierarchical RCU implementation.
    [14:23:44:986][    0.000000]  Build-time adjustment of leaf fanout to 32.
    [14:23:44:997][    0.000000] NR_IRQS:16 nr_irqs:16 16
    [14:23:44:998][    0.000000] ti_dt_clocks_register: failed to lookup clock node gmac_gmii_ref_clk_div
    [14:23:45:007][    0.000000] OMAP clockevent source: timer1 at 32786 Hz
    [14:23:45:010][    0.000000] Architected cp15 timer(s) running at 6.14MHz (phys).
    [14:23:45:016][    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x16af5adb9, max_idle_ns: 440795202250 ns
    [14:23:45:028][    0.000005] sched_clock: 56 bits at 6MHz, resolution 162ns, wraps every 4398046511023ns
    [14:23:45:029][    0.000016] Switching to timer-based delay loop, resolution 162ns
    [14:23:45:034][    0.000337] clocksource: 32k_counter: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 58327039986419 ns
    [14:23:45:048][    0.000345] OMAP clocksource: 32k_counter at 32768 Hz
    [14:23:45:049][    0.000817] Console: colour dummy device 80x30
    [14:23:45:057][    0.000837] Calibrating delay loop (skipped), value calculated using timer frequency.. 12.29 BogoMIPS (lpj=61475)
    [14:23:45:071][    0.000850] pid_max: default: 32768 minimum: 301
    [14:23:45:072][    0.000944] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
    [14:23:45:082][    0.000955] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
    [14:23:45:083][    0.001491] Initializing cgroup subsys io
    [14:23:45:094][    0.001508] Initializing cgroup subsys memory
    [14:23:45:095][    0.001532] Initializing cgroup subsys devices
    [14:23:45:095][    0.001545] Initializing cgroup subsys freezer
    [14:23:45:105][    0.001556] Initializing cgroup subsys perf_event
    [14:23:45:106][    0.001567] Initializing cgroup subsys pids
    [14:23:45:117][    0.001593] CPU: Testing write buffer coherency: ok
    [14:23:45:118][    0.001796] /cpus/cpu@0 missing clock-frequency property
    [14:23:45:128][    0.001812] /cpus/cpu@1 missing clock-frequency property
    [14:23:45:129][    0.001822] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
    [14:23:45:138][    0.001868] Setting up static identity map for 0x80008340 - 0x800083a0
    [14:23:45:138][    0.080086] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
    [14:23:45:139][    0.080154] Brought up 2 CPUs
    [14:23:45:150][    0.080167] SMP: Total of 2 processors activated (24.59 BogoMIPS).
    [14:23:45:152][    0.080174] CPU: All CPU(s) started in HYP mode.
    [14:23:45:163][    0.080179] CPU: Virtualization extensions available.
    [14:23:45:164][    0.081221] devtmpfs: initialized
    [14:23:45:173][    0.110590] VFP support v0.3: implementor 41 architecture 4 part 30 variant f rev 0
    [14:23:45:175][    0.111538] omap_hwmod: l3_main_2 using broken dt data from ocp
    [14:23:45:183][    0.226892] omap_hwmod: dcan1: _wait_target_disable failed
    [14:23:45:196][    0.323813] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
    [14:23:45:197][    0.323838] futex hash table entries: 512 (order: 3, 32768 bytes)
    [14:23:45:206][    0.325991] pinctrl core: initialized pinctrl subsystem
    [14:23:45:207][    0.326841] NET: Registered protocol family 16
    [14:23:45:217][    0.327811] DMA: preallocated 256 KiB pool for atomic coherent allocations
    [14:23:45:218][    0.350192] cpuidle: using governor ladder
    [14:23:45:219][    0.380219] cpuidle: using governor menu
    [14:23:45:232][    0.388873] OMAP GPIO hardware version 0.1
    [14:23:45:234][    0.393045] GPIO line 161 (radio_rst) hogged as output/low
    [14:23:45:241][    0.395456] irq: no irq domain found for /ocp/l4@4a000000/scm@2000/pinmux@1400 !
    [14:23:45:252][    0.419807] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
    [14:23:45:254][    0.419817] hw-breakpoint: maximum watchpoint size is 8 bytes.
    [14:23:45:260][    0.420319] omap4_sram_init:Unable to allocate sram needed to handle errata I688
    [14:23:45:274][    0.420329] omap4_sram_init:Unable to get sram pool needed to handle errata I688
    [14:23:45:275][    0.420809] OMAP DMA hardware revision 0.0
    [14:23:45:284][    0.461571] omap-dma-engine 4a056000.dma-controller: OMAP DMA engine driver (LinkedList1/2/3 supported)
    [14:23:45:285][    0.462712] edma 43300000.edma: memcpy is disabled
    [14:23:45:296][    0.467558] edma 43300000.edma: TI EDMA DMA engine driver
    [14:23:45:297][    0.472144] omap-iommu 40d01000.mmu: 40d01000.mmu registered
    [14:23:45:305][    0.472323] omap-iommu 40d02000.mmu: 40d02000.mmu registered
    [14:23:45:306][    0.472491] omap-iommu 58882000.mmu: 58882000.mmu registered
    [14:23:45:316][    0.472647] omap-iommu 55082000.mmu: 55082000.mmu registered
    [14:23:45:317][    0.472920] omap-iommu 41501000.mmu: 41501000.mmu registered
    [14:23:45:328][    0.473116] omap-iommu 41502000.mmu: 41502000.mmu registered
    [14:23:45:329][    0.476159] palmas 0-0058: IRQ missing: skipping irq request
    [14:23:45:339][    0.490723] palmas 0-0058: Muxing GPIO 51, PWM 0, LED 2
    [14:23:45:340][    0.541258] irq: no irq domain found for /ocp/i2c@48070000/tps65917@58 !
    [14:23:45:351][    0.541802] pcf857x: probe of 0-0020 failed with error -121
    [14:23:45:352][    0.542057] pcf857x: probe of 0-0021 failed with error -121
    [14:23:45:363][    0.542284] pcf857x: probe of 0-0026 failed with error -121
    [14:23:45:364][    0.542442] omap_i2c 48070000.i2c: bus 0 rev0.12 at 400 kHz
    [14:23:45:373][    0.542853] omap_i2c 48060000.i2c: bus 2 rev0.12 at 400 kHz
    [14:23:45:373][    0.560589] pcf857x: probe of 3-0021 failed with error -121
    [14:23:45:384][    0.560627] omap_i2c 4807a000.i2c: bus 3 rev0.12 at 400 kHz
    [14:23:45:385][    0.560822] media: Linux media interface: v0.10
    [14:23:45:396][    0.560872] Linux video capture interface: v2.00
    [14:23:45:397][    0.560912] pps_core: LinuxPPS API ver. 1 registered
    [14:23:45:406][    0.560918] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
    [14:23:45:407][    0.560941] PTP clock support registered
    [14:23:45:418][    0.560984] EDAC MC: Ver: 3.0.0
    [14:23:45:418][    0.561740] omap-mailbox 48840000.mailbox: omap mailbox rev 0x400
    [14:23:45:430][    0.562038] omap-mailbox 48842000.mailbox: omap mailbox rev 0x400
    [14:23:45:430][    0.562390] Advanced Linux Sound Architecture Driver Initialized.
    [14:23:45:440][    0.563245] clocksource: Switched to clocksource arch_sys_counter
    [14:23:45:441][    0.573593] NET: Registered protocol family 2
    [14:23:45:451][    0.574085] TCP established hash table entries: 4096 (order: 2, 16384 bytes)
    [14:23:45:452][    0.574126] TCP bind hash table entries: 4096 (order: 3, 32768 bytes)
    [14:23:45:463][    0.574192] TCP: Hash tables configured (established 4096 bind 4096)
    [14:23:45:464][    0.574232] UDP hash table entries: 256 (order: 1, 8192 bytes)
    [14:23:45:474][    0.574253] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes)
    [14:23:45:475][    0.574441] NET: Registered protocol family 1
    [14:23:45:498][    0.574696] RPC: Registered named UNIX socket transport module.
    [14:23:45:498][    0.574705] RPC: Registered udp transport module.
    [14:23:45:499][    0.574712] RPC: Registered tcp transport module.
    [14:23:45:500][    0.574719] RPC: Registered tcp NFSv4.1 backchannel transport module.
    [14:23:45:505][    0.575701] hw perfevents: enabled with armv7_cortex_a15 PMU driver, 7 counters available
    [14:23:45:518][    0.584714] squashfs: version 4.0 (2009/01/31) Phillip Lougher
    [14:23:45:519][    0.585349] NFS: Registering the id_resolver key type
    [14:23:45:519][    0.585376] Key type id_resolver registered
    [14:23:45:530][    0.585383] Key type id_legacy registered
    [14:23:45:531][    0.585452] ntfs: driver 2.1.32 [Flags: R/O].
    [14:23:45:541][    0.586855] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247)
    [14:23:45:542][    0.586875] io scheduler noop registered
    [14:23:45:552][    0.586886] io scheduler deadline registered
    [14:23:45:552][    0.586918] io scheduler cfq registered (default)
    [14:23:45:553][    0.589320] vsys_5v0: supplied by vsys_12v0
    [14:23:45:564][    0.589367] ldo3: supplied by vsys_5v0
    [14:23:45:565][    0.593013] pinctrl-single 4a003400.pinmux: 282 pins at pa fc003400 size 1128
    [14:23:45:572][    0.596314] PCI host bridge /ocp/axi@0/pcie_rc@51000000 ranges:
    [14:23:45:586][    0.596328]   No bus range found for /ocp/axi@0/pcie_rc@51000000, using [bus 00-ff]
    [14:23:45:587][    0.596362]    IO 0x20003000..0x20012fff -> 0x00000000
    [14:23:45:587][    0.596384]   MEM 0x20013000..0x2fffffff -> 0x20013000
    [14:23:45:597][    0.625945] dra7-pcie 51000000.pcie_rc: link is not up
    [14:23:45:598][    0.626110] dra7-pcie 51000000.pcie_rc: PCI host bridge to bus 0000:00
    [14:23:45:605][    0.626123] pci_bus 0000:00: root bus resource [bus 00-ff]
    [14:23:45:620][    0.626134] pci_bus 0000:00: root bus resource [io  0x0000-0xffff]
    [14:23:45:620][    0.626143] pci_bus 0000:00: root bus resource [mem 0x20013000-0x2fffffff]
    [14:23:45:631][    0.626553] PCI: bus0: Fast back to back transfers disabled
    [14:23:45:632][    0.626677] PCI: bus1: Fast back to back transfers enabled
    [14:23:45:642][    0.626759] pci 0000:00:00.0: BAR 0: assigned [mem 0x20100000-0x201fffff]
    [14:23:45:643][    0.626774] pci 0000:00:00.0: BAR 1: assigned [mem 0x20020000-0x2002ffff]
    [14:23:45:653][    0.626787] pci 0000:00:00.0: PCI bridge to [bus 01]
    [14:23:45:654][    0.627006] pcieport 0000:00:00.0: Signaling PME through PCIe PME interrupt
    [14:23:45:664][    0.687160] Serial: 8250/16550 driver, 10 ports, IRQ sharing disabled
    [14:23:45:664][    0.690526] console [ttyS0] disabled
    [14:23:45:676][    0.690578] 4806a000.serial: ttyS0 at MMIO 0x4806a000 (irq = 301, base_baud = 3000000) is a 8250
    [14:23:45:678][    1.704700] console [ttyS0] enabled
    [14:23:45:685][    1.709088] 4806c000.serial: ttyS1 at MMIO 0x4806c000 (irq = 302, base_baud = 3000000) is a 8250
    [14:23:45:697][    1.718792] 48020000.serial: ttyS2 at MMIO 0x48020000 (irq = 303, base_baud = 3000000) is a 8250
    [14:23:45:713][    1.728448] 4ae2b000.serial: ttyS9 at MMIO 0x4ae2b000 (irq = 304, base_baud = 3000000) is a 8250
    [14:23:45:714][    1.738490] [drm] Initialized drm 1.1.0 20060810
    [14:23:45:725][    1.744031] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
    [14:23:45:726][    1.750675] [drm] No driver support for vblank timestamp query.
    [14:23:45:731][    1.756839] [drm] Initialized vdrm 1.0.0 20110917 on minor 0
    [14:23:45:750][    1.769830] loop: module loaded
    [14:23:45:750][    1.775700] vmemexp device MAJOR num = 245
    [14:23:45:751][    1.779829] vmemexp class registered
    [14:23:45:764][    1.783558] /dev/vmemexp device registered
    [14:23:45:765][    1.787671] ioctl DBUFIOC_EXPORT_VIRTMEM = -1072899120
    [14:23:45:779][    1.795952] m25p80 spi32766.0: unrecognized JEDEC id bytes: 00,  0,  0
    [14:23:45:780][    1.803643] libphy: Fixed MDIO Bus: probed
    [14:23:45:833][    1.853277] davinci_mdio 48485000.mdio: davinci mdio revision 1.6
    [14:23:45:834][    1.859400] libphy: 48485000.mdio: probed
    [14:23:45:843][    1.866309] davinci_mdio 48485000.mdio: phy[1]: device 48485000.mdio:01, driver RTL9000A Gigabit Ethernet
    [14:23:45:858][    1.876557] cpsw 48484000.ethernet: Detected MACID = f8:36:9b:99:10:c0
    [14:23:45:859][    1.883198] cpsw 48484000.ethernet: cpts: overflow check period 800
    [14:23:45:867][    1.890181] cpsw 48484000.ethernet: cpsw: Detected MACID = f8:36:9b:99:10:c1
    [14:23:45:879][    1.898794] mousedev: PS/2 mouse device common for all mice
    [14:23:45:880][    1.905018] i2c /dev entries driver
    [14:23:45:891][    1.913727] omap_hsmmc 4809c000.mmc: Got CD GPIO
    [14:23:45:892][    1.918560] omap_hsmmc 4809c000.mmc: no pinctrl state for sdr104 mode
    [14:23:45:900][    1.925045] omap_hsmmc 4809c000.mmc: no pinctrl state for ddr50 mode
    [14:23:45:915][    1.931427] omap_hsmmc 4809c000.mmc: no pinctrl state for sdr50 mode
    [14:23:45:916][    1.937824] omap_hsmmc 4809c000.mmc: no pinctrl state for sdr25 mode
    [14:23:45:926][    1.944219] omap_hsmmc 4809c000.mmc: no pinctrl state for sdr12 mode
    [14:23:45:928][    1.950850] vsys_3v3: supplied by vsys_12v0
    [14:23:45:939][    1.955118] vio_3v3: supplied by vsys_3v3
    [14:23:45:940][    1.959176] vio_3v3_sd: supplied by vio_3v3
    [14:23:45:940][    1.963705] ldo4: supplied by vsys_5v0
    [14:23:45:989][    2.013677] omap_hsmmc 480b4000.mmc: no pinctrl state for sdr25 mode
    [14:23:45:996][    2.020061] omap_hsmmc 480b4000.mmc: no pinctrl state for sdr12 mode
    [14:23:46:012][    2.033559] smps5: supplied by vsys_3v3
    [14:23:46:013][    2.037626] vio_1v8: supplied by smps5
    [14:23:46:053][    2.074115] ledtrig-cpu: registered to indicate activity on CPUs
    [14:23:46:071][    2.085259] hwspinlock_user gatemp: requested 20 hwspinlocks
    [14:23:46:071][    2.092169] aic_dvdd: supplied by vio_3v3
    [14:23:46:072][    2.097469] davinci-mcasp 48464000.mcasp: DAI is shared
    [14:23:46:086][    2.103585] davinci-mcasp 48474000.mcasp: DAI is shared
    [14:23:46:087][    2.110067] NET: Registered protocol family 10
    [14:23:46:103][    2.125398] sit: IPv6 over IPv4 tunneling driver
    [14:23:46:104][    2.130585] NET: Registered protocol family 17
    [14:23:46:115][    2.135311] Key type dns_resolver registered
    [14:23:46:116][    2.139708] omap_voltage_late_init: Voltage driver support not added
    [14:23:46:127][    2.146593] Adding alias for supply vdd,cpu0 -> vdd,4a003b20.oppdm
    [14:23:46:128][    2.152800] Adding alias for supply vbb,cpu0 -> vbb,4a003b20.oppdm
    [14:23:46:138][    2.159091] buck10: supplied by vsys_3v3
    [14:23:46:139][    2.163653] Adding alias for supply vdd,cpu0 -> vdd,4a003b20.oppdm
    [14:23:46:151][    2.169860] Adding alias for supply vbb,cpu0 -> vbb,4a003b20.oppdm
    [14:23:46:152][    2.177635] Power Management for TI OMAP4+ devices.
    [14:23:46:165][    2.182672] Registering SWP/SWPB emulation handler
    [14:23:46:165][    2.188285] dmm 4e000000.dmm: workaround for errata i878 in use
    [14:23:46:179][    2.195328] dmm 4e000000.dmm: initialized all PAT entries
    [14:23:46:180][    2.201329] [drm] Initialized omapdrm 1.0.0 20110917 on minor 1
    [14:23:46:195][    2.218533] asoc-simple-card sound0: tlv320aic3x-hifi <-> 48468000.mcasp mapping ok
    [14:23:46:213][    2.237994] hctosys: unable to open rtc device (rtc0)
    [14:23:46:229][    2.240581] mmc0: host does not support reading read-only switch, assuming write-enable
    [14:23:46:229][    2.242613] mmc0: new high speed SDHC card at address 59b4
    [14:23:46:237][    2.252907] mmcblk0: mmc0:59b4 USD00 7.33 GiB 
    [14:23:46:239][    2.257399]  mmcblk0: p1 p2
    [14:23:46:250][    2.270818] aic_dvdd: disabling
    [14:23:46:250][    2.274130] ALSA device list:
    [14:23:46:250][    2.277105]   #0: DRA7xx-EVM
    [14:23:46:260][    2.281417] EXT4-fs (mmcblk0p2): couldn't mount as ext3 due to feature incompatibilities
    [14:23:46:277][    2.290063] EXT4-fs (mmcblk0p2): couldn't mount as ext2 due to feature incompatibilities
    [14:23:46:278][    2.296946] mmc1: MAN_BKOPS_EN bit is not set
    [14:23:46:294][    2.305798] mmc1: new HS200 MMC card at address 0001
    [14:23:46:296][    2.311074] mmcblk1: mmc1:0001 DG4008 7.28 GiB 
    [14:23:46:306][    2.315829] mmcblk1boot0: mmc1:0001 DG4008 partition 1 4.00 MiB
    [14:23:46:306][    2.321925] mmcblk1boot1: mmc1:0001 DG4008 partition 2 4.00 MiB
    [14:23:46:746][    2.768721] EXT4-fs (mmcblk0p2): recovery complete
    [14:23:46:761][    2.776791] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
    [14:23:46:761][    2.784956] VFS: Mounted root (ext4 filesystem) on device 179:2.
    [14:23:46:762][    2.791869] devtmpfs: mounted
    [14:23:46:778][    2.795041] Freeing unused kernel memory: 332K
    [14:23:46:778][    2.799501] This architecture does not have kernel memory protection.
    [14:23:46:979][    3.003580] systemd[1]: System time before build time, advancing clock.
    [14:23:47:038][    3.059418] random: systemd: uninitialized urandom read (16 bytes read, 18 bits of entropy available)
    [14:23:47:049][    3.071873] random: systemd: uninitialized urandom read (16 bytes read, 18 bits of entropy available)
    [14:23:47:074][    3.089060] systemd[1]: systemd 229 running in system mode. (+PAM -AUDIT -SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP -LIBCRYPTSETUP -GCRYPT +GNUTLS +ACL +XZ -LZ4 -SECCOMP +BLKID -ELFUTILS +KMOD -IDN)
    [14:23:47:093][    3.107606] systemd[1]: Detected architecture arm.
    [14:23:47:093]
    [14:23:47:093]Welcome to Arago 2016.12!
    [14:23:47:094]
    [14:23:47:108][    3.134108] systemd[1]: Set hostname to <dra7xx-evm>.
    [14:23:47:175][    3.199985] random: systemd-gpt-aut: uninitialized urandom read (16 bytes read, 19 bits of entropy available)
    [14:23:47:188][    3.210514] random: systemd-gpt-aut: uninitialized urandom read (16 bytes read, 19 bits of entropy available)
    [14:23:47:216][    3.237004] random: systemd-sysv-ge: uninitialized urandom read (16 bytes read, 20 bits of entropy available)
    [14:23:47:241][    3.258748] random: systemd-sysv-ge: uninitialized urandom read (16 bytes read, 20 bits of entropy available)
    [14:23:47:254][    3.274138] random: systemd-sysv-ge: uninitialized urandom read (16 bytes read, 21 bits of entropy available)
    [14:23:47:344][    3.369392] random: systemd: uninitialized urandom read (16 bytes read, 23 bits of entropy available)
    [14:23:47:357][    3.378865] random: systemd: uninitialized urandom read (16 bytes read, 23 bits of entropy available)
    [14:23:47:367][    3.388768] random: systemd: uninitialized urandom read (16 bytes read, 23 bits of entropy available)
    [14:23:47:680][    3.704694] systemd[1]: sysinit.target: Found ordering cycle on sysinit.target/start
    [14:23:47:691][    3.712482] systemd[1]: sysinit.target: Found dependency on alignment.service/start
    [14:23:47:706][    3.720262] systemd[1]: sysinit.target: Found dependency on sysinit.target/start
    [14:23:47:707][    3.727732] systemd[1]: sysinit.target: Breaking ordering cycle by deleting job alignment.service/start
    [14:23:47:713][    3.737204] systemd[1]: alignment.service: Job alignment.service/start deleted to break ordering cycle starting with sysinit.target/start
    [14:23:47:726][ SKIP ] Ordering cycle found, skipping alignment.service
    [14:23:47:766][    3.786562] systemd[1]: Reached target Swap.
    [14:23:47:767][  OK  ] Reached target Swap.
    [14:23:47:798][    3.815907] systemd[1]: Created slice User and Session Slice.
    [14:23:47:799][  OK  ] Created slice User and Session Slice.
    [14:23:47:825][    3.843556] systemd[1]: Listening on Syslog Socket.
    [14:23:47:826][  OK  ] Listening on Syslog Socket.
    [14:23:47:838][    3.863594] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
    [14:23:47:850][  OK  ] Started Dispatch Password Requests to Console Directory Watch.
    [14:23:47:868][    3.893582] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
    [14:23:47:877][  OK  ] Started Forward Password Requests to Wall Directory Watch.
    [14:23:47:906][    3.923531] systemd[1]: Listening on udev Control Socket.
    [14:23:47:907][  OK  ] Listening on udev Control Socket.
    [14:23:47:935][    3.953494] systemd[1]: Listening on udev Kernel Socket.
    [14:23:47:936][  OK  ] Listening on udev Kernel Socket.
    [14:23:47:964][    3.983527] systemd[1]: Listening on Journal Socket.
    [14:23:47:965][  OK  ] Listening on Journal Socket.
    [14:23:47:978][    4.003556] systemd[1]: Listening on /dev/initctl Compatibility Named Pipe.
    [14:23:47:986][  OK  ] Listening on /dev/initctl Compatibility Named Pipe.
    [14:23:48:015][    4.034068] systemd[1]: Created slice System Slice.
    [14:23:48:016][  OK  ] Created slice System Slice.
    [14:23:48:075][    4.093609] systemd[1]: Starting Setup Virtual Console...
    [14:23:48:075]         Starting Setup Virtual Console...
    [14:23:48:109][    4.127661] systemd[1]: Starting Load Kernel Modules...
    [14:23:48:109]         Starting Load Kernel Modules...
    [14:23:48:134][    4.153496] systemd[1]: Reached target Slices.
    [14:23:48:135][  OK  ] Reached target Slices.
    [14:23:48:186][    4.203449] systemd[1]: Mounting Temporary Directory...
    [14:23:48:187]         Mounting Temporary Directory...
    [14:23:48:211][    4.235920] systemd[1]: Starting Create list of required static device nodes for the current kernel...
    [14:23:48:222]         Starting Create list of required st... nodes for the current kernel...
    [14:23:48:249][    4.274219] systemd[1]: Created slice system-serial\x2dgetty.slice.
    [14:23:48:256][  OK  ] Created slice system-serial\x2dgetty.slice.
    [14:23:48:288][    4.303494] systemd[1]: Reached target Remote File Systems.
    [14:23:48:289][  OK  ] Reached target Remote File Systems.
    [14:23:48:350][    4.373599] systemd[1]: Starting Remount Root and Kernel File Systems...
    [14:23:48:367]         Starting Remount Root and Kernel File Systems...
    [14:23:48:368][    4.389762] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
    [14:23:48:387][    4.405065] systemd[1]: Created slice system-getty.slice.
    [14:23:48:388][  OK  ] Created slice system-getty.slice.
    [14:23:48:416][    4.435603] systemd[1]: Mounting Debug File System...
    [14:23:48:418]         Mounting Debug File System...
    [14:23:48:439][    4.463586] systemd[1]: Listening on Journal Socket (/dev/log).
    [14:23:48:445][  OK  ] Listening on Journal Socket (/dev/log).
    [14:23:48:505][    4.523610] systemd[1]: Starting Journal Service...
    [14:23:48:506]         Starting Journal Service...
    [14:23:48:529][    4.555640] systemd[1]: Mounting POSIX Message Queue File System...
    [14:23:48:540]         Mounting POSIX Message Queue File System...
    [14:23:48:561][    4.583667] systemd[1]: Listening on Network Service Netlink Socket.
    [14:23:48:567][  OK  ] Listening on Network Service Netlink Socket.
    [14:23:48:593][    4.613510] systemd[1]: Reached target Paths.
    [14:23:48:594][  OK  ] Reached target Paths.
    [14:23:48:650][    4.668130] systemd[1]: Mounted Debug File System.
    [14:23:48:651][  OK  ] Mounted Debug File System.
    [14:23:48:669][    4.693510] systemd[1]: Mounted POSIX Message Queue File System.
    [14:23:48:675][  OK  ] Mounted POSIX Message Queue File System.
    [14:23:48:697][    4.713484] systemd[1]: Mounted Temporary Directory.
    [14:23:48:698][  OK  ] Mounted Temporary Directory.
    [14:23:48:715][    4.733636] systemd[1]: Started Journal Service.
    [14:23:48:716][  OK  ] Started Journal Service.
    [14:23:48:731][  OK  ] Started Setup Virtual Console.
    [14:23:48:750][FAILED] Failed to start Load Kernel Modules.
    [14:23:48:770]See 'systemctl status systemd-modules-load.service' for details.
    [14:23:48:793][  OK  ] Started Create list of required sta...ce nodes for the current kernel.
    [14:23:48:820][  OK  ] Started Remount Root and Kernel File Systems.
    [14:23:49:079]         Starting udev Coldplug all Devices...
    [14:23:49:102]         Starting Create Static Device Nodes in /dev...
    [14:23:49:120]         Starting Apply Kernel Variables...
    [14:23:49:144]         Starting Flush Journal to Persistent Storage...
    [14:23:49:202][  OK  ] Started Apply Kernel Variables.
    [14:23:49:229][  OK  ] Started Create Static Device Nodes in /dev.
    [14:23:49:337][    5.359692] systemd-journald[142]: Received request to flush runtime journal from PID 1
    [14:23:49:381]         Starting udev Kernel Device Manager...
    [14:23:49:398][  OK  ] Reached target Local File Systems (Pre).
    [14:23:49:425]         Mounting /media/ram...
    [14:23:49:458]         Mounting /var/volatile...
    [14:23:49:525][  OK  ] Mounted /var/volatile.
    [14:23:49:544][  OK  ] Mounted /media/ram.
    [14:23:49:544][  OK  ] Started udev Kernel Device Manager.
    [14:23:49:560][  OK  ] Started Flush Journal to Persistent Storage.
    [14:23:49:656][  OK  ] Started udev Coldplug all Devices.
    [14:23:49:689][    5.712298] omap-rproc 58820000.ipu: assigned reserved memory node ipu1_cma@9a000000
    [14:23:49:703][    5.729576]  remoteproc0: 58820000.ipu is available
    [14:23:49:727][    5.749884]  remoteproc0: Note: remoteproc is still under development and considered experimental.
    [14:23:49:747][    5.767715]  remoteproc0: THE BINARY FORMAT IS NOT YET FINALIZED, and backward compatibility isn't yet guaranteed.
    [14:23:49:768][    5.790682] omap-rproc 55020000.ipu: assigned reserved memory node ipu2_cma@96000000
    [14:23:49:783][    5.809208]  remoteproc1: 55020000.ipu is available
    [14:23:49:802]         Starting Load/Save Random Seed...
    [14:23:49:831][  OK  ] Reached target Local File Systems.[    5.852221]  remoteproc0: registered virtio0 (type 7)
    [14:23:49:832]
    [14:23:49:841][    5.863473]  remoteproc1: Note: remoteproc is still under development and considered experimental.
    [14:23:49:864][    5.885162]  remoteproc1: THE BINARY FORMAT IS NOT YET FINALIZED, and backward compatibility isn't yet guaranteed.
    [14:23:49:895]         Starting Create Volatile Files and Directories...
    [14:23:49:911][    5.936199] omap_rng 48090000.rng: OMAP Random Number Generator ver. 20
    [14:23:49:937][  OK  ] Started Load/Save Random Seed.
    [14:23:49:973][  OK  ] Started Create Volatile Files and Directories.
    [14:23:49:995][    6.022287] omap-des 480a5000.des: OMAP DES hw accel rev: 2.2
    [14:23:50:021][  OK  ] Found device /dev/ttyS0.
    [14:23:50:152]         Starting Update UTMP about System Boot/Shutdown...
    [14:23:50:181]         Starting Network Time Synchronization...
    [14:23:50:297][  OK  ] Started Network Time Synchronization.
    [14:23:50:321][    6.340716] omap-sham 4b101000.sham: hw accel on OMAP rev 4.3
    [14:23:50:322][  OK  ] Reached target System Time Synchronized.
    [14:23:50:334][    6.357940] omap-aes 4b500000.aes: OMAP AES hw accel rev: 3.3
    [14:23:50:340][    6.366310] omap-aes 4b700000.aes: OMAP AES hw accel rev: 3.3
    [14:23:50:380]         Starting Synchronize System and HW clocks...
    [14:23:50:439][  OK  ] Started Update UTMP about System Boot/Shutdown.
    [14:23:50:462][FAILED] Failed to start Synchronize System and HW clocks.
    [14:23:50:477]See 'systemctl status sync-clocks.service' for details.
    [14:23:50:505][    6.529695]  remoteproc1: registered virtio1 (type 7)
    [14:23:50:692][  OK  ] Reached target Sound Card.
    [14:23:50:708][  OK  ] Reached target System Initialization.
    [14:23:50:736][  OK  ] Started Daily Cleanup of Temporary Directories.
    [14:23:50:737][    6.759068] SCSI subsystem initialized
    [14:23:50:757][  OK  ] Reached target Timers.
    [14:23:50:812][  OK  ] Listening on D-Bus System Message Bus Socket.
    [14:23:50:832][  OK  ] Reached target Sockets.
    [14:23:50:852][  OK  ] Reached target Basic System.
    [14:23:50:946][    6.971814] [drm] Initialized pvr 1.14.3699939 20110701 on minor 2
    [14:23:50:979][  OK  ] Started System Logging Service.
    [14:23:50:990]         Starting Permit User Sessions...
    [14:23:51:008]         Starting rc.pvr.service...
    [14:23:51:040]         Starting Save/Restore Sound Card State...
    [14:23:51:079][    7.099982] ahci 4a140000.sata: SSS flag set, parallel bus scan disabled
    [14:23:51:088][    7.111391] ahci 4a140000.sata: AHCI 0001.0300 32 slots 1 ports 3 Gbps 0x1 impl platform mode
    [14:23:51:104][  OK  ] Started Kernel Logging Service.
    [14:23:51:128][  OK  ] Started D-Bus System Message Bus.
    [14:23:51:134][    7.158411] PVR_K: UM DDK-(3699939) and KM DDK-(3699939) match. [ OK ]
    [14:23:51:153][    7.176177] ahci 4a140000.sata: flags: 64bit ncq sntf stag pm led clo only pmp pio slum part ccc apst 
    [14:23:51:205][    7.222434] scsi host0: ahci
    [14:23:51:206][    7.225658] ata1: SATA max UDMA/133 mmio [mem 0x4a140000-0x4a1410ff] port 0x100 irq 342
    [14:23:51:309][    7.331432] FAT-fs (mmcblk0p1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
    [14:23:51:333][    7.361385]  remoteproc0: powering up 58820000.ipu
    [14:23:51:348][    7.372876]  remoteproc0: Booting fw image dra7-ipu1-fw.xem4, size 614132
    [14:23:51:372][    7.391041] omap-iommu 58882000.mmu: 58882000.mmu: version 2.1
    [14:23:51:373]         Starting Network Service...
    [14:23:51:384][    7.408439]  remoteproc0: remote processor 58820000.ipu is now up
    [14:23:51:401][    7.416094] virtio_rpmsg_bus virtio0: rpmsg host is online
    [14:23:51:402][    7.424262]  remoteproc1: powering up 55020000.ipu
    [14:23:51:406]         Starting Login Service...
    [14:23:51:453][  OK  ] Started Permit User Sessions.
    [14:23:51:474][    7.497116]  remoteproc1: Booting fw image dra7-ipu2-fw.xem4, size 7282956
    [14:23:51:489][    7.507178] omap-iommu 55082000.mmu: 55082000.mmu: version 2.1
    [14:23:51:490][  OK  ] Started rc.pvr.service.
    [14:23:51:508][  OK  ] Started Save/Restore Sound Card State.
    [14:23:51:510][    7.529880] net eth1: initializing cpsw version 1.15 (0)
    [14:23:51:519][    7.544776]  remoteproc1: remote processor 55020000.ipu is now up
    [14:23:51:533][    7.544923] net eth0: initialized cpsw ale version 1.4
    [14:23:51:533][    7.544926] net eth0: ALE Table size 1024
    [14:23:51:535][    7.547742] libphy: PHY 48485000.mdio:03 not found
    [14:23:51:544][    7.547746] net eth1: phy "48485000.mdio:03" not found on slave 1, err -19
    [14:23:51:545][    7.558683] IPv6: ADDRCONF(NETDEV_UP): eth1: link is not ready
    [14:23:51:557][    7.560182] net eth0: initializing cpsw version 1.15 (0)
    [14:23:51:558][    7.584345] ata1: SATA link down (SStatus 0 SControl 300)
    [14:23:51:570][  OK  ] Started Network Service.
    [14:23:51:572][    7.596016] virtio_rpmsg_bus virtio1: rpmsg host is online
    [14:23:51:579][    7.597816] virtio_rpmsg_bus virtio1: creating channel rpmsg-proto addr 0x50
    [14:23:51:585][    7.597935] virtio_rpmsg_bus virtio0: creating channel rpmsg-proto addr 0x50
    [14:23:51:609][    7.636120] NET: Registered protocol family 41
    [14:23:51:708][    7.734900] net eth0: phy found : id is : 0x1ccb00
    [14:23:51:723][    7.748073] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
    [14:23:52:028][  OK  ] Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
    [14:23:52:046][  OK  ] Reached target Network.
    [14:23:52:097]         Starting Network Name Resolution...
    [14:23:52:119]         Starting LSB: Dropbear Secure Shell server...
    [14:23:52:143][    8.161959] usbcore: registered new interface driver usbfs
    [14:23:52:146][    8.170885] usbcore: registered new interface driver hub
    [14:23:52:158][    8.177149] usbcore: registered new device driver usb
    [14:23:52:158]         Starting weston.service...
    [14:23:52:230][  OK  ] Started Serial Getty on ttyS0.
    [14:23:52:257][  OK  ] Started Getty on tty1.
    [14:23:52:258][    8.282313] xhci-hcd xhci-hcd.2.auto: xHCI Host Controller
    [14:23:52:265][    8.288662] xhci-hcd xhci-hcd.2.auto: new USB bus registered, assigned bus number 1
    [14:23:52:279][    8.302706] xhci-hcd xhci-hcd.2.auto: hcc params 0x0220f04c hci version 0x100 quirks 0x00210010
    [14:23:52:293][    8.312594] xhci-hcd xhci-hcd.2.auto: irq 462, io mem 0x488d0000
    [14:23:52:294][    8.319279] hub 1-0:1.0: USB hub found
    [14:23:52:310][    8.323221] hub 1-0:1.0: 1 port detected
    [14:23:52:312][    8.327474] xhci-hcd xhci-hcd.2.auto: xHCI Host Controller
    [14:23:52:322][    8.327484] xhci-hcd xhci-hcd.2.auto: new USB bus registered, assigned bus number 2
    [14:23:52:323][    8.327542] usb usb2: We don't know the algorithms for LPM for this host, disabling LPM.
    [14:23:52:342][    8.328034] hub 2-0:1.0: USB hub found
    [14:23:52:342][    8.328056] hub 2-0:1.0: 1 port detected
    [14:23:52:345][  OK  ] Started Network Name Resolution.
    [14:23:52:359][  OK  ] Started LSB: Dropbear Secure Shell server.
    [14:23:52:379][  OK  ] Started weston.service.
    [14:23:52:403][  OK  ] Started Login Service.
    [14:23:52:497]         Starting tiipclad-daemon.service...
    [14:23:52:518]         Starting telnetd.service...
    [14:23:52:539][  OK  ] Started tiipclad-daemon.service.
    [14:23:52:557][  OK  ] Started telnetd.service.
    [14:23:52:636]         Starting ecarxinit.service...
    [14:23:52:692][    8.710633] DMA: Module install successful, device major num = 242 
    [14:23:52:694][    8.717149] DRV: Module install successful
    [14:23:53:306][    9.332278] omap_l3_noc 44000000.ocp: L3 application error: target 3 mod:2 (unclearable)
    [14:23:53:317][    9.340447] omap_l3_noc 44000000.ocp: L3 debug error: target 3 mod:2 (unclearable)
    [14:23:58:260]
    [14:23:58:280] _____                    _____           _         _   
    [14:23:58:280]|  _  |___ ___ ___ ___   |  _  |___ ___  |_|___ ___| |_ 
    [14:23:58:290]|     |  _| .'| . | . |  |   __|  _| . | | | -_|  _|  _|
    [14:23:58:291]|__|__|_| |__,|_  |___|  |__|  |_| |___|_| |___|___|_|  
    [14:23:58:303]              |___|                    |___|            
    [14:23:58:303]
    [14:23:58:303]Arago Project http://arago-project.org dra7xx-evm ttyS0
    [14:23:58:303]
    [14:23:58:304]Arago 2016.12 dra7xx-evm ttyS0
    [14:23:58:309]
    [14:24:00:235]dra7xx-evm login: root
    [14:24:00:420]
    [14:24:06:905]root@dra7xx-evm:~# 2;164Rcat /run/media/mmcblk0p1/u
    [14:24:06:906]u-boot.img  uenv.txt    
    [14:24:07:120]root@dra7xx-evm:~# 2;164Rcat /run/media/mmcblk0p1/u
    [14:24:07:121]u-boot.img  uenv.txt    
    [14:24:08:290]root@dra7xx-evm:~# 2;164Rcat /run/media/mmcblk0p1/uenv.txt 
    [14:24:08:318]-sh: 2: command not found
    [14:24:08:319]-sh: 164Rcat: command not found
    [14:24:10:264]root@dra7xx-evm:~# 2;164Rcat /run/media/mmcblk0p1/uenv.txt 
    [14:24:10:289]-sh: 2: command not found
    [14:24:10:290]-sh: 164Rcat: command not found
    [14:24:15:043]root@dra7xx-evm:~# cat /run/media/mmcblk0p1/uenv.txt       
    [14:24:15:069]fdtfile=dra76-evm-infoadas.dtb
    [14:24:15:079]args_mmc=part uuid mmc 0:2 uuid; setenv bootargs "console=ttyS0,115200n8 vram=16M root=PARTUUID=${uuid} rw rootwait ip=none mem=512M "
    

    bootwithvmalloc=256m.log
    [14:22:28:445]spl: error reading i[    0.000000] Booting Linux on physical CPU 0x0
    [14:22:28:445][    0.000000] Initializing cgroup subsys cpuset
    [14:22:28:456][    0.000000] Initializing cgroup subsys cpu
    [14:22:28:457][    0.000000] Initializing cgroup subsys cpuacct
    [14:22:28:467][    0.000000] Linux version 4.4.84 (root@ubuntu) (gcc version 5.3.1 20160113 (Linaro GCC 5.3-2016.02) ) #17 SMP PREEMPT Mon Jan 14 18:29:14 PST 2019
    [14:22:28:478][    0.000000] CPU: ARMv7 Processor [412fc0f2] revision 2 (ARMv7), cr=10c5387d
    [14:22:28:478][    0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache
    [14:22:28:490][    0.000000] Machine model: TI DRA762 EVM
    [14:22:28:490][    0.000000] Reserved memory: created DMA memory pool at 0x40300000, size 3 MiB
    [14:22:28:501][    0.000000] Reserved memory: initialized node cmem@40300000, compatible id shared-dma-pool
    [14:22:28:512][    0.000000] Reserved memory: regions without no-map are not yet supported
    [14:22:28:512][    0.000000] Reserved memory: regions without no-map are not yet supported
    [14:22:28:524][    0.000000] Reserved memory: created CMA memory pool at 0x96000000, size 32 MiB
    [14:22:28:536][    0.000000] Reserved memory: initialized node ipu2_cma@96000000, compatible id shared-dma-pool
    [14:22:28:546][    0.000000] Reserved memory: created CMA memory pool at 0x98000000, size 16 MiB
    [14:22:28:546][    0.000000] Reserved memory: initialized node dsp1_cma@98000000, compatible id shared-dma-pool
    [14:22:28:557][    0.000000] Reserved memory: created CMA memory pool at 0x99000000, size 16 MiB
    [14:22:28:568][    0.000000] Reserved memory: initialized node dsp2_cma@99000000, compatible id shared-dma-pool
    [14:22:28:568][    0.000000] Reserved memory: created CMA memory pool at 0x9a000000, size 16 MiB
    [14:22:28:579][    0.000000] Reserved memory: initialized node ipu1_cma@9a000000, compatible id shared-dma-pool
    [14:22:28:590][    0.000000] Reserved memory: created DMA memory pool at 0x9e000000, size 16 MiB
    [14:22:28:601][    0.000000] Reserved memory: initialized node cmem@9e000000, compatible id shared-dma-pool
    [14:22:28:602][    0.000000] Reserved memory: regions without no-map are not yet supported
    [14:22:28:613][    0.000000] cma: Reserved 24 MiB at 0x9c800000
    [14:22:28:613][    0.000000] Memory policy: Data cache writealloc
    [14:22:28:613][    0.000000] OMAP4: Map 0x9fe00000 to fe600000 for dram barrier
    [14:22:28:624][    0.000000] DRA762 ES1.0
    [14:22:28:624][    0.000000] PERCPU: Embedded 11 pages/cpu @df5c9000 s14912 r8192 d21952 u45056
    [14:22:28:635][    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 124288
    [14:22:28:646][    0.000000] Kernel command line: console=ttyS0,115200n8 vram=16M root=PARTUUID=cf7ef352-02 rw rootwait ip=none mem=512M vmalloc=256M
    [14:22:28:658][    0.000000] PID hash table entries: 2048 (order: 1, 8192 bytes)
    [14:22:28:658][    0.000000] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
    [14:22:28:669][    0.000000] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
    [14:22:28:680][    0.000000] Memory: 198344K/501760K available (6663K kernel code, 319K rwdata, 2392K rodata, 332K init, 286K bss, 196920K reserved, 106496K cma-reserved, 0K highmem)
    [14:22:28:695][    0.000000] Virtual kernel memory layout:
    [14:22:28:696][    0.000000]     vector  : 0xffff0000 - 0xffff1000   (   4 kB)
    [14:22:28:706][    0.000000]     fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
    [14:22:28:707][    0.000000]     vmalloc : 0xe0800000 - 0xff800000   ( 496 MB)
    [14:22:28:717][    0.000000]     lowmem  : 0xc0000000 - 0xe0000000   ( 512 MB)
    [14:22:28:718][    0.000000]     pkmap   : 0xbfe00000 - 0xc0000000   (   2 MB)
    [14:22:28:729][    0.000000]     modules : 0xbf000000 - 0xbfe00000   (  14 MB)
    [14:22:28:730][    0.000000]       .text : 0xc0008000 - 0xc08e000c   (9057 kB)
    [14:22:28:742][    0.000000]       .init : 0xc08e1000 - 0xc0934000   ( 332 kB)
    [14:22:28:742][    0.000000]       .data : 0xc0934000 - 0xc0983e20   ( 320 kB)
    [14:22:28:751][    0.000000]        .bss : 0xc0985000 - 0xc09cc980   ( 287 kB)
    [14:22:28:752][    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1
    [14:22:28:762][    0.000000] Preemptible hierarchical RCU implementation.
    [14:22:28:763][    0.000000]  Build-time adjustment of leaf fanout to 32.
    [14:22:28:772][    0.000000] NR_IRQS:16 nr_irqs:16 16
    [14:22:28:774][    0.000000] ti_dt_clocks_register: failed to lookup clock node gmac_gmii_ref_clk_div
    [14:22:28:783][    0.000000] OMAP clockevent source: timer1 at 32786 Hz
    [14:22:28:784][    0.000000] Architected cp15 timer(s) running at 6.14MHz (phys).
    [14:22:28:792][    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x16af5adb9, max_idle_ns: 440795202250 ns
    [14:22:28:803][    0.000005] sched_clock: 56 bits at 6MHz, resolution 162ns, wraps every 4398046511023ns
    [14:22:28:817][    0.000016] Switching to timer-based delay loop, resolution 162ns
    [14:22:28:818][    0.000336] clocksource: 32k_counter: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 58327039986419 ns
    [14:22:28:828][    0.000344] OMAP clocksource: 32k_counter at 32768 Hz
    [14:22:28:829][    0.000814] Console: colour dummy device 80x30
    [14:22:28:837][    0.000833] Calibrating delay loop (skipped), value calculated using timer frequency.. 12.29 BogoMIPS (lpj=61475)
    [14:22:28:851][    0.000846] pid_max: default: 32768 minimum: 301
    [14:22:28:854][    0.000942] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
    [14:22:28:866][    0.000952] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
    [14:22:28:868][    0.001489] Initializing cgroup subsys io
    [14:22:28:879][    0.001506] Initializing cgroup subsys memory
    [14:22:28:879][    0.001531] Initializing cgroup subsys devices
    [14:22:28:880][    0.001544] Initializing cgroup subsys freezer
    [14:22:28:888][    0.001554] Initializing cgroup subsys perf_event
    [14:22:28:890][    0.001565] Initializing cgroup subsys pids
    [14:22:28:898][    0.001591] CPU: Testing write buffer coherency: ok
    [14:22:28:899][    0.001791] /cpus/cpu@0 missing clock-frequency property
    [14:22:28:908][    0.001807] /cpus/cpu@1 missing clock-frequency property
    [14:22:28:909][    0.001817] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
    [14:22:28:918][    0.001864] Setting up static identity map for 0x80008340 - 0x800083a0
    [14:22:28:918][    0.080085] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
    [14:22:28:919][    0.080154] Brought up 2 CPUs
    [14:22:28:929][    0.080167] SMP: Total of 2 processors activated (24.59 BogoMIPS).
    [14:22:28:930][    0.080173] CPU: All CPU(s) started in HYP mode.
    [14:22:28:942][    0.080179] CPU: Virtualization extensions available.
    [14:22:28:943][    0.081216] devtmpfs: initialized
    [14:22:28:951][    0.110718] VFP support v0.3: implementor 41 architecture 4 part 30 variant f rev 0
    [14:22:28:952][    0.111671] omap_hwmod: l3_main_2 using broken dt data from ocp
    [14:22:28:960][    0.226468] omap_hwmod: dcan1: _wait_target_disable failed
    [14:22:28:975][    0.323300] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
    [14:22:28:976][    0.323325] futex hash table entries: 512 (order: 3, 32768 bytes)
    [14:22:28:986][    0.325459] pinctrl core: initialized pinctrl subsystem
    [14:22:28:987][    0.326309] NET: Registered protocol family 16
    [14:22:28:997][    0.327284] DMA: preallocated 256 KiB pool for atomic coherent allocations
    [14:22:28:997][    0.350197] cpuidle: using governor ladder
    [14:22:29:009][    0.380221] cpuidle: using governor menu
    [14:22:29:009][    0.388897] OMAP GPIO hardware version 0.1
    [14:22:29:010][    0.393059] GPIO line 161 (radio_rst) hogged as output/low
    [14:22:29:016][    0.395467] irq: no irq domain found for /ocp/l4@4a000000/scm@2000/pinmux@1400 !
    [14:22:29:030][    0.419751] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
    [14:22:29:031][    0.419761] hw-breakpoint: maximum watchpoint size is 8 bytes.
    [14:22:29:040][    0.420261] omap4_sram_init:Unable to allocate sram needed to handle errata I688
    [14:22:29:054][    0.420271] omap4_sram_init:Unable to get sram pool needed to handle errata I688
    [14:22:29:055][    0.420756] OMAP DMA hardware revision 0.0
    [14:22:29:064][    0.461540] omap-dma-engine 4a056000.dma-controller: OMAP DMA engine driver (LinkedList1/2/3 supported)
    [14:22:29:066][    0.462694] edma 43300000.edma: memcpy is disabled
    [14:22:29:076][    0.467556] edma 43300000.edma: TI EDMA DMA engine driver
    [14:22:29:077][    0.472169] omap-iommu 40d01000.mmu: 40d01000.mmu registered
    [14:22:29:086][    0.472346] omap-iommu 40d02000.mmu: 40d02000.mmu registered
    [14:22:29:087][    0.472516] omap-iommu 58882000.mmu: 58882000.mmu registered
    [14:22:29:098][    0.472671] omap-iommu 55082000.mmu: 55082000.mmu registered
    [14:22:29:099][    0.472946] omap-iommu 41501000.mmu: 41501000.mmu registered
    [14:22:29:109][    0.473141] omap-iommu 41502000.mmu: 41502000.mmu registered
    [14:22:29:110][    0.476185] palmas 0-0058: IRQ missing: skipping irq request
    [14:22:29:120][    0.490664] palmas 0-0058: Muxing GPIO 51, PWM 0, LED 2
    [14:22:29:122][    0.541213] irq: no irq domain found for /ocp/i2c@48070000/tps65917@58 !
    [14:22:29:131][    0.541755] pcf857x: probe of 0-0020 failed with error -121
    [14:22:29:132][    0.542011] pcf857x: probe of 0-0021 failed with error -121
    [14:22:29:142][    0.542242] pcf857x: probe of 0-0026 failed with error -121
    [14:22:29:143][    0.542400] omap_i2c 48070000.i2c: bus 0 rev0.12 at 400 kHz
    [14:22:29:153][    0.542811] omap_i2c 48060000.i2c: bus 2 rev0.12 at 400 kHz
    [14:22:29:155][    0.560528] pcf857x: probe of 3-0021 failed with error -121
    [14:22:29:164][    0.560566] omap_i2c 4807a000.i2c: bus 3 rev0.12 at 400 kHz
    [14:22:29:165][    0.560760] media: Linux media interface: v0.10
    [14:22:29:176][    0.560809] Linux video capture interface: v2.00
    [14:22:29:177][    0.560847] pps_core: LinuxPPS API ver. 1 registered
    [14:22:29:186][    0.560854] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
    [14:22:29:187][    0.560877] PTP clock support registered
    [14:22:29:198][    0.560920] EDAC MC: Ver: 3.0.0
    [14:22:29:199][    0.561676] omap-mailbox 48840000.mailbox: omap mailbox rev 0x400
    [14:22:29:215][    0.561975] omap-mailbox 48842000.mailbox: omap mailbox rev 0x400
    [14:22:29:216][    0.562323] Advanced Linux Sound Architecture Driver Initialized.
    [14:22:29:227][    0.563190] clocksource: Switched to clocksource arch_sys_counter
    [14:22:29:228][    0.573556] NET: Registered protocol family 2
    [14:22:29:236][    0.574044] TCP established hash table entries: 4096 (order: 2, 16384 bytes)
    [14:22:29:237][    0.574085] TCP bind hash table entries: 4096 (order: 3, 32768 bytes)
    [14:22:29:246][    0.574152] TCP: Hash tables configured (established 4096 bind 4096)
    [14:22:29:247][    0.574191] UDP hash table entries: 256 (order: 1, 8192 bytes)
    [14:22:29:257][    0.574212] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes)
    [14:22:29:258][    0.574400] NET: Registered protocol family 1
    [14:22:29:265][    0.574654] RPC: Registered named UNIX socket transport module.
    [14:22:29:266][    0.574663] RPC: Registered udp transport module.
    [14:22:29:276][    0.574669] RPC: Registered tcp transport module.
    [14:22:29:277][    0.574676] RPC: Registered tcp NFSv4.1 backchannel transport module.
    [14:22:29:285][    0.575666] hw perfevents: enabled with armv7_cortex_a15 PMU driver, 7 counters available
    [14:22:29:298][    0.584645] squashfs: version 4.0 (2009/01/31) Phillip Lougher
    [14:22:29:299][    0.585279] NFS: Registering the id_resolver key type
    [14:22:29:300][    0.585305] Key type id_resolver registered
    [14:22:29:310][    0.585312] Key type id_legacy registered
    [14:22:29:311][    0.585378] ntfs: driver 2.1.32 [Flags: R/O].
    [14:22:29:321][    0.586778] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247)
    [14:22:29:322][    0.586797] io scheduler noop registered
    [14:22:29:332][    0.586809] io scheduler deadline registered
    [14:22:29:333][    0.586839] io scheduler cfq registered (default)
    [14:22:29:333][    0.589230] vsys_5v0: supplied by vsys_12v0
    [14:22:29:343][    0.589279] ldo3: supplied by vsys_5v0
    [14:22:29:344][    0.592931] pinctrl-single 4a003400.pinmux: 282 pins at pa fc003400 size 1128
    [14:22:29:352][    0.596218] PCI host bridge /ocp/axi@0/pcie_rc@51000000 ranges:
    [14:22:29:366][    0.596231]   No bus range found for /ocp/axi@0/pcie_rc@51000000, using [bus 00-ff]
    [14:22:29:367][    0.596265]    IO 0x20003000..0x20012fff -> 0x00000000
    [14:22:29:377][    0.596286]   MEM 0x20013000..0x2fffffff -> 0x20013000
    [14:22:29:378][    0.625821] dra7-pcie 51000000.pcie_rc: link is not up
    [14:22:29:389][    0.625986] dra7-pcie 51000000.pcie_rc: PCI host bridge to bus 0000:00
    [14:22:29:390][    0.625999] pci_bus 0000:00: root bus resource [bus 00-ff]
    [14:22:29:399][    0.626010] pci_bus 0000:00: root bus resource [io  0x0000-0xffff]
    [14:22:29:400][    0.626020] pci_bus 0000:00: root bus resource [mem 0x20013000-0x2fffffff]
    [14:22:29:411][    0.626430] PCI: bus0: Fast back to back transfers disabled
    [14:22:29:412][    0.626556] PCI: bus1: Fast back to back transfers enabled
    [14:22:29:423][    0.626638] pci 0000:00:00.0: BAR 0: assigned [mem 0x20100000-0x201fffff]
    [14:22:29:424][    0.626653] pci 0000:00:00.0: BAR 1: assigned [mem 0x20020000-0x2002ffff]
    [14:22:29:430][    0.626665] pci 0000:00:00.0: PCI bridge to [bus 01]
    [14:22:29:444][    0.626882] pcieport 0000:00:00.0: Signaling PME through PCIe PME interrupt
    [14:22:29:444][    0.687513] Serial: 8250/16550 driver, 10 ports, IRQ sharing disabled
    [14:22:29:445][    0.690867] console [ttyS0] disabled
    [14:22:29:453][    0.690919] 4806a000.serial: ttyS0 at MMIO 0x4806a000 (irq = 301, base_baud = 3000000) is a 8250
    [14:22:29:467][    1.706057] console [ttyS0] enabled
    [14:22:29:468][    1.710444] 4806c000.serial: ttyS1 at MMIO 0x4806c000 (irq = 302, base_baud = 3000000) is a 8250
    [14:22:29:477][    1.720141] 48020000.serial: ttyS2 at MMIO 0x48020000 (irq = 303, base_baud = 3000000) is a 8250
    [14:22:29:493][    1.729799] 4ae2b000.serial: ttyS9 at MMIO 0x4ae2b000 (irq = 304, base_baud = 3000000) is a 8250
    [14:22:29:494][    1.739845] [drm] Initialized drm 1.1.0 20060810
    [14:22:29:506][    1.745388] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
    [14:22:29:506][    1.752031] [drm] No driver support for vblank timestamp query.
    [14:22:29:512][    1.758198] [drm] Initialized vdrm 1.0.0 20110917 on minor 0
    [14:22:29:531][    1.771170] loop: module loaded
    [14:22:29:531][    1.777094] vmemexp device MAJOR num = 245
    [14:22:29:532][    1.781221] vmemexp class registered
    [14:22:29:545][    1.784956] /dev/vmemexp device registered
    [14:22:29:546][    1.789069] ioctl DBUFIOC_EXPORT_VIRTMEM = -1072899120
    [14:22:29:561][    1.797324] m25p80 spi32766.0: unrecognized JEDEC id bytes: 00,  0,  0
    [14:22:29:562][    1.805013] libphy: Fixed MDIO Bus: probed
    [14:22:29:613][    1.853222] davinci_mdio 48485000.mdio: davinci mdio revision 1.6
    [14:22:29:614][    1.859345] libphy: 48485000.mdio: probed
    [14:22:29:622][    1.866090] davinci_mdio 48485000.mdio: phy[1]: device 48485000.mdio:01, driver RTL9000A Gigabit Ethernet
    [14:22:29:637][    1.876356] cpsw 48484000.ethernet: Detected MACID = f8:36:9b:99:10:c0
    [14:22:29:639][    1.882998] cpsw 48484000.ethernet: cpts: overflow check period 800
    [14:22:29:648][    1.889997] cpsw 48484000.ethernet: cpsw: Detected MACID = f8:36:9b:99:10:c1
    [14:22:29:665][    1.898660] mousedev: PS/2 mouse device common for all mice
    [14:22:29:666][    1.904907] i2c /dev entries driver
    [14:22:29:678][    1.913634] omap_hsmmc 4809c000.mmc: Got CD GPIO
    [14:22:29:679][    1.918465] omap_hsmmc 4809c000.mmc: no pinctrl state for sdr104 mode
    [14:22:29:684][    1.924977] omap_hsmmc 4809c000.mmc: no pinctrl state for ddr50 mode
    [14:22:29:694][    1.931360] omap_hsmmc 4809c000.mmc: no pinctrl state for sdr50 mode
    [14:22:29:695][    1.937756] omap_hsmmc 4809c000.mmc: no pinctrl state for sdr25 mode
    [14:22:29:706][    1.944150] omap_hsmmc 4809c000.mmc: no pinctrl state for sdr12 mode
    [14:22:29:707][    1.950782] vsys_3v3: supplied by vsys_12v0
    [14:22:29:719][    1.955049] vio_3v3: supplied by vsys_3v3
    [14:22:29:720][    1.959106] vio_3v3_sd: supplied by vio_3v3
    [14:22:29:721][    1.964010] ldo4: supplied by vsys_5v0
    [14:22:29:768][    2.013620] omap_hsmmc 480b4000.mmc: no pinctrl state for sdr25 mode
    [14:22:29:776][    2.020004] omap_hsmmc 480b4000.mmc: no pinctrl state for sdr12 mode
    [14:22:29:794][    2.033508] smps5: supplied by vsys_3v3
    [14:22:29:795][    2.037593] vio_1v8: supplied by smps5
    [14:22:29:828][    2.074063] ledtrig-cpu: registered to indicate activity on CPUs
    [14:22:29:846][    2.085200] hwspinlock_user gatemp: requested 20 hwspinlocks
    [14:22:29:847][    2.092108] aic_dvdd: supplied by vio_3v3
    [14:22:29:859][    2.097392] davinci-mcasp 48464000.mcasp: DAI is shared
    [14:22:29:860][    2.103489] davinci-mcasp 48474000.mcasp: DAI is shared
    [14:22:29:866][    2.109965] NET: Registered protocol family 10
    [14:22:29:884][    2.125287] sit: IPv6 over IPv4 tunneling driver
    [14:22:29:885][    2.130475] NET: Registered protocol family 17
    [14:22:29:895][    2.135204] Key type dns_resolver registered
    [14:22:29:896][    2.139607] omap_voltage_late_init: Voltage driver support not added
    [14:22:29:908][    2.146495] Adding alias for supply vdd,cpu0 -> vdd,4a003b20.oppdm
    [14:22:29:909][    2.152703] Adding alias for supply vbb,cpu0 -> vbb,4a003b20.oppdm
    [14:22:29:918][    2.158997] buck10: supplied by vsys_3v3
    [14:22:29:919][    2.163546] Adding alias for supply vdd,cpu0 -> vdd,4a003b20.oppdm
    [14:22:29:932][    2.169753] Adding alias for supply vbb,cpu0 -> vbb,4a003b20.oppdm
    [14:22:29:933][    2.177510] Power Management for TI OMAP4+ devices.
    [14:22:29:944][    2.182545] Registering SWP/SWPB emulation handler
    [14:22:29:945][    2.188152] dmm 4e000000.dmm: workaround for errata i878 in use
    [14:22:29:958][    2.195192] dmm 4e000000.dmm: initialized all PAT entries
    [14:22:29:959][    2.201191] [drm] Initialized omapdrm 1.0.0 20110917 on minor 1
    [14:22:29:965][    2.208389] asoc-simple-card sound0: tlv320aic3x-hifi <-> 48468000.mcasp mapping ok
    [14:22:29:982][    2.227857] hctosys: unable to open rtc device (rtc0)
    [14:22:29:997][    2.230521] mmc0: host does not support reading read-only switch, assuming write-enable
    [14:22:29:998][    2.232552] mmc0: new high speed SDHC card at address 59b4
    [14:22:30:008][    2.242844] mmcblk0: mmc0:59b4 USD00 7.33 GiB 
    [14:22:30:009][    2.247265]  mmcblk0: p1 p2
    [14:22:30:026][    2.260655] aic_dvdd: disabling
    [14:22:30:026][    2.263969] ALSA device list:
    [14:22:30:027][    2.266945]   #0: DRA7xx-EVM
    [14:22:30:031][    2.271253] EXT4-fs (mmcblk0p2): couldn't mount as ext3 due to feature incompatibilities
    [14:22:30:046][    2.279899] EXT4-fs (mmcblk0p2): couldn't mount as ext2 due to feature incompatibilities
    [14:22:30:046][    2.286921] mmc1: MAN_BKOPS_EN bit is not set
    [14:22:30:058][    2.295742] mmc1: new HS200 MMC card at address 0001
    [14:22:30:065][    2.301014] mmcblk1: mmc1:0001 DG4008 7.28 GiB 
    [14:22:30:074][    2.305760] mmcblk1boot0: mmc1:0001 DG4008 partition 1 4.00 MiB
    [14:22:30:076][    2.311864] mmcblk1boot1: mmc1:0001 DG4008 partition 2 4.00 MiB
    [14:22:30:507][    2.749154] EXT4-fs (mmcblk0p2): recovery complete
    [14:22:30:522][    2.757225] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
    [14:22:30:522][    2.765391] VFS: Mounted root (ext4 filesystem) on device 179:2.
    [14:22:30:523][    2.772192] devtmpfs: mounted
    [14:22:30:539][    2.775360] Freeing unused kernel memory: 332K
    [14:22:30:539][    2.779819] This architecture does not have kernel memory protection.
    [14:22:30:734][    2.978285] systemd[1]: System time before build time, advancing clock.
    [14:22:30:793][    3.034285] random: systemd: uninitialized urandom read (16 bytes read, 18 bits of entropy available)
    [14:22:30:806][    3.047393] random: systemd: uninitialized urandom read (16 bytes read, 18 bits of entropy available)
    [14:22:30:830][    3.063880] systemd[1]: systemd 229 running in system mode. (+PAM -AUDIT -SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP -LIBCRYPTSETUP -GCRYPT +GNUTLS +ACL +XZ -LZ4 -SECCOMP +BLKID -ELFUTILS +KMOD -IDN)
    [14:22:30:847][    3.082421] systemd[1]: Detected architecture arm.
    [14:22:30:847]
    [14:22:30:847]Welcome to Arago 2016.12!
    [14:22:30:848]
    [14:22:30:864][    3.104064] systemd[1]: Set hostname to <dra7xx-evm>.
    [14:22:30:925][    3.169786] random: systemd-gpt-aut: uninitialized urandom read (16 bytes read, 19 bits of entropy available)
    [14:22:30:940][    3.180268] random: systemd-gpt-aut: uninitialized urandom read (16 bytes read, 19 bits of entropy available)
    [14:22:30:965][    3.206467] random: systemd-sysv-ge: uninitialized urandom read (16 bytes read, 19 bits of entropy available)
    [14:22:30:988][    3.228221] random: systemd-sysv-ge: uninitialized urandom read (16 bytes read, 20 bits of entropy available)
    [14:22:31:003][    3.243609] random: systemd-sysv-ge: uninitialized urandom read (16 bytes read, 20 bits of entropy available)
    [14:22:31:094][    3.338966] random: systemd: uninitialized urandom read (16 bytes read, 23 bits of entropy available)
    [14:22:31:105][    3.348435] random: systemd: uninitialized urandom read (16 bytes read, 23 bits of entropy available)
    [14:22:31:116][    3.358305] random: systemd: uninitialized urandom read (16 bytes read, 23 bits of entropy available)
    [14:22:31:428][    3.673821] systemd[1]: basic.target: Found ordering cycle on basic.target/start
    [14:22:31:443][    3.681275] systemd[1]: basic.target: Found dependency on sysinit.target/start
    [14:22:31:443][    3.688590] systemd[1]: basic.target: Found dependency on alignment.service/start
    [14:22:31:451][    3.696181] systemd[1]: basic.target: Found dependency on basic.target/start
    [14:22:31:462][    3.703306] systemd[1]: basic.target: Breaking ordering cycle by deleting job alignment.service/start
    [14:22:31:474][    3.712579] systemd[1]: alignment.service: Job alignment.service/start deleted to break ordering cycle starting with basic.target/start
    [14:22:31:481][ SKIP ] Ordering cycle found, skipping alignment.service
    [14:22:31:507][    3.745378] systemd[1]: Listening on udev Control Socket.
    [14:22:31:508][  OK  ] Listening on udev Control Socket.
    [14:22:31:538][    3.775882] systemd[1]: Created slice User and Session Slice.
    [14:22:31:539][  OK  ] Created slice User and Session Slice.
    [14:22:31:559][    3.803483] systemd[1]: Listening on /dev/initctl Compatibility Named Pipe.
    [14:22:31:567][  OK  ] Listening on /dev/initctl Compatibility Named Pipe.
    [14:22:31:588][    3.833537] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
    [14:22:31:597][  OK  ] Started Dispatch Password Requests to Console Directory Watch.
    [14:22:31:624][    3.863937] systemd[1]: Created slice System Slice.
    [14:22:31:625][  OK  ] Created slice System Slice.
    [14:22:31:656][    3.894007] systemd[1]: Created slice system-getty.slice.
    [14:22:31:657][  OK  ] Created slice system-getty.slice.
    [14:22:31:678][    3.923981] systemd[1]: Created slice system-serial\x2dgetty.slice.
    [14:22:31:684][  OK  ] Created slice system-serial\x2dgetty.slice.
    [14:22:31:720][    3.964934] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
    [14:22:31:728][  OK  ] Started Forward Password Requests to Wall Directory Watch.
    [14:22:31:754][    3.993387] systemd[1]: Reached target Paths.
    [14:22:31:755][  OK  ] Reached target Paths.
    [14:22:31:775][    4.013387] systemd[1]: Reached target Remote File Systems.
    [14:22:31:777][  OK  ] Reached target Remote File Systems.
    [14:22:31:804][    4.043376] systemd[1]: Reached target Swap.
    [14:22:31:805][  OK  ] Reached target Swap.
    [14:22:31:818][    4.063578] systemd[1]: Listening on Network Service Netlink Socket.
    [14:22:31:825][  OK  ] Listening on Network Service Netlink Socket.
    [14:22:31:848][    4.093497] systemd[1]: Listening on Journal Socket (/dev/log).
    [14:22:31:854][  OK  ] Listening on Journal Socket (/dev/log).
    [14:22:31:886][    4.123433] systemd[1]: Listening on Syslog Socket.
    [14:22:31:887][  OK  ] Listening on Syslog Socket.
    [14:22:31:905][    4.143485] systemd[1]: Listening on Journal Socket.
    [14:22:31:906][  OK  ] Listening on Journal Socket.
    [14:22:31:953][    4.193386] systemd[1]: Mounting Debug File System...
    [14:22:31:954]         Mounting Debug File System...
    [14:22:31:981][    4.218438] systemd[1]: Starting Load Kernel Modules...
    [14:22:31:982]         Starting Load Kernel Modules...
    [14:22:32:004][    4.245665] systemd[1]: Starting Create list of required static device nodes for the current kernel...
    [14:22:32:014]         Starting Create list of required st... nodes for the current kernel...
    [14:22:32:075][    4.313397] systemd[1]: Mounting Temporary Directory...
    [14:22:32:076]         Mounting Temporary Directory...
    [14:22:32:108][    4.345509] systemd[1]: Starting Journal Service...
    [14:22:32:109]         Starting Journal Service...
    [14:22:32:139][    4.375572] systemd[1]: Mounting POSIX Message Queue File System...
    [14:22:32:140]         Mounting POSIX Message Queue File System...
    [14:22:32:169][    4.406442] systemd[1]: Starting Setup Virtual Console...
    [14:22:32:170]         Starting Setup Virtual Console...
    [14:22:32:191][    4.435717] systemd[1]: Starting Remount Root and Kernel File Systems...
    [14:22:32:214]         Starting Remount Root and Kernel File Systems...[    4.454819] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
    [14:22:32:215]
    [14:22:32:236][    4.473512] systemd[1]: Listening on udev Kernel Socket.
    [14:22:32:238][  OK  ] Listening on udev Kernel Socket.
    [14:22:32:254][    4.493697] systemd[1]: Reached target Slices.
    [14:22:32:255][  OK  ] Reached target Slices.
    [14:22:32:309][    4.548103] systemd[1]: Mounted Debug File System.
    [14:22:32:310][  OK  ] Mounted Debug File System.
    [14:22:32:328][    4.573517] systemd[1]: Mounted POSIX Message Queue File System.
    [14:22:32:336][  OK  ] Mounted POSIX Message Queue File System.
    [14:22:32:366][    4.603422] systemd[1]: Mounted Temporary Directory.
    [14:22:32:367][  OK  ] Mounted Temporary Directory.
    [14:22:32:385][    4.623605] systemd[1]: Started Journal Service.
    [14:22:32:386][  OK  ] Started Journal Service.
    [14:22:32:401][FAILED] Failed to start Load Kernel Modules.
    [14:22:32:418]See 'systemctl status systemd-modules-load.service' for details.
    [14:22:32:443][  OK  ] Started Create list of required sta...ce nodes for the current kernel.
    [14:22:32:470][  OK  ] Started Setup Virtual Console.
    [14:22:32:490][  OK  ] Started Remount Root and Kernel File Systems.
    [14:22:32:747]         Starting udev Coldplug all Devices...
    [14:22:32:770]         Starting Create Static Device Nodes in /dev...
    [14:22:32:790]         Starting Apply Kernel Variables...
    [14:22:32:815]         Starting Flush Journal to Persistent Storage...
    [14:22:32:899][  OK  ] Started Apply Kernel Variables.
    [14:22:32:920][  OK  ] Started Create Static Device Nodes in /dev.
    [14:22:33:002][    5.244329] systemd-journald[127]: Received request to flush runtime journal from PID 1
    [14:22:33:017][  OK  ] Started Flush Journal to Persistent Storage.
    [14:22:33:057][  OK  ] Reached target Local File Systems (Pre).
    [14:22:33:107]         Mounting /media/ram...
    [14:22:33:134]         Mounting /var/volatile...
    [14:22:33:165]         Starting udev Kernel Device Manager...
    [14:22:33:195][  OK  ] Mounted /var/volatile.
    [14:22:33:217][  OK  ] Mounted /media/ram.
    [14:22:33:248][  OK  ] Started udev Kernel Device Manager.
    [14:22:33:272][  OK  ] Started udev Coldplug all Devices.
    [14:22:33:392][    5.635622] omap-rproc 58820000.ipu: assigned reserved memory node ipu1_cma@9a000000
    [14:22:33:404][    5.651652]  remoteproc0: 58820000.ipu is available
    [14:22:33:441][    5.683304]  remoteproc0: Note: remoteproc is still under development and considered experimental.
    [14:22:33:476][    5.718323]  remoteproc0: THE BINARY FORMAT IS NOT YET FINALIZED, and backward compatibility isn't yet guaranteed.
    [14:22:33:514][    5.757262] omap-rproc 55020000.ipu: assigned reserved memory node ipu2_cma@96000000
    [14:22:33:531][    5.777101]  remoteproc1: 55020000.ipu is available
    [14:22:33:544][    5.791226]  remoteproc0: registered virtio0 (type 7)
    [14:22:33:567][  OK  ] Found device /dev/ttyS0.[    5.801604]  remoteproc1: Note: remoteproc is still under development and considered experimental.
    [14:22:33:568]
    [14:22:33:594][    5.835873]  remoteproc1: THE BINARY FORMAT IS NOT YET FINALIZED, and backward compatibility isn't yet guaranteed.
    [14:22:33:603][  OK  ] Reached target Local File Systems.
    [14:22:33:622][    5.867616] omap-des 480a5000.des: OMAP DES hw accel rev: 2.2
    [14:22:33:644][    5.888869] omap_rng 48090000.rng: OMAP Random Number Generator ver. 20
    [14:22:33:685]         Starting Create Volatile Files and Directories...
    [14:22:33:700]         Starting Load/Save Random Seed...
    [14:22:33:832][  OK  ] Started Load/Save Random Seed.
    [14:22:33:862][  OK  ] Started Create Volatile Files and Directories.
    [14:22:33:913][    6.160003] omap-sham 4b101000.sham: hw accel on OMAP rev 4.3
    [14:22:33:931]         Starting Network Time Synchronization...
    [14:22:33:954]         Starting Update UTMP about System Boot/Shutdown...
    [14:22:34:131][    6.379417] SCSI subsystem initialized
    [14:22:34:211][    6.457359]  remoteproc1: registered virtio1 (type 7)
    [14:22:34:278][    6.521420] omap-aes 4b500000.aes: OMAP AES hw accel rev: 3.3
    [14:22:34:284][    6.529597] omap-aes 4b700000.aes: OMAP AES hw accel rev: 3.3
    [14:22:34:332][  OK  ] Reached target Sound Card.
    [14:22:34:379][  OK  ] Started Update UTMP about System Boot/Shutdown.
    [14:22:34:445][  OK  ] Started Network Time Synchronization.
    [14:22:34:642][  OK  ] Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
    [14:22:34:667][  OK  ] Reached target System Time Synchronized.
    [14:22:34:712][    6.956819] [drm] Initialized pvr 1.14.3699939 20110701 on minor 2
    [14:22:34:730][    6.963530] ahci 4a140000.sata: SSS flag set, parallel bus scan disabled
    [14:22:34:731][    6.972323] ahci 4a140000.sata: AHCI 0001.0300 32 slots 1 ports 3 Gbps 0x1 impl platform mode
    [14:22:34:738]         Starting Synchronize System and HW clocks...
    [14:22:34:746][    6.988382] ahci 4a140000.sata: flags: 64bit ncq sntf stag pm led clo only pmp pio slum part ccc apst 
    [14:22:34:766][FAILED] Failed to start Synchronize System and HW clocks.
    [14:22:34:767][    7.011226] scsi host0: ahci
    [14:22:34:786][    7.018689] ata1: SATA max UDMA/133 mmio [mem 0x4a140000-0x4a1410ff] port 0x100 irq 342
    [14:22:34:787]See 'systemctl status sync-clocks.service' for details.
    [14:22:34:841][    7.081584]  remoteproc0: powering up 58820000.ipu
    [14:22:34:847][    7.092008]  remoteproc0: Booting fw image dra7-ipu1-fw.xem4, size 614132
    [14:22:34:871][    7.113381] omap-iommu 58882000.mmu: 58882000.mmu: version 2.1
    [14:22:34:886][    7.132499]  remoteproc0: remote processor 58820000.ipu is now up
    [14:22:34:907][    7.143671] virtio_rpmsg_bus virtio0: rpmsg host is online
    [14:22:34:907][    7.150599]  remoteproc1: powering up 55020000.ipu
    [14:22:34:934][    7.178648]  remoteproc1: Booting fw image dra7-ipu2-fw.xem4, size 7282956
    [14:22:34:953][    7.199144] omap-iommu 55082000.mmu: 55082000.mmu: version 2.1
    [14:22:34:988][    7.229374] FAT-fs (mmcblk0p1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
    [14:22:35:029][    7.269016]  remoteproc1: remote processor 55020000.ipu is now up
    [14:22:35:048][    7.294115] virtio_rpmsg_bus virtio1: rpmsg host is online
    [14:22:35:080][    7.322910] virtio_rpmsg_bus virtio1: creating channel rpmsg-proto addr 0x50
    [14:22:35:088][    7.333368] virtio_rpmsg_bus virtio0: creating channel rpmsg-proto addr 0x50
    [14:22:35:110][    7.356515] NET: Registered protocol family 41
    [14:22:35:127][    7.373276] ata1: SATA link down (SStatus 0 SControl 300)
    [14:22:35:241][  OK  ] Reached target System Initialization.
    [14:22:35:260][  OK  ] Listening on D-Bus System Message Bus Socket.
    [14:22:35:277][  OK  ] Reached target Sockets.
    [14:22:35:298][  OK  ] Started Daily Cleanup of Temporary Directories.
    [14:22:35:317][  OK  ] Reached target Timers.
    [14:22:35:337][  OK  ] Reached target Basic System.
    [14:22:35:421]         Starting rc.pvr.service...
    [14:22:35:565][    7.807499] usbcore: registered new interface driver usbfs
    [14:22:35:566][    7.813614] usbcore: registered new interface driver hub
    [14:22:35:583][    7.819504] usbcore: registered new device driver usb
    [14:22:35:584][  OK  ] Started System Logging Service.
    [14:22:35:600][  OK  ] Started Kernel Logging Service.
    [14:22:35:619]         Starting Permit User Sessions...
    [14:22:35:642][  OK  ] Started D-Bus System Message Bus.
    [14:22:35:712][    7.956391] PVR_K: UM DDK-(3699939) and KM DDK-(3699939) match. [ OK ]
    [14:22:35:724][    7.970119] xhci-hcd xhci-hcd.2.auto: xHCI Host Controller
    [14:22:35:738][    7.981345] xhci-hcd xhci-hcd.2.auto: new USB bus registered, assigned bus number 1
    [14:22:35:754][    7.999670] xhci-hcd xhci-hcd.2.auto: hcc params 0x0220f04c hci version 0x100 quirks 0x00210010
    [14:22:35:769][    8.008489] xhci-hcd xhci-hcd.2.auto: irq 462, io mem 0x488d0000
    [14:22:35:770][    8.015429] hub 1-0:1.0: USB hub found
    [14:22:35:780][    8.019221] hub 1-0:1.0: 1 port detected
    [14:22:35:781][    8.023542] xhci-hcd xhci-hcd.2.auto: xHCI Host Controller
    [14:22:35:795][    8.029073] xhci-hcd xhci-hcd.2.auto: new USB bus registered, assigned bus number 2
    [14:22:35:796][    8.039397] usb usb2: We don't know the algorithms for LPM for this host, disabling LPM.
    [14:22:35:806][    8.048812] hub 2-0:1.0: USB hub found
    [14:22:35:808][    8.052620] hub 2-0:1.0: 1 port detected
    [14:22:35:876]         Starting Network Service...
    [14:22:35:899]         Starting Save/Restore Sound Card State...
    [14:22:35:918]         Starting Login Service...
    [14:22:35:940][  OK  ] Started rc.pvr.service.
    [14:22:35:963][    8.205815] net eth1: initializing cpsw version 1.15 (0)
    [14:22:35:964][   8.211375] net eth0: initialized cpsw ale version 1.4
    [14:22:35:972][    8.216693] net eth0: ALE Table size 1024
    [14:22:35:988][  OK  ] Started Permit User Sessions.[    8.224109] libphy: PHY 48485000.mdio:03 not found
    [14:22:35:988]
    [14:22:35:989][    8.230613] net eth1: phy "48485000.mdio:03" not found on slave 1, err -19
    [14:22:36:003][    8.244573] IPv6: ADDRCONF(NETDEV_UP): eth1: link is not ready
    [14:22:36:004][  OK  ] Started Save/Restore Sound Card State.
    [14:22:36:022][    8.252391] net eth0: initializing cpsw version 1.15 (0)
    [14:22:36:022][  OK  ] Started Network Service.
    [14:22:36:181][  OK  ] Reached target Network.
    [14:22:36:182][    8.425146] net eth0: phy found : id is : 0x1ccb00
    [14:22:36:193][    8.439377] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
    [14:22:36:236]         Starting Network Name Resolution...
    [14:22:36:258][  OK  ] Started Getty on tty1.
    [14:22:36:280][  OK  ] Started Serial Getty on ttyS0.
    [14:22:36:298]         Starting weston.service...
    [14:22:36:320]         Starting LSB: Dropbear Secure Shell server...
    [14:22:36:343][  OK  ] Started Network Name Resolution.
    [14:22:36:358][  OK  ] Started weston.service.
    [14:22:36:377][  OK  ] Started Login Service.
    [14:22:36:399][  OK  ] Started LSB: Dropbear Secure Shell server.
    [14:22:36:487]         Starting tiipclad-daemon.service...
    [14:22:36:509]         Starting telnetd.service...
    [14:22:36:529][  OK  ] Started tiipclad-daemon.service.
    [14:22:36:547][  OK  ] Started telnetd.service.
    [14:22:36:656]         Starting ecarxinit.service...
    [14:22:36:708][    8.945171] DMA: Module install successful, device major num = 242 
    [14:22:36:709][    8.951473] DRV: Module install successful
    [14:22:37:322][    9.568400] omap_l3_noc 44000000.ocp: L3 application error: target 3 mod:2 (unclearable)
    [14:22:37:332][    9.576570] omap_l3_noc 44000000.ocp: L3 debug error: target 3 mod:2 (unclearable)
    [14:22:42:552]
    [14:22:42:579] _____                    _____           _         _   
    [14:22:42:580]|  _  |___ ___ ___ ___   |  _  |___ ___  |_|___ ___| |_ 
    [14:22:42:590]|     |  _| .'| . | . |  |   __|  _| . | | | -_|  _|  _|
    [14:22:42:591]|__|__|_| |__,|_  |___|  |__|  |_| |___|_| |___|___|_|  
    [14:22:42:601]              |___|                    |___|            
    [14:22:42:601]
    [14:22:42:601]Arago Project http://arago-project.org dra7xx-evm ttyS0
    [14:22:42:601]
    [14:22:42:602]Arago 2016.12 dra7xx-evm ttyS0
    [14:22:42:607]
    [14:22:45:165]dra7xx-evm login: root
    [14:22:46:217]root@dra7xx-evm:~# 
    [14:22:46:382]root@dra7xx-evm:~# 
    [14:22:46:592]root@dra7xx-evm:~# 
    [14:22:46:764]root@dra7xx-evm:~# 
    

  • I see that the total memory that you are using itself is 512MB. Correct me if I am wrong.
    In that case, having lowmem 512M is fine.

    To check the reserved mem regions, I request you to upload your DTS file or a DTB file for Linux kernel.

    Regards,
    Nikhil D
  • Hi Nikhil D:

       Yes, for our board, 512M in total. the memory footprint is like:

    and the modified DTS and DTB is here

    4278.dts.rar

  • Hi,

    You seem to have lot of memory footprint. Total 512M and out of that multiple chunks are reserved for vision SDK.. More than half of total memory.

    When does the issue occur? Are you running something else on Linux?

    Regards

    Nikhil D

  • Nikhil Devshatwar said:
    You seem to have lot of memory footprint. Total 512M and out of that multiple chunks are reserved for vision SDK.. More than half of total memory.

     Yes, for Linux is about 300M, and after linux launched, 200M remains. even we change the memory footprint like following, the issue still existed. (one chunk memory for Linux)

    Nikhil Devshatwar said:
    When does the issue occur? Are you running something else on Linux?

      we're using sgxfrmcpy to implement the surround view(AVM), the issue happened when we start the apps.out.(occasionally).

    For now, as stated above, we change the  "sg_alloc_table(sgt, nr, GFP_KERNEL)" 0 to GFP_KERNEL, then issue is fixed.

  • Glad to know that the GFP_KERNEL solved the issue.

    What was it before?

    Regards,

    Nikhil D

  • HI Nikhil D:

      

    Nikhil Devshatwar said:
    What was it before?

      It was 0. when go through driver source code, most of all prefer the GFP_KERNEL, so we try it and it works.

    1.  Can you share more why not use the GFP_KERNEL flag in vmemexport?
    2.   Should be a bug?

  • Hi,

    GFP_KERNEL is expected flag in such kind of allocations.

    You are right. This should be a bug. Thanks for pointing out.

    Regards,

    Nikhil D