Delete record counting problems

[patrickzurek]

JIRA issue created by: rcook Originally opened: 2012-03-16 03:00 PM

Issue body: (nt)

[patrickzurek]

JIRA Coment by user: rcook JIRA Timestamp: 2012-03-16 03:00 PM

Comment body:

From email

From: John Brand [mailto:john.f.brand@gmail.com] Sent: Friday, March 16, 2012 8:28 AM To: Cook, Randall Subject: Fwd: fb 730

You have reminded me there is an issue with record counting regarding deleted record processing and record counts. I believe the summary information is accurate but it derives and displays the counts based on the query below (highlighted in red).

I don't recall if there is an open FB issue around this. I tried to find one briefly, and did not succeed.

This was complicated, and having been away from it for a while, I am not sure how well I can even describe the issue but I summarized it pretty well below. ---------- Forwarded message ---------- From: John Brand john.f.brand@gmail.com Date: Thu, Sep 1, 2011 at 10:56 AM Subject: Re: fb 730 To: "Anderson, Benjamin D" banderson@library.rochester.edu

Yeah, I figured you would not. LOL. Actually this is quite complex.

My record counts I displayed and used for rules calculations were not quite right in regards to holdings. Just trying to come up with a way to get accurate numbers. The totals you display in a log seem accurate but are based on a db query:

the command run by RepositoryDAO to determine record count totals:

mysql -u root --password=root -D xc_marctoxctransformation -e "select rs.set_id type, r.status status, count(*) c from record_sets rs, records r where r.record_id = rs.record_id group by rs.set_id, r.status" +------+--------+----------+ | type | status | c | +------+--------+----------+ | 8 | A | 11038699 | | 8 | H | 10931 | +------+--------+----------+

I get counts out of xc_marctoxctransformation.outgoing_record_counts. Within this there is not a total of 10931 because of records deleted during T2, I guess I need to do some additional figuring to get the correct 'totals' to use for rules calculations.

Questions:

1) I should be operating out of the record_counts tables, right? not directly looking at records? 2) I need to develop an accurate 'rule' to get the correct total.

I used 11,055 - that did not account for the 124 that were held, now active?, so the real number is 10,931. So the rule that works 'this' time is:

new_held_cnt - upd_active_prev_held_cnt

Below is the snippet of the 247 transformation log.

outgoing all time work new_act_cnt: 2,808,321 new_held_cnt: 0 new_del_cnt: 0 outgoing all time work upd_act_cnt: 0 upd_held_cnt: 0 upd_del_cnt: 0 outgoing all time work upd_act_prev_act_cnt: 0 upd_act_prev_held_cnt: 0 upd_act_prev_del_cnt: 0 outgoing all time work upd_held_prev_act_cnt: 0 upd_held_prev_held_cnt: 0 upd_held_prev_del_cnt: 0 outgoing all time work upd_del_prev_act_cnt: 0 upd_del_prev_held_cnt: 0 upd_del_prev_del_cnt: 0 outgoing all time holdings new_act_cnt: 2,791,319 new_held_cnt: 11,055 new_del_cnt: 0 outgoing all time holdings upd_act_cnt: 124 upd_held_cnt: 0 upd_del_cnt: 0 outgoing all time holdings upd_act_prev_act_cnt: 0 upd_act_prev_held_cnt: 124 upd_act_prev_del_cnt: 0 outgoing all time holdings upd_held_prev_act_cnt: 0 upd_held_prev_held_cnt: 0 upd_held_prev_del_cnt: 0 outgoing all time holdings upd_del_prev_act_cnt: 0 upd_del_prev_held_cnt: 0 upd_del_prev_del_cnt: 0 outgoing all time expression new_act_cnt: 2,808,321 new_held_cnt: 0 new_del_cnt: 0 outgoing all time expression upd_act_cnt: 0 upd_held_cnt: 0 upd_del_cnt: 0 outgoing all time expression upd_act_prev_act_cnt: 0 upd_act_prev_held_cnt: 0 upd_act_prev_del_cnt: 0 outgoing all time expression upd_held_prev_act_cnt: 0 upd_held_prev_held_cnt: 0 upd_held_prev_del_cnt: 0 outgoing all time expression upd_del_prev_act_cnt: 0 upd_del_prev_held_cnt: 0 upd_del_prev_del_cnt: 0 outgoing all time manifestation new_act_cnt: 2,630,614 new_held_cnt: 0 new_del_cnt: 0 outgoing all time manifestation upd_act_cnt: 0 upd_held_cnt: 0 upd_del_cnt: 0 outgoing all time manifestation upd_act_prev_act_cnt: 0 upd_act_prev_held_cnt: 0 upd_act_prev_del_cnt: 0 outgoing all time manifestation upd_held_prev_act_cnt: 0 upd_held_prev_held_cnt: 0 upd_held_prev_del_cnt: 0 outgoing all time manifestation upd_del_prev_act_cnt: 0 upd_del_prev_held_cnt: 0 upd_del_prev_del_cnt: 0 outgoing all time TOTALS new_act_cnt: 11,038,575 new_held_cnt: 11,055 new_del_cnt: 0 outgoing all time TOTALS upd_act_cnt: 124 upd_held_cnt: 0 upd_del_cnt: 0 outgoing all time TOTALS upd_act_prev_act_cnt: 0 upd_act_prev_held_cnt: 124 upd_act_prev_del_cnt: 0 outgoing all time TOTALS upd_held_prev_act_cnt: 0 upd_held_prev_held_cnt: 0 upd_held_prev_del_cnt: 0 outgoing all time TOTALS upd_del_prev_act_cnt: 0 upd_del_prev_held_cnt: 0 upd_del_prev_del_cnt: 0 29 Aug 2011 20:28:39,870 INFO [SERVICE_17253] - e-active: 2,808,321 h-active: 2,791,443 h-held: 10,931 m-active: 2,630,614 w-active: 2,808,321 total-active: 11,038,699 total-held: 10,931

On Thu, Sep 1, 2011 at 10:38 AM, Anderson, Benjamin D banderson@library.rochester.edu wrote: don’t understand

From: John Brand [mailto:john.f.brand@gmail.com] Sent: Thursday, September 01, 2011 10:34 AM To: Anderson, Benjamin D Subject: Re: fb 730

I need to ask your opinion on this. I noticed you get the totals for record counts via a database query instead of from the record_counts tables. I believe for the rules, I really need to be using the record_counts tables, so I need to adjust some formulas to account for deleted documents. Agree? Don't understand the issue? Or 'other?' On Tue, Aug 30, 2011 at 12:33 PM, John Brand john.f.brand@gmail.com wrote: Yes, 10,931 is correct. My rules value is incorrect. Bug. Thank you.

On Tue, Aug 30, 2011 at 9:41 AM, Cook, Randall rcook@library.rochester.edu wrote: John,

According to the log, we had 124 previously held records that have been switched to active and we processed 11, 055 new held records for a total held record count of 10,931. The status facet also shows 10,931. Can you confirm as the number is different than your “pass/fail rule�? Also, I think this run was a single large batch, T0 right? Are these 124 records that were marked held and then moved to active as the result of service processing of the batch, as opposed to the “net result� of running the batch? I was thinking that it was the net effect, but maybe that is not a correct understanding. Just wanting to understand how it works. Thanks.

[patrickzurek]

JIRA Coment by user: rcook JIRA Timestamp: 2012-03-21 04:38 PM

Comment body:

Is this related to MST-448 or similar enough that it should be fixed at the same time?

[patrickzurek]

JIRA Comment by user: Chris Delis (cedelis) JIRA Timestamp: 2012-03-21 04:59 PM

Comment body:

My gut tells me that it is probably related. I think it makes sense to proceed with 1046 first and see if fixing it has any impact on these totals. The one thing about 1046 that concerns me is not so much the difficulty in solving it (in and of itself), but the potential of it affecting other totals. And since I haven't yet delved deeply into the statistics portion of the MST code, I am probably not the best person to notice all the unintended consequences. Do there already exist regression tests that verify record totals?

[patrickzurek]

JIRA Coment by user: jbrand JIRA Timestamp: 2012-03-21 06:23 PM

Comment body:

There is this:

branches\marc_agg\mst-service\custom\MARCToXCTransformation\test\mock_harvest_input\recordCounts

but I am not sure how comprehensive it is.

For instance there is no corresponding directory in mock_harvest_expected_output.

Regarding Chris's statement: "I think it makes sense to proceed with 1046 first and see if fixing it has any impact on these totals. "

I totally agree with this approach. It makes a whole bunch of sense.

[patrickzurek]

JIRA Comment by user: Chris Delis (cedelis) JIRA Timestamp: 2012-04-06 05:04 PM

Comment body:

Can someone tell me what the difference between this issue and 1046? Also, what does "Delete" have to do with this?

I'm working on creating a tiny repo that replicates these accounting issues, but I'm a bit confused by the differences (or lack thereof) between them.

Thanks.

P.S., I (think I) understand that the issue here has to do with upd_act_prev_held_cnt being set where it probably shouldn't (because perhaps a new holding record came before its parent? and was set to held, then active, causing the stats for this record to be an update instead of a new record?), whereas in issue 1046 we have something similar?

[patrickzurek]

JIRA Coment by user: jbrand JIRA Timestamp: 2012-04-06 05:55 PM

Comment body:

1046 is an aesthetics issue which could be handled with different data modeling, i.e. separating out hold status from active/deleted.

Should the records be marked 'updated' in the record counts because a different record (the bib it is waiting on) arrived? Beats me.

With this one, there might be a bug with record counting? new_held_cnt: 11,055 - should this have been decremented when held record activated? I don't know, but the record counts formula doesn't work right in this case. Would changing the data modeling for 1046 help this? I am not sure. It definitely might.

Another possible fix is to have another counter, current_held_cnt. That seems to be what the database query provides (by the way I am not sure I am showing the correct query below).

For the rules calculations to be flexible (easily changeable) I was hoping to be able to write rules based on values found in the RecordCounts object.

Maybe with your small test set that included held then activated records, look at the result of the transformation rules? (rules log in the main directory).

[patrickzurek]

JIRA Comment by user: Chris Delis (cedelis) JIRA Timestamp: 2012-04-06 06:06 PM

Comment body:

First of all, I think the subject of this issue is confusing. Again, what does it have to do with "Delete" in particular? (I'm new to this aspect of MST and subjects do matter when trying to learn, i.e., causes confusion :-).

I think the two issues are more similar than purely aesthetics. While I still believe the held/active property should have been modeled separately from new/update/deleted, it just wasn't; and trying to retrofit/refactor at this point turned out to not be trivial (to me, anyway; but then again, I'm new to this).

As for the "rules" aspect of this, did any of the rules actually fail?

Thanks.

P.S., I think it would be extremely helpful to be able to somehow come up with a reproducible set of records/harvests that I can work with, something manageable (while references to a "real" situation are helpful in diagnosis, etc., it doesn't help me actually fix anything).

P.P.S., The rules log for my simple set (which includes just two records, one holding record -- which comes first hence is held in the beginning -- and one "parent" bib, which when arrives changes the status of the holding record from held to active) contains no FAILs:

06 Apr 2012 11:44:13,271 INFO [http-8080-2] - Updated the user with the username admin 06 Apr 2012 11:47:06,364 INFO [SERVICE_11647] - %%% 06 Apr 2012 11:47:06,364 INFO [SERVICE_11647] - Rules for Normalization: 06 Apr 2012 11:47:06,364 INFO [SERVICE_11647] - Normalization Total In Active (NTIA) = Normalization Total Out Active (NTOA) 06 Apr 2012 11:47:06,364 INFO [SERVICE_11647] - NTIA=2, NTOA=2 \ PASS 06 Apr 2012 11:47:06,364 INFO [SERVICE_11647] - Normalization Bibs In Active (NBIA) = Normalization Bibs Out Active (NBOA) 06 Apr 2012 11:47:06,364 INFO [SERVICE_11647] - NBIA=1, NBOA=1 \ PASS 06 Apr 2012 11:47:06,364 INFO [SERVICE_11647] - Normalization Holdings In Active (NHIA) = Normalization Holdings Out Active (NHOA) 06 Apr 2012 11:47:06,365 INFO [SERVICE_11647] - NHIA=1, NHOA=1 \ PASS 06 Apr 2012 11:47:06,365 INFO [SERVICE_11647] - %%% 06 Apr 2012 11:47:11,842 INFO [SERVICE_11647] - %%% 06 Apr 2012 11:47:11,842 INFO [SERVICE_11647] - Rules for MarcToXCTransformation: 06 Apr 2012 11:47:11,842 INFO [SERVICE_11647] - Transformation Bibs In Active (TBIA) = Transformation Manifestations Active (TMA) 06 Apr 2012 11:47:11,843 INFO [SERVICE_11647] - TBIA=1, TMA=1 \ PASS 06 Apr 2012 11:47:11,843 INFO [SERVICE_11647] - Transformation Bibs In Deleted (TBID) = Transformation Manifestations Deleted (TMD) 06 Apr 2012 11:47:11,843 INFO [SERVICE_11647] - TBID=0, TMD=0 \ PASS 06 Apr 2012 11:47:11,843 INFO [SERVICE_11647] - Transformation Holdings In Active (THIA) <= Transformation Holdings Out Active (THOA) + Transformation Holdings Held (THH) 06 Apr 2012 11:47:11,843 INFO [SERVICE_11647] - THIA=1, THOA=0, THH=1 \ PASS 06 Apr 2012 11:47:11,843 INFO [SERVICE_11647] - Transformation Expressions Active (TEA) = Transformation Works Active (TWA) 06 Apr 2012 11:47:11,843 INFO [SERVICE_11647] - TEA=1, TWA=1 \ PASS 06 Apr 2012 11:47:11,843 INFO [SERVICE_11647] - Transformation Works Active (TWA) >= Transformation Manifestations Active (TMA) 06 Apr 2012 11:47:11,843 INFO [SERVICE_11647] - TWA=1, TMA=1 \ PASS 06 Apr 2012 11:47:11,844 INFO [SERVICE_11647] - Transformation Expressions Active (TEA) >= Transformation Manifestations Active (TMA) 06 Apr 2012 11:47:11,844 INFO [SERVICE_11647] - TWA=1, TMA=1 \ PASS ** 06 Apr 2012 11:47:11,844 INFO [SERVICE_11647] - %%%

P.P.P.S., But similar to the issue logged above, it does have upd_act_prev_held_cnt set:

06 Apr 2012 11:47:11,838 xc.mst.utils.LogWriter:65 INFO [SERVICE_11647] - outgoing all time work new_act_cnt: 1 new_held_cnt: 0 new_del_cnt: 0 outgoing all time work upd_act_cnt: 0 upd_held_cnt: 0 upd_del_cnt: 0 outgoing all time work upd_act_prev_act_cnt: 0 upd_act_prev_held_cnt: 0 upd_act_prev_del_cnt: 0 outgoing all time work upd_held_prev_act_cnt: 0 upd_held_prev_held_cnt: 0 upd_held_prev_del_cnt: 0 outgoing all time work upd_del_prev_act_cnt: 0 upd_del_prev_held_cnt: 0 upd_del_prev_del_cnt: 0 outgoing all time holdings new_act_cnt: 0 new_held_cnt: 1 new_del_cnt: 0 outgoing all time holdings upd_act_cnt: 1 upd_held_cnt: 0 upd_del_cnt: 0 outgoing all time holdings upd_act_prev_act_cnt: 0 upd_act_prev_held_cnt: 1 upd_act_prev_del_cnt: 0 outgoing all time holdings upd_held_prev_act_cnt: 0 upd_held_prev_held_cnt: 0 upd_held_prev_del_cnt: 0 outgoing all time holdings upd_del_prev_act_cnt: 0 upd_del_prev_held_cnt: 0 upd_del_prev_del_cnt: 0 outgoing all time expression new_act_cnt: 1 new_held_cnt: 0 new_del_cnt: 0 outgoing all time expression upd_act_cnt: 0 upd_held_cnt: 0 upd_del_cnt: 0 outgoing all time expression upd_act_prev_act_cnt: 0 upd_act_prev_held_cnt: 0 upd_act_prev_del_cnt: 0 outgoing all time expression upd_held_prev_act_cnt: 0 upd_held_prev_held_cnt: 0 upd_held_prev_del_cnt: 0 outgoing all time expression upd_del_prev_act_cnt: 0 upd_del_prev_held_cnt: 0 upd_del_prev_del_cnt: 0 outgoing all time manifestation new_act_cnt: 1 new_held_cnt: 0 new_del_cnt: 0 outgoing all time manifestation upd_act_cnt: 0 upd_held_cnt: 0 upd_del_cnt: 0 outgoing all time manifestation upd_act_prev_act_cnt: 0 upd_act_prev_held_cnt: 0 upd_act_prev_del_cnt: 0 outgoing all time manifestation upd_held_prev_act_cnt: 0 upd_held_prev_held_cnt: 0 upd_held_prev_del_cnt: 0 outgoing all time manifestation upd_del_prev_act_cnt: 0 upd_del_prev_held_cnt: 0 upd_del_prev_del_cnt: 0 outgoing all time TOTALS new_act_cnt: 3 new_held_cnt: 1 new_del_cnt: 0 outgoing all time TOTALS upd_act_cnt: 1 upd_held_cnt: 0 upd_del_cnt: 0 outgoing all time TOTALS upd_act_prev_act_cnt: 0 upd_act_prev_held_cnt: 1 upd_act_prev_del_cnt: 0 outgoing all time TOTALS upd_held_prev_act_cnt: 0 upd_held_prev_held_cnt: 0 upd_held_prev_del_cnt: 0 outgoing all time TOTALS upd_del_prev_act_cnt: 0 upd_del_prev_held_cnt: 0 upd_del_prev_del_cnt: 0

[patrickzurek]

JIRA Coment by user: jbrand JIRA Timestamp: 2012-04-06 06:28 PM

Comment body:

Yes it is very confusing, and I am probably not helping. I don't recall anymore whether the rule failed (Trans HoldingsActive<=Trans Holdings Out Active + Transformation Holdings Held) or whether it was just purely trying to understand what was going on to try to answer Randy's question:

" According to the log, we had 124 previously held records that have been switched to active and we processed 11, 055 new held records for a total held record count of 10,931. The status facet also shows 10,931. Can you confirm as the number is different than your “pass/fail rule�? Also, I think this run was a single large batch, T0 right? Are these 124 records that were marked held and then moved to active as the result of service processing of the batch, as opposed to the “net result� of running the batch? I was thinking that it was the net effect, but maybe that is not a correct understanding. Just wanting to understand how it works. Thanks."

If the rule passes, and we agree the rules are correct, and all we can 'bank on' then I think we are done with this one.

[patrickzurek]

JIRA Coment by user: jbrand JIRA Timestamp: 2012-04-13 03:53 PM

Comment body:

recommend that we close this one as 'not a bug' (after much investigation)

[patrickzurek]

Issue resolved: 2012-05-01 05:52 PM