How to read postgres.log output?

I need to improve my database performance, in order to achieve that, I enabled the log in my postgresql.conf:

log_statement = 'all'
log_connections = on
log_disconnections = on

Why do I have 3 duration output in this SELECT ?

2016-02-29 15:35:07 CET [3492-349] postgres@uat LOG:  execute : SELECT ID FROM public.document WHERE documentID is NULL AND StatusID = (SELECT ID FROM public.status WHERE status = 'New') ORDER BY PriorityID DESC, ModTime ASC FOR UPDATE LIMIT 1
2016-02-29 15:35:07 CET [3492-350] postgres@uat LOG:  duration: 31.096 ms
2016-02-29 15:35:08 CET [3494-223] postgres@uat LOG:  duration: 0.090 ms
2016-02-29 15:35:08 CET [3494-224] postgres@uat LOG:  duration: 0.061 ms

EDIT

More information:

log_min_duration_statement = 2  
log_line_prefix = '%t [%p-%l] %q%u@%d '

Another example:

2016-02-29 16:56:14 CET [2145-1225] postgres@uat LOG:  execute : SELECT ID FROM public.document WHERE documentID is NULL AND StatusID = 1 ORDER BY PriorityID DESC, ModTime ASC FOR UPDATE LIMIT 1
2016-02-29 16:56:14 CET [2139-9001] postgres@uat LOG:  duration: 48.190 ms
2016-02-29 16:56:14 CET [2139-9002] postgres@uat LOG:  duration: 0.022 ms
2016-02-29 16:56:14 CET [2139-9003] postgres@uat LOG:  execute S_3: COMMIT
2016-02-29 16:56:14 CET [2139-9004] postgres@uat LOG:  duration: 0.207 ms
2016-02-29 16:56:14 CET [2145-1226] postgres@uat LOG:  duration: 51.172 ms
2016-02-29 16:56:15 CET [2143-1691] postgres@uat LOG:  duration: 0.079 ms
2016-02-29 16:56:15 CET [2143-1692] postgres@uat LOG:  duration: 0.055 ms

With csvlog as output:

```
2016-02-29 17:06:28.475 CET,"postgres","uat",2317,"eniac:50690",56d46bee.90d,1765,"SELECT",2016-02-29 17:03:58 CET,15/442,0,LOG,00000,"execute : SELECT ID FROM public.document WHERE documentID is NULL AND StatusID = 1 ORDER BY PriorityID DESC, ModTime ASC FOR UPDATE LIMIT 1",,,,,,,,,""
2016-02-29 17:06:28.507 CET,"postgres","uat",2317,"eniac:50690",56d46bee.90d,1766,"SELECT",2016-02-29 17:03:58 CET,

For clients using the extended query protocol, durations of PARSE, BIND, and EXECUTE steps are logged independently. See also the description of log_min_duration_statement.

Note: when not using csvlog as log_destination, one can still collect all the necessary information by configuring the log_line_prefix setting in postgresql.conf (and reload PostgreSQL when done).

log_line_prefix = '%t %h %p %u '        # special values:
                                        #   %a = application name
                                        #   %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
                                        #   %e = SQL state
                                        #   %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. ''

StackExchange Database Administrators Q#130794, answer score: 3