cannot run in uwsgi

[slavkoja]

Hi, i installed syn server and i was success to run it from console and sync with linux's and android's anki. But i want to serve it behind uWSGI (and latter via nginx due TLS), and deploy it in public net (to have more robust solution as python's simple server), but i encounter a problem, which i am not able to solve.

I prepared simple file for uWSGI (with some "debug" prints):

import os
from pathlib import Path
import sys

import uwsgi
import ankisyncd.config
from ankisyncd.sync_app import SyncApp
from ankisyncd.thread import shutdown

print(sys.path)

# Replace with your app's method of configuration
cfgfile  = os.environ.get('ANKI_CONFIG', Path(__file__).parent.resolve() / "ankisyncd.conf")

print("Loading config from %s" % cfgfile)
config = ankisyncd.config.load(cfgfile)

print(config)

# uWSGI will look for this variable
print("Initialize application...")
application = SyncApp(config)

def do_shutdown():
    print("Doing shutdown...")
    shutdown()

# will be invoked after uWSGI reload or shutdown
uwsgi.atexit = do_shutdown

Then i run uWSGI simple instance from anksi-sync-server's directory:

uwsgi --plugin python3,http --http :27701 --master --enable-threads --wsgi-file uwsgi.py

It basically loads application object from uwsgi.py file, which is SyncApp() object and serves it via HTTP. Apps starts nicely:

*** Starting uWSGI 2.0.18-debian (64bit) on [Sun May 12 09:57:31 2019] ***
compiled with version: 8.2.0 on 10 February 2019 02:42:46
os: Linux-4.19.0-4-amd64 #1 SMP Debian 4.19.28-2 (2019-03-15)
nodename: debmail
machine: x86_64
clock source: unix
pcre jit disabled
detected number of CPU cores: 1
current working directory: /home/slavko/anki-sync-server
detected binary path: /usr/bin/uwsgi-core
your processes number limit is 1818
your memory page size is 4096 bytes
detected max file descriptor number: 1024
lock engine: pthread robust mutexes
thunder lock: disabled (you can enable it with --thunder-lock)
uWSGI http bound on :27701 fd 4
uwsgi socket 0 bound to TCP address 127.0.0.1:40809 (port auto-assigned) fd 3
Python version: 3.7.3rc1 (default, Mar 13 2019, 11:01:15)  [GCC 8.3.0]
Python main interpreter initialized at 0x55f67b1314d0
python threads support enabled
your server socket listen backlog is limited to 100 connections
your mercy for graceful operations on workers is 60 seconds
mapped 145840 bytes (142 KB) for 1 cores
*** Operational MODE: single process ***
['./anki-bundled', '/usr/share/anki', '.', '', '/usr/lib/python37.zip', '/usr/lib/python3.7', '/usr/lib/python3.7/lib-dynload', '/usr/local/lib/python3.7/dist-packages', '/usr/lib/python3/dist-packages']
Loading config from /home/slavko/anki-sync-server/ankisyncd.conf
<Section: sync_app>
Initialize application...
WSGI app 0 (mountpoint='') ready in 1 seconds on interpreter 0x55f67b1314d0 pid: 2748 (default app)
*** uWSGI is running in multiple interpreter mode ***
spawned uWSGI master process (pid: 2748)
spawned uWSGI worker 1 (pid: 2751, cores: 1)
spawned uWSGI http 1 (pid: 2752)

Here you can see print's output (after "Operational MODE: single process" line), that paths are added into sys.path, config is loaded, and app initialized. I am able to connect to it, then it basically works:

wget -qO- --server-response http://debmail.skk:27701/
  HTTP/1.1 200 OK
  Content-Type: text/html; charset=UTF-8
  Content-Length: 16
Anki Sync Server

But when i try to sync with it, i got error about missing module anki.sched:

--- Logging error ---
Traceback (most recent call last):
  File "./ankisyncd/thread.py", line 98, in _run
  File "./ankisyncd/collection.py", line 42, in execute
  File "./ankisyncd/collection.py", line 72, in open
  File "./ankisyncd/collection.py", line 66, in _get_collection
  File "./anki-bundled/anki/storage.py", line 40, in Collection
  File "./anki-bundled/anki/collection.py", line 75, in __init__
  File "./anki-bundled/anki/collection.py", line 100, in _loadScheduler
ModuleNotFoundError: No module named 'anki.sched'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.7/logging/__init__.py", line 1034, in emit
    msg = self.format(record)
  File "/usr/lib/python3.7/logging/__init__.py", line 880, in format
    return fmt.format(record)
  File "/usr/lib/python3.7/logging/__init__.py", line 619, in format
    record.message = record.getMessage()
  File "/usr/lib/python3.7/logging/__init__.py", line 380, in getMessage
    msg = msg % self.args
TypeError: not all arguments converted during string formatting
Call stack:
  File "/usr/lib/python3.7/threading.py", line 885, in _bootstrap
    self._bootstrap_inner()
  File "/usr/lib/python3.7/threading.py", line 917, in _bootstrap_inner
    self.run()
  File "/usr/lib/python3.7/threading.py", line 865, in run
    self._target(*self._args, **self._kwargs)
  File "./ankisyncd/thread.py", line 101, in _run
Message: 'Unable to %s(*%s, **%s): %s'
Arguments: ('/home/slavko/anki-sync-server/collections/slavko/collection.anki2', 'meta', '[]', "{'v': 9, 'cv': 'ankidesktop,2.1.8,lin:debian:buster/sid'}", ModuleNotFoundError("No module named 'anki.sched'"))
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/webob/dec.py", line 129, in __call__
    resp = self.call_func(req, *args, **kw)
  File "/usr/lib/python3/dist-packages/webob/dec.py", line 193, in call_func
    return self.func(req, *args, **kwargs)
  File "./ankisyncd/sync_app.py", line 557, in __call__
  File "./ankisyncd/sync_app.py", line 634, in _execute_handler_method_in_thread
  File "./ankisyncd/thread.py", line 79, in execute
  File "./ankisyncd/thread.py", line 98, in _run
  File "./ankisyncd/collection.py", line 42, in execute
  File "./ankisyncd/collection.py", line 72, in open
  File "./ankisyncd/collection.py", line 66, in _get_collection
  File "./anki-bundled/anki/storage.py", line 40, in Collection
  File "./anki-bundled/anki/collection.py", line 75, in __init__
  File "./anki-bundled/anki/collection.py", line 100, in _loadScheduler
ModuleNotFoundError: No module named 'anki.sched'
[pid: 2751|app: 0|req: 2/2] 192.168.10.1 () {36 vars in 465 bytes} [Sun May 12 10:00:04 2019] POST /sync/meta => generated 0 bytes in 221 msecs (HTTP/1.1 500) 0 headers in 0 bytes (0 switches on core 0)

When i run the same instance directly, all works:

python3 -m ankisyncd
[2019-05-12 10:13:55,609]:INFO:ankisyncd:Loaded config from /home/slavko/anki-sync-server/ankisyncd.conf
[2019-05-12 10:13:55,610]:INFO:ankisyncd.users:Found auth_db_path in config, using SqliteUserManager for auth
[2019-05-12 10:13:55,611]:INFO:ankisyncd.sessions:Found session_db_path in config, using SqliteSessionManager for auth
[2019-05-12 10:13:55,612]:INFO:ankisyncd:Serving HTTP on 0.0.0.0 port 27701...
[2019-05-12 10:14:01,516]:INFO:ankisyncd.CollectionThread[slavko]:Starting...
[2019-05-12 10:14:01,517]:INFO:ankisyncd.CollectionThread[slavko]:Running meta(*[], **{'v': 9, 'cv': 'ankidesktop,2.1.8,lin:debian:buster/sid'})
[2019-05-12 10:14:01,524]:INFO:ankisyncd.http:192.168.10.1 "POST /sync/meta HTTP/1.1" 200 108
[2019-05-12 10:14:41,099]:INFO:ankisyncd.CollectionThread[slavko]:Running meta(*[], **{'v': 9, 'cv': 'ankidesktop,2.1.8,lin:debian:buster/sid'})
[2019-05-12 10:14:41,100]:INFO:ankisyncd.http:192.168.10.1 "POST /sync/meta HTTP/1.1" 200 108

I really don't know, what is missing, can you please give me some tips, where to go?

[AntonOfTheWoods]

You probably worked this out already but for posterity, the problem looks like a classic python path issue. I have never used uwsgi so can't help much there. There may also be an issue with python 3.7 but I'm guessing a bit there.

[slavkoja]

No, i was not able to solve this problem. I agree, that it seems as import path problem, I did some debug prints of sys.path in both cases - the uwsgi's and direct instance. The pats seems to be identical. It seems that there is needed some uwsgi's trick ;-) I don agree, that the python 3.7 can be problem (in this case), because directly (without uwsgi) it works with the same python version.

For now, the sync server runs as systemd's unit, which simple do direct python run (3.5 on debian stable). It works some time now without issues for me as only one user.