Intermittent '500 Internal Server Error' (possibly due to postgres query syntax)

[trap000d]

Hi there, I've caught another issue. I'm getting random HTTP 500 errors when connect to it. Quick look at supysonic-server logs hasn't shown anything meaningful.

Hint: I've managed to 100% reproduce the bug. Postgres crashes if select "Recently Added" in any client app (either Jamstash or DSub)

2023-02-21 10:19:49,100 [ERROR] Exception on /folder [GET]
Traceback (most recent call last):
  File "/usr/lib/python3.10/site-packages/peewee.py", line 3237, in execute_sql
    cursor.execute(sql, params or ())
psycopg2.errors.InFailedSqlTransaction: current transaction is aborted, commands ignored until end of transaction block

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.10/site-packages/flask/app.py", line 2525, in wsgi_app
    response = self.full_dispatch_request()
  File "/usr/lib/python3.10/site-packages/flask/app.py", line 1822, in full_dispatch_request
    rv = self.handle_user_exception(e)
  File "/usr/lib/python3.10/site-packages/flask/app.py", line 1818, in full_dispatch_request
    rv = self.preprocess_request()
  File "/usr/lib/python3.10/site-packages/flask/app.py", line 2309, in preprocess_request
    rv = self.ensure_sync(before_func)()
  File "/usr/lib/python3.10/site-packages/supysonic/frontend/__init__.py", line 41, in login_check
    user = UserManager.get(session.get("userid"))
  File "/usr/lib/python3.10/site-packages/supysonic/managers/user.py", line 27, in get
    return User[uid]
  File "/usr/lib/python3.10/site-packages/peewee.py", line 6390, in __getitem__
    return self.get_by_id(key)
  File "/usr/lib/python3.10/site-packages/peewee.py", line 6635, in get_by_id
    return cls.get(cls._meta.primary_key == pk)
  File "/usr/lib/python3.10/site-packages/peewee.py", line 6624, in get
    return sq.get()
  File "/usr/lib/python3.10/site-packages/peewee.py", line 7072, in get
    return clone.execute(database)[0]
  File "/usr/lib/python3.10/site-packages/peewee.py", line 1962, in inner
    return method(self, database, *args, **kwargs)
  File "/usr/lib/python3.10/site-packages/peewee.py", line 2033, in execute
    return self._execute(database)
  File "/usr/lib/python3.10/site-packages/peewee.py", line 2206, in _execute
    cursor = database.execute(self)
  File "/usr/lib/python3.10/site-packages/peewee.py", line 3250, in execute
    return self.execute_sql(sql, params, commit=commit)
  File "/usr/lib/python3.10/site-packages/peewee.py", line 3234, in execute_sql
    with __exception_wrapper__:
  File "/usr/lib/python3.10/site-packages/peewee.py", line 3010, in __exit__
    reraise(new_type, new_type(exc_value, *exc_args), traceback)
  File "/usr/lib/python3.10/site-packages/peewee.py", line 192, in reraise
    raise value.with_traceback(tb)
  File "/usr/lib/python3.10/site-packages/peewee.py", line 3237, in execute_sql
    cursor.execute(sql, params or ())
peewee.InternalError: current transaction is aborted, commands ignored until end of transaction block

After searching through postgresql logs I've spotted some complains about syntax error (happened a day before!).

Feb 20 21:18:57 localhost postgres[2239085]: 2023-02-20 21:18:57.564 NZDT [2239085] ERROR:  column "t2.created" must appear in the GROUP BY clause or be used in an aggregate function at character 143
Feb 20 21:18:57 localhost postgres[2239085]: 2023-02-20 21:18:57.564 NZDT [2239085] STATEMENT:  SELECT "t1"."folder_id" FROM "track" AS "t1" INNER JOIN "folder" AS "t2" ON ("t1"."folder_id" = "t2"."id") GROUP BY "t1"."folder_id"
 ORDER BY "t2"."created" DESC LIMIT 20 OFFSET 0
Feb 20 21:19:00 localhost postgres[2239085]: 2023-02-20 21:19:00.113 NZDT [2239085] ERROR:  current transaction is aborted, commands ignored until end of transaction block

After that all further transactions are getting aborted.

Regards,

UPD: Just found a relevant log record.

2023-02-22 16:26:21,690 [ERROR] Exception on /rest/getAlbumList.view [GET]
Traceback (most recent call last):
  File "/usr/lib/python3.10/site-packages/peewee.py", line 3237, in execute_sql
    cursor.execute(sql, params or ())
psycopg2.errors.GroupingError: column "t2.created" must appear in the GROUP BY clause or be used in an aggregate function
LINE 1: ..." = "t2"."id") GROUP BY "t1"."folder_id" ORDER BY "t2"."crea...
                                                             ^

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.10/site-packages/flask/app.py", line 2525, in wsgi_app
    response = self.full_dispatch_request()
  File "/usr/lib/python3.10/site-packages/flask/app.py", line 1822, in full_dispatch_request
    rv = self.handle_user_exception(e)
  File "/usr/lib/python3.10/site-packages/flask/app.py", line 1820, in full_dispatch_request
    rv = self.dispatch_request()
  File "/usr/lib/python3.10/site-packages/flask/app.py", line 1796, in dispatch_request
    return self.ensure_sync(self.view_functions[rule.endpoint])(**view_args)
  File "/usr/lib/python3.10/site-packages/supysonic/api/albums_songs.py", line 124, in album_list
    "album": [
  File "/usr/lib/python3.10/site-packages/peewee.py", line 7062, in __iter__
    self.execute()
  File "/usr/lib/python3.10/site-packages/peewee.py", line 1962, in inner
    return method(self, database, *args, **kwargs)
  File "/usr/lib/python3.10/site-packages/peewee.py", line 2033, in execute
    return self._execute(database)
  File "/usr/lib/python3.10/site-packages/peewee.py", line 2206, in _execute
    cursor = database.execute(self)
  File "/usr/lib/python3.10/site-packages/peewee.py", line 3250, in execute
    return self.execute_sql(sql, params, commit=commit)
  File "/usr/lib/python3.10/site-packages/peewee.py", line 3234, in execute_sql
    with __exception_wrapper__:
  File "/usr/lib/python3.10/site-packages/peewee.py", line 3010, in __exit__
    reraise(new_type, new_type(exc_value, *exc_args), traceback)
  File "/usr/lib/python3.10/site-packages/peewee.py", line 192, in reraise
    raise value.with_traceback(tb)
  File "/usr/lib/python3.10/site-packages/peewee.py", line 3237, in execute_sql
    cursor.execute(sql, params or ())
peewee.ProgrammingError: column "t2.created" must appear in the GROUP BY clause or be used in an aggregate function
LINE 1: ..." = "t2"."id") GROUP BY "t1"."folder_id" ORDER BY "t2"."crea...
                                                             ^

2023-02-22 16:26:31,399 [ERROR] Exception on /rest/getAlbumList.view [GET]
Traceback (most recent call last):
  File "/usr/lib/python3.10/site-packages/peewee.py", line 3237, in execute_sql
    cursor.execute(sql, params or ())
psycopg2.errors.InFailedSqlTransaction: current transaction is aborted, commands ignored until end of transaction block

[trap000d]

Tired of postgres bugs - switched to sqlite backend. Haven't spotted any performance issues.

[spl0k]

Sorry I take too long to fix this. I started working on it but didn't had time to finish it. This is, as you found out, an issue with Postgres being picky about the syntax of some queries. It affects at least the getAlbumList and getAlbumList2 endpoints.

Even if it is advertised as supported, I would advise against SQLite unless you have a single-user installation (and even then it can have issues). As this is an embedded database it doesn't properly handle connections from different processes, and as you are running multiple workers you might run into issues if at least two of them try to access the database at the same time. The problem also exists between the web app and the daemon.

[trap000d]

No worries. Although I prefer postgres over other db's (including mysql/mariadb), sqlite seems does the work. If/when this issue is fixed, I immediately switch back to postgres.

I had a look at SQL queries, but with a little knowledge of internal structures I simply have no idea of what data and in what format should be in output, and how to build all these queries through Python classes and objects.

As for sqlite multi-process, indeed, that was a real issue decade ago, but now it is thread-safe (at least they said it officially): https://www.sqlite.org/threadsafe.html