Unable to reboot via GUI

Hi,

   Thanks for the report , your issue is track as NC-22127.

Best Regards,

Rana Sharma

Here you go

DEBUG Sep 19 08:14:12 [listener:964]: ln_recvfrom: fd '5.UDP.INET.server': 336 bytes are read by listener
DEBUG Sep 19 08:14:12 [listener:964]: register_request_inet: request from port '58892'
INFO Sep 19 08:14:12 [listener:964]: protocol dbhandle not found
INFO Sep 19 08:14:12 [listener:964]: Assigning free worker 966
DEBUG Sep 19 08:14:12 [listener:964]: assign_to_busy_queue: assigning worker 966
DEBUG Sep 19 08:14:12 [listener:964]: send_data_to_sockpair: listener has send 322 bytes to sockpair worker 966
DEBUG Sep 19 08:14:12 [worker:966]: read_packet: read() 322 bytes from listener
DEBUG Sep 19 08:14:12 [worker:966]: # OPCODE Called: 'apiInterface'
DEBUG Sep 19 08:14:12 [worker:966]: request:
-----------
DEBUG Sep 19 08:14:12 [worker:966]: request method = opcode
DEBUG Sep 19 08:14:12 [worker:966]: request name = apiInterface
DEBUG Sep 19 08:14:12 [worker:966]: request version = 1.10
DEBUG Sep 19 08:14:12 [worker:966]: content length = 270
DEBUG Sep 19 08:14:12 [worker:966]: content type = json
DEBUG Sep 19 08:14:12 [worker:966]: response code = 0
DEBUG Sep 19 08:14:12 [worker:966]: response string len = 0
DEBUG Sep 19 08:14:12 [worker:966]: response content = '{"reboot":"1","mode":193,"reason":"a","currentlyloggedinuserid":3,"___serverport":4444,"___component":"GUI","APIVersion":"1700.1","___serverprotocol":"HTTP","___username":"admin","transactionid":"8247","currentlyloggedinuserip":"192.168.0.3","___serverip":"192.168.0.2"}'
DEBUG Sep 19 08:14:12 [worker:966]:
-----------
DEBUG Sep 19 08:14:12 [worker:966]: Main TLV:{ 1, data:{ 2, 4, C6300} , 9}
DEBUG Sep 19 08:14:12 [worker:966]: recv_dbtlv_data: tlv->type(1) : 96601
DEBUG Sep 19 08:14:12 [worker:966]: worker_proc: dbhandle init for 966(1,96601)
DEBUG Sep 19 08:14:12 [worker:966]: ### insert_uuid: hdr: len=270 content=0 method=0 name=apiInterface
DEBUG Sep 19 08:14:12 [worker:966]: ### insert_uuid: trying to insert uuid into body: '{"reboot":"1","mode":193,"reason":"a","currentlyloggedinuserid":3,"___serverport":4444,"___component":"GUI","APIVersion":"1700.1","___serverprotocol":"HTTP","___username":"admin","transactionid":"8247","currentlyloggedinuserip":"192.168.0.3","___serverip":"192.168.0.2"}'
DEBUG Sep 19 08:14:12 [worker:966]: ### insert_uuid: skipping uuid insertion because empty '"autogen_uuid"' not found in body
DEBUG Sep 19 08:14:12 [worker:966]: ### insert_uuid: uuid insertion took 0 s 73100 ns
INFO Sep 19 08:14:12 [apiInterface:966]: creating json object
DEBUG Sep 19 08:14:12 [apiInterface:966]: json_to_perl: Object
INFO Sep 19 08:14:12 [apiInterface:966]: ACTION: CALL validateRequestType
INFO Sep 19 08:14:12 [apiInterface:966]: ACTION: CALL variableInitialization
DEBUG Sep 19 08:14:13 [apiInterface:966]: do_query: 'start transaction'
DEBUG Sep 19 08:14:13 [apiInterface:966]: do_query: 'start transaction'
INFO Sep 19 08:14:13 [apiInterface:966]: csc_query: After PQexec, result not NULL
INFO Sep 19 08:14:13 [apiInterface:966]: csc_query: After PQexec, result2 not NULL
INFO Sep 19 08:14:13 [apiInterface:966]: csc_query: Txid:22042
INFO Sep 19 08:14:13 [apiInterface:966]: csc_query: After PQclear
DEBUG Sep 19 08:14:13 [apiInterface:966]: logger: applog
DEBUG Sep 19 08:14:13 [apiInterface:966]: do_log_to_file: length=17 string='Request type = 1
'
INFO Sep 19 08:14:13 [apiInterface:966]: ACTION: CALL isAPIVersionSupported
DEBUG Sep 19 08:14:13 [apiInterface:966]: logger: applog
DEBUG Sep 19 08:14:13 [apiInterface:966]: do_log_to_file: length=37 string='apiInterface:versionsupported: true.
'
INFO Sep 19 08:14:13 [apiInterface:966]: ACTION: CALL opcodePreProcess
INFO Sep 19 08:14:13 [apiInterface:966]: executing FORLOOP
INFO Sep 19 08:14:13 [apiInterface:966]: FORLOOP condition true
INFO Sep 19 08:14:13 [apiInterface:966]: ACTION: CALL checkUserPermission
DEBUG Sep 19 08:14:13 [apiInterface:966]: do_query: 'select entityid from tblcrevent where mode = 193'
DEBUG Sep 19 08:14:13 [apiInterface:966]: do_query: 'select entityid from tblcrevent where mode = 193'
INFO Sep 19 08:14:13 [apiInterface:966]: create_act_out_perl_obj: varname=result
INFO Sep 19 08:14:13 [apiInterface:966]: create_act_out_perl_obj: result.status=0
INFO Sep 19 08:14:13 [apiInterface:966]: create_act_out_perl_obj: JSON result.output={ "entityid": [ 48 ] }
DEBUG Sep 19 08:14:13 [apiInterface:966]: json_to_perl: Object
DEBUG Sep 19 08:14:13 [apiInterface:966]: json_to_perl: Array
DEBUG Sep 19 08:14:13 [apiInterface:966]: do_query: 'select roleid from tbluserrolerelation where userid = 3'
DEBUG Sep 19 08:14:13 [apiInterface:966]: do_query: 'select roleid from tbluserrolerelation where userid = 3'
INFO Sep 19 08:14:13 [apiInterface:966]: create_act_out_perl_obj: varname=result
INFO Sep 19 08:14:13 [apiInterface:966]: create_act_out_perl_obj: result.status=0
INFO Sep 19 08:14:13 [apiInterface:966]: create_act_out_perl_obj: JSON result.output={ "roleid": [ 1 ] }
DEBUG Sep 19 08:14:13 [apiInterface:966]: json_to_perl: Object
DEBUG Sep 19 08:14:13 [apiInterface:966]: json_to_perl: Array
DEBUG Sep 19 08:14:13 [apiInterface:966]: do_query: 'select operationallowed from tblacldefinition where roleid = 1 and entityid = 48'
DEBUG Sep 19 08:14:13 [apiInterface:966]: do_query: 'select operationallowed from tblacldefinition where roleid = 1 and entityid = 48'
INFO Sep 19 08:14:13 [apiInterface:966]: create_act_out_perl_obj: varname=result
INFO Sep 19 08:14:13 [apiInterface:966]: create_act_out_perl_obj: result.status=0
INFO Sep 19 08:14:13 [apiInterface:966]: create_act_out_perl_obj: JSON result.output={ "operationallowed": [ 15 ] }
DEBUG Sep 19 08:14:13 [apiInterface:966]: json_to_perl: Object
DEBUG Sep 19 08:14:13 [apiInterface:966]: json_to_perl: Array
INFO Sep 19 08:14:13 [apiInterface:966]: ACTION: CALL preMigration
INFO Sep 19 08:14:13 [apiInterface:966]: ACTION: CALL createModeJSON
DEBUG Sep 19 08:14:13 [apiInterface:966]: logger: applog
DEBUG Sep 19 08:14:13 [apiInterface:966]: do_log_to_file: length=34 string='apiInterface:request mode -> 193.
'
INFO Sep 19 08:14:13 [apiInterface:966]: ACTION: CALL migrateToCurrVersion
DEBUG Sep 19 08:14:13 [apiInterface:966]: logger: applog
DEBUG Sep 19 08:14:13 [apiInterface:966]: do_log_to_file: length=38 string='apiInterface:Current ver :::'1700.1'
'
INFO Sep 19 08:14:13 [apiInterface:966]: ACTION: CALL createJson
INFO Sep 19 08:14:13 [apiInterface:966]: ACTION: CALL validateJson
DEBUG Sep 19 08:14:13 [apiInterface:966]: logger: applog
DEBUG Sep 19 08:14:13 [apiInterface:966]: do_log_to_file: length=85 string='apiInterface:entityjson::::::::dashboard::dashboardshutdownappliance=HASH(0xaedb6e0)
'
INFO Sep 19 08:14:13 [apiInterface:966]: ACTION: CALL handleDeleteRequest
INFO Sep 19 08:14:13 [apiInterface:966]: ACTION: CALL replyIfErrorAtValidation
INFO Sep 19 08:14:13 [apiInterface:966]: ACTION: CALL getOldObject
DEBUG Sep 19 08:14:13 [apiInterface:966]: do_query: 'select opcode,opcodetype,perlpackagename from tblcrevent where mode=193'
DEBUG Sep 19 08:14:13 [apiInterface:966]: do_query: 'select opcode,opcodetype,perlpackagename from tblcrevent where mode=193'
INFO Sep 19 08:14:13 [apiInterface:966]: create_act_out_perl_obj: varname=opout
INFO Sep 19 08:14:13 [apiInterface:966]: create_act_out_perl_obj: opout.status=0
INFO Sep 19 08:14:13 [apiInterface:966]: create_act_out_perl_obj: JSON opout.output={ "opcode": [ "shutdown_appliance" ], "opcodetype": [ "2" ], "perlpackagename": [ "" ] }
DEBUG Sep 19 08:14:13 [apiInterface:966]: json_to_perl: Object
DEBUG Sep 19 08:14:13 [apiInterface:966]: json_to_perl: Array
DEBUG Sep 19 08:14:13 [apiInterface:966]: json_to_perl: Array
DEBUG Sep 19 08:14:13 [apiInterface:966]: json_to_perl: Array
DEBUG Sep 19 08:14:13 [apiInterface:966]: logger: applog
DEBUG Sep 19 08:14:13 [apiInterface:966]: do_log_to_file: length=150 string='CRITICAL WARNING :: Transaction will not be rolled back for opcode shutdown_appliance. If any operation fails, request is part of multiple request :
'
DEBUG Sep 19 08:14:13 [apiInterface:966]: execute_action: DYNACODE variable:opcodename
DEBUG Sep 19 08:14:13 [apiInterface:966]: execute_action: DYNACODE opcode:shutdown_appliance
DEBUG Sep 19 08:14:13 [apiInterface:966]: do_ao: OPCODE shutdown_appliance
DEBUG Sep 19 08:14:13 [apiInterface:966]: perl_to_json: FLAG_SET: INTEGER! Returning integer type!
DEBUG Sep 19 08:14:13 [apiInterface:966]: perl_to_json: FLAG_SET: INTEGER! Returning integer type!
DEBUG Sep 19 08:14:13 [apiInterface:966]: perl_to_json: FLAG_SET: INTEGER! Returning integer type!
DEBUG Sep 19 08:14:13 [apiInterface:966]: do_ao: OPCODE shutdown_appliance CONTENT-TYPE:json, BODY:{ "___serverip": "192.168.0.2", "reboot": "1", "___serverprotocol": "HTTP", "___serverport": 4444, "reason": "a", "___component": "GUI", "APIVersion": "1700.1", "currentlyloggedinuserip": "192.168.0.3", "currentlyloggedinuserid": 3, "mode": 193, "transactionid": "8247", "___username": "admin" }, BODY_LEN:295
DEBUG Sep 19 08:14:13 [listener:964]: ln_recvfrom: fd '94.TCP.INET.auxilary': 382 bytes are read by listener
DEBUG Sep 19 08:14:13 [listener:964]: register_request_inet: request from port '0'
INFO Sep 19 08:14:13 [listener:964]: Assigning free worker 969
DEBUG Sep 19 08:14:13 [listener:964]: assign_to_busy_queue: assigning worker 969
DEBUG Sep 19 08:14:13 [listener:964]: send_data_to_sockpair: listener has send 347 bytes to sockpair worker 969
DEBUG Sep 19 08:14:13 [worker:969]: read_packet: read() 347 bytes from listener
DEBUG Sep 19 08:14:13 [worker:969]: # OPCODE Called: 'shutdown_appliance'
DEBUG Sep 19 08:14:13 [worker:969]: request:
-----------
DEBUG Sep 19 08:14:13 [worker:969]: request method = opcode
DEBUG Sep 19 08:14:13 [worker:969]: request name = shutdown_appliance
DEBUG Sep 19 08:14:13 [worker:969]: request version = 1.14
DEBUG Sep 19 08:14:13 [worker:969]: content length = 295
DEBUG Sep 19 08:14:13 [worker:969]: content type = json
DEBUG Sep 19 08:14:13 [worker:969]: response code = 0
DEBUG Sep 19 08:14:13 [worker:969]: response string len = 0
DEBUG Sep 19 08:14:13 [worker:969]: response content = '{ "___serverip": "192.168.0.2", "reboot": "1", "___serverprotocol": "HTTP", "___serverport": 4444, "reason": "a", "___component": "GUI", "APIVersion": "1700.1", "currentlyloggedinuserip": "192.168.0.3", "currentlyloggedinuserid": 3, "mode": 193, "transactionid": "8247", "___username": "admin" }'
DEBUG Sep 19 08:14:13 [worker:969]:
-----------
DEBUG Sep 19 08:14:13 [worker:969]: ### insert_uuid: hdr: len=295 content=0 method=0 name=shutdown_appliance
DEBUG Sep 19 08:14:13 [worker:969]: ### insert_uuid: skipping uuid insertion
DEBUG Sep 19 08:14:13 [worker:969]: ### insert_uuid: uuid insertion took 0 s 15600 ns
INFO Sep 19 08:14:13 [shutdown_appliance:969]: creating json object
DEBUG Sep 19 08:14:13 [shutdown_appliance:969]: json_to_perl: Object
DEBUG Sep 19 08:14:13 [shutdown_appliance:969]: do_ao: OPCODE getappkey
DEBUG Sep 19 08:14:13 [shutdown_appliance:969]: do_ao: OPCODE getappkey CONTENT-TYPE:text, BODY:(null), BODY_LEN:0
DEBUG Sep 19 08:14:13 [listener:964]: ln_recvfrom: fd '5.UDP.INET.server': 41 bytes are read by listener
DEBUG Sep 19 08:14:13 [listener:964]: register_request_inet: request from port '46312'
INFO Sep 19 08:14:13 [listener:964]: protocol content type not found
INFO Sep 19 08:14:13 [listener:964]: protocol length not found
INFO Sep 19 08:14:13 [listener:964]: Assigning free worker 973
DEBUG Sep 19 08:14:13 [listener:964]: assign_to_busy_queue: assigning worker 973
DEBUG Sep 19 08:14:13 [listener:964]: send_data_to_sockpair: listener has send 52 bytes to sockpair worker 973
DEBUG Sep 19 08:14:13 [worker:973]: read_packet: read() 52 bytes from listener
DEBUG Sep 19 08:14:13 [worker:973]: # OPCODE Called: 'getappkey'
DEBUG Sep 19 08:14:13 [worker:973]: request:
-----------
DEBUG Sep 19 08:14:13 [worker:973]: request method = opcode
DEBUG Sep 19 08:14:13 [worker:973]: request name = getappkey
DEBUG Sep 19 08:14:13 [worker:973]: request version = 1.14
DEBUG Sep 19 08:14:13 [worker:973]: content length = 0
DEBUG Sep 19 08:14:13 [worker:973]: content type = text
DEBUG Sep 19 08:14:13 [worker:973]: response code = 0
DEBUG Sep 19 08:14:13 [worker:973]: response string len = 0
DEBUG Sep 19 08:14:13 [worker:973]:
-----------
DEBUG Sep 19 08:14:13 [worker:973]: ### insert_uuid: hdr: len=0 content=1 method=0 name=getappkey
DEBUG Sep 19 08:14:13 [worker:973]: ### insert_uuid: skipping uuid insertion
DEBUG Sep 19 08:14:13 [worker:973]: ### insert_uuid: uuid insertion took 0 s 21700 ns
INFO Sep 19 08:14:13 [getappkey:973]: ACTION: DLOPEN(do_nvram_eget, li.serial)
INFO Sep 19 08:14:13 [getappkey:973]: do_nvram_eget: li.serial in appkey var
ERROR Sep 19 08:14:13 [getappkey:973]: nvram_eget(li.serial): failed with -16
DEBUG Sep 19 08:14:13 [getappkey:973]: logger: applog
DEBUG Sep 19 08:14:13 [getappkey:973]: do_log_to_file: length=23 string='Get Serial Key failed
'
INFO Sep 19 08:14:13 [getappkey:973]: opcode 'getappkey': time taken: 0.164270400 seconds
DEBUG Sep 19 08:14:13 [worker:973]: response:
-----------
DEBUG Sep 19 08:14:13 [worker:973]: request method = opcode
DEBUG Sep 19 08:14:13 [worker:973]: request name = getappkey
DEBUG Sep 19 08:14:13 [worker:973]: request version = 1.14
DEBUG Sep 19 08:14:13 [worker:973]: content length = 6
DEBUG Sep 19 08:14:13 [worker:973]: content type = text
DEBUG Sep 19 08:14:13 [worker:973]: response code = 500
DEBUG Sep 19 08:14:13 [worker:973]: response string len = 2
DEBUG Sep 19 08:14:13 [worker:973]: response string is = 'OK'
DEBUG Sep 19 08:14:13 [worker:973]: response content = 'failed'
DEBUG Sep 19 08:14:13 [worker:973]:
-----------
DEBUG Sep 19 08:14:13 [worker:973]: # OPCODE Exited: 'getappkey' with Status: '500'
DEBUG Sep 19 08:14:13 [worker:973]: write_packet: 52+6+2
DEBUG Sep 19 08:14:13 [worker:973]: write_packet: write 60 bytes to listener
DEBUG Sep 19 08:14:13 [listener:964]: read_response_from_sockpair: 60 bytes read from sockpair worker 973
DEBUG Sep 19 08:14:13 [listener:964]: is_response_complete: Complete response is received from sockpair worker 973
DEBUG Sep 19 08:14:13 [listener:964]: read_response_from_worker:
-----------
DEBUG Sep 19 08:14:13 [listener:964]: request method = opcode
DEBUG Sep 19 08:14:13 [listener:964]: request name = getappkey
DEBUG Sep 19 08:14:13 [listener:964]: request version = 1.14
DEBUG Sep 19 08:14:13 [listener:964]: content length = 6
DEBUG Sep 19 08:14:13 [listener:964]: content type = text
DEBUG Sep 19 08:14:13 [listener:964]: response code = 500
DEBUG Sep 19 08:14:13 [listener:964]: response string len = 2
DEBUG Sep 19 08:14:13 [listener:964]: response string is = 'OK'
DEBUG Sep 19 08:14:13 [listener:964]: response content = 'failed'
DEBUG Sep 19 08:14:13 [listener:964]:
-----------
DEBUG Sep 19 08:14:13 [listener:964]: response: 'csc/1.14 500 OK
content-length:6

failed'
DEBUG Sep 19 08:14:13 [listener:964]: ln_sendto: fd '5.UDP.INET.server' has sent 40 bytes to requester
DEBUG Sep 19 08:14:13 [listener:964]: Listener has sent data to requester
DEBUG Sep 19 08:14:13 [listener:964]: Worker 973 is removed from busy list
DEBUG Sep 19 08:14:13 [listener:964]: Realising worker 973
INFO Sep 19 08:14:13 [shutdown_appliance:969]: create_act_out_perl_obj: varname=result
INFO Sep 19 08:14:13 [shutdown_appliance:969]: create_act_out_perl_obj: result.status=500
INFO Sep 19 08:14:13 [shutdown_appliance:969]: create_act_out_perl_obj: TEXT result.output=failed
INFO Sep 19 08:14:13 [shutdown_appliance:969]: create_act_out_perl_obj: result.error=OK
DEBUG Sep 19 08:14:13 [shutdown_appliance:969]: logger: applog
DEBUG Sep 19 08:14:13 [shutdown_appliance:969]: do_log_to_file: length=13 string='reboot failed'
INFO Sep 19 08:14:13 [shutdown_appliance:969]: opcode 'shutdown_appliance': time taken: 0.310054100 seconds
DEBUG Sep 19 08:14:13 [worker:969]: response:
-----------
DEBUG Sep 19 08:14:13 [worker:969]: request method = opcode
DEBUG Sep 19 08:14:13 [worker:969]: request name = shutdown_appliance
DEBUG Sep 19 08:14:13 [worker:969]: request version = 1.14
DEBUG Sep 19 08:14:13 [worker:969]: content length = 53
DEBUG Sep 19 08:14:13 [worker:969]: content type = text
DEBUG Sep 19 08:14:13 [worker:969]: response code = 500
DEBUG Sep 19 08:14:13 [worker:969]: response string len = 2
DEBUG Sep 19 08:14:13 [worker:969]: response string is = 'OK'
DEBUG Sep 19 08:14:13 [worker:969]: response content = '{ "status": "500", "statusmessage": "reboot failed" }'
DEBUG Sep 19 08:14:13 [worker:969]:
-----------
DEBUG Sep 19 08:14:13 [worker:969]: # OPCODE Exited: 'shutdown_appliance' with Status: '500'
DEBUG Sep 19 08:14:13 [worker:969]: write_packet: 52+53+2
DEBUG Sep 19 08:14:13 [listener:964]: read_response_from_sockpair: 107 bytes read from sockpair worker 969
DEBUG Sep 19 08:14:13 [listener:964]: is_response_complete: Complete response is received from sockpair worker 969
DEBUG Sep 19 08:14:13 [listener:964]: read_response_from_worker:
-----------
DEBUG Sep 19 08:14:13 [listener:964]: request method = opcode
DEBUG Sep 19 08:14:13 [listener:964]: request name = shutdown_appliance
DEBUG Sep 19 08:14:13 [listener:964]: request version = 1.14
DEBUG Sep 19 08:14:13 [listener:964]: content length = 53
DEBUG Sep 19 08:14:13 [listener:964]: content type = text
DEBUG Sep 19 08:14:13 [listener:964]: response code = 500
DEBUG Sep 19 08:14:13 [listener:964]: response string len = 2
DEBUG Sep 19 08:14:13 [listener:964]: response string is = 'OK'
DEBUG Sep 19 08:14:13 [listener:964]: response content = '{ "status": "500", "statusmessage": "reboot failed" }'
DEBUG Sep 19 08:14:13 [listener:964]:
-----------
DEBUG Sep 19 08:14:13 [listener:964]: response: 'csc/1.14 500 OK
content-length:53

{ "status": "500", "statusmessage": "reboot failed" }'
DEBUG Sep 19 08:14:13 [listener:964]: ln_sendto: fd '94.TCP.INET.auxilary' has sent 88 bytes to requester
DEBUG Sep 19 08:14:13 [listener:964]: Listener has sent data to requester
DEBUG Sep 19 08:14:13 [listener:964]: Worker 969 is removed from busy list
DEBUG Sep 19 08:14:13 [listener:964]: Realising worker 969
INFO Sep 19 08:14:13 [apiInterface:966]: create_act_out_perl_obj: varname=out
INFO Sep 19 08:14:13 [apiInterface:966]: create_act_out_perl_obj: out.status=500
INFO Sep 19 08:14:13 [apiInterface:966]: create_act_out_perl_obj: TEXT out.output={ "status": "500", "statusmessage": "reboot failed" }
INFO Sep 19 08:14:13 [apiInterface:966]: create_act_out_perl_obj: out.error=OK
DEBUG Sep 19 08:14:13 [apiInterface:966]: do_query: 'rollback'
DEBUG Sep 19 08:14:13 [apiInterface:966]: do_query: 'rollback'
ERROR Sep 19 08:14:13 [listener:964]: ln_recvfrom: fd '94.TCP.INET.auxilary': peer connection closed'Success'
DEBUG Sep 19 08:14:13 [listener:964]: release_fd_struct: fd '94.TCP.INET.auxilary' is closed
DEBUG Sep 19 08:14:13 [worker:969]: write_packet: write 107 bytes to listener
INFO Sep 19 08:14:13 [apiInterface:966]: ACTION: CALL replyFailureMessage
INFO Sep 19 08:14:13 [apiInterface:966]: ACTION: DLOPEN(json2hash, response)
DEBUG Sep 19 08:14:13 [apiInterface:966]: json_to_perl: Object
INFO Sep 19 08:14:13 [apiInterface:966]: ACTION: CALL opcodeCCCFailLog
DEBUG Sep 19 08:14:13 [apiInterface:966]: do_query: 'select servicevalue from tblclientservices where servicekey='CCCEnabled''
DEBUG Sep 19 08:14:13 [apiInterface:966]: do_query: 'select servicevalue from tblclientservices where servicekey='CCCEnabled''
INFO Sep 19 08:14:13 [apiInterface:966]: create_act_out_perl_obj: varname=cccEnable
INFO Sep 19 08:14:13 [apiInterface:966]: create_act_out_perl_obj: cccEnable.status=0
INFO Sep 19 08:14:13 [apiInterface:966]: create_act_out_perl_obj: JSON cccEnable.output={ "servicevalue": [ "no" ] }
DEBUG Sep 19 08:14:13 [apiInterface:966]: json_to_perl: Object
DEBUG Sep 19 08:14:13 [apiInterface:966]: json_to_perl: Array

PAckage ::::dashboard::dashboardshutdownapplianceINFO Sep 19 08:14:13 [apiInterface:966]: opcode 'apiInterface': time taken: 0.925800700 seconds
DEBUG Sep 19 08:14:13 [worker:966]: worker_proc: going to release dbhandle for 966(1,96601)
DEBUG Sep 19 08:14:13 [worker:966]: Main TLV:{ 4, data:{ 1, 4, 597910} data:{ 2, 4, C6300} data:{ 5, 4, 0000} , 27}
DEBUG Sep 19 08:14:13 [worker:966]: response:
-----------
DEBUG Sep 19 08:14:13 [worker:966]: request method = opcode
DEBUG Sep 19 08:14:13 [worker:966]: request name = apiInterface
DEBUG Sep 19 08:14:13 [worker:966]: request version = 1.10
DEBUG Sep 19 08:14:13 [worker:966]: content length = 53
DEBUG Sep 19 08:14:13 [worker:966]: content type = text
DEBUG Sep 19 08:14:13 [worker:966]: response code = 500
DEBUG Sep 19 08:14:13 [worker:966]: response string len = 2
DEBUG Sep 19 08:14:13 [worker:966]: response string is = 'OK'
DEBUG Sep 19 08:14:13 [worker:966]: response content = '{ "status": "500", "statusmessage": "reboot failed" }'
DEBUG Sep 19 08:14:13 [worker:966]:
-----------
DEBUG Sep 19 08:14:13 [worker:966]: # OPCODE Exited: 'apiInterface' with Status: '500'
DEBUG Sep 19 08:14:13 [worker:966]: write_packet: 52+53+2
DEBUG Sep 19 08:14:13 [listener:964]: read_response_from_sockpair: 107 bytes read from sockpair worker 966
DEBUG Sep 19 08:14:13 [listener:964]: is_response_complete: Complete response is received from sockpair worker 966
DEBUG Sep 19 08:14:13 [listener:964]: read_response_from_worker:
-----------
DEBUG Sep 19 08:14:13 [listener:964]: request method = opcode
DEBUG Sep 19 08:14:13 [listener:964]: request name = apiInterface
DEBUG Sep 19 08:14:13 [listener:964]: request version = 1.10
DEBUG Sep 19 08:14:13 [listener:964]: content length = 53
DEBUG Sep 19 08:14:13 [listener:964]: content type = text
DEBUG Sep 19 08:14:13 [listener:964]: response code = 500
DEBUG Sep 19 08:14:13 [listener:964]: response string len = 2
DEBUG Sep 19 08:14:13 [listener:964]: response string is = 'OK'
DEBUG Sep 19 08:14:13 [listener:964]: response content = '{ "status": "500", "statusmessage": "reboot failed" }'
DEBUG Sep 19 08:14:13 [listener:964]:
-----------
DEBUG Sep 19 08:14:13 [listener:964]: response: 'csc/1.10 500 OK
content-length:53

{ "status": "500", "statusmessage": "reboot failed" }'
DEBUG Sep 19 08:14:13 [listener:964]: ln_sendto: fd '5.UDP.INET.server' has sent 88 bytes to requester
DEBUG Sep 19 08:14:13 [listener:964]: Listener has sent data to requester
DEBUG Sep 19 08:14:13 [listener:964]: Worker 966 is removed from busy list
DEBUG Sep 19 08:14:13 [listener:964]: Realising worker 966
DEBUG Sep 19 08:14:13 [worker:966]: write_packet: write 107 bytes to listener
DEBUG Sep 19 08:14:30 [listener:964]: ln_recvfrom: fd '5.UDP.INET.server': 45 bytes are read by listener
DEBUG Sep 19 08:14:30 [listener:964]: register_request_inet: request from port '59047'
INFO Sep 19 08:14:30 [listener:964]: protocol content type not found
INFO Sep 19 08:14:30 [listener:964]: protocol length not found
INFO Sep 19 08:14:30 [listener:964]: Assigning free worker 966
DEBUG Sep 19 08:14:30 [listener:964]: assign_to_busy_queue: assigning worker 966
DEBUG Sep 19 08:14:30 [listener:964]: send_data_to_sockpair: listener has send 52 bytes to sockpair worker 966
DEBUG Sep 19 08:14:30 [worker:966]: read_packet: read() 52 bytes from listener
DEBUG Sep 19 08:14:30 [worker:966]: # OPCODE Called: 'u2d_pt_installer'
DEBUG Sep 19 08:14:30 [worker:966]: request:
-----------
DEBUG Sep 19 08:14:30 [worker:966]: request method = nopcode
DEBUG Sep 19 08:14:30 [worker:966]: request name = u2d_pt_installer
DEBUG Sep 19 08:14:30 [worker:966]: request version = 1.10
DEBUG Sep 19 08:14:30 [worker:966]: content length = 0
DEBUG Sep 19 08:14:30 [worker:966]: content type = text
DEBUG Sep 19 08:14:30 [worker:966]: response code = 0
DEBUG Sep 19 08:14:30 [worker:966]: response string len = 0
DEBUG Sep 19 08:14:30 [worker:966]:
-----------
DEBUG Sep 19 08:14:30 [worker:966]: Main TLV:{ 1, data:{ 2, 4, C6300} , 9}
DEBUG Sep 19 08:14:30 [worker:966]: recv_dbtlv_data: tlv->type(1) : 96601
DEBUG Sep 19 08:14:30 [worker:966]: worker_proc: dbhandle init for 966(1,96601)
DEBUG Sep 19 08:14:30 [worker:966]: ### insert_uuid: hdr: len=0 content=1 method=1 name=u2d_pt_installer
DEBUG Sep 19 08:14:30 [worker:966]: ### insert_uuid: skipping uuid insertion
DEBUG Sep 19 08:14:30 [worker:966]: ### insert_uuid: uuid insertion took 0 s 21200 ns
INFO Sep 19 08:14:30 [u2d_pt_installer:966]: TRYLOCK: 14
DEBUG Sep 19 08:14:30 [u2d_pt_installer:966]: exec: filename '/bin/sh'
DEBUG Sep 19 08:14:30 [u2d_pt_installer:966]: exec: argv[0] = '/bin/sh'
DEBUG Sep 19 08:14:30 [u2d_pt_installer:966]: exec: argv[1] = '-c'
DEBUG Sep 19 08:14:30 [u2d_pt_installer:966]: exec: argv[2] = '/bin/nvram qget is_eula'
MESSAGE Sep 19 08:14:30 [u2d_pt_installer:966]: Child exited with status 244
DEBUG Sep 19 08:14:30 [u2d_pt_installer:966]: CHILD WITH ARGS: /bin/sh -c /bin/nvram qget is_eula
INFO Sep 19 08:14:30 [u2d_pt_installer:966]: create_act_out_perl_obj: varname=is_eula
INFO Sep 19 08:14:30 [u2d_pt_installer:966]: create_act_out_perl_obj: is_eula.status=16777204
WARNING Sep 19 08:14:30 [u2d_pt_installer:966]: action with nofail failed
DEBUG Sep 19 08:14:30 [u2d_pt_installer:966]: exec: filename '/bin/sh'
DEBUG Sep 19 08:14:30 [u2d_pt_installer:966]: exec: argv[0] = '/bin/sh'
DEBUG Sep 19 08:14:30 [u2d_pt_installer:966]: exec: argv[1] = '-c'
DEBUG Sep 19 08:14:30 [u2d_pt_installer:966]: exec: argv[2] = '/scripts/u2d/u2d_pt_dload_checker.sh'
DEBUG Sep 19 08:14:30 [listener:964]: ln_recvfrom: fd '5.UDP.INET.server': 37 bytes are read by listener
DEBUG Sep 19 08:14:30 [listener:964]: register_request_inet: request from port '55693'
INFO Sep 19 08:14:30 [listener:964]: protocol content type not found
INFO Sep 19 08:14:30 [listener:964]: protocol length not found
INFO Sep 19 08:14:30 [listener:964]: Assigning free worker 969
DEBUG Sep 19 08:14:30 [listener:964]: assign_to_busy_queue: assigning worker 969
DEBUG Sep 19 08:14:30 [listener:964]: send_data_to_sockpair: listener has send 52 bytes to sockpair worker 969
DEBUG Sep 19 08:14:30 [worker:969]: read_packet: read() 52 bytes from listener
DEBUG Sep 19 08:14:30 [worker:969]: # OPCODE Called: 'gethainfo'
DEBUG Sep 19 08:14:30 [worker:969]: request:
-----------
DEBUG Sep 19 08:14:30 [worker:969]: request method = opcode
DEBUG Sep 19 08:14:30 [worker:969]: request name = gethainfo
DEBUG Sep 19 08:14:30 [worker:969]: request version = 1.10
DEBUG Sep 19 08:14:30 [worker:969]: content length = 0
DEBUG Sep 19 08:14:30 [worker:969]: content type = text
DEBUG Sep 19 08:14:30 [worker:969]: response code = 0
DEBUG Sep 19 08:14:30 [worker:969]: response string len = 0
DEBUG Sep 19 08:14:30 [worker:969]:
-----------
DEBUG Sep 19 08:14:30 [worker:969]: Main TLV:{ 1, data:{ 2, 4, C9300} , 9}
DEBUG Sep 19 08:14:30 [worker:969]: recv_dbtlv_data: tlv->type(1) : 96902
DEBUG Sep 19 08:14:30 [worker:969]: worker_proc: dbhandle init for 969(1,96902)
DEBUG Sep 19 08:14:30 [worker:969]: ### insert_uuid: hdr: len=0 content=1 method=0 name=gethainfo
DEBUG Sep 19 08:14:30 [worker:969]: ### insert_uuid: skipping uuid insertion
DEBUG Sep 19 08:14:30 [worker:969]: ### insert_uuid: uuid insertion took 0 s 17000 ns
INFO Sep 19 08:14:30 [gethainfo:969]: do_get: g_ha_mode
INFO Sep 19 08:14:30 [gethainfo:969]: opcode 'gethainfo': time taken: 0.151836200 seconds
DEBUG Sep 19 08:14:30 [worker:969]: worker_proc: going to release dbhandle for 969(1,96902)
DEBUG Sep 19 08:14:30 [worker:969]: Main TLV:{ 4, data:{ 1, 4, 867A10} data:{ 2, 4, C9300} data:{ 5, 4, 0000} , 27}
DEBUG Sep 19 08:14:30 [worker:969]: response:
-----------
DEBUG Sep 19 08:14:30 [worker:969]: request method = opcode
DEBUG Sep 19 08:14:30 [worker:969]: request name = gethainfo
DEBUG Sep 19 08:14:30 [worker:969]: request version = 1.10
DEBUG Sep 19 08:14:30 [worker:969]: content length = 168
DEBUG Sep 19 08:14:30 [worker:969]: content type = text
DEBUG Sep 19 08:14:30 [worker:969]: response code = 200
DEBUG Sep 19 08:14:30 [worker:969]: response string len = 2
DEBUG Sep 19 08:14:30 [worker:969]: response string is = 'OK'
DEBUG Sep 19 08:14:30 [worker:969]: response content = 'hamode=0,haconfigmode=,ownstatus=,peerstatus=,ownappkey=,peerappkey=,loadbal=,dedicatedlink=,monitorlink=,peerdedicatedip=,peeraccesslink=,peeraccessip=,peeraccessipv6='
DEBUG Sep 19 08:14:30 [worker:969]:
-----------
DEBUG Sep 19 08:14:30 [worker:969]: # OPCODE Exited: 'gethainfo' with Status: '200'
DEBUG Sep 19 08:14:30 [worker:969]: write_packet: 52+168+2
DEBUG Sep 19 08:14:30 [listener:964]: read_response_from_sockpair: 222 bytes read from sockpair worker 969
DEBUG Sep 19 08:14:30 [listener:964]: is_response_complete: Complete response is received from sockpair worker 969
DEBUG Sep 19 08:14:30 [listener:964]: read_response_from_worker:
-----------
DEBUG Sep 19 08:14:30 [listener:964]: request method = opcode
DEBUG Sep 19 08:14:30 [listener:964]: request name = gethainfo
DEBUG Sep 19 08:14:30 [listener:964]: request version = 1.10
DEBUG Sep 19 08:14:30 [listener:964]: content length = 168
DEBUG Sep 19 08:14:30 [listener:964]: content type = text
DEBUG Sep 19 08:14:30 [listener:964]: response code = 200
DEBUG Sep 19 08:14:30 [listener:964]: response string len = 2
DEBUG Sep 19 08:14:30 [listener:964]: response string is = 'OK'
DEBUG Sep 19 08:14:30 [listener:964]: response content = 'hamode=0,haconfigmode=,ownstatus=,peerstatus=,ownappkey=,peerappkey=,loadbal=,dedicatedlink=,monitorlink=,peerdedicatedip=,peeraccesslink=,peeraccessip=,peeraccessipv6='
DEBUG Sep 19 08:14:30 [listener:964]:
-----------
DEBUG Sep 19 08:14:30 [listener:964]: response: 'csc/1.10 200 OK
content-length:168

hamode=0,haconfigmode=,ownstatus=,peerstatus=,ownappkey=,peerappkey=,loadbal=,dedicatedlink=,monitorlink=,peerdedicatedip=,peeraccesslink=,peeraccessip=,peeraccessipv6='
DEBUG Sep 19 08:14:30 [listener:964]: ln_sendto: fd '5.UDP.INET.server' has sent 204 bytes to requester
DEBUG Sep 19 08:14:30 [listener:964]: Listener has sent data to requester
DEBUG Sep 19 08:14:30 [listener:964]: Worker 969 is removed from busy list
DEBUG Sep 19 08:14:30 [listener:964]: Realising worker 969
DEBUG Sep 19 08:14:30 [worker:969]: write_packet: write 222 bytes to listener
INFO Sep 19 08:14:30 [u2d_pt_installer:966]: Child exited with status 0
INFO Sep 19 08:14:30 [u2d_pt_installer:966]: create_act_out_perl_obj: varname=out
INFO Sep 19 08:14:30 [u2d_pt_installer:966]: create_act_out_perl_obj: out.status=0
INFO Sep 19 08:14:30 [u2d_pt_installer:966]: create_act_out_perl_obj: TEXT out.output=UPDATE 1

INFO Sep 19 08:14:30 [u2d_pt_installer:966]: UNLOCK: 14
INFO Sep 19 08:14:30 [u2d_pt_installer:966]: opcode 'u2d_pt_installer': time taken: 0.403286600 seconds
DEBUG Sep 19 08:14:30 [worker:966]: worker_proc: going to release dbhandle for 966(1,96601)
DEBUG Sep 19 08:14:30 [worker:966]: Main TLV:{ 4, data:{ 1, 4, 597910} data:{ 2, 4, C6300} data:{ 5, 4, 0000} , 27}
DEBUG Sep 19 08:14:30 [worker:966]: response:
-----------
DEBUG Sep 19 08:14:30 [worker:966]: request method = nopcode
DEBUG Sep 19 08:14:30 [worker:966]: request name = u2d_pt_installer
DEBUG Sep 19 08:14:30 [worker:966]: request version = 1.10
DEBUG Sep 19 08:14:30 [worker:966]: content length = 2
DEBUG Sep 19 08:14:30 [worker:966]: content type = text
DEBUG Sep 19 08:14:30 [worker:966]: response code = 200
DEBUG Sep 19 08:14:30 [worker:966]: response string len = 2
DEBUG Sep 19 08:14:30 [worker:966]: response string is = 'OK'
DEBUG Sep 19 08:14:30 [worker:966]: response content = 'OK'
DEBUG Sep 19 08:14:30 [worker:966]:
-----------
DEBUG Sep 19 08:14:30 [worker:966]: # OPCODE Exited: 'u2d_pt_installer' with Status: '200'
DEBUG Sep 19 08:14:30 [worker:966]: write_packet: 52+2+2
DEBUG Sep 19 08:14:30 [listener:964]: read_response_from_sockpair: 56 bytes read from sockpair worker 966
DEBUG Sep 19 08:14:30 [listener:964]: is_response_complete: Complete response is received from sockpair worker 966
DEBUG Sep 19 08:14:30 [listener:964]: read_response_from_worker:
-----------
DEBUG Sep 19 08:14:30 [listener:964]: request method = nopcode
DEBUG Sep 19 08:14:30 [listener:964]: request name = u2d_pt_installer
DEBUG Sep 19 08:14:30 [listener:964]: request version = 1.10
DEBUG Sep 19 08:14:30 [listener:964]: content length = 2
DEBUG Sep 19 08:14:30 [listener:964]: content type = text
DEBUG Sep 19 08:14:30 [listener:964]: response code = 200
DEBUG Sep 19 08:14:30 [listener:964]: response string len = 2
DEBUG Sep 19 08:14:30 [listener:964]: response string is = 'OK'
DEBUG Sep 19 08:14:30 [listener:964]: response content = 'OK'
DEBUG Sep 19 08:14:30 [listener:964]:
-----------
DEBUG Sep 19 08:14:30 [listener:964]: response: 'csc/1.10 200 OK
content-length:2

OK'
INFO Sep 19 08:14:30 [listener:964]: send_buffer_to_requester: Not sending response to requester
DEBUG Sep 19 08:14:30 [listener:964]: Worker 966 is removed from busy list
DEBUG Sep 19 08:14:30 [listener:964]: Realising worker 966
DEBUG Sep 19 08:14:30 [worker:966]: write_packet: write 56 bytes to listener
^C
SF01V_SO01_SFOS 17.0.0 Beta-1#

Hi,

Thank you for looking into that. Please run below command and get the csc.log.

"csc custom debug"

This condition only happens after the first boot after running the initial configuration wizard. If you reboot the firewall via command line, the subsequent reboots are successful.

There is nothing out of the ordinary in tomcat log

final opcode :                                                                  
opcode apiInterface csc/1.2                                                     
content-type:json                                                               
content-length:296

I get the following lines in csc.log when I try to reboot

PAckage ::::dashboard::dashboardshutdownapplianceERROR     Sep 18 09:31:24  [li
stener:964]: ln_recvfrom: fd '94.TCP.INET.auxilary': peer connection closed'Succ
ess'                                                                            
                                                                                
                                                                                
 MODE:1329 FILE NOT FOUND 

and

 PAckage ::::dashboard::dashboardshutdownapplianceERROR     Sep 18 09:32:57  [li
stener:964]: ln_recvfrom: fd '94.TCP.INET.auxilary': peer connection closed'Succ
ess'                                                                            
                                                                                
                                                                                
 MODE:1329 FILE NOT FOUND 
on shutdown command.

Hi Billybob,

Thank you for the reporting one. We tried to reproduce here but it is working fine.

Request to provide the access details or snapshot of logs csc.log, tomcat.log, when you run the command.

Regards,

Deepti Bhavsar

As Moeller pointed out once you reboot via cli, it works fine on subsequent tries. Initially you get the error message of reboot/shutdown failed. Tested with SW-SFOS_17.0.0_Beta-1-32 in hyper v server 2012

Running clean install on Hyper-V.

Can't reboot or shutdown via gui.

Had the same issue, but after rebooting via CLI I was able to reboot via GUI.

Running on HyperV

Tried with a XG85. No problems, device is rebooting.

I probably should have added this is a VM clean installed using the Vmware installer image.