Use of uninitialized value in hash element at tail_n_mail line 3811

[joecreighton]

More specifically, these 6 lines came to us in email from cron:

Use of uninitialized value in hash element at tail_n_mail line 3811. Use of uninitialized value in hash element at tail_n_mail line 3811. Use of uninitialized value in printf at tail_n_mail line 3811. Use of uninitialized value in printf at tail_n_mail line 3811. Use of uninitialized value in printf at tail_n_mail line 3811. Use of uninitialized value in printf at tail_n_mail line 3811.

The logs roll over at midnight. We scan the logs during business hours only so this morning's first run looked at yesterday's log and today's log.

The alert we received by email was missing the filenames in the "From A,B" line, and was missing process and transaction numbers in the first "DETAIL" line from yesterday's log; the second "DETAIL" line in the alert is using transaction and process IDs from the first error instead of the second.

The alert (without the [transaction] to save space) received by email:

[1] From A, B(between lines 81,635 of  and 28 of , occurs 2 times) (1, 1)
First: [A] 2021-06-17 19:20:45 CDT userid@database 21064 domainname(46264)
Last:  [B] 2021-06-18 00:20:49 CDT userid@database 13533 domainname(59282)
ERROR: deadlock detected
DETAIL: Process ? waits for ShareLock on transaction ?; blocked by process ?. Process ? waits for ShareLock on transaction ?; blocked by process ?. Process ?: [transaction]
HINT: See server log for query details.
CONTEXT: while locking tuple(?) in relation "node"
STATEMENT: [transaction]
...
ERROR: deadlock detected
DETAIL: Process 21064 waits for ShareLock on transaction 2512098105; blocked by process 21065. Process 21065 waits for ShareLock on transaction 2512098104; blocked by process 21064. Process 21064: [transaction] Process 21065: [transaction]
HINT: See server log for query details.
CONTEXT: while locking tuple (2259,58) in relation "node"
STATEMENT: [transaction]

The first error from yesterday's log which is presented as the second error:

2021-06-17 19:20:45 CDT userid@database 21064 domanname(46264) ERROR:  deadlock detected
2021-06-17 19:20:45 CDT userid@database 21064 domainname(46264) DETAIL:  Process 21064 waits
 for ShareLock on transaction 2512098105; blocked by process 21065.
	Process 21065 waits for ShareLock on transaction 2512098104; blocked by process 21064.
	Process 21064: [transaction]
	Process 21065: [transaction]

The second error from today's log:

2021-06-18 00:20:49 CDT userid@database 13533 domainname(59282) ERROR:  deadlock detected
2021-06-18 00:20:49 CDT userid@database 13533 domainname(59282) DETAIL:  Process 13533 waits
 for ShareLock on transaction 2512503071; blocked by process 13532.
	Process 13532 waits for ShareLock on transaction 2512503070; blocked by process 13533.
	Process 13533: [transaction]
	Process 13532: [transaction]

[joecreighton]

Possibly related new data: no error from cron is received but the missing process and transaction numbers also seem to happen when both errors are in "yesterday's" log with none in "today's" log (2021-06-21). For example:

[1] (between lines 65,978 and 72,633, occurs 2 times)
First: 2021-06-20 17:20:24 CDT userid@database 55654 domainname(49354)
Last:  2021-06-20 19:20:36 CDT userid@database 13093 domainname(53958)
ERROR: deadlock detected
DETAIL: Process ? waits for ShareLock on transaction ?; blocked by process ?. Process ? waits for ShareLock on transaction ?; blocked by process ?. Process ?: [transaction]
HINT: See server log for query details.
CONTEXT: while locking tuple(?) in relation "node"
STATEMENT: [transaction]
...
ERROR: deadlock detected
DETAIL: Process 55654 waits for ShareLock on transaction 2517625502; blocked by process 55653. Process 55653 waits for ShareLock on transaction 2517625501; blocked by process 55654. Process 55654: [transaction]
HINT: See server log for query details.
CONTEXT: while locking tuple (2259,63) in relation "node"
STATEMENT: [transaction]