Hello
I’m having some issues with my analytics server in my cluster.
The mysql server is also holding the sphinx and dwh roles.
mysql> select * from locks;
±--------±-----------------±--------------------±-----------+
| lock_id | lock_name | lock_time | lock_state |
±--------±-----------------±--------------------±-----------+
| 1 | daily_lock | 2016-07-05 11:12:18 | 0 |
| 2 | retention_lock | 2016-07-05 11:12:23 | 0 |
| 3 | hourly_mysql | 2016-07-05 11:12:06 | 0 |
| 4 | update_dims_lock | 2016-07-05 11:12:12 | 0 |
±--------±-----------------±--------------------±-----------+
4 rows in set (0.00 sec)
I have no erros whatsoever in :
rw-r–r--. 1 kaltura kaltura 76358 Jul 5 11:12 etl_daily-20160705.log
-rw-r–r--. 1 kaltura kaltura 21602 Jul 5 11:12 etl_hourly-20160705-11.log
-rw-r–r--. 1 kaltura kaltura 4071 Jul 5 11:12 etl_perform_retention_policy-20160705.log
-rw-r–r--. 1 kaltura kaltura 23601 Jul 5 11:12 etl_update_dims-20160705-11.log
-rw-r–r--. 1 kaltura kaltura 9580 Jul 5 11:12 log_aggregation_perform_aggregations.log
-rw-r–r--. 1 kaltura kaltura 10893 Jul 5 11:12 log_events_events.log
-rw-r–r--. 1 kaltura kaltura 63882 Jul 5 11:12 log_perform_referential_integrity.log
-rw-r–r--. 1 kaltura kaltura 1778 Jul 5 11:12 log_storage_usage_calc_storage_usage.log
-rw-r–r--. 1 kaltura kaltura 1066 Jul 5 11:12 log_totals_calc_totals.log
-rw-r–r--. 1 kaltura kaltura 634 Jul 5 11:12 log_transcoding_usage_calc_transcoding_usage.log
*[root@mysql logs]# tail -f .log
==> etl_daily-20160705.log <==
INFO 05-07 11:12:18,326 - daily - Finished job entry [Success 1] (result=[true])
INFO 05-07 11:12:18,326 - daily - Finished job entry [Release daily lock] (result=[true])
INFO 05-07 11:12:18,326 - daily - Finished job entry [Execute daily sequence] (result=[true])
INFO 05-07 11:12:18,327 - daily - Finished job entry [Set jobs sequence file name] (result=[true])
INFO 05-07 11:12:18,327 - daily - Finished job entry [Seize daily lock] (result=[true])
INFO 05-07 11:12:18,327 - daily - Finished job entry [Check if update_dims_lock is seized] (result=[true])
INFO 05-07 11:12:18,327 - daily - Job execution finished
INFO 05-07 11:12:18,328 - Kitchen - Finished!
INFO 05-07 11:12:18,328 - Kitchen - Start=2016/07/05 11:12:16.288, Stop=2016/07/05 11:12:18.328
INFO 05-07 11:12:18,328 - Kitchen - Processing ended after 2 seconds.
==> etl_hourly-20160705-11.log <==
INFO 05-07 11:12:06,604 - hourly - Finished job entry [Success 1] (result=[true])
INFO 05-07 11:12:06,604 - hourly - Finished job entry [Release hourly etl server lock ] (result=[true])
INFO 05-07 11:12:06,604 - hourly - Finished job entry [Execute hourly sequence] (result=[true])
INFO 05-07 11:12:06,605 - hourly - Finished job entry [Set jobs sequence file name] (result=[true])
INFO 05-07 11:12:06,605 - hourly - Finished job entry [Seize hourly etl server lock] (result=[true])
INFO 05-07 11:12:06,605 - hourly - Finished job entry [Register etl_server] (result=[true])
INFO 05-07 11:12:06,605 - hourly - Job execution finished
INFO 05-07 11:12:06,606 - Kitchen - Finished!
INFO 05-07 11:12:06,606 - Kitchen - Start=2016/07/05 11:12:04.496, Stop=2016/07/05 11:12:06.606
INFO 05-07 11:12:06,606 - Kitchen - Processing ended after 2 seconds.
==> etl_perform_retention_policy-20160705.log <==
INFO 05-07 11:12:23,126 - perform retention policy - Starting entry [Success 1]
INFO 05-07 11:12:23,127 - perform retention policy - Finished job entry [Success 1] (result=[true])
INFO 05-07 11:12:23,127 - perform retention policy - Finished job entry [Release retention lock] (result=[true])
INFO 05-07 11:12:23,127 - perform retention policy - Finished job entry [Create future partitions] (result=[true])
INFO 05-07 11:12:23,127 - perform retention policy - Finished job entry [Move old partitions to archive] (result=[true])
INFO 05-07 11:12:23,128 - perform retention policy - Finished job entry [Seize retention lock] (result=[true])
INFO 05-07 11:12:23,128 - perform retention policy - Job execution finished
INFO 05-07 11:12:23,140 - Kitchen - Finished!
INFO 05-07 11:12:23,140 - Kitchen - Start=2016/07/05 11:12:22.076, Stop=2016/07/05 11:12:23.140
INFO 05-07 11:12:23,140 - Kitchen - Processing ended after 1 seconds.
==> etl_update_dims-20160705-11.log <==
INFO 05-07 11:12:12,424 - Update Dimensions - Finished job entry [Iterate sequences] (result=[true])
INFO 05-07 11:12:12,424 - Update Dimensions - Finished job entry [Get Sequence] (result=[true])
INFO 05-07 11:12:12,424 - Update Dimensions - Finished job entry [get_operational_replication_synced_at] (result=[true])
INFO 05-07 11:12:12,425 - Update Dimensions - Finished job entry [get_last_updated_at] (result=[true])
INFO 05-07 11:12:12,425 - Update Dimensions - Finished job entry [Seize update dims lock] (result=[true])
INFO 05-07 11:12:12,425 - Update Dimensions - Finished job entry [Check if daily_lock is seized] (result=[true])
INFO 05-07 11:12:12,425 - Update Dimensions - Job execution finished
INFO 05-07 11:12:12,494 - Kitchen - Finished!
INFO 05-07 11:12:12,494 - Kitchen - Start=2016/07/05 11:12:10.361, Stop=2016/07/05 11:12:12.494
INFO 05-07 11:12:12,494 - Kitchen - Processing ended after 2 seconds.
==> log_aggregation_perform_aggregations.log <==
2016/07/05 11:12:17 - Table input.0 - Finished processing (I=0, O=0, R=1, W=0, U=0, E=0)
2016/07/05 11:12:17 - Table input.0 - Finished processing (I=0, O=0, R=1, W=0, U=0, E=0)
2016/07/05 11:12:17 - Read days to calc.0 - Finished processing (I=0, O=0, R=1, W=0, U=0, E=0)
2016/07/05 11:12:17 - aggregate events.0 - Finished reading query, closing connection.
2016/07/05 11:12:17 - aggregate bandwidth usage.0 - Finished reading query, closing connection.
2016/07/05 11:12:17 - aggregate plays.0 - Finished reading query, closing connection.
2016/07/05 11:12:17 - Read days to calc.0 - Finished reading query, closing connection.
2016/07/05 11:12:17 - Read days to calc.0 - Finished processing (I=0, O=0, R=1, W=0, U=0, E=0)
2016/07/05 11:12:17 - aggregate bandwidth usage.0 - Finished reading query, closing connection.
2016/07/05 11:12:18 - perform aggregations - Finished job entry [Perform aggregations] (result=[true])
==> log_events_events.log <==
2016/07/05 11:12:06 - Get cycle id.0 - Finished reading query, closing connection.
2016/07/05 11:12:06 - Get cycle id.0 - Finished processing (I=0, O=0, R=1, W=0, U=0, E=0)
2016/07/05 11:12:06 - transfer cycle - Starting entry [transfer cycle]
2016/07/05 11:12:06 - transfer cycle - Loading transformation from XML file [file:////opt/kaltura/dwh/etlsource/cycles/transfer_cycle.ktr]
2016/07/05 11:12:06 - transfer cycle - Finished job entry [transfer cycle] (result=[true])
2016/07/05 11:12:06 - transfer cycle - Finished job entry [Get processed cycle] (result=[true])
2016/07/05 11:12:06 - events cycle process - Finished job entry [transfer cycle] (result=[true])
2016/07/05 11:12:06 - events cycle process - Finished job entry [process cycle] (result=[true])
2016/07/05 11:12:06 - events cycle process - Finished job entry [generate_cycle] (result=[true])
2016/07/05 11:12:06 - events cycle process - Finished job entry [Set Main Variables] (result=[true])
==> log_perform_referential_integrity.log <==
2016/07/05 11:12:18 - Write to log.0 - last_updated_parameter_id = 00000000000000000000008
2016/07/05 11:12:18 - Write to log.0 -
2016/07/05 11:12:18 - Write to log.0 - ====================
2016/07/05 11:12:18 - Write to log.0 - Finished processing (I=0, O=0, R=1, W=1, U=0, E=0)
2016/07/05 11:12:18 - Update new last_updated_at.0 - Finished processing (I=1, O=0, R=1, W=1, U=1, E=0)
2016/07/05 11:12:18 - Perform Referencial Integrity - Starting entry [UPDATE aggr_managment RI]
2016/07/05 11:12:18 - Perform Referencial Integrity - Finished job entry [UPDATE aggr_managment RI] (result=[true])
2016/07/05 11:12:18 - Perform Referencial Integrity - Finished job entry [set_last_updated_at] (result=[true])
2016/07/05 11:12:18 - Perform Referencial Integrity - Finished job entry [perform referential integrity] (result=[true])
2016/07/05 11:12:18 - Perform Referencial Integrity - Finished job entry [get_last_updated_at] (result=[true])
==> log_storage_usage_calc_storage_usage.log <==
2016/07/05 11:12:17 - Table input.0 - Finished reading query, closing connection.
2016/07/05 11:12:17 - Execute SQL script.0 - Finished reading query, closing connection.
2016/07/05 11:12:17 - calc_storage_usage - Starting entry [Calc user storage usage]
2016/07/05 11:12:17 - Calc user storage usage - Loading transformation from XML file [/opt/kaltura/dwh/etlsource/storage_usage/calc_user_storage_usage.ktr]
2016/07/05 11:12:17 - calc_user_storage_usage - Dispatching started for transformation [calc_user_storage_usage]
2016/07/05 11:12:17 - Table input.0 - Finished reading query, closing connection.
2016/07/05 11:12:17 - Execute SQL script.0 - Finished reading query, closing connection.
2016/07/05 11:12:17 - calc_storage_usage - Finished job entry [Calc user storage usage] (result=[true])
2016/07/05 11:12:17 - calc_storage_usage - Finished job entry [Calc storage usage] (result=[true])
2016/07/05 11:12:17 - calc_storage_usage - Finished job entry [Add Storage Usage Missing Days] (result=[true])
==> log_totals_calc_totals.log <==
2016/07/05 11:12:17 - Add Storage Usage Missing Days - Loading transformation from XML file [/opt/kaltura/dwh/etlsource/aggregation/add_aggr_missing_days.ktr]
2016/07/05 11:12:17 - add_aggr_missing_days - Dispatching started for transformation [add_aggr_missing_days]
2016/07/05 11:12:17 - Table input.0 - Finished reading query, closing connection.
2016/07/05 11:12:17 - calc_totals - Starting entry [Calc Totals]
2016/07/05 11:12:17 - Calc Totals - Loading transformation from XML file [file:///opt/kaltura/dwh/etlsource/totals/calc_totals.ktr]
2016/07/05 11:12:17 - calc_totals - Dispatching started for transformation [calc_totals]
2016/07/05 11:12:17 - Table input.0 - Finished reading query, closing connection.
2016/07/05 11:12:17 - Execute SQL script.0 - Finished reading query, closing connection.
2016/07/05 11:12:17 - calc_totals - Finished job entry [Calc Totals] (result=[true])
2016/07/05 11:12:17 - calc_totals - Finished job entry [Add Totals Missing Days] (result=[true])
==> log_transcoding_usage_calc_transcoding_usage.log <==
2016/07/05 11:12:17 - calc_transcoding_usage - Starting entry [Calc transcoding usage]
2016/07/05 11:12:17 - Calc transcoding usage - Loading transformation from XML file [/opt/kaltura/dwh/etlsource/transcoding_usage/calc_transcoding_usage.ktr]
2016/07/05 11:12:17 - calc_transcoding_usage - Dispatching started for transformation [calc_transcoding_usage]
2016/07/05 11:12:17 - Table input.0 - Finished reading query, closing connection.
2016/07/05 11:12:17 - Execute SQL script.0 - Finished reading query, closing connection.
2016/07/05 11:12:17 - calc_transcoding_usage - Finished job entry [Calc transcoding usage] (result=[true])
/opt/kalltura/dwh/.kettle/kettle.proprieties is correctly populated.
In /etc/logrotate.d/ i have :
-rw-r–r--. 1 root root 139 Jul 24 2015 dracut
-rw-r–r--. 1 root root 172 Jul 23 2015 iscsiuiolog
lrwxrwxrwx. 1 root root 56 Jun 27 07:01 kaltura_apache -> /opt/kaltura/app/configurations/logrotate/kaltura_apache
lrwxrwxrwx. 1 root root 53 Jun 27 06:39 kaltura_api -> /opt/kaltura/app/configurations/logrotate/kaltura_api
lrwxrwxrwx. 1 root root 54 Jun 27 06:39 kaltura_base -> /opt/kaltura/app/configurations/logrotate/kaltura_base
-rw-r–r--. 1 root root 871 May 11 02:31 mysqld
-rw-r–r--. 1 root root 210 Dec 10 2014 syslog
-rw-r–r--. 1 root root 87 Jul 24 2015 yum
In the apache logs from the Front Node i have the GET request for collectings stats:
GET //api_v3/index.php?service=stats&action=collect&kalsig=88088ddc79d5a16f664f09eafa9f7f65&event%3AisFirstInSession=false&partnerId=102&event%3Aduration=5&apiVersion=3%2E1%2E5&event%3AentryId=0%5Fgw1g8o8g&event%3AsessionId=22C47495%2D95BB%2DCD8B%2DD7C3%2DBAC33C3D389C&event%3Aseek=false&event%3AuiconfId=23448232&clientTag=kdp%3Av3%2E9%2E9&ks=YjU5ZWM5YThlN2NhZjMxOWEyMDIzOWQ1Y2VlNjVjMDkwNTAzMzhhN3wxMDI7MTAyOzE0Njc4MDM1NzQ7MDsxNDY3NzE3MTc0LjE3MDQ7MDt2aWV3Oiosd2lkZ2V0OjE7Ow%3D%3D&event%3Areferrer=http%253A%2F%2F31%2E14%2E40%2E116%2Fkaltura%2Ehtml&event%3AobjectType=KalturaStatsEvent&event%3AeventType=13&event%3AcurrentPoint=0&event%3ApartnerId=102&event%3AeventTimestamp=1467732864836&ignoreNull=1&event%3AclientVer=3%2E0%3Av3%2E9%2E9 HTTP/1.1" 200 368 0/303 “http://31.14.40.116/kaltura.html” “Mozilla/5.0 (Windows NT 6.3; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/51.0.2704.103 Safari/537.36” “-” 162.244.80.123 “-” “portal.servcast.net” 4834 - - 1384 “-” “-” “-” “-” “-” -
As a side note, i am running behind a load balancer ( portal.servcast.net ) is the load balancer’s address.
/etc/cron.d look like:
-rw-r–r--. 1 root root 113 Nov 10 2015 0hourly
lrwxrwxrwx. 1 root root 40 Jul 5 07:32 kaltura-dwh -> /opt/kaltura/app/configurations/cron/dwh
-rw-------. 1 root root 108 May 20 2015 raid-check
WHERE
[root@mysql cron.d]# cat kaltura-dwh
00 * * * * kaltura /opt/kaltura/dwh/etlsource/execute/etl_hourly.sh -p /opt/kaltura/dwh -k /opt/kaltura/pentaho/pdi/kitchen.sh
00 * * * * kaltura /opt/kaltura/dwh/etlsource/execute/etl_update_dims.sh -p /opt/kaltura/dwh -k /opt/kaltura/pentaho/pdi/kitchen.sh
59 0,4,8,12,16,20 * * * kaltura /opt/kaltura/dwh/etlsource/execute/etl_daily.sh -p /opt/kaltura/dwh -k /opt/kaltura/pentaho/pdi/kitchen.sh
30 12 * * * kaltura /opt/kaltura/dwh/etlsource/execute/etl_perform_retention_policy.sh -p /opt/kaltura/dwh -k /opt/kaltura/pentaho/pdi/kitchen.sh
0 10 * * * kaltura /opt/kaltura/app/alpha/scripts/dwh/dwh_plays_views_sync.sh >> /opt/kaltura/log/cron.log
If i run ./opt/kaltura/bin/kaltura-run-dwh.sh, I get:
[root@mysql bin]# ./kaltura-run-dwh.sh
reading config file /etc/logrotate.d/kaltura_apache
reading config info for /opt/kaltura/log/kaltura_apache_errors.log
error: /etc/logrotate.d/kaltura_apache:12 unknown option ‘su’ – ignoring line
error: /etc/logrotate.d/kaltura_apache:12 unexpected text
reading config info for /opt/kaltura/log/kaltura_apache_access.log
error: /etc/logrotate.d/kaltura_apache:26 unknown option ‘su’ – ignoring line
error: /etc/logrotate.d/kaltura_apache:26 unexpected text
reading config info for /opt/kaltura/log/kaltura_apache_errors_ssl.log
error: /etc/logrotate.d/kaltura_apache:40 unknown option ‘su’ – ignoring line
error: /etc/logrotate.d/kaltura_apache:40 unexpected text
reading config info for /opt/kaltura/log/kaltura_apache_access_ssl.log
error: /etc/logrotate.d/kaltura_apache:54 unknown option ‘su’ – ignoring line
error: /etc/logrotate.d/kaltura_apache:54 unexpected text
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
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
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
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
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
considering log /opt/kaltura/log/kaltura_apache_errors_ssl.log
log /opt/kaltura/log/kaltura_apache_errors_ssl.log does not exist – skipping
not running postrotate script, since no logs were rotated
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
considering log /opt/kaltura/log/kaltura_apache_access_ssl.log
log /opt/kaltura/log/kaltura_apache_access_ssl.log does not exist – skipping
not running last action script, since no logs will be rotated
set default create context
Thank you and sorry for the long post.
Regards,
Jacob R.