linstor-controller 1.28.0 hangs after startup
Adam Goryachev
mailinglists at websitemanagers.com.au
Sat Jul 13 03:11:18 CEST 2024
Hi all, hoping to get some ideas on how to investigate this issue
further, including as many details as I can below...
I've been a bit lax, and had a few issues with my linstor cluster
recently, one of which was I ended up with some mis-matched versions on
one or two satellites (ie,
linstor-client/python-linstor/linstor-satellite) although the
linstor-satellite versions all matched and all nodes were online and
working.
Except, I also had an issue where I tried to resize (grow) one volume,
and this was producing error reports on the satellite about the drbd res
files not being valid, as well as the return code from a drbdadm command
as 5 instead of what it should be (this seemed to be due to using a
newer version of drbdadm compared to linstor-controller, although there
was no actual error message, just a warning about timeout values was the
output).
So, I thought I should do the obvious, and upgrade everything to the
latest versions, to make sure drbd-utils, drbd, linstor-controller,
linstor-client, python-linstor etc all matched across all nodes. I
started with the controller node, and it seemed to go smoothly, showing
all nodes as offline/version mismatch when done. I proceeded with the
first diskful satellite, and it came online, so I moved onto the next.
When I checked linstor node list, the controller was not responding, so
after some time, I restarted the controller service, and it all was
working as expected (3 nodes online, and the rest offline/version mismatch).
However, after a short amount of time, the linstor controller just stops
responding again, with basic commands like "linstor node list" timing
out after 5 minutes.
At this point, I'm not seeing any new logs, or anything at all regarding
linstor-controller. So I'm not really sure what the issue is, or why it
seems to be stuck, so any advice is of course appreciated.
I'll include the output from journalctl which shows all the startup
messages, but not sure what else I should include or where else to look.
Also, I'm concerned about the status of some of the resources, since I
can't really see what is happening with them, although using drbdadm
status I'm seeing mostly what I expect, where all resources are showing
2 nodes in-sync, except for the original resize one I mentioned above
which is showing this:
The one diskfull satellite not yet upgraded (san6):
crossbow role:Secondary
disk:UpToDate
castle role:Secondary
peer-disk:UpToDate
flail connection:Connecting
san7 connection:Connecting
xen1 role:Primary
peer-disk:Diskless peer-client:yes
The controller:
crossbow role:Secondary
disk:UpToDate
flail connection:Connecting
san5 role:Secondary
peer-disk:Inconsistent
san6 role:Secondary
peer-disk:UpToDate
san7 connection:Connecting
xen1 role:Primary
peer-disk:Diskless peer-client:yes
I added san5 in an attempt to get at least a proper second copy of the
data before attempting to upgrade san6 which is still offline due to
version mismatch.
output from journalctl -u linstor-controller, including the shutdown
logs in case that provides some hints on where it was hung:
Jul 13 10:06:01 castle systemd[1]: Stopping linstor-controller.service -
LINSTOR Controller Service...
Jul 13 10:06:01 castle Controller[30333]: 10:06:01.567 [Thread-2] INFO
LINSTOR/Controller - SYSTEM - Shutdown in progress
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: State
'stop-sigterm' timed out. Killing.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30333 (java) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30345 (Main) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30346 (GC Thread#0) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30347 (G1 Main Marker) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30348 (G1 Conc#0) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30349 (G1 Refine#0) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30350 (G1 Service) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30351 (VM Thread) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30352 (Reference Handl) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30353 (Finalizer) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30354 (Signal Dispatch) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30355 (Service Thread) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30356 (Monitor Deflati) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30357 (C2 CompilerThre) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30358 (C1 CompilerThre) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30359 (Sweeper thread) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30360 (Notification Th) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30361 (VM Periodic Tas) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30362 (Common-Cleaner) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30363 (GC Thread#1) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30372 (G1 Refine#1) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30373 (MainWorkerPool-) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30374 (MainWorkerPool-) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30375 (TimerEventServi) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30378 (TaskScheduleSer) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30379 (SslConnector) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30380 (EbsStatusPoll) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30381 (HttpServer-0) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30382 (grizzly-nio-ker) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30383 (grizzly-nio-ker) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30384 (n/a) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30385 (n/a) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30386 (grizzly-http-se) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30387 (grizzly-http-se) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30388 (grizzly-http-se) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 30423 (parallel-3) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 48151 (n/a) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 79597 (n/a) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Killing
process 79601 (n/a) with signal SIGKILL.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Main
process exited, code=killed, status=9/KILL
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Failed
with result 'timeout'.
Jul 13 10:07:31 castle systemd[1]: Stopped linstor-controller.service -
LINSTOR Controller Service.
Jul 13 10:07:31 castle systemd[1]: linstor-controller.service: Consumed
4min 13.152s CPU time.
Jul 13 10:07:31 castle systemd[1]: Starting linstor-controller.service -
LINSTOR Controller Service...
Jul 13 10:07:32 castle Controller[79818]: LINSTOR, Module Controller
Jul 13 10:07:32 castle Controller[79818]: Version: 1.28.0
(959382f7b4fb9436fefdd21dfa262e90318edaed)
Jul 13 10:07:32 castle Controller[79818]: Build time:
2024-07-11T10:56:25+00:00
Jul 13 10:07:32 castle Controller[79818]: Java Version: 17
Jul 13 10:07:32 castle Controller[79818]: Java VM: Debian, Version
17.0.11+9-Debian-1deb12u1
Jul 13 10:07:32 castle Controller[79818]: Operating system: Linux,
Version 6.1.0-22-amd64
Jul 13 10:07:32 castle Controller[79818]: Environment: amd64, 2
processors, 1978 MiB memory reserved for allocations
Jul 13 10:07:32 castle Controller[79818]: System components
initialization in progress
Jul 13 10:07:32 castle Controller[79818]: Loading configuration file
"/etc/linstor/linstor.toml"
Jul 13 10:07:33 castle Controller[79818]: 10:07:32,952 |-INFO in
ch.qos.logback.classic.LoggerContext[default] - This is logback-classic
version 1.3.8
Jul 13 10:07:33 castle Controller[79818]: 10:07:32,987 |-INFO in
ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource
[logback-test.xml]
Jul 13 10:07:33 castle Controller[79818]: 10:07:32,988 |-INFO in
ch.qos.logback.classic.LoggerContext[default] - Found resource
[logback.xml] at [file:/usr/share/linstor-server/lib/conf/logback.xml]
Jul 13 10:07:33 castle Controller[79818]: 10:07:33,248 |-INFO in
ch.qos.logback.core.model.processor.AppenderModelHandler - Processing
appender named [STDOUT]
Jul 13 10:07:33 castle Controller[79818]: 10:07:33,248 |-INFO in
ch.qos.logback.core.model.processor.AppenderModelHandler - About to
instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
Jul 13 10:07:33 castle Controller[79818]: 10:07:33,270 |-INFO in
ch.qos.logback.core.model.processor.ImplicitModelHandler - Assuming
default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for
[encoder] property
Jul 13 10:07:33 castle Controller[79818]: 10:07:33,303 |-WARN in
ch.qos.logback.core.model.processor.AppenderModelHandler - Appender
named [FILE] not referenced. Skipping further processing.
Jul 13 10:07:33 castle Controller[79818]: 10:07:33,304 |-INFO in
ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting
level of logger [okhttp3] to OFF
Jul 13 10:07:33 castle Controller[79818]: 10:07:33,304 |-INFO in
ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting
level of logger [org.apache.http] to INFO
Jul 13 10:07:33 castle Controller[79818]: 10:07:33,304 |-INFO in
ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting
level of logger [cron] to INFO
Jul 13 10:07:33 castle Controller[79818]: 10:07:33,304 |-INFO in
ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting
level of logger [LINSTOR/Controller] to INFO
Jul 13 10:07:33 castle Controller[79818]: 10:07:33,304 |-INFO in
ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting
additivity of logger [LINSTOR/Controller] to false
Jul 13 10:07:33 castle Controller[79818]: 10:07:33,304 |-INFO in
ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching
appender named [STDOUT] to Logger[LINSTOR/Controller]
Jul 13 10:07:33 castle Controller[79818]: 10:07:33,305 |-INFO in
ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting
level of logger [LINSTOR/Satellite] to INFO
Jul 13 10:07:33 castle Controller[79818]: 10:07:33,305 |-INFO in
ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting
additivity of logger [LINSTOR/Satellite] to false
Jul 13 10:07:33 castle Controller[79818]: 10:07:33,305 |-INFO in
ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching
appender named [STDOUT] to Logger[LINSTOR/Satellite]
Jul 13 10:07:33 castle Controller[79818]: 10:07:33,306 |-INFO in
ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting
level of logger [LINSTOR/TESTS] to OFF
Jul 13 10:07:33 castle Controller[79818]: 10:07:33,306 |-INFO in
ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting
additivity of logger [LINSTOR/TESTS] to false
Jul 13 10:07:33 castle Controller[79818]: 10:07:33,306 |-INFO in
ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching
appender named [STDOUT] to Logger[LINSTOR/TESTS]
Jul 13 10:07:33 castle Controller[79818]: 10:07:33,306 |-INFO in
ch.qos.logback.classic.model.processor.RootLoggerModelHandler - Setting
level of ROOT logger to INFO
Jul 13 10:07:33 castle Controller[79818]: 10:07:33,306 |-INFO in
ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching
appender named [STDOUT] to Logger[ROOT]
Jul 13 10:07:33 castle Controller[79818]: 10:07:33,307 |-INFO in
ch.qos.logback.core.model.processor.DefaultProcessor at 5d7148e2 - End of
configuration.
Jul 13 10:07:33 castle Controller[79818]: 10:07:33,308 |-INFO in
ch.qos.logback.classic.joran.JoranConfigurator at 25fb8912 - Registering
current configuration as safe fallback point
Jul 13 10:07:34 castle Controller[79818]: 10:07:34.169 [main] INFO
LINSTOR/Controller - SYSTEM - ErrorReporter DB version 1 found.
Jul 13 10:07:34 castle Controller[79818]: 10:07:34.173 [main] INFO
LINSTOR/Controller - SYSTEM - Log directory set to:
'/var/log/linstor-controller'
Jul 13 10:07:34 castle Controller[79818]: 10:07:34.229 [main] INFO
LINSTOR/Controller - SYSTEM - Database type is SQL
Jul 13 10:07:34 castle Controller[79818]: 10:07:34.231 [Main] INFO
LINSTOR/Controller - SYSTEM - Loading API classes started.
Jul 13 10:07:35 castle Controller[79818]: 10:07:35.478 [Main] INFO
LINSTOR/Controller - SYSTEM - API classes loading finished: 1246ms
Jul 13 10:07:35 castle Controller[79818]: 10:07:35.479 [Main] INFO
LINSTOR/Controller - SYSTEM - Dependency injection started.
Jul 13 10:07:35 castle Controller[79818]: 10:07:35.536 [Main] INFO
LINSTOR/Controller - SYSTEM - Attempting dynamic load of extension
module "com.linbit.linstor.modularcrypto.FipsCryptoModule"
Jul 13 10:07:35 castle Controller[79818]: 10:07:35.537 [Main] INFO
LINSTOR/Controller - SYSTEM - Extension module
"com.linbit.linstor.modularcrypto.FipsCryptoModule" is not installed
Jul 13 10:07:35 castle Controller[79818]: 10:07:35.537 [Main] INFO
LINSTOR/Controller - SYSTEM - Attempting dynamic load of extension
module "com.linbit.linstor.modularcrypto.JclCryptoModule"
Jul 13 10:07:35 castle Controller[79818]: 10:07:35.562 [Main] INFO
LINSTOR/Controller - SYSTEM - Dynamic load of extension module
"com.linbit.linstor.modularcrypto.JclCryptoModule" was successful
Jul 13 10:07:35 castle Controller[79818]: 10:07:35.563 [Main] INFO
LINSTOR/Controller - SYSTEM - Attempting dynamic load of extension
module "com.linbit.linstor.spacetracking.ControllerSpaceTrackingModule"
Jul 13 10:07:35 castle Controller[79818]: 10:07:35.563 [Main] INFO
LINSTOR/Controller - SYSTEM - Extension module
"com.linbit.linstor.spacetracking.ControllerSpaceTrackingModule" is not
installed
Jul 13 10:07:35 castle Controller[79818]: 10:07:35.563 [Main] INFO
LINSTOR/Controller - SYSTEM - Attempting dynamic load of extension
module "com.linbit.linstor.spacetracking.DefaultSpaceTrackingModule"
Jul 13 10:07:35 castle Controller[79818]: 10:07:35.564 [Main] INFO
LINSTOR/Controller - SYSTEM - Dynamic load of extension module
"com.linbit.linstor.spacetracking.DefaultSpaceTrackingModule" was successful
Jul 13 10:07:37 castle Controller[79818]: 10:07:37.772 [Main] INFO
LINSTOR/Controller - SYSTEM - Dependency injection finished: 2293ms
Jul 13 10:07:37 castle Controller[79818]: 10:07:37.774 [Main] INFO
LINSTOR/Controller - SYSTEM - Cryptography provider: Using default
cryptography module
Jul 13 10:07:38 castle Controller[79818]: 10:07:38.414 [Main] INFO
LINSTOR/Controller - SYSTEM - Initializing authentication subsystem
Jul 13 10:07:39 castle Controller[79818]: 10:07:39.051 [Main] INFO
LINSTOR/Controller - SYSTEM - Starting service instance
'TimerEventService' of type TimerEventService
Jul 13 10:07:39 castle Controller[79818]: 10:07:39.053 [Main] INFO
LINSTOR/Controller - SYSTEM - Initializing the database connection pool
Jul 13 10:07:39 castle Controller[79818]: 10:07:39.054 [Main] INFO
LINSTOR/Controller - SYSTEM - SQL database connection URL is
"jdbc:h2:/var/lib/linstor/linstordb"
Jul 13 10:07:39 castle Controller[79818]: 10:07:39.337 [Main] INFO
LINSTOR/Controller - SYSTEM - SQL database is H2
Jul 13 10:07:39 castle Controller[79818]: 10:07:39.512 [Main] INFO
org.flywaydb.core.internal.license.VersionPrinter - Flyway Community
Edition 7.15.0 by Redgate
Jul 13 10:07:39 castle Controller[79818]: 10:07:39.513 [Main] INFO
org.flywaydb.core.internal.database.base.BaseDatabaseType - Database:
jdbc:h2:/var/lib/linstor/linstordb (H2 1.4)
Jul 13 10:07:39 castle Controller[79818]: 10:07:39.697 [Main] INFO
org.flywaydb.core.internal.command.DbValidate - Successfully validated
78 migrations (execution time 00:00.141s)
Jul 13 10:07:39 castle Controller[79818]: 10:07:39.826 [Main] INFO
org.flywaydb.core.internal.command.DbMigrate - Current version of schema
"LINSTOR": 2024.04.19.10.00
Jul 13 10:07:39 castle Controller[79818]: 10:07:39.828 [Main] WARN
org.flywaydb.core.internal.command.DbMigrate - outOfOrder mode is
active. Migration of schema "LINSTOR" may not be reproducible.
Jul 13 10:07:39 castle Controller[79818]: 10:07:39.864 [Main] INFO
org.flywaydb.core.internal.command.DbMigrate - Schema "LINSTOR" is up to
date. No migration necessary.
Jul 13 10:07:39 castle Controller[79818]: 10:07:39.872 [Main] INFO
LINSTOR/Controller - SYSTEM - Starting service instance
'DatabaseService' of type DatabaseService
Jul 13 10:07:39 castle Controller[79818]: 10:07:39.877 [Main] INFO
LINSTOR/Controller - SYSTEM - Security objects load from database is in
progress
Jul 13 10:07:39 castle Controller[79818]: 10:07:39.952 [Main] INFO
LINSTOR/Controller - SYSTEM - Security objects load from database completed
Jul 13 10:07:39 castle Controller[79818]: 10:07:39.954 [Main] INFO
LINSTOR/Controller - SYSTEM - Core objects load from database is in progress
Jul 13 10:07:40 castle Controller[79818]: 10:07:40.597 [Main] INFO
LINSTOR/Controller - SYSTEM - Core objects load from database completed
Jul 13 10:07:40 castle Controller[79818]: 10:07:40.609 [Main] INFO
LINSTOR/Controller - SYSTEM - Starting service instance
'TaskScheduleService' of type TaskScheduleService
Jul 13 10:07:40 castle Controller[79818]: 10:07:40.615 [Main] INFO
LINSTOR/Controller - SYSTEM - Initializing network communications services
Jul 13 10:07:40 castle Controller[79818]: 10:07:40.616 [Main] WARN
LINSTOR/Controller - SYSTEM - The SSL network communication service
'DebugSslConnector' could not be started because the keyStore file
(/etc/linstor/ssl/keyst>
Jul 13 10:07:40 castle Controller[79818]: 10:07:40.629 [Main] INFO
LINSTOR/Controller - SYSTEM - Created network communication service
'PlainConnector'
Jul 13 10:07:40 castle Controller[79818]: 10:07:40.629 [Main] WARN
LINSTOR/Controller - SYSTEM - The SSL network communication service
'SslConnector' could not be started because the keyStore file
(/etc/linstor/ssl/keystore.j>
Jul 13 10:07:40 castle Controller[79818]: 10:07:40.629 [Main] INFO
LINSTOR/Controller - SYSTEM - Created network communication service
'SslConnector'
Jul 13 10:07:40 castle Controller[79818]: 10:07:40.630 [Main] INFO
LINSTOR/Controller - SYSTEM - Reconnecting to previously known nodes
Jul 13 10:07:40 castle Controller[79818]: 10:07:40.635 [Main] INFO
LINSTOR/Controller - SYSTEM - Establishing connection to node 'castle'
via /192.168.5.204:3366 ...
Jul 13 10:07:40 castle Controller[79818]: 10:07:40.662 [Main] INFO
LINSTOR/Controller - SYSTEM - Establishing connection to node 'docker1'
via /192.168.5.137:3366 ...
Jul 13 10:07:40 castle Controller[79818]: 10:07:40.664 [Main] INFO
LINSTOR/Controller - SYSTEM - Establishing connection to node 'flail'
via /192.168.5.15:3366 ...
Jul 13 10:07:40 castle Controller[79818]: 10:07:40.666 [Main] INFO
LINSTOR/Controller - SYSTEM - Establishing connection to node 'pi-01'
via /192.168.5.193:3366 ...
Jul 13 10:07:40 castle Controller[79818]: 10:07:40.668 [Main] INFO
LINSTOR/Controller - SYSTEM - Establishing connection to node 'pi-02'
via /192.168.5.127:3366 ...
Jul 13 10:07:40 castle Controller[79818]: 10:07:40.670 [Main] INFO
LINSTOR/Controller - SYSTEM - Establishing connection to node 'pi-03'
via /192.168.5.126:3366 ...
Jul 13 10:07:40 castle Controller[79818]: 10:07:40.671 [Main] INFO
LINSTOR/Controller - SYSTEM - Establishing connection to node 'pi-04'
via /192.168.5.182:3366 ...
Jul 13 10:07:40 castle Controller[79818]: 10:07:40.673 [Main] INFO
LINSTOR/Controller - SYSTEM - Establishing connection to node 'pi-05'
via /192.168.5.91:3366 ...
Jul 13 10:07:40 castle Controller[79818]: 10:07:40.675 [Main] INFO
LINSTOR/Controller - SYSTEM - Establishing connection to node 'pi-06'
via /192.168.5.93:3366 ...
Jul 13 10:07:40 castle Controller[79818]: 10:07:40.677 [Main] INFO
LINSTOR/Controller - SYSTEM - Establishing connection to node 'pi-07'
via /192.168.5.94:3366 ...
Jul 13 10:07:40 castle Controller[79818]: 10:07:40.679 [Main] INFO
LINSTOR/Controller - SYSTEM - Establishing connection to node 'pi-08'
via /192.168.5.185:3366 ...
Jul 13 10:07:40 castle Controller[79818]: 10:07:40.681 [Main] INFO
LINSTOR/Controller - SYSTEM - Establishing connection to node 'pi-09'
via /192.168.5.154:3366 ...
Jul 13 10:07:40 castle Controller[79818]: 10:07:40.683 [Main] INFO
LINSTOR/Controller - SYSTEM - Establishing connection to node 'pi-10'
via /192.168.5.87:3366 ...
Jul 13 10:07:40 castle Controller[79818]: 10:07:40.685 [Main] INFO
LINSTOR/Controller - SYSTEM - Establishing connection to node 'pi-11'
via /192.168.5.82:3366 ...
Jul 13 10:07:40 castle Controller[79818]: 10:07:40.687 [Main] INFO
LINSTOR/Controller - SYSTEM - Establishing connection to node 'pi-12'
via /192.168.5.81:3366 ...
Jul 13 10:07:40 castle Controller[79818]: 10:07:40.689 [Main] INFO
LINSTOR/Controller - SYSTEM - Establishing connection to node 'san5' via
/192.168.5.205:3366 ...
Jul 13 10:07:40 castle Controller[79818]: 10:07:40.692 [Main] INFO
LINSTOR/Controller - SYSTEM - Establishing connection to node 'san6' via
/192.168.5.206:3366 ...
Jul 13 10:07:40 castle Controller[79818]: 10:07:40.694 [Main] INFO
LINSTOR/Controller - SYSTEM - Establishing connection to node 'san7' via
/192.168.5.207:3366 ...
Jul 13 10:07:40 castle Controller[79818]: 10:07:40.697 [Main] INFO
LINSTOR/Controller - SYSTEM - Establishing connection to node 'xen1' via
/192.168.5.21:3366 ...
Jul 13 10:07:40 castle Controller[79818]: 10:07:40.703 [Main] INFO
LINSTOR/Controller - SYSTEM - Reconnect requests sent
Jul 13 10:07:40 castle Controller[79818]: 10:07:40.706 [Main] INFO
LINSTOR/Controller - SYSTEM - Starting service instance
'ScheduleBackupService' of type ScheduleBackupService
Jul 13 10:07:40 castle Controller[79818]: 10:07:40.708 [Main] INFO
LINSTOR/Controller - SYSTEM - Starting service instance 'EbsStatusPoll'
of type EbsStatusPoll
Jul 13 10:07:41 castle Controller[79818]: July 13, 2024 10:07:41 AM
org.glassfish.jersey.server.wadl.WadlFeature configure
Jul 13 10:07:41 castle Controller[79818]: WARNING: JAX-B API not found .
WADL feature is disabled.
Jul 13 10:07:42 castle Controller[79818]: July 13, 2024 10:07:42 AM
org.glassfish.grizzly.http.server.NetworkListener start
Jul 13 10:07:42 castle Controller[79818]: INFO: Started listener bound
to [[::]:3370]
Jul 13 10:07:42 castle Controller[79818]: July 13, 2024 10:07:42 AM
org.glassfish.grizzly.http.server.HttpServer start
Jul 13 10:07:42 castle Controller[79818]: INFO: [HttpServer] Started.
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.588 [Main] INFO
LINSTOR/Controller - SYSTEM - Controller initialized
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.593 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'castle'
Jul 13 10:07:42 castle systemd[1]: Started linstor-controller.service -
LINSTOR Controller Service.
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.674
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - Establishing
connection to node 'xen1' via /192.168.5.21:3366 ...
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.679
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - Establishing
connection to node 'pi-08' via /192.168.5.185:3366 ...
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.688
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - Establishing
connection to node 'pi-10' via /192.168.5.87:3366 ...
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.694
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - Establishing
connection to node 'san5' via /192.168.5.205:3366 ...
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.703
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - Establishing
connection to node 'pi-06' via /192.168.5.93:3366 ...
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.705 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'pi-06'
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.708
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - Establishing
connection to node 'docker1' via /192.168.5.137:3366 ...
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.714
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - Establishing
connection to node 'pi-01' via /192.168.5.193:3366 ...
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.722
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - Establishing
connection to node 'pi-12' via /192.168.5.81:3366 ...
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.730
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - Establishing
connection to node 'flail' via /192.168.5.15:3366 ...
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.733 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'san6'
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.737
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - Establishing
connection to node 'pi-04' via /192.168.5.182:3366 ...
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.741
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - Establishing
connection to node 'pi-05' via /192.168.5.91:3366 ...
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.743 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'pi-11'
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.747
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - Establishing
connection to node 'san7' via /192.168.5.207:3366 ...
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.748 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'san5'
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.754
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - Establishing
connection to node 'pi-09' via /192.168.5.154:3366 ...
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.761
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - Establishing
connection to node 'pi-02' via /192.168.5.127:3366 ...
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.766
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - Establishing
connection to node 'pi-07' via /192.168.5.94:3366 ...
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.769
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - LogArchive:
Running log archive on directory: /var/log/linstor-controller
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.774
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - LogArchive: No
logs to archive.
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.776
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM -
BalanceResourcesTask/START
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.779 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'pi-10'
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.795 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'pi-08'
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.800
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM -
BalanceResourcesTask/END: Adjusted: 0 - Removed: 0
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.824 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'xen1'
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.841 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'pi-12'
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.843 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'pi-05'
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.845 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'pi-04'
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.847 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'san7'
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.851 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'pi-06'
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.853 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'pi-02'
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.868 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'flail'
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.870 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'pi-01'
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.873 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'pi-09'
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.877 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'docker1'
Jul 13 10:07:42 castle Controller[79818]: 10:07:42.895 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'pi-07'
Jul 13 10:07:43 castle Controller[79818]: 10:07:43.043
[MainWorkerPool-1] INFO LINSTOR/Controller - SYSTEM - Changing
connection state of node 'san6' from OFFLINE -> VERSION_MISMATCH
Jul 13 10:07:43 castle Controller[79818]: 10:07:43.043
[MainWorkerPool-1] ERROR LINSTOR/Controller - SYSTEM - Satellite 'san6'
version mismatch(v1.19.1).
Jul 13 10:07:43 castle Controller[79818]: 10:07:43.049
[MainWorkerPool-1] INFO LINSTOR/Controller - SYSTEM - Changing
connection state of node 'flail' from OFFLINE -> VERSION_MISMATCH
Jul 13 10:07:43 castle Controller[79818]: 10:07:43.049
[MainWorkerPool-1] ERROR LINSTOR/Controller - SYSTEM - Satellite 'flail'
version mismatch(v1.19.1).
Jul 13 10:07:43 castle Controller[79818]: 10:07:43.060
[MainWorkerPool-2] INFO LINSTOR/Controller - SYSTEM - Changing
connection state of node 'pi-11' from OFFLINE -> VERSION_MISMATCH
Jul 13 10:07:43 castle Controller[79818]: 10:07:43.061
[MainWorkerPool-2] ERROR LINSTOR/Controller - SYSTEM - Satellite 'pi-11'
version mismatch(v1.19.1).
Jul 13 10:07:43 castle Controller[79818]: 10:07:43.066
[MainWorkerPool-1] INFO LINSTOR/Controller - SYSTEM - Changing
connection state of node 'pi-10' from OFFLINE -> VERSION_MISMATCH
Jul 13 10:07:43 castle Controller[79818]: 10:07:43.066
[MainWorkerPool-1] ERROR LINSTOR/Controller - SYSTEM - Satellite 'pi-10'
version mismatch(v1.19.1).
Jul 13 10:07:43 castle Controller[79818]: 10:07:43.084
[MainWorkerPool-2] INFO LINSTOR/Controller - SYSTEM - Changing
connection state of node 'pi-08' from OFFLINE -> VERSION_MISMATCH
Jul 13 10:07:43 castle Controller[79818]: 10:07:43.085
[MainWorkerPool-2] ERROR LINSTOR/Controller - SYSTEM - Satellite 'pi-08'
version mismatch(v1.19.1).
Jul 13 10:07:43 castle Controller[79818]: 10:07:43.094
[MainWorkerPool-1] INFO LINSTOR/Controller - SYSTEM - Changing
connection state of node 'pi-07' from OFFLINE -> VERSION_MISMATCH
Jul 13 10:07:43 castle Controller[79818]: 10:07:43.095
[MainWorkerPool-1] ERROR LINSTOR/Controller - SYSTEM - Satellite 'pi-07'
version mismatch(v1.19.1).
Jul 13 10:07:43 castle Controller[79818]: 10:07:43.098
[MainWorkerPool-2] INFO LINSTOR/Controller - SYSTEM - Changing
connection state of node 'pi-06' from OFFLINE -> VERSION_MISMATCH
Jul 13 10:07:43 castle Controller[79818]: 10:07:43.099
[MainWorkerPool-2] ERROR LINSTOR/Controller - SYSTEM - Satellite 'pi-06'
version mismatch(v1.19.1).
Jul 13 10:07:43 castle Controller[79818]: 10:07:43.108
[MainWorkerPool-2] INFO LINSTOR/Controller - SYSTEM - Changing
connection state of node 'pi-12' from OFFLINE -> VERSION_MISMATCH
Jul 13 10:07:43 castle Controller[79818]: 10:07:43.109
[MainWorkerPool-2] ERROR LINSTOR/Controller - SYSTEM - Satellite 'pi-12'
version mismatch(v1.19.1).
Jul 13 10:07:43 castle Controller[79818]: 10:07:43.114
[MainWorkerPool-1] INFO LINSTOR/Controller - SYSTEM - Changing
connection state of node 'pi-05' from OFFLINE -> VERSION_MISMATCH
Jul 13 10:07:43 castle Controller[79818]: 10:07:43.114
[MainWorkerPool-1] ERROR LINSTOR/Controller - SYSTEM - Satellite 'pi-05'
version mismatch(v1.19.1).
Jul 13 10:07:43 castle Controller[79818]: 10:07:43.127
[MainWorkerPool-1] INFO LINSTOR/Controller - SYSTEM - Changing
connection state of node 'pi-09' from OFFLINE -> VERSION_MISMATCH
Jul 13 10:07:43 castle Controller[79818]: 10:07:43.128
[MainWorkerPool-1] ERROR LINSTOR/Controller - SYSTEM - Satellite 'pi-09'
version mismatch(v1.19.1).
Jul 13 10:07:43 castle Controller[79818]: 10:07:43.136
[MainWorkerPool-2] INFO LINSTOR/Controller - SYSTEM - Changing
connection state of node 'pi-01' from OFFLINE -> VERSION_MISMATCH
Jul 13 10:07:43 castle Controller[79818]: 10:07:43.137
[MainWorkerPool-2] ERROR LINSTOR/Controller - SYSTEM - Satellite 'pi-01'
version mismatch(v1.19.1).
Jul 13 10:07:43 castle Controller[79818]: 10:07:43.144
[MainWorkerPool-1] INFO LINSTOR/Controller - SYSTEM - Changing
connection state of node 'pi-02' from OFFLINE -> VERSION_MISMATCH
Jul 13 10:07:43 castle Controller[79818]: 10:07:43.145
[MainWorkerPool-1] ERROR LINSTOR/Controller - SYSTEM - Satellite 'pi-02'
version mismatch(v1.19.1).
Jul 13 10:07:43 castle Controller[79818]: 10:07:43.152
[MainWorkerPool-1] INFO LINSTOR/Controller - SYSTEM - Changing
connection state of node 'xen1' from OFFLINE -> VERSION_MISMATCH
Jul 13 10:07:43 castle Controller[79818]: 10:07:43.153
[MainWorkerPool-1] ERROR LINSTOR/Controller - SYSTEM - Satellite 'xen1'
version mismatch(v1.19.1).
Jul 13 10:07:43 castle Controller[79818]: 10:07:43.241
[MainWorkerPool-2] INFO LINSTOR/Controller - SYSTEM - Changing
connection state of node 'pi-04' from OFFLINE -> VERSION_MISMATCH
Jul 13 10:07:43 castle Controller[79818]: 10:07:43.242
[MainWorkerPool-2] ERROR LINSTOR/Controller - SYSTEM - Satellite 'pi-04'
version mismatch(v1.19.1).
Jul 13 10:07:43 castle Controller[79818]: 10:07:43.491
[MainWorkerPool-1] INFO LINSTOR/Controller - SYSTEM - Changing
connection state of node 'san7' from OFFLINE -> CONNECTED
Jul 13 10:07:43 castle Controller[79818]: 10:07:43.494
[MainWorkerPool-1] INFO LINSTOR/Controller - SYSTEM - Satellite 'san7'
authenticated
Jul 13 10:07:43 castle Controller[79818]: 10:07:43.512
[MainWorkerPool-1] INFO LINSTOR/Controller - SYSTEM - Sending full sync
to Node: 'san7'.
Jul 13 10:07:44 castle Controller[79818]: 10:07:44.020
[MainWorkerPool-2] INFO LINSTOR/Controller - SYSTEM - Changing
connection state of node 'san5' from OFFLINE -> CONNECTED
Jul 13 10:07:44 castle Controller[79818]: 10:07:44.021
[MainWorkerPool-2] INFO LINSTOR/Controller - SYSTEM - Satellite 'san5'
authenticated
Jul 13 10:07:44 castle Controller[79818]: 10:07:44.022
[MainWorkerPool-2] INFO LINSTOR/Controller - SYSTEM - Sending full sync
to Node: 'san5'.
Jul 13 10:07:44 castle Controller[79818]: 10:07:44.059
[MainWorkerPool-2] INFO LINSTOR/Controller - SYSTEM - Changing
connection state of node 'docker1' from OFFLINE -> VERSION_MISMATCH
Jul 13 10:07:44 castle Controller[79818]: 10:07:44.059
[MainWorkerPool-2] ERROR LINSTOR/Controller - SYSTEM - Satellite
'docker1' version mismatch(v1.19.1).
Jul 13 10:07:44 castle Controller[79818]: 10:07:44.069
[MainWorkerPool-1] INFO LINSTOR/Controller - SYSTEM - Changing
connection state of node 'castle' from OFFLINE -> CONNECTED
Jul 13 10:07:44 castle Controller[79818]: 10:07:44.071
[MainWorkerPool-1] INFO LINSTOR/Controller - SYSTEM - Satellite
'castle' authenticated
Jul 13 10:07:44 castle Controller[79818]: 10:07:44.071
[MainWorkerPool-1] INFO LINSTOR/Controller - SYSTEM - Sending full sync
to Node: 'castle'.
Jul 13 10:07:46 castle Controller[79818]: 10:07:46.828
[MainWorkerPool-2] INFO LINSTOR/Controller - SYSTEM - Changing
connection state of node 'san7' from CONNECTED -> ONLINE
Jul 13 10:07:47 castle Controller[79818]: 10:07:47.169
[MainWorkerPool-1] INFO LINSTOR/Controller - SYSTEM - Changing
connection state of node 'san5' from CONNECTED -> ONLINE
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.633
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - Establishing
connection to node 'pi-01' via /192.168.5.193:3366 ...
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.636
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - Establishing
connection to node 'pi-05' via /192.168.5.91:3366 ...
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.638 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'pi-01'
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.644
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - Establishing
connection to node 'flail' via /192.168.5.15:3366 ...
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.645 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'pi-05'
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.649
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - Establishing
connection to node 'pi-02' via /192.168.5.127:3366 ...
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.650 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'flail'
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.654
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - Establishing
connection to node 'pi-08' via /192.168.5.185:3366 ...
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.655 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'pi-02'
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.658
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - Establishing
connection to node 'xen1' via /192.168.5.21:3366 ...
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.664 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'pi-08'
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.667
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - Establishing
connection to node 'san6' via /192.168.5.206:3366 ...
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.669 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'xen1'
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.673
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - Establishing
connection to node 'pi-07' via /192.168.5.94:3366 ...
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.674 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'san6'
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.677
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - Establishing
connection to node 'pi-12' via /192.168.5.81:3366 ...
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.678 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'pi-07'
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.683
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - Establishing
connection to node 'docker1' via /192.168.5.137:3366 ...
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.684 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'pi-12'
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.687
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - Establishing
connection to node 'pi-06' via /192.168.5.93:3366 ...
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.688 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'docker1'
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.690
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - Establishing
connection to node 'pi-11' via /192.168.5.82:3366 ...
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.692 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'pi-06'
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.695
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - Establishing
connection to node 'pi-04' via /192.168.5.182:3366 ...
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.697 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'pi-11'
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.705
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - Establishing
connection to node 'pi-10' via /192.168.5.87:3366 ...
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.712 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'pi-04'
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.720
[TaskScheduleService] INFO LINSTOR/Controller - SYSTEM - Establishing
connection to node 'pi-09' via /192.168.5.154:3366 ...
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.723 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'pi-10'
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.724
[MainWorkerPool-1] INFO LINSTOR/Controller - SYSTEM - Changing
connection state of node 'san6' from OFFLINE -> VERSION_MISMATCH
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.724
[MainWorkerPool-1] ERROR LINSTOR/Controller - SYSTEM - Satellite 'san6'
version mismatch(v1.19.1).
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.733
[MainWorkerPool-2] INFO LINSTOR/Controller - SYSTEM - Changing
connection state of node 'xen1' from OFFLINE -> VERSION_MISMATCH
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.733
[MainWorkerPool-2] ERROR LINSTOR/Controller - SYSTEM - Satellite 'xen1'
version mismatch(v1.19.1).
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.737 [SslConnector]
INFO LINSTOR/Controller - SYSTEM - Sending authentication to satellite
'pi-09'
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.744
[MainWorkerPool-1] INFO LINSTOR/Controller - SYSTEM - Changing
connection state of node 'castle' from CONNECTED -> ONLINE
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.749
[MainWorkerPool-2] INFO LINSTOR/Controller - SYSTEM - Changing
connection state of node 'flail' from OFFLINE -> VERSION_MISMATCH
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.749
[MainWorkerPool-2] ERROR LINSTOR/Controller - SYSTEM - Satellite 'flail'
version mismatch(v1.19.1).
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.815
[MainWorkerPool-2] INFO LINSTOR/Controller - SYSTEM - Changing
connection state of node 'pi-01' from OFFLINE -> VERSION_MISMATCH
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.816
[MainWorkerPool-2] ERROR LINSTOR/Controller - SYSTEM - Satellite 'pi-01'
version mismatch(v1.19.1).
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.820
[MainWorkerPool-2] INFO LINSTOR/Controller - SYSTEM - Changing
connection state of node 'pi-05' from OFFLINE -> VERSION_MISMATCH
Jul 13 10:07:50 castle Controller[79818]: 10:07:50.820
[MainWorkerPool-2] ERROR LINSTOR/Controller - SYSTEM - Satellite 'pi-05'
version mismatch(v1.19.1).
Jul 13 10:07:51 castle Controller[79818]: 10:07:51.097
[grizzly-http-server-0] INFO LINSTOR/Controller - SYSTEM - REST/API
RestClient(192.168.5.93; 'linstor-csi/v0.20.0-1-g4ee8dce')/LstRscDfn
Jul 13 10:07:51 castle Controller[79818]: 10:07:51.233
[grizzly-http-server-1] INFO LINSTOR/Controller - SYSTEM - REST/API
RestClient(192.168.5.93; 'linstor-csi/v0.20.0-1-g4ee8dce')/LstRsc
Jul 13 10:08:10 castle Controller[79818]: 10:08:10.695
[grizzly-http-server-2] INFO LINSTOR/Controller - SYSTEM - REST/API
RestClient(192.168.5.193; 'linstor-csi/v0.20.0-1-g4ee8dce')/LstRscDfn
Jul 13 10:08:10 castle Controller[79818]: 10:08:10.730
[grizzly-http-server-3] INFO LINSTOR/Controller - SYSTEM - REST/API
RestClient(192.168.5.193; 'linstor-csi/v0.20.0-1-g4ee8dce')/LstRscDfn
Jul 13 10:08:34 castle Controller[79818]: 10:08:34.179
[grizzly-http-server-3] INFO LINSTOR/Controller - SYSTEM - REST/API
RestClient(192.168.5.204; 'PythonLinstor/1.23.0 (API1.0.4): Client
1.23.0')/LstNode
Jul 13 10:08:35 castle Controller[79818]: 10:08:35.896
[grizzly-http-server-0] INFO LINSTOR/Controller - SYSTEM - REST/API
RestClient(192.168.5.205; 'PythonLinstor/1.23.0 (API1.0.4): Client
1.23.0')/LstVlm
Jul 13 10:09:12 castle Controller[79818]: 10:09:12.577
[grizzly-http-server-2] INFO LINSTOR/Controller - SYSTEM - REST/API
RestClient(192.168.5.193; 'linstor-csi/v0.20.0-1-g4ee8dce')/LstRscDfn
Jul 13 10:09:12 castle Controller[79818]: 10:09:12.610
[grizzly-http-server-2] INFO LINSTOR/Controller - SYSTEM - REST/API
RestClient(192.168.5.193; 'linstor-csi/v0.20.0-1-g4ee8dce')/LstRscDfn
Jul 13 10:09:23 castle Controller[79818]: 10:09:23.345
[grizzly-http-server-2] INFO LINSTOR/Controller - SYSTEM - REST/API
RestClient(192.168.5.94; 'linstor-csi/v0.20.0-1-g4ee8dce')/LstVlm
Nothing after this, though current time is now 11:03, so stuck for
almost an hour.
PS, node pi-03 is expected to be offline/down, long story, but
effectively, that node doesn't exist, pending hardware replacement.
More information about the drbd-user
mailing list