Crash of MPE client when trying to sync calendar (watchdog?)

Anmeldedatum: 18.02.2015 Beiträge: 2

Hello all,

when trying to get my phone and pc to synchronize, the android client dies when the process is almost completed.

Current setup:
win8.1 running Outlook 2010
MyPhoneExplorer 1.8.6
Samsung Galaxy S3 mini (GT-I8190) running Android 4.1.2
MPE client 1.0.34

I can connect via either bluetooth, wifi or usb cable, this works fine.
When syncing my agenda, the process runs almost to completion and then the MPE client dies. The client does restart however and then waits for a new connection. The PC side keeps trying for some time and then finally reports a timeout

Can anyone of you tell me what is going on and give me any hints on what to do to fix this ?
please let me know if you need more info. (I have both original debug.txt and AndroidDebug.txt available)

thanks for your help !

---------------------------------------------
debug.txt

Logdatei MyPhoneExplorer
************************
Programmversion: 1.8.6
Datum: 18-2-2015

21:13:47.59 Setting Port: 999
21:13:47.59 Setting Baud: 115200
21:13:47.59 Avaiable Ports: COM3=\Device\BthModem0; COM4=\Device\ssudmdm0000;
21:13:47.59 Main Load frmSplash
21:13:47.61 Load frmSplash...
21:13:47.81 Hauptfenster wird geladen
21:13:47.91 Sidebar fertig geladen
21:13:47.95 UC SMS wird geladen
21:13:47.99 UC Phonebook wird geladen
21:13:48.02 UC Phonebook fertig geladen
21:13:48.02 UC Calls wird geladen
21:13:48.03 UC Organizer wird geladen
21:13:48.08 Grid sorted: 0 Rows, Time: 0
21:13:48.09 Organizer initiated
21:13:48.09 Startpage=1
21:13:48.09 UC Filebrowser wird geladen
21:13:48.13 Cleardetails...
21:13:48.13 Cleardetails fertig
21:13:48.13 UC Filebrowser fertig geladen
21:13:48.13 UC AppBrowser wird geladen
21:13:48.13 UC Notes wird geladen
21:13:48.14 UC Calls wird geladen
21:13:48.17 Setting Lastuser: samsung GT-I8190 [359077053118290]
21:13:48.17 Lade Userdatenbank: samsung GT-I8190 [359077053118290]
21:13:48.25 Before loading Phonebook.dat
21:13:48.25 LoadDatafile: pb_metadata.xml(3469 Bytes)
21:13:48.27 LoadDatafile: Phonebook.dat(85494 Bytes)
21:13:48.27 Splitted and reformated contactdata (3354 lines)
21:13:48.33 Contactdata imported, 444 Items added
21:13:48.33 TempLuids reassigned
21:13:48.33 CheckGroups
21:13:48.33 CheckGroups ende
21:13:48.33 Phonebook.dat was loaded
21:13:48.33 Grid sorted: 0 Rows, Time: 0
21:13:48.33 SIM Contacts were loaded
21:13:48.33 RefreshSearchArray (ExactCompare=False)
21:13:48.33 RefreshSearchArray completed
21:13:48.33 Searcharray was refreshed
21:13:48.47 Grid sorted: 444 Rows, Time: 0
21:13:48.49 Contactlist was refreshed
21:13:48.50 Phonebook was loaded for User
21:13:48.50 Kontakte geladen
21:13:48.50 LoadDatafile: Calls.dat(1002 Bytes)
21:13:48.50 ParseDialedCalls needed 0ms
21:13:48.53 Grid sorted: 22 Rows, Time: 0
21:13:48.55 Grid sorted: 11 Rows, Time: 0
21:13:48.55 Grid sorted: 10 Rows, Time: 0
21:13:48.55 Grid sorted: 3 Rows, Time: 0
21:13:48.55 Anrufe geladen
21:13:48.55 Organizer LoadUser DefaultTimeColWidth=114
21:13:48.56 LoadDatafile: Organizer.dat(45 Bytes)
21:13:48.56 LoadDatafile: cal_metadata.xml(1215 Bytes)
21:13:48.56 Grid sorted: 0 Rows, Time: 0
21:13:48.56 Grid sorted: 0 Rows, Time: 0
21:13:48.56 Organizer geladen
21:13:48.56 Grid sorted: 0 Rows, Time: 0
21:13:48.56 Notizen geladen
21:13:48.56 Load SMS Data...
21:13:48.58 Grid sorted: 0 Rows, Time: 0
21:13:48.58 Grid sorted: 0 Rows, Time: 0
21:13:48.58 Grid sorted: 0 Rows, Time: 0
21:13:48.58 Grid sorted: 0 Rows, Time: 0
21:13:48.58 RefreshList (Archive): Addrows=0 Sort=0 MenuUpdate=0 Redraw=0
21:13:48.58 SMS Data Loaded...
21:13:48.58 SMS geladen
21:13:48.69 Hauptfenster fertig geladen
21:13:48.70 GotAppCommand: debug-OK

21:13:48.83 Init Android Connection for future connect via USB
21:13:48.83 RunADBCommand: start-server
21:13:49.05 Downloader: RC=6 BytesMax=5 URL=http://www.fjsoft.at/myphoneexplorer/version.txt
21:13:52.91 ADB CommandResponse:
21:13:52.91 Run DeviceTracker
21:13:52.93 Init Tracker
21:13:52.94 Device Tracker Message: OKAY00184790d00fbd36901a device

21:13:52.94 Init Android Connection for future connect via WiFi
21:13:52.94 Start UPnP Discovery
21:13:52.94 Broadcaster started
21:13:52.99 UPnP Device: IBHR-PC: installatieburo@roumen.net:
21:13:53.48 UPnP Device: WDMyCloud
21:13:53.71 UPnP Device: IC-C37315
21:13:53.85 UPnP Device: VGV7519 WFA-WCN Device
21:13:54.13 UPnP Device: WDMyCloud
21:13:54.90 Closing Broadcaster
21:13:54.90 RunADBCommand: start-server
21:13:54.96 ADB CommandResponse:
21:13:54.96 RunADBCommand: devices
21:13:55.02 ADB CommandResponse: List of devices attached
4790d00fbd36901a device
21:13:55.10 RunADBCommand: -s "4790d00fbd36901a" forward tcp:5210 tcp:5210
21:13:55.15 ADB CommandResponse:
21:13:55.15 Try connecting to 127.0.0.1...
21:13:55.16 Socket closed
21:13:55.16 RunADBCommand: -s "4790d00fbd36901a" shell am start -n com.fjsoft.myphoneexplorer.client/.MainActivity --ez adb true --ez debug true
21:13:57.10 ADB CommandResponse: Starting: Intent { cmp=com.fjsoft.myphoneexplorer.client/.MainActivity (has extras) }
21:13:57.26 Try launch USB connection
21:13:57.27 Socket closed
21:13:57.57 Try launch USB connection
21:13:57.69 Connect to Android OK (127.0.0.1)
21:13:57.69 Settimeout: RT=2000 WT=500
21:13:57.69 bOpened=True
21:13:57.69 [TX]: AT+CGSN
21:13:57.73 [RX]: AT+CGSN
21:13:57.73 [RX]: 359077053118290
21:13:57.73 [RX]: OK
21:13:57.73 Settimeout: RT=15000 WT=1000
21:13:57.73 [TX]: AT*PIN=4f9d778a72f4314c4f701b5d4df5668d
21:13:57.76 [RX]: AT*PIN=4f9d778a72f4314c4f701b5d4df5668d
21:13:57.76 [RX]: *PIN: ACCESS OK,10
21:13:57.76 [RX]: OK
21:13:57.76 [TX]: ATI
21:13:57.79 [RX]: ATI
21:13:57.79 [RX]: samsung GT-I8190
21:13:57.79 [RX]: OK
21:13:57.79 [TX]: AT*APPVERSION=1.8.6
21:13:57.82 [RX]: AT*APPVERSION=1.8.6
21:13:57.82 [RX]: 16,1.0.34
21:13:57.82 [RX]: OK
21:13:57.82 [TX]: AT+CSCS="UTF-8"
21:13:57.85 [RX]: AT+CSCS="UTF-8"
21:13:57.85 [RX]: OK
21:13:57.85 [TX]: AT*ECAM=1
21:13:57.88 [RX]: AT*ECAM=1
21:13:57.88 [RX]: OK
21:13:57.88 [TX]: AT+CBC
21:13:57.91 [RX]: AT+CBC
21:13:57.91 [RX]: +CBC: 1,83
21:13:57.91 [RX]: OK
21:13:57.91 [TX]: AT+CSQ
21:13:57.94 [RX]: AT+CSQ
21:13:57.94 [RX]: +CSQ: 99,99
21:13:57.94 [RX]: OK
21:13:57.94 Alle Verbindungsaktionen beendet
21:14:07.94 Settimeout: RT=3500 WT=800
21:14:07.94 [TX]: AT+CBC
21:14:07.97 [RX]: AT+CBC
21:14:07.97 [RX]: +CBC: 1,84
21:14:07.97 [RX]: OK
21:14:07.97 [TX]: AT+CSQ
21:14:08.00 [RX]: AT+CSQ
21:14:08.00 [RX]: +CSQ: 99,99
21:14:08.00 [RX]: OK
21:14:18.00 [TX]: AT+CBC
21:14:18.03 [RX]: AT+CBC
21:14:18.03 [RX]: +CBC: 1,84
21:14:18.03 [RX]: OK
21:14:18.03 [TX]: AT+CSQ
21:14:18.06 [RX]: AT+CSQ
21:14:18.06 [RX]: +CSQ: 99,99
21:14:18.06 [RX]: OK
21:14:27.30 DoItemUpdate
21:14:27.31 DoItemUpdate fertig
21:14:28.06 [TX]: AT+CBC
21:14:28.09 [RX]: AT+CBC
21:14:28.09 [RX]: +CBC: 1,84
21:14:28.09 [RX]: OK
21:14:28.09 [TX]: AT+CSQ
21:14:28.12 [RX]: AT+CSQ
21:14:28.12 [RX]: +CSQ: 99,99
21:14:28.12 [RX]: OK
21:14:30.61 fSync.DoSync Operation=7
21:14:30.61 fSync: Wait for frmSplash.bChecking=False
21:14:30.61 fSync Check Connection
21:14:30.61 Settimeout: RT=15000 WT=1000
21:14:30.61 [TX]: AT+CBC
21:14:30.64 [RX]: AT+CBC
21:14:30.64 [RX]: +CBC: 1,84
21:14:30.64 [RX]: OK
21:14:30.65 fSync Show Window
21:14:30.67 Form_Activate fSync Operation=7
21:14:30.68 pSyncOrgWithApp...
21:14:30.68 Sync MPE<>Phone...
21:14:30.70 [TX]: AT+CPROT=0
21:14:30.73 [RX]: AT+CPROT=0
21:14:30.73 [RX]: CONNECT
21:14:30.73 OBEX Connect: 16384 Bytes Paketgröße, Target: IRMC-SYNC
21:14:30.73 [TX]: 80 00 13 10 00 40 00 46 00 0C 49 52 4D 43 2D 53 59 4E 43
21:14:31.17 [RX]: A0 00 18 10 00 FF FF CB 00 00 00 01 4A 00 0C 49 52 4D 43 2D 53 59 4E 43
21:14:31.17 Connection ID:1
21:14:31.17 Paketgröße: 16384, maximal möglich:65535
21:14:31.17 OBEX Connected...
21:14:31.17 Ermittle und verarbeite info.log
21:14:31.17 Settimeout: RT=20000 WT=10000
21:14:31.17 OBEX Get: telecom/cal/info.log
21:14:31.17 [TX]: 83 00 35 CB 00 00 00 01 01 00 2D 00 74 00 65 00 6C 00 65 00 63 00 6F 00 6D 00 2F 00 63 00 61 00 6C 00 2F 00 69 00 6E 00 66 00 6F 00 2E 00 6C 00 6F 00 67 00 00
21:14:32.59 [RX]: A0 00 19 49 00 16 54 6F 74 61 6C 2D 52 65 63 6F 72 64 73 3A 32 36 36 31 35
21:14:32.59 ObexGet Fertig, Returncode=A0
21:14:32.59 Info.log:
Total-Records:26615
21:14:32.59 Settimeout: RT=90000 WT=10000
21:14:32.59 OBEX Get: telecom/cal/initsync
21:14:32.59 [TX]: 83 00 35 CB 00 00 00 01 01 00 2D 00 74 00 65 00 6C 00 65 00 63 00 6F 00 6D 00 2F 00 63 00 61 00 6C 00 2F 00 69 00 6E 00 69 00 74 00 73 00 79 00 6E 00 63 00 00
21:14:38.04 [RX]: 90 00 12 48 00 0F 0D 0A 32 30 32 30 2F 32 36 36 31 35
21:14:38.04 [TX]: 83 00 03
21:14:43.19 [RX]: 90 00 12 48 00 0F 0D 0A 35 30 32 30 2F 32 36 36 31 35
21:14:43.19 [TX]: 83 00 03
21:14:48.21 [RX]: 90 00 12 48 00 0F 0D 0A 38 33 30 30 2F 32 36 36 31 35
21:14:48.21 [TX]: 83 00 03
21:14:54.43 [RX]: 90 00 13 48 00 10 0D 0A 31 31 30 32 30 2F 32 36 36 31 35
21:14:54.43 [TX]: 83 00 03
21:14:59.45 [RX]: 90 00 13 48 00 10 0D 0A 31 33 38 30 30 2F 32 36 36 31 35
21:14:59.45 [TX]: 83 00 03
21:15:04.48 [RX]: 90 00 13 48 00 10 0D 0A 31 36 30 32 30 2F 32 36 36 31 35
21:15:04.48 [TX]: 83 00 03
21:15:09.50 [RX]: 90 00 13 48 00 10 0D 0A 31 38 36 34 30 2F 32 36 36 31 35
21:15:09.50 [TX]: 83 00 03
21:15:14.50 [RX]: 90 00 13 48 00 10 0D 0A 32 31 33 34 30 2F 32 36 36 31 35
21:15:14.50 [TX]: 83 00 03
21:15:19.51 [RX]: 90 00 13 48 00 10 0D 0A 32 34 32 30 30 2F 32 36 36 31 35
21:15:19.51 [TX]: 83 00 03
21:15:24.08 [RX]: 90 00 13 48 00 10 0D 0A 32 36 36 31 35 2F 32 36 36 31 35
21:15:24.08 [TX]: 83 00 03
21:16:54.07 [RX]: 00
21:16:54.07 Lesevorgang fehlerhaft! - Systemerror: 0 [De bewerking is voltooid.]
21:16:54.07 ObexGet Fertig, Returncode=0
21:16:54.07 OBEX Errorcode: 00 - Phone didn't answer, Timeout
21:16:54.07 ErrMsg: OBEX Errorcode: 00 - Phone didn't answer, Timeout
21:17:57.82 Socket closed
21:17:57.82 CheckCOM did not work, force closing Socket
21:17:57.82 Port wurde geschlossen
21:20:49.73 Sync MPE<>Phone fertig
21:20:49.73 Grid sorted: 0 Rows, Time: 0
21:20:49.73 DoItemUpdate
21:20:49.75 DoItemUpdate fertig
----------------------------------------------------------------------------

AndroidDebug.txt (tail section)

WAIT_FOR_CONCURRENT_GC blocked 0ms

[ 02-18 21:06:35.564 12156:19271 D/dalvikvm ]
GC_EXPLICIT freed 245K, 14% free 9617K/11143K, paused 3ms+4ms, total 36ms

[ 02-18 21:06:35.804 17008:17016 I/dalvikvm-heap ]
Clamp target GC heap from 72.002MB to 64.000MB

[ 02-18 21:06:35.804 17008:17016 D/dalvikvm ]
GC_FOR_ALLOC freed 0K, 2% free 64519K/65543K, paused 286ms, total 286ms

[ 02-18 21:06:35.804 17008:17016 I/dalvikvm-heap ]
Clamp target GC heap from 64.002MB to 64.000MB

[ 02-18 21:06:35.804 17008:17016 I/dalvikvm-heap ]
Grow heap (frag case) to 64.000MB for 144-byte allocation

[ 02-18 21:06:36.114 2025: 3907 D/dalvikvm ]
WAIT_FOR_CONCURRENT_GC blocked 0ms

[ 02-18 21:06:36.114 17008:17016 I/dalvikvm-heap ]
Clamp target GC heap from 72.002MB to 64.000MB

[ 02-18 21:06:36.114 17008:17016 D/dalvikvm ]
GC_FOR_ALLOC freed 0K, 2% free 64519K/65543K, paused 314ms, total 314ms

[ 02-18 21:06:36.114 17008:17016 I/dalvikvm-heap ]
Clamp target GC heap from 64.002MB to 64.000MB

[ 02-18 21:06:36.114 17008:17016 I/dalvikvm-heap ]
Grow heap (frag case) to 64.000MB for 16-byte allocation

[ 02-18 21:06:36.114 17008:19729 D/dalvikvm ]
WAIT_FOR_CONCURRENT_GC blocked 2036ms

[ 02-18 21:06:36.114 17008:19729 I/dalvikvm-heap ]
Clamp target GC heap from 64.002MB to 64.000MB

[ 02-18 21:06:36.114 17008:19729 I/dalvikvm-heap ]
Grow heap (frag case) to 64.000MB for 78-byte allocation

[ 02-18 21:06:36.204 2025: 2207 E/Watchdog ]
!@Sync 15101

[ 02-18 21:06:36.334 2025: 3907 D/dalvikvm ]
GC_EXPLICIT freed 74K, 62% free 29464K/75719K, paused 12ms+21ms, total 228ms

[ 02-18 21:06:36.404 17008:19729 I/dalvikvm-heap ]
Clamp target GC heap from 72.002MB to 64.000MB

[ 02-18 21:06:36.404 17008:19729 D/dalvikvm ]
GC_FOR_ALLOC freed 0K, 2% free 64519K/65543K, paused 285ms, total 285ms

[ 02-18 21:06:36.404 17008:19729 I/dalvikvm-heap ]
Clamp target GC heap from 64.002MB to 64.000MB

[ 02-18 21:06:36.404 17008:19729 I/dalvikvm-heap ]
Grow heap (frag case) to 64.000MB for 24-byte allocation

[ 02-18 21:06:36.404 17008:17027 D/dalvikvm ]
WAIT_FOR_CONCURRENT_GC blocked 2326ms

[ 02-18 21:06:36.404 17008:17027 I/dalvikvm-heap ]
Clamp target GC heap from 64.002MB to 64.000MB

[ 02-18 21:06:36.404 17008:17027 I/dalvikvm-heap ]
Grow heap (frag case) to 64.000MB for 48-byte allocation

[ 02-18 21:06:36.695 17008:17027 I/dalvikvm-heap ]
Clamp target GC heap from 72.002MB to 64.000MB

[ 02-18 21:06:36.695 17008:17027 D/dalvikvm ]
GC_FOR_ALLOC freed <1K, 2% free 64519K/65543K, paused 297ms, total 297ms

[ 02-18 21:06:36.695 17008:17027 I/dalvikvm-heap ]
Clamp target GC heap from 64.002MB to 64.000MB

[ 02-18 21:06:36.695 17008:17027 I/dalvikvm-heap ]
Grow heap (frag case) to 64.000MB for 80-byte allocation

[ 02-18 21:06:36.915 12156:12157 D/dalvikvm ]
GC_CONCURRENT freed 278K, 13% free 9784K/11143K, paused 13ms+4ms, total 36ms

[ 02-18 21:06:36.995 17008:17027 I/dalvikvm-heap ]
Clamp target GC heap from 72.002MB to 64.000MB

[ 02-18 21:06:36.995 17008:17027 D/dalvikvm ]
GC_FOR_ALLOC freed <1K, 2% free 64519K/65543K, paused 293ms, total 293ms

[ 02-18 21:06:36.995 17008:17027 I/dalvikvm-heap ]
Clamp target GC heap from 64.002MB to 64.000MB

[ 02-18 21:06:36.995 17008:17027 I/dalvikvm-heap ]
Grow heap (frag case) to 64.000MB for 20-byte allocation

[ 02-18 21:06:37.045 2025: 3174 D/dalvikvm ]
WAIT_FOR_CONCURRENT_GC blocked 0ms

[ 02-18 21:06:37.265 17008:17027 I/dalvikvm-heap ]
Clamp target GC heap from 72.002MB to 64.000MB

[ 02-18 21:06:37.265 17008:17027 D/dalvikvm ]
GC_FOR_ALLOC freed 0K, 2% free 64519K/65543K, paused 275ms, total 275ms

[ 02-18 21:06:37.265 17008:17027 I/dalvikvm-heap ]
Clamp target GC heap from 64.002MB to 64.000MB

[ 02-18 21:06:37.265 17008:17027 I/dalvikvm-heap ]
Grow heap (frag case) to 64.000MB for 48-byte allocation

[ 02-18 21:06:37.265 17008:17039 D/dalvikvm ]
WAIT_FOR_CONCURRENT_GC blocked 3191ms

[ 02-18 21:06:37.265 17008:17039 I/dalvikvm-heap ]
Clamp target GC heap from 64.002MB to 64.000MB

[ 02-18 21:06:37.265 17008:17039 I/dalvikvm-heap ]
Grow heap (frag case) to 64.000MB for 100-byte allocation

[ 02-18 21:06:37.285 2025: 3174 D/dalvikvm ]
GC_EXPLICIT freed 74K, 62% free 29465K/75719K, paused 7ms+21ms, total 236ms

[ 02-18 21:06:37.355 12156:19271 D/dalvikvm ]
WAIT_FOR_CONCURRENT_GC blocked 0ms

Anmeldedatum: 18.02.2015 Beiträge: 2

although I'm new to Andoid app programming, it seems that an out of memory is causing the apps crash (from logging : Clamp target GC heap from 64.002MB to 64.000MB )

Does anybody know of a way to prevent or circumvent this ? Is there a way to 'slow down' on memory usage (e.g. syncing incrementally, saller intervals etc.)
THe actual amount of free memory in the phone does not seem to be the bottleneck (appox. 300 megs free)

Informationen zum Datenschutz auf dieser Website