Bug#436340: Installation freezes during "configure the clock" step
I spent some more time trying to understand what happens, and I came to the
following conclusions:
The problem seems to occur in the line 29 of the script
/var/lib/dpkg/info/clock-setup.postinst, "db_progress step 1".
If I comment out this line, everything goes on fine.
I'm new to debian, but I guess that it has something to do with the progress
bar (which seems to remain stuck at 0% after this modification, i really can't
tell because the screen changes very quickly).
What happens is quite strange, however. After I noticed that both the systems
I was trying to install on had a negative clock skew of 2 hours or more from the
retrieved UTC time, I experimented a bit with hw clock values (changing them from
bios) and found out that:
- Only negative clock skew make the script hang.
- The script seems not to hang, but to *wait* an amount of time proportional to
the clock skew found by rdate before going on to the partitioning step.
I've actually tried this with -1s, -30s, -90s...
In the end I was quite curious, so I've tried to search for some documentation for
db_progress in the debian developer's reference and in the debconf specification,
but I couldn't find nothing really useful (at first sight, anyway).
Hopefully, with this info the problem should be replicable.
Anyway, I'm sending back the logs of an execution trace of the lock-setup.postinst
script.
Aug 7 17:17:53 init: Starting pid 1123, console /dev/tty2: '/bin/sh'
Aug 7 17:18:35 init: Starting pid 1126, console /dev/tty3: '/bin/sh'
Aug 7 17:18:38 main-menu[1166]: INFO: Falling back to the package description for auto-install
Aug 7 17:18:38 main-menu[1166]: INFO: Falling back to the package description for ai-choosers
Aug 7 17:18:38 main-menu[1166]: INFO: Menu item 'clock-setup' selected
Aug 7 17:18:42 main-menu[1166]: (process:9336): + . /usr/share/debconf/confmodule
Aug 7 17:18:42 main-menu[1166]: (process:9336): + [ ! 1 ]
Aug 7 17:18:42 main-menu[1166]: (process:9336): + [ -z 1 ]
Aug 7 17:18:42 main-menu[1166]: (process:9336): + DEBCONF_OLD_FD_BASE=4
Aug 7 17:18:42 main-menu[1166]: (process:9336): + export DEBCONF_OLD_FD_BASE
Aug 7 17:18:42 main-menu[1166]: (process:9336): + db_input medium clock-setup/ntp
Aug 7 17:18:42 main-menu[1166]: (process:9336): + _db_cmd INPUT medium clock-setup/ntp
Aug 7 17:18:42 main-menu[1166]: (process:9336): + IFS= printf %s\n INPUT medium clock-setup/ntp
Aug 7 17:18:42 main-menu[1166]: (process:9336): + IFS=
Aug 7 17:18:42 main-menu[1166]: (process:9336): read -r _db_internal_line
Aug 7 17:18:42 main-menu[1166]: (process:9336): + RET=question will be asked
Aug 7 17:18:42 main-menu[1166]: (process:9336): + return 0
Aug 7 17:18:42 main-menu[1166]: (process:9336): + db_go
Aug 7 17:18:42 main-menu[1166]: (process:9336): + _db_cmd GO
Aug 7 17:18:42 main-menu[1166]: (process:9336): + IFS= printf %s\n GO
Aug 7 17:18:42 main-menu[1166]: (process:9336): + IFS=
Aug 7 17:18:42 main-menu[1166]: (process:9336): read -r _db_internal_line
Aug 7 17:18:42 main-menu[1166]: (process:9336): + RET=ok
Aug 7 17:18:42 main-menu[1166]: (process:9336): + return 0
Aug 7 17:18:42 main-menu[1166]: (process:9336): + db_get clock-setup/ntp
Aug 7 17:18:42 main-menu[1166]: (process:9336): + _db_cmd GET clock-setup/ntp
Aug 7 17:18:42 main-menu[1166]: (process:9336): + IFS= printf %s\n GET clock-setup/ntp
Aug 7 17:18:42 main-menu[1166]: (process:9336): + IFS=
Aug 7 17:18:42 main-menu[1166]: (process:9336): read -r _db_internal_line
Aug 7 17:18:42 main-menu[1166]: (process:9336): +
Aug 7 17:18:42 main-menu[1166]: (process:9336): RET=true
Aug 7 17:18:42 main-menu[1166]: (process:9336):
Aug 7 17:18:42 main-menu[1166]: (process:9336): +
Aug 7 17:18:42 main-menu[1166]: (process:9336): return
Aug 7 17:18:42 main-menu[1166]: (pro
Aug 7 17:18:42 main-menu[1166]: cess:9336): 0
Aug 7 17:18:42 main-menu[1166]: (process:9336):
Aug 7 17:18:42 main-menu[1166]: (process:9336): +
Aug 7 17:18:42 main-menu[1166]: (process:9336): [
Aug 7 17:18:42 main-menu[1166]: (process:9336): true
Aug 7 17:18:42 main-menu[1166]: (process:9336): =
Aug 7 17:18:42 main-menu[1166]: (process:9336): true
Aug 7 17:18:42 main-menu[1166]: (process:9336): ]
Aug 7 17:18:42 main-menu[1166]: (process:9336):
Aug 7 17:18:42 main-menu[1166]: (process:9336): +
Aug 7 17:18:42 main-menu[1166]: (process:9336): db_input
Aug 7 17:18:42 main-menu[1166]: (process:9336): low
Aug 7 17:18:42 main-menu[1166]: (process:9336): clock-setup/ntp-server
Aug 7 17:18:42 main-menu[1166]: (process:9336):
Aug 7 17:18:42 main-menu[1166]: (process:9336): +
Aug 7 17:18:42 main-menu[1166]: (process:9336): _db_cmd
Aug 7 17:18:42 main-menu[1166]: (process:9336): INPUT low
Aug 7 17:18:42 main-menu[1166]: (process:9336): clock-setup/ntp-server
Aug 7 17:18:42 main-menu[1166]: (process:9336):
Aug 7 17:18:42 main-menu[1166]: (process:9336): +
Aug 7 17:18:42 main-menu[1166]: (process:9336): IFS=
Aug 7 17:18:42 main-menu[1166]: (process:9336): printf
Aug 7 17:18:42 main-menu[1166]: (process:9336): %s\n
Aug 7 17:18:42 main-menu[1166]: (process:9336): INPUT low clock-setup/ntp-server
Aug 7 17:18:42 main-menu[1166]: (process:9336):
Aug 7 17:18:42 main-menu[1166]: (process:9336): +
Aug 7 17:18:42 main-menu[1166]: (process:9336): IFS=
Aug 7 17:18:42 main-menu[1166]: (process:9336): read
Aug 7 17:18:42 main-menu[1166]: (process:9336): -r
Aug 7 17:18:42 main-menu[1166]: (process:9336): _db_internal_line
Aug 7 17:18:42 main-menu[1166]: (process:9336):
Aug 7 17:18:42 main-menu[1166]: (process:9336): +
Aug 7 17:18:42 main-menu[1166]: (process:9336): RET=question will be asked
Aug 7 17:18:42 main-menu[1166]: (process:9336):
Aug 7 17:18:42 main-menu[1166]: (process:9336): +
Aug 7 17:18:42 main-menu[1166]: (process:9336): return
Aug 7 17:18:42 main-menu[1166]: (process:9336): 0
Aug 7 17:18:42 main-menu[1166]: (process:9336):
Aug 7 17:18:42 main-menu[1166]: (process:9336): +
Aug 7 17:18:42 main-menu[1166]: (process:9336): db_go
Aug 7 17:18:42 main-menu[1166]: (process:9336):
Aug 7 17:18:42 main-menu[1166]: (process:9336): +
Aug 7 17:18:42 main-menu[1166]: (process:9336): _db_cmd
Aug 7 17:18:42 main-menu[1166]: (process:9336): GO
Aug 7 17:18:42 main-menu[1166]: (process:9336):
Aug 7 17:18:42 main-menu[1166]: (process:9336): +
Aug 7 17:18:42 main-menu[1166]: (pro
Aug 7 17:19:04 main-menu[1166]: cess:9336): IFS=
Aug 7 17:19:04 main-menu[1166]: (process:9336): printf
Aug 7 17:19:04 main-menu[1166]: (process:9336): %s\n
Aug 7 17:19:04 main-menu[1166]: (process:9336): GO
Aug 7 17:19:04 main-menu[1166]: (process:9336):
Aug 7 17:19:04 main-menu[1166]: (process:9336): +
Aug 7 17:19:04 main-menu[1166]: (process:9336): IFS=
Aug 7 17:19:04 main-menu[1166]: (process:9336): read
Aug 7 17:19:04 main-menu[1166]: (process:9336): -r
Aug 7 17:19:04 main-menu[1166]: (process:9336): _db_internal_line
Aug 7 17:19:04 main-menu[1166]: (process:9336):
Aug 7 17:19:04 main-menu[1166]: (process:9336): +
Aug 7 17:19:04 main-menu[1166]: (process:9336): RET=ok
Aug 7 17:19:04 main-menu[1166]: (process:9336):
Aug 7 17:19:04 main-menu[1166]: (process:9336): +
Aug 7 17:19:04 main-menu[1166]: (process:9336): return
Aug 7 17:19:04 main-menu[1166]: (process:9336): 0
Aug 7 17:19:04 main-menu[1166]: (process:9336):
Aug 7 17:19:04 main-menu[1166]: (process:9336): +
Aug 7 17:19:04 main-menu[1166]: (process:9336): db_get
Aug 7 17:19:04 main-menu[1166]: (process:9336): clock-setup/ntp-server
Aug 7 17:19:04 main-menu[1166]: (process:9336):
Aug 7 17:19:04 main-menu[1166]: (process:9336): +
Aug 7 17:19:04 main-menu[1166]: (process:9336): _db_cmd
Aug 7 17:19:04 main-menu[1166]: (process:9336): GET clock-setup/ntp-server
Aug 7 17:19:04 main-menu[1166]: (process:9336):
Aug 7 17:19:04 main-menu[1166]: (process:9336): +
Aug 7 17:19:04 main-menu[1166]: (process:9336): IFS=
Aug 7 17:19:04 main-menu[1166]: (process:9336): printf
Aug 7 17:19:04 main-menu[1166]: (process:9336): %s\n
Aug 7 17:19:04 main-menu[1166]: (process:9336): GET clock-setup/ntp-server
Aug 7 17:19:04 main-menu[1166]: (process:9336):
Aug 7 17:19:04 main-menu[1166]: (process:9336): +
Aug 7 17:19:04 main-menu[1166]: (process:9336): IFS=
Aug 7 17:19:04 main-menu[1166]: (process:9336): read
Aug 7 17:19:04 main-menu[1166]: (process:9336): -r
Aug 7 17:19:04 main-menu[1166]: (process:9336): _db_internal_line
Aug 7 17:19:04 main-menu[1166]: (process:9336):
Aug 7 17:19:04 main-menu[1166]: (process:9336): +
Aug 7 17:19:04 main-menu[1166]: (process:9336): RET=0.debian.pool.ntp.org
Aug 7 17:19:04 main-menu[1166]: (process:9336):
Aug 7 17:19:04 main-menu[1166]: (process:9336): +
Aug 7 17:19:04 main-menu[1166]: (process:9336): return
Aug 7 17:19:04 main-menu[1166]: (process:9336): 0
Aug 7 17:19:04 main-menu[1166]: (process:9336):
Aug 7 17:19:04 main-menu[1166]: (process:9
Aug 7 17:19:04 main-menu[1166]: 336): +
Aug 7 17:19:04 main-menu[1166]: (process:9336): server=0.debian.pool.ntp.org
Aug 7 17:19:04 main-menu[1166]: (process:9336):
Aug 7 17:19:04 main-menu[1166]: (process:9336): +
Aug 7 17:19:04 main-menu[1166]: (process:9336): db_progress
Aug 7 17:19:04 main-menu[1166]: (process:9336): START
Aug 7 17:19:04 main-menu[1166]: (process:9336): 0
Aug 7 17:19:04 main-menu[1166]: (process:9336): 1
Aug 7 17:19:04 main-menu[1166]: (process:9336): clock-setup/progress/title
Aug 7 17:19:04 main-menu[1166]: (process:9336):
Aug 7 17:19:04 main-menu[1166]: (process:9336): +
Aug 7 17:19:04 main-menu[1166]: (process:9336): _db_cmd
Aug 7 17:19:04 main-menu[1166]: (process:9336): PROGRESS START
Aug 7 17:19:04 main-menu[1166]: (process:9336): 0
Aug 7 17:19:04 main-menu[1166]: (process:9336): 1
Aug 7 17:19:04 main-menu[1166]: (process:9336): clock-setup/progress/title
Aug 7 17:19:04 main-menu[1166]: (process:9336):
Aug 7 17:19:04 main-menu[1166]: (process:9336): +
Aug 7 17:19:04 main-menu[1166]: (process:9336): IFS=
Aug 7 17:19:04 main-menu[1166]: (process:9336): printf
Aug 7 17:19:04 main-menu[1166]: (process:9336): %s\n
Aug 7 17:19:04 main-menu[1166]: (process:9336): PROGRESS START 0 1 clock-setup/progress/title
Aug 7 17:19:04 main-menu[1166]: (process:9336):
Aug 7 17:19:04 main-menu[1166]: (process:9336): +
Aug 7 17:19:04 main-menu[1166]: (process:9336): IFS=
Aug 7 17:19:04 main-menu[1166]: (process:9336): read
Aug 7 17:19:04 main-menu[1166]: (process:9336): -r
Aug 7 17:19:04 main-menu[1166]: (process:9336): _db_internal_line
Aug 7 17:19:04 main-menu[1166]: (process:9336):
Aug 7 17:19:04 main-menu[1166]: (process:9336): +
Aug 7 17:19:04 main-menu[1166]: (process:9336): RET=OK
Aug 7 17:19:04 main-menu[1166]: (process:9336):
Aug 7 17:19:04 main-menu[1166]: (process:9336): +
Aug 7 17:19:04 main-menu[1166]: (process:9336): return
Aug 7 17:19:04 main-menu[1166]: (process:9336): 0
Aug 7 17:19:04 main-menu[1166]: (process:9336):
Aug 7 17:19:04 main-menu[1166]: (process:9336): +
Aug 7 17:19:04 main-menu[1166]: (process:9336): db_progress
Aug 7 17:19:04 main-menu[1166]: (process:9336): INFO
Aug 7 17:19:04 main-menu[1166]: (process:9336): clock-setup/progress/ntp
Aug 7 17:19:04 main-menu[1166]: (process:9336):
Aug 7 17:19:04 main-menu[1166]: (process:9336): +
Aug 7 17:19:04 main-menu[1166]: (process:9336): _db_cmd
Aug 7 17:19:04 main-menu[1166]: (
Aug 7 15:20:13 main-menu[1166]: process:9336): PROGRESS INFO
Aug 7 15:20:13 main-menu[1166]: (process:9336): clock-setup/progress/ntp
Aug 7 15:20:13 main-menu[1166]: (process:9336):
Aug 7 15:20:13 main-menu[1166]: (process:9336): +
Aug 7 15:20:13 main-menu[1166]: (process:9336): IFS=
Aug 7 15:20:13 main-menu[1166]: (process:9336): printf
Aug 7 15:20:13 main-menu[1166]: (process:9336): %s\n
Aug 7 15:20:13 main-menu[1166]: (process:9336): PROGRESS INFO clock-setup/progress/ntp
Aug 7 15:20:13 main-menu[1166]: (process:9336):
Aug 7 15:20:13 main-menu[1166]: (process:9336): +
Aug 7 15:20:13 main-menu[1166]: (process:9336): IFS=
Aug 7 15:20:13 main-menu[1166]: (process:9336): read
Aug 7 15:20:13 main-menu[1166]: (process:9336): -r
Aug 7 15:20:13 main-menu[1166]: (process:9336): _db_internal_line
Aug 7 15:20:13 main-menu[1166]: (process:9336):
Aug 7 15:20:13 main-menu[1166]: (process:9336): +
Aug 7 15:20:13 main-menu[1166]: (process:9336): RET=OK
Aug 7 15:20:13 main-menu[1166]: (process:9336):
Aug 7 15:20:13 main-menu[1166]: (process:9336): +
Aug 7 15:20:13 main-menu[1166]: (process:9336): return
Aug 7 15:20:13 main-menu[1166]: (process:9336): 0
Aug 7 15:20:13 main-menu[1166]: (process:9336):
Aug 7 15:20:13 main-menu[1166]: (process:9336): +
Aug 7 15:20:13 main-menu[1166]: (process:9336): log-output
Aug 7 15:20:13 main-menu[1166]: (process:9336): -t
Aug 7 15:20:13 main-menu[1166]: (process:9336): clock-setup
Aug 7 15:20:13 main-menu[1166]: (process:9336): --pass-stdout
Aug 7 15:20:13 main-menu[1166]: (process:9336): rdate
Aug 7 15:20:13 main-menu[1166]: (process:9336): -o
Aug 7 15:20:13 main-menu[1166]: (process:9336): 123
Aug 7 15:20:13 main-menu[1166]: (process:9336): -nv
Aug 7 15:20:13 main-menu[1166]: (process:9336): 0.debian.pool.ntp.org
Aug 7 15:20:13 main-menu[1166]: (process:9336):
Aug 7 15:20:13 main-menu[1166]: (process:9336): +
Aug 7 15:20:13 main-menu[1166]: (process:9336): RDATE_OUT=Tue Aug 7 15:20:13 UTC 2007
Aug 7 15:20:13 main-menu[1166]: (process:9336): rdate: adjust local clock by -7136.538513 seconds
Aug 7 15:20:13 main-menu[1166]: (process:9336):
Aug 7 15:20:13 main-menu[1166]: (process:9336): +
Aug 7 15:20:13 main-menu[1166]: (process:9336): log
Aug 7 15:20:13 main-menu[1166]: (process:9336): Tue Aug 7 15:20:13 UTC
Aug 7 15:20:13 clock-setup: Tue Aug 7 15:20:13 UTC 2007 rdate: adjust local clock by -7136.538513 seconds
Reply to: