Permission caching trying to implode a non-array [#108349]

A custom authentication module I wrote for our organization works in 4.7 but causes 5.0 to display a red error box above the starting page content. The error only appears when the user doesn't already exist and has to be created by Drupal. Subsequent logins, and page refreshes do not generate the error message.

* warning: array_keys() [function.array-keys]: The first argument should be an array in /var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/modules/user/user.module on line 358.

* warning: implode() [function.implode]: Bad arguments. in /var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/modules/user/user.module on line 358.

* user warning: You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near ')' at line 1 query: SELECT DISTINCT(p.perm) FROM communityrole r INNER JOIN communitypermission p ON p.rid = r.rid WHERE r.rid IN () in /var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/includes/database.mysql.inc on line 167.

Above line 358 in the user.module changing this if:

// To reduce the number of SQL queries, we cache the user's permissions                                          
// in a static variable.                                                                                         
if (!isset($perm[$account->uid])) {

// To reduce the number of SQL queries, we cache the user's permissions                                          
// in a static variable.                                                                                         
if (!isset($perm[$account->uid]) && is_array($account->roles) ) {

Stops the error message, but is probably just covering up a different problem. :)

Comment	File	Size	Author
#13	dummyauth.tar.gz	403 bytes	twibberjix

Comments

Comment #1

RobRoy commented 11 January 2007 at 02:02

$account->roles should always be an array. Sounds like your module may be messing with the user object and setting roles to a scalar?

Comment #2

twibberjix commented 11 January 2007 at 17:45

None of my debugging of the module has revealed anything wrong with the user object at various points inside it. Since I have the time I'm currently trying to pinpoint when the error is occurring exactly. The order of the log messages is "PHP error", "new external user created", "session opened" so I'm focusing on what's going on right before the the new account is created.

Is there anything about the external auth process that changed from 4.7 to 5?

Comment #3

twibberjix commented 11 January 2007 at 19:03

After taking the user.module from 4.7.4 and replacing module_exit() with module_exists() and inserting the user_login_block() function from version 5 - I was able to "New external user: nate@launchpad using module launchpad." without having any errors preceding it.

I will continue searching for what's causing the error messages in version 5.

Comment #4

twibberjix commented 11 January 2007 at 19:09

Just to clarify - that previous message meant that I was replacing the user.module that ships with 5rc1 with the user.module that ships with 4.7.4.

Comment #5

twibberjix commented 11 January 2007 at 20:41

Aha!

I appended debug_print_backtrace() to the messages watchdog was recording and discovered that the problem appears to come from the Profile, and the Category access control lite modules. The respective traces follow.

#1 array_keys() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/modules/user/user.module:359]
#2 user_access() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/modules/profile/profile.module:816]
#3 _profile_get_fields() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/modules/profile/profile.module:531]
#4 profile_save_profile() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/modules/profile/profile.module:176]
#5 profile_user() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/modules/user/user.module:19]
#6 user_module_invoke() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/modules/user/user.module:197]
#7 user_save() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/modules/user/user.module:999]
#8 user_authenticate() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/modules/user/user.module:928]
#9 user_login_validate() called at [(null):0]
#10 call_user_func_array() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/includes/form.inc:557]
#11 _form_validate() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/includes/form.inc:400]
#12 drupal_validate_form() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/includes/form.inc:252]
#13 drupal_process_form() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/includes/form.inc:79]
#14 drupal_get_form() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/modules/user/user.module:549]
#15 user_block() called at [(null):0]
#16 call_user_func_array() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/includes/module.inc:386]
#17 module_invoke() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/modules/block/block.module:691]
#18 block_list() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/includes/theme.inc:988]
#19 theme_blocks() called at [(null):0]
#20 call_user_func_array() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/includes/theme.inc:166]
#21 theme() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/themes/engines/phptemplate/phptemplate.engine:171]
#22 phptemplate_page() called at [(null):0]
#23 call_user_func_array() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/includes/theme.inc:166]
#24 theme() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/index.php:33]

#1 array_keys() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/modules/user/user.module:359]
#2 user_access() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/modules/category/contrib/cac_lite/cac_lite.module:188]
#3 cac_lite_user() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/modules/user/user.module:19]
#4 user_module_invoke() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/modules/user/user.module:82]
#5 user_load() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/modules/user/user.module:195]
#6 user_save() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/modules/user/user.module:999]
#7 user_authenticate() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/modules/user/user.module:928]
#8 user_login_validate() called at [(null):0]
#9 call_user_func_array() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/includes/form.inc:557]
#10 _form_validate() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/includes/form.inc:400]
#11 drupal_validate_form() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/includes/form.inc:252]
#12 drupal_process_form() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/includes/form.inc:79]
#13 drupal_get_form() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/modules/user/user.module:549]
#14 user_block() called at [(null):0]
#15 call_user_func_array() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/includes/module.inc:386]
#16 module_invoke() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/modules/block/block.module:691]
#17 block_list() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/includes/theme.inc:988]
#18 theme_blocks() called at [(null):0]
#19 call_user_func_array() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/includes/theme.inc:166]
#20 theme() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/themes/engines/phptemplate/phptemplate.engine:171]
#21 phptemplate_page() called at [(null):0]
#22 call_user_func_array() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/includes/theme.inc:166]
#23 theme() called at [/var/httpd/vhosts/community.viedu.org/drupal-5.0-rc1/index.php:33]

Without either of those turned on the problem does not occur. Not sure what to do from here, so I will wait. :)

Comment #6

RobRoy commented 11 January 2007 at 21:28

Disable any contrib modules (cac_lite) and see if there is a problem with profile module. If not, move this issue to cac_lite.

Comment #7

twibberjix commented 12 January 2007 at 00:15

Component:

user.module

» profile.module

It happens when either one is enabled, and when both are enabled. I didn't provide the backtrace for when both were enabled because it was basically a combination of the other two backtraces.

Comment #8

RobRoy commented 12 January 2007 at 01:12

Can you test this on 5.x-dev to see if the problem has been fixed in the development snapshot?

Comment #9

twibberjix commented 12 January 2007 at 16:56

Version:

5.0-rc1

» 5.x-dev

Tried it with CVS checkout this morning and the problem is still there, here's the backtrace:

#1 array_keys() called at [/var/httpd/vhosts/community.viedu.org/cvs/drupal-head/modules/user/user.module:361]
#2 user_access() called at [/var/httpd/vhosts/community.viedu.org/cvs/drupal-head/modules/profile/profile.module:813]
#3 _profile_get_fields() called at [/var/httpd/vhosts/community.viedu.org/cvs/drupal-head/modules/profile/profile.module:528]
#4 profile_save_profile() called at [/var/httpd/vhosts/community.viedu.org/cvs/drupal-head/modules/profile/profile.module:176]
#5 profile_user() called at [/var/httpd/vhosts/community.viedu.org/cvs/drupal-head/modules/user/user.module:22]
#6 user_module_invoke() called at [/var/httpd/vhosts/community.viedu.org/cvs/drupal-head/modules/user/user.module:199]
#7 user_save() called at [/var/httpd/vhosts/community.viedu.org/cvs/drupal-head/modules/user/user.module:1000]
#8 user_authenticate() called at [/var/httpd/vhosts/community.viedu.org/cvs/drupal-head/modules/user/user.module:929]
#9 user_login_validate() called at [(null):0]
#10 call_user_func_array() called at [/var/httpd/vhosts/community.viedu.org/cvs/drupal-head/includes/form.inc:562]
#11 _form_validate() called at [/var/httpd/vhosts/community.viedu.org/cvs/drupal-head/includes/form.inc:400]
#12 drupal_validate_form() called at [/var/httpd/vhosts/community.viedu.org/cvs/drupal-head/includes/form.inc:252]
#13 drupal_process_form() called at [/var/httpd/vhosts/community.viedu.org/cvs/drupal-head/includes/form.inc:79]
#14 drupal_get_form() called at [/var/httpd/vhosts/community.viedu.org/cvs/drupal-head/modules/user/user.module:551]
#15 user_block() called at [(null):0]
#16 call_user_func_array() called at [/var/httpd/vhosts/community.viedu.org/cvs/drupal-head/includes/module.inc:386]
#17 module_invoke() called at [/var/httpd/vhosts/community.viedu.org/cvs/drupal-head/modules/block/block.module:689]
#18 block_list() called at [/var/httpd/vhosts/community.viedu.org/cvs/drupal-head/includes/theme.inc:1013]
#19 theme_blocks() called at [(null):0]
#20 call_user_func_array() called at [/var/httpd/vhosts/community.viedu.org/cvs/drupal-head/includes/theme.inc:170]
#21 theme() called at [/var/httpd/vhosts/community.viedu.org/cvs/drupal-head/themes/engines/phptemplate/phptemplate.engine:171]
#22 phptemplate_page() called at [(null):0]
#23 call_user_func_array() called at [/var/httpd/vhosts/community.viedu.org/cvs/drupal-head/includes/theme.inc:170]
#24 theme() called at [/var/httpd/vhosts/community.viedu.org/cvs/drupal-head/index.php:33]

I did not try the CAC lite module.

Comment #10

twibberjix commented 12 January 2007 at 19:40

Here's some more debugging info created from adding print_r($user) to the beginning of some profile.module functions and user_access from user.module. I'm still trying to figure out how this is happening, it looks like $user is lost somewhere between the profile_save_profile and _profile_get_fields calls ?????

print_r($user) from inside user_access($string="administer users", $account=):stdClass Object
(
    [uid] => 0
    [hostname] => 69.105.92.2
    [roles] => Array
        (
            [1] => anonymous user
        )

    [session] => 
)

print_r($user) from inside user_access($string="administer access control", $account=):stdClass Object
(
    [uid] => 0
    [hostname] => 69.105.92.2
    [roles] => Array
        (
            [1] => anonymous user
        )

    [session] => 
)

print_r($user) from inside user_access($string="access user profiles", $account=):stdClass Object
(
    [uid] => 0
    [hostname] => 69.105.92.2
    [roles] => Array
        (
            [1] => anonymous user
        )

    [session] => 
)

print_r($user) from inside profile_save_profile($edit=Array,$user=Object id #2,$category=account)::stdClass Object
(
    [uid] => 13
    [name] => nate@launchpad
    [pass] => 3858eb8d14d29c9654280d365734e08e
    [mail] => nate@viedu.org
    [mode] => 0
    [sort] => 0
    [threshold] => 0
    [theme] => 
    [signature] => 
    [created] => 1168629939
    [access] => 0
    [login] => 0
    [status] => 1
    [timezone] => 
    [language] => 
    [picture] => 
    [init] => nate@launchpad
    [data] => 
    [roles] => Array
        (
            [2] => authenticated user
        )

    [launchpad] => Array
        (
            [lpUserID] => 1
            [lpRoleID] => 1
            [lpRoleName] => Programmer
        )

)

print_r($user) from inside _profile_get_fields($category=account, $register=):

print_r($user) from inside user_access($string="administer users", $account=):

stopping here because $users->roles is not an array

The beginning of the user_access function in user.module looks like:

function user_access($string, $account = NULL) {                                                                   
  global $user;                                                                                                    
                                                                                                                   
  print "<pre>";                                                                                                   
  print "print_r(\$user) from inside user_access(\$string=\"$string\", \$account=$account):";                      
  print_r($user);                                                                                                  
  print "</pre>";                                                                                                  
                                                                                                                   
  if (!is_array($user->roles) ) die("stopping here because \$users->roles is not an array");                       
           
. . . . .

Similar stuff is in profile.module without the die command if user->roles is not an array.

Comment #11

H3rnand3z commented 12 January 2007 at 21:46

Could it be your authentication module clobbering $user object? I was getting similar errors using cac_lite and Webserver Auth module, new users started getting this error at first login.

warning: array_keys() [function.array-keys]: The first argument should be an array in C:\wamp\www\modules\user.module on line 352.
warning: implode() [function.implode]: Bad arguments. in C:\wamp\www\modules\user.module on line 352.
user warning: You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near ')' at line 1 query: user_access SELECT DISTINCT(p.perm) FROM role r INNER JOIN permission p ON p.rid = r.rid WHERE r.rid IN () in C:\wamp\www\includes\database.mysql.inc on line 121.
warning: array_keys() [function.array-keys]: The first argument should be an array in C:\wamp\www\modules\views\views.module on line 437.
warning: array_intersect() [function.array-intersect]: Argument #2 is not an array in C:\wamp\www\modules\views\views.module on line 444.
warning: array_keys() [function.array-keys]: The first argument should be an array in C:\wamp\www\modules\views\views.module on line 437.
warning: array_keys() [function.array-keys]: The first argument should be an array in C:\wamp\www\modules\views\views.module on line 437.
warning: Invalid argument supplied for foreach() in C:\wamp\www\modules\cac_lite\cac_lite.module on line 368.

If it helps, there is more info on the webserver_auth issue here http://drupal.org/node/64949

Comment #12

twibberjix commented 12 January 2007 at 22:54

While I'm totally willing to entertain the idea that my code has somehow disrupted the natural order of all things Drupal - as I stated before:

None of my debugging of the module has revealed anything wrong with the user object at various points inside it.

I would not have created an issue if I thought it was my module screwing something up :(

The problem can be addressed by making the following modifications to profile.module:

For function profile_save_profile:

function profile_save_profile(&$edit, &$user, $category) {                                                         
                                                                                                                   
    global $saveProfileUser;                                                                                       
    $saveProfileUser = $user;

For function _profile_get_fields:

function _profile_get_fields($category, $register = FALSE) {                                                       
                                                                                                                   
  global $saveProfileUser;                                                                                         
  global $user;                                                                                                    
                                                                                                                   
  if ( is_object($saveProfileUser)  && !is_object($user) )                                                         
    $user = $saveProfileUser;

Comment #13

twibberjix commented 12 January 2007 at 23:45

Status	File	Size
new	dummyauth.tar.gz	403 bytes

Here's a dummy authorization module that always returns true. If you enable it and profile.module and then log in with somerandomname@dummyauth and somerandompassword you should see the error. If you apply the changes I suggested to profile.module and then try logging in with a different randomname@dummyauth you should no longer see the error upon initial account creation.

Hope that helps for testing purposes.

Comment #14

damien tournoud commented 6 August 2010 at 09:42

Category:	bug	» support
Status:	Active	» Closed (won't fix)

Seems that no actual bug has been identified here.

Permission caching trying to implode a non-array