[Samba] Samba 2.2.5 and srv_spoolss_nt error

Fri Jun 21 07:05:03 GMT 2002

Hi!

I'm having problems with printing with Samba 2.2.5 and WinXP. I have samba
setup as a PDC and have 3 printers: HP LaserJet 5000N, HP LaserJet 8550DN
and HP DesignJet 1055CM. I used WinXP to upload the drivers for the
printers to XP clients and to 98 clients, and all went fine. I downloaded
the lastest PCL6 drivers for the Laserjet printers and the HPGL2/RTL
driver for the Designjet.

I can connect to the printers, view properties, print, cancel and resume
jobs. The problem is that the print queues on XP never refresh, and I
always have to hit F5 to refresh the queues manually after I print, cancel
or resume a job. In the logs I always get  an
"srv_spoolss_receive_message: got incorrect message size (14)!" error
after printing, canceling or resuming jobs.

I already deleted nt*.tdb and started all over but the error persists.

I had the same problem with 2.2.3a and 2.2.4.

***********************************
Level 6 log follows:

[2002/06/21 13:31:01, 3] smbd/ipc.c:api_fd_reply(296)
  Got API command 0x26 on pipe "spoolss" (pnum 7116)write_to_pipe: 7116
name: sp
oolss open: Yes len: 56
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_debug(60)
  000000 smb_io_rpc_hdr 
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
      0000 major     : 05
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
      0001 minor     : 00
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
      0002 pkt_type  : 00
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
      0003 flags     : 03
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
      0004 pack_type0: 10
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
      0005 pack_type1: 00
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
      0006 pack_type2: 00
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
      0007 pack_type3: 00
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint16(529)
      0008 frag_len  : 0038
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint16(529)
      000a auth_len  : 0000
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint32(558)
      000c call_id   : 00005d15
[2002/06/21 13:31:01, 5]
rpc_server/srv_pipe_hnd.c:unmarshall_rpc_header(391)
  unmarshall_rpc_header: using little-endian RPC
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_debug(60)
  000000 smb_io_rpc_hdr_req req
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint32(558)
      0000 alloc_hint: 00000020
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint16(529)
      0004 context_id: 0000
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint16(529)
      0006 opnum     : 0002
[2002/06/21 13:31:01, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(448)
  free_pipe_context: destroying talloc pool of size 0
[2002/06/21 13:31:01, 3] rpc_server/srv_pipe.c:api_pipe_request(1148)
  Doing \PIPE\spoolss
[2002/06/21 13:31:01, 4] rpc_server/srv_pipe.c:api_rpcTNP(1173)
  api_rpcTNP: api_spoolss_rpc op 0x2 - api_rpcTNP: pipe 28950 rpc
command: SPOOL
SS_SETJOB
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_debug(60)
  000000 spoolss_io_q_setjob 
[2002/06/21 13:31:01, 6] rpc_parse/parse_prs.c:prs_debug(60)
      000000 smb_io_pol_hnd printer handle
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint32(558)
          0000 data1: 00000000
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint32(558)
          0004 data2: 00000067
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint16(529)
          0008 data3: 0000
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint16(529)
          000a data4: 0000
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8s(645)
          000c data5: 63 1c 13 3d 66 0b 00 00 
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint32(558)
      0014 jobid: 000000f8
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint32(558)
      0018 level: 00000000
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint32(558)
      001c command: 00000005
[2002/06/21 13:31:01, 4]
rpc_server/srv_lsa_hnd.c:find_policy_by_hnd_internal(16
8)
  Found policy hnd[0] [000] 00 00 00 00 67 00 00 00  00 00 00 00 63 1C 13
3D  ..
..g... ....c..=
[2002/06/21 13:31:01, 4] lib/util.c:dump_data(1537)
  [010] 66 0B 00 00                                       f... 
[2002/06/21 13:31:01, 4] rpc_server/srv_spoolss_nt.c:get_printer_snum(362)
  short name:preto
[2002/06/21 13:31:01, 3] printing/print_generic.c:print_run_command(88)
  Running the command `/usr/bin/lprm -Ppreto 183' gave 0
[2002/06/21 13:31:01, 3] printing/print_generic.c:print_run_command(88)
  Running the command `/usr/bin/lpq  -Ppreto' gave 0
[2002/06/21 13:31:01, 3] printing/printing.c:print_queue_update(416)
  5 jobs in queue for preto
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_debug(60)
  000000 spoolss_io_r_setjob 
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_werror(617)
      0000 status: WERR_OK
[2002/06/21 13:31:01, 5] rpc_server/srv_pipe.c:api_rpcTNP(1218)
  api_rpcTNP: called api_spoolss_rpc successfully
[2002/06/21 13:31:01, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(448)
  free_pipe_context: destroying talloc pool of size 0
[2002/06/21 13:31:01, 6] rpc_server/srv_pipe_hnd.c:read_from_pipe(803)
  read_from_pipe: 7116 name: spoolss len: 5680
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_debug(60)
  000000 smb_io_rpc_hdr hdr
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
      0000 major     : 05
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
      0001 minor     : 00
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
      0002 pkt_type  : 02
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
      0003 flags     : 03
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
      0004 pack_type0: 10
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
      0005 pack_type1: 00
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
      0006 pack_type2: 00
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
      0007 pack_type3: 00
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint16(529)
      0008 frag_len  : 001c
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint16(529)
      000a auth_len  : 0000
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint32(558)
      000c call_id   : 00005d15
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_debug(60)
  000010 smb_io_rpc_hdr_resp resp
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint32(558)
      0010 alloc_hint: 00000004
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint16(529)
      0014 context_id: 0000
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
      0016 cancel_ct : 00
[2002/06/21 13:31:01, 5] rpc_parse/parse_prs.c:prs_uint8(500)
      0017 reserved  : 00
[2002/06/21 13:31:01, 5] smbd/ipc.c:copy_trans_params_and_data(62)
  copy_trans_params_and_data: params[0..0] data[0..28]
[2002/06/21 13:31:01, 5] lib/util.c:show_msg(268)
  size=84
  smb_com=0x25
  smb_rcls=0
  smb_reh=0
  smb_err=0
  smb_flg=136
  smb_flg2=1
[2002/06/21 13:31:01, 5] lib/util.c:show_msg(276)
  smb_tid=1
  smb_pid=1092
  smb_uid=100
  smb_mid=32832
  smt_wct=10
[2002/06/21 13:31:01, 5] lib/util.c:show_msg(285)
  smb_vwv[0]=0 (0x0)
[2002/06/21 13:31:01, 5] lib/util.c:show_msg(285)
  smb_vwv[1]=28 (0x1C)
[2002/06/21 13:31:01, 5] lib/util.c:show_msg(285)
  smb_vwv[2]=0 (0x0)
[2002/06/21 13:31:01, 5] lib/util.c:show_msg(285)
  smb_vwv[3]=0 (0x0)
[2002/06/21 13:31:01, 5] lib/util.c:show_msg(285)
  smb_vwv[4]=56 (0x38)
[2002/06/21 13:31:01, 5] lib/util.c:show_msg(285)
  smb_vwv[5]=0 (0x0)
[2002/06/21 13:31:01, 5] lib/util.c:show_msg(285)
  smb_vwv[6]=28 (0x1C)
[2002/06/21 13:31:01, 5] lib/util.c:show_msg(285)
  smb_vwv[7]=56 (0x38)
[2002/06/21 13:31:01, 5] lib/util.c:show_msg(285)
  smb_vwv[8]=0 (0x0)
[2002/06/21 13:31:01, 5] lib/util.c:show_msg(285)
  smb_vwv[9]=0 (0x0)
[2002/06/21 13:31:01, 5] lib/util.c:show_msg(291)
  smb_bcc=29
[2002/06/21 13:31:01, 6] lib/util_sock.c:write_socket(518)
  write_socket(12,88)
[2002/06/21 13:31:01, 6] lib/util_sock.c:write_socket(521)
  write_socket(12,88) wrote 88
[2002/06/21 13:31:01, 2]
rpc_server/srv_spoolss_nt.c:srv_spoolss_receive_message (730)
  srv_spoolss_receive_message: got incorrect message size (14)!
[2002/06/21 13:31:01, 5] smbd/oplock.c:receive_local_message(108)
  receive_local_message: doing select with timeout of 1 ms
[2002/06/21 13:31:04, 6] smbd/process.c:process_smb(876)

Thank you for your help

Nuno Beirao