[Bug]: Airsonic-advanced doesn't start with latest releases

[Dikakus]

What happened?

Hi. I can't start the service with releases after [11.1.3-SNAPSHOT.20230919003332]. The log stops in those lines:

Oct 02 14:08:31 raspberrypi java[28044]: 2023-10-02 14:08:31.678 DEBUG --- o.a.player.dao.AbstractDao               : Found suitable field changedBy (as changedBy) in class org.airsonic.player.domain.SavedPlayQueue for table play_queue column changed_by
Oct 02 14:08:35 raspberrypi java[28044]: 2023-10-02 14:08:35.450  INFO --- o.a.p.s.TaskSchedulingService            : Task remote-playstatus-cleanup scheduled
Oct 02 14:08:35 raspberrypi java[28044]: 2023-10-02 14:08:35.991 TRACE --- o.a.player.dao.AbstractDao               : Executing query: [delete from player where name is null and client_id is null and (last_seen is null or last_seen < ?)]
Oct 02 14:08:36 raspberrypi java[28044]: 2023-10-02 14:08:36.070 TRACE --- o.a.player.dao.AbstractDao               : Updated 0 rows

And nothing more happens.

Steps to reproduce

Starting any war with release after 11.1.3-SNAPSHOT.20230919003332.

Version

11.1.x (Edge)

Version Detail

11.1.3-SNAPSHOT.20230930223645

Operating System

Raspbian OS Bullseye (Raspberrypi)

Java Version

Java 17.0.7

Database

Other

DB Detail

hsqlite

Configuration paramter

Type=simple ExecStartPre=/bin/sleep 30 Environment="JAVA_JAR=/srv/airsonic/airsonic.war" Environment="JAVA_OPTS=-Xmx2048m" Environment="AIRSONIC_HOME=/var/airsonic" Environment="PORT=8085" Environment="CONTEXT_PATH=/airsonic" Environment="DEBUG_LEVEL=TRACE" Environment="JAVA_ARGS=" EnvironmentFile=-/etc/sysconfig/airsonic ExecStart=/usr/bin/java \ $JAVA_OPTS \ -Dairsonic.home=${AIRSONIC_HOME} \ -Dserver.forward-headers-strategy=native \ -Dserver.servlet.context-path=${CONTEXT_PATH} \ -Dserver.port=${PORT} \ -Dlogging.level.org.airsonic=${DEBUG_LEVEL} \ -jar ${JAVA_JAR} $JAVA_ARGS

Proxy Server

No response

client detail

No response

language

None

Relevant log output

No response

[kagemomiji]

@Dikakus If it's the edge latest version (Edge Release 11.1.3-SNAPSHOT.20230930223645), the continuation of the log you provided should be INFO --- o.a.p.s.TaskSchedulingService : Task podcast-channel-refresh--1 scheduled. If it's the release where the problem started (Edge Release 11.1.3-SNAPSHOT.20230919003332), the continuation of the log you provided should be o.a.player.dao.AbstractDao : Found suitable field fileCount (as fileCount) in class org.airsonic.player.domain.Playlist for table playlist column file_count. Can I recognize the issue as a bug where it doesn't proceed beyond "Updated 0 rows"?

[Dikakus]

Hi, @kagemomiji. I've tried again the versions you indicated with these last lines in the log:

• Edge Release 11.1.3-SNAPSHOT.20230930223645:

  Oct 03 09:24:10 raspberrypi java[12602]: 2023-10-03 09:24:10.615 DEBUG --- o.a.player.dao.AbstractDao               : Found suitable field positionMillis (as positionMillis) in class org.airsonic.player.domain.SavedPlayQueue for table play_queue column position_millis
  Oct 03 09:24:14 raspberrypi java[12602]: 2023-10-03 09:24:14.964  INFO --- o.a.p.s.TaskSchedulingService            : Task remote-playstatus-cleanup scheduled
  Oct 03 09:24:15 raspberrypi java[12602]: 2023-10-03 09:24:15.530 TRACE --- o.a.player.dao.AbstractDao               : Executing query: [delete from player where name is null and client_id is null and (last_seen is null or last_seen < ?)]
  Oct 03 09:24:15 raspberrypi java[12602]: 2023-10-03 09:24:15.617 TRACE --- o.a.player.dao.AbstractDao               : Updated 0 rows

I waited a reasonable time for the server to start but nothing happens after the update line.

• Edge Release 11.1.3-SNAPSHOT.20230919003332:

  
  2023-10-03 07:30:46.029 DEBUG --- o.a.player.dao.AbstractDao               : Found suitable field dynamicIp (as dynamicIp) in class org.airsonic.player.domai
  n.Player for table player column dynamic_ip
  2023-10-03 07:30:48.235  INFO --- o.a.p.s.TaskSchedulingService            : Task remote-playstatus-cleanup scheduled
  2023-10-03 07:30:48.621 TRACE --- o.a.player.dao.AbstractDao               : Executing query: [delete from player where name is null and client_id is null and (last_seen is null or last_seen < ?)]
  2023-10-03 07:30:48.716 TRACE --- o.a.player.dao.AbstractDao               : Updated 0 rows
  2023-10-03 07:30:49.302 DEBUG --- o.a.player.dao.AbstractDao               : Found suitable field username (as username) in class org.airsonic.player.domain.Playlist for table playlist column username
  2023-10-03 07:30:49.303 DEBUG --- o.a.player.dao.AbstractDao               : Found suitable field comment (as comment) in class org.airsonic.player.domain.Playlist for table playlist column comment
  2023-10-03 07:30:49.302 DEBUG --- o.a.player.dao.AbstractDao               : Found suitable field shared (as is_public) in class org.airsonic.player.domain.Playlist for table playlist column is_public
  2023-10-03 07:30:49.302 DEBUG --- o.a.player.dao.AbstractDao               : Found suitable field name (as name) in class org.airsonic.player.domain.Playlist for table playlist column name
  2023-10-03 07:30:49.305 DEBUG --- o.a.player.dao.AbstractDao               : Found suitable field created (as created) in class org.airsonic.player.domain.Playlist for table playlist column created

(and continue)

The sever starts and I can play music!!! ^_^

So yes, you can. Something must happen after the update in the new versions, don't you think?

[DutchComputerKid]

I'm also having the same issue, hanging at 2023-10-03 14:12:54.969 INFO --- o.a.p.s.TaskSchedulingService : Task remote-playstatus-cleanup scheduled.

Edit: It also fails to shut down using the standard service file, the timeout reaches and Airsonic gets killed instead.

Is downgrading safe to do?

[Dikakus]

@DutchComputerKid, I downloaded and started the edge release 11.1.3-SNAPSHOT.20230919003332 which works without any problems (apparently). Having a backup of your db it's always a good idea. ;)

[DutchComputerKid]

Yeah with the built in DB thats easy enough. Anyway, 20230929030503 does start so thats something.

[Dikakus]

Hi, @kagemomiji. I tried to start the server with the las war 11.1.3-SNAPSHOT.20231216223104 and it works. So, I think we can close this issue.