Problems updating Sonar Enterprise from 8.1 to 8.9.X

xaviersojo · October 5, 2021, 9:37am

Hi all,
this is my first post looking for help from the experts. I’ve been trying to update Sonarqube Enterprise from 8.1 to 8.9.X and up until now, I haven’t succeeded because looks like there is something wrong when upgrading the DB.
This is the problem description:

Upgrade process from 8.0 to 8.9.0/8.9.2 get hanged at step 3543.
This process seems to do an ALTER TABLE to live_measures table, that have 95208033 records.
This process seems to take more than 10 minutes.
I noticed that when Postgres stops processing the query/table (by monitoring disc and CPU usage), Postgres talks back to the Sonarqube process on SonarQube server, but this does not reply, although the TCP connection is in ESTABLISHED status.
Connection to the server changes to “idle in transaction” and it eventually dies (is removed)
No activity (CPU or DISK) from this point onward.

I think it may be some kind of bug or connection issue on the SonarQube, as it is not answering to the notification. The issue could be related to the amount of time that step 3543 takes.

Could give me some advice or tip to make this process work?

Thanks in advance!

Joe · October 13, 2021, 8:46pm

Hello @xaviersojo ,

Welcome to SonarSource community

Can you zip your $SONARQUBE_HOME/logs and attach them here? If you prefer a private thread, please let me know also.

Joe

Joe · October 14, 2021, 9:46pm

Hello @xaviersojo ,

Before we proceed with further troubleshooting, please backup your database, copy it to another database, and we will test the migration on a test instance of SonarQube. This ensures we do not harm your production data once we have a good plan to fix this issue.

Next, can you confirm if the primary key pk_live_measures exists on the uuid column of live_measures table?

One way to get all the PKs on all your tables:

select kcu.table_schema,
       kcu.table_name,
       tco.constraint_name,
       kcu.ordinal_position as position,
       kcu.column_name as key_column
from information_schema.table_constraints tco
join information_schema.key_column_usage kcu 
     on kcu.constraint_name = tco.constraint_name
     and kcu.constraint_schema = tco.constraint_schema
     and kcu.constraint_name = tco.constraint_name
where tco.constraint_type = 'PRIMARY KEY'
order by kcu.table_schema,
         kcu.table_name,
         position;

In any case, I suggest you perform a VACUUM FULL ANALYZE as discussed in this Community guide.

After that, please try running your migration once more. If it hangs again at step 3543, please notify me.

Joe

Sergio_Lopez · October 18, 2021, 8:36am

Hello @Joe ,

Thanks a lot for your answer.
I’m Xavi’s co-worker. We can confirm that this primary key exists in the table lives_measures as you indicate.
We will try it again next week.

Thanks,
Sergio.

Joe · October 18, 2021, 1:43pm

Hi @Sergio_Lopez ,

Thanks for the update. If you can, can you try stopping the upgrade (quit SonarQube), then retry the upgrade (restart SonarQube and go to the URL <YOUR-SONARQUBE-URL>/setup) and see what happens?

Regards,
Joe

Sergio_Lopez · October 18, 2021, 2:08pm

Hi @Joe,

We did rollback and we continue working with Version 8.1
Now the message in /setup is " Database is up-to-date".
We’ll try the sonar update again next week.

Thanks,
Sergio

xaviersojo · November 15, 2021, 10:00am

Hello @Joe, sorry for the late response. We have tried to update Sonarqube and, again, the process stopped at some point.
After 1.5 hours, more or less, the log was printing just this (same message every few seconds, this is just 30 seconds of log):

2021.11.10 17:30:00 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-5,5,main] serves /api/system/status
2021.11.10 17:30:01 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-3,5,main] serves /api/system/status
2021.11.10 17:30:01 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-4,5,main] serves /api/system/status
2021.11.10 17:30:01 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-2,5,main] serves /api/system/db_migration_status
2021.11.10 17:30:01 TRACE web[][sql] time=1ms | sql=select version from schema_migrations
2021.11.10 17:30:01 TRACE web[][sql] time=1ms | sql=select version from schema_migrations
2021.11.10 17:30:01 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-1,5,main] serves /api/system/status
2021.11.10 17:30:03 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-5,5,main] serves /api/system/status
2021.11.10 17:30:03 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-3,5,main] serves /api/system/db_migration_status
2021.11.10 17:30:03 TRACE web[][sql] time=1ms | sql=select version from schema_migrations
2021.11.10 17:30:03 TRACE web[][sql] time=1ms | sql=select version from schema_migrations
2021.11.10 17:30:04 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-4,5,main] serves /api/developers/search_events
2021.11.10 17:30:05 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-2,5,main] serves /api/developers/search_events
2021.11.10 17:30:06 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-1,5,main] serves /api/system/status
2021.11.10 17:30:06 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-5,5,main] serves /api/system/status
2021.11.10 17:30:07 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-3,5,main] serves /api/system/status
2021.11.10 17:30:07 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-4,5,main] serves /api/system/db_migration_status
2021.11.10 17:30:07 TRACE web[][sql] time=0ms | sql=select version from schema_migrations
2021.11.10 17:30:07 TRACE web[][sql] time=0ms | sql=select version from schema_migrations
2021.11.10 17:30:08 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-2,5,main] serves /api/system/status
2021.11.10 17:30:09 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-1,5,main] serves /api/system/status
2021.11.10 17:30:09 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-5,5,main] serves /api/system/db_migration_status
2021.11.10 17:30:09 TRACE web[][sql] time=0ms | sql=select version from schema_migrations
2021.11.10 17:30:09 TRACE web[][sql] time=0ms | sql=select version from schema_migrations
2021.11.10 17:30:11 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-3,5,main] serves /api/system/status
2021.11.10 17:30:12 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-4,5,main] serves /api/system/status
2021.11.10 17:30:13 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-2,5,main] serves /api/system/status
2021.11.10 17:30:13 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-1,5,main] serves /api/system/db_migration_status
2021.11.10 17:30:13 TRACE web[][sql] time=1ms | sql=select version from schema_migrations
2021.11.10 17:30:13 TRACE web[][sql] time=0ms | sql=select version from schema_migrations
2021.11.10 17:30:15 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-5,5,main] serves /api/system/status
2021.11.10 17:30:15 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-3,5,main] serves /api/system/status
2021.11.10 17:30:15 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-4,5,main] serves /api/system/db_migration_status
2021.11.10 17:30:15 TRACE web[][sql] time=1ms | sql=select version from schema_migrations
2021.11.10 17:30:15 TRACE web[][sql] time=1ms | sql=select version from schema_migrations
2021.11.10 17:30:16 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-2,5,main] serves /api/system/status
2021.11.10 17:30:18 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-1,5,main] serves /api/system/status
2021.11.10 17:30:19 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-5,5,main] serves /api/system/status
2021.11.10 17:30:19 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-3,5,main] serves /api/system/db_migration_status
2021.11.10 17:30:19 TRACE web[][sql] time=1ms | sql=select version from schema_migrations
2021.11.10 17:30:19 TRACE web[][sql] time=0ms | sql=select version from schema_migrations
2021.11.10 17:30:21 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-4,5,main] serves /api/system/status
2021.11.10 17:30:21 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-2,5,main] serves /api/system/db_migration_status
2021.11.10 17:30:21 TRACE web[][sql] time=1ms | sql=select version from schema_migrations
2021.11.10 17:30:21 TRACE web[][sql] time=1ms | sql=select version from schema_migrations
2021.11.10 17:30:21 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-1,5,main] serves /api/system/status
2021.11.10 17:30:22 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-5,5,main] serves /api/system/status
2021.11.10 17:30:24 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-3,5,main] serves /api/system/status
2021.11.10 17:30:25 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-4,5,main] serves /api/system/status
2021.11.10 17:30:25 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-2,5,main] serves /api/system/db_migration_status
2021.11.10 17:30:25 TRACE web[][sql] time=0ms | sql=select version from schema_migrations
2021.11.10 17:30:25 TRACE web[][sql] time=0ms | sql=select version from schema_migrations
2021.11.10 17:30:26 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-5,5,main] serves /api/system/status
2021.11.10 17:30:27 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-3,5,main] serves /api/system/status
2021.11.10 17:30:27 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-4,5,main] serves /api/system/db_migration_status
2021.11.10 17:30:27 TRACE web[][sql] time=1ms | sql=select version from schema_migrations
2021.11.10 17:30:27 TRACE web[][sql] time=1ms | sql=select version from schema_migrations
2021.11.10 17:30:29 TRACE web[][o.s.s.p.w.UserSessionFilter] Thread[http-nio-IP-ADDRESS-8090-exec-2,5,main] serves /api/system/status

And this is a screenshot of the DDBB status at this moment:

So I would say that the process stopped for a different reason than the origiinal post, now looks that something could be happening with the query:

sql=select version from schema_migrations

Any ideas?
Thanks in advance!

xaviersojo · December 14, 2021, 5:15pm

Hello @Joe, I’m writing just to update you with the latest attempt to upgrade Sonarqube.
Brief description: It worked!

We did the “VACUUM FULL ANALYZE” as you recommended (attached), but the process stopped again in the step 3543 meanwhile the web.log in TRACE mode was displaying the API URLs “system/status” and “system/db_migration_status”.
There was no reason for that, but after 15 minutes I decided to launch these URLs in my browser and, suddenly, the process started again and finished successfully in less than 10 minutes.
It is hard to believe that there is a connection between the execution of these URLs and the database upgrade but, I don’t know how and why… it worked.
Next step will be trying to update to the latest 9.2.2

Anyway, I want to really thank you for your help, your kindness and support on this issue. I really appreciate it.
Best regards!

vacuum_execution.txt (27.2 KB)

Joe · December 14, 2021, 5:39pm

@xaviersojo I’m happy to hear about your success! Great job on pushing forward and testing those URLs. Very strange behavior, if I do say so myself, but in any case, I’m glad it worked.

system · December 21, 2021, 5:40pm

This topic was automatically closed 7 days after the last reply. New replies are no longer allowed.