Errors when trying to "Approve All"

gistfile1

INFO  01:26:06 ubuntu rails[8959]: Started PUT "/po_hdrs/000000000022151" for 127.0.0.1 at 2013-06-26 01:26:06 -0400
INFO  01:26:06 ubuntu controllers[8959]: Processing by PoHdrsController#update as JSON
INFO  01:26:06 ubuntu controllers[8959]:   Parameters: {"utf8"=>"✓", "authenticity_token"=>"oyX4cWhEcmUGc8oChYViZ8MqjHp3bfuwxxSjsv3Lr9c=", "po_hdr"=>{"approved"=>"1"}, "id"=>"000000000022151"}
DEBUG 01:26:06 ubuntu models[8959]:   User Load (91.5ms)  EXEC sp_executesql N'SELECT TOP (1) [users].* FROM [users] WHERE [users].[id] = 6'
DEBUG 01:26:06 ubuntu models[8959]:   Role Load (87.6ms)  EXEC sp_executesql N'SELECT TOP (1) [roles].* FROM [roles] INNER JOIN [user_roles] ON [roles].[id] = [user_roles].[role_id] WHERE [user_roles].[user_id] = 6'
DEBUG 01:26:06 ubuntu models[8959]:   PoHdr Load (89.5ms)  EXEC sp_executesql N'SELECT TOP (1) [dbo].[POHDRF00].po_no FROM [dbo].[POHDRF00] LEFT OUTER JOIN [dbo].[POLINF00] ON [dbo].[POLINF00].[po_no] = [dbo].[POHDRF00].[po_no] WHERE [dbo].[POHDRF00].[po_no] = @0 GROUP BY [dbo].[POHDRF00].po_no', N'@0 char(15)', @0 = N'000000000022151'  [["po_no", "000000000022151"]]
DEBUG 01:26:06 ubuntu models[8959]:   SQL (340.2ms)  EXEC sp_executesql N'SELECT [dbo].[POHDRF00].[po_no] AS t0_r0, [dbo].[POHDRF00].[batch_no] AS t0_r1, [dbo].[POHDRF00].[usr_id] AS t0_r2, [dbo].[POHDRF00].[vend_no] AS t0_r3, [dbo].[POHDRF00].[alt_po_no] AS t0_r4, [dbo].[POHDRF00].[po_hdr_dat] AS t0_r5, [dbo].[POHDRF00].[alt_po_no_2] AS t0_r6, [dbo].[POHDRF00].[vend_nam] AS t0_r7, [dbo].[POHDRF00].[vend_loc_cod] AS t0_r8, [dbo].[POHDRF00].[vend_addr_1] AS t0_r9, [dbo].[POHDRF00].[vend_addr_2] AS t0_r10, [dbo].[POHDRF00].[vend_addr_3] AS t0_r11, [dbo].[POHDRF00].[vend_cntry] AS t0_r12, [dbo].[POHDRF00].[po_hdr_fob] AS t0_r13, [dbo].[POHDRF00].[po_hdr_ship_via] AS t0_r14, [dbo].[POHDRF00].[po_hdr_ord_by] AS t0_r15, [dbo].[POHDRF00].[po_hdr_spec_terms] AS t0_r16, [dbo].[POHDRF00].[po_hdr_deliv_to] AS t0_r17, [dbo].[POHDRF00].[confirm_flg] AS t0_r18, [dbo].[POHDRF00].[po_hdr_spec_msg] AS t0_r19, [dbo].[POHDRF00].[no_open_lins] AS t0_r20, [dbo].[POHDRF00].[no_clsd_lins] AS t0_r21, [dbo].[POHDRF00].[lst_chng_no] AS t0_r22, [dbo].[POHDRF00].[lst_chng_dat] AS t0_r23, [dbo].[POHDRF00].[lst_chng_user_id] AS t0_r24, [dbo].[POHDRF00].[po_hdr_prt_flg] AS t0_r25, [dbo].[POHDRF00].[po_hdr_cancel_flg] AS t0_r26, [dbo].[POHDRF00].[mult_drop_flg] AS t0_r27, [dbo].[POHDRF00].[blnkt_po_flg] AS t0_r28, [dbo].[POHDRF00].[blnkt_rel_no] AS t0_r29, [dbo].[POHDRF00].[blnkt_rel_dat] AS t0_r30, [dbo].[POHDRF00].[blnkt_rel_prd] AS t0_r31, [dbo].[POHDRF00].[blnkt_rel_no_prds] AS t0_r32, [dbo].[POHDRF00].[bill_vend_no] AS t0_r33, [dbo].[POHDRF00].[currency_cod] AS t0_r34, [dbo].[POHDRF00].[po_verifd] AS t0_r35, [dbo].[POHDRF00].[po_hdr_sls_ord_no] AS t0_r36, [dbo].[POHDRF00].[timestamp] AS t0_r37, [dbo].[POHDRF00].[A4GLIdentity] AS t0_r38, [dbo].[POLINF00].[A4GLIdentity] AS t1_r0, [dbo].[POLINF00].[po_no] AS t1_r1, [dbo].[POLINF00].[lin_no] AS t1_r2, [dbo].[POLINF00].[item_no] AS t1_r3, [dbo].[POLINF00].[alt_po_no] AS t1_r4, [dbo].[POLINF00].[alt_lin_no] AS t1_r5, [dbo].[POLINF00].[alt_item_no_1] AS t1_r6, [dbo].[POLINF00].[vend_no] AS t1_r7, [dbo].[POLINF00].[lin_dat] AS t1_r8, [dbo].[POLINF00].[alt_po_no_1] AS t1_r9, [dbo].[POLINF00].[alt_lin_no_1] AS t1_r10, [dbo].[POLINF00].[alt_item_no_2] AS t1_r11, [dbo].[POLINF00].[alt_dat_2] AS t1_r12, [dbo].[POLINF00].[alt_vend_no_2] AS t1_r13, [dbo].[POLINF00].[alt_po_no_2] AS t1_r14, [dbo].[POLINF00].[alt_lin_no_2] AS t1_r15, [dbo].[POLINF00].[item_desc_1] AS t1_r16, [dbo].[POLINF00].[item_desc_2] AS t1_r17, [dbo].[POLINF00].[vend_item_no] AS t1_r18, [dbo].[POLINF00].[vend_item_desc_1] AS t1_r19, [dbo].[POLINF00].[vend_item_desc_2] AS t1_r20, [dbo].[POLINF00].[more_desc_flg] AS t1_r21, [dbo].[POLINF00].[wrksht_no] AS t1_r22, [dbo].[POLINF00].[our_unit] AS t1_r23, [dbo].[POLINF00].[vend_sell_unit] AS t1_r24, [dbo].[POLINF00].[vend_shp_unit] AS t1_r25, [dbo].[POLINF00].[our_conv] AS t1_r26, [dbo].[POLINF00].[vend_conv] AS t1_r27, [dbo].[POLINF00].[sell_shp_conv_flg] AS t1_r28, [dbo].[POLINF00].[qty_ord] AS t1_r29, [dbo].[POLINF00].[unit_prc] AS t1_r30, [dbo].[POLINF00].[deliv_loc_1] AS t1_r31, [dbo].[POLINF00].[deliv_loc_2] AS t1_r32, [dbo].[POLINF00].[deliv_loc_3] AS t1_r33, [dbo].[POLINF00].[deliv_loc_4] AS t1_r34, [dbo].[POLINF00].[deliv_dat_1] AS t1_r35, [dbo].[POLINF00].[deliv_dat_2] AS t1_r36, [dbo].[POLINF00].[deliv_dat_3] AS t1_r37, [dbo].[POLINF00].[deliv_dat_4] AS t1_r38, [dbo].[POLINF00].[deliv_qty_1] AS t1_r39, [dbo].[POLINF00].[deliv_qty_2] AS t1_r40, [dbo].[POLINF00].[deliv_qty_3] AS t1_r41, [dbo].[POLINF00].[deliv_qty_4] AS t1_r42, [dbo].[POLINF00].[deliv_expedite_day_1] AS t1_r43, [dbo].[POLINF00].[deliv_expedite_day_2] AS t1_r44, [dbo].[POLINF00].[deliv_expedite_day_3] AS t1_r45, [dbo].[POLINF00].[deliv_expedite_day_4] AS t1_r46, [dbo].[POLINF00].[deliv_recd_qty_1] AS t1_r47, [dbo].[POLINF00].[deliv_recd_qty_2] AS t1_r48, [dbo].[POLINF00].[deliv_recd_qty_3] AS t1_r49, [dbo].[POLINF00].[deliv_recd_qty_4] AS t1_r50, [dbo].[POLINF00].[deliv_clsd_flg_1] AS t1_r51, [dbo].[POLINF00].[deliv_clsd_flg_2] AS t1_r52, [dbo].[POLINF00].[deliv_clsd_flg_3] AS t1_r53, [dbo].[POLINF00].[deliv_clsd_flg_4] AS t1_r54, [dbo].[POLINF00].[abc_cod] AS t1_r55, [dbo].[POLINF00].[item_typ] AS t1_r56, [dbo].[POLINF00].[vend_item_flg] AS t1_r57, [dbo].[POLINF00].[lin_clsd_flg] AS t1_r58, [dbo].[POLINF00].[blnkt_tot_rel_qty] AS t1_r59, [dbo].[POLINF00].[no_lin_notes] AS t1_r60, [dbo].[POLINF00].[lst_notes_no] AS t1_r61, [dbo].[POLINF00].[edd_dat] AS t1_r62, [dbo].[POLINF00].[timestamp] AS t1_r63 FROM [dbo].[POHDRF00] LEFT OUTER JOIN [dbo].[POLINF00] ON [dbo].[POLINF00].[po_no] = [dbo].[POHDRF00].[po_no] WHERE [dbo].[POHDRF00].[po_no] = @0 AND [dbo].[POHDRF00].[po_no] IN (N''000000000022151'')', N'@0 char(15)', @0 = N'000000000022151'  [["po_no", "000000000022151"]]
DEBUG 01:26:07 ubuntu models[8959]:   PoLinx Load (98.3ms)  EXEC sp_executesql N'SELECT TOP (1) [dbo].[POLINX00].* FROM [dbo].[POLINX00] WHERE [dbo].[POLINX00].[po_lin_id] = 8914'
DEBUG 01:26:07 ubuntu models[8959]:   SQL (83.4ms)  BEGIN TRANSACTION
DEBUG 01:26:07 ubuntu models[8959]:    (87.4ms)  EXEC sp_executesql N'UPDATE [dbo].[POLINX00] SET [po_lin_aux_approved] = N''Y'' WHERE [dbo].[POLINX00].[A4GLIdentity] = 95; SELECT @@ROWCOUNT AS AffectedRows'
DEBUG 01:26:07 ubuntu models[8959]:   PoLin Load (104.4ms)  EXEC sp_executesql N'SELECT TOP (1) [dbo].[POLINF00].* FROM [dbo].[POLINF00] WHERE [dbo].[POLINF00].[A4GLIdentity] = 8914'
DEBUG 01:26:07 ubuntu models[8959]:   PoHdr Load (96.9ms)  EXEC sp_executesql N'SELECT TOP (1) [dbo].[POHDRF00].* FROM [dbo].[POHDRF00] WHERE [dbo].[POHDRF00].[po_no] = N''000000000022151'''
DEBUG 01:26:07 ubuntu models[8959]:   PoLin Load (114.9ms)  EXEC sp_executesql N'SELECT [dbo].[POLINF00].* FROM [dbo].[POLINF00] WHERE [dbo].[POLINF00].[po_no] = N''000000000022151'''
DEBUG 01:26:07 ubuntu models[8959]:   PoLinx Load (90.9ms)  EXEC sp_executesql N'SELECT TOP (1) [dbo].[POLINX00].* FROM [dbo].[POLINX00] WHERE [dbo].[POLINX00].[po_lin_id] = 8914'
DEBUG 01:26:07 ubuntu models[8959]:   PoLinx Load (92.1ms)  EXEC sp_executesql N'SELECT TOP (1) [dbo].[POLINX00].* FROM [dbo].[POLINX00] WHERE [dbo].[POLINX00].[po_lin_id] = 8915'
DEBUG 01:26:07 ubuntu models[8959]:   CACHE (0.0ms)  SELECT @@TRANCOUNT
DEBUG 01:26:07 ubuntu models[8959]:   CACHE (0.0ms)  SELECT @@TRANCOUNT
DEBUG 01:26:07 ubuntu models[8959]:   SQL (101.0ms)  COMMIT TRANSACTION
DEBUG 01:26:07 ubuntu models[8959]:   CACHE (0.0ms)  SELECT TOP (1) [dbo].[POLINX00].* FROM [dbo].[POLINX00] WHERE [dbo].[POLINX00].[po_lin_id] = 8915
INFO  01:26:07 ubuntu controllers[8959]: Completed 500 Internal Server Error in 1624ms
FATAL 01:26:08 ubuntu rails[8959]: 
RuntimeError (expected po_linx):
  app/models/po_lin.rb:78:in `approve!'
  app/controllers/po_hdrs_controller.rb:67:in `update'

I've been trying to recreate this error, but it always either works or gets a DB timeout. Any ideas?