[NC- 48712] BUG - /bin/avd: error while loading shared libraries: /sdisk/savi/engine/libsavi.so.3: invalid ELF header

Question

What feature is impacted? Malware Protection / Antivirus Summary of the issues: since update to SFOS 18.0.0 EAP1-Refresh1 Antivirus Service is stopped Changing the engine to Sophos or avira doesn't help Web Proxy is Blocking everything because of Malware scanning error How do we reproduce it (Provide instructions to help us reproduce the behavior): install v18?? -------------------------- SFVUNL_HV01_SFOS 18.0.0 EAP1-Refresh1# service -S antispam RUNNING antivirus STOPPED SFVUNL_HV01_SFOS 18.0.0 EAP1-Refresh1# antivirus: restart 200 OK SFVUNL_HV01_SFOS 18.0.0 EAP1-Refresh1# service -S antispam RUNNING antivirus STOPPED SFVUNL_HV01_SFOS 18.0.0 EAP1-Refresh1# ------------------------ pattern: Avira AV 1.0.404676 - 09:52:02, Nov 01 2019 Failed --------------------------- u2d.log DEBUG Nov 07 13:45:37 [6740]: --serial = C01001V3DKP72C0 DEBUG Nov 07 13:45:37 [6740]: --deviceid = 4dc0510c-8f10-4c9b-be0e-6dd8dd3af5d3 DEBUG Nov 07 13:45:37 [6740]: --fwversion = 18.0.0.113 DEBUG Nov 07 13:45:37 [6740]: --productcode = CN DEBUG Nov 07 13:45:37 [6740]: --model = SF01V DEBUG Nov 07 13:45:37 [6740]: --vendor = HV01 DEBUG Nov 07 13:45:37 [6740]: --pkg_ips_version = 18.16.43 DEBUG Nov 07 13:45:37 [6740]: --pkg_ips_cv = 15.0 DEBUG Nov 07 13:45:37 [6740]: --pkg_atp_version = 1.0.0269 DEBUG Nov 07 13:45:37 [6740]: --pkg_atp_cv = 1.00 DEBUG Nov 07 13:45:37 [6740]: --pkg_savi_version = 1.0.14785 DEBUG Nov 07 13:45:37 [6740]: --pkg_savi_cv = 1.00 DEBUG Nov 07 13:45:37 [6740]: --pkg_avira_version = 1.0.404676 DEBUG Nov 07 13:45:37 [6740]: --pkg_avira_cv = 4.00 DEBUG Nov 07 13:45:37 [6740]: --pkg_apfw_version = 11.0.009 DEBUG Nov 07 13:45:37 [6740]: --pkg_apfw_cv = 1.00 DEBUG Nov 07 13:45:37 [6740]: --pkg_sslvpn_version = 1.0.007 DEBUG Nov 07 13:45:37 [6740]: --pkg_sslvpn_cv = 1.00 DEBUG Nov 07 13:45:37 [6740]: --pkg_ipsec_version = 1.4.001 DEBUG Nov 07 13:45:37 [6740]: --pkg_ipsec_cv = 1.00 DEBUG Nov 07 13:45:37 [6740]: --pkg_geoip_version = 1.0.001 DEBUG Nov 07 13:45:37 [6740]: --pkg_geoip_cv = 1.00 DEBUG Nov 07 13:45:37 [6740]: --pkg_clientauth_version = 1.0.0017 DEBUG Nov 07 13:45:37 [6740]: --pkg_clientauth_cv = 2.00 DEBUG Nov 07 13:45:37 [6740]: --pkg_redfw_version = 2.0.018 DEBUG Nov 07 13:45:37 [6740]: --pkg_redfw_cv = 2.00 DEBUG Nov 07 13:45:37 [6740]: --oem = Sophos DEBUG Nov 07 13:45:37 [6740]: Added new server : Host - us-west-2.u2d.sophos.com., Port - 443 DEBUG Nov 07 13:45:37 [6740]: Added new server : Host - eu-west-1.u2d.sophos.com., Port - 443 DEBUG Nov 07 13:45:37 [6740]: Added new server : Host - ap-northeast-1.u2d.sophos.com., Port - 443 DEBUG Nov 07 13:45:37 [6740]: Final query string is : ?&serialkey=C01001V3DKP72C0&deviceid=4dc0510c-8f10-4c9b-be0e-6dd8dd3af5d3&fwversion=18.0.0.113&productcode=CN&appmodel=SF01V&appvendor=HV01&useragent=SF&oem=Sophos&pkg_ips_version=18.16.43&pkg_ips_cv=15.0&pkg_atp_version=1.0.0269&pkg_atp_cv=1.00&pkg_savi_version=1.0.14785&pkg_savi_patch=2&pkg_savi_cv=1.00&pkg_avira_version=1.0.404676&pkg_avira_patch=2&pkg_avira_cv=4.00&pkg_geoip_version=1.0.001&pkg_geoip_cv=1.00&pkg_clientauth_version=1.0.0017&pkg_clientauth_cv=2.00&pkg_apfw_version=11.0.009&pkg_apfw_cv=1.00&pkg_redfw_version=2.0.018&pkg_redfw_cv=2.00&pkg_sslvpn_version=1.0.007&pkg_sslvpn_cv=1.00&pkg_ipsec_version=1.4.001&pkg_ipsec_cv=1.00 DEBUG Nov 07 13:45:38 [6740]: Response code : 200 DEBUG Nov 07 13:45:38 [6740]: Response body : d30ncyzaneb4q0.cloudfront.net/.../location> 1.0.404805 119373174 a6d23f3792aef6d0e8d55dcc42a43343 avira 4.00 full d30ncyzaneb4q0.cloudfront.net/.../location> 1.0.14813 200450618 dea14e36c979cb4aebd2035d20e8af23 savi 1.00 full DEBUG Nov 07 13:45:38 [6740]: Response length : 788 DEBUG Nov 07 13:45:38 [6740]: Received name : avira_4.00_1.0.404805_full.tar.gz.gpg DEBUG Nov 07 13:45:38 [6740]: Received location : d30ncyzaneb4q0.cloudfront.net/avira_4.00_1.0.404805_full.tar.gz.gpg DEBUG Nov 07 13:45:38 [6740]: Received version : 1.0.404805 DEBUG Nov 07 13:45:38 [6740]: Received size : 119373174 DEBUG Nov 07 13:45:38 [6740]: Received md5sum : a6d23f3792aef6d0e8d55dcc42a43343 DEBUG Nov 07 13:45:38 [6740]: Received module : avira DEBUG Nov 07 13:45:38 [6740]: Received cv : 4.00 DEBUG Nov 07 13:45:38 [6740]: Received type : full DEBUG Nov 07 13:45:38 [6740]: Received name : savi_1.00_1.0.14813_full.tar.gz.gpg DEBUG Nov 07 13:45:38 [6740]: Received location : d30ncyzaneb4q0.cloudfront.net/savi_1.00_1.0.14813_full.tar.gz.gpg DEBUG Nov 07 13:45:38 [6740]: Received version : 1.0.14813 DEBUG Nov 07 13:45:38 [6740]: Received size : 200450618 DEBUG Nov 07 13:45:38 [6740]: Received md5sum : dea14e36c979cb4aebd2035d20e8af23 DEBUG Nov 07 13:45:38 [6740]: Received module : savi DEBUG Nov 07 13:45:38 [6740]: Received cv : 1.00 DEBUG Nov 07 13:45:38 [6740]: Received type : full avd.log: 2019-11-01 09:55:30 :[INFO] 0 display_sophos_version: Extended version : 1 2019-11-01 09:55:30 :[INFO] 0 display_sophos_version: Threat data version string(IDE) : 5.69 2019-11-01 09:55:30 :[INFO] 0 display_sophos_version: Number of detectable threats : 43353052 2019-11-01 09:55:30 :[INFO] 0 display_sophos_version: Date of threat data (D/M/Y) : 22/10/2019 2019-11-01 09:55:30 :[INFO] 99 sophos_reload_sig: Every thread reloaded new savi object, safe to start scanning /bin/avd: error while loading shared libraries: /sdisk/savi/engine/libsavi.so.3: invalid ELF header /bin/avd: error while loading shared libraries: /sdisk/savi/engine/libsavi.so.3: invalid ELF header /bin/avd: error while loading shared libraries: /sdisk/savi/engine/libsavi.so.3: invalid ELF header /bin/avd: error while loading shared libraries: /sdisk/savi/engine/libsavi.so.3: invalid ELF header /bin/avd: error while loading shared libraries: /sdisk/savi/engine/libsavi.so.3: invalid ELF header /bin/avd: error while loading shared libraries: /sdisk/savi/engine/libsavi.so.3: invalid ELF header ------------------------- csc.log DEBUG Nov 07 13:19:15 [antivirus:1392]: # SERVICE Called: 'antivirus:start' DEBUG Nov 07 13:19:15 [antivirus:1392]: antivirus: ------------- DEBUG Nov 07 13:19:15 [antivirus:1392]: request method = service DEBUG Nov 07 13:19:15 [antivirus:1392]: request name = antivirus:start DEBUG Nov 07 13:19:15 [antivirus:1392]: request version = 1.14 DEBUG Nov 07 13:19:15 [antivirus:1392]: content length = 0 DEBUG Nov 07 13:19:15 [antivirus:1392]: content type = text DEBUG Nov 07 13:19:15 [antivirus:1392]: response code = 0 DEBUG Nov 07 13:19:15 [antivirus:1392]: response string len = 0 DEBUG Nov 07 13:19:15 [antivirus:1392]: ----------- INFO Nov 07 13:19:15 [antivirus:1392]: handle_service_command: start: status = STOPPED NOTICE Nov 07 13:19:15 [antivirus:1392]: do_start(): (try=0) current-status = STOPPED INFO Nov 07 13:19:15 [antivirus:1392]: do_real_start() INFO Nov 07 13:19:15 [antivirus:1392]: do_real_start(): running before_start INFO Nov 07 13:19:15 [antivirus:1392]: do_real_start(): before_start success INFO Nov 07 13:19:15 [antivirus:1392]: start_service() in foreground DEBUG Nov 07 13:19:15 [antivirus:1392]: start_service[antivirus]: started successfully INFO Nov 07 13:19:15 [antivirus:1392]: service command 'bstart': time taken: 0.071412900 seconds DEBUG Nov 07 13:19:15 [antivirus:1392]: # SERVICE Exited: 'antivirus:bstart' with Status: '200' DEBUG Nov 07 13:19:15 [antivirus:1392]: write_packet: 52+0+2 DEBUG Nov 07 13:19:15 [listener:1336]: read_response_from_sockpair: 54 bytes read from sockpair service antivirus DEBUG Nov 07 13:19:15 [listener:1336]: is_response_complete: Complete response is received from sockpair service antivirus DEBUG Nov 07 13:19:15 [listener:1336]: Received response from worker DEBUG Nov 07 13:19:15 [listener:1336]: ln_sendto: fd '5.UDP.INET.server' has sent 17 bytes to requester DEBUG Nov 07 13:19:15 [listener:1336]: Listener has sent data to requester INFO Nov 07 13:19:15 [manage_servers:2636]: create_act_out_perl_obj: varname=out INFO Nov 07 13:19:15 [manage_servers:2636]: create_act_out_perl_obj: out.status=200 INFO Nov 07 13:19:15 [manage_servers:2636]: create_act_out_perl_obj: out.error=OK INFO Nov 07 13:19:15 [manage_servers:2636]: ACTION: CALL LOG_MESSAGE INFO Nov 07 13:19:15 [manage_servers:2636]: ACTION: DLOPEN(get_time, (null)) DEBUG Nov 07 13:19:15 [manage_servers:2636]: ws_do_evlog: FD: 4 DEBUG Nov 07 13:19:15 [manage_servers:2636]: do_evlog_to_file: FD: 4 DEBUG Nov 07 13:19:15 [antivirus:1392]: write_packet: write 54 bytes to listener INFO Nov 07 13:19:15 [manage_servers:2636]: opcode 'manage_servers': time taken: 0.197292100 seconds DEBUG Nov 07 13:19:15 [worker:2636]: response: PAckage ::::system::servicesmanageINFO Nov 07 13:19:15 [child:2647]: run_service() DEBUG Nov 07 13:19:15 [child:2647]: EXPORT LD_LIBRARY_PATH = /sdisk/savi/engine:/sdisk/avira4:/sdisk/conan_new/conan/libs ERROR Nov 07 13:19:15 [listener:1336]: csc_waitpid: pid(2636) exited with signal 9 DEBUG Nov 07 13:19:15 [listener:1336]: Main TLV:{ 4, data:{ 1, 4, 0000} data:{ 2, 4, 4CA00} data:{ 5, 4, 1000} , 27} DEBUG Nov 07 13:19:15 [listener:1336]: csc_socketpair called: biggest fd is 107 DEBUG Nov 07 13:19:15 [listener:1336]: Realising worker 2648 ERROR Nov 07 13:19:15 [listener:1336]: ln_recvfrom: fd '106.TCP.INET.auxilary': peer connection closed'Success' DEBUG Nov 07 13:19:15 [listener:1336]: release_fd_struct: fd '106.TCP.INET.auxilary' is closed DEBUG Nov 07 13:19:15 [child:2647]: run_service: filename '/bin/avd' DEBUG Nov 07 13:19:15 [child:2647]: run_service: argv[0] = '/bin/avd' DEBUG Nov 07 13:19:15 [child:2647]: run_service: argv[1] = '-c' DEBUG Nov 07 13:19:15 [child:2647]: run_service: argv[2] = '/cfs/proxy/av/avd.conf' INFO Nov 07 13:19:15 [child:2647]: in_fd: -1 DEBUG Nov 07 13:19:15 [child:2647]: open_log_fd INFO Nov 07 13:19:15 [child:2647]: open_log_fd: 1 NOTICE Nov 07 13:19:15 [antivirus:1392]: received SIGCHLD MESSAGE Nov 07 13:19:15 [antivirus:1392]: do_stop(): status = EXITING DEBUG Nov 07 13:19:15 [antivirus:1392]: stop_service(): stop foreground service with pid 2647 DEBUG Nov 07 13:19:15 [antivirus:1392]: kill_service(): killpg(2647,9) DEBUG Nov 07 13:19:15 [antivirus:1392]: do_waitpid: cpid=2647 timeout=-1 pollmsec=100 MESSAGE Nov 07 13:19:15 [antivirus:1392]: do_waitpid: pid 2647 exited with status 127 INFO Nov 07 13:19:15 [antivirus:1392]: stop_service[antivirus] stopped NOTICE Nov 07 13:19:15 [antivirus:1392]: will retry after '15' seconds EBUG Nov 07 13:19:15 [antivirus:1392]: read_packet: read() 52 bytes from listener DEBUG Nov 07 13:19:15 [antivirus:1392]: # SERVICE Called: 'antivirus:status' DEBUG Nov 07 13:19:15 [antivirus:1392]: antivirus: ----------- DEBUG Nov 07 13:19:15 [antivirus:1392]: request method = service DEBUG Nov 07 13:19:15 [antivirus:1392]: request name = antivirus:status DEBUG Nov 07 13:19:15 [antivirus:1392]: request version = 1.10 DEBUG Nov 07 13:19:15 [antivirus:1392]: content length = 0 DEBUG Nov 07 13:19:15 [antivirus:1392]: content type = text DEBUG Nov 07 13:19:15 [antivirus:1392]: response code = 0 DEBUG Nov 07 13:19:15 [antivirus:1392]: response string len = 0 DEBUG Nov 07 13:19:15 [antivirus:1392]: ----------- INFO Nov 07 13:19:15 [antivirus:1392]: service command 'status': time taken: 0.000000600 seconds DEBUG Nov 07 13:19:15 [antivirus:1392]: # SERVICE Exited: 'antivirus:status' with Status: '200' DEBUG Nov 07 13:19:15 [antivirus:1392]: write_packet: 52+0+7 DEBUG Nov 07 13:19:15 [antivirus:1392]: write_packet: write 59 bytes to listener

Apurv Patel · Accepted Answer

Hi ReBorn, 
 Thanks for the device access. 
 We have checked old logs and identify that this issue is the same as JIRA id NC- 48712. 
 This bug is resolved and part of the EAP2 firmware.