diff --git a/source/scripts/init/service.d/lan_handler.sh b/source/scripts/init/service.d/lan_handler.sh index 25b33d05..c4914b59 100755 --- a/source/scripts/init/service.d/lan_handler.sh +++ b/source/scripts/init/service.d/lan_handler.sh @@ -162,7 +162,9 @@ case "$1" in fi ;; ipv4_*-status) + echo_t "LAN HANDLER : Received $1 event with status $2" if [ x"up" = x${2} ]; then + echo_t "LAN HANDLER : Handling LAN up event for instance ${1}" INST=${1#*_} INST=${INST%-*} RG_MODE=`syscfg get last_erouter_mode` @@ -184,12 +186,14 @@ case "$1" in if [ xbrlan0 = x${LAN_IFNAME} ]; then + echo_t "LAN HANDLER : Handling LAN up event for brlan0, configuring IPv6 address if needed" SYSEVT_lan_ipaddr_v6_prev=`sysevent get lan_ipaddr_v6_prev` if [ "1" = "$(sysevent get ula_ipv6_enabled)" ] && [ "1" != "$(syscfg get Device_Mode)" ]; then SYSEVT_lan_ipaddr_v6=$(sysevent get ipv6_prefix_ula | cut -d "/" -f 1) SYSEVT_lan_ipaddr_v6=${SYSEVT_lan_ipaddr_v6}1 else + echo_t "LAN HANDLER : Using global IPv6 address for LAN" SYSEVT_lan_ipaddr_v6=`sysevent get lan_ipaddr_v6` fi SYSEVT_lan_prefix_v6=`sysevent get lan_prefix_v6` @@ -255,6 +259,7 @@ case "$1" in elif [ x"ready" != x`sysevent get start-misc` ] && ( [ "$MANUFACTURE" = "Technicolor" ] || [ "$MANUFACTURE" = "Sercomm" ] ) ; then #TCH XBx/TCCBR based startup post.d scripts which includes Firewall restart and dhcp start. sysevent set lan-status started + echo_t "LAN HANDLER : lan status set to started" firewall if [ ! -f "$POSTD_START_FILE" ]; then @@ -264,6 +269,7 @@ case "$1" in else echo_t "LAN HANDLER : Triggering DHCP server using LAN status" sysevent set lan-status started + echo_t "LAN HANDLER : lan status set to started" echo_t "LAN HANDLER : Triggering RDKB_FIREWALL_RESTART" t2CountNotify "RF_INFO_RDKB_FIREWALL_RESTART" sysevent set firewall-restart @@ -314,6 +320,8 @@ case "$1" in sysevent set firewall-restart if [ -e "/usr/bin/print_uptime" ]; then /usr/bin/print_uptime "Laninit_complete" + echo_t "LAN HANDLER : Laninit_complete uptime: $(cut -d. -f1 /proc/uptime)" + echo_t "LAN HANDLER : Checking lan-status after lan init complete, lan-status = $(sysevent get lan-status)" fi uptime=$(cut -d. -f1 /proc/uptime) @@ -344,7 +352,7 @@ case "$1" in pnm-status | bring-lan) if [ -e "/usr/bin/print_uptime" ]; then /usr/bin/print_uptime "Lan_init_start" - fi + fi uptime=$(cut -d. -f1 /proc/uptime) if [ -e "/usr/bin/onboarding_log" ]; then /usr/bin/onboarding_log "Lan_init_start:$uptime" @@ -354,7 +362,6 @@ case "$1" in if [ -z "$INST" ] then echo_t "THE INSTANT=$INST" - echo_t "THE INSTANT=$INST" #(use a simpler test than this -- but Hacky, since it assumes everything we want is not XB3!!)if [ "$BOX_TYPE" = "TCCBR" ] || [ "$BOX_TYPE" = "XB6" -a "$MANUFACTURE" = "Technicolor" ] || [ "$BOX_TYPE" = "XB7" -a "$MANUFACTURE" = "Technicolor" ] ; then if ( [ "$BOX_TYPE" != "XB3" ] && ( [ "$MANUFACTURE" = "Technicolor" ] || [ "$MANUFACTURE" = "Sercomm" ] ) ) || [ "$BOX_TYPE" = "rpi" ] || [ "$BOX_TYPE" = "bpi" ]; then COUNTER=1 @@ -371,7 +378,7 @@ case "$1" in echo_t "THE COUNTER =$COUNTER" done else - echo_t "RDKB_SYSTEM_BOOT_UP_LOG : INST rerurned null, retrying" + echo_t "RDKB_SYSTEM_BOOT_UP_LOG : INST returned null, retrying" INST=`psmcli get dmsb.MultiLAN.PrimaryLAN_l3net` fi @@ -436,11 +443,10 @@ case "$1" in sysevent set primary_lan_l3net $L3NET fi fi - elif [ "$BOX_TYPE" = "TCCBR" ]; then - if [ -z "$INST" ]; then - echo "*****SET THE PRIMARY LAN ******" > /dev/null - syseven set primary_lan_l3net 4 - fi + fi + if [ -z "$INST" ] && [ "$BOX_TYPE" = "TCCBR" ]; then + echo_t "INST is empty on TCCBR; defaulting primary_lan_l3net to 4" + sysevent set primary_lan_l3net 4 fi fi @@ -565,4 +571,4 @@ case "$1" in echo "Usage: service-${SERVICE_NAME} [ ${SERVICE_NAME}-start | ${SERVICE_NAME}-stop | ${SERVICE_NAME}-restart]" > /dev/console exit 3 ;; -esac +esac \ No newline at end of file diff --git a/source/scripts/init/service.d/service_lan.sh b/source/scripts/init/service.d/service_lan.sh index 9f6f18c8..7956db4c 100755 --- a/source/scripts/init/service.d/service_lan.sh +++ b/source/scripts/init/service.d/service_lan.sh @@ -33,6 +33,15 @@ # See the License for the specific language governing permissions and # limitations under the License. ####################################################################### +log() { + local level="$1"; shift + local message="$*" + local timestamp + local log_file + timestamp=$(date +'%Y-%m-%d %H:%M:%S') + log_file="/tmp/service_lan.log" + echo "$timestamp [$level] $message" | tee -a "$log_file" +} source /etc/utopia/service.d/interface_functions.sh source /etc/utopia/service.d/ulog_functions.sh @@ -45,6 +54,9 @@ source /lib/rdk/t2Shared_api.sh SERVICE_NAME="lan" +log INFO "Script started." +echo_t "service_lan: Script started." + subnet() { if [ "$2" ]; then NM="$2" @@ -664,26 +676,43 @@ service_start () { # echo "lan service start called" > /dev/console #song: register_docsis_handler + log INFO "Starting LAN service" + echo_t "service_lan: Starting LAN service" wait_till_end_state ${SERVICE_NAME} CcspHome_Security=`sysevent get HomeSecuritySupport` STATUS=`sysevent get ${SERVICE_NAME}-status` + echo_t "Current LAN service status: $STATUS" + log INFO "Current LAN service status: $STATUS" if [ "started" != "$STATUS" ] ; then sysevent set ${SERVICE_NAME}-errinfo sysevent set ${SERVICE_NAME}-status starting + log INFO "LAN service status set to starting" + echo_t "service_lan: LAN service status set to starting" + + log INFO "LAN interfaces: $LAN_IFNAMES" + echo_t "service_lan: LAN interfaces: $LAN_IFNAMES" if [ -n "$LAN_IFNAMES" ]; then + log INFO "Bringing up LAN with bridge" + echo_t "service_lan : Bringing up LAN with bridge" do_start else + log INFO "Bringing up LAN without bridge" + echo_t "service_lan : Bringing up LAN without bridge" do_start_no_bridge fi ERR=$? if [ "$ERR" -ne "0" ] ; then + log ERROR "Unable to bringup lan, error code: $ERR" + echo_t "service_lan : Unable to bringup lan, error code: $ERR" check_err $? "Unable to bringup lan" elif [ "" = "$SYSCFG_lan_dhcp_client" -o "0" = "$SYSCFG_lan_dhcp_client" ] ; then + log INFO "LAN service started successfully, setting status to started" sysevent set ${SERVICE_NAME}-errinfo sysevent set ${SERVICE_NAME}-status started #song: add_docsis_bridge echo_t "service_lan : Triggering RDKB_FIREWALL_RESTART" + log INFO "Triggering RDKB_FIREWALL_RESTART" t2CountNotify "SYS_SH_RDKB_FIREWALL_RESTART" sysevent set firewall-restart fi @@ -715,25 +744,44 @@ service_start () #-------------------------------------------------------------- service_stop () { + log INFO "Stopping LAN service" + echo_t "service_lan: Stopping LAN service" wait_till_end_state ${SERVICE_NAME} - STATUS=`sysevent get ${SERVICE_NAME}-status` + STATUS=`sysevent get ${SERVICE_NAME}-status` + echo_t "Current LAN service status: $STATUS" + log INFO "Current LAN service status: $STATUS" if [ "stopped" != "$STATUS" ] ; then sysevent set ${SERVICE_NAME}-errinfo sysevent set ${SERVICE_NAME}-status stopping + log INFO "LAN service status set to stopping" + echo_t "service_lan: LAN service status set to stopping" + + log INFO "LAN interfaces: $LAN_IFNAMES" + echo_t "service_lan: LAN interfaces: $LAN_IFNAMES" if [ -n "$LAN_IFNAMES" ]; then do_stop + log INFO "Bringing down LAN with bridge" + echo_t "service_lan: Bringing down LAN with bridge" else do_stop_no_bridge + log INFO "Bringing down LAN without bridge" + echo_t "service_lan: Bringing down LAN without bridge" fi ERR=$? if [ "$ERR" -ne "0" ] ; then check_err $ERR "Unable to teardown lan" + log ERROR "Unable to teardown lan, error code: $ERR" + echo_t "service_lan: Unable to teardown lan, error code: $ERR" elif [ "" = "$SYSCFG_lan_dhcp_client" -o "0" = "$SYSCFG_lan_dhcp_client" ] ; then + log INFO "LAN service stopped successfully, setting status to stopped" + echo_t "service_lan: LAN service stopped successfully, setting status to stopped" sysevent set ${SERVICE_NAME}-errinfo sysevent set ${SERVICE_NAME}-status stopped fi #unregister wecb_master from pmon to let this script to bring it up when lan restart. + log INFO "Unregistering wecb_master from pmon" + echo_t "service_lan : Unregistering web_master from pmon" /etc/utopia/service.d/pmon.sh unregister wecb_master #rongwei added # killall wecb_master 2>/dev/null diff --git a/source/scripts/init/service.d/service_routed.sh b/source/scripts/init/service.d/service_routed.sh index 03d65159..3432206a 100755 --- a/source/scripts/init/service.d/service_routed.sh +++ b/source/scripts/init/service.d/service_routed.sh @@ -41,6 +41,19 @@ source /etc/device.properties +log() { + local level="$1"; shift + local message="$*" + local timestamp + local log_file + timestamp=$(date +'%Y-%m-%d %H:%M:%S') + log_file="/tmp/service_routed.log" + echo "$timestamp [$level] $message" | tee -a "$log_file" +} + +# Start logging +log INFO "Script started." + SERVICE_NAME="routed" LANULASupport=`sysevent get LANULASupport` case "$1" in @@ -59,19 +72,24 @@ case "$1" in wan-status) status=$(sysevent get wan-status) if [ "$status" == "started" ]; then + log INFO "WAN status started. Starting routed service." service_routed start elif [ "$status" == "stopped" ]; then + log INFO "WAN status stopped. Stopping routed service." service_routed stop fi ;; lan-status) status=$(sysevent get lan-status) if [ "$status" == "started" ]; then + log INFO "LAN status started. Starting routed service." service_routed start if [ "$BOX_TYPE" == "WNXL11BWL" ]; then + log INFO "LAN status started. Starting zebra" service_routed radv-start fi elif [ "$status" == "stopped" ]; then + log INFO "LAN status stopped. Stopping routed service." # As per Sky requirement, radvd should run with ULA prefix though the wan-status is down if [ "$BOX_TYPE" != "HUB4" ] && [ "$BOX_TYPE" != "SR300" ] && [ "$BOX_TYPE" != "SE501" ] && [ "$BOX_TYPE" != "SR213" ] && [ "$BOX_TYPE" != "WNXL11BWL" ] && [ "$LANULASupport" != "true" ]; then service_routed stop diff --git a/source/service_deviceMode/service_devicemode.c b/source/service_deviceMode/service_devicemode.c index 01bff266..33ae9527 100644 --- a/source/service_deviceMode/service_devicemode.c +++ b/source/service_deviceMode/service_devicemode.c @@ -72,6 +72,21 @@ #endif #include "print_uptime.h" +#define LOG_FILE_ROUTED "/tmp/service_deviceMode.txt" +#define APPLY_PRINT(fmt ...) {\ +FILE *logfp = fopen(LOG_FILE_ROUTED , "a+");\ +if (logfp){\ +time_t s = time(NULL);\ +struct tm* current_time = localtime(&s);\ +fprintf(logfp, "[%02d:%02d:%02d] ",\ +current_time->tm_hour,\ +current_time->tm_min,\ +current_time->tm_sec);\ +fprintf(logfp, fmt);\ +fclose(logfp);\ +}\ +}\ + #ifndef RETURN_OK #define RETURN_OK 0 #endif @@ -304,18 +319,21 @@ int runCommandInShellBlocking(char *command) int service_stop(int mode) { + APPLY_PRINT("%s : Stopping services for mode %d\n", __FUNCTION___, mode); char buf[256]; memset(buf,0,sizeof(buf)); switch(mode) { case DEVICE_MODE_ROUTER: { + APPLY_PRINT("%s : Stopping Router Mode Services\n", __FUNCTION__); sysevent_set(sysevent_fd, sysevent_token, "lan-stop", "", 0); sysevent_set(sysevent_fd, sysevent_token, "ipv4-down", "5", 0); #if defined (_COSA_BCM_ARM_) sysevent_set(sysevent_fd, sysevent_token, "wan-stop", "", 0); #endif //lte-1312 + APPLY_PRINT("%s : Stopping zebra Process\n", __FUNCTION__); runCommandInShellBlocking("killall zebra"); snprintf(buf,sizeof(buf),"execute_dir %s stop", ROUTER_MODE_SERVICES_PATH_1); runCommandInShellBlocking(buf); @@ -375,6 +393,7 @@ int GetL2InterfaceNameFromPsm(int instanceNumber, char *pName, int len) int service_start(int mode) { + APPLY_PRINT("%s : Starting services for mode %d\n", __FUNCTION__, mode); char buf[256]; memset(buf,0,sizeof(buf)); int rc = -1; @@ -382,6 +401,7 @@ int service_start(int mode) { case DEVICE_MODE_ROUTER: { + APPLY_PRINT("%s : Starting Router Mode Services\n", __FUNCTION__); int bridgemode = 0; if( 0 == syscfg_get( NULL, "bridge_mode", buf, sizeof(buf) ) ) { @@ -391,14 +411,17 @@ int service_start(int mode) runCommandInShellBlocking(buf); if (bridgemode == 0) { + APPLY_PRINT("%s : Starting LAN in Router mode\n", __FUNCTION__); sysevent_set(sysevent_fd, sysevent_token, "lan-start", "", 0); } else { + APPLY_PRINT("%s : Starting Bridge\n", __FUNCTION__); sysevent_set(sysevent_fd, sysevent_token, "bridge-start", "", 0); } // Do wan start only in XB technicolor for xb->xb backup wan testing. #if defined (_COSA_BCM_ARM_) + APPLY_PRINT("%s : Starting WAN\n", __FUNCTION__); sysevent_set(sysevent_fd, sysevent_token, "wan-start", "", 0); #endif // start ipv4 for XHS @@ -418,14 +441,17 @@ int service_start(int mode) #endif runCommandInShellBlocking("systemctl restart CcspLMLite.service"); #if !defined(_WNXL11BWL_PRODUCT_REQ_) + APPLY_PRINT("%s : Restarting zebra Process\n", __FUNCTION__); sysevent_set(sysevent_fd, sysevent_token, "zebra-restart", "", 0); #endif } break; case DEVICE_MODE_EXTENDER: { + APPLY_PRINT("%s : Starting Extender Mode Services\n", __FUNCTION__); char tmpbuf[64] = {0}; //lte-1312 + APPLY_PRINT("%s : Stopping zebra Process if running\n", __FUNCTION__); runCommandInShellBlocking("killall zebra"); sysevent_set(sysevent_fd, sysevent_token, "lan-start", "", 0); sysevent_set(sysevent_fd, sysevent_token, "lan_status-dhcp", "started", 0); diff --git a/source/service_dhcp/lan_handler.c b/source/service_dhcp/lan_handler.c index 875f55b0..33d46455 100644 --- a/source/service_dhcp/lan_handler.c +++ b/source/service_dhcp/lan_handler.c @@ -293,7 +293,7 @@ void bring_lan_up() snprintf(l_cPsm_Parameter, sizeof(l_cPsm_Parameter), "dmsb.MultiLAN.PrimaryLAN_l3net"); l_iRet_Val = PSM_VALUE_GET_STRING(l_cPsm_Parameter, l_cpPsm_Get); if (CCSP_SUCCESS != l_iRet_Val || l_cpPsm_Get == NULL) - { + { fprintf(g_fArmConsoleLog, "RDKB_SYSTEM_BOOT_UP_LOG : L3INST returned null, retrying\n"); l_iRet_Val = PSM_VALUE_GET_STRING(l_cPsm_Parameter, l_cpPsm_Get); if(CCSP_SUCCESS != l_iRet_Val || l_cpPsm_Get == NULL) @@ -307,7 +307,7 @@ void bring_lan_up() } } else - { + { strncpy(l_cPrimaryLan_L3Net, l_cpPsm_Get, sizeof(l_cPrimaryLan_L3Net)); fprintf(g_fArmConsoleLog, "RDKB_SYSTEM_BOOT_UP_LOG : L3INST is:%s\n", l_cPrimaryLan_L3Net); } @@ -409,6 +409,10 @@ void bring_lan_up() sysevent_set(g_iSyseventfd, g_tSysevent_token, "homesecurity_lan_l3net", l_cHomeSecurity_L3net, 0); #endif } + else + { + fprintf(g_fArmConsoleLog, "LAN HANDLER FAILURE : PrimaryLAN_l3net is empty after all PSM retries, LAN start cannot proceed\n"); + } } else { @@ -450,6 +454,14 @@ void ipv4_status(int l3_inst, char *status) sysevent_get(g_iSyseventfd, g_tSysevent_token, "primary_lan_l3net", primary_l3net, sizeof(primary_l3net)); + if ('\0' == primary_l3net[0]) + { + fprintf(g_fArmConsoleLog, "LAN HANDLER FAILURE : primary_lan_l3net sysevent is empty, LAN start decision cannot be made for l3_inst=%d\n", l3_inst); + } + + fprintf(g_fArmConsoleLog, "LAN HANDLER DEBUG: ipv4_status entry - l3_inst=%d, status=%s, primary_lan_l3net=%s, is_primary=%d\n", + l3_inst, status, primary_l3net, (l3_inst == atoi(primary_l3net))); + #if defined (WAN_FAILOVER_SUPPORTED) || defined(RDKB_EXTENDER_ENABLED) int devMode=0, ulaEnable=0; char buf[128] = {0}; @@ -465,6 +477,10 @@ void ipv4_status(int l3_inst, char *status) } sysevent_get(g_iSyseventfd, g_tSysevent_token, l_cSysevent_Cmd, l_cLanIfName, sizeof(l_cLanIfName)); + if (l_cLanIfName[0] == '\0') + { + fprintf(g_fArmConsoleLog, "LAN HANDLER FAILURE : LAN interface name is empty for l3_inst=%d, LAN start may fail\n", l3_inst); + } // if it's ipv4 only, not enable link local if (!strncmp(l_cLast_Erouter_Mode, "1", 1)) { @@ -594,7 +610,13 @@ void ipv4_status(int l3_inst, char *status) //sysevent set current_lan_ipaddr `sysevent get ipv4_${INST}-ipv4addr` snprintf(l_cSysevent_Cmd, sizeof(l_cSysevent_Cmd), "ipv4_%d-ipv4addr", l3_inst); sysevent_get(g_iSyseventfd, g_tSysevent_token, l_cSysevent_Cmd, - l_cCur_Ipv4_Addr, sizeof(l_cCur_Ipv4_Addr)); + l_cCur_Ipv4_Addr, sizeof(l_cCur_Ipv4_Addr)); + + if (0 == l_cCur_Ipv4_Addr[0]) + { + fprintf(g_fArmConsoleLog, "LAN HANDLER FAILURE : IPv4 address is empty for l3_inst=%d, LAN may not function correctly\n", l3_inst); + t2_event_d("SYS_ERROR_LAN_IPv4Addr_Empty", 1); + } if ( l3_inst == 4 ) { @@ -612,12 +634,14 @@ void ipv4_status(int l3_inst, char *status) sysevent_get(g_iSyseventfd, g_tSysevent_token, "parcon_nfq_status", l_cParcon_Nfq_Status, sizeof(l_cParcon_Nfq_Status)); + fprintf(g_fArmConsoleLog, "LAN HANDLER DEBUG: Decision inputs - last_erouter_mode=%s, start_misc=%s, current_wan_ipaddr=%s, parcon_nfq=%s\n", + l_cLast_Erouter_Mode, l_cStart_Misc, l_cCurrentWan_IpAddr, l_cParcon_Nfq_Status); if ((!strncmp(l_cLast_Erouter_Mode, "2", 1)) && (strncmp(l_cStart_Misc, "ready", 5))) { if ( l3_inst == atoi(primary_l3net)) { - fprintf(g_fArmConsoleLog, "LAN HANDLER : Triggering DHCP server using LAN status based on RG_MODE:2"); + fprintf(g_fArmConsoleLog, "LAN HANDLER : Setting LAN start (Branch1-RG_MODE2) and Triggering DHCP server using LAN status based on RG_MODE:2"); sysevent_set(g_iSyseventfd, g_tSysevent_token, "lan-status", "started", 0); } system("firewall"); @@ -635,7 +659,7 @@ void ipv4_status(int l3_inst, char *status) if ( l3_inst == atoi(primary_l3net)) { - fprintf(g_fArmConsoleLog, "LAN HANDLER : Triggering DHCP server using LAN status based on start misc\n"); + fprintf(g_fArmConsoleLog, "LAN HANDLER : Starting LAN (primary l3net) and Triggering DHCP server using LAN status based on start misc\n"); sysevent_set(g_iSyseventfd, g_tSysevent_token, "lan-status", "started", 0); } if (strncmp(l_cParcon_Nfq_Status, "started", 7)) @@ -690,9 +714,11 @@ void ipv4_status(int l3_inst, char *status) } else { + fprintf(g_fArmConsoleLog, "LAN HANDLER DEBUG: Entered ELSE/fallback branch - erouter_mode=%s, start_misc=%s, wan_ip=%s\n", + l_cLast_Erouter_Mode, l_cStart_Misc, l_cCurrentWan_IpAddr); if ( l3_inst == atoi(primary_l3net)) { - fprintf(g_fArmConsoleLog, "LAN HANDLER : Triggering DHCP server using LAN status\n"); + fprintf(g_fArmConsoleLog, "LAN HANDLER : setting lan-status=started, Triggering DHCP server using LAN status\n"); sysevent_set(g_iSyseventfd, g_tSysevent_token, "lan-status", "started", 0); } fprintf(g_fArmConsoleLog, "LAN HANDLER : Triggering RDKB_FIREWALL_RESTART\n"); @@ -705,6 +731,7 @@ void ipv4_status(int l3_inst, char *status) sysinfo(&l_sSysInfo); snprintf(l_cLan_Uptime, sizeof(l_cLan_Uptime), "%ld", l_sSysInfo.uptime); sysevent_set(g_iSyseventfd, g_tSysevent_token, "lan_start_time", l_cLan_Uptime, 0); + fprintf(g_fArmConsoleLog, "LAN HANDLER DEBUG: lan_start_time=%s, l3_inst=%d, setting ipv4_%d_status_configured\n", l_cLan_Uptime, l3_inst, l3_inst); if (4 == l3_inst) { @@ -725,6 +752,7 @@ void ipv4_status(int l3_inst, char *status) fprintf(g_fArmConsoleLog, "LAN HANDLER : DHCP configuration status got is:%s\n", l_cDhcp_Server_Prog); if (!strncmp(l_cLast_Erouter_Mode, "2", 1) && (strncmp(l_cDsLite_Enabled, "1", 1))) { + fprintf(g_fArmConsoleLog, "LAN HANDLER : Stopping DHCP server - IPv6 only mode (erouter_mode=2) and DSlite disabled\n"); sysevent_set(g_iSyseventfd, g_tSysevent_token, "dhcp_server-stop", "", 0); } else if ((strncmp(l_cLast_Erouter_Mode, "0", 1)) && @@ -733,6 +761,14 @@ void ipv4_status(int l3_inst, char *status) fprintf(g_fArmConsoleLog, "LAN HANDLER : Triggering dhcp start based on last erouter mode\n"); sysevent_set(g_iSyseventfd, g_tSysevent_token, "dhcp_server-start", "", 0); } + else if (!strncmp(l_cLast_Erouter_Mode, "0", 1)) + { + fprintf(g_fArmConsoleLog, "LAN HANDLER FAILURE : DHCP server not started - erouter_mode is 0 (disabled), LAN clients will not get IP addresses\n"); + } + else + { + fprintf(g_fArmConsoleLog, "LAN HANDLER WARNING : DHCP server start skipped - already in progress (dhcp_server_prog=%s)\n", l_cDhcp_Server_Prog); + } if (0 != l_cIpv6_Prefix[0]) { @@ -745,6 +781,7 @@ void ipv4_status(int l3_inst, char *status) } else { + fprintf(g_fArmConsoleLog, "LAN HANDLER DEBUG: ipv4_status - status is NOT 'up' (status=%s), l3_inst=%d\n", status, l3_inst); if ( l3_inst == atoi(primary_l3net)) { sysevent_get(g_iSyseventfd, g_tSysevent_token, "lan-status", diff --git a/source/service_dhcp/service_dhcp.c b/source/service_dhcp/service_dhcp.c index c83ab9d4..75f34aa9 100644 --- a/source/service_dhcp/service_dhcp.c +++ b/source/service_dhcp/service_dhcp.c @@ -41,6 +41,22 @@ #include "errno.h" #include "util.h" +#include +#define LOG_FILE_ROUTED "/rdklogs/logs/Consolelog.txt.0" +#define APPLY_PRINT(fmt ...) {\ +FILE *logfp = fopen(LOG_FILE_ROUTED , "a+");\ +if (logfp){\ +time_t s = time(NULL);\ +struct tm* current_time = localtime(&s);\ +fprintf(logfp, "[%02d:%02d:%02d] ",\ +current_time->tm_hour,\ +current_time->tm_min,\ +current_time->tm_sec);\ +fprintf(logfp, fmt);\ +fclose(logfp);\ +}\ +}\ + #ifdef UNIT_TEST_DOCKER_SUPPORT #define STATIC extern FILE* fopen_mock(const char* filename, const char* mode); @@ -472,8 +488,14 @@ int service_dhcp_main(int argc, char *argv[]) { dhcp_server_stop(); } + else if (!strncmp(argv[1], "lan-status", 10)) { + APPLY_PRINT("%s: Checking lan-status \n", __FUNCTION__); + char store[24] = {0}; + sysevent_get(g_iSyseventfd, g_tSysevent_token, + "lan-status", store, sizeof(store)); + APPLY_PRINT("%s : lan-status is %s\n", __FUNCTION__, store); //If lan-status is called with lan_not_restart then //the same is used in further function calls if (4 == argc) @@ -496,8 +518,10 @@ int service_dhcp_main(int argc, char *argv[]) dhcp_server_start(NULL); } #endif + else if (!strncmp(argv[1], "lan-restart", 11)) { + APPLY_PRINT("%s: call lan_restart \n", __FUNCTION__); lan_restart(); } else if ((!strncmp(argv[1], "ipv4_4-status", 13)) || @@ -576,16 +600,19 @@ int service_dhcp_main(int argc, char *argv[]) } else if (!strncmp(argv[1], "lan-stop", 8)) { + APPLY_PRINT("%s: Stopping LAN \n", __FUNCTION__); lan_stop(); } else if (!strncmp(argv[1], "lan-start", 9)) { + APPLY_PRINT("%s: Starting LAN \n", __FUNCTION__); sysevent_get(g_iSyseventfd, g_tSysevent_token, "primary_lan_l3net", l_cL3Inst, sizeof(l_cL3Inst)); l_iL3Inst = atoi(l_cL3Inst); fprintf(g_fArmConsoleLog, "Calling ipv4_up with L3 Instance:%d\n", l_iL3Inst); + APPLY_PRINT("%s: Calling ipv4_up with L3 Instance\n", __FUNCTION__); sysevent_set(g_iSyseventfd, g_tSysevent_token, "ipv4-up", l_cL3Inst, 0); } //service_ipv4.sh related @@ -619,6 +646,7 @@ int service_dhcp_main(int argc, char *argv[]) sizeof(syslog_status_buf)); if(!strncmp(syslog_status_buf, "started", 7)) { + APPLY_PRINT("%s: Syslog is started, requesting restart\n", __FUNCTION__); syslog_restart_request(); } } diff --git a/source/service_dslite/service_dslite.c b/source/service_dslite/service_dslite.c index e3d0c333..27136a9f 100644 --- a/source/service_dslite/service_dslite.c +++ b/source/service_dslite/service_dslite.c @@ -39,6 +39,21 @@ #include "safec_lib_common.h" #include "secure_wrapper.h" +#define LOG_FILE_ROUTED "/tmp/utopia_service_dslite.txt" +#define APPLY_PRINT(fmt ...) {\ +FILE *logfp = fopen(LOG_FILE_ROUTED , "a+");\ +if (logfp){\ +time_t s = time(NULL);\ +struct tm* current_time = localtime(&s);\ +fprintf(logfp, "[%02d:%02d:%02d] ",\ +current_time->tm_hour,\ +current_time->tm_min,\ +current_time->tm_sec);\ +fprintf(logfp, fmt);\ +fclose(logfp);\ +}\ +}\ + #define PROG_NAME "SERVICE-DSLITE" #define ER_NETDEVNAME "erouter0" #define TNL_NETDEVNAME "ipip6tun0" @@ -284,6 +299,7 @@ static void wan_dhcp_stop (void) static void restart_zebra (struct serv_dslite *sd) { + APPLY_PRINT("%s: Restarting zebra \n", __FUNCTION__); FILE *zebra_pid_fd; FILE *zebra_cmdline_fd; char pid_str[10]; @@ -309,6 +325,7 @@ static void restart_zebra (struct serv_dslite *sd) { if (strstr(cmdline_buf, "zebra")) { + APPLY_PRINT("%s: Zebra is running, no need to restart\n", __FUNCTION__); restart_needed = 0; } } @@ -318,6 +335,7 @@ static void restart_zebra (struct serv_dslite *sd) if (restart_needed) { + APPLY_PRINT("%s: Zebra is not running, need to restart\n", __FUNCTION__); sysevent_set (sd->sefd, sd->setok, "zebra-restart", "", 0); } } diff --git a/source/service_ipv6/service_ipv6.c b/source/service_ipv6/service_ipv6.c index aa5f5a14..93bff0d9 100644 --- a/source/service_ipv6/service_ipv6.c +++ b/source/service_ipv6/service_ipv6.c @@ -53,6 +53,22 @@ #include "ccsp_memory.h" #endif +#include +#define LOG_FILE_ROUTED "/tmp/utopia_service_ipv6.txt" +#define APPLY_PRINT(fmt ...) {\ +FILE *logfp = fopen(LOG_FILE_ROUTED , "a+");\ +if (logfp){\ +time_t s = time(NULL);\ +struct tm* current_time = localtime(&s);\ +fprintf(logfp, "[%02d:%02d:%02d] ",\ +current_time->tm_hour,\ +current_time->tm_min,\ +current_time->tm_sec);\ +fprintf(logfp, fmt);\ +fclose(logfp);\ +}\ +}\ + #ifdef _ONESTACK_PRODUCT_REQ_ #include #include @@ -1297,6 +1313,7 @@ STATIC void update_mtu(void){ */ STATIC int lan_addr6_set(struct serv_ipv6 *si6) { + APPLY_PRINT("%s: Entering function\n", __FUNCTION__); unsigned int l2_insts[MAX_LAN_IF_NUM] = {0}; #if defined(MULTILAN_FEATURE) unsigned int primary_l2_instance = 0; @@ -1328,6 +1345,7 @@ STATIC int lan_addr6_set(struct serv_ipv6 *si6) */ if (divide_ipv6_prefix(si6) != 0) { fprintf(stderr, "divide the operator-delegated prefix to sub-prefix error.\n"); + APPLY_PRINT("%s: divide the operator-delegated prefix to sub-prefix error.\n", __FUNCTION__); sysevent_set(si6->sefd, si6->setok, "service_ipv6-status", "error", 0); return -1; } @@ -1335,6 +1353,7 @@ STATIC int lan_addr6_set(struct serv_ipv6 *si6) sysevent_get(si6->sefd, si6->setok, "ipv6_prefix-divided", evt_val, sizeof(evt_val)); if (strcmp(evt_val, "ready")) { fprintf(stderr, "[%s] ipv6 prefix is not divided.\n", __FUNCTION__); + APPLY_PRINT("%s: ipv6 prefix is not divided.\n", __FUNCTION__); return -1; } @@ -1470,6 +1489,7 @@ STATIC int lan_addr6_set(struct serv_ipv6 *si6) //Intel Proposed RDKB Generic Bug Fix from XB6 SDK /*start zebra*/ + APPLY_PRINT("%s: Starting zebra\n", __FUNCTION__); sysevent_set(si6->sefd, si6->setok, "zebra-restart", NULL, 0); return 0; @@ -2106,6 +2126,7 @@ STATIC int dhcpv6s_restart(struct serv_ipv6 *si6) STATIC int serv_ipv6_start(struct serv_ipv6 *si6) { + APPLY_PRINT("%s: Starting service_ipv6\n", __FUNCTION__); fprintf(stderr, "Entered serv_ipv6_start \n"); char rtmod[16]; #if defined (_ONESTACK_PRODUCT_REQ_) @@ -2122,6 +2143,7 @@ STATIC int serv_ipv6_start(struct serv_ipv6 *si6) if (atoi(rtmod) != 1) { /* IPv6-only or Dual-Stack */ if (!si6->wan_ready) { fprintf(stderr, "%s: IPv6-WAN is not ready !\n", __FUNCTION__); + APPLY_PRINT("%s: IPv6-WAN is not ready !\n", __FUNCTION__); return -1; } } else {/* IPv4-only */ @@ -2189,6 +2211,7 @@ STATIC int serv_ipv6_start(struct serv_ipv6 *si6) //Intel Proposed RDKB Generic Bug Fix from XB6 SDK /*start zebra*/ + APPLY_PRINT("%s: Starting zebra\n", __FUNCTION__); sysevent_set(si6->sefd, si6->setok, "zebra-restart", NULL, 0); if (dhcpv6s_start(si6) != 0) { diff --git a/source/service_routed/service_routed.c b/source/service_routed/service_routed.c index c01695c9..3c32c2e8 100644 --- a/source/service_routed/service_routed.c +++ b/source/service_routed/service_routed.c @@ -98,6 +98,22 @@ static const char* const service_routed_component_id = "ccsp.routed"; #include #endif +#include +#define LOG_FILE_ROUTED "/tmp/service_routed.txt" +#define APPLY_PRINT(fmt ...) {\ +FILE *logfp = fopen(LOG_FILE_ROUTED , "a+");\ +if (logfp){\ +time_t s = time(NULL);\ +struct tm* current_time = localtime(&s);\ +fprintf(logfp, "[%02d:%02d:%02d] ",\ +current_time->tm_hour,\ +current_time->tm_min,\ +current_time->tm_sec);\ +fprintf(logfp, fmt);\ +fclose(logfp);\ +}\ +}\ + #define ZEBRA_PID_FILE "/var/zebra.pid" #define RIPD_PID_FILE "/var/ripd.pid" #define ZEBRA_CONF_FILE "/var/zebra.conf" @@ -2073,12 +2089,15 @@ STATIC void checkIfModeIsSwitched(int sefd, token_t setok) #endif STATIC int radv_start(struct serv_routed *sr) { + APPLY_PRINT("%s: Starting radv daemon\n", __FUNCTION__); #ifdef RDKB_EXTENDER_ENABLED int deviceMode = GetDeviceNetworkMode(); + APPLY_PRINT("%s: Device Mode is %d\n", __FUNCTION__, deviceMode); if ( DEVICE_MODE_EXTENDER == deviceMode ) { fprintf(logfptr, "Device is EXT mode , no need of running zebra for radv\n"); + APPLY_PRINT("%s: Device is EXT mode , no need of running zebra for radv\n", __FUNCTION__); return -1; } #endif @@ -2111,9 +2130,11 @@ STATIC int radv_start(struct serv_routed *sr) char aBridgeMode[8]; syscfg_get(NULL, "bridge_mode", aBridgeMode, sizeof(aBridgeMode)); + APPLY_PRINT("%s: bridge_mode = %s and LAN ready value = %d\n", __FUNCTION__, aBridgeMode, sr->lan_ready); if ((!strcmp(aBridgeMode, "0")) && (!sr->lan_ready)) { fprintf(logfptr, "%s: LAN is not ready !\n", __FUNCTION__); + APPLY_PRINT("%s: LAN is not ready !\n", __FUNCTION__); return -1; } #endif @@ -2125,10 +2146,12 @@ STATIC int radv_start(struct serv_routed *sr) result = getLanIpv6Info(&ipv6_enable, &ula_enable); if(result != 0) { fprintf(logfptr, "getLanIpv6Info failed"); + APPLY_PRINT("%s: getLanIpv6Info failed", __FUNCTION__); return -1; } if(ipv6_enable == 0) { daemon_stop(ZEBRA_PID_FILE, "zebra"); + APPLY_PRINT("%s: IPv6 is not enabled so stopping zebra for radv\n", __FUNCTION__); return -1; } } @@ -2146,6 +2169,7 @@ STATIC int radv_start(struct serv_routed *sr) if (gen_zebra_conf(sr->sefd, sr->setok) != 0) { fprintf(logfptr, "%s: fail to save zebra config\n", __FUNCTION__); + APPLY_PRINT("%s: fail to save zebra config\n", __FUNCTION__); return -1; } @@ -2171,17 +2195,29 @@ STATIC int radv_start(struct serv_routed *sr) syscfg_get(NULL, "dhcpv6s00::serverenable", dhcpv6Enable , sizeof(dhcpv6Enable)); bool bEnabled = (strncmp(dhcpv6Enable,"1",1)==0?true:false); + APPLY_PRINT("%s : Starting Zebra Process\n", __FUNCTION__); v_secure_system("zebra -d -f %s -P 0 2> /tmp/.zedra_error", ZEBRA_CONF_FILE); + APPLY_PRINT("%s : Zebra Process Started\n", __FUNCTION__); printf("DHCPv6 is %s. Starting zebra Process\n", (bEnabled?"Enabled":"Disabled")); #else v_secure_system("zebra -d -f %s -P 0 2> /tmp/.zedra_error", ZEBRA_CONF_FILE); + APPLY_PRINT("%s : Zebra Process Started\n", __FUNCTION__); #endif + + if(is_daemon_running(ZEBRA_PID_FILE, "zebra") == 0) + { + APPLY_PRINT("%s: Failed to start zebra process\n", __FUNCTION__); + } + else { + APPLY_PRINT("%s: Zebra is running\n", __FUNCTION__); + } return 0; } STATIC int radv_stop(struct serv_routed *sr) { + APPLY_PRINT("%s : Stopping radv services \n", __FUNCTION__); if(is_daemon_running(ZEBRA_PID_FILE, "zebra")) { return 0; @@ -2191,8 +2227,10 @@ STATIC int radv_stop(struct serv_routed *sr) STATIC int radv_restart(struct serv_routed *sr) { + APPLY_PRINT("%s: Restarting radv daemon\n", __FUNCTION__); if (radv_stop(sr) != 0){ fprintf(logfptr, "%s: radv_stop error\n", __FUNCTION__); + APPLY_PRINT("%s: radv_stop error\n", __FUNCTION__); } return radv_start(sr); } @@ -2335,6 +2373,7 @@ STATIC int serv_routed_start(struct serv_routed *sr) /* RA daemon */ if (radv_start(sr) != 0) { fprintf(logfptr, "%s: radv_start error\n", __FUNCTION__); + APPLY_PRINT("%s: radv_start error\n", __FUNCTION__); sysevent_set(sr->sefd, sr->setok, "routed-status", "error", 0); return -1; } @@ -2409,11 +2448,15 @@ STATIC int serv_routed_init(struct serv_routed *sr) sysevent_get(sr->sefd, sr->setok, "wan-status", wan_st, sizeof(wan_st)); if (strcmp(wan_st, "started") == 0) - sr->wan_ready = true; + { sr->wan_ready = true; + APPLY_PRINT("%s: WAN is ready and WAN value = %d\n", __FUNCTION__, sr->wan_ready); + } sysevent_get(sr->sefd, sr->setok, "lan-status", lan_st, sizeof(lan_st)); if (strcmp(lan_st, "started") == 0) - sr->lan_ready = true; + { sr->lan_ready = true; + APPLY_PRINT("%s: LAN is ready and LAN value = %d\n", __FUNCTION__, sr->lan_ready); + } return 0; } @@ -2747,6 +2790,7 @@ STATIC void usage(void) int service_routed_main(int argc, char *argv[]) { + APPLY_PRINT("%s: Entering %s\n", PROG_NAME, __FUNCTION__); int i; struct serv_routed sr; logfptr = fopen ( LOG_FILE_NAME , "a+"); @@ -2785,6 +2829,7 @@ int service_routed_main(int argc, char *argv[]) if (serv_routed_init(&sr) != 0){ exit(1); } + APPLY_PRINT("%s: Service routed initialized\n", PROG_NAME); for (i = 0; i < NELEMS(cmd_ops); i++) { if (strcmp(argv[1], cmd_ops[i].cmd) != 0 || !cmd_ops[i].exec) continue;