Sep 14 12:56:32:553 [140032843372288] 0 Controller: Selecting robotip from configuration. config_robotip = 192.168.3.20, cglob robotip = 192.168.3.20, local_ip_validation = 1, validate_ip_suggestion = 0, strict_ip_binding = 0 Sep 14 12:56:32:553 [140032843372288] 0 Controller: -------------------------------------------------------------------------------------------------------- Sep 14 12:56:32:553 [140032843372288] 0 Controller: ----- Robot controller 9.35 [Build 9.35.240, May 10 2022] started ----- Sep 14 12:56:32:553 [140032843372288] 0 Controller: Name = gokususe, IP = 192.168.3.20, Port = 48000 Sep 14 12:56:32:553 [140032843372288] 0 Controller: OS = UNIX / Linux / Linux 4.12.14-122.37-default #1 SMP Sun Sep 6 05:00:36 UTC 2020 (fe8cacf) x86_64 Sep 14 12:56:32:553 [140032843372288] 0 Controller: Domain = hubp_domain Sep 14 12:56:32:553 [140032843372288] 0 Controller: Primary HUB = /hubp_domain/hubs/hubs 192.168.3.75 Sep 14 12:56:32:553 [140032843372288] 0 Controller: Loglevel = 0, Logfile = controller.log Sep 14 12:56:32:554 [140032843372288] 0 Controller: Running as user root (0) Sep 14 12:56:32:554 [140032843372288] 0 Controller: ----- Sep 14 12:56:32:555 [140032843372288] 0 Controller: Controller on gokususe port 48000 started Sep 14 12:56:33:655 [140032843372288] 0 Controller: Hub hubs(192.168.3.75) contact established Sep 14 12:56:33:658 [140032843372288] 0 Controller: primary hub changed name to hubp_domain/hubs/hubs Sep 14 12:56:33:658 [140032843372288] 0 Controller: temp hub changed name to hubp_domain/hubs/hubs Sep 14 12:56:33:658 [140032843372288] 0 Controller: _ProcStart - Probe 'spooler' - starting Sep 14 12:56:34:710 [140032843372288] 0 Controller: _ProcStart - Probe 'hdb' - starting Sep 14 12:58:16:239 [140032843372288] 0 Controller: Going down... Sep 14 12:58:24:329 [140032843372288] 0 Controller: Down Sep 14 12:58:58:936 [140524608743168] 0 Controller: Selecting robotip from configuration. config_robotip = 192.168.3.20, cglob robotip = 192.168.3.20, local_ip_validation = 1, validate_ip_suggestion = 0, strict_ip_binding = 0 Sep 14 12:58:58:936 [140524608743168] 0 Controller: -------------------------------------------------------------------------------------------------------- Sep 14 12:58:58:936 [140524608743168] 0 Controller: ----- Robot controller 9.35 [Build 9.35.240, May 10 2022] started ----- Sep 14 12:58:58:936 [140524608743168] 0 Controller: Name = gokususe, IP = 192.168.3.20, Port = 48000 Sep 14 12:58:58:936 [140524608743168] 0 Controller: OS = UNIX / Linux / Linux 4.12.14-122.37-default #1 SMP Sun Sep 6 05:00:36 UTC 2020 (fe8cacf) x86_64 Sep 14 12:58:58:936 [140524608743168] 0 Controller: Domain = hubp_domain Sep 14 12:58:58:936 [140524608743168] 0 Controller: Primary HUB = /hubp_domain/hubs/hubs 192.168.3.75 Sep 14 12:58:58:936 [140524608743168] 0 Controller: Loglevel = 0, Logfile = controller.log Sep 14 12:58:58:937 [140524608743168] 0 Controller: Running as user root (0) Sep 14 12:58:58:937 [140524608743168] 0 Controller: ----- Sep 14 12:58:58:937 [140524608743168] 0 Controller: Controller on gokususe port 48000 started Sep 14 12:58:59:939 [140524608743168] 0 Controller: Hub hubs(192.168.3.75) contact established Sep 14 12:58:59:941 [140524608743168] 0 Controller: _ProcStart - Probe 'spooler' - starting Sep 14 12:59:00:993 [140524608743168] 0 Controller: _ProcStart - Probe 'hdb' - starting Sep 14 12:59:17:579 [140524608743168] 0 Controller: Selecting robotip from configuration. config_robotip = 192.168.3.20, cglob robotip = 192.168.3.20, local_ip_validation = 1, validate_ip_suggestion = 0, strict_ip_binding = 0 Sep 14 12:59:18:582 [140524608743168] 0 Controller: Going down... Sep 14 12:59:23:584 [140524608743168] 0 Controller: stop failed (communication error) Sep 14 12:59:26:589 [140524608743168] 0 Controller: Down Sep 14 12:59:56:984 [139729176205056] 0 Controller: Selecting robotip from configuration. config_robotip = 192.168.3.20, cglob robotip = 192.168.3.20, local_ip_validation = 1, validate_ip_suggestion = 0, strict_ip_binding = 0 Sep 14 12:59:56:984 [139729176205056] 0 Controller: -------------------------------------------------------------------------------------------------------- Sep 14 12:59:56:984 [139729176205056] 0 Controller: ----- Robot controller 9.35 [Build 9.35.240, May 10 2022] started ----- Sep 14 12:59:56:984 [139729176205056] 0 Controller: Name = gokususe, IP = 192.168.3.20, Port = 48000 Sep 14 12:59:56:984 [139729176205056] 0 Controller: OS = UNIX / Linux / Linux 4.12.14-122.37-default #1 SMP Sun Sep 6 05:00:36 UTC 2020 (fe8cacf) x86_64 Sep 14 12:59:56:984 [139729176205056] 0 Controller: Domain = hubp_domain Sep 14 12:59:56:984 [139729176205056] 0 Controller: Primary HUB = /hubp_domain/hubs/hubs 192.168.3.75 Sep 14 12:59:56:984 [139729176205056] 0 Controller: Loglevel = 0, Logfile = controller.log Sep 14 12:59:56:984 [139729176205056] 0 Controller: Running as user root (0) Sep 14 12:59:56:985 [139729176205056] 0 Controller: ----- Sep 14 12:59:56:985 [139729176205056] 0 Controller: Controller on gokususe port 48000 started Sep 14 12:59:57:988 [139729176205056] 0 Controller: Hub hubs(192.168.3.75) contact established Sep 14 12:59:57:989 [139729176205056] 0 Controller: _ProcStart - Probe 'spooler' - starting Sep 14 12:59:59:048 [139729176205056] 0 Controller: _ProcStart - Probe 'hdb' - starting Sep 14 13:00:37:839 [139729176205056] 0 Controller: Going down... Sep 14 13:00:45:845 [139729176205056] 0 Controller: Down Sep 14 13:00:49:072 [140610322003712] 0 Controller: Selecting robotip from configuration. config_robotip = 192.168.3.20, cglob robotip = 192.168.3.20, local_ip_validation = 1, validate_ip_suggestion = 0, strict_ip_binding = 0 Sep 14 13:00:49:072 [140610322003712] 0 Controller: -------------------------------------------------------------------------------------------------------- Sep 14 13:00:49:072 [140610322003712] 0 Controller: ----- Robot controller 9.35 [Build 9.35.240, May 10 2022] started ----- Sep 14 13:00:49:072 [140610322003712] 0 Controller: Name = gokususe, IP = 192.168.3.20, Port = 48000 Sep 14 13:00:49:072 [140610322003712] 0 Controller: OS = UNIX / Linux / Linux 4.12.14-122.37-default #1 SMP Sun Sep 6 05:00:36 UTC 2020 (fe8cacf) x86_64 Sep 14 13:00:49:072 [140610322003712] 0 Controller: Domain = hubp_domain Sep 14 13:00:49:072 [140610322003712] 0 Controller: Primary HUB = /hubp_domain/hubs/hubs 192.168.3.75 Sep 14 13:00:49:072 [140610322003712] 0 Controller: Loglevel = 0, Logfile = controller.log Sep 14 13:00:49:072 [140610322003712] 0 Controller: Running as user root (0) Sep 14 13:00:49:072 [140610322003712] 0 Controller: ----- Sep 14 13:00:49:072 [140610322003712] 0 Controller: Controller on gokususe port 48000 started Sep 14 13:00:50:075 [140610322003712] 0 Controller: Hub hubs(192.168.3.75) contact established Sep 14 13:00:50:078 [140610322003712] 0 Controller: _ProcStart - Probe 'spooler' - starting Sep 14 13:00:51:129 [140610322003712] 0 Controller: _ProcStart - Probe 'hdb' - starting Sep 14 13:01:17:421 [140610322003712] 0 Controller: Going down... Sep 14 13:01:25:428 [140610322003712] 0 Controller: Down Sep 14 13:01:28:571 [140482212910848] 0 Controller: Selecting robotip from configuration. config_robotip = 192.168.3.20, cglob robotip = 192.168.3.20, local_ip_validation = 1, validate_ip_suggestion = 0, strict_ip_binding = 0 Sep 14 13:01:28:572 [140482212910848] 0 Controller: -------------------------------------------------------------------------------------------------------- Sep 14 13:01:28:572 [140482212910848] 0 Controller: ----- Robot controller 9.35 [Build 9.35.240, May 10 2022] started ----- Sep 14 13:01:28:572 [140482212910848] 0 Controller: Name = gokususe, IP = 192.168.3.20, Port = 48000 Sep 14 13:01:28:572 [140482212910848] 0 Controller: OS = UNIX / Linux / Linux 4.12.14-122.37-default #1 SMP Sun Sep 6 05:00:36 UTC 2020 (fe8cacf) x86_64 Sep 14 13:01:28:572 [140482212910848] 0 Controller: Domain = hubp_domain Sep 14 13:01:28:572 [140482212910848] 0 Controller: Primary HUB = /hubp_domain/hubs/hubs 192.168.3.75 Sep 14 13:01:28:572 [140482212910848] 0 Controller: Loglevel = 0, Logfile = controller.log Sep 14 13:01:28:572 [140482212910848] 0 Controller: Running as user root (0) Sep 14 13:01:28:572 [140482212910848] 0 Controller: ----- Sep 14 13:01:28:572 [140482212910848] 0 Controller: Controller on gokususe port 48000 started Sep 14 13:01:29:575 [140482212910848] 0 Controller: Hub hubs(192.168.3.75) contact established Sep 14 13:01:29:577 [140482212910848] 0 Controller: _ProcStart - Probe 'spooler' - starting Sep 14 13:01:30:629 [140482212910848] 0 Controller: _ProcStart - Probe 'hdb' - starting Sep 14 13:03:10:812 [140482212910848] 0 Controller: Going down... Sep 14 13:03:18:818 [140482212910848] 0 Controller: Down Sep 14 13:03:22:072 [139898869724928] 0 Controller: Selecting robotip from configuration. config_robotip = 192.168.3.20, cglob robotip = 192.168.3.20, local_ip_validation = 1, validate_ip_suggestion = 0, strict_ip_binding = 0 Sep 14 13:03:22:072 [139898869724928] 0 Controller: -------------------------------------------------------------------------------------------------------- Sep 14 13:03:22:072 [139898869724928] 0 Controller: ----- Robot controller 9.35 [Build 9.35.240, May 10 2022] started ----- Sep 14 13:03:22:072 [139898869724928] 0 Controller: Name = gokususe, IP = 192.168.3.20, Port = 48000 Sep 14 13:03:22:072 [139898869724928] 0 Controller: OS = UNIX / Linux / Linux 4.12.14-122.37-default #1 SMP Sun Sep 6 05:00:36 UTC 2020 (fe8cacf) x86_64 Sep 14 13:03:22:072 [139898869724928] 0 Controller: Domain = hubp_domain Sep 14 13:03:22:072 [139898869724928] 0 Controller: Primary HUB = /hubp_domain/hubs/hubs 192.168.3.75 Sep 14 13:03:22:072 [139898869724928] 0 Controller: Loglevel = 0, Logfile = controller.log Sep 14 13:03:22:072 [139898869724928] 0 Controller: Running as user root (0) Sep 14 13:03:22:072 [139898869724928] 0 Controller: ----- Sep 14 13:03:22:073 [139898869724928] 0 Controller: Controller on gokususe port 48000 started Sep 14 13:03:23:076 [139898869724928] 0 Controller: Hub hubs(192.168.3.75) contact established Sep 14 13:03:23:078 [139898869724928] 0 Controller: _ProcStart - Probe 'spooler' - starting Sep 14 13:03:24:130 [139898869724928] 0 Controller: _ProcStart - Probe 'hdb' - starting Sep 14 13:03:47:249 [139898869724928] 0 Controller: Going down... Sep 14 13:03:55:256 [139898869724928] 0 Controller: Down Sep 14 13:03:58:572 [139820756838144] 0 Controller: Selecting robotip from configuration. config_robotip = 192.168.3.20, cglob robotip = 192.168.3.20, local_ip_validation = 1, validate_ip_suggestion = 0, strict_ip_binding = 0 Sep 14 13:03:58:572 [139820756838144] 0 Controller: -------------------------------------------------------------------------------------------------------- Sep 14 13:03:58:572 [139820756838144] 0 Controller: ----- Robot controller 9.35 [Build 9.35.240, May 10 2022] started ----- Sep 14 13:03:58:572 [139820756838144] 0 Controller: Name = gokususe, IP = 192.168.3.20, Port = 48000 Sep 14 13:03:58:572 [139820756838144] 0 Controller: OS = UNIX / Linux / Linux 4.12.14-122.37-default #1 SMP Sun Sep 6 05:00:36 UTC 2020 (fe8cacf) x86_64 Sep 14 13:03:58:572 [139820756838144] 0 Controller: Domain = hubp_domain Sep 14 13:03:58:572 [139820756838144] 0 Controller: Primary HUB = /hubp_domain/hubs/hubs 192.168.3.75 Sep 14 13:03:58:572 [139820756838144] 0 Controller: Loglevel = 0, Logfile = controller.log Sep 14 13:03:58:572 [139820756838144] 0 Controller: Running as user root (0) Sep 14 13:03:58:572 [139820756838144] 0 Controller: ----- Sep 14 13:03:58:573 [139820756838144] 0 Controller: Controller on gokususe port 48000 started Sep 14 13:03:59:576 [139820756838144] 0 Controller: Hub hubs(192.168.3.75) contact established Sep 14 13:03:59:578 [139820756838144] 0 Controller: _ProcStart - Probe 'spooler' - starting Sep 14 13:04:00:631 [139820756838144] 0 Controller: _ProcStart - Probe 'hdb' - starting Sep 14 13:54:47:514 [139820756838144] 1 Controller: log_level: Changing 0 -> 3 Sep 14 13:54:47:514 [139820756838144] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62712 Sep 14 13:54:47:514 [139820756838144] 3 Controller: RREQUEST: _close <-192.168.3.65/62712 h=433 d=0 fd=7 Sep 14 13:54:47:516 [139820756838144] 3 Controller: RREQUEST: probe_config_set <-192.168.3.65/62713 h=444 d=1487 fd=7 Sep 14 13:54:47:516 [139820756838144] 2 Controller: nimVerifyLogin robot Sep 14 13:54:47:516 [139820756838144] 3 Controller: SREQUEST: verify_login ->192.168.3.75/48002 Sep 14 13:54:47:516 [139820756838144] 3 Controller: RREPLY: status=OK(0) <-192.168.3.75/48002 h=37 d=56 fd=8 Sep 14 13:54:47:516 [139820756838144] 3 Controller: SREQUEST: _close ->192.168.3.75/48002 Sep 14 13:54:47:516 [139820756838144] 3 Controller: probe_config_set: called from '192.168.3.65/62713' Sep 14 13:54:47:517 [139820756838144] 3 Controller: probe_config_set: starting thread for 'controller' Sep 14 13:54:47:517 [139820733302528] 3 Controller: pcs_thread: processing msg 0x210bd40 for 'controller' Sep 14 13:54:47:517 [139820733302528] 2 Controller: GetUserFromSid - administrator Sep 14 13:54:47:517 [139820733302528] 1 Controller: probe_config_set (controller) from 192.168.3.65/62713 Sep 14 13:54:47:517 [139820733302528] 3 Controller: validating character encoding of config file: robot/robot.cfg Sep 14 13:54:47:517 [139820733302528] 1 Controller: Applied configuration change file to 'robot/robot.cfg', reprotecting Sep 14 13:54:47:517 [139820733302528] 1 Controller: File 'robot/robot.cfg' should not be protected, skipping checksum creation Sep 14 13:54:47:517 [139820733302528] 3 Controller: nimSession:0x21094e0:7:192.168.3.65/62713:192.168.3.65/62713 - needs cross-thread locking Sep 14 13:54:47:517 [139820733302528] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62713 Sep 14 13:54:48:518 [139820756838144] 3 Controller: RREQUEST: _close <-192.168.3.65/62713 h=433 d=0 fd=7 Sep 14 13:54:48:870 [139820756838144] 3 Controller: RREQUEST: _restart <-192.168.3.65/62714 h=435 d=0 fd=7 Sep 14 13:54:48:870 [139820756838144] 2 Controller: nimVerifyLogin robot Sep 14 13:54:48:871 [139820756838144] 3 Controller: SREQUEST: verify_login ->192.168.3.75/48002 Sep 14 13:54:48:871 [139820756838144] 3 Controller: RREPLY: status=OK(0) <-192.168.3.75/48002 h=37 d=56 fd=8 Sep 14 13:54:48:871 [139820756838144] 3 Controller: SREQUEST: _close ->192.168.3.75/48002 Sep 14 13:54:48:871 [139820756838144] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62714 Sep 14 13:54:48:871 [139820756838144] 1 Controller: _restart from 192.168.3.65/62714 Sep 14 13:54:48:871 [139820756838144] 1 Controller: RestartHandler called Sep 14 13:54:48:871 [139820756838144] 2 Controller: MyPutEnv NIM_STRICT_BINDING=0 Sep 14 13:54:48:871 [139820756838144] 2 Controller: NIM_STRICT_BINDING=0 Sep 14 13:54:48:872 [139820756838144] 0 Controller: Selecting robotip from configuration. config_robotip = 192.168.3.20, cglob robotip = 192.168.3.20, local_ip_validation = 1, validate_ip_suggestion = 0, strict_ip_binding = 0 Sep 14 13:54:48:872 [139820756838144] 2 Controller: check_configured_ip - local ip list = |||192.168.3.20|fe80::20c:29ff:fe1e:3efc| Sep 14 13:54:48:872 [139820756838144] 3 Controller: IsIPInList ip=192.168.3.20, list=|||192.168.3.20|fe80::20c:29ff:fe1e:3efc|, found=1 Sep 14 13:54:48:872 [139820756838144] 1 Controller: Explicit controller to hub login enabled Sep 14 13:54:48:872 [139820756838144] 2 Controller: MyPutEnv LD_LIBRARY_PATH=.:$LD_LIBRARY_PATH Sep 14 13:54:48:872 [139820756838144] 2 Controller: LD_LIBRARY_PATH=.:.:$LD_LIBRARY_PATH Sep 14 13:54:48:872 [139820756838144] 1 Controller: (parserobotcfg) calling LoadControllerPlugins refresh. Default path is /opt/nimsoft/plugins Sep 14 13:54:48:872 [139820756838144] 3 Controller: validating character encoding of config file: /opt/nimsoft/robot/robot.cfg Sep 14 13:54:48:872 [139820756838144] 3 Controller: validating character encoding of config file: /opt/nimsoft/robot/spooler.cfg Sep 14 13:54:48:872 [139820756838144] 2 Controller: nimCharsetSet() - charset= Sep 14 13:54:48:872 [139820756838144] 3 Controller: Controller - set logging options Sep 14 13:54:48:872 [139820756838144] 3 Controller: Controller - logging options set Sep 14 13:54:48:872 [139820756838144] 2 Controller: MyPutEnv NIMCPRID Sep 14 13:54:48:872 [139820756838144] 2 Controller: RestartHandler - sending restart to spooler at 192.168.3.20/48001 Sep 14 13:54:48:872 [139820756838144] 3 Controller: SREQUEST: _restart ->192.168.3.20/48001 Sep 14 13:54:48:872 [139820756838144] 3 Controller: RREPLY: status=OK(0) <-192.168.3.20/48001 h=37 d=0 fd=8 Sep 14 13:54:48:872 [139820756838144] 3 Controller: SREQUEST: _close ->192.168.3.20/48001 Sep 14 13:54:48:872 [139820756838144] 2 Controller: RestartHandler - got return 'OK' Sep 14 13:54:48:873 [139820756838144] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62714 Sep 14 13:54:48:873 [139820756838144] 3 Controller: RREQUEST: _close <-192.168.3.65/62714 h=433 d=0 fd=7 Sep 14 13:54:49:875 [139820756838144] 1 Controller: Internal queue statistics: to hub queued(current 0, highpoint 0) inprogress(current 0, highpoint 0) to probe queued(current 0, highpoint 2) Sep 14 13:54:51:877 [139820756838144] 2 Controller: medt_timeout; hubok = 1, hubnocontact = 0 Sep 14 13:54:51:878 [139820756838144] 3 Controller: SREQUEST: probelist ->192.168.3.75/48002 Sep 14 13:54:51:878 [139820756838144] 3 Controller: RREPLY: status=OK(0) <-192.168.3.75/48002 h=37 d=178 fd=7 Sep 14 13:54:51:878 [139820756838144] 3 Controller: SREQUEST: _close ->192.168.3.75/48002 Sep 14 13:54:51:878 [139820756838144] 1 Controller: probeportlist sent to hub hubs(192.168.3.75) Sep 14 13:55:02:896 [139820756838144] 2 Controller: medt_timeout; hubok = 1, hubnocontact = 0 Sep 14 13:55:07:736 [139820756838144] 2 Controller: ServiceStop Sep 14 13:55:08:738 [139820756838144] 0 Controller: Going down... Sep 14 13:55:08:738 [139820756838144] 1 Controller: Sending 'gokususe is NOT alive' to hubs(192.168.3.75) Sep 14 13:55:08:738 [139820756838144] 3 Controller: SREQUEST: alive ->192.168.3.75/48002 Sep 14 13:55:08:738 [139820756838144] 3 Controller: RREPLY: status=OK(0) <-192.168.3.75/48002 h=37 d=0 fd=7 Sep 14 13:55:08:738 [139820756838144] 3 Controller: SREQUEST: _close ->192.168.3.75/48002 Sep 14 13:55:08:739 [139820756838144] 1 Controller: Stopping probe 'hdb' (pid=2912) Sep 14 13:55:08:739 [139820756838144] 3 Controller: portFind hdb Sep 14 13:55:08:739 [139820756838144] 3 Controller: (async)async_req 192.168.3.20/48007 - _stop Sep 14 13:55:08:739 [139820756838144] 2 Controller: Sent _stop to hdb (192.168.3.20/48007) Sep 14 13:55:08:739 [139820756838144] 1 Controller: Stopping probe 'spooler' (pid=2910) Sep 14 13:55:08:739 [139820756838144] 3 Controller: portFind spooler Sep 14 13:55:08:739 [139820756838144] 3 Controller: (async)async_req 192.168.3.20/48001 - _stop Sep 14 13:55:08:739 [139820756838144] 2 Controller: Sent _stop to spooler (192.168.3.20/48001) Sep 14 13:55:08:739 [139820756838144] 3 Controller: (async)cb_pacallback Sep 14 13:55:08:739 [139820756838144] 3 Controller: (async)cb_pacallback - diff = 0, cmd = _stop Sep 14 13:55:08:739 [139820756838144] 3 Controller: SREQUEST: _stop ->192.168.3.20/48001 Sep 14 13:55:08:739 [139820756838144] 3 Controller: (async)cb_pacallback Sep 14 13:55:08:739 [139820756838144] 3 Controller: (async)cb_pacallback - diff = 0, cmd = _stop Sep 14 13:55:08:739 [139820756838144] 3 Controller: SREQUEST: _stop ->192.168.3.20/48007 Sep 14 13:55:08:739 [139820756838144] 3 Controller: RREPLY: status=OK(0) <-192.168.3.20/48001 h=37 d=0 fd=8 Sep 14 13:55:08:739 [139820756838144] 3 Controller: (async)cb_pacallback Sep 14 13:55:08:739 [139820756838144] 3 Controller: (async)cb_pacallback - diff = 0, cmd = _stop Sep 14 13:55:08:739 [139820756838144] 3 Controller: cb_pacallback - cb_reply from 192.168.3.20/48001 Sep 14 13:55:08:739 [139820756838144] 3 Controller: SREQUEST: _close ->192.168.3.20/48001 Sep 14 13:55:08:739 [139820756838144] 3 Controller: RREQUEST: port_unregister <-192.168.3.20/53000 h=117 d=13 fd=8 Sep 14 13:55:08:739 [139820756838144] 1 Controller: port_unregister (hdb) from 192.168.3.20/53000 Sep 14 13:55:08:739 [139820756838144] 2 Controller: portUnregister - name=hdb, pid=0 Sep 14 13:55:08:739 [139820756838144] 3 Controller: FindNamePid hdb - 0 Sep 14 13:55:08:739 [139820756838144] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.20/53000 Sep 14 13:55:08:739 [139820756838144] 3 Controller: RREPLY: status=OK(0) <-192.168.3.20/48007 h=37 d=0 fd=7 Sep 14 13:55:08:739 [139820756838144] 3 Controller: (async)cb_pacallback Sep 14 13:55:08:739 [139820756838144] 3 Controller: (async)cb_pacallback - diff = 0, cmd = _stop Sep 14 13:55:08:739 [139820756838144] 3 Controller: cb_pacallback - cb_reply from 192.168.3.20/48007 Sep 14 13:55:08:739 [139820756838144] 3 Controller: SREQUEST: _close ->192.168.3.20/48007 Sep 14 13:55:08:739 [139820756838144] 3 Controller: RREQUEST: _close <-192.168.3.20/53000 h=107 d=0 fd=8 Sep 14 13:55:13:739 [139820756838144] 3 Controller: RREQUEST: port_unregister <-192.168.3.20/53002 h=117 d=17 fd=7 Sep 14 13:55:13:739 [139820756838144] 1 Controller: port_unregister (spooler) from 192.168.3.20/53002 Sep 14 13:55:13:739 [139820756838144] 2 Controller: portUnregister - name=spooler, pid=0 Sep 14 13:55:13:739 [139820756838144] 3 Controller: FindNamePid spooler - 0 Sep 14 13:55:13:739 [139820756838144] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.20/53002 Sep 14 13:55:13:739 [139820756838144] 3 Controller: RREQUEST: _close <-192.168.3.20/53002 h=107 d=0 fd=7 Sep 14 13:55:16:744 [139820756838144] 1 Controller: Process stopped (probe=spooler, pid=2910) Sep 14 13:55:16:744 [139820756838144] 1 Controller: Process stopped (probe=hdb, pid=2912) Sep 14 13:55:16:744 [139820756838144] 0 Controller: Down Sep 14 13:55:16:744 [139820756838144] 2 Controller: nimEnd Sep 14 13:55:20:071 [140645050816256] 3 Controller: Controller - logging options set Sep 14 13:55:20:071 [140645050816256] 1 Controller: robot_env read - error, read pds from file '/opt/nimsoft/robot/robot_env.sds' failed Sep 14 13:55:20:071 [140645050816256] 1 Controller: robot_env read - error, read failed, file = '/opt/nimsoft/robot/robot_env.sds', rc = 1663178638 (unknown error) Sep 14 13:55:20:071 [140645050816256] 0 Controller: Selecting robotip from configuration. config_robotip = 192.168.3.20, cglob robotip = 192.168.3.20, local_ip_validation = 1, validate_ip_suggestion = 0, strict_ip_binding = 0 Sep 14 13:55:20:071 [140645050816256] 2 Controller: check_configured_ip - local ip list = |||192.168.3.20|fe80::20c:29ff:fe1e:3efc| Sep 14 13:55:20:071 [140645050816256] 3 Controller: IsIPInList ip=192.168.3.20, list=|||192.168.3.20|fe80::20c:29ff:fe1e:3efc|, found=1 Sep 14 13:55:20:071 [140645050816256] 1 Controller: Explicit controller to hub login enabled Sep 14 13:55:20:071 [140645050816256] 2 Controller: MyPutEnv LD_LIBRARY_PATH=.:$LD_LIBRARY_PATH Sep 14 13:55:20:071 [140645050816256] 2 Controller: LD_LIBRARY_PATH=.:$LD_LIBRARY_PATH Sep 14 13:55:20:071 [140645050816256] 1 Controller: (parserobotcfg) calling LoadControllerPlugins refresh. Default path is /opt/nimsoft/plugins Sep 14 13:55:20:071 [140645050816256] 3 Controller: validating character encoding of config file: /opt/nimsoft/robot/robot.cfg Sep 14 13:55:20:071 [140645050816256] 3 Controller: validating character encoding of config file: /opt/nimsoft/robot/spooler.cfg Sep 14 13:55:20:071 [140645050816256] 2 Controller: nimCharsetSet() - charset= Sep 14 13:55:20:071 [140645050816256] 3 Controller: Controller - set logging options Sep 14 13:55:20:071 [140645050816256] 0 Controller: -------------------------------------------------------------------------------------------------------- Sep 14 13:55:20:071 [140645050816256] 0 Controller: ----- Robot controller 9.35 [Build 9.35.240, May 10 2022] started ----- Sep 14 13:55:20:071 [140645050816256] 0 Controller: Name = gokususe, IP = 192.168.3.20, Port = 48000 Sep 14 13:55:20:071 [140645050816256] 0 Controller: OS = UNIX / Linux / Linux 4.12.14-122.37-default #1 SMP Sun Sep 6 05:00:36 UTC 2020 (fe8cacf) x86_64 Sep 14 13:55:20:071 [140645050816256] 0 Controller: Domain = hubp_domain Sep 14 13:55:20:071 [140645050816256] 0 Controller: Primary HUB = /hubp_domain/hubs/hubs 192.168.3.75 Sep 14 13:55:20:071 [140645050816256] 0 Controller: Loglevel = 3, Logfile = controller.log Sep 14 13:55:20:071 [140645050816256] 1 Controller: System Uptime QoS = no Sep 14 13:55:20:071 [140645050816256] 3 Controller: Cluster_support = 0 Sep 14 13:55:20:071 [140645050816256] 1 Controller: major=LINUX minor=LINUX_222_64 Sep 14 13:55:20:071 [140645050816256] 1 Controller: Robot device ID = D3AAB9F270FA51254C9B8262FDB2AC12F Sep 14 13:55:20:071 [140645050816256] 2 Controller: MyPutEnv NIM_DEVICE_ID=D3AAB9F270FA51254C9B8262FDB2AC12F Sep 14 13:55:20:071 [140645050816256] 2 Controller: NIM_DEVICE_ID=D3AAB9F270FA51254C9B8262FDB2AC12F Sep 14 13:55:20:071 [140645050816256] 2 Controller: ciOpen - initializing global CI cache Sep 14 13:55:20:071 [140645050816256] 2 Controller: ciSave - saving CI [C90AE95468CB75297AC9FE39B085B9821] Sep 14 13:55:20:071 [140645050816256] 2 Controller: ciSaveMetric - saving MET [MD3C6C6D917992BACDDE50C451A6DA16F] 10.2:5 Sep 14 13:55:20:071 [140645050816256] 1 Controller: Robot state metric ID = MD3C6C6D917992BACDDE50C451A6DA16F Sep 14 13:55:20:071 [140645050816256] 1 Controller: File validation information cache not loaded Sep 14 13:55:20:072 [140645050816256] 0 Controller: Running as user root (0) Sep 14 13:55:20:072 [140645050816256] 0 Controller: ----- Sep 14 13:55:20:072 [140645050816256] 3 Controller: Controller - fetch expire information Sep 14 13:55:20:072 [140645050816256] 2 Controller: expire/fetch_expire - find full path to expire.cfg Sep 14 13:55:20:072 [140645050816256] 2 Controller: expire/fetch_expire - allocate space for /opt/nimsoft/robot/expire.cfg Sep 14 13:55:20:072 [140645050816256] 2 Controller: expire/fetch_expire - check access to /opt/nimsoft/robot/expire.cfg Sep 14 13:55:20:072 [140645050816256] 2 Controller: expire/fetch_expire - CRC check Sep 14 13:55:20:072 [140645050816256] 2 Controller: expire/VerifyCrc - /opt/nimsoft/robot/expire.cfg, /opt/nimsoft/robot/expire.crc Sep 14 13:55:20:072 [140645050816256] 2 Controller: expire/VerifyCrc - generate checksum based on robot name Sep 14 13:55:20:072 [140645050816256] 2 Controller: expire/gen_key /opt/nimsoft/robot/expire.cfg Sep 14 13:55:20:072 [140645050816256] 2 Controller: expire/gen_key g49tUBqdY5Oars+JujNnPA== Sep 14 13:55:20:072 [140645050816256] 2 Controller: expire/gen_key gokususe Sep 14 13:55:20:072 [140645050816256] 2 Controller: expire/gen_key 3Tb4hp+lJWbCM3iNpKA50+PNILVFCfONzXXF0dh95jCy/xdeuBpUSuslFVuIAOve Sep 14 13:55:20:072 [140645050816256] 2 Controller: expire/VerifyCrc - open crc file and compare Sep 14 13:55:20:072 [140645050816256] 3 Controller: expire/VerifyCrc - found: 1 Sep 14 13:55:20:072 [140645050816256] 2 Controller: expire/fetch_expire - ok; read Sep 14 13:55:20:072 [140645050816256] 2 Controller: expire/fetch_expire - done Sep 14 13:55:20:072 [140645050816256] 2 Controller: Change directory to /opt/nimsoft Sep 14 13:55:20:072 [140645050816256] 3 Controller: validating character encoding of config file: /opt/nimsoft/robot/controller.cfg Sep 14 13:55:20:072 [140645050816256] 2 Controller: nimSessionServer - port = 48000 Sep 14 13:55:20:072 [140645050816256] 2 Controller: sockServer - 0xc74710:0.0.0.0/48000:fd=5 Sep 14 13:55:20:072 [140645050816256] 0 Controller: Controller on gokususe port 48000 started Sep 14 13:55:20:072 [140645050816256] 2 Controller: nimSessionServer - port = 48000 Sep 14 13:55:20:072 [140645050816256] 2 Controller: sockServer - 0xc7ab10:0.0.0.0/48000:fd=6 Sep 14 13:55:20:072 [140645050816256] 3 Controller: validating character encoding of config file: /opt/nimsoft/robot/controller.cfg Sep 14 13:55:20:072 [140645050816256] 2 Controller: portRegister - name=controller, port=48000, ip=, pid=9427 Sep 14 13:55:20:072 [140645050816256] 3 Controller: FindNamePid controller - 9427 Sep 14 13:55:20:072 [140645050816256] 3 Controller: reserve_port (controller) - assigned to 48000 Sep 14 13:55:20:088 [140645050816256] 3 Controller: RREQUEST: get_info <-192.168.3.71/61881 h=361 d=17 fd=7 Sep 14 13:55:20:088 [140645050816256] 1 Controller: get_info from 192.168.3.71/61881 Sep 14 13:55:20:089 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.71/61881 Sep 14 13:55:20:090 [140645050816256] 3 Controller: RREQUEST: get_info <-192.168.3.71/61883 h=361 d=17 fd=8 Sep 14 13:55:20:090 [140645050816256] 1 Controller: get_info from 192.168.3.71/61883 Sep 14 13:55:20:090 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.71/61883 Sep 14 13:55:20:104 [140645050816256] 3 Controller: RREQUEST: _close <-192.168.3.71/61883 h=359 d=0 fd=8 Sep 14 13:55:20:105 [140645050816256] 3 Controller: RREQUEST: _close <-192.168.3.71/61881 h=359 d=0 fd=7 Sep 14 13:55:21:106 [140645050816256] 1 Controller: Internal queue statistics: to hub queued(current 0, highpoint 0) inprogress(current 0, highpoint 0) to probe queued(current 0, highpoint 0) Sep 14 13:55:21:106 [140645050816256] 2 Controller: Try primary hub Sep 14 13:55:21:106 [140645050816256] 3 Controller: dorobotup - Sep 14 13:55:21:106 [140645050816256] 3 Controller: hubdomain=hubp_domain Sep 14 13:55:21:106 [140645050816256] 3 Controller: hubname=hubs Sep 14 13:55:21:106 [140645050816256] 3 Controller: hubip=192.168.3.75, hubport=48002 Sep 14 13:55:21:106 [140645050816256] 3 Controller: hub_dns_name= Sep 14 13:55:21:106 [140645050816256] 3 Controller: robotip_alias= Sep 14 13:55:21:106 [140645050816256] 1 Controller: 'robotup' to hubs(192.168.3.75) for gokususe Sep 14 13:55:21:107 [140645050816256] 3 Controller: SREQUEST: robotup ->192.168.3.75/48002 Sep 14 13:55:21:107 [140645050816256] 3 Controller: RREPLY: status=OK(0) <-192.168.3.75/48002 h=37 d=217 fd=7 Sep 14 13:55:21:107 [140645050816256] 3 Controller: SREQUEST: _close ->192.168.3.75/48002 Sep 14 13:55:21:107 [140645050816256] 1 Controller: AuditEnable - Disable Sep 14 13:55:21:107 [140645050816256] 0 Controller: Hub hubs(192.168.3.75) contact established Sep 14 13:55:21:107 [140645050816256] 2 Controller: origin_mode from hub: pending=hubs, hubok=1, which_hub=PRIMARY Sep 14 13:55:21:107 [140645050816256] 2 Controller: origin_mode updated origin from pending: old="" new="hubs" Sep 14 13:55:21:107 [140645050816256] 2 Controller: origin_mode is INHERITED (primary): hubs Sep 14 13:55:21:107 [140645050816256] 1 Controller: dorobotup - cglob.robotip_alias = Sep 14 13:55:21:107 [140645050816256] 1 Controller: dorobotup - robotip_alias = Sep 14 13:55:21:107 [140645050816256] 3 Controller: set which_hub=0 Sep 14 13:55:21:107 [140645050816256] 2 Controller: origin_mode is INHERITED (primary): hubs Sep 14 13:55:21:108 [140645050816256] 3 Controller: validating character encoding of config file: /opt/nimsoft/robot/robot.cfg Sep 14 13:55:21:108 [140645050816256] 3 Controller: NimCryptographerEncryptPds using crypto mode TWOFISH Sep 14 13:55:21:108 [140645050816256] 3 Controller: SREQUEST: login ->192.168.3.75/48002 Sep 14 13:55:21:108 [140645050816256] 3 Controller: RREPLY: status=OK(0) <-192.168.3.75/48002 h=37 d=171 fd=7 Sep 14 13:55:21:108 [140645050816256] 3 Controller: SREQUEST: _close ->192.168.3.75/48002 Sep 14 13:55:21:109 [140645050816256] 1 Controller: Controller hub login completed successfully Sep 14 13:55:21:109 [140645050816256] 2 Controller: medt_timeout; hubok = 1, hubnocontact = 0 Sep 14 13:55:21:109 [140645050816256] 3 Controller: SREQUEST: probelist ->192.168.3.75/48002 Sep 14 13:55:21:109 [140645050816256] 3 Controller: RREPLY: status=OK(0) <-192.168.3.75/48002 h=37 d=178 fd=7 Sep 14 13:55:21:109 [140645050816256] 3 Controller: SREQUEST: _close ->192.168.3.75/48002 Sep 14 13:55:21:109 [140645050816256] 1 Controller: probeportlist sent to hub hubs(192.168.3.75) Sep 14 13:55:21:109 [140645050816256] 3 Controller: restart probes if env changed - Initial save of env values completed. Sep 14 13:55:21:109 [140645050816256] 3 Controller: probe deploy - deploy file 'request.cfg' does not exist, do not make requests to deploy probes Sep 14 13:55:21:109 [140645050816256] 3 Controller: probe deploy - success or nothing to do, rc=0 (OK) Sep 14 13:55:21:109 [140645050816256] 0 Controller: _ProcStart - Probe 'spooler' - starting Sep 14 13:55:21:109 [140645050816256] 3 Controller: probeGenerateMagicKey for spooler Sep 14 13:55:21:109 [140645050816256] 3 Controller: probeFindCRCs for spooler Sep 14 13:55:21:157 [140645050816256] 3 Controller: probeFindCRCs - 0 Sep 14 13:55:21:157 [140645050816256] 3 Controller: probeGenerateMagicKey - 0P1ffOhinYU1bLuq3PM/mqHVVJ4XJFzx1Ea9CSMPpufcd5nJQgYwzbdqODINDFysjcemiWf0xjNKf36LOZS3Yz+q+xYaNQIeDn4/3Jd6oTgbq5oV0u54h79FTm4jd5ou Sep 14 13:55:21:157 [140645050816256] 3 Controller: reserve_port (spooler) starting at 48000 Sep 14 13:55:21:157 [140645050816256] 3 Controller: reserve_port (spooler) - assigned to 48001 Sep 14 13:55:21:157 [140645050816256] 2 Controller: MyStringExpand (spooler)... Sep 14 13:55:21:157 [140645050816256] 1 Controller: Probe 'spooler' started (pid=9429) Sep 14 13:55:21:159 [140645050816256] 3 Controller: RREQUEST: probe_checkin <-192.168.3.20/53010 h=115 d=30 fd=7 Sep 14 13:55:21:159 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.20/53010 Sep 14 13:55:21:159 [140645050816256] 3 Controller: RREQUEST: _close <-192.168.3.20/53010 h=107 d=0 fd=7 Sep 14 13:55:21:159 [140645050816256] 3 Controller: RREQUEST: gethub <-192.168.3.20/53012 h=107 d=0 fd=7 Sep 14 13:55:21:159 [140645050816256] 1 Controller: gethub from 192.168.3.20/53012 Sep 14 13:55:21:159 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.20/53012 Sep 14 13:55:21:159 [140645050816256] 3 Controller: RREQUEST: _close <-192.168.3.20/53012 h=107 d=0 fd=7 Sep 14 13:55:21:159 [140645050816256] 3 Controller: RREQUEST: gethub <-192.168.3.20/53014 h=107 d=0 fd=7 Sep 14 13:55:21:159 [140645050816256] 1 Controller: gethub from 192.168.3.20/53014 Sep 14 13:55:21:159 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.20/53014 Sep 14 13:55:21:159 [140645050816256] 3 Controller: RREQUEST: _close <-192.168.3.20/53014 h=107 d=0 fd=7 Sep 14 13:55:21:160 [140645050816256] 3 Controller: RREQUEST: port_register <-192.168.3.20/53016 h=115 d=32 fd=7 Sep 14 13:55:21:160 [140645050816256] 1 Controller: port_register (spooler) from 192.168.3.20/53016 Sep 14 13:55:21:160 [140645050816256] 2 Controller: portRegister - name=spooler, port=48001, ip=192.168.3.20, pid=0 Sep 14 13:55:21:160 [140645050816256] 3 Controller: FindNamePid spooler - 0 Sep 14 13:55:21:160 [140645050816256] 3 Controller: reserve_port (spooler) - updated from 48001 to 48001 Sep 14 13:55:21:160 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.20/53016 Sep 14 13:55:21:160 [140645050816256] 3 Controller: RREQUEST: _close <-192.168.3.20/53016 h=107 d=0 fd=7 Sep 14 13:55:22:162 [140645050816256] 0 Controller: _ProcStart - Probe 'hdb' - starting Sep 14 13:55:22:162 [140645050816256] 3 Controller: probeGenerateMagicKey for hdb Sep 14 13:55:22:162 [140645050816256] 3 Controller: probeFindCRCs for hdb Sep 14 13:55:22:211 [140645050816256] 3 Controller: probeFindCRCs - 0 Sep 14 13:55:22:211 [140645050816256] 3 Controller: probeGenerateMagicKey - 0P1ffOhinYU1bLuq3PM/mqHVVJ4XJFzx1Ea9CSMPpufcd5nJQgYwzbdqODINDFysjcemiWf0xjNKf36LOZS3Yz+q+xYaNQIeDn4/3Jd6oTg5U4zWh85+sWP/BH4/Te0B Sep 14 13:55:22:211 [140645050816256] 3 Controller: reserve_port (hdb) starting at 48000 Sep 14 13:55:22:211 [140645050816256] 3 Controller: reserve_port (hdb) - assigned to 48007 Sep 14 13:55:22:211 [140645050816256] 2 Controller: MyStringExpand (hdb)... Sep 14 13:55:22:211 [140645050816256] 1 Controller: Probe 'hdb' started (pid=9431) Sep 14 13:55:22:212 [140645050816256] 3 Controller: RREQUEST: probe_checkin <-192.168.3.20/53018 h=115 d=31 fd=7 Sep 14 13:55:22:212 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.20/53018 Sep 14 13:55:22:212 [140645050816256] 3 Controller: RREQUEST: _close <-192.168.3.20/53018 h=107 d=0 fd=7 Sep 14 13:55:22:213 [140645050816256] 3 Controller: RREQUEST: port_register <-192.168.3.20/53020 h=115 d=28 fd=7 Sep 14 13:55:22:213 [140645050816256] 1 Controller: port_register (hdb) from 192.168.3.20/53020 Sep 14 13:55:22:213 [140645050816256] 2 Controller: portRegister - name=hdb, port=48007, ip=192.168.3.20, pid=0 Sep 14 13:55:22:213 [140645050816256] 3 Controller: FindNamePid hdb - 0 Sep 14 13:55:22:213 [140645050816256] 3 Controller: reserve_port (hdb) - updated from 48007 to 48007 Sep 14 13:55:22:213 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.20/53020 Sep 14 13:55:22:213 [140645050816256] 3 Controller: RREQUEST: _close <-192.168.3.20/53020 h=107 d=0 fd=7 Sep 14 13:55:32:226 [140645050816256] 2 Controller: medt_timeout; hubok = 1, hubnocontact = 0 Sep 14 13:55:32:227 [140645050816256] 3 Controller: SREQUEST: probelist ->192.168.3.75/48002 Sep 14 13:55:32:227 [140645050816256] 3 Controller: RREPLY: status=OK(0) <-192.168.3.75/48002 h=37 d=178 fd=7 Sep 14 13:55:32:227 [140645050816256] 3 Controller: SREQUEST: _close ->192.168.3.75/48002 Sep 14 13:55:32:227 [140645050816256] 1 Controller: probeportlist sent to hub hubs(192.168.3.75) Sep 14 13:55:35:106 [140645050816256] 3 Controller: RREQUEST: probe_list <-192.168.3.71/61935 h=364 d=0 fd=7 Sep 14 13:55:35:106 [140645050816256] 2 Controller: nimVerifyLogin robot Sep 14 13:55:35:106 [140645050816256] 3 Controller: SREQUEST: verify_login ->192.168.3.75/48002 Sep 14 13:55:35:106 [140645050816256] 3 Controller: RREPLY: status=OK(0) <-192.168.3.75/48002 h=37 d=55 fd=8 Sep 14 13:55:35:106 [140645050816256] 3 Controller: SREQUEST: _close ->192.168.3.75/48002 Sep 14 13:55:35:106 [140645050816256] 1 Controller: probe_list from 192.168.3.71/61935 Sep 14 13:55:35:106 [140645050816256] 3 Controller: portFind controller Sep 14 13:55:35:106 [140645050816256] 3 Controller: portFind controller Sep 14 13:55:35:106 [140645050816256] 3 Controller: portFind spooler Sep 14 13:55:35:106 [140645050816256] 3 Controller: portFind spooler Sep 14 13:55:35:106 [140645050816256] 3 Controller: portFind hdb Sep 14 13:55:35:106 [140645050816256] 3 Controller: portFind hdb Sep 14 13:55:35:107 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.71/61935 Sep 14 13:55:35:108 [140645050816256] 3 Controller: RREQUEST: port_list <-192.168.3.71/61935 h=363 d=0 fd=7 Sep 14 13:55:35:108 [140645050816256] 1 Controller: port_list from 192.168.3.71/61935 Sep 14 13:55:35:108 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.71/61935 Sep 14 13:55:35:112 [140645050816256] 3 Controller: RREQUEST: probe_list <-192.168.3.71/61938 h=364 d=0 fd=8 Sep 14 13:55:35:112 [140645050816256] 2 Controller: nimVerifyLogin robot Sep 14 13:55:35:112 [140645050816256] 3 Controller: SREQUEST: verify_login ->192.168.3.75/48002 Sep 14 13:55:35:113 [140645050816256] 3 Controller: RREPLY: status=OK(0) <-192.168.3.75/48002 h=37 d=55 fd=9 Sep 14 13:55:35:113 [140645050816256] 3 Controller: SREQUEST: _close ->192.168.3.75/48002 Sep 14 13:55:35:113 [140645050816256] 1 Controller: probe_list from 192.168.3.71/61938 Sep 14 13:55:35:113 [140645050816256] 3 Controller: portFind controller Sep 14 13:55:35:113 [140645050816256] 3 Controller: portFind controller Sep 14 13:55:35:113 [140645050816256] 3 Controller: portFind spooler Sep 14 13:55:35:113 [140645050816256] 3 Controller: portFind spooler Sep 14 13:55:35:113 [140645050816256] 3 Controller: portFind hdb Sep 14 13:55:35:113 [140645050816256] 3 Controller: portFind hdb Sep 14 13:55:35:113 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.71/61938 Sep 14 13:55:35:113 [140645050816256] 3 Controller: RREQUEST: port_list <-192.168.3.71/61938 h=363 d=0 fd=8 Sep 14 13:55:35:113 [140645050816256] 1 Controller: port_list from 192.168.3.71/61938 Sep 14 13:55:35:113 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.71/61938 Sep 14 13:55:35:183 [140645050816256] 3 Controller: RREQUEST: _close <-192.168.3.71/61938 h=359 d=0 fd=8 Sep 14 13:55:35:183 [140645050816256] 3 Controller: RREQUEST: _close <-192.168.3.71/61935 h=359 d=0 fd=7 Sep 14 13:55:43:194 [140645050816256] 2 Controller: medt_timeout; hubok = 1, hubnocontact = 0 Sep 14 13:55:43:194 [140645050816256] 3 Controller: SREQUEST: set_hub ->192.168.3.20/48001 Sep 14 13:55:43:195 [140645050816256] 3 Controller: RREPLY: status=OK(0) <-192.168.3.20/48001 h=37 d=47 fd=7 Sep 14 13:55:43:195 [140645050816256] 3 Controller: SREQUEST: _close ->192.168.3.20/48001 Sep 14 13:55:43:195 [140645050816256] 1 Controller: set_hub sent to spooler hub = hubs(192.168.3.75) ON Sep 14 13:55:49:723 [140645050816256] 3 Controller: RREQUEST: get_info <-192.168.3.65/62753 h=435 d=0 fd=7 Sep 14 13:55:49:723 [140645050816256] 1 Controller: get_info from 192.168.3.65/62753 Sep 14 13:55:49:723 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62753 Sep 14 13:55:49:723 [140645050816256] 3 Controller: RREQUEST: _close <-192.168.3.65/62753 h=433 d=0 fd=7 Sep 14 13:55:49:724 [140645050816256] 3 Controller: RREQUEST: probe_list <-192.168.3.65/62754 h=438 d=21 fd=7 Sep 14 13:55:49:724 [140645050816256] 2 Controller: nimVerifyLogin robot Sep 14 13:55:49:724 [140645050816256] 3 Controller: SREQUEST: verify_login ->192.168.3.75/48002 Sep 14 13:55:49:725 [140645050816256] 3 Controller: RREPLY: status=OK(0) <-192.168.3.75/48002 h=37 d=56 fd=8 Sep 14 13:55:49:725 [140645050816256] 3 Controller: SREQUEST: _close ->192.168.3.75/48002 Sep 14 13:55:49:725 [140645050816256] 1 Controller: probe_list (controller) from 192.168.3.65/62754 Sep 14 13:55:49:725 [140645050816256] 3 Controller: portFind controller Sep 14 13:55:49:725 [140645050816256] 3 Controller: portFind controller Sep 14 13:55:49:725 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62754 Sep 14 13:55:49:725 [140645050816256] 3 Controller: RREQUEST: _close <-192.168.3.65/62754 h=433 d=0 fd=7 Sep 14 13:55:50:110 [140645050816256] 3 Controller: RREQUEST: probe_list <-192.168.3.71/62055 h=364 d=0 fd=7 Sep 14 13:55:50:110 [140645050816256] 2 Controller: nimVerifyLogin robot Sep 14 13:55:50:110 [140645050816256] 3 Controller: SREQUEST: verify_login ->192.168.3.75/48002 Sep 14 13:55:50:111 [140645050816256] 3 Controller: RREPLY: status=OK(0) <-192.168.3.75/48002 h=37 d=55 fd=8 Sep 14 13:55:50:111 [140645050816256] 3 Controller: SREQUEST: _close ->192.168.3.75/48002 Sep 14 13:55:50:111 [140645050816256] 1 Controller: probe_list from 192.168.3.71/62055 Sep 14 13:55:50:111 [140645050816256] 3 Controller: portFind controller Sep 14 13:55:50:111 [140645050816256] 3 Controller: portFind controller Sep 14 13:55:50:111 [140645050816256] 3 Controller: portFind spooler Sep 14 13:55:50:111 [140645050816256] 3 Controller: portFind spooler Sep 14 13:55:50:111 [140645050816256] 3 Controller: portFind hdb Sep 14 13:55:50:111 [140645050816256] 3 Controller: portFind hdb Sep 14 13:55:50:111 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.71/62055 Sep 14 13:55:50:112 [140645050816256] 3 Controller: RREQUEST: port_list <-192.168.3.71/62055 h=363 d=0 fd=7 Sep 14 13:55:50:112 [140645050816256] 1 Controller: port_list from 192.168.3.71/62055 Sep 14 13:55:50:112 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.71/62055 Sep 14 13:55:50:204 [140645050816256] 3 Controller: RREQUEST: _close <-192.168.3.71/62055 h=359 d=0 fd=7 Sep 14 13:55:51:233 [140645050816256] 3 Controller: RREQUEST: probe_tail_logfile <-192.168.3.65/62758 h=446 d=53 fd=7 Sep 14 13:55:51:233 [140645050816256] 2 Controller: nimVerifyLogin robot Sep 14 13:55:51:233 [140645050816256] 3 Controller: SREQUEST: verify_login ->192.168.3.75/48002 Sep 14 13:55:51:233 [140645050816256] 3 Controller: RREPLY: status=OK(0) <-192.168.3.75/48002 h=37 d=56 fd=8 Sep 14 13:55:51:233 [140645050816256] 3 Controller: SREQUEST: _close ->192.168.3.75/48002 Sep 14 13:55:51:233 [140645050816256] 3 Controller: probe_tail_logfile (controller) from 192.168.3.65/62758 Sep 14 13:55:51:234 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62758 Sep 14 13:55:52:373 [140645050816256] 3 Controller: RREQUEST: probe_tail_logfile <-192.168.3.65/62758 h=446 d=53 fd=7 Sep 14 13:55:52:373 [140645050816256] 3 Controller: probe_tail_logfile (controller) from 192.168.3.65/62758 Sep 14 13:55:52:373 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62758 Sep 14 13:55:53:389 [140645050816256] 3 Controller: RREQUEST: probe_tail_logfile <-192.168.3.65/62758 h=446 d=53 fd=7 Sep 14 13:55:53:389 [140645050816256] 3 Controller: probe_tail_logfile (controller) from 192.168.3.65/62758 Sep 14 13:55:53:389 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62758 Sep 14 13:55:54:391 [140645050816256] 2 Controller: medt_timeout; hubok = 1, hubnocontact = 0 Sep 14 13:55:54:406 [140645050816256] 3 Controller: RREQUEST: probe_tail_logfile <-192.168.3.65/62758 h=446 d=53 fd=7 Sep 14 13:55:54:406 [140645050816256] 3 Controller: probe_tail_logfile (controller) from 192.168.3.65/62758 Sep 14 13:55:54:406 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62758 Sep 14 13:55:55:420 [140645050816256] 3 Controller: RREQUEST: probe_tail_logfile <-192.168.3.65/62758 h=446 d=53 fd=7 Sep 14 13:55:55:420 [140645050816256] 3 Controller: probe_tail_logfile (controller) from 192.168.3.65/62758 Sep 14 13:55:55:420 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62758 Sep 14 13:55:56:436 [140645050816256] 3 Controller: RREQUEST: probe_tail_logfile <-192.168.3.65/62758 h=446 d=53 fd=7 Sep 14 13:55:56:436 [140645050816256] 3 Controller: probe_tail_logfile (controller) from 192.168.3.65/62758 Sep 14 13:55:56:436 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62758 Sep 14 13:55:57:450 [140645050816256] 3 Controller: RREQUEST: probe_tail_logfile <-192.168.3.65/62758 h=446 d=53 fd=7 Sep 14 13:55:57:450 [140645050816256] 3 Controller: probe_tail_logfile (controller) from 192.168.3.65/62758 Sep 14 13:55:57:450 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62758 Sep 14 13:55:58:470 [140645050816256] 3 Controller: RREQUEST: probe_tail_logfile <-192.168.3.65/62758 h=446 d=53 fd=7 Sep 14 13:55:58:470 [140645050816256] 3 Controller: probe_tail_logfile (controller) from 192.168.3.65/62758 Sep 14 13:55:58:470 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62758 Sep 14 13:55:59:490 [140645050816256] 3 Controller: RREQUEST: probe_tail_logfile <-192.168.3.65/62758 h=446 d=53 fd=7 Sep 14 13:55:59:490 [140645050816256] 3 Controller: probe_tail_logfile (controller) from 192.168.3.65/62758 Sep 14 13:55:59:490 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62758 Sep 14 13:56:00:496 [140645050816256] 3 Controller: RREQUEST: probe_tail_logfile <-192.168.3.65/62758 h=446 d=53 fd=7 Sep 14 13:56:00:496 [140645050816256] 3 Controller: probe_tail_logfile (controller) from 192.168.3.65/62758 Sep 14 13:56:00:496 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62758 Sep 14 13:56:01:510 [140645050816256] 3 Controller: RREQUEST: probe_tail_logfile <-192.168.3.65/62758 h=447 d=53 fd=7 Sep 14 13:56:01:510 [140645050816256] 3 Controller: probe_tail_logfile (controller) from 192.168.3.65/62758 Sep 14 13:56:01:511 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62758 Sep 14 13:56:02:527 [140645050816256] 3 Controller: RREQUEST: probe_tail_logfile <-192.168.3.65/62758 h=447 d=53 fd=7 Sep 14 13:56:02:527 [140645050816256] 3 Controller: probe_tail_logfile (controller) from 192.168.3.65/62758 Sep 14 13:56:02:527 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62758 Sep 14 13:56:03:547 [140645050816256] 3 Controller: RREQUEST: probe_tail_logfile <-192.168.3.65/62758 h=447 d=53 fd=7 Sep 14 13:56:03:547 [140645050816256] 3 Controller: probe_tail_logfile (controller) from 192.168.3.65/62758 Sep 14 13:56:03:547 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62758 Sep 14 13:56:04:561 [140645050816256] 3 Controller: RREQUEST: probe_tail_logfile <-192.168.3.65/62758 h=447 d=53 fd=7 Sep 14 13:56:04:561 [140645050816256] 3 Controller: probe_tail_logfile (controller) from 192.168.3.65/62758 Sep 14 13:56:04:561 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62758 Sep 14 13:56:05:563 [140645050816256] 2 Controller: medt_timeout; hubok = 1, hubnocontact = 0 Sep 14 13:56:05:590 [140645050816256] 3 Controller: RREQUEST: probe_tail_logfile <-192.168.3.65/62758 h=447 d=53 fd=7 Sep 14 13:56:05:590 [140645050816256] 3 Controller: probe_tail_logfile (controller) from 192.168.3.65/62758 Sep 14 13:56:05:590 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62758 Sep 14 13:56:06:622 [140645050816256] 3 Controller: RREQUEST: probe_tail_logfile <-192.168.3.65/62758 h=447 d=53 fd=7 Sep 14 13:56:06:623 [140645050816256] 3 Controller: probe_tail_logfile (controller) from 192.168.3.65/62758 Sep 14 13:56:06:623 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62758 Sep 14 13:56:07:440 [140645050816256] 3 Controller: RREQUEST: _close <-192.168.3.65/62758 h=434 d=0 fd=7 Sep 14 13:56:15:220 [140645050816256] 2 Controller: ServiceStop Sep 14 13:56:16:221 [140645050816256] 2 Controller: medt_timeout; hubok = 1, hubnocontact = 0 Sep 14 13:56:16:221 [140645050816256] 0 Controller: Going down... Sep 14 13:56:16:221 [140645050816256] 1 Controller: Sending 'gokususe is NOT alive' to hubs(192.168.3.75) Sep 14 13:56:16:222 [140645050816256] 3 Controller: SREQUEST: alive ->192.168.3.75/48002 Sep 14 13:56:16:222 [140645050816256] 3 Controller: RREPLY: status=OK(0) <-192.168.3.75/48002 h=37 d=0 fd=7 Sep 14 13:56:16:222 [140645050816256] 3 Controller: SREQUEST: _close ->192.168.3.75/48002 Sep 14 13:56:16:222 [140645050816256] 1 Controller: Stopping probe 'hdb' (pid=9431) Sep 14 13:56:16:222 [140645050816256] 3 Controller: portFind hdb Sep 14 13:56:16:222 [140645050816256] 3 Controller: (async)async_req 192.168.3.20/48007 - _stop Sep 14 13:56:16:222 [140645050816256] 2 Controller: Sent _stop to hdb (192.168.3.20/48007) Sep 14 13:56:16:222 [140645050816256] 1 Controller: Stopping probe 'spooler' (pid=9429) Sep 14 13:56:16:222 [140645050816256] 3 Controller: portFind spooler Sep 14 13:56:16:222 [140645050816256] 3 Controller: (async)async_req 192.168.3.20/48001 - _stop Sep 14 13:56:16:222 [140645050816256] 2 Controller: Sent _stop to spooler (192.168.3.20/48001) Sep 14 13:56:16:222 [140645050816256] 3 Controller: (async)cb_pacallback Sep 14 13:56:16:222 [140645050816256] 3 Controller: (async)cb_pacallback - diff = 0, cmd = _stop Sep 14 13:56:16:222 [140645050816256] 3 Controller: SREQUEST: _stop ->192.168.3.20/48001 Sep 14 13:56:16:222 [140645050816256] 3 Controller: (async)cb_pacallback Sep 14 13:56:16:222 [140645050816256] 3 Controller: (async)cb_pacallback - diff = 0, cmd = _stop Sep 14 13:56:16:222 [140645050816256] 3 Controller: SREQUEST: _stop ->192.168.3.20/48007 Sep 14 13:56:16:223 [140645050816256] 3 Controller: RREPLY: status=OK(0) <-192.168.3.20/48007 h=37 d=0 fd=7 Sep 14 13:56:16:223 [140645050816256] 3 Controller: (async)cb_pacallback Sep 14 13:56:16:223 [140645050816256] 3 Controller: (async)cb_pacallback - diff = 0, cmd = _stop Sep 14 13:56:16:223 [140645050816256] 3 Controller: cb_pacallback - cb_reply from 192.168.3.20/48007 Sep 14 13:56:16:223 [140645050816256] 3 Controller: SREQUEST: _close ->192.168.3.20/48007 Sep 14 13:56:16:223 [140645050816256] 3 Controller: RREPLY: status=OK(0) <-192.168.3.20/48001 h=37 d=0 fd=8 Sep 14 13:56:16:223 [140645050816256] 3 Controller: (async)cb_pacallback Sep 14 13:56:16:223 [140645050816256] 3 Controller: (async)cb_pacallback - diff = 0, cmd = _stop Sep 14 13:56:16:223 [140645050816256] 3 Controller: cb_pacallback - cb_reply from 192.168.3.20/48001 Sep 14 13:56:16:223 [140645050816256] 3 Controller: SREQUEST: _close ->192.168.3.20/48001 Sep 14 13:56:16:223 [140645050816256] 3 Controller: RREQUEST: port_unregister <-192.168.3.20/53042 h=117 d=13 fd=7 Sep 14 13:56:16:223 [140645050816256] 1 Controller: port_unregister (hdb) from 192.168.3.20/53042 Sep 14 13:56:16:223 [140645050816256] 2 Controller: portUnregister - name=hdb, pid=0 Sep 14 13:56:16:223 [140645050816256] 3 Controller: FindNamePid hdb - 0 Sep 14 13:56:16:223 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.20/53042 Sep 14 13:56:16:223 [140645050816256] 3 Controller: RREQUEST: _close <-192.168.3.20/53042 h=107 d=0 fd=7 Sep 14 13:56:20:130 [140645050816256] 3 Controller: RREQUEST: get_info <-192.168.3.71/63245 h=361 d=17 fd=7 Sep 14 13:56:20:130 [140645050816256] 1 Controller: get_info from 192.168.3.71/63245 Sep 14 13:56:20:130 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.71/63245 Sep 14 13:56:20:139 [140645050816256] 3 Controller: RREQUEST: _close <-192.168.3.71/63245 h=359 d=0 fd=7 Sep 14 13:56:21:223 [140645050816256] 3 Controller: RREQUEST: port_unregister <-192.168.3.20/53044 h=117 d=17 fd=7 Sep 14 13:56:21:223 [140645050816256] 1 Controller: port_unregister (spooler) from 192.168.3.20/53044 Sep 14 13:56:21:223 [140645050816256] 2 Controller: portUnregister - name=spooler, pid=0 Sep 14 13:56:21:223 [140645050816256] 3 Controller: FindNamePid spooler - 0 Sep 14 13:56:21:223 [140645050816256] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.20/53044 Sep 14 13:56:21:224 [140645050816256] 3 Controller: RREQUEST: _close <-192.168.3.20/53044 h=107 d=0 fd=7 Sep 14 13:56:24:227 [140645050816256] 1 Controller: Process stopped (probe=spooler, pid=9429) Sep 14 13:56:24:227 [140645050816256] 1 Controller: Process stopped (probe=hdb, pid=9431) Sep 14 13:56:24:227 [140645050816256] 0 Controller: Down Sep 14 13:56:24:227 [140645050816256] 2 Controller: nimEnd Sep 14 13:56:27:571 [140022815602432] 3 Controller: Controller - logging options set Sep 14 13:56:27:571 [140022815602432] 1 Controller: robot_env read - error, read pds from file '/opt/nimsoft/robot/robot_env.sds' failed Sep 14 13:56:27:571 [140022815602432] 1 Controller: robot_env read - error, read failed, file = '/opt/nimsoft/robot/robot_env.sds', rc = 1663181720 (unknown error) Sep 14 13:56:27:571 [140022815602432] 0 Controller: Selecting robotip from configuration. config_robotip = 192.168.3.20, cglob robotip = 192.168.3.20, local_ip_validation = 1, validate_ip_suggestion = 0, strict_ip_binding = 0 Sep 14 13:56:27:571 [140022815602432] 2 Controller: check_configured_ip - local ip list = |||192.168.3.20|fe80::20c:29ff:fe1e:3efc| Sep 14 13:56:27:571 [140022815602432] 3 Controller: IsIPInList ip=192.168.3.20, list=|||192.168.3.20|fe80::20c:29ff:fe1e:3efc|, found=1 Sep 14 13:56:27:571 [140022815602432] 1 Controller: Explicit controller to hub login enabled Sep 14 13:56:27:571 [140022815602432] 2 Controller: MyPutEnv LD_LIBRARY_PATH=.:$LD_LIBRARY_PATH Sep 14 13:56:27:571 [140022815602432] 2 Controller: LD_LIBRARY_PATH=.:$LD_LIBRARY_PATH Sep 14 13:56:27:571 [140022815602432] 1 Controller: (parserobotcfg) calling LoadControllerPlugins refresh. Default path is /opt/nimsoft/plugins Sep 14 13:56:27:571 [140022815602432] 3 Controller: validating character encoding of config file: /opt/nimsoft/robot/robot.cfg Sep 14 13:56:27:571 [140022815602432] 3 Controller: validating character encoding of config file: /opt/nimsoft/robot/spooler.cfg Sep 14 13:56:27:571 [140022815602432] 2 Controller: nimCharsetSet() - charset= Sep 14 13:56:27:571 [140022815602432] 3 Controller: Controller - set logging options Sep 14 13:56:27:571 [140022815602432] 0 Controller: -------------------------------------------------------------------------------------------------------- Sep 14 13:56:27:571 [140022815602432] 0 Controller: ----- Robot controller 9.35 [Build 9.35.240, May 10 2022] started ----- Sep 14 13:56:27:571 [140022815602432] 0 Controller: Name = gokususe, IP = 192.168.3.20, Port = 48000 Sep 14 13:56:27:571 [140022815602432] 0 Controller: OS = UNIX / Linux / Linux 4.12.14-122.37-default #1 SMP Sun Sep 6 05:00:36 UTC 2020 (fe8cacf) x86_64 Sep 14 13:56:27:571 [140022815602432] 0 Controller: Domain = hubp_domain Sep 14 13:56:27:571 [140022815602432] 0 Controller: Primary HUB = /hubp_domain/hubs/hubs 192.168.3.75 Sep 14 13:56:27:571 [140022815602432] 0 Controller: Loglevel = 3, Logfile = controller.log Sep 14 13:56:27:571 [140022815602432] 1 Controller: System Uptime QoS = no Sep 14 13:56:27:571 [140022815602432] 3 Controller: Cluster_support = 0 Sep 14 13:56:27:571 [140022815602432] 1 Controller: major=LINUX minor=LINUX_222_64 Sep 14 13:56:27:571 [140022815602432] 1 Controller: Robot device ID = D3AAB9F270FA51254C9B8262FDB2AC12F Sep 14 13:56:27:571 [140022815602432] 2 Controller: MyPutEnv NIM_DEVICE_ID=D3AAB9F270FA51254C9B8262FDB2AC12F Sep 14 13:56:27:571 [140022815602432] 2 Controller: NIM_DEVICE_ID=D3AAB9F270FA51254C9B8262FDB2AC12F Sep 14 13:56:27:571 [140022815602432] 2 Controller: ciOpen - initializing global CI cache Sep 14 13:56:27:571 [140022815602432] 2 Controller: ciSave - saving CI [C90AE95468CB75297AC9FE39B085B9821] Sep 14 13:56:27:571 [140022815602432] 2 Controller: ciSaveMetric - saving MET [MD3C6C6D917992BACDDE50C451A6DA16F] 10.2:5 Sep 14 13:56:27:571 [140022815602432] 1 Controller: Robot state metric ID = MD3C6C6D917992BACDDE50C451A6DA16F Sep 14 13:56:27:571 [140022815602432] 1 Controller: File validation information cache not loaded Sep 14 13:56:27:571 [140022815602432] 0 Controller: Running as user root (0) Sep 14 13:56:27:571 [140022815602432] 0 Controller: ----- Sep 14 13:56:27:572 [140022815602432] 3 Controller: Controller - fetch expire information Sep 14 13:56:27:572 [140022815602432] 2 Controller: expire/fetch_expire - find full path to expire.cfg Sep 14 13:56:27:572 [140022815602432] 2 Controller: expire/fetch_expire - allocate space for /opt/nimsoft/robot/expire.cfg Sep 14 13:56:27:572 [140022815602432] 2 Controller: expire/fetch_expire - check access to /opt/nimsoft/robot/expire.cfg Sep 14 13:56:27:572 [140022815602432] 2 Controller: expire/fetch_expire - CRC check Sep 14 13:56:27:572 [140022815602432] 2 Controller: expire/VerifyCrc - /opt/nimsoft/robot/expire.cfg, /opt/nimsoft/robot/expire.crc Sep 14 13:56:27:572 [140022815602432] 2 Controller: expire/VerifyCrc - generate checksum based on robot name Sep 14 13:56:27:572 [140022815602432] 2 Controller: expire/gen_key /opt/nimsoft/robot/expire.cfg Sep 14 13:56:27:572 [140022815602432] 2 Controller: expire/gen_key g49tUBqdY5Oars+JujNnPA== Sep 14 13:56:27:572 [140022815602432] 2 Controller: expire/gen_key gokususe Sep 14 13:56:27:572 [140022815602432] 2 Controller: expire/gen_key 3Tb4hp+lJWbCM3iNpKA50+PNILVFCfONzXXF0dh95jCy/xdeuBpUSuslFVuIAOve Sep 14 13:56:27:572 [140022815602432] 2 Controller: expire/VerifyCrc - open crc file and compare Sep 14 13:56:27:572 [140022815602432] 3 Controller: expire/VerifyCrc - found: 1 Sep 14 13:56:27:572 [140022815602432] 2 Controller: expire/fetch_expire - ok; read Sep 14 13:56:27:572 [140022815602432] 2 Controller: expire/fetch_expire - done Sep 14 13:56:27:572 [140022815602432] 2 Controller: Change directory to /opt/nimsoft Sep 14 13:56:27:572 [140022815602432] 3 Controller: validating character encoding of config file: /opt/nimsoft/robot/controller.cfg Sep 14 13:56:27:572 [140022815602432] 2 Controller: nimSessionServer - port = 48000 Sep 14 13:56:27:572 [140022815602432] 2 Controller: sockServer - 0x22bf710:0.0.0.0/48000:fd=5 Sep 14 13:56:27:572 [140022815602432] 0 Controller: Controller on gokususe port 48000 started Sep 14 13:56:27:572 [140022815602432] 2 Controller: nimSessionServer - port = 48000 Sep 14 13:56:27:572 [140022815602432] 2 Controller: sockServer - 0x22c5b10:0.0.0.0/48000:fd=6 Sep 14 13:56:27:572 [140022815602432] 3 Controller: validating character encoding of config file: /opt/nimsoft/robot/controller.cfg Sep 14 13:56:27:572 [140022815602432] 2 Controller: portRegister - name=controller, port=48000, ip=, pid=9467 Sep 14 13:56:27:572 [140022815602432] 3 Controller: FindNamePid controller - 9467 Sep 14 13:56:27:572 [140022815602432] 3 Controller: reserve_port (controller) - assigned to 48000 Sep 14 13:56:28:573 [140022815602432] 1 Controller: Internal queue statistics: to hub queued(current 0, highpoint 0) inprogress(current 0, highpoint 0) to probe queued(current 0, highpoint 0) Sep 14 13:56:28:573 [140022815602432] 2 Controller: Try primary hub Sep 14 13:56:28:573 [140022815602432] 3 Controller: dorobotup - Sep 14 13:56:28:573 [140022815602432] 3 Controller: hubdomain=hubp_domain Sep 14 13:56:28:573 [140022815602432] 3 Controller: hubname=hubs Sep 14 13:56:28:573 [140022815602432] 3 Controller: hubip=192.168.3.75, hubport=48002 Sep 14 13:56:28:573 [140022815602432] 3 Controller: hub_dns_name= Sep 14 13:56:28:573 [140022815602432] 3 Controller: robotip_alias= Sep 14 13:56:28:573 [140022815602432] 1 Controller: 'robotup' to hubs(192.168.3.75) for gokususe Sep 14 13:56:28:574 [140022815602432] 3 Controller: SREQUEST: robotup ->192.168.3.75/48002 Sep 14 13:56:28:574 [140022815602432] 3 Controller: RREPLY: status=OK(0) <-192.168.3.75/48002 h=37 d=217 fd=7 Sep 14 13:56:28:574 [140022815602432] 3 Controller: SREQUEST: _close ->192.168.3.75/48002 Sep 14 13:56:28:574 [140022815602432] 1 Controller: AuditEnable - Disable Sep 14 13:56:28:574 [140022815602432] 0 Controller: Hub hubs(192.168.3.75) contact established Sep 14 13:56:28:574 [140022815602432] 2 Controller: origin_mode from hub: pending=hubs, hubok=1, which_hub=PRIMARY Sep 14 13:56:28:575 [140022815602432] 2 Controller: origin_mode updated origin from pending: old="" new="hubs" Sep 14 13:56:28:575 [140022815602432] 2 Controller: origin_mode is INHERITED (primary): hubs Sep 14 13:56:28:575 [140022815602432] 1 Controller: dorobotup - cglob.robotip_alias = Sep 14 13:56:28:575 [140022815602432] 1 Controller: dorobotup - robotip_alias = Sep 14 13:56:28:575 [140022815602432] 3 Controller: set which_hub=0 Sep 14 13:56:28:575 [140022815602432] 2 Controller: origin_mode is INHERITED (primary): hubs Sep 14 13:56:28:575 [140022815602432] 3 Controller: validating character encoding of config file: /opt/nimsoft/robot/robot.cfg Sep 14 13:56:28:575 [140022815602432] 3 Controller: NimCryptographerEncryptPds using crypto mode TWOFISH Sep 14 13:56:28:575 [140022815602432] 3 Controller: SREQUEST: login ->192.168.3.75/48002 Sep 14 13:56:28:576 [140022815602432] 3 Controller: RREPLY: status=OK(0) <-192.168.3.75/48002 h=37 d=171 fd=7 Sep 14 13:56:28:576 [140022815602432] 3 Controller: SREQUEST: _close ->192.168.3.75/48002 Sep 14 13:56:28:576 [140022815602432] 1 Controller: Controller hub login completed successfully Sep 14 13:56:28:576 [140022815602432] 2 Controller: medt_timeout; hubok = 1, hubnocontact = 0 Sep 14 13:56:28:576 [140022815602432] 3 Controller: SREQUEST: probelist ->192.168.3.75/48002 Sep 14 13:56:28:576 [140022815602432] 3 Controller: RREPLY: status=OK(0) <-192.168.3.75/48002 h=37 d=178 fd=7 Sep 14 13:56:28:577 [140022815602432] 3 Controller: SREQUEST: _close ->192.168.3.75/48002 Sep 14 13:56:28:577 [140022815602432] 1 Controller: probeportlist sent to hub hubs(192.168.3.75) Sep 14 13:56:28:577 [140022815602432] 3 Controller: restart probes if env changed - Initial save of env values completed. Sep 14 13:56:28:577 [140022815602432] 3 Controller: probe deploy - deploy file 'request.cfg' does not exist, do not make requests to deploy probes Sep 14 13:56:28:577 [140022815602432] 3 Controller: probe deploy - success or nothing to do, rc=0 (OK) Sep 14 13:56:28:577 [140022815602432] 0 Controller: _ProcStart - Probe 'spooler' - starting Sep 14 13:56:28:577 [140022815602432] 3 Controller: probeGenerateMagicKey for spooler Sep 14 13:56:28:577 [140022815602432] 3 Controller: probeFindCRCs for spooler Sep 14 13:56:28:624 [140022815602432] 3 Controller: probeFindCRCs - 0 Sep 14 13:56:28:624 [140022815602432] 3 Controller: probeGenerateMagicKey - 0P1ffOhinYU1bLuq3PM/mqHVVJ4XJFzx1Ea9CSMPpufcd5nJQgYwzbdqODINDFysjcemiWf0xjNKf36LOZS3Yz+q+xYaNQIeDn4/3Jd6oTgbq5oV0u54h79FTm4jd5ou Sep 14 13:56:28:624 [140022815602432] 3 Controller: reserve_port (spooler) starting at 48000 Sep 14 13:56:28:624 [140022815602432] 3 Controller: reserve_port (spooler) - assigned to 48001 Sep 14 13:56:28:624 [140022815602432] 2 Controller: MyStringExpand (spooler)... Sep 14 13:56:28:625 [140022815602432] 1 Controller: Probe 'spooler' started (pid=9469) Sep 14 13:56:28:626 [140022815602432] 3 Controller: RREQUEST: probe_checkin <-192.168.3.20/53052 h=115 d=30 fd=7 Sep 14 13:56:28:626 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.20/53052 Sep 14 13:56:28:626 [140022815602432] 3 Controller: RREQUEST: _close <-192.168.3.20/53052 h=107 d=0 fd=7 Sep 14 13:56:28:626 [140022815602432] 3 Controller: RREQUEST: gethub <-192.168.3.20/53054 h=107 d=0 fd=7 Sep 14 13:56:28:626 [140022815602432] 1 Controller: gethub from 192.168.3.20/53054 Sep 14 13:56:28:626 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.20/53054 Sep 14 13:56:28:626 [140022815602432] 3 Controller: RREQUEST: _close <-192.168.3.20/53054 h=107 d=0 fd=7 Sep 14 13:56:28:626 [140022815602432] 3 Controller: RREQUEST: gethub <-192.168.3.20/53056 h=107 d=0 fd=7 Sep 14 13:56:28:626 [140022815602432] 1 Controller: gethub from 192.168.3.20/53056 Sep 14 13:56:28:626 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.20/53056 Sep 14 13:56:28:627 [140022815602432] 3 Controller: RREQUEST: _close <-192.168.3.20/53056 h=107 d=0 fd=7 Sep 14 13:56:28:627 [140022815602432] 3 Controller: RREQUEST: port_register <-192.168.3.20/53058 h=115 d=32 fd=7 Sep 14 13:56:28:627 [140022815602432] 1 Controller: port_register (spooler) from 192.168.3.20/53058 Sep 14 13:56:28:627 [140022815602432] 2 Controller: portRegister - name=spooler, port=48001, ip=192.168.3.20, pid=0 Sep 14 13:56:28:627 [140022815602432] 3 Controller: FindNamePid spooler - 0 Sep 14 13:56:28:627 [140022815602432] 3 Controller: reserve_port (spooler) - updated from 48001 to 48001 Sep 14 13:56:28:628 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.20/53058 Sep 14 13:56:28:628 [140022815602432] 3 Controller: RREQUEST: _close <-192.168.3.20/53058 h=107 d=0 fd=7 Sep 14 13:56:29:629 [140022815602432] 0 Controller: _ProcStart - Probe 'hdb' - starting Sep 14 13:56:29:629 [140022815602432] 3 Controller: probeGenerateMagicKey for hdb Sep 14 13:56:29:629 [140022815602432] 3 Controller: probeFindCRCs for hdb Sep 14 13:56:29:677 [140022815602432] 3 Controller: probeFindCRCs - 0 Sep 14 13:56:29:677 [140022815602432] 3 Controller: probeGenerateMagicKey - 0P1ffOhinYU1bLuq3PM/mqHVVJ4XJFzx1Ea9CSMPpufcd5nJQgYwzbdqODINDFysjcemiWf0xjNKf36LOZS3Yz+q+xYaNQIeDn4/3Jd6oTg5U4zWh85+sWP/BH4/Te0B Sep 14 13:56:29:677 [140022815602432] 3 Controller: reserve_port (hdb) starting at 48000 Sep 14 13:56:29:677 [140022815602432] 3 Controller: reserve_port (hdb) - assigned to 48007 Sep 14 13:56:29:677 [140022815602432] 2 Controller: MyStringExpand (hdb)... Sep 14 13:56:29:677 [140022815602432] 1 Controller: Probe 'hdb' started (pid=9471) Sep 14 13:56:29:679 [140022815602432] 3 Controller: RREQUEST: probe_checkin <-192.168.3.20/53060 h=115 d=31 fd=7 Sep 14 13:56:29:679 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.20/53060 Sep 14 13:56:29:679 [140022815602432] 3 Controller: RREQUEST: _close <-192.168.3.20/53060 h=107 d=0 fd=7 Sep 14 13:56:29:679 [140022815602432] 3 Controller: RREQUEST: port_register <-192.168.3.20/53062 h=115 d=28 fd=7 Sep 14 13:56:29:679 [140022815602432] 1 Controller: port_register (hdb) from 192.168.3.20/53062 Sep 14 13:56:29:679 [140022815602432] 2 Controller: portRegister - name=hdb, port=48007, ip=192.168.3.20, pid=0 Sep 14 13:56:29:679 [140022815602432] 3 Controller: FindNamePid hdb - 0 Sep 14 13:56:29:679 [140022815602432] 3 Controller: reserve_port (hdb) - updated from 48007 to 48007 Sep 14 13:56:29:679 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.20/53062 Sep 14 13:56:29:679 [140022815602432] 3 Controller: RREQUEST: _close <-192.168.3.20/53062 h=107 d=0 fd=7 Sep 14 13:56:34:346 [140022815602432] 3 Controller: RREQUEST: get_info <-192.168.3.65/62804 h=435 d=0 fd=7 Sep 14 13:56:34:346 [140022815602432] 1 Controller: get_info from 192.168.3.65/62804 Sep 14 13:56:34:346 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62804 Sep 14 13:56:34:346 [140022815602432] 3 Controller: RREQUEST: _close <-192.168.3.65/62804 h=433 d=0 fd=7 Sep 14 13:56:34:347 [140022815602432] 3 Controller: RREQUEST: probe_list <-192.168.3.65/62805 h=438 d=13 fd=7 Sep 14 13:56:34:347 [140022815602432] 2 Controller: nimVerifyLogin robot Sep 14 13:56:34:348 [140022815602432] 3 Controller: SREQUEST: verify_login ->192.168.3.75/48002 Sep 14 13:56:34:348 [140022815602432] 3 Controller: RREPLY: status=OK(0) <-192.168.3.75/48002 h=37 d=56 fd=8 Sep 14 13:56:34:348 [140022815602432] 3 Controller: SREQUEST: _close ->192.168.3.75/48002 Sep 14 13:56:34:348 [140022815602432] 1 Controller: probe_list (hdb) from 192.168.3.65/62805 Sep 14 13:56:34:348 [140022815602432] 3 Controller: portFind hdb Sep 14 13:56:34:348 [140022815602432] 3 Controller: portFind hdb Sep 14 13:56:34:348 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62805 Sep 14 13:56:34:348 [140022815602432] 3 Controller: RREQUEST: _close <-192.168.3.65/62805 h=433 d=0 fd=7 Sep 14 13:56:35:151 [140022815602432] 3 Controller: RREQUEST: probe_list <-192.168.3.71/63308 h=364 d=0 fd=7 Sep 14 13:56:35:151 [140022815602432] 2 Controller: nimVerifyLogin robot Sep 14 13:56:35:152 [140022815602432] 3 Controller: SREQUEST: verify_login ->192.168.3.75/48002 Sep 14 13:56:35:152 [140022815602432] 3 Controller: RREPLY: status=OK(0) <-192.168.3.75/48002 h=37 d=56 fd=8 Sep 14 13:56:35:152 [140022815602432] 3 Controller: SREQUEST: _close ->192.168.3.75/48002 Sep 14 13:56:35:152 [140022815602432] 1 Controller: probe_list from 192.168.3.71/63308 Sep 14 13:56:35:152 [140022815602432] 3 Controller: portFind controller Sep 14 13:56:35:152 [140022815602432] 3 Controller: portFind controller Sep 14 13:56:35:152 [140022815602432] 3 Controller: portFind spooler Sep 14 13:56:35:152 [140022815602432] 3 Controller: portFind spooler Sep 14 13:56:35:152 [140022815602432] 3 Controller: portFind hdb Sep 14 13:56:35:152 [140022815602432] 3 Controller: portFind hdb Sep 14 13:56:35:152 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.71/63308 Sep 14 13:56:35:153 [140022815602432] 3 Controller: RREQUEST: port_list <-192.168.3.71/63308 h=363 d=0 fd=7 Sep 14 13:56:35:153 [140022815602432] 1 Controller: port_list from 192.168.3.71/63308 Sep 14 13:56:35:153 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.71/63308 Sep 14 13:56:35:856 [140022815602432] 3 Controller: RREQUEST: probe_tail_logfile <-192.168.3.65/62810 h=446 d=45 fd=8 Sep 14 13:56:35:856 [140022815602432] 2 Controller: nimVerifyLogin robot Sep 14 13:56:35:857 [140022815602432] 3 Controller: SREQUEST: verify_login ->192.168.3.75/48002 Sep 14 13:56:35:857 [140022815602432] 3 Controller: RREPLY: status=OK(0) <-192.168.3.75/48002 h=37 d=56 fd=9 Sep 14 13:56:35:857 [140022815602432] 3 Controller: SREQUEST: _close ->192.168.3.75/48002 Sep 14 13:56:35:857 [140022815602432] 3 Controller: probe_tail_logfile (hdb) from 192.168.3.65/62810 Sep 14 13:56:35:858 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62810 Sep 14 13:56:35:981 [140022815602432] 3 Controller: RREQUEST: probe_list <-192.168.3.71/63309 h=364 d=0 fd=9 Sep 14 13:56:35:981 [140022815602432] 2 Controller: nimVerifyLogin robot Sep 14 13:56:35:982 [140022815602432] 3 Controller: SREQUEST: verify_login ->192.168.3.75/48002 Sep 14 13:56:35:982 [140022815602432] 3 Controller: RREPLY: status=OK(0) <-192.168.3.75/48002 h=37 d=56 fd=10 Sep 14 13:56:35:982 [140022815602432] 3 Controller: SREQUEST: _close ->192.168.3.75/48002 Sep 14 13:56:35:982 [140022815602432] 1 Controller: probe_list from 192.168.3.71/63309 Sep 14 13:56:35:982 [140022815602432] 3 Controller: portFind controller Sep 14 13:56:35:982 [140022815602432] 3 Controller: portFind controller Sep 14 13:56:35:982 [140022815602432] 3 Controller: portFind spooler Sep 14 13:56:35:982 [140022815602432] 3 Controller: portFind spooler Sep 14 13:56:35:982 [140022815602432] 3 Controller: portFind hdb Sep 14 13:56:35:982 [140022815602432] 3 Controller: portFind hdb Sep 14 13:56:35:982 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.71/63309 Sep 14 13:56:35:983 [140022815602432] 3 Controller: RREQUEST: port_list <-192.168.3.71/63309 h=363 d=0 fd=9 Sep 14 13:56:35:983 [140022815602432] 1 Controller: port_list from 192.168.3.71/63309 Sep 14 13:56:35:983 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.71/63309 Sep 14 13:56:35:984 [140022815602432] 3 Controller: RREQUEST: _close <-192.168.3.71/63308 h=359 d=0 fd=7 Sep 14 13:56:35:990 [140022815602432] 3 Controller: RREQUEST: _close <-192.168.3.71/63309 h=359 d=0 fd=9 Sep 14 13:56:36:982 [140022815602432] 3 Controller: RREQUEST: probe_tail_logfile <-192.168.3.65/62810 h=446 d=45 fd=8 Sep 14 13:56:36:982 [140022815602432] 3 Controller: probe_tail_logfile (hdb) from 192.168.3.65/62810 Sep 14 13:56:36:983 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62810 Sep 14 13:56:37:979 [140022815602432] 3 Controller: RREQUEST: probe_tail_logfile <-192.168.3.65/62810 h=446 d=45 fd=8 Sep 14 13:56:37:979 [140022815602432] 3 Controller: probe_tail_logfile (hdb) from 192.168.3.65/62810 Sep 14 13:56:37:979 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62810 Sep 14 13:56:38:293 [140022815602432] 3 Controller: RREQUEST: _close <-192.168.3.65/62810 h=433 d=0 fd=8 Sep 14 13:56:39:295 [140022815602432] 2 Controller: medt_timeout; hubok = 1, hubnocontact = 0 Sep 14 13:56:39:295 [140022815602432] 3 Controller: SREQUEST: probelist ->192.168.3.75/48002 Sep 14 13:56:39:296 [140022815602432] 3 Controller: RREPLY: status=OK(0) <-192.168.3.75/48002 h=37 d=178 fd=7 Sep 14 13:56:39:296 [140022815602432] 3 Controller: SREQUEST: _close ->192.168.3.75/48002 Sep 14 13:56:39:296 [140022815602432] 1 Controller: probeportlist sent to hub hubs(192.168.3.75) Sep 14 13:56:43:290 [140022815602432] 3 Controller: RREQUEST: get_info <-192.168.3.65/62818 h=435 d=0 fd=7 Sep 14 13:56:43:290 [140022815602432] 1 Controller: get_info from 192.168.3.65/62818 Sep 14 13:56:43:290 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62818 Sep 14 13:56:43:290 [140022815602432] 3 Controller: RREQUEST: _close <-192.168.3.65/62818 h=433 d=0 fd=7 Sep 14 13:56:43:291 [140022815602432] 3 Controller: RREQUEST: probe_list <-192.168.3.65/62819 h=438 d=21 fd=7 Sep 14 13:56:43:291 [140022815602432] 2 Controller: nimVerifyLogin robot Sep 14 13:56:43:291 [140022815602432] 3 Controller: SREQUEST: verify_login ->192.168.3.75/48002 Sep 14 13:56:43:292 [140022815602432] 3 Controller: RREPLY: status=OK(0) <-192.168.3.75/48002 h=37 d=55 fd=8 Sep 14 13:56:43:292 [140022815602432] 3 Controller: SREQUEST: _close ->192.168.3.75/48002 Sep 14 13:56:43:292 [140022815602432] 1 Controller: probe_list (controller) from 192.168.3.65/62819 Sep 14 13:56:43:292 [140022815602432] 3 Controller: portFind controller Sep 14 13:56:43:292 [140022815602432] 3 Controller: portFind controller Sep 14 13:56:43:292 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62819 Sep 14 13:56:43:292 [140022815602432] 3 Controller: RREQUEST: _close <-192.168.3.65/62819 h=433 d=0 fd=7 Sep 14 13:56:44:801 [140022815602432] 3 Controller: RREQUEST: probe_tail_logfile <-192.168.3.65/62820 h=446 d=53 fd=7 Sep 14 13:56:44:801 [140022815602432] 2 Controller: nimVerifyLogin robot Sep 14 13:56:44:802 [140022815602432] 3 Controller: SREQUEST: verify_login ->192.168.3.75/48002 Sep 14 13:56:44:802 [140022815602432] 3 Controller: RREPLY: status=OK(0) <-192.168.3.75/48002 h=37 d=56 fd=8 Sep 14 13:56:44:802 [140022815602432] 3 Controller: SREQUEST: _close ->192.168.3.75/48002 Sep 14 13:56:44:802 [140022815602432] 3 Controller: probe_tail_logfile (controller) from 192.168.3.65/62820 Sep 14 13:56:44:802 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62820 Sep 14 13:56:45:917 [140022815602432] 3 Controller: RREQUEST: probe_tail_logfile <-192.168.3.65/62820 h=446 d=53 fd=7 Sep 14 13:56:45:917 [140022815602432] 3 Controller: probe_tail_logfile (controller) from 192.168.3.65/62820 Sep 14 13:56:45:917 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62820 Sep 14 13:56:46:933 [140022815602432] 3 Controller: RREQUEST: probe_tail_logfile <-192.168.3.65/62820 h=446 d=53 fd=7 Sep 14 13:56:46:933 [140022815602432] 3 Controller: probe_tail_logfile (controller) from 192.168.3.65/62820 Sep 14 13:56:46:933 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62820 Sep 14 13:56:47:948 [140022815602432] 3 Controller: RREQUEST: probe_tail_logfile <-192.168.3.65/62820 h=446 d=53 fd=7 Sep 14 13:56:47:948 [140022815602432] 3 Controller: probe_tail_logfile (controller) from 192.168.3.65/62820 Sep 14 13:56:47:948 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62820 Sep 14 13:56:48:842 [140022815602432] 3 Controller: RREQUEST: _close <-192.168.3.65/62820 h=433 d=0 fd=7 Sep 14 13:56:50:151 [140022815602432] 2 Controller: medt_timeout; hubok = 1, hubnocontact = 0 Sep 14 13:56:50:151 [140022815602432] 3 Controller: SREQUEST: set_hub ->192.168.3.20/48001 Sep 14 13:56:50:152 [140022815602432] 3 Controller: RREPLY: status=OK(0) <-192.168.3.20/48001 h=37 d=47 fd=8 Sep 14 13:56:50:152 [140022815602432] 3 Controller: SREQUEST: _close ->192.168.3.20/48001 Sep 14 13:56:50:152 [140022815602432] 1 Controller: set_hub sent to spooler hub = hubs(192.168.3.75) ON Sep 14 13:56:50:152 [140022815602432] 3 Controller: RREQUEST: probe_list <-192.168.3.71/63395 h=364 d=0 fd=7 Sep 14 13:56:50:152 [140022815602432] 2 Controller: nimVerifyLogin robot Sep 14 13:56:50:152 [140022815602432] 3 Controller: SREQUEST: verify_login ->192.168.3.75/48002 Sep 14 13:56:50:152 [140022815602432] 3 Controller: RREPLY: status=OK(0) <-192.168.3.75/48002 h=37 d=55 fd=8 Sep 14 13:56:50:152 [140022815602432] 3 Controller: SREQUEST: _close ->192.168.3.75/48002 Sep 14 13:56:50:152 [140022815602432] 1 Controller: probe_list from 192.168.3.71/63395 Sep 14 13:56:50:152 [140022815602432] 3 Controller: portFind controller Sep 14 13:56:50:152 [140022815602432] 3 Controller: portFind controller Sep 14 13:56:50:152 [140022815602432] 3 Controller: portFind spooler Sep 14 13:56:50:152 [140022815602432] 3 Controller: portFind spooler Sep 14 13:56:50:152 [140022815602432] 3 Controller: portFind hdb Sep 14 13:56:50:152 [140022815602432] 3 Controller: portFind hdb Sep 14 13:56:50:153 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.71/63395 Sep 14 13:56:50:153 [140022815602432] 3 Controller: RREQUEST: port_list <-192.168.3.71/63395 h=363 d=0 fd=7 Sep 14 13:56:50:153 [140022815602432] 1 Controller: port_list from 192.168.3.71/63395 Sep 14 13:56:50:153 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.71/63395 Sep 14 13:56:50:161 [140022815602432] 3 Controller: RREQUEST: _close <-192.168.3.71/63395 h=359 d=0 fd=7 Sep 14 13:56:50:162 [140022815602432] 3 Controller: RREQUEST: probe_list <-192.168.3.71/63398 h=364 d=0 fd=8 Sep 14 13:56:50:162 [140022815602432] 2 Controller: nimVerifyLogin robot Sep 14 13:56:50:162 [140022815602432] 3 Controller: SREQUEST: verify_login ->192.168.3.75/48002 Sep 14 13:56:50:162 [140022815602432] 3 Controller: RREPLY: status=OK(0) <-192.168.3.75/48002 h=37 d=55 fd=7 Sep 14 13:56:50:162 [140022815602432] 3 Controller: SREQUEST: _close ->192.168.3.75/48002 Sep 14 13:56:50:162 [140022815602432] 1 Controller: probe_list from 192.168.3.71/63398 Sep 14 13:56:50:163 [140022815602432] 3 Controller: portFind controller Sep 14 13:56:50:163 [140022815602432] 3 Controller: portFind controller Sep 14 13:56:50:163 [140022815602432] 3 Controller: portFind spooler Sep 14 13:56:50:163 [140022815602432] 3 Controller: portFind spooler Sep 14 13:56:50:163 [140022815602432] 3 Controller: portFind hdb Sep 14 13:56:50:163 [140022815602432] 3 Controller: portFind hdb Sep 14 13:56:50:163 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.71/63398 Sep 14 13:56:50:163 [140022815602432] 3 Controller: RREQUEST: port_list <-192.168.3.71/63398 h=363 d=0 fd=8 Sep 14 13:56:50:163 [140022815602432] 1 Controller: port_list from 192.168.3.71/63398 Sep 14 13:56:50:163 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.71/63398 Sep 14 13:56:50:170 [140022815602432] 3 Controller: RREQUEST: _close <-192.168.3.71/63398 h=359 d=0 fd=8 Sep 14 13:57:01:248 [140022815602432] 2 Controller: medt_timeout; hubok = 1, hubnocontact = 0 Sep 14 13:57:02:494 [140022815602432] 3 Controller: RREQUEST: get_info <-192.168.3.65/62833 h=435 d=0 fd=7 Sep 14 13:57:02:494 [140022815602432] 1 Controller: get_info from 192.168.3.65/62833 Sep 14 13:57:02:494 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62833 Sep 14 13:57:02:494 [140022815602432] 3 Controller: RREQUEST: _close <-192.168.3.65/62833 h=433 d=0 fd=7 Sep 14 13:57:02:495 [140022815602432] 3 Controller: RREQUEST: probe_list <-192.168.3.65/62834 h=438 d=21 fd=7 Sep 14 13:57:02:495 [140022815602432] 2 Controller: nimVerifyLogin robot Sep 14 13:57:02:496 [140022815602432] 3 Controller: SREQUEST: verify_login ->192.168.3.75/48002 Sep 14 13:57:02:496 [140022815602432] 3 Controller: RREPLY: status=OK(0) <-192.168.3.75/48002 h=37 d=55 fd=8 Sep 14 13:57:02:496 [140022815602432] 3 Controller: SREQUEST: _close ->192.168.3.75/48002 Sep 14 13:57:02:496 [140022815602432] 1 Controller: probe_list (controller) from 192.168.3.65/62834 Sep 14 13:57:02:496 [140022815602432] 3 Controller: portFind controller Sep 14 13:57:02:496 [140022815602432] 3 Controller: portFind controller Sep 14 13:57:02:496 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62834 Sep 14 13:57:02:496 [140022815602432] 3 Controller: RREQUEST: _close <-192.168.3.65/62834 h=433 d=0 fd=7 Sep 14 13:57:02:497 [140022815602432] 3 Controller: RREQUEST: _status <-192.168.3.65/62835 h=434 d=0 fd=7 Sep 14 13:57:02:497 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62835 Sep 14 13:57:02:498 [140022815602432] 3 Controller: RREQUEST: _close <-192.168.3.65/62835 h=433 d=0 fd=7 Sep 14 13:57:02:498 [140022815602432] 3 Controller: RREQUEST: probe_config_get <-192.168.3.65/62836 h=445 d=21 fd=7 Sep 14 13:57:02:498 [140022815602432] 2 Controller: nimVerifyLogin robot Sep 14 13:57:02:499 [140022815602432] 3 Controller: SREQUEST: verify_login ->192.168.3.75/48002 Sep 14 13:57:02:499 [140022815602432] 3 Controller: RREPLY: status=OK(0) <-192.168.3.75/48002 h=37 d=55 fd=8 Sep 14 13:57:02:499 [140022815602432] 3 Controller: SREQUEST: _close ->192.168.3.75/48002 Sep 14 13:57:02:499 [140022815602432] 3 Controller: (probe_config_get) - called from 192.168.3.65/62836 Sep 14 13:57:02:499 [140022792066816] 3 Controller: nimSession:0x22c94e0:7:192.168.3.65/62836:192.168.3.65/62836 - needs cross-thread locking Sep 14 13:57:02:499 [140022792066816] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62836 Sep 14 13:57:02:502 [140022815602432] 3 Controller: RREQUEST: _close <-192.168.3.65/62836 h=434 d=0 fd=7 Sep 14 13:57:02:502 [140022815602432] 3 Controller: RREQUEST: _status <-192.168.3.65/62837 h=434 d=0 fd=8 Sep 14 13:57:02:502 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62837 Sep 14 13:57:02:502 [140022815602432] 3 Controller: RREQUEST: _close <-192.168.3.65/62837 h=433 d=0 fd=8 Sep 14 13:57:02:503 [140022815602432] 3 Controller: RREQUEST: get_info <-192.168.3.65/62838 h=435 d=0 fd=7 Sep 14 13:57:02:503 [140022815602432] 1 Controller: get_info from 192.168.3.65/62838 Sep 14 13:57:02:503 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62838 Sep 14 13:57:02:503 [140022815602432] 3 Controller: RREQUEST: _close <-192.168.3.65/62838 h=433 d=0 fd=7 Sep 14 13:57:02:505 [140022815602432] 3 Controller: RREQUEST: gethub <-192.168.3.65/62839 h=433 d=0 fd=7 Sep 14 13:57:02:505 [140022815602432] 1 Controller: gethub from 192.168.3.65/62839 Sep 14 13:57:02:505 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62839 Sep 14 13:57:02:505 [140022815602432] 3 Controller: RREQUEST: _close <-192.168.3.65/62839 h=433 d=0 fd=7 Sep 14 13:57:02:508 [140022815602432] 3 Controller: RREQUEST: gethub <-192.168.3.65/62840 h=433 d=0 fd=7 Sep 14 13:57:02:508 [140022815602432] 1 Controller: gethub from 192.168.3.65/62840 Sep 14 13:57:02:508 [140022815602432] 3 Controller: SREPLY: status = 0(OK) ->192.168.3.65/62840 Sep 14 13:57:02:508 [140022815602432] 3 Controller: RREQUEST: _close <-192.168.3.65/62840 h=433 d=0 fd=7 Sep 14 13:57:02:517 [140022815602432] 3 Controller: RREQUEST: probe_config_get <-192.168.3.65/62844 h=444 d=53 fd=7 Sep 14 13:57:02:517 [140022815602432] 2 Controller: nimVerifyLogin robot Sep 14 13:57:02:518 [140022815602432] 3 Controller: SREQUEST: verify_login ->192.168.3.75/48002 Sep 14 13:57:02:518 [140022815602432] 3 Controller: RREPLY: status=OK(0) <-192.168.3.75/48002 h=37 d=55 fd=8 Sep 14 13:57:02:518 [140022815602432] 3 Controller: SREQUEST: _close ->192.168.3.75/48002 Sep 14 13:57:02:518 [140022815602432] 3 Controller: (probe_config_get) - called from 192.168.3.65/62844 Sep 14 13:57:02:518 [140022792066816] 2 Controller: handle_probe_config_get: finding value of section=/spooler, key=origin Sep 14 13:57:02:518 [140022792066816] 1 Controller: handle_probe_config_get : could not find value of section=/spooler, key=origin Sep 14 13:57:02:518 [140022792066816] 3 Controller: nimSession:0x22c94e0:7:192.168.3.65/62844:192.168.3.65/62844 - needs cross-thread locking Sep 14 13:57:02:518 [140022792066816] 3 Controller: SREPLY: status = 4(not found) ->192.168.3.65/62844 Sep 14 13:57:03:518 [140022815602432] 3 Controller: RREQUEST: _close <-192.168.3.65/62844 h=433 d=0 fd=7 Sep 14 13:57:09:557 [140022815602432] 3 Controller: RREQUEST: log_level <-192.168.3.65/62848 h=437 d=12 fd=7 Sep 14 13:57:09:557 [140022815602432] 2 Controller: nimVerifyLogin robot Sep 14 13:57:09:558 [140022815602432] 3 Controller: SREQUEST: verify_login ->192.168.3.75/48002 Sep 14 13:57:09:558 [140022815602432] 3 Controller: RREPLY: status=OK(0) <-192.168.3.75/48002 h=37 d=56 fd=8 Sep 14 13:57:09:558 [140022815602432] 3 Controller: SREQUEST: _close ->192.168.3.75/48002 Sep 14 13:57:10:628 [140022815602432] 0 Controller: Selecting robotip from configuration. config_robotip = 192.168.3.20, cglob robotip = 192.168.3.20, local_ip_validation = 1, validate_ip_suggestion = 0, strict_ip_binding = 0