Android Question [SOLVED] Unexpected Bluetooth issue after upgrading to v9.80

Jeffrey Cameron

Well-Known Member
Licensed User
I upgraded from v9.5 to v9.8 this morning without apparent issue. A project I was working on yesterday that was working fine under the previous version is now behaving oddly. The only change (other than clean project and re-compile) was changing the target SDK from 26 to 28. It is a complex project with many moving parts: MQTT client, Bluetooth printer, BT serial barcode scanner (SPP not HID), a remote display device (done via IP/Socket to another B4A app running on the remote display device). The remote display connects and displays properly. And while the barcode scanner is attempted to re-connect every couple of seconds (it is not usually on) the printer is only connected to in a print attempt which I haven't even tried yet.

Running the app in debug mode on v9.5 was decidedly slower than in release mode, but in v9.8 it is now so slow as to be unusable. At some point during the startup the app will just freeze and then eventually exit without any messages (no log messages, filtered or unfiltered). I then figured I'd try in release mode with bridgelogging enabled, and while it does run without self-terminating, I'm seeing a Bluetooth error message spammed into the unfiltered logs (I apologize for the length but I don't know what may be relevant):
Unflitered log:
Starting remote logger. Port: 12095
After accept
common created.
Starting remote logger. Port: 12095
Add to mViews: DecorView@1669fd4[main], this = android.view.WindowManagerGlobal@f5cd57d
HWUI GL Pipeline
hardware acceleration = true , fakeHwAccelerated = false, sRendererDisabled = false, forceHwAccelerated = false, sSystemRendererDisabled = false
DecorView setVisiblity: visibility = 0, Parent = ViewRoot{f412c72 phx.erpregister/phx.erpregister.main,ident = 0}, this = DecorView@1669fd4[main]
*** Service (starter) Create ***
** Service (starter) Start **
** Activity (main) Create, isFirst = true **
** Activity (main) Resume **
android::hardware::configstore::V1_0::ISurfaceFlingerConfigs::hasWideColorDisplay retrieved: 0
Initialized EGL, version 1.4
Swap behavior 2
type=1400 audit(0.0:65): avc: denied { search } for name="clients" dev="debugfs" ino=5988 scontext=u:r:untrusted_app:s0:c512,c768 tcontext=u:object_r:debugfs_ion:s0 tclass=dir permissive=0
** Activity (main) Pause, UserClosed = true **
DecorView setVisiblity: visibility = 4, Parent = null, this = DecorView@fb317ed[]
Add to mViews: DecorView@fb317ed[actinitialize], this = android.view.WindowManagerGlobal@f5cd57d
hardware acceleration = true , fakeHwAccelerated = false, sRendererDisabled = false, forceHwAccelerated = false, sSystemRendererDisabled = false
DecorView setVisiblity: visibility = 0, Parent = ViewRoot{4ef1e70 phx.erpregister/phx.erpregister.actinitialize,ident = 1}, this = DecorView@fb317ed[actinitialize]
** Activity (actinitialize) Create, isFirst = true **
** Activity (actinitialize) Resume **
After accept
*** Service (httputils2service) Create ***
No Network Security Config specified, using platform default
** Service (httputils2service) Start **
port:443
[Warning] assignParent to null: this = DecorView@1669fd4[main]
Remove from mViews: DecorView@1669fd4[main], this = android.view.WindowManagerGlobal@f5cd57d
Invoking build picture cache for acct #1136
*** Service (srvimageloader) Create ***
** Service (srvimageloader) Start **
Begin Build_PictureCache
End Build_PictureCache - 100 items found on local device.
srvImageLoder cache has been built.
Do partial code cache collection, code=30KB, data=30KB
After code cache collection, code=30KB, data=30KB
Increasing code cache capacity to 128KB
ProductImageDataset received - 100 images on website.
ProductImageDataset waiting for imageloader cache
Comparing list of 100 images.
Load list built, beginning process.
No download queue loaded.
Do partial code cache collection, code=53KB, data=43KB
After code cache collection, code=53KB, data=43KB
Increasing code cache capacity to 256KB
** Activity (actinitialize) Pause, UserClosed = true **
Sleep not resumed (context is paused): phx.busyindicatortest.busyindicator$ResumableSub_MainLoop
DecorView setVisiblity: visibility = 4, Parent = null, this = DecorView@e52c645[]
Add to mViews: DecorView@e52c645[actregister], this = android.view.WindowManagerGlobal@f5cd57d
hardware acceleration = true , fakeHwAccelerated = false, sRendererDisabled = false, forceHwAccelerated = false, sSystemRendererDisabled = false
DecorView setVisiblity: visibility = 0, Parent = ViewRoot{d602a8 phx.erpregister/phx.erpregister.actregister,ident = 2}, this = DecorView@e52c645[actregister]
** Activity (actregister) Create, isFirst = true **
Deoptimizing android.view.ViewGroup$LayoutParams anywheresoftware.b4a.objects.ViewWrapper.getLayoutParams() due to JIT inline cache
** Activity (actregister) Resume **
getBluetoothService() called with no BluetoothManagerCallback
Deoptimizing boolean anywheresoftware.b4a.objects.ViewWrapper.getVisible() due to JIT inline cache
port:51043
Do full code cache collection, code=119KB, data=92KB
After code cache collection, code=103KB, data=67KB
[Warning] assignParent to null: this = DecorView@fb317ed[actinitialize]
Remove from mViews: DecorView@fb317ed[actinitialize], this = android.view.WindowManagerGlobal@f5cd57d
port:1883
ErpMqtt Connected
ErpMqtt Subscribed to /1136/1/FromWeb
ErpMqtt Subscribed to /1136/1/FromDevice
java.io.IOException: read failed, socket might closed or timeout, read ret: -1
at android.bluetooth.BluetoothSocket.readAll(BluetoothSocket.java:685)
at android.bluetooth.BluetoothSocket.readInt(BluetoothSocket.java:697)
at android.bluetooth.BluetoothSocket.connect(BluetoothSocket.java:374)
at anywheresoftware.b4a.objects.Serial$1.run(Serial.java:159)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:457)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636)
at java.lang.Thread.run(Thread.java:764)
close() this: android.bluetooth.BluetoothSocket@6eab897, channel: -1, mSocketIS: android.net.LocalSocketImpl$SocketInputStream@1f8ca84, mSocketOS: android.net.LocalSocketImpl$SocketOutputStream@abaa26dmSocket: android.net.LocalSocket@c428ea2 impl:android.net.LocalSocketImpl@3184733 fd:java.io.FileDescriptor@b7a0af0, mSocketState: INIT
getBluetoothService() called with no BluetoothManagerCallback
Add to mViews: android.widget.LinearLayout{75e139b V.E...... ......I. 0,0-0,0}, this = android.view.WindowManagerGlobal@f5cd57d
hardware acceleration = true , fakeHwAccelerated = false, sRendererDisabled = false, forceHwAccelerated = false, sSystemRendererDisabled = false
[Warning] assignParent to null: this = android.widget.LinearLayout{75e139b V.E...... ......ID 0,0-312,89}
Remove from mViews: android.widget.LinearLayout{75e139b V.E...... ......ID 0,0-312,89}, this = android.view.WindowManagerGlobal@f5cd57d
java.io.IOException: read failed, socket might closed or timeout, read ret: -1
at android.bluetooth.BluetoothSocket.readAll(BluetoothSocket.java:685)
at android.bluetooth.BluetoothSocket.readInt(BluetoothSocket.java:697)
at android.bluetooth.BluetoothSocket.connect(BluetoothSocket.java:374)
at anywheresoftware.b4a.objects.Serial$1.run(Serial.java:159)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:457)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636)
at java.lang.Thread.run(Thread.java:764)
close() this: android.bluetooth.BluetoothSocket@f7ddb4d, channel: -1, mSocketIS: android.net.LocalSocketImpl$SocketInputStream@bf60602, mSocketOS: android.net.LocalSocketImpl$SocketOutputStream@5215b13mSocket: android.net.LocalSocket@ca5c150 impl:android.net.LocalSocketImpl@759df49 fd:java.io.FileDescriptor@ec2804e, mSocketState: INIT
getBluetoothService() called with no BluetoothManagerCallback
CustDisplay.moClient_Connected - connection failed: (SocketTimeoutException) java.net.SocketTimeoutException: failed to connect to /10.0.0.38 (port 51043) from /10.0.0.108 (port 56354) after 15000ms
java.net.SocketException: Socket is not connected
at java.net.Socket.shutdownInput(Socket.java:1586)
at anywheresoftware.b4a.objects.SocketWrapper$3.run(SocketWrapper.java:250)
at anywheresoftware.b4a.objects.SocketWrapper.Close(SocketWrapper.java:266)
at phx.erpregister.custdisplay._closeclient(custdisplay.java:219)
at phx.erpregister.custdisplay._moclient_connected(custdisplay.java:396)
at java.lang.reflect.Method.invoke(Native Method)
at anywheresoftware.b4a.BA.raiseEvent2(BA.java:196)
at anywheresoftware.b4a.BA$2.run(BA.java:370)
at android.os.Handler.handleCallback(Handler.java:790)
at android.os.Handler.dispatchMessage(Handler.java:99)
at android.os.Looper.loop(Looper.java:164)
at android.app.ActivityThread.main(ActivityThread.java:6523)
at java.lang.reflect.Method.invoke(Native Method)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:438)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:857)
Add to mViews: android.widget.LinearLayout{127198b V.E...... ......I. 0,0-0,0}, this = android.view.WindowManagerGlobal@f5cd57d
hardware acceleration = true , fakeHwAccelerated = false, sRendererDisabled = false, forceHwAccelerated = false, sSystemRendererDisabled = false
port:51043
[Warning] assignParent to null: this = android.widget.LinearLayout{127198b V.E...... ......ID 0,0-530,75}
Remove from mViews: android.widget.LinearLayout{127198b V.E...... ......ID 0,0-530,75}, this = android.view.WindowManagerGlobal@f5cd57d
java.io.IOException: read failed, socket might closed or timeout, read ret: -1
at android.bluetooth.BluetoothSocket.readAll(BluetoothSocket.java:685)
at android.bluetooth.BluetoothSocket.readInt(BluetoothSocket.java:697)
at android.bluetooth.BluetoothSocket.connect(BluetoothSocket.java:374)
at anywheresoftware.b4a.objects.Serial$1.run(Serial.java:159)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:457)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636)
at java.lang.Thread.run(Thread.java:764)
close() this: android.bluetooth.BluetoothSocket@c7b4ca0, channel: -1, mSocketIS: android.net.LocalSocketImpl$SocketInputStream@5989059, mSocketOS: android.net.LocalSocketImpl$SocketOutputStream@bc6c41emSocket: android.net.LocalSocket@96d4ff impl:android.net.LocalSocketImpl@15892cc fd:java.io.FileDescriptor@538d915, mSocketState: INIT
getBluetoothService() called with no BluetoothManagerCallback
java.io.IOException: read failed, socket might closed or timeout, read ret: -1
    at android.bluetooth.BluetoothSocket.readAll(BluetoothSocket.java:685)
    at android.bluetooth.BluetoothSocket.readInt(BluetoothSocket.java:697)
    at android.bluetooth.BluetoothSocket.connect(BluetoothSocket.java:374)
    at anywheresoftware.b4a.objects.Serial$1.run(Serial.java:159)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:457)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636)
    at java.lang.Thread.run(Thread.java:764)
close() this: android.bluetooth.BluetoothSocket@40dc21b, channel: -1, mSocketIS: android.net.LocalSocketImpl$SocketInputStream@6e20fb8, mSocketOS: android.net.LocalSocketImpl$SocketOutputStream@f5af191mSocket: android.net.LocalSocket@67938f6 impl:android.net.LocalSocketImpl@53c64f7 fd:java.io.FileDescriptor@f846f64, mSocketState: INIT
getBluetoothService() called with no BluetoothManagerCallback
java.io.IOException: read failed, socket might closed or timeout, read ret: -1
    at android.bluetooth.BluetoothSocket.readAll(BluetoothSocket.java:685)
    at android.bluetooth.BluetoothSocket.readInt(BluetoothSocket.java:697)
    at android.bluetooth.BluetoothSocket.connect(BluetoothSocket.java:374)
    at anywheresoftware.b4a.objects.Serial$1.run(Serial.java:159)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:457)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636)
The "BluetoothManagerCallback" message is repeating every half-second or less while the app is running, and I am quite confident my barcode scanner re-attempt connect is firing only every 2 seconds. Perhaps there is a dependent library that I failed to update when I updated the B4A?
 
Last edited:

Jeffrey Cameron

Well-Known Member
Licensed User
After adding a plethora of log statements, I tracked down a re-entrancy issue that was recursively calling the connect method which I have addressed. The debug mode compile is still unusable, however.

One thing I have noticed, though, is when the app ends there are a lot of the following lines about close() Bluetooth:
B4X:
[Warning] assignParent to null: this = DecorView@5c14023[actregister]
Remove from mViews: DecorView@5c14023[actregister], this = android.view.WindowManagerGlobal@f5cd57d
close() this: android.bluetooth.BluetoothSocket@40f14c7, channel: 1, mSocketIS: android.net.LocalSocketImpl$SocketInputStream@baaaaf4, mSocketOS: android.net.LocalSocketImpl$SocketOutputStream@479521dmSocket: null, mSocketState: CLOSED
close() this: android.bluetooth.BluetoothSocket@d6b447a, channel: -1, mSocketIS: android.net.LocalSocketImpl$SocketInputStream@5e5842b, mSocketOS: android.net.LocalSocketImpl$SocketOutputStream@5409088mSocket: android.net.LocalSocket@9b72a21 impl:android.net.LocalSocketImpl@8592e46 fd:java.io.FileDescriptor@a363807, mSocketState: INIT
close() this: android.bluetooth.BluetoothSocket@a922d34, channel: -1, mSocketIS: android.net.LocalSocketImpl$SocketInputStream@43b475d, mSocketOS: android.net.LocalSocketImpl$SocketOutputStream@be9e8d2mSocket: android.net.LocalSocket@bf44da3 impl:android.net.LocalSocketImpl@5bee8a0 fd:java.io.FileDescriptor@8e9fc59, mSocketState: INIT
close() this: android.bluetooth.BluetoothSocket@c59c01e, channel: -1, mSocketIS: android.net.LocalSocketImpl$SocketInputStream@ff420ff, mSocketOS: android.net.LocalSocketImpl$SocketOutputStream@139eeccmSocket: android.net.LocalSocket@a350515 impl:android.net.LocalSocketImpl@35dc02a fd:java.io.FileDescriptor@9f3ce1b, mSocketState: INIT
close() this: android.bluetooth.BluetoothSocket@97d2bb8, channel: -1, mSocketIS: android.net.LocalSocketImpl$SocketInputStream@5eddd91, mSocketOS: android.net.LocalSocketImpl$SocketOutputStream@eefb4f6mSocket: android.net.LocalSocket@17730f7 impl:android.net.LocalSocketImpl@6b54b64 fd:java.io.FileDescriptor@b81c1cd, mSocketState: INIT
close() this: android.bluetooth.BluetoothSocket@da2a82, channel: -1, mSocketIS: android.net.LocalSocketImpl$SocketInputStream@863e593, mSocketOS: android.net.LocalSocketImpl$SocketOutputStream@52db9d0mSocket: android.net.LocalSocket@9f5adc9 impl:android.net.LocalSocketImpl@b046cce fd:java.io.FileDescriptor@f5d47ef, mSocketState: INIT
close() this: android.bluetooth.BluetoothSocket@87ca2fc, channel: -1, mSocketIS: android.net.LocalSocketImpl$SocketInputStream@1a25d85, mSocketOS: android.net.LocalSocketImpl$SocketOutputStream@47e87damSocket: android.net.LocalSocket@3e0740b impl:android.net.LocalSocketImpl@56ef2e8 fd:java.io.FileDescriptor@5b04d01, mSocketState: INIT
close() this: android.bluetooth.BluetoothSocket@34d47a6, channel: -1, mSocketIS: android.net.LocalSocketImpl$SocketInputStream@42045e7, mSocketOS: android.net.LocalSocketImpl$SocketOutputStream@eb45594mSocket: android.net.LocalSocket@953b83d impl:android.net.LocalSocketImpl@6f63832 fd:java.io.FileDescriptor@4a15983, mSocketState: INIT
close() this: android.bluetooth.BluetoothSocket@4b3700, channel: -1, mSocketIS: android.net.LocalSocketImpl$SocketInputStream@4c89b39, mSocketOS: android.net.LocalSocketImpl$SocketOutputStream@fcba57emSocket: android.net.LocalSocket@3960adf impl:android.net.LocalSocketImpl@5acc32c fd:java.io.FileDescriptor@e0eb1f5, mSocketState: INIT
close() this: android.bluetooth.BluetoothSocket@ef89b8a, channel: -1, mSocketIS: android.net.LocalSocketImpl$SocketInputStream@5fa75fb, mSocketOS: android.net.LocalSocketImpl$SocketOutputStream@6b8e618mSocket: android.net.LocalSocket@1657871 impl:android.net.LocalSocketImpl@b4ce656 fd:java.io.FileDescriptor@a7076d7, mSocketState: INIT
close() this: android.bluetooth.BluetoothSocket@7624bc4, channel: -1, mSocketIS: android.net.LocalSocketImpl$SocketInputStream@5882aad, mSocketOS: android.net.LocalSocketImpl$SocketOutputStream@6c911e2mSocket: android.net.LocalSocket@ddba973 impl:android.net.LocalSocketImpl@61a6030 fd:java.io.FileDescriptor@7a9c4a9, mSocketState: INIT
close() this: android.bluetooth.BluetoothSocket@ea6a2e, channel: -1, mSocketIS: android.net.LocalSocketImpl$SocketInputStream@dbd69cf, mSocketOS: android.net.LocalSocketImpl$SocketOutputStream@4fd4f5cmSocket: android.net.LocalSocket@b310265 impl:android.net.LocalSocketImpl@1b6fb3a fd:java.io.FileDescriptor@450d3eb, mSocketState: INIT
close() this: android.bluetooth.BluetoothSocket@9be0548, channel: -1, mSocketIS: android.net.LocalSocketImpl$SocketInputStream@9345fe1, mSocketOS: android.net.LocalSocketImpl$SocketOutputStream@9899106mSocket: android.net.LocalSocket@a66c3c7 impl:android.net.LocalSocketImpl@522df4 fd:java.io.FileDescriptor@bb6191d, mSocketState: INIT
close() this: android.bluetooth.BluetoothSocket@19db792, channel: -1, mSocketIS: android.net.LocalSocketImpl$SocketInputStream@b01d563, mSocketOS: android.net.LocalSocketImpl$SocketOutputStream@c5e3560mSocket: android.net.LocalSocket@a02a19 impl:android.net.LocalSocketImpl@95bbade fd:java.io.FileDescriptor@4b264bf, mSocketState: INIT
close() this: android.bluetooth.BluetoothSocket@561478c, channel: -1, mSocketIS: android.net.LocalSocketImpl$SocketInputStream@804ed5, mSocketOS: android.net.LocalSocketImpl$SocketOutputStream@c64a6eamSocket: android.net.LocalSocket@4b28ddb impl:android.net.LocalSocketImpl@9a15078 fd:java.io.FileDescriptor@5040351, mSocketState: INIT
** Service (srvimageloader) Destroy **
** Service (httputils2service) Destroy **
** Service (starter) Destroy (ignored)**
I am only initializing the serial socket once in the Initialize event. Is this normal? Do I need to worry about a memory leak or some other stack issue attempting to re-connect to a non-powered Bluetooth device every few seconds?
 
Top