[rt-users] RT 4.2.10 crash

Thu Jun 4 04:32:35 EDT 2015

Hi all,
I have recently implemented approvals for one queue in our RT (v4.2.10).

I am experiencing a crash, and I cannot find the reason for it.
As soon as the approver approves a ticket, he gets an error message (see attached image001.png).

The log is not very clear (not for me at least) on the reason for the crash.

Here is an excerpt of the log just around the crash:

[25336] [Wed Jun  3 15:14:27 2015] [debug]: Found 3 scrips for TransactionBatch stage with applicable type(s) Status for txn #1533997 on ticket #105388 (/opt/rt4/sbin/../lib/RT/Scrips.pm:477)
[25336] [Wed Jun  3 15:14:27 2015] [debug]: Skipping Scrip #50 because it isn't applicable (/opt/rt4/sbin/../lib/RT/Scrips.pm:337)
[25336] [Wed Jun  3 15:14:27 2015] [info]: -- Scrip 6 -- ((eval 694):1)
[25336] [Wed Jun  3 15:14:27 2015] [debug]: Skipping Scrip #6 because it isn't applicable (/opt/rt4/sbin/../lib/RT/Scrips.pm:337)
[25336] [Wed Jun  3 15:14:27 2015] [info]: -- Scrip 10 -- ((eval 695):1)
[25336] [Wed Jun  3 15:14:27 2015] [debug]: Skipping Scrip #10 because it isn't applicable (/opt/rt4/sbin/../lib/RT/Scrips.pm:337)
[25336] [Wed Jun  3 15:14:27 2015] [debug]: Found 3 scrips for TransactionBatch stage with applicable type(s) Comment for txn #1533993 on ticket #105388 (/opt/rt4/sbin/../lib/RT/Scrips.pm:477)
[25336] [Wed Jun  3 15:14:27 2015] [debug]: Skipping Scrip #50 because it isn't applicable (/opt/rt4/sbin/../lib/RT/Scrips.pm:337)
[25336] [Wed Jun  3 15:14:27 2015] [info]: -- Scrip 6 -- ((eval 696):1)
[25336] [Wed Jun  3 15:14:27 2015] [debug]: Skipping Scrip #6 because it isn't applicable (/opt/rt4/sbin/../lib/RT/Scrips.pm:337)
[25336] [Wed Jun  3 15:14:27 2015] [info]: -- Scrip 10 -- ((eval 697):1)
[25336] [Wed Jun  3 15:14:27 2015] [debug]: Skipping Scrip #10 because it isn't applicable (/opt/rt4/sbin/../lib/RT/Scrips.pm:337)
[25336] [Wed Jun  3 15:14:27 2015] [debug]: Found 3 scrips for TransactionBatch stage with applicable type(s) Comment for txn #1533994 on ticket #105388 (/opt/rt4/sbin/../lib/RT/Scrips.pm:477)
[25336] [Wed Jun  3 15:14:27 2015] [debug]: Skipping Scrip #50 because it isn't applicable (/opt/rt4/sbin/../lib/RT/Scrips.pm:337)
[25336] [Wed Jun  3 15:14:27 2015] [info]: -- Scrip 6 -- ((eval 698):1)
[25336] [Wed Jun  3 15:14:27 2015] [debug]: Skipping Scrip #6 because it isn't applicable (/opt/rt4/sbin/../lib/RT/Scrips.pm:337)
[25336] [Wed Jun  3 15:14:27 2015] [info]: -- Scrip 10 -- ((eval 699):1)
[25336] [Wed Jun  3 15:14:27 2015] [debug]: Skipping Scrip #10 because it isn't applicable (/opt/rt4/sbin/../lib/RT/Scrips.pm:337)
[25336] [Wed Jun  3 15:14:27 2015] [error]: Died at /opt/rt4/sbin/../lib/RT/Rule.pm line 100.

Stack:
  [/opt/rt4/sbin/../lib/RT/Rule.pm:100]
  [/opt/rt4/sbin/../lib/RT/Approval/Rule/Passed.pm:104]
  [/opt/rt4/sbin/../lib/RT/Ruleset.pm:73]
  [/opt/rt4/sbin/../lib/RT/Transaction.pm:212]
  [/opt/rt4/sbin/../lib/RT/Record.pm:1693]
  [/opt/rt4/sbin/../lib/RT/Ticket.pm:2696]
  [/opt/rt4/sbin/../lib/RT/Ticket.pm:2398]
  [/opt/rt4/sbin/../lib/RT/Ticket.pm:2348]
  [/opt/rt4/share/html/Approvals/index.html:86]
  [/opt/rt4/share/html/Approvals/autohandler:53]
  [/opt/rt4/sbin/../lib/RT/Interface/Web.pm:681]
  [/opt/rt4/sbin/../lib/RT/Interface/Web.pm:369]
  [/opt/rt4/share/html/autohandler:53] (/opt/rt4/sbin/../lib/RT/Interface/Web/Handler.pm:208)
[25336] [Wed Jun  3 15:14:27 2015] [warning]: Rollback and commit are mixed while escaping nested transaction at /usr/local/share/perl5/DBIx/SearchBuilder/Handle.pm line 848. (/usr/local/share/perl5/DBIx/SearchBuilder/Handle.pm:848)
[25336] [Wed Jun  3 15:14:27 2015] [critical]: Transaction not committed. Usually indicates a software fault.Data loss may have occurred (/opt/rt4/sbin/../lib/RT/Interface/Web/Handler.pm:168)

I found evidence of some problems in a scrip a little earlier in the log:
[25227] [Wed Jun  3 13:49:47 2015] [info]: -- Scrip 21 -- ((eval 790):1)
[25227] [Wed Jun  3 13:49:47 2015] [warning]: Use of uninitialized value $principal in pattern match (m//) at /opt/rt4/sbin/../lib/RT/Group.pm line 1155. (/opt/rt4/sbin/../lib/RT/Group.pm:1153)
[25227] [Wed Jun  3 13:49:47 2015] [error]: Group::HasMember was called with an argument that isn't an RT::Principal or id. It's (undefined) (/opt/rt4/sbin/../lib/RT/Group.pm:1158)
[25227] [Wed Jun  3 13:49:47 2015] [warning]: Use of uninitialized value $principal in pattern match (m//) at /opt/rt4/sbin/../lib/RT/Group.pm line 1155. (/opt/rt4/sbin/../lib/RT/Group.pm:1153)
[25227] [Wed Jun  3 13:49:47 2015] [error]: Group::HasMember was called with an argument that isn't an RT::Principal or id. It's (undefined) (/opt/rt4/sbin/../lib/RT/Group.pm:1158)
[25227] [Wed Jun  3 13:49:47 2015] [warning]: Use of uninitialized value $principal in pattern match (m//) at /opt/rt4/sbin/../lib/RT/Group.pm line 1155. (/opt/rt4/sbin/../lib/RT/Group.pm:1153)
[25227] [Wed Jun  3 13:49:47 2015] [error]: Group::HasMember was called with an argument that isn't an RT::Principal or id. It's (undefined) (/opt/rt4/sbin/../lib/RT/Group.pm:1158)
[25227] [Wed Jun  3 13:49:47 2015] [warning]: Use of uninitialized value $addr in concatenation (.) or string at (eval 790) line 54. ((eval 790):54)
[25227] [Wed Jun  3 13:49:47 2015] [warning]: Use of uninitialized value $Principal in concatenation (.) or string at (eval 790) line 54. ((eval 790):54)
[25227] [Wed Jun  3 13:49:47 2015] [error]: Scrip:AddWatchersOnCorrespond: Failed to add new Cc watcher to ticket #105369:  (#) - One, and only one, of PrincipalId/User/Group is required ((eval 790):54)

However, this was an earlier instance of the error. After that, I tried to disable scrip 21 (AddWatchersOnCorrespond) but the approver got the error again.

I am attaching the complete log related to the latest instance of the error.

I would be extremely grateful if someone could shed some light on the problem, especially since I am somewhat scared that we're corrupting our data.

Thank you in advance.
Cris

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.bestpractical.com/pipermail/rt-users/attachments/20150604/786ea99b/attachment.htm>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: image001.png
Type: image/png
Size: 13343 bytes
Desc: image001.png
URL: <http://lists.bestpractical.com/pipermail/rt-users/attachments/20150604/786ea99b/attachment.png>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: rt_debug_log.zip
Type: application/x-zip-compressed
Size: 5060 bytes
Desc: rt_debug_log.zip
URL: <http://lists.bestpractical.com/pipermail/rt-users/attachments/20150604/786ea99b/attachment.bin>