Обсуждение: Showing debug messages in my C function

Поиск
Список
Период
Сортировка

Showing debug messages in my C function

От
Jorge Arevalo
Дата:
Hello,

I'm sorry, because this may be a simple question: I'm programming a C
function that returns a set (PostgreSQL 8.4). The function crash, and
I'm trying to
debug it. I've read:

http://www.postgresql.org/docs/8.4/interactive/xfunc-c.html
http://www.postgresql.org/docs/8.4/interactive/error-message-reporting.html
http://www.postgresql.org/docs/current/static/runtime-config-logging.html

but I can't see any of my log messages. I'm using lines like this:

ereport(WARNING,(errcode(ERRCODE_WARNING), errmsg("This is a warning
message")));

or even simpler

elog(WARNING, "This is a warning message");

I've changed the level from WARNING to ERROR, and it doesn't work. A
log file is created, and when I start server, stop it, run a query... I can
see the messages logged by the server, but not my own messages, raised
with ereport or elog.

What's happening? This is the log part of my postgresql.conf

#------------------------------------------------------------------------------
# ERROR REPORTING AND LOGGING
#------------------------------------------------------------------------------

# - Where to Log -

log_destination = 'stderr'        # Valid values are combinations of
                    # stderr, csvlog, syslog and eventlog,
                    # depending on platform.  csvlog
                    # requires logging_collector to be on.

# This is used when logging to stderr:
logging_collector = on        # Enable capturing of stderr and csvlog
                    # into log files. Required to be on for
                    # csvlogs.
                    # (change requires restart)

# These are only used if logging_collector is on:
log_directory = 'pg_log'        # directory where log files are written,
                    # can be absolute or relative to PGDATA
log_filename = 'postgresql-%Y-%m-%d_%H%M%S.log'    # log file name pattern,
                    # can include strftime() escapes
#log_truncate_on_rotation = off        # If on, an existing log file of the
                    # same name as the new log file will be
                    # truncated rather than appended to.
                    # But such truncation only occurs on
                    # time-driven rotation, not on restarts
                    # or size-driven rotation.  Default is
                    # off, meaning append to existing files
                    # in all cases.
log_rotation_age = 1d            # Automatic rotation of logfiles will
                    # happen after that time.  0 disables.
log_rotation_size = 10MB        # Automatic rotation of logfiles will
                    # happen after that much log output.
                    # 0 disables.

# These are relevant when logging to syslog:
#syslog_facility = 'LOCAL0'
#syslog_ident = 'postgres'

#silent_mode = off            # Run server silently.
                    # DO NOT USE without syslog or
                    # logging_collector
                    # (change requires restart)


# - When to Log -

#client_min_messages = notice        # values in order of decreasing detail:
                    #   debug5
                    #   debug4
                    #   debug3
                    #   debug2
                    #   debug1
                    #   log
                    #   notice
                    #   warning
                    #   error

log_min_messages = debug5        # values in order of decreasing detail:
                    #   debug5
                    #   debug4
                    #   debug3
                    #   debug2
                    #   debug1
                    #   info
                    #   notice
                    #   warning
                    #   error
                    #   log
                    #   fatal
                    #   panic

log_error_verbosity = verbose        # terse, default, or verbose messages

log_min_error_statement = debug5    # values in order of decreasing detail:
                     #   debug5
                    #   debug4
                    #   debug3
                    #   debug2
                    #   debug1
                     #   info
                    #   notice
                    #   warning
                    #   error
                    #   log
                    #   fatal
                    #   panic (effectively off)

log_min_duration_statement = 0        # -1 is disabled, 0 logs all statements
                    # and their durations, > 0 logs only
                    # statements running at least this number
                    # of milliseconds


# - What to Log -

debug_print_parse = on
debug_print_rewritten = on
debug_print_plan = on
debug_pretty_print = on
#log_checkpoints = off
#log_connections = off
#log_disconnections = off
log_duration = on
#log_hostname = off
log_line_prefix = '%t '            # special values:
                    #   %u = user name
                    #   %d = database name
                    #   %r = remote host and port
                    #   %h = remote host
                    #   %p = process ID
                    #   %t = timestamp without milliseconds
                    #   %m = timestamp with milliseconds
                    #   %i = command tag
                    #   %c = session ID
                    #   %l = session line number
                    #   %s = session start timestamp
                    #   %v = virtual transaction ID
                    #   %x = transaction ID (0 if none)
                    #   %q = stop here in non-session
                    #        processes
                    #   %% = '%'
                    # e.g. '<%u%%%d> '
#log_lock_waits = off            # log lock waits >= deadlock_timeout
log_statement = 'all'            # none, ddl, mod, all
#log_temp_files = -1            # log temporary files equal or larger
                    # than the specified size in kilobytes;
                    # -1 disables, 0 logs all temp files
#log_timezone = unknown            # actually, defaults to TZ environment
                    # setting


Thanks in advance, and best regards
Jorge

Re: Showing debug messages in my C function

От
Tom Lane
Дата:
Jorge Arevalo <jorgearevalo@gis4free.org> writes:
> I'm sorry, because this may be a simple question: I'm programming a C
> function that returns a set (PostgreSQL 8.4). The function crash, and
> I'm trying to
> debug it. I've read:

> http://www.postgresql.org/docs/8.4/interactive/xfunc-c.html
> http://www.postgresql.org/docs/8.4/interactive/error-message-reporting.html
> http://www.postgresql.org/docs/current/static/runtime-config-logging.html

> but I can't see any of my log messages.

Seems likely to me that the function is crashing before it gets to any
of the elog calls; which would most likely be a problem in linking or in
declaring the function.  Did you remember to use the
PG_FUNCTION_INFO_V1() macro?  Try writing a trivial function that only
does an elog and see what it takes to get that to work.

            regards, tom lane

Re: Showing debug messages in my C function

От
Jorge Arevalo
Дата:
On Tue, Apr 13, 2010 at 10:04 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> Jorge Arevalo <jorgearevalo@gis4free.org> writes:
>> I'm sorry, because this may be a simple question: I'm programming a C
>> function that returns a set (PostgreSQL 8.4). The function crash, and
>> I'm trying to
>> debug it. I've read:
>
>> http://www.postgresql.org/docs/8.4/interactive/xfunc-c.html
>> http://www.postgresql.org/docs/8.4/interactive/error-message-reporting.html
>> http://www.postgresql.org/docs/current/static/runtime-config-logging.html
>
>> but I can't see any of my log messages.
>
> Seems likely to me that the function is crashing before it gets to any
> of the elog calls; which would most likely be a problem in linking or in
> declaring the function.  Did you remember to use the
> PG_FUNCTION_INFO_V1() macro?  Try writing a trivial function that only
> does an elog and see what it takes to get that to work.
>
>                        regards, tom lane
>

Yes, I put the PG_FUNCTION_INFO_V1(myFunction) macro.

I solved some small bugs, and I checked the function is called, but I
get a segmentation fault when try to call SRF_IS_FIRSTCALL. I think
this has no much sense, and the problem keeps hidden for another
reason.

I'm going to continue debugging, but if helps, I provide the
interesting part of log file.

Thanks!

Best regards,
Jorge

Вложения

Re: Showing debug messages in my C function

От
Jorge Arevalo
Дата:
Sorry, a mistake:

> Ok, I've tested the simple example of a SRF from
> http://www.postgresql.org/docs/8.4/interactive/xfunc-c.html (section
> 34.9.10) and the application crash in the same way. When tries to
> access SRF_IS_FIRSTCALL(), or any other PostgreSQL macro like
> SRF_FIRST_CALL_INIT(), PG_GETARG_UINT32(0), etc. But in the rest of my
> functions (non-SRF functions), everything works fine with these macros
> and the rest of the code.

The rest of my functions, non-SRF functions, don't use these macros,
of course. But work fine. Only the SRF-function crash.

Thanks and sorry for being annoying.

On Fri, Apr 16, 2010 at 12:51 PM, Jorge Arevalo
<jorgearevalo@gis4free.org> wrote:
> On Thu, Apr 15, 2010 at 8:16 PM, Jorge Arevalo
> <jorgearevalo@gis4free.org> wrote:
>> On Tue, Apr 13, 2010 at 10:04 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>>> Jorge Arevalo <jorgearevalo@gis4free.org> writes:
>>>> I'm sorry, because this may be a simple question: I'm programming a C
>>>> function that returns a set (PostgreSQL 8.4). The function crash, and
>>>> I'm trying to
>>>> debug it. I've read:
>>>
>>>> http://www.postgresql.org/docs/8.4/interactive/xfunc-c.html
>>>> http://www.postgresql.org/docs/8.4/interactive/error-message-reporting.html
>>>> http://www.postgresql.org/docs/current/static/runtime-config-logging.html
>>>
>>>> but I can't see any of my log messages.
>>>
>>> Seems likely to me that the function is crashing before it gets to any
>>> of the elog calls; which would most likely be a problem in linking or in
>>> declaring the function.  Did you remember to use the
>>> PG_FUNCTION_INFO_V1() macro?  Try writing a trivial function that only
>>> does an elog and see what it takes to get that to work.
>>>
>>>                        regards, tom lane
>>>
>>
>> Yes, I put the PG_FUNCTION_INFO_V1(myFunction) macro.
>>
>> I solved some small bugs, and I checked the function is called, but I
>> get a segmentation fault when try to call SRF_IS_FIRSTCALL. I think
>> this has no much sense, and the problem keeps hidden for another
>> reason.
>>
>> I'm going to continue debugging, but if helps, I provide the
>> interesting part of log file.
>>
>> Thanks!
>>
>> Best regards,
>> Jorge
>>
>
> Ok, I've tested the simple example of a SRF from
> http://www.postgresql.org/docs/8.4/interactive/xfunc-c.html (section
> 34.9.10) and the application crash in the same way. When tries to
> access SRF_IS_FIRSTCALL(), or any other PostgreSQL macro like
> SRF_FIRST_CALL_INIT(), PG_GETARG_UINT32(0), etc. But in the rest of my
> functions (non-SRF functions), everything works fine with these macros
> and the rest of the code.
>
> I provide another log file, with the results of the simple example
> execution. Another signal 11: Segmentation Fault. caused by line with
> SRF_IS_FIRSTCALL().
>
> Debugging...
>