Open zotz opened 10 months ago
ElvishArtisan
commented
10 months ago Hard to say what's going on beyond the fact that you've obviously got database corruption. The cart type (AUDIO or MACRO) is definitively determined by the value of the CART.TYPE field in the database. Nothing in generating a log should cause that field to change, or even alter anything in the CART table at all.
zotz
commented
10 months ago Thanks for the reply, Just ran this with these results:
rd@rddr:~$ sudo rddbmgr --check [sudo] password for rd: Checking DB/table attributes... done.
Checking voice tracks... done.
Checking for stale cart reservations... done.
Checking schedule code rules... done.
Checking for orphaned carts... done.
Checking for orphaned cuts... done.
Checking cart->cuts counters... done.
Checking for orphaned audio... done.
Validating audio lengths (this may take some time)... done.
Validating character strings (this may take some time)... done.
Checking log line IDs... done.
Any thoughts on where I should go from here? Any particular tests you can think of?
This is V4.1.0 db 371 on Ubuntu studio here.
I think I am going to create a service with a clock that mixes audio and macros and see how that generates.
all the best, drew
zotz
commented
10 months ago Just did the mixed hour for the new service. The problem remains.
Just to be very clear. All I have to do in logedit to fix a line is click edit and then save.
ElvishArtisan
commented
10 months ago 'Kay, if I'm understanding the context correctly, the only change you made was:
I made a change a few days ago to include a time TOH video sweeper. All seemed fine.
What precisely was that change? And, if you revert it, does the problem go away?
zotz
commented
10 months ago I would not bet it was the only change I made, but I can get rid of it and see what I see. I have been doing way too much lately trying to get a demo going to refine my ideas with respect to issue 887 here:
https://github.com/ElvishArtisan/rivendell/issues/887
Let me revert the change and report back.
Most of the things I am doing, I am trying to keep "on the outside" of rivendell. Or pypad reports and read only database queries. And on that day, trying to script some rdclilogedit stuff with expect and python pexpect.
zotz
commented
10 months ago I removed the offending even from the clock, regenerated the log, and the problem persists.
This is what the event looks like:
It is a TOH timed 15 second long event designed to keep the day somewhat on time.
Although the problem persists, it does not seem to be causing all of the issues I was seeing yesterday. More investigating.
zotz
commented
10 months ago I still cannot figure this out.
Here are the first 8 lines of today's and tomorrow's logs. Today's, I have done the edit / save routine on the first 4 lines. Tomorrow's I have not manipulated in any way since creating it.
`localhost:3306/Rivendell/LOG_LINES/ http://192.168.86.114/phpmyadmin/index.php?route=/table/sql&db=Rivendell&table=LOG_LINES
Showing rows 0 - 7 (8 total, Query took 0.0171 seconds.)
SELECT ID,LOG_NAME,LINE_ID,COUNT,TYPE,SOURCE,START_TIME,GRACE_TIME,CART_NUMBER,TIME_TYPE,TRANS_TYPE FROM LOG_LINES WHERE LOG_NAME LIKE "VID_2023_08_25" LIMIT 8;
ID LOG_NAME LINE_ID COUNT TYPE SOURCE START_TIME GRACE_TIME CART_NUMBER TIME_TYPE TRANS_TYPE
246262 VID_2023_08_25 0 0 2 2 0 0 700005 0 0
246263 VID_2023_08_25 1 1 2 2 0 0 700015 0 0
246264 VID_2023_08_25 2 2 2 2 0 0 700011 0 0
246265 VID_2023_08_25 3 3 2 2 0 0 700003 0 0
246266 VID_2023_08_25 4 4 0 2 720000 0 700000 0 0
246267 VID_2023_08_25 5 5 0 2 900000 0 700012 0 0
246268 VID_2023_08_25 6 6 0 2 1080000 0 700002 0 0
246269 VID_2023_08_25 7 7 0 2 1260000 0 700013 0 0
====================
localhost:3306/Rivendell/LOG_LINES/ http://192.168.86.114/phpmyadmin/index.php?route=/table/sql&db=Rivendell&table=LOG_LINES
Showing rows 0 - 7 (8 total, Query took 0.0176 seconds.)
SELECT ID,LOG_NAME,LINE_ID,COUNT,TYPE,SOURCE,START_TIME,GRACE_TIME,CART_NUMBER,TIME_TYPE,TRANS_TYPE FROM LOG_LINES WHERE LOG_NAME LIKE "VID_2023_08_26" LIMIT 8;
ID LOG_NAME LINE_ID COUNT TYPE SOURCE START_TIME GRACE_TIME CART_NUMBER TIME_TYPE TRANS_TYPE
246743 VID_2023_08_26 0 0 0 2 0 0 700015 0 0
246744 VID_2023_08_26 1 1 0 2 180000 0 700013 0 0
246745 VID_2023_08_26 2 2 0 2 360000 0 700010 0 0
246746 VID_2023_08_26 3 3 0 2 540000 0 700000 0 0
246747 VID_2023_08_26 4 4 0 2 720000 0 700011 0 0
246748 VID_2023_08_26 5 5 0 2 900000 0 700007 0 0
246749 VID_2023_08_26 6 6 0 2 1080000 0 700012 0 0
246750 VID_2023_08_26 7 7 0 2 1260000 0 700001 0 0
`
ElvishArtisan
commented
10 months ago What exactly is generating these SQL calls, and what is consuming the resulting rows?
FWIW, all of the rows being returned are referencing macro carts (TYPE=2).
zotz
commented
10 months ago I am basically writing the sql ccalls by hand in phpmyadmin. Nothing is consuming them in what I am talking about here.
rdlogmanager is creating the logs and I am seeing audio icons (little speaker) for the lines instead of command/macro icons (little sprocket?) when I view the logs in rdlogedit.
"FWIW, all of the rows being returned are referencing macro carts (TYPE=2)."
Please look again. 4 rows have type=2, the rest have type=0. The 4 that have type=2 are the rows I edited and then immediately saved in rdlogedit without actually editing anything.
Here are 3 samples I pulled out by hand from the above post:
<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.0 Transitional//EN">
zotz
commented
10 months ago Older version of Rivendell is not showing this problem.
zotz
commented
10 months ago I am getting more and more confused. I just pulled this data today:
<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.0 Transitional//EN">
zotz
commented
10 months ago Well, I know what happened there. I madethe edits in rdlogedit but had not yet saved the changed log. Here is what it looks like after the save:
<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.0 Transitional//EN">
zotz
commented
10 months ago These were both hand made in logedit, hmle33 on v3, hmle4 on v4:
<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.0 Transitional//EN">
Sprockets show correctly in both.
ElvishArtisan
commented
10 months ago Please look again. 4 rows have type=2, the rest have type=0. The 4 that have type=2 are the rows I edited and then immediately saved in rdlogedit without actually editing anything.
Tip: I typically use the mysql(1) monitor for doing this sort of thing, which by default will return query results in an easy-to-read column format.
For example, to run your original query on my test rig, you first start the monitor:
mysql` -u rduser -p[secret] Rivendell
which will return something like:
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A
Welcome to the MariaDB monitor. Commands end with ; or \g.
Your MariaDB connection id is 208353
Server version: 5.5.68-MariaDB MariaDB Server
Copyright (c) 2000, 2018, Oracle, MariaDB Corporation Ab and others.
Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.
MariaDB [Rivendell]> then, just enter the query (I've changed the log name for obvious reasons), followed by a semicolon (";"):
SELECT ID,LOG_NAME,LINE_ID,COUNT,TYPE,SOURCE,START_TIME,GRACE_TIME,CART_NUMBER,TIME_TYPE,TRANS_TYPE FROM LOG_LINES WHERE LOG_NAME LIKE "DerRosenkavalier" LIMIT 8;
which returns:
| ID | LOG_NAME | LINE_ID | COUNT | TYPE | SOURCE | START_TIME | GRACE_TIME | CART_NUMBER | TIME_TYPE | TRANS_TYPE |
+-------+------------------+---------+-------+------+--------+------------+------------+-------------+-----------+------------+
| 81210 | DerRosenkavalier | 1 | 0 | 0 | 0 | 0 | 0 | 830063 | 0 | 2 |
| 81211 | DerRosenkavalier | 2 | 1 | 0 | 0 | 0 | 0 | 830064 | 0 | 2 |
| 81212 | DerRosenkavalier | 3 | 2 | 0 | 0 | 0 | 0 | 830065 | 0 | 2 |
+-------+------------------+---------+-------+------+--------+------------+------------+-------------+-----------+------------+To quit the monitor, just do:
exit;
ElvishArtisan
commented
10 months ago I am getting more and more confused. I just pulled this data today:
Any chance you could e-mail me a SQL dump of your database?
zotz
commented
10 months ago I am getting more and more confused. I just pulled this data today:
Any chance you could e-mail me a SQL dump of your database?
Sure, any particular way you want me to create it? Just a normal rivendell database backup or some other way?
Shall I use the normal email address I have for you?
Just a point of information, I set up the video/macro side of things on another machine this morning with not "taint" of the database I thought I might have messed up. It is showing the same issue with the green lines and speaker icons instead of sprocket icons.
zotz
commented
10 months ago SELECT ID,LOG_NAME,LINE_ID,COUNT,TYPE,SOURCE,START_TIME,GRACE_TIME,CART_NUMBER,TIME_TYPE,TRANS_TYPE FROM LOG_LINES WHERE LOG_NAME LIKE "DerRosenkavalier" LIMIT 8;
Here you go: Top: Existing machine (rddr) MariaDB [Rivendell]> +--------+----------------+---------+-------+------+--------+------------+------------+-------------+-----------+------------+ | ID | LOG_NAME | LINE_ID | COUNT | TYPE | SOURCE | START_TIME | GRACE_TIME | CART_NUMBER | TIME_TYPE | TRANS_TYPE | +--------+----------------+---------+-------+------+--------+------------+------------+-------------+-----------+------------+ | 254793 | VID_2023_08_28 | 0 | 0 | 2 | 3 | 0 | -1 | 790200 | 1 | 1 | | 254794 | VID_2023_08_28 | 1 | 1 | 0 | 2 | 15000 | -1 | 700000 | 0 | 0 | | 254795 | VID_2023_08_28 | 2 | 2 | 0 | 2 | 180000 | 0 | 700011 | 0 | 0 | | 254796 | VID_2023_08_28 | 3 | 3 | 0 | 2 | 360000 | 0 | 700009 | 0 | 0 | | 254797 | VID_2023_08_28 | 4 | 4 | 0 | 2 | 540000 | 0 | 700014 | 0 | 0 | | 254798 | VID_2023_08_28 | 5 | 5 | 0 | 2 | 720000 | 0 | 700012 | 0 | 0 | | 254799 | VID_2023_08_28 | 6 | 6 | 0 | 2 | 900000 | 0 | 700008 | 0 | 0 | | 254800 | VID_2023_08_28 | 7 | 7 | 0 | 2 | 1080000 | 0 | 700010 | 0 | 0 | +--------+----------------+---------+-------+------+--------+------------+------------+-------------+-----------+------------+ 8 rows in set (0.031 sec)
Bottom: New machine (rdporch) MariaDB [Rivendell]> SELECT ID,LOG_NAME,LINE_ID,COUNT,TYPE,SOURCE,START_TIME,GRACE_TIME,CART_NUMBER,TIME_TYPE,TRANS_TYPE FROM LOG_LINES WHERE LOG_NAME LIKE "VID_2023_08_28" LIMIT 8; +-------+----------------+---------+-------+------+--------+------------+------------+-------------+-----------+------------+ | ID | LOG_NAME | LINE_ID | COUNT | TYPE | SOURCE | START_TIME | GRACE_TIME | CART_NUMBER | TIME_TYPE | TRANS_TYPE | +-------+----------------+---------+-------+------+--------+------------+------------+-------------+-----------+------------+ | 11065 | VID_2023_08_28 | 0 | 0 | 0 | 2 | 0 | 0 | 700008 | 0 | 0 | | 11066 | VID_2023_08_28 | 1 | 1 | 0 | 2 | 180000 | 0 | 700015 | 0 | 0 | | 11067 | VID_2023_08_28 | 2 | 2 | 0 | 2 | 360000 | 0 | 700005 | 0 | 0 | | 11068 | VID_2023_08_28 | 3 | 3 | 0 | 2 | 540000 | 0 | 700014 | 0 | 0 | | 11069 | VID_2023_08_28 | 4 | 4 | 0 | 2 | 720000 | 0 | 700003 | 0 | 0 | | 11070 | VID_2023_08_28 | 5 | 5 | 0 | 2 | 900000 | 0 | 700012 | 0 | 0 | | 11071 | VID_2023_08_28 | 6 | 6 | 0 | 2 | 1080000 | 0 | 700001 | 0 | 0 | | 11072 | VID_2023_08_28 | 7 | 7 | 0 | 2 | 1260000 | 0 | 700000 | 0 | 0 | +-------+----------------+---------+-------+------+--------+------------+------------+-------------+-----------+------------+ 8 rows in set (0.001 sec)
Sorry, they look good in my text editor but not when I put them here.
It seems like my logmanager has started creating macro lines as audio lines.
(At least that's what I think is going on.)
I have a log where every line is supposed to be a macro. (This is to do with my rivendell does video project.) It seems to have been working fine for days now.
I made a change a few days ago to include a time TOH video sweeper. All seemed fine.
Today I noticed a problem with the log machine that plays the video logs shoring stuck in the LOG_MACHINES table of the database.
This is too complex to explain but generating new logs for today and tomorrow for that service results in this:
Here I have edited and immediately saved 2 lines and not we see this:
Help please.