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

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 :
<Up2Date>
  <Package u2dtype="pattern">
    <File name="avira_4.00_1.0.404805_full.tar.gz.gpg">
      <location>d30ncyzaneb4q0.cloudfront.net/.../location>
      <version>1.0.404805</version>
      <size>119373174</size>
      <md5sum>a6d23f3792aef6d0e8d55dcc42a43343</md5sum>
      <module>avira</module>
      <cv>4.00</cv>
      <type>full</type>
    </File>
    <File name="savi_1.00_1.0.14813_full.tar.gz.gpg">
      <location>d30ncyzaneb4q0.cloudfront.net/.../location>
      <version>1.0.14813</version>
      <size>200450618</size>
      <md5sum>dea14e36c979cb4aebd2035d20e8af23</md5sum>
      <module>savi</module>
      <cv>1.00</cv>
      <type>full</type>
    </File>
  </Package>
</Up2Date>
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