OK, I found what's happening. Logging is getting called in the private
DB.runPreparedStatement, and also in the DB.exec method. Mapper uses exec
within the runPreparedStatement call. It seems like exec is the more
appropriate place to be running the logging, since you could have multiple
execs on a prepared statement but you generally wouldn't prepare a statement
without executing it. Thoughts on removing the logging from
runPreparedStatement?
Derek
On Wed, Oct 14, 2009 at 11:42 PM, Derek Chen-Becker
<dchenbec...@gmail.com>wrote:
> I don't think so. In this case I'm seeing a ResultSet in both log entries,
> which shouldn't show up in the part where it's being prepared.
>
> Derek
>
>
> On Tue, Oct 13, 2009 at 6:09 PM, Jonathan Ferguson <j...@spiralarm.com>wrote:
>
>> Is this related to a previous query dated 15 Sept, the title was
>> [Lift] Mapper: Why is every SQL query sent twice? (second time with NULL
>> parameters)
>> The response from @dpp was
>>
>> "The SQL is not being sent twice. There are two different points (when
>> the Statement is created and after the Statement is executed) that the same
>> query is logged."
>>
>>
>> Cheers
>> Jono
>>
>>
>> 2009/10/14 Derek Chen-Becker <dchenbec...@gmail.com>
>>
>> OK, I'm seeing the same thing here. I'll open an issue and work on it.
>>>
>>> Derek
>>>
>>>
>>> On Tue, Oct 13, 2009 at 10:07 AM, harryh <har...@gmail.com> wrote:
>>>
>>>>
>>>> I'm also seeing this double logging behavior (using PostgreSQL. I was
>>>> under the impression that it was happening because the SQL statement
>>>> is first prepared, and then executed (each of which cause a log
>>>> entry). It's not critical or anything, but it would be nice if this
>>>> could be fixed at some point.
>>>>
>>>> -harryh
>>>>
>>>> On Oct 13, 10:28 am, Derek Chen-Becker <dchenbec...@gmail.com> wrote:
>>>> > I'm not sure how that could be getting logged twice, especially since
>>>> it's
>>>> > the exact same ResultSet being returned. When I tested this on my
>>>> local app
>>>> > (against both PG and MySQL) I didn't get this behavior, but I'll try
>>>> pulling
>>>> > from master and testing again just in case something changed.
>>>> >
>>>> > Derek
>>>> >
>>>> > On Tue, Oct 13, 2009 at 6:56 AM, Jeppe Nejsum Madsen <
>>>> je...@ingolfs.dk>wrote:
>>>> >
>>>> >
>>>> >
>>>> > > Hi,
>>>> >
>>>> > > Just wanted to update to the new db logging by adding the following
>>>> to
>>>> > > boot:
>>>> >
>>>> > > DB.addLogFunc {
>>>> > > case (query:DBLog, time) => {
>>>> > > LogBoot.loggerByName("query").info(">>> All queries took " +
>>>> time +
>>>> > > "ms: ")
>>>> > > query.statementEntries.foreach({ case DBLogEntry(stmt,
>>>> duration) =>
>>>> > > LogBoot.loggerByName("query").info(" "+stmt + " took " + duration
>>>> +
>>>> > > "ms")})
>>>> > > LogBoot.loggerByName("query").info("<<< End queries")
>>>> > > }
>>>> > > }
>>>> >
>>>> > > But it seems all executed statements are logged twice. I have this
>>>> > > snippet:
>>>> >
>>>> > > def currentUser(xhtml: Group): NodeSeq =
>>>> > > Text(User.currentUser.dmap(S.?("Anonym"))(user => user.firstName + "
>>>> " +
>>>> > > user.lastName))
>>>> >
>>>> > > This logs:
>>>> >
>>>> > > 14:46:09.068 [tp-1029120287-4] INFO query
>>>> -
>>>> > > >>> All queries took 5ms:
>>>> > > 14:46:09.068 [tp-1029120287-4] INFO query
>>>> -
>>>> > > Exec query "SELECT users.id, users.firstname, users.lastname,
>>>> > > users.email, users.locale, users.timezone, users.password_pw,
>>>> > > users.password_slt, users.account_id, users.superuser,
>>>> users.uniqueid,
>>>> > > users.validated FROM users WHERE id = 2 (scale -5)" :
>>>> > > org.postgresql.jdbc4.jdbc4result...@77f31432 took 4ms
>>>> > > 14:46:09.069 [tp-1029120287-4] INFO query
>>>> -
>>>> > > <<< End queries
>>>> > > 14:46:09.069 [tp-1029120287-4] INFO query
>>>> -
>>>> > > >>> All queries took 8ms:
>>>> > > 14:46:09.069 [tp-1029120287-4] INFO query
>>>> -
>>>> > > Exec query "SELECT users.id, users.firstname, users.lastname,
>>>> > > users.email, users.locale, users.timezone, users.password_pw,
>>>> > > users.password_slt, users.account_id, users.superuser,
>>>> users.uniqueid,
>>>> > > users.validated FROM users WHERE id = 2 (scale -5)" :
>>>> > > org.postgresql.jdbc4.jdbc4result...@77f31432 took 4ms
>>>> > > 14:46:09.069 [tp-1029120287-4] INFO query
>>>> > > - <<< End queries
>>>> >
>>>> > > Note the same resultset. The postgres logs also shows that only a
>>>> single
>>>> > > statement is executed....
>>>> >
>>>> > > So, what did I miss?
>>>> >
>>>> > > /Jeppe
>>>>
>>>>
>>>
>>>
>>>
>>
>> >>
>>
>
--~--~---------~--~----~------------~-------~--~----~
You received this message because you are subscribed to the Google Groups
"Lift" group.
To post to this group, send email to liftweb@googlegroups.com
To unsubscribe from this group, send email to
liftweb+unsubscr...@googlegroups.com
For more options, visit this group at
http://groups.google.com/group/liftweb?hl=en
-~----------~----~----~----~------~----~------~--~---
