Beefy Boxes and Bandwidth Generously Provided by pair Networks
Pathologically Eclectic Rubbish Lister
 
PerlMonks  

DBI trace has limited output

by Anonymous Monk
on Oct 23, 2021 at 15:43 UTC ( #11137916=perlquestion: print w/replies, xml ) Need Help??

Anonymous Monk has asked for the wisdom of the Perl Monks concerning the following question:

I've enabled DBI trace with level 15 so it shows the full trace but it has no effect.the output remains the same whether level 1 or 99. In particular I'd like to capture the SQL queries with the values interpolated.In other machines I do.In this case I have a CGI script called by Apache which accesses the database and does some queries. It's a bit of an old system with DBI version 1.64. I can't make any modifications to the system because it's production. Do you think it's because of the old DBI version?

Replies are listed 'Best First'.
Re: DBI trace has limited output
by kcott (Bishop) on Oct 23, 2021 at 18:34 UTC

    This is vague, contradictory, and missing information. You'll need to supply a lot more information before we can effectively help you.

    "I've enabled DBI trace with level 15 so it shows the full trace but it has no effect."

    On the surface, this is contradictory: "so it shows the full trace" is the expected effect. Did you perhaps mean the opposite: "but it doesn't show the full trace"? Suggests a coding problem but, as you've shown no code, that's just guesswork.

    "the output remains the same whether level 1 or 99"

    There is no trace level 99. The valid range is 0-15.

    "In particular I'd like to capture the SQL queries with the values interpolated."

    See "DBI: Trace Flags"; in particular,

    SQL - trace SQL statements executed (not yet implemented in DBI but implemented in some DBDs)

    You haven't told us which DBD you're using, so I'm unable to comment on that part. There's also the possibility of a coding error; again, no code so only guesses.

    "In other machines I do."

    Please tell what machine you're currently using and the machines on which the same code is capturing the SQL queries.

    "It's a bit of an old system with DBI version 1.64."

    There is no "DBI version 1.64". See DBI: there are versions like 1.64x, where x is 0-3 and dates are 2018-2020 (so none are particularly old); BackPAN has a v0.64 from 1995.

    In an attempt to provide some basic help, I created this dummy test database:

    $ sqlite3 pm_11137916_anon SQLite version 3.34.0 2020-12-01 16:14:00 Enter ".help" for usage hints. sqlite> create table Planet (id, name, type); sqlite> insert into Planet values (3, 'Earth', 'rock'); sqlite> insert into Planet values (5, 'Jupiter', 'gas'); sqlite> insert into Planet values (9, 'Pluto', 'dwarf'); sqlite> select * from Planet; 3|Earth|rock 5|Jupiter|gas 9|Pluto|dwarf sqlite>

    I then wrote this very simple Perl script (trace_none.pl) as a basic test:

    #!/usr/bin/env perl use strict; use warnings; use DBI; DBI->trace(0); my $dbh = DBI->connect('dbi:SQLite:dbname=pm_11137916_anon'); print join('|', @$_), "\n" for $dbh->selectall_array('select * from Pl +anet');

    The output from that is the same as from the raw SQL statement:

    $ ./trace_none.pl 3|Earth|rock 5|Jupiter|gas 9|Pluto|dwarf

    Then I made multiple copies of that which changed the trace level to 1, 4, 5 and 15 (e.g. DBI->trace(4);). I then made equivalent copies that included the SQL trace flag (e.g. DBI->trace("4|SQL");). At each increased trace level, more information was produced. The SQL trace flag made no noticeable difference (so it doesn't look like DBD::SQLite is one of the DBDs that support that flag).

    The output from all of those is far too great to post here; you can, of course, try them for yourself. However, I did capture the output from all of those; you can see how they increase with each trace level:

    $ ls -al *.out -rw-r--r-- 1 ken None 1839 Oct 24 03:50 trace_dbi_1.out -rw-r--r-- 1 ken None 1853 Oct 24 03:51 trace_dbi_1_sql.out -rw-r--r-- 1 ken None 16771 Oct 24 04:14 trace_dbi_15.out -rw-r--r-- 1 ken None 16893 Oct 24 04:15 trace_dbi_15_sql.out -rw-r--r-- 1 ken None 6512 Oct 24 03:45 trace_dbi_4.out -rw-r--r-- 1 ken None 6570 Oct 24 03:45 trace_dbi_4_sql.out -rw-r--r-- 1 ken None 10574 Oct 24 04:02 trace_dbi_5.out -rw-r--r-- 1 ken None 10632 Oct 24 04:03 trace_dbi_5_sql.out

    The first thing for you to do would be to read "How do I post a question effectively?" so that you understand the type of information we need and how to format it. Then create one or more SSCCE's to allow us to investigate: keep these as simple as possible, much like I've shown above.

    All of my examples use Perl 5.34 and DBI 1.643.

    — Ken

      Just some side notes:

      • Trace levels 1 and 2 are reserved for the DBI itself
      • The DBI itself only features levels 1..15, but the underlying DBD might support up to whatever they like. I think I saw one that took all over 100 to be special, but my recollection might be troubled.
      • Some DBD's support additional trace flags
        (all that from the documentation, they might have undocumented debugging flags)
      • Not all of the trace messages come from DBI itself, so check the DBD you use if they have additional documentation

      Enjoy, Have FUN! H.Merijn

        G'day Tux,

        ++ Thanks for supplying all of that extra info. It looks like you went to a fair amount of effort.

        — Ken

      Thanks a lot for your effort.I found what happens.I had to wrap the following in a BEGIN block at the top of the CGI script:

      BEGIN { $ENV{DBI_TRACE}='15=/var/www/xx/dbitrace.log';use DBI; }

      The output now shows everything including the sql statements and the data retrieved.
      What does BEGIN do and why has it made such a big difference? I think it has something to do with the environment that Apache/CGI runs,like that Apache initializes something before the perl script runs? What do you think?

        This is equivalent to DBI_TRACE=15 perl myscript.pl. Your solution looks to me to be the nuclear option. I would investigate further. With Apache, since Re: DBI trace has limited output (this has already done it for you without Apache.

Re: DBI trace has limited output
by Anonymous Monk on Oct 23, 2021 at 17:31 UTC

    The DBI documentation says that SQL statement tracing is not implemented in DBI, but in some DBDs. That might be one line of investigation. If your database driver does not support SQL tracing you are out of luck.

    Another line of investigation is whether you are enabling trace correctly. I have not used CGI in a long time, and may not be of help, but I suspect that to get help on that you will need to say how you are trying to enable tracing.

      I use DBI->trace( 99, 'my_program.trace' ); and it's other variations.I know that the dbd driver works because in other environments(non CGI) I get the desired outcome.
Re: DBI trace has limited output
by Anonymous Monk on Oct 23, 2021 at 17:48 UTC
    Where output are you looking?

Log In?
Username:
Password:

What's my password?
Create A New User
Domain Nodelet?
Node Status?
node history
Node Type: perlquestion [id://11137916]
Approved by Corion
help
Chatterbox?
and the web crawler heard nothing...

How do I use this? | Other CB clients
Other Users?
Others studying the Monastery: (2)
As of 2021-12-02 01:58 GMT
Sections?
Information?
Find Nodes?
Leftovers?
    Voting Booth?
    R or B?



    Results (16 votes). Check out past polls.

    Notices?