Very Long restart.

[Kzah]

If you want to receive support we need this info to help you properly.
» Find Revision
L2J Revision Number: 6098
L2JDP Revision Number: 9859

Hello,

I do not know where the problem is, so I just ask for help. My server runs on Ubuntu and it seems very slow to restart.

The proof:

GM shutdown countdown is over. restarting NOW!
OfflineTradersTable: Offline traders stored.
Offline Traders Table: Offline shops stored(2075ms).
All players disconnected and saved(139088ms).
Stopping GameTimeController
Game Time Controller: Timer stopped(0ms).
All ThreadPools are now stopped
Thread Pool Manager: Manager has been shut down(5176ms).
Community Server Thread: Thread interruped(0ms).
Login Server Thread: Thread interruped(0ms).
GM restart received. Restarting NOW!
SevenSigns: Seven Signs data saved(63031ms).
SevenSigns: Seven Signs status saved(192ms).
RaidBossSpawnManager: All raidboss info saved(61446ms).
GrandBossManager: All Grand Boss info saved(3343ms).
Hellbound Manager: Data saved(0ms).
Item Auction Manager: All tasks stopped(0ms).
Olympiad System: Data saved(1ms).
Hero System: Data saved(1ms).
Clan System: Data saved(2381ms).
Cursed Weapons Manager: Data saved(193ms).
Castle Manor Manager: Data saved(2435ms).
FortressOfResistance: Sucessfully saved attackers down to database!
DevastatedCastle: Sucessfully saved attackers down to database!
BanditStronghold: Sucessfully saved attackers down to database!
WildBeastReserve: Sucessfully saved attackers down to database!
FortressOfTheDead: Sucessfully saved attackers down to database!
CHSiegeManager: Siegable hall attacker lists saved!
Quest Manager: Data saved(323ms).
Global Variables Manager: Variables saved(2ms).
Items On Ground Manager: Data saved(186495ms).
Items On Ground Manager: Cleaned up(1ms).
Game Server: Selector thread has been shut down(0ms).
L2Database Factory: Database connection has been shut down(8ms).

An Idea ?

Thanks !

[Arantir]

Player count? How long server works between restarts? Are database and gameserver on same machine?

What I can say is that indicated rows are related with storing data to database. So some of problems could be: large amount of data (many players), slow connection (different DB and GS physical servers), slow work of database (unoptimized settings, slow server machine).

[Kzah]

There was only me connected with three offline at this time. Otherwise there are 674 characters in the database.
The server restart was two hours ago.
And database and gameserver are on same machine.

I have a server with this configurations :
i3 2130 3.4+ GHz
8 Go RAM
Connection 100 Mbps

[Arantir]

Yeah, it's really strange... 139 sec. for 4 characters...
Seems like connection is fine.

Olympiad System: Data saved(1ms).
Hero System: Data saved(1ms).

Or it is unstable. But that doesn't look like truth with local connections...

Doesn't seem like there is something other but storing data which could cause such delays between "Offline shops stored" and "All players disconnected and saved" messages. Especially for so small character count.

Can you enable slow log in mysql (there is a line about this in my.cnf/my.ini) and make restart for a test?

[St3eT]

Try check Load avarage during restart.

[Kzah]

The CPU for java is 6% during the restart and RAM to 30%, but when the server starts, the CPU for java increases up to 150% or more.

After enable slow log in mysql :

Code: Select all

OfflineTradersTable: Offline traders stored.Offline Traders Table: Offline shops stored(3ms).All players disconnected and saved(1ms).Stopping GameTimeControllerGame Time Controller: Timer stopped(0ms).All ThreadPools are now stoppedThread Pool Manager: Manager has been shut down(5478ms).Community Server Thread: Thread interruped(0ms).Login Server Thread: Thread interruped(0ms).SIGTERM received. Shutting down NOW!SevenSigns: Seven Signs data saved(50568ms).SevenSigns: Seven Signs status saved(308ms).RaidBossSpawnManager: All raidboss info saved(56330ms).GrandBossManager: All Grand Boss info saved(2842ms).Hellbound Manager: Data saved(0ms).Item Auction Manager: All tasks stopped(1ms).Olympiad System: Data saved(2ms).Hero System: Data saved(0ms).Clan System: Data saved(1297ms).Cursed Weapons Manager: Data saved(3ms).Castle Manor Manager: Data saved(2250ms).FortressOfResistance: Sucessfully saved attackers down to database!DevastatedCastle: Sucessfully saved attackers down to database!BanditStronghold: Sucessfully saved attackers down to database!WildBeastReserve: Sucessfully saved attackers down to database!FortressOfTheDead: Sucessfully saved attackers down to database!CHSiegeManager: Siegable hall attacker lists saved!Quest Manager: Data saved(214ms).Global Variables Manager: Variables saved(3ms).Exception in thread "GeneralSTPool-12" java.lang.NullPointerException    at com.l2jserver.gameserver.instancemanager.FourSepulchersManager.clean(FourSepulchersManager.java:259)    at com.l2jserver.gameserver.instancemanager.FourSepulchersManager$ChangeCoolDownTime.run(FourSepulchersManager.java:1756)    at com.l2jserver.gameserver.ThreadPoolManager$RunnableWrapper.run(ThreadPoolManager.java:93)    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)    at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)    at java.util.concurrent.FutureTask.run(FutureTask.java:166)    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)    at java.lang.Thread.run(Thread.java:724)Items On Ground Manager: Data saved(729279ms).Items On Ground Manager: Cleaned up(1ms).Game Server: Selector thread has been shut down(1ms).L2Database Factory: Database connection has been shut down(273ms). 

The server is still running despite it being down by seeing the error.

Would you like me to post the mysql-slow.log ?

[JMD]

Might be a silly question but do you have a dedicated (root) server or virtual (vps) one?

[Kzah]

A dedicated server.

[u3games]

If you want to receive support we need this info to help you properly.
» Find Revision
L2J Revision Number: 6098
L2JDP Revision Number: 9859

Hello,

I do not know where the problem is, so I just ask for help. My server runs on Ubuntu and it seems very slow to restart.

The proof:

GM shutdown countdown is over. restarting NOW!
OfflineTradersTable: Offline traders stored.
Offline Traders Table: Offline shops stored(2075ms).
All players disconnected and saved(139088ms).
Stopping GameTimeController
Game Time Controller: Timer stopped(0ms).
All ThreadPools are now stopped
Thread Pool Manager: Manager has been shut down(5176ms).
Community Server Thread: Thread interruped(0ms).
Login Server Thread: Thread interruped(0ms).
GM restart received. Restarting NOW!
SevenSigns: Seven Signs data saved(63031ms).
SevenSigns: Seven Signs status saved(192ms).
RaidBossSpawnManager: All raidboss info saved(61446ms).
GrandBossManager: All Grand Boss info saved(3343ms).
Hellbound Manager: Data saved(0ms).
Item Auction Manager: All tasks stopped(0ms).
Olympiad System: Data saved(1ms).
Hero System: Data saved(1ms).
Clan System: Data saved(2381ms).
Cursed Weapons Manager: Data saved(193ms).
Castle Manor Manager: Data saved(2435ms).
FortressOfResistance: Sucessfully saved attackers down to database!
DevastatedCastle: Sucessfully saved attackers down to database!
BanditStronghold: Sucessfully saved attackers down to database!
WildBeastReserve: Sucessfully saved attackers down to database!
FortressOfTheDead: Sucessfully saved attackers down to database!
CHSiegeManager: Siegable hall attacker lists saved!
Quest Manager: Data saved(323ms).
Global Variables Manager: Variables saved(2ms).
Items On Ground Manager: Data saved(186495ms).
Items On Ground Manager: Cleaned up(1ms).
Game Server: Selector thread has been shut down(0ms).
L2Database Factory: Database connection has been shut down(8ms).

An Idea ?

Thanks !

Same happens to me :S (dedicated root server)

[Arantir]

Would you like me to post the mysql-slow.log ?

Have you looked inside? If there is something but log header, you may post it.
I expect one of two ways: or there is nothing, or there're queries with intervals almost similar to intervals in java log.

[Kzah]

There is nothing particular to the first view.

Code: Select all

/usr/sbin/mysqld, Version: 5.5.31-0ubuntu0.12.04.2-log ((Ubuntu)). started with:Tcp port: 3306  Unix socket: /var/run/mysqld/mysqld.sockTime                 Id Command    Argument# Time: 130721  5:38:00# User@Host: Login[Login] @ localhost [127.0.0.1]# Query_time: 0.000122  Lock_time: 0.000051 Rows_sent: 0  Rows_examined: 0use l2j_gs;SET timestamp=1374377880;DELETE FROM character_offline_trade;# User@Host: Login[Login] @ localhost [127.0.0.1]# Query_time: 0.000056  Lock_time: 0.000020 Rows_sent: 0  Rows_examined: 0SET timestamp=1374377880;DELETE FROM character_offline_trade_items;# Time: 130721  5:39:52# User@Host: Login[Login] @ localhost [127.0.0.1]# Query_time: 0.000094  Lock_time: 0.000041 Rows_sent: 0  Rows_examined: 0SET timestamp=1374377992;DELETE FROM grandboss_list;# Time: 130721  5:39:59# User@Host: Login[Login] @ localhost [127.0.0.1]# Query_time: 0.000104  Lock_time: 0.000043 Rows_sent: 0  Rows_examined: 0SET timestamp=1374377999;DELETE FROM clanhall_siege_attackers WHERE clanhall_id = 21;# User@Host: Login[Login] @ localhost [127.0.0.1]# Query_time: 0.000087  Lock_time: 0.000037 Rows_sent: 0  Rows_examined: 0SET timestamp=1374377999;DELETE FROM clanhall_siege_attackers WHERE clanhall_id = 34; etc ....

[Arantir]

There is something =)

# Time: 130721 5:39:52
# User@Host: Login[Login] @ localhost [127.0.0.1]
# Query_time: 0.000094 Lock_time: 0.000041 Rows_sent: 0 Rows_examined: 0
SET timestamp=1374377992;
DELETE FROM grandboss_list;
# Time: 130721 5:39:59

Now we can be sure mysql isn't one who takes this time.
So

the CPU for java increases up to 150% or more.

it's java.
But I can't imagine the reason. Even on my laptop server restart takes a half minute (if there was only me).
Did you change startup settings in GameServer_loop.sh? As I remember not all of -XX are recommended to use.

[Kzah]

Code: Select all

#!/bin/bash # exit codes of GameServer:#  0 normal shutdown#  2 reboot attempt while :; do    [ -f log/java0.log.0 ] && mv log/java0.log.0 "log/`date +%Y-%m-%d_%H-%M-%S`_java.log"    [ -f log/stdout.log ] && mv log/stdout.log "log/`date +%Y-%m-%d_%H-%M-%S`_stdout.log"    java -Djava.util.logging.manager=com.l2jserver.util.L2LogManager -Xms2048m -Xmx4096m -cp ./../libs/*:l2jserver.jar com.l2jserver.gameserver.GameServer > log/stdout.log 2>&1    [ $? -ne 2 ] && break#   /etc/init.d/mysql restart    sleep 10done

I have just change -Xms2048m -Xmx4096m.

[marcoviny]

Men this is not in server configuration but, ae in your mysql configuration verify your Mysql Configurations

1 post my configs


max_connections=3000


innodb_flush_log_at_trx_commit=2


innodb_buffer_pool_size=1024M


innodb_thread_concurrency=80

[Kzah]

#
# The MySQL database server configuration file.
#
# You can copy this to one of:
# - "/etc/mysql/my.cnf" to set global options,
# - "~/.my.cnf" to set user-specific options.
#
# One can use all long options that the program supports.
# Run program with --help to get a list of available options and with
# --print-defaults to see which it would actually understand and use.
#
# For explanations see
# http://dev.mysql.com/doc/mysql/en/serve ... ables.html

# This will be passed to all mysql clients
# It has been reported that passwords should be enclosed with ticks/quotes
# escpecially if they contain "#" chars...
# Remember to edit /etc/mysql/debian.cnf when changing the socket location.
[client]
port = 3306
socket = /var/run/mysqld/mysqld.sock

# Here is entries for some specific programs
# The following values assume you have at least 32M ram

# This was formally known as [safe_mysqld]. Both versions are currently parsed.
[mysqld_safe]
socket = /var/run/mysqld/mysqld.sock
nice = 0

[mysqld]
#
# * Basic Settings
#
user = mysql
pid-file = /var/run/mysqld/mysqld.pid
socket = /var/run/mysqld/mysqld.sock
port = 3306
basedir = /usr
datadir = /var/lib/mysql
tmpdir = /tmp
lc-messages-dir = /usr/share/mysql
skip-external-locking
#
# Instead of skip-networking the default is now to listen only on
# localhost which is more compatible and is not less secure.
bind-address = 127.0.0.1
#
# * Fine Tuning
#
key_buffer = 16M
max_allowed_packet = 16M
thread_stack = 192K
thread_cache_size = 8
# This replaces the startup script and checks MyISAM tables if needed
# the first time they are touched
myisam-recover = BACKUP
#max_connections = 100
#table_cache = 64
#thread_concurrency = 10
#
# * Query Cache Configuration
#
query_cache_limit = 1M
query_cache_size = 16M
#
# * Logging and Replication
#
# Both location gets rotated by the cronjob.
# Be aware that this log type is a performance killer.
# As of 5.1 you can enable the log at runtime!
#general_log_file = /var/log/mysql/mysql.log
#general_log = 1
#
# Error log - should be very few entries.
#
log_error = /var/log/mysql/error.log
#
# Here you can see queries with especially long duration
log_slow_queries = /var/log/mysql/mysql-slow.log
long_query_time = 2
log-queries-not-using-indexes
#
# The following can be used as easy to replay backup logs or for replication.
# note: if you are setting up a replication slave, see README.Debian about
# other settings you may need to change.
#server-id = 1
#log_bin = /var/log/mysql/mysql-bin.log
expire_logs_days = 10
max_binlog_size = 100M
#binlog_do_db = include_database_name
#binlog_ignore_db = include_database_name
#
# * InnoDB
#
# InnoDB is enabled by default with a 10MB datafile in /var/lib/mysql/.
# Read the manual for more InnoDB related options. There are many!
#
# * Security Features
#
# Read the manual, too, if you want chroot!
# chroot = /var/lib/mysql/
#
# For generating SSL certificates I recommend the OpenSSL GUI "tinyca".
#
# ssl-ca=/etc/mysql/cacert.pem
# ssl-cert=/etc/mysql/server-cert.pem
# ssl-key=/etc/mysql/server-key.pem

[mysqldump]
quick
quote-names
max_allowed_packet = 16M

[mysql]
#no-auto-rehash # faster start of mysql but no tab completition

[isamchk]
key_buffer = 16M

#
# * IMPORTANT: Additional settings that can override those from this file!
# The files must end with '.cnf', otherwise they'll be ignored.
#
!includedir /etc/mysql/conf.d/

Actually, i have this configurations.
And here very different. ><

innodb_flush_log_at_trx_commit=2

innodb_buffer_pool_size=1024M

innodb_thread_concurrency=80

Is'nt present by default ?