DWH Missing Stored Procedure After Upgrade

Hello, currently troubleshooting my DWH install after updating to the latest. Hitting this error when I manually run the analytics script:

ERROR 30-06 11:22:02,905 - Execute SQL script - Unexpected error
ERROR 30-06 11:22:02,906 - Execute SQL script - org.pentaho.di.core.exception.KettleStepException:
Error while running this step!

Couldn’t execute SQL: Call kalturadw.calc_aggr_day_partner_totals(20210611)

PROCEDURE kalturadw.calc_aggr_day_partner_totals does not exist

    at org.pentaho.di.trans.steps.sql.ExecSQL.processRow(ExecSQL.java:208)
    at org.pentaho.di.trans.step.RunThread.run(RunThread.java:40)
    at java.lang.Thread.run(Thread.java:748)

Caused by: org.pentaho.di.core.exception.KettleDatabaseException:
Couldn’t execute SQL: Call kalturadw.calc_aggr_day_partner_totals(20210611)

PROCEDURE kalturadw.calc_aggr_day_partner_totals does not exist

Haven’t been able to find where this is being called, or the procedure itself on GitHub. Any ideas?

Just an update, I did end up finding the stored procedure on the GitHub repo under:
/opt/kaltura/dwh/ddl/dw/aggr/

Grabbed the SQL, made the file in that directory on my DWH server, called the file from the mariadb CLI to create the stored procedure. No more errors in the /dwh/logs directory concerning this procedure.

However, I was missing a table under kalturadw but I found the SQL to recreate that table under:

After that, it was having an issue running move_innodb so I just added another partition as specified here:

No errors after running kaltura-dwh-run.sh manually, hopefully everything updates in the analytics tab now. Will update after.

So, no further errors encountered on the manual runs of kaltura-dwh-run, and I have data in the Contributors tab as well as Usage, but nothing under Audience (Engagement, interations, etc.)

The log files are being inserted into
kalturadw_ds.files
Nothing inside of dwh_fact_events

Web logs for the past week do contain collect events:

IPADDR - - [30/Jun/2021:02:50:00 -0400] “GET /api_v3/index.php?service=stats&apiVersion=3.1&expiry=86400&clientTag=kwidget%3Av2.85&format=1&ignoreNull=1**&action=collect&**event:eventType=13&event:clientVer=2.85&event:currentPoint=4082174&event:duration=4391.81&event:eventTimestamp=1625035800403&event:isFirstInSession=false&event:objectType=KalturaStatsEvent&event:partnerId=101&event:sessionId=a616fcf5-6f4c-9f01-4fc2-650826ab00ff&event:uiconfId=23449262&event:seek=false&event:entryId=0_i4zs2e0e&event:historyEvents=111111000001100000000000-54-54&event:widgetId=_101&event:referrer=https%253A%252F%252Fwww.refer.com%252FPage%252F15927&hasKanalony=false&kalsig=5b4dd218bf032fcca1959031056f0a56 HTTP/1.1” 200 612 0/15670 “https://www.refer.com/Page/15927” “Mozilla/5.0 (iPhone; CPU iPhone OS 14_3 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/14.0.2 Mobile/15E148 Safari/604.1” “-”

Played a bunch of embeds to generate more logs from my web nodes, rotated the logs, then ran the wrapper script for DWH again. This time I did get an error from etl_update_dims-20210701-12.log

[root@kaltura-dw1 logs]# grep ERROR *
etl_update_dims-20210701-12.log:ERROR 01-07 12:00:11,520 - Lock is already seized - Row nr 1 causing abort : [update_dims_lock], [1], [0], [null]
etl_update_dims-20210701-12.log:ERROR 01-07 12:00:11,520 - Lock is already seized - Aborting after having seen 1 rows.
etl_update_dims-20210701-12.log:ERROR 01-07 12:00:11,520 - seize_lock_by_name - Errors detected!
etl_update_dims-20210701-12.log:ERROR 01-07 12:00:11,520 - seize_lock_by_name - Errors detected!

Full log isn’t that big, here:

[root@kaltura-dw1 logs]# cat etl_update_dims-20210701-12.log
INFO 01-07 12:00:03,990 - Kitchen - Start of run.
INFO 01-07 12:00:04,057 - Update Dimensions - Start of job execution
INFO 01-07 12:00:11,220 - Update Dimensions - Starting entry [Check if daily_lock is seized]
INFO 01-07 12:00:11,249 - Update Dimensions - Starting entry [Seize update dims lock]
INFO 01-07 12:00:11,250 - Seize update dims lock - Loading transformation from XML file [/opt/kaltura/dwh/etlsource//common/seize_lock_by_name.ktr]
INFO 01-07 12:00:11,299 - seize_lock_by_name - Dispatching started for transformation [seize_lock_by_name]
INFO 01-07 12:00:11,353 - get_update_dims_lock_name - Dispatching started for transformation [get_update_dims_lock_name]
INFO 01-07 12:00:11,433 - Generate Row - Finished processing (I=0, O=0, R=0, W=1, U=0, E=0)
INFO 01-07 12:00:11,502 - Mapping input specification - Finished processing (I=0, O=0, R=1, W=1, U=0, E=0)
INFO 01-07 12:00:11,504 - Set lock name = dims_lock - Finished processing (I=0, O=0, R=1, W=1, U=0, E=0)
INFO 01-07 12:00:11,506 - Mapping output specification - Finished processing (I=0, O=0, R=1, W=1, U=0, E=0)
INFO 01-07 12:00:11,508 - Get lock name - Finished processing (I=0, O=0, R=1, W=1, U=0, E=0)
INFO 01-07 12:00:11,509 - Create lock states - Finished processing (I=0, O=0, R=1, W=1, U=0, E=0)
INFO 01-07 12:00:11,515 - Register lock - Finished processing (I=1, O=0, R=1, W=1, U=0, E=0)
ERROR 01-07 12:00:11,520 - Lock is already seized - Row nr 1 causing abort : [update_dims_lock], [1], [0], [null]
ERROR 01-07 12:00:11,520 - Lock is already seized - Aborting after having seen 1 rows.
ERROR 01-07 12:00:11,520 - seize_lock_by_name - Errors detected!
ERROR 01-07 12:00:11,520 - seize_lock_by_name - Errors detected!
INFO 01-07 12:00:11,521 - Get free lock - Finished processing (I=0, O=0, R=1, W=1, U=0, E=0)
INFO 01-07 12:00:11,521 - Lock is already seized - Finished processing (I=0, O=0, R=1, W=1, U=0, E=1)
INFO 01-07 12:00:11,521 - seize_lock_by_name - seize_lock_by_name
INFO 01-07 12:00:11,521 - Lock is free - Finished processing (I=0, O=0, R=1, W=1, U=0, E=0)
INFO 01-07 12:00:11,521 - seize_lock_by_name - seize_lock_by_name
INFO 01-07 12:00:11,706 - Update Dimensions - Starting entry [Success 1]
INFO 01-07 12:00:11,707 - Update Dimensions - Finished job entry [Success 1] (result=[true])
INFO 01-07 12:00:11,707 - Update Dimensions - Finished job entry [Seize update dims lock] (result=[true])
INFO 01-07 12:00:11,707 - Update Dimensions - Finished job entry [Check if daily_lock is seized] (result=[true])
INFO 01-07 12:00:11,707 - Update Dimensions - Job execution finished
INFO 01-07 12:00:12,614 - Kitchen - Finished!
INFO 01-07 12:00:12,615 - Kitchen - Start=2021/07/01 12:00:03.992, Stop=2021/07/01 12:00:12.614
INFO 01-07 12:00:12,615 - Kitchen - Processing ended after 8 seconds.

No other nodes in the cluster are running DWH scripts, just this DWH node. I have not seen locks on this or previous runs, have checked each time before running:

MariaDB [(none)]> select * from kalturadw_ds.locks ;
±--------±--------------------------------±--------------------±-----------+
| lock_id | lock_name | lock_time | lock_state |
±--------±--------------------------------±--------------------±-----------+
| 1 | daily_lock | 2021-07-01 11:55:03 | 0 |
| 2 | retention_lock | 2021-07-01 11:55:11 | 0 |
| 3 | hourly_kaltura-dw1.prod.cps.loc | 2021-07-01 12:00:16 | 0 |
| 4 | update_dims_lock | 2021-07-01 12:00:12 | 0 |
| 5 | hourly_kaltura-sphinx1 | 2021-07-01 12:00:25 | 0 |
±--------±--------------------------------±--------------------±-----------+
5 rows in set (0.00 sec)

Hello @siactive,

The “Lock is already seized” error occurs because “etl_hourly.sh” or “etl_daily.sh” is locking tables in database.
“etl_update_dims.sh” waits for the lock to be released, but it may time-out and stop its process.
At such cases, you will see this error.

The process of “etl_update_dims.sh” does not have to be successful every time.
This process only needs to be successful several times a day.

The Linux server runs log-rotation between 3am and 4am.
Then, the log-rotation process moves Apache access logs to a shared directory (/opt/kaltura/web/logs).
After the log-rotation, the shell scripts read the log-files at 4 am and store log information in the database.
“etl_hourly.sh” and “etl_update_dims.sh” run every hour, so if they fail at 4am they have a chance to succeed at 5am and 6am.
But, “etl_daily.sh” runs every 4 hours (0:59, 4:59, 8;59, etc.).
So that, if “etl_update_dims.sh” never succeeds between 4am and 8am, there is something wrong with Kaltura analytics.
In such cases, the performance of the database server or DWH server must be improved.

Alternatively, the database server or DWH server may not be performing as it should due to a system trouble.

Regards,

Thanks, it may have just been a bad run. I haven’t seen that again while troubleshooting. Still no “Audience” analytics. Content and usage are populating though.

Found something maybe that could be causing the issue? Finding Javascript errors in etl Hourly/Daily:
Javascript error:
`

TypeError: [JavaPackage eu.bitwalker.useragentutils.UserAgent.parseUserAgentString] is not a function, it is object. (script#7)

`