Push Message Job Appear to be Stuck

Bill Norris · Oct 2, 2012

Sent push message to my devices to download a new file. All but one was successful. The "unsuccessful" one showed a message to the effect of "Your App is Not Responding. Do You Want To Wait", with a Yes button and a No button. I selected YES. I did not receive my customary "Download Complete" toastmsg, so I sent the push again. The log says NEW MESSAGE ARRIVED", followed by "Already working. Request ignored". I take that to mean it is still processing the original message, but it has been a very long time, so I am guessing the job is stuck at some point that I cannot determine through the logs. I This happened once before and I had to Force Stop the app and restart to get the download to work. Any ideas why the Job would get stuck? I can post the log contents from the point of the original msg received if anyone can make sense of it.

Erel · Oct 3, 2012

The push example is based on HttpUtils. Unlike HttpUtils2, HttpUtils only allow you to run a single job. Other submitted jobs will be ignored. It shouldn't be difficult to convert it to HttpUtils2.

You should check the logs and find out why your app is not responding during the first message.

Bill Norris · Oct 4, 2012

RE:

Erel -- this is the log from just before the initial message was received, all the way until the second message was received. I can't really make any sense out of this that could lead me to why the initail job did not complete. Perhaps you can interpret?

B4X:

@PowerManagement: Auto-dim timeout
level:93 scale:100 status:4 health:2 present:true dock_status:1 dock_level:0 dock_ac_online:false voltage: 8 temperature: 265 technology: Li-ion AC powered:false USB powered:false icon:17302840 invalid charger:0
battery level:93 plugged:0
Removed alarm Alarm{418a1068 type 2 com.google.android.gsf} type:ELAPSED_REALTIME_WAKEUP
Added alarm Alarm{41a28e58 type 2 com.google.android.gsf} type:ELAPSED_REALTIME_WAKEUP when: After 0h:15m:0.0s
[DataMsgMgr] broadcast intent callback: result=CANCELLED forIntent { act=com.google.android.c2dm.intent.RECEIVE cat=[wine_tablet.pss] (has extras) }
** Service (pushservice) Start **
New message arrived: GET_APK
Starting Job: Job3[/COLOR]
** Service (httputilsservice) Create **
@PowerManagement: 'KEEP_SCREEN_ON_FLAG' releaseWakeLock when screen locked
Timeout executing service: ServiceRecord{41a68ca8 wine_tablet.pss/.httputilsservice}
Sending signal. PID: 12353 SIG: 3
threadid=3: reacting to signal 3
Wrote stack traces to '/data/anr/traces.txt'
Sending signal. PID: 164 SIG: 3
threadid=3: reacting to signal 3
Wrote stack traces to '/data/anr/traces.txt'
Sending signal. PID: 269 SIG: 3
threadid=3: reacting to signal 3
Wrote stack traces to '/data/anr/traces.txt'
Sending signal. PID: 369 SIG: 3
threadid=3: reacting to signal 3
Wrote stack traces to '/data/anr/traces.txt'
Sending signal. PID: 400 SIG: 3
threadid=3: reacting to signal 3
Wrote stack traces to '/data/anr/traces.txt'
GC_CONCURRENT freed 2097K, 29% free 13852K/19335K, paused 3ms+7ms
GC_EXPLICIT freed 642K, 28% free 13959K/19335K, paused 3ms+5ms
ANR in wine_tablet.pss
Reason: Executing service wine_tablet.pss/.httputilsservice
Load: 0.0 / 0.07 / 0.24
CPU usage from 5439ms to 0ms ago:
  92% 12353/wine_tablet.pss: 90% user + 1.6% kernel / faults: 7 minor
  2.2% 84/surfaceflinger: 1.1% user + 1.1% kernel
  1.8% 164/system_server: 0.3% user + 1.4% kernel / faults: 6 minor
  0.1% 269/com.android.systemui: 0.1% user + 0% kernel
  0.1% 5112/ksdioirqd/mmc2: 0% user + 0.1% kernel
  0.1% 11731/kworker/u:3: 0% user + 0.1% kernel
  0.1% 12250/kworker/1:1: 0% user + 0.1% kernel
  0% 12926/kworker/0:0: 0% user + 0% kernel
48% TOTAL: 46% user + 2.4% kernel
CPU usage from 401ms to 916ms later:
  90% 12353/wine_tablet.pss: 90% user + 0% kernel
    92% 12353/wine_tablet.pss: 92% user + 0% kernel
  1.9% 84/surfaceflinger: 1.9% user + 0% kernel
    1.9% 143/SurfaceFlinger: 1.9% user + 0% kernel
  1.5% 11731/kworker/u:3: 0% user + 1.5% kernel
49% TOTAL: 46% user + 2.9% kernel
battery level:93 plugged:0
Jit: resizing JitTable from 8192 to 16384
setLightsOn(true)
Window already focused, ignoring focus gain of: com.android.internal.view.IInputMethodClient$Stub$Proxy@41733be8
battery level:93 plugged:0
battery level:93 plugged:0
unable to find stats for iface rmnet0
GC_CONCURRENT freed 1925K, 23% free 16703K/21511K, paused 1ms+14ms
battery level:93 plugged:0
level:92 scale:100 status:4 health:2 present:true dock_status:1 dock_level:0 dock_ac_online:false voltage: 8 temperature: 270 technology: Li-ion AC powered:false USB powered:false icon:17302840 invalid charger:0
battery level:92 plugged:0
void cb_onMotion(uint16_t)
START {flg=0x20000 cmp=wine_tablet.pss/.navigator} from pid 12353
** Activity (main) Pause, UserClosed = true **
adjustConfigurationLw, config:{1.0 0mcc0mnc (no locale) layoutdir=0 sw800dp w1280dp h752dp xlrg land ?uimode ?night finger -keyb/v/h -nav/v} mLidOpen:-1 mHasDockFeature:true mHasHallSensorFeature:true config.hardKeyboardHidden:2
** Activity (navigator) Resume **
setLightsOn(true)
GC_FOR_ALLOC freed 5970K, 42% free 12479K/21511K, paused 22ms
GC_FOR_ALLOC freed 129K, 36% free 13898K/21511K, paused 18ms
GC_FOR_ALLOC freed 24K, 31% free 14898K/21511K, paused 17ms
TextType = 0x0
START {flg=0x20000 cmp=wine_tablet.pss/.about} from pid 12353
** Activity (navigator) Pause, UserClosed = false **
adjustConfigurationLw, config:{1.0 0mcc0mnc (no locale) layoutdir=0 sw800dp w1280dp h752dp xlrg land ?uimode ?night finger -keyb/v/h -nav/v} mLidOpen:-1 mHasDockFeature:true mHasHallSensorFeature:true config.hardKeyboardHidden:2
setLightsOn(true)
** Activity (about) Create, isFirst = false **
GC_CONCURRENT freed 117K, 23% free 16759K/21511K, paused 1ms+4ms
** Activity (about) Resume **
TextType = 0x0
Displayed wine_tablet.pss/.about: +376ms
void cb_onMotion(uint16_t)
START {flg=0x20000 cmp=wine_tablet.pss/.navigator} from pid 12353
** Activity (about) Pause, UserClosed = true **
adjustConfigurationLw, config:{1.0 0mcc0mnc (no locale) layoutdir=0 sw800dp w1280dp h752dp xlrg land ?uimode ?night finger -keyb/v/h -nav/v} mLidOpen:-1 mHasDockFeature:true mHasHallSensorFeature:true config.hardKeyboardHidden:2
** Activity (navigator) Resume **
setLightsOn(true)
GC_FOR_ALLOC freed 6009K, 42% free 12574K/21511K, paused 22ms
GC_FOR_ALLOC freed 205K, 36% free 13916K/21511K, paused 19ms
GC_FOR_ALLOC freed 24K, 31% free 14917K/21511K, paused 17ms
TextType = 0x0
GC_CONCURRENT freed 423K, 43% free 7050K/12359K, paused 2ms+3ms
START {flg=0x20000 cmp=wine_tablet.pss/.main} from pid 12353
** Activity (navigator) Pause, UserClosed = false **
adjustConfigurationLw, config:{1.0 0mcc0mnc (no locale) layoutdir=0 sw800dp w1280dp h752dp xlrg land ?uimode ?night finger -keyb/v/h -nav/v} mLidOpen:-1 mHasDockFeature:true mHasHallSensorFeature:true config.hardKeyboardHidden:2
setLightsOn(true)
** Activity (main) Create, isFirst = false **
GC_CONCURRENT freed 132K, 22% free 16789K/21511K, paused 4ms+4ms
** Activity (main) Resume **
TextType = 0x0
Displayed wine_tablet.pss/.main: +223ms
** Service (pushservice) Start **
Launch timeout has expired, giving up wake lock!
Activity idle timeout for ActivityRecord{41722940 wine_tablet.pss/.main}
Removed alarm Alarm{41a28e58 type 2 com.google.android.gsf} type:ELAPSED_REALTIME_WAKEUP
Added alarm Alarm{4161ec88 type 2 com.google.android.gsf} type:ELAPSED_REALTIME_WAKEUP when: After 0h:14m:59.0s
[DataMsgMgr] broadcast intent callback: result=CANCELLED forIntent { act=com.google.android.c2dm.intent.RECEIVE cat=[wine_tablet.pss] (has extras) }
** Service (pushservice) Start **
New message arrived: GET_APK
Already working. Request ignored (Job3)[/COLOR]

Erel · Oct 5, 2012

Do you have some loop waiting for HttpUtils to finish?

Bill Norris · Oct 5, 2012

RE:

No -- not that I am aware. I only reference httputils for these downloads.

Erel · Oct 5, 2012

Can you post the code that handles the message?

Bill Norris · Oct 5, 2012

RE:

Here is the code -- works fine about 90% of the time

B4X:

Sub MessageArrived (Intent As Intent)
   Dim From, CollapseKey   ', data As String
   If Intent.HasExtra("from") Then From = Intent.GetExtra("from")
   If Intent.HasExtra("data") Then data = Intent.GetExtra("data")
   If Intent.HasExtra("collapse_key") Then CollapseKey = Intent.GetExtra("collapse_key")

   'Here you should handle the new message:
   Log("New message arrived: " & data)
   ToastMessageShow("New message: " & data, True)
   
   'Data messages indicate what needs to be downloaded. 
      'GET_DB will download a new database
      
      'GET_APK will download new APK file
   CallSub("","get_new_data")
   
End Sub

Sub get_new_data
      
   Select data
      Case "GET_APK"
         Dim FileUrl As String
         FileUrl="http://www.parksquarecellar.com/tablet/apk/WINETAB.apk"
         HttpUtils.CallbackActivity = "PushService" 'Current activity name.
          HttpUtils.CallbackJobDoneSub = "JobDone"
          HttpUtils.Download("Job3", FileUrl)   'Job1 is used for APK download

      Case "GET_DB"
         Dim FileUrl As String
         FileUrl="http://www.parksquarecellar.com/tablet/database/wine_tablet.db"
         HttpUtils.CallbackActivity = "PushService" 'Current activity name.
          HttpUtils.CallbackJobDoneSub = "JobDone"
          HttpUtils.Download("Job1", FileUrl)   'Job1 is used for database download
   End Select
   
End Sub

Sub JobDone (Job As String)

   Select Job
      Case "Job1"  'database file only
         Dim FileUrl As String
         FileUrl=HttpUtils.tasks.Get(0)
         If HttpUtils.IsSuccess(FileUrl) Then 
            Dim database As InputStream
            database=HttpUtils.GetInputStream(FileUrl)
            Dim out As OutputStream
            Main.sql_main.Close
            out = File.OpenOutput(File.DirDefaultExternal,"WINE_TABLET.DB",False)
            File.Copy2(HttpUtils.GetInputStream(FileUrl), out)
            out.Close
            ToastMessageShow("Database Download Complete", True)
            'create a text file to show date of most recent db download
            Dim t As Long
            t = DateTime.Now
            writer.Initialize(File.OpenOutput(File.DirDefaultExternal, "db.txt" , False))
            writer.Writeline(DateTime.GetMonth(t) & "/" & DateTime.GetDayOfMonth(t) & "/" & DateTime.GetYear(t) & " - " & DateTime.Time(DateTime.Now))
            writer.Close
         End If
      
      Case "Job3"   'new APK file
         Dim FileUrl As String
         FileUrl=HttpUtils.tasks.Get(0)
         If HttpUtils.IsSuccess(FileUrl) Then 
            Dim apk_file As InputStream
            apk_file=HttpUtils.GetInputStream(FileUrl)
            Dim out As OutputStream
            out = File.OpenOutput(File.DirRootExternal,"winetab.apk",False)
            File.Copy2(HttpUtils.GetInputStream(FileUrl), out)
              out.Close

                                'create a text file to show date of most recent apk download
            Dim t As Long
            t = DateTime.Now
            writer.Initialize(File.OpenOutput(File.DirDefaultExternal, "apk.txt" , False))
            writer.Writeline(DateTime.GetMonth(t) & "/" & DateTime.GetDayOfMonth(t) & "/" & DateTime.GetYear(t) & " - " & DateTime.Time(DateTime.Now))
            writer.Close   
            Dim Intent1 As Intent
            Intent1.Initialize(Intent1.ACTION_VIEW, "file:///sdcard/winetab.apk")
            Intent1.SetType("application/vnd.android.package-archive")
            StartActivity(Intent1)

         End If
   End Select
End Sub

Erel · Oct 7, 2012

Try to use CallSubDelayed instead of CallSub("", "get_new_data"). This will allow the broadcast receiver to finish quickly and avoid hitting any timeout.

I recommend you to use HttpUtils2 instead of HttpUtils. HttpUtils2 can handle multiple running jobs.

Push Message Job Appear to be Stuck

Bill Norris

Active Member

Erel

B4X founder

Bill Norris

Active Member

Erel

B4X founder

Bill Norris

Active Member

Erel

B4X founder

Bill Norris

Active Member

Erel

B4X founder