SERVICE_FORBIDDEN error when adding entries on dropfolders

felipe.borrero · August 3, 2018, 12:06am

I have configured a Local Drop folder for an account on my Kaltura CE On-prem. It is configured to ingest on content (not xml). When I copy a File to the drop folder, the file gets listed on the DropFolder Ingestion list but I always got an error as the Drop Folder File cannot be updated.

I have check the logs and found a SERVICE_FORBIDDEN error for the dropfolder_dropfolderfile->updateStatus action.

I’v looked at the database and permissions for dropFolder are active for the partner_id.

I have checked the permissions_item table and also permissions_to_permissions_item but there are no records related to the partner_id on those two tables

Is there anything else I am missing?

@jess, could you give us a hand on this?

Regards,

Felipe Borrero
Operations Director
Calipso Comunicaciones S.A.

felipe.borrero · August 3, 2018, 12:14am

Forgot to add the evidence

This is my drop folder config:

select * from drop_folder where id=5\G;
*************************** 1. row ***************************
                   id: 5
           partner_id: 107
                 name: AmericaTV
          description:
                 type: 1
               status: 1
                   dc: 0
                 path: /opt/kaltura/web/dropfolders/AmericaTV
conversion_profile_id: 23
   file_delete_policy: 2
    file_handler_type: 1
   file_name_patterns: *
  file_handler_config: O:34:"DropFolderContentFileHandlerConfig":3:{s:54:" DropFolderContentFileHandlerConfig contentMatchPolicy";i:1;s:45:" DropFolderContentFileHandlerConfig slugRegex";s:30:"/(?P<referenceId>.+)[.]\w{2,}/";s:14:" * handlerType";i:1;}
                 tags:
           error_code: 0
    error_description:
           created_at: 2018-08-02 16:41:41
           updated_at: 2018-08-02 19:14:25
          custom_data: a:10:{s:24:"file_size_check_interval";i:10;s:21:"auto_file_delete_days";i:0;s:25:"ignore_file_name_patterns";s:9:"*.partial";s:11:"incremental";b:0;s:19:"last_file_timestamp";i:0;s:19:"metadata_profile_id";i:0;s:30:"categories_metadata_field_name";s:0:"";s:19:"enforce_entitlement";b:0;s:18:"should_validate_ks";b:0;s:16:"last_accessed_at";i:1533255265;}

Here is the entry on the drop_folder_file table:

select * from drop_folder_file where id=6\G;
*************************** 1. row ***************************
                         id: 6
                 partner_id: 117
             drop_folder_id: 6
                  file_name: PesebreTimeLapse.mov
                       type: 1
                     status: 1
                  file_size: 49439374
      file_size_last_set_at: 2018-08-02 17:07:17
                 error_code: 8
          error_description: Failed to update the drop folder file record in Kaltura.
                parsed_slug: NULL
              parsed_flavor: NULL
   lead_drop_folder_file_id: NULL
deleted_drop_folder_file_id: 0
              md5_file_name: 67d4b1c11e0a93df9035512c84398004
                   entry_id: NULL
                 created_at: 2018-08-02 17:07:17
                 updated_at: 2018-08-02 19:16:26
   upload_start_detected_at: 2018-08-02 17:07:17
     upload_end_detected_at: 2018-08-02 19:16:26
          import_started_at: NULL
            import_ended_at: NULL
                custom_data: a:1:{s:22:"last_modification_time";s:10:"1533247623";}

and here is the error log fragment:

    2018-08-02 19:17:27 [0.000106] [2037070628] [1063] [BATCH] [KalturaClientBase->doCurl] INFO: post: {"format":"3","ignoreNull":true,"clientTag":"batch: web01.cloudvideo.com.co KAsyncDropFolderWatcher index: 0 sessionId: 2037070628","apiVersion":"3.3.0","dropFolderFileId":"4","status":"9","partnerId":"107","ks":"====OMITED====","kalsig":"====OMITED===="}
2018-08-02 19:17:27 [0.015646] [2037070628] [1064] [BATCH] [KalturaClientBase->doQueue] INFO: server: [====OMITED====], session: [1692642584]
2018-08-02 19:17:27 [0.000139] [2037070628] [1065] [BATCH] [KalturaClientBase->doQueue] INFO: result (serialized): a:4:{s:4:"code";s:17:"SERVICE_FORBIDDEN";s:7:"message";s:76:"The access to service [dropfolder_dropfolderfile->updateStatus] is forbidden";s:10:"objectType";s:19:"KalturaAPIException";s:4:"args";a:1:{s:7:"SERVICE";s:39:"dropfolder_dropfolderfile->updateStatus";}}
2018-08-02 19:17:27 [0.000137] [2037070628] [1066] [BATCH] [KalturaClientBase->doQueue] INFO: result (object dump): Array
(
    [code] => SERVICE_FORBIDDEN
    [message] => The access to service [dropfolder_dropfolderfile->updateStatus] is forbidden
    [objectType] => KalturaAPIException
    [args] => Array
        (
            [SERVICE] => dropfolder_dropfolderfile->updateStatus
        )

)

Regards,

Felipe Borrero
Operations Director
Calipso Comunicaciones S.A.

felipe.borrero · August 30, 2018, 4:39pm

I wonder if some one has a possible solution for this issue

We have installed a fresh Kaltura CE on a different server and we had no trouble with the DropFolder ingestion.

We have compared all databases involved (as far as we know) and there are no great differences. We have changed some fields to the values on the fresh install but we had the same problem.

It is not possible to access the service dropfolder_dropfolderfile->updateStatus

Any clues that someone else could give us will be highly appreciated.

Regards,

Felipe Borrero
Operations Director
Calipso Comunicaciones S.A

jess · August 30, 2018, 4:54pm

Hi @felipe.borrero,

Is DROPFOLDER_PLUGIN_PERMISSION enabled for the partner?
To verify, go to Admin Console->Publishers->Your Partner->Actions->Configure and ensure the Content Ingestion - Drop Folder/s checkbox is checked.

Assuming that it is, if it still doesn’t work then check for errors in /opt/kaltura/log/kaltura_api_v3.log as well as in /opt/kaltura/log/batch/dropfolder*.log

Once you’ve got the relevant log lines, post them here and I’ll have a look.

felipe.borrero · August 31, 2018, 8:17pm

Hi @jess

I have double checked the Content Ingestion Drop Folders option for the publisher. I even remove the option, saved the publisher and set to on the option again. Got the same error

Here are the logs (posted on several replies as there is a limit for each reply)

2018-08-31 12:17:13 [0.002487] [181.135.216.36] [1050991477] [1] [API] [global] DEBUG: >------------------------------------- api_v3 -------------------------------------
2018-08-31 12:17:13 [0.000154] [181.135.216.36] [1050991477] [2] [API] [global] INFO: API-start pid:25006
2018-08-31 12:17:13 [0.000841] [127.0.0.1] [1152126973] [13] [API] [KalturaStatement->execute] DEBUG: /* web01.cloudvideo.com.co[1152126973][propel] */ SELECT permission.ID, permission.TYPE, permission.NAME, permission.FRIENDLY_NAME, permission.DESCRIPTION, permission.PAR
TNER_ID, permission.STATUS, permission.DEPENDS_ON_PERMISSION_NAMES, permission.TAGS, permission.CREATED_AT, permission.UPDATED_AT, permission.CUSTOM_DATA FROM `permission` WHERE permission.PARTNER_ID IN ('117','0') AND permission.NAME='FEATURE_ENTITLEMENT' ORDER BY permis
sion.STATUS ASC LIMIT 1
2018-08-31 12:17:13 [0.000381] [181.135.216.36] [1050991477] [3] [API] [KalturaFrontController->run] DEBUG: Params [Array
2018-08-31 12:17:13 [0.000785] [127.0.0.1] [1152126973] [14] [API] [KalturaStatement->execute] DEBUG: Sql took - 0.00058984756469727 seconds
2018-08-31 12:17:13 [0.001589] [127.0.0.1] [1152126973] [15] [API] [KalturaStatement->execute] DEBUG: /* web01.cloudvideo.com.co[1152126973][propel] */ SELECT permission.ID, permission.TYPE, permission.NAME, permission.FRIENDLY_NAME, permission.DESCRIPTION, permission.PAR
TNER_ID, permission.STATUS, permission.DEPENDS_ON_PERMISSION_NAMES, permission.TAGS, permission.CREATED_AT, permission.UPDATED_AT, permission.CUSTOM_DATA FROM `permission` WHERE permission.PARTNER_ID IN ('117','0') AND permission.NAME='DROPFOLDER_PLUGIN_PERMISSION' ORDER
BY permission.STATUS ASC LIMIT 1
2018-08-31 12:17:13 [0.000573] [127.0.0.1] [1152126973] [16] [API] [KalturaStatement->execute] DEBUG: Sql took - 0.00037312507629395 seconds
2018-08-31 12:17:13 [0.000254] [127.0.0.1] [1152126973] [17] [API] [KalturaDispatcher->dispatch] DEBUG: Invoke start
2018-08-31 12:17:13 [0.003537] [181.135.216.36] [1050991477] [4] [API] [KalturaDispatcher->dispatch] DEBUG: Dispatching service [stats], action [collect], reqIndex [1] with params Array
2018-08-31 12:17:13 [0.000877] [127.0.0.1] [1152126973] [18] [API] [KalturaStatement->execute] DEBUG: /* web01.cloudvideo.com.co[1152126973][propel] */ SELECT drop_folder.ID, drop_folder.PARTNER_ID, drop_folder.NAME, drop_folder.DESCRIPTION, drop_folder.TYPE, drop_folder.
STATUS, drop_folder.DC, drop_folder.PATH, drop_folder.CONVERSION_PROFILE_ID, drop_folder.FILE_DELETE_POLICY, drop_folder.FILE_HANDLER_TYPE, drop_folder.FILE_NAME_PATTERNS, drop_folder.FILE_HANDLER_CONFIG, drop_folder.TAGS, drop_folder.ERROR_CODE, drop_folder.ERROR_DESCRIP
TION, drop_folder.CREATED_AT, drop_folder.UPDATED_AT, drop_folder.CUSTOM_DATA FROM `drop_folder` WHERE drop_folder.ID='8' AND drop_folder.STATUS<>'2' AND drop_folder.PARTNER_ID='117'
2018-08-31 12:17:13 [0.000513] [127.0.0.1] [1152126973] [19] [API] [KalturaStatement->execute] DEBUG: Sql took - 0.00037002563476562 seconds
2018-08-31 12:17:13 [0.001703] [181.135.216.36] [1050991477] [5] [API] [KalturaPDO->__construct] DEBUG: conn took - 0.00053691864013672 seconds to mysql:host=127.0.0.1;port=3306;dbname=kaltura;
2018-08-31 12:17:13 [0.000185] [181.135.216.36] [1050991477] [6] [API] [Propel::initConnection] NOTICE: total conn took 0.00082206726074219 mysql:host=127.0.0.1;port=3306;dbname=kaltura;
2018-08-31 12:17:13 [0.000475] [181.135.216.36] [1050991477] [7] [API] [KalturaStatement->execute] DEBUG: /* web01.cloudvideo.com.co[1050991477][propel] */ SELECT permission.ID, permission.TYPE, permission.NAME, permission.FRIENDLY_NAME, permission.DESCRIPTION, permission
.PARTNER_ID, permission.STATUS, permission.DEPENDS_ON_PERMISSION_NAMES, permission.TAGS, permission.CREATED_AT, permission.UPDATED_AT, permission.CUSTOM_DATA FROM `permission` WHERE permission.PARTNER_ID IN ('','0') AND permission.NAME IN ('FEATURE_END_USER_REPORTS','FEAT
URE_ENTITLEMENT') AND permission.STATUS='1' GROUP BY permission.NAME
2018-08-31 12:17:13 [0.001851] [127.0.0.1] [1152126973] [20] [API] [KalturaStatement->execute] DEBUG: /* web01.cloudvideo.com.co[1152126973][propel] */ INSERT INTO drop_folder_file (`ID`,`PARTNER_ID`,`DROP_FOLDER_ID`,`FILE_NAME`,`TYPE`,`STATUS`,`FILE_SIZE`,`FILE_SIZE_LAST_SET_AT`,`MD5_FILE_NAME`,`CREATED_AT`,`UPDATED_AT`,`UPLOAD_START_DETECTED_AT`,`CUSTOM_DATA`) VALUES (NULL,'117','8','PesebreTimeLapse.mov','1','1','49439374','2018-08-31 12:17:13','67d4b1c11e0a93df9035512c84398004','2018-08-31 12:17:13','2018-08-31 12:17:13','2018-08-31 12:17:13','a:1:{s:22:"last_modification_time";s:10:"1535735824";}')
2018-08-31 12:17:13 [0.000658] [181.135.216.36] [1050991477] [8] [API] [KalturaStatement->execute] DEBUG: Sql took - 0.00051188468933105 seconds
2018-08-31 12:17:13 [0.001910] [181.135.216.36] [1050991477] [9] [API] [KalturaStatement->execute] DEBUG: /* web01.cloudvideo.com.co[1050991477][propel] */ SELECT kuser.ID, kuser.LOGIN_DATA_ID, kuser.IS_ADMIN, kuser.SCREEN_NAME, kuser.FULL_NAME, kuser.FIRST_NAME, kuser.LAST_NAME, kuser.EMAIL, kuser.SHA1_PASSWORD, kuser.SALT, kuser.DATE_OF_BIRTH, kuser.COUNTRY, kuser.STATE, kuser.CITY, kuser.ZIP, kuser.URL_LIST, kuser.PICTURE, kuser.ICON, kuser.ABOUT_ME, kuser.TAGS, kuser.TAGLINE, kuser.NETWORK_HIGHSCHOOL, kuser.NETWORK_COLLEGE, kuser.NETWORK_OTHER, kuser.MOBILE_NUM, kuser.MATURE_CONTENT, kuser.GENDER, kuser.REGISTRATION_IP, kuser.REGISTRATION_COOKIE, kuser.IM_LIST, kuser.VIEWS, kuser.FANS, kuser.ENTRIES, kuser.STORAGE_SIZE, kuser.PRODUCED_KSHOWS, kuser.STATUS, kuser.CREATED_AT, kuser.UPDATED_AT, kuser.PARTNER_ID, kuser.DISPLAY_IN_SEARCH, kuser.PARTNER_DATA, kuser.PUSER_ID, kuser.ADMIN_TAGS, kuser.INDEXED_PARTNER_DATA_INT, kuser.INDEXED_PARTNER_DATA_STRING, kuser.CUSTOM_DATA, kuser.TYPE FROM `kuser` WHERE kuser.PARTNER_ID IS NULL  AND kuser.PUSER_ID IS NULL  AND kuser.STATUS<>'2' ORDER BY kuser.UPDATED_AT DESC LIMIT 1
2018-08-31 12:17:13 [0.000759] [181.135.216.36] [1050991477] [10] [API] [KalturaStatement->execute] DEBUG: Sql took - 0.00060510635375977 seconds
2018-08-31 12:17:13 [0.000349] [181.135.216.36] [1050991477] [11] [API] [UserRolePeer::getIdByStrId] DEBUG: UserRole str_id [NO_SESSION_ROLE] mapped to id [3] - fetched from cache
2018-08-31 12:17:13 [0.000285] [181.135.216.36] [1050991477] [12] [API] [kPermissionManager::getFromCache] DEBUG: Found a cache value for key [role_3_partner_null_internal_1] map hash [d7dee0470975362628005734344f0c71] in layer [apcSerialized]
2018-08-31 12:17:13 [0.003679] [127.0.0.1] [1152126973] [21] [API] [KalturaStatement->execute] DEBUG: Sql took - 0.0035278797149658 seconds
2018-08-31 12:17:13 [0.000439] [127.0.0.1] [1152126973] [22] [API] [kObjectCreatedEvent->__construct] DEBUG: Event [kObjectCreatedEvent] object type [DropFolderFile] id [19]
2018-08-31 12:17:13 [0.000786] [181.135.216.36] [1050991477] [13] [API] [KalturaStatement->execute] DEBUG: /* web01.cloudvideo.com.co[1050991477][propel] */ SELECT partner.ID, partner.PARTNER_NAME, partner.PARTNER_ALIAS, partner.URL1, partner.URL2, partner.SECRET, partner.ADMIN_SECRET, partner.MAX_NUMBER_OF_HITS_PER_DAY, partner.APPEAR_IN_SEARCH, partner.DEBUG_LEVEL, partner.CREATED_AT, partner.UPDATED_AT, partner.ANONYMOUS_KUSER_ID, partner.KS_MAX_EXPIRY_IN_SECONDS, partner.CREATE_USER_ON_DEMAND, partner.PREFIX, partner.ADMIN_NAME, partner.ADMIN_EMAIL, partner.DESCRIPTION, partner.COMMERCIAL_USE, partner.MODERATE_CONTENT, partner.NOTIFY, partner.CUSTOM_DATA, partner.SERVICE_CONFIG_ID, partner.STATUS, partner.CONTENT_CATEGORIES, partner.TYPE, partner.PHONE, partner.DESCRIBE_YOURSELF, partner.ADULT_CONTENT, partner.PARTNER_PACKAGE, partner.USAGE_PERCENT, partner.STORAGE_USAGE, partner.EIGHTY_PERCENT_WARNING, partner.USAGE_LIMIT_WARNING, partner.MONITOR_USAGE, partner.PRIORITY_GROUP_ID, partner.PARTNER_GROUP_TYPE, partner.PARTNER_PARENT_ID, partner.KMC_VERSION FROM `partner` WHERE partner.ID='0'
2018-08-31 12:17:13 [0.002443] [127.0.0.1] [1152126973] [23] [API] [KalturaStatement->execute] DEBUG: /* web01.cloudvideo.com.co[1152126973][propel] */ SELECT permission.ID, permission.TYPE, permission.NAME, permission.FRIENDLY_NAME, permission.DESCRIPTION, permission.PARTNER_ID, permission.STATUS, permission.DEPENDS_ON_PERMISSION_NAMES, permission.TAGS, permission.CREATED_AT, permission.UPDATED_AT, permission.CUSTOM_DATA FROM `permission` WHERE permission.PARTNER_ID IN ('117','0') AND permission.NAME='EVENTNOTIFICATION_PLUGIN_PERMISSION' ORDER BY permission.STATUS ASC LIMIT 1
2018-08-31 12:17:13 [0.003258] [181.135.216.36] [1050991477] [14] [API] [KalturaStatement->execute] DEBUG: Sql took - 0.0030019283294678 seconds
2018-08-31 12:17:13 [0.001100] [127.0.0.1] [1152126973] [24] [API] [KalturaStatement->execute] DEBUG: Sql took - 0.00089883804321289 seconds
2018-08-31 12:17:13 [0.000316] [181.135.216.36] [1050991477] [15] [API] [KalturaDispatcher->dispatch] DEBUG: Invoke start
2018-08-31 12:17:13 [0.000225] [181.135.216.36] [1050991477] [16] [API] [KalturaDispatcher->dispatch] DEBUG: Invoke took - 0.00022411346435547 seconds
2018-08-31 12:17:13 [0.000094] [181.135.216.36] [1050991477] [17] [API] [KalturaDispatcher->dispatch] DEBUG: Dispatch took - 0.014251947402954 seconds, memory: 3145728
2018-08-31 12:17:13 [0.000186] [181.135.216.36] [1050991477] [18] [API] [KalturaFrontController->serializeResponse] DEBUG: Serialize start
2018-08-31 12:17:13 [0.000114] [181.135.216.36] [1050991477] [19] [API] [KalturaFrontController->serializeResponse] DEBUG: Serialize took - 0.00011014938354492
2018-08-31 12:17:13 [0.000845] [127.0.0.1] [1152126973] [25] [API] [KalturaStatement->execute] DEBUG: /* web01.cloudvideo.com.co[1152126973][propel] */ SELECT event_notification_template.ID, event_notification_template.PARTNER_ID, event_notification_template.NAME, event_notification_template.SYSTEM_NAME, event_notification_template.DESCRIPTION, event_notification_template.TYPE, event_notification_template.STATUS, event_notification_template.CREATED_AT, event_notification_template.UPDATED_AT, event_notification_template.CUSTOM_DATA, event_notification_template.EVENT_TYPE, event_notification_template.OBJECT_TYPE FROM `event_notification_template` WHERE (event_notification_template.STATUS='2' AND event_notification_template.STATUS<>'3') AND event_notification_template.PARTNER_ID IN ('0','117')
2018-08-31 12:17:13 [0.000086] [181.135.216.36] [1050991477] [20] [API] [global] INFO: API-end [0.017887830734253]
2018-08-31 12:17:13 [0.000079] [181.135.216.36] [1050991477] [21] [API] [global] DEBUG: <------------------------------------- api_v3 -------------------------------------

felipe.borrero · August 31, 2018, 8:18pm

2018-08-31 12:17:13 [0.001946] [127.0.0.1] [256466926] [1] [API] [global] DEBUG: >------------------------------------- api_v3 -------------------------------------
2018-08-31 12:17:13 [0.000105] [127.0.0.1] [256466926] [2] [API] [global] INFO: API-start pid:29341
2018-08-31 12:17:13 [0.000244] [127.0.0.1] [256466926] [3] [API] [KalturaFrontController->run] DEBUG: Params [Array
2018-08-31 12:17:13 [0.001581] [127.0.0.1] [256466926] [4] [API] [KalturaDispatcher->dispatch] DEBUG: Dispatching service [dropfolder_dropfolder], action [freeexclusivedropfolder], reqIndex [1] with params Array
2018-08-31 12:17:13 [0.001141] [127.0.0.1] [256466926] [5] [API] [KalturaPDO->__construct] DEBUG: conn took - 0.00034499168395996 seconds to mysql:host=127.0.0.1;port=3306;dbname=kaltura;
2018-08-31 12:17:13 [0.000166] [127.0.0.1] [256466926] [6] [API] [Propel::initConnection] NOTICE: total conn took 0.00055599212646484 mysql:host=127.0.0.1;port=3306;dbname=kaltura;
2018-08-31 12:17:13 [0.000433] [127.0.0.1] [256466926] [7] [API] [KalturaStatement->execute] DEBUG: /* web01.cloudvideo.com.co[256466926][propel] */ SELECT permission.ID, permission.TYPE, permission.NAME, permission.FRIENDLY_NAME, permission.DESCRIPTION, permission.PARTNER_ID, permission.STATUS, permission.DEPENDS_ON_PERMISSION_NAMES, permission.TAGS, permission.CREATED_AT, permission.UPDATED_AT, permission.CUSTOM_DATA FROM `permission` WHERE permission.PARTNER_ID IN ('-1','0') AND permission.NAME IN ('FEATURE_END_USER_REPORTS','FEATURE_ENTITLEMENT') AND permission.STATUS='1' GROUP BY permission.NAME
2018-08-31 12:17:13 [0.000661] [127.0.0.1] [256466926] [8] [API] [KalturaStatement->execute] DEBUG: Sql took - 0.00051498413085938 seconds
2018-08-31 12:17:13 [0.000857] [127.0.0.1] [256466926] [9] [API] [UserRolePeer::getIdByStrId] DEBUG: UserRole str_id [PARTNER_ADMIN_ROLE] mapped to id [2] - fetched from cache
2018-08-31 12:17:13 [0.001119] [127.0.0.1] [256466926] [10] [API] [kPermissionManager::getFromCache] DEBUG: Found a cache value for key [role_2_partner_-1_internal_1] map hash [5bfc389313978a27c96127d2930d07c4] in layer [apcSerialized]
2018-08-31 12:17:13 [0.000811] [127.0.0.1] [256466926] [11] [API] [KalturaStatement->execute] DEBUG: /* web01.cloudvideo.com.co[256466926][propel] */ SELECT partner.ID, partner.PARTNER_NAME, partner.PARTNER_ALIAS, partner.URL1, partner.URL2, partner.SECRET, partner.ADMIN_SECRET, partner.MAX_NUMBER_OF_HITS_PER_DAY, partner.APPEAR_IN_SEARCH, partner.DEBUG_LEVEL, partner.CREATED_AT, partner.UPDATED_AT, partner.ANONYMOUS_KUSER_ID, partner.KS_MAX_EXPIRY_IN_SECONDS, partner.CREATE_USER_ON_DEMAND, partner.PREFIX, partner.ADMIN_NAME, partner.ADMIN_EMAIL, partner.DESCRIPTION, partner.COMMERCIAL_USE, partner.MODERATE_CONTENT, partner.NOTIFY, partner.CUSTOM_DATA, partner.SERVICE_CONFIG_ID, partner.STATUS, partner.CONTENT_CATEGORIES, partner.TYPE, partner.PHONE, partner.DESCRIBE_YOURSELF, partner.ADULT_CONTENT, partner.PARTNER_PACKAGE, partner.USAGE_PERCENT, partner.STORAGE_USAGE, partner.EIGHTY_PERCENT_WARNING, partner.USAGE_LIMIT_WARNING, partner.MONITOR_USAGE, partner.PRIORITY_GROUP_ID, partner.PARTNER_GROUP_TYPE, partner.PARTNER_PARENT_ID, partner.KMC_VERSION FROM `partner` WHERE partner.ID='-1'
2018-08-31 12:17:13 [0.000586] [127.0.0.1] [256466926] [12] [API] [KalturaStatement->execute] DEBUG: Sql took - 0.00044488906860352 seconds
2018-08-31 12:17:13 [0.000431] [127.0.0.1] [256466926] [13] [API] [KalturaDispatcher->dispatch] DEBUG: Invoke start
2018-08-31 12:17:13 [0.000197] [127.0.0.1] [256466926] [14] [API] [kLockBase::safeLog] NOTICE: Releasing lock [__LOCKdropFolderLock_8]
2018-08-31 12:17:13 [0.000124] [127.0.0.1] [256466926] [15] [API] [kLockBase::safeLog] NOTICE: Lock released [__LOCKdropFolderLock_8]
2018-08-31 12:17:13 [0.000714] [127.0.0.1] [256466926] [16] [API] [KalturaStatement->execute] DEBUG: /* web01.cloudvideo.com.co[256466926][propel] */ SELECT drop_folder.ID, drop_folder.PARTNER_ID, drop_folder.NAME, drop_folder.DESCRIPTION, drop_folder.TYPE, drop_folder.STATUS, drop_folder.DC, drop_folder.PATH, drop_folder.CONVERSION_PROFILE_ID, drop_folder.FILE_DELETE_POLICY, drop_folder.FILE_HANDLER_TYPE, drop_folder.FILE_NAME_PATTERNS, drop_folder.FILE_HANDLER_CONFIG, drop_folder.TAGS, drop_folder.ERROR_CODE, drop_folder.ERROR_DESCRIPTION, drop_folder.CREATED_AT, drop_folder.UPDATED_AT, drop_folder.CUSTOM_DATA FROM `drop_folder` WHERE drop_folder.ID='8' AND drop_folder.STATUS<>'2'
2018-08-31 12:17:13 [0.000530] [127.0.0.1] [256466926] [17] [API] [KalturaStatement->execute] DEBUG: Sql took - 0.00039505958557129 seconds
2018-08-31 12:17:13 [0.000785] [127.0.0.1] [256466926] [18] [API] [KalturaStatement->execute] DEBUG: /* web01.cloudvideo.com.co[256466926][propel] */ UPDATE drop_folder SET `UPDATED_AT`='2018-08-31 12:17:13', `CUSTOM_DATA`='a:10:{s:24:"file_size_check_interval";i:10;s:21:"auto_file_delete_days";i:0;s:25:"ignore_file_name_patterns";s:0:"";s:11:"incremental";b:0;s:19:"last_file_timestamp";i:0;s:19:"metadata_profile_id";i:0;s:30:"categories_metadata_field_name";s:0:"";s:19:"enforce_entitlement";b:0;s:18:"should_validate_ks";b:0;s:16:"last_accessed_at";i:1535735833;}' WHERE drop_folder.ID='8' AND MD5(cast(drop_folder.CUSTOM_DATA as char character set latin1)) = 'fd736c6ab120d14112f97f5ba5bb9a8d'
2018-08-31 12:17:13 [0.008041] [127.0.0.1] [256466926] [19] [API] [KalturaStatement->execute] DEBUG: Sql took - 0.0079009532928467 seconds
2018-08-31 12:17:13 [0.000266] [127.0.0.1] [256466926] [20] [API] [kObjectChangedEvent->__construct] DEBUG: Event [kObjectChangedEvent] object type [DropFolder] id [8] modified columns [Array
2018-08-31 12:17:13 [0.001833] [127.0.0.1] [256466926] [21] [API] [KalturaStatement->execute] DEBUG: /* web01.cloudvideo.com.co[256466926][propel] */ SELECT partner.ID, partner.PARTNER_NAME, partner.PARTNER_ALIAS, partner.URL1, partner.URL2, partner.SECRET, partner.ADMIN_SECRET, partner.MAX_NUMBER_OF_HITS_PER_DAY, partner.APPEAR_IN_SEARCH, partner.DEBUG_LEVEL, partner.CREATED_AT, partner.UPDATED_AT, partner.ANONYMOUS_KUSER_ID, partner.KS_MAX_EXPIRY_IN_SECONDS, partner.CREATE_USER_ON_DEMAND, partner.PREFIX, partner.ADMIN_NAME, partner.ADMIN_EMAIL, partner.DESCRIPTION, partner.COMMERCIAL_USE, partner.MODERATE_CONTENT, partner.NOTIFY, partner.CUSTOM_DATA, partner.SERVICE_CONFIG_ID, partner.STATUS, partner.CONTENT_CATEGORIES, partner.TYPE, partner.PHONE, partner.DESCRIBE_YOURSELF, partner.ADULT_CONTENT, partner.PARTNER_PACKAGE, partner.USAGE_PERCENT, partner.STORAGE_USAGE, partner.EIGHTY_PERCENT_WARNING, partner.USAGE_LIMIT_WARNING, partner.MONITOR_USAGE, partner.PRIORITY_GROUP_ID, partner.PARTNER_GROUP_TYPE, partner.PARTNER_PARENT_ID, partner.KMC_VERSION FROM `partner` WHERE partner.ID='117'
2018-08-31 12:17:13 [0.000566] [127.0.0.1] [256466926] [22] [API] [KalturaStatement->execute] DEBUG: Sql took - 0.00042200088500977 seconds
2018-08-31 12:17:13 [0.000468] [127.0.0.1] [256466926] [23] [API] [KalturaStatement->execute] DEBUG: /* web01.cloudvideo.com.co[256466926][propel] */ SELECT permission.ID, permission.TYPE, permission.NAME, permission.FRIENDLY_NAME, permission.DESCRIPTION, permission.PARTNER_ID, permission.STATUS, permission.DEPENDS_ON_PERMISSION_NAMES, permission.TAGS, permission.CREATED_AT, permission.UPDATED_AT, permission.CUSTOM_DATA FROM `permission` WHERE permission.PARTNER_ID IN ('117','0') AND permission.NAME='EVENTNOTIFICATION_PLUGIN_PERMISSION' ORDER BY permission.STATUS ASC LIMIT 1
2018-08-31 12:17:13 [0.000588] [127.0.0.1] [256466926] [24] [API] [KalturaStatement->execute] DEBUG: Sql took - 0.00043988227844238 seconds
2018-08-31 12:17:13 [0.000950] [127.0.0.1] [256466926] [25] [API] [KalturaStatement->execute] DEBUG: /* web01.cloudvideo.com.co[256466926][propel] */ SELECT event_notification_template.ID, event_notification_template.PARTNER_ID, event_notification_template.NAME, event_notification_template.SYSTEM_NAME, event_notification_template.DESCRIPTION, event_notification_template.TYPE, event_notification_template.STATUS, event_notification_template.CREATED_AT, event_notification_template.UPDATED_AT, event_notification_template.CUSTOM_DATA, event_notification_template.EVENT_TYPE, event_notification_template.OBJECT_TYPE FROM `event_notification_template` WHERE (event_notification_template.STATUS='2' AND event_notification_template.STATUS<>'3') AND event_notification_template.PARTNER_ID IN ('0','117')
2018-08-31 12:17:13 [0.000542] [127.0.0.1] [256466926] [26] [API] [KalturaStatement->execute] DEBUG: Sql took - 0.0004119873046875 seconds
2018-08-31 12:17:13 [0.000144] [127.0.0.1] [256466926] [27] [API] [kEventNotificationFlowManager::getNotificationTemplates] INFO: Found [0] templates
2018-08-31 12:17:13 [0.000152] [127.0.0.1] [256466926] [28] [API] [kObjectSavedEvent->__construct] DEBUG: Event [kObjectSavedEvent] object type [DropFolder] id [8]
2018-08-31 12:17:13 [0.000935] [127.0.0.1] [256466926] [29] [API] [KalturaDispatcher->dispatch] DEBUG: Invoke took - 0.016833066940308 seconds
2018-08-31 12:17:13 [0.000101] [127.0.0.1] [256466926] [30] [API] [KalturaDispatcher->dispatch] DEBUG: Dispatch took - 0.024481058120728 seconds, memory: 3932160
2018-08-31 12:17:13 [0.000185] [127.0.0.1] [256466926] [31] [API] [KalturaFrontController->serializeResponse] DEBUG: Serialize start
2018-08-31 12:17:13 [0.000198] [127.0.0.1] [256466926] [32] [API] [KalturaFrontController->serializeResponse] DEBUG: Serialize took - 0.00019192695617676
2018-08-31 12:17:13 [0.000090] [127.0.0.1] [256466926] [33] [API] [global] INFO: API-end [0.027428865432739]
2018-08-31 12:17:13 [0.000079] [127.0.0.1] [256466926] [34] [API] [global] DEBUG: <------------------------------------- api_v3 -------------------------------------

felipe.borrero · August 31, 2018, 8:18pm

2018-08-31 12:17:13 [0.002896] [127.0.0.1] [673317474] [1] [API] [global] DEBUG: >------------------------------------- api_v3 -------------------------------------
2018-08-31 12:17:13 [0.000168] [127.0.0.1] [673317474] [2] [API] [global] INFO: API-start pid:3785
2018-08-31 12:17:13 [0.000356] [127.0.0.1] [673317474] [3] [API] [KalturaFrontController->run] DEBUG: Params [Array
2018-08-31 12:17:13 [0.003151] [127.0.0.1] [673317474] [4] [API] [KalturaDispatcher->dispatch] DEBUG: Dispatching service [dropfolder_dropfolderfile], action [update], reqIndex [1] with params Array
2018-08-31 12:17:13 [0.001259] [127.0.0.1] [673317474] [5] [API] [KalturaPDO->__construct] DEBUG: conn took - 0.00042200088500977 seconds to mysql:host=127.0.0.1;port=3306;dbname=kaltura;
2018-08-31 12:17:13 [0.000168] [127.0.0.1] [673317474] [6] [API] [Propel::initConnection] NOTICE: total conn took 0.0006401538848877 mysql:host=127.0.0.1;port=3306;dbname=kaltura;
2018-08-31 12:17:13 [0.000447] [127.0.0.1] [673317474] [7] [API] [KalturaStatement->execute] DEBUG: /* web01.cloudvideo.com.co[673317474][propel] */ SELECT permission.ID, permission.TYPE, permission.NAME, permission.FRIENDLY_NAME, permission.DESCRIPTION, permission.PARTNER_ID, permission.STATUS, permission.DEPENDS_ON_PERMISSION_NAMES, permission.TAGS, permission.CREATED_AT, permission.UPDATED_AT, permission.CUSTOM_DATA FROM `permission` WHERE permission.PARTNER_ID IN ('-1','0') AND permission.NAME IN ('FEATURE_END_USER_REPORTS','FEATURE_ENTITLEMENT') AND permission.STATUS='1' GROUP BY permission.NAME
2018-08-31 12:17:13 [0.000983] [127.0.0.1] [673317474] [8] [API] [KalturaStatement->execute] DEBUG: Sql took - 0.00084686279296875 seconds
2018-08-31 12:17:13 [0.000962] [127.0.0.1] [673317474] [9] [API] [UserRolePeer::getIdByStrId] DEBUG: UserRole str_id [PARTNER_ADMIN_ROLE] mapped to id [2] - fetched from cache
2018-08-31 12:17:13 [0.001134] [127.0.0.1] [673317474] [10] [API] [kPermissionManager::getFromCache] DEBUG: Found a cache value for key [role_2_partner_-1_internal_1] map hash [5bfc389313978a27c96127d2930d07c4] in layer [apcSerialized]
2018-08-31 12:17:13 [0.000747] [127.0.0.1] [673317474] [11] [API] [KalturaStatement->execute] DEBUG: /* web01.cloudvideo.com.co[673317474][propel] */ SELECT partner.ID, partner.PARTNER_NAME, partner.PARTNER_ALIAS, partner.URL1, partner.URL2, partner.SECRET, partner.ADMIN_SECRET, partner.MAX_NUMBER_OF_HITS_PER_DAY, partner.APPEAR_IN_SEARCH, partner.DEBUG_LEVEL, partner.CREATED_AT, partner.UPDATED_AT, partner.ANONYMOUS_KUSER_ID, partner.KS_MAX_EXPIRY_IN_SECONDS, partner.CREATE_USER_ON_DEMAND, partner.PREFIX, partner.ADMIN_NAME, partner.ADMIN_EMAIL, partner.DESCRIPTION, partner.COMMERCIAL_USE, partner.MODERATE_CONTENT, partner.NOTIFY, partner.CUSTOM_DATA, partner.SERVICE_CONFIG_ID, partner.STATUS, partner.CONTENT_CATEGORIES, partner.TYPE, partner.PHONE, partner.DESCRIBE_YOURSELF, partner.ADULT_CONTENT, partner.PARTNER_PACKAGE, partner.USAGE_PERCENT, partner.STORAGE_USAGE, partner.EIGHTY_PERCENT_WARNING, partner.USAGE_LIMIT_WARNING, partner.MONITOR_USAGE, partner.PRIORITY_GROUP_ID, partner.PARTNER_GROUP_TYPE, partner.PARTNER_PARENT_ID, partner.KMC_VERSION FROM `partner` WHERE partner.ID='107'




2018-08-31 12:17:13 [0.001799] [190.242.60.250] [2093152673] [1] [API] [global] DEBUG: >------------------------------------- api_v3 -------------------------------------
2018-08-31 12:17:13 [0.000583] [127.0.0.1] [673317474] [12] [API] [KalturaStatement->execute] DEBUG: Sql took - 0.00044989585876465 seconds
2018-08-31 12:17:13 [0.000110] [190.242.60.250] [2093152673] [2] [API] [global] INFO: API-start pid:19579
2018-08-31 12:17:13 [0.000266] [190.242.60.250] [2093152673] [3] [API] [KalturaFrontController->run] DEBUG: Params [Array
2018-08-31 12:17:13 [0.000570] [127.0.0.1] [673317474] [13] [API] [KalturaStatement->execute] DEBUG: /* web01.cloudvideo.com.co[673317474][propel] */ SELECT permission.ID, permission.TYPE, permission.NAME, permission.FRIENDLY_NAME, permission.DESCRIPTION, permission.PARTNER_ID, permission.STATUS, permission.DEPENDS_ON_PERMISSION_NAMES, permission.TAGS, permission.CREATED_AT, permission.UPDATED_AT, permission.CUSTOM_DATA FROM `permission` WHERE permission.PARTNER_ID IN ('107','0') AND permission.NAME='FEATURE_ENTITLEMENT' ORDER BY permission.STATUS ASC LIMIT 1
2018-08-31 12:17:13 [0.000639] [127.0.0.1] [673317474] [14] [API] [KalturaStatement->execute] DEBUG: Sql took - 0.00049519538879395 seconds
2018-08-31 12:17:13 [0.001089] [127.0.0.1] [673317474] [15] [API] [KalturaStatement->execute] DEBUG: /* web01.cloudvideo.com.co[673317474][propel] */ SELECT permission.ID, permission.TYPE, permission.NAME, permission.FRIENDLY_NAME, permission.DESCRIPTION, permission.PARTNER_ID, permission.STATUS, permission.DEPENDS_ON_PERMISSION_NAMES, permission.TAGS, permission.CREATED_AT, permission.UPDATED_AT, permission.CUSTOM_DATA FROM `permission` WHERE permission.PARTNER_ID IN ('107','0') AND permission.NAME='DROPFOLDER_PLUGIN_PERMISSION' ORDER BY permission.STATUS ASC LIMIT 1
2018-08-31 12:17:13 [0.000496] [127.0.0.1] [673317474] [16] [API] [KalturaStatement->execute] DEBUG: Sql took - 0.00036501884460449 seconds
2018-08-31 12:17:13 [0.000196] [127.0.0.1] [673317474] [17] [API] [KalturaDispatcher->dispatch] DEBUG: Invoke start
2018-08-31 12:17:13 [0.002665] [190.242.60.250] [2093152673] [4] [API] [KalturaDispatcher->dispatch] DEBUG: Dispatching service [stats], action [collect], reqIndex [1] with params Array
2018-08-31 12:17:13 [0.000852] [127.0.0.1] [673317474] [18] [API] [KalturaStatement->execute] DEBUG: /* web01.cloudvideo.com.co[673317474][propel] */ SELECT drop_folder_file.ID, drop_folder_file.PARTNER_ID, drop_folder_file.DROP_FOLDER_ID, drop_folder_file.FILE_NAME, drop_folder_file.TYPE, drop_folder_file.STATUS, drop_folder_file.FILE_SIZE, drop_folder_file.FILE_SIZE_LAST_SET_AT, drop_folder_file.ERROR_CODE, drop_folder_file.ERROR_DESCRIPTION, drop_folder_file.PARSED_SLUG, drop_folder_file.PARSED_FLAVOR, drop_folder_file.LEAD_DROP_FOLDER_FILE_ID, drop_folder_file.DELETED_DROP_FOLDER_FILE_ID, drop_folder_file.MD5_FILE_NAME, drop_folder_file.ENTRY_ID, drop_folder_file.CREATED_AT, drop_folder_file.UPDATED_AT, drop_folder_file.UPLOAD_START_DETECTED_AT, drop_folder_file.UPLOAD_END_DETECTED_AT, drop_folder_file.IMPORT_STARTED_AT, drop_folder_file.IMPORT_ENDED_AT, drop_folder_file.CUSTOM_DATA FROM `drop_folder_file` WHERE drop_folder_file.ID='9' AND drop_folder_file.STATUS<>'7' AND drop_folder_file.PARTNER_ID='107'
2018-08-31 12:17:13 [0.000515] [127.0.0.1] [673317474] [19] [API] [KalturaStatement->execute] DEBUG: Sql took - 0.00036191940307617 seconds
2018-08-31 12:17:13 [0.001659] [190.242.60.250] [2093152673] [5] [API] [KalturaPDO->__construct] DEBUG: conn took - 0.00047588348388672 seconds to mysql:host=127.0.0.1;port=3306;dbname=kaltura;
2018-08-31 12:17:13 [0.000187] [190.242.60.250] [2093152673] [6] [API] [Propel::initConnection] NOTICE: total conn took 0.00075316429138184 mysql:host=127.0.0.1;port=3306;dbname=kaltura;
2018-08-31 12:17:13 [0.000948] [127.0.0.1] [673317474] [20] [API] [KalturaDispatcher->dispatch] DEBUG: Invoke took - 0.0023128986358643 seconds
2018-08-31 12:17:13 [0.000510] [190.242.60.250] [2093152673] [7] [API] [KalturaStatement->execute] DEBUG: /* web01.cloudvideo.com.co[2093152673][propel] */ SELECT permission.ID, permission.TYPE, permission.NAME, permission.FRIENDLY_NAME, permission.DESCRIPTION, permission.PARTNER_ID, permission.STATUS, permission.DEPENDS_ON_PERMISSION_NAMES, permission.TAGS, permission.CREATED_AT, permission.UPDATED_AT, permission.CUSTOM_DATA FROM `permission` WHERE permission.PARTNER_ID IN ('','0') AND permission.NAME IN ('FEATURE_END_USER_REPORTS','FEATURE_ENTITLEMENT') AND permission.STATUS='1' GROUP BY permission.NAME
2018-08-31 12:17:13 [0.000103] [127.0.0.1] [673317474] [21] [API] [KalturaDispatcher->dispatch] DEBUG: Dispatch took - 0.014513969421387 seconds, memory: 3670016
2018-08-31 12:17:13 [0.000190] [127.0.0.1] [673317474] [22] [API] [KalturaFrontController->serializeResponse] DEBUG: Serialize start
2018-08-31 12:17:13 [0.000179] [127.0.0.1] [673317474] [23] [API] [KalturaFrontController->serializeResponse] DEBUG: Serialize took - 0.00017189979553223
2018-08-31 12:17:13 [0.000091] [127.0.0.1] [673317474] [24] [API] [global] INFO: API-end [0.018658876419067]
2018-08-31 12:17:13 [0.000081] [127.0.0.1] [673317474] [25] [API] [global] DEBUG: <------------------------------------- api_v3 -------------------------------------


2018-08-31 12:17:13 [0.002674] [127.0.0.1] [971371506] [1] [API] [global] DEBUG: >------------------------------------- api_v3 -------------------------------------
2018-08-31 12:17:13 [0.000152] [127.0.0.1] [971371506] [2] [API] [global] INFO: API-start pid:25006
2018-08-31 12:17:13 [0.000335] [127.0.0.1] [971371506] [3] [API] [KalturaFrontController->run] DEBUG: Params [Array
2018-08-31 12:17:13 [0.002802] [127.0.0.1] [971371506] [4] [API] [KalturaDispatcher->dispatch] DEBUG: Dispatching service [dropfolder_dropfolderfile], action [updatestatus], reqIndex [1] with params Array

felipe.borrero · August 31, 2018, 8:19pm

2018-08-31 12:17:13 [0.001606] [181.68.4.140] [1038212575] [1] [API] [global] DEBUG: >------------------------------------- api_v3 -------------------------------------
2018-08-31 12:17:13 [0.000113] [181.68.4.140] [1038212575] [2] [API] [global] INFO: API-start pid:25395
2018-08-31 12:17:13 [0.001761] [181.68.4.140] [1929380002] [5] [API] [KalturaPDO->__construct] DEBUG: conn took - 0.0005490779876709 seconds to mysql:host=127.0.0.1;port=3306;dbname=kaltura;
2018-08-31 12:17:13 [0.000202] [181.68.4.140] [1929380002] [6] [API] [Propel::initConnection] NOTICE: total conn took 0.00086092948913574 mysql:host=127.0.0.1;port=3306;dbname=kaltura;
2018-08-31 12:17:13 [0.000250] [181.68.4.140] [1038212575] [3] [API] [KalturaFrontController->run] DEBUG: Params [Array
2018-08-31 12:17:13 [0.000946] [127.0.0.1] [971371506] [9] [API] [UserRolePeer::getIdByStrId] DEBUG: UserRole str_id [PARTNER_ADMIN_ROLE] mapped to id [2] - fetched from cache
2018-08-31 12:17:13 [0.000512] [181.68.4.140] [1929380002] [7] [API] [KalturaStatement->execute] DEBUG: /* web01.cloudvideo.com.co[1929380002][propel] */ SELECT permission.ID, permission.TYPE, permission.NAME, permission.FRIENDLY_NAME, permission.DESCRIPTION, permission.PARTNER_ID, permission.STATUS, permission.DEPENDS_ON_PERMISSION_NAMES, permission.TAGS, permission.CREATED_AT, permission.UPDATED_AT, permission.CUSTOM_DATA FROM `permission` WHERE permission.PARTNER_ID IN ('','0') AND permission.NAME IN ('FEATURE_END_USER_REPORTS','FEATURE_ENTITLEMENT') AND permission.STATUS='1' GROUP BY permission.NAME
2018-08-31 12:17:13 [0.001017] [181.68.4.140] [1038212575] [4] [API] [KalturaDispatcher->dispatch] DEBUG: Dispatching service [session], action [startwidgetsession], reqIndex [1] with params Array
2018-08-31 12:17:13 [0.000646] [181.68.4.140] [1929380002] [8] [API] [KalturaStatement->execute] DEBUG: Sql took - 0.00050806999206543 seconds
2018-08-31 12:17:13 [0.001135] [127.0.0.1] [971371506] [10] [API] [kPermissionManager::getFromCache] DEBUG: Found a cache value for key [role_2_partner_-1_internal_1] map hash [5bfc389313978a27c96127d2930d07c4] in layer [apcSerialized]
2018-08-31 12:17:13 [0.000754] [127.0.0.1] [971371506] [11] [API] [KalturaStatement->execute] DEBUG: /* web01.cloudvideo.com.co[971371506][propel] */ SELECT partner.ID, partner.PARTNER_NAME, partner.PARTNER_ALIAS, partner.URL1, partner.URL2, partner.SECRET, partner.ADMIN_SECRET, partner.MAX_NUMBER_OF_HITS_PER_DAY, partner.APPEAR_IN_SEARCH, partner.DEBUG_LEVEL, partner.CREATED_AT, partner.UPDATED_AT, partner.ANONYMOUS_KUSER_ID, partner.KS_MAX_EXPIRY_IN_SECONDS, partner.CREATE_USER_ON_DEMAND, partner.PREFIX, partner.ADMIN_NAME, partner.ADMIN_EMAIL, partner.DESCRIPTION, partner.COMMERCIAL_USE, partner.MODERATE_CONTENT, partner.NOTIFY, partner.CUSTOM_DATA, partner.SERVICE_CONFIG_ID, partner.STATUS, partner.CONTENT_CATEGORIES, partner.TYPE, partner.PHONE, partner.DESCRIBE_YOURSELF, partner.ADULT_CONTENT, partner.PARTNER_PACKAGE, partner.USAGE_PERCENT, partner.STORAGE_USAGE, partner.EIGHTY_PERCENT_WARNING, partner.USAGE_LIMIT_WARNING, partner.MONITOR_USAGE, partner.PRIORITY_GROUP_ID, partner.PARTNER_GROUP_TYPE, partner.PARTNER_PARENT_ID, partner.KMC_VERSION FROM `partner` WHERE partner.ID='107'
2018-08-31 12:17:13 [0.000631] [127.0.0.1] [971371506] [12] [API] [KalturaStatement->execute] DEBUG: Sql took - 0.00050187110900879 seconds
2018-08-31 12:17:13 [0.001651] [181.68.4.140] [1038212575] [5] [API] [KalturaPDO->__construct] DEBUG: conn took - 0.00048685073852539 seconds to mysql:host=127.0.0.1;port=3306;dbname=kaltura;
2018-08-31 12:17:13 [0.000196] [181.68.4.140] [1038212575] [6] [API] [Propel::initConnection] NOTICE: total conn took 0.00076603889465332 mysql:host=127.0.0.1;port=3306;dbname=kaltura;
2018-08-31 12:17:13 [0.001964] [181.68.4.140] [1929380002] [9] [API] [KalturaStatement->execute] DEBUG: /* web01.cloudvideo.com.co[1929380002][propel] */ SELECT kuser.ID, kuser.LOGIN_DATA_ID, kuser.IS_ADMIN, kuser.SCREEN_NAME, kuser.FULL_NAME, kuser.FIRST_NAME, kuser.LAST_NAME, kuser.EMAIL, kuser.SHA1_PASSWORD, kuser.SALT, kuser.DATE_OF_BIRTH, kuser.COUNTRY, kuser.STATE, kuser.CITY, kuser.ZIP, kuser.URL_LIST, kuser.PICTURE, kuser.ICON, kuser.ABOUT_ME, kuser.TAGS, kuser.TAGLINE, kuser.NETWORK_HIGHSCHOOL, kuser.NETWORK_COLLEGE, kuser.NETWORK_OTHER, kuser.MOBILE_NUM, kuser.MATURE_CONTENT, kuser.GENDER, kuser.REGISTRATION_IP, kuser.REGISTRATION_COOKIE, kuser.IM_LIST, kuser.VIEWS, kuser.FANS, kuser.ENTRIES, kuser.STORAGE_SIZE, kuser.PRODUCED_KSHOWS, kuser.STATUS, kuser.CREATED_AT, kuser.UPDATED_AT, kuser.PARTNER_ID, kuser.DISPLAY_IN_SEARCH, kuser.PARTNER_DATA, kuser.PUSER_ID, kuser.ADMIN_TAGS, kuser.INDEXED_PARTNER_DATA_INT, kuser.INDEXED_PARTNER_DATA_STRING, kuser.CUSTOM_DATA, kuser.TYPE FROM `kuser` WHERE kuser.PARTNER_ID IS NULL  AND kuser.PUSER_ID IS NULL  AND kuser.STATUS<>'2' ORDER BY kuser.UPDATED_AT DESC LIMIT 1
2018-08-31 12:17:13 [0.000572] [127.0.0.1] [971371506] [13] [API] [KalturaStatement->execute] DEBUG: /* web01.cloudvideo.com.co[971371506][propel] */ SELECT permission.ID, permission.TYPE, permission.NAME, permission.FRIENDLY_NAME, permission.DESCRIPTION, permission.PARTNER_ID, permission.STATUS, permission.DEPENDS_ON_PERMISSION_NAMES, permission.TAGS, permission.CREATED_AT, permission.UPDATED_AT, permission.CUSTOM_DATA FROM `permission` WHERE permission.PARTNER_ID IN ('107','0') AND permission.NAME='FEATURE_ENTITLEMENT' ORDER BY permission.STATUS ASC LIMIT 1
2018-08-31 12:17:13 [0.000476] [181.68.4.140] [1038212575] [7] [API] [KalturaStatement->execute] DEBUG: /* web01.cloudvideo.com.co[1038212575][propel] */ SELECT permission.ID, permission.TYPE, permission.NAME, permission.FRIENDLY_NAME, permission.DESCRIPTION, permission.PARTNER_ID, permission.STATUS, permission.DEPENDS_ON_PERMISSION_NAMES, permission.TAGS, permission.CREATED_AT, permission.UPDATED_AT, permission.CUSTOM_DATA FROM `permission` WHERE permission.PARTNER_ID IN ('','0') AND permission.NAME IN ('FEATURE_END_USER_REPORTS','FEATURE_ENTITLEMENT') AND permission.STATUS='1' GROUP BY permission.NAME
2018-08-31 12:17:13 [0.000628] [127.0.0.1] [971371506] [14] [API] [KalturaStatement->execute] DEBUG: Sql took - 0.00049901008605957 seconds
2018-08-31 12:17:13 [0.000772] [181.68.4.140] [1929380002] [10] [API] [KalturaStatement->execute] DEBUG: Sql took - 0.00062394142150879 seconds
2018-08-31 12:17:13 [0.000737] [181.68.4.140] [1038212575] [8] [API] [KalturaStatement->execute] DEBUG: Sql took - 0.00061678886413574 seconds
2018-08-31 12:17:13 [0.000348] [181.68.4.140] [1929380002] [11] [API] [UserRolePeer::getIdByStrId] DEBUG: UserRole str_id [NO_SESSION_ROLE] mapped to id [3] - fetched from cache
2018-08-31 12:17:13 [0.000584] [127.0.0.1] [971371506] [15] [API] [kPermissionManager::isPartnerAccessAllowed] DEBUG: Operating partner [-1] not allowed using requested partner [107] with partner group [-1]
2018-08-31 12:17:13 [0.000286] [181.68.4.140] [1929380002] [12] [API] [kPermissionManager::getFromCache] DEBUG: Found a cache value for key [role_3_partner_null_internal_1] map hash [d7dee0470975362628005734344f0c71] in layer [apcSerialized]
2018-08-31 12:17:13 [0.000174] [127.0.0.1] [971371506] [16] [API] [kPermissionManager::isActionPermitted] ERR: exception 'Exception' with message 'Partner is not allowed' in /opt/kaltura/app/infra/log/KalturaLog.php:83
2018-08-31 12:17:13 [0.000167] [127.0.0.1] [971371506] [17] [API] [KalturaBaseService->isPermitted] ERR: exception 'Exception' with message 'Action is not permitted' in /opt/kaltura/app/infra/log/KalturaLog.php:83
2018-08-31 12:17:13 [0.000192] [127.0.0.1] [971371506] [18] [API] [KalturaBaseService->isPermitted] ERR: exception 'Exception' with message 'Kaltura network is not allowed' in /opt/kaltura/app/infra/log/KalturaLog.php:83
2018-08-31 12:17:13 [0.000376] [127.0.0.1] [971371506] [19] [API] [KalturaFrontController->getExceptionObject] ERR: exception 'KalturaAPIException' with message 'The access to service [dropfolder_dropfolderfile->updateStatus] is forbidden' in /opt/kaltura/app/api_v3/lib/KalturaBaseService.php:135
2018-08-31 12:17:13 [0.000742] [181.68.4.140] [1929380002] [13] [API] [KalturaStatement->execute] DEBUG: /* web01.cloudvideo.com.co[1929380002][propel] */ SELECT partner.ID, partner.PARTNER_NAME, partner.PARTNER_ALIAS, partner.URL1, partner.URL2, partner.SECRET, partner.ADMIN_SECRET, partner.MAX_NUMBER_OF_HITS_PER_DAY, partner.APPEAR_IN_SEARCH, partner.DEBUG_LEVEL, partner.CREATED_AT, partner.UPDATED_AT, partner.ANONYMOUS_KUSER_ID, partner.KS_MAX_EXPIRY_IN_SECONDS, partner.CREATE_USER_ON_DEMAND, partner.PREFIX, partner.ADMIN_NAME, partner.ADMIN_EMAIL, partner.DESCRIPTION, partner.COMMERCIAL_USE, partner.MODERATE_CONTENT, partner.NOTIFY, partner.CUSTOM_DATA, partner.SERVICE_CONFIG_ID, partner.STATUS, partner.CONTENT_CATEGORIES, partner.TYPE, partner.PHONE, partner.DESCRIBE_YOURSELF, partner.ADULT_CONTENT, partner.PARTNER_PACKAGE, partner.USAGE_PERCENT, partner.STORAGE_USAGE, partner.EIGHTY_PERCENT_WARNING, partner.USAGE_LIMIT_WARNING, partner.MONITOR_USAGE, partner.PRIORITY_GROUP_ID, partner.PARTNER_GROUP_TYPE, partner.PARTNER_PARENT_ID, partner.KMC_VERSION FROM `partner` WHERE partner.ID='0'
2018-08-31 12:17:13 [0.000187] [127.0.0.1] [971371506] [20] [API] [KalturaFrontController->serializeResponse] DEBUG: Serialize start
2018-08-31 12:17:13 [0.000123] [127.0.0.1] [971371506] [21] [API] [KalturaFrontController->serializeResponse] DEBUG: Serialize took - 0.00011897087097168
2018-08-31 12:17:13 [0.000102] [127.0.0.1] [971371506] [22] [API] [global] INFO: API-end [0.015249967575073]

jess · August 31, 2018, 9:39pm

Hi @felipe.borrero,

What does:

mysql> SELECT permission.ID, permission.TYPE, permission.NAME, permission.FRIENDLY_NAME, permission.DESCRIPTION, permission.PARTNER_ID, permission.STATUS, permission.DEPENDS_ON_PERMISSION_NAMES, permission.TAGS, permission.CREATED_AT, permission.UPDATED_AT, permission.CUSTOM_DATA FROM `permission` WHERE permission.PARTNER_ID IN ('107','0') AND permission.NAME='DROPFOLDER_PLUGIN_PERMISSION' ORDER BY permission.STATUS ASC LIMIT 1;

Return?

It should return a record similar to this one:

*************************** 1. row ***************************
                         ID: 344
                       TYPE: 3
                       NAME: DROPFOLDER_PLUGIN_PERMISSION
              FRIENDLY_NAME: NULL
                DESCRIPTION: NULL
                 PARTNER_ID: 107
                     STATUS: 1
DEPENDS_ON_PERMISSION_NAMES: NULL
                       TAGS: NULL
                 CREATED_AT: 2018-08-31 17:08:47
                 UPDATED_AT: 2018-08-31 17:08:47
                CUSTOM_DATA: NULL
1 row in set (0.00 sec)

Of course, the above is just for illustration and the ID and other values will vary but there should be a record for your partner ID [107 according to your log output] with the status column set to 1.

The final failure point is here /opt/kaltura/app/alpha/apps/kaltura/lib/kPermissionManager.php:
in the isPartnerAccessAllowed() function. It calls myPartnerUtils::allowPartnerAccessPartner() which is defined in /opt/kaltura/app/alpha/apps/kaltura/lib/myPartnerUtils.class.php, since it doesn’t return true, access is defined.

Assuming the relevant DB record is in place, I’d advise purging the cache [both on disk and APC by restarting Apache] on all relevant nodes [I believe you’re running a cluster] and giving it another go.
If it still doesn’t work, I suggest you add some debug prints to discern exactly where it fails and why.