6 Replies Latest reply on Mar 16, 2016 4:01 AM by r.venderbosch@tis-gmbh.de

    TC75: EMDK service unstable / failure to create DataWedge profile

    r.venderbosch@tis-gmbh.de

      Hello.

       

      We are experiencing major problems with the EMDK service and the DataWedge service.

       

      In our applications on the TC75 we are using some EMDK APIs, for example to create the DataWedge profile for barcode scanning, to set the system time, to disable the BT pairing dialogue and to install or upgrade APKs.

      Sometimes, after a number of successful EMDK API calls, any further API call does not execute correctly anymore.

      We then have to warm boot the TC75 to get EMDK API calls working again.

       

      Another problem we recently see on TC75 devices here on our devices but also on customers devices, is that DataWedge profiles are sometimes not created successfully.

      For example after a manual reset of the DataWedge profiles, the Velocity profile is sometimes not created again when the Velocity application is started.

       

      To investigate these problems with a simple application I compiled the "ProfileDataCapture" sample (from Data Capture - Zebra Technologies Online Documentation) and tested it on my TC75.

      After several times starting and leaving the sample application I could reproduce a permanent error.The application always displays "Profile initialization failed" when started.

      In logcat I see these entries:

       

      03-15 13:28:50.981 7319-7319/? D/com.symbol.emdk.emdkservice.barcode.SvcScanEventCallback: SvcScanEventCallback::barcodeManager

      03-15 13:28:50.981 7319-7319/? D/dd:BT:: SvcBluetoothScanner::registerConnectionNotification

      03-15 13:28:50.981 7319-7319/? D/dd:BT:: SvcBluetoothScanner::unregisterConnectionNotification

      03-15 13:28:50.981 7319-7319/? D/com.symbol.emdk.emdkservice.EMDKService: The EMDKService was created.

      03-15 13:28:50.981 7319-7319/? D/com.symbol.emdk.emdkservice.EMDKService: The AIDLProfileService was binded.

      03-15 13:28:50.981 7319-7319/? D/com.symbol.emdk.emdkservice.MxServiceConnection: Binding Mx srvice

      03-15 13:28:50.981 13335-13335/com.symbol.profiledatacapturesample1 D/com.symbol.emdk.EMDKServiceConnection: The EMDK Service will be connected soon (asynchronus call)!

      03-15 13:28:50.991 7319-7319/? D/com.symbol.emdk.emdkservice.ProfileService: getVersion - Entering

      03-15 13:28:50.991 7319-7319/? D/com.symbol.emdk.emdkservice.ProfileService: getVersion - Leaving

      03-15 13:28:50.991 7319-7319/? D/EmdkService: EMDK Version=4.0.2.0

      03-15 13:28:50.991 7319-7319/? D/MxVersionHandler: MxVersionHandler Constructor

      03-15 13:28:50.991 945-945/? D/PhoneStatusBar: setSystemUiVisibility vis=0 mask=ffffffff oldVal=400 newVal=0 diff=400

      03-15 13:28:50.991 945-945/? D/PhoneStatusBar: hiding the MENU button

      03-15 13:28:51.001 13335-13335/com.symbol.profiledatacapturesample1 D/com.symbol.emdk.EMDKServiceConnection: The EMDK Service is now connected!

      03-15 13:28:51.011 7319-8409/? D/com.symbol.emdk.emdkservice.ProfileService: initializeProfileService - starts

      03-15 13:28:51.011 7319-8409/? D/com.symbol.emdk.emdkservice.ProfileHandler: ProfileHandler - Entering

      03-15 13:28:51.032 7319-8409/? D/com.symbol.emdk.emdkservice.ProfileHandler: ProfileHandler - Leaving

      03-15 13:28:51.032 7319-8409/? D/com.symbol.emdk.emdkservice.ProfileService: initializeProfileService - ends

      03-15 13:28:51.062 13335-13335/com.symbol.profiledatacapturesample1 E/HAL: hw_get_module_by_class path = /system/lib/hw/gralloc.msm8960.so

      03-15 13:28:51.092 7319-9849/? D/com.symbol.emdk.emdkservice.ProfileHandler: createProfile - Entering

      03-15 13:28:51.092 7319-9849/? D/com.symbol.emdk.emdkservice.ProfileHandler: createProfile - profileName=DataCaptureProfile-1

      03-15 13:28:51.092 7319-9849/? D/com.symbol.emdk.emdkservice.ProfileHandler: createProfile - profileNameCriteria.length=1

      03-15 13:28:51.092 7319-9849/? D/com.symbol.emdk.emdkservice.ProfileHandler: profileNameCriteria.length>1 else block

      03-15 13:28:51.092 7319-9849/? D/com.symbol.emdk.emdkservice.ProfileHandler: isBarcodePresentInProfile - Enetring

      03-15 13:28:51.102 7319-9849/? D/com.symbol.emdk.emdkservice.ProfileHandler: isBarcodePresentInProfile - Before expr.evaluate

      03-15 13:28:51.102 13335-13335/com.symbol.profiledatacapturesample1 I/ActivityManager: Timeline: Activity_idle id: android.os.BinderProxy@41d72b28 time:12936676

      03-15 13:28:51.112 808-892/? I/ActivityManager: Displayed com.symbol.profiledatacapturesample1/.MainActivity: +188ms

      03-15 13:28:51.122 7319-9849/? D/com.symbol.emdk.emdkservice.ProfileHandler: isBarcodePresentInProfile - After expr.evaluate

      03-15 13:28:51.122 7319-9849/? D/com.symbol.emdk.emdkservice.ProfileHandler: isBarcodePresentInProfile - result!=null

      03-15 13:28:51.122 7319-9849/? D/com.symbol.emdk.emdkservice.ProfileHandler: isBarcodePresentInProfile - After profileNode.getParentNode().getChildNodes()

      03-15 13:28:51.122 7319-9849/? D/com.symbol.emdk.emdkservice.ProfileHandler: isBarcodePresentInProfile - Leaving

      03-15 13:28:51.122 7319-9849/? D/com.symbol.emdk.emdkservice.ProfileHandler: isBarcodePresentInProfile=true

      03-15 13:28:51.122 7319-9849/? D/com.symbol.emdk.emdkservice.ProfileHandler: isMxPresentInProfile - Enetring

      03-15 13:28:51.122 7319-9849/? D/com.symbol.emdk.emdkservice.ProfileHandler: isMxPresentInProfile - Before expr.evaluate

      03-15 13:28:51.142 7319-9849/? D/com.symbol.emdk.emdkservice.ProfileHandler: isMxPresentInProfile - After expr.evaluate

      03-15 13:28:51.142 7319-9849/? D/com.symbol.emdk.emdkservice.ProfileHandler: isMxPresentInProfile - result!=null

      03-15 13:28:51.142 7319-9849/? D/com.symbol.emdk.emdkservice.ProfileHandler: isMxPresentInProfile - After profileNode.getParentNode().getChildNodes()

      03-15 13:28:51.142 7319-9849/? D/com.symbol.emdk.emdkservice.ProfileHandler: isMxPresentInProfile - Leaving

      03-15 13:28:51.142 7319-9849/? D/com.symbol.emdk.emdkservice.ProfileHandler: >>>creating a profile<<<

      03-15 13:28:51.162 7319-9849/? D/com.symbol.emdk.emdkservice.ProfileHandler: >>>check if profile is found<<<

      03-15 13:28:51.162 7319-9849/? D/com.symbol.emdk.emdkservice.ProfileHandler: >>>Creating a profile from XML only<<<

      03-15 13:28:51.162 7319-9849/? D/com.symbol.emdk.emdkservice.DatabaseHelper: exportProfileToDB Entering

      03-15 13:28:51.232 1217-17614/? E/AndroidRuntime: ERROR: thread detach failed

      03-15 13:28:51.272 808-892/? I/ActivityManager: Timeline: Activity_windows_visible id: ActivityRecord{41ad5ef0 u0 com.symbol.profiledatacapturesample1/.MainActivity t102} time:12936847

      03-15 13:28:51.322 1217-1217/? E/Image-JNI: Imager enable true..

      03-15 13:28:51.432 189-17741/? E/mm-camera: [CAM] calibration file did NOT exist!!!

      03-15 13:28:51.432 189-17741/? W/linker: libmmcamera_faceproc.so has text relocations. This is wasting memory and is a security risk. Please fix.

      03-15 13:28:51.442 1217-1217/? E/ImagerControl: TransferI2C mIOControlFunction Failed retry

      03-15 13:28:51.512 1217-1217/? E/QualCommAdapter: ISS v4lInitMmap Success

      03-15 13:28:51.542 1217-1217/? D/dalvikvm: GC_FOR_ALLOC freed 1833K, 40% free 6810K/11228K, paused 29ms, total 29ms

      03-15 13:28:51.542 1217-1217/? D/libimgkit: sysflags 38

      03-15 13:28:51.552 1217-1217/? E/SE4750Control: PERF IC-Acquisition Mode +

      03-15 13:28:51.562 1217-1217/? E/ImagerControl: TransferI2C mIOControlFunction Failed retry

      03-15 13:28:51.572 1217-1217/? I/Image-JNI: LogDebugLevel=1

      03-15 13:28:51.582 1217-1217/? D/ScanningProfile: enabling SimulScan plug-in

      03-15 13:28:53.684 7319-9849/? E/SQLiteLog: (5) database is locked

      03-15 13:28:53.684 7319-9849/? E/SQLiteDatabase: Failed to open database '/enterprise/device/settings/datawedge/autoimport/dwprofile_DataCaptureProfile-1.tmp'.

                                                       android.database.sqlite.SQLiteDatabaseLockedException: database is locked (code 5): , while compiling: PRAGMA journal_mode

                                                           at android.database.sqlite.SQLiteConnection.nativePrepareStatement(Native Method)

                                                           at android.database.sqlite.SQLiteConnection.acquirePreparedStatement(SQLiteConnection.java:889)

                                                           at android.database.sqlite.SQLiteConnection.executeForString(SQLiteConnection.java:634)

                                                           at android.database.sqlite.SQLiteConnection.setJournalMode(SQLiteConnection.java:320)

                                                           at android.database.sqlite.SQLiteConnection.setWalModeFromConfiguration(SQLiteConnection.java:294)

                                                           at android.database.sqlite.SQLiteConnection.open(SQLiteConnection.java:215)

                                                           at android.database.sqlite.SQLiteConnection.open(SQLiteConnection.java:193)

                                                           at android.database.sqlite.SQLiteConnectionPool.openConnectionLocked(SQLiteConnectionPool.java:463)

                                                           at android.database.sqlite.SQLiteConnectionPool.open(SQLiteConnectionPool.java:185)

                                                           at android.database.sqlite.SQLiteConnectionPool.open(SQLiteConnectionPool.java:177)

                                                           at android.database.sqlite.SQLiteDatabase.openInner(SQLiteDatabase.java:804)

                                                           at android.database.sqlite.SQLiteDatabase.open(SQLiteDatabase.java:789)

                                                           at android.database.sqlite.SQLiteDatabase.openDatabase(SQLiteDatabase.java:694)

                                                           at android.database.sqlite.SQLiteDatabase.openDatabase(SQLiteDatabase.java:669)

                                                           at com.symbol.emdk.emdkservice.DatabaseHelper.exportProfileToDB(DatabaseHelper.java:140)

                                                           at com.symbol.emdk.emdkservice.ProfileHandler.createProfile(ProfileHandler.java:1588)

                                                           at com.symbol.emdk.emdkservice.ProfileHandler.doSetProfile(ProfileHandler.java:1083)

                                                           at com.symbol.emdk.emdkservice.ProfileService.setProfile(ProfileService.java:325)

                                                           at com.symbol.emdk.emdkservice.IEMDKService$Stub.onTransact(IEMDKService.java:81)

                                                           at android.os.Binder.execTransact(Binder.java:404)

                                                           at dalvik.system.NativeStart.run(Native Method)

      03-15 13:28:53.684 7319-9849/? W/System.err: android.database.sqlite.SQLiteDatabaseLockedException: database is locked (code 5): , while compiling: PRAGMA journal_mode

      03-15 13:28:53.684 7319-9849/? W/System.err:     at android.database.sqlite.SQLiteConnection.nativePrepareStatement(Native Method)

      03-15 13:28:53.684 7319-9849/? W/System.err:     at android.database.sqlite.SQLiteConnection.acquirePreparedStatement(SQLiteConnection.java:889)

      03-15 13:28:53.684 7319-9849/? W/System.err:     at android.database.sqlite.SQLiteConnection.executeForString(SQLiteConnection.java:634)

      03-15 13:28:53.684 7319-9849/? W/System.err:     at android.database.sqlite.SQLiteConnection.setJournalMode(SQLiteConnection.java:320)

      03-15 13:28:53.684 7319-9849/? W/System.err:     at android.database.sqlite.SQLiteConnection.setWalModeFromConfiguration(SQLiteConnection.java:294)

      03-15 13:28:53.684 7319-9849/? W/System.err:     at android.database.sqlite.SQLiteConnection.open(SQLiteConnection.java:215)

      03-15 13:28:53.684 7319-9849/? W/System.err:     at android.database.sqlite.SQLiteConnection.open(SQLiteConnection.java:193)

      03-15 13:28:53.684 7319-9849/? W/System.err:     at android.database.sqlite.SQLiteConnectionPool.openConnectionLocked(SQLiteConnectionPool.java:463)

      03-15 13:28:53.684 7319-9849/? W/System.err:     at android.database.sqlite.SQLiteConnectionPool.open(SQLiteConnectionPool.java:185)

      03-15 13:28:53.684 7319-9849/? W/System.err:     at android.database.sqlite.SQLiteConnectionPool.open(SQLiteConnectionPool.java:177)

      03-15 13:28:53.684 7319-9849/? W/System.err:     at android.database.sqlite.SQLiteDatabase.openInner(SQLiteDatabase.java:804)

      03-15 13:28:53.684 7319-9849/? W/System.err:     at android.database.sqlite.SQLiteDatabase.open(SQLiteDatabase.java:789)

      03-15 13:28:53.684 7319-9849/? W/System.err:     at android.database.sqlite.SQLiteDatabase.openDatabase(SQLiteDatabase.java:694)

      03-15 13:28:53.684 7319-9849/? W/System.err:     at android.database.sqlite.SQLiteDatabase.openDatabase(SQLiteDatabase.java:669)

      03-15 13:28:53.684 7319-9849/? W/System.err:     at com.symbol.emdk.emdkservice.DatabaseHelper.exportProfileToDB(DatabaseHelper.java:140)

      03-15 13:28:53.684 7319-9849/? W/System.err:     at com.symbol.emdk.emdkservice.ProfileHandler.createProfile(ProfileHandler.java:1588)

      03-15 13:28:53.684 7319-9849/? W/System.err:     at com.symbol.emdk.emdkservice.ProfileHandler.doSetProfile(ProfileHandler.java:1083)

      03-15 13:28:53.684 7319-9849/? W/System.err:     at com.symbol.emdk.emdkservice.ProfileService.setProfile(ProfileService.java:325)

      03-15 13:28:53.684 7319-9849/? W/System.err:     at com.symbol.emdk.emdkservice.IEMDKService$Stub.onTransact(IEMDKService.java:81)

      03-15 13:28:53.684 7319-9849/? W/System.err:     at android.os.Binder.execTransact(Binder.java:404)

      03-15 13:28:53.684 7319-9849/? W/System.err:     at dalvik.system.NativeStart.run(Native Method)

      03-15 13:28:54.135 169-905/? D/ALSADevice: standby: handle 0xb7a91720 h 0x0

      03-15 13:28:54.135 169-905/? V/ALSADevice: standby handle h 0xb7aa8f90

       

      It looks like that there is a lock on the SQLite database for DataWedge profiles.

       

      In another case I got a message box on the screen indicating that EMDK service had stopped.

       

      Device data:

      Device 'TC75'

      Android version '4.4.3'

      Kernel version '3.4.0'

      Build Id '01-23257-K-14-04-00-MV'

      MX Framework: 5.0.10

      EMDK service: 4.0.2.0

      DataWedge: 3.1.40

      Imager firmware: PAABVC02-001-R00

       

      How do we get these problems fixed?

        • Re: TC75: EMDK service unstable / failure to create DataWedge profile
          Bill Hecox

          Hello Richard, So no changes were made to the ProfileDataCapture sample code other than profile changes, and you were still able to duplicate this issue?

            • Re: TC75: EMDK service unstable / failure to create DataWedge profile
              r.venderbosch@tis-gmbh.de

              The sample application has not been changed in anyway.

               

              We can reliably reproduce the "Profile initialization failed" error message by starting the application immediately after rebooting the TC75.

              But this is not the permanent error which I got earlier this day.

              In this case when I close the application (with back key or by removing it from the recent apps list) and start it again then profile initialization is successful.

              So is rather a timing issue. Waiting several seconds (say 30 seconds) after reboot and before start of the sample application does not produce this error.

              But at the customer our application is automatically started after reboot by the launcher. Thus even this "transient" and non-fatal issue is a serious problem for the customer because he can not use the scanner as intended.

               

              The other issues are not that easily to reproduce.

                • Re: TC75: EMDK service unstable / failure to create DataWedge profile
                  Pietro Maggi

                  Hi Richard,

                  Mx takes some time to be ready after device boot.

                   

                  If you plan to have your application running at device boot, your best option is to use EMDK v4.0 and use the Async method to retrieve a reference to the Profile Manager with:

                   

                  // Get the ProfileManager object to process the profiles
                  try {
                    emdkManager.getInstanceAsync(EMDKManager.FEATURE_TYPE.PROFILE, this);
                  } catch (EMDKException e) {
                    e.printStackTrace();
                  }
                  

                  and to apply the profile with the processProfileAsync()  registering a DataListerner to get called by the ProfileManager at the end of this operation: profileManager.addDataListener

                   

                   

                  Let us know if you need a modified sample using the Async modality.

                  4451621.jpg

                  Best regards

                  ~Pietro

                    • Re: TC75: EMDK service unstable / failure to create DataWedge profile
                      r.venderbosch@tis-gmbh.de

                      Hello Pietro.

                       

                      Yes, I would like to get a modified sample.

                       

                      Does the Wavelink Velocity application also use this new API method?

                      I ask because - as I wrote earlier - we observe problems with Velocity sometimes not creating the DataWedge profile.

                        • Re: TC75: EMDK service unstable / failure to create DataWedge profile
                          r.venderbosch@tis-gmbh.de

                          Hello.

                           

                          I managed to get the sample application modified to use the async method to request access to the ProfileManager.

                          Now profile initialization succeeds after every reboot.

                           

                          But nevertheless I still can get the permanent issue with the SQLite database lock:

                           

                          03-16 10:55:12.433 1921-1931/? E/SQLiteLog: (5) database is locked

                          03-16 10:55:12.453 1921-1931/? E/SQLiteDatabase: Failed to open database '/enterprise/device/settings/datawedge/autoimport/dwprofile_DataCaptureProfile-1.tmp'.

                                                                           android.database.sqlite.SQLiteDatabaseLockedException: database is locked (code 5): , while compiling: PRAGMA journal_mode

                          ....

                           

                          To reproduce the database lock exception I just have start and stop the sample application several times in short succession.

                           

                          As soon as the TC75 (or the EMDK service) is in this state, the sample application is not able to recreate its DataWedge profile.

                           

                          And this seems to have an impact on other applications too which themselves are not able to create DataWedge profiles anymore.

                          At least this is what I currently observe with our own application:

                           

                          03-16 11:58:27.992 3937-3937/? D/TisLogMobileZebraExecMn: OnBroadcastIntent (de.tisgmbh.tislog.mobile.emdkexec.intent.action.ACTION_SET_SCANNER_PARAMS)

                          03-16 11:58:27.992 3937-3937/? D/TisLogMobileZebraExecSt: Setting standard scanning parameters (profile: 'TisBarcodeScanning' application: 'de.tisgmbh.tislog.mobile.app' activity: 'MobiApp')

                          03-16 11:58:28.242 3937-3937/? D/TisLogMobileZebraExecSt: EMDK profile manager result FAILURE

                      • Re: TC75: EMDK service unstable / failure to create DataWedge profile
                        Bill Hecox

                        There is a known issue when trying to use the EMDK directly after boot, and a new API call has been added to EMDK for Android 4.0 to address this issue. Refer to #9 of the Description section in the release notes for version 4.0 Release Notes - EMDK for Android v4.0

                         

                        You should use EMDKManager.getInstanceAsync instead of EMDKManager.getInstance if your application is to be launched directly on boot.