Analytics not appearing in kaltura_apache_access_ssl.log when playing a video

cedricguindon · October 13, 2020, 7:38pm

Hello

I’ve got a working kaltura CE working on a allinone server with SSL

I can upload a video, watch it from the flavor tab and i can also embed the code on an external server fine. The problem is that the analytics from playing the video are not showing up anywhere.

I started to follow the analytics troubleshooting from here: https://github.com/kaltura/platform-install-packages/blob/Propus-16.8.0/doc/kaltura-packages-faq.md#analytics-issues The first step is to check if you have the following pattern

[service=stats&action=collect]

in the [/opt/kaltura/log/kaltura_apache_access.log] file

tail -f ./kaltura_apache_access_ssl.log | grep “api_v3/index.php?service=”

The above is giving me the following:

/api_v3/index.php?service=multirequest&
/api_v3/index.php?service=uiconf
/api_v3/index.php?service=session&

but no /api_v3/index.php?service=stats

It’s not even getting to the cron job steps.

I also did the following, just in case:

MariaDB [(none)]> select * from kalturadw_ds.locks ;
+---------+----------------+-----------+------------+
| lock_id | lock_name      | lock_time | lock_state |
+---------+----------------+-----------+------------+
|       1 | daily_lock     | NULL      |          0 |
|       2 | retention_lock | NULL      |          0 |
+---------+----------------+-----------+------------+
2 rows in set (0.00 sec)

No lock as per the above

MariaDB [(none)]> select * from kalturadw_ds.files;
Empty set (0.00 sec)

No access files as per the above

MariaDB [(none)]> select * from kalturadw.dwh_fact_events;
Empty set (0.01 sec)

Nothing in the above

Executed /opt/kaltura/bin/kaltura-run-dwh.sh

[root@kaltura-dev-v5 log]# sh /opt/kaltura/bin/kaltura-run-dwh.sh
reading config file /etc/logrotate.d/kaltura_apache
Allocating hash table for state file, size 15360 B

Handling 4 logs

rotating pattern: /opt/kaltura/log/kaltura_apache_errors.log  forced from command line (5 rotations)
empty log files are not rotated, old logs are removed
switching euid to 0 and egid to 7373
considering log /opt/kaltura/log/kaltura_apache_errors.log
log /opt/kaltura/log/kaltura_apache_errors.log does not exist -- skipping
not running postrotate script, since no logs were rotated
switching euid to 0 and egid to 0

rotating pattern: /opt/kaltura/log/kaltura_apache_access.log  forced from command line (5 rotations)
empty log files are not rotated, old logs are removed
switching euid to 0 and egid to 7373
considering log /opt/kaltura/log/kaltura_apache_access.log
log /opt/kaltura/log/kaltura_apache_access.log does not exist -- skipping
not running last action script, since no logs will be rotated
switching euid to 0 and egid to 0

rotating pattern: /opt/kaltura/log/kaltura_apache_errors_ssl.log  forced from command line (5 rotations)
empty log files are not rotated, old logs are removed
switching euid to 0 and egid to 7373
considering log /opt/kaltura/log/kaltura_apache_errors_ssl.log
log does not need rotating (log is empty)not running postrotate script, since no logs were rotated
switching euid to 0 and egid to 0

rotating pattern: /opt/kaltura/log/kaltura_apache_access_ssl.log  forced from command line (5 rotations)
empty log files are not rotated, old logs are removed
switching euid to 0 and egid to 7373
considering log /opt/kaltura/log/kaltura_apache_access_ssl.log
log needs rotating
rotating log /opt/kaltura/log/kaltura_apache_access_ssl.log, log->rotateCount is 5
dateext suffix '-20201013'
glob pattern '-[0-9][0-9][0-9][0-9][0-9][0-9][0-9][0-9]'
glob finding old rotated logs failed
fscreate context set to system_u:object_r:usr_t:s0
renaming /opt/kaltura/log/kaltura_apache_access_ssl.log to /opt/kaltura/log/kaltura_apache_access_ssl.log-20201013
compressing log with: /bin/gzip
set default create context to system_u:object_r:usr_t:s0
switching uid to 0 and gid to 7373
running last action script
switching euid to 0 and egid to 0
Redirecting to /bin/systemctl reload httpd.service
switching euid to 0 and egid to 0
set default create context
bash: /opt/kaltura/log/cron.log: Permission denied

After all did, i loaded a page on the external server that contained the embed video, played it until the end, here’s the output of

tail -f ./kaltura_apache_access_ssl.log | grep “api_v3/index.php?service=”

XX.XX.XX.XX - - [13/Oct/2020:19:21:10 +0000] “GET /api_v3/index.php?service=session&action=startWidgetSession&apiVersion=3.1.6&format=3&clientTag=html5iframe%3A2.83%2Ccache_st%3A+&ignoreNull=1&widgetId=_102&expiry=86400&kalsig=cdee821915cc16bcc4cddc433961ec77 HTTP/1.1” 200 4065 0/36366 “-” “curl/7.11.1” “-” XX.XX.XX.XX “-” “kaltura-dev-v5.cXXXXX.com” 6976 992883017 + 832 “-” “-” “-” “-” “no-store, no-cache, must-revalidate, post-check=0, pre-check=0” -

XX.XX.XX.XX - - [13/Oct/2020:19:21:10 +0000] “GET /api_v3/index.php?service=uiconf&action=get&apiVersion=3.1.6&format=3&clientTag=html5iframe%3A2.83%2Ccache_st%3A+&ignoreNull=1&id=23
448172&ks=OWUyZGViNmJjMzgwY2I1NmY2M2E4MDk4MDQ2NDFkZDBmNTRhYjA5MXwxMDI7MTAyOzE2MDI3MDMyNzA7MDsxNjAyNjE2ODcwLjgwMjM7MDt2aWV3Oiosd2lkZ2V0OjE7Ow%3D%3D&kalsig=27ba17af95718bc6bcf66c538535f
fd1 HTTP/1.1” 200 4364 0/74407 “-” “curl/7.11.1” “-” XX.XX.XX.XX “-” “kaltura-dev-v5.cXXXXX.com” 7004 1362788776 + 941 “-” “-” “-” “-” “no-store, no-cache, must
-revalidate, post-check=0, pre-check=0” 102

XX.XX.XX.XX - - [13/Oct/2020:19:21:11 +0000] “GET /api_v3/index.php?service=session&action=startWidgetSession&apiVersion=3.1.6&format=3&clientTag=html5iframe%3A2.83%2Ccache_st%3A+160
2616471&ignoreNull=1&widgetId=_102&expiry=86400&kalsig=a93cfe1e2bd1e6a5f193c2ec31b016fd HTTP/1.1” 200 4063 0/13557 “-” “Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like
Gecko) Chrome/85.0.4183.121 Safari/537.36” “-” XX.XX.XX.XX “-” “kaltura-dev-v5.cXXXXX.com” 7004 116984674 + 936 “-” “-” “-” “-” “no-store, no-cache, must-reval
idate, post-check=0, pre-check=0” -

XX.XX.XX.XX - - [13/Oct/2020:19:21:11 +0000] “GET /api_v3/index.php?service=multirequest&apiVersion=3.1.6&format=3&clientTag=html5iframe%3A2.83%2Ccache_st%3A+1602616471&ignoreNull=1&
1%3Aservice=baseEntry&1%3Aaction=list&1%3Afilter%3AobjectType=KalturaBaseEntryFilter&1%3Afilter%3AredirectFromEntryId=0_3z3s914c&1%3AresponseProfile%3Atype=2&1%3AresponseProfile%3Afie
lds=userId%2CcreatorId&1%3Aks=ZDJmODZjN2ZlNTU2MTcyMzk3MDc2YjBkYmIwNmQ0OWNhZjkyODFjM3wxMDI7MTAyOzE2MDI3MDMyNzE7MDsxNjAyNjE2ODcxLjE0NTU7MDt2aWV3Oiosd2lkZ2V0OjE7Ow%3D%3D&2%3Aservice=base
Entry&2%3Aaction=getContextData&2%3AcontextDataParams%3AobjectType=KalturaEntryContextDataParams&2%3AcontextDataParams%3AflavorTags=all&2%3AcontextDataParams%3Areferrer=https%3A%2F%2F
lp-web-dXXXXX.com%2F&2%3AcontextDataParams%3AuserAgent=Mozilla%2F5.0+%28X11%3B+Linux+x86_64%29+AppleWebKit%2F537.36+%28KHTML%2C+like+Gecko%29+Chrome%2F85.0.
4183.121+Safari%2F537.36&2%3AentryId=%7B1%3Aresult%3Aobjects%3A0%3Aid%7D&2%3Aks=ZDJmODZjN2ZlNTU2MTcyMzk3MDc2YjBkYmIwNmQ0OWNhZjkyODFjM3wxMDI7MTAyOzE2MDI3MDMyNzE7MDsxNjAyNjE2ODcxLjE0NTU
7MDt2aWV3Oiosd2lkZ2V0OjE7Ow%3D%3D&3%3Aservice=metadata_metadata&3%3Aaction=list&3%3Afilter%3AobjectType=KalturaMetadataFilter&3%3Afilter%3AmetadataObjectTypeEqual=1&3%3Afilter%3Aobjec
tIdEqual=%7B1%3Aresult%3Aobjects%3A0%3Aid%7D&3%3Afilter%3AorderBy=%2BcreatedAt&3%3A0=metadataPager&3%3A1%3AobjectType=KalturaFilterPager&3%3A1%3ApageSize=1&3%3Aks=ZDJmODZjN2ZlNTU2MTcy
Mzk3MDc2YjBkYmIwNmQ0OWNhZjkyODFjM3wxMDI7MTAyOzE2MDI3MDMyNzE7MDsxNjAyNjE2ODcxLjE0NTU7MDt2aWV3Oiosd2lkZ2V0OjE7Ow%3D%3D&4%3Aservice=cuepoint_cuepoint&4%3Aaction=list&4%3Afilter%3AobjectT
ype=KalturaCuePointFilter&4%3Afilter%3AentryIdEqual=%7B1%3Aresult%3Aobjects%3A0%3Aid%7D&4%3Afilter%3AorderBy=%2BstartTime&4%3Aks=ZDJmODZjN2ZlNTU2MTcyMzk3MDc2YjBkYmIwNmQ0OWNhZjkyODFjM3
wxMDI7MTAyOzE2MDI3MDMyNzE7MDsxNjAyNjE2ODcxLjE0NTU7MDt2aWV3Oiosd2lkZ2V0OjE7Ow%3D%3D&kalsig=0a989009578424984250a2a202edcf9d HTTP/1.1” 200 5446 0/179103 “-” “Mozilla/5.0 (X11; Linux x86
_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.121 Safari/537.36” “-”
XX.XX.XX.XX “-” “kaltura-dev-v5.cXXXXX.com” 6977 1550467901 + 2618 “-” “-” "
-" “-” “no-store, no-cache, must-revalidate, post-check=0, pre-check=0” 102

I got 4 entry that contained the api_v3/index.php?service= entry but no service=stats

I saw some troubleshooting steps for cron related problem and DB problem, but not for data missing from the log file.
I’ve found a post that had a similar problem, but his got fixed without an explanation.

Has anybody experienced this before and was able to fix it?

Thank you!

jess · October 14, 2020, 5:56pm

Hello @cedricguindon,

Let’s start with the basics:) The request for the stats.collect() action is sent from the player.
Before hitting play, open your browser’s dev tools, navigate to the “Network” tab and check whether the request is issued. Based on that, we can start looking further.

Also, what are the kaltura-base and kaltura-html5lib versions?

cedricguindon · October 14, 2020, 6:13pm

Thank you for answering @jess

I can’t see any request with the “stats” param, i mainly see URL with HLS on port 8443 and URL directly to the /p/ path. I used the “Share and Embed” code to load my video in case it matters.

I checked online on other website that have kaltura videos and most of them have “/api_v3/index.php?service=analytics&apiVersion=3.1” but i dont, as a matter of fact, i have no network request that goes to the api_v3 link.

As for the version:

[root@kaltura-dev-v5 admin_vm]# rpm -q “kaltura-base”
kaltura-base-16.5.0-15.noarch
[root@kaltura-dev-v5 admin_vm]# rpm -q “kaltura-html5lib”
kaltura-html5lib-v2.83-1.noarch

jess · October 14, 2020, 6:17pm

Hello @cedricguindon,

/api_v3/index.php?service=analytics requests will go out from players that belong to our SaaS ENV. They report to an endpoint used by our other Analytics system [KAVA] which is not used for CE.

You should, however, see several different API v3 requests, including, though not limited to, the playManifest API, without which, nothing can be played.

Is there a sample embed page I can look at?

cedricguindon · October 14, 2020, 6:23pm

I sent you a PM with the info, it contains URLs if you don’t mind not posting it over here
Thank you!

cedricguindon · October 14, 2020, 7:22pm

It seems my video playing is only streaming through HLS and nginx but not using apache, i might be wrong though.

I also tested on a kaltura demo site https://kaltura.github.io/EmbedCodeGenerator/demo/ I added my IDs and same thing, no “service=stats” in the URLs.

jess · October 15, 2020, 11:59am

Hello @cedricguindon,

Serving for content should go via the Nginx, which has the nginx-vod-module [see https://github.com/kaltura/nginx-vod-module] loaded.

As I wrote in response to your private message:

Please edit /opt/kaltura/apps/html5/html5lib/v2.83/modules/KalturaSupport/UiConfResult.php
and uncomment line 212. Then check again and confirm that you see the request going out.

Thanks,

cedricguindon · October 15, 2020, 12:04pm

Hello @jess

I uncommented the line and now i have the service=stats line when i hit play on a video.
Any reason why this was commented?

I checked the stats page, nothing yet, but since they are based on the cron schedule i guess it’s normal.

So i checked the lock state and got 1 lock

> MariaDB [(none)]> select * from kalturadw_ds.locks ;
> +---------+-----------------------+---------------------+------------+
> | lock_id | lock_name             | lock_time           | lock_state |
> +---------+-----------------------+---------------------+------------+
> |       1 | daily_lock            | 2020-10-15 11:48:27 |          0 |
> |       2 | retention_lock        | 2020-10-15 11:48:30 |          1 |
> |       3 | hourly_kaltura-dev-v5 | 2020-10-15 11:48:21 |          0 |
> |       4 | update_dims_lock      | 2020-10-15 11:48:24 |          0 |
> +---------+-----------------------+---------------------+------------+
> 4 rows in set (0.00 sec)

I updated the lock to read 0.

There was 4 items in
mysql> select * from kalturadw_ds.files
Nothing in
mysql> select * from kalturadw.dwh_fact_events

Executed the following
/opt/kaltura/bin/kaltura-run-dwh.sh

The lock is back at 1 but no stats
The DB is in the same server as everything, the timezone should be fine.

I did not reinstall/reconfigure DWH, should i simply be patient at this time and wait for tomorrow?

jess · October 15, 2020, 5:51pm

Hello @cedricguindon,

As noted in the documentation, and as you can see by reviewing /etc/cron.d/kaltura-dwh the analytics mechanism for CE is not a real time one.

Running /opt/kaltura/bin/kaltura-run-dwh.sh, however, forces everything to happen immediately (only meant for testing when you have a small amount to process, or when you’ve disabled the cron jobs).

If you still don’t see stats, check whether any of the related DWH jobs are still processing, if they finished running, check the log for errors.

cedricguindon · October 15, 2020, 7:25pm

Hello @jess

I executed kaltura-run-dwh.sh again, i can see a new entry in kalturadw_ds.files, looks like a new play on a video, the stats are still not showing up in the UI.

I checked the etl_update_dims-DATE.log and found the following error

ERROR 15-10 18:33:22,280 - Mapping (sub-transformation) - org.pentaho.di.core.exception.KettleException:
Unable to load the specified mapping

Error reading object from XML file

Unable to load step info from XML step nodeorg.pentaho.di.core.exception.KettleStepLoaderException:
Unable to load class for step/plugin with id [MapperFieldRunner]. Check if the plugin is available in the plugins subdirectory of the Kettle distribution.

Out of curiosity, i found the file that contains this path /opt/kaltura/dwh/etlsource/dimensions/execute_sequence.ktr and at the MapperFieldRunner step i could not find anything suspicious, i honestly can’t tell you what to look for but the file looks normal.

I saw in one of your previous post that it might be a permission issue, i checked the logs but could not find anywhere a path was mentionned, the user kaltura has access to read pretty much everything. in /opt/kaltura/

I also checked in the /opt/kaltura/pentaho/pdi/plugins/steps folder and could not find the MapperFieldRunner folder, not sure if that’s normal or i’m missing some plugins for some reason?

cedricguindon · October 19, 2020, 12:40pm

UPDATE

I have an old version of kaltura CE already running, i checked the pentaho/pdi/plugins/steps/ folder and found some plugins that were not in the new version, mainly MapperFieldRunner, so out of curiosity, i transferred the plugins from the old version to the new one, the errors in the dwh/logs folder are now gone. It’s not missing the step/plugin with id [MapperFieldRunner] anymore, no other step missing for that matter.

I checked the analytics and they were still not updated, i did the troubleshooting steps in https://github.com/kaltura/platform-install-packages/blob/Kajam-11.21.0/doc/kaltura-packages-faq.md#analytics-issues and they are still not showing up, but no errors however.

I could wait a day to see if my analytics are updating if needed but i’m not sure where to look at anymore.

Thank you!