search

jupyter / nbgrader

A system for assigning and grading notebooks
https://nbgrader.readthedocs.io/
BSD 3-Clause "New" or "Revised" License
1.28k stars 316 forks source link

Multiple instructors documentation #1176

Closed mkzia closed 4 years ago

mkzia commented 5 years ago

I followed the thread on PR#1000 and could not setup the multiple instructors scenario with course folder located in /course. Here is my attempt to document how to setup multiple instructors from scratch. What have I missed?

Installing JupyterHub with Nbgrader for multiple instructors and one student

Starting with a new ubuntu1804 instance

Setup Jupyterhub

sudo apt-get update
sudo apt-get -y install npm
sudo npm install -g configurable-http-proxy
sudo apt-get -y install python3-pip
sudo pip3 install jupyterhub
sudo mkdir -p /etc/jupyterhub/
cd /etc/jupyterhub/
sudo openssl req -x509 -newkey rsa:2048 -keyout jupyterhub_key.pem -out jupyterhub_cert.pem -days 365 -nodes

Create /etc/jupyterhub/jupyterhub_config.py and add: sudo vim /etc/jupyterhub/jupyterhub_config.py

c = get_config()
c.JupyterHub.bind_url = 'https://:443'
c.JupyterHub.ssl_cert = '/etc/jupyterhub/jupyterhub_cert.pem'
c.JupyterHub.ssl_key = '/etc/jupyterhub/jupyterhub_key.pem'

Create /etc/systemd/system/jupyterhub.service and add: sudo vim /etc/systemd/system/jupyterhub.service

[Unit]
Description=Jupyterhub
After=syslog.target network.target

[Service]
User=root
Environment="PATH=/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin"
ExecStart=/usr/bin/python3 /usr/local/bin/jupyterhub --config=/etc/jupyterhub/jupyterhub_config.py

[Install]
WantedBy=multi-user.target
sudo systemctl daemon-reload
sudo systemctl start jupyterhub

Check that the website works.

Setup users

Add two instructors

sudo adduser instructor1
sudo adduser instructor2

Add one student

sudo adduser student1
sudo adduser student2

Add group 

sudo addgroup  instructors
sudo usermod -a -G instructors instructor1
sudo usermod -a -G instructors instructor2
sudo usermod -a -G instructors student1
sudo usermod -a -G instructors student2

Setup Nbgrader -- checkout PR # 1000

cd /tmp
git clone https://github.com/AaltoScienceIT/nbgrader.git
cd nbgrader
sudo pip3 install -e .
sudo mkdir -p /srv/nbgrader/exchange
sudo chmod -R 2777 /srv
sudo chown -R :instructors /srv
cd /
sudo nbgrader quickstart testcourse
sudo chgrp instructors /testcourse/
sudo chmod 2770 /testcourse/

As instructor1 create .jupyter/nbgrader_config.py:

mkdir .jupyter

sudo vim .jupyter/nbgrader_config.py add the following to the file

c = get_config()
c.CourseDirectory.root = "/testcourse"
c.Exchange.course_id = "testcourse"
c.Exchange.multiuser = True
c.Exchange.groupshared = True
c.BaseConverter.groupshared = True

As root user:

sudo mkdir /etc/jupyter

As root create vim /etc/jupyter/nbgrader_config.py and add the following:

c = get_config()
c.CourseDirectory.course_id = "eas503f2019"

Log in as instructor1 and enable all the extensions:

jupyter nbextension install --user --py nbgrader --overwrite
jupyter nbextension enable --user --py nbgrader
jupyter serverextension enable --user --py nbgrader

Log in as instructor2 and enable all the extensions:

jupyter nbextension install --user --py nbgrader --overwrite
jupyter nbextension enable --user --py nbgrader
jupyter serverextension enable --user --py nbgrader

As root user enable the following extensions system-wide

jupyter nbextension install --sys-prefix --py nbgrader --overwrite
jupyter nbextension enable --sys-prefix assignment_list/main 
jupyter nbextension enable --sys-prefix assignment_list/main --section=tree
jupyter nbextension enable --sys-prefix  validate_assignment/main --section=notebook
jupyter serverextension enable --sys-prefix nbgrader.server_extensions.assignment_list
jupyter serverextension enable --sys-prefix nbgrader.server_extensions.validate_assignment
jupyter serverextension enable --sys-prefix nbgrader.server_extensions.formgrader
sudo systemctl restart jupyterhub
rkdarst commented 5 years ago

I notice this:

git clone https://github.com/AaltoScienceIT/nbgrader.git
cd nbgrader
sudo pip3 install -e .

You should git checkout groupshared to get the right branch, it's not in master. I didn't find anything else wrong, but didn't look too hard either. Copies of logs messages would help (it should have said that groupshared was an unrecognized option).

I guess you know the way most people do this is https://github.com/jupyterhub/jupyterhub/tree/master/examples/service-notebook ?

mkzia commented 5 years ago

@rkdarst Thanks for pointing that out. I have tried to setup the shared-notebook service method, but that does not work either. I will post my instructions in the next post.

mkzia commented 5 years ago

Here are my instructions for setting up a shared-notebook service. I cannot seem to get this working also. When I log in as instructor1 and click on formgrader, I get the following error message: Sorry, the formgrader encountered an error. Please contact the administrator of the formgrader for further assistance.

jupyterhub.log does not show any relevant error message and Nbgrader is not logging anything.

Can anyone please review my instructions to see what I am doing wrong.

Installing JupyterHub with Nbgrader for multiple instructors using Shared Services

Starting with a new ubuntu1804 instance

Setup Jupyterhub

sudo apt-get update
sudo apt-get -y install npm
sudo npm install -g configurable-http-proxy
sudo apt-get -y install python3-pip
sudo pip3 install jupyterhub
sudo mkdir -p /etc/jupyterhub/
cd /etc/jupyterhub/
sudo openssl req -x509 -newkey rsa:2048 -keyout jupyterhub_key.pem -out jupyterhub_cert.pem -days 365 -nodes

Setup Jupyterhub config

sudo vim /etc/jupyterhub/jupyterhub_config.py

Add the following to the config file:

c = get_config()
c.JupyterHub.bind_url = 'https://:443'
c.JupyterHub.ssl_cert = '/etc/jupyterhub/jupyterhub_cert.pem'
c.JupyterHub.ssl_key = '/etc/jupyterhub/jupyterhub_key.pem'
c.JupyterHub.extra_log_file = '/var/log/jupyterhub.log'

Create Jupyterhub service

sudo vim /etc/systemd/system/jupyterhub.service

Add the following to the file:

[Unit]
Description=Jupyterhub
After=syslog.target network.target

[Service]
User=root
Environment="PATH=/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin"
ExecStart=/usr/bin/python3 /usr/local/bin/jupyterhub --config=/etc/jupyterhub/jupyterhub_config.py

[Install]
WantedBy=multi-user.target

Enable Jupyterhub service

sudo systemctl daemon-reload
sudo systemctl start jupyterhub

Check that the website works.

Setup grader, instructor, and student users and an instructor group

Add one (1) grader account

sudo adduser grader

Add two (2) instructor accounts

sudo adduser instructor1
sudo adduser instructor2

Add two (2) student accounts

sudo adduser student1
sudo adduser student2

Add instructors group 

sudo addgroup  instructors

Add all three instructors to instructors group

sudo usermod -a -G instructors grader
sudo usermod -a -G instructors instructor1
sudo usermod -a -G instructors instructor2

Install Nbgrader

cd /tmp
git clone https://github.com/jupyter/nbgrader.git
cd nbgrader
sudo pip3 install -e .

Add a course group and add grader, instructors, and students to the group so the students can access feedback files returned from instructors.

sudo addgroup  course
sudo usermod -a -G course grader
sudo usermod -a -G course instructor1
sudo usermod -a -G course instructor2
sudo usermod -a -G course student1
sudo usermod -a -G course student1
sudo mkdir -p /srv/nbgrader/exchange
sudo chmod -R 2777 /srv
sudo chown -R :course /srv

Create the course directory in the grader account home directory and fix up permissions

sudo su - grader
nbgrader quickstart testcourse
chgrp -R instructors testcourse/
chmod -R 2770 testcourse

Setup nbgrader_config for grader account

mkdir ~/.jupyter

vim ~/.jupyter/nbgrader_config.py

add the following 

c = get_config()
c.CourseDirectory.course_id = 'testcourse'
c.CourseDirectory.root = '/home/grader/testcourse'

Exit the grader account

exit

Setup system-wide nbgrader_config

sudo mkdir /etc/jupyter/

sudo vim /etc/jupyter/nbgrader_config.py and add the following:

c = get_config()
c.Application.log_level = 'DEBUG'
c.NbGrader.log = '/var/log/nbgrader.log'
c.CourseDirectory.course_id = 'testcourse'
c.CourseDirectory.root = '/home/grader/testcourse/'
c.Exchange.root = '/srv/nbgrader/exchange'

Update Jupytherhub config to run a shared-notebook service

Source: https://github.com/jupyterhub/jupyterhub/tree/master/examples/service-notebook

sudo vim /etc/jupyterhub/jupyterhub_config.py

c = get_config()
c.JupyterHub.bind_url = 'https://:443'
c.JupyterHub.ssl_cert = '/etc/jupyterhub/jupyterhub_cert.pem'
c.JupyterHub.ssl_key = '/etc/jupyterhub/jupyterhub_key.pem'
c.JupyterHub.extra_log_file = '/var/log/jupyterhub.log'

c.JupyterHub.load_groups = {
    'instructors': [
        'grader',
        'instructor1',
        'instructor2'
    ]
}

c.JupyterHub.services = [
    {
        'name': 'testcourse',
        'url': 'http://127.0.0.1:443',
        'command': [
            'jupyterhub-singleuser',
            '--group=instructors',
            '--debug',
        ],
        'user': 'grader',
        'cwd': '/home/grader'
    }
]

System-wide Nbgrader settings

sudo jupyter nbextension install --sys-prefix --py nbgrader --overwrite
sudo jupyter nbextension enable --sys-prefix assignment_list/main 
sudo jupyter nbextension enable --sys-prefix assignment_list/main --section=tree
sudo jupyter nbextension enable --sys-prefix  validate_assignment/main --section=notebook
sudo jupyter serverextension enable --sys-prefix nbgrader.server_extensions.assignment_list
sudo jupyter serverextension enable --sys-prefix nbgrader.server_extensions.validate_assignment
sudo jupyter serverextension enable --sys-prefix nbgrader.server_extensions.formgrader

For the two instructor and one grader account enable everything

sudo su - grader
jupyter nbextension install --user --py nbgrader --overwrite
jupyter nbextension enable --user --py nbgrader
jupyter serverextension enable --user --py nbgrader
exit
sudo su - instructor1
jupyter nbextension install --user --py nbgrader --overwrite
jupyter nbextension enable --user --py nbgrader
jupyter serverextension enable --user --py nbgrader
exit
sudo su - instructor2
jupyter nbextension install --user --py nbgrader --overwrite
jupyter nbextension enable --user --py nbgrader
jupyter serverextension enable --user --py nbgrader
exit
sudo systemctl restart jupyterhub

Post Install

After releasing the first assignment using the grader account, you will have to update the exchange directory permissions again.

sudo chmod -R 2777 /srv
sudo chown -R :course /srv
jhamrick commented 5 years ago

From reading through your setup it's not immediately clear what is wrong. Logs would really help if you can figure out how to get JupyterHub to log them for single user services (I unfortunately don't remember off the top of my head).

I can try to have a closer look this weekend.

mkzia commented 5 years ago

I enabled logging by adding the following to jupyterhub_config.py

#c.JupyterHub.extra_log_file = '/var/log/jupyterhub.log'
c.JupyterHub.log_level = 'DEBUG'
c.Spawner.debug = True
c.LocalProcessSpawner.debug = True

Then I ran the notebook using sudo /usr/bin/python3 /usr/local/bin/jupyterhub --config=/etc/jupyterhub/jupyterhub_config.py &> /tmp/log.txt

Contents of log.txt 

[I 2019-08-21 17:07:04.043 JupyterHub app:2120] Using Authenticator: jupyterhub.auth.PAMAuthenticator-1.0.0
[I 2019-08-21 17:07:04.043 JupyterHub app:2120] Using Spawner: jupyterhub.spawner.LocalProcessSpawner-1.0.0
[D 2019-08-21 17:07:04.044 JupyterHub app:2073] Could not load pycurl: No module named 'pycurl'
    pycurl is recommended if you have a large number of users.
[I 2019-08-21 17:07:04.046 JupyterHub app:1257] Loading cookie_secret from /home/mkzia/jupyterhub_cookie_secret
[D 2019-08-21 17:07:04.046 JupyterHub app:1424] Connecting to db: sqlite:///jupyterhub.sqlite
[D 2019-08-21 17:07:04.067 JupyterHub orm:749] database schema version found: 4dc2d5a8c53c
[I 2019-08-21 17:07:04.072 JupyterHub proxy:460] Generating new CONFIGPROXY_AUTH_TOKEN
[W 2019-08-21 17:07:04.074 JupyterHub app:1532] No admin users, admin interface will be unavailable.
[W 2019-08-21 17:07:04.074 JupyterHub app:1534] Add any administrative users to `c.Authenticator.admin_users` in config.
[I 2019-08-21 17:07:04.074 JupyterHub app:1563] Not using whitelist. Any authenticated user will be allowed.
[D 2019-08-21 17:07:04.164 JupyterHub app:1910] Loading state for instructor1 from db
[D 2019-08-21 17:07:04.165 JupyterHub app:1910] Loading state for instructor2 from db
[D 2019-08-21 17:07:04.165 JupyterHub app:1910] Loading state for grader from db
[D 2019-08-21 17:07:04.166 JupyterHub app:1926] Loaded users:
    instructor1
    instructor2
      grader
[I 2019-08-21 17:07:04.176 JupyterHub app:2337] Hub API listening on http://127.0.0.1:8081/hub/
[I 2019-08-21 17:07:04.177 JupyterHub proxy:645] Starting proxy @ https://:443
[D 2019-08-21 17:07:04.177 JupyterHub proxy:646] Proxy cmd: ['configurable-http-proxy', '--ip', '', '--port', '443', '--api-ip', '127.0.0.1', '--api-port', '8001', '--error-target', 'http://127.0.0.1:8081/hub/error', '--ssl-key', '/etc/jupyterhub/jupyterhub_key.pem', '--ssl-cert', '/etc/jupyterhub/jupyterhub_cert.pem']
[D 2019-08-21 17:07:04.180 JupyterHub proxy:561] Writing proxy pid file: jupyterhub-proxy.pid
[E 2019-08-21 17:07:04.182 JupyterHub utils:75] Unexpected error connecting to jpyhub3:443 [Errno 22] Invalid argument
[E 2019-08-21 17:07:04.332 JupyterHub utils:75] Unexpected error connecting to jpyhub3:443 [Errno 22] Invalid argument
[E 2019-08-21 17:07:04.451 JupyterHub utils:75] Unexpected error connecting to jpyhub3:443 [Errno 22] Invalid argument
17:07:04.814 [ConfigProxy] info: Proxying https://*:443 to (no default)
17:07:04.818 [ConfigProxy] info: Proxy API at http://127.0.0.1:8001/api/routes
[D 2019-08-21 17:07:04.995 JupyterHub proxy:681] Proxy started and appears to be up
[I 2019-08-21 17:07:04.996 JupyterHub app:2362] Starting managed service testcourse at http://127.0.0.1:443
[I 2019-08-21 17:07:04.997 JupyterHub service:316] Starting service 'testcourse': ['jupyterhub-singleuser', '--group=instructors', '--debug']
[I 2019-08-21 17:07:05.001 JupyterHub service:121] Spawning jupyterhub-singleuser --group=instructors --debug
[D 2019-08-21 17:07:05.007 JupyterHub spawner:1084] Polling subprocess every 30s
[D 2019-08-21 17:07:05.531 SingleUserNotebookApp application:177] Searching ['/home/grader', '/home/grader/.jupyter', '/usr/etc/jupyter', '/usr/local/etc/jupyter', '/etc/jupyter'] for config files
[D 2019-08-21 17:07:05.532 SingleUserNotebookApp application:555] Looking for jupyter_config in /etc/jupyter
[D 2019-08-21 17:07:05.532 SingleUserNotebookApp application:555] Looking for jupyter_config in /usr/local/etc/jupyter
[D 2019-08-21 17:07:05.533 SingleUserNotebookApp application:555] Looking for jupyter_config in /usr/etc/jupyter
[D 2019-08-21 17:07:05.533 SingleUserNotebookApp application:555] Looking for jupyter_config in /home/grader/.jupyter
[D 2019-08-21 17:07:05.533 SingleUserNotebookApp application:555] Looking for jupyter_config in /home/grader
[D 2019-08-21 17:07:05.534 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /etc/jupyter
[D 2019-08-21 17:07:05.534 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /usr/local/etc/jupyter
[D 2019-08-21 17:07:05.534 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /usr/etc/jupyter
[D 2019-08-21 17:07:05.535 SingleUserNotebookApp application:577] Loaded config file: /usr/etc/jupyter/jupyter_notebook_config.json
[D 2019-08-21 17:07:05.535 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /home/grader/.jupyter
[D 2019-08-21 17:07:05.535 SingleUserNotebookApp application:577] Loaded config file: /home/grader/.jupyter/jupyter_notebook_config.json
[D 2019-08-21 17:07:05.535 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /home/grader
[D 2019-08-21 17:07:05.542 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /etc/jupyter/jupyter_notebook_config.json
[D 2019-08-21 17:07:05.542 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /usr/local/etc/jupyter/jupyter_notebook_config.json
[D 2019-08-21 17:07:05.543 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /usr/etc/jupyter/jupyter_notebook_config.json
[D 2019-08-21 17:07:05.543 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /home/grader/.jupyter/jupyter_notebook_config.json
[W 2019-08-21 17:07:05.808 SingleUserNotebookApp notebookapp:1448] Permission to listen on port 443 denied
[C 2019-08-21 17:07:05.808 SingleUserNotebookApp notebookapp:1457] ERROR: the notebook server could not be started because no available port could be found.
[D 2019-08-21 17:07:05.808 SingleUserNotebookApp application:647] Exiting application: jupyter-notebook
[E 2019-08-21 17:07:05.941 JupyterHub app:2392] Service testcourse exited with status 1
[D 2019-08-21 17:07:05.941 JupyterHub proxy:314] Fetching routes to check
[D 2019-08-21 17:07:05.941 JupyterHub proxy:765] Proxy: Fetching GET http://127.0.0.1:8001/api/routes
17:07:05.950 [ConfigProxy] info: 200 GET /api/routes 
[I 2019-08-21 17:07:05.950 JupyterHub proxy:319] Checking routes
[I 2019-08-21 17:07:05.951 JupyterHub proxy:399] Adding default route for Hub: / => http://127.0.0.1:8081
[W 2019-08-21 17:07:05.952 JupyterHub proxy:373] Adding missing route for testcourse (Server(url=http://127.0.0.1:443/services/testcourse/, bind_url=http://127.0.0.1:443/services/testcourse/))
[D 2019-08-21 17:07:05.952 JupyterHub proxy:765] Proxy: Fetching POST http://127.0.0.1:8001/api/routes/
[I 2019-08-21 17:07:05.954 JupyterHub proxy:242] Adding service testcourse to proxy /services/testcourse/ => http://127.0.0.1:443
[D 2019-08-21 17:07:05.955 JupyterHub proxy:765] Proxy: Fetching POST http://127.0.0.1:8001/api/routes/services/testcourse
17:07:05.958 [ConfigProxy] info: Adding route / -> http://127.0.0.1:8081
17:07:05.959 [ConfigProxy] info: Route added / -> http://127.0.0.1:8081
17:07:05.960 [ConfigProxy] info: 201 POST /api/routes/ 
17:07:05.960 [ConfigProxy] info: Adding route /services/testcourse -> http://127.0.0.1:443
17:07:05.961 [ConfigProxy] info: Route added /services/testcourse -> http://127.0.0.1:443
17:07:05.961 [ConfigProxy] info: 201 POST /api/routes/services/testcourse 
[I 2019-08-21 17:07:05.962 JupyterHub app:2422] JupyterHub is now running at https://:443
[D 2019-08-21 17:07:10.367 JupyterHub base:482] Setting cookie for instructor1: jupyterhub-services
[D 2019-08-21 17:07:10.367 JupyterHub base:478] Setting cookie jupyterhub-services: {'httponly': True, 'secure': True, 'path': '/services'}
[D 2019-08-21 17:07:10.368 JupyterHub base:478] Setting cookie jupyterhub-session-id: {'httponly': True, 'secure': True}
[D 2019-08-21 17:07:10.368 JupyterHub base:482] Setting cookie for instructor1: jupyterhub-hub-login
[D 2019-08-21 17:07:10.368 JupyterHub base:478] Setting cookie jupyterhub-hub-login: {'httponly': True, 'secure': True, 'path': '/hub/'}
[I 2019-08-21 17:07:10.368 JupyterHub base:663] User logged in: instructor1
[D 2019-08-21 17:07:10.369 JupyterHub user:240] Creating <class 'jupyterhub.spawner.LocalProcessSpawner'> for instructor1:
[I 2019-08-21 17:07:10.371 JupyterHub log:174] 302 POST /hub/login?next= -> /hub/spawn (instructor1@::ffff:128.205.40.121) 32.35ms
[D 2019-08-21 17:07:10.399 JupyterHub pages:165] Triggering spawn with default options for instructor1
[D 2019-08-21 17:07:10.399 JupyterHub base:780] Initiating spawn for instructor1
[D 2019-08-21 17:07:10.400 JupyterHub base:787] 0/100 concurrent spawns
[D 2019-08-21 17:07:10.400 JupyterHub base:792] 0 active servers
[W 2019-08-21 17:07:10.625 JupyterHub auth:941] Failed to open PAM session for instructor1: [PAM Error 14] Cannot make/remove an entry for the specified session
[W 2019-08-21 17:07:10.625 JupyterHub auth:942] Disabling PAM sessions from now on.
[D 2019-08-21 17:07:10.641 JupyterHub user:542] Calling Spawner.start for instructor1
[I 2019-08-21 17:07:10.642 JupyterHub spawner:1387] Spawning jupyterhub-singleuser --port=39415 --debug
[D 2019-08-21 17:07:10.659 JupyterHub spawner:1084] Polling subprocess every 30s
[D 2019-08-21 17:07:11.155 SingleUserNotebookApp application:177] Searching ['/home/instructor1', '/home/instructor1/.jupyter', '/usr/etc/jupyter', '/usr/local/etc/jupyter', '/etc/jupyter'] for config files
[D 2019-08-21 17:07:11.156 SingleUserNotebookApp application:555] Looking for jupyter_config in /etc/jupyter
[D 2019-08-21 17:07:11.156 SingleUserNotebookApp application:555] Looking for jupyter_config in /usr/local/etc/jupyter
[D 2019-08-21 17:07:11.157 SingleUserNotebookApp application:555] Looking for jupyter_config in /usr/etc/jupyter
[D 2019-08-21 17:07:11.157 SingleUserNotebookApp application:555] Looking for jupyter_config in /home/instructor1/.jupyter
[D 2019-08-21 17:07:11.157 SingleUserNotebookApp application:555] Looking for jupyter_config in /home/instructor1
[D 2019-08-21 17:07:11.158 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /etc/jupyter
[D 2019-08-21 17:07:11.158 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /usr/local/etc/jupyter
[D 2019-08-21 17:07:11.158 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /usr/etc/jupyter
[D 2019-08-21 17:07:11.158 SingleUserNotebookApp application:577] Loaded config file: /usr/etc/jupyter/jupyter_notebook_config.json
[D 2019-08-21 17:07:11.159 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /home/instructor1/.jupyter
[D 2019-08-21 17:07:11.159 SingleUserNotebookApp application:577] Loaded config file: /home/instructor1/.jupyter/jupyter_notebook_config.json
[D 2019-08-21 17:07:11.159 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /home/instructor1
[D 2019-08-21 17:07:11.165 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /etc/jupyter/jupyter_notebook_config.json
[D 2019-08-21 17:07:11.166 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /usr/local/etc/jupyter/jupyter_notebook_config.json
[D 2019-08-21 17:07:11.166 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /usr/etc/jupyter/jupyter_notebook_config.json
[D 2019-08-21 17:07:11.167 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /home/instructor1/.jupyter/jupyter_notebook_config.json
[I 2019-08-21 17:07:11.403 JupyterHub log:174] 302 GET /hub/spawn -> /hub/spawn-pending/instructor1 (instructor1@::ffff:128.205.40.121) 1014.42ms
[I 2019-08-21 17:07:11.428 JupyterHub pages:303] instructor1 is pending spawn
[I 2019-08-21 17:07:11.457 JupyterHub log:174] 200 GET /hub/spawn-pending/instructor1 (instructor1@::ffff:128.205.40.121) 39.85ms
[D 2019-08-21 17:07:11.491 JupyterHub log:174] 200 GET /hub/static/css/style.min.css?v=883a1cf654bd9f5cdc5ca7c91efe7d71 (@::ffff:128.205.40.121) 4.26ms
[D 2019-08-21 17:07:11.743 JupyterHub log:174] 200 GET /hub/static/components/font-awesome/fonts/fontawesome-webfont.woff2?v=4.7.0 (@::ffff:128.205.40.121) 1.47ms
[I 2019-08-21 17:07:11.861 SingleUserNotebookApp handlers:301] Loading the assignment_list nbgrader serverextension
[I 2019-08-21 17:07:11.865 SingleUserNotebookApp handlers:200] Loading the course_list nbgrader serverextension
[I 2019-08-21 17:07:11.868 SingleUserNotebookApp formgrader:84] Loading the formgrader nbgrader serverextension
[D 2019-08-21 17:07:11.872 SingleUserNotebookApp application:177] Searching ['/home/instructor1', '/home/instructor1/.jupyter', '/usr/etc/jupyter', '/usr/local/etc/jupyter', '/etc/jupyter'] for config files
[D 2019-08-21 17:07:11.873 SingleUserNotebookApp application:555] Looking for jupyter_config in /etc/jupyter
[D 2019-08-21 17:07:11.873 SingleUserNotebookApp application:555] Looking for jupyter_config in /usr/local/etc/jupyter
[D 2019-08-21 17:07:11.873 SingleUserNotebookApp application:555] Looking for jupyter_config in /usr/etc/jupyter
[D 2019-08-21 17:07:11.873 SingleUserNotebookApp application:555] Looking for jupyter_config in /home/instructor1/.jupyter
[D 2019-08-21 17:07:11.873 SingleUserNotebookApp application:555] Looking for jupyter_config in /home/instructor1
[D 2019-08-21 17:07:11.874 SingleUserNotebookApp application:555] Looking for nbgrader_config in /etc/jupyter
[D 2019-08-21 17:07:11.875 SingleUserNotebookApp application:577] Loaded config file: /etc/jupyter/nbgrader_config.py
[D 2019-08-21 17:07:11.875 SingleUserNotebookApp application:555] Looking for nbgrader_config in /usr/local/etc/jupyter
[D 2019-08-21 17:07:11.875 SingleUserNotebookApp application:555] Looking for nbgrader_config in /usr/etc/jupyter
[D 2019-08-21 17:07:11.875 SingleUserNotebookApp application:555] Looking for nbgrader_config in /home/instructor1/.jupyter
[D 2019-08-21 17:07:11.876 SingleUserNotebookApp application:577] Loaded config file: /home/instructor1/.jupyter/nbgrader_config.py
[D 2019-08-21 17:07:11.876 SingleUserNotebookApp application:555] Looking for nbgrader_config in /home/instructor1
[W 2019-08-21 17:07:11.877 SingleUserNotebookApp configurable:168] Config option `log` not recognized by `FormgradeExtension`.  Did you mean `logfile`?
[D 2019-08-21 17:07:11.878 SingleUserNotebookApp application:555] Looking for nbgrader_config in /home/grader/testcourse
[D 2019-08-21 17:07:11.878 SingleUserNotebookApp application:577] Loaded config file: /home/grader/testcourse/nbgrader_config.py
[E 2019-08-21 17:07:11.879 SingleUserNotebookApp formgrader:45] The course directory root is not a subdirectory of the notebook server root. This means that nbgrader will not work correctly. If you want to use nbgrader, please ensure the course directory root is in a subdirectory of the notebook root: /home/instructor1
[I 2019-08-21 17:07:11.894 SingleUserNotebookApp handlers:137] Loading the validate_assignment nbgrader serverextension
[I 2019-08-21 17:07:11.894 SingleUserNotebookApp singleuser:561] Starting jupyterhub-singleuser server version 1.0.0
[I 2019-08-21 17:07:11.898 JupyterHub log:174] 200 GET /hub/api (@127.0.0.1) 0.93ms
[D 2019-08-21 17:07:11.899 SingleUserNotebookApp _version:60] jupyterhub and jupyterhub-singleuser both on version 1.0.0
[I 2019-08-21 17:07:11.899 SingleUserNotebookApp notebookapp:1825] Serving notebooks from local directory: /home/instructor1
[I 2019-08-21 17:07:11.899 SingleUserNotebookApp notebookapp:1825] The Jupyter Notebook is running at:
[I 2019-08-21 17:07:11.899 SingleUserNotebookApp notebookapp:1825] http://127.0.0.1:39415/user/instructor1/
[I 2019-08-21 17:07:11.899 SingleUserNotebookApp notebookapp:1826] Use Control-C to stop this server and shut down all kernels (twice to skip confirmation).
[I 2019-08-21 17:07:11.904 SingleUserNotebookApp singleuser:542] Updating Hub with activity every 300 seconds
[D 2019-08-21 17:07:11.905 SingleUserNotebookApp singleuser:503] Notifying Hub of activity 2019-08-21T21:07:11.170861Z
[D 2019-08-21 17:07:11.921 JupyterHub users:716] Not updating activity for <User(instructor1 1/1 running)>: 2019-08-21T21:07:11.170861Z < 2019-08-21T21:07:11.751175Z
[D 2019-08-21 17:07:11.921 JupyterHub users:729] Activity on server instructor1/: 2019-08-21T21:07:11.170861Z
[I 2019-08-21 17:07:11.928 JupyterHub log:174] 200 POST /hub/api/users/instructor1/activity (instructor1@127.0.0.1) 21.37ms
[I 2019-08-21 17:07:12.641 SingleUserNotebookApp log:174] 302 GET /user/instructor1/ -> /user/instructor1/tree? (@127.0.0.1) 0.92ms
[D 2019-08-21 17:07:12.641 JupyterHub utils:218] Server at http://127.0.0.1:39415/user/instructor1/ responded with 302
[D 2019-08-21 17:07:12.641 JupyterHub _version:60] jupyterhub and jupyterhub-singleuser both on version 1.0.0
[I 2019-08-21 17:07:12.641 JupyterHub base:810] User instructor1 took 2.242 seconds to start
[I 2019-08-21 17:07:12.642 JupyterHub proxy:261] Adding user instructor1 to proxy /user/instructor1/ => http://127.0.0.1:39415
[D 2019-08-21 17:07:12.642 JupyterHub proxy:765] Proxy: Fetching POST http://127.0.0.1:8001/api/routes/user/instructor1
17:07:12.644 [ConfigProxy] info: Adding route /user/instructor1 -> http://127.0.0.1:39415
17:07:12.644 [ConfigProxy] info: Route added /user/instructor1 -> http://127.0.0.1:39415
17:07:12.645 [ConfigProxy] info: 201 POST /api/routes/user/instructor1 
[I 2019-08-21 17:07:12.646 JupyterHub users:606] Server instructor1 is ready
[I 2019-08-21 17:07:12.647 JupyterHub log:174] 200 GET /hub/api/users/instructor1/server/progress (instructor1@::ffff:128.205.40.121) 899.52ms
[I 2019-08-21 17:07:12.676 JupyterHub log:174] 302 GET /hub/spawn-pending/instructor1 -> /user/instructor1/ (instructor1@::ffff:128.205.40.121) 11.11ms
[I 2019-08-21 17:07:12.692 SingleUserNotebookApp log:174] 302 GET /user/instructor1/ -> /user/instructor1/tree? (@::ffff:128.205.40.121) 0.84ms
[D 2019-08-21 17:07:12.707 SingleUserNotebookApp auth:501] No user identified
[D 2019-08-21 17:07:12.708 SingleUserNotebookApp auth:832] Redirecting to login url: /hub/api/oauth2/authorize?client_id=jupyterhub-user-instructor1&redirect_uri=%2Fuser%2Finstructor1%2Foauth_callback&response_type=code&state=eyJ1dWlkIjogImE3OGE1N2U0YzAzMTRiZGJhZGE5NjNhNzA2YWMxNWM0IiwgIm5leHRfdXJsIjogIi91c2VyL2luc3RydWN0b3IxL3RyZWU_In0
[I 2019-08-21 17:07:12.709 SingleUserNotebookApp log:174] 302 GET /user/instructor1/tree? -> /hub/api/oauth2/authorize?client_id=jupyterhub-user-instructor1&redirect_uri=%2Fuser%2Finstructor1%2Foauth_callback&response_type=code&state=[secret] (@::ffff:128.205.40.121) 2.44ms
[D 2019-08-21 17:07:12.741 JupyterHub provider:414] Validating client id jupyterhub-user-instructor1
[D 2019-08-21 17:07:12.744 JupyterHub provider:492] validate_redirect_uri: client_id=jupyterhub-user-instructor1, redirect_uri=/user/instructor1/oauth_callback
[D 2019-08-21 17:07:12.746 JupyterHub auth:222] Skipping oauth confirmation for <User(instructor1 1/1 running)> accessing Server at /user/instructor1/
[D 2019-08-21 17:07:12.747 JupyterHub provider:414] Validating client id jupyterhub-user-instructor1
[D 2019-08-21 17:07:12.748 JupyterHub provider:492] validate_redirect_uri: client_id=jupyterhub-user-instructor1, redirect_uri=/user/instructor1/oauth_callback
[D 2019-08-21 17:07:12.749 JupyterHub provider:241] Saving authorization code jupyterhub-user-instructor1, UjY..., (), {}
[I 2019-08-21 17:07:12.761 JupyterHub log:174] 302 GET /hub/api/oauth2/authorize?client_id=jupyterhub-user-instructor1&redirect_uri=%2Fuser%2Finstructor1%2Foauth_callback&response_type=code&state=[secret] -> /user/instructor1/oauth_callback?code=[secret]&state=[secret] (instructor1@::ffff:128.205.40.121) 36.12ms
[D 2019-08-21 17:07:12.776 SingleUserNotebookApp auth:501] No user identified
[D 2019-08-21 17:07:12.792 JupyterHub provider:60] authenticate_client <oauthlib.Request SANITIZED>
[D 2019-08-21 17:07:12.800 JupyterHub provider:119] confirm_redirect_uri: client_id=jupyterhub-user-instructor1, redirect_uri=/user/instructor1/oauth_callback
[D 2019-08-21 17:07:12.801 JupyterHub provider:339] Saving bearer token {'access_token': 'REDACTED', 'expires_in': 3600, 'token_type': 'Bearer', 'scope': 'identify', 'refresh_token': 'REDACTED'}
[D 2019-08-21 17:07:12.812 JupyterHub provider:194] Deleting oauth code UjY... for jupyterhub-user-instructor1
[I 2019-08-21 17:07:12.823 JupyterHub log:174] 200 POST /hub/api/oauth2/token (instructor1@127.0.0.1) 42.18ms
[D 2019-08-21 17:07:12.824 SingleUserNotebookApp auth:310] HubAuth cache miss: token:e64efed89cc84960bf649f7fafb0460a:9cp1jBJp5O50SadkqT5MlxX2Zp4ZG0
[I 2019-08-21 17:07:12.860 JupyterHub log:174] 200 GET /hub/api/authorizations/token/[secret] (instructor1@127.0.0.1) 34.10ms
[D 2019-08-21 17:07:12.860 SingleUserNotebookApp auth:316] Received request from Hub user {'kind': 'user', 'name': 'instructor1', 'admin': False, 'groups': ['instructors'], 'server': '/user/instructor1/', 'pending': None, 'created': '2019-08-20T14:59:35.721069Z', 'last_activity': '2019-08-21T21:07:12.849247Z', 'servers': None}
[I 2019-08-21 17:07:12.861 SingleUserNotebookApp auth:981] Logged-in user {'kind': 'user', 'name': 'instructor1', 'admin': False, 'groups': ['instructors'], 'server': '/user/instructor1/', 'pending': None, 'created': '2019-08-20T14:59:35.721069Z', 'last_activity': '2019-08-21T21:07:12.849247Z', 'servers': None}
[D 2019-08-21 17:07:12.861 SingleUserNotebookApp auth:744] Setting oauth cookie for ::ffff:128.205.40.121: jupyterhub-user-instructor1, {'path': '/user/instructor1/', 'httponly': True, 'secure': True}
[I 2019-08-21 17:07:12.862 SingleUserNotebookApp log:174] 302 GET /user/instructor1/oauth_callback?code=[secret]&state=[secret] -> /user/instructor1/tree? (@::ffff:128.205.40.121) 86.22ms
[D 2019-08-21 17:07:12.878 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-21 17:07:12.879 SingleUserNotebookApp handlers:260] Using contents: services/contents
[D 2019-08-21 17:07:12.930 SingleUserNotebookApp handlers:840] Path base/images/favicon.ico served from /usr/local/lib/python3.6/dist-packages/notebook/static/base/images/favicon.ico
[D 2019-08-21 17:07:12.930 SingleUserNotebookApp handlers:840] Path components/jquery-ui/themes/smoothness/jquery-ui.min.css served from /usr/local/lib/python3.6/dist-packages/notebook/static/components/jquery-ui/themes/smoothness/jquery-ui.min.css
[D 2019-08-21 17:07:12.930 SingleUserNotebookApp handlers:840] Path components/jquery-typeahead/dist/jquery.typeahead.min.css served from /usr/local/lib/python3.6/dist-packages/notebook/static/components/jquery-typeahead/dist/jquery.typeahead.min.css
[D 2019-08-21 17:07:12.931 SingleUserNotebookApp handlers:840] Path style/style.min.css served from /usr/local/lib/python3.6/dist-packages/notebook/static/style/style.min.css
[D 2019-08-21 17:07:12.932 SingleUserNotebookApp handlers:840] Path components/es6-promise/promise.min.js served from /usr/local/lib/python3.6/dist-packages/notebook/static/components/es6-promise/promise.min.js
[D 2019-08-21 17:07:12.932 SingleUserNotebookApp handlers:840] Path components/react/react.production.min.js served from /usr/local/lib/python3.6/dist-packages/notebook/static/components/react/react.production.min.js
[E 2019-08-21 17:07:12.932 SingleUserNotebookApp web:2991] Could not open static file ''
[D 2019-08-21 17:07:12.933 SingleUserNotebookApp handlers:840] Path components/create-react-class/index.js served from /usr/local/lib/python3.6/dist-packages/notebook/static/components/create-react-class/index.js
[D 2019-08-21 17:07:12.933 SingleUserNotebookApp handlers:840] Path components/requirejs/require.js served from /usr/local/lib/python3.6/dist-packages/notebook/static/components/requirejs/require.js
[D 2019-08-21 17:07:12.934 SingleUserNotebookApp handlers:840] Path tree/js/main.min.js served from /usr/local/lib/python3.6/dist-packages/notebook/static/tree/js/main.min.js
[I 2019-08-21 17:07:12.940 SingleUserNotebookApp log:174] 200 GET /user/instructor1/tree? (instructor1@::ffff:128.205.40.121) 62.03ms
[D 2019-08-21 17:07:12.974 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-21 17:07:12.975 SingleUserNotebookApp log:174] 200 GET /user/instructor1/static/components/jquery-ui/themes/smoothness/jquery-ui.min.css?v=3c2a865c832a1322285c55c6ed99abb2 (instructor1@::ffff:128.205.40.121) 2.03ms
[D 2019-08-21 17:07:12.984 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-21 17:07:12.985 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-21 17:07:12.986 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-21 17:07:12.987 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-21 17:07:12.988 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-21 17:07:12.990 SingleUserNotebookApp log:174] 200 GET /user/instructor1/static/components/jquery-typeahead/dist/jquery.typeahead.min.css?v=7afb461de36accb1aa133a1710f5bc56 (instructor1@::ffff:128.205.40.121) 7.08ms
[D 2019-08-21 17:07:12.991 SingleUserNotebookApp log:174] 200 GET /user/instructor1/static/style/style.min.css?v=e91a43337d7c294cc9fab2938fa723b3 (instructor1@::ffff:128.205.40.121) 7.28ms
[D 2019-08-21 17:07:12.992 SingleUserNotebookApp handlers:840] Path custom.css served from /usr/local/lib/python3.6/dist-packages/notebook/static/custom/custom.css
[D 2019-08-21 17:07:12.996 SingleUserNotebookApp log:174] 200 GET /user/instructor1/custom/custom.css (instructor1@::ffff:128.205.40.121) 11.16ms
[D 2019-08-21 17:07:12.997 SingleUserNotebookApp log:174] 200 GET /user/instructor1/static/components/es6-promise/promise.min.js?v=f004a16cb856e0ff11781d01ec5ca8fe (instructor1@::ffff:128.205.40.121) 10.96ms
[D 2019-08-21 17:07:12.998 SingleUserNotebookApp log:174] 200 GET /user/instructor1/static/components/react/react.production.min.js?v=34f96ffc962a7deecc83037ccb582b58 (instructor1@::ffff:128.205.40.121) 10.74ms
[D 2019-08-21 17:07:13.007 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-21 17:07:13.008 SingleUserNotebookApp log:174] 200 GET /user/instructor1/static/components/create-react-class/index.js?v=94feb9971ce6d26211729abc43f96cd2 (instructor1@::ffff:128.205.40.121) 1.49ms
[D 2019-08-21 17:07:13.010 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-21 17:07:13.011 SingleUserNotebookApp log:174] 200 GET /user/instructor1/static/components/requirejs/require.js?v=951f856e81496aaeec2e71a1c2c0d51f (instructor1@::ffff:128.205.40.121) 1.49ms
[D 2019-08-21 17:07:13.014 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-21 17:07:13.015 SingleUserNotebookApp handlers:260] Using contents: services/contents
[W 2019-08-21 17:07:13.022 SingleUserNotebookApp log:174] 404 GET /user/instructor1/static/components/react/react-dom.production.min.js (instructor1@::ffff:128.205.40.121) 7.91ms
[D 2019-08-21 17:07:13.023 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-21 17:07:13.027 SingleUserNotebookApp log:174] 200 GET /user/instructor1/static/tree/js/main.min.js?v=14330cdaf7734bc96358311b42a8d42b (instructor1@::ffff:128.205.40.121) 4.08ms
[D 2019-08-21 17:07:13.174 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-21 17:07:13.174 SingleUserNotebookApp handlers:840] Path services/contents.js served from /usr/local/lib/python3.6/dist-packages/notebook/static/services/contents.js
[D 2019-08-21 17:07:13.175 SingleUserNotebookApp log:174] 200 GET /user/instructor1/static/services/contents.js?v=20190821170711 (instructor1@::ffff:128.205.40.121) 1.94ms
[D 2019-08-21 17:07:13.203 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-21 17:07:13.204 SingleUserNotebookApp config_manager:98] Paths used for configuration of tree: 
        /etc/jupyter/nbconfig/tree.json
[D 2019-08-21 17:07:13.205 SingleUserNotebookApp config_manager:98] Paths used for configuration of tree: 
        /usr/local/etc/jupyter/nbconfig/tree.json
[D 2019-08-21 17:07:13.205 SingleUserNotebookApp config_manager:98] Paths used for configuration of tree: 
        /usr/etc/jupyter/nbconfig/tree.json
[D 2019-08-21 17:07:13.206 SingleUserNotebookApp config_manager:98] Paths used for configuration of tree: 
        /home/instructor1/.jupyter/nbconfig/tree.json
[I 2019-08-21 17:07:13.207 SingleUserNotebookApp log:174] 200 GET /user/instructor1/api/config/tree?_=1566421633134 (instructor1@::ffff:128.205.40.121) 4.07ms
[D 2019-08-21 17:07:13.208 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-21 17:07:13.208 SingleUserNotebookApp config_manager:98] Paths used for configuration of common: 
        /etc/jupyter/nbconfig/common.json
[D 2019-08-21 17:07:13.209 SingleUserNotebookApp config_manager:98] Paths used for configuration of common: 
        /usr/local/etc/jupyter/nbconfig/common.json
[D 2019-08-21 17:07:13.209 SingleUserNotebookApp config_manager:98] Paths used for configuration of common: 
        /usr/etc/jupyter/nbconfig/common.json
[D 2019-08-21 17:07:13.210 SingleUserNotebookApp config_manager:98] Paths used for configuration of common: 
        /home/instructor1/.jupyter/nbconfig/common.json
[I 2019-08-21 17:07:13.211 SingleUserNotebookApp log:174] 200 GET /user/instructor1/api/config/common?_=1566421633135 (instructor1@::ffff:128.205.40.121) 3.29ms
[D 2019-08-21 17:07:13.220 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-21 17:07:13.221 SingleUserNotebookApp kernelspec:169] Found kernel python3 in /usr/local/share/jupyter/kernels
[I 2019-08-21 17:07:13.224 SingleUserNotebookApp log:174] 200 GET /user/instructor1/api/kernelspecs (instructor1@::ffff:128.205.40.121) 4.52ms
[D 2019-08-21 17:07:13.225 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[I 2019-08-21 17:07:13.226 SingleUserNotebookApp log:174] 200 GET /user/instructor1/api/terminals?_=1566421633136 (instructor1@::ffff:128.205.40.121) 1.14ms
[D 2019-08-21 17:07:13.227 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-21 17:07:13.228 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[I 2019-08-21 17:07:13.230 SingleUserNotebookApp log:174] 200 GET /user/instructor1/api/sessions?_=1566421633137 (instructor1@::ffff:128.205.40.121) 3.38ms
[I 2019-08-21 17:07:13.230 SingleUserNotebookApp log:174] 200 GET /user/instructor1/api/terminals?_=1566421633138 (instructor1@::ffff:128.205.40.121) 2.46ms
[D 2019-08-21 17:07:13.232 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-21 17:07:13.233 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-21 17:07:13.233 SingleUserNotebookApp handlers:840] Path components/font-awesome/fonts/fontawesome-webfont.woff2 served from /usr/local/lib/python3.6/dist-packages/notebook/static/components/font-awesome/fonts/fontawesome-webfont.woff2
[D 2019-08-21 17:07:13.234 SingleUserNotebookApp log:174] 200 GET /user/instructor1/static/components/font-awesome/fonts/fontawesome-webfont.woff2?v=4.7.0 (instructor1@::ffff:128.205.40.121) 3.10ms
[D 2019-08-21 17:07:13.235 SingleUserNotebookApp handlers:840] Path custom.js served from /usr/local/lib/python3.6/dist-packages/notebook/static/custom/custom.js
[D 2019-08-21 17:07:13.235 SingleUserNotebookApp log:174] 200 GET /user/instructor1/custom/custom.js?v=20190821170711 (instructor1@::ffff:128.205.40.121) 3.08ms
[D 2019-08-21 17:07:13.243 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-21 17:07:13.244 SingleUserNotebookApp handlers:840] Path assignment_list/main.js served from /home/instructor1/.local/share/jupyter/nbextensions/assignment_list/main.js
[D 2019-08-21 17:07:13.245 SingleUserNotebookApp log:174] 200 GET /user/instructor1/nbextensions/assignment_list/main.js?v=20190821170711 (instructor1@::ffff:128.205.40.121) 1.71ms
[D 2019-08-21 17:07:13.245 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-21 17:07:13.246 SingleUserNotebookApp handlers:840] Path formgrader/main.js served from /home/instructor1/.local/share/jupyter/nbextensions/formgrader/main.js
[D 2019-08-21 17:07:13.247 SingleUserNotebookApp log:174] 200 GET /user/instructor1/nbextensions/formgrader/main.js?v=20190821170711 (instructor1@::ffff:128.205.40.121) 1.64ms
[D 2019-08-21 17:07:13.248 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[I 2019-08-21 17:07:13.250 SingleUserNotebookApp log:174] 200 GET /user/instructor1/api/contents?type=directory&_=1566421633139 (instructor1@::ffff:128.205.40.121) 2.86ms
[D 2019-08-21 17:07:13.256 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-21 17:07:13.256 SingleUserNotebookApp handlers:840] Path course_list/main.js served from /home/instructor1/.local/share/jupyter/nbextensions/course_list/main.js
[D 2019-08-21 17:07:13.257 SingleUserNotebookApp log:174] 200 GET /user/instructor1/nbextensions/course_list/main.js?v=20190821170711 (instructor1@::ffff:128.205.40.121) 1.69ms
[D 2019-08-21 17:07:13.264 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-21 17:07:13.264 SingleUserNotebookApp handlers:840] Path assignment_list/assignment_list.js served from /home/instructor1/.local/share/jupyter/nbextensions/assignment_list/assignment_list.js
[D 2019-08-21 17:07:13.265 SingleUserNotebookApp log:174] 200 GET /user/instructor1/nbextensions/assignment_list/assignment_list.js?v=20190821170711 (instructor1@::ffff:128.205.40.121) 1.71ms
[D 2019-08-21 17:07:13.284 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-21 17:07:13.284 SingleUserNotebookApp handlers:840] Path assignment_list/assignment_list.css served from /home/instructor1/.local/share/jupyter/nbextensions/assignment_list/assignment_list.css
[D 2019-08-21 17:07:13.285 SingleUserNotebookApp log:174] 200 GET /user/instructor1/nbextensions/assignment_list/assignment_list.css (instructor1@::ffff:128.205.40.121) 1.64ms
[D 2019-08-21 17:07:13.286 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[I 2019-08-21 17:07:13.287 SingleUserNotebookApp log:174] 200 GET /user/instructor1/nbgrader_version?version=0.6.0.dev&_=1566421633140 (instructor1@::ffff:128.205.40.121) 1.16ms
[D 2019-08-21 17:07:13.293 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-21 17:07:13.294 SingleUserNotebookApp handlers:840] Path course_list/course_list.js served from /home/instructor1/.local/share/jupyter/nbextensions/course_list/course_list.js
[D 2019-08-21 17:07:13.295 SingleUserNotebookApp log:174] 200 GET /user/instructor1/nbextensions/course_list/course_list.js?v=20190821170711 (instructor1@::ffff:128.205.40.121) 6.54ms
[D 2019-08-21 17:07:13.311 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-21 17:07:13.312 SingleUserNotebookApp handlers:840] Path course_list/course_list.css served from /home/instructor1/.local/share/jupyter/nbextensions/course_list/course_list.css
[D 2019-08-21 17:07:13.312 SingleUserNotebookApp log:174] 200 GET /user/instructor1/nbextensions/course_list/course_list.css (instructor1@::ffff:128.205.40.121) 1.64ms
[D 2019-08-21 17:07:13.317 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[I 2019-08-21 17:07:13.318 SingleUserNotebookApp log:174] 200 GET /user/instructor1/nbgrader_version?version=0.6.0.dev&_=1566421633141 (instructor1@::ffff:128.205.40.121) 1.15ms
[D 2019-08-21 17:07:14.538 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[I 2019-08-21 17:07:14.546 SingleUserNotebookApp log:174] 200 GET /user/instructor1/formgrader (instructor1@::ffff:128.205.40.121) 8.89ms
[D 2019-08-21 17:07:14.597 SingleUserNotebookApp log:174] 200 GET /user/instructor1/formgrader/static/components/datatables.net-bs/css/dataTables.bootstrap.min.css (@::ffff:128.205.40.121) 1.31ms
[D 2019-08-21 17:07:14.600 SingleUserNotebookApp log:174] 200 GET /user/instructor1/formgrader/static/css/nbgrader.css (@::ffff:128.205.40.121) 2.29ms
[D 2019-08-21 17:07:14.601 SingleUserNotebookApp log:174] 200 GET /user/instructor1/formgrader/static/js/utils.js (@::ffff:128.205.40.121) 2.83ms
[D 2019-08-21 17:07:14.602 SingleUserNotebookApp log:174] 200 GET /user/instructor1/formgrader/static/components/jquery/jquery.min.js (@::ffff:128.205.40.121) 3.87ms
[D 2019-08-21 17:07:14.603 SingleUserNotebookApp log:174] 200 GET /user/instructor1/formgrader/static/components/underscore/underscore-min.js (@::ffff:128.205.40.121) 4.41ms
[D 2019-08-21 17:07:14.605 SingleUserNotebookApp log:174] 200 GET /user/instructor1/formgrader/static/components/backbone/backbone-min.js (@::ffff:128.205.40.121) 1.18ms
[D 2019-08-21 17:07:14.609 SingleUserNotebookApp log:174] 200 GET /user/instructor1/formgrader/static/components/bootstrap/css/bootstrap.min.css (@::ffff:128.205.40.121) 1.61ms
[D 2019-08-21 17:07:14.613 SingleUserNotebookApp log:174] 200 GET /user/instructor1/formgrader/static/components/bootstrap/js/bootstrap.min.js (@::ffff:128.205.40.121) 1.18ms
[D 2019-08-21 17:07:14.615 SingleUserNotebookApp log:174] 200 GET /user/instructor1/formgrader/static/components/datatables.net/js/jquery.dataTables.min.js (@::ffff:128.205.40.121) 1.40ms
[D 2019-08-21 17:07:14.618 SingleUserNotebookApp log:174] 200 GET /user/instructor1/formgrader/static/components/datatables.net-bs/js/dataTables.bootstrap.min.js (@::ffff:128.205.40.121) 1.00ms
[D 2019-08-21 17:07:14.619 SingleUserNotebookApp log:174] 200 GET /user/instructor1/formgrader/static/js/backbone_xsrf.js (@::ffff:128.205.40.121) 0.99ms
[E 2019-08-21 17:07:35.011 JupyterHub service:357] Service testcourse exited with status 1
[I 2019-08-21 17:07:35.011 JupyterHub service:316] Starting service 'testcourse': ['jupyterhub-singleuser', '--group=instructors', '--debug']
[I 2019-08-21 17:07:35.016 JupyterHub service:121] Spawning jupyterhub-singleuser --group=instructors --debug
[D 2019-08-21 17:07:35.031 JupyterHub spawner:1084] Polling subprocess every 30s
[D 2019-08-21 17:07:35.562 SingleUserNotebookApp application:177] Searching ['/home/grader', '/home/grader/.jupyter', '/usr/etc/jupyter', '/usr/local/etc/jupyter', '/etc/jupyter'] for config files
[D 2019-08-21 17:07:35.563 SingleUserNotebookApp application:555] Looking for jupyter_config in /etc/jupyter
[D 2019-08-21 17:07:35.563 SingleUserNotebookApp application:555] Looking for jupyter_config in /usr/local/etc/jupyter
[D 2019-08-21 17:07:35.563 SingleUserNotebookApp application:555] Looking for jupyter_config in /usr/etc/jupyter
[D 2019-08-21 17:07:35.563 SingleUserNotebookApp application:555] Looking for jupyter_config in /home/grader/.jupyter
[D 2019-08-21 17:07:35.563 SingleUserNotebookApp application:555] Looking for jupyter_config in /home/grader
[D 2019-08-21 17:07:35.564 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /etc/jupyter
[D 2019-08-21 17:07:35.564 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /usr/local/etc/jupyter
[D 2019-08-21 17:07:35.564 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /usr/etc/jupyter
[D 2019-08-21 17:07:35.565 SingleUserNotebookApp application:577] Loaded config file: /usr/etc/jupyter/jupyter_notebook_config.json
[D 2019-08-21 17:07:35.565 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /home/grader/.jupyter
[D 2019-08-21 17:07:35.565 SingleUserNotebookApp application:577] Loaded config file: /home/grader/.jupyter/jupyter_notebook_config.json
[D 2019-08-21 17:07:35.566 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /home/grader
[D 2019-08-21 17:07:35.572 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /etc/jupyter/jupyter_notebook_config.json
[D 2019-08-21 17:07:35.572 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /usr/local/etc/jupyter/jupyter_notebook_config.json
[D 2019-08-21 17:07:35.573 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /usr/etc/jupyter/jupyter_notebook_config.json
[D 2019-08-21 17:07:35.573 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /home/grader/.jupyter/jupyter_notebook_config.json
[W 2019-08-21 17:07:35.837 SingleUserNotebookApp notebookapp:1448] Permission to listen on port 443 denied
[C 2019-08-21 17:07:35.837 SingleUserNotebookApp notebookapp:1457] ERROR: the notebook server could not be started because no available port could be found.
[D 2019-08-21 17:07:35.837 SingleUserNotebookApp application:647] Exiting application: jupyter-notebook
[E 2019-08-21 17:08:05.033 JupyterHub service:357] Service testcourse exited with status 1
[I 2019-08-21 17:08:05.033 JupyterHub service:316] Starting service 'testcourse': ['jupyterhub-singleuser', '--group=instructors', '--debug']
[I 2019-08-21 17:08:05.038 JupyterHub service:121] Spawning jupyterhub-singleuser --group=instructors --debug
[D 2019-08-21 17:08:05.046 JupyterHub spawner:1084] Polling subprocess every 30s
[D 2019-08-21 17:08:05.595 SingleUserNotebookApp application:177] Searching ['/home/grader', '/home/grader/.jupyter', '/usr/etc/jupyter', '/usr/local/etc/jupyter', '/etc/jupyter'] for config files
[D 2019-08-21 17:08:05.595 SingleUserNotebookApp application:555] Looking for jupyter_config in /etc/jupyter
[D 2019-08-21 17:08:05.596 SingleUserNotebookApp application:555] Looking for jupyter_config in /usr/local/etc/jupyter
[D 2019-08-21 17:08:05.596 SingleUserNotebookApp application:555] Looking for jupyter_config in /usr/etc/jupyter
[D 2019-08-21 17:08:05.596 SingleUserNotebookApp application:555] Looking for jupyter_config in /home/grader/.jupyter
[D 2019-08-21 17:08:05.596 SingleUserNotebookApp application:555] Looking for jupyter_config in /home/grader
[D 2019-08-21 17:08:05.597 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /etc/jupyter
[D 2019-08-21 17:08:05.597 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /usr/local/etc/jupyter
[D 2019-08-21 17:08:05.597 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /usr/etc/jupyter
[D 2019-08-21 17:08:05.598 SingleUserNotebookApp application:577] Loaded config file: /usr/etc/jupyter/jupyter_notebook_config.json
[D 2019-08-21 17:08:05.598 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /home/grader/.jupyter
[D 2019-08-21 17:08:05.598 SingleUserNotebookApp application:577] Loaded config file: /home/grader/.jupyter/jupyter_notebook_config.json
[D 2019-08-21 17:08:05.599 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /home/grader
[D 2019-08-21 17:08:05.605 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /etc/jupyter/jupyter_notebook_config.json
[D 2019-08-21 17:08:05.605 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /usr/local/etc/jupyter/jupyter_notebook_config.json
[D 2019-08-21 17:08:05.606 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /usr/etc/jupyter/jupyter_notebook_config.json
[D 2019-08-21 17:08:05.606 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /home/grader/.jupyter/jupyter_notebook_config.json
[W 2019-08-21 17:08:05.878 SingleUserNotebookApp notebookapp:1448] Permission to listen on port 443 denied
[C 2019-08-21 17:08:05.878 SingleUserNotebookApp notebookapp:1457] ERROR: the notebook server could not be started because no available port could be found.
[D 2019-08-21 17:08:05.878 SingleUserNotebookApp application:647] Exiting application: jupyter-notebook
[D 2019-08-21 17:08:05.965 JupyterHub app:1812] Managed service testcourse running at http://127.0.0.1:443
[E 2019-08-21 17:08:35.049 JupyterHub service:357] Service testcourse exited with status 1
[I 2019-08-21 17:08:35.049 JupyterHub service:316] Starting service 'testcourse': ['jupyterhub-singleuser', '--group=instructors', '--debug']
[I 2019-08-21 17:08:35.052 JupyterHub service:121] Spawning jupyterhub-singleuser --group=instructors --debug
[D 2019-08-21 17:08:35.058 JupyterHub spawner:1084] Polling subprocess every 30s
[D 2019-08-21 17:08:35.561 SingleUserNotebookApp application:177] Searching ['/home/grader', '/home/grader/.jupyter', '/usr/etc/jupyter', '/usr/local/etc/jupyter', '/etc/jupyter'] for config files
[D 2019-08-21 17:08:35.562 SingleUserNotebookApp application:555] Looking for jupyter_config in /etc/jupyter
[D 2019-08-21 17:08:35.562 SingleUserNotebookApp application:555] Looking for jupyter_config in /usr/local/etc/jupyter
[D 2019-08-21 17:08:35.562 SingleUserNotebookApp application:555] Looking for jupyter_config in /usr/etc/jupyter
[D 2019-08-21 17:08:35.562 SingleUserNotebookApp application:555] Looking for jupyter_config in /home/grader/.jupyter
[D 2019-08-21 17:08:35.562 SingleUserNotebookApp application:555] Looking for jupyter_config in /home/grader
[D 2019-08-21 17:08:35.563 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /etc/jupyter
[D 2019-08-21 17:08:35.564 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /usr/local/etc/jupyter
[D 2019-08-21 17:08:35.564 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /usr/etc/jupyter
[D 2019-08-21 17:08:35.564 SingleUserNotebookApp application:577] Loaded config file: /usr/etc/jupyter/jupyter_notebook_config.json
[D 2019-08-21 17:08:35.564 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /home/grader/.jupyter
[D 2019-08-21 17:08:35.565 SingleUserNotebookApp application:577] Loaded config file: /home/grader/.jupyter/jupyter_notebook_config.json
[D 2019-08-21 17:08:35.565 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /home/grader
[D 2019-08-21 17:08:35.571 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /etc/jupyter/jupyter_notebook_config.json
[D 2019-08-21 17:08:35.572 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /usr/local/etc/jupyter/jupyter_notebook_config.json
[D 2019-08-21 17:08:35.572 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /usr/etc/jupyter/jupyter_notebook_config.json
[D 2019-08-21 17:08:35.573 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /home/grader/.jupyter/jupyter_notebook_config.json
[W 2019-08-21 17:08:35.821 SingleUserNotebookApp notebookapp:1448] Permission to listen on port 443 denied
[C 2019-08-21 17:08:35.821 SingleUserNotebookApp notebookapp:1457] ERROR: the notebook server could not be started because no available port could be found.
[D 2019-08-21 17:08:35.821 SingleUserNotebookApp application:647] Exiting application: jupyter-notebook
[E 2019-08-21 17:09:05.060 JupyterHub service:357] Service testcourse exited with status 1
[I 2019-08-21 17:09:05.060 JupyterHub service:316] Starting service 'testcourse': ['jupyterhub-singleuser', '--group=instructors', '--debug']
[I 2019-08-21 17:09:05.064 JupyterHub service:121] Spawning jupyterhub-singleuser --group=instructors --debug
[D 2019-08-21 17:09:05.072 JupyterHub spawner:1084] Polling subprocess every 30s
jhamrick commented 5 years ago

Thanks for the logs! I noticed these lines:

[W 2019-08-21 17:07:05.808 SingleUserNotebookApp notebookapp:1448] Permission to listen on port 443 denied
[C 2019-08-21 17:07:05.808 SingleUserNotebookApp notebookapp:1457] ERROR: the notebook server could not be started because no available port could be found.
[D 2019-08-21 17:07:05.808 SingleUserNotebookApp application:647] Exiting application: jupyter-notebook
[E 2019-08-21 17:07:05.941 JupyterHub app:2392] Service testcourse exited with status 1

Which makes it sound like port 443 is already in use. And I re-checked your config and it indeed looks like you're setting port 443 both for the main JupyterHub instance and for the testcourse service. Can you try using different ports there and see if it works?

mkzia commented 5 years ago

Hello Jessica!

Thank you so much for helping me out!

I started from scratch again, so I am using the latest master branch (5bc6f37).

I have updated my jupyterhub_config to as follows:

c = get_config()
c.JupyterHub.bind_url = 'https://:443'
c.JupyterHub.ssl_cert = '/etc/jupyterhub/jupyterhub_cert.pem'
c.JupyterHub.ssl_key = '/etc/jupyterhub/jupyterhub_key.pem'
c.JupyterHub.log_level = 'DEBUG'
c.Spawner.debug = True
c.LocalProcessSpawner.debug = True

c.JupyterHub.load_groups = {
    'instructors': [
        'grader',
        'instructor1',
        'instructor2'
    ]
}

c.JupyterHub.services = [
    {
        'name': 'testcourse',
        'url': 'http://127.0.0.1:8000',
        'command': [
            'jupyterhub-singleuser',
            '--group=instructors',
            '--debug',
        ],
        'user': 'grader',
        'cwd': '/home/grader'
    }
]

I still cannot get instructor1 to access the formgrader. I think the relevant error message is [E 2019-08-24 20:50:04.840 SingleUserNotebookApp formgrader:45] The course directory root is not a subdirectory of the notebook server root. This means that nbgrader will not work correctly. If you want to use nbgrader, please ensure the course directory root is in a subdirectory of the notebook root: /home/instructor1

Should I put the course folder somewhere else on the system?

Contents of /home/instructor1/.jupyter/jupyter_notebook_config.json:

{
  "NotebookApp": {
    "nbserver_extensions": {
      "nbgrader.server_extensions.formgrader": true,
      "nbgrader.server_extensions.validate_assignment": true,
      "nbgrader.server_extensions.assignment_list": true,
      "nbgrader.server_extensions.course_list": true
    }
  }
}

The full log is as follows:

[I 2019-08-24 20:49:31.639 JupyterHub app:2120] Using Authenticator: jupyterhub.auth.PAMAuthenticator-1.0.0
[I 2019-08-24 20:49:31.639 JupyterHub app:2120] Using Spawner: jupyterhub.spawner.LocalProcessSpawner-1.0.0
[D 2019-08-24 20:49:31.640 JupyterHub app:2073] Could not load pycurl: No module named 'pycurl'
    pycurl is recommended if you have a large number of users.
[I 2019-08-24 20:49:31.641 JupyterHub app:1257] Loading cookie_secret from /tmp/nbgrader/jupyterhub_cookie_secret
[D 2019-08-24 20:49:31.641 JupyterHub app:1424] Connecting to db: sqlite:///jupyterhub.sqlite
[D 2019-08-24 20:49:31.655 JupyterHub orm:749] database schema version found: 4dc2d5a8c53c
[I 2019-08-24 20:49:31.658 JupyterHub proxy:460] Generating new CONFIGPROXY_AUTH_TOKEN
[W 2019-08-24 20:49:31.659 JupyterHub app:1532] No admin users, admin interface will be unavailable.
[W 2019-08-24 20:49:31.659 JupyterHub app:1534] Add any administrative users to `c.Authenticator.admin_users` in config.
[I 2019-08-24 20:49:31.659 JupyterHub app:1563] Not using whitelist. Any authenticated user will be allowed.
[D 2019-08-24 20:49:31.735 JupyterHub app:1910] Loading state for grader from db
[D 2019-08-24 20:49:31.736 JupyterHub app:1910] Loading state for instructor1 from db
[D 2019-08-24 20:49:31.736 JupyterHub app:1910] Loading state for instructor2 from db
[D 2019-08-24 20:49:31.736 JupyterHub app:1926] Loaded users:
      grader
    instructor1
    instructor2
[I 2019-08-24 20:49:31.744 JupyterHub app:2337] Hub API listening on http://127.0.0.1:8081/hub/
[I 2019-08-24 20:49:31.744 JupyterHub proxy:645] Starting proxy @ https://:443
[D 2019-08-24 20:49:31.745 JupyterHub proxy:646] Proxy cmd: ['configurable-http-proxy', '--ip', '', '--port', '443', '--api-ip', '127.0.0.1', '--api-port', '8001', '--error-target', 'http://127.0.0.1:8081/hub/error', '--ssl-key', '/etc/jupyterhub/jupyterhub_key.pem', '--ssl-cert', '/etc/jupyterhub/jupyterhub_cert.pem']
[D 2019-08-24 20:49:31.747 JupyterHub proxy:561] Writing proxy pid file: jupyterhub-proxy.pid
[E 2019-08-24 20:49:31.748 JupyterHub utils:75] Unexpected error connecting to jupyterhub2:443 [Errno 22] Invalid argument
[E 2019-08-24 20:49:31.874 JupyterHub utils:75] Unexpected error connecting to jupyterhub2:443 [Errno 22] Invalid argument
20:49:32.198 [ConfigProxy] info: Proxying https://*:443 to (no default)
20:49:32.201 [ConfigProxy] info: Proxy API at http://127.0.0.1:8001/api/routes
[D 2019-08-24 20:49:32.249 JupyterHub proxy:681] Proxy started and appears to be up
[I 2019-08-24 20:49:32.249 JupyterHub app:2362] Starting managed service testcourse at http://127.0.0.1:8000
[I 2019-08-24 20:49:32.250 JupyterHub service:316] Starting service 'testcourse': ['jupyterhub-singleuser', '--group=instructors', '--debug']
[I 2019-08-24 20:49:32.253 JupyterHub service:121] Spawning jupyterhub-singleuser --group=instructors --debug
[D 2019-08-24 20:49:32.257 JupyterHub spawner:1084] Polling subprocess every 30s
[D 2019-08-24 20:49:32.616 SingleUserNotebookApp application:177] Searching ['/home/grader', '/home/grader/.jupyter', '/usr/etc/jupyter', '/usr/local/etc/jupyter', '/etc/jupyter'] for config files
[D 2019-08-24 20:49:32.617 SingleUserNotebookApp application:555] Looking for jupyter_config in /etc/jupyter
[D 2019-08-24 20:49:32.617 SingleUserNotebookApp application:555] Looking for jupyter_config in /usr/local/etc/jupyter
[D 2019-08-24 20:49:32.617 SingleUserNotebookApp application:555] Looking for jupyter_config in /usr/etc/jupyter
[D 2019-08-24 20:49:32.617 SingleUserNotebookApp application:555] Looking for jupyter_config in /home/grader/.jupyter
[D 2019-08-24 20:49:32.617 SingleUserNotebookApp application:555] Looking for jupyter_config in /home/grader
[D 2019-08-24 20:49:32.618 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /etc/jupyter
[D 2019-08-24 20:49:32.618 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /usr/local/etc/jupyter
[D 2019-08-24 20:49:32.618 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /usr/etc/jupyter
[D 2019-08-24 20:49:32.618 SingleUserNotebookApp application:577] Loaded config file: /usr/etc/jupyter/jupyter_notebook_config.json
[D 2019-08-24 20:49:32.618 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /home/grader/.jupyter
[D 2019-08-24 20:49:32.619 SingleUserNotebookApp application:577] Loaded config file: /home/grader/.jupyter/jupyter_notebook_config.json
[D 2019-08-24 20:49:32.619 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /home/grader
[D 2019-08-24 20:49:32.623 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /etc/jupyter/jupyter_notebook_config.json
[D 2019-08-24 20:49:32.624 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /usr/local/etc/jupyter/jupyter_notebook_config.json
[D 2019-08-24 20:49:32.624 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /usr/etc/jupyter/jupyter_notebook_config.json
[D 2019-08-24 20:49:32.625 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /home/grader/.jupyter/jupyter_notebook_config.json
[I 2019-08-24 20:49:33.116 SingleUserNotebookApp handlers:337] Loading the assignment_list nbgrader serverextension
[I 2019-08-24 20:49:33.118 SingleUserNotebookApp handlers:234] Loading the course_list nbgrader serverextension
[I 2019-08-24 20:49:33.121 SingleUserNotebookApp formgrader:84] Loading the formgrader nbgrader serverextension
[D 2019-08-24 20:49:33.124 SingleUserNotebookApp application:177] Searching ['/home/grader', '/home/grader/.jupyter', '/usr/etc/jupyter', '/usr/local/etc/jupyter', '/etc/jupyter'] for config files
[D 2019-08-24 20:49:33.124 SingleUserNotebookApp application:555] Looking for jupyter_config in /etc/jupyter
[D 2019-08-24 20:49:33.125 SingleUserNotebookApp application:555] Looking for jupyter_config in /usr/local/etc/jupyter
[D 2019-08-24 20:49:33.125 SingleUserNotebookApp application:555] Looking for jupyter_config in /usr/etc/jupyter
[D 2019-08-24 20:49:33.125 SingleUserNotebookApp application:555] Looking for jupyter_config in /home/grader/.jupyter
[D 2019-08-24 20:49:33.125 SingleUserNotebookApp application:555] Looking for jupyter_config in /home/grader
[D 2019-08-24 20:49:33.125 SingleUserNotebookApp application:555] Looking for nbgrader_config in /etc/jupyter
[D 2019-08-24 20:49:33.126 SingleUserNotebookApp application:577] Loaded config file: /etc/jupyter/nbgrader_config.py
[D 2019-08-24 20:49:33.126 SingleUserNotebookApp application:555] Looking for nbgrader_config in /usr/local/etc/jupyter
[D 2019-08-24 20:49:33.126 SingleUserNotebookApp application:555] Looking for nbgrader_config in /usr/etc/jupyter
[D 2019-08-24 20:49:33.126 SingleUserNotebookApp application:555] Looking for nbgrader_config in /home/grader/.jupyter
[D 2019-08-24 20:49:33.126 SingleUserNotebookApp application:577] Loaded config file: /home/grader/.jupyter/nbgrader_config.py
[D 2019-08-24 20:49:33.127 SingleUserNotebookApp application:555] Looking for nbgrader_config in /home/grader
[W 2019-08-24 20:49:33.127 SingleUserNotebookApp configurable:168] Config option `log` not recognized by `FormgradeExtension`.  Did you mean `logfile`?
[D 2019-08-24 20:49:33.128 SingleUserNotebookApp application:555] Looking for nbgrader_config in /home/grader/testcourse
[D 2019-08-24 20:49:33.128 SingleUserNotebookApp application:577] Loaded config file: /home/grader/testcourse/nbgrader_config.py
[I 2019-08-24 20:49:33.141 SingleUserNotebookApp handlers:137] Loading the validate_assignment nbgrader serverextension
[I 2019-08-24 20:49:33.141 SingleUserNotebookApp singleuser:561] Starting jupyterhub-singleuser server version 1.0.0
[I 2019-08-24 20:49:33.144 SingleUserNotebookApp log:174] 302 GET /services/testcourse/ -> /services/testcourse/tree? (@127.0.0.1) 1.30ms
[D 2019-08-24 20:49:33.144 JupyterHub utils:218] Server at http://127.0.0.1:8000/services/testcourse/ responded with 302
[D 2019-08-24 20:49:33.146 JupyterHub proxy:314] Fetching routes to check
[D 2019-08-24 20:49:33.146 JupyterHub proxy:765] Proxy: Fetching GET http://127.0.0.1:8001/api/routes
[I 2019-08-24 20:49:33.147 JupyterHub log:174] 200 GET /hub/api (@127.0.0.1) 1.81ms
[D 2019-08-24 20:49:33.147 SingleUserNotebookApp _version:60] jupyterhub and jupyterhub-singleuser both on version 1.0.0
[I 2019-08-24 20:49:33.147 SingleUserNotebookApp notebookapp:1825] Serving notebooks from local directory: /home/grader
[I 2019-08-24 20:49:33.147 SingleUserNotebookApp notebookapp:1825] The Jupyter Notebook is running at:
[I 2019-08-24 20:49:33.148 SingleUserNotebookApp notebookapp:1825] http://127.0.0.1:8000/services/testcourse/
[I 2019-08-24 20:49:33.148 SingleUserNotebookApp notebookapp:1826] Use Control-C to stop this server and shut down all kernels (twice to skip confirmation).
[W 2019-08-24 20:49:33.152 SingleUserNotebookApp singleuser:539] Activity events disabled
[I 2019-08-24 20:49:33.154 JupyterHub proxy:319] Checking routes
[I 2019-08-24 20:49:33.154 JupyterHub proxy:399] Adding default route for Hub: / => http://127.0.0.1:8081
20:49:33.155 [ConfigProxy] info: 200 GET /api/routes 
[W 2019-08-24 20:49:33.156 JupyterHub proxy:373] Adding missing route for testcourse (Server(url=http://127.0.0.1:8000/services/testcourse/, bind_url=http://127.0.0.1:8000/services/testcourse/))
[D 2019-08-24 20:49:33.156 JupyterHub proxy:765] Proxy: Fetching POST http://127.0.0.1:8001/api/routes/
[I 2019-08-24 20:49:33.157 JupyterHub proxy:242] Adding service testcourse to proxy /services/testcourse/ => http://127.0.0.1:8000
[D 2019-08-24 20:49:33.158 JupyterHub proxy:765] Proxy: Fetching POST http://127.0.0.1:8001/api/routes/services/testcourse
20:49:33.161 [ConfigProxy] info: Adding route / -> http://127.0.0.1:8081
20:49:33.161 [ConfigProxy] info: Route added / -> http://127.0.0.1:8081
20:49:33.162 [ConfigProxy] info: 201 POST /api/routes/ 
20:49:33.162 [ConfigProxy] info: Adding route /services/testcourse -> http://127.0.0.1:8000
20:49:33.163 [ConfigProxy] info: Route added /services/testcourse -> http://127.0.0.1:8000
20:49:33.163 [ConfigProxy] info: 201 POST /api/routes/services/testcourse 
[I 2019-08-24 20:49:33.163 JupyterHub app:2422] JupyterHub is now running at https://:443
[D 2019-08-24 20:49:38.510 JupyterHub base:482] Setting cookie for grader: jupyterhub-services
[D 2019-08-24 20:49:38.511 JupyterHub base:478] Setting cookie jupyterhub-services: {'httponly': True, 'secure': True, 'path': '/services'}
[D 2019-08-24 20:49:38.511 JupyterHub base:478] Setting cookie jupyterhub-session-id: {'httponly': True, 'secure': True}
[D 2019-08-24 20:49:38.511 JupyterHub base:482] Setting cookie for grader: jupyterhub-hub-login
[D 2019-08-24 20:49:38.511 JupyterHub base:478] Setting cookie jupyterhub-hub-login: {'httponly': True, 'secure': True, 'path': '/hub/'}
[I 2019-08-24 20:49:38.511 JupyterHub base:663] User logged in: grader
[D 2019-08-24 20:49:38.511 JupyterHub user:240] Creating <class 'jupyterhub.spawner.LocalProcessSpawner'> for grader:
[I 2019-08-24 20:49:38.513 JupyterHub log:174] 302 POST /hub/login?next= -> /hub/spawn (grader@::ffff:128.205.245.21) 21.34ms
[D 2019-08-24 20:49:38.787 JupyterHub pages:165] Triggering spawn with default options for grader
[D 2019-08-24 20:49:38.787 JupyterHub base:780] Initiating spawn for grader
[D 2019-08-24 20:49:38.787 JupyterHub base:787] 0/100 concurrent spawns
[D 2019-08-24 20:49:38.787 JupyterHub base:792] 0 active servers
[W 2019-08-24 20:49:38.947 JupyterHub auth:941] Failed to open PAM session for grader: [PAM Error 14] Cannot make/remove an entry for the specified session
[W 2019-08-24 20:49:38.948 JupyterHub auth:942] Disabling PAM sessions from now on.
[D 2019-08-24 20:49:38.958 JupyterHub user:542] Calling Spawner.start for grader
[I 2019-08-24 20:49:38.960 JupyterHub spawner:1387] Spawning jupyterhub-singleuser --port=40931 --debug
[D 2019-08-24 20:49:38.972 JupyterHub spawner:1084] Polling subprocess every 30s
[D 2019-08-24 20:49:39.335 SingleUserNotebookApp application:177] Searching ['/home/grader', '/home/grader/.jupyter', '/usr/etc/jupyter', '/usr/local/etc/jupyter', '/etc/jupyter'] for config files
[D 2019-08-24 20:49:39.335 SingleUserNotebookApp application:555] Looking for jupyter_config in /etc/jupyter
[D 2019-08-24 20:49:39.335 SingleUserNotebookApp application:555] Looking for jupyter_config in /usr/local/etc/jupyter
[D 2019-08-24 20:49:39.335 SingleUserNotebookApp application:555] Looking for jupyter_config in /usr/etc/jupyter
[D 2019-08-24 20:49:39.335 SingleUserNotebookApp application:555] Looking for jupyter_config in /home/grader/.jupyter
[D 2019-08-24 20:49:39.336 SingleUserNotebookApp application:555] Looking for jupyter_config in /home/grader
[D 2019-08-24 20:49:39.336 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /etc/jupyter
[D 2019-08-24 20:49:39.337 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /usr/local/etc/jupyter
[D 2019-08-24 20:49:39.337 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /usr/etc/jupyter
[D 2019-08-24 20:49:39.337 SingleUserNotebookApp application:577] Loaded config file: /usr/etc/jupyter/jupyter_notebook_config.json
[D 2019-08-24 20:49:39.337 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /home/grader/.jupyter
[D 2019-08-24 20:49:39.337 SingleUserNotebookApp application:577] Loaded config file: /home/grader/.jupyter/jupyter_notebook_config.json
[D 2019-08-24 20:49:39.338 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /home/grader
[D 2019-08-24 20:49:39.342 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /etc/jupyter/jupyter_notebook_config.json
[D 2019-08-24 20:49:39.343 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /usr/local/etc/jupyter/jupyter_notebook_config.json
[D 2019-08-24 20:49:39.343 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /usr/etc/jupyter/jupyter_notebook_config.json
[D 2019-08-24 20:49:39.344 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /home/grader/.jupyter/jupyter_notebook_config.json
[I 2019-08-24 20:49:39.789 JupyterHub log:174] 302 GET /hub/spawn -> /hub/spawn-pending/grader (grader@::ffff:128.205.245.21) 1011.52ms
[I 2019-08-24 20:49:39.846 SingleUserNotebookApp handlers:337] Loading the assignment_list nbgrader serverextension
[I 2019-08-24 20:49:39.848 SingleUserNotebookApp handlers:234] Loading the course_list nbgrader serverextension
[I 2019-08-24 20:49:39.851 SingleUserNotebookApp formgrader:84] Loading the formgrader nbgrader serverextension
[D 2019-08-24 20:49:39.854 SingleUserNotebookApp application:177] Searching ['/home/grader', '/home/grader/.jupyter', '/usr/etc/jupyter', '/usr/local/etc/jupyter', '/etc/jupyter'] for config files
[D 2019-08-24 20:49:39.854 SingleUserNotebookApp application:555] Looking for jupyter_config in /etc/jupyter
[D 2019-08-24 20:49:39.854 SingleUserNotebookApp application:555] Looking for jupyter_config in /usr/local/etc/jupyter
[D 2019-08-24 20:49:39.855 SingleUserNotebookApp application:555] Looking for jupyter_config in /usr/etc/jupyter
[D 2019-08-24 20:49:39.855 SingleUserNotebookApp application:555] Looking for jupyter_config in /home/grader/.jupyter
[D 2019-08-24 20:49:39.855 SingleUserNotebookApp application:555] Looking for jupyter_config in /home/grader
[D 2019-08-24 20:49:39.855 SingleUserNotebookApp application:555] Looking for nbgrader_config in /etc/jupyter
[D 2019-08-24 20:49:39.856 SingleUserNotebookApp application:577] Loaded config file: /etc/jupyter/nbgrader_config.py
[D 2019-08-24 20:49:39.856 SingleUserNotebookApp application:555] Looking for nbgrader_config in /usr/local/etc/jupyter
[D 2019-08-24 20:49:39.856 SingleUserNotebookApp application:555] Looking for nbgrader_config in /usr/etc/jupyter
[D 2019-08-24 20:49:39.856 SingleUserNotebookApp application:555] Looking for nbgrader_config in /home/grader/.jupyter
[D 2019-08-24 20:49:39.856 SingleUserNotebookApp application:577] Loaded config file: /home/grader/.jupyter/nbgrader_config.py
[D 2019-08-24 20:49:39.857 SingleUserNotebookApp application:555] Looking for nbgrader_config in /home/grader
[W 2019-08-24 20:49:39.857 SingleUserNotebookApp configurable:168] Config option `log` not recognized by `FormgradeExtension`.  Did you mean `logfile`?
[D 2019-08-24 20:49:39.858 SingleUserNotebookApp application:555] Looking for nbgrader_config in /home/grader/testcourse
[D 2019-08-24 20:49:39.858 SingleUserNotebookApp application:577] Loaded config file: /home/grader/testcourse/nbgrader_config.py
[I 2019-08-24 20:49:39.871 SingleUserNotebookApp handlers:137] Loading the validate_assignment nbgrader serverextension
[I 2019-08-24 20:49:39.872 SingleUserNotebookApp singleuser:561] Starting jupyterhub-singleuser server version 1.0.0
[I 2019-08-24 20:49:39.874 SingleUserNotebookApp log:174] 302 GET /user/grader/ -> /user/grader/tree? (@127.0.0.1) 1.38ms
[D 2019-08-24 20:49:39.875 JupyterHub utils:218] Server at http://127.0.0.1:40931/user/grader/ responded with 302
[D 2019-08-24 20:49:39.875 JupyterHub _version:60] jupyterhub and jupyterhub-singleuser both on version 1.0.0
[I 2019-08-24 20:49:39.875 JupyterHub base:810] User grader took 1.088 seconds to start
[I 2019-08-24 20:49:39.875 JupyterHub proxy:261] Adding user grader to proxy /user/grader/ => http://127.0.0.1:40931
[D 2019-08-24 20:49:39.875 JupyterHub proxy:765] Proxy: Fetching POST http://127.0.0.1:8001/api/routes/user/grader
[I 2019-08-24 20:49:39.877 JupyterHub log:174] 200 GET /hub/api (@127.0.0.1) 1.13ms
20:49:39.878 [ConfigProxy] info: Adding route /user/grader -> http://127.0.0.1:40931
20:49:39.878 [ConfigProxy] info: Route added /user/grader -> http://127.0.0.1:40931
20:49:39.879 [ConfigProxy] info: 201 POST /api/routes/user/grader 
[D 2019-08-24 20:49:39.878 SingleUserNotebookApp _version:60] jupyterhub and jupyterhub-singleuser both on version 1.0.0
[I 2019-08-24 20:49:39.879 SingleUserNotebookApp notebookapp:1825] Serving notebooks from local directory: /home/grader
[I 2019-08-24 20:49:39.879 SingleUserNotebookApp notebookapp:1825] The Jupyter Notebook is running at:
[I 2019-08-24 20:49:39.879 SingleUserNotebookApp notebookapp:1825] http://127.0.0.1:40931/user/grader/
[I 2019-08-24 20:49:39.879 SingleUserNotebookApp notebookapp:1826] Use Control-C to stop this server and shut down all kernels (twice to skip confirmation).
[I 2019-08-24 20:49:39.883 SingleUserNotebookApp singleuser:542] Updating Hub with activity every 300 seconds
[D 2019-08-24 20:49:39.884 SingleUserNotebookApp singleuser:503] Notifying Hub of activity 2019-08-25T00:49:39.346693Z
[D 2019-08-24 20:49:39.898 JupyterHub users:708] Activity for user grader: 2019-08-25T00:49:39.346693Z
[D 2019-08-24 20:49:39.898 JupyterHub users:729] Activity on server grader/: 2019-08-25T00:49:39.346693Z
[I 2019-08-24 20:49:39.905 JupyterHub log:174] 200 POST /hub/api/users/grader/activity (grader@127.0.0.1) 20.02ms
[I 2019-08-24 20:49:40.046 JupyterHub log:174] 302 GET /hub/spawn-pending/grader -> /user/grader/ (grader@::ffff:128.205.245.21) 8.80ms
[I 2019-08-24 20:49:40.257 SingleUserNotebookApp log:174] 302 GET /user/grader/ -> /user/grader/tree? (@::ffff:128.205.245.21) 1.14ms
[D 2019-08-24 20:49:40.469 SingleUserNotebookApp auth:501] No user identified
[D 2019-08-24 20:49:40.470 SingleUserNotebookApp auth:832] Redirecting to login url: /hub/api/oauth2/authorize?client_id=jupyterhub-user-grader&redirect_uri=%2Fuser%2Fgrader%2Foauth_callback&response_type=code&state=eyJ1dWlkIjogIjE2YjU5Mjk0YTAxMDQ4NWM4OWNlNzY1NzA0YzRlM2M0IiwgIm5leHRfdXJsIjogIi91c2VyL2dyYWRlci90cmVlPyJ9
[I 2019-08-24 20:49:40.471 SingleUserNotebookApp log:174] 302 GET /user/grader/tree? -> /hub/api/oauth2/authorize?client_id=jupyterhub-user-grader&redirect_uri=%2Fuser%2Fgrader%2Foauth_callback&response_type=code&state=[secret] (@::ffff:128.205.245.21) 2.35ms
[D 2019-08-24 20:49:40.699 JupyterHub provider:414] Validating client id jupyterhub-user-grader
[D 2019-08-24 20:49:40.701 JupyterHub provider:492] validate_redirect_uri: client_id=jupyterhub-user-grader, redirect_uri=/user/grader/oauth_callback
[D 2019-08-24 20:49:40.702 JupyterHub auth:222] Skipping oauth confirmation for <User(grader 1/1 running)> accessing Server at /user/grader/
[D 2019-08-24 20:49:40.702 JupyterHub provider:414] Validating client id jupyterhub-user-grader
[D 2019-08-24 20:49:40.703 JupyterHub provider:492] validate_redirect_uri: client_id=jupyterhub-user-grader, redirect_uri=/user/grader/oauth_callback
[D 2019-08-24 20:49:40.704 JupyterHub provider:241] Saving authorization code jupyterhub-user-grader, 1gy..., (), {}
[I 2019-08-24 20:49:40.727 JupyterHub log:174] 302 GET /hub/api/oauth2/authorize?client_id=jupyterhub-user-grader&redirect_uri=%2Fuser%2Fgrader%2Foauth_callback&response_type=code&state=[secret] -> /user/grader/oauth_callback?code=[secret]&state=[secret] (grader@::ffff:128.205.245.21) 37.27ms
[D 2019-08-24 20:49:40.957 SingleUserNotebookApp auth:501] No user identified
[D 2019-08-24 20:49:40.971 JupyterHub provider:60] authenticate_client <oauthlib.Request SANITIZED>
[D 2019-08-24 20:49:40.977 JupyterHub provider:119] confirm_redirect_uri: client_id=jupyterhub-user-grader, redirect_uri=/user/grader/oauth_callback
[D 2019-08-24 20:49:40.978 JupyterHub provider:339] Saving bearer token {'access_token': 'REDACTED', 'expires_in': 3600, 'token_type': 'Bearer', 'scope': 'identify', 'refresh_token': 'REDACTED'}
[D 2019-08-24 20:49:40.989 JupyterHub provider:194] Deleting oauth code 1gy... for jupyterhub-user-grader
[I 2019-08-24 20:49:41.000 JupyterHub log:174] 200 POST /hub/api/oauth2/token (grader@127.0.0.1) 40.71ms
[D 2019-08-24 20:49:41.001 SingleUserNotebookApp auth:310] HubAuth cache miss: token:8b88dd069bd247bda97dc09eb7a90835:MBWH6Bhu5oaGgNTBTGHa913eefFiYK
[I 2019-08-24 20:49:41.034 JupyterHub log:174] 200 GET /hub/api/authorizations/token/[secret] (grader@127.0.0.1) 31.84ms
[D 2019-08-24 20:49:41.035 SingleUserNotebookApp auth:316] Received request from Hub user {'kind': 'user', 'name': 'grader', 'admin': False, 'groups': ['instructors'], 'server': '/user/grader/', 'pending': None, 'created': '2019-08-25T00:41:50.066232Z', 'last_activity': '2019-08-25T00:49:41.025086Z', 'servers': None}
[I 2019-08-24 20:49:41.035 SingleUserNotebookApp auth:981] Logged-in user {'kind': 'user', 'name': 'grader', 'admin': False, 'groups': ['instructors'], 'server': '/user/grader/', 'pending': None, 'created': '2019-08-25T00:41:50.066232Z', 'last_activity': '2019-08-25T00:49:41.025086Z', 'servers': None}
[D 2019-08-24 20:49:41.035 SingleUserNotebookApp auth:744] Setting oauth cookie for ::ffff:128.205.245.21: jupyterhub-user-grader, {'path': '/user/grader/', 'httponly': True, 'secure': True}
[I 2019-08-24 20:49:41.036 SingleUserNotebookApp log:174] 302 GET /user/grader/oauth_callback?code=[secret]&state=[secret] -> /user/grader/tree? (@::ffff:128.205.245.21) 79.66ms
[D 2019-08-24 20:49:41.257 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[D 2019-08-24 20:49:41.257 SingleUserNotebookApp handlers:260] Using contents: services/contents
[D 2019-08-24 20:49:41.300 SingleUserNotebookApp handlers:840] Path base/images/favicon.ico served from /usr/local/lib/python3.6/dist-packages/notebook/static/base/images/favicon.ico
[D 2019-08-24 20:49:41.300 SingleUserNotebookApp handlers:840] Path components/jquery-ui/themes/smoothness/jquery-ui.min.css served from /usr/local/lib/python3.6/dist-packages/notebook/static/components/jquery-ui/themes/smoothness/jquery-ui.min.css
[D 2019-08-24 20:49:41.300 SingleUserNotebookApp handlers:840] Path components/jquery-typeahead/dist/jquery.typeahead.min.css served from /usr/local/lib/python3.6/dist-packages/notebook/static/components/jquery-typeahead/dist/jquery.typeahead.min.css
[D 2019-08-24 20:49:41.301 SingleUserNotebookApp handlers:840] Path style/style.min.css served from /usr/local/lib/python3.6/dist-packages/notebook/static/style/style.min.css
[D 2019-08-24 20:49:41.301 SingleUserNotebookApp handlers:840] Path components/es6-promise/promise.min.js served from /usr/local/lib/python3.6/dist-packages/notebook/static/components/es6-promise/promise.min.js
[D 2019-08-24 20:49:41.302 SingleUserNotebookApp handlers:840] Path components/react/react.production.min.js served from /usr/local/lib/python3.6/dist-packages/notebook/static/components/react/react.production.min.js
[D 2019-08-24 20:49:41.302 SingleUserNotebookApp handlers:840] Path components/react/react-dom.production.min.js served from /usr/local/lib/python3.6/dist-packages/notebook/static/components/react/react-dom.production.min.js
[D 2019-08-24 20:49:41.302 SingleUserNotebookApp handlers:840] Path components/create-react-class/index.js served from /usr/local/lib/python3.6/dist-packages/notebook/static/components/create-react-class/index.js
[D 2019-08-24 20:49:41.302 SingleUserNotebookApp handlers:840] Path components/requirejs/require.js served from /usr/local/lib/python3.6/dist-packages/notebook/static/components/requirejs/require.js
[D 2019-08-24 20:49:41.303 SingleUserNotebookApp handlers:840] Path tree/js/main.min.js served from /usr/local/lib/python3.6/dist-packages/notebook/static/tree/js/main.min.js
[I 2019-08-24 20:49:41.307 SingleUserNotebookApp log:174] 200 GET /user/grader/tree? (grader@::ffff:128.205.245.21) 50.55ms
[D 2019-08-24 20:49:41.587 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[D 2019-08-24 20:49:41.588 SingleUserNotebookApp log:174] 200 GET /user/grader/static/components/jquery-typeahead/dist/jquery.typeahead.min.css?v=7afb461de36accb1aa133a1710f5bc56 (grader@::ffff:128.205.245.21) 1.56ms
[D 2019-08-24 20:49:41.589 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[D 2019-08-24 20:49:41.590 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[D 2019-08-24 20:49:41.590 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[D 2019-08-24 20:49:41.591 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[D 2019-08-24 20:49:41.592 SingleUserNotebookApp log:174] 200 GET /user/grader/static/components/react/react-dom.production.min.js?v=b14d91fb641317cda38dbc9dbf985ab4 (grader@::ffff:128.205.245.21) 3.26ms
[D 2019-08-24 20:49:41.592 SingleUserNotebookApp handlers:840] Path custom.css served from /usr/local/lib/python3.6/dist-packages/notebook/static/custom/custom.css
[D 2019-08-24 20:49:41.593 SingleUserNotebookApp log:174] 200 GET /user/grader/custom/custom.css (grader@::ffff:128.205.245.21) 3.44ms
[D 2019-08-24 20:49:41.594 SingleUserNotebookApp log:174] 200 GET /user/grader/static/components/create-react-class/index.js?v=94feb9971ce6d26211729abc43f96cd2 (grader@::ffff:128.205.245.21) 3.45ms
[D 2019-08-24 20:49:41.595 SingleUserNotebookApp log:174] 200 GET /user/grader/static/style/style.min.css?v=e91a43337d7c294cc9fab2938fa723b3 (grader@::ffff:128.205.245.21) 3.95ms
[D 2019-08-24 20:49:41.750 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[D 2019-08-24 20:49:41.751 SingleUserNotebookApp log:174] 200 GET /user/grader/static/components/jquery-ui/themes/smoothness/jquery-ui.min.css?v=3c2a865c832a1322285c55c6ed99abb2 (grader@::ffff:128.205.245.21) 1.13ms
[D 2019-08-24 20:49:41.773 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[D 2019-08-24 20:49:41.773 SingleUserNotebookApp log:174] 200 GET /user/grader/static/components/requirejs/require.js?v=951f856e81496aaeec2e71a1c2c0d51f (grader@::ffff:128.205.245.21) 1.17ms
[D 2019-08-24 20:49:41.789 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[D 2019-08-24 20:49:41.789 SingleUserNotebookApp log:174] 200 GET /user/grader/static/components/es6-promise/promise.min.js?v=f004a16cb856e0ff11781d01ec5ca8fe (grader@::ffff:128.205.245.21) 1.09ms
[D 2019-08-24 20:49:41.795 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[D 2019-08-24 20:49:41.796 SingleUserNotebookApp log:174] 200 GET /user/grader/static/components/react/react.production.min.js?v=34f96ffc962a7deecc83037ccb582b58 (grader@::ffff:128.205.245.21) 1.07ms
[D 2019-08-24 20:49:42.108 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[D 2019-08-24 20:49:42.110 SingleUserNotebookApp log:174] 200 GET /user/grader/static/tree/js/main.min.js?v=e508036c41e6650c0b55bd2ec1514535 (grader@::ffff:128.205.245.21) 2.67ms
[D 2019-08-24 20:49:44.360 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[D 2019-08-24 20:49:44.360 SingleUserNotebookApp handlers:840] Path services/contents.js served from /usr/local/lib/python3.6/dist-packages/notebook/static/services/contents.js
[D 2019-08-24 20:49:44.361 SingleUserNotebookApp log:174] 200 GET /user/grader/static/services/contents.js?v=20190824204939 (grader@::ffff:128.205.245.21) 1.46ms
[D 2019-08-24 20:49:44.596 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[D 2019-08-24 20:49:44.596 SingleUserNotebookApp handlers:840] Path components/font-awesome/fonts/fontawesome-webfont.woff2 served from /usr/local/lib/python3.6/dist-packages/notebook/static/components/font-awesome/fonts/fontawesome-webfont.woff2
[D 2019-08-24 20:49:44.597 SingleUserNotebookApp log:174] 200 GET /user/grader/static/components/font-awesome/fonts/fontawesome-webfont.woff2?v=4.7.0 (grader@::ffff:128.205.245.21) 1.36ms
[D 2019-08-24 20:49:44.611 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[D 2019-08-24 20:49:44.612 SingleUserNotebookApp config_manager:98] Paths used for configuration of tree: 
        /etc/jupyter/nbconfig/tree.json
[D 2019-08-24 20:49:44.612 SingleUserNotebookApp config_manager:98] Paths used for configuration of tree: 
        /usr/local/etc/jupyter/nbconfig/tree.json
[D 2019-08-24 20:49:44.612 SingleUserNotebookApp config_manager:98] Paths used for configuration of tree: 
        /usr/etc/jupyter/nbconfig/tree.json
[D 2019-08-24 20:49:44.613 SingleUserNotebookApp config_manager:98] Paths used for configuration of tree: 
        /home/grader/.jupyter/nbconfig/tree.json
[I 2019-08-24 20:49:44.613 SingleUserNotebookApp log:174] 200 GET /user/grader/api/config/tree?_=1566694184141 (grader@::ffff:128.205.245.21) 3.17ms
[D 2019-08-24 20:49:44.614 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[I 2019-08-24 20:49:44.615 SingleUserNotebookApp log:174] 200 GET /user/grader/api/terminals?_=1566694184145 (grader@::ffff:128.205.245.21) 0.88ms
[D 2019-08-24 20:49:44.700 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[D 2019-08-24 20:49:44.700 SingleUserNotebookApp kernelspec:169] Found kernel python3 in /usr/local/share/jupyter/kernels
[I 2019-08-24 20:49:44.702 SingleUserNotebookApp log:174] 200 GET /user/grader/api/kernelspecs (grader@::ffff:128.205.245.21) 3.13ms
[D 2019-08-24 20:49:44.778 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[I 2019-08-24 20:49:44.779 SingleUserNotebookApp log:174] 200 GET /user/grader/api/sessions?_=1566694184144 (grader@::ffff:128.205.245.21) 1.50ms
[D 2019-08-24 20:49:44.785 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[I 2019-08-24 20:49:44.786 SingleUserNotebookApp log:174] 200 GET /user/grader/api/terminals?_=1566694184143 (grader@::ffff:128.205.245.21) 0.85ms
[D 2019-08-24 20:49:44.787 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[D 2019-08-24 20:49:44.788 SingleUserNotebookApp handlers:840] Path custom.js served from /usr/local/lib/python3.6/dist-packages/notebook/static/custom/custom.js
[D 2019-08-24 20:49:44.788 SingleUserNotebookApp log:174] 200 GET /user/grader/custom/custom.js?v=20190824204939 (grader@::ffff:128.205.245.21) 1.40ms
[D 2019-08-24 20:49:44.878 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[I 2019-08-24 20:49:44.880 SingleUserNotebookApp log:174] 200 GET /user/grader/api/contents?type=directory&_=1566694184146 (grader@::ffff:128.205.245.21) 2.30ms
[D 2019-08-24 20:49:44.930 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[D 2019-08-24 20:49:44.930 SingleUserNotebookApp handlers:840] Path assignment_list/main.js served from /home/grader/.local/share/jupyter/nbextensions/assignment_list/main.js
[D 2019-08-24 20:49:44.931 SingleUserNotebookApp log:174] 200 GET /user/grader/nbextensions/assignment_list/main.js?v=20190824204939 (grader@::ffff:128.205.245.21) 1.29ms
[D 2019-08-24 20:49:44.973 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[D 2019-08-24 20:49:44.974 SingleUserNotebookApp config_manager:98] Paths used for configuration of common: 
        /etc/jupyter/nbconfig/common.json
[D 2019-08-24 20:49:44.974 SingleUserNotebookApp config_manager:98] Paths used for configuration of common: 
        /usr/local/etc/jupyter/nbconfig/common.json
[D 2019-08-24 20:49:44.975 SingleUserNotebookApp config_manager:98] Paths used for configuration of common: 
        /usr/etc/jupyter/nbconfig/common.json
[D 2019-08-24 20:49:44.975 SingleUserNotebookApp config_manager:98] Paths used for configuration of common: 
        /home/grader/.jupyter/nbconfig/common.json
[I 2019-08-24 20:49:44.976 SingleUserNotebookApp log:174] 200 GET /user/grader/api/config/common?_=1566694184142 (grader@::ffff:128.205.245.21) 2.70ms
[D 2019-08-24 20:49:44.977 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[D 2019-08-24 20:49:44.977 SingleUserNotebookApp handlers:840] Path formgrader/main.js served from /home/grader/.local/share/jupyter/nbextensions/formgrader/main.js
[D 2019-08-24 20:49:44.977 SingleUserNotebookApp log:174] 200 GET /user/grader/nbextensions/formgrader/main.js?v=20190824204939 (grader@::ffff:128.205.245.21) 1.33ms
[D 2019-08-24 20:49:45.023 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[D 2019-08-24 20:49:45.023 SingleUserNotebookApp handlers:840] Path course_list/main.js served from /home/grader/.local/share/jupyter/nbextensions/course_list/main.js
[D 2019-08-24 20:49:45.024 SingleUserNotebookApp log:174] 200 GET /user/grader/nbextensions/course_list/main.js?v=20190824204939 (grader@::ffff:128.205.245.21) 1.26ms
[D 2019-08-24 20:49:45.150 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[D 2019-08-24 20:49:45.150 SingleUserNotebookApp handlers:840] Path assignment_list/assignment_list.js served from /home/grader/.local/share/jupyter/nbextensions/assignment_list/assignment_list.js
[D 2019-08-24 20:49:45.151 SingleUserNotebookApp log:174] 200 GET /user/grader/nbextensions/assignment_list/assignment_list.js?v=20190824204939 (grader@::ffff:128.205.245.21) 1.21ms
[D 2019-08-24 20:49:45.282 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[D 2019-08-24 20:49:45.282 SingleUserNotebookApp handlers:840] Path assignment_list/assignment_list.css served from /home/grader/.local/share/jupyter/nbextensions/assignment_list/assignment_list.css
[D 2019-08-24 20:49:45.283 SingleUserNotebookApp log:174] 200 GET /user/grader/nbextensions/assignment_list/assignment_list.css (grader@::ffff:128.205.245.21) 1.18ms
[D 2019-08-24 20:49:45.429 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[D 2019-08-24 20:49:45.429 SingleUserNotebookApp handlers:840] Path course_list/course_list.js served from /home/grader/.local/share/jupyter/nbextensions/course_list/course_list.js
[D 2019-08-24 20:49:45.430 SingleUserNotebookApp log:174] 200 GET /user/grader/nbextensions/course_list/course_list.js?v=20190824204939 (grader@::ffff:128.205.245.21) 1.46ms
[D 2019-08-24 20:49:45.430 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[I 2019-08-24 20:49:45.431 SingleUserNotebookApp log:174] 200 GET /user/grader/nbgrader_version?version=0.6.0.dev&_=1566694184147 (grader@::ffff:128.205.245.21) 0.85ms
[D 2019-08-24 20:49:45.672 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[D 2019-08-24 20:49:45.672 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[D 2019-08-24 20:49:45.673 SingleUserNotebookApp handlers:840] Path course_list/course_list.css served from /home/grader/.local/share/jupyter/nbextensions/course_list/course_list.css
[D 2019-08-24 20:49:45.673 SingleUserNotebookApp log:174] 200 GET /user/grader/nbextensions/course_list/course_list.css (grader@::ffff:128.205.245.21) 1.91ms
[I 2019-08-24 20:49:45.674 SingleUserNotebookApp log:174] 200 GET /user/grader/nbgrader_version?version=0.6.0.dev&_=1566694184148 (grader@::ffff:128.205.245.21) 1.59ms
[D 2019-08-24 20:49:46.647 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[I 2019-08-24 20:49:46.650 SingleUserNotebookApp list:138] Released assignments:
[I 2019-08-24 20:49:46.650 SingleUserNotebookApp list:140] testcourse ps1
[I 2019-08-24 20:49:46.652 SingleUserNotebookApp list:138] Released assignments:
[I 2019-08-24 20:49:46.652 SingleUserNotebookApp list:140] testcourse ps1
[I 2019-08-24 20:49:46.654 SingleUserNotebookApp list:138] Released assignments:
[I 2019-08-24 20:49:46.654 SingleUserNotebookApp list:140] testcourse ps1
[I 2019-08-24 20:49:46.663 SingleUserNotebookApp log:174] 200 GET /user/grader/formgrader (grader@::ffff:128.205.245.21) 16.00ms
[D 2019-08-24 20:49:46.938 SingleUserNotebookApp log:174] 200 GET /user/grader/formgrader/static/components/bootstrap/js/bootstrap.min.js (@::ffff:128.205.245.21) 1.25ms
[D 2019-08-24 20:49:46.939 SingleUserNotebookApp log:174] 200 GET /user/grader/formgrader/static/components/datatables.net/js/jquery.dataTables.min.js (@::ffff:128.205.245.21) 2.06ms
[D 2019-08-24 20:49:46.941 SingleUserNotebookApp log:174] 200 GET /user/grader/formgrader/static/css/nbgrader.css (@::ffff:128.205.245.21) 0.84ms
[D 2019-08-24 20:49:47.091 SingleUserNotebookApp log:174] 200 GET /user/grader/formgrader/static/components/bootstrap/css/bootstrap.min.css (@::ffff:128.205.245.21) 1.16ms
[D 2019-08-24 20:49:47.190 SingleUserNotebookApp log:174] 200 GET /user/grader/formgrader/static/components/datatables.net-bs/css/dataTables.bootstrap.min.css (@::ffff:128.205.245.21) 0.77ms
[D 2019-08-24 20:49:47.235 SingleUserNotebookApp log:174] 200 GET /user/grader/formgrader/static/js/utils.js (@::ffff:128.205.245.21) 0.86ms
[D 2019-08-24 20:49:47.368 SingleUserNotebookApp log:174] 200 GET /user/grader/formgrader/static/components/jquery/jquery.min.js (@::ffff:128.205.245.21) 1.04ms
[D 2019-08-24 20:49:47.372 SingleUserNotebookApp log:174] 200 GET /user/grader/formgrader/static/components/underscore/underscore-min.js (@::ffff:128.205.245.21) 0.76ms
[D 2019-08-24 20:49:47.414 SingleUserNotebookApp log:174] 200 GET /user/grader/formgrader/static/components/backbone/backbone-min.js (@::ffff:128.205.245.21) 0.76ms
[D 2019-08-24 20:49:47.520 SingleUserNotebookApp log:174] 200 GET /user/grader/formgrader/static/components/datatables.net-bs/js/dataTables.bootstrap.min.js (@::ffff:128.205.245.21) 0.89ms
[D 2019-08-24 20:49:47.617 SingleUserNotebookApp log:174] 200 GET /user/grader/formgrader/static/js/backbone_xsrf.js (@::ffff:128.205.245.21) 0.87ms
[D 2019-08-24 20:49:47.663 SingleUserNotebookApp log:174] 200 GET /user/grader/formgrader/static/js/manage_assignments.js (@::ffff:128.205.245.21) 0.84ms
[D 2019-08-24 20:49:47.949 SingleUserNotebookApp log:174] 200 GET /user/grader/formgrader/static/components/bootstrap/fonts/glyphicons-halflings-regular.woff2 (@::ffff:128.205.245.21) 0.79ms
[D 2019-08-24 20:49:48.226 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[I 2019-08-24 20:49:48.228 SingleUserNotebookApp list:138] Released assignments:
[I 2019-08-24 20:49:48.228 SingleUserNotebookApp list:140] testcourse ps1
[I 2019-08-24 20:49:48.229 SingleUserNotebookApp list:138] Released assignments:
[I 2019-08-24 20:49:48.229 SingleUserNotebookApp list:140] testcourse ps1
[I 2019-08-24 20:49:48.282 SingleUserNotebookApp log:174] 200 GET /user/grader/formgrader/api/assignments (grader@::ffff:128.205.245.21) 56.44ms
[D 2019-08-24 20:49:51.237 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user grader
[I 2019-08-24 20:49:51.237 SingleUserNotebookApp log:174] 302 GET /user/grader/logout -> /hub/logout (grader@::ffff:128.205.245.21) 1.12ms
[I 2019-08-24 20:49:51.617 JupyterHub login:43] User logged out: grader
[D 2019-08-24 20:49:51.628 JupyterHub base:444] Deleted 1 access tokens for grader
[I 2019-08-24 20:49:51.638 JupyterHub log:174] 302 GET /hub/logout -> /hub/login (grader@::ffff:128.205.245.21) 32.66ms
[I 2019-08-24 20:49:54.374 JupyterHub log:174] 200 GET /hub/login (@::ffff:128.205.245.21) 24.10ms
[D 2019-08-24 20:49:54.620 JupyterHub log:174] 200 GET /hub/static/css/style.min.css?v=883a1cf654bd9f5cdc5ca7c91efe7d71 (@::ffff:128.205.245.21) 1.89ms
[D 2019-08-24 20:49:54.672 JupyterHub log:174] 200 GET /hub/static/components/requirejs/require.js?v=f0cc8bbb2fcef87fc194fecbb632fcfa (@::ffff:128.205.245.21) 2.15ms
[D 2019-08-24 20:49:54.672 JupyterHub log:174] 200 GET /hub/static/components/bootstrap/dist/js/bootstrap.min.js?v=2f34b630ffe30ba2ff2b91e3f3c322a1 (@::ffff:128.205.245.21) 2.28ms
[D 2019-08-24 20:49:54.674 JupyterHub log:174] 200 GET /hub/static/components/jquery/dist/jquery.min.js?v=220afd743d9e9643852e31a135a9f3ae (@::ffff:128.205.245.21) 3.94ms
[D 2019-08-24 20:49:54.675 JupyterHub log:174] 200 GET /hub/logo (@::ffff:128.205.245.21) 4.15ms
[D 2019-08-24 20:50:03.623 JupyterHub base:482] Setting cookie for instructor1: jupyterhub-services
[D 2019-08-24 20:50:03.623 JupyterHub base:478] Setting cookie jupyterhub-services: {'httponly': True, 'secure': True, 'path': '/services'}
[D 2019-08-24 20:50:03.623 JupyterHub base:478] Setting cookie jupyterhub-session-id: {'httponly': True, 'secure': True}
[D 2019-08-24 20:50:03.623 JupyterHub base:482] Setting cookie for instructor1: jupyterhub-hub-login
[D 2019-08-24 20:50:03.623 JupyterHub base:478] Setting cookie jupyterhub-hub-login: {'httponly': True, 'secure': True, 'path': '/hub/'}
[I 2019-08-24 20:50:03.623 JupyterHub base:663] User logged in: instructor1
[D 2019-08-24 20:50:03.623 JupyterHub user:240] Creating <class 'jupyterhub.spawner.LocalProcessSpawner'> for instructor1:
[I 2019-08-24 20:50:03.625 JupyterHub log:174] 302 POST /hub/login?next= -> /hub/spawn (instructor1@::ffff:128.205.245.21) 19.76ms
[D 2019-08-24 20:50:03.916 JupyterHub pages:165] Triggering spawn with default options for instructor1
[D 2019-08-24 20:50:03.916 JupyterHub base:780] Initiating spawn for instructor1
[D 2019-08-24 20:50:03.916 JupyterHub base:787] 0/100 concurrent spawns
[D 2019-08-24 20:50:03.916 JupyterHub base:792] 1 active servers
[D 2019-08-24 20:50:03.956 JupyterHub user:542] Calling Spawner.start for instructor1
[I 2019-08-24 20:50:03.957 JupyterHub spawner:1387] Spawning jupyterhub-singleuser --port=51833 --debug
[D 2019-08-24 20:50:03.971 JupyterHub spawner:1084] Polling subprocess every 30s
[D 2019-08-24 20:50:04.327 SingleUserNotebookApp application:177] Searching ['/home/instructor1', '/home/instructor1/.jupyter', '/usr/etc/jupyter', '/usr/local/etc/jupyter', '/etc/jupyter'] for config files
[D 2019-08-24 20:50:04.327 SingleUserNotebookApp application:555] Looking for jupyter_config in /etc/jupyter
[D 2019-08-24 20:50:04.328 SingleUserNotebookApp application:555] Looking for jupyter_config in /usr/local/etc/jupyter
[D 2019-08-24 20:50:04.328 SingleUserNotebookApp application:555] Looking for jupyter_config in /usr/etc/jupyter
[D 2019-08-24 20:50:04.328 SingleUserNotebookApp application:555] Looking for jupyter_config in /home/instructor1/.jupyter
[D 2019-08-24 20:50:04.328 SingleUserNotebookApp application:555] Looking for jupyter_config in /home/instructor1
[D 2019-08-24 20:50:04.329 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /etc/jupyter
[D 2019-08-24 20:50:04.329 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /usr/local/etc/jupyter
[D 2019-08-24 20:50:04.329 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /usr/etc/jupyter
[D 2019-08-24 20:50:04.329 SingleUserNotebookApp application:577] Loaded config file: /usr/etc/jupyter/jupyter_notebook_config.json
[D 2019-08-24 20:50:04.329 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /home/instructor1/.jupyter
[D 2019-08-24 20:50:04.329 SingleUserNotebookApp application:577] Loaded config file: /home/instructor1/.jupyter/jupyter_notebook_config.json
[D 2019-08-24 20:50:04.329 SingleUserNotebookApp application:555] Looking for jupyter_notebook_config in /home/instructor1
[D 2019-08-24 20:50:04.334 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /etc/jupyter/jupyter_notebook_config.json
[D 2019-08-24 20:50:04.335 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /usr/local/etc/jupyter/jupyter_notebook_config.json
[D 2019-08-24 20:50:04.335 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /usr/etc/jupyter/jupyter_notebook_config.json
[D 2019-08-24 20:50:04.336 SingleUserNotebookApp config_manager:98] Paths used for configuration of jupyter_notebook_config: 
        /home/instructor1/.jupyter/jupyter_notebook_config.json
[I 2019-08-24 20:50:04.827 SingleUserNotebookApp handlers:337] Loading the assignment_list nbgrader serverextension
[I 2019-08-24 20:50:04.830 SingleUserNotebookApp handlers:234] Loading the course_list nbgrader serverextension
[I 2019-08-24 20:50:04.832 SingleUserNotebookApp formgrader:84] Loading the formgrader nbgrader serverextension
[D 2019-08-24 20:50:04.835 SingleUserNotebookApp application:177] Searching ['/home/instructor1', '/home/instructor1/.jupyter', '/usr/etc/jupyter', '/usr/local/etc/jupyter', '/etc/jupyter'] for config files
[D 2019-08-24 20:50:04.836 SingleUserNotebookApp application:555] Looking for jupyter_config in /etc/jupyter
[D 2019-08-24 20:50:04.836 SingleUserNotebookApp application:555] Looking for jupyter_config in /usr/local/etc/jupyter
[D 2019-08-24 20:50:04.836 SingleUserNotebookApp application:555] Looking for jupyter_config in /usr/etc/jupyter
[D 2019-08-24 20:50:04.836 SingleUserNotebookApp application:555] Looking for jupyter_config in /home/instructor1/.jupyter
[D 2019-08-24 20:50:04.836 SingleUserNotebookApp application:555] Looking for jupyter_config in /home/instructor1
[D 2019-08-24 20:50:04.837 SingleUserNotebookApp application:555] Looking for nbgrader_config in /etc/jupyter
[D 2019-08-24 20:50:04.837 SingleUserNotebookApp application:577] Loaded config file: /etc/jupyter/nbgrader_config.py
[D 2019-08-24 20:50:04.837 SingleUserNotebookApp application:555] Looking for nbgrader_config in /usr/local/etc/jupyter
[D 2019-08-24 20:50:04.837 SingleUserNotebookApp application:555] Looking for nbgrader_config in /usr/etc/jupyter
[D 2019-08-24 20:50:04.838 SingleUserNotebookApp application:555] Looking for nbgrader_config in /home/instructor1/.jupyter
[D 2019-08-24 20:50:04.838 SingleUserNotebookApp application:555] Looking for nbgrader_config in /home/instructor1
[W 2019-08-24 20:50:04.838 SingleUserNotebookApp configurable:168] Config option `log` not recognized by `FormgradeExtension`.  Did you mean `logfile`?
[W 2019-08-24 20:50:04.839 SingleUserNotebookApp coursedir:258] root '/home/grader/testcourse/' is not absolute, standardizing it to '/home/grader/testcourse
[D 2019-08-24 20:50:04.839 SingleUserNotebookApp application:555] Looking for nbgrader_config in /home/grader/testcourse
[D 2019-08-24 20:50:04.840 SingleUserNotebookApp application:577] Loaded config file: /home/grader/testcourse/nbgrader_config.py
[E 2019-08-24 20:50:04.840 SingleUserNotebookApp formgrader:45] The course directory root is not a subdirectory of the notebook server root. This means that nbgrader will not work correctly. If you want to use nbgrader, please ensure the course directory root is in a subdirectory of the notebook root: /home/instructor1
[I 2019-08-24 20:50:04.852 SingleUserNotebookApp handlers:137] Loading the validate_assignment nbgrader serverextension
[I 2019-08-24 20:50:04.853 SingleUserNotebookApp singleuser:561] Starting jupyterhub-singleuser server version 1.0.0
[I 2019-08-24 20:50:04.856 JupyterHub log:174] 200 GET /hub/api (@127.0.0.1) 1.20ms
[D 2019-08-24 20:50:04.857 SingleUserNotebookApp _version:60] jupyterhub and jupyterhub-singleuser both on version 1.0.0
[I 2019-08-24 20:50:04.857 SingleUserNotebookApp notebookapp:1825] Serving notebooks from local directory: /home/instructor1
[I 2019-08-24 20:50:04.857 SingleUserNotebookApp notebookapp:1825] The Jupyter Notebook is running at:
[I 2019-08-24 20:50:04.857 SingleUserNotebookApp notebookapp:1825] http://127.0.0.1:51833/user/instructor1/
[I 2019-08-24 20:50:04.857 SingleUserNotebookApp notebookapp:1826] Use Control-C to stop this server and shut down all kernels (twice to skip confirmation).
[I 2019-08-24 20:50:04.861 SingleUserNotebookApp singleuser:542] Updating Hub with activity every 300 seconds
[D 2019-08-24 20:50:04.862 SingleUserNotebookApp singleuser:503] Notifying Hub of activity 2019-08-25T00:50:04.338523Z
[D 2019-08-24 20:50:04.878 JupyterHub users:708] Activity for user instructor1: 2019-08-25T00:50:04.338523Z
[D 2019-08-24 20:50:04.878 JupyterHub users:729] Activity on server instructor1/: 2019-08-25T00:50:04.338523Z
[I 2019-08-24 20:50:04.886 JupyterHub log:174] 200 POST /hub/api/users/instructor1/activity (instructor1@127.0.0.1) 23.35ms
[I 2019-08-24 20:50:04.889 SingleUserNotebookApp log:174] 302 GET /user/instructor1/ -> /user/instructor1/tree? (@127.0.0.1) 0.70ms
[D 2019-08-24 20:50:04.889 JupyterHub utils:218] Server at http://127.0.0.1:51833/user/instructor1/ responded with 302
[D 2019-08-24 20:50:04.889 JupyterHub _version:60] jupyterhub and jupyterhub-singleuser both on version 1.0.0
[I 2019-08-24 20:50:04.889 JupyterHub base:810] User instructor1 took 0.973 seconds to start
[I 2019-08-24 20:50:04.889 JupyterHub proxy:261] Adding user instructor1 to proxy /user/instructor1/ => http://127.0.0.1:51833
[D 2019-08-24 20:50:04.889 JupyterHub proxy:765] Proxy: Fetching POST http://127.0.0.1:8001/api/routes/user/instructor1
20:50:04.891 [ConfigProxy] info: Adding route /user/instructor1 -> http://127.0.0.1:51833
20:50:04.891 [ConfigProxy] info: Route added /user/instructor1 -> http://127.0.0.1:51833
20:50:04.891 [ConfigProxy] info: 201 POST /api/routes/user/instructor1 
[I 2019-08-24 20:50:04.892 JupyterHub log:174] 302 GET /hub/spawn -> /hub/spawn-pending/instructor1 (instructor1@::ffff:128.205.245.21) 986.00ms
[I 2019-08-24 20:50:05.586 JupyterHub log:174] 302 GET /hub/spawn-pending/instructor1 -> /user/instructor1/ (instructor1@::ffff:128.205.245.21) 10.04ms
[I 2019-08-24 20:50:05.880 SingleUserNotebookApp log:174] 302 GET /user/instructor1/ -> /user/instructor1/tree? (@::ffff:128.205.245.21) 0.69ms
[D 2019-08-24 20:50:06.134 SingleUserNotebookApp auth:501] No user identified
[D 2019-08-24 20:50:06.135 SingleUserNotebookApp auth:832] Redirecting to login url: /hub/api/oauth2/authorize?client_id=jupyterhub-user-instructor1&redirect_uri=%2Fuser%2Finstructor1%2Foauth_callback&response_type=code&state=eyJ1dWlkIjogIjJkMDgxMzI3ZTA5ZDQ3Y2E4OWY0NDk4ZjMwZDU3ODZmIiwgIm5leHRfdXJsIjogIi91c2VyL2luc3RydWN0b3IxL3RyZWU_In0
[I 2019-08-24 20:50:06.136 SingleUserNotebookApp log:174] 302 GET /user/instructor1/tree? -> /hub/api/oauth2/authorize?client_id=jupyterhub-user-instructor1&redirect_uri=%2Fuser%2Finstructor1%2Foauth_callback&response_type=code&state=[secret] (@::ffff:128.205.245.21) 1.93ms
[D 2019-08-24 20:50:06.383 JupyterHub provider:414] Validating client id jupyterhub-user-instructor1
[D 2019-08-24 20:50:06.385 JupyterHub provider:492] validate_redirect_uri: client_id=jupyterhub-user-instructor1, redirect_uri=/user/instructor1/oauth_callback
[D 2019-08-24 20:50:06.386 JupyterHub auth:222] Skipping oauth confirmation for <User(instructor1 1/1 running)> accessing Server at /user/instructor1/
[D 2019-08-24 20:50:06.387 JupyterHub provider:414] Validating client id jupyterhub-user-instructor1
[D 2019-08-24 20:50:06.387 JupyterHub provider:492] validate_redirect_uri: client_id=jupyterhub-user-instructor1, redirect_uri=/user/instructor1/oauth_callback
[D 2019-08-24 20:50:06.388 JupyterHub provider:241] Saving authorization code jupyterhub-user-instructor1, uUQ..., (), {}
[I 2019-08-24 20:50:06.401 JupyterHub log:174] 302 GET /hub/api/oauth2/authorize?client_id=jupyterhub-user-instructor1&redirect_uri=%2Fuser%2Finstructor1%2Foauth_callback&response_type=code&state=[secret] -> /user/instructor1/oauth_callback?code=[secret]&state=[secret] (instructor1@::ffff:128.205.245.21) 28.03ms
[D 2019-08-24 20:50:06.637 SingleUserNotebookApp auth:501] No user identified
[D 2019-08-24 20:50:06.650 JupyterHub provider:60] authenticate_client <oauthlib.Request SANITIZED>
[D 2019-08-24 20:50:06.655 JupyterHub provider:119] confirm_redirect_uri: client_id=jupyterhub-user-instructor1, redirect_uri=/user/instructor1/oauth_callback
[D 2019-08-24 20:50:06.655 JupyterHub provider:339] Saving bearer token {'access_token': 'REDACTED', 'expires_in': 3600, 'token_type': 'Bearer', 'scope': 'identify', 'refresh_token': 'REDACTED'}
[D 2019-08-24 20:50:06.704 JupyterHub provider:194] Deleting oauth code uUQ... for jupyterhub-user-instructor1
[I 2019-08-24 20:50:06.730 JupyterHub log:174] 200 POST /hub/api/oauth2/token (instructor1@127.0.0.1) 89.11ms
[D 2019-08-24 20:50:06.731 SingleUserNotebookApp auth:310] HubAuth cache miss: token:b37fe457ffb7495e846bc3a106a39de7:sru4QYHKnwZT9GXYaYGOMPhiPqm35l
[D 2019-08-24 20:50:06.759 SingleUserNotebookApp auth:316] Received request from Hub user {'kind': 'user', 'name': 'instructor1', 'admin': False, 'groups': ['instructors'], 'server': '/user/instructor1/', 'pending': None, 'created': '2019-08-25T00:41:50.069660Z', 'last_activity': '2019-08-25T00:50:06.751695Z', 'servers': None}
[I 2019-08-24 20:50:06.759 SingleUserNotebookApp auth:981] Logged-in user {'kind': 'user', 'name': 'instructor1', 'admin': False, 'groups': ['instructors'], 'server': '/user/instructor1/', 'pending': None, 'created': '2019-08-25T00:41:50.069660Z', 'last_activity': '2019-08-25T00:50:06.751695Z', 'servers': None}
[D 2019-08-24 20:50:06.759 SingleUserNotebookApp auth:744] Setting oauth cookie for ::ffff:128.205.245.21: jupyterhub-user-instructor1, {'path': '/user/instructor1/', 'httponly': True, 'secure': True}
[I 2019-08-24 20:50:06.760 SingleUserNotebookApp log:174] 302 GET /user/instructor1/oauth_callback?code=[secret]&state=[secret] -> /user/instructor1/tree? (@::ffff:128.205.245.21) 122.68ms
[I 2019-08-24 20:50:06.761 JupyterHub log:174] 200 GET /hub/api/authorizations/token/[secret] (instructor1@127.0.0.1) 28.67ms
[D 2019-08-24 20:50:06.984 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-24 20:50:06.985 SingleUserNotebookApp handlers:260] Using contents: services/contents
[D 2019-08-24 20:50:07.025 SingleUserNotebookApp handlers:840] Path base/images/favicon.ico served from /usr/local/lib/python3.6/dist-packages/notebook/static/base/images/favicon.ico
[D 2019-08-24 20:50:07.025 SingleUserNotebookApp handlers:840] Path components/jquery-ui/themes/smoothness/jquery-ui.min.css served from /usr/local/lib/python3.6/dist-packages/notebook/static/components/jquery-ui/themes/smoothness/jquery-ui.min.css
[D 2019-08-24 20:50:07.025 SingleUserNotebookApp handlers:840] Path components/jquery-typeahead/dist/jquery.typeahead.min.css served from /usr/local/lib/python3.6/dist-packages/notebook/static/components/jquery-typeahead/dist/jquery.typeahead.min.css
[D 2019-08-24 20:50:07.025 SingleUserNotebookApp handlers:840] Path style/style.min.css served from /usr/local/lib/python3.6/dist-packages/notebook/static/style/style.min.css
[D 2019-08-24 20:50:07.026 SingleUserNotebookApp handlers:840] Path components/es6-promise/promise.min.js served from /usr/local/lib/python3.6/dist-packages/notebook/static/components/es6-promise/promise.min.js
[D 2019-08-24 20:50:07.026 SingleUserNotebookApp handlers:840] Path components/react/react.production.min.js served from /usr/local/lib/python3.6/dist-packages/notebook/static/components/react/react.production.min.js
[D 2019-08-24 20:50:07.026 SingleUserNotebookApp handlers:840] Path components/react/react-dom.production.min.js served from /usr/local/lib/python3.6/dist-packages/notebook/static/components/react/react-dom.production.min.js
[D 2019-08-24 20:50:07.027 SingleUserNotebookApp handlers:840] Path components/create-react-class/index.js served from /usr/local/lib/python3.6/dist-packages/notebook/static/components/create-react-class/index.js
[D 2019-08-24 20:50:07.027 SingleUserNotebookApp handlers:840] Path components/requirejs/require.js served from /usr/local/lib/python3.6/dist-packages/notebook/static/components/requirejs/require.js
[D 2019-08-24 20:50:07.028 SingleUserNotebookApp handlers:840] Path tree/js/main.min.js served from /usr/local/lib/python3.6/dist-packages/notebook/static/tree/js/main.min.js
[I 2019-08-24 20:50:07.031 SingleUserNotebookApp log:174] 200 GET /user/instructor1/tree? (instructor1@::ffff:128.205.245.21) 47.63ms
[D 2019-08-24 20:50:07.324 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-24 20:50:07.324 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-24 20:50:07.325 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-24 20:50:07.326 SingleUserNotebookApp log:174] 200 GET /user/instructor1/static/components/jquery-typeahead/dist/jquery.typeahead.min.css?v=7afb461de36accb1aa133a1710f5bc56 (instructor1@::ffff:128.205.245.21) 3.04ms
[D 2019-08-24 20:50:07.327 SingleUserNotebookApp log:174] 200 GET /user/instructor1/static/style/style.min.css?v=e91a43337d7c294cc9fab2938fa723b3 (instructor1@::ffff:128.205.245.21) 3.20ms
[D 2019-08-24 20:50:07.327 SingleUserNotebookApp handlers:840] Path custom.css served from /usr/local/lib/python3.6/dist-packages/notebook/static/custom/custom.css
[D 2019-08-24 20:50:07.328 SingleUserNotebookApp log:174] 200 GET /user/instructor1/custom/custom.css (instructor1@::ffff:128.205.245.21) 3.09ms
[D 2019-08-24 20:50:07.424 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-24 20:50:07.425 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-24 20:50:07.426 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-24 20:50:07.427 SingleUserNotebookApp log:174] 200 GET /user/instructor1/static/components/jquery-ui/themes/smoothness/jquery-ui.min.css?v=3c2a865c832a1322285c55c6ed99abb2 (instructor1@::ffff:128.205.245.21) 2.63ms
[D 2019-08-24 20:50:07.427 SingleUserNotebookApp log:174] 200 GET /user/instructor1/static/components/es6-promise/promise.min.js?v=f004a16cb856e0ff11781d01ec5ca8fe (instructor1@::ffff:128.205.245.21) 2.46ms
[D 2019-08-24 20:50:07.428 SingleUserNotebookApp log:174] 200 GET /user/instructor1/static/components/react/react.production.min.js?v=34f96ffc962a7deecc83037ccb582b58 (instructor1@::ffff:128.205.245.21) 2.34ms
[D 2019-08-24 20:50:07.467 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-24 20:50:07.468 SingleUserNotebookApp log:174] 200 GET /user/instructor1/static/components/react/react-dom.production.min.js?v=b14d91fb641317cda38dbc9dbf985ab4 (instructor1@::ffff:128.205.245.21) 1.16ms
[D 2019-08-24 20:50:07.552 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-24 20:50:07.553 SingleUserNotebookApp log:174] 200 GET /user/instructor1/static/components/create-react-class/index.js?v=94feb9971ce6d26211729abc43f96cd2 (instructor1@::ffff:128.205.245.21) 1.71ms
[D 2019-08-24 20:50:07.746 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-24 20:50:07.747 SingleUserNotebookApp log:174] 200 GET /user/instructor1/static/components/requirejs/require.js?v=951f856e81496aaeec2e71a1c2c0d51f (instructor1@::ffff:128.205.245.21) 1.18ms
[D 2019-08-24 20:50:07.832 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-24 20:50:07.834 SingleUserNotebookApp log:174] 200 GET /user/instructor1/static/tree/js/main.min.js?v=e508036c41e6650c0b55bd2ec1514535 (instructor1@::ffff:128.205.245.21) 2.21ms
[D 2019-08-24 20:50:10.588 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-24 20:50:10.589 SingleUserNotebookApp handlers:840] Path services/contents.js served from /usr/local/lib/python3.6/dist-packages/notebook/static/services/contents.js
[D 2019-08-24 20:50:10.589 SingleUserNotebookApp log:174] 200 GET /user/instructor1/static/services/contents.js?v=20190824205004 (instructor1@::ffff:128.205.245.21) 1.25ms
[D 2019-08-24 20:50:10.834 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-24 20:50:10.834 SingleUserNotebookApp kernelspec:169] Found kernel python3 in /usr/local/share/jupyter/kernels
[I 2019-08-24 20:50:10.837 SingleUserNotebookApp log:174] 200 GET /user/instructor1/api/kernelspecs (instructor1@::ffff:128.205.245.21) 3.12ms
[D 2019-08-24 20:50:10.841 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-24 20:50:10.841 SingleUserNotebookApp handlers:840] Path components/font-awesome/fonts/fontawesome-webfont.woff2 served from /usr/local/lib/python3.6/dist-packages/notebook/static/components/font-awesome/fonts/fontawesome-webfont.woff2
[D 2019-08-24 20:50:10.842 SingleUserNotebookApp log:174] 200 GET /user/instructor1/static/components/font-awesome/fonts/fontawesome-webfont.woff2?v=4.7.0 (instructor1@::ffff:128.205.245.21) 1.21ms
[D 2019-08-24 20:50:10.844 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[I 2019-08-24 20:50:10.845 SingleUserNotebookApp log:174] 200 GET /user/instructor1/api/sessions?_=1566694210378 (instructor1@::ffff:128.205.245.21) 1.36ms
[D 2019-08-24 20:50:10.930 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[I 2019-08-24 20:50:10.930 SingleUserNotebookApp log:174] 200 GET /user/instructor1/api/terminals?_=1566694210377 (instructor1@::ffff:128.205.245.21) 0.78ms
[D 2019-08-24 20:50:10.931 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[I 2019-08-24 20:50:10.932 SingleUserNotebookApp log:174] 200 GET /user/instructor1/api/terminals?_=1566694210379 (instructor1@::ffff:128.205.245.21) 0.77ms
[D 2019-08-24 20:50:10.974 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-24 20:50:10.974 SingleUserNotebookApp config_manager:98] Paths used for configuration of tree: 
        /etc/jupyter/nbconfig/tree.json
[D 2019-08-24 20:50:10.975 SingleUserNotebookApp config_manager:98] Paths used for configuration of tree: 
        /usr/local/etc/jupyter/nbconfig/tree.json
[D 2019-08-24 20:50:10.975 SingleUserNotebookApp config_manager:98] Paths used for configuration of tree: 
        /usr/etc/jupyter/nbconfig/tree.json
[D 2019-08-24 20:50:10.976 SingleUserNotebookApp config_manager:98] Paths used for configuration of tree: 
        /home/instructor1/.jupyter/nbconfig/tree.json
[I 2019-08-24 20:50:10.976 SingleUserNotebookApp log:174] 200 GET /user/instructor1/api/config/tree?_=1566694210375 (instructor1@::ffff:128.205.245.21) 2.69ms
[D 2019-08-24 20:50:11.016 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-24 20:50:11.016 SingleUserNotebookApp config_manager:98] Paths used for configuration of common: 
        /etc/jupyter/nbconfig/common.json
[D 2019-08-24 20:50:11.017 SingleUserNotebookApp config_manager:98] Paths used for configuration of common: 
        /usr/local/etc/jupyter/nbconfig/common.json
[D 2019-08-24 20:50:11.017 SingleUserNotebookApp config_manager:98] Paths used for configuration of common: 
        /usr/etc/jupyter/nbconfig/common.json
[D 2019-08-24 20:50:11.017 SingleUserNotebookApp config_manager:98] Paths used for configuration of common: 
        /home/instructor1/.jupyter/nbconfig/common.json
[I 2019-08-24 20:50:11.018 SingleUserNotebookApp log:174] 200 GET /user/instructor1/api/config/common?_=1566694210376 (instructor1@::ffff:128.205.245.21) 2.52ms
[D 2019-08-24 20:50:11.099 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[I 2019-08-24 20:50:11.100 SingleUserNotebookApp log:174] 200 GET /user/instructor1/api/contents?type=directory&_=1566694210380 (instructor1@::ffff:128.205.245.21) 1.91ms
[D 2019-08-24 20:50:11.160 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-24 20:50:11.160 SingleUserNotebookApp handlers:840] Path course_list/main.js served from /home/instructor1/.local/share/jupyter/nbextensions/course_list/main.js
[D 2019-08-24 20:50:11.161 SingleUserNotebookApp log:174] 200 GET /user/instructor1/nbextensions/course_list/main.js?v=20190824205004 (instructor1@::ffff:128.205.245.21) 1.27ms
[D 2019-08-24 20:50:11.199 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-24 20:50:11.200 SingleUserNotebookApp handlers:840] Path custom.js served from /usr/local/lib/python3.6/dist-packages/notebook/static/custom/custom.js
[D 2019-08-24 20:50:11.200 SingleUserNotebookApp log:174] 200 GET /user/instructor1/custom/custom.js?v=20190824205004 (instructor1@::ffff:128.205.245.21) 1.25ms
[D 2019-08-24 20:50:11.213 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-24 20:50:11.213 SingleUserNotebookApp handlers:840] Path assignment_list/main.js served from /home/instructor1/.local/share/jupyter/nbextensions/assignment_list/main.js
[D 2019-08-24 20:50:11.214 SingleUserNotebookApp log:174] 200 GET /user/instructor1/nbextensions/assignment_list/main.js?v=20190824205004 (instructor1@::ffff:128.205.245.21) 1.25ms
[D 2019-08-24 20:50:11.238 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-24 20:50:11.238 SingleUserNotebookApp handlers:840] Path formgrader/main.js served from /home/instructor1/.local/share/jupyter/nbextensions/formgrader/main.js
[D 2019-08-24 20:50:11.238 SingleUserNotebookApp log:174] 200 GET /user/instructor1/nbextensions/formgrader/main.js?v=20190824205004 (instructor1@::ffff:128.205.245.21) 1.12ms
[D 2019-08-24 20:50:11.375 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-24 20:50:11.376 SingleUserNotebookApp handlers:840] Path course_list/course_list.js served from /home/instructor1/.local/share/jupyter/nbextensions/course_list/course_list.js
[D 2019-08-24 20:50:11.376 SingleUserNotebookApp log:174] 200 GET /user/instructor1/nbextensions/course_list/course_list.js?v=20190824205004 (instructor1@::ffff:128.205.245.21) 1.27ms
[D 2019-08-24 20:50:11.439 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-24 20:50:11.439 SingleUserNotebookApp handlers:840] Path course_list/course_list.css served from /home/instructor1/.local/share/jupyter/nbextensions/course_list/course_list.css
[D 2019-08-24 20:50:11.440 SingleUserNotebookApp log:174] 200 GET /user/instructor1/nbextensions/course_list/course_list.css (instructor1@::ffff:128.205.245.21) 1.05ms
[D 2019-08-24 20:50:11.601 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-24 20:50:11.602 SingleUserNotebookApp handlers:840] Path assignment_list/assignment_list.js served from /home/instructor1/.local/share/jupyter/nbextensions/assignment_list/assignment_list.js
[D 2019-08-24 20:50:11.602 SingleUserNotebookApp log:174] 200 GET /user/instructor1/nbextensions/assignment_list/assignment_list.js?v=20190824205004 (instructor1@::ffff:128.205.245.21) 1.20ms
[D 2019-08-24 20:50:11.603 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[I 2019-08-24 20:50:11.604 SingleUserNotebookApp log:174] 200 GET /user/instructor1/nbgrader_version?version=0.6.0.dev&_=1566694210381 (instructor1@::ffff:128.205.245.21) 0.84ms
[D 2019-08-24 20:50:11.901 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[D 2019-08-24 20:50:11.902 SingleUserNotebookApp handlers:840] Path assignment_list/assignment_list.css served from /home/instructor1/.local/share/jupyter/nbextensions/assignment_list/assignment_list.css
[D 2019-08-24 20:50:11.902 SingleUserNotebookApp log:174] 200 GET /user/instructor1/nbextensions/assignment_list/assignment_list.css (instructor1@::ffff:128.205.245.21) 1.13ms
[D 2019-08-24 20:50:11.906 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[I 2019-08-24 20:50:11.906 SingleUserNotebookApp log:174] 200 GET /user/instructor1/nbgrader_version?version=0.6.0.dev&_=1566694210382 (instructor1@::ffff:128.205.245.21) 0.79ms
[D 2019-08-24 20:50:12.414 SingleUserNotebookApp auth:871] Allowing whitelisted Hub user instructor1
[I 2019-08-24 20:50:12.421 SingleUserNotebookApp log:174] 200 GET /user/instructor1/formgrader (instructor1@::ffff:128.205.245.21) 7.16ms
[D 2019-08-24 20:50:12.698 SingleUserNotebookApp log:174] 200 GET /user/instructor1/formgrader/static/components/bootstrap/js/bootstrap.min.js (@::ffff:128.205.245.21) 0.86ms
[D 2019-08-24 20:50:12.699 SingleUserNotebookApp log:174] 200 GET /user/instructor1/formgrader/static/components/datatables.net-bs/css/dataTables.bootstrap.min.css (@::ffff:128.205.245.21) 0.74ms
[D 2019-08-24 20:50:12.701 SingleUserNotebookApp log:174] 200 GET /user/instructor1/formgrader/static/components/backbone/backbone-min.js (@::ffff:128.205.245.21) 0.79ms
[D 2019-08-24 20:50:12.780 SingleUserNotebookApp log:174] 200 GET /user/instructor1/formgrader/static/css/nbgrader.css (@::ffff:128.205.245.21) 0.74ms
[D 2019-08-24 20:50:12.947 SingleUserNotebookApp log:174] 200 GET /user/instructor1/formgrader/static/components/bootstrap/css/bootstrap.min.css (@::ffff:128.205.245.21) 1.24ms
[D 2019-08-24 20:50:13.021 SingleUserNotebookApp log:174] 200 GET /user/instructor1/formgrader/static/js/utils.js (@::ffff:128.205.245.21) 0.76ms
[D 2019-08-24 20:50:13.022 SingleUserNotebookApp log:174] 200 GET /user/instructor1/formgrader/static/components/jquery/jquery.min.js (@::ffff:128.205.245.21) 0.97ms
[D 2019-08-24 20:50:13.024 SingleUserNotebookApp log:174] 200 GET /user/instructor1/formgrader/static/components/underscore/underscore-min.js (@::ffff:128.205.245.21) 0.75ms
[D 2019-08-24 20:50:13.064 SingleUserNotebookApp log:174] 200 GET /user/instructor1/formgrader/static/components/datatables.net-bs/js/dataTables.bootstrap.min.js (@::ffff:128.205.245.21) 0.74ms
[D 2019-08-24 20:50:13.192 SingleUserNotebookApp log:174] 200 GET /user/instructor1/formgrader/static/js/backbone_xsrf.js (@::ffff:128.205.245.21) 0.77ms
[D 2019-08-24 20:50:13.270 SingleUserNotebookApp log:174] 200 GET /user/instructor1/formgrader/static/components/datatables.net/js/jquery.dataTables.min.js (@::ffff:128.205.245.21) 1.04ms
[C 2019-08-24 20:50:17.988 JupyterHub app:2448] Received signal SIGINT, initiating shutdown...
[D 2019-08-24 20:50:17.988 JupyterHub app:2454] Cancelling pending tasks
[D 2019-08-24 20:50:17.988 JupyterHub app:2466] Task status: <Task pending coro=<JupyterHub.shutdown_cancel_tasks() running at /usr/local/lib/python3.6/dist-packages/jupyterhub/app.py:2466>>
[D 2019-08-24 20:50:17.989 JupyterHub app:2466] Task status: <Task finished coro=<HTTP1ServerConnection._server_request_loop() done, defined at /usr/local/lib/python3.6/dist-packages/tornado/http1connection.py:809> result=None>
[D 2019-08-24 20:50:17.989 JupyterHub app:2466] Task status: <Task finished coro=<HTTP1ServerConnection._server_request_loop() done, defined at /usr/local/lib/python3.6/dist-packages/tornado/http1connection.py:809> result=None>
[I 2019-08-24 20:50:17.989 JupyterHub app:2150] Cleaning up 1 services...
[D 2019-08-24 20:50:17.989 JupyterHub service:363] Stopping service testcourse
[D 2019-08-24 20:50:17.997 JupyterHub spawner:1481] Interrupting 17092
[I 2019-08-24 20:50:17.998 SingleUserNotebookApp notebookapp:1694] Shutting down 0 kernels
[I 2019-08-24 20:50:18.144 JupyterHub app:2155] Cleaning up single-user servers...
[D 2019-08-24 20:50:18.144 JupyterHub app:2167] Stopping proxy
[I 2019-08-24 20:50:18.144 JupyterHub proxy:705] Cleaning up proxy[17086]...
[D 2019-08-24 20:50:18.145 JupyterHub proxy:569] Removing proxy pid file jupyterhub-proxy.pid
[D 2019-08-24 20:50:18.145 JupyterHub user:724] Stopping grader
[D 2019-08-24 20:50:18.145 JupyterHub spawner:1481] Interrupting 17129
[D 2019-08-24 20:50:18.145 JupyterHub user:724] Stopping instructor1
[D 2019-08-24 20:50:18.145 JupyterHub spawner:1481] Interrupting 17139
[I 2019-08-24 20:50:18.146 SingleUserNotebookApp notebookapp:1694] Shutting down 0 kernels
[I 2019-08-24 20:50:18.146 SingleUserNotebookApp notebookapp:1694] Shutting down 0 kernels
[D 2019-08-24 20:50:18.319 JupyterHub user:752] Deleting oauth client jupyterhub-user-instructor1
[D 2019-08-24 20:50:18.329 JupyterHub user:755] Finished stopping instructor1
[D 2019-08-24 20:50:18.939 JupyterHub user:752] Deleting oauth client jupyterhub-user-grader
[D 2019-08-24 20:50:18.947 JupyterHub user:755] Finished stopping grader
[I 2019-08-24 20:50:18.954 JupyterHub app:2187] ...done
Last login: Sat Aug 24 20:47:02 EDT 2019
Welcome to Ubuntu 18.04.3 LTS (GNU/Linux 4.15.0-39-generic x86_64)

 * Documentation:  https://help.ubuntu.com
 * Management:     https://landscape.canonical.com
 * Support:        https://ubuntu.com/advantage

 * Keen to learn Istio? It's included in the single-package MicroK8s.

     https://snapcraft.io/microk8s
jhamrick commented 5 years ago

Should I put the course folder somewhere else on the system?

Yes, as the error messages says, the course directory must be in the same folder (or in a subdirectory) of the place where the notebook server is being run. If your course directory is in /course then you need to run your notebook server in / or /course as well.

However, to have your course directory in a global location like /course is a very experimental option that I will not be able to help you debug very well (though if @rkdarst has time maybe he could). Instead, I would recommend trying to use the more supported setup described here which I will be better able to help you with: https://nbgrader.readthedocs.io/en/master/configuration/jupyterhub_config.html#example-use-case-one-class-multiple-graders

Also, I just added a working demo of how to configure nbgrader to work in the standard case of one class with multiple graders, which is available here and which might help: https://github.com/jupyter/nbgrader/tree/master/demos

mkzia commented 5 years ago

Hello Jessica!

Thank you so much for putting together the demo!

I have figured out what I was doing wrong. 1) The grader user is not used. It is only used for the purposes of sharing the course directory.

2) The instructor users are supposed to access the formgrader module from the course tab, not the formgrader tab itself. Since I was using a self-signed certificate, the course tab was displaying an SSL verification error instead of the course. And I error that I was reporting, that was from trying to directly access the formgrader module tab.

I am using Ubuntu 18.04.3 LTS. I had to make the following changes to the demo files:

1) Added mkdir -p /etc/jupyter/ before cp global_nbgrader_config.py /etc/jupyter/nbgrader_config.py in setup_demo.sh because the directory did not exist, so the copy command would fail.

2) Jupyterhub requires Python version 3. The default pip in my Ubuntu installation is associated with Python2. So I modified the utils.sh to use pip3 instead of pip. This required installing pip3. Also, npm and configurable-http-proxy had to be installed. Upgrading pip was causing errors, so I commented it out (see https://github.com/pypa/pip/issues/5447).

Here are the changes I made. 

--- a/demos/restart_demo.sh
+++ b/demos/restart_demo.sh
@@ -23,9 +23,12 @@ source utils.sh

 install_dependencies () {
     echo "Installing dependencies..."
-    pip install -U pip
-    pip install -U jupyter
-    pip install -U jupyterhub
+    apt install -y npm
+    npm install -g configurable-http-proxy
+    apt install -y python3-pip
+    # pip3 install -U pip
+    pip3 install -U jupyter
+    pip3 install -U jupyterhub
 }

 install_nbgrader () {
@@ -47,7 +50,7 @@ install_nbgrader () {
     git pull

     # Install requirements and nbgrader.
-    pip install -U -r requirements.txt -e .
+    pip3 install -U -r requirements.txt -e .

     # Install global extensions, and disable them globally. We will re-enable
     # specific ones for different user accounts in each demo.

Thanks again!

jhamrick commented 5 years ago

Oh great, I'm so glad the demo helped!

Thanks for pointing out that you need to specifically use python 3---I think on my server I installed python 3 a long time ago and symlinked it to pip hence why I didn't need to do anything special. Would you want to make a PR with these changes so the demos are easier for others to use in the future too?

mkzia commented 5 years ago

Yes. I can make PR with the changes.

jhamrick commented 4 years ago

I have opened a new issue for making these changes (#1261), and will close this one.