--------- beginning of /dev/log/system 02-09 14:16:47.197 D/ActivityManager( 1375): Starting: Intent { cmp=com.verizon.ams.tesla/com.verizon.mediamanager.AudioItemList (has extras) } from pid 16259 --------- beginning of /dev/log/main 02-09 14:16:47.799 D/mediamanager(16259): start getting album items pageNo #1 02-09 14:16:47.893 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:16:47.893 I/LAB126 ( 1442): window changed 02-09 14:16:48.135 I/ActivityManager( 1375): Displayed com.verizon.ams.tesla/com.verizon.mediamanager.AudioItemList: +933ms 02-09 14:16:48.510 D/mediamanager(16259): HTTP get http://www22.verizon.com/M3/svc/auth/mediaservice.svc/com/users/UserName/albums/05f16538-62aa-476e-8afd-9e2bf19aa742?bGetAlbums=false&fmt=xml&ftype=3&sortorder=DESC&SortBy=UploadDate&pageNo=1&pageSize=250&nonull=true&Enc=1&dojo.preventCache=1264392598150 02-09 14:16:48.588 D/dalvikvm(16259): GC_FOR_MALLOC freed 1624K, 44% free 5447K/9607K, external 6795K/8057K, paused 30ms 02-09 14:16:48.783 W/ResponseProcessCookies(16259): Cookie rejected: "BasicClientCookie[version=0,name=ak-sf,domain=verizon.com,path=/m3/,expiry=Thu Feb 09 14:21:48 CST 2012]". Illegal path attribute "/m3/". Path of origin: "/M3/svc/auth/mediaservice.svc/com/users/UserName/albums/05f16538-62aa-476e-8afd-9e2bf19aa742" 02-09 14:16:48.994 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:16:48.994 I/LAB126 ( 1442): window changed 02-09 14:16:54.877 D/vzAnalytics(16259): Moved 4 events from thread 1 to bg thread. bg thread pending events 4 02-09 14:16:54.877 D/vzAnalytics(16259): Saving log to db on thread 11 for 4 events 02-09 14:16:55.143 D/vzAnalytics(16259): WiFi:true, CellData:false 02-09 14:16:55.143 D/vzAnalytics(16259): Enqueuing server log task. 02-09 14:16:55.143 D/vzAnalytics(16259): Running server log task on thread 11 for 1 events. url :http://www22.verizon.com/clickStream/Tracker.svc/xml/async/postmetrics 02-09 14:16:55.330 D/vzAnalytics(16259): deleting events after server log. 02-09 14:16:55.393 I/vzAnalytics(16259): complete server log task. success :true 02-09 14:16:55.393 D/vzAnalytics(16259): Scheduling db and net save task 02-09 14:16:57.252 I/MSV (16259): send downloading event 02-09 14:16:57.713 D/mediamanager(16259): intent received com.verizon.flexview.mediamanager.action_audio_play 02-09 14:16:57.728 W/InputManagerService( 1375): Window already focused, ignoring focus gain of: com.android.internal.view.IInputMethodClient$Stub$Proxy@4077d7a8 02-09 14:16:58.150 D/dalvikvm( 1375): GC_CONCURRENT freed 2079K, 49% free 6272K/12103K, external 4301K/5371K, paused 3ms+8ms 02-09 14:16:58.314 W/ASFDummyExtractor( 1294): ASF parser is not available 02-09 14:16:58.314 E/MPEG4Extractor( 1294): both mdat,ftyp not found 02-09 14:16:58.322 D/dalvikvm( 1375): GC_CONCURRENT freed 2409K, 52% free 5836K/12103K, external 4301K/5371K, paused 2ms+4ms 02-09 14:16:58.361 D/Omap4ALSA( 1294): open called for devices 00000002 in mode 0 channels 00000000... 02-09 14:16:58.369 I/Omap4ALSA( 1294): Using ping-pong! 02-09 14:16:58.369 I/Omap4ALSA( 1294): Buffer size: 4096 02-09 14:16:58.369 I/Omap4ALSA( 1294): Latency: 92879 02-09 14:16:58.424 I/Omap4ALSA( 1294): Initialized ALSA PLAYBACK device 'plughw:0,0' 02-09 14:16:58.424 E/AudioHardwareALSA( 1294): RE-OPEN AFTER STANDBY:: took 67 msecs 02-09 14:16:58.471 D/dalvikvm( 1375): GC_CONCURRENT freed 1862K, 52% free 5839K/12103K, external 4301K/5371K, paused 2ms+4ms 02-09 14:16:58.627 D/dalvikvm( 1375): GC_CONCURRENT freed 1872K, 52% free 5826K/12103K, external 4301K/5371K, paused 3ms+7ms 02-09 14:16:58.783 D/dalvikvm( 1375): GC_CONCURRENT freed 1853K, 52% free 5834K/12103K, external 4301K/5371K, paused 3ms+4ms 02-09 14:16:58.939 D/dalvikvm( 1375): GC_CONCURRENT freed 1847K, 52% free 5850K/12103K, external 4301K/5371K, paused 2ms+4ms 02-09 14:16:59.088 D/dalvikvm( 1375): GC_CONCURRENT freed 1859K, 52% free 5858K/12103K, external 4301K/5371K, paused 3ms+4ms 02-09 14:16:59.221 D/dalvikvm( 1375): GC_CONCURRENT freed 1913K, 52% free 5814K/12103K, external 4301K/5371K, paused 3ms+4ms 02-09 14:16:59.307 D/dalvikvm( 1375): GC_CONCURRENT freed 1839K, 52% free 5829K/12103K, external 4301K/5371K, paused 3ms+4ms 02-09 14:17:02.736 I/LAB126 ( 1442): open notifications from tap in the status bar, child count: 6 02-09 14:17:02.869 D/dalvikvm( 1442): GC_CONCURRENT freed 907K, 50% free 3622K/7111K, external 3607K/3851K, paused 2ms+5ms 02-09 14:17:02.900 D/dalvikvm( 1442): GC_EXTERNAL_ALLOC freed 48K, 50% free 3574K/7111K, external 3607K/3851K, paused 32ms 02-09 14:17:03.150 D/LAB126 ( 1442): expand softkeys 02-09 14:17:03.275 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:17:03.275 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:17:03.275 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:17:03.275 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:17:03.275 D/IconMerger( 1442): notification for com.android.systemui (1) 02-09 14:17:03.275 D/IconMerger( 1442): sum of notifications: 5 02-09 14:17:05.533 D/ActivityManager( 1375): Starting: Intent { flg=0x4000000 cmp=com.verizon.ams.tesla/.ui.TabDownloadsActivity bnds=[0,400][600,510] (has extras) } from pid -1 02-09 14:17:05.533 W/ActivityManager( 1375): startActivity called from non-Activity context; forcing Intent.FLAG_ACTIVITY_NEW_TASK for: Intent { flg=0x4000000 cmp=com.verizon.ams.tesla/.ui.TabDownloadsActivity bnds=[0,400][600,510] (has extras) } 02-09 14:17:05.533 D/LAB126 ( 1442): collapsing softkeys because notification closing. 02-09 14:17:05.533 D/LAB126 ( 1442): collapse softkeys 02-09 14:17:05.611 W/ResourceType(16259): Skipping entry 0x7f02015d in package table 0 because it is not complex! 02-09 14:17:05.611 W/ResourceType(16259): Skipping entry 0x7f02015d in package table 0 because it is not complex! 02-09 14:17:05.611 W/ResourceType(16259): Skipping entry 0x7f02015d in package table 0 because it is not complex! 02-09 14:17:05.611 W/ResourceType(16259): Skipping entry 0x7f02015d in package table 0 because it is not complex! 02-09 14:17:05.611 W/ResourceType(16259): Skipping entry 0x7f02015d in package table 0 because it is not complex! 02-09 14:17:05.611 W/ResourceType(16259): Skipping entry 0x7f02015d in package table 0 because it is not complex! 02-09 14:17:05.916 I/dalvikvm(16259): Jit: resizing JitTable from 4096 to 8192 02-09 14:17:05.939 D/LAB126 ( 1442): collapse softkeys 02-09 14:17:06.002 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:17:06.002 I/LAB126 ( 1442): window changed 02-09 14:17:06.080 D/dalvikvm( 1375): GC_CONCURRENT freed 1752K, 52% free 5815K/12103K, external 4301K/5371K, paused 3ms+4ms 02-09 14:17:06.127 I/ActivityManager( 1375): Displayed com.verizon.ams.tesla/.ui.TabDownloadsActivity: +595ms 02-09 14:17:09.221 V/DeviceStorageMonitorService( 1375): mTotalMemory is 11734999 02-09 14:17:10.002 I/LAB126 ( 1442): open notifications from tap in the status bar, child count: 6 02-09 14:17:10.424 D/LAB126 ( 1442): expand softkeys 02-09 14:17:14.041 D/ActivityManager( 1375): Starting: Intent { cmp=com.verizon.ams.tesla/.msv.DownloadListActivity bnds=[0,510][600,620] } from pid -1 02-09 14:17:14.041 W/ActivityManager( 1375): startActivity called from non-Activity context; forcing Intent.FLAG_ACTIVITY_NEW_TASK for: Intent { cmp=com.verizon.ams.tesla/.msv.DownloadListActivity bnds=[0,510][600,620] } 02-09 14:17:14.041 D/LAB126 ( 1442): collapsing softkeys because notification closing. 02-09 14:17:14.041 D/LAB126 ( 1442): collapse softkeys 02-09 14:17:14.135 E/MSV (16259): null == m_progressBar 02-09 14:17:14.236 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:17:14.236 I/LAB126 ( 1442): window changed 02-09 14:17:14.385 I/ActivityManager( 1375): Displayed com.verizon.ams.tesla/.msv.DownloadListActivity: +345ms 02-09 14:17:14.447 D/LAB126 ( 1442): collapse softkeys 02-09 14:17:15.408 D/vzAnalytics(16259): Moved 4 events from thread 1 to bg thread. bg thread pending events 4 02-09 14:17:15.408 D/vzAnalytics(16259): Saving log to db on thread 11 for 4 events 02-09 14:17:15.705 D/vzAnalytics(16259): WiFi:true, CellData:false 02-09 14:17:15.705 D/vzAnalytics(16259): Enqueuing server log task. 02-09 14:17:15.705 D/vzAnalytics(16259): Running server log task on thread 11 for 7 events. url :http://www22.verizon.com/clickStream/Tracker.svc/xml/async/postmetrics 02-09 14:17:15.846 D/vzAnalytics(16259): deleting events after server log. 02-09 14:17:16.260 I/vzAnalytics(16259): complete server log task. success :true 02-09 14:17:16.877 I/LAB126 ( 1442): open notifications from tap in the status bar, child count: 6 02-09 14:17:17.307 D/LAB126 ( 1442): expand softkeys 02-09 14:17:21.666 D/ActivityManager( 1375): Starting: Intent { flg=0x4000000 cmp=com.verizon.ams.tesla/.ui.TabDownloadsActivity bnds=[0,400][600,510] (has extras) } from pid -1 02-09 14:17:21.666 W/ActivityManager( 1375): startActivity called from non-Activity context; forcing Intent.FLAG_ACTIVITY_NEW_TASK for: Intent { flg=0x4000000 cmp=com.verizon.ams.tesla/.ui.TabDownloadsActivity bnds=[0,400][600,510] (has extras) } 02-09 14:17:21.666 D/LAB126 ( 1442): collapsing softkeys because notification closing. 02-09 14:17:21.666 D/LAB126 ( 1442): collapse softkeys 02-09 14:17:21.752 W/ResourceType(16259): Skipping entry 0x7f02015d in package table 0 because it is not complex! 02-09 14:17:21.752 W/ResourceType(16259): Skipping entry 0x7f02015d in package table 0 because it is not complex! 02-09 14:17:21.752 W/ResourceType(16259): Skipping entry 0x7f02015d in package table 0 because it is not complex! 02-09 14:17:21.752 W/ResourceType(16259): Skipping entry 0x7f02015d in package table 0 because it is not complex! 02-09 14:17:21.752 W/ResourceType(16259): Skipping entry 0x7f02015d in package table 0 because it is not complex! 02-09 14:17:21.752 W/ResourceType(16259): Skipping entry 0x7f02015d in package table 0 because it is not complex! 02-09 14:17:21.752 D/vzAnalytics(16259): Scheduling db and net save task 02-09 14:17:21.814 D/dalvikvm(16259): GC_CONCURRENT freed 1877K, 44% free 5599K/9927K, external 7289K/8057K, paused 2ms+6ms 02-09 14:17:22.072 D/LAB126 ( 1442): collapse softkeys 02-09 14:17:22.127 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:17:22.127 I/LAB126 ( 1442): window changed 02-09 14:17:22.268 I/ActivityManager( 1375): Displayed com.verizon.ams.tesla/.ui.TabDownloadsActivity: +593ms 02-09 14:17:23.986 D/mediamanager(16259): Playing 10 Millionaire.mp3 02-09 14:17:23.986 D/mediamanager(16259): intent received com.verizon.flexview.mediamanager.action_audio_play 02-09 14:17:23.986 D/ActivityManager( 1375): Starting: Intent { cmp=com.verizon.ams.tesla/com.verizon.mediamanager.AudioPlayer } from pid 16259 02-09 14:17:24.041 D/dalvikvm(16259): GC_EXTERNAL_ALLOC freed 419K, 46% free 5455K/9927K, external 7200K/8057K, paused 42ms 02-09 14:17:24.244 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:17:24.244 I/LAB126 ( 1442): window changed 02-09 14:17:24.400 I/ActivityManager( 1375): Displayed com.verizon.ams.tesla/com.verizon.mediamanager.AudioPlayer: +406ms 02-09 14:17:24.596 W/ASFDummyExtractor( 1294): ASF parser is not available 02-09 14:17:24.596 E/MPEG4Extractor( 1294): both mdat,ftyp not found 02-09 14:17:25.619 D/LAB126 ( 1442): got back button softkey click! 02-09 14:17:25.619 D/LAB126 ( 1442): collapse because of back button 02-09 14:17:25.619 W/KeyCharacterMap(16259): No keyboard for id 0 02-09 14:17:25.619 W/KeyCharacterMap(16259): Using default keymap: /system/usr/keychars/qwerty.kcm.bin 02-09 14:17:25.619 D/LAB126 ( 1442): collapse softkeys 02-09 14:17:25.752 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:17:25.752 I/LAB126 ( 1442): window changed 02-09 14:17:27.158 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:17:27.158 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:17:27.158 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:17:27.158 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:17:27.158 D/IconMerger( 1442): notification for com.android.systemui (1) 02-09 14:17:27.158 D/IconMerger( 1442): sum of notifications: 5 02-09 14:17:27.830 D/mediamanager(16259): Playing 13 Jai Ho.mp3 02-09 14:17:27.830 D/mediamanager(16259): intent received com.verizon.flexview.mediamanager.action_audio_play 02-09 14:17:27.830 D/ActivityManager( 1375): Starting: Intent { cmp=com.verizon.ams.tesla/com.verizon.mediamanager.AudioPlayer } from pid 16259 02-09 14:17:27.986 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:17:27.986 I/LAB126 ( 1442): window changed 02-09 14:17:28.143 I/ActivityManager( 1375): Displayed com.verizon.ams.tesla/com.verizon.mediamanager.AudioPlayer: +308ms 02-09 14:17:28.447 W/ASFDummyExtractor( 1294): ASF parser is not available 02-09 14:17:28.447 E/MPEG4Extractor( 1294): both mdat,ftyp not found 02-09 14:17:28.978 D/LAB126 ( 1442): got back button softkey click! 02-09 14:17:28.978 D/LAB126 ( 1442): collapse because of back button 02-09 14:17:28.978 D/LAB126 ( 1442): collapse softkeys 02-09 14:17:29.111 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:17:29.111 I/LAB126 ( 1442): window changed 02-09 14:17:30.900 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:17:30.900 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:17:30.900 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:17:30.900 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:17:30.900 D/IconMerger( 1442): notification for com.android.systemui (1) 02-09 14:17:30.900 D/IconMerger( 1442): sum of notifications: 5 02-09 14:17:32.025 D/mediamanager(16259): Playing 13 Jai Ho.mp3 02-09 14:17:32.025 D/mediamanager(16259): intent received com.verizon.flexview.mediamanager.action_audio_play 02-09 14:17:32.025 D/ActivityManager( 1375): Starting: Intent { cmp=com.verizon.ams.tesla/com.verizon.mediamanager.AudioPlayer } from pid 16259 02-09 14:17:32.064 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:17:32.064 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:17:32.064 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:17:32.064 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:17:32.072 D/IconMerger( 1442): notification for com.android.systemui (1) 02-09 14:17:32.072 D/IconMerger( 1442): sum of notifications: 5 02-09 14:17:32.158 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:17:32.158 I/LAB126 ( 1442): window changed 02-09 14:17:32.330 I/ActivityManager( 1375): Displayed com.verizon.ams.tesla/com.verizon.mediamanager.AudioPlayer: +296ms 02-09 14:17:32.627 W/ASFDummyExtractor( 1294): ASF parser is not available 02-09 14:17:32.627 E/MPEG4Extractor( 1294): both mdat,ftyp not found 02-09 14:17:33.314 D/LAB126 ( 1442): got back button softkey click! 02-09 14:17:33.314 D/LAB126 ( 1442): collapse because of back button 02-09 14:17:33.314 D/LAB126 ( 1442): collapse softkeys 02-09 14:17:33.447 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:17:33.447 I/LAB126 ( 1442): window changed 02-09 14:17:41.760 D/vzAnalytics(16259): Moved 7 events from thread 1 to bg thread. bg thread pending events 7 02-09 14:17:41.760 D/vzAnalytics(16259): Saving log to db on thread 11 for 7 events 02-09 14:17:42.228 D/vzAnalytics(16259): WiFi:true, CellData:false 02-09 14:17:42.236 D/vzAnalytics(16259): Enqueuing server log task. 02-09 14:17:42.236 D/vzAnalytics(16259): Running server log task on thread 11 for 7 events. url :http://www22.verizon.com/clickStream/Tracker.svc/xml/async/postmetrics 02-09 14:17:42.432 D/vzAnalytics(16259): deleting events after server log. 02-09 14:17:42.814 I/vzAnalytics(16259): complete server log task. success :true 02-09 14:17:59.518 D/dalvikvm( 1375): GC_CONCURRENT freed 1697K, 51% free 5977K/12103K, external 4301K/5371K, paused 2ms+5ms 02-09 14:17:59.674 D/dalvikvm( 1375): GC_CONCURRENT freed 2036K, 52% free 5840K/12103K, external 4301K/5371K, paused 3ms+4ms 02-09 14:17:59.799 D/dalvikvm( 1375): GC_CONCURRENT freed 1860K, 52% free 5847K/12103K, external 4301K/5371K, paused 2ms+4ms 02-09 14:17:59.986 D/dalvikvm( 1375): GC_CONCURRENT freed 1871K, 52% free 5843K/12103K, external 4301K/5371K, paused 2ms+4ms 02-09 14:18:00.158 D/dalvikvm( 1375): GC_CONCURRENT freed 1867K, 52% free 5841K/12103K, external 4301K/5371K, paused 2ms+4ms 02-09 14:18:00.314 D/dalvikvm( 1375): GC_CONCURRENT freed 1866K, 52% free 5841K/12103K, external 4301K/5371K, paused 2ms+3ms 02-09 14:18:00.471 D/dalvikvm( 1375): GC_CONCURRENT freed 1865K, 52% free 5841K/12103K, external 4301K/5371K, paused 3ms+4ms 02-09 14:18:00.611 D/dalvikvm( 1375): GC_CONCURRENT freed 1845K, 52% free 5848K/12103K, external 4301K/5371K, paused 3ms+4ms 02-09 14:18:00.705 D/dalvikvm( 1375): GC_CONCURRENT freed 1848K, 52% free 5853K/12103K, external 4301K/5371K, paused 3ms+6ms 02-09 14:18:00.791 D/dalvikvm( 1375): GC_CONCURRENT freed 1861K, 52% free 5846K/12103K, external 4301K/5371K, paused 2ms+4ms 02-09 14:18:09.221 V/DeviceStorageMonitorService( 1375): mTotalMemory is 11734999 02-09 14:18:11.596 D/LAB126 ( 1442): got back button softkey click! 02-09 14:18:11.596 D/LAB126 ( 1442): collapse because of back button 02-09 14:18:11.596 D/LAB126 ( 1442): collapse softkeys 02-09 14:18:12.064 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:18:12.064 I/LAB126 ( 1442): window changed 02-09 14:18:30.650 D/dalvikvm( 1801): GC_EXPLICIT freed 404K, 44% free 4479K/7879K, external 847K/1181K, paused 46ms 02-09 14:18:32.205 D/LAB126 ( 1442): got back button softkey click! 02-09 14:18:32.205 D/LAB126 ( 1442): collapse because of back button 02-09 14:18:32.205 D/LAB126 ( 1442): collapse softkeys 02-09 14:18:32.494 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:18:32.494 I/LAB126 ( 1442): window changed 02-09 14:18:33.111 D/LAB126 ( 1442): got back button softkey click! 02-09 14:18:33.111 D/LAB126 ( 1442): collapse because of back button 02-09 14:18:33.111 D/LAB126 ( 1442): collapse softkeys 02-09 14:18:33.260 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:18:33.260 I/LAB126 ( 1442): window changed 02-09 14:18:33.799 D/LAB126 ( 1442): got menu button softkey click! 02-09 14:18:33.799 D/LAB126 ( 1442): collapse because of menu 02-09 14:18:33.799 D/LAB126 ( 1442): collapse softkeys 02-09 14:18:35.674 I/CommonSSO(16259): ############# logout() called ############################################################### 02-09 14:18:35.783 D/vzAnalytics(16259): Scheduling db and net save task 02-09 14:18:35.814 D/AuthenticationService(16259): SSOService Authentication Service started. 02-09 14:18:35.814 D/AuthenticationService(16259): getBinder()... returning the AccountAuthenticator binder for intent Intent { act=android.accounts.AccountAuthenticator cmp=com.verizon.ams.tesla/com.verizon.sso.AuthenticationService } 02-09 14:18:35.814 D/mediamanager(16259): intent received com.verizon.flexview.mediamanager.action_audio_stop 02-09 14:18:35.846 D/mediamanager(16259): Running Delete Queue:queue_item_status='1' OR queue_item_status='5' OR queue_item_status='0' OR queue_item_status='3' 02-09 14:18:35.846 W/InputManagerService( 1375): Window already focused, ignoring focus gain of: com.android.internal.view.IInputMethodClient$Stub$Proxy@4073a008 02-09 14:18:35.924 D/ContactsProvider( 1484): removing data for removed account Account {name=ironman1058, type=com.verizon.sso.user} 02-09 14:18:37.627 D/AuthenticationService(16259): SSOService Authentication Service stopped. 02-09 14:18:37.635 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:18:37.635 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:18:37.635 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:18:37.635 D/IconMerger( 1442): notification for com.android.systemui (1) 02-09 14:18:37.635 D/IconMerger( 1442): sum of notifications: 4 02-09 14:18:37.650 I/LAB126 ( 1442): StatusBarService hears intent. action: com.amazon.dcp.sso.action.AmazonAccountPropertyService.property.changed 02-09 14:18:37.721 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:18:37.721 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:18:37.721 D/IconMerger( 1442): notification for com.android.systemui (1) 02-09 14:18:37.721 D/IconMerger( 1442): sum of notifications: 3 02-09 14:18:38.939 E/Omap4ALSA( 1294): called drain&close 02-09 14:18:39.478 D/ActivityManager( 1375): Starting: Intent { act=android.intent.action.VIEW dat=app://com.verizon.ams.tesla/mymusic cmp=com.verizon.ams.tesla/com.verizon.mediamanager.AudioAlbumList } from pid 16259 02-09 14:18:39.502 D/mediamanager(16259): isAuthenticated:false. SsoService.hasValidCookie:false, SsoService.getRememberMe:false 02-09 14:18:39.525 D/mediamanager(16259): validation started. setting up SSO. 02-09 14:18:39.525 D/mediamanager(16259): setting environment for mmol : PRODUCTION 02-09 14:18:39.533 V/SSOWebUtils(16259): PrepareSSO() Start 02-09 14:18:39.533 V/SSOWebUtils(16259): PrepareSSO() Calling SsoService.login(t); 02-09 14:18:39.572 D/dalvikvm( 1375): GC_CONCURRENT freed 1493K, 50% free 6117K/12103K, external 4301K/5371K, paused 2ms+9ms 02-09 14:18:39.744 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:18:39.744 I/LAB126 ( 1442): window changed 02-09 14:18:39.916 I/ActivityManager( 1375): Displayed com.verizon.ams.tesla/com.verizon.mediamanager.AudioAlbumList: +429ms 02-09 14:18:40.744 D/LatinKeyboard( 1450): Setting IME options 02-09 14:18:40.799 D/dalvikvm( 1450): GC_EXTERNAL_ALLOC freed 245K, 52% free 2965K/6087K, external 3528K/3529K, paused 30ms 02-09 14:18:40.799 D/LatinKeyboard( 1450): Setting IME options 02-09 14:18:40.885 D/dalvikvm( 1450): GC_EXTERNAL_ALLOC freed 57K, 53% free 2915K/6087K, external 2281K/2839K, paused 40ms 02-09 14:18:44.885 D/LatinKeyboard( 1450): Setting IME options 02-09 14:18:47.408 D/dalvikvm(16259): GC_CONCURRENT freed 1909K, 44% free 5650K/10055K, external 7963K/9418K, paused 2ms+6ms 02-09 14:18:48.807 I/LAB126 ( 1442): StatusBarService hears intent. action: com.amazon.dcp.sso.action.AmazonAccountPropertyService.property.changed 02-09 14:18:48.885 D/SyncManager( 1375): setSyncAutomatically: , provider com.verizon.sso.accounts -> false 02-09 14:18:48.908 D/SyncManager( 1375): setSyncAutomatically: already set to false, doing nothing 02-09 14:18:49.658 V/SSOWebUtils(16259): msg from SSO what:0, arg1:0, arg2:0 02-09 14:18:49.658 V/SSOWebUtils(16259): SSO HANDLER: SSO SUCCESS 02-09 14:18:49.674 I/UrlComposer(16259): >>>>>> GETUSERPROFILE <<<<<< 02-09 14:18:49.674 V/SSOWebUtils(16259): fetchUserProfile() :: url = https://www36.verizon.com/MSVAppServices/Authenticated/POX/AccountMgrXmlServices.asmx/MSVAppRequest? 02-09 14:18:49.674 V/SSOWebUtils(16259): fetchUserProfile() :: postData = strInputXML=GETMSVPROFILEironman1058DNETtrans_12BB001 02-09 14:18:49.674 V/MSV (16259): WebUtils url:https://www36.verizon.com/MSVAppServices/Authenticated/POX/AccountMgrXmlServices.asmx/MSVAppRequest? 02-09 14:18:49.674 V/MSV (16259): WebUtils body:strInputXML=GETMSVPROFILEironman1058DNETtrans_12BB001 02-09 14:18:49.713 D/LatinKeyboard( 1450): Setting IME options 02-09 14:18:51.197 I/SSOWebUtils(16259): validationResponseHandler.GET_MSV_PROFILE_REQUEST.. 02-09 14:18:51.205 V/MSV (16259): WebUtils finished http post call 02-09 14:18:51.205 V/SSOWebUtils(16259): User Profile: [userId:reswio0m][domain:DNET][userType:A][subscriptionAvailable:true][timeOffset:0] 02-09 14:18:51.213 I/UrlComposer(16259): >>>>>> GETTERMSOFSERVICE <<<<<< 02-09 14:18:51.213 V/SSOWebUtils(16259): FetchTOS url = https://www36.verizon.com/MSVAppServices/Authenticated/POX/AccountMgrXmlServices.asmx/MSVAppRequest? 02-09 14:18:51.213 V/SSOWebUtils(16259): FetchTOS postData = strInputXML=GETUSERTOSironman1058DNETtrans_12BB001 02-09 14:18:51.213 V/MSV (16259): WebUtils url:https://www36.verizon.com/MSVAppServices/Authenticated/POX/AccountMgrXmlServices.asmx/MSVAppRequest? 02-09 14:18:51.213 V/MSV (16259): WebUtils body:strInputXML=GETUSERTOSironman1058DNETtrans_12BB001 02-09 14:18:51.549 D/dalvikvm(16259): GC_FOR_MALLOC freed 1091K, 43% free 5857K/10183K, external 6963K/8696K, paused 37ms 02-09 14:18:51.588 D/dalvikvm(16259): GC_FOR_MALLOC freed 392K, 47% free 5550K/10311K, external 6963K/8696K, paused 34ms 02-09 14:18:52.385 I/SSOWebUtils(16259): validationResponseHandler.GET_TOS_REQUEST ... 02-09 14:18:52.385 V/MSV_TOS (16259): TOS CREATED 02-09 14:18:52.393 V/MSV (16259): WebUtils finished http post call 02-09 14:18:52.775 V/MetaDataSyncService(16259): downloadPurchaseList() :: url = https://www36.verizon.com/MSVAppServices/Authenticated/POX/AccountMgrXmlServices.asmx/MSVAppRequest? 02-09 14:18:52.775 V/MetaDataSyncService(16259): downloadPurchaseList() :: postData = strInputXML=GETPURCHASEDTITLESironman1058DNETtrans_12BB001YDESCproduct_purchasedDateALLAverageRatingALLALL 02-09 14:18:52.775 V/MSV (16259): WebUtils url:https://www36.verizon.com/MSVAppServices/Authenticated/POX/AccountMgrXmlServices.asmx/MSVAppRequest? 02-09 14:18:52.775 V/MSV (16259): WebUtils body:strInputXML=GETPURCHASEDTITLESironman1058DNETtrans_12BB001YDESCproduct_purchasedDateALLAverageRatingALLALL 02-09 14:18:52.791 V/MetaDataSyncService(16259): downloadWatchList() :: url = https://www36.verizon.com/MSVAppServices/Authenticated/POX/AccountMgrXmlServices.asmx/MSVAppRequest? 02-09 14:18:52.791 V/MetaDataSyncService(16259): downloadWatchList() :: postData = strInputXML=GETWATCHLISTironman1058DNETtrans_12BB001DESCproduct_dtmcreateDateALLAverageRatingALLALL 02-09 14:18:52.791 V/MSV (16259): WebUtils url:https://www36.verizon.com/MSVAppServices/Authenticated/POX/AccountMgrXmlServices.asmx/MSVAppRequest? 02-09 14:18:52.791 V/MSV (16259): WebUtils body:strInputXML=GETWATCHLISTironman1058DNETtrans_12BB001DESCproduct_dtmcreateDateALLAverageRatingALLALL 02-09 14:18:53.041 D/mediamanager(16259): HTTP get http://www22.verizon.com/M3/svc/auth/mediaservice.svc/com/users/ironman1058/userinfo?fmt=xml 02-09 14:18:53.119 V/MSV (16259): WebUtils url:https://www36.verizon.com/MSVAppServices/Authenticated/POX/CatalogXmlServices.asmx/MSVAppRequest? 02-09 14:18:53.119 V/MSV (16259): WebUtils body:strInputXML=GETUSERRATINGSironman1058DNETtrans_12BB001 02-09 14:18:53.182 D/dalvikvm(16259): GC_FOR_MALLOC freed 461K, 44% free 5805K/10311K, external 6963K/8696K, paused 34ms 02-09 14:18:53.588 I/MetaDataSyncService(16259): getting purchaselist successful! 02-09 14:18:53.588 V/MSV (16259): WebUtils finished http post call 02-09 14:18:53.752 I/MetaDataSyncService(16259): purchaselistIndex size bobby:0 02-09 14:18:53.752 I/MetaDataSyncService(16259): purchaselistIndex size bobby:0 02-09 14:18:53.752 I/MetaDataSyncService(16259): Purchasehistory list Parsing successfully 02-09 14:18:54.033 W/ResponseProcessCookies(16259): Cookie rejected: "BasicClientCookie[version=0,name=ak-sf,domain=verizon.com,path=/m3/,expiry=Thu Feb 09 14:23:54 CST 2012]". Illegal path attribute "/m3/". Path of origin: "/M3/svc/auth/mediaservice.svc/com/users/ironman1058/userinfo" 02-09 14:18:54.041 D/mediamanager(16259): TOKEN REFRESHED 02-09 14:18:54.322 D/mediamanager(16259): received message from sso. msg.arg1:0 02-09 14:18:54.322 D/mediamanager(16259): checking device registration. 02-09 14:18:54.322 V/SSOWebUtils(16259): PrepareSSO() Start 02-09 14:18:54.455 D/dalvikvm(16259): GC_FOR_MALLOC freed 700K, 44% free 5874K/10311K, external 6963K/8696K, paused 40ms 02-09 14:18:54.455 V/SSOWebUtils(16259): PrepareSSO() VALID COOKIE AVAILABLE 02-09 14:18:54.463 V/MSV (16259): >>>> SSO HANDLER. Response MSG =0/0 02-09 14:18:54.463 W/InputManagerService( 1375): Window already focused, ignoring focus gain of: com.android.internal.view.IInputMethodClient$Stub$Proxy@408ad628 02-09 14:18:54.478 V/DeviceManager(16259): url: https://www36.verizon.com/MSVAppServices/Authenticated/POX/DeviceXmlServices.asmx/MSVAppRequest? 02-09 14:18:54.478 V/DeviceManager(16259): body: strInputXML=GETALLDEVICESironman1058DNETtrans_12BB001Y 02-09 14:18:54.478 V/MSV (16259): WebUtils url:https://www36.verizon.com/MSVAppServices/Authenticated/POX/DeviceXmlServices.asmx/MSVAppRequest? 02-09 14:18:54.478 V/MSV (16259): WebUtils body:strInputXML=GETALLDEVICESironman1058DNETtrans_12BB001Y 02-09 14:18:54.752 V/MSV (16259): Silent request done... 02-09 14:18:54.752 V/MSV (16259): getting watchlist successful! 02-09 14:18:54.752 V/MSV (16259): WebUtils finished http post call 02-09 14:18:54.853 V/MSV (16259): watchlist index created!9 02-09 14:18:54.853 I/MSV (16259): Watchlist Parsing successfully 02-09 14:18:55.080 D/dalvikvm(16259): GC_FOR_MALLOC freed 687K, 45% free 5691K/10311K, external 6939K/8666K, paused 41ms 02-09 14:18:55.783 D/vzAnalytics(16259): Moved 5 events from thread 1 to bg thread. bg thread pending events 5 02-09 14:18:55.783 D/vzAnalytics(16259): Saving log to db on thread 11 for 5 events 02-09 14:18:56.057 D/vzAnalytics(16259): WiFi:true, CellData:false 02-09 14:18:56.057 D/vzAnalytics(16259): Enqueuing server log task. 02-09 14:18:56.057 D/vzAnalytics(16259): Running server log task on thread 11 for 5 events. url :http://www22.verizon.com/clickStream/Tracker.svc/xml/async/postmetrics 02-09 14:18:56.252 D/vzAnalytics(16259): deleting events after server log. 02-09 14:18:56.424 V/MSV (16259): WebUtils finished http post call 02-09 14:18:56.619 I/vzAnalytics(16259): complete server log task. success :true 02-09 14:18:56.760 D/dalvikvm(16259): GC_FOR_MALLOC freed 732K, 45% free 5708K/10311K, external 6939K/8666K, paused 34ms 02-09 14:18:56.932 V/MSV (16259): WebUtils finished http post call 02-09 14:18:56.932 D/mediamanager(16259): handlerDeviceMgr(): got 11110000:11110007 02-09 14:18:56.932 D/mediamanager(16259): Device registration succeeded 02-09 14:18:56.932 D/mediamanager(16259): Audio album list onValidated. 02-09 14:18:56.939 W/InputManagerService( 1375): Window already focused, ignoring focus gain of: com.android.internal.view.IInputMethodClient$Stub$Proxy@4083ecd0 02-09 14:18:57.025 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:18:57.025 I/LAB126 ( 1442): window changed 02-09 14:18:57.361 D/mediamanager(16259): HTTP get http://www22.verizon.com/M3/svc/auth/mediaservice.svc/com/users/UserName/albums/type/AudioAlbum?fmt=xml&sortorder=ASC&SortBy=Title&dojo.preventCache=1264380228170 02-09 14:18:57.603 W/ResponseProcessCookies(16259): Cookie rejected: "BasicClientCookie[version=0,name=ak-sf,domain=verizon.com,path=/m3/,expiry=Thu Feb 09 14:23:57 CST 2012]". Illegal path attribute "/m3/". Path of origin: "/M3/svc/auth/mediaservice.svc/com/users/UserName/albums/type/AudioAlbum" 02-09 14:18:57.619 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:18:57.619 I/LAB126 ( 1442): window changed 02-09 14:18:59.072 D/ActivityManager( 1375): Starting: Intent { cmp=com.verizon.ams.tesla/com.verizon.mediamanager.AudioItemList (has extras) } from pid 16259 02-09 14:18:59.502 D/mediamanager(16259): start getting album items pageNo #1 02-09 14:18:59.502 D/vzAnalytics(16259): Scheduling db and net save task 02-09 14:18:59.596 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:18:59.596 I/LAB126 ( 1442): window changed 02-09 14:18:59.744 D/dalvikvm( 1375): GC_CONCURRENT freed 1431K, 47% free 6521K/12103K, external 4301K/5371K, paused 2ms+10ms 02-09 14:18:59.760 D/mediamanager(16259): HTTP get http://www22.verizon.com/M3/svc/auth/mediaservice.svc/com/users/UserName/albums/05f16538-62aa-476e-8afd-9e2bf19aa742?bGetAlbums=false&fmt=xml&ftype=3&sortorder=DESC&SortBy=UploadDate&pageNo=1&pageSize=250&nonull=true&Enc=1&dojo.preventCache=1264392598150 02-09 14:18:59.838 I/ActivityManager( 1375): Displayed com.verizon.ams.tesla/com.verizon.mediamanager.AudioItemList: +766ms 02-09 14:18:59.861 D/dalvikvm(16259): GC_FOR_MALLOC freed 425K, 43% free 5933K/10311K, external 6983K/8666K, paused 53ms 02-09 14:19:00.041 W/ResponseProcessCookies(16259): Cookie rejected: "BasicClientCookie[version=0,name=ak-sf,domain=verizon.com,path=/m3/,expiry=Thu Feb 09 14:24:00 CST 2012]". Illegal path attribute "/m3/". Path of origin: "/M3/svc/auth/mediaservice.svc/com/users/UserName/albums/05f16538-62aa-476e-8afd-9e2bf19aa742" 02-09 14:19:00.244 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:19:00.244 I/LAB126 ( 1442): window changed 02-09 14:19:01.041 D/dalvikvm( 1375): GC_CONCURRENT freed 2719K, 52% free 5831K/12103K, external 4301K/5371K, paused 2ms+4ms 02-09 14:19:01.174 D/dalvikvm( 1375): GC_CONCURRENT freed 1847K, 52% free 5839K/12103K, external 4301K/5371K, paused 3ms+3ms 02-09 14:19:01.330 D/dalvikvm( 1375): GC_CONCURRENT freed 1877K, 52% free 5826K/12103K, external 4301K/5371K, paused 2ms+4ms 02-09 14:19:01.478 D/dalvikvm( 1375): GC_CONCURRENT freed 1861K, 52% free 5826K/12103K, external 4301K/5371K, paused 2ms+4ms 02-09 14:19:01.627 D/dalvikvm( 1375): GC_CONCURRENT freed 1843K, 52% free 5844K/12103K, external 4301K/5371K, paused 3ms+3ms 02-09 14:19:01.775 D/dalvikvm( 1375): GC_CONCURRENT freed 1884K, 52% free 5826K/12103K, external 4301K/5371K, paused 2ms+5ms 02-09 14:19:01.924 D/dalvikvm( 1375): GC_CONCURRENT freed 1858K, 52% free 5829K/12103K, external 4301K/5371K, paused 2ms+4ms 02-09 14:19:02.010 D/dalvikvm( 1375): GC_CONCURRENT freed 1880K, 53% free 5804K/12103K, external 4301K/5371K, paused 2ms+4ms 02-09 14:19:02.103 D/dalvikvm( 1375): GC_CONCURRENT freed 1835K, 52% free 5822K/12103K, external 4301K/5371K, paused 3ms+4ms 02-09 14:19:06.619 V/QueueItem(16259): QueueItem(Parcel in)... 02-09 14:19:06.721 V/QueueItem(16259): QueueItem(Parcel in)... 02-09 14:19:06.791 W/InputManagerService( 1375): Window already focused, ignoring focus gain of: com.android.internal.view.IInputMethodClient$Stub$Proxy@40574108 02-09 14:19:07.025 V/QueueItem(16259): QueueItem(Parcel in)... 02-09 14:19:07.135 D/mediamanager(16259): HTTP download http://fvccd.verizon.net/m3/svc/dl/sec/med/dl2.dl?cxt=ZeuSM35uMit1O5GGjMwa55HBtEaI8RJykqrKzj8AfHMiDYZshQpmWkKb73oFENu9JNGLWh6DCVB17bP5Yc9qukEyhJS9gJtoqxzmlGs3mds%3d&tt=ri2gL9bf0KSX88GW%2f4Ki9LxtiynwmRcdceHcl5x0HK18utePpUlgjbx3KuP8KaADdVsbPAEoe3KnBs%2f8jVmR5A%3d%3d&HTTP_ACCESSPOINTID=MP007&HTTP_OS=Android&HTTP_VERSION=2.6.35.7+&HTTP_MM_APP_MEDIA=com.verizon.mediamanager&HTTP_MM_APP_VERSION=1.5.0&HTTP_HARDWARE_MODEL=Kindle_Fire&HTTP_HARDWARE_MAKE=Amazon& 02-09 14:19:07.189 D/mediamanager(16259): HTTP download http://fvccd.verizon.net/m3/svc/dl/sec/med/dl2.dl?cxt=RXCidVadDEXnfBmzJXjMXPSxXGHsRvZArPyreCbQTj%2fbgZ6to1A5iT5pC0%2fx7zeyHojwBX82X6ceT3C2GUw%2fBt29qr87EdXVGSIva348VZA%3d&tt=ri2gL9bf0KSX88GW%2f4Ki9LxtiynwmRcdceHcl5x0HK18utePpUlgjbx3KuP8KaADdVsbPAEoe3KnBs%2f8jVmR5A%3d%3d&HTTP_ACCESSPOINTID=MP007&HTTP_OS=Android&HTTP_VERSION=2.6.35.7+&HTTP_MM_APP_MEDIA=com.verizon.mediamanager&HTTP_MM_APP_VERSION=1.5.0&HTTP_HARDWARE_MODEL=Kindle_Fire&HTTP_HARDWARE_MAKE=Amazon& 02-09 14:19:07.955 V/QueueItem(16259): QueueItem(Parcel in)... 02-09 14:19:08.064 D/mediamanager(16259): HTTP download http://fvccd.verizon.net/m3/svc/dl/sec/med/dl2.dl?cxt=3kS2hgst4rqUHvBmBpcI1I%2fjy4zMTLvcvUht1cSJFLDSE8Z293Oh4mxVFlRuaPi12evRepaDTldZz2EXMjWXQFB4CNTAW9pbqllArc5FQqo%3d&tt=ri2gL9bf0KSX88GW%2f4Ki9LxtiynwmRcdceHcl5x0HK18utePpUlgjbx3KuP8KaADdVsbPAEoe3KnBs%2f8jVmR5A%3d%3d&HTTP_ACCESSPOINTID=MP007&HTTP_OS=Android&HTTP_VERSION=2.6.35.7+&HTTP_MM_APP_MEDIA=com.verizon.mediamanager&HTTP_MM_APP_VERSION=1.5.0&HTTP_HARDWARE_MODEL=Kindle_Fire&HTTP_HARDWARE_MAKE=Amazon& 02-09 14:19:08.182 V/QueueItem(16259): QueueItem(Parcel in)... 02-09 14:19:08.228 D/dalvikvm(16259): GC_FOR_MALLOC freed 812K, 41% free 6180K/10439K, external 7022K/8666K, paused 42ms 02-09 14:19:08.338 V/QueueItem(16259): QueueItem(Parcel in)... 02-09 14:19:08.471 V/QueueItem(16259): QueueItem(Parcel in)... 02-09 14:19:08.564 V/QueueItem(16259): QueueItem(Parcel in)... 02-09 14:19:08.658 V/QueueItem(16259): QueueItem(Parcel in)... 02-09 14:19:08.783 V/QueueItem(16259): QueueItem(Parcel in)... 02-09 14:19:08.947 V/QueueItem(16259): QueueItem(Parcel in)... 02-09 14:19:09.221 V/DeviceStorageMonitorService( 1375): mTotalMemory is 11734999 02-09 14:19:09.572 V/QueueItem(16259): QueueItem(Parcel in)... 02-09 14:19:09.689 V/QueueItem(16259): QueueItem(Parcel in)... 02-09 14:19:09.728 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:19:09.728 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:19:09.728 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:19:09.728 D/IconMerger( 1442): notification for com.android.systemui (1) 02-09 14:19:09.728 D/IconMerger( 1442): sum of notifications: 4 02-09 14:19:09.783 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:19:09.783 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:19:09.783 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:19:09.783 D/IconMerger( 1442): notification for com.android.systemui (1) 02-09 14:19:09.783 D/IconMerger( 1442): sum of notifications: 4 02-09 14:19:09.799 V/QueueItem(16259): QueueItem(Parcel in)... 02-09 14:19:09.900 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:19:09.900 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:19:09.900 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:19:09.900 D/IconMerger( 1442): notification for com.android.systemui (1) 02-09 14:19:09.900 V/QueueItem(16259): QueueItem(Parcel in)... 02-09 14:19:09.900 D/IconMerger( 1442): sum of notifications: 4 02-09 14:19:10.018 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:19:10.018 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:19:10.018 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:19:10.018 D/IconMerger( 1442): notification for com.android.systemui (1) 02-09 14:19:10.018 D/IconMerger( 1442): sum of notifications: 4 02-09 14:19:10.783 I/ChargeProtectionService( 1375): Battery discharging, resuming charging 02-09 14:19:13.494 D/LAB126 ( 1442): got back button softkey click! 02-09 14:19:13.494 D/LAB126 ( 1442): collapse because of back button 02-09 14:19:13.494 D/LAB126 ( 1442): collapse softkeys 02-09 14:19:14.353 D/LAB126 ( 1442): got back button softkey click! 02-09 14:19:14.353 D/LAB126 ( 1442): collapse because of back button 02-09 14:19:14.353 D/InputDispatcher( 1375): channel '4099d7a0 com.verizon.ams.tesla/com.verizon.mediamanager.AudioItemList (server)' ~ Synthesized 1 cancelation events to bring channel back in sync with reality: inbound event was dropped because the policy consumed it, options=2. 02-09 14:19:14.353 D/LAB126 ( 1442): collapse softkeys 02-09 14:19:14.619 W/KeyCharacterMap(16259): No keyboard for id 0 02-09 14:19:14.619 W/KeyCharacterMap(16259): Using default keymap: /system/usr/keychars/qwerty.kcm.bin 02-09 14:19:15.033 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:19:15.033 I/LAB126 ( 1442): window changed 02-09 14:19:16.135 D/mediamanager(16259): downloaded 5611245 bytes from http://fvccd.verizon.net/m3/svc/dl/sec/med/dl2.dl?cxt=3kS2hgst4rqUHvBmBpcI1I%2fjy4zMTLvcvUht1cSJFLDSE8Z293Oh4mxVFlRuaPi12evRepaDTldZz2EXMjWXQFB4CNTAW9pbqllArc5FQqo%3d&tt=ri2gL9bf0KSX88GW%2f4Ki9LxtiynwmRcdceHcl5x0HK18utePpUlgjbx3KuP8KaADdVsbPAEoe3KnBs%2f8jVmR5A%3d%3d&HTTP_ACCESSPOINTID=MP007&HTTP_OS=Android&HTTP_VERSION=2.6.35.7+&HTTP_MM_APP_MEDIA=com.verizon.mediamanager&HTTP_MM_APP_VERSION=1.5.0&HTTP_HARDWARE_MODEL=Kindle_Fire&HTTP_HARDWARE_MAKE=Amazon& 02-09 14:19:16.689 D/mediamanager(16259): downloaded 6166110 bytes from http://fvccd.verizon.net/m3/svc/dl/sec/med/dl2.dl?cxt=RXCidVadDEXnfBmzJXjMXPSxXGHsRvZArPyreCbQTj%2fbgZ6to1A5iT5pC0%2fx7zeyHojwBX82X6ceT3C2GUw%2fBt29qr87EdXVGSIva348VZA%3d&tt=ri2gL9bf0KSX88GW%2f4Ki9LxtiynwmRcdceHcl5x0HK18utePpUlgjbx3KuP8KaADdVsbPAEoe3KnBs%2f8jVmR5A%3d%3d&HTTP_ACCESSPOINTID=MP007&HTTP_OS=Android&HTTP_VERSION=2.6.35.7+&HTTP_MM_APP_MEDIA=com.verizon.mediamanager&HTTP_MM_APP_VERSION=1.5.0&HTTP_HARDWARE_MODEL=Kindle_Fire&HTTP_HARDWARE_MAKE=Amazon& 02-09 14:19:19.307 D/ActivityManager( 1375): Starting: Intent { cmp=com.verizon.ams.tesla/com.verizon.mediamanager.AudioItemList (has extras) } from pid 16259 02-09 14:19:19.353 D/mediamanager(16259): HTTP download http://fvccd.verizon.net/m3/svc/dl/sec/med/dl2.dl?cxt=QdxKGT4fpaB0V0HsF4KUl%2fE1Q4lUNvhUTQbQSl3XLvMVRVQtQEwNdrKLC8aq1rTeLy2jvFEfs6vHvyn%2b5dz%2bvkRlZvYwmfoS3P%2fngT3Z568%3d&tt=ri2gL9bf0KSX88GW%2f4Ki9LxtiynwmRcdceHcl5x0HK18utePpUlgjbx3KuP8KaADdVsbPAEoe3KnBs%2f8jVmR5A%3d%3d&HTTP_ACCESSPOINTID=MP007&HTTP_OS=Android&HTTP_VERSION=2.6.35.7+&HTTP_MM_APP_MEDIA=com.verizon.mediamanager&HTTP_MM_APP_VERSION=1.5.0&HTTP_HARDWARE_MODEL=Kindle_Fire&HTTP_HARDWARE_MAKE=Amazon& 02-09 14:19:19.447 D/mediamanager(16259): HTTP download http://fvccd.verizon.net/m3/svc/dl/sec/med/dl2.dl?cxt=oNdnMTLEWz90L72v6oVA7ikIBvQpHsM%2bnewq7HiblZACs8Nyw2soMRrOLD0tMuQEyHbCNPdcBN%2bJQctuKe1tGSoddoHR2x1NbLYGRNZ%2bHjA%3d&tt=ri2gL9bf0KSX88GW%2f4Ki9LxtiynwmRcdceHcl5x0HK18utePpUlgjbx3KuP8KaADdVsbPAEoe3KnBs%2f8jVmR5A%3d%3d&HTTP_ACCESSPOINTID=MP007&HTTP_OS=Android&HTTP_VERSION=2.6.35.7+&HTTP_MM_APP_MEDIA=com.verizon.mediamanager&HTTP_MM_APP_VERSION=1.5.0&HTTP_HARDWARE_MODEL=Kindle_Fire&HTTP_HARDWARE_MAKE=Amazon& 02-09 14:19:19.893 D/mediamanager(16259): downloaded 8194507 bytes from http://fvccd.verizon.net/m3/svc/dl/sec/med/dl2.dl?cxt=ZeuSM35uMit1O5GGjMwa55HBtEaI8RJykqrKzj8AfHMiDYZshQpmWkKb73oFENu9JNGLWh6DCVB17bP5Yc9qukEyhJS9gJtoqxzmlGs3mds%3d&tt=ri2gL9bf0KSX88GW%2f4Ki9LxtiynwmRcdceHcl5x0HK18utePpUlgjbx3KuP8KaADdVsbPAEoe3KnBs%2f8jVmR5A%3d%3d&HTTP_ACCESSPOINTID=MP007&HTTP_OS=Android&HTTP_VERSION=2.6.35.7+&HTTP_MM_APP_MEDIA=com.verizon.mediamanager&HTTP_MM_APP_VERSION=1.5.0&HTTP_HARDWARE_MODEL=Kindle_Fire&HTTP_HARDWARE_MAKE=Amazon& 02-09 14:19:20.033 D/dalvikvm(16259): GC_CONCURRENT freed 1549K, 39% free 6629K/10695K, external 7002K/8666K, paused 3ms+6ms 02-09 14:19:20.049 D/dalvikvm( 1375): GC_CONCURRENT freed 1295K, 49% free 6278K/12103K, external 4301K/5371K, paused 2ms+13ms 02-09 14:19:26.689 I/InputDispatcher( 1375): Application is not responding: AppWindowToken{407c1a00 token=HistoryRecord{40a23bd0 com.verizon.ams.tesla/com.verizon.mediamanager.AudioItemList}}. 5001.2ms since event, 5001.1ms since wait started 02-09 14:19:26.689 I/Process ( 1375): Sending signal. PID: 16259 SIG: 3 02-09 14:19:26.689 I/dalvikvm(16259): threadid=4: reacting to signal 3 02-09 14:19:26.689 I/WindowManager( 1375): Input event dispatching timed out sending to application AppWindowToken{407c1a00 token=HistoryRecord{40a23bd0 com.verizon.ams.tesla/com.verizon.mediamanager.AudioItemList}} 02-09 14:19:26.893 I/Process ( 1375): Sending signal. PID: 1375 SIG: 3 02-09 14:19:26.893 I/dalvikvm( 1375): threadid=4: reacting to signal 3 02-09 14:19:26.963 I/dalvikvm( 1375): Wrote stack traces to '/data/anr/traces.txt' 02-09 14:19:26.963 I/Process ( 1375): Sending signal. PID: 1442 SIG: 3 02-09 14:19:26.963 I/dalvikvm( 1442): threadid=4: reacting to signal 3 02-09 14:19:26.963 I/dalvikvm( 1442): Wrote stack traces to '/data/anr/traces.txt' 02-09 14:19:26.971 I/dalvikvm(16259): Wrote stack traces to '/data/anr/traces.txt' 02-09 14:19:27.166 D/dalvikvm( 1375): GC_EXPLICIT freed 1338K, 50% free 6069K/12103K, external 4301K/5371K, paused 62ms 02-09 14:19:27.174 D/mediamanager(16259): start getting album items pageNo #1 02-09 14:19:27.174 D/mediamanager(16259): Cache hit for http://www22.verizon.com/M3/svc/auth/mediaservice.svc/com/users/UserName/albums/05f16538-62aa-476e-8afd-9e2bf19aa742?bGetAlbums=false&fmt=xml&ftype=3&sortorder=DESC&SortBy=UploadDate&pageNo=1&pageSize=250&nonull=true&Enc=1&dojo.preventCache=1264392598150 02-09 14:19:27.268 D/vzAnalytics(16259): Moved 2 events from thread 1 to bg thread. bg thread pending events 2 02-09 14:19:27.268 D/vzAnalytics(16259): Saving log to db on thread 11 for 2 events 02-09 14:19:27.432 D/vzAnalytics(16259): WiFi:true, CellData:false 02-09 14:19:27.439 D/vzAnalytics(16259): Enqueuing server log task. 02-09 14:19:27.439 D/vzAnalytics(16259): Running server log task on thread 11 for 2 events. url :http://www22.verizon.com/clickStream/Tracker.svc/xml/async/postmetrics 02-09 14:19:27.596 D/vzAnalytics(16259): deleting events after server log. 02-09 14:19:27.705 I/Process ( 1375): Sending signal. PID: 1574 SIG: 3 02-09 14:19:27.736 I/Process ( 1375): Sending signal. PID: 16044 SIG: 3 02-09 14:19:27.760 E/ActivityManager( 1375): ANR in com.verizon.ams.tesla (com.verizon.ams.tesla/com.verizon.mediamanager.AudioItemList) 02-09 14:19:27.760 E/ActivityManager( 1375): Reason: keyDispatchingTimedOut 02-09 14:19:27.760 E/ActivityManager( 1375): Load: 1.45 / 1.46 / 1.1 02-09 14:19:27.760 E/ActivityManager( 1375): CPU usage from 5884ms to 868ms ago with 99% awake: 02-09 14:19:27.760 E/ActivityManager( 1375): 8.3% 16259/com.verizon.ams.tesla: 6.7% user + 1.5% kernel / faults: 6 minor 02-09 14:19:27.760 E/ActivityManager( 1375): 7.3% 1433/tiwlan_wq: 0% user + 7.3% kernel 02-09 14:19:27.760 E/ActivityManager( 1375): 1.9% 3/ksoftirqd/0: 0% user + 1.9% kernel 02-09 14:19:27.760 E/ActivityManager( 1375): 1.9% 1375/system_server: 1.3% user + 0.5% kernel / faults: 71 minor 02-09 14:19:27.760 E/ActivityManager( 1375): 0.9% 783/mmcqd: 0% user + 0.9% kernel 02-09 14:19:27.760 E/ActivityManager( 1375): 0.7% 16044/com.amazon.kindle.otter: 0.7% user + 0% kernel / faults: 1 minor 02-09 14:19:27.760 E/ActivityManager( 1375): 0.3% 7/events/0: 0% user + 0.3% kernel 02-09 14:19:27.760 E/ActivityManager( 1375): 0.3% 1574/com.amazon.cloud9: 0.3% user + 0% kernel / faults: 11 minor 02-09 14:19:27.760 E/ActivityManager( 1375): 0.1% 501/kswapd0: 0% user + 0.1% kernel 02-09 14:19:27.760 E/ActivityManager( 1375): 0.1% 1280/jbd2/mmcblk0p10: 0% user + 0.1% kernel 02-09 14:19:27.760 E/ActivityManager( 1375): 0.1% 1374/flush-179:0: 0% user + 0.1% kernel 02-09 14:19:27.760 E/ActivityManager( 1375): 0.1% 1442/com.android.systemui: 0% user + 0.1% kernel / faults: 16 minor 02-09 14:19:27.760 E/ActivityManager( 1375): 93% TOTAL: 4.1% user + 5.8% kernel + 82% iowait + 0.9% softirq 02-09 14:19:27.760 E/ActivityManager( 1375): CPU usage from 479ms to 997ms later: 02-09 14:19:27.760 E/ActivityManager( 1375): 61% 16259/com.verizon.ams.tesla: 48% user + 13% kernel / faults: 127 minor 02-09 14:19:27.760 E/ActivityManager( 1375): 46% 16259/rizon.ams.tesla: 40% user + 5.7% kernel 02-09 14:19:27.760 E/ActivityManager( 1375): 5.7% 16287/Thread-11: 1.9% user + 3.8% kernel 02-09 14:19:27.760 E/ActivityManager( 1375): 3.8% 16440/AsyncTask #1: 3.8% user + 0% kernel 02-09 14:19:27.760 E/ActivityManager( 1375): 9.2% 1574/com.amazon.cloud9: 7.6% user + 1.5% kernel / faults: 7 minor 02-09 14:19:27.760 E/ActivityManager( 1375): 9.2% 15899/SpdyClient-Work: 9.2% user + 0% kernel 02-09 14:19:27.760 E/ActivityManager( 1375): 1.5% 15503/SpdyConnectionF: 1.5% user + 0% kernel 02-09 14:19:27.760 E/ActivityManager( 1375): 7.6% 1433/tiwlan_wq: 0% user + 7.6% kernel 02-09 14:19:27.760 E/ActivityManager( 1375): 3.8% 1375/system_server: 0% user + 3.8% kernel / faults: 3 minor 02-09 14:19:27.760 E/ActivityManager( 1375): 1.9% 1382/SurfaceFlinger: 1.9% user + 0% kernel 02-09 14:19:27.760 E/ActivityManager( 1375): 1.9% 1416/InputDispatcher: 0% user + 1.9% kernel 02-09 14:19:27.760 E/ActivityManager( 1375): 1.6% 16044/com.amazon.kindle.otter: 1.6% user + 0% kernel 02-09 14:19:27.760 E/ActivityManager( 1375): 1.6% 16249/logcat: 0% user + 1.6% kernel 02-09 14:19:27.760 E/ActivityManager( 1375): 63% TOTAL: 31% user + 12% kernel + 17% iowait + 1.9% softirq 02-09 14:19:27.799 I/vzAnalytics(16259): complete server log task. success :true 02-09 14:19:28.064 D/dalvikvm( 1375): GC_FOR_MALLOC freed 1429K, 50% free 6169K/12103K, external 4519K/5371K, paused 71ms 02-09 14:19:28.103 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:19:28.103 I/LAB126 ( 1442): window changed 02-09 14:19:28.205 D/dalvikvm( 1375): GC_FOR_MALLOC freed 368K, 48% free 6336K/12103K, external 4515K/5371K, paused 50ms 02-09 14:19:28.260 D/dalvikvm( 1375): GC_FOR_MALLOC freed 494K, 46% free 6580K/12103K, external 4515K/5371K, paused 47ms 02-09 14:19:28.260 I/dalvikvm-heap( 1375): Grow heap (frag case) to 13.911MB for 729162-byte allocation 02-09 14:19:28.314 D/dalvikvm( 1375): GC_FOR_MALLOC freed 0K, 44% free 7293K/12871K, external 4515K/5371K, paused 45ms 02-09 14:19:28.369 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:19:28.369 I/LAB126 ( 1442): window changed 02-09 14:19:28.947 D/mediamanager(16259): HTTP download http://fvccd.verizon.net/m3/svc/dl/sec/med/dl2.dl?cxt=6H5OFXf1FrOGz2%2f3SWxdtfEPOdU6OmP995Tz69545wFpbRmW4QMGlJjbiz3GIMiIzTSkBuEFgq25UqTKpJgQzAns%2f1lBgs9i%2b3ImjWJWfqY%3d&tt=ri2gL9bf0KSX88GW%2f4Ki9LxtiynwmRcdceHcl5x0HK18utePpUlgjbx3KuP8KaADdVsbPAEoe3KnBs%2f8jVmR5A%3d%3d&HTTP_ACCESSPOINTID=MP007&HTTP_OS=Android&HTTP_VERSION=2.6.35.7+&HTTP_MM_APP_MEDIA=com.verizon.mediamanager&HTTP_MM_APP_VERSION=1.5.0&HTTP_HARDWARE_MODEL=Kindle_Fire&HTTP_HARDWARE_MAKE=Amazon& 02-09 14:19:31.275 W/ActivityManager( 1375): Force finishing activity com.verizon.ams.tesla/com.verizon.mediamanager.AudioItemList 02-09 14:19:31.283 I/Process ( 1375): Sending signal. PID: 16259 SIG: 9 02-09 14:19:31.283 I/ActivityManager( 1375): Killing com.verizon.ams.tesla (pid=16259): user's request 02-09 14:19:31.314 E/InputDispatcher( 1375): channel '4091e260 com.verizon.ams.tesla/com.verizon.ams.tesla.ui.MainActivity (server)' ~ Consumer closed input channel or an error occurred. events=0x8 02-09 14:19:31.314 E/InputDispatcher( 1375): channel '4091e260 com.verizon.ams.tesla/com.verizon.ams.tesla.ui.MainActivity (server)' ~ Channel is unrecoverably broken and will be disposed! 02-09 14:19:31.314 E/InputDispatcher( 1375): channel '40907af0 com.verizon.ams.tesla/com.verizon.mediamanager.AudioAlbumList (server)' ~ Consumer closed input channel or an error occurred. events=0x8 02-09 14:19:31.314 E/InputDispatcher( 1375): channel '40907af0 com.verizon.ams.tesla/com.verizon.mediamanager.AudioAlbumList (server)' ~ Channel is unrecoverably broken and will be disposed! 02-09 14:19:31.314 I/WindowManager( 1375): WINDOW DIED Window{4091e260 com.verizon.ams.tesla/com.verizon.ams.tesla.ui.MainActivity paused=false} 02-09 14:19:31.314 I/ActivityManager( 1375): Process com.verizon.ams.tesla (pid 16259) has died. 02-09 14:19:31.314 W/ActivityManager( 1375): Service crashed 2 times, stopping: ServiceRecord{409746d8 com.verizon.ams.tesla/com.verizon.mediamanager.queue.QueueService} 02-09 14:19:31.314 W/ActivityManager( 1375): Service crashed 2 times, stopping: ServiceRecord{407684d8 com.verizon.ams.tesla/.service.download.MetaDataSyncService} 02-09 14:19:31.314 W/ActivityManager( 1375): Service crashed 2 times, stopping: ServiceRecord{4085bcb0 com.verizon.ams.tesla/com.verizon.mediamanager.VideoPlayerService} 02-09 14:19:31.314 W/ActivityManager( 1375): Service crashed 2 times, stopping: ServiceRecord{40767a90 com.verizon.ams.tesla/.service.download.DownloadService} 02-09 14:19:31.330 E/InputDispatcher( 1375): channel '406a6d68 com.verizon.ams.tesla/com.verizon.mediamanager.AudioItemList (server)' ~ Consumer closed input channel or an error occurred. events=0x8 02-09 14:19:31.330 E/InputDispatcher( 1375): channel '406a6d68 com.verizon.ams.tesla/com.verizon.mediamanager.AudioItemList (server)' ~ Channel is unrecoverably broken and will be disposed! 02-09 14:19:31.330 I/WindowManager( 1375): WINDOW DIED Window{40907af0 com.verizon.ams.tesla/com.verizon.mediamanager.AudioAlbumList paused=false} 02-09 14:19:31.330 W/WindowManager( 1375): Failed looking up window 02-09 14:19:31.330 W/WindowManager( 1375): java.lang.IllegalArgumentException: Requested window android.os.BinderProxy@409078f0 does not exist 02-09 14:19:31.330 W/WindowManager( 1375): at com.android.server.WindowManagerService.windowForClientLocked(WindowManagerService.java:8177) 02-09 14:19:31.330 W/WindowManager( 1375): at com.android.server.WindowManagerService.windowForClientLocked(WindowManagerService.java:8168) 02-09 14:19:31.330 W/WindowManager( 1375): at com.android.server.WindowManagerService$WindowState$DeathRecipient.binderDied(WindowManagerService.java:7027) 02-09 14:19:31.330 W/WindowManager( 1375): at android.os.BinderProxy.sendDeathNotice(Binder.java:381) 02-09 14:19:31.330 W/WindowManager( 1375): at dalvik.system.NativeStart.run(Native Method) 02-09 14:19:31.330 I/WindowManager( 1375): WIN DEATH: null 02-09 14:19:31.338 I/WindowManager( 1375): WIN DEATH: Window{406a6d68 com.verizon.ams.tesla/com.verizon.mediamanager.AudioItemList paused=true} 02-09 14:19:31.346 I/ActivityManager( 1375): Start proc com.verizon.ams.tesla for activity com.verizon.ams.tesla/com.verizon.mediamanager.AudioAlbumList: pid=16486 uid=10028 gids={3003, 1015} 02-09 14:19:31.385 D/dalvikvm(16486): Debugger has detached; object registry had 1 entries 02-09 14:19:31.400 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:19:31.400 I/LAB126 ( 1442): window changed 02-09 14:19:31.400 I/LAB126 ( 1442): don't set softkey config for 'Starting...' window 02-09 14:19:31.416 I/ActivityManager( 1375): Displayed com.verizon.ams.tesla/com.verizon.mediamanager.AudioItemList: +12s104ms 02-09 14:19:32.791 I/ActivityThread(16486): Pub com.verizon.mediamanager.SearchSuggestion: com.verizon.mediamanager.SearchSuggestion 02-09 14:19:32.791 D/ContentProvider(16486): Videos folder exist 02-09 14:19:32.791 D/ContentProvider(16486): Pictures folder exists 02-09 14:19:32.791 I/MSV (16486): FiosTV Remote DVR Configuration 02-09 14:19:32.791 I/MSV (16486): =============================== 02-09 14:19:32.791 I/MSV (16486): Config: production 02-09 14:19:32.799 I/MSV (16486): Device Model: Kindle Fire 02-09 14:19:32.799 I/MSV (16486): Proxy URL: https://www32.verizon.com/vvmapp2/VVM_LAB.aspx?URL= 02-09 14:19:32.799 I/MSV (16486): Network Timeout: 25000 ms 02-09 14:19:32.799 I/MSV (16486): =============================== 02-09 14:19:32.807 V/MSVAppData(16486): init MSV data 02-09 14:19:32.807 V/MSVAppData(16486): ********* DEVICEID:4f631457dd1d2ab 02-09 14:19:32.814 D/mediamanager(16486): APP CONTEXT RECYCLING 02-09 14:19:32.814 D/mediamanager(16486): setting environment for mmol : PRODUCTION 02-09 14:19:33.877 D/mediamanager(16486): isAuthenticated:false. SsoService.isLoggedIn:true, FVApplication.userInfo.ssoUserId:ironman1058, deviceRegistration:false 02-09 14:19:33.916 D/dalvikvm(16486): GC_CONCURRENT freed 366K, 48% free 3112K/5959K, external 1091K/1181K, paused 1ms+2ms 02-09 14:19:33.947 D/dalvikvm(16486): GC_EXTERNAL_ALLOC freed 1K, 48% free 3111K/5959K, external 1091K/1181K, paused 25ms 02-09 14:19:34.018 D/dalvikvm(16486): GC_EXTERNAL_ALLOC freed 33K, 49% free 3078K/5959K, external 4841K/6045K, paused 25ms 02-09 14:19:34.072 D/vzAnalytics(16486): WiFi:true, CellData:false 02-09 14:19:34.072 D/vzAnalytics(16486): Started network thread 1328818774086 02-09 14:19:34.072 D/vzAnalytics(16486): Initializing session 1328818774085-5KNWR0C 02-09 14:19:34.080 D/vzAnalytics(16486): Scheduling db and net save task 02-09 14:19:34.080 I/vzAnalytics(16486): Initialized vz analytics. version 2.0.2 02-09 14:19:34.111 I/MSV (16486): added African Cats 02-09 14:19:34.119 V/MSV (16486): WebUtils url:https://www36.verizon.com/MSVAppServices/Anonymous/POX/CatalogXmlServices.asmx/MSVAppRequest? 02-09 14:19:34.119 V/MSV (16486): WebUtils body:strInputXML=GETMEDIADOWNLOADURLDNETtrans_12BB001342339SMSD 02-09 14:19:34.143 D/mediamanager(16486): validation started. setting up SSO. 02-09 14:19:34.213 D/dalvikvm(16486): GC_CONCURRENT freed 309K, 46% free 3312K/6087K, external 2794K/3467K, paused 2ms+2ms 02-09 14:19:34.299 V/DesEncrypter(16486): error while decrypt: javax.crypto.IllegalBlockSizeException: last block incomplete in decryption 02-09 14:19:34.299 I/System.out(16486): Account Migration Exception : java.lang.NullPointerException 02-09 14:19:34.322 V/DRMManager(16486): PV Lib not linked 02-09 14:19:34.322 E/FVApplication(16486): TRY MOTO DRM 02-09 14:19:34.322 E/FVApplication(16486): SUCCESS bind to Janus DRM API 02-09 14:19:34.322 V/DeviceDRMInfoManager(16486): fetchDeviceDRMInfo() :: url = http://www98-west.verizon.com/mobilesvc/adLibSvc/adLibRestSvc/Devicelist?Model=Kindle+Fire&firmware=default&ostype=android&osversion=10&appname=MM&appversion=1.5.0&format=xml 02-09 14:19:34.322 W/ActivityManager( 1375): Unable to start service Intent { act=com.motorola.android.wmdrm.IWmdrmService }: not found 02-09 14:19:34.330 V/MSV (16486): WebUtils url:http://www98-west.verizon.com/mobilesvc/adLibSvc/adLibRestSvc/Devicelist?Model=Kindle+Fire&firmware=default&ostype=android&osversion=10&appname=MM&appversion=1.5.0&format=xml 02-09 14:19:34.330 V/MetaDataSyncService(16486): getMediaIds(): 02-09 14:19:34.369 D/vzAnalytics(16486): Loaded 0 config keys 02-09 14:19:34.377 V/SSOWebUtils(16486): PrepareSSO() Start 02-09 14:19:34.557 V/SSOWebUtils(16486): PrepareSSO() VALID COOKIE AVAILABLE 02-09 14:19:34.588 I/UrlComposer(16486): >>>>>> GETUSERPROFILE <<<<<< 02-09 14:19:34.588 V/SSOWebUtils(16486): fetchUserProfile() :: url = https://www36.verizon.com/MSVAppServices/Authenticated/POX/AccountMgrXmlServices.asmx/MSVAppRequest? 02-09 14:19:34.588 V/SSOWebUtils(16486): fetchUserProfile() :: postData = strInputXML=GETMSVPROFILEironman1058DNETtrans_12BB001 02-09 14:19:34.588 V/MSV (16486): WebUtils url:https://www36.verizon.com/MSVAppServices/Authenticated/POX/AccountMgrXmlServices.asmx/MSVAppRequest? 02-09 14:19:34.588 V/MSV (16486): WebUtils body:strInputXML=GETMSVPROFILEironman1058DNETtrans_12BB001 02-09 14:19:34.705 I/ActivityManager( 1375): Displayed com.verizon.ams.tesla/com.verizon.mediamanager.AudioAlbumList: +3s366ms 02-09 14:19:34.713 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:19:34.713 I/LAB126 ( 1442): window changed 02-09 14:19:34.900 D/dalvikvm(16486): GC_FOR_MALLOC freed 523K, 45% free 3815K/6855K, external 2849K/3467K, paused 35ms 02-09 14:19:34.932 V/MetaDataSyncService(16486): downloadPurchaseList() :: url = https://www36.verizon.com/MSVAppServices/Authenticated/POX/AccountMgrXmlServices.asmx/MSVAppRequest? 02-09 14:19:34.932 V/MetaDataSyncService(16486): downloadPurchaseList() :: postData = strInputXML=GETPURCHASEDTITLESironman1058DNETtrans_12BB001YDESCproduct_purchasedDateALLAverageRatingALLALL 02-09 14:19:34.932 V/MSV (16486): WebUtils url:https://www36.verizon.com/MSVAppServices/Authenticated/POX/AccountMgrXmlServices.asmx/MSVAppRequest? 02-09 14:19:34.932 V/MSV (16486): WebUtils body:strInputXML=GETPURCHASEDTITLESironman1058DNETtrans_12BB001YDESCproduct_purchasedDateALLAverageRatingALLALL 02-09 14:19:34.939 V/MetaDataSyncService(16486): downloadWatchList() :: url = https://www36.verizon.com/MSVAppServices/Authenticated/POX/AccountMgrXmlServices.asmx/MSVAppRequest? 02-09 14:19:34.939 V/MetaDataSyncService(16486): downloadWatchList() :: postData = strInputXML=GETWATCHLISTironman1058DNETtrans_12BB001DESCproduct_dtmcreateDateALLAverageRatingALLALL 02-09 14:19:34.939 V/MSV (16486): WebUtils url:https://www36.verizon.com/MSVAppServices/Authenticated/POX/AccountMgrXmlServices.asmx/MSVAppRequest? 02-09 14:19:34.939 V/MSV (16486): WebUtils body:strInputXML=GETWATCHLISTironman1058DNETtrans_12BB001DESCproduct_dtmcreateDateALLAverageRatingALLALL 02-09 14:19:35.447 V/MSV (16486): WebUtils url:https://www36.verizon.com/MSVAppServices/Authenticated/POX/CatalogXmlServices.asmx/MSVAppRequest? 02-09 14:19:35.447 V/MSV (16486): WebUtils body:strInputXML=GETUSERRATINGSironman1058DNETtrans_12BB001 02-09 14:19:35.447 V/MetaDataSyncService(16486): getContentItemIds(): PKGE0450000000492574 02-09 14:19:35.447 V/MetaDataSyncService(16486): downloadSubMetadata() :: url = https://www36.verizon.com/MSVAppServices/Anonymous/POX/CatalogXmlServices.asmx/MSVAppRequest? 02-09 14:19:35.447 V/MetaDataSyncService(16486): downloadSubMetadata() :: postData = strInputXML=GETALLCONTENTDETAILSBYCONTENTIDDNETtrans_12BB001PKGE0450000000492574 02-09 14:19:35.447 V/MSV (16486): WebUtils url:https://www36.verizon.com/MSVAppServices/Anonymous/POX/CatalogXmlServices.asmx/MSVAppRequest? 02-09 14:19:35.447 V/MSV (16486): WebUtils body:strInputXML=GETALLCONTENTDETAILSBYCONTENTIDDNETtrans_12BB001PKGE0450000000492574 02-09 14:19:35.682 I/SSOWebUtils(16486): validationResponseHandler.GET_MSV_PROFILE_REQUEST.. 02-09 14:19:35.682 V/MSV (16486): WebUtils finished http post call 02-09 14:19:35.705 V/SSOWebUtils(16486): User Profile: [userId:reswio0m][domain:DNET][userType:A][subscriptionAvailable:true][timeOffset:0] 02-09 14:19:35.713 I/UrlComposer(16486): >>>>>> GETTERMSOFSERVICE <<<<<< 02-09 14:19:35.713 V/SSOWebUtils(16486): FetchTOS url = https://www36.verizon.com/MSVAppServices/Authenticated/POX/AccountMgrXmlServices.asmx/MSVAppRequest? 02-09 14:19:35.713 V/SSOWebUtils(16486): FetchTOS postData = strInputXML=GETUSERTOSironman1058DNETtrans_12BB001 02-09 14:19:35.713 V/MSV (16486): WebUtils url:https://www36.verizon.com/MSVAppServices/Authenticated/POX/AccountMgrXmlServices.asmx/MSVAppRequest? 02-09 14:19:35.713 V/MSV (16486): WebUtils body:strInputXML=GETUSERTOSironman1058DNETtrans_12BB001 02-09 14:19:35.744 V/MSV (16486): WebUtils finished http post call 02-09 14:19:35.752 I/WifiManager(16486): WiFi lock 0 acquired for DownloadMgr wifi lock. 02-09 14:19:36.166 V/MSV (16486): WebUtils finished http post call 02-09 14:19:36.166 I/SSOWebUtils(16486): validationResponseHandler.GET_TOS_REQUEST ... 02-09 14:19:36.166 V/MSV_TOS (16486): TOS CREATED 02-09 14:19:36.174 D/mediamanager(16486): received message from sso. msg.arg1:0 02-09 14:19:36.174 D/mediamanager(16486): checking device registration. 02-09 14:19:36.189 E/DeviceIdentity(16486): readPhoneNumberFile() 02-09 14:19:36.189 E/DeviceIdentity(16486): java.io.FileNotFoundException: /data/data/com.verizon.ams.tesla/files/wtn.txt (No such file or directory) 02-09 14:19:36.189 E/DeviceIdentity(16486): at org.apache.harmony.luni.platform.OSFileSystem.open(Native Method) 02-09 14:19:36.189 E/DeviceIdentity(16486): at dalvik.system.BlockGuard$WrappedFileSystem.open(BlockGuard.java:232) 02-09 14:19:36.189 E/DeviceIdentity(16486): at java.io.RandomAccessFile.(RandomAccessFile.java:132) 02-09 14:19:36.189 E/DeviceIdentity(16486): at com.verizon.ams.tesla.device.DeviceIdentity.readPhoneNumberFile(DeviceIdentity.java:87) 02-09 14:19:36.189 E/DeviceIdentity(16486): at com.verizon.ams.tesla.device.DeviceIdentity.getPhoneNumber(DeviceIdentity.java:54) 02-09 14:19:36.189 E/DeviceIdentity(16486): at com.verizon.ams.tesla.device.DeviceIdentity.getDeviceLabel(DeviceIdentity.java:42) 02-09 14:19:36.189 E/DeviceIdentity(16486): at com.verizon.ams.tesla.msv.data.Device.Init(Device.java:27) 02-09 14:19:36.189 E/DeviceIdentity(16486): at com.verizon.ams.tesla.msv.data.Device.(Device.java:21) 02-09 14:19:36.189 E/DeviceIdentity(16486): at com.verizon.ams.tesla.device.DeviceManager.checkAndRegisterDevice(DeviceManager.java:286) 02-09 14:19:36.189 E/DeviceIdentity(16486): at com.verizon.mediamanager.ProtectedActivity.checkAndRegisterDevice(ProtectedActivity.java:239) 02-09 14:19:36.189 E/DeviceIdentity(16486): at com.verizon.mediamanager.ProtectedActivity.access$1(ProtectedActivity.java:232) 02-09 14:19:36.189 E/DeviceIdentity(16486): at com.verizon.mediamanager.ProtectedActivity$1.handleMessage(ProtectedActivity.java:208) 02-09 14:19:36.189 E/DeviceIdentity(16486): at android.os.Handler.dispatchMessage(Handler.java:99) 02-09 14:19:36.189 E/DeviceIdentity(16486): at android.os.Looper.loop(Looper.java:130) 02-09 14:19:36.189 E/DeviceIdentity(16486): at android.app.ActivityThread.main(ActivityThread.java:3683) 02-09 14:19:36.189 E/DeviceIdentity(16486): at java.lang.reflect.Method.invokeNative(Native Method) 02-09 14:19:36.189 E/DeviceIdentity(16486): at java.lang.reflect.Method.invoke(Method.java:507) 02-09 14:19:36.189 E/DeviceIdentity(16486): at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:850) 02-09 14:19:36.189 E/DeviceIdentity(16486): at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:608) 02-09 14:19:36.189 E/DeviceIdentity(16486): at dalvik.system.NativeStart.main(Native Method) 02-09 14:19:36.189 V/SSOWebUtils(16486): PrepareSSO() Start 02-09 14:19:36.221 V/MSV (16486): WebUtils finished http get call 02-09 14:19:36.228 I/DeviceDRMInfoManager(16486): deviceDRMHandler.. 02-09 14:19:36.228 D/dalvikvm(16486): GC_CONCURRENT freed 747K, 43% free 4366K/7559K, external 2849K/3467K, paused 2ms+2ms 02-09 14:19:36.268 V/DeviceDRMInfoManager(16486): DRM FOR THE DEVICE: [SM] 02-09 14:19:36.307 V/SSOWebUtils(16486): PrepareSSO() VALID COOKIE AVAILABLE 02-09 14:19:36.307 I/UrlComposer(16486): >>>>>> GETTERMSOFSERVICE <<<<<< 02-09 14:19:36.307 V/SSOWebUtils(16486): FetchTOS url = https://www36.verizon.com/MSVAppServices/Authenticated/POX/AccountMgrXmlServices.asmx/MSVAppRequest? 02-09 14:19:36.307 V/SSOWebUtils(16486): FetchTOS postData = strInputXML=GETUSERTOSironman1058DNETtrans_12BB001 02-09 14:19:36.307 V/MSV (16486): WebUtils url:https://www36.verizon.com/MSVAppServices/Authenticated/POX/AccountMgrXmlServices.asmx/MSVAppRequest? 02-09 14:19:36.307 V/MSV (16486): WebUtils body:strInputXML=GETUSERTOSironman1058DNETtrans_12BB001 02-09 14:19:36.322 W/InputManagerService( 1375): Got RemoteException sending setActive(false) notification to pid 16259 uid 10028 02-09 14:19:36.947 I/SSOWebUtils(16486): validationResponseHandler.GET_TOS_REQUEST ... 02-09 14:19:36.947 V/MSV_TOS (16486): TOS CREATED 02-09 14:19:36.947 V/MSV (16486): >>>> SSO HANDLER. Response MSG =0/0 02-09 14:19:36.955 V/MSV (16486): WebUtils finished http post call 02-09 14:19:36.978 V/DeviceManager(16486): url: https://www36.verizon.com/MSVAppServices/Authenticated/POX/DeviceXmlServices.asmx/MSVAppRequest? 02-09 14:19:36.978 V/DeviceManager(16486): body: strInputXML=GETALLDEVICESironman1058DNETtrans_12BB001Y 02-09 14:19:36.978 V/MSV (16486): WebUtils url:https://www36.verizon.com/MSVAppServices/Authenticated/POX/DeviceXmlServices.asmx/MSVAppRequest? 02-09 14:19:36.978 V/MSV (16486): WebUtils body:strInputXML=GETALLDEVICESironman1058DNETtrans_12BB001Y 02-09 14:19:37.025 I/MetaDataSyncService(16486): getting purchaselist successful! 02-09 14:19:37.033 V/MSV (16486): WebUtils finished http post call 02-09 14:19:37.346 I/MetaDataSyncService(16486): purchaselistIndex size bobby:0 02-09 14:19:37.346 I/MetaDataSyncService(16486): purchaselistIndex size bobby:0 02-09 14:19:37.346 I/MetaDataSyncService(16486): Purchasehistory list Parsing successfully 02-09 14:19:39.486 V/MSV (16486): WebUtils finished http post call 02-09 14:19:39.486 V/MSV (16486): WebUtils finished http post call 02-09 14:19:39.494 V/MSV (16486): Silent request done... 02-09 14:19:39.494 V/MSV (16486): getting watchlist successful! 02-09 14:19:39.533 D/dalvikvm(16486): GC_CONCURRENT freed 1112K, 44% free 4700K/8263K, external 3073K/3467K, paused 2ms+2ms 02-09 14:19:39.650 V/MSV (16486): watchlist index created!9 02-09 14:19:39.650 I/MSV (16486): Watchlist Parsing successfully 02-09 14:19:40.072 I/MetaDataSyncService(16486): Getting Metadata successful! 02-09 14:19:40.080 V/MSV (16486): WebUtils finished http post call 02-09 14:19:40.088 I/MetaDataSyncService(16486): Metadata Parsing successful 02-09 14:19:40.182 I/CommonUtils(16486): Date Parse Exception = Unparseable date: "2011-09-01" 02-09 14:19:40.182 W/System.err(16486): java.text.ParseException: Unparseable date: "2011-09-01" 02-09 14:19:40.182 W/System.err(16486): at java.text.DateFormat.parse(DateFormat.java:626) 02-09 14:19:40.182 W/System.err(16486): at com.verizon.ams.tesla.utils.CommonUtils.convertDateToMsec(CommonUtils.java:1156) 02-09 14:19:40.189 W/System.err(16486): at com.verizon.ams.tesla.utils.CommonUtils.checkProductExpiration(CommonUtils.java:1496) 02-09 14:19:40.189 W/System.err(16486): at com.verizon.ams.tesla.service.download.MetaDataSyncService$MetadataSyncTask$3.handleMessage(MetaDataSyncService.java:625) 02-09 14:19:40.189 W/System.err(16486): at android.os.Handler.dispatchMessage(Handler.java:99) 02-09 14:19:40.189 W/System.err(16486): at android.os.Looper.loop(Looper.java:130) 02-09 14:19:40.189 W/System.err(16486): at android.os.HandlerThread.run(HandlerThread.java:60) 02-09 14:19:41.408 V/MSV (16486): WebUtils finished http post call 02-09 14:19:41.408 D/mediamanager(16486): handlerDeviceMgr(): got 11110000:11110007 02-09 14:19:41.408 D/mediamanager(16486): Device registration succeeded 02-09 14:19:41.408 D/mediamanager(16486): Audio album list onValidated. 02-09 14:19:41.416 W/InputManagerService( 1375): Window already focused, ignoring focus gain of: com.android.internal.view.IInputMethodClient$Stub$Proxy@4092c708 02-09 14:19:41.502 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:19:41.502 I/LAB126 ( 1442): window changed 02-09 14:19:43.275 D/mediamanager(16486): HTTP get http://www22.verizon.com/M3/svc/auth/Mediaservice.svc/com/users/reswio0m/TimeToken 02-09 14:19:44.369 W/ResponseProcessCookies(16486): Cookie rejected: "BasicClientCookie[version=0,name=ak-sf,domain=verizon.com,path=/m3/,expiry=Thu Feb 09 14:24:44 CST 2012]". Illegal path attribute "/m3/". Path of origin: "/M3/svc/auth/Mediaservice.svc/com/users/reswio0m/TimeToken" 02-09 14:19:44.369 D/mediamanager(16486): TOKEN REFRESHED 02-09 14:19:44.416 D/dalvikvm(16486): GC_CONCURRENT freed 1493K, 46% free 4822K/8775K, external 3017K/3467K, paused 1ms+3ms 02-09 14:19:44.596 D/mediamanager(16486): HTTP get http://www22.verizon.com/M3/svc/auth/mediaservice.svc/com/users/UserName/albums/type/AudioAlbum?fmt=xml&sortorder=ASC&SortBy=Title&dojo.preventCache=1264380228170 02-09 14:19:44.994 W/ResponseProcessCookies(16486): Cookie rejected: "BasicClientCookie[version=0,name=ak-sf,domain=verizon.com,path=/m3/,expiry=Thu Feb 09 14:24:44 CST 2012]". Illegal path attribute "/m3/". Path of origin: "/M3/svc/auth/mediaservice.svc/com/users/UserName/albums/type/AudioAlbum" 02-09 14:19:45.010 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:19:45.010 I/LAB126 ( 1442): window changed 02-09 14:19:46.978 D/ActivityManager( 1375): Starting: Intent { cmp=com.verizon.ams.tesla/com.verizon.mediamanager.AudioItemList (has extras) } from pid 16486 02-09 14:19:47.158 D/dalvikvm( 1375): GC_CONCURRENT freed 2756K, 50% free 6485K/12871K, external 4515K/5371K, paused 2ms+10ms 02-09 14:19:47.260 D/dalvikvm(16486): GC_EXTERNAL_ALLOC freed 564K, 48% free 4585K/8775K, external 3062K/3467K, paused 33ms 02-09 14:19:47.564 D/mediamanager(16486): start getting album items pageNo #1 02-09 14:19:47.658 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:19:47.658 I/LAB126 ( 1442): window changed 02-09 14:19:47.900 I/ActivityManager( 1375): Displayed com.verizon.ams.tesla/com.verizon.mediamanager.AudioItemList: +916ms 02-09 14:19:48.853 D/mediamanager(16486): HTTP get http://www22.verizon.com/M3/svc/auth/mediaservice.svc/com/users/UserName/albums/05f16538-62aa-476e-8afd-9e2bf19aa742?bGetAlbums=false&fmt=xml&ftype=3&sortorder=DESC&SortBy=UploadDate&pageNo=1&pageSize=250&nonull=true&Enc=1&dojo.preventCache=1264392598150 02-09 14:19:49.127 W/ResponseProcessCookies(16486): Cookie rejected: "BasicClientCookie[version=0,name=ak-sf,domain=verizon.com,path=/m3/,expiry=Thu Feb 09 14:24:49 CST 2012]". Illegal path attribute "/m3/". Path of origin: "/M3/svc/auth/mediaservice.svc/com/users/UserName/albums/05f16538-62aa-476e-8afd-9e2bf19aa742" 02-09 14:19:49.346 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:19:49.346 I/LAB126 ( 1442): window changed 02-09 14:19:51.463 D/dalvikvm(16486): GC_EXTERNAL_ALLOC freed 549K, 48% free 4649K/8775K, external 5684K/5903K, paused 35ms 02-09 14:19:51.572 D/dalvikvm(16486): GC_EXTERNAL_ALLOC freed 313K, 51% free 4354K/8775K, external 6884K/7074K, paused 34ms 02-09 14:19:54.111 D/vzAnalytics(16486): Moved 3 events from thread 1 to bg thread. bg thread pending events 3 02-09 14:19:54.111 D/vzAnalytics(16486): Saving log to db on thread 11 for 3 events 02-09 14:19:54.299 D/vzAnalytics(16486): WiFi:true, CellData:false 02-09 14:19:54.299 D/vzAnalytics(16486): Enqueuing server log task. 02-09 14:19:54.299 D/vzAnalytics(16486): Running server log task on thread 11 for 1 events. url :http://www22.verizon.com/clickStream/Tracker.svc/xml/async/postmetrics 02-09 14:19:54.471 D/vzAnalytics(16486): deleting events after server log. 02-09 14:19:54.518 I/vzAnalytics(16486): complete server log task. success :true 02-09 14:19:54.518 D/vzAnalytics(16486): Scheduling db and net save task 02-09 14:19:56.064 I/MSV (16486): send downloading event 02-09 14:19:56.080 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:19:56.080 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:19:56.080 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:19:56.080 D/IconMerger( 1442): notification for com.android.systemui (1) 02-09 14:19:56.080 D/IconMerger( 1442): sum of notifications: 4 02-09 14:19:56.861 D/LAB126 ( 1442): got back button softkey click! 02-09 14:19:56.861 D/LAB126 ( 1442): collapse because of back button 02-09 14:19:56.861 W/KeyCharacterMap(16486): No keyboard for id 0 02-09 14:19:56.861 W/KeyCharacterMap(16486): Using default keymap: /system/usr/keychars/qwerty.kcm.bin 02-09 14:19:56.861 D/LAB126 ( 1442): collapse softkeys 02-09 14:19:57.119 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:19:57.119 I/LAB126 ( 1442): window changed 02-09 14:19:58.338 D/LAB126 ( 1442): got back button softkey click! 02-09 14:19:58.338 D/LAB126 ( 1442): collapse because of back button 02-09 14:19:58.338 D/LAB126 ( 1442): collapse softkeys 02-09 14:19:58.455 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:19:58.455 I/LAB126 ( 1442): window changed 02-09 14:19:58.455 I/LAB126 ( 1442): don't set softkey config for 'Starting...' window 02-09 14:19:58.549 D/dalvikvm(16486): GC_EXTERNAL_ALLOC freed 250K, 49% free 4513K/8775K, external 5077K/6325K, paused 46ms 02-09 14:19:58.807 I/ActivityManager( 1375): Displayed com.verizon.ams.tesla/.ui.MainActivity: +392ms 02-09 14:19:58.814 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:19:58.814 I/LAB126 ( 1442): window changed 02-09 14:19:59.088 V/MSV (16486): finished http post call 02-09 14:19:59.393 D/dalvikvm(16486): GC_CONCURRENT freed 1559K, 45% free 5021K/9031K, external 5750K/6268K, paused 2ms+4ms 02-09 14:19:59.838 D/skia (16486): Loading ARM decoder... 02-09 14:19:59.853 D/skia (16486): Loading ARM decoder... 02-09 14:19:59.853 D/skia (16486): sk_fill_input_buffer():54:: !!!Premature end of JPEG file. Sending dummy EOI. 02-09 14:19:59.853 D/skia (16486): --- decoder->decode returned false 02-09 14:19:59.853 I/System.out(16486): resolveUri failed on bad bitmap uri: /data/data/com.verizon.ams.tesla/cache/703194789.cachefile 02-09 14:19:59.932 D/skia (16486): Loading ARM decoder... 02-09 14:19:59.963 D/dalvikvm(16486): GC_EXTERNAL_ALLOC freed 313K, 46% free 4956K/9031K, external 6261K/6268K, paused 36ms 02-09 14:19:59.986 D/skia (16486): Loading ARM decoder... 02-09 14:19:59.986 D/skia (16486): sk_fill_input_buffer():54:: !!!Premature end of JPEG file. Sending dummy EOI. 02-09 14:19:59.986 D/skia (16486): --- decoder->decode returned false 02-09 14:19:59.986 I/System.out(16486): resolveUri failed on bad bitmap uri: /data/data/com.verizon.ams.tesla/cache/703194789.cachefile 02-09 14:20:00.080 D/skia (16486): Loading ARM decoder... 02-09 14:20:00.111 D/skia (16486): Loading ARM decoder... 02-09 14:20:00.119 D/skia (16486): Loading ARM decoder... 02-09 14:20:00.478 D/ActivityManager( 1375): Starting: Intent { act=android.intent.action.VIEW dat=app://com.verizon.ams.tesla/mydownloads cmp=com.verizon.ams.tesla/.ui.TabDownloadsActivity } from pid 16486 02-09 14:20:00.572 W/ResourceType(16486): Skipping entry 0x7f02015d in package table 0 because it is not complex! 02-09 14:20:00.572 W/ResourceType(16486): Skipping entry 0x7f02015d in package table 0 because it is not complex! 02-09 14:20:00.572 W/ResourceType(16486): Skipping entry 0x7f02015d in package table 0 because it is not complex! 02-09 14:20:00.572 W/ResourceType(16486): Skipping entry 0x7f02015d in package table 0 because it is not complex! 02-09 14:20:00.572 W/ResourceType(16486): Skipping entry 0x7f02015d in package table 0 because it is not complex! 02-09 14:20:00.572 W/ResourceType(16486): Skipping entry 0x7f02015d in package table 0 because it is not complex! 02-09 14:20:00.588 V/MediaLibraryActivity(16486): MediaLibraryActivity.Done Waiting. READ NOW 02-09 14:20:00.588 V/MediaLibraryActivity(16486): getMediaIds(): 02-09 14:20:00.666 I/dalvikvm(16486): Jit: resizing JitTable from 4096 to 8192 02-09 14:20:00.713 V/MediaLibraryActivity(16486): getContentItemIds(): 02-09 14:20:00.744 I/CommonUtils(16486): updatePurchaseStatusForMediaCache .... 02-09 14:20:00.838 V/MediaLibraryActivity(16486): downloadPurchaseList() :: url = https://www36.verizon.com/MSVAppServices/Authenticated/POX/AccountMgrXmlServices.asmx/MSVAppRequest? 02-09 14:20:00.838 V/MediaLibraryActivity(16486): downloadPurchaseList() :: postData = strInputXML=GETPURCHASEDTITLESDNETtrans_12BB001Y 02-09 14:20:00.853 V/MSV (16486): WebUtils url:https://www36.verizon.com/MSVAppServices/Authenticated/POX/AccountMgrXmlServices.asmx/MSVAppRequest? 02-09 14:20:00.853 V/MSV (16486): WebUtils body:strInputXML=GETPURCHASEDTITLESDNETtrans_12BB001Y 02-09 14:20:00.877 V/MSV (16486): WebUtils url:http://www36.verizon.com/MSVAppServices/anonymous/Images/GreenHornet_HD_2011_128x192_bc.jpg 02-09 14:20:00.877 D/MSC_V3.2.7(16486): API MSC_V3.2.7 : getRemainingRightsInfo - START 02-09 14:20:00.877 D/MSC_V3.2.7(16486): initialize sm. 02-09 14:20:00.877 D/MSC_V3.2.7(16486): absolute path : /data/data/com.verizon.ams.tesla/app_msc_home 02-09 14:20:00.877 D/MSC_V3.2.7(16486): asset exists in msc home, NOT copying 02-09 14:20:00.877 D/MSC_V3.2.7(16486): absolute path : /data/data/com.verizon.ams.tesla/app_msc_home 02-09 14:20:00.877 D/MSC_V3.2.7(16486): asset exists in msc home, NOT copying 02-09 14:20:00.877 D/MSC_V3.2.7(16486): MSC CERTS to MSC HOME done 02-09 14:20:00.877 D/dalvikvm(16486): Trying to load lib /data/data/com.verizon.ams.tesla/lib/libSMutility.so 0x40515068 02-09 14:20:00.885 D/dalvikvm(16486): Added shared lib /data/data/com.verizon.ams.tesla/lib/libSMutility.so 0x40515068 02-09 14:20:00.885 D/dalvikvm(16486): No JNI_OnLoad found in /data/data/com.verizon.ams.tesla/lib/libSMutility.so 0x40515068, skipping init 02-09 14:20:00.885 D/dalvikvm(16486): Trying to load lib /data/data/com.verizon.ams.tesla/lib/libsmsimpleclient.so 0x40515068 02-09 14:20:00.885 D/dalvikvm(16486): Added shared lib /data/data/com.verizon.ams.tesla/lib/libsmsimpleclient.so 0x40515068 02-09 14:20:00.885 D/dalvikvm(16486): No JNI_OnLoad found in /data/data/com.verizon.ams.tesla/lib/libsmsimpleclient.so 0x40515068, skipping init 02-09 14:20:00.885 D/MSC_V3.2.7(16486): MSChome : /data/data/com.verizon.ams.tesla/app_msc_home 02-09 14:20:00.885 D/MSC_V3.2.7(16486): SMhome : /data/data/com.verizon.ams.tesla/app_msc_home/sm_home 02-09 14:20:00.885 D/MSC_V3.2.7(16486): DeviceRooted: Genuine 02-09 14:20:00.885 I/SecureMedia(16486): 2012-02-09 14:20:00,smsimpleclient.c(739),INFO,Thread SimpleClient initing with: -l 4 -webapi.allowremote -https.insecure -webapi.port 0 -https.cainfo /data/data/com.verizon.ams.tesla/app_msc_home/MSC_Client_RootCA.pem -https.cert /data/data/com.verizon.ams.tesla/app_msc_home/MSC_Client_chain.pem -https.key /data/data/com.verizon.ams.tesla/app_msc_home/MSC_Client_chain.pem -ps.dirname /data/data/com.verizon.ams.tesla/app_msc_home/sm_home 02-09 14:20:00.885 I/SecureMedia(16486): . 02-09 14:20:00.893 D/SecureMedia(16486): 2012-02-09 14:20:00,smplatform.c(154),TRACE,Main SecureMedia v2.1.0.5699 (Android) 02-09 14:20:00.939 D/SecureMedia(16486): 2012-02-09 14:20:00,smx.c(318),TRACE,Main SMX: No SN for EMM listener in the persistent store. 02-09 14:20:00.939 D/SecureMedia(16486): 2012-02-09 14:20:00,smclient.c(578),TRACE,Main No plugins to communicate with 02-09 14:20:00.939 D/SecureMedia(16486): 2012-02-09 14:20:00,smclient.c(578),TRACE,Main No plugins to communicate with 02-09 14:20:00.939 D/SecureMedia(16486): 2012-02-09 14:20:00,smclient.c(578),TRACE,Main No plugins to communicate with 02-09 14:20:00.947 I/SecureMedia(16486): 2012-02-09 14:20:00,smclientdaemon.c(699),INFO,PingWorker-0 Pinging SecureMedia Broadcast Subscription Service... 02-09 14:20:00.947 D/SecureMedia(16486): 2012-02-09 14:20:00,smdecryptor_tk.c(232),TRACE,Main Setting protection scheme: SHARK 02-09 14:20:00.947 D/SecureMedia(16486): 2012-02-09 14:20:00,smdecryptor_tk.c(237),TRACE,Main _SetSpec: spec=SHARK 02-09 14:20:00.947 D/SecureMedia(16486): 2012-02-09 14:20:00,smdecryptor_tk.c(232),TRACE,Main Setting protection scheme: SHARK 02-09 14:20:00.947 D/SecureMedia(16486): 2012-02-09 14:20:00,smdecryptor_tk.c(237),TRACE,Main _SetSpec: spec=SHARK 02-09 14:20:00.963 I/SecureMedia(16486): 2012-02-09 14:20:00,smsc.c(680),INFO,PingWorker-0 Ping state for 'BSS': SN = 4f631457dd1d2ab, current kids are: 02-09 14:20:00.971 D/SecureMedia(16486): 2012-02-09 14:20:00,smclientplugin.c(359),TRACE,Main Protection scheme: SHARK 02-09 14:20:00.971 D/SecureMedia(16486): 2012-02-09 14:20:00,smm2dec.c(87),TRACE,Main Scramble specification is AES-ECB-BEG 02-09 14:20:00.971 D/SecureMedia(16486): 2012-02-09 14:20:00,smaes.c(428),TRACE,Main AES Copyright: AES Cipher Copyright (c) 2001, Dr Brian Gladman 02-09 14:20:00.971 D/SecureMedia(16486): 2012-02-09 14:20:00,smm2dec.c(87),TRACE,Main Scramble specification is AES-ECB-BEG 02-09 14:20:00.971 D/SecureMedia(16486): 2012-02-09 14:20:00,smclient.c(618),TRACE,Main Note that plugin session has not been initialized yet and thus no encryption will be done on the message id = 10 02-09 14:20:01.596 V/MSV (16486): WebUtils finished http post call 02-09 14:20:02.322 D/dalvikvm( 1375): GC_CONCURRENT freed 2413K, 53% free 6119K/12871K, external 4301K/5371K, paused 3ms+7ms 02-09 14:20:02.369 I/SecureMedia(16486): 2012-02-09 14:20:02,smclient.c(404),INFO,PingWorker-0 Establishing session with 'smclient' 02-09 14:20:02.369 I/SecureMedia(16486): 2012-02-09 14:20:02,smclient.c(658),INFO,PingWorker-0 Establishing session with daemon 02-09 14:20:02.369 D/SecureMedia(16486): 2012-02-09 14:20:02,smclient.c(659),TRACE,PingWorker-0 SMC 02-09 14:20:02.369 D/SecureMedia(16486): 2012-02-09 14:20:02,smwatermark.c(309),TRACE,PingWorker-0 SessionID set to 63506 02-09 14:20:02.369 I/SecureMedia(16486): 2012-02-09 14:20:02,smclientdaemon.c(711),INFO,PingWorker-0 Next BSS ping in 3553 seconds 02-09 14:20:02.369 I/SecureMedia(16486): 2012-02-09 14:20:02,smclientdaemon.c(718),INFO,PingWorker-0 Pinging SecureMedia On-Demand Subscription Service... 02-09 14:20:02.369 I/SecureMedia(16486): 2012-02-09 14:20:02,smclientdaemon.c(730),INFO,PingWorker-0 Next ODSS ping in 86400 seconds 02-09 14:20:02.393 V/MSV (16486): WebUtils finished http get call 02-09 14:20:02.502 D/dalvikvm( 1375): GC_CONCURRENT freed 2250K, 55% free 5797K/12871K, external 4301K/5371K, paused 2ms+3ms 02-09 14:20:02.643 D/dalvikvm( 1375): GC_CONCURRENT freed 1724K, 55% free 5843K/12871K, external 4301K/5371K, paused 3ms+3ms 02-09 14:20:02.807 D/dalvikvm( 1375): GC_CONCURRENT freed 1749K, 55% free 5839K/12871K, external 4301K/5371K, paused 3ms+4ms 02-09 14:20:02.971 D/dalvikvm( 1375): GC_CONCURRENT freed 1833K, 55% free 5872K/12871K, external 4301K/5371K, paused 2ms+3ms 02-09 14:20:02.994 D/SecureMedia(16486): 2012-02-09 14:20:03,smesam2.c(253),TRACE,PingWorker-0 Service not configured: IDETECT(0x6000A): Unknown service 02-09 14:20:02.994 D/SecureMedia(16486): 2012-02-09 14:20:03,smesam2.c(529),TRACE,PingWorker-0 SMC 02-09 14:20:02.994 D/SecureMedia(16486): 2012-02-09 14:20:03,smesam2.c(872),TRACE,PingWorker-0 SMC 02-09 14:20:02.994 D/SecureMedia(16486): 2012-02-09 14:20:03,smesam2.c(905),TRACE,PingWorker-0 SME(0x6000A) 02-09 14:20:02.994 D/SecureMedia(16486): 2012-02-09 14:20:03,smesam2.c(1135),TRACE,PingWorker-0 SMC 02-09 14:20:02.994 D/SecureMedia(16486): 2012-02-09 14:20:03,smclientidetect.c(83),TRACE,PingWorker-0 SMC 02-09 14:20:02.994 D/SecureMedia(16486): 2012-02-09 14:20:03,smclientidetect.c(145),TRACE,PingWorker-0 SMC 02-09 14:20:02.994 D/SecureMedia(16486): 2012-02-09 14:20:03,smmisc.c(466),TRACE,PingWorker-0 Initializing SRNG. 02-09 14:20:02.994 I/SecureMedia(16486): 2012-02-09 14:20:03,smclientidetect.c(157),INFO,PingWorker-0 Next iDetect server check in 85446 seconds 02-09 14:20:02.994 E/SecureMedia(16486): 2012-02-09 14:20:03,smclientidetect.c(161),ERROR,PingWorker-0 iDetect (0x6000A): Unknown service 02-09 14:20:02.994 D/SecureMedia(16486): 2012-02-09 14:20:03,smclientidetect.c(173),TRACE,PingWorker-0 SMC 02-09 14:20:03.033 I/SecureMedia(16486): 2012-02-09 14:20:03,smsimpleclient.c(741),INFO,Main SimpleClient started. 02-09 14:20:03.033 I/SecureMedia(16486): 2012-02-09 14:20:03,smsimpleclient.c(750),INFO,Main Result = 0x0 02-09 14:20:03.033 D/MSC_V3.2.7(16486): initing SM DONE GOOD 02-09 14:20:03.127 D/dalvikvm( 1375): GC_CONCURRENT freed 1873K, 55% free 5872K/12871K, external 4301K/5371K, paused 3ms+4ms 02-09 14:20:03.275 D/dalvikvm( 1375): GC_CONCURRENT freed 1887K, 55% free 5857K/12871K, external 4301K/5371K, paused 2ms+3ms 02-09 14:20:03.330 I/System.out(16486): BEFORE starting to loadlibraries 02-09 14:20:03.330 D/dalvikvm(16486): Trying to load lib /data/data/com.verizon.ams.tesla/lib/libIPRM_Common.so 0x40515068 02-09 14:20:03.330 D/dalvikvm(16486): Added shared lib /data/data/com.verizon.ams.tesla/lib/libIPRM_Common.so 0x40515068 02-09 14:20:03.330 D/dalvikvm(16486): No JNI_OnLoad found in /data/data/com.verizon.ams.tesla/lib/libIPRM_Common.so 0x40515068, skipping init 02-09 14:20:03.330 D/dalvikvm(16486): Trying to load lib /data/data/com.verizon.ams.tesla/lib/libIPRM_Transport.so 0x40515068 02-09 14:20:03.330 D/dalvikvm(16486): Added shared lib /data/data/com.verizon.ams.tesla/lib/libIPRM_Transport.so 0x40515068 02-09 14:20:03.330 D/dalvikvm(16486): No JNI_OnLoad found in /data/data/com.verizon.ams.tesla/lib/libIPRM_Transport.so 0x40515068, skipping init 02-09 14:20:03.330 D/dalvikvm(16486): Trying to load lib /data/data/com.verizon.ams.tesla/lib/libIPRM_CryptoLibraryRobust.so 0x40515068 02-09 14:20:03.330 D/dalvikvm(16486): Added shared lib /data/data/com.verizon.ams.tesla/lib/libIPRM_CryptoLibraryRobust.so 0x40515068 02-09 14:20:03.330 D/dalvikvm(16486): No JNI_OnLoad found in /data/data/com.verizon.ams.tesla/lib/libIPRM_CryptoLibraryRobust.so 0x40515068, skipping init 02-09 14:20:03.330 D/dalvikvm(16486): Trying to load lib /data/data/com.verizon.ams.tesla/lib/libIPRM_CertLibrary.so 0x40515068 02-09 14:20:03.330 D/dalvikvm(16486): Added shared lib /data/data/com.verizon.ams.tesla/lib/libIPRM_CertLibrary.so 0x40515068 02-09 14:20:03.330 D/dalvikvm(16486): No JNI_OnLoad found in /data/data/com.verizon.ams.tesla/lib/libIPRM_CertLibrary.so 0x40515068, skipping init 02-09 14:20:03.330 D/dalvikvm(16486): Trying to load lib /data/data/com.verizon.ams.tesla/lib/libIPRM_SecurityProcessor.so 0x40515068 02-09 14:20:03.330 D/dalvikvm(16486): Added shared lib /data/data/com.verizon.ams.tesla/lib/libIPRM_SecurityProcessor.so 0x40515068 02-09 14:20:03.330 D/dalvikvm(16486): No JNI_OnLoad found in /data/data/com.verizon.ams.tesla/lib/libIPRM_SecurityProcessor.so 0x40515068, skipping init 02-09 14:20:03.330 D/dalvikvm(16486): Trying to load lib /data/data/com.verizon.ams.tesla/lib/libIPRM_ESBThin.so 0x40515068 02-09 14:20:03.338 D/dalvikvm(16486): Added shared lib /data/data/com.verizon.ams.tesla/lib/libIPRM_ESBThin.so 0x40515068 02-09 14:20:03.338 D/dalvikvm(16486): No JNI_OnLoad found in /data/data/com.verizon.ams.tesla/lib/libIPRM_ESBThin.so 0x40515068, skipping init 02-09 14:20:03.338 D/dalvikvm(16486): Trying to load lib /data/data/com.verizon.ams.tesla/lib/libIPRM_RightManagement.so 0x40515068 02-09 14:20:03.338 D/dalvikvm(16486): Added shared lib /data/data/com.verizon.ams.tesla/lib/libIPRM_RightManagement.so 0x40515068 02-09 14:20:03.338 D/dalvikvm(16486): No JNI_OnLoad found in /data/data/com.verizon.ams.tesla/lib/libIPRM_RightManagement.so 0x40515068, skipping init 02-09 14:20:03.338 D/dalvikvm(16486): Trying to load lib /data/data/com.verizon.ams.tesla/lib/libIPRM_DRMRulesConverter.so 0x40515068 02-09 14:20:03.338 D/dalvikvm(16486): Added shared lib /data/data/com.verizon.ams.tesla/lib/libIPRM_DRMRulesConverter.so 0x40515068 02-09 14:20:03.338 D/dalvikvm(16486): No JNI_OnLoad found in /data/data/com.verizon.ams.tesla/lib/libIPRM_DRMRulesConverter.so 0x40515068, skipping init 02-09 14:20:03.338 D/dalvikvm(16486): Trying to load lib /data/data/com.verizon.ams.tesla/lib/libIPRM_ThinAgent.so 0x40515068 02-09 14:20:03.338 D/dalvikvm(16486): Added shared lib /data/data/com.verizon.ams.tesla/lib/libIPRM_ThinAgent.so 0x40515068 02-09 14:20:03.346 D/dalvikvm(16486): No JNI_OnLoad found in /data/data/com.verizon.ams.tesla/lib/libIPRM_ThinAgent.so 0x40515068, skipping init 02-09 14:20:03.346 D/dalvikvm(16486): Trying to load lib /data/data/com.verizon.ams.tesla/lib/libIPRM_JNI.so 0x40515068 02-09 14:20:03.346 D/dalvikvm(16486): Added shared lib /data/data/com.verizon.ams.tesla/lib/libIPRM_JNI.so 0x40515068 02-09 14:20:03.346 D/dalvikvm(16486): No JNI_OnLoad found in /data/data/com.verizon.ams.tesla/lib/libIPRM_JNI.so 0x40515068, skipping init 02-09 14:20:03.346 I/System.out(16486): loadlibraries DONE 02-09 14:20:03.346 D/jAgentHN(16486): before calling native iprmInit 02-09 14:20:03.893 D/------ Activity(16486): iprm init DONE GOOD 02-09 14:20:03.893 D/MSC_V3.2.7(16486): before starting CRMonitorT 02-09 14:20:03.893 D/CRMonitorT(16486): newing CRMonitorT 02-09 14:20:03.893 D/MSC_V3.2.7(16486): Done starting the thread 02-09 14:20:03.893 D/MSC_V3.2.7(16486): END of initilizeSM 02-09 14:20:03.893 D/CRMonitorT(16486): am AWAKE Again ! 02-09 14:20:03.893 D/CRMonitorT(16486): LKGT : 1328818553 02-09 14:20:03.893 D/CRMonitorT(16486): TIME service : service=RightsInfoInt&ver=1.0&scmd=timequery 02-09 14:20:03.900 D/MSC_V3.2.7(16486): device id : 4f631457dd1d2ab 02-09 14:20:03.900 D/MSC_V3.2.7(16486): Getting Rights info from LOCAL for : /mnt/sdcard/.video/The-G_sub_PKGE0450000000492574.mp4 02-09 14:20:03.900 D/MSC_V3.2.7(16486): getRemainingRights for :/mnt/sdcard/.video/The-G_sub_PKGE0450000000492574.mp4 02-09 14:20:03.900 D/MSC_V3.2.7(16486): BEFORE calling iprmHandle.getSMVODRule for content: The-G_sub_PKGE0450000000492574.mp4 02-09 14:20:03.908 D/MSC_V3.2.7(16486): AFTER getSMVODRule 02-09 14:20:03.908 D/MSC_V3.2.7(16486): rentalflag = false 02-09 14:20:03.908 D/MSC_V3.2.7(16486): start time = 0 02-09 14:20:03.908 D/MSC_V3.2.7(16486): play window = 0 02-09 14:20:03.908 D/MSC_V3.2.7(16486): expiry time = 1328894434 02-09 14:20:03.908 D/MSC_V3.2.7(16486): returning RightsInfo 02-09 14:20:03.908 D/MSC_V3.2.7(16486): API MSC_V3.2.7 : getRemainingRightsInfo - END 02-09 14:20:03.978 D/dalvikvm( 1375): GC_CONCURRENT freed 1882K, 55% free 5838K/12871K, external 4301K/5371K, paused 2ms+4ms 02-09 14:20:04.033 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:20:04.033 I/LAB126 ( 1442): window changed 02-09 14:20:04.049 E/FVApplication(16486): Updating Storage Info 02-09 14:20:04.080 I/MediaLibraryActivity(16486): getting purchaselist successful! 02-09 14:20:04.111 D/dalvikvm( 1375): GC_CONCURRENT freed 1822K, 55% free 5873K/12871K, external 4301K/5371K, paused 2ms+10ms 02-09 14:20:04.150 I/MediaLibraryActivity(16486): purchaselistIndex size bobby:19 02-09 14:20:04.150 I/MediaLibraryActivity(16486): purchaselistIndex size bobby:19 02-09 14:20:04.150 I/MediaLibraryActivity(16486): Purchasehistory list Parsing successfully 02-09 14:20:04.158 D/skia (16486): Loading ARM decoder... 02-09 14:20:04.166 V/MediaLibraryActivity(16486): MediaLibraryActivity.Done Waiting. READ NOW 02-09 14:20:04.346 D/dalvikvm(16486): GC_CONCURRENT freed 1592K, 43% free 5422K/9479K, external 7479K/8089K, paused 3ms+5ms 02-09 14:20:04.369 W/InputManagerService( 1375): Window already focused, ignoring focus gain of: com.android.internal.view.IInputMethodClient$Stub$Proxy@406afa28 02-09 14:20:04.627 I/CommonUtils(16486): updatePurchaseStatusForMediaCache .... 02-09 14:20:04.635 D/CRMonitorT(16486): LKST RESPONSE: 0Success2012-02-09T15:20:04-05:00 02-09 14:20:04.635 D/RMTimeQueryProcessor(16486): Parsing : 0Success2012-02-09T15:20:04-05:00 02-09 14:20:04.643 D/-------MyUtils(16486): out : time in seconds:1328818804 02-09 14:20:04.643 D/CRMonitorT(16486): LKST VALUE : 2012-02-09T14:20:04-06:00 02-09 14:20:04.643 D/CRMonitorT(16486): updating lkgt with server time 02-09 14:20:04.643 D/CRMonitorT(16486): cdt is less than lkgt 02-09 14:20:04.650 D/CRMonitorT(16486): save LKGT, result = true 02-09 14:20:04.650 D/CRMonitorT(16486): going to SLEEP, next wakeup in [379987] milliseconds 02-09 14:20:04.650 V/MSV (16486): WebUtils url:http://www36.verizon.com/MSVAppServices/anonymous/Images/GreenHornet_HD_2011_128x192_bc.jpg 02-09 14:20:04.650 D/MSC_V3.2.7(16486): API MSC_V3.2.7 : getRemainingRightsInfo - START 02-09 14:20:04.650 V/MSV (16486): WebUtils finished http get call 02-09 14:20:04.658 D/MSC_V3.2.7(16486): device id : 4f631457dd1d2ab 02-09 14:20:04.658 D/MSC_V3.2.7(16486): Getting Rights info from LOCAL for : /mnt/sdcard/.video/The-G_sub_PKGE0450000000492574.mp4 02-09 14:20:04.658 D/MSC_V3.2.7(16486): getRemainingRights for :/mnt/sdcard/.video/The-G_sub_PKGE0450000000492574.mp4 02-09 14:20:04.658 D/MSC_V3.2.7(16486): BEFORE calling iprmHandle.getSMVODRule for content: The-G_sub_PKGE0450000000492574.mp4 02-09 14:20:04.666 D/MSC_V3.2.7(16486): AFTER getSMVODRule 02-09 14:20:04.666 D/MSC_V3.2.7(16486): rentalflag = false 02-09 14:20:04.666 D/MSC_V3.2.7(16486): start time = 0 02-09 14:20:04.666 D/MSC_V3.2.7(16486): play window = 0 02-09 14:20:04.666 D/MSC_V3.2.7(16486): expiry time = 1328894434 02-09 14:20:04.666 D/MSC_V3.2.7(16486): returning RightsInfo 02-09 14:20:04.666 D/MSC_V3.2.7(16486): API MSC_V3.2.7 : getRemainingRightsInfo - END 02-09 14:20:04.744 D/skia (16486): Loading ARM decoder... 02-09 14:20:05.549 D/LAB126 ( 1442): got menu button softkey click! 02-09 14:20:05.549 D/LAB126 ( 1442): collapse because of menu 02-09 14:20:05.549 W/KeyCharacterMap(16486): No keyboard for id 0 02-09 14:20:05.549 W/KeyCharacterMap(16486): Using default keymap: /system/usr/keychars/qwerty.kcm.bin 02-09 14:20:05.549 D/LAB126 ( 1442): collapse softkeys 02-09 14:20:05.775 I/ActivityManager( 1375): Displayed com.verizon.ams.tesla/.ui.TabDownloadsActivity: +5s268ms 02-09 14:20:05.846 D/LAB126 ( 1442): got menu button softkey click! 02-09 14:20:05.846 D/LAB126 ( 1442): collapse because of menu 02-09 14:20:05.846 D/LAB126 ( 1442): collapse softkeys 02-09 14:20:05.853 W/InputManagerService( 1375): Window already focused, ignoring focus gain of: com.android.internal.view.IInputMethodClient$Stub$Proxy@407e0b80 02-09 14:20:06.541 D/LAB126 ( 1442): got menu button softkey click! 02-09 14:20:06.541 D/LAB126 ( 1442): collapse because of menu 02-09 14:20:06.541 D/LAB126 ( 1442): collapse softkeys 02-09 14:20:07.103 D/ActivityManager( 1375): Starting: Intent { cmp=com.verizon.ams.tesla/.msv.DownloadListActivity } from pid 16486 02-09 14:20:07.111 I/MSV (16486): WebUtils futureTask is done 02-09 14:20:07.111 V/MediaLibraryActivity(16486): MediaLibraryActivity.Writing CACHE 02-09 14:20:07.111 V/MediaLibraryActivity(16486): MediaLibraryActivity.Count: 1 02-09 14:20:07.174 V/MediaLibraryActivity(16486): MediaLibraryActivity.DONE Writing 02-09 14:20:07.189 E/MSV (16486): null == m_progressBar 02-09 14:20:07.268 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:20:07.268 I/LAB126 ( 1442): window changed 02-09 14:20:07.447 I/ActivityManager( 1375): Displayed com.verizon.ams.tesla/.msv.DownloadListActivity: +335ms 02-09 14:20:09.221 V/DeviceStorageMonitorService( 1375): mTotalMemory is 11734999 02-09 14:20:14.518 D/vzAnalytics(16486): Moved 3 events from thread 1 to bg thread. bg thread pending events 3 02-09 14:20:14.518 D/vzAnalytics(16486): Saving log to db on thread 11 for 3 events 02-09 14:20:14.705 D/vzAnalytics(16486): WiFi:true, CellData:false 02-09 14:20:14.713 D/vzAnalytics(16486): Enqueuing server log task. 02-09 14:20:14.713 D/vzAnalytics(16486): Running server log task on thread 11 for 5 events. url :http://www22.verizon.com/clickStream/Tracker.svc/xml/async/postmetrics 02-09 14:20:14.846 D/vzAnalytics(16486): deleting events after server log. 02-09 14:20:15.096 I/vzAnalytics(16486): complete server log task. success :true 02-09 14:20:16.080 D/dalvikvm( 1375): GC_CONCURRENT freed 1840K, 55% free 5819K/12871K, external 4301K/5371K, paused 3ms+5ms 02-09 14:20:22.361 I/LAB126 ( 1442): tap on collapsed status bar we eat 02-09 14:20:23.143 I/LAB126 ( 1442): open notifications from tap in the status bar, child count: 5 02-09 14:20:23.564 D/LAB126 ( 1442): expand softkeys 02-09 14:20:24.869 D/ActivityManager( 1375): Starting: Intent { flg=0x4000000 cmp=com.verizon.ams.tesla/.ui.TabDownloadsActivity bnds=[0,400][600,510] (has extras) } from pid -1 02-09 14:20:24.869 W/ActivityManager( 1375): startActivity called from non-Activity context; forcing Intent.FLAG_ACTIVITY_NEW_TASK for: Intent { flg=0x4000000 cmp=com.verizon.ams.tesla/.ui.TabDownloadsActivity bnds=[0,400][600,510] (has extras) } 02-09 14:20:24.869 D/LAB126 ( 1442): collapsing softkeys because notification closing. 02-09 14:20:24.869 D/LAB126 ( 1442): collapse softkeys 02-09 14:20:24.924 W/ResourceType(16486): Skipping entry 0x7f02015d in package table 0 because it is not complex! 02-09 14:20:24.924 W/ResourceType(16486): Skipping entry 0x7f02015d in package table 0 because it is not complex! 02-09 14:20:24.924 W/ResourceType(16486): Skipping entry 0x7f02015d in package table 0 because it is not complex! 02-09 14:20:24.924 W/ResourceType(16486): Skipping entry 0x7f02015d in package table 0 because it is not complex! 02-09 14:20:24.924 W/ResourceType(16486): Skipping entry 0x7f02015d in package table 0 because it is not complex! 02-09 14:20:24.924 W/ResourceType(16486): Skipping entry 0x7f02015d in package table 0 because it is not complex! 02-09 14:20:24.932 D/vzAnalytics(16486): Scheduling db and net save task 02-09 14:20:25.244 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:20:25.244 I/LAB126 ( 1442): window changed 02-09 14:20:25.268 D/LAB126 ( 1442): collapse softkeys 02-09 14:20:25.416 I/ActivityManager( 1375): Displayed com.verizon.ams.tesla/.ui.TabDownloadsActivity: +549ms 02-09 14:20:29.322 D/dalvikvm(16486): GC_EXTERNAL_ALLOC freed 1226K, 45% free 5296K/9479K, external 7961K/8089K, paused 42ms 02-09 14:20:31.127 D/dalvikvm( 1828): GC_EXPLICIT freed 43K, 36% free 4925K/7687K, external 847K/1359K, paused 51ms 02-09 14:20:33.135 D/mediamanager(16486): Playing 08 Latika's Theme.mp3 02-09 14:20:33.135 D/ActivityManager( 1375): Starting: Intent { cmp=com.verizon.ams.tesla/com.verizon.mediamanager.AudioPlayer } from pid 16486 02-09 14:20:33.143 D/mediamanager(16486): intent received com.verizon.flexview.mediamanager.action_audio_play 02-09 14:20:33.197 D/dalvikvm(16486): GC_EXTERNAL_ALLOC freed 111K, 45% free 5298K/9479K, external 8926K/9861K, paused 39ms 02-09 14:20:33.393 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:20:33.393 I/LAB126 ( 1442): window changed 02-09 14:20:33.549 I/ActivityManager( 1375): Displayed com.verizon.ams.tesla/com.verizon.mediamanager.AudioPlayer: +402ms 02-09 14:20:33.752 W/ASFDummyExtractor( 1294): ASF parser is not available 02-09 14:20:33.752 E/MPEG4Extractor( 1294): both mdat,ftyp not found 02-09 14:20:33.830 D/Omap4ALSA( 1294): open called for devices 00000002 in mode 0 channels 00000000... 02-09 14:20:33.846 I/Omap4ALSA( 1294): Using ping-pong! 02-09 14:20:33.846 I/Omap4ALSA( 1294): Buffer size: 4096 02-09 14:20:33.846 I/Omap4ALSA( 1294): Latency: 92879 02-09 14:20:33.900 I/Omap4ALSA( 1294): Initialized ALSA PLAYBACK device 'plughw:0,0' 02-09 14:20:33.900 E/AudioHardwareALSA( 1294): RE-OPEN AFTER STANDBY:: took 69 msecs 02-09 14:20:36.299 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:20:36.299 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:20:36.299 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:20:36.299 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:20:36.299 D/IconMerger( 1442): notification for com.android.systemui (1) 02-09 14:20:36.299 D/IconMerger( 1442): sum of notifications: 5 02-09 14:20:37.424 D/mediamanager(16486): intent received com.verizon.flexview.mediamanager.action_audio_pause 02-09 14:20:37.439 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:20:37.439 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:20:37.447 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:20:37.447 D/IconMerger( 1442): notification for com.android.systemui (1) 02-09 14:20:37.447 D/IconMerger( 1442): sum of notifications: 4 02-09 14:20:38.213 D/mediamanager(16486): intent received com.verizon.flexview.mediamanager.action_audio_play 02-09 14:20:41.252 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:20:41.252 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:20:41.252 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:20:41.252 D/IconMerger( 1442): notification for com.verizon.ams.tesla (1) 02-09 14:20:41.252 D/IconMerger( 1442): notification for com.android.systemui (1) 02-09 14:20:41.252 D/IconMerger( 1442): sum of notifications: 5 02-09 14:20:44.932 D/vzAnalytics(16486): Moved 5 events from thread 1 to bg thread. bg thread pending events 5 02-09 14:20:44.932 D/vzAnalytics(16486): Saving log to db on thread 11 for 5 events 02-09 14:20:44.955 D/LAB126 ( 1442): got back button softkey click! 02-09 14:20:44.955 D/LAB126 ( 1442): collapse because of back button 02-09 14:20:44.955 D/LAB126 ( 1442): collapse softkeys 02-09 14:20:44.963 W/KeyCharacterMap(16486): No keyboard for id 0 02-09 14:20:44.963 W/KeyCharacterMap(16486): Using default keymap: /system/usr/keychars/qwerty.kcm.bin 02-09 14:20:45.080 I/LAB126 ( 1442): StatusBarService hears intent. action: com.lab126.intent.TOP_WINDOW_CHANGED 02-09 14:20:45.080 I/LAB126 ( 1442): window changed 02-09 14:20:45.471 D/vzAnalytics(16486): WiFi:true, CellData:false 02-09 14:20:45.478 D/vzAnalytics(16486): Enqueuing server log task. 02-09 14:20:45.478 D/vzAnalytics(16486): Running server log task on thread 11 for 5 events. url :http://www22.verizon.com/clickStream/Tracker.svc/xml/async/postmetrics 02-09 14:20:45.650 D/vzAnalytics(16486): deleting events after server log. 02-09 14:20:45.916 I/vzAnalytics(16486): complete server log task. success :true 02-09 14:20:51.166 W/ProcessStats( 1375): Skipping unknown process pid 16579 02-09 14:20:51.189 D/dalvikvm( 1774): GC_EXPLICIT freed 230K, 52% free 3072K/6279K, external 847K/1181K, paused 35ms