Why would custom module code fail when called from drush but work fine when invoked from cron button in admin/config/system/cron?

Question

Background: I have developed a custom module to process a CSV file of user data imported from an external system. The module updates the standard Drupal user fields and also their Profile 2 fields. I have tested this via pressing the cron button on admin/config/system/cron and it works fine. However, ultimately I don't want to run this with cron but instead at a single specific time regular time. I want to invoke it via Jenkins issuing a drush command. So I implemented a drush command and issued this and got the following (names have been changed in case of an issues making public). Here's what I see when I issued the drush command (my development environment details follow the output):

$ drush mysync
WD user: PDOException: SQLSTATE[22001]: String data, right truncated: 1406 Data too long for column 'name' at row 1: INSERT INTO {users} (uid, name, pass, mail, created, status,  [error]
init, data) VALUES (:db_insert_placeholder_0, :db_insert_placeholder_1, :db_insert_placeholder_2, :db_insert_placeholder_3, :db_insert_placeholder_4, :db_insert_placeholder_5,
:db_insert_placeholder_6, :db_insert_placeholder_7); Array
(
    [:db_insert_placeholder_0] => 17328
    [:db_insert_placeholder_1] => RequestTimeTooSmywebsiteedThe difference between the request time and the current time is too
large.20151222T173152Z2015-12-22T17:50:06Z9000007C6B68377122D467B3WpFicMSuociMXhAz4zJ4aydh6THmo7Q5gcBRkVdY86d962a3J+F+wx93sgHOdFQIUZYpg4pLE=
    [:db_insert_placeholder_2] => $S$D9dNnB8ROhS9.EZudAfxp/dvkbD1f4HswTAzRJ1q4KbaldtmzwzR
    [:db_insert_placeholder_3] => 
    [:db_insert_placeholder_4] => 1450805510
    [:db_insert_placeholder_5] => 1
    [:db_insert_placeholder_6] => 
    [:db_insert_placeholder_7] => a:2:{s:7:"contact";i:1;s:17:"mimemail_textonly";i:0;}
)
 in drupal_write_record() (line 7316 of /var/www/mywebsite.dev/includes/common.inc).
exception 'PDOException' with message 'SQLSTATE[22001]: String data, right truncated: 1406 Data too long for column 'name' at row 1' in                                            [error]
/var/www/mywebsite.dev/includes/database/database.inc:2171
Stack trace:
#0 /var/www/mywebsite.dev/includes/database/database.inc(2171): PDOStatement->execute(Array)
#1 /var/www/mywebsite.dev/includes/database/database.inc(683): DatabaseStatementBase->execute(Array, Array)
#2 /var/www/mywebsite.dev/includes/database/mysql/query.inc(36): DatabaseConnection->query('INSERT INTO {us...', Array, Array)
#3 /var/www/mywebsite.dev/includes/common.inc(7316): InsertQuery_mysql->execute()
#4 /var/www/mywebsite.dev/modules/user/user.module(582): drupal_write_record('users', Object(stdClass))
#5 /var/www/mywebsite.dev/sites/all/modules/custom/mywebsite_externalsystem_integration/mywebsite_externalsystem_integration.module(564): user_save('', Array)
#6 /var/www/mywebsite.dev/sites/all/modules/custom/mywebsite_externalsystem_integration/mywebsite_externalsystem_integration.module(239): _mywebsite_externalsystem_integration_create_new_user(Array)
#7 /var/www/mywebsite.dev/sites/all/modules/custom/mywebsite_externalsystem_integration/mywebsite_externalsystem_integration.module(26): _mywebsite_externalsystem_integration_update_and_create_user_records(Array)
#8 /var/www/mywebsite.dev/sites/all/modules/custom/mywebsite_externalsystem_integration/mywebsite_externalsystem_integration.drush.inc(17): _mywebsite_externalsystem_integration_sync()
#9 [internal function]: drush_mywebsite_externalsystem_integration_externalsystem_sync_command()
#10 /usr/share/drush/includes/command.inc(359): call_user_func_array('drush_mywebsite_ag...', Array)
#11 /usr/share/drush/includes/command.inc(210): _drush_invoke_hooks(Array, Array)
#12 [internal function]: drush_command()
#13 /usr/share/drush/includes/command.inc(178): call_user_func_array('drush_command', Array)
#14 /usr/share/drush/lib/Drush/Boot/BaseBoot.php(62): drush_dispatch(Array)
#15 /usr/share/drush/drush.php(70): Drush\Boot\BaseBoot->bootstrap_and_dispatch()
#16 /usr/share/drush/drush.php(11): drush_main()
#17 {main}

My environment:

• Ubuntu 14.04 Linux VM provisioned via puphpet.com manifest using Vagrant running on Mac OS X El Capitan
• PHP version: PHP 5.6.16-2+deb.sury.org~trusty+1 (cli)
• I have compared the php.ini files for Apache (Web) and for CLI (that drush uses) - see screenshot (the file names have been renamed and moved to a position where my host comparison tool, Beyond Compare can compare them in the shared file system of the VM):

• I did some research and a plausible reason for the error is that the UTF character set is different, e.g. it was UTF-8 on apache (where it worked and perhaps UTF-16 on drush cli where it fails with the truncation - because twice the width, however, they are both the same:

I just don't understand why this code would work when run within Drupal via the web, but not in drush. The database attempted to be written to is the same, the data I'm attempting to write is the same, it must be some kind of environmental difference, but apart from php.ini I don't know what it could be. Please advise.

Answer 1

Since you're having MySQL error, you should rather check my.cnf, not php.ini, unless PHP CLI and Apache are using different instances of MySQL (via mysql.sock).

However your problem is something else.

You you look closely into the error:

Data too long for column 'name' at row 1

it complains that your name column is too long.

Now check your db placeholders:

uid:

[:db_insert_placeholder_0] => 17328

name:

[:db_insert_placeholder_1] => RequestTimeTooSmywebsiteedThe difference between the request time and the current time is too

that means you've problem with the username, as above value is not valid username, secondly it's too long.

So you've to double check the code in:

mywebsite_externalsystem_integration.module:564: user_save('', Array)

and its Array (especially value of name).

The way how you call it:

#5 mywebsite_externalsystem_integration.module(564): user_save('', Array)
#6 mywebsite_externalsystem_integration.module(239): _mywebsite_externalsystem_integration_create_new_user(Array)
#7 mywebsite_externalsystem_integration.module(26): _mywebsite_externalsystem_integration_update_and_create_user_records(Array)
#8 mywebsite_externalsystem_integration.drush.inc(17): _mywebsite_externalsystem_integration_sync()

doesn't seems you're running cron task from your code (but executing custom drush command), so nothing to do with it, that's why it's not happening during your cron.php.

So to summarize it, this is a bug of your custom code which you need to find and fix it.

---

Check: user_save() API for the valid syntax, where:

$edit: An array of fields and values to save. For example array('name' => 'My name').

---

Going more deeply, the following error (changed based on my assumption):

RequestTimeTooSkewed: The difference between the request time and the current time is too large.

sounds like the error of Amazon S3 service (possibly you're using Storage API module). So I assuming your code doesn't have failing scenario and populating the error message, instead of the username (connecting issues?).

So the only difference between Web and drush is how the code implements the user import. If you're using some specific credentials or performing HTTP requests, make sure you're loading the right variables, site profile, using the right host, proxy settings, etc. Plus print some debugs (-v/-d). For example:

drush -vd -l http://mywebsite.dev mysync

and check your watchdog messages (drush ws --tail).

Some people suggests that your local box is out of sync with the current time, so try to correct it.

So please double check that you followed installation instruction of the module correctly, as below:

This service requires an account with the external service provider. Please refer to the online documentation for additional help: https://www.drupal.org/node/656716

See: Amazon S3 at Drupal.org

So possible solution is to run as root the following commands:

ntpdate ntp.ubuntu.com
echo "ntpdate ntp.ubuntu.com" >> /etc/cron.daily/ntpdate && chmod 755 /etc/cron.daily/ntpdate

depending on your Linux distribution.