astrada / google-drive-ocamlfuse

FUSE filesystem over Google Drive
https://astrada.github.io/google-drive-ocamlfuse/
MIT License
5.45k stars 346 forks source link

Failure Code: 77, Description: CURLE_SSL_CACERT_BADFILE #511

Open mschaaf opened 5 years ago

mschaaf commented 5 years ago

After some hours of running I get this error. I can recover by unmounting and mounting again. I found the following in the logs.

[5571.199586] TID=56638: BEGIN: Updating mode (remote id=1rplUOe9KalADEkIhwQhvhjdL1cuhfFOc, mode=100600)
[5571.251983] TID=56638: Error during request: Code: 77, Description: CURLE_SSL_CACERT_BADFILE, ErrorBuffer: ~*ï\

[5571.252091] TID=56638: Giving up
[5571.252155] TID=56638: Exception:Failure("Code: 77, Description: CURLE_SSL_CACERT_BADFILE, ErrorBuffer: \144~*\239\\\127\n")
Backtrace:
[7051.219670] TID=56639: getattr /
[7051.219812] TID=56639: BEGIN: Getting metadata from context
[7051.219860] TID=56639: END: Getting metadata: Not valid
[7051.219902] TID=56639: BEGIN: Refreshing metadata
[7051.268353] TID=56639: Error during request: Code: 77, Description: CURLE_SSL_CACERT_BADFILE, ErrorBuffer:  ~*ï\

[7051.268460] TID=56639: Giving up
[7051.268525] TID=56639: Exception:Failure("Code: 77, Description: CURLE_SSL_CACERT_BADFILE, ErrorBuffer: \160~*\239\\\127\n")
Backtrace:

I run version 0.7.1 on Ubuntu 18.04. How can I prevent this error?

astrada commented 5 years ago

There is some problem with your certificates/certificate storage. Other than a failing file-system, do you have any proxy/profiler that intercepts SSL connections (something like this)?

mschaaf commented 5 years ago

I don't use any proxy/profiler that intercepts SSL connections. I also don't see how the linked post applies here. Please clarify what I should look for exactly. If there is an issue with my certificate storage why does it work on a fresh start of google-drive-ocamlfuse? How can I debug the difference in the certificate handling between a fresh start of google-drive-ocamlfuse and the handling on the metadata refresh? Who is throwing the error "CURLE_SSL_CACERT_BADFILE" google-drive-ocamlfuse or a 3rd party library?

astrada commented 5 years ago

If you mount with -debug you will see in curl.log which path/certificate libcurl is going to use. E.g.:

[0.245063] curl: info:   Trying 172.217.23.106...
[0.245149] curl: info: TCP_NODELAY set
[0.278671] curl: info: Connected to www.googleapis.com (172.217.23.106) port 443 (#0)
[0.297485] curl: info: found 133 certificates in /etc/ssl/certs/ca-certificates.crt
[0.928481] curl: info: found 402 certificates in /etc/ssl/certs
[0.928576] curl: info: ALPN, offering h2
[0.928589] curl: info: ALPN, offering http/1.1
[1.112760] curl: info: SSL connection using TLS1.2 / ECDHE_ECDSA_CHACHA20_POLY1305
[1.233939] curl: info:   server certificate verification OK
[1.233984] curl: info:   server certificate status verification SKIPPED
[1.234423] curl: info:   common name: *.googleapis.com (matched)
[1.234440] curl: info:   server certificate expiration date OK
[1.234449] curl: info:   server certificate activation date OK
[1.234468] curl: info:   certificate public key: EC/ECDSA
[1.234478] curl: info:   certificate version: #3
[1.234523] curl: info:   subject: C=US,ST=California,L=Mountain View,O=Google LLC,CN=*.googleapis.com
[1.234545] curl: info:   start date: Tue, 30 Oct 2018 13:14:00 GMT
[1.234557] curl: info:   expire date: Tue, 22 Jan 2019 13:14:00 GMT
[1.234585] curl: info:   issuer: C=US,O=Google Trust Services,CN=Google Internet Authority G3
[1.234595] curl: info:   compression: NULL
mschaaf commented 5 years ago

So I started with debug and get the same message like you, but when it fails the message is:

[8282.566132] curl: info: Connection #0 to host www.googleapis.com left intact
[8282.619868] curl: info:   Trying 216.58.207.42...
[8282.619967] curl: info: TCP_NODELAY set
[8282.639570] curl: info: Connected to www.googleapis.com (216.58.207.42) port 443 (#0)
[8282.639797] curl: info: error reading ca cert file /etc/ssl/certs/ca-certificates.crt (Error while reading file.)
[8282.639911] curl: info: Closing connection 0
[9124.139679] curl: info: Could not resolve host: www.googleapis.com
[9124.139759] curl: info: Closing connection 0
[9124.144580] curl: info: Could not resolve host: www.googleapis.com
[9124.144637] curl: info: Closing connection 0

The file /etc/ssl/certs/ca-certificates.crt is readable as the user that starts the service.

The gdfuse.log has the following in it at the time of failure

[8282.950376] TID=93597: Error during request: Code: 77, Description: CURLE_SSL_CACERT_BADFILE, ErrorBuffer: 0~Té<

[8282.950447] TID=93597: Giving up
[8282.950508] TID=93597: Exception:Failure("Code: 77, Description: CURLE_SSL_CACERT_BADFILE, ErrorBuffer: 0~T\233<\127\n")
Backtrace:
[8284.269589] TID=1: Flushing DB...[8284.270796] TID=1: Retrying (1/8) final_step after exception: Failure("Sqlite3 error: CANTOPEN")
[8285.839713] TID=1: Retrying (2/8) final_step after exception: Failure("Sqlite3 error: CANTOPEN")
[8287.890251] TID=1: Retrying (3/8) final_step after exception: Failure("Sqlite3 error: CANTOPEN")
[8292.202643] TID=1: Retrying (4/8) final_step after exception: Failure("Sqlite3 error: CANTOPEN")
[8300.990211] TID=1: Retrying (5/8) final_step after exception: Failure("Sqlite3 error: CANTOPEN")
[8317.010240] TID=1: Retrying (6/8) final_step after exception: Failure("Sqlite3 error: CANTOPEN")
[8349.342196] TID=1: Retrying (7/8) final_step after exception: Failure("Sqlite3 error: CANTOPEN")
[8413.530260] TID=1: Retrying (8/8) final_step after exception: Failure("Sqlite3 error: CANTOPEN")
[8541.955867] TID=1: Error during final_step after 8 attempts: Failure("Sqlite3 error: CANTOPEN")
[8541.956023] TID=1: Retrying (1/8) close_db after exception: Failure("close_db")
[8543.785186] TID=1: Retrying (2/8) close_db after exception: Failure("close_db")
[8546.348769] TID=1: Retrying (3/8) close_db after exception: Failure("close_db")
[8550.598195] TID=1: Retrying (4/8) close_db after exception: Failure("close_db")
[8559.466345] TID=1: Retrying (5/8) close_db after exception: Failure("close_db")
[8576.028543] TID=1: Retrying (6/8) close_db after exception: Failure("close_db")
[8608.366172] TID=1: Retrying (7/8) close_db after exception: Failure("close_db")
[8673.238186] TID=1: Retrying (8/8) close_db after exception: Failure("close_db")
[8801.758164] TID=1: Error during close_db after 8 attempts: Failure("close_db")
[8801.758282] TID=1: Error in finally block:
Exception:Failure("close_db")
Backtrace:
[9124.445248] TID=93598: getattr /
[9124.445341] TID=93598: BEGIN: Getting metadata from context
[9124.445378] TID=93598: END: Getting metadata: Not valid
[9124.445410] TID=93598: BEGIN: Refreshing metadata
[9124.446324] TID=93599: getattr /
[9124.450095] TID=93598: Error during request: Code: 6, Description: CURLE_COULDNT_RESOLVE_HOST, ErrorBuffer: Could not resolve host: www.googleapis.com

[9124.450140] TID=93598: Offline
[9124.450185] TID=93598: Exception:Failure("Code: 6, Description: CURLE_COULDNT_RESOLVE_HOST, ErrorBuffer: Could not resolve host: www.googleapis.com\n")
Backtrace:
[9124.450213] TID=93599: BEGIN: Getting metadata from context
[9124.450373] TID=93599: END: Getting metadata: Not valid
[9124.450420] TID=93599: BEGIN: Refreshing metadata
[9124.454934] TID=93599: Error during request: Code: 6, Description: CURLE_COULDNT_RESOLVE_HOST, ErrorBuffer: Could not resolve host: www.googleapis.com

[9124.454970] TID=93599: Offline
[9124.455008] TID=93599: Exception:Failure("Code: 6, Description: CURLE_COULDNT_RESOLVE_HOST, ErrorBuffer: Could not resolve host: www.googleapis.com\n")
Backtrace:
[9421.582030] TID=93600: getattr /
[9421.582092] TID=93601: getattr /
[9421.582151] TID=93600: BEGIN: Getting metadata from context
[9421.582250] TID=93600: END: Getting metadata: Not valid
[9421.582305] TID=93600: BEGIN: Refreshing metadata
[9421.586815] TID=93600: Error during request: Code: 6, Description: CURLE_COULDNT_RESOLVE_HOST, ErrorBuffer: Could not resolve host: www.googleapis.com

[9421.586840] TID=93600: Offline
[9421.586865] TID=93600: Exception:Failure("Code: 6, Description: CURLE_COULDNT_RESOLVE_HOST, ErrorBuffer: Could not resolve host: www.googleapis.com\n")
Backtrace:
[9421.586874] TID=93601: BEGIN: Getting metadata from context
[9421.586913] TID=93601: END: Getting metadata: Not valid
[9421.586931] TID=93601: BEGIN: Refreshing metadata
[9421.591343] TID=93601: Error during request: Code: 6, Description: CURLE_COULDNT_RESOLVE_HOST, ErrorBuffer: Could not resolve host: www.googleapis.com

[9421.591364] TID=93601: Offline
[9421.591387] TID=93601: Exception:Failure("Code: 6, Description: CURLE_COULDNT_RESOLVE_HOST, ErrorBuffer: Could not resolve host: www.googleapis.com\n")
Backtrace:
[9424.144247] TID=93602: getattr /
[9424.144413] TID=93602: BEGIN: Getting metadata from context
[9424.144474] TID=93602: END: Getting metadata: Not valid
[9424.144521] TID=93602: BEGIN: Refreshing metadata
[9424.145537] TID=93603: getattr /
[9424.149517] TID=93602: Error during request: Code: 6, Description: CURLE_COULDNT_RESOLVE_HOST, ErrorBuffer: Could not resolve host: www.googleapis.com

[9424.149608] TID=93602: Offline
[9424.149700] TID=93602: Exception:Failure("Code: 6, Description: CURLE_COULDNT_RESOLVE_HOST, ErrorBuffer: Could not resolve host: www.googleapis.com\n")
Backtrace:
[9424.151165] TID=93603: BEGIN: Getting metadata from context
[9424.151314] TID=93603: END: Getting metadata: Not valid
[9424.151380] TID=93603: BEGIN: Refreshing metadata
[9424.156317] TID=93603: Error during request: Code: 6, Description: CURLE_COULDNT_RESOLVE_HOST, ErrorBuffer: Could not resolve host: www.googleapis.com

[9424.156393] TID=93603: Offline
[9424.156478] TID=93603: Exception:Failure("Code: 6, Description: CURLE_COULDNT_RESOLVE_HOST, ErrorBuffer: Could not resolve host: www.googleapis.com\n")
Backtrace:

It looks to me like google-drive-ocamlfuse is not able to recover from a connection lose.