I noticed a problem I have with my site since I upgraded core to 7.54 and ctools to 7.x-1.12 (but it happens even with 7.x-dev)
Basically I have certain "in code" pages that I enable and after a while (maybe 30 mins or an hour) they reverse to disabled again. This is extremely unpleasant and a site cannot work this way. It happens to almost all the "in code" pages actually. I want to stress out that the "reversing" doesn't happen immediately. Those pages "stay" enabled for a while. I even cleared the cache and they stay ok. But after a while they just disable. Is there an explanation for this? I don't know if it's relevant but the default jQuery version I have enabled is 1.10.

Comments

Virgil created an issue. See original summary.

rivimey’s picture

Priority: Critical » Major

Virgil, I have a fresh D7 7.54 install on ctools 7.x-1.x-dev, and 2 hours ago I enabled and configured some panels pages (search-node et al) ; they are still enabled. I have not heard of this problem elsewhere either, so my first thought is that something else specific to your site is changing it.

Can you tell us how these pages are created -- is it panels_node, direct calls to page_manager, features, views, ...?

I think it would help to try logging the change:

The UI way to change the enabled state (enable or disable) uses the function page_manager_enable_page() in page_manager/page_manager.admin.inc. This then delegates the task via the 'enable callback' of the appropriate ctools plugin. So for example the function that actually does the work for the node_view plugin is called page_manager_node_view_enable(). This particular callback then uses variable_set() / variable_get() to store the status, using the variable name "page_manager_node_view_disabled". So, at least for node_view, a change to the "page_manager_node_view_disabled" variable will change whether a node_view page is considered to be enabled or not.

On your site could you put some calls at the top of the page_manager_enable_page() function to the watchdog() that would record the call stack (use debug_backtrace() ) and anything else (e.g. the value of $page, details from $_GET) that might help. Put those in the $variables array, which will store arrays as arrays and objects as objects rather than convert them to a string. Then see if that call gets hit in the next hour or so...

See http://alvinalexander.com/drupal/drupal-how-log-errors-messages-watchdog for details of calling watchdog().

See the results of this using "drush ws --extended" or from the reports page.

If the function is not hit, then that suggests something is messing with the database. If your site is not busy it would be enough to use the mysql general log (can be enabled from mysql CLI), which would provide the source of the connection to the server and the SQL command used, which would be a help in narrowing down the caller.

Hope this helps,
Ruth

Virgil’s picture

Hi Ruth,
Thank you for your detailed answer. I really appreciate it. First I must say I'm not a developer/programmer but only what you call a builder. I'm going to tell you as better as I can what's happening. The "pages" I'm talking about are the "Node template" and the "User profile template" you can see on the admin/structure/pages.
As far as I understand they belong to the "page manager" module, that in D7 is part of CTools.
If I enable these templates (or the other listed there) they "stay" enabled for a while but after a period of time (30 mins to an hour or sometimes more, or less) they end up in an enabled state again. So I have no idea why is this happening. I need to add that each of them (the 2 I mentioned) have active variants in them. When they get disabled the variants layout is no longer active (as expected) and the pages are displayed in a "wrong" manner.
I'm going to try to enable the monitoring suggestions you told me about and see if something comes up.

rivimey’s picture

Hi Virgil, thanks for your reply. I really think additional information from your site is needed to solve this.

The Node template is, I believe, managed by the node_view plugin, so you should be able to use the function names I was talking about earlier.

Not sure if it helps, but could the delay (30 min / 1hr) be anything to do with 'cron' running? That might be an angle to look at.

Virgil’s picture

Hi Ruth,
thank you again, very much. This really helps me. I finally was able to un-"blob" the value of those variables in the dbase variable table.
I don't know on which file exactly to put those calls. So, for now I enabled and configured syslog to spit out messages about the node variable (for now) and I'm watching it.
On the other note, you mentioned the cron job. Most I have are 15 mins or 1 hour. The only one running against the CTools module is a 15 mins for cleaning up old caches. Is there something specific I should look into regarding this? I need to add that I haven's change(configured) anything in the cron config since before the upgrade so (at least deliberately) I haven't done anything there that should trigger something. And, shouldn't be necessary to have a pretty elaborate rule to be able to mimic deselection of those templates?

rivimey’s picture

Virgil, I only mentioned cron because it seemed possible that a thing that happened at those sorts of intervals might be initiated by code called from a cron run, but I know of nothing specifically that would cause this.

Re 'unblob'ing: the encoding used there is from the php function 'serialize' (i.e. call 'unserialize' to get the original vriable back, and then 'var_dump' or 'var_export' to print it out (they print in slightly different formats). If you can use drush, you can print out a variable using 'drush vget varname', and you can execute arbitrary php code (such as calling unserialize) using 'drush eval', but in both cases you need terminal (ssh) access to the site.

It is very likely that something is changing the variables table in the database using an SQL command. It might be a result of the calls to variable_set I mentioned earlier, or it might be something else.

I have just wondered - have you by any chance set up some sort of replication or backup thing that might be resetting the tables with values from another database?

If not those, then you'll have to monitor what is happening in php and on the db server and try to find out what is causing the change. Use of watchdog() + debug_backtrace() will help identify where if it is in php-land -- using watchdog means you're not losing output in some rendered page somewhere, and debug_bactrace gives you a 'history' of how execution reached a given place. So. e.g a debug_backtrace in the variable_set code would print out the caller of variable_set, and the caller of the caller, and so on, effectively going back in time...

If you're stumped, adding more calls to watchdog(), to provide context to the ones you have, is probably a good place to start with. When I'm doing this sort of work I sometimes just put a call at the start and end of every function in a file... and see what happens. At least you have a reproducible problem :-)

With databases it's harder: sometimes the nature of the SQL query is enough: there's only one thing that could have created that particular SQL. In this case you're not likely to be that lucky, so it will probably be down to matching up the SQL with other logs by matching up clock-face time.

Not sure if you're aware but terminal-based tools like "less" and "tail" can be very helpful if you're tring to monitor several log files at once. in a terminal type 'man less' or 'man tail' for more info.

Best of luck.

Virgil’s picture

Hi,
I think I misspoke. I didn't actually un-"blob" the fields. What I did is that I reconfigured phpMyAdmin to show the BLOBs in actual string.

Virgil’s picture

Hi Ruth,

I have absolutely no idea if I've done right but I put this:

watchdog('pagemanager', 'page-manager-message', array('node_view', 'user_view',
'ip' => ip_address(),
'timestamp' => time(), ), WATCHDOG_DEBUG, NULL);

in the page_manager.admin.inc file

Where is the log going to be recorded? In the messages log file?
Sorry to be so not knowledgeable.

Virgil’s picture

The problem is solved. The issue was caused by a bug or dysfunction in this module: https://www.drupal.org/project/disable_term_node_listings
Once disabled that module the problem stopped.

rivimey’s picture

Status: Active » Closed (works as designed)

Hi Virgil, great you've got it sorted.
I'll close this issue now.