B4J Question Sending Firebase Message - Object should first be initialized / timeout

[aaronk]

Hi,

I am running the following code to send a firebase push notification:

Private Sub SendMessage(Topic As String, Title As String, Body As String, sound As String) As ResumableSub

    Dim Token As String = GetTokenValue(ServiceAccountFilePath)
  
    Dim Job As HttpJob
    Job.Initialize("", Me)
    Dim data As Map = CreateMap("title": Title, "body": Body)
    Dim message As Map = CreateMap("topic": Topic, "data": data)
    If Topic.StartsWith("ios_") Then
        'B4i
        Dim Badge As Int = 0
        Dim iosalert As Map =  CreateMap("title": Title, "body": Body)
        message.Put("notification", iosalert)
        message.Put("apns", CreateMap("headers": _
            CreateMap("apns-priority": "10"), _
            "payload": CreateMap("aps": CreateMap("sound": sound, "badge": Badge))))
    Else
        'B4A
        message.Put("android", CreateMap("priority": "high"))
    End If
    Dim jg As JSONGenerator
    jg.Initialize(CreateMap("message": message))
  
    'Log(jg.ToPrettyString(4))
    Job.PostString($"https://fcm.googleapis.com/v1/projects/${ProjectID}/messages:send"$, jg.ToString)
    Job.GetRequest.SetContentType("application/json;charset=UTF-8")
    Job.GetRequest.SetHeader("Authorization", "Bearer " & Token)
  
    Wait For (Job) JobDone(Job As HttpJob)
    If Job.Success Then
        'Log(Job.GetString)
        Else
            Log(LastException.Message)
            SendMessage(Topic, Title, Body, sound)
    End If
    Job.Release
    Return True

End Sub

When I run this code, it sometimes sends the push notification and sometimes it shows:

java.net.SocketTimeoutException: timeout
    at okhttp3.internal.http2.Http2Stream$StreamTimeout.newTimeoutException(Http2Stream.kt:677)
    at okhttp3.internal.http2.Http2Stream$StreamTimeout.exitAndThrowIfTimedOut(Http2Stream.kt:686)
    at okhttp3.internal.http2.Http2Stream.takeHeaders(Http2Stream.kt:143)
    at okhttp3.internal.http2.Http2ExchangeCodec.readResponseHeaders(Http2ExchangeCodec.kt:96)
    at okhttp3.internal.connection.Exchange.readResponseHeaders(Exchange.kt:106)
    at okhttp3.internal.http.CallServerInterceptor.intercept(CallServerInterceptor.kt:79)
    at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
    at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.kt:34)
    at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
    at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.kt:95)
    at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
    at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.kt:83)
    at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
    at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.kt:76)
    at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
    at okhttp3.internal.connection.RealCall.getResponseWithInterceptorChain$okhttp(RealCall.kt:201)
    at okhttp3.internal.connection.RealCall.execute(RealCall.kt:154)
    at anywheresoftware.b4h.okhttp.OkHttpClientWrapper.executeWithTimeout(OkHttpClientWrapper.java:175)
    at anywheresoftware.b4h.okhttp.OkHttpClientWrapper.access$0(OkHttpClientWrapper.java:172)
    at anywheresoftware.b4h.okhttp.OkHttpClientWrapper$ExecuteHelper.run(OkHttpClientWrapper.java:220)
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630)
    at java.base/java.lang.Thread.run(Thread.java:832)
ResponseError. Reason: java.net.SocketTimeoutException: timeout, Response:
java.lang.RuntimeException: Object should first be initialized (Exception).
java.net.SocketTimeoutException: timeout
    at okhttp3.internal.http2.Http2Stream$StreamTimeout.newTimeoutException(Http2Stream.kt:677)
    at okhttp3.internal.http2.Http2Stream$StreamTimeout.exitAndThrowIfTimedOut(Http2Stream.kt:686)
    at okhttp3.internal.http2.Http2Stream.takeHeaders(Http2Stream.kt:143)
    at okhttp3.internal.http2.Http2ExchangeCodec.readResponseHeaders(Http2ExchangeCodec.kt:96)
    at okhttp3.internal.connection.Exchange.readResponseHeaders(Exchange.kt:106)
    at okhttp3.internal.http.CallServerInterceptor.intercept(CallServerInterceptor.kt:79)
    at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
    at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.kt:34)
    at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
    at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.kt:95)
    at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
    at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.kt:83)
    at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
    at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.kt:76)
    at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
    at okhttp3.internal.connection.RealCall.getResponseWithInterceptorChain$okhttp(RealCall.kt:201)
    at okhttp3.internal.connection.RealCall.execute(RealCall.kt:154)
    at anywheresoftware.b4h.okhttp.OkHttpClientWrapper.executeWithTimeout(OkHttpClientWrapper.java:175)
    at anywheresoftware.b4h.okhttp.OkHttpClientWrapper.access$0(OkHttpClientWrapper.java:172)
    at anywheresoftware.b4h.okhttp.OkHttpClientWrapper$ExecuteHelper.run(OkHttpClientWrapper.java:220)
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630)
    at java.base/java.lang.Thread.run(Thread.java:832)
ResponseError. Reason: java.net.SocketTimeoutException: timeout, Response:
java.lang.RuntimeException: Object should first be initialized (Exception).

The error 'Object should first be initialized (Exception)' is logged from line 33 of the code above.

Running B4J version 10.00
jOKHTTPUtils2 lib 3.03

Anyone know why it keeps showing timeout or why it shows Object should first be initialized ?

It was working and now all of a sudden it's coming up with this issue.

 

[giannimaione]

interesting code; I have to have an experience

 

[aaronk]

I also found when running the code as per post 1, it will take 59926ms to 81882ms to run the function. The more messages I pass to function it will take longer and longer. It eventually takes 20-30 minutes before the message is received.

The code used to run ok, but all of a sudden it's running slow.

If I run this function like below (without the wait for) it will run that function within 130-200ms

Private Sub SendMessage(Topic As String, Title As String, Body As String, sound As String)
Dim n As Long = DateTime.now
    Dim Token As String = GetTokenValue(ServiceAccountFilePath)
 
    Dim Job As HttpJob
    Job.Initialize("", Me)
    Dim data As Map = CreateMap("title": Title, "body": Body)
    Dim message As Map = CreateMap("topic": Topic, "data": data)
    If Topic.StartsWith("ios_") Then
        'B4i
        Dim Badge As Int = 0
        Dim iosalert As Map =  CreateMap("title": Title, "body": Body)
        message.Put("notification", iosalert)
        message.Put("apns", CreateMap("headers": _
            CreateMap("apns-priority": "10"), _
            "payload": CreateMap("aps": CreateMap("sound": sound, "badge": Badge))))
    Else
        'B4A
        message.Put("android", CreateMap("priority": "high"))
    End If
    Dim jg As JSONGenerator
    jg.Initialize(CreateMap("message": message))
 
    'Log(jg.ToPrettyString(4))
    Job.PostString($"https://fcm.googleapis.com/v1/projects/${ProjectID}/messages:send"$, jg.ToString)
    Job.GetRequest.SetContentType("application/json;charset=UTF-8")
    Job.GetRequest.SetHeader("Authorization", "Bearer " & Token)
 Log("Total Firebase Command Took: " & (DateTime.Now - n))
    Job.Release
    Return True

End Sub

However, even knowing it takes 130-200ms to run the above code, the push notification doesn't display on my phone for a few minutes. In some cases it can take 20 minutes. Most likely not the correct way in logging how long it took since it might have not been sent at that time and it just logged the value.

The Body of my push notification contains the timestamp it sent the message. This way I know when it hits my phone I know what time the server sent the push notification from my code. The timestamp matches the server time, but took time to arrive.

The way it triggers my SendMessage function is, I am sending a MQTT message to my B4J app. (the same MQTT message is sent to my B4A/B4i apps so I can see the MQTT message).

When the B4J app gets this MQTT message it checks a map to see if it contains the message already and if it does then it ignores the message and doesn't send the push notification. If it doesn't contain the message it will run the SendMessage function. (There is another MQTT message that will remove the message from the map.)

I have checked to see how long it took to check the map, and it takes 0-1ms. For troubleshooting I removed this part of the code, so I can rule this out in case it was somehow slowing down my code.

For troubleshooting, if I add 'Return True' to the start of the SendMessage function to stop the push notification from being sent then log all incoming MQTT messages it logs the message in realtime. Pretty much instant.

I also added an integer to the SendMessage function for troubleshooting and then got a Timer to log the value every 1 second. While it's not running the firebase code in the SendMessage function it was logging values between 10-20 every second. Therefore my code is running approx 10-20 messages per second.

If I then allow messages to be processed in the SendMessage function again, (as well as log the incoming MQTT message) the MQTT message arrives on my phone from the MQTT broker instantly (not the push notification but the MQTT message), and then I wait for the MQTT message to arrive in the B4J app and it took around 20-30 seconds before it logged the message in the IDE.

Seems that the SendMessage function is slowing down my B4J app completely. Before it was logging the MQTT instantly but while running the SendMessage firebase code it's not logging it instantly.

The integer value it logged every 1 second was now logging the values between 70-100. This is most likely queuing the messages since it's taking time to process the firebase code?

The above was done in debug mode. I then switch to release mode and got similar results where everything was delayed when it was running the firebase code.

I can't seem to work out why the code in the SendMessage function is running slow and not processing quickly and causing everything to run show.

I have tried it on different computers, and internet connections in case it was my internet connection, and all got the same result.

 

[DonManfred]

is that the sendingtool code from the 2023 tutorial?

 

[aaronk]

is that the sendingtool code from the 2023 tutorial?

Yes.

 

[Erel]

1. It should be Log(Job.ErrorMessage).
2. You can increase Job.GetRequest.Timeout.
3. And it is better to add Sleep(5000) before making another attempt.

 

[aaronk]

1. It should be Log(Job.ErrorMessage).
2. You can increase Job.GetRequest.Timeout.
3. And it is better to add Sleep(5000) before making another attempt.

I will change it to Log(Job.ErrorMessage).

I did try today setting the timeout. There wasn't much difference in performance.

I removed the Wait For (Job)... part as having the wait for part slowed down everything. Now I am not capturing if it failed and it seems to make it a little faster.

At this very moment, things are running fast and the push notifications are showing up on the phone within 1-2 seconds. Not sure what has changed at Google's end or somewhere in-between. All I have done is remove the wait for part in the code, nothing else.

Not sure how long before it starts to run slow again.

 

[Erel]

removed the Wait For (Job)... part as having the wait for part slowed down everything.

Sounds like a big mistake.

 

[Erel]

You can call SendMessage multiple times and the requests will be sent in parallel.

 

[aaronk]

Sounds like a big mistake.

I agree.

You can call SendMessage multiple times and the requests will be sent in parallel.

That is what I thought, but couldn't work out why it was running slow.

I only remove part of the code to detect what is slowing things down, so I knew what it was so I could fix it and that is what I detected.

I now have the code as per below.

So far it has been working for the past 20 minutes and it's running fine.

I will continue monitoring it and see how it goes.

Private Sub SendMessage(Topic As String, Title As String, Body As String, sound As String) As ResumableSub

    Dim Token As String = GetTokenValue(ServiceAccountFilePath)
    
    Dim Job As HttpJob
    Job.Initialize("", Me)
    Dim data As Map = CreateMap("title": Title, "body": Body)
    Dim message As Map = CreateMap("topic": Topic, "data": data)
    If Topic.StartsWith("ios_") Then
        'B4i
        Dim Badge As Int = 0
        Dim iosalert As Map =  CreateMap("title": Title, "body": Body)
        message.Put("notification", iosalert)
        message.Put("apns", CreateMap("headers": _
            CreateMap("apns-priority": "10"), _
            "payload": CreateMap("aps": CreateMap("sound": sound, "badge": Badge))))
    Else
        'B4A
        message.Put("android", CreateMap("priority": "high"))
    End If
    Dim jg As JSONGenerator
    jg.Initialize(CreateMap("message": message))
    
    'Log(jg.ToPrettyString(4))
    Job.PostString($"https://fcm.googleapis.com/v1/projects/${ProjectID}/messages:send"$, jg.ToString)
    Job.GetRequest.SetContentType("application/json;charset=UTF-8")
    Job.GetRequest.SetHeader("Authorization", "Bearer " & Token)
    Job.GetRequest.Timeout = 5000
    
        Wait For (Job) JobDone(Job As HttpJob)
        If Job.Success Then
            'Log(Job.GetString)
        Else
            Log(Job.ErrorMessage)
            Log("Failed to process Firebase. Topic = " & Topic)
            Sleep(5000)
            SendMessage(Topic, Title, Body, sound)
        End If
        Job.Release
    
    Return True
End Sub

 

[aaronk]

I am noticing it's timing out again.

I have the timeout set to 5000 and most are failing to send. I then have a sleep(5000) which should then try and resend again 5 seconds later, but get the same result where it will timeout.

I increased the timeout to 10000 but get the same result.

Eventually it will send. but will take around 2-3 minutes.
Leaving it run, it is now taking around 20-30 minutes to send.
The timestamp in the push notification is correct (as I put the timestamp in the body), but it's just taking time to process this on my server.

I then stopped my B4J app and then started again, and it takes around 2-3 minutes to send as it keeps timing out.

From my last post (little over a week ago) it was running OK, but now it's timing out on most messages.

Running the same code on my PC I get the same result.