[freeside-users] Error with 1.9cvs continues
Timothy Butkiewicz
tbutkiewicz at cybermind.biz
Mon Jan 5 12:30:33 PST 2009
Still having problems with the CVS (hold the flames - I know I know this
is CVS and not stable). None the less it was working great up to a month
or so ago. Now when we try and pull up customers who have a long history
of invoices etc with us - it takes hours to display the customer, if the
customer gets displayed at all.
I have been refreshing our copy of the 1.9 with the CVS copy
periodically, hopefully to pick up bug fixes etc. It seems that this
problem crept up in one of our refreshes.
Our setup -
Freeside 1.9.0cvs (as of and up to 1.5.2009)
Apache 2 (started with Apache1, went to Apache2 no real change)
Postgres 8.3.5 (Started with 8.1.x, went to 8.3.5 no real change)
Fedora Core 3 box
Latest DBIx::SearchBuilder (1.54)
Here's what I see process wise:
postgres 11603 0.0 0.8 378476 7644 ? S Jan02 0:16
/usr/bin/postmaster -p 5432 -D /var/lib/pgsql/data
postgres 11607 0.0 0.2 9736 2168 ? Ss Jan02 0:00 postgres:
logger process
postgres 11615 0.0 2.8 378796 25576 ? Ss Jan02 0:03 postgres:
writer process
postgres 11616 0.0 0.8 378656 7656 ? Ss Jan02 0:01 postgres:
wal writer process
postgres 11617 0.0 0.8 379044 8000 ? Ss Jan02 0:12 postgres:
autovacuum launcher process
postgres 11618 0.0 0.2 10132 2476 ? Ss Jan02 1:14 postgres:
stats collector process
postgres 2491 6.9 2.1 381000 19872 ? Ss 13:14 9:02 postgres:
freeside freeside [local] SELECT waiting
postgres 2519 6.5 2.1 381000 19872 ? Ss 13:16 8:21 postgres:
freeside freeside [local] SELECT waiting
postgres 2615 5.4 2.1 381000 19872 ? Ss 13:26 6:27 postgres:
freeside freeside [local] idle in transaction
postgres 2623 5.1 2.1 380988 19916 ? Ss 13:28 6:00 postgres:
freeside freeside [local] SELECT waiting
postgres 2747 9.9 2.9 380980 26812 ? Ss 13:38 10:37 postgres:
freeside freeside [local] idle
postgres 2945 10.1 2.9 380980 26596 ? Rs 13:58 8:44 postgres:
freeside freeside [local] idle in transaction
postgres 3620 0.7 1.9 381136 17800 ? Ss 15:09 0:06 postgres:
freeside freeside [local] idle
postgres 3652 0.0 1.6 380432 14740 ? Ss 15:11 0:00 postgres:
freeside freeside [local] idle
postgres 3655 0.0 1.4 380352 12748 ? Ss 15:11 0:00 postgres:
freeside freeside [local] idle
postgres 3658 0.0 1.1 379664 10612 ? Ss 15:11 0:00 postgres:
freeside freeside [local] idle
postgres 3659 0.8 1.9 381136 17800 ? Ss 15:11 0:06 postgres:
freeside freeside [local] idle
postgres 3698 0.0 1.3 380352 12624 ? Ss 15:16 0:00 postgres:
freeside freeside [local] idle
postgres 3704 0.0 1.3 380352 12624 ? Ss 15:17 0:00 postgres:
freeside freeside [local] idle
Here's some output from psql - appears that the queries are getting hung
up on the "SELECT * FROM cust_main WHERE custnum = $1 FOR UPDATE"
Now this really isn't an active system - I will have between 2 and at
max 5 people looking up customers at any given time. They use the system
casual to moderate.
freeside=> SELECT datname,procpid,current_query FROM pg_stat_activity;
datname | procpid | current_query
----------+---------+---------------------------------------------------
----------
freeside | 3550 | <IDLE> in transaction
freeside | 2623 | SELECT * FROM cust_main WHERE custnum = $1 FOR
UPDATE
freeside | 3547 | <IDLE> in transaction
freeside | 2519 | SELECT * FROM cust_main WHERE custnum = $1 FOR
UPDATE
freeside | 3551 | <IDLE>
freeside | 3300 | <IDLE>
freeside | 2491 | <IDLE> in transaction
freeside | 3548 | <IDLE>
freeside | 2615 | SELECT * FROM cust_main WHERE custnum = $1 FOR
UPDATE
freeside | 2945 | SELECT * FROM cust_main WHERE custnum = $1 FOR
UPDATE
freeside | 2747 | SELECT * FROM cust_bill_pay WHERE paynum = $1
freeside | 3480 | <IDLE> in transaction
freeside | 3453 | <IDLE>
freeside | 3455 | SELECT datname,procpid,current_query FROM
pg_stat_activity;
(14 rows)
Pulling up customers with minimal to standard invoice and payment
history happens pretty quick - in a time frame to be expected -
customers with longer invoice and payment history is where we find the
problem.
I have updated the bejeebees out of the system - tuning pacahe and
postgres, refreshing cpan modules, updating cvs copies and can't seem to
get around the slowness issue.
Am I misisng an index? Are their queries to be optimized? Staff is
getting pretty antzy as there are some folks they just can't pull up.
Thank you in advance for any and all assistance you can provide.
-Timothy
Some more psql snapshots (these were taken now - interval every couple
seconds)
freeside=> SELECT datname,procpid,current_query FROM pg_stat_activity;
datname | procpid | current_query
----------+---------+---------------------------------------------------
----------
freeside | 3652 | <IDLE>
freeside | 2623 | SELECT * FROM cust_main WHERE custnum = $1 FOR
UPDATE
freeside | 3655 | <IDLE>
freeside | 2519 | SELECT * FROM cust_main WHERE custnum = $1 FOR
UPDATE
freeside | 3659 | <IDLE>
freeside | 3698 | <IDLE>
freeside | 2491 | <IDLE> in transaction
freeside | 3620 | <IDLE>
freeside | 2615 | SELECT * FROM cust_main WHERE custnum = $1 FOR
UPDATE
freeside | 2945 | SELECT * FROM conf WHERE ( agentnum IS NULL ) AND
name = $1
freeside | 2747 | <IDLE>
freeside | 3704 | <IDLE>
freeside | 3864 | SELECT datname,procpid,current_query FROM
pg_stat_activity;
freeside | 3658 | <IDLE>
(14 rows)
freeside | 3652 | <IDLE>
freeside | 2623 | SELECT * FROM cust_main WHERE custnum = $1 FOR
UPDATE
freeside | 3655 | <IDLE>
freeside | 2519 | SELECT part_event.* FROM part_event CROSS JOIN
cust_pkg LEFT JOIN cust_main USING ( custnum ) LEFT JOIN
part_event_condition AS cond_balance_age ON ( part_event.eventpart =
cond_balance_age.eventpart AND cond_balance_age.conditionname =
'balance_age' ) LEFT JOIN part_event_condition AS cond_cust_status
ON ( part_event.eventpart = cond_cust_status.eventpart AND
cond_cust_status.conditionname = 'cust_status' ) LEFT JOIN
part_event_condition AS cond_pkg_age ON ( part_event.eventpart =
cond_pkg_age.eventpart AND cond_pkg_age.conditionname = 'pkg_age'
) LEFT JOIN part_event_condition AS cond_has_referral_custnum ON (
part_event.eventpart = cond_has_referral_custnum.eventpart AND
cond_has_referral_custnum.conditionname = 'has_referral_custnum' )
LEFT JOIN part_event_condition AS cond_pkg_class ON (
part_event.eventpart = cond_pkg_class.eventpart AND
cond_pkg_class.conditionname = 'pkg_class' ) LEFT JOIN
part_event_condition AS cond_balance_under ON ( part_eve
freeside | 3659 | <IDLE>
freeside | 3698 | <IDLE>
freeside | 2491 | <IDLE>
freeside | 3620 | <IDLE>
freeside | 2615 | SELECT * FROM cust_main WHERE custnum = $1 FOR
UPDATE
freeside | 2945 | <IDLE> in transaction
freeside | 2747 | <IDLE>
freeside | 3704 | <IDLE>
freeside | 3864 | SELECT datname,procpid,current_query FROM
pg_stat_activity;
freeside | 3658 | <IDLE>
(14 rows)
freeside=> SELECT datname,procpid,current_query FROM pg_stat_activity;
datname | procpid | current_query
----------+---------+---------------------------------------------------
----------
freeside | 3652 | <IDLE>
freeside | 2623 | SELECT * FROM cust_main WHERE custnum = $1 FOR
UPDATE
freeside | 3655 | <IDLE>
freeside | 2519 | <IDLE> in transaction
freeside | 3659 | <IDLE>
freeside | 3698 | <IDLE>
freeside | 2491 | SELECT * FROM cust_main WHERE custnum = $1 FOR
UPDATE
freeside | 3620 | <IDLE>
freeside | 2615 | SELECT * FROM cust_main WHERE custnum = $1 FOR
UPDATE
freeside | 2945 | SELECT * FROM cust_bill_pay WHERE paynum = $1
freeside | 2747 | <IDLE>
freeside | 3704 | <IDLE>
freeside | 3864 | SELECT datname,procpid,current_query FROM
pg_stat_activity;
freeside | 3658 | <IDLE>
(14 rows)
freeside | 3652 | <IDLE>
freeside | 2623 | SELECT * FROM cust_main WHERE custnum = $1 FOR
UPDATE
freeside | 3655 | <IDLE>
freeside | 2519 | SELECT part_event.* FROM part_event CROSS JOIN
cust_bill LEFT JOIN cust_main USING ( custnum ) LEFT JOIN
part_event_condition AS cond_balance_age ON ( part_event.eventpart =
cond_balance_age.eventpart AND cond_balance_age.conditionname =
'balance_age' ) LEFT JOIN part_event_condition AS
cond_cust_bill_owed ON ( part_event.eventpart =
cond_cust_bill_owed.eventpart AND
cond_cust_bill_owed.conditionname = 'cust_bill_owed' ) LEFT JOIN
part_event_condition AS cond_cust_status ON ( part_event.eventpart =
cond_cust_status.eventpart AND cond_cust_status.conditionname =
'cust_status' ) LEFT JOIN part_event_condition AS
cond_has_referral_custnum ON ( part_event.eventpart =
cond_has_referral_custnum.eventpart AND
cond_has_referral_custnum.conditionname = 'has_referral_custnum' )
LEFT JOIN part_event_condition AS cond_balance_under ON (
part_event.eventpart = cond_balance_under.eventpart AND
cond_balance_under.conditionname = 'balance_under' ) LEFT JOIN
part_event_c
freeside | 3659 | <IDLE>
freeside | 3698 | <IDLE>
freeside | 2491 | SELECT * FROM cust_main WHERE custnum = $1 FOR
UPDATE
freeside | 3620 | <IDLE>
freeside | 2615 | SELECT * FROM cust_main WHERE custnum = $1 FOR
UPDATE
freeside | 2945 | <IDLE> in transaction
freeside | 2747 | <IDLE>
freeside | 3704 | <IDLE>
freeside | 3864 | SELECT datname,procpid,current_query FROM
pg_stat_activity;
freeside | 3658 | <IDLE>
(14 rows)
freeside | 3652 | <IDLE>
freeside | 2623 | SELECT * FROM cust_main WHERE custnum = $1 FOR
UPDATE
freeside | 3655 | <IDLE>
freeside | 2519 | SELECT part_event.* FROM part_event CROSS JOIN
cust_main LEFT JOIN part_event_condition AS cond_balance_age ON (
part_event.eventpart = cond_balance_age.eventpart AND
cond_balance_age.conditionname = 'balance_age' ) LEFT JOIN
part_event_condition AS cond_cust_status ON ( part_event.eventpart =
cond_cust_status.eventpart AND cond_cust_status.conditionname =
'cust_status' ) LEFT JOIN part_event_condition AS
cond_has_referral_custnum ON ( part_event.eventpart =
cond_has_referral_custnum.eventpart AND
cond_has_referral_custnum.conditionname = 'has_referral_custnum' )
LEFT JOIN part_event_condition AS cond_balance_under ON (
part_event.eventpart = cond_balance_under.eventpart AND
cond_balance_under.conditionname = 'balance_under' ) LEFT JOIN
part_event_condition AS cond_once ON ( part_event.eventpart =
cond_once.eventpart AND cond_once.conditionname = 'once' )
LEFT JOIN part_event_condition AS cond_dundate ON (
part_event.eventpart = cond_dundate.eventpart
freeside | 3659 | <IDLE>
freeside | 3698 | <IDLE>
freeside | 2491 | SELECT * FROM cust_main WHERE custnum = $1 FOR
UPDATE
freeside | 3620 | <IDLE>
freeside | 2615 | SELECT * FROM cust_main WHERE custnum = $1 FOR
UPDATE
freeside | 2945 | SELECT * FROM cust_pay_refund WHERE paynum = $1
freeside | 2747 | <IDLE>
freeside | 3704 | <IDLE>
freeside | 3864 | SELECT datname,procpid,current_query FROM
pg_stat_activity;
freeside | 3658 | <IDLE>
(14 rows)
freeside=> SELECT datname,procpid,current_query FROM pg_stat_activity;
datname | procpid | current_query
----------+---------+---------------------------------------------------
----------
freeside | 3652 | <IDLE>
freeside | 2623 | SELECT * FROM cust_main WHERE custnum = $1 FOR
UPDATE
freeside | 3655 | <IDLE>
freeside | 2519 | <IDLE> in transaction
freeside | 3659 | <IDLE>
freeside | 3698 | <IDLE>
freeside | 2491 | SELECT * FROM cust_main WHERE custnum = $1 FOR
UPDATE
freeside | 3620 | <IDLE>
freeside | 2615 | SELECT * FROM cust_main WHERE custnum = $1 FOR
UPDATE
freeside | 2945 | SELECT * FROM conf WHERE ( agentnum IS NULL ) AND
name = $1
freeside | 2747 | <IDLE>
freeside | 3704 | <IDLE>
freeside | 3864 | SELECT datname,procpid,current_query FROM
pg_stat_activity;
freeside | 3658 | <IDLE>
(14 rows)
More information about the freeside-users
mailing list