Thread Info
  • State Verified Answer
  • Locked Locked
  • Replies 8 replies
  • Subscribers 29 subscribers
  • Views 3265 views
  • Users 0 members are here
Options
Suggested
This discussion has been locked.
You can no longer post new replies to this discussion. If you have a question you can start a new discussion

Webproxy fails to start with any of the new firmwares

Bobten Berge

Currently running SFOS 17.1.3 MR-3, everything is working just fine.

I tried upgrading to SW-17.5.0_GA.SFW-321, but the webproxy won't start.

So I booted back to 17.1.3 MR-3, everything was working fine again.

I tried upgrading again, this time to SW-17.1.4_MR-4.SFW-254. Again, the webproxy fails to start.

Right now I'm back to the working 17.1.3 MR-3 firmware.

 

When the webproxy failed to start on the newer firmware versions, the awarrenhttp.log entries always stopped right after the last line from this snippet:

1548831635.915375955 [ 9654/ (nil)] awarrenhttp.c:378 main ------------------------------------------------------------------
1548831635.915380792 [ 9654/ (nil)] awarrenhttp.c:379 main Starting ...
1548831635.915416492 [ 9654/ (nil)] awarrenhttp.c:404 main reading configuration
1548831635.915422537 [ 9654/ (nil)] config.c:378 config_init called
1548831636.064432413 [ 9654/ (nil)] config.c:179 cfg_init No sandstorm license!
1548831637.073973540 [ 9654/ (nil)] acl-ds-db.c:420 db_init database connection established [corporate]
1548831637.076516323 [ 9654/ (nil)] acl-ds-db.c:436 db_init database connection established [signature]
1548831637.077140263 [ 9654/ (nil)] acl-parsefile.c:1001 read_frm_file Processing [/static/proxy/awarrenhttp/header]
1548831637.077312444 [ 9654/ (nil)] acl-common.c:769 validate_addr Not CIDR mask; continuing as it is...
1548831637.077362128 [ 9654/ (nil)] acl-common.c:769 validate_addr Not CIDR mask; continuing as it is...
1548831637.090675887 [ 9654/ (nil)] acl-parsefile.c:531 parse_acl_line Duplicate acl name 'ALL', at lineno 79
1548831638.521904444 [ 9654/ (nil)] acl-parsefile.c:1001 read_frm_file Processing [/static/proxy/awarrenhttp/tailer]
1548831638.527675594 [ 9654/ (nil)] diskcache.c:1816 disk_cache_read fopen: /sdisk/httpcache/cacheidx: No such file or directory
1548831638.527715113 [ 9654/ (nil)] diskcache.c:224 disk_cache_zap creating cache
1548831638.755476219 [ 9673/ (nil)] diskcache.c:518 rmdir_recursive_background_func removing zapped cache root folder /sdisk/httpcache.001
1548831638.755569162 [ 9654/ (nil)] awarrenhttp.c:307 init_process Limits: threads: 2, maxconns: 11264, max fd: 67708, coredump: yes
1548831638.763974779 [ 9654/ (nil)] ssl.c:964 ssl_load_cert Failed to read file: '/conf/certificate/cacerts/8d28ae65.0'
1548831638.764002122 [ 9654/ (nil)] ssl.c:1041 ssl_prepare_chain Couldn't find Issuer certificate
1548831638.764006854 [ 9654/ (nil)] ssl.c:1221 init_portal Failed to create ssl chain
1548831638.764365115 [ 9654/ (nil)] ssl.c:964 ssl_load_cert Failed to read file: '/conf/certificate/cacerts/d8ed19fe.0'
1548831638.764372704 [ 9654/ (nil)] ssl.c:1041 ssl_prepare_chain Couldn't find Issuer certificate
1548831638.764377030 [ 9654/ (nil)] ssl.c:1221 init_portal Failed to create ssl chain

Now I thought the problem was coming from wither the missing file or directory "/sdisk/httpcache/cacheidx", or perhaps the missing certificate files, but:
On the current firmware (17.1.3 MR-3) with a working webproxy, the log shows:

1548831832.589621911 [ 3052/ (nil)] awarrenhttp.c:378 main ------------------------------------------------------------------
1548831832.589632979 [ 3052/ (nil)] awarrenhttp.c:379 main Starting ...
1548831832.707459646 [ 3052/ (nil)] awarrenhttp.c:404 main reading configuration
1548831832.797488620 [ 3052/ (nil)] config.c:378 config_init called
1548831869.303533074 [ 3052/ (nil)] config.c:179 cfg_init No sandstorm license!
1548831869.579866909 [ 3052/ (nil)] acl-ds-db.c:420 db_init database connection established [corporate]
1548831869.626971402 [ 3052/ (nil)] acl-ds-db.c:436 db_init database connection established [signature]
1548831869.627578249 [ 3052/ (nil)] acl-parsefile.c:1001 read_frm_file Processing [/static/proxy/awarrenhttp/header]
1548831869.631299308 [ 3052/ (nil)] acl-common.c:769 validate_addr Not CIDR mask; continuing as it is...
1548831869.631378706 [ 3052/ (nil)] acl-common.c:769 validate_addr Not CIDR mask; continuing as it is...
1548831894.152405230 [ 3052/ (nil)] acl-parsefile.c:531 parse_acl_line Duplicate acl name 'ALL', at lineno 79
1548831903.234682127 [ 3052/ (nil)] acl-parsefile.c:1001 read_frm_file Processing [/static/proxy/awarrenhttp/tailer]
1548831903.263270321 [ 3052/ (nil)] diskcache.c:1816 disk_cache_read fopen: /sdisk/httpcache/cacheidx: No such file or directory
1548831903.263312303 [ 3052/ (nil)] diskcache.c:224 disk_cache_zap creating cache
1548831903.490120754 [ 3052/ (nil)] awarrenhttp.c:307 init_process Limits: threads: 2, maxconns: 11264, max fd: 67708, coredump: yes
1548831903.503588679 [ 5482/ (nil)] diskcache.c:518 rmdir_recursive_background_func removing zapped cache root folder /sdisk/httpcache.001
1548831903.543539227 [ 3052/ (nil)] ssl.c:964 ssl_load_cert Failed to read file: '/conf/certificate/cacerts/8d28ae65.0'
1548831903.543558492 [ 3052/ (nil)] ssl.c:1041 ssl_prepare_chain Couldn't find Issuer certificate
1548831903.543563757 [ 3052/ (nil)] ssl.c:1221 init_portal Failed to create ssl chain
1548831903.586339795 [ 3052/ (nil)] awarrenhttp.c:447 main Using 2 worker threads
1548831903.586363862 [ 3052/ (nil)] epoll.c:1130 event_threads_init called
1548831903.588902465 [ 5485/ (nil)] dns.c:1550 dns_cache_init initialized
1548831903.604437365 [ 3052/ (nil)] awarrenhttp.c:453 main finished startup
1548831903.604456785 [ 3052/ (nil)] awarrenhttp.c:455 main Integrated HTTP-Proxy Release aa6cbf1@0.local1537360069
1548831904.530090077 [ 5482/ (nil)] diskcache.c:518 rmdir_recursive_background_func removing zapped cache root folder /sdisk/httpcache.002
1548831904.923288104 [ 5386/ (nil)] config.c:263 process_sig_event [1210] signal: Hangup
1548831904.923316059 [ 5386/ (nil)] config.c:195 cfg_reload reloading config
1548831906.113767654 [ 5482/ (nil)] diskcache.c:518 rmdir_recursive_background_func removing zapped cache root folder /sdisk/httpcache.003
1548831906.744612535 [ 5386/ (nil)] config.c:179 cfg_init No sandstorm license!
1548831906.821316825 [ 5386/ (nil)] acl-ds-db.c:420 db_init database connection established [corporate]
1548831906.890106568 [ 5386/ (nil)] acl-ds-db.c:436 db_init database connection established [signature]
1548831906.890731386 [ 5386/ (nil)] acl-parsefile.c:1001 read_frm_file Processing [/static/proxy/awarrenhttp/header]
1548831906.890871220 [ 5386/ (nil)] acl-common.c:769 validate_addr Not CIDR mask; continuing as it is...
1548831906.890921577 [ 5386/ (nil)] acl-common.c:769 validate_addr Not CIDR mask; continuing as it is...
1548831907.356483445 [ 5482/ (nil)] diskcache.c:518 rmdir_recursive_background_func removing zapped cache root folder /sdisk/httpcache.004
1548831908.300418118 [ 5482/ (nil)] diskcache.c:518 rmdir_recursive_background_func removing zapped cache root folder /sdisk/httpcache.005
1548831909.225631071 [ 5482/ (nil)] diskcache.c:518 rmdir_recursive_background_func removing zapped cache root folder /sdisk/httpcache.006
1548831910.575056408 [ 5482/ (nil)] diskcache.c:518 rmdir_recursive_background_func removing zapped cache root folder /sdisk/httpcache.007
1548831911.560964975 [ 5482/ (nil)] diskcache.c:518 rmdir_recursive_background_func removing zapped cache root folder /sdisk/httpcache.008
1548831912.543642227 [ 5482/ (nil)] diskcache.c:518 rmdir_recursive_background_func removing zapped cache root folder /sdisk/httpcache.009
1548831913.482103968 [ 5482/ (nil)] diskcache.c:518 rmdir_recursive_background_func removing zapped cache root folder /sdisk/httpcache.010
1548831914.438064422 [ 5482/ (nil)] diskcache.c:518 rmdir_recursive_background_func removing zapped cache root folder /sdisk/httpcache.011
1548831927.233302448 [ 5386/ (nil)] acl-parsefile.c:531 parse_acl_line Duplicate acl name 'ALL', at lineno 79
1548831930.262614633 [ 5486/0x7ffaf38bf800] http_transform.c:245 http_transform_apply_one_io_async unable to execute io transform
1548831931.514962978 [ 5386/ (nil)] acl-parsefile.c:1001 read_frm_file Processing [/static/proxy/awarrenhttp/tailer]
1548831931.560159309 [ 5386/ (nil)] config.c:209 cfg_reload reloaded signer key/cert
1548831931.560521555 [ 5386/ (nil)] ssl.c:964 ssl_load_cert Failed to read file: '/conf/certificate/cacerts/8d28ae65.0'
1548831931.560533700 [ 5386/ (nil)] ssl.c:1041 ssl_prepare_chain Couldn't find Issuer certificate
1548831931.560538597 [ 5386/ (nil)] ssl.c:1221 init_portal Failed to create ssl chain
1548831931.561187680 [ 5386/ (nil)] config.c:213 cfg_reload reloaded portal key/cert
1548831931.561332227 [ 5386/ (nil)] config.c:217 cfg_reload reloaded client key/cert
1548831931.567766871 [ 5386/ (nil)] config.c:225 cfg_reload reloading config done
1548831931.567816079 [ 5386/ (nil)] config.c:263 process_sig_event [1210] signal: Hangup
1548831931.567821788 [ 5386/ (nil)] config.c:195 cfg_reload reloading config
1548831932.541325264 [ 5386/ (nil)] config.c:179 cfg_init No sandstorm license!
1548831932.562439913 [ 5386/ (nil)] acl-ds-db.c:420 db_init database connection established [corporate]
1548831932.581515032 [ 5386/ (nil)] acl-ds-db.c:436 db_init database connection established [signature]
1548831932.582151448 [ 5386/ (nil)] acl-parsefile.c:1001 read_frm_file Processing [/static/proxy/awarrenhttp/header]
1548831932.582265879 [ 5386/ (nil)] acl-common.c:769 validate_addr Not CIDR mask; continuing as it is...
1548831932.582316897 [ 5386/ (nil)] acl-common.c:769 validate_addr Not CIDR mask; continuing as it is...
1548831940.567897524 [ 5386/ (nil)] acl-parsefile.c:531 parse_acl_line Duplicate acl name 'ALL', at lineno 79
1548831943.603154327 [ 5485/0x7ffaee149400] http_transform.c:245 http_transform_apply_one_io_async unable to execute io transform
1548831944.132443298 [ 5386/ (nil)] acl-parsefile.c:1001 read_frm_file Processing [/static/proxy/awarrenhttp/tailer]
1548831944.151420207 [ 5386/ (nil)] config.c:209 cfg_reload reloaded signer key/cert
1548831944.151746317 [ 5386/ (nil)] ssl.c:964 ssl_load_cert Failed to read file: '/conf/certificate/cacerts/8d28ae65.0'
1548831944.151754618 [ 5386/ (nil)] ssl.c:1041 ssl_prepare_chain Couldn't find Issuer certificate
1548831944.151758924 [ 5386/ (nil)] ssl.c:1221 init_portal Failed to create ssl chain
1548831944.152373791 [ 5386/ (nil)] config.c:213 cfg_reload reloaded portal key/cert
1548831944.152512603 [ 5386/ (nil)] config.c:217 cfg_reload reloaded client key/cert
1548831944.158116249 [ 5386/ (nil)] config.c:225 cfg_reload reloading config done

 

The "disk_cache_read fopen: /sdisk/httpcache/cacheidx: No such file or directory"and "init_portal Failed to create ssl chain" errors are still here, but the process does go on starting up and working as intended.

I checked for the reported missing files, but even with the running webproxy they aren't there.

So why won't the webproxy start with either of the newer firmware versions? I'm very reluctant to upgrade right now...



This thread was automatically locked due to age.
Parents Reply Children
  • 0 in reply to Aditya Patel

    Thanks for trying to help so far LuCar and Aditya.

    I've upgraded to 17.5 MR 1 and the problem still exists.

     

    The logging ends the same:

    1548880107.786288336 [ 8070/ (nil)] awarrenhttp.c:378 main ------------------------------------------------------------------
    1548880107.786295503 [ 8070/ (nil)] awarrenhttp.c:379 main Starting ...
    1548880107.786333719 [ 8070/ (nil)] awarrenhttp.c:404 main reading configuration
    1548880107.786342441 [ 8070/ (nil)] config.c:382 config_init called
    1548880107.787984908 [ 8070/ (nil)] config.c:179 cfg_init No sandstorm license!
    1548880108.796333689 [ 8070/ (nil)] acl-ds-db.c:479 db_init database connection established [corporate]
    1548880108.798994321 [ 8070/ (nil)] acl-ds-db.c:495 db_init database connection established [signature]
    1548880108.799607118 [ 8070/ (nil)] acl-parsefile.c:1002 read_frm_file Processing [/static/proxy/awarrenhttp/header]
    1548880108.799775474 [ 8070/ (nil)] acl-common.c:772 validate_addr Not CIDR mask; continuing as it is...
    1548880108.799822006 [ 8070/ (nil)] acl-common.c:772 validate_addr Not CIDR mask; continuing as it is...
    1548880108.814360251 [ 8070/ (nil)] acl-parsefile.c:532 parse_acl_line Duplicate acl name 'ALL', at lineno 80
    1548880110.323253482 [ 8070/ (nil)] acl-parsefile.c:1002 read_frm_file Processing [/static/proxy/awarrenhttp/tailer]
    1548880110.330985319 [ 8070/ (nil)] diskcache.c:1816 disk_cache_read fopen: /sdisk/httpcache/cacheidx: No such file or directory
    1548880110.331096678 [ 8070/ (nil)] diskcache.c:224 disk_cache_zap creating cache
    1548880110.413103989 [ 8070/ (nil)] awarrenhttp.c:307 init_process Limits: threads: 2, maxconns: 11264, max fd: 67708, coredump: yes
    1548880110.420410764 [ 8084/ (nil)] diskcache.c:518 rmdir_recursive_background_func removing zapped cache root folder /sdisk/httpcache.001
    1548880110.421760022 [ 8070/ (nil)] ssl.c:964 ssl_load_cert Failed to read file: '/conf/certificate/cacerts/8d28ae65.1'
    1548880110.421861772 [ 8070/ (nil)] ssl.c:1041 ssl_prepare_chain Couldn't find Issuer certificate
    1548880110.421910895 [ 8070/ (nil)] ssl.c:1221 init_portal Failed to create ssl chain
    1548880110.422352980 [ 8070/ (nil)] ssl.c:964 ssl_load_cert Failed to read file: '/conf/certificate/cacerts/d8ed19fe.0'
    1548880110.422428258 [ 8070/ (nil)] ssl.c:1041 ssl_prepare_chain Couldn't find Issuer certificate
    1548880110.422489887 [ 8070/ (nil)] ssl.c:1221 init_portal Failed to create ssl chain
    It now refers to "/conf/certificate/cacerts/8d28ae65.1" instead of "/conf/certificate/cacerts/8d28ae65.0", because I linked the latter to Default.pem.

    At one point I was able to run "awarrenhttp -n -c /cfs/proxy/http/awarrenhttp.conf" manually after I made that symbolic link, but while it was active, the page System Services -> Services would not load at all anymore.

    It didn't work at all anymore after killing the awarrenhttp process. I have rebooted the firewall to go back to a "clean" state, where I didn't make any changes in the CLI.

    I'll keep the firmware at 17.5.1 MR-1 for now, without any web policy active. If I can try anything out, please let me know.

  • 0 in reply to Bobten Berge

    Hello Bobten,

    That is not expected, have you raised the service request with Sophos Support to verify the issue. At least you have upgraded the firmware to represent the issue on the latest firmware.

    It does seem an issue with the configuration file and certificate so best to open a case and private me the details with the reference to this thread.

  • 0 in reply to Aditya Patel

    Thank you Aditya, I have opened a support case and PM'd you the case # and reference to this topic.

    I'm not sure, but I have some additional issues that seem related.

    I've been trying to add a private CA, to test if that fixes the main webproxy issue, but I'm not able to upload any CA certificates.

    Uploading a regular certificate does work.

     

    Whenever I try to upload a CA certificate and key (plus password), the whole process times out and I get to see this popup forhalf a second:

    The System log however, never shows anything about this.

    Everytime I try something with the CA certificates, this process "/sbin/perl /bin/c_rehash /conf/certificate/cacerts/" uses up 99% CPU for a minute or two and then just ends.

    My custom CA never gets added.

  • +1 in reply to Bobten Berge

    Good news, I fixed the problem!

    I ran the script "perl /bin/c_rehash /conf/certificate/cacerts" manually and noticed that it generated a seemingly endless output on one certificate:

    Doing myutm.mydomain.org_CA_59DFBD16.pem
    Doing myutm.mydomain.org_CA_59DFBD16.pem
    Doing myutm.mydomain.org_CA_59DFBD16.pem
    Doing myutm.mydomain.org_CA_59DFBD16.pem
    Doing myutm.mydomain.org_CA_59DFBD16.pem
    Doing myutm.mydomain.org_CA_59DFBD16.pem
    Doing myutm.mydomain.org_CA_59DFBD16.pem
    Doing myutm.mydomain.org_CA_59DFBD16.pem
    Doing myutm.mydomain.org_CA_59DFBD16.pem
    Doing myutm.mydomain.org_CA_59DFBD16.pem
    Doing myutm.mydomain.org_CA_59DFBD16.pem

    I happen to have a certificate signed by Komodo, using it for administration access. NOT for the webproxy (this isn't even possible, because it's not a CA certificate).

    I figured that the above "myutm.mydomain.org_CA_59DFBD16.pem" must be one of the intermediate CA certificates, so I looked it up under "Certificate Authorities" and re-uploaded one of the 3 provided trusted certificates. Uploading the CA certificate actually worked this time, so I was hopeful!

    After doing this, I re-ran the perl script and this time it finished in no time. Still looking good!

    I returned to "System Services" -> "Services" in the GUI and clicked Restart next to Webproxy. It actually started and it's still running!

    Furthermore, this also fixed the issue that I couldn't upload my private CA certificate and key.

    So, short story long, it looks like one of the intermediate trust CA certificates from Komodo was corrupted somehow, after uploading it again this problem was solved.

  • 0 in reply to Bobten Berge

    The PFX format includes intermediate certificates, however there was an reported issue (that we could not reproduce) where the web proxy had trouble with it.  However I don't think that caused the proxy to not start.  The solution was to import the intermediate certificate separately.

     

    Oh, I should add that that certificate used by WebAdmin is also used by the web proxy for Captive Portal, Sandstorm, and a few other pages on port :8090.