OpenSAF / Tickets / #2687 rde: Missing rda callback causes opensafd failed to start

#2687 rde: Missing rda callback causes opensafd failed to start

Milestone: 5.18.02

Status: fixed

Owner: nobody

Labels: None

Type: defect

Component: rde

Part: d

Version:

Priority: major

Blocker: False

Updated: 2018-02-02

Created: 2017-11-19

Creator: Minh Hon Chau

Private: No

Syslog:
2017-11-15 15:00:57.754 SC-1 opensafd: Starting OpenSAF Services(5.18.01 - 87095e7ca1ba384c5ff8695462cf45a096a42f85) (Using TCP)
2017-11-15 15:00:57.761 SC-1 opensafd[112]: /etc/init.d/opensafd: 121: /etc/init.d/opensafd: cannot create /proc/sys/kernel/core_pattern: Read-only file system
2017-11-15 15:00:57.761 SC-1 opensafd[143]: logtrace: trace enabled to file 'opensafd.log', mask=0x0
2017-11-15 15:00:57.761 SC-1 opensafd[143]: NO spawn service: TRANSPORT
2017-11-15 15:00:57.775 SC-1 kernel:[16556.012681] eth0: renamed from vethI8F8U1
2017-11-15 15:00:57.794 SC-1 osafdtmd[154]: mkfifo already exists: /var/lib/opensaf/osafdtmd.fifo File exists
2017-11-15 15:00:57.795 SC-1 osafdtmd[154]: create_fifofile successfully
2017-11-15 15:00:57.796 SC-1 osafdtmd[154]: Started
2017-11-15 15:00:57.816 SC-1 osafdtmd[154]: nid_notify by aab49daa:TRANSPORT:1
2017-11-15 15:00:57.816 SC-1 opensafd[143]: NO start monitor service: TRANSPORT
2017-11-15 15:00:57.816 SC-1 opensafd[143]: NO spawn service: CLMNA
2017-11-15 15:00:57.823 SC-1 osaftransportd[161]: create_fifofile successfully
2017-11-15 15:00:57.823 SC-1 osaftransportd[161]: Started
2017-11-15 15:00:57.823 SC-1 opensafd[143]: NO Read fifo /var/lib/opensaf/osaftransportd.fifo successfully
2017-11-15 15:00:57.823 SC-1 opensafd[143]: NO Monitoring of TRANSPORT started
2017-11-15 15:00:57.873 SC-1 osafclmna[168]: create_fifofile successfully
2017-11-15 15:00:57.874 SC-1 osafclmna[168]: Started
2017-11-15 15:00:57.885 SC-1 osafclmna[168]: nid_notify by aab49daa:CLMNA:1
2017-11-15 15:00:57.885 SC-1 opensafd[143]: NO start monitor service: CLMNA
2017-11-15 15:00:57.885 SC-1 opensafd[143]: NO spawn service: RDE
2017-11-15 15:00:57.885 SC-1 opensafd[143]: NO Read fifo /var/lib/opensaf/osafclmna.fifo successfully
2017-11-15 15:00:57.885 SC-1 opensafd[143]: NO Monitoring of CLMNA started
2017-11-15 15:00:57.909 SC-1 osafrded[177]: create_fifofile successfully
2017-11-15 15:00:57.911 SC-1 osafrded[177]: Started
2017-11-15 15:00:57.912 SC-1 osafrded[177]: nid_notify by aab49daa:RDE:1
2017-11-15 15:00:57.915 SC-1 opensafd[143]: NO start monitor service: RDE
2017-11-15 15:00:57.915 SC-1 opensafd[143]: NO spawn service: HLFM
2017-11-15 15:00:57.915 SC-1 opensafd[143]: NO Read fifo /var/lib/opensaf/osafrded.fifo successfully
2017-11-15 15:00:57.915 SC-1 opensafd[143]: NO Monitoring of RDE started
2017-11-15 15:00:57.985 SC-1 osaffmd[186]: create_fifofile successfully
2017-11-15 15:00:58.017 SC-1 kernel:[16556.254796] IPv6: ADDRCONF(NETDEV_CHANGE): vethP5WNSX: link becomes ready
2017-11-15 15:00:58.023 SC-1 osaffmd[186]: Started
2017-11-15 15:00:58.023 SC-1 osaffmd[186]: NO Remote fencing is disabled
2017-11-15 15:00:58.035 SC-1 osaffmd[186]: nid_notify by aab49daa:HLFM:1
2017-11-15 15:00:58.035 SC-1 opensafd[143]: NO start monitor service: HLFM
2017-11-15 15:00:58.038 SC-1 opensafd[143]: NO spawn service: IMMD
2017-11-15 15:00:58.038 SC-1 opensafd[143]: NO Read fifo /var/lib/opensaf/osaffmd.fifo successfully
2017-11-15 15:00:58.038 SC-1 opensafd[143]: NO Monitoring of HLFM started
2017-11-15 15:00:58.085 SC-1 osafimmd[196]: create_fifofile successfully
2017-11-15 15:00:58.091 SC-1 osafimmd[196]: Started
2017-11-15 15:00:58.099 SC-1 osafclmna[168]: NO Starting to promote this node to a system controller
2017-11-15 15:00:58.100 SC-1 osafrded[177]: NO Requesting ACTIVE role
2017-11-15 15:00:58.100 SC-1 osafrded[177]: NO RDE role set to Undefined
2017-11-15 15:00:58.255 SC-1 kernel:[16556.489595] lxcbr0: port 5(vethNY9WFX) entered blocking state
2017-11-15 15:00:58.255 SC-1 kernel:[16556.489596] lxcbr0: port 5(vethNY9WFX) entered disabled state
2017-11-15 15:00:58.255 SC-1 kernel:[16556.490326] device vethNY9WFX entered promiscuous mode
2017-11-15 15:00:58.255 SC-1 kernel:[16556.490392] IPv6: ADDRCONF(NETDEV_UP): vethNY9WFX: link is not ready
2017-11-15 15:00:58.255 SC-1 kernel:[16556.490394] lxcbr0: port 5(vethNY9WFX) entered blocking state
2017-11-15 15:00:58.255 SC-1 kernel:[16556.490396] lxcbr0: port 5(vethNY9WFX) entered forwarding state
2017-11-15 15:00:58.584 SC-1 osafdtmd[154]: NO Established contact with 'SC-2'
2017-11-15 15:00:58.805 SC-1 osafdtmd[154]: NO Established contact with 'PL-3'
2017-11-15 15:00:58.930 SC-1 osafdtmd[154]: NO Established contact with 'PL-4'
2017-11-15 15:00:58.970 SC-1 osafdtmd[154]: NO Established contact with 'PL-5'
2017-11-15 15:01:00.103 SC-1 osafrded[177]: NO Running '/usr/local/lib/opensaf/opensaf_sc_active' with 0 argument(s)
2017-11-15 15:01:00.107 SC-1 osafrded[177]: NO Switched to ACTIVE from Undefined
2017-11-15 15:01:00.108 SC-1 osaffmd[186]: NO Starting activation supervision: 300000ms
2017-11-15 15:01:00.109 SC-1 osafimmd[196]: nid_notify by aab49daa:IMMD:1
2017-11-15 15:01:00.111 SC-1 opensafd[143]: NO start monitor service: IMMD
2017-11-15 15:01:00.111 SC-1 opensafd[143]: NO spawn service: IMMND
2017-11-15 15:01:00.112 SC-1 opensafd[143]: NO Read fifo /var/lib/opensaf/osafimmd.fifo successfully
2017-11-15 15:01:00.113 SC-1 opensafd[143]: NO Monitoring of IMMD started
2017-11-15 15:01:00.114 SC-1 osafimmd[196]: NO * SC_ABSENCE_ALLOWED (Headless Hydra) is configured: 900 *****
2017-11-15 15:01:00.123 SC-1 osafimmnd[209]: create_fifofile successfully
2017-11-15 15:01:00.124 SC-1 osafimmnd[209]: Started
2017-11-15 15:01:00.125 SC-1 osafimmnd[209]: NO Persistent Back-End capability configured, Pbe file:imm.db (suffix may get added)
2017-11-15 15:02:27.751 SC-1 systemd[1]: opensafd.service: Start operation timed out. Terminating.
2017-11-15 15:02:27.758 SC-1 osafimmnd[209]: MDTM:SOCKET recd_bytes :0, conn lost with dh server
2017-11-15 15:02:27.758 SC-1 opensafd[112]: Starting OpenSAF Services (Using TCP):Terminated
2017-11-15 15:02:27.759 SC-1 osaffmd[186]: exiting for shutdown
2017-11-15 15:02:27.759 SC-1 osafclmna[168]: exiting for shutdown
2017-11-15 15:02:27.762 SC-1 osafrded[177]: exiting for shutdown
2017-11-15 15:02:27.763 SC-1 osafimmd[196]: MDTM:SOCKET recd_bytes :0, conn lost with dh server
2017-11-15 15:02:27.763 SC-1 osaftransportd[161]: exiting for shutdown
2017-11-15 15:02:27.763 SC-1 osafimmnd[209]: exiting for shutdown
2017-11-15 15:02:27.764 SC-1 osafimmd[196]: exiting for shutdown
2017-11-15 15:02:27.766 SC-1 opensafd[112]: rmdir: failed to remove '/var/lock/subsys/opensafd_inprogress': No such file or directory
2017-11-15 15:02:27.767 SC-1 systemd[1]: opensafd.service: Control process exited, code=exited status=1
2017-11-15 15:02:27.767 SC-1 systemd[1]: Failed to start OpenSAF daemon.

During starting up, fmd and immd registers rda callback. But in this scenario, only fmd succeeded, the register request of immd came a bit later. When rde switched to ACTIVE, rde only sent callback to fmd because immd has not registerd yet, thus when immd's register request came, immd did not receive any callback and the start up sequence stucked from there

<143>1 2017-11-15T15:08:09.815838+11:00 SC-1 osafrded 177 osafrded [meta sequenceId="37"] [177:src/rde/rded/rde_rda.cc:0332] >> rde_rda_process_reg_cb
<143>1 2017-11-15T15:08:09.815852+11:00 SC-1 osafrded 177 osafrded [meta sequenceId="38"] [177:src/rde/rded/rde_rda.cc:0184] >> rde_rda_write_msg: 20 - '7'
<143>1 2017-11-15T15:08:09.815863+11:00 SC-1 osafrded 177 osafrded [meta sequenceId="39"] [177:src/rde/rded/rde_rda.cc:0000] << rde_rda_write_msg
<143>1 2017-11-15T15:08:09.815872+11:00 SC-1 osafrded 177 osafrded [meta sequenceId="40"] [177:src/rde/rded/rde_rda.cc:0000] << rde_rda_process_reg_cb

<141>1 2017-11-15T15:08:11.923742+11:00 SC-1 osafrded 177 osafrded [meta sequenceId="94"] [177:src/rde/rded/role.cc:0065] NO Switched to ACTIVE from Undefined
<143>1 2017-11-15T15:08:11.923752+11:00 SC-1 osafrded 177 osafrded [meta sequenceId="95"] [177:src/rde/rded/rde_rda.cc:0524] TR Sending role 1 to RDA
<143>1 2017-11-15T15:08:11.923762+11:00 SC-1 osafrded 177 osafrded [meta sequenceId="96"] [177:src/rde/rded/rde_rda.cc:0184] >> rde_rda_write_msg: 20 - '10 1'
<143>1 2017-11-15T15:08:11.92378+11:00 SC-1 osafrded 177 osafrded [meta sequenceId="97"] [177:src/rde/rded/rde_rda.cc:0000] << rde_rda_write_msg
<143>1 2017-11-15T15:08:11.923802+11:00 SC-1 osafrded 177 osafrded [meta sequenceId="98"] [177:src/rde/rded/rde_main.cc:0321] TR received msg on fd 21

<143>1 2017-11-15T15:08:11.924023+11:00 SC-1 osafrded 177 osafrded [meta sequenceId="118"] [177:src/rde/rded/rde_rda.cc:0332] >> rde_rda_process_reg_cb
<143>1 2017-11-15T15:08:11.924031+11:00 SC-1 osafrded 177 osafrded [meta sequenceId="119"] [177:src/rde/rded/rde_rda.cc:0184] >> rde_rda_write_msg: 22 - '7'
<143>1 2017-11-15T15:08:11.924122+11:00 SC-1 osafrded 177 osafrded [meta sequenceId="120"] [177:src/rde/rded/rde_rda.cc:0000] << rde_rda_write_msg
<143>1 2017-11-15T15:08:11.924136+11:00 SC-1 osafrded 177 osafrded [meta sequenceId="121"] [177:src/rde/rded/rde_rda.cc:0000] << rde_rda_process_reg_cb

Minh Hon Chau - 2017-11-19

status: unassigned --> assigned

assigned_to: Minh Hon Chau
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Minh Hon Chau - 2017-11-20

status: assigned --> review
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Minh Hon Chau - 2017-11-24

status: review --> fixed

assigned_to: Minh Hon Chau --> nobody
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Minh Hon Chau - 2017-11-24

[develop]
commit: e4c99b061667ab9bf944b2f346627ebd95fffa65
[release]
commit: d36ac73a757825c1dd90b39bfe9387ae4c69f800

If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

rde: Missing rda callback causes opensafd failed to start

Milestone

Searches

Help

#2687 rde: Missing rda callback causes opensafd failed to start

Related

Discussion