sdwdate error subshell for sclockadj exited with unexpected non-zero exit code 1 / 127

Support
#1

I’ve been seeing these issues every day at various times when whonix just sits idle. It started a few days ago.

ERROR: timesync_post_error has been run with the following error text:
############################################

Error detected! Please report this bug!

BASH_SOURCE: /usr/lib/sdwdate/modules.d/sdwdate

SDW_EXIT_ON_ERROR: 1

SDW_MODE: daemon

SDWDATE_SUBSHELL_SCLOCKADJ_EXIT_CODE: 1

current_time: Mon Sep 21 06:10:00 UTC 2015

exit_code: 127

error_cause:

sdwdate_error_handler signal ERR detected in line 1318 with BASH_COMMAND: sdwdate_error “$FUNCNAME: subshell for sclockadj exited with unexpected non-zero exit code: $SDWDATE_SUBSHELL_SCLOCKADJ_EXIT_CODE”
############################################

#2

Using apparmor?

Which Whonix version?

#8
  • using whonix 11 stable repository + qubes 3 stable

ERROR: timesync_post_error has been run with the following error text:
############################################
## Error detected! Please report this bug! #
##
## BASH_SOURCE: /usr/lib/sdwdate/modules.d/sdwdate
## SDW_EXIT_ON_ERROR: 1
## SDW_MODE: daemon
## SDWDATE_SUBSHELL_SCLOCKADJ_EXIT_CODE: 127
## current_time: Tue Nov 24 15:11:15 UTC 2015
##
## exit_code: 127
## error_cause:
sdwdate_error_handler signal ERR detected in line 1318 with BASH_COMMAND: sdwdate_error “$FUNCNAME: subshell for sclockadj exited with unexpected non-zero exit code: $SDWDATE_SUBSHELL_SCLOCKADJ_EXIT_CODE”
############################################

kwrite /var/log/sdwdate.log

22279: Running sdwdate... pid: 22279 | LD_PRELOAD: 
22279: sdwdate_preparation: who_ami is set to user.
22279: dispatching DISPATCH_PRE (SDW_MODE: restartup): /usr/lib/timesync/timesync_pre --autostart --identifier "timesync" --progressbaridx "$ID" --mode "$SDW_MODE" --whoami "$who_ami"
22279: dispatching DISPATCH_PRE done.
22279: SDWDATE_CURRENT_POOL: SDWDATE_POOL_ONE | array_length: 14 | allowed_member_failures: 5 | temp: 4.76 | array_length_remember: 0
22279: dispatching DISPATCH_PREREQUISITE (SDW_MODE: restartup) (LD_PRELOAD: ): /usr/lib/anon-shared-helper-scripts/te_pe_tb_check
22279: DISPATCH_PREREQUISITE exited 0, continuing...
22279: dispatching {SDWDATE_TIME_TOOL_DISPATCH_PRE[SDWDATE_POOL_ONE]} (SDW_MODE: restartup): /usr/lib/timesync/timesync_progress --identifier "timesync" --progressbaridx "$ID" --mode "$SDW_MODE" --whoami "$who_ami" --progressx 15
22279: dispatching {SDWDATE_TIME_TOOL_DISPATCH_PRE[SDWDATE_POOL_ONE]} done.
22279: get   : swdi5ymnwmrqhycl.onion:80 | local time: Tue Nov 24 15:11:24 UTC 2015 | link_comment_part: NRKbeta	https://nrkbeta.no/tips	swdi5ymnwmrqhycl.onion
22279: result: swdi5ymnwmrqhycl.onion:80 | local time: Tue Nov 24 15:11:27 UTC 2015 | status: success | took: 5s | diff: 0 second(s)
22279: dispatching {SDWDATE_TIME_TOOL_DISPATCH_POST[SDWDATE_POOL_ONE]} (SDW_MODE: restartup): /usr/lib/timesync/timesync_progress --identifier "timesync" --progressbaridx "$ID" --mode "$SDW_MODE" --whoami "$who_ami" --progressx 30
22279: dispatching {SDWDATE_TIME_TOOL_DISPATCH_POST[SDWDATE_POOL_ONE]} done.
22279: SDWDATE_CURRENT_POOL: SDWDATE_POOL_TWO | array_length: 17 | allowed_member_failures: 6 | temp: 5.78 | array_length_remember: 0
22279: dispatching DISPATCH_PREREQUISITE (SDW_MODE: restartup) (LD_PRELOAD: ): /usr/lib/anon-shared-helper-scripts/te_pe_tb_check
22279: DISPATCH_PREREQUISITE exited 0, continuing...
22279: dispatching {SDWDATE_TIME_TOOL_DISPATCH_PRE[SDWDATE_POOL_TWO]} (SDW_MODE: restartup): /usr/lib/timesync/timesync_progress --identifier "timesync" --progressbaridx "$ID" --mode "$SDW_MODE" --whoami "$who_ami" --progressx 45
22279: dispatching {SDWDATE_TIME_TOOL_DISPATCH_PRE[SDWDATE_POOL_TWO]} done.
22279: get   : pltloztihmfrg2sw.onion:80 | local time: Tue Nov 24 15:11:31 UTC 2015 | link_comment_part: Salzburger-Piratenpartei 	2014-March-4 	Activism 	pltloztihmfrg2sw.onion 	https://pltloztihmfrg2sw.tor2web.org 	Austria
22279: result: pltloztihmfrg2sw.onion:80 | local time: Tue Nov 24 15:13:31 UTC 2015 | status: failed  | took: 122s | download_tool_exit_code: 2 | stdout:  | stderr: connect error: 0x06: TTL expired
22279: SDWDATE_CURRENT_POOL: SDWDATE_POOL_TWO | array_length: 17 | allowed_member_failures: 6 | temp: 5.78 | array_length_remember: 1
22279: dispatching DISPATCH_PREREQUISITE (SDW_MODE: restartup) (LD_PRELOAD: ): /usr/lib/anon-shared-helper-scripts/te_pe_tb_check
22279: DISPATCH_PREREQUISITE exited 0, continuing...
22279: dispatching {SDWDATE_TIME_TOOL_DISPATCH_PRE[SDWDATE_POOL_TWO]} (SDW_MODE: restartup): /usr/lib/timesync/timesync_progress --identifier "timesync" --progressbaridx "$ID" --mode "$SDW_MODE" --whoami "$who_ami" --progressx 45
22279: dispatching {SDWDATE_TIME_TOOL_DISPATCH_PRE[SDWDATE_POOL_TWO]} done.
22279: get   : ppdz5djzpo3w5k2z.onion:80 | local time: Tue Nov 24 15:13:33 UTC 2015 | link_comment_part: WildLeaks [34][35][36][37][38][39] 	2014-February-7 	WildLife Crime Activism 	ppdz5djzpo3w5k2z.onion 	https://secure.wildleaks.org 	United States/Africa
22279: result: ppdz5djzpo3w5k2z.onion:80 | local time: Tue Nov 24 15:13:43 UTC 2015 | status: success | took: 12s | diff: -2 second(s)
22279: dispatching {SDWDATE_TIME_TOOL_DISPATCH_POST[SDWDATE_POOL_TWO]} (SDW_MODE: restartup): /usr/lib/timesync/timesync_progress --identifier "timesync" --progressbaridx "$ID" --mode "$SDW_MODE" --whoami "$who_ami" --progressx 60
22279: dispatching {SDWDATE_TIME_TOOL_DISPATCH_POST[SDWDATE_POOL_TWO]} done.
22279: SDWDATE_CURRENT_POOL: SDWDATE_POOL_THREE | array_length: 11 | allowed_member_failures: 4 | temp: 3.74 | array_length_remember: 0
22279: dispatching DISPATCH_PREREQUISITE (SDW_MODE: restartup) (LD_PRELOAD: ): /usr/lib/anon-shared-helper-scripts/te_pe_tb_check
22279: DISPATCH_PREREQUISITE exited 0, continuing...
22279: dispatching {SDWDATE_TIME_TOOL_DISPATCH_PRE[SDWDATE_POOL_THREE]} (SDW_MODE: restartup): /usr/lib/timesync/timesync_progress --identifier "timesync" --progressbaridx "$ID" --mode "$SDW_MODE" --whoami "$who_ami" --progressx 65
22279: dispatching {SDWDATE_TIME_TOOL_DISPATCH_PRE[SDWDATE_POOL_THREE]} done.
22279: get   : 3g2upl4pq6kufc4m.onion:80 | local time: Tue Nov 24 15:13:44 UTC 2015 | link_comment_part: https://duck.co/forum/thread/1762/is-the-duckduckgo-hidden-service-legitimate
22279: result: 3g2upl4pq6kufc4m.onion:80 | local time: Tue Nov 24 15:13:53 UTC 2015 | status: success | took: 10s | diff: 0 second(s)
22279: dispatching {SDWDATE_TIME_TOOL_DISPATCH_POST[SDWDATE_POOL_THREE]} (SDW_MODE: restartup): /usr/lib/timesync/timesync_progress --identifier "timesync" --progressbaridx "$ID" --mode "$SDW_MODE" --whoami "$who_ami" --progressx 80
22279: dispatching {SDWDATE_TIME_TOOL_DISPATCH_POST[SDWDATE_POOL_THREE]} done.
22279: Results summary: one: 0 | two: -2 | three: 0 | second(s)
22279: Min: -2 | Max: 0 | Median diff: 0 second(s) [0 nanosecond(s)]
22279: local unixtime : 1448378035 | local time : Tue Nov 24 15:13:55 UTC 2015
22279: remote unixtime: 1448378035 | remote time: Tue Nov 24 15:13:55 UTC 2015
22279: require time change: 0 second(s) [0 nanosecond(s)]
22279: No need to set clock.
22279: dispatching DISPATCH_POST_SUCCESS (SDW_MODE: restartup): /usr/lib/timesync/timesync_post_success --autostart --identifier "timesync" --progressbaridx "$ID" --mode "$SDW_MODE" --whoami "$who_ami"
22279: dispatching DISPATCH_POST_SUCCESS done.
22279: Sleeping for 90 minutes. (RANDOMIZE: 1)
#9

It’s mysterious. We need a replacement for sclockadj anyhow. That will be sclockadj2. Which is non-trivial. And hopefully being worked on.