Cannot write log entry

Started by Sqveeze, April 10, 2016, 02:45:06 PM

Previous topic - Next topic
Print
Go Down Pages1
User actions

Sqveeze

April 10, 2016, 02:45:06 PM
Hello,

2016-04-10 11:38:18   TELNET_CONNECTION   Accepted telnet connection from 127.0.0.1...
2016-04-10 11:38:19   TELNET_CONNECTION   Closed telnet connection to 127.0.0.1...
2016-04-10 11:38:20   TELNET_CONNECTION   Accepted telnet connection from 127.0.0.1...
2016-04-10 11:38:20   TELNET_CONNECTION   Closed telnet connection to 127.0.0.1...
2016-04-10 11:38:21   TELNET_CONNECTION   Accepted telnet connection from 127.0.0.1...
2016-04-10 11:38:22   TELNET_CONNECTION   Closed telnet connection to 127.0.0.1...
2016-04-10 11:38:28   TELNET_CONNECTION   Accepted telnet connection from 127.0.0.1...
2016-04-10 11:38:29   TELNET_CONNECTION   Closed telnet connection to 127.0.0.1...
2016-04-10 11:38:30   TELNET_CONNECTION   Accepted telnet connection from 127.0.0.1...
2016-04-10 11:38:31   TELNET_CONNECTION   Closed telnet connection to 127.0.0.1...
2016-04-10 11:38:33   TELNET_CONNECTION   Accepted telnet connection from 127.0.0.1...
2016-04-10 11:38:33   TELNET_CONNECTION   Closed telnet connection to 127.0.0.1...
2016-04-10 11:38:35   TELNET_CONNECTION   Accepted telnet connection from 127.0.0.1...
2016-04-10 11:38:35   TELNET_CONNECTION   Closed telnet connection to 127.0.0.1...
2016-04-10 11:38:37   TELNET_CONNECTION   Accepted telnet connection from 127.0.0.1...
2016-04-10 11:38:38   START_INSTANCE   Got telnet command from 127.0.0.1 to start virtual bot instance GeTreKt...
2016-04-10 11:38:38   TELNET_CONNECTION   Closed telnet connection to 127.0.0.1...
2016-04-10 11:38:38   TELNET_CONNECTION   Accepted telnet connection from 127.0.0.1...
2016-04-10 11:38:38   LOGGER_SQL_ERROR   Critical: Cannot write log entry to MySQL server!
2016-04-10 11:38:38   JTS3ServerMod 6.1.1 Hosting Edition (04.04.2016): EXCEPTION
com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet successfully received from the server was 762,767 milliseconds ago.  The last packet sent successfully to the server was 67 milliseconds ago.
   at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
   at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
   at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
   at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
   at com.mysql.jdbc.Util.handleNewInstance(Util.java:404)
   at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:981)
   at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3465)
   at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3365)
   at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3805)
   at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2478)
   at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2625)
   at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2551)
   at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1861)
   at com.mysql.jdbc.PreparedStatement.executeUpdateInternal(PreparedStatement.java:2073)
   at com.mysql.jdbc.PreparedStatement.executeUpdateInternal(PreparedStatement.java:2009)
   at com.mysql.jdbc.PreparedStatement.executeLargeUpdate(PreparedStatement.java:5094)
   at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1994)
   at de.stefan1200.jts3servermod.u.a(Unknown Source)
   at de.stefan1200.jts3servermod.u.a(Unknown Source)
   at de.stefan1200.jts3servermod.JTS3ServerMod.addLogEntry(Unknown Source)
   at de.stefan1200.jts3servermod.JTS3ServerMod.a(Unknown Source)
   at de.stefan1200.jts3servermod.JTS3ServerMod.b(Unknown Source)
   at de.stefan1200.jts3servermod.o.run(Unknown Source)
   at java.lang.Thread.run(Thread.java:745)
Caused by: java.io.EOFException: Can not read response from server. Expected to read 4 bytes, read 0 bytes before connection was unexpectedly lost.
   at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:2957)
   at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3375)
   ... 17 more
2016-04-10 11:38:38   LOGGER_SQL_ERROR   Try to reconnect to MySQL server...
2016-04-10 11:38:38   LOGGER_SQL_CONNECT   Successfully connected to MySQL server for logging!
2016-04-10 11:38:39   TELNET_CONNECTION   Closed telnet connection to 127.0.0.1...
2016-04-10 11:38:45   TELNET_CONNECTION   Accepted telnet connection from 127.0.0.1...

I just see this in the log.

After i start the bot, its work for a few minutes like 20 or 25min, then i see this in the log and then the bot closes itself.

Stefan1200

#1
April 10, 2016, 03:02:33 PM
Maybe inactivity disconnection from the MySQL server? Check the MySQL server settings.

But why the bot closes? I can't see that in the log. Please post the log file, where I can see, that the bot was closed.

CaptainsLP

#2
April 11, 2016, 06:09:13 AM
Sqveeze, what kind of System are you running the Bot on?

Windows/Debian/Ubuntu and which version.


If you are running on Debian based systems then take a look @
/var/log/mysql.log or /var/log/mysql/error.log
and /var/log/syslog

If java crashes for some reason and kills the Bot Process it will be at least in the syslog.
everything else should be in the Botlog.

Stefan1200

#3
April 11, 2016, 07:45:47 AM
Quote from: CaptainsLP on April 11, 2016, 06:09:13 AM
If java crashes for some reason and kills the Bot Process it will be at least in the syslog.
everything else should be in the Botlog.

As you can see in the log, it is not Java or the bot, the MySQL server was disconnecting the database connection.

Sqveeze

#4
April 13, 2016, 10:38:52 AM
Running the bot on CentOS 7.

And the last entry i see in the log is that the telnet connect then disconnect after then when i go check "screen -ls" there is no screen for jtsbot

Stefan1200

#5
April 13, 2016, 10:50:26 AM
Quote from: Sqveeze on April 13, 2016, 10:38:52 AM
And the last entry i see in the log is that the telnet connect then disconnect

That is normal, the web interface just needs a connection to the query interface for less than 0,6 seconds and disconnect again.


Quote from: Sqveeze on April 13, 2016, 10:38:52 AM
after then when i go check "screen -ls" there is no screen for jtsbot

And what is in the log file? Because the JTS3ServerMod always writes something to the log, if the process will be stopped.

Sqveeze

#6
April 13, 2016, 10:51:36 AM
Just tried to run the bot again, this time with more ram 100MB, and then the bot was last for like 3 minutes:

Full log today:

2016-04-13 08:42:46   START_MANAGER   JTS3ServerMod 6.1.1 Hosting Edition (04.04.2016) Instance Manager started...
2016-04-13 08:42:46   CONFIG   Loading InstanceManager config file from: /home/jtsbot/config/JTS3ServerMod_InstanceManager.cfg
2016-04-13 08:42:46   CONFIG   Bot chat command !exec is disabled!
2016-04-13 08:42:46   CONFIG   Multi IP Mode disabled!
2016-04-13 08:42:46   CONFIG   Automatic MySQL log delete for entries older than 7 days is activated!
2016-04-13 08:42:46   CONFIG   Automatic MySQL connection log delete for entries older than 7 days is activated!
2016-04-13 08:42:47   LOGGER_SQL_CONNECT   Successfully connected to MySQL server for logging!
2016-04-13 08:42:47   CONFIG   MySQL mode enabled!
2016-04-13 08:42:47   LICENCE_CHECK   Licence key is valid! Thank you very much for your support, Sqveeze!
2016-04-13 08:42:47   START_INSTANCE   Start virtual bot instance GeTreKt...
2016-04-13 08:42:47   TELNET_START   Query Interface started on port 5873!
2016-04-13 08:43:44   TELNET_CONNECTION   Accepted telnet connection from 127.0.0.1...
2016-04-13 08:43:45   TELNET_CONNECTION   Closed telnet connection to 127.0.0.1...
2016-04-13 08:43:48   TELNET_CONNECTION   Accepted telnet connection from 127.0.0.1...
2016-04-13 08:43:48   TELNET_CONNECTION   Closed telnet connection to 127.0.0.1...
2016-04-13 08:43:50   TELNET_CONNECTION   Accepted telnet connection from 127.0.0.1...
2016-04-13 08:43:50   TELNET_CONNECTION   Closed telnet connection to 127.0.0.1...
2016-04-13 08:43:54   TELNET_CONNECTION   Accepted telnet connection from 127.0.0.1...
2016-04-13 08:43:55   TELNET_CONNECTION   Closed telnet connection to 127.0.0.1...
2016-04-13 08:44:04   TELNET_CONNECTION   Accepted telnet connection from 127.0.0.1...
2016-04-13 08:44:05   TELNET_CONNECTION   Closed telnet connection to 127.0.0.1...
2016-04-13 08:44:08   TELNET_CONNECTION   Accepted telnet connection from 127.0.0.1...
2016-04-13 08:44:08   TELNET_CONNECTION   Closed telnet connection to 127.0.0.1...
2016-04-13 08:44:18   TELNET_CONNECTION   Accepted telnet connection from 127.0.0.1...
2016-04-13 08:44:18   TELNET_CONNECTION   Closed telnet connection to 127.0.0.1...
2016-04-13 08:44:28   TELNET_CONNECTION   Accepted telnet connection from 127.0.0.1...
2016-04-13 08:44:28   TELNET_CONNECTION   Closed telnet connection to 127.0.0.1...
2016-04-13 08:44:38   TELNET_CONNECTION   Accepted telnet connection from 127.0.0.1...
2016-04-13 08:44:38   TELNET_CONNECTION   Closed telnet connection to 127.0.0.1...
2016-04-13 08:44:48   TELNET_CONNECTION   Accepted telnet connection from 127.0.0.1...
2016-04-13 08:44:48   TELNET_CONNECTION   Closed telnet connection to 127.0.0.1...
2016-04-13 08:44:58   TELNET_CONNECTION   Accepted telnet connection from 127.0.0.1...
2016-04-13 08:44:58   TELNET_CONNECTION   Closed telnet connection to 127.0.0.1...

Stefan1200

#7
April 13, 2016, 10:54:29 AM
Try to use 30 MB heap space, not 100 MB.

Please check if something will be written to stdout and stderr.

Sqveeze

#8
April 13, 2016, 10:58:22 AM
I attached myself to the active screen and then i seen this:

JTS3ServerMod 6.1.1 Hosting Edition (04.04.2016) Instance Manager started...
Writing InstanceManager log file to: /home/jtsbot/JTS3ServerMod_InstanceManager.log
Loading InstanceManager config file from: /home/jtsbot/config/JTS3ServerMod_InstanceManager.cfg
Successfully connected to MySQL server for logging!
MySQL mode enabled!
Licence key is valid! Thank you very much for your support, Sqveeze!
Query Interface started on port 5873!
Killed

Why the process gets killed? And what killing it?

Stefan1200

#9
April 13, 2016, 11:00:53 AM
Quote from: Sqveeze on April 13, 2016, 10:58:22 AM
I attached myself to the active screen and then i seen this:
[...]
Why the process gets killed? And what killing it?

Your server is a vserver? If yes, than the virtualisation software is killing it, because the process exceeds a hard limit.

Did you tried it with a heap space set to 30M?

Sqveeze

#10
April 13, 2016, 11:03:08 AM
its a VPS from blazingfast, if you may know something about that host. Now trying with 30MB. Will report back if its works or not.

Stefan1200

#11
April 13, 2016, 11:08:32 AM
Blazingfast...terrible company.

If 30M is not working, you or the support have to check the virtualisation logs, which limit is causing the process kill and set a higher limit. You can also try a different JavaVM (some users reported, that the original Oracle VM is working better on vservers than OpenJDK). I can't change anything on my end.

CaptainsLP

#12
April 14, 2016, 11:52:46 AM Last Edit: April 14, 2016, 11:54:37 AM by CaptainsLP
Hi Sqveeze,


you said you are running on a VPS, then your Hoster could be the problem,
some Virtualization tools like KVM or Virtuozzo are killing processes on the VPS system when they are using too much
Memory and/or CPU based on your plan take a look how much CPU Power your Hoster gives your VPS.

Some of them limit the CPU Power to GuestVM's to 60 - 80% to not overload the Host.
Print
Go Up Pages1
User actions