Hi,
to reproduce the deadlock problem with RT 4.4.1 on Postgres I tried to install
RT 4.4.1 as clean new instalation:
1. On Debian 8.6 stable + Postgres 9.4
2. On Debian sid (unstable) + Postgres 9.6 (there was a need to
change one sql command, option NOCREATEUSER -> NOCREATEROLE)
To my surprise I created ticket in queue General (default) and the bug
appeared immediately when I tried to change owner of a ticket and record
comment together.
Can anybody confirm on different system?
Steps:
1. Create Postgres cluster (server instance):
pg_createcluster 9.6 main --locale cs_CZ.UTF-8
2. Change access to rt4 database, so I don't need to set password for rt_user
in /etc/postgresql/9.6/main/pg_hba.conf
diff --git a/postgresql/9.6/main/pg_hba.conf
b/postgresql/9.6/main/pg_hba.conf
index b708a885..85857f64 100644
--- a/postgresql/9.6/main/pg_hba.conf
+++ b/postgresql/9.6/main/pg_hba.conf
@@ -86,6 +86,8 @@ local all postgres
peer
# TYPE DATABASE USER ADDRESS METHOD
+local rt4 rt_user trust
+
# "local" is for Unix domain socket connections only
local all all peer
# IPv4 local connections:
3. Start Postgres & check
pg_ctlcluster 9.6 main start
pg_lsclusters
4. Install RT 4.4.1 from RT sources...
cd rt-4.4.1-sources
./configure --prefix=/opt/rt --with-db-type=Pg
sudo make install
Change db host, so the connection will go through unix domain socket
cd /opt/rt
cat <<'EOT' >etc/RT_SiteConfig.pm
Set($WebPort, 8888);
Set($DatabaseHost, undef);
Set($DatabaseRTHost, undef);
1;
EOT
Postgres user needs to read schame etc
chmod a+r etc/{acl,initialdata,schema}*
Postgres 9.6 no longer support NOCREATEUSER, but NOTCREATEROLE
(https://www.postgresql.org/docs/9.6/static/release-9-6.html)
sed -i -e 's/NOCREATEUSER/NOCREATEROLE/;' etc/acl.Pg
Initialize database (if something went wrong, remove not finished database
using 'sudo -u postgres dropdb rt4' and try better again)
sudo -u postgres /usr/bin/perl -I/opt/rt/local/lib -I/opt/rt/lib
sbin/rt-setup-database --action init
5. Start RT built int HTTP server by hand:
sudo -u www-data /opt/rt/sbin/rt-server --port 8888
6. Go to browser and type location localhost:8888
- login as root / password
- click on "New ticket in" General, enter something into subject and message
and click "Create"
(Owner is nobody, requestor is root)
- Go Actions / Comment, type something into message and change owner
to root. Click "Update ticket"
- If owner was changed, try repeat previous step switching owner
between nobody & root, until error.
My session:
bobek:/opt/rt# sudo -u www-data /opt/rt/sbin/rt-server --port 8888
[21132] [Mon Jan 2 15:58:50 2017] [info]: Successful login for root from
127.0.0.1 (/opt/rt/sbin/../lib/RT/Interface/Web.pm:831)
[21133] [Mon Jan 2 16:00:21 2017] [info]:
<rt-4.4.1-21133-1483372820-1051.1-...@example.com> #1/31 - Scrip 7 On Create
Autoreply To Requestors (/opt/rt/sbin/../lib/RT/Action/SendEmail.pm:285)
[21133] [Mon Jan 2 16:00:21 2017] [info]:
<rt-4.4.1-21133-1483372820-1051.1-...@example.com> sent To: root@localhost
(/opt/rt/sbin/../lib/RT/Action/SendEmail.pm:316)
[21133] [Mon Jan 2 16:00:21 2017] [info]:
<rt-4.4.1-21133-1483372821-1765.1-...@example.com> #1/31 - Scrip 8 On Create
Notify Owner and AdminCcs (/opt/rt/sbin/../lib/RT/Action/SendEmail.pm:285)
[21133] [Mon Jan 2 16:00:21 2017] [info]:
<rt-4.4.1-21133-1483372821-1765.1-...@example.com> No recipients found. Not
sending. (/opt/rt/sbin/../lib/RT/Interface/Email.pm:806)
[21133] [Mon Jan 2 16:00:21 2017] [info]:
<rt-4.4.1-21133-1483372821-1271.1-...@example.com> #1/31 - Scrip 9 On Create
Notify Ccs (/opt/rt/sbin/../lib/RT/Action/SendEmail.pm:285)
[21133] [Mon Jan 2 16:00:21 2017] [info]:
<rt-4.4.1-21133-1483372821-1271.1-...@example.com> No recipients found. Not
sending. (/opt/rt/sbin/../lib/RT/Interface/Email.pm:806)
[21133] [Mon Jan 2 16:00:21 2017] [info]:
<rt-4.4.1-21133-1483372821-1685.1-1...@example.com> #1/31 - Scrip 10 On Create
Notify Other Recipients (/opt/rt/sbin/../lib/RT/Action/SendEmail.pm:285)
[21133] [Mon Jan 2 16:00:21 2017] [info]:
<rt-4.4.1-21133-1483372821-1685.1-1...@example.com> No recipients found. Not
sending. (/opt/rt/sbin/../lib/RT/Interface/Email.pm:806)
[21133] [Mon Jan 2 16:00:21 2017] [info]: Ticket 1 created in queue 'General'
by root (/opt/rt/sbin/../lib/RT/Ticket.pm:567)
[21132] [Mon Jan 2 16:02:37 2017] [info]:
<rt-4.4.1-21132-1483372957-1152.1-1...@example.com> not sending to
root@localhost, creator of the transaction, due to NotifyActor setting
(/opt/rt/sbin/../lib/RT/Action/SendEmail.pm:901)
[21133] [Mon Jan 2 16:02:48 2017] [info]:
<rt-4.4.1-21133-1483372968-1533.1-1...@example.com> not sending to
root@localhost, creator of the transaction, due to NotifyActor setting
(/opt/rt/sbin/../lib/RT/Action/SendEmail.pm:901)
[21133] [Mon Jan 2 16:02:48 2017] [info]:
<rt-4.4.1-21133-1483372968-1533.1-1...@example.com> #1/39 - Scrip 11 On Owner
Change Notify Owner (/opt/rt/sbin/../lib/RT/Action/SendEmail.pm:285)
[21133] [Mon Jan 2 16:02:48 2017] [info]:
<rt-4.4.1-21133-1483372968-1533.1-1...@example.com> No recipients found. Not
sending. (/opt/rt/sbin/../lib/RT/Interface/Email.pm:806)
[21133] [Mon Jan 2 16:03:19 2017] [info]:
<rt-4.4.1-21133-1483372999-1299.1-...@example.com> #1/45 - Scrip 1 On Comment
Notify AdminCcs as Comment (/opt/rt/sbin/../lib/RT/Action/SendEmail.pm:285)
[21133] [Mon Jan 2 16:03:19 2017] [info]:
<rt-4.4.1-21133-1483372999-1299.1-...@example.com> No recipients found. Not
sending. (/opt/rt/sbin/../lib/RT/Interface/Email.pm:806)
[21133] [Mon Jan 2 16:03:19 2017] [info]:
<rt-4.4.1-21133-1483372999-1044.1-...@example.com> #1/45 - Scrip 2 On Comment
Notify Other Recipients as Comment
(/opt/rt/sbin/../lib/RT/Action/SendEmail.pm:285)
[21133] [Mon Jan 2 16:03:19 2017] [info]:
<rt-4.4.1-21133-1483372999-1044.1-...@example.com> No recipients found. Not
sending. (/opt/rt/sbin/../lib/RT/Interface/Email.pm:806)
[21133] [Mon Jan 2 16:03:19 2017] [info]:
<rt-4.4.1-21133-1483372999-1062.1-1...@example.com> #1/46 - Scrip 11 On Owner
Change Notify Owner (/opt/rt/sbin/../lib/RT/Action/SendEmail.pm:285)
[21133] [Mon Jan 2 16:03:19 2017] [info]:
<rt-4.4.1-21133-1483372999-1062.1-1...@example.com> No recipients found. Not
sending. (/opt/rt/sbin/../lib/RT/Interface/Email.pm:806)
[21132] [Mon Jan 2 16:03:34 2017] [info]:
<rt-4.4.1-21132-1483373014-750.1-1...@example.com> not sending to
root@localhost, creator of the transaction, due to NotifyActor setting
(/opt/rt/sbin/../lib/RT/Action/SendEmail.pm:901)
[21140] [Mon Jan 2 16:03:37 2017] [info]:
<rt-4.4.1-21140-1483373017-415.1-...@example.com> #1/53 - Scrip 1 On Comment
Notify AdminCcs as Comment (/opt/rt/sbin/../lib/RT/Action/SendEmail.pm:285)
[21140] [Mon Jan 2 16:03:37 2017] [info]:
<rt-4.4.1-21140-1483373017-415.1-...@example.com> No recipients found. Not
sending. (/opt/rt/sbin/../lib/RT/Interface/Email.pm:806)
[21140] [Mon Jan 2 16:03:37 2017] [info]:
<rt-4.4.1-21140-1483373017-851.1-...@example.com> #1/53 - Scrip 2 On Comment
Notify Other Recipients as Comment
(/opt/rt/sbin/../lib/RT/Action/SendEmail.pm:285)
[21140] [Mon Jan 2 16:03:37 2017] [info]:
<rt-4.4.1-21140-1483373017-851.1-...@example.com> No recipients found. Not
sending. (/opt/rt/sbin/../lib/RT/Interface/Email.pm:806)
[21140] [Mon Jan 2 16:03:38 2017] [warning]: DBD::Pg::st execute failed:
ERROR: deadlock detected
DETAIL: Process 21479 waits for ShareLock on transaction 1134; blocked by
process 21157.
Process 21157 waits for ShareLock on transaction 1135; blocked by process 21479.
HINT: See server log for query details.
CONTEXT: while updating tuple (0,21) in relation "tickets" at
/usr/share/perl5/DBIx/SearchBuilder/Handle.pm line 586.
(/usr/share/perl5/DBIx/SearchBuilder/Handle.pm:586)
[21140] [Mon Jan 2 16:03:38 2017] [warning]: RT::Handle=HASH(0x55fc4d97fd18)
couldn't execute the query 'UPDATE Tickets SET Owner=? WHERE id=? ' at
/usr/share/perl5/DBIx/SearchBuilder/Handle.pm line 599.
DBIx::SearchBuilder::Handle::SimpleQuery(RT::Handle=HASH(0x55fc4d97fd18),
"UPDATE Tickets SET Owner=? WHERE id=? ", 14, 1) called at
/usr/share/perl5/DBIx/SearchBuilder/Handle.pm line 453
DBIx::SearchBuilder::Handle::UpdateRecordValue(RT::Handle=HASH(0x55fc4d97fd18),
"Column", "Owner", "Table", "Tickets", "PrimaryKeys", HASH(0x55fc4de23ab8),
"Value", ...) called at /usr/share/perl5/DBIx/SearchBuilder/Record.pm line 871
DBIx::SearchBuilder::Record::__Set(RT::Ticket=HASH(0x55fc4dce9210),
"Field", "Owner", "Value", 14, "IsSQL", undef) called at
/usr/share/perl5/DBIx/SearchBuilder/Record/Cachable.pm line 140
DBIx::SearchBuilder::Record::Cachable::__Set(RT::Ticket=HASH(0x55fc4dce9210),
"Field", "Owner", "Value", 14, "IsSQL", undef) called at
/usr/share/perl5/DBIx/SearchBuilder/Record.pm line 744
DBIx::SearchBuilder::Record::_Set(RT::Ticket=HASH(0x55fc4dce9210),
"Field", "Owner", "Value", 14, "IsSQL", undef) called at
/opt/rt/sbin/../lib/RT/Record.pm line 462
RT::Record::_Set(RT::Ticket=HASH(0x55fc4dce9210), "Field", "Owner",
"Value", 14) called at /opt/rt/sbin/../lib/RT/Ticket.pm line 2634
RT::Ticket::_Set(RT::Ticket=HASH(0x55fc4dce9210), "Field", "Owner",
"Value", 14, "CheckACL", 0, "RecordTransaction", ...) called at
/opt/rt/sbin/../lib/RT/Group.pm line 993
RT::Group::_AddMember(RT::Group=HASH(0x55fc4db25448), "PrincipalId",
14, "InsideTransaction", 1, "Object", RT::Ticket=HASH(0x55fc4dce9210)) called
at /opt/rt/sbin/../lib/RT/Ticket.pm line 1968
RT::Ticket::SetOwner(RT::Ticket=HASH(0x55fc4dce9210), 14, "Set") called
at /opt/rt/sbin/../lib/RT/Interface/Web.pm line 2975
HTML::Mason::Commands::ProcessTicketBasics("ARGSRef",
HASH(0x55fc4dc9a470), "TicketObj", RT::Ticket=HASH(0x55fc4dce9210)) called at
/opt/rt/share/html/Ticket/Display.html line 190
HTML::Mason::Commands::__ANON__("TicketObj",
RT::Ticket=HASH(0x55fc4dce9210), "SubmitTicket", "Update Ticket",
"TxnRecipients", "", "QuoteTransaction", "", ...) called at
/usr/share/perl5/HTML/Mason/Component.pm line 135
HTML::Mason::Component::run(HTML::Mason::Component::FileBased=HASH(0x55fc4dc8e118),
"TicketObj", RT::Ticket=HASH(0x55fc4dce9210), "SubmitTicket", "Update Ticket",
"TxnRecipients", "", "QuoteTransaction", ...) called at
/usr/share/perl5/HTML/Mason/Request.pm line 1302
eval {...} called at /usr/share/perl5/HTML/Mason/Request.pm line 1292
HTML::Mason::Request::comp(undef, undef, "TicketObj",
RT::Ticket=HASH(0x55fc4dce9210), "SubmitTicket", "Update Ticket",
"TxnRecipients", "", ...) called at /opt/rt/share/html/Ticket/Update.html line
347
HTML::Mason::Commands::__ANON__("UpdateTimeWorked", "", "Action",
"Comment", "DefaultStatus", "new", "UpdateBcc", "", ...) called at
/usr/share/perl5/HTML/Mason/Component.pm line 135
HTML::Mason::Component::run(HTML::Mason::Component::FileBased=HASH(0x55fc4dbdba78),
"UpdateTimeWorked", "", "Action", "Comment", "DefaultStatus", "new",
"UpdateBcc", ...) called at /usr/share/perl5/HTML/Mason/Request.pm line 1302
eval {...} called at /usr/share/perl5/HTML/Mason/Request.pm line 1292
HTML::Mason::Request::comp(undef, undef, undef, "UpdateTimeWorked", "",
"Action", "Comment", "DefaultStatus", ...) called at
/usr/share/perl5/HTML/Mason/Request.pm line 955
HTML::Mason::Request::call_next(RT::Interface::Web::Request=HASH(0x55fc4d5afea0))
called at /opt/rt/share/html/Ticket/autohandler line 66
HTML::Mason::Commands::__ANON__("UpdateTimeWorked", "", "Action",
"Comment", "DefaultStatus", "new", "UpdateBcc", "", ...) called at
/usr/share/perl5/HTML/Mason/Component.pm line 135
HTML::Mason::Component::run(HTML::Mason::Component::FileBased=HASH(0x55fc4dbf6580),
"UpdateTimeWorked", "", "Action", "Comment", "DefaultStatus", "new",
"UpdateBcc", ...) called at /usr/share/perl5/HTML/Mason/Request.pm line 1302
eval {...} called at /usr/share/perl5/HTML/Mason/Request.pm line 1292
HTML::Mason::Request::comp(undef, undef, undef, "UpdateTimeWorked", "",
"Action", "Comment", "DefaultStatus", ...) called at
/opt/rt/sbin/../lib/RT/Interface/Web.pm line 696
RT::Interface::Web::ShowRequestedPage(HASH(0x55fc4da121e8)) called at
/opt/rt/sbin/../lib/RT/Interface/Web.pm line 375
RT::Interface::Web::HandleRequest(HASH(0x55fc4da121e8)) called at
/opt/rt/share/html/autohandler line 53
HTML::Mason::Commands::__ANON__("QuoteTransaction", "",
"TxnRecipients", "", "SubmitTicket", "Update Ticket",
"UpdateTimeWorked-TimeUnits", "minutes", ...) called at
/usr/share/perl5/HTML/Mason/Component.pm line 135
HTML::Mason::Component::run(HTML::Mason::Component::FileBased=HASH(0x55fc4d9d0930),
"QuoteTransaction", "", "TxnRecipients", "", "SubmitTicket", "Update Ticket",
"UpdateTimeWorked-TimeUnits", ...) called at
/usr/share/perl5/HTML/Mason/Request.pm line 1300
eval {...} called at /usr/share/perl5/HTML/Mason/Request.pm line 1292
HTML::Mason::Request::comp(undef, undef, undef, "QuoteTransaction", "",
"TxnRecipients", "", "SubmitTicket", ...) called at
/usr/share/perl5/HTML/Mason/Request.pm line 481
eval {...} called at /usr/share/perl5/HTML/Mason/Request.pm line 481
eval {...} called at /usr/share/perl5/HTML/Mason/Request.pm line 433
HTML::Mason::Request::exec(RT::Interface::Web::Request=HASH(0x55fc4d5afea0))
called at /usr/share/perl5/HTML/Mason/PSGIHandler.pm line 96
eval {...} called at /usr/share/perl5/HTML/Mason/PSGIHandler.pm line 96
HTML::Mason::Request::PSGI::exec(RT::Interface::Web::Request=HASH(0x55fc4d5afea0))
called at /usr/share/perl5/HTML/Mason/Interp.pm line 342
HTML::Mason::Interp::exec(undef, undef, "QuoteTransaction", "",
"TxnRecipients", "", "SubmitTicket", "Update Ticket", ...) called at
/usr/share/perl5/HTML/Mason/PSGIHandler.pm line 59
eval {...} called at /usr/share/perl5/HTML/Mason/PSGIHandler.pm line 59
HTML::Mason::PSGIHandler::invoke_mason(HTML::Mason::PSGIHandler::Streamy=HASH(0x55fc4d5ae0a8),
HASH(0x55fc4d9c9e38), HASH(0x55fc4d9b4de8)) called at
/usr/share/perl5/HTML/Mason/PSGIHandler/Streamy.pm line 52
HTML::Mason::PSGIHandler::Streamy::__ANON__(CODE(0x55fc4d9b4ba8))
called at /usr/share/perl5/Plack/Util.pm line 339
Plack::Util::__ANON__(CODE(0x55fc4dcc5180)) called at
/usr/share/perl5/Starlet/Server.pm line 377
Starlet::Server::handle_connection(Plack::Handler::Starlet=HASH(0x55fc4d79b858),
HASH(0x55fc4da86f38), IO::Socket::INET=GLOB(0x55fc4d9c9b80),
CODE(0x55fc4d353d00), "", "", "") called at /usr/share/perl5/Starlet/Server.pm
line 190
Starlet::Server::accept_loop(Plack::Handler::Starlet=HASH(0x55fc4d79b858),
CODE(0x55fc4d353d00), 100) called at /usr/share/perl5/Plack/Handler/Starlet.pm
line 80
Plack::Handler::Starlet::run(Plack::Handler::Starlet=HASH(0x55fc4d79b858),
CODE(0x55fc4d353d00)) called at /usr/share/perl5/Plack/Loader.pm line 84
Plack::Loader::run(Plack::Loader=HASH(0x55fc4d45ee08),
Plack::Handler::Starlet=HASH(0x55fc4d79b858)) called at
/usr/share/perl5/Plack/Runner.pm line 277
Plack::Runner::run(RT::PlackRunner=HASH(0x55fc46c5af10)) called at
/opt/rt/sbin/../lib/RT/PlackRunner.pm line 141
eval {...} called at /opt/rt/sbin/../lib/RT/PlackRunner.pm line 141
RT::PlackRunner::run(RT::PlackRunner=HASH(0x55fc46c5af10)) called at
/opt/rt/sbin/rt-server line 162 (/usr/share/perl/5.24/Carp.pm:170)
[21140] [Mon Jan 2 16:03:38 2017] [warning]: Rollback and commit are mixed
while escaping nested transaction at
/usr/share/perl5/DBIx/SearchBuilder/Handle.pm line 845.
(/usr/share/perl5/DBIx/SearchBuilder/Handle.pm:845)
[21131] [Mon Jan 2 16:03:38 2017] [info]:
<rt-4.4.1-21131-1483373018-15.1-1...@example.com> not sending to
root@localhost, creator of the transaction, due to NotifyActor setting
(/opt/rt/sbin/../lib/RT/Action/SendEmail.pm:901)
PS: I reported this problem already on https://issues.bestpractical.com/:
#32381: RT 4.4 database deadlock during comment/correspondence + owner
change together
--
Zito
