Void virtualWrite -> boolean virtualWrite, time for a change?

Have you maxed out the debug level for the server?

No, have never read of such a feature :slight_smile:
Mind pointing me in the right direction?

check server.properties for debug level, set to max, see if it helps identify any problems and then reset to default logging. Obviously you need to read the logs.

1 Like

“trace|debug|info|error”
Which is the more precise?

trace

1 Like

Much appreciated :slight_smile: Will return in a while as the log builds up (Y) Thank you

So anyone got any translation for this error? Seems to reoccur in my log

16:48:16.503 TRACE- Blynk server IOException.
java.io.IOException: >A current connection was force closed by host computer <translated from swedish
	at sun.nio.ch.SocketDispatcher.read0(Native Method) ~[?:1.8.0_161]
	at sun.nio.ch.SocketDispatcher.read(Unknown Source) ~[?:1.8.0_161]
	at sun.nio.ch.IOUtil.readIntoNativeBuffer(Unknown Source) ~[?:1.8.0_161]
	at sun.nio.ch.IOUtil.read(Unknown Source) ~[?:1.8.0_161]
	at sun.nio.ch.SocketChannelImpl.read(Unknown Source) ~[?:1.8.0_161]
	at io.netty.buffer.PooledUnsafeDirectByteBuf.setBytes(PooledUnsafeDirectByteBuf.java:288) ~[server-0.30.0-java8.jar:?]
	at io.netty.buffer.AbstractByteBuf.writeBytes(AbstractByteBuf.java:1108) ~[server-0.30.0-java8.jar:?]
	at io.netty.channel.socket.nio.NioSocketChannel.doReadBytes(NioSocketChannel.java:345) ~[server-0.30.0-java8.jar:?]
	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:126) ~[server-0.30.0-java8.jar:?]
	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:645) ~[server-0.30.0-java8.jar:?]
	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:580) ~[server-0.30.0-java8.jar:?]
	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:497) ~[server-0.30.0-java8.jar:?]
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:459) ~[server-0.30.0-java8.jar:?]
	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:886) ~[server-0.30.0-java8.jar:?]
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[server-0.30.0-java8.jar:?]
	at java.lang.Thread.run(Unknown Source) [?:1.8.0_161]

That’s fine. You may ignore it.

1 Like

What of this then

16:55:44.737 DEBUG- [id: 0x4fa537d6, L:/192.168.1.3:8443 - R:/192.168.1.1:43366] Swallowing a harmless 'connection reset by peer / broken pipe' error that occurred while writing close_notify in response to the peer's close_notify
java.io.IOException: En befintlig anslutning tvingades att stänga av fjärrvärddatorn
	at sun.nio.ch.SocketDispatcher.read0(Native Method) ~[?:1.8.0_161]
	at sun.nio.ch.SocketDispatcher.read(Unknown Source) ~[?:1.8.0_161]
	at sun.nio.ch.IOUtil.readIntoNativeBuffer(Unknown Source) ~[?:1.8.0_161]
	at sun.nio.ch.IOUtil.read(Unknown Source) ~[?:1.8.0_161]
	at sun.nio.ch.SocketChannelImpl.read(Unknown Source) ~[?:1.8.0_161]
	at io.netty.buffer.PooledUnsafeDirectByteBuf.setBytes(PooledUnsafeDirectByteBuf.java:288) ~[server-0.30.0-java8.jar:?]
	at io.netty.buffer.AbstractByteBuf.writeBytes(AbstractByteBuf.java:1108) ~[server-0.30.0-java8.jar:?]
	at io.netty.channel.socket.nio.NioSocketChannel.doReadBytes(NioSocketChannel.java:345) ~[server-0.30.0-java8.jar:?]
	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:126) ~[server-0.30.0-java8.jar:?]
	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:645) ~[server-0.30.0-java8.jar:?]
	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:580) ~[server-0.30.0-java8.jar:?]
	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:497) ~[server-0.30.0-java8.jar:?]
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:459) ~[server-0.30.0-java8.jar:?]
	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:886) ~[server-0.30.0-java8.jar:?]
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[server-0.30.0-java8.jar:?]
	at java.lang.Thread.run(Unknown Source) [?:1.8.0_161]

That’s also fine. This is just a warning about unexpected connection drop.

@Fettkeewl maybe third time lucky :slight_smile:

Thanks @Dmytro!

I’m getting tired of this lol :stuck_out_tongue:
Not understanding why it works sometimes and sometimes not (makes me believe there is no issue to my code, else it wouldnt work any time)

I’ll just keep monitoring the logs :stuck_out_tongue:

Alright here is a capture of Blynk.log when my device

  • Woke up
  • Updated a few widgets
  • Disconnected

It did not update terminal. So what is a ‘hardware timeout disconnect’ from a Blynk perspective?

19:29:56.841 TRACE- Incoming HardwareMessage{id=10, command=Hardware, length=8, body='vw 15 69'}
19:30:16.228 TRACE- Incoming id=16, command=Ping, length=0, body=''
19:30:18.905 TRACE- State handler. Hardware timeout disconnect. Event : WRITER_IDLE. Closing.
19:30:18.905 TRACE- Hardware channel disconnect for UserKey{email='adiiss_@hotmail.com', appName='Blynk'}, dashId 1, deviceId 0, token ****************.
19:30:18.905 TRACE- Changing device status. DeviceId 0, dashId 1
19:30:18.905 TRACE- Sending device offline message.
19:30:46.576 TRACE- Incoming id=17, command=Ping, length=0, body=''
19:31:16.257 TRACE- Incoming id=18, command=Ping, length=0, body=''

This is how it now looks when it works:

19:29:46.391 TRACE- Incoming id=15, command=Ping, length=0, body=''
19:29:55.558 TRACE- Incoming LoginMessage{id=1, command=Login, length=32, body='*************'}
19:29:55.558 DEBUG- completeLogin. [id: 0x2f090fa4, L:/192.168.1.3:8442 - R:/192.168.1.15:49153]
19:29:55.558 TRACE- Connected device id 0, dash id 1
19:29:55.558 INFO - adiiss_@hotmail.com hardware joined.
19:29:55.639 TRACE- Incoming id=2, command=Internal, length=72, body='ver 0.5.0 h-beat 10 buff-in 1024 dev Arduino build Jan 26 2018 19:24:46 '
19:29:55.639 TRACE- Info command. heartbeat interval 10
19:29:55.640 DEBUG- Changing read timeout interval to 23
19:29:55.707 TRACE- Incoming id=3, command=Internal, length=8, body='rtc sync'
19:29:55.847 TRACE- Incoming id=4, command=HardwareSync, length=5, body='vr 16'
19:29:55.904 TRACE- Incoming id=5, command=HardwareSync, length=13, body='vr 10 12 2 14'
19:29:55.995 TRACE- Incoming HardwareMessage{id=5, command=Hardware, length=8, body='vw 11 15'}
19:29:56.151 TRACE- Incoming HardwareMessage{id=5, command=Hardware, length=8, body='vw 13 30'}
19:29:56.151 TRACE- Incoming HardwareMessage{id=6, command=Hardware, length=13, body='vw 0 976.0000'}
19:29:56.151 TRACE- Incoming HardwareMessage{id=7, command=Hardware, length=10, body='vw 1 4.008'}
19:29:56.647 TRACE- Incoming HardwareMessage{id=8, command=Hardware, length=12, body='vw 5 28.0000'}
19:29:56.715 TRACE- Incoming HardwareMessage{id=9, command=Hardware, length=14, body='vw 3 LOCKED ?'}
19:29:56.841 TRACE- Incoming HardwareMessage{id=10, command=Hardware, length=8, body='vw 15 69'}
19:30:16.228 TRACE- Incoming id=16, command=Ping, length=0, body=''
19:30:18.905 TRACE- State handler. Hardware timeout disconnect. Event : WRITER_IDLE. Closing.
19:30:18.905 TRACE- Hardware channel disconnect for UserKey{email='adiiss_@hotmail.com', appName='Blynk'}, dashId 1, deviceId 0, token *************.
19:30:18.905 TRACE- Changing device status. DeviceId 0, dashId 1
19:30:18.905 TRACE- Sending device offline message.
19:30:46.576 TRACE- Incoming id=17, command=Ping, length=0, body=''
19:31:16.257 TRACE- Incoming id=18, command=Ping, length=0, body=''
19:31:46.578 TRACE- Incoming id=19, command=Ping, length=0, body=''
19:32:16.222 TRACE- Incoming id=20, command=Ping, length=0, body=''
19:32:46.224 TRACE- Incoming id=21, command=Ping, length=0, body=''
19:32:48.980 TRACE- Incoming LoginMessage{id=1, command=Login, length=32, body='*************'}
19:32:48.980 DEBUG- Re registering hard channel. [id: 0x0020b5ec, L:/192.168.1.3:8442 - R:/192.168.1.15:49153]
19:32:48.980 DEBUG- completeLogin. [id: 0x0020b5ec, L:/192.168.1.3:8442 - R:/192.168.1.15:49153]
19:32:48.981 TRACE- Connected device id 0, dash id 1
19:32:48.981 INFO - adiiss_@hotmail.com hardware joined.
19:32:49.052 TRACE- Incoming id=2, command=Internal, length=72, body='ver 0.5.0 h-beat 10 buff-in 1024 dev Arduino build Jan 26 2018 19:24:46 '
19:32:49.052 TRACE- Info command. heartbeat interval 10
19:32:49.052 DEBUG- Changing read timeout interval to 23
19:32:49.131 TRACE- Incoming id=3, command=Internal, length=8, body='rtc sync'
19:32:49.207 TRACE- Incoming id=4, command=HardwareSync, length=5, body='vr 16'
19:32:49.318 TRACE- Incoming id=5, command=HardwareSync, length=13, body='vr 10 12 2 14'
19:32:49.351 TRACE- Incoming HardwareMessage{id=6, command=Hardware, length=13, body='vw 0 978.0000'}
19:32:49.426 TRACE- Incoming HardwareMessage{id=5, command=Hardware, length=8, body='vw 11 15'}
19:32:49.502 TRACE- Incoming HardwareMessage{id=5, command=Hardware, length=8, body='vw 13 30'}
19:32:49.503 TRACE- Incoming HardwareMessage{id=7, command=Hardware, length=10, body='vw 1 4.016'}
19:32:50.014 TRACE- Incoming HardwareMessage{id=8, command=Hardware, length=11, body='vw 5 26.375'}
19:32:50.141 TRACE- Incoming HardwareMessage{id=9, command=Hardware, length=14, body='vw 3 LOCKED ?'}
19:32:50.262 TRACE- Incoming HardwareMessage{id=10, command=Hardware, length=8, body='vw 15 70'}
19:32:50.262 TRACE- Incoming HardwareMessage{id=11, command=Hardware, length=322, body='vw 20 
---------------- 19:32:49 ----------------
Wake Reason: Door open
Chip RstReason: Deep-Sleep Wake
Battery voltage: 4.02
Battery raw: 978.00
Sleep time: 15 minutes
Recheck time: 30 seconds
Voltage factor (977): 0.977
Temperature: 26.37 °C
Door is closed
Door is unlocked
WiFi signal at 70 %
Sleeping until: 19:33:20
'}
19:32:50.338 TRACE- Incoming HardwareMessage{id=12, command=Hardware, length=14, body='vw 17 19:33:20'}
19:33:12.318 TRACE- State handler. Hardware timeout disconnect. Event : WRITER_IDLE. Closing.
19:33:12.318 TRACE- Hardware channel disconnect for UserKey{email='adiiss_@hotmail.com', appName='Blynk'}, dashId 1, deviceId 0, token *************.
19:33:12.318 TRACE- Changing device status. DeviceId 0, dashId 1
19:33:12.318 TRACE- Sending device offline message.
19:33:16.235 TRACE- Incoming id=22, command=Ping, length=0, body=''
``

In your case I’m guessing it means you sent the MCU to deepSleep.

So I let my device run over night, waking every 1 hour and reporting stuff to my local server.
With this interval I hit 1 miss in connection.

I have edited around the error in the log with hashtags. @Dmytro all other wake cycles successfully deliver their messages and behavior is OK (i.e. there should not be anything wrong with my code since 1 of about 12 wake cycles failed. According to Blynk.log (seen in link)
the failed cycle was atempting an RTC sync and then HW got disconnected. Last night some cycles failed after RTC sync when the device was doing a syncVirtual. So it’s not code specific as much as connection to server specific.

Always with the following text:
State handler. Hardware timeout disconnect. Event : WRITER_IDLE. Closing.

This error is strange since I have my sketch sprinkled with Blynk.run where ever there is a possibility for “longer” runs.

My next attempt:
Increase Heartbeat
Increase network timeout
Increase everything!! :stuck_out_tongue:

This exception just says that connection was broken and after 30 seconds of missing pings server closed it.

sometimes i also had “missing” terminal prints. try to do it like this:

terminal.println("");
terminal.flush();

terminal.println(logEvents);
terminal.flush();

terminal.println("");
terminal.flush();

for me, this solved the issue 99%

Thanks I shall try it!
Although I have more concluded it to be a connection issue due to logs, rather than a terminal issue, but I’m all up for trying new things :slight_smile:

i just shared my experience and what solved the problem for me. it is not the best solution from professional point of view, i know :slight_smile: