According to CVS, most of the people who have changed add_to_log() in datalib.php are people who's code we should be emulating.
However, I don't understand why it is written like it is. Why isn't it using the standard insert_record() and update_record() functions? Why do we touch the user tables here of all places?
And most importantly, when called from the OU-specific code I am currently trying to debug, why does it fail to work when I debug mode is turned off, but work when debug is on? ARGH! bangs head into wall some more.
Tim.
You are right, add_to_log() breaks all the rules. Caught us!
The thing is that it is possibly the most-often-exec'd insert to DB call, so it is heavily optimized for performance. Using insert_record() is optimized for ease of use and safety, but it is more costly.
And most importantly, when called from the OU-specific code I am currently trying to debug, why does it fail to work when I debug mode is turned off, but work when debug is on? ARGH! bangs head into wall some more.
Ouch, sounds like you have a Heisenbug. Impossible to know from here... if you can think of ways of making it more reliable (not dependent on debug modes) I'm interested...
One problem that just came up in the quiz module under mysql 5 is that the 'action' field in the log_display table is varchar(20) but in the log table it is only varchar(15). Now apparently mysql is rather more fussy when it is given a string that is longer than the field. Old versions of mysql just truncated the string, mysql 5 gives an error.
Should we make both fields varchar(15) or both varchar(20)?
Should we make both fields varchar(15) or both varchar(20)?
You are right, add_to_log() breaks all the rules. Caught us! 
I thought it might be something like that, but there really should be a comment there explaining. I've just checked one in.
One thing I can think of to improve this method further is in the attached patch. It changes things so that if one request to the server causes two calls to add_log, then the user tables are only updated once, saving a few update queries. I am not sure whether that is a good or bad idea though.
I think the bug I am grappling with is related to my use of transactions (We are talking postgres here). This is in our code to do with creating new courses. After moodle creates the new course, it uses data from other OU systems to create an initial set of blocks and modules and so on. Then my bit of code stores some metatdata in some other tables, basically a list of which people are responsible for finishing the course an approving it. We are using transactions here because so many database updates are happening at once, I could not face manually cleaning up the mess if it failed half way.
I am being lazy in my code. Having updated the data in my tables, I call an existing function for SELECTing all the data about a particular course, because that gets me all the data I need in the form I need. I could, instead, update my data structures in memory, which would save a DB query, but be more work for me and less robust if that data structure changes.
With Moodle in debug mode, this works. With moodle in non-debug mode, the select query fails. If I commit the transaction just before running the select query, the query works again. It's baffling. I think I am going to give up trying to undersand what is happening, and rewrite the code to avoid the unnecessary select query.
Tim.
In reply to Tim Hunt
Re: What's going on in add_to_log() - fix to get_record_sql() checked into CVS
by Tim Hunt -
Found it!
At last!
It is actually the fault of get_record_sql(). When debug is off, it adds ' limit 1' to the end of the query becuase you said you only wanted one record, so it does not bother getting more. I was terminating my query with a semicolon, so appending 'limit 1' caused a syntax error, but debug was off, so it failed silently.
(When debug is on, it does not add the limit becuase your query really ought to only return one record and you should know if it is returning more.)
I think what we should do is to add ' limit 100' to queries in debug mode, so that errors caused by messing around with SQL show up, but we still get the benefits of not having limit 1. I am sure this is a good idea, so I have committed it already.
At last!
It is actually the fault of get_record_sql(). When debug is off, it adds ' limit 1' to the end of the query becuase you said you only wanted one record, so it does not bother getting more. I was terminating my query with a semicolon, so appending 'limit 1' caused a syntax error, but debug was off, so it failed silently.
(When debug is on, it does not add the limit becuase your query really ought to only return one record and you should know if it is returning more.)
I think what we should do is to add ' limit 100' to queries in debug mode, so that errors caused by messing around with SQL show up, but we still get the benefits of not having limit 1. I am sure this is a good idea, so I have committed it already.
In reply to Tim Hunt
Re: What's going on in add_to_log() - fix to get_record_sql() checked into CVS
by Petr Skoda -
I was bitten by this too. "limit 100" is IMO good idea 