Showing debug messages in my C function

Started by Jorge Arevaloalmost 16 years ago4 messagesgeneral
Jump to latest
#1Jorge Arevalo
jorgearevalo@gis4free.org

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

#2Tom Lane
tgl@sss.pgh.pa.us
In reply to: Jorge Arevalo (#1)
Re: Showing debug messages in my C function

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

#3Jorge Arevalo
jorgearevalo@gis4free.org
In reply to: Tom Lane (#2)
Re: Showing debug messages in my C function

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

Attachments:

postgresql-2010-04-15_195917.logapplication/octet-stream; name=postgresql-2010-04-15_195917.logDownload
#4Jorge Arevalo
jorgearevalo@gis4free.org
In reply to: Jorge Arevalo (#1)
Re: Showing debug messages in my C function

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:

Show quoted text

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...