Issue accessing git repo when restoring from backups

Hi there,

So I’m attempting to manually restore a rsynced copy of phabricator data in preparation for writing some quick backup restore scripts.

I’ve downloaded the phabricator git repo to /opt/phabricator

Restored my sql db from a sqldump.

Ensured that my user described in my restored local.json can access the correct db’s in mysql.

And I’ve installed this nginx config file and verified it working, being able to access various data through the UI:

server {
  listen         80;
  server_name    vanilla.foo.io;
  return         301 https://$server_name$request_uri;
}



server {
  listen 443 ssl;
  
  server_name vanilla.foo.io;
  root        /opt/phabricator/webroot;
  
  ssl on;
  ssl_certificate /etc/letsencrypt/live/vanilla.foo.io/fullchain.pem;
  ssl_certificate_key /etc/letsencrypt/live/vanilla.foo.io/privkey.pem;
  
  ssl_protocols TLSv1 TLSv1.1 TLSv1.2;
  ssl_prefer_server_ciphers on;
  #ssl_dhparam /etc/ssl/certs/dhparam.pem;
  ssl_ciphers 'ECDHE-RSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-ECDSA-AES256-GCM-SHA384:DHE-RSA-AES128-GCM-SHA256:DHE-DSS-AES128-GCM-SHA256:kEDH+AESGCM:ECDHE-RSA-AES128-SHA256:ECDHE-ECDSA-AES128-SHA256:ECDHE-RSA-AES128-SHA:ECDHE-ECDSA-AES128-SHA:ECDHE-RSA-AES256-SHA384:ECDHE-ECDSA-AES256-SHA384:ECDHE-RSA-AES256-SHA:ECDHE-ECDSA-AES256-SHA:DHE-RSA-AES128-SHA256:DHE-RSA-AES128-SHA:DHE-DSS-AES128-SHA256:DHE-RSA-AES256-SHA256:DHE-DSS-AES256-SHA:DHE-RSA-AES256-SHA:AES128-GCM-SHA256:AES256-GCM-SHA384:AES128-SHA256:AES256-SHA256:AES128-SHA:AES256-SHA:AES:CAMELLIA:DES-CBC3-SHA:!aNULL:!eNULL:!EXPORT:!DES:!RC4:!MD5:!PSK:!aECDH:!EDH-DSS-DES-CBC3-SHA:!EDH-RSA-DES-CBC3-SHA:!KRB5-DES-CBC3-SHA';
  ssl_session_timeout 1d;
  ssl_session_cache shared:SSL:50m;
  ssl_stapling on;
  ssl_stapling_verify on;
  add_header Strict-Transport-Security max-age=15768000;

  location / {
    index index.php;
    rewrite ^/(.*)$ /index.php?__path__=/$1 last;
  }

  location = /favicon.ico {
    try_files $uri =204;
  }

  location /index.php {
    fastcgi_pass   unix:/var/run/php/php7.2-fpm.sock;
    #fastcgi_pass   127.0.0.1:9000;
    #fastcgi_index   index.php;

    #required if PHP was built with --enable-force-cgi-redirect
    fastcgi_param  REDIRECT_STATUS    200;

    #variables to make the $_SERVER populate in PHP
    fastcgi_param  SCRIPT_FILENAME    $document_root$fastcgi_script_name;
    fastcgi_param  QUERY_STRING       $query_string;
    fastcgi_param  REQUEST_METHOD     $request_method;
    fastcgi_param  CONTENT_TYPE       $content_type;
    fastcgi_param  CONTENT_LENGTH     $content_length;

    fastcgi_param  SCRIPT_NAME        $fastcgi_script_name;

    fastcgi_param  GATEWAY_INTERFACE  CGI/1.1;
    fastcgi_param  SERVER_SOFTWARE    nginx/$nginx_version;

    fastcgi_param  REMOTE_ADDR        $remote_addr;
   }

  location ~ /.well-known {
    allow all;
  }
}

However despite being able to see various files in the web UI, when I try to clone a git repo I end up with this error:

nhendrickson@salt-master:~$ git clone http://vanilla.foo.io/source/salt.git salt-two
Cloning into 'salt-two'...
Username for 'https://vanilla.foo.io': nhendrickson
Password for 'https://nhendrickson@vanilla.foo.io': 
fatal: unable to access 'https://vanilla.foo.io/source/salt.git/': The requested URL returned error: 500
nhendrickson@salt-master:~$ 

Curious where I should be looking, admittedly I don’t have a git user set up for managing git repo access over ssh.
But given I’m just doing this over https I figured it should be fine for a quick test run.
Any thoughts?

You should have some logs about the error in Nginx’s logs.

Yeah was one of the first places I looked, nothing specifically in nginx logs when I try a git clone.
Might need to turn on debug logging however.

In an nginx + PHP-FPM log setup, PHP-FPM often has a separate error log. Generally, if the server returns an HTTP/500, one of the two logs should have something useful.

Gotcha I’ll check logs there.

Originally I had an error from my phd daemon user not existing, after fixing that I then realized my phd daemons weren’t running.

However think there’s a separate issue given it seems to me that phd isn’t running all four daemons like it should.

root@nhendrickson-test-box:~# /opt/phabricator/bin/phd restart
Interrupting process 15882...
Process 15882 exited.
 STOP  Stopped PID 15882 ("php ./phd-daemon")
Freeing active task leases...
Freed 331 task lease(s).
Launching daemons:
(Logs will appear in "/var/tmp/phd/log/daemons.log".)

    (Pool: 1) PhabricatorRepositoryPullLocalDaemon
    (Pool: 1) PhabricatorTriggerDaemon
    (Pool: 1) PhabricatorFactDaemon
    (Pool: 4) PhabricatorTaskmasterDaemon

Done.
root@nhendrickson-test-box:~# /opt/phabricator/bin/phd status
PID   Command
24696 php ./phd-daemon

Since when I run it on an older box/phab revision, I get:

nhendrickson@hack:~$ sudo /opt/phabricator/bin/phd status
Log    Daemon       Host                 Overseer Started                 Class                                Arguments
136647 21401:5cdkvc localhost            21401    Oct 18 2019, 7:17:51 PM PhabricatorRepositoryPullLocalDaemon 
136649 21401:zj454g localhost            21401    Oct 18 2019, 7:17:51 PM PhabricatorFactDaemon                
136650 21401:qretb5 localhost            21401    Oct 18 2019, 7:17:51 PM PhabricatorTaskmasterDaemon          
194089 21401:odd6o7 localhost            21401    Oct 18 2019, 7:17:51 PM PhabricatorTaskmasterDaemon          
194092 21401:av6she localhost            21401    Oct 18 2019, 7:17:51 PM PhabricatorTaskmasterDaemon          
194093 21401:74xsqx localhost            21401    Oct 18 2019, 7:17:51 PM PhabricatorTaskmasterDaemon          
136648 21401:xeermc hack.foo.io 21401    Oct 18 2019, 7:17:51 PM PhabricatorTriggerDaemon             
nhendrickson@hack:~$ 

The daemon pool autoscales down if there’s no work to do, so it’s expected that you may see fewer than 4 processes. (See https://secure.phabricator.com/T12217 for context.)

Hmm, so I am seeing somethin in my nginx debug log:

2020/01/14 21:36:47 [debug] 16334#16334: *22 http fastcgi header: "Status: 500 Error 1: sudo: sorry, you must have a tty to run sudo"
2020/01/14 21:36:47 [debug] 16334#16334: *22 http fastcgi parser: 0
2020/01/14 21:36:47 [debug] 16334#16334: *22 http fastcgi header: "Content-Encoding: gzip"
2020/01/14 21:36:47 [debug] 16334#16334: *22 http fastcgi parser: 0
2020/01/14 21:36:47 [debug] 16334#16334: *22 http fastcgi header: "Vary: Accept-Encoding"
2020/01/14 21:36:47 [debug] 16334#16334: *22 http fastcgi parser: 0
2020/01/14 21:36:47 [debug] 16334#16334: *22 http fastcgi header: "Content-type: text/html; charset=UTF-8"
2020/01/14 21:36:47 [debug] 16334#16334: *22 http fastcgi parser: 1
2020/01/14 21:36:47 [debug] 16334#16334: *22 http fastcgi header done
2020/01/14 21:36:47 [debug] 16334#16334: *22 xslt filter header
2020/01/14 21:36:47 [debug] 16334#16334: *22 posix_memalign: 000056297D0D8940:4096 @16
2020/01/14 21:36:47 [debug] 16334#16334: *22 HTTP/1.1 500 Error 1: sudo: sorry, you must have a tty to run sudo

Your /etc/sudoers file may have Defaults requiretty, which means a TTY is required to run sudo.

This is normally intended to prevent invocation of sudo when a password would be echoed in cleartext. It is not relevant for NOPASSWD: configuration.

You can comment out the Defaults requiretty line, or check the sudo documentation for more surgical ways to configure it (Defaults:username !requiretty, perhaps).

Yeah I thought it was odd sudo was getting invoked.

Odder still the only sudoers conf file that has requiretty is the one for my org user group profiles.

However while removing it got rid of the error in my nginx debug log, still not having success cloning from http as I still get 500 errors.

Perhaps my command is malformed:
nhendrickson@salt-master:~$ git -c http.sslVerify=false clone https://vanilla.foo.io/source/salt.git salt-two

Broadly, nothing you do on the client should be able to produce a HTTP 500 on the server if things are configured correctly.

You’re now getting HTTP 500 in the response with no errors in either error log?

That is correct, yes.

I have no idea how to reproduce that state, so I don’t have any guidance. If I had a reproduction case available, I’d likely proceed from here by adding debug tracing to DiffusionServeController.

The expectation is that HTTP/500 essentially only results from server misconfiguration and generates errors in the logs.

Gotcha I’ll take a look there then.

Is there a set of documents for turning on debug logging for phab?

There is no concept of a “debug logging” mode in Phabricator.

Fair enough.

After some fiddling finally got it downloading, need to futz with perms and what user is running it seems.

Stupid of me not to have tried that first.

Thanks for all the help rubber ducking this.

Think it can be closed out.