Hello,
I encountered an issue similar to https://www.tango-controls.org/community/forum/c/general/development/astor-heartbeat-error/

On a server running 2 devices, the Starter service is launched by tango-starter.
When I launch it through service command, device do not start, and neither can I start them through Astor.

If I launched it manually through my account, it works:

$ /usr/lib/tango/Starter srv-6 -ORBendPoint giop:tcp:192.168.229.105:20001 -ORBendPointPublish giop:tcp:192.168.229.105:20001
Starter::Starter() init device tango/admin/srv-6
UseEvents = False
interStartupLevelWait = 1
serverStartupTimeout = 1
fireFromDbase = 1
logFileHome = /var/tmp
StartServersAtStartup = 1
AutoRestartDuration = 0
—-> starter_log_file = /var/tmp/ds.log/Starter.log
—-> starter_stat_file = /var/tmp/ds.log/Starter.stat
Starter::dev_start_all(): entering for level 1… !
Starter::dev_start_all(): entering for level 2… !
Starter::dev_start_all(): entering for level 3… !
Starter::dev_start_all(): entering for level 4… !
Starter::dev_start_all(): entering for level 5… !
Check startup for HdbArchiver/01
Try to start /opt/ArchivingRoot/device/linux//HdbArchiver
Check startup for TdbArchiver/01
Try to start /opt/ArchivingRoot/device/linux//TdbArchiver
Ready to accept request


If I launched it with tango account, it works also:

$ sudo -E -u tango /usr/lib/tango/Starter srv-6 -ORBendPoint giop:tcp:192.168.229.105:20001 -ORBendPointPublish giop:tcp:192.168.229.105:20001
Starter::Starter() init device tango/admin/srv-6
UseEvents = False
interStartupLevelWait = 1
serverStartupTimeout = 1
fireFromDbase = 1
logFileHome = /var/tmp
StartServersAtStartup = 1
AutoRestartDuration = 0
—-> starter_log_file = /var/tmp/ds.log/Starter.log
—-> starter_stat_file = /var/tmp/ds.log/Starter.stat
Starter::dev_start_all(): entering for level 1… !
Starter::dev_start_all(): entering for level 2… !
Starter::dev_start_all(): entering for level 3… !
Starter::dev_start_all(): entering for level 4… !
Starter::dev_start_all(): entering for level 5… !
Check startup for HdbArchiver/01
Already running….
Check startup for TdbArchiver/01
Already running….
Ready to accept request

When I launch HdbArchiver manually, I got this output:


$ sudo -E -u tango /opt/ArchivingRoot/device/linux/HdbArchiver 01
ERROR 2021-10-28 19:24:33,121 - main | o.t.c.d.cache.ServerCache.loadCache:56 - Failed to load cache for server HdbArchiver/01 on host srv-6
ERROR 2021-10-28 19:24:33,140 - main | o.t.c.d.cache.ServerCache.logDevFailed:126 - Error Level 0 :
ERROR 2021-10-28 19:24:33,141 - main | o.t.c.d.cache.ServerCache.logDevFailed:127 - - desc: The stored procedure failed with a MySQL error!!!
ERROR 2021-10-28 19:24:33,141 - main | o.t.c.d.cache.ServerCache.logDevFailed:128 - - origin: DataBase::DbGetDataForServerCache()
ERROR 2021-10-28 19:24:33,141 - main | o.t.c.d.cache.ServerCache.logDevFailed:129 - - reason: DB_StoredProcedureFailed
ERROR 2021-10-28 19:24:33,142 - main | o.t.c.d.cache.ServerCache.logDevFailed:138 - - severity: ERROR
ERROR 2021-10-28 19:24:33,142 - main | o.t.c.d.cache.ServerCache.logDevFailed:126 - Error Level 1 :
ERROR 2021-10-28 19:24:33,142 - main | o.t.c.d.cache.ServerCache.logDevFailed:127 - - desc: Cannot execute command DbGetDataForServerCache on sys/database/2
ERROR 2021-10-28 19:24:33,142 - main | o.t.c.d.cache.ServerCache.logDevFailed:128 - - origin: Connection.command_inout()
ERROR 2021-10-28 19:24:33,142 - main | o.t.c.d.cache.ServerCache.logDevFailed:129 - - reason: TangoApi_CANNOT_EXECUTE_COMMAND
ERROR 2021-10-28 19:24:33,143 - main | o.t.c.d.cache.ServerCache.logDevFailed:138 - - severity: PANIC
INFO 2021-10-28 19:24:33,350 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.init:187 - init in
INFO 2021-10-28 19:24:33,351 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.init:195 - isforceUseEvents= false, isDedicated = false
INFO 2021-10-28 19:24:33,351 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.init:196 - reservedAttributes = [, ]
create file /var/archivage/hdb/01/hdbarchiver.01.log
ERROR 2021-10-28 19:24:33,354 - main | o.t.s.events.EventManager.initializeClientHwm:175 - CtrlSystem/EventBufferHwm property is not a number:
set logging level archiving/hdb/hdbarchiver.01-INFO
INFO 2021-10-28 19:24:33,359 - archiving/hdb/hdbarchiver.01 Init | f.s.a.c.a.ConnectionFactory.connect:54 - getting connector for db jdbc:mysql://srv-6/hdb with user hdbarchiver
INFO 2021-10-28 19:24:33,369 - main | o.t.server.ServerManager.init:252 - TANGO server HdbArchiver/01 started
INFO 2021-10-28 19:24:33,400 - archiving/hdb/hdbarchiver.01 Init | f.s.a.c.a.ConnectionFactory.connect:73 - got connector to db jdbc:mysql://srv-6/hdb
INFO 2021-10-28 19:24:33,705 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:316 - start archiving of [RI-C2/VA/PEG.03/pressure, RI-C1/VA/PEG.03/pressure, OC/VA/PEG.01/pressure, LI/VA/PEG.04/pressure, TL/VA/PEG.02/pressure, RI-C1/VA/PEG.06/pressure, LI/VA/PEG.01/pressure, OC/VA/PEG.03/pressure, TL/VA/PEG.01/pressure, EL/VA/PEG.01/pressure, RI-C2/VA/PEG.04/pressure, RI-C1/VA/PEG.04/pressure, RI-C2/VA/PEG.01/pressure, RI-C1/VA/PEG.01/pressure, XLI/VA/PIG.01/Pressure, LI/VA/PEG.03/pressure, TL/VA/PEG.00/pressure, RI-C1/VA/PEG.07/pressure, RI-C2/VA/PEG.02/pressure, XLI/VA/PIG.03/Pressure, LI/VA/PEG.05/pressure, LI/VA/PEG.02/pressure, RI-C1/VA/PEG.05/pressure, RI-C1/VA/PEG.02/pressure, XLI/VA/PIG.02/Pressure, OC/VA/PEG.02/pressure]
INFO 2021-10-28 19:24:33,795 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:385 - start RI-C2/VA/PEG.03/pressure OK
INFO 2021-10-28 19:24:33,827 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:385 - start RI-C1/VA/PEG.03/pressure OK
INFO 2021-10-28 19:24:33,837 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:385 - start OC/VA/PEG.01/pressure OK
INFO 2021-10-28 19:24:33,859 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:385 - start LI/VA/PEG.04/pressure OK
INFO 2021-10-28 19:24:33,871 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:385 - start TL/VA/PEG.02/pressure OK
INFO 2021-10-28 19:24:33,879 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:385 - start RI-C1/VA/PEG.06/pressure OK
INFO 2021-10-28 19:24:33,887 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:385 - start LI/VA/PEG.01/pressure OK
INFO 2021-10-28 19:24:33,907 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:385 - start OC/VA/PEG.03/pressure OK
INFO 2021-10-28 19:24:33,923 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:385 - start TL/VA/PEG.01/pressure OK
INFO 2021-10-28 19:24:33,939 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:385 - start EL/VA/PEG.01/pressure OK
INFO 2021-10-28 19:24:33,946 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:385 - start RI-C2/VA/PEG.04/pressure OK
INFO 2021-10-28 19:24:33,967 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:385 - start RI-C1/VA/PEG.04/pressure OK
INFO 2021-10-28 19:24:33,983 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:385 - start RI-C2/VA/PEG.01/pressure OK
INFO 2021-10-28 19:24:33,999 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:385 - start RI-C1/VA/PEG.01/pressure OK
INFO 2021-10-28 19:24:34,041 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:385 - start XLI/VA/PIG.01/Pressure OK
INFO 2021-10-28 19:24:34,065 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:385 - start LI/VA/PEG.03/pressure OK
INFO 2021-10-28 19:24:34,083 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:385 - start TL/VA/PEG.00/pressure OK
INFO 2021-10-28 19:24:34,091 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:385 - start RI-C1/VA/PEG.07/pressure OK
INFO 2021-10-28 19:24:34,119 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:385 - start RI-C2/VA/PEG.02/pressure OK
INFO 2021-10-28 19:24:34,159 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:385 - start XLI/VA/PIG.03/Pressure OK
INFO 2021-10-28 19:24:34,167 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:385 - start LI/VA/PEG.05/pressure OK
INFO 2021-10-28 19:24:34,187 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:385 - start LI/VA/PEG.02/pressure OK
INFO 2021-10-28 19:24:34,201 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:385 - start RI-C1/VA/PEG.05/pressure OK
INFO 2021-10-28 19:24:34,219 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:385 - start RI-C1/VA/PEG.02/pressure OK
INFO 2021-10-28 19:24:34,251 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:385 - start XLI/VA/PIG.02/Pressure OK
INFO 2021-10-28 19:24:34,259 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:385 - start OC/VA/PEG.02/pressure OK
INFO 2021-10-28 19:24:34,260 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:414 - start archiving done with 0 KO and 26 OK
INFO 2021-10-28 19:24:34,260 - archiving/hdb/hdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.init:210 - init device OK


and


$ sudo -E -u tango /opt/ArchivingRoot/device/linux/TdbArchiver 01
ERROR 2021-10-28 19:31:15,303 - main | o.t.c.d.cache.ServerCache.loadCache:56 - Failed to load cache for server TdbArchiver/01 on host srv-6
ERROR 2021-10-28 19:31:15,323 - main | o.t.c.d.cache.ServerCache.logDevFailed:126 - Error Level 0 :
ERROR 2021-10-28 19:31:15,324 - main | o.t.c.d.cache.ServerCache.logDevFailed:127 - - desc: The stored procedure failed with a MySQL error!!!
ERROR 2021-10-28 19:31:15,324 - main | o.t.c.d.cache.ServerCache.logDevFailed:128 - - origin: DataBase::DbGetDataForServerCache()
ERROR 2021-10-28 19:31:15,324 - main | o.t.c.d.cache.ServerCache.logDevFailed:129 - - reason: DB_StoredProcedureFailed
ERROR 2021-10-28 19:31:15,324 - main | o.t.c.d.cache.ServerCache.logDevFailed:138 - - severity: ERROR
ERROR 2021-10-28 19:31:15,324 - main | o.t.c.d.cache.ServerCache.logDevFailed:126 - Error Level 1 :
ERROR 2021-10-28 19:31:15,325 - main | o.t.c.d.cache.ServerCache.logDevFailed:127 - - desc: Cannot execute command DbGetDataForServerCache on sys/database/2
ERROR 2021-10-28 19:31:15,325 - main | o.t.c.d.cache.ServerCache.logDevFailed:128 - - origin: Connection.command_inout()
ERROR 2021-10-28 19:31:15,325 - main | o.t.c.d.cache.ServerCache.logDevFailed:129 - - reason: TangoApi_CANNOT_EXECUTE_COMMAND
ERROR 2021-10-28 19:31:15,325 - main | o.t.c.d.cache.ServerCache.logDevFailed:138 - - severity: PANIC
INFO 2021-10-28 19:31:15,538 - archiving/tdb/tdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.init:187 - init in
INFO 2021-10-28 19:31:15,539 - archiving/tdb/tdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.init:195 - isforceUseEvents= false, isDedicated = false
INFO 2021-10-28 19:31:15,540 - archiving/tdb/tdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.init:196 - reservedAttributes = [, ]
create file /var/archivage/tdb/01/tdbarchiver.01.log
ERROR 2021-10-28 19:31:15,542 - main | o.t.s.events.EventManager.initializeClientHwm:175 - CtrlSystem/EventBufferHwm property is not a number:
set logging level archiving/tdb/tdbarchiver.01-DEBUG
INFO 2021-10-28 19:31:15,547 - archiving/tdb/tdbarchiver.01 Init | f.s.a.c.a.ConnectionFactory.connect:54 - getting connector for db jdbc:mysql://srv-6/tdb with user tdbarchiver
INFO 2021-10-28 19:31:15,556 - main | o.t.server.ServerManager.init:252 - TANGO server TdbArchiver/01 started
INFO 2021-10-28 19:31:15,587 - archiving/tdb/tdbarchiver.01 Init | f.s.a.c.a.ConnectionFactory.connect:73 - got connector to db jdbc:mysql://srv-6/tdb
INFO 2021-10-28 19:31:15,874 - archiving/tdb/tdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:316 - start archiving of [XLI/OP/TMD.01/I1, XLI/OP/TMD.01/I4, XLI/OP/TMD.01/I3, XLI/OP/TMD.01/I2]
INFO 2021-10-28 19:31:15,890 - archiving/tdb/tdbarchiver.01 Init | o.t.c.i.ArchivingTemporaryFile.openFile:286 - open file /var/archivage/tdb/01/att_00005-20211028-193115.dat
INFO 2021-10-28 19:31:15,973 - archiving/tdb/tdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:385 - start XLI/OP/TMD.01/I1 OK
INFO 2021-10-28 19:31:15,974 - archiving/tdb/tdbarchiver.01 Init | o.t.c.i.ArchivingTemporaryFile.openFile:286 - open file /var/archivage/tdb/01/att_00006-20211028-193115.dat
INFO 2021-10-28 19:31:15,990 - archiving/tdb/tdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:385 - start XLI/OP/TMD.01/I4 OK
INFO 2021-10-28 19:31:15,992 - archiving/tdb/tdbarchiver.01 Init | o.t.c.i.ArchivingTemporaryFile.openFile:286 - open file /var/archivage/tdb/01/att_00007-20211028-193115.dat
INFO 2021-10-28 19:31:15,994 - archiving/tdb/tdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:385 - start XLI/OP/TMD.01/I3 OK
INFO 2021-10-28 19:31:15,996 - archiving/tdb/tdbarchiver.01 Init | o.t.c.i.ArchivingTemporaryFile.openFile:286 - open file /var/archivage/tdb/01/att_00008-20211028-193115.dat
INFO 2021-10-28 19:31:15,998 - archiving/tdb/tdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:385 - start XLI/OP/TMD.01/I2 OK
INFO 2021-10-28 19:31:15,999 - archiving/tdb/tdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.triggerArchiving:414 - start archiving done with 0 KO and 4 OK
INFO 2021-10-28 19:31:15,999 - archiving/tdb/tdbarchiver.01 Init | o.t.a.s.a.HdbArchiver.init:210 - init device OK


I do not understand the errors displayed:
  • concerning SQL procedure, I failed to locate it and understand what it does
  • CtrlSystem/EventBufferHwm is not defined, so default value should be 1000 according to the doc

Note: srv-6 has 2 IP, 1 public and 1 private. This is why I use "ORBendPointPublish" as suggested by Reynald here.

Do you have any idea how to solve this?

Regards.
- Philippe
Edited 3 years ago